search

s3fs-fuse / s3fs-fuse

FUSE-based file system backed by Amazon S3
GNU General Public License v2.0
8.72k stars 1.02k forks source link

s3fs adds characters to file #2107

Open mabi08 opened 1 year ago

mabi08 commented 1 year ago

Additional Information

Version of s3fs being used (s3fs --version)

Amazon Simple Storage Service File System V1.91 (commit:unknown) with OpenSSL

Version of fuse being used (pkg-config --modversion fuse, rpm -qi fuse or dpkg -s fuse)

Name : fuse Version : 2.9.2 Release : 11.amzn2 Architecture: x86_64 Install Date: Thu 26 Jan 2023 10:49:48 PM UTC Group : System Environment/Base Size : 222809 License : GPL+ Signature : RSA/SHA256, Thu 06 Dec 2018 07:31:53 PM UTC, Key ID 11cf1f95c87f5b1a Source RPM : fuse-2.9.2-11.amzn2.src.rpm Build Date : Fri 16 Nov 2018 08:35:39 PM UTC Build Host : build.amazon.com Relocations : (not relocatable) Packager : Amazon Linux Vendor : Amazon Linux URL : https://github.com/libfuse/libfuse Summary : File System in Userspace (FUSE) utilities

Kernel information (uname -r)

4.14.301-224.520.amzn2.x86_64

GNU/Linux Distribution, if applicable (cat /etc/os-release)

NAME="Amazon Linux" VERSION="2" ID="amzn" ID_LIKE="centos rhel fedora" VERSION_ID="2" PRETTY_NAME="Amazon Linux 2" ANSI_COLOR="0;33" CPE_NAME="cpe:2.3:o:amazon:amazon_linux:2" HOME_URL="https://amazonlinux.com/"

How to run s3fs, if applicable

[] command line
[x] /etc/fstab

Details about issue

Hi,

we are using s3fs to mount s3 buckets on AWS appliances (Amazon Linux 2). However, we are currently facing a bug where removing characters from a file seems to add weird characters. In Jupyterlab editor those are shown as red dots in the file, afterwards the file is not usable anymore. This is reproducible also with other type of files. We tried building s3fs from source but this does not fix the issue for us. I attached a gif showing the problem.

Kind regards Maik

s3fs_issue

ggtakec commented 1 year ago

@mabi08 Please tell me the line in fstab when starting s3fs. And if you can use the s3fs options(dbglevel=info, curldbg) and get the log file, please let us show about it.

This phenomenon looks like when s3fs uploads(updates) a file, it doesn't change the size of the original file(or is not instructed to do so). However, I am not familiar with the Jupyterlab editor, so parsing may be difficult.

iptizer commented 1 year ago

Having the same problem at the moment and added the debug logs as requested. I will try to add some details from our troubleshooting and see whether this maybe alsready helps to debug or give us a hint. The logs are a bit difficult to anonymize, so I am reducing it to what I think could be relevant.

What we did:

After saving, opening the file with vim shows that 85 null characters are added:

20230220_s3fs_nullcharacter

Below a part of the logs after saving (there is much more, but this seems to be interesting):

20230220_s3fs_save.log

The interesting thing is, that in the end there is a "partial upload" of 85 characters.

