conversions and AJAX calls

[Juza Petr]

Hello,
I have please problem with conversations and AJAX calls.
I use grid view component from NetAdvantage
(http://java.samples.infragistics.com/NetAdvantage/JSF/2008.1/featurebro
wser/webgrid/rowSelection/index.faces) that is AJAX-based (pagination,
sorting).

I have detail page with one grid view. There is detailBean related to
detail page set with "conversation.access" scope.

I see from logs this behavior:
1) user visits detail page, conversation starts
2) user clicks to go to next page on grid view, AJAX call is processed
-> conversation is deleted!
3) user clicks to go to next page on grid view -> error occures because
detailBean has wrong data, because new conversation is created.

I don't know why this happen because detailBean is called during AJAX
call.

I also attach some HTTP headers from AJAX call:
(Request-Line) POST /rmt/assetDetail.faces?conversationContext=1
HTTP/1.1
Host localhost:8080
Keep-Alive 300
Connection keep-alive
Content-Type application/x-www-form-urlencoded; charset=UTF-8
Referer
http://localhost:8080/rmt/assetDetail.faces?conversationContext=1
Content-Length 19939
Cookie JSESSIONID=010F3FDC8F110E8A52707E12EDBD4672
Pragma no-cache
Cache-Control no-cacheconversation.access

I would appreciate any help.
Thank you in advance,
PETER

[Simon Kitching]

Hi Petr,

Juza Petr schrieb:

> Hello,
> I have please problem with conversations and AJAX calls.
> I use grid view component from NetAdvantage
> (http://java.samples.infragistics.com/NetAdvantage/JSF/2008.1/featurebro
> wser/webgrid/rowSelection/index.faces) that is AJAX-based (pagination,
> sorting).
>
> I have detail page with one grid view. There is detailBean related to
> detail page set with "conversation.access" scope.
>
> I see from logs this behavior:
> 1) user visits detail page, conversation starts
> 2) user clicks to go to next page on grid view, AJAX call is processed
> -> conversation is deleted!
> 3) user clicks to go to next page on grid view -> error occures because
> detailBean has wrong data, because new conversation is created.
>
> I don't know why this happen because detailBean is called during AJAX
> call.
>
> I also attach some HTTP headers from AJAX call:
> (Request-Line) POST /rmt/assetDetail.faces?conversationContext=1
> HTTP/1.1
> Host localhost:8080
> Keep-Alive 300
> Connection keep-alive
> Content-Type application/x-www-form-urlencoded; charset=UTF-8
> Referer
> http://localhost:8080/rmt/assetDetail.faces?conversationContext=1
> Content-Length 19939
> Cookie JSESSIONID=010F3FDC8F110E8A52707E12EDBD4672
> Pragma no-cache
> Cache-Control no-cacheconversation.access
>
> I would appreciate any help.
> Thank you in advance,
> PETER
>
>  

First, when sending emails to the myfaces list, please put the project
name in the email subject. We now have a lot of different projects
sharing this mailing list, and that ensures that people can see which
emails are about the projects they are involved in. I've already
modified the subject line of this reply...

This is going to be a rather tricky one to diagnose I think.

You say "detailBean is called during AJAX call". Can you please provide
further details on this?

Please also enable debug-level logging for the category
"org.apache.myfaces.orchestra" and check those messages for anything useful.

Regards, Simon

[Juza Petr]

You say "detailBean is called during AJAX call". Can you please provide
further details on this?

When I put breakpoint into detailBean a see that execution is stopped in
that place.

I attach some debug information:
Bean started ...
2008-08-27 14:59:18,593 DEBUG
[org.apache.myfaces.orchestra.conversation.spring.OrchestraAdvisorBeanPo
stProcessor]: Processing scope [conversation.access]
2008-08-27 14:59:18,593 DEBUG
[org.springframework.aop.framework.autoproxy.AbstractAutoProxyCreator]:
Creating implicit proxy for bean 'assetDetailController' with 0 common
interceptors and 1 specific interceptors
2008-08-27 14:59:18,593 DEBUG
[org.apache.myfaces.orchestra.conversation.Conversation]: put bean to
conversation:org.springframework.beans.factory.support.DisposableBeanAda
pter@8371737(bean=org.apache.myfaces.orchestra.conversation.spring.Abstr
actSpringOrchestraScope$1@996f0e)
2008-08-27 14:59:18,593 DEBUG
[org.apache.myfaces.orchestra.conversation.Conversation]: put bean to
conversation:assetDetailController(bean=com.anect.rmt.web.controllers.as
sets.AssetDetailController@14a0698)

