search

OneBusAway / onebusaway-gtfs-realtime-exporter

A Java library to help in implementing GTFS-realtime data sources.
https://github.com/OneBusAway/onebusaway-gtfs-realtime-exporter/wiki
Other
17 stars 12 forks source link

Frequent connect/disconnect blocks update. #2

Open koch-t opened 11 years ago

koch-t commented 11 years ago

If a client fast connect/disconnects, it results in a complete block in new updates. Other clients will no longer receive updates over websockets nor are there new GTFS-RT files written by the FileWriter. The jetty HTTP interface still works but doesn't offer new data.

Possible culprit: sendmessage method in Jetty hangs forever: https://github.com/OneBusAway/onebusaway-gtfs-realtime-exporter/blob/master/src/main/java/org/onebusaway/gtfs_realtime/exporter/GtfsRealtimeServlet.java#L138 Resulting in a block of this for loop https://github.com/OneBusAway/onebusaway-gtfs-realtime-exporter/blob/master/src/main/java/org/onebusaway/gtfs_realtime/exporter/GtfsRealtimeExporterImpl.java#L104

clinct commented 11 years ago

Hi, just to chime in with some information I found concerning this issue (we're in the same boat).

If I understand correctly, onebusaway is currently using Jetty 8, which does apparently has some issues with websockets (https://bugs.eclipse.org/bugs/buglist.cgi?quicksearch=websockets). Within some of these issues it's also mentioned that it's fixed in Jetty 9, but not easy to backport to 8.

Perhaps it's possible to migrate to this version? (although it isn't the easiest path: http://dev.eclipse.org/mhonarc/lists/jetty-users/msg03689.html and they also changed the supported standards between 8 and 9: http://www.eclipse.org/jetty/documentation/current/websocket-intro.html#ws-intro-provides )

bdferris commented 11 years ago

Thanks for the updates. Ironically, I had originally implemented this using Jetty 9, but reverted back to 8 so I didn't have to introduce a Java 1.7 requirement. I will see if I can find some time to upgrade to Jetty 9 to see if that helps.

bdferris commented 11 years ago

Ok, I've bumped the exporter to use Jetty 9. Note that because this also bumped the library from requiring only Java 1.6 to Java 1.7, I also bumped the library version number to 1.2.0-SNAPSHOT. You'll need to depend on this version to get the latest behavior.

Let me know if this helps?

koch-t commented 11 years ago

I can replicate the exact same scenario but now it will resume working after 5 minutes. Afaik the latter wasn't the case in Jetty 8. So it seems we're getting there now just reduce the write timeout?

koch-t commented 11 years ago

I may have spoken too soon, it seems it was only one update, now it's "down" again and i noticed the filewriter was never triggered. I suppose there are still one or more servlets still present in the list with listeners all taking up to the 3 minute time

koch-t commented 11 years ago 

"SIGINT handler" daemon prio=10 tid=0x0000000001aa9800 nid=0x4e5b waiting for monitor entry [0x00007f5165faa000]
   java.lang.Thread.State: BLOCKED (on object monitor)
        at java.lang.Shutdown.exit(Shutdown.java:212)
        - waiting to lock <0x000000078eba6928> (a java.lang.Class for java.lang.Shutdown)
        at java.lang.Terminator$1.handle(Terminator.java:52)
        at sun.misc.Signal$1.run(Signal.java:212)
        at java.lang.Thread.run(Thread.java:722)

"SIGINT handler" daemon prio=10 tid=0x0000000002347000 nid=0x4e55 waiting for monitor entry [0x00007f5059523000]
   java.lang.Thread.State: BLOCKED (on object monitor)
        at java.lang.Shutdown.exit(Shutdown.java:212)
        - waiting to lock <0x000000078eba6928> (a java.lang.Class for java.lang.Shutdown)
        at java.lang.Terminator$1.handle(Terminator.java:52)
        at sun.misc.Signal$1.run(Signal.java:212)
        at java.lang.Thread.run(Thread.java:722)

"SIGINT handler" daemon prio=10 tid=0x00000000009fd000 nid=0x4e07 waiting for monitor entry [0x00007f5165ba6000]
   java.lang.Thread.State: BLOCKED (on object monitor)
        at java.lang.Shutdown.exit(Shutdown.java:212)
        - waiting to lock <0x000000078eba6928> (a java.lang.Class for java.lang.Shutdown)
        at java.lang.Terminator$1.handle(Terminator.java:52)
        at sun.misc.Signal$1.run(Signal.java:212)
        at java.lang.Thread.run(Thread.java:722)

"SIGINT handler" daemon prio=10 tid=0x0000000000933000 nid=0x4e05 waiting for monitor entry [0x00007f51656a1000]
   java.lang.Thread.State: BLOCKED (on object monitor)
        at java.lang.Shutdown.exit(Shutdown.java:212)
        - waiting to lock <0x000000078eba6928> (a java.lang.Class for java.lang.Shutdown)
        at java.lang.Terminator$1.handle(Terminator.java:52)
        at sun.misc.Signal$1.run(Signal.java:212)
        at java.lang.Thread.run(Thread.java:722)

"SIGINT handler" daemon prio=10 tid=0x00000000009fb800 nid=0x4deb waiting for monitor entry [0x00007f5164a91000]
   java.lang.Thread.State: BLOCKED (on object monitor)
        at java.lang.Shutdown.exit(Shutdown.java:212)
        - waiting to lock <0x000000078eba6928> (a java.lang.Class for java.lang.Shutdown)
        at java.lang.Terminator$1.handle(Terminator.java:52)
        at sun.misc.Signal$1.run(Signal.java:212)
        at java.lang.Thread.run(Thread.java:722)

"SIGINT handler" daemon prio=10 tid=0x00000000012f0800 nid=0x4de2 waiting for monitor entry [0x00007f51655a0000]
   java.lang.Thread.State: BLOCKED (on object monitor)
        at java.lang.Shutdown.exit(Shutdown.java:212)
        - waiting to lock <0x000000078eba6928> (a java.lang.Class for java.lang.Shutdown)
        at java.lang.Terminator$1.handle(Terminator.java:52)
        at sun.misc.Signal$1.run(Signal.java:212)
        at java.lang.Thread.run(Thread.java:722)

"Thread-1" prio=10 tid=0x0000000004282800 nid=0x4dcd in Object.wait() [0x00007f5020798000]
   java.lang.Thread.State: TIMED_WAITING (on object monitor)
        at java.lang.Object.wait(Native Method)
        - waiting on <0x000000078e5b28c8> (a java.lang.Thread)
        at java.lang.Thread.join(Thread.java:1266)
        - locked <0x000000078e5b28c8> (a java.lang.Thread)
        at org.eclipse.jetty.util.thread.QueuedThreadPool.doStop(QueuedThreadPool.java:153)
        at org.eclipse.jetty.util.component.AbstractLifeCycle.stop(AbstractLifeCycle.java:90)
        - locked <0x000000078e5b2850> (a java.lang.Object)
        at org.eclipse.jetty.util.component.ContainerLifeCycle.stop(ContainerLifeCycle.java:119)
        at org.eclipse.jetty.util.component.ContainerLifeCycle.doStop(ContainerLifeCycle.java:138)
        at org.eclipse.jetty.server.handler.AbstractHandler.doStop(AbstractHandler.java:69)
        at org.eclipse.jetty.server.Server.doStop(Server.java:409)
        at org.eclipse.jetty.util.component.AbstractLifeCycle.stop(AbstractLifeCycle.java:90)
        - locked <0x000000078e5b6a70> (a java.lang.Object)
        at org.onebusaway.guice.jetty_exporter.JettyExporterServiceImpl.stop(JettyExporterServiceImpl.java:79)
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at java.lang.reflect.Method.invoke(Method.java:601)
        at org.onebusaway.guice.jsr250.JSR250Module$ObjectAndMethod.execute(JSR250Module.java:139)
        at org.onebusaway.guice.jsr250.JSR250Module$LifecycleServiceImpl.stop(JSR250Module.java:220)
        at org.onebusaway.guice.jsr250.JSR250Module$PreDestroyShutdownHook.run(JSR250Module.java:242)
        at java.lang.Thread.run(Thread.java:722)

"SIGINT handler" daemon prio=10 tid=0x0000000004280000 nid=0x4dcc in Object.wait() [0x00007f502089a000]
   java.lang.Thread.State: WAITING (on object monitor)
        at java.lang.Object.wait(Native Method)
        - waiting on <0x000000078eba67d8> (a java.lang.Thread)
        at java.lang.Thread.join(Thread.java:1258)
        - locked <0x000000078eba67d8> (a java.lang.Thread)
        at java.lang.Thread.join(Thread.java:1332)
        at java.lang.ApplicationShutdownHooks.runHooks(ApplicationShutdownHooks.java:106)
        at java.lang.ApplicationShutdownHooks$1.run(ApplicationShutdownHooks.java:46)
        at java.lang.Shutdown.runHooks(Shutdown.java:123)
        at java.lang.Shutdown.sequence(Shutdown.java:167)
        at java.lang.Shutdown.exit(Shutdown.java:212)
        - locked <0x000000078eba6928> (a java.lang.Class for java.lang.Shutdown)
        at java.lang.Terminator$1.handle(Terminator.java:52)
        at sun.misc.Signal$1.run(Signal.java:212)
        at java.lang.Thread.run(Thread.java:722)

"pool-4-thread-5009" prio=10 tid=0x000000000427e000 nid=0x4dcb waiting for monitor entry [0x00007f502099b000]
   java.lang.Thread.State: BLOCKED (on object monitor)
        at org.onebusaway.gtfs_realtime.exporter.GtfsRealtimeExporterImpl.handleIncrementalUpdate(GtfsRealtimeExporterImpl.java:83)
        - waiting to lock <0x000000078e629340> (a org.onebusaway.gtfs_realtime.exporter.GtfsRealtimeExporterImpl)
        at nl.ovapi.rid.gtfsrt.services.BisonToGtfsRealtimeService$ProcessKV6Task.run(BisonToGtfsRealtimeService.java:503)
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
        at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:334)
        at java.util.concurrent.FutureTask.run(FutureTask.java:166)
        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:722)

------------------Snapped similar threads to above (handleincrementalupdate)

"iothread-2" prio=10 tid=0x00007f5160073000 nid=0x201d runnable [0x00007f516539e000]
   java.lang.Thread.State: RUNNABLE
        at sun.nio.ch.EPollArrayWrapper.epollWait(Native Method)
        at sun.nio.ch.EPollArrayWrapper.poll(EPollArrayWrapper.java:228)
        at sun.nio.ch.EPollSelectorImpl.doSelect(EPollSelectorImpl.java:81)
        at sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:87)
        - locked <0x0000000797d3bf60> (a sun.nio.ch.Util$2)
        - locked <0x0000000797d3bf50> (a java.util.Collections$UnmodifiableSet)
        - locked <0x0000000797d3bc80> (a sun.nio.ch.EPollSelectorImpl)
        at sun.nio.ch.SelectorImpl.select(SelectorImpl.java:98)
        at zmq.Poller.run(Poller.java:203)
        at java.lang.Thread.run(Thread.java:722)

"reaper-1" prio=10 tid=0x00007f51600c5800 nid=0x201c runnable [0x00007f516549f000]
   java.lang.Thread.State: RUNNABLE
        at sun.nio.ch.EPollArrayWrapper.epollWait(Native Method)
        at sun.nio.ch.EPollArrayWrapper.poll(EPollArrayWrapper.java:228)
        at sun.nio.ch.EPollSelectorImpl.doSelect(EPollSelectorImpl.java:81)
        at sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:87)
        - locked <0x0000000797d47460> (a sun.nio.ch.Util$2)
        - locked <0x0000000797d47450> (a java.util.Collections$UnmodifiableSet)
        - locked <0x0000000797d47200> (a sun.nio.ch.EPollSelectorImpl)
        at sun.nio.ch.SelectorImpl.select(SelectorImpl.java:98)
        at zmq.Poller.run(Poller.java:203)
        at java.lang.Thread.run(Thread.java:722)

"qtp871484051-20-selector-4" prio=10 tid=0x00007f5160307800 nid=0x1ff7 waiting for monitor entry [0x00007f5165da7000]
   java.lang.Thread.State: BLOCKED (on object monitor)
        at org.onebusaway.gtfs_realtime.exporter.GtfsRealtimeExporterImpl.removeIncrementalListener(GtfsRealtimeExporterImpl.java:144)
        - waiting to lock <0x000000078e629340> (a org.onebusaway.gtfs_realtime.exporter.GtfsRealtimeExporterImpl)
        at org.onebusaway.gtfs_realtime.exporter.GtfsRealtimeServlet$DataWebSocket.onClose(GtfsRealtimeServlet.java:141)
        at sun.reflect.GeneratedMethodAccessor53.invoke(Unknown Source)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at java.lang.reflect.Method.invoke(Method.java:601)
        at org.eclipse.jetty.websocket.common.events.EventMethod.call(EventMethod.java:102)
        at org.eclipse.jetty.websocket.common.events.AnnotatedEventDriver.onClose(AnnotatedEventDriver.java:116)
        at org.eclipse.jetty.websocket.common.WebSocketSession.notifyClose(WebSocketSession.java:341)
        at org.eclipse.jetty.websocket.common.io.AbstractWebSocketConnection$FlushCallback.failed(AbstractWebSocketConnection.java:100)
        at org.eclipse.jetty.websocket.common.io.WriteBytesProvider.failAll(WriteBytesProvider.java:191)
        - locked <0x000000079852c868> (a org.eclipse.jetty.websocket.common.io.WriteBytesProvider)
        at org.eclipse.jetty.websocket.common.io.WriteBytesProvider.failed(WriteBytesProvider.java:207)
        at org.eclipse.jetty.io.WriteFlusher$PendingState.fail(WriteFlusher.java:259)
        at org.eclipse.jetty.io.WriteFlusher.completeWrite(WriteFlusher.java:427)
        at org.eclipse.jetty.io.SelectChannelEndPoint.onSelected(SelectChannelEndPoint.java:111)
        at org.eclipse.jetty.io.SelectorManager$ManagedSelector.processKey(SelectorManager.java:498)
        at org.eclipse.jetty.io.SelectorManager$ManagedSelector.select(SelectorManager.java:455)
        at org.eclipse.jetty.io.SelectorManager$ManagedSelector.run(SelectorManager.java:420)
        at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:601)
        at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:532)
        at java.lang.Thread.run(Thread.java:722)

"qtp871484051-19" prio=10 tid=0x00007f5160305800 nid=0x1ff6 waiting for monitor entry [0x00007f5165ea8000]
   java.lang.Thread.State: BLOCKED (on object monitor)
        at org.onebusaway.gtfs_realtime.exporter.GtfsRealtimeExporterImpl.removeIncrementalListener(GtfsRealtimeExporterImpl.java:144)
        - waiting to lock <0x000000078e629340> (a org.onebusaway.gtfs_realtime.exporter.GtfsRealtimeExporterImpl)
        at org.onebusaway.gtfs_realtime.exporter.GtfsRealtimeServlet$DataWebSocket.onClose(GtfsRealtimeServlet.java:141)
        at sun.reflect.GeneratedMethodAccessor53.invoke(Unknown Source)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at java.lang.reflect.Method.invoke(Method.java:601)
        at org.eclipse.jetty.websocket.common.events.EventMethod.call(EventMethod.java:102)
        at org.eclipse.jetty.websocket.common.events.AnnotatedEventDriver.onClose(AnnotatedEventDriver.java:116)
        at org.eclipse.jetty.websocket.common.WebSocketSession.notifyClose(WebSocketSession.java:341)
        at org.eclipse.jetty.websocket.common.io.AbstractWebSocketConnection$FlushCallback.failed(AbstractWebSocketConnection.java:100)
        at org.eclipse.jetty.websocket.common.io.WriteBytesProvider.failAll(WriteBytesProvider.java:191)
        - locked <0x000000079857c028> (a org.eclipse.jetty.websocket.common.io.WriteBytesProvider)
        at org.eclipse.jetty.websocket.common.io.WriteBytesProvider.close(WriteBytesProvider.java:118)
        at org.eclipse.jetty.websocket.common.io.AbstractWebSocketConnection.onClose(AbstractWebSocketConnection.java:439)
        at org.eclipse.jetty.websocket.server.WebSocketServerConnection.onClose(WebSocketServerConnection.java:64)
        at org.eclipse.jetty.io.SelectorManager.connectionClosed(SelectorManager.java:247)
        at org.eclipse.jetty.io.SelectorManager$ManagedSelector.destroyEndPoint(SelectorManager.java:587)
        at org.eclipse.jetty.io.SelectChannelEndPoint.close(SelectChannelEndPoint.java:166)
        at org.eclipse.jetty.websocket.common.io.AbstractWebSocketConnection.disconnect(AbstractWebSocketConnection.java:272)
        at org.eclipse.jetty.websocket.common.io.AbstractWebSocketConnection.disconnect(AbstractWebSocketConnection.java:259)
        at org.eclipse.jetty.websocket.common.io.AbstractWebSocketConnection$OnDisconnectCallback.writeFailed(AbstractWebSocketConnection.java:150)
        at org.eclipse.jetty.websocket.common.io.WriteCallbackWrapper.failed(WriteCallbackWrapper.java:50)
        at org.eclipse.jetty.websocket.common.io.WriteBytesProvider.notifySafeFailure(WriteBytesProvider.java:267)
        at org.eclipse.jetty.websocket.common.io.WriteBytesProvider.access$300(WriteBytesProvider.java:40)
        at org.eclipse.jetty.websocket.common.io.WriteBytesProvider$FrameEntry.notifyFailure(WriteBytesProvider.java:68)
        at org.eclipse.jetty.websocket.common.io.WriteBytesProvider.failAll(WriteBytesProvider.java:173)
        - locked <0x000000079857c028> (a org.eclipse.jetty.websocket.common.io.WriteBytesProvider)
        at org.eclipse.jetty.websocket.common.io.WriteBytesProvider.failed(WriteBytesProvider.java:207)
        at org.eclipse.jetty.io.WriteFlusher.write(WriteFlusher.java:366)
        at org.eclipse.jetty.io.AbstractEndPoint.write(AbstractEndPoint.java:125)
        at org.eclipse.jetty.websocket.common.io.AbstractWebSocketConnection.write(AbstractWebSocketConnection.java:654)
        at org.eclipse.jetty.websocket.common.io.AbstractWebSocketConnection.flush(AbstractWebSocketConnection.java:348)
        at org.eclipse.jetty.websocket.common.io.AbstractWebSocketConnection.outgoingFrame(AbstractWebSocketConnection.java:540)
        at org.eclipse.jetty.websocket.common.io.AbstractWebSocketConnection.onConnectionStateChange(AbstractWebSocketConnection.java:458)
        at org.eclipse.jetty.websocket.common.io.IOState.notifyStateListeners(IOState.java:145)
        at org.eclipse.jetty.websocket.common.io.IOState.onCloseLocal(IOState.java:236)
        at org.eclipse.jetty.websocket.common.io.AbstractWebSocketConnection.enqueClose(AbstractWebSocketConnection.java:288)
        at org.eclipse.jetty.websocket.common.io.AbstractWebSocketConnection.close(AbstractWebSocketConnection.java:229)
        at org.eclipse.jetty.websocket.common.io.AbstractWebSocketConnection.close(AbstractWebSocketConnection.java:223)
        at org.eclipse.jetty.io.SelectorManager$ManagedSelector$EndPointCloser.run(SelectorManager.java:836)
        at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:601)
        at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:532)
        at java.lang.Thread.run(Thread.java:722)

"qtp871484051-13" prio=10 tid=0x00007f51602f3000 nid=0x1fee waiting for monitor entry [0x00007f51664ae000]
   java.lang.Thread.State: BLOCKED (on object monitor)
        at org.onebusaway.gtfs_realtime.exporter.GtfsRealtimeExporterImpl.removeIncrementalListener(GtfsRealtimeExporterImpl.java:144)
        - waiting to lock <0x000000078e629340> (a org.onebusaway.gtfs_realtime.exporter.GtfsRealtimeExporterImpl)
        at org.onebusaway.gtfs_realtime.exporter.GtfsRealtimeServlet$DataWebSocket.onClose(GtfsRealtimeServlet.java:141)
        at sun.reflect.GeneratedMethodAccessor53.invoke(Unknown Source)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at java.lang.reflect.Method.invoke(Method.java:601)
        at org.eclipse.jetty.websocket.common.events.EventMethod.call(EventMethod.java:102)
        at org.eclipse.jetty.websocket.common.events.AnnotatedEventDriver.onClose(AnnotatedEventDriver.java:116)
        at org.eclipse.jetty.websocket.common.WebSocketSession.notifyClose(WebSocketSession.java:341)
        at org.eclipse.jetty.websocket.common.io.AbstractWebSocketConnection$FlushCallback.failed(AbstractWebSocketConnection.java:100)
        at org.eclipse.jetty.websocket.common.io.WriteBytesProvider.failAll(WriteBytesProvider.java:191)
        - locked <0x0000000798585048> (a org.eclipse.jetty.websocket.common.io.WriteBytesProvider)
        at org.eclipse.jetty.websocket.common.io.WriteBytesProvider.close(WriteBytesProvider.java:118)
        at org.eclipse.jetty.websocket.common.io.AbstractWebSocketConnection.onClose(AbstractWebSocketConnection.java:439)
        at org.eclipse.jetty.websocket.server.WebSocketServerConnection.onClose(WebSocketServerConnection.java:64)
        at org.eclipse.jetty.io.SelectorManager.connectionClosed(SelectorManager.java:247)
        at org.eclipse.jetty.io.SelectorManager$ManagedSelector.destroyEndPoint(SelectorManager.java:587)
        at org.eclipse.jetty.io.SelectChannelEndPoint.close(SelectChannelEndPoint.java:166)
        at org.eclipse.jetty.websocket.common.io.AbstractWebSocketConnection.disconnect(AbstractWebSocketConnection.java:272)
        at org.eclipse.jetty.websocket.common.io.AbstractWebSocketConnection.disconnect(AbstractWebSocketConnection.java:259)
        at org.eclipse.jetty.websocket.common.io.AbstractWebSocketConnection$OnDisconnectCallback.writeFailed(AbstractWebSocketConnection.java:150)
        at org.eclipse.jetty.websocket.common.io.WriteCallbackWrapper.failed(WriteCallbackWrapper.java:50)
        at org.eclipse.jetty.websocket.common.io.WriteBytesProvider.notifySafeFailure(WriteBytesProvider.java:267)
        at org.eclipse.jetty.websocket.common.io.WriteBytesProvider.access$300(WriteBytesProvider.java:40)
        at org.eclipse.jetty.websocket.common.io.WriteBytesProvider$FrameEntry.notifyFailure(WriteBytesProvider.java:68)
        at org.eclipse.jetty.websocket.common.io.WriteBytesProvider.failAll(WriteBytesProvider.java:173)
        - locked <0x0000000798585048> (a org.eclipse.jetty.websocket.common.io.WriteBytesProvider)
        at org.eclipse.jetty.websocket.common.io.WriteBytesProvider.failed(WriteBytesProvider.java:207)
        at org.eclipse.jetty.io.WriteFlusher.write(WriteFlusher.java:366)
        at org.eclipse.jetty.io.AbstractEndPoint.write(AbstractEndPoint.java:125)
        at org.eclipse.jetty.websocket.common.io.AbstractWebSocketConnection.write(AbstractWebSocketConnection.java:654)
        at org.eclipse.jetty.websocket.common.io.AbstractWebSocketConnection.flush(AbstractWebSocketConnection.java:348)
        at org.eclipse.jetty.websocket.common.io.AbstractWebSocketConnection.outgoingFrame(AbstractWebSocketConnection.java:540)
        at org.eclipse.jetty.websocket.common.io.AbstractWebSocketConnection.onConnectionStateChange(AbstractWebSocketConnection.java:458)
        at org.eclipse.jetty.websocket.common.io.IOState.notifyStateListeners(IOState.java:145)
        at org.eclipse.jetty.websocket.common.io.IOState.onCloseLocal(IOState.java:236)
        at org.eclipse.jetty.websocket.common.io.AbstractWebSocketConnection.enqueClose(AbstractWebSocketConnection.java:288)
        at org.eclipse.jetty.websocket.common.io.AbstractWebSocketConnection.close(AbstractWebSocketConnection.java:229)
        at org.eclipse.jetty.websocket.common.io.AbstractWebSocketConnection.close(AbstractWebSocketConnection.java:223)
        at org.eclipse.jetty.io.SelectorManager$ManagedSelector$EndPointCloser.run(SelectorManager.java:836)
        at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:601)
        at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:532)
        at java.lang.Thread.run(Thread.java:722)

"DateCache" daemon prio=10 tid=0x00007f51602c5800 nid=0x1fed in Object.wait() [0x00007f51665b0000]
   java.lang.Thread.State: TIMED_WAITING (on object monitor)
        at java.lang.Object.wait(Native Method)
        - waiting on <0x000000078e5986e0> (a java.util.TaskQueue)
        at java.util.TimerThread.mainLoop(Timer.java:552)
        - locked <0x000000078e5986e0> (a java.util.TaskQueue)
        at java.util.TimerThread.run(Timer.java:505)

"com.google.inject.internal.util.$Finalizer" daemon prio=10 tid=0x00007f516019f800 nid=0x1fec in Object.wait() [0x00007f51666b1000]
   java.lang.Thread.State: WAITING (on object monitor)
        at java.lang.Object.wait(Native Method)
        - waiting on <0x000000078e5a0268> (a java.lang.ref.ReferenceQueue$Lock)
        at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:135)
        - locked <0x000000078e5a0268> (a java.lang.ref.ReferenceQueue$Lock)
        at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:151)
        at com.google.inject.internal.util.$Finalizer.run(Finalizer.java:114)

"Service Thread" daemon prio=10 tid=0x000000000086d000 nid=0x1fe7 runnable [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"C2 CompilerThread1" daemon prio=10 tid=0x0000000000867800 nid=0x1fe6 waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"C2 CompilerThread0" daemon prio=10 tid=0x0000000000864800 nid=0x1fe5 waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"Signal Dispatcher" daemon prio=10 tid=0x0000000000862800 nid=0x1fe4 waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"Finalizer" daemon prio=10 tid=0x0000000000806800 nid=0x1fe3 in Object.wait() [0x00007f51684a7000]
   java.lang.Thread.State: WAITING (on object monitor)
        at java.lang.Object.wait(Native Method)
        - waiting on <0x000000078e5ca8f8> (a java.lang.ref.ReferenceQueue$Lock)
        at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:135)
        - locked <0x000000078e5ca8f8> (a java.lang.ref.ReferenceQueue$Lock)
        at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:151)
        at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:189)

"Reference Handler" daemon prio=10 tid=0x0000000000804000 nid=0x1fe2 in Object.wait() [0x00007f51685a8000]
   java.lang.Thread.State: WAITING (on object monitor)
        at java.lang.Object.wait(Native Method)
        - waiting on <0x000000078e5ca3b8> (a java.lang.ref.Reference$Lock)
        at java.lang.Object.wait(Object.java:503)
        at java.lang.ref.Reference$ReferenceHandler.run(Reference.java:133)
        - locked <0x000000078e5ca3b8> (a java.lang.ref.Reference$Lock)

"VM Thread" prio=10 tid=0x00000000007fb800 nid=0x1fe1 runnable 

"GC task thread#0 (ParallelGC)" prio=10 tid=0x000000000061c000 nid=0x1fd9 runnable 

"GC task thread#1 (ParallelGC)" prio=10 tid=0x000000000061d800 nid=0x1fda runnable 

"GC task thread#2 (ParallelGC)" prio=10 tid=0x000000000061f800 nid=0x1fdb runnable 

"GC task thread#3 (ParallelGC)" prio=10 tid=0x0000000000621800 nid=0x1fdc runnable 

"GC task thread#4 (ParallelGC)" prio=10 tid=0x0000000000623000 nid=0x1fdd runnable 

"GC task thread#5 (ParallelGC)" prio=10 tid=0x0000000000625000 nid=0x1fde runnable 

"GC task thread#6 (ParallelGC)" prio=10 tid=0x0000000000627000 nid=0x1fdf runnable 

"GC task thread#7 (ParallelGC)" prio=10 tid=0x0000000000628800 nid=0x1fe0 runnable 

"VM Periodic Task Thread" prio=10 tid=0x0000000000877800 nid=0x1fe8 waiting on condition 

JNI global references: 216

Found one Java-level deadlock:
=============================
"pool-4-thread-5009":
  waiting to lock monitor 0x0000000001f87130 (object 0x000000078e629340, a org.onebusaway.gtfs_realtime.exporter.GtfsRealtimeExporterImpl),
  which is held by "pool-4-thread-4"
"pool-4-thread-4":
  waiting to lock monitor 0x0000000001f851b0 (object 0x000000079852c868, a org.eclipse.jetty.websocket.common.io.WriteBytesProvider),
  which is held by "qtp871484051-20-selector-4"
