Seam Conversations and JSFUnit.

[djn]

Hi.

It would seem I'm doing something very wrong, althoug I'm not sure what it is.

In my test case I reference a seam conversation scoped variable called routeAnalysis. I want to ensure some state after an ajax call.

However this fails:

 Object o = server.getManagedBeanValue("#{seamconversation.routeAnalysis}");
 assertNotNull(o);

But if i iterate through the session like this:

 HttpSession s = (HttpSession) server.getFacesContext().getExternalContext().getSession(false);
 final Enumeration attributeNames = s.getAttributeNames();
 while (attributeNames.hasMoreElements()) {
 final Object o = attributeNames.nextElement();
 log.debug("element: " + o );
 }

I get:

16:09:11,541 DEBUG [ReportEditTest] element: org.ajax4jsf.application.AjaxStateManager.view_sequence
16:09:11,541 DEBUG [ReportEditTest] element: org.jboss.seam.CONVERSATION#808$blipZonesConfigEntityManager
16:09:11,541 DEBUG [ReportEditTest] element: org.jboss.seam.CONVERSATION#808$routeAnalysisHome
16:09:11,541 DEBUG [ReportEditTest] element: org.jboss.seam.international.timeZoneSelector
16:09:11,541 DEBUG [ReportEditTest] element: org.jboss.seam.CONVERSATION#808$reportHome
16:09:11,541 DEBUG [ReportEditTest] element: org.jboss.jsfunit.framework.WebClientSpecsessionkey
16:09:11,542 DEBUG [ReportEditTest] element: org.jboss.seam.security.ruleBasedPermissionResolver
16:09:11,542 DEBUG [ReportEditTest] element: org.jboss.seam.security.rememberMe
16:09:11,542 DEBUG [ReportEditTest] element: org.jboss.seam.CONVERSATION#808$org.jboss.seam.ui.EntityConverter
16:09:11,542 DEBUG [ReportEditTest] element: org.jboss.jsfunit.seam.JSFUnitLifecycle.SEAM_CONVERSATION_CACHE
16:09:11,542 DEBUG [ReportEditTest] element: org.ajax4jsf.application.AjaxStateHolder
16:09:11,542 DEBUG [ReportEditTest] element: org.jboss.seam.security.identity
16:09:11,543 DEBUG [ReportEditTest] element: componentNavigator
16:09:11,543 DEBUG [ReportEditTest] element: org.jboss.seam.core.conversationEntries
16:09:11,543 DEBUG [ReportEditTest] element: org.jboss.seam.CONVERSATION#808$userGroupFiltering
16:09:11,543 DEBUG [ReportEditTest] element: org.jboss.seam.security.credentials
16:09:11,543 DEBUG [ReportEditTest] element: org.jboss.seam.CONVERSATION#808$report
16:09:11,543 DEBUG [ReportEditTest] element: org.jboss.seam.international.localeSelector
16:09:11,543 DEBUG [ReportEditTest] element: authenticatedUser
16:09:11,543 DEBUG [ReportEditTest] element: org.jboss.seam.CONVERSATION#808$routeAnalysis
16:09:11,543 DEBUG [ReportEditTest] element: org.jboss.seam.CONVERSATION#808$org.jboss.seam.persistence.persistenceContexts
16:09:11,543 DEBUG [ReportEditTest] element: org.jboss.seam.CONVERSATION#808$org.jboss.seam.international.statusMessages
16:09:11,543 DEBUG [ReportEditTest] element: org.jboss.seam.web.session
16:09:11,543 DEBUG [ReportEditTest] element: javax.faces.request.charset
16:09:11,543 DEBUG [ReportEditTest] element: org.jboss.jsfunit.context.JSFUnitFacesContext.sessionkey
16:09:11,544 DEBUG [ReportEditTest] element: org.jboss.seam.CONVERSATION#808$org.jboss.seam.core.conversation

Notice the line with 16:09:11,543 DEBUG [ReportEditTest] element: org.jboss.seam.CONVERSATION#808$routeAnalysis.

So I dont get why I cannot retrieve the variable from the seamconvesation. Any ideas?

[ssilvert]

Seam conversation scope is special case for JSFUnit. At the end of a request, JSFUnit caches all conversation-scoped objects in a Map referenced by org.jboss.jsfunit.seam.JSFUnitLifecycle.SEAM_CONVERSATION_CACHE.

So you need to get that Map out of the session and see if your object is in there. It's possible that at the end of the request, the conversation is over and therefore the object is no longer in the cache.

Let me know what you find.

Regards,

Stan

[djn]

Hi Stan, and thank you for your reply.

The flow I'm testing goes something like this:

1. 
   
2. Login
   
   
3. Navigate to a list of entities
   
   
4. Click "create new" button (starts new long running conversation and initialises a bunch of components, also the one called routeAnalysis)
   
   
5. Simulate clicking a button in the interface vha client.click and checks that the interface re-renders correctly (it does! RichFaces and JSFUnit plays together quite nice)
   
   
6. Validate some fields on routeAnalysis (this fails with the above errors)
   
   
   I tried your suggestion and run the following code in between testing the rerenders of my create new page:
   
   

    HttpSession s = (HttpSession) server.getFacesContext().getExternalContext().getSession(false);
    HashMap cache = (HashMap) s.getAttribute("org.jboss.jsfunit.seam.JSFUnitLifecycle.SEAM_CONVERSATION_CACHE");
    for (Object k : cache.keySet()) {
    Object v = cache.get(k);
    log.debug("key: " + k);
    log.debug("value: " + v);
    }
   

   
   which produces the following output:
   
   

   10:30:06,258 DEBUG [ReportEditTest] key: org.jboss.seam.handledException
   10:30:06,259 DEBUG [ReportEditTest] value: org.jboss.seam.security.NotLoggedInException
   10:30:06,259 DEBUG [ReportEditTest] key: org.jboss.seam.faces.redirect
   10:30:06,259 DEBUG [ReportEditTest] value: org.jboss.seam.faces.Redirect@161caaa
   10:30:06,259 DEBUG [ReportEditTest] key: org.jboss.seam.caughtException
   10:30:06,259 DEBUG [ReportEditTest] value: org.jboss.seam.security.NotLoggedInException
   10:30:06,259 DEBUG [ReportEditTest] key: org.jboss.seam.persistence.persistenceContexts
   10:30:06,259 DEBUG [ReportEditTest] value: org.jboss.seam.persistence.PersistenceContexts@140827c
   10:30:06,260 DEBUG [ReportEditTest] key: org.jboss.seam.core.conversation
   10:30:06,260 DEBUG [ReportEditTest] value: org.jboss.seam.core.Conversation@36a6d1
   10:30:06,260 DEBUG [ReportEditTest] key: org.jboss.seam.international.statusMessages
   10:30:06,260 DEBUG [ReportEditTest] value: org.jboss.seam.faces.FacesMessages@1e99a
   

   
   
   This looks conspicuously similar to my issues with navigating directly to the create new wizard described here: http://www.jboss.org/index.html?module=bb&op=viewtopic&t=152468
   
   I tried printing the facesmessages and handledException with the following code:
   
   

    FacesMessages messages = (FacesMessages) cache.get("org.jboss.seam.international.statusMessages");
    List<FacesMessage> facesMessageList = messages.getCurrentMessages();
    log.debug("no messages " + facesMessageList.size());
    for (FacesMessage message : facesMessageList) {
    log.debug("message: " + message.getSummary());
    }
    facesMessageList = messages.getCurrentGlobalMessages();
    log.debug("no messages " + facesMessageList.size());
    for (FacesMessage message : facesMessageList) {
    log.debug("message global: " + message.getSummary());
    }
   
    NotLoggedInException handledException = (NotLoggedInException) cache.get("org.jboss.seam.handledException");
    log.debug("handledException: ", handledException);
   

   
   And got:
   

   10:42:31,485 DEBUG [ReportEditTest] no messages 0
   10:42:31,485 DEBUG [ReportEditTest] no messages 0
   10:42:31,486 DEBUG [ReportEditTest] handledException:
   org.jboss.seam.security.NotLoggedInException
    at org.jboss.seam.security.Identity.checkRestriction(Identity.java:217)
    at org.jboss.seam.navigation.Page.checkPermission(Page.java:245)
    at org.jboss.seam.navigation.Page.preRender(Page.java:265)
    at org.jboss.seam.navigation.Pages.preRender(Pages.java:366)
    at org.jboss.seam.jsf.SeamPhaseListener.preRenderPage(SeamPhaseListener.java:562)
    at org.jboss.seam.jsf.SeamPhaseListener.beforeRenderResponse(SeamPhaseListener.java:473)
    at org.jboss.seam.jsf.SeamPhaseListener.beforeServletPhase(SeamPhaseListener.java:146)
    at org.jboss.seam.jsf.SeamPhaseListener.beforePhase(SeamPhaseListener.java:116)
    at com.sun.faces.lifecycle.Phase.handleBeforePhase(Phase.java:214)
    at com.sun.faces.lifecycle.Phase.doPhase(Phase.java:96)
    at com.sun.faces.lifecycle.LifecycleImpl.render(LifecycleImpl.java:139)
    at org.jboss.jsfunit.seam.JSFUnitLifecycle.render(JSFUnitLifecycle.java:59)
    at javax.faces.webapp.FacesServlet.service(FacesServlet.java:266)
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:290)
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
    at org.jboss.seam.servlet.SeamFilter$FilterChainImpl.doFilter(SeamFilter.java:83)
    at org.jboss.seam.web.IdentityFilter.doFilter(IdentityFilter.java:40)
    at org.jboss.seam.servlet.SeamFilter$FilterChainImpl.doFilter(SeamFilter.java:69)
    at org.jboss.seam.web.MultipartFilter.doFilter(MultipartFilter.java:90)
    at org.jboss.seam.servlet.SeamFilter$FilterChainImpl.doFilter(SeamFilter.java:69)
    at org.jboss.seam.web.ExceptionFilter.doFilter(ExceptionFilter.java:64)
    at org.jboss.seam.servlet.SeamFilter$FilterChainImpl.doFilter(SeamFilter.java:69)
    at org.jboss.seam.web.RedirectFilter.doFilter(RedirectFilter.java:45)
    at org.jboss.seam.servlet.SeamFilter$FilterChainImpl.doFilter(SeamFilter.java:69)
    at org.jboss.seam.servlet.SeamFilter$FilterChainImpl.doFilter(SeamFilter.java:73)
    at org.ajax4jsf.webapp.BaseXMLFilter.doXmlFilter(BaseXMLFilter.java:178)
    at org.ajax4jsf.webapp.BaseFilter.handleRequest(BaseFilter.java:290)
    at org.ajax4jsf.webapp.BaseFilter.processUploadsAndHandleRequest(BaseFilter.java:390)
    at org.ajax4jsf.webapp.BaseFilter.doFilter(BaseFilter.java:517)
    at org.jboss.seam.web.Ajax4jsfFilter.doFilter(Ajax4jsfFilter.java:56)
    at org.jboss.seam.servlet.SeamFilter$FilterChainImpl.doFilter(SeamFilter.java:69)
    at org.jboss.seam.web.LoggingFilter.doFilter(LoggingFilter.java:58)
    at org.jboss.seam.servlet.SeamFilter$FilterChainImpl.doFilter(SeamFilter.java:69)
    at org.jboss.seam.web.HotDeployFilter.doFilter(HotDeployFilter.java:53)
    at org.jboss.seam.servlet.SeamFilter$FilterChainImpl.doFilter(SeamFilter.java:69)
    at org.jboss.seam.servlet.SeamFilter.doFilter(SeamFilter.java:158)
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235)
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
    at org.jboss.web.tomcat.filters.ReplyHeaderFilter.doFilter(ReplyHeaderFilter.java:96)
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235)
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
    at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:230)
    at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:175)
    at org.jboss.web.tomcat.security.SecurityAssociationValve.invoke(SecurityAssociationValve.java:179)
    at org.jboss.web.tomcat.security.JaccContextValve.invoke(JaccContextValve.java:84)
    at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:127)
    at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:102)
    at org.jboss.web.tomcat.service.jca.CachedConnectionValve.invoke(CachedConnectionValve.java:157)
    at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109)
    at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:262)
    at org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:844)
    at org.apache.coyote.http11.Http11Protocol$Http11ConnectionHandler.process(Http11Protocol.java:583)
    at org.apache.tomcat.util.net.JIoEndpoint$Worker.run(JIoEndpoint.java:446)
    at java.lang.Thread.run(Thread.java:619)
   

   
   
   However, I'm quite certain that I'm logged in as I can navigate the system, and that requires a valid login.
   
   I'm unsure of where to look next.
   
   

[djn]

Hi again.

I've finally been having time to investigate further. My problems could be related to how the JSFUnit conversation cache is updated. But it is a long shot.

The NotLoggedInException in the "handledException" conversation variable might come from me requiring a login to the page. I'm guessing that JSFUnit first hits the page specified by the WebClientSpec and then uses the SimpleInitialRequestStrategy to log in. However, the handledException is not removed from the conversation cache.

I've revised my session and conversation cache printing to the following:

 while (attributeNames.hasMoreElements()) {
 String name = (String) attributeNames.nextElement();
 if (name.contains("CONVERSATION")) {
 Object attribute = s.getAttribute(name);
 log.debug("session key: " + name);
 log.debug("session attribute: " + attribute.getClass());
 }
 }

 HashMap cache = (HashMap) s.getAttribute("org.jboss.jsfunit.seam.JSFUnitLifecycle.SEAM_CONVERSATION_CACHE");
 for (Object k : cache.keySet()) {
 Object v = cache.get(k);
 log.debug("Conversation key: " + k);
 log.debug("Conversation value class: " + v.getClass());
 }

Giving the output for the session:

14:29:44,877 DEBUG [ReportEditTest] session key: org.jboss.seam.CONVERSATION#198$org.jboss.seam.core.conversation
14:29:44,878 DEBUG [ReportEditTest] session attribute: class org.jboss.seam.core.Conversation
14:29:44,878 DEBUG [ReportEditTest] session key: org.jboss.seam.CONVERSATION#198$userGroupFiltering
14:29:44,878 DEBUG [ReportEditTest] session attribute: class com.blipsystems.blipzones.web.action.report.UserGroupFilteringWrapper_$$_javassist_20
14:29:44,878 DEBUG [ReportEditTest] session key: org.jboss.seam.CONVERSATION#198$blipZonesConfigEntityManager
14:29:44,879 DEBUG [ReportEditTest] session attribute: class org.jboss.seam.persistence.ManagedPersistenceContext
14:29:44,879 DEBUG [ReportEditTest] session key: org.jboss.seam.CONVERSATION#198$org.jboss.seam.persistence.persistenceContexts
14:29:44,879 DEBUG [ReportEditTest] session attribute: class org.jboss.seam.persistence.PersistenceContexts
14:29:44,879 DEBUG [ReportEditTest] session key: org.jboss.seam.CONVERSATION#198$org.jboss.seam.ui.EntityConverter
14:29:44,879 DEBUG [ReportEditTest] session attribute: class org.jboss.seam.ui.EntityConverter
14:29:44,879 DEBUG [ReportEditTest] session key: org.jboss.jsfunit.seam.JSFUnitLifecycle.SEAM_CONVERSATION_CACHE
14:29:44,879 DEBUG [ReportEditTest] session attribute: class java.util.HashMap
14:29:44,879 DEBUG [ReportEditTest] session key: org.jboss.seam.CONVERSATION#198$org.jboss.seam.international.statusMessages
14:29:44,879 DEBUG [ReportEditTest] session attribute: class org.jboss.seam.faces.FacesMessages
14:29:44,879 DEBUG [ReportEditTest] session key: org.jboss.seam.CONVERSATION#198$routeAnalysis
14:29:44,880 DEBUG [ReportEditTest] session attribute: class org.jboss.seam.contexts.EntityBean
14:29:44,880 DEBUG [ReportEditTest] session key: org.jboss.seam.CONVERSATION#198$report
14:29:44,880 DEBUG [ReportEditTest] session attribute: class org.jboss.seam.contexts.EntityBean
14:29:44,880 DEBUG [ReportEditTest] session key: org.jboss.seam.CONVERSATION#198$routeAnalysisHome
14:29:44,880 DEBUG [ReportEditTest] session attribute: class com.blipsystems.blipzones.web.action.report.RouteAnalysisHome_$$_javassist_12
14:29:44,880 DEBUG [ReportEditTest] session key: org.jboss.seam.CONVERSATION#198$reportHome
14:29:44,880 DEBUG [ReportEditTest] session attribute: class com.blipsystems.blipzones.web.action.report.ReportHome_$$_javassist_11

