[hibernate-issues] [Hibernate-JIRA] Created: (HHH-4607) Deleted entities incorrectly reloaded within persistence context due to 2L cache

Guenther Demetz (JIRA) noreply at atlassian.com
Tue Nov 24 10:06:08 EST 2009


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.jspa
-
For more information on JIRA, see: http://www.atlassian.com/software/jira

        


More information about the hibernate-issues mailing list