Ajax form submission is slow for large multi selects

[pwnell]

I have a JBoss seam app and am using RichFaces.  Both are at the newest versions - Seam 2.2.1 Final and RichFaces 3.3.3.Final.  On one specific page I have a h:selectManyListBox, and this box can have 300 - 500 entries.  I also have a4j:commandButton and a4j:support event="onclick" elements.  Both of them exhibit the same behaviour.

When the multi select box has only a few elements selected (say less than 10), the form submission happens quickly and without delay.  However, when I select say 100 entries and try to submit the form, the processing slows down.  The duration after the requestDelay has elapsed (in my case 0 ms), until the action method of is executed gradually grows longer as more elements are selected in the multi select box.  For 100 selected entries I can wait easily up to 20 seconds before the form is submitted.  During this time my CPU is on 0% - it is perfectly idling.

This happens in Safari 5, Firefox 4, IE 9 etc.

I found this related article but in there it states it has been fixed, and my AJAX.js indeed has the fix. 

https://issues.jboss.org/browse/RF-3801

Any help would be greatly appreciated.

[nbelaevski]

Hi Waldo,

Can you try profiling the app using Firebug/IE9 developer tools and post where the time is spent here?

[pwnell]

Attached.  I think I selected about 523 entries.  Let me know if you need anything else.

[nbelaevski]

Please attach output from a4j:log and page code.

[pwnell]

Done.

[ilya_shaikovsky]

20 seconds lost at server side and client side processing is really fast according to a4j:log attached. so you should perform profiling of server side code instead of looking to client log.

[pwnell]

I disagree.  Unless there is something I do not understand...  But it takes 20 - 30 seconds to hit this action method:

<a4j:support event="onclick" action="#{advancedSearch.addField(set.val)}" reRender="advanced_search" requestDelay="0" ignoreDupResponses="true" oncomplete="document.getElementById('advanced_search_form:fieldset_#{set.val}').style.display = 'none'; return true;"/>

When I select an entry in the box, it takes 20 - 30 seconds before the method advancedSearch.addField(set.val) is called.  So where would the server side processing be tied up?

I do not know what this means:

debug[16:18:26,898]: Request state : 1

debug[16:18:46,074]: Request state : 2

Where has the time gone between those two calls?  It is most certainly not my action method as it only gets called after Request state 2

[nbelaevski]

Those are request states: http://www.w3.org/TR/XMLHttpRequest/#dom-xmlhttprequest-unsent

1 means that request has been sent, while 2 means that response headers have been received.

So, request is sent momentarily, but processing on the server takes a lot of time. Please add phase tracker to your application and post the output.

[pwnell]

Ah I see.  Here you go:

10:15:13,290 INFO  [helper] BEFORE RESTORE_VIEW 1

10:15:13,298 INFO  [helper] AFTER RESTORE_VIEW 1

10:15:13,300 INFO  [helper] BEFORE APPLY_REQUEST_VALUES 2

10:15:13,321 INFO  [helper] AFTER APPLY_REQUEST_VALUES 2

10:15:13,322 INFO  [helper] BEFORE PROCESS_VALIDATIONS 3

10:16:02,340 INFO  [helper] AFTER PROCESS_VALIDATIONS 3

10:16:02,341 INFO  [helper] BEFORE UPDATE_MODEL_VALUES 4

10:16:02,345 INFO  [helper] AFTER UPDATE_MODEL_VALUES 4

10:16:02,346 INFO  [helper] BEFORE INVOKE_APPLICATION 5

10:16:02,346 INFO  [helper] AFTER INVOKE_APPLICATION 5

10:16:02,348 INFO  [helper] BEFORE RENDER_RESPONSE 6

10:16:02,530 INFO  [helper] AFTER RENDER_RESPONSE 6

But does that refer to Hibernate validations?  For these two specific entities I am not using any hibernate validations except on one field unrelated to the multi select box.

Wait... I found the problem.  This code gets executed once for every selected list item:

<s:selectItems value="#{advancedSearch.getLookupData(sc.searchCondition.lookupQuery)}" var="field" label="#{field.value2}" itemValue="#{field.value1}"/>

And that obviously goes to the DB.  I apoligise to Ilya, it is indeed the backend code that causes this delay.  But that being said, why does the .xhtml file call that selectItems value action so many times?  Surely it should only call it once, not once per selected select box item?

If you were wondering, I confirmed that this:

<ui:repeat value="#{advancedSearchCriteria.selectedSearchConditions}" var="sc">

should only execute once because (1) I only see one set rendered and (2) I verified advancedSearchCriteria.selectedSearchConditions is 1 before the submit and 2 after the submit.

