I think, that the server should respond with SshMsgChannelSuccess after successfully starting sftp subsystem. OpenSsh sshd responds with SshMsgChannelFailure even though my client can later talk with the server. The bug shows up on WindosXp/Cygwin and on Linux. I am not sure if this bug should be assigned to 'sshd' or 'sftp-server'. Steps to reproduce the bug: 1. open connection to a sshd server 2. exchange keys and authenticate user 3. open a ssh channel 4. send SSH_MSG_CHANNEL_REQUEST for sftp subsystem 5. observe how the server responds with - SSH_MSG_CHANNEL_WINDOWS_ADJUST - -----> SSH_MSG_CHANNEL_FAILURE <-------- (a bug?) 6. continue talking with the sftp server as if nothing happened (I can do everything I would expect to: ls, get, put, etc.) Verbose log from my client (showing sent and received ssh messages) follows. ---------sendSshMsg/sent message follows: Kexinit {cookie = [233,175,242,83,223,235,73,20,255,141,1,87,103,225,194,124], k exAlgs = ["diffie-hellman-group1-sha1"], serverHostKeyAlgs = ["ssh-dss"], encryp tionAlgsClnt2Srvr = ["3des-cbc"], encryptionAlgsSrvr2Clnt = ["3des-cbc"], macAlg sClnt2Srvr = ["hmac-sha1"], macAlgsSrvr2Clnt = ["hmac-sha1"], compressionAlgsCln t2Srvr = ["none"], compressionAlgsSrvr2Clnt = ["none"], languagesClnt2Srvr = [], languagesSrvr2Clnt = [], firstKexPacketFollows = False, reserved = 0} ---------sendSshMsg/sent message ends. ---------readingThread/rcvd message follows: Kexinit {cookie = [50,238,207,15,169,90,234,102,37,223,136,65,198,251,101,37], k exAlgs = ["diffie-hellman-group-exchange-sha1","diffie-hellman-group1-sha1"], se rverHostKeyAlgs = ["ssh-rsa","ssh-dss"], encryptionAlgsClnt2Srvr = ["aes128-cbc" ,"3des-cbc","blowfish-cbc","cast128-cbc","arcfour","aes192-cbc","aes256-cbc","ri jndael-cbc@lysator.liu.se","aes128-ctr","aes192-ctr","aes256-ctr"], encryptionAl gsSrvr2Clnt = ["aes128-cbc","3des-cbc","blowfish-cbc","cast128-cbc","arcfour","aes192-cbc","aes256-cbc","rijndael-cbc@lysator.liu.se","aes128-ctr","aes192-ctr","aes256-ctr"], macAlgsClnt2Srvr = ["hmac-md5","hmac-sha1","hmac-ripemd160","hmac-ripemd160@openssh.com","hmac-sha1-96","hmac-md5-96"], macAlgsSrvr2Clnt = ["hmac-md5","hmac-sha1","hmac-ripemd160","hmac-ripemd160@openssh.com","hmac-sha1-96","hmac-md5-96"], compressionAlgsClnt2Srvr = ["none","zlib"], compressionAlgsSrvr2Clnt = ["none","zlib"], languagesClnt2Srvr = [], languagesSrvr2Clnt = [], firstKexPacketFollows = False, reserved = 0} ---------readingThread/rcvd message ends. ---------sendSshMsg/sent message follows: Kexdh_init {eInteger = 18633255786787081608156836570309995274512701348955067998513396793082007292289160726682844268171120018964946091492033960675625166491968204969903216602165453153724816384536430513735406968284630674980652430195416331046850595734481479051734705432043779259464936222585571846317512885512796504946348076764496827837} ---------sendSshMsg/sent message ends. ---------readingThread/rcvd message follows: Kexdh_reply {srvrPublicHostKeyAndCertificates = [0,0,0,7,115,115,104,45,100,115,115,0,0,0,129,0,166,197,156,245,233,143,182,171,129,160,11,149,153,226,20,20,45,203,181,33,210,238,83,146,189,172,38,142,5,149,33,1,82,73,169,110,169,200,103,249,210,68,111,125,8,139,146,133,160,209,52,208,195,160,205,65,175,78,4,199,10,58,233,41,64,46,100,25,188,95,136,196,250,137,159,3,66,82,250,233,82,188,21,63,71,149,12,151,80,235,18,56,78,163,52,218,238,64,97,226,92,11,232,211,93,85,165,222,132,59,85,112,131,254,154,138,56,214,93,68,54,144,41,146,222,62,169,85,0,0,0,21,0,219,121,198,165,225,157,226,123,110,214,236,203,102,93,150,160,177,107,115,23,0,0,0,128,46,206,46,106,72,170,114,83,206,156,8,200,34,51,197,221,250,226,207,200,107,58,249,171,83,68,19,52,64,183,113,156,99,78,190,239,222,98,118,228,129,229,41,178,5,211,237,233,200,117,40,184,158,73,128,28,215,161,175,188,158,105,198,231,228,38,101,206,214,61,215,212,167,107,35,72,195,56,117,226,30,49,215,242,253,207,165,32,138,187,13,247,188,204,115,38,133,136,151,221,219,101,12,193,146,127,209,130,125,154,180,84,2,142,10,81,162,36,216,22,99,82,165,38,108,203,23,99,0,0,0,129,0,158,127,244,88,51,92,120,15,22,150,107,187,83,199,40,97,114,166,140,204,159,83,200,120,82,121,64,175,97,53,97,87,178,133,46,232,155,23,167,220,233,76,175,199,123,69,167,24,165,63,212,110,55,175,23,115,20,2,132,35,44,120,152,52,21,216,58,77,69,207,170,210,159,64,79,217,182,9,75,168,227,230,163,10,210,228,113,21,91,86,112,158,238,46,194,82,28,10,10,192,216,27,113,233,111,228,219,215,48,7,51,197,216,175,136,89,100,35,164,175,56,79,70,238,137,221,77,24], fInteger = 17045365973072878852930627388920946932870494510128823028158775245163523341982978135426690438187125675753742647757222332381007234885115523309372458013542884564113495349166671833985131624728346582145833511579268448523614768062070103498327188796294300623975527317948841366028896223362692963268540349404383209626, signatureOfH = [ 0,0,0,7,115,115,104,45,100,115,115,0,0,0,40,179,177,71,143,103,192,249,85,156,37,143,0,69,142,203,102,99,186,128,167,18,188,224,93,232,224,51,8,86,70,75,141,153,211,39,217,67,213,240,145]} ---------readingThread/rcvd message ends. ---------sendSshMsg/sent message follows: Newkeys ---------sendSshMsg/sent message ends. ---------readingThread/rcvd message follows: Newkeys ---------readingThread/rcvd message ends. ---------sendSshMsg/sent message follows: Service_request {serviceName = "ssh-userauth"} ---------sendSshMsg/sent message ends. ---------readingThread/rcvd message follows: Service_accept {serviceName = "ssh-userauth"} ---------readingThread/rcvd message ends. login: lukasz password: ---------sendSshMsg/sent message follows: Userauth_request {userName = "lukasz", serviceName = "ssh-connection", methodName = "password", authData = [confidential :-)]} ---------sendSshMsg/sent message ends. ---------readingThread/rcvd message follows: Userauth_success ---------readingThread/rcvd message ends. Logged in successfully. ---------sendSshMsg/sent message follows: Channel_open {channelType = "session", senderChannel = 12345, initialWindowSize = 2147483648, maximumPacketSize = 2147483648} ---------sendSshMsg/sent message ends. ---------readingThread/rcvd message follows: Channel_open_cnfrmtn {recipientChannel = 12345, senderChannel = 0, initialWindowSize = 0, maximumPacketSize = 32768, channelData = []} ---------readingThread/rcvd message ends. ---------sendSshMsg/sent message follows: Channel_request {recipientChannel = 0, requestType = "subsystem", wantReply = True, dataBody = [0,0,0,4,115,102,116,112]} ---------sendSshMsg/sent message ends. ---------readingThread/rcvd message follows: Channel_window_adjust {recipientChannel = 12345, bytesToAdd = 131072} ---------readingThread/rcvd message ends. ---------readingThread/rcvd message follows: Channel_failure {recipientChannel = 12345} ^^^^^THIS IS THE MESSAGE I DIDN'T EXPECT TO RECEIVE ---------readingThread/rcvd message ends. ---------sendSshMsg/sent message follows: Channel_data {recipientChannel = 0, dataBody = [0,0,0,5,1,0,0,0,5]} ---------sendSshMsg/sent message ends. ---------readingThread/rcvd message follows: Channel_data {recipientChannel = 12345, dataBody = [0,0,0,5,2,0,0,0,3]} ---------readingThread/rcvd message ends.
We don't see this when using OpenSSH as the client. Have a look at ssh.c - we ask for the subsystem with want_reply == 1 to ensure we get it and obviously we don't error out. What does the server say?
1. I can work with OpenSsh-sftp-server (using OpenSsh-sftp-client, or my-own-sftp-client). The problem I am trying to report is that the sshd-server incorrectly sends SSH_MSG_CHANNEL_FAILURE I think it should respond with SSH_MSG_CHANNEL_SUCCESS (this is how I understand section 5.4 of [SSH-CONNECTION] draft) 2. As you can see from the log I sent, I also have want_reply = 1 3. I don't understand your question: "what does the server say" (have a look at the log I sent to you in the bug report)
I think what djm was asking for is the debug output from sshd -ddd for this session (as an attachment not inline text, please).
I can't tell much without a debug log from the sshd server (e.g. "sshd -ddd"). This is probably a problem with your client, given that we have never seen this problem with OpenSSH's sftp nor any of the other clients (ssh.com, psftp or WinSCP3)
Created attachment 598 [details] log from sshd while launching a sftp subsystem I am sending the sshd log as requested. I'll send log from my client from that session in the next attachment. Server was run with: sshd -ddd -p 12345 >x 2>&1 Unfortunately debugging with 3 d-s doesn't give information if the server tried to send CHANNEL_SUCCESS or CHANNEL_FAILURE.
You were right - it was a problem with my client. Before submitting the bug I double checked message numbers in my client, but didn't look at message creation procedures - failure and success were swapped.
works fine.