[GH-ISSUE #1245] Increased “Transport endpoint is not connected” rate with 1.86 #665

Closed
opened 2026-03-04 01:47:40 +03:00 by kerem · 17 comments
Owner

Originally created by @acdha on GitHub (Feb 14, 2020).
Original GitHub issue: https://github.com/s3fs-fuse/s3fs-fuse/issues/1245

Additional Information

I've noticed what appears to be an increased rate of “transport endpoint is not connected” errors with 1.86, although that could be a coincidence due to load — this has been a long-running problem which I was hoping 1.86 would improve.

Version of s3fs being used (s3fs --version)

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

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

2.9.7-1ubuntu1

Kernel information (uname -r)

4.15.0-1058-aws

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

NAME="Ubuntu"
VERSION="18.04.4 LTS (Bionic Beaver)"
ID=ubuntu
ID_LIKE=debian
PRETTY_NAME="Ubuntu 18.04.4 LTS"
VERSION_ID="18.04"
HOME_URL="https://www.ubuntu.com/"
SUPPORT_URL="https://help.ubuntu.com/"
BUG_REPORT_URL="https://bugs.launchpad.net/ubuntu/"
PRIVACY_POLICY_URL="https://www.ubuntu.com/legal/terms-and-policies/privacy-policy"
VERSION_CODENAME=bionic
UBUNTU_CODENAME=bionic

/etc/fstab entry, if applicable

s3fs#bucket /srv/bucket fuse _netdev,umask=0022,uid=5000,gid=5000,noexec,nosuid,nodev,noatime,allow_other,nonempty,ensure_diskfree=1024,retries=8,max_stat_cache_size=1500000,multireq_max=500,parallel_count=40,dbglevel=warning,use_cache=/var/cache/bucket 0 0

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

Feb 14 14:01:04 ip-172-31-37-246 s3fs[1903]: curl.cpp:RequestPerform(2459): HTTP response code 500, returning EIO. Body Text:
Feb 14 14:04:09 ip-172-31-37-246 s3fs[13075]: curl.cpp:RequestPerform(2459): HTTP response code 500, returning EIO. Body Text: <?xml version="1.0" encoding="UTF-8"?>#012<Error><Code>InternalError</Code><Message>We encountered an internal error. Please try again.</Message><RequestId>46F50FB3676B4F34</RequestId><HostId>sd7O+cTT9mEUli9wMoeHvQKPFTN2SOYGCd2QtHvWA3tvtT4MZ4vFF3qzDnQNyRzO/1N6VhYglmY=</HostId></Error>
Feb 14 14:04:09 ip-172-31-37-246 s3fs[13075]: s3fs.cpp:list_bucket(2632): ListBucketRequest returns with error.
Feb 14 14:04:09 ip-172-31-37-246 s3fs[13075]: s3fs.cpp:directory_empty(1178): list_bucket returns error.
Feb 14 14:05:02 ip-172-31-37-246 s3fs[13362]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN]
Feb 14 14:10:01 ip-172-31-37-246 s3fs[13607]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN]
Feb 14 14:15:01 ip-172-31-37-246 s3fs[13887]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN]
Feb 14 14:20:01 ip-172-31-37-246 s3fs[14238]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN]
Feb 14 14:25:01 ip-172-31-37-246 s3fs[14603]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN]
Feb 14 14:30:01 ip-172-31-37-246 s3fs[14837]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN]
Feb 14 14:36:01 ip-172-31-37-246 s3fs[15148]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN]
Feb 14 14:41:01 ip-172-31-37-246 s3fs[15393]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN]
Feb 14 14:41:53 ip-172-31-37-246 s3fs[15395]: curl.cpp:RequestPerform(2459): HTTP response code 500, returning EIO. Body Text:
Feb 14 14:46:02 ip-172-31-37-246 s3fs[15634]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN]
Feb 14 14:51:01 ip-172-31-37-246 s3fs[15794]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN]
Feb 14 14:54:23 ip-172-31-37-246 s3fs[1903]: curl.cpp:RequestPerform(2459): HTTP response code 500, returning EIO. Body Text:
Feb 14 14:56:01 ip-172-31-37-246 s3fs[15944]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN]
Feb 14 14:57:53 ip-172-31-37-246 s3fs[1903]: curl.cpp:RequestPerform(2459): HTTP response code 500, returning EIO. Body Text:
Feb 14 15:00:24 ip-172-31-37-246 s3fs[1903]: curl.cpp:RequestPerform(2459): HTTP response code 500, returning EIO. Body Text:
Feb 14 15:01:01 ip-172-31-37-246 s3fs[16115]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN]
Feb 14 15:06:01 ip-172-31-37-246 s3fs[16405]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN]
Feb 14 15:12:01 ip-172-31-37-246 s3fs[16627]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN]
Feb 14 15:17:01 ip-172-31-37-246 s3fs[16864]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN]
Feb 14 15:22:01 ip-172-31-37-246 s3fs[17259]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN]
Feb 14 15:27:01 ip-172-31-37-246 s3fs[17548]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN]
Feb 14 15:32:01 ip-172-31-37-246 s3fs[17796]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN]
Feb 14 15:37:02 ip-172-31-37-246 s3fs[18023]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN]
Feb 14 15:42:01 ip-172-31-37-246 s3fs[18376]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN]
Feb 14 15:48:01 ip-172-31-37-246 s3fs[18761]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN]
Feb 14 15:53:01 ip-172-31-37-246 s3fs[18998]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN]
Feb 14 15:58:01 ip-172-31-37-246 s3fs[19265]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN]
Feb 14 16:03:01 ip-172-31-37-246 s3fs[19571]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN]
Feb 14 16:08:01 ip-172-31-37-246 s3fs[19893]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN]
Feb 14 16:13:01 ip-172-31-37-246 s3fs[20176]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN]
Feb 14 16:18:01 ip-172-31-37-246 s3fs[20608]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN]
Feb 14 16:24:02 ip-172-31-37-246 s3fs[20915]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN]
Feb 14 16:29:01 ip-172-31-37-246 s3fs[21193]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN]
Feb 14 16:34:01 ip-172-31-37-246 s3fs[21471]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN]
Feb 14 16:39:02 ip-172-31-37-246 s3fs[21658]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN]
Feb 14 16:44:01 ip-172-31-37-246 s3fs[21860]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN]
Feb 14 16:49:01 ip-172-31-37-246 s3fs[22066]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN]
Feb 14 16:54:01 ip-172-31-37-246 s3fs[22332]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN]
Feb 14 17:00:01 ip-172-31-37-246 s3fs[22614]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN]
Feb 14 17:00:17 ip-172-31-37-246 s3fs[22616]: curl.cpp:RequestPerform(2459): HTTP response code 500, returning EIO. Body Text: <?xml version="1.0" encoding="UTF-8"?>#012<Error><Code>InternalError</Code><Message>We encountered an internal error. Please try again.</Message><RequestId>2CA093F657D7857B</RequestId><HostId>Ip1JeLu0N8IcQgXucbo/AJahvWfgLSNioFXx/ARf5inBiac9JE/Yv3iWXSJQieL4J+deqnM8hqc=</HostId></Error>
Feb 14 17:00:17 ip-172-31-37-246 s3fs[22616]: s3fs.cpp:list_bucket(2632): ListBucketRequest returns with error.
Feb 14 17:00:17 ip-172-31-37-246 s3fs[22616]: s3fs.cpp:directory_empty(1178): list_bucket returns error.
Feb 14 17:05:02 ip-172-31-37-246 s3fs[22799]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN]
Feb 14 17:10:01 ip-172-31-37-246 s3fs[23116]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN]
Feb 14 17:15:01 ip-172-31-37-246 s3fs[23450]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN]
Feb 14 17:20:01 ip-172-31-37-246 s3fs[24370]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN]
Feb 14 17:25:02 ip-172-31-37-246 s3fs[24601]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN]
Feb 14 17:30:01 ip-172-31-37-246 s3fs[24912]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN]
Feb 14 17:35:01 ip-172-31-37-246 s3fs[25213]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN]
Feb 14 17:41:01 ip-172-31-37-246 s3fs[32192]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN]
Feb 14 17:46:01 ip-172-31-37-246 s3fs[6549]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN]
Feb 14 17:51:01 ip-172-31-37-246 s3fs[14717]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN]
Feb 14 17:56:01 ip-172-31-37-246 s3fs[20558]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN]
Feb 14 18:01:01 ip-172-31-37-246 s3fs[29951]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN]
Feb 14 18:07:01 ip-172-31-37-246 s3fs[30615]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN]
Feb 14 18:08:43 ip-172-31-37-246 s3fs[1075]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN]
Feb 14 18:08:43 ip-172-31-37-246 s3fs[1071]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN]
Feb 14 18:08:43 ip-172-31-37-246 s3fs[1072]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN]
Feb 14 18:12:01 ip-172-31-37-246 s3fs[17113]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN]
Feb 14 18:17:01 ip-172-31-37-246 s3fs[22766]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN]
Feb 14 18:22:01 ip-172-31-37-246 s3fs[27551]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN]
Feb 14 18:27:01 ip-172-31-37-246 s3fs[13075]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN]
Feb 14 18:32:01 ip-172-31-37-246 s3fs[13673]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN]
Feb 14 18:37:01 ip-172-31-37-246 s3fs[13833]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN]
Feb 14 18:42:01 ip-172-31-37-246 s3fs[14097]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN]
Feb 14 18:47:01 ip-172-31-37-246 s3fs[20378]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN]
Feb 14 18:53:01 ip-172-31-37-246 s3fs[20548]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN]
Feb 14 18:58:02 ip-172-31-37-246 s3fs[20675]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN]
Feb 14 19:03:01 ip-172-31-37-246 s3fs[20955]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN]
Feb 14 19:08:01 ip-172-31-37-246 s3fs[21439]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN]
Feb 14 19:13:02 ip-172-31-37-246 s3fs[21722]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN]
Feb 14 19:18:01 ip-172-31-37-246 s3fs[22168]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN]
Feb 14 19:23:01 ip-172-31-37-246 s3fs[22430]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN]
Feb 14 19:28:02 ip-172-31-37-246 s3fs[22782]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN]
Feb 14 19:33:01 ip-172-31-37-246 s3fs[22994]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN]
Feb 14 19:39:01 ip-172-31-37-246 s3fs[23418]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN]
Feb 14 19:44:01 ip-172-31-37-246 s3fs[23669]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN]
Feb 14 19:49:01 ip-172-31-37-246 s3fs[24098]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN]
Feb 14 19:54:01 ip-172-31-37-246 s3fs[24551]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN]
Feb 14 19:59:01 ip-172-31-37-246 s3fs[24880]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN]
Feb 14 20:04:01 ip-172-31-37-246 s3fs[25150]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN]
Feb 14 20:09:01 ip-172-31-37-246 s3fs[25432]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN]
Feb 14 20:14:01 ip-172-31-37-246 s3fs[25557]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN]
Feb 14 20:19:01 ip-172-31-37-246 s3fs[25836]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN]
Feb 14 20:25:02 ip-172-31-37-246 s3fs[26007]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN]
Feb 14 20:30:01 ip-172-31-37-246 s3fs[26293]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN]
Feb 14 20:35:01 ip-172-31-37-246 s3fs[26498]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN]
Feb 14 20:40:01 ip-172-31-37-246 s3fs[26674]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN]
Feb 14 20:45:02 ip-172-31-37-246 s3fs[26881]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN]
Feb 14 20:50:01 ip-172-31-37-246 s3fs[27128]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN]
Feb 14 20:55:01 ip-172-31-37-246 s3fs[27439]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN]
Feb 14 21:00:01 ip-172-31-37-246 s3fs[27659]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN]
Feb 14 21:05:01 ip-172-31-37-246 s3fs[27874]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN]
Feb 14 21:11:01 ip-172-31-37-246 s3fs[28097]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN]
Feb 14 21:16:01 ip-172-31-37-246 s3fs[28474]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN]
Feb 14 21:21:01 ip-172-31-37-246 s3fs[28656]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN]
Feb 14 21:26:01 ip-172-31-37-246 s3fs[28901]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN]
Feb 14 21:31:01 ip-172-31-37-246 s3fs[29319]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN]
Feb 14 21:36:01 ip-172-31-37-246 s3fs[4015]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN]
Feb 14 21:41:01 ip-172-31-37-246 s3fs[6341]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN]
Feb 14 21:46:01 ip-172-31-37-246 s3fs[6770]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN]
Feb 14 21:51:01 ip-172-31-37-246 s3fs[7349]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN]
Feb 14 21:57:01 ip-172-31-37-246 s3fs[9976]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN]
Feb 14 22:02:01 ip-172-31-37-246 s3fs[10625]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN]
Feb 14 22:07:01 ip-172-31-37-246 s3fs[11092]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN]
Feb 14 22:09:20 ip-172-31-37-246 s3fs[1003]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN]
Feb 14 22:09:20 ip-172-31-37-246 s3fs[1004]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN]
Feb 14 22:09:20 ip-172-31-37-246 s3fs[1005]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN]
Feb 14 22:12:01 ip-172-31-37-246 s3fs[3050]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN]
Feb 14 22:17:01 ip-172-31-37-246 s3fs[3255]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN]
Feb 14 22:22:01 ip-172-31-37-246 s3fs[3582]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN]
Feb 14 22:27:02 ip-172-31-37-246 s3fs[12514]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN]
Feb 14 22:28:23 ip-172-31-37-246 s3fs[12516]: curl.cpp:RequestPerform(2459): HTTP response code 500, returning EIO. Body Text:

Details about issue

I have a cron task which runs every minute to remount dead s3fs mountpoints after s3fs crashes or hangs so the logs are a bit noisy from those new processes starting.

Originally created by @acdha on GitHub (Feb 14, 2020). Original GitHub issue: https://github.com/s3fs-fuse/s3fs-fuse/issues/1245 ### Additional Information I've noticed what appears to be an increased rate of “transport endpoint is not connected” errors with 1.86, although that could be a coincidence due to load — this has been a long-running problem which I was hoping 1.86 would improve. #### Version of s3fs being used (s3fs --version) Amazon Simple Storage Service File System V1.86 (commit:unknown) with OpenSSL #### Version of fuse being used (pkg-config --modversion fuse, rpm -qi fuse, dpkg -s fuse) 2.9.7-1ubuntu1 #### Kernel information (uname -r) 4.15.0-1058-aws #### GNU/Linux Distribution, if applicable (cat /etc/os-release) ``` NAME="Ubuntu" VERSION="18.04.4 LTS (Bionic Beaver)" ID=ubuntu ID_LIKE=debian PRETTY_NAME="Ubuntu 18.04.4 LTS" VERSION_ID="18.04" HOME_URL="https://www.ubuntu.com/" SUPPORT_URL="https://help.ubuntu.com/" BUG_REPORT_URL="https://bugs.launchpad.net/ubuntu/" PRIVACY_POLICY_URL="https://www.ubuntu.com/legal/terms-and-policies/privacy-policy" VERSION_CODENAME=bionic UBUNTU_CODENAME=bionic ``` #### /etc/fstab entry, if applicable ``` s3fs#bucket /srv/bucket fuse _netdev,umask=0022,uid=5000,gid=5000,noexec,nosuid,nodev,noatime,allow_other,nonempty,ensure_diskfree=1024,retries=8,max_stat_cache_size=1500000,multireq_max=500,parallel_count=40,dbglevel=warning,use_cache=/var/cache/bucket 0 0 ``` #### s3fs syslog messages (grep s3fs /var/log/syslog, journalctl | grep s3fs, or s3fs outputs) <details> ``` Feb 14 14:01:04 ip-172-31-37-246 s3fs[1903]: curl.cpp:RequestPerform(2459): HTTP response code 500, returning EIO. Body Text: Feb 14 14:04:09 ip-172-31-37-246 s3fs[13075]: curl.cpp:RequestPerform(2459): HTTP response code 500, returning EIO. Body Text: <?xml version="1.0" encoding="UTF-8"?>#012<Error><Code>InternalError</Code><Message>We encountered an internal error. Please try again.</Message><RequestId>46F50FB3676B4F34</RequestId><HostId>sd7O+cTT9mEUli9wMoeHvQKPFTN2SOYGCd2QtHvWA3tvtT4MZ4vFF3qzDnQNyRzO/1N6VhYglmY=</HostId></Error> Feb 14 14:04:09 ip-172-31-37-246 s3fs[13075]: s3fs.cpp:list_bucket(2632): ListBucketRequest returns with error. Feb 14 14:04:09 ip-172-31-37-246 s3fs[13075]: s3fs.cpp:directory_empty(1178): list_bucket returns error. Feb 14 14:05:02 ip-172-31-37-246 s3fs[13362]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN] Feb 14 14:10:01 ip-172-31-37-246 s3fs[13607]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN] Feb 14 14:15:01 ip-172-31-37-246 s3fs[13887]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN] Feb 14 14:20:01 ip-172-31-37-246 s3fs[14238]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN] Feb 14 14:25:01 ip-172-31-37-246 s3fs[14603]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN] Feb 14 14:30:01 ip-172-31-37-246 s3fs[14837]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN] Feb 14 14:36:01 ip-172-31-37-246 s3fs[15148]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN] Feb 14 14:41:01 ip-172-31-37-246 s3fs[15393]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN] Feb 14 14:41:53 ip-172-31-37-246 s3fs[15395]: curl.cpp:RequestPerform(2459): HTTP response code 500, returning EIO. Body Text: Feb 14 14:46:02 ip-172-31-37-246 s3fs[15634]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN] Feb 14 14:51:01 ip-172-31-37-246 s3fs[15794]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN] Feb 14 14:54:23 ip-172-31-37-246 s3fs[1903]: curl.cpp:RequestPerform(2459): HTTP response code 500, returning EIO. Body Text: Feb 14 14:56:01 ip-172-31-37-246 s3fs[15944]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN] Feb 14 14:57:53 ip-172-31-37-246 s3fs[1903]: curl.cpp:RequestPerform(2459): HTTP response code 500, returning EIO. Body Text: Feb 14 15:00:24 ip-172-31-37-246 s3fs[1903]: curl.cpp:RequestPerform(2459): HTTP response code 500, returning EIO. Body Text: Feb 14 15:01:01 ip-172-31-37-246 s3fs[16115]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN] Feb 14 15:06:01 ip-172-31-37-246 s3fs[16405]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN] Feb 14 15:12:01 ip-172-31-37-246 s3fs[16627]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN] Feb 14 15:17:01 ip-172-31-37-246 s3fs[16864]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN] Feb 14 15:22:01 ip-172-31-37-246 s3fs[17259]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN] Feb 14 15:27:01 ip-172-31-37-246 s3fs[17548]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN] Feb 14 15:32:01 ip-172-31-37-246 s3fs[17796]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN] Feb 14 15:37:02 ip-172-31-37-246 s3fs[18023]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN] Feb 14 15:42:01 ip-172-31-37-246 s3fs[18376]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN] Feb 14 15:48:01 ip-172-31-37-246 s3fs[18761]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN] Feb 14 15:53:01 ip-172-31-37-246 s3fs[18998]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN] Feb 14 15:58:01 ip-172-31-37-246 s3fs[19265]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN] Feb 14 16:03:01 ip-172-31-37-246 s3fs[19571]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN] Feb 14 16:08:01 ip-172-31-37-246 s3fs[19893]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN] Feb 14 16:13:01 ip-172-31-37-246 s3fs[20176]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN] Feb 14 16:18:01 ip-172-31-37-246 s3fs[20608]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN] Feb 14 16:24:02 ip-172-31-37-246 s3fs[20915]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN] Feb 14 16:29:01 ip-172-31-37-246 s3fs[21193]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN] Feb 14 16:34:01 ip-172-31-37-246 s3fs[21471]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN] Feb 14 16:39:02 ip-172-31-37-246 s3fs[21658]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN] Feb 14 16:44:01 ip-172-31-37-246 s3fs[21860]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN] Feb 14 16:49:01 ip-172-31-37-246 s3fs[22066]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN] Feb 14 16:54:01 ip-172-31-37-246 s3fs[22332]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN] Feb 14 17:00:01 ip-172-31-37-246 s3fs[22614]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN] Feb 14 17:00:17 ip-172-31-37-246 s3fs[22616]: curl.cpp:RequestPerform(2459): HTTP response code 500, returning EIO. Body Text: <?xml version="1.0" encoding="UTF-8"?>#012<Error><Code>InternalError</Code><Message>We encountered an internal error. Please try again.</Message><RequestId>2CA093F657D7857B</RequestId><HostId>Ip1JeLu0N8IcQgXucbo/AJahvWfgLSNioFXx/ARf5inBiac9JE/Yv3iWXSJQieL4J+deqnM8hqc=</HostId></Error> Feb 14 17:00:17 ip-172-31-37-246 s3fs[22616]: s3fs.cpp:list_bucket(2632): ListBucketRequest returns with error. Feb 14 17:00:17 ip-172-31-37-246 s3fs[22616]: s3fs.cpp:directory_empty(1178): list_bucket returns error. Feb 14 17:05:02 ip-172-31-37-246 s3fs[22799]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN] Feb 14 17:10:01 ip-172-31-37-246 s3fs[23116]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN] Feb 14 17:15:01 ip-172-31-37-246 s3fs[23450]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN] Feb 14 17:20:01 ip-172-31-37-246 s3fs[24370]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN] Feb 14 17:25:02 ip-172-31-37-246 s3fs[24601]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN] Feb 14 17:30:01 ip-172-31-37-246 s3fs[24912]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN] Feb 14 17:35:01 ip-172-31-37-246 s3fs[25213]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN] Feb 14 17:41:01 ip-172-31-37-246 s3fs[32192]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN] Feb 14 17:46:01 ip-172-31-37-246 s3fs[6549]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN] Feb 14 17:51:01 ip-172-31-37-246 s3fs[14717]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN] Feb 14 17:56:01 ip-172-31-37-246 s3fs[20558]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN] Feb 14 18:01:01 ip-172-31-37-246 s3fs[29951]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN] Feb 14 18:07:01 ip-172-31-37-246 s3fs[30615]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN] Feb 14 18:08:43 ip-172-31-37-246 s3fs[1075]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN] Feb 14 18:08:43 ip-172-31-37-246 s3fs[1071]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN] Feb 14 18:08:43 ip-172-31-37-246 s3fs[1072]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN] Feb 14 18:12:01 ip-172-31-37-246 s3fs[17113]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN] Feb 14 18:17:01 ip-172-31-37-246 s3fs[22766]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN] Feb 14 18:22:01 ip-172-31-37-246 s3fs[27551]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN] Feb 14 18:27:01 ip-172-31-37-246 s3fs[13075]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN] Feb 14 18:32:01 ip-172-31-37-246 s3fs[13673]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN] Feb 14 18:37:01 ip-172-31-37-246 s3fs[13833]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN] Feb 14 18:42:01 ip-172-31-37-246 s3fs[14097]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN] Feb 14 18:47:01 ip-172-31-37-246 s3fs[20378]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN] Feb 14 18:53:01 ip-172-31-37-246 s3fs[20548]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN] Feb 14 18:58:02 ip-172-31-37-246 s3fs[20675]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN] Feb 14 19:03:01 ip-172-31-37-246 s3fs[20955]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN] Feb 14 19:08:01 ip-172-31-37-246 s3fs[21439]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN] Feb 14 19:13:02 ip-172-31-37-246 s3fs[21722]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN] Feb 14 19:18:01 ip-172-31-37-246 s3fs[22168]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN] Feb 14 19:23:01 ip-172-31-37-246 s3fs[22430]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN] Feb 14 19:28:02 ip-172-31-37-246 s3fs[22782]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN] Feb 14 19:33:01 ip-172-31-37-246 s3fs[22994]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN] Feb 14 19:39:01 ip-172-31-37-246 s3fs[23418]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN] Feb 14 19:44:01 ip-172-31-37-246 s3fs[23669]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN] Feb 14 19:49:01 ip-172-31-37-246 s3fs[24098]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN] Feb 14 19:54:01 ip-172-31-37-246 s3fs[24551]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN] Feb 14 19:59:01 ip-172-31-37-246 s3fs[24880]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN] Feb 14 20:04:01 ip-172-31-37-246 s3fs[25150]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN] Feb 14 20:09:01 ip-172-31-37-246 s3fs[25432]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN] Feb 14 20:14:01 ip-172-31-37-246 s3fs[25557]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN] Feb 14 20:19:01 ip-172-31-37-246 s3fs[25836]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN] Feb 14 20:25:02 ip-172-31-37-246 s3fs[26007]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN] Feb 14 20:30:01 ip-172-31-37-246 s3fs[26293]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN] Feb 14 20:35:01 ip-172-31-37-246 s3fs[26498]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN] Feb 14 20:40:01 ip-172-31-37-246 s3fs[26674]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN] Feb 14 20:45:02 ip-172-31-37-246 s3fs[26881]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN] Feb 14 20:50:01 ip-172-31-37-246 s3fs[27128]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN] Feb 14 20:55:01 ip-172-31-37-246 s3fs[27439]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN] Feb 14 21:00:01 ip-172-31-37-246 s3fs[27659]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN] Feb 14 21:05:01 ip-172-31-37-246 s3fs[27874]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN] Feb 14 21:11:01 ip-172-31-37-246 s3fs[28097]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN] Feb 14 21:16:01 ip-172-31-37-246 s3fs[28474]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN] Feb 14 21:21:01 ip-172-31-37-246 s3fs[28656]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN] Feb 14 21:26:01 ip-172-31-37-246 s3fs[28901]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN] Feb 14 21:31:01 ip-172-31-37-246 s3fs[29319]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN] Feb 14 21:36:01 ip-172-31-37-246 s3fs[4015]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN] Feb 14 21:41:01 ip-172-31-37-246 s3fs[6341]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN] Feb 14 21:46:01 ip-172-31-37-246 s3fs[6770]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN] Feb 14 21:51:01 ip-172-31-37-246 s3fs[7349]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN] Feb 14 21:57:01 ip-172-31-37-246 s3fs[9976]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN] Feb 14 22:02:01 ip-172-31-37-246 s3fs[10625]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN] Feb 14 22:07:01 ip-172-31-37-246 s3fs[11092]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN] Feb 14 22:09:20 ip-172-31-37-246 s3fs[1003]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN] Feb 14 22:09:20 ip-172-31-37-246 s3fs[1004]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN] Feb 14 22:09:20 ip-172-31-37-246 s3fs[1005]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN] Feb 14 22:12:01 ip-172-31-37-246 s3fs[3050]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN] Feb 14 22:17:01 ip-172-31-37-246 s3fs[3255]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN] Feb 14 22:22:01 ip-172-31-37-246 s3fs[3582]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN] Feb 14 22:27:02 ip-172-31-37-246 s3fs[12514]: s3fs.cpp:set_s3fs_log_level(297): change debug level from [CRT] to [WAN] Feb 14 22:28:23 ip-172-31-37-246 s3fs[12516]: curl.cpp:RequestPerform(2459): HTTP response code 500, returning EIO. Body Text: ``` </details> ### Details about issue I have a cron task which runs every minute to remount dead s3fs mountpoints after s3fs crashes or hangs so the logs are a bit noisy from those new processes starting.
kerem closed this issue 2026-03-04 01:47:41 +03:00
Author
Owner

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