2008-08-27 14:59:22,496 DEBUG
[org.apache.myfaces.orchestra.lib.jsf.OrchestraFacesContextFactory]:
getFacesContext: entry
2008-08-27 14:59:22,496 DEBUG
[org.apache.myfaces.orchestra.lib.jsf.OrchestraFacesContextFactory]:
getFacesContext: creating custom instance
2008-08-27 14:59:22,496 DEBUG
[org.apache.myfaces.orchestra.lib.jsf.OrchestraFacesContextFactory$1]:
getFacesContext: running inner constructor
2008-08-27 14:59:22,496 DEBUG
[org.apache.myfaces.orchestra.lib.jsf.OrchestraFacesContextFactory$1]:
Running inithandler of type
org.apache.myfaces.orchestra.lib.jsf.ContextLockRequestHandler
2008-08-27 14:59:22,496 DEBUG
[org.apache.myfaces.orchestra.lib.jsf.OrchestraFacesContextFactory$1]:
Running inithandler of type
org.apache.myfaces.orchestra.lib.jsf.FrameworkAdapterRequestHandler
2008-08-27 14:59:22,527 DEBUG
[org.apache.myfaces.orchestra.lib.jsf.FrameworkAdapterRequestHandler]:
init
2008-08-27 14:59:22,543 DEBUG
[org.apache.myfaces.orchestra.lib.jsf.FrameworkAdapterRequestHandler]:
creating jsfFrameworkAdapter
2008-08-27 14:59:22,543 DEBUG
[org.apache.myfaces.orchestra.frameworkAdapter.jsf.JsfFrameworkAdapter]:
Beginning request
2008-08-27 14:59:22,543 DEBUG
[org.apache.myfaces.orchestra.lib.jsf.OrchestraFacesContextFactory$1]:
Running inithandler of type
org.apache.myfaces.orchestra.lib.jsf.ConversationManagerRequestHandler
2008-08-27 14:59:22,543 DEBUG
[org.apache.myfaces.orchestra.lib.jsf.OrchestraFacesContextFactory$1]:
Running inithandler of type
org.apache.myfaces.orchestra.lib.jsf.DataSourceLeakRequestHandler
2008-08-27 14:59:22,543 DEBUG
[org.apache.myfaces.el.VariableResolverImpl]: Variable 'assetDetail'
could not be resolved.
2008-08-27 14:59:22,559 DEBUG
[org.apache.myfaces.el.VariableResolverImpl]: Variable
'org.apache.myfaces.orchestra.conversation.FlashScopeManager' could not
be resolved.
2008-08-27 14:59:22,559 DEBUG
[org.apache.myfaces.el.VariableResolverImpl]: Variable
'org.apache.myfaces.orchestra.conversation.FlashScopeManagerConfiguratio
n' could not be resolved.

2008-08-27 14:59:22,574 INFO
[org.apache.catalina.core.ApplicationContext]: INFRAGISTICS: Start
rendering a SmartRefresh request (AJAX call)

2008-08-27 14:59:22,652 DEBUG
[org.apache.myfaces.orchestra.conversation.jsf.AccessScopePhaseListener]
: Clearing access-scoped conversation assetDetailController after
rendering view /assetDetail.jsp
2008-08-27 14:59:22,652 DEBUG
[org.apache.myfaces.orchestra.conversation.Conversation]: destroy
conversation:assetDetailController
Bean destroid ...

PETER

-----Original Message-----
From: Simon Kitching [mailto:skitching@...]
Sent: Wednesday, August 27, 2008 2:38 PM
To: MyFaces Discussion
Subject: Re: [Orchestra] conversions and AJAX calls

Hi Petr,

Juza Petr schrieb:
> Hello,
> I have please problem with conversations and AJAX calls.
> I use grid view component from NetAdvantage
>
(http://java.samples.infragistics.com/NetAdvantage/JSF/2008.1/featurebro

> wser/webgrid/rowSelection/index.faces) that is AJAX-based (pagination,
> sorting).
>
> I have detail page with one grid view. There is detailBean related to
> detail page set with "conversation.access" scope.
>
> I see from logs this behavior:
> 1) user visits detail page, conversation starts
> 2) user clicks to go to next page on grid view, AJAX call is processed
> -> conversation is deleted!
> 3) user clicks to go to next page on grid view -> error occures

because
> detailBean has wrong data, because new conversation is created.
>
> I don't know why this happen because detailBean is called during AJAX
> call.
>
> I also attach some HTTP headers from AJAX call:
> (Request-Line) POST
/rmt/assetDetail.faces?conversationContext=1

> HTTP/1.1
> Host localhost:8080
> Keep-Alive 300
> Connection keep-alive
> Content-Type application/x-www-form-urlencoded; charset=UTF-8
> Referer
> http://localhost:8080/rmt/assetDetail.faces?conversationContext=1
> Content-Length 19939
> Cookie JSESSIONID=010F3FDC8F110E8A52707E12EDBD4672
> Pragma no-cache
> Cache-Control no-cacheconversation.access
>
> I would appreciate any help.
> Thank you in advance,
> PETER
>
>  

First, when sending emails to the myfaces list, please put the project
name in the email subject. We now have a lot of different projects
sharing this mailing list, and that ensures that people can see which
emails are about the projects they are involved in. I've already
modified the subject line of this reply...

This is going to be a rather tricky one to diagnose I think.

You say "detailBean is called during AJAX call". Can you please provide
further details on this?

Please also enable debug-level logging for the category
"org.apache.myfaces.orchestra" and check those messages for anything
useful.

Regards, Simon

[Simon Kitching]

