Question about winscp GET -delete and SSH_FXP_STATUS with SFTP

Advertisement

Guest

Question about winscp GET -delete and SSH_FXP_STATUS with SFTP

I've noticed with one of our users is having issues deleting files from our server. We tracked things down to their winscp batch script not waiting for SSH_FXP_STATUS after sending SSH_FXP_CLOSE. The script quickly moves onto SSH_FXP_REMOVE. Is this a known issue with the 'GET' command with the -delete flag in Winscp? Sorry if there's a better source for this information, I was unable to find it. I don't have the client's exact software information, but I can get it.

Here's an example log from our server which demonstrates winscp's behavior:

2020-04-27 11:55:32,027 DEBUG SFTPSubsystemServer [Session.2188476:Default Site:testuser:123.456.789.10] Received message (SSH_FXP_CLOSE)
2020-04-27 11:55:32,027 DEBUG SFTPSubsystemServer [Session.2188476:Default Site:testuser:123.456.789.10] OnClose()
2020-04-27 11:55:32,027 DEBUG SFTPSubsystemServer [Session.2188476:Default Site:testuser:123.456.789.10] Queued FXP_CLOSE for file handle 939632750
2020-04-27 11:55:32,027 DEBUG SFTPConnection [Session.2188476:Default Site:testuser:123.456.789.10] PreProcessPacket pt=SSH_MSG_CHANNEL_DATA,len=76
2020-04-27 11:55:32,027 DEBUG SFTPConnection [Session.2188476:Default Site:testuser:123.456.789.10] SSH_MSG_CHANNEL_DATA for channel 0
2020-04-27 11:55:32,027 DEBUG SSHServerChannel [Session.2188476:Default Site:testuser:123.456.789.10] Channel 0: ProcessPacket pt=SSH_MSG_CHANNEL_DATA
2020-04-27 11:55:32,027 DEBUG SFTPServerMessageFactory [Session.2188476:Default Site:testuser:123.456.789.10] Received message (type=13,len=76)
2020-04-27 11:55:32,027 DEBUG SFTPSubsystemServer [Session.2188476:Default Site:testuser:123.456.789.10] Received message (SSH_FXP_REMOVE)
2020-04-27 11:55:32,027 DEBUG SFTPSubsystemServer [Session.2188476:Default Site:testuser:123.456.789.10] OnFileRemove(/outgoing/test.txt)
2020-04-27 11:55:32,027 DEBUG WindowsAdapter [Session.2188476:Default Site:testuser:123.456.789.10] Exception thrown while service_account was accessing test.txt - System.IO.IOException:The process cannot access the file 'test.txt' because it is being used by another process.
2020-04-27 11:55:32,027 DEBUG FileDetails [Session.2188476:Default Site:testuser:123.456.789.10] Closing file handle 939632750
2020-04-27 11:55:32,042 INFO FileDetails [Session.2188476:Default Site:testuser:123.456.789.10] Closed file /Root/partner/outgoing/test.txt after reading 4 bytes
2020-04-27 11:55:32,042 DEBUG FileDetails [Session.2188476:Default Site:testuser:123.456.789.10] Notifying stream closed 939632750
2020-04-27 11:55:32,042 DEBUG FileDetails [Session.2188476:Default Site:testuser:123.456.789.10] Notified stream closed 939632750
2020-04-27 11:55:32,042 DEBUG FileDetails [Session.2188476:Default Site:testuser:123.456.789.10] File /Root/partner/outgoing/test.txt: 0 messages to process
2020-04-27 11:55:32,042 DEBUG FileDetails [Session.2188476:Default Site:testuser:123.456.789.10] Removed file handle 939632750
2020-04-27 11:55:32,042 DEBUG SFTPSubsystemServer [Session.2188476:Default Site:testuser:123.456.789.10] Sending SSH_FXP_STATUS [requestid=47108,code=0]

Reply with quote

Advertisement

nbutkowski
Joined:
Posts:
3
Location:
New York State

The behavior with the delete flag appears to conflict with the SFTP specification. Specifically, the client should wait for an SSH_FXP_STATUS message from SSH_FXP_CLOSE before SSH_FXP_REMOVE is sent to the server. Can anyone with access to the source for WinSCP confirm the expected behavior? I will try to recreate it, but without access to see what's happening or to contribute a fix, I don't know how to handle this.

Reply with quote

martin
Site Admin
martin avatar
Joined:
Posts:
33,846
Location:
Prague, Czechia

nbutkowski wrote:

The behavior with the delete flag appears to conflict with the SFTP specification.
How does it conflict?
I believe it perfectly conforms to the specification:
https://tools.ietf.org/html/draft-ietf-secsh-filexfer-13#section-4.1
In other
words, if an application submits multiple requests to the server, the
results in the responses will be the same as if it had sent the
requests one at a time and waited for the response in each case.

Reply with quote

nbutkowski
Joined:
Posts:
3
Location:
New York State

@martin Thank you for your response. My comment was probably a poor choice of words. If a client doesn't wait for a response to SSH_FXP_CLOSE (and handle that appropriately), then it's setting up SSH_FXP_REMOVE to fail. Instead, it's safer for WinSCP to wait. But I don't know what the program is doing under the hood, so I could be entirely mistaken.

Particularly I think the client is exposed here because the server may not have yet released the resources but the client will assume it has.
The response to this request will be a SSH_FXP_STATUS message. Note
that on some server platforms even a close can fail. For example, if
the server operating system caches writes, and an error occurs while
flushing cached writes, the close operation may fail.

Note that the handle is invalid regardless of the SSH_FXP_STATUS
result. There is no way for the client to recover a handle that
fails to close. The client MUST release all resources associated
with the handle regardless of the status. The server SHOULD take
whatever steps it can to recover from a close failure and to ensure
that all resources associated with the handle on the server are
correctly released.

Reply with quote

martin
Site Admin
martin avatar
Joined:
Posts:
33,846
Location:
Prague, Czechia

nbutkowski wrote:

If a client doesn't wait for a response to SSH_FXP_CLOSE (and handle that appropriately), then it's setting up SSH_FXP_REMOVE to fail. Instead, it's safer for WinSCP to wait.
Please read again the quote in my previous post. The server must process the requests in the correct order.

And btw, the way most SFTP servers are implemented (particularly OpenSSH), they won't even know/care that the other requests were sent before the client got a responses. They read a request from the connection, process it, send a response, and only then they read another request, etc.

And during the 17 years that WinSCP supports SFTP, I've never seen an SFTP server that has any problem with this.

Reply with quote

Advertisement

nbutkowski

@martin thank you for clarifying. It looks like the order of processing commands is correct serverside, but maybe the servers internal queueing can be improved. I still feel it would be safer to document any behavioral differences between GET -DEL and GET + DEL.

Reply with quote

Advertisement

You can post new topics in this forum