You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@mina.apache.org by "Guillaume Nodet (JIRA)" <ji...@apache.org> on 2013/07/18 17:22:49 UTC

[jira] [Commented] (SSHD-138) Fresh git clone failed on ScpTest testWithGanymede

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

Guillaume Nodet commented on SSHD-138:
--------------------------------------

One of the problem comes from the fact that SSHD may send an exit-status after the channel being closed:

2013-07-18 16:58:41,344 [NioProcessor-2 ] DEBUG ServerSession                  - Received packet SSH_MSG_CHANNEL_CLOSE
2013-07-18 16:58:41,344 [NioProcessor-2 ] DEBUG ChannelSession                 - Received SSH_MSG_CHANNEL_CLOSE on channel 1
2013-07-18 16:58:41,344 [NioProcessor-2 ] DEBUG ChannelSession                 - Send SSH_MSG_CHANNEL_CLOSE on channel 1
2013-07-18 16:58:41,344 [target/scp/gan]] TRACE ServerSession                  - Sending packet #19: 60 00 00 00 65
2013-07-18 16:58:41,345 [NioProcessor-2 ] TRACE ServerSession                  - Sending packet #20: 61 00 00 00 65
2013-07-18 16:58:41,345 [target/scp/gan]] DEBUG ChannelSession                 - Send SSH_MSG_CHANNEL_REQUEST exit-status on channel 1

                
> Fresh git clone failed on ScpTest testWithGanymede
> --------------------------------------------------
>
>                 Key: SSHD-138
>                 URL: https://issues.apache.org/jira/browse/SSHD-138
>             Project: MINA SSHD
>          Issue Type: Bug
>    Affects Versions: 0.5.0
>         Environment: Windows Xp sp3 32 bit java 1.6.0.26
>            Reporter: Denis Bardadym
>            Assignee: Guillaume Nodet
>
> Console log
> Testsuite: org.apache.sshd.ScpTest
> 2011-07-25 11:24:27,109 [main           ] INFO  SecurityUtils                  - Trying to register BouncyCastle as a JCE provider
> 2011-07-25 11:24:27,671 [main           ] INFO  SecurityUtils                  - Registration succeeded
> Log(jsch,1): Connecting to localhost port 2963
> Log(jsch,1): Connection established
> 2011-07-25 11:24:28,062 [NioProcessor-2 ] INFO  ServerSession                  - Session created...
> Log(jsch,1): Remote version string: SSH-2.0-SSHD-CORE-0.5.1-SNAPSHOT
> Log(jsch,1): Local version string: SSH-2.0-JSCH-0.1.42
> Log(jsch,1): CheckCiphers: aes256-ctr,aes192-ctr,aes128-ctr,aes256-cbc,aes192-cbc,aes128-cbc,3des-ctr,arcfour,arcfour128,arcfour256
> 2011-07-25 11:24:28,156 [NioProcessor-2 ] INFO  ServerSession                  - Client version string: SSH-2.0-JSCH-0.1.42
> Log(jsch,1): aes256-ctr is not available.
> Log(jsch,1): aes192-ctr is not available.
> Log(jsch,1): aes256-cbc is not available.
> Log(jsch,1): aes192-cbc is not available.
> Log(jsch,1): arcfour256 is not available.
> Log(jsch,1): SSH_MSG_KEXINIT sent
> Log(jsch,1): SSH_MSG_KEXINIT received
> 2011-07-25 11:24:28,328 [NioProcessor-2 ] INFO  ServerSession                  - Received SSH_MSG_KEXINIT
> Log(jsch,1): kex: server->client aes128-cbc hmac-md5 none
> Log(jsch,1): kex: client->server aes128-cbc hmac-md5 none
> Log(jsch,1): SSH_MSG_KEXDH_INIT sent
> Log(jsch,1): expecting SSH_MSG_KEXDH_REPLY
> 2011-07-25 11:24:28,390 [NioProcessor-2 ] INFO  DHG1                           - Received SSH_MSG_KEXDH_INIT
> 2011-07-25 11:24:28,468 [NioProcessor-2 ] INFO  DHG1                           - Send SSH_MSG_KEXDH_REPLY
> 2011-07-25 11:24:28,468 [NioProcessor-2 ] INFO  ServerSession                  - Send SSH_MSG_NEWKEYS
> Log(jsch,1): ssh_rsa_verify: signature true
> Log(jsch,2): Permanently added 'localhost' (RSA) to the list of known hosts.
> Log(jsch,1): SSH_MSG_NEWKEYS sent
> Log(jsch,1): SSH_MSG_NEWKEYS received
> 2011-07-25 11:24:28,500 [NioProcessor-2 ] INFO  ServerSession                  - Received SSH_MSG_NEWKEYS
> Log(jsch,1): SSH_MSG_SERVICE_REQUEST sent
> 2011-07-25 11:24:28,578 [NioProcessor-2 ] INFO  ServerSession                  - Received SSH_MSG_SERVICE_REQUEST 'ssh-userauth'
> 2011-07-25 11:24:28,578 [NioProcessor-2 ] INFO  ServerSession                  - Accepting user authentication request
> 2011-07-25 11:24:28,578 [NioProcessor-2 ] INFO  ServerSession                  - Authorized authentication methods: password
> Log(jsch,1): SSH_MSG_SERVICE_ACCEPT received
> 2011-07-25 11:24:28,578 [NioProcessor-2 ] INFO  ServerSession                  - Received SSH_MSG_USERAUTH_REQUEST
> 2011-07-25 11:24:28,687 [NioProcessor-2 ] INFO  ServerSession                  - Authenticating user 'sshd' with method 'none'
> 2011-07-25 11:24:28,687 [NioProcessor-2 ] INFO  ServerSession                  - Unsupported authentication method 'none'
> Log(jsch,1): Authentications that can continue: password
> Log(jsch,1): Next authentication method: password
> 2011-07-25 11:24:28,687 [NioProcessor-2 ] INFO  ServerSession                  - Received SSH_MSG_USERAUTH_REQUEST
> 2011-07-25 11:24:28,687 [NioProcessor-2 ] INFO  ServerSession                  - Authenticating user 'sshd' with method 'password'
> 2011-07-25 11:24:28,687 [NioProcessor-2 ] INFO  ServerSession                  - Authentication succeeded
> Log(jsch,1): Authentication succeeded (password).
> 2011-07-25 11:24:28,718 [NioProcessor-2 ] INFO  ServerSession                  - Received SSH_MSG_CHANNEL_OPEN session
> 2011-07-25 11:24:28,781 [NioProcessor-2 ] INFO  ChannelSession                 - Received SSH_MSG_CHANNEL_REQUEST on channel 0
> 2011-07-25 11:24:28,781 [NioProcessor-2 ] INFO  ChannelSession                 - Received channel request: exec
> 2011-07-25 11:24:28,781 [NioProcessor-2 ] INFO  ChannelSession                 - Executing command: scp -t target/scp/out.txt
> 2011-07-25 11:24:28,906 [NioProcessor-2 ] INFO  ChannelSession                 - Received SSH_MSG_CHANNEL_CLOSE on channel 0
> 2011-07-25 11:24:28,906 [NioProcessor-2 ] INFO  ChannelSession                 - Send SSH_MSG_CHANNEL_CLOSE on channel 0
> 2011-07-25 11:24:28,906 [et/scp/out.txt]] INFO  ScpCommand                     - Error in scp command
> java.io.IOException: Pipe closed
> 	at org.apache.sshd.common.channel.ChannelPipedInputStream.read(ChannelPipedInputStream.java:72)
> 	at org.apache.sshd.common.channel.ChannelPipedInputStream.read(ChannelPipedInputStream.java:58)
> 	at org.apache.sshd.server.command.ScpCommand.readAck(ScpCommand.java:422)
> 	at org.apache.sshd.server.command.ScpCommand.run(ScpCommand.java:147)
> 	at java.lang.Thread.run(Thread.java:662)
> 2011-07-25 11:24:29,015 [et/scp/out.txt]] INFO  ChannelSession                 - Send SSH_MSG_CHANNEL_EOF on channel 0
> 2011-07-25 11:24:29,015 [et/scp/out.txt]] INFO  ChannelSession                 - Send SSH_MSG_CHANNEL_REQUEST exit-status on channel 0
> 2011-07-25 11:24:29,015 [NioProcessor-2 ] INFO  ServerSession                  - Received SSH_MSG_CHANNEL_OPEN session
> 2011-07-25 11:24:29,015 [NioProcessor-2 ] INFO  ChannelSession                 - Received SSH_MSG_CHANNEL_REQUEST on channel 1
> 2011-07-25 11:24:29,015 [NioProcessor-2 ] INFO  ChannelSession                 - Received channel request: exec
> 2011-07-25 11:24:29,109 [NioProcessor-2 ] INFO  ChannelSession                 - Executing command: scp -t target/scp
> 2011-07-25 11:24:29,234 [NioProcessor-2 ] INFO  ChannelSession                 - Received SSH_MSG_CHANNEL_CLOSE on channel 1
> 2011-07-25 11:24:29,234 [NioProcessor-2 ] INFO  ChannelSession                 - Send SSH_MSG_CHANNEL_CLOSE on channel 1
> 2011-07-25 11:24:29,234 [-t, target/scp]] INFO  ScpCommand                     - Error in scp command
> java.io.IOException: Pipe closed
> 	at org.apache.sshd.common.channel.ChannelPipedInputStream.read(ChannelPipedInputStream.java:72)
> 	at org.apache.sshd.common.channel.ChannelPipedInputStream.read(ChannelPipedInputStream.java:58)
> 	at org.apache.sshd.server.command.ScpCommand.readAck(ScpCommand.java:422)
> 	at org.apache.sshd.server.command.ScpCommand.run(ScpCommand.java:147)
> 	at java.lang.Thread.run(Thread.java:662)
> 2011-07-25 11:24:29,328 [-t, target/scp]] INFO  ChannelSession                 - Send SSH_MSG_CHANNEL_EOF on channel 1
> 2011-07-25 11:24:29,328 [-t, target/scp]] INFO  ChannelSession                 - Send SSH_MSG_CHANNEL_REQUEST exit-status on channel 1
> 2011-07-25 11:24:29,343 [NioProcessor-2 ] INFO  ServerSession                  - Received SSH_MSG_CHANNEL_OPEN session
> 2011-07-25 11:24:29,406 [NioProcessor-2 ] INFO  ChannelSession                 - Received SSH_MSG_CHANNEL_REQUEST on channel 2
> 2011-07-25 11:24:29,406 [NioProcessor-2 ] INFO  ChannelSession                 - Received channel request: exec
> 2011-07-25 11:24:29,406 [NioProcessor-2 ] INFO  ChannelSession                 - Executing command: scp -t target
> 2011-07-25 11:24:29,406 [cp, -t, target]] INFO  ScpCommand                     - Error in scp command
> java.io.IOException: File is a directory: org.apache.sshd.server.filesystem.NativeSshFile@82764b
> 	at org.apache.sshd.server.command.ScpCommand.writeFile(ScpCommand.java:314)
> 	at org.apache.sshd.server.command.ScpCommand.run(ScpCommand.java:171)
> 	at java.lang.Thread.run(Thread.java:662)
> 2011-07-25 11:24:29,437 [cp, -t, target]] INFO  ChannelSession                 - Send SSH_MSG_CHANNEL_EOF on channel 2
> 2011-07-25 11:24:29,437 [cp, -t, target]] INFO  ChannelSession                 - Send SSH_MSG_CHANNEL_REQUEST exit-status on channel 2
> 2011-07-25 11:24:29,437 [cp, -t, target]] INFO  ChannelSession                 - Send SSH_MSG_CHANNEL_CLOSE on channel 2
> 2011-07-25 11:24:29,406 [NioProcessor-2 ] INFO  ChannelSession                 - Received SSH_MSG_CHANNEL_CLOSE on channel 2
> 2011-07-25 11:24:29,437 [NioProcessor-2 ] INFO  ServerSession                  - Received SSH_MSG_CHANNEL_OPEN session
> 2011-07-25 11:24:29,468 [NioProcessor-2 ] INFO  ChannelSession                 - Received SSH_MSG_CHANNEL_REQUEST on channel 3
> 2011-07-25 11:24:29,468 [NioProcessor-2 ] INFO  ChannelSession                 - Received channel request: exec
> 2011-07-25 11:24:29,468 [NioProcessor-2 ] INFO  ChannelSession                 - Executing command: scp -f target/scp
> 2011-07-25 11:24:29,468 [-f, target/scp]] INFO  ScpCommand                     - Error in scp command
> java.io.IOException: org.apache.sshd.server.filesystem.NativeSshFile@1e4f7c2 not a regular file
> 	at org.apache.sshd.server.command.ScpCommand.run(ScpCommand.java:216)
> 	at java.lang.Thread.run(Thread.java:662)
> 2011-07-25 11:24:29,546 [-f, target/scp]] INFO  ChannelSession                 - Send SSH_MSG_CHANNEL_EOF on channel 3
> 2011-07-25 11:24:29,546 [-f, target/scp]] INFO  ChannelSession                 - Send SSH_MSG_CHANNEL_REQUEST exit-status on channel 3
> 2011-07-25 11:24:29,546 [-f, target/scp]] INFO  ChannelSession                 - Send SSH_MSG_CHANNEL_CLOSE on channel 3
> 2011-07-25 11:24:29,468 [NioProcessor-2 ] INFO  ChannelSession                 - Received SSH_MSG_CHANNEL_CLOSE on channel 3
> 2011-07-25 11:24:29,546 [NioProcessor-2 ] INFO  ServerSession                  - Received SSH_MSG_CHANNEL_OPEN session
> 2011-07-25 11:24:29,593 [NioProcessor-2 ] INFO  ChannelSession                 - Received SSH_MSG_CHANNEL_REQUEST on channel 4
> 2011-07-25 11:24:29,593 [NioProcessor-2 ] INFO  ChannelSession                 - Received channel request: exec
> 2011-07-25 11:24:29,593 [NioProcessor-2 ] INFO  ChannelSession                 - Executing command: scp -f target/scp/out.txt
> 2011-07-25 11:24:29,593 [NioProcessor-2 ] INFO  ChannelSession                 - Received SSH_MSG_CHANNEL_CLOSE on channel 4
> 2011-07-25 11:24:29,593 [et/scp/out.txt]] INFO  ChannelSession                 - Send SSH_MSG_CHANNEL_EOF on channel 4
> 2011-07-25 11:24:29,656 [et/scp/out.txt]] INFO  ChannelSession                 - Send SSH_MSG_CHANNEL_REQUEST exit-status on channel 4
> 2011-07-25 11:24:29,593 [NioProcessor-2 ] INFO  ChannelSession                 - Send SSH_MSG_CHANNEL_CLOSE on channel 4
> 2011-07-25 11:24:29,656 [NioProcessor-2 ] INFO  ServerSession                  - Received SSH_MSG_CHANNEL_OPEN session
> 2011-07-25 11:24:29,718 [NioProcessor-2 ] INFO  ChannelSession                 - Received SSH_MSG_CHANNEL_REQUEST on channel 5
> 2011-07-25 11:24:29,718 [NioProcessor-2 ] INFO  ChannelSession                 - Received channel request: exec
> 2011-07-25 11:24:29,718 [NioProcessor-2 ] INFO  ChannelSession                 - Executing command: scp -r -f target/scp
> 2011-07-25 11:24:29,781 [NioProcessor-2 ] INFO  ChannelSession                 - Received SSH_MSG_CHANNEL_CLOSE on channel 5
> 2011-07-25 11:24:29,781 [NioProcessor-2 ] INFO  ChannelSession                 - Send SSH_MSG_CHANNEL_CLOSE on channel 5
> 2011-07-25 11:24:29,781 [-f, target/scp]] INFO  ScpCommand                     - Error in scp command
> java.io.IOException: Pipe closed
> 	at org.apache.sshd.common.channel.ChannelPipedInputStream.read(ChannelPipedInputStream.java:72)
> 	at org.apache.sshd.common.channel.ChannelPipedInputStream.read(ChannelPipedInputStream.java:58)
> 	at org.apache.sshd.server.command.ScpCommand.readAck(ScpCommand.java:422)
> 	at org.apache.sshd.server.command.ScpCommand.readDir(ScpCommand.java:413)
> 	at org.apache.sshd.server.command.ScpCommand.run(ScpCommand.java:218)
> 	at java.lang.Thread.run(Thread.java:662)
> 2011-07-25 11:24:29,875 [-f, target/scp]] INFO  ChannelSession                 - Send SSH_MSG_CHANNEL_EOF on channel 5
> 2011-07-25 11:24:29,875 [-f, target/scp]] INFO  ChannelSession                 - Send SSH_MSG_CHANNEL_REQUEST exit-status on channel 5
> 2011-07-25 11:24:29,781 [NioProcessor-2 ] INFO  ServerSession                  - Received SSH_MSG_CHANNEL_OPEN session
> 2011-07-25 11:24:29,906 [NioProcessor-2 ] INFO  ChannelSession                 - Received SSH_MSG_CHANNEL_REQUEST on channel 6
> 2011-07-25 11:24:29,906 [NioProcessor-2 ] INFO  ChannelSession                 - Received channel request: exec
> 2011-07-25 11:24:29,906 [NioProcessor-2 ] INFO  ChannelSession                 - Executing command: scp -t -r target
> Log(jsch,1): Disconnecting from localhost port 2963
> 2011-07-25 11:24:30,031 [NioProcessor-2 ] INFO  ChannelSession                 - Received SSH_MSG_CHANNEL_CLOSE on channel 6
> 2011-07-25 11:24:30,031 [NioProcessor-2 ] INFO  ChannelSession                 - Send SSH_MSG_CHANNEL_CLOSE on channel 6
> 2011-07-25 11:24:30,031 [-t, -r, target]] INFO  ScpCommand                     - Error in scp command
> java.io.IOException: Pipe closed
> 	at org.apache.sshd.common.channel.ChannelPipedInputStream.read(ChannelPipedInputStream.java:72)
> 	at org.apache.sshd.common.channel.ChannelPipedInputStream.read(ChannelPipedInputStream.java:58)
> 	at org.apache.sshd.server.command.ScpCommand.readAck(ScpCommand.java:422)
> 	at org.apache.sshd.server.command.ScpCommand.run(ScpCommand.java:147)
> 	at java.lang.Thread.run(Thread.java:662)
> 2011-07-25 11:24:30,031 [NioProcessor-2 ] INFO  ServerSession                  - Closing session
> 2011-07-25 11:24:30,093 [-t, -r, target]] INFO  ChannelSession                 - Send SSH_MSG_CHANNEL_EOF on channel 6
> 2011-07-25 11:24:30,093 [-t, -r, target]] INFO  ChannelSession                 - Send SSH_MSG_CHANNEL_REQUEST exit-status on channel 6
> 2011-07-25 11:24:30,234 [NioProcessor-6 ] INFO  ServerSession                  - Session created...
> 2011-07-25 11:24:30,234 [NioProcessor-6 ] INFO  ServerSession                  - Client version string: SSH-2.0-Ganymed Build_210
> 2011-07-25 11:24:30,250 [NioProcessor-6 ] INFO  ServerSession                  - Received SSH_MSG_KEXINIT
> 2011-07-25 11:24:30,515 [NioProcessor-6 ] INFO  DHG14                          - Received SSH_MSG_KEXDH_INIT
> 2011-07-25 11:24:30,796 [NioProcessor-6 ] INFO  DHG14                          - Send SSH_MSG_KEXDH_REPLY
> 2011-07-25 11:24:30,796 [NioProcessor-6 ] INFO  ServerSession                  - Send SSH_MSG_NEWKEYS
> 2011-07-25 11:24:31,046 [NioProcessor-6 ] INFO  ServerSession                  - Received SSH_MSG_NEWKEYS
> 2011-07-25 11:24:31,093 [NioProcessor-6 ] INFO  ServerSession                  - Received SSH_MSG_SERVICE_REQUEST 'ssh-userauth'
> 2011-07-25 11:24:31,093 [NioProcessor-6 ] INFO  ServerSession                  - Accepting user authentication request
> 2011-07-25 11:24:31,093 [NioProcessor-6 ] INFO  ServerSession                  - Authorized authentication methods: password
> 2011-07-25 11:24:31,093 [NioProcessor-6 ] INFO  ServerSession                  - Received SSH_MSG_USERAUTH_REQUEST
> 2011-07-25 11:24:31,093 [NioProcessor-6 ] INFO  ServerSession                  - Authenticating user 'sshd' with method 'none'
> 2011-07-25 11:24:31,187 [NioProcessor-6 ] INFO  ServerSession                  - Unsupported authentication method 'none'
> 2011-07-25 11:24:31,187 [NioProcessor-6 ] INFO  ServerSession                  - Received SSH_MSG_USERAUTH_REQUEST
> 2011-07-25 11:24:31,187 [NioProcessor-6 ] INFO  ServerSession                  - Authenticating user 'sshd' with method 'password'
> 2011-07-25 11:24:31,187 [NioProcessor-6 ] INFO  ServerSession                  - Authentication succeeded
> 2011-07-25 11:24:31,203 [NioProcessor-6 ] INFO  ServerSession                  - Received SSH_MSG_CHANNEL_OPEN session
> 2011-07-25 11:24:31,203 [NioProcessor-6 ] INFO  ChannelSession                 - Received SSH_MSG_CHANNEL_REQUEST on channel 0
> 2011-07-25 11:24:31,296 [NioProcessor-6 ] INFO  ChannelSession                 - Received channel request: exec
> 2011-07-25 11:24:31,296 [NioProcessor-6 ] INFO  ChannelSession                 - Executing command: scp -t -d target/scp/gan
> 2011-07-25 11:24:31,296 [NioProcessor-6 ] INFO  ChannelSession                 - Received SSH_MSG_CHANNEL_CLOSE on channel 0
> 2011-07-25 11:24:31,296 [NioProcessor-6 ] INFO  ChannelSession                 - Send SSH_MSG_CHANNEL_CLOSE on channel 0
> 2011-07-25 11:24:31,296 [target/scp/gan]] INFO  ChannelSession                 - Send SSH_MSG_CHANNEL_EOF on channel 0
> 2011-07-25 11:24:31,296 [NioProcessor-6 ] INFO  ServerSession                  - Received SSH_MSG_CHANNEL_OPEN session
> 2011-07-25 11:24:31,296 [target/scp/gan]] INFO  ChannelSession                 - Send SSH_MSG_CHANNEL_REQUEST exit-status on channel 0
> 2011-07-25 11:24:31,296 [NioProcessor-6 ] INFO  ServerSession                  - Closing session
> 2011-07-25 11:24:31,406 [NioProcessor-6 ] INFO  ChannelSession                 - Closing channel 1 immediately
> Tests run: 2, Failures: 0, Errors: 1, Time elapsed: 4.719 sec
> ------------- Standard Output ---------------
> 2011-07-25 11:24:27,109 [main           ] INFO  SecurityUtils                  - Trying to register BouncyCastle as a JCE provider
> 2011-07-25 11:24:27,671 [main           ] INFO  SecurityUtils                  - Registration succeeded
> Log(jsch,1): Connecting to localhost port 2963
> Log(jsch,1): Connection established
> 2011-07-25 11:24:28,062 [NioProcessor-2 ] INFO  ServerSession                  - Session created...
> Log(jsch,1): Remote version string: SSH-2.0-SSHD-CORE-0.5.1-SNAPSHOT
> Log(jsch,1): Local version string: SSH-2.0-JSCH-0.1.42
> Log(jsch,1): CheckCiphers: aes256-ctr,aes192-ctr,aes128-ctr,aes256-cbc,aes192-cbc,aes128-cbc,3des-ctr,arcfour,arcfour128,arcfour256
> 2011-07-25 11:24:28,156 [NioProcessor-2 ] INFO  ServerSession                  - Client version string: SSH-2.0-JSCH-0.1.42
> Log(jsch,1): aes256-ctr is not available.
> Log(jsch,1): aes192-ctr is not available.
> Log(jsch,1): aes256-cbc is not available.
> Log(jsch,1): aes192-cbc is not available.
> Log(jsch,1): arcfour256 is not available.
> Log(jsch,1): SSH_MSG_KEXINIT sent
> Log(jsch,1): SSH_MSG_KEXINIT received
> 2011-07-25 11:24:28,328 [NioProcessor-2 ] INFO  ServerSession                  - Received SSH_MSG_KEXINIT
> Log(jsch,1): kex: server->client aes128-cbc hmac-md5 none
> Log(jsch,1): kex: client->server aes128-cbc hmac-md5 none
> Log(jsch,1): SSH_MSG_KEXDH_INIT sent
> Log(jsch,1): expecting SSH_MSG_KEXDH_REPLY
> 2011-07-25 11:24:28,390 [NioProcessor-2 ] INFO  DHG1                           - Received SSH_MSG_KEXDH_INIT
> 2011-07-25 11:24:28,468 [NioProcessor-2 ] INFO  DHG1                           - Send SSH_MSG_KEXDH_REPLY
> 2011-07-25 11:24:28,468 [NioProcessor-2 ] INFO  ServerSession                  - Send SSH_MSG_NEWKEYS
> Log(jsch,1): ssh_rsa_verify: signature true
> Log(jsch,2): Permanently added 'localhost' (RSA) to the list of known hosts.
> Log(jsch,1): SSH_MSG_NEWKEYS sent
> Log(jsch,1): SSH_MSG_NEWKEYS received
> 2011-07-25 11:24:28,500 [NioProcessor-2 ] INFO  ServerSession                  - Received SSH_MSG_NEWKEYS
> Log(jsch,1): SSH_MSG_SERVICE_REQUEST sent
> 2011-07-25 11:24:28,578 [NioProcessor-2 ] INFO  ServerSession                  - Received SSH_MSG_SERVICE_REQUEST 'ssh-userauth'
> 2011-07-25 11:24:28,578 [NioProcessor-2 ] INFO  ServerSession                  - Accepting user authentication request
> 2011-07-25 11:24:28,578 [NioProcessor-2 ] INFO  ServerSession                  - Authorized authentication methods: password
> Log(jsch,1): SSH_MSG_SERVICE_ACCEPT received
> 2011-07-25 11:24:28,578 [NioProcessor-2 ] INFO  ServerSession                  - Received SSH_MSG_USERAUTH_REQUEST
> 2011-07-25 11:24:28,687 [NioProcessor-2 ] INFO  ServerSession                  - Authenticating user 'sshd' with method 'none'
> 2011-07-25 11:24:28,687 [NioProcessor-2 ] INFO  ServerSession                  - Unsupported authentication method 'none'
> Log(jsch,1): Authentications that can continue: password
> Log(jsch,1): Next authentication method: password
> 2011-07-25 11:24:28,687 [NioProcessor-2 ] INFO  ServerSession                  - Received SSH_MSG_USERAUTH_REQUEST
> 2011-07-25 11:24:28,687 [NioProcessor-2 ] INFO  ServerSession                  - Authenticating user 'sshd' with method 'password'
> 2011-07-25 11:24:28,687 [NioProcessor-2 ] INFO  ServerSession                  - Authentication succeeded
> Log(jsch,1): Authentication succeeded (password).
> 2011-07-25 11:24:28,718 [NioProcessor-2 ] INFO  ServerSession                  - Received SSH_MSG_CHANNEL_OPEN session
> 2011-07-25 11:24:28,781 [NioProcessor-2 ] INFO  ChannelSession                 - Received SSH_MSG_CHANNEL_REQUEST on channel 0
> 2011-07-25 11:24:28,781 [NioProcessor-2 ] INFO  ChannelSession                 - Received channel request: exec
> 2011-07-25 11:24:28,781 [NioProcessor-2 ] INFO  ChannelSession                 - Executing command: scp -t target/scp/out.txt
> 2011-07-25 11:24:28,906 [NioProcessor-2 ] INFO  ChannelSession                 - Received SSH_MSG_CHANNEL_CLOSE on channel 0
> 2011-07-25 11:24:28,906 [NioProcessor-2 ] INFO  ChannelSession                 - Send SSH_MSG_CHANNEL_CLOSE on channel 0
> 2011-07-25 11:24:28,906 [et/scp/out.txt]] INFO  ScpCommand                     - Error in scp command
> java.io.IOException: Pipe closed
> 	at org.apache.sshd.common.channel.ChannelPipedInputStream.read(ChannelPipedInputStream.java:72)
> 	at org.apache.sshd.common.channel.ChannelPipedInputStream.read(ChannelPipedInputStream.java:58)
> 	at org.apache.sshd.server.command.ScpCommand.readAck(ScpCommand.java:422)
> 	at org.apache.sshd.server.command.ScpCommand.run(ScpCommand.java:147)
> 	at java.lang.Thread.run(Thread.java:662)
> 2011-07-25 11:24:29,015 [et/scp/out.txt]] INFO  ChannelSession                 - Send SSH_MSG_CHANNEL_EOF on channel 0
> 2011-07-25 11:24:29,015 [et/scp/out.txt]] INFO  ChannelSession                 - Send SSH_MSG_CHANNEL_REQUEST exit-status on channel 0
> 2011-07-25 11:24:29,015 [NioProcessor-2 ] INFO  ServerSession                  - Received SSH_MSG_CHANNEL_OPEN session
> 2011-07-25 11:24:29,015 [NioProcessor-2 ] INFO  ChannelSession                 - Received SSH_MSG_CHANNEL_REQUEST on channel 1
> 2011-07-25 11:24:29,015 [NioProcessor-2 ] INFO  ChannelSession                 - Received channel request: exec
> 2011-07-25 11:24:29,109 [NioProcessor-2 ] INFO  ChannelSession                 - Executing command: scp -t target/scp
> 2011-07-25 11:24:29,234 [NioProcessor-2 ] INFO  ChannelSession                 - Received SSH_MSG_CHANNEL_CLOSE on channel 1
> 2011-07-25 11:24:29,234 [NioProcessor-2 ] INFO  ChannelSession                 - Send SSH_MSG_CHANNEL_CLOSE on channel 1
> 2011-07-25 11:24:29,234 [-t, target/scp]] INFO  ScpCommand                     - Error in scp command
> java.io.IOException: Pipe closed
> 	at org.apache.sshd.common.channel.ChannelPipedInputStream.read(ChannelPipedInputStream.java:72)
> 	at org.apache.sshd.common.channel.ChannelPipedInputStream.read(ChannelPipedInputStream.java:58)
> 	at org.apache.sshd.server.command.ScpCommand.readAck(ScpCommand.java:422)
> 	at org.apache.sshd.server.command.ScpCommand.run(ScpCommand.java:147)
> 	at java.lang.Thread.run(Thread.java:662)
> 2011-07-25 11:24:29,328 [-t, target/scp]] INFO  ChannelSession                 - Send SSH_MSG_CHANNEL_EOF on channel 1
> 2011-07-25 11:24:29,328 [-t, target/scp]] INFO  ChannelSession                 - Send SSH_MSG_CHANNEL_REQUEST exit-status on channel 1
> 2011-07-25 11:24:29,343 [NioProcessor-2 ] INFO  ServerSession                  - Received SSH_MSG_CHANNEL_OPEN session
> 2011-07-25 11:24:29,406 [NioProcessor-2 ] INFO  ChannelSession                 - Received SSH_MSG_CHANNEL_REQUEST on channel 2
> 2011-07-25 11:24:29,406 [NioProcessor-2 ] INFO  ChannelSession                 - Received channel request: exec
> 2011-07-25 11:24:29,406 [NioProcessor-2 ] INFO  ChannelSession                 - Executing command: scp -t target
> 2011-07-25 11:24:29,406 [cp, -t, target]] INFO  ScpCommand                     - Error in scp command
> java.io.IOException: File is a directory: org.apache.sshd.server.filesystem.NativeSshFile@82764b
> 	at org.apache.sshd.server.command.ScpCommand.writeFile(ScpCommand.java:314)
> 	at org.apache.sshd.server.command.ScpCommand.run(ScpCommand.java:171)
> 	at java.lang.Thread.run(Thread.java:662)
> 2011-07-25 11:24:29,437 [cp, -t, target]] INFO  ChannelSession                 - Send SSH_MSG_CHANNEL_EOF on channel 2
> 2011-07-25 11:24:29,437 [cp, -t, target]] INFO  ChannelSession                 - Send SSH_MSG_CHANNEL_REQUEST exit-status on channel 2
> 2011-07-25 11:24:29,437 [cp, -t, target]] INFO  ChannelSession                 - Send SSH_MSG_CHANNEL_CLOSE on channel 2
> 2011-07-25 11:24:29,406 [NioProcessor-2 ] INFO  ChannelSession                 - Received SSH_MSG_CHANNEL_CLOSE on channel 2
> 2011-07-25 11:24:29,437 [NioProcessor-2 ] INFO  ServerSession                  - Received SSH_MSG_CHANNEL_OPEN session
> 2011-07-25 11:24:29,468 [NioProcessor-2 ] INFO  ChannelSession                 - Received SSH_MSG_CHANNEL_REQUEST on channel 3
> 2011-07-25 11:24:29,468 [NioProcessor-2 ] INFO  ChannelSession                 - Received channel request: exec
> 2011-07-25 11:24:29,468 [NioProcessor-2 ] INFO  ChannelSession                 - Executing command: scp -f target/scp
> 2011-07-25 11:24:29,468 [-f, target/scp]] INFO  ScpCommand                     - Error in scp command
> java.io.IOException: org.apache.sshd.server.filesystem.NativeSshFile@1e4f7c2 not a regular file
> 	at org.apache.sshd.server.command.ScpCommand.run(ScpCommand.java:216)
> 	at java.lang.Thread.run(Thread.java:662)
> 2011-07-25 11:24:29,546 [-f, target/scp]] INFO  ChannelSession                 - Send SSH_MSG_CHANNEL_EOF on channel 3
> 2011-07-25 11:24:29,546 [-f, target/scp]] INFO  ChannelSession                 - Send SSH_MSG_CHANNEL_REQUEST exit-status on channel 3
> 2011-07-25 11:24:29,546 [-f, target/scp]] INFO  ChannelSession                 - Send SSH_MSG_CHANNEL_CLOSE on channel 3
> 2011-07-25 11:24:29,468 [NioProcessor-2 ] INFO  ChannelSession                 - Received SSH_MSG_CHANNEL_CLOSE on channel 3
> 2011-07-25 11:24:29,546 [NioProcessor-2 ] INFO  ServerSession                  - Received SSH_MSG_CHANNEL_OPEN session
> 2011-07-25 11:24:29,593 [NioProcessor-2 ] INFO  ChannelSession                 - Received SSH_MSG_CHANNEL_REQUEST on channel 4
> 2011-07-25 11:24:29,593 [NioProcessor-2 ] INFO  ChannelSession                 - Received channel request: exec
> 2011-07-25 11:24:29,593 [NioProcessor-2 ] INFO  ChannelSession                 - Executing command: scp -f target/scp/out.txt
> 2011-07-25 11:24:29,593 [NioProcessor-2 ] INFO  ChannelSession                 - Received SSH_MSG_CHANNEL_CLOSE on channel 4
> 2011-07-25 11:24:29,593 [et/scp/out.txt]] INFO  ChannelSession                 - Send SSH_MSG_CHANNEL_EOF on channel 4
> 2011-07-25 11:24:29,656 [et/scp/out.txt]] INFO  ChannelSession                 - Send SSH_MSG_CHANNEL_REQUEST exit-status on channel 4
> 2011-07-25 11:24:29,593 [NioProcessor-2 ] INFO  ChannelSession                 - Send SSH_MSG_CHANNEL_CLOSE on channel 4
> 2011-07-25 11:24:29,656 [NioProcessor-2 ] INFO  ServerSession                  - Received SSH_MSG_CHANNEL_OPEN session
> 2011-07-25 11:24:29,718 [NioProcessor-2 ] INFO  ChannelSession                 - Received SSH_MSG_CHANNEL_REQUEST on channel 5
> 2011-07-25 11:24:29,718 [NioProcessor-2 ] INFO  ChannelSession                 - Received channel request: exec
> 2011-07-25 11:24:29,718 [NioProcessor-2 ] INFO  ChannelSession                 - Executing command: scp -r -f target/scp
> 2011-07-25 11:24:29,781 [NioProcessor-2 ] INFO  ChannelSession                 - Received SSH_MSG_CHANNEL_CLOSE on channel 5
> 2011-07-25 11:24:29,781 [NioProcessor-2 ] INFO  ChannelSession                 - Send SSH_MSG_CHANNEL_CLOSE on channel 5
> 2011-07-25 11:24:29,781 [-f, target/scp]] INFO  ScpCommand                     - Error in scp command
> java.io.IOException: Pipe closed
> 	at org.apache.sshd.common.channel.ChannelPipedInputStream.read(ChannelPipedInputStream.java:72)
> 	at org.apache.sshd.common.channel.ChannelPipedInputStream.read(ChannelPipedInputStream.java:58)
> 	at org.apache.sshd.server.command.ScpCommand.readAck(ScpCommand.java:422)
> 	at org.apache.sshd.server.command.ScpCommand.readDir(ScpCommand.java:413)
> 	at org.apache.sshd.server.command.ScpCommand.run(ScpCommand.java:218)
> 	at java.lang.Thread.run(Thread.java:662)
> 2011-07-25 11:24:29,875 [-f, target/scp]] INFO  ChannelSession                 - Send SSH_MSG_CHANNEL_EOF on channel 5
> 2011-07-25 11:24:29,875 [-f, target/scp]] INFO  ChannelSession                 - Send SSH_MSG_CHANNEL_REQUEST exit-status on channel 5
> 2011-07-25 11:24:29,781 [NioProcessor-2 ] INFO  ServerSession                  - Received SSH_MSG_CHANNEL_OPEN session
> 2011-07-25 11:24:29,906 [NioProcessor-2 ] INFO  ChannelSession                 - Received SSH_MSG_CHANNEL_REQUEST on channel 6
> 2011-07-25 11:24:29,906 [NioProcessor-2 ] INFO  ChannelSession                 - Received channel request: exec
> 2011-07-25 11:24:29,906 [NioProcessor-2 ] INFO  ChannelSession                 - Executing command: scp -t -r target
> Log(jsch,1): Disconnecting from localhost port 2963
> 2011-07-25 11:24:30,031 [NioProcessor-2 ] INFO  ChannelSession                 - Received SSH_MSG_CHANNEL_CLOSE on channel 6
> 2011-07-25 11:24:30,031 [NioProcessor-2 ] INFO  ChannelSession                 - Send SSH_MSG_CHANNEL_CLOSE on channel 6
> 2011-07-25 11:24:30,031 [-t, -r, target]] INFO  ScpCommand                     - Error in scp command
> java.io.IOException: Pipe closed
> 	at org.apache.sshd.common.channel.ChannelPipedInputStream.read(ChannelPipedInputStream.java:72)
> 	at org.apache.sshd.common.channel.ChannelPipedInputStream.read(ChannelPipedInputStream.java:58)
> 	at org.apache.sshd.server.command.ScpCommand.readAck(ScpCommand.java:422)
> 	at org.apache.sshd.server.command.ScpCommand.run(ScpCommand.java:147)
> 	at java.lang.Thread.run(Thread.java:662)
> 2011-07-25 11:24:30,031 [NioProcessor-2 ] INFO  ServerSession                  - Closing session
> 2011-07-25 11:24:30,093 [-t, -r, target]] INFO  ChannelSession                 - Send SSH_MSG_CHANNEL_EOF on channel 6
> 2011-07-25 11:24:30,093 [-t, -r, target]] INFO  ChannelSession                 - Send SSH_MSG_CHANNEL_REQUEST exit-status on channel 6
> 2011-07-25 11:24:30,234 [NioProcessor-6 ] INFO  ServerSession                  - Session created...
> 2011-07-25 11:24:30,234 [NioProcessor-6 ] INFO  ServerSession                  - Client version string: SSH-2.0-Ganymed Build_210
> 2011-07-25 11:24:30,250 [NioProcessor-6 ] INFO  ServerSession                  - Received SSH_MSG_KEXINIT
> 2011-07-25 11:24:30,515 [NioProcessor-6 ] INFO  DHG14                          - Received SSH_MSG_KEXDH_INIT
> 2011-07-25 11:24:30,796 [NioProcessor-6 ] INFO  DHG14                          - Send SSH_MSG_KEXDH_REPLY
> 2011-07-25 11:24:30,796 [NioProcessor-6 ] INFO  ServerSession                  - Send SSH_MSG_NEWKEYS
> 2011-07-25 11:24:31,046 [NioProcessor-6 ] INFO  ServerSession                  - Received SSH_MSG_NEWKEYS
> 2011-07-25 11:24:31,093 [NioProcessor-6 ] INFO  ServerSession                  - Received SSH_MSG_SERVICE_REQUEST 'ssh-userauth'
> 2011-07-25 11:24:31,093 [NioProcessor-6 ] INFO  ServerSession                  - Accepting user authentication request
> 2011-07-25 11:24:31,093 [NioProcessor-6 ] INFO  ServerSession                  - Authorized authentication methods: password
> 2011-07-25 11:24:31,093 [NioProcessor-6 ] INFO  ServerSession                  - Received SSH_MSG_USERAUTH_REQUEST
> 2011-07-25 11:24:31,093 [NioProcessor-6 ] INFO  ServerSession                  - Authenticating user 'sshd' with method 'none'
> 2011-07-25 11:24:31,187 [NioProcessor-6 ] INFO  ServerSession                  - Unsupported authentication method 'none'
> 2011-07-25 11:24:31,187 [NioProcessor-6 ] INFO  ServerSession                  - Received SSH_MSG_USERAUTH_REQUEST
> 2011-07-25 11:24:31,187 [NioProcessor-6 ] INFO  ServerSession                  - Authenticating user 'sshd' with method 'password'
> 2011-07-25 11:24:31,187 [NioProcessor-6 ] INFO  ServerSession                  - Authentication succeeded
> 2011-07-25 11:24:31,203 [NioProcessor-6 ] INFO  ServerSession                  - Received SSH_MSG_CHANNEL_OPEN session
> 2011-07-25 11:24:31,203 [NioProcessor-6 ] INFO  ChannelSession                 - Received SSH_MSG_CHANNEL_REQUEST on channel 0
> 2011-07-25 11:24:31,296 [NioProcessor-6 ] INFO  ChannelSession                 - Received channel request: exec
> 2011-07-25 11:24:31,296 [NioProcessor-6 ] INFO  ChannelSession                 - Executing command: scp -t -d target/scp/gan
> 2011-07-25 11:24:31,296 [NioProcessor-6 ] INFO  ChannelSession                 - Received SSH_MSG_CHANNEL_CLOSE on channel 0
> 2011-07-25 11:24:31,296 [NioProcessor-6 ] INFO  ChannelSession                 - Send SSH_MSG_CHANNEL_CLOSE on channel 0
> 2011-07-25 11:24:31,296 [target/scp/gan]] INFO  ChannelSession                 - Send SSH_MSG_CHANNEL_EOF on channel 0
> 2011-07-25 11:24:31,296 [NioProcessor-6 ] INFO  ServerSession                  - Received SSH_MSG_CHANNEL_OPEN session
> 2011-07-25 11:24:31,296 [target/scp/gan]] INFO  ChannelSession                 - Send SSH_MSG_CHANNEL_REQUEST exit-status on channel 0
> 2011-07-25 11:24:31,296 [NioProcessor-6 ] INFO  ServerSession                  - Closing session
> 2011-07-25 11:24:31,406 [NioProcessor-6 ] INFO  ChannelSession                 - Closing channel 1 immediately
> ------------- ---------------- ---------------
> Testcase: testWithGanymede(org.apache.sshd.ScpTest):	Caused an ERROR
> Error during SCP transfer.
> java.io.IOException: Error during SCP transfer.
> 	at ch.ethz.ssh2.SCPClient.put(SCPClient.java:510)
> 	at ch.ethz.ssh2.SCPClient.put(SCPClient.java:466)
> 	at org.apache.sshd.ScpTest.testWithGanymede(ScpTest.java:171)
> Caused by: java.io.IOException: Could not open channel (The connection is being shutdown)
> 	at ch.ethz.ssh2.channel.ChannelManager.waitUntilChannelOpen(ChannelManager.java:123)
> 	at ch.ethz.ssh2.channel.ChannelManager.openSessionChannel(ChannelManager.java:568)
> 	at ch.ethz.ssh2.Session.<init>(Session.java:39)
> 	at ch.ethz.ssh2.Connection.openSession(Connection.java:965)
> 	at ch.ethz.ssh2.SCPClient.put(SCPClient.java:504)
> Test org.apache.sshd.ScpTest FAILED
> test:
> Deleting: D:\DOCUME~1\DENIS~1.BAR\LOCALS~1\Temp\TEST-org.apache.sshd.ScpTest.xml
> BUILD SUCCESSFUL (total time: 6 seconds)

--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators
For more information on JIRA, see: http://www.atlassian.com/software/jira