This is a bummer: I am persisting an object using EntityManager.persist() in a transaction which is properly commited.
Later on I try to retrieve that same object from storage using find(). You can imagine my surprise to receive a SerializationException when Hibernate tries to read the ID property of the object it had earlier persisted. The ID property is database (Oracle 10g) type NUMBER(10) generated by Hibernate using hbm2ddl, and its generated value is currently lower than 100 (therefore valid Integer).
Detailed information can be found below:
Hibernate version: Core 3.2.6 GA, Annotations 3.3.1 GA (also tried 3.3.0 GA), EntityManager 3.3.2 GA (also tried 3.3.1 GA)
Name and version of the database you are using: Oracle 10g
Debug level Hibernate log excerpt:
Code:
[2008-05-14 11:15:47,483] DEBUG org.hibernate.jdbc.AbstractBatcher about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
[2008-05-14 11:15:47,483] DEBUG org.hibernate.SQL
select
searchrequ0_.SEARCHID as SEARCHID10_1_,
searchrequ0_.SEARCHALIAS as SEARCHAL2_10_1_,
searchrequ0_.AMOUNTPROCESSED as AMOUNTPR3_10_1_,
searchrequ0_.BLOCKEDNUMBERS as BLOCKEDN4_10_1_,
searchrequ0_.DISPDATE as DISPDATE10_1_,
searchrequ0_.DUPLICATEDREGISTERS as DUPLICAT6_10_1_,
searchrequ0_.FREQUENCYDAYS as FREQUENC7_10_1_,
searchrequ0_.LASTUPDATE as LASTUPDATE10_1_,
searchrequ0_.PORTREGISTERS as PORTREGI9_10_1_,
searchrequ0_.PRIORITY as PRIORITY10_1_,
searchrequ0_.RANGEEND as RANGEEND10_1_,
searchrequ0_.RANGESTART as RANGESTART10_1_,
searchrequ0_.AVAILABLEREPORT as AVAILAB13_10_1_,
searchrequ0_.REQUESTDATE as REQUEST14_10_1_,
searchrequ0_.SCHEDULEDATE as SCHEDUL15_10_1_,
searchrequ0_.SCHEDULEDATEEND as SCHEDUL16_10_1_,
searchrequ0_.SEARCHSTART as SEARCHS17_10_1_,
searchrequ0_.SEARCHTYPE as SEARCHTYPE10_1_,
searchrequ0_.STATUS as STATUS10_1_,
searchrequ0_.USERID as USERID10_1_,
searchprog1_.REQUEST_ID as REQUEST1_7_0_,
searchprog1_.FILES_PROCESSED as FILES2_7_0_,
searchprog1_.TOTAL_RECORDS as TOTAL3_7_0_
from
ESETOOLSEARCH searchrequ0_
left outer join
ESETOOLSEARCH_PROGRESS searchprog1_
on searchrequ0_.SEARCHID=searchprog1_.REQUEST_ID
where
searchrequ0_.SEARCHID=?
[2008-05-14 11:15:47,483] DEBUG org.hibernate.jdbc.AbstractBatcher preparing statement
[2008-05-14 11:15:47,483] DEBUG org.hibernate.type.IntegerType binding '62' to parameter: 1
[2008-05-14 11:15:47,483] DEBUG org.hibernate.jdbc.AbstractBatcher about to open ResultSet (open ResultSets: 0, globally: 0)
[2008-05-14 11:15:47,483] DEBUG org.hibernate.loader.Loader processing result set
[2008-05-14 11:15:47,483] DEBUG org.hibernate.loader.Loader result set row: 0
[2008-05-14 11:15:47,483] DEBUG org.hibernate.type.SerializableType returning null as column: REQUEST1_7_0_
[2008-05-14 11:15:47,483] DEBUG org.hibernate.loader.Loader result row: null, EntityKey[org.venturus.pid.xdr.db.SearchRequest#62]
[2008-05-14 11:15:47,483] DEBUG org.hibernate.loader.Loader Initializing object from ResultSet: [org.venturus.pid.xdr.db.SearchRequest#62]
[2008-05-14 11:15:47,483] DEBUG org.hibernate.persister.entity.AbstractEntityPersister Hydrating entity: [org.venturus.pid.xdr.db.SearchRequest#62]
[2008-05-14 11:15:47,483] DEBUG org.hibernate.type.StringType returning 'testmgr_0' as column: SEARCHAL2_10_1_
[2008-05-14 11:15:47,483] DEBUG org.hibernate.type.IntegerType returning null as column: AMOUNTPR3_10_1_
[2008-05-14 11:15:47,483] DEBUG org.hibernate.type.IntegerType returning null as column: BLOCKEDN4_10_1_
[2008-05-14 11:15:47,483] DEBUG org.hibernate.type.TimestampType returning null as column: DISPDATE10_1_
[2008-05-14 11:15:47,483] DEBUG org.hibernate.type.IntegerType returning null as column: DUPLICAT6_10_1_
[2008-05-14 11:15:47,483] DEBUG org.hibernate.type.IntegerType returning null as column: FREQUENC7_10_1_
[2008-05-14 11:15:47,483] DEBUG org.hibernate.type.TimestampType returning '2008-05-14 11:15:47' as column: LASTUPDATE10_1_
[2008-05-14 11:15:47,483] DEBUG org.hibernate.type.IntegerType returning null as column: PORTREGI9_10_1_
[2008-05-14 11:15:47,483] DEBUG org.hibernate.type.EnumType Returning null as column PRIORITY10_1_
[2008-05-14 11:15:47,483] DEBUG org.hibernate.util.SerializationHelper Starting deserialization of object
[2008-05-14 11:15:47,499] INFO org.hibernate.type.SerializableType could not read column value from result set: SEARCHID10_1_; could not deserialize
[2008-05-14 11:15:47,499] DEBUG org.hibernate.jdbc.AbstractBatcher about to close ResultSet (open ResultSets: 1, globally: 1)
[2008-05-14 11:15:47,499] DEBUG org.hibernate.jdbc.AbstractBatcher about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
[2008-05-14 11:15:47,499] DEBUG org.hibernate.jdbc.AbstractBatcher closing statement
[2008-05-14 11:15:47,499] INFO org.hibernate.event.def.DefaultLoadEventListener Error performing load command
org.hibernate.type.SerializationException: could not deserialize
at org.hibernate.util.SerializationHelper.deserialize(SerializationHelper.java:217)
at org.hibernate.util.SerializationHelper.deserialize(SerializationHelper.java:240)
at org.hibernate.type.SerializableType.fromBytes(SerializableType.java:82)
at org.hibernate.type.SerializableType.get(SerializableType.java:39)
at org.hibernate.type.NullableType.nullSafeGet(NullableType.java:163)
at org.hibernate.type.NullableType.nullSafeGet(NullableType.java:154)
at org.hibernate.type.ManyToOneType.hydrate(ManyToOneType.java:103)
at org.hibernate.persister.entity.AbstractEntityPersister.hydrate(AbstractEntityPersister.java:2101)
at org.hibernate.loader.Loader.loadFromResultSet(Loader.java:1380)
at org.hibernate.loader.Loader.instanceNotYetLoaded(Loader.java:1308)
at org.hibernate.loader.Loader.getRow(Loader.java:1206)
at org.hibernate.loader.Loader.getRowFromResultSet(Loader.java:580)
at org.hibernate.loader.Loader.doQuery(Loader.java:701)
at org.hibernate.loader.Loader.doQueryAndInitializeNonLazyCollections(Loader.java:236)
at org.hibernate.loader.Loader.loadEntity(Loader.java:1860)
at org.hibernate.loader.entity.AbstractEntityLoader.load(AbstractEntityLoader.java:48)
at org.hibernate.loader.entity.AbstractEntityLoader.load(AbstractEntityLoader.java:42)
at org.hibernate.persister.entity.AbstractEntityPersister.load(AbstractEntityPersister.java:3049)
at org.hibernate.event.def.DefaultLoadEventListener.loadFromDatasource(DefaultLoadEventListener.java:399)
at org.hibernate.event.def.DefaultLoadEventListener.doLoad(DefaultLoadEventListener.java:375)
at org.hibernate.event.def.DefaultLoadEventListener.load(DefaultLoadEventListener.java:139)
at org.hibernate.event.def.DefaultLoadEventListener.onLoad(DefaultLoadEventListener.java:98)
at org.hibernate.impl.SessionImpl.fireLoad(SessionImpl.java:878)
at org.hibernate.impl.SessionImpl.immediateLoad(SessionImpl.java:836)
at org.hibernate.proxy.AbstractLazyInitializer.initialize(AbstractLazyInitializer.java:66)
at org.hibernate.proxy.AbstractLazyInitializer.getImplementation(AbstractLazyInitializer.java:111)
at org.hibernate.proxy.pojo.cglib.CGLIBLazyInitializer.invoke(CGLIBLazyInitializer.java:150)
at org.venturus.pid.xdr.db.SearchRequest$$EnhancerByCGLIB$$437300d.setStatus(<generated>)
at org.venturus.pid.xdr.db.business.SearchRequestService.updateStatus(SearchRequestService.java:116)
at org.venturus.pid.xdr.searchmgr.listeners.LifecycleSearchListener.started(LifecycleSearchListener.java:83)
at org.venturus.pid.xdr.search.AbstractSearchRunnable.fireStarted(AbstractSearchRunnable.java:85)
at org.venturus.pid.xdr.search.SearchEngine.run(SearchEngine.java:23)
at java.lang.Thread.run(Unknown Source)
Caused by: java.io.EOFException
at java.io.ObjectInputStream$PeekInputStream.readFully(Unknown Source)
at java.io.ObjectInputStream$BlockDataInputStream.readShort(Unknown Source)
at java.io.ObjectInputStream.readStreamHeader(Unknown Source)
at java.io.ObjectInputStream.<init>(Unknown Source)
at org.hibernate.util.SerializationHelper$CustomObjectInputStream.<init>(SerializationHelper.java:252)
at org.hibernate.util.SerializationHelper.deserialize(SerializationHelper.java:209)
... 32 more
The two most important pieces in this piece of logging are: a query that is successfully executed and this line:
INFO org.hibernate.type.SerializableType could not read column value from result set: SEARCHID10_1_This column had the same value as the parameter that was passed in: 62. It is declared in my entity class as:
Code:
@Id
@Column(name = "SEARCHID")
@SequenceGenerator(name = "SearchSequence", sequenceName = "SEQ_ESETOOLSEARCH")
@GeneratedValue(generator = "SearchSequence", strategy = GenerationType.AUTO)
private Integer id;
This entity and all of its properties are serializable.
Anyone has a clue about what could be going on here? This is driving me nuts.