VPF::Hibernate Query Cache - показательный пример

powerOn

Дата 9.10.2011, 19:36 (ссылка)

(нет голосов)

Загрузка ...

software saboteur

Профиль
Группа: Участник
Сообщений: 4367
Регистрация: 7.10.2005

Репутация: 28
Всего: 159

Всем привет.

Пытаюсь добиться показательной работы query cache у Hibernate, но пока без результатов. Может быть у меня само понимание о работе кэша запросов не верное?
Вот что делаю:
1) Есть простая сущность SimpleEntity.

Код


@Entity
@Immutable
@Cacheable(true)
@Cache(usage = CacheConcurrencyStrategy.READ_WRITE)
public class SimpleEntity implements Serializable
{
    @Id
    @GeneratedValue
    protected long id;


    public long getId()
    {
        return id;
    }


    public SimpleEntity()
    {
        Logger.getLogger(this.getClass()).info("create new simple entity");
    }
}

2) Есть Dao:

Код


public class SimpleEntityDaoImpl extends HibernateDaoSupport implements SimpleEntityDao
{
    @Override
    public SimpleEntity create(SimpleEntity entity)
    {
        getSession().persist(entity);
        return entity;
    }


    @Override
    public Statistics getStatistics()
    {
        return getSession().getSessionFactory().getStatistics();
    }


    @Override
    public List<SimpleEntity> findAll()
    {
        final Query query = getSession().createQuery("from SimpleEntity");
        query.setCacheMode(CacheMode.NORMAL);
        query.setCacheable(true);
        return query.list();
    }


    @Override
    public SimpleEntity findById(long id)
    {
        final Query query = getSession().createQuery("from SimpleEntity as se where se.id = ?");
        query.setParameter(0, id);
        query.setCacheMode(CacheMode.NORMAL);
        query.setCacheable(true);
        return (SimpleEntity) query.uniqueResult();
    }
}

3) Есть настройки Hibernate:

Код


<?xml version="1.0" encoding="UTF-8"?>
<beans xmlns="http://www.springframework.org/schema/beans"
       xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
       xmlns:tx="http://www.springframework.org/schema/tx"
       xsi:schemaLocation="http://www.springframework.org/schema/beans
       http://www.springframework.org/schema/beans/spring-beans-3.0.xsd
       http://www.springframework.org/schema/tx http://www.springframework.org/schema/tx/spring-tx-3.0.xsd">

    <tx:annotation-driven transaction-manager="transactionManager"/>

    <bean id="dataSource" class="org.springframework.jdbc.datasource.DriverManagerDataSource">
        <property name="driverClassName">
            <value>org.apache.derby.jdbc.EmbeddedDriver</value> 
        </property>
        <property name="url">
            <value>jdbc:derby:memory:dbtest;create=true</value> 
        </property>
        <property name="username">
            <value>root</value>
        </property>
        <property name="password">
            <value>root</value>
        </property>
    </bean>

    <bean id="transactionManager" class="org.springframework.orm.hibernate3.HibernateTransactionManager">
        <property name="sessionFactory" ref="sessionFactory"/>
    </bean>

    <bean id="hibernateDaoSupport" abstract="true"
          class="org.springframework.orm.hibernate3.support.HibernateDaoSupport">
        <property name="sessionFactory" ref="sessionFactory"/>
    </bean>

    <bean id="sessionFactory" class="org.springframework.orm.hibernate3.annotation.AnnotationSessionFactoryBean">
        <property name="dataSource" ref="dataSource" />
        <property name="packagesToScan">
            <list>
                <value>com.mycompany.dbtest.entity</value>
            </list>
        </property>
        <property name="hibernateProperties">
            <props>
                <prop key="hibernate.hbm2ddl.auto">update</prop>
                <prop key="hibernate.connection.useUnicode">true</prop>
                <prop key="hibernate.connection.characterEncoding">utf8</prop>
                <prop key="hibernate.connection.pool_size">20</prop>
                <prop key="hibernate.current_session_context_class">thread</prop>
                <prop key="hibernate.show_sql">true</prop>
                
                <prop key="hibernate.cache.use_query_cache">true</prop>
                <prop key="hibernate.cache.use_second_level_cache">true</prop>
                <prop key="hibernate.cache.provider_class">org.hibernate.cache.EhCacheProvider</prop>
                
                <prop key="hibernate.c3p0.max_size">20</prop>
                <prop key="hibernate.generate_statistics">true</prop>
            </props>
        </property>
    </bean>

    <bean id="simpleEntityDao" class="com.mycompany.dbtest.dao.impl.SimpleEntityDaoImpl" parent="hibernateDaoSupport" />