For the jsfunit conversation cache

14:29:44,880 DEBUG [ReportEditTest] Conversation key: org.jboss.seam.handledException
14:29:44,881 DEBUG [ReportEditTest] Conversation value class: class org.jboss.seam.security.NotLoggedInException
14:29:44,881 DEBUG [ReportEditTest] Conversation key: blipZonesConfigEntityManager
14:29:44,881 DEBUG [ReportEditTest] Conversation value class: class org.jboss.seam.persistence.ManagedPersistenceContext
14:29:44,881 DEBUG [ReportEditTest] Conversation key: org.jboss.seam.faces.redirect
14:29:44,881 DEBUG [ReportEditTest] Conversation value class: class org.jboss.seam.faces.Redirect
14:29:44,881 DEBUG [ReportEditTest] Conversation key: routeAnalysisHome
14:29:44,881 DEBUG [ReportEditTest] Conversation value class: class com.blipsystems.blipzones.web.action.report.RouteAnalysisHome_$$_javassist_12
14:29:44,881 DEBUG [ReportEditTest] Conversation key: org.jboss.seam.caughtException
14:29:44,881 DEBUG [ReportEditTest] Conversation value class: class org.jboss.seam.security.NotLoggedInException
14:29:44,882 DEBUG [ReportEditTest] Conversation key: org.jboss.seam.persistence.persistenceContexts
14:29:44,882 DEBUG [ReportEditTest] Conversation value class: class org.jboss.seam.persistence.PersistenceContexts
14:29:44,882 DEBUG [ReportEditTest] Conversation key: org.jboss.seam.core.conversation
14:29:44,882 DEBUG [ReportEditTest] Conversation value class: class org.jboss.seam.core.Conversation
14:29:44,882 DEBUG [ReportEditTest] Conversation key: reportHome
14:29:44,882 DEBUG [ReportEditTest] Conversation value class: class com.blipsystems.blipzones.web.action.report.ReportHome_$$_javassist_11
14:29:44,882 DEBUG [ReportEditTest] Conversation key: org.jboss.seam.international.statusMessages
14:29:44,882 DEBUG [ReportEditTest] Conversation value class: class org.jboss.seam.faces.FacesMessages

