oncomplete not executed at the end...

[ronanker]

i have a strange case where oncomplete isn't the last event executed :
my a4j:logs is :

debug[14:40:00,080]: Have Event [object Object] with properties: target: [object HTMLImageElement], srcElement: undefined, type: click
debug[14:40:00,080]: NEW AJAX REQUEST !!! with form :formMenu
...
debug[14:40:00,090]: Start XmlHttpRequest
debug[14:40:00,091]: Reqest state : 1
debug[14:40:00,091]: QueryString: AJAXREQUEST=...
...
debug[14:40:00,879]: Reqest end with state 4
debug[14:40:00,879]: Response with content-type: text/xml;charset=UTF-8
debug[14:40:00,880]: Full response content: <?xml version="1.0"?> ...
debug[14:40:00,881]: Header Ajax-Expired not found, search in <meta>
debug[14:40:00,881]: search for elements by name 'meta' in element #document
debug[14:40:00,884]: Find <meta name='Ajax-Update-Ids' content='...'>
debug[14:40:00,884]: Find <meta name='Ajax-Response' content='true'>
debug[14:40:00,885]: Header Ajax-Update-Ids not found, search in <meta>
debug[14:40:00,885]: search for elements by name 'meta' in element #document
debug[14:40:00,888]: Find <meta name='Ajax-Update-Ids' content='...'>
debug[14:40:00,888]: Update page by list of rendered areas from response ...
debug[14:40:00,888]: search for elements by name 'script' in element #document
...
debug[14:40:00,904]: <script> in response with src=/MonitorMakerWeb/static/js/NumberFormat.js
debug[14:40:00,904]: Such element exist in document
debug[14:40:00,904]: <script> in response with src=/MonitorMakerWeb/static/js/general.js
debug[14:40:00,905]: Such element exist in document
debug[14:40:00,905]: <script> in response with src=/MonitorMakerWeb/static/looknfeel/template/template.js
debug[14:40:00,905]: Such element exist in document
debug[14:40:00,905]: <script> in response with src=/MonitorMakerWeb/static/js/suggestionbox.js
debug[14:40:00,906]: Such element exist in document
debug[14:40:00,906]: <script> in response with src=/MonitorMakerWeb/static/js/tiny_mce/tiny_mce_gzip.js
debug[14:40:00,906]: Such element exist in document
debug[14:40:00,906]: search for elements by name 'link' in element #document
debug[14:40:00,911]: <link> in response with src=/MonitorMakerWeb/a4j_3_2_1.CR3org/richfaces/skin-ext-classes.xcss/DATB/eAELTrh-PXT5DGkAExEEEQ__.jsf
debug[14:40:00,911]: Such element exist in document
debug[14:40:00,911]: <link> in response with src=/MonitorMakerWeb/static/looknfeel/template/template.css
debug[14:40:00,911]: Such element exist in document
debug[14:40:00,911]: <link> in response with src=/MonitorMakerWeb/a4j_3_2_1.CR3styles.xcss/DATB/eAELTrh-PXT5DGkAExEEEQ__.jsf
debug[14:40:00,911]: Such element exist in document
debug[14:40:00,912]: <link> in response with src=/MonitorMakerWeb/static/looknfeel/themes/moderne/theme.css
debug[14:40:00,912]: Such element exist in document
...
debug[14:40:00,974]: Attempt to update part of page for Id: formPage
debug[14:40:00,974]: call getElementById for id= formPage
debug[14:40:01,001]: Replace content of node by replaceChild()
debug[14:40:01,041]: search for elements by name 'script' in element form
debug[14:40:01,044]: Scripts in updated part count : 0
debug[14:40:01,045]: Update part of page for Id: formPage successful
...
debug[14:40:01,097]: Attempt to update part of page for Id: panelAlerte
debug[14:40:01,098]: call getElementById for id= panelAlerte
debug[14:40:01,098]: Replace content of node by replaceChild()
debug[14:40:01,098]: search for elements by name 'script' in element span
debug[14:40:01,102]: Scripts in updated part count : 0

debug[14:40:01,102]: call getElementById for id= org.ajax4jsf.oncomplete
 debug[14:40:01,142]: Update part of page for Id: panelAlerte successful
debug[14:40:01,142]: call getElementById for id= ajax-view-state
debug[14:40:01,143]: Hidden JSF state fields: [object HTMLSpanElement]
debug[14:40:01,143]: Namespace for hidden view-state input fields is undefined
debug[14:40:01,143]: search for elements by name 'input' in element span
debug[14:40:01,146]: Replace value for inputs: 49 by new values: 1
debug[14:40:01,146]: Input in response: javax.faces.ViewState
debug[14:40:01,146]: Found same input on page with type: hidden
...
debug[14:40:01,148]: search for elements by name 'INPUT' in element span
debug[14:40:01,150]: Replace value for inputs: 49 by new values: 0
debug[14:40:01,150]: call getElementById for id= _A4J.AJAX.focus
debug[14:40:01,150]: No focus information in response
debug[14:40:01,377]: Evaluate script replaced area in document: // window.document.... //
debug[14:40:01,380]: Evaluate script replaced area in document: // window.document.... //
debug[14:40:01,381]: Evaluate script replaced area in document: // Richfaces.onAvailable... //
debug[14:40:01,387]: Evaluate script replaced area in document: // window.document.... //
debug[14:40:01,390]: Evaluate script replaced area in document: // window.document.... //
debug[14:40:01,392]: Evaluate script replaced area in document: // Richfaces.onAvailable... //
debug[14:40:01,397]: Evaluate script replaced area in document: // new Calendar(... //
debug[14:40:01,422]: Evaluate script replaced area in document: // new Calendar(... //

this cause my function endOfAjaxRequest() called before the evaluations of the replaced scripts and then it can't find elements that are created by those scripts (in my case the calendars).

<a4j:status onstop="endOfAjaxRequest()"/>

to solve the problem, i just added this at the end of my page :

<a4j:outputPanel id="hacks" ajaxRendered="true">
 <script>//hack pour corriger execution de oncomplete()</script>
</a4j:outputPanel>

and then my a4j:logs is :

debug[14:34:42,319]: Have Event [object Object] with properties: target: [object HTMLImageElement], srcElement: undefined, type: click
debug[14:34:42,319]: NEW AJAX REQUEST !!! with form :formMenu
...
debug[14:34:42,329]: Start XmlHttpRequest
debug[14:34:42,330]: Reqest state : 1
debug[14:34:42,330]: QueryString: AJAXREQUEST=...
...
debug[14:34:43,176]: Reqest end with state 4
debug[14:34:43,176]: Response with content-type: text/xml;charset=UTF-8
debug[14:34:43,177]: Full response content: <?xml version="1.0"?> ...
debug[14:34:43,177]: Header Ajax-Expired not found, search in <meta>
debug[14:34:43,177]: search for elements by name 'meta' in element #document
debug[14:34:43,181]: Find <meta name='Ajax-Update-Ids' content='...'>
debug[14:34:43,181]: Find <meta name='Ajax-Response' content='true'>
debug[14:34:43,181]: Header Ajax-Update-Ids not found, search in <meta>
debug[14:34:43,181]: search for elements by name 'meta' in element #document
debug[14:34:43,184]: Find <meta name='Ajax-Update-Ids' content='...'>
debug[14:34:43,184]: Update page by list of rendered areas from response ...
debug[14:34:43,185]: search for elements by name 'script' in element #document
...
debug[14:34:43,200]: <script> in response with src=/MonitorMakerWeb/static/js/NumberFormat.js
debug[14:34:43,201]: Such element exist in document
debug[14:34:43,201]: <script> in response with src=/MonitorMakerWeb/static/js/general.js
debug[14:34:43,201]: Such element exist in document
debug[14:34:43,201]: <script> in response with src=/MonitorMakerWeb/static/looknfeel/template/template.js
debug[14:34:43,202]: Such element exist in document
debug[14:34:43,202]: <script> in response with src=/MonitorMakerWeb/static/js/suggestionbox.js
debug[14:34:43,202]: Such element exist in document
debug[14:34:43,202]: <script> in response with src=/MonitorMakerWeb/static/js/tiny_mce/tiny_mce_gzip.js
debug[14:34:43,203]: Such element exist in document
debug[14:34:43,203]: search for elements by name 'link' in element #document
debug[14:34:43,207]: <link> in response with src=/MonitorMakerWeb/a4j_3_2_1.CR3org/richfaces/skin-ext-classes.xcss/DATB/eAELTrh-PXT5DGkAExEEEQ__.jsf
debug[14:34:43,208]: Such element exist in document
debug[14:34:43,208]: <link> in response with src=/MonitorMakerWeb/static/looknfeel/template/template.css
debug[14:34:43,208]: Such element exist in document
debug[14:34:43,208]: <link> in response with src=/MonitorMakerWeb/a4j_3_2_1.CR3styles.xcss/DATB/eAELTrh-PXT5DGkAExEEEQ__.jsf
debug[14:34:43,208]: Such element exist in document
debug[14:34:43,208]: <link> in response with src=/MonitorMakerWeb/static/looknfeel/themes/moderne/theme.css
debug[14:34:43,208]: Such element exist in document
...
debug[14:34:43,271]: Attempt to update part of page for Id: formPage
debug[14:34:43,271]: call getElementById for id= formPage
debug[14:34:43,296]: Replace content of node by replaceChild()
debug[14:34:43,326]: search for elements by name 'script' in element form
debug[14:34:43,330]: Scripts in updated part count : 0
debug[14:34:43,330]: Update part of page for Id: formPage successful
...
debug[14:34:43,381]: Attempt to update part of page for Id: panelAlerte
debug[14:34:43,381]: call getElementById for id= panelAlerte
debug[14:34:43,381]: Replace content of node by replaceChild()
debug[14:34:43,382]: search for elements by name 'script' in element span
debug[14:34:43,385]: Scripts in updated part count : 0
debug[14:34:43,385]: Update part of page for Id: panelAlerte successful
debug[14:34:43,385]: Attempt to update part of page for Id: hacks
 debug[14:34:43,385]: call getElementById for id= hacks
 debug[14:34:43,386]: Replace content of node by replaceChild()
 debug[14:34:43,386]: search for elements by name 'script' in element span
 debug[14:34:43,389]: Scripts in updated part count : 1
 debug[14:34:43,389]: Update part of page for Id: hacks successful

