Issue2462

Server sockets that are returned from socket.accept() never initiate a handshake, even when do_handshake_on_connect=True. This can be replicated if you have an ssl client that does not handshake on connect (attached a server/client.py to demonstrate).

This has to do with the fact that sockets returned from .accept() have an underlying socket, which is of the type ChildSocket. in ssl.py, if said socket is a ChildSocket, the handshake request is purposely ignored.

Note: I also added this JVM flag to see the ssl handshake output 
-Djavax.net.debug=all

Some more work needs to be done, but I've attached a partial fix for this bug that might be worth testing.

Note that test_socket currently fails, without progress, at testSendAll. Most likely this is due to not properly going through the activation barrier. Additionally test_socket_jy has to be revisited now that a ValueError is raised if do_handshake_on_connect=True and the socket is nonblocking, which matches what CPython does.

One more thing: I also upgraded the Netty jars to latest to remove the need for RaceFreeSslHandler (I found a bug in that workaround as I was playing with lots of race conditions to solve this problem... easiest to do the upgrade.)

Here's a complete fix, which passes all tests.

We still need to write tests that capture what was done in client.py and server.py, ideally with running a CPython client. We can also vary do_handshake_on_connect over (True, False).

Tried the patch. Not sure yet if it is the root cause, but during regrtest jython deadlocked. Investigating.

Also, sporadically (while running test_logging, where the deadlock happened during regrtest).

java.util.concurrent.RejectedExecutionException: event executor terminated
	at io.netty.util.concurrent.SingleThreadEventExecutor.reject(SingleThreadEventExecutor.java:715)
	at io.netty.util.concurrent.SingleThreadEventExecutor.addTask(SingleThreadEventExecutor.java:300)
	at io.netty.util.concurrent.SingleThreadEventExecutor.execute(SingleThreadEventExecutor.java:691)
	at io.netty.util.concurrent.DefaultPromise.execute(DefaultPromise.java:671)
	at io.netty.util.concurrent.DefaultPromise.notifyLateListener(DefaultPromise.java:641)
	at io.netty.util.concurrent.DefaultPromise.addListener(DefaultPromise.java:138)
	at io.netty.channel.DefaultChannelPromise.addListener(DefaultChannelPromise.java:93)
	at io.netty.channel.DefaultChannelPromise.addListener(DefaultChannelPromise.java:28)
	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:606)
	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:497)
	at org.python.core.PyObject.__call__(PyObject.java:501)
	at org.python.core.PyMethod.__call__(PyMethod.java:141)
	at _socket$py.close$89(/Users/darjus/Documents/jython/dist/Lib/_socket.py:1092)
	at _socket$py.call_function(/Users/darjus/Documents/jython/dist/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$127(/Users/darjus/Documents/jython/dist/Lib/_socket.py:1494)
	at _socket$py.call_function(/Users/darjus/Documents/jython/dist/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__$129(/Users/darjus/Documents/jython/dist/Lib/_socket.py:1507)
	at _socket$py.call_function(/Users/darjus/Documents/jython/dist/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:82)
	at org.python.core.finalization.FinalizeTrigger.performFinalization(FinalizeTrigger.java:168)
	at org.python.core.finalization.FinalizeTrigger.finalize(FinalizeTrigger.java:207)
	at java.lang.System$2.invokeFinalize(System.java:1213)
	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)

msg10815 is well known. It mostly occurs in testing, but it's hard to avoid (see http://stackoverflow.com/questions/32239955/why-does-this-jython-loop-fail-after-a-single-run and https://issues.apache.org/jira/browse/CASSANDRA-6336, even if that was in Netty 3)

We might be able to silence, but it's a separable issue from this one.

re the thread dump:

Note that it's deadlocking here in PyType.fromClass:

    public static synchronized PyType fromClass(Class<?> c, boolean hardRef) {
        if (class_to_type == null) {
            class_to_type = new MapMaker().weakKeys().weakValues().makeMap();
            addFromClass(PyType.class, null);
        }

with respect to ending a call to a method (initChannel) defined in a Java superclass (ChannelInitializer), which is running in a Netty thread pool.

So I don't think this is a problem in this patch per se, just something that is stressing things in regrtest.

I don't like that singleton setup at all, we should be using the "Initialization On Demand Holder" idiom instead (http://www.cs.umd.edu/~pugh/java/memoryModel/jsr-133-faq.html#dcl). Most likely that's the root cause here.

Fixed as of https://hg.python.org/jython/rev/aea64acc5e47