phpseclib / phpseclib

PHP Secure Communications Library
http://phpseclib.com/
MIT License
5.35k stars 891 forks source link

Attempt to assign property of non-object Net\SFTP L1152 and L1155 #1235

Open cgsmith opened 6 years ago

cgsmith commented 6 years ago

This seems to be similar to what @ytilotti was experiencing in this issue

I receive these messages after using Flysysytem's Delete call for deleting an SFTP file.

Warning: Attempt to assign property of non-object in vendor\phpseclib\phpseclib\phpseclib\Net\SFTP.php on line 1152

Warning: Attempt to assign property of non-object in vendor\phpseclib\phpseclib\phpseclib\Net\SFTP.php on line 1155

Here is the related Flysystem issue which is causing the warning to be raised.

$sftp = new Filesystem(new SftpAdapter([
            'host' => $this->config['ftpServer'],
            'port' => $this->config['ftpPort'],
            'username' => $this->config['ftpUser'],
            'password' => $this->config['ftpPass'],
            'timeout' => 10,
        ]));

$manager = new MountManager([
            'sftp' => $sftp,
        ]);

$contents = $manager->read('sftp://'.$file['path']); // Read contents
$manager->delete('sftp://'.$file['path']); // Delete file

The file does not delete from the remote SFTP site.

Versions PHP: 7.0.11 Flysystem-SFTP: 1.0 phpseclib: 2.0.9

terrafrost commented 6 years ago

I'd say do two things. First, in SFTP.php, add this right before line 1152:

if (!if_object($value)) {
    throw new \Exception('zzz');
}

The exception should hopefully get me a stacktrace so I can see what the sequence of steps was that led you up to that.

Also, try posting the SSH logs. You can get them by doing define('NET_SSH2_LOGGING', 3);. That'll output the logs real-time.

I've not really used Flysystem before so I'd need to play around with that some to provide you more guidance. Like is it possible to directly access the phpseclib SFTP object? I have no idea. For that matter I'm not even sure throwing an exception will get me a stacktrace. It's possible Flysystem catches exceptions and silently discards them idk.

cgsmith commented 6 years ago

Thanks for the advice @terrafrost - I should have provided the exception and call stack before opening a ticket.

Here is what happens with throwing an exception before line 1152:


<b>Fatal error</b>:  Uncaught Exception: zzz in C:\Users\csmith\PhpstormProjects\neesvigs-integrations\vendor\phpseclib\phpseclib\phpseclib\Net\SFTP.php:1152
--
  | Stack trace:
  | #0 vendor\phpseclib\phpseclib\phpseclib\Net\SFTP.php(920): phpseclib\Net\SFTP->_update_stat_cache('/Dev/Outbound/I...', Array)
  | #1 vendor\phpseclib\phpseclib\phpseclib\Net\SFTP.php(2347): phpseclib\Net\SFTP->_list('/Dev/Outbound/I...', true)
  | #2 vendor\phpseclib\phpseclib\phpseclib\Net\SFTP.php(2321): phpseclib\Net\SFTP->_delete_recursive('/Dev/Outbound/I...', 0)
  | #3 vendor\league\flysystem-sftp\src\SftpAdapter.php(460): phpseclib\Net\SFTP->delete('/Dev/Outbound/I...')
  | #4 vendor\league\flysystem\src\Filesystem.php(237): League\Flysystem\Sftp\SftpAdapter->delete('Dev/Outbound/IL...')
  | #5 [internal in <b>vendor\phpseclib\phpseclib\phpseclib\Net\SFTP.php</b> on line <b>1152</b><br />

I also see this in the SSH log, "Cannot delete no file permission"

-> NET_SSH2_MSG_CHANNEL_DATA (since last: 0.0024, network: 0.0001s)
00000000  00:00:01:00:00:00:00:3a:00:00:00:36:04:00:00:00  .......:...6....
00000010  01:00:00:00:2d:30:20:2f:44:65:76:2f:4f:75:74:62  ....-0 /Dev/Outb
00000020  6f:75:6e:64:2f:49:4c:53:5f:4f:72:64:65:72:73:5f  ound/ILS_Orders_
00000030  32:30:31:37:31:32:32:38:5f:31:35:32:31:38:2e:74  20171228_15218.t
00000040  78:74                                            xt

<- NET_SSH2_MSG_CHANNEL_DATA (since last: 0.1022, network: 0.102s)
00000000  00:00:01:00:00:00:00:15:00:00:00:11:65:00:00:00  ............e...
00000010  01:00:00:00:00:00:00:00:00:00:00:00:00           .............

-> NET_SSH2_MSG_CHANNEL_DATA (since last: 0.0004, network: 0.0001s)
00000000  00:00:01:00:00:00:00:38:00:00:00:34:0d:00:00:00  .......8...4....
00000010  01:00:00:00:2b:2f:44:65:76:2f:4f:75:74:62:6f:75  ....+/Dev/Outbou
00000020  6e:64:2f:49:4c:53:5f:4f:72:64:65:72:73:5f:32:30  nd/ILS_Orders_20
00000030  31:37:31:32:32:38:5f:31:35:32:31:38:2e:74:78:74  171228_15218.txt

<- NET_SSH2_MSG_CHANNEL_DATA (since last: 0.1045, network: 0.1043s)
00000000  00:00:01:00:00:00:00:37:00:00:00:33:65:00:00:00  .......7...3e...
00000010  01:00:00:00:03:00:00:00:22:43:61:6e:6e:6f:74:20  ........"Cannot 
00000020  64:65:6c:65:74:65:20:66:69:6c:65:2e:20:4e:6f:20  delete file. No 
00000030  70:65:72:6d:69:73:73:69:6f:6e:2e:00:00:00:00     permission.....

-> NET_SSH2_MSG_CHANNEL_DATA (since last: 0.0003, network: 0.0001s)
00000000  00:00:01:00:00:00:00:38:00:00:00:34:0b:00:00:00  .......8...4....
00000010  01:00:00:00:2b:2f:44:65:76:2f:4f:75:74:62:6f:75  ....+/Dev/Outbou
00000020  6e:64:2f:49:4c:53:5f:4f:72:64:65:72:73:5f:32:30  nd/ILS_Orders_20
00000030  31:37:31:32:32:38:5f:31:35:32:31:38:2e:74:78:74  171228_15218.txt

<- NET_SSH2_MSG_CHANNEL_DATA (since last: 0.0958, network: 0.0957s)
00000000  00:00:01:00:00:00:00:3a:00:00:00:36:66:00:00:00  .......:...6f...
00000010  01:00:00:00:2d:30:20:2f:44:65:76:2f:4f:75:74:62  ....-0 /Dev/Outb
00000020  6f:75:6e:64:2f:49:4c:53:5f:4f:72:64:65:72:73:5f  ound/ILS_Orders_
00000030  32:30:31:37:31:32:32:38:5f:31:35:32:31:38:2e:74  20171228_15218.t
00000040  78:74                                            xt

I am guessing that there is no way to know if a file is deleted or not?

terrafrost commented 6 years ago

I extracted the SFTP logs from what you posted:

-> NET_SFTP_REMOVE
00000000  00:00:00:01:00:00:00:2b:2f:44:65:76:2f:4f:75:74  .......+/Dev/Out
00000010  62:6f:75:6e:64:2f:49:4c:53:5f:4f:72:64:65:72:73  bound/ILS_Orders
00000020  5f:32:30:31:37:31:32:32:38:5f:31:35:32:31:38:2e  _20171228_15218.
00000030  74:78:74                                         txt

<- NET_SFTP_STATUS
00000000  00:00:00:01:00:00:00:03:00:00:00:22:43:61:6e:6e  ..........."Cann
00000010  6f:74:20:64:65:6c:65:74:65:20:66:69:6c:65:2e:20  ot delete file.
00000020  4e:6f:20:70:65:72:6d:69:73:73:69:6f:6e:2e:00:00  No permission...
00000030  00:00                                            ..

-> NET_SFTP_OPENDIR
00000000  00:00:00:01:00:00:00:2b:2f:44:65:76:2f:4f:75:74  .......+/Dev/Out
00000010  62:6f:75:6e:64:2f:49:4c:53:5f:4f:72:64:65:72:73  bound/ILS_Orders
00000020  5f:32:30:31:37:31:32:32:38:5f:31:35:32:31:38:2e  _20171228_15218.
00000030  74:78:74                                         txt

<- NET_SFTP_HANDLE
00000000  00:00:00:01:00:00:00:2d:30:20:2f:44:65:76:2f:4f  .......-0 /Dev/O
00000010  75:74:62:6f:75:6e:64:2f:49:4c:53:5f:4f:72:64:65  utbound/ILS_Orde
00000020  72:73:5f:32:30:31:37:31:32:32:38:5f:31:35:32:31  rs_20171228_1521
00000030  38:2e:74:78:74                                   8.txt

So when delete() doesn't succeed in deleting a file it, by default, thinks that perchance the file is actually a directory and tries a recursive delete on it. So _delete_recursive() is called. Thinking the "file" is a directory _delete_recursive() calls _list(), which sends the OPENDIR packet. This explains why, in the SFTP logs, it does REMOVE and then OPENDIR.

Based on the filename of ILS_Orders_20171228_15218.txt I'm assuming it isn't actually a directory and yet the SFTP server responds as tho it was.

What happens next is a bit bizzare. The server actually responds with a handle.

When I try to open a file as a directory on my server the server responds with this:

<- NET_SFTP_STATUS (0.0587s)
00000000  00:00:00:02:00:00:00:0c:4e:6f:20:73:75:63:68:20  ........No such
00000010  66:69:6c:65:00:00:00:00                          file....

So I'd say your server is misbehaving.

At this point the server attempts to update the stat cache based on it's understanding that the file just opened is a directory. The only problem is that the file is already in the stat cache as a file and therein lies the problem.

https://github.com/phpseclib/phpseclib/commit/30a11a3951ffcf36c157147285c9111f630fac08 should fix the immediate issue at hand but the stat cache is gonna be all messed up with the way this server is behaving.

As for trying to open something to determine if it's a directory.... sometimes that's just the way you gotta do things in SFTP. In-so-far as phpseclib knows /Dev/Outbound/ILS_Orders_20171228_15218.txt used to be a file but then it was changed to a directory after phpseclib did OPENDIR on /Dev/Outbound. I suppose phpseclib could do another OPENDIR on /Dev/Outbound/ but the same thing could happen in theory - the file type could change after phpseclib did the OPENDIR. Plus, technically, the permissions could change too. Maybe if you do OPENDIR once the permissions of the directory are then changed to disallow reading whilst the ILS_Orders_20171228_15218.txt still has read permissions available to you.

All of that is pretty implausible, I will concede, but that doesn't mean it's impossible and phpseclib makes no assumptions as to plausibility.

Fact is, the server should not be letting a file be opened as a directory.

Kinda makes me wonder what'd happen if you tried to do $sftp->nlist('/Dev/Outbound/ILS_Orders_20171228_15218.txt') lol

bantu commented 6 years ago

Did you see the "no permission" in the log? Does the user not have permission to delete the file and phpseclib then assumes its a directory?

terrafrost commented 6 years ago

Did you see the "no permission" in the log? Does the user not have permission to delete the file and phpseclib then assumes its a directory?

I did, however, I'm kinda treating error messages with a grain of salt.

Consider what happened on my own server when I tried to open a file as a directory. I got a "no such file" error. Only problem: it does exist as a file - it just doesn't exist as a directory.

If you do rm dirname in bash you'll get a rm: cannot remove 'dirname': Is a directory error back. delete() basically tries to do an rm first. Then it tries rm -rf dirname. So that we can't delete directories as files has precedent within Linux. Of course, Linux's error is more verbose than the errors you can get back with SFTP. With SFTP you have an error code and then an error message. The error message should just be ignored because that can be in any language under the sun. So we're left with the error code. And here are the available error codes for SFTPv3:

https://tools.ietf.org/html/draft-ietf-secsh-filexfer-02#page-21

        #define SSH_FX_OK                            0
        #define SSH_FX_EOF                           1
        #define SSH_FX_NO_SUCH_FILE                  2
        #define SSH_FX_PERMISSION_DENIED             3
        #define SSH_FX_FAILURE                       4
        #define SSH_FX_BAD_MESSAGE                   5
        #define SSH_FX_NO_CONNECTION                 6
        #define SSH_FX_CONNECTION_LOST               7
        #define SSH_FX_OP_UNSUPPORTED                8

There is no SSH_FX_IS_A_DIRECTORY error code so the server is forced to pigeonhole the actual error into one of the available error types (SSH_FX_NO_SUCH_FILE).

In the OP's case the server gave us SSH_FX_PERMISSION_DENIED back. I'm gonna assume that that actually is the issue but, as I've demonstrated above, already, error codes can't necessarily be taken at face value. If the file actually was a directory would SSH_FX_PERMISSION_DENIED be any worse of a response than SSH_FX_NO_SUCH_FILE?

Maybe OpenSSH on Linux always predictably responds with the same thing but what about on other OS's or other SFTP servers?

terrafrost commented 6 years ago

I am guessing that there is no way to know if a file is deleted or not?

One thing that might be a good idea in your case: disable the stat cache. idk how you'd do that with Flysystem but if you could access the underlying phpseclib SFTP object you could do $sftp->disableStatCache(). At that point you could do $sftp->stat('/Dev/Outbound/ILS_Orders_20171228_15218.txt') to see if the file existed after a deletion attempt.