> -----Original Message-----
> From: Simon Kitching [mailto:skitching@...]
> Sent: Wednesday, August 27, 2008 2:38 PM
> To: MyFaces Discussion
> Subject: Re: [Orchestra] conversions and AJAX calls
>
> Hi Petr,
>
> Juza Petr schrieb:
>  
>> Hello,
>> I have please problem with conversations and AJAX calls.
>> I use grid view component from NetAdvantage
>>
>>    
> (http://java.samples.infragistics.com/NetAdvantage/JSF/2008.1/featurebro
>  
>> wser/webgrid/rowSelection/index.faces) that is AJAX-based (pagination,
>> sorting).
>>
>> I have detail page with one grid view. There is detailBean related to
>> detail page set with "conversation.access" scope.
>>
>> I see from logs this behavior:
>> 1) user visits detail page, conversation starts
>> 2) user clicks to go to next page on grid view, AJAX call is processed
>> -> conversation is deleted!
>> 3) user clicks to go to next page on grid view -> error occures
>>    
> because
>  
>> detailBean has wrong data, because new conversation is created.
>>
>> I don't know why this happen because detailBean is called during AJAX
>> call.
>>
>> I also attach some HTTP headers from AJAX call:
>> (Request-Line) POST
>>    
> /rmt/assetDetail.faces?conversationContext=1
>  
>> HTTP/1.1
>> Host localhost:8080
>> Keep-Alive 300
>> Connection keep-alive
>> Content-Type application/x-www-form-urlencoded; charset=UTF-8
>> Referer
>> http://localhost:8080/rmt/assetDetail.faces?conversationContext=1
>> Content-Length 19939
>> Cookie JSESSIONID=010F3FDC8F110E8A52707E12EDBD4672
>> Pragma no-cache
>> Cache-Control no-cacheconversation.access
>>
>> I would appreciate any help.
>> Thank you in advance,
>> PETER
>>
>>  
>>    
> First, when sending emails to the myfaces list, please put the project
> name in the email subject. We now have a lot of different projects
> sharing this mailing list, and that ensures that people can see which
> emails are about the projects they are involved in. I've already
> modified the subject line of this reply...
>
> This is going to be a rather tricky one to diagnose I think.
>
> You say "detailBean is called during AJAX call". Can you please provide
> further details on this?
>
> Please also enable debug-level logging for the category
> "org.apache.myfaces.orchestra" and check those messages for anything
> useful.
>
> Regards, Simon
>
>
>  

When I put breakpoint into detailBean a see that execution is stopped in
that place.

I attach some debug information:
Bean started ...
2008-08-27 14:59:18,593 DEBUG
[org.apache.myfaces.orchestra.conversation.spring.OrchestraAdvisorBeanPo
stProcessor]: Processing scope [conversation.access]
2008-08-27 14:59:18,593 DEBUG
[org.springframework.aop.framework.autoproxy.AbstractAutoProxyCreator]:
Creating implicit proxy for bean 'assetDetailController' with 0 common
interceptors and 1 specific interceptors
2008-08-27 14:59:18,593 DEBUG
[org.apache.myfaces.orchestra.conversation.Conversation]: put bean to
conversation:org.springframework.beans.factory.support.DisposableBeanAda
pter@8371737(bean=org.apache.myfaces.orchestra.conversation.spring.Abstr
actSpringOrchestraScope$1@996f0e)
2008-08-27 14:59:18,593 DEBUG
[org.apache.myfaces.orchestra.conversation.Conversation]: put bean to
conversation:assetDetailController(bean=com.anect.rmt.web.controllers.as
sets.AssetDetailController@14a0698)

2008-08-27 14:59:22,496 DEBUG
[org.apache.myfaces.orchestra.lib.jsf.OrchestraFacesContextFactory]:
getFacesContext: entry
2008-08-27 14:59:22,496 DEBUG
[org.apache.myfaces.orchestra.lib.jsf.OrchestraFacesContextFactory]:
getFacesContext: creating custom instance
2008-08-27 14:59:22,496 DEBUG
[org.apache.myfaces.orchestra.lib.jsf.OrchestraFacesContextFactory$1]:
getFacesContext: running inner constructor
2008-08-27 14:59:22,496 DEBUG
[org.apache.myfaces.orchestra.lib.jsf.OrchestraFacesContextFactory$1]:
Running inithandler of type
org.apache.myfaces.orchestra.lib.jsf.ContextLockRequestHandler
2008-08-27 14:59:22,496 DEBUG
[org.apache.myfaces.orchestra.lib.jsf.OrchestraFacesContextFactory$1]:
Running inithandler of type
org.apache.myfaces.orchestra.lib.jsf.FrameworkAdapterRequestHandler
2008-08-27 14:59:22,527 DEBUG
[org.apache.myfaces.orchestra.lib.jsf.FrameworkAdapterRequestHandler]:
init
2008-08-27 14:59:22,543 DEBUG
[org.apache.myfaces.orchestra.lib.jsf.FrameworkAdapterRequestHandler]:
creating jsfFrameworkAdapter
2008-08-27 14:59:22,543 DEBUG
[org.apache.myfaces.orchestra.frameworkAdapter.jsf.JsfFrameworkAdapter]:
Beginning request
2008-08-27 14:59:22,543 DEBUG
[org.apache.myfaces.orchestra.lib.jsf.OrchestraFacesContextFactory$1]:
Running inithandler of type
org.apache.myfaces.orchestra.lib.jsf.ConversationManagerRequestHandler
2008-08-27 14:59:22,543 DEBUG
[org.apache.myfaces.orchestra.lib.jsf.OrchestraFacesContextFactory$1]:
Running inithandler of type
org.apache.myfaces.orchestra.lib.jsf.DataSourceLeakRequestHandler
2008-08-27 14:59:22,543 DEBUG
[org.apache.myfaces.el.VariableResolverImpl]: Variable 'assetDetail'
could not be resolved.
2008-08-27 14:59:22,559 DEBUG
[org.apache.myfaces.el.VariableResolverImpl]: Variable
'org.apache.myfaces.orchestra.conversation.FlashScopeManager' could not
be resolved.
2008-08-27 14:59:22,559 DEBUG
[org.apache.myfaces.el.VariableResolverImpl]: Variable
'org.apache.myfaces.orchestra.conversation.FlashScopeManagerConfiguratio
n' could not be resolved.

