The principal reason I'm using Hibernate is because the base JPA unfortunately doesn't provide support for non-standard type persistence, and so a few of my entities are annotated with @Type in order to use custom mappings for some of the org.joda.time classes (the Order object in question being one of them.)
I've now got debug logging working; here is one interesting bit; after adding a logging check to see whether the EntityManager is open: def list(xhtml: NodeSeq) : NodeSeq = { Log.info("Entity manager is open: " + em.isOpen().toString()) val orders = em.createQuery("FROM Order").getResultList().asInstanceOf[java.util.List[Order]] I get: INFO lift - Entity manager is open: true DEBUG impl.SessionImpl - opened session at timestamp: 12209812983 DEBUG ejb.AbstractEntityManagerImpl - Looking for a JTA transaction to join DEBUG ejb.AbstractEntityManagerImpl - No JTA transaction found Since there's no JTA transaction found, I'm suspecting that Hibernate is creating its own session to use for the fetch, and is closing it afterward. The failure to find a JTA transaction is a bit telling, though - I wonder if in the standard Glassfish stack, JTA transactions are established in a servlet filter that's not being used with Lift - that Lift does request handling too far upstream or something. DEBUG ast.QueryTranslatorImpl - parse() - HQL: FROM com.gaiam.gcsi.entities.subscription.Order DEBUG ast.HqlParser - weakKeywords() : new LT(1) token - ["Order",<120> previously: <41>,line=1,col=43,possibleID=true] DEBUG ast.AST - --- HQL AST --- \-[QUERY] 'query' \-[SELECT_FROM] 'SELECT_FROM' \-[FROM] 'FROM' \-[RANGE] 'RANGE' \-[DOT] '.' +-[DOT] '.' | +-[DOT] '.' | | +-[DOT] '.' | | | +-[DOT] '.' | | | | +-[IDENT] 'com' | | | | \-[IDENT] 'gaiam' | | | \-[IDENT] 'gcsi' | | \-[IDENT] 'entities' | \-[IDENT] 'subscription' \-[IDENT] 'Order' DEBUG ast.ErrorCounter - throwQueryException() : no errors DEBUG antlr.HqlSqlBaseWalker - select << begin [level=1, statement=select] DEBUG tree.FromElement - FromClause{level=1} : com.gaiam.gcsi.entities.subscription.Order (no alias) -> order0_ DEBUG antlr.HqlSqlBaseWalker - select : finishing up [level=1, statement=select] DEBUG ast.HqlSqlWalker - processQuery() : ( SELECT ( FromClause{level=1} orders order0_ ) ) DEBUG ast.HqlSqlWalker - Derived SELECT clause created. DEBUG util.JoinProcessor - Using FROM fragment [orders order0_] DEBUG antlr.HqlSqlBaseWalker - select >> end [level=1, statement=select] DEBUG ast.AST - --- SQL AST --- \-[SELECT] QueryNode: 'SELECT' querySpaces (orders) +-[SELECT_CLAUSE] SelectClause: '{derived select clause}' | +-[SELECT_EXPR] SelectExpressionImpl: 'order0_.id as id506_' {FromElement{explicit,not a collection join,not a fetch join,fetch non-lazy properties,classAlias=null,role=null,tableName=orders,tableAlias=order0_,origin=null,colums={,className=com.gaiam.gcsi.entities.subscription.Order}}} | \-[SQL_TOKEN] SqlFragment: 'order0_.uuid as uuid506_, order0_.affiliate_id as affiliate5_506_, order0_.order_date as order3_506_, order0_.payment_source_id as payment6_506_, order0_.shipping_address_id as shipping7_506_, order0_.source_id as source8_506_, order0_.state as state506_, order0_.user_id as user9_506_' \-[FROM] FromClause: 'FROM' FromClause{level=1, fromElementCounter=1, fromElements=1, fromElementByClassAlias=[], fromElementByTableAlias=[order0_], fromElementsByPath=[], collectionJoinFromElementsByPath=[], impliedElements=[]} \-[FROM_FRAGMENT] FromElement: 'orders order0_' FromElement{explicit,not a collection join,not a fetch join,fetch non-lazy properties,classAlias=null,role=null,tableName=orders,tableAlias=order0_,origin=null,colums={,className=com.gaiam.gcsi.entities.subscription.Order}} DEBUG ast.ErrorCounter - throwQueryException() : no errors DEBUG ast.QueryTranslatorImpl - HQL: FROM com.gaiam.gcsi.entities.subscription.Order DEBUG ast.QueryTranslatorImpl - SQL: select order0_.id as id506_, order0_.uuid as uuid506_, order0_.affiliate_id as affiliate5_506_, order0_.order_date as order3_506_, order0_.payment_source_id as payment6_506_, order0_.shipping_address_id as shipping7_506_, order0_.source_id as source8_506_, order0_.state as state506_, order0_.user_id as user9_506_ from orders order0_ DEBUG ast.ErrorCounter - throwQueryException() : no errors DEBUG jdbc.AbstractBatcher - about to open PreparedStatement (open PreparedStatements: 0, globally: 0) DEBUG jdbc.ConnectionManager - opening JDBC connection DEBUG hibernate.SQL - select order0_.id as id506_, order0_.uuid as uuid506_, order0_.affiliate_id as affiliate5_506_, order0_.order_date as order3_506_, order0_.payment_source_id as payment6_506_, order0_.shipping_address_id as shipping7_506_, order0_.source_id as source8_506_, order0_.state as state506_, order0_.user_id as user9_506_ from orders order0_ DEBUG jdbc.AbstractBatcher - about to open ResultSet (open ResultSets: 0, globally: 0) DEBUG loader.Loader - result row: EntityKey[com.gaiam.gcsi.entities.subscription.Order#1] DEBUG jdbc.AbstractBatcher - about to close ResultSet (open ResultSets: 1, globally: 1) DEBUG jdbc.AbstractBatcher - about to close PreparedStatement (open PreparedStatements: 1, globally: 1) DEBUG jdbc.ConnectionManager - aggressively releasing JDBC connection DEBUG jdbc.ConnectionManager - releasing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)] DEBUG engine.TwoPhaseLoad - resolving associations for [com.gaiam.gcsi.entities.subscription.Order#1] DEBUG loader.Loader - loading entity: [com.gaiam.gcsi.entities.user.PaymentSource#2] DEBUG jdbc.AbstractBatcher - about to open PreparedStatement (open PreparedStatements: 0, globally: 0) DEBUG jdbc.ConnectionManager - opening JDBC connection DEBUG hibernate.SQL - select paymentsou0_.id as id483_3_, paymentsou0_.uuid as uuid483_3_, paymentsou0_.description as descript3_483_3_, paymentsou0_.reusable as reusable483_3_, paymentsou0_.user_id as user6_483_3_, paymentsou0_.valid as valid483_3_, paymentsou0_1_.billing_address_id as billing7_492_3_, paymentsou0_1_.cardholder as cardholder492_3_, paymentsou0_1_.exp_month as exp2_492_3_, paymentsou0_1_.exp_year as exp3_492_3_, paymentsou0_1_.last_digits as last4_492_3_, paymentsou0_1_.type as type492_3_, case when paymentsou0_1_.id is not null then 1 when paymentsou0_.id is not null then 0 end as clazz_3_, user1_.id as id481_0_, user1_.uuid as uuid481_0_, user1_.created_at as created3_481_0_, user1_.email as email481_0_, user1_.encrypted_password as encrypted5_481_0_, user1_.encryption_algorithm as encryption6_481_0_, user1_.first_name as first7_481_0_, user1_.last_name as last8_481_0_, user1_.login as login481_0_, address2_.id as id503_1_, address2_.uuid as uuid503_1_, address2_.address1 as address3_503_1_, address2_.address2 as address4_503_1_, address2_.city as city503_1_, address2_.latitude as latitude503_1_, address2_.longitude as longitude503_1_, address2_.phone as phone503_1_, address2_.postal_code as postal9_503_1_, address2_.recipient as recipient503_1_, address2_.region_id as region11_503_1_, address2_.user_id as user12_503_1_, region3_.id as id501_2_, region3_.ecometry_code as ecometry2_501_2_, region3_.iso as iso501_2_, region3_.iso3 as iso4_501_2_, region3_.name as name501_2_, region3_.num_code as num6_501_2_, region3_.parent_id as parent10_501_2_, region3_.real_name as real7_501_2_, region3_.shipping_code as shipping8_501_2_, region3_.type as type501_2_ from payment_source paymentsou0_ left outer join credit_card paymentsou0_1_ on paymentsou0_.id=paymentsou0_1_.id left outer join users user1_ on paymentsou0_.user_id=user1_.id left outer join address address2_ on paymentsou0_1_.billing_address_id=address2_.id left outer join region region3_ on address2_.region_id=region3_.id where paymentsou0_.id=? DEBUG jdbc.AbstractBatcher - about to open ResultSet (open ResultSets: 0, globally: 0) DEBUG loader.Loader - result row: EntityKey[com.gaiam.gcsi.entities.user.User#3], EntityKey[com.gaiam.gcsi.entities.user.Address#4], EntityKey[com.gaiam.gcsi.entities.Region#5], EntityKey[com.gaiam.gcsi.entities.user.PaymentSource#2] DEBUG jdbc.AbstractBatcher - about to close ResultSet (open ResultSets: 1, globally: 1) DEBUG jdbc.AbstractBatcher - about to close PreparedStatement (open PreparedStatements: 1, globally: 1) DEBUG jdbc.ConnectionManager - aggressively releasing JDBC connection DEBUG jdbc.ConnectionManager - releasing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)] DEBUG engine.TwoPhaseLoad - resolving associations for [com.gaiam.gcsi.entities.user.User#3] DEBUG engine.TwoPhaseLoad - done materializing entity [com.gaiam.gcsi.entities.user.User#3] DEBUG engine.TwoPhaseLoad - resolving associations for [com.gaiam.gcsi.entities.user.Address#4] DEBUG engine.TwoPhaseLoad - done materializing entity [com.gaiam.gcsi.entities.user.Address#4] DEBUG engine.TwoPhaseLoad - resolving associations for [com.gaiam.gcsi.entities.Region#5] DEBUG engine.TwoPhaseLoad - done materializing entity [com.gaiam.gcsi.entities.Region#5] DEBUG engine.TwoPhaseLoad - resolving associations for [com.gaiam.gcsi.entities.user.CreditCard#2] DEBUG engine.TwoPhaseLoad - done materializing entity [com.gaiam.gcsi.entities.user.CreditCard#2] DEBUG loader.Loader - done entity load DEBUG loader.Loader - loading entity: [com.gaiam.gcsi.entities.GaiamDivision#7] DEBUG jdbc.AbstractBatcher - about to open PreparedStatement (open PreparedStatements: 0, globally: 0) DEBUG jdbc.ConnectionManager - opening JDBC connection DEBUG hibernate.SQL - select gaiamdivis0_.id as id496_0_, gaiamdivis0_.ecometry_company_id as ecometry2_496_0_, gaiamdivis0_.ecometry_division_id as ecometry3_496_0_, gaiamdivis0_.name as name496_0_, gaiamdivis0_.paymentech_login as paymentech5_496_0_, gaiamdivis0_.paymentech_merchant_id as paymentech6_496_0_, gaiamdivis0_.paymentech_password as paymentech7_496_0_, gaiamdivis0_.paymentech_terminal_id as paymentech8_496_0_ from gaiam_division gaiamdivis0_ where gaiamdivis0_.id=? DEBUG jdbc.AbstractBatcher - about to open ResultSet (open ResultSets: 0, globally: 0) DEBUG loader.Loader - result row: EntityKey[com.gaiam.gcsi.entities.GaiamDivision#7] DEBUG jdbc.AbstractBatcher - about to close ResultSet (open ResultSets: 1, globally: 1) DEBUG jdbc.AbstractBatcher - about to close PreparedStatement (open PreparedStatements: 1, globally: 1) DEBUG jdbc.ConnectionManager - aggressively releasing JDBC connection DEBUG jdbc.ConnectionManager - releasing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)] DEBUG engine.TwoPhaseLoad - resolving associations for [com.gaiam.gcsi.entities.GaiamDivision#7] DEBUG engine.TwoPhaseLoad - done materializing entity [com.gaiam.gcsi.entities.GaiamDivision#7] DEBUG loader.Loader - done entity load DEBUG engine.TwoPhaseLoad - done materializing entity [com.gaiam.gcsi.entities.subscription.Order#1] DEBUG engine.StatefulPersistenceContext - initializing non-lazy collections So Hibernate is doing fine with the primary query and the eager fetch, but then we're on to the previously seen error. ERROR hibernate.LazyInitializationException - failed to lazily initialize a collection of role: com.gaiam.gcsi.entities.subscription.Order.subscriptions, no session or session was closed org.hibernate.LazyInitializationException: failed to lazily initialize a collection of role: com.gaiam.gcsi.entities.subscription.Order.subscriptions, no session or session was closed Guess I'm going to have to dive into the Glassfish code. Bleah. Kris On Tue, Sep 9, 2008 at 11:08 AM, Derek Chen-Becker <[EMAIL PROTECTED]> wrote: > I'm pretty sure that the RequestVar should be around for the life of the > Lift session, which means that you should still have a valid lift session in > *any* snippet that would get called. Viktor's correct that this is a common > error that people run into with JPA, but it's usually because they're doing > something wrong. For instance, in Struts, you might naievely open and close > an EntityManager within one of your Action classes, but forget that the > lists won't actually be fetched until the resulting JSP is processed. In > Lift, the RequestVar should be set up before any of your code is called and > shouldn't be shut down until all of your code is finished. I haven't used > GlassFish at all, but I would assume that they have some debugging of their > EM implementation that may be helpful in tracking this down. If you're > getting the same error immediately following the call then that's pretty > weird. One other thing: GlassFish provides its own JPA stack; is there a > reason you're still using the Hibernate EM? The fact that you're using JNDI > from inside GlassFish makes me worried that you may have some implementation > conflicts between GlassFish's JPA stack (TopLink, I believe) and the > Hibernate one that would get packaged automatically if you haven't edited > the POM. I think you probably want to change the scope on the persistence > pom so that the javax.persistence's scope is "provided" and the Hibernate > and HSQLDB are "test". Let me know what you find or if that helps. > > Derek > > On Tue, Sep 9, 2008 at 9:24 AM, Kris Nuttycombe <[EMAIL PROTECTED]> > wrote: >> >> > On Tue, Sep 9, 2008 at 10:09 AM, Oliver <[EMAIL PROTECTED]> wrote: >> >> >> >> Actually, is this the essence of the cookie. Why has the object been >> >> detached in the example Kris gives - is there something wrong with >> >> RequestVar lifecycle? >> >> Right; sorry, I should have been more clear about my question. I >> expected that the persistence session would be bound to the scope of >> the request at the appserver level, and that since Lift runs as a >> servlet filter that this binding would persist throughout the Lift >> call stack. >> >> > Actually, just add a simple debug-print when the session is created and >> > when >> > it's closed. And if it prints that it is closed _before_ the execption >> > is >> > raised then there certainly is a problem with the requestvar lifecycle. >> >> At this point, I'm beginning to think that this is not even >> Lift-related; when I add a log statement immediately after running the >> query I'm seeing the same result. It may be that the EntityManager is >> not being bound correctly to the request in the first place and that >> all retrieved objects are immediately detached, though I'm not certain >> how to go about tracking that down. >> >> > Ideally the entitymanager should be managed outside the scope of >> > request-vars, since the order of request-var destruction isn't given, >> > which >> > means that if the cleanup is done in the "wrong" order, the Session is >> > closed before referenced objects are cleaned up, which introduces the >> > possibility for weirdness. >> >> Hrm; in the other Lift/JPA thread folks seem to be moving *toward* the >> RequestVar solution, particularly taking advantage of the cleanup >> hooks in 0.10. >> >> Thanks, >> >> Kris >> >> > > > > > --~--~---------~--~----~------------~-------~--~----~ You received this message because you are subscribed to the Google Groups "Lift" group. To post to this group, send email to liftweb@googlegroups.com To unsubscribe from this group, send email to [EMAIL PROTECTED] For more options, visit this group at http://groups.google.com/group/liftweb?hl=en -~----------~----~----~----~------~----~------~--~---