Sam Gardner created SSHD-557:
--------------------------------

             Summary: MINA SSHD deadlocks upon multiple concurrent HTTP 
downloads over locally-forwarded ports
                 Key: SSHD-557
                 URL: https://issues.apache.org/jira/browse/SSHD-557
             Project: MINA SSHD
          Issue Type: Bug
    Affects Versions: 0.14.0, 1.0.0
         Environment: *OS*: {{Linux buildenv.sgardner 3.17.4-301.fc21.x86_64 #1 
SMP Thu Nov 27 19:09:10 UTC 2014 x86_64 x86_64 x86_64 GNU/Linux}}

*Java*: {noformat}
openjdk version "1.8.0_51"
OpenJDK Runtime Environment (build 1.8.0_51-b16)
OpenJDK 64-Bit Server VM (build 25.51-b03, mixed mode)
{noformat}
            Reporter: Sam Gardner
            Priority: Critical


SSHD-Core 1.0.0 deadlocks when multiple concurrent downloads are in progress 
over ChannelOutputStreams

In both Mina-SSHD 0.14.0 and 1.0.0 the server will become deadlocked if 
multiple concurrent downloads are started over a locally-forwarded TCP socket. 
In this state the process is still alive and client connections stay open, but 
no data can be transmitted and new connections will not be accepted - when 
inspected via telnet, the SSH port will not even return a banner.

Inspection of the hung process using the {{jstack}} tool shows that each NIO 
thread is in the following state: {noformat}
"sshd-SshServer[36f6e879]-nio2-thread-4" #14 daemon prio=5 os_prio=0 
tid=0x00007f219c009000 nid=0x34c6 in Object.wait() [0x00007f21c8439000]
   java.lang.Thread.State: WAITING (on object monitor)
        at java.lang.Object.wait(Native Method)
        - waiting on <0x00000000d799f9b0> (a 
org.apache.sshd.common.channel.Window)
        at java.lang.Object.wait(Object.java:502)
        at org.apache.sshd.common.channel.Window.waitForSpace(Window.java:175)
        - locked <0x00000000d799f9b0> (a org.apache.sshd.common.channel.Window)
        at 
org.apache.sshd.common.channel.ChannelOutputStream.flush(ChannelOutputStream.java:126)
        - locked <0x00000000d799fa68> (a 
org.apache.sshd.common.channel.ChannelOutputStream)
        at 
org.apache.sshd.server.forward.TcpipServerChannel$1.messageReceived(TcpipServerChannel.java:156)
        at 
org.apache.sshd.common.io.nio2.Nio2Session$2.onCompleted(Nio2Session.java:220)
        at 
org.apache.sshd.common.io.nio2.Nio2Session$2.onCompleted(Nio2Session.java:212)
        at 
org.apache.sshd.common.io.nio2.Nio2CompletionHandler$1.run(Nio2CompletionHandler.java:34)
        at java.security.AccessController.doPrivileged(Native Method)
        at 
org.apache.sshd.common.io.nio2.Nio2CompletionHandler.completed(Nio2CompletionHandler.java:31)
        at sun.nio.ch.Invoker.invokeUnchecked(Invoker.java:126)
        at sun.nio.ch.Invoker.invokeDirect(Invoker.java:157)
        at 
sun.nio.ch.UnixAsynchronousSocketChannelImpl.implRead(UnixAsynchronousSocketChannelImpl.java:553)
        at 
sun.nio.ch.AsynchronousSocketChannelImpl.read(AsynchronousSocketChannelImpl.java:276)
        at 
sun.nio.ch.AsynchronousSocketChannelImpl.read(AsynchronousSocketChannelImpl.java:297)
        at 
java.nio.channels.AsynchronousSocketChannel.read(AsynchronousSocketChannel.java:420)
        at 
org.apache.sshd.common.io.nio2.Nio2Session.doReadCycle(Nio2Session.java:247)
        at 
org.apache.sshd.common.io.nio2.Nio2Session$2.onCompleted(Nio2Session.java:224)
        at 
org.apache.sshd.common.io.nio2.Nio2Session$2.onCompleted(Nio2Session.java:212)
        at 
org.apache.sshd.common.io.nio2.Nio2CompletionHandler$1.run(Nio2CompletionHandler.java:34)
        at java.security.AccessController.doPrivileged(Native Method)
        at 
org.apache.sshd.common.io.nio2.Nio2CompletionHandler.completed(Nio2CompletionHandler.java:31)
        at sun.nio.ch.Invoker.invokeUnchecked(Invoker.java:126)
        at sun.nio.ch.Invoker.invokeDirect(Invoker.java:157)
        at 
sun.nio.ch.UnixAsynchronousSocketChannelImpl.implRead(UnixAsynchronousSocketChannelImpl.java:553)
        at 
sun.nio.ch.AsynchronousSocketChannelImpl.read(AsynchronousSocketChannelImpl.java:276)
        at 
sun.nio.ch.AsynchronousSocketChannelImpl.read(AsynchronousSocketChannelImpl.java:297)
        at 
java.nio.channels.AsynchronousSocketChannel.read(AsynchronousSocketChannel.java:420)
        at 
org.apache.sshd.common.io.nio2.Nio2Session.doReadCycle(Nio2Session.java:247)
        at 
org.apache.sshd.common.io.nio2.Nio2Session$2.onCompleted(Nio2Session.java:224)
        at 
org.apache.sshd.common.io.nio2.Nio2Session$2.onCompleted(Nio2Session.java:212)
        at 
org.apache.sshd.common.io.nio2.Nio2CompletionHandler$1.run(Nio2CompletionHandler.java:34)
        at java.security.AccessController.doPrivileged(Native Method)
        at 
org.apache.sshd.common.io.nio2.Nio2CompletionHandler.completed(Nio2CompletionHandler.java:31)
        at sun.nio.ch.Invoker.invokeUnchecked(Invoker.java:126)
        at sun.nio.ch.Invoker.invokeDirect(Invoker.java:157)
        at 
sun.nio.ch.UnixAsynchronousSocketChannelImpl.implRead(UnixAsynchronousSocketChannelImpl.java:553)
        at 
sun.nio.ch.AsynchronousSocketChannelImpl.read(AsynchronousSocketChannelImpl.java:276)
        at 
sun.nio.ch.AsynchronousSocketChannelImpl.read(AsynchronousSocketChannelImpl.java:297)
        at 
java.nio.channels.AsynchronousSocketChannel.read(AsynchronousSocketChannel.java:420)
        at 
org.apache.sshd.common.io.nio2.Nio2Session.doReadCycle(Nio2Session.java:247)
        at 
org.apache.sshd.common.io.nio2.Nio2Session$2.onCompleted(Nio2Session.java:224)
        at 
org.apache.sshd.common.io.nio2.Nio2Session$2.onCompleted(Nio2Session.java:212)
        at 
org.apache.sshd.common.io.nio2.Nio2CompletionHandler$1.run(Nio2CompletionHandler.java:34)
        at java.security.AccessController.doPrivileged(Native Method)
        at 
org.apache.sshd.common.io.nio2.Nio2CompletionHandler.completed(Nio2CompletionHandler.java:31)
        at sun.nio.ch.Invoker.invokeUnchecked(Invoker.java:126)
        at sun.nio.ch.Invoker.invokeDirect(Invoker.java:157)
        at 
sun.nio.ch.UnixAsynchronousSocketChannelImpl.implRead(UnixAsynchronousSocketChannelImpl.java:553)
        at 
sun.nio.ch.AsynchronousSocketChannelImpl.read(AsynchronousSocketChannelImpl.java:276)
        at 
sun.nio.ch.AsynchronousSocketChannelImpl.read(AsynchronousSocketChannelImpl.java:297)
        at 
java.nio.channels.AsynchronousSocketChannel.read(AsynchronousSocketChannel.java:420)
        at 
org.apache.sshd.common.io.nio2.Nio2Session.doReadCycle(Nio2Session.java:247)
        at 
org.apache.sshd.common.io.nio2.Nio2Session$2.onCompleted(Nio2Session.java:224)
        at 
org.apache.sshd.common.io.nio2.Nio2Session$2.onCompleted(Nio2Session.java:212)
        at 
org.apache.sshd.common.io.nio2.Nio2CompletionHandler$1.run(Nio2CompletionHandler.java:34)
        at java.security.AccessController.doPrivileged(Native Method)
        at 
org.apache.sshd.common.io.nio2.Nio2CompletionHandler.completed(Nio2CompletionHandler.java:31)
        at sun.nio.ch.Invoker.invokeUnchecked(Invoker.java:126)
        at sun.nio.ch.Invoker.invokeDirect(Invoker.java:157)
        at 
sun.nio.ch.UnixAsynchronousSocketChannelImpl.implRead(UnixAsynchronousSocketChannelImpl.java:553)
        at 
sun.nio.ch.AsynchronousSocketChannelImpl.read(AsynchronousSocketChannelImpl.java:276)
        at 
sun.nio.ch.AsynchronousSocketChannelImpl.read(AsynchronousSocketChannelImpl.java:297)
        at 
java.nio.channels.AsynchronousSocketChannel.read(AsynchronousSocketChannel.java:420)
        at 
org.apache.sshd.common.io.nio2.Nio2Session.doReadCycle(Nio2Session.java:247)
        at 
org.apache.sshd.common.io.nio2.Nio2Session$2.onCompleted(Nio2Session.java:224)
        at 
org.apache.sshd.common.io.nio2.Nio2Session$2.onCompleted(Nio2Session.java:212)
        at 
org.apache.sshd.common.io.nio2.Nio2CompletionHandler$1.run(Nio2CompletionHandler.java:34)
        at java.security.AccessController.doPrivileged(Native Method)
        at 
org.apache.sshd.common.io.nio2.Nio2CompletionHandler.completed(Nio2CompletionHandler.java:31)
        at sun.nio.ch.Invoker.invokeUnchecked(Invoker.java:126)
        at sun.nio.ch.Invoker.invokeDirect(Invoker.java:157)
        at 
sun.nio.ch.UnixAsynchronousSocketChannelImpl.implRead(UnixAsynchronousSocketChannelImpl.java:553)
        at 
sun.nio.ch.AsynchronousSocketChannelImpl.read(AsynchronousSocketChannelImpl.java:276)
        at 
sun.nio.ch.AsynchronousSocketChannelImpl.read(AsynchronousSocketChannelImpl.java:297)
        at 
java.nio.channels.AsynchronousSocketChannel.read(AsynchronousSocketChannel.java:420)
        at 
org.apache.sshd.common.io.nio2.Nio2Session.doReadCycle(Nio2Session.java:247)
        at 
org.apache.sshd.common.io.nio2.Nio2Session$2.onCompleted(Nio2Session.java:224)
        at 
org.apache.sshd.common.io.nio2.Nio2Session$2.onCompleted(Nio2Session.java:212)
        at 
org.apache.sshd.common.io.nio2.Nio2CompletionHandler$1.run(Nio2CompletionHandler.java:34)
        at java.security.AccessController.doPrivileged(Native Method)
        at 
org.apache.sshd.common.io.nio2.Nio2CompletionHandler.completed(Nio2CompletionHandler.java:31)
        at sun.nio.ch.Invoker.invokeUnchecked(Invoker.java:126)
        at sun.nio.ch.Invoker.invokeDirect(Invoker.java:157)
        at 
sun.nio.ch.UnixAsynchronousSocketChannelImpl.implRead(UnixAsynchronousSocketChannelImpl.java:553)
        at 
sun.nio.ch.AsynchronousSocketChannelImpl.read(AsynchronousSocketChannelImpl.java:276)
        at 
sun.nio.ch.AsynchronousSocketChannelImpl.read(AsynchronousSocketChannelImpl.java:297)
        at 
java.nio.channels.AsynchronousSocketChannel.read(AsynchronousSocketChannel.java:420)
        at 
org.apache.sshd.common.io.nio2.Nio2Session.doReadCycle(Nio2Session.java:247)
        at 
org.apache.sshd.common.io.nio2.Nio2Session$2.onCompleted(Nio2Session.java:224)
        at 
org.apache.sshd.common.io.nio2.Nio2Session$2.onCompleted(Nio2Session.java:212)
        at 
org.apache.sshd.common.io.nio2.Nio2CompletionHandler$1.run(Nio2CompletionHandler.java:34)
        at java.security.AccessController.doPrivileged(Native Method)
        at 
org.apache.sshd.common.io.nio2.Nio2CompletionHandler.completed(Nio2CompletionHandler.java:31)
        at sun.nio.ch.Invoker.invokeUnchecked(Invoker.java:126)
        at sun.nio.ch.Invoker.invokeDirect(Invoker.java:157)
        at 
sun.nio.ch.UnixAsynchronousSocketChannelImpl.implRead(UnixAsynchronousSocketChannelImpl.java:553)
        at 
sun.nio.ch.AsynchronousSocketChannelImpl.read(AsynchronousSocketChannelImpl.java:276)
        at 
sun.nio.ch.AsynchronousSocketChannelImpl.read(AsynchronousSocketChannelImpl.java:297)
        at 
java.nio.channels.AsynchronousSocketChannel.read(AsynchronousSocketChannel.java:420)
        at 
org.apache.sshd.common.io.nio2.Nio2Session.doReadCycle(Nio2Session.java:247)
        at 
org.apache.sshd.common.io.nio2.Nio2Session$2.onCompleted(Nio2Session.java:224)
        at 
org.apache.sshd.common.io.nio2.Nio2Session$2.onCompleted(Nio2Session.java:212)
        at 
org.apache.sshd.common.io.nio2.Nio2CompletionHandler$1.run(Nio2CompletionHandler.java:34)
        at java.security.AccessController.doPrivileged(Native Method)
        at 
org.apache.sshd.common.io.nio2.Nio2CompletionHandler.completed(Nio2CompletionHandler.java:31)
        at sun.nio.ch.Invoker.invokeUnchecked(Invoker.java:126)
        at sun.nio.ch.Invoker.invokeDirect(Invoker.java:157)
        at 
sun.nio.ch.UnixAsynchronousSocketChannelImpl.implRead(UnixAsynchronousSocketChannelImpl.java:553)
        at 
sun.nio.ch.AsynchronousSocketChannelImpl.read(AsynchronousSocketChannelImpl.java:276)
        at 
sun.nio.ch.AsynchronousSocketChannelImpl.read(AsynchronousSocketChannelImpl.java:297)
        at 
java.nio.channels.AsynchronousSocketChannel.read(AsynchronousSocketChannel.java:420)
        at 
org.apache.sshd.common.io.nio2.Nio2Session.doReadCycle(Nio2Session.java:247)
        at 
org.apache.sshd.common.io.nio2.Nio2Session$2.onCompleted(Nio2Session.java:224)
        at 
org.apache.sshd.common.io.nio2.Nio2Session$2.onCompleted(Nio2Session.java:212)
        at 
org.apache.sshd.common.io.nio2.Nio2CompletionHandler$1.run(Nio2CompletionHandler.java:34)
        at java.security.AccessController.doPrivileged(Native Method)
        at 
org.apache.sshd.common.io.nio2.Nio2CompletionHandler.completed(Nio2CompletionHandler.java:31)
        at sun.nio.ch.Invoker.invokeUnchecked(Invoker.java:126)
        at sun.nio.ch.Invoker$2.run(Invoker.java:218)
        at 
sun.nio.ch.AsynchronousChannelGroupImpl$1.run(AsynchronousChannelGroupImpl.java:112)
        at 
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
        at 
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
        at java.lang.Thread.run(Thread.java:745)
{noformat}

These are the steps to reproduce:
# Start up approximately 200 separate SSH sessions with one local forward to an 
HTTP server:
{{ssh -N -LXXXXX:<HTTP_SERVER>:80 account@<MINA_SSHD_SERVER>}}
## To simplify this process, I modified 
[org.apache.sshd.server.auth.AbstractUserAuth|^AbstractUserAuth.java] to always 
accept requests - this makes it possible to create the sessions on the same 
client (though I've also reproduced this on separate clients as well).
## This [script|^setup-tunnels.sh] will setup the client sessions as background 
processes
# With the above sessions alive and backgrounded, fetch large files 
concurrently from the HTTP server over multiple forwarded ports:
{{wget http://localhost:XXXXX/hugefile}}
## This [script|^ssh-load.sh] will start {{wget}} downloads in the above manner.
# After a time, the {{wget}} downloads will stop progressing, and inspection of 
the SSH server process via {{jstack <PID>}} will show each of the 
{{nio2-thread-[0-9]}} threads in the deadlocked state.

Note: I previously filed SSHD-539 on this, and have since reproduced it on 
vanilla MINA SSHD-Core without our proprietary modifications.

The JAR files I used to reproduced are attached to this ticket as well.



--
This message was sent by Atlassian JIRA
(v6.3.4#6332)

Reply via email to