Linking to parent Myfaces 2 compatibility case.

Assigning to Mircea to investigate conflict with Push. To replicate run Auction and/or AuctionMonitor examples with Push deactivated and then with Push activated.

Deryk

Looks like MyFaces uses a linked list of view state keys to track the changes in the view state. When push is present new keys are sent back to the client but the submitted forms used by the different controls are still using the old view state key (set during page load). The server side will restore the state corresponding to these old keys which do not correspond anymore to the state of the client.

The fix updates the participating forms to use the latest returned view state key so that the next submit will work with the latest saved state.

Issue https://issues.apache.org/jira/browse/MYFACES-2799 might explain the behavior we're seeing.

More related talk: http://permalink.gmane.org/gmane.comp.java.jsr314/71

From what I can tell, the view states now seem to be properly aligned for all the forms but it doesn't appear to have fixed all the issues related to push. For example, the progress monitor in compat showcase still doesn't update reliably (or at all), chat doesn't work in auctionMonitor, and interaction in auction is still a bit dodgy.

After fiddling with a bunch of things, one thing that did improve things immensely was changing anything ViewScoped to SessionScoped. After doing that, the progress monitor updated as designed and chat worked again. Interaction with auction was still unpredictable but that app doesn't use any compat components - only stock so there may be a separate issue involved.

Using a simplified version of the progress bar example, we can see the unique treatment of View-scoped beans in MyFaces. I instrumented the constructor of the OutputProgressController (annotated with View scope) as well as added logging to a PostConstruct method:

The first time it is needed, the OutputProgressController is created and the PostConstruct method is called as expected:

INFO: BEFORE RENDER_RESPONSE(6) from /compat-basic/progress.jsf
OutputProgressController: constructor called for org.icefaces.demo.basic.progress.OutputProgressController@787f189
@javax.faces.bean.ManagedBean(name=outputProgressController, eager=false)
@javax.faces.bean.ViewScoped()
OutputProgressController.afterConstruction: org.icefaces.demo.basic.progress.OutputProgressController@787f189
OutputProgressController.getPercentComplete:
thread : Thread["http-bio-8080"-exec-69,5,main]
controller: org.icefaces.demo.basic.progress.OutputProgressController@787f189

During the next lifecycle which is caused by clicking the button to start Timer task, you can see the instance has a different hashcode but we've not been instructed that a new instance has been created. This is the reference the timer task will always have:

INFO: BEFORE INVOKE_APPLICATION(5) from /compat-basic/progress.jsf
OutputProgressController.setPercentComplete:
thread : Thread[Timer-14,5,main]
controller: org.icefaces.demo.basic.progress.OutputProgressController@e27fdb9
29-Aug-2011 10:08:37 AM org.icefaces.impl.util.DebugPhaseListener afterPhase
INFO: AFTER INVOKE_APPLICATION(5) from /compat-basic/progress.jsf
29-Aug-2011 10:08:37 AM org.icefaces.impl.util.DebugPhaseListener beforePhase
INFO: BEFORE RENDER_RESPONSE(6) from /compat-basic/progress.jsf
OutputProgressController.getPercentComplete:
thread : Thread["http-bio-8080"-exec-71,5,main]
controller: org.icefaces.demo.basic.progress.OutputProgressController@e27fdb9
29-Aug-2011 10:08:37 AM org.icefaces.impl.util.DebugPhaseListener afterPhase
INFO: AFTER RENDER_RESPONSE(6) from /compat-basic/progress.jsf

During the next lifecycle, we get the percent vvalue from an instance that has yet another different hashcode:

INFO: BEFORE RENDER_RESPONSE(6) from /compat-basic/progress.jsf
OutputProgressController.getPercentComplete:
thread : Thread["http-bio-8080"-exec-71,5,main]
controller: org.icefaces.demo.basic.progress.OutputProgressController@63b6feb1
29-Aug-2011 10:08:37 AM org.icefaces.impl.util.DebugPhaseListener afterPhase
INFO: AFTER RENDER_RESPONSE(6) from /compat-basic/progress.jsf

The next lifecycle, we see yet another "instance" but the timer thread is setting the percent complete on a previous instance:

INFO: BEFORE RENDER_RESPONSE(6) from /compat-basic/progress.jsf
OutputProgressController.getPercentComplete:
thread : Thread["http-bio-8080"-exec-71,5,main]
controller: org.icefaces.demo.basic.progress.OutputProgressController@3d3d2941
29-Aug-2011 10:08:38 AM org.icefaces.impl.util.DebugPhaseListener afterPhase
INFO: AFTER RENDER_RESPONSE(6) from /compat-basic/progress.jsf
OutputProgressController.setPercentComplete:
thread : Thread[Timer-14,5,main]
controller: org.icefaces.demo.basic.progress.OutputProgressController@e27fdb9

Again, we are getting from what appears to be a different instance:

