Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

[gwt] AtmosphereProxy - exponential backoff on reconnect #497

Closed
memoens opened this issue Jul 9, 2012 · 5 comments
Closed

[gwt] AtmosphereProxy - exponential backoff on reconnect #497

memoens opened this issue Jul 9, 2012 · 5 comments
Assignees
@pierreh

Comments

@memoens
Copy link

memoens commented Jul 9, 2012

Currently when your GWT application looses connection to the server it will automatically reconnect to the server.
This is a good thing, but it has some nasty consequences.
Whenever your server is (really) down and does not respond to http requests, it will take some time before the connection attempts from the client timeout and hence the client will only be sending one request every 10 seconds or so.

However when your server is not down, (or only partially started), the server could respond with a 404, and then the client will go in a sort of DDOS mode and constantly reconnect to the server.

This can be seen in this log file:

...
Mon Jul 09 21:28:25 CEST 2012 xx.ui.client.event.bridge.ServerPushEventBridge
INFO: comet.disconnected
Mon Jul 09 21:28:25 CEST 2012 xx.ui.client.event.bridge.ServerPushEventBridge
INFO: comet.beforeDisconnected
Unexpected response code: 404 :8080:1
Mon Jul 09 21:28:25 CEST 2012 xx.ui.client.event.bridge.ServerPushEventBridge
INFO: comet.disconnected
Mon Jul 09 21:28:25 CEST 2012 xx.ui.client.event.bridge.ServerPushEventBridge
INFO: comet.beforeDisconnected
Unexpected response code: 404 :8080:1
Mon Jul 09 21:28:25 CEST 2012 xx.ui.client.event.bridge.ServerPushEventBridge
INFO: comet.disconnected
Mon Jul 09 21:28:25 CEST 2012 xx.ui.client.event.bridge.ServerPushEventBridge
INFO: comet.beforeDisconnected
Unexpected response code: 404 :8080:1
Mon Jul 09 21:28:25 CEST 2012 xx.ui.client.event.bridge.ServerPushEventBridge
INFO: comet.disconnected
Mon Jul 09 21:28:25 CEST 2012 xx.ui.client.event.bridge.ServerPushEventBridge
INFO: comet.beforeDisconnected
Unexpected response code: 404 :8080:1
Mon Jul 09 21:28:25 CEST 2012 xx.ui.client.event.bridge.ServerPushEventBridge
INFO: comet.disconnected
Mon Jul 09 21:28:25 CEST 2012 xx.ui.client.event.bridge.ServerPushEventBridge
INFO: comet.beforeDisconnected
Unexpected response code: 404 :8080:1
Mon Jul 09 21:28:25 CEST 2012 xx.ui.client.event.bridge.ServerPushEventBridge
INFO: comet.disconnected
Mon Jul 09 21:28:25 CEST 2012 xx.ui.client.event.bridge.ServerPushEventBridge
INFO: comet.beforeDisconnected
Unexpected response code: 404 :8080:1
Mon Jul 09 21:28:25 CEST 2012 xx.ui.client.event.bridge.ServerPushEventBridge
INFO: comet.disconnected
Mon Jul 09 21:28:25 CEST 2012 xx.ui.client.event.bridge.ServerPushEventBridge
INFO: comet.beforeDisconnected
Unexpected response code: 404 :8080:1
Mon Jul 09 21:28:25 CEST 2012 xx.ui.client.event.bridge.ServerPushEventBridge
INFO: comet.disconnected
Mon Jul 09 21:28:25 CEST 2012 xx.ui.client.event.bridge.ServerPushEventBridge
INFO: comet.beforeDisconnected
Unexpected response code: 404 :8080:1
Mon Jul 09 21:28:25 CEST 2012 xx.ui.client.event.bridge.ServerPushEventBridge
INFO: comet.disconnected
Mon Jul 09 21:28:25 CEST 2012 xx.ui.client.event.bridge.ServerPushEventBridge
INFO: comet.beforeDisconnected
Unexpected response code: 404 :8080:1
Mon Jul 09 21:28:25 CEST 2012 xx.ui.client.event.bridge.ServerPushEventBridge
INFO: comet.disconnected
Mon Jul 09 21:28:25 CEST 2012 xx.ui.client.event.bridge.ServerPushEventBridge
INFO: comet.beforeDisconnected
Unexpected response code: 404 :8080:1
Mon Jul 09 21:28:25 CEST 2012 xx.ui.client.event.bridge.ServerPushEventBridge
INFO: comet.disconnected
Mon Jul 09 21:28:25 CEST 2012 xx.ui.client.event.bridge.ServerPushEventBridge
INFO: comet.beforeDisconnected
Unexpected response code: 404 :8080:1
Mon Jul 09 21:28:25 CEST 2012 xx.ui.client.event.bridge.ServerPushEventBridge
INFO: comet.disconnected
Mon Jul 09 21:28:25 CEST 2012 xx.ui.client.event.bridge.ServerPushEventBridge
INFO: comet.beforeDisconnected
Unexpected response code: 404 :8080:1
Mon Jul 09 21:28:25 CEST 2012 xx.ui.client.event.bridge.ServerPushEventBridge
INFO: comet.disconnected
Mon Jul 09 21:28:25 CEST 2012 xx.ui.client.event.bridge.ServerPushEventBridge
INFO: comet.beforeDisconnected
Unexpected response code: 404 :8080:1
Mon Jul 09 21:28:25 CEST 2012 xx.ui.client.event.bridge.ServerPushEventBridge
INFO: comet.disconnected
Mon Jul 09 21:28:25 CEST 2012 xx.ui.client.event.bridge.ServerPushEventBridge
INFO: comet.beforeDisconnected
Unexpected response code: 404 :8080:1
Mon Jul 09 21:28:25 CEST 2012 xx.ui.client.event.bridge.ServerPushEventBridge
INFO: comet.disconnected
Mon Jul 09 21:28:25 CEST 2012 xx.ui.client.event.bridge.ServerPushEventBridge
INFO: comet.beforeDisconnected
Unexpected response code: 404 :8080:1
Mon Jul 09 21:28:25 CEST 2012 xx.ui.client.event.bridge.ServerPushEventBridge
INFO: comet.disconnected
Mon Jul 09 21:28:25 CEST 2012 xx.ui.client.event.bridge.ServerPushEventBridge
INFO: comet.beforeDisconnected
Unexpected response code: 404 :8080:1
Mon Jul 09 21:28:25 CEST 2012 xx.ui.client.event.bridge.ServerPushEventBridge
INFO: comet.disconnected
Mon Jul 09 21:28:25 CEST 2012 xx.ui.client.event.bridge.ServerPushEventBridge
INFO: comet.beforeDisconnected
Unexpected response code: 404 :8080:1
Mon Jul 09 21:28:25 CEST 2012 xx.ui.client.event.bridge.ServerPushEventBridge
INFO: comet.disconnected
Mon Jul 09 21:28:25 CEST 2012 xx.ui.client.event.bridge.ServerPushEventBridge
INFO: comet.beforeDisconnected
Unexpected response code: 404 :8080:1
Mon Jul 09 21:28:25 CEST 2012 xx.ui.client.event.bridge.ServerPushEventBridge
INFO: comet.disconnected
Mon Jul 09 21:28:25 CEST 2012 xx.ui.client.event.bridge.ServerPushEventBridge
INFO: comet.beforeDisconnected
Unexpected response code: 404 :8080:1
Mon Jul 09 21:28:25 CEST 2012 xx.ui.client.event.bridge.ServerPushEventBridge
INFO: comet.disconnected
Mon Jul 09 21:28:25 CEST 2012 xx.ui.client.event.bridge.ServerPushEventBridge
INFO: comet.beforeDisconnected
Unexpected response code: 404 :8080:1
Mon Jul 09 21:28:25 CEST 2012 xx.ui.client.event.bridge.ServerPushEventBridge
INFO: comet.disconnected
Mon Jul 09 21:28:25 CEST 2012 xx.ui.client.event.bridge.ServerPushEventBridge
INFO: comet.beforeDisconnected
Unexpected response code: 404 :8080:1
Mon Jul 09 21:28:25 CEST 2012 xx.ui.client.event.bridge.ServerPushEventBridge
INFO: comet.disconnected
Mon Jul 09 21:28:25 CEST 2012 xx.ui.client.event.bridge.ServerPushEventBridge
INFO: comet.beforeDisconnected
Unexpected response code: 404 :8080:1
Mon Jul 09 21:28:25 CEST 2012 xx.ui.client.event.bridge.ServerPushEventBridge
INFO: comet.disconnected
Mon Jul 09 21:28:25 CEST 2012 xx.ui.client.event.bridge.ServerPushEventBridge
INFO: comet.beforeDisconnected
Unexpected response code: 404 :8080:1
Mon Jul 09 21:28:25 CEST 2012 xx.ui.client.event.bridge.ServerPushEventBridge
INFO: comet.disconnected
Mon Jul 09 21:28:25 CEST 2012 xx.ui.client.event.bridge.ServerPushEventBridge
INFO: comet.beforeDisconnected
Unexpected response code: 404 :8080:1
Mon Jul 09 21:28:26 CEST 2012 xx.ui.client.event.bridge.ServerPushEventBridge
INFO: comet.disconnected
...

This is just one client, constantly trying to reconnect, you can imagine what would happen if you have 100's of clients... :-)

Another problem is that this is also occurring during every redeploy of my application, and I really need to navigate away to a different url for the deploy to finnish.

It would be nice to have some configurable reconnect delay, gwt timer, or even an exponential backoff mechanism on the client in order not to bring down the server.
@ghost ghost assigned pierreh Jul 10, 2012
@pierreh
Copy link

pierreh commented Jul 10, 2012

Currently you can set the reconnectionTimeout. The default is 1000 millisecond. It does not have backoff mechanism

@memoens
Copy link
Author

memoens commented Jul 10, 2012

The problem is that the reconnectionTimeout is not used, if you look in the about log file you will see up to 20 calls per second from the client. This is the relevant excerpt from the browser console:

Tue Jul 10 19:40:17 CEST 2012 be.memoens.ophthalmo.ui.client.event.bridge.ServerPushEventBridge
INFO: comet.heartbeat
Tue Jul 10 19:40:34 CEST 2012 be.memoens.ophthalmo.ui.client.event.bridge.ServerPushEventBridge
INFO: comet.disconnected
Tue Jul 10 19:40:34 CEST 2012 be.memoens.ophthalmo.ui.client.event.bridge.ServerPushEventBridge
INFO: comet.beforeDisconnected
Unexpected response code: 404 :8080:1
Tue Jul 10 19:40:34 CEST 2012 be.memoens.ophthalmo.ui.client.event.bridge.ServerPushEventBridge
INFO: comet.disconnected
Tue Jul 10 19:40:34 CEST 2012 be.memoens.ophthalmo.ui.client.event.bridge.ServerPushEventBridge
INFO: comet.beforeDisconnected
Unexpected response code: 404 :8080:1
Tue Jul 10 19:40:34 CEST 2012 be.memoens.ophthalmo.ui.client.event.bridge.ServerPushEventBridge
INFO: comet.disconnected
Tue Jul 10 19:40:34 CEST 2012 be.memoens.ophthalmo.ui.client.event.bridge.ServerPushEventBridge
INFO: comet.beforeDisconnected