"qtp871484051-20-selector-4":
  waiting to lock monitor 0x0000000001f87130 (object 0x000000078e629340, a org.onebusaway.gtfs_realtime.exporter.GtfsRealtimeExporterImpl),
  which is held by "pool-4-thread-4"

Java stack information for the threads listed above:
===================================================
"pool-4-thread-5009":
        at org.onebusaway.gtfs_realtime.exporter.GtfsRealtimeExporterImpl.handleIncrementalUpdate(GtfsRealtimeExporterImpl.java:83)
        - waiting to lock <0x000000078e629340> (a org.onebusaway.gtfs_realtime.exporter.GtfsRealtimeExporterImpl)
        at nl.ovapi.rid.gtfsrt.services.BisonToGtfsRealtimeService$ProcessKV6Task.run(BisonToGtfsRealtimeService.java:503)
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
        at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:334)
        at java.util.concurrent.FutureTask.run(FutureTask.java:166)
        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:722)
"pool-4-thread-4":
        at org.eclipse.jetty.websocket.common.io.WriteBytesProvider.enqueue(WriteBytesProvider.java:127)
        - waiting to lock <0x000000079852c868> (a org.eclipse.jetty.websocket.common.io.WriteBytesProvider)
        at org.eclipse.jetty.websocket.common.io.AbstractWebSocketConnection.outgoingFrame(AbstractWebSocketConnection.java:538)
        at org.eclipse.jetty.websocket.common.extensions.ExtensionStack.outgoingFrame(ExtensionStack.java:236)
        at org.eclipse.jetty.websocket.common.WebSocketRemoteEndpoint.sendAsyncFrame(WebSocketRemoteEndpoint.java:88)
        at org.eclipse.jetty.websocket.common.WebSocketRemoteEndpoint.blockingWrite(WebSocketRemoteEndpoint.java:55)
        at org.eclipse.jetty.websocket.common.WebSocketRemoteEndpoint.sendBytes(WebSocketRemoteEndpoint.java:109)
        at org.onebusaway.gtfs_realtime.exporter.GtfsRealtimeServlet$DataWebSocket.handleFeed(GtfsRealtimeServlet.java:161)
        at org.onebusaway.gtfs_realtime.exporter.GtfsRealtimeExporterImpl.handleIncrementalUpdate(GtfsRealtimeExporterImpl.java:104)
        - locked <0x000000078e629340> (a org.onebusaway.gtfs_realtime.exporter.GtfsRealtimeExporterImpl)
        at nl.ovapi.rid.gtfsrt.services.BisonToGtfsRealtimeService$ProcessKV6Task.run(BisonToGtfsRealtimeService.java:503)
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
        at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:334)
        at java.util.concurrent.FutureTask.run(FutureTask.java:166)
        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:722)
"qtp871484051-20-selector-4":
        at org.onebusaway.gtfs_realtime.exporter.GtfsRealtimeExporterImpl.removeIncrementalListener(GtfsRealtimeExporterImpl.java:144)
        - waiting to lock <0x000000078e629340> (a org.onebusaway.gtfs_realtime.exporter.GtfsRealtimeExporterImpl)
        at org.onebusaway.gtfs_realtime.exporter.GtfsRealtimeServlet$DataWebSocket.onClose(GtfsRealtimeServlet.java:141)
        at sun.reflect.GeneratedMethodAccessor53.invoke(Unknown Source)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at java.lang.reflect.Method.invoke(Method.java:601)
        at org.eclipse.jetty.websocket.common.events.EventMethod.call(EventMethod.java:102)
        at org.eclipse.jetty.websocket.common.events.AnnotatedEventDriver.onClose(AnnotatedEventDriver.java:116)
        at org.eclipse.jetty.websocket.common.WebSocketSession.notifyClose(WebSocketSession.java:341)
        at org.eclipse.jetty.websocket.common.io.AbstractWebSocketConnection$FlushCallback.failed(AbstractWebSocketConnection.java:100)
        at org.eclipse.jetty.websocket.common.io.WriteBytesProvider.failAll(WriteBytesProvider.java:191)
        - locked <0x000000079852c868> (a org.eclipse.jetty.websocket.common.io.WriteBytesProvider)
        at org.eclipse.jetty.websocket.common.io.WriteBytesProvider.failed(WriteBytesProvider.java:207)
        at org.eclipse.jetty.io.WriteFlusher$PendingState.fail(WriteFlusher.java:259)
        at org.eclipse.jetty.io.WriteFlusher.completeWrite(WriteFlusher.java:427)
        at org.eclipse.jetty.io.SelectChannelEndPoint.onSelected(SelectChannelEndPoint.java:111)
        at org.eclipse.jetty.io.SelectorManager$ManagedSelector.processKey(SelectorManager.java:498)
        at org.eclipse.jetty.io.SelectorManager$ManagedSelector.select(SelectorManager.java:455)
        at org.eclipse.jetty.io.SelectorManager$ManagedSelector.run(SelectorManager.java:420)
        at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:601)
        at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:532)
        at java.lang.Thread.run(Thread.java:722)

Found 1 deadlock.

Heap
 PSYoungGen      total 258432K, used 245796K [0x00000007d5560000, 0x00000007f2bc0000, 0x0000000800000000)
  eden space 163072K, 92% used [0x00000007d5560000,0x00000007de8510f8,0x00000007df4a0000)
  from space 95360K, 99% used [0x00000007df820000,0x00000007e5538020,0x00000007e5540000)
  to   space 159296K, 0% used [0x00000007e9030000,0x00000007e9030000,0x00000007f2bc0000)
 ParOldGen       total 667776K, used 435252K [0x0000000780000000, 0x00000007a8c20000, 0x00000007d5560000)
  object space 667776K, 65% used [0x0000000780000000,0x000000079a90d138,0x00000007a8c20000)
 PSPermGen       total 25024K, used 18740K [0x0000000775a00000, 0x0000000777270000, 0x0000000780000000)
  object space 25024K, 74% used [0x0000000775a00000,0x0000000776c4d380,0x0000000777270000)
koch-t commented 11 years ago

Another thread dump similar to above but now directly after locking giving less clutter: http://pastebin.com/Zj8xBCuA

Most interesting is this:

Found one Java-level deadlock:
=============================
"pool-4-thread-34":
  waiting to lock monitor 0x00000000008a8be0 (object 0x000000078e596080, a org.onebusaway.gtfs_realtime.exporter.GtfsRealtimeExporterImpl),
  which is held by "pool-4-thread-2"
"pool-4-thread-2":
  waiting to lock monitor 0x00000000008a8b38 (object 0x00000007e9348070, a org.eclipse.jetty.websocket.common.io.WriteBytesProvider),
  which is held by "qtp1575495023-18-selector-2"
"qtp1575495023-18-selector-2":
  waiting to lock monitor 0x00000000008a8be0 (object 0x000000078e596080, a org.onebusaway.gtfs_realtime.exporter.GtfsRealtimeExporterImpl),
  which is held by "pool-4-thread-2"

Java stack information for the threads listed above:
===================================================
"pool-4-thread-34":
        at org.onebusaway.gtfs_realtime.exporter.GtfsRealtimeExporterImpl.handleIncrementalUpdate(GtfsRealtimeExporterImpl.java:83)
        - waiting to lock <0x000000078e596080> (a org.onebusaway.gtfs_realtime.exporter.GtfsRealtimeExporterImpl)
        at nl.ovapi.rid.gtfsrt.services.BisonToGtfsRealtimeService$ProcessKV6Task.run(BisonToGtfsRealtimeService.java:503)
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
        at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:334)
        at java.util.concurrent.FutureTask.run(FutureTask.java:166)
        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:722)
"pool-4-thread-2":
        at org.eclipse.jetty.websocket.common.io.WriteBytesProvider.enqueue(WriteBytesProvider.java:127)
        - waiting to lock <0x00000007e9348070> (a org.eclipse.jetty.websocket.common.io.WriteBytesProvider)
        at org.eclipse.jetty.websocket.common.io.AbstractWebSocketConnection.outgoingFrame(AbstractWebSocketConnection.java:538)
        at org.eclipse.jetty.websocket.common.extensions.ExtensionStack.outgoingFrame(ExtensionStack.java:236)
        at org.eclipse.jetty.websocket.common.WebSocketRemoteEndpoint.sendAsyncFrame(WebSocketRemoteEndpoint.java:88)
        at org.eclipse.jetty.websocket.common.WebSocketRemoteEndpoint.blockingWrite(WebSocketRemoteEndpoint.java:55)
        at org.eclipse.jetty.websocket.common.WebSocketRemoteEndpoint.sendBytes(WebSocketRemoteEndpoint.java:109)
        at org.onebusaway.gtfs_realtime.exporter.GtfsRealtimeServlet$DataWebSocket.handleFeed(GtfsRealtimeServlet.java:161)
        at org.onebusaway.gtfs_realtime.exporter.GtfsRealtimeExporterImpl.handleIncrementalUpdate(GtfsRealtimeExporterImpl.java:104)
        - locked <0x000000078e596080> (a org.onebusaway.gtfs_realtime.exporter.GtfsRealtimeExporterImpl)
        at nl.ovapi.rid.gtfsrt.services.BisonToGtfsRealtimeService$ProcessKV6Task.run(BisonToGtfsRealtimeService.java:503)
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
        at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:334)
        at java.util.concurrent.FutureTask.run(FutureTask.java:166)
        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:722)
"qtp1575495023-18-selector-2":
        at org.onebusaway.gtfs_realtime.exporter.GtfsRealtimeExporterImpl.removeIncrementalListener(GtfsRealtimeExporterImpl.java:144)
        - waiting to lock <0x000000078e596080> (a org.onebusaway.gtfs_realtime.exporter.GtfsRealtimeExporterImpl)
        at org.onebusaway.gtfs_realtime.exporter.GtfsRealtimeServlet$DataWebSocket.onClose(GtfsRealtimeServlet.java:141)
        at sun.reflect.GeneratedMethodAccessor43.invoke(Unknown Source)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at java.lang.reflect.Method.invoke(Method.java:601)
        at org.eclipse.jetty.websocket.common.events.EventMethod.call(EventMethod.java:102)
        at org.eclipse.jetty.websocket.common.events.AnnotatedEventDriver.onClose(AnnotatedEventDriver.java:116)
        at org.eclipse.jetty.websocket.common.WebSocketSession.notifyClose(WebSocketSession.java:341)
        at org.eclipse.jetty.websocket.common.io.AbstractWebSocketConnection$FlushCallback.failed(AbstractWebSocketConnection.java:100)
        at org.eclipse.jetty.websocket.common.io.WriteBytesProvider.failAll(WriteBytesProvider.java:191)
        - locked <0x00000007e9348070> (a org.eclipse.jetty.websocket.common.io.WriteBytesProvider)
        at org.eclipse.jetty.websocket.common.io.WriteBytesProvider.failed(WriteBytesProvider.java:207)
        at org.eclipse.jetty.io.WriteFlusher$PendingState.fail(WriteFlusher.java:259)
        at org.eclipse.jetty.io.WriteFlusher.completeWrite(WriteFlusher.java:427)
        at org.eclipse.jetty.io.SelectChannelEndPoint.onSelected(SelectChannelEndPoint.java:111)
        at org.eclipse.jetty.io.SelectorManager$ManagedSelector.processKey(SelectorManager.java:498)
        at org.eclipse.jetty.io.SelectorManager$ManagedSelector.select(SelectorManager.java:455)
        at org.eclipse.jetty.io.SelectorManager$ManagedSelector.run(SelectorManager.java:420)
        at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:601)
        at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:532)
        at java.lang.Thread.run(Thread.java:722)

Found 1 deadlock.
koch-t commented 11 years ago

Seems like it's a deadlock in the OBA library instead of just jetty.

bdferris commented 11 years ago

Ok, I wrote some integration stress-tests and attempted to address the concurrency issues I found as result of that. Maybe give the latest version a try?

koch-t commented 11 years ago

Thanks, to make my life a bit easier could the version be bumped? Don't think the maven artifact got updated, http://nexus.onebusaway.org/content/groups/public/org/onebusaway/onebusaway-gtfs-realtime-exporter/1.2.0-SNAPSHOT/maven-metadata.xml

bdferris commented 11 years ago

Actually, it didn't update because the deadlock test failed on the CI server:

http://ci.onebusaway.org/job/onebusaway-gtfs-realtime-exporter/org.onebusaway$onebusaway-gtfs-realtime-exporter/32/testReport/junit/org.onebusaway.gtfs_realtime.exporter/DeadlockTest/testIncrementalFeed/

I will have to take a closer look tonight.

On Wed, Sep 25, 2013 at 2:18 PM, skywave notifications@github.com wrote:

Thanks, to make my life a bit easier could the version be bumped? Don't think the maven artifact got updated, http://nexus.onebusaway.org/content/groups/public/org/onebusaway/onebusaway-gtfs-realtime-exporter/1.2.0-SNAPSHOT/maven-metadata.xml

— Reply to this email directly or view it on GitHubhttps://github.com/OneBusAway/onebusaway-gtfs-realtime-exporter/issues/2#issuecomment-25081292 .

bdferris commented 11 years ago

Ok, this time, the build succeeded on the CI server. Give it a shot.

koch-t commented 11 years ago

The JVM still detects deadlocks but the rest seems to keeps working. It's definitely harder to replicate the old issue, now it's seems only my client starts giving hickups.

Did manage to crash the server by putting a simple client in a while loop that kept making new clients, maybe allow to set a max number of clients in the exporter and reject too many clients?

Found one Java-level deadlock:
=============================
"pool-4-thread-18":
  waiting to lock monitor 0x00007f7410809148 (object 0x000000078da73a60, a org.onebusaway.gtfs_realtime.exporter.GtfsRealtimeExporterImpl),
  which is held by "pool-4-thread-2"
"pool-4-thread-2":
  waiting to lock monitor 0x00007f741080c130 (object 0x00000007da6eb970, a org.onebusaway.gtfs_realtime.exporter.GtfsRealtimeServlet$DataWebSocket),
  which is held by "qtp871484051-57"
"qtp871484051-57":
  waiting to lock monitor 0x00007f7410807ee8 (object 0x00000007da6ec5b0, a org.eclipse.jetty.websocket.common.io.WriteBytesProvider),
  which is held by "qtp871484051-13-selector-0"
"qtp871484051-13-selector-0":
  waiting to lock monitor 0x00007f741080c130 (object 0x00000007da6eb970, a org.onebusaway.gtfs_realtime.exporter.GtfsRealtimeServlet$DataWebSocket),
  which is held by "qtp871484051-57"

Java stack information for the threads listed above:
===================================================
"pool-4-thread-18":
        at org.onebusaway.gtfs_realtime.exporter.GtfsRealtimeExporterImpl.handleIncrementalUpdate(GtfsRealtimeExporterImpl.java:83)
        - waiting to lock <0x000000078da73a60> (a org.onebusaway.gtfs_realtime.exporter.GtfsRealtimeExporterImpl)
        at nl.ovapi.rid.gtfsrt.services.BisonToGtfsRealtimeService$ProcessKV6Task.run(BisonToGtfsRealtimeService.java:505)
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
        at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:334)
        at java.util.concurrent.FutureTask.run(FutureTask.java:166)
        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:722)
"pool-4-thread-2":
        at org.onebusaway.gtfs_realtime.exporter.GtfsRealtimeServlet$DataWebSocket.sendMessage(GtfsRealtimeServlet.java:173)
        - waiting to lock <0x00000007da6eb970> (a org.onebusaway.gtfs_realtime.exporter.GtfsRealtimeServlet$DataWebSocket)
        at org.onebusaway.gtfs_realtime.exporter.GtfsRealtimeServlet$DataWebSocket.handleFeed(GtfsRealtimeServlet.java:169)
        at org.onebusaway.gtfs_realtime.exporter.GtfsRealtimeExporterImpl.handleIncrementalUpdate(GtfsRealtimeExporterImpl.java:104)
        - locked <0x000000078da73a60> (a org.onebusaway.gtfs_realtime.exporter.GtfsRealtimeExporterImpl)
        at nl.ovapi.rid.gtfsrt.services.BisonToGtfsRealtimeService$ProcessKV6Task.run(BisonToGtfsRealtimeService.java:505)
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
        at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:334)
        at java.util.concurrent.FutureTask.run(FutureTask.java:166)
        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:722)
"qtp871484051-57":
        at org.eclipse.jetty.websocket.common.io.WriteBytesProvider.enqueue(WriteBytesProvider.java:127)
        - waiting to lock <0x00000007da6ec5b0> (a org.eclipse.jetty.websocket.common.io.WriteBytesProvider)
        at org.eclipse.jetty.websocket.common.io.AbstractWebSocketConnection.outgoingFrame(AbstractWebSocketConnection.java:538)
        at org.eclipse.jetty.websocket.common.io.AbstractWebSocketConnection.onConnectionStateChange(AbstractWebSocketConnection.java:458)
        at org.eclipse.jetty.websocket.common.io.IOState.notifyStateListeners(IOState.java:145)
        at org.eclipse.jetty.websocket.common.io.IOState.onCloseLocal(IOState.java:236)
        at org.eclipse.jetty.websocket.common.io.AbstractWebSocketConnection.enqueClose(AbstractWebSocketConnection.java:288)
        at org.eclipse.jetty.websocket.common.io.AbstractWebSocketConnection.close(AbstractWebSocketConnection.java:229)
        at org.eclipse.jetty.websocket.common.WebSocketSession.close(WebSocketSession.java:119)
        at org.eclipse.jetty.websocket.common.WebSocketSession.close(WebSocketSession.java:107)
        at org.onebusaway.gtfs_realtime.exporter.GtfsRealtimeServlet$DataWebSocket.sendMessage(GtfsRealtimeServlet.java:188)
        - locked <0x00000007da6eb970> (a org.onebusaway.gtfs_realtime.exporter.GtfsRealtimeServlet$DataWebSocket)
        at org.onebusaway.gtfs_realtime.exporter.GtfsRealtimeServlet$DataWebSocket.handleFeed(GtfsRealtimeServlet.java:169)
        at org.onebusaway.gtfs_realtime.exporter.GtfsRealtimeExporterImpl.addIncrementalListener(GtfsRealtimeExporterImpl.java:137)
        at org.onebusaway.gtfs_realtime.exporter.GtfsRealtimeServlet$DataWebSocket.onOpen(GtfsRealtimeServlet.java:142)
        at sun.reflect.GeneratedMethodAccessor42.invoke(Unknown Source)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at java.lang.reflect.Method.invoke(Method.java:601)
        at org.eclipse.jetty.websocket.common.events.EventMethod.call(EventMethod.java:102)
        at org.eclipse.jetty.websocket.common.events.AnnotatedEventDriver.onConnect(AnnotatedEventDriver.java:125)
        at org.eclipse.jetty.websocket.common.events.EventDriver.openSession(EventDriver.java:168)
        at org.eclipse.jetty.websocket.common.WebSocketSession.open(WebSocketSession.java:382)
        at org.eclipse.jetty.websocket.server.WebSocketServerFactory.sessionOpened(WebSocketServerFactory.java:351)
        at org.eclipse.jetty.websocket.server.WebSocketServerConnection.onOpen(WebSocketServerConnection.java:74)
        at org.eclipse.jetty.server.HttpConnection.completed(HttpConnection.java:376)
        at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:335)
        at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:229)
        at org.eclipse.jetty.io.AbstractConnection$ReadCallback.run(AbstractConnection.java:358)
        at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:601)
        at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:532)
        at java.lang.Thread.run(Thread.java:722)
"qtp871484051-13-selector-0":
        at org.onebusaway.gtfs_realtime.exporter.GtfsRealtimeServlet$DataWebSocket.onClose(GtfsRealtimeServlet.java:150)
        - waiting to lock <0x00000007da6eb970> (a org.onebusaway.gtfs_realtime.exporter.GtfsRealtimeServlet$DataWebSocket)
        at sun.reflect.GeneratedMethodAccessor43.invoke(Unknown Source)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at java.lang.reflect.Method.invoke(Method.java:601)
        at org.eclipse.jetty.websocket.common.events.EventMethod.call(EventMethod.java:102)
        at org.eclipse.jetty.websocket.common.events.AnnotatedEventDriver.onClose(AnnotatedEventDriver.java:116)
        at org.eclipse.jetty.websocket.common.WebSocketSession.notifyClose(WebSocketSession.java:341)
        at org.eclipse.jetty.websocket.common.io.AbstractWebSocketConnection$FlushCallback.failed(AbstractWebSocketConnection.java:100)
        at org.eclipse.jetty.websocket.common.io.WriteBytesProvider.failAll(WriteBytesProvider.java:191)
        - locked <0x00000007da6ec5b0> (a org.eclipse.jetty.websocket.common.io.WriteBytesProvider)
        at org.eclipse.jetty.websocket.common.io.WriteBytesProvider.failed(WriteBytesProvider.java:207)
        at org.eclipse.jetty.io.WriteFlusher$PendingState.fail(WriteFlusher.java:259)
        at org.eclipse.jetty.io.WriteFlusher.completeWrite(WriteFlusher.java:427)
        at org.eclipse.jetty.io.SelectChannelEndPoint.onSelected(SelectChannelEndPoint.java:111)
        at org.eclipse.jetty.io.SelectorManager$ManagedSelector.processKey(SelectorManager.java:498)
        at org.eclipse.jetty.io.SelectorManager$ManagedSelector.select(SelectorManager.java:455)
        at org.eclipse.jetty.io.SelectorManager$ManagedSelector.run(SelectorManager.java:420)
        at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:601)
        at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:532)
        at java.lang.Thread.run(Thread.java:722)

Found one Java-level deadlock:
=============================
"qtp871484051-61":
  waiting to lock monitor 0x00007f741080cbb0 (object 0x00000007d9cd1fb8, a org.eclipse.jetty.websocket.common.io.WriteBytesProvider),
  which is held by "qtp871484051-15-selector-7"
"qtp871484051-15-selector-7":
  waiting to lock monitor 0x0000000000ab7078 (object 0x00000007d9cd1378, a org.onebusaway.gtfs_realtime.exporter.GtfsRealtimeServlet$DataWebSocket),
  which is held by "qtp871484051-61"

Java stack information for the threads listed above:
===================================================
"qtp871484051-61":
        at org.eclipse.jetty.websocket.common.io.WriteBytesProvider.enqueue(WriteBytesProvider.java:127)
        - waiting to lock <0x00000007d9cd1fb8> (a org.eclipse.jetty.websocket.common.io.WriteBytesProvider)
        at org.eclipse.jetty.websocket.common.io.AbstractWebSocketConnection.outgoingFrame(AbstractWebSocketConnection.java:538)
        at org.eclipse.jetty.websocket.common.io.AbstractWebSocketConnection.onConnectionStateChange(AbstractWebSocketConnection.java:458)
        at org.eclipse.jetty.websocket.common.io.IOState.notifyStateListeners(IOState.java:145)
        at org.eclipse.jetty.websocket.common.io.IOState.onCloseLocal(IOState.java:236)
        at org.eclipse.jetty.websocket.common.io.AbstractWebSocketConnection.enqueClose(AbstractWebSocketConnection.java:288)
        at org.eclipse.jetty.websocket.common.io.AbstractWebSocketConnection.close(AbstractWebSocketConnection.java:229)
        at org.eclipse.jetty.websocket.common.WebSocketSession.close(WebSocketSession.java:119)
        at org.eclipse.jetty.websocket.common.WebSocketSession.close(WebSocketSession.java:107)
        at org.onebusaway.gtfs_realtime.exporter.GtfsRealtimeServlet$DataWebSocket.sendMessage(GtfsRealtimeServlet.java:188)
        - locked <0x00000007d9cd1378> (a org.onebusaway.gtfs_realtime.exporter.GtfsRealtimeServlet$DataWebSocket)
        at org.onebusaway.gtfs_realtime.exporter.GtfsRealtimeServlet$DataWebSocket.handleFeed(GtfsRealtimeServlet.java:169)
        at org.onebusaway.gtfs_realtime.exporter.GtfsRealtimeExporterImpl.addIncrementalListener(GtfsRealtimeExporterImpl.java:137)
        at org.onebusaway.gtfs_realtime.exporter.GtfsRealtimeServlet$DataWebSocket.onOpen(GtfsRealtimeServlet.java:142)
        at sun.reflect.GeneratedMethodAccessor42.invoke(Unknown Source)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at java.lang.reflect.Method.invoke(Method.java:601)
        at org.eclipse.jetty.websocket.common.events.EventMethod.call(EventMethod.java:102)
        at org.eclipse.jetty.websocket.common.events.AnnotatedEventDriver.onConnect(AnnotatedEventDriver.java:125)
        at org.eclipse.jetty.websocket.common.events.EventDriver.openSession(EventDriver.java:168)
        at org.eclipse.jetty.websocket.common.WebSocketSession.open(WebSocketSession.java:382)
        at org.eclipse.jetty.websocket.server.WebSocketServerFactory.sessionOpened(WebSocketServerFactory.java:351)
        at org.eclipse.jetty.websocket.server.WebSocketServerConnection.onOpen(WebSocketServerConnection.java:74)
        at org.eclipse.jetty.server.HttpConnection.completed(HttpConnection.java:376)
        at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:335)
        at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:229)
        at org.eclipse.jetty.io.AbstractConnection$ReadCallback.run(AbstractConnection.java:358)
        at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:601)
        at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:532)
        at java.lang.Thread.run(Thread.java:722)
"qtp871484051-15-selector-7":
        at org.onebusaway.gtfs_realtime.exporter.GtfsRealtimeServlet$DataWebSocket.onClose(GtfsRealtimeServlet.java:150)
        - waiting to lock <0x00000007d9cd1378> (a org.onebusaway.gtfs_realtime.exporter.GtfsRealtimeServlet$DataWebSocket)
        at sun.reflect.GeneratedMethodAccessor43.invoke(Unknown Source)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at java.lang.reflect.Method.invoke(Method.java:601)
        at org.eclipse.jetty.websocket.common.events.EventMethod.call(EventMethod.java:102)
        at org.eclipse.jetty.websocket.common.events.AnnotatedEventDriver.onClose(AnnotatedEventDriver.java:116)
        at org.eclipse.jetty.websocket.common.WebSocketSession.notifyClose(WebSocketSession.java:341)
        at org.eclipse.jetty.websocket.common.io.AbstractWebSocketConnection$FlushCallback.failed(AbstractWebSocketConnection.java:100)
        at org.eclipse.jetty.websocket.common.io.WriteBytesProvider.failAll(WriteBytesProvider.java:191)
        - locked <0x00000007d9cd1fb8> (a org.eclipse.jetty.websocket.common.io.WriteBytesProvider)
        at org.eclipse.jetty.websocket.common.io.WriteBytesProvider.failed(WriteBytesProvider.java:207)
        at org.eclipse.jetty.io.WriteFlusher$PendingState.fail(WriteFlusher.java:259)
        at org.eclipse.jetty.io.WriteFlusher.completeWrite(WriteFlusher.java:427)
        at org.eclipse.jetty.io.SelectChannelEndPoint.onSelected(SelectChannelEndPoint.java:111)
        at org.eclipse.jetty.io.SelectorManager$ManagedSelector.processKey(SelectorManager.java:498)
        at org.eclipse.jetty.io.SelectorManager$ManagedSelector.select(SelectorManager.java:455)
        at org.eclipse.jetty.io.SelectorManager$ManagedSelector.run(SelectorManager.java:420)
        at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:601)
        at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:532)
        at java.lang.Thread.run(Thread.java:722)

Found one Java-level deadlock:
=============================
"qtp871484051-60":
  waiting to lock monitor 0x00007f741080c910 (object 0x00000007d9f33a38, a org.eclipse.jetty.websocket.common.io.WriteBytesProvider),
  which is held by "qtp871484051-20-selector-6"
"qtp871484051-20-selector-6":
  waiting to lock monitor 0x00007f7410809490 (object 0x00000007d9f32df8, a org.onebusaway.gtfs_realtime.exporter.GtfsRealtimeServlet$DataWebSocket),
  which is held by "qtp871484051-60"

Java stack information for the threads listed above:
===================================================
"qtp871484051-60":
        at org.eclipse.jetty.websocket.common.io.WriteBytesProvider.enqueue(WriteBytesProvider.java:127)
        - waiting to lock <0x00000007d9f33a38> (a org.eclipse.jetty.websocket.common.io.WriteBytesProvider)
        at org.eclipse.jetty.websocket.common.io.AbstractWebSocketConnection.outgoingFrame(AbstractWebSocketConnection.java:538)
        at org.eclipse.jetty.websocket.common.io.AbstractWebSocketConnection.onConnectionStateChange(AbstractWebSocketConnection.java:458)
        at org.eclipse.jetty.websocket.common.io.IOState.notifyStateListeners(IOState.java:145)
        at org.eclipse.jetty.websocket.common.io.IOState.onCloseLocal(IOState.java:236)
        at org.eclipse.jetty.websocket.common.io.AbstractWebSocketConnection.enqueClose(AbstractWebSocketConnection.java:288)
        at org.eclipse.jetty.websocket.common.io.AbstractWebSocketConnection.close(AbstractWebSocketConnection.java:229)
        at org.eclipse.jetty.websocket.common.WebSocketSession.close(WebSocketSession.java:119)
        at org.eclipse.jetty.websocket.common.WebSocketSession.close(WebSocketSession.java:107)
        at org.onebusaway.gtfs_realtime.exporter.GtfsRealtimeServlet$DataWebSocket.sendMessage(GtfsRealtimeServlet.java:188)
        - locked <0x00000007d9f32df8> (a org.onebusaway.gtfs_realtime.exporter.GtfsRealtimeServlet$DataWebSocket)
        at org.onebusaway.gtfs_realtime.exporter.GtfsRealtimeServlet$DataWebSocket.handleFeed(GtfsRealtimeServlet.java:169)
        at org.onebusaway.gtfs_realtime.exporter.GtfsRealtimeExporterImpl.addIncrementalListener(GtfsRealtimeExporterImpl.java:137)
        at org.onebusaway.gtfs_realtime.exporter.GtfsRealtimeServlet$DataWebSocket.onOpen(GtfsRealtimeServlet.java:142)
        at sun.reflect.GeneratedMethodAccessor42.invoke(Unknown Source)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at java.lang.reflect.Method.invoke(Method.java:601)
        at org.eclipse.jetty.websocket.common.events.EventMethod.call(EventMethod.java:102)
        at org.eclipse.jetty.websocket.common.events.AnnotatedEventDriver.onConnect(AnnotatedEventDriver.java:125)
        at org.eclipse.jetty.websocket.common.events.EventDriver.openSession(EventDriver.java:168)
        at org.eclipse.jetty.websocket.common.WebSocketSession.open(WebSocketSession.java:382)
        at org.eclipse.jetty.websocket.server.WebSocketServerFactory.sessionOpened(WebSocketServerFactory.java:351)
        at org.eclipse.jetty.websocket.server.WebSocketServerConnection.onOpen(WebSocketServerConnection.java:74)
        at org.eclipse.jetty.server.HttpConnection.completed(HttpConnection.java:376)
        at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:335)
        at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:229)
        at org.eclipse.jetty.io.AbstractConnection$ReadCallback.run(AbstractConnection.java:358)
        at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:601)
        at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:532)
        at java.lang.Thread.run(Thread.java:722)
"qtp871484051-20-selector-6":
        at org.onebusaway.gtfs_realtime.exporter.GtfsRealtimeServlet$DataWebSocket.onClose(GtfsRealtimeServlet.java:150)
        - waiting to lock <0x00000007d9f32df8> (a org.onebusaway.gtfs_realtime.exporter.GtfsRealtimeServlet$DataWebSocket)
        at sun.reflect.GeneratedMethodAccessor43.invoke(Unknown Source)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at java.lang.reflect.Method.invoke(Method.java:601)
        at org.eclipse.jetty.websocket.common.events.EventMethod.call(EventMethod.java:102)
        at org.eclipse.jetty.websocket.common.events.AnnotatedEventDriver.onClose(AnnotatedEventDriver.java:116)
        at org.eclipse.jetty.websocket.common.WebSocketSession.notifyClose(WebSocketSession.java:341)
        at org.eclipse.jetty.websocket.common.io.AbstractWebSocketConnection$FlushCallback.failed(AbstractWebSocketConnection.java:100)
        at org.eclipse.jetty.websocket.common.io.WriteBytesProvider.failAll(WriteBytesProvider.java:191)
        - locked <0x00000007d9f33a38> (a org.eclipse.jetty.websocket.common.io.WriteBytesProvider)
        at org.eclipse.jetty.websocket.common.io.WriteBytesProvider.failed(WriteBytesProvider.java:207)
        at org.eclipse.jetty.io.WriteFlusher$PendingState.fail(WriteFlusher.java:259)
        at org.eclipse.jetty.io.WriteFlusher.completeWrite(WriteFlusher.java:427)
        at org.eclipse.jetty.io.SelectChannelEndPoint.onSelected(SelectChannelEndPoint.java:111)
        at org.eclipse.jetty.io.SelectorManager$ManagedSelector.processKey(SelectorManager.java:498)
        at org.eclipse.jetty.io.SelectorManager$ManagedSelector.select(SelectorManager.java:455)
        at org.eclipse.jetty.io.SelectorManager$ManagedSelector.run(SelectorManager.java:420)
        at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:601)
        at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:532)
        at java.lang.Thread.run(Thread.java:722)

Found 3 deadlocks.

Heap
 PSYoungGen      total 396928K, used 120111K [0x00000007d5560000, 0x0000000800000000, 0x0000000800000000)
  eden space 233088K, 41% used [0x00000007d5560000,0x00000007db3b07d0,0x00000007e3900000)
  from space 163840K, 14% used [0x00000007f6000000,0x00000007f76fb450,0x0000000800000000)
  to   space 232960K, 0% used [0x00000007e3900000,0x00000007e3900000,0x00000007f1c80000)
 ParOldGen       total 671680K, used 411158K [0x0000000780000000, 0x00000007a8ff0000, 0x00000007d5560000)
  object space 671680K, 61% used [0x0000000780000000,0x00000007991858f8,0x00000007a8ff0000)
 PSPermGen       total 25024K, used 18281K [0x0000000775a00000, 0x0000000777270000, 0x0000000780000000)
  object space 25024K, 73% used [0x0000000775a00000,0x0000000776bda460,0x0000000777270000)

Second attempt


Found one Java-level deadlock:
=============================
"qtp871484051-53":
  waiting to lock monitor 0x0000000000a45ab0 (object 0x00000007df3b2bd0, a org.eclipse.jetty.websocket.common.io.WriteBytesProvider),
  which is held by "qtp871484051-20-selector-5"
"qtp871484051-20-selector-5":
  waiting to lock monitor 0x0000000000a44e38 (object 0x00000007df3b1f90, a org.onebusaway.gtfs_realtime.exporter.GtfsRealtimeServlet$DataWebSocket),
  which is held by "qtp871484051-53"

Java stack information for the threads listed above:
===================================================
"qtp871484051-53":
        at org.eclipse.jetty.websocket.common.io.WriteBytesProvider.enqueue(WriteBytesProvider.java:127)
        - waiting to lock <0x00000007df3b2bd0> (a org.eclipse.jetty.websocket.common.io.WriteBytesProvider)
        at org.eclipse.jetty.websocket.common.io.AbstractWebSocketConnection.outgoingFrame(AbstractWebSocketConnection.java:538)
        at org.eclipse.jetty.websocket.common.io.AbstractWebSocketConnection.onConnectionStateChange(AbstractWebSocketConnection.java:458)
        at org.eclipse.jetty.websocket.common.io.IOState.notifyStateListeners(IOState.java:145)
        at org.eclipse.jetty.websocket.common.io.IOState.onCloseLocal(IOState.java:236)
        at org.eclipse.jetty.websocket.common.io.AbstractWebSocketConnection.enqueClose(AbstractWebSocketConnection.java:288)
        at org.eclipse.jetty.websocket.common.io.AbstractWebSocketConnection.close(AbstractWebSocketConnection.java:229)
        at org.eclipse.jetty.websocket.common.WebSocketSession.close(WebSocketSession.java:119)
        at org.eclipse.jetty.websocket.common.WebSocketSession.close(WebSocketSession.java:107)
        at org.onebusaway.gtfs_realtime.exporter.GtfsRealtimeServlet$DataWebSocket.sendMessage(GtfsRealtimeServlet.java:188)
        - locked <0x00000007df3b1f90> (a org.onebusaway.gtfs_realtime.exporter.GtfsRealtimeServlet$DataWebSocket)
        at org.onebusaway.gtfs_realtime.exporter.GtfsRealtimeServlet$DataWebSocket.handleFeed(GtfsRealtimeServlet.java:169)
        at org.onebusaway.gtfs_realtime.exporter.GtfsRealtimeExporterImpl.addIncrementalListener(GtfsRealtimeExporterImpl.java:137)
        at org.onebusaway.gtfs_realtime.exporter.GtfsRealtimeServlet$DataWebSocket.onOpen(GtfsRealtimeServlet.java:142)
        at sun.reflect.GeneratedMethodAccessor42.invoke(Unknown Source)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at java.lang.reflect.Method.invoke(Method.java:601)
        at org.eclipse.jetty.websocket.common.events.EventMethod.call(EventMethod.java:102)
        at org.eclipse.jetty.websocket.common.events.AnnotatedEventDriver.onConnect(AnnotatedEventDriver.java:125)
        at org.eclipse.jetty.websocket.common.events.EventDriver.openSession(EventDriver.java:168)
        at org.eclipse.jetty.websocket.common.WebSocketSession.open(WebSocketSession.java:382)
        at org.eclipse.jetty.websocket.server.WebSocketServerFactory.sessionOpened(WebSocketServerFactory.java:351)
        at org.eclipse.jetty.websocket.server.WebSocketServerConnection.onOpen(WebSocketServerConnection.java:74)
        at org.eclipse.jetty.server.HttpConnection.completed(HttpConnection.java:376)
        at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:335)
        at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:229)
        at org.eclipse.jetty.io.AbstractConnection$ReadCallback.run(AbstractConnection.java:358)
        at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:601)
        at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:532)
        at java.lang.Thread.run(Thread.java:722)