INFO: BEFORE RENDER_RESPONSE(6) from /compat-basic/progress.jsf
OutputProgressController.getPercentComplete:
thread : Thread["http-bio-8080"-exec-72,5,main]
controller: org.icefaces.demo.basic.progress.OutputProgressController@25bf26fe
29-Aug-2011 10:08:39 AM org.icefaces.impl.util.DebugPhaseListener afterPhase
INFO: AFTER RENDER_RESPONSE(6) from /compat-basic/progress.jsf

Getting from a new instance but setting on the one that the Timer task originally had a reference to:

INFO: BEFORE RENDER_RESPONSE(6) from /compat-basic/progress.jsf
OutputProgressController.getPercentComplete:
thread : Thread["http-bio-8080"-exec-72,5,main]
controller: org.icefaces.demo.basic.progress.OutputProgressController@64699c99
29-Aug-2011 10:08:40 AM org.icefaces.impl.util.DebugPhaseListener afterPhase
INFO: AFTER RENDER_RESPONSE(6) from /compat-basic/progress.jsf
OutputProgressController.setPercentComplete:
thread : Thread[Timer-14,5,main]
controller: org.icefaces.demo.basic.progress.OutputProgressController@e27fdb9

This mismatch between the instance that the Timer task has a reference to and the one that the requests are getting the value from continues and explains why the updates to the client never change the value - they are always '0', the default value of a new bean.

Auction and AuctionMonitor still appear to have issues when running with MyFaces. Not sure if push is a relevant variable or not. In Firebug, if I query for all the ViewState tags in the page, I can see an inconsistency after I've interacted. Will attach screen shot that shows the values of the ViewState for the 4 forms on the page and how 1 is not the same as the others.

Screenshot of Firebug showing inconsistent ViewState values for the forms on the page.

Resolved by the fixes for ICE-7188.

Re-opening. Currently this case is blocked by ICE-7242. Need to re-evaluate once the other case has been addressed.

So I've retested the Auction application with the ICEpush fix and it behaves better and is generally more responsive than before but there are still times when the app is not responsive to clicks (bidding or dropping down the row details). There is also a specific set of steps that can be executed that leads to a client-side error. So running Auction with MyFaces:

1) Click the Bid button
2) Click the accept bid checkmark (bid should update)
3) Click the accept bid checkmark again (bid rejected and message should say that bid was too low)
4) Click the cancel bid 'X'.

This should cause an "Uncaught cannot find enclosing form" error on the client. I've attached a screen snapshot that shows the result as well.

I still have the feeling that there is some sort of interaction between Push and MyFaces. While it takes some time and patience to reproduce, it's possible to require more than 1 click to have the interface respond properly. The other issue with the steps described above is always reproducible.

Adding a ticking clock to basic shows similar problems but only after causing a commandLink to be updated in each push. diff is attached.

For command links (and perhaps other components but this would require more analysis to verify), MyFaces renders out different event handling code for onclick depending on whether or not <f:ajax> is enabled for the command link:

MyFaces <h:commandLink>

with <f:ajax>

<a href="#" onclick="jsf.util.chain(document.getElementById('theLink'), event,'jsf.ajax.request(\'theLink\',event,

)'); return false;" ...

without <f:ajax>

<a href="#" onclick="return myfaces.oam.submitForm('theForm','theLink');" ...

Mojarra does this as well but it doesn't appear to impact the behaviour adversely.

Mojarra <h:commandLink>

with <f:ajax>

<a id="theLink" href="#" onclick="mojarra.ab(this,event,'action',0,0);return false" ...

without <f:ajax>

<a href="#" onclick="mojarra.jsfcljs(document.getElementById('theForm'),

,'');return false" ...

Typically, when running with ICEfaces, standard components are automatically "Ajax-ified" without having to actually include the <f:ajax> tag. Because there is no f:ajax tag, MyFaces renders out the non-Ajax version of the onclick handler for the command link. This handler leads to running specific client-side logic for the commandLink component. Logic that assumes a standard full-page type submission.

Because of this different code path, it impacts the requests on the MyFaces client request queue. Timing issues created by push requests can lead to not submitting the required information for the commandLink action to get fired. In the case of commandLink, the hidden field containing the id of the command link is cleared before the request generated by clicking on the commandLink gets sent. When the form is finally serialized, it's missing the crucial bit of information needed to trigger the action.

We saw something similar in Mojarra where, because of queueing, requests needed to be serialized when the click happens rather than just before they are sent or the data can be stale. According to comments in Mojarra's client code, it specifically encodes the form only when sent because the viewid can change on every request.

/**

• Sends an Ajax request
  */
  send : function() {
  try {
  //we have to encode at send time, otherwise
  //we pick up old viewstates

The workaround is to add the <f:ajax> tag to the commandLink in order to have MyFaces render out the Ajax version of the handler. As noted, commandLink is currently the only known component where this occurs. And though there is similar behaviour with Mojarra, it doesn't appear to have any detrimental impact.

I've checked in a fix to the core that uses a SystemEventListener to modify the h:commandLink but only when running with MyFaces and an ICEfaces view.

The patch listens for commandLinks and, if there are no AjaxBehaviors associated with the commandLink, it adds one. This causes MyFaces to detect that Ajax is in plan and render out the correct handler.