Feb 20 13:30:23 ip-1-2-3-4 s3fs[21329]: < HTTP/1.1 206 Partial Content
Feb 20 13:30:23 ip-1-2-3-4 s3fs[21329]: < x-amz-id-2: XXXXaIHS9J2nKBwQsK3n4WZwUEpsHj0w17NzdqiQUBQ=
Feb 20 13:30:23 ip-1-2-3-4 s3fs[21329]: < x-amz-request-id: 1R3117ECVDZ0HGRB
Feb 20 13:30:23 ip-1-2-3-4 s3fs[21329]: < Date: Mon, 20 Feb 2023 13:30:24 GMT
Feb 20 13:30:23 ip-1-2-3-4 s3fs[21329]: < Last-Modified: Mon, 20 Feb 2023 13:30:24 GMT
Feb 20 13:30:23 ip-1-2-3-4 s3fs[21329]: < ETag: "abcdefb8e26af35cebbe2c21"
Feb 20 13:30:23 ip-1-2-3-4 s3fs[21329]: < x-amz-server-side-encryption: AES256
Feb 20 13:30:23 ip-1-2-3-4 s3fs[21329]: < x-amz-meta-ctime: 1676899823
Feb 20 13:30:23 ip-1-2-3-4 s3fs[21329]: < x-amz-meta-mode: 33277
Feb 20 13:30:23 ip-1-2-3-4 s3fs[21329]: < x-amz-meta-gid: 500179772
Feb 20 13:30:23 ip-1-2-3-4 s3fs[21329]: < x-amz-meta-uid: 500179772
Feb 20 13:30:23 ip-1-2-3-4 s3fs[21329]: < x-amz-meta-atime: 1676899441
Feb 20 13:30:23 ip-1-2-3-4 s3fs[21329]: < x-amz-meta-mtime: 1676899823
Feb 20 13:30:23 ip-1-2-3-4 s3fs[21329]: < x-amz-version-id: versionGMxTMmQ59Cs1
Feb 20 13:30:23 ip-1-2-3-4 s3fs[21329]: < Accept-Ranges: bytes
Feb 20 13:30:23 ip-1-2-3-4 s3fs[21329]: < Content-Range: bytes 15576-15660/15661
Feb 20 13:30:23 ip-1-2-3-4 s3fs[21329]: < Content-Type: application/octet-stream
Feb 20 13:30:23 ip-1-2-3-4 s3fs[21329]: < Server: AmazonS3
Feb 20 13:30:23 ip-1-2-3-4 s3fs[21329]: < Content-Length: 85

Maybe you have an idea where this comes from?

Thanks in advance for the help here!

ggtakec commented 1 year ago

This phenomenon is very similar to the bug that occurred with s3fs in the past. Internally, it seems to be caused by not being able to change the file size, we could not know that trigger from your log.

By the way, I would like to know the result when the same operation is performed with vim -n (without creating a swap file). I would like to know if this is a problem that only occurs in JupyterNotebook

The s3fs master branch has recently had a fix that may be related to this. (Maybe #2122 is involved) If you can, try the code on the master branch.

iptizer commented 1 year ago

Haven't tried with vim -n, but vim itself does not produce this result. I will try the -n flag and report back.

But what I can say is, that we observe the same result with RStudio another web based IDE.

What are your thoughts on the difference between vim and other editors? Is there anything we could trace? Would it help to provide the exact parameters we use? Would it help to provide larger volume of logs? Maybe what is not obvious to me might be obvious to you :).

We will also see whether a new build fixes the problem.

ggtakec commented 1 year ago

First of all, the purpose of using vim's -n option is to operate the target file directly(for the file descriptor) without using a temporary file.

If the flow is to open, edit, and close files with s3fs, I don't think there will be any problems. Regarding this issue, I would like to know if it is possible that JupyterNotebook is flushing the file with it open. I would expect s3fs to work even if I had operated it that way. However, there may be some hidden problem.

I'm sorry to trouble you, but it would be helpful if you could try it with the new code.

ggtakec commented 1 year ago

I may have been able to reproduce a similar phenomenon. It seems that it could be reproduced when closing the target file without flushing it after truncating the file size.(JupyterNotebook may be doing the same) I'll do some more research and check.

ggtakec commented 1 year ago

I was able to identify the cause of the bug and posted a PR #2131 that fixed it.

It was a bug that if user shrinks the file while it is open and read the file before flushing, the file size becomes the original size. If you can, please try the code of PR and let us know if you found a problem.

ggtakec commented 1 year ago

@iptizer

2131 was not completely fixed, so #2133 was newly created.

(#2131 is closed, #2133 will move forward to resolve this issue) If you are still able to test, please try #2133. Thanks in advance for your assistance.

ggtakec commented 1 year ago

@mabi08 I merged #2133, but I understand that you are still reporting issues after merging #2133, so we will continue to investigate this issue.

Currently, I have installed Jupyter Notebook on Ubuntu 22.04 and modfied files on browser, but I have not been able to reproduce the same phenomenon. It's not reproducible in both v1.91 and latest code(merged #2133).

Again, could you tell us the exact options when starting s3fs? I've tried with multipart-upload, stream-upload, with/without cache-directory, but I can't reproduce it, so we'll need to try with the exact same your options.

mabi08 commented 1 year ago

@ggtakec We are running s3fs on Amazon Linux 2 and mounting multiple S3 buckets on those appliances using fstab.

Here is an extract of /etc/fstab: image

What I did for testing was uninstall the old s3fs version via yum + install the latest commit and restart the machine. Could there be some caching mechanism involved?

We really appreciate your effort!

ggtakec commented 1 year ago

@mabi08 We have made some progress that may be relevant to this issue and will be contacting you. PR #2152 (by @eryugey) has been merged. This code fix includes a fix for correct exclusive control when file operations are performed from multiple processes. It may have addressed the remaining bugs in this issue, I hope so. We didn't make it into the new version v1.92 in time, but if you can try the code in this master branch, please do so.

senfbrot commented 1 year ago

Hi @ggtakec,

I've coincidently stumbled over this update. After trying the latest version from source, it seems as if it does still not work.

Additional Information

Version of s3fs being used (s3fs --version)

Amazon Simple Storage Service File System V1.92 (commit:4b3e715) with OpenSSL

Version of fuse being used (pkg-config --modversion fuse, rpm -qi fuse or dpkg -s fuse)

2.9.2

Kernel information (uname -r)

4.14.314-237.533.amzn2.x86_64`

GNU/Linux Distribution, if applicable (cat /etc/os-release)

NAME="Amazon Linux"
VERSION="2"
ID="amzn"
ID_LIKE="centos rhel fedora"
VERSION_ID="2"
PRETTY_NAME="Amazon Linux 2"
ANSI_COLOR="0;33"
CPE_NAME="cpe:2.3:o:amazon:amazon_linux:2"
HOME_URL="https://amazonlinux.com/"

How to run s3fs, if applicable

[] command line
[x] /etc/fstab 

UUID=9697d457-123c-483b-a84c-efd437479b18     /           xfs    defaults,noatime  1   1
s3fs#cdl-9zyt-uidx1234-t41payjfc763yue7oxry54dqtgi3qeuc1a-s3alias:/9zyt-uidx1234 /mnt/home-dataset/ fuse rw,_netdev,allow_other,use_cache=/tmp/s3fs-cache/home-dataset/,ensure_diskfree=5000,endpoint=eu-central-1,url=https://s3.eu-central-1.amazonaws.com,iam_role=auto,uid=uidx1234,gid=sshusers,umask=002 0 0

s3fs syslog messages (grep s3fs /var/log/syslog, journalctl | grep s3fs, or s3fs outputs)

May 30 10:49:18 ip-10-46-59-142.eu-central-1.compute.internal kernel: s3fs[6556]: segfault at 7fd1dc6809d0 ip 00007fd1e09946ae sp 00007ffe55f489f0 error 4 in libpthread-2.26.so[7fd1e098c000+18000]
May 30 10:49:18 ip-10-46-59-142.eu-central-1.compute.internal kernel: s3fs[6629]: segfault at 7f62bfc1b9d0 ip 00007f62c3f2f6ae sp 00007ffef95099f0 error 4 in libpthread-2.26.so[7f62c3f27000+18000]
May 30 10:49:18 ip-10-46-59-142.eu-central-1.compute.internal kernel: s3fs[6785]: segfault at 7fa589b969d0 ip 00007fa58deaa6ae sp 00007fff5c8227f0 error 4 in libpthread-2.26.so[7fa58dea2000+18000]
May 30 10:49:18 ip-10-46-59-142.eu-central-1.compute.internal kernel: s3fs[6699]: segfault at 7ff3611379d0 ip 00007ff36544b6ae sp 00007ffc5ee0f0f0 error 4 in libpthread-2.26.so[7ff365443000+18000]
May 30 10:49:18 ip-10-46-59-142.eu-central-1.compute.internal kernel: s3fs[6751]: segfault at 7ff7d56109d0 ip 00007ff7d99246ae sp 00007ffc83b51b10 error 4 in libpthread-2.26.so[7ff7d991c000+18000]
May 30 10:49:18 ip-10-46-59-142.eu-central-1.compute.internal kernel: s3fs[6647]: segfault at 7fea0fe8f9d0 ip 00007fea141a36ae sp 00007ffeeae543a0 error 4 in libpthread-2.26.so[7fea1419b000+18000]
May 30 10:49:18 ip-10-46-59-142.eu-central-1.compute.internal kernel: s3fs[6598]: segfault at 7f4d6bee29d0 ip 00007f4d701f66ae sp 00007ffd7fb4e3d0 error 4 in libpthread-2.26.so[7f4d701ee000+18000]
May 30 10:49:19 ip-10-46-59-142.eu-central-1.compute.internal kernel: s3fs[6571]: segfault at 7ff45fa5c9d0 ip 00007ff463d706ae sp 00007ffcd900d4c0 error 4 in libpthread-2.26.so[7ff463d68000+18000]
May 30 10:50:48 ip-10-46-59-142.eu-central-1.compute.internal kernel: s3fs[4567]: segfault at 7f23cf4f19d0 ip 00007f23d38056ae sp 00007ffd01012640 error 4 in libpthread-2.26.so[7f23d37fd000+18000]
May 30 10:50:48 ip-10-46-59-142.eu-central-1.compute.internal kernel: s3fs[4092]: segfault at 7f9fe48119d0 ip 00007f9fe8b256ae sp 00007ffc2d9d6820 error 4 in libpthread-2.26.so[7f9fe8b1d000+18000]
May 30 10:50:48 ip-10-46-59-142.eu-central-1.compute.internal kernel: s3fs[4263]: segfault at 7fc75a2b69d0 ip 00007fc75e5ca6ae sp 00007fff90df99d0 error 4 in libpthread-2.26.so[7fc75e5c2000+18000]
May 30 10:50:48 ip-10-46-59-142.eu-central-1.compute.internal kernel: s3fs[4582]: segfault at 7f2de464b9d0 ip 00007f2de895f6ae sp 00007ffe288ecd20 error 4
May 30 10:50:48 ip-10-46-59-142.eu-central-1.compute.internal kernel: s3fs[4722]: segfault at 7fc828dea9d0 ip 00007fc82d0fe6ae sp 00007fff92931310 error 4 in libpthread-2.26.so[7fc82d0f6000+18000]
May 30 10:50:48 ip-10-46-59-142.eu-central-1.compute.internal kernel: s3fs[4080]: segfault at 7f07aaf1e9d0 ip 00007f07afc336ae sp 00007ffe60f98c60 error 4 in libpthread-2.26.so[7f07afc2b000+18000]
May 30 10:50:48 ip-10-46-59-142.eu-central-1.compute.internal kernel: s3fs[4183]: segfault at 7fc42fce19d0 ip 00007fc433ff56ae sp 00007ffff90c9420 error 4
May 30 10:50:48 ip-10-46-59-142.eu-central-1.compute.internal kernel: s3fs[4108]: segfault at 7fd6c486c9d0 ip 00007fd6c8b806ae sp 00007ffe5dd18520 error 4 in libpthread-2.26.so[7fd6c8b78000+18000]
May 30 10:50:49 ip-10-46-59-142.eu-central-1.compute.internal kernel: s3fs[4831]: segfault at 7f8d7ff839d0 ip 00007f8d842976ae sp 00007ffc93d08c80 error 4 in libpthread-2.26.so[7f8d8428f000+18000]
May 30 10:50:49 ip-10-46-59-142.eu-central-1.compute.internal kernel: s3fs[4337]: segfault at 7f1e163509d0 ip 00007f1e1a6646ae sp 00007ffd4d09a3f0 error 4 in libpthread-2.26.so[7f1e1a65c000+18000]
May 30 10:51:48 ip-10-46-59-142.eu-central-1.compute.internal s3fs[3772]: s3fs version 1.92(4b3e715) : s3fs -o rw,allow_other,use_cache=/tmp/s3fs-cache/home-dataset/,ensure_diskfree=5000,endpoint=eu-central-1,url=https://s3.eu-central-1.amazonaws.com,iam_role=auto,uid=500089196,gid=993,umask=002,dev,suid cdl-9zyt-uidx1234-t41payjfc763yue7oxry54dqtgi3qeuc1a-s3alias:/9zyt-uidx1234 /mnt/home-dataset
May 30 10:51:48 ip-10-46-59-142.eu-central-1.compute.internal s3fs[3772]: Loaded mime information from /etc/mime.types
May 30 10:51:48 ip-10-46-59-142.eu-central-1.compute.internal s3fs[3948]: s3fs_cred.cpp:VersionS3fsCredential(60): Check why built-in function was called, the external credential library must have VersionS3fsCredential function.
May 30 10:51:48 ip-10-46-59-142.eu-central-1.compute.internal s3fs[3948]: init v1.92(commit:4b3e715) with OpenSSL, credential-library(built-in)
May 30 10:51:59 ip-10-46-59-142.eu-central-1.compute.internal s3fs[5084]: s3fs version 1.92(4b3e715) : s3fs -o rw,allow_other,use_cache=/tmp/s3fs-cache/home-dataset/,ensure_diskfree=5000,endpoint=eu-central-1,url=https://s3.eu-central-1.amazonaws.com,iam_role=auto,uid=500089196,gid=993,umask=002,dev,suid cdl-9zyt-uidx1234-t41payjfc763yue7oxry54dqtgi3qeuc1a-s3alias:/9zyt-uidx1234 /mnt/home-dataset
May 30 10:51:59 ip-10-46-59-142.eu-central-1.compute.internal s3fs[5084]: s3fs: MOUNTPOINT directory /mnt/home-dataset is not empty. if you are sure this is safe, can use the 'nonempty' mount option.
May 30 10:52:01 ip-10-46-59-142.eu-central-1.compute.internal s3fs[5642]: s3fs.cpp:s3fs_check_service(4424): Failed to connect by sigv4, so retry to connect by signature version 2. But you should to review url and endpoint option.
May 30 10:52:01 ip-10-46-59-142.eu-central-1.compute.internal s3fs[5642]: s3fs.cpp:s3fs_check_service(4436): Failed to check bucket and directory for mount point : Bad Request(host=https://s3.eu-central-1.amazonaws.com)
May 30 10:52:01 ip-10-46-59-142.eu-central-1.compute.internal kernel: s3fs[5642]: segfault at 7f2c53ec69d0 ip 00007f2c581da6ae sp 00007ffd58c8d6c0 error 4 in libpthread-2.26.so[7f2c581d2000+18000]
May 30 10:57:48 ip-10-46-59-142.eu-central-1.compute.internal s3fs[9234]: s3fs version 1.92(4b3e715) : s3fs outputs
May 30 10:57:48 ip-10-46-59-142.eu-central-1.compute.internal s3fs[9234]: Loaded mime information from /etc/mime.types
May 30 10:57:48 ip-10-46-59-142.eu-central-1.compute.internal s3fs[9234]: s3fs: missing MOUNTPOINT argument.
ggtakec commented 1 year ago

@senfbrot Thank you for your prompt reply. It seems that we need to investigate further to see if there are other causes. However, I haven't been able to reproduce the same phenomenon yet, so it will take some time to investigate.

senfbrot commented 1 year ago

Please find attached the curldbg output for the following actions in JupyterLab:

s3fs.log