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
-~----------~----~----~----~------~----~------~--~---

Reply via email to