[jira] [Comment Edited] (SSHD-939) SSH threads get blocked in Object.wait() method forever resulting in CLOSE_WAIT connections
[
https://issues.apache.org/jira/browse/SSHD-939?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel=16927711#comment-16927711
]
Anudeep edited comment on SSHD-939 at 9/11/19 4:00 PM:
---
Please answer above questions just for the understanding and then you can
proceed with the closure.
was (Author: anudeepgangasani):
Please answer below and then you can proceed with the closure.
> SSH threads get blocked in Object.wait() method forever resulting in
> CLOSE_WAIT connections
> ---
>
> Key: SSHD-939
> URL: https://issues.apache.org/jira/browse/SSHD-939
> Project: MINA SSHD
> Issue Type: Bug
>Affects Versions: 0.13.0
>Reporter: Anudeep
>Assignee: Goldstein Lyor
>Priority: Major
> Attachments: svc-1-bnsiserv_06_09_2019-server.7z,
> svc-1-bnsiserv_thread.log
>
>
> Ssh threads get blocked in object.wait() for ever and if the count of such
> threads crosses 3 no more ssh requests are served.
> We had an analysis of the logs and from the thread model of apache we see the
> maximum number of I/O threads is number of cores +1 in our server the number
> of cores is 2.
> SO after three such blocked threads we are not able to open any new ssh
> connection.
> Can you please confirm if the above logic is correct .
>
> We too found a ticket raised in 0.14.0
> (https://issues.apache.org/jira/browse/SSHD-348)which says threads in blocked
> state are fixed with 0.14.0 so we need a confirmation from you if 0.14.0 will
> fix the threads to be released and do not hung the process even if there are
> more than 3 of such a kind.
>
> Logs from thread dumps
> {code:java}
> From the thread dump it looks like we have a deadlock, e.g.
> In one thread we're trying to send out data on an SSH connection, but we're
> waiting for "space"
> "pool-7-thread-2213" #2677 prio=5 os_prio=0 tid=0x7f85554cc800 nid=0x61e3
> in Object.wait() [0x7f84ea29f000]
> 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.apache.sshd.common.channel.Window.waitForSpace(Window.java:148)
> - locked <0x000764942ad8> (a
> org.apache.sshd.common.channel.Window)
> at
> org.apache.sshd.common.channel.ChannelOutputStream.flush(ChannelOutputStream.java:116)
> - eliminated <0x000764942c20> (a
> org.apache.sshd.common.channel.ChannelOutputStream)
> at
> org.apache.sshd.common.channel.ChannelOutputStream.write(ChannelOutputStream.java:84)
> - locked <0x000764942c20> (a
> org.apache.sshd.common.channel.ChannelOutputStream)
> at sun.nio.cs.StreamEncoder.writeBytes(StreamEncoder.java:221)
> at sun.nio.cs.StreamEncoder.implWrite(StreamEncoder.java:282)
> at sun.nio.cs.StreamEncoder.write(StreamEncoder.java:125)
> - locked <0x000764943500> (a java.io.OutputStreamWriter)
> at java.io.OutputStreamWriter.write(OutputStreamWriter.java:207)
> at java.io.BufferedWriter.write(BufferedWriter.java:188)
> - locked <0x000764943500> (a java.io.OutputStreamWriter)
> at java.io.PrintWriter.write(PrintWriter.java:426)
> - locked <0x0007649434d8> (a java.io.BufferedWriter)
> at java.io.PrintWriter.write(PrintWriter.java:443)
> In another thread, we trying to close the same connection
> "sshd-SshServer[1ae27e4e]-nio2-thread-3" #356 prio=5 os_prio=0
> tid=0x015f6000 nid=0x30b8 waiting for monitor entry
> [0x7f851ab9c000]
> java.lang.Thread.State: BLOCKED (on object monitor)
> at
> org.apache.sshd.common.channel.ChannelOutputStream.close(ChannelOutputStream.java:146)
> - waiting to lock <0x000764942c20> (a
> org.apache.sshd.common.channel.ChannelOutputStream)
> at
> com.ericsson.oss.nbi.connection.ssh.SshCommandContext.shutdown(SshCommandContext.java:146)
> at
> com.ericsson.oss.nbi.connection.ssh.SshCommand$ContextStarter.shutdown(SshCommand.java:104)
> at
> com.ericsson.oss.nbi.connection.ssh.SshCommand.destroy(SshCommand.java:78)
> at
> org.apache.sshd.server.channel.ChannelSession.doCloseImmediately(ChannelSession.java:242)
> at
> org.apache.sshd.common.util.CloseableUtils$AbstractCloseable.close(CloseableUtils.java:276)
> at
> org.apache.sshd.common.util.CloseableUtils$ParallelCloseable.doClose(CloseableUtils.java:182)
> at
> org.apache.sshd.common.util.CloseableUtils$SimpleCloseable.close(CloseableUtils.java:151)
> at
> org.apache.sshd.common.io.nio2.Nio2Session$1.onFailed(Nio2Session.java:199)
> at
> org.apache.sshd.common.io.nio2.Nio2CompletionHandler$2.run(Nio2CompletionHandler.java:41)
> at
[jira] [Reopened] (SSHD-939) SSH threads get blocked in Object.wait() method forever resulting in CLOSE_WAIT connections
[
https://issues.apache.org/jira/browse/SSHD-939?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
Anudeep reopened SSHD-939:
--
Please answer below and then you can proceed with the closure.
> SSH threads get blocked in Object.wait() method forever resulting in
> CLOSE_WAIT connections
> ---
>
> Key: SSHD-939
> URL: https://issues.apache.org/jira/browse/SSHD-939
> Project: MINA SSHD
> Issue Type: Bug
>Affects Versions: 0.13.0
>Reporter: Anudeep
>Assignee: Goldstein Lyor
>Priority: Major
> Attachments: svc-1-bnsiserv_06_09_2019-server.7z,
> svc-1-bnsiserv_thread.log
>
>
> Ssh threads get blocked in object.wait() for ever and if the count of such
> threads crosses 3 no more ssh requests are served.
> We had an analysis of the logs and from the thread model of apache we see the
> maximum number of I/O threads is number of cores +1 in our server the number
> of cores is 2.
> SO after three such blocked threads we are not able to open any new ssh
> connection.
> Can you please confirm if the above logic is correct .
>
> We too found a ticket raised in 0.14.0
> (https://issues.apache.org/jira/browse/SSHD-348)which says threads in blocked
> state are fixed with 0.14.0 so we need a confirmation from you if 0.14.0 will
> fix the threads to be released and do not hung the process even if there are
> more than 3 of such a kind.
>
> Logs from thread dumps
> {code:java}
> From the thread dump it looks like we have a deadlock, e.g.
> In one thread we're trying to send out data on an SSH connection, but we're
> waiting for "space"
> "pool-7-thread-2213" #2677 prio=5 os_prio=0 tid=0x7f85554cc800 nid=0x61e3
> in Object.wait() [0x7f84ea29f000]
> 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.apache.sshd.common.channel.Window.waitForSpace(Window.java:148)
> - locked <0x000764942ad8> (a
> org.apache.sshd.common.channel.Window)
> at
> org.apache.sshd.common.channel.ChannelOutputStream.flush(ChannelOutputStream.java:116)
> - eliminated <0x000764942c20> (a
> org.apache.sshd.common.channel.ChannelOutputStream)
> at
> org.apache.sshd.common.channel.ChannelOutputStream.write(ChannelOutputStream.java:84)
> - locked <0x000764942c20> (a
> org.apache.sshd.common.channel.ChannelOutputStream)
> at sun.nio.cs.StreamEncoder.writeBytes(StreamEncoder.java:221)
> at sun.nio.cs.StreamEncoder.implWrite(StreamEncoder.java:282)
> at sun.nio.cs.StreamEncoder.write(StreamEncoder.java:125)
> - locked <0x000764943500> (a java.io.OutputStreamWriter)
> at java.io.OutputStreamWriter.write(OutputStreamWriter.java:207)
> at java.io.BufferedWriter.write(BufferedWriter.java:188)
> - locked <0x000764943500> (a java.io.OutputStreamWriter)
> at java.io.PrintWriter.write(PrintWriter.java:426)
> - locked <0x0007649434d8> (a java.io.BufferedWriter)
> at java.io.PrintWriter.write(PrintWriter.java:443)
> In another thread, we trying to close the same connection
> "sshd-SshServer[1ae27e4e]-nio2-thread-3" #356 prio=5 os_prio=0
> tid=0x015f6000 nid=0x30b8 waiting for monitor entry
> [0x7f851ab9c000]
> java.lang.Thread.State: BLOCKED (on object monitor)
> at
> org.apache.sshd.common.channel.ChannelOutputStream.close(ChannelOutputStream.java:146)
> - waiting to lock <0x000764942c20> (a
> org.apache.sshd.common.channel.ChannelOutputStream)
> at
> com.ericsson.oss.nbi.connection.ssh.SshCommandContext.shutdown(SshCommandContext.java:146)
> at
> com.ericsson.oss.nbi.connection.ssh.SshCommand$ContextStarter.shutdown(SshCommand.java:104)
> at
> com.ericsson.oss.nbi.connection.ssh.SshCommand.destroy(SshCommand.java:78)
> at
> org.apache.sshd.server.channel.ChannelSession.doCloseImmediately(ChannelSession.java:242)
> at
> org.apache.sshd.common.util.CloseableUtils$AbstractCloseable.close(CloseableUtils.java:276)
> at
> org.apache.sshd.common.util.CloseableUtils$ParallelCloseable.doClose(CloseableUtils.java:182)
> at
> org.apache.sshd.common.util.CloseableUtils$SimpleCloseable.close(CloseableUtils.java:151)
> at
> org.apache.sshd.common.io.nio2.Nio2Session$1.onFailed(Nio2Session.java:199)
> at
> org.apache.sshd.common.io.nio2.Nio2CompletionHandler$2.run(Nio2CompletionHandler.java:41)
> at java.security.AccessController.doPrivileged(Native Method)
> at
> org.apache.sshd.common.io.nio2.Nio2CompletionHandler.failed(Nio2CompletionHandler.java:39)
> at
>
[jira] [Commented] (SSHD-939) SSH threads get blocked in Object.wait() method forever resulting in CLOSE_WAIT connections
[
https://issues.apache.org/jira/browse/SSHD-939?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel=16927710#comment-16927710
]
Anudeep commented on SSHD-939:
--
Hi [~lgoldstein] ,
Its ok ,we suppose to get back to you for help if we face some hurdles in
uplifting.
One last question which we do not understand from logs is invalid length.
Is there a way to decode it .The log in Abstract session prints the encrypted
packet length /actual packet length ?
Below one
// Read packet length decoderLength = decoderBuffer.getInt();
{code:java}
for (;;) {
// Wait for beginning of packet
if (decoderState == 0) {
// The read position should always be 0 at this point because
we have compacted this buffer
assert decoderBuffer.rpos() == 0;
// If we have received enough bytes, start processing those
if (decoderBuffer.available() > inCipherSize) {
// Decrypt the first bytes
if (inCipher != null) {
inCipher.update(decoderBuffer.array(), 0, inCipherSize);
}
// Read packet length
decoderLength = decoderBuffer.getInt();
// Check packet length validity
if (decoderLength < 5 || decoderLength > (256 * 1024)) {
log.info("Error decoding packet (invalid length) {}",
decoderBuffer.printHex());
throw new
SshException(SshConstants.SSH2_DISCONNECT_PROTOCOL_ERROR,
"Invalid packet length: " +
decoderLength);
}
// Ok, that's good, we can go to the next step
decoderState = 1;
} else {
// need more data
break;
} {code}
Why we ask is the previous log before invalid length says it has read 184 bytes
and in the exception we see it as some long negative integer and even some
times a long positive integer.
{code:java}
2019-08-22 09:53:29,106 DEBUG [org.apache.sshd.common.io.nio2.Nio2Session]
(sshd-SshServer[6162dce4]-nio2-th
read-2) Read 184 bytes
2019-08-22 09:53:29,106 INFO [org.apache.sshd.server.session.ServerSession]
(sshd-SshServer[6162dce4]-nio2-
thread-2) Error decoding packet (invalid length) a5 5f 74 5f a6 6f ea 41 02 c0
0a 54 83 22 e4 77 53 7d 0d b9
25 de 36 1d 07 cb cd 43 66 95 51 b2 72 54 d5 4e 2d 0a d5 17 f4 5e 81 4d 6a b8
ab f7 00 bf 4d 40 f5 56 b7 61
9b 8a be fe 54 d4 89 a2 c5 07 3c de 25 95 44 18 4f 90 dc aa 5b de 40 85 71 12
cc f6 c0 34 8d 0e 75 95 a5 5b
8d f6 b9 f6 94 04 d8 b5 25 5c d5 58 06 d1 82 68 13 2f 4c a0 ee 78 6b 20 97 52
2d 93 4c 88 bc 17 53 ca eb 34
23 c1 c6 1e 5a f9 31 e7 52 f9 ef 88 03 de e8 af ba 11 5e 97 50 1e c2 26 ba 80
34 55 3f 38 49 0c a9 80 8c a3
fe 6f b6 b6 5d 45 41 e9 e0 e6 d5 15 d6 44 f8 c4
2019-08-22 09:53:29,106 DEBUG [org.apache.sshd.common.io.nio2.Nio2Session]
(sshd-SshServer[6162dce4]-nio2-th
read-2) Caught exception, now calling handler
2019-08-22 09:53:29,106 WARN [org.apache.sshd.server.session.ServerSession]
(sshd-SshServer[6162dce4]-nio2-
thread-2) Exception caught: org.apache.sshd.common.SshException: Invalid packet
length: -16976455
at
org.apache.sshd.common.session.AbstractSession.decode(AbstractSession.java:677)
[sshd-core-0.13.0
.jar:0.13.0]
{code}
Please let us know if there is way to know what has caused this invalid length.
Regards,
Anudeep
> SSH threads get blocked in Object.wait() method forever resulting in
> CLOSE_WAIT connections
> ---
>
> Key: SSHD-939
> URL: https://issues.apache.org/jira/browse/SSHD-939
> Project: MINA SSHD
> Issue Type: Bug
>Affects Versions: 0.13.0
>Reporter: Anudeep
>Assignee: Goldstein Lyor
>Priority: Major
> Attachments: svc-1-bnsiserv_06_09_2019-server.7z,
> svc-1-bnsiserv_thread.log
>
>
> Ssh threads get blocked in object.wait() for ever and if the count of such
> threads crosses 3 no more ssh requests are served.
> We had an analysis of the logs and from the thread model of apache we see the
> maximum number of I/O threads is number of cores +1 in our server the number
> of cores is 2.
> SO after three such blocked threads we are not able to open any new ssh
> connection.
> Can you please confirm if the above logic is correct .
>
> We too found a ticket raised in 0.14.0
> (https://issues.apache.org/jira/browse/SSHD-348)which says threads in blocked
> state are fixed with 0.14.0 so we need a confirmation from you if 0.14.0 will
> fix the threads to be released and do not hung the process even if there are
> more than 3 of such a kind.
>
> Logs from thread dumps
>
[jira] [Closed] (SSHD-939) SSH threads get blocked in Object.wait() method forever resulting in CLOSE_WAIT connections
[
https://issues.apache.org/jira/browse/SSHD-939?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
Goldstein Lyor closed SSHD-939.
---
Assignee: Goldstein Lyor
Resolution: Won't Fix
> SSH threads get blocked in Object.wait() method forever resulting in
> CLOSE_WAIT connections
> ---
>
> Key: SSHD-939
> URL: https://issues.apache.org/jira/browse/SSHD-939
> Project: MINA SSHD
> Issue Type: Bug
>Affects Versions: 0.13.0
>Reporter: Anudeep
>Assignee: Goldstein Lyor
>Priority: Major
> Attachments: svc-1-bnsiserv_06_09_2019-server.7z,
> svc-1-bnsiserv_thread.log
>
>
> Ssh threads get blocked in object.wait() for ever and if the count of such
> threads crosses 3 no more ssh requests are served.
> We had an analysis of the logs and from the thread model of apache we see the
> maximum number of I/O threads is number of cores +1 in our server the number
> of cores is 2.
> SO after three such blocked threads we are not able to open any new ssh
> connection.
> Can you please confirm if the above logic is correct .
>
> We too found a ticket raised in 0.14.0
> (https://issues.apache.org/jira/browse/SSHD-348)which says threads in blocked
> state are fixed with 0.14.0 so we need a confirmation from you if 0.14.0 will
> fix the threads to be released and do not hung the process even if there are
> more than 3 of such a kind.
>
> Logs from thread dumps
> {code:java}
> From the thread dump it looks like we have a deadlock, e.g.
> In one thread we're trying to send out data on an SSH connection, but we're
> waiting for "space"
> "pool-7-thread-2213" #2677 prio=5 os_prio=0 tid=0x7f85554cc800 nid=0x61e3
> in Object.wait() [0x7f84ea29f000]
> 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.apache.sshd.common.channel.Window.waitForSpace(Window.java:148)
> - locked <0x000764942ad8> (a
> org.apache.sshd.common.channel.Window)
> at
> org.apache.sshd.common.channel.ChannelOutputStream.flush(ChannelOutputStream.java:116)
> - eliminated <0x000764942c20> (a
> org.apache.sshd.common.channel.ChannelOutputStream)
> at
> org.apache.sshd.common.channel.ChannelOutputStream.write(ChannelOutputStream.java:84)
> - locked <0x000764942c20> (a
> org.apache.sshd.common.channel.ChannelOutputStream)
> at sun.nio.cs.StreamEncoder.writeBytes(StreamEncoder.java:221)
> at sun.nio.cs.StreamEncoder.implWrite(StreamEncoder.java:282)
> at sun.nio.cs.StreamEncoder.write(StreamEncoder.java:125)
> - locked <0x000764943500> (a java.io.OutputStreamWriter)
> at java.io.OutputStreamWriter.write(OutputStreamWriter.java:207)
> at java.io.BufferedWriter.write(BufferedWriter.java:188)
> - locked <0x000764943500> (a java.io.OutputStreamWriter)
> at java.io.PrintWriter.write(PrintWriter.java:426)
> - locked <0x0007649434d8> (a java.io.BufferedWriter)
> at java.io.PrintWriter.write(PrintWriter.java:443)
> In another thread, we trying to close the same connection
> "sshd-SshServer[1ae27e4e]-nio2-thread-3" #356 prio=5 os_prio=0
> tid=0x015f6000 nid=0x30b8 waiting for monitor entry
> [0x7f851ab9c000]
> java.lang.Thread.State: BLOCKED (on object monitor)
> at
> org.apache.sshd.common.channel.ChannelOutputStream.close(ChannelOutputStream.java:146)
> - waiting to lock <0x000764942c20> (a
> org.apache.sshd.common.channel.ChannelOutputStream)
> at
> com.ericsson.oss.nbi.connection.ssh.SshCommandContext.shutdown(SshCommandContext.java:146)
> at
> com.ericsson.oss.nbi.connection.ssh.SshCommand$ContextStarter.shutdown(SshCommand.java:104)
> at
> com.ericsson.oss.nbi.connection.ssh.SshCommand.destroy(SshCommand.java:78)
> at
> org.apache.sshd.server.channel.ChannelSession.doCloseImmediately(ChannelSession.java:242)
> at
> org.apache.sshd.common.util.CloseableUtils$AbstractCloseable.close(CloseableUtils.java:276)
> at
> org.apache.sshd.common.util.CloseableUtils$ParallelCloseable.doClose(CloseableUtils.java:182)
> at
> org.apache.sshd.common.util.CloseableUtils$SimpleCloseable.close(CloseableUtils.java:151)
> at
> org.apache.sshd.common.io.nio2.Nio2Session$1.onFailed(Nio2Session.java:199)
> at
> org.apache.sshd.common.io.nio2.Nio2CompletionHandler$2.run(Nio2CompletionHandler.java:41)
> at java.security.AccessController.doPrivileged(Native Method)
> at
> org.apache.sshd.common.io.nio2.Nio2CompletionHandler.failed(Nio2CompletionHandler.java:39)
> at
>
[jira] [Commented] (SSHD-939) SSH threads get blocked in Object.wait() method forever resulting in CLOSE_WAIT connections
[
https://issues.apache.org/jira/browse/SSHD-939?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel=16927636#comment-16927636
]
Goldstein Lyor commented on SSHD-939:
-
There were indeed a +few+ issues with synchronization and locking - not just
the one you mentioned. Again, the version you are using (0.13.0) and the one
you mention as having "solved" this issue (0.14.0) are extremely old. As
mentioned in the past, due to the very limited R resources at our disposal
(~1.5 volunteers) we cannot offer backpatches - especially for such old
versions. My advice is this: please upgrade to the +latest+ version (2.3.0).
As far as using 0.14.0 that supposedly fixes this issue - I can say for sure
that it does not (since we fixed something similar in version 2.1.0). It
alleviates the condition, but there are some flows that can cause threads to
deadlock (although very rarely). Again, you seem to keep encountering issues
due to the extremely old version in use. Please (again) upgrade to latest
version and then (a) you will most likely not encounter these bugs, and (b) it
would be easier to fix new bugs that you might encounter.
> SSH threads get blocked in Object.wait() method forever resulting in
> CLOSE_WAIT connections
> ---
>
> Key: SSHD-939
> URL: https://issues.apache.org/jira/browse/SSHD-939
> Project: MINA SSHD
> Issue Type: Bug
>Affects Versions: 0.13.0
>Reporter: Anudeep
>Priority: Major
> Attachments: svc-1-bnsiserv_06_09_2019-server.7z,
> svc-1-bnsiserv_thread.log
>
>
> Ssh threads get blocked in object.wait() for ever and if the count of such
> threads crosses 3 no more ssh requests are served.
> We had an analysis of the logs and from the thread model of apache we see the
> maximum number of I/O threads is number of cores +1 in our server the number
> of cores is 2.
> SO after three such blocked threads we are not able to open any new ssh
> connection.
> Can you please confirm if the above logic is correct .
>
> We too found a ticket raised in 0.14.0
> (https://issues.apache.org/jira/browse/SSHD-348)which says threads in blocked
> state are fixed with 0.14.0 so we need a confirmation from you if 0.14.0 will
> fix the threads to be released and do not hung the process even if there are
> more than 3 of such a kind.
>
> Logs from thread dumps
> {code:java}
> From the thread dump it looks like we have a deadlock, e.g.
> In one thread we're trying to send out data on an SSH connection, but we're
> waiting for "space"
> "pool-7-thread-2213" #2677 prio=5 os_prio=0 tid=0x7f85554cc800 nid=0x61e3
> in Object.wait() [0x7f84ea29f000]
> 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.apache.sshd.common.channel.Window.waitForSpace(Window.java:148)
> - locked <0x000764942ad8> (a
> org.apache.sshd.common.channel.Window)
> at
> org.apache.sshd.common.channel.ChannelOutputStream.flush(ChannelOutputStream.java:116)
> - eliminated <0x000764942c20> (a
> org.apache.sshd.common.channel.ChannelOutputStream)
> at
> org.apache.sshd.common.channel.ChannelOutputStream.write(ChannelOutputStream.java:84)
> - locked <0x000764942c20> (a
> org.apache.sshd.common.channel.ChannelOutputStream)
> at sun.nio.cs.StreamEncoder.writeBytes(StreamEncoder.java:221)
> at sun.nio.cs.StreamEncoder.implWrite(StreamEncoder.java:282)
> at sun.nio.cs.StreamEncoder.write(StreamEncoder.java:125)
> - locked <0x000764943500> (a java.io.OutputStreamWriter)
> at java.io.OutputStreamWriter.write(OutputStreamWriter.java:207)
> at java.io.BufferedWriter.write(BufferedWriter.java:188)
> - locked <0x000764943500> (a java.io.OutputStreamWriter)
> at java.io.PrintWriter.write(PrintWriter.java:426)
> - locked <0x0007649434d8> (a java.io.BufferedWriter)
> at java.io.PrintWriter.write(PrintWriter.java:443)
> In another thread, we trying to close the same connection
> "sshd-SshServer[1ae27e4e]-nio2-thread-3" #356 prio=5 os_prio=0
> tid=0x015f6000 nid=0x30b8 waiting for monitor entry
> [0x7f851ab9c000]
> java.lang.Thread.State: BLOCKED (on object monitor)
> at
> org.apache.sshd.common.channel.ChannelOutputStream.close(ChannelOutputStream.java:146)
> - waiting to lock <0x000764942c20> (a
> org.apache.sshd.common.channel.ChannelOutputStream)
> at
> com.ericsson.oss.nbi.connection.ssh.SshCommandContext.shutdown(SshCommandContext.java:146)
> at
> com.ericsson.oss.nbi.connection.ssh.SshCommand$ContextStarter.shutdown(SshCommand.java:104)
> at
>
[jira] [Updated] (SSHD-939) SSH threads get blocked in Object.wait() method forever resulting in CLOSE_WAIT connections
[
https://issues.apache.org/jira/browse/SSHD-939?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
Anudeep updated SSHD-939:
-
Attachment: svc-1-bnsiserv_06_09_2019-server.7z
> SSH threads get blocked in Object.wait() method forever resulting in
> CLOSE_WAIT connections
> ---
>
> Key: SSHD-939
> URL: https://issues.apache.org/jira/browse/SSHD-939
> Project: MINA SSHD
> Issue Type: Bug
>Affects Versions: 0.13.0
>Reporter: Anudeep
>Priority: Major
> Attachments: svc-1-bnsiserv_06_09_2019-server.7z,
> svc-1-bnsiserv_thread.log
>
>
> Ssh threads get blocked in object.wait() for ever and if the count of such
> threads crosses 3 no more ssh requests are served.
> We had an analysis of the logs and from the thread model of apache we see the
> maximum number of I/O threads is number of cores +1 in our server the number
> of cores is 2.
> SO after three such blocked threads we are not able to open any new ssh
> connection.
> Can you please confirm if the above logic is correct .
>
> We too found a ticket raised in 0.14.0
> (https://issues.apache.org/jira/browse/SSHD-348)which says threads in blocked
> state are fixed with 0.14.0 so we need a confirmation from you if 0.14.0 will
> fix the threads to be released and do not hung the process even if there are
> more than 3 of such a kind.
>
> Logs from thread dumps
> {code:java}
> From the thread dump it looks like we have a deadlock, e.g.
> In one thread we're trying to send out data on an SSH connection, but we're
> waiting for "space"
> "pool-7-thread-2213" #2677 prio=5 os_prio=0 tid=0x7f85554cc800 nid=0x61e3
> in Object.wait() [0x7f84ea29f000]
> 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.apache.sshd.common.channel.Window.waitForSpace(Window.java:148)
> - locked <0x000764942ad8> (a
> org.apache.sshd.common.channel.Window)
> at
> org.apache.sshd.common.channel.ChannelOutputStream.flush(ChannelOutputStream.java:116)
> - eliminated <0x000764942c20> (a
> org.apache.sshd.common.channel.ChannelOutputStream)
> at
> org.apache.sshd.common.channel.ChannelOutputStream.write(ChannelOutputStream.java:84)
> - locked <0x000764942c20> (a
> org.apache.sshd.common.channel.ChannelOutputStream)
> at sun.nio.cs.StreamEncoder.writeBytes(StreamEncoder.java:221)
> at sun.nio.cs.StreamEncoder.implWrite(StreamEncoder.java:282)
> at sun.nio.cs.StreamEncoder.write(StreamEncoder.java:125)
> - locked <0x000764943500> (a java.io.OutputStreamWriter)
> at java.io.OutputStreamWriter.write(OutputStreamWriter.java:207)
> at java.io.BufferedWriter.write(BufferedWriter.java:188)
> - locked <0x000764943500> (a java.io.OutputStreamWriter)
> at java.io.PrintWriter.write(PrintWriter.java:426)
> - locked <0x0007649434d8> (a java.io.BufferedWriter)
> at java.io.PrintWriter.write(PrintWriter.java:443)
> In another thread, we trying to close the same connection
> "sshd-SshServer[1ae27e4e]-nio2-thread-3" #356 prio=5 os_prio=0
> tid=0x015f6000 nid=0x30b8 waiting for monitor entry
> [0x7f851ab9c000]
> java.lang.Thread.State: BLOCKED (on object monitor)
> at
> org.apache.sshd.common.channel.ChannelOutputStream.close(ChannelOutputStream.java:146)
> - waiting to lock <0x000764942c20> (a
> org.apache.sshd.common.channel.ChannelOutputStream)
> at
> com.ericsson.oss.nbi.connection.ssh.SshCommandContext.shutdown(SshCommandContext.java:146)
> at
> com.ericsson.oss.nbi.connection.ssh.SshCommand$ContextStarter.shutdown(SshCommand.java:104)
> at
> com.ericsson.oss.nbi.connection.ssh.SshCommand.destroy(SshCommand.java:78)
> at
> org.apache.sshd.server.channel.ChannelSession.doCloseImmediately(ChannelSession.java:242)
> at
> org.apache.sshd.common.util.CloseableUtils$AbstractCloseable.close(CloseableUtils.java:276)
> at
> org.apache.sshd.common.util.CloseableUtils$ParallelCloseable.doClose(CloseableUtils.java:182)
> at
> org.apache.sshd.common.util.CloseableUtils$SimpleCloseable.close(CloseableUtils.java:151)
> at
> org.apache.sshd.common.io.nio2.Nio2Session$1.onFailed(Nio2Session.java:199)
> at
> org.apache.sshd.common.io.nio2.Nio2CompletionHandler$2.run(Nio2CompletionHandler.java:41)
> at java.security.AccessController.doPrivileged(Native Method)
> at
> org.apache.sshd.common.io.nio2.Nio2CompletionHandler.failed(Nio2CompletionHandler.java:39)
> at
> org.apache.sshd.common.io.nio2.Nio2Session$1.onCompleted(Nio2Session.java:195)
> at
>
[jira] [Updated] (SSHD-939) SSH threads get blocked in Object.wait() method forever resulting in CLOSE_WAIT connections
[
https://issues.apache.org/jira/browse/SSHD-939?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
Anudeep updated SSHD-939:
-
Attachment: svc-1-bnsiserv_thread.log
> SSH threads get blocked in Object.wait() method forever resulting in
> CLOSE_WAIT connections
> ---
>
> Key: SSHD-939
> URL: https://issues.apache.org/jira/browse/SSHD-939
> Project: MINA SSHD
> Issue Type: Bug
>Affects Versions: 0.13.0
>Reporter: Anudeep
>Priority: Major
> Attachments: svc-1-bnsiserv_thread.log
>
>
> Ssh threads get blocked in object.wait() for ever and if the count of such
> threads crosses 3 no more ssh requests are served.
> We had an analysis of the logs and from the thread model of apache we see the
> maximum number of I/O threads is number of cores +1 in our server the number
> of cores is 2.
> SO after three such blocked threads we are not able to open any new ssh
> connection.
> Can you please confirm if the above logic is correct .
>
> We too found a ticket raised in 0.14.0
> (https://issues.apache.org/jira/browse/SSHD-348)which says threads in blocked
> state are fixed with 0.14.0 so we need a confirmation from you if 0.14.0 will
> fix the threads to be released and do not hung the process even if there are
> more than 3 of such a kind.
>
> Logs from thread dumps
> {code:java}
> From the thread dump it looks like we have a deadlock, e.g.
> In one thread we're trying to send out data on an SSH connection, but we're
> waiting for "space"
> "pool-7-thread-2213" #2677 prio=5 os_prio=0 tid=0x7f85554cc800 nid=0x61e3
> in Object.wait() [0x7f84ea29f000]
> 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.apache.sshd.common.channel.Window.waitForSpace(Window.java:148)
> - locked <0x000764942ad8> (a
> org.apache.sshd.common.channel.Window)
> at
> org.apache.sshd.common.channel.ChannelOutputStream.flush(ChannelOutputStream.java:116)
> - eliminated <0x000764942c20> (a
> org.apache.sshd.common.channel.ChannelOutputStream)
> at
> org.apache.sshd.common.channel.ChannelOutputStream.write(ChannelOutputStream.java:84)
> - locked <0x000764942c20> (a
> org.apache.sshd.common.channel.ChannelOutputStream)
> at sun.nio.cs.StreamEncoder.writeBytes(StreamEncoder.java:221)
> at sun.nio.cs.StreamEncoder.implWrite(StreamEncoder.java:282)
> at sun.nio.cs.StreamEncoder.write(StreamEncoder.java:125)
> - locked <0x000764943500> (a java.io.OutputStreamWriter)
> at java.io.OutputStreamWriter.write(OutputStreamWriter.java:207)
> at java.io.BufferedWriter.write(BufferedWriter.java:188)
> - locked <0x000764943500> (a java.io.OutputStreamWriter)
> at java.io.PrintWriter.write(PrintWriter.java:426)
> - locked <0x0007649434d8> (a java.io.BufferedWriter)
> at java.io.PrintWriter.write(PrintWriter.java:443)
> In another thread, we trying to close the same connection
> "sshd-SshServer[1ae27e4e]-nio2-thread-3" #356 prio=5 os_prio=0
> tid=0x015f6000 nid=0x30b8 waiting for monitor entry
> [0x7f851ab9c000]
> java.lang.Thread.State: BLOCKED (on object monitor)
> at
> org.apache.sshd.common.channel.ChannelOutputStream.close(ChannelOutputStream.java:146)
> - waiting to lock <0x000764942c20> (a
> org.apache.sshd.common.channel.ChannelOutputStream)
> at
> com.ericsson.oss.nbi.connection.ssh.SshCommandContext.shutdown(SshCommandContext.java:146)
> at
> com.ericsson.oss.nbi.connection.ssh.SshCommand$ContextStarter.shutdown(SshCommand.java:104)
> at
> com.ericsson.oss.nbi.connection.ssh.SshCommand.destroy(SshCommand.java:78)
> at
> org.apache.sshd.server.channel.ChannelSession.doCloseImmediately(ChannelSession.java:242)
> at
> org.apache.sshd.common.util.CloseableUtils$AbstractCloseable.close(CloseableUtils.java:276)
> at
> org.apache.sshd.common.util.CloseableUtils$ParallelCloseable.doClose(CloseableUtils.java:182)
> at
> org.apache.sshd.common.util.CloseableUtils$SimpleCloseable.close(CloseableUtils.java:151)
> at
> org.apache.sshd.common.io.nio2.Nio2Session$1.onFailed(Nio2Session.java:199)
> at
> org.apache.sshd.common.io.nio2.Nio2CompletionHandler$2.run(Nio2CompletionHandler.java:41)
> at java.security.AccessController.doPrivileged(Native Method)
> at
> org.apache.sshd.common.io.nio2.Nio2CompletionHandler.failed(Nio2CompletionHandler.java:39)
> at
> org.apache.sshd.common.io.nio2.Nio2Session$1.onCompleted(Nio2Session.java:195)
> at
>
[jira] [Created] (SSHD-939) SSH threads get blocked in Object.wait() method forever resulting in CLOSE_WAIT connections
Anudeep created SSHD-939:
Summary: SSH threads get blocked in Object.wait() method forever
resulting in CLOSE_WAIT connections
Key: SSHD-939
URL: https://issues.apache.org/jira/browse/SSHD-939
Project: MINA SSHD
Issue Type: Bug
Affects Versions: 0.13.0
Reporter: Anudeep
Ssh threads get blocked in object.wait() for ever and if the count of such
threads crosses 3 no more ssh requests are served.
We had an analysis of the logs and from the thread model of apache we see the
maximum number of I/O threads is number of cores +1 in our server the number of
cores is 2.
SO after three such blocked threads we are not able to open any new ssh
connection.
Can you please confirm if the above logic is correct .
We too found a ticket raised in 0.14.0 which says threads in blocked state are
fixed with 0.14.0 so we need a confirmation from you if 0.14.0 will fix the
threads to release and do not hung the process even if there are more than 3 of
such a kind of threads in blocked state.
Logs from thread dumps
{code:java}
>From the thread dump it looks like we have a deadlock, e.g.
In one thread we're trying to send out data on an SSH connection, but we're
waiting for "space"
"pool-7-thread-2213" #2677 prio=5 os_prio=0 tid=0x7f85554cc800 nid=0x61e3
in Object.wait() [0x7f84ea29f000]
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.apache.sshd.common.channel.Window.waitForSpace(Window.java:148)
- locked <0x000764942ad8> (a org.apache.sshd.common.channel.Window)
at
org.apache.sshd.common.channel.ChannelOutputStream.flush(ChannelOutputStream.java:116)
- eliminated <0x000764942c20> (a
org.apache.sshd.common.channel.ChannelOutputStream)
at
org.apache.sshd.common.channel.ChannelOutputStream.write(ChannelOutputStream.java:84)
- locked <0x000764942c20> (a
org.apache.sshd.common.channel.ChannelOutputStream)
at sun.nio.cs.StreamEncoder.writeBytes(StreamEncoder.java:221)
at sun.nio.cs.StreamEncoder.implWrite(StreamEncoder.java:282)
at sun.nio.cs.StreamEncoder.write(StreamEncoder.java:125)
- locked <0x000764943500> (a java.io.OutputStreamWriter)
at java.io.OutputStreamWriter.write(OutputStreamWriter.java:207)
at java.io.BufferedWriter.write(BufferedWriter.java:188)
- locked <0x000764943500> (a java.io.OutputStreamWriter)
at java.io.PrintWriter.write(PrintWriter.java:426)
- locked <0x0007649434d8> (a java.io.BufferedWriter)
at java.io.PrintWriter.write(PrintWriter.java:443)
In another thread, we trying to close the same connection
"sshd-SshServer[1ae27e4e]-nio2-thread-3" #356 prio=5 os_prio=0
tid=0x015f6000 nid=0x30b8 waiting for monitor entry [0x7f851ab9c000]
java.lang.Thread.State: BLOCKED (on object monitor)
at
org.apache.sshd.common.channel.ChannelOutputStream.close(ChannelOutputStream.java:146)
- waiting to lock <0x000764942c20> (a
org.apache.sshd.common.channel.ChannelOutputStream)
at
com.ericsson.oss.nbi.connection.ssh.SshCommandContext.shutdown(SshCommandContext.java:146)
at
com.ericsson.oss.nbi.connection.ssh.SshCommand$ContextStarter.shutdown(SshCommand.java:104)
at
com.ericsson.oss.nbi.connection.ssh.SshCommand.destroy(SshCommand.java:78)
at
org.apache.sshd.server.channel.ChannelSession.doCloseImmediately(ChannelSession.java:242)
at
org.apache.sshd.common.util.CloseableUtils$AbstractCloseable.close(CloseableUtils.java:276)
at
org.apache.sshd.common.util.CloseableUtils$ParallelCloseable.doClose(CloseableUtils.java:182)
at
org.apache.sshd.common.util.CloseableUtils$SimpleCloseable.close(CloseableUtils.java:151)
at
org.apache.sshd.common.io.nio2.Nio2Session$1.onFailed(Nio2Session.java:199)
at
org.apache.sshd.common.io.nio2.Nio2CompletionHandler$2.run(Nio2CompletionHandler.java:41)
at java.security.AccessController.doPrivileged(Native Method)
at
org.apache.sshd.common.io.nio2.Nio2CompletionHandler.failed(Nio2CompletionHandler.java:39)
at
org.apache.sshd.common.io.nio2.Nio2Session$1.onCompleted(Nio2Session.java:195)
at
org.apache.sshd.common.io.nio2.Nio2Session$1.onCompleted(Nio2Session.java:170)
at
org.apache.sshd.common.io.nio2.Nio2CompletionHandler$1.run(Nio2CompletionHandler.java:32)
at java.security.AccessController.doPrivileged(Native Method)
at
org.apache.sshd.common.io.nio2.Nio2CompletionHandler.completed(Nio2CompletionHandler.java:30)
at sun.nio.ch.Invoker.invokeUnchecked(Invoker.java:126)
at sun.nio.ch.Invoker$2.run(Invoker.java:218)
at
[jira] [Updated] (SSHD-939) SSH threads get blocked in Object.wait() method forever resulting in CLOSE_WAIT connections
[
https://issues.apache.org/jira/browse/SSHD-939?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
Anudeep updated SSHD-939:
-
Description:
Ssh threads get blocked in object.wait() for ever and if the count of such
threads crosses 3 no more ssh requests are served.
We had an analysis of the logs and from the thread model of apache we see the
maximum number of I/O threads is number of cores +1 in our server the number of
cores is 2.
SO after three such blocked threads we are not able to open any new ssh
connection.
Can you please confirm if the above logic is correct .
We too found a ticket raised in 0.14.0
(https://issues.apache.org/jira/browse/SSHD-348)which says threads in blocked
state are fixed with 0.14.0 so we need a confirmation from you if 0.14.0 will
fix the threads to be released and do not hung the process even if there are
more than 3 of such a kind.
Logs from thread dumps
{code:java}
>From the thread dump it looks like we have a deadlock, e.g.
In one thread we're trying to send out data on an SSH connection, but we're
waiting for "space"
"pool-7-thread-2213" #2677 prio=5 os_prio=0 tid=0x7f85554cc800 nid=0x61e3
in Object.wait() [0x7f84ea29f000]
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.apache.sshd.common.channel.Window.waitForSpace(Window.java:148)
- locked <0x000764942ad8> (a org.apache.sshd.common.channel.Window)
at
org.apache.sshd.common.channel.ChannelOutputStream.flush(ChannelOutputStream.java:116)
- eliminated <0x000764942c20> (a
org.apache.sshd.common.channel.ChannelOutputStream)
at
org.apache.sshd.common.channel.ChannelOutputStream.write(ChannelOutputStream.java:84)
- locked <0x000764942c20> (a
org.apache.sshd.common.channel.ChannelOutputStream)
at sun.nio.cs.StreamEncoder.writeBytes(StreamEncoder.java:221)
at sun.nio.cs.StreamEncoder.implWrite(StreamEncoder.java:282)
at sun.nio.cs.StreamEncoder.write(StreamEncoder.java:125)
- locked <0x000764943500> (a java.io.OutputStreamWriter)
at java.io.OutputStreamWriter.write(OutputStreamWriter.java:207)
at java.io.BufferedWriter.write(BufferedWriter.java:188)
- locked <0x000764943500> (a java.io.OutputStreamWriter)
at java.io.PrintWriter.write(PrintWriter.java:426)
- locked <0x0007649434d8> (a java.io.BufferedWriter)
at java.io.PrintWriter.write(PrintWriter.java:443)
In another thread, we trying to close the same connection
"sshd-SshServer[1ae27e4e]-nio2-thread-3" #356 prio=5 os_prio=0
tid=0x015f6000 nid=0x30b8 waiting for monitor entry [0x7f851ab9c000]
java.lang.Thread.State: BLOCKED (on object monitor)
at
org.apache.sshd.common.channel.ChannelOutputStream.close(ChannelOutputStream.java:146)
- waiting to lock <0x000764942c20> (a
org.apache.sshd.common.channel.ChannelOutputStream)
at
com.ericsson.oss.nbi.connection.ssh.SshCommandContext.shutdown(SshCommandContext.java:146)
at
com.ericsson.oss.nbi.connection.ssh.SshCommand$ContextStarter.shutdown(SshCommand.java:104)
at
com.ericsson.oss.nbi.connection.ssh.SshCommand.destroy(SshCommand.java:78)
at
org.apache.sshd.server.channel.ChannelSession.doCloseImmediately(ChannelSession.java:242)
at
org.apache.sshd.common.util.CloseableUtils$AbstractCloseable.close(CloseableUtils.java:276)
at
org.apache.sshd.common.util.CloseableUtils$ParallelCloseable.doClose(CloseableUtils.java:182)
at
org.apache.sshd.common.util.CloseableUtils$SimpleCloseable.close(CloseableUtils.java:151)
at
org.apache.sshd.common.io.nio2.Nio2Session$1.onFailed(Nio2Session.java:199)
at
org.apache.sshd.common.io.nio2.Nio2CompletionHandler$2.run(Nio2CompletionHandler.java:41)
at java.security.AccessController.doPrivileged(Native Method)
at
org.apache.sshd.common.io.nio2.Nio2CompletionHandler.failed(Nio2CompletionHandler.java:39)
at
org.apache.sshd.common.io.nio2.Nio2Session$1.onCompleted(Nio2Session.java:195)
at
org.apache.sshd.common.io.nio2.Nio2Session$1.onCompleted(Nio2Session.java:170)
at
org.apache.sshd.common.io.nio2.Nio2CompletionHandler$1.run(Nio2CompletionHandler.java:32)
at java.security.AccessController.doPrivileged(Native Method)
at
org.apache.sshd.common.io.nio2.Nio2CompletionHandler.completed(Nio2CompletionHandler.java:30)
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:1149)
at