2008-08-27 14:59:22,574 INFO
[org.apache.catalina.core.ApplicationContext]: INFRAGISTICS: Start
rendering a SmartRefresh request (AJAX call)

2008-08-27 14:59:22,652 DEBUG
[org.apache.myfaces.orchestra.conversation.jsf.AccessScopePhaseListener]
: Clearing access-scoped conversation assetDetailController after
rendering view /assetDetail.jsp
2008-08-27 14:59:22,652 DEBUG
[org.apache.myfaces.orchestra.conversation.Conversation]: destroy
conversation:assetDetailController
Bean destroid ...

PETER



Please don't use "top-posting"
(http://en.wikipedia.org/wiki/Top-posting) when someone has already
replied in "inline-posting" style. It is rather rude..(people using
mobile phones etc. are forgiven however)

The breakpoint shows that *some instance* of that bean has been invoked.
Are you quite sure that it really is the instance that is in the
conversation? Have a look at the stack-trace when your breakpoint is
triggered; does it show any Orchestra classes in the stack? Which ones?

Please also show the relevant spring configuration. You say for example
that your bean is "detailBean" but the access-conversation that got
destroyed was called "assetDetailController"....


Regards,
Simon

[Juza Petr]

Hello,
I see this from log:
1) detail page is created -> new assetDetailController (@1aa4bb4) is
created and new conversation is created
2) transfer to next page in grid view -> assetDetailController
(@1aa4bb4) is called, but the conversation is cleared at the end.
3) transfer to next page in grid view -> new assetDetailController
(@13699a61aa4bb4) is created and also new conversation

Here are my (relevant) config files:
Orchestra setting:
  <!-- 1. initialization of all orchestra modules (required for core15
module) -->
  <import resource="classpath*:/META-INF/spring-orchestra-init.xml" />

  <!-- 2. the conversation scopes definition -->
  <bean
class="org.springframework.beans.factory.config.CustomScopeConfigurer">
    <property name="scopes">
      <map>
        <entry key="conversation.manual">
          <bean
class="org.apache.myfaces.orchestra.conversation.spring.SpringConversati
onScope">
            <property name="timeout" value="30" />
          </bean>
        </entry>

        <entry key="conversation.access">
          <bean
class="org.apache.myfaces.orchestra.conversation.spring.SpringConversati
onScope">
            <property name="timeout" value="30" />
            <property name="lifetime" value="access"/>
          </bean>
        </entry>
      </map>
    </property>
  </bean>

Detail controller (note: I use "detailBean" name for simplification
only):
  <bean id="assetDetailController" parent="baseAssetController"
scope="conversation.access"
 
class="com.anect.rmt.web.controllers.assets.AssetDetailController">
  </bean>

JSF config:
 
<variable-resolver>org.springframework.web.jsf.SpringBeanVariableResolve
r</variable-resolver>

web.xml
  <listener>
 
<listener-class>org.springframework.web.context.request.RequestContextLi
stener</listener-class>
  </listener>
 
  <listener>
 
<listener-class>org.apache.myfaces.orchestra.conversation.servlet.Conver
sationManagerSessionListener</listener-class>
  </listener>  


