[jbossseam-issues] [JBoss JIRA] Commented: (JBSEAM-3519) Excessive JNDI lookups for "java:comp/UserTransation"

[Jay Balunas (JIRA)]

    [ https://jira.jboss.org/jira/browse/JBSEAM-3519?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12432745#action_12432745 ] 

Jay Balunas commented on JBSEAM-3519:
-------------------------------------

All of the JNDI requests for UserTransaction go through the org.jboss.seam.transaction.Transaction class (see : http://fisheye.jboss.org/browse/Seam/trunk/src/main/org/jboss/seam/transaction/Transaction.java?r=5875 ).  This is an event scoped component so its lifecycle covers the entire request from RESTORE_VIEW through RENDER_RESPONSE.

I modified it (see attached patch Transaction.txt) so that it stores the result of the transaction lookup (UserTransaction, EjbTransaction, or NoTransaction).  It then returns this result the next time a transaction is requested. 

This drastically cuts down the number of JNDI lookups.  For the wiki user forum front page the number of lookups went from 114 to 6!!  One at the very start of the RESTORE_VIEW phase.  Then the 5 others are after the REDER_RESPONSE phase.  I'm assuming because of ajax related calls for caching.

I ran this change through the 25 and 50 user performance runs and saw a small increase in performance, but I have not yet investigated the details in the profiler to determine exactly where we are spending the time now.  I would guess that we are not not blocking as heavily on the InitialContext lookups, but instead are passing through that code quickly and hitting further blocks, or processing bottlenecks in the persistence layer.

I looked a bit at using synchronizations in an attempt to clear the stored value if the transaction is completed during the event scope but I ran into some issues with that.  The current approach seems to working fine, and the wiki behaves normally, but I wanted to get some more opinions on this

What is the risk of caching this transaction instance in the event scope? 

<Emmanuel>Does seam components support something like the REQUIRES_NEW semantic of SessionBeans? If so, then caching might not be appropriate.
Generally speaking if something use the TransactionManager to create new transactions or suspend them, you are screwed.</Emmanuel>

How can we determine when/if the transaction is not valid anymore - do we need to? 

Does the behavior need to be different for UTTransaction vs CMTTransaction?

> Excessive JNDI lookups for "java:comp/UserTransation"
> -----------------------------------------------------
>
>                 Key: JBSEAM-3519
>                 URL: https://jira.jboss.org/jira/browse/JBSEAM-3519
>             Project: Seam
>          Issue Type: Bug
>          Components: Core, Performance and Scalability
>    Affects Versions: 2.1.0.CR1
>            Reporter: Jay Balunas
>            Assignee: Shane Bryzak
>            Priority: Critical
>             Fix For: 2.1.1.CR1
>
>         Attachments: Transaction.txt
>
>
> NOTE: There are more details to this on the seam-dev email list and its archives.  Below is the primary email that broke down the behavior.
> A single user making a single request to the Seam wiki example's user forum front page performs 114 JNDI lookups for "java:comp/UserTransation".  This means that not only are 144 instances of IntialContext created, but we have 114 actual lookups as well.  This is nearly linear with 2 requests creating 228 JNDI lookups + some for ajax4jsf caching calls as described below.  Extrapolating to the 25 user test that would be 25x114=2850 jndi lookups for each round of requests. 
> At least for the wiki page I am testing there were no other JNDI lookups.
> Who is looking up "java:comp/UserTransation"
> --------------------------------------------------------
> All of these calls can be traced to Transaction.instance().  I broke down all of the calls to Transaction.instance() during a single request to the user forum page on the wiki.  
> 81 - seam.util.Work.workInTransaction(Work.java:34) via (TransactionInterceptor.java:34)
>   1 - SeamPhaseListener.handleTransactionsBeforePhase(SeamPhaseListener.java:319)
>   3 - SeamPhaseListener.begin(SeamPhaseListener.java:591)                          
>   3 - SeamPhaseListener.begin(SeamPhaseListener.java:594)                          
>   3 - SeamPhaseListener.commitOrRollback(SeamPhaseListener.java:611)       
>   3 - SeamPhaseListener.commitOrRollback(SeamPhaseListener.java:614)       
>   8 - ManagedPersistenceContext.joinTransaction(ManagedPersistenceContext.java:120)
>   6 - Contexts.flushAndDestroyContexts(Contexts.java:331)                          
>   6 - ManagedPersistenceContext.close(ManagedPersistenceContext.java:192)        
> -------------
> 114 - Total
> I then broke it down by which JSF lifecycle phase it was done in.
> Phase Breakdown:
> ------------------
> 3   - During RESTORE_VIEW                    
> 2   - Between RESTORE_VIEW and RENDER_RESPONSE
> 91 - During RENDER_RESPONSE                  
> 18 - After RENDER_RESPONSE                  
> ----------
> 114 total
> I then did the same break down on a second follow up request with the same session
> Second Request showed a different distribution:
> ------------------------------------------------
> 3   - During RESTORE_VIEW                          
> 2   - Between RESTORE_VIEW and RENDER_RESPONSE     
> 91 - During RENDER_RESPONSE                      
> 5   - After RENDER_RESPONSE                        
> 3   - During 2nd RESTORE_VIEW                      
> 0   - Between 2nd RESTORE_VIEW and RENDER_RESPONSE 
> 1   - During 2nd RENDER_RESPONSE                   
> 3   - After 2nd RENDER_RESPONSE                    
> 3   - During 3rd RESTORE_VIEW                      
> 0   - Between 3rd RESTORE_VIEW and RENDER_RESPONSE 
> 1   - During 3rd RENDER_RESPONSE                   
> 16 - After 3rd RENDER_RESPONSE                   
> ------------          
> 128 total
> The extra 14 lookups are all during the extra 2 mini requests.  They all pass through this ajax4jsf class "org.ajax4jsf.resource.ResourceLifecycle.invokePhaseListener(ResourceLifecycle.java:[199/201])".  I'm assuming that these extra calls are related to page fragment caching and/or resources that are provided through the ajax4jsf InternetResourceService.  Christian can you confirm?
> Conclusions:
> ---------------------
> We obviously need to find more ways to improve this behavior.  The primary offender is "Work.java" (see: http://fisheye.jboss.org/browse/Seam/trunk/src/main/org/jboss/seam/util/Work.java?r=8624#l34 ).  This single line is checking if the transaction is currently active.  81 time it is active and processing continues as normal.  Is there a way we can cache this value for the length of the request (either the transaction, or the result)?  Caching the result could be bad if something changed during the request, so we would need the actual transaction.
> Also many of the lookups were the result of EL processing during the RENDER_RESPONSE phase.  Ideally these would primarily be read-only requests or close to it.  Could there be a way to disable the transactional calls for items somehow tagged read only?  I have not give that much thought yet so it might need some flushing out ;-)

-- 
This message is automatically generated by JIRA.
-
If you think it was sent incorrectly contact one of the administrators: https://jira.jboss.org/jira/secure/Administrators.jspa
-
For more information on JIRA, see: http://www.atlassian.com/software/jira