Session Expired - Early expiration based on some machines

Support
#1

We’re seeing a bit of an odd behavior with some clients with regard to user session expiration. By default, CUBA has a 30 minute session timeout which we haven’t changed.

We’ve deployed our application on our servers. When we hit the application from our network, that 30 minute timeout appears to be honored. However, many of our clients are seeing their sessions expire much, much quicker than that. We’ve seen it ourselves from off-site. Sessions can end after as quick as 3-4 minutes of inactivity.

Has anyone encountered this behavior? Could it be a policy thing on their networks that is causing this?

#2

I’m experiencing similar problem.
I have a test application deployed on my home server as UberJar + Postgresql 9.4.
Cuba platform version 6.7.4, server Raspberry Pi 3.
The application runs surprisingly fast on this configuration and I can connect and work normally from different places and devices.
So far I found one place - my office - where I have the connection timeout problems. I’ve tried different browsers and the problem is the same. Jetty kicks me out after 30-60 seconds after the login.
This is what I found in the app.log. I hope this could help to identify the problem:

> 2017-12-19 09:55:18.272 WARN  [qtp13257035-13/zero-cent/admin] org.atmosphere.cpr.DefaultBroadcaster - Duplicate resource 75a20a57-02c6-4ccf-98de-45fbb4c7c12d. Could be caused by a dead connection not detected by your server. Replacing the old one with the fresh one
> 2017-12-19 09:56:18.481 WARN  [qtp13257035-13/zero-cent/admin] org.atmosphere.cpr.AtmosphereResourceImpl - Exception during suspend() operation java.lang.IllegalStateException: Response is committed
> 2017-12-19 09:56:18.489 WARN  [qtp13257035-13/zero-cent/admin] org.atmosphere.cpr.AtmosphereResourceImpl - Listener error {}
#3

Hi,

Currently, it is really hard to say what is wrong and why sessions are expiring.

Could you please share more details of your deployment? What version of CUBA do you use?

Do you have any HTTP proxy or Internet proxy between your server and users? Do you use two or more tomcat / jetty instances on the same domain name?

#4

I can speak on behalf of Ryan, our setup is:

  • Windows Server 2012R2
  • Apache Tomcat 9.0.1 using a Tomcat Connector isapi_redirect.dll.
  • IIS 8.5.9600

We have IIS running in which the redirector is setup to redirect the specific cuba application to Tomcat.

https://tomcat.apache.org/connectors-doc/reference/iis.html

we are also running SSL with a public certificate.

we are running the latest Cuba 6.7.6

we do not have a proxy between our server and clients other than standard firewall rules.

#5

Why do you need to use IIS and isapi_redirect with Tomcat? Is the problem reproduced without IIS? Do you have two or more Tomcat servers behind IIS?

#6

I think that problem with Jetty is not related to IIS redirects installation. Could you please open a separate topic and describe your problem in details there?

#7

The reason for IIS is that there is other websites also being hosted using IIS. Since the main point of entry is to IIS, to allow the site to be hosted without the customer having to put in :8080 in the URL, redirection is required.

#8

If I understand you are using IIS as proxy server. Is it correct? Or it is used only for initial redirect of URL to Tomcat :8080 port? What session timeout is set in IIS config?

#9

Hi Yuriy,

Thanks for the continued help on this. The IIS timeout is set to 30 minutes for both the website and the application pool, which is the same as the CUBA/Tomcat settings.

I’ve enabled the User Session Log for our client’s application and it seems like the server is just continually issuing new sessions to the same client. I can see the same User and IP Address with active sessions multiple times, and then over time, old sessions that are no longer used by the client expire 30 minutes later.

I’ve attached the log I get from Vaadin debug when this occurs. It’s pretty consistent that the application will timeout after just 5 minutes, which I’ve read is the default VAADIN heartbeat. In this instance, customer might have deployed the application behind an HTTP proxy. Could the fact that the heartbeat doesn’t reach my client machine cause the browser to invalidate the session?

vaadinlog.xlsx (21.1 KB)

#10

I see that somehow push connection is established only after 5 min of inactivity (301347ms). That is really strange.

Let’s try to figure out what is going on.

First of all, enable logging of HTTP session expiration in logback.xml config or using Server Login window:

<logger name="com.haulmont.cuba.core.sys" level="DEBUG"/>

You will see the following log statements in app.log:

2018-01-08 16:38:37.090 DEBUG [ContainerBackgroundProcessor[StandardEngine[Catalina]]] com.haulmont.cuba.web.sys.CubaVaadinServletService - HttpSession destroyed: org.apache.catalina.session.StandardSessionFacade@5d9b1bd5

