s3fs hangs after successful connection to S3 bucket (ReturnHandler(110): Pool full)

[askol-lurie]

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.
Keep in mind that the commands we provide to retrieve information are oriented to GNU/Linux Distributions, so you could need to use others if you use s3fs on macOS or BSD

Version of s3fs being used (s3fs --version)

1.88

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

2.9.4

Kernel information (uname -r)

4.14.193-113.317.amzn1.x86_64

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

command result:
NAME="Amazon Linux AMI"
VERSION="2018.03"
ID="amzn"
ID_LIKE="rhel fedora"
VERSION_ID="2018.03"
PRETTY_NAME="Amazon Linux AMI 2018.03"
ANSI_COLOR="0;33"
CPE_NAME="cpe:/o:amazon:linux:2018.03:ga"
HOME_URL="http://aws.amazon.com/amazon-linux-ami/"

s3fs command line used, if applicable

sudo /usr/local/bin/s3fs -f -d  -o curldbg  -o dbglevel=info -o use_cache=/tmp -o allow_other -o uid=1001 -o mp_umask=002 -o multireq_max=5 -o url="https://s3-us-east-2.amazonaws.com" -o endpoint="us-east-2" lcbioi-res-2021-s3fs-testing /S3

/etc/fstab entry, if applicable

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

if you execute s3fs with dbglevel, curldbg option, you can get detail debug messages

2021-02-16T19:04:40.514Z [CRT] s3fs_logger.cpp:LowSetLogLevel(202): change debug level from [\
CRT] to [INF]
2021-02-16T19:04:40.514Z [INF]     s3fs.cpp:set_mountpoint_attribute(4014): PROC(uid=0, gid=0\
) - MountPoint(uid=0, gid=0, mode=40777)
2021-02-16T19:04:40.516Z [INF] curl.cpp:InitMimeType(435): Loaded mime information from /etc/\
mime.types
2021-02-16T19:04:40.517Z [INF] s3fs.cpp:s3fs_init(3325): init v1.88(commit:d33f252) with Open\
SSL
2021-02-16T19:04:40.517Z [INF] s3fs.cpp:s3fs_check_service(3441): check services.
2021-02-16T19:04:40.517Z [INF]       curl.cpp:CheckBucket(3363): check a bucket.
2021-02-16T19:04:40.517Z [INF]       curl_util.cpp:prepare_url(250): URL is https://s3-us-eas\
t-2.amazonaws.com/lcbioi-res-2021-s3fs-test/
2021-02-16T19:04:40.517Z [INF]       curl_util.cpp:prepare_url(283): URL changed is https://l\
cbioi-res-2021-s3fs-test.s3-us-east-2.amazonaws.com/
2021-02-16T19:04:40.517Z [INF]       curl.cpp:insertV4Headers(2639): computing signature [GET\
] [/] [] []
2021-02-16T19:04:40.517Z [INF]       curl_util.cpp:url_to_host(327): url is https://s3-us-eas\
t-2.amazonaws.com
2021-02-16T19:04:40.560Z [CURL DBG] *   Trying 52.219.104.120...
2021-02-16T19:04:40.560Z [CURL DBG] * TCP_NODELAY set
2021-02-16T19:04:40.561Z [CURL DBG] * Connected to lcbioi-res-2021-s3fs-test.s3-us-east-2.ama\
zonaws.com (52.219.104.120) port 443 (#0)
2021-02-16T19:04:40.561Z [CURL DBG] * Cipher selection: ALL:!EXPORT:!EXPORT40:!EXPORT56:!aNUL\
L:!LOW:!RC4:@STRENGTH
2021-02-16T19:04:40.567Z [CURL DBG] * successfully set certificate verify locations:
2021-02-16T19:04:40.567Z [CURL DBG] *   CAfile: /etc/pki/tls/certs/ca-bundle.crt
  CApath: none
2021-02-16T19:04:40.567Z [CURL DBG] * TLSv1.2 (OUT), TLS header, Certificate Status (22):
2021-02-16T19:04:40.567Z [CURL DBG] * TLSv1.2 (OUT), TLS handshake, Client hello (1):
2021-02-16T19:04:40.576Z [CURL DBG] * TLSv1.2 (IN), TLS handshake, Server hello (2):
2021-02-16T19:04:40.576Z [CURL DBG] * TLSv1.2 (IN), TLS handshake, Certificate (11):
2021-02-16T19:04:40.577Z [CURL DBG] * TLSv1.2 (IN), TLS handshake, Server key exchange (12):
2021-02-16T19:04:40.578Z [CURL DBG] * TLSv1.2 (IN), TLS handshake, Server finished (14):
2021-02-16T19:04:40.578Z [CURL DBG] * TLSv1.2 (OUT), TLS handshake, Client key exchange (16):
2021-02-16T19:04:40.578Z [CURL DBG] * TLSv1.2 (OUT), TLS change cipher, Change cipher spec (1\
):
2021-02-16T19:04:40.578Z [CURL DBG] * TLSv1.2 (OUT), TLS handshake, Finished (20):
2021-02-16T19:04:40.585Z [CURL DBG] * TLSv1.2 (IN), TLS change cipher, Change cipher spec (1)\
:
2021-02-16T19:04:40.585Z [CURL DBG] * TLSv1.2 (IN), TLS handshake, Finished (20):
2021-02-16T19:04:40.585Z [CURL DBG] * TLSv1.2 (IN), TLS handshake, Finished (20):
2021-02-16T19:04:40.585Z [CURL DBG] * SSL connection using TLSv1.2 / ECDHE-RSA-AES128-GCM-SHA\
256
2021-02-16T19:04:40.585Z [CURL DBG] * Server certificate:
2021-02-16T19:04:40.585Z [CURL DBG] *  subject: C=US; ST=Washington; L=Seattle; O=Amazon.com,\
 Inc.; CN=*.s3.us-east-2.amazonaws.com
2021-02-16T19:04:40.585Z [CURL DBG] *  start date: Jul 24 00:00:00 2020 GMT
2021-02-16T19:04:40.585Z [CURL DBG] *  expire date: May 27 12:00:00 2021 GMT
2021-02-16T19:04:40.585Z [CURL DBG] *  subjectAltName: host "lcbioi-res-2021-s3fs-test.s3-us-\
east-2.amazonaws.com" matched cert's "*.s3-us-east-2.amazonaws.com"
2021-02-16T19:04:40.585Z [CURL DBG] *  issuer: C=US; O=DigiCert Inc; OU=www.digicert.com; CN=\
DigiCert Baltimore CA-2 G2
2021-02-16T19:04:40.585Z [CURL DBG] *  SSL certificate verify ok.
2021-02-16T19:04:40.585Z [CURL DBG] > GET / HTTP/1.1
2021-02-16T19:04:40.585Z [CURL DBG] > Host: lcbioi-res-2021-s3fs-test.s3-us-east-2.amazonaws.\
com
2021-02-16T19:04:40.585Z [CURL DBG] > User-Agent: s3fs/1.88 (commit hash d33f252; OpenSSL)
2021-02-16T19:04:40.585Z [CURL DBG] > Accept: */*
2021-02-16T19:04:40.585Z [CURL DBG] > Authorization: AWS4-HMAC-SHA256 Credential=*******/20210216/us-east-2/s3/aws4_request, SignedHeaders=host;x-amz-content-sha256;x-amz-da\
te, Signature=*****
2021-02-16T19:04:40.585Z [CURL DBG] > x-amz-content-sha256: e3b0c44******f4c8996fb9242\
7ae41e4649b934ca495991b7852b855
2021-02-16T19:04:40.585Z [CURL DBG] > x-amz-date: 20210216T190440Z
2021-02-16T19:04:40.585Z [CURL DBG] >
2021-02-16T19:04:40.648Z [CURL DBG] < HTTP/1.1 200 OK
2021-02-16T19:04:40.648Z [CURL DBG] < x-amz-id-2: AyZPdxl2G8YmaRKFG0MWtoEAPyUcpA4nU45mncsgimU\
oxXR6DQ6xOglaGsinWiSU3TfhpX45D1k=
2021-02-16T19:04:40.648Z [CURL DBG] < x-amz-request-id: 626SPT3K3AWVGH44
2021-02-16T19:04:40.648Z [CURL DBG] < Date: Tue, 16 Feb 2021 19:04:41 GMT
2021-02-16T19:04:40.648Z [CURL DBG] < x-amz-bucket-region: us-east-2
2021-02-16T19:04:40.648Z [CURL DBG] < Content-Type: application/xml
2021-02-16T19:04:40.648Z [CURL DBG] < Transfer-Encoding: chunked
2021-02-16T19:04:40.648Z [CURL DBG] < Server: AmazonS3
2021-02-16T19:04:40.648Z [CURL DBG] <
2021-02-16T19:04:40.650Z [CURL DBG] * Connection #0 to host lcbioi-res-2021-s3fs-test.s3-us-e\
ast-2.amazonaws.com left intact
2021-02-16T19:04:40.650Z [INF]       curl.cpp:RequestPerform(2286): HTTP response code 200
2021-02-16T19:04:40.650Z [INF] curl_handlerpool.cpp:ReturnHandler(110): Pool full: destroy th\
2021-02-16T19:06:01.307Z [INF] s3fs.cpp:s3fs_destroy(3383): destroy

Details about issue

I first tried mounting the S3 using IAM used to create the S3 bucket. That was unsuccessful. I got further by placing the access key information in /etc/passwd-s3fs.

After issuing the command above s3fs gets hung with the curl_handlerpool.cpp:ReturnHandler(110): Pool full: destroy the oldest handler. I do not see any errors up to this point.

My issue seems very similar to: #1518

Thanks for any help.

[johncthomas]

Hanging at the same place, it's been half an hour so far. Will it eventually work?

[ggtakec]

@johncthomas I'm sorry for the late reply.
I found a bug in the part you pointed out. (But I don't think it hangs.)
I will post a PR about it soon.

If you can, please you try it(hangup) with the latest version v1.91 or the code in the master branch?
Thanks in advance for your help.

[johncthomas]

Thanks for getting back. It's hanging in the same place after I compiled from the latest git. I've realised that the S3 bucket and the EC2 instance are not in the same region, so maybe that's it? I've also figured out I don't actually need the fuse now, so don't worry about this on my behalf.

[ggtakec]

@johncthomas Thank you for your quick response.
From your logs, I know that this code has been executed, but I don't know the possibility of hangs after that yet.

If the url or endpoint option is incorrect, s3fs may exit with the logs shown below:

2022-07-06T23:08:43.435Z [DBG] curl_handlerpool.cpp:ReturnHandler(103): Return handler to pool
2022-07-06T23:08:43.435Z [ERR] s3fs.cpp:s3fs_exit_fuseloop(3390): Exiting FUSE event loop due to errors
2022-07-06T23:08:43.438Z [INF] s3fs.cpp:s3fs_destroy(3444): destroy

However, just before that, I should get an error saying that the endpoint is wrong, such as HTTP response code 301(Moved Permanently: also happens when bucket's region is incorrect)....

This log is very similar to your log.(However, it does not hangup and ends normally.)

In your log, s3fs_destroy is being called in the same way, so it seems that the bucket check failed and s3fs is about to exit(but it hanged up).
Could you run s3fs with the correct url/endpoint options and without any error?

[perry-mitchell]

Happening to me, latest master version as of now:

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

Relevant logs:

2023-04-20T12:08:29.841Z [INF] s3fs version 1.91(c4f95f1) : s3fs -f -o passwd_file=/mnt/s3/<snip>.passwd-s3fs -o use_path_request_style -o curldbg -o f2 -o url=https://s3.eu-west-1.amazonaws.com -o endpoint=eu-west-1 <snip> /mnt/s3/<snip>
2023-04-20T12:08:29.842Z [CRT] s3fs_logger.cpp:LowSetLogLevel(239): change debug level from [CRT] to [DBG] 
2023-04-20T12:08:29.842Z [INF]     s3fs.cpp:set_mountpoint_attribute(4403): PROC(uid=0, gid=0) - MountPoint(uid=0, gid=0, mode=40755)
2023-04-20T12:08:29.842Z [DBG] curl.cpp:InitMimeType(407): Try to load mime types from /etc/mime.types file.
2023-04-20T12:08:29.842Z [DBG] curl.cpp:InitMimeType(411): The old mime types are cleared to load new mime types.
2023-04-20T12:08:29.843Z [INF] curl.cpp:InitMimeType(431): Loaded mime information from /etc/mime.types
2023-04-20T12:08:29.843Z [INF] fdcache_stat.cpp:CheckCacheFileStatTopDir(78): The path to cache top dir is empty, thus not need to check permission.
2023-04-20T12:08:29.843Z [INF] threadpoolman.cpp:StopThreads(195): Any threads are running now, then nothing to do.
2023-04-20T12:08:29.843Z [INF]       threadpoolman.cpp:Worker(76): Start worker thread in ThreadPoolMan.
2023-04-20T12:08:29.843Z [INF]       threadpoolman.cpp:Worker(76): Start worker thread in ThreadPoolMan.
2023-04-20T12:08:29.843Z [INF]       threadpoolman.cpp:Worker(76): Start worker thread in ThreadPoolMan.
2023-04-20T12:08:29.843Z [INF]       threadpoolman.cpp:Worker(76): Start worker thread in ThreadPoolMan.
2023-04-20T12:08:29.843Z [INF]       threadpoolman.cpp:Worker(76): Start worker thread in ThreadPoolMan.
2023-04-20T12:08:29.844Z [CRT] s3fs_cred.cpp:VersionS3fsCredential(60): Check why built-in function was called, the external credential library must have VersionS3fsCredential function.
2023-04-20T12:08:29.844Z [INF] s3fs.cpp:s3fs_init(4126): init v1.91(commit:c4f95f1) with OpenSSL, credential-library(built-in)
2023-04-20T12:08:29.844Z [INF] s3fs.cpp:s3fs_check_service(4270): check services.
2023-04-20T12:08:29.844Z [INF]       curl.cpp:CheckBucket(3672): check a bucket.
2023-04-20T12:08:29.844Z [DBG] curl_handlerpool.cpp:GetHandler(79): Get handler from pool: rest = 31
2023-04-20T12:08:29.844Z [INF]       curl_util.cpp:prepare_url(257): URL is https://s3.eu-west-1.amazonaws.com/<snip>/
2023-04-20T12:08:29.844Z [INF]       curl_util.cpp:prepare_url(290): URL changed is https://s3.eu-west-1.amazonaws.com/<snip>/
2023-04-20T12:08:29.844Z [DBG] curl.cpp:RequestPerform(2484): connecting to URL https://s3.eu-west-1.amazonaws.com/<snip>/
2023-04-20T12:08:29.844Z [INF]       curl.cpp:insertV4Headers(2891): computing signature [GET] [/] [] []
2023-04-20T12:08:29.844Z [INF]       curl_util.cpp:url_to_host(334): url is https://s3.eu-west-1.amazonaws.com
2023-04-20T12:08:29.893Z [CURL DBG] *   Trying 52.218.84.90:443...
2023-04-20T12:08:29.968Z [CURL DBG] * Connected to s3.eu-west-1.amazonaws.com (52.218.84.90) port 443 (#0)
2023-04-20T12:08:29.987Z [CURL DBG] * found 387 certificates in /etc/ssl/certs
2023-04-20T12:08:30.133Z [CURL DBG] * SSL connection using TLS1.2 / ECDHE_RSA_AES_128_GCM_SHA256
2023-04-20T12:08:30.134Z [CURL DBG] *      server certificate verification OK
2023-04-20T12:08:30.134Z [CURL DBG] *      server certificate status verification SKIPPED
2023-04-20T12:08:30.134Z [CURL DBG] *      common name: *.s3-eu-west-1.amazonaws.com (matched)
2023-04-20T12:08:30.134Z [CURL DBG] *      server certificate expiration date OK
2023-04-20T12:08:30.134Z [CURL DBG] *      server certificate activation date OK
2023-04-20T12:08:30.134Z [CURL DBG] *      certificate public key: RSA
2023-04-20T12:08:30.134Z [CURL DBG] *      certificate version: #3
2023-04-20T12:08:30.134Z [CURL DBG] *      subject: CN=*.s3-eu-west-1.amazonaws.com
2023-04-20T12:08:30.134Z [CURL DBG] *      start date: Wed, 21 Sep 2022 00:00:00 GMT
2023-04-20T12:08:30.134Z [CURL DBG] *      expire date: Wed, 30 Aug 2023 23:59:59 GMT

Note that this same command works on my local (Ubuntu 22.04), but not in my docker container (Debian 10 slim). Am I missing some software or is there some known compatibility here?

I'm building from source, and connecting both AWS S3 and Scaleway Object Storage. Scaleway works and AWS S3 does not. Super strange.

EDIT: To clarify, it hangs here, after those last logs - and never progresses or exits.

EDIT2: Using similar settings on rclone mounts the bucket fine.. so there's possibly something in my s3fs config or some bug that's causing it to hang. I'd guess the latter as it doesn't seem to time out.

[ggtakec]

@perry-mitchell
It seems to hang up in the communication from inside the docker container to outside.
Could you possible to check the communication route between container and outside network?
And if you have problems with that and need a PROXY setting, you can specify things like the proxy and proxy_cred_file options added in #2075, or use things like the HTTP(S)_PROXY environment variable.
Thanks in advance for your assistance.

[xplosionmind]

I am having the same error here! I cannot see if the connection was successful after the command has completed, and the only way to check is by enabling the debug flag.

[zhao-ji]

Having the same issue here.

[alter]

same ...

[ggtakec]

@xplosionmind @zhao-ji @alter
Is it possible to start s3fs with dbglevel=info (or dbg) and curldbg options and collect logs of the problem in question?
Perhaps those are needed to determine the cause.
Thanks in advance for your assistance.