No error message if writing to s3 backend fails

[lsowen]

I had an issue where permissions on the s3 bucket did not allow writes (but did allow proper ListBucket/GetObject). The upload was accepted without issue by sftpgo (as expected, because it writes to the local directory temporarily), but does not appear to give an error message when the write to the s3 backend fails.

[drakkan]

Hi,

thanks for reporting this issue, I'll try myself later today, meantime can you please post the full logs?

[lsowen]

🤦 It does, sorry for the incorrect issue report.

{"level":"info","time":"2020-05-19T00:01:54.361","sender":"Upload","elapsed_ms":187,"size_bytes":79076,"username":"test-user,"file_path":"test/test.txt","connection_id":"455b6d4b590dd5008ba255bb93cca566a608ba7a","protocol":"SFTP"}
{"level":"debug","time":"2020-05-19T00:01:54.361","sender":"S3Fs bucket: \"<REDACTED>\"","connection_id":"455b6d4b590dd5008ba255bb93cca566a608ba7a","message":"upload completed, path: \"/test/test.txt\", response: <nil>, readed bytes: 79076, err: AccessDenied: Access Denied\n\tstatus code: 403, request id: 71AF7E63F7CA84F1, host id: mhEksH6k+RvSLzKH/1AL5y8DLm/gU+BY2O5SDUog0nJC6cGbJqGJo4f/R8qLbqvUA4XE/Y7EZsY="}

I think I missed it because it was debug level. Thanks for this awesome tool!

[drakkan]

well, the logs can be improved, if you disable the debug level they are not clear, I'll address this minor usability issue, thank you for reporting it

[drakkan]

This is a bug, if the upload of a small file (less than upload part size) to S3/GCS fails without uploading any bytes no error is returned to the SFTP client

[drakkan]

Hi,

I was able to replicate a similar error locally using minio. It would be useful if you can check that the above commit fixes the error for you too (I have no way to test against AWS for now), thanks!

[mpucholblasco]

Hi @drakkan ,
found a similar (not 100% sure if it's the same) problem on version 1.1.1.

From time to time (due to that it's difficult to obtain the real cause), some uploads to S3 fails, but the client (according to our users) receives an OK as response.

Our logs show:

{"level":"debug","time":"2020-11-04T14:57:33.271","sender":"SFTP","connection_id":"SFTP_827110715b3029629247cfb3b1b1c8bf74ea52a9c3e86d3117246f4185cf173d_1","message":"transfer added, id: 1, active transfers: 1"}
{"level":"warn","time":"2020-11-04T14:57:33.271","sender":"SFTP","connection_id":"SFTP_827110715b3029629247cfb3b1b1c8bf74ea52a9c3e86d3117246f4185cf173d_1","message":"Unexpected error for transfer, path: \"/path/filename\", error: \"EOF\" bytes sent: 0, bytes received: 0 transfer running since 0 ms"}
{"level":"debug","time":"2020-11-04T14:57:33.271","sender":"S3Fs bucket: \"sequra-prod-sftp-debt-collection-providers\"","connection_id":"827110715b3029629247cfb3b1b1c8bf74ea52a9c3e86d3117246f4185cf173d","message":"upload completed, path: \"/path/filename\", response: <nil>, readed bytes: 0, err: ReadRequestBody: read upload data failed\ncaused by: context canceled"}
{"level":"debug","time":"2020-11-04T14:57:33.341","sender":"SFTP","connection_id":"SFTP_827110715b3029629247cfb3b1b1c8bf74ea52a9c3e86d3117246f4185cf173d_1","message":"upload file size 0 stat error 404 no such file or directory"}
{"level":"info","time":"2020-11-04T14:57:33.341","sender":"Upload","elapsed_ms":0,"size_bytes":0,"username":"inconcert","file_path":"/path/filename","connection_id":"SFTP_827110715b3029629247cfb3b1b1c8bf74ea52a9c3e86d3117246f4185cf173d_1","protocol":"SFTP"}
{"level":"warn","time":"2020-11-04T14:57:33.341","sender":"SFTP","connection_id":"SFTP_827110715b3029629247cfb3b1b1c8bf74ea52a9c3e86d3117246f4185cf173d_1","message":"transfer error: EOF, path: \"/path/filename\""}
{"level":"debug","time":"2020-11-04T14:57:33.341","sender":"SFTP","connection_id":"SFTP_827110715b3029629247cfb3b1b1c8bf74ea52a9c3e86d3117246f4185cf173d_1","message":"transfer removed, id: 1 active transfers: 0"}
{"level":"debug","time":"2020-11-04T14:57:33.341","sender":"SFTP","connection_id":"SFTP_827110715b3029629247cfb3b1b1c8bf74ea52a9c3e86d3117246f4185cf173d_1","message":"connection closed, sending exit status"}
{"level":"debug","time":"2020-11-04T14:57:33.341","sender":"SFTP","connection_id":"SFTP_827110715b3029629247cfb3b1b1c8bf74ea52a9c3e86d3117246f4185cf173d_1","message":"sent exit status {Status:0} error: EOF"}

[drakkan]

Hi,

based on these logs:

1. the client closed the connection unexpectedly and this generated the log Unexpected error for transfer, path and so the upload context was canceled
2. so we have the log ReadRequestBody: read upload data failed\ncaused by: context canceled
3. pkg/sftp closed the transfer probably here
4. from base transfer close we should return EOF
5. and so we should return an error to the client EOF should be converted in sftp.ErrSSHFxFailure
6. I'm not sure the client read the response

I'll do some more checking later, thank you

EDIT: If the client closes the transfer but not the connection it will receive a zero exit status (success) for the connection size the error returned by pkg/sftp is EOF but it should receive an error for the transfer, maybe some details about the client could help

[drakkan]

Maybe this patch could help here

[mpucholblasco]

Thanks a lot @drakkan (efficient and fast 👍 ).

I will test it when it will be merged.