"go test -v -timeout 1h0m0s -remote TestCache: -verbose" - Starting (try 1/5)
2025/03/22 06:20:04 NOTICE: Running with the following params: 
 remote: TestInternalCache
2025/03/22 06:20:04 NOTICE: Temp Upload Dir: /tmp/rclonecache-tmp3226816588
=== RUN   TestInternalListRootAndInnerRemotes
2025/03/22 06:20:04 DEBUG : Using config file from "/home/rclone/.rclone.conf"
    cache_internal_test.go:858: Need remote (TestInternalCache) to exist
--- SKIP: TestInternalListRootAndInnerRemotes (0.00s)
=== RUN   TestInternalObjWrapFsFound
2025/03/22 06:20:04 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/03/22 06:20:04 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2025/03/22 06:20:04 NOTICE: WARNING: Cache backend is deprecated and may be removed in future. Please use VFS instead.
2025/03/22 06:20:04 DEBUG : Creating backend with remote "TestInternalCache-local:/tmp/TestInternalCache-local/tionf1742624404"
2025/03/22 06:20:04 DEBUG : TestInternalCache: wrapped TestInternalCache-local:/tmp/TestInternalCache-local/tionf1742624404 at root tionf1742624404
2025/03/22 06:20:04 INFO  : TestInternalCache: Cache DB path: /home/rclone/.cache/rclone/cache-backend/TestInternalCache.db
2025/03/22 06:20:04 INFO  : TestInternalCache: Cache chunk path: /home/rclone/.cache/rclone/cache-backend/TestInternalCache
2025/03/22 06:20:04 INFO  : TestInternalCache: Chunk Memory: true
2025/03/22 06:20:04 INFO  : TestInternalCache: Chunk Size: 5Mi
2025/03/22 06:20:04 INFO  : TestInternalCache: Chunk Total Size: 10Gi
2025/03/22 06:20:04 INFO  : TestInternalCache: Chunk Clean Interval: 1m0s
2025/03/22 06:20:04 INFO  : TestInternalCache: Workers: 4
2025/03/22 06:20:04 INFO  : TestInternalCache: File Age: 6h0m0s
2025/03/22 06:20:04 DEBUG : Waiting for deletions to finish
2025/03/22 06:20:04 DEBUG : Cache remote TestInternalCache:tionf1742624404: list ''
2025/03/22 06:20:04 DEBUG : : list: error: couldn't open bucket (tionf1742624404)
2025/03/22 06:20:04 ERROR : : error listing: directory not found
2025/03/22 06:20:04 DEBUG : Cache remote TestInternalCache:tionf1742624404: list ''
2025/03/22 06:20:04 DEBUG : : list: error: couldn't open bucket (tionf1742624404)
2025/03/22 06:20:04 ERROR : Cache remote TestInternalCache:tionf1742624404: Failed to list "": directory not found
2025/03/22 06:20:04 DEBUG : removing 1 level 0 directories
2025/03/22 06:20:04 INFO  : Cache remote TestInternalCache:tionf1742624404: Removing directory
2025/03/22 06:20:04 DEBUG : Cache remote TestInternalCache:tionf1742624404: rmdir ''
2025/03/22 06:20:04 ERROR : : Failed to rmdir: stat /tmp/TestInternalCache-local/tionf1742624404: no such file or directory
2025/03/22 06:20:04 DEBUG : Cache remote TestInternalCache:tionf1742624404: mkdir ''
2025/03/22 06:20:04 DEBUG : : mkdir: created dir in source fs
2025/03/22 06:20:04 DEBUG : : mkdir: added to cache
2025/03/22 06:20:04 DEBUG : : cache: expired tionf1742624404
2025/03/22 06:20:04 INFO  : : mkdir: cache expired
2025/03/22 06:20:04 DEBUG : Cache remote TestInternalCache:tionf1742624404: new object '404'
2025/03/22 06:20:04 DEBUG : 404: find: error: couldn't find object (404)
2025/03/22 06:20:04 DEBUG : find failed: not found in either local or remote fs
2025/03/22 06:20:04 DEBUG : Waiting for deletions to finish
2025/03/22 06:20:04 DEBUG : Cache remote TestInternalCache:tionf1742624404: list ''
2025/03/22 06:20:04 DEBUG : : list: cold listing: 2025-03-22 00:20:04.14872491 +0000 UTC
2025/03/22 06:20:04 DEBUG : : list: read 0 from source
2025/03/22 06:20:04 DEBUG : : list: source entries: []
2025/03/22 06:20:04 DEBUG : : list: cached directories: 0
2025/03/22 06:20:04 DEBUG : : list: cached dir: 'tionf1742624404', cache ts: 2025-03-22 06:20:04.150031844 +0000 UTC m=+0.043922470
2025/03/22 06:20:04 DEBUG : Cache remote TestInternalCache:tionf1742624404: list ''
2025/03/22 06:20:04 DEBUG : : list: empty listing
2025/03/22 06:20:04 DEBUG : : list: read 0 from source
2025/03/22 06:20:04 DEBUG : : list: source entries: []
2025/03/22 06:20:04 DEBUG : : list: cached directories: 0
2025/03/22 06:20:04 DEBUG : : list: cached dir: 'tionf1742624404', cache ts: 2025-03-22 06:20:04.151218813 +0000 UTC m=+0.045109439
2025/03/22 06:20:04 DEBUG : removing 1 level 0 directories
2025/03/22 06:20:04 INFO  : Cache remote TestInternalCache:tionf1742624404: Removing directory
2025/03/22 06:20:04 DEBUG : Cache remote TestInternalCache:tionf1742624404: rmdir ''
2025/03/22 06:20:04 DEBUG : : rmdir: removed dir in source fs
2025/03/22 06:20:04 DEBUG : : rmdir: removed from cache
2025/03/22 06:20:04 INFO  : : rmdir: cache expired
2025/03/22 06:20:04 DEBUG : Cache remote TestInternalCache:tionf1742624404: Services stopped
--- PASS: TestInternalObjNotFound (0.04s)
=== RUN   TestInternalCachedWrittenContentMatches
2025/03/22 06:20:04 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2025/03/22 06:20:04 DEBUG : Creating backend with remote "TestInternalCache-local:/tmp/TestInternalCache-local/ticwcm1742624404"
2025/03/22 06:20:04 DEBUG : TestInternalCache: wrapped TestInternalCache-local:/tmp/TestInternalCache-local/ticwcm1742624404 at root ticwcm1742624404
2025/03/22 06:20:04 INFO  : TestInternalCache: Cache DB path: /home/rclone/.cache/rclone/cache-backend/TestInternalCache.db
2025/03/22 06:20:04 INFO  : TestInternalCache: Cache chunk path: /home/rclone/.cache/rclone/cache-backend/TestInternalCache
2025/03/22 06:20:04 INFO  : TestInternalCache: Chunk Memory: true
2025/03/22 06:20:04 INFO  : TestInternalCache: Chunk Size: 5Mi
2025/03/22 06:20:04 INFO  : TestInternalCache: Chunk Total Size: 10Gi
2025/03/22 06:20:04 INFO  : TestInternalCache: Chunk Clean Interval: 1m0s
2025/03/22 06:20:04 INFO  : TestInternalCache: Workers: 4
2025/03/22 06:20:04 INFO  : TestInternalCache: File Age: 6h0m0s
2025/03/22 06:20:04 DEBUG : Waiting for deletions to finish
2025/03/22 06:20:04 DEBUG : Cache remote TestInternalCache:ticwcm1742624404: list ''
2025/03/22 06:20:04 DEBUG : : list: error: couldn't open bucket (ticwcm1742624404)
2025/03/22 06:20:04 ERROR : : error listing: directory not found
2025/03/22 06:20:04 DEBUG : Cache remote TestInternalCache:ticwcm1742624404: list ''
2025/03/22 06:20:04 DEBUG : : list: error: couldn't open bucket (ticwcm1742624404)
2025/03/22 06:20:04 ERROR : Cache remote TestInternalCache:ticwcm1742624404: Failed to list "": directory not found
2025/03/22 06:20:04 DEBUG : removing 1 level 0 directories
2025/03/22 06:20:04 INFO  : Cache remote TestInternalCache:ticwcm1742624404: Removing directory
2025/03/22 06:20:04 DEBUG : Cache remote TestInternalCache:ticwcm1742624404: rmdir ''
2025/03/22 06:20:04 ERROR : : Failed to rmdir: stat /tmp/TestInternalCache-local/ticwcm1742624404: no such file or directory
2025/03/22 06:20:04 DEBUG : Cache remote TestInternalCache:ticwcm1742624404: mkdir ''
2025/03/22 06:20:04 DEBUG : : mkdir: created dir in source fs
2025/03/22 06:20:04 DEBUG : : mkdir: added to cache
2025/03/22 06:20:04 DEBUG : : cache: expired ticwcm1742624404
2025/03/22 06:20:04 INFO  : : mkdir: cache expired
2025/03/22 06:20:04 DEBUG : Cache remote TestInternalCache:ticwcm1742624404: put data at 'data.bin'
2025/03/22 06:20:04 DEBUG : data.bin: put: uploaded to remote fs
2025/03/22 06:20:04 DEBUG : data.bin: put: added to cache
2025/03/22 06:20:04 DEBUG : : cache: expired ticwcm1742624404
2025/03/22 06:20:04 INFO  : : put: cache expired
2025/03/22 06:20:04 DEBUG : Cache remote TestInternalCache:ticwcm1742624404: new object 'data.bin'
2025/03/22 06:20:04 DEBUG : data.bin: find: warm object: data.bin, expiring on: 2025-03-22 12:20:04.748741783 +0000 UTC
2025/03/22 06:20:04 DEBUG : Cache remote TestInternalCache:ticwcm1742624404: new object 'data.bin'
2025/03/22 06:20:04 DEBUG : data.bin: find: warm object: data.bin, expiring on: 2025-03-22 12:20:04.748741783 +0000 UTC
2025/03/22 06:20:04 DEBUG : ticwcm1742624404/data.bin: moving offset set from 0 to 2621440
2025/03/22 06:20:04 DEBUG : ticwcm1742624404/data.bin: 0: chunk retry storage: 0
2025/03/22 06:20:04 DEBUG : worker-3 <data.bin>: downloaded chunk 15728640
2025/03/22 06:20:04 DEBUG : worker-2 <data.bin>: downloaded chunk 10485760
2025/03/22 06:20:04 DEBUG : worker-1 <data.bin>: downloaded chunk 5242880
2025/03/22 06:20:04 DEBUG : worker-0 <data.bin>: downloaded chunk 0
2025/03/22 06:20:05 DEBUG : ticwcm1742624404/data.bin: cache reader closed 5242880
2025/03/22 06:20:05 DEBUG : Waiting for deletions to finish
2025/03/22 06:20:05 DEBUG : Cache remote TestInternalCache:ticwcm1742624404: list ''
2025/03/22 06:20:05 DEBUG : : list: cold listing: 2025-03-22 00:20:04.750845814 +0000 UTC
2025/03/22 06:20:05 DEBUG : : list: read 1 from source
2025/03/22 06:20:05 DEBUG : : list: source entries: [data.bin]
2025/03/22 06:20:05 DEBUG : : list: cached object: data.bin
2025/03/22 06:20:05 DEBUG : : list: cached directories: 0
2025/03/22 06:20:05 DEBUG : : list: cached dir: 'ticwcm1742624404', cache ts: 2025-03-22 06:20:05.271563191 +0000 UTC m=+1.165453817
2025/03/22 06:20:05 DEBUG : data.bin: removing object
2025/03/22 06:20:05 DEBUG : : cache: expired ticwcm1742624404
2025/03/22 06:20:05 INFO  : data.bin: Deleted
2025/03/22 06:20:05 DEBUG : Cache remote TestInternalCache:ticwcm1742624404: list ''
2025/03/22 06:20:05 DEBUG : : list: cold listing: 2025-03-22 00:20:05.280692359 +0000 UTC
2025/03/22 06:20:05 DEBUG : : list: read 0 from source
2025/03/22 06:20:05 DEBUG : : list: source entries: []
2025/03/22 06:20:05 DEBUG : : list: cached directories: 0
2025/03/22 06:20:05 DEBUG : : list: cached dir: 'ticwcm1742624404', cache ts: 2025-03-22 06:20:05.282254443 +0000 UTC m=+1.176145069
2025/03/22 06:20:05 DEBUG : removing 1 level 0 directories
2025/03/22 06:20:05 INFO  : Cache remote TestInternalCache:ticwcm1742624404: Removing directory
2025/03/22 06:20:05 DEBUG : Cache remote TestInternalCache:ticwcm1742624404: rmdir ''
2025/03/22 06:20:05 DEBUG : : rmdir: removed dir in source fs
2025/03/22 06:20:05 DEBUG : : rmdir: removed from cache
2025/03/22 06:20:05 INFO  : : rmdir: cache expired
2025/03/22 06:20:05 DEBUG : Cache remote TestInternalCache:ticwcm1742624404: Services stopped
--- PASS: TestInternalCachedWrittenContentMatches (1.14s)
=== RUN   TestInternalDoubleWrittenContentMatches
2025/03/22 06:20:05 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2025/03/22 06:20:05 DEBUG : Creating backend with remote "TestInternalCache-local:/tmp/TestInternalCache-local/tidwcm1742624405"
2025/03/22 06:20:05 DEBUG : TestInternalCache: wrapped TestInternalCache-local:/tmp/TestInternalCache-local/tidwcm1742624405 at root tidwcm1742624405
2025/03/22 06:20:05 INFO  : TestInternalCache: Cache DB path: /home/rclone/.cache/rclone/cache-backend/TestInternalCache.db
2025/03/22 06:20:05 INFO  : TestInternalCache: Cache chunk path: /home/rclone/.cache/rclone/cache-backend/TestInternalCache
2025/03/22 06:20:05 INFO  : TestInternalCache: Chunk Memory: true
2025/03/22 06:20:05 INFO  : TestInternalCache: Chunk Size: 5Mi
2025/03/22 06:20:05 INFO  : TestInternalCache: Chunk Total Size: 10Gi
2025/03/22 06:20:05 INFO  : TestInternalCache: Chunk Clean Interval: 1m0s
2025/03/22 06:20:05 INFO  : TestInternalCache: Workers: 4
2025/03/22 06:20:05 INFO  : TestInternalCache: File Age: 6h0m0s
2025/03/22 06:20:05 DEBUG : Waiting for deletions to finish
2025/03/22 06:20:05 DEBUG : Cache remote TestInternalCache:tidwcm1742624405: list ''
2025/03/22 06:20:05 DEBUG : : list: error: couldn't open bucket (tidwcm1742624405)
2025/03/22 06:20:05 ERROR : : error listing: directory not found
2025/03/22 06:20:05 DEBUG : Cache remote TestInternalCache:tidwcm1742624405: list ''
2025/03/22 06:20:05 DEBUG : : list: error: couldn't open bucket (tidwcm1742624405)
2025/03/22 06:20:05 ERROR : Cache remote TestInternalCache:tidwcm1742624405: Failed to list "": directory not found
2025/03/22 06:20:05 DEBUG : removing 1 level 0 directories
2025/03/22 06:20:05 INFO  : Cache remote TestInternalCache:tidwcm1742624405: Removing directory
2025/03/22 06:20:05 DEBUG : Cache remote TestInternalCache:tidwcm1742624405: rmdir ''
2025/03/22 06:20:05 ERROR : : Failed to rmdir: stat /tmp/TestInternalCache-local/tidwcm1742624405: no such file or directory
2025/03/22 06:20:05 DEBUG : Cache remote TestInternalCache:tidwcm1742624405: mkdir ''
2025/03/22 06:20:05 DEBUG : : mkdir: created dir in source fs
2025/03/22 06:20:05 DEBUG : : mkdir: added to cache
2025/03/22 06:20:05 DEBUG : : cache: expired tidwcm1742624405
2025/03/22 06:20:05 INFO  : : mkdir: cache expired
2025/03/22 06:20:05 DEBUG : Cache remote TestInternalCache:tidwcm1742624405: put data at 'one'
2025/03/22 06:20:05 DEBUG : one: put: uploaded to remote fs
2025/03/22 06:20:05 DEBUG : one: put: added to cache
2025/03/22 06:20:05 DEBUG : : cache: expired tidwcm1742624405
2025/03/22 06:20:05 INFO  : : put: cache expired
2025/03/22 06:20:05 DEBUG : Cache remote TestInternalCache:tidwcm1742624405: new object 'one'
2025/03/22 06:20:05 DEBUG : one: find: warm object: one, expiring on: 2025-03-22 12:20:05.317529218 +0000 UTC
2025/03/22 06:20:05 DEBUG : Cache remote TestInternalCache:tidwcm1742624405: new object 'one'
2025/03/22 06:20:05 DEBUG : one: find: warm object: one, expiring on: 2025-03-22 12:20:05.317529218 +0000 UTC
2025/03/22 06:20:05 DEBUG : one: updating object contents with size 19
2025/03/22 06:20:05 DEBUG : Cache remote TestInternalCache:tidwcm1742624405: new object 'one'
2025/03/22 06:20:05 DEBUG : one: find: warm object: one, expiring on: 2025-03-22 12:20:05.323965136 +0000 UTC
2025/03/22 06:20:05 DEBUG : one: updating object contents with size 26
2025/03/22 06:20:05 DEBUG : Cache remote TestInternalCache:tidwcm1742624405: new object 'one'
2025/03/22 06:20:05 DEBUG : one: find: warm object: one, expiring on: 2025-03-22 12:20:05.327190315 +0000 UTC
2025/03/22 06:20:05 DEBUG : tidwcm1742624405/one: moving offset set from 0 to 0
2025/03/22 06:20:05 DEBUG : tidwcm1742624405/one: 0: chunk retry storage: 0
2025/03/22 06:20:05 DEBUG : worker-1 <one>: partial downloaded chunk 0
2025/03/22 06:20:05 DEBUG : tidwcm1742624405/one: cache reader closed 26
2025/03/22 06:20:05 DEBUG : Waiting for deletions to finish
2025/03/22 06:20:05 DEBUG : Cache remote TestInternalCache:tidwcm1742624405: list ''
2025/03/22 06:20:05 DEBUG : : list: cold listing: 2025-03-22 00:20:05.319094548 +0000 UTC
2025/03/22 06:20:05 DEBUG : : list: read 1 from source
2025/03/22 06:20:05 DEBUG : : list: source entries: [one]
2025/03/22 06:20:05 DEBUG : : list: cached object: one
2025/03/22 06:20:05 DEBUG : : list: cached directories: 0
2025/03/22 06:20:05 DEBUG : : list: cached dir: 'tidwcm1742624405', cache ts: 2025-03-22 06:20:05.831435752 +0000 UTC m=+1.725326379
2025/03/22 06:20:05 DEBUG : one: removing object
2025/03/22 06:20:05 DEBUG : : cache: expired tidwcm1742624405
2025/03/22 06:20:05 INFO  : one: Deleted
2025/03/22 06:20:05 DEBUG : Cache remote TestInternalCache:tidwcm1742624405: list ''
2025/03/22 06:20:05 DEBUG : : list: cold listing: 2025-03-22 00:20:05.834930066 +0000 UTC
2025/03/22 06:20:05 DEBUG : : list: read 0 from source
2025/03/22 06:20:05 DEBUG : : list: source entries: []
2025/03/22 06:20:05 DEBUG : : list: cached directories: 0
2025/03/22 06:20:05 DEBUG : : list: cached dir: 'tidwcm1742624405', cache ts: 2025-03-22 06:20:05.836129689 +0000 UTC m=+1.730020314
2025/03/22 06:20:05 DEBUG : removing 1 level 0 directories
2025/03/22 06:20:05 INFO  : Cache remote TestInternalCache:tidwcm1742624405: Removing directory
2025/03/22 06:20:05 DEBUG : Cache remote TestInternalCache:tidwcm1742624405: rmdir ''
2025/03/22 06:20:05 DEBUG : : rmdir: removed dir in source fs
2025/03/22 06:20:05 DEBUG : : rmdir: removed from cache
2025/03/22 06:20:05 INFO  : : rmdir: cache expired
2025/03/22 06:20:05 DEBUG : Cache remote TestInternalCache:tidwcm1742624405: Services stopped
--- PASS: TestInternalDoubleWrittenContentMatches (0.54s)
=== RUN   TestInternalCachedUpdatedContentMatches
2025/03/22 06:20:05 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2025/03/22 06:20:05 DEBUG : Creating backend with remote "TestInternalCache-local:/tmp/TestInternalCache-local/ticucm1742624405"
2025/03/22 06:20:05 DEBUG : TestInternalCache: wrapped TestInternalCache-local:/tmp/TestInternalCache-local/ticucm1742624405 at root ticucm1742624405
2025/03/22 06:20:05 INFO  : TestInternalCache: Cache DB path: /home/rclone/.cache/rclone/cache-backend/TestInternalCache.db
2025/03/22 06:20:05 INFO  : TestInternalCache: Cache chunk path: /home/rclone/.cache/rclone/cache-backend/TestInternalCache
2025/03/22 06:20:05 INFO  : TestInternalCache: Chunk Memory: true
2025/03/22 06:20:05 INFO  : TestInternalCache: Chunk Size: 5Mi
2025/03/22 06:20:05 INFO  : TestInternalCache: Chunk Total Size: 10Gi
2025/03/22 06:20:05 INFO  : TestInternalCache: Chunk Clean Interval: 1m0s
2025/03/22 06:20:05 INFO  : TestInternalCache: Workers: 4
2025/03/22 06:20:05 INFO  : TestInternalCache: File Age: 6h0m0s
2025/03/22 06:20:05 DEBUG : Waiting for deletions to finish
2025/03/22 06:20:05 DEBUG : Cache remote TestInternalCache:ticucm1742624405: list ''
2025/03/22 06:20:05 DEBUG : : list: error: couldn't open bucket (ticucm1742624405)
2025/03/22 06:20:05 ERROR : : error listing: directory not found
2025/03/22 06:20:05 DEBUG : Cache remote TestInternalCache:ticucm1742624405: list ''
2025/03/22 06:20:05 DEBUG : : list: error: couldn't open bucket (ticucm1742624405)
2025/03/22 06:20:05 ERROR : Cache remote TestInternalCache:ticucm1742624405: Failed to list "": directory not found
2025/03/22 06:20:05 DEBUG : removing 1 level 0 directories
2025/03/22 06:20:05 INFO  : Cache remote TestInternalCache:ticucm1742624405: Removing directory
2025/03/22 06:20:05 DEBUG : Cache remote TestInternalCache:ticucm1742624405: rmdir ''
2025/03/22 06:20:05 ERROR : : Failed to rmdir: stat /tmp/TestInternalCache-local/ticucm1742624405: no such file or directory
2025/03/22 06:20:05 DEBUG : Cache remote TestInternalCache:ticucm1742624405: mkdir ''
2025/03/22 06:20:05 DEBUG : : mkdir: created dir in source fs
2025/03/22 06:20:05 DEBUG : : mkdir: added to cache
2025/03/22 06:20:05 DEBUG : : cache: expired ticucm1742624405
2025/03/22 06:20:05 INFO  : : mkdir: cache expired
2025/03/22 06:20:05 DEBUG : Cache remote TestInternalCache:ticucm1742624405: put data at 'data.bin'
2025/03/22 06:20:05 DEBUG : data.bin: put: uploaded to remote fs
2025/03/22 06:20:05 DEBUG : data.bin: put: added to cache
2025/03/22 06:20:05 DEBUG : : cache: expired ticucm1742624405
2025/03/22 06:20:05 INFO  : : put: cache expired
2025/03/22 06:20:05 DEBUG : Cache remote TestInternalCache:ticucm1742624405: new object 'data.bin'
2025/03/22 06:20:05 DEBUG : data.bin: find: warm object: data.bin, expiring on: 2025-03-22 12:20:05.853427628 +0000 UTC
2025/03/22 06:20:05 DEBUG : data.bin: updating object contents with size 200
2025/03/22 06:20:05 DEBUG : Cache remote TestInternalCache:ticucm1742624405: new object 'data.bin'
2025/03/22 06:20:05 DEBUG : data.bin: find: warm object: data.bin, expiring on: 2025-03-22 12:20:05.859050109 +0000 UTC
2025/03/22 06:20:05 DEBUG : ticucm1742624405/data.bin: moving offset set from 0 to 0
2025/03/22 06:20:05 DEBUG : ticucm1742624405/data.bin: 0: chunk retry storage: 0
2025/03/22 06:20:05 DEBUG : worker-1 <data.bin>: partial downloaded chunk 0
2025/03/22 06:20:06 DEBUG : ticucm1742624405/data.bin: cache reader closed 200
2025/03/22 06:20:06 DEBUG : Waiting for deletions to finish
2025/03/22 06:20:06 DEBUG : Cache remote TestInternalCache:ticucm1742624405: list ''
2025/03/22 06:20:06 DEBUG : : list: cold listing: 2025-03-22 00:20:05.855356491 +0000 UTC
2025/03/22 06:20:06 DEBUG : : list: read 1 from source
2025/03/22 06:20:06 DEBUG : : list: source entries: [data.bin]
2025/03/22 06:20:06 DEBUG : : list: cached object: data.bin
2025/03/22 06:20:06 DEBUG : : list: cached directories: 0
2025/03/22 06:20:06 DEBUG : : list: cached dir: 'ticucm1742624405', cache ts: 2025-03-22 06:20:06.369446069 +0000 UTC m=+2.263336735
2025/03/22 06:20:06 DEBUG : data.bin: removing object
2025/03/22 06:20:06 DEBUG : : cache: expired ticucm1742624405
2025/03/22 06:20:06 INFO  : data.bin: Deleted
2025/03/22 06:20:06 DEBUG : Cache remote TestInternalCache:ticucm1742624405: list ''
2025/03/22 06:20:06 DEBUG : : list: cold listing: 2025-03-22 00:20:06.373222301 +0000 UTC
2025/03/22 06:20:06 DEBUG : : list: read 0 from source
2025/03/22 06:20:06 DEBUG : : list: source entries: []
2025/03/22 06:20:06 DEBUG : : list: cached directories: 0
2025/03/22 06:20:06 DEBUG : : list: cached dir: 'ticucm1742624405', cache ts: 2025-03-22 06:20:06.374653509 +0000 UTC m=+2.268544165
2025/03/22 06:20:06 DEBUG : removing 1 level 0 directories
2025/03/22 06:20:06 INFO  : Cache remote TestInternalCache:ticucm1742624405: Removing directory
2025/03/22 06:20:06 DEBUG : Cache remote TestInternalCache:ticucm1742624405: rmdir ''
2025/03/22 06:20:06 DEBUG : : rmdir: removed dir in source fs
2025/03/22 06:20:06 DEBUG : : rmdir: removed from cache
2025/03/22 06:20:06 INFO  : : rmdir: cache expired
2025/03/22 06:20:06 DEBUG : Cache remote TestInternalCache:ticucm1742624405: Services stopped
--- PASS: TestInternalCachedUpdatedContentMatches (0.53s)
=== RUN   TestInternalWrappedWrittenContentMatches
2025/03/22 06:20:06 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/03/22 06:20:06 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/03/22 06:20:06 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2025/03/22 06:20:06 DEBUG : Creating backend with remote "TestInternalCache-local:/tmp/TestInternalCache-local/tiwfcns1742624406"
2025/03/22 06:20:06 DEBUG : TestInternalCache: wrapped TestInternalCache-local:/tmp/TestInternalCache-local/tiwfcns1742624406 at root tiwfcns1742624406
2025/03/22 06:20:06 INFO  : TestInternalCache: Cache DB path: /home/rclone/.cache/rclone/cache-backend/TestInternalCache.db
2025/03/22 06:20:06 INFO  : TestInternalCache: Cache chunk path: /home/rclone/.cache/rclone/cache-backend/TestInternalCache
2025/03/22 06:20:06 INFO  : TestInternalCache: Chunk Memory: true
2025/03/22 06:20:06 INFO  : TestInternalCache: Chunk Size: 5Mi
2025/03/22 06:20:06 INFO  : TestInternalCache: Chunk Total Size: 10Gi
2025/03/22 06:20:06 INFO  : TestInternalCache: Chunk Clean Interval: 1m0s
2025/03/22 06:20:06 INFO  : TestInternalCache: Workers: 4
2025/03/22 06:20:06 INFO  : TestInternalCache: File Age: 6h0m0s
2025/03/22 06:20:06 DEBUG : Waiting for deletions to finish
2025/03/22 06:20:06 DEBUG : Cache remote TestInternalCache:tiwfcns1742624406: list ''
2025/03/22 06:20:06 DEBUG : : list: error: couldn't open bucket (tiwfcns1742624406)
2025/03/22 06:20:06 ERROR : : error listing: directory not found
2025/03/22 06:20:06 DEBUG : Cache remote TestInternalCache:tiwfcns1742624406: list ''
2025/03/22 06:20:06 DEBUG : : list: error: couldn't open bucket (tiwfcns1742624406)
2025/03/22 06:20:06 ERROR : Cache remote TestInternalCache:tiwfcns1742624406: Failed to list "": directory not found
2025/03/22 06:20:06 DEBUG : removing 1 level 0 directories
2025/03/22 06:20:06 INFO  : Cache remote TestInternalCache:tiwfcns1742624406: Removing directory
2025/03/22 06:20:06 DEBUG : Cache remote TestInternalCache:tiwfcns1742624406: rmdir ''
2025/03/22 06:20:06 ERROR : : Failed to rmdir: stat /tmp/TestInternalCache-local/tiwfcns1742624406: no such file or directory
2025/03/22 06:20:06 DEBUG : Cache remote TestInternalCache:tiwfcns1742624406: mkdir ''
2025/03/22 06:20:06 DEBUG : : mkdir: created dir in source fs
2025/03/22 06:20:06 DEBUG : : mkdir: added to cache
2025/03/22 06:20:06 DEBUG : : cache: expired tiwfcns1742624406
2025/03/22 06:20:06 INFO  : : mkdir: cache expired
2025/03/22 06:20:06 DEBUG : Cache remote TestInternalCache:tiwfcns1742624406: put data at 'data.bin'
2025/03/22 06:20:06 DEBUG : data.bin: put: uploaded to remote fs
2025/03/22 06:20:06 DEBUG : data.bin: put: added to cache
2025/03/22 06:20:06 DEBUG : : cache: expired tiwfcns1742624406
2025/03/22 06:20:06 INFO  : : put: cache expired
2025/03/22 06:20:06 DEBUG : Cache remote TestInternalCache:tiwfcns1742624406: new object 'data.bin'
2025/03/22 06:20:06 DEBUG : data.bin: find: warm object: data.bin, expiring on: 2025-03-22 12:20:06.965840195 +0000 UTC
2025/03/22 06:20:06 DEBUG : Cache remote TestInternalCache:tiwfcns1742624406: new object 'data.bin'
2025/03/22 06:20:06 DEBUG : data.bin: find: warm object: data.bin, expiring on: 2025-03-22 12:20:06.965840195 +0000 UTC
2025/03/22 06:20:06 NOTICE: original size: 23592960
2025/03/22 06:20:06 NOTICE: updated size: 12
2025/03/22 06:20:06 DEBUG : Cache remote TestInternalCache:tiwfcns1742624406: new object 'data.bin'
2025/03/22 06:20:06 DEBUG : data.bin: find: warm object: data.bin, expiring on: 2025-03-22 12:20:06.965840195 +0000 UTC
2025/03/22 06:20:06 DEBUG : Waiting for deletions to finish
2025/03/22 06:20:06 DEBUG : Cache remote TestInternalCache:tiwfcns1742624406: list ''
2025/03/22 06:20:06 DEBUG : : list: cold listing: 2025-03-22 00:20:06.96771169 +0000 UTC
2025/03/22 06:20:06 DEBUG : : list: read 1 from source
2025/03/22 06:20:06 DEBUG : : list: source entries: [data.bin]
2025/03/22 06:20:06 DEBUG : : list: cached object: data.bin
2025/03/22 06:20:06 DEBUG : : list: cached directories: 0
2025/03/22 06:20:06 DEBUG : : list: cached dir: 'tiwfcns1742624406', cache ts: 2025-03-22 06:20:06.973985063 +0000 UTC m=+2.867875689
2025/03/22 06:20:06 DEBUG : data.bin: removing object
2025/03/22 06:20:06 DEBUG : : cache: expired tiwfcns1742624406
2025/03/22 06:20:06 INFO  : data.bin: Deleted
2025/03/22 06:20:06 DEBUG : Cache remote TestInternalCache:tiwfcns1742624406: list ''
2025/03/22 06:20:06 DEBUG : : list: cold listing: 2025-03-22 00:20:06.976103551 +0000 UTC
2025/03/22 06:20:06 DEBUG : : list: read 0 from source
2025/03/22 06:20:06 DEBUG : : list: source entries: []
2025/03/22 06:20:06 DEBUG : : list: cached directories: 0
2025/03/22 06:20:06 DEBUG : : list: cached dir: 'tiwfcns1742624406', cache ts: 2025-03-22 06:20:06.976830086 +0000 UTC m=+2.870720712
2025/03/22 06:20:06 DEBUG : removing 1 level 0 directories
2025/03/22 06:20:06 INFO  : Cache remote TestInternalCache:tiwfcns1742624406: Removing directory
2025/03/22 06:20:06 DEBUG : Cache remote TestInternalCache:tiwfcns1742624406: rmdir ''
2025/03/22 06:20:06 DEBUG : : rmdir: removed dir in source fs
2025/03/22 06:20:06 DEBUG : : rmdir: removed from cache
2025/03/22 06:20:06 INFO  : : rmdir: cache expired
2025/03/22 06:20:06 DEBUG : Cache remote TestInternalCache:tiwfcns1742624406: Services stopped
--- PASS: TestInternalWrappedFsChangeNotSeen (0.60s)
=== RUN   TestInternalMoveWithNotify
2025/03/22 06:20:06 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2025/03/22 06:20:06 DEBUG : Creating backend with remote "TestInternalCache-local:/tmp/TestInternalCache-local/timwn1742624406"
2025/03/22 06:20:06 DEBUG : TestInternalCache: wrapped TestInternalCache-local:/tmp/TestInternalCache-local/timwn1742624406 at root timwn1742624406
2025/03/22 06:20:06 INFO  : TestInternalCache: Cache DB path: /home/rclone/.cache/rclone/cache-backend/TestInternalCache.db
2025/03/22 06:20:06 INFO  : TestInternalCache: Cache chunk path: /home/rclone/.cache/rclone/cache-backend/TestInternalCache
2025/03/22 06:20:06 INFO  : TestInternalCache: Chunk Memory: true
2025/03/22 06:20:06 INFO  : TestInternalCache: Chunk Size: 5Mi
2025/03/22 06:20:06 INFO  : TestInternalCache: Chunk Total Size: 10Gi
2025/03/22 06:20:06 INFO  : TestInternalCache: Chunk Clean Interval: 1m0s
2025/03/22 06:20:06 INFO  : TestInternalCache: Workers: 4
2025/03/22 06:20:06 INFO  : TestInternalCache: File Age: 6h0m0s
2025/03/22 06:20:06 DEBUG : Waiting for deletions to finish
2025/03/22 06:20:06 DEBUG : Cache remote TestInternalCache:timwn1742624406: list ''
2025/03/22 06:20:06 DEBUG : : list: error: couldn't open bucket (timwn1742624406)
2025/03/22 06:20:06 ERROR : : error listing: directory not found
2025/03/22 06:20:06 DEBUG : Cache remote TestInternalCache:timwn1742624406: list ''
2025/03/22 06:20:06 DEBUG : : list: error: couldn't open bucket (timwn1742624406)
2025/03/22 06:20:06 ERROR : Cache remote TestInternalCache:timwn1742624406: Failed to list "": directory not found
2025/03/22 06:20:06 DEBUG : removing 1 level 0 directories
2025/03/22 06:20:06 INFO  : Cache remote TestInternalCache:timwn1742624406: Removing directory
2025/03/22 06:20:06 DEBUG : Cache remote TestInternalCache:timwn1742624406: rmdir ''
2025/03/22 06:20:06 ERROR : : Failed to rmdir: stat /tmp/TestInternalCache-local/timwn1742624406: no such file or directory
2025/03/22 06:20:06 DEBUG : Cache remote TestInternalCache:timwn1742624406: mkdir ''
2025/03/22 06:20:06 DEBUG : : mkdir: created dir in source fs
2025/03/22 06:20:06 DEBUG : : mkdir: added to cache
2025/03/22 06:20:06 DEBUG : : cache: expired timwn1742624406
2025/03/22 06:20:06 INFO  : : mkdir: cache expired
    cache_internal_test.go:453: Not external
2025/03/22 06:20:06 DEBUG : Waiting for deletions to finish
2025/03/22 06:20:06 DEBUG : Cache remote TestInternalCache:timwn1742624406: list ''
2025/03/22 06:20:06 DEBUG : : list: cold listing: 2025-03-22 00:20:06.993816312 +0000 UTC
2025/03/22 06:20:06 DEBUG : : list: read 0 from source
2025/03/22 06:20:06 DEBUG : : list: source entries: []
2025/03/22 06:20:06 DEBUG : : list: cached directories: 0
2025/03/22 06:20:06 DEBUG : : list: cached dir: 'timwn1742624406', cache ts: 2025-03-22 06:20:06.996262616 +0000 UTC m=+2.890153242
2025/03/22 06:20:06 DEBUG : Cache remote TestInternalCache:timwn1742624406: list ''
2025/03/22 06:20:06 DEBUG : : list: empty listing
2025/03/22 06:20:06 DEBUG : : list: read 0 from source
2025/03/22 06:20:06 DEBUG : : list: source entries: []
2025/03/22 06:20:06 DEBUG : : list: cached directories: 0
2025/03/22 06:20:06 DEBUG : : list: cached dir: 'timwn1742624406', cache ts: 2025-03-22 06:20:06.996998718 +0000 UTC m=+2.890889345
2025/03/22 06:20:06 DEBUG : removing 1 level 0 directories
2025/03/22 06:20:06 INFO  : Cache remote TestInternalCache:timwn1742624406: Removing directory
2025/03/22 06:20:06 DEBUG : Cache remote TestInternalCache:timwn1742624406: rmdir ''
2025/03/22 06:20:06 DEBUG : : rmdir: removed dir in source fs
2025/03/22 06:20:06 DEBUG : : rmdir: removed from cache
2025/03/22 06:20:06 INFO  : : rmdir: cache expired
2025/03/22 06:20:06 DEBUG : Cache remote TestInternalCache:timwn1742624406: Services stopped
--- SKIP: TestInternalMoveWithNotify (0.02s)
=== RUN   TestInternalNotifyCreatesEmptyParts
2025/03/22 06:20:07 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2025/03/22 06:20:07 DEBUG : Creating backend with remote "TestInternalCache-local:/tmp/TestInternalCache-local/tincep1742624407"
2025/03/22 06:20:07 DEBUG : TestInternalCache: wrapped TestInternalCache-local:/tmp/TestInternalCache-local/tincep1742624407 at root tincep1742624407
2025/03/22 06:20:07 INFO  : TestInternalCache: Cache DB path: /home/rclone/.cache/rclone/cache-backend/TestInternalCache.db
2025/03/22 06:20:07 INFO  : TestInternalCache: Cache chunk path: /home/rclone/.cache/rclone/cache-backend/TestInternalCache
2025/03/22 06:20:07 INFO  : TestInternalCache: Chunk Memory: true
2025/03/22 06:20:07 INFO  : TestInternalCache: Chunk Size: 5Mi
2025/03/22 06:20:07 INFO  : TestInternalCache: Chunk Total Size: 10Gi
2025/03/22 06:20:07 INFO  : TestInternalCache: Chunk Clean Interval: 1m0s
2025/03/22 06:20:07 INFO  : TestInternalCache: Workers: 4
2025/03/22 06:20:07 INFO  : TestInternalCache: File Age: 6h0m0s
2025/03/22 06:20:07 DEBUG : Waiting for deletions to finish
2025/03/22 06:20:07 DEBUG : Cache remote TestInternalCache:tincep1742624407: list ''
2025/03/22 06:20:07 DEBUG : : list: error: couldn't open bucket (tincep1742624407)
2025/03/22 06:20:07 ERROR : : error listing: directory not found
2025/03/22 06:20:07 DEBUG : Cache remote TestInternalCache:tincep1742624407: list ''
2025/03/22 06:20:07 DEBUG : : list: error: couldn't open bucket (tincep1742624407)
2025/03/22 06:20:07 ERROR : Cache remote TestInternalCache:tincep1742624407: Failed to list "": directory not found
2025/03/22 06:20:07 DEBUG : removing 1 level 0 directories
2025/03/22 06:20:07 INFO  : Cache remote TestInternalCache:tincep1742624407: Removing directory
2025/03/22 06:20:07 DEBUG : Cache remote TestInternalCache:tincep1742624407: rmdir ''
2025/03/22 06:20:07 ERROR : : Failed to rmdir: stat /tmp/TestInternalCache-local/tincep1742624407: no such file or directory
2025/03/22 06:20:07 DEBUG : Cache remote TestInternalCache:tincep1742624407: mkdir ''
2025/03/22 06:20:07 DEBUG : : mkdir: created dir in source fs
2025/03/22 06:20:07 DEBUG : : mkdir: added to cache
2025/03/22 06:20:07 DEBUG : : cache: expired tincep1742624407
2025/03/22 06:20:07 INFO  : : mkdir: cache expired
    cache_internal_test.go:539: Not external
