Code and logfile output follows, but I'll describe my problem first.
I am developing an application and want to mix bulk-updates
with normal hibernate operations.
The bulk updates work fine, but invalidate the whole region and I've found
no possibility to prevent this.
There would be 2 options to improve:
- Invalidate only the modified objects if the ids where given as Query-parameters.
- Let me deactivate the invalidation so I can invalidate the affected objects myself.
The reference documentation does not mention caching at all:
http://www.hibernate.org/hib_docs/v3/re ... tch-direct
The best documentation I've found is:
http://blog.hibernate.org/cgi-bin/blosx ... #dml-basic
Maybe this could be added to the reference documentation...
Many thanks in advance!
Hibernate version: 3.2.0
Mapping documents:
Code:
<?xml version="1.0"?>
<!DOCTYPE hibernate-mapping PUBLIC
"-//Hibernate/Hibernate Mapping DTD 3.0//EN"
"http://hibernate.sourceforge.net/hibernate-mapping-3.0.dtd" >
<hibernate-mapping package="org.hibernate.test">
<class name="Settings" table="SETTINGS" lazy="true">
<cache usage="read-only"/>
<id
name="Id"
type="long"
column="USER_ID"
>
<generator class="assigned"/>
</id>
<property
name="SizeLimit"
column="SIZE_LIMIT"
type="long"
not-null="false"
length="10"
/>
</class>
</hibernate-mapping>
Code between sessionFactory.openSession() and session.close():Code:
public class HibernateBulkTest extends TestCase {
public void testCacheInteraction() {
final long settingsId = 1;
final SessionFactory sessionFactory = new Configuration().configure("org/hibernate/test/hibernate.cfg.xml").buildSessionFactory();
try {
Session session = sessionFactory.openSession();;
SecondLevelCacheStatistics settingsStatistics = sessionFactory.getStatistics().getSecondLevelCacheStatistics(Settings.class.getC
anonicalName());
assertEquals(0, settingsStatistics.getMissCount());
assertEquals(0, settingsStatistics.getHitCount());
// fill cache
Transaction tx = session.beginTransaction();
session.get(Settings.class, settingsId);
assertEquals(1, settingsStatistics.getMissCount());
assertEquals(0, settingsStatistics.getHitCount());
tx.rollback();
session.close();
// do executeUpdate
session = sessionFactory.openSession();
tx = session.beginTransaction();
Query query = session.createQuery("update Settings m set m.SizeLimit = ? where m.id = ?");
query.setLong(0, 100000L);
query.setLong(1, -1L);
query.executeUpdate();
tx.rollback();
session.close();
// data is not in cache anymore
session = sessionFactory.openSession();
tx = session.beginTransaction();
session.get(Settings.class, settingsId);
// these asserts fail!
assertEquals(1, settingsStatistics.getMissCount());
assertEquals(1, settingsStatistics.getHitCount());
tx.rollback();
session.close();
} finally {
sessionFactory.close();
}
}
}
Name and version of the database you are using:Oracle: 9.2.0
18:06:19,990 INFO Environment:500 - Hibernate 3.2.0
18:06:20,003 INFO Environment:533 - hibernate.properties not found
18:06:20,006 INFO Environment:667 - Bytecode provider name : cglib
18:06:20,013 INFO Environment:584 - using JDK 1.4 java.sql.Timestamp handling
18:06:20,119 INFO Configuration:1350 - configuring from resource: org/hibernate/test/hibernate.cfg.xml
18:06:20,121 INFO Configuration:1327 - Configuration resource: org/hibernate/test/hibernate.cfg.xml
18:06:20,247 DEBUG DTDEntityResolver:38 - trying to resolve system-id [http://hibernate.sourceforge.net/hibernate-configuration-3.0.dtd]
18:06:20,248 DEBUG DTDEntityResolver:40 - recognized hibernate namespace; attempting to resolve on classpath under org/hibernate/
18:06:20,251 DEBUG DTDEntityResolver:50 - located [http://hibernate.sourceforge.net/hibernate-configuration-3.0.dtd] in classpath
18:06:20,316 DEBUG Configuration:1311 - connection.driver_class=oracle.jdbc.driver.OracleDriver
18:06:20,316 DEBUG Configuration:1311 - connection.url=jdbc:oracle:thin:@xxxxxxxxxxxxxxxxxxxxxxxx:xxxx:xxxx
18:06:20,318 DEBUG Configuration:1311 - connection.username=xxxx
18:06:20,320 DEBUG Configuration:1311 - connection.password=xxxx
18:06:20,321 DEBUG Configuration:1311 - connection.pool_size=1
18:06:20,322 DEBUG Configuration:1311 - dialect=org.hibernate.dialect.Oracle9Dialect
18:06:20,325 DEBUG Configuration:1311 - current_session_context_class=thread
18:06:20,328 DEBUG Configuration:1311 - cache.provider_class=org.hibernate.cache.NoCacheProvider
18:06:20,329 DEBUG Configuration:1311 - show_sql=true
18:06:20,329 DEBUG Configuration:1311 - hibernate.cache.provider_class=org.hibernate.cache.EhCacheProvider
18:06:20,330 DEBUG Configuration:1311 - hibernate.cache.use_query_cache=true
18:06:20,331 DEBUG Configuration:1311 - hibernate.generate_statistics=true
18:06:20,334 DEBUG Configuration:1510 - null<-org.dom4j.tree.DefaultAttribute@1995d80 [Attribute: name resource value "org/hibernate/test/Settings.hbm.xml"]
18:06:20,336 INFO Configuration:507 - Reading mappings from resource: org/hibernate/test/Settings.hbm.xml
18:06:20,340 DEBUG DTDEntityResolver:38 - trying to resolve system-id [http://hibernate.sourceforge.net/hibernate-mapping-3.0.dtd]
18:06:20,343 DEBUG DTDEntityResolver:40 - recognized hibernate namespace; attempting to resolve on classpath under org/hibernate/
18:06:20,348 DEBUG DTDEntityResolver:50 - located [http://hibernate.sourceforge.net/hibernate-mapping-3.0.dtd] in classpath
18:06:20,686 INFO HbmBinder:300 - Mapping class: org.hibernate.test.Settings -> SETTINGS
18:06:20,701 DEBUG HbmBinder:1270 - Mapped property: Id -> USER_ID
18:06:20,718 DEBUG HbmBinder:1270 - Mapped property: SizeLimit -> SIZE_LIMIT
18:06:20,720 INFO Configuration:1465 - Configured SessionFactory: null
, java.vm.name=Java HotSpot(TM) Client VM, cache.provider_class=org.hibernate.cache.NoCacheProvider, file.encoding=ISO-8859-1, java.specification.version=1.5, hibernate.show_sql=true, hibernate.connection.pool_size=1}
18:06:20,725 DEBUG Configuration:1209 - Preparing to build session factory with filters : {}
18:06:20,725 DEBUG Configuration:1044 - processing extends queue
18:06:20,728 DEBUG Configuration:1048 - processing collection mappings
18:06:20,729 DEBUG Configuration:1059 - processing native query and ResultSetMapping mappings
18:06:20,731 DEBUG Configuration:1067 - processing association property references
18:06:20,733 DEBUG Configuration:1089 - processing foreign key constraints
18:06:20,921 INFO DriverManagerConnectionProvider:41 - Using Hibernate built-in connection pool (not for production use!)
18:06:20,922 INFO DriverManagerConnectionProvider:42 - Hibernate connection pool size: 1
18:06:20,925 INFO DriverManagerConnectionProvider:45 - autocommit mode: false
18:06:21,040 INFO DriverManagerConnectionProvider:80 - using driver: oracle.jdbc.driver.OracleDriver at URL: jdbc:oracle:thin:@xxxxxxxxxxxxxxxxxxxxxxxx:xxxx:xxxx
18:06:21,043 INFO DriverManagerConnectionProvider:83 - connection properties: {user=xxxx, password=xxxx}
18:06:21,046 DEBUG DriverManagerConnectionProvider:109 - opening new JDBC connection
18:06:21,528 DEBUG DriverManagerConnectionProvider:115 - created connection to: jdbc:oracle:thin:@xxxxxxxxxxxxxxxxxxxxxxxx:xxxx:xxxx, Isolation Level: 2
18:06:21,540 INFO SettingsFactory:81 - RDBMS: Oracle, version: Oracle9i Enterprise Edition Release 9.2.0.1.0 - Production
With the Partitioning, OLAP and Oracle Data Mining options
JServer Release 9.2.0.1.0 - Production
18:06:21,548 INFO SettingsFactory:82 - JDBC driver: Oracle JDBC driver, version: 9.2.0.8.0
18:06:21,584 INFO Dialect:141 - Using dialect: org.hibernate.dialect.Oracle9Dialect
18:06:21,603 INFO TransactionFactoryFactory:31 - Using default transaction strategy (direct JDBC transactions)
18:06:21,607 INFO TransactionManagerLookupFactory:33 - No TransactionManagerLookup configured (in JTA environment, use of read-write or transactional second-level cache is not recommended)
18:06:21,609 INFO SettingsFactory:134 - Automatic flush during beforeCompletion(): disabled
18:06:21,611 INFO SettingsFactory:138 - Automatic session close at end of transaction: disabled
18:06:21,612 INFO SettingsFactory:145 - JDBC batch size: 15
18:06:21,613 INFO SettingsFactory:148 - JDBC batch updates for versioned data: disabled
18:06:21,615 INFO SettingsFactory:153 - Scrollable result sets: enabled
18:06:21,616 DEBUG SettingsFactory:157 - Wrap result sets: disabled
18:06:21,619 INFO SettingsFactory:161 - JDBC3 getGeneratedKeys(): disabled
18:06:21,620 INFO SettingsFactory:169 - Connection release mode: auto
18:06:21,622 INFO SettingsFactory:196 - Default batch fetch size: 1
18:06:21,624 INFO SettingsFactory:200 - Generate SQL with comments: disabled
18:06:21,625 INFO SettingsFactory:204 - Order SQL updates by primary key: disabled
18:06:21,626 INFO SettingsFactory:369 - Query translator: org.hibernate.hql.ast.ASTQueryTranslatorFactory
18:06:21,630 INFO ASTQueryTranslatorFactory:24 - Using ASTQueryTranslatorFactory
18:06:21,632 INFO SettingsFactory:212 - Query language substitutions: {}
18:06:21,633 INFO SettingsFactory:217 - JPA-QL strict compliance: disabled
18:06:21,645 INFO SettingsFactory:222 - Second-level cache: enabled
18:06:21,649 INFO SettingsFactory:226 - Query cache: enabled
18:06:21,650 INFO SettingsFactory:356 - Cache provider: org.hibernate.cache.EhCacheProvider
18:06:21,657 INFO SettingsFactory:241 - Optimize cache for minimal puts: disabled
18:06:21,658 INFO SettingsFactory:250 - Structured second-level cache entries: disabled
18:06:21,660 INFO SettingsFactory:343 - Query cache factory: org.hibernate.cache.StandardQueryCacheFactory
18:06:21,672 INFO SettingsFactory:270 - Echoing all SQL to stdout
18:06:21,675 INFO SettingsFactory:277 - Statistics: enabled
18:06:21,676 INFO SettingsFactory:281 - Deleted entity synthetic identifier rollback: disabled
18:06:21,677 INFO SettingsFactory:296 - Default entity-mode: pojo
18:06:21,767 INFO SessionFactoryImpl:161 - building session factory
18:06:21,770 DEBUG SessionFactoryImpl:173 - Session factory constructed with filter configurations : {}
, java.vm.name=Java HotSpot(TM) Client VM, cache.provider_class=org.hibernate.cache.NoCacheProvider, file.encoding=ISO-8859-1, java.specification.version=1.5, hibernate.connection.pool_size=1, hibernate.show_sql=true}
18:06:22,003 DEBUG CacheFactory:39 - instantiating cache region: org.hibernate.test.Settings usage strategy: read-only
18:06:22,005 WARN CacheFactory:43 - read-only cache configured for mutable class: org.hibernate.test.Settings
18:06:22,007 WARN EhCacheProvider:86 - Could not find configuration [org.hibernate.test.Settings]; using defaults.
18:06:22,008 DEBUG EhCacheProvider:89 - started EHCache region: org.hibernate.test.Settings
18:06:22,380 DEBUG AbstractEntityPersister:2673 - Static SQL for entity: org.hibernate.test.Settings
18:06:22,381 DEBUG AbstractEntityPersister:2678 - Version select: select USER_ID from SETTINGS where USER_ID =?
18:06:22,382 DEBUG AbstractEntityPersister:2681 - Snapshot select: select settings_.USER_ID, settings_.SIZE_LIMIT as SIZE2_0_ from SETTINGS settings_ where settings_.USER_ID=?
18:06:22,382 DEBUG AbstractEntityPersister:2684 - Insert 0: insert into SETTINGS (SIZE_LIMIT, USER_ID) values (?, ?)
18:06:22,383 DEBUG AbstractEntityPersister:2685 - Update 0: update SETTINGS set SIZE_LIMIT=? where USER_ID=?
18:06:22,383 DEBUG AbstractEntityPersister:2686 - Delete 0: delete from SETTINGS where USER_ID=?
18:06:22,420 DEBUG EntityLoader:79 - Static select for entity org.hibernate.test.Settings: select settings0_.USER_ID as USER1_0_0_, settings0_.SIZE_LIMIT as SIZE2_0_0_ from SETTINGS settings0_ where settings0_.USER_ID=?
18:06:22,421 DEBUG EntityLoader:79 - Static select for entity org.hibernate.test.Settings: select settings0_.USER_ID as USER1_0_0_, settings0_.SIZE_LIMIT as SIZE2_0_0_ from SETTINGS settings0_ where settings0_.USER_ID=?
18:06:22,425 DEBUG EntityLoader:79 - Static select for entity org.hibernate.test.Settings: select settings0_.USER_ID as USER1_0_0_, settings0_.SIZE_LIMIT as SIZE2_0_0_ from SETTINGS settings0_ where settings0_.USER_ID=? for update
18:06:22,426 DEBUG EntityLoader:79 - Static select for entity org.hibernate.test.Settings: select settings0_.USER_ID as USER1_0_0_, settings0_.SIZE_LIMIT as SIZE2_0_0_ from SETTINGS settings0_ where settings0_.USER_ID=? for update nowait
18:06:22,427 DEBUG EntityLoader:79 - Static select for entity org.hibernate.test.Settings: select settings0_.USER_ID as USER1_0_0_, settings0_.SIZE_LIMIT as SIZE2_0_0_ from SETTINGS settings0_ where settings0_.USER_ID=? for update nowait
18:06:22,440 DEBUG EntityLoader:34 - Static select for action ACTION_MERGE on entity org.hibernate.test.Settings: select settings0_.USER_ID as USER1_0_0_, settings0_.SIZE_LIMIT as SIZE2_0_0_ from SETTINGS settings0_ where settings0_.USER_ID=?
18:06:22,443 DEBUG EntityLoader:34 - Static select for action ACTION_REFRESH on entity org.hibernate.test.Settings: select settings0_.USER_ID as USER1_0_0_, settings0_.SIZE_LIMIT as SIZE2_0_0_ from SETTINGS settings0_ where settings0_.USER_ID=?
18:06:22,448 DEBUG SessionFactoryObjectFactory:39 - initializing class SessionFactoryObjectFactory
18:06:22,452 DEBUG SessionFactoryObjectFactory:76 - registered: 2c91c84f0ea9a2b1010ea9a2b46d0000 (unnamed)
18:06:22,453 INFO SessionFactoryObjectFactory:82 - Not binding factory to JNDI, no JNDI name configured
18:06:22,454 DEBUG SessionFactoryImpl:308 - instantiated session factory
18:06:22,463 INFO UpdateTimestampsCache:41 - starting update timestamps cache at region: org.hibernate.cache.UpdateTimestampsCache
18:06:22,466 INFO StandardQueryCache:52 - starting query cache at region: org.hibernate.cache.StandardQueryCache
18:06:22,469 DEBUG SessionFactoryImpl:390 - Checking 0 named HQL queries
18:06:22,470 DEBUG SessionFactoryImpl:410 - Checking 0 named SQL queries
18:06:22,632 DEBUG SessionImpl:220 - opened session at timestamp: 4761547499438080
18:06:22,638 DEBUG JDBCTransaction:54 - begin
18:06:22,642 DEBUG ConnectionManager:415 - opening JDBC connection
18:06:22,643 DEBUG JDBCTransaction:59 - current autocommit status: false
18:06:22,648 DEBUG EhCache:68 - key: org.hibernate.test.Settings#21429419
18:06:22,649 DEBUG EhCache:77 - Element for org.hibernate.test.Settings#21429419 is null
18:06:22,652 DEBUG Loader:1776 - loading entity: [org.hibernate.test.Settings#21429419]
18:06:22,659 DEBUG AbstractBatcher:358 - about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
18:06:22,660 DEBUG SQL:393 - select settings0_.USER_ID as USER1_0_0_, settings0_.SIZE_LIMIT as SIZE2_0_0_ from SETTINGS settings0_ where settings0_.USER_ID=?
18:06:22,774 DEBUG AbstractBatcher:374 - about to open ResultSet (open ResultSets: 0, globally: 0)
18:06:22,776 DEBUG Loader:1164 - result row: EntityKey[org.hibernate.test.Settings#21429419]
18:06:22,792 DEBUG AbstractBatcher:381 - about to close ResultSet (open ResultSets: 1, globally: 1)
18:06:22,793 DEBUG AbstractBatcher:366 - about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
18:06:22,821 DEBUG TwoPhaseLoad:107 - resolving associations for [org.hibernate.test.Settings#21429419]
18:06:22,827 DEBUG TwoPhaseLoad:135 - adding entity to second-level cache: [org.hibernate.test.Settings#21429419]
18:06:22,832 DEBUG ReadOnlyCache:58 - Caching: org.hibernate.test.Settings#21429419
18:06:22,836 DEBUG TwoPhaseLoad:206 - done materializing entity [org.hibernate.test.Settings#21429419]
18:06:22,839 DEBUG StatefulPersistenceContext:748 - initializing non-lazy collections
18:06:22,840 DEBUG Loader:1807 - done entity load
18:06:22,841 DEBUG JDBCTransaction:152 - rollback
18:06:22,844 DEBUG JDBCTransaction:163 - rolled back JDBC Connection
18:06:22,844 DEBUG ConnectionManager:398 - aggressively releasing JDBC connection
18:06:22,846 DEBUG ConnectionManager:435 - releasing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)]
18:06:22,851 DEBUG SessionImpl:220 - opened session at timestamp: 4761547500953600
18:06:22,852 DEBUG JDBCTransaction:54 - begin
18:06:22,853 DEBUG ConnectionManager:415 - opening JDBC connection
18:06:22,854 DEBUG JDBCTransaction:59 - current autocommit status: false
18:06:22,979 DEBUG QueryTranslatorImpl:246 - parse() - HQL: update org.hibernate.test.Settings m set m.SizeLimit = ? where m.id = ?
18:06:23,016 DEBUG AST:266 - --- HQL AST ---
\-[UPDATE] 'update'
+-[FROM] 'FROM'
| \-[RANGE] 'RANGE'
| +-[DOT] '.'
| | +-[DOT] '.'
| | | +-[DOT] '.'
| | | | +-[IDENT] 'org'
| | | | \-[IDENT] 'hibernate'
| | | \-[IDENT] 'test'
| | \-[IDENT] 'Settings'
| \-[ALIAS] 'm'
+-[SET] 'set'
| \-[EQ] '='
| +-[DOT] '.'
| | +-[IDENT] 'm'
| | \-[IDENT] 'SizeLimit'
| \-[PARAM] '?'
\-[WHERE] 'where'
\-[EQ] '='
+-[DOT] '.'
| +-[IDENT] 'm'
| \-[IDENT] 'id'
\-[PARAM] '?'
18:06:23,019 DEBUG ErrorCounter:68 - throwQueryException() : no errors
18:06:23,093 DEBUG HqlSqlBaseWalker:111 - update << begin [level=1, statement=update]
18:06:23,119 DEBUG FromElement:105 - FromClause{level=1} : org.hibernate.test.Settings (m) -> settings0_
18:06:23,127 DEBUG FromReferenceNode:51 - Resolved : m -> USER_ID
18:06:23,129 DEBUG DotNode:541 - getDataType() : SizeLimit -> org.hibernate.type.LongType@d3c6a3
18:06:23,129 WARN FromElementType:349 - Using non-qualified column reference [SizeLimit -> ([SIZE_LIMIT])]
18:06:23,131 DEBUG FromReferenceNode:51 - Resolved : m.SizeLimit -> SIZE_LIMIT
18:06:23,137 DEBUG FromReferenceNode:51 - Resolved : m -> USER_ID
18:06:23,157 DEBUG DotNode:541 - getDataType() : id -> org.hibernate.type.LongType@d3c6a3
18:06:23,158 WARN FromElementType:349 - Using non-qualified column reference [id -> ([USER_ID])]
18:06:23,160 DEBUG FromReferenceNode:51 - Resolved : m.id -> USER_ID
18:06:23,161 DEBUG HqlSqlBaseWalker:117 - update : finishing up [level=1, statement=update]
18:06:23,163 DEBUG HqlSqlBaseWalker:123 - update >> end [level=1, statement=update]
18:06:23,174 DEBUG AST:232 - --- SQL AST ---
\-[UPDATE] UpdateStatement: 'update' querySpaces (SETTINGS)
+-[FROM] FromClause: 'FROM' FromClause{level=1, fromElementCounter=1, fromElements=1, fromElementByClassAlias=[m], fromElementByTableAlias=[settings0_], fromElementsByPath=[], collectionJoinFromElementsByPath=[], impliedElements=[]}
| \-[FROM_FRAGMENT] FromElement: 'SETTINGS' FromElement{explicit,not a collection join,not a fetch join,fetch non-lazy properties,classAlias=m,role=null,tableName=SETTINGS,tableAlias=settings0_,origin=null,colums={,className=org.hibernate.test.Settings}}
+-[SET] SqlNode: 'set'
| \-[EQ] BinaryLogicOperatorNode: '='
| +-[DOT] DotNode: 'SIZE_LIMIT' {propertyName=SizeLimit,dereferenceType=4,propertyPath=SizeLimit,path=m.SizeLimit,tableAlias=settings0_,className=org.hibernate.test.Settings,classAlias=m}
| | +-[ALIAS_REF] IdentNode: 'USER_ID' {alias=m, className=org.hibernate.test.Settings, tableAlias=settings0_}
| | \-[IDENT] IdentNode: 'SizeLimit' {originalText=SizeLimit}
| \-[PARAM] ParameterNode: '?' {ordinal=0, expectedType=org.hibernate.type.LongType@d3c6a3}
\-[WHERE] SqlNode: 'where'
\-[EQ] BinaryLogicOperatorNode: '='
+-[DOT] DotNode: 'USER_ID' {propertyName=id,dereferenceType=4,propertyPath=id,path=m.id,tableAlias=settings0_,className=org.hibernate.test.Settings,classAlias=m}
| +-[ALIAS_REF] IdentNode: 'USER_ID' {alias=m, className=org.hibernate.test.Settings, tableAlias=settings0_}
| \-[IDENT] IdentNode: 'id' {originalText=id}
\-[PARAM] ParameterNode: '?' {ordinal=1, expectedType=org.hibernate.type.LongType@d3c6a3}
18:06:23,175 DEBUG ErrorCounter:68 - throwQueryException() : no errors
18:06:23,210 DEBUG ErrorCounter:68 - throwQueryException() : no errors
18:06:23,230 DEBUG SessionFactoryImpl:828 - evicting second-level cache: org.hibernate.test.Settings
18:06:23,232 DEBUG AbstractBatcher:358 - about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
18:06:23,233 DEBUG SQL:393 - update SETTINGS set SIZE_LIMIT=? where USER_ID=?
18:06:23,239 DEBUG AbstractBatcher:366 - about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
18:06:23,242 DEBUG JDBCTransaction:152 - rollback
18:06:23,243 DEBUG JDBCTransaction:163 - rolled back JDBC Connection
18:06:23,244 DEBUG ConnectionManager:398 - aggressively releasing JDBC connection
18:06:23,245 DEBUG ConnectionManager:435 - releasing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)]
18:06:23,247 DEBUG SessionFactoryImpl:828 - evicting second-level cache: org.hibernate.test.Settings
18:06:23,249 DEBUG UpdateTimestampsCache:65 - Invalidating space [SETTINGS], timestamp: 4761547502592000
18:06:23,251 DEBUG SessionImpl:220 - opened session at timestamp: 4761547502592001
18:06:23,272 DEBUG JDBCTransaction:54 - begin
18:06:23,274 DEBUG ConnectionManager:415 - opening JDBC connection
18:06:23,274 DEBUG JDBCTransaction:59 - current autocommit status: false
18:06:23,275 DEBUG EhCache:68 - key: org.hibernate.test.Settings#21429419
18:06:23,277 DEBUG EhCache:77 - Element for org.hibernate.test.Settings#21429419 is null
18:06:23,278 DEBUG Loader:1776 - loading entity: [org.hibernate.test.Settings#21429419]
18:06:23,279 DEBUG AbstractBatcher:358 - about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
18:06:23,281 DEBUG SQL:393 - select settings0_.USER_ID as USER1_0_0_, settings0_.SIZE_LIMIT as SIZE2_0_0_ from SETTINGS settings0_ where settings0_.USER_ID=?
18:06:23,290 DEBUG AbstractBatcher:374 - about to open ResultSet (open ResultSets: 0, globally: 0)
18:06:23,292 DEBUG Loader:1164 - result row: EntityKey[org.hibernate.test.Settings#21429419]
18:06:23,293 DEBUG AbstractBatcher:381 - about to close ResultSet (open ResultSets: 1, globally: 1)
18:06:23,295 DEBUG AbstractBatcher:366 - about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
18:06:23,298 DEBUG TwoPhaseLoad:107 - resolving associations for [org.hibernate.test.Settings#21429419]
18:06:23,300 DEBUG TwoPhaseLoad:135 - adding entity to second-level cache: [org.hibernate.test.Settings#21429419]
18:06:23,301 DEBUG ReadOnlyCache:58 - Caching: org.hibernate.test.Settings#21429419
18:06:23,304 DEBUG TwoPhaseLoad:206 - done materializing entity [org.hibernate.test.Settings#21429419]
18:06:23,306 DEBUG StatefulPersistenceContext:748 - initializing non-lazy collections
18:06:23,308 DEBUG Loader:1807 - done entity load
18:06:23,309 INFO SessionFactoryImpl:767 - closing
Code:
Code: