"go test -v -timeout 1h0m0s -remote TestCache: -verbose" - Starting (try 1/5)
2025/05/06 01:17:21 NOTICE: Running with the following params: 
 remote: TestInternalCache
2025/05/06 01:17:21 NOTICE: Temp Upload Dir: /tmp/rclonecache-tmp2951136544
=== RUN   TestInternalListRootAndInnerRemotes
2025/05/06 01:17:21 DEBUG : Using config file from "/home/rclone/.rclone.conf"
    cache_internal_test.go:858: Need remote (TestInternalCache) to exist
--- SKIP: TestInternalListRootAndInnerRemotes (0.01s)
=== RUN   TestInternalObjWrapFsFound
2025/05/06 01:17:21 DEBUG : Using config file from "/home/rclone/.rclone.conf"
    cache_internal_test.go:858: Need remote (TestInternalCache) to exist
--- SKIP: TestInternalObjWrapFsFound (0.00s)
=== RUN   TestInternalObjNotFound
2025/05/06 01:17:21 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2025/05/06 01:17:21 NOTICE: WARNING: Cache backend is deprecated and may be removed in future. Please use VFS instead.
2025/05/06 01:17:21 DEBUG : Creating backend with remote "TestInternalCache-local:/tmp/TestInternalCache-local/tionf1746494241"
2025/05/06 01:17:21 DEBUG : TestInternalCache: wrapped TestInternalCache-local:/tmp/TestInternalCache-local/tionf1746494241 at root tionf1746494241
2025/05/06 01:17:21 INFO  : TestInternalCache: Cache DB path: /home/rclone/.cache/rclone/cache-backend/TestInternalCache.db
2025/05/06 01:17:21 INFO  : TestInternalCache: Cache chunk path: /home/rclone/.cache/rclone/cache-backend/TestInternalCache
2025/05/06 01:17:21 INFO  : TestInternalCache: Chunk Memory: true
2025/05/06 01:17:21 INFO  : TestInternalCache: Chunk Size: 5Mi
2025/05/06 01:17:21 INFO  : TestInternalCache: Chunk Total Size: 10Gi
2025/05/06 01:17:21 INFO  : TestInternalCache: Chunk Clean Interval: 1m0s
2025/05/06 01:17:21 INFO  : TestInternalCache: Workers: 4
2025/05/06 01:17:21 INFO  : TestInternalCache: File Age: 6h0m0s
2025/05/06 01:17:21 DEBUG : Waiting for deletions to finish
2025/05/06 01:17:21 DEBUG : Cache remote TestInternalCache:tionf1746494241: list ''
2025/05/06 01:17:21 DEBUG : : list: error: couldn't open bucket (tionf1746494241)
2025/05/06 01:17:21 ERROR : : error listing: directory not found
2025/05/06 01:17:21 DEBUG : Cache remote TestInternalCache:tionf1746494241: list ''
2025/05/06 01:17:21 DEBUG : : list: error: couldn't open bucket (tionf1746494241)
2025/05/06 01:17:21 ERROR : Cache remote TestInternalCache:tionf1746494241: Failed to list "": directory not found
2025/05/06 01:17:21 DEBUG : removing 1 level 0 directories
2025/05/06 01:17:21 INFO  : Cache remote TestInternalCache:tionf1746494241: Removing directory
2025/05/06 01:17:21 DEBUG : Cache remote TestInternalCache:tionf1746494241: rmdir ''
2025/05/06 01:17:21 ERROR : : Failed to rmdir: stat /tmp/TestInternalCache-local/tionf1746494241: no such file or directory
2025/05/06 01:17:21 DEBUG : Cache remote TestInternalCache:tionf1746494241: mkdir ''
2025/05/06 01:17:21 DEBUG : : mkdir: created dir in source fs
2025/05/06 01:17:21 DEBUG : : mkdir: added to cache
2025/05/06 01:17:21 DEBUG : : cache: expired tionf1746494241
2025/05/06 01:17:21 INFO  : : mkdir: cache expired
2025/05/06 01:17:21 DEBUG : Cache remote TestInternalCache:tionf1746494241: new object '404'
2025/05/06 01:17:21 DEBUG : 404: find: error: couldn't find object (404)
2025/05/06 01:17:21 DEBUG : find failed: not found in either local or remote fs
2025/05/06 01:17:21 DEBUG : Waiting for deletions to finish
2025/05/06 01:17:21 DEBUG : Cache remote TestInternalCache:tionf1746494241: list ''
2025/05/06 01:17:21 DEBUG : : list: cold listing: 2025-05-05 19:17:21.549265092 +0000 UTC
2025/05/06 01:17:21 DEBUG : : list: read 0 from source
2025/05/06 01:17:21 DEBUG : : list: source entries: []
2025/05/06 01:17:21 DEBUG : : list: cached directories: 0
2025/05/06 01:17:21 DEBUG : : list: cached dir: 'tionf1746494241', cache ts: 2025-05-06 01:17:21.551233215 +0000 UTC m=+0.037155988
2025/05/06 01:17:21 DEBUG : Cache remote TestInternalCache:tionf1746494241: list ''
2025/05/06 01:17:21 DEBUG : : list: empty listing
2025/05/06 01:17:21 DEBUG : : list: read 0 from source
2025/05/06 01:17:21 DEBUG : : list: source entries: []
2025/05/06 01:17:21 DEBUG : : list: cached directories: 0
2025/05/06 01:17:21 DEBUG : : list: cached dir: 'tionf1746494241', cache ts: 2025-05-06 01:17:21.552821054 +0000 UTC m=+0.038743837
2025/05/06 01:17:21 DEBUG : removing 1 level 0 directories
2025/05/06 01:17:21 INFO  : Cache remote TestInternalCache:tionf1746494241: Removing directory
2025/05/06 01:17:21 DEBUG : Cache remote TestInternalCache:tionf1746494241: rmdir ''
2025/05/06 01:17:21 DEBUG : : rmdir: removed dir in source fs
2025/05/06 01:17:21 DEBUG : : rmdir: removed from cache
2025/05/06 01:17:21 INFO  : : rmdir: cache expired
2025/05/06 01:17:21 DEBUG : Cache remote TestInternalCache:tionf1746494241: Services stopped
--- PASS: TestInternalObjNotFound (0.03s)
=== RUN   TestInternalCachedWrittenContentMatches
2025/05/06 01:17:21 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2025/05/06 01:17:21 DEBUG : Creating backend with remote "TestInternalCache-local:/tmp/TestInternalCache-local/ticwcm1746494241"
2025/05/06 01:17:21 DEBUG : TestInternalCache: wrapped TestInternalCache-local:/tmp/TestInternalCache-local/ticwcm1746494241 at root ticwcm1746494241
2025/05/06 01:17:21 INFO  : TestInternalCache: Cache DB path: /home/rclone/.cache/rclone/cache-backend/TestInternalCache.db
2025/05/06 01:17:21 INFO  : TestInternalCache: Cache chunk path: /home/rclone/.cache/rclone/cache-backend/TestInternalCache
2025/05/06 01:17:21 INFO  : TestInternalCache: Chunk Memory: true
2025/05/06 01:17:21 INFO  : TestInternalCache: Chunk Size: 5Mi
2025/05/06 01:17:21 INFO  : TestInternalCache: Chunk Total Size: 10Gi
2025/05/06 01:17:21 INFO  : TestInternalCache: Chunk Clean Interval: 1m0s
2025/05/06 01:17:21 INFO  : TestInternalCache: Workers: 4
2025/05/06 01:17:21 INFO  : TestInternalCache: File Age: 6h0m0s
2025/05/06 01:17:21 DEBUG : Waiting for deletions to finish
2025/05/06 01:17:21 DEBUG : Cache remote TestInternalCache:ticwcm1746494241: list ''
2025/05/06 01:17:21 DEBUG : : list: error: couldn't open bucket (ticwcm1746494241)
2025/05/06 01:17:21 ERROR : : error listing: directory not found
2025/05/06 01:17:21 DEBUG : Cache remote TestInternalCache:ticwcm1746494241: list ''
2025/05/06 01:17:21 DEBUG : : list: error: couldn't open bucket (ticwcm1746494241)
2025/05/06 01:17:21 ERROR : Cache remote TestInternalCache:ticwcm1746494241: Failed to list "": directory not found
2025/05/06 01:17:21 DEBUG : removing 1 level 0 directories
2025/05/06 01:17:21 INFO  : Cache remote TestInternalCache:ticwcm1746494241: Removing directory
2025/05/06 01:17:21 DEBUG : Cache remote TestInternalCache:ticwcm1746494241: rmdir ''
2025/05/06 01:17:21 ERROR : : Failed to rmdir: stat /tmp/TestInternalCache-local/ticwcm1746494241: no such file or directory
2025/05/06 01:17:21 DEBUG : Cache remote TestInternalCache:ticwcm1746494241: mkdir ''
2025/05/06 01:17:21 DEBUG : : mkdir: created dir in source fs
2025/05/06 01:17:21 DEBUG : : mkdir: added to cache
2025/05/06 01:17:21 DEBUG : : cache: expired ticwcm1746494241
2025/05/06 01:17:21 INFO  : : mkdir: cache expired
2025/05/06 01:17:22 DEBUG : Cache remote TestInternalCache:ticwcm1746494241: put data at 'data.bin'
2025/05/06 01:17:22 DEBUG : data.bin: put: uploaded to remote fs
2025/05/06 01:17:22 DEBUG : data.bin: put: added to cache
2025/05/06 01:17:22 DEBUG : : cache: expired ticwcm1746494241
2025/05/06 01:17:22 INFO  : : put: cache expired
2025/05/06 01:17:22 DEBUG : Cache remote TestInternalCache:ticwcm1746494241: new object 'data.bin'
2025/05/06 01:17:22 DEBUG : data.bin: find: warm object: data.bin, expiring on: 2025-05-06 07:17:22.112538508 +0000 UTC
2025/05/06 01:17:22 DEBUG : Cache remote TestInternalCache:ticwcm1746494241: new object 'data.bin'
2025/05/06 01:17:22 DEBUG : data.bin: find: warm object: data.bin, expiring on: 2025-05-06 07:17:22.112538508 +0000 UTC
2025/05/06 01:17:22 DEBUG : ticwcm1746494241/data.bin: moving offset set from 0 to 2621440
2025/05/06 01:17:22 DEBUG : ticwcm1746494241/data.bin: 0: chunk retry storage: 0
2025/05/06 01:17:22 DEBUG : worker-1 <data.bin>: downloaded chunk 0
2025/05/06 01:17:22 DEBUG : worker-3 <data.bin>: downloaded chunk 15728640
2025/05/06 01:17:22 DEBUG : worker-0 <data.bin>: downloaded chunk 5242880
2025/05/06 01:17:22 DEBUG : worker-2 <data.bin>: downloaded chunk 10485760
2025/05/06 01:17:22 DEBUG : ticwcm1746494241/data.bin: cache reader closed 5242880
2025/05/06 01:17:22 DEBUG : Waiting for deletions to finish
2025/05/06 01:17:22 DEBUG : Cache remote TestInternalCache:ticwcm1746494241: list ''
2025/05/06 01:17:22 DEBUG : : list: cold listing: 2025-05-05 19:17:22.115307242 +0000 UTC
2025/05/06 01:17:22 DEBUG : : list: read 1 from source
2025/05/06 01:17:22 DEBUG : : list: source entries: [data.bin]
2025/05/06 01:17:22 DEBUG : : list: cached object: data.bin
2025/05/06 01:17:22 DEBUG : : list: cached directories: 0
2025/05/06 01:17:22 DEBUG : : list: cached dir: 'ticwcm1746494241', cache ts: 2025-05-06 01:17:22.634200426 +0000 UTC m=+1.120123219
2025/05/06 01:17:22 DEBUG : data.bin: removing object
2025/05/06 01:17:22 DEBUG : : cache: expired ticwcm1746494241
2025/05/06 01:17:22 INFO  : data.bin: Deleted
2025/05/06 01:17:22 DEBUG : Cache remote TestInternalCache:ticwcm1746494241: list ''
2025/05/06 01:17:22 DEBUG : : list: cold listing: 2025-05-05 19:17:22.646525602 +0000 UTC
2025/05/06 01:17:22 DEBUG : : list: read 0 from source
2025/05/06 01:17:22 DEBUG : : list: source entries: []
2025/05/06 01:17:22 DEBUG : : list: cached directories: 0
2025/05/06 01:17:22 DEBUG : : list: cached dir: 'ticwcm1746494241', cache ts: 2025-05-06 01:17:22.648292669 +0000 UTC m=+1.134215482
2025/05/06 01:17:22 DEBUG : removing 1 level 0 directories
2025/05/06 01:17:22 INFO  : Cache remote TestInternalCache:ticwcm1746494241: Removing directory
2025/05/06 01:17:22 DEBUG : Cache remote TestInternalCache:ticwcm1746494241: rmdir ''
2025/05/06 01:17:22 DEBUG : : rmdir: removed dir in source fs
2025/05/06 01:17:22 DEBUG : : rmdir: removed from cache
2025/05/06 01:17:22 INFO  : : rmdir: cache expired
2025/05/06 01:17:22 DEBUG : Cache remote TestInternalCache:ticwcm1746494241: Services stopped
--- PASS: TestInternalCachedWrittenContentMatches (1.10s)
=== RUN   TestInternalDoubleWrittenContentMatches
2025/05/06 01:17:22 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2025/05/06 01:17:22 DEBUG : Creating backend with remote "TestInternalCache-local:/tmp/TestInternalCache-local/tidwcm1746494242"
2025/05/06 01:17:22 DEBUG : TestInternalCache: wrapped TestInternalCache-local:/tmp/TestInternalCache-local/tidwcm1746494242 at root tidwcm1746494242
2025/05/06 01:17:22 INFO  : TestInternalCache: Cache DB path: /home/rclone/.cache/rclone/cache-backend/TestInternalCache.db
2025/05/06 01:17:22 INFO  : TestInternalCache: Cache chunk path: /home/rclone/.cache/rclone/cache-backend/TestInternalCache
2025/05/06 01:17:22 INFO  : TestInternalCache: Chunk Memory: true
2025/05/06 01:17:22 INFO  : TestInternalCache: Chunk Size: 5Mi
2025/05/06 01:17:22 INFO  : TestInternalCache: Chunk Total Size: 10Gi
2025/05/06 01:17:22 INFO  : TestInternalCache: Chunk Clean Interval: 1m0s
2025/05/06 01:17:22 INFO  : TestInternalCache: Workers: 4
2025/05/06 01:17:22 INFO  : TestInternalCache: File Age: 6h0m0s
2025/05/06 01:17:22 DEBUG : Waiting for deletions to finish
2025/05/06 01:17:22 DEBUG : Cache remote TestInternalCache:tidwcm1746494242: list ''
2025/05/06 01:17:22 DEBUG : : list: error: couldn't open bucket (tidwcm1746494242)
2025/05/06 01:17:22 ERROR : : error listing: directory not found
2025/05/06 01:17:22 DEBUG : Cache remote TestInternalCache:tidwcm1746494242: list ''
2025/05/06 01:17:22 DEBUG : : list: error: couldn't open bucket (tidwcm1746494242)
2025/05/06 01:17:22 ERROR : Cache remote TestInternalCache:tidwcm1746494242: Failed to list "": directory not found
2025/05/06 01:17:22 DEBUG : removing 1 level 0 directories
2025/05/06 01:17:22 INFO  : Cache remote TestInternalCache:tidwcm1746494242: Removing directory
2025/05/06 01:17:22 DEBUG : Cache remote TestInternalCache:tidwcm1746494242: rmdir ''
2025/05/06 01:17:22 ERROR : : Failed to rmdir: stat /tmp/TestInternalCache-local/tidwcm1746494242: no such file or directory
2025/05/06 01:17:22 DEBUG : Cache remote TestInternalCache:tidwcm1746494242: mkdir ''
2025/05/06 01:17:22 DEBUG : : mkdir: created dir in source fs
2025/05/06 01:17:22 DEBUG : : mkdir: added to cache
2025/05/06 01:17:22 DEBUG : : cache: expired tidwcm1746494242
2025/05/06 01:17:22 INFO  : : mkdir: cache expired
2025/05/06 01:17:22 DEBUG : Cache remote TestInternalCache:tidwcm1746494242: put data at 'one'
2025/05/06 01:17:22 DEBUG : one: put: uploaded to remote fs
2025/05/06 01:17:22 DEBUG : one: put: added to cache
2025/05/06 01:17:22 DEBUG : : cache: expired tidwcm1746494242
2025/05/06 01:17:22 INFO  : : put: cache expired
2025/05/06 01:17:22 DEBUG : Cache remote TestInternalCache:tidwcm1746494242: new object 'one'
2025/05/06 01:17:22 DEBUG : one: find: warm object: one, expiring on: 2025-05-06 07:17:22.671099421 +0000 UTC
2025/05/06 01:17:22 DEBUG : Cache remote TestInternalCache:tidwcm1746494242: new object 'one'
2025/05/06 01:17:22 DEBUG : one: find: warm object: one, expiring on: 2025-05-06 07:17:22.671099421 +0000 UTC
2025/05/06 01:17:22 DEBUG : one: updating object contents with size 19
2025/05/06 01:17:22 DEBUG : Cache remote TestInternalCache:tidwcm1746494242: new object 'one'
2025/05/06 01:17:22 DEBUG : one: find: warm object: one, expiring on: 2025-05-06 07:17:22.677093638 +0000 UTC
2025/05/06 01:17:22 DEBUG : one: updating object contents with size 26
2025/05/06 01:17:22 DEBUG : Cache remote TestInternalCache:tidwcm1746494242: new object 'one'
2025/05/06 01:17:22 DEBUG : one: find: warm object: one, expiring on: 2025-05-06 07:17:22.680232377 +0000 UTC
2025/05/06 01:17:22 DEBUG : tidwcm1746494242/one: moving offset set from 0 to 0
2025/05/06 01:17:22 DEBUG : tidwcm1746494242/one: 0: chunk retry storage: 0
2025/05/06 01:17:22 DEBUG : worker-1 <one>: partial downloaded chunk 0
2025/05/06 01:17:23 DEBUG : tidwcm1746494242/one: cache reader closed 26
2025/05/06 01:17:23 DEBUG : Waiting for deletions to finish
2025/05/06 01:17:23 DEBUG : Cache remote TestInternalCache:tidwcm1746494242: list ''
2025/05/06 01:17:23 DEBUG : : list: cold listing: 2025-05-05 19:17:22.673437799 +0000 UTC
2025/05/06 01:17:23 DEBUG : : list: read 1 from source
2025/05/06 01:17:23 DEBUG : : list: source entries: [one]
2025/05/06 01:17:23 DEBUG : : list: cached object: one
2025/05/06 01:17:23 DEBUG : : list: cached directories: 0
2025/05/06 01:17:23 DEBUG : : list: cached dir: 'tidwcm1746494242', cache ts: 2025-05-06 01:17:23.185248664 +0000 UTC m=+1.671171446
2025/05/06 01:17:23 DEBUG : one: removing object
2025/05/06 01:17:23 DEBUG : : cache: expired tidwcm1746494242
2025/05/06 01:17:23 INFO  : one: Deleted
2025/05/06 01:17:23 DEBUG : Cache remote TestInternalCache:tidwcm1746494242: list ''
2025/05/06 01:17:23 DEBUG : : list: cold listing: 2025-05-05 19:17:23.189180481 +0000 UTC
2025/05/06 01:17:23 DEBUG : : list: read 0 from source
2025/05/06 01:17:23 DEBUG : : list: source entries: []
2025/05/06 01:17:23 DEBUG : : list: cached directories: 0
2025/05/06 01:17:23 DEBUG : : list: cached dir: 'tidwcm1746494242', cache ts: 2025-05-06 01:17:23.190459411 +0000 UTC m=+1.676382194
2025/05/06 01:17:23 DEBUG : removing 1 level 0 directories
2025/05/06 01:17:23 INFO  : Cache remote TestInternalCache:tidwcm1746494242: Removing directory
2025/05/06 01:17:23 DEBUG : Cache remote TestInternalCache:tidwcm1746494242: rmdir ''
2025/05/06 01:17:23 DEBUG : : rmdir: removed dir in source fs
2025/05/06 01:17:23 DEBUG : : rmdir: removed from cache
2025/05/06 01:17:23 INFO  : : rmdir: cache expired
2025/05/06 01:17:23 DEBUG : Cache remote TestInternalCache:tidwcm1746494242: Services stopped
--- PASS: TestInternalDoubleWrittenContentMatches (0.54s)
=== RUN   TestInternalCachedUpdatedContentMatches
2025/05/06 01:17:23 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2025/05/06 01:17:23 DEBUG : Creating backend with remote "TestInternalCache-local:/tmp/TestInternalCache-local/ticucm1746494243"
2025/05/06 01:17:23 DEBUG : TestInternalCache: wrapped TestInternalCache-local:/tmp/TestInternalCache-local/ticucm1746494243 at root ticucm1746494243
2025/05/06 01:17:23 INFO  : TestInternalCache: Cache DB path: /home/rclone/.cache/rclone/cache-backend/TestInternalCache.db
2025/05/06 01:17:23 INFO  : TestInternalCache: Cache chunk path: /home/rclone/.cache/rclone/cache-backend/TestInternalCache
2025/05/06 01:17:23 INFO  : TestInternalCache: Chunk Memory: true
2025/05/06 01:17:23 INFO  : TestInternalCache: Chunk Size: 5Mi
2025/05/06 01:17:23 INFO  : TestInternalCache: Chunk Total Size: 10Gi
2025/05/06 01:17:23 INFO  : TestInternalCache: Chunk Clean Interval: 1m0s
2025/05/06 01:17:23 INFO  : TestInternalCache: Workers: 4
2025/05/06 01:17:23 INFO  : TestInternalCache: File Age: 6h0m0s
2025/05/06 01:17:23 DEBUG : Waiting for deletions to finish
2025/05/06 01:17:23 DEBUG : Cache remote TestInternalCache:ticucm1746494243: list ''
2025/05/06 01:17:23 DEBUG : : list: error: couldn't open bucket (ticucm1746494243)
2025/05/06 01:17:23 ERROR : : error listing: directory not found
2025/05/06 01:17:23 DEBUG : Cache remote TestInternalCache:ticucm1746494243: list ''
2025/05/06 01:17:23 DEBUG : : list: error: couldn't open bucket (ticucm1746494243)
2025/05/06 01:17:23 ERROR : Cache remote TestInternalCache:ticucm1746494243: Failed to list "": directory not found
2025/05/06 01:17:23 DEBUG : removing 1 level 0 directories
2025/05/06 01:17:23 INFO  : Cache remote TestInternalCache:ticucm1746494243: Removing directory
2025/05/06 01:17:23 DEBUG : Cache remote TestInternalCache:ticucm1746494243: rmdir ''
2025/05/06 01:17:23 ERROR : : Failed to rmdir: stat /tmp/TestInternalCache-local/ticucm1746494243: no such file or directory
2025/05/06 01:17:23 DEBUG : Cache remote TestInternalCache:ticucm1746494243: mkdir ''
2025/05/06 01:17:23 DEBUG : : mkdir: created dir in source fs
2025/05/06 01:17:23 DEBUG : : mkdir: added to cache
2025/05/06 01:17:23 DEBUG : : cache: expired ticucm1746494243
2025/05/06 01:17:23 INFO  : : mkdir: cache expired
2025/05/06 01:17:23 DEBUG : Cache remote TestInternalCache:ticucm1746494243: put data at 'data.bin'
2025/05/06 01:17:23 DEBUG : data.bin: put: uploaded to remote fs
2025/05/06 01:17:23 DEBUG : data.bin: put: added to cache
2025/05/06 01:17:23 DEBUG : : cache: expired ticucm1746494243
2025/05/06 01:17:23 INFO  : : put: cache expired
2025/05/06 01:17:23 DEBUG : Cache remote TestInternalCache:ticucm1746494243: new object 'data.bin'
2025/05/06 01:17:23 DEBUG : data.bin: find: warm object: data.bin, expiring on: 2025-05-06 07:17:23.207184132 +0000 UTC
2025/05/06 01:17:23 DEBUG : data.bin: updating object contents with size 200
2025/05/06 01:17:23 DEBUG : Cache remote TestInternalCache:ticucm1746494243: new object 'data.bin'
2025/05/06 01:17:23 DEBUG : data.bin: find: warm object: data.bin, expiring on: 2025-05-06 07:17:23.213392852 +0000 UTC
2025/05/06 01:17:23 DEBUG : ticucm1746494243/data.bin: moving offset set from 0 to 0
2025/05/06 01:17:23 DEBUG : ticucm1746494243/data.bin: 0: chunk retry storage: 0
2025/05/06 01:17:23 DEBUG : worker-1 <data.bin>: partial downloaded chunk 0
2025/05/06 01:17:23 DEBUG : ticucm1746494243/data.bin: cache reader closed 200
2025/05/06 01:17:23 DEBUG : Waiting for deletions to finish
2025/05/06 01:17:23 DEBUG : Cache remote TestInternalCache:ticucm1746494243: list ''
2025/05/06 01:17:23 DEBUG : : list: cold listing: 2025-05-05 19:17:23.209514495 +0000 UTC
2025/05/06 01:17:23 DEBUG : : list: read 1 from source
2025/05/06 01:17:23 DEBUG : : list: source entries: [data.bin]
2025/05/06 01:17:23 DEBUG : : list: cached object: data.bin
2025/05/06 01:17:23 DEBUG : : list: cached directories: 0
2025/05/06 01:17:23 DEBUG : : list: cached dir: 'ticucm1746494243', cache ts: 2025-05-06 01:17:23.717805546 +0000 UTC m=+2.203728329
2025/05/06 01:17:23 DEBUG : data.bin: removing object
2025/05/06 01:17:23 DEBUG : : cache: expired ticucm1746494243
2025/05/06 01:17:23 INFO  : data.bin: Deleted
2025/05/06 01:17:23 DEBUG : Cache remote TestInternalCache:ticucm1746494243: list ''
2025/05/06 01:17:23 DEBUG : : list: cold listing: 2025-05-05 19:17:23.721824136 +0000 UTC
2025/05/06 01:17:23 DEBUG : : list: read 0 from source
2025/05/06 01:17:23 DEBUG : : list: source entries: []
2025/05/06 01:17:23 DEBUG : : list: cached directories: 0
2025/05/06 01:17:23 DEBUG : : list: cached dir: 'ticucm1746494243', cache ts: 2025-05-06 01:17:23.723352183 +0000 UTC m=+2.209274966
2025/05/06 01:17:23 DEBUG : removing 1 level 0 directories
2025/05/06 01:17:23 INFO  : Cache remote TestInternalCache:ticucm1746494243: Removing directory
2025/05/06 01:17:23 DEBUG : Cache remote TestInternalCache:ticucm1746494243: rmdir ''
2025/05/06 01:17:23 DEBUG : : rmdir: removed dir in source fs
2025/05/06 01:17:23 DEBUG : : rmdir: removed from cache
2025/05/06 01:17:23 INFO  : : rmdir: cache expired
2025/05/06 01:17:23 DEBUG : Cache remote TestInternalCache:ticucm1746494243: Services stopped
--- PASS: TestInternalCachedUpdatedContentMatches (0.53s)
=== RUN   TestInternalWrappedWrittenContentMatches
2025/05/06 01:17:23 DEBUG : Using config file from "/home/rclone/.rclone.conf"
    cache_internal_test.go:858: Need remote (TestInternalCache) to exist
--- SKIP: TestInternalWrappedWrittenContentMatches (0.00s)
=== RUN   TestInternalLargeWrittenContentMatches
2025/05/06 01:17:23 DEBUG : Using config file from "/home/rclone/.rclone.conf"
    cache_internal_test.go:858: Need remote (TestInternalCache) to exist
--- SKIP: TestInternalLargeWrittenContentMatches (0.00s)
=== RUN   TestInternalWrappedFsChangeNotSeen
2025/05/06 01:17:23 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2025/05/06 01:17:23 DEBUG : Creating backend with remote "TestInternalCache-local:/tmp/TestInternalCache-local/tiwfcns1746494243"
2025/05/06 01:17:23 DEBUG : TestInternalCache: wrapped TestInternalCache-local:/tmp/TestInternalCache-local/tiwfcns1746494243 at root tiwfcns1746494243
2025/05/06 01:17:23 INFO  : TestInternalCache: Cache DB path: /home/rclone/.cache/rclone/cache-backend/TestInternalCache.db
2025/05/06 01:17:23 INFO  : TestInternalCache: Cache chunk path: /home/rclone/.cache/rclone/cache-backend/TestInternalCache
2025/05/06 01:17:23 INFO  : TestInternalCache: Chunk Memory: true
2025/05/06 01:17:23 INFO  : TestInternalCache: Chunk Size: 5Mi
2025/05/06 01:17:23 INFO  : TestInternalCache: Chunk Total Size: 10Gi
2025/05/06 01:17:23 INFO  : TestInternalCache: Chunk Clean Interval: 1m0s
2025/05/06 01:17:23 INFO  : TestInternalCache: Workers: 4
2025/05/06 01:17:23 INFO  : TestInternalCache: File Age: 6h0m0s
2025/05/06 01:17:23 DEBUG : Waiting for deletions to finish
2025/05/06 01:17:23 DEBUG : Cache remote TestInternalCache:tiwfcns1746494243: list ''
2025/05/06 01:17:23 DEBUG : : list: error: couldn't open bucket (tiwfcns1746494243)
2025/05/06 01:17:23 ERROR : : error listing: directory not found
2025/05/06 01:17:23 DEBUG : Cache remote TestInternalCache:tiwfcns1746494243: list ''
2025/05/06 01:17:23 DEBUG : : list: error: couldn't open bucket (tiwfcns1746494243)
2025/05/06 01:17:23 ERROR : Cache remote TestInternalCache:tiwfcns1746494243: Failed to list "": directory not found
2025/05/06 01:17:23 DEBUG : removing 1 level 0 directories
2025/05/06 01:17:23 INFO  : Cache remote TestInternalCache:tiwfcns1746494243: Removing directory
2025/05/06 01:17:23 DEBUG : Cache remote TestInternalCache:tiwfcns1746494243: rmdir ''
2025/05/06 01:17:23 ERROR : : Failed to rmdir: stat /tmp/TestInternalCache-local/tiwfcns1746494243: no such file or directory
2025/05/06 01:17:23 DEBUG : Cache remote TestInternalCache:tiwfcns1746494243: mkdir ''
2025/05/06 01:17:23 DEBUG : : mkdir: created dir in source fs
2025/05/06 01:17:23 DEBUG : : mkdir: added to cache
2025/05/06 01:17:23 DEBUG : : cache: expired tiwfcns1746494243
2025/05/06 01:17:23 INFO  : : mkdir: cache expired
2025/05/06 01:17:24 DEBUG : Cache remote TestInternalCache:tiwfcns1746494243: put data at 'data.bin'
2025/05/06 01:17:24 DEBUG : data.bin: put: uploaded to remote fs
2025/05/06 01:17:24 DEBUG : data.bin: put: added to cache
2025/05/06 01:17:24 DEBUG : : cache: expired tiwfcns1746494243
2025/05/06 01:17:24 INFO  : : put: cache expired
2025/05/06 01:17:24 DEBUG : Cache remote TestInternalCache:tiwfcns1746494243: new object 'data.bin'
2025/05/06 01:17:24 DEBUG : data.bin: find: warm object: data.bin, expiring on: 2025-05-06 07:17:24.293291016 +0000 UTC
2025/05/06 01:17:24 DEBUG : Cache remote TestInternalCache:tiwfcns1746494243: new object 'data.bin'
2025/05/06 01:17:24 DEBUG : data.bin: find: warm object: data.bin, expiring on: 2025-05-06 07:17:24.293291016 +0000 UTC
2025/05/06 01:17:24 NOTICE: original size: 23592960
2025/05/06 01:17:24 NOTICE: updated size: 12
2025/05/06 01:17:24 DEBUG : Cache remote TestInternalCache:tiwfcns1746494243: new object 'data.bin'
2025/05/06 01:17:24 DEBUG : data.bin: find: warm object: data.bin, expiring on: 2025-05-06 07:17:24.293291016 +0000 UTC
2025/05/06 01:17:24 DEBUG : Waiting for deletions to finish
2025/05/06 01:17:24 DEBUG : Cache remote TestInternalCache:tiwfcns1746494243: list ''
2025/05/06 01:17:24 DEBUG : : list: cold listing: 2025-05-05 19:17:24.2958942 +0000 UTC
2025/05/06 01:17:24 DEBUG : : list: read 1 from source
2025/05/06 01:17:24 DEBUG : : list: source entries: [data.bin]
2025/05/06 01:17:24 DEBUG : : list: cached object: data.bin
2025/05/06 01:17:24 DEBUG : : list: cached directories: 0
2025/05/06 01:17:24 DEBUG : : list: cached dir: 'tiwfcns1746494243', cache ts: 2025-05-06 01:17:24.304142337 +0000 UTC m=+2.790065090
2025/05/06 01:17:24 DEBUG : data.bin: removing object
2025/05/06 01:17:24 DEBUG : : cache: expired tiwfcns1746494243
2025/05/06 01:17:24 INFO  : data.bin: Deleted
2025/05/06 01:17:24 DEBUG : Cache remote TestInternalCache:tiwfcns1746494243: list ''
2025/05/06 01:17:24 DEBUG : : list: cold listing: 2025-05-05 19:17:24.307403967 +0000 UTC
2025/05/06 01:17:24 DEBUG : : list: read 0 from source
2025/05/06 01:17:24 DEBUG : : list: source entries: []
2025/05/06 01:17:24 DEBUG : : list: cached directories: 0
2025/05/06 01:17:24 DEBUG : : list: cached dir: 'tiwfcns1746494243', cache ts: 2025-05-06 01:17:24.308579984 +0000 UTC m=+2.794502737
2025/05/06 01:17:24 DEBUG : removing 1 level 0 directories
2025/05/06 01:17:24 INFO  : Cache remote TestInternalCache:tiwfcns1746494243: Removing directory
2025/05/06 01:17:24 DEBUG : Cache remote TestInternalCache:tiwfcns1746494243: rmdir ''
2025/05/06 01:17:24 DEBUG : : rmdir: removed dir in source fs
2025/05/06 01:17:24 DEBUG : : rmdir: removed from cache
2025/05/06 01:17:24 INFO  : : rmdir: cache expired
2025/05/06 01:17:24 DEBUG : Cache remote TestInternalCache:tiwfcns1746494243: Services stopped
--- PASS: TestInternalWrappedFsChangeNotSeen (0.58s)
=== RUN   TestInternalMoveWithNotify
2025/05/06 01:17:24 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2025/05/06 01:17:24 DEBUG : Creating backend with remote "TestInternalCache-local:/tmp/TestInternalCache-local/timwn1746494244"
2025/05/06 01:17:24 DEBUG : TestInternalCache: wrapped TestInternalCache-local:/tmp/TestInternalCache-local/timwn1746494244 at root timwn1746494244
2025/05/06 01:17:24 INFO  : TestInternalCache: Cache DB path: /home/rclone/.cache/rclone/cache-backend/TestInternalCache.db
2025/05/06 01:17:24 INFO  : TestInternalCache: Cache chunk path: /home/rclone/.cache/rclone/cache-backend/TestInternalCache
2025/05/06 01:17:24 INFO  : TestInternalCache: Chunk Memory: true
2025/05/06 01:17:24 INFO  : TestInternalCache: Chunk Size: 5Mi
2025/05/06 01:17:24 INFO  : TestInternalCache: Chunk Total Size: 10Gi
2025/05/06 01:17:24 INFO  : TestInternalCache: Chunk Clean Interval: 1m0s
2025/05/06 01:17:24 INFO  : TestInternalCache: Workers: 4
2025/05/06 01:17:24 INFO  : TestInternalCache: File Age: 6h0m0s
2025/05/06 01:17:24 DEBUG : Waiting for deletions to finish
2025/05/06 01:17:24 DEBUG : Cache remote TestInternalCache:timwn1746494244: list ''
2025/05/06 01:17:24 DEBUG : : list: error: couldn't open bucket (timwn1746494244)
2025/05/06 01:17:24 ERROR : : error listing: directory not found
2025/05/06 01:17:24 DEBUG : Cache remote TestInternalCache:timwn1746494244: list ''
2025/05/06 01:17:24 DEBUG : : list: error: couldn't open bucket (timwn1746494244)
2025/05/06 01:17:24 ERROR : Cache remote TestInternalCache:timwn1746494244: Failed to list "": directory not found
2025/05/06 01:17:24 DEBUG : removing 1 level 0 directories
2025/05/06 01:17:24 INFO  : Cache remote TestInternalCache:timwn1746494244: Removing directory
2025/05/06 01:17:24 DEBUG : Cache remote TestInternalCache:timwn1746494244: rmdir ''
2025/05/06 01:17:24 ERROR : : Failed to rmdir: stat /tmp/TestInternalCache-local/timwn1746494244: no such file or directory
2025/05/06 01:17:24 DEBUG : Cache remote TestInternalCache:timwn1746494244: mkdir ''
2025/05/06 01:17:24 DEBUG : : mkdir: created dir in source fs
2025/05/06 01:17:24 DEBUG : : mkdir: added to cache
2025/05/06 01:17:24 DEBUG : : cache: expired timwn1746494244
2025/05/06 01:17:24 INFO  : : mkdir: cache expired
    cache_internal_test.go:453: Not external
2025/05/06 01:17:24 DEBUG : Waiting for deletions to finish
2025/05/06 01:17:24 DEBUG : Cache remote TestInternalCache:timwn1746494244: list ''
2025/05/06 01:17:24 DEBUG : : list: cold listing: 2025-05-05 19:17:24.326131326 +0000 UTC
2025/05/06 01:17:24 DEBUG : : list: read 0 from source
2025/05/06 01:17:24 DEBUG : : list: source entries: []
2025/05/06 01:17:24 DEBUG : : list: cached directories: 0
2025/05/06 01:17:24 DEBUG : : list: cached dir: 'timwn1746494244', cache ts: 2025-05-06 01:17:24.327760202 +0000 UTC m=+2.813682954
2025/05/06 01:17:24 DEBUG : Cache remote TestInternalCache:timwn1746494244: list ''
2025/05/06 01:17:24 DEBUG : : list: empty listing
2025/05/06 01:17:24 DEBUG : : list: read 0 from source
2025/05/06 01:17:24 DEBUG : : list: source entries: []
2025/05/06 01:17:24 DEBUG : : list: cached directories: 0
2025/05/06 01:17:24 DEBUG : : list: cached dir: 'timwn1746494244', cache ts: 2025-05-06 01:17:24.329160038 +0000 UTC m=+2.815082791
2025/05/06 01:17:24 DEBUG : removing 1 level 0 directories
2025/05/06 01:17:24 INFO  : Cache remote TestInternalCache:timwn1746494244: Removing directory
2025/05/06 01:17:24 DEBUG : Cache remote TestInternalCache:timwn1746494244: rmdir ''
2025/05/06 01:17:24 DEBUG : : rmdir: removed dir in source fs
2025/05/06 01:17:24 DEBUG : : rmdir: removed from cache
2025/05/06 01:17:24 INFO  : : rmdir: cache expired
2025/05/06 01:17:24 DEBUG : Cache remote TestInternalCache:timwn1746494244: Services stopped
--- SKIP: TestInternalMoveWithNotify (0.02s)
=== RUN   TestInternalNotifyCreatesEmptyParts
2025/05/06 01:17:24 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2025/05/06 01:17:24 DEBUG : Creating backend with remote "TestInternalCache-local:/tmp/TestInternalCache-local/tincep1746494244"
2025/05/06 01:17:24 DEBUG : TestInternalCache: wrapped TestInternalCache-local:/tmp/TestInternalCache-local/tincep1746494244 at root tincep1746494244
2025/05/06 01:17:24 INFO  : TestInternalCache: Cache DB path: /home/rclone/.cache/rclone/cache-backend/TestInternalCache.db
2025/05/06 01:17:24 INFO  : TestInternalCache: Cache chunk path: /home/rclone/.cache/rclone/cache-backend/TestInternalCache
2025/05/06 01:17:24 INFO  : TestInternalCache: Chunk Memory: true
2025/05/06 01:17:24 INFO  : TestInternalCache: Chunk Size: 5Mi
2025/05/06 01:17:24 INFO  : TestInternalCache: Chunk Total Size: 10Gi
2025/05/06 01:17:24 INFO  : TestInternalCache: Chunk Clean Interval: 1m0s
2025/05/06 01:17:24 INFO  : TestInternalCache: Workers: 4
2025/05/06 01:17:24 INFO  : TestInternalCache: File Age: 6h0m0s
2025/05/06 01:17:24 DEBUG : Waiting for deletions to finish
2025/05/06 01:17:24 DEBUG : Cache remote TestInternalCache:tincep1746494244: list ''
2025/05/06 01:17:24 DEBUG : : list: error: couldn't open bucket (tincep1746494244)
2025/05/06 01:17:24 ERROR : : error listing: directory not found
2025/05/06 01:17:24 DEBUG : Cache remote TestInternalCache:tincep1746494244: list ''
2025/05/06 01:17:24 DEBUG : : list: error: couldn't open bucket (tincep1746494244)
2025/05/06 01:17:24 ERROR : Cache remote TestInternalCache:tincep1746494244: Failed to list "": directory not found
2025/05/06 01:17:24 DEBUG : removing 1 level 0 directories
2025/05/06 01:17:24 INFO  : Cache remote TestInternalCache:tincep1746494244: Removing directory
2025/05/06 01:17:24 DEBUG : Cache remote TestInternalCache:tincep1746494244: rmdir ''
2025/05/06 01:17:24 ERROR : : Failed to rmdir: stat /tmp/TestInternalCache-local/tincep1746494244: no such file or directory
2025/05/06 01:17:24 DEBUG : Cache remote TestInternalCache:tincep1746494244: mkdir ''
2025/05/06 01:17:24 DEBUG : : mkdir: created dir in source fs
2025/05/06 01:17:24 DEBUG : : mkdir: added to cache
2025/05/06 01:17:24 DEBUG : : cache: expired tincep1746494244
2025/05/06 01:17:24 INFO  : : mkdir: cache expired
    cache_internal_test.go:539: Not external
2025/05/06 01:17:24 DEBUG : Waiting for deletions to finish
2025/05/06 01:17:24 DEBUG : Cache remote TestInternalCache:tincep1746494244: list ''
2025/05/06 01:17:24 DEBUG : : list: cold listing: 2025-05-05 19:17:24.345031659 +0000 UTC
2025/05/06 01:17:24 DEBUG : : list: read 0 from source
2025/05/06 01:17:24 DEBUG : : list: source entries: []
2025/05/06 01:17:24 DEBUG : : list: cached directories: 0
2025/05/06 01:17:24 DEBUG : : list: cached dir: 'tincep1746494244', cache ts: 2025-05-06 01:17:24.3466421 +0000 UTC m=+2.832564894
2025/05/06 01:17:24 DEBUG : Cache remote TestInternalCache:tincep1746494244: list ''
2025/05/06 01:17:24 DEBUG : : list: empty listing
2025/05/06 01:17:24 DEBUG : : list: read 0 from source
2025/05/06 01:17:24 DEBUG : : list: source entries: []
2025/05/06 01:17:24 DEBUG : : list: cached directories: 0
2025/05/06 01:17:24 DEBUG : : list: cached dir: 'tincep1746494244', cache ts: 2025-05-06 01:17:24.348252813 +0000 UTC m=+2.834175595
2025/05/06 01:17:24 DEBUG : removing 1 level 0 directories
2025/05/06 01:17:24 INFO  : Cache remote TestInternalCache:tincep1746494244: Removing directory
2025/05/06 01:17:24 DEBUG : Cache remote TestInternalCache:tincep1746494244: rmdir ''
2025/05/06 01:17:24 DEBUG : : rmdir: removed dir in source fs
2025/05/06 01:17:24 DEBUG : : rmdir: removed from cache
2025/05/06 01:17:24 INFO  : : rmdir: cache expired
2025/05/06 01:17:24 DEBUG : Cache remote TestInternalCache:tincep1746494244: Services stopped
--- SKIP: TestInternalNotifyCreatesEmptyParts (0.02s)
=== RUN   TestInternalChangeSeenAfterDirCacheFlush
2025/05/06 01:17:24 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2025/05/06 01:17:24 DEBUG : Creating backend with remote "TestInternalCache-local:/tmp/TestInternalCache-local/ticsadcf1746494244"
2025/05/06 01:17:24 DEBUG : TestInternalCache: wrapped TestInternalCache-local:/tmp/TestInternalCache-local/ticsadcf1746494244 at root ticsadcf1746494244
2025/05/06 01:17:24 INFO  : TestInternalCache: Cache DB path: /home/rclone/.cache/rclone/cache-backend/TestInternalCache.db
2025/05/06 01:17:24 INFO  : TestInternalCache: Cache chunk path: /home/rclone/.cache/rclone/cache-backend/TestInternalCache
2025/05/06 01:17:24 INFO  : TestInternalCache: Chunk Memory: true
2025/05/06 01:17:24 INFO  : TestInternalCache: Chunk Size: 5Mi
2025/05/06 01:17:24 INFO  : TestInternalCache: Chunk Total Size: 10Gi
2025/05/06 01:17:24 INFO  : TestInternalCache: Chunk Clean Interval: 1m0s
2025/05/06 01:17:24 INFO  : TestInternalCache: Workers: 4
2025/05/06 01:17:24 INFO  : TestInternalCache: File Age: 6h0m0s
2025/05/06 01:17:24 DEBUG : Waiting for deletions to finish
2025/05/06 01:17:24 DEBUG : Cache remote TestInternalCache:ticsadcf1746494244: list ''
2025/05/06 01:17:24 DEBUG : : list: error: couldn't open bucket (ticsadcf1746494244)
2025/05/06 01:17:24 ERROR : : error listing: directory not found
2025/05/06 01:17:24 DEBUG : Cache remote TestInternalCache:ticsadcf1746494244: list ''
2025/05/06 01:17:24 DEBUG : : list: error: couldn't open bucket (ticsadcf1746494244)
2025/05/06 01:17:24 ERROR : Cache remote TestInternalCache:ticsadcf1746494244: Failed to list "": directory not found
2025/05/06 01:17:24 DEBUG : removing 1 level 0 directories
2025/05/06 01:17:24 INFO  : Cache remote TestInternalCache:ticsadcf1746494244: Removing directory
2025/05/06 01:17:24 DEBUG : Cache remote TestInternalCache:ticsadcf1746494244: rmdir ''
2025/05/06 01:17:24 ERROR : : Failed to rmdir: stat /tmp/TestInternalCache-local/ticsadcf1746494244: no such file or directory
2025/05/06 01:17:24 DEBUG : Cache remote TestInternalCache:ticsadcf1746494244: mkdir ''
2025/05/06 01:17:24 DEBUG : : mkdir: created dir in source fs
2025/05/06 01:17:24 DEBUG : : mkdir: added to cache
2025/05/06 01:17:24 DEBUG : : cache: expired ticsadcf1746494244
2025/05/06 01:17:24 INFO  : : mkdir: cache expired
2025/05/06 01:17:24 DEBUG : Cache remote TestInternalCache:ticsadcf1746494244: put data at 'data.bin'
2025/05/06 01:17:24 DEBUG : data.bin: put: uploaded to remote fs
2025/05/06 01:17:24 DEBUG : data.bin: put: added to cache
2025/05/06 01:17:24 DEBUG : : cache: expired ticsadcf1746494244
2025/05/06 01:17:24 INFO  : : put: cache expired
2025/05/06 01:17:24 DEBUG : Cache remote TestInternalCache:ticsadcf1746494244: new object 'data.bin'
2025/05/06 01:17:24 DEBUG : data.bin: find: warm object: data.bin, expiring on: 2025-05-06 07:17:24.856212934 +0000 UTC
2025/05/06 01:17:24 DEBUG : Cache remote TestInternalCache:ticsadcf1746494244: new object 'data.bin'
2025/05/06 01:17:24 DEBUG : data.bin: find: warm object: data.bin, expiring on: 2025-05-06 07:17:24.856212934 +0000 UTC
2025/05/06 01:17:24 DEBUG : Cache remote TestInternalCache:ticsadcf1746494244: new object 'data.bin'
2025/05/06 01:17:24 DEBUG : data.bin: find: error: couldn't open parent bucket for ticsadcf1746494244
2025/05/06 01:17:24 DEBUG : data.bin: find: cached object
2025/05/06 01:17:24 DEBUG : Waiting for deletions to finish
2025/05/06 01:17:24 DEBUG : Cache remote TestInternalCache:ticsadcf1746494244: list ''
2025/05/06 01:17:24 DEBUG : : list: error: missing cached dir: 
2025/05/06 01:17:24 DEBUG : : list: read 1 from source
2025/05/06 01:17:24 DEBUG : : list: source entries: [data.bin]
2025/05/06 01:17:24 DEBUG : : list: cached object: data.bin
2025/05/06 01:17:24 DEBUG : : list: cached directories: 0
2025/05/06 01:17:24 DEBUG : : list: cached dir: 'ticsadcf1746494244', cache ts: 2025-05-06 01:17:24.862500541 +0000 UTC m=+3.348423294
2025/05/06 01:17:24 DEBUG : data.bin: removing object
2025/05/06 01:17:24 DEBUG : : cache: expired ticsadcf1746494244
2025/05/06 01:17:24 INFO  : data.bin: Deleted
2025/05/06 01:17:24 DEBUG : Cache remote TestInternalCache:ticsadcf1746494244: list ''
2025/05/06 01:17:24 DEBUG : : list: cold listing: 2025-05-05 19:17:24.868186009 +0000 UTC
2025/05/06 01:17:24 DEBUG : : list: read 0 from source
2025/05/06 01:17:24 DEBUG : : list: source entries: []
2025/05/06 01:17:24 DEBUG : : list: cached directories: 0
2025/05/06 01:17:24 DEBUG : : list: cached dir: 'ticsadcf1746494244', cache ts: 2025-05-06 01:17:24.869273008 +0000 UTC m=+3.355195761
2025/05/06 01:17:24 DEBUG : removing 1 level 0 directories
2025/05/06 01:17:24 INFO  : Cache remote TestInternalCache:ticsadcf1746494244: Removing directory
2025/05/06 01:17:24 DEBUG : Cache remote TestInternalCache:ticsadcf1746494244: rmdir ''
2025/05/06 01:17:24 DEBUG : : rmdir: removed dir in source fs
2025/05/06 01:17:24 DEBUG : : rmdir: removed from cache
2025/05/06 01:17:24 INFO  : : rmdir: cache expired
2025/05/06 01:17:24 DEBUG : Cache remote TestInternalCache:ticsadcf1746494244: Services stopped
--- PASS: TestInternalChangeSeenAfterDirCacheFlush (0.52s)
=== RUN   TestInternalCacheWrites
2025/05/06 01:17:24 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2025/05/06 01:17:24 DEBUG : Creating backend with remote "TestInternalCache-local:/tmp/TestInternalCache-local/ticw"
2025/05/06 01:17:24 DEBUG : TestInternalCache: wrapped TestInternalCache-local:/tmp/TestInternalCache-local/ticw at root ticw
2025/05/06 01:17:24 INFO  : TestInternalCache: Cache DB path: /home/rclone/.cache/rclone/cache-backend/TestInternalCache.db
2025/05/06 01:17:24 INFO  : TestInternalCache: Cache chunk path: /home/rclone/.cache/rclone/cache-backend/TestInternalCache
2025/05/06 01:17:24 INFO  : TestInternalCache: Chunk Memory: true
2025/05/06 01:17:24 INFO  : TestInternalCache: Chunk Size: 5Mi
2025/05/06 01:17:24 INFO  : TestInternalCache: Chunk Total Size: 10Gi
2025/05/06 01:17:24 INFO  : TestInternalCache: Chunk Clean Interval: 1m0s
2025/05/06 01:17:24 INFO  : TestInternalCache: Workers: 4
2025/05/06 01:17:24 INFO  : TestInternalCache: File Age: 6h0m0s
2025/05/06 01:17:24 INFO  : TestInternalCache: Cache Writes: enabled
2025/05/06 01:17:24 DEBUG : Waiting for deletions to finish
2025/05/06 01:17:24 DEBUG : Cache remote TestInternalCache:ticw: list ''
2025/05/06 01:17:24 DEBUG : : list: error: couldn't open bucket (ticw)
2025/05/06 01:17:24 ERROR : : error listing: directory not found
2025/05/06 01:17:24 DEBUG : Cache remote TestInternalCache:ticw: list ''
2025/05/06 01:17:24 DEBUG : : list: error: couldn't open bucket (ticw)
2025/05/06 01:17:24 ERROR : Cache remote TestInternalCache:ticw: Failed to list "": directory not found
2025/05/06 01:17:24 DEBUG : removing 1 level 0 directories
2025/05/06 01:17:24 INFO  : Cache remote TestInternalCache:ticw: Removing directory
2025/05/06 01:17:24 DEBUG : Cache remote TestInternalCache:ticw: rmdir ''
2025/05/06 01:17:24 ERROR : : Failed to rmdir: stat /tmp/TestInternalCache-local/ticw: no such file or directory
2025/05/06 01:17:24 DEBUG : Cache remote TestInternalCache:ticw: mkdir ''
2025/05/06 01:17:24 DEBUG : : mkdir: created dir in source fs
2025/05/06 01:17:24 DEBUG : : mkdir: added to cache
2025/05/06 01:17:24 DEBUG : : cache: expired ticw
2025/05/06 01:17:24 INFO  : : mkdir: cache expired
2025/05/06 01:17:25 DEBUG : Cache remote TestInternalCache:ticw: put data at 'data.bin'
2025/05/06 01:17:25 DEBUG : data.bin: put: uploaded to remote fs and saved in cache
2025/05/06 01:17:25 DEBUG : data.bin: put: added to cache
2025/05/06 01:17:25 DEBUG : : cache: expired ticw
2025/05/06 01:17:25 INFO  : : put: cache expired
2025/05/06 01:17:25 DEBUG : Cache remote TestInternalCache:ticw: new object 'data.bin'
2025/05/06 01:17:25 DEBUG : data.bin: find: warm object: data.bin, expiring on: 2025-05-06 07:17:25.460647482 +0000 UTC
2025/05/06 01:17:25 DEBUG : Waiting for deletions to finish
2025/05/06 01:17:25 DEBUG : Cache remote TestInternalCache:ticw: list ''
2025/05/06 01:17:25 DEBUG : : list: cold listing: 2025-05-05 19:17:25.471544008 +0000 UTC
2025/05/06 01:17:25 DEBUG : : list: read 1 from source
2025/05/06 01:17:25 DEBUG : : list: source entries: [data.bin]
2025/05/06 01:17:25 DEBUG : : list: cached object: data.bin
2025/05/06 01:17:25 DEBUG : : list: cached directories: 0
2025/05/06 01:17:25 DEBUG : : list: cached dir: 'ticw', cache ts: 2025-05-06 01:17:25.474261146 +0000 UTC m=+3.960183909
2025/05/06 01:17:25 DEBUG : data.bin: removing object
2025/05/06 01:17:25 DEBUG : : cache: expired ticw
2025/05/06 01:17:25 INFO  : data.bin: Deleted
2025/05/06 01:17:25 DEBUG : Cache remote TestInternalCache:ticw: list ''
2025/05/06 01:17:25 DEBUG : : list: cold listing: 2025-05-05 19:17:25.480997456 +0000 UTC
2025/05/06 01:17:25 DEBUG : : list: read 0 from source
2025/05/06 01:17:25 DEBUG : : list: source entries: []
2025/05/06 01:17:25 DEBUG : : list: cached directories: 0
2025/05/06 01:17:25 DEBUG : : list: cached dir: 'ticw', cache ts: 2025-05-06 01:17:25.482103301 +0000 UTC m=+3.968026064
2025/05/06 01:17:25 DEBUG : removing 1 level 0 directories
2025/05/06 01:17:25 INFO  : Cache remote TestInternalCache:ticw: Removing directory
2025/05/06 01:17:25 DEBUG : Cache remote TestInternalCache:ticw: rmdir ''
2025/05/06 01:17:25 DEBUG : : rmdir: removed dir in source fs
2025/05/06 01:17:25 DEBUG : : rmdir: removed from cache
2025/05/06 01:17:25 INFO  : : rmdir: cache expired
2025/05/06 01:17:25 DEBUG : Cache remote TestInternalCache:ticw: Services stopped
--- PASS: TestInternalCacheWrites (0.62s)
=== RUN   TestInternalMaxChunkSizeRespected
2025/05/06 01:17:25 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2025/05/06 01:17:25 DEBUG : Creating backend with remote "TestInternalCache-local:/tmp/TestInternalCache-local/timcsr1746494245"
2025/05/06 01:17:25 DEBUG : TestInternalCache: wrapped TestInternalCache-local:/tmp/TestInternalCache-local/timcsr1746494245 at root timcsr1746494245
2025/05/06 01:17:25 INFO  : TestInternalCache: Cache DB path: /home/rclone/.cache/rclone/cache-backend/TestInternalCache.db
2025/05/06 01:17:25 INFO  : TestInternalCache: Cache chunk path: /home/rclone/.cache/rclone/cache-backend/TestInternalCache
2025/05/06 01:17:25 INFO  : TestInternalCache: Chunk Memory: true
2025/05/06 01:17:25 INFO  : TestInternalCache: Chunk Size: 5Mi
2025/05/06 01:17:25 INFO  : TestInternalCache: Chunk Total Size: 10Gi
2025/05/06 01:17:25 INFO  : TestInternalCache: Chunk Clean Interval: 1m0s
2025/05/06 01:17:25 INFO  : TestInternalCache: Workers: 1
2025/05/06 01:17:25 INFO  : TestInternalCache: File Age: 6h0m0s
2025/05/06 01:17:25 DEBUG : Waiting for deletions to finish
2025/05/06 01:17:25 DEBUG : Cache remote TestInternalCache:timcsr1746494245: list ''
2025/05/06 01:17:25 DEBUG : : list: error: couldn't open bucket (timcsr1746494245)
2025/05/06 01:17:25 ERROR : : error listing: directory not found
2025/05/06 01:17:25 DEBUG : Cache remote TestInternalCache:timcsr1746494245: list ''
2025/05/06 01:17:25 DEBUG : : list: error: couldn't open bucket (timcsr1746494245)
2025/05/06 01:17:25 ERROR : Cache remote TestInternalCache:timcsr1746494245: Failed to list "": directory not found
2025/05/06 01:17:25 DEBUG : removing 1 level 0 directories
2025/05/06 01:17:25 INFO  : Cache remote TestInternalCache:timcsr1746494245: Removing directory
2025/05/06 01:17:25 DEBUG : Cache remote TestInternalCache:timcsr1746494245: rmdir ''
2025/05/06 01:17:25 ERROR : : Failed to rmdir: stat /tmp/TestInternalCache-local/timcsr1746494245: no such file or directory
2025/05/06 01:17:25 DEBUG : Cache remote TestInternalCache:timcsr1746494245: mkdir ''
2025/05/06 01:17:25 DEBUG : : mkdir: created dir in source fs
2025/05/06 01:17:25 DEBUG : : mkdir: added to cache
2025/05/06 01:17:25 DEBUG : : cache: expired timcsr1746494245
2025/05/06 01:17:25 INFO  : : mkdir: cache expired
2025/05/06 01:17:27 DEBUG : Cache remote TestInternalCache:timcsr1746494245: put data at 'data.bin'
2025/05/06 01:17:27 DEBUG : data.bin: put: uploaded to remote fs
2025/05/06 01:17:27 DEBUG : data.bin: put: added to cache
2025/05/06 01:17:27 DEBUG : : cache: expired timcsr1746494245
2025/05/06 01:17:27 INFO  : : put: cache expired
2025/05/06 01:17:27 DEBUG : Cache remote TestInternalCache:timcsr1746494245: new object 'data.bin'
2025/05/06 01:17:27 DEBUG : data.bin: find: warm object: data.bin, expiring on: 2025-05-06 07:17:27.759437185 +0000 UTC
2025/05/06 01:17:27 DEBUG : Cache remote TestInternalCache:timcsr1746494245: new object 'data.bin'
2025/05/06 01:17:27 DEBUG : data.bin: find: warm object: data.bin, expiring on: 2025-05-06 07:17:27.759437185 +0000 UTC
2025/05/06 01:17:27 DEBUG : timcsr1746494245/data.bin: moving offset set from 0 to 0
2025/05/06 01:17:27 DEBUG : timcsr1746494245/data.bin: 0: chunk retry storage: 0
2025/05/06 01:17:27 DEBUG : worker-0 <data.bin>: downloaded chunk 0
2025/05/06 01:17:28 DEBUG : timcsr1746494245/data.bin: cache reader closed 5242880
2025/05/06 01:17:28 DEBUG : timcsr1746494245/data.bin: moving offset set from 0 to 5242880
2025/05/06 01:17:28 DEBUG : timcsr1746494245/data.bin: 5242880: chunk retry storage: 0
2025/05/06 01:17:28 DEBUG : worker-0 <data.bin>: downloaded chunk 5242880
2025/05/06 01:17:28 DEBUG : timcsr1746494245/data.bin: cache reader closed 10485760
2025/05/06 01:17:28 DEBUG : timcsr1746494245/data.bin: moving offset set from 0 to 10485760
2025/05/06 01:17:28 DEBUG : timcsr1746494245/data.bin: 10485760: chunk retry storage: 0
2025/05/06 01:17:28 DEBUG : worker-0 <data.bin>: downloaded chunk 10485760
2025/05/06 01:17:29 DEBUG : timcsr1746494245/data.bin: cache reader closed 15728640
2025/05/06 01:17:29 DEBUG : timcsr1746494245/data.bin: moving offset set from 0 to 15728640
2025/05/06 01:17:29 DEBUG : timcsr1746494245/data.bin: 15728640: chunk retry storage: 0
2025/05/06 01:17:29 DEBUG : worker-0 <data.bin>: downloaded chunk 15728640
2025/05/06 01:17:29 DEBUG : timcsr1746494245/data.bin: cache reader closed 20971520
2025/05/06 01:17:29 DEBUG : timcsr1746494245/data.bin: moving offset set from 0 to 20971520
2025/05/06 01:17:29 DEBUG : timcsr1746494245/data.bin: 20971520: chunk retry storage: 0
2025/05/06 01:17:29 DEBUG : worker-0 <data.bin>: downloaded chunk 20971520
2025/05/06 01:17:30 DEBUG : timcsr1746494245/data.bin: cache reader closed 26214400
2025/05/06 01:17:30 DEBUG : timcsr1746494245/data.bin: moving offset set from 0 to 26214400
2025/05/06 01:17:30 DEBUG : timcsr1746494245/data.bin: 26214400: chunk retry storage: 0
2025/05/06 01:17:30 DEBUG : worker-0 <data.bin>: downloaded chunk 26214400
2025/05/06 01:17:30 DEBUG : timcsr1746494245/data.bin: cache reader closed 31457280
2025/05/06 01:17:30 DEBUG : Waiting for deletions to finish
2025/05/06 01:17:30 DEBUG : Cache remote TestInternalCache:timcsr1746494245: list ''
2025/05/06 01:17:30 DEBUG : : list: cold listing: 2025-05-05 19:17:27.767708474 +0000 UTC
2025/05/06 01:17:30 DEBUG : : list: read 1 from source
2025/05/06 01:17:30 DEBUG : : list: source entries: [data.bin]
2025/05/06 01:17:30 DEBUG : : list: cached object: data.bin
2025/05/06 01:17:30 DEBUG : : list: cached directories: 0
2025/05/06 01:17:30 DEBUG : : list: cached dir: 'timcsr1746494245', cache ts: 2025-05-06 01:17:30.984030688 +0000 UTC m=+9.469953441
2025/05/06 01:17:30 DEBUG : data.bin: removing object
2025/05/06 01:17:30 DEBUG : : cache: expired timcsr1746494245
2025/05/06 01:17:30 INFO  : data.bin: Deleted
2025/05/06 01:17:30 DEBUG : Cache remote TestInternalCache:timcsr1746494245: list ''
2025/05/06 01:17:30 DEBUG : : list: cold listing: 2025-05-05 19:17:30.993372337 +0000 UTC
2025/05/06 01:17:30 DEBUG : : list: read 0 from source
2025/05/06 01:17:30 DEBUG : : list: source entries: []
2025/05/06 01:17:30 DEBUG : : list: cached directories: 0
2025/05/06 01:17:30 DEBUG : : list: cached dir: 'timcsr1746494245', cache ts: 2025-05-06 01:17:30.994948543 +0000 UTC m=+9.480871327
2025/05/06 01:17:30 DEBUG : removing 1 level 0 directories
2025/05/06 01:17:30 INFO  : Cache remote TestInternalCache:timcsr1746494245: Removing directory
2025/05/06 01:17:30 DEBUG : Cache remote TestInternalCache:timcsr1746494245: rmdir ''
2025/05/06 01:17:30 DEBUG : : rmdir: removed dir in source fs
2025/05/06 01:17:30 DEBUG : : rmdir: removed from cache
2025/05/06 01:17:30 INFO  : : rmdir: cache expired
2025/05/06 01:17:30 DEBUG : Cache remote TestInternalCache:timcsr1746494245: Services stopped
--- PASS: TestInternalMaxChunkSizeRespected (5.52s)
=== RUN   TestInternalExpiredEntriesRemoved
2025/05/06 01:17:31 DEBUG : Using config file from "/home/rclone/.rclone.conf"
    cache_internal_test.go:858: Need remote (TestInternalCache) to exist
--- SKIP: TestInternalExpiredEntriesRemoved (0.00s)
=== RUN   TestInternalBug2117
2025/05/06 01:17:31 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2025/05/06 01:17:31 DEBUG : Creating backend with remote "TestInternalCache-local:/tmp/TestInternalCache-local/tib21171746494251"
2025/05/06 01:17:31 DEBUG : TestInternalCache: wrapped TestInternalCache-local:/tmp/TestInternalCache-local/tib21171746494251 at root tib21171746494251
2025/05/06 01:17:31 INFO  : TestInternalCache: Cache DB path: /home/rclone/.cache/rclone/cache-backend/TestInternalCache.db
2025/05/06 01:17:31 INFO  : TestInternalCache: Cache chunk path: /home/rclone/.cache/rclone/cache-backend/TestInternalCache
2025/05/06 01:17:31 INFO  : TestInternalCache: Chunk Memory: true
2025/05/06 01:17:31 INFO  : TestInternalCache: Chunk Size: 5Mi
2025/05/06 01:17:31 INFO  : TestInternalCache: Chunk Total Size: 10Gi
2025/05/06 01:17:31 INFO  : TestInternalCache: Chunk Clean Interval: 15m0s
2025/05/06 01:17:31 INFO  : TestInternalCache: Workers: 4
2025/05/06 01:17:31 INFO  : TestInternalCache: File Age: 3d
2025/05/06 01:17:31 DEBUG : Waiting for deletions to finish
2025/05/06 01:17:31 DEBUG : Cache remote TestInternalCache:tib21171746494251: list ''
2025/05/06 01:17:31 DEBUG : : list: error: couldn't open bucket (tib21171746494251)
2025/05/06 01:17:31 ERROR : : error listing: directory not found
2025/05/06 01:17:31 DEBUG : Cache remote TestInternalCache:tib21171746494251: list ''
2025/05/06 01:17:31 DEBUG : : list: error: couldn't open bucket (tib21171746494251)
2025/05/06 01:17:31 ERROR : Cache remote TestInternalCache:tib21171746494251: Failed to list "": directory not found
2025/05/06 01:17:31 DEBUG : removing 1 level 0 directories
2025/05/06 01:17:31 INFO  : Cache remote TestInternalCache:tib21171746494251: Removing directory
2025/05/06 01:17:31 DEBUG : Cache remote TestInternalCache:tib21171746494251: rmdir ''
2025/05/06 01:17:31 ERROR : : Failed to rmdir: stat /tmp/TestInternalCache-local/tib21171746494251: no such file or directory
2025/05/06 01:17:31 DEBUG : Cache remote TestInternalCache:tib21171746494251: mkdir ''
2025/05/06 01:17:31 DEBUG : : mkdir: created dir in source fs
2025/05/06 01:17:31 DEBUG : : mkdir: added to cache
2025/05/06 01:17:31 DEBUG : : cache: expired tib21171746494251
2025/05/06 01:17:31 INFO  : : mkdir: cache expired
2025/05/06 01:17:31 DEBUG : Cache remote TestInternalCache:tib21171746494251: list 'test/dir1/dir2'
2025/05/06 01:17:31 DEBUG : test/dir1/dir2: list: error: couldn't open bucket (tib21171746494251/test/dir1/dir2)
2025/05/06 01:17:31 DEBUG : test/dir1/dir2: list: read 1 from source
2025/05/06 01:17:31 DEBUG : test/dir1/dir2: list: source entries: [test/dir1/dir2/test.txt]
2025/05/06 01:17:31 DEBUG : test/dir1/dir2: list: cached object: test/dir1/dir2/test.txt
2025/05/06 01:17:31 DEBUG : test/dir1/dir2: list: cached directories: 0
2025/05/06 01:17:31 DEBUG : test/dir1/dir2: list: cached dir: 'tib21171746494251/test/dir1/dir2', cache ts: 2025-05-06 01:17:31.031634349 +0000 UTC m=+9.517557132
2025/05/06 01:17:31 NOTICE: len: 1
2025/05/06 01:18:01 DEBUG : Cache remote TestInternalCache:tib21171746494251: list 'test/dir1/dir2'
2025/05/06 01:18:01 DEBUG : test/dir1/dir2: list: warm 1 from cache for: tib21171746494251/test/dir1/dir2, expiring on: 2025-05-09 01:17:31.031634349 +0000 UTC
2025/05/06 01:18:01 DEBUG : test/dir1/dir2: list: cached entries: [test/dir1/dir2/test.txt]
2025/05/06 01:18:01 NOTICE: len: 1
2025/05/06 01:18:01 DEBUG : Cache remote TestInternalCache:tib21171746494251: list 'test/dir1'
2025/05/06 01:18:01 DEBUG : test/dir1: list: error: missing cached dir: test/dir1
2025/05/06 01:18:01 DEBUG : test/dir1: list: read 4 from source
2025/05/06 01:18:01 DEBUG : test/dir1: list: source entries: [test/dir1/dir3 test/dir1/dir2 test/dir1/dir4 test/dir1/dir1]
2025/05/06 01:18:01 DEBUG : test/dir1: list: cached directories: 4
2025/05/06 01:18:01 DEBUG : test/dir1: list: cached dir: 'tib21171746494251/test/dir1', cache ts: 2025-05-06 01:18:01.036090784 +0000 UTC m=+39.522013547
2025/05/06 01:18:01 NOTICE: len: 4
2025/05/06 01:18:01 DEBUG : Cache remote TestInternalCache:tib21171746494251: list 'test'
2025/05/06 01:18:01 DEBUG : test: list: error: missing cached dir: test
2025/05/06 01:18:01 DEBUG : test: list: read 4 from source
2025/05/06 01:18:01 DEBUG : test: list: source entries: [test/dir3 test/dir2 test/dir4 test/dir1]
2025/05/06 01:18:01 DEBUG : test: list: cached directories: 4
2025/05/06 01:18:01 DEBUG : test: list: cached dir: 'tib21171746494251/test', cache ts: 2025-05-06 01:18:01.038678961 +0000 UTC m=+39.524601724
2025/05/06 01:18:01 NOTICE: len: 4
2025/05/06 01:18:01 DEBUG : Waiting for deletions to finish
2025/05/06 01:18:01 DEBUG : Cache remote TestInternalCache:tib21171746494251: list ''
2025/05/06 01:18:01 DEBUG : : list: cold listing: 2025-05-03 01:17:31.022066636 +0000 UTC
2025/05/06 01:18:01 DEBUG : : list: read 1 from source
2025/05/06 01:18:01 DEBUG : : list: source entries: [test]
2025/05/06 01:18:01 DEBUG : : list: cached directories: 1
2025/05/06 01:18:01 DEBUG : : list: cached dir: 'tib21171746494251', cache ts: 2025-05-06 01:18:01.041477051 +0000 UTC m=+39.527399814
2025/05/06 01:18:01 DEBUG : Cache remote TestInternalCache:tib21171746494251: list 'test'
2025/05/06 01:18:01 DEBUG : test: list: warm 4 from cache for: tib21171746494251/test, expiring on: 2025-05-09 01:18:01.040222106 +0000 UTC
2025/05/06 01:18:01 DEBUG : test: list: cached entries: [test/dir1 test/dir2 test/dir3 test/dir4]
2025/05/06 01:18:01 DEBUG : Cache remote TestInternalCache:tib21171746494251: list 'test/dir4'
2025/05/06 01:18:01 DEBUG : test/dir4: list: empty listing
2025/05/06 01:18:01 DEBUG : Cache remote TestInternalCache:tib21171746494251: list 'test/dir2'
2025/05/06 01:18:01 DEBUG : Cache remote TestInternalCache:tib21171746494251: list 'test/dir3'
2025/05/06 01:18:01 DEBUG : test/dir3: list: empty listing
2025/05/06 01:18:01 DEBUG : test/dir2: list: empty listing
2025/05/06 01:18:01 DEBUG : test/dir3: list: read 4 from source
2025/05/06 01:18:01 DEBUG : test/dir3: list: source entries: [test/dir3/dir3 test/dir3/dir2 test/dir3/dir4 test/dir3/dir1]
2025/05/06 01:18:01 DEBUG : test/dir2: list: read 4 from source
2025/05/06 01:18:01 DEBUG : test/dir2: list: source entries: [test/dir2/dir3 test/dir2/dir2 test/dir2/dir4 test/dir2/dir1]
2025/05/06 01:18:01 DEBUG : test/dir4: list: read 4 from source
2025/05/06 01:18:01 DEBUG : test/dir4: list: source entries: [test/dir4/dir3 test/dir4/dir2 test/dir4/dir4 test/dir4/dir1]
2025/05/06 01:18:01 DEBUG : Cache remote TestInternalCache:tib21171746494251: list 'test/dir1'
2025/05/06 01:18:01 DEBUG : test/dir1: list: warm 4 from cache for: tib21171746494251/test/dir1, expiring on: 2025-05-09 01:18:01.03749543 +0000 UTC
2025/05/06 01:18:01 DEBUG : test/dir1: list: cached entries: [test/dir1/dir1 test/dir1/dir2 test/dir1/dir3 test/dir1/dir4]
2025/05/06 01:18:01 DEBUG : Cache remote TestInternalCache:tib21171746494251: list 'test/dir1/dir4'
2025/05/06 01:18:01 DEBUG : test/dir1/dir4: list: empty listing
2025/05/06 01:18:01 DEBUG : test/dir1/dir4: list: read 1 from source
2025/05/06 01:18:01 DEBUG : test/dir1/dir4: list: source entries: [test/dir1/dir4/test.txt]
2025/05/06 01:18:01 DEBUG : Cache remote TestInternalCache:tib21171746494251: list 'test/dir1/dir1'
2025/05/06 01:18:01 DEBUG : test/dir1/dir1: list: empty listing
2025/05/06 01:18:01 DEBUG : test/dir1/dir1: list: read 1 from source
2025/05/06 01:18:01 DEBUG : test/dir1/dir1: list: source entries: [test/dir1/dir1/test.txt]
2025/05/06 01:18:01 DEBUG : Cache remote TestInternalCache:tib21171746494251: list 'test/dir1/dir2'
2025/05/06 01:18:01 DEBUG : test/dir1/dir2: list: warm 1 from cache for: tib21171746494251/test/dir1/dir2, expiring on: 2025-05-09 01:18:01.034322597 +0000 UTC
2025/05/06 01:18:01 DEBUG : test/dir1/dir2: list: cached entries: [test/dir1/dir2/test.txt]
2025/05/06 01:18:01 DEBUG : Cache remote TestInternalCache:tib21171746494251: list 'test/dir1/dir3'
2025/05/06 01:18:01 DEBUG : test/dir1/dir3: list: empty listing
2025/05/06 01:18:01 DEBUG : test/dir1/dir3: list: read 1 from source
2025/05/06 01:18:01 DEBUG : test/dir1/dir3: list: source entries: [test/dir1/dir3/test.txt]
2025/05/06 01:18:01 DEBUG : test/dir3: list: cached directories: 4
2025/05/06 01:18:01 DEBUG : test/dir3: list: cached dir: 'tib21171746494251/test/dir3', cache ts: 2025-05-06 01:18:01.044454828 +0000 UTC m=+39.530377591
2025/05/06 01:18:01 DEBUG : Cache remote TestInternalCache:tib21171746494251: list 'test/dir3/dir3'
2025/05/06 01:18:01 DEBUG : Cache remote TestInternalCache:tib21171746494251: list 'test/dir3/dir1'
2025/05/06 01:18:01 DEBUG : test/dir3/dir1: list: empty listing
2025/05/06 01:18:01 DEBUG : test/dir3/dir3: list: empty listing
2025/05/06 01:18:01 DEBUG : test/dir3/dir1: list: read 1 from source
2025/05/06 01:18:01 DEBUG : test/dir3/dir1: list: source entries: [test/dir3/dir1/test.txt]
2025/05/06 01:18:01 DEBUG : Cache remote TestInternalCache:tib21171746494251: list 'test/dir3/dir2'
2025/05/06 01:18:01 DEBUG : test/dir3/dir2: list: empty listing
2025/05/06 01:18:01 DEBUG : test/dir3/dir2: list: read 1 from source
2025/05/06 01:18:01 DEBUG : test/dir3/dir2: list: source entries: [test/dir3/dir2/test.txt]
2025/05/06 01:18:01 DEBUG : test/dir3/dir3: list: read 1 from source
2025/05/06 01:18:01 DEBUG : test/dir3/dir3: list: source entries: [test/dir3/dir3/test.txt]
2025/05/06 01:18:01 DEBUG : test/dir2: list: cached directories: 4
2025/05/06 01:18:01 DEBUG : test/dir4: list: cached directories: 4
2025/05/06 01:18:01 DEBUG : test/dir1/dir4: list: cached object: test/dir1/dir4/test.txt
2025/05/06 01:18:01 DEBUG : test/dir1/dir4: list: cached directories: 0
2025/05/06 01:18:01 DEBUG : test/dir1/dir1: list: cached object: test/dir1/dir1/test.txt
2025/05/06 01:18:01 DEBUG : test/dir1/dir1: list: cached directories: 0
2025/05/06 01:18:01 DEBUG : test/dir1/dir2/test.txt: removing object
2025/05/06 01:18:01 DEBUG : test/dir1/dir3: list: cached object: test/dir1/dir3/test.txt
2025/05/06 01:18:01 DEBUG : test/dir1/dir3: list: cached directories: 0
2025/05/06 01:18:01 DEBUG : test/dir3/dir1: list: cached object: test/dir3/dir1/test.txt
2025/05/06 01:18:01 DEBUG : test/dir3/dir1: list: cached directories: 0
2025/05/06 01:18:01 DEBUG : test/dir3/dir2: list: cached object: test/dir3/dir2/test.txt
2025/05/06 01:18:01 DEBUG : test/dir3/dir2: list: cached directories: 0
2025/05/06 01:18:01 DEBUG : test/dir3/dir3: list: cached object: test/dir3/dir3/test.txt
2025/05/06 01:18:01 DEBUG : test/dir3/dir3: list: cached directories: 0
2025/05/06 01:18:01 DEBUG : test/dir2: list: cached dir: 'tib21171746494251/test/dir2', cache ts: 2025-05-06 01:18:01.046855463 +0000 UTC m=+39.532778245
2025/05/06 01:18:01 DEBUG : Cache remote TestInternalCache:tib21171746494251: list 'test/dir3/dir4'
2025/05/06 01:18:01 DEBUG : test/dir3/dir4: list: empty listing
2025/05/06 01:18:01 DEBUG : test/dir3/dir4: list: read 1 from source
2025/05/06 01:18:01 DEBUG : test/dir3/dir4: list: source entries: [test/dir3/dir4/test.txt]
2025/05/06 01:18:01 DEBUG : test/dir4: list: cached dir: 'tib21171746494251/test/dir4', cache ts: 2025-05-06 01:18:01.048023194 +0000 UTC m=+39.533945976
2025/05/06 01:18:01 DEBUG : Cache remote TestInternalCache:tib21171746494251: list 'test/dir2/dir1'
2025/05/06 01:18:01 DEBUG : test/dir2/dir1: list: empty listing
2025/05/06 01:18:01 DEBUG : test/dir2/dir1: list: read 1 from source
2025/05/06 01:18:01 DEBUG : test/dir2/dir1: list: source entries: [test/dir2/dir1/test.txt]
2025/05/06 01:18:01 DEBUG : test/dir1/dir4: list: cached dir: 'tib21171746494251/test/dir1/dir4', cache ts: 2025-05-06 01:18:01.049306652 +0000 UTC m=+39.535229435
2025/05/06 01:18:01 DEBUG : Cache remote TestInternalCache:tib21171746494251: list 'test/dir2/dir2'
2025/05/06 01:18:01 DEBUG : test/dir2/dir2: list: empty listing
2025/05/06 01:18:01 DEBUG : test/dir1/dir4/test.txt: removing object
2025/05/06 01:18:01 DEBUG : test/dir2/dir2: list: read 1 from source
2025/05/06 01:18:01 DEBUG : test/dir2/dir2: list: source entries: [test/dir2/dir2/test.txt]
2025/05/06 01:18:01 DEBUG : test/dir1/dir1: list: cached dir: 'tib21171746494251/test/dir1/dir1', cache ts: 2025-05-06 01:18:01.050442373 +0000 UTC m=+39.536365157
2025/05/06 01:18:01 DEBUG : Cache remote TestInternalCache:tib21171746494251: list 'test/dir2/dir3'
2025/05/06 01:18:01 DEBUG : test/dir2/dir3: list: empty listing
2025/05/06 01:18:01 DEBUG : test/dir2/dir3: list: read 1 from source
2025/05/06 01:18:01 DEBUG : test/dir2/dir3: list: source entries: [test/dir2/dir3/test.txt]
2025/05/06 01:18:01 DEBUG : test/dir1/dir1/test.txt: removing object
2025/05/06 01:18:01 DEBUG : test/dir1/dir3: list: cached dir: 'tib21171746494251/test/dir1/dir3', cache ts: 2025-05-06 01:18:01.052721119 +0000 UTC m=+39.538643913
2025/05/06 01:18:01 DEBUG : Cache remote TestInternalCache:tib21171746494251: list 'test/dir2/dir4'
2025/05/06 01:18:01 DEBUG : test/dir2/dir4: list: empty listing
2025/05/06 01:18:01 DEBUG : test/dir2/dir4: list: read 1 from source
2025/05/06 01:18:01 DEBUG : test/dir2/dir4: list: source entries: [test/dir2/dir4/test.txt]
2025/05/06 01:18:01 DEBUG : test/dir1/dir3/test.txt: removing object
2025/05/06 01:18:01 DEBUG : test/dir3/dir1: list: cached dir: 'tib21171746494251/test/dir3/dir1', cache ts: 2025-05-06 01:18:01.053800724 +0000 UTC m=+39.539723517
2025/05/06 01:18:01 DEBUG : Cache remote TestInternalCache:tib21171746494251: list 'test/dir4/dir1'
2025/05/06 01:18:01 DEBUG : test/dir4/dir1: list: empty listing
2025/05/06 01:18:01 DEBUG : test/dir4/dir1: list: read 1 from source
2025/05/06 01:18:01 DEBUG : test/dir4/dir1: list: source entries: [test/dir4/dir1/test.txt]
2025/05/06 01:18:01 DEBUG : test/dir3/dir1/test.txt: removing object
2025/05/06 01:18:01 DEBUG : test/dir3/dir2: list: cached dir: 'tib21171746494251/test/dir3/dir2', cache ts: 2025-05-06 01:18:01.055025572 +0000 UTC m=+39.540948365
2025/05/06 01:18:01 DEBUG : Cache remote TestInternalCache:tib21171746494251: list 'test/dir4/dir2'
2025/05/06 01:18:01 DEBUG : test/dir4/dir2: list: empty listing
2025/05/06 01:18:01 DEBUG : test/dir3/dir2/test.txt: removing object
2025/05/06 01:18:01 DEBUG : test/dir4/dir2: list: read 1 from source
2025/05/06 01:18:01 DEBUG : test/dir4/dir2: list: source entries: [test/dir4/dir2/test.txt]
2025/05/06 01:18:01 DEBUG : test/dir3/dir3: list: cached dir: 'tib21171746494251/test/dir3/dir3', cache ts: 2025-05-06 01:18:01.056088948 +0000 UTC m=+39.542011741
2025/05/06 01:18:01 DEBUG : Cache remote TestInternalCache:tib21171746494251: list 'test/dir4/dir3'
2025/05/06 01:18:01 DEBUG : test/dir4/dir3: list: empty listing
2025/05/06 01:18:01 DEBUG : test/dir4/dir3: list: read 1 from source
2025/05/06 01:18:01 DEBUG : test/dir4/dir3: list: source entries: [test/dir4/dir3/test.txt]
2025/05/06 01:18:01 DEBUG : test/dir3/dir3/test.txt: removing object
2025/05/06 01:18:01 DEBUG : test/dir3/dir4: list: cached object: test/dir3/dir4/test.txt
2025/05/06 01:18:01 DEBUG : test/dir3/dir4: list: cached directories: 0
2025/05/06 01:18:01 DEBUG : test/dir2/dir1: list: cached object: test/dir2/dir1/test.txt
2025/05/06 01:18:01 DEBUG : test/dir2/dir1: list: cached directories: 0
2025/05/06 01:18:01 DEBUG : test/dir2/dir2: list: cached object: test/dir2/dir2/test.txt
2025/05/06 01:18:01 DEBUG : test/dir2/dir2: list: cached directories: 0
2025/05/06 01:18:01 DEBUG : test/dir2/dir3: list: cached object: test/dir2/dir3/test.txt
2025/05/06 01:18:01 DEBUG : test/dir2/dir3: list: cached directories: 0
2025/05/06 01:18:01 DEBUG : test/dir2/dir4: list: cached object: test/dir2/dir4/test.txt
2025/05/06 01:18:01 DEBUG : test/dir2/dir4: list: cached directories: 0
2025/05/06 01:18:01 DEBUG : test/dir4/dir1: list: cached object: test/dir4/dir1/test.txt
2025/05/06 01:18:01 DEBUG : test/dir4/dir1: list: cached directories: 0
2025/05/06 01:18:01 DEBUG : test/dir4/dir2: list: cached object: test/dir4/dir2/test.txt
2025/05/06 01:18:01 DEBUG : test/dir4/dir2: list: cached directories: 0
2025/05/06 01:18:01 DEBUG : test/dir4/dir3: list: cached object: test/dir4/dir3/test.txt
2025/05/06 01:18:01 DEBUG : test/dir4/dir3: list: cached directories: 0
2025/05/06 01:18:01 DEBUG : test/dir3/dir4: list: cached dir: 'tib21171746494251/test/dir3/dir4', cache ts: 2025-05-06 01:18:01.072195631 +0000 UTC m=+39.558118434
2025/05/06 01:18:01 DEBUG : Cache remote TestInternalCache:tib21171746494251: list 'test/dir4/dir4'
2025/05/06 01:18:01 DEBUG : test/dir4/dir4: list: empty listing
2025/05/06 01:18:01 DEBUG : test/dir4/dir4: list: read 1 from source
2025/05/06 01:18:01 DEBUG : test/dir4/dir4: list: source entries: [test/dir4/dir4/test.txt]
2025/05/06 01:18:01 DEBUG : test/dir3/dir4/test.txt: removing object
2025/05/06 01:18:01 DEBUG : test/dir2/dir1: list: cached dir: 'tib21171746494251/test/dir2/dir1', cache ts: 2025-05-06 01:18:01.073946285 +0000 UTC m=+39.559869048
2025/05/06 01:18:01 DEBUG : test/dir2/dir2: list: cached dir: 'tib21171746494251/test/dir2/dir2', cache ts: 2025-05-06 01:18:01.076730058 +0000 UTC m=+39.562652831
2025/05/06 01:18:01 DEBUG : test/dir1/dir2: cache: expired tib21171746494251/test/dir1/dir2
2025/05/06 01:18:01 DEBUG : test/dir1/dir2: cache: expired tib21171746494251/test/dir1
2025/05/06 01:18:01 DEBUG : test/dir1/dir2: cache: expired tib21171746494251/test
2025/05/06 01:18:01 DEBUG : test/dir1/dir2: cache: expired tib21171746494251
2025/05/06 01:18:01 DEBUG : test/dir2/dir3: list: cached dir: 'tib21171746494251/test/dir2/dir3', cache ts: 2025-05-06 01:18:01.078043934 +0000 UTC m=+39.563966707
2025/05/06 01:18:01 INFO  : test/dir1/dir2/test.txt: Deleted
2025/05/06 01:18:01 DEBUG : test/dir2/dir1/test.txt: removing object
2025/05/06 01:18:01 DEBUG : test/dir2/dir4: list: cached dir: 'tib21171746494251/test/dir2/dir4', cache ts: 2025-05-06 01:18:01.081577574 +0000 UTC m=+39.567500356
2025/05/06 01:18:01 DEBUG : test/dir4/dir1: list: cached dir: 'tib21171746494251/test/dir4/dir1', cache ts: 2025-05-06 01:18:01.083825401 +0000 UTC m=+39.569748195
2025/05/06 01:18:01 DEBUG : test/dir4/dir2: list: cached dir: 'tib21171746494251/test/dir4/dir2', cache ts: 2025-05-06 01:18:01.087009607 +0000 UTC m=+39.572932360
2025/05/06 01:18:01 DEBUG : test/dir4/dir3: list: cached dir: 'tib21171746494251/test/dir4/dir3', cache ts: 2025-05-06 01:18:01.08782196 +0000 UTC m=+39.573744714
2025/05/06 01:18:01 DEBUG : test/dir4/dir4: list: cached object: test/dir4/dir4/test.txt
2025/05/06 01:18:01 DEBUG : test/dir4/dir4: list: cached directories: 0
2025/05/06 01:18:01 DEBUG : test/dir1/dir4: cache: expired tib21171746494251/test/dir1/dir4
2025/05/06 01:18:01 DEBUG : test/dir1/dir4: cache: expired tib21171746494251/test/dir1
2025/05/06 01:18:01 DEBUG : test/dir1/dir4: cache: expired tib21171746494251/test
2025/05/06 01:18:01 DEBUG : test/dir1/dir4: cache: expired tib21171746494251
2025/05/06 01:18:01 INFO  : test/dir1/dir4/test.txt: Deleted
2025/05/06 01:18:01 DEBUG : test/dir2/dir2/test.txt: removing object
2025/05/06 01:18:01 DEBUG : test/dir4/dir4: list: cached dir: 'tib21171746494251/test/dir4/dir4', cache ts: 2025-05-06 01:18:01.101972362 +0000 UTC m=+39.587895115
2025/05/06 01:18:01 DEBUG : test/dir1/dir1: cache: expired tib21171746494251/test/dir1/dir1
2025/05/06 01:18:01 DEBUG : test/dir1/dir1: cache: expired tib21171746494251/test/dir1
2025/05/06 01:18:01 DEBUG : test/dir1/dir1: cache: expired tib21171746494251/test
2025/05/06 01:18:01 DEBUG : test/dir1/dir1: cache: expired tib21171746494251
2025/05/06 01:18:01 INFO  : test/dir1/dir1/test.txt: Deleted
2025/05/06 01:18:01 DEBUG : test/dir2/dir3/test.txt: removing object
2025/05/06 01:18:01 DEBUG : test/dir1/dir3: cache: expired tib21171746494251/test/dir1/dir3
2025/05/06 01:18:01 DEBUG : test/dir1/dir3: cache: expired tib21171746494251/test/dir1
2025/05/06 01:18:01 DEBUG : test/dir1/dir3: cache: expired tib21171746494251/test
2025/05/06 01:18:01 DEBUG : test/dir1/dir3: cache: expired tib21171746494251
2025/05/06 01:18:01 INFO  : test/dir1/dir3/test.txt: Deleted
2025/05/06 01:18:01 DEBUG : test/dir2/dir4/test.txt: removing object
2025/05/06 01:18:01 DEBUG : test/dir3/dir1: cache: expired tib21171746494251/test/dir3/dir1
2025/05/06 01:18:01 DEBUG : test/dir3/dir1: cache: expired tib21171746494251/test/dir3
2025/05/06 01:18:01 DEBUG : test/dir3/dir1: cache: expired tib21171746494251/test
2025/05/06 01:18:01 DEBUG : test/dir3/dir1: cache: expired tib21171746494251
2025/05/06 01:18:01 INFO  : test/dir3/dir1/test.txt: Deleted
2025/05/06 01:18:01 DEBUG : test/dir4/dir1/test.txt: removing object
2025/05/06 01:18:01 DEBUG : test/dir3/dir2: cache: expired tib21171746494251/test/dir3/dir2
2025/05/06 01:18:01 DEBUG : test/dir3/dir2: cache: expired tib21171746494251/test/dir3
2025/05/06 01:18:01 DEBUG : test/dir3/dir2: cache: expired tib21171746494251/test
2025/05/06 01:18:01 DEBUG : test/dir3/dir2: cache: expired tib21171746494251
2025/05/06 01:18:01 INFO  : test/dir3/dir2/test.txt: Deleted
2025/05/06 01:18:01 DEBUG : test/dir4/dir2/test.txt: removing object
2025/05/06 01:18:01 DEBUG : test/dir3/dir3: cache: expired tib21171746494251/test/dir3/dir3
2025/05/06 01:18:01 DEBUG : test/dir3/dir3: cache: expired tib21171746494251/test/dir3
2025/05/06 01:18:01 DEBUG : test/dir3/dir3: cache: expired tib21171746494251/test
2025/05/06 01:18:01 DEBUG : test/dir3/dir3: cache: expired tib21171746494251
2025/05/06 01:18:01 INFO  : test/dir3/dir3/test.txt: Deleted
2025/05/06 01:18:01 DEBUG : test/dir4/dir3/test.txt: removing object
2025/05/06 01:18:01 DEBUG : test/dir3/dir4: cache: expired tib21171746494251/test/dir3/dir4
2025/05/06 01:18:01 DEBUG : test/dir3/dir4: cache: expired tib21171746494251/test/dir3
2025/05/06 01:18:01 DEBUG : test/dir3/dir4: cache: expired tib21171746494251/test
2025/05/06 01:18:01 DEBUG : test/dir3/dir4: cache: expired tib21171746494251
2025/05/06 01:18:01 INFO  : test/dir3/dir4/test.txt: Deleted
2025/05/06 01:18:01 DEBUG : test/dir4/dir4/test.txt: removing object
2025/05/06 01:18:01 DEBUG : test/dir2/dir1: cache: expired tib21171746494251/test/dir2/dir1
2025/05/06 01:18:01 DEBUG : test/dir2/dir1: cache: expired tib21171746494251/test/dir2
2025/05/06 01:18:01 DEBUG : test/dir2/dir1: cache: expired tib21171746494251/test
2025/05/06 01:18:01 DEBUG : test/dir2/dir1: cache: expired tib21171746494251
2025/05/06 01:18:01 INFO  : test/dir2/dir1/test.txt: Deleted
2025/05/06 01:18:01 DEBUG : test/dir2/dir2: cache: expired tib21171746494251/test/dir2/dir2
2025/05/06 01:18:01 DEBUG : test/dir2/dir2: cache: expired tib21171746494251/test/dir2
2025/05/06 01:18:01 DEBUG : test/dir2/dir2: cache: expired tib21171746494251/test
2025/05/06 01:18:01 DEBUG : test/dir2/dir2: cache: expired tib21171746494251
2025/05/06 01:18:01 INFO  : test/dir2/dir2/test.txt: Deleted
2025/05/06 01:18:01 DEBUG : test/dir2/dir3: cache: expired tib21171746494251/test/dir2/dir3
2025/05/06 01:18:01 DEBUG : test/dir2/dir3: cache: expired tib21171746494251/test/dir2
2025/05/06 01:18:01 DEBUG : test/dir2/dir3: cache: expired tib21171746494251/test
2025/05/06 01:18:01 DEBUG : test/dir2/dir3: cache: expired tib21171746494251
2025/05/06 01:18:01 INFO  : test/dir2/dir3/test.txt: Deleted
2025/05/06 01:18:01 DEBUG : test/dir2/dir4: cache: expired tib21171746494251/test/dir2/dir4
2025/05/06 01:18:01 DEBUG : test/dir2/dir4: cache: expired tib21171746494251/test/dir2
2025/05/06 01:18:01 DEBUG : test/dir2/dir4: cache: expired tib21171746494251/test
2025/05/06 01:18:01 DEBUG : test/dir2/dir4: cache: expired tib21171746494251
2025/05/06 01:18:01 INFO  : test/dir2/dir4/test.txt: Deleted
2025/05/06 01:18:01 DEBUG : test/dir4/dir1: cache: expired tib21171746494251/test/dir4/dir1
2025/05/06 01:18:01 DEBUG : test/dir4/dir1: cache: expired tib21171746494251/test/dir4
2025/05/06 01:18:01 DEBUG : test/dir4/dir1: cache: expired tib21171746494251/test
2025/05/06 01:18:01 DEBUG : test/dir4/dir1: cache: expired tib21171746494251
2025/05/06 01:18:01 INFO  : test/dir4/dir1/test.txt: Deleted
2025/05/06 01:18:01 DEBUG : test/dir4/dir2: cache: expired tib21171746494251/test/dir4/dir2
2025/05/06 01:18:01 DEBUG : test/dir4/dir2: cache: expired tib21171746494251/test/dir4
2025/05/06 01:18:01 DEBUG : test/dir4/dir2: cache: expired tib21171746494251/test
2025/05/06 01:18:01 DEBUG : test/dir4/dir2: cache: expired tib21171746494251
2025/05/06 01:18:01 INFO  : test/dir4/dir2/test.txt: Deleted
2025/05/06 01:18:01 DEBUG : test/dir4/dir3: cache: expired tib21171746494251/test/dir4/dir3
2025/05/06 01:18:01 DEBUG : test/dir4/dir3: cache: expired tib21171746494251/test/dir4
2025/05/06 01:18:01 DEBUG : test/dir4/dir3: cache: expired tib21171746494251/test
2025/05/06 01:18:01 DEBUG : test/dir4/dir3: cache: expired tib21171746494251
2025/05/06 01:18:01 INFO  : test/dir4/dir3/test.txt: Deleted
2025/05/06 01:18:01 DEBUG : test/dir4/dir4: cache: expired tib21171746494251/test/dir4/dir4
2025/05/06 01:18:01 DEBUG : test/dir4/dir4: cache: expired tib21171746494251/test/dir4
2025/05/06 01:18:01 DEBUG : test/dir4/dir4: cache: expired tib21171746494251/test
2025/05/06 01:18:01 DEBUG : test/dir4/dir4: cache: expired tib21171746494251
2025/05/06 01:18:01 INFO  : test/dir4/dir4/test.txt: Deleted
2025/05/06 01:18:01 DEBUG : Cache remote TestInternalCache:tib21171746494251: list ''
2025/05/06 01:18:01 DEBUG : : list: cold listing: 2025-05-03 01:18:01.1316087 +0000 UTC
2025/05/06 01:18:01 DEBUG : : list: read 1 from source
2025/05/06 01:18:01 DEBUG : : list: source entries: [test]
2025/05/06 01:18:01 DEBUG : : list: cached directories: 0
2025/05/06 01:18:01 DEBUG : : list: cached dir: 'tib21171746494251', cache ts: 2025-05-06 01:18:01.132495795 +0000 UTC m=+39.618418548
2025/05/06 01:18:01 DEBUG : Cache remote TestInternalCache:tib21171746494251: list 'test'
2025/05/06 01:18:01 DEBUG : test: list: cold listing: 2025-05-03 01:18:01.1316087 +0000 UTC
2025/05/06 01:18:01 DEBUG : test: list: read 4 from source
2025/05/06 01:18:01 DEBUG : test: list: source entries: [test/dir3 test/dir2 test/dir4 test/dir1]
2025/05/06 01:18:01 DEBUG : test: list: cached directories: 0
2025/05/06 01:18:01 DEBUG : test: list: cached dir: 'tib21171746494251/test', cache ts: 2025-05-06 01:18:01.13338866 +0000 UTC m=+39.619311413
2025/05/06 01:18:01 DEBUG : Cache remote TestInternalCache:tib21171746494251: list 'test/dir4'
2025/05/06 01:18:01 DEBUG : test/dir4: list: cold listing: 2025-05-03 01:18:01.1316087 +0000 UTC
2025/05/06 01:18:01 DEBUG : Cache remote TestInternalCache:tib21171746494251: list 'test/dir2'
2025/05/06 01:18:01 DEBUG : Cache remote TestInternalCache:tib21171746494251: list 'test/dir3'
2025/05/06 01:18:01 DEBUG : test/dir3: list: cold listing: 2025-05-03 01:18:01.118675944 +0000 UTC
2025/05/06 01:18:01 DEBUG : test/dir3: list: read 4 from source
2025/05/06 01:18:01 DEBUG : test/dir3: list: source entries: [test/dir3/dir3 test/dir3/dir2 test/dir3/dir4 test/dir3/dir1]
2025/05/06 01:18:01 DEBUG : test/dir3: list: cached directories: 0
2025/05/06 01:18:01 DEBUG : test/dir2: list: cold listing: 2025-05-03 01:18:01.125576562 +0000 UTC
2025/05/06 01:18:01 DEBUG : test/dir2: list: read 4 from source
2025/05/06 01:18:01 DEBUG : test/dir2: list: source entries: [test/dir2/dir3 test/dir2/dir2 test/dir2/dir4 test/dir2/dir1]
2025/05/06 01:18:01 DEBUG : test/dir2: list: cached directories: 0
2025/05/06 01:18:01 DEBUG : test/dir4: list: read 4 from source
2025/05/06 01:18:01 DEBUG : test/dir4: list: source entries: [test/dir4/dir3 test/dir4/dir2 test/dir4/dir4 test/dir4/dir1]
2025/05/06 01:18:01 DEBUG : test/dir4: list: cached directories: 0
2025/05/06 01:18:01 DEBUG : Cache remote TestInternalCache:tib21171746494251: list 'test/dir1'
2025/05/06 01:18:01 DEBUG : test/dir1: list: cold listing: 2025-05-03 01:18:01.10891568 +0000 UTC
2025/05/06 01:18:01 DEBUG : test/dir3: list: cached dir: 'tib21171746494251/test/dir3', cache ts: 2025-05-06 01:18:01.134364301 +0000 UTC m=+39.620287053
2025/05/06 01:18:01 DEBUG : Cache remote TestInternalCache:tib21171746494251: list 'test/dir3/dir4'
2025/05/06 01:18:01 DEBUG : test/dir3/dir4: list: cold listing: 2025-05-03 01:18:01.118675944 +0000 UTC
2025/05/06 01:18:01 DEBUG : test/dir3/dir4: list: read 0 from source
2025/05/06 01:18:01 DEBUG : test/dir1: list: read 4 from source
2025/05/06 01:18:01 DEBUG : test/dir1: list: source entries: [test/dir1/dir3 test/dir1/dir2 test/dir1/dir4 test/dir1/dir1]
2025/05/06 01:18:01 DEBUG : test/dir1: list: cached directories: 0
2025/05/06 01:18:01 DEBUG : test/dir3/dir4: list: source entries: []
2025/05/06 01:18:01 DEBUG : test/dir3/dir4: list: cached directories: 0
2025/05/06 01:18:01 DEBUG : Cache remote TestInternalCache:tib21171746494251: list 'test/dir3/dir2'
2025/05/06 01:18:01 DEBUG : test/dir3/dir2: list: cold listing: 2025-05-03 01:18:01.114332484 +0000 UTC
2025/05/06 01:18:01 DEBUG : test/dir3/dir2: list: read 0 from source
2025/05/06 01:18:01 DEBUG : test/dir3/dir2: list: source entries: []
2025/05/06 01:18:01 DEBUG : test/dir3/dir2: list: cached directories: 0
2025/05/06 01:18:01 DEBUG : Cache remote TestInternalCache:tib21171746494251: list 'test/dir3/dir1'
2025/05/06 01:18:01 DEBUG : test/dir3/dir1: list: cold listing: 2025-05-03 01:18:01.11179895 +0000 UTC
2025/05/06 01:18:01 DEBUG : test/dir3/dir1: list: read 0 from source
2025/05/06 01:18:01 DEBUG : test/dir3/dir1: list: source entries: []
2025/05/06 01:18:01 DEBUG : test/dir3/dir1: list: cached directories: 0
2025/05/06 01:18:01 DEBUG : Cache remote TestInternalCache:tib21171746494251: list 'test/dir3/dir3'
2025/05/06 01:18:01 DEBUG : test/dir3/dir3: list: cold listing: 2025-05-03 01:18:01.116559292 +0000 UTC
2025/05/06 01:18:01 DEBUG : test/dir3/dir3: list: read 0 from source
2025/05/06 01:18:01 DEBUG : test/dir3/dir3: list: source entries: []
2025/05/06 01:18:01 DEBUG : test/dir3/dir3: list: cached directories: 0
2025/05/06 01:18:01 DEBUG : test/dir2: list: cached dir: 'tib21171746494251/test/dir2', cache ts: 2025-05-06 01:18:01.134721841 +0000 UTC m=+39.620644634
2025/05/06 01:18:01 DEBUG : Cache remote TestInternalCache:tib21171746494251: list 'test/dir2/dir2'
2025/05/06 01:18:01 DEBUG : test/dir2/dir2: list: cold listing: 2025-05-03 01:18:01.12270308 +0000 UTC
2025/05/06 01:18:01 DEBUG : test/dir2/dir2: list: read 0 from source
2025/05/06 01:18:01 DEBUG : test/dir2/dir2: list: source entries: []
2025/05/06 01:18:01 DEBUG : test/dir2/dir2: list: cached directories: 0
2025/05/06 01:18:01 DEBUG : Cache remote TestInternalCache:tib21171746494251: list 'test/dir2/dir1'
2025/05/06 01:18:01 DEBUG : test/dir2/dir1: list: cold listing: 2025-05-03 01:18:01.120733584 +0000 UTC
2025/05/06 01:18:01 DEBUG : test/dir2/dir1: list: read 0 from source
2025/05/06 01:18:01 DEBUG : test/dir2/dir1: list: source entries: []
2025/05/06 01:18:01 DEBUG : test/dir2/dir1: list: cached directories: 0
2025/05/06 01:18:01 DEBUG : test/dir2/dir2: list: cached dir: 'tib21171746494251/test/dir2/dir2', cache ts: 2025-05-06 01:18:01.136064201 +0000 UTC m=+39.621986954
2025/05/06 01:18:01 DEBUG : Cache remote TestInternalCache:tib21171746494251: list 'test/dir2/dir3'
2025/05/06 01:18:01 DEBUG : test/dir2/dir3: list: cold listing: 2025-05-03 01:18:01.124219856 +0000 UTC
2025/05/06 01:18:01 DEBUG : test/dir2/dir3: list: read 0 from source
2025/05/06 01:18:01 DEBUG : test/dir2/dir3: list: source entries: []
2025/05/06 01:18:01 DEBUG : test/dir2/dir3: list: cached directories: 0
2025/05/06 01:18:01 DEBUG : test/dir4: list: cached dir: 'tib21171746494251/test/dir4', cache ts: 2025-05-06 01:18:01.134878526 +0000 UTC m=+39.620801319
2025/05/06 01:18:01 DEBUG : Cache remote TestInternalCache:tib21171746494251: list 'test/dir2/dir4'
2025/05/06 01:18:01 DEBUG : test/dir2/dir4: list: cold listing: 2025-05-03 01:18:01.125576562 +0000 UTC
2025/05/06 01:18:01 DEBUG : test/dir2/dir4: list: read 0 from source
2025/05/06 01:18:01 DEBUG : test/dir2/dir4: list: source entries: []
2025/05/06 01:18:01 DEBUG : test/dir2/dir4: list: cached directories: 0
2025/05/06 01:18:01 DEBUG : test/dir1: list: cached dir: 'tib21171746494251/test/dir1', cache ts: 2025-05-06 01:18:01.135263649 +0000 UTC m=+39.621186431
2025/05/06 01:18:01 DEBUG : Cache remote TestInternalCache:tib21171746494251: list 'test/dir4/dir1'
2025/05/06 01:18:01 DEBUG : test/dir4/dir1: list: cold listing: 2025-05-03 01:18:01.127099349 +0000 UTC
2025/05/06 01:18:01 DEBUG : test/dir4/dir1: list: read 0 from source
2025/05/06 01:18:01 DEBUG : test/dir4/dir1: list: source entries: []
2025/05/06 01:18:01 DEBUG : test/dir4/dir1: list: cached directories: 0
2025/05/06 01:18:01 DEBUG : test/dir3/dir4: list: cached dir: 'tib21171746494251/test/dir3/dir4', cache ts: 2025-05-06 01:18:01.135275851 +0000 UTC m=+39.621198644
2025/05/06 01:18:01 DEBUG : Cache remote TestInternalCache:tib21171746494251: list 'test/dir4/dir2'
2025/05/06 01:18:01 DEBUG : test/dir4/dir2: list: cold listing: 2025-05-03 01:18:01.128715822 +0000 UTC
2025/05/06 01:18:01 DEBUG : test/dir4/dir2: list: read 0 from source
2025/05/06 01:18:01 DEBUG : test/dir4/dir2: list: source entries: []
2025/05/06 01:18:01 DEBUG : test/dir4/dir2: list: cached directories: 0
2025/05/06 01:18:01 DEBUG : test/dir3/dir2: list: cached dir: 'tib21171746494251/test/dir3/dir2', cache ts: 2025-05-06 01:18:01.135456831 +0000 UTC m=+39.621379614
2025/05/06 01:18:01 DEBUG : Cache remote TestInternalCache:tib21171746494251: list 'test/dir4/dir3'
2025/05/06 01:18:01 DEBUG : test/dir4/dir3: list: cold listing: 2025-05-03 01:18:01.130219323 +0000 UTC
2025/05/06 01:18:01 DEBUG : test/dir4/dir3: list: read 0 from source
2025/05/06 01:18:01 DEBUG : test/dir4/dir3: list: source entries: []
2025/05/06 01:18:01 DEBUG : test/dir4/dir3: list: cached directories: 0
2025/05/06 01:18:01 DEBUG : test/dir3/dir1: list: cached dir: 'tib21171746494251/test/dir3/dir1', cache ts: 2025-05-06 01:18:01.135626429 +0000 UTC m=+39.621549212
2025/05/06 01:18:01 DEBUG : Cache remote TestInternalCache:tib21171746494251: list 'test/dir4/dir4'
2025/05/06 01:18:01 DEBUG : test/dir4/dir4: list: cold listing: 2025-05-03 01:18:01.1316087 +0000 UTC
2025/05/06 01:18:01 DEBUG : test/dir4/dir4: list: read 0 from source
2025/05/06 01:18:01 DEBUG : test/dir4/dir4: list: source entries: []
2025/05/06 01:18:01 DEBUG : test/dir4/dir4: list: cached directories: 0
2025/05/06 01:18:01 DEBUG : test/dir3/dir3: list: cached dir: 'tib21171746494251/test/dir3/dir3', cache ts: 2025-05-06 01:18:01.135811345 +0000 UTC m=+39.621734129
2025/05/06 01:18:01 DEBUG : Cache remote TestInternalCache:tib21171746494251: list 'test/dir1/dir1'
2025/05/06 01:18:01 DEBUG : test/dir1/dir1: list: cold listing: 2025-05-03 01:18:01.105386087 +0000 UTC
2025/05/06 01:18:01 DEBUG : test/dir1/dir1: list: read 0 from source
2025/05/06 01:18:01 DEBUG : test/dir1/dir1: list: source entries: []
2025/05/06 01:18:01 DEBUG : test/dir1/dir1: list: cached directories: 0
2025/05/06 01:18:01 DEBUG : test/dir2/dir1: list: cached dir: 'tib21171746494251/test/dir2/dir1', cache ts: 2025-05-06 01:18:01.136340389 +0000 UTC m=+39.622263182
2025/05/06 01:18:01 DEBUG : Cache remote TestInternalCache:tib21171746494251: list 'test/dir1/dir2'
2025/05/06 01:18:01 DEBUG : test/dir1/dir2: list: cold listing: 2025-05-03 01:18:01.080406957 +0000 UTC
2025/05/06 01:18:01 DEBUG : test/dir1/dir2: list: read 0 from source
2025/05/06 01:18:01 DEBUG : test/dir1/dir2: list: source entries: []
2025/05/06 01:18:01 DEBUG : test/dir1/dir2: list: cached directories: 0
2025/05/06 01:18:01 DEBUG : test/dir2/dir3: list: cached dir: 'tib21171746494251/test/dir2/dir3', cache ts: 2025-05-06 01:18:01.137148795 +0000 UTC m=+39.623071578
2025/05/06 01:18:01 DEBUG : Cache remote TestInternalCache:tib21171746494251: list 'test/dir1/dir3'
2025/05/06 01:18:01 DEBUG : test/dir1/dir3: list: cold listing: 2025-05-03 01:18:01.10891568 +0000 UTC
2025/05/06 01:18:01 DEBUG : test/dir1/dir3: list: read 0 from source
2025/05/06 01:18:01 DEBUG : test/dir1/dir3: list: source entries: []
2025/05/06 01:18:01 DEBUG : test/dir1/dir3: list: cached directories: 0
2025/05/06 01:18:01 DEBUG : test/dir2/dir4: list: cached dir: 'tib21171746494251/test/dir2/dir4', cache ts: 2025-05-06 01:18:01.138134245 +0000 UTC m=+39.624057027
2025/05/06 01:18:01 DEBUG : Cache remote TestInternalCache:tib21171746494251: list 'test/dir1/dir4'
2025/05/06 01:18:01 DEBUG : test/dir1/dir4: list: cold listing: 2025-05-03 01:18:01.096757608 +0000 UTC
2025/05/06 01:18:01 DEBUG : test/dir1/dir4: list: read 0 from source
2025/05/06 01:18:01 DEBUG : test/dir1/dir4: list: source entries: []
2025/05/06 01:18:01 DEBUG : test/dir1/dir4: list: cached directories: 0
2025/05/06 01:18:01 DEBUG : test/dir4/dir1: list: cached dir: 'tib21171746494251/test/dir4/dir1', cache ts: 2025-05-06 01:18:01.139155751 +0000 UTC m=+39.625078535
2025/05/06 01:18:01 DEBUG : test/dir4/dir2: list: cached dir: 'tib21171746494251/test/dir4/dir2', cache ts: 2025-05-06 01:18:01.139826139 +0000 UTC m=+39.625748942
2025/05/06 01:18:01 DEBUG : test/dir4/dir3: list: cached dir: 'tib21171746494251/test/dir4/dir3', cache ts: 2025-05-06 01:18:01.140526153 +0000 UTC m=+39.626448936
2025/05/06 01:18:01 DEBUG : test/dir4/dir4: list: cached dir: 'tib21171746494251/test/dir4/dir4', cache ts: 2025-05-06 01:18:01.141306216 +0000 UTC m=+39.627228999
2025/05/06 01:18:01 DEBUG : test/dir1/dir1: list: cached dir: 'tib21171746494251/test/dir1/dir1', cache ts: 2025-05-06 01:18:01.142140492 +0000 UTC m=+39.628063284
2025/05/06 01:18:01 DEBUG : test/dir1/dir2: list: cached dir: 'tib21171746494251/test/dir1/dir2', cache ts: 2025-05-06 01:18:01.145537246 +0000 UTC m=+39.631460039
2025/05/06 01:18:01 DEBUG : test/dir1/dir3: list: cached dir: 'tib21171746494251/test/dir1/dir3', cache ts: 2025-05-06 01:18:01.146314363 +0000 UTC m=+39.632237147
2025/05/06 01:18:01 DEBUG : test/dir1/dir4: list: cached dir: 'tib21171746494251/test/dir1/dir4', cache ts: 2025-05-06 01:18:01.147214342 +0000 UTC m=+39.633137136
2025/05/06 01:18:01 DEBUG : removing 16 level 3 directories
2025/05/06 01:18:01 INFO  : test/dir2/dir4: Removing directory
2025/05/06 01:18:01 DEBUG : Cache remote TestInternalCache:tib21171746494251: rmdir 'test/dir2/dir4'
2025/05/06 01:18:01 INFO  : test/dir1/dir4: Removing directory
2025/05/06 01:18:01 DEBUG : Cache remote TestInternalCache:tib21171746494251: rmdir 'test/dir1/dir4'
2025/05/06 01:18:01 DEBUG : test/dir2/dir4: rmdir: removed dir in source fs
2025/05/06 01:18:01 DEBUG : test/dir1/dir4: rmdir: removed dir in source fs
2025/05/06 01:18:01 INFO  : test/dir1/dir1: Removing directory
2025/05/06 01:18:01 DEBUG : Cache remote TestInternalCache:tib21171746494251: rmdir 'test/dir1/dir1'
2025/05/06 01:18:01 INFO  : test/dir1/dir3: Removing directory
2025/05/06 01:18:01 DEBUG : Cache remote TestInternalCache:tib21171746494251: rmdir 'test/dir1/dir3'
2025/05/06 01:18:01 DEBUG : test/dir1/dir1: rmdir: removed dir in source fs
2025/05/06 01:18:01 INFO  : test/dir2/dir2: Removing directory
2025/05/06 01:18:01 DEBUG : Cache remote TestInternalCache:tib21171746494251: rmdir 'test/dir2/dir2'
2025/05/06 01:18:01 INFO  : test/dir2/dir3: Removing directory
2025/05/06 01:18:01 DEBUG : Cache remote TestInternalCache:tib21171746494251: rmdir 'test/dir2/dir3'
2025/05/06 01:18:01 DEBUG : test/dir2/dir2: rmdir: removed dir in source fs
2025/05/06 01:18:01 DEBUG : test/dir1/dir3: rmdir: removed dir in source fs
2025/05/06 01:18:01 INFO  : test/dir2/dir1: Removing directory
2025/05/06 01:18:01 DEBUG : Cache remote TestInternalCache:tib21171746494251: rmdir 'test/dir2/dir1'
2025/05/06 01:18:01 DEBUG : test/dir2/dir3: rmdir: removed dir in source fs
2025/05/06 01:18:01 DEBUG : test/dir2/dir1: rmdir: removed dir in source fs
2025/05/06 01:18:01 INFO  : test/dir1/dir2: Removing directory
2025/05/06 01:18:01 DEBUG : Cache remote TestInternalCache:tib21171746494251: rmdir 'test/dir1/dir2'
2025/05/06 01:18:01 DEBUG : test/dir1/dir2: rmdir: removed dir in source fs
2025/05/06 01:18:01 DEBUG : test/dir2/dir4: rmdir: removed from cache
2025/05/06 01:18:01 DEBUG : test/dir2: cache: expired tib21171746494251/test/dir2
2025/05/06 01:18:01 DEBUG : test/dir2: cache: expired tib21171746494251/test
2025/05/06 01:18:01 DEBUG : test/dir2: cache: expired tib21171746494251
2025/05/06 01:18:01 INFO  : test/dir2: rmdir: cache expired
2025/05/06 01:18:01 INFO  : test/dir3/dir1: Removing directory
2025/05/06 01:18:01 DEBUG : Cache remote TestInternalCache:tib21171746494251: rmdir 'test/dir3/dir1'
2025/05/06 01:18:01 DEBUG : test/dir3/dir1: rmdir: removed dir in source fs
2025/05/06 01:18:01 DEBUG : test/dir1/dir4: rmdir: removed from cache
2025/05/06 01:18:01 DEBUG : test/dir1/dir1: rmdir: removed from cache
2025/05/06 01:18:01 DEBUG : test/dir1: cache: expired tib21171746494251/test/dir1
2025/05/06 01:18:01 DEBUG : test/dir1: cache: expired tib21171746494251/test
2025/05/06 01:18:01 DEBUG : test/dir1: cache: expired tib21171746494251
2025/05/06 01:18:01 INFO  : test/dir1: rmdir: cache expired
2025/05/06 01:18:01 INFO  : test/dir3/dir2: Removing directory
2025/05/06 01:18:01 DEBUG : Cache remote TestInternalCache:tib21171746494251: rmdir 'test/dir3/dir2'
2025/05/06 01:18:01 DEBUG : test/dir3/dir2: rmdir: removed dir in source fs
2025/05/06 01:18:01 DEBUG : test/dir2/dir2: rmdir: removed from cache
2025/05/06 01:18:01 DEBUG : test/dir1/dir3: rmdir: removed from cache
2025/05/06 01:18:01 DEBUG : test/dir2/dir3: rmdir: removed from cache
2025/05/06 01:18:01 DEBUG : test/dir2/dir1: rmdir: removed from cache
2025/05/06 01:18:01 DEBUG : test/dir1/dir2: rmdir: removed from cache
2025/05/06 01:18:01 DEBUG : test/dir3/dir1: rmdir: removed from cache
2025/05/06 01:18:01 DEBUG : test/dir1: cache: expired tib21171746494251/test/dir1
2025/05/06 01:18:01 DEBUG : test/dir1: cache: expired tib21171746494251/test
2025/05/06 01:18:01 DEBUG : test/dir1: cache: expired tib21171746494251
2025/05/06 01:18:01 INFO  : test/dir1: rmdir: cache expired
2025/05/06 01:18:01 INFO  : test/dir3/dir3: Removing directory
2025/05/06 01:18:01 DEBUG : Cache remote TestInternalCache:tib21171746494251: rmdir 'test/dir3/dir3'
2025/05/06 01:18:01 DEBUG : test/dir3/dir3: rmdir: removed dir in source fs
2025/05/06 01:18:01 DEBUG : test/dir3/dir2: rmdir: removed from cache
2025/05/06 01:18:01 DEBUG : test/dir2: cache: expired tib21171746494251/test/dir2
2025/05/06 01:18:01 DEBUG : test/dir2: cache: expired tib21171746494251/test
2025/05/06 01:18:01 DEBUG : test/dir2: cache: expired tib21171746494251
2025/05/06 01:18:01 INFO  : test/dir2: rmdir: cache expired
2025/05/06 01:18:01 DEBUG : test/dir1: cache: expired tib21171746494251/test/dir1
2025/05/06 01:18:01 INFO  : test/dir3/dir4: Removing directory
2025/05/06 01:18:01 DEBUG : test/dir1: cache: expired tib21171746494251/test
2025/05/06 01:18:01 DEBUG : test/dir1: cache: expired tib21171746494251
2025/05/06 01:18:01 DEBUG : Cache remote TestInternalCache:tib21171746494251: rmdir 'test/dir3/dir4'
2025/05/06 01:18:01 DEBUG : test/dir3/dir4: rmdir: removed dir in source fs
2025/05/06 01:18:01 DEBUG : test/dir2: cache: expired tib21171746494251/test/dir2
2025/05/06 01:18:01 DEBUG : test/dir2: cache: expired tib21171746494251/test
2025/05/06 01:18:01 DEBUG : test/dir2: cache: expired tib21171746494251
2025/05/06 01:18:01 INFO  : test/dir1: rmdir: cache expired
2025/05/06 01:18:01 INFO  : test/dir4/dir1: Removing directory
2025/05/06 01:18:01 DEBUG : Cache remote TestInternalCache:tib21171746494251: rmdir 'test/dir4/dir1'
2025/05/06 01:18:01 DEBUG : test/dir4/dir1: rmdir: removed dir in source fs
2025/05/06 01:18:01 DEBUG : test/dir2: cache: expired tib21171746494251/test/dir2
2025/05/06 01:18:01 DEBUG : test/dir2: cache: expired tib21171746494251/test
2025/05/06 01:18:01 DEBUG : test/dir2: cache: expired tib21171746494251
2025/05/06 01:18:01 INFO  : test/dir2: rmdir: cache expired
2025/05/06 01:18:01 INFO  : test/dir4/dir2: Removing directory
2025/05/06 01:18:01 DEBUG : Cache remote TestInternalCache:tib21171746494251: rmdir 'test/dir4/dir2'
2025/05/06 01:18:01 DEBUG : test/dir4/dir2: rmdir: removed dir in source fs
2025/05/06 01:18:01 DEBUG : test/dir1: cache: expired tib21171746494251/test/dir1
2025/05/06 01:18:01 INFO  : test/dir2: rmdir: cache expired
2025/05/06 01:18:01 DEBUG : test/dir1: cache: expired tib21171746494251/test
2025/05/06 01:18:01 INFO  : test/dir4/dir3: Removing directory
2025/05/06 01:18:01 DEBUG : Cache remote TestInternalCache:tib21171746494251: rmdir 'test/dir4/dir3'
2025/05/06 01:18:01 DEBUG : test/dir1: cache: expired tib21171746494251
2025/05/06 01:18:01 DEBUG : test/dir4/dir3: rmdir: removed dir in source fs
2025/05/06 01:18:01 DEBUG : test/dir3: cache: expired tib21171746494251/test/dir3
2025/05/06 01:18:01 DEBUG : test/dir3: cache: expired tib21171746494251/test
2025/05/06 01:18:01 INFO  : test/dir1: rmdir: cache expired
2025/05/06 01:18:01 DEBUG : test/dir3: cache: expired tib21171746494251
2025/05/06 01:18:01 INFO  : test/dir4/dir4: Removing directory
2025/05/06 01:18:01 DEBUG : Cache remote TestInternalCache:tib21171746494251: rmdir 'test/dir4/dir4'
2025/05/06 01:18:01 DEBUG : test/dir4/dir4: rmdir: removed dir in source fs
2025/05/06 01:18:01 INFO  : test/dir3: rmdir: cache expired
2025/05/06 01:18:01 DEBUG : test/dir3: cache: expired tib21171746494251/test/dir3
2025/05/06 01:18:01 DEBUG : test/dir3: cache: expired tib21171746494251/test
2025/05/06 01:18:01 DEBUG : test/dir3/dir3: rmdir: removed from cache
2025/05/06 01:18:01 DEBUG : test/dir3: cache: expired tib21171746494251
2025/05/06 01:18:01 INFO  : test/dir3: rmdir: cache expired
2025/05/06 01:18:01 DEBUG : test/dir3/dir4: rmdir: removed from cache
2025/05/06 01:18:01 DEBUG : test/dir4/dir1: rmdir: removed from cache
2025/05/06 01:18:01 DEBUG : test/dir4/dir2: rmdir: removed from cache
2025/05/06 01:18:01 DEBUG : test/dir4/dir3: rmdir: removed from cache
2025/05/06 01:18:01 DEBUG : test/dir3: cache: expired tib21171746494251/test/dir3
2025/05/06 01:18:01 DEBUG : test/dir4/dir4: rmdir: removed from cache
2025/05/06 01:18:01 DEBUG : test/dir3: cache: expired tib21171746494251/test
2025/05/06 01:18:01 DEBUG : test/dir3: cache: expired tib21171746494251
2025/05/06 01:18:01 DEBUG : test/dir3: cache: expired tib21171746494251/test/dir3
2025/05/06 01:18:01 INFO  : test/dir3: rmdir: cache expired
2025/05/06 01:18:01 DEBUG : test/dir3: cache: expired tib21171746494251/test
2025/05/06 01:18:01 DEBUG : test/dir3: cache: expired tib21171746494251
2025/05/06 01:18:01 DEBUG : test/dir4: cache: expired tib21171746494251/test/dir4
2025/05/06 01:18:01 INFO  : test/dir3: rmdir: cache expired
2025/05/06 01:18:01 DEBUG : test/dir4: cache: expired tib21171746494251/test
2025/05/06 01:18:01 DEBUG : test/dir4: cache: expired tib21171746494251
2025/05/06 01:18:01 DEBUG : test/dir4: cache: expired tib21171746494251/test/dir4
2025/05/06 01:18:01 DEBUG : test/dir4: cache: expired tib21171746494251/test
2025/05/06 01:18:01 INFO  : test/dir4: rmdir: cache expired
2025/05/06 01:18:01 DEBUG : test/dir4: cache: expired tib21171746494251
2025/05/06 01:18:01 INFO  : test/dir4: rmdir: cache expired
2025/05/06 01:18:01 DEBUG : test/dir4: cache: expired tib21171746494251/test/dir4
2025/05/06 01:18:01 DEBUG : test/dir4: cache: expired tib21171746494251/test
2025/05/06 01:18:01 DEBUG : test/dir4: cache: expired tib21171746494251
2025/05/06 01:18:01 DEBUG : test/dir4: cache: expired tib21171746494251/test/dir4
2025/05/06 01:18:01 INFO  : test/dir4: rmdir: cache expired
2025/05/06 01:18:01 DEBUG : test/dir4: cache: expired tib21171746494251/test
2025/05/06 01:18:01 DEBUG : test/dir4: cache: expired tib21171746494251
2025/05/06 01:18:01 INFO  : test/dir4: rmdir: cache expired
2025/05/06 01:18:01 DEBUG : removing 4 level 2 directories
2025/05/06 01:18:01 INFO  : test/dir4: Removing directory
2025/05/06 01:18:01 INFO  : test/dir3: Removing directory
2025/05/06 01:18:01 DEBUG : Cache remote TestInternalCache:tib21171746494251: rmdir 'test/dir4'
2025/05/06 01:18:01 DEBUG : Cache remote TestInternalCache:tib21171746494251: rmdir 'test/dir3'
2025/05/06 01:18:01 DEBUG : test/dir3: rmdir: removed dir in source fs
2025/05/06 01:18:01 INFO  : test/dir2: Removing directory
2025/05/06 01:18:01 DEBUG : Cache remote TestInternalCache:tib21171746494251: rmdir 'test/dir2'
2025/05/06 01:18:01 INFO  : test/dir1: Removing directory
2025/05/06 01:18:01 DEBUG : Cache remote TestInternalCache:tib21171746494251: rmdir 'test/dir1'
2025/05/06 01:18:01 DEBUG : test/dir4: rmdir: removed dir in source fs
2025/05/06 01:18:01 DEBUG : test/dir1: rmdir: removed dir in source fs
2025/05/06 01:18:01 DEBUG : test/dir2: rmdir: removed dir in source fs
2025/05/06 01:18:01 DEBUG : test/dir3: rmdir: removed from cache
2025/05/06 01:18:01 DEBUG : test: cache: expired tib21171746494251/test
2025/05/06 01:18:01 DEBUG : test: cache: expired tib21171746494251
2025/05/06 01:18:01 INFO  : test: rmdir: cache expired
2025/05/06 01:18:01 DEBUG : test/dir4: rmdir: removed from cache
2025/05/06 01:18:01 DEBUG : test: cache: expired tib21171746494251/test
2025/05/06 01:18:01 DEBUG : test: cache: expired tib21171746494251
2025/05/06 01:18:01 INFO  : test: rmdir: cache expired
2025/05/06 01:18:01 DEBUG : test/dir1: rmdir: removed from cache
2025/05/06 01:18:01 DEBUG : test/dir2: rmdir: removed from cache
2025/05/06 01:18:01 DEBUG : test: cache: expired tib21171746494251/test
2025/05/06 01:18:01 DEBUG : test: cache: expired tib21171746494251
2025/05/06 01:18:01 INFO  : test: rmdir: cache expired
2025/05/06 01:18:01 DEBUG : test: cache: expired tib21171746494251/test
2025/05/06 01:18:01 DEBUG : test: cache: expired tib21171746494251
2025/05/06 01:18:01 INFO  : test: rmdir: cache expired
2025/05/06 01:18:01 DEBUG : removing 1 level 1 directories
2025/05/06 01:18:01 INFO  : test: Removing directory
2025/05/06 01:18:01 DEBUG : Cache remote TestInternalCache:tib21171746494251: rmdir 'test'
2025/05/06 01:18:01 DEBUG : test: rmdir: removed dir in source fs
2025/05/06 01:18:01 DEBUG : test: rmdir: removed from cache
2025/05/06 01:18:01 DEBUG : : cache: expired tib21171746494251
2025/05/06 01:18:01 INFO  : : rmdir: cache expired
2025/05/06 01:18:01 DEBUG : removing 1 level 0 directories
2025/05/06 01:18:01 INFO  : Cache remote TestInternalCache:tib21171746494251: Removing directory
2025/05/06 01:18:01 DEBUG : Cache remote TestInternalCache:tib21171746494251: rmdir ''
2025/05/06 01:18:01 DEBUG : : rmdir: removed dir in source fs
2025/05/06 01:18:01 DEBUG : : rmdir: removed from cache
2025/05/06 01:18:01 INFO  : : rmdir: cache expired
2025/05/06 01:18:01 DEBUG : Cache remote TestInternalCache:tib21171746494251: Services stopped
--- PASS: TestInternalBug2117 (30.19s)
=== RUN   TestIntegration
    fstests.go:438: Using remote "TestCache:"