Clearly, there are discrepancies between the variables in the jsfunit cache and in the session CONVERSATION#198.

Any input is greatly appreciated.

Regards,
Daniel

[ssilvert]

The way this works is that at the end of the JSF lifecycle I call org.jboss.seam.contexts.Contexts.getConversationContext(). So any object returned by getConversationContext().getNames() is put into JSFUnit's conversation cache. If Seam is not returning all the names (for whatever reason) then there would be a discrepancy.

You didn't say when you were checking the cache. If you are checking from a JSFUnit test then the two should be in sync unless Seam is not giving me all the names. If you are checking DURING a JSF request then then JSFUnit's cache and Seam's conversation objects would be out of sync.

Furthermore, it is possible that Seam is updating the conversation in a filter after the FacesServlet is done. If so, then that could also explain the difference. JSFUnit is updating its cache at the end of the JSF lifecycle.

Stan

[djn]

Hi Stan, and thank you very much for your reply.

The checks for the cache occurs in a JSFUnit testcase, after I've logged in, navigated to the correct page and clicked the checkbox a few times.

I'll try to reproduce this error in a simple jsfunit app.

Regards,
./Daniel

[ssilvert]

Any luck on this? A sample app would be very helpful.

Stan

[djn]

Hi.

It is on my todo - however, other issues both at work and at home require my attention at the moment.

