Bug 48750

Summary: performance problems with JSF 1.2
Product: Tomcat 6 Reporter: Michael Heinen <mhn4dev>
Component: JasperAssignee: Tomcat Developers Mailing List <dev>
Status: RESOLVED DUPLICATE    
Severity: major CC: mhn4dev
Priority: P2    
Version: 6.0.24   
Target Milestone: default   
Hardware: All   
OS: Windows XP   
Attachments: Jsps - source and java

Description Michael Heinen 2010-02-16 11:42:13 UTC
I noticed serious performance problems with JSF 1.2 and Tomcat which seems to be caused by Tomcat.
The corresponding discussion is available here: http://marc.info/?l=tomcat-user&m=126607491020706&w=2

Metadata-complete is set to true in web.xml 
(see https://issues.apache.org/bugzilla/show_bug.cgi?id=48600)

I deployed two web apps to Tomcat and Jetty and compared performance data.
Average results of 500 calls of a simple jsf page (jsp) with 1000 h:output tags:

JSF 1.1:
  Tomcat 6.0.24: 26ms
  Jetty 7.0.1: 35ms
 
JSF 1.2:
  Tomcat 6.0.24: 72ms
  Jetty 7.0.1: 41ms

Result:
Tomcat is much faster with JSF 1.1 but terrible slow with JSF 1.2!

One difference between Tomcat and Jetty in the compiled jsp is the AnnotationHelper.

Compiled method for a single outputtext tag:
Tomcat:
private boolean _jspx_meth_h_005foutputText_005f999(javax.servlet.jsp.tagext.JspTag _jspx_th_h_005fform_005f0, PageContext _jspx_page_context)
        throws Throwable {
  PageContext pageContext = _jspx_page_context;
  JspWriter out = _jspx_page_context.getOut();
  //  h:outputText
  org.apache.myfaces.taglib.html.HtmlOutputTextTag _jspx_th_h_005foutputText_005f999 = new org.apache.myfaces.taglib.html.HtmlOutputTextTag();
  org.apache.jasper.runtime.AnnotationHelper.postConstruct(_jsp_annotationprocessor, _jspx_th_h_005foutputText_005f999);
  _jspx_th_h_005foutputText_005f999.setPageContext(_jspx_page_context);
  _jspx_th_h_005foutputText_005f999.setParent((javax.servlet.jsp.tagext.Tag) _jspx_th_h_005fform_005f0);
  // /1000hout.jsp(1021,0) name = value type = javax.el.ValueExpression reqTime = false required = false fragment = false deferredValue = true expectedTypeName = java.lang.Object deferredMethod = false methodSignature = null
  _jspx_th_h_005foutputText_005f999.setValue(new org.apache.jasper.el.JspValueExpression("/1000hout.jsp(1021,0) '1'",_el_expressionfactory.createValueExpression("1",java.lang.Object.class)));
  // /1000hout.jsp(1021,0) name = style type = javax.el.ValueExpression reqTime = false required = false fragment = false deferredValue = true expectedTypeName = java.lang.Object deferredMethod = false methodSignature = null
  _jspx_th_h_005foutputText_005f999.setStyle(new org.apache.jasper.el.JspValueExpression("/1000hout.jsp(1021,0) 'z-index:29202;'",_el_expressionfactory.createValueExpression("z-index:29202;",java.lang.Object.class)));
  _jspx_th_h_005foutputText_005f999.setJspId("jsp_711124934_1001");
  int _jspx_eval_h_005foutputText_005f999 = _jspx_th_h_005foutputText_005f999.doStartTag();
  if (_jspx_th_h_005foutputText_005f999.doEndTag() == javax.servlet.jsp.tagext.Tag.SKIP_PAGE) {
    _jspx_th_h_005foutputText_005f999.release();
    org.apache.jasper.runtime.AnnotationHelper.preDestroy(_jsp_annotationprocessor, _jspx_th_h_005foutputText_005f999);
    return true;
  }
  _jspx_th_h_005foutputText_005f999.release();
  org.apache.jasper.runtime.AnnotationHelper.preDestroy(_jsp_annotationprocessor, _jspx_th_h_005foutputText_005f999);
  return false;
}
  
Jetty:
private boolean _jspx_meth_h_outputText_999(javax.servlet.jsp.tagext.JspTag _jspx_th_h_form_0, PageContext _jspx_page_context)
        throws Throwable {
  PageContext pageContext = _jspx_page_context;
  JspWriter out = _jspx_page_context.getOut();
  //  h:outputText
  org.apache.myfaces.taglib.html.HtmlOutputTextTag _jspx_th_h_outputText_999 = new org.apache.myfaces.taglib.html.HtmlOutputTextTag();
  if (_jspx_resourceInjector != null) {
    _jspx_resourceInjector.inject(_jspx_th_h_outputText_999      );
  }
  _jspx_th_h_outputText_999.setPageContext(_jspx_page_context);
  _jspx_th_h_outputText_999.setParent((javax.servlet.jsp.tagext.Tag) _jspx_th_h_form_0);
  _jspx_th_h_outputText_999.setJspId("id2019");
  _jspx_th_h_outputText_999.setValue(org.apache.jasper.runtime.PageContextImpl.getValueExpression("1", (PageContext)_jspx_page_context, java.lang.Object.class, null));
  _jspx_th_h_outputText_999.setStyle(org.apache.jasper.runtime.PageContextImpl.getValueExpression("z-index:29202;", (PageContext)_jspx_page_context, java.lang.Object.class, null));
  int _jspx_eval_h_outputText_999 = _jspx_th_h_outputText_999.doStartTag();
  if (_jspx_th_h_outputText_999.doEndTag() == javax.servlet.jsp.tagext.Tag.SKIP_PAGE) {
    _jspx_tagPool_h_outputText_value_style_nobody.reuse(_jspx_th_h_outputText_999);
    return true;
  }
  _jspx_tagPool_h_outputText_value_style_nobody.reuse(_jspx_th_h_outputText_999);
  return false;
}

A demo web app is attached
Just call http://<server>:<port>/jsf12/faces/1000hout.jsp

Can the AnnotationHelper be turned off completely?
Comment 1 Michael Heinen 2010-02-16 12:24:01 UTC
Created attachment 25001 [details]
Jsps - source and java

- Source jsp 1000hout.jsp
- JSP compiled with Tomcat and Jetty (java and class)
Comment 2 Michael Heinen 2010-02-16 12:42:44 UTC
The demo web app is available here:
http://www.datafilehost.com/download-9e9da3b8.html
Comment 3 Remy Maucherat 2010-02-16 13:00:02 UTC

*** This bug has been marked as a duplicate of bug 48600 ***
Comment 4 Michael Heinen 2010-02-16 13:17:13 UTC
Could anybody pls explain why this is a duplicate of bug #48600?

I set metadata-complete="true" in web.xml
Moreover the patch attached in 48600 does not improve speed further more therefore I thought this would be another issue.

#48600 is classified as P2 enhancement. It is much more critical from my point of view because the performance is really poor. This means more parallel requests and at the end we can serve just half of the users anymore.
Comment 5 Remy Maucherat 2010-02-16 13:56:03 UTC
The performance levels do not seem catastrophic, so the severity is very appropriate.