[GH-ISSUE #810] Flaky behavior when fused to sftp directory #467

Closed
opened 2026-03-04 01:45:51 +03:00 by kerem · 5 comments
Owner

Originally created by @dland512 on GitHub (Aug 17, 2018).
Original GitHub issue: https://github.com/s3fs-fuse/s3fs-fuse/issues/810

Additional Information

The following information is very important in order to help us to help you. Omission of the following details may delay your support request or receive no attention at all.

Version of s3fs being used (s3fs --version)

Amazon Simple Storage Service File System V1.79(commit:unknown) with GnuTLS(gcrypt)

Version of fuse being used (pkg-config --modversion fuse)

apparently pkg-config is not insallted

System information (uname -r)

4.4.0-1062-aws

Distro (cat /etc/issue)

Ubuntu 16.04.4 LTS \n \l

s3fs command line used (if applicable)

sudo s3fs my-bucket /home/myuser/thedir -o passwd_file=/some/dir/.pwdfile -o dbglevel=info -f -o curldbg -o allow_other

/etc/fstab entry (if applicable):

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

Nothing in syslog. Here is the s3fs output. There are a lot of HTTP 404s mixed in with some HTTP 200s. Keep in mind that this is just a small sample from the logs. There are a ton of entries just like this at the time the file was being transferred.

< HTTP/1.1 404 Not Found
< x-amz-request-id: 72F446CCAD1BFB72
< x-amz-id-2: PvjmvHrFjrdSvNFhMLM61ckte8uyocV8weajfHYOOJ39bnAg48L4g5R/CHXc9N65pZrQDEsrwKI=
< Content-Type: application/xml
< Transfer-Encoding: chunked
< Date: Fri, 17 Aug 2018 09:01:25 GMT
< Server: AmazonS3
< 
* Connection #0 to host my-bucket.s3-us-east-2.amazonaws.com left intact
* Hostname my-bucket.s3-us-east-2.amazonaws.com was found in DNS cache
*   Trying 52.219.96.32...
* Connected to my-bucket.s3-us-east-2.amazonaws.com (52.219.96.32) port 80 (#0)
> HEAD /thefile.zip/ HTTP/1.1
host: my-bucket.s3-us-east-2.amazonaws.com
Accept: */*
Authorization: AWS4-HMAC-SHA256 Credential=ABCD/20180817/us-east-2/s3/aws4_request, SignedHeaders=host;x-amz-content-sha256;x-amz-date, Signature=fa0bb73e8d29bb2aed1f0afe2ee53cb264d2e2a7a10343f7a0881dd29ee4f4d0
x-amz-content-sha256: abc123
x-amz-date: 20180817T090126Z

< HTTP/1.1 404 Not Found
< x-amz-request-id: 4079640258CBA4F8
< x-amz-id-2: bgyphbONQvhFcR2I1KeCyoJSvbPwi0eYhDJ/rPFLP5o0nb0Ip65ungU+m+G2K6OKSBk78dAlGko=
< Content-Type: application/xml
< Transfer-Encoding: chunked
< Date: Fri, 17 Aug 2018 09:01:25 GMT
< Server: AmazonS3
< 
* Connection #0 to host my-bucket.s3-us-east-2.amazonaws.com left intact
* Hostname my-bucket.s3-us-east-2.amazonaws.com was found in DNS cache
*   Trying 52.219.96.32...
* Connected to my-bucket.s3-us-east-2.amazonaws.com (52.219.96.32) port 80 (#0)
> HEAD /thefile.zip_%24folder%24 HTTP/1.1
host: my-bucket.s3-us-east-2.amazonaws.com
Accept: */*
Authorization: AWS4-HMAC-SHA256 Credential=ABCD/20180817/us-east-2/s3/aws4_request, SignedHeaders=host;x-amz-content-sha256;x-amz-date, Signature=42a3e32f5dd3fc2eb1082636563813e0c4933224a3bc67018aa15199cd8425ac
x-amz-content-sha256: abc123
x-amz-date: 20180817T090126Z

< HTTP/1.1 404 Not Found
< x-amz-request-id: ACC374D168AB9AF9
< x-amz-id-2: g3FBobFODLEbom71XVcS1ZxJUJI75J5JwO27KAYnQS/41AdLSj2mKucrsPj8RO7PAc3CMATbpbI=
< Content-Type: application/xml
< Transfer-Encoding: chunked
< Date: Fri, 17 Aug 2018 09:01:25 GMT
< Server: AmazonS3
< 
* Connection #0 to host my-bucket.s3-us-east-2.amazonaws.com left intact
* Rebuilt URL to: http://my-bucket.s3-us-east-2.amazonaws.com/?delimiter=/&max-keys=1&prefix=thefile.zip/
* Hostname my-bucket.s3-us-east-2.amazonaws.com was found in DNS cache
*   Trying 52.219.96.32...
* Connected to my-bucket.s3-us-east-2.amazonaws.com (52.219.96.32) port 80 (#0)
> GET /?delimiter=/&max-keys=1&prefix=thefile.zip/ HTTP/1.1
host: my-bucket.s3-us-east-2.amazonaws.com
Accept: */*
Authorization: AWS4-HMAC-SHA256 Credential=ABCD/20180817/us-east-2/s3/aws4_request, SignedHeaders=host;x-amz-content-sha256;x-amz-date, Signature=90235c8aa7494f0a6b10ec41161b420fdd82ea66480fed1542023643f570d8ba
x-amz-content-sha256: abc123
x-amz-date: 20180817T090126Z

< HTTP/1.1 200 OK
< x-amz-id-2: UI8aBiH/zawE4uOqUwyXXsNR5ynQWE/VubXEyvrj249+cJxQN5l/x3nNpm9pPB/87O9+6+oWigs=
< x-amz-request-id: 0B33A930EC074ABE
< Date: Fri, 17 Aug 2018 09:01:27 GMT
< x-amz-bucket-region: us-east-2
< Content-Type: application/xml
< Transfer-Encoding: chunked
< Server: AmazonS3
< 
* Connection #0 to host my-bucket.s3-us-east-2.amazonaws.com left intact
th=/thefile.zip][fd=6][offset=0][size=4775936]
[INF]       Close(1319): [ent->file=/thefile.zip][ent->fd=6]
[INF]       Close(560): [path=/thefile.zip][fd=6][refcnt=1]
[INF] s3fs_getxattr(3045): [path=/thefile.zip][name=security.capability][value=(nil)][size=0]
[INF]       HeadRequest(2276): [tpath=/thefile.zip]
[INF]       PreHeadRequest(2214): [tpath=/thefile.zip][bpath=][save=][sseckeypos=-1]
[INF]       prepare_url(4085): URL is http://s3-us-east-2.amazonaws.com/my-bucket/thefile.zip
[INF]       prepare_url(4117): URL changed is http://my-bucket.s3-us-east-2.amazonaws.com/thefile.zip
[INF]       insertV4Headers(2069): computing signature [HEAD] [/thefile.zip] [] []
[INF]       url_to_host(99): url is http://s3-us-east-2.amazonaws.com
[INF]       RequestPerform(1765): HTTP response code 404 was returned, returning ENOENT
[INF]       HeadRequest(2276): [tpath=/thefile.zip/]
[INF]       PreHeadRequest(2214): [tpath=/thefile.zip/][bpath=][save=][sseckeypos=-1]
[INF]       prepare_url(4085): URL is http://s3-us-east-2.amazonaws.com/my-bucket/thefile.zip/
[INF]       prepare_url(4117): URL changed is http://my-bucket.s3-us-east-2.amazonaws.com/thefile.zip/
[INF]       insertV4Headers(2069): computing signature [HEAD] [/thefile.zip/] [] []
[INF]       url_to_host(99): url is http://s3-us-east-2.amazonaws.com
[INF]       RequestPerform(1765): HTTP response code 404 was returned, returning ENOENT
[INF]       HeadRequest(2276): [tpath=/thefile.zip_$folder$]
[INF]       PreHeadRequest(2214): [tpath=/thefile.zip_$folder$][bpath=][save=][sseckeypos=-1]
[INF]       prepare_url(4085): URL is http://s3-us-east-2.amazonaws.com/my-bucket/thefile.zip_%24folder%24
[INF]       prepare_url(4117): URL changed is http://my-bucket.s3-us-east-2.amazonaws.com/thefile.zip_%24folder%24
[INF]       insertV4Headers(2069): computing signature [HEAD] [/thefile.zip_$folder$] [] []
[INF]       url_to_host(99): url is http://s3-us-east-2.amazonaws.com
[INF]       RequestPerform(1765): HTTP response code 404 was returned, returning ENOENT
[INF]   list_bucket(2408): [path=/thefile.zip]
[INF]       ListBucketRequest(2682): [tpath=/thefile.zip]
[INF]       prepare_url(4085): URL is http://s3-us-east-2.amazonaws.com/my-bucket?delimiter=/&max-keys=1&prefix=thefile.zip/
[INF]       prepare_url(4117): URL changed is http://my-bucket.s3-us-east-2.amazonaws.com?delimiter=/&max-keys=1&prefix=thefile.zip/
[INF]       insertV4Headers(2069): computing signature [GET] [delimiter=/&max-keys=1&prefix=thefile.zip/] [] []
[INF]       url_to_host(99): url is http://s3-us-east-2.amazonaws.com
[INF]       RequestPerform(1743): HTTP response code 200
[ERR] append_objects_from_xml_ex(2504): contents_xp->nodesetval is empty.
[ERR] append_objects_from_xml_ex(2504): contents_xp->nodesetval is empty.
[INF]       ExistOpen(1275): [path=/thefile.zip][fd=6]
[INF]       Open(1224): [path=/thefile.zip][size=-1][time=-1]
[INF]       Open(600): [path=/thefile.zip][fd=6][size=-1][time=-1]
[INF]       Dup(584): [path=/thefile.zip][fd=6][refcnt=2]
[INF]       Write(985): [path=/thefile.zip][fd=6][offset=4779894][size=138]
[INF]       Load(807): [path=/thefile.zip][fd=6][offset=0][size=4779894]
[INF]       Close(1319): [ent->file=/thefile.zip][ent->fd=6]
[INF]       Close(560): [path=/thefile.zip][fd=6][refcnt=1]
[INF]       ExistOpen(1275): [path=/thefile.zip][fd=6]
[INF]       Open(1224): [path=/thefile.zip][size=-1][time=-1]
[INF]       Open(600): [path=/thefile.zip][fd=6][size=-1][time=-1]
[INF]       Dup(584): [path=/thefile.zip][fd=6][refcnt=2]
[INF]       Write(985): [path=/thefile.zip][fd=6][offset=4780032][size=4096]
[INF]       Load(807): [path=/thefile.zip][fd=6][offset=0][size=4780032]
[INF]       Close(1319): [ent->file=/thefile.zip][ent->fd=6]
[INF]       Close(560): [path=/thefile.zip][fd=6][refcnt=1]
[INF]       ExistOpen(1275): [path=/thefile.zip][fd=6]
[INF]       Open(1224): [path=/thefile.zip][size=-1][time=-1]
[INF]       Open(600): [path=/thefile.zip][fd=6][size=-1][time=-1]
[INF]       Dup(584): [path=/thefile.zip][fd=6][refcnt=2]
[INF]       Write(985): [path=/thefile.zip][fd=6][offset=4784128][size=4096]
[INF]       Load(807): [path=/thefile.zip][fd=6][offset=0][size=4784128]
[INF]       Close(1319): [ent->file=/thefile.zip][ent->fd=6]
[INF]       Close(560): [path=/thefile.zip][fd=6][refcnt=1]
[INF]       ExistOpen(1275): [path=/thefile.zip][fd=6]
[INF]       Open(1224): [path=/thefile.zip][size=-1][time=-1]
[INF]       Open(600): [path=/thefile.zip][fd=6][size=-1][time=-1]
[INF]       Dup(584): [path=/thefile.zip][fd=6][refcnt=2]
[INF]       Write(985): [path=/thefile.zip][fd=6][offset=4788224][size=4096]
[INF]       Load(807): [path=/thefile.zip][fd=6][offset=0][size=4788224]
[INF]       Close(1319): [ent->file=/thefile.zip][ent->fd=6]
[INF]       Close(560): [path=/thefile.zip][fd=6][refcnt=1]
[INF]       ExistOpen(1275): [path=/thefile.zip][fd=6]
[INF]       Open(1224): [path=/thefile.zip][size=-1][time=-1]
[INF]       Open(600): [path=/thefile.zip][fd=6][size=-1][time=-1]
[INF]       Dup(584): [path=/thefile.zip][fd=6][refcnt=2]
[INF]       Write(985): [path=/thefile.zip][fd=6][offset=4792320][size=4096]
[INF]       Load(807): [path=/thefile.zip][fd=6][offset=0][size=4792320]
[INF]       Close(1319): [ent->file=/thefile.zip][ent->fd=6]
[INF]       Close(560): [path=/thefile.zip][fd=6][refcnt=1]
[INF]       ExistOpen(1275): [path=/thefile.zip][fd=6]
[INF]       Open(1224): [path=/thefile.zip][size=-1][time=-1]
[INF]       Open(600): [path=/thefile.zip][fd=6][size=-1][time=-1]
[INF]       Dup(584): [path=/thefile.zip][fd=6][refcnt=2]
[INF]       Write(985): [path=/thefile.zip][fd=6][offset=4796416][size=4096]
[INF]       Load(807): [path=/thefile.zip][fd=6][offset=0][size=4796416]
[INF]       Close(1319): [ent->file=/thefile.zip][ent->fd=6]
[INF]       Close(560): [path=/thefile.zip][fd=6][refcnt=1]
[INF]       ExistOpen(1275): [path=/thefile.zip][fd=6]
[INF]       Open(1224): [path=/thefile.zip][size=-1][time=-1]
[INF]       Open(600): [path=/thefile.zip][fd=6][size=-1][time=-1]
[INF]       Dup(584): [path=/thefile.zip][fd=6][refcnt=2]
[INF]       Write(985): [path=/thefile.zip][fd=6][offset=4800512][size=4096]
[INF]       Load(807): [path=/thefile.zip][fd=6][offset=0][size=4800512]
[INF]       Close(1319): [ent->file=/thefile.zip][ent->fd=6]
[INF]       Close(560): [path=/thefile.zip][fd=6][refcnt=1]
[INF]       ExistOpen(1275): [path=/thefile.zip][fd=6]
[INF]       Open(1224): [path=/thefile.zip][size=-1][time=-1]
[INF]       Open(600): [path=/thefile.zip][fd=6][size=-1][time=-1]
[INF]       Dup(584): [path=/thefile.zip][fd=6][refcnt=2]
[INF]       Write(985): [path=/thefile.zip][fd=6][offset=4804608][size=4096]
[INF]       Load(807): [path=/thefile.zip][fd=6][offset=0][size=4804608]
[INF]       Close(1319): [ent->file=/thefile.zip][ent->fd=6]
[INF]       Close(560): [path=/thefile.zip][fd=6][refcnt=1]
[INF]       ExistOpen(1275): [path=/thefile.zip][fd=6]
[INF]       Open(1224): [path=/thefile.zip][size=-1][time=-1]
[INF]       Open(600): [path=/thefile.zi* Hostname my-bucket.s3-us-east-2.amazonaws.com was found in DNS cache
*   Trying 52.219.96.32...
* Connected to my-bucket.s3-us-east-2.amazonaws.com (52.219.96.32) port 80 (#0)
> HEAD /thefile.zip HTTP/1.1
host: my-bucket.s3-us-east-2.amazonaws.com
Accept: */*
Authorization: AWS4-HMAC-SHA256 Credential=ABCD/20180817/us-east-2/s3/aws4_request, SignedHeaders=host;x-amz-content-sha256;x-amz-date, Signature=50be1a67b231710a1ca29e30d67bf46a5b21deeade1bb87ad9238e97f63e8522
x-amz-content-sha256: abc123
x-amz-date: 20180817T090126Z

Details about issue

I have sftp set up on an aws ec2 instance with s3fs. A client in transferring a 20 MB - 30 MB file over via sftp every night directly into the folder that is fused with S3. About half the time the transfer doesn't work and the file never shows up on disk or in S3. I've tried it myself from various clients and I can't reproduce the issue.

Is it possible that s3fs is not playing nicely with sftp? Should I try having them ftp the files to a non-fused directory and then copying it over to the fused directory?

Originally created by @dland512 on GitHub (Aug 17, 2018). Original GitHub issue: https://github.com/s3fs-fuse/s3fs-fuse/issues/810 ### Additional Information _The following information is very important in order to help us to help you. Omission of the following details may delay your support request or receive no attention at all._ #### Version of s3fs being used (s3fs --version) Amazon Simple Storage Service File System V1.79(commit:unknown) with GnuTLS(gcrypt) #### Version of fuse being used (pkg-config --modversion fuse) apparently `pkg-config` is not insallted #### System information (uname -r) 4.4.0-1062-aws #### Distro (cat /etc/issue) Ubuntu 16.04.4 LTS \n \l #### s3fs command line used (if applicable) ``` sudo s3fs my-bucket /home/myuser/thedir -o passwd_file=/some/dir/.pwdfile -o dbglevel=info -f -o curldbg -o allow_other ``` #### /etc/fstab entry (if applicable): ``` ``` #### s3fs syslog messages (grep s3fs /var/log/syslog, or s3fs outputs) Nothing in syslog. Here is the `s3fs` output. There are a lot of HTTP `404`s mixed in with some HTTP `200`s. Keep in mind that this is just a small sample from the logs. There are a ton of entries just like this at the time the file was being transferred. ``` < HTTP/1.1 404 Not Found < x-amz-request-id: 72F446CCAD1BFB72 < x-amz-id-2: PvjmvHrFjrdSvNFhMLM61ckte8uyocV8weajfHYOOJ39bnAg48L4g5R/CHXc9N65pZrQDEsrwKI= < Content-Type: application/xml < Transfer-Encoding: chunked < Date: Fri, 17 Aug 2018 09:01:25 GMT < Server: AmazonS3 < * Connection #0 to host my-bucket.s3-us-east-2.amazonaws.com left intact * Hostname my-bucket.s3-us-east-2.amazonaws.com was found in DNS cache * Trying 52.219.96.32... * Connected to my-bucket.s3-us-east-2.amazonaws.com (52.219.96.32) port 80 (#0) > HEAD /thefile.zip/ HTTP/1.1 host: my-bucket.s3-us-east-2.amazonaws.com Accept: */* Authorization: AWS4-HMAC-SHA256 Credential=ABCD/20180817/us-east-2/s3/aws4_request, SignedHeaders=host;x-amz-content-sha256;x-amz-date, Signature=fa0bb73e8d29bb2aed1f0afe2ee53cb264d2e2a7a10343f7a0881dd29ee4f4d0 x-amz-content-sha256: abc123 x-amz-date: 20180817T090126Z < HTTP/1.1 404 Not Found < x-amz-request-id: 4079640258CBA4F8 < x-amz-id-2: bgyphbONQvhFcR2I1KeCyoJSvbPwi0eYhDJ/rPFLP5o0nb0Ip65ungU+m+G2K6OKSBk78dAlGko= < Content-Type: application/xml < Transfer-Encoding: chunked < Date: Fri, 17 Aug 2018 09:01:25 GMT < Server: AmazonS3 < * Connection #0 to host my-bucket.s3-us-east-2.amazonaws.com left intact * Hostname my-bucket.s3-us-east-2.amazonaws.com was found in DNS cache * Trying 52.219.96.32... * Connected to my-bucket.s3-us-east-2.amazonaws.com (52.219.96.32) port 80 (#0) > HEAD /thefile.zip_%24folder%24 HTTP/1.1 host: my-bucket.s3-us-east-2.amazonaws.com Accept: */* Authorization: AWS4-HMAC-SHA256 Credential=ABCD/20180817/us-east-2/s3/aws4_request, SignedHeaders=host;x-amz-content-sha256;x-amz-date, Signature=42a3e32f5dd3fc2eb1082636563813e0c4933224a3bc67018aa15199cd8425ac x-amz-content-sha256: abc123 x-amz-date: 20180817T090126Z < HTTP/1.1 404 Not Found < x-amz-request-id: ACC374D168AB9AF9 < x-amz-id-2: g3FBobFODLEbom71XVcS1ZxJUJI75J5JwO27KAYnQS/41AdLSj2mKucrsPj8RO7PAc3CMATbpbI= < Content-Type: application/xml < Transfer-Encoding: chunked < Date: Fri, 17 Aug 2018 09:01:25 GMT < Server: AmazonS3 < * Connection #0 to host my-bucket.s3-us-east-2.amazonaws.com left intact * Rebuilt URL to: http://my-bucket.s3-us-east-2.amazonaws.com/?delimiter=/&max-keys=1&prefix=thefile.zip/ * Hostname my-bucket.s3-us-east-2.amazonaws.com was found in DNS cache * Trying 52.219.96.32... * Connected to my-bucket.s3-us-east-2.amazonaws.com (52.219.96.32) port 80 (#0) > GET /?delimiter=/&max-keys=1&prefix=thefile.zip/ HTTP/1.1 host: my-bucket.s3-us-east-2.amazonaws.com Accept: */* Authorization: AWS4-HMAC-SHA256 Credential=ABCD/20180817/us-east-2/s3/aws4_request, SignedHeaders=host;x-amz-content-sha256;x-amz-date, Signature=90235c8aa7494f0a6b10ec41161b420fdd82ea66480fed1542023643f570d8ba x-amz-content-sha256: abc123 x-amz-date: 20180817T090126Z < HTTP/1.1 200 OK < x-amz-id-2: UI8aBiH/zawE4uOqUwyXXsNR5ynQWE/VubXEyvrj249+cJxQN5l/x3nNpm9pPB/87O9+6+oWigs= < x-amz-request-id: 0B33A930EC074ABE < Date: Fri, 17 Aug 2018 09:01:27 GMT < x-amz-bucket-region: us-east-2 < Content-Type: application/xml < Transfer-Encoding: chunked < Server: AmazonS3 < * Connection #0 to host my-bucket.s3-us-east-2.amazonaws.com left intact th=/thefile.zip][fd=6][offset=0][size=4775936] [INF] Close(1319): [ent->file=/thefile.zip][ent->fd=6] [INF] Close(560): [path=/thefile.zip][fd=6][refcnt=1] [INF] s3fs_getxattr(3045): [path=/thefile.zip][name=security.capability][value=(nil)][size=0] [INF] HeadRequest(2276): [tpath=/thefile.zip] [INF] PreHeadRequest(2214): [tpath=/thefile.zip][bpath=][save=][sseckeypos=-1] [INF] prepare_url(4085): URL is http://s3-us-east-2.amazonaws.com/my-bucket/thefile.zip [INF] prepare_url(4117): URL changed is http://my-bucket.s3-us-east-2.amazonaws.com/thefile.zip [INF] insertV4Headers(2069): computing signature [HEAD] [/thefile.zip] [] [] [INF] url_to_host(99): url is http://s3-us-east-2.amazonaws.com [INF] RequestPerform(1765): HTTP response code 404 was returned, returning ENOENT [INF] HeadRequest(2276): [tpath=/thefile.zip/] [INF] PreHeadRequest(2214): [tpath=/thefile.zip/][bpath=][save=][sseckeypos=-1] [INF] prepare_url(4085): URL is http://s3-us-east-2.amazonaws.com/my-bucket/thefile.zip/ [INF] prepare_url(4117): URL changed is http://my-bucket.s3-us-east-2.amazonaws.com/thefile.zip/ [INF] insertV4Headers(2069): computing signature [HEAD] [/thefile.zip/] [] [] [INF] url_to_host(99): url is http://s3-us-east-2.amazonaws.com [INF] RequestPerform(1765): HTTP response code 404 was returned, returning ENOENT [INF] HeadRequest(2276): [tpath=/thefile.zip_$folder$] [INF] PreHeadRequest(2214): [tpath=/thefile.zip_$folder$][bpath=][save=][sseckeypos=-1] [INF] prepare_url(4085): URL is http://s3-us-east-2.amazonaws.com/my-bucket/thefile.zip_%24folder%24 [INF] prepare_url(4117): URL changed is http://my-bucket.s3-us-east-2.amazonaws.com/thefile.zip_%24folder%24 [INF] insertV4Headers(2069): computing signature [HEAD] [/thefile.zip_$folder$] [] [] [INF] url_to_host(99): url is http://s3-us-east-2.amazonaws.com [INF] RequestPerform(1765): HTTP response code 404 was returned, returning ENOENT [INF] list_bucket(2408): [path=/thefile.zip] [INF] ListBucketRequest(2682): [tpath=/thefile.zip] [INF] prepare_url(4085): URL is http://s3-us-east-2.amazonaws.com/my-bucket?delimiter=/&max-keys=1&prefix=thefile.zip/ [INF] prepare_url(4117): URL changed is http://my-bucket.s3-us-east-2.amazonaws.com?delimiter=/&max-keys=1&prefix=thefile.zip/ [INF] insertV4Headers(2069): computing signature [GET] [delimiter=/&max-keys=1&prefix=thefile.zip/] [] [] [INF] url_to_host(99): url is http://s3-us-east-2.amazonaws.com [INF] RequestPerform(1743): HTTP response code 200 [ERR] append_objects_from_xml_ex(2504): contents_xp->nodesetval is empty. [ERR] append_objects_from_xml_ex(2504): contents_xp->nodesetval is empty. [INF] ExistOpen(1275): [path=/thefile.zip][fd=6] [INF] Open(1224): [path=/thefile.zip][size=-1][time=-1] [INF] Open(600): [path=/thefile.zip][fd=6][size=-1][time=-1] [INF] Dup(584): [path=/thefile.zip][fd=6][refcnt=2] [INF] Write(985): [path=/thefile.zip][fd=6][offset=4779894][size=138] [INF] Load(807): [path=/thefile.zip][fd=6][offset=0][size=4779894] [INF] Close(1319): [ent->file=/thefile.zip][ent->fd=6] [INF] Close(560): [path=/thefile.zip][fd=6][refcnt=1] [INF] ExistOpen(1275): [path=/thefile.zip][fd=6] [INF] Open(1224): [path=/thefile.zip][size=-1][time=-1] [INF] Open(600): [path=/thefile.zip][fd=6][size=-1][time=-1] [INF] Dup(584): [path=/thefile.zip][fd=6][refcnt=2] [INF] Write(985): [path=/thefile.zip][fd=6][offset=4780032][size=4096] [INF] Load(807): [path=/thefile.zip][fd=6][offset=0][size=4780032] [INF] Close(1319): [ent->file=/thefile.zip][ent->fd=6] [INF] Close(560): [path=/thefile.zip][fd=6][refcnt=1] [INF] ExistOpen(1275): [path=/thefile.zip][fd=6] [INF] Open(1224): [path=/thefile.zip][size=-1][time=-1] [INF] Open(600): [path=/thefile.zip][fd=6][size=-1][time=-1] [INF] Dup(584): [path=/thefile.zip][fd=6][refcnt=2] [INF] Write(985): [path=/thefile.zip][fd=6][offset=4784128][size=4096] [INF] Load(807): [path=/thefile.zip][fd=6][offset=0][size=4784128] [INF] Close(1319): [ent->file=/thefile.zip][ent->fd=6] [INF] Close(560): [path=/thefile.zip][fd=6][refcnt=1] [INF] ExistOpen(1275): [path=/thefile.zip][fd=6] [INF] Open(1224): [path=/thefile.zip][size=-1][time=-1] [INF] Open(600): [path=/thefile.zip][fd=6][size=-1][time=-1] [INF] Dup(584): [path=/thefile.zip][fd=6][refcnt=2] [INF] Write(985): [path=/thefile.zip][fd=6][offset=4788224][size=4096] [INF] Load(807): [path=/thefile.zip][fd=6][offset=0][size=4788224] [INF] Close(1319): [ent->file=/thefile.zip][ent->fd=6] [INF] Close(560): [path=/thefile.zip][fd=6][refcnt=1] [INF] ExistOpen(1275): [path=/thefile.zip][fd=6] [INF] Open(1224): [path=/thefile.zip][size=-1][time=-1] [INF] Open(600): [path=/thefile.zip][fd=6][size=-1][time=-1] [INF] Dup(584): [path=/thefile.zip][fd=6][refcnt=2] [INF] Write(985): [path=/thefile.zip][fd=6][offset=4792320][size=4096] [INF] Load(807): [path=/thefile.zip][fd=6][offset=0][size=4792320] [INF] Close(1319): [ent->file=/thefile.zip][ent->fd=6] [INF] Close(560): [path=/thefile.zip][fd=6][refcnt=1] [INF] ExistOpen(1275): [path=/thefile.zip][fd=6] [INF] Open(1224): [path=/thefile.zip][size=-1][time=-1] [INF] Open(600): [path=/thefile.zip][fd=6][size=-1][time=-1] [INF] Dup(584): [path=/thefile.zip][fd=6][refcnt=2] [INF] Write(985): [path=/thefile.zip][fd=6][offset=4796416][size=4096] [INF] Load(807): [path=/thefile.zip][fd=6][offset=0][size=4796416] [INF] Close(1319): [ent->file=/thefile.zip][ent->fd=6] [INF] Close(560): [path=/thefile.zip][fd=6][refcnt=1] [INF] ExistOpen(1275): [path=/thefile.zip][fd=6] [INF] Open(1224): [path=/thefile.zip][size=-1][time=-1] [INF] Open(600): [path=/thefile.zip][fd=6][size=-1][time=-1] [INF] Dup(584): [path=/thefile.zip][fd=6][refcnt=2] [INF] Write(985): [path=/thefile.zip][fd=6][offset=4800512][size=4096] [INF] Load(807): [path=/thefile.zip][fd=6][offset=0][size=4800512] [INF] Close(1319): [ent->file=/thefile.zip][ent->fd=6] [INF] Close(560): [path=/thefile.zip][fd=6][refcnt=1] [INF] ExistOpen(1275): [path=/thefile.zip][fd=6] [INF] Open(1224): [path=/thefile.zip][size=-1][time=-1] [INF] Open(600): [path=/thefile.zip][fd=6][size=-1][time=-1] [INF] Dup(584): [path=/thefile.zip][fd=6][refcnt=2] [INF] Write(985): [path=/thefile.zip][fd=6][offset=4804608][size=4096] [INF] Load(807): [path=/thefile.zip][fd=6][offset=0][size=4804608] [INF] Close(1319): [ent->file=/thefile.zip][ent->fd=6] [INF] Close(560): [path=/thefile.zip][fd=6][refcnt=1] [INF] ExistOpen(1275): [path=/thefile.zip][fd=6] [INF] Open(1224): [path=/thefile.zip][size=-1][time=-1] [INF] Open(600): [path=/thefile.zi* Hostname my-bucket.s3-us-east-2.amazonaws.com was found in DNS cache * Trying 52.219.96.32... * Connected to my-bucket.s3-us-east-2.amazonaws.com (52.219.96.32) port 80 (#0) > HEAD /thefile.zip HTTP/1.1 host: my-bucket.s3-us-east-2.amazonaws.com Accept: */* Authorization: AWS4-HMAC-SHA256 Credential=ABCD/20180817/us-east-2/s3/aws4_request, SignedHeaders=host;x-amz-content-sha256;x-amz-date, Signature=50be1a67b231710a1ca29e30d67bf46a5b21deeade1bb87ad9238e97f63e8522 x-amz-content-sha256: abc123 x-amz-date: 20180817T090126Z ``` ### Details about issue I have sftp set up on an aws ec2 instance with `s3fs`. A client in transferring a 20 MB - 30 MB file over via sftp every night directly into the folder that is fused with S3. About half the time the transfer doesn't work and the file never shows up on disk or in S3. I've tried it myself from various clients and I can't reproduce the issue. Is it possible that `s3fs` is not playing nicely with sftp? Should I try having them ftp the files to a non-fused directory and then copying it over to the fused directory?
kerem closed this issue 2026-03-04 01:45:52 +03:00
Author
Owner

@dland512 commented on GitHub (Aug 22, 2018):

FYI, this does seem to be due to some the interaction between sftp and fuse. I have turned off s3fs and am now successfully receiving ftp files. Unfortunately, I can't say exactly what the issue is. Since I don't control the sftp client that is having the issue, I don't have the option of doing a lot of debugging. Some sftp clients work fine and one of them does not.

<!-- gh-comment-id:415119916 --> @dland512 commented on GitHub (Aug 22, 2018): FYI, this does seem to be due to some the interaction between sftp and fuse. I have turned off s3fs and am now successfully receiving ftp files. Unfortunately, I can't say exactly what the issue is. Since I don't control the sftp client that is having the issue, I don't have the option of doing a lot of debugging. Some sftp clients work fine and one of them does not.
Author
Owner

@gaul commented on GitHub (Feb 2, 2019):

Do you know which operations are failing or blocking? In #928 we discovered that a long-lived write operation will block a simultaneous readdir operation.

<!-- gh-comment-id:459929560 --> @gaul commented on GitHub (Feb 2, 2019): Do you know which operations are failing or blocking? In #928 we discovered that a long-lived write operation will block a simultaneous readdir operation.
Author
Owner

@dland512 commented on GitHub (Feb 2, 2019):

Unfortunately, I don't know the specific ftp commands the client was issuing. It seemed like the file was being received then it just disappeared. I would see things like this in the logs:

Aug 17 09:01:19 internal-sftp[16260]: session opened for local user someuser from [111.222.333.444]
Aug 17 09:01:19 internal-sftp[16260]: received client version 4
Aug 17 09:01:19 internal-sftp[16260]: realpath "."
Aug 17 09:01:19 internal-sftp[16260]: debug1: request 3294: sent names count 1
Aug 17 09:01:19 internal-sftp[16260]: opendir "/somedir"
Aug 17 09:01:19 internal-sftp[16260]: debug1: request 1110: sent handle handle 0
Aug 17 09:01:19 internal-sftp[16260]: debug1: request 3021: readdir "/somedir" (handle 0)
Aug 17 09:01:19 internal-sftp[16260]: debug1: request 3021: sent names count 3
Aug 17 09:01:19 internal-sftp[16260]: debug1: request 3021: readdir "/somedir" (handle 0)
Aug 17 09:01:19 internal-sftp[16260]: sent status End of file
Aug 17 09:01:20 internal-sftp[16260]: closedir "/somedir"
Aug 17 09:01:20 internal-sftp[16260]: sent status Success
Aug 17 09:01:20 internal-sftp[16260]: open "/somedir/somefile.zip" flags WRITE,CREATE,TRUNCATE mode 0666
Aug 17 09:01:20 internal-sftp[16260]: debug1: request 1383: sent handle handle 0
Aug 17 09:01:20 internal-sftp[16260]: debug1: request 1234: write "/somedir/somefile.zip" (handle 0) off 0 len 32739
Aug 17 09:01:20 internal-sftp[16260]: sent status Success
Aug 17 09:01:20 internal-sftp[16260]: debug1: request 1234: write "/somedir/somefile.zip" (handle 0) off 32739 len 32739
Aug 17 09:01:20 internal-sftp[16260]: sent status Success
(more lines...)
Aug 17 09:01:54 internal-sftp[16260]: debug1: request 1234: write "/somedir/somefile.zip" (handle 0) off 27238848 len 10072
Aug 17 09:01:55 internal-sftp[16260]: sent status Success
Aug 17 09:01:55 internal-sftp[16260]: close "/somedir/somefile.zip" bytes read 0 written 27248920
Aug 17 09:01:55 internal-sftp[16260]: sent status No such file
Aug 17 09:01:55 internal-sftp[16260]: debug1: read eof
Aug 17 09:01:55 internal-sftp[16260]: session closed for local user someuser from [111.222.333.444]

You can see it uploads a file of 27248920 byes then shortly after that says sent status No such file. So I think it's possible that this could be caused by #928, unfortunately, I was never able to reproduce the issue on my own. It's something about that specific sftp client combined with the s3fs fuse.

<!-- gh-comment-id:459937449 --> @dland512 commented on GitHub (Feb 2, 2019): Unfortunately, I don't know the specific ftp commands the client was issuing. It seemed like the file was being received then it just disappeared. I would see things like this in the logs: ``` Aug 17 09:01:19 internal-sftp[16260]: session opened for local user someuser from [111.222.333.444] Aug 17 09:01:19 internal-sftp[16260]: received client version 4 Aug 17 09:01:19 internal-sftp[16260]: realpath "." Aug 17 09:01:19 internal-sftp[16260]: debug1: request 3294: sent names count 1 Aug 17 09:01:19 internal-sftp[16260]: opendir "/somedir" Aug 17 09:01:19 internal-sftp[16260]: debug1: request 1110: sent handle handle 0 Aug 17 09:01:19 internal-sftp[16260]: debug1: request 3021: readdir "/somedir" (handle 0) Aug 17 09:01:19 internal-sftp[16260]: debug1: request 3021: sent names count 3 Aug 17 09:01:19 internal-sftp[16260]: debug1: request 3021: readdir "/somedir" (handle 0) Aug 17 09:01:19 internal-sftp[16260]: sent status End of file Aug 17 09:01:20 internal-sftp[16260]: closedir "/somedir" Aug 17 09:01:20 internal-sftp[16260]: sent status Success Aug 17 09:01:20 internal-sftp[16260]: open "/somedir/somefile.zip" flags WRITE,CREATE,TRUNCATE mode 0666 Aug 17 09:01:20 internal-sftp[16260]: debug1: request 1383: sent handle handle 0 Aug 17 09:01:20 internal-sftp[16260]: debug1: request 1234: write "/somedir/somefile.zip" (handle 0) off 0 len 32739 Aug 17 09:01:20 internal-sftp[16260]: sent status Success Aug 17 09:01:20 internal-sftp[16260]: debug1: request 1234: write "/somedir/somefile.zip" (handle 0) off 32739 len 32739 Aug 17 09:01:20 internal-sftp[16260]: sent status Success (more lines...) Aug 17 09:01:54 internal-sftp[16260]: debug1: request 1234: write "/somedir/somefile.zip" (handle 0) off 27238848 len 10072 Aug 17 09:01:55 internal-sftp[16260]: sent status Success Aug 17 09:01:55 internal-sftp[16260]: close "/somedir/somefile.zip" bytes read 0 written 27248920 Aug 17 09:01:55 internal-sftp[16260]: sent status No such file Aug 17 09:01:55 internal-sftp[16260]: debug1: read eof Aug 17 09:01:55 internal-sftp[16260]: session closed for local user someuser from [111.222.333.444] ``` You can see it uploads a file of 27248920 byes then shortly after that says `sent status No such file`. So I think it's possible that this could be caused by #928, unfortunately, I was never able to reproduce the issue on my own. It's something about that specific sftp client combined with the s3fs fuse.
Author
Owner

@gaul commented on GitHub (Jul 10, 2019):

@dland512 50d13255e4 should fix this. Could you test with the latest master and report back?

<!-- gh-comment-id:510199005 --> @gaul commented on GitHub (Jul 10, 2019): @dland512 50d13255e4a732a620e7dad294204090d7e37655 should fix this. Could you test with the latest master and report back?
Author
Owner

@gaul commented on GitHub (Feb 3, 2020):

Closing due to inactivity. Please reopen if symptoms persist.

<!-- gh-comment-id:581292897 --> @gaul commented on GitHub (Feb 3, 2020): Closing due to inactivity. Please reopen if symptoms persist.
Sign in to join this conversation.
No milestone
No project
No assignees
1 participant
Notifications
Due date
The due date is invalid or out of range. Please use the format "yyyy-mm-dd".

No due date set.

Dependencies

No dependencies set.

Reference
starred/s3fs-fuse#467
No description provided.