Skip to main content

Same JSF request seems to execute page twice

3 replies [Last post]
ngchihou
Offline
Joined: 2009-05-19

Hi,

As we're debugging performance issues on our webapp, we were surprised to see that our JSF backing beans action being executed twice and we can see the RENDER_RESPONSE phase get invoked twice for every page request as well:

2009-05-19 02:15:48,416 INFO com.proace.util.ConsoleListener - BEFORE - RENDER_RESPONSE 6 : /dummy.jsp [http://isa-stage-doc-0101.sea3.proace.com:8090/console/dummy.jsp] http-8090-1~12 com.sun.faces.context.FacesContextImpl@c3358b [com.sun.faces.renderKitImplForRequest, com.sun.faces.managedBeanStack, com.sun.faces.FacesContextImpl, com.exade.vcp.Filter.done, com.sun.faces.INVOCATION_PATH, org.restfaces.ISNOTPOSTBACK, com.sun.faces.ExternalContextImpl, ajaxContext, com.exade.vcp.Filter.ResponseWrapper]

2009-05-19 02:15:48,417 INFO com.proace.util.ConsoleListener - BEFORE - RENDER_RESPONSE 6 : /dummy.jsp [http://isa-stage-doc-0101.sea3.proace.com:8090/console/dummy.jsp] http-8090-1~12 com.sun.faces.context.FacesContextImpl@c3358b [com.sun.faces.renderKitImplForRequest, com.sun.faces.managedBeanStack, com.sun.faces.FacesContextImpl, com.exade.vcp.Filter.done, com.sun.faces.INVOCATION_PATH, org.restfaces.ISNOTPOSTBACK, com.sun.faces.ExternalContextImpl, ajaxContext, com.exade.vcp.Filter.ResponseWrapper]

2009-05-19 02:15:49,826 INFO com.proace.util.ConsoleListener - AFTER - RENDER_RESPONSE 6 : /dummy.jsp [http://isa-stage-doc-0101.sea3.proace.com:8090/console/dummy.jsp] http-8090-1~12 com.sun.faces.context.FacesContextImpl@c3358b [org/richfaces/renderkit/html/scripts/skinning.js, org.ajax4jsf.framework.HEAD_EVENTS_LIST, org.ajax4jsf.framework.HEADER_PROCESSED, /org/richfaces/skin.xcss, org.ajax4jsf.context.ViewResources$1, org.ajax4jsf.component.QueueRegistry, com.sun.faces.renderKitImplForRequest, com.sun.faces.managedBeanStack, com.exade.vcp.Filter.done, com.sun.faces.FacesContextImpl, javax.servlet.jsp.jstl.fmt.locale.request, org/richfaces/renderkit/html/css/basic_both.xcss, org/richfaces/renderkit/html/css/extended_both.xcss, com.sun.faces.INVOCATION_PATH, org.restfaces.ISNOTPOSTBACK, dummy, com.sun.faces.ExternalContextImpl, org.ajax4jsf.skin.HASH_CODES_MAP, org.ajax4jsf.VIEW_ID, ajaxContext, com.exade.vcp.Filter.ResponseWrapper]

2009-05-19 02:15:49,826 INFO com.proace.util.ConsoleListener - null
org.restfaces.application.RestFacesPhaseListener@1de45e2
org.ajax4jsf.event.AjaxPhaseListener@1be2893
com.proace.util.ConsoleListener@b3f9b8
org.restfaces.application.RestFacesPhaseListener@39c8c1
org.ajax4jsf.event.AjaxPhaseListener@1ab2b55
com.proace.util.ConsoleListener@4b11e9
com.sun.rave.web.ui.appbase.faces.ViewHandlerImpl@54824

2009-05-19 02:15:49,826 INFO com.proace.util.ConsoleListener - AFTER - RENDER_RESPONSE 6 : /dummy.jsp [http://isa-stage-doc-0101.sea3.proace.com:8090/console/dummy.jsp] http-8090-1~12 com.sun.faces.context.FacesContextImpl@c3358b [org/richfaces/renderkit/html/scripts/skinning.js, org.ajax4jsf.framework.HEAD_EVENTS_LIST, org.ajax4jsf.framework.HEADER_PROCESSED, /org/richfaces/skin.xcss, org.ajax4jsf.context.ViewResources$1, org.ajax4jsf.component.QueueRegistry, com.sun.faces.renderKitImplForRequest, com.sun.faces.managedBeanStack, com.exade.vcp.Filter.done, com.sun.faces.FacesContextImpl, javax.servlet.jsp.jstl.fmt.locale.request, org/richfaces/renderkit/html/css/basic_both.xcss, org/richfaces/renderkit/html/css/extended_both.xcss, com.sun.faces.INVOCATION_PATH, org.restfaces.ISNOTPOSTBACK, dummy, com.sun.faces.ExternalContextImpl, org.ajax4jsf.skin.HASH_CODES_MAP, org.ajax4jsf.VIEW_ID, ajaxContext, com.exade.vcp.Filter.ResponseWrapper]
2009-05-19 02:16:48,910 INFO org.apache.tiles.access.TilesAccess - Removing TilesContext for context: org.apache.tiles.web.util.ServletContextAdapter

The above log is generated by the custom phase listener that listen to all phases of the lifecycle, clearly show that the render response phase is executed twice, could you provide information of why this is happening?

Reply viewing options

Select your preferred way to display the comments and click "Save settings" to activate your changes.
bbergquist
Offline
Joined: 2007-04-02

Could you inadvertently have two ViewHandler's being found and used, one delegating to the other and also doing its own thing? This might happen when mixing JSF frameworks...

ngchihou
Offline
Joined: 2009-05-19

Thanks for the insight, is there any known issue with the following combination of frameworks:

JSF 1.2 + Richfaces 3.3 + Restfaces 1.3.1

How is the ViewHandler being loaded and initialized? And is there a way to get the list of ViewHandlers currently registered to verify your theory?

ngchihou
Offline
Joined: 2009-05-19

Can someone share some insights into this problem, right now I have to manually remove the duplicated phase listeners but I think the page is still being rendered twice, the page load latency is still high.