If I look in the source code from the AtmosphereClient, once the redeploy is starting on the server, the clients gets disconnected and directly tries to reconnect to the server.

 private void doOnDisconnected(CometClientTransportWrapper transport) {
        if (refreshState != null) {
            if (transport == primaryTransport) {
                if (refreshState != RefreshState.CONNECTING) {
                    throw new IllegalStateException("Unexpected refreshState");
                }
                refreshState = RefreshState.PRIMARY_DISCONNECTED;
                GWT.log("CometClient: primary disconnected before refresh transport was connected");
            } else {
                // the refresh transport has disconnected
                failedRefresh();
            }
        } else {
            listener.onDisconnected();

            if (running) {
                doConnect();
            }
        }
    }

...
   private void doConnect() {
        primaryTransport.connect();
    }

The reconnect timer is only used when an error is detected, however the onError listener is never called, so I guess the transport never detects the 404 as an error?

Maybe this is relevant it is on chrome 20.0.1132.47

@pierreh
Copy link

pierreh commented Jul 11, 2012

Thanks for the catch

pierreh pushed a commit that referenced this issue Jul 11, 2012
Additional fix for #497
5ba29c9
@memoens
Copy link
Author

memoens commented Jul 16, 2012

Seems to fix the issue. Many thanks!

I do still see a different behavior between Firefox and Chome; I firefox the on error callback is called immediately, in chrome it is never called. In chrome the connection resumes after the server is restarted in firefox it does not.... Not really important for me, but wanted to let you know

@pierreh
Copy link

pierreh commented Jul 17, 2012

Yes this difference is in the way the browser handle the situation, nothing we can do about that as long as we respond properly to the events.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees

@pierreh pierreh

Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
2 participants
@pierreh @memoens