Hibernate Statistics Logging

Question

私は、Hibernateのセッションログを解釈していません。 私が実装したTimeWatchのいくつかのログに基づいて、多くのクエリが遅くなるという主な問題があります。 さらに問題を追跡するために、私は、クエリを実行したり接続を取得するために時間が失われているかどうかを確認する目的で、セッションのロギングを有効にしました（これは誤った構成を意味します）。

少しのユースケースについて - Oracle DB、Spring、Hibernate。 「忙しい時」には最大値があります。データベースに対してクエリを実行する15個のスレッドのうちの1つです。何も特別なことはないと思います。

これで、hibernateセッションログが好きです。

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) 

しかし、それは正確に何を意味するのでしょうか？

クエリを実行するために、私は現時点で解釈何

• 1509926ナノ秒（1.5ミリ秒）：接続を取得するためのOK
• 2893793341ナノ秒（2.8秒）ようだ：OKではない を:(文を調製するための
• 2893869403ナノ秒（2.8秒）： OKではない:(

準備声明は何を意味していますか？ javadocから読み込んだものは、クエリが最適化のためにデータベースに送られることを意味します。 しかし、なぜそれは常に接続の必要性を取得する時間の周りですか？

問題を追跡する方法についてのアドバイス、根本的な原因がさらにありますか？

問題の原因に関するヒントはありますか？

ありがとうございました！

敬具、 ステファン

Answer 1

デフォルトのHibernate統計は非常に有益ではありません。今後のバージョンの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クラスを持っています

Etvoilà！

これで、統計を監視して、Dropwizard Metricsがサポートする任意の形式にエクスポートできます。また、Dropwizard Metricsはさまざまなリザーバを使用しているため、ユースケースに最適なものを選択できます。

Dropwizardメトリックの実際の能力を確認するには、FlexyPoolもチェックしてください。