</beans>

4) Есть тест для проверки работы кэша:

Код


@ContextConfiguration(locations = "classpath*:/META-INF/spring/*.xml")
@TestExecutionListeners(TransactionalTestExecutionListener.class)
@Transactional(propagation = Propagation.REQUIRES_NEW)
public class SimpleEntityDaoTest extends AbstractTestNGSpringContextTests
{
    @Resource(name = "simpleEntityDao")
    private SimpleEntityDao simpleEntityDao;


    @Test
    public void queryCache()
    {
        final SimpleEntity entity = simpleEntityDao.create(new SimpleEntity());

        simpleEntityDao.findById(entity.getId());
        simpleEntityDao.findById(entity.getId());

        System.out.println(simpleEntityDao.getStatistics());
    }
}

Как видно из теста, я дергаю simpleEntityDao.findById(entity.getId()); два раза, ожидая, что максимум один запрос пойдет к базе. Однако, как я не крутил настройки, в логе вижу два select-а:

Цитата

Running TestSuite
20:28:48,521  INFO main RegionFactoryCacheProviderBridge:<init>:61 - Cache provider: org.hibernate.cache.EhCacheProvider
20:28:48,599  WARN main EhCacheProvider:buildCache:93 - Could not find configuration [com.mycompany.dbtest.entity.SimpleEntity]; using defaults.
20:28:48,599 DEBUG main EhCacheProvider:buildCache:96 - started EHCache region: com.mycompany.dbtest.entity.SimpleEntity
20:28:48,631  INFO main SimpleEntity:<init>:36 - create new simple entity
20:28:48,911  INFO main UpdateTimestampsCache:<init>:57 - starting update timestamps cache at region: org.hibernate.cache.UpdateTimestampsCache
20:28:48,911  WARN main EhCacheProvider:buildCache:93 - Could not find configuration [org.hibernate.cache.UpdateTimestampsCache]; using defaults.
20:28:48,911 DEBUG main EhCacheProvider:buildCache:96 - started EHCache region: org.hibernate.cache.UpdateTimestampsCache
20:28:48,911  INFO main StandardQueryCache:<init>:76 - starting query cache at region: org.hibernate.cache.StandardQueryCache
20:28:48,911  WARN main EhCacheProvider:buildCache:93 - Could not find configuration [org.hibernate.cache.StandardQueryCache]; using defaults.
20:28:48,911 DEBUG main EhCacheProvider:buildCache:96 - started EHCache region: org.hibernate.cache.StandardQueryCache
20:28:48,958  INFO main SimpleEntity:<init>:36 - create new simple entity
Hibernate: insert into SimpleEntity (id) values (default)
Hibernate: values identity_val_local()
20:28:48,989 DEBUG main UpdateTimestampsCache:preinvalidate:71 - Pre-invalidating space [SimpleEntity]
20:28:49,099 DEBUG main StandardQueryCache:get:125 - checking cached query results in region: org.hibernate.cache.StandardQueryCache
20:28:49,099 DEBUG main EhCache:get:74 - key: sql: select simpleenti0_.id as id0_ from SimpleEntity simpleenti0_ where simpleenti0_.id=?; parameters: 1, ; named parameters: {}
20:28:49,099 DEBUG main EhCache:get:83 - Element for sql: select simpleenti0_.id as id0_ from SimpleEntity simpleenti0_ where simpleenti0_.id=?; parameters: 1, ; named parameters: {} is null
20:28:49,099 DEBUG main StandardQueryCache:get:130 - query results were not found in cache
Hibernate: select simpleenti0_.id as id0_ from SimpleEntity simpleenti0_ where simpleenti0_.id=?
20:28:49,099 DEBUG main StandardQueryCache:put:96 - caching query results in region: org.hibernate.cache.StandardQueryCache; timestamp=5399255978389504
20:28:49,099 DEBUG main StandardQueryCache:get:125 - checking cached query results in region: org.hibernate.cache.StandardQueryCache
20:28:49,099 DEBUG main EhCache:get:74 - key: sql: select simpleenti0_.id as id0_ from SimpleEntity simpleenti0_ where simpleenti0_.id=?; parameters: 1, ; named parameters: {}
20:28:49,099 DEBUG main StandardQueryCache:isUpToDate:183 - Checking query spaces for up-to-dateness: [SimpleEntity]
20:28:49,099 DEBUG main EhCache:get:74 - key: SimpleEntity
20:28:49,099 DEBUG main UpdateTimestampsCache:isUpToDate:122 - [SimpleEntity] last update timestamp: 5399256223698944, result set timestamp: 5399255978389504
20:28:49,099 DEBUG main StandardQueryCache:get:136 - cached query results were not up to date
Hibernate: select simpleenti0_.id as id0_ from SimpleEntity simpleenti0_ where simpleenti0_.id=?
20:28:49,099 DEBUG main StandardQueryCache:put:96 - caching query results in region: org.hibernate.cache.StandardQueryCache; timestamp=5399255978389505
Statistics[start time=1318177728537,sessions opened=1,sessions closed=0,transactions=0,successful transactions=0,optimistic lock failures=0,flushes=0,connections obtained=1,statements prepared=4,statements closed=4,second level cache puts=0,second level cache hits=0,second level cache misses=0,entities loaded=0,entities updated=0,entities inserted=1,entities deleted=0,entities fetched=0,collections loaded=0,collections updated=0,collections removed=0,collections recreated=0,collections fetched=0,queries executed to database=2,query cache puts=2,query cache hits=0,query cache misses=2,max query time=0]
20:28:49,099 DEBUG main UpdateTimestampsCache:invalidate:95 - Invalidating space [SimpleEntity], timestamp: 5399255978389506
Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 1.56 sec