I also attach logs from transfer to next page:
2008-08-28 07:42:47,376 DEBUG: Bound request context to thread:
org.apache.catalina.connector.RequestFacade@12c7887
2008-08-28 07:42:47,376 DEBUG: getFacesContext: entry
2008-08-28 07:42:47,376 DEBUG: getFacesContext: creating custom instance
2008-08-28 07:42:47,376 DEBUG: getFacesContext: running inner
constructor
2008-08-28 07:42:47,376 DEBUG: Running inithandler of type
org.apache.myfaces.orchestra.lib.jsf.ContextLockRequestHandler
2008-08-28 07:42:47,376 DEBUG: Running inithandler of type
org.apache.myfaces.orchestra.lib.jsf.FrameworkAdapterRequestHandler
2008-08-28 07:42:47,376 DEBUG: init
2008-08-28 07:42:47,376 DEBUG: creating jsfFrameworkAdapter
2008-08-28 07:42:47,376 DEBUG: Beginning request
2008-08-28 07:42:47,376 DEBUG: Running inithandler of type
org.apache.myfaces.orchestra.lib.jsf.ConversationManagerRequestHandler
2008-08-28 07:42:47,408 DEBUG: Running inithandler of type
org.apache.myfaces.orchestra.lib.jsf.DataSourceLeakRequestHandler
2008-08-28 07:42:47,408 DEBUG: Attempting to resolve variable
'traceData' in Spring ApplicationContext
2008-08-28 07:42:47,408 DEBUG: Attempting to resolve variable
'traceData' via original VariableResolver
2008-08-28 07:42:47,408 DEBUG: Successfully resolved variable
'traceData' via original VariableResolver
2008-08-28 07:42:47,408 DEBUG: Attempting to resolve variable
'org.apache.myfaces.orchestra.viewController.ViewControllerManager' in
Spring ApplicationContext
2008-08-28 07:42:47,408 DEBUG: Successfully resolved variable
'org.apache.myfaces.orchestra.viewController.ViewControllerManager' in
Spring ApplicationContext
2008-08-28 07:42:47,408 DEBUG: Returning cached instance of singleton
bean 'org.apache.myfaces.orchestra.viewController.ViewControllerManager'
2008-08-28 07:42:47,439 DEBUG: Returning cached instance of singleton
bean 'org.apache.myfaces.orchestra.viewController.ViewControllerManager'
2008-08-28 07:42:47,439 DEBUG: Attempting to resolve variable
'assetDetail' in Spring ApplicationContext
2008-08-28 07:42:47,439 DEBUG: Attempting to resolve variable
'assetDetail' via original VariableResolver
2008-08-28 07:42:47,439 DEBUG: Attempting to resolve variable
'assetDetailController' in Spring ApplicationContext
2008-08-28 07:42:47,439 DEBUG: Successfully resolved variable
'assetDetailController' in Spring ApplicationContext
2008-08-28 07:42:47,439 DEBUG: Attempting to resolve variable
'org.apache.myfaces.orchestra.conversation.FlashScopeManager' in Spring
ApplicationContext
2008-08-28 07:42:47,439 DEBUG: Attempting to resolve variable
'org.apache.myfaces.orchestra.conversation.FlashScopeManager' via
original VariableResolver
2008-08-28 07:42:47,439 DEBUG: Variable
'org.apache.myfaces.orchestra.conversation.FlashScopeManager' could not
be resolved.
2008-08-28 07:42:47,439 DEBUG: Attempting to resolve variable
'org.apache.myfaces.orchestra.conversation.FlashScopeManagerConfiguratio
n' in Spring ApplicationContext
2008-08-28 07:42:47,439 DEBUG: Attempting to resolve variable
'org.apache.myfaces.orchestra.conversation.FlashScopeManagerConfiguratio
n' via original VariableResolver
2008-08-28 07:42:47,439 DEBUG: Variable
'org.apache.myfaces.orchestra.conversation.FlashScopeManagerConfiguratio
n' could not be resolved.
2008-08-28 07:42:47,439 DEBUG: Attempting to resolve variable
'org.apache.myfaces.orchestra.conversation.AccessScopeManager' in Spring
ApplicationContext
2008-08-28 07:42:47,439 DEBUG: Successfully resolved variable
'org.apache.myfaces.orchestra.conversation.AccessScopeManager' in Spring
ApplicationContext
2008-08-28 07:42:47,439 DEBUG: Creating instance of bean
'org.apache.myfaces.orchestra.conversation.AccessScopeManager'
2008-08-28 07:42:47,455 DEBUG: Returning cached instance of singleton
bean
'org.apache.myfaces.orchestra.conversation.AccessScopeManagerConfigurati
on'
2008-08-28 07:42:47,455 DEBUG: Finished creating instance of bean
'org.apache.myfaces.orchestra.conversation.AccessScopeManager'
2008-08-28 07:42:47,455 DEBUG: AssetDetailController is called
com.anect.rmt.web.controllers.assets.AssetDetailController@175d3d7
2008-08-28 07:42:47,455 DEBUG: Attempting to resolve variable
'assetDetailController' in Spring ApplicationContext
2008-08-28 07:42:47,455 DEBUG: Successfully resolved variable
'assetDetailController' in Spring ApplicationContext
2008-08-28 07:42:47,455 DEBUG: AssetDetailController is called
com.anect.rmt.web.controllers.assets.AssetDetailController@175d3d7
2008-08-28 07:42:47,455 DEBUG: Attempting to resolve variable
'facesContext' in Spring ApplicationContext
2008-08-28 07:42:47,455 DEBUG: Attempting to resolve variable
'facesContext' via original VariableResolver
2008-08-28 07:42:47,455 DEBUG: Successfully resolved variable
'facesContext' via original VariableResolver
2008-08-28 07:42:47,455 DEBUG: Attempting to resolve variable
'org.apache.myfaces.orchestra.viewController.ViewControllerManager' in
Spring ApplicationContext
2008-08-28 07:42:47,455 DEBUG: Successfully resolved variable
'org.apache.myfaces.orchestra.viewController.ViewControllerManager' in
Spring ApplicationContext
2008-08-28 07:42:47,455 DEBUG: Returning cached instance of singleton
bean 'org.apache.myfaces.orchestra.viewController.ViewControllerManager'
2008-08-28 07:42:47,455 DEBUG: Attempting to resolve variable
'org.apache.myfaces.orchestra.viewController.ViewControllerManager' in
Spring ApplicationContext
2008-08-28 07:42:47,455 DEBUG: Successfully resolved variable
'org.apache.myfaces.orchestra.viewController.ViewControllerManager' in
Spring ApplicationContext
2008-08-28 07:42:47,455 DEBUG: Returning cached instance of singleton
bean 'org.apache.myfaces.orchestra.viewController.ViewControllerManager'
2008-08-28 07:42:47,455 DEBUG: Attempting to resolve variable
'assetDetailController' in Spring ApplicationContext
2008-08-28 07:42:47,455 DEBUG: Successfully resolved variable
'assetDetailController' in Spring ApplicationContext
2008-08-28 07:42:47,455 DEBUG: AssetDetailController is called
com.anect.rmt.web.controllers.assets.AssetDetailController@175d3d7
2008-08-28 07:42:47,455 DEBUG: Attempting to resolve variable
'assetDetailController' in Spring ApplicationContext
2008-08-28 07:42:47,455 DEBUG: Successfully resolved variable
'assetDetailController' in Spring ApplicationContext
2008-08-28 07:42:47,455 DEBUG: AssetDetailController is called
com.anect.rmt.web.controllers.assets.AssetDetailController@175d3d7
2008-08-28 07:42:47,455 DEBUG: Attempting to resolve variable
'facesContext' in Spring ApplicationContext
2008-08-28 07:42:47,455 DEBUG: Attempting to resolve variable
'facesContext' via original VariableResolver
2008-08-28 07:42:47,455 DEBUG: Successfully resolved variable
'facesContext' via original VariableResolver
2008-08-28 07:42:47,455 DEBUG: Attempting to resolve variable
'org.apache.myfaces.orchestra.viewController.ViewControllerManager' in
Spring ApplicationContext
2008-08-28 07:42:47,455 DEBUG: Successfully resolved variable
'org.apache.myfaces.orchestra.viewController.ViewControllerManager' in
Spring ApplicationContext
2008-08-28 07:42:47,455 DEBUG: Returning cached instance of singleton
bean 'org.apache.myfaces.orchestra.viewController.ViewControllerManager'
2008-08-28 07:42:47,455 DEBUG: Attempting to resolve variable
'org.apache.myfaces.orchestra.viewController.ViewControllerManager' in
Spring ApplicationContext
2008-08-28 07:42:47,455 DEBUG: Successfully resolved variable
'org.apache.myfaces.orchestra.viewController.ViewControllerManager' in
Spring ApplicationContext
2008-08-28 07:42:47,455 DEBUG: Returning cached instance of singleton
bean 'org.apache.myfaces.orchestra.viewController.ViewControllerManager'
2008-08-28 07:42:47,455 DEBUG: Attempting to resolve variable
'assetDetailController' in Spring ApplicationContext
2008-08-28 07:42:47,455 DEBUG: Successfully resolved variable
'assetDetailController' in Spring ApplicationContext
2008-08-28 07:42:47,455 DEBUG: AssetDetailController is called
com.anect.rmt.web.controllers.assets.AssetDetailController@175d3d7
2008-08-28 07:42:47,455 DEBUG: Attempting to resolve variable
'assetDetailController' in Spring ApplicationContext
2008-08-28 07:42:47,455 DEBUG: Successfully resolved variable
'assetDetailController' in Spring ApplicationContext
2008-08-28 07:42:47,455 DEBUG: AssetDetailController is called
com.anect.rmt.web.controllers.assets.AssetDetailController@175d3d7
2008-08-28 07:42:47,455 DEBUG: Attempting to resolve variable
'facesContext' in Spring ApplicationContext
2008-08-28 07:42:47,455 DEBUG: Attempting to resolve variable
'facesContext' via original VariableResolver
2008-08-28 07:42:47,455 DEBUG: Successfully resolved variable
'facesContext' via original VariableResolver
2008-08-28 07:42:47,455 DEBUG: Attempting to resolve variable
'org.apache.myfaces.orchestra.viewController.ViewControllerManager' in
Spring ApplicationContext
2008-08-28 07:42:47,455 DEBUG: Successfully resolved variable
'org.apache.myfaces.orchestra.viewController.ViewControllerManager' in
Spring ApplicationContext
2008-08-28 07:42:47,455 DEBUG: Returning cached instance of singleton
bean 'org.apache.myfaces.orchestra.viewController.ViewControllerManager'
2008-08-28 07:42:47,455 DEBUG: Attempting to resolve variable
'org.apache.myfaces.orchestra.viewController.ViewControllerManager' in
Spring ApplicationContext
2008-08-28 07:42:47,455 DEBUG: Successfully resolved variable
'org.apache.myfaces.orchestra.viewController.ViewControllerManager' in
Spring ApplicationContext
2008-08-28 07:42:47,455 DEBUG: Returning cached instance of singleton
bean 'org.apache.myfaces.orchestra.viewController.ViewControllerManager'
2008-08-28 07:42:47,455 DEBUG: Attempting to resolve variable
'org.apache.myfaces.orchestra.viewController.ViewControllerManager' in
Spring ApplicationContext
2008-08-28 07:42:47,455 DEBUG: Successfully resolved variable
'org.apache.myfaces.orchestra.viewController.ViewControllerManager' in
Spring ApplicationContext
2008-08-28 07:42:47,455 DEBUG: Returning cached instance of singleton
bean 'org.apache.myfaces.orchestra.viewController.ViewControllerManager'
2008-08-28 07:42:47,455 DEBUG: Attempting to resolve variable
'assetDetail' in Spring ApplicationContext
2008-08-28 07:42:47,455 DEBUG: Attempting to resolve variable
'assetDetail' via original VariableResolver
2008-08-28 07:42:47,455 DEBUG: Variable 'assetDetail' could not be
resolved.
2008-08-28 07:42:47,455 DEBUG: Attempting to resolve variable
'org.apache.myfaces.orchestra.viewController.ViewControllerManager' in
Spring ApplicationContext
2008-08-28 07:42:47,455 DEBUG: Successfully resolved variable
'org.apache.myfaces.orchestra.viewController.ViewControllerManager' in
Spring ApplicationContext
2008-08-28 07:42:47,455 DEBUG: Returning cached instance of singleton
bean 'org.apache.myfaces.orchestra.viewController.ViewControllerManager'
2008-08-28 07:42:47,455 INFO : INFRAGISTICS: Start rendering a
SmartRefresh request
2008-08-28 07:42:47,533 DEBUG: Attempting to resolve variable
'assetDetailController' in Spring ApplicationContext
2008-08-28 07:42:47,533 DEBUG: Successfully resolved variable
'assetDetailController' in Spring ApplicationContext
2008-08-28 07:42:47,533 DEBUG: AssetDetailController is called
com.anect.rmt.web.controllers.assets.AssetDetailController@175d3d7
2008-08-28 07:42:47,564 DEBUG: Attempting to resolve variable
'com_infragistics_faces_THEME' in Spring ApplicationContext
2008-08-28 07:42:47,564 DEBUG: Attempting to resolve variable
'com_infragistics_faces_THEME' via original VariableResolver
2008-08-28 07:42:47,564 DEBUG: Variable 'com_infragistics_faces_THEME'
could not be resolved.
2008-08-28 07:42:47,580 DEBUG: Attempting to resolve variable
'org.apache.myfaces.orchestra.viewController.ViewControllerManager' in
Spring ApplicationContext
2008-08-28 07:42:47,580 DEBUG: Successfully resolved variable
'org.apache.myfaces.orchestra.viewController.ViewControllerManager' in
Spring ApplicationContext
2008-08-28 07:42:47,580 DEBUG: Returning cached instance of singleton
bean 'org.apache.myfaces.orchestra.viewController.ViewControllerManager'
2008-08-28 07:42:47,580 DEBUG: Attempting to resolve variable
'org.apache.myfaces.orchestra.viewController.ViewControllerManager' in
Spring ApplicationContext
2008-08-28 07:42:47,580 DEBUG: Successfully resolved variable
'org.apache.myfaces.orchestra.viewController.ViewControllerManager' in
Spring ApplicationContext
2008-08-28 07:42:47,580 DEBUG: Returning cached instance of singleton
bean 'org.apache.myfaces.orchestra.viewController.ViewControllerManager'
2008-08-28 07:42:47,580 DEBUG: Clearing access-scoped conversation
assetDetailController after rendering view /assetDetail.jsp
2008-08-28 07:42:47,580 DEBUG: destroy
conversation:assetDetailController
2008-08-28 07:42:47,580 DEBUG: Invoking destroy() on bean with name
'assetDetailController'
Bean destroid ...
2008-08-28 07:42:47,580 DEBUG: Running release
2008-08-28 07:42:47,580 DEBUG: Ending request
2008-08-28 07:42:47,580 DEBUG: Release completed
2008-08-28 07:42:47,580 DEBUG: Cleared thread-bound request context:
org.apache.catalina.connector.RequestFacade@12c7887

