Okhttp: RejectedExecutionException in RealWebSocket.onClose()

[dusanvita]

I'm getting a lot of RejectedExecutionException from line okhttp3.internal.ws.RealWebSocket$1.onClose (RealWebSocket.java:82) while using the engine.io/socket.io library.

I assume that ping response runnable that is writing the pong by locking the thread, is staying in the pool long enough to create a problem when server requests socket close in the meantime? Since only one runnable can be in the pool at the time and so RejectedExecutionException is thrown.

https://github.com/square/okhttp/commit/8a1e6ceec92963423b4cc9f5edded6363fc2c43f#diff-84851fc7b3d535627088311c7ca1951dR70

Library version 3.0.1

Sorry for not writing the test case, I spent the whole day so far trying to find the issue...

[hamberluo]

i also met this problem.

Fatal Exception: java.util.concurrent.RejectedExecutionException: Task okhttp3.internal.ws.RealWebSocket$1$2@21f58605 rejected from java.util.concurrent.ThreadPoolExecutor@313dc65a[Terminated, pool size = 0, active threads = 0, queued tasks = 0, completed tasks = 0]
       at java.util.concurrent.ThreadPoolExecutor$AbortPolicy.rejectedExecution(ThreadPoolExecutor.java:2011)
       at java.util.concurrent.ThreadPoolExecutor.reject(ThreadPoolExecutor.java:793)
       at java.util.concurrent.ThreadPoolExecutor.execute(ThreadPoolExecutor.java:1339)
       at okhttp3.internal.ws.RealWebSocket$1.onClose(RealWebSocket.java:82)
       at okhttp3.internal.ws.WebSocketReader.readControlFrame(WebSocketReader.java:205)
       at okhttp3.internal.ws.WebSocketReader.processNextFrame(WebSocketReader.java:106)
       at okhttp3.internal.ws.RealWebSocket.readMessage(RealWebSocket.java:97)
       at okhttp3.ws.WebSocketCall.createWebSocket(WebSocketCall.java:151)
       at okhttp3.ws.WebSocketCall.access$000(WebSocketCall.java:41)
       at okhttp3.ws.WebSocketCall$1.onResponse(WebSocketCall.java:97)
       at okhttp3.RealCall$AsyncCall.execute(RealCall.java:133)
       at okhttp3.internal.NamedRunnable.run(NamedRunnable.java:32)
       at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1112)
       at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:587)
       at java.lang.Thread.run(Thread.java:818)

[hamberluo]

3.3.1 still has this bug.

[PiotrWpl]

Is there a chance to fix this in 3.4?

[swankjesse]

Can you write a test case to reproduce the problem? We've got a bunch of WebSocket tests to get you started.

[PiotrWpl]

I can't reproduce this. I just seeing it in Crashlytics. All Android versions, different devices.
I'm using https://github.com/socketio/socket.io-client-java (0.7.0) as websocket client and https://github.com/socketio/socket.io (1.4.5) on the server side.

[PiotrWpl]

This is how it looks in Fabric (Crashlytics) at last 30 days.

issue_911_crash_577a0373013a00012f05cbdb0dca4161.txt

[rafaelekol]

Have same crash report for our app in Crashlytics
We use OkHttp 3.3.1 with io.socket:socket.io-client:0.7.0
Here is the log:

#0. Crashed: OkHttp Dispatcher: 0 0 0x0000000000000000
       at java.util.concurrent.ThreadPoolExecutor$AbortPolicy.rejectedExecution(ThreadPoolExecutor.java:2011)
       at java.util.concurrent.ThreadPoolExecutor.reject(ThreadPoolExecutor.java:793)
       at java.util.concurrent.ThreadPoolExecutor.execute(ThreadPoolExecutor.java:1339)
       at okhttp3.internal.ws.RealWebSocket$1.onClose(RealWebSocket.java:82)
       at okhttp3.internal.ws.WebSocketReader.readControlFrame(WebSocketReader.java:205)
       at okhttp3.internal.ws.WebSocketReader.processNextFrame(WebSocketReader.java:106)
       at okhttp3.internal.ws.RealWebSocket.readMessage(RealWebSocket.java:97)
       at okhttp3.ws.WebSocketCall.createWebSocket(WebSocketCall.java:152)
       at okhttp3.ws.WebSocketCall.access$000(WebSocketCall.java:41)
       at okhttp3.ws.WebSocketCall$1.onResponse(WebSocketCall.java:97)
       at okhttp3.RealCall$AsyncCall.execute(RealCall.java:133)
       at okhttp3.internal.NamedRunnable.run(NamedRunnable.java:32)
       at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1112)
       at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:587)
       at java.lang.Thread.run(Thread.java:811)

--

Fatal Exception: java.util.concurrent.RejectedExecutionException: Task okhttp3.internal.ws.RealWebSocket$1$2@2d270c9d rejected from java.util.concurrent.ThreadPoolExecutor@3de66512[Terminated, pool size = 0, active threads = 0, queued tasks = 0, completed tasks = 0]
       at java.util.concurrent.ThreadPoolExecutor$AbortPolicy.rejectedExecution(ThreadPoolExecutor.java:2011)
       at java.util.concurrent.ThreadPoolExecutor.reject(ThreadPoolExecutor.java:793)
       at java.util.concurrent.ThreadPoolExecutor.execute(ThreadPoolExecutor.java:1339)
       at okhttp3.internal.ws.RealWebSocket$1.onClose(RealWebSocket.java:82)
       at okhttp3.internal.ws.WebSocketReader.readControlFrame(WebSocketReader.java:205)
       at okhttp3.internal.ws.WebSocketReader.processNextFrame(WebSocketReader.java:106)
       at okhttp3.internal.ws.RealWebSocket.readMessage(RealWebSocket.java:97)
       at okhttp3.ws.WebSocketCall.createWebSocket(WebSocketCall.java:152)
       at okhttp3.ws.WebSocketCall.access$000(WebSocketCall.java:41)
       at okhttp3.ws.WebSocketCall$1.onResponse(WebSocketCall.java:97)
       at okhttp3.RealCall$AsyncCall.execute(RealCall.java:133)
       at okhttp3.internal.NamedRunnable.run(NamedRunnable.java:32)
       at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1112)
       at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:587)
       at java.lang.Thread.run(Thread.java:811)

#0. Crashed: OkHttp Dispatcher: 0 0 0x0000000000000000
       at java.util.concurrent.ThreadPoolExecutor$AbortPolicy.rejectedExecution(ThreadPoolExecutor.java:2011)
       at java.util.concurrent.ThreadPoolExecutor.reject(ThreadPoolExecutor.java:793)
       at java.util.concurrent.ThreadPoolExecutor.execute(ThreadPoolExecutor.java:1339)
       at okhttp3.internal.ws.RealWebSocket$1.onClose(RealWebSocket.java:82)
       at okhttp3.internal.ws.WebSocketReader.readControlFrame(WebSocketReader.java:205)
       at okhttp3.internal.ws.WebSocketReader.processNextFrame(WebSocketReader.java:106)
       at okhttp3.internal.ws.RealWebSocket.readMessage(RealWebSocket.java:97)
       at okhttp3.ws.WebSocketCall.createWebSocket(WebSocketCall.java:152)
       at okhttp3.ws.WebSocketCall.access$000(WebSocketCall.java:41)
       at okhttp3.ws.WebSocketCall$1.onResponse(WebSocketCall.java:97)
       at okhttp3.RealCall$AsyncCall.execute(RealCall.java:133)
       at okhttp3.internal.NamedRunnable.run(NamedRunnable.java:32)
       at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1112)
       at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:587)
       at java.lang.Thread.run(Thread.java:811)

[dave-r12]

I think I've found a way to trigger this, and part of it is that engine.io library is closing the socket then trying to write to it!

        if (wsCall != null) {
            wsCall.cancel();
        }
        if (ws != null) {
            try {
                ws.close(1000, "");
            } catch (IOException e) {
                // websocket already closed
            } catch (IllegalStateException e) {
                // websocket already closed
            }
        }

I'm gonna see if I can add a fix for this unusual scenario.

[swankjesse]

Calling cancel() and then close() should work. Cancel is intended to be async, so in this case the close should just fail with an IOException.

My guess is that the executor is either configured wrong (not a long enough queue) or its being shutdown.

[dave-r12]

Yes, ws.close fails with IOException, causing it to shutdown the executor. Shouldn't their code first call ws.close, then cancel?

[swankjesse]

Ahhhh... shutting down the executor seems like a mistake.

[rajeefmk]

A little bit confused here. I also got this error after updating to socket.io 0.7.0

So the issue is really with socket.io ( / engine.io) closing the socket then trying to write to it ? This one -https://github.com/socketio/socket.io-client-java/issues/287 ?

[dusanvita]

Yeah, the problem lies in the engine.io library when shutting down the executor when switching the transport from Polling to Websocket. Quick fix if you can allow yourself not to use the Polling transport but only Websocket when setting up the socket.io library.

So, by default it will do a handshake via Polling and switch to Websocket if the server responds with an upgrade to websocket command in the handshake response. Here's the code from Socket constructor:

this.transports = new ArrayList<String>(Arrays.asList(opts.transports != null ?
                opts.transports : new String[]{Polling.NAME, WebSocket.NAME}));

So you can just completely avoid using the Polling transport by passing the options to the constructor with transport explicitly set to:

options.transports = new String[] { WebSocket.NAME };

[dave-r12]

After mucking with the socket.io client and server a bit more, I see there is a race condition in the tear down code. If you call disconnect(true) from the server, it will send a data frame, then a close frame. When the client processes the data frame, they appear to encode that the connection should be closed, and spawn an async task that turns around and calls WebSocket#close(). If that async task happens to execute just prior to processing the close frame, then this exception is thrown (because they close the socket, then try to write to it which shuts down the executor.)

I opened this pull request https://github.com/socketio/engine.io-client-java/pull/61.

Currently I do not see a workaround to this scenario other than changing the code.

[PiotrWpl]

@dusanvita

Quick fix if you can allow yourself not to use the Polling transport but only Websocket when setting up the socket.io library.

Thx, but how can I determine, that I can use only websockets? ;)

[joshimohit]

@swankjesse : What shall we do, change the io.socket:socket.io-client:0.7.0 library as suggested by @dave-r12 or use square#2455 .

[fingdo]

I use okhttp 3.4.2 , and all project and module use okhttp 3.4.2

java.util.concurrent.RejectedExecutionException: Task okhttp3.internal.ws.RealWebSocket$1$2@2ddff9b rejected from java.util.concurrent.ThreadPoolExecutor@9493f38[Terminated, pool size = 0, active threads = 0, queued tasks = 0, completed tasks = 0]
    at java.util.concurrent.ThreadPoolExecutor$AbortPolicy.rejectedExecution(ThreadPoolExecutor.java:2014)
    at java.util.concurrent.ThreadPoolExecutor.reject(ThreadPoolExecutor.java:794)
    at java.util.concurrent.ThreadPoolExecutor.execute(ThreadPoolExecutor.java:1340)
    at okhttp3.internal.ws.RealWebSocket$1.onClose(RealWebSocket.java:82)
    at okhttp3.internal.ws.WebSocketReader.readControlFrame(WebSocketReader.java:205)
    at okhttp3.internal.ws.WebSocketReader.processNextFrame(WebSocketReader.java:106)
    at okhttp3.internal.ws.RealWebSocket.readMessage(RealWebSocket.java:97)
    at okhttp3.ws.WebSocketCall.createWebSocket(WebSocketCall.java:152)
    at okhttp3.ws.WebSocketCall.access$000(WebSocketCall.java:41)
    at okhttp3.ws.WebSocketCall$1.onResponse(WebSocketCall.java:97)
    at okhttp3.RealCall$AsyncCall.execute(RealCall.java:126)
    at okhttp3.internal.NamedRunnable.run(NamedRunnable.java:32)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1113)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:588)
    at java.lang.Thread.run(Thread.java:833)

@JakeWharton

[sucese]

The problem log:

java.util.concurrent.RejectedExecutionException: Task okhttp3.internal.ws.RealWebSocket$1$2@2ddff9b rejected from java.util.concurrent.ThreadPoolExecutor@9493f38[Terminated, pool size = 0, active threads = 0, queued tasks = 0, completed tasks = 0]
    at java.util.concurrent.ThreadPoolExecutor$AbortPolicy.rejectedExecution(ThreadPoolExecutor.java:2014)
    at java.util.concurrent.ThreadPoolExecutor.reject(ThreadPoolExecutor.java:794)
    at java.util.concurrent.ThreadPoolExecutor.execute(ThreadPoolExecutor.java:1340)
    at okhttp3.internal.ws.RealWebSocket$1.onClose(RealWebSocket.java:82)
    at okhttp3.internal.ws.WebSocketReader.readControlFrame(WebSocketReader.java:205)
    at okhttp3.internal.ws.WebSocketReader.processNextFrame(WebSocketReader.java:106)
    at okhttp3.internal.ws.RealWebSocket.readMessage(RealWebSocket.java:97)
    at okhttp3.ws.WebSocketCall.createWebSocket(WebSocketCall.java:152)
    at okhttp3.ws.WebSocketCall.access$000(WebSocketCall.java:41)
    at okhttp3.ws.WebSocketCall$1.onResponse(WebSocketCall.java:97)
    at okhttp3.RealCall$AsyncCall.execute(RealCall.java:126)
    at okhttp3.internal.NamedRunnable.run(NamedRunnable.java:32)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1113)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:588)
    at java.lang.Thread.run(Thread.java:833)

When you call shutdown(), it can cause this problem. Just like this:

mOkHttpClient.dispatcher().executorService().shutdown();