exception when loading dependent objects
mmarcom May 18, 2006 9:14 AMhi all,
i have written an app which contains 3 entity EJBs
- Expense
- Product
- Item
Expense has a 1ToMany CMR with Item, here's the code
package com.myapp.econtrol.entities; import java.io.Serializable; import java.sql.Date; import java.util.ArrayList; import java.util.Collection; import javax.persistence.*; import org.jboss.seam.annotations.Name; import org.jboss.seam.annotations.Scope; @Entity // @Name("expense") @Table(name = "expense") @NamedQueries({ @NamedQuery ( name="findExpenseByDate", query="SELECT e FROM Expense e where e.date < :expenseDate" ), @NamedQuery ( name="findAllExpenses", query="FROM Expense e" ), @NamedQuery ( name="findExpenseBySite", query="SELECT e FROM Expense e where e.site = :site" ) }) public class Expense implements Serializable { private int id; private String site; private Date date; private Collection<Item> items = new ArrayList<Item>(); public Expense () { } public Expense (String site, Date date, Collection items) { this.site = site; this.date = date; this.items = items; } @Id @GeneratedValue public int getId () { return id; } public void setId (int id) { this.id = id; } public String getSite () { return site; } public void setSite (String site) { this.site = site; } public Date getDate() { return date; } public void setDate (Date date) { this.date = date; } @OneToMany(cascade=(CascadeType.ALL)) public Collection<Item> getItems() { return items; } public void setItems(Collection<Item> items) { this.items = items; }
I have a JUnit tests which contains following code:
Collection expenses = sessionFacade.getExpenseBySite("Sainsbury"); assertEquals("We should have 1 expense here..", 1, expenses.size()); Expense exp = (Expense)(expenses.iterator().next()); Collection _items = exp.getItems(); assertEquals("We should have 2 items in the expense", 2, _items.size());
When i run my junit tests i get the following exception:
2006-05-18 14:12:44,078 ERROR org.hibernate.LazyInitializationException [main] - failed to lazily initialize a collection of role: com.myapp.econtrol.entities.Expense.items, no session or session was closed org.hibernate.LazyInitializationException: failed to lazily initialize a collection of role: com.myapp.econtrol.entities.Expense.items, no session or session was closed at org.hibernate.collection.AbstractPersistentCollection.throwLazyInitializationException(AbstractPersistentCollection.java:358) at org.hibernate.collection.AbstractPersistentCollection.throwLazyInitializationExceptionIfNotConnected(AbstractPersistentCollection.java:350) at org.hibernate.collection.AbstractPersistentCollection.readSize(AbstractPersistentCollection.java:97) at org.hibernate.collection.PersistentBag.size(PersistentBag.java:222) at example1.TestExpense.testFindExpenseBySite(TestExpense.java:113) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(Unknown Source) at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source) at java.lang.reflect.Method.invoke(Unknown Source) at org.testng.internal.MethodHelper.invokeMethod(MethodHelper.java:552) at org.testng.internal.Invoker.invokeMethod(Invoker.java:407) at org.testng.internal.Invoker.invokeTestMethods(Invoker.java:778) at org.testng.internal.TestMethodWorker.run(TestMethodWorker.java:105) at org.testng.TestRunner.privateRun(TestRunner.java:682) at org.testng.TestRunner.run(TestRunner.java:566) at org.testng.SuiteRunner.privateRun(SuiteRunner.java:220) at org.testng.SuiteRunner.run(SuiteRunner.java:146) at org.testng.TestNG.createAndRunSuiteRunners(TestNG.java:713) at org.testng.TestNG.runSuitesLocally(TestNG.java:676) at org.apache.maven.surefire.testng.TestNGExecutor.executeTestNG(TestNGExecutor.java:64) at org.apache.maven.surefire.testng.TestNGXmlTestSuite.execute(TestNGXmlTestSuite.java:75) at org.apache.maven.surefire.Surefire.run(Surefire.java:129) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(Unknown Source) at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source) at java.lang.reflect.Method.invoke(Unknown Source) at org.apache.maven.surefire.booter.SurefireBooter.runSuitesInProcess(SurefireBooter.java:220) at org.apache.maven.surefire.booter.SurefireBooter.main(SurefireBooter.java:733)
can anyone tell me wha'ts the problem? did i forgot to specify additional attributes in hte CMR annotation?
i m currently running tests using jboss-embeddable-alpha5...
here's an excerpt of jboss logs
Persisting expense 2006-05-18 14:12:43,953 DEBUG org.hibernate.jdbc.JDBCContext [main] - successfully registered Synchronization 2006-05-18 14:12:43,953 DEBUG org.hibernate.impl.SessionImpl [main] - opened session at timestamp: 4702035820220416 2006-05-18 14:12:43,953 DEBUG org.hibernate.engine.IdentifierValue [main] - id unsaved-value: 0 2006-05-18 14:12:43,953 DEBUG org.hibernate.event.def.AbstractSaveEventListener [main] - transient instance of: com.myapp.econtrol.entities.Expense 2006-05-18 14:12:43,953 DEBUG org.hibernate.event.def.DefaultPersistEventListener [main] - saving transient instance 2006-05-18 14:12:43,968 DEBUG org.hibernate.event.def.AbstractSaveEventListener [main] - saving [com.myapp.econtrol.entities.Expense#<null>] 2006-05-18 14:12:43,968 DEBUG org.hibernate.event.def.AbstractSaveEventListener [main] - executing insertions 2006-05-18 14:12:43,968 DEBUG org.hibernate.engine.Cascade [main] - processing cascade ACTION_PERSIST for: com.myapp.econtrol.entities.Expense 2006-05-18 14:12:43,968 DEBUG org.hibernate.engine.Cascade [main] - done processing cascade ACTION_PERSIST for: com.myapp.econtrol.entities.Expense 2006-05-18 14:12:43,968 DEBUG org.hibernate.event.def.WrapVisitor [main] - Wrapped collection in role: com.myapp.econtrol.entities.Expense.items 2006-05-18 14:12:43,984 DEBUG org.hibernate.persister.entity.AbstractEntityPersister [main] - Inserting entity: com.myapp.econtrol.entities.Expense (native id) 2006-05-18 14:12:43,984 DEBUG org.hibernate.jdbc.AbstractBatcher [main] - about to open PreparedStatement (open PreparedStatements: 0, globally: 0) 2006-05-18 14:12:43,984 DEBUG org.hibernate.jdbc.ConnectionManager [main] - opening JDBC connection 2006-05-18 14:12:43,984 DEBUG org.hibernate.SQL [main] - insert into expense (site, date, id) values (?, ?, null) 2006-05-18 14:12:43,984 DEBUG org.hibernate.jdbc.AbstractBatcher [main] - preparing statement 2006-05-18 14:12:43,984 DEBUG org.hibernate.persister.entity.AbstractEntityPersister [main] - Dehydrating entity: [com.myapp.econtrol.entities.Expense#<null>] 2006-05-18 14:12:43,984 DEBUG org.hibernate.type.StringType [main] - binding 'Sainsbury' to parameter: 1 2006-05-18 14:12:43,984 DEBUG org.hibernate.type.DateType [main] - binding '18 May 2006' to parameter: 2 2006-05-18 14:12:44,015 DEBUG org.hibernate.jdbc.AbstractBatcher [main] - about to close PreparedStatement (open PreparedStatements: 1, globally: 1) 2006-05-18 14:12:44,015 DEBUG org.hibernate.jdbc.AbstractBatcher [main] - closing statement 2006-05-18 14:12:44,015 DEBUG org.hibernate.jdbc.ConnectionManager [main] - aggressively releasing JDBC connection 2006-05-18 14:12:44,015 DEBUG org.hibernate.jdbc.ConnectionManager [main] - releasing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)] 2006-05-18 14:12:44,015 DEBUG org.hibernate.jdbc.AbstractBatcher [main] - about to open PreparedStatement (open PreparedStatements: 0, globally: 0) 2006-05-18 14:12:44,015 DEBUG org.hibernate.jdbc.ConnectionManager [main] - opening JDBC connection 2006-05-18 14:12:44,015 DEBUG org.hibernate.SQL [main] - call identity() 2006-05-18 14:12:44,015 DEBUG org.hibernate.jdbc.AbstractBatcher [main] - preparing statement 2006-05-18 14:12:44,015 DEBUG org.hibernate.id.IdentifierGeneratorFactory [main] - Natively generated identity: 1 2006-05-18 14:12:44,015 DEBUG org.hibernate.jdbc.AbstractBatcher [main] - about to close PreparedStatement (open PreparedStatements: 1, globally: 1) 2006-05-18 14:12:44,015 DEBUG org.hibernate.jdbc.AbstractBatcher [main] - closing statement 2006-05-18 14:12:44,015 DEBUG org.hibernate.jdbc.ConnectionManager [main] - aggressively releasing JDBC connection 2006-05-18 14:12:44,015 DEBUG org.hibernate.jdbc.ConnectionManager [main] - releasing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)] 2006-05-18 14:12:44,015 DEBUG org.hibernate.engine.Cascade [main] - processing cascade ACTION_PERSIST for: com.myapp.econtrol.entities.Expense 2006-05-18 14:12:44,015 DEBUG org.hibernate.engine.Cascade [main] - cascade ACTION_PERSIST for collection: com.myapp.econtrol.entities.Expense.items 2006-05-18 14:12:44,015 DEBUG org.hibernate.engine.CascadingAction [main] - cascading to persist: com.myapp.econtrol.entities.Item 2006-05-18 14:12:44,015 DEBUG org.hibernate.engine.IdentifierValue [main] - id unsaved-value: 0 2006-05-18 14:12:44,015 DEBUG org.hibernate.event.def.AbstractSaveEventListener [main] - transient instance of: com.myapp.econtrol.entities.Item 2006-05-18 14:12:44,015 DEBUG org.hibernate.event.def.DefaultPersistEventListener [main] - saving transient instance 2006-05-18 14:12:44,015 DEBUG org.hibernate.event.def.AbstractSaveEventListener [main] - saving [com.myapp.econtrol.entities.Item#<null>] 2006-05-18 14:12:44,015 DEBUG org.hibernate.event.def.AbstractSaveEventListener [main] - executing insertions 2006-05-18 14:12:44,015 DEBUG org.hibernate.persister.entity.AbstractEntityPersister [main] - Inserting entity: com.myapp.econtrol.entities.Item (native id) 2006-05-18 14:12:44,015 DEBUG org.hibernate.jdbc.AbstractBatcher [main] - about to open PreparedStatement (open PreparedStatements: 0, globally: 0) 2006-05-18 14:12:44,015 DEBUG org.hibernate.jdbc.ConnectionManager [main] - opening JDBC connection 2006-05-18 14:12:44,015 DEBUG org.hibernate.SQL [main] - insert into item (price, name, id) values (?, ?, null) 2006-05-18 14:12:44,015 DEBUG org.hibernate.jdbc.AbstractBatcher [main] - preparing statement 2006-05-18 14:12:44,015 DEBUG org.hibernate.persister.entity.AbstractEntityPersister [main] - Dehydrating entity: [com.myapp.econtrol.entities.Item#<null>] 2006-05-18 14:12:44,015 DEBUG org.hibernate.type.DoubleType [main] - binding '1.75' to parameter: 1 2006-05-18 14:12:44,015 DEBUG org.hibernate.type.StringType [main] - binding 'Banana' to parameter: 2 2006-05-18 14:12:44,015 DEBUG org.hibernate.jdbc.AbstractBatcher [main] - about to close PreparedStatement (open PreparedStatements: 1, globally: 1) 2006-05-18 14:12:44,015 DEBUG org.hibernate.jdbc.AbstractBatcher [main] - closing statement 2006-05-18 14:12:44,015 DEBUG org.hibernate.jdbc.ConnectionManager [main] - aggressively releasing JDBC connection 2006-05-18 14:12:44,015 DEBUG org.hibernate.jdbc.ConnectionManager [main] - releasing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)] 2006-05-18 14:12:44,015 DEBUG org.hibernate.jdbc.AbstractBatcher [main] - about to open PreparedStatement (open PreparedStatements: 0, globally: 0) 2006-05-18 14:12:44,015 DEBUG org.hibernate.jdbc.ConnectionManager [main] - opening JDBC connection 2006-05-18 14:12:44,015 DEBUG org.hibernate.SQL [main] - call identity() 2006-05-18 14:12:44,015 DEBUG org.hibernate.jdbc.AbstractBatcher [main] - preparing statement 2006-05-18 14:12:44,015 DEBUG org.hibernate.id.IdentifierGeneratorFactory [main] - Natively generated identity: 1 2006-05-18 14:12:44,015 DEBUG org.hibernate.jdbc.AbstractBatcher [main] - about to close PreparedStatement (open PreparedStatements: 1, globally: 1) 2006-05-18 14:12:44,015 DEBUG org.hibernate.jdbc.AbstractBatcher [main] - closing statement 2006-05-18 14:12:44,015 DEBUG org.hibernate.jdbc.ConnectionManager [main] - aggressively releasing JDBC connection 2006-05-18 14:12:44,015 DEBUG org.hibernate.jdbc.ConnectionManager [main] - releasing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)] 2006-05-18 14:12:44,015 DEBUG org.hibernate.engine.CascadingAction [main] - cascading to persist: com.myapp.econtrol.entities.Item 2006-05-18 14:12:44,015 DEBUG org.hibernate.engine.IdentifierValue [main] - id unsaved-value: 0 2006-05-18 14:12:44,015 DEBUG org.hibernate.event.def.AbstractSaveEventListener [main] - transient instance of: com.myapp.econtrol.entities.Item 2006-05-18 14:12:44,015 DEBUG org.hibernate.event.def.DefaultPersistEventListener [main] - saving transient instance 2006-05-18 14:12:44,015 DEBUG org.hibernate.event.def.AbstractSaveEventListener [main] - saving [com.myapp.econtrol.entities.Item#<null>] 2006-05-18 14:12:44,015 DEBUG org.hibernate.event.def.AbstractSaveEventListener [main] - executing insertions 2006-05-18 14:12:44,015 DEBUG org.hibernate.persister.entity.AbstractEntityPersister [main] - Inserting entity: com.myapp.econtrol.entities.Item (native id) 2006-05-18 14:12:44,015 DEBUG org.hibernate.jdbc.AbstractBatcher [main] - about to open PreparedStatement (open PreparedStatements: 0, globally: 0) 2006-05-18 14:12:44,015 DEBUG org.hibernate.jdbc.ConnectionManager [main] - opening JDBC connection 2006-05-18 14:12:44,015 DEBUG org.hibernate.SQL [main] - insert into item (price, name, id) values (?, ?, null) 2006-05-18 14:12:44,015 DEBUG org.hibernate.jdbc.AbstractBatcher [main] - preparing statement 2006-05-18 14:12:44,015 DEBUG org.hibernate.persister.entity.AbstractEntityPersister [main] - Dehydrating entity: [com.myapp.econtrol.entities.Item#<null>] 2006-05-18 14:12:44,015 DEBUG org.hibernate.type.DoubleType [main] - binding '0.75' to parameter: 1 2006-05-18 14:12:44,015 DEBUG org.hibernate.type.StringType [main] - binding 'IceCream' to parameter: 2 2006-05-18 14:12:44,015 DEBUG org.hibernate.jdbc.AbstractBatcher [main] - about to close PreparedStatement (open PreparedStatements: 1, globally: 1) 2006-05-18 14:12:44,015 DEBUG org.hibernate.jdbc.AbstractBatcher [main] - closing statement 2006-05-18 14:12:44,015 DEBUG org.hibernate.jdbc.ConnectionManager [main] - aggressively releasing JDBC connection 2006-05-18 14:12:44,015 DEBUG org.hibernate.jdbc.ConnectionManager [main] - releasing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)] 2006-05-18 14:12:44,015 DEBUG org.hibernate.jdbc.AbstractBatcher [main] - about to open PreparedStatement (open PreparedStatements: 0, globally: 0) 2006-05-18 14:12:44,015 DEBUG org.hibernate.jdbc.ConnectionManager [main] - opening JDBC connection 2006-05-18 14:12:44,015 DEBUG org.hibernate.SQL [main] - call identity() 2006-05-18 14:12:44,015 DEBUG org.hibernate.jdbc.AbstractBatcher [main] - preparing statement 2006-05-18 14:12:44,015 DEBUG org.hibernate.id.IdentifierGeneratorFactory [main] - Natively generated identity: 2 2006-05-18 14:12:44,015 DEBUG org.hibernate.jdbc.AbstractBatcher [main] - about to close PreparedStatement (open PreparedStatements: 1, globally: 1) 2006-05-18 14:12:44,015 DEBUG org.hibernate.jdbc.AbstractBatcher [main] - closing statement 2006-05-18 14:12:44,015 DEBUG org.hibernate.jdbc.ConnectionManager [main] - aggressively releasing JDBC connection 2006-05-18 14:12:44,015 DEBUG org.hibernate.jdbc.ConnectionManager [main] - releasing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)] 2006-05-18 14:12:44,015 DEBUG org.hibernate.engine.Cascade [main] - done cascade ACTION_PERSIST for collection: com.myapp.econtrol.entities.Expense.items 2006-05-18 14:12:44,015 DEBUG org.hibernate.engine.Cascade [main] - done processing cascade ACTION_PERSIST for: com.myapp.econtrol.entities.Expense Expense persisted.. 2006-05-18 14:12:44,015 DEBUG org.hibernate.transaction.CacheSynchronization [main] - transaction before completion callback 2006-05-18 14:12:44,015 DEBUG org.hibernate.transaction.CacheSynchronization [main] - automatically flushing session 2006-05-18 14:12:44,015 DEBUG org.hibernate.impl.SessionImpl [main] - automatically flushing session 2006-05-18 14:12:44,015 DEBUG org.hibernate.event.def.AbstractFlushingEventListener [main] - flushing session 2006-05-18 14:12:44,015 DEBUG org.hibernate.event.def.AbstractFlushingEventListener [main] - processing flush-time cascades 2006-05-18 14:12:44,015 DEBUG org.hibernate.engine.Cascade [main] - processing cascade ACTION_PERSIST_ON_FLUSH for: com.myapp.econtrol.entities.Expense 2006-05-18 14:12:44,015 DEBUG org.hibernate.engine.Cascade [main] - cascade ACTION_PERSIST_ON_FLUSH for collection: com.myapp.econtrol.entities.Expense.items 2006-05-18 14:12:44,015 DEBUG org.hibernate.engine.CascadingAction [main] - cascading to persistOnFlush: com.myapp.econtrol.entities.Item 2006-05-18 14:12:44,015 DEBUG org.hibernate.event.def.AbstractSaveEventListener [main] - persistent instance of: com.myapp.econtrol.entities.Item 2006-05-18 14:12:44,015 DEBUG org.hibernate.event.def.DefaultPersistEventListener [main] - ignoring persistent instance 2006-05-18 14:12:44,031 DEBUG org.hibernate.engine.CascadingAction [main] - cascading to persistOnFlush: com.myapp.econtrol.entities.Item 2006-05-18 14:12:44,031 DEBUG org.hibernate.event.def.AbstractSaveEventListener [main] - persistent instance of: com.myapp.econtrol.entities.Item 2006-05-18 14:12:44,031 DEBUG org.hibernate.event.def.DefaultPersistEventListener [main] - ignoring persistent instance 2006-05-18 14:12:44,031 DEBUG org.hibernate.engine.Cascade [main] - done cascade ACTION_PERSIST_ON_FLUSH for collection: com.myapp.econtrol.entities.Expense.items 2006-05-18 14:12:44,031 DEBUG org.hibernate.engine.Cascade [main] - done processing cascade ACTION_PERSIST_ON_FLUSH for: com.myapp.econtrol.entities.Expense 2006-05-18 14:12:44,031 DEBUG org.hibernate.event.def.AbstractFlushingEventListener [main] - dirty checking collections 2006-05-18 14:12:44,031 DEBUG org.hibernate.event.def.AbstractFlushingEventListener [main] - Flushing entities and processing referenced collections 2006-05-18 14:12:44,031 DEBUG org.hibernate.engine.Collections [main] - Collection found: [com.myapp.econtrol.entities.Expense.items#1], was: [<unreferenced>] (initialized) 2006-05-18 14:12:44,031 DEBUG org.hibernate.event.def.AbstractFlushingEventListener [main] - Processing unreferenced collections 2006-05-18 14:12:44,031 DEBUG org.hibernate.event.def.AbstractFlushingEventListener [main] - Scheduling collection removes/(re)creates/updates 2006-05-18 14:12:44,031 DEBUG org.hibernate.event.def.AbstractFlushingEventListener [main] - Flushed: 0 insertions, 0 updates, 0 deletions to 3 objects 2006-05-18 14:12:44,031 DEBUG org.hibernate.event.def.AbstractFlushingEventListener [main] - Flushed: 1 (re)creations, 0 updates, 0 removals to 1 collections 2006-05-18 14:12:44,031 DEBUG org.hibernate.pretty.Printer [main] - listing entities: 2006-05-18 14:12:44,031 DEBUG org.hibernate.pretty.Printer [main] - com.myapp.econtrol.entities.Expense{site=Sainsbury, items=[com.myapp.econtrol.entities.Item#1, com.myapp.econtrol.entities.Item#2], date=18 May 2006, id=1} 2006-05-18 14:12:44,031 DEBUG org.hibernate.pretty.Printer [main] - com.myapp.econtrol.entities.Item{price=0.75, name=IceCream, id=2} 2006-05-18 14:12:44,031 DEBUG org.hibernate.pretty.Printer [main] - com.myapp.econtrol.entities.Item{price=1.75, name=Banana, id=1} 2006-05-18 14:12:44,031 DEBUG org.hibernate.event.def.AbstractFlushingEventListener [main] - executing flush 2006-05-18 14:12:44,031 DEBUG org.hibernate.persister.collection.AbstractCollectionPersister [main] - Inserting collection: [com.myapp.econtrol.entities.Expense.items#1] 2006-05-18 14:12:44,031 DEBUG org.hibernate.jdbc.AbstractBatcher [main] - about to open PreparedStatement (open PreparedStatements: 0, globally: 0) 2006-05-18 14:12:44,031 DEBUG org.hibernate.jdbc.ConnectionManager [main] - opening JDBC connection 2006-05-18 14:12:44,031 DEBUG org.hibernate.SQL [main] - insert into expense_item (expense_id, items_id) values (?, ?) 2006-05-18 14:12:44,031 DEBUG org.hibernate.jdbc.AbstractBatcher [main] - preparing statement 2006-05-18 14:12:44,031 DEBUG org.hibernate.type.IntegerType [main] - binding '1' to parameter: 1 2006-05-18 14:12:44,031 DEBUG org.hibernate.type.IntegerType [main] - binding '1' to parameter: 2 2006-05-18 14:12:44,031 DEBUG org.hibernate.jdbc.AbstractBatcher [main] - Adding to batch 2006-05-18 14:12:44,031 DEBUG org.hibernate.jdbc.AbstractBatcher [main] - reusing prepared statement 2006-05-18 14:12:44,031 DEBUG org.hibernate.SQL [main] - insert into expense_item (expense_id, items_id) values (?, ?) 2006-05-18 14:12:44,031 DEBUG org.hibernate.type.IntegerType [main] - binding '1' to parameter: 1 2006-05-18 14:12:44,031 DEBUG org.hibernate.type.IntegerType [main] - binding '2' to parameter: 2 2006-05-18 14:12:44,031 DEBUG org.hibernate.jdbc.AbstractBatcher [main] - Adding to batch 2006-05-18 14:12:44,031 DEBUG org.hibernate.persister.collection.AbstractCollectionPersister [main] - done inserting collection: 2 rows inserted 2006-05-18 14:12:44,031 DEBUG org.hibernate.jdbc.AbstractBatcher [main] - Executing batch size: 2 2006-05-18 14:12:44,031 DEBUG org.hibernate.jdbc.AbstractBatcher [main] - about to close PreparedStatement (open PreparedStatements: 1, globally: 1) 2006-05-18 14:12:44,031 DEBUG org.hibernate.jdbc.AbstractBatcher [main] - closing statement 2006-05-18 14:12:44,031 DEBUG org.hibernate.jdbc.ConnectionManager [main] - aggressively releasing JDBC connection 2006-05-18 14:12:44,031 DEBUG org.hibernate.jdbc.ConnectionManager [main] - releasing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)] 2006-05-18 14:12:44,031 DEBUG org.hibernate.event.def.AbstractFlushingEventListener [main] - post flush 2006-05-18 14:12:44,031 DEBUG org.hibernate.jdbc.JDBCContext [main] - before transaction completion 2006-05-18 14:12:44,031 DEBUG org.hibernate.impl.SessionImpl [main] - before transaction completion 2006-05-18 14:12:44,031 DEBUG org.jboss.ejb3.entity.ManagedEntityManagerFactory [main] - ************** closing entity managersession ************** 2006-05-18 14:12:44,031 DEBUG org.hibernate.impl.SessionImpl [main] - closing session 2006-05-18 14:12:44,031 DEBUG org.hibernate.jdbc.ConnectionManager [main] - connection already null in cleanup : no action 2006-05-18 14:12:44,031 DEBUG org.hibernate.transaction.CacheSynchronization [main] - transaction after completion callback, status: 3 2006-05-18 14:12:44,031 DEBUG org.hibernate.jdbc.JDBCContext [main] - after transaction completion 2006-05-18 14:12:44,031 DEBUG org.hibernate.impl.SessionImpl [main] - after transaction completion Persisting expense 2006-05-18 14:12:44,031 DEBUG org.hibernate.jdbc.JDBCContext [main] - successfully registered Synchronization 2006-05-18 14:12:44,031 DEBUG org.hibernate.impl.SessionImpl [main] - opened session at timestamp: 4702035820670976 2006-05-18 14:12:44,031 DEBUG org.hibernate.engine.IdentifierValue [main] - id unsaved-value: 0 2006-05-18 14:12:44,031 DEBUG org.hibernate.event.def.AbstractSaveEventListener [main] - transient instance of: com.myapp.econtrol.entities.Expense 2006-05-18 14:12:44,031 DEBUG org.hibernate.event.def.DefaultPersistEventListener [main] - saving transient instance 2006-05-18 14:12:44,031 DEBUG org.hibernate.event.def.AbstractSaveEventListener [main] - saving [com.myapp.econtrol.entities.Expense#<null>] 2006-05-18 14:12:44,031 DEBUG org.hibernate.event.def.AbstractSaveEventListener [main] - executing insertions 2006-05-18 14:12:44,031 DEBUG org.hibernate.engine.Cascade [main] - processing cascade ACTION_PERSIST for: com.myapp.econtrol.entities.Expense 2006-05-18 14:12:44,031 DEBUG org.hibernate.engine.Cascade [main] - done processing cascade ACTION_PERSIST for: com.myapp.econtrol.entities.Expense 2006-05-18 14:12:44,031 DEBUG org.hibernate.event.def.WrapVisitor [main] - Wrapped collection in role: com.myapp.econtrol.entities.Expense.items 2006-05-18 14:12:44,031 DEBUG org.hibernate.persister.entity.AbstractEntityPersister [main] - Inserting entity: com.myapp.econtrol.entities.Expense (native id) 2006-05-18 14:12:44,031 DEBUG org.hibernate.jdbc.AbstractBatcher [main] - about to open PreparedStatement (open PreparedStatements: 0, globally: 0) 2006-05-18 14:12:44,031 DEBUG org.hibernate.jdbc.ConnectionManager [main] - opening JDBC connection 2006-05-18 14:12:44,031 DEBUG org.hibernate.SQL [main] - insert into expense (site, date, id) values (?, ?, null) 2006-05-18 14:12:44,031 DEBUG org.hibernate.jdbc.AbstractBatcher [main] - preparing statement 2006-05-18 14:12:44,031 DEBUG org.hibernate.persister.entity.AbstractEntityPersister [main] - Dehydrating entity: [com.myapp.econtrol.entities.Expense#<null>] 2006-05-18 14:12:44,031 DEBUG org.hibernate.type.StringType [main] - binding 'Sains' to parameter: 1 2006-05-18 14:12:44,031 DEBUG org.hibernate.type.DateType [main] - binding '18 May 2006' to parameter: 2 2006-05-18 14:12:44,031 DEBUG org.hibernate.jdbc.AbstractBatcher [main] - about to close PreparedStatement (open PreparedStatements: 1, globally: 1) 2006-05-18 14:12:44,031 DEBUG org.hibernate.jdbc.AbstractBatcher [main] - closing statement 2006-05-18 14:12:44,031 DEBUG org.hibernate.jdbc.ConnectionManager [main] - aggressively releasing JDBC connection 2006-05-18 14:12:44,031 DEBUG org.hibernate.jdbc.ConnectionManager [main] - releasing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)] 2006-05-18 14:12:44,031 DEBUG org.hibernate.jdbc.AbstractBatcher [main] - about to open PreparedStatement (open PreparedStatements: 0, globally: 0) 2006-05-18 14:12:44,046 DEBUG org.hibernate.jdbc.ConnectionManager [main] - opening JDBC connection 2006-05-18 14:12:44,046 DEBUG org.hibernate.SQL [main] - call identity() 2006-05-18 14:12:44,046 DEBUG org.hibernate.jdbc.AbstractBatcher [main] - preparing statement 2006-05-18 14:12:44,046 DEBUG org.hibernate.id.IdentifierGeneratorFactory [main] - Natively generated identity: 2 2006-05-18 14:12:44,046 DEBUG org.hibernate.jdbc.AbstractBatcher [main] - about to close PreparedStatement (open PreparedStatements: 1, globally: 1) 2006-05-18 14:12:44,046 DEBUG org.hibernate.jdbc.AbstractBatcher [main] - closing statement 2006-05-18 14:12:44,046 DEBUG org.hibernate.jdbc.ConnectionManager [main] - aggressively releasing JDBC connection 2006-05-18 14:12:44,046 DEBUG org.hibernate.jdbc.ConnectionManager [main] - releasing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)] 2006-05-18 14:12:44,046 DEBUG org.hibernate.engine.Cascade [main] - processing cascade ACTION_PERSIST for: com.myapp.econtrol.entities.Expense 2006-05-18 14:12:44,046 DEBUG org.hibernate.engine.Cascade [main] - cascade ACTION_PERSIST for collection: com.myapp.econtrol.entities.Expense.items 2006-05-18 14:12:44,046 DEBUG org.hibernate.engine.Cascade [main] - done cascade ACTION_PERSIST for collection: com.myapp.econtrol.entities.Expense.items 2006-05-18 14:12:44,046 DEBUG org.hibernate.engine.Cascade [main] - done processing cascade ACTION_PERSIST for: com.myapp.econtrol.entities.Expense Expense persisted.. 2006-05-18 14:12:44,046 DEBUG org.hibernate.transaction.CacheSynchronization [main] - transaction before completion callback 2006-05-18 14:12:44,046 DEBUG org.hibernate.transaction.CacheSynchronization [main] - automatically flushing session 2006-05-18 14:12:44,046 DEBUG org.hibernate.impl.SessionImpl [main] - automatically flushing session 2006-05-18 14:12:44,046 DEBUG org.hibernate.event.def.AbstractFlushingEventListener [main] - flushing session 2006-05-18 14:12:44,046 DEBUG org.hibernate.event.def.AbstractFlushingEventListener [main] - processing flush-time cascades 2006-05-18 14:12:44,046 DEBUG org.hibernate.engine.Cascade [main] - processing cascade ACTION_PERSIST_ON_FLUSH for: com.myapp.econtrol.entities.Expense 2006-05-18 14:12:44,046 DEBUG org.hibernate.engine.Cascade [main] - cascade ACTION_PERSIST_ON_FLUSH for collection: com.myapp.econtrol.entities.Expense.items 2006-05-18 14:12:44,046 DEBUG org.hibernate.engine.Cascade [main] - done cascade ACTION_PERSIST_ON_FLUSH for collection: com.myapp.econtrol.entities.Expense.items 2006-05-18 14:12:44,046 DEBUG org.hibernate.engine.Cascade [main] - done processing cascade ACTION_PERSIST_ON_FLUSH for: com.myapp.econtrol.entities.Expense 2006-05-18 14:12:44,046 DEBUG org.hibernate.event.def.AbstractFlushingEventListener [main] - dirty checking collections 2006-05-18 14:12:44,046 DEBUG org.hibernate.event.def.AbstractFlushingEventListener [main] - Flushing entities and processing referenced collections 2006-05-18 14:12:44,046 DEBUG org.hibernate.engine.Collections [main] - Collection found: [com.myapp.econtrol.entities.Expense.items#2], was: [<unreferenced>] (initialized) 2006-05-18 14:12:44,046 DEBUG org.hibernate.event.def.AbstractFlushingEventListener [main] - Processing unreferenced collections 2006-05-18 14:12:44,046 DEBUG org.hibernate.event.def.AbstractFlushingEventListener [main] - Scheduling collection removes/(re)creates/updates 2006-05-18 14:12:44,046 DEBUG org.hibernate.event.def.AbstractFlushingEventListener [main] - Flushed: 0 insertions, 0 updates, 0 deletions to 1 objects 2006-05-18 14:12:44,046 DEBUG org.hibernate.event.def.AbstractFlushingEventListener [main] - Flushed: 1 (re)creations, 0 updates, 0 removals to 1 collections 2006-05-18 14:12:44,046 DEBUG org.hibernate.pretty.Printer [main] - listing entities: 2006-05-18 14:12:44,046 DEBUG org.hibernate.pretty.Printer [main] - com.myapp.econtrol.entities.Expense{site=Sains, items=[], date=18 May 2006, id=2} 2006-05-18 14:12:44,046 DEBUG org.hibernate.event.def.AbstractFlushingEventListener [main] - executing flush 2006-05-18 14:12:44,046 DEBUG org.hibernate.persister.collection.AbstractCollectionPersister [main] - Inserting collection: [com.myapp.econtrol.entities.Expense.items#2] 2006-05-18 14:12:44,046 DEBUG org.hibernate.persister.collection.AbstractCollectionPersister [main] - collection was empty 2006-05-18 14:12:44,046 DEBUG org.hibernate.event.def.AbstractFlushingEventListener [main] - post flush 2006-05-18 14:12:44,046 DEBUG org.hibernate.jdbc.JDBCContext [main] - before transaction completion 2006-05-18 14:12:44,046 DEBUG org.hibernate.impl.SessionImpl [main] - before transaction completion 2006-05-18 14:12:44,046 DEBUG org.jboss.ejb3.entity.ManagedEntityManagerFactory [main] - ************** closing entity managersession ************** 2006-05-18 14:12:44,046 DEBUG org.hibernate.impl.SessionImpl [main] - closing session 2006-05-18 14:12:44,046 DEBUG org.hibernate.jdbc.ConnectionManager [main] - connection already null in cleanup : no action 2006-05-18 14:12:44,046 DEBUG org.hibernate.transaction.CacheSynchronization [main] - transaction after completion callback, status: 3 2006-05-18 14:12:44,046 DEBUG org.hibernate.jdbc.JDBCContext [main] - after transaction completion 2006-05-18 14:12:44,046 DEBUG org.hibernate.impl.SessionImpl [main] - after transaction completion ...gettign epxense by tyhpe.. 2006-05-18 14:12:44,046 DEBUG org.hibernate.jdbc.JDBCContext [main] - successfully registered Synchronization 2006-05-18 14:12:44,046 DEBUG org.hibernate.impl.SessionImpl [main] - opened session at timestamp: 4702035820732416 2006-05-18 14:12:44,046 DEBUG org.hibernate.engine.query.QueryPlanCache [main] - located HQL query plan in cache (SELECT e FROM Expense e where e.site = :site) 2006-05-18 14:12:44,046 DEBUG org.hibernate.engine.query.QueryPlanCache [main] - located HQL query plan in cache (SELECT e FROM Expense e where e.site = :site) 2006-05-18 14:12:44,046 DEBUG org.hibernate.engine.query.HQLQueryPlan [main] - find: SELECT e FROM Expense e where e.site = :site 2006-05-18 14:12:44,046 DEBUG org.hibernate.engine.QueryParameters [main] - named parameters: {site=Sainsbury} 2006-05-18 14:12:44,046 DEBUG org.hibernate.jdbc.AbstractBatcher [main] - about to open PreparedStatement (open PreparedStatements: 0, globally: 0) 2006-05-18 14:12:44,046 DEBUG org.hibernate.jdbc.ConnectionManager [main] - opening JDBC connection 2006-05-18 14:12:44,062 DEBUG org.hibernate.SQL [main] - select expense0_.id as id0_, expense0_.site as site0_, expense0_.date as date0_ from expense expense0_ where expense0_.site=? 2006-05-18 14:12:44,062 DEBUG org.hibernate.jdbc.AbstractBatcher [main] - preparing statement 2006-05-18 14:12:44,062 DEBUG org.hibernate.loader.hql.QueryLoader [main] - bindNamedParameters() Sainsbury -> site [1] 2006-05-18 14:12:44,062 DEBUG org.hibernate.type.StringType [main] - binding 'Sainsbury' to parameter: 1 2006-05-18 14:12:44,062 DEBUG org.hibernate.jdbc.AbstractBatcher [main] - about to open ResultSet (open ResultSets: 0, globally: 0) 2006-05-18 14:12:44,062 DEBUG org.hibernate.loader.Loader [main] - processing result set 2006-05-18 14:12:44,062 DEBUG org.hibernate.loader.Loader [main] - result set row: 0 2006-05-18 14:12:44,062 DEBUG org.hibernate.type.IntegerType [main] - returning '1' as column: id0_ 2006-05-18 14:12:44,062 DEBUG org.hibernate.loader.Loader [main] - result row: EntityKey[com.myapp.econtrol.entities.Expense#1] 2006-05-18 14:12:44,062 DEBUG org.hibernate.loader.Loader [main] - Initializing object from ResultSet: [com.myapp.econtrol.entities.Expense#1] 2006-05-18 14:12:44,062 DEBUG org.hibernate.persister.entity.AbstractEntityPersister [main] - Hydrating entity: [com.myapp.econtrol.entities.Expense#1] 2006-05-18 14:12:44,062 DEBUG org.hibernate.type.StringType [main] - returning 'Sainsbury' as column: site0_ 2006-05-18 14:12:44,062 DEBUG org.hibernate.type.DateType [main] - returning '18 May 2006' as column: date0_ 2006-05-18 14:12:44,062 DEBUG org.hibernate.loader.Loader [main] - done processing result set (1 rows) 2006-05-18 14:12:44,062 DEBUG org.hibernate.jdbc.AbstractBatcher [main] - about to close ResultSet (open ResultSets: 1, globally: 1) 2006-05-18 14:12:44,062 DEBUG org.hibernate.jdbc.AbstractBatcher [main] - about to close PreparedStatement (open PreparedStatements: 1, globally: 1) 2006-05-18 14:12:44,062 DEBUG org.hibernate.jdbc.AbstractBatcher [main] - closing statement 2006-05-18 14:12:44,062 DEBUG org.hibernate.jdbc.ConnectionManager [main] - aggressively releasing JDBC connection 2006-05-18 14:12:44,062 DEBUG org.hibernate.jdbc.ConnectionManager [main] - releasing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)] 2006-05-18 14:12:44,062 DEBUG org.hibernate.loader.Loader [main] - total objects hydrated: 1 2006-05-18 14:12:44,062 DEBUG org.hibernate.engine.TwoPhaseLoad [main] - resolving associations for [com.myapp.econtrol.entities.Expense#1] 2006-05-18 14:12:44,062 DEBUG org.hibernate.engine.CollectionLoadContext [main] - creating collection wrapper:[com.myapp.econtrol.entities.Expense.items#1] 2006-05-18 14:12:44,062 DEBUG org.hibernate.engine.TwoPhaseLoad [main] - done materializing entity [com.myapp.econtrol.entities.Expense#1] 2006-05-18 14:12:44,062 DEBUG org.hibernate.engine.StatefulPersistenceContext [main] - initializing non-lazy collections 2006-05-18 14:12:44,062 DEBUG org.hibernate.transaction.CacheSynchronization [main] - transaction before completion callback 2006-05-18 14:12:44,062 DEBUG org.hibernate.transaction.CacheSynchronization [main] - automatically flushing session 2006-05-18 14:12:44,062 DEBUG org.hibernate.impl.SessionImpl [main] - automatically flushing session 2006-05-18 14:12:44,062 DEBUG org.hibernate.event.def.AbstractFlushingEventListener [main] - flushing session 2006-05-18 14:12:44,062 DEBUG org.hibernate.event.def.AbstractFlushingEventListener [main] - processing flush-time cascades 2006-05-18 14:12:44,062 DEBUG org.hibernate.engine.Cascade [main] - processing cascade ACTION_PERSIST_ON_FLUSH for: com.myapp.econtrol.entities.Expense 2006-05-18 14:12:44,062 DEBUG org.hibernate.engine.Cascade [main] - cascade ACTION_PERSIST_ON_FLUSH for collection: com.myapp.econtrol.entities.Expense.items 2006-05-18 14:12:44,062 DEBUG org.hibernate.engine.Cascade [main] - done cascade ACTION_PERSIST_ON_FLUSH for collection: com.myapp.econtrol.entities.Expense.items 2006-05-18 14:12:44,062 DEBUG org.hibernate.engine.Cascade [main] - done processing cascade ACTION_PERSIST_ON_FLUSH for: com.myapp.econtrol.entities.Expense 2006-05-18 14:12:44,062 DEBUG org.hibernate.event.def.AbstractFlushingEventListener [main] - dirty checking collections 2006-05-18 14:12:44,062 DEBUG org.hibernate.event.def.AbstractFlushingEventListener [main] - Flushing entities and processing referenced collections 2006-05-18 14:12:44,062 DEBUG org.hibernate.engine.Collections [main] - Collection found: [com.myapp.econtrol.entities.Expense.items#1], was: [com.myapp.econtrol.entities.Expense.items#1] (uninitialized) 2006-05-18 14:12:44,062 DEBUG org.hibernate.event.def.AbstractFlushingEventListener [main] - Processing unreferenced collections 2006-05-18 14:12:44,062 DEBUG org.hibernate.event.def.AbstractFlushingEventListener [main] - Scheduling collection removes/(re)creates/updates 2006-05-18 14:12:44,062 DEBUG org.hibernate.event.def.AbstractFlushingEventListener [main] - Flushed: 0 insertions, 0 updates, 0 deletions to 1 objects 2006-05-18 14:12:44,062 DEBUG org.hibernate.event.def.AbstractFlushingEventListener [main] - Flushed: 0 (re)creations, 0 updates, 0 removals to 1 collections 2006-05-18 14:12:44,062 DEBUG org.hibernate.pretty.Printer [main] - listing entities: 2006-05-18 14:12:44,062 DEBUG org.hibernate.pretty.Printer [main] - com.myapp.econtrol.entities.Expense{site=Sainsbury, items=<uninitialized>, date=18 May 2006, id=1} 2006-05-18 14:12:44,062 DEBUG org.hibernate.event.def.AbstractFlushingEventListener [main] - executing flush 2006-05-18 14:12:44,062 DEBUG org.hibernate.event.def.AbstractFlushingEventListener [main] - post flush 2006-05-18 14:12:44,062 DEBUG org.hibernate.jdbc.JDBCContext [main] - before transaction completion 2006-05-18 14:12:44,062 DEBUG org.hibernate.impl.SessionImpl [main] - before transaction completion 2006-05-18 14:12:44,062 DEBUG org.jboss.ejb3.entity.ManagedEntityManagerFactory [main] - ************** closing entity managersession ************** 2006-05-18 14:12:44,062 DEBUG org.hibernate.impl.SessionImpl [main] - closing session 2006-05-18 14:12:44,062 DEBUG org.hibernate.jdbc.ConnectionManager [main] - connection already null in cleanup : no action 2006-05-18 14:12:44,062 DEBUG org.hibernate.transaction.CacheSynchronization [main] - transaction after completion callback, status: 3 2006-05-18 14:12:44,062 DEBUG org.hibernate.jdbc.JDBCContext [main] - after transaction completion 2006-05-18 14:12:44,062 DEBUG org.hibernate.impl.SessionImpl [main] - after transaction completion 2006-05-18 14:12:44,078 ERROR org.hibernate.LazyInitializationException [main] - failed to lazily initialize a collection of role: com.myapp.econtrol.entities.Expense.items, no session or session was closed org.hibernate.LazyInitializationException: failed to lazily initialize a collection of role: com.myapp.econtrol.entities.Expense.items, no session or session was closed at org.hiberna