ICEfaces
  1. ICEfaces
  2. ICE-2607

Query does not contain parameter named: ice.session

          Details

          • Type: Bug Bug
          • Status: Closed
          • Priority: Major Major
          • Resolution: Fixed
          • Affects Version/s: 1.6.2, 1.7DR#2
          • Fix Version/s: 1.7RC1, 1.7
          • Component/s: None
          • Labels:
            None
          • Environment:
            Tomcat 5.5.23 on Windows 2000 Server
            Tomcat 6.0
            Glassfish v2

            Description

            ICEfaces throws this exception after user leaves the application open in the browser for an undefined length of time.
            Doesn't always occur. Another user may leave the application open all day, only using it intermittently, and has no such exception.

            http://jira.icefaces.org/browse/ICE-2143 was closed off as not reproducible.


            java.lang.RuntimeException: Query does not contain parameter named: ice.session
            at com.icesoft.faces.webapp.http.servlet.ServletRequestResponse.checkExistenceOf(ServletRequestResponse.java:231)
            at com.icesoft.faces.webapp.http.servlet.ServletRequestResponse.getParameter(ServletRequestResponse.java:97)
            at com.icesoft.faces.webapp.http.core.IDVerifier.service(IDVerifier.java:23)
            at com.icesoft.faces.webapp.http.common.standard.PathDispatcherServer$Matcher.serviceOnMatch(PathDispatcherServer.java:50)
            at com.icesoft.faces.webapp.http.common.standard.PathDispatcherServer.service(PathDispatcherServer.java:19)
            at com.icesoft.faces.webapp.http.servlet.ThreadBlockingAdaptingServlet.service(ThreadBlockingAdaptingServlet.java:19)
            at com.icesoft.faces.webapp.http.servlet.EnvironmentAdaptingServlet.service(EnvironmentAdaptingServlet.java:29)
            at com.icesoft.faces.webapp.http.servlet.MainSessionBoundServlet.service(MainSessionBoundServlet.java:117)
            at com.icesoft.faces.webapp.http.servlet.SessionDispatcher.service(SessionDispatcher.java:35)
            at com.icesoft.faces.webapp.http.servlet.PathDispatcher$Matcher.serviceOnMatch(PathDispatcher.java:52)
            at com.icesoft.faces.webapp.http.servlet.PathDispatcher.service(PathDispatcher.java:29)
            at com.icesoft.faces.webapp.http.servlet.MainServlet.service(MainServlet.java:76)
            at javax.servlet.http.HttpServlet.service(HttpServlet.java:803)
            at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:269)
            at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:188)
            at org.apache.catalina.core.ApplicationDispatcher.invoke(ApplicationDispatcher.java:691)
            at org.apache.catalina.core.ApplicationDispatcher.processRequest(ApplicationDispatcher.java:469)
            at org.apache.catalina.core.ApplicationDispatcher.doForward(ApplicationDispatcher.java:364)
            at org.apache.catalina.core.ApplicationDispatcher.forward(ApplicationDispatcher.java:301)
            at com.icesoft.faces.webapp.xmlhttp.BlockingServlet.service(BlockingServlet.java:54)
            at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:269)
            at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:188)
            at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:210)
            at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:174)
            at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:127)
            at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:117)
            at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:108)
            at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:151)
            at org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:870)
            at org.apache.coyote.http11.Http11BaseProtocol$Http11ConnectionHandler.processConnection(Http11BaseProtocol.java:665)
            at org.apache.tomcat.util.net.PoolTcpEndpoint.processSocket(PoolTcpEndpoint.java:528)
            at org.apache.tomcat.util.net.LeaderFollowerWorkerThread.runIt(LeaderFollowerWorkerThread.java:81)
            at org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run(ThreadPool.java:685)
            at java.lang.Thread.run(Unknown Source)


              Issue Links

              is duplicated by

              Bug - A problem which impairs or prevents the functions of the product. ICE-2143 BlockingServlet throws java.lang.RuntimeException: "Query does not contain parameter named: ice.session" in Liferay 4.3.2

              • Major - Major loss of function.
              • Closed

                Activity

                Ascending order - Click to sort in descending order
                12 older comments
                Hide
                Permalink
                Greg Dick added a comment -

                Here's a snippet of the IE javascript log when a message missing the ice.session parameter is posted. It may be informative.

                3:36:13 info [window.async-connection.heartbeat] : ping
                3:36:15 debug [window.async-connection.ui] : [2511824] : send asynchronous POST
                3:36:16 debug [window.async-connection.blocking] : [5947530] : receive [200] OK
                3:36:16 debug [window.async-connection.ui] : [2511824] : receive [200] OK
                3:36:16 debug [window.async-connection.ui] : [2510065] : send asynchronous POST
                3:36:16 debug [window.async-connection] : closing previous connection...
                3:36:16 debug [window.async-connection.blocking] : [5947530] : connection closed
                3:36:16 debug [window.async-connection] : connect...
                3:36:17 debug [window.async-connection.blocking] : [3875609] : send asynchronous POST
                3:36:17 warn [window.async-connection.heartbeat] : pong lost
                3:36:17 warn [window] : connection in trouble
                3:36:17 debug [window.async-connection] : retry to connect...
                3:36:17 debug [window.async-connection] : closing previous connection...
                3:36:17 debug [window.async-connection.blocking] : [3875609] : connection closed
                3:36:17 debug [window.async-connection] : connect...
                3:36:18 debug [window.async-connection.blocking] : [1931911] : send asynchronous POST
                3:36:18 debug [window.async-connection.ui] : [2510065] : receive [200] OK
                3:36:18 info [window.async-connection.heartbeat] : pong
                3:36:18 debug [window.async-connection.ui] : [2510065] : connection closed
                3:36:36 info [window.async-connection.heartbeat] : ping

                I would suspect that the portion of the code where it says 'retry to connect' followed by "closing previous connection" is exactly the place where the ngrep log shows the [AF] protocol packets, and that further, this is happening at exactly the wrong time for the exchange that is ongoing at that time. Once the session is expired, the following output is logged:

                3:42:50 info [window.async-connection.heartbeat] : ping
                3:42:50 debug [window.async-connection.ui] : [2293878] : send asynchronous POST
                3:42:50 debug [window.async-connection.ui] : [2293878] : receive [200] OK
                3:42:53 warn [window.async-connection.heartbeat] : pong lost
                3:42:53 warn [window] : connection in trouble
                3:42:53 debug [window.async-connection] : retry to connect...
                3:43:10 info [window.async-connection.heartbeat] : ping
                3:43:10 debug [window.async-connection.ui] : [5219114] : send asynchronous POST
                3:43:11 debug [window.async-connection.ui] : [5219114] : receive [200] OK
                3:43:13 warn [window.async-connection.heartbeat] : pong lost
                3:43:13 warn [window] : connection in trouble
                3:43:13 debug [window.async-connection] : retry to connect...
                3:43:31 info [window.async-connection.heartbeat] : ping
                3:43:31 debug [window.async-connection.ui] : [2266888] : send asynchronous POST
                3:43:31 debug [window.async-connection.ui] : [2266888] : receive [200] OK
                3:43:34 warn [window.async-connection.heartbeat] : pong lost
                3:43:34 warn [window] : connection in trouble
                3:43:34 debug [window.async-connection] : retry to connect...

                Which provides ample opportunity for the error to occur.

                Show
                Greg Dick added a comment - Here's a snippet of the IE javascript log when a message missing the ice.session parameter is posted. It may be informative. 3:36:13 info [window.async-connection.heartbeat] : ping 3:36:15 debug [window.async-connection.ui] : [2511824] : send asynchronous POST 3:36:16 debug [window.async-connection.blocking] : [5947530] : receive [200] OK 3:36:16 debug [window.async-connection.ui] : [2511824] : receive [200] OK 3:36:16 debug [window.async-connection.ui] : [2510065] : send asynchronous POST 3:36:16 debug [window.async-connection] : closing previous connection... 3:36:16 debug [window.async-connection.blocking] : [5947530] : connection closed 3:36:16 debug [window.async-connection] : connect... 3:36:17 debug [window.async-connection.blocking] : [3875609] : send asynchronous POST 3:36:17 warn [window.async-connection.heartbeat] : pong lost 3:36:17 warn [window] : connection in trouble 3:36:17 debug [window.async-connection] : retry to connect... 3:36:17 debug [window.async-connection] : closing previous connection... 3:36:17 debug [window.async-connection.blocking] : [3875609] : connection closed 3:36:17 debug [window.async-connection] : connect... 3:36:18 debug [window.async-connection.blocking] : [1931911] : send asynchronous POST 3:36:18 debug [window.async-connection.ui] : [2510065] : receive [200] OK 3:36:18 info [window.async-connection.heartbeat] : pong 3:36:18 debug [window.async-connection.ui] : [2510065] : connection closed 3:36:36 info [window.async-connection.heartbeat] : ping I would suspect that the portion of the code where it says 'retry to connect' followed by "closing previous connection" is exactly the place where the ngrep log shows the [AF] protocol packets, and that further, this is happening at exactly the wrong time for the exchange that is ongoing at that time. Once the session is expired, the following output is logged: 3:42:50 info [window.async-connection.heartbeat] : ping 3:42:50 debug [window.async-connection.ui] : [2293878] : send asynchronous POST 3:42:50 debug [window.async-connection.ui] : [2293878] : receive [200] OK 3:42:53 warn [window.async-connection.heartbeat] : pong lost 3:42:53 warn [window] : connection in trouble 3:42:53 debug [window.async-connection] : retry to connect... 3:43:10 info [window.async-connection.heartbeat] : ping 3:43:10 debug [window.async-connection.ui] : [5219114] : send asynchronous POST 3:43:11 debug [window.async-connection.ui] : [5219114] : receive [200] OK 3:43:13 warn [window.async-connection.heartbeat] : pong lost 3:43:13 warn [window] : connection in trouble 3:43:13 debug [window.async-connection] : retry to connect... 3:43:31 info [window.async-connection.heartbeat] : ping 3:43:31 debug [window.async-connection.ui] : [2266888] : send asynchronous POST 3:43:31 debug [window.async-connection.ui] : [2266888] : receive [200] OK 3:43:34 warn [window.async-connection.heartbeat] : pong lost 3:43:34 warn [window] : connection in trouble 3:43:34 debug [window.async-connection] : retry to connect... Which provides ample opportunity for the error to occur.
                Hide
                Permalink
                Mircea Toma added a comment -

                Remove delay when starting monitoring thread (1.6 branch). This fixes the problem we saw with pings being sent repeatedly after the session-expired message was received by the bridge.

                We cannot reproduce the issue with the trunk (1.7 release), so no changes were necessary.

                Show
                Mircea Toma added a comment - Remove delay when starting monitoring thread (1.6 branch). This fixes the problem we saw with pings being sent repeatedly after the session-expired message was received by the bridge. We cannot reproduce the issue with the trunk (1.7 release), so no changes were necessary.
                Hide
                Permalink
                Ken Fyten added a comment -

                Previous changes have not completely resolved this issue. Re-opened.

                Show
                Ken Fyten added a comment - Previous changes have not completely resolved this issue. Re-opened.
                Hide
                Permalink
                Mircea Toma added a comment -

                After more debugging it seems that some of the requests coming from the browser don't contain any parameters at all. The logs also show that Tomcat fails to parse the HTTP requests. This might be caused by a very fast interaction with the page, creating a lot of successive AJAX request that might cancel each other.

                Show
                Mircea Toma added a comment - After more debugging it seems that some of the requests coming from the browser don't contain any parameters at all. The logs also show that Tomcat fails to parse the HTTP requests. This might be caused by a very fast interaction with the page, creating a lot of successive AJAX request that might cancel each other.
                Hide
                Permalink
                Mircea Toma added a comment -

                Improved request verification. Drop connections for invalid requests.

                Show
                Mircea Toma added a comment - Improved request verification. Drop connections for invalid requests.

                  People

                  • Assignee:
                    Unassigned
                    Reporter:
                    Philip Ralph
                  • Votes:
                    1 Vote for this issue
                    Watchers:
                    2 Start watching this issue

                    Dates

                    • Created:
                      Updated:
                      Resolved: