Hibernate - 第2レベルのキャッシュ使用状況を確認するにはどうすればよいですか？

Question

私はSpring HibernateをEhcache経由で第2レベルのキャッシュとともに使用しています。

<!-- JDK version --> 
<java.version>1.8</java.version> 

<!-- Spring version --> 
<spring.version>4.1.0.RELEASE</spring.version> 

<!-- Hibernate version --> 
<hibernate.version>4.3.4.Final</hibernate.version> 

私は定義された2つのエンティティクラスました：

エンティティはHBMファイルを介しマッピングされている

TEd5BatTrigとTEd5Jobを。

TEd5BatTrig.hbm.xml - >

<hibernate-mapping> 
    <class name="com.mycompany.myapp.domain.TEd5BatTrig" table="T_ED5_BAT_TRIG"> 
     <cache usage="read-only"/> 
     <id name="batTrigCd" type="string"> 
      <column name="BAT_TRIG_CD" length="20" /> 
      <generator class="assigned" /> 
     </id> 
     <property name="batTrigDescTx" type="string"> 
      <column name="BAT_TRIG_DESC_TX" /> 
     </property> 
     <property name="lupUserId" type="string"> 
      <column name="LUP_USER_ID" length="20" not-null="true" /> 
     </property> 
     <property name="lupTs" type="java.sql.Timestamp"> 
      <column name="LUP_TS" not-null="true" /> 
     </property> 
     <set name="TEd5Jobs" table="T_ED5_JOB" inverse="true" lazy="true" fetch="select"> 
      <key> 
       <column name="BAT_TRIG_CD" length="20" /> 
      </key> 
      <one-to-many class="com.mycompany.myapp.domain.TEd5Job" /> 
     </set> 
    </class> 
</hibernate-mapping> 

TEd5Job.hbm.xml - 以下>

<hibernate-mapping> 
    <class name="com.mycompany.myapp.domain.TEd5Job" table="T_ED5_JOB"> 
     <cache usage="read-only"/> 
     <id name="jobId" type="big_decimal"> 
      <column name="JOB_ID" precision="22" scale="0" /> 
      <generator class="assigned" /> 
     </id> 
     <many-to-one name="TEd5BatTrig" class="com.mycompany.myapp.domain.TEd5BatTrig" fetch="select"> 
      <column name="BAT_TRIG_CD" length="20" /> 
     </many-to-one> 
     <property name="calledPgmNm" type="string"> 
      <column name="CALLED_PGM_NM" length="100" /> 
     </property> 
     <property name="lupUserId" type="string"> 
      <column name="LUP_USER_ID" length="20" not-null="true" /> 
     </property> 
     <property name="lupTs" type="java.sql.Timestamp"> 
      <column name="LUP_TS" not-null="true" /> 
     </property> 
    </class> 
</hibernate-mapping> 

私の春の設定（言及のみ関連する詳細情報）

<bean id="sessionFactory" 
     class="org.springframework.orm.hibernate4.LocalSessionFactoryBean"> 
     <property name="dataSource" ref="dataSource"></property> 
     <property name="hibernateProperties"> 
      <props> 
       <prop key="hibernate.dialect">org.hibernate.dialect.Oracle10gDialect</prop> 

       <!-- enable 2nd level cache --> 
       <prop key="hibernate.cache.use_second_level_cache">true</prop> 

       <!-- setup 2nd level cache --> 
       <prop key="hibernate.cache.region.factory_class">org.hibernate.cache.ehcache.EhCacheRegionFactory 
       </prop> 

       <prop key="show_sql">true</prop> 

       <prop key="hibernate.generate_statistics">true</prop> 

       <prop key="net.sf.ehcache.configurationResourceName">/ehcache.xml</prop> 

      </props> 
     </property> 
     <property name="mappingLocations"> 

      <list> 

       <!-- <value>classpath*:hbm.xml</value> --> 
       <value>classpath*:TEd5BatTrig.hbm.xml</value> 
       <value>classpath*:TEd5Job.hbm.xml</value> 

      </list> 
     </property> 
     <!-- set auto scan the Entity, otherwise you will get 'Unknown entiy' error --> 
     <property name="packagesToScan" value="com.mycompany.myapp.domain" /> 
    </bean> 

