ICEpush
  1. ICEpush
  2. PUSH-144

ICEpush gets into a tight loop of requests for browser id when running as a portlet

    Details

    • Type: Bug Bug
    • Status: Closed
    • Priority: Major Major
    • Resolution: Fixed
    • Affects Version/s: 2.0-Alpha3
    • Fix Version/s: 3.0
    • Component/s: Push Library
    • Labels:
      None
    • Environment:
      ICEfaces 2 ICEpush 2 portlets portal

      Description

      You can easily reproduce the problem by running the chat-portlet example on Liferay. Only once instance is needed on a portal page. Bring up up the initial login panel and create a handle then click the button. This will start push and you can see in the client the tight request loop for getting the browser id.

      Adding some logging shows odd behaviour when the BrowserDispatcher.service method is called. The first time through, no servlet has been registered yet:

      BrowserDispatcher.service:
        browserId : 1gu01haq9
        dispatcher : org.icepush.servlet.MainServlet$1@12773a6
        servlets : {}

      24-Oct-2011 7:08:05 PM org.icepush.servlet.EnvironmentAdaptingServlet <init>
      INFO: Adapting to Thread Blocking environment

      24-Oct-2011 7:08:05 PM org.icepush.servlet.BrowserDispatcher$BrowserEntry <init>
      FINEST: New browser detected, assigning ID '1gu01haq9'.

      But the next request that comes in has a different browser id in the cookie which doesn't match the one we originally stored:

      BrowserDispatcher.service:
        browserId : 1gu5ua3fe
        dispatcher : org.icepush.servlet.MainServlet$1@12773a6
        servlets : {1gu01haq9=org.icepush.servlet.BrowserDispatcher$BrowserEntry@18476474}

      24-Oct-2011 7:08:06 PM org.icepush.servlet.EnvironmentAdaptingServlet <init>
      INFO: Adapting to Thread Blocking environment

      24-Oct-2011 7:08:06 PM org.icepush.servlet.BrowserDispatcher$BrowserEntry <init>
      FINEST: New browser detected, assigning ID '1gu5ua3fe'.

      This cycle is just repeated where the new cookie value coming in does not match any of the values in the map of servlets.

        Issue Links

          Activity

          Deryk Sinotte created issue -
          Hide
          Deryk Sinotte added a comment -

          Assigning to Mircea.

          Show
          Deryk Sinotte added a comment - Assigning to Mircea.
          Deryk Sinotte made changes -
          Field Original Value New Value
          Salesforce Case []
          Fix Version/s 2.1 [ 10259 ]
          Fix Version/s 2.0-Beta [ 10232 ]
          Assignee Priority P1
          Description You can easily reproduce the problem by running the chat-portlet example on Liferay. Only once instance is needed on a portal page. Bring up up the initial login panel and create a handle then click the button. This will start push and you can see in the client the tight request loop for getting the browser id.

          Adding some logging shows odd behaviour when the BrowserDispatcher.service method is called. The first time through, no servlet has been registered yet:

          BrowserDispatcher.service:
            browserId : 1gu01haq9
            dispatcher : org.icepush.servlet.MainServlet$1@12773a6
            servlets : {}

          24-Oct-2011 7:08:05 PM org.icepush.servlet.EnvironmentAdaptingServlet <init>
          INFO: Adapting to Thread Blocking environment

          24-Oct-2011 7:08:05 PM org.icepush.servlet.BrowserDispatcher$BrowserEntry <init>
          FINEST: New browser detected, assigning ID '1gu01haq9'.

          But the next request that comes in has a different browser id in the cookie which doesn't match the one we originally stored:

          BrowserDispatcher.service:
            browserId : 1gu5ua3fe
            dispatcher : org.icepush.servlet.MainServlet$1@12773a6
            servlets : {1gu01haq9=org.icepush.servlet.BrowserDispatcher$BrowserEntry@18476474}

          24-Oct-2011 7:08:06 PM org.icepush.servlet.EnvironmentAdaptingServlet <init>
          INFO: Adapting to Thread Blocking environment

          24-Oct-2011 7:08:06 PM org.icepush.servlet.BrowserDispatcher$BrowserEntry <init>
          FINEST: New browser detected, assigning ID '1gu5ua3fe'.
          You can easily reproduce the problem by running the chat-portlet example on Liferay. Only once instance is needed on a portal page. Bring up up the initial login panel and create a handle then click the button. This will start push and you can see in the client the tight request loop for getting the browser id.

          Adding some logging shows odd behaviour when the BrowserDispatcher.service method is called. The first time through, no servlet has been registered yet:

          BrowserDispatcher.service:
            browserId : 1gu01haq9
            dispatcher : org.icepush.servlet.MainServlet$1@12773a6
            servlets : {}

          24-Oct-2011 7:08:05 PM org.icepush.servlet.EnvironmentAdaptingServlet <init>
          INFO: Adapting to Thread Blocking environment

          24-Oct-2011 7:08:05 PM org.icepush.servlet.BrowserDispatcher$BrowserEntry <init>
          FINEST: New browser detected, assigning ID '1gu01haq9'.

          But the next request that comes in has a different browser id in the cookie which doesn't match the one we originally stored:

          BrowserDispatcher.service:
            browserId : 1gu5ua3fe
            dispatcher : org.icepush.servlet.MainServlet$1@12773a6
            servlets : {1gu01haq9=org.icepush.servlet.BrowserDispatcher$BrowserEntry@18476474}

          24-Oct-2011 7:08:06 PM org.icepush.servlet.EnvironmentAdaptingServlet <init>
          INFO: Adapting to Thread Blocking environment

          24-Oct-2011 7:08:06 PM org.icepush.servlet.BrowserDispatcher$BrowserEntry <init>
          FINEST: New browser detected, assigning ID '1gu5ua3fe'.

          This cycle is just repeated where the new cookie value coming in does not match any of the values in the map of servlets.
          Assignee Mircea Toma [ mircea.toma ]
          Hide
          Deryk Sinotte added a comment -

          Also meant to add that I'm seeing, on the client, two values for the browser cookie. From Chrome's console:

          Cookie:csfcfc=3Xfn_3Xfn; ice.push.browser=8agu5rj1qg; COOKIE_SUPPORT=true; ice.push.browser=1gu01haq9; COMPANY_ID=1; ID=3670776a4d466c2b7356493d; PASSWORD=50514d304c3651686973303d; LOGIN=6272756e6f4037636f67732e636f6d; SCREEN_NAME=50514d304c3651686973303d; LFR_SESSION_STATE_10870=1319240774163; ice.pushids=; JSESSIONID=9B4C6C91F276F2815EBD4477692C2B16; GUEST_LANGUAGE_ID=en_US; ice.connection.contextpath=/; ice.connection.running=ba44d:acquired; ice.connection.lease=1319479979999

          Perhaps the cookie pathing logic is not quite working in portlets.

          Show
          Deryk Sinotte added a comment - Also meant to add that I'm seeing, on the client, two values for the browser cookie. From Chrome's console: Cookie:csfcfc=3Xfn_3Xfn; ice.push.browser=8agu5rj1qg; COOKIE_SUPPORT=true; ice.push.browser=1gu01haq9; COMPANY_ID=1; ID=3670776a4d466c2b7356493d; PASSWORD=50514d304c3651686973303d; LOGIN=6272756e6f4037636f67732e636f6d; SCREEN_NAME=50514d304c3651686973303d; LFR_SESSION_STATE_10870=1319240774163; ice.pushids=; JSESSIONID=9B4C6C91F276F2815EBD4477692C2B16; GUEST_LANGUAGE_ID=en_US; ice.connection.contextpath=/; ice.connection.running=ba44d:acquired; ice.connection.lease=1319479979999 Perhaps the cookie pathing logic is not quite working in portlets.
          Ken Fyten made changes -
          Salesforce Case []
          Affects [Documentation (User Guide, Ref. Guide, etc.)]
          Deryk Sinotte made changes -
          Link This issue blocks ICE-7190 [ ICE-7190 ]
          Hide
          Deryk Sinotte added a comment -

          This issue prevents Ajax Push from operating properly with portlets when running with MyFaces.

          Show
          Deryk Sinotte added a comment - This issue prevents Ajax Push from operating properly with portlets when running with MyFaces.
          Hide
          Deryk Sinotte added a comment -

          So it looks as if the problem is related to ConfigurationServer and some logic about redirect. Logging indicates that when the request comes in with a cookie that has an unknown browser id, we set a new one and add it as a BrowserEntry but right after that, we send a response back with a newly generated one. Because of this, the next browser id cookie is always "new".

          BrowserDispatcher.service:
          browserId : 1guh72fju
          dispatcher : org.icepush.servlet.MainServlet$1@3abc6623
          servlets :

          {1bguh694y9=org.icepush.servlet.BrowserDispatcher$BrowserEntry@47596c17}

          BrowserDispatcher.checkSession: could not find 1guh72fju
          1-Nov-2011 5:51:31 PM org.icepush.servlet.EnvironmentAdaptingServlet <init>
          INFO: Adapting to Thread Blocking environment
          1-Nov-2011 5:51:31 PM org.icepush.servlet.BrowserDispatcher$BrowserEntry <init>
          FINEST: new browser detected with id 1guh72fju
          1-Nov-2011 5:51:31 PM org.icepush.ConfigurationServer$SetBrowserID writeTo
          FINE: new browser id generated: 2guh72fkh

          BrowserDispatcher.getBrowserIDFromCookie:
          name : ice.push.browser
          value : 2guh72fkh
          path : null
          BrowserDispatcher.service:
          browserId : 2guh72fkh
          dispatcher : org.icepush.servlet.MainServlet$1@3abc6623
          servlets :

          {1guh72fju=org.icepush.servlet.BrowserDispatcher$BrowserEntry@19d4a8bf, 1bguh694y9=org.icepush.servlet.BrowserDispatcher$BrowserEntry@47596c17}

          BrowserDispatcher.checkSession: could not find 2guh72fkh
          1-Nov-2011 5:51:31 PM org.icepush.servlet.EnvironmentAdaptingServlet <init>
          INFO: Adapting to Thread Blocking environment
          1-Nov-2011 5:51:31 PM org.icepush.servlet.BrowserDispatcher$BrowserEntry <init>
          FINEST: new browser detected with id 2guh72fkh
          1-Nov-2011 5:51:31 PM org.icepush.ConfigurationServer$SetBrowserID writeTo
          FINE: new browser id generated: 3guh72fl7

          The problem appears to be in ConfigurationServer.service. In here there is a check based on "redirect || request.containsParameter("ice.sendConfiguration")" which is always true because redirect is always true. Once inside the block, the browserIDCookie is always "null" so we immediately send back a response with a newly generated browser id and the cycle repeats:

          public void service(Request request) throws Exception {
          Cookie browserIDCookie = Cookie.readCookie(request, BrowserIDCookieName);

          if (redirect || request.containsParameter("ice.sendConfiguration")) {
          boolean browserIDNotSet = browserIDCookie == null;
          if (nonDefaultConfiguration && browserIDNotSet)

          { request.respondWith(setBrowserIDAndConfigureBridgeMacro); }

          else if (nonDefaultConfiguration)

          { request.respondWith(configureBridge); }

          else if (browserIDNotSet)

          { request.respondWith(setBrowserID); }

          else

          { blockingConnectionServer.service(request); }

          } else

          { blockingConnectionServer.service(request); }

          }

          So either the redirect calculation is incorrect or the check for the cookie is not being done properly. Logging that particular section shows that the redirect calculation will always be true

          redirect = context != null && !servletContext.getContextPath().equals(contextPath);

          because the two context paths never match.

          ConfigurationServer:
          context : org.icepush.PushContext@2c26618f
          original context path: null
          servlet context path : /chat-portlet
          match : false

          Show
          Deryk Sinotte added a comment - So it looks as if the problem is related to ConfigurationServer and some logic about redirect. Logging indicates that when the request comes in with a cookie that has an unknown browser id, we set a new one and add it as a BrowserEntry but right after that, we send a response back with a newly generated one. Because of this, the next browser id cookie is always "new". BrowserDispatcher.service: browserId : 1guh72fju dispatcher : org.icepush.servlet.MainServlet$1@3abc6623 servlets : {1bguh694y9=org.icepush.servlet.BrowserDispatcher$BrowserEntry@47596c17} BrowserDispatcher.checkSession: could not find 1guh72fju 1-Nov-2011 5:51:31 PM org.icepush.servlet.EnvironmentAdaptingServlet <init> INFO: Adapting to Thread Blocking environment 1-Nov-2011 5:51:31 PM org.icepush.servlet.BrowserDispatcher$BrowserEntry <init> FINEST: new browser detected with id 1guh72fju 1-Nov-2011 5:51:31 PM org.icepush.ConfigurationServer$SetBrowserID writeTo FINE: new browser id generated: 2guh72fkh BrowserDispatcher.getBrowserIDFromCookie: name : ice.push.browser value : 2guh72fkh path : null BrowserDispatcher.service: browserId : 2guh72fkh dispatcher : org.icepush.servlet.MainServlet$1@3abc6623 servlets : {1guh72fju=org.icepush.servlet.BrowserDispatcher$BrowserEntry@19d4a8bf, 1bguh694y9=org.icepush.servlet.BrowserDispatcher$BrowserEntry@47596c17} BrowserDispatcher.checkSession: could not find 2guh72fkh 1-Nov-2011 5:51:31 PM org.icepush.servlet.EnvironmentAdaptingServlet <init> INFO: Adapting to Thread Blocking environment 1-Nov-2011 5:51:31 PM org.icepush.servlet.BrowserDispatcher$BrowserEntry <init> FINEST: new browser detected with id 2guh72fkh 1-Nov-2011 5:51:31 PM org.icepush.ConfigurationServer$SetBrowserID writeTo FINE: new browser id generated: 3guh72fl7 The problem appears to be in ConfigurationServer.service. In here there is a check based on "redirect || request.containsParameter("ice.sendConfiguration")" which is always true because redirect is always true. Once inside the block, the browserIDCookie is always "null" so we immediately send back a response with a newly generated browser id and the cycle repeats: public void service(Request request) throws Exception { Cookie browserIDCookie = Cookie.readCookie(request, BrowserIDCookieName); if (redirect || request.containsParameter("ice.sendConfiguration")) { boolean browserIDNotSet = browserIDCookie == null; if (nonDefaultConfiguration && browserIDNotSet) { request.respondWith(setBrowserIDAndConfigureBridgeMacro); } else if (nonDefaultConfiguration) { request.respondWith(configureBridge); } else if (browserIDNotSet) { request.respondWith(setBrowserID); } else { blockingConnectionServer.service(request); } } else { blockingConnectionServer.service(request); } } So either the redirect calculation is incorrect or the check for the cookie is not being done properly. Logging that particular section shows that the redirect calculation will always be true redirect = context != null && !servletContext.getContextPath().equals(contextPath); because the two context paths never match. ConfigurationServer: context : org.icepush.PushContext@2c26618f original context path: null servlet context path : /chat-portlet match : false
          Hide
          Deryk Sinotte added a comment -

          At this point, I'm not sure if the non-matching context paths are the root issue or whether the null "Cookie" header value check afterward is the ultimate culprit.

          Show
          Deryk Sinotte added a comment - At this point, I'm not sure if the non-matching context paths are the root issue or whether the null "Cookie" header value check afterward is the ultimate culprit.
          Repository Revision Date User Message
          ICEsoft Public SVN Repository #26201 Wed Nov 02 09:09:03 MDT 2011 deryk.sinotte PUSH-144: additional strategy for getting browserID from the incoming cookies to prevent failure in portlets
          Files Changed
          Commit graph MODIFY /icepush/trunk/icepush/core/src/main/java/org/icepush/http/standard/Cookie.java
          Commit graph MODIFY /icepush/trunk/icepush/core/src/main/java/org/icepush/http/standard/RequestProxy.java
          Commit graph MODIFY /icepush/trunk/icepush/core/src/main/java/org/icepush/servlet/ServletRequestResponse.java
          Commit graph MODIFY /icepush/trunk/icepush/core/src/main/java/org/icepush/http/Request.java
          Hide
          Deryk Sinotte added a comment -

          Mircea suggested fixing the logic where we attempt to find the Cookie header. It appears that Liferay (or perhaps the PortletFaces Bridge) may be stripping out the actual "Cookie" header but it's still available via the original request.getCookies() method. So I've added an extra attempt to get the cookie via this method.

          Show
          Deryk Sinotte added a comment - Mircea suggested fixing the logic where we attempt to find the Cookie header. It appears that Liferay (or perhaps the PortletFaces Bridge) may be stripping out the actual "Cookie" header but it's still available via the original request.getCookies() method. So I've added an extra attempt to get the cookie via this method.
          Deryk Sinotte made changes -
          Status Open [ 1 ] Resolved [ 5 ]
          Affects [Documentation (User Guide, Ref. Guide, etc.)]
          Resolution Fixed [ 1 ]
          Assignee Mircea Toma [ mircea.toma ] Deryk Sinotte [ deryk.sinotte ]
          Ken Fyten made changes -
          Status Resolved [ 5 ] Closed [ 6 ]
          Assignee Priority P1

            People

            • Assignee:
              Deryk Sinotte
              Reporter:
              Deryk Sinotte
            • Votes:
              0 Vote for this issue
              Watchers:
              0 Start watching this issue

              Dates

              • Created:
                Updated:
                Resolved: