Uploaded image for project: 'OpenAM'
  1. OpenAM
  2. OPENAM-11571

SAML Performance tests breaks under load

    Details

    • Sprint:
      Sprint 2017.11 - Newton
    • Needs backport:
      Yes
    • Needs QA verification:
      Yes
    • Functional tests:
      No
    • Are the reproduction steps defined?:
      Yes and I used the same an in the description

      Description

      SAML performance tests are broken for quite a while where we see that the test throws HTTP 500s and openam federation debugs logs are filled with below error:

      ERROR: IDPSingleLogout.initiateLogoutRequest:
      com.sun.identity.saml2.common.SAML2Exception: Single Logout Failed. 
      	at com.sun.identity.saml2.profile.LogoutUtil.doSLOBySOAP(LogoutUtil.java:460)
      	at com.sun.identity.saml2.profile.LogoutUtil.doLogout(LogoutUtil.java:299)
      	at com.sun.identity.saml2.profile.IDPSingleLogout.initiateLogoutRequest(IDPSingleLogout.java:307)
      	at org.apache.jsp.saml2.jsp.idpSingleLogoutInit_jsp._jspService(idpSingleLogoutInit_jsp.java:279)
      	at org.apache.jasper.runtime.HttpJspBase.service(HttpJspBase.java:70)
      	at javax.servlet.http.HttpServlet.service(HttpServlet.java:729)
      	at org.apache.jasper.servlet.JspServletWrapper.service(JspServletWrapper.java:438)
      	at org.apache.jasper.servlet.JspServlet.serviceJspFile(JspServlet.java:396)
      	at org.apache.jasper.servlet.JspServlet.service(JspServlet.java:340)
      	at javax.servlet.http.HttpServlet.service(HttpServlet.java:729)
      	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:292)
      	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:207)
      	at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:52)
      	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:240)
      	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:207)
      	at org.forgerock.openam.validation.ResponseValidationFilter.doFilter(ResponseValidationFilter.java:36)
      	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:240)
      	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:207)
      	at org.forgerock.openam.headers.SetHeadersFilter.doFilter(SetHeadersFilter.java:80)
      	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:240)
      	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:207)
      	at com.sun.identity.setup.AMSetupFilter.doFilter(AMSetupFilter.java:111)
      	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:240)
      	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:207)
      	at org.forgerock.openam.audit.context.AuditContextFilter.doFilter(AuditContextFilter.java:46)
      	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:240)
      	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:207)
      	at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:212)
      	at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:94)
      	at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:504)
      	at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:141)
      	at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:79)
      	at org.apache.catalina.valves.AbstractAccessLogValve.invoke(AbstractAccessLogValve.java:620)
      	at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:88)
      	at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:502)
      	at org.apache.coyote.http11.AbstractHttp11Processor.process(AbstractHttp11Processor.java:1132)
      	at org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:684)
      	at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1533)
      	at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.run(NioEndpoint.java:1489)
      	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
      	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
      	at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
      	at java.lang.Thread.run(Thread.java:745)
      

      Error on test:

      GET http://cheddar.internal.forgerock.com:8081/fedlet/fedletapplication?SAMLart=AAQAAPtAEuRO76ux9H6X6vCAT5esvIKdo7qH8dYb4hxg%2FMTSbsQDWZPVMDE%3D
      headers=
      Accept: */*
      User-Agent: curl/7.43.0
      Referer: http://cheddar.internal.forgerock.com:8081/fedlet/index.jsp
      Cookie: JSESSIONID=1976285572BA2BAE341F9687642B36E2; amlbcookie=01; iPlanetDirectoryPro="AQIC5wM2LY4SfcxfdQB6W5knsIYXyAOs5TXxkpJ1AJcXCtA.*AAJTSQACMDEAAlNLABM3MTAxMTI3NTk3MjE2NjI1NDk3AAJTMQAA*"; iPlanetDirectoryPro=AQIC5wM2LY4SfcxfdQB6W5knsIYXyAOs5TXxkpJ1AJcXCtA.*AAJTSQACMDEAAlNLABM3MTAxMTI3NTk3MjE2NjI1NDk3AAJTMQAA*
      Host: cheddar.internal.forgerock.com:8081
      =========================
      HTTP response:
      status=
      500 Internal Server Error
      headers= 
      Server: Apache-Coyote/1.1
      Content-Type: text/html;charset=ISO-8859-1
      Content-Language: en
      Content-Length: 3105
      Date: Thu, 17 Aug 2017 08:15:09 GMT
      Connection: close
      
      body=
      <!DOCTYPE html><html><head><title>Apache Tomcat/8.0.45 - Error report</title><style type="text/css">H1 {font-family:Tahoma,Arial,sans-serif;color:white;background-color:#525D76;font-size:22px;} H2 {font-family:Tahoma,Arial,sans-serif;color:white;background-color:#525D76;font-size:16px;} H3 {font-family:Tahoma,Arial,sans-serif;color:white;background-color:#525D76;font-size:14px;} BODY {font-family:Tahoma,Arial,sans-serif;color:black;background-color:white;} B {font-family:Tahoma,Arial,sans-serif;color:white;background-color:#525D76;} P {font-family:Tahoma,Arial,sans-serif;background:white;color:black;font-size:12px;}A {color : black;}A.name {color : black;}.line {height: 1px; background-color: #525D76; border: none;}</style> </head><body><h1>HTTP Status 500 - An exception occurred processing JSP page /fedletSampleApp.jsp at line 90</h1><div class="line"></div><p><b>type</b> Exception report</p><p><b>message</b> <u>An exception occurred processing JSP page /fedletSampleApp.jsp at line 90</u></p><p><b>description</b> <u>The server encountered an internal error that prevented it from fulfilling this request.</u></p><p><b>exception</b></p><pre>org.apache.jasper.JasperException: An exception occurred processing JSP page /fedletSampleApp.jsp at line 90
      
      87:         // validation etc.  
      88:         map = SPACSUtils.processResponseForFedlet(request, response, new PrintWriter(out, true));
      89:     } catch (SAML2Exception sme) {
      90:         SAMLUtils.sendError(request, response,
      91:             response.SC_INTERNAL_SERVER_ERROR, &quot;failedToProcessSSOResponse&quot;,
      92:             sme.getMessage());
      93:         return;
      
      
      Stacktrace:
      	org.apache.jasper.servlet.JspServletWrapper.handleJspException(JspServletWrapper.java:579)
      	org.apache.jasper.servlet.JspServletWrapper.service(JspServletWrapper.java:471)
      	org.apache.jasper.servlet.JspServlet.serviceJspFile(JspServlet.java:396)
      	org.apache.jasper.servlet.JspServlet.service(JspServlet.java:340)
      	javax.servlet.http.HttpServlet.service(HttpServlet.java:729)
      	org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:52)
      </pre><p><b>root cause</b></p><pre>java.lang.IllegalStateException: Cannot forward after response has been committed
      	com.sun.identity.saml.common.SAMLUtils.forwardRequest(SAMLUtils.java:1812)
      	com.sun.identity.saml.common.SAMLUtils.sendError(SAMLUtils.java:1766)
      	org.apache.jsp.fedletSampleApp_jsp._jspService(fedletSampleApp_jsp.java:330)
      	org.apache.jasper.runtime.HttpJspBase.service(HttpJspBase.java:70)
      	javax.servlet.http.HttpServlet.service(HttpServlet.java:729)
      	org.apache.jasper.servlet.JspServletWrapper.service(JspServletWrapper.java:438)
      	org.apache.jasper.servlet.JspServlet.serviceJspFile(JspServlet.java:396)
      	org.apache.jasper.servlet.JspServlet.service(JspServlet.java:340)
      	javax.servlet.http.HttpServlet.service(HttpServlet.java:729)
      	org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:52)
      </pre><p><b>note</b> <u>The full stack trace of the root cause is available in the Apache Tomcat/8.0.45 logs.</u></p><hr class="line"><h3>Apache Tomcat/8.0.45</h3></body></html>
      <<<<<<<<<<<<<<<<<<<<<<<<<
      
      

      the issue can be recreated by running below test on pyforge:

      ./run-pybot.py -c perf -s SAML -n openam
      

      with 100000 users and 10 concurrent users.

        Attachments

          Activity

            People

            • Assignee:
              peter.major Peter Major
              Reporter:
              narita.saxena Narita Saxena
            • Votes:
              0 Vote for this issue
              Watchers:
              3 Start watching this issue

              Dates

              • Created:
                Updated:
                Resolved: