[jira] [Updated] (SSHD-711) Apache hangs sending file

2016-11-07 Thread Roger Hart (JIRA) 

 [ 
https://issues.apache.org/jira/browse/SSHD-711?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
 ]

Roger Hart updated SSHD-711:

Attachment: SSHDgood.log
SSHDbad.log

> Apache hangs sending file
> -
>
> Key: SSHD-711
> URL: https://issues.apache.org/jira/browse/SSHD-711
> Project: MINA SSHD
>  Issue Type: Bug
>Affects Versions: 1.1.0
>Reporter: Roger Hart
>Priority: Minor
> Attachments: SSHDbad.log, SSHDgood.log
>
>
> We're running 1.1.0 but I get the same problem with 1.2.0. When sending a 
> file to a particular server we have problems on some machines but not others. 
> I've attached a DEBUG log for a "good" machine and a "bad" machine.  For the 
> "bad" machine, the system hangs midway through sending the file. Here are the 
> final log entries.
> My theory is that "normally" you see a "Writing X bytes" message, followed by 
> a "Finished writing" message, followed by a "Read Y bytes" message. But on 
> the "bad" machine there seems to be 2 "Write" messages before the hang. I 
> think this is because there are 2 threads putting a write request in the 
> write queue and both are written out to the socket. I'm wondering if this can 
> cause the max packet size specified in the SSH_MSG_CHANNEL_OPEN_CONFIRMATION 
> message to be exceeded. The "good" machine has fewer threads than the "bad" 
> machine, and we've also observed that a smaller files is less likely to hit 
> the problem.
> Do you think this theory is valid?
> Thanks,
> Roger
> 10:29:22.448 7-Nov-16 -0800 | (lient.channel.ChannelSubsystem) 
> handleData(ChannelSubsystem[id=0, 
> recipient=0]-ClientSessionImpl[USER@/X.X.X.X:22][sftp]) SSH_MSG_CHANNEL_DATA 
> len=19
> 10:29:22.450 7-Nov-16 -0800 | (che.sshd.common.channel.Window) 
> waitForSpace(ChannelSubsystem[id=0, 
> recipient=0]-ClientSessionImpl[USER@/X.X.X.X:22][sftp]: client remote window) 
> available: 1073741779
> 10:29:22.450 7-Nov-16 -0800 | (che.sshd.common.channel.Window) 
> waitAndConsume(ChannelSubsystem[id=0, 
> recipient=0]-ClientSessionImpl[USER@/X.X.X.X:22][sftp]: client remote window) 
> - requested=32768, available=1073741779
> 10:29:22.463 7-Nov-16 -0800 | (shd.common.io.nio2.Nio2Session) Writing 32820 
> bytes
> 10:29:22.464 7-Nov-16 -0800 | (che.sshd.common.channel.Window) 
> waitForSpace(ChannelSubsystem[id=0, 
> recipient=0]-ClientSessionImpl[USER@/X.X.X.X:22][sftp]: client remote window) 
> available: 1073709011
> 10:29:22.464 7-Nov-16 -0800 | (che.sshd.common.channel.Window) 
> waitAndConsume(ChannelSubsystem[id=0, 
> recipient=0]-ClientSessionImpl[USER@/X.X.X.X:22][sftp]: client remote window) 
> - requested=31, available=1073709011
> 10:29:22.464 7-Nov-16 -0800 | (shd.common.io.nio2.Nio2Session) Writing 84 
> bytes
> 10:29:22.534 7-Nov-16 -0800 | (shd.common.io.nio2.Nio2Session) Finished 
> writing
> 10:29:22.534 7-Nov-16 -0800 | (shd.common.io.nio2.Nio2Session) Finished 
> writing



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

[jira] [Created] (SSHD-711) Apache hangs sending file

2016-11-07 Thread Roger Hart (JIRA) 
Roger Hart created SSHD-711:
---

 Summary: Apache hangs sending file
 Key: SSHD-711
 URL: https://issues.apache.org/jira/browse/SSHD-711
 Project: MINA SSHD
  Issue Type: Bug
Affects Versions: 1.1.0
Reporter: Roger Hart
Priority: Minor


We're running 1.1.0 but I get the same problem with 1.2.0. When sending a file 
to a particular server we have problems on some machines but not others. I've 
attached a DEBUG log for a "good" machine and a "bad" machine.  For the "bad" 
machine, the system hangs midway through sending the file. Here are the final 
log entries.

My theory is that "normally" you see a "Writing X bytes" message, followed by a 
"Finished writing" message, followed by a "Read Y bytes" message. But on the 
"bad" machine there seems to be 2 "Write" messages before the hang. I think 
this is because there are 2 threads putting a write request in the write queue 
and both are written out to the socket. I'm wondering if this can cause the max 
packet size specified in the SSH_MSG_CHANNEL_OPEN_CONFIRMATION message to be 
exceeded. The "good" machine has fewer threads than the "bad" machine, and 
we've also observed that a smaller files is less likely to hit the problem.

Do you think this theory is valid?

Thanks,
Roger


10:29:22.448 7-Nov-16 -0800 | (lient.channel.ChannelSubsystem) 
handleData(ChannelSubsystem[id=0, 
recipient=0]-ClientSessionImpl[USER@/X.X.X.X:22][sftp]) SSH_MSG_CHANNEL_DATA 
len=19
10:29:22.450 7-Nov-16 -0800 | (che.sshd.common.channel.Window) 
waitForSpace(ChannelSubsystem[id=0, 
recipient=0]-ClientSessionImpl[USER@/X.X.X.X:22][sftp]: client remote window) 
available: 1073741779
10:29:22.450 7-Nov-16 -0800 | (che.sshd.common.channel.Window) 
waitAndConsume(ChannelSubsystem[id=0, 
recipient=0]-ClientSessionImpl[USER@/X.X.X.X:22][sftp]: client remote window) - 
requested=32768, available=1073741779
10:29:22.463 7-Nov-16 -0800 | (shd.common.io.nio2.Nio2Session) Writing 32820 
bytes
10:29:22.464 7-Nov-16 -0800 | (che.sshd.common.channel.Window) 
waitForSpace(ChannelSubsystem[id=0, 
recipient=0]-ClientSessionImpl[USER@/X.X.X.X:22][sftp]: client remote window) 
available: 1073709011
10:29:22.464 7-Nov-16 -0800 | (che.sshd.common.channel.Window) 
waitAndConsume(ChannelSubsystem[id=0, 
recipient=0]-ClientSessionImpl[USER@/X.X.X.X:22][sftp]: client remote window) - 
requested=31, available=1073709011
10:29:22.464 7-Nov-16 -0800 | (shd.common.io.nio2.Nio2Session) Writing 84 bytes
10:29:22.534 7-Nov-16 -0800 | (shd.common.io.nio2.Nio2Session) Finished writing
10:29:22.534 7-Nov-16 -0800 | (shd.common.io.nio2.Nio2Session) Finished writing




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

[jira] [Commented] (SSHD-701) IllegalArgumentException processing SSH_MSG_CHANNEL_OPEN_CONFIRMATION with initial window size of -1

2016-09-30 Thread Roger Hart (JIRA) 

[ 
https://issues.apache.org/jira/browse/SSHD-701?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel=15536985#comment-15536985
 ] 

Roger Hart commented on SSHD-701:
-

[~lgoldstein] I tested your change and it worked great! Thanks again.

> IllegalArgumentException processing SSH_MSG_CHANNEL_OPEN_CONFIRMATION with 
> initial window size of -1
> 
>
> Key: SSHD-701
> URL: https://issues.apache.org/jira/browse/SSHD-701
> Project: MINA SSHD
>  Issue Type: Improvement
>Affects Versions: 1.2.0
>Reporter: Roger Hart
>Assignee: Goldstein Lyor
>Priority: Minor
> Fix For: 1.4.0
>
>
> We're using Apache MINA SSHD 1.2.0 successfully except for one server which 
> sends an init window size of -1 in the SSH_MSG_CHANNEL_OPEN_CONFIRMATION 
> message (other servers send 0). This causes SSHD to throw an 
> IllegalArgumentException here: 
> ValidateUtils.checkTrue(window >= 0, "Negative window size: %d", window);
> I'm able to send files to this server using the Win SCP command line client.
> It would be nice if SSHD was more robust and treated a negative window size 
> as 0.
> Here's the SSHD log entries:
> 10:56:13.296 23-Sep-16 -0700 | (ultConfigFileHostEntryResolver) 
> resolveEffectiveHost(@/X.XX.XXX.XX:22) => null
> 10:56:13.296 23-Sep-16 -0700 | (g.apache.sshd.client.SshClient) 
> connect(@/X.XX.XXX.XX:22) no overrides
> 10:56:13.296 23-Sep-16 -0700 | (d.common.io.nio2.Nio2Connector) Connecting to 
> /X.XX.XXX.XX:22
> 10:56:13.297 23-Sep-16 -0700 | (d.common.io.nio2.Nio2Connector) 
> setOption(SO_REUSEADDR)[true] from property=socket-reuseaddr
> 10:56:13.389 23-Sep-16 -0700 | (shd.common.io.nio2.Nio2Session) Creating 
> IoSession on /0:0:0:0:0:0:0:0:57579 from /X.XX.XXX.XX:22
> 10:56:13.390 23-Sep-16 -0700 | (ient.session.ClientSessionImpl) Client 
> session created: Nio2Session[local=/0:0:0:0:0:0:0:0:57579, 
> remote=/X.XX.XXX.XX:22]
> 10:56:13.391 23-Sep-16 -0700 | (.session.ClientUserAuthService) 
> ClientUserAuthService(ClientSessionImpl[null@/X.XX.XXX.XX:22]) client 
> methods: [publickey, keyboard-interactive, password]
> 10:56:13.391 23-Sep-16 -0700 | (helpers.SessionTimeoutListener) 
> sessionCreated(ClientSessionImpl[null@/X.XX.XXX.XX:22]) tracking
> 10:56:13.391 23-Sep-16 -0700 | (ient.session.ClientSessionImpl) 
> sendIdentification(ClientSessionImpl[null@/X.XX.XXX.XX:22]): 
> SSH-2.0-SSHD-CORE-1.2.0
> 10:56:13.391 23-Sep-16 -0700 | (shd.common.io.nio2.Nio2Session) Writing 25 
> bytes
> 10:56:13.392 23-Sep-16 -0700 | (ient.session.ClientSessionImpl) 
> sendKexInit(ClientSessionImpl[null@/X.XX.XXX.XX:22]) Send SSH_MSG_KEXINIT
> 10:56:13.392 23-Sep-16 -0700 | (shd.common.io.nio2.Nio2Session) Writing 592 
> bytes
> 10:56:13.393 23-Sep-16 -0700 | (.session.ClientUserAuthService) 
> auth(ClientSessionImpl[@/X.XX.XXX.XX:22])[ssh-connection] send 
> SSH_MSG_USERAUTH_REQUEST for 'none'
> 10:56:13.393 23-Sep-16 -0700 | (shd.common.io.nio2.Nio2Session) 
> handleCompletedWriteCycle(Nio2Session[local=/0:0:0:0:0:0:0:0:57579, 
> remote=/X.XX.XXX.XX:22]) finished writing len=25
> 10:56:13.395 23-Sep-16 -0700 | (ient.session.ClientSessionImpl) 
> writePacket(ClientSessionImpl[@/X.XX.XXX.XX:22])[SSH_MSG_USERAUTH_REQUEST]
>  Start flagging packets as pending until key exchange is done
> 10:56:13.396 23-Sep-16 -0700 | (shd.common.io.nio2.Nio2Session) 
> handleCompletedWriteCycle(Nio2Session[local=/0:0:0:0:0:0:0:0:57579, 
> remote=/X.XX.XXX.XX:22]) finished writing len=592
> 10:56:13.480 23-Sep-16 -0700 | (shd.common.io.nio2.Nio2Session) 
> handleReadCycleCompletion(Nio2Session[local=/0:0:0:0:0:0:0:0:57579, 
> remote=/X.XX.XXX.XX:22]) read 568 bytes
> 10:56:13.480 23-Sep-16 -0700 | (ient.session.ClientSessionImpl) 
> doReadIdentification(ClientSessionImpl[@/X.XX.XXX.XX:22]) 
> line='SSH-2.0-mod_sftp/0.9.7'
> 10:56:13.480 23-Sep-16 -0700 | (ient.session.ClientSessionImpl) 
> readIdentification(ClientSessionImpl[@/X.XX.XXX.XX:22]) Server 
> version string: SSH-2.0-mod_sftp/0.9.7
> 10:56:13.480 23-Sep-16 -0700 | (ient.session.ClientSessionImpl) 
> handleKexInit(ClientSessionImpl[@/X.XX.XXX.XX:22]) SSH_MSG_KEXINIT
> 10:56:13.480 23-Sep-16 -0700 | (ient.session.ClientSessionImpl) 
> setNegotiationResult(ClientSessionImpl[@/X.XX.XXX.XX:22]) Kex: 
> server->client aes128-ctr hmac-sha1 none
> 10:56:13.480 23-Sep-16 -0700 | (ient.session.ClientSessionImpl) 
> setNegotiationResult(ClientSessionImpl[@/X.XX.XXX.XX:22]) Kex: 
> client->server aes128-ctr hmac-sha1 none
> 10:56:13.480 23-Sep-16 -0700 | (he.sshd.client.kex.DHGEXClient) 
> init(ClientSessionImpl[@/X.XX.XXX.XX:22]) Send 
> SSH_MSG_KEX_DH_GEX_REQUEST
> 10:56:13.480 23-Sep-16 -0700 | (shd.common.io.nio2.Nio2Session) Writing 32 
> bytes
>

[jira] [Commented] (SSHD-701) IllegalArgumentException processing SSH_MSG_CHANNEL_OPEN_CONFIRMATION with initial window size of -1

2016-09-30 Thread Roger Hart (JIRA) 

[ 
https://issues.apache.org/jira/browse/SSHD-701?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel=15536494#comment-15536494
 ] 

Roger Hart commented on SSHD-701:
-

OK. Thanks.

> IllegalArgumentException processing SSH_MSG_CHANNEL_OPEN_CONFIRMATION with 
> initial window size of -1
> 
>
> Key: SSHD-701
> URL: https://issues.apache.org/jira/browse/SSHD-701
> Project: MINA SSHD
>  Issue Type: Improvement
>Affects Versions: 1.2.0
>Reporter: Roger Hart
>Assignee: Goldstein Lyor
>Priority: Minor
> Fix For: 1.4.0
>
>
> We're using Apache MINA SSHD 1.2.0 successfully except for one server which 
> sends an init window size of -1 in the SSH_MSG_CHANNEL_OPEN_CONFIRMATION 
> message (other servers send 0). This causes SSHD to throw an 
> IllegalArgumentException here: 
> ValidateUtils.checkTrue(window >= 0, "Negative window size: %d", window);
> I'm able to send files to this server using the Win SCP command line client.
> It would be nice if SSHD was more robust and treated a negative window size 
> as 0.
> Here's the SSHD log entries:
> 10:56:13.296 23-Sep-16 -0700 | (ultConfigFileHostEntryResolver) 
> resolveEffectiveHost(@/X.XX.XXX.XX:22) => null
> 10:56:13.296 23-Sep-16 -0700 | (g.apache.sshd.client.SshClient) 
> connect(@/X.XX.XXX.XX:22) no overrides
> 10:56:13.296 23-Sep-16 -0700 | (d.common.io.nio2.Nio2Connector) Connecting to 
> /X.XX.XXX.XX:22
> 10:56:13.297 23-Sep-16 -0700 | (d.common.io.nio2.Nio2Connector) 
> setOption(SO_REUSEADDR)[true] from property=socket-reuseaddr
> 10:56:13.389 23-Sep-16 -0700 | (shd.common.io.nio2.Nio2Session) Creating 
> IoSession on /0:0:0:0:0:0:0:0:57579 from /X.XX.XXX.XX:22
> 10:56:13.390 23-Sep-16 -0700 | (ient.session.ClientSessionImpl) Client 
> session created: Nio2Session[local=/0:0:0:0:0:0:0:0:57579, 
> remote=/X.XX.XXX.XX:22]
> 10:56:13.391 23-Sep-16 -0700 | (.session.ClientUserAuthService) 
> ClientUserAuthService(ClientSessionImpl[null@/X.XX.XXX.XX:22]) client 
> methods: [publickey, keyboard-interactive, password]
> 10:56:13.391 23-Sep-16 -0700 | (helpers.SessionTimeoutListener) 
> sessionCreated(ClientSessionImpl[null@/X.XX.XXX.XX:22]) tracking
> 10:56:13.391 23-Sep-16 -0700 | (ient.session.ClientSessionImpl) 
> sendIdentification(ClientSessionImpl[null@/X.XX.XXX.XX:22]): 
> SSH-2.0-SSHD-CORE-1.2.0
> 10:56:13.391 23-Sep-16 -0700 | (shd.common.io.nio2.Nio2Session) Writing 25 
> bytes
> 10:56:13.392 23-Sep-16 -0700 | (ient.session.ClientSessionImpl) 
> sendKexInit(ClientSessionImpl[null@/X.XX.XXX.XX:22]) Send SSH_MSG_KEXINIT
> 10:56:13.392 23-Sep-16 -0700 | (shd.common.io.nio2.Nio2Session) Writing 592 
> bytes
> 10:56:13.393 23-Sep-16 -0700 | (.session.ClientUserAuthService) 
> auth(ClientSessionImpl[@/X.XX.XXX.XX:22])[ssh-connection] send 
> SSH_MSG_USERAUTH_REQUEST for 'none'
> 10:56:13.393 23-Sep-16 -0700 | (shd.common.io.nio2.Nio2Session) 
> handleCompletedWriteCycle(Nio2Session[local=/0:0:0:0:0:0:0:0:57579, 
> remote=/X.XX.XXX.XX:22]) finished writing len=25
> 10:56:13.395 23-Sep-16 -0700 | (ient.session.ClientSessionImpl) 
> writePacket(ClientSessionImpl[@/X.XX.XXX.XX:22])[SSH_MSG_USERAUTH_REQUEST]
>  Start flagging packets as pending until key exchange is done
> 10:56:13.396 23-Sep-16 -0700 | (shd.common.io.nio2.Nio2Session) 
> handleCompletedWriteCycle(Nio2Session[local=/0:0:0:0:0:0:0:0:57579, 
> remote=/X.XX.XXX.XX:22]) finished writing len=592
> 10:56:13.480 23-Sep-16 -0700 | (shd.common.io.nio2.Nio2Session) 
> handleReadCycleCompletion(Nio2Session[local=/0:0:0:0:0:0:0:0:57579, 
> remote=/X.XX.XXX.XX:22]) read 568 bytes
> 10:56:13.480 23-Sep-16 -0700 | (ient.session.ClientSessionImpl) 
> doReadIdentification(ClientSessionImpl[@/X.XX.XXX.XX:22]) 
> line='SSH-2.0-mod_sftp/0.9.7'
> 10:56:13.480 23-Sep-16 -0700 | (ient.session.ClientSessionImpl) 
> readIdentification(ClientSessionImpl[@/X.XX.XXX.XX:22]) Server 
> version string: SSH-2.0-mod_sftp/0.9.7
> 10:56:13.480 23-Sep-16 -0700 | (ient.session.ClientSessionImpl) 
> handleKexInit(ClientSessionImpl[@/X.XX.XXX.XX:22]) SSH_MSG_KEXINIT
> 10:56:13.480 23-Sep-16 -0700 | (ient.session.ClientSessionImpl) 
> setNegotiationResult(ClientSessionImpl[@/X.XX.XXX.XX:22]) Kex: 
> server->client aes128-ctr hmac-sha1 none
> 10:56:13.480 23-Sep-16 -0700 | (ient.session.ClientSessionImpl) 
> setNegotiationResult(ClientSessionImpl[@/X.XX.XXX.XX:22]) Kex: 
> client->server aes128-ctr hmac-sha1 none
> 10:56:13.480 23-Sep-16 -0700 | (he.sshd.client.kex.DHGEXClient) 
> init(ClientSessionImpl[@/X.XX.XXX.XX:22]) Send 
> SSH_MSG_KEX_DH_GEX_REQUEST
> 10:56:13.480 23-Sep-16 -0700 | (shd.common.io.nio2.Nio2Session) Writing 32 
> bytes
> 10:56:13.481 23-Sep-16 -0700 | (shd.common.io.nio2.Nio2Session)

[jira] [Commented] (SSHD-701) IllegalArgumentException processing SSH_MSG_CHANNEL_OPEN_CONFIRMATION with initial window size of -1

2016-09-30 Thread Roger Hart (JIRA) 

[ 
https://issues.apache.org/jira/browse/SSHD-701?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel=15536433#comment-15536433
 ] 

Roger Hart commented on SSHD-701:
-

[~lgoldstein] Thanks for the quick fix. Could I get a build with this fix for 
testing?

Regards,
Roger

> IllegalArgumentException processing SSH_MSG_CHANNEL_OPEN_CONFIRMATION with 
> initial window size of -1
> 
>
> Key: SSHD-701
> URL: https://issues.apache.org/jira/browse/SSHD-701
> Project: MINA SSHD
>  Issue Type: Improvement
>Affects Versions: 1.2.0
>Reporter: Roger Hart
>Assignee: Goldstein Lyor
>Priority: Minor
> Fix For: 1.4.0
>
>
> We're using Apache MINA SSHD 1.2.0 successfully except for one server which 
> sends an init window size of -1 in the SSH_MSG_CHANNEL_OPEN_CONFIRMATION 
> message (other servers send 0). This causes SSHD to throw an 
> IllegalArgumentException here: 
> ValidateUtils.checkTrue(window >= 0, "Negative window size: %d", window);
> I'm able to send files to this server using the Win SCP command line client.
> It would be nice if SSHD was more robust and treated a negative window size 
> as 0.
> Here's the SSHD log entries:
> 10:56:13.296 23-Sep-16 -0700 | (ultConfigFileHostEntryResolver) 
> resolveEffectiveHost(@/X.XX.XXX.XX:22) => null
> 10:56:13.296 23-Sep-16 -0700 | (g.apache.sshd.client.SshClient) 
> connect(@/X.XX.XXX.XX:22) no overrides
> 10:56:13.296 23-Sep-16 -0700 | (d.common.io.nio2.Nio2Connector) Connecting to 
> /X.XX.XXX.XX:22
> 10:56:13.297 23-Sep-16 -0700 | (d.common.io.nio2.Nio2Connector) 
> setOption(SO_REUSEADDR)[true] from property=socket-reuseaddr
> 10:56:13.389 23-Sep-16 -0700 | (shd.common.io.nio2.Nio2Session) Creating 
> IoSession on /0:0:0:0:0:0:0:0:57579 from /X.XX.XXX.XX:22
> 10:56:13.390 23-Sep-16 -0700 | (ient.session.ClientSessionImpl) Client 
> session created: Nio2Session[local=/0:0:0:0:0:0:0:0:57579, 
> remote=/X.XX.XXX.XX:22]
> 10:56:13.391 23-Sep-16 -0700 | (.session.ClientUserAuthService) 
> ClientUserAuthService(ClientSessionImpl[null@/X.XX.XXX.XX:22]) client 
> methods: [publickey, keyboard-interactive, password]
> 10:56:13.391 23-Sep-16 -0700 | (helpers.SessionTimeoutListener) 
> sessionCreated(ClientSessionImpl[null@/X.XX.XXX.XX:22]) tracking
> 10:56:13.391 23-Sep-16 -0700 | (ient.session.ClientSessionImpl) 
> sendIdentification(ClientSessionImpl[null@/X.XX.XXX.XX:22]): 
> SSH-2.0-SSHD-CORE-1.2.0
> 10:56:13.391 23-Sep-16 -0700 | (shd.common.io.nio2.Nio2Session) Writing 25 
> bytes
> 10:56:13.392 23-Sep-16 -0700 | (ient.session.ClientSessionImpl) 
> sendKexInit(ClientSessionImpl[null@/X.XX.XXX.XX:22]) Send SSH_MSG_KEXINIT
> 10:56:13.392 23-Sep-16 -0700 | (shd.common.io.nio2.Nio2Session) Writing 592 
> bytes
> 10:56:13.393 23-Sep-16 -0700 | (.session.ClientUserAuthService) 
> auth(ClientSessionImpl[@/X.XX.XXX.XX:22])[ssh-connection] send 
> SSH_MSG_USERAUTH_REQUEST for 'none'
> 10:56:13.393 23-Sep-16 -0700 | (shd.common.io.nio2.Nio2Session) 
> handleCompletedWriteCycle(Nio2Session[local=/0:0:0:0:0:0:0:0:57579, 
> remote=/X.XX.XXX.XX:22]) finished writing len=25
> 10:56:13.395 23-Sep-16 -0700 | (ient.session.ClientSessionImpl) 
> writePacket(ClientSessionImpl[@/X.XX.XXX.XX:22])[SSH_MSG_USERAUTH_REQUEST]
>  Start flagging packets as pending until key exchange is done
> 10:56:13.396 23-Sep-16 -0700 | (shd.common.io.nio2.Nio2Session) 
> handleCompletedWriteCycle(Nio2Session[local=/0:0:0:0:0:0:0:0:57579, 
> remote=/X.XX.XXX.XX:22]) finished writing len=592
> 10:56:13.480 23-Sep-16 -0700 | (shd.common.io.nio2.Nio2Session) 
> handleReadCycleCompletion(Nio2Session[local=/0:0:0:0:0:0:0:0:57579, 
> remote=/X.XX.XXX.XX:22]) read 568 bytes
> 10:56:13.480 23-Sep-16 -0700 | (ient.session.ClientSessionImpl) 
> doReadIdentification(ClientSessionImpl[@/X.XX.XXX.XX:22]) 
> line='SSH-2.0-mod_sftp/0.9.7'
> 10:56:13.480 23-Sep-16 -0700 | (ient.session.ClientSessionImpl) 
> readIdentification(ClientSessionImpl[@/X.XX.XXX.XX:22]) Server 
> version string: SSH-2.0-mod_sftp/0.9.7
> 10:56:13.480 23-Sep-16 -0700 | (ient.session.ClientSessionImpl) 
> handleKexInit(ClientSessionImpl[@/X.XX.XXX.XX:22]) SSH_MSG_KEXINIT
> 10:56:13.480 23-Sep-16 -0700 | (ient.session.ClientSessionImpl) 
> setNegotiationResult(ClientSessionImpl[@/X.XX.XXX.XX:22]) Kex: 
> server->client aes128-ctr hmac-sha1 none
> 10:56:13.480 23-Sep-16 -0700 | (ient.session.ClientSessionImpl) 
> setNegotiationResult(ClientSessionImpl[@/X.XX.XXX.XX:22]) Kex: 
> client->server aes128-ctr hmac-sha1 none
> 10:56:13.480 23-Sep-16 -0700 | (he.sshd.client.kex.DHGEXClient) 
> init(ClientSessionImpl[@/X.XX.XXX.XX:22]) Send 
> SSH_MSG_KEX_DH_GEX_REQUEST
> 10:56:13.480 23-Sep-16 -0700 |

[jira] [Commented] (SSHD-701) IllegalArgumentException processing SSH_MSG_CHANNEL_OPEN_CONFIRMATION with initial window size of -1

2016-09-26 Thread Roger Hart (JIRA) 

[ 
https://issues.apache.org/jira/browse/SSHD-701?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel=15523829#comment-15523829
 ] 

Roger Hart commented on SSHD-701:
-

The spec is silent on negative values for initial window size, so I think it's 
reasonable and robust to interpret negative values as 0, meaning that no data 
can be sent without adjusting the window. Throwing up your hands with an 
IllegalArgumentException seems unwarranted.

> IllegalArgumentException processing SSH_MSG_CHANNEL_OPEN_CONFIRMATION with 
> initial window size of -1
> 
>
> Key: SSHD-701
> URL: https://issues.apache.org/jira/browse/SSHD-701
> Project: MINA SSHD
>  Issue Type: Improvement
>Affects Versions: 1.2.0
>Reporter: Roger Hart
>Priority: Minor
>
> We're using Apache MINA SSHD 1.2.0 successfully except for one server which 
> sends an init window size of -1 in the SSH_MSG_CHANNEL_OPEN_CONFIRMATION 
> message (other servers send 0). This causes SSHD to throw an 
> IllegalArgumentException here: 
> ValidateUtils.checkTrue(window >= 0, "Negative window size: %d", window);
> I'm able to send files to this server using the Win SCP command line client.
> It would be nice if SSHD was more robust and treated a negative window size 
> as 0.
> Here's the SSHD log entries:
> 10:56:13.296 23-Sep-16 -0700 | (ultConfigFileHostEntryResolver) 
> resolveEffectiveHost(@/X.XX.XXX.XX:22) => null
> 10:56:13.296 23-Sep-16 -0700 | (g.apache.sshd.client.SshClient) 
> connect(@/X.XX.XXX.XX:22) no overrides
> 10:56:13.296 23-Sep-16 -0700 | (d.common.io.nio2.Nio2Connector) Connecting to 
> /X.XX.XXX.XX:22
> 10:56:13.297 23-Sep-16 -0700 | (d.common.io.nio2.Nio2Connector) 
> setOption(SO_REUSEADDR)[true] from property=socket-reuseaddr
> 10:56:13.389 23-Sep-16 -0700 | (shd.common.io.nio2.Nio2Session) Creating 
> IoSession on /0:0:0:0:0:0:0:0:57579 from /X.XX.XXX.XX:22
> 10:56:13.390 23-Sep-16 -0700 | (ient.session.ClientSessionImpl) Client 
> session created: Nio2Session[local=/0:0:0:0:0:0:0:0:57579, 
> remote=/X.XX.XXX.XX:22]
> 10:56:13.391 23-Sep-16 -0700 | (.session.ClientUserAuthService) 
> ClientUserAuthService(ClientSessionImpl[null@/X.XX.XXX.XX:22]) client 
> methods: [publickey, keyboard-interactive, password]
> 10:56:13.391 23-Sep-16 -0700 | (helpers.SessionTimeoutListener) 
> sessionCreated(ClientSessionImpl[null@/X.XX.XXX.XX:22]) tracking
> 10:56:13.391 23-Sep-16 -0700 | (ient.session.ClientSessionImpl) 
> sendIdentification(ClientSessionImpl[null@/X.XX.XXX.XX:22]): 
> SSH-2.0-SSHD-CORE-1.2.0
> 10:56:13.391 23-Sep-16 -0700 | (shd.common.io.nio2.Nio2Session) Writing 25 
> bytes
> 10:56:13.392 23-Sep-16 -0700 | (ient.session.ClientSessionImpl) 
> sendKexInit(ClientSessionImpl[null@/X.XX.XXX.XX:22]) Send SSH_MSG_KEXINIT
> 10:56:13.392 23-Sep-16 -0700 | (shd.common.io.nio2.Nio2Session) Writing 592 
> bytes
> 10:56:13.393 23-Sep-16 -0700 | (.session.ClientUserAuthService) 
> auth(ClientSessionImpl[@/X.XX.XXX.XX:22])[ssh-connection] send 
> SSH_MSG_USERAUTH_REQUEST for 'none'
> 10:56:13.393 23-Sep-16 -0700 | (shd.common.io.nio2.Nio2Session) 
> handleCompletedWriteCycle(Nio2Session[local=/0:0:0:0:0:0:0:0:57579, 
> remote=/X.XX.XXX.XX:22]) finished writing len=25
> 10:56:13.395 23-Sep-16 -0700 | (ient.session.ClientSessionImpl) 
> writePacket(ClientSessionImpl[@/X.XX.XXX.XX:22])[SSH_MSG_USERAUTH_REQUEST]
>  Start flagging packets as pending until key exchange is done
> 10:56:13.396 23-Sep-16 -0700 | (shd.common.io.nio2.Nio2Session) 
> handleCompletedWriteCycle(Nio2Session[local=/0:0:0:0:0:0:0:0:57579, 
> remote=/X.XX.XXX.XX:22]) finished writing len=592
> 10:56:13.480 23-Sep-16 -0700 | (shd.common.io.nio2.Nio2Session) 
> handleReadCycleCompletion(Nio2Session[local=/0:0:0:0:0:0:0:0:57579, 
> remote=/X.XX.XXX.XX:22]) read 568 bytes
> 10:56:13.480 23-Sep-16 -0700 | (ient.session.ClientSessionImpl) 
> doReadIdentification(ClientSessionImpl[@/X.XX.XXX.XX:22]) 
> line='SSH-2.0-mod_sftp/0.9.7'
> 10:56:13.480 23-Sep-16 -0700 | (ient.session.ClientSessionImpl) 
> readIdentification(ClientSessionImpl[@/X.XX.XXX.XX:22]) Server 
> version string: SSH-2.0-mod_sftp/0.9.7
> 10:56:13.480 23-Sep-16 -0700 | (ient.session.ClientSessionImpl) 
> handleKexInit(ClientSessionImpl[@/X.XX.XXX.XX:22]) SSH_MSG_KEXINIT
> 10:56:13.480 23-Sep-16 -0700 | (ient.session.ClientSessionImpl) 
> setNegotiationResult(ClientSessionImpl[@/X.XX.XXX.XX:22]) Kex: 
> server->client aes128-ctr hmac-sha1 none
> 10:56:13.480 23-Sep-16 -0700 | (ient.session.ClientSessionImpl) 
> setNegotiationResult(ClientSessionImpl[@/X.XX.XXX.XX:22]) Kex: 
> client->server aes128-ctr hmac-sha1 none
> 10:56:13.480 23-Sep-16 -0700 | (he.sshd.client.kex.DHGEXClient) 
>

[jira] [Created] (SSHD-701) IllegalArgumentException processing SSH_MSG_CHANNEL_OPEN_CONFIRMATION with initial window size of -1

2016-09-26 Thread Roger Hart (JIRA) 
Roger Hart created SSHD-701:
---

 Summary: IllegalArgumentException processing 
SSH_MSG_CHANNEL_OPEN_CONFIRMATION with initial window size of -1
 Key: SSHD-701
 URL: https://issues.apache.org/jira/browse/SSHD-701
 Project: MINA SSHD
  Issue Type: Bug
Affects Versions: 1.2.0
Reporter: Roger Hart


We're using Apache MINA SSHD 1.2.0 successfully except for one server which 
sends an init window size of -1 in the SSH_MSG_CHANNEL_OPEN_CONFIRMATION 
message (other servers send 0). This causes SSHD to throw an 
IllegalArgumentException here: 

ValidateUtils.checkTrue(window >= 0, "Negative window size: %d", window);

I'm able to send files to this server using the Win SCP command line client.

It would be nice if SSHD was more robust and treated a negative window size as 
0.

Here's the SSHD log entries:

10:56:13.296 23-Sep-16 -0700 | (ultConfigFileHostEntryResolver) 
resolveEffectiveHost(@/X.XX.XXX.XX:22) => null
10:56:13.296 23-Sep-16 -0700 | (g.apache.sshd.client.SshClient) 
connect(@/X.XX.XXX.XX:22) no overrides
10:56:13.296 23-Sep-16 -0700 | (d.common.io.nio2.Nio2Connector) Connecting to 
/X.XX.XXX.XX:22
10:56:13.297 23-Sep-16 -0700 | (d.common.io.nio2.Nio2Connector) 
setOption(SO_REUSEADDR)[true] from property=socket-reuseaddr
10:56:13.389 23-Sep-16 -0700 | (shd.common.io.nio2.Nio2Session) Creating 
IoSession on /0:0:0:0:0:0:0:0:57579 from /X.XX.XXX.XX:22
10:56:13.390 23-Sep-16 -0700 | (ient.session.ClientSessionImpl) Client session 
created: Nio2Session[local=/0:0:0:0:0:0:0:0:57579, remote=/X.XX.XXX.XX:22]
10:56:13.391 23-Sep-16 -0700 | (.session.ClientUserAuthService) 
ClientUserAuthService(ClientSessionImpl[null@/X.XX.XXX.XX:22]) client methods: 
[publickey, keyboard-interactive, password]
10:56:13.391 23-Sep-16 -0700 | (helpers.SessionTimeoutListener) 
sessionCreated(ClientSessionImpl[null@/X.XX.XXX.XX:22]) tracking
10:56:13.391 23-Sep-16 -0700 | (ient.session.ClientSessionImpl) 
sendIdentification(ClientSessionImpl[null@/X.XX.XXX.XX:22]): 
SSH-2.0-SSHD-CORE-1.2.0
10:56:13.391 23-Sep-16 -0700 | (shd.common.io.nio2.Nio2Session) Writing 25 bytes
10:56:13.392 23-Sep-16 -0700 | (ient.session.ClientSessionImpl) 
sendKexInit(ClientSessionImpl[null@/X.XX.XXX.XX:22]) Send SSH_MSG_KEXINIT
10:56:13.392 23-Sep-16 -0700 | (shd.common.io.nio2.Nio2Session) Writing 592 
bytes
10:56:13.393 23-Sep-16 -0700 | (.session.ClientUserAuthService) 
auth(ClientSessionImpl[@/X.XX.XXX.XX:22])[ssh-connection] send 
SSH_MSG_USERAUTH_REQUEST for 'none'
10:56:13.393 23-Sep-16 -0700 | (shd.common.io.nio2.Nio2Session) 
handleCompletedWriteCycle(Nio2Session[local=/0:0:0:0:0:0:0:0:57579, 
remote=/X.XX.XXX.XX:22]) finished writing len=25
10:56:13.395 23-Sep-16 -0700 | (ient.session.ClientSessionImpl) 
writePacket(ClientSessionImpl[@/X.XX.XXX.XX:22])[SSH_MSG_USERAUTH_REQUEST]
 Start flagging packets as pending until key exchange is done
10:56:13.396 23-Sep-16 -0700 | (shd.common.io.nio2.Nio2Session) 
handleCompletedWriteCycle(Nio2Session[local=/0:0:0:0:0:0:0:0:57579, 
remote=/X.XX.XXX.XX:22]) finished writing len=592
10:56:13.480 23-Sep-16 -0700 | (shd.common.io.nio2.Nio2Session) 
handleReadCycleCompletion(Nio2Session[local=/0:0:0:0:0:0:0:0:57579, 
remote=/X.XX.XXX.XX:22]) read 568 bytes
10:56:13.480 23-Sep-16 -0700 | (ient.session.ClientSessionImpl) 
doReadIdentification(ClientSessionImpl[@/X.XX.XXX.XX:22]) 
line='SSH-2.0-mod_sftp/0.9.7'
10:56:13.480 23-Sep-16 -0700 | (ient.session.ClientSessionImpl) 
readIdentification(ClientSessionImpl[@/X.XX.XXX.XX:22]) Server version 
string: SSH-2.0-mod_sftp/0.9.7
10:56:13.480 23-Sep-16 -0700 | (ient.session.ClientSessionImpl) 
handleKexInit(ClientSessionImpl[@/X.XX.XXX.XX:22]) SSH_MSG_KEXINIT
10:56:13.480 23-Sep-16 -0700 | (ient.session.ClientSessionImpl) 
setNegotiationResult(ClientSessionImpl[@/X.XX.XXX.XX:22]) Kex: 
server->client aes128-ctr hmac-sha1 none
10:56:13.480 23-Sep-16 -0700 | (ient.session.ClientSessionImpl) 
setNegotiationResult(ClientSessionImpl[@/X.XX.XXX.XX:22]) Kex: 
client->server aes128-ctr hmac-sha1 none
10:56:13.480 23-Sep-16 -0700 | (he.sshd.client.kex.DHGEXClient) 
init(ClientSessionImpl[@/X.XX.XXX.XX:22]) Send 
SSH_MSG_KEX_DH_GEX_REQUEST
10:56:13.480 23-Sep-16 -0700 | (shd.common.io.nio2.Nio2Session) Writing 32 bytes
10:56:13.481 23-Sep-16 -0700 | (shd.common.io.nio2.Nio2Session) 
handleCompletedWriteCycle(Nio2Session[local=/0:0:0:0:0:0:0:0:57579, 
remote=/X.XX.XXX.XX:22]) finished writing len=32
10:56:13.575 23-Sep-16 -0700 | (shd.common.io.nio2.Nio2Session) 
handleReadCycleCompletion(Nio2Session[local=/0:0:0:0:0:0:0:0:57579, 
remote=/X.XX.XXX.XX:22]) read 536 bytes
10:56:13.575 23-Sep-16 -0700 | (he.sshd.client.kex.DHGEXClient) 
next(DHGEXClient[diffie-hellman-group-exchange-sha256])[ClientSessionImpl[@/X.XX.XXX.XX:22]]
 process command=SSH_MSG_KEX_DH_GEX_GROUP
10:56:13.731