Интересна так же статистика:

Цитата

Statistics[start time=1318176760211,sessions opened=1,sessions closed=0,transactions=0,successful transactions=0,optimistic lock failures=0,flushes=0,connections obtained=1,statements prepared=4,statements closed=4,second level cache puts=0,second level cache hits=0,second level cache misses=0,entities loaded=0,entities updated=0,entities inserted=1,entities deleted=0,entities fetched=0,collections loaded=0,collections updated=0,collections removed=0,collections recreated=0,collections fetched=0,queries executed to database=2,query cache puts=2,query cache hits=0,query cache misses=2,max query time=0]

Она как бы намекает, что выполнено 2 запроса. Но у меня их по сути 3: insert и два select. Типа кэш отработал? При этом, query cache misses=2 - т.е. ничего не отработало... Что я делаю не так?

P.S.: Прикрепил maven проект. mvn clean install - все должно запуститься без дополнительных настроек.

Присоединённый файл ( Кол-во скачиваний: 3 )

dbtest.zip 6,25 Kb

--------------------

нет времени думать - нужно писать КОД!

powerOn

Дата 9.10.2011, 21:36 (ссылка)

(нет голосов)

Загрузка ...

software saboteur

Профиль
Группа: Участник
Сообщений: 4367
Регистрация: 7.10.2005

Репутация: 28
Всего: 159

продолжая попытки разобраться с кэшем запросов, я начал экспериментировать с транзакциями, что дало несколько неожиданных результатов.
выключаем транзакции:

