6 Replies Latest reply on Dec 3, 2013 11:25 AM by Ryan Koziel

    Failed to re-establish the session for the returning user

      BSA 8.2.3.416

      Application servers: RHEL 5.9 64-bit

      DB Server: SQL Server 2008 on Windows 2008

       

      We have a process that will start a job in BSA by using the BSA web services over SOAP. Occasionally we are hitting the following exception:

       

      [12 Nov 2013 14:24:02,167] [http-9843-21] [ERROR] [BSMA-Auto:BLAdmins:10.22.50.134] [] Failed to re-establish the session for the returning user.

       

      The 'SessionCredentialLifetime' and 'MaximumSessionCredentialLifetime' configuration options under AuthServer have not been edited from their defaults (so 600 minutes/10 hours is the default from what I have read on communities). But the process is running all the time and we are only seeing the error every now and then (i.e. if the SessionCredentialLifetime was part of the issue I would expect to see it more often, like every 10 hours).

       

      For the BSA gurus out there, does anyone have any input on what would be causing it or what should be looked at? I see a message in the stack trace below (Caused by: com.bladelogic.om.infra.session.client.SessionRejectedException) and while it contains the phrase "caused by" I am not clear on what would cause the session to be rejected.

       

      The full stack trace, and other messages occurring before and after it with the same session ID, is below.

       

      Regards,
      Ryan

       

      [12 Nov 2013 14:24:01,796] [http-9843-21] [INFO] [::] [] LoginUsingUserCredentialResponse | Login Request with session id urn:uuid:1C36C77FEE8F7506281384291465409

      [12 Nov 2013 14:24:01,796] [http-9843-21] [INFO] [::] [] LoginUsingUserCredentialResponse | Login Request with transaction id null

      ...

      [12 Nov 2013 14:24:01,967] [http-9843-21] [INFO] [BSMA-Auto:Anonymous:10.22.50.134] [] User(BSMA-Auto) is authenticated with the authentication service.

      ...

      [12 Nov 2013 14:24:01,986] [http-9843-21] [INFO] [BSMA-Auto:Anonymous:10.22.50.134] [] Assuming the role: BLAdmins for the current soap session.

      ...

      [12 Nov 2013 14:24:02,069] [http-9843-21] [INFO] [BSMA-Auto:BLAdmins:10.22.50.134] [] Creating connection pool for urn:uuid:1C36C77FEE8F7506281384291465409

      ...

      [12 Nov 2013 14:24:02,167] [http-9843-21] [ERROR] [BSMA-Auto:BLAdmins:10.22.50.134] [] Exception when trying to fetch a connection from pool : urn:uuid:1C36C77FEE8F7506281384291465409 com.bladelogic.om.infra.mfw.util.BlException: java.io.SyncFailedException: lost message framing

      [12 Nov 2013 14:24:02,167] [http-9843-21] [ERROR] [BSMA-Auto:BLAdmins:10.22.50.134] [] Failed to re-establish the session for the returning user.

              at com.bladelogic.webservices.framework.WSInFlowAuthenticationHandler.invoke(WSInFlowAuthenticationHandler.java:216)

              at org.apache.axis2.engine.Phase.invoke(Phase.java:318)

              at org.apache.axis2.engine.AxisEngine.invoke(AxisEngine.java:251)

              at org.apache.axis2.engine.AxisEngine.receive(AxisEngine.java:160)

              at org.apache.axis2.transport.http.HTTPTransportUtils.processHTTPPostRequest(HTTPTransportUtils.java:167)

              at org.apache.axis2.transport.http.AxisServlet.doPost(AxisServlet.java:142)

              at javax.servlet.http.HttpServlet.service(HttpServlet.java:637)

              at javax.servlet.http.HttpServlet.service(HttpServlet.java:717)

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

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

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

              at org.apache.catalina.security.SecurityUtil$1.run(SecurityUtil.java:270)

              at org.apache.catalina.security.SecurityUtil$1.run(SecurityUtil.java:269)

              at java.security.AccessController.doPrivileged(Native Method)

              at javax.security.auth.Subject.doAsPrivileged(Subject.java:517)

              at org.apache.catalina.security.SecurityUtil.execute(SecurityUtil.java:302)

              at org.apache.catalina.security.SecurityUtil.doAsPrivilege(SecurityUtil.java:163)

              at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:283)

              at org.apache.catalina.core.ApplicationFilterChain.access$000(ApplicationFilterChain.java:56)

              at org.apache.catalina.core.ApplicationFilterChain$1.run(ApplicationFilterChain.java:189)

              at java.security.AccessController.doPrivileged(Native Method)

              at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:185)

              at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:233)

              at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:191)

              at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:127)

              at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:102)

              at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109)

              at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:298)

              at org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:859)

              at org.apache.coyote.http11.Http11Protocol$Http11ConnectionHandler.process(Http11Protocol.java:588)

              at org.apache.tomcat.util.net.JIoEndpoint$Worker.run(JIoEndpoint.java:489)

              at java.lang.Thread.run(Thread.java:662)

      Caused by: com.bladelogic.om.infra.session.client.SessionRejectedException

              at com.bladelogic.webservices.framework.WSSessionFactory.createClientConnectionPool(WSSessionFactory.java:541)

              at com.bladelogic.webservices.framework.WSSessionFactory.createClientSession(WSSessionFactory.java:303)

              at com.bladelogic.webservices.framework.WSAuthenticationFactory.reEstablishWSSession(WSAuthenticationFactory.java:373)

              at com.bladelogic.webservices.framework.WSInFlowAuthenticationHandler.invoke(WSInFlowAuthenticationHandler.java:211)

              ... 31 more

      ...

      [12 Nov 2013 15:00:31,974] [http-9843-21] [ERROR] [::] [] Unable to find corresponding context for the serviceGroupId: urn:uuid:1C36C77FEE8F7506281384291465409

      org.apache.axis2.AxisFault: Unable to find corresponding context for the serviceGroupId: urn:uuid:1C36C77FEE8F7506281384291465409

              at org.apache.axis2.context.ConfigurationContext.getServiceGroupContextFromSoapSessionTable(ConfigurationContext.java:541)

              at org.apache.axis2.context.ConfigurationContext.fillServiceContextAndServiceGroupContext(ConfigurationContext.java:249)

              at com.bladelogic.webservices.framework.WSInFlowDispatchPhase.loadContexts(WSInFlowDispatchPhase.java:264)

              at com.bladelogic.webservices.framework.WSInFlowDispatchPhase.checkPostConditions(WSInFlowDispatchPhase.java:153)

              at org.apache.axis2.engine.Phase.invoke(Phase.java:334)

              at org.apache.axis2.engine.AxisEngine.invoke(AxisEngine.java:251)

              at org.apache.axis2.engine.AxisEngine.receive(AxisEngine.java:160)

              at org.apache.axis2.transport.http.HTTPTransportUtils.processHTTPPostRequest(HTTPTransportUtils.java:167)

              at org.apache.axis2.transport.http.AxisServlet.doPost(AxisServlet.java:142)

              at javax.servlet.http.HttpServlet.service(HttpServlet.java:637)

              at javax.servlet.http.HttpServlet.service(HttpServlet.java:717)

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

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

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

              at org.apache.catalina.security.SecurityUtil$1.run(SecurityUtil.java:270)

              at org.apache.catalina.security.SecurityUtil$1.run(SecurityUtil.java:269)

              at java.security.AccessController.doPrivileged(Native Method)

              at javax.security.auth.Subject.doAsPrivileged(Subject.java:517)

              at org.apache.catalina.security.SecurityUtil.execute(SecurityUtil.java:302)

              at org.apache.catalina.security.SecurityUtil.doAsPrivilege(SecurityUtil.java:163)

              at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:283)

              at org.apache.catalina.core.ApplicationFilterChain.access$000(ApplicationFilterChain.java:56)

              at org.apache.catalina.core.ApplicationFilterChain$1.run(ApplicationFilterChain.java:189)

              at java.security.AccessController.doPrivileged(Native Method)

              at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:185)

              at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:233)

              at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:191)

              at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:127)

              at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:102)

              at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109)

              at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:298)

              at org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:859)

              at org.apache.coyote.http11.Http11Protocol$Http11ConnectionHandler.process(Http11Protocol.java:588)

              at org.apache.tomcat.util.net.JIoEndpoint$Worker.run(JIoEndpoint.java:489)

              at java.lang.Thread.run(Thread.java:662)

        • 1. Re: Failed to re-establish the session for the returning user
          John O'Toole

          Hi Ryan,

           

          Do you have multiple appservers in this environment? If so, since the issue occurs intermittently, have you noticed any pattern in which appservers display the following? Or does it occur across all intermittently?

           

          [12 Nov 2013 14:24:02,167] [http-9843-21] [ERROR] [BSMA-Auto:BLAdmins:10.22.50.134] [] Failed to re-establish the session for the returning user.

           

          I looked around and found only one other customer issue with this error. I'm not sure in that case if the issue was intermittent or not but it was closed with the following update:

           

          "this case can be closed.  the problem was caused by a second loopback address in /etc/hosts"

           

          Not sure if this will in any way be useful for you but thought I would share it since the error message matched.

           

          John

          • 2. Re: Failed to re-establish the session for the returning user
            Bill Robinson

            How often are you authenticating when you make the soap call ?

             

            Are you using a new session id for each call or trying to re-use something.

             

            Can you post whatever code is making the soap call ?

            • 3. Re: Failed to re-establish the session for the returning user

              Hi John - We have multiple application servers (hosts) and also multiple logical application servers on each host (3 JOB, 1 ALL). I haven't noticed any pattern; it occurs across all intermittently. I am not pointing to a load balancer (yet) just directly to one of the hosts.

               

              I checked the /etc/hosts file on the host that we're pointing to and there is no duplicate loopback entry; just the single loopback and also another entry for the hostname in the event DNS has an issue (something the SAs do as part of their standard). In talking with the SAs on this we don't think that should cause any problems but it could potentially be removed if it is.

               

              Regards,
              Ryan

              • 4. Re: Failed to re-establish the session for the returning user

                Hi Bill - With each CLI object we instantiate (CLITunnelService) we authenticate. That CLI is then re-used for subsequent requests, but each to do something we check on the status of the CLI:

                 

                        public void GetClient()
                        {
                            if (this.CLI == null)
                                EstablishSession();
                            else
                            {
                                if (IsExpiredSession())
                                    EstablishSession();
                            }
                        }

                 

                The way in which IsExpiredSession() works right now is by issuing a "Server serverExists" using the application server as the argument. If an exception is thrown then EstablishSession() is called which goes through the motions of creating the new CLI object.

                 

                        private void EstablishSession()
                        {
                            // Login.
                            LoginService l = new LoginService();
                            l.Url = _loginSvcEndpoint;
                            string u = _loginSvcUser;
                            string p = _loginSvcPassword;
                            string m = _loginSvcMethod;
                            string sessionID = string.Empty;
                            l.loginUsingUserCredential(u, p, m, out sessionID);

                 

                            // Assume configured role.
                            AssumeRoleService a = new AssumeRoleService();
                            a.Url = _assumeRoleSvcEndpoint;
                            string r = _roleToAssume;
                            string[] argsArr = new string[1];
                            argsArr[0] = sessionID;
                            a.sessionId = new @string();
                            a.sessionId.Text = argsArr;
                            a.assumeRole(r);

                 

                            // Create instance of the CLITunnelService class.
                            CLITunnelService c = new CLITunnelService();
                            c.Url = _cliTunnelSvcEndpoint;
                            c.sessionId = new @string();
                            c.sessionId.Text = argsArr;
                            this.CLI = c;
                        }

                 

                Not ideal but it works fine for the most part. I think it would be better to use the WS_SSOSessionCredential returned from the call to loginUsingUserCredential, which is something that needs to be looked at.

                 

                As far as the code that is kicking all of this off, we have a .NET implementation of the BLCLI commands. Below is the ExecuteAgainstServers method from our Job class.

                 

                        public static string ExecuteAgainstServers(NetBLCLI netCLI, string jobDBKey, List<string> servers)
                        {
                          ...

                 

                            netCLI.GetClient();
                          ...
                        }

                 

                Regards,

                Ryan

                • 5. Re: Failed to re-establish the session for the returning user
                  Bill Robinson

                  each tunnelservice connection should have its own auth and session id - it's possible the session gets closed down right when you try to re-use it ?

                  1 of 1 people found this helpful
                  • 6. Re: Failed to re-establish the session for the returning user

                    Each of the NetBLCLI objects has it's own CLITunnelService object (and it's own auth and session ID).

                     

                    As far as the session closing right before I try to re-use it...I believe that is what is happening. I was able to reproduce that during testing yesterday but only once (the check on a valid session succeeded milliseconds before it was to actually going to expire and be used - contributing to the randomness of the issue).

                     

                    I have put in a check to see if the session expiration is within a "window" of time relative to the current time (say 5 minutes) and if it is go ahead and re-establish the session rather than using the existing session that could potentially expire prior the call to CLITunnelService.

                     

                    So far that seems to be working well. I appreciate your response as it confirms what I ran into yesterday. I think that is the correct answer but will wait until I can confirm this with some more testing.