mscdex / ssh2

SSH2 client and server modules written in pure JavaScript for node.js
MIT License
5.54k stars 669 forks source link

SFTP: open/fastGet filename problem #320

Closed luigi22 closed 8 years ago

luigi22 commented 9 years ago

Hi, I've noticed strange behavior while trying to open/fastGet file with some exact filename length (51 characters) - script hangs and callback function isn't firing.

Example code:

var FTPClient = require('ssh2').Client;

var client = new FTPClient();
client.on('ready', function() {
    client.sftp(function(err, sftp) {
        sftp.open('home/NN_NAME_NAME_NAME_NAME_NAME_NAME_NAME_NAME.TXT', 'r', function() { // 51 characters
            console.log('worked');
            client.end();
        });
    });
});
client.connect({...});

When I try filenames shorter/longer by one character:

callback function is executed correctly.

Details: os: OS X 10.10.5 node: 0.12.7 ssh2: 0.4.11

mscdex commented 9 years ago

Can you enable debug output with debug: console.log in your connection options and post the output here?

luigi22 commented 9 years ago

Of course, here's the output:

DEBUG: Local ident: 'SSH-2.0-ssh2js0.0.15'
DEBUG: Client: Trying 10.10.10.10 on port 22 ...
DEBUG: Client: Connected
DEBUG: Parser: IN_INIT
DEBUG: Parser: IN_GREETING
DEBUG: Parser: IN_HEADER
DEBUG: Remote ident: 'SSH-2.0-OpenSSH_6.6p2-hpn14v4'
DEBUG: Outgoing: Writing KEXINIT
DEBUG: Parser: IN_PACKETBEFORE (expecting 8)
DEBUG: Parser: IN_PACKET
DEBUG: Parser: pktLen:940,padLen:8,remainLen:936
DEBUG: Parser: IN_PACKETDATA
DEBUG: Parser: IN_PACKETDATAAFTER, packet: KEXINIT
DEBUG: Comparing KEXINITs ...
DEBUG: (local) KEX algorithms: diffie-hellman-group-exchange-sha256,diffie-hellman-group-exchange-sha1,diffie-hellman-group14-sha1,diffie-hellman-group1-sha1
DEBUG: (remote) KEX algorithms: curve25519-sha256@libssh.org,ecdh-sha2-nistp256,ecdh-sha2-nistp384,ecdh-sha2-nistp521,diffie-hellman-group-exchange-sha256,diffie-hellman-group14-sha1
DEBUG: KEX algorithm: diffie-hellman-group-exchange-sha256
DEBUG: (local) Host key formats: ssh-rsa,ssh-dss
DEBUG: (remote) Host key formats: ssh-rsa,ssh-dss,ecdsa-sha2-nistp256
DEBUG: Host key format: ssh-rsa
DEBUG: (local) Client->Server ciphers: aes256-ctr,aes192-ctr,aes128-ctr,aes128-gcm,aes128-gcm@openssh.com,aes256-gcm,aes256-gcm@openssh.com,aes256-cbc,aes192-cbc,aes128-cbc,blowfish-cbc,3des-cbc,arcfour256,arcfour128,cast128-cbc,arcfour
DEBUG: (remote) Client->Server ciphers: aes128-ctr,aes192-ctr,aes256-ctr,aes128-gcm@openssh.com,aes256-gcm@openssh.com,chacha20-poly1305@openssh.com
DEBUG: Client->Server Cipher: aes256-ctr
DEBUG: (local) Server->Client ciphers: aes256-ctr,aes192-ctr,aes128-ctr,aes128-gcm,aes128-gcm@openssh.com,aes256-gcm,aes256-gcm@openssh.com,aes256-cbc,aes192-cbc,aes128-cbc,blowfish-cbc,3des-cbc,arcfour256,arcfour128,cast128-cbc,arcfour
DEBUG: (remote) Server->Client ciphers: aes128-ctr,aes192-ctr,aes256-ctr,aes128-gcm@openssh.com,aes256-gcm@openssh.com,chacha20-poly1305@openssh.com
DEBUG: Server->Client Cipher: aes256-ctr
DEBUG: (local) Client->Server HMAC algorithms: hmac-md5,hmac-sha1,hmac-sha2-256,hmac-sha2-256-96,hmac-sha2-512,hmac-sha2-512-96,hmac-ripemd160,hmac-sha1-96,hmac-md5-96
DEBUG: (remote) Client->Server HMAC algorithms: umac-64-etm@openssh.com,umac-128-etm@openssh.com,hmac-sha2-256-etm@openssh.com,hmac-sha2-512-etm@openssh.com,hmac-sha1-etm@openssh.com,umac-64@openssh.com,umac-128@openssh.com,hmac-sha2-256,hmac-sha2-512,hmac-sha1
DEBUG: Client->Server HMAC algorithm: hmac-sha1
DEBUG: (local) Server->Client HMAC algorithms: hmac-md5,hmac-sha1,hmac-sha2-256,hmac-sha2-256-96,hmac-sha2-512,hmac-sha2-512-96,hmac-ripemd160,hmac-sha1-96,hmac-md5-96
DEBUG: (remote) Server->Client HMAC algorithms: umac-64-etm@openssh.com,umac-128-etm@openssh.com,hmac-sha2-256-etm@openssh.com,hmac-sha2-512-etm@openssh.com,hmac-sha1-etm@openssh.com,umac-64@openssh.com,umac-128@openssh.com,hmac-sha2-256,hmac-sha2-512,hmac-sha1
DEBUG: Server->Client HMAC algorithm: hmac-sha1
DEBUG: (local) Client->Server compression algorithms: none
DEBUG: (remote) Client->Server compression algorithms: none,zlib@openssh.com
DEBUG: Client->Server compression algorithm: none
DEBUG: (local) Server->Client compression algorithms: none
DEBUG: (remote) Server->Client compression algorithms: none,zlib@openssh.com
DEBUG: Server->Client compression algorithm: none
DEBUG: Outgoing: Writing KEXDH_GEX_REQUEST
DEBUG: Parser: IN_PACKETBEFORE (expecting 8)
DEBUG: Parser: IN_PACKET
DEBUG: Parser: pktLen:276,padLen:8,remainLen:272
DEBUG: Parser: IN_PACKETDATA
DEBUG: Parser: IN_PACKETDATAAFTER, packet: KEXDH_GEX_GROUP
DEBUG: Outgoing: Writing KEXDH_GEX_INIT
DEBUG: Parser: IN_PACKETBEFORE (expecting 8)
DEBUG: Parser: IN_PACKET
DEBUG: Parser: pktLen:828,padLen:8,remainLen:824
DEBUG: Parser: IN_PACKETDATA
DEBUG: Parser: IN_PACKETDATAAFTER, packet: KEXDH_GEX_REPLY
DEBUG: Checking host key format
DEBUG: Checking signature format
DEBUG: Verifying host fingerprint
DEBUG: Host accepted by default (no verification)
DEBUG: Verifying signature
DEBUG: Outgoing: Writing NEWKEYS
DEBUG: Parser: IN_PACKETBEFORE (expecting 8)
DEBUG: Parser: IN_PACKET
DEBUG: Parser: pktLen:12,padLen:10,remainLen:8
DEBUG: Parser: IN_PACKETDATA
DEBUG: Parser: IN_PACKETDATAAFTER, packet: NEWKEYS
DEBUG: Outgoing: Writing SERVICE_REQUEST (ssh-userauth)
DEBUG: Parser: IN_PACKETBEFORE (expecting 16)
DEBUG: Parser: IN_PACKET
DEBUG: Parser: Decrypting
DEBUG: Parser: pktLen:28,padLen:10,remainLen:16
DEBUG: Parser: IN_PACKETDATA
DEBUG: Parser: Decrypting
DEBUG: Parser: HMAC size:20
DEBUG: Parser: IN_PACKETDATAVERIFY
DEBUG: Parser: Verifying MAC
DEBUG: Parser: IN_PACKETDATAVERIFY (Valid HMAC)
DEBUG: Parser: IN_PACKETDATAAFTER, packet: SERVICE_ACCEPT
DEBUG: Outgoing: Writing USERAUTH_REQUEST (password)
DEBUG: Parser: IN_PACKETBEFORE (expecting 16)
DEBUG: Parser: IN_PACKET
DEBUG: Parser: Decrypting
DEBUG: Parser: pktLen:12,padLen:10,remainLen:0
DEBUG: Parser: IN_PACKETDATA
DEBUG: Parser: HMAC size:20
DEBUG: Parser: IN_PACKETDATAVERIFY
DEBUG: Parser: Verifying MAC
DEBUG: Parser: IN_PACKETDATAVERIFY (Valid HMAC)
DEBUG: Parser: IN_PACKETDATAAFTER, packet: USERAUTH_SUCCESS
DEBUG: Outgoing: Writing CHANNEL_OPEN (0, session)
DEBUG: Parser: IN_PACKETBEFORE (expecting 16)
DEBUG: Parser: IN_PACKET
DEBUG: Parser: Decrypting
DEBUG: Parser: pktLen:940,padLen:8,remainLen:928
DEBUG: Parser: IN_PACKETDATA
DEBUG: Parser: Decrypting
DEBUG: Parser: HMAC size:20
DEBUG: Parser: IN_PACKETDATAVERIFY
DEBUG: Parser: Verifying MAC
DEBUG: Parser: IN_PACKETDATAVERIFY (Valid HMAC)
DEBUG: Parser: IN_PACKETDATAAFTER, packet: KEXINIT
DEBUG: Received re-key request
DEBUG: Outgoing: Writing KEXINIT
DEBUG: Comparing KEXINITs ...
DEBUG: (local) KEX algorithms: diffie-hellman-group-exchange-sha256,diffie-hellman-group-exchange-sha1,diffie-hellman-group14-sha1,diffie-hellman-group1-sha1
DEBUG: (remote) KEX algorithms: curve25519-sha256@libssh.org,ecdh-sha2-nistp256,ecdh-sha2-nistp384,ecdh-sha2-nistp521,diffie-hellman-group-exchange-sha256,diffie-hellman-group14-sha1
DEBUG: KEX algorithm: diffie-hellman-group-exchange-sha256
DEBUG: (local) Host key formats: ssh-rsa,ssh-dss
DEBUG: (remote) Host key formats: ssh-rsa,ssh-dss,ecdsa-sha2-nistp256
DEBUG: Host key format: ssh-rsa
DEBUG: (local) Client->Server ciphers: aes256-ctr,aes192-ctr,aes128-ctr,aes128-gcm,aes128-gcm@openssh.com,aes256-gcm,aes256-gcm@openssh.com,aes256-cbc,aes192-cbc,aes128-cbc,blowfish-cbc,3des-cbc,arcfour256,arcfour128,cast128-cbc,arcfour
DEBUG: (remote) Client->Server ciphers: aes128-ctr,aes192-ctr,aes256-ctr,aes128-gcm@openssh.com,aes256-gcm@openssh.com,chacha20-poly1305@openssh.com
DEBUG: Client->Server Cipher: aes256-ctr
DEBUG: (local) Server->Client ciphers: aes256-ctr,aes192-ctr,aes128-ctr,aes128-gcm,aes128-gcm@openssh.com,aes256-gcm,aes256-gcm@openssh.com,aes256-cbc,aes192-cbc,aes128-cbc,blowfish-cbc,3des-cbc,arcfour256,arcfour128,cast128-cbc,arcfour
DEBUG: (remote) Server->Client ciphers: aes128-ctr,aes192-ctr,aes256-ctr,aes128-gcm@openssh.com,aes256-gcm@openssh.com,chacha20-poly1305@openssh.com
DEBUG: Server->Client Cipher: aes256-ctr
DEBUG: (local) Client->Server HMAC algorithms: hmac-md5,hmac-sha1,hmac-sha2-256,hmac-sha2-256-96,hmac-sha2-512,hmac-sha2-512-96,hmac-ripemd160,hmac-sha1-96,hmac-md5-96
DEBUG: (remote) Client->Server HMAC algorithms: umac-64-etm@openssh.com,umac-128-etm@openssh.com,hmac-sha2-256-etm@openssh.com,hmac-sha2-512-etm@openssh.com,hmac-sha1-etm@openssh.com,umac-64@openssh.com,umac-128@openssh.com,hmac-sha2-256,hmac-sha2-512,hmac-sha1
DEBUG: Client->Server HMAC algorithm: hmac-sha1
DEBUG: (local) Server->Client HMAC algorithms: hmac-md5,hmac-sha1,hmac-sha2-256,hmac-sha2-256-96,hmac-sha2-512,hmac-sha2-512-96,hmac-ripemd160,hmac-sha1-96,hmac-md5-96
DEBUG: (remote) Server->Client HMAC algorithms: umac-64-etm@openssh.com,umac-128-etm@openssh.com,hmac-sha2-256-etm@openssh.com,hmac-sha2-512-etm@openssh.com,hmac-sha1-etm@openssh.com,umac-64@openssh.com,umac-128@openssh.com,hmac-sha2-256,hmac-sha2-512,hmac-sha1
DEBUG: Server->Client HMAC algorithm: hmac-sha1
DEBUG: (local) Client->Server compression algorithms: none
DEBUG: (remote) Client->Server compression algorithms: none,zlib@openssh.com
DEBUG: Client->Server compression algorithm: none
DEBUG: (local) Server->Client compression algorithms: none
DEBUG: (remote) Server->Client compression algorithms: none,zlib@openssh.com
DEBUG: Server->Client compression algorithm: none
DEBUG: Outgoing: Writing KEXDH_GEX_REQUEST
DEBUG: Parser: IN_PACKETBEFORE (expecting 16)
DEBUG: Parser: IN_PACKET
DEBUG: Parser: Decrypting
DEBUG: Parser: pktLen:284,padLen:16,remainLen:272
DEBUG: Parser: IN_PACKETDATA
DEBUG: Parser: Decrypting
DEBUG: Parser: HMAC size:20
DEBUG: Parser: IN_PACKETDATAVERIFY
DEBUG: Parser: Verifying MAC
DEBUG: Parser: IN_PACKETDATAVERIFY (Valid HMAC)
DEBUG: Parser: IN_PACKETDATAAFTER, packet: KEXDH_GEX_GROUP
DEBUG: Outgoing: Writing KEXDH_GEX_INIT
DEBUG: Parser: IN_PACKETBEFORE (expecting 16)
DEBUG: Parser: IN_PACKET
DEBUG: Parser: Decrypting
DEBUG: Parser: pktLen:828,padLen:8,remainLen:816
DEBUG: Parser: IN_PACKETDATA
DEBUG: Parser: Decrypting
DEBUG: Parser: HMAC size:20
DEBUG: Parser: IN_PACKETDATAVERIFY
DEBUG: Parser: Verifying MAC
DEBUG: Parser: IN_PACKETDATAVERIFY (Valid HMAC)
DEBUG: Parser: IN_PACKETDATAAFTER, packet: KEXDH_GEX_REPLY
DEBUG: Checking host key format
DEBUG: Checking signature format
DEBUG: Verifying signature
DEBUG: Outgoing: Writing NEWKEYS
DEBUG: Parser: IN_PACKETBEFORE (expecting 16)
DEBUG: Parser: IN_PACKET
DEBUG: Parser: Decrypting
DEBUG: Parser: pktLen:12,padLen:10,remainLen:0
DEBUG: Parser: IN_PACKETDATA
DEBUG: Parser: HMAC size:20
DEBUG: Parser: IN_PACKETDATAVERIFY
DEBUG: Parser: Verifying MAC
DEBUG: Parser: IN_PACKETDATAVERIFY (Valid HMAC)
DEBUG: Parser: IN_PACKETDATAAFTER, packet: NEWKEYS
DEBUG: Parser: IN_PACKETBEFORE (expecting 16)
DEBUG: Parser: IN_PACKET
DEBUG: Parser: Decrypting
DEBUG: Parser: pktLen:28,padLen:10,remainLen:16
DEBUG: Parser: IN_PACKETDATA
DEBUG: Parser: Decrypting
DEBUG: Parser: HMAC size:20
DEBUG: Parser: IN_PACKETDATAVERIFY
DEBUG: Parser: Verifying MAC
DEBUG: Parser: IN_PACKETDATAVERIFY (Valid HMAC)
DEBUG: Parser: IN_PACKETDATAAFTER, packet: CHANNEL_OPEN_CONFIRMATION
DEBUG: Outgoing: Writing CHANNEL_REQUEST (0, subsystem: sftp)
DEBUG: Parser: IN_PACKETBEFORE (expecting 16)
DEBUG: Parser: IN_PACKET
DEBUG: Parser: Decrypting
DEBUG: Parser: pktLen:28,padLen:18,remainLen:16
DEBUG: Parser: IN_PACKETDATA
DEBUG: Parser: Decrypting
DEBUG: Parser: HMAC size:20
DEBUG: Parser: IN_PACKETDATAVERIFY
DEBUG: Parser: Verifying MAC
DEBUG: Parser: IN_PACKETDATAVERIFY (Valid HMAC)
DEBUG: Parser: IN_PACKETDATAAFTER, packet: CHANNEL_WINDOW_ADJUST (0, 87380)
DEBUG: Parser: IN_PACKETBEFORE (expecting 16)
DEBUG: Parser: IN_PACKET
DEBUG: Parser: Decrypting
DEBUG: Parser: pktLen:12,padLen:6,remainLen:0
DEBUG: Parser: IN_PACKETDATA
DEBUG: Parser: HMAC size:20
DEBUG: Parser: IN_PACKETDATAVERIFY
DEBUG: Parser: Verifying MAC
DEBUG: Parser: IN_PACKETDATAVERIFY (Valid HMAC)
DEBUG: Parser: IN_PACKETDATAAFTER, packet: CHANNEL_SUCCESS (0)
DEBUG: Parser: IN_PACKETBEFORE (expecting 16)
DEBUG: Outgoing: Writing CHANNEL_DATA (0)
DEBUG: Parser: IN_PACKET
DEBUG: Parser: Decrypting
DEBUG: Parser: pktLen:172,padLen:8,remainLen:160
DEBUG: Parser: IN_PACKETDATA
DEBUG: Parser: Decrypting
DEBUG: Parser: HMAC size:20
DEBUG: Parser: IN_PACKETDATAVERIFY
DEBUG: Parser: Verifying MAC
DEBUG: Parser: IN_PACKETDATAVERIFY (Valid HMAC)
DEBUG: Parser: IN_PACKETDATAAFTER, packet: CHANNEL_DATA (0)
DEBUG[SFTP]: Outgoing: Writing OPEN
DEBUG: Outgoing: Writing CHANNEL_DATA (0)
DEBUG: Parser: IN_PACKETBEFORE (expecting 16)
DEBUG: Parser: IN_PACKET
DEBUG: Parser: Decrypting
DEBUG: Parser: pktLen:44,padLen:5,remainLen:32
DEBUG: Parser: IN_PACKETDATA
DEBUG: Parser: Decrypting
DEBUG: Parser: HMAC size:20
DEBUG: Parser: IN_PACKETDATAVERIFY
DEBUG: Parser: Verifying MAC
DEBUG: Parser: IN_PACKETDATAVERIFY (Valid HMAC)
DEBUG: Parser: IN_PACKETDATAAFTER, packet: CHANNEL_REQUEST (0, exit-signal)
DEBUG: Outgoing: Writing CHANNEL_CLOSE (0)
DEBUG: Parser: IN_PACKETBEFORE (expecting 16)
DEBUG: Parser: IN_PACKET
DEBUG: Parser: Decrypting
DEBUG: Parser: pktLen:12,padLen:6,remainLen:0
DEBUG: Parser: IN_PACKETDATA
DEBUG: Parser: HMAC size:20
DEBUG: Parser: IN_PACKETDATAVERIFY
DEBUG: Parser: Verifying MAC
DEBUG: Parser: IN_PACKETDATAVERIFY (Valid HMAC)
DEBUG: Parser: IN_PACKETDATAAFTER, packet: CHANNEL_EOF (0)
DEBUG: Parser: IN_PACKETBEFORE (expecting 16)
DEBUG: Parser: IN_PACKET
DEBUG: Parser: Decrypting
DEBUG: Parser: pktLen:12,padLen:6,remainLen:0
DEBUG: Parser: IN_PACKETDATA
DEBUG: Parser: HMAC size:20
DEBUG: Parser: IN_PACKETDATAVERIFY
DEBUG: Parser: Verifying MAC
DEBUG: Parser: IN_PACKETDATAVERIFY (Valid HMAC)
DEBUG: Parser: IN_PACKETBEFORE (expecting 16)
mscdex commented 9 years ago

Ok, so for some reason the server is closing the SFTP connection right after the open request is sent. I'll have to see if I can duplicate this. The hpn OpenSSH patches have been known to do "strange" things, so I wouldn't be surprised if it had something to do with that.

In the meantime, if you re-npm install ssh2, it should pick up the new ssh2-streams version that should at least take care of any outstanding callbacks.

mscdex commented 8 years ago

I tried duplicating this but am not able to reproduce it, even with the versions of ssh2 and ssh2-streams available at that time and OpenSSH 6.6p1 with hpn14v5 patches applied (hpn14v4 did not apply cleanly to 6.6p1).

Have you tried again with the latest versions of ssh2 and ssh2-streams?

mscdex commented 8 years ago

Closing this for now, if you are able to come up with a setup that I can duplicate on my end, let me know. Or if you can provide detailed debugging output from the ssh server, that may help as well.