Код


@ContextConfiguration(locations = "classpath*:/META-INF/spring/*.xml")
//@TestExecutionListeners(TransactionalTestExecutionListener.class)
//@Transactional(propagation = Propagation.REQUIRED)
public class SimpleEntityDaoTest extends AbstractTestNGSpringContextTests
{
    @Resource(name = "simpleEntityDao")
    private SimpleEntityDao simpleEntityDao;


    @Test
    public void queryCache()
    {
        final SimpleEntity entity = simpleEntityDao.create(new SimpleEntity());

        simpleEntityDao.findById(entity.getId());
        simpleEntityDao.findById(entity.getId());

        System.out.println(simpleEntityDao.getStatistics());
    }
}

результат:

Цитата

Running TestSuite
22:18:10,700  INFO main RegionFactoryCacheProviderBridge:<init>:61 - Cache provider: org.hibernate.cache.EhCacheProvider
22:18:10,771  WARN main EhCacheProvider:buildCache:93 - Could not find configuration [com.mycompany.dbtest.entity.SimpleEntity]; using defaults.
22:18:10,784 DEBUG main EhCacheProvider:buildCache:96 - started EHCache region: com.mycompany.dbtest.entity.SimpleEntity
22:18:10,803  INFO main SimpleEntity:<init>:36 - create new simple entity
22:18:11,096  INFO main UpdateTimestampsCache:<init>:57 - starting update timestamps cache at region: org.hibernate.cache.UpdateTimestampsCache
22:18:11,097  WARN main EhCacheProvider:buildCache:93 - Could not find configuration [org.hibernate.cache.UpdateTimestampsCache]; using defaults.
22:18:11,098 DEBUG main EhCacheProvider:buildCache:96 - started EHCache region: org.hibernate.cache.UpdateTimestampsCache
22:18:11,098  INFO main StandardQueryCache:<init>:76 - starting query cache at region: org.hibernate.cache.StandardQueryCache
22:18:11,099  WARN main EhCacheProvider:buildCache:93 - Could not find configuration [org.hibernate.cache.StandardQueryCache]; using defaults.
22:18:11,099 DEBUG main EhCacheProvider:buildCache:96 - started EHCache region: org.hibernate.cache.StandardQueryCache
22:18:11,124  INFO main SimpleEntity:<init>:36 - create new simple entity
22:18:11,254 DEBUG main StandardQueryCache:get:125 - checking cached query results in region: org.hibernate.cache.StandardQueryCache
22:18:11,255 DEBUG main EhCache:get:74 - key: sql: select simpleenti0_.id as id0_ from SimpleEntity simpleenti0_ where simpleenti0_.id=?; parameters: 0, ; named parameters: {}
22:18:11,255 DEBUG main EhCache:get:83 - Element for sql: select simpleenti0_.id as id0_ from SimpleEntity simpleenti0_ where simpleenti0_.id=?; parameters: 0, ; named parameters: {} is null
22:18:11,255 DEBUG main StandardQueryCache:get:130 - query results were not found in cache
Hibernate: select simpleenti0_.id as id0_ from SimpleEntity simpleenti0_ where simpleenti0_.id=?
22:18:11,261 DEBUG main StandardQueryCache:put:96 - caching query results in region: org.hibernate.cache.StandardQueryCache; timestamp=5399282857005056
22:18:11,264 DEBUG main StandardQueryCache:get:125 - checking cached query results in region: org.hibernate.cache.StandardQueryCache
22:18:11,264 DEBUG main EhCache:get:74 - key: sql: select simpleenti0_.id as id0_ from SimpleEntity simpleenti0_ where simpleenti0_.id=?; parameters: 0, ; named parameters: {}
22:18:11,264 DEBUG main StandardQueryCache:isUpToDate:183 - Checking query spaces for up-to-dateness: [SimpleEntity]
22:18:11,264 DEBUG main EhCache:get:74 - key: SimpleEntity
22:18:11,264 DEBUG main EhCache:get:83 - Element for SimpleEntity is null
22:18:11,264 DEBUG main StandardQueryCache:get:140 - returning cached query results
Statistics[start time=1318184290719,sessions opened=4,sessions closed=0,transactions=0,successful transactions=0,optimistic lock failures=0,flushes=0,connections obtained=1,statements prepared=1,statements closed=1,second level cache puts=0,second level cache hits=0,second level cache misses=0,entities loaded=0,entities updated=0,entities inserted=0,entities deleted=0,entities fetched=0,collections loaded=0,collections updated=0,collections removed=0,collections recreated=0,collections fetched=0,queries executed to database=1,query cache puts=1,query cache hits=1,query cache misses=1,max query time=5]
Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 1.58 sec

