Issue2457
Created on 2016-02-01.22:41:09 by nickmbailey, last changed 2016-02-11.20:26:09 by zyasoft.
Messages | |||
---|---|---|---|
msg10673 (view) | Author: Nick (nickmbailey) | Date: 2016-02-01.22:41:08 | |
There is an issue with the synchronization in PySystemStateCloser. It's synchronizing on the class object which is problematic because there will be many instances of that object and the synchronization lock will also need to be acquired during GC. I think we just need to switch to synchronizing on individual instances of the object. I have a script to demonstrate the issue here: https://gist.github.com/nickmbailey/979614eae0f9607616e9 I think the patch in that gist is required to make GC slow enough to see the issue or something like that. The script won't reproduce the issue until you add the patch. |
|||
msg10674 (view) | Author: Nick (nickmbailey) | Date: 2016-02-01.23:19:39 | |
I believe this pr fixes the issue: https://github.com/jythontools/jython/pull/30 |
|||
msg10675 (view) | Author: Stefan Richthofer (stefan.richthofer) | Date: 2016-02-02.00:47:08 | |
It looks like the proposed fix interferes with the fix (https://hg.python.org/jython/rev/f79dc13778f9) for Issue 2280 (http://bugs.jython.org/issue2280). An overall synchonization solution for this stuff is needed. However I did not yet investigate the details of this issue. Do you have jstack output available? (Once I find time for it I can try to produce this myself based on your script.) |
|||
msg10676 (view) | Author: Nick (nickmbailey) | Date: 2016-02-02.01:31:10 | |
Here's the jstack. The full output is rather large since the script creates 60ish threads but the deadlock is at the end so I've just included that. Found one Java-level deadlock: ============================= "Thread-80717": waiting to lock monitor 0x00007fd8e6041c28 (object 0x00000006c0fa89b0, a java.lang.Class), which is held by "MainThread" "MainThread": waiting to lock monitor 0x00007fd8e2b39b28 (object 0x000000079c93fcd8, a org.python.modules._io.Closer), which is held by "Thread-80671" "Thread-80671": waiting to lock monitor 0x00007fd8e6041c28 (object 0x00000006c0fa89b0, a java.lang.Class), which is held by "MainThread" Java stack information for the threads listed above: =================================================== "Thread-80717": at org.python.core.PySystemState$PySystemStateCloser.registerCloser(PySystemState.java:1531) - waiting to lock <0x00000006c0fa89b0> (a java.lang.Class for org.python.core.PySystemState$PySystemStateCloser) at org.python.core.PySystemState$PySystemStateCloser.access$100(PySystemState.java:1508) at org.python.core.PySystemState.registerCloser(PySystemState.java:1495) at org.python.modules._io.Closer.<init>(Closer.java:38) at org.python.modules._io.PyIOBase.<init>(PyIOBase.java:59) at org.python.modules._io.PyIOBase.<init>(PyIOBase.java:53) at org.python.modules._io.PyIOBase._IOBase___new__(PyIOBase.java:80) at org.python.modules._io.PyIOBase$exposed___new__.new_impl(Unknown Source) at org.python.core.PyType.invokeNew(PyType.java:494) at org.python.core.PyType.type___call__(PyType.java:1708) at org.python.core.PyType.__call__(PyType.java:1698) at org.python.core.PyObject.__call__(PyObject.java:464) at org.python.core.PyObject.__call__(PyObject.java:468) at org.python.pycode._pyx0.create_gc$1(repro.py:9) at org.python.pycode._pyx0.call_function(repro.py) at org.python.core.PyTableCode.call(PyTableCode.java:167) at org.python.core.PyBaseCode.call(PyBaseCode.java:308) at org.python.core.PyFunction.function___call__(PyFunction.java:471) at org.python.core.PyFunction.__call__(PyFunction.java:466) at org.python.core.PyFunction.__call__(PyFunction.java:461) at org.python.core.PyObject._callextra(PyObject.java:620) at threading$py.run$52(/Users/nick/workspace/git/jython/dist/Lib/threading.py:361) at threading$py.call_function(/Users/nick/workspace/git/jython/dist/Lib/threading.py) at org.python.core.PyTableCode.call(PyTableCode.java:167) at org.python.core.PyBaseCode.call(PyBaseCode.java:139) at org.python.core.PyFunction.__call__(PyFunction.java:413) at org.python.core.PyMethod.__call__(PyMethod.java:126) at threading$py._Thread__bootstrap$36(/Users/nick/workspace/git/jython/dist/Lib/threading.py:266) at threading$py.call_function(/Users/nick/workspace/git/jython/dist/Lib/threading.py) at org.python.core.PyTableCode.call(PyTableCode.java:167) at org.python.core.PyBaseCode.call(PyBaseCode.java:308) at org.python.core.PyBaseCode.call(PyBaseCode.java:199) at org.python.core.PyFunction.__call__(PyFunction.java:482) at org.python.core.PyMethod.instancemethod___call__(PyMethod.java:237) at org.python.core.PyMethod.__call__(PyMethod.java:228) at org.python.core.PyMethod.__call__(PyMethod.java:218) at org.python.core.PyMethod.__call__(PyMethod.java:213) at org.python.core.FunctionThread.run(FunctionThread.java:25) "MainThread": at org.python.modules._io.Closer.call(Closer.java:58) - waiting to lock <0x000000079c93fcd8> (a org.python.modules._io.Closer) at org.python.modules._io.Closer.call(Closer.java:27) at org.python.core.PySystemState$PySystemStateCloser.runClosers(PySystemState.java:1584) - locked <0x00000006c0fa89b0> (a java.lang.Class for org.python.core.PySystemState$PySystemStateCloser) at org.python.core.PySystemState$PySystemStateCloser.cleanup(PySystemState.java:1562) - locked <0x00000006c0fa89b0> (a java.lang.Class for org.python.core.PySystemState$PySystemStateCloser) - locked <0x00000006c0f59f18> (a org.python.core.PySystemState$PySystemStateCloser) at org.python.core.PySystemState$PySystemStateCloser.access$300(PySystemState.java:1508) at org.python.core.PySystemState.cleanup(PySystemState.java:1503) at org.python.util.PythonInterpreter.cleanup(PythonInterpreter.java:409) at org.python.util.jython.run(jython.java:426) at org.python.util.jython.main(jython.java:142) "Thread-80671": at org.python.core.PySystemState$PySystemStateCloser.unregisterCloser(PySystemState.java:1539) - waiting to lock <0x00000006c0fa89b0> (a java.lang.Class for org.python.core.PySystemState$PySystemStateCloser) at org.python.core.PySystemState$PySystemStateCloser.access$200(PySystemState.java:1508) at org.python.core.PySystemState.unregisterCloser(PySystemState.java:1499) at org.python.modules._io.Closer.dismiss(Closer.java:47) - locked <0x000000079c93fcd8> (a org.python.modules._io.Closer) at org.python.modules._io.PyIOBase._IOBase_close(PyIOBase.java:233) at org.python.modules._io.PyIOBase$_IOBase_close_exposer.__call__(Unknown Source) at org.python.core.PyObject.__call__(PyObject.java:468) at org.python.pycode._pyx0.call_close$2(repro.py:16) at org.python.pycode._pyx0.call_function(repro.py) at org.python.core.PyTableCode.call(PyTableCode.java:167) at org.python.core.PyBaseCode.call(PyBaseCode.java:308) at org.python.core.PyFunction.function___call__(PyFunction.java:471) at org.python.core.PyFunction.__call__(PyFunction.java:466) at org.python.core.PyFunction.__call__(PyFunction.java:461) at org.python.core.PyObject._callextra(PyObject.java:620) at threading$py.run$52(/Users/nick/workspace/git/jython/dist/Lib/threading.py:361) at threading$py.call_function(/Users/nick/workspace/git/jython/dist/Lib/threading.py) at org.python.core.PyTableCode.call(PyTableCode.java:167) at org.python.core.PyBaseCode.call(PyBaseCode.java:139) at org.python.core.PyFunction.__call__(PyFunction.java:413) at org.python.core.PyMethod.__call__(PyMethod.java:126) at threading$py._Thread__bootstrap$36(/Users/nick/workspace/git/jython/dist/Lib/threading.py:266) at threading$py.call_function(/Users/nick/workspace/git/jython/dist/Lib/threading.py) at org.python.core.PyTableCode.call(PyTableCode.java:167) at org.python.core.PyBaseCode.call(PyBaseCode.java:308) at org.python.core.PyBaseCode.call(PyBaseCode.java:199) at org.python.core.PyFunction.__call__(PyFunction.java:482) at org.python.core.PyMethod.instancemethod___call__(PyMethod.java:237) at org.python.core.PyMethod.__call__(PyMethod.java:228) at org.python.core.PyMethod.__call__(PyMethod.java:218) at org.python.core.PyMethod.__call__(PyMethod.java:213) at org.python.core.FunctionThread.run(FunctionThread.java:25) Found 1 deadlock. |
|||
msg10681 (view) | Author: Jim Baker (zyasoft) | Date: 2016-02-02.03:53:57 | |
Handing it to Stefan, but I would like to review before we decide. I'm hoping we can get this in for the RC. We need to wrap beta 3, which should be the case now with the latest changes. |
|||
msg10683 (view) | Author: Stefan Richthofer (stefan.richthofer) | Date: 2016-02-02.05:28:28 | |
This can likely be fixed by adjusting org.python.modules._io.Closer a bit (see our discussion at https://github.com/jythontools/jython/pull/30): AtomicBoolean dismissed = new AtomicBoolean(); public void dismiss() { if (dismissed.compareAndSet(false, true)) sys.unregisterCloser(this); } public synchronized Void call() { if (dismissed.compareAndSet(false, true)) { ... } } Note that dismiss does not need to be synchronized any more, still maintaining the old behavior. If Nick can confirm that this solves the issue, we can maybe get it already into beta 3 right now. Later we should add a note to documentation of PySystemState.registerCloser and related API that Callable-implementors must not introduce their own locks because of deadlock risk. They rather should lock on PySystemStateCloser.class or use non-blocking locks like this AtomicBoolean variant. However I'd add this doc-stuff later for the RC. |
|||
msg10684 (view) | Author: Nick (nickmbailey) | Date: 2016-02-02.05:39:11 | |
I can confirm that the following patch also appears to fix the issue. diff --git a/src/org/python/modules/_io/Closer.java b/src/org/python/modules/_io/Closer.java index 3aec84f..d4a8a8e 100644 --- a/src/org/python/modules/_io/Closer.java +++ b/src/org/python/modules/_io/Closer.java @@ -3,6 +3,7 @@ package org.python.modules._io; import java.lang.ref.WeakReference; import java.util.concurrent.Callable; +import java.util.concurrent.atomic.AtomicBoolean; import org.python.core.PyObject; import org.python.core.PySystemState; @@ -32,9 +33,12 @@ class Closer<C extends PyIOBase> implements Callable<Void> { /** Interpreter state that will call {@link #call()} on shutdown. */ protected PySystemState sys; + private AtomicBoolean dismissed; + public Closer(C toClose, PySystemState sys) { this.client = new WeakReference<C>(toClose); this.sys = sys; + this.dismissed = new AtomicBoolean(false); sys.registerCloser(this); } @@ -42,10 +46,9 @@ class Closer<C extends PyIOBase> implements Callable<Void> { * Tell the Closer that its services are no longer required. This unhooks it from the shutdown * list. Repeated calls are allowed but only the first has any effect. */ - public synchronized void dismiss() { - if (sys != null) { + public void dismiss() { + if (dismissed.compareAndSet(false, true)) { sys.unregisterCloser(this); - sys = null; } } @@ -55,9 +58,8 @@ class Closer<C extends PyIOBase> implements Callable<Void> { */ @Override public synchronized Void call() { - if (sys != null) { + if (dismissed.compareAndSet(false, true)) { // This will prevent repeated work and dismiss() manipulating the list of closers - sys = null; // Call close on the client (if it still exists) C toClose = client.get(); if (toClose != null) { @@ -66,4 +68,4 @@ class Closer<C extends PyIOBase> implements Callable<Void> { } return null; } -} \ No newline at end of file +} |
|||
msg10685 (view) | Author: Stefan Richthofer (stefan.richthofer) | Date: 2016-02-02.05:50:25 | |
Nice! I will do another regression test run with this and if Jim has no concerns merge it into the repository. I must leave now, but can get back to this in early afternoon, so it should hopefully be still in time for beta3. |
|||
msg10686 (view) | Author: Stefan Richthofer (stefan.richthofer) | Date: 2016-02-02.05:58:54 | |
I think we can also remove 'synchronized' from 'call' then or do I overlook something? With the atomic boolean only one thread can ever enter the if-block and perform toClose.invoke. Also, it seems no other code locks on _io.Closer.class, does it? |
|||
msg10687 (view) | Author: Nick (nickmbailey) | Date: 2016-02-02.06:00:06 | |
Oh yeah, good point. That works as well. |
|||
msg10696 (view) | Author: Jim Baker (zyasoft) | Date: 2016-02-02.17:24:56 | |
+1 with the combined solution, makes perfect sense to me |
|||
msg10698 (view) | Author: Stefan Richthofer (stefan.richthofer) | Date: 2016-02-02.23:13:04 | |
I applied the bare fix so far to have it in quickly. It passes regrtests for me and there is no reason to assume a problem with it. Remaining todo is adding doc to PySystemStateCloser API warning about deadlocks. It is sufficient to get this done for RC. |
|||
msg10704 (view) | Author: Nick (nickmbailey) | Date: 2016-02-03.19:47:43 | |
Unfortunately there is still an issue here somewhere. The fix seems to solve the reproduction script I posted earlier, but I'm still getting deadlocks in my application. Here is the stack dump I'm seeing now: 2016-02-03 13:44:37 Full thread dump Java HotSpot(TM) 64-Bit Server VM (25.45-b02 mixed mode): "Attach Listener" #109 daemon prio=9 os_prio=31 tid=0x00007f80b3800000 nid=0x7603 waiting on condition [0x0000000000000000] java.lang.Thread.State: RUNNABLE "Jython-Netty-Child-49" #68 daemon prio=5 os_prio=31 tid=0x00007f80b1150000 nid=0x7403 runnable [0x0000700002733000] java.lang.Thread.State: RUNNABLE at sun.nio.ch.KQueueArrayWrapper.kevent0(Native Method) at sun.nio.ch.KQueueArrayWrapper.poll(KQueueArrayWrapper.java:198) at sun.nio.ch.KQueueSelectorImpl.doSelect(KQueueSelectorImpl.java:103) at sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:86) - locked <0x0000000795377508> (a org.python.netty.channel.nio.SelectedSelectionKeySet) - locked <0x00000007953795d8> (a java.util.Collections$UnmodifiableSet) - locked <0x00000007953773f8> (a sun.nio.ch.KQueueSelectorImpl) at sun.nio.ch.SelectorImpl.select(SelectorImpl.java:97) at org.python.netty.channel.nio.NioEventLoop.select(NioEventLoop.java:622) at org.python.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:310) at org.python.netty.util.concurrent.SingleThreadEventExecutor$2.run(SingleThreadEventExecutor.java:112) at java.lang.Thread.run(Thread.java:745) "Jython-Netty-Child-48" #67 daemon prio=5 os_prio=31 tid=0x00007f80b19c6800 nid=0x7203 runnable [0x0000700002630000] java.lang.Thread.State: RUNNABLE at sun.nio.ch.KQueueArrayWrapper.kevent0(Native Method) at sun.nio.ch.KQueueArrayWrapper.poll(KQueueArrayWrapper.java:198) at sun.nio.ch.KQueueSelectorImpl.doSelect(KQueueSelectorImpl.java:103) at sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:86) - locked <0x000000079538d3d8> (a org.python.netty.channel.nio.SelectedSelectionKeySet) - locked <0x000000079538f4a8> (a java.util.Collections$UnmodifiableSet) - locked <0x000000079538d2c8> (a sun.nio.ch.KQueueSelectorImpl) at sun.nio.ch.SelectorImpl.select(SelectorImpl.java:97) at org.python.netty.channel.nio.NioEventLoop.select(NioEventLoop.java:622) at org.python.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:310) at org.python.netty.util.concurrent.SingleThreadEventExecutor$2.run(SingleThreadEventExecutor.java:112) at java.lang.Thread.run(Thread.java:745) "Jython-Netty-Child-47" #66 daemon prio=5 os_prio=31 tid=0x00007f80b20e2800 nid=0x7003 runnable [0x000070000252d000] java.lang.Thread.State: RUNNABLE at sun.nio.ch.KQueueArrayWrapper.kevent0(Native Method) at sun.nio.ch.KQueueArrayWrapper.poll(KQueueArrayWrapper.java:198) at sun.nio.ch.KQueueSelectorImpl.doSelect(KQueueSelectorImpl.java:103) at sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:86) - locked <0x00000007953b20d0> (a org.python.netty.channel.nio.SelectedSelectionKeySet) - locked <0x00000007953b41a0> (a java.util.Collections$UnmodifiableSet) - locked <0x0000000795391fa8> (a sun.nio.ch.KQueueSelectorImpl) at sun.nio.ch.SelectorImpl.select(SelectorImpl.java:97) at org.python.netty.channel.nio.NioEventLoop.select(NioEventLoop.java:622) at org.python.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:310) at org.python.netty.util.concurrent.SingleThreadEventExecutor$2.run(SingleThreadEventExecutor.java:112) at java.lang.Thread.run(Thread.java:745) "Jython-Netty-Child-46" #65 daemon prio=5 os_prio=31 tid=0x00007f80b0dd9000 nid=0x6e03 runnable [0x000070000242a000] java.lang.Thread.State: RUNNABLE at sun.nio.ch.KQueueArrayWrapper.kevent0(Native Method) at sun.nio.ch.KQueueArrayWrapper.poll(KQueueArrayWrapper.java:198) at sun.nio.ch.KQueueSelectorImpl.doSelect(KQueueSelectorImpl.java:103) at sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:86) - locked <0x00000007953b6db0> (a org.python.netty.channel.nio.SelectedSelectionKeySet) - locked <0x00000007953b8e80> (a java.util.Collections$UnmodifiableSet) - locked <0x00000007953b6ca0> (a sun.nio.ch.KQueueSelectorImpl) at sun.nio.ch.SelectorImpl.select(SelectorImpl.java:97) at org.python.netty.channel.nio.NioEventLoop.select(NioEventLoop.java:622) at org.python.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:310) at org.python.netty.util.concurrent.SingleThreadEventExecutor$2.run(SingleThreadEventExecutor.java:112) at java.lang.Thread.run(Thread.java:745) "Jython-Netty-Child-45" #64 daemon prio=5 os_prio=31 tid=0x00007f80ac05c800 nid=0x6c03 runnable [0x0000700002327000] java.lang.Thread.State: RUNNABLE at sun.nio.ch.KQueueArrayWrapper.kevent0(Native Method) at sun.nio.ch.KQueueArrayWrapper.poll(KQueueArrayWrapper.java:198) at sun.nio.ch.KQueueSelectorImpl.doSelect(KQueueSelectorImpl.java:103) at sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:86) - locked <0x000000079540dd70> (a org.python.netty.channel.nio.SelectedSelectionKeySet) - locked <0x000000079540fe60> (a java.util.Collections$UnmodifiableSet) - locked <0x000000079540dc60> (a sun.nio.ch.KQueueSelectorImpl) at sun.nio.ch.SelectorImpl.select(SelectorImpl.java:97) at org.python.netty.channel.nio.NioEventLoop.select(NioEventLoop.java:622) at org.python.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:310) at org.python.netty.util.concurrent.SingleThreadEventExecutor$2.run(SingleThreadEventExecutor.java:112) at java.lang.Thread.run(Thread.java:745) "Jython-Netty-Child-44" #63 daemon prio=5 os_prio=31 tid=0x00007f80b2691000 nid=0x6a03 runnable [0x0000700002224000] java.lang.Thread.State: RUNNABLE at sun.nio.ch.KQueueArrayWrapper.kevent0(Native Method) at sun.nio.ch.KQueueArrayWrapper.poll(KQueueArrayWrapper.java:198) at sun.nio.ch.KQueueSelectorImpl.doSelect(KQueueSelectorImpl.java:103) at sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:86) - locked <0x00000007953d5cb8> (a org.python.netty.channel.nio.SelectedSelectionKeySet) - locked <0x00000007953d8f80> (a java.util.Collections$UnmodifiableSet) - locked <0x00000007953d5bb8> (a sun.nio.ch.KQueueSelectorImpl) at sun.nio.ch.SelectorImpl.select(SelectorImpl.java:97) at org.python.netty.channel.nio.NioEventLoop.select(NioEventLoop.java:622) at org.python.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:310) at org.python.netty.util.concurrent.SingleThreadEventExecutor$2.run(SingleThreadEventExecutor.java:112) at java.lang.Thread.run(Thread.java:745) "Jython-Netty-Child-43" #62 daemon prio=5 os_prio=31 tid=0x00007f80ad22e000 nid=0x6803 runnable [0x0000700002121000] java.lang.Thread.State: RUNNABLE at sun.nio.ch.KQueueArrayWrapper.kevent0(Native Method) at sun.nio.ch.KQueueArrayWrapper.poll(KQueueArrayWrapper.java:198) at sun.nio.ch.KQueueSelectorImpl.doSelect(KQueueSelectorImpl.java:103) at sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:86) - locked <0x00000007953d9ab8> (a org.python.netty.channel.nio.SelectedSelectionKeySet) - locked <0x00000007953ec0d0> (a java.util.Collections$UnmodifiableSet) - locked <0x00000007953d99a8> (a sun.nio.ch.KQueueSelectorImpl) at sun.nio.ch.SelectorImpl.select(SelectorImpl.java:97) at org.python.netty.channel.nio.NioEventLoop.select(NioEventLoop.java:622) at org.python.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:310) at org.python.netty.util.concurrent.SingleThreadEventExecutor$2.run(SingleThreadEventExecutor.java:112) at java.lang.Thread.run(Thread.java:745) "Jython-Netty-Child-42" #61 daemon prio=5 os_prio=31 tid=0x00007f80b2597800 nid=0x6603 runnable [0x000070000201e000] java.lang.Thread.State: RUNNABLE at sun.nio.ch.KQueueArrayWrapper.kevent0(Native Method) at sun.nio.ch.KQueueArrayWrapper.poll(KQueueArrayWrapper.java:198) at sun.nio.ch.KQueueSelectorImpl.doSelect(KQueueSelectorImpl.java:103) at sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:86) - locked <0x00000007953eece0> (a org.python.netty.channel.nio.SelectedSelectionKeySet) - locked <0x00000007953f0db0> (a java.util.Collections$UnmodifiableSet) - locked <0x00000007953eebd0> (a sun.nio.ch.KQueueSelectorImpl) at sun.nio.ch.SelectorImpl.select(SelectorImpl.java:97) at org.python.netty.channel.nio.NioEventLoop.select(NioEventLoop.java:622) at org.python.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:310) at org.python.netty.util.concurrent.SingleThreadEventExecutor$2.run(SingleThreadEventExecutor.java:112) at java.lang.Thread.run(Thread.java:745) "Jython-Netty-Child-41" #60 daemon prio=5 os_prio=31 tid=0x00007f80b2596800 nid=0x6403 waiting on condition [0x0000700001f1a000] java.lang.Thread.State: WAITING (parking) at sun.misc.Unsafe.park(Native Method) - parking to wait for <0x000000076bbf0620> (a java.util.concurrent.CountDownLatch$Sync) at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175) at java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(AbstractQueuedSynchronizer.java:836) at java.util.concurrent.locks.AbstractQueuedSynchronizer.doAcquireSharedInterruptibly(AbstractQueuedSynchronizer.java:997) at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireSharedInterruptibly(AbstractQueuedSynchronizer.java:1304) at java.util.concurrent.CountDownLatch.await(CountDownLatch.java:231) at sun.reflect.GeneratedMethodAccessor56.invoke(Unknown Source) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:497) at org.python.core.PyReflectedFunction.__call__(PyReflectedFunction.java:186) at org.python.core.PyReflectedFunction.__call__(PyReflectedFunction.java:204) at org.python.core.PyObject.__call__(PyObject.java:480) at org.python.core.PyObject.__call__(PyObject.java:484) at org.python.core.PyMethod.__call__(PyMethod.java:126) at _socket$py._wait_on_latch$121(/Users/nick/.m2/repository/com/datastax/opscenter/jython/2.7.1-rc6/jython-2.7.1-rc6.jar/Lib/_socket.py:1426) at _socket$py.call_function(/Users/nick/.m2/repository/com/datastax/opscenter/jython/2.7.1-rc6/jython-2.7.1-rc6.jar/Lib/_socket.py) at org.python.core.PyTableCode.call(PyTableCode.java:167) at org.python.core.PyBaseCode.call(PyBaseCode.java:139) at org.python.core.PyFunction.__call__(PyFunction.java:413) at org.python.core.PyMethod.__call__(PyMethod.java:126) at _socket$py.initChannel$57(/Users/nick/.m2/repository/com/datastax/opscenter/jython/2.7.1-rc6/jython-2.7.1-rc6.jar/Lib/_socket.py:641) at _socket$py.call_function(/Users/nick/.m2/repository/com/datastax/opscenter/jython/2.7.1-rc6/jython-2.7.1-rc6.jar/Lib/_socket.py) at org.python.core.PyTableCode.call(PyTableCode.java:167) at org.python.core.PyBaseCode.call(PyBaseCode.java:308) at org.python.core.PyBaseCode.call(PyBaseCode.java:199) at org.python.core.PyFunction.__call__(PyFunction.java:482) at org.python.core.PyMethod.instancemethod___call__(PyMethod.java:237) at org.python.core.PyMethod.__call__(PyMethod.java:228) at org.python.core.PyMethod.__call__(PyMethod.java:218) at org.python.core.PyMethod.__call__(PyMethod.java:213) at org.python.core.PyObject._jcallexc(PyObject.java:3645) at org.python.proxies._socket$ChildSocketHandler$2.initChannel(Unknown Source) at org.python.netty.channel.ChannelInitializer.channelRegistered(ChannelInitializer.java:68) at org.python.netty.channel.AbstractChannelHandlerContext.invokeChannelRegistered(AbstractChannelHandlerContext.java:143) at org.python.netty.channel.AbstractChannelHandlerContext.fireChannelRegistered(AbstractChannelHandlerContext.java:129) at org.python.netty.channel.DefaultChannelPipeline.fireChannelRegistered(DefaultChannelPipeline.java:733) at org.python.netty.channel.AbstractChannel$AbstractUnsafe.register0(AbstractChannel.java:450) at org.python.netty.channel.AbstractChannel$AbstractUnsafe.access$100(AbstractChannel.java:378) at org.python.netty.channel.AbstractChannel$AbstractUnsafe$1.run(AbstractChannel.java:424) at org.python.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:358) at org.python.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:357) at org.python.netty.util.concurrent.SingleThreadEventExecutor$2.run(SingleThreadEventExecutor.java:112) at java.lang.Thread.run(Thread.java:745) "Jython-Netty-Child-40" #59 daemon prio=5 os_prio=31 tid=0x00007f80b18f5000 nid=0x5507 runnable [0x0000700001e18000] java.lang.Thread.State: RUNNABLE at sun.nio.ch.KQueueArrayWrapper.kevent0(Native Method) at sun.nio.ch.KQueueArrayWrapper.poll(KQueueArrayWrapper.java:198) at sun.nio.ch.KQueueSelectorImpl.doSelect(KQueueSelectorImpl.java:103) at sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:86) - locked <0x00000007953f8918> (a org.python.netty.channel.nio.SelectedSelectionKeySet) - locked <0x000000079540b0c0> (a java.util.Collections$UnmodifiableSet) - locked <0x00000007953f8808> (a sun.nio.ch.KQueueSelectorImpl) at sun.nio.ch.SelectorImpl.select(SelectorImpl.java:97) at org.python.netty.channel.nio.NioEventLoop.select(NioEventLoop.java:622) at org.python.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:310) at org.python.netty.util.concurrent.SingleThreadEventExecutor$2.run(SingleThreadEventExecutor.java:112) at java.lang.Thread.run(Thread.java:745) "Jython-Netty-Parent-70" #89 daemon prio=5 os_prio=31 tid=0x00007f80b07ee000 nid=0x6203 runnable [0x0000700001d15000] java.lang.Thread.State: RUNNABLE at sun.nio.ch.KQueueArrayWrapper.kevent0(Native Method) at sun.nio.ch.KQueueArrayWrapper.poll(KQueueArrayWrapper.java:198) at sun.nio.ch.KQueueSelectorImpl.doSelect(KQueueSelectorImpl.java:103) at sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:86) - locked <0x0000000795ae2c88> (a org.python.netty.channel.nio.SelectedSelectionKeySet) - locked <0x0000000795af5528> (a java.util.Collections$UnmodifiableSet) - locked <0x0000000795ae2bd8> (a sun.nio.ch.KQueueSelectorImpl) at sun.nio.ch.SelectorImpl.select(SelectorImpl.java:97) at org.python.netty.channel.nio.NioEventLoop.select(NioEventLoop.java:622) at org.python.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:310) at org.python.netty.util.concurrent.SingleThreadEventExecutor$2.run(SingleThreadEventExecutor.java:112) at java.lang.Thread.run(Thread.java:745) "Jython-Netty-Parent-50" #69 daemon prio=5 os_prio=31 tid=0x00007f80ad36f000 nid=0x410b runnable [0x0000700001c12000] java.lang.Thread.State: RUNNABLE at sun.nio.ch.KQueueArrayWrapper.kevent0(Native Method) at sun.nio.ch.KQueueArrayWrapper.poll(KQueueArrayWrapper.java:198) at sun.nio.ch.KQueueSelectorImpl.doSelect(KQueueSelectorImpl.java:103) at sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:86) - locked <0x0000000795a2f130> (a org.python.netty.channel.nio.SelectedSelectionKeySet) - locked <0x0000000795a31220> (a java.util.Collections$UnmodifiableSet) - locked <0x0000000795a2f080> (a sun.nio.ch.KQueueSelectorImpl) at sun.nio.ch.SelectorImpl.select(SelectorImpl.java:97) at org.python.netty.channel.nio.NioEventLoop.select(NioEventLoop.java:622) at org.python.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:310) at org.python.netty.util.concurrent.SingleThreadEventExecutor$2.run(SingleThreadEventExecutor.java:112) at java.lang.Thread.run(Thread.java:745) "Jython-Netty-Parent-30" #49 daemon prio=5 os_prio=31 tid=0x00007f80b2855000 nid=0x100f runnable [0x0000700001b0f000] java.lang.Thread.State: RUNNABLE at sun.nio.ch.KQueueArrayWrapper.kevent0(Native Method) at sun.nio.ch.KQueueArrayWrapper.poll(KQueueArrayWrapper.java:198) at sun.nio.ch.KQueueSelectorImpl.doSelect(KQueueSelectorImpl.java:103) at sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:86) - locked <0x00000007953749b0> (a org.python.netty.channel.nio.SelectedSelectionKeySet) - locked <0x0000000795376cb0> (a java.util.Collections$UnmodifiableSet) - locked <0x0000000795374910> (a sun.nio.ch.KQueueSelectorImpl) at sun.nio.ch.SelectorImpl.select(SelectorImpl.java:97) at org.python.netty.channel.nio.NioEventLoop.select(NioEventLoop.java:622) at org.python.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:310) at org.python.netty.util.concurrent.SingleThreadEventExecutor$2.run(SingleThreadEventExecutor.java:112) at java.lang.Thread.run(Thread.java:745) "Jython-Netty-Child-20" #37 daemon prio=5 os_prio=31 tid=0x00007f80af325800 nid=0x5f03 runnable [0x0000700001a0c000] java.lang.Thread.State: RUNNABLE at sun.nio.ch.KQueueArrayWrapper.kevent0(Native Method) at sun.nio.ch.KQueueArrayWrapper.poll(KQueueArrayWrapper.java:198) at sun.nio.ch.KQueueSelectorImpl.doSelect(KQueueSelectorImpl.java:103) at sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:86) - locked <0x00000006c2775770> (a org.python.netty.channel.nio.SelectedSelectionKeySet) - locked <0x00000006c2775790> (a java.util.Collections$UnmodifiableSet) - locked <0x00000006c2775720> (a sun.nio.ch.KQueueSelectorImpl) at sun.nio.ch.SelectorImpl.select(SelectorImpl.java:97) at org.python.netty.channel.nio.NioEventLoop.select(NioEventLoop.java:622) at org.python.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:310) at org.python.netty.util.concurrent.SingleThreadEventExecutor$2.run(SingleThreadEventExecutor.java:112) at java.lang.Thread.run(Thread.java:745) "Jython-Netty-Client-0" #16 daemon prio=5 os_prio=31 tid=0x00007f80acfe3000 nid=0x5d03 runnable [0x0000700001909000] java.lang.Thread.State: RUNNABLE at sun.nio.ch.KQueueArrayWrapper.kevent0(Native Method) at sun.nio.ch.KQueueArrayWrapper.poll(KQueueArrayWrapper.java:198) at sun.nio.ch.KQueueSelectorImpl.doSelect(KQueueSelectorImpl.java:103) at sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:86) - locked <0x00000006c29dd068> (a org.python.netty.channel.nio.SelectedSelectionKeySet) - locked <0x00000006c29dd088> (a java.util.Collections$UnmodifiableSet) - locked <0x00000006c29dd018> (a sun.nio.ch.KQueueSelectorImpl) at sun.nio.ch.SelectorImpl.select(SelectorImpl.java:97) at org.python.netty.channel.nio.NioEventLoop.select(NioEventLoop.java:622) at org.python.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:310) at org.python.netty.util.concurrent.SingleThreadEventExecutor$2.run(SingleThreadEventExecutor.java:112) at java.lang.Thread.run(Thread.java:745) "Jython-Netty-Parent-10" #27 daemon prio=5 os_prio=31 tid=0x00007f80b1e1e000 nid=0x5b07 runnable [0x0000700001806000] java.lang.Thread.State: RUNNABLE at sun.nio.ch.KQueueArrayWrapper.kevent0(Native Method) at sun.nio.ch.KQueueArrayWrapper.poll(KQueueArrayWrapper.java:198) at sun.nio.ch.KQueueSelectorImpl.doSelect(KQueueSelectorImpl.java:103) at sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:86) - locked <0x00000006c28a86e8> (a org.python.netty.channel.nio.SelectedSelectionKeySet) - locked <0x00000006c28aaa18> (a java.util.Collections$UnmodifiableSet) - locked <0x00000006c28a8648> (a sun.nio.ch.KQueueSelectorImpl) at sun.nio.ch.SelectorImpl.select(SelectorImpl.java:97) at org.python.netty.channel.nio.NioEventLoop.select(NioEventLoop.java:622) at org.python.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:310) at org.python.netty.util.concurrent.SingleThreadEventExecutor$2.run(SingleThreadEventExecutor.java:112) at java.lang.Thread.run(Thread.java:745) "weakref reaper" #26 daemon prio=5 os_prio=31 tid=0x00007f80ac20e800 nid=0x5903 in Object.wait() [0x0000700001703000] java.lang.Thread.State: WAITING (on object monitor) at java.lang.Object.wait(Native Method) at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:143) - locked <0x00000006c23a9ac0> (a java.lang.ref.ReferenceQueue$Lock) at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:164) at org.python.modules._weakref.GlobalRef$RefReaper.collect(GlobalRef.java:437) at org.python.modules._weakref.GlobalRef$RefReaper.run(GlobalRef.java:453) at java.lang.Thread.run(Thread.java:745) "NonBlockingInputStreamThread" #13 daemon prio=5 os_prio=31 tid=0x00007f80b02d0800 nid=0x5703 in Object.wait() [0x0000700001600000] java.lang.Thread.State: WAITING (on object monitor) at java.lang.Object.wait(Native Method) - waiting on <0x00000006c1381fd8> (a org.python.jline.internal.NonBlockingInputStream) at org.python.jline.internal.NonBlockingInputStream.run(NonBlockingInputStream.java:275) - locked <0x00000006c1381fd8> (a org.python.jline.internal.NonBlockingInputStream) at java.lang.Thread.run(Thread.java:745) "Service Thread" #9 daemon prio=9 os_prio=31 tid=0x00007f80af83c800 nid=0x5103 runnable [0x0000000000000000] java.lang.Thread.State: RUNNABLE "C1 CompilerThread3" #8 daemon prio=9 os_prio=31 tid=0x00007f80ac010800 nid=0x4f03 waiting on condition [0x0000000000000000] java.lang.Thread.State: RUNNABLE "C2 CompilerThread2" #7 daemon prio=9 os_prio=31 tid=0x00007f80af833800 nid=0x4d03 waiting on condition [0x0000000000000000] java.lang.Thread.State: RUNNABLE "C2 CompilerThread1" #6 daemon prio=9 os_prio=31 tid=0x00007f80b0012800 nid=0x4b03 waiting on condition [0x0000000000000000] java.lang.Thread.State: RUNNABLE "C2 CompilerThread0" #5 daemon prio=9 os_prio=31 tid=0x00007f80ac00f800 nid=0x4903 waiting on condition [0x0000000000000000] java.lang.Thread.State: RUNNABLE "Signal Dispatcher" #4 daemon prio=9 os_prio=31 tid=0x00007f80ad80a800 nid=0x420f runnable [0x0000000000000000] java.lang.Thread.State: RUNNABLE "Finalizer" #3 daemon prio=8 os_prio=31 tid=0x00007f80b0003000 nid=0x3803 in Object.wait() [0x0000700000d39000] java.lang.Thread.State: WAITING (on object monitor) at java.lang.Object.wait(Native Method) at java.lang.Object.wait(Object.java:502) at org.python.netty.util.concurrent.DefaultPromise.await(DefaultPromise.java:254) - locked <0x000000076c336720> (a org.python.netty.channel.DefaultChannelPromise) at org.python.netty.channel.DefaultChannelPromise.await(DefaultChannelPromise.java:129) at org.python.netty.channel.DefaultChannelPromise.await(DefaultChannelPromise.java:28) at org.python.netty.util.concurrent.DefaultPromise.sync(DefaultPromise.java:218) at org.python.netty.channel.DefaultChannelPromise.sync(DefaultChannelPromise.java:117) at org.python.netty.channel.DefaultChannelPromise.sync(DefaultChannelPromise.java:28) at sun.reflect.GeneratedMethodAccessor60.invoke(Unknown Source) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:497) at org.python.core.PyReflectedFunction.__call__(PyReflectedFunction.java:186) at org.python.core.PyReflectedFunction.__call__(PyReflectedFunction.java:204) at org.python.core.PyObject.__call__(PyObject.java:480) at org.python.core.PyObject.__call__(PyObject.java:484) at org.python.core.PyMethod.__call__(PyMethod.java:126) at _socket$py.close$88(/Users/nick/.m2/repository/com/datastax/opscenter/jython/2.7.1-rc6/jython-2.7.1-rc6.jar/Lib/_socket.py:1080) at _socket$py.call_function(/Users/nick/.m2/repository/com/datastax/opscenter/jython/2.7.1-rc6/jython-2.7.1-rc6.jar/Lib/_socket.py) at org.python.core.PyTableCode.call(PyTableCode.java:167) at org.python.core.PyBaseCode.call(PyBaseCode.java:139) at org.python.core.PyFunction.__call__(PyFunction.java:413) at org.python.core.PyMethod.__call__(PyMethod.java:126) at _socket$py.close$126(/Users/nick/.m2/repository/com/datastax/opscenter/jython/2.7.1-rc6/jython-2.7.1-rc6.jar/Lib/_socket.py:1464) at _socket$py.call_function(/Users/nick/.m2/repository/com/datastax/opscenter/jython/2.7.1-rc6/jython-2.7.1-rc6.jar/Lib/_socket.py) at org.python.core.PyTableCode.call(PyTableCode.java:167) at org.python.core.PyBaseCode.call(PyBaseCode.java:139) at org.python.core.PyFunction.__call__(PyFunction.java:413) at org.python.core.PyMethod.__call__(PyMethod.java:126) at _socket$py.__del__$128(/Users/nick/.m2/repository/com/datastax/opscenter/jython/2.7.1-rc6/jython-2.7.1-rc6.jar/Lib/_socket.py:1477) at _socket$py.call_function(/Users/nick/.m2/repository/com/datastax/opscenter/jython/2.7.1-rc6/jython-2.7.1-rc6.jar/Lib/_socket.py) at org.python.core.PyTableCode.call(PyTableCode.java:167) at org.python.core.PyBaseCode.call(PyBaseCode.java:139) at org.python.core.PyFunction.__call__(PyFunction.java:413) at org.python.core.PyMethod.__call__(PyMethod.java:126) at org.python.core.PyMethod.__call__(PyMethod.java:117) at org.python.core.PyObjectDerived.__del_derived__(PyObjectDerived.java:24) at org.python.core.finalization.FinalizeTrigger.runFinalizer(FinalizeTrigger.java:83) - locked <0x00000006c1593b98> (a java.lang.Class for org.python.core.PySystemState$PySystemStateCloser) at org.python.core.finalization.FinalizeTrigger.performFinalization(FinalizeTrigger.java:170) at org.python.core.finalization.FinalizeTrigger.finalize(FinalizeTrigger.java:209) at java.lang.System$2.invokeFinalize(System.java:1270) at java.lang.ref.Finalizer.runFinalizer(Finalizer.java:98) at java.lang.ref.Finalizer.access$100(Finalizer.java:34) at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:210) "Reference Handler" #2 daemon prio=10 os_prio=31 tid=0x00007f80b0002000 nid=0x3603 in Object.wait() [0x0000700000c37000] java.lang.Thread.State: WAITING (on object monitor) at java.lang.Object.wait(Native Method) at java.lang.Object.wait(Object.java:502) at java.lang.ref.Reference$ReferenceHandler.run(Reference.java:157) - locked <0x00000006c147bd98> (a java.lang.ref.Reference$Lock) "MainThread" #1 prio=5 os_prio=31 tid=0x00007f80ae801800 nid=0xc0b waiting for monitor entry [0x0000700000213000] java.lang.Thread.State: BLOCKED (on object monitor) at org.python.core.PySystemState$PySystemStateCloser.registerCloser(PySystemState.java:1531) - waiting to lock <0x00000006c1593b98> (a java.lang.Class for org.python.core.PySystemState$PySystemStateCloser) at org.python.core.PySystemState$PySystemStateCloser.access$100(PySystemState.java:1508) at org.python.core.PySystemState.registerCloser(PySystemState.java:1495) at org.python.modules._io.Closer.<init>(Closer.java:40) at org.python.modules._io.PyIOBase.<init>(PyIOBase.java:59) at org.python.modules._io.PyIOBaseDerived.<init>(PyIOBaseDerived.java:51) at org.python.modules._io.PyIOBase._IOBase___new__(PyIOBase.java:83) at org.python.modules._io.PyIOBase$exposed___new__.new_impl(Unknown Source) at org.python.core.PyType.invokeNew(PyType.java:494) at org.python.core.PyType.type___call__(PyType.java:1708) at org.python.core.PyType.__call__(PyType.java:1698) at org.python.core.PyObject.__call__(PyObject.java:464) at org.python.core.PyObject.__call__(PyObject.java:468) at twisted.web.http$py.gotLength$37(/Users/nick/workspace/git/ripcord/opscenterd/lib/py/twisted/web/http.py:729) at twisted.web.http$py.call_function(/Users/nick/workspace/git/ripcord/opscenterd/lib/py/twisted/web/http.py) at org.python.core.PyTableCode.call(PyTableCode.java:167) at org.python.core.PyBaseCode.call(PyBaseCode.java:154) at org.python.core.PyFunction.__call__(PyFunction.java:423) at org.python.core.PyMethod.__call__(PyMethod.java:141) at twisted.web.http$py.allHeadersReceived$94(/Users/nick/workspace/git/ripcord/opscenterd/lib/py/twisted/web/http.py:1776) at twisted.web.http$py.call_function(/Users/nick/workspace/git/ripcord/opscenterd/lib/py/twisted/web/http.py) at org.python.core.PyTableCode.call(PyTableCode.java:167) at org.python.core.PyBaseCode.call(PyBaseCode.java:139) at org.python.core.PyFunction.__call__(PyFunction.java:413) at org.python.core.PyMethod.__call__(PyMethod.java:126) at twisted.web.http$py.lineReceived$88(/Users/nick/workspace/git/ripcord/opscenterd/lib/py/twisted/web/http.py:1688) at twisted.web.http$py.call_function(/Users/nick/workspace/git/ripcord/opscenterd/lib/py/twisted/web/http.py) at org.python.core.PyTableCode.call(PyTableCode.java:167) at org.python.core.PyBaseCode.call(PyBaseCode.java:154) at org.python.core.PyFunction.__call__(PyFunction.java:423) at org.python.core.PyMethod.__call__(PyMethod.java:141) at twisted.protocols.basic$py.dataReceived$35(/Users/nick/workspace/git/ripcord/opscenterd/lib/py/twisted/protocols/basic.py:582) at twisted.protocols.basic$py.call_function(/Users/nick/workspace/git/ripcord/opscenterd/lib/py/twisted/protocols/basic.py) at org.python.core.PyTableCode.call(PyTableCode.java:167) at org.python.core.PyBaseCode.call(PyBaseCode.java:154) at org.python.core.PyFunction.__call__(PyFunction.java:423) at org.python.core.PyMethod.__call__(PyMethod.java:141) at twisted.internet.tcp$py._dataReceived$14(/Users/nick/workspace/git/ripcord/opscenterd/lib/py/twisted/internet/tcp.py:218) at twisted.internet.tcp$py.call_function(/Users/nick/workspace/git/ripcord/opscenterd/lib/py/twisted/internet/tcp.py) at org.python.core.PyTableCode.call(PyTableCode.java:167) at org.python.core.PyBaseCode.call(PyBaseCode.java:154) at org.python.core.PyFunction.__call__(PyFunction.java:423) at org.python.core.PyMethod.__call__(PyMethod.java:141) at twisted.internet.tcp$py.doRead$13(/Users/nick/workspace/git/ripcord/opscenterd/lib/py/twisted/internet/tcp.py:202) at twisted.internet.tcp$py.call_function(/Users/nick/workspace/git/ripcord/opscenterd/lib/py/twisted/internet/tcp.py) at org.python.core.PyTableCode.call(PyTableCode.java:167) at org.python.core.PyBaseCode.call(PyBaseCode.java:139) at org.python.core.PyFunction.__call__(PyFunction.java:413) at org.python.core.PyMethod.__call__(PyMethod.java:126) at twisted.internet.selectreactor$py._doReadOrWrite$6(/Users/nick/workspace/git/ripcord/opscenterd/lib/py/twisted/internet/selectreactor.py:154) at twisted.internet.selectreactor$py.call_function(/Users/nick/workspace/git/ripcord/opscenterd/lib/py/twisted/internet/selectreactor.py) at org.python.core.PyTableCode.call(PyTableCode.java:167) at org.python.core.PyBaseCode.call(PyBaseCode.java:308) at org.python.core.PyBaseCode.call(PyBaseCode.java:199) at org.python.core.PyFunction.__call__(PyFunction.java:482) at org.python.core.PyMethod.instancemethod___call__(PyMethod.java:237) at org.python.core.PyMethod.__call__(PyMethod.java:228) at org.python.core.PyMethod.__call__(PyMethod.java:223) at org.python.core.PyObject._callextra(PyObject.java:620) at twisted.python.context$py.callWithContext$3(/Users/nick/workspace/git/ripcord/opscenterd/lib/py/twisted/python/context.py:83) at twisted.python.context$py.call_function(/Users/nick/workspace/git/ripcord/opscenterd/lib/py/twisted/python/context.py) at org.python.core.PyTableCode.call(PyTableCode.java:167) at org.python.core.PyBaseCode.call(PyBaseCode.java:308) at org.python.core.PyBaseCode.call(PyBaseCode.java:199) at org.python.core.PyFunction.__call__(PyFunction.java:482) at org.python.core.PyMethod.instancemethod___call__(PyMethod.java:237) at org.python.core.PyMethod.__call__(PyMethod.java:228) at org.python.core.PyMethod.__call__(PyMethod.java:223) at org.python.core.PyObject._callextra(PyObject.java:620) at twisted.python.context$py.callWithContext$8(/Users/nick/workspace/git/ripcord/opscenterd/lib/py/twisted/python/context.py:118) at twisted.python.context$py.call_function(/Users/nick/workspace/git/ripcord/opscenterd/lib/py/twisted/python/context.py) at org.python.core.PyTableCode.call(PyTableCode.java:167) at org.python.core.PyBaseCode.call(PyBaseCode.java:308) at org.python.core.PyBaseCode.call(PyBaseCode.java:199) at org.python.core.PyFunction.__call__(PyFunction.java:482) at org.python.core.PyMethod.instancemethod___call__(PyMethod.java:237) at org.python.core.PyMethod.__call__(PyMethod.java:228) at org.python.core.PyMethod.__call__(PyMethod.java:223) at org.python.core.PyObject._callextra(PyObject.java:620) at twisted.python.log$py.callWithContext$4(/Users/nick/workspace/git/ripcord/opscenterd/lib/py/twisted/python/log.py:84) at twisted.python.log$py.call_function(/Users/nick/workspace/git/ripcord/opscenterd/lib/py/twisted/python/log.py) at org.python.core.PyTableCode.call(PyTableCode.java:167) at org.python.core.PyBaseCode.call(PyBaseCode.java:308) at org.python.core.PyFunction.function___call__(PyFunction.java:471) at org.python.core.PyFunction.__call__(PyFunction.java:466) at org.python.core.PyFunction.__call__(PyFunction.java:461) at org.python.core.PyObject._callextra(PyObject.java:620) at twisted.python.log$py.callWithLogger$5(/Users/nick/workspace/git/ripcord/opscenterd/lib/py/twisted/python/log.py:105) at twisted.python.log$py.call_function(/Users/nick/workspace/git/ripcord/opscenterd/lib/py/twisted/python/log.py) at org.python.core.PyTableCode.call(PyTableCode.java:167) at org.python.core.PyBaseCode.call(PyBaseCode.java:308) at org.python.core.PyBaseCode.call(PyBaseCode.java:179) at org.python.core.PyFunction.__call__(PyFunction.java:446) at twisted.internet.selectreactor$py.doSelect$5(/Users/nick/workspace/git/ripcord/opscenterd/lib/py/twisted/internet/selectreactor.py:135) at twisted.internet.selectreactor$py.call_function(/Users/nick/workspace/git/ripcord/opscenterd/lib/py/twisted/internet/selectreactor.py) at org.python.core.PyTableCode.call(PyTableCode.java:167) at org.python.core.PyBaseCode.call(PyBaseCode.java:154) at org.python.core.PyFunction.__call__(PyFunction.java:423) at org.python.core.PyMethod.__call__(PyMethod.java:141) at twisted.internet.base$py.mainLoop$91(/Users/nick/workspace/git/ripcord/opscenterd/lib/py/twisted/internet/base.py:1198) at twisted.internet.base$py.call_function(/Users/nick/workspace/git/ripcord/opscenterd/lib/py/twisted/internet/base.py) at org.python.core.PyTableCode.call(PyTableCode.java:167) at org.python.core.PyBaseCode.call(PyBaseCode.java:139) at org.python.core.PyFunction.__call__(PyFunction.java:413) at org.python.core.PyMethod.__call__(PyMethod.java:126) at twisted.internet.base$py.run$90(/Users/nick/workspace/git/ripcord/opscenterd/lib/py/twisted/internet/base.py:1194) at twisted.internet.base$py.call_function(/Users/nick/workspace/git/ripcord/opscenterd/lib/py/twisted/internet/base.py) at org.python.core.PyTableCode.call(PyTableCode.java:167) at org.python.core.PyBaseCode.call(PyBaseCode.java:308) at org.python.core.PyBaseCode.call(PyBaseCode.java:132) at org.python.core.PyFunction.__call__(PyFunction.java:413) at org.python.core.PyMethod.__call__(PyMethod.java:126) at twisted.application.app$py.runReactorWithLogging$20(/Users/nick/workspace/git/ripcord/opscenterd/lib/py/twisted/application/app.py:292) at twisted.application.app$py.call_function(/Users/nick/workspace/git/ripcord/opscenterd/lib/py/twisted/application/app.py) at org.python.core.PyTableCode.call(PyTableCode.java:167) at org.python.core.PyBaseCode.call(PyBaseCode.java:308) at org.python.core.PyFunction.function___call__(PyFunction.java:471) at org.python.core.PyFunction.__call__(PyFunction.java:466) at org.python.core.PyFunction.__call__(PyFunction.java:456) at twisted.application.app$py.startReactor$28(/Users/nick/workspace/git/ripcord/opscenterd/lib/py/twisted/application/app.py:363) at twisted.application.app$py.call_function(/Users/nick/workspace/git/ripcord/opscenterd/lib/py/twisted/application/app.py) at org.python.core.PyTableCode.call(PyTableCode.java:167) at org.python.core.PyBaseCode.call(PyBaseCode.java:189) at org.python.core.PyFunction.__call__(PyFunction.java:446) at org.python.core.PyMethod.__call__(PyMethod.java:171) at twisted.scripts._twistd_unix$py.postApplication$13(/Users/nick/workspace/git/ripcord/opscenterd/lib/py/twisted/scripts/_twistd_unix.py:227) at twisted.scripts._twistd_unix$py.call_function(/Users/nick/workspace/git/ripcord/opscenterd/lib/py/twisted/scripts/_twistd_unix.py) at org.python.core.PyTableCode.call(PyTableCode.java:167) at org.python.core.PyBaseCode.call(PyBaseCode.java:139) at org.python.core.PyFunction.__call__(PyFunction.java:413) at org.python.core.PyMethod.__call__(PyMethod.java:126) at twisted.application.app$py.run$27(/Users/nick/workspace/git/ripcord/opscenterd/lib/py/twisted/application/app.py:353) at twisted.application.app$py.call_function(/Users/nick/workspace/git/ripcord/opscenterd/lib/py/twisted/application/app.py) at org.python.core.PyTableCode.call(PyTableCode.java:167) at org.python.core.PyBaseCode.call(PyBaseCode.java:139) at org.python.core.PyFunction.__call__(PyFunction.java:413) at org.python.core.PyMethod.__call__(PyMethod.java:126) at twisted.scripts.twistd$py.runApp$1(/Users/nick/workspace/git/ripcord/opscenterd/lib/py/twisted/scripts/twistd.py:25) at twisted.scripts.twistd$py.call_function(/Users/nick/workspace/git/ripcord/opscenterd/lib/py/twisted/scripts/twistd.py) at org.python.core.PyTableCode.call(PyTableCode.java:167) at org.python.core.PyBaseCode.call(PyBaseCode.java:139) at org.python.core.PyFunction.__call__(PyFunction.java:413) at twisted.application.app$py.run$45(/Users/nick/workspace/git/ripcord/opscenterd/lib/py/twisted/application/app.py:617) at twisted.application.app$py.call_function(/Users/nick/workspace/git/ripcord/opscenterd/lib/py/twisted/application/app.py) at org.python.core.PyTableCode.call(PyTableCode.java:167) at org.python.core.PyBaseCode.call(PyBaseCode.java:154) at org.python.core.PyFunction.__call__(PyFunction.java:423) at twisted.scripts.twistd$py.run$2(/Users/nick/workspace/git/ripcord/opscenterd/lib/py/twisted/scripts/twistd.py:29) at twisted.scripts.twistd$py.call_function(/Users/nick/workspace/git/ripcord/opscenterd/lib/py/twisted/scripts/twistd.py) at org.python.core.PyTableCode.call(PyTableCode.java:167) at org.python.core.PyBaseCode.call(PyBaseCode.java:125) at org.python.core.PyFunction.__call__(PyFunction.java:403) at org.python.pycode._pyx0.f$0(./bin/twistd:29) at org.python.pycode._pyx0.call_function(./bin/twistd) at org.python.core.PyTableCode.call(PyTableCode.java:167) at org.python.core.PyCode.call(PyCode.java:18) at org.python.core.Py.runCode(Py.java:1401) at org.python.util.PythonInterpreter.execfile(PythonInterpreter.java:296) at org.python.util.jython.run(jython.java:362) at org.python.util.jython.main(jython.java:142) "VM Thread" os_prio=31 tid=0x00007f80ad013000 nid=0x3403 runnable "GC task thread#0 (ParallelGC)" os_prio=31 tid=0x00007f80af003800 nid=0x1b07 runnable "GC task thread#1 (ParallelGC)" os_prio=31 tid=0x00007f80ac800800 nid=0x260b runnable "GC task thread#2 (ParallelGC)" os_prio=31 tid=0x00007f80ad002000 nid=0x2803 runnable "GC task thread#3 (ParallelGC)" os_prio=31 tid=0x00007f80ad805000 nid=0x2a03 runnable "GC task thread#4 (ParallelGC)" os_prio=31 tid=0x00007f80ae80a800 nid=0x2c03 runnable "GC task thread#5 (ParallelGC)" os_prio=31 tid=0x00007f80ad806000 nid=0x2e03 runnable "GC task thread#6 (ParallelGC)" os_prio=31 tid=0x00007f80ae80b000 nid=0x3003 runnable "GC task thread#7 (ParallelGC)" os_prio=31 tid=0x00007f80af004000 nid=0x3203 runnable "VM Periodic Task Thread" os_prio=31 tid=0x00007f80ac041000 nid=0x5303 waiting on condition JNI global references: 342 |
|||
msg10705 (view) | Author: Nick (nickmbailey) | Date: 2016-02-03.19:52:23 | |
I'm still leaning towards removing synchronization on a class object when multiple instances of that object (in multiple threads) and the finalizer all lock on it. I *think* the solution we just applied for this solves the issue in http://bugs.jython.org/issue2280 by not having any locking in Closer.java. So I think in this issue we can safely remove the class synchronization. |
|||
msg10706 (view) | Author: Jim Baker (zyasoft) | Date: 2016-02-03.19:53:58 | |
This does not block beta 3 from being finalized, but definitely we want to resolve for the RC. Changing status/resolution accordingly. |
|||
msg10711 (view) | Author: Nick (nickmbailey) | Date: 2016-02-03.21:03:15 | |
Opened a new pull request similar to the first. https://github.com/jythontools/jython/pull/31 As I mentioned earlier, from what I can tell, the previous commit for this ticket to remove synchronization from Closer.java should solve 2280 in a way that doesn't require synchronizing on class objects. So I believe the correct fix here is to remove that. |
|||
msg10712 (view) | Author: Nick (nickmbailey) | Date: 2016-02-03.21:32:20 | |
I can at least confirm that the branch I've opened a pull request doesn't cause the deadlock in my application or with the reproduction script I attached. |
|||
msg10713 (view) | Author: Stefan Richthofer (stefan.richthofer) | Date: 2016-02-03.22:24:58 | |
Looking at issue 2280 in detail again I agree that our switch to a non-blocking lock in Closer.java should solve 2280 too, given that it also involved Closer.dismiss and Closer.call. So in principle I'd be willing to accept your (@Nick) patch. I'm a bit concerned though that we don't have handy unittests for this stuff. So before accepting it I'd like to - have Jim review it since he applied the original fix of issue 2280 - assess whether there's a difference to "just" reverting the patch for 2280 (which now appears to be obsolete) and - if yes - what, why etc - understand/solve why the pullrequest triggers this error message "Your tests failed on CircleCI" Nick, I suppose you're the best person to help answer these quickly, then we're ready to go. |
|||
msg10714 (view) | Author: Nick (nickmbailey) | Date: 2016-02-03.22:36:08 | |
There are 2 differences between this and reverting 2280. 1. I use a synchronized collection for the set of things that need to be closed and therefore don't synchronize on registerCloser/unregisterCloser. 2. I pass in the PySystemStateCloser instance to the shutdown thread and let the shutdown thread synchronize on that. Previously it was just synchronizing on it's own instance which isn't what we wanted. I'll look into the circle ci failure. |
|||
msg10715 (view) | Author: Nick (nickmbailey) | Date: 2016-02-03.22:55:34 | |
So circlci is complaining that 'test_weakset' is failing. But on my machine that test passes and instead 'test_list_jy' 'test_marshal' and 'test_sort' fail. So I'm not sure what's going on there honestly. |
|||
msg10716 (view) | Author: Jim Baker (zyasoft) | Date: 2016-02-03.23:16:14 | |
Ignore test_weakset - we are trying to test behavior that is hard to test on Java, namely observing garbage collection and its interaction with weak references. I will take a look at the proposed change! |
|||
msg10717 (view) | Author: Jim Baker (zyasoft) | Date: 2016-02-03.23:17:31 | |
Also 'test_list_jy' 'test_marshal' and 'test_sort' are known to fail on Java 8. This is due to changes in sorting implementation from 7 to 8. Something we will look at for 2.7.2. |
|||
msg10718 (view) | Author: Jim Baker (zyasoft) | Date: 2016-02-04.01:10:26 | |
See #2399 re test_sort, which captures some aspects. The other is that the sort implementation in Java 8 is less forgiving of crazy comparators (that is, those defined for testing purposes that do not maintain invariants) than in Java 7. Enough on that! |
|||
msg10719 (view) | Author: Jim Baker (zyasoft) | Date: 2016-02-04.01:40:02 | |
Committed Nick's PR from https://github.com/jythontools/jython/pull/31 in https://hg.python.org/jython/rev/94b447b00840 Nick, sorry about inadvertently committing this under my name. We need automated tools to avoid silly human errors! But they are coming, hopefully by the end of this year. |
History | |||
---|---|---|---|
Date | User | Action | Args |
2016-02-11 20:26:09 | zyasoft | set | status: pending -> closed |
2016-02-04 01:40:03 | zyasoft | set | status: open -> pending resolution: accepted -> fixed messages: + msg10719 |
2016-02-04 01:10:26 | zyasoft | set | messages: + msg10718 |
2016-02-03 23:17:31 | zyasoft | set | messages: + msg10717 |
2016-02-03 23:16:14 | zyasoft | set | messages: + msg10716 |
2016-02-03 22:55:34 | nickmbailey | set | messages: + msg10715 |
2016-02-03 22:36:08 | nickmbailey | set | messages: + msg10714 |
2016-02-03 22:24:58 | stefan.richthofer | set | messages: + msg10713 |
2016-02-03 21:32:20 | nickmbailey | set | messages: + msg10712 |
2016-02-03 21:03:15 | nickmbailey | set | messages: + msg10711 |
2016-02-03 19:53:59 | zyasoft | set | status: pending -> open resolution: fixed -> accepted messages: + msg10706 |
2016-02-03 19:52:23 | nickmbailey | set | messages: + msg10705 |
2016-02-03 19:47:45 | nickmbailey | set | messages: + msg10704 |
2016-02-02 23:13:27 | stefan.richthofer | set | resolution: fixed |
2016-02-02 23:13:05 | stefan.richthofer | set | status: open -> pending messages: + msg10698 |
2016-02-02 17:24:56 | zyasoft | set | status: pending -> open messages: + msg10696 |
2016-02-02 06:00:06 | nickmbailey | set | messages: + msg10687 |
2016-02-02 05:58:54 | stefan.richthofer | set | messages: + msg10686 |
2016-02-02 05:50:25 | stefan.richthofer | set | status: open -> pending messages: + msg10685 |
2016-02-02 05:39:12 | nickmbailey | set | messages: + msg10684 |
2016-02-02 05:28:28 | stefan.richthofer | set | messages: + msg10683 |
2016-02-02 03:53:58 | zyasoft | set | assignee: zyasoft -> stefan.richthofer messages: + msg10681 milestone: Jython 2.7.1 |
2016-02-02 01:31:11 | nickmbailey | set | messages: + msg10676 |
2016-02-02 00:47:09 | stefan.richthofer | set | nosy:
+ stefan.richthofer messages: + msg10675 |
2016-02-01 23:22:45 | zyasoft | set | priority: urgent assignee: zyasoft nosy: + zyasoft |
2016-02-01 23:19:39 | nickmbailey | set | messages: + msg10674 |
2016-02-01 22:41:09 | nickmbailey | create |
Supported by Python Software Foundation,
Powered by Roundup