This is not expected behavior. Can you run again with -f -d and share the logs?

<!-- gh-comment-id:587447983 --> @gaul commented on GitHub (Feb 18, 2020): This is not expected behavior. Can you run again with `-f -d` and share the logs?
Author
Owner

@acdha commented on GitHub (Mar 2, 2020):

This looks like it may be related to #1191 — it's happening many times per day and we definitely use ensure_diskfree.

output from -f -d
[DBG] s3fs.cpp:check_object_access(618): [path=/dlc_laperm_ver01/data/sn83025881/print/1800010301/0003.xml]
[DBG] s3fs.cpp:get_object_attribute(471): [path=/dlc_laperm_ver01/data/sn83025881/print/1800010301/0003.xml]
[INF]       curl.cpp:HeadRequest(3049): [tpath=/dlc_laperm_ver01/data/sn83025881/print/1800010301/0003.xml]
[INF]       curl.cpp:PreHeadRequest(3009): [tpath=/dlc_laperm_ver01/data/sn83025881/print/1800010301/0003.xml][bpath=][save=][sseckeypos=-1]
[INF]       curl.cpp:prepare_url(4703): URL is https://s3.amazonaws.com/bucketname/dlc_laperm_ver01/data/sn83025881/print/1800010301/0003.xml
[INF]       curl.cpp:prepare_url(4736): URL changed is https://bucketname.s3.amazonaws.com/dlc_laperm_ver01/data/sn83025881/print/1800010301/0003.xml
[DBG] curl.cpp:GetHandler(289): Get handler from pool: rest = 30
[DBG] curl.cpp:RequestPerform(2384): connecting to URL https://bucketname.s3.amazonaws.com/dlc_laperm_ver01/data/sn83025881/print/1800010301/0003.xml
[INF]       curl.cpp:insertV4Headers(2753): computing signature [HEAD] [/dlc_laperm_ver01/data/sn83025881/print/1800010301/0003.xml] [] []
[INF]       curl.cpp:url_to_host(99): url is https://s3.amazonaws.com
[INF]       curl.cpp:RequestPerform(2416): HTTP response code 200
[DBG] curl.cpp:ReturnHandler(311): Return handler to pool
[INF]       cache.cpp:AddStat(371): add stat cache entry[path=/dlc_laperm_ver01/data/sn83025881/print/1800010301/0003.xml]
[DBG] cache.cpp:GetStat(295): stat cache hit [path=/dlc_laperm_ver01/data/sn83025881/print/1800010301/0003.xml][time=113567.986464332][hit count=0]
[DBG] s3fs.cpp:get_object_attribute(471): [path=/dlc_laperm_ver01/data/sn83025881/print/1800010301/0003.xml]
[DBG] cache.cpp:GetStat(295): stat cache hit [path=/dlc_laperm_ver01/data/sn83025881/print/1800010301/0003.xml][time=113567.986464332][hit count=1]
[DBG] fdcache.cpp:Open(2537): [path=/dlc_laperm_ver01/data/sn83025881/print/1800010301/0003.xml][size=762529][time=1514241354]
[DBG] fdcache.cpp:Open(1160): [path=/dlc_laperm_ver01/data/sn83025881/print/1800010301/0003.xml][fd=-1][size=762529][time=1514241354]
[DBG] fdcache.cpp:Open(1167): [path=/dlc_laperm_ver01/data/sn83025881/print/1800010301/0003.xml][fd=-1][size=762529][time=1514241354]
[DBG] fdcache.cpp:Open(254): file locked(/dlc_laperm_ver01/data/sn83025881/print/1800010301/0003.xml - /var/cache/s3fs-project-data-batches/.bucketname.stat/dlc_laperm_ver01/data/sn83025881/print/1800010301/0003.xml)
terminate called after throwing an instance of 'std::invalid_argument'
  what():  s3fs_strtoofft
Aborted
<!-- gh-comment-id:593478456 --> @acdha commented on GitHub (Mar 2, 2020): This looks like it may be related to #1191 — it's happening many times per day and we definitely use `ensure_diskfree`. <details> <summary>output from -f -d</summary> ``` [DBG] s3fs.cpp:check_object_access(618): [path=/dlc_laperm_ver01/data/sn83025881/print/1800010301/0003.xml] [DBG] s3fs.cpp:get_object_attribute(471): [path=/dlc_laperm_ver01/data/sn83025881/print/1800010301/0003.xml] [INF] curl.cpp:HeadRequest(3049): [tpath=/dlc_laperm_ver01/data/sn83025881/print/1800010301/0003.xml] [INF] curl.cpp:PreHeadRequest(3009): [tpath=/dlc_laperm_ver01/data/sn83025881/print/1800010301/0003.xml][bpath=][save=][sseckeypos=-1] [INF] curl.cpp:prepare_url(4703): URL is https://s3.amazonaws.com/bucketname/dlc_laperm_ver01/data/sn83025881/print/1800010301/0003.xml [INF] curl.cpp:prepare_url(4736): URL changed is https://bucketname.s3.amazonaws.com/dlc_laperm_ver01/data/sn83025881/print/1800010301/0003.xml [DBG] curl.cpp:GetHandler(289): Get handler from pool: rest = 30 [DBG] curl.cpp:RequestPerform(2384): connecting to URL https://bucketname.s3.amazonaws.com/dlc_laperm_ver01/data/sn83025881/print/1800010301/0003.xml [INF] curl.cpp:insertV4Headers(2753): computing signature [HEAD] [/dlc_laperm_ver01/data/sn83025881/print/1800010301/0003.xml] [] [] [INF] curl.cpp:url_to_host(99): url is https://s3.amazonaws.com [INF] curl.cpp:RequestPerform(2416): HTTP response code 200 [DBG] curl.cpp:ReturnHandler(311): Return handler to pool [INF] cache.cpp:AddStat(371): add stat cache entry[path=/dlc_laperm_ver01/data/sn83025881/print/1800010301/0003.xml] [DBG] cache.cpp:GetStat(295): stat cache hit [path=/dlc_laperm_ver01/data/sn83025881/print/1800010301/0003.xml][time=113567.986464332][hit count=0] [DBG] s3fs.cpp:get_object_attribute(471): [path=/dlc_laperm_ver01/data/sn83025881/print/1800010301/0003.xml] [DBG] cache.cpp:GetStat(295): stat cache hit [path=/dlc_laperm_ver01/data/sn83025881/print/1800010301/0003.xml][time=113567.986464332][hit count=1] [DBG] fdcache.cpp:Open(2537): [path=/dlc_laperm_ver01/data/sn83025881/print/1800010301/0003.xml][size=762529][time=1514241354] [DBG] fdcache.cpp:Open(1160): [path=/dlc_laperm_ver01/data/sn83025881/print/1800010301/0003.xml][fd=-1][size=762529][time=1514241354] [DBG] fdcache.cpp:Open(1167): [path=/dlc_laperm_ver01/data/sn83025881/print/1800010301/0003.xml][fd=-1][size=762529][time=1514241354] [DBG] fdcache.cpp:Open(254): file locked(/dlc_laperm_ver01/data/sn83025881/print/1800010301/0003.xml - /var/cache/s3fs-project-data-batches/.bucketname.stat/dlc_laperm_ver01/data/sn83025881/print/1800010301/0003.xml) terminate called after throwing an instance of 'std::invalid_argument' what(): s3fs_strtoofft Aborted ``` </details>
Author
Owner