If thread is ContainerBackgroundProcessor then session has been evicted by servlet container due to inactivity.

Second, there is a chance that your problem is related to this Vaadin issue: Heartbeats blocked during long run request · Issue #9663 · vaadin/framework · GitHub This issue has been fixed in Vaadin 7.7.13 and we will bring updated Vaadin version in the very next bug fix release 6.7.7 https://youtrack.cuba-platform.com/issue/PL-10210

I’d recommend that you properly set proxy settings if your customers use something like Nginx / Apache proxy: Server Push Settings - CUBA Platform. Developer’s Manual Take into account these headers:

    proxy_set_header Upgrade $http_upgrade;
    proxy_set_header Connection "upgrade";

Also, you can try to disable WebSocket (cuba.web.pushEnabled app property) or switch to long polling directly using cuba.web.pushLongPolling app property. It seems that the problem is somehow related to WebSocket and proxy settings.

Are there heartbeat log statements in your app.log like the following ?

2018-01-08 16:43:40.570 DEBUG [http-nio-8080-exec-10/app/admin] com.haulmont.cuba.web.App - Ping middleware session

There should be 3 log statements per session life time, thus if session timeout is 30min - every 10 min.

#11

Hi Yuriy,

Here’s the log file that the customer sent us shortly after he experienced a client side “Session expired” message after only a couple minutes in the system.

We’re working on getting their project upgraded to the newest hotfix release to rule out the Vaadin issue you linked and I’ll follow up with the results of that once I can. Just wanted to leave this log file here in case you could tell what is happening. We don’t seem to get any HttpSession destroyed message occurring when this happens.

stdout.2018-01-10.log (506.1 KB)

#12

2018-01-10 16:16:29.450 DEBUG [ajp-nio-8009-exec-8/] com.haulmont.cuba.web.App - Ping session

It seems that you use AJP connector with Apache Server proxy, don’t you? Did you set up WebSocket options for this proxy?

We don’t seem to get any HttpSession destroyed message occurring when this happens.

As I see you didn’t set logging of the com.haulmont.cuba.core.sys to DEBUG.

#13

Hi Yuriy,

Thanks for the help on this. Sorry I got busy and haven’t been able to follow back up. There definitely is some type of WebSocket issue happening here because each time I get the Session Expiration occurring, I get this in the debug logs:

08-Feb-2018 06:27:16.978 SEVERE [ajp-nio-8013-exec-5] org.apache.catalina.core.StandardWrapperValve.invoke Servlet.service() for servlet [app_servlet] in context with path [/gmpdemo] threw exception
 java.lang.UnsupportedOperationException: HTTP upgrade is not supported by this protocol
at org.apache.coyote.AbstractProcessor.doHttpUpgrade(AbstractProcessor.java:725)
at org.apache.coyote.AbstractProcessor.action(AbstractProcessor.java:478)
at org.apache.coyote.Request.action(Request.java:407)
at org.apache.catalina.connector.Request.upgrade(Request.java:2007)
at org.apache.catalina.connector.RequestFacade.upgrade(RequestFacade.java:1123)
at org.apache.tomcat.websocket.server.UpgradeUtil.doUpgrade(UpgradeUtil.java:235)
at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:78)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
at com.haulmont.cuba.web.sys.CubaHttpFilter.handleNotFiltered(CubaHttpFilter.java:116)
at com.haulmont.cuba.web.sys.CubaHttpFilter.doFilter(CubaHttpFilter.java:103)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:199)
at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:96)
at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:475)
at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:140)
at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:80)
at org.apache.catalina.valves.AbstractAccessLogValve.invoke(AbstractAccessLogValve.java:625)
at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:87)
at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:342)
at org.apache.coyote.ajp.AjpProcessor.service(AjpProcessor.java:403)
at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:66)
at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:796)
at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1372)
at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49)
at java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
at java.lang.Thread.run(Unknown Source)
#14

Until you investigate what is wrong with your proxies I’d recommend that you explicitly switch to Long polling mode using cuba.web.pushLongPolling app property: Appendix B: Application Properties - CUBA Platform. Developer’s Manual

Unfortunately, I cannot say what is the problem with proxy settings without proxy configuration.

1 Like
#15

After some research we discovered the AJP 1.3 connector does not support WebSocket, there is mention of how to redirect the WebSocket, however there simplest method is to use cuba.web.pushLongPolling = true.

Thanks for all your help.

1 Like