search

kahing / goofys

a high-performance, POSIX-ish Amazon S3 file system written in Go
Apache License 2.0
5.22k stars 523 forks source link

rmdir don't work #289

Open andyzasl opened 6 years ago

andyzasl commented 6 years ago

VERSION: 0.19.0-2e8ba3adb4f58bc0c977e53ab859c145fae3220e

user@hostname /tmp$ ls -la s3 1 total 120 drwxr-xr-x 2 user user 4096 Mar 14 04:42 . drwxrwxrwt 13 root root 106496 Mar 14 04:40 .. drwxr-xr-x 2 user user 4096 Mar 14 04:42 1 drwxr-xr-x 2 user user 4096 Mar 14 04:42 devdb user@hostname /tmp$ rmdir s3/1 rmdir: failed to remove ‘s3/1’: No such file or directory user@hostname /tmp$ rm -rf ./s3/1 1 user@hostname /tmp$ ls -la s3 total 120 drwxr-xr-x 2 user user 4096 Mar 14 04:42 . drwxrwxrwt 13 root root 106496 Mar 14 04:40 .. drwxr-xr-x 2 user user 4096 Mar 14 04:42 1 drwxr-xr-x 2 user user 4096 Mar 14 04:42 devdb

Log: ./goofys --no-implicit-dir --debug_s3 -f --endpoint https://s3-napp-vx.root.devdomain.local:8082 --profile netapp-dev-db dev-backups-db /tmp/s3/ 2018/03/14 04:44:05.241755 s3.DEBUG HEAD https://s3-napp-vx.root.devdomain.local:8082/ssync-dev-backups-db = 403 [] 2018/03/14 04:44:05.242788 s3.DEBUG X-Amz-Request-Id = [403160408] 2018/03/14 04:44:05.243234 s3.DEBUG Date = [Wed, 14 Mar 2018 11:44:05 GMT] 2018/03/14 04:44:05.243992 s3.DEBUG Server = [StorageGRID/11.0.1] 2018/03/14 04:44:05.245818 s3.DEBUG DEBUG: Request s3/HeadObject Details: ---[ REQUEST POST-SIGN ]----------------------------- HEAD /ssync-dev-backups-db/a1bq1ehymmfd1x8i23y8w9wf6tt63cch HTTP/1.1 Host: s3-napp-vx.root.devdomain.local:8082 User-Agent: aws-sdk-go/1.13.12 (go1.9.4; linux; amd64) Authorization: AWS4-HMAC-SHA256 Credential=H97LMSJGL19DHIXWNJW7/20180314/us-east-1/s3/aws4_request, SignedHeaders=host;x-amz-content-sha256;x-amz-date, Signature=31b8752342656ee0f8aab3dc6c7aa0c7c1f04d1f27194f81e52dd67b03ac2637 X-Amz-Content-Sha256: e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855 X-Amz-Date: 20180314T114405Z

2018/03/14 04:44:06.272982 s3.DEBUG DEBUG: Response s3/HeadObject Details: ---[ RESPONSE ]-------------------------------------- HTTP/1.1 404 Not Found Connection: close Connection: KEEP-ALIVE Date: Wed, 14 Mar 2018 11:44:06 GMT Server: StorageGRID/11.0.1 X-Amz-Request-Id: 1756409855

2018/03/14 04:44:06.273041 s3.DEBUG DEBUG: Validate Response s3/HeadObject failed, not retrying, error NotFound: Not Found status code: 404, request id: 1756409855, host id: 2018/03/14 04:44:06.275054 s3.DEBUG DEBUG: Request s3/ListMultipartUploads Details: ---[ REQUEST POST-SIGN ]----------------------------- GET /ssync-dev-backups-db?uploads= HTTP/1.1 Host: s3-napp-vx.root.devdomain.local:8082 User-Agent: aws-sdk-go/1.13.12 (go1.9.4; linux; amd64) Accept-Encoding: identity Authorization: AWS4-HMAC-SHA256 Credential=H97LMSJGL19DHIXWNJW7/20180314/us-east-1/s3/aws4_request, SignedHeaders=host;x-amz-content-sha256;x-amz-date, Signature=ad4595d16e00ec93e32301b2b98cdbf994aaad5e06a6a1a39e53f39c311e48d4 X-Amz-Content-Sha256: e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855 X-Amz-Date: 20180314T114406Z

2018/03/14 04:44:06.276390 main.INFO File system has been successfully mounted. 2018/03/14 04:44:06.483499 s3.DEBUG DEBUG: Response s3/ListMultipartUploads Details: ---[ RESPONSE ]-------------------------------------- HTTP/1.1 200 OK Content-Length: 370 Connection: KEEP-ALIVE Content-Type: application/xml Date: Wed, 14 Mar 2018 11:44:06 GMT Server: StorageGRID/11.0.1 X-Amz-Request-Id: 1756409855

2018/03/14 04:44:06.483641 s3.DEBUG { Bucket: "ssync-dev-backups-db", IsTruncated: false, KeyMarker: "", MaxUploads: 1000, NextKeyMarker: "", NextUploadIdMarker: "", UploadIdMarker: "" } 2018/03/14 04:44:14.101666 s3.DEBUG DEBUG: Request s3/ListObjects Details: ---[ REQUEST POST-SIGN ]----------------------------- GET /ssync-dev-backups-db?delimiter=%2F&prefix= HTTP/1.1 Host: s3-napp-vx.root.devdomain.local:8082 User-Agent: aws-sdk-go/1.13.12 (go1.9.4; linux; amd64) Accept-Encoding: identity Authorization: AWS4-HMAC-SHA256 Credential=H97LMSJGL19DHIXWNJW7/20180314/us-east-1/s3/aws4_request, SignedHeaders=host;x-amz-content-sha256;x-amz-date, Signature=2104c7e4c91ea1322fcd652e4368acc596394f78b66dd47d8a2e6cf90d5a0f0c X-Amz-Content-Sha256: e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855 X-Amz-Date: 20180314T114414Z

2018/03/14 04:44:14.334232 s3.DEBUG DEBUG: Response s3/ListObjects Details: ---[ RESPONSE ]-------------------------------------- HTTP/1.1 200 OK Content-Length: 380 Connection: KEEP-ALIVE Content-Type: application/xml Date: Wed, 14 Mar 2018 11:44:14 GMT Server: StorageGRID/11.0.1 X-Amz-Request-Id: 1756409855

2018/03/14 04:44:14.334630 s3.DEBUG { CommonPrefixes: [{ Prefix: "1/" },{ Prefix: "devfmdb/" }], Delimiter: "/", IsTruncated: false, Marker: "", MaxKeys: 1000, Name: "ssync-dev-backups-db", Prefix: "" } 2018/03/14 04:44:18.807881 s3.DEBUG DEBUG: Request s3/ListObjects Details: ---[ REQUEST POST-SIGN ]----------------------------- GET /ssync-dev-backups-db?delimiter=%2F&prefix=1%2F HTTP/1.1 Host: s3-napp-vx.root.devdomain.local:8082 User-Agent: aws-sdk-go/1.13.12 (go1.9.4; linux; amd64) Accept-Encoding: identity Authorization: AWS4-HMAC-SHA256 Credential=H97LMSJGL19DHIXWNJW7/20180314/us-east-1/s3/aws4_request, SignedHeaders=host;x-amz-content-sha256;x-amz-date, Signature=c621edf146ed89ca0b66ce94c428c0ee13d80e7fe37ebe0959f9c3dc53c82938 X-Amz-Content-Sha256: e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855 X-Amz-Date: 20180314T114418Z

2018/03/14 04:44:19.021510 s3.DEBUG DEBUG: Response s3/ListObjects Details: ---[ RESPONSE ]-------------------------------------- HTTP/1.1 200 OK Content-Length: 272 Connection: KEEP-ALIVE Content-Type: application/xml Date: Wed, 14 Mar 2018 11:44:18 GMT Server: StorageGRID/11.0.1 X-Amz-Request-Id: 1756409855

2018/03/14 04:44:19.021650 s3.DEBUG { Delimiter: "/", IsTruncated: false, Marker: "", MaxKeys: 1000, Name: "ssync-dev-backups-db", Prefix: "1/" } 2018/03/14 04:44:19.023333 s3.DEBUG DEBUG: Request s3/ListObjects Details: ---[ REQUEST POST-SIGN ]----------------------------- GET /ssync-dev-backups-db?delimiter=%2F&max-keys=2&prefix=1%2F HTTP/1.1 Host: s3-napp-vx.root.devdomain.local:8082 User-Agent: aws-sdk-go/1.13.12 (go1.9.4; linux; amd64) Accept-Encoding: identity Authorization: AWS4-HMAC-SHA256 Credential=H97LMSJGL19DHIXWNJW7/20180314/us-east-1/s3/aws4_request, SignedHeaders=host;x-amz-content-sha256;x-amz-date, Signature=5424647d317b7b76cea18e21f14ffced9fe97b8af75befaa7f6b8784f700fbb4 X-Amz-Content-Sha256: e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855 X-Amz-Date: 20180314T114419Z

2018/03/14 04:44:19.235192 s3.DEBUG DEBUG: Response s3/ListObjects Details: ---[ RESPONSE ]-------------------------------------- HTTP/1.1 200 OK Content-Length: 269 Connection: KEEP-ALIVE Content-Type: application/xml Date: Wed, 14 Mar 2018 11:44:19 GMT Server: StorageGRID/11.0.1 X-Amz-Request-Id: 1756409855

^C2018/03/14 04:44:23.815777 main.INFO Received interrupt, attempting to unmount... 2018/03/14 04:44:23.840713 main.INFO Successfully exiting. 2018/03/14 04:44:23.841484 main.INFO Successfully unmounted /tmp/s3/ in response to interrupt

kahing commented 6 years ago

could you include the complete log, preferably also with --debug_fuse?

andyzasl commented 6 years ago

It's the same scenario: ./goofys --no-implicit-dir --debug_s3 --debug_fuse -f --endpoint https://s3-napp-vx.root.devdomain.local:8082 --profile netapp-dev-db ssync-dev-backups-db /tmp/s3/ 2018/03/21 07:16:37.901740 s3.DEBUG HEAD https://s3-napp-vx.root.devdomain.local:8082/ssync-dev-backups-db = 403 [] 2018/03/21 07:16:37.902777 s3.DEBUG Server = [StorageGRID/11.0.1] 2018/03/21 07:16:37.903243 s3.DEBUG X-Amz-Request-Id = [61148928] 2018/03/21 07:16:37.903732 s3.DEBUG Date = [Wed, 21 Mar 2018 14:16:38 GMT] 2018/03/21 07:16:37.907167 s3.DEBUG DEBUG: Request s3/HeadObject Details: ---[ REQUEST POST-SIGN ]----------------------------- HEAD /ssync-dev-backups-db/el026azggw7p733qar53k1012eiamqx2 HTTP/1.1 Host: s3-napp-vx.root.devdomain.local:8082 User-Agent: aws-sdk-go/1.13.12 (go1.9.4; linux; amd64) Authorization: AWS4-HMAC-SHA256 Credential=H97LMSJGL19DHIXWNJW7/20180321/us-east-1/s3/aws4_request, SignedHeaders=host;x-amz-content-sha256;x-amz-date, Signature=889b6532df7f6d449232809bb7d569906ae9a8c0eb3f358a4bfe7c118cb8a76e X-Amz-Content-Sha256: e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855 X-Amz-Date: 20180321T141637Z

2018/03/21 07:16:39.021654 s3.DEBUG DEBUG: Response s3/HeadObject Details: ---[ RESPONSE ]-------------------------------------- HTTP/1.1 404 Not Found Connection: close Connection: KEEP-ALIVE Date: Wed, 21 Mar 2018 14:16:39 GMT Server: StorageGRID/11.0.1 X-Amz-Request-Id: 1087412118

2018/03/21 07:16:39.021754 s3.DEBUG DEBUG: Validate Response s3/HeadObject failed, not retrying, error NotFound: Not Found status code: 404, request id: 1087412118, host id: 2018/03/21 07:16:39.022489 s3.DEBUG DEBUG: Request s3/ListMultipartUploads Details: ---[ REQUEST POST-SIGN ]----------------------------- GET /ssync-dev-backups-db?uploads= HTTP/1.1 Host: s3-napp-vx.root.devdomain.local:8082 User-Agent: aws-sdk-go/1.13.12 (go1.9.4; linux; amd64) Accept-Encoding: identity Authorization: AWS4-HMAC-SHA256 Credential=H97LMSJGL19DHIXWNJW7/20180321/us-east-1/s3/aws4_request, SignedHeaders=host;x-amz-content-sha256;x-amz-date, Signature=8fbd0498bf78367b511615c7c1483b49027a1ee01772db4eeada7a438512611c X-Amz-Content-Sha256: e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855 X-Amz-Date: 20180321T141639Z

2018/03/21 07:16:39.048341 fuse.DEBUG Op 0x00000001 connection.go:395] <- init 2018/03/21 07:16:39.048477 fuse.DEBUG Op 0x00000001 connection.go:478] -> OK () 2018/03/21 07:16:39.048512 main.INFO File system has been successfully mounted. 2018/03/21 07:16:39.239206 s3.DEBUG DEBUG: Response s3/ListMultipartUploads Details: ---[ RESPONSE ]-------------------------------------- HTTP/1.1 200 OK Content-Length: 370 Connection: KEEP-ALIVE Content-Type: application/xml Date: Wed, 21 Mar 2018 14:16:40 GMT Server: StorageGRID/11.0.1 X-Amz-Request-Id: 1087412118

2018/03/21 07:16:39.239525 s3.DEBUG { Bucket: "ssync-dev-backups-db", IsTruncated: false, KeyMarker: "", MaxUploads: 1000, NextKeyMarker: "", NextUploadIdMarker: "", UploadIdMarker: "" } 2018/03/21 07:16:57.708187 fuse.DEBUG Op 0x00000002 connection.go:395] <- GetInodeAttributes (inode 1) 2018/03/21 07:16:57.708411 fuse.DEBUG GetAttributes 1 [] 2018/03/21 07:16:57.708451 fuse.DEBUG Op 0x00000002 connection.go:478] -> OK () 2018/03/21 07:16:57.708643 fuse.DEBUG Op 0x00000003 connection.go:395] <- LookUpInode (parent 1, name "1") 2018/03/21 07:16:57.708917 fuse.DEBUG Inode.LookUp 1 [1] 2018/03/21 07:16:57.709285 s3.DEBUG DEBUG: Request s3/HeadObject Details: ---[ REQUEST POST-SIGN ]----------------------------- HEAD /ssync-dev-backups-db/1 HTTP/1.1 Host: s3-napp-vx.root.devdomain.local:8082 User-Agent: aws-sdk-go/1.13.12 (go1.9.4; linux; amd64) Authorization: AWS4-HMAC-SHA256 Credential=H97LMSJGL19DHIXWNJW7/20180321/us-east-1/s3/aws4_request, SignedHeaders=host;x-amz-content-sha256;x-amz-date, Signature=b9a85391c9ff4d7f6a623a01d1ba80e2b6abb6e81055b7bb92e7334200d7081b X-Amz-Content-Sha256: e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855 X-Amz-Date: 20180321T141657Z

2018/03/21 07:16:57.709296 s3.DEBUG DEBUG: Request s3/HeadObject Details: ---[ REQUEST POST-SIGN ]----------------------------- HEAD /ssync-dev-backups-db/1/ HTTP/1.1 Host: s3-napp-vx.root.devdomain.local:8082 User-Agent: aws-sdk-go/1.13.12 (go1.9.4; linux; amd64) Authorization: AWS4-HMAC-SHA256 Credential=H97LMSJGL19DHIXWNJW7/20180321/us-east-1/s3/aws4_request, SignedHeaders=host;x-amz-content-sha256;x-amz-date, Signature=b64928049e32a91e50bb06d8fc50d70fc42809ff0e7ce4f1327d12597fa02b91 X-Amz-Content-Sha256: e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855 X-Amz-Date: 20180321T141657Z

2018/03/21 07:16:57.927954 s3.DEBUG DEBUG: Response s3/HeadObject Details: ---[ RESPONSE ]-------------------------------------- HTTP/1.1 404 Not Found Connection: close Connection: KEEP-ALIVE Date: Wed, 21 Mar 2018 14:16:58 GMT Server: StorageGRID/11.0.1 X-Amz-Request-Id: 1087412118

2018/03/21 07:16:57.928002 s3.DEBUG DEBUG: Validate Response s3/HeadObject failed, not retrying, error NotFound: Not Found status code: 404, request id: 1087412118, host id: 2018/03/21 07:16:57.928026 s3.DEBUG HEAD 1 = no such file or directory 2018/03/21 07:16:58.144358 s3.DEBUG DEBUG: Response s3/HeadObject Details: ---[ RESPONSE ]-------------------------------------- HTTP/1.1 404 Not Found Connection: close Connection: KEEP-ALIVE Date: Wed, 21 Mar 2018 14:16:58 GMT Server: StorageGRID/11.0.1 X-Amz-Request-Id: 1087412118

2018/03/21 07:16:58.144533 s3.DEBUG DEBUG: Validate Response s3/HeadObject failed, not retrying, error NotFound: Not Found status code: 404, request id: 1087412118, host id: 2018/03/21 07:16:58.144590 s3.DEBUG HEAD 1/ = no such file or directory 2018/03/21 07:16:58.144700 fuse.DEBUG <-- LookUpInode 1 1 no such file or directory 2018/03/21 07:16:58.144777 fuse.DEBUG Op 0x00000003 connection.go:480] -> Error: "no such file or directory" 2018/03/21 07:16:58.145510 fuse.DEBUG Op 0x00000004 connection.go:395] <- MkDir (parent 1, name "1") 2018/03/21 07:16:58.146340 fuse.DEBUG MkDir 1 [1] 2018/03/21 07:16:58.147122 s3.DEBUG DEBUG: Request s3/PutObject Details: ---[ REQUEST POST-SIGN ]----------------------------- PUT /ssync-dev-backups-db/1/ HTTP/1.1 Host: s3-napp-vx.root.devdomain.local:8082 User-Agent: aws-sdk-go/1.13.12 (go1.9.4; linux; amd64) Content-Length: 0 Authorization: AWS4-HMAC-SHA256 Credential=H97LMSJGL19DHIXWNJW7/20180321/us-east-1/s3/aws4_request, SignedHeaders=content-md5;host;x-amz-content-sha256;x-amz-date, Signature=a99b0f23781a015b9c64fef2a4546f62ed9749389a2a66954e55055bd4f27f88 Content-Md5: 1B2M2Y8AsgTpgAmY7PhCfg== X-Amz-Content-Sha256: e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855 X-Amz-Date: 20180321T141658Z Accept-Encoding: gzip

2018/03/21 07:16:58.390178 s3.DEBUG DEBUG: Response s3/PutObject Details: ---[ RESPONSE ]-------------------------------------- HTTP/1.1 200 OK Content-Length: 0 Connection: KEEP-ALIVE Date: Wed, 21 Mar 2018 14:16:59 GMT Etag: "d41d8cd98f00b204e9800998ecf8427e" Server: StorageGRID/11.0.1 X-Amz-Request-Id: 1087412118

2018/03/21 07:16:58.390374 fuse.DEBUG Op 0x00000004 connection.go:478] -> OK (inode 2) 2018/03/21 07:17:06.012858 fuse.DEBUG Op 0x00000005 connection.go:395] <- GetInodeAttributes (inode 1) 2018/03/21 07:17:06.013135 fuse.DEBUG GetAttributes 1 [] 2018/03/21 07:17:06.013191 fuse.DEBUG Op 0x00000005 connection.go:478] -> OK () 2018/03/21 07:17:06.013461 fuse.DEBUG Op 0x00000006 connection.go:395] <- GetXattr (inode 1, name "security.selinux", name security.selinux) 2018/03/21 07:17:06.013609 fuse.DEBUG GetXattr 1 [security.selinux] 2018/03/21 07:17:06.013641 fuse.DEBUG Op 0x00000006 connection.go:480] -> Error: "no data available" 2018/03/21 07:17:06.013931 fuse.DEBUG Op 0x00000007 connection.go:395] <- GetXattr (inode 1, name "system.posix_acl_access", name system.posix_acl_access) 2018/03/21 07:17:06.014407 fuse.DEBUG GetXattr 1 [system.posix_acl_access] 2018/03/21 07:17:06.014452 fuse.DEBUG Op 0x00000007 connection.go:480] -> Error: "no data available" 2018/03/21 07:17:06.014617 fuse.DEBUG Op 0x00000008 connection.go:395] <- GetXattr (inode 1, name "system.posix_acl_default", name system.posix_acl_default) 2018/03/21 07:17:06.014727 fuse.DEBUG GetXattr 1 [system.posix_acl_default] 2018/03/21 07:17:06.014786 fuse.DEBUG Op 0x00000008 connection.go:480] -> Error: "no data available" 2018/03/21 07:17:06.015373 fuse.DEBUG Op 0x00000009 connection.go:395] <- OpenDir (inode 1) 2018/03/21 07:17:06.015523 fuse.DEBUG OpenDir 1 [] 2018/03/21 07:17:06.015559 fuse.DEBUG Op 0x00000009 connection.go:478] -> OK () 2018/03/21 07:17:06.015840 fuse.DEBUG Op 0x0000000a connection.go:395] <- ReadDir (inode 1) 2018/03/21 07:17:06.015968 fuse.DEBUG ReadDir 1 [0] 2018/03/21 07:17:06.015986 fuse.DEBUG <-- ReadDir 1 [. 1] 2018/03/21 07:17:06.015997 fuse.DEBUG <-- ReadDir 1 [.. 2] 2018/03/21 07:17:06.016671 s3.DEBUG DEBUG: Request s3/ListObjects Details: ---[ REQUEST POST-SIGN ]----------------------------- GET /ssync-dev-backups-db?delimiter=%2F&prefix= HTTP/1.1 Host: s3-napp-vx.root.devdomain.local:8082 User-Agent: aws-sdk-go/1.13.12 (go1.9.4; linux; amd64) Accept-Encoding: identity Authorization: AWS4-HMAC-SHA256 Credential=H97LMSJGL19DHIXWNJW7/20180321/us-east-1/s3/aws4_request, SignedHeaders=host;x-amz-content-sha256;x-amz-date, Signature=5c80cedab7a47dbea72c9d1b4c26ae1daad210911cbe3ad8182d9f93021ea191 X-Amz-Content-Sha256: e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855 X-Amz-Date: 20180321T141706Z

2018/03/21 07:17:06.277572 s3.DEBUG DEBUG: Response s3/ListObjects Details: ---[ RESPONSE ]-------------------------------------- HTTP/1.1 200 OK Content-Length: 380 Connection: KEEP-ALIVE Content-Type: application/xml Date: Wed, 21 Mar 2018 14:17:07 GMT Server: StorageGRID/11.0.1 X-Amz-Request-Id: 2826272726

2018/03/21 07:17:06.278950 s3.DEBUG { CommonPrefixes: [{ Prefix: "1/" },{ Prefix: "devfmdb/" }], Delimiter: "/", IsTruncated: false, Marker: "", MaxKeys: 1000, Name: "ssync-dev-backups-db", Prefix: "" } 2018/03/21 07:17:06.278990 fuse.DEBUG <-- ReadDir 1 [1 3] 2018/03/21 07:17:06.279000 fuse.DEBUG <-- ReadDir 1 [devfmdb 4] 2018/03/21 07:17:06.279058 fuse.DEBUG Op 0x0000000a connection.go:478] -> OK () 2018/03/21 07:17:06.279303 fuse.DEBUG Op 0x0000000b connection.go:395] <- GetInodeAttributes (inode 1) 2018/03/21 07:17:06.279799 fuse.DEBUG GetAttributes 1 [] 2018/03/21 07:17:06.279854 fuse.DEBUG Op 0x0000000b connection.go:478] -> OK () 2018/03/21 07:17:06.280113 fuse.DEBUG Op 0x0000000c connection.go:395] <- GetXattr (inode 1, name "security.selinux", name security.selinux) 2018/03/21 07:17:06.280487 fuse.DEBUG GetXattr 1 [security.selinux] 2018/03/21 07:17:06.280776 fuse.DEBUG Op 0x0000000c connection.go:480] -> Error: "no data available" 2018/03/21 07:17:06.281287 fuse.DEBUG Op 0x0000000d connection.go:395] <- GetXattr (inode 1, name "system.posix_acl_access", name system.posix_acl_access) 2018/03/21 07:17:06.281482 fuse.DEBUG GetXattr 1 [system.posix_acl_access] 2018/03/21 07:17:06.281504 fuse.DEBUG Op 0x0000000d connection.go:480] -> Error: "no data available" 2018/03/21 07:17:06.281653 fuse.DEBUG Op 0x0000000e connection.go:395] <- GetXattr (inode 1, name "system.posix_acl_default", name system.posix_acl_default) 2018/03/21 07:17:06.282447 fuse.DEBUG GetXattr 1 [system.posix_acl_default] 2018/03/21 07:17:06.282547 fuse.DEBUG Op 0x0000000e connection.go:480] -> Error: "no data available" 2018/03/21 07:17:06.282931 fuse.DEBUG Op 0x0000000f connection.go:395] <- GetXattr (inode 2, name "security.selinux", name security.selinux) 2018/03/21 07:17:06.283116 fuse.DEBUG GetXattr 2 1 [security.selinux] 2018/03/21 07:17:06.283478 fuse.DEBUG Op 0x0000000f connection.go:480] -> Error: "no data available" 2018/03/21 07:17:06.283757 fuse.DEBUG Op 0x00000010 connection.go:395] <- GetXattr (inode 2, name "system.posix_acl_access", name system.posix_acl_access) 2018/03/21 07:17:06.284000 fuse.DEBUG GetXattr 2 1 [system.posix_acl_access] 2018/03/21 07:17:06.284039 fuse.DEBUG Op 0x00000010 connection.go:480] -> Error: "no data available" 2018/03/21 07:17:06.284236 fuse.DEBUG Op 0x00000011 connection.go:395] <- GetXattr (inode 2, name "system.posix_acl_default", name system.posix_acl_default) 2018/03/21 07:17:06.284425 fuse.DEBUG GetXattr 2 1 [system.posix_acl_default] 2018/03/21 07:17:06.284468 fuse.DEBUG Op 0x00000011 connection.go:480] -> Error: "no data available" 2018/03/21 07:17:06.284833 fuse.DEBUG Op 0x00000012 connection.go:395] <- LookUpInode (parent 1, name "devfmdb") 2018/03/21 07:17:06.285074 fuse.DEBUG Ref 6 devfmdb [0] 2018/03/21 07:17:06.285194 fuse.DEBUG <-- LookUpInode 1 devfmdb 2018/03/21 07:17:06.285273 fuse.DEBUG Op 0x00000012 connection.go:478] -> OK (inode 6) 2018/03/21 07:17:06.285632 fuse.DEBUG Op 0x00000013 connection.go:395] <- GetXattr (inode 6, name "security.selinux", name security.selinux) 2018/03/21 07:17:06.285856 fuse.DEBUG GetXattr 6 devfmdb [security.selinux] 2018/03/21 07:17:06.285991 fuse.DEBUG Op 0x00000013 connection.go:480] -> Error: "no data available" 2018/03/21 07:17:06.286270 fuse.DEBUG Op 0x00000014 connection.go:395] <- GetXattr (inode 6, name "system.posix_acl_access", name system.posix_acl_access) 2018/03/21 07:17:06.289659 fuse.DEBUG GetXattr 6 devfmdb [system.posix_acl_access] 2018/03/21 07:17:06.289700 fuse.DEBUG Op 0x00000014 connection.go:480] -> Error: "no data available" 2018/03/21 07:17:06.289889 fuse.DEBUG Op 0x00000015 connection.go:395] <- GetXattr (inode 6, name "system.posix_acl_default", name system.posix_acl_default) 2018/03/21 07:17:06.290201 fuse.DEBUG GetXattr 6 devfmdb [system.posix_acl_default] 2018/03/21 07:17:06.290233 fuse.DEBUG Op 0x00000015 connection.go:480] -> Error: "no data available" 2018/03/21 07:17:06.290432 fuse.DEBUG Op 0x00000016 connection.go:395] <- ReadDir (inode 1) 2018/03/21 07:17:06.292586 fuse.DEBUG ReadDir 1 [4] 2018/03/21 07:17:06.292619 fuse.DEBUG Op 0x00000016 connection.go:478] -> OK () 2018/03/21 07:17:06.292858 fuse.DEBUG Op 0x00000017 connection.go:395] <- ReleaseDirHandle 2018/03/21 07:17:06.293191 fuse.DEBUG ReleaseDirHandle 2018/03/21 07:17:06.293244 fuse.DEBUG Op 0x00000017 connection.go:478] -> OK () 2018/03/21 07:17:10.500684 fuse.DEBUG Op 0x00000018 connection.go:395] <- GetInodeAttributes (inode 1) 2018/03/21 07:17:10.500850 fuse.DEBUG GetAttributes 1 [] 2018/03/21 07:17:10.500914 fuse.DEBUG Op 0x00000018 connection.go:478] -> OK () 2018/03/21 07:17:10.501145 fuse.DEBUG Op 0x00000019 connection.go:395] <- RmDir (parent 1, name "1") 2018/03/21 07:17:10.501291 fuse.DEBUG Rmdir 1 [1] 2018/03/21 07:17:10.501701 s3.DEBUG DEBUG: Request s3/ListObjects Details: ---[ REQUEST POST-SIGN ]----------------------------- GET /ssync-dev-backups-db?delimiter=%2F&max-keys=2&prefix=1%2F HTTP/1.1 Host: s3-napp-vx.root.devdomain.local:8082 User-Agent: aws-sdk-go/1.13.12 (go1.9.4; linux; amd64) Accept-Encoding: identity Authorization: AWS4-HMAC-SHA256 Credential=H97LMSJGL19DHIXWNJW7/20180321/us-east-1/s3/aws4_request, SignedHeaders=host;x-amz-content-sha256;x-amz-date, Signature=dcb5fa6889b217225afa47def6edb50819acce9e15a00fddf9f704354e6ca75d X-Amz-Content-Sha256: e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855 X-Amz-Date: 20180321T141710Z

2018/03/21 07:17:10.718247 s3.DEBUG DEBUG: Response s3/ListObjects Details: ---[ RESPONSE ]-------------------------------------- HTTP/1.1 200 OK Content-Length: 269 Connection: KEEP-ALIVE Content-Type: application/xml Date: Wed, 21 Mar 2018 14:17:11 GMT Server: StorageGRID/11.0.1 X-Amz-Request-Id: 2826272726

2018/03/21 07:17:10.718432 fuse.DEBUG <-- RmDir 1 [1 no such file or directory] 2018/03/21 07:17:10.718514 fuse.DEBUG Op 0x00000019 connection.go:480] -> Error: "no such file or directory" 2018/03/21 07:17:12.444952 fuse.DEBUG Op 0x0000001a connection.go:395] <- GetXattr (inode 1, name "security.selinux", name security.selinux) 2018/03/21 07:17:12.445226 fuse.DEBUG GetXattr 1 [security.selinux] 2018/03/21 07:17:12.445266 fuse.DEBUG Op 0x0000001a connection.go:480] -> Error: "no data available" 2018/03/21 07:17:12.445371 fuse.DEBUG Op 0x0000001b connection.go:395] <- GetXattr (inode 1, name "system.posix_acl_access", name system.posix_acl_access) 2018/03/21 07:17:12.446173 fuse.DEBUG GetXattr 1 [system.posix_acl_access] 2018/03/21 07:17:12.446209 fuse.DEBUG Op 0x0000001b connection.go:480] -> Error: "no data available" 2018/03/21 07:17:12.446253 fuse.DEBUG Op 0x0000001c connection.go:395] <- GetXattr (inode 1, name "system.posix_acl_default", name system.posix_acl_default) 2018/03/21 07:17:12.446343 fuse.DEBUG GetXattr 1 [system.posix_acl_default] 2018/03/21 07:17:12.446379 fuse.DEBUG Op 0x0000001c connection.go:480] -> Error: "no data available" 2018/03/21 07:17:12.446817 fuse.DEBUG Op 0x0000001d connection.go:395] <- OpenDir (inode 1) 2018/03/21 07:17:12.446904 fuse.DEBUG OpenDir 1 [] 2018/03/21 07:17:12.446935 fuse.DEBUG Op 0x0000001d connection.go:478] -> OK () 2018/03/21 07:17:12.447042 fuse.DEBUG Op 0x0000001e connection.go:395] <- ReadDir (inode 1) 2018/03/21 07:17:12.447170 fuse.DEBUG ReadDir 1 [0] 2018/03/21 07:17:12.447246 fuse.DEBUG <-- ReadDir 1 [. 1] 2018/03/21 07:17:12.447269 fuse.DEBUG <-- ReadDir 1 [.. 2] 2018/03/21 07:17:12.447277 fuse.DEBUG <-- ReadDir 1 [1 3] 2018/03/21 07:17:12.447283 fuse.DEBUG <-- ReadDir 1 [devfmdb 4] 2018/03/21 07:17:12.447327 fuse.DEBUG Op 0x0000001e connection.go:478] -> OK () 2018/03/21 07:17:12.447483 fuse.DEBUG Op 0x0000001f connection.go:395] <- GetInodeAttributes (inode 1) 2018/03/21 07:17:12.448042 fuse.DEBUG GetAttributes 1 [] 2018/03/21 07:17:12.448103 fuse.DEBUG Op 0x0000001f connection.go:478] -> OK () 2018/03/21 07:17:12.448163 fuse.DEBUG Op 0x00000020 connection.go:395] <- GetXattr (inode 1, name "security.selinux", name security.selinux) 2018/03/21 07:17:12.448280 fuse.DEBUG GetXattr 1 [security.selinux] 2018/03/21 07:17:12.448314 fuse.DEBUG Op 0x00000020 connection.go:480] -> Error: "no data available" 2018/03/21 07:17:12.448445 fuse.DEBUG Op 0x00000021 connection.go:395] <- GetXattr (inode 1, name "system.posix_acl_access", name system.posix_acl_access) 2018/03/21 07:17:12.448557 fuse.DEBUG GetXattr 1 [system.posix_acl_access] 2018/03/21 07:17:12.448604 fuse.DEBUG Op 0x00000021 connection.go:480] -> Error: "no data available" 2018/03/21 07:17:12.448702 fuse.DEBUG Op 0x00000022 connection.go:395] <- GetXattr (inode 1, name "system.posix_acl_default", name system.posix_acl_default) 2018/03/21 07:17:12.448842 fuse.DEBUG GetXattr 1 [system.posix_acl_default] 2018/03/21 07:17:12.448892 fuse.DEBUG Op 0x00000022 connection.go:480] -> Error: "no data available" 2018/03/21 07:17:12.449055 fuse.DEBUG Op 0x00000023 connection.go:395] <- GetXattr (inode 2, name "security.selinux", name security.selinux) 2018/03/21 07:17:12.449538 fuse.DEBUG GetXattr 2 1 [security.selinux] 2018/03/21 07:17:12.449589 fuse.DEBUG Op 0x00000023 connection.go:480] -> Error: "no data available" 2018/03/21 07:17:12.449665 fuse.DEBUG Op 0x00000024 connection.go:395] <- GetXattr (inode 2, name "system.posix_acl_access", name system.posix_acl_access) 2018/03/21 07:17:12.449793 fuse.DEBUG GetXattr 2 1 [system.posix_acl_access] 2018/03/21 07:17:12.449839 fuse.DEBUG Op 0x00000024 connection.go:480] -> Error: "no data available" 2018/03/21 07:17:12.449878 fuse.DEBUG Op 0x00000025 connection.go:395] <- GetXattr (inode 2, name "system.posix_acl_default", name system.posix_acl_default) 2018/03/21 07:17:12.450056 fuse.DEBUG GetXattr 2 1 [system.posix_acl_default] 2018/03/21 07:17:12.450087 fuse.DEBUG Op 0x00000025 connection.go:480] -> Error: "no data available" 2018/03/21 07:17:12.450173 fuse.DEBUG Op 0x00000026 connection.go:395] <- GetXattr (inode 6, name "security.selinux", name security.selinux) 2018/03/21 07:17:12.450315 fuse.DEBUG GetXattr 6 devfmdb [security.selinux] 2018/03/21 07:17:12.450354 fuse.DEBUG Op 0x00000026 connection.go:480] -> Error: "no data available" 2018/03/21 07:17:12.450476 fuse.DEBUG Op 0x00000027 connection.go:395] <- GetXattr (inode 6, name "system.posix_acl_access", name system.posix_acl_access) 2018/03/21 07:17:12.450641 fuse.DEBUG GetXattr 6 devfmdb [system.posix_acl_access] 2018/03/21 07:17:12.450689 fuse.DEBUG Op 0x00000027 connection.go:480] -> Error: "no data available" 2018/03/21 07:17:12.450786 fuse.DEBUG Op 0x00000028 connection.go:395] <- GetXattr (inode 6, name "system.posix_acl_default", name system.posix_acl_default) 2018/03/21 07:17:12.450946 fuse.DEBUG GetXattr 6 devfmdb [system.posix_acl_default] 2018/03/21 07:17:12.450996 fuse.DEBUG Op 0x00000028 connection.go:480] -> Error: "no data available" 2018/03/21 07:17:12.451051 fuse.DEBUG Op 0x00000029 connection.go:395] <- ReadDir (inode 1) 2018/03/21 07:17:12.451161 fuse.DEBUG ReadDir 1 [4] 2018/03/21 07:17:12.451222 fuse.DEBUG Op 0x00000029 connection.go:478] -> OK () 2018/03/21 07:17:12.451315 fuse.DEBUG Op 0x0000002a connection.go:395] <- ReleaseDirHandle 2018/03/21 07:17:12.451557 fuse.DEBUG ReleaseDirHandle 2018/03/21 07:17:12.451607 fuse.DEBUG Op 0x0000002a connection.go:478] -> OK () ^C2018/03/21 07:17:18.819611 main.INFO Received interrupt, attempting to unmount... 2018/03/21 07:17:18.862809 main.INFO Successfully exiting. 2018/03/21 07:17:18.863148 main.INFO Successfully unmounted /tmp/s3/ in response to interrupt `

lnicola commented 6 years ago

I'm also seeing this. Could it be that the directory itself is included when listing its children?

Jul 24 18:16:17 pcd3266.c-s.ro /usr/bin/goofys[1481]: fuse.DEBUG Rmdir 2 test [foo]
Jul 24 18:16:17 pcd3266.c-s.ro /usr/bin/goofys[1481]: s3.DEBUG DEBUG: Request s3/ListObjects Details:
                                                      ---[ REQUEST POST-SIGN ]-----------------------------
                                                      GET /C02?delimiter=%2F&encoding-type=url&max-keys=2&prefix=test%2Ffoo%2F HTTP/1.1
                                                      Host: eocloud.eu:8080
                                                      User-Agent: aws-sdk-go/1.8.25 (go1.10.3; linux; amd64)
                                                      Accept-Encoding: identity
                                                      Authorization: SNIP
                                                      X-Amz-Content-Sha256: e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855
                                                      X-Amz-Date: 20180724T151617Z

                                                      -----------------------------------------------------
Jul 24 18:16:17 pcd3266.c-s.ro /usr/bin/goofys[1481]: s3.DEBUG DEBUG: Response s3/ListObjects Details:
                                                      ---[ RESPONSE ]--------------------------------------
                                                      HTTP/1.1 200 OK
                                                      Content-Length: 606
                                                      Content-Type: application/xml
                                                      Date: Tue, 24 Jul 2018 15:16:17 GMT
                                                      X-Amz-Request-Id: tx0000000000000017645fb-005b5742c1-292b6f80-default

                                                      -----------------------------------------------------
Jul 24 18:16:17 pcd3266.c-s.ro /usr/bin/goofys[1481]: s3.DEBUG {
                                                        Contents: [{
                                                            ETag: "\"d41d8cd98f00b204e9800998ecf8427e\"",
                                                            Key: "test%2Ffoo%2F",
                                                            LastModified: 2018-07-24 15:08:29.551 +0000 UTC,
                                                            Owner: {
                                                              DisplayName: "cloud_00503 project_with_eo",
                                                              ID: "c4760e89c8d940cd9a6dbfc7b71d6cbc"
                                                            },
                                                            Size: 0,
                                                            StorageClass: "STANDARD"
                                                          }],
                                                        Delimiter: "/",
                                                        EncodingType: "url",
                                                        IsTruncated: false,
                                                        Marker: "",
                                                        MaxKeys: 1,
                                                        Name: "C02",
                                                        Prefix: "test/foo/"
                                                      }
Jul 24 18:16:17 pcd3266.c-s.ro /usr/bin/goofys[1481]: s3.DEBUG DEBUG: Response s3/ListObjects Details:
                                                      ---[ RESPONSE ]--------------------------------------
                                                      HTTP/1.1 200 OK
                                                      Content-Length: 606
                                                      Content-Type: application/xml
                                                      Date: Tue, 24 Jul 2018 15:16:17 GMT
                                                      X-Amz-Request-Id: tx00000000000000280ac4c-005b5742c1-23ef8a30-default

                                                      -----------------------------------------------------
Jul 24 18:16:17 pcd3266.c-s.ro /usr/bin/goofys[1481]: fuse.DEBUG <-- RmDir 2 test [foo directory not empty]
Jul 24 18:16:17 pcd3266.c-s.ro /usr/bin/goofys[1481]: fuse.DEBUG Op 0x00000030        connection.go:480] -> Error: "directory not empty"
SolarisYan commented 4 years ago

@kahing the same to me, after mounted sometimes, with some read fimes, i can't ls the mounted directoy, it says: ls: reading directory '/data/': Permission denied