debug[14:34:43,390]: call getElementById for id= ajax-view-state
debug[14:34:43,390]: Hidden JSF state fields: [object HTMLSpanElement]
debug[14:34:43,390]: Namespace for hidden view-state input fields is undefined
debug[14:34:43,390]: search for elements by name 'input' in element span
debug[14:34:43,393]: Replace value for inputs: 49 by new values: 1
debug[14:34:43,393]: Input in response: javax.faces.ViewState
debug[14:34:43,393]: Found same input on page with type: hidden
...
debug[14:34:43,395]: search for elements by name 'INPUT' in element span
debug[14:34:43,397]: Replace value for inputs: 49 by new values: 0
debug[14:34:43,397]: call getElementById for id= _A4J.AJAX.focus
debug[14:34:43,398]: No focus information in response
debug[14:34:43,641]: Evaluate script replaced area in document: // window.document.... //
debug[14:34:43,643]: Evaluate script replaced area in document: // window.document.... //
debug[14:34:43,645]: Evaluate script replaced area in document: // Richfaces.onAvailable... //
debug[14:34:43,649]: Evaluate script replaced area in document: // window.document.... //
debug[14:34:43,651]: Evaluate script replaced area in document: // window.document.... //
debug[14:34:43,653]: Evaluate script replaced area in document: // Richfaces.onAvailable... //
debug[14:34:43,659]: Evaluate script replaced area in document: // new Calendar(... //
debug[14:34:43,682]: Evaluate script replaced area in document: // new Calendar(... //
debug[14:34:43,705]: Evaluate script replaced area in document: // //hack pour corriger execution de oncomplete() //
debug[14:34:43,752]: call getElementById for id= org.ajax4jsf.oncomplete

can someone explain / correct ?

[nbelaevski]

Hi Ronan,

Look at this:

evalScripts : function(node, isLast){
 var newscripts = this.getElementsByTagName("script",node);
 LOG.debug("Scripts in updated part count : " + newscripts.length);
 if( newscripts.length > 0 ){
 var _this = this;
 window.setTimeout(function() {
 for (var i = 0; i < newscripts.length; i++){
 var includeComments = !A4J.AJAX.isXhtmlScriptMode();
 var newscript = A4J.AJAX.getText(newscripts, includeComments) ; // TODO - Mozilla disable innerHTML in XML page ..."";

 try {
 LOG.debug("Evaluate script replaced area in document: ", newscript);
 if (window.execScript) {
 window.execScript( newscript );
 } else {
 window.eval(newscript);
 }
 } catch(e){
 LOG.error("ERROR Evaluate script: Error name: " + e.name + e.message?". Error message: "+e.message:"");
 }
 }
 newscripts = null;
 if (isLast)
 {
 _this.doFinish();
 _this = undefined;
 }
 }, 0);
 } else
 {
 if (isLast)
 {
 this.doFinish();
 }
 }
 },

else branch is executed just in time, but not on timeout, and that is the thing that most likely causes problems. Try changing

if (isLast)
 {
 this.doFinish();
 }

to something like:

var _this = this; setTimeout(function(){_this.doFinish();_this=undefined;}, 0);

[ronanker]

ok, thanks, now i understand how it works...

i think i'll keep my little hack (less intrusive) until i upgrade to a version that will include your patch. i think it'll be included in 3.3, won't it ?

thanks.

[nbelaevski]

Ronan,

I was not right, sorry. The right place to insert setTimeout() invocation is in finishRequest() function.

I've created JIRA issue for the problem: https://jira.jboss.org/jira/browse/RF-5271

[ronanker]

ok, i've seen the correction in the jira -> code diff
without testing, i think it will correct the bug but the logs will be confusing as it will still show the same as i posted in this post...
the line 1121 :
var oncomp = request.getElementById('org.ajax4jsf.oncomplete');
that generates the log i've put in red, is always executed just in time in the case the last block doesn't contain any script.

sure this isn't critical, but can be confusing.

[ronanker]

other solution to please me would be adding an other log line inside the processing of the oncomplete and status.Stop
that would enable the debugger to know that all is executing the right order.

also the 'if then else...' writes log for 2 of the 3 case, should add something like LOG.debug( "no oncomplete function to call, finish process after processing updates" );

in general, personnaly, i'm not found of "do something after somethingElse" log, i prefer "do somethingElse" and later "do something"...
is there a reason why using the fist ?
or "queue something for after sometingElse" then "do somethingElse" then "do something"...

(i agree we can't add i debug line before each line of code)