AsyncServer deadlock

[oasalonen]

Hi,

I have a problem where the semaphore in AsyncServer.run(Runnable) is not released. I can reproduce it 100% with the latest jar from maven and with the master branch (commit 8777610).

I have a really simple setup where I listen to an incoming WebSocket connection, then flood it with send() requests about once every 50 ms. So far I've only run it on the Android emulator. In any case, after about 2-3 seconds, everything hangs. And I tracked it to a thread waiting for semaphore.acquire() in AsyncServer.java line 199. I didn't have time at least yet to look any further to see why it doesn't get released.

Any ideas why this is happening?

[oasalonen]

It has something to do with the select() statement in AsyncServer.runLoop() on line 747. At some point the server goes there and since my client is not sending anything, the select() never returns and thus never releases the synchronization lock that surrounds the select() statement. And that means that the post() call that is made from AsyncServer.run(Runnable) is stuck waiting for access to the synchronized block in AsyncServer.postDelayed().

If I make my client send a message to the server, it removes the deadlock since the select() statement returns and allows the runnables to continue sending data to the client. That is, until it deadlocks again a bit later.

[koush]

Can you provide a simple test to demonstrate this?

post should release the semaphore to process the message queue.

[andredigenova]

I have the same issue and am experiencing it on an actual device.

I've connected with wss to my node.js websocket server and spam send() to it using AndroidAsync as the client. 99% of the time it will deadlock on AsyncServer line 199.

Edit:

I worked around the issue by not interacting with AndroidAsync at all in AndroidAsync's own callback thread. For example:

 webSocket.setStringCallback(new WebSocket.StringCallback() {
    @Override
    public void onStringAvailable(final String message) {
        handler.post(new Runnable() {
            @Override
            public void run() {
                webSocket.send("potato");
            }
        });
    }
});

[oasalonen]

Here is an Android test project that reproduces it: https://onedrive.live.com/redir?resid=B8FFD77F3FC3B955!45081&authkey=!AKWny_gUZYbdN9E&ithint=file%2czip

Start the app, then open testclient/index.html in your browser. You may have to modify the websocket address it tries to connect to. Right now it uses localhost:8080.

You should see the messages count label start to increase. When the app deadlocks (anywhere from 1 sec -> 1 min), you can click the Refresh button on the page. This sends a message to the server, which temporarily seems to remove the deadlock and the message count should increase again.

[koush]

thanks will take a look

[akafazov]

I have the same issue. I receive deadlock in onStringAvailable while calling socket.send() from another thread.

[weiqj]

Hello I am still having the deadlock problem. Has it been resolved?

    at java.util.concurrent.locks.AbstractQueuedSynchronizer.doAcquireSharedInterruptibly(AbstractQueuedSynchronizer.java:1022)
    at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireSharedInterruptibly(AbstractQueuedSynchronizer.java:1328)
    at java.util.concurrent.Semaphore.acquire(Semaphore.java:318)
    at com.koushikdutta.async.AsyncServer.run(AsyncServer.java:216)
    at com.koushikdutta.async.BufferedDataSink.write(BufferedDataSink.java:64)
    at com.koushikdutta.async.BufferedDataSink.write(BufferedDataSink.java:59)

[tiawu]

We've been hitting this issue quite a lot when use the send method 5~10 times per second. And we noticed if you wait long enough and somehow the select returns -> let the semaphore get released, it will continue execution by waking up the selectorwrapper. Work around is to reduce the frequency calling send method but still would be good to get this fixed.

A thread dump is here.

"<11> AsyncServer-worker-1@830021219360" prio=5 waiting
  java.lang.Thread.State: WAITING
      at java.lang.Object.wait(Object.java:-1)
      at java.lang.Thread.parkFor(Thread.java:1231)
      at sun.misc.Unsafe.park(Unsafe.java:323)
      at java.util.concurrent.locks.LockSupport.park(LockSupport.java:159)
      at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2019)
      at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:413)
      at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1013)
      at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1073)
      at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:573)
      at java.lang.Thread.run(Thread.java:856)

"<10> AsyncServer@830021218264" prio=5 runnable
  java.lang.Thread.State: RUNNABLE
      at libcore.io.Posix.poll(Posix.java:-1)
      at libcore.io.BlockGuardOs.poll(BlockGuardOs.java:119)
      at java.nio.SelectorImpl.selectInternal(SelectorImpl.java:179)
      at java.nio.SelectorImpl.select(SelectorImpl.java:156)
      at com.koushikdutta.async.SelectorWrapper.select(SelectorWrapper.java:36)
      at com.koushikdutta.async.SelectorWrapper.select(SelectorWrapper.java:30)
      at com.koushikdutta.async.AsyncServer.runLoop(AsyncServer.java:780)
      at com.koushikdutta.async.AsyncServer.run(AsyncServer.java:658)
      at com.koushikdutta.async.AsyncServer.access$800(AsyncServer.java:44)
      at com.koushikdutta.async.AsyncServer$14.run(AsyncServer.java:600)

"<17> pool-2-thread-1@830022054160" prio=5 waiting
  java.lang.Thread.State: WAITING
      at java.lang.Object.wait(Object.java:-1)
      at java.lang.Thread.parkFor(Thread.java:1231)
      at sun.misc.Unsafe.park(Unsafe.java:323)
      at java.util.concurrent.locks.LockSupport.park(LockSupport.java:159)
      at java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(AbstractQueuedSynchronizer.java:810)
      at java.util.concurrent.locks.AbstractQueuedSynchronizer.doAcquireSharedInterruptibly(AbstractQueuedSynchronizer.java:970)
      at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireSharedInterruptibly(AbstractQueuedSynchronizer.java:1279)
      at java.util.concurrent.Semaphore.acquire(Semaphore.java:285)
      at com.koushikdutta.async.AsyncServer.run(AsyncServer.java:216)
      at com.koushikdutta.async.BufferedDataSink.write(BufferedDataSink.java:64)
      at com.koushikdutta.async.BufferedDataSink.write(BufferedDataSink.java:59)
      at com.koushikdutta.async.http.WebSocketImpl.send(WebSocketImpl.java:239)
      at com.maxtropy.zapdos.android.socket.SocketServer$8.run(SocketServer.java:293)
      at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1080)
      at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:573)
      at java.lang.Thread.run(Thread.java:856)