I have been doing posts without much response from anyone. I may have ignored a minor setting that may be taking hours and hours of my time away. Please help me out, otherwise I will be in doldrums. Below is a detailed description of my problem.

The problem I am facing is that logs say transaction successful, but I am not seeing rows created in the database

I have a RequestVO(Parent) class and a Request StatusVO(Child) class.

One Request could have multiple Request Statuses. Therefore I chose unidirectonal many-to-one association mapping from Request Status to Request. Each class has its own individual table with Request Status table that has a foreign key REQUESTID as a column that maps to ID column of Request table.

Request.ID = RequestStatus.REQUESTID
requestVO is a property of type RequestVO in RequestStatusVO class

I am finding a requestVO class by its ID and calling the setter for requestVO in RequestStatusVO class.


Hibernate version:
2.1.6
Mapping documents:

The only mapping that I made is on RequestStatus side as mentioned above is as follows.

RequestStatus.hbm.xml
<many-to-one name="requestVO" class="com.aol.ic.art.data.vo.RequestVO" column="REQUESTID"/>


Code between sessionFactory.openSession() and session.close():


Full stack trace of any exception that occurs:

Name and version of the database you are using:
Oracle 8.1.7
Debug level Hibernate log excerpt:

2004-08-16 20:23:32 DEBUG JDBCTransaction.begin(41) - current autocommit status:false
2004-08-16 20:23:32 INFO TestRequestStatusDAOUtils.testCreateRequestStatus(?) - In testCreateRequestStatus
2004-08-16 20:23:32 DEBUG SessionImpl.doLoadByClass(1982) - loading [com.aol.ic.art.data.vo.RequestVO#28]
2004-08-16 20:23:32 DEBUG SessionImpl.doLoad(2079) - attempting to resolve [com.aol.ic.art.data.vo.RequestVO#28]
2004-08-16 20:23:32 DEBUG SessionImpl.doLoad(2112) - object not resolved in any cache [com.aol.ic.art.data.vo.RequestVO#28]
2004-08-16 20:23:32 DEBUG EntityPersister.load(416) - Materializing entity: [com.aol.ic.art.data.vo.RequestVO#28]
2004-08-16 20:23:32 DEBUG BatcherImpl.logOpenPreparedStatement(196) - about to open: 0 open PreparedStatements, 0 open ResultSets
2004-08-16 20:23:32 DEBUG BatcherImpl.getPreparedStatement(237) - select requestvo0_.ID as ID0_, requestvo0_.REQUESTORDN as REQUESTO2_0_, requestvo0_.CUSTOMERDN as CUSTOMERDN0_, requestvo0_.FULFILLMEN
TBUILDINGDN as FULFILLM4_0_, requestvo0_.FULFILLMENTROOMNUMBER as FULFILLM5_0_, requestvo0_.LASTAPPROVERDN as LASTAPPR6_0_, requestvo0_.NEXTAPPROVERROLEDN as NEXTAPPR7_0_, requestvo0_.TICKETNUMBER as
TICKETNU8_0_, requestvo0_.STATUS as STATUS0_, requestvo0_.TYPE as TYPE0_, requestvo0_.COMMENTS as COMMENTS0_ from REQUEST requestvo0_ where requestvo0_.ID=?
Hibernate: select requestvo0_.ID as ID0_, requestvo0_.REQUESTORDN as REQUESTO2_0_, requestvo0_.CUSTOMERDN as CUSTOMERDN0_, requestvo0_.FULFILLMENTBUILDINGDN as FULFILLM4_0_, requestvo0_.FULFILLMENTROO
MNUMBER as FULFILLM5_0_, requestvo0_.LASTAPPROVERDN as LASTAPPR6_0_, requestvo0_.NEXTAPPROVERROLEDN as NEXTAPPR7_0_, requestvo0_.TICKETNUMBER as TICKETNU8_0_, requestvo0_.STATUS as STATUS0_, requestvo
0_.TYPE as TYPE0_, requestvo0_.COMMENTS as COMMENTS0_ from REQUEST requestvo0_ where requestvo0_.ID=?
2004-08-16 20:23:32 DEBUG BatcherImpl.getPreparedStatement(241) - preparing statement
2004-08-16 20:23:32 DEBUG NullableType.nullSafeSet(46) - binding '28' to parameter: 1
2004-08-16 20:23:32 DEBUG Loader.doQuery(197) - processing result set
2004-08-16 20:23:32 DEBUG Loader.getRow(405) - result row: 28
2004-08-16 20:23:32 DEBUG Loader.loadFromResultSet(536) - Initializing object from ResultSet: 28
2004-08-16 20:23:32 DEBUG Loader.hydrate(605) - Hydrating entity: com.aol.ic.art.data.vo.RequestVO#28
2004-08-16 20:23:32 DEBUG NullableType.nullSafeGet(68) - returning 'requestorDn' as column: REQUESTO2_0_
2004-08-16 20:23:32 DEBUG NullableType.nullSafeGet(68) - returning 'customerDn' as column: CUSTOMERDN0_
2004-08-16 20:23:32 DEBUG NullableType.nullSafeGet(68) - returning '200200' as column: FULFILLM4_0_
2004-08-16 20:23:32 DEBUG NullableType.nullSafeGet(68) - returning 'nextApproverRoleDn' as column: FULFILLM5_0_
2004-08-16 20:23:32 DEBUG NullableType.nullSafeGet(68) - returning 'lastApproverDn' as column: LASTAPPR6_0_
2004-08-16 20:23:32 DEBUG NullableType.nullSafeGet(68) - returning 'fulfillmentBuildingDn' as column: NEXTAPPR7_0_
2004-08-16 20:23:32 DEBUG NullableType.nullSafeGet(68) - returning 'ticketNumber' as column: TICKETNU8_0_
2004-08-16 20:23:32 DEBUG NullableType.nullSafeGet(68) - returning 'OPEN' as column: STATUS0_
2004-08-16 20:23:32 DEBUG NullableType.nullSafeGet(68) - returning 'SOFTWARE' as column: TYPE0_
2004-08-16 20:23:32 DEBUG NullableType.nullSafeGet(68) - returning 'comments' as column: COMMENTS0_
2004-08-16 20:23:32 DEBUG Loader.doQuery(226) - done processing result set (1 rows)
2004-08-16 20:23:32 DEBUG BatcherImpl.logClosePreparedStatement(203) - done closing: 0 open PreparedStatements, 0 open ResultSets
2004-08-16 20:23:32 DEBUG BatcherImpl.closePreparedStatement(261) - closing statement
2004-08-16 20:23:32 DEBUG Loader.doQuery(239) - total objects hydrated: 1
2004-08-16 20:23:32 DEBUG SessionImpl.initializeEntity(2198) - resolving associations for [com.aol.ic.art.data.vo.RequestVO#28]
2004-08-16 20:23:32 DEBUG SessionImpl.getCollection(3929) - creating collection wrapper:[com.aol.ic.art.data.vo.RequestVO.products#28]
2004-08-16 20:23:32 DEBUG SessionImpl.initializeEntity(2222) - done materializing entity [com.aol.ic.art.data.vo.RequestVO#28]
2004-08-16 20:23:32 DEBUG SessionImpl.initializeNonLazyCollections(3112) - initializing non-lazy collections
2004-08-16 20:23:32 INFO TestRequestDAOUtils.testFind(?) - requestorDn.customerDn.comments.200200.nextApproverRoleDn.lastApproverDn.fulfillmentBuildingDn.OPEN.ticketNumber.REQUEST
2004-08-16 20:23:32 INFO TestRequestStatusDAOUtils.testCreateRequestStatus(?) - RequestVO: requestorDn.customerDn.comments.200200.nextApproverRoleDn.lastApproverDn.fulfillmentBuildingDn.OPEN.ticketNu
mber.REQUEST
2004-08-16 20:23:32 INFO TestRequestStatusDAOUtils.testCreateRequestStatus(?) - RequestStatusVO: com.aol.ic.art.data.vo.RequestStatusVO@6bd9e0
2004-08-16 20:23:32 DEBUG SessionImpl.saveOrUpdate(1386) - saveOrUpdate() unsaved instance
2004-08-16 20:23:32 DEBUG BatcherImpl.logOpenPreparedStatement(196) - about to open: 0 open PreparedStatements, 0 open ResultSets
2004-08-16 20:23:32 DEBUG BatcherImpl.getPreparedStatement(237) - select RSTATE_SEQUENCE.nextval from dual
Hibernate: select RSTATE_SEQUENCE.nextval from dual
2004-08-16 20:23:32 DEBUG BatcherImpl.getPreparedStatement(241) - preparing statement
2004-08-16 20:23:32 DEBUG SequenceGenerator.generate(81) - Sequence identifier generated: 16
2004-08-16 20:23:32 DEBUG BatcherImpl.logClosePreparedStatement(203) - done closing: 0 open PreparedStatements, 0 open ResultSets
2004-08-16 20:23:32 DEBUG BatcherImpl.closePreparedStatement(261) - closing statement
2004-08-16 20:23:32 DEBUG SessionImpl.saveWithGeneratedIdentifier(778) - generated identifier: 16
2004-08-16 20:23:32 DEBUG SessionImpl.doSave(825) - saving [com.aol.ic.art.data.vo.RequestStatusVO#16]
2004-08-16 20:23:32 DEBUG HibernateUtil.commitTransaction(?) - Committing database transaction of this thread.
2004-08-16 20:23:32 DEBUG JDBCTransaction.commit(59) - commit
2004-08-16 20:23:32 DEBUG SessionImpl.flushEverything(2242) - flushing session
2004-08-16 20:23:32 DEBUG SessionImpl.flushEntities(2435) - Flushing entities and processing referenced collections
2004-08-16 20:23:32 DEBUG SessionImpl.updateReachableCollection(2880) - Collection found: [com.aol.ic.art.data.vo.RequestVO.products#28], was: [com.aol.ic.art.data.vo.RequestVO.products#28]
2004-08-16 20:23:32 DEBUG SessionImpl.flushCollections(2776) - Processing unreferenced collections
2004-08-16 20:23:32 DEBUG SessionImpl.flushCollections(2790) - Scheduling collection removes/(re)creates/updates
2004-08-16 20:23:32 DEBUG SessionImpl.flushEverything(2266) - Flushed: 1 insertions, 0 updates, 0 deletions to 2 objects
2004-08-16 20:23:32 DEBUG SessionImpl.flushEverything(2271) - Flushed: 0 (re)creations, 0 updates, 0 removals to 1 collections
2004-08-16 20:23:32 DEBUG Printer.toString(75) - listing entities:
2004-08-16 20:23:32 DEBUG Printer.toString(82) - com.aol.ic.art.data.vo.RequestStatusVO{requestVO=RequestVO#28, state=PENDING_APPROVAL, dateStateAttained=16 August 2004 20:23:32, id=16}
2004-08-16 20:23:32 DEBUG Printer.toString(82) - com.aol.ic.art.data.vo.RequestVO{comments=comments, products=uninitialized, fulfillmentRoomNumber=nextApproverRoleDn, customerDn=customerDn, requestTyp
e=SOFTWARE, lastApproverDn=lastApproverDn, fulfillmentBuildingDn=200200, state=OPEN, ticketNumber=ticketNumber, nextApproverRoleDn=fulfillmentBuildingDn, id=28, requestorDn=requestorDn}
2004-08-16 20:23:32 DEBUG SessionImpl.execute(2355) - executing flush
2004-08-16 20:23:32 DEBUG EntityPersister.insert(453) - Inserting entity: [com.aol.ic.art.data.vo.RequestStatusVO#16]
2004-08-16 20:23:32 DEBUG BatcherImpl.logOpenPreparedStatement(196) - about to open: 0 open PreparedStatements, 0 open ResultSets
2004-08-16 20:23:32 DEBUG BatcherImpl.getPreparedStatement(237) - insert into REQUEST_STATE (REQUESTID, STATE, DATE_STATE_ATTAINED, ID) values (?, ?, ?, ?)
Hibernate: insert into REQUEST_STATE (REQUESTID, STATE, DATE_STATE_ATTAINED, ID) values (?, ?, ?, ?)
2004-08-16 20:23:32 DEBUG BatcherImpl.getPreparedStatement(241) - preparing statement
2004-08-16 20:23:32 DEBUG EntityPersister.dehydrate(388) - Dehydrating entity: [com.aol.ic.art.data.vo.RequestStatusVO#16]
2004-08-16 20:23:32 DEBUG NullableType.nullSafeSet(46) - binding '28' to parameter: 1
2004-08-16 20:23:32 DEBUG NullableType.nullSafeSet(46) - binding 'PENDING_APPROVAL' to parameter: 2
2004-08-16 20:23:32 DEBUG NullableType.nullSafeSet(46) - binding '16 August 2004 20:23:32' to parameter: 3
2004-08-16 20:23:32 DEBUG NullableType.nullSafeSet(46) - binding '16' to parameter: 4
2004-08-16 20:23:32 DEBUG BatcherImpl.logClosePreparedStatement(203) - done closing: 0 open PreparedStatements, 0 open ResultSets
2004-08-16 20:23:32 DEBUG BatcherImpl.closePreparedStatement(261) - closing statement
2004-08-16 20:23:32 DEBUG SessionImpl.postFlush(2820) - post flush
2004-08-16 20:23:32 DEBUG SessionImpl.afterTransactionCompletion(585) - transaction completion
2004-08-16 20:23:32 INFO TestRequestStatusDAOUtils.testCreateRequestStatus(?) - After creating requestStatusVO
2004-08-16 20:23:32 INFO TestRequestStatusDAOUtils.testCreateRequestStatus(?) - Saving RequestStatusVO

I am guessing that the below log could be the problem. What does it mean that there are deletions to 2 objects, removals to 1 collections?

[com.aol.ic.art.data.vo.RequestVO.products#28], was: [com.aol.ic.art.data.vo.RequestVO.products#28]
2004-08-16 20:23:32 DEBUG SessionImpl.flushCollections(2776) - Processing unreferenced collections
2004-08-16 20:23:32 DEBUG SessionImpl.flushCollections(2790) - Scheduling collection removes/(re)creates/updates
2004-08-16 20:23:32 DEBUG SessionImpl.flushEverything(2266) - Flushed: 1 insertions, 0 updates, 0 deletions to 2 objects
2004-08-16 20:23:32 DEBUG SessionImpl.flushEverything(2271) - Flushed: 0 (re)creations, 0 updates, 0 removals to 1 collections

It is the damn stupid Oracle database 8.1.7 version that was giving me problems. It works - YOHOOOOOO. thanks all - sorry for the comments during my misery phase