Whenever I delete a file on my gcsfuse mounted file system, the DeleteObject
command is always followed by an UpdateObject
command, which fails, because the file does not exist anymore. The delete itself succeeds, both locally and on the bucket, so the delete behaves as expected, but I would like to understand why the UpdateObject
command is sent and if this is just expected behaviour or perhaps points to a configuration issue on my side. Here are some setup details and a log extract (Sensitive info redacted with '#' characters):
gcsfuse version: 0.40.0
Mounting command: /usr/bin/gcsfuse --foreground --debug_fuse --debug_fs --debug_gcs --debug_http --debug_mutex --debug_invariants --log-file /home/###/gcsfuse.log ### /home/###/###
Delete Command: rm deltest.txt
Log extract:
{
"name": "root",
"levelname": "DEBUG",
"severity": "DEBUG",
"message": "fuse_debug: Op 0x000037c6 connection.go:416] <- Unlink (parent 26, name \"deltest.txt\", PID 1193)\n",
"timestampSeconds": 1649408345,
"timestampNanos": 564194468
}
{
"name": "root",
"levelname": "DEBUG",
"severity": "DEBUG",
"message": "gcs: Req 0x44: <- DeleteObject(\"deltest.txt\")\n",
"timestampSeconds": 1649408345,
"timestampNanos": 564300578
}
{
"name": "root",
"levelname": "DEBUG",
"severity": "DEBUG",
"message": "http: ========== REQUEST:\nDELETE http://www.googleapis.com:443/storage/v1/b/###/o/deltest.txt HTTP/1.1\r\nHost: www.googleapis.com:443\r\nUser-Agent: gcsfuse/0.40.0 (Go version go1.17.6) \r\nAuthorization: Bearer ###\r\nAccept-Encoding: gzip\r\n\r\n",
"timestampSeconds": 1649408345,
"timestampNanos": 564477178
}
{
"name": "root",
"levelname": "DEBUG",
"severity": "DEBUG",
"message": "http: ========== RESPONSE:\nHTTP/2.0 204 No Content\r\nCache-Control: no-cache, no-store, max-age=0, must-revalidate\r\nContent-Type: application/json\r\nDate: Fri, 08 Apr 2022 08:59:05 GMT\r\nExpires: Mon, 01 Jan 1990 00:00:00 GMT\r\nPragma: no-cache\r\nServer: UploadServer\r\nVary: Origin\r\nVary: X-Origin\r\nX-Guploader-Uploadid: ###\r\n\r\n",
"timestampSeconds": 1649408345,
"timestampNanos": 599754186
}
{
"name": "root",
"levelname": "DEBUG",
"severity": "DEBUG",
"message": "http: ====================\n",
"timestampSeconds": 1649408345,
"timestampNanos": 599813546
}
{
"name": "root",
"levelname": "DEBUG",
"severity": "DEBUG",
"message": "gcs: Req 0x44: -> DeleteObject(\"deltest.txt\") (35.528748ms): OK\n",
"timestampSeconds": 1649408345,
"timestampNanos": 599832746
}
{
"name": "root",
"levelname": "DEBUG",
"severity": "DEBUG",
"message": "debug_fs: Unlink(26, \"deltest.txt\"): <nil>\n",
"timestampSeconds": 1649408345,
"timestampNanos": 599883646
}
{
"name": "root",
"levelname": "DEBUG",
"severity": "DEBUG",
"message": "fuse_debug: Op 0x000037c6 connection.go:498] -> OK ()\n",
"timestampSeconds": 1649408345,
"timestampNanos": 599908336
}
{
"name": "root",
"levelname": "DEBUG",
"severity": "DEBUG",
"message": "fuse_debug: Op 0x000037c8 connection.go:416] <- SetInodeAttributes (inode 35, PID 1193, mtime 2022-04-08 08:58:51.943138607 +0000 UTC)\n",
"timestampSeconds": 1649408345,
"timestampNanos": 599978196
}
{
"name": "root",
"levelname": "DEBUG",
"severity": "DEBUG",
"message": "gcs: Req 0x45: <- UpdateObject(\"deltest.txt\")\n",
"timestampSeconds": 1649408345,
"timestampNanos": 600124196
}
{
"name": "root",
"levelname": "DEBUG",
"severity": "DEBUG",
"message": "http: ========== REQUEST:\nPATCH http://www.googleapis.com:443/storage/v1/b/###/o/deltest.txt?generation=###&ifMetagenerationMatch=1&projection=full HTTP/1.1\r\nHost: www.googleapis.com:443\r\nUser-Agent: gcsfuse/0.40.0 (Go version go1.17.6) \r\nContent-Length: 64\r\nAuthorization: Bearer ###\r\nContent-Type: application/json\r\nAccept-Encoding: gzip\r\n\r\n{\"metadata\":{\"gcsfuse_mtime\":\"2022-04-08T08:58:51.943138607Z\"}}\n",
"timestampSeconds": 1649408345,
"timestampNanos": 600343366
}
{
"name": "root",
"levelname": "DEBUG",
"severity": "DEBUG",
"message": "http: ========== RESPONSE:\nHTTP/2.0 404 Not Found\r\nContent-Length: 383\r\nCache-Control: no-cache, no-store, max-age=0, must-revalidate\r\nContent-Type: application/json; charset=UTF-8\r\nDate: Fri, 08 Apr 2022 08:59:05 GMT\r\nExpires: Mon, 01 Jan 1990 00:00:00 GMT\r\nPragma: no-cache\r\nServer: UploadServer\r\nVary: Origin\r\nVary: X-Origin\r\nX-Guploader-Uploadid: ###\r\n\r\n{\n \"error\": {\n \"code\": 404,\n \"message\": \"No such object:###/deltest.txt\",\n \"errors\": [\n {\n \"message\": \"No such object: ###/deltest.txt\",\n \"domain\": \"global\",\n \"reason\": \"notFound\"\n }\n ]\n }\n}\n",
"timestampSeconds": 1649408345,
"timestampNanos": 618031945
}
{
"name": "root",
"levelname": "DEBUG",
"severity": "DEBUG",
"message": "http: ====================\n",
"timestampSeconds": 1649408345,
"timestampNanos": 618071915
}
{
"name": "root",
"levelname": "DEBUG",
"severity": "DEBUG",
"message": "gcs: Req 0x45: -> UpdateObject(\"deltest.txt\") (18.039079ms): not retrying UpdateObject(\"deltest.txt\"): gcs.NotFoundError: googleapi: Error 404: No such object: ###/deltest.txt, notFound\n",
"timestampSeconds": 1649408345,
"timestampNanos": 618163665
}
{
"name": "root",
"levelname": "DEBUG",
"severity": "DEBUG",
"message": "debug_fs: SetInodeAttributes(35): SetMtime: UpdateObject: not retrying UpdateObject(\"###/deltest.txt\"): gcs.NotFoundError: googleapi: Error 404: No such object: ###/deltest.txt, notFound\n",
"timestampSeconds": 1649408345,
"timestampNanos": 618178515
}
{
"name": "root",
"levelname": "ERROR",
"severity": "ERROR",
"message": "SetInodeAttributes: input/output error, SetMtime: UpdateObject: not retrying UpdateObject(\"###/deltest.txt\"): gcs.NotFoundError: googleapi: Error 404: No such object: ###/deltest.txt, notFound\n",
"timestampSeconds": 1649408345,
"timestampNanos": 618219465
}
{
"name": "root",
"levelname": "DEBUG",
"severity": "DEBUG",
"message": "fuse_debug: Op 0x000037c8 connection.go:500] -> Error: \"input/output error\"\n",
"timestampSeconds": 1649408345,
"timestampNanos": 618257045
}
{
"name": "root",
"levelname": "ERROR",
"severity": "ERROR",
"message": "fuse: *fuseops.SetInodeAttributesOp error: input/output error\n",
"timestampSeconds": 1649408345,
"timestampNanos": 618267145
}