[hibernate-issues] [Hibernate-JIRA] Resolved: (HHH-6680) 2L caching appears to ignore collections

Strong Liu (JIRA) noreply at atlassian.com
Sun Oct 9 01:51:23 EDT 2011


     [ http://opensource.atlassian.com/projects/hibernate/browse/HHH-6680?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]

Strong Liu resolved HHH-6680.
-----------------------------

    Resolution: Rejected

13:49:14,916  INFO Version:37 - HCANN000001: Hibernate Commons Annotations {4.0.0.CR2}
13:49:14,939  INFO Version:41 - HHH000412: Hibernate Core {[WORKING]}
13:49:14,951  INFO Environment:224 - HHH000205: Loaded properties from resource hibernate.properties: {hibernate.connection.username=sa, hibernate.cache.region_prefix=hibernate.test, hibernate.connection.pool_size=5, hibernate.dialect=org.hibernate.dialect.H2Dialect, hibernate.connection.url=jdbc:h2:mem:db1;DB_CLOSE_DELAY=-1;MVCC=TRUE, hibernate.bytecode.use_reflection_optimizer=false, hibernate.connection.driver_class=org.h2.Driver}
13:49:14,953  INFO Environment:342 - HHH000021: Bytecode provider name : javassist
13:49:14,980  INFO Configuration:713 - HHH000221: Reading mappings from resource: org/hibernate/issue/Pet.hbm.xml
13:49:15,637  INFO DriverManagerConnectionProviderImpl:88 - HHH000402: Using Hibernate built-in connection pool (not for production use!)
13:49:15,641  INFO DriverManagerConnectionProviderImpl:108 - HHH000115: Hibernate connection pool size: 5
13:49:15,642  INFO DriverManagerConnectionProviderImpl:111 - HHH000006: Autocommit mode: true
13:49:15,642  INFO DriverManagerConnectionProviderImpl:125 - HHH000401: using driver [org.h2.Driver] at URL [jdbc:h2:mem:db1;DB_CLOSE_DELAY=-1;MVCC=TRUE]
13:49:15,643  INFO DriverManagerConnectionProviderImpl:128 - HHH000046: Connection properties: {user=sa, autocommit=true}
13:49:15,952  INFO Dialect:118 - HHH000400: Using dialect: org.hibernate.dialect.H2Dialect
13:49:15,965  INFO LobCreatorBuilder:94 - HHH000423: Disabling contextual LOB creation as JDBC driver reported JDBC version [3] less than 4
13:49:15,978  INFO TransactionFactoryInitiator:68 - HHH000399: Using default transaction strategy (direct JDBC transactions)
13:49:15,984  INFO ASTQueryTranslatorFactory:48 - HHH000397: Using ASTQueryTranslatorFactory
13:49:16,256  INFO Version:24 - Hibernate Validator 4.2.0.Final
13:49:16,393  WARN AbstractEhcacheRegionFactory:172 - HHH020003: Could not find a specific ehcache configuration for cache named [hibernate.test.org.hibernate.issue.Owner]; using defaults.
13:49:16,525  WARN AbstractEhcacheRegionFactory:172 - HHH020003: Could not find a specific ehcache configuration for cache named [hibernate.test.org.hibernate.issue.Pet]; using defaults.
13:49:16,536  WARN AbstractEhcacheRegionFactory:172 - HHH020003: Could not find a specific ehcache configuration for cache named [hibernate.test.org.hibernate.issue.Owner.pets]; using defaults.
13:49:16,592  INFO SchemaExport:330 - HHH000227: Running hbm2ddl schema export
Hibernate: 
    alter table dogs 
        drop constraint FK2F22B76BD39EFC
13:49:16,603 ERROR SchemaExport:412 - HHH000389: Unsuccessful: alter table dogs drop constraint FK2F22B76BD39EFC
13:49:16,603 ERROR SchemaExport:3589 - Table "DOGS" not found; SQL statement:

    alter table dogs 
        drop constraint FK2F22B76BD39EFC [42102-145]
Hibernate: 
    alter table owners_pets 
        drop constraint FK26BE5BF3C5D57733
13:49:16,604 ERROR SchemaExport:412 - HHH000389: Unsuccessful: alter table owners_pets drop constraint FK26BE5BF3C5D57733
13:49:16,605 ERROR SchemaExport:3589 - Table "OWNERS_PETS" not found; SQL statement:

    alter table owners_pets 
        drop constraint FK26BE5BF3C5D57733 [42102-145]
Hibernate: 
    alter table owners_pets 
        drop constraint FK26BE5BF330B7F5FF
13:49:16,606 ERROR SchemaExport:412 - HHH000389: Unsuccessful: alter table owners_pets drop constraint FK26BE5BF330B7F5FF
13:49:16,606 ERROR SchemaExport:3589 - Table "OWNERS_PETS" not found; SQL statement:

    alter table owners_pets 
        drop constraint FK26BE5BF330B7F5FF [42102-145]
Hibernate: 
    drop table dogs if exists
Hibernate: 
    drop table owners if exists
Hibernate: 
    drop table owners_pets if exists
Hibernate: 
    drop table pets if exists
Hibernate: 
    create table dogs (
        id integer not null,
        feet integer,
        primary key (id)
    )
Hibernate: 
    create table owners (
        owner_id integer generated by default as identity,
        owner_name varchar(255) not null unique,
        primary key (owner_id)
    )
Hibernate: 
    create table owners_pets (
        id integer not null,
        pet_id integer not null,
        name varchar(255) not null,
        primary key (id, name)
    )
Hibernate: 
    create table pets (
        pet_id integer generated by default as identity,
        pet_type varchar(255) not null,
        pet_age integer,
        primary key (pet_id)
    )
Hibernate: 
    alter table dogs 
        add constraint FK2F22B76BD39EFC 
        foreign key (id) 
        references pets
Hibernate: 
    alter table owners_pets 
        add constraint FK26BE5BF3C5D57733 
        foreign key (id) 
        references owners
Hibernate: 
    alter table owners_pets 
        add constraint FK26BE5BF330B7F5FF 
        foreign key (pet_id) 
        references pets
13:49:16,639  INFO SchemaExport:392 - HHH000230: Schema export complete
13:49:16,643  INFO UpdateTimestampsCache:63 - HHH000250: Starting update timestamps cache at region: hibernate.test.org.hibernate.cache.spi.UpdateTimestampsCache
13:49:16,646  WARN AbstractEhcacheRegionFactory:172 - HHH020003: Could not find a specific ehcache configuration for cache named [hibernate.test.org.hibernate.cache.spi.UpdateTimestampsCache]; using defaults.
13:49:16,649  INFO StandardQueryCache:80 - HHH000248: Starting query cache at region: hibernate.test.org.hibernate.cache.internal.StandardQueryCache
13:49:16,650  WARN AbstractEhcacheRegionFactory:172 - HHH020003: Could not find a specific ehcache configuration for cache named [hibernate.test.org.hibernate.cache.internal.StandardQueryCache]; using defaults.
Hibernate: 
    insert 
    into
        owners
        (owner_id, owner_name) 
    values
        (null, ?)
Hibernate: 
    insert 
    into
        pets
        (pet_id, pet_age, pet_type) 
    values
        (null, ?, 'dog')
Hibernate: 
    insert 
    into
        dogs
        (feet, id) 
    values
        (?, ?)
Hibernate: 
    insert 
    into
        owners_pets
        (id, name, pet_id) 
    values
        (?, ?, ?)
Hibernate: 
    select
        owner0_.owner_id as owner1_0_,
        owner0_.owner_name as owner2_0_ 
    from
        owners owner0_
Hibernate: 
    select
        pets0_.id as id0_1_,
        pets0_.pet_id as pet2_1_,
        pets0_.name as name1_,
        pet1_.pet_id as pet1_2_0_,
        pet1_.pet_age as pet3_2_0_,
        pet1_.pet_type as pet2_2_0_ 
    from
        owners_pets pets0_ 
    inner join
        pets pet1_ 
            on pets0_.pet_id=pet1_.pet_id 
    where
        pets0_.id=?
Hibernate: 
    select
        pet_1_.feet as feet3_ 
    from
        dogs pet_1_ 
    where
        pet_1_.id=?
13:49:17,060  INFO ConcurrentStatisticsImpl:332 - HHH000117: HQL: select o from Owner o, time: 26ms, rows: 1
13:49:18,012  INFO ConcurrentStatisticsImpl:580 - HHH000161: Logging statistics....
13:49:18,013  INFO ConcurrentStatisticsImpl:581 - HHH000251: Start time: 1318139357063
13:49:18,014  INFO ConcurrentStatisticsImpl:582 - HHH000242: Sessions opened: 1
13:49:18,014  INFO ConcurrentStatisticsImpl:583 - HHH000241: Sessions closed: 1
13:49:18,015  INFO ConcurrentStatisticsImpl:584 - HHH000266: Transactions: 1
13:49:18,015  INFO ConcurrentStatisticsImpl:585 - HHH000258: Successful transactions: 1
13:49:18,015  INFO ConcurrentStatisticsImpl:586 - HHH000187: Optimistic lock failures: 0
13:49:18,016  INFO ConcurrentStatisticsImpl:587 - HHH000105: Flushes: 1
13:49:18,016  INFO ConcurrentStatisticsImpl:588 - HHH000048: Connections obtained: 1
13:49:18,016  INFO ConcurrentStatisticsImpl:589 - HHH000253: Statements prepared: 0
13:49:18,017  INFO ConcurrentStatisticsImpl:590 - HHH000252: Statements closed: 0
13:49:18,017  INFO ConcurrentStatisticsImpl:591 - HHH000239: Second level cache puts: 0
13:49:18,018  INFO ConcurrentStatisticsImpl:592 - HHH000237: Second level cache hits: 3
13:49:18,020  INFO ConcurrentStatisticsImpl:593 - HHH000238: Second level cache misses: 0
13:49:18,020  INFO ConcurrentStatisticsImpl:594 - HHH000079: Entities loaded: 0
13:49:18,020  INFO ConcurrentStatisticsImpl:595 - HHH000080: Entities updated: 0
13:49:18,021  INFO ConcurrentStatisticsImpl:596 - HHH000078: Entities inserted: 0
13:49:18,021  INFO ConcurrentStatisticsImpl:597 - HHH000076: Entities deleted: 0
13:49:18,022  INFO ConcurrentStatisticsImpl:598 - HHH000077: Entities fetched (minimize this): 0
13:49:18,022  INFO ConcurrentStatisticsImpl:599 - HHH000033: Collections loaded: 0
13:49:18,022  INFO ConcurrentStatisticsImpl:600 - HHH000036: Collections updated: 0
13:49:18,023  INFO ConcurrentStatisticsImpl:601 - HHH000035: Collections removed: 0
13:49:18,023  INFO ConcurrentStatisticsImpl:602 - HHH000034: Collections recreated: 0
13:49:18,023  INFO ConcurrentStatisticsImpl:603 - HHH000032: Collections fetched (minimize this): 0
13:49:18,024  INFO ConcurrentStatisticsImpl:604 - HHH000210: Queries executed to database: 0
13:49:18,024  INFO ConcurrentStatisticsImpl:605 - HHH000215: Query cache puts: 0
13:49:18,024  INFO ConcurrentStatisticsImpl:606 - HHH000433: update timestamps cache puts: 0
13:49:18,026  INFO ConcurrentStatisticsImpl:607 - HHH000434: update timestamps cache hits: 2500
13:49:18,027  INFO ConcurrentStatisticsImpl:608 - HHH000435: update timestamps cache misses: 0
13:49:18,028  INFO ConcurrentStatisticsImpl:609 - HHH000213: Query cache hits: 2500
13:49:18,028  INFO ConcurrentStatisticsImpl:610 - HHH000214: Query cache misses: 0
13:49:18,029  INFO ConcurrentStatisticsImpl:611 - HHH000173: Max query time: 0ms
13:49:18,057  INFO UpdateChecker:98 - New update(s) found: 2.4.5 [http://www.terracotta.org/confluence/display/release/Release+Notes+Ehcache+Core+2.4]. Please check http://ehcache.org for the latest version.

Process finished with exit code 0


> 2L caching appears to ignore collections
> ----------------------------------------
>
>                 Key: HHH-6680
>                 URL: http://opensource.atlassian.com/projects/hibernate/browse/HHH-6680
>             Project: Hibernate Core
>          Issue Type: Bug
>          Components: caching (L2)
>    Affects Versions: 3.6.7
>         Environment: 3.6.7 on Derby 10.8.1.2 and Oracle 11g
>            Reporter: Ben Hood
>
> I have a scenario where a (read-mostly) mapped collection is eagerly loaded with the parent object, but when I retrieve the graph, the 2L cache appears to get ignored and the data is hydrated from the DB.
> I have created a test case to reproduce this issue as a runnable Maven project on Github : https://github.com/0x6e6562/hibernate_2L

--
This message is automatically generated by JIRA.
For more information on JIRA, see: http://www.atlassian.com/software/jira

        


More information about the hibernate-issues mailing list