2025/03/22 06:20:07 DEBUG : Cache remote TestInternalCache:tincep1742624407: list ''
2025/03/22 06:20:07 DEBUG : : list: cold listing: 2025-03-22 00:20:07.007159162 +0000 UTC
2025/03/22 06:20:07 DEBUG : : list: read 0 from source
2025/03/22 06:20:07 DEBUG : : list: source entries: []
2025/03/22 06:20:07 DEBUG : : list: cached directories: 0
2025/03/22 06:20:07 DEBUG : Waiting for deletions to finish
2025/03/22 06:20:07 DEBUG : : list: cached dir: 'tincep1742624407', cache ts: 2025-03-22 06:20:07.008422567 +0000 UTC m=+2.902313212
2025/03/22 06:20:07 DEBUG : Cache remote TestInternalCache:tincep1742624407: list ''
2025/03/22 06:20:07 DEBUG : : list: empty listing
2025/03/22 06:20:07 DEBUG : : list: read 0 from source
2025/03/22 06:20:07 DEBUG : : list: source entries: []
2025/03/22 06:20:07 DEBUG : : list: cached directories: 0
2025/03/22 06:20:07 DEBUG : : list: cached dir: 'tincep1742624407', cache ts: 2025-03-22 06:20:07.009614445 +0000 UTC m=+2.903505081
2025/03/22 06:20:07 DEBUG : removing 1 level 0 directories
2025/03/22 06:20:07 INFO  : Cache remote TestInternalCache:tincep1742624407: Removing directory
2025/03/22 06:20:07 DEBUG : Cache remote TestInternalCache:tincep1742624407: rmdir ''
2025/03/22 06:20:07 DEBUG : : rmdir: removed dir in source fs
2025/03/22 06:20:07 DEBUG : : rmdir: removed from cache
2025/03/22 06:20:07 INFO  : : rmdir: cache expired
2025/03/22 06:20:07 DEBUG : Cache remote TestInternalCache:tincep1742624407: Services stopped
--- SKIP: TestInternalNotifyCreatesEmptyParts (0.02s)
=== RUN   TestInternalChangeSeenAfterDirCacheFlush
2025/03/22 06:20:07 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2025/03/22 06:20:07 DEBUG : Creating backend with remote "TestInternalCache-local:/tmp/TestInternalCache-local/ticsadcf1742624407"
2025/03/22 06:20:07 DEBUG : TestInternalCache: wrapped TestInternalCache-local:/tmp/TestInternalCache-local/ticsadcf1742624407 at root ticsadcf1742624407
2025/03/22 06:20:07 INFO  : TestInternalCache: Cache DB path: /home/rclone/.cache/rclone/cache-backend/TestInternalCache.db
2025/03/22 06:20:07 INFO  : TestInternalCache: Cache chunk path: /home/rclone/.cache/rclone/cache-backend/TestInternalCache
2025/03/22 06:20:07 INFO  : TestInternalCache: Chunk Memory: true
2025/03/22 06:20:07 INFO  : TestInternalCache: Chunk Size: 5Mi
2025/03/22 06:20:07 INFO  : TestInternalCache: Chunk Total Size: 10Gi
2025/03/22 06:20:07 INFO  : TestInternalCache: Chunk Clean Interval: 1m0s
2025/03/22 06:20:07 INFO  : TestInternalCache: Workers: 4
2025/03/22 06:20:07 INFO  : TestInternalCache: File Age: 6h0m0s
2025/03/22 06:20:07 DEBUG : Waiting for deletions to finish
2025/03/22 06:20:07 DEBUG : Cache remote TestInternalCache:ticsadcf1742624407: list ''
2025/03/22 06:20:07 DEBUG : : list: error: couldn't open bucket (ticsadcf1742624407)
2025/03/22 06:20:07 ERROR : : error listing: directory not found
2025/03/22 06:20:07 DEBUG : Cache remote TestInternalCache:ticsadcf1742624407: list ''
2025/03/22 06:20:07 DEBUG : : list: error: couldn't open bucket (ticsadcf1742624407)
2025/03/22 06:20:07 ERROR : Cache remote TestInternalCache:ticsadcf1742624407: Failed to list "": directory not found
2025/03/22 06:20:07 DEBUG : removing 1 level 0 directories
2025/03/22 06:20:07 INFO  : Cache remote TestInternalCache:ticsadcf1742624407: Removing directory
2025/03/22 06:20:07 DEBUG : Cache remote TestInternalCache:ticsadcf1742624407: rmdir ''
2025/03/22 06:20:07 ERROR : : Failed to rmdir: stat /tmp/TestInternalCache-local/ticsadcf1742624407: no such file or directory
2025/03/22 06:20:07 DEBUG : Cache remote TestInternalCache:ticsadcf1742624407: mkdir ''
2025/03/22 06:20:07 DEBUG : : mkdir: created dir in source fs
2025/03/22 06:20:07 DEBUG : : mkdir: added to cache
2025/03/22 06:20:07 DEBUG : : cache: expired ticsadcf1742624407
2025/03/22 06:20:07 INFO  : : mkdir: cache expired
2025/03/22 06:20:07 DEBUG : Cache remote TestInternalCache:ticsadcf1742624407: put data at 'data.bin'
2025/03/22 06:20:07 DEBUG : data.bin: put: uploaded to remote fs
2025/03/22 06:20:07 DEBUG : data.bin: put: added to cache
2025/03/22 06:20:07 DEBUG : : cache: expired ticsadcf1742624407
2025/03/22 06:20:07 INFO  : : put: cache expired
2025/03/22 06:20:07 DEBUG : Cache remote TestInternalCache:ticsadcf1742624407: new object 'data.bin'
2025/03/22 06:20:07 DEBUG : data.bin: find: warm object: data.bin, expiring on: 2025-03-22 12:20:07.646136541 +0000 UTC
2025/03/22 06:20:07 DEBUG : Cache remote TestInternalCache:ticsadcf1742624407: new object 'data.bin'
2025/03/22 06:20:07 DEBUG : data.bin: find: warm object: data.bin, expiring on: 2025-03-22 12:20:07.646136541 +0000 UTC
2025/03/22 06:20:07 DEBUG : Cache remote TestInternalCache:ticsadcf1742624407: new object 'data.bin'
2025/03/22 06:20:07 DEBUG : data.bin: find: error: couldn't open parent bucket for ticsadcf1742624407
2025/03/22 06:20:07 DEBUG : data.bin: find: cached object
2025/03/22 06:20:07 DEBUG : Waiting for deletions to finish
2025/03/22 06:20:07 DEBUG : Cache remote TestInternalCache:ticsadcf1742624407: list ''
2025/03/22 06:20:07 DEBUG : : list: error: missing cached dir: 
2025/03/22 06:20:07 DEBUG : : list: read 1 from source
2025/03/22 06:20:07 DEBUG : : list: source entries: [data.bin]
2025/03/22 06:20:07 DEBUG : : list: cached object: data.bin
2025/03/22 06:20:07 DEBUG : : list: cached directories: 0
2025/03/22 06:20:07 DEBUG : : list: cached dir: 'ticsadcf1742624407', cache ts: 2025-03-22 06:20:07.651794568 +0000 UTC m=+3.545685193
2025/03/22 06:20:07 DEBUG : data.bin: removing object
2025/03/22 06:20:07 DEBUG : : cache: expired ticsadcf1742624407
2025/03/22 06:20:07 INFO  : data.bin: Deleted
2025/03/22 06:20:07 DEBUG : Cache remote TestInternalCache:ticsadcf1742624407: list ''
2025/03/22 06:20:07 DEBUG : : list: cold listing: 2025-03-22 00:20:07.657080306 +0000 UTC
2025/03/22 06:20:07 DEBUG : : list: read 0 from source
2025/03/22 06:20:07 DEBUG : : list: source entries: []
2025/03/22 06:20:07 DEBUG : : list: cached directories: 0
2025/03/22 06:20:07 DEBUG : : list: cached dir: 'ticsadcf1742624407', cache ts: 2025-03-22 06:20:07.65789755 +0000 UTC m=+3.551788167
2025/03/22 06:20:07 DEBUG : removing 1 level 0 directories
2025/03/22 06:20:07 INFO  : Cache remote TestInternalCache:ticsadcf1742624407: Removing directory
2025/03/22 06:20:07 DEBUG : Cache remote TestInternalCache:ticsadcf1742624407: rmdir ''
2025/03/22 06:20:07 DEBUG : : rmdir: removed dir in source fs
2025/03/22 06:20:07 DEBUG : : rmdir: removed from cache
2025/03/22 06:20:07 INFO  : : rmdir: cache expired
2025/03/22 06:20:07 DEBUG : Cache remote TestInternalCache:ticsadcf1742624407: Services stopped
--- PASS: TestInternalChangeSeenAfterDirCacheFlush (0.66s)
=== RUN   TestInternalCacheWrites
2025/03/22 06:20:07 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2025/03/22 06:20:07 DEBUG : Creating backend with remote "TestInternalCache-local:/tmp/TestInternalCache-local/ticw"
2025/03/22 06:20:07 DEBUG : TestInternalCache: wrapped TestInternalCache-local:/tmp/TestInternalCache-local/ticw at root ticw
2025/03/22 06:20:07 INFO  : TestInternalCache: Cache DB path: /home/rclone/.cache/rclone/cache-backend/TestInternalCache.db
2025/03/22 06:20:07 INFO  : TestInternalCache: Cache chunk path: /home/rclone/.cache/rclone/cache-backend/TestInternalCache
2025/03/22 06:20:07 INFO  : TestInternalCache: Chunk Memory: true
2025/03/22 06:20:07 INFO  : TestInternalCache: Chunk Size: 5Mi
2025/03/22 06:20:07 INFO  : TestInternalCache: Chunk Total Size: 10Gi
2025/03/22 06:20:07 INFO  : TestInternalCache: Chunk Clean Interval: 1m0s
2025/03/22 06:20:07 INFO  : TestInternalCache: Workers: 4
2025/03/22 06:20:07 INFO  : TestInternalCache: File Age: 6h0m0s
2025/03/22 06:20:07 INFO  : TestInternalCache: Cache Writes: enabled
2025/03/22 06:20:07 DEBUG : Waiting for deletions to finish
2025/03/22 06:20:07 DEBUG : Cache remote TestInternalCache:ticw: list ''
2025/03/22 06:20:07 DEBUG : : list: error: couldn't open bucket (ticw)
2025/03/22 06:20:07 ERROR : : error listing: directory not found
2025/03/22 06:20:07 DEBUG : Cache remote TestInternalCache:ticw: list ''
2025/03/22 06:20:07 DEBUG : : list: error: couldn't open bucket (ticw)
2025/03/22 06:20:07 ERROR : Cache remote TestInternalCache:ticw: Failed to list "": directory not found
2025/03/22 06:20:07 DEBUG : removing 1 level 0 directories
2025/03/22 06:20:07 INFO  : Cache remote TestInternalCache:ticw: Removing directory
2025/03/22 06:20:07 DEBUG : Cache remote TestInternalCache:ticw: rmdir ''
2025/03/22 06:20:07 ERROR : : Failed to rmdir: stat /tmp/TestInternalCache-local/ticw: no such file or directory
2025/03/22 06:20:07 DEBUG : Cache remote TestInternalCache:ticw: mkdir ''
2025/03/22 06:20:07 DEBUG : : mkdir: created dir in source fs
2025/03/22 06:20:07 DEBUG : : mkdir: added to cache
2025/03/22 06:20:07 DEBUG : : cache: expired ticw
2025/03/22 06:20:07 INFO  : : mkdir: cache expired
2025/03/22 06:20:08 DEBUG : Cache remote TestInternalCache:ticw: put data at 'data.bin'
2025/03/22 06:20:08 DEBUG : data.bin: put: uploaded to remote fs and saved in cache
2025/03/22 06:20:08 DEBUG : data.bin: put: added to cache
2025/03/22 06:20:08 DEBUG : : cache: expired ticw
2025/03/22 06:20:08 INFO  : : put: cache expired
2025/03/22 06:20:08 DEBUG : Cache remote TestInternalCache:ticw: new object 'data.bin'
2025/03/22 06:20:08 DEBUG : data.bin: find: warm object: data.bin, expiring on: 2025-03-22 12:20:08.234005913 +0000 UTC
2025/03/22 06:20:08 DEBUG : Waiting for deletions to finish
2025/03/22 06:20:08 DEBUG : Cache remote TestInternalCache:ticw: list ''
2025/03/22 06:20:08 DEBUG : : list: cold listing: 2025-03-22 00:20:08.239019701 +0000 UTC
2025/03/22 06:20:08 DEBUG : : list: read 1 from source
2025/03/22 06:20:08 DEBUG : : list: source entries: [data.bin]
2025/03/22 06:20:08 DEBUG : : list: cached object: data.bin
2025/03/22 06:20:08 DEBUG : : list: cached directories: 0
2025/03/22 06:20:08 DEBUG : : list: cached dir: 'ticw', cache ts: 2025-03-22 06:20:08.242233316 +0000 UTC m=+4.136123952
2025/03/22 06:20:08 DEBUG : data.bin: removing object
2025/03/22 06:20:08 DEBUG : : cache: expired ticw
2025/03/22 06:20:08 INFO  : data.bin: Deleted
2025/03/22 06:20:08 DEBUG : Cache remote TestInternalCache:ticw: list ''
2025/03/22 06:20:08 DEBUG : : list: cold listing: 2025-03-22 00:20:08.250003721 +0000 UTC
2025/03/22 06:20:08 DEBUG : : list: read 0 from source
2025/03/22 06:20:08 DEBUG : : list: source entries: []
2025/03/22 06:20:08 DEBUG : : list: cached directories: 0
2025/03/22 06:20:08 DEBUG : : list: cached dir: 'ticw', cache ts: 2025-03-22 06:20:08.251156767 +0000 UTC m=+4.145047403
2025/03/22 06:20:08 DEBUG : removing 1 level 0 directories
2025/03/22 06:20:08 INFO  : Cache remote TestInternalCache:ticw: Removing directory
2025/03/22 06:20:08 DEBUG : Cache remote TestInternalCache:ticw: rmdir ''
2025/03/22 06:20:08 DEBUG : : rmdir: removed dir in source fs
2025/03/22 06:20:08 DEBUG : : rmdir: removed from cache
2025/03/22 06:20:08 INFO  : : rmdir: cache expired
2025/03/22 06:20:08 DEBUG : Cache remote TestInternalCache:ticw: Services stopped
--- PASS: TestInternalCacheWrites (0.58s)
=== RUN   TestInternalMaxChunkSizeRespected
2025/03/22 06:20:08 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2025/03/22 06:20:08 DEBUG : Creating backend with remote "TestInternalCache-local:/tmp/TestInternalCache-local/timcsr1742624408"
2025/03/22 06:20:08 DEBUG : TestInternalCache: wrapped TestInternalCache-local:/tmp/TestInternalCache-local/timcsr1742624408 at root timcsr1742624408
2025/03/22 06:20:08 INFO  : TestInternalCache: Cache DB path: /home/rclone/.cache/rclone/cache-backend/TestInternalCache.db
2025/03/22 06:20:08 INFO  : TestInternalCache: Cache chunk path: /home/rclone/.cache/rclone/cache-backend/TestInternalCache
2025/03/22 06:20:08 INFO  : TestInternalCache: Chunk Memory: true
2025/03/22 06:20:08 INFO  : TestInternalCache: Chunk Size: 5Mi
2025/03/22 06:20:08 INFO  : TestInternalCache: Chunk Total Size: 10Gi
2025/03/22 06:20:08 INFO  : TestInternalCache: Chunk Clean Interval: 1m0s
2025/03/22 06:20:08 INFO  : TestInternalCache: Workers: 1
2025/03/22 06:20:08 INFO  : TestInternalCache: File Age: 6h0m0s
2025/03/22 06:20:08 DEBUG : Waiting for deletions to finish
2025/03/22 06:20:08 DEBUG : Cache remote TestInternalCache:timcsr1742624408: list ''
2025/03/22 06:20:08 DEBUG : : list: error: couldn't open bucket (timcsr1742624408)
2025/03/22 06:20:08 ERROR : : error listing: directory not found
2025/03/22 06:20:08 DEBUG : Cache remote TestInternalCache:timcsr1742624408: list ''
2025/03/22 06:20:08 DEBUG : : list: error: couldn't open bucket (timcsr1742624408)
2025/03/22 06:20:08 ERROR : Cache remote TestInternalCache:timcsr1742624408: Failed to list "": directory not found
2025/03/22 06:20:08 DEBUG : removing 1 level 0 directories
2025/03/22 06:20:08 INFO  : Cache remote TestInternalCache:timcsr1742624408: Removing directory
2025/03/22 06:20:08 DEBUG : Cache remote TestInternalCache:timcsr1742624408: rmdir ''
2025/03/22 06:20:08 ERROR : : Failed to rmdir: stat /tmp/TestInternalCache-local/timcsr1742624408: no such file or directory
2025/03/22 06:20:08 DEBUG : Cache remote TestInternalCache:timcsr1742624408: mkdir ''
2025/03/22 06:20:08 DEBUG : : mkdir: created dir in source fs
2025/03/22 06:20:08 DEBUG : : mkdir: added to cache
2025/03/22 06:20:08 DEBUG : : cache: expired timcsr1742624408
2025/03/22 06:20:08 INFO  : : mkdir: cache expired
2025/03/22 06:20:10 DEBUG : Cache remote TestInternalCache:timcsr1742624408: put data at 'data.bin'
2025/03/22 06:20:10 DEBUG : data.bin: put: uploaded to remote fs
2025/03/22 06:20:10 DEBUG : data.bin: put: added to cache
2025/03/22 06:20:10 DEBUG : : cache: expired timcsr1742624408
2025/03/22 06:20:10 INFO  : : put: cache expired
2025/03/22 06:20:10 DEBUG : Cache remote TestInternalCache:timcsr1742624408: new object 'data.bin'
2025/03/22 06:20:10 DEBUG : data.bin: find: warm object: data.bin, expiring on: 2025-03-22 12:20:10.405644161 +0000 UTC
2025/03/22 06:20:10 DEBUG : Cache remote TestInternalCache:timcsr1742624408: new object 'data.bin'
2025/03/22 06:20:10 DEBUG : data.bin: find: warm object: data.bin, expiring on: 2025-03-22 12:20:10.405644161 +0000 UTC
2025/03/22 06:20:10 DEBUG : timcsr1742624408/data.bin: moving offset set from 0 to 0
2025/03/22 06:20:10 DEBUG : timcsr1742624408/data.bin: 0: chunk retry storage: 0
2025/03/22 06:20:10 DEBUG : worker-0 <data.bin>: downloaded chunk 0
2025/03/22 06:20:11 DEBUG : timcsr1742624408/data.bin: cache reader closed 5242880
2025/03/22 06:20:11 DEBUG : timcsr1742624408/data.bin: moving offset set from 0 to 5242880
2025/03/22 06:20:11 DEBUG : timcsr1742624408/data.bin: 5242880: chunk retry storage: 0
2025/03/22 06:20:11 DEBUG : worker-0 <data.bin>: downloaded chunk 5242880
2025/03/22 06:20:11 DEBUG : timcsr1742624408/data.bin: cache reader closed 10485760
2025/03/22 06:20:11 DEBUG : timcsr1742624408/data.bin: moving offset set from 0 to 10485760
2025/03/22 06:20:11 DEBUG : timcsr1742624408/data.bin: 10485760: chunk retry storage: 0
2025/03/22 06:20:11 DEBUG : worker-0 <data.bin>: downloaded chunk 10485760
2025/03/22 06:20:12 DEBUG : timcsr1742624408/data.bin: cache reader closed 15728640
2025/03/22 06:20:12 DEBUG : timcsr1742624408/data.bin: moving offset set from 0 to 15728640
2025/03/22 06:20:12 DEBUG : timcsr1742624408/data.bin: 15728640: chunk retry storage: 0
2025/03/22 06:20:12 DEBUG : worker-0 <data.bin>: downloaded chunk 15728640
2025/03/22 06:20:12 DEBUG : timcsr1742624408/data.bin: cache reader closed 20971520
2025/03/22 06:20:12 DEBUG : timcsr1742624408/data.bin: moving offset set from 0 to 20971520
2025/03/22 06:20:12 DEBUG : timcsr1742624408/data.bin: 20971520: chunk retry storage: 0
2025/03/22 06:20:12 DEBUG : worker-0 <data.bin>: downloaded chunk 20971520
2025/03/22 06:20:13 DEBUG : timcsr1742624408/data.bin: cache reader closed 26214400
2025/03/22 06:20:13 DEBUG : timcsr1742624408/data.bin: moving offset set from 0 to 26214400
2025/03/22 06:20:13 DEBUG : timcsr1742624408/data.bin: 26214400: chunk retry storage: 0
2025/03/22 06:20:13 DEBUG : worker-0 <data.bin>: downloaded chunk 26214400
2025/03/22 06:20:13 DEBUG : timcsr1742624408/data.bin: cache reader closed 31457280
2025/03/22 06:20:13 DEBUG : Waiting for deletions to finish
2025/03/22 06:20:13 DEBUG : Cache remote TestInternalCache:timcsr1742624408: list ''
2025/03/22 06:20:13 DEBUG : : list: cold listing: 2025-03-22 00:20:10.408063897 +0000 UTC
2025/03/22 06:20:13 DEBUG : : list: read 1 from source
2025/03/22 06:20:13 DEBUG : : list: source entries: [data.bin]
2025/03/22 06:20:13 DEBUG : : list: cached object: data.bin
2025/03/22 06:20:13 DEBUG : : list: cached directories: 0
2025/03/22 06:20:13 DEBUG : : list: cached dir: 'timcsr1742624408', cache ts: 2025-03-22 06:20:13.571335111 +0000 UTC m=+9.465225777
2025/03/22 06:20:13 DEBUG : data.bin: removing object
2025/03/22 06:20:13 DEBUG : : cache: expired timcsr1742624408
2025/03/22 06:20:13 INFO  : data.bin: Deleted
2025/03/22 06:20:13 DEBUG : Cache remote TestInternalCache:timcsr1742624408: list ''
2025/03/22 06:20:13 DEBUG : : list: cold listing: 2025-03-22 00:20:13.587340512 +0000 UTC
2025/03/22 06:20:13 DEBUG : : list: read 0 from source
2025/03/22 06:20:13 DEBUG : : list: source entries: []
2025/03/22 06:20:13 DEBUG : : list: cached directories: 0
2025/03/22 06:20:13 DEBUG : : list: cached dir: 'timcsr1742624408', cache ts: 2025-03-22 06:20:13.588953521 +0000 UTC m=+9.482844188
2025/03/22 06:20:13 DEBUG : removing 1 level 0 directories
2025/03/22 06:20:13 INFO  : Cache remote TestInternalCache:timcsr1742624408: Removing directory
2025/03/22 06:20:13 DEBUG : Cache remote TestInternalCache:timcsr1742624408: rmdir ''
2025/03/22 06:20:13 DEBUG : : rmdir: removed dir in source fs
2025/03/22 06:20:13 DEBUG : : rmdir: removed from cache
2025/03/22 06:20:13 INFO  : : rmdir: cache expired
2025/03/22 06:20:13 DEBUG : Cache remote TestInternalCache:timcsr1742624408: Services stopped
--- PASS: TestInternalMaxChunkSizeRespected (5.34s)
=== RUN   TestInternalExpiredEntriesRemoved
2025/03/22 06:20:13 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/03/22 06:20:13 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2025/03/22 06:20:13 DEBUG : Creating backend with remote "TestInternalCache-local:/tmp/TestInternalCache-local/tib21171742624413"
2025/03/22 06:20:13 DEBUG : TestInternalCache: wrapped TestInternalCache-local:/tmp/TestInternalCache-local/tib21171742624413 at root tib21171742624413
2025/03/22 06:20:13 INFO  : TestInternalCache: Cache DB path: /home/rclone/.cache/rclone/cache-backend/TestInternalCache.db
2025/03/22 06:20:13 INFO  : TestInternalCache: Cache chunk path: /home/rclone/.cache/rclone/cache-backend/TestInternalCache
2025/03/22 06:20:13 INFO  : TestInternalCache: Chunk Memory: true
2025/03/22 06:20:13 INFO  : TestInternalCache: Chunk Size: 5Mi
2025/03/22 06:20:13 INFO  : TestInternalCache: Chunk Total Size: 10Gi
2025/03/22 06:20:13 INFO  : TestInternalCache: Chunk Clean Interval: 15m0s
2025/03/22 06:20:13 INFO  : TestInternalCache: Workers: 4
2025/03/22 06:20:13 INFO  : TestInternalCache: File Age: 3d
2025/03/22 06:20:13 DEBUG : Waiting for deletions to finish
2025/03/22 06:20:13 DEBUG : Cache remote TestInternalCache:tib21171742624413: list ''
2025/03/22 06:20:13 DEBUG : : list: error: couldn't open bucket (tib21171742624413)
2025/03/22 06:20:13 ERROR : : error listing: directory not found
2025/03/22 06:20:13 DEBUG : Cache remote TestInternalCache:tib21171742624413: list ''
2025/03/22 06:20:13 DEBUG : : list: error: couldn't open bucket (tib21171742624413)
2025/03/22 06:20:13 ERROR : Cache remote TestInternalCache:tib21171742624413: Failed to list "": directory not found
2025/03/22 06:20:13 DEBUG : removing 1 level 0 directories
2025/03/22 06:20:13 INFO  : Cache remote TestInternalCache:tib21171742624413: Removing directory
2025/03/22 06:20:13 DEBUG : Cache remote TestInternalCache:tib21171742624413: rmdir ''
2025/03/22 06:20:13 ERROR : : Failed to rmdir: stat /tmp/TestInternalCache-local/tib21171742624413: no such file or directory
2025/03/22 06:20:13 DEBUG : Cache remote TestInternalCache:tib21171742624413: mkdir ''
2025/03/22 06:20:13 DEBUG : : mkdir: created dir in source fs
2025/03/22 06:20:13 DEBUG : : mkdir: added to cache
2025/03/22 06:20:13 DEBUG : : cache: expired tib21171742624413
2025/03/22 06:20:13 INFO  : : mkdir: cache expired
2025/03/22 06:20:13 DEBUG : Cache remote TestInternalCache:tib21171742624413: list 'test/dir1/dir2'
2025/03/22 06:20:13 DEBUG : test/dir1/dir2: list: error: couldn't open bucket (tib21171742624413/test/dir1/dir2)
2025/03/22 06:20:13 DEBUG : test/dir1/dir2: list: read 1 from source
2025/03/22 06:20:13 DEBUG : test/dir1/dir2: list: source entries: [test/dir1/dir2/test.txt]
2025/03/22 06:20:13 DEBUG : test/dir1/dir2: list: cached object: test/dir1/dir2/test.txt
2025/03/22 06:20:13 DEBUG : test/dir1/dir2: list: cached directories: 0
2025/03/22 06:20:13 DEBUG : test/dir1/dir2: list: cached dir: 'tib21171742624413/test/dir1/dir2', cache ts: 2025-03-22 06:20:13.616060866 +0000 UTC m=+9.509951532
2025/03/22 06:20:13 NOTICE: len: 1
2025/03/22 06:20:43 DEBUG : Cache remote TestInternalCache:tib21171742624413: list 'test/dir1/dir2'
2025/03/22 06:20:43 DEBUG : test/dir1/dir2: list: warm 1 from cache for: tib21171742624413/test/dir1/dir2, expiring on: 2025-03-25 06:20:13.616060866 +0000 UTC
2025/03/22 06:20:43 DEBUG : test/dir1/dir2: list: cached entries: [test/dir1/dir2/test.txt]
2025/03/22 06:20:43 NOTICE: len: 1
2025/03/22 06:20:43 DEBUG : Cache remote TestInternalCache:tib21171742624413: list 'test/dir1'
2025/03/22 06:20:43 DEBUG : test/dir1: list: error: missing cached dir: test/dir1
2025/03/22 06:20:43 DEBUG : test/dir1: list: read 4 from source
2025/03/22 06:20:43 DEBUG : test/dir1: list: source entries: [test/dir1/dir3 test/dir1/dir2 test/dir1/dir4 test/dir1/dir1]
2025/03/22 06:20:43 DEBUG : test/dir1: list: cached directories: 4
2025/03/22 06:20:43 DEBUG : test/dir1: list: cached dir: 'tib21171742624413/test/dir1', cache ts: 2025-03-22 06:20:43.626490509 +0000 UTC m=+39.520381164
2025/03/22 06:20:43 NOTICE: len: 4
2025/03/22 06:20:43 DEBUG : Cache remote TestInternalCache:tib21171742624413: list 'test'
2025/03/22 06:20:43 DEBUG : test: list: error: missing cached dir: test
2025/03/22 06:20:43 DEBUG : test: list: read 4 from source
2025/03/22 06:20:43 DEBUG : test: list: source entries: [test/dir3 test/dir2 test/dir4 test/dir1]
2025/03/22 06:20:43 DEBUG : test: list: cached directories: 4
2025/03/22 06:20:43 DEBUG : test: list: cached dir: 'tib21171742624413/test', cache ts: 2025-03-22 06:20:43.629576805 +0000 UTC m=+39.523467461
2025/03/22 06:20:43 NOTICE: len: 4
2025/03/22 06:20:43 DEBUG : Waiting for deletions to finish
2025/03/22 06:20:43 DEBUG : Cache remote TestInternalCache:tib21171742624413: list ''
2025/03/22 06:20:43 DEBUG : : list: cold listing: 2025-03-19 06:20:13.611186901 +0000 UTC
2025/03/22 06:20:43 DEBUG : : list: read 1 from source
2025/03/22 06:20:43 DEBUG : : list: source entries: [test]
2025/03/22 06:20:43 DEBUG : : list: cached directories: 1
2025/03/22 06:20:43 DEBUG : : list: cached dir: 'tib21171742624413', cache ts: 2025-03-22 06:20:43.632346166 +0000 UTC m=+39.526236792
2025/03/22 06:20:43 DEBUG : Cache remote TestInternalCache:tib21171742624413: list 'test'
2025/03/22 06:20:43 DEBUG : test: list: warm 4 from cache for: tib21171742624413/test, expiring on: 2025-03-25 06:20:43.631259946 +0000 UTC
2025/03/22 06:20:43 DEBUG : test: list: cached entries: [test/dir1 test/dir2 test/dir3 test/dir4]
2025/03/22 06:20:43 DEBUG : Cache remote TestInternalCache:tib21171742624413: list 'test/dir4'
2025/03/22 06:20:43 DEBUG : test/dir4: list: empty listing
2025/03/22 06:20:43 DEBUG : test/dir4: list: read 4 from source
2025/03/22 06:20:43 DEBUG : test/dir4: list: source entries: [test/dir4/dir3 test/dir4/dir2 test/dir4/dir4 test/dir4/dir1]
2025/03/22 06:20:43 DEBUG : Cache remote TestInternalCache:tib21171742624413: list 'test/dir2'
2025/03/22 06:20:43 DEBUG : test/dir2: list: empty listing
2025/03/22 06:20:43 DEBUG : test/dir2: list: read 4 from source
2025/03/22 06:20:43 DEBUG : test/dir2: list: source entries: [test/dir2/dir3 test/dir2/dir2 test/dir2/dir4 test/dir2/dir1]
2025/03/22 06:20:43 DEBUG : Cache remote TestInternalCache:tib21171742624413: list 'test/dir1'
2025/03/22 06:20:43 DEBUG : test/dir1: list: warm 4 from cache for: tib21171742624413/test/dir1, expiring on: 2025-03-25 06:20:43.628376491 +0000 UTC
2025/03/22 06:20:43 DEBUG : test/dir1: list: cached entries: [test/dir1/dir1 test/dir1/dir2 test/dir1/dir3 test/dir1/dir4]
2025/03/22 06:20:43 DEBUG : Cache remote TestInternalCache:tib21171742624413: list 'test/dir1/dir4'
2025/03/22 06:20:43 DEBUG : test/dir1/dir4: list: empty listing
2025/03/22 06:20:43 DEBUG : test/dir1/dir4: list: read 1 from source
2025/03/22 06:20:43 DEBUG : test/dir1/dir4: list: source entries: [test/dir1/dir4/test.txt]
2025/03/22 06:20:43 DEBUG : Cache remote TestInternalCache:tib21171742624413: list 'test/dir1/dir1'
2025/03/22 06:20:43 DEBUG : test/dir1/dir1: list: empty listing
2025/03/22 06:20:43 DEBUG : test/dir1/dir1: list: read 1 from source
2025/03/22 06:20:43 DEBUG : test/dir1/dir1: list: source entries: [test/dir1/dir1/test.txt]
2025/03/22 06:20:43 DEBUG : Cache remote TestInternalCache:tib21171742624413: list 'test/dir1/dir2'
2025/03/22 06:20:43 DEBUG : test/dir1/dir2: list: warm 1 from cache for: tib21171742624413/test/dir1/dir2, expiring on: 2025-03-25 06:20:43.624881376 +0000 UTC
2025/03/22 06:20:43 DEBUG : test/dir1/dir2: list: cached entries: [test/dir1/dir2/test.txt]
2025/03/22 06:20:43 DEBUG : Cache remote TestInternalCache:tib21171742624413: list 'test/dir1/dir3'
2025/03/22 06:20:43 DEBUG : test/dir1/dir3: list: empty listing
2025/03/22 06:20:43 DEBUG : test/dir1/dir3: list: read 1 from source
2025/03/22 06:20:43 DEBUG : test/dir1/dir3: list: source entries: [test/dir1/dir3/test.txt]
2025/03/22 06:20:43 DEBUG : test/dir4: list: cached directories: 4
2025/03/22 06:20:43 DEBUG : Cache remote TestInternalCache:tib21171742624413: list 'test/dir3'
2025/03/22 06:20:43 DEBUG : test/dir3: list: empty listing
2025/03/22 06:20:43 DEBUG : test/dir3: list: read 4 from source
2025/03/22 06:20:43 DEBUG : test/dir3: list: source entries: [test/dir3/dir3 test/dir3/dir2 test/dir3/dir4 test/dir3/dir1]
2025/03/22 06:20:43 DEBUG : test/dir4: list: cached dir: 'tib21171742624413/test/dir4', cache ts: 2025-03-22 06:20:43.634891697 +0000 UTC m=+39.528782323
2025/03/22 06:20:43 DEBUG : Cache remote TestInternalCache:tib21171742624413: list 'test/dir4/dir3'
2025/03/22 06:20:43 DEBUG : test/dir4/dir3: list: empty listing
2025/03/22 06:20:43 DEBUG : test/dir4/dir3: list: read 1 from source
2025/03/22 06:20:43 DEBUG : test/dir4/dir3: list: source entries: [test/dir4/dir3/test.txt]
2025/03/22 06:20:43 DEBUG : Cache remote TestInternalCache:tib21171742624413: list 'test/dir4/dir1'
2025/03/22 06:20:43 DEBUG : test/dir4/dir1: list: empty listing
2025/03/22 06:20:43 DEBUG : test/dir4/dir1: list: read 1 from source
2025/03/22 06:20:43 DEBUG : test/dir4/dir1: list: source entries: [test/dir4/dir1/test.txt]
2025/03/22 06:20:43 DEBUG : Cache remote TestInternalCache:tib21171742624413: list 'test/dir4/dir2'
2025/03/22 06:20:43 DEBUG : test/dir4/dir2: list: empty listing
2025/03/22 06:20:43 DEBUG : test/dir4/dir2: list: read 1 from source
2025/03/22 06:20:43 DEBUG : test/dir4/dir2: list: source entries: [test/dir4/dir2/test.txt]
2025/03/22 06:20:43 DEBUG : test/dir4/dir3: list: cached object: test/dir4/dir3/test.txt
2025/03/22 06:20:43 DEBUG : test/dir4/dir3: list: cached directories: 0
2025/03/22 06:20:43 DEBUG : test/dir4/dir3: list: cached dir: 'tib21171742624413/test/dir4/dir3', cache ts: 2025-03-22 06:20:43.637286546 +0000 UTC m=+39.531177172
2025/03/22 06:20:43 DEBUG : Cache remote TestInternalCache:tib21171742624413: list 'test/dir4/dir4'
2025/03/22 06:20:43 DEBUG : test/dir4/dir4: list: empty listing
2025/03/22 06:20:43 DEBUG : test/dir4/dir4: list: read 1 from source
2025/03/22 06:20:43 DEBUG : test/dir4/dir4: list: source entries: [test/dir4/dir4/test.txt]
2025/03/22 06:20:43 DEBUG : test/dir4/dir3/test.txt: removing object
2025/03/22 06:20:43 DEBUG : test/dir3: list: cached directories: 4
2025/03/22 06:20:43 DEBUG : test/dir4/dir1: list: cached object: test/dir4/dir1/test.txt
2025/03/22 06:20:43 DEBUG : test/dir4/dir1: list: cached directories: 0
2025/03/22 06:20:43 DEBUG : test/dir1/dir4: list: cached object: test/dir1/dir4/test.txt
2025/03/22 06:20:43 DEBUG : test/dir1/dir4: list: cached directories: 0
2025/03/22 06:20:43 DEBUG : test/dir1/dir1: list: cached object: test/dir1/dir1/test.txt
2025/03/22 06:20:43 DEBUG : test/dir1/dir1: list: cached directories: 0
2025/03/22 06:20:43 DEBUG : test/dir1/dir2/test.txt: removing object
2025/03/22 06:20:43 DEBUG : test/dir1/dir3: list: cached object: test/dir1/dir3/test.txt
2025/03/22 06:20:43 DEBUG : test/dir1/dir3: list: cached directories: 0
2025/03/22 06:20:43 DEBUG : test/dir2: list: cached directories: 4
2025/03/22 06:20:43 DEBUG : test/dir4/dir2: list: cached object: test/dir4/dir2/test.txt
2025/03/22 06:20:43 DEBUG : test/dir4/dir2: list: cached directories: 0
2025/03/22 06:20:43 DEBUG : test/dir4/dir4: list: cached object: test/dir4/dir4/test.txt
2025/03/22 06:20:43 DEBUG : test/dir4/dir4: list: cached directories: 0
2025/03/22 06:20:43 DEBUG : test/dir3: list: cached dir: 'tib21171742624413/test/dir3', cache ts: 2025-03-22 06:20:43.639571607 +0000 UTC m=+39.533462264
2025/03/22 06:20:43 DEBUG : Cache remote TestInternalCache:tib21171742624413: list 'test/dir3/dir1'
2025/03/22 06:20:43 DEBUG : test/dir3/dir1: list: empty listing
2025/03/22 06:20:43 DEBUG : test/dir3/dir1: list: read 1 from source
2025/03/22 06:20:43 DEBUG : test/dir3/dir1: list: source entries: [test/dir3/dir1/test.txt]
2025/03/22 06:20:43 DEBUG : test/dir4/dir1: list: cached dir: 'tib21171742624413/test/dir4/dir1', cache ts: 2025-03-22 06:20:43.640774957 +0000 UTC m=+39.534665624
2025/03/22 06:20:43 DEBUG : Cache remote TestInternalCache:tib21171742624413: list 'test/dir3/dir2'
2025/03/22 06:20:43 DEBUG : test/dir3/dir2: list: empty listing
2025/03/22 06:20:43 DEBUG : test/dir4/dir1/test.txt: removing object
2025/03/22 06:20:43 DEBUG : test/dir3/dir2: list: read 1 from source
2025/03/22 06:20:43 DEBUG : test/dir3/dir2: list: source entries: [test/dir3/dir2/test.txt]
2025/03/22 06:20:43 DEBUG : test/dir1/dir4: list: cached dir: 'tib21171742624413/test/dir1/dir4', cache ts: 2025-03-22 06:20:43.642013183 +0000 UTC m=+39.535903909
2025/03/22 06:20:43 DEBUG : Cache remote TestInternalCache:tib21171742624413: list 'test/dir3/dir3'
2025/03/22 06:20:43 DEBUG : test/dir1/dir4/test.txt: removing object
2025/03/22 06:20:43 DEBUG : test/dir3/dir3: list: empty listing
2025/03/22 06:20:43 DEBUG : test/dir3/dir3: list: read 1 from source
2025/03/22 06:20:43 DEBUG : test/dir3/dir3: list: source entries: [test/dir3/dir3/test.txt]
2025/03/22 06:20:43 DEBUG : test/dir1/dir1: list: cached dir: 'tib21171742624413/test/dir1/dir1', cache ts: 2025-03-22 06:20:43.643342309 +0000 UTC m=+39.537232965
2025/03/22 06:20:43 DEBUG : Cache remote TestInternalCache:tib21171742624413: list 'test/dir3/dir4'
2025/03/22 06:20:43 DEBUG : test/dir1/dir1/test.txt: removing object
2025/03/22 06:20:43 DEBUG : test/dir3/dir4: list: empty listing
2025/03/22 06:20:43 DEBUG : test/dir3/dir4: list: read 1 from source
2025/03/22 06:20:43 DEBUG : test/dir3/dir4: list: source entries: [test/dir3/dir4/test.txt]
2025/03/22 06:20:43 DEBUG : test/dir1/dir3: list: cached dir: 'tib21171742624413/test/dir1/dir3', cache ts: 2025-03-22 06:20:43.646136888 +0000 UTC m=+39.540027513
2025/03/22 06:20:43 DEBUG : test/dir1/dir3/test.txt: removing object
2025/03/22 06:20:43 DEBUG : test/dir2: list: cached dir: 'tib21171742624413/test/dir2', cache ts: 2025-03-22 06:20:43.64769326 +0000 UTC m=+39.541583927
2025/03/22 06:20:43 DEBUG : Cache remote TestInternalCache:tib21171742624413: list 'test/dir2/dir2'
2025/03/22 06:20:43 DEBUG : Cache remote TestInternalCache:tib21171742624413: list 'test/dir2/dir1'
2025/03/22 06:20:43 DEBUG : test/dir2/dir2: list: empty listing
2025/03/22 06:20:43 DEBUG : test/dir2/dir1: list: empty listing
2025/03/22 06:20:43 DEBUG : test/dir2/dir2: list: read 1 from source
2025/03/22 06:20:43 DEBUG : test/dir2/dir2: list: source entries: [test/dir2/dir2/test.txt]
2025/03/22 06:20:43 DEBUG : test/dir2/dir1: list: read 1 from source
2025/03/22 06:20:43 DEBUG : test/dir2/dir1: list: source entries: [test/dir2/dir1/test.txt]
2025/03/22 06:20:43 DEBUG : test/dir4/dir2: list: cached dir: 'tib21171742624413/test/dir4/dir2', cache ts: 2025-03-22 06:20:43.649154876 +0000 UTC m=+39.543045502
2025/03/22 06:20:43 DEBUG : Cache remote TestInternalCache:tib21171742624413: list 'test/dir2/dir3'
2025/03/22 06:20:43 DEBUG : test/dir2/dir3: list: empty listing
2025/03/22 06:20:43 DEBUG : test/dir2/dir3: list: read 1 from source
2025/03/22 06:20:43 DEBUG : test/dir2/dir3: list: source entries: [test/dir2/dir3/test.txt]
2025/03/22 06:20:43 DEBUG : test/dir4/dir2/test.txt: removing object
2025/03/22 06:20:43 DEBUG : test/dir4/dir4: list: cached dir: 'tib21171742624413/test/dir4/dir4', cache ts: 2025-03-22 06:20:43.650284748 +0000 UTC m=+39.544175374
2025/03/22 06:20:43 DEBUG : Cache remote TestInternalCache:tib21171742624413: list 'test/dir2/dir4'
2025/03/22 06:20:43 DEBUG : test/dir2/dir4: list: empty listing
2025/03/22 06:20:43 DEBUG : test/dir4/dir4/test.txt: removing object
2025/03/22 06:20:43 DEBUG : test/dir2/dir4: list: read 1 from source
2025/03/22 06:20:43 DEBUG : test/dir2/dir4: list: source entries: [test/dir2/dir4/test.txt]
2025/03/22 06:20:43 DEBUG : test/dir3/dir1: list: cached object: test/dir3/dir1/test.txt
2025/03/22 06:20:43 DEBUG : test/dir3/dir1: list: cached directories: 0
2025/03/22 06:20:43 DEBUG : test/dir3/dir2: list: cached object: test/dir3/dir2/test.txt
2025/03/22 06:20:43 DEBUG : test/dir3/dir2: list: cached directories: 0
2025/03/22 06:20:43 DEBUG : test/dir3/dir3: list: cached object: test/dir3/dir3/test.txt
2025/03/22 06:20:43 DEBUG : test/dir3/dir3: list: cached directories: 0
2025/03/22 06:20:43 DEBUG : test/dir3/dir4: list: cached object: test/dir3/dir4/test.txt
2025/03/22 06:20:43 DEBUG : test/dir3/dir4: list: cached directories: 0
2025/03/22 06:20:43 DEBUG : test/dir2/dir2: list: cached object: test/dir2/dir2/test.txt
2025/03/22 06:20:43 DEBUG : test/dir2/dir2: list: cached directories: 0
2025/03/22 06:20:43 DEBUG : test/dir2/dir1: list: cached object: test/dir2/dir1/test.txt
2025/03/22 06:20:43 DEBUG : test/dir2/dir1: list: cached directories: 0
2025/03/22 06:20:43 DEBUG : test/dir2/dir3: list: cached object: test/dir2/dir3/test.txt
2025/03/22 06:20:43 DEBUG : test/dir2/dir3: list: cached directories: 0
2025/03/22 06:20:43 DEBUG : test/dir2/dir4: list: cached object: test/dir2/dir4/test.txt
2025/03/22 06:20:43 DEBUG : test/dir4/dir3: cache: expired tib21171742624413/test/dir4/dir3
2025/03/22 06:20:43 DEBUG : test/dir2/dir4: list: cached directories: 0
2025/03/22 06:20:43 DEBUG : test/dir4/dir3: cache: expired tib21171742624413/test/dir4
2025/03/22 06:20:43 DEBUG : test/dir4/dir3: cache: expired tib21171742624413/test
2025/03/22 06:20:43 DEBUG : test/dir4/dir3: cache: expired tib21171742624413
2025/03/22 06:20:43 INFO  : test/dir4/dir3/test.txt: Deleted
2025/03/22 06:20:43 DEBUG : test/dir3/dir1: list: cached dir: 'tib21171742624413/test/dir3/dir1', cache ts: 2025-03-22 06:20:43.667832376 +0000 UTC m=+39.561723031
2025/03/22 06:20:43 DEBUG : test/dir3/dir1/test.txt: removing object
2025/03/22 06:20:43 DEBUG : test/dir3/dir2: list: cached dir: 'tib21171742624413/test/dir3/dir2', cache ts: 2025-03-22 06:20:43.671863066 +0000 UTC m=+39.565753692
2025/03/22 06:20:43 DEBUG : test/dir3/dir3: list: cached dir: 'tib21171742624413/test/dir3/dir3', cache ts: 2025-03-22 06:20:43.674839306 +0000 UTC m=+39.568729963
2025/03/22 06:20:43 DEBUG : test/dir3/dir4: list: cached dir: 'tib21171742624413/test/dir3/dir4', cache ts: 2025-03-22 06:20:43.678157889 +0000 UTC m=+39.572048625
2025/03/22 06:20:43 DEBUG : test/dir2/dir2: list: cached dir: 'tib21171742624413/test/dir2/dir2', cache ts: 2025-03-22 06:20:43.681061983 +0000 UTC m=+39.574952639
2025/03/22 06:20:43 DEBUG : test/dir2/dir1: list: cached dir: 'tib21171742624413/test/dir2/dir1', cache ts: 2025-03-22 06:20:43.6826251 +0000 UTC m=+39.576515756
2025/03/22 06:20:43 DEBUG : test/dir2/dir3: list: cached dir: 'tib21171742624413/test/dir2/dir3', cache ts: 2025-03-22 06:20:43.684081073 +0000 UTC m=+39.577971730
2025/03/22 06:20:43 DEBUG : test/dir1/dir2: cache: expired tib21171742624413/test/dir1/dir2
2025/03/22 06:20:43 DEBUG : test/dir1/dir2: cache: expired tib21171742624413/test/dir1
2025/03/22 06:20:43 DEBUG : test/dir1/dir2: cache: expired tib21171742624413/test
2025/03/22 06:20:43 DEBUG : test/dir1/dir2: cache: expired tib21171742624413
2025/03/22 06:20:43 DEBUG : test/dir2/dir4: list: cached dir: 'tib21171742624413/test/dir2/dir4', cache ts: 2025-03-22 06:20:43.688197536 +0000 UTC m=+39.582088202
2025/03/22 06:20:43 INFO  : test/dir1/dir2/test.txt: Deleted
2025/03/22 06:20:43 DEBUG : test/dir3/dir2/test.txt: removing object
2025/03/22 06:20:43 DEBUG : test/dir4/dir1: cache: expired tib21171742624413/test/dir4/dir1
2025/03/22 06:20:43 DEBUG : test/dir4/dir1: cache: expired tib21171742624413/test/dir4
2025/03/22 06:20:43 DEBUG : test/dir4/dir1: cache: expired tib21171742624413/test
2025/03/22 06:20:43 DEBUG : test/dir4/dir1: cache: expired tib21171742624413
2025/03/22 06:20:43 INFO  : test/dir4/dir1/test.txt: Deleted
2025/03/22 06:20:43 DEBUG : test/dir3/dir3/test.txt: removing object
2025/03/22 06:20:43 DEBUG : test/dir1/dir4: cache: expired tib21171742624413/test/dir1/dir4
2025/03/22 06:20:43 DEBUG : test/dir1/dir4: cache: expired tib21171742624413/test/dir1
2025/03/22 06:20:43 DEBUG : test/dir1/dir4: cache: expired tib21171742624413/test
2025/03/22 06:20:43 DEBUG : test/dir1/dir4: cache: expired tib21171742624413
2025/03/22 06:20:43 INFO  : test/dir1/dir4/test.txt: Deleted
2025/03/22 06:20:43 DEBUG : test/dir3/dir4/test.txt: removing object
2025/03/22 06:20:43 DEBUG : test/dir1/dir1: cache: expired tib21171742624413/test/dir1/dir1
2025/03/22 06:20:43 DEBUG : test/dir1/dir1: cache: expired tib21171742624413/test/dir1
2025/03/22 06:20:43 DEBUG : test/dir1/dir1: cache: expired tib21171742624413/test
2025/03/22 06:20:43 DEBUG : test/dir1/dir1: cache: expired tib21171742624413
2025/03/22 06:20:43 INFO  : test/dir1/dir1/test.txt: Deleted
2025/03/22 06:20:43 DEBUG : test/dir2/dir2/test.txt: removing object
2025/03/22 06:20:43 DEBUG : test/dir1/dir3: cache: expired tib21171742624413/test/dir1/dir3
2025/03/22 06:20:43 DEBUG : test/dir1/dir3: cache: expired tib21171742624413/test/dir1
2025/03/22 06:20:43 DEBUG : test/dir1/dir3: cache: expired tib21171742624413/test
2025/03/22 06:20:43 DEBUG : test/dir1/dir3: cache: expired tib21171742624413
2025/03/22 06:20:43 INFO  : test/dir1/dir3/test.txt: Deleted
2025/03/22 06:20:43 DEBUG : test/dir2/dir1/test.txt: removing object
2025/03/22 06:20:43 DEBUG : test/dir4/dir2: cache: expired tib21171742624413/test/dir4/dir2
2025/03/22 06:20:43 DEBUG : test/dir4/dir2: cache: expired tib21171742624413/test/dir4
2025/03/22 06:20:43 DEBUG : test/dir4/dir2: cache: expired tib21171742624413/test
2025/03/22 06:20:43 DEBUG : test/dir4/dir2: cache: expired tib21171742624413
2025/03/22 06:20:43 INFO  : test/dir4/dir2/test.txt: Deleted
2025/03/22 06:20:43 DEBUG : test/dir2/dir3/test.txt: removing object
2025/03/22 06:20:43 DEBUG : test/dir4/dir4: cache: expired tib21171742624413/test/dir4/dir4
2025/03/22 06:20:43 DEBUG : test/dir4/dir4: cache: expired tib21171742624413/test/dir4
2025/03/22 06:20:43 DEBUG : test/dir4/dir4: cache: expired tib21171742624413/test
2025/03/22 06:20:43 DEBUG : test/dir4/dir4: cache: expired tib21171742624413
2025/03/22 06:20:43 INFO  : test/dir4/dir4/test.txt: Deleted
2025/03/22 06:20:43 DEBUG : test/dir2/dir4/test.txt: removing object
2025/03/22 06:20:43 DEBUG : test/dir3/dir1: cache: expired tib21171742624413/test/dir3/dir1
2025/03/22 06:20:43 DEBUG : test/dir3/dir1: cache: expired tib21171742624413/test/dir3
2025/03/22 06:20:43 DEBUG : test/dir3/dir1: cache: expired tib21171742624413/test
2025/03/22 06:20:43 DEBUG : test/dir3/dir1: cache: expired tib21171742624413
2025/03/22 06:20:43 INFO  : test/dir3/dir1/test.txt: Deleted
2025/03/22 06:20:43 DEBUG : test/dir3/dir2: cache: expired tib21171742624413/test/dir3/dir2
2025/03/22 06:20:43 DEBUG : test/dir3/dir2: cache: expired tib21171742624413/test/dir3
2025/03/22 06:20:43 DEBUG : test/dir3/dir2: cache: expired tib21171742624413/test
2025/03/22 06:20:43 DEBUG : test/dir3/dir2: cache: expired tib21171742624413
2025/03/22 06:20:43 INFO  : test/dir3/dir2/test.txt: Deleted
2025/03/22 06:20:43 DEBUG : test/dir3/dir3: cache: expired tib21171742624413/test/dir3/dir3
2025/03/22 06:20:43 DEBUG : test/dir3/dir3: cache: expired tib21171742624413/test/dir3
2025/03/22 06:20:43 DEBUG : test/dir3/dir3: cache: expired tib21171742624413/test
2025/03/22 06:20:43 DEBUG : test/dir3/dir3: cache: expired tib21171742624413
2025/03/22 06:20:43 INFO  : test/dir3/dir3/test.txt: Deleted
2025/03/22 06:20:43 DEBUG : test/dir3/dir4: cache: expired tib21171742624413/test/dir3/dir4
2025/03/22 06:20:43 DEBUG : test/dir3/dir4: cache: expired tib21171742624413/test/dir3
2025/03/22 06:20:43 DEBUG : test/dir3/dir4: cache: expired tib21171742624413/test
2025/03/22 06:20:43 DEBUG : test/dir3/dir4: cache: expired tib21171742624413
2025/03/22 06:20:43 INFO  : test/dir3/dir4/test.txt: Deleted
2025/03/22 06:20:43 DEBUG : test/dir2/dir2: cache: expired tib21171742624413/test/dir2/dir2
2025/03/22 06:20:43 DEBUG : test/dir2/dir2: cache: expired tib21171742624413/test/dir2
2025/03/22 06:20:43 DEBUG : test/dir2/dir2: cache: expired tib21171742624413/test
2025/03/22 06:20:43 DEBUG : test/dir2/dir2: cache: expired tib21171742624413
2025/03/22 06:20:43 INFO  : test/dir2/dir2/test.txt: Deleted
2025/03/22 06:20:43 DEBUG : test/dir2/dir1: cache: expired tib21171742624413/test/dir2/dir1
2025/03/22 06:20:43 DEBUG : test/dir2/dir1: cache: expired tib21171742624413/test/dir2
2025/03/22 06:20:43 DEBUG : test/dir2/dir1: cache: expired tib21171742624413/test
2025/03/22 06:20:43 DEBUG : test/dir2/dir1: cache: expired tib21171742624413
2025/03/22 06:20:43 INFO  : test/dir2/dir1/test.txt: Deleted
2025/03/22 06:20:43 DEBUG : test/dir2/dir3: cache: expired tib21171742624413/test/dir2/dir3
2025/03/22 06:20:43 DEBUG : test/dir2/dir3: cache: expired tib21171742624413/test/dir2
2025/03/22 06:20:43 DEBUG : test/dir2/dir3: cache: expired tib21171742624413/test
2025/03/22 06:20:43 DEBUG : test/dir2/dir3: cache: expired tib21171742624413
2025/03/22 06:20:43 INFO  : test/dir2/dir3/test.txt: Deleted
2025/03/22 06:20:43 DEBUG : test/dir2/dir4: cache: expired tib21171742624413/test/dir2/dir4
2025/03/22 06:20:43 DEBUG : test/dir2/dir4: cache: expired tib21171742624413/test/dir2
2025/03/22 06:20:43 DEBUG : test/dir2/dir4: cache: expired tib21171742624413/test
2025/03/22 06:20:43 DEBUG : test/dir2/dir4: cache: expired tib21171742624413
2025/03/22 06:20:43 INFO  : test/dir2/dir4/test.txt: Deleted
2025/03/22 06:20:43 DEBUG : Cache remote TestInternalCache:tib21171742624413: list ''
2025/03/22 06:20:43 DEBUG : : list: cold listing: 2025-03-19 06:20:43.736902903 +0000 UTC
2025/03/22 06:20:43 DEBUG : : list: read 1 from source
2025/03/22 06:20:43 DEBUG : : list: source entries: [test]
2025/03/22 06:20:43 DEBUG : : list: cached directories: 0
2025/03/22 06:20:43 DEBUG : : list: cached dir: 'tib21171742624413', cache ts: 2025-03-22 06:20:43.738487349 +0000 UTC m=+39.632378005
2025/03/22 06:20:43 DEBUG : Cache remote TestInternalCache:tib21171742624413: list 'test'
2025/03/22 06:20:43 DEBUG : test: list: cold listing: 2025-03-19 06:20:43.736902903 +0000 UTC
2025/03/22 06:20:43 DEBUG : test: list: read 4 from source
2025/03/22 06:20:43 DEBUG : test: list: source entries: [test/dir3 test/dir2 test/dir4 test/dir1]
2025/03/22 06:20:43 DEBUG : test: list: cached directories: 0
2025/03/22 06:20:43 DEBUG : test: list: cached dir: 'tib21171742624413/test', cache ts: 2025-03-22 06:20:43.744455588 +0000 UTC m=+39.638346214
2025/03/22 06:20:43 DEBUG : Cache remote TestInternalCache:tib21171742624413: list 'test/dir4'
2025/03/22 06:20:43 DEBUG : Cache remote TestInternalCache:tib21171742624413: list 'test/dir2'
2025/03/22 06:20:43 DEBUG : Cache remote TestInternalCache:tib21171742624413: list 'test/dir3'
2025/03/22 06:20:43 DEBUG : test/dir3: list: cold listing: 2025-03-19 06:20:43.729212048 +0000 UTC
2025/03/22 06:20:43 DEBUG : test/dir2: list: cold listing: 2025-03-19 06:20:43.736902903 +0000 UTC
2025/03/22 06:20:43 DEBUG : test/dir3: list: read 4 from source
2025/03/22 06:20:43 DEBUG : test/dir3: list: source entries: [test/dir3/dir3 test/dir3/dir2 test/dir3/dir4 test/dir3/dir1]
2025/03/22 06:20:43 DEBUG : test/dir3: list: cached directories: 0
2025/03/22 06:20:43 DEBUG : test/dir2: list: read 4 from source
2025/03/22 06:20:43 DEBUG : test/dir2: list: source entries: [test/dir2/dir3 test/dir2/dir2 test/dir2/dir4 test/dir2/dir1]
2025/03/22 06:20:43 DEBUG : test/dir2: list: cached directories: 0
2025/03/22 06:20:43 DEBUG : test/dir4: list: cold listing: 2025-03-19 06:20:43.718492114 +0000 UTC
2025/03/22 06:20:43 DEBUG : test/dir4: list: read 4 from source
2025/03/22 06:20:43 DEBUG : test/dir4: list: source entries: [test/dir4/dir3 test/dir4/dir2 test/dir4/dir4 test/dir4/dir1]
2025/03/22 06:20:43 DEBUG : test/dir4: list: cached directories: 0
2025/03/22 06:20:43 DEBUG : Cache remote TestInternalCache:tib21171742624413: list 'test/dir1'
2025/03/22 06:20:43 DEBUG : test/dir1: list: cold listing: 2025-03-19 06:20:43.712920831 +0000 UTC
2025/03/22 06:20:43 DEBUG : test/dir1: list: read 4 from source
2025/03/22 06:20:43 DEBUG : test/dir1: list: source entries: [test/dir1/dir3 test/dir1/dir2 test/dir1/dir4 test/dir1/dir1]
2025/03/22 06:20:43 DEBUG : test/dir1: list: cached directories: 0
2025/03/22 06:20:43 DEBUG : test/dir3: list: cached dir: 'tib21171742624413/test/dir3', cache ts: 2025-03-22 06:20:43.746446778 +0000 UTC m=+39.640337434
2025/03/22 06:20:43 DEBUG : Cache remote TestInternalCache:tib21171742624413: list 'test/dir3/dir4'
2025/03/22 06:20:43 DEBUG : test/dir3/dir4: list: cold listing: 2025-03-19 06:20:43.729212048 +0000 UTC
2025/03/22 06:20:43 DEBUG : Cache remote TestInternalCache:tib21171742624413: list 'test/dir3/dir2'
2025/03/22 06:20:43 DEBUG : Cache remote TestInternalCache:tib21171742624413: list 'test/dir3/dir1'
2025/03/22 06:20:43 DEBUG : test/dir3/dir2: list: cold listing: 2025-03-19 06:20:43.72446423 +0000 UTC
2025/03/22 06:20:43 DEBUG : test/dir3/dir1: list: cold listing: 2025-03-19 06:20:43.721685261 +0000 UTC
2025/03/22 06:20:43 DEBUG : test/dir3/dir1: list: read 0 from source
2025/03/22 06:20:43 DEBUG : test/dir3/dir2: list: read 0 from source
2025/03/22 06:20:43 DEBUG : test/dir3/dir1: list: source entries: []
2025/03/22 06:20:43 DEBUG : test/dir3/dir2: list: source entries: []
2025/03/22 06:20:43 DEBUG : test/dir3/dir1: list: cached directories: 0
2025/03/22 06:20:43 DEBUG : test/dir3/dir2: list: cached directories: 0
2025/03/22 06:20:43 DEBUG : Cache remote TestInternalCache:tib21171742624413: list 'test/dir3/dir3'
2025/03/22 06:20:43 DEBUG : test/dir3/dir3: list: cold listing: 2025-03-19 06:20:43.726554607 +0000 UTC
2025/03/22 06:20:43 DEBUG : test/dir3/dir3: list: read 0 from source
2025/03/22 06:20:43 DEBUG : test/dir3/dir3: list: source entries: []
2025/03/22 06:20:43 DEBUG : test/dir3/dir3: list: cached directories: 0
2025/03/22 06:20:43 DEBUG : test/dir3/dir4: list: read 0 from source
2025/03/22 06:20:43 DEBUG : test/dir3/dir4: list: source entries: []
2025/03/22 06:20:43 DEBUG : test/dir3/dir4: list: cached directories: 0
2025/03/22 06:20:43 DEBUG : test/dir2: list: cached dir: 'tib21171742624413/test/dir2', cache ts: 2025-03-22 06:20:43.746724069 +0000 UTC m=+39.640614725
2025/03/22 06:20:43 DEBUG : Cache remote TestInternalCache:tib21171742624413: list 'test/dir2/dir2'
2025/03/22 06:20:43 DEBUG : test/dir2/dir2: list: cold listing: 2025-03-19 06:20:43.731303055 +0000 UTC
2025/03/22 06:20:43 DEBUG : test/dir2/dir2: list: read 0 from source
2025/03/22 06:20:43 DEBUG : test/dir2/dir2: list: source entries: []
2025/03/22 06:20:43 DEBUG : Cache remote TestInternalCache:tib21171742624413: list 'test/dir2/dir1'
2025/03/22 06:20:43 DEBUG : test/dir2/dir2: list: cached directories: 0
2025/03/22 06:20:43 DEBUG : test/dir2/dir1: list: cold listing: 2025-03-19 06:20:43.733201972 +0000 UTC
2025/03/22 06:20:43 DEBUG : test/dir2/dir1: list: read 0 from source
2025/03/22 06:20:43 DEBUG : test/dir2/dir1: list: source entries: []
2025/03/22 06:20:43 DEBUG : test/dir2/dir1: list: cached directories: 0
2025/03/22 06:20:43 DEBUG : test/dir4: list: cached dir: 'tib21171742624413/test/dir4', cache ts: 2025-03-22 06:20:43.746938532 +0000 UTC m=+39.640829189
2025/03/22 06:20:43 DEBUG : Cache remote TestInternalCache:tib21171742624413: list 'test/dir2/dir3'
2025/03/22 06:20:43 DEBUG : test/dir2/dir3: list: cold listing: 2025-03-19 06:20:43.734946599 +0000 UTC
2025/03/22 06:20:43 DEBUG : test/dir2/dir3: list: read 0 from source
2025/03/22 06:20:43 DEBUG : test/dir2/dir3: list: source entries: []
2025/03/22 06:20:43 DEBUG : test/dir2/dir3: list: cached directories: 0
2025/03/22 06:20:43 DEBUG : test/dir1: list: cached dir: 'tib21171742624413/test/dir1', cache ts: 2025-03-22 06:20:43.747202547 +0000 UTC m=+39.641093204
2025/03/22 06:20:43 DEBUG : Cache remote TestInternalCache:tib21171742624413: list 'test/dir2/dir4'
2025/03/22 06:20:43 DEBUG : test/dir2/dir4: list: cold listing: 2025-03-19 06:20:43.736902903 +0000 UTC
2025/03/22 06:20:43 DEBUG : test/dir2/dir4: list: read 0 from source
2025/03/22 06:20:43 DEBUG : test/dir2/dir4: list: source entries: []
2025/03/22 06:20:43 DEBUG : test/dir2/dir4: list: cached directories: 0
2025/03/22 06:20:43 DEBUG : test/dir3/dir1: list: cached dir: 'tib21171742624413/test/dir3/dir1', cache ts: 2025-03-22 06:20:43.748197897 +0000 UTC m=+39.642088523
2025/03/22 06:20:43 DEBUG : Cache remote TestInternalCache:tib21171742624413: list 'test/dir4/dir1'
2025/03/22 06:20:43 DEBUG : test/dir4/dir1: list: cold listing: 2025-03-19 06:20:43.704225829 +0000 UTC
2025/03/22 06:20:43 DEBUG : test/dir4/dir1: list: read 0 from source
2025/03/22 06:20:43 DEBUG : test/dir4/dir1: list: source entries: []
2025/03/22 06:20:43 DEBUG : test/dir4/dir1: list: cached directories: 0
2025/03/22 06:20:43 DEBUG : test/dir3/dir2: list: cached dir: 'tib21171742624413/test/dir3/dir2', cache ts: 2025-03-22 06:20:43.748201755 +0000 UTC m=+39.642092410
2025/03/22 06:20:43 DEBUG : Cache remote TestInternalCache:tib21171742624413: list 'test/dir4/dir2'
2025/03/22 06:20:43 DEBUG : test/dir4/dir2: list: cold listing: 2025-03-19 06:20:43.715585145 +0000 UTC
2025/03/22 06:20:43 DEBUG : test/dir4/dir2: list: read 0 from source
2025/03/22 06:20:43 DEBUG : test/dir4/dir2: list: source entries: []
2025/03/22 06:20:43 DEBUG : test/dir4/dir2: list: cached directories: 0
2025/03/22 06:20:43 DEBUG : test/dir4/dir2: list: cached dir: 'tib21171742624413/test/dir4/dir2', cache ts: 2025-03-22 06:20:43.755174822 +0000 UTC m=+39.649065447
2025/03/22 06:20:43 DEBUG : Cache remote TestInternalCache:tib21171742624413: list 'test/dir4/dir3'
2025/03/22 06:20:43 DEBUG : test/dir4/dir3: list: cold listing: 2025-03-19 06:20:43.664778962 +0000 UTC
2025/03/22 06:20:43 DEBUG : test/dir4/dir3: list: read 0 from source
2025/03/22 06:20:43 DEBUG : test/dir4/dir3: list: source entries: []
2025/03/22 06:20:43 DEBUG : test/dir4/dir3: list: cached directories: 0
2025/03/22 06:20:43 DEBUG : test/dir3/dir3: list: cached dir: 'tib21171742624413/test/dir3/dir3', cache ts: 2025-03-22 06:20:43.748257489 +0000 UTC m=+39.642148115
2025/03/22 06:20:43 DEBUG : Cache remote TestInternalCache:tib21171742624413: list 'test/dir4/dir4'
2025/03/22 06:20:43 DEBUG : test/dir4/dir4: list: cold listing: 2025-03-19 06:20:43.718492114 +0000 UTC
2025/03/22 06:20:43 DEBUG : test/dir4/dir4: list: read 0 from source
2025/03/22 06:20:43 DEBUG : test/dir4/dir4: list: source entries: []
2025/03/22 06:20:43 DEBUG : test/dir4/dir4: list: cached directories: 0
2025/03/22 06:20:43 DEBUG : test/dir3/dir4: list: cached dir: 'tib21171742624413/test/dir3/dir4', cache ts: 2025-03-22 06:20:43.748349552 +0000 UTC m=+39.642240218
2025/03/22 06:20:43 DEBUG : Cache remote TestInternalCache:tib21171742624413: list 'test/dir1/dir1'
2025/03/22 06:20:43 DEBUG : test/dir1/dir1: list: cold listing: 2025-03-19 06:20:43.71035433 +0000 UTC
2025/03/22 06:20:43 DEBUG : test/dir1/dir1: list: read 0 from source
2025/03/22 06:20:43 DEBUG : test/dir1/dir1: list: source entries: []
2025/03/22 06:20:43 DEBUG : test/dir1/dir1: list: cached directories: 0
2025/03/22 06:20:43 DEBUG : test/dir2/dir2: list: cached dir: 'tib21171742624413/test/dir2/dir2', cache ts: 2025-03-22 06:20:43.749480075 +0000 UTC m=+39.643370731
2025/03/22 06:20:43 DEBUG : Cache remote TestInternalCache:tib21171742624413: list 'test/dir1/dir2'
2025/03/22 06:20:43 DEBUG : test/dir1/dir2: list: cold listing: 2025-03-19 06:20:43.690879934 +0000 UTC
2025/03/22 06:20:43 DEBUG : test/dir1/dir2: list: read 0 from source
2025/03/22 06:20:43 DEBUG : test/dir1/dir2: list: source entries: []
2025/03/22 06:20:43 DEBUG : test/dir1/dir2: list: cached directories: 0
2025/03/22 06:20:43 DEBUG : test/dir2/dir1: list: cached dir: 'tib21171742624413/test/dir2/dir1', cache ts: 2025-03-22 06:20:43.749536892 +0000 UTC m=+39.643427518
2025/03/22 06:20:43 DEBUG : Cache remote TestInternalCache:tib21171742624413: list 'test/dir1/dir3'
2025/03/22 06:20:43 DEBUG : test/dir1/dir3: list: cold listing: 2025-03-19 06:20:43.712920831 +0000 UTC
2025/03/22 06:20:43 DEBUG : test/dir1/dir3: list: read 0 from source
2025/03/22 06:20:43 DEBUG : test/dir1/dir3: list: source entries: []
2025/03/22 06:20:43 DEBUG : test/dir1/dir3: list: cached directories: 0
2025/03/22 06:20:43 DEBUG : test/dir2/dir3: list: cached dir: 'tib21171742624413/test/dir2/dir3', cache ts: 2025-03-22 06:20:43.750873873 +0000 UTC m=+39.644764539
2025/03/22 06:20:43 DEBUG : Cache remote TestInternalCache:tib21171742624413: list 'test/dir1/dir4'
2025/03/22 06:20:43 DEBUG : test/dir1/dir4: list: cold listing: 2025-03-19 06:20:43.70772436 +0000 UTC
2025/03/22 06:20:43 DEBUG : test/dir1/dir4: list: read 0 from source
2025/03/22 06:20:43 DEBUG : test/dir1/dir4: list: source entries: []
2025/03/22 06:20:43 DEBUG : test/dir1/dir4: list: cached directories: 0
2025/03/22 06:20:43 DEBUG : test/dir2/dir4: list: cached dir: 'tib21171742624413/test/dir2/dir4', cache ts: 2025-03-22 06:20:43.752450144 +0000 UTC m=+39.646340770
2025/03/22 06:20:43 DEBUG : test/dir4/dir1: list: cached dir: 'tib21171742624413/test/dir4/dir1', cache ts: 2025-03-22 06:20:43.753762498 +0000 UTC m=+39.647653134
2025/03/22 06:20:43 DEBUG : test/dir4/dir3: list: cached dir: 'tib21171742624413/test/dir4/dir3', cache ts: 2025-03-22 06:20:43.756426111 +0000 UTC m=+39.650316737
2025/03/22 06:20:43 DEBUG : test/dir4/dir4: list: cached dir: 'tib21171742624413/test/dir4/dir4', cache ts: 2025-03-22 06:20:43.757496772 +0000 UTC m=+39.651387398
2025/03/22 06:20:43 DEBUG : test/dir1/dir1: list: cached dir: 'tib21171742624413/test/dir1/dir1', cache ts: 2025-03-22 06:20:43.75867214 +0000 UTC m=+39.652562766
2025/03/22 06:20:43 DEBUG : test/dir1/dir2: list: cached dir: 'tib21171742624413/test/dir1/dir2', cache ts: 2025-03-22 06:20:43.75979027 +0000 UTC m=+39.653680896
2025/03/22 06:20:43 DEBUG : test/dir1/dir3: list: cached dir: 'tib21171742624413/test/dir1/dir3', cache ts: 2025-03-22 06:20:43.761173227 +0000 UTC m=+39.655063853
2025/03/22 06:20:43 DEBUG : test/dir1/dir4: list: cached dir: 'tib21171742624413/test/dir1/dir4', cache ts: 2025-03-22 06:20:43.7629264 +0000 UTC m=+39.656817026
2025/03/22 06:20:43 DEBUG : removing 16 level 3 directories
2025/03/22 06:20:43 INFO  : test/dir2/dir4: Removing directory
2025/03/22 06:20:43 DEBUG : Cache remote TestInternalCache:tib21171742624413: rmdir 'test/dir2/dir4'
2025/03/22 06:20:43 INFO  : test/dir1/dir2: Removing directory
2025/03/22 06:20:43 DEBUG : Cache remote TestInternalCache:tib21171742624413: rmdir 'test/dir1/dir2'
2025/03/22 06:20:43 INFO  : test/dir1/dir4: Removing directory
2025/03/22 06:20:43 DEBUG : Cache remote TestInternalCache:tib21171742624413: rmdir 'test/dir1/dir4'
2025/03/22 06:20:43 DEBUG : test/dir2/dir4: rmdir: removed dir in source fs
2025/03/22 06:20:43 DEBUG : test/dir1/dir2: rmdir: removed dir in source fs
2025/03/22 06:20:43 INFO  : test/dir1/dir1: Removing directory
2025/03/22 06:20:43 DEBUG : Cache remote TestInternalCache:tib21171742624413: rmdir 'test/dir1/dir1'
2025/03/22 06:20:43 DEBUG : test/dir1/dir4: rmdir: removed dir in source fs
2025/03/22 06:20:43 INFO  : test/dir1/dir3: Removing directory
2025/03/22 06:20:43 DEBUG : Cache remote TestInternalCache:tib21171742624413: rmdir 'test/dir1/dir3'
2025/03/22 06:20:43 DEBUG : test/dir1/dir1: rmdir: removed dir in source fs
2025/03/22 06:20:43 INFO  : test/dir2/dir2: Removing directory
2025/03/22 06:20:43 DEBUG : Cache remote TestInternalCache:tib21171742624413: rmdir 'test/dir2/dir2'
2025/03/22 06:20:43 DEBUG : test/dir1/dir3: rmdir: removed dir in source fs
2025/03/22 06:20:43 INFO  : test/dir2/dir3: Removing directory
2025/03/22 06:20:43 DEBUG : Cache remote TestInternalCache:tib21171742624413: rmdir 'test/dir2/dir3'
2025/03/22 06:20:43 DEBUG : test/dir2/dir2: rmdir: removed dir in source fs
2025/03/22 06:20:43 INFO  : test/dir2/dir1: Removing directory
2025/03/22 06:20:43 DEBUG : Cache remote TestInternalCache:tib21171742624413: rmdir 'test/dir2/dir1'
2025/03/22 06:20:43 DEBUG : test/dir2/dir3: rmdir: removed dir in source fs
2025/03/22 06:20:43 DEBUG : test/dir2/dir1: rmdir: removed dir in source fs
2025/03/22 06:20:43 DEBUG : test/dir2/dir4: rmdir: removed from cache
2025/03/22 06:20:43 DEBUG : test/dir1/dir2: rmdir: removed from cache
2025/03/22 06:20:43 DEBUG : test/dir1: cache: expired tib21171742624413/test/dir1
2025/03/22 06:20:43 DEBUG : test/dir1: cache: expired tib21171742624413/test
2025/03/22 06:20:43 DEBUG : test/dir1: cache: expired tib21171742624413
2025/03/22 06:20:43 INFO  : test/dir1: rmdir: cache expired
2025/03/22 06:20:43 INFO  : test/dir3/dir1: Removing directory
2025/03/22 06:20:43 DEBUG : Cache remote TestInternalCache:tib21171742624413: rmdir 'test/dir3/dir1'
2025/03/22 06:20:43 DEBUG : test/dir3/dir1: rmdir: removed dir in source fs
2025/03/22 06:20:43 DEBUG : test/dir1/dir4: rmdir: removed from cache
2025/03/22 06:20:43 DEBUG : test/dir1/dir1: rmdir: removed from cache
2025/03/22 06:20:43 DEBUG : test/dir1/dir3: rmdir: removed from cache
2025/03/22 06:20:43 DEBUG : test/dir2/dir2: rmdir: removed from cache
2025/03/22 06:20:43 DEBUG : test/dir2/dir3: rmdir: removed from cache
2025/03/22 06:20:43 DEBUG : test/dir2: cache: expired tib21171742624413/test/dir2
2025/03/22 06:20:43 DEBUG : test/dir2/dir1: rmdir: removed from cache
2025/03/22 06:20:43 DEBUG : test/dir2: cache: expired tib21171742624413/test
2025/03/22 06:20:43 DEBUG : test/dir2: cache: expired tib21171742624413
2025/03/22 06:20:43 INFO  : test/dir2: rmdir: cache expired
2025/03/22 06:20:43 INFO  : test/dir3/dir2: Removing directory
2025/03/22 06:20:43 DEBUG : Cache remote TestInternalCache:tib21171742624413: rmdir 'test/dir3/dir2'
2025/03/22 06:20:43 DEBUG : test/dir3/dir2: rmdir: removed dir in source fs
2025/03/22 06:20:43 DEBUG : test/dir3/dir1: rmdir: removed from cache
2025/03/22 06:20:43 DEBUG : test/dir1: cache: expired tib21171742624413/test/dir1
2025/03/22 06:20:43 DEBUG : test/dir1: cache: expired tib21171742624413/test
2025/03/22 06:20:43 DEBUG : test/dir1: cache: expired tib21171742624413
2025/03/22 06:20:43 DEBUG : test/dir1: cache: expired tib21171742624413/test/dir1
2025/03/22 06:20:43 DEBUG : test/dir1: cache: expired tib21171742624413/test
2025/03/22 06:20:43 DEBUG : test/dir1: cache: expired tib21171742624413
2025/03/22 06:20:43 INFO  : test/dir1: rmdir: cache expired
2025/03/22 06:20:43 INFO  : test/dir3/dir3: Removing directory
2025/03/22 06:20:43 DEBUG : Cache remote TestInternalCache:tib21171742624413: rmdir 'test/dir3/dir3'
2025/03/22 06:20:43 DEBUG : test/dir3/dir3: rmdir: removed dir in source fs
2025/03/22 06:20:43 DEBUG : test/dir1: cache: expired tib21171742624413/test/dir1
2025/03/22 06:20:43 INFO  : test/dir1: rmdir: cache expired
2025/03/22 06:20:43 DEBUG : test/dir1: cache: expired tib21171742624413/test
2025/03/22 06:20:43 DEBUG : test/dir1: cache: expired tib21171742624413
2025/03/22 06:20:43 INFO  : test/dir3/dir4: Removing directory
2025/03/22 06:20:43 DEBUG : Cache remote TestInternalCache:tib21171742624413: rmdir 'test/dir3/dir4'
2025/03/22 06:20:43 DEBUG : test/dir3/dir4: rmdir: removed dir in source fs
2025/03/22 06:20:43 DEBUG : test/dir2: cache: expired tib21171742624413/test/dir2
2025/03/22 06:20:43 INFO  : test/dir1: rmdir: cache expired
2025/03/22 06:20:43 INFO  : test/dir4/dir1: Removing directory
2025/03/22 06:20:43 DEBUG : test/dir2: cache: expired tib21171742624413/test
2025/03/22 06:20:43 DEBUG : Cache remote TestInternalCache:tib21171742624413: rmdir 'test/dir4/dir1'
2025/03/22 06:20:43 DEBUG : test/dir2: cache: expired tib21171742624413
2025/03/22 06:20:43 DEBUG : test/dir4/dir1: rmdir: removed dir in source fs
2025/03/22 06:20:43 DEBUG : test/dir2: cache: expired tib21171742624413/test/dir2
2025/03/22 06:20:43 DEBUG : test/dir2: cache: expired tib21171742624413/test
2025/03/22 06:20:43 INFO  : test/dir2: rmdir: cache expired
2025/03/22 06:20:43 INFO  : test/dir4/dir2: Removing directory
2025/03/22 06:20:43 DEBUG : Cache remote TestInternalCache:tib21171742624413: rmdir 'test/dir4/dir2'
2025/03/22 06:20:43 DEBUG : test/dir4/dir2: rmdir: removed dir in source fs
2025/03/22 06:20:43 DEBUG : test/dir2: cache: expired tib21171742624413
2025/03/22 06:20:43 DEBUG : test/dir2: cache: expired tib21171742624413/test/dir2
2025/03/22 06:20:43 INFO  : test/dir2: rmdir: cache expired
2025/03/22 06:20:43 DEBUG : test/dir2: cache: expired tib21171742624413/test
2025/03/22 06:20:43 DEBUG : test/dir2: cache: expired tib21171742624413
2025/03/22 06:20:43 INFO  : test/dir4/dir3: Removing directory
2025/03/22 06:20:43 DEBUG : Cache remote TestInternalCache:tib21171742624413: rmdir 'test/dir4/dir3'
2025/03/22 06:20:43 DEBUG : test/dir4/dir3: rmdir: removed dir in source fs
2025/03/22 06:20:43 INFO  : test/dir2: rmdir: cache expired
2025/03/22 06:20:43 INFO  : test/dir4/dir4: Removing directory
2025/03/22 06:20:43 DEBUG : Cache remote TestInternalCache:tib21171742624413: rmdir 'test/dir4/dir4'
2025/03/22 06:20:43 DEBUG : test/dir4/dir4: rmdir: removed dir in source fs
2025/03/22 06:20:43 DEBUG : test/dir3: cache: expired tib21171742624413/test/dir3
2025/03/22 06:20:43 DEBUG : test/dir3: cache: expired tib21171742624413/test
2025/03/22 06:20:43 DEBUG : test/dir3: cache: expired tib21171742624413
2025/03/22 06:20:43 DEBUG : test/dir3/dir2: rmdir: removed from cache
2025/03/22 06:20:43 INFO  : test/dir3: rmdir: cache expired
2025/03/22 06:20:43 DEBUG : test/dir3/dir3: rmdir: removed from cache
2025/03/22 06:20:43 DEBUG : test/dir3/dir4: rmdir: removed from cache
2025/03/22 06:20:43 DEBUG : test/dir4/dir1: rmdir: removed from cache
2025/03/22 06:20:43 DEBUG : test/dir4/dir2: rmdir: removed from cache
2025/03/22 06:20:43 DEBUG : test/dir4/dir3: rmdir: removed from cache
2025/03/22 06:20:43 DEBUG : test/dir4/dir4: rmdir: removed from cache
2025/03/22 06:20:43 DEBUG : test/dir3: cache: expired tib21171742624413/test/dir3
2025/03/22 06:20:43 DEBUG : test/dir3: cache: expired tib21171742624413/test
2025/03/22 06:20:43 DEBUG : test/dir3: cache: expired tib21171742624413
2025/03/22 06:20:43 INFO  : test/dir3: rmdir: cache expired
2025/03/22 06:20:43 DEBUG : test/dir3: cache: expired tib21171742624413/test/dir3
2025/03/22 06:20:43 DEBUG : test/dir3: cache: expired tib21171742624413/test
2025/03/22 06:20:43 DEBUG : test/dir3: cache: expired tib21171742624413
2025/03/22 06:20:43 DEBUG : test/dir3: cache: expired tib21171742624413/test/dir3
2025/03/22 06:20:43 INFO  : test/dir3: rmdir: cache expired
2025/03/22 06:20:43 DEBUG : test/dir3: cache: expired tib21171742624413/test
2025/03/22 06:20:43 DEBUG : test/dir3: cache: expired tib21171742624413
2025/03/22 06:20:43 DEBUG : test/dir4: cache: expired tib21171742624413/test/dir4
2025/03/22 06:20:43 DEBUG : test/dir4: cache: expired tib21171742624413/test
2025/03/22 06:20:43 INFO  : test/dir3: rmdir: cache expired
2025/03/22 06:20:43 DEBUG : test/dir4: cache: expired tib21171742624413
2025/03/22 06:20:43 DEBUG : test/dir4: cache: expired tib21171742624413/test/dir4
2025/03/22 06:20:43 INFO  : test/dir4: rmdir: cache expired
2025/03/22 06:20:43 DEBUG : test/dir4: cache: expired tib21171742624413/test
2025/03/22 06:20:43 DEBUG : test/dir4: cache: expired tib21171742624413
2025/03/22 06:20:43 DEBUG : test/dir4: cache: expired tib21171742624413/test/dir4
2025/03/22 06:20:43 INFO  : test/dir4: rmdir: cache expired
2025/03/22 06:20:43 DEBUG : test/dir4: cache: expired tib21171742624413/test
2025/03/22 06:20:43 DEBUG : test/dir4: cache: expired tib21171742624413
2025/03/22 06:20:43 DEBUG : test/dir4: cache: expired tib21171742624413/test/dir4
2025/03/22 06:20:43 DEBUG : test/dir4: cache: expired tib21171742624413/test
2025/03/22 06:20:43 DEBUG : test/dir4: cache: expired tib21171742624413
2025/03/22 06:20:43 INFO  : test/dir4: rmdir: cache expired
2025/03/22 06:20:43 INFO  : test/dir4: rmdir: cache expired
2025/03/22 06:20:43 DEBUG : removing 4 level 2 directories
2025/03/22 06:20:43 INFO  : test/dir4: Removing directory
2025/03/22 06:20:43 DEBUG : Cache remote TestInternalCache:tib21171742624413: rmdir 'test/dir4'
2025/03/22 06:20:43 INFO  : test/dir2: Removing directory
2025/03/22 06:20:43 INFO  : test/dir3: Removing directory
2025/03/22 06:20:43 DEBUG : Cache remote TestInternalCache:tib21171742624413: rmdir 'test/dir3'
2025/03/22 06:20:43 INFO  : test/dir1: Removing directory
2025/03/22 06:20:43 DEBUG : Cache remote TestInternalCache:tib21171742624413: rmdir 'test/dir1'
2025/03/22 06:20:43 DEBUG : test/dir3: rmdir: removed dir in source fs
2025/03/22 06:20:43 DEBUG : test/dir1: rmdir: removed dir in source fs
2025/03/22 06:20:43 DEBUG : Cache remote TestInternalCache:tib21171742624413: rmdir 'test/dir2'
2025/03/22 06:20:43 DEBUG : test/dir2: rmdir: removed dir in source fs
2025/03/22 06:20:43 DEBUG : test/dir4: rmdir: removed dir in source fs
2025/03/22 06:20:43 DEBUG : test/dir3: rmdir: removed from cache
2025/03/22 06:20:43 DEBUG : test: cache: expired tib21171742624413/test
2025/03/22 06:20:43 DEBUG : test: cache: expired tib21171742624413
2025/03/22 06:20:43 INFO  : test: rmdir: cache expired
2025/03/22 06:20:43 DEBUG : test/dir1: rmdir: removed from cache
2025/03/22 06:20:43 DEBUG : test/dir2: rmdir: removed from cache
2025/03/22 06:20:43 DEBUG : test: cache: expired tib21171742624413/test
2025/03/22 06:20:43 DEBUG : test/dir4: rmdir: removed from cache
2025/03/22 06:20:43 DEBUG : test: cache: expired tib21171742624413
2025/03/22 06:20:43 DEBUG : test: cache: expired tib21171742624413/test
2025/03/22 06:20:43 INFO  : test: rmdir: cache expired
2025/03/22 06:20:43 DEBUG : test: cache: expired tib21171742624413
2025/03/22 06:20:43 DEBUG : test: cache: expired tib21171742624413/test
2025/03/22 06:20:43 INFO  : test: rmdir: cache expired
2025/03/22 06:20:43 DEBUG : test: cache: expired tib21171742624413
2025/03/22 06:20:43 INFO  : test: rmdir: cache expired
2025/03/22 06:20:43 DEBUG : removing 1 level 1 directories
2025/03/22 06:20:43 INFO  : test: Removing directory
2025/03/22 06:20:43 DEBUG : Cache remote TestInternalCache:tib21171742624413: rmdir 'test'
2025/03/22 06:20:43 DEBUG : test: rmdir: removed dir in source fs
2025/03/22 06:20:43 DEBUG : test: rmdir: removed from cache
2025/03/22 06:20:43 DEBUG : : cache: expired tib21171742624413
2025/03/22 06:20:43 INFO  : : rmdir: cache expired
2025/03/22 06:20:43 DEBUG : removing 1 level 0 directories
2025/03/22 06:20:43 INFO  : Cache remote TestInternalCache:tib21171742624413: Removing directory
2025/03/22 06:20:43 DEBUG : Cache remote TestInternalCache:tib21171742624413: rmdir ''
2025/03/22 06:20:43 DEBUG : : rmdir: removed dir in source fs
2025/03/22 06:20:43 DEBUG : : rmdir: removed from cache
2025/03/22 06:20:43 INFO  : : rmdir: cache expired
2025/03/22 06:20:43 DEBUG : Cache remote TestInternalCache:tib21171742624413: Services stopped
--- PASS: TestInternalBug2117 (30.25s)
=== RUN   TestIntegration
    fstests.go:438: Using remote "TestCache:"
