Deleted entities incorrectly reloaded within persistence context due to 2L cache -------------------------------------------------------------------------------- Key: HHH-4607 URL: http://opensource.atlassian.com/projects/hibernate/browse/HHH-4607 Project: Hibernate Core Issue Type: Bug Components: caching (L2) Affects Versions: 3.3.2 Environment: Hibernate3.3.2GA, SQLServer2008 used with COMMITED_READ isolation level Reporter: Guenther Demetz Attachments: TestCaseReloadAfterDelete.jar Normally hibernate_session.get(entityName, id) returns null if the concerning entity is scheduled for removal, indipendently if the current context was already flushed or not, and this is also correct. Attached testcase indeed shows, that with active 2Lcache hibernate_session.get(entityName, id) suddenly and incorrectly returns the concerning entity again if the deletion is already flushed and if in meantime another concurrent session do load the entity (possible with COMMITED_READ isolation)! Please see the attached testcase for detailed informations. Here the output of the testcase: 15:37:30,417 INFO Version:15 - Hibernate Annotations 3.4.0.GA 15:37:30,446 INFO Environment:560 - Hibernate 3.3.2.GA 15:37:30,452 INFO Environment:593 - hibernate.properties not found 15:37:30,461 INFO Environment:771 - Bytecode provider name : javassist 15:37:30,470 INFO Environment:652 - using JDK 1.4 java.sql.Timestamp handling 15:37:30,580 INFO Version:14 - Hibernate Commons Annotations 3.1.0.GA 15:37:30,587 INFO Version:16 - Hibernate EntityManager 3.4.0.CR1 15:37:30,993 INFO AnnotationBinder:419 - Binding entity from annotated class: hello.Customer$Passport 15:37:31,048 INFO EntityBinder:422 - Bind entity hello.Customer$Passport on table Customer$Passport 15:37:31,141 INFO AnnotationBinder:419 - Binding entity from annotated class: hello.Customer 15:37:31,143 INFO EntityBinder:422 - Bind entity hello.Customer on table Customer 15:37:31,191 INFO AnnotationBinder:419 - Binding entity from annotated class: hello.A 15:37:31,193 INFO EntityBinder:422 - Bind entity hello.A on table A 15:37:31,206 INFO AnnotationBinder:419 - Binding entity from annotated class: hello.Messag 15:37:31,207 INFO EntityBinder:422 - Bind entity hello.Messag on table MESSAG 15:37:31,221 INFO AnnotationBinder:419 - Binding entity from annotated class: hello.SMS 15:37:31,224 INFO EntityBinder:422 - Bind entity hello.SMS on table SMS 15:37:31,240 INFO AnnotationBinder:419 - Binding entity from annotated class: hello.C 15:37:31,241 INFO EntityBinder:422 - Bind entity hello.C on table C 15:37:31,252 INFO AnnotationBinder:419 - Binding entity from annotated class: hello.B 15:37:31,254 INFO EntityBinder:422 - Bind entity hello.B on table B 15:37:31,257 INFO AnnotationBinder:419 - Binding entity from annotated class: hello.Amme 15:37:31,258 INFO EntityBinder:422 - Bind entity hello.Amme on table Amme 15:37:31,262 INFO AnnotationBinder:419 - Binding entity from annotated class: hello.Footballer 15:37:31,263 INFO EntityBinder:422 - Bind entity hello.Footballer on table Footballer 15:37:31,360 INFO CollectionBinder:650 - Mapping collection: hello.C.aggC -> C 15:37:31,370 INFO Version:17 - Hibernate Validator 3.1.0.GA 15:37:31,443 INFO HibernateSearchEventListenerRegister:53 - Unable to find org.hibernate.search.event.FullTextIndexEventListener on the classpath. Hibernate Search is not enabled. 15:37:31,503 INFO DriverManagerConnectionProvider:64 - Using Hibernate built-in connection pool (not for production use!) 15:37:31,504 INFO DriverManagerConnectionProvider:65 - Hibernate connection pool size: 20 15:37:31,505 INFO DriverManagerConnectionProvider:68 - autocommit mode: true 15:37:31,506 INFO DriverManagerConnectionProvider:72 - JDBC isolation level: READ_COMMITTED 15:37:31,658 INFO DriverManagerConnectionProvider:103 - using driver: com.microsoft.sqlserver.jdbc.SQLServerDriver at URL: jdbc:sqlserver://phx00081:1433;databasename=jpaexample 15:37:31,660 INFO DriverManagerConnectionProvider:109 - connection properties: {user=sa, password=****, autocommit=true, release_mode=auto} 15:37:32,305 INFO SettingsFactory:114 - RDBMS: Microsoft SQL Server, version: 10.00.1600 15:37:32,314 INFO SettingsFactory:115 - JDBC driver: Microsoft SQL Server JDBC Driver 2.0, version: 2.0.1803.100 15:37:32,353 INFO Dialect:175 - Using dialect: org.hibernate.dialect.SQLServerDialect 15:37:32,365 INFO TransactionFactoryFactory:62 - Transaction strategy: org.hibernate.transaction.JDBCTransactionFactory 15:37:32,367 INFO TransactionManagerLookupFactory:80 - No TransactionManagerLookup configured (in JTA environment, use of read-write or transactional second-level cache is not recommended) 15:37:32,367 INFO SettingsFactory:161 - Automatic flush during beforeCompletion(): disabled 15:37:32,368 INFO SettingsFactory:165 - Automatic session close at end of transaction: disabled 15:37:32,369 INFO SettingsFactory:180 - Scrollable result sets: enabled 15:37:32,370 INFO SettingsFactory:188 - JDBC3 getGeneratedKeys(): enabled 15:37:32,370 INFO SettingsFactory:196 - Connection release mode: auto 15:37:32,376 INFO SettingsFactory:223 - Default batch fetch size: 1 15:37:32,379 INFO SettingsFactory:227 - Generate SQL with comments: disabled 15:37:32,379 INFO SettingsFactory:231 - Order SQL updates by primary key: disabled 15:37:32,380 INFO SettingsFactory:235 - Order SQL inserts for batching: disabled 15:37:32,380 INFO SettingsFactory:397 - Query translator: org.hibernate.hql.ast.ASTQueryTranslatorFactory 15:37:32,384 INFO ASTQueryTranslatorFactory:47 - Using ASTQueryTranslatorFactory 15:37:32,385 INFO SettingsFactory:243 - Query language substitutions: {} 15:37:32,385 INFO SettingsFactory:248 - JPA-QL strict compliance: enabled 15:37:32,385 INFO SettingsFactory:253 - Second-level cache: enabled 15:37:32,386 INFO SettingsFactory:257 - Query cache: disabled 15:37:32,391 INFO SettingsFactory:382 - Cache region factory : org.hibernate.cache.impl.bridge.RegionFactoryCacheProviderBridge 15:37:32,392 INFO RegionFactoryCacheProviderBridge:61 - Cache provider: org.hibernate.cache.EhCacheProvider 15:37:32,398 INFO SettingsFactory:267 - Optimize cache for minimal puts: disabled 15:37:32,398 INFO SettingsFactory:276 - Structured second-level cache entries: disabled 15:37:32,404 INFO SettingsFactory:305 - Statistics: disabled 15:37:32,404 INFO SettingsFactory:309 - Deleted entity synthetic identifier rollback: disabled 15:37:32,405 INFO SettingsFactory:324 - Default entity-mode: pojo 15:37:32,405 INFO SettingsFactory:328 - Named query checking : enabled 15:37:32,474 INFO SessionFactoryImpl:193 - building session factory 15:37:32,496 WARN ConfigurationFactory:127 - No configuration found. Configuring ehcache from ehcache-failsafe.xml found in the classpath: jar:file:/home/pb00067/hibernate-distribution-3.3.2.GA/lib/optional/ehcache/ehcache-1.2.3.jar!/ehcache-failsafe.xml 15:37:32,552 WARN EhCacheProvider:93 - Could not find configuration [hello.A]; using defaults. 15:37:32,719 INFO PojoInstantiator:84 - no default (no-argument) constructor for class: hello.Customer$Passport (class must be instantiated by Interceptor) 15:37:32,841 INFO SessionFactoryObjectFactory:105 - Not binding factory to JNDI, no JNDI name configured 15:37:32,875 INFO SchemaExport:226 - Running hbm2ddl schema export 15:37:32,877 INFO SchemaExport:251 - exporting generated schema to database 15:37:32,960 INFO SchemaExport:268 - schema export complete The problem stays probably in method DefaultLoadEventListener#doLoad: as the delete-action is already flushed, the concerning entity is not present in the sessioncache anymore, where it was previously marked as REMOVED DefaultLoadEventListener#doLoad: ... Object entity = loadFromSessionCache( event, keyToLoad, options ); if ( entity == REMOVED_ENTITY_MARKER ) { log.debug( "load request found matching entity in context, but it is scheduled for removal; returning null" ); return null; } ... entity = loadFromSecondLevelCache(event, persister, options); if ( entity != null ) { ... return entity; } Afterwards doLoad attempts to load the entity from SecondLevelCache, where in meantime it may be put again due another concurrent session. N.B.: I believe the problem arises too if I would use JTA using the same transaction manager for both hibernate and 2LC (JBoss). best regards G.D. -- This message is automatically generated by JIRA. - If you think it was sent incorrectly contact one of the administrators: http://opensource.atlassian.com/projects/hibernate/secure/Administrators.... - For more information on JIRA, see: http://www.atlassian.com/software/jira