Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Put files truncating at 100kb when not reading from file #531

Closed
tristansokol opened this issue Apr 18, 2024 · 6 comments
Closed

Put files truncating at 100kb when not reading from file #531

tristansokol opened this issue Apr 18, 2024 · 6 comments

Comments

@tristansokol
Copy link

tristansokol commented Apr 18, 2024

Hi! I'm encountering a weird bug and am hoping for some direction on where to go.

  • Node version you are using: 20.3.1
  • Version of ssh2-sftp-client you are using: "ssh2-sftp-client": "^10.0.3"
  • Platform your client is running on (Linux, macOS, Windows): Linux & WSL
  • Platform and software for the remote SFTP server when possible: its a windows machine, but My contact doesn't really know, said something about openSSH

Basically I have files that are being truncated after the first 102,000 bytes. Smaller files work fine, but larger ones report success but are clearly truncated. "manually" connecting with $ sftp from the same machine works fine which from what I understand eliminates the issues of #342

The code is very simple:

  const sftp = new SFTPClient();
  await sftp.connect({
    host: ...,
    port: '22',
    username: ...,
    password: ...
  });
  console.log(data.length) // just over a million bytes
  console.log(await sftp.put(Buffer.from(data), `/D:/Shares/${name}.pdf`));
  await sftp.end();

and the logs:

CLIENT[sftp]: connect: Debugging turned on
CLIENT[sftp]: ssh2-sftp-client Version: 10.0.3  {
 "node": "20.3.1",
 "acorn": "8.8.2",
 "ada": "2.5.0",
 "ares": "1.19.1",
 "base64": "0.5.0",
 "brotli": "1.0.9",
 "cjs_module_lexer": "1.2.2",
 "cldr": "43.0",
 "icu": "73.1",
 "llhttp": "8.1.1",
 "modules": "115",
 "napi": "9",
 "nghttp2": "1.53.0",
 "nghttp3": "0.7.0",
 "ngtcp2": "0.8.1",
 "openssl": "3.0.9+quic",
 "simdutf": "3.2.12",
 "tz": "2023c",
 "undici": "5.22.1",
 "unicode": "15.0",
 "uv": "1.45.0",
 "uvwasi": "0.0.18",
 "v8": "11.3.244.8-node.9",
 "zlib": "1.2.13.1-motley"
}
CLIENT[sftp]: connect: Connect attempt 1
Custom crypto binding not available
Local ident: 'SSH-2.0-ssh2js1.15.0'
Client: Trying sftp.... on port 22 ...
Socket connected
Remote ident: 'SSH-2.0-OpenSSH_for_Windows_8.1'
Outbound: Sending KEXINIT
Inbound: Handshake in progress
Handshake: (local) KEX method: curve25519-sha256@libssh.org,curve25519-sha256,ecdh-sha2-nistp256,ecdh-sha2-nistp384,ecdh-sha2-nistp521,diffie-hellman-group-exchange-sha256,diffie-hellman-group14-sha256,diffie-hellman-group15-sha512,diffie-hellman-group16-sha512,diffie-hellman-group17-sha512,diffie-hellman-group18-sha512,ext-info-c,kex-strict-c-v00@openssh.com
Handshake: (remote) KEX method: curve25519-sha256,curve25519-sha256@libssh.org,ecdh-sha2-nistp256,ecdh-sha2-nistp384,ecdh-sha2-nistp521,diffie-hellman-group-exchange-sha256,diffie-hellman-group16-sha512,diffie-hellman-group18-sha512,diffie-hellman-group14-sha256,diffie-hellman-group14-sha1
Handshake: KEX algorithm: curve25519-sha256@libssh.org
Handshake: (local) Host key format: ssh-ed25519,ecdsa-sha2-nistp256,ecdsa-sha2-nistp384,ecdsa-sha2-nistp521,rsa-sha2-512,rsa-sha2-256,ssh-rsa
Handshake: (remote) Host key format: rsa-sha2-512,rsa-sha2-256,ssh-rsa,ecdsa-sha2-nistp256,ssh-ed25519
Handshake: Host key format: ssh-ed25519
Handshake: (local) C->S cipher: aes128-gcm@openssh.com,aes256-gcm@openssh.com,aes128-ctr,aes192-ctr,aes256-ctr,chacha20-poly1305@openssh.com
Handshake: (remote) C->S cipher: chacha20-poly1305@openssh.com,aes128-ctr,aes192-ctr,aes256-ctr,aes128-gcm@openssh.com,aes256-gcm@openssh.com
Handshake: C->S Cipher: aes128-gcm@openssh.com
Handshake: (local) S->C cipher: aes128-gcm@openssh.com,aes256-gcm@openssh.com,aes128-ctr,aes192-ctr,aes256-ctr,chacha20-poly1305@openssh.com
Handshake: (remote) S->C cipher: chacha20-poly1305@openssh.com,aes128-ctr,aes192-ctr,aes256-ctr,aes128-gcm@openssh.com,aes256-gcm@openssh.com
Handshake: S->C cipher: aes128-gcm@openssh.com
Handshake: (local) C->S MAC: hmac-sha2-256-etm@openssh.com,hmac-sha2-512-etm@openssh.com,hmac-sha1-etm@openssh.com,hmac-sha2-256,hmac-sha2-512,hmac-sha1
Handshake: (remote) C->S MAC: 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
Handshake: C->S MAC: <implicit>
Handshake: (local) S->C MAC: hmac-sha2-256-etm@openssh.com,hmac-sha2-512-etm@openssh.com,hmac-sha1-etm@openssh.com,hmac-sha2-256,hmac-sha2-512,hmac-sha1
Handshake: (remote) S->C MAC: 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
Handshake: S->C MAC: <implicit>
Handshake: (local) C->S compression: none,zlib@openssh.com,zlib
Handshake: (remote) C->S compression: none,zlib@openssh.com
Handshake: C->S compression: none
Handshake: (local) S->C compression: none,zlib@openssh.com,zlib
Handshake: (remote) S->C compression: none,zlib@openssh.com
Handshake: S->C compression: none
Outbound: Sending KEXECDH_INIT
Received DH Reply
Host accepted by default (no verification)
Host accepted (verified)
Outbound: Sending NEWKEYS
Inbound: NEWKEYS
Verifying signature ...
Verified signature
Handshake completed
Outbound: Sending SERVICE_REQUEST (ssh-userauth)
Inbound: Received EXT_INFO
Inbound: Received SERVICE_ACCEPT (ssh-userauth)
Outbound: Sending USERAUTH_REQUEST (none)
Inbound: Received USERAUTH_FAILURE (publickey,password,keyboard-interactive)
Client: none auth failed
Outbound: Sending USERAUTH_REQUEST (password)
Inbound: Received USERAUTH_SUCCESS
CLIENT[sftp]: getConnection ready listener: got connection - promise resolved
Outbound: Sending CHANNEL_OPEN (r:0, session)
Inbound: GLOBAL_REQUEST (hostkeys-00@openssh.com)
Inbound: CHANNEL_OPEN_CONFIRMATION (r:0, s:0)
Outbound: Sending CHANNEL_REQUEST (r:0, subsystem: sftp)
Inbound: CHANNEL_WINDOW_ADJUST (r:0, 2097152)
Inbound: CHANNEL_SUCCESS (r:0)
Outbound: Sending CHANNEL_DATA (r:0, 9)
Inbound: CHANNEL_DATA (r:0, 183)
SFTP: Inbound: Received VERSION (v3, exts:posix-rename@openssh.com,statvfs@openssh.com,fstatvfs@openssh.com,hardlink@openssh.com,fsync@openssh.com,lsetstat@openssh.com)
Outbound: Sending CHANNEL_DATA (r:0, 86)
SFTP: Outbound: Buffered OPEN
CLIENT[sftp]: put source is a buffer
Inbound: CHANNEL_DATA (r:0, 17)
SFTP: Inbound: Received HANDLE (id:0)
Outbound: Sending CHANNEL_DATA (r:0, 25)
SFTP: Outbound: Buffered FSETSTAT
Inbound: CHANNEL_DATA (r:0, 28)
SFTP: Inbound: Received STATUS (id:1, 0, "Success")
Outbound: Sending CHANNEL_DATA (r:0, 32768)
Outbound: Sending CHANNEL_DATA (r:0, 32768)
Outbound: Sending CHANNEL_DATA (r:0, 32768)
Outbound: Sending CHANNEL_DATA (r:0, 32768)
Outbound: Sending CHANNEL_DATA (r:0, 32768)
Outbound: Sending CHANNEL_DATA (r:0, 32768)
Outbound: Sending CHANNEL_DATA (r:0, 32768)
Outbound: Sending CHANNEL_DATA (r:0, 30749)
SFTP: Outbound: Sent WRITE (id:2)
Inbound: CHANNEL_WINDOW_ADJUST (r:0, 98424)
Inbound: CHANNEL_WINDOW_ADJUST (r:0, 131072)
Inbound: CHANNEL_DATA (r:0, 28)
SFTP: Inbound: Received STATUS (id:2, 4, "Failure")
Outbound: Sending CHANNEL_DATA (r:0, 17)
SFTP: Outbound: Buffered CLOSE
Inbound: CHANNEL_DATA (r:0, 28)
SFTP: Inbound: Received STATUS (id:3, 0, "Success")
Uploaded data stream to /D:/test.pdf
Outbound: Sending DISCONNECT (11)
Socket error: read ECONNRESET
CLIENT[sftp]: end errorListener - ignoring handled error
CLIENT[sftp]: Global error event: Ignoring expected and handled event
Socket closed
CLIENT[sftp]: end: Connection closed
CLIENT[sftp]: end closeListener - handled close event
CLIENT[sftp]: Global close event: Ignoring expected and handled event