@IanTangney commented on GitHub (Mar 10, 2020):

Same issue after upgrading to 1.86, resolved after downgrading to 1.85

s3fs --version
Amazon Simple Storage Service File System V1.86 (commit:unknown) with OpenSSL

This is on a CentOS7 system, with the version of s3fs off of EPEL.

I'm not using ensure_diskfree. Here is the entry in /etc/fstab
s3fs#[bucket_name] /path/to/mount fuse umask=007,uid=[username],gid=[groupname],allow_other,url=[s3_url],use_cache=/mnt/fuse-cache 0 0

The cache filesystem disk utilization never exceeded 75% of its capacity.

I wasn't able to capture the debug logs, because my priority was on resolving the errors.

<!-- gh-comment-id:597319754 --> @IanTangney commented on GitHub (Mar 10, 2020): Same issue after upgrading to 1.86, resolved after downgrading to 1.85 ``` s3fs --version Amazon Simple Storage Service File System V1.86 (commit:unknown) with OpenSSL ``` This is on a CentOS7 system, with the version of s3fs off of EPEL. I'm not using `ensure_diskfree`. Here is the entry in /etc/fstab `s3fs#[bucket_name] /path/to/mount fuse umask=007,uid=[username],gid=[groupname],allow_other,url=[s3_url],use_cache=/mnt/fuse-cache 0 0` The cache filesystem disk utilization never exceeded 75% of its capacity. I wasn't able to capture the debug logs, because my priority was on resolving the errors.
Author
Owner

@woodcoder commented on GitHub (Mar 14, 2020):

Same issue, with some investigation it appears to be a cache .stat file getting corrupted:

018484
0:818484:1:0

I believe that what's happening is that the stat file is being overwritten with a 0 total size, but then not being truncated.

<!-- gh-comment-id:599047227 --> @woodcoder commented on GitHub (Mar 14, 2020): Same issue, with some investigation it appears to be a cache .stat file getting corrupted: ``` 018484 0:818484:1:0 ``` I believe that what's happening is that the stat file is being overwritten with a 0 total size, but then not being truncated.
Author
Owner

@dfslezak commented on GitHub (Mar 14, 2020):

I am having the same problem. While this is solved, which version do you recommend to avoid this problem? Thanks

<!-- gh-comment-id:599066779 --> @dfslezak commented on GitHub (Mar 14, 2020): I am having the same problem. While this is solved, which version do you recommend to avoid this problem? Thanks
Author
Owner

@IanTangney commented on GitHub (Mar 15, 2020):

@dfslezak
I do not experience this issue anywhere near as frequently on 1.85.

<!-- gh-comment-id:599241286 --> @IanTangney commented on GitHub (Mar 15, 2020): @dfslezak I do not experience this issue anywhere near as frequently on 1.85.
Author
Owner

@gaul commented on GitHub (Apr 8, 2020):

Could you test with -o nomixupload? s3fs 1.86 introduced this optimization and it may be the cause of your symptoms.

<!-- gh-comment-id:610913108 --> @gaul commented on GitHub (Apr 8, 2020): Could you test with `-o nomixupload`? s3fs 1.86 introduced this optimization and it may be the cause of your symptoms.
Author
Owner

@acdha commented on GitHub (Apr 8, 2020):

I can test but I would expect to make no difference since the workload where I see frequent failures is read-only.

<!-- gh-comment-id:611093448 --> @acdha commented on GitHub (Apr 8, 2020): I can test but I would expect to make no difference since the workload where I see frequent failures is read-only.
Author
Owner

@acdha commented on GitHub (Apr 8, 2020):

Confirmed, the errors happen with nomixupload mount option as well. Deleting the stat caches seems to help but it still crashes pretty frequently under load.

<!-- gh-comment-id:611185106 --> @acdha commented on GitHub (Apr 8, 2020): Confirmed, the errors happen with `nomixupload` mount option as well. Deleting the stat caches seems to help but it still crashes pretty frequently under load.
Author
Owner

@Morc001 commented on GitHub (Apr 14, 2020):

Maybe this is just repeating the same, maybe not, but what I noticed is that it always hangs after "file locked" when it's not followed by a "file unlocked". I see no error message in syslog. I don't use ensure_diskfree as s3fs has a separate cache partition. I mount with these mount options:
nodev,nosuid,allow_other,_netdev,use_sse,endpoint=eu-central-1,use_cache=/var/lib/s3fs/cache,enable_noobj_cache,max_stat_cache_size=500000

<!-- gh-comment-id:613348876 --> @Morc001 commented on GitHub (Apr 14, 2020): Maybe this is just repeating the same, maybe not, but what I noticed is that it always hangs after "file locked" when it's not followed by a "file unlocked". I see no error message in syslog. I don't use ensure_diskfree as s3fs has a separate cache partition. I mount with these mount options: nodev,nosuid,allow_other,_netdev,use_sse,endpoint=eu-central-1,use_cache=/var/lib/s3fs/cache,enable_noobj_cache,max_stat_cache_size=500000
Author
Owner

@woodcoder commented on GitHub (Apr 14, 2020):

I put together a quick fix/workaround for the corrupted stat files I discovered:
https://github.com/s3fs-fuse/s3fs-fuse/issues/1245#issuecomment-599047227
and this has been running with no issue for me now for over a month.

As I say, I believe the first character of the stat files are being overwritten with a 0 character, but then not truncated so the size on a subsequent read is corrupted. This causes the terminate called after throwing an instance of 'std::invalid_argument' exception in s3fs_strtoofft shown in @acdha's logging.

(I wondered whether this maybe happens when a separate cleanup script deletes a file from the cache?)

The workaround patch simply looks for sizes that start with 0 but still have more characters in the buffer and doesn't try to load from disk. This seems to be working fine.

<!-- gh-comment-id:613377796 --> @woodcoder commented on GitHub (Apr 14, 2020): I put together a quick fix/workaround for the corrupted stat files I discovered: https://github.com/s3fs-fuse/s3fs-fuse/issues/1245#issuecomment-599047227 and this has been running with no issue for me now for over a month. As I say, I believe the first character of the stat files are being overwritten with a 0 character, but then _not_ truncated so the size on a subsequent read is corrupted. This causes the `terminate called after throwing an instance of 'std::invalid_argument'` exception in `s3fs_strtoofft` shown in @acdha's logging. (I wondered whether this maybe happens when a separate cleanup script deletes a file from the cache?) The workaround patch simply looks for sizes that start with 0 but still have more characters in the buffer and doesn't try to load from disk. This seems to be working fine.
Author
Owner

@ggtakec commented on GitHub (Apr 14, 2020):

@woodcoder As you say, the problem seems to have been the failure to truncate the file (stat) that shows the status of the cache file.
I'll upload the patch code immediately and, if the test passes, will merge it into master.
But if you are using s3fs with packages, I don't think this problem can be solved immediately.
Thanks for your kindness.

<!-- gh-comment-id:613482136 --> @ggtakec commented on GitHub (Apr 14, 2020): @woodcoder As you say, the problem seems to have been the failure to truncate the file (stat) that shows the status of the cache file. I'll upload the patch code immediately and, if the test passes, will merge it into master. But if you are using s3fs with packages, I don't think this problem can be solved immediately. Thanks for your kindness.
Author
Owner

@Morc001 commented on GitHub (Apr 14, 2020):

@woodcoder I applied your patch to commit feafb44 but it did not resolve the problem entirely. Although the problem appears less frequently now, but still happens. The commit from today only adds a test, so should not matter.

<!-- gh-comment-id:613599972 --> @Morc001 commented on GitHub (Apr 14, 2020): @woodcoder I applied your patch to commit feafb44 but it did not resolve the problem entirely. Although the problem appears less frequently now, but still happens. The commit from today only adds a test, so should not matter.
Author
Owner

@ggtakec commented on GitHub (Apr 14, 2020):

@Morc001 If you can, please try the code of #1271(not yet merged now).
Thanks in advance for your assistance.

<!-- gh-comment-id:613733240 --> @ggtakec commented on GitHub (Apr 14, 2020): @Morc001 If you can, please try the code of #1271(not yet merged now). Thanks in advance for your assistance.
Author
Owner

@Morc001 commented on GitHub (Apr 16, 2020):

@ggtakec Thanks, that seems to have worked! :) Thanks all for your input!

<!-- gh-comment-id:614745923 --> @Morc001 commented on GitHub (Apr 16, 2020): @ggtakec Thanks, that seems to have worked! :) Thanks all for your input!
Author
Owner

@ggtakec commented on GitHub (Apr 18, 2020):

@Morc001 Thanks for try to use it.

<!-- gh-comment-id:615891293 --> @ggtakec commented on GitHub (Apr 18, 2020): @Morc001 Thanks for try to use it.
Author
Owner

@gaul commented on GitHub (Apr 22, 2020):

Fixed by #1271.

<!-- gh-comment-id:617564498 --> @gaul commented on GitHub (Apr 22, 2020): Fixed by #1271.
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#665
No description provided.