profit?

А в рамках транзакции нельзя? smile

Дальнейшие манипуляции привели меня в идее сохранить сущность в одной, законченной транзакции. Запросы на выборку делать после её завершения, что снова привело к успеху.

Код


public class SimpleEntityDaoImpl extends HibernateDaoSupport implements SimpleEntityDao
{
    @Override
    @Transactional(propagation = Propagation.REQUIRES_NEW) // выполняем метод в рамках отдельной транзакции
    public SimpleEntity create(SimpleEntity entity)
    {
        getSession().persist(entity);
        return entity;
    }


    @Override
    public Statistics getStatistics()
    {
        return getSession().getSessionFactory().getStatistics();
    }


    @Override
    public List<SimpleEntity> findAll()
    {
        final Query query = getSession().createQuery("from SimpleEntity");
        query.setCacheMode(CacheMode.NORMAL);
        query.setCacheable(true);
        return query.list();
    }


    @Override
    public SimpleEntity findById(long id)
    {
        final Query query = getSession().createQuery("from SimpleEntity as se where se.id = ?");
        query.setParameter(0, id);
        query.setCacheMode(CacheMode.NORMAL);
        query.setCacheable(true);
        return (SimpleEntity) query.uniqueResult();
    }
}

Код


@ContextConfiguration(locations = "classpath*:/META-INF/spring/*.xml")
@TestExecutionListeners(TransactionalTestExecutionListener.class) // вернем транзакционные атрибуты для тестов
@Transactional(propagation = Propagation.REQUIRED)
public class SimpleEntityDaoTest extends AbstractTestNGSpringContextTests
{
    @Resource(name = "simpleEntityDao")
    private SimpleEntityDao simpleEntityDao;


    @Test
    public void queryCache()
    {
        final SimpleEntity entity = simpleEntityDao.create(new SimpleEntity());

        simpleEntityDao.findById(entity.getId());
        simpleEntityDao.findById(entity.getId());

        System.out.println(simpleEntityDao.getStatistics());
    }
}

Цитата