2025/05/06 01:18:01 DEBUG : Creating backend with remote "TestCache:rclone-test-yenafiz5yamu"
2025/05/06 01:18:01 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2025/05/06 01:18:01 DEBUG : Setting cache db_wait_time="30m" from environment variable RCLONE_CACHE_DB_WAIT_TIME
2025/05/06 01:18:01 DEBUG : TestCache: detected overridden config - adding "{VDL3R}" suffix to name
2025/05/06 01:18:01 DEBUG : Setting cache db_wait_time="30m" from environment variable RCLONE_CACHE_DB_WAIT_TIME
2025/05/06 01:18:01 DEBUG : Creating backend with remote "/tmp/rclone_cache_test/rclone-test-yenafiz5yamu"
2025/05/06 01:18:01 DEBUG : TestCache{VDL3R}: wrapped local:/tmp/rclone_cache_test/rclone-test-yenafiz5yamu at root rclone-test-yenafiz5yamu
2025/05/06 01:18:01 INFO  : TestCache{VDL3R}: Cache DB path: /home/rclone/.cache/rclone/cache-backend/TestCache{VDL3R}.db
2025/05/06 01:18:01 INFO  : TestCache{VDL3R}: Cache chunk path: /home/rclone/.cache/rclone/cache-backend/TestCache{VDL3R}
2025/05/06 01:18:21 INFO  : Cache remote TestInternalCache:tionf1746494241: stopping cleanup
2025/05/06 01:18:21 INFO  : Cache remote TestInternalCache:ticwcm1746494241: stopping cleanup
2025/05/06 01:18:22 INFO  : Cache remote TestInternalCache:tidwcm1746494242: stopping cleanup
2025/05/06 01:18:23 INFO  : Cache remote TestInternalCache:ticucm1746494243: stopping cleanup
2025/05/06 01:18:23 INFO  : Cache remote TestInternalCache:tiwfcns1746494243: stopping cleanup
2025/05/06 01:18:24 INFO  : Cache remote TestInternalCache:timwn1746494244: stopping cleanup
2025/05/06 01:18:24 INFO  : Cache remote TestInternalCache:tincep1746494244: stopping cleanup
2025/05/06 01:18:24 INFO  : Cache remote TestInternalCache:ticsadcf1746494244: stopping cleanup
2025/05/06 01:18:24 INFO  : Cache remote TestInternalCache:ticw: stopping cleanup
2025/05/06 01:18:25 INFO  : Cache remote TestInternalCache:timcsr1746494245: stopping cleanup
2025/05/06 01:32:31 INFO  : Cache remote TestInternalCache:tib21171746494251: stopping cleanup
2025/05/06 01:48:01 ERROR : /home/rclone/.cache/rclone/cache-backend/TestCache{VDL3R}.db: Error opening storage cache. Is there another rclone running on the same remote? failed to open a cache connection to "/home/rclone/.cache/rclone/cache-backend/TestCache{VDL3R}.db": timeout
    fstests.go:462: 
        	Error Trace:	/home/rclone/go/src/github.com/rclone/rclone/fstest/fstests/fstests.go:462
        	            				/home/rclone/go/src/github.com/rclone/rclone/backend/cache/cache_test.go:17
        	Error:      	Received unexpected error:
        	            	failed to start cache db: failed to open a cache connection to "/home/rclone/.cache/rclone/cache-backend/TestCache{VDL3R}.db": timeout
        	Test:       	TestIntegration
        	Messages:   	unexpected error: failed to start cache db: failed to open a cache connection to "/home/rclone/.cache/rclone/cache-backend/TestCache{VDL3R}.db": timeout
--- FAIL: TestIntegration (1799.98s)
=== RUN   TestInternalUploadTempDirCreated
2025/05/06 01:48:01 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2025/05/06 01:48:01 DEBUG : Creating backend with remote "TestInternalCache-local:/tmp/TestInternalCache-local/tiutdc1746496081"
2025/05/06 01:48:01 DEBUG : TestInternalCache: wrapped TestInternalCache-local:/tmp/TestInternalCache-local/tiutdc1746496081 at root tiutdc1746496081
2025/05/06 01:48:01 INFO  : TestInternalCache: Cache DB path: /home/rclone/.cache/rclone/cache-backend/TestInternalCache.db
2025/05/06 01:48:01 INFO  : TestInternalCache: Cache chunk path: /home/rclone/.cache/rclone/cache-backend/TestInternalCache
2025/05/06 01:48:01 INFO  : TestInternalCache: Chunk Memory: true
2025/05/06 01:48:01 INFO  : TestInternalCache: Chunk Size: 5Mi
2025/05/06 01:48:01 INFO  : TestInternalCache: Chunk Total Size: 10Gi
2025/05/06 01:48:01 INFO  : TestInternalCache: Chunk Clean Interval: 1m0s
2025/05/06 01:48:01 INFO  : TestInternalCache: Workers: 4
2025/05/06 01:48:01 INFO  : TestInternalCache: File Age: 6h0m0s
2025/05/06 01:48:01 DEBUG : Creating backend with remote "/tmp/rclonecache-tmp2951136544/tiutdc1746496081"
2025/05/06 01:48:01 INFO  : TestInternalCache: Upload Temp Rest Time: 15s
2025/05/06 01:48:01 INFO  : TestInternalCache: Upload Temp FS: /tmp/rclonecache-tmp2951136544/tiutdc1746496081
2025/05/06 01:48:01 DEBUG : Waiting for deletions to finish
2025/05/06 01:48:01 DEBUG : Cache remote TestInternalCache:tiutdc1746496081: list ''
2025/05/06 01:48:01 DEBUG : : list: error: couldn't open bucket (tiutdc1746496081)
2025/05/06 01:48:01 DEBUG : : list: read 0 from temp fs
2025/05/06 01:48:01 DEBUG : : list: temp fs entries: []
2025/05/06 01:48:01 ERROR : : error listing: directory not found
2025/05/06 01:48:01 DEBUG : Cache remote TestInternalCache:tiutdc1746496081: list ''
2025/05/06 01:48:01 DEBUG : : list: error: couldn't open bucket (tiutdc1746496081)
2025/05/06 01:48:01 DEBUG : : list: read 0 from temp fs
2025/05/06 01:48:01 DEBUG : : list: temp fs entries: []
2025/05/06 01:48:01 ERROR : Cache remote TestInternalCache:tiutdc1746496081: Failed to list "": directory not found
2025/05/06 01:48:01 DEBUG : removing 1 level 0 directories
2025/05/06 01:48:01 INFO  : Cache remote TestInternalCache:tiutdc1746496081: Removing directory
2025/05/06 01:48:01 DEBUG : Cache remote TestInternalCache:tiutdc1746496081: rmdir ''
2025/05/06 01:48:02 DEBUG : : rmdir: read 0 from temp fs
2025/05/06 01:48:02 DEBUG : : rmdir: temp fs entries: []
2025/05/06 01:48:02 DEBUG : tiutdc1746496081: couldn't delete from cache: bucket not found
2025/05/06 01:48:02 DEBUG : : rmdir: removed from cache
2025/05/06 01:48:02 INFO  : : rmdir: cache expired
2025/05/06 01:48:02 DEBUG : Cache remote TestInternalCache:tiutdc1746496081: mkdir ''
2025/05/06 01:48:02 DEBUG : : mkdir: created dir in source fs
2025/05/06 01:48:02 DEBUG : : mkdir: added to cache
2025/05/06 01:48:02 DEBUG : : cache: expired tiutdc1746496081
2025/05/06 01:48:02 INFO  : : mkdir: cache expired
2025/05/06 01:48:02 DEBUG : Waiting for deletions to finish
2025/05/06 01:48:02 DEBUG : Cache remote TestInternalCache:tiutdc1746496081: list ''
2025/05/06 01:48:02 DEBUG : : list: cold listing: 2025-05-05 19:48:02.690464925 +0000 UTC
2025/05/06 01:48:02 DEBUG : : list: read 0 from temp fs
2025/05/06 01:48:02 DEBUG : : list: temp fs entries: []
2025/05/06 01:48:02 DEBUG : : list: read 0 from source
2025/05/06 01:48:02 DEBUG : : list: source entries: []
2025/05/06 01:48:02 DEBUG : : list: cached directories: 0
2025/05/06 01:48:02 DEBUG : : list: cached dir: 'tiutdc1746496081', cache ts: 2025-05-06 01:48:02.691972174 +0000 UTC m=+1841.177894967
2025/05/06 01:48:02 DEBUG : Cache remote TestInternalCache:tiutdc1746496081: list ''
2025/05/06 01:48:02 DEBUG : : list: empty listing
2025/05/06 01:48:02 DEBUG : : list: read 0 from temp fs
2025/05/06 01:48:02 DEBUG : : list: temp fs entries: []
2025/05/06 01:48:02 DEBUG : : list: read 0 from source
2025/05/06 01:48:02 DEBUG : : list: source entries: []
2025/05/06 01:48:02 DEBUG : : list: cached directories: 0
2025/05/06 01:48:02 DEBUG : : list: cached dir: 'tiutdc1746496081', cache ts: 2025-05-06 01:48:02.693276232 +0000 UTC m=+1841.179199015
2025/05/06 01:48:02 DEBUG : removing 1 level 0 directories
2025/05/06 01:48:02 INFO  : Cache remote TestInternalCache:tiutdc1746496081: Removing directory
2025/05/06 01:48:02 DEBUG : Cache remote TestInternalCache:tiutdc1746496081: rmdir ''
2025/05/06 01:48:03 DEBUG : : rmdir: removed dir in source fs
2025/05/06 01:48:03 DEBUG : : rmdir: read 0 from temp fs
2025/05/06 01:48:03 DEBUG : : rmdir: temp fs entries: []
2025/05/06 01:48:03 DEBUG : : rmdir: removed from cache
2025/05/06 01:48:03 INFO  : : rmdir: cache expired
2025/05/06 01:48:05 DEBUG : Cache remote TestInternalCache:tiutdc1746496081: Services stopped
--- PASS: TestInternalUploadTempDirCreated (4.01s)
=== RUN   TestInternalUploadQueueOneFileNoRest
2025/05/06 01:48:05 DEBUG : Using config file from "/home/rclone/.rclone.conf"
    cache_internal_test.go:858: Need remote (TestInternalCache) to exist
--- SKIP: TestInternalUploadQueueOneFileNoRest (0.00s)
=== RUN   TestInternalUploadQueueOneFileWithRest
2025/05/06 01:48:05 DEBUG : Using config file from "/home/rclone/.rclone.conf"
    cache_internal_test.go:858: Need remote (TestInternalCache) to exist
--- SKIP: TestInternalUploadQueueOneFileWithRest (0.00s)
=== RUN   TestInternalUploadMoveExistingFile
2025/05/06 01:48:05 DEBUG : Using config file from "/home/rclone/.rclone.conf"
    cache_internal_test.go:858: Need remote (TestInternalCache) to exist
--- SKIP: TestInternalUploadMoveExistingFile (0.00s)
=== RUN   TestInternalUploadTempPathCleaned
2025/05/06 01:48:05 DEBUG : Using config file from "/home/rclone/.rclone.conf"
    cache_internal_test.go:858: Need remote (TestInternalCache) to exist
--- SKIP: TestInternalUploadTempPathCleaned (0.00s)
=== RUN   TestInternalUploadQueueMoreFiles
2025/05/06 01:48:05 DEBUG : Using config file from "/home/rclone/.rclone.conf"
    cache_internal_test.go:858: Need remote (TestInternalCache) to exist
--- SKIP: TestInternalUploadQueueMoreFiles (0.00s)
=== RUN   TestInternalUploadTempFileOperations
2025/05/06 01:48:05 DEBUG : Using config file from "/home/rclone/.rclone.conf"
    cache_internal_test.go:858: Need remote (TestInternalCache) to exist
--- SKIP: TestInternalUploadTempFileOperations (0.00s)
=== RUN   TestInternalUploadUploadingFileOperations
2025/05/06 01:48:05 DEBUG : Using config file from "/home/rclone/.rclone.conf"
    cache_internal_test.go:858: Need remote (TestInternalCache) to exist
--- SKIP: TestInternalUploadUploadingFileOperations (0.00s)
FAIL
exit status 1
FAIL	github.com/rclone/rclone/backend/cache	1843.697s
"go test -v -timeout 1h0m0s -remote TestCache: -verbose" - Finished ERROR in 30m44.879172898s (try 1/5): exit status 1: Failed [TestIntegration]