[
https://issues.apache.org/jira/browse/SSHD-1032?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=17162065#comment-17162065
]
Evgeny Pasynkov commented on SSHD-1032:
---------------------------------------
Ok, I can reproduce the problem locally quite easy. The problem usually occurs
when a couple of GBs already sent into channel.
The only strange thing I see in logs that an exception is prepended by a number
of SSH_MSG_CHANNEL_WINDOW_ADJUST messages without sending actual data frames
{code:java}
[2020-07-21 12:58:52,843] DEBUG [ sshd-nio2-29] ssh-101
Mock User ssh.server.SSHChannelSessionEx -
handleWindowAdjust(SSHChannelSessionEx[id=0,
recipient=0]-SSHServerSessionEx[pasynkov@/0:0:0:0:0:0:0:1:57312])
SSH_MSG_CHANNEL_WINDOW_ADJUST window=65520
[2020-07-21 12:58:52,844] DEBUG [4 @coroutine#11] ssh-101
:1e:95:c1:93 .ssh.server.SSHServerSessionEx -
encode(SSHServerSessionEx[pasynkov@/0:0:0:0:0:0:0:1:57312]) packet #138960
sending command=94[SSH_MSG_CHANNEL_DATA] len=16393
[2020-07-21 12:58:52,844] DEBUG [4 @coroutine#11] ssh-101
:1e:95:c1:93 .ssh.server.SSHServerSessionEx -
encode(SSHServerSessionEx[pasynkov@/0:0:0:0:0:0:0:1:57312]) packet #138961
sending command=94[SSH_MSG_CHANNEL_DATA] len=16393
[2020-07-21 12:58:52,844] DEBUG [4 @coroutine#11] ssh-101
:1e:95:c1:93 .ssh.server.SSHServerSessionEx -
encode(SSHServerSessionEx[pasynkov@/0:0:0:0:0:0:0:1:57312]) packet #138962
sending command=94[SSH_MSG_CHANNEL_DATA] len=16393
[2020-07-21 12:58:52,844] DEBUG [4 @coroutine#11] ssh-101
:1e:95:c1:93 .ssh.server.SSHServerSessionEx -
encode(SSHServerSessionEx[pasynkov@/0:0:0:0:0:0:0:1:57312]) packet #138963
sending command=94[SSH_MSG_CHANNEL_DATA] len=16393
[2020-07-21 12:58:52,845] DEBUG [ sshd-nio2-11] ssh-101
Mock User ssh.server.SSHChannelSessionEx -
handleWindowAdjust(SSHChannelSessionEx[id=0,
recipient=0]-SSHServerSessionEx[pasynkov@/0:0:0:0:0:0:0:1:57312])
SSH_MSG_CHANNEL_WINDOW_ADJUST window=65520
[2020-07-21 12:58:52,845] DEBUG [ sshd-nio2-11] ssh-101
Mock User .ssh.server.SSHServerSessionEx -
encode(SSHServerSessionEx[pasynkov@/0:0:0:0:0:0:0:1:57312]) packet #138964
sending command=94[SSH_MSG_CHANNEL_DATA] len=16393
[2020-07-21 12:58:52,845] DEBUG [2 @coroutine#11] ssh-101
:1e:95:c1:93 .ssh.server.SSHServerSessionEx -
encode(SSHServerSessionEx[pasynkov@/0:0:0:0:0:0:0:1:57312]) packet #138965
sending command=94[SSH_MSG_CHANNEL_DATA] len=16393
[2020-07-21 12:58:52,846] DEBUG [3 @coroutine#11] ssh-101
:1e:95:c1:93 .ssh.server.SSHServerSessionEx -
encode(SSHServerSessionEx[pasynkov@/0:0:0:0:0:0:0:1:57312]) packet #138966
sending command=94[SSH_MSG_CHANNEL_DATA] len=16393
[2020-07-21 12:58:52,846] DEBUG [9 @coroutine#11] ssh-101
:1e:95:c1:93 .ssh.server.SSHServerSessionEx -
encode(SSHServerSessionEx[pasynkov@/0:0:0:0:0:0:0:1:57312]) packet #138967
sending command=94[SSH_MSG_CHANNEL_DATA] len=16393
[2020-07-21 12:58:52,847] DEBUG [ sshd-nio2-26] ssh-101
Mock User ssh.server.SSHChannelSessionEx -
handleWindowAdjust(SSHChannelSessionEx[id=0,
recipient=0]-SSHServerSessionEx[pasynkov@/0:0:0:0:0:0:0:1:57312])
SSH_MSG_CHANNEL_WINDOW_ADJUST window=65520
[2020-07-21 12:58:52,847] DEBUG [ sshd-nio2-26] ssh-101
Mock User .ssh.server.SSHServerSessionEx -
encode(SSHServerSessionEx[pasynkov@/0:0:0:0:0:0:0:1:57312]) packet #138968
sending command=94[SSH_MSG_CHANNEL_DATA] len=16393
[2020-07-21 12:58:52,848] DEBUG [2 @coroutine#11] ssh-101
:1e:95:c1:93 .ssh.server.SSHServerSessionEx -
encode(SSHServerSessionEx[pasynkov@/0:0:0:0:0:0:0:1:57312]) packet #138969
sending command=94[SSH_MSG_CHANNEL_DATA] len=16393
[2020-07-21 12:58:52,848] DEBUG [3 @coroutine#11] ssh-101
:1e:95:c1:93 .ssh.server.SSHServerSessionEx -
encode(SSHServerSessionEx[pasynkov@/0:0:0:0:0:0:0:1:57312]) packet #138970
sending command=94[SSH_MSG_CHANNEL_DATA] len=16393
[2020-07-21 12:58:52,848] DEBUG [7 @coroutine#11] ssh-101
:1e:95:c1:93 .ssh.server.SSHServerSessionEx -
encode(SSHServerSessionEx[pasynkov@/0:0:0:0:0:0:0:1:57312]) packet #138971
sending command=94[SSH_MSG_CHANNEL_DATA] len=16393
[2020-07-21 12:58:52,849] DEBUG [ sshd-nio2-33] ssh-101
Mock User ssh.server.SSHChannelSessionEx -
handleWindowAdjust(SSHChannelSessionEx[id=0,
recipient=0]-SSHServerSessionEx[pasynkov@/0:0:0:0:0:0:0:1:57312])
SSH_MSG_CHANNEL_WINDOW_ADJUST window=65520
[2020-07-21 12:58:52,849] DEBUG [ sshd-nio2-33] ssh-101
Mock User .ssh.server.SSHServerSessionEx -
encode(SSHServerSessionEx[pasynkov@/0:0:0:0:0:0:0:1:57312]) packet #138972
sending command=94[SSH_MSG_CHANNEL_DATA] len=16393
[2020-07-21 12:58:52,850] DEBUG [ sshd-nio2-3] ssh-101
Mock User ssh.server.SSHChannelSessionEx -
handleWindowAdjust(SSHChannelSessionEx[id=0,
recipient=0]-SSHServerSessionEx[pasynkov@/0:0:0:0:0:0:0:1:57312])
SSH_MSG_CHANNEL_WINDOW_ADJUST window=65520
[2020-07-21 12:58:52,851] DEBUG [ sshd-nio2-8] ssh-101
Mock User ssh.server.SSHChannelSessionEx -
handleWindowAdjust(SSHChannelSessionEx[id=0,
recipient=0]-SSHServerSessionEx[pasynkov@/0:0:0:0:0:0:0:1:57312])
SSH_MSG_CHANNEL_WINDOW_ADJUST window=65520
[2020-07-21 12:58:52,852] DEBUG [ sshd-nio2-6] ssh-101
Mock User ssh.server.SSHChannelSessionEx -
handleWindowAdjust(SSHChannelSessionEx[id=0,
recipient=0]-SSHServerSessionEx[pasynkov@/0:0:0:0:0:0:0:1:57312])
SSH_MSG_CHANNEL_WINDOW_ADJUST window=65520
[2020-07-21 12:58:52,853] DEBUG [ sshd-nio2-15] ssh-101
Mock User ssh.server.SSHChannelSessionEx -
handleWindowAdjust(SSHChannelSessionEx[id=0,
recipient=0]-SSHServerSessionEx[pasynkov@/0:0:0:0:0:0:0:1:57312])
SSH_MSG_CHANNEL_WINDOW_ADJUST window=65520
[2020-07-21 12:58:52,854] DEBUG [ sshd-nio2-30] ssh-101
Mock User ssh.server.SSHChannelSessionEx -
handleWindowAdjust(SSHChannelSessionEx[id=0,
recipient=0]-SSHServerSessionEx[pasynkov@/0:0:0:0:0:0:0:1:57312])
SSH_MSG_CHANNEL_WINDOW_ADJUST window=65520
[2020-07-21 12:58:52,855] DEBUG [ sshd-nio2-2] ssh-101
Mock User ssh.server.SSHChannelSessionEx -
handleWindowAdjust(SSHChannelSessionEx[id=0,
recipient=0]-SSHServerSessionEx[pasynkov@/0:0:0:0:0:0:0:1:57312])
SSH_MSG_CHANNEL_WINDOW_ADJUST window=65520
[2020-07-21 12:58:52,856] DEBUG [ sshd-nio2-27] ssh-101
Mock User ssh.server.SSHChannelSessionEx -
handleWindowAdjust(SSHChannelSessionEx[id=0,
recipient=0]-SSHServerSessionEx[pasynkov@/0:0:0:0:0:0:0:1:57312])
SSH_MSG_CHANNEL_WINDOW_ADJUST window=65520
[2020-07-21 12:58:52,856] DEBUG [ sshd-nio2-22] ssh-101
Mock User ssh.server.SSHChannelSessionEx -
handleWindowAdjust(SSHChannelSessionEx[id=0,
recipient=0]-SSHServerSessionEx[pasynkov@/0:0:0:0:0:0:0:1:57312])
SSH_MSG_CHANNEL_WINDOW_ADJUST window=65520
[2020-07-21 12:58:52,857] DEBUG [ sshd-nio2-5] ssh-101
Mock User ssh.server.SSHChannelSessionEx -
handleWindowAdjust(SSHChannelSessionEx[id=0,
recipient=0]-SSHServerSessionEx[pasynkov@/0:0:0:0:0:0:0:1:57312])
SSH_MSG_CHANNEL_WINDOW_ADJUST window=65520
[2020-07-21 12:58:52,858] DEBUG [ sshd-nio2-32] ssh-101
Mock User ssh.server.SSHChannelSessionEx -
handleWindowAdjust(SSHChannelSessionEx[id=0,
recipient=0]-SSHServerSessionEx[pasynkov@/0:0:0:0:0:0:0:1:57312])
SSH_MSG_CHANNEL_WINDOW_ADJUST window=65520
java.io.IOException: Error writing 16384 bytes. Channel:
ChannelAsyncOutputStream[SSHChannelSessionEx[id=0,
recipient=0]-SSHServerSessionEx[pasynkov@/0:0:0:0:0:0:0:1:57312]]
cmd=SSH_MSG_CHANNEL_DATAjava.io.IOException: Error writing 16384 bytes.
Channel: ChannelAsyncOutputStream[SSHChannelSessionEx[id=0,
recipient=0]-SSHServerSessionEx[pasynkov@/0:0:0:0:0:0:0:1:57312]]
cmd=SSH_MSG_CHANNEL_DATA at
jetbrains.ssh.server.command.BaseCommand$executeCommand$$inlined$ifTrue$lambda$1$1.invokeSuspend(MDC.kt:108)
at
kotlin.coroutines.jvm.internal.BaseContinuationImpl.resumeWith(ContinuationImpl.kt:33)
at kotlinx.coroutines.internal.ScopeCoroutine.afterResume(Scopes.kt:32) at
kotlinx.coroutines.AbstractCoroutine.resumeWith(AbstractCoroutine.kt:113) at
kotlin.coroutines.jvm.internal.BaseContinuationImpl.resumeWith(ContinuationImpl.kt:46)
at kotlinx.coroutines.DispatchedTask.run(DispatchedTask.kt:56) at
java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
at
java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
at
libraries.io.DaemonThreadFactory$newThread$th$1.run(DaemonThreadFactory.kt:15)
at java.base/java.lang.Thread.run(Thread.java:834)Caused by:
java.lang.ArrayIndexOutOfBoundsException: arraycopy: last source index 32768
out of bounds for byte[16384] at java.base/java.lang.System.arraycopy(Native
Method) at
org.apache.sshd.common.util.buffer.ByteArrayBuffer.putRawBytes(ByteArrayBuffer.java:230)
at
org.apache.sshd.common.channel.ChannelAsyncOutputStream.createSendBuffer(ChannelAsyncOutputStream.java:229)
at
org.apache.sshd.common.channel.ChannelAsyncOutputStream.doWriteIfPossible(ChannelAsyncOutputStream.java:164)
at
org.apache.sshd.common.channel.ChannelAsyncOutputStream.writePacket(ChannelAsyncOutputStream.java:70)
at
jetbrains.ssh.server.command.BaseCommand$executeCommand$$inlined$ifTrue$lambda$1$1.invokeSuspend(MDC.kt:104)
... 9 common frames omitted
{code}
> java.lang.ArrayIndexOutOfBoundsException arraycopy
> --------------------------------------------------
>
> Key: SSHD-1032
> URL: https://issues.apache.org/jira/browse/SSHD-1032
> Project: MINA SSHD
> Issue Type: Bug
> Affects Versions: 2.5.0
> Reporter: Evgeny Pasynkov
> Priority: Major
>
> When invoking writePacket, I quite often get the following exception:
> {noformat}
> Caused by: java.lang.ArrayIndexOutOfBoundsException arraycopy: last source
> index 32768 out of bounds for byte[8192]
> at java.base/java.lang.System.arraycopy(Native Method)
> at
> org.apache.sshd.common.util.buffer.ByteArrayBuffer.putRawBytes(ByteArrayBuffer.java:230)
>
> at
> org.apache.sshd.common.channel.ChannelAsyncOutputStream.createSendBuffer(ChannelAsyncOutputStream.java:229)
>
> at
> org.apache.sshd.common.channel.ChannelAsyncOutputStream.doWriteIfPossible(ChannelAsyncOutputStream.java:164)
>
> at
> org.apache.sshd.common.channel.ChannelAsyncOutputStream.writePacket(ChannelAsyncOutputStream.java:70){noformat}
> This never happened in 2.4.0, so it is definitely a regression
--
This message was sent by Atlassian Jira
(v8.3.4#803005)
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscr...@mina.apache.org
For additional commands, e-mail: dev-h...@mina.apache.org
