Infinite recursion on sftp upward traversal; causes call stack overflow

[mplewis]

Hey @lepture,

Thanks for this package! I really like what you've done with scp2. It has been working very well for my uses except for the one bug I keep seeing repeatedly.

The Issue

Some of my SCP operations copy entire directories via SCP. During a fraction of these operations, I see the following error thrown:

/Users/mplewis/Dropbox (Personal)/projectsync/nodejs/statichook/node_modules/scp2/node_modules/ssh2/lib/SFTP/SFTPv3.js:873
    err = new Error('Underlying stream not writable');
          ^
RangeError: Maximum call stack size exceeded
    at new Error (native)
    at SFTP._send (/Users/mplewis/Dropbox (Personal)/projectsync/nodejs/statichook/node_modules/scp2/node_modules/ssh2/lib/SFTP/SFTPv3.js:873:11)
    at SFTP.stat (/Users/mplewis/Dropbox (Personal)/projectsync/nodejs/statichook/node_modules/scp2/node_modules/ssh2/lib/SFTP/SFTPv3.js:627:15)
    at /Users/mplewis/Dropbox (Personal)/projectsync/nodejs/statichook/node_modules/scp2/lib/client.js:130:12
    at Object.async.until (/Users/mplewis/Dropbox (Personal)/projectsync/nodejs/statichook/node_modules/scp2/node_modules/async/lib/async.js:647:13)
    at /Users/mplewis/Dropbox (Personal)/projectsync/nodejs/statichook/node_modules/scp2/node_modules/async/lib/async.js:651:23
    at /Users/mplewis/Dropbox (Personal)/projectsync/nodejs/statichook/node_modules/scp2/lib/client.js:137:9
    at SFTP._send (/Users/mplewis/Dropbox (Personal)/projectsync/nodejs/statichook/node_modules/scp2/node_modules/ssh2/lib/SFTP/SFTPv3.js:875:7)
    at SFTP.stat (/Users/mplewis/Dropbox (Personal)/projectsync/nodejs/statichook/node_modules/scp2/node_modules/ssh2/lib/SFTP/SFTPv3.js:627:15)
    at /Users/mplewis/Dropbox (Personal)/projectsync/nodejs/statichook/node_modules/scp2/lib/client.js:130:12

I've narrowed it down to scp2/lib/client.js as follows.

Debugging the Error

Below is a visual representation of the stack overflow taken from node-debug:

I inserted some debug lines into the subroutine inside Client.prototype.mkdir as shown:

/* Line */
/* 130 */   sftp.stat(dir, function(err, attr) {
/* 131 */     console.log('ERR:  ', err);
/* 132 */     console.log('DIR:  ', dir);
/* 133 */     console.log('DIRS: ', dirs);
/* 134 */     if (err) {
/* 135 */       dirs.push(dir);

These debug lines produced the following output during program runtime:

ERR:   [Error: Underlying stream not writable]
DIR:   /home/public/ieee-checkin
DIRS:  []
ERR:   [Error: Underlying stream not writable]
DIR:   /home/public
DIRS:  [ '/home/public/ieee-checkin' ]
ERR:   [Error: Underlying stream not writable]
DIR:   /home
DIRS:  [ '/home/public/ieee-checkin', '/home/public' ]
ERR:   [Error: Underlying stream not writable]
DIR:   /
DIRS:  [ '/home/public/ieee-checkin', '/home/public', '/home' ]
ERR:   [Error: Underlying stream not writable]
DIR:   /
DIRS:  [ '/home/public/ieee-checkin', '/home/public', '/home', '/' ]
ERR:   [Error: Underlying stream not writable]
DIR:   /
DIRS:  [ '/home/public/ieee-checkin', '/home/public', '/home', '/', '/' ]
ERR:   [Error: Underlying stream not writable]
DIR:   /
DIRS:  [ '/home/public/ieee-checkin', '/home/public', '/home', '/', '/', '/' ]
ERR:   [Error: Underlying stream not writable]
DIR:   /
DIRS:  [ '/home/public/ieee-checkin', '/home/public', '/home', '/', '/', '/', '/' ]
...continues...

Once the program hit the call stack limit, it crashed.

Diagnosis

It looks like the program is attempting to create a directory, but failing due to the Underlying stream not writable error.

I believe you're trying to handle this error:

ERR:   { [Error: No such file] type: 'NO_SUCH_FILE', lang: '' }

I think your code is seeing the Underlying stream not writable error, catching it as if it were a NO_SUCH_FILE error, and proceeds to assume the directory in which it's trying to mkdir doesn't exist. Because of this, the function continues to iterate up the directory tree and continues to get that error and attempt recursion until the call stack overflows.

Suggestions

• Only catch the NO_SUCH_FILE error. Let all other errors throw. I'm working on a patch for that for my code.
• Alternately, figure out why the Underlying stream not writable error appears. It stems from line 892 in SFTPv3.js in the ssh2 library.

Edit: New discovery!

Possible root cause

Underlying stream not writable appears if I call the same hook twice in a row, connecting to the same server and uploading the same files using the same password/key.

This leads me to believe that Client.prototype.close is not being called properly and possibly that I am reusing the sftp object in an improper way. Does any of this sound right?

Fix based on possible root cause

I've implemented changes to scp.js that mitigate this problem.

The changes involve making the client object in scp.js no longer a singleton pointing to a once-instantiated new Client().

Instead, Client is imported as follows:

var Client = require('./client').Client;

and client is set to an instance of Client:

var client = new Client();

Then, each time scp is called, client is reinstantiated:

exports.scp = function(src, dest, callback) {
  client = new Client();
  /* ... other code ... */
};

This may be wasteful and it may trigger garbage collection more often, but it is a functional workaround that I will use for the time being.

tl;dr: using a new Client for each scp(...) solves this problem on my machine

Other Info

My system versions are as follows:

Node 0.11.9
scp2 0.1.4
OS X 10.9.3

I'm not sure if there's any way for you to reproduce this on your machine or if you've seen this before. I'm happy to help out.

I'm connecting via SCP with password to a NearlyFreeSpeech server. I think this issue may be server-system-specific or server-SCP-version-specific. I don't think that any more—see suggestion #2.

Let me know what you think. Thanks for taking a look!

Matt

[toddtarsi]

+1

[lepture]

Thanks for your feedback. Could you send me a patch?