"qtp871484051-20-selector-5":
        at org.onebusaway.gtfs_realtime.exporter.GtfsRealtimeServlet$DataWebSocket.onClose(GtfsRealtimeServlet.java:150)
        - waiting to lock <0x00000007df3b1f90> (a org.onebusaway.gtfs_realtime.exporter.GtfsRealtimeServlet$DataWebSocket)
        at sun.reflect.GeneratedMethodAccessor43.invoke(Unknown Source)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at java.lang.reflect.Method.invoke(Method.java:601)
        at org.eclipse.jetty.websocket.common.events.EventMethod.call(EventMethod.java:102)
        at org.eclipse.jetty.websocket.common.events.AnnotatedEventDriver.onClose(AnnotatedEventDriver.java:116)
        at org.eclipse.jetty.websocket.common.WebSocketSession.notifyClose(WebSocketSession.java:341)
        at org.eclipse.jetty.websocket.common.io.AbstractWebSocketConnection$FlushCallback.failed(AbstractWebSocketConnection.java:100)
        at org.eclipse.jetty.websocket.common.io.WriteBytesProvider.failAll(WriteBytesProvider.java:191)
        - locked <0x00000007df3b2bd0> (a org.eclipse.jetty.websocket.common.io.WriteBytesProvider)
        at org.eclipse.jetty.websocket.common.io.WriteBytesProvider.failed(WriteBytesProvider.java:207)
        at org.eclipse.jetty.io.WriteFlusher$PendingState.fail(WriteFlusher.java:259)
        at org.eclipse.jetty.io.WriteFlusher.completeWrite(WriteFlusher.java:427)
        at org.eclipse.jetty.io.SelectChannelEndPoint.onSelected(SelectChannelEndPoint.java:111)
        at org.eclipse.jetty.io.SelectorManager$ManagedSelector.processKey(SelectorManager.java:498)
        at org.eclipse.jetty.io.SelectorManager$ManagedSelector.select(SelectorManager.java:455)
        at org.eclipse.jetty.io.SelectorManager$ManagedSelector.run(SelectorManager.java:420)
        at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:601)
        at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:532)
        at java.lang.Thread.run(Thread.java:722)

Found one Java-level deadlock:
=============================
"qtp871484051-28":
  waiting to lock monitor 0x0000000000a41130 (object 0x00000007e0298be8, a org.eclipse.jetty.websocket.common.io.WriteBytesProvider),
  which is held by "qtp871484051-14-selector-6"
"qtp871484051-14-selector-6":
  waiting to lock monitor 0x00000000009b2db0 (object 0x00000007e0297fa8, a org.onebusaway.gtfs_realtime.exporter.GtfsRealtimeServlet$DataWebSocket),
  which is held by "qtp871484051-28"

Java stack information for the threads listed above:
===================================================
"qtp871484051-28":
        at org.eclipse.jetty.websocket.common.io.WriteBytesProvider.enqueue(WriteBytesProvider.java:127)
        - waiting to lock <0x00000007e0298be8> (a org.eclipse.jetty.websocket.common.io.WriteBytesProvider)
        at org.eclipse.jetty.websocket.common.io.AbstractWebSocketConnection.outgoingFrame(AbstractWebSocketConnection.java:538)
        at org.eclipse.jetty.websocket.common.io.AbstractWebSocketConnection.onConnectionStateChange(AbstractWebSocketConnection.java:458)
        at org.eclipse.jetty.websocket.common.io.IOState.notifyStateListeners(IOState.java:145)
        at org.eclipse.jetty.websocket.common.io.IOState.onCloseLocal(IOState.java:236)
        at org.eclipse.jetty.websocket.common.io.AbstractWebSocketConnection.enqueClose(AbstractWebSocketConnection.java:288)
        at org.eclipse.jetty.websocket.common.io.AbstractWebSocketConnection.close(AbstractWebSocketConnection.java:229)
        at org.eclipse.jetty.websocket.common.WebSocketSession.close(WebSocketSession.java:119)
        at org.eclipse.jetty.websocket.common.WebSocketSession.close(WebSocketSession.java:107)
        at org.onebusaway.gtfs_realtime.exporter.GtfsRealtimeServlet$DataWebSocket.sendMessage(GtfsRealtimeServlet.java:188)
        - locked <0x00000007e0297fa8> (a org.onebusaway.gtfs_realtime.exporter.GtfsRealtimeServlet$DataWebSocket)
        at org.onebusaway.gtfs_realtime.exporter.GtfsRealtimeServlet$DataWebSocket.handleFeed(GtfsRealtimeServlet.java:169)
        at org.onebusaway.gtfs_realtime.exporter.GtfsRealtimeExporterImpl.addIncrementalListener(GtfsRealtimeExporterImpl.java:137)
        at org.onebusaway.gtfs_realtime.exporter.GtfsRealtimeServlet$DataWebSocket.onOpen(GtfsRealtimeServlet.java:142)
        at sun.reflect.GeneratedMethodAccessor42.invoke(Unknown Source)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at java.lang.reflect.Method.invoke(Method.java:601)
        at org.eclipse.jetty.websocket.common.events.EventMethod.call(EventMethod.java:102)
        at org.eclipse.jetty.websocket.common.events.AnnotatedEventDriver.onConnect(AnnotatedEventDriver.java:125)
        at org.eclipse.jetty.websocket.common.events.EventDriver.openSession(EventDriver.java:168)
        at org.eclipse.jetty.websocket.common.WebSocketSession.open(WebSocketSession.java:382)
        at org.eclipse.jetty.websocket.server.WebSocketServerFactory.sessionOpened(WebSocketServerFactory.java:351)
        at org.eclipse.jetty.websocket.server.WebSocketServerConnection.onOpen(WebSocketServerConnection.java:74)
        at org.eclipse.jetty.server.HttpConnection.completed(HttpConnection.java:376)
        at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:335)
        at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:229)
        at org.eclipse.jetty.io.AbstractConnection$ReadCallback.run(AbstractConnection.java:358)
        at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:601)
        at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:532)
        at java.lang.Thread.run(Thread.java:722)
"qtp871484051-14-selector-6":
        at org.onebusaway.gtfs_realtime.exporter.GtfsRealtimeServlet$DataWebSocket.onClose(GtfsRealtimeServlet.java:150)
        - waiting to lock <0x00000007e0297fa8> (a org.onebusaway.gtfs_realtime.exporter.GtfsRealtimeServlet$DataWebSocket)
        at sun.reflect.GeneratedMethodAccessor43.invoke(Unknown Source)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at java.lang.reflect.Method.invoke(Method.java:601)
        at org.eclipse.jetty.websocket.common.events.EventMethod.call(EventMethod.java:102)
        at org.eclipse.jetty.websocket.common.events.AnnotatedEventDriver.onClose(AnnotatedEventDriver.java:116)
        at org.eclipse.jetty.websocket.common.WebSocketSession.notifyClose(WebSocketSession.java:341)
        at org.eclipse.jetty.websocket.common.io.AbstractWebSocketConnection$FlushCallback.failed(AbstractWebSocketConnection.java:100)
        at org.eclipse.jetty.websocket.common.io.WriteBytesProvider.failAll(WriteBytesProvider.java:191)
        - locked <0x00000007e0298be8> (a org.eclipse.jetty.websocket.common.io.WriteBytesProvider)
        at org.eclipse.jetty.websocket.common.io.WriteBytesProvider.failed(WriteBytesProvider.java:207)
        at org.eclipse.jetty.io.WriteFlusher$PendingState.fail(WriteFlusher.java:259)
        at org.eclipse.jetty.io.WriteFlusher.completeWrite(WriteFlusher.java:427)
        at org.eclipse.jetty.io.SelectChannelEndPoint.onSelected(SelectChannelEndPoint.java:111)
        at org.eclipse.jetty.io.SelectorManager$ManagedSelector.processKey(SelectorManager.java:498)
        at org.eclipse.jetty.io.SelectorManager$ManagedSelector.select(SelectorManager.java:455)
        at org.eclipse.jetty.io.SelectorManager$ManagedSelector.run(SelectorManager.java:420)
        at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:601)
        at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:532)
        at java.lang.Thread.run(Thread.java:722)

Found 2 deadlocks.
koch-t commented 11 years ago

Bad stuff still happens when a user leaves the connection without a disconnect.

koch-t commented 11 years ago

Oh and the DeadlockTest fails on my laptop.

bdferris commented 11 years ago

Any logging output you can provide would be super helpful ;)

On Fri, Sep 27, 2013 at 3:19 PM, skywave notifications@github.com wrote:

Oh and the DeadlockTest fails on my laptop.

— Reply to this email directly or view it on GitHubhttps://github.com/OneBusAway/onebusaway-gtfs-realtime-exporter/issues/2#issuecomment-25244279 .

koch-t commented 11 years ago

I know :) I was still doing some digging but having troubles with the onebusaway maven repo giving 503's. I actually wanted to do a completely clean run to avoid Maven troubles.

Pastebinn'ed as it's too long for github: http://pastebin.com/tgNL7sS9

If i take the _session = [null | session] out of the syncronized block and remove the synchronized block the test passes. Any idea why it was put in a synchronized block?

diff --git a/src/main/java/org/onebusaway/gtfs_realtime/exporter/GtfsRealtimeServlet.java b/src/main/java/org/onebusaway/gtfs_realtime/exporter/GtfsRealtimeS
index 7c0d433..e1a0a4a 100644
--- a/src/main/java/org/onebusaway/gtfs_realtime/exporter/GtfsRealtimeServlet.java
+++ b/src/main/java/org/onebusaway/gtfs_realtime/exporter/GtfsRealtimeServlet.java
@@ -131,9 +131,9 @@ public class GtfsRealtimeServlet extends WebSocketServlet implements
     @OnWebSocketConnect
     public void onOpen(Session session) {
       _log.info("client connect");
-      synchronized (this) {
+      //synchronized (this) {
         _session = session;
-      }
+      //}
       // When we add ourselves as an incremental listener to the
       // GtfsRealtimeSource, it typically triggers a "handleFeed" update
       // immediately. Thus, we don't want to call this until we've released the
@@ -146,9 +146,9 @@ public class GtfsRealtimeServlet extends WebSocketServlet implements
     public void onClose(Session sesion, int closeCode, String message) {
       _log.info("client close");
       _source.removeIncrementalListener(this);
-      synchronized (this) {
+      //synchronized (this) {
         _session = null;
-      }
+      //}
     }