PETER

[Juza Petr]

I found interesting information in log file (at the end of AJAX call):

2008-08-28 14:21:34,622 DEBUG: exiting from lifecycle.execute in
RENDER_RESPONSE(6) because getResponseComplete is true from one of the
before listeners
2008-08-28 14:21:34,622 DEBUG: Clearing access-scoped conversation
assetController after rendering view /assetEdit.jsp

This means that render phase isn't finished but exited. Isn't it problem
for Orchestra?

PETER

[Simon Kitching]

On Thu, 2008-08-28 at 14:24 +0200, Juza Petr wrote:

> I found interesting information in log file (at the end of AJAX call):
>
> 2008-08-28 14:21:34,622 DEBUG: exiting from lifecycle.execute in
> RENDER_RESPONSE(6) because getResponseComplete is true from one of the
> before listeners
> 2008-08-28 14:21:34,622 DEBUG: Clearing access-scoped conversation
> assetController after rendering view /assetEdit.jsp
>
> This means that render phase isn't finished but exited. Isn't it problem
> for Orchestra?

Yes, this could possibly be the problem.

Orchestra regards a conversation as being "accessed" if a method on some
bean in the conversation has been called between calls to
  AccessScopePhaseListener.beforePhase
and
  AccessScopePhaseListener.afterPhase

