Error when downloading file - Expected NET_SFTP_DATA or NET_SFTP_STATUS. Got packet type:

[haridarshan]

Hi @terrafrost

I'm getting the same issue #1555 when trying to download large media files (~4-7GB) from our client's SFTP Server. Some of the files are getting downloaded successfully but for some, getting this error/exception

I'm using phpseclib - 3.0.8

UnexpectedValueException Object
(
    [message:protected] => Expected NET_SFTP_DATA or NET_SFTP_STATUS. Got packet type: 
    [string:Exception:private] => 
    [code:protected] => 0
    [file:protected] => /var/www/html/vendor/phpseclib/phpseclib/phpseclib/Net/SFTP.php
    [line:protected] => 2219
    [trace:Exception:private] => ...<truncated>...

On debugging, SSH Error logs shows nothing but SFTP error logs shows

[sftp_errors:phpseclib3\Net\SFTP:private] => Array
  (
      [0] => : The file is EOF
      [1] => : The file is EOF
      [2] => : The file is EOF
      [3] => : The file is EOF
  )

Sample code from the script

define('NET_SSH2_LOGGING', SSH2::LOG_COMPLEX);

try {
    $sftp = new SFTP($sftpServerHost, $sftpServerPort, $sftpTimeout);
    $sftp->sendKEXINITLast();
    $sftp->setTimeout(0);
    $sftp->setKeepAlive(5);
    $sftp->enableDatePreservation();

    $isLoggedIn = $sftp->login($user, $password);

    try {
        $status = $sftp->get(
            '/mediaarchive/profile5/feature/BM_11146_hd_h264_p005.ts.gpg',
            '/11146/BM_11146_hd_h264_p005.ts.gpg'
        );

        echo $status;
    } catch (Throwable $exception) {
        print_r($sftp->getErrors());
        print_r($sftp->getSFTPErrors());
        print_r($exception->getMessage());
    }
} catch (Throwable $exception) {
    print_r($exception);
}

Attached entire stack trace
nohup.txt

[terrafrost]

Can you get me the SSH logs? You're already doing define('NET_SSH2_LOGGING', SSH2::LOG_COMPLEX) - you just gotta do echo $ssh->getLog();

That's more helpful because what's prob going on is that there's some sequence of packets that's causing things to get messed up.

Thanks!

[haridarshan]

@terrafrost
here is the complete ssh logs
44431-ssh-error.txt

One more thing, since am downloading media files one-by-one in a loop, when this exception is thrown, for next file it gives
"Connection closed prematurely"

[terrafrost]

So phpseclib is sending 32x SSH_FXP_READ packets at a time and is expecting 32x SSH_FXP_DATA or SSH_FXP_STATUS packets in response. The 32 is configurable through the NET_SFTP_QUEUE_SIZE constant.

Each successive SSH_FXP_DATA packet is requesting 32kb at a time with the offsets increasing by 32kb with each request.

The last SSH_FXP_READ packet your server is responding to is requesting 32kb of data that's 4,674,158,592 bytes into the file. It responds to that request without issue but then when processing the request for data 4,674,191,360 bytes in it kills the channel. If there isn't data available beyond that offset what it should do is respond with an SSH_FXP_STATUS message. Quoting https://tools.ietf.org/html/draft-ietf-secsh-filexfer-02#section-6.4:

In response to this request, the server will read as many bytes as it
can from the file (up to `len'), and return them in a SSH_FXP_DATA
message. If an error occurs or EOF is encountered before reading any
data, the server will respond with SSH_FXP_STATUS.

That's not what your server is doing.

You can probably reproduce this more simply by doing this:

$sftp->get(
    '/sfa/mediaarchive/profile5/feature/BM_44431_hd_h264_p005.ts.gpg:N0CUN',
    0x1169a8000,
    0x8000
);

(idk that /sfa/mediaarchive/profile5/feature/BM_44431_hd_h264_p005.ts.gpg:N0CUN is actually the name of the file that you're trying to load. with SFTP the way it works is that you send an SSH_FXP_OPEN packet, you get a handle, and then you send a bunch of SSH_FXP_READ packets that use that handle. normally that handle is just a random sequence of bytes but in your servers case that handle appears to be the filename)

I'm also curious to know what you're using for your SSH server. You can get that by doing echo $ssh->getServerIdentification().

Anyway, lmk about my hypothesis for $sftp->get() and what the server identication string is.

If my hypothesis pans out then get me the logs and I'll use those logs to develop / test a fix.

Thanks!

[haridarshan]

@terrafrost

Actually the server am accessing is not our own, it's a server of Media Content Provider from where am downloading the media files for processing and the issue is not specific to a file, its random.

Server Identification is: SSH-2.0-CrushFTPSSHD

I've tried to reproduce this issue with the get method you've provided but file got downloaded successfully so as I said it's random

[hari@LT0342 ~]# ls -l 4674191360
-rw-r--r-- 1 hari hari 5164188703 Mar 1 14:35 4674191360

Also, If you'll notice there is difference in filesize by 32Kb

sftp> ls -l BM_44431_hd_h264_p005.ts.gpg
-rwxrwxrwx ? 0 0 5164221471 Mar 1 14:35 BM_44431_hd_h264_p005.ts.gpg

And If I echo filesize

echo $sftp->filesize('/mediaarchive/profile5/feature/BM_44431_hd_h264_p005.ts.gpg')

outputs 5164221471.

[terrafrost]

So I actually gave you the wrong command to try lol. Try this:

$sftp->get(
    '/sfa/mediaarchive/profile5/feature/BM_44431_hd_h264_p005.ts.gpg',
    false,
    0x1169a8000,
    0x8000
);

That said, I did download and install SSH-2.0-CrushFTPSSHD and tried my own test:

$sftp->delete('dummyfile');
$sftp->put('dummyfile', str_repeat('a', 10));
$str = $sftp->get('dummyfile', false, 100, 32);

I wasn't able to reproduce the behavior your seeing with that script.

I have an idea for a change that I think will "fix" the issue for you (altho there is a case to be made that the problem is with SSH-2.0-CrushFTPSSHD and not phpsclib but whatever) but in lieu of being able to reliably reproduce the issue I won't be able to test it.

Anyway, I'll try to work on my idea in the next day or two.

Thanks!

[haridarshan]

@terrafrost

Thanks,

I've tried with the new command you've provided and it didn't throw/raised any exception but status was failed.
Here is the ssh logs just in-case if you need them
ssh_packet.txt

lol, since this thing is really getting on my nerve, I've tried downloading these media files via Python (pysftp & paramiko) but both were complete failure.

I'm not sure whether this random issue is getting caused by having multiple (~10) ssh sftp sockets open to download media files concurrently or not but I'll try to download these media files sequentially one-by-one and will see if this issue occurs or not.

[terrafrost]

Does https://github.com/terrafrost/phpseclib/tree/3.0-channel-closure fix the issue for you?

[haridarshan]

@terrafrost

Thanks.
Locally everything is working fine, no issues till now, so giving it a try on Production to download actual Content concurrently to test it thoroughly. If any issue occurs, will let you know.

I would like to ask two thing,

• like python library "paramiko" which allows client/user to mdify "Window Size" & "Max Packet Size" for a session over the Transport channel, why these two parameters are not allowed to be modified in this library?
• I don't have much knowledge how things are working in this library at low level so just out of curiousity this question came to mind, are we having Rekeying in place in-case of symmteric portion of SSH Transport Protocol "RFC 4344"?

[terrafrost]

like python library "paramiko" which allows client/user to mdify "Window Size" & "Max Packet Size" for a session over the Transport channel, why these two parameters are not allowed to be modified in this library?

I'm not sure why anyone would want to?

I don't have much knowledge how things are working in this library at low level so just out of curiousity this question came to mind, are we having Rekeying in place in-case of symmteric portion of SSH Transport Protocol "RFC 4344"?

Re-keying is recommended every 1h or after every 1GB. phpseclib doesn't initiate re-keying itself - rather, it relies on the server to initiate it.

But in this case, no, the server isn't sending any rekey requests based on the logs you provided. If it was expecting one (as opposed to initiating one) then I'd expect the whole connection - and not just the channel - would be closed.

[haridarshan]

Thanks @terrafrost

Branch 3.0-channel-closure solved the issue. So, far able to download 500+ Media Files from SFTP server each file 5GB+.

[terrafrost]

The change for this is live:

9c47b0a

I did make a few tweaks to what I did in the 3.0-channel-closure branch, so I'd switch to the 3.0 branch, instead.

Thanks!