Framework: EOFException in Atmosphere/WebSockets

Created on 3 Apr 2017  ·  13Comments  ·  Source: vaadin/framework

If the user closes the tab/browser _some_ deinitialization occurs, for instance the Spring SecurityContextHolder is cleared and other things happen. Then, after three missed heart beats, UI.detach() is called and the UI is already semi-deinitialized.

One of the results is the below stack trace, I cannot trace it since there is none of our code in it.

We run
<vaadin-bom.version>7.7.6</vaadin-bom.version> <vaadin.plugin.version>${vaadin-bom.version}</vaadin.plugin.version> <vaadin-spring.version>1.0.2</vaadin-spring.version>

Vaadin version: 7.7.6
Tomcat version: 8.5.3
Spring version: Athens-RELEASE

Apr 03, 2017 10:55:54 AM org.atmosphere.container.JSR356Endpoint onError SEVERE: java.io.EOFException at org.apache.tomcat.util.net.NioEndpoint$NioSocketWrapper.fillReadBuffer(NioEndpoint.java:1222) at org.apache.tomcat.util.net.NioEndpoint$NioSocketWrapper.isReadyForRead(NioEndpoint.java:1128) at org.apache.tomcat.websocket.server.WsFrameServer.onDataAvailable(WsFrameServer.java:58) at org.apache.tomcat.websocket.server.WsHttpUpgradeHandler.upgradeDispatch(WsHttpUpgradeHandler.java:148) at org.apache.coyote.http11.upgrade.UpgradeProcessorInternal.dispatch(UpgradeProcessorInternal.java:54) at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:53) at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:785) at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1425) at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:52) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61) at java.lang.Thread.run(Thread.java:745)

question Stale
Source
picture danmattsson
👍5

All 13 comments

Additional disclosure: we run an Nginx front end as proxy. This whole websocket/proxy/SSL/browser connection and´d how they all relate to each other is still kind of a mystery to me.

danmattsson picture danmattsson on 3 Apr 2017
👍1

I'm seeing the same stacktrace:

Aug 11 18:25:31 6745fa5c63fd ecs-cr_td-55-c0b7bedec6a9acb0c901: Aug 11, 2017 4:25:31 PM org.atmosphere.container.JSR356Endpoint onError 
Aug 11 18:25:31 6745fa5c63fd ecs-cr_td-55-c0b7bedec6a9acb0c901: SEVERE:  
Aug 11 18:25:31 6745fa5c63fd ecs-cr_td-55-c0b7bedec6a9acb0c901: java.io.EOFException 
Aug 11 18:25:31 6745fa5c63fd ecs-cr_td-55-c0b7bedec6a9acb0c901:     at org.apache.tomcat.util.net.NioEndpoint$NioSocketWrapper.fillReadBuffer(NioEndpoint.java:1244) 
Aug 11 18:25:31 6745fa5c63fd ecs-cr_td-55-c0b7bedec6a9acb0c901:     at org.apache.tomcat.util.net.NioEndpoint$NioSocketWrapper.read(NioEndpoint.java:1184) 
Aug 11 18:25:31 6745fa5c63fd ecs-cr_td-55-c0b7bedec6a9acb0c901:     at org.apache.tomcat.websocket.server.WsFrameServer.onDataAvailable(WsFrameServer.java:72) 
Aug 11 18:25:31 6745fa5c63fd ecs-cr_td-55-c0b7bedec6a9acb0c901:     at org.apache.tomcat.websocket.server.WsFrameServer.doOnDataAvailable(WsFrameServer.java:171) 
Aug 11 18:25:31 6745fa5c63fd ecs-cr_td-55-c0b7bedec6a9acb0c901:     at org.apache.tomcat.websocket.server.WsFrameServer.notifyDataAvailable(WsFrameServer.java:151) 
Aug 11 18:25:31 6745fa5c63fd ecs-cr_td-55-c0b7bedec6a9acb0c901:     at org.apache.tomcat.websocket.server.WsHttpUpgradeHandler.upgradeDispatch(WsHttpUpgradeHandler.java:148) 
Aug 11 18:25:31 6745fa5c63fd ecs-cr_td-55-c0b7bedec6a9acb0c901:     at org.apache.coyote.http11.upgrade.UpgradeProcessorInternal.dispatch(UpgradeProcessorInternal.java:54) 
Aug 11 18:25:31 6745fa5c63fd ecs-cr_td-55-c0b7bedec6a9acb0c901:     at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:53) 
Aug 11 18:25:31 6745fa5c63fd ecs-cr_td-55-c0b7bedec6a9acb0c901:     at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:868) 
Aug 11 18:25:31 6745fa5c63fd ecs-cr_td-55-c0b7bedec6a9acb0c901:     at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1457) 
Aug 11 18:25:31 6745fa5c63fd ecs-cr_td-55-c0b7bedec6a9acb0c901:     at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49) 
Aug 11 18:25:31 6745fa5c63fd ecs-cr_td-55-c0b7bedec6a9acb0c901:     at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) 
Aug 11 18:25:31 6745fa5c63fd ecs-cr_td-55-c0b7bedec6a9acb0c901:     at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java) 
Aug 11 18:25:31 6745fa5c63fd ecs-cr_td-55-c0b7bedec6a9acb0c901:     at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61) 
Aug 11 18:25:31 6745fa5c63fd ecs-cr_td-55-c0b7bedec6a9acb0c901:     at java.lang.Thread.run(Thread.java:748)

We're running behind an Amazon Application Load Balancer. According to the documentation the ALB will close frontend connections if the backend hasn't given sign of life during idle_timeout. Could it be that the ping-pong mechanism only acknowledges pings, but doesn't pong?

manuelbernhardt picture manuelbernhardt on 15 Aug 2017

spring boot : 2.0.0.M5
vaadin: 8.2.0.alpha2
vaadin spring boot: 2.0.1
tomcat embed: 8.5.23

.log(JDK14LoggerAdapter.java:588)                    |-ERROR   |2017-11-03 15:17:33.445| 
java.io.IOException: Unable to unwrap data, invalid status [CLOSED]
        at org.apache.tomcat.util.net.SecureNioChannel.read(SecureNioChannel.java:618)
        at org.apache.tomcat.util.net.NioEndpoint$NioSocketWrapper.fillReadBuffer(NioEndpoint.java:1248)
        at org.apache.tomcat.util.net.NioEndpoint$NioSocketWrapper.fillReadBuffer(NioEndpoint.java:1221)
        at org.apache.tomcat.util.net.NioEndpoint$NioSocketWrapper.read(NioEndpoint.java:1194)
        at org.apache.tomcat.websocket.server.WsFrameServer.onDataAvailable(WsFrameServer.java:72)
        at org.apache.tomcat.websocket.server.WsFrameServer.doOnDataAvailable(WsFrameServer.java:171)
        at org.apache.tomcat.websocket.server.WsFrameServer.notifyDataAvailable(WsFrameServer.java:151)
        at org.apache.tomcat.websocket.server.WsHttpUpgradeHandler.upgradeDispatch(WsHttpUpgradeHandler.java:148)
        at org.apache.coyote.http11.upgrade.UpgradeProcessorInternal.dispatch(UpgradeProcessorInternal.java:54)
        at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:53)
        at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:868)
        at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1459)
        at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
        at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
        at java.lang.Thread.run(Thread.java:748)

nginx.conf

server {
        listen xxx.xxx.xxx.xxx:443 ssl http2;

        server_name mydomain.com;
        server_name www.mydomain.com;
        server_name ipv4.mydomain.com;

        ssl_certificate             /opt/psa/var/certificates/cert-HtaT9k;
        ssl_certificate_key         /opt/psa/var/certificates/cert-HtaT9k;
        ssl_client_certificate      /opt/psa/var/certificates/cert-4M1dWh;

        client_max_body_size 128m;

        # disable unsupported ciphers
        ssl_ciphers AESGCM:HIGH:!aNULL:!MD5;

        # ssl optimizations
        ssl_session_cache shared:SSL:30m;
        ssl_session_timeout 30m;
        add_header Strict-Transport-Security "max-age=31536000";

        root "/var/www/vhosts/mydomain.com/httpdocs";
        access_log "/var/www/vhosts/system/mydomain.com/logs/proxy_access_ssl_log";
        error_log "/var/www/vhosts/system/mydomain.com/logs/proxy_error_log";

        location / {
                proxy_pass https://xxx.xxx.xxx.xxx:801;
                proxy_set_header Host             $host;
                proxy_set_header X-Real-IP        $remote_addr;
                proxy_set_header X-Forwarded-For  $proxy_add_x_forwarded_for;
                proxy_set_header X-Accel-Internal /internal-nginx-static-location;
                access_log off;
                proxy_set_header Upgrade $http_upgrade;
                proxy_set_header Connection "upgrade";

                proxy_http_version 1.1;
                proxy_set_header Connection "";
                proxy_connect_timeout       300;
                proxy_send_timeout          300;
                proxy_read_timeout          300;
                send_timeout                300;
        }

        add_header X-Powered-By PleskLin;

        include "/var/www/vhosts/system/mydomain.com/conf/vhost_nginx.conf";
}
# Vaadin PUSH
map $http_upgrade $connection_upgrade {
        default upgrade;
        '' close;
}


server {
        listen xxx.xxx.xxx.xxx:80;

        server_name mydomain.com;
        server_name www.mydomain.com;
        server_name ipv4.mydomain.com;

        client_max_body_size 128m;

        return 301 https://$host$request_uri;
}
tstsogoo picture tstsogoo on 3 Nov 2017

Faced same issue (Tested with Tomcat embedded 8.5.27.0).
It seems that the issue only occurs with Tomcat embedded which runs on webapp-runner (https://github.com/jsimone/webapp-runner).

letrthang picture letrthang on 6 Feb 2018
👍1

The issue happens whenever below issue occurs:

2018-02-06T17:06:40.721580+00:00 heroku[router]: at=error code=H15 desc="Idle connection" method=GET path="/PUSH?v-uiId=0&v-pushId=9330bb7a-2fea-40a4-a91e-3aa542de74f3&X-Atmosphere-tracking-id=0&X-Atmosphere-Framework=2.3.2.vaadin1-javascript&X-Atmosphere-Transport=websocket&X-Atmosphere-TrackMessageSize=true&Content-Type=application/json;%20charset=UTF-8&X-atmo-protocol=true" host=www.neonplatform.com request_id=0e7b2e14-be1b-4179-934f-ce0f92feced2 fwd="27.74.157.203" dyno=web.1 connect=0ms service=75208ms status=503 bytes= protocol=http

Not sure this is reason:
https://stackoverflow.com/questions/13063683/h15-on-heroku-sse-request

letrthang picture letrthang on 6 Feb 2018

We face the same problem with:

Vaadin version: 7.7.13
Tomcat version: 8.5.11

Apr 04, 2018 7:57:38 AM org.atmosphere.container.JSR356Endpoint onError SCHWERWIEGEND:
java.io.EOFException
at org.apache.tomcat.util.net.NioEndpoint$NioSocketWrapper.fillReadBuffer(NioEndpoint.java:1221)
at org.apache.tomcat.util.net.NioEndpoint$NioSocketWrapper.read(NioEndpoint.java:1161)
at org.apache.tomcat.websocket.server.WsFrameServer.onDataAvailable(WsFrameServer.java:63)
at org.apache.tomcat.websocket.server.WsHttpUpgradeHandler.upgradeDispatch(WsHttpUpgradeHandler.java:148)
at org.apache.coyote.http11.upgrade.UpgradeProcessorInternal.dispatch(UpgradeProcessorInternal.java:54)
at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:53)
at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:798)
at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1434)
at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
at java.lang.Thread.run(Thread.java:745)

knoobie picture knoobie on 4 Apr 2018

@knoobie We also encountered the same problem，Tomcat 9.0.1 websocket，
How did you deal with this problem?
thank you

kenneyLee picture kenneyLee on 10 Jul 2018

@kenneyLee Sadly not in a good way.. we ignore it.. anything works (at least it seems so) just the Log spamming is kinda annoying.

knoobie picture knoobie on 10 Jul 2018

Hello there!

We are sorry that this issue hasn't progressed lately. We are prioritizing issues by severity and the number of customers we expect are experiencing this and haven't gotten around to fix this issue yet.

There are a couple of things you could help to get things rolling on this issue (this is an automated message, so expect that some of these are already in use):

  • Check if the issue is still valid for the latest version. There are dozens of duplicates in our issue tracker, so it is possible that the issue is already tackled. If it appears to be fixed, close the issue, otherwise report to the issue that it is still valid.
  • Provide more details how to reproduce the issue.
  • Explain why it is important to get this issue fixed and politely draw others attention to it e.g. via the forum or social media.
  • Add a reduced test case about the issue, so it is easier for somebody to start working on a solution.
  • Try fixing the issue yourself and create a pull request that contains the test case and/or a fix for it. Handling the pull requests is the top priority for the core team.
  • If the issue is clearly a bug, use the Warranty in your Vaadin subscription to raise its priority.

Thanks again for your contributions! Even though we haven't been able to get this issue fixed, we hope you to report your findings and enhancement ideas in the future too!

stale[bot] picture stale[bot] on 29 Dec 2018

Resume of vaadin issues: almost closed by stale bot.
Solution provided by vaadin team: create a new framework.
👏👏👏👏👏

dyorgio picture dyorgio on 29 Dec 2018

The "problem" is that Atmosphere logs everything here https://github.com/Atmosphere/atmosphere/blob/master/modules/runtime/src/main/java/org/atmosphere/container/JSR356Endpoint.java#L303

So it will produce sometimes some excess log in cases like this, which seems to be non-issue.

In newer version of Atmosphere log level has been reduced to debug, but it is still being logged.

TatuLund picture TatuLund on 29 Dec 2018

As a follow-up on Tatu's comment:

Here's the issue in the Athmosphere project: https://github.com/Atmosphere/atmosphere/pull/2240

It has been merged into Atmosphere 2.4.15 and 2.5 and onwards. For comparison Vaadin7 uses Athmosphere v2.2. Therefore, for any Vaadin framework which doesn't use a somewhat recent Atmosphere then you'll have to find a way to silence these messages yourself if you don't want them in the log. For example if you are using J.U.L. you can implement a Logging Filter. Similarly for other logging frameworks.

lbruun picture lbruun on 8 Mar 2019
👍1

Hello there!

We are sorry that this issue hasn't progressed lately. We are prioritizing issues by severity and the number of customers we expect are experiencing this and haven't gotten around to fix this issue yet.

There are a couple of things you could help to get things rolling on this issue (this is an automated message, so expect that some of these are already in use):

  • Check if the issue is still valid for the latest version. There are dozens of duplicates in our issue tracker, so it is possible that the issue is already tackled. If it appears to be fixed, close the issue, otherwise report to the issue that it is still valid.
  • Provide more details how to reproduce the issue.
  • Explain why it is important to get this issue fixed and politely draw others attention to it e.g. via the forum or social media.
  • Add a reduced test case about the issue, so it is easier for somebody to start working on a solution.
  • Try fixing the issue yourself and create a pull request that contains the test case and/or a fix for it. Handling the pull requests is the top priority for the core team.
  • If the issue is clearly a bug, use the Warranty in your Vaadin subscription to raise its priority.

Thanks again for your contributions! Even though we haven't been able to get this issue fixed, we hope you to report your findings and enhancement ideas in the future too!

stale[bot] picture stale[bot] on 5 Aug 2019
Was this page helpful?
0 / 5 - 0 ratings

Related issues

vaadin-bot picture vaadin-bot  ·  7Comments
vaadin-bot picture vaadin-bot  ·  7Comments
SomeoneToIgnore picture SomeoneToIgnore  ·  7Comments
FSchliephacke picture FSchliephacke  ·  4Comments
hannuvaadin picture hannuvaadin  ·  6Comments