This of course covers the entire normal render phase, which is when
beans are expected to be accessed.

Now if things are set up so that:
* this ajax phase-listener runs *before* the orchestra one
* the ajax phase-listener walks the component tree to generate the
custom xml output from *within* its beforePhase method
* the ajax phase-listener then calls responseComplete at the end of its
beforePhase method
then a problem will occur.

When a phaselistener calls responseComplete, the actual phase processing
is skipped. But all the beforePhase and afterPhase methods of all
PhaseListeners are still run.

So the conversations will be correctly marked as being "accessed", but
during the ajax listener's beforePhase method call. Then
AccessScopePhaseListener.beforePhase runs *afterwards*. Orchestra of
course expects the accesses to occur during the actual rendering phase -
but in this particular ajax framework, "rendering" has effectively been
moved earlier in time.

Could you please set that breakpoint on the getter method in your bean
again, and see whether the beforePhase method of a PhaseListener
associated with the ajax library is in the call-stack?

You could try renaming file "myfaces-orchestra-core-1.2.jar" to
"aaa-myfaces-orchestra-core-1.2.jar". This might cause the jsf
environment to process the orchestra faces-config first, and therefore
cause its phaselistener to be run before the ajax phaselistener.

If this really is shown to be the problem here, I don't think it really
qualifies as an orchestra bug; rendering is supposed to happen during
the rendering phase, not in the "before phase" processing. Of course
even then it would be nice for Orchestra to work around the issue - but
it is not immediately obvious how. A custom Lifecycle class could
certainly clear the "access" flag at the very start of rendering
(without caring about PhaseListener ordering) but that is a pretty
intrusive solution. If you can confirm this is the problem, though, I
will give the issue some more thought.