Running TestSuite
22:29:44,808  INFO main RegionFactoryCacheProviderBridge:<init>:61 - Cache provider: org.hibernate.cache.EhCacheProvider
22:29:44,886  WARN main EhCacheProvider:buildCache:93 - Could not find configuration [com.mycompany.dbtest.entity.SimpleEntity]; using defaults.
22:29:44,900 DEBUG main EhCacheProvider:buildCache:96 - started EHCache region: com.mycompany.dbtest.entity.SimpleEntity
22:29:44,920  INFO main SimpleEntity:<init>:36 - create new simple entity
22:29:45,230  INFO main UpdateTimestampsCache:<init>:57 - starting update timestamps cache at region: org.hibernate.cache.UpdateTimestampsCache
22:29:45,230  WARN main EhCacheProvider:buildCache:93 - Could not find configuration [org.hibernate.cache.UpdateTimestampsCache]; using defaults.
22:29:45,231 DEBUG main EhCacheProvider:buildCache:96 - started EHCache region: org.hibernate.cache.UpdateTimestampsCache
22:29:45,232  INFO main StandardQueryCache:<init>:76 - starting query cache at region: org.hibernate.cache.StandardQueryCache
22:29:45,232  WARN main EhCacheProvider:buildCache:93 - Could not find configuration [org.hibernate.cache.StandardQueryCache]; using defaults.
22:29:45,232 DEBUG main EhCacheProvider:buildCache:96 - started EHCache region: org.hibernate.cache.StandardQueryCache
22:29:45,292  INFO main SimpleEntity:<init>:36 - create new simple entity
Hibernate: insert into SimpleEntity (id) values (default)
Hibernate: values identity_val_local()
22:29:45,322 DEBUG main UpdateTimestampsCache:preinvalidate:71 - Pre-invalidating space [SimpleEntity]
22:29:45,327 DEBUG main UpdateTimestampsCache:invalidate:95 - Invalidating space [SimpleEntity], timestamp: 5399285699899392
22:29:45,439 DEBUG main StandardQueryCache:get:125 - checking cached query results in region: org.hibernate.cache.StandardQueryCache
22:29:45,439 DEBUG main EhCache:get:74 - key: sql: select simpleenti0_.id as id0_ from SimpleEntity simpleenti0_ where simpleenti0_.id=?; parameters: 1, ; named parameters: {}
22:29:45,439 DEBUG main EhCache:get:83 - Element for sql: select simpleenti0_.id as id0_ from SimpleEntity simpleenti0_ where simpleenti0_.id=?; parameters: 1, ; named parameters: {} is null
22:29:45,440 DEBUG main StandardQueryCache:get:130 - query results were not found in cache
Hibernate: select simpleenti0_.id as id0_ from SimpleEntity simpleenti0_ where simpleenti0_.id=?
22:29:45,445  INFO main SimpleEntity:<init>:36 - create new simple entity
22:29:45,447 DEBUG main EhCache:get:74 - key: com.mycompany.dbtest.entity.SimpleEntity#1
22:29:45,447 DEBUG main EhCache:get:83 - Element for com.mycompany.dbtest.entity.SimpleEntity#1 is null
22:29:45,449 DEBUG main StandardQueryCache:put:96 - caching query results in region: org.hibernate.cache.StandardQueryCache; timestamp=5399285700399104
22:29:45,449 DEBUG main StandardQueryCache:get:125 - checking cached query results in region: org.hibernate.cache.StandardQueryCache
22:29:45,449 DEBUG main EhCache:get:74 - key: sql: select simpleenti0_.id as id0_ from SimpleEntity simpleenti0_ where simpleenti0_.id=?; parameters: 1, ; named parameters: {}
22:29:45,449 DEBUG main StandardQueryCache:isUpToDate:183 - Checking query spaces for up-to-dateness: [SimpleEntity]
22:29:45,449 DEBUG main EhCache:get:74 - key: SimpleEntity
22:29:45,450 DEBUG main UpdateTimestampsCache:isUpToDate:122 - [SimpleEntity] last update timestamp: 5399285699899392, result set timestamp: 5399285700399104
22:29:45,450 DEBUG main StandardQueryCache:get:140 - returning cached query results
Statistics[start time=1318184984824,sessions opened=2,sessions closed=1,transactions=2,successful transactions=1,optimistic lock failures=0,flushes=1,connections obtained=2,statements prepared=3,statements closed=3,second level cache puts=1,second level cache hits=0,second level cache misses=0,entities loaded=1,entities updated=0,entities inserted=1,entities deleted=0,entities fetched=0,collections loaded=0,collections updated=0,collections removed=0,collections recreated=0,collections fetched=0,queries executed to database=1,query cache puts=1,query cache hits=1,query cache misses=1,max query time=7]
Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 1.7 sec

Выводы: Пока транзакция не завершена, кэширование её изменений в рамках query cache не имеет смысла, что скорее всего правильно.

--------------------

нет времени думать - нужно писать КОД!

0 Пользователей читают эту тему (0 Гостей и 0 Скрытых Пользователей)
0 Пользователей:
« Предыдущая тема \| Java EE (J2EE) и Spring \| Следующая тема »