Hibernate二级缓存,日志说明一切????

于 2009-10-12 22:29:46 发布
阅读量610 收藏
点赞数
分类专栏： Hibernate 文章标签： Hibernate Cache 企业应用 Linux 设计模式

....................

.........

2009-10-12 22:23:35,046 -- DEBUG -- throwQueryException() : no errors
2009-10-12 22:23:35,062 -- DEBUG -- HQL: from com.demo.model.Student where id<?
2009-10-12 22:23:35,062 -- DEBUG -- SQL: select student0_.id as id0_, student0_.name as name0_, student0_.age as age0_, student0_.sex as sex0_, student0_.id_teacher as id5_0_ from student student0_ where student0_.id<?
2009-10-12 22:23:35,062 -- DEBUG -- throwQueryException() : no errors
2009-10-12 22:23:35,078 -- DEBUG -- HQL param location recognition took 0 mills (from Student where id<?)
2009-10-12 22:23:35,078 -- DEBUG -- located HQL query plan in cache (from Student where id<?)
2009-10-12 22:23:35,078 -- DEBUG -- find: from Student where id<?
2009-10-12 22:23:35,078 -- DEBUG -- parameters: [4]
2009-10-12 22:23:35,078 -- DEBUG -- named parameters: {}
2009-10-12 22:23:35,078 -- INFO -- starting query cache at region: com.demo.model.Student
2009-10-12 22:23:35,078 -- DEBUG -- checking cached query results in region: com.demo.model.Student
2009-10-12 22:23:35,078 -- DEBUG -- key: sql: select student0_.id as id0_, student0_.name as name0_, student0_.age as age0_, student0_.sex as sex0_, student0_.id_teacher as id5_0_ from student student0_ where student0_.id<?; parameters: 4, ; named parameters: {}

第一次HQL miss
2009-10-12 22:23:35,078 -- DEBUG -- com.demo.model.StudentCache: com.demo.model.StudentMemoryStore miss for sql: select student0_.id as id0_, student0_.name as name0_, student0_.age as age0_, student0_.sex as sex0_, student0_.id_teacher as id5_0_ from student student0_ where student0_.id<?; parameters: 4, ; named parameters: {}
2009-10-12 22:23:35,078 -- DEBUG -- com.demo.model.Student cache - Miss
2009-10-12 22:23:35,078 -- DEBUG -- Element for sql: select student0_.id as id0_, student0_.name as name0_, student0_.age as age0_, student0_.sex as sex0_, student0_.id_teacher as id5_0_ from student student0_ where student0_.id<?; parameters: 4, ; named parameters: {} is null
2009-10-12 22:23:35,078 -- DEBUG -- query results were not found in cache
2009-10-12 22:23:35,078 -- DEBUG -- about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
2009-10-12 22:23:35,078 -- DEBUG -- select student0_.id as id0_, student0_.name as name0_, student0_.age as age0_, student0_.sex as sex0_, student0_.id_teacher as id5_0_ from student student0_ where student0_.id<?
Hibernate: select student0_.id as id0_, student0_.name as name0_, student0_.age as age0_, student0_.sex as sex0_, student0_.id_teacher as id5_0_ from student student0_ where student0_.id<?
2009-10-12 22:23:35,078 -- DEBUG -- preparing statement
2009-10-12 22:23:35,093 -- DEBUG -- Implementing interface java.sql.PreparedStatement
2009-10-12 22:23:35,093 -- DEBUG -- Implementing interface java.sql.Statement
2009-10-12 22:23:35,171 -- DEBUG -- binding '4' to parameter: 1
2009-10-12 22:23:35,171 -- DEBUG -- about to open ResultSet (open ResultSets: 0, globally: 0)
2009-10-12 22:23:35,187 -- DEBUG -- processing result set
2009-10-12 22:23:35,187 -- DEBUG -- result set row: 0
2009-10-12 22:23:35,203 -- DEBUG -- returning '1' as column: id0_
2009-10-12 22:23:35,203 -- DEBUG -- result row: EntityKey[com.demo.model.Student#1]
2009-10-12 22:23:35,203 -- DEBUG -- Initializing object from ResultSet: [com.demo.model.Student#1]
2009-10-12 22:23:35,203 -- DEBUG -- Hydrating entity: [com.demo.model.Student#1]
2009-10-12 22:23:35,203 -- DEBUG -- returning 'I'am Hibernate' as column: name0_
2009-10-12 22:23:35,203 -- DEBUG -- returning '21' as column: age0_
2009-10-12 22:23:35,203 -- DEBUG -- returning '1' as column: sex0_
2009-10-12 22:23:35,203 -- DEBUG -- returning null as column: id5_0_
2009-10-12 22:23:35,203 -- DEBUG -- result set row: 1
2009-10-12 22:23:35,203 -- DEBUG -- returning '2' as column: id0_
2009-10-12 22:23:35,203 -- DEBUG -- result row: EntityKey[com.demo.model.Student#2]
2009-10-12 22:23:35,203 -- DEBUG -- Initializing object from ResultSet: [com.demo.model.Student#2]
2009-10-12 22:23:35,203 -- DEBUG -- Hydrating entity: [com.demo.model.Student#2]
2009-10-12 22:23:35,203 -- DEBUG -- returning 'I'am Hibernate' as column: name0_
2009-10-12 22:23:35,203 -- DEBUG -- returning '21' as column: age0_
2009-10-12 22:23:35,203 -- DEBUG -- returning '1' as column: sex0_
2009-10-12 22:23:35,203 -- DEBUG -- returning null as column: id5_0_
2009-10-12 22:23:35,203 -- DEBUG -- result set row: 2
2009-10-12 22:23:35,203 -- DEBUG -- returning '3' as column: id0_
2009-10-12 22:23:35,203 -- DEBUG -- result row: EntityKey[com.demo.model.Student#3]
2009-10-12 22:23:35,203 -- DEBUG -- Initializing object from ResultSet: [com.demo.model.Student#3]
2009-10-12 22:23:35,203 -- DEBUG -- Hydrating entity: [com.demo.model.Student#3]
2009-10-12 22:23:35,203 -- DEBUG -- returning 'I'am Hibernate' as column: name0_
2009-10-12 22:23:35,203 -- DEBUG -- returning '21' as column: age0_
2009-10-12 22:23:35,203 -- DEBUG -- returning '1' as column: sex0_
2009-10-12 22:23:35,203 -- DEBUG -- returning null as column: id5_0_
2009-10-12 22:23:35,203 -- DEBUG -- done processing result set (3 rows)
2009-10-12 22:23:35,203 -- DEBUG -- about to close ResultSet (open ResultSets: 1, globally: 1)
2009-10-12 22:23:35,203 -- DEBUG -- about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
2009-10-12 22:23:35,203 -- DEBUG -- closing statement
2009-10-12 22:23:35,203 -- DEBUG -- total objects hydrated: 3
2009-10-12 22:23:35,203 -- DEBUG -- resolving associations for [com.demo.model.Student#1]
2009-10-12 22:23:35,218 -- DEBUG -- adding entity to second-level cache: [com.demo.model.Student#1]
2009-10-12 22:23:35,218 -- DEBUG -- Caching: com.demo.model.Student#1
2009-10-12 22:23:35,218 -- DEBUG -- key: com.demo.model.Student#1
2009-10-12 22:23:35,218 -- DEBUG -- com.demo.model.StudentCache: com.demo.model.StudentMemoryStore miss for com.demo.model.Student#1
2009-10-12 22:23:35,218 -- DEBUG -- com.demo.model.Student cache - Miss
2009-10-12 22:23:35,218 -- DEBUG -- Element for com.demo.model.Student#1 is null
2009-10-12 22:23:35,218 -- DEBUG -- Cached: com.demo.model.Student#1
2009-10-12 22:23:35,218 -- DEBUG -- done materializing entity [com.demo.model.Student#1]
2009-10-12 22:23:35,218 -- DEBUG -- resolving associations for [com.demo.model.Student#2]
2009-10-12 22:23:35,218 -- DEBUG -- adding entity to second-level cache: [com.demo.model.Student#2]
2009-10-12 22:23:35,218 -- DEBUG -- Caching: com.demo.model.Student#2
2009-10-12 22:23:35,218 -- DEBUG -- key: com.demo.model.Student#2
2009-10-12 22:23:35,218 -- DEBUG -- com.demo.model.StudentCache: com.demo.model.StudentMemoryStore miss for com.demo.model.Student#2
2009-10-12 22:23:35,218 -- DEBUG -- com.demo.model.Student cache - Miss
2009-10-12 22:23:35,218 -- DEBUG -- Element for com.demo.model.Student#2 is null
2009-10-12 22:23:35,218 -- DEBUG -- Cached: com.demo.model.Student#2
2009-10-12 22:23:35,218 -- DEBUG -- done materializing entity [com.demo.model.Student#2]
2009-10-12 22:23:35,218 -- DEBUG -- resolving associations for [com.demo.model.Student#3]
2009-10-12 22:23:35,218 -- DEBUG -- adding entity to second-level cache: [com.demo.model.Student#3]
2009-10-12 22:23:35,218 -- DEBUG -- Caching: com.demo.model.Student#3
2009-10-12 22:23:35,218 -- DEBUG -- key: com.demo.model.Student#3
2009-10-12 22:23:35,218 -- DEBUG -- com.demo.model.StudentCache: com.demo.model.StudentMemoryStore miss for com.demo.model.Student#3
2009-10-12 22:23:35,218 -- DEBUG -- com.demo.model.Student cache - Miss
2009-10-12 22:23:35,218 -- DEBUG -- Element for com.demo.model.Student#3 is null
2009-10-12 22:23:35,218 -- DEBUG -- Cached: com.demo.model.Student#3
2009-10-12 22:23:35,218 -- DEBUG -- done materializing entity [com.demo.model.Student#3]
2009-10-12 22:23:35,218 -- DEBUG -- initializing non-lazy collections
2009-10-12 22:23:35,218 -- DEBUG -- caching query results in region: com.demo.model.Student; timestamp=5141943970942976
2009-10-12 22:23:35,218 -- DEBUG -- commit
2009-10-12 22:23:35,218 -- DEBUG -- automatically flushing session
2009-10-12 22:23:35,218 -- DEBUG -- flushing session
2009-10-12 22:23:35,218 -- DEBUG -- processing flush-time cascades
2009-10-12 22:23:35,218 -- DEBUG -- dirty checking collections
2009-10-12 22:23:35,218 -- DEBUG -- Flushing entities and processing referenced collections
2009-10-12 22:23:35,234 -- DEBUG -- Processing unreferenced collections
2009-10-12 22:23:35,234 -- DEBUG -- Scheduling collection removes/(re)creates/updates
2009-10-12 22:23:35,234 -- DEBUG -- Flushed: 0 insertions, 0 updates, 0 deletions to 3 objects
2009-10-12 22:23:35,234 -- DEBUG -- Flushed: 0 (re)creations, 0 updates, 0 removals to 0 collections
2009-10-12 22:23:35,234 -- DEBUG -- listing entities:
2009-10-12 22:23:35,234 -- DEBUG -- com.demo.model.Student{sex=1, age=21, teacher=null, name=I'am Hibernate, id=1}
2009-10-12 22:23:35,234 -- DEBUG -- com.demo.model.Student{sex=1, age=21, teacher=null, name=I'am Hibernate, id=3}
2009-10-12 22:23:35,234 -- DEBUG -- com.demo.model.Student{sex=1, age=21, teacher=null, name=I'am Hibernate, id=2}
2009-10-12 22:23:35,234 -- DEBUG -- executing flush
2009-10-12 22:23:35,234 -- DEBUG -- registering flush begin
2009-10-12 22:23:35,234 -- DEBUG -- registering flush end
2009-10-12 22:23:35,234 -- DEBUG -- post flush
2009-10-12 22:23:35,234 -- DEBUG -- before transaction completion
2009-10-12 22:23:35,234 -- DEBUG -- before transaction completion
2009-10-12 22:23:35,234 -- DEBUG -- committed JDBC Connection
2009-10-12 22:23:35,234 -- DEBUG -- after transaction completion
2009-10-12 22:23:35,234 -- DEBUG -- aggressively releasing JDBC connection
2009-10-12 22:23:35,234 -- DEBUG -- releasing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)]
2009-10-12 22:23:35,234 -- DEBUG -- #1 - autoCommit reset back to true
2009-10-12 22:23:35,234 -- DEBUG -- after transaction completion
2009-10-12 22:23:35,234 -- DEBUG -- automatically closing session
2009-10-12 22:23:35,234 -- DEBUG -- closing session
2009-10-12 22:23:35,234 -- DEBUG -- connection already null in cleanup : no action
第一次查询的信息

结果集大小:3
Thread-0 使用时间:547毫秒
2009-10-12 22:23:35,234 -- DEBUG -- opened session at timestamp: 5141943972798464
2009-10-12 22:23:35,234 -- DEBUG -- allowing method [beginTransaction] in non-transacted context
2009-10-12 22:23:35,234 -- DEBUG -- allowing proxied method [beginTransaction] to proceed to real session
2009-10-12 22:23:35,234 -- DEBUG -- begin
2009-10-12 22:23:35,234 -- DEBUG -- opening JDBC connection
2009-10-12 22:23:35,234 -- DEBUG -- current autocommit status: false
2009-10-12 22:23:35,234 -- DEBUG -- after transaction begin
2009-10-12 22:23:35,234 -- DEBUG -- allowing proxied method [createQuery] to proceed to real session
2009-10-12 22:23:35,234 -- DEBUG -- located HQL query plan in cache (from Student where id<?)
2009-10-12 22:23:35,234 -- DEBUG -- located HQL query plan in cache (from Student where id<?)
2009-10-12 22:23:35,234 -- DEBUG -- find: from Student where id<?
2009-10-12 22:23:35,234 -- DEBUG -- parameters: [3]
2009-10-12 22:23:35,234 -- DEBUG -- named parameters: {}
2009-10-12 22:23:35,234 -- DEBUG -- checking cached query results in region: com.demo.model.Student
2009-10-12 22:23:35,234 -- DEBUG -- key: sql: select student0_.id as id0_, student0_.name as name0_, student0_.age as age0_, student0_.sex as sex0_, student0_.id_teacher as id5_0_ from student student0_ where student0_.id<?; parameters: 3, ; named parameters: {}

第二次HQL miss
2009-10-12 22:23:35,234 -- DEBUG -- com.demo.model.StudentCache: com.demo.model.StudentMemoryStore miss for sql: select student0_.id as id0_, student0_.name as name0_, student0_.age as age0_, student0_.sex as sex0_, student0_.id_teacher as id5_0_ from student student0_ where student0_.id<?; parameters: 3, ; named parameters: {}
2009-10-12 22:23:35,234 -- DEBUG -- com.demo.model.Student cache - Miss
2009-10-12 22:23:35,234 -- DEBUG -- Element for sql: select student0_.id as id0_, student0_.name as name0_, student0_.age as age0_, student0_.sex as sex0_, student0_.id_teacher as id5_0_ from student student0_ where student0_.id<?; parameters: 3, ; named parameters: {} is null
2009-10-12 22:23:35,234 -- DEBUG -- query results were not found in cache
2009-10-12 22:23:35,234 -- DEBUG -- about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
2009-10-12 22:23:35,234 -- DEBUG -- select student0_.id as id0_, student0_.name as name0_, student0_.age as age0_, student0_.sex as sex0_, student0_.id_teacher as id5_0_ from student student0_ where student0_.id<?
Hibernate: select student0_.id as id0_, student0_.name as name0_, student0_.age as age0_, student0_.sex as sex0_, student0_.id_teacher as id5_0_ from student student0_ where student0_.id<?
2009-10-12 22:23:35,234 -- DEBUG -- preparing statement
2009-10-12 22:23:35,234 -- DEBUG -- binding '3' to parameter: 1
2009-10-12 22:23:35,234 -- DEBUG -- about to open ResultSet (open ResultSets: 0, globally: 0)
2009-10-12 22:23:35,234 -- DEBUG -- processing result set
2009-10-12 22:23:35,234 -- DEBUG -- result set row: 0
2009-10-12 22:23:35,234 -- DEBUG -- returning '1' as column: id0_
2009-10-12 22:23:35,234 -- DEBUG -- result row: EntityKey[com.demo.model.Student#1]
2009-10-12 22:23:35,234 -- DEBUG -- Initializing object from ResultSet: [com.demo.model.Student#1]
2009-10-12 22:23:35,234 -- DEBUG -- Hydrating entity: [com.demo.model.Student#1]
2009-10-12 22:23:35,234 -- DEBUG -- returning 'I'am Hibernate' as column: name0_
2009-10-12 22:23:35,234 -- DEBUG -- returning '21' as column: age0_
2009-10-12 22:23:35,234 -- DEBUG -- returning '1' as column: sex0_
2009-10-12 22:23:35,234 -- DEBUG -- returning null as column: id5_0_
2009-10-12 22:23:35,234 -- DEBUG -- result set row: 1
2009-10-12 22:23:35,234 -- DEBUG -- returning '2' as column: id0_
2009-10-12 22:23:35,250 -- DEBUG -- result row: EntityKey[com.demo.model.Student#2]
2009-10-12 22:23:35,250 -- DEBUG -- Initializing object from ResultSet: [com.demo.model.Student#2]
2009-10-12 22:23:35,250 -- DEBUG -- Hydrating entity: [com.demo.model.Student#2]
2009-10-12 22:23:35,250 -- DEBUG -- returning 'I'am Hibernate' as column: name0_
2009-10-12 22:23:35,250 -- DEBUG -- returning '21' as column: age0_
2009-10-12 22:23:35,250 -- DEBUG -- returning '1' as column: sex0_
2009-10-12 22:23:35,250 -- DEBUG -- returning null as column: id5_0_
2009-10-12 22:23:35,250 -- DEBUG -- done processing result set (2 rows)
2009-10-12 22:23:35,250 -- DEBUG -- about to close ResultSet (open ResultSets: 1, globally: 1)
2009-10-12 22:23:35,250 -- DEBUG -- about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
2009-10-12 22:23:35,250 -- DEBUG -- closing statement
2009-10-12 22:23:35,250 -- DEBUG -- total objects hydrated: 2
2009-10-12 22:23:35,250 -- DEBUG -- resolving associations for [com.demo.model.Student#1]
2009-10-12 22:23:35,250 -- DEBUG -- adding entity to second-level cache: [com.demo.model.Student#1]
2009-10-12 22:23:35,250 -- DEBUG -- Caching: com.demo.model.Student#1
2009-10-12 22:23:35,250 -- DEBUG -- key: com.demo.model.Student#1

对象的命中,
2009-10-12 22:23:35,250 -- DEBUG -- com.demo.model.StudentCache: com.demo.model.StudentMemoryStore hit for com.demo.model.Student#1
2009-10-12 22:23:35,250 -- DEBUG -- Item was already cached: com.demo.model.Student#1
2009-10-12 22:23:35,250 -- DEBUG -- done materializing entity [com.demo.model.Student#1]
2009-10-12 22:23:35,250 -- DEBUG -- resolving associations for [com.demo.model.Student#2]
2009-10-12 22:23:35,250 -- DEBUG -- adding entity to second-level cache: [com.demo.model.Student#2]
2009-10-12 22:23:35,250 -- DEBUG -- Caching: com.demo.model.Student#2
2009-10-12 22:23:35,250 -- DEBUG -- key: com.demo.model.Student#2
2009-10-12 22:23:35,250 -- DEBUG -- com.demo.model.StudentCache: com.demo.model.StudentMemoryStore hit for com.demo.model.Student#2
2009-10-12 22:23:35,250 -- DEBUG -- Item was already cached: com.demo.model.Student#2
2009-10-12 22:23:35,250 -- DEBUG -- done materializing entity [com.demo.model.Student#2]
2009-10-12 22:23:35,250 -- DEBUG -- initializing non-lazy collections
2009-10-12 22:23:35,250 -- DEBUG -- caching query results in region: com.demo.model.Student; timestamp=5141943972798464
2009-10-12 22:23:35,250 -- DEBUG -- commit
2009-10-12 22:23:35,250 -- DEBUG -- automatically flushing session
2009-10-12 22:23:35,250 -- DEBUG -- flushing session
2009-10-12 22:23:35,250 -- DEBUG -- processing flush-time cascades
2009-10-12 22:23:35,250 -- DEBUG -- dirty checking collections
2009-10-12 22:23:35,250 -- DEBUG -- Flushing entities and processing referenced collections
2009-10-12 22:23:35,250 -- DEBUG -- Processing unreferenced collections
2009-10-12 22:23:35,250 -- DEBUG -- Scheduling collection removes/(re)creates/updates
2009-10-12 22:23:35,250 -- DEBUG -- Flushed: 0 insertions, 0 updates, 0 deletions to 2 objects
2009-10-12 22:23:35,250 -- DEBUG -- Flushed: 0 (re)creations, 0 updates, 0 removals to 0 collections
2009-10-12 22:23:35,250 -- DEBUG -- listing entities:
2009-10-12 22:23:35,250 -- DEBUG -- com.demo.model.Student{sex=1, age=21, teacher=null, name=I'am Hibernate, id=1}
2009-10-12 22:23:35,250 -- DEBUG -- com.demo.model.Student{sex=1, age=21, teacher=null, name=I'am Hibernate, id=2}
2009-10-12 22:23:35,250 -- DEBUG -- executing flush
2009-10-12 22:23:35,250 -- DEBUG -- registering flush begin
2009-10-12 22:23:35,250 -- DEBUG -- registering flush end
2009-10-12 22:23:35,250 -- DEBUG -- post flush
2009-10-12 22:23:35,250 -- DEBUG -- before transaction completion
2009-10-12 22:23:35,250 -- DEBUG -- before transaction completion
2009-10-12 22:23:35,250 -- DEBUG -- committed JDBC Connection
2009-10-12 22:23:35,250 -- DEBUG -- after transaction completion
2009-10-12 22:23:35,250 -- DEBUG -- aggressively releasing JDBC connection
2009-10-12 22:23:35,250 -- DEBUG -- releasing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)]
2009-10-12 22:23:35,250 -- DEBUG -- #2 - autoCommit reset back to true
2009-10-12 22:23:35,250 -- DEBUG -- after transaction completion
2009-10-12 22:23:35,250 -- DEBUG -- automatically closing session
2009-10-12 22:23:35,250 -- DEBUG -- closing session
2009-10-12 22:23:35,250 -- DEBUG -- connection already null in cleanup : no action

第二次查询信息
结果集大小:2
Thread-0 使用时间:16毫秒
2009-10-12 22:23:35,250 -- DEBUG -- opened session at timestamp: 5141943972864000
2009-10-12 22:23:35,250 -- DEBUG -- allowing method [beginTransaction] in non-transacted context
2009-10-12 22:23:35,250 -- DEBUG -- allowing proxied method [beginTransaction] to proceed to real session
2009-10-12 22:23:35,250 -- DEBUG -- begin
2009-10-12 22:23:35,250 -- DEBUG -- opening JDBC connection
2009-10-12 22:23:35,250 -- DEBUG -- current autocommit status: false
2009-10-12 22:23:35,250 -- DEBUG -- after transaction begin
2009-10-12 22:23:35,250 -- DEBUG -- allowing proxied method [createQuery] to proceed to real session
2009-10-12 22:23:35,250 -- DEBUG -- located HQL query plan in cache (from Student where id<?)
2009-10-12 22:23:35,250 -- DEBUG -- located HQL query plan in cache (from Student where id<?)
2009-10-12 22:23:35,250 -- DEBUG -- find: from Student where id<?
2009-10-12 22:23:35,250 -- DEBUG -- parameters: [3]
2009-10-12 22:23:35,250 -- DEBUG -- named parameters: {}
2009-10-12 22:23:35,250 -- DEBUG -- checking cached query results in region: com.demo.model.Student
2009-10-12 22:23:35,250 -- DEBUG -- key: sql: select student0_.id as id0_, student0_.name as name0_, student0_.age as age0_, student0_.sex as sex0_, student0_.id_teacher as id5_0_ from student student0_ where student0_.id<?; parameters: 3, ; named parameters: {}

第三次同第二次HQL一样,在此命中了
2009-10-12 22:23:35,250 -- DEBUG -- com.demo.model.StudentCache: com.demo.model.StudentMemoryStore hit for sql: select student0_.id as id0_, student0_.name as name0_, student0_.age as age0_, student0_.sex as sex0_, student0_.id_teacher as id5_0_ from student student0_ where student0_.id<?; parameters: 3, ; named parameters: {}
2009-10-12 22:23:35,250 -- DEBUG -- Checking query spaces for up-to-dateness: [student]
2009-10-12 22:23:35,250 -- DEBUG -- key: student
2009-10-12 22:23:35,250 -- DEBUG -- org.hibernate.cache.UpdateTimestampsCacheCache: org.hibernate.cache.UpdateTimestampsCacheMemoryStore miss for student
2009-10-12 22:23:35,250 -- DEBUG -- org.hibernate.cache.UpdateTimestampsCache cache - Miss
2009-10-12 22:23:35,250 -- DEBUG -- Element for student is null
2009-10-12 22:23:35,250 -- DEBUG -- returning cached query results
2009-10-12 22:23:35,250 -- DEBUG -- loading entity: [com.demo.model.Student#1]
2009-10-12 22:23:35,250 -- DEBUG -- attempting to resolve: [com.demo.model.Student#1]
2009-10-12 22:23:35,250 -- DEBUG -- Cache lookup: com.demo.model.Student#1
2009-10-12 22:23:35,250 -- DEBUG -- key: com.demo.model.Student#1
2009-10-12 22:23:35,250 -- DEBUG -- com.demo.model.StudentCache: com.demo.model.StudentMemoryStore hit for com.demo.model.Student#1
2009-10-12 22:23:35,250 -- DEBUG -- Cache hit: com.demo.model.Student#1
2009-10-12 22:23:35,250 -- DEBUG -- assembling entity from second-level cache: [com.demo.model.Student#1]
2009-10-12 22:23:35,250 -- DEBUG -- Cached Version: null
2009-10-12 22:23:35,250 -- DEBUG -- initializing non-lazy collections
2009-10-12 22:23:35,250 -- DEBUG -- resolved object in second-level cache: [com.demo.model.Student#1]
2009-10-12 22:23:35,250 -- DEBUG -- loading entity: [com.demo.model.Student#2]
2009-10-12 22:23:35,250 -- DEBUG -- attempting to resolve: [com.demo.model.Student#2]
2009-10-12 22:23:35,250 -- DEBUG -- Cache lookup: com.demo.model.Student#2
2009-10-12 22:23:35,250 -- DEBUG -- key: com.demo.model.Student#2
2009-10-12 22:23:35,250 -- DEBUG -- com.demo.model.StudentCache: com.demo.model.StudentMemoryStore hit for com.demo.model.Student#2
2009-10-12 22:23:35,250 -- DEBUG -- Cache hit: com.demo.model.Student#2
2009-10-12 22:23:35,250 -- DEBUG -- assembling entity from second-level cache: [com.demo.model.Student#2]
2009-10-12 22:23:35,250 -- DEBUG -- Cached Version: null
2009-10-12 22:23:35,250 -- DEBUG -- initializing non-lazy collections
2009-10-12 22:23:35,250 -- DEBUG -- resolved object in second-level cache: [com.demo.model.Student#2]
2009-10-12 22:23:35,250 -- DEBUG -- commit
2009-10-12 22:23:35,250 -- DEBUG -- automatically flushing session
2009-10-12 22:23:35,250 -- DEBUG -- flushing session
2009-10-12 22:23:35,250 -- DEBUG -- processing flush-time cascades
2009-10-12 22:23:35,250 -- DEBUG -- dirty checking collections
2009-10-12 22:23:35,250 -- DEBUG -- Flushing entities and processing referenced collections
2009-10-12 22:23:35,250 -- DEBUG -- Processing unreferenced collections
2009-10-12 22:23:35,250 -- DEBUG -- Scheduling collection removes/(re)creates/updates
2009-10-12 22:23:35,250 -- DEBUG -- Flushed: 0 insertions, 0 updates, 0 deletions to 2 objects
2009-10-12 22:23:35,250 -- DEBUG -- Flushed: 0 (re)creations, 0 updates, 0 removals to 0 collections
2009-10-12 22:23:35,250 -- DEBUG -- listing entities:
2009-10-12 22:23:35,250 -- DEBUG -- com.demo.model.Student{sex=1, age=21, teacher=null, name=I'am Hibernate, id=1}
2009-10-12 22:23:35,250 -- DEBUG -- com.demo.model.Student{sex=1, age=21, teacher=null, name=I'am Hibernate, id=2}
2009-10-12 22:23:35,250 -- DEBUG -- executing flush
2009-10-12 22:23:35,250 -- DEBUG -- registering flush begin
2009-10-12 22:23:35,250 -- DEBUG -- registering flush end
2009-10-12 22:23:35,250 -- DEBUG -- post flush
2009-10-12 22:23:35,250 -- DEBUG -- before transaction completion
2009-10-12 22:23:35,250 -- DEBUG -- before transaction completion
2009-10-12 22:23:35,250 -- DEBUG -- committed JDBC Connection
2009-10-12 22:23:35,250 -- DEBUG -- after transaction completion
2009-10-12 22:23:35,250 -- DEBUG -- aggressively releasing JDBC connection
2009-10-12 22:23:35,250 -- DEBUG -- releasing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)]
2009-10-12 22:23:35,250 -- DEBUG -- #3 - autoCommit reset back to true
2009-10-12 22:23:35,250 -- DEBUG -- after transaction completion
2009-10-12 22:23:35,250 -- DEBUG -- automatically closing session
2009-10-12 22:23:35,250 -- DEBUG -- closing session
2009-10-12 22:23:35,250 -- DEBUG -- connection already null in cleanup : no action
结果集大小:2
Thread-0 使用时间:0毫秒
2009-10-12 22:23:35,250 -- DEBUG -- Running ShutdownHook
2009-10-12 22:23:35,250 -- INFO -- Shutting down 'pool1' pool immediately [Shutdown Hook]
2009-10-12 22:23:35,250 -- DEBUG -- 000004 (00/02/00) - #0003 removed because of shutdown.
2009-10-12 22:23:35,250 -- DEBUG -- Connection #3 closed
2009-10-12 22:23:35,265 -- DEBUG -- 000004 (00/01/00) - #0002 removed because of shutdown.
2009-10-12 22:23:35,265 -- DEBUG -- Connection #2 closed
2009-10-12 22:23:35,265 -- DEBUG -- 000004 (00/00/00) - #0001 removed because of shutdown.
2009-10-12 22:23:35,265 -- DEBUG -- Connection #1 closed
2009-10-12 22:23:35,265 -- INFO -- 'pool1' pool has been closed down by Shutdown Hook in 15 milliseconds.
2009-10-12 22:23:35,265 -- INFO -- Stopping Prototyper thread
2009-10-12 22:23:35,265 -- INFO -- Stopping HouseKeeper thread

 

 

 

测试:

 

Hibernate: select student0_.id as id0_, student0_.name as name0_, student0_.age as age0_, student0_.sex as sex0_, student0_.id_teacher as id5_0_ from student student0_ where student0_.id<?
结果集大小:0
Thread-0 使用时间:469毫秒

 

hql="from Student where id<600";
Hibernate: select student0_.id as id0_, student0_.name as name0_, student0_.age as age0_, student0_.sex as sex0_, student0_.id_teacher as id5_0_ from student student0_ where student0_.id<600
结果集大小:599
Thread-0 使用时间:172毫秒

 

hql="from Student where id>600 and id<1200";
Hibernate: select student0_.id as id0_, student0_.name as name0_, student0_.age as age0_, student0_.sex as sex0_, student0_.id_teacher as id5_0_ from student student0_ where student0_.id>600 and student0_.id<1200
结果集大小:599
Thread-0 使用时间:141毫秒

 

hql="from Student where id<600";
结果集大小:599
Thread-0 使用时间:78毫秒

 

hql="from Student where id>600 and id<1200";
结果集大小:599
Thread-0 使用时间:31毫秒

评论
添加红包

请填写红包祝福语或标题

个

红包个数最小为10个

元

红包金额最低5元

当前余额3.43元 前往充值 >
需支付：10.00元
成就一亿技术人!
领取后你会自动成为博主和红包主的粉丝 规则
hope_wisdom
发出的红包
实付元
使用余额支付
点击重新获取
扫码支付
钱包余额 0

抵扣说明：

1.余额是钱包充值的虚拟货币，按照1:1的比例进行支付金额的抵扣。
2.余额无法直接购买下载，可以购买VIP、付费专栏及课程。

余额充值