2017-03-30 4 views
2

최대 절전 모드 세션 로그를 해석하지 못했습니다. 필자는 구현 한 일부 TimeWatch 로깅을 기반으로 많은 쿼리가 느린 것과 같은 주된 문제가 있습니다. 문제를 추가로 추적하기 위해 최대 절전 모드 세션 기록을 사용하여 쿼리를 실행하거나 연결을 얻는 데 시간이 손실되는지 확인하는 것이 목표였습니다 (이는 잘못된 구성을 의미합니다).최대 절전 모드 통계 로깅

약간의 유스 케이스에 대해 - Oracle DB, Spring, Hibernate. "바쁜 시간"에는 최대치가 있습니다. 데이터베이스에 대해 쿼리를 실행하는 15 개의 스레드 그래서 특별한 것은 없습니다.

이제 최대 절전 모드 세션 로그를 볼 수 있습니다.

2017-03-30 13:35:13.834+0200 [process-documents-task-6] I [/] o.h.e.i.StatisticalLoggingSessionEventListener - Session Metrics { 
    636713687 nanoseconds spent acquiring 1 JDBC connections; 
    57993 nanoseconds spent releasing 1 JDBC connections; 
    636859879 nanoseconds spent preparing 1 JDBC statements; 
    2231526 nanoseconds spent executing 1 JDBC statements; 
    0 nanoseconds spent executing 0 JDBC batches; 
    0 nanoseconds spent performing 0 L2C puts; 
    0 nanoseconds spent performing 0 L2C hits; 
    0 nanoseconds spent performing 0 L2C misses; 
    0 nanoseconds spent executing 0 flushes (flushing a total of 0 entities and 0 collections); 
    9261 nanoseconds spent executing 1 partial-flushes (flushing a total of 0 entities and 0 collections) 

또는

2017-03-30 13:35:16.073+0200 [process-documents-task-8] I [/] o.h.e.i.StatisticalLoggingSessionEventListener - Session Metrics { 
    2893793341 nanoseconds spent acquiring 1 JDBC connections; 
    22196 nanoseconds spent releasing 1 JDBC connections; 
    2893869403 nanoseconds spent preparing 1 JDBC statements; 
    1509926 nanoseconds spent executing 1 JDBC statements; 
    0 nanoseconds spent executing 0 JDBC batches; 
    0 nanoseconds spent performing 0 L2C puts; 
    0 nanoseconds spent performing 0 L2C hits; 
    0 nanoseconds spent performing 0 L2C misses; 
    0 nanoseconds spent executing 0 flushes (flushing a total of 0 entities and 0 collections); 
    4056 nanoseconds spent executing 1 partial-flushes (flushing a total of 0 entities and 0 collections) 

하지만 그건 정확히 무엇을 의미합니까?

나는 순간

    쿼리 (1.5 밀리 초)을 실행하기위한
  • 1509926 나노초에서 해석하는 것 : 연결 (2.8 초) 취득에 대한 확인
  • 2893793341 나노초를 보인다 : 확인하지 을 :(성명 (2.8 초) 준비를위한
  • 2893869403 나노초 : 확인되지 않음을 :(

성명서 작성의 의미는 무엇입니까? javadoc에서 읽은 것에서는 쿼리가 최적화를 위해 데이터베이스로 전송된다는 의미 일 수 있습니다. 하지만 연결 요구 사항을 얻는 데 항상 시간이 걸리는 이유는 무엇입니까?

문제를 근본적으로 추적하는 방법에 대한 조언은 무엇입니까?

또는 문제의 원인에 대한 힌트가 있습니까?

도움 주셔서 감사합니다.

안부, 스테판

+0

DB 연결 풀 구성도 제공하는 것이 좋습니다. – zloster

+0

풀 : 최소 크기 2, 최대 크기 15 모든 스레드가 열리는 별도의 트랜잭션이 있습니다 스레드가 서로 다른 데이터베이스에 연결합니다 (모두 동일한 풀 설정을 사용합니다) – StrongSteve

+0

여기 SO 요청 구성에있는 누군가가 실제 구성을 볼 것으로 예상됩니다 즉 XML 또는 속성 파일 등). 예를 들어 다음을보십시오. http://stackoverflow.com/a/11827895/25429. 다음 단계는 DB 연결 풀의 로그를 검사하는 방법을 찾는 것입니다. c3p0에서 연결에 대한 로그 예 : http://stackoverflow.com/questions/11819610/connection-pool-c3p0-logging#comment15714502_11821121 풀이 응용 프로그램에 제공 할 수있는 4 개의 무료 연결이 있음을 알립니다. 사용중인 DB 풀의 문서를 참조해야합니다. – zloster

답변

0

기본 최대 절전 모드 통계는 매우 유익하지 않습니다. 우리는 Hibernate의 차후 버전에서이 부분을 향상시킬 계획이다.

그러나 my book에서 설명한 것처럼 Dropwizard Metrics 위에 빌드 된 Statistics 구현을 제공 할 수 있습니다.

public class TransactionStatisticsFactory implements StatisticsFactory { 

    @Override 
    public StatisticsImplementor buildStatistics(SessionFactoryImplementor sessionFactory) { 
     return new TransactionStatistics(); 
    } 
} 

그리고 다음과 같이 구성합니다 :

당신은 StatisticsFactory 구현을 만들 필요가

public class TransactionStatistics extends ConcurrentStatisticsImpl { 

    private static final ThreadLocal<AtomicLong> startNanos = new ThreadLocal<AtomicLong>() { 
     @Override protected AtomicLong initialValue() { 
      return new AtomicLong(); 
     } 
    }; 

    private static final ThreadLocal<AtomicLong> connectionCounter = new ThreadLocal<AtomicLong>() { 
     @Override protected AtomicLong initialValue() { 
      return new AtomicLong(); 
     } 
    }; 

    private StatisticsReport report = new StatisticsReport(); 

    @Override public void connect() { 
     connectionCounter.get().incrementAndGet(); 
     startNanos.get().compareAndSet(0, System.nanoTime()); 
     super.connect(); 
    } 

    @Override public void endTransaction(boolean success) { 
     try { 
      report.transactionTime(System.nanoTime() - startNanos.get().get()); 
      report.connectionsCount(connectionCounter.get().get()); 
      report.generate(); 
     } finally { 
      startNanos.remove(); 
      connectionCounter.remove(); 
     } 
     super.endTransaction(success); 
    } 
} 

: 당신을 가정 한마디로

org.hibernate.stat.internal.ConcurrentStatisticsImpl 확장하는 TransactionStatistics 클래스가

Et voilà!

이제 통계를 모니터링하고 Dropwizard Metrics가 지원하는 모든 형식으로 통계를 내보낼 수 있습니다. 그리고 Dropwizard Metrics는 다양한 저장소를 사용하므로 사용 사례에 맞는 최상의 저장소를 선택할 수 있습니다.

Dropwizard Metrics의 진정한 힘을 보려면 FlexyPool도 확인하십시오.

관련 문제