Regards,
Simon

[Juza Petr]

Hi Simon,
I renamed "myfaces-orchestra-core-1.2.jar" to
"before-na-orchestra-core.jar" and it helped! Thank you very much Simon.
Where is implemented order of loading faces-config.xml files? Is it
MyFaces feature only?

Note to custom Lifecycle class - it's true that it would be intrusive
solution but still better then using session scope or manual
conversations - this solution is much more instrusive.

Thank you once again.
PETER

[Simon Kitching]

Juza Petr schrieb:
> Hi Simon,
> I renamed "myfaces-orchestra-core-1.2.jar" to
> "before-na-orchestra-core.jar" and it helped! Thank you very much Simon.
> Where is implemented order of loading faces-config.xml files? Is it
> MyFaces feature only?
>  
It is not officially part of the JSF specification, but there is an
"unofficial" agreement between all JSF implementations that
faces-config.xml files should be processed in the alphabetical order of
the jarfile name. So this behaviour is portable.
> Note to custom Lifecycle class - it's true that it would be intrusive
> solution but still better then using session scope or manual
> conversations - this solution is much more instrusive.
>  

I have created issue
  http://issues.apache.org/jira/browse/ORCHESTRA-29
for this.

I have also committed a patch that will hopefully solve this, by simply
checking facesContext.getResponseComplete() and skipping the
access-scope checking in that case. To test this patch you will need to
check out the latest orchestra code from
   http://svn.apache.org/repos/asf/myfaces/orchestra/trunk/core
and build it with maven2. Or wait for a nightly build from 29 Aug or
later to show up here:
 http://people.apache.org/repo/m2-snapshot-repository/org/apache/myfaces/orchestra/myfaces-orchestra-core/1.3-SNAPSHOT/

Regards,
Simon

[Juza Petr]

Hello Simon,
I tried latest patch and it works fine for previous problem but I found
new one.

AJAX calls mentioned in previous communication were for sorting and
pagination of the table. When I want to search for new data of the data
then AJAX call is little bit different - JSF lifecycle is exited in
INVOKE_APPLICATION phase, look at log:

2008-08-30 06:55:22,731 DEBUG: entering INVOKE_APPLICATION(5) in
org.apache.myfaces.lifecycle.LifecycleImpl
... (some bussines logic)
2008-08-30 06:55:23,450 DEBUG: exiting from lifecycle.execute in
INVOKE_APPLICATION(5) because getRenderResponse is true from one of the
after listeners
2008-08-30 06:55:23,450 DEBUG: entering RENDER_RESPONSE(6) in
org.apache.myfaces.lifecycle.LifecycleImpl
2008-08-30 06:55:23,450 INFO : INFRAGISTICS: Start rendering a
SmartRefresh request
2008-08-30 06:55:23,497 DEBUG: exiting from lifecycle.execute in
RENDER_RESPONSE(6) because getResponseComplete is true from one of the
before listeners
2008-08-30 06:55:23,497 DEBUG: Clearing access-scoped conversation
assetController after rendering view /assetEdit.jsp
2008-08-30 06:55:23,497 DEBUG: destroy conversation:assetController

And there is still here "the problem".

Best regards,
PETER