[
https://issues.apache.org/jira/browse/SSHD-891?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=16764711#comment-16764711
]
Anudeep commented on SSHD-891:
------------------------------
Hi [~lgoldstein],
Regarding the message sent that would be a message from server(there is a timer
at server side which sends "HB" message from server for every 30 seconds if
there are no incoming packets from server to client.
Please find below logs
Lsof output :svc-2-sg
Wed Feb 6 05:30:17 CET 2019
COMMAND PID USER FD TYPE DEVICE SIZE/OFF NODE NAME
java 4409 root 502u IPv6 1015404 0t0 TCP svc-2-sg:8345->192.168.42.24:33589
(ESTABLISHED)
java 4409 root 525u IPv6 19463 0t0 TCP *:8345 (LISTEN)
502 is the FD here for the VM
VM Server.log :
{code:java}
Please find Apache being idle in the 10 mins as mentioned (ie 5:29 to 5:39) in
the server.log of VM.
2019-02-06 05:28:27,759 INFO [com.ericsson.oss.itpf.COMMAND_LOGGER]
(pool-7-thread-1888) [omega, Acknowledge, STARTED, BNSI NBI Client, BNSI NBI
Server, NotificationIdentifier = 140154550]
2019-02-06 05:28:57,723 TRACE [org.apache.sshd.common.channel.Window] (EJB
default - 8) Consume server remote window by 4 down to 79982
2019-02-06 05:28:57,724 DEBUG [org.apache.sshd.common.io.nio2.Nio2Session] (EJB
default - 8) Writing 68 bytes
2019-02-06 05:28:57,726 DEBUG [org.apache.sshd.common.io.nio2.Nio2Session]
(sshd-SshServer[4166a223]-nio2-thread-3) Finished writing
2019-02-06 05:29:27,721 TRACE [org.apache.sshd.common.channel.Window] (EJB
default - 19) Consume server remote window by 4 down to 79978
2019-02-06 05:29:27,722 DEBUG [org.apache.sshd.common.io.nio2.Nio2Session] (EJB
default - 19) Writing 68 bytes
2019-02-06 05:29:27,723 DEBUG [org.apache.sshd.common.io.nio2.Nio2Session]
(sshd-SshServer[4166a223]-nio2-thread-1) Finished writing
2019-02-06 05:29:27,724 DEBUG [org.apache.sshd.common.io.nio2.Nio2Session] (EJB
default - 19) Writing 532 bytes
2019-02-06 05:29:27,725 DEBUG [org.apache.sshd.common.io.nio2.Nio2Session]
(sshd-SshServer[4166a223]-nio2-thread-3) Finished writing
2019-02-06 05:29:57,722 TRACE [org.apache.sshd.common.channel.Window] (EJB
default - 32) Consume server remote window by 4 down to 79974
2019-02-06 05:30:27,721 TRACE [org.apache.sshd.common.channel.Window] (EJB
default - 42) Consume server remote window by 4 down to 79970
2019-02-06 05:30:57,722 TRACE [org.apache.sshd.common.channel.Window] (EJB
default - 53) Consume server remote window by 4 down to 79966
2019-02-06 05:31:27,722 TRACE [org.apache.sshd.common.channel.Window] (EJB
default - 65) Consume server remote window by 4 down to 79962
2019-02-06 05:31:57,721 TRACE [org.apache.sshd.common.channel.Window] (EJB
default - 75) Consume server remote window by 4 down to 79958
2019-02-06 05:32:10,641 TRACE [org.apache.sshd.common.channel.Window]
(Thread-1259 (HornetQ-client-global-threads-22246058)) Consume server remote
window by 1532 down to 78426
2019-02-06 05:32:40,645 TRACE [org.apache.sshd.common.channel.Window] (EJB
default - 91) Consume server remote window by 4 down to 78422
2019-02-06 05:33:10,652 TRACE [org.apache.sshd.common.channel.Window] (EJB
default - 101) Consume server remote window by 4 down to 78418
2019-02-06 05:33:30,662 TRACE [org.apache.sshd.common.channel.Window]
(Thread-1260 (HornetQ-client-global-threads-22246058)) Consume server remote
window by 1532 down to 76886
2019-02-06 05:34:00,665 TRACE [org.apache.sshd.common.channel.Window] (EJB
default - 121) Consume server remote window by 4 down to 76882
2019-02-06 05:34:30,668 TRACE [org.apache.sshd.common.channel.Window] (EJB
default - 3) Consume server remote window by 4 down to 76878
2019-02-06 05:35:00,665 TRACE [org.apache.sshd.common.channel.Window] (EJB
default - 15) Consume server remote window by 4 down to 76874
2019-02-06 05:35:30,666 TRACE [org.apache.sshd.common.channel.Window] (EJB
default - 27) Consume server remote window by 4 down to 76870
2019-02-06 05:36:00,665 TRACE [org.apache.sshd.common.channel.Window] (EJB
default - 37) Consume server remote window by 4 down to 76866
2019-02-06 05:36:30,665 TRACE [org.apache.sshd.common.channel.Window] (EJB
default - 51) Consume server remote window by 4 down to 76862
2019-02-06 05:37:00,665 TRACE [org.apache.sshd.common.channel.Window] (EJB
default - 59) Consume server remote window by 4 down to 76858
2019-02-06 05:37:30,666 TRACE [org.apache.sshd.common.channel.Window] (EJB
default - 70) Consume server remote window by 4 down to 76854
2019-02-06 05:38:00,665 TRACE [org.apache.sshd.common.channel.Window] (EJB
default - 84) Consume server remote window by 4 down to 76850
2019-02-06 05:38:30,666 TRACE [org.apache.sshd.common.channel.Window] (EJB
default - 90) Consume server remote window by 4 down to 76846
2019-02-06 05:39:00,666 TRACE [org.apache.sshd.common.channel.Window] (EJB
default - 103) Consume server remote window by 4 down to 76842
2019-02-06 05:39:28,487 DEBUG [org.apache.sshd.common.io.nio2.Nio2Session]
(sshd-SshServer[4166a223]-timer-thread-1) Writing 116 bytes
2019-02-06 05:39:28,488 DEBUG [org.apache.sshd.common.io.nio2.Nio2Session]
(sshd-SshServer[4166a223]-nio2-thread-1) Finished writing
{code}
STRACE:
{code:java}
>From the Strace we found that Write operations to the FD :502 were exist only
>till the time 5:29 and again after 10 mins at 5:39 before the session get
>closed. There were no Read or Write Operations on the FD 502 iin the 10 mins
>of idle time . Please find the Strace snippet shared below:
7245 05:28:57 write(502,
"\x64\x84\x34\x49\x87\x8a\xd6\x2d\xeb\xa3\xed\xb1\xc0\x66\x77\x44\x0b\x29\x27\xde\x5f\xf1\xf1\xe1\xf7\x8e\x0e\x1f\xd4\x08\xed\x6b\xcc\xd1\x87\xd6\x53\x4e\x17\x95\x74\xfe\xed\xac\x85\x03\xa8\x0b\x9a\xa0\x3a\x13\xd6\xef\x50\x08\x4f\x1d\xb6\x88\x6f\x6d\xfb\x6c\xe7\xfc\xcb\x3b",
68) = 68
7395 05:29:27 write(502,
"\x80\x34\xca\xd8\x09\x03\xab\x4b\x9c\x1b\x96\xe3\xbd\x1d\x44\x7d\x87\x5a\xca\x26\xac\x75\x6f\x36\x4d\xf0\xa2\x40\xf3\xc2\xa1\x74\x3a\x4a\xcc\xd1\xb5\x4f\xea\xb0\x87\xa1\x72\xe1\xbb\x20\xb8\x94\x92\x07\x67\xa3\x05\xbc\xbc\xab\x28\x5c\x54\x83\xe7\xe3\x46\x58\xbe\x6c\x74\xb8",
68) = 68
7395 05:29:27 write(502,
"\x8a\xf9\x17\x19\x7a\x9b\x72\xa4\x64\x91\x31\x87\x76\xbc\x91\x83\x78\xd1\x5c\x1c\x2e\xd4\x82\x2c\x1a\xd1\xdc\x6c\xec\x11\x6f\xb8\xc5\xfd\xe1\x0b\x7e\x9d\x92\xba\x73\x64\xce\x11\x18\x5f\xb7\xa1\x51\xb5\xe3\x3b\xe3\x43\x0a\x7f\xe6\x75\x99\xc0\x4f\xa7\x50\x0b\xde\x8e\x30\x05\xab\x31\xe0\x56\xfd\x11\xee\x36\x7e\x26\x38\x92\xc5\x1c\x4c\xb6\x39\x2a\x28\xa0\xa3\x8c\xd6\x52\xc2\x6a\xbf\x53\x12\x30\x6a\xd3\x89\xc1\xe0\x1c\xc4\xde\x0a\x50\x8e\xfa\x81\x43\x73\xc7\x07\x1d\x5a\x6c\x22\x69\xf5\x4f\xad\xbe\xc0\x49\xdf\x70\x0e\xfb\xe2\xee\xee\xd6\xcd\x75\xd1\x30\x55\xf5\xfb\x9b\x0c\x71\xe1\x23\xcb\x34\xca\x7d\x39\x8b\xe6\x2e\x68\x50\x99\x62\x45\xca\x75\xca\x00\x9d\x0c\xca\x77\xad\x2e\xea\xbe\xfb\x47\xb9\x40\xe5\x28\x51\xa2\x8a\x2a\x98\x78\x77\xdd\x28\xcf\x20\x16\x1e\xf9\xfa\xa0\x0f\x13\x41\x7f\xb3\x39\x25\x25\x29\x25\x51\xab\x12\xb6\x4a\xde\x1b\xd5\xa2\xa0\x17\x83\x0c\xfe\xb6\x44\x83\x5d\xa3\x07\x09\xf7\x31\x9f\xe3\xe2\xf9\x6c\x62\xb4\xaf\xcd\xe1\x52\xb2\x65\xf4\x76\x0f\xa4\x70\xac\x0a\x18\xba\x4d\x9d\x70\x9a\x6c\x7b\x4e\xc5\x92\xc4\x17\x46\x04\x41\x5b\x26\xda\xc5\xb6\x6a\x61\x10\x52\x82\xe0\x91\x54\x21\x47\x11\x9b\xb3\x53\xd4\x76\x1e\x73\x58\xbc\x97\x80\x54\xd7\x30\x47\xdf\xef\x6f\xa9\x72\x3a\x58\xa1\xd4\x2b\x47\x86\x44\xac\x8a\x98\x8d\x9c\x96\x2e\x0d\xe4\xcd\xe3\xe5\xcd\x18\x5f\x52\x4a\x76\x1d\x3a\x49\x08\x33\x4b\xa4\x0c\x69\x83\xd8\x7f\xa3\xe1\x55\x45\x59\x14\xa2\x5a\x1e\x02\x6f\xb5\x42\xc0\x51\x58\xa4\xd7\x0d\x2d\x58\xc8\x99\x7b\x2b\x3b\xca\x4f\x1e\x3f\x22\x61\xb4\x9d\xb6\x35\x78\x83\xce\x7d\x25\xa5\x7d\x4d\x9f\x3f\x7e\xf2\x9c\xf8\xc2\xdf\x0b\x50\x00\x53\xe3\xb9\x58\xc6\x81\xd3\x29\xaa\xf4\xe7\x9a\xe3\x42\xa2\x12\xd9\xd7\xda\xe5\x4a\x27\x94\x4b\x78\xda\xe5\x1e\xa3\x71\x67\x28\xe9\xc3\x5d\x20\x58\x47\xac\x0c\x99\xdc\x12\xef\xe4\x65\xc3\x2a\x56\x7f\x1c\x0c\x98\xc9\xf6\xdb\x23\xed\xc7\x6d\xb7\x3e\x51\x19\xae\xea\xd0\x07\xb5\xb7\x06\x00\xee\xc7\xff\x27\xbd\x3c\xb2\x64\xd3\x95\x48\x69\xd7\x19\xf9\xb3\x74\x8a\xe8\xc8\xc3\x2c\x08\x7b\x4e\x60\xee\x4f\xd8\x61\x67\xad\xcc\x5d\xef\x83\x1e\x4d\x46\x8d\x49\x11\xd0\xbd\xe9\x0a\xa6\xb0\xe7\x52\x30\xcc\x12\x8d\xd8\xe0\x1a\xb6\xf6\x6b\x5e\x86\x12\x28\x1d\xd3\xba\x82\x9d",
532) = 532
5604 05:39:28 write(502,
"\x8d\x5d\x54\xf9\x9a\x88\x70\xe3\xb0\x4f\x85\xa6\x6f\x49\xf6\xa6\x95\x63\x15\x37\x48\x94\x59\x36\xf8\xee\x47\x51\x3d\x92\x2b\x66\x2a\x99\xa6\x60\xd1\x7a\x48\xf0\xac\xf5\x1a\x6a\xb2\x10\x71\x63\xee\xd7\xea\xe0\x9b\xdd\x3a\x76\xf4\x55\xa5\x8c\x4c\x34\xaf\x28\xb5\x74\x8b\xcc\xe0\xff\x35\x62\xb0\xb6\xca\xe0\x73\x59\x18\x51\xba\x61\xec\xf6\xe4\xc7\x06\xf6\xab\x3d\x82\x2a\x96\x93\x28\xb1\x93\x09\xfd\xa4\xee\x7c\xb6\xcb\xae\x8c\x0c\x8f\xa3\x40\x7f\x9c\x70\xf0\xa9\x40",
116) = 116
4631 05:39:36 write(502, "HTTP/1.1 401 Unauthorized\r\nContent-length:
0\r\nWww-authenticate: Digest
realm=\"ManagementRealm\",nonce=\"397f3540050036d602ec035c4d34e389\"\r\nX-frame-options:
SAMEORIGIN\r\nDate: Wed, 06 Feb 2019 04:39:36 GMT\r\n\r\n", 205) = 205
4631 05:39:36 write(502, "HTTP/1.1 200 OK\r\nTransfer-encoding:
chunked\r\nContent-type: application/json\r\nX-frame-options:
SAMEORIGIN\r\nDate: Wed, 06 Feb 2019 04:39:36 GMT\r\n\r\n", 145) = 145
4631 05:39:36 write(502, "37\r\n\{\n \"outcome\" : \"success\",\n \"result\" :
\"running\"\n}\r\n", 61) = 61
4631 05:39:36 write(502, "0\r\n\r\n", 5) = 5
4631 05:39:36 write(502, "HTTP/1.1 401 Unauthorized\r\nContent-length:
0\r\nWww-authenticate: Digest realm=\"ManagementRealm\",nonc:
{code}
So now we want to know from the Apache end that why it is not allowing vm to
write after 1 hour of the active subscription.Atleast we need so workaround
untill we migrate.
Please let us know if you need any other inputs.
Regards,
Anudeep
> SSh connections gets closed for every one hour with 0.13.0 version
> ------------------------------------------------------------------
>
> Key: SSHD-891
> URL: https://issues.apache.org/jira/browse/SSHD-891
> Project: MINA SSHD
> Issue Type: Bug
> Reporter: Anudeep
> Assignee: Goldstein Lyor
> Priority: Blocker
>
> SSH connections are getting closed for every one hours after 10 mins of idle
> time even though there are incoming pacets data is not being wriiten to
> client for every one hour and is being idle(10 mins which is default timeout
> of ssh session).
--
This message was sent by Atlassian JIRA
(v7.6.3#76005)