[nbelaevski]

Waldo,

Sorry I don't know the details of s:selectItems implementation. Can you use lazy initialization in the bean?

[pwnell]

I could, but the queries are all dynamic so I would not know what it is until the user selected the search criteria.  I guess this is now in the hands of JBoss Seam and not RichFaces.  Will post there.  A BIG thank you for reminding me how to perform basic troubleshooting.  Seems like I am getting old and forgetting basic things

[pwnell]

Maybe this helps.  this is the stack trace of the action listener being called repeatedly.  Is this an a4j issue or seam?

...

        at za.co.matrixmarketing.matrixweb.web.actions.AdvancedSearchAction_$$_javassist_seam_13.getLookupData(AdvancedSearchAction_$$_javassist_seam_13.java)

        at sun.reflect.GeneratedMethodAccessor482.invoke(Unknown Source)

        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)

        at java.lang.reflect.Method.invoke(Method.java:597)

        at org.jboss.el.util.ReflectionUtil.invokeMethod(ReflectionUtil.java:335)

        at org.jboss.el.util.ReflectionUtil.invokeMethod(ReflectionUtil.java:280)

        at org.jboss.el.parser.AstMethodSuffix.getValue(AstMethodSuffix.java:59)

        at org.jboss.el.parser.AstValue.getValue(AstValue.java:67)

        at org.jboss.el.ValueExpressionImpl.getValue(ValueExpressionImpl.java:186)

        at com.sun.facelets.el.TagValueExpression.getValue(TagValueExpression.java:71)

        at javax.faces.component.UISelectItems.getValue(UISelectItems.java:141)

        at org.jboss.seam.ui.component.UISelectItems.getValue(UISelectItems.java:161)

        at javax.faces.component.SelectItemsIterator.next(SelectItemsIterator.java:149)

        at javax.faces.component.SelectItemsIterator.next(SelectItemsIterator.java:61)

        at javax.faces.component.SelectUtils.matchValue(SelectUtils.java:82)

        at javax.faces.component.UISelectMany.validateValue(UISelectMany.java:465)

        at javax.faces.component.UIInput.validate(UIInput.java:875)

        at javax.faces.component.UIInput.executeValidate(UIInput.java:1072)

        at javax.faces.component.UIInput.processValidators(UIInput.java:672)

        at javax.faces.component.UIComponentBase.processValidators(UIComponentBase.java:1058)

        at javax.faces.component.UIComponentBase.processValidators(UIComponentBase.java:1058)

        at com.sun.facelets.component.UIRepeat.process(UIRepeat.java:366)

        at com.sun.facelets.component.UIRepeat.processValidators(UIRepeat.java:447)

        at javax.faces.component.UIComponentBase.processValidators(UIComponentBase.java:1058)

        at javax.faces.component.UIComponentBase.processValidators(UIComponentBase.java:1058)

        at javax.faces.component.UIComponentBase.processValidators(UIComponentBase.java:1058)

        at org.ajax4jsf.component.UIAjaxRegion.processValidators(UIAjaxRegion.java:121)

        at org.ajax4jsf.component.AjaxViewRoot$3.invokeContextCallback(AjaxViewRoot.java:447)

        at org.ajax4jsf.component.ContextCallbackWrapper.invokeContextCallback(ContextCallbackWrapper.java:44)

        at javax.faces.component.UIComponent.invokeOnComponent(UIComponent.java:711)

        at javax.faces.component.UIComponentBase.invokeOnComponent(UIComponentBase.java:675)

...

[pwnell]

I can maybe just add, I also have a non ajax submission link on that page and that, when submitted, never delays. It is only when I perform an ajax submit that the system hangs on those server validations for 20 seconds.

[ilya_shaikovsky]

I'm not sure about

I also have a non ajax submission link on that page and that, when submitted, never delays.

maybe that link is immediate?

But in general - instead of pointing JSF components direclty to the getters which performs the DB call use lazy initialization at least in request context. I mean getting the data only on the first call for the value(and if it's non populated already). Component values could be get numerous times for every component and that's really how it should works according to JSF specification. Let me show a few examples:

input will call getValue twice on decode and rendering. first time to populate changed event (compare old one with submitted one) and second to render the HTML at render phase.

selectItems get's at validation phase in order to confirm that submitted value really exist in the list. and also will be called then to render that list again at render phase.

Most problematic from that point of view could be tables. If them are connected to huge db tables - model should be implemented really carefully in order to get data only required currently considerting  current page, filter options and so on(and such data calls should be only performed ideally if some of the parameters changed and cached in other cases). And bound direclty to database data iteration components will cause huge performance degrades also.