2025/03/22 06:20:43 DEBUG : Creating backend with remote "TestCache:rclone-test-xorifon6hupu"
2025/03/22 06:20:43 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2025/03/22 06:20:43 DEBUG : Setting cache db_wait_time="30m" from environment variable RCLONE_CACHE_DB_WAIT_TIME
2025/03/22 06:20:43 DEBUG : TestCache: detected overridden config - adding "{VDL3R}" suffix to name
2025/03/22 06:20:43 DEBUG : Setting cache db_wait_time="30m" from environment variable RCLONE_CACHE_DB_WAIT_TIME
2025/03/22 06:20:43 DEBUG : Creating backend with remote "/tmp/rclone_cache_test/rclone-test-xorifon6hupu"
2025/03/22 06:20:43 DEBUG : TestCache{VDL3R}: wrapped local:/tmp/rclone_cache_test/rclone-test-xorifon6hupu at root rclone-test-xorifon6hupu
2025/03/22 06:20:43 INFO  : TestCache{VDL3R}: Cache DB path: /home/rclone/.cache/rclone/cache-backend/TestCache{VDL3R}.db
2025/03/22 06:20:43 INFO  : TestCache{VDL3R}: Cache chunk path: /home/rclone/.cache/rclone/cache-backend/TestCache{VDL3R}
2025/03/22 06:21:04 INFO  : Cache remote TestInternalCache:tionf1742624404: stopping cleanup
2025/03/22 06:21:04 INFO  : Cache remote TestInternalCache:ticwcm1742624404: stopping cleanup
2025/03/22 06:21:05 INFO  : Cache remote TestInternalCache:tidwcm1742624405: stopping cleanup
2025/03/22 06:21:05 INFO  : Cache remote TestInternalCache:ticucm1742624405: stopping cleanup
2025/03/22 06:21:06 INFO  : Cache remote TestInternalCache:tiwfcns1742624406: stopping cleanup
2025/03/22 06:21:06 INFO  : Cache remote TestInternalCache:timwn1742624406: stopping cleanup
2025/03/22 06:21:07 INFO  : Cache remote TestInternalCache:tincep1742624407: stopping cleanup
2025/03/22 06:21:07 INFO  : Cache remote TestInternalCache:ticsadcf1742624407: stopping cleanup
2025/03/22 06:21:07 INFO  : Cache remote TestInternalCache:ticw: stopping cleanup
2025/03/22 06:21:08 INFO  : Cache remote TestInternalCache:timcsr1742624408: stopping cleanup
2025/03/22 06:35:13 INFO  : Cache remote TestInternalCache:tib21171742624413: stopping cleanup
2025/03/22 06:50:43 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.99s)
=== RUN   TestInternalUploadTempDirCreated
2025/03/22 06:50:43 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2025/03/22 06:50:43 DEBUG : Creating backend with remote "TestInternalCache-local:/tmp/TestInternalCache-local/tiutdc1742626243"
2025/03/22 06:50:43 DEBUG : TestInternalCache: wrapped TestInternalCache-local:/tmp/TestInternalCache-local/tiutdc1742626243 at root tiutdc1742626243
2025/03/22 06:50:43 INFO  : TestInternalCache: Cache DB path: /home/rclone/.cache/rclone/cache-backend/TestInternalCache.db
2025/03/22 06:50:43 INFO  : TestInternalCache: Cache chunk path: /home/rclone/.cache/rclone/cache-backend/TestInternalCache
2025/03/22 06:50:43 INFO  : TestInternalCache: Chunk Memory: true
2025/03/22 06:50:43 INFO  : TestInternalCache: Chunk Size: 5Mi
2025/03/22 06:50:43 INFO  : TestInternalCache: Chunk Total Size: 10Gi
2025/03/22 06:50:43 INFO  : TestInternalCache: Chunk Clean Interval: 1m0s
2025/03/22 06:50:43 INFO  : TestInternalCache: Workers: 4
2025/03/22 06:50:43 INFO  : TestInternalCache: File Age: 6h0m0s
2025/03/22 06:50:43 DEBUG : Creating backend with remote "/tmp/rclonecache-tmp3226816588/tiutdc1742626243"
2025/03/22 06:50:43 INFO  : TestInternalCache: Upload Temp Rest Time: 15s
2025/03/22 06:50:43 INFO  : TestInternalCache: Upload Temp FS: /tmp/rclonecache-tmp3226816588/tiutdc1742626243
2025/03/22 06:50:43 DEBUG : Waiting for deletions to finish
2025/03/22 06:50:43 DEBUG : Cache remote TestInternalCache:tiutdc1742626243: list ''
2025/03/22 06:50:43 DEBUG : : list: error: couldn't open bucket (tiutdc1742626243)
2025/03/22 06:50:43 DEBUG : : list: read 0 from temp fs
2025/03/22 06:50:43 DEBUG : : list: temp fs entries: []
2025/03/22 06:50:43 ERROR : : error listing: directory not found
2025/03/22 06:50:43 DEBUG : Cache remote TestInternalCache:tiutdc1742626243: list ''
2025/03/22 06:50:43 DEBUG : : list: error: couldn't open bucket (tiutdc1742626243)
2025/03/22 06:50:43 DEBUG : : list: read 0 from temp fs
2025/03/22 06:50:43 DEBUG : : list: temp fs entries: []
2025/03/22 06:50:43 ERROR : Cache remote TestInternalCache:tiutdc1742626243: Failed to list "": directory not found
2025/03/22 06:50:43 DEBUG : removing 1 level 0 directories
2025/03/22 06:50:43 INFO  : Cache remote TestInternalCache:tiutdc1742626243: Removing directory
2025/03/22 06:50:43 DEBUG : Cache remote TestInternalCache:tiutdc1742626243: rmdir ''
2025/03/22 06:50:44 DEBUG : : rmdir: read 0 from temp fs
2025/03/22 06:50:44 DEBUG : : rmdir: temp fs entries: []
2025/03/22 06:50:44 DEBUG : tiutdc1742626243: couldn't delete from cache: bucket not found
2025/03/22 06:50:44 DEBUG : : rmdir: removed from cache
2025/03/22 06:50:44 INFO  : : rmdir: cache expired
2025/03/22 06:50:45 DEBUG : Cache remote TestInternalCache:tiutdc1742626243: mkdir ''
2025/03/22 06:50:45 DEBUG : : mkdir: created dir in source fs
2025/03/22 06:50:45 DEBUG : : mkdir: added to cache
2025/03/22 06:50:45 DEBUG : : cache: expired tiutdc1742626243
2025/03/22 06:50:45 INFO  : : mkdir: cache expired
2025/03/22 06:50:45 DEBUG : Waiting for deletions to finish
2025/03/22 06:50:45 DEBUG : Cache remote TestInternalCache:tiutdc1742626243: list ''
2025/03/22 06:50:45 DEBUG : : list: cold listing: 2025-03-22 00:50:45.355567245 +0000 UTC
2025/03/22 06:50:45 DEBUG : : list: read 0 from temp fs
2025/03/22 06:50:45 DEBUG : : list: temp fs entries: []
2025/03/22 06:50:45 DEBUG : : list: read 0 from source
2025/03/22 06:50:45 DEBUG : : list: source entries: []
2025/03/22 06:50:45 DEBUG : : list: cached directories: 0
2025/03/22 06:50:45 DEBUG : : list: cached dir: 'tiutdc1742626243', cache ts: 2025-03-22 06:50:45.357370512 +0000 UTC m=+1841.251261168
2025/03/22 06:50:45 DEBUG : Cache remote TestInternalCache:tiutdc1742626243: list ''
2025/03/22 06:50:45 DEBUG : : list: empty listing
2025/03/22 06:50:45 DEBUG : : list: read 0 from temp fs
2025/03/22 06:50:45 DEBUG : : list: temp fs entries: []
2025/03/22 06:50:45 DEBUG : : list: read 0 from source
2025/03/22 06:50:45 DEBUG : : list: source entries: []
2025/03/22 06:50:45 DEBUG : : list: cached directories: 0
2025/03/22 06:50:45 DEBUG : : list: cached dir: 'tiutdc1742626243', cache ts: 2025-03-22 06:50:45.35892887 +0000 UTC m=+1841.252819525
2025/03/22 06:50:45 DEBUG : removing 1 level 0 directories
2025/03/22 06:50:45 INFO  : Cache remote TestInternalCache:tiutdc1742626243: Removing directory
2025/03/22 06:50:45 DEBUG : Cache remote TestInternalCache:tiutdc1742626243: rmdir ''
2025/03/22 06:50:46 DEBUG : : rmdir: removed dir in source fs
2025/03/22 06:50:46 DEBUG : : rmdir: read 0 from temp fs
2025/03/22 06:50:46 DEBUG : : rmdir: temp fs entries: []
2025/03/22 06:50:46 DEBUG : : rmdir: removed from cache
2025/03/22 06:50:46 INFO  : : rmdir: cache expired
2025/03/22 06:50:47 DEBUG : Cache remote TestInternalCache:tiutdc1742626243: Services stopped
--- PASS: TestInternalUploadTempDirCreated (4.02s)
=== RUN   TestInternalUploadQueueOneFileNoRest
2025/03/22 06:50:47 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/03/22 06:50:47 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/03/22 06:50:47 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/03/22 06:50:47 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/03/22 06:50:47 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/03/22 06:50:47 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/03/22 06:50:47 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.785s
"go test -v -timeout 1h0m0s -remote TestCache: -verbose" - Finished ERROR in 30m45.778099787s (try 1/5): exit status 1: Failed [TestIntegration]