Inconsistent file writing

[mikroskeem]

I've observed this very odd issue where my team member manages to write file over partially, previous file content's end remains after uploading (seems to happen when new content is smaller than old content, sounds like file is not getting truncated properly).

Team member uses sshfs-win to manage files. This issue seems to happen more often using this client, but can be seen every once in a while using vanilla sshfs as well. This issue seems to be quite hard to be reproducible consistently.

More interesting fact is that sshfs reports correct file contents, while remote server has previously described corrupted contents (which is probably because of sshfs-level caching I think? Not sure but worth mentioning).

Does not happen with OpenSSH, so probably not an issue with sshfs.

I'm not sure whose fault this is right now - is it because of SFTPGo? Or is it because of (kind of unlikely) ZFS oddities? I'm lost.

Any ideas where to start looking?

SFTPGo version info

SFTPGo version:

/ $ /bin/sftpgo -v
SFTPGo 1.0.0 +metrics +gcs +s3 +bolt +mysql +pgsql +sqlite +portable

Go version:

go version go1.14.7 linux/amd64

Build commands:

go get -d github.com/drakkan/sftpgo
git checkout `git rev-list --tags --max-count=1`
go build -i -ldflags "-s -w -X github.com/drakkan/sftpgo/utils.commit=`git describe --always --dirty` -X github.com/drakkan/sftpgo/utils.date=`date -u +%FT%TZ`" -o /go/bin/sftpgo

[mikroskeem]

cooldown: 0 should be the last line in this file, but as you can see from this picture, previous contents are leaking here.

Another example:

[mikroskeem]

Also happens on 4c9a5c0083b0ff158745eaf565ec0a69deb713b

[drakkan]

Hi,

can you please enable verbose logging and post the logs after you reproduce the issue? The logs could help me to understand what happen. This issue could be related to pkg/sftp#295. I'll try to reproduce myself in the next days

[mikroskeem]

https://gist.github.com/mikroskeem/7ba2e97793c577db46ca85de875eeb33 here you go.

[mikroskeem]

Easy reproduction steps (figured out now):

1. Grab a moderate sized file which structure you can inspect easily. For example yaml file, >100 lines long.
2. Add a comment to the end to make it even easier to inspect (vim comment or so).
3. Edit file, remove something from the beginning or middle using text editor and write the changes.
4. Inspect the file on filesystem directly. You'll see file end being messed up.

[drakkan]

Hi, I did some tests myself and I was able to reproduce the issue.

This workaround fix the problem for me:

sshfs a@127.0.0.1:/ /tmp/mnt -p 2022 -o workaround=truncate

On my system I have these logs for OpenSSH:

ago 19 23:28:53 p1 sftp-server[4902]: debug3: request 26: open flags 2
ago 19 23:28:53 p1 sftp-server[4902]: open "/tmp/a/ros1.txt" flags WRITE mode 00
ago 19 23:28:53 p1 sftp-server[4902]: debug1: request 26: sent handle handle 0
ago 19 23:28:53 p1 sftp-server[4902]: debug3: request 27: lstat
ago 19 23:28:53 p1 sftp-server[4902]: lstat name "/tmp/a/ros1.txt"
ago 19 23:28:53 p1 sftp-server[4902]: debug1: request 27: sent attrib have 0xf
ago 19 23:28:53 p1 sftp-server[4902]: debug1: request 28: fsetstat handle 0
ago 19 23:28:53 p1 sftp-server[4902]: set "/tmp/a/ros1.txt" size 0
ago 19 23:28:53 p1 sftp-server[4902]: debug3: request 28: sent status 0
ago 19 23:28:53 p1 sftp-server[4902]: sent status Success
ago 19 23:28:53 p1 sftp-server[4902]: debug1: request 29: fstat "/tmp/a/ros1.txt" (handle 0)
ago 19 23:28:53 p1 sftp-server[4902]: debug1: request 29: sent attrib have 0xf
ago 19 23:28:53 p1 sftp-server[4902]: debug1: request 30: write "/tmp/a/ros1.txt" (handle 0) off 0 len 3358
ago 19 23:28:53 p1 sftp-server[4902]: debug3: request 30: sent status 0

SFTPGo does not receive this command:

debug1: request 28: fsetstat handle 0 
set "/tmp/a/ros1.txt" size 0

I'll try to fix the root issue, in the meantime please use the above workaround, thank you

[mikroskeem]

Thank you, that does the trick for sshfs on Linux 😄

On Windows however (sshfs-win), I discovered more bizarre behaviour (sorry for droll examples):

And result...

While on OpenSSH_8.3p1, OpenSSL 1.1.1g 21 Apr 2020, this does not happen:

On Windows, tried both combinations of latest pre-releases and releases of sshfs-win and winfsp:

• SSHFS-Win 2020.1 Beta1 & WinFsp 2020.2 Beta2
• SSHFS-Win 2020 & WinFsp 2020.1

[drakkan]

Hi, the truncate bug should be fixed in this commit, so the option -o workaround=truncate should not be needed anymore.

If you don't want to build yourself the latest version you can download pre-built binaries from here.

Can you please confirm that sshfs on Linux now works as expected for you too? Thank you

[drakkan]

Hi,

regarding your second issue I think

Thank you, that does the trick for sshfs on Linux

On Windows however (sshfs-win), I discovered more bizarre behaviour (sorry for droll examples):

And result...

While on OpenSSH_8.3p1, OpenSSL 1.1.1g 21 Apr 2020, this does not happen:

On Windows, tried both combinations of latest pre-releases and releases of sshfs-win and winfsp:

• SSHFS-Win 2020.1 Beta1 & WinFsp 2020.2 Beta2
• SSHFS-Win 2020 & WinFsp 2020.1

Hi,

I replicated the issue using sshfs-win, I think it happens because the same file is opened for both reading and writing and this mode is not currently supported in pkg/sftp. This is a big change in pkg/sftp so I have to agree with their maintainers what is the best way to support this feature. So the fix could require some time, sorry.

I'll ask you to try a preliminary patch, when it will be ready, if you want, thank you.

[mikroskeem]

Confirmed with Linux sshfs that 7381a86 fixes truncation issue. With Windows version, at least with VSCode (I think it opens file differently) this issue is gone as well.

I'll ask you to try a preliminary patch, when it will be ready, if you want, thank you.

Definitely! 😄

[drakkan]

Hi again, can you please confirm that my proof of concept patch works for your use case? Thank you

[mikroskeem]

That seems to do the trick

And result:

[drakkan]

Great! Thanks for confirming, please let me know if you have other issues.

[drakkan]

Hi,

I updated the pkg/sftp patch and rebased the sftpgo patch on current master. I think I will merge the updated patch the next week, please let me know if you have any issue. I think it should work also if you run sftpgo on Windows but I haven't yet tested this. Thank you.

[mikroskeem]

Will let you know later today (20:00, Europe/Tallinn timezone). Getting connectivity issues to gopkg.in and other repositories where Go modules are being downloaded right now.

[drakkan]

Thank you! You can also download a pre-built binary from here

[mikroskeem]

Everything seems to work fine right now, I didn't encounter any issues. Forgot about testing at promised time, sorry.

[drakkan]

thanks for confirming