I'm guessing I will have time to investigate further this weekend.

Regards,

./Daniel

[djn]

Hi.

Unplanned freetime happened to day :-) So I went ahead and created a sample app which demonstrates the differences between JSFUnit conversation cache and Seam convesation contexts.

It is a large hack, but the output in the logs shows the differences.

The app is approx 870kb zipped, can I mail it?

Regards,
./Daniel

[ssilvert]

Yes. Feel free to mail it to me.

So what will I be looking at? For this to be a JSFUnit bug, I assume the following must be demonstrated (Please correct my assumptions if they are wrong):

1) I submit a request (using AJAX?)
2) There is an object in conversation scope that still exists in conversation scope when the request is done.
3) I call server.getManagedBeanValue("#{myobject}") where #{myobject} resolves to the object from step #2.
4) The call in step #3 returns null.

Just because we hack into the session and see a reference, doesn't mean that step #2 is true. I can't be certain about how Seam is managing the conversation. So to double-check, we should really have a step #5 that submits a request with something like a phase listener that verifies that Seam thinks #{myobject} is still alive in the conversation.

Note that I'm not doubting that you have found a problem. I'm betting that you have. But I just want to make sure we know what we are dealing with. Under the hood, Seam is really, really complicated. So it's hard to know what is going on.

Stan

[djn]

Hi.

Sorry for the period of silence.

1) a long running conversation is started, by clicking a button or navigating to a page. The conversation scoped object is used to render the first page.
2) yes, as the object is also used on page two of a multipage conversation.
3) yes.
4) yes, unless called from page two of the wizard, as my example code demonstrates.

As the object is reachable on page two of the wizard, I concluded that the object is in the conversation. I haven't used a phaselistener to double check.

Poking around, I have a hunch that the issue is related to @Factory components and how these are constructed. Perhaps Seam treats those differently?

I will mail the application today.

Regards,
./Daniel

[ssilvert]

Thanks Daniel. I'll be looking at it today.

Stan

[ssilvert]

Hi Daniel,

Sorry this is taking so long, but I had to change the way I was finding things in conversation scope. Your sample app was a huge help!

Can you try out this snapshot?
http://snapshots.jboss.org/maven2/org/jboss/jsfunit/jboss-jsfunit-core/1.1.0.GA-SNAPSHOT/jboss-jsfunit-core-1.1.0.GA-20090501.141030-4.jar

Stan

[djn]

Hi Stan.

Indeed, the snapshot solves the issue in my sample app. It seems that the session scoped JSFUnit conversation cache is gone?

It is also looking good on our primary project.

Thank you :-)

Regards,
./Daniel

[ssilvert]

I don't use the session scoped conversation cache any more. I have to rebuild it every time it is needed. After I get some feedback from the Seam team I might look into how to optimize that.

Glad it is working for you now.

Stan