endless loop while calling DefaultBroadcaster.removeAtmosphereResource()

[chrisgunnink]

I’m running Java HotSpot(TM) 64-Bit Server VM (24.45-b08 mixed mode), using Atmosphere 1.0.13. I know this is not the most recent version, but I see the same logic is still used on the Master branch.

I’m getting an endless loop while calling DefaultBroadcaster.removeAtmosphereResource(). Here is the full stack:

"event-broadcaster-thread-10" prio=10 tid=0x00007f6a0c54c800 nid=0x4d80 runnable [0x00007f6a9091f000]
   java.lang.Thread.State: RUNNABLE
                at java.util.concurrent.ConcurrentLinkedQueue.remove(ConcurrentLinkedQueue.java:489)
                at org.atmosphere.cpr.DefaultBroadcaster.removeAtmosphereResource(DefaultBroadcaster.java:1576)
                - locked <0x0000000500bf3750> (a java.util.concurrent.ConcurrentLinkedQueue)
                at org.atmosphere.cpr.DefaultBroadcaster.removeAtmosphereResource(DefaultBroadcaster.java:1565)
                at org.apache.wicket.atmosphere.EventBus.buildResponse(EventBus.java:439)
                at org.apache.wicket.atmosphere.EventBus.buildResponse(EventBus.java:391)
                at org.apache.wicket.atmosphere.EventBus.handleStateless(EventBus.java:286)
                at org.apache.wicket.atmosphere.EventBus.post(EventBus.java:272)
                at com.tf2center.event.web.GenericWebObserver.notify(GenericWebObserver.java:33)
                at com.tf2center.event.service.AsynchronousEventWorker.broadcastFirstEvent(AsynchronousEventWorker.java:67)
                at com.tf2center.event.service.AsynchronousEventWorker.run(AsynchronousEventWorker.java:51)
                at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
                at java.util.concurrent.FutureTask.run(FutureTask.java:262)
                at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:178)
                at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:292)
                at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
                at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
                at java.lang.Thread.run(Thread.java:744)

So, the stack above just seems to “hang” in the JVM, resulting in 1 core getting 100% CPU load. By “hanging” I mean literally, hanging all day on that same stack frame. I have been making several stack dumps to ensure this.

Of course, I see that this problem may be inside ConcurrentLinkedQueue. However, the queue is about 1000 elements long, so I wouldn’t consider that “big” in any way.

[jfarcand]

Can you pas the entire stack trace? For sure this is not a bug in Atmosphere :-) I'm closing the bug, but if you can add the complete dump I can take a look.

[chrisgunnink]

Updated stack.

Out of curiosity: why would you synchronize on DefaultBroadcaster.resources while it is already Thread-safe?

[jfarcand]

Where is the updated stack? I'm seeing your comments, but not the stack.

[chrisgunnink]

"event-broadcaster-thread-10" prio=10 tid=0x00007f6a0c54c800 nid=0x4d80 runnable [0x00007f6a9091f000]
   java.lang.Thread.State: RUNNABLE
                at java.util.concurrent.ConcurrentLinkedQueue.remove(ConcurrentLinkedQueue.java:489)
                at org.atmosphere.cpr.DefaultBroadcaster.removeAtmosphereResource(DefaultBroadcaster.java:1576)
                - locked <0x0000000500bf3750> (a java.util.concurrent.ConcurrentLinkedQueue)
                at org.atmosphere.cpr.DefaultBroadcaster.removeAtmosphereResource(DefaultBroadcaster.java:1565)
                at org.apache.wicket.atmosphere.EventBus.buildResponse(EventBus.java:439)
                at org.apache.wicket.atmosphere.EventBus.buildResponse(EventBus.java:391)
                at org.apache.wicket.atmosphere.EventBus.handleStateless(EventBus.java:286)
                at org.apache.wicket.atmosphere.EventBus.post(EventBus.java:272)
                at com.tf2center.event.web.GenericWebObserver.notify(GenericWebObserver.java:33)
                at com.tf2center.event.service.AsynchronousEventWorker.broadcastFirstEvent(AsynchronousEventWorker.java:67)
                at com.tf2center.event.service.AsynchronousEventWorker.run(AsynchronousEventWorker.java:51)
                at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
                at java.util.concurrent.FutureTask.run(FutureTask.java:262)
                at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:178)
                at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:292)
                at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
                at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
                at java.lang.Thread.run(Thread.java:744)

[jfarcand]

I means the complete stack trace :-)

[chrisgunnink]

How can it be more "complete" when it starts with java.lang.Thread.run(Thread.java:744)?

[jfarcand]

I need the full thread dump of the VM, not only one thread. One thread I cannot help.

[chrisgunnink]

http://chrisgunnink.nl/tmp/tf2center-2014-03-05_1205.jstack

[jfarcand]

I don't think the thread is stuck since the state is runnable. You observe it with high load, right?

[chrisgunnink]

Yes, it's hard to reproduce, but it will happen eventually. Do you have a suggestion for another Queue implementation I could experiment with?

[jfarcand]

When it happens, it the thread marked as blocked? I don't think another queue will help. I don't know if you can update, but trying 1.0.18/19 may help for sure, but will require some work.

[chrisgunnink]

blocking is not the problem here. I will try 1.0.18 then ;-)