socketio / engine.io-client-java

Engine.IO Client Library for Java
http://socketio.github.io/engine.io-client-java
Other
360 stars 167 forks source link

Messages beyond first one are serialized but not flushed #104

Closed rgov closed 4 years ago

rgov commented 4 years ago

I am calling socket.emit() repeatedly in a loop (with a few seconds between). However, the server only sees the first message. No disconnection or error event seems to be firing, the subsequent messages are simply dropped.

The first message that goes out generates these logs on the client:

[2020-05-11 13:08:24] [FINE   ] writing packet io.socket.parser.Packet@23450a07 
[2020-05-11 13:08:24] [FINE   ] encoding packet io.socket.parser.Packet@23450a07 
[2020-05-11 13:08:24] [FINE   ] encoded io.socket.parser.Packet@23450a07 as 2["update",{"time":"Mon, 11 May 2020 13:08:24 -0400"}] 
[2020-05-11 13:08:24] [FINE   ] flushing 1 packets in socket 
[2020-05-11 13:08:24] [FINE   ] xhr open POST: http://localhost:9041/socket.io/?EIO=3&transport=polling&token=secret_publisher_token&sid=3zJKvfWdf3i8q0veAAAe 
[2020-05-11 13:08:24] [FINE   ] sending xhr with url http://localhost:9041/socket.io/?EIO=3&transport=polling&token=secret_publisher_token&sid=3zJKvfWdf3i8q0veAAAe | data 55:42["update",{"time":"Mon, 11 May 2020 13:08:24 -0400"}] 

The next one looks like this:

[2020-05-11 13:08:25] [FINE   ] writing packet io.socket.parser.Packet@738bf600 
[2020-05-11 13:08:25] [FINE   ] encoding packet io.socket.parser.Packet@738bf600 
[2020-05-11 13:08:25] [FINE   ] encoded io.socket.parser.Packet@738bf600 as 2["update",{"time":"Mon, 11 May 2020 13:08:25 -0400"}] 

Notably, the second log sequence does not contain flushing 1 packets in socket which I assume means that the message is just being queued up and is never going out. Why would that be?

rgov commented 4 years ago

In the Polling transport's write method, the transport is set to read-only with this.writable = false;. A callback callbackfn is defined which is meant to switch back to read-write.

The callbackfn is passed to self.doWrite() as fn, and it's supposed to be called on Request.EVENT_SUCCESS. And it appears to be:

EventThread.exec(new Runnable() {
    @Override
    public void run() {
        fn.run();
    }
});

However, this does not work.

rgov commented 4 years ago

The EventThread is being blocked by polling: PollingXHR.doPoll()'s handler for Request.EVENT_DATA events calls Polling._onData() on the EventThread, which gets stuck.

rgov commented 4 years ago

Resolved. This was an issue in client code. Essentially, a handler for an message type or event can block itself if it tries to emit a message but doesn't return.