です

以下は私のehcache設定ファイルです：

最後に、以下の10

<?xml version="1.0" encoding="UTF-8"?> 
<ehcache xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" 
    xsi:noNamespaceSchemaLocation="ehcache.xsd" updateCheck="true" 
    monitoring="autodetect" dynamicConfig="true"> 

    <defaultCache eternal="false" 
     timeToIdleSeconds="1200" timeToLiveSeconds="1200"> 
    </defaultCache> 

    <cache name="com.mycompany.myapp.domain.TEd5BatTrig" 
      eternal="false" 
      diskSpoolBufferSizeMB="20" 
      timeToIdleSeconds="300" 
      timeToLiveSeconds="600" 
      transactionalMode="off"> 
    </cache> 

    <cache name="com.mycompany.myapp.domain.TEd5Job" 
      eternal="false" 
      diskSpoolBufferSizeMB="20" 
      timeToIdleSeconds="300" 
      timeToLiveSeconds="600" 
      transactionalMode="off"> 
    </cache> 


</ehcache> 

L2キャッシュの使用の使用のための春のコンテキストおよびテストをロードするための主な方法で自分のテストクラスです：mainメソッドを実行するには

public class AppMain { 

    private static final Logger log = LoggerFactory.getLogger(AppMain.class); 

    public static void main(String[] args) { 
     EDSBaseDAO edsBaseDAO = null; 
     ApplicationContext context = null; 
     try { 
      log.debug("I'm IN !"); 
      context = new ClassPathXmlApplicationContext("spring-config.xml"); 
      edsBaseDAO = (EDSBaseDAO) context.getBean("edsBaseDAO"); 
      Session session = edsBaseDAO.getSessionFactory().openSession(); 
      session.beginTransaction(); 
      TEd5BatTrig row1 = (TEd5BatTrig) session.load(TEd5BatTrig.class, "TIME"); 
      //System.out.println("row1 --> " + row1.toString()); 
      System.out.println("row1 --> " + row1.getBatTrigDescTx()); 
      try{ 
       System.out.println("row1 --> " + row1.getTEd5Jobs()); 
      }catch(Throwable e) { 
       e.printStackTrace(); 
      } 

      TEd5BatTrig row2 = (TEd5BatTrig) session.load(TEd5BatTrig.class, "TIME"); 
      //System.out.println("row1 --> " + row1.toString()); 
      System.out.println("row2 --> " + row2.getBatTrigDescTx()); 
      try{ 
       System.out.println("row2 --> " + row2.getTEd5Jobs()); 
      }catch(Throwable e) { 
       e.printStackTrace(); 
      } 

      session.getTransaction().commit(); 
      session.close(); 

      /* #################################### */ 

      Session session2 = edsBaseDAO.getSessionFactory().openSession(); 
      session2.beginTransaction(); 
      TEd5BatTrig row3 = (TEd5BatTrig) session2.load(TEd5BatTrig.class, "TIME"); 
      //System.out.println("row1 --> " + row1.toString()); 
      System.out.println("row3 --> " + row3.getBatTrigDescTx()); 
      try{ 
       System.out.println("row3 --> " + row3.getTEd5Jobs()); 
      }catch(Throwable e) { 
       e.printStackTrace(); 
      } 

      TEd5BatTrig row4 = (TEd5BatTrig) session2.load(TEd5BatTrig.class, "TIME"); 
      //System.out.println("row1 --> " + row1.toString()); 
      System.out.println("row4 --> " + row4.getBatTrigDescTx()); 
      try{ 
       System.out.println("row4 --> " + row4.getTEd5Jobs()); 
      }catch(Throwable e) { 
       e.printStackTrace(); 
      } 

      session2.getTransaction().commit(); 
      session2.close(); 

      /* #################################### */ 

      Session session3 = edsBaseDAO.getSessionFactory().openSession(); 
      session3.beginTransaction(); 
      TEd5BatTrig row5 = (TEd5BatTrig) session3.load(TEd5BatTrig.class, "TIME"); 
      //System.out.println("row1 --> " + row1.toString()); 
      System.out.println("row5 --> " + row5.getBatTrigDescTx()); 
      try{ 
       System.out.println("row5 --> " + row5.getTEd5Jobs()); 
      }catch(Throwable e) { 
       e.printStackTrace(); 
      } 

      TEd5BatTrig row6 = (TEd5BatTrig) session3.load(TEd5BatTrig.class, "TIME"); 
      //System.out.println("row1 --> " + row1.toString()); 
      System.out.println("row6 --> " + row6.getBatTrigDescTx()); 
      try{ 
       System.out.println("row6 --> " + row6.getTEd5Jobs()); 
      }catch(Throwable e) { 
       e.printStackTrace(); 
      } 

      session3.getTransaction().commit(); 
      session3.close(); 
     } finally { 
      /*System.out.println(edsBaseDAO.getSessionFactory().getStatistics().getEntityFetchCount()); 
      System.out.println(edsBaseDAO.getSessionFactory().getStatistics().getSecondLevelCacheHitCount());*/ 

      Statistics stat = edsBaseDAO.getSessionFactory().getStatistics(); 
      String regions[] = stat.getSecondLevelCacheRegionNames(); 
      System.out.println(regions.toString()); 
      System.out.println("edsBaseDAO.getSessionFactory().getStatistics().getEntityFetchCount() --> " + 
            edsBaseDAO.getSessionFactory().getStatistics().getEntityFetchCount()); 
      System.out.println("edsBaseDAO.getSessionFactory().getStatistics().getSecondLevelCacheHitCount() -->" + 
            edsBaseDAO.getSessionFactory().getStatistics().getSecondLevelCacheHitCount()); 
      for(String regionName:regions) { 
       SecondLevelCacheStatistics stat2 = stat.getSecondLevelCacheStatistics(regionName); 
       System.out.println("2nd Level Cache(" +regionName+") Put Count: "+stat2.getPutCount()); 
       System.out.println("2nd Level Cache(" +regionName+") HIt Count: "+stat2.getHitCount()); 
       System.out.println("2nd Level Cache(" +regionName+") Miss Count: "+stat2.getMissCount()); 
      } 


      // shut down the Spring context. 
      ((ConfigurableApplicationContext) context).close(); 
     } 
    } 
} 

