atmosphere client unsubscribe not closing request, and reconnect attempts flooding tomcat access log.

[infa-tklingle]

current setup spring application:

org.atmosphere.extensions.atmosphere-gwt20-client  v2.4.21
org.atmosphere.extensions.atmosphere-gwt20-server  v2.4.21
org.atmosphere.atmosphere-runtime v2.4.21

tomcat container: v7.0.75

atmosphere client config:
atmosphere.defaultTransport=streaming
atmosphere.fallbackTransport=long-polling
atmosphere.connectTimeout=-1
atmosphere.timeout=300000
atmosphere.logLevel=debug
atmosphere.maxReconnectOnClose=5 
atmosphere.reconnectInterval=0

This issue got our intention, while we found our tomcat access logs, flooded with millions of atmosphere hardbeats, which came in approximately every millisecond and filled up the log files within a week to 20GB.

[06/Apr/2018:13:14:49 +0200] "GET /hsx/atmosphereGwt?X-Atmosphere-tracking-id=51d20d4f-7019-4290-b518-1c6d7ccb6e18&X-Atmosphere-Framework=2.2.3-javascript&X-Atmosphere-Transport=streaming&Content-Type=text%2Fx-gwt-rpc%3B%20charset%3DUTF-8&X-atmo-protocol=true&_=1523013289140 HTTP/1.1" 302 -
[06/Apr/2018:13:14:49 +0200] "GET /hsx/atmosphereGwt?X-Atmosphere-tracking-id=51d20d4f-7019-4290-b518-1c6d7ccb6e18&X-Atmosphere-Framework=2.2.3-javascript&X-Atmosphere-Transport=streaming&Content-Type=text%2Fx-gwt-rpc%3B%20charset%3DUTF-8&X-atmo-protocol=true&_=1523013289141 HTTP/1.1" 302 -
[06/Apr/2018:13:14:49 +0200] "GET /hsx/html/login.html?continue=X-Atmosphere-tracking-id%3D51d20d4f-7019-4290-b518-1c6d7ccb6e18%26X-Atmosphere-Framework%3D2.2.3-javascript%26X-Atmosphere-Transport%3Dstreaming%26Content-Type%3Dtext%252Fx-gwt-rpc%253B%2520charset%253DUTF-8%26X-atmo-protocol%3Dtrue%26_%3D1523013289140 HTTP/1.1" 200 3340
[06/Apr/2018:13:14:49 +0200] "GET /hsx/html/login.html?continue=X-Atmosphere-tracking-id%3D51d20d4f-7019-4290-b518-1c6d7ccb6e18%26X-Atmosphere-Framework%3D2.2.3-javascript%26X-Atmosphere-Transport%3Dstreaming%26Content-Type%3Dtext%252Fx-gwt-rpc%253B%2520charset%253DUTF-8%26X-atmo-protocol%3Dtrue%26_%3D1523013289141 HTTP/1.1" 200 3340
[06/Apr/2018:13:14:49 +0200] "GET /hsx/atmosphereGwt?X-Atmosphere-tracking-id=51d20d4f-7019-4290-b518-1c6d7ccb6e18&X-Atmosphere-Framework=2.2.3-javascript&X-Atmosphere-Transport=streaming&Content-Type=text%2Fx-gwt-rpc%3B%20charset%3DUTF-8&X-atmo-protocol=true&_=1523013289182 HTTP/1.1" 302 -
[06/Apr/2018:13:14:49 +0200] "GET /hsx/atmosphereGwt?X-Atmosphere-tracking-id=51d20d4f-7019-4290-b518-1c6d7ccb6e18&X-Atmosphere-Framework=2.2.3-javascript&X-Atmosphere-Transport=streaming&Content-Type=text%2Fx-gwt-rpc%3B%20charset%3DUTF-8&X-atmo-protocol=true&_=1523013289182 HTTP/1.1" 302 -
[06/Apr/2018:13:14:49 +0200] "GET /hsx/html/login.html?continue=X-Atmosphere-tracking-id%3D51d20d4f-7019-4290-b518-1c6d7ccb6e18%26X-Atmosphere-Framework%3D2.2.3-javascript%26X-Atmosphere-Transport%3Dstreaming%26Content-Type%3Dtext%252Fx-gwt-rpc%253B%2520charset%253DUTF-8%26X-atmo-protocol%3Dtrue%26_%3D1523013289182 HTTP/1.1" 200 3340

After some research, we could reproduce this issue by restarting our tomcat application server while having a open atmosphere client session. In this case, after the server is back online, the client session seems to try to reconnect to the server and never stops contacting it, until the browser is closed.

In a normal case the atmosphere request is started after user login and operating on a authenticated session, but after restarting the server this session is gone and that's why the reconnects ( or hardbeats, not sure how to call them) are hitting our authentication filter which redirects them to a login page while the session is not valid anymore.

I tried to catch this by implementing a redirect handler within the gwt atmosphere client module and checking on reconnect if this session is still valid. While it's not I just call atmosphere.unsubscribe(), which in my opinion should close the client session, but it seems to lead to an endless try to reconnect or error handling behavior I could not figure out what exactly was producing this flood of messages/hardbeats...

		final Atmosphere atmosphere = Atmosphere.create();
		config.setReconnectHandler(new AtmosphereReconnectHandler() {

			@Override
			public void onReconnect(RequestConfig request, AtmosphereResponse response) {
				
				if ( !securityContext.isAuthenticated()){
					atmosphere.unsubscribe();	
				}
			}
		});

We would be glad for any help.
Thank
Thomas

[infa-tklingle]

While researching for the root cause of this issue I updated atmosphere from 2.2.3 to 2.4.21 thats why the logs differ from the setup description. But same issue for the newer atmosphere version.