"./operations.test -test.v -test.timeout 1h0m0s -remote TestShade: -verbose -test.run '^(TestMaxDelete|TestRmdirsNoLeaveRoot)$'" - Starting (try 2/5)
2026/09/19 04:27:30 DEBUG : Creating backend with remote "TestShade:rclone-test-xarazeh1nime"
2026/09/19 04:27:30 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2026/09/19 04:27:30 DEBUG : Creating new ShadeFS backend with drive: cf193d00-c783-4bab-aa7a-fd84b3700d27
2026/09/19 04:27:30 DEBUG : Creating backend with remote "/tmp/rclone476617836"
=== RUN   TestMaxDelete
    run.go:198: Remote "Shade drive cf193d00-c783-4bab-aa7a-fd84b3700d27 path rclone-test-xarazeh1nime", Local "Local file system at /tmp/rclone476617836", Modify Window "876000h0m0s"
2026/09/19 04:27:30 DEBUG : small: multipart upload: starting chunk 0 size 10 offset 0/10
2026/09/19 04:27:32 DEBUG : medium: multipart upload: starting chunk 0 size 60 offset 0/60
2026/09/19 04:27:34 DEBUG : large: multipart upload: starting chunk 0 size 100 offset 0/100
2026/09/19 04:27:36 DEBUG : Waiting for deletions to finish
2026/09/19 04:27:36 ERROR : large: Got fatal error on delete: --max-delete threshold reached
2026/09/19 04:27:36 DEBUG : pacer: low level retry 1/10 (error HTTP error 500 (500 Internal Server Error) returned body: "ENTRY_NOT_FOUND")
2026/09/19 04:27:36 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2026/09/19 04:27:36 DEBUG : pacer: low level retry 1/10 (error HTTP error 500 (500 Internal Server Error) returned body: "ENTRY_NOT_FOUND")
2026/09/19 04:27:36 DEBUG : pacer: Rate limited, increasing sleep to 40ms
2026/09/19 04:27:36 DEBUG : pacer: low level retry 2/10 (error HTTP error 500 (500 Internal Server Error) returned body: "ENTRY_NOT_FOUND")
2026/09/19 04:27:36 DEBUG : pacer: Rate limited, increasing sleep to 80ms
2026/09/19 04:27:36 DEBUG : pacer: low level retry 2/10 (error HTTP error 500 (500 Internal Server Error) returned body: "ENTRY_NOT_FOUND")
2026/09/19 04:27:36 DEBUG : pacer: Rate limited, increasing sleep to 160ms
2026/09/19 04:27:36 DEBUG : pacer: low level retry 3/10 (error HTTP error 500 (500 Internal Server Error) returned body: "ENTRY_NOT_FOUND")
2026/09/19 04:27:36 DEBUG : pacer: Rate limited, increasing sleep to 320ms
2026/09/19 04:27:37 DEBUG : pacer: low level retry 3/10 (error HTTP error 500 (500 Internal Server Error) returned body: "ENTRY_NOT_FOUND")
2026/09/19 04:27:37 DEBUG : pacer: Rate limited, increasing sleep to 640ms
2026/09/19 04:27:37 DEBUG : pacer: low level retry 4/10 (error HTTP error 500 (500 Internal Server Error) returned body: "ENTRY_NOT_FOUND")
2026/09/19 04:27:37 DEBUG : pacer: Rate limited, increasing sleep to 1.28s
2026/09/19 04:27:37 DEBUG : pacer: Reducing sleep to 640ms
2026/09/19 04:27:37 INFO  : medium: Deleted
2026/09/19 04:27:39 DEBUG : pacer: Reducing sleep to 320ms
2026/09/19 04:27:39 INFO  : small: Deleted
2026/09/19 04:27:39 DEBUG : pacer: Reducing sleep to 160ms
2026/09/19 04:27:40 DEBUG : pacer: Reducing sleep to 80ms
2026/09/19 04:27:40 DEBUG : pacer: Reducing sleep to 40ms
2026/09/19 04:27:40 DEBUG : pacer: low level retry 1/10 (error HTTP error 500 (500 Internal Server Error) returned body: "ENTRY_NOT_FOUND")
2026/09/19 04:27:40 DEBUG : pacer: Rate limited, increasing sleep to 80ms
2026/09/19 04:27:40 DEBUG : pacer: low level retry 2/10 (error HTTP error 500 (500 Internal Server Error) returned body: "ENTRY_NOT_FOUND")
2026/09/19 04:27:40 DEBUG : pacer: Rate limited, increasing sleep to 160ms
2026/09/19 04:27:40 DEBUG : pacer: low level retry 3/10 (error HTTP error 500 (500 Internal Server Error) returned body: "ENTRY_NOT_FOUND")
2026/09/19 04:27:40 DEBUG : pacer: Rate limited, increasing sleep to 320ms
2026/09/19 04:27:40 DEBUG : pacer: low level retry 4/10 (error HTTP error 500 (500 Internal Server Error) returned body: "ENTRY_NOT_FOUND")
2026/09/19 04:27:40 DEBUG : pacer: Rate limited, increasing sleep to 640ms
2026/09/19 04:27:41 DEBUG : pacer: low level retry 5/10 (error HTTP error 500 (500 Internal Server Error) returned body: "ENTRY_NOT_FOUND")
2026/09/19 04:27:41 DEBUG : pacer: Rate limited, increasing sleep to 1.28s
2026/09/19 04:27:41 DEBUG : pacer: low level retry 6/10 (error HTTP error 500 (500 Internal Server Error) returned body: "ENTRY_NOT_FOUND")
2026/09/19 04:27:41 DEBUG : pacer: Rate limited, increasing sleep to 2.56s
2026/09/19 04:27:43 DEBUG : pacer: Reducing sleep to 1.28s
2026/09/19 04:27:45 DEBUG : pacer: Reducing sleep to 640ms
2026/09/19 04:27:46 DEBUG : pacer: Reducing sleep to 320ms
--- PASS: TestMaxDelete (16.54s)
=== RUN   TestRmdirsNoLeaveRoot
    run.go:198: Remote "Shade drive cf193d00-c783-4bab-aa7a-fd84b3700d27 path rclone-test-xarazeh1nime", Local "Local file system at /tmp/rclone476617836", Modify Window "876000h0m0s"
2026/09/19 04:27:47 DEBUG : pacer: Reducing sleep to 160ms
2026/09/19 04:27:47 DEBUG : pacer: Reducing sleep to 80ms
2026/09/19 04:27:48 DEBUG : pacer: Reducing sleep to 40ms
2026/09/19 04:27:48 DEBUG : pacer: Reducing sleep to 20ms
2026/09/19 04:27:48 DEBUG : A1/B1/C1/one: multipart upload: starting chunk 0 size 3 offset 0/3
2026/09/19 04:27:48 DEBUG : pacer: Reducing sleep to 10ms
2026/09/19 04:27:49 INFO  : A2: Making directory
2026/09/19 04:27:50 INFO  : A1/B2: Making directory
2026/09/19 04:27:50 INFO  : A1/B2/C2: Making directory
2026/09/19 04:27:50 INFO  : A1/B1/C3: Making directory
2026/09/19 04:27:50 INFO  : A3: Making directory
2026/09/19 04:27:50 INFO  : A3/B3: Making directory
2026/09/19 04:27:50 INFO  : A3/B3/C4: Making directory
2026/09/19 04:27:51 DEBUG : A1/two: multipart upload: starting chunk 0 size 3 offset 0/3
2026/09/19 04:27:53 DEBUG : pacer: low level retry 1/10 (error HTTP error 500 (500 Internal Server Error) returned body: "ENTRY_NOT_FOUND")
2026/09/19 04:27:53 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2026/09/19 04:27:53 DEBUG : pacer: Reducing sleep to 10ms
2026/09/19 04:27:53 DEBUG : removing 1 level 3 directories
2026/09/19 04:27:53 INFO  : A3/B3/C4: Removing directory
2026/09/19 04:27:54 DEBUG : pacer: low level retry 1/10 (error HTTP error 500 (500 Internal Server Error) returned body: "ENTRY_NOT_FOUND")
2026/09/19 04:27:54 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2026/09/19 04:27:54 DEBUG : pacer: Reducing sleep to 10ms
2026/09/19 04:27:54 DEBUG : pacer: low level retry 2/10 (error HTTP error 500 (500 Internal Server Error) returned body: "ENTRY_NOT_FOUND")
2026/09/19 04:27:54 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2026/09/19 04:27:54 DEBUG : pacer: Reducing sleep to 10ms
2026/09/19 04:27:54 DEBUG : pacer: low level retry 3/10 (error HTTP error 500 (500 Internal Server Error) returned body: "ENTRY_NOT_FOUND")
2026/09/19 04:27:54 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2026/09/19 04:27:54 DEBUG : pacer: low level retry 4/10 (error HTTP error 500 (500 Internal Server Error) returned body: "ENTRY_NOT_FOUND")
2026/09/19 04:27:54 DEBUG : pacer: Rate limited, increasing sleep to 40ms
2026/09/19 04:27:55 DEBUG : pacer: low level retry 5/10 (error HTTP error 500 (500 Internal Server Error) returned body: "ENTRY_NOT_FOUND")
2026/09/19 04:27:55 DEBUG : pacer: Rate limited, increasing sleep to 80ms
2026/09/19 04:27:55 DEBUG : pacer: low level retry 6/10 (error HTTP error 500 (500 Internal Server Error) returned body: "ENTRY_NOT_FOUND")
2026/09/19 04:27:55 DEBUG : pacer: Rate limited, increasing sleep to 160ms
2026/09/19 04:27:55 DEBUG : pacer: low level retry 7/10 (error HTTP error 500 (500 Internal Server Error) returned body: "ENTRY_NOT_FOUND")
2026/09/19 04:27:55 DEBUG : pacer: Rate limited, increasing sleep to 320ms
2026/09/19 04:27:55 DEBUG : pacer: low level retry 8/10 (error HTTP error 500 (500 Internal Server Error) returned body: "ENTRY_NOT_FOUND")
2026/09/19 04:27:55 DEBUG : pacer: Rate limited, increasing sleep to 640ms
2026/09/19 04:27:55 DEBUG : pacer: low level retry 9/10 (error HTTP error 500 (500 Internal Server Error) returned body: "ENTRY_NOT_FOUND")
2026/09/19 04:27:55 DEBUG : pacer: Rate limited, increasing sleep to 1.28s
2026/09/19 04:27:56 DEBUG : pacer: low level retry 10/10 (error HTTP error 500 (500 Internal Server Error) returned body: "ENTRY_NOT_FOUND")
2026/09/19 04:27:56 DEBUG : pacer: Rate limited, increasing sleep to 2.56s
2026/09/19 04:27:56 DEBUG : Shade drive cf193d00-c783-4bab-aa7a-fd84b3700d27 path rclone-test-xarazeh1nime: Error from List call: HTTP error 500 (500 Internal Server Error) returned body: "ENTRY_NOT_FOUND"
2026/09/19 04:27:56 ERROR : A3/B3: error listing: directory not found
2026/09/19 04:27:57 DEBUG : pacer: Reducing sleep to 1.28s
2026/09/19 04:28:00 DEBUG : pacer: Reducing sleep to 640ms
2026/09/19 04:28:01 DEBUG : pacer: Reducing sleep to 320ms
2026/09/19 04:28:02 DEBUG : pacer: Reducing sleep to 160ms
2026/09/19 04:28:02 DEBUG : pacer: Reducing sleep to 80ms
2026/09/19 04:28:02 DEBUG : pacer: Reducing sleep to 40ms
2026/09/19 04:28:02 DEBUG : pacer: Reducing sleep to 20ms
2026/09/19 04:28:02 DEBUG : pacer: Reducing sleep to 10ms
2026/09/19 04:28:03 DEBUG : removing 2 level 3 directories
2026/09/19 04:28:03 INFO  : A1/B2/C2: Removing directory
2026/09/19 04:28:03 INFO  : A1/B1/C3: Removing directory
2026/09/19 04:28:03 DEBUG : removing 2 level 2 directories
2026/09/19 04:28:03 INFO  : A3/B3: Removing directory
2026/09/19 04:28:03 INFO  : A1/B2: Removing directory
2026/09/19 04:28:03 DEBUG : pacer: low level retry 1/10 (error HTTP error 500 (500 Internal Server Error) returned body: "ENTRY_NOT_FOUND")
2026/09/19 04:28:03 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2026/09/19 04:28:03 DEBUG : pacer: Reducing sleep to 10ms
2026/09/19 04:28:03 DEBUG : pacer: low level retry 2/10 (error HTTP error 500 (500 Internal Server Error) returned body: "ENTRY_NOT_FOUND")
2026/09/19 04:28:03 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2026/09/19 04:28:03 DEBUG : pacer: low level retry 3/10 (error HTTP error 500 (500 Internal Server Error) returned body: "ENTRY_NOT_FOUND")
2026/09/19 04:28:03 DEBUG : pacer: Rate limited, increasing sleep to 40ms
2026/09/19 04:28:03 DEBUG : pacer: low level retry 4/10 (error HTTP error 500 (500 Internal Server Error) returned body: "ENTRY_NOT_FOUND")
2026/09/19 04:28:03 DEBUG : pacer: Rate limited, increasing sleep to 80ms
2026/09/19 04:28:04 DEBUG : pacer: low level retry 5/10 (error HTTP error 500 (500 Internal Server Error) returned body: "ENTRY_NOT_FOUND")
2026/09/19 04:28:04 DEBUG : pacer: Rate limited, increasing sleep to 160ms
2026/09/19 04:28:04 DEBUG : pacer: low level retry 6/10 (error HTTP error 500 (500 Internal Server Error) returned body: "ENTRY_NOT_FOUND")
2026/09/19 04:28:04 DEBUG : pacer: Rate limited, increasing sleep to 320ms
2026/09/19 04:28:04 DEBUG : pacer: low level retry 7/10 (error HTTP error 500 (500 Internal Server Error) returned body: "ENTRY_NOT_FOUND")
2026/09/19 04:28:04 DEBUG : pacer: Rate limited, increasing sleep to 640ms
2026/09/19 04:28:04 DEBUG : pacer: low level retry 8/10 (error HTTP error 500 (500 Internal Server Error) returned body: "ENTRY_NOT_FOUND")
2026/09/19 04:28:04 DEBUG : pacer: Rate limited, increasing sleep to 1.28s
2026/09/19 04:28:05 DEBUG : pacer: Reducing sleep to 640ms
2026/09/19 04:28:06 DEBUG : pacer: Reducing sleep to 320ms
2026/09/19 04:28:06 DEBUG : removing 2 level 1 directories
2026/09/19 04:28:06 INFO  : A3: Removing directory
2026/09/19 04:28:06 INFO  : A2: Removing directory
2026/09/19 04:28:07 DEBUG : pacer: Reducing sleep to 160ms
2026/09/19 04:28:07 DEBUG : pacer: Reducing sleep to 80ms
2026/09/19 04:28:07 DEBUG : pacer: Reducing sleep to 40ms
2026/09/19 04:28:07 DEBUG : pacer: Reducing sleep to 20ms
2026/09/19 04:28:07 DEBUG : pacer: Reducing sleep to 10ms
2026/09/19 04:28:09 DEBUG : pacer: low level retry 1/10 (error HTTP error 500 (500 Internal Server Error) returned body: "ENTRY_NOT_FOUND")
2026/09/19 04:28:09 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2026/09/19 04:28:09 DEBUG : pacer: low level retry 2/10 (error HTTP error 500 (500 Internal Server Error) returned body: "ENTRY_NOT_FOUND")
2026/09/19 04:28:09 DEBUG : pacer: Rate limited, increasing sleep to 40ms
2026/09/19 04:28:09 DEBUG : pacer: low level retry 3/10 (error HTTP error 500 (500 Internal Server Error) returned body: "ENTRY_NOT_FOUND")
2026/09/19 04:28:09 DEBUG : pacer: Rate limited, increasing sleep to 80ms
2026/09/19 04:28:10 DEBUG : pacer: low level retry 4/10 (error HTTP error 500 (500 Internal Server Error) returned body: "ENTRY_NOT_FOUND")
2026/09/19 04:28:10 DEBUG : pacer: Rate limited, increasing sleep to 160ms
2026/09/19 04:28:10 DEBUG : pacer: low level retry 5/10 (error HTTP error 500 (500 Internal Server Error) returned body: "ENTRY_NOT_FOUND")
2026/09/19 04:28:10 DEBUG : pacer: Rate limited, increasing sleep to 320ms
2026/09/19 04:28:10 DEBUG : pacer: low level retry 6/10 (error HTTP error 500 (500 Internal Server Error) returned body: "ENTRY_NOT_FOUND")
2026/09/19 04:28:10 DEBUG : pacer: Rate limited, increasing sleep to 640ms
2026/09/19 04:28:10 DEBUG : pacer: Reducing sleep to 320ms
2026/09/19 04:28:10 DEBUG : removing 1 level 3 directories
2026/09/19 04:28:10 INFO  : A1/B1/C1: Removing directory
2026/09/19 04:28:11 DEBUG : pacer: Reducing sleep to 160ms
2026/09/19 04:28:11 DEBUG : pacer: Reducing sleep to 80ms
2026/09/19 04:28:11 DEBUG : removing 1 level 2 directories
2026/09/19 04:28:11 INFO  : A1/B1: Removing directory
2026/09/19 04:28:11 DEBUG : pacer: low level retry 1/10 (error HTTP error 500 (500 Internal Server Error) returned body: "ENTRY_NOT_FOUND")
2026/09/19 04:28:11 DEBUG : pacer: Rate limited, increasing sleep to 160ms
2026/09/19 04:28:12 DEBUG : pacer: low level retry 2/10 (error HTTP error 500 (500 Internal Server Error) returned body: "ENTRY_NOT_FOUND")
2026/09/19 04:28:12 DEBUG : pacer: Rate limited, increasing sleep to 320ms
2026/09/19 04:28:12 DEBUG : pacer: low level retry 3/10 (error HTTP error 500 (500 Internal Server Error) returned body: "ENTRY_NOT_FOUND")
2026/09/19 04:28:12 DEBUG : pacer: Rate limited, increasing sleep to 640ms
2026/09/19 04:28:12 DEBUG : pacer: low level retry 4/10 (error HTTP error 500 (500 Internal Server Error) returned body: "ENTRY_NOT_FOUND")
2026/09/19 04:28:12 DEBUG : pacer: Rate limited, increasing sleep to 1.28s
2026/09/19 04:28:13 DEBUG : pacer: low level retry 5/10 (error HTTP error 500 (500 Internal Server Error) returned body: "ENTRY_NOT_FOUND")
2026/09/19 04:28:13 DEBUG : pacer: Rate limited, increasing sleep to 2.56s
2026/09/19 04:28:14 DEBUG : pacer: low level retry 6/10 (error HTTP error 500 (500 Internal Server Error) returned body: "ENTRY_NOT_FOUND")
2026/09/19 04:28:14 DEBUG : pacer: Rate limited, increasing sleep to 5.12s
2026/09/19 04:28:16 DEBUG : pacer: Reducing sleep to 2.56s
2026/09/19 04:28:22 DEBUG : pacer: Reducing sleep to 1.28s
2026/09/19 04:28:22 DEBUG : removing 1 level 1 directories
2026/09/19 04:28:22 INFO  : A1: Removing directory
2026/09/19 04:28:24 DEBUG : pacer: Reducing sleep to 640ms
2026/09/19 04:28:25 DEBUG : pacer: Reducing sleep to 320ms
2026/09/19 04:28:25 DEBUG : removing 1 level 0 directories
2026/09/19 04:28:25 INFO  : Shade drive cf193d00-c783-4bab-aa7a-fd84b3700d27 path rclone-test-xarazeh1nime: Removing directory
2026/09/19 04:28:26 DEBUG : pacer: low level retry 1/10 (error HTTP error 500 (500 Internal Server Error) returned body: "ENTRY_NOT_FOUND")
2026/09/19 04:28:26 DEBUG : pacer: Rate limited, increasing sleep to 640ms
2026/09/19 04:28:26 DEBUG : pacer: low level retry 2/10 (error HTTP error 500 (500 Internal Server Error) returned body: "ENTRY_NOT_FOUND")
2026/09/19 04:28:26 DEBUG : pacer: Rate limited, increasing sleep to 1.28s
2026/09/19 04:28:27 DEBUG : pacer: low level retry 3/10 (error HTTP error 500 (500 Internal Server Error) returned body: "ENTRY_NOT_FOUND")
2026/09/19 04:28:27 DEBUG : pacer: Rate limited, increasing sleep to 2.56s
2026/09/19 04:28:28 DEBUG : pacer: Reducing sleep to 1.28s
2026/09/19 04:28:31 DEBUG : pacer: Reducing sleep to 640ms
2026/09/19 04:28:32 DEBUG : pacer: Reducing sleep to 320ms
2026/09/19 04:28:32 DEBUG : Shade drive cf193d00-c783-4bab-aa7a-fd84b3700d27 path rclone-test-xarazeh1nime: Error from List call: HTTP error 404 (404 Not Found) returned body: "ENTRY_NOT_FOUND"
2026/09/19 04:28:32 ERROR : error listing: directory not found
2026/09/19 04:28:33 DEBUG : pacer: Reducing sleep to 160ms
2026/09/19 04:28:33 DEBUG : Shade drive cf193d00-c783-4bab-aa7a-fd84b3700d27 path rclone-test-xarazeh1nime: Error from List call: HTTP error 404 (404 Not Found) returned body: "ENTRY_NOT_FOUND"
2026/09/19 04:28:33 ERROR : error listing: directory not found
--- PASS: TestRmdirsNoLeaveRoot (46.38s)
PASS
2026/09/19 04:28:33 DEBUG : pacer: Reducing sleep to 80ms
2026/09/19 04:28:33 DEBUG : Shade drive cf193d00-c783-4bab-aa7a-fd84b3700d27 path rclone-test-xarazeh1nime: Error from List call: HTTP error 404 (404 Not Found) returned body: "ENTRY_NOT_FOUND"
2026/09/19 04:28:33 ERROR : error listing: directory not found
2026/09/19 04:28:33 DEBUG : Shade drive cf193d00-c783-4bab-aa7a-fd84b3700d27 path rclone-test-xarazeh1nime: Purge dir ""
2026/09/19 04:28:33 DEBUG : pacer: Reducing sleep to 40ms
2026/09/19 04:28:33 NOTICE: purge failed to rmdir "": HTTP error 404 (404 Not Found) returned body: "ENTRY_NOT_FOUND"
2026/09/19 04:28:33 NOTICE: purge failed: directory not found
"./operations.test -test.v -test.timeout 1h0m0s -remote TestShade: -verbose -test.run '^(TestMaxDelete|TestRmdirsNoLeaveRoot)$'" - Finished OK in 1m3.637301617s (try 2/5)