、私は唯一の言及（コンソール出力のログを下回っ取得ログファイルの最後の数行SOメッセージ本文に制限があるとして）

2016-11-25 15:20:36 DEBUG spi.AbstractTransactionImpl:160 - begin 
2016-11-25 15:20:36 DEBUG internal.LogicalConnectionImpl:226 - Obtaining JDBC connection 
2016-11-25 15:20:36 DEBUG internal.LogicalConnectionImpl:232 - Obtained JDBC connection 
2016-11-25 15:20:36 DEBUG jdbc.JdbcTransaction:69 - initial autocommit status: true 
2016-11-25 15:20:36 DEBUG jdbc.JdbcTransaction:71 - disabling autocommit 
2016-11-25 15:20:36 DEBUG internal.SessionImpl:972 - Initializing proxy: [com.mycompany.myapp.domain.TEd5BatTrig#TIME] 
row5 --> Time Trigger Time 
2016-11-25 15:20:36 DEBUG plan.AbstractLoadPlanBasedCollectionInitializer:88 - Loading collection: [com.mycompany.myapp.domain.TEd5BatTrig.TEd5Jobs#TIME] 
2016-11-25 15:20:36 DEBUG hibernate.SQL:109 - select ted5jobs0_.BAT_TRIG_CD as BAT_TRIG_CD2_0_0_, ted5jobs0_.JOB_ID as JOB_ID1_1_0_, ted5jobs0_.JOB_ID as JOB_ID1_1_1_, ted5jobs0_.BAT_TRIG_CD as BAT_TRIG_CD2_1_1_, ted5jobs0_.CALLED_PGM_NM as CALLED_PGM_NM3_1_1_, ted5jobs0_.LUP_USER_ID as LUP_USER_ID4_1_1_, ted5jobs0_.LUP_TS as LUP_TS5_1_1_ from T_ED5_JOB ted5jobs0_ where ted5jobs0_.BAT_TRIG_CD=? 
2016-11-25 15:20:36 DEBUG internal.ResultSetProcessorImpl:168 - Preparing collection intializer : [com.mycompany.myapp.domain.TEd5BatTrig.TEd5Jobs#TIME] 
2016-11-25 15:20:36 DEBUG internal.ResultSetProcessorImpl:127 - Starting ResultSet row #0 
2016-11-25 15:20:36 DEBUG internal.CollectionReferenceInitializerImpl:77 - Found row of collection: [com.mycompany.myapp.domain.TEd5BatTrig.TEd5Jobs#TIME] 
2016-11-25 15:20:36 DEBUG internal.ResultSetProcessorImpl:127 - Starting ResultSet row #1 
2016-11-25 15:20:36 DEBUG internal.CollectionReferenceInitializerImpl:77 - Found row of collection: [com.mycompany.myapp.domain.TEd5BatTrig.TEd5Jobs#TIME] 
2016-11-25 15:20:36 DEBUG internal.ResultSetProcessorImpl:127 - Starting ResultSet row #2 
2016-11-25 15:20:36 DEBUG internal.CollectionReferenceInitializerImpl:77 - Found row of collection: [com.mycompany.myapp.domain.TEd5BatTrig.TEd5Jobs#TIME] 
2016-11-25 15:20:36 DEBUG internal.TwoPhaseLoad:160 - Resolving associations for [com.mycompany.myapp.domain.TEd5Job#2002] 
2016-11-25 15:20:36 DEBUG internal.TwoPhaseLoad:194 - Adding entity to second-level cache: [com.mycompany.myapp.domain.TEd5Job#2002] 
2016-11-25 15:20:36 DEBUG internal.TwoPhaseLoad:286 - Done materializing entity [com.mycompany.myapp.domain.TEd5Job#2002] 
2016-11-25 15:20:36 DEBUG internal.TwoPhaseLoad:160 - Resolving associations for [com.mycompany.myapp.domain.TEd5Job#5689] 
2016-11-25 15:20:36 DEBUG internal.TwoPhaseLoad:194 - Adding entity to second-level cache: [com.mycompany.myapp.domain.TEd5Job#5689] 
2016-11-25 15:20:36 DEBUG internal.TwoPhaseLoad:286 - Done materializing entity [com.mycompany.myapp.domain.TEd5Job#5689] 
2016-11-25 15:20:36 DEBUG internal.TwoPhaseLoad:160 - Resolving associations for [com.mycompany.myapp.domain.TEd5Job#505] 
2016-11-25 15:20:36 DEBUG internal.TwoPhaseLoad:194 - Adding entity to second-level cache: [com.mycompany.myapp.domain.TEd5Job#505] 
2016-11-25 15:20:36 DEBUG internal.TwoPhaseLoad:286 - Done materializing entity [com.mycompany.myapp.domain.TEd5Job#505] 
2016-11-25 15:20:36 DEBUG internal.CollectionLoadContext:232 - 1 collections were found in result set for role: com.mycompany.myapp.domain.TEd5BatTrig.TEd5Jobs 
2016-11-25 15:20:36 DEBUG internal.CollectionLoadContext:280 - Collection fully initialized: [com.mycompany.myapp.domain.TEd5BatTrig.TEd5Jobs#TIME] 
2016-11-25 15:20:36 DEBUG internal.CollectionLoadContext:240 - 1 collections initialized for role: com.mycompany.myapp.domain.TEd5BatTrig.TEd5Jobs 
2016-11-25 15:20:36 DEBUG plan.AbstractLoadPlanBasedCollectionInitializer:118 - Done loading collection 
row5 --> [com.mycompany.myapp.domain.TEd5Job@3b809711, com.mycompany.myapp.domain.TEd5Job@3b0f7d9d, com.mycompany.myapp.domain.TEd5Job@236ab296] 
row6 --> Time Trigger Time 
row6 --> [com.mycompany.myapp.domain.TEd5Job@3b809711, com.mycompany.myapp.domain.TEd5Job@3b0f7d9d, com.mycompany.myapp.domain.TEd5Job@236ab296] 
2016-11-25 15:20:36 DEBUG spi.AbstractTransactionImpl:175 - committing 
2016-11-25 15:20:36 DEBUG internal.AbstractFlushingEventListener:149 - Processing flush-time cascades 
2016-11-25 15:20:36 DEBUG internal.AbstractFlushingEventListener:189 - Dirty checking collections 
2016-11-25 15:20:36 DEBUG internal.Collections:194 - Collection found: [com.mycompany.myapp.domain.TEd5BatTrig.TEd5Jobs#TIME], was: [com.mycompany.myapp.domain.TEd5BatTrig.TEd5Jobs#TIME] (initialized) 
2016-11-25 15:20:36 DEBUG internal.AbstractFlushingEventListener:123 - Flushed: 0 insertions, 0 updates, 0 deletions to 4 objects 
2016-11-25 15:20:36 DEBUG internal.AbstractFlushingEventListener:130 - Flushed: 0 (re)creations, 0 updates, 0 removals to 1 collections 
2016-11-25 15:20:36 DEBUG util.EntityPrinter:114 - Listing entities: 
2016-11-25 15:20:36 DEBUG util.EntityPrinter:121 - com.mycompany.myapp.domain.TEd5BatTrig{batTrigDescTx=Time Trigger Time, batTrigCd=TIME, TEd5Jobs=[com.mycompany.myapp.domain.TEd5Job#2002, com.mycompany.myapp.domain.TEd5Job#5689, com.mycompany.myapp.domain.TEd5Job#505], lupTs=2014-01-15 20:58:27.0, lupUserId=XXX_SIT} 
2016-11-25 15:20:36 DEBUG util.EntityPrinter:121 - com.mycompany.myapp.domain.TEd5Job{jobId=5689, TEd5BatTrig=com.mycompany.myapp.domain.TEd5BatTrig#TIME, calledPgmNm=59+95, lupTs=2015-08-18 07:36:40.657919, lupUserId=XXX_USER} 
2016-11-25 15:20:36 DEBUG util.EntityPrinter:121 - com.mycompany.myapp.domain.TEd5Job{jobId=505, TEd5BatTrig=com.mycompany.myapp.domain.TEd5BatTrig#TIME, calledPgmNm=null, lupTs=2015-08-25 06:25:31.983473, lupUserId=XXX_USER} 
2016-11-25 15:20:36 DEBUG util.EntityPrinter:121 - com.mycompany.myapp.domain.TEd5Job{jobId=2002, TEd5BatTrig=com.mycompany.myapp.domain.TEd5BatTrig#TIME, calledPgmNm=sdfsd, lupTs=2015-08-05 06:48:21.14686, lupUserId=XXX_USER} 
2016-11-25 15:20:36 DEBUG jdbc.JdbcTransaction:113 - committed JDBC Connection 
2016-11-25 15:20:36 DEBUG jdbc.JdbcTransaction:126 - re-enabling autocommit 
2016-11-25 15:20:36 INFO internal.StatisticalLoggingSessionEventListener:275 - Session Metrics { 
    15179 nanoseconds spent acquiring 1 JDBC connections; 
    0 nanoseconds spent releasing 0 JDBC connections; 
    69333 nanoseconds spent preparing 1 JDBC statements; 
    15325767 nanoseconds spent executing 1 JDBC statements; 
    0 nanoseconds spent executing 0 JDBC batches; 
    72204 nanoseconds spent performing 3 L2C puts; 
    39384 nanoseconds spent performing 1 L2C hits; 
    0 nanoseconds spent performing 0 L2C misses; 
    2885299 nanoseconds spent executing 1 flushes (flushing a total of 4 entities and 1 collections); 
    0 nanoseconds spent executing 0 partial-flushes (flushing a total of 0 entities and 0 collections) 
} 
2016-11-25 15:20:36 DEBUG internal.LogicalConnectionImpl:246 - Releasing JDBC connection 
2016-11-25 15:20:36 DEBUG internal.LogicalConnectionImpl:264 - Released JDBC connection 
[Ljava.lang.String;@2a415aa9 
edsBaseDAO.getSessionFactory().getStatistics().getEntityFetchCount() --> 1 
edsBaseDAO.getSessionFactory().getStatistics().getSecondLevelCacheHitCount() -->2 
2nd Level Cache(com.mycompany.myapp.domain.TEd5Job) Put Count: 3 
2nd Level Cache(com.mycompany.myapp.domain.TEd5Job) HIt Count: 0 
2nd Level Cache(com.mycompany.myapp.domain.TEd5Job) Miss Count: 0 
2nd Level Cache(com.mycompany.myapp.domain.TEd5BatTrig) Put Count: 1 
2nd Level Cache(com.mycompany.myapp.domain.TEd5BatTrig) HIt Count: 2 
2nd Level Cache(com.mycompany.myapp.domain.TEd5BatTrig) Miss Count: 1 
2016-11-25 15:20:36 INFO support.ClassPathXmlApplicationContext:862 - Closing org.springframework.context.support.ClassPathXmlApplicationContext@379619aa: startup date [Fri Nov 25 15:20:34 EST 2016]; root of context hierarchy 
2016-11-25 15:20:36 DEBUG support.DefaultListableBeanFactory:247 - Returning cached instance of singleton bean 'lifecycleProcessor' 
2016-11-25 15:20:36 DEBUG support.DefaultListableBeanFactory:499 - Destroying singletons in org.springframework.beans.factory.support.DefaultListableBeanFactory@7a187f14: defining beans [org.springframework.context.annotation.internalConfigurationAnnotationProcessor,org.springframework.context.annotation.internalAutowiredAnnotationProcessor,org.springframework.context.annotation.internalRequiredAnnotationProcessor,org.springframework.context.annotation.internalCommonAnnotationProcessor,org.springframework.context.annotation.internalPersistenceAnnotationProcessor,edsBaseDAO,edsColumnFamilyDAO,org.springframework.aop.config.internalAutoProxyCreator,org.springframework.transaction.annotation.AnnotationTransactionAttributeSource#0,org.springframework.transaction.interceptor.TransactionInterceptor#0,org.springframework.transaction.config.internalTransactionAdvisor,dataSource,sessionFactory,transactionManager,org.springframework.context.annotation.ConfigurationClassPostProcessor.importAwareProcessor,org.springframework.context.annotation.ConfigurationClassPostProcessor.enhancedConfigurationProcessor]; root of factory hierarchy 
2016-11-25 15:20:36 DEBUG support.DisposableBeanAdapter:245 - Invoking destroy() on bean with name 'sessionFactory' 
2016-11-25 15:20:36 DEBUG internal.SessionFactoryImpl:1339 - HHH000031: Closing 
2016-11-25 15:20:36 DEBUG support.DisposableBeanAdapter:323 - Invoking destroy method 'close' on bean with name 'dataSource' 

マイクエリ： 1）私のセカンドレベルキャッシュが実際に使用されている場合はどのように確認するのですか？統計ではsecondlevelcachehitのカウントが増加していますが、同時にHibernateがSQLを吐き出してjdbc接続を作成しているログも見ています。 2）使用していないときにL2キャッシュを使用してメモリ性能を示すために使用できるツール（できればオープンソース）はありますか？

ありがとうございます！

Answer 1

ハイバーネイトレベル2キャッシングは2通りの方法で動作します。あなたがidでロードすると、それはキャッシュから来ます。したがって、SQLクエリは発生しません。ただし、クエリを実行すると、クエリキャッシングを構成しないかぎりクエリは実行されます。次に、結果セットは、水和されると、第2レベルのキャッシュからそれ自身を供給することができる。ベンチマーク、GCログとCensumは、メモリフットプリントが送信