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

Agent 4.x can not login to an AM cluster if reaching various servers during authentication process

    XMLWordPrintable

    Details

    • Bug
    • Status: Open
    • Major
    • Resolution: Unresolved
    • 5.5.1
    • None
    • authentication, web agents
    • Rank:
      1|hzuyen:

      Description

      Bug description

      Agent 4.1 uses a multistep process to login to AM. If stickiness can not be enforced it will:

      • fail to install
      • intermittently fail to login to AM

      How to reproduce the issue

      1. Install a cluster with two AM instances
      2. Add each server in a site: http://lb.example.com:8080/openam
      3. Front them with HAProxy with round robin
      4. Try to install agent to http://lb.example.com:8080/openam
      Expected behaviour
      Agent get installed
      Current behaviour

      Agent install fails with:

      <?xml version="1.0" encoding="UTF-8" standalone="yes"?>
      <ResponseSet vers="1.0" svcid="auth" reqid="0">
      <Response><![CDATA[<?xml version="1.0" encoding="UTF-8"?>
      <AuthContext version="1.0"><Response authIdentifier="2yPFIKj-T-pm-SCisADgs55qkmM.*AAJTSQACMDMAAlNLABxwM2oxVWMrL2MzSlE2OTRNb3lFdlB0eEx1Mmc9AAJTMQACMDE.*"><LoginStatus status="in_progress"></LoginStatus></Response></AuthContext>]]></Response>
      </ResponseSet>
      2017-12-14 20:55:35  send_login_request(): sending 1189 bytes to http://lb.example.com:8080/openam/authservice
      2017-12-14 20:55:35  send_login_request(): authenticate response status code: 200
      <?xml version="1.0" encoding="UTF-8" standalone="yes"?>
      <ResponseSet vers="1.0" svcid="auth" reqid="0">
      <Response><![CDATA[<?xml version="1.0" encoding="UTF-8"?>
      <AuthContext version="1.0"><Response authIdentifier="null"><Exception message="Session has timed out"  errorCode="110" templateName="session_timeout.jsp"></Exception></Response></AuthContext>]]></Response>
      <Response><![CDATA[<?xml version="1.0" encoding="UTF-8"?>
      <AuthContext version="1.0"><Response authIdentifier="null"><Exception message="Session has timed out"  errorCode="110" templateName="session_timeout.jsp"></Exception></Response></AuthContext>]]></Response>
      </ResponseSet>
      2017-12-14 20:55:35  am_agent_login(): closing connection after failure
      2017-12-14 20:55:35  error validating OpenAM agent configuration
      2017-12-14 20:55:35  installation error
      2017-12-14 20:55:35  installation exit

      You would see the same kind of error message on an installed agent trying to login to a cluster during normal uptime.

      Work around

      1) To install, you can either force install with AM down, or you can install on a server and modify the config afterwards to the lb

      2) You need to set com.sun.identity.agents.config.load.balancer.enable=true so that the agent uses amlbcookie. This will however not help for agent authentication process.

      3) You can "try" to set the setting org.forgerock.agents.config.keepalive.disable=false so that the agent uses a single socket connection for all of the login sequence call; however that requires the LB to support socket keepalives, which is not always the case

      OR

      You need to ensure stickiness through source address at the LB

      Note that this should no longer be an issue with Agents 5.x as they do not use the same process to login.

      Logs analysis

      When the issue shows on the agent debug logs, you will see the following scenario on the AM Authentication debug logs.

      On server1, the Authentication Identifier is created:

      amAuth:12/14/2017 08:55:35:664 PM GMT: Thread[http-nio-18080-exec-7,5,main]: TransactionId[fdaa1631-8062-4a8a-9f67-3be23bdb4193-2427]
      LoginState:createAuthenticationSession: New session/sid=2yPFIKj-T-pm-SCisADgs55qkmM.*AAJTSQACMDMAAlNLABxwM2oxVWMrL2MzSlE2OTRNb3lFdlB0eEx1Mmc9AAJTMQACMDE.*
      

      Then the rest of the authentication process reaches server2:

      amAuth:12/14/2017 08:55:35:863 PM GMT: Thread[http-nio-38080-exec-5,5,main]: TransactionId[eb5153dd-7ae6-4937-b790-8f378bc5c06d-642]
      Retrieving authentication session with sessionID 2yPFIKj-T-pm-SCisADgs55qkmM.*AAJTSQACMDMAAlNLABxwM2oxVWMrL2MzSlE2OTRNb3lFdlB0eEx1Mmc9AAJTMQACMDE.*
      amAuth:12/14/2017 08:55:35:863 PM GMT: Thread[http-nio-38080-exec-5,5,main]: TransactionId[eb5153dd-7ae6-4937-b790-8f378bc5c06d-642]
      getSession for %s
      amAuth:12/14/2017 08:55:35:920 PM GMT: Thread[http-nio-38080-exec-5,5,main]: TransactionId[eb5153dd-7ae6-4937-b790-8f378bc5c06d-642]
      getSession returned null
      amAuthUtils:12/14/2017 08:55:35:920 PM GMT: Thread[http-nio-38080-exec-5,5,main]: TransactionId[eb5153dd-7ae6-4937-b790-8f378bc5c06d-642]
      AuthUtil:getAuthContext:sid is.. .: 2yPFIKj-T-pm-SCisADgs55qkmM.*AAJTSQACMDMAAlNLABxwM2oxVWMrL2MzSlE2OTRNb3lFdlB0eEx1Mmc9AAJTMQACMDE.*
      amAuthUtils:12/14/2017 08:55:35:920 PM GMT: Thread[http-nio-38080-exec-5,5,main]: TransactionId[eb5153dd-7ae6-4937-b790-8f378bc5c06d-642]
      AuthUtil:getAuthContext:authContext is.. .: null
      amAuthUtils:12/14/2017 08:55:35:920 PM GMT: Thread[http-nio-38080-exec-5,5,main]: TransactionId[eb5153dd-7ae6-4937-b790-8f378bc5c06d-642]
      AuthUtil:getAuthContext:sessionUpgrade is.. .: false
      amAuthUtils:12/14/2017 08:55:35:920 PM GMT: Thread[http-nio-38080-exec-5,5,main]: TransactionId[eb5153dd-7ae6-4937-b790-8f378bc5c06d-642]
      AuthUtil:getAuthContext:ForceAuth is.. .: false
      amAuthUtils:12/14/2017 08:55:35:920 PM GMT: Thread[http-nio-38080-exec-5,5,main]: TransactionId[eb5153dd-7ae6-4937-b790-8f378bc5c06d-642]
      ERROR: Cannot create authcontext with null org
      amAuthUtils:12/14/2017 08:55:35:920 PM GMT: Thread[http-nio-38080-exec-5,5,main]: TransactionId[eb5153dd-7ae6-4937-b790-8f378bc5c06d-642]
      Creating AuthContextLocal 2: 
      com.sun.identity.authentication.service.AuthException: Session has timed out|session_timeout.jsp
              at com.sun.identity.authentication.service.AuthUtils.getAuthContext(AuthUtils.java:952)
              at com.sun.identity.authentication.server.AuthXMLRequestParser.parseXML(AuthXMLRequestParser.java:229)
              at com.sun.identity.authentication.server.AuthXMLRequest.parseXML(AuthXMLRequest.java:146)
              at com.sun.identity.authentication.server.AuthXMLHandler.processRequest(AuthXMLHandler.java:241)
              at com.sun.identity.authentication.server.AuthXMLHandler.process(AuthXMLHandler.java:144)
              at com.iplanet.services.comm.server.PLLRequestServlet.handleRequest(PLLRequestServlet.java:202)
              at com.iplanet.services.comm.server.PLLRequestServlet.doPost(PLLRequestServlet.java:140)
              at javax.servlet.http.HttpServlet.service(HttpServlet.java:648)
              at javax.servlet.http.HttpServlet.service(HttpServlet.java:729)
              at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:230)
              at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:165)
              at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:52)
              at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:192)
              at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:165)
              at org.forgerock.openam.validation.ResponseValidationFilter.doFilter(ResponseValidationFilter.java:36)
              at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:192)
              at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:165)
              at org.forgerock.openam.headers.SetHeadersFilter.doFilter(SetHeadersFilter.java:80)
              at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:192)
              at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:165)
              at com.sun.identity.setup.AMSetupFilter.doFilter(AMSetupFilter.java:111)
              at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:192)
              at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:165)
              at org.forgerock.openam.audit.context.AuditContextFilter.doFilter(AuditContextFilter.java:46)
              at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:192)
              at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:165)
              at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:198)
              at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:108)
              at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:472)
              at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:140)
              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:87)
              at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:349)
              at org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:784)
              at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:66)
              at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:802)
              at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1410)
              at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49)
              at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
              at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
              at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
              at java.lang.Thread.run(Thread.java:748)
      amAuthClientUtils:12/14/2017 08:55:35:924 PM GMT: Thread[http-nio-38080-exec-5,5,main]: TransactionId[eb5153dd-7ae6-4937-b790-8f378bc5c06d-642]
      errorCod='110', resProperty='Session has timed out|session_timeout.jsp'
      

        Attachments

          Activity

            People

            Unassigned Unassigned
            nathalie.hoet Nathalie Hoet
            Votes:
            1 Vote for this issue
            Watchers:
            8 Start watching this issue

              Dates

              Created:
              Updated: