Using Oracle 10g, Hibernate versions / settings:
<hibernate.entitymanager.version>3.3.1.ga</hibernate.entitymanager.version>
<hibernate.version>3.2.5.ga</hibernate.version> <hibernate.dialect>org.hibernate.dialect.Oracle10gDialect</hibernate.dialect>
<jdbc.driverClassName>oracle.jdbc.OracleDriver</jdbc.driverClassName>
I have a JPA entity "CachedMessage" which has a CLOB field message. I have defined it to be lazy fetched:
Code:
@Basic(fetch=FetchType.LAZY)
@Lob @Column(nullable = false)
public String getMessage() {
return message;
}
I search for the correct entity using org.springframework.orm.jpa.JpaTemplate.findByNamedParameters("select CachedMessage c where....", params) and use the entity
Code:
CachedMessage c = findCachedMessage(...);
String mess = c.getMessage();
log.debug("beginning of message=" + mess.substring(0, Math.min(mess.length() -1, 10000)));
Looking at the logs, it seems that the clob is not lazy loaded
Code:
DEBUG - com.foo.fooProject.service.impl.MessageCacheServiceImpl.getCachedMessagebyType(25) | searching with criteria: QueryCriteria, field=messageTypeCode
, op==, value=5
DEBUG - org.hibernate.hql.ast.QueryTranslatorImpl.parse(246) | parse() - HQL: SELECT e FROM com.foo.fooProject.model.CachedMessage e where e.messageTypeCo
de=:parameter1
DEBUG - org.hibernate.hql.ast.QueryTranslatorImpl.showHqlAst(266) | --- HQL AST ---
\-[QUERY] 'query'
+-[SELECT_FROM] 'SELECT_FROM'
| +-[FROM] 'FROM'
| | \-[RANGE] 'RANGE'
| | +-[DOT] '.'
| | | +-[DOT] '.'
| | | | +-[DOT] '.'
| | | | | +-[DOT] '.'
| | | | | | +-[IDENT] 'com'
| | | | | | \-[IDENT] 'foo'
| | | | | \-[IDENT] 'fooProject'
| | | | \-[IDENT] 'model'
| | | \-[IDENT] 'CachedMessage'
| | \-[ALIAS] 'e'
| \-[SELECT] 'SELECT'
| \-[IDENT] 'e'
\-[WHERE] 'where'
\-[EQ] '='
+-[DOT] '.'
| +-[IDENT] 'e'
| \-[IDENT] 'messageTypeCode'
\-[COLON] ':'
\-[IDENT] 'parameter1'
DEBUG - org.hibernate.hql.ast.ErrorCounter.throwQueryException(68) | throwQueryException() : no errors
DEBUG - org.hibernate.hql.antlr.HqlSqlBaseWalker.beforeStatement(111) | select << begin [level=1, statement=select]
DEBUG - org.hibernate.hql.ast.tree.FromElement.doInitialize(108) | FromClause{level=1} : com.foo.fooProject.model.CachedMessage (e) -> cachedmess0_
DEBUG - org.hibernate.hql.ast.tree.FromReferenceNode.setResolved(51) | Resolved : e -> cachedmess0_.id
DEBUG - org.hibernate.hql.ast.tree.FromReferenceNode.setResolved(51) | Resolved : e -> cachedmess0_.id
DEBUG - org.hibernate.hql.ast.tree.DotNode.getDataType(568) | getDataType() : messageTypeCode -> org.hibernate.type.IntegerType@1b67d6a
DEBUG - org.hibernate.hql.ast.tree.FromReferenceNode.setResolved(51) | Resolved : e.messageTypeCode -> cachedmess0_.MESSAGE_TYPE
DEBUG - org.hibernate.hql.antlr.HqlSqlBaseWalker.beforeStatementCompletion(117) | select : finishing up [level=1, statement=select]
DEBUG - org.hibernate.hql.ast.HqlSqlWalker.processQuery(509) | processQuery() : ( SELECT ( {select clause} cachedmess0_.id ) ( FromClause{level=1} MESSAGE
_CACHE cachedmess0_ ) ( where ( = ( cachedmess0_.MESSAGE_TYPE cachedmess0_.id messageTypeCode ) ? ) ) )
DEBUG - org.hibernate.hql.ast.util.JoinProcessor.addJoinNodes(148) | Using FROM fragment [MESSAGE_CACHE cachedmess0_]
DEBUG - org.hibernate.hql.antlr.HqlSqlBaseWalker.afterStatementCompletion(123) | select >> end [level=1, statement=select]
DEBUG - org.hibernate.hql.ast.QueryTranslatorImpl.analyze(232) | --- SQL AST ---
\-[SELECT] QueryNode: 'SELECT' querySpaces (MESSAGE_CACHE)
+-[SELECT_CLAUSE] SelectClause: '{select clause}'
| +-[ALIAS_REF] IdentNode: 'cachedmess0_.id as id3_' {alias=e, className=com.foo.fooProject.model.CachedMessage, tableAlias=cachedmess0_}
| \-[SQL_TOKEN] SqlFragment: 'cachedmess0_.LAST_MODIFIED as LAST2_3_, cachedmess0_.message as message3_, cachedmess0_.MESSAGE_TYPE as MESSAGE4_3_'
+-[FROM] FromClause: 'FROM' FromClause{level=1, fromElementCounter=1, fromElements=1, fromElementByClassAlias=[e], fromElementByTableAlias=[cachedmess0
_], fromElementsByPath=[], collectionJoinFromElementsByPath=[], impliedElements=[]}
| \-[FROM_FRAGMENT] FromElement: 'MESSAGE_CACHE cachedmess0_' FromElement{explicit,not a collection join,not a fetch join,fetch non-lazy properties,cl
assAlias=e,role=null,tableName=MESSAGE_CACHE,tableAlias=cachedmess0_,origin=null,colums={,className=com.foo.fooProject.model.CachedMessage}}
\-[WHERE] SqlNode: 'where'
\-[EQ] BinaryLogicOperatorNode: '='
+-[DOT] DotNode: 'cachedmess0_.MESSAGE_TYPE' {propertyName=messageTypeCode,dereferenceType=4,propertyPath=messageTypeCode,path=e.messageTypeCode,
tableAlias=cachedmess0_,className=com.foo.fooProject.model.CachedMessage,classAlias=e}
| +-[ALIAS_REF] IdentNode: 'cachedmess0_.id' {alias=e, className=com.foo.fooProject.model.CachedMessage, tableAlias=cachedmess0_}
| \-[IDENT] IdentNode: 'messageTypeCode' {originalText=messageTypeCode}
\-[NAMED_PARAM] ParameterNode: '?' {name=parameter1, expectedType=org.hibernate.type.IntegerType@1b67d6a}
DEBUG - org.hibernate.hql.ast.ErrorCounter.throwQueryException(68) | throwQueryException() : no errors
DEBUG - org.hibernate.hql.ast.QueryTranslatorImpl.generate(216) | HQL: SELECT e FROM com.foo.fooProject.model.CachedMessage e where e.messageTypeCode=:par
ameter1
DEBUG - org.hibernate.hql.ast.QueryTranslatorImpl.generate(217) | SQL: select cachedmess0_.id as id3_, cachedmess0_.LAST_MODIFIED as LAST2_3_, cachedmess0_
.message as message3_, cachedmess0_.MESSAGE_TYPE as MESSAGE4_3_ from MESSAGE_CACHE cachedmess0_ where cachedmess0_.MESSAGE_TYPE=?
DEBUG - org.hibernate.hql.ast.ErrorCounter.throwQueryException(68) | throwQueryException() : no errors
DEBUG - org.hibernate.jdbc.AbstractBatcher.logOpenPreparedStatement(366) | about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
DEBUG - org.hibernate.jdbc.AbstractBatcher.log(401) | select cachedmess0_.id as id3_, cachedmess0_.LAST_MODIFIED as LAST2_3_, cachedmess0_.message as messa
ge3_, cachedmess0_.MESSAGE_TYPE as MESSAGE4_3_ from MESSAGE_CACHE cachedmess0_ where cachedmess0_.MESSAGE_TYPE=?
DEBUG - org.hibernate.jdbc.AbstractBatcher.logOpenResults(382) | about to open ResultSet (open ResultSets: 0, globally: 0)
DEBUG - org.hibernate.loader.Loader.getRow(1173) | result row: EntityKey[com.foo.fooProject.model.CachedMessage#2100]
DEBUG - org.hibernate.jdbc.AbstractBatcher.logCloseResults(389) | about to close ResultSet (open ResultSets: 1, globally: 1)
DEBUG - org.hibernate.jdbc.AbstractBatcher.logClosePreparedStatement(374) | about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
DEBUG - org.hibernate.engine.TwoPhaseLoad.initializeEntity(107) | resolving associations for [com.foo.fooProject.model.CachedMessage#2100]
DEBUG - org.hibernate.engine.TwoPhaseLoad.initializeEntity(206) | done materializing entity [com.foo.fooProject.model.CachedMessage#2100]
DEBUG - org.hibernate.engine.StatefulPersistenceContext.initializeNonLazyCollections(790) | initializing non-lazy collections
DEBUG - org.hibernate.transaction.JDBCTransaction.commit(103) | commit
DEBUG - org.hibernate.event.def.AbstractFlushingEventListener.prepareEntityFlushes(111) | processing flush-time cascades
DEBUG - org.hibernate.event.def.AbstractFlushingEventListener.prepareCollectionFlushes(154) | dirty checking collections
DEBUG - org.hibernate.event.def.AbstractFlushingEventListener.flushEverythingToExecutions(85) | Flushed: 0 insertions, 0 updates, 0 deletions to 1 objects
DEBUG - org.hibernate.event.def.AbstractFlushingEventListener.flushEverythingToExecutions(91) | Flushed: 0 (re)creations, 0 updates, 0 removals to 0 collec
tions
DEBUG - org.hibernate.pretty.Printer.toString(83) | listing entities:
DEBUG - org.hibernate.pretty.Printer.toString(90) | com.foo.fooProject.model.CachedMessage{messageTypeCode=5, message=<LamDataResponse xmlns="http://www.
foo.com/fooProject/schemas"><timestamp><utc>2008-01-18T16:55:45Z</utc><localtime>2008-01-18T18:55:45+02:00</localtime></timestamp><lamdynamicdata /></LamDa
taResponse>, lastModified=2008-01-18 18:55:45, id=2100}
DEBUG - org.hibernate.transaction.JDBCTransaction.commit(116) | committed JDBC Connection
DEBUG - org.hibernate.jdbc.ConnectionManager.aggressiveRelease(404) | aggressively releasing JDBC connection
DEBUG - org.hibernate.jdbc.ConnectionManager.closeConnection(441) | releasing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open ResultSets:
0, globally: 0)]
DEBUG - com.foo.fooProject.App.foo(75) | beginning of message=<Response xmlns="http://www.foo.com/fooProject/schemas"><timestamp><utc>2008-01-18T1
6:55:45Z</utc><localtime>2008-01-18T18:55:45+02:00</localtime></timestamp><data /></Response