I the log message Uploaded data stream to /D:/Shares/0097643.pdf which seems like everything is correct. what does the SFTP: Inbound: Received STATUS (id:2, 4, "Failure") mean? I initially suspected there being some kind of FPT quota or something, but again, I am able to transfer larger files just fine from the same machine with other SFTP tools.

Any advice as to where to dig in more? Could this be a bug?

@tristansokol
Copy link
Author

Additionally, wrapping my filename in a createReadStream seems to work just fine, so I am kind of leaning towards there being a bug, or at least I'm using the filename or buffer methods incorrectly.

@tristansokol
Copy link
Author

Alright instead of more comments I'll just update this one with my findings

  const sftp = new SFTPClient();
  await sftp.connect({
    host:
    port: '22',
    username: 
    password: 
  });
`console.log(pdf.length, pdf.byteLength, Buffer.isBuffer(pdf)); //1882193 1882193 true`

  await sftp.put(pdf, `${name}.pdf`);
  console.log(await sftp.stat(`${name}.pdf`));
  await sftp.end();
Technique Result
.put(pdf,.. size: 102400,
writeFileSync('./test.pdf', pdf); await put('./test.pdf',..); size: 1882193,
put(createReadStream('./test.pdf'),... size: 1882193,
put(Readable.from(pdf),... size: 102400,
put(readFileSync('./test.pdf'),...//reading the file logs 1882193 bytes size: 102400,

@tristansokol tristansokol changed the title Put files truncating at 100kb Put files truncating at 100kb when not reading from file Apr 18, 2024
@theophilusx
Copy link
Owner

theophilusx commented Apr 18, 2024 via email

@tristansokol
Copy link
Author

Thank you! I had actually caught that I forgot those important details and made a fast follow-on edit, but I know they don't update the emails so I'll include them here as well

  • Node version you are using: 20.3.1
  • Version of ssh2-sftp-client you are using: "ssh2-sftp-client": "^10.0.3"
  • Platform your client is running on (Linux, macOS, Windows): Linux & WSL
  • Platform and software for the remote SFTP server when possible: some sort of windows openssh combination I believe.

I created the following script using the (hopefully innocent) 1mb file I randomly found googling:
https://gist.githubusercontent.com/khaykov/a6105154becce4c0530da38e723c2330/raw/41ab415ac41c93a198f7da5b47d604956157c5c3/gistfile1.txt

import SFTPClient from 'ssh2-sftp-client';
const file = readFileSync('./gistfile1.txt');
console.log(file.length, Buffer.isBuffer(file));
const sftp = new SFTPClient();
await sftp.connect({
  host: '...',
  port: '22',
  username: ...
  password: ...,
  // debug: (msg) => {
  //   console.error(msg);
  // },
});
await sftp.put(file, `/D:/test.pdf`);
console.log(await sftp.stat(`/D:/test.pdf`));
await sftp.end();

which exhibits the issues I describe:

1048575 true //file is a 1mb buffer
{
  mode: 33159,
  uid: 0,
  gid: 0,
  size: 102400, //only part of it gets uploaded
  accessTime: 1713484422000,
  modifyTime: 1713484422000,
  isDirectory: false,
  isFile: true,
  isBlockDevice: false,
  isCharacterDevice: false,
  isSymbolicLink: false,
  isFIFO: false,
  isSocket: false
}

I tried your removing end() but it made no difference (aside from causing the script to hang)

  1. Create a test file by writing your buffer to a local file. Open a
    local write stream and pipe the buffer into the stream use the stream
    pipe() method (this mirrors how the client works internally). Verify the
    integrity and size of the crated file.
    Since I'm using a local file to start now I think this should be handled, but let me know if I misunderstood.
  1. Use the file created above and call put() using the filename. If this
    works, then we know it is some issue with the buffer source.
const sftp = new SFTPClient();
await sftp.connect({
  host: '...',
  port: '22',
  username: ...,
  password: ...,
  // debug: (msg) => {
  //   console.error(msg);
  // },
});
await sftp.put('./gistfile1.txt', '/D:/test.pdf');
console.log(await sftp.stat('/D:/test.pdf'));
await sftp.end();
{
  mode: 33159,
  uid: 0,
  gid: 0,
  size: 1048575, //full file size
  accessTime: 1713487711000,
  modifyTime: 1713487711000,
  isDirectory: false,
  isFile: true,
  isBlockDevice: false,
  isCharacterDevice: false,
  isSymbolicLink: false,
  isFIFO: false,
  isSocket: false
}

This works as intended, but I'm not sure if I would agree that this indicates an issue with the buffer source. (the buffer source is readFileSync, which by all means available seems to be reading the file as a buffer correctly. )

  1. As another test, open a read stream on the test file created in 1 and
    pass that in as the source to put(). If that also works, then we have
    even more confirmation the problem is with the buffer being passed in.
const sftp = new SFTPClient();
await sftp.connect({
  host: '...',
  port: '22',
  username: ...,
  password: ...,
  // debug: (msg) => {
  //   console.error(msg);
  // },
});
await sftp.put(createReadStream('./gistfile1.txt'), '/D:/test.pdf');
console.log(await sftp.stat('/D:/test.pdf'));
await sftp.end();

This works just fine as well.

I am testing locally with WSL (Ubuntu 22.04.2 LTS) but have confirmed this behavior on linux instances in GCP.

Let me know if this triggers any other thoughts!

@theophilusx
Copy link
Owner

theophilusx commented Apr 20, 2024 via email

@tristansokol
Copy link
Author

Thanks again for your help.

to close the loop here, I was able to get the server upgraded from OpenSSH 8.1 > 9.5 and that seems to have fixed the issue.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

2 participants