"go test -v -timeout 1h0m0s -remote TestCache: -verbose" - Starting (try 1/5)
2025/04/15 01:36:15 NOTICE: Running with the following params: 
 remote: TestInternalCache
2025/04/15 01:36:15 NOTICE: Temp Upload Dir: /tmp/rclonecache-tmp4140236242
=== RUN   TestInternalListRootAndInnerRemotes
2025/04/15 01:36:15 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/04/15 01:36:15 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/04/15 01:36:15 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2025/04/15 01:36:15 NOTICE: WARNING: Cache backend is deprecated and may be removed in future. Please use VFS instead.
2025/04/15 01:36:15 DEBUG : Creating backend with remote "TestInternalCache-local:/tmp/TestInternalCache-local/tionf1744680975"
2025/04/15 01:36:15 DEBUG : TestInternalCache: wrapped TestInternalCache-local:/tmp/TestInternalCache-local/tionf1744680975 at root tionf1744680975
2025/04/15 01:36:15 INFO  : TestInternalCache: Cache DB path: /home/rclone/.cache/rclone/cache-backend/TestInternalCache.db
2025/04/15 01:36:15 INFO  : TestInternalCache: Cache chunk path: /home/rclone/.cache/rclone/cache-backend/TestInternalCache
2025/04/15 01:36:15 INFO  : TestInternalCache: Chunk Memory: true
2025/04/15 01:36:15 INFO  : TestInternalCache: Chunk Size: 5Mi
2025/04/15 01:36:15 INFO  : TestInternalCache: Chunk Total Size: 10Gi
2025/04/15 01:36:15 INFO  : TestInternalCache: Chunk Clean Interval: 1m0s
2025/04/15 01:36:15 INFO  : TestInternalCache: Workers: 4
2025/04/15 01:36:15 INFO  : TestInternalCache: File Age: 6h0m0s
2025/04/15 01:36:15 DEBUG : Waiting for deletions to finish
2025/04/15 01:36:15 DEBUG : Cache remote TestInternalCache:tionf1744680975: list ''
2025/04/15 01:36:15 DEBUG : : list: error: couldn't open bucket (tionf1744680975)
2025/04/15 01:36:15 ERROR : : error listing: directory not found
2025/04/15 01:36:15 DEBUG : Cache remote TestInternalCache:tionf1744680975: list ''
2025/04/15 01:36:15 DEBUG : : list: error: couldn't open bucket (tionf1744680975)
2025/04/15 01:36:15 ERROR : Cache remote TestInternalCache:tionf1744680975: Failed to list "": directory not found
2025/04/15 01:36:15 DEBUG : removing 1 level 0 directories
2025/04/15 01:36:15 INFO  : Cache remote TestInternalCache:tionf1744680975: Removing directory
2025/04/15 01:36:15 DEBUG : Cache remote TestInternalCache:tionf1744680975: rmdir ''
2025/04/15 01:36:15 ERROR : : Failed to rmdir: stat /tmp/TestInternalCache-local/tionf1744680975: no such file or directory
2025/04/15 01:36:15 DEBUG : Cache remote TestInternalCache:tionf1744680975: mkdir ''
2025/04/15 01:36:15 DEBUG : : mkdir: created dir in source fs
2025/04/15 01:36:15 DEBUG : : mkdir: added to cache
2025/04/15 01:36:15 DEBUG : : cache: expired tionf1744680975
2025/04/15 01:36:15 INFO  : : mkdir: cache expired
2025/04/15 01:36:15 DEBUG : Cache remote TestInternalCache:tionf1744680975: new object '404'
2025/04/15 01:36:15 DEBUG : 404: find: error: couldn't find object (404)
2025/04/15 01:36:15 DEBUG : find failed: not found in either local or remote fs
2025/04/15 01:36:15 DEBUG : Waiting for deletions to finish
2025/04/15 01:36:15 DEBUG : Cache remote TestInternalCache:tionf1744680975: list ''
2025/04/15 01:36:15 DEBUG : : list: cold listing: 2025-04-14 19:36:15.568392226 +0000 UTC
2025/04/15 01:36:15 DEBUG : : list: read 0 from source
2025/04/15 01:36:15 DEBUG : : list: source entries: []
2025/04/15 01:36:15 DEBUG : : list: cached directories: 0
2025/04/15 01:36:15 DEBUG : : list: cached dir: 'tionf1744680975', cache ts: 2025-04-15 01:36:15.570300509 +0000 UTC m=+0.040717434
2025/04/15 01:36:15 DEBUG : Cache remote TestInternalCache:tionf1744680975: list ''
2025/04/15 01:36:15 DEBUG : : list: empty listing
2025/04/15 01:36:15 DEBUG : : list: read 0 from source
2025/04/15 01:36:15 DEBUG : : list: source entries: []
2025/04/15 01:36:15 DEBUG : : list: cached directories: 0
2025/04/15 01:36:15 DEBUG : : list: cached dir: 'tionf1744680975', cache ts: 2025-04-15 01:36:15.571656565 +0000 UTC m=+0.042073480
2025/04/15 01:36:15 DEBUG : removing 1 level 0 directories
2025/04/15 01:36:15 INFO  : Cache remote TestInternalCache:tionf1744680975: Removing directory
2025/04/15 01:36:15 DEBUG : Cache remote TestInternalCache:tionf1744680975: rmdir ''
2025/04/15 01:36:15 DEBUG : : rmdir: removed dir in source fs
2025/04/15 01:36:15 DEBUG : : rmdir: removed from cache
2025/04/15 01:36:15 INFO  : : rmdir: cache expired
2025/04/15 01:36:15 DEBUG : Cache remote TestInternalCache:tionf1744680975: Services stopped
--- PASS: TestInternalObjNotFound (0.03s)
=== RUN   TestInternalCachedWrittenContentMatches
2025/04/15 01:36:15 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2025/04/15 01:36:15 DEBUG : Creating backend with remote "TestInternalCache-local:/tmp/TestInternalCache-local/ticwcm1744680975"
2025/04/15 01:36:15 DEBUG : TestInternalCache: wrapped TestInternalCache-local:/tmp/TestInternalCache-local/ticwcm1744680975 at root ticwcm1744680975
2025/04/15 01:36:15 INFO  : TestInternalCache: Cache DB path: /home/rclone/.cache/rclone/cache-backend/TestInternalCache.db
2025/04/15 01:36:15 INFO  : TestInternalCache: Cache chunk path: /home/rclone/.cache/rclone/cache-backend/TestInternalCache
2025/04/15 01:36:15 INFO  : TestInternalCache: Chunk Memory: true
2025/04/15 01:36:15 INFO  : TestInternalCache: Chunk Size: 5Mi
2025/04/15 01:36:15 INFO  : TestInternalCache: Chunk Total Size: 10Gi
2025/04/15 01:36:15 INFO  : TestInternalCache: Chunk Clean Interval: 1m0s
2025/04/15 01:36:15 INFO  : TestInternalCache: Workers: 4
2025/04/15 01:36:15 INFO  : TestInternalCache: File Age: 6h0m0s
2025/04/15 01:36:15 DEBUG : Waiting for deletions to finish
2025/04/15 01:36:15 DEBUG : Cache remote TestInternalCache:ticwcm1744680975: list ''
2025/04/15 01:36:15 DEBUG : : list: error: couldn't open bucket (ticwcm1744680975)
2025/04/15 01:36:15 ERROR : : error listing: directory not found
2025/04/15 01:36:15 DEBUG : Cache remote TestInternalCache:ticwcm1744680975: list ''
2025/04/15 01:36:15 DEBUG : : list: error: couldn't open bucket (ticwcm1744680975)
2025/04/15 01:36:15 ERROR : Cache remote TestInternalCache:ticwcm1744680975: Failed to list "": directory not found
2025/04/15 01:36:15 DEBUG : removing 1 level 0 directories
2025/04/15 01:36:15 INFO  : Cache remote TestInternalCache:ticwcm1744680975: Removing directory
2025/04/15 01:36:15 DEBUG : Cache remote TestInternalCache:ticwcm1744680975: rmdir ''
2025/04/15 01:36:15 ERROR : : Failed to rmdir: stat /tmp/TestInternalCache-local/ticwcm1744680975: no such file or directory
2025/04/15 01:36:15 DEBUG : Cache remote TestInternalCache:ticwcm1744680975: mkdir ''
2025/04/15 01:36:15 DEBUG : : mkdir: created dir in source fs
2025/04/15 01:36:15 DEBUG : : mkdir: added to cache
2025/04/15 01:36:15 DEBUG : : cache: expired ticwcm1744680975
2025/04/15 01:36:15 INFO  : : mkdir: cache expired
2025/04/15 01:36:16 DEBUG : Cache remote TestInternalCache:ticwcm1744680975: put data at 'data.bin'
2025/04/15 01:36:16 DEBUG : data.bin: put: uploaded to remote fs
2025/04/15 01:36:16 DEBUG : data.bin: put: added to cache
2025/04/15 01:36:16 DEBUG : : cache: expired ticwcm1744680975
2025/04/15 01:36:16 INFO  : : put: cache expired
2025/04/15 01:36:16 DEBUG : Cache remote TestInternalCache:ticwcm1744680975: new object 'data.bin'
2025/04/15 01:36:16 DEBUG : data.bin: find: warm object: data.bin, expiring on: 2025-04-15 07:36:16.089546776 +0000 UTC
2025/04/15 01:36:16 DEBUG : Cache remote TestInternalCache:ticwcm1744680975: new object 'data.bin'
2025/04/15 01:36:16 DEBUG : data.bin: find: warm object: data.bin, expiring on: 2025-04-15 07:36:16.089546776 +0000 UTC
2025/04/15 01:36:16 DEBUG : ticwcm1744680975/data.bin: moving offset set from 0 to 2621440
2025/04/15 01:36:16 DEBUG : ticwcm1744680975/data.bin: 0: chunk retry storage: 0
2025/04/15 01:36:16 DEBUG : worker-3 <data.bin>: downloaded chunk 15728640
2025/04/15 01:36:16 DEBUG : worker-0 <data.bin>: downloaded chunk 0
2025/04/15 01:36:16 DEBUG : worker-2 <data.bin>: downloaded chunk 5242880
2025/04/15 01:36:16 DEBUG : worker-1 <data.bin>: downloaded chunk 10485760
2025/04/15 01:36:16 DEBUG : ticwcm1744680975/data.bin: cache reader closed 5242880
2025/04/15 01:36:16 DEBUG : Waiting for deletions to finish
2025/04/15 01:36:16 DEBUG : Cache remote TestInternalCache:ticwcm1744680975: list ''
2025/04/15 01:36:16 DEBUG : : list: cold listing: 2025-04-14 19:36:16.092002807 +0000 UTC
2025/04/15 01:36:16 DEBUG : : list: read 1 from source
2025/04/15 01:36:16 DEBUG : : list: source entries: [data.bin]
2025/04/15 01:36:16 DEBUG : : list: cached object: data.bin
2025/04/15 01:36:16 DEBUG : : list: cached directories: 0
2025/04/15 01:36:16 DEBUG : : list: cached dir: 'ticwcm1744680975', cache ts: 2025-04-15 01:36:16.610260516 +0000 UTC m=+1.080677481
2025/04/15 01:36:16 DEBUG : data.bin: removing object
2025/04/15 01:36:16 DEBUG : : cache: expired ticwcm1744680975
2025/04/15 01:36:16 INFO  : data.bin: Deleted
2025/04/15 01:36:16 DEBUG : Cache remote TestInternalCache:ticwcm1744680975: list ''
2025/04/15 01:36:16 DEBUG : : list: cold listing: 2025-04-14 19:36:16.62171331 +0000 UTC
2025/04/15 01:36:16 DEBUG : : list: read 0 from source
2025/04/15 01:36:16 DEBUG : : list: source entries: []
2025/04/15 01:36:16 DEBUG : : list: cached directories: 0
2025/04/15 01:36:16 DEBUG : : list: cached dir: 'ticwcm1744680975', cache ts: 2025-04-15 01:36:16.623080918 +0000 UTC m=+1.093497873
2025/04/15 01:36:16 DEBUG : removing 1 level 0 directories
2025/04/15 01:36:16 INFO  : Cache remote TestInternalCache:ticwcm1744680975: Removing directory
2025/04/15 01:36:16 DEBUG : Cache remote TestInternalCache:ticwcm1744680975: rmdir ''
2025/04/15 01:36:16 DEBUG : : rmdir: removed dir in source fs
2025/04/15 01:36:16 DEBUG : : rmdir: removed from cache
2025/04/15 01:36:16 INFO  : : rmdir: cache expired
2025/04/15 01:36:16 DEBUG : Cache remote TestInternalCache:ticwcm1744680975: Services stopped
--- PASS: TestInternalCachedWrittenContentMatches (1.06s)
=== RUN   TestInternalDoubleWrittenContentMatches
2025/04/15 01:36:16 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2025/04/15 01:36:16 DEBUG : Creating backend with remote "TestInternalCache-local:/tmp/TestInternalCache-local/tidwcm1744680976"
2025/04/15 01:36:16 DEBUG : TestInternalCache: wrapped TestInternalCache-local:/tmp/TestInternalCache-local/tidwcm1744680976 at root tidwcm1744680976
2025/04/15 01:36:16 INFO  : TestInternalCache: Cache DB path: /home/rclone/.cache/rclone/cache-backend/TestInternalCache.db
2025/04/15 01:36:16 INFO  : TestInternalCache: Cache chunk path: /home/rclone/.cache/rclone/cache-backend/TestInternalCache
2025/04/15 01:36:16 INFO  : TestInternalCache: Chunk Memory: true
2025/04/15 01:36:16 INFO  : TestInternalCache: Chunk Size: 5Mi
2025/04/15 01:36:16 INFO  : TestInternalCache: Chunk Total Size: 10Gi
2025/04/15 01:36:16 INFO  : TestInternalCache: Chunk Clean Interval: 1m0s
2025/04/15 01:36:16 INFO  : TestInternalCache: Workers: 4
2025/04/15 01:36:16 INFO  : TestInternalCache: File Age: 6h0m0s
2025/04/15 01:36:16 DEBUG : Waiting for deletions to finish
2025/04/15 01:36:16 DEBUG : Cache remote TestInternalCache:tidwcm1744680976: list ''
2025/04/15 01:36:16 DEBUG : : list: error: couldn't open bucket (tidwcm1744680976)
2025/04/15 01:36:16 ERROR : : error listing: directory not found
2025/04/15 01:36:16 DEBUG : Cache remote TestInternalCache:tidwcm1744680976: list ''
2025/04/15 01:36:16 DEBUG : : list: error: couldn't open bucket (tidwcm1744680976)
2025/04/15 01:36:16 ERROR : Cache remote TestInternalCache:tidwcm1744680976: Failed to list "": directory not found
2025/04/15 01:36:16 DEBUG : removing 1 level 0 directories
2025/04/15 01:36:16 INFO  : Cache remote TestInternalCache:tidwcm1744680976: Removing directory
2025/04/15 01:36:16 DEBUG : Cache remote TestInternalCache:tidwcm1744680976: rmdir ''
2025/04/15 01:36:16 ERROR : : Failed to rmdir: stat /tmp/TestInternalCache-local/tidwcm1744680976: no such file or directory
2025/04/15 01:36:16 DEBUG : Cache remote TestInternalCache:tidwcm1744680976: mkdir ''
2025/04/15 01:36:16 DEBUG : : mkdir: created dir in source fs
2025/04/15 01:36:16 DEBUG : : mkdir: added to cache
2025/04/15 01:36:16 DEBUG : : cache: expired tidwcm1744680976
2025/04/15 01:36:16 INFO  : : mkdir: cache expired
2025/04/15 01:36:16 DEBUG : Cache remote TestInternalCache:tidwcm1744680976: put data at 'one'
2025/04/15 01:36:16 DEBUG : one: put: uploaded to remote fs
2025/04/15 01:36:16 DEBUG : one: put: added to cache
2025/04/15 01:36:16 DEBUG : : cache: expired tidwcm1744680976
2025/04/15 01:36:16 INFO  : : put: cache expired
2025/04/15 01:36:16 DEBUG : Cache remote TestInternalCache:tidwcm1744680976: new object 'one'
2025/04/15 01:36:16 DEBUG : one: find: warm object: one, expiring on: 2025-04-15 07:36:16.65238439 +0000 UTC
2025/04/15 01:36:16 DEBUG : Cache remote TestInternalCache:tidwcm1744680976: new object 'one'
2025/04/15 01:36:16 DEBUG : one: find: warm object: one, expiring on: 2025-04-15 07:36:16.65238439 +0000 UTC
2025/04/15 01:36:16 DEBUG : one: updating object contents with size 19
2025/04/15 01:36:16 DEBUG : Cache remote TestInternalCache:tidwcm1744680976: new object 'one'
2025/04/15 01:36:16 DEBUG : one: find: warm object: one, expiring on: 2025-04-15 07:36:16.657716861 +0000 UTC
2025/04/15 01:36:16 DEBUG : one: updating object contents with size 26
2025/04/15 01:36:16 DEBUG : Cache remote TestInternalCache:tidwcm1744680976: new object 'one'
2025/04/15 01:36:16 DEBUG : one: find: warm object: one, expiring on: 2025-04-15 07:36:16.661373448 +0000 UTC
2025/04/15 01:36:16 DEBUG : tidwcm1744680976/one: moving offset set from 0 to 0
2025/04/15 01:36:16 DEBUG : tidwcm1744680976/one: 0: chunk retry storage: 0
2025/04/15 01:36:16 DEBUG : worker-0 <one>: partial downloaded chunk 0
2025/04/15 01:36:17 DEBUG : tidwcm1744680976/one: cache reader closed 26
2025/04/15 01:36:17 DEBUG : Waiting for deletions to finish
2025/04/15 01:36:17 DEBUG : Cache remote TestInternalCache:tidwcm1744680976: list ''
2025/04/15 01:36:17 DEBUG : : list: cold listing: 2025-04-14 19:36:16.654393562 +0000 UTC
2025/04/15 01:36:17 DEBUG : : list: read 1 from source
2025/04/15 01:36:17 DEBUG : : list: source entries: [one]
2025/04/15 01:36:17 DEBUG : : list: cached object: one
2025/04/15 01:36:17 DEBUG : : list: cached directories: 0
2025/04/15 01:36:17 DEBUG : : list: cached dir: 'tidwcm1744680976', cache ts: 2025-04-15 01:36:17.165904673 +0000 UTC m=+1.636321638
2025/04/15 01:36:17 DEBUG : one: removing object
2025/04/15 01:36:17 DEBUG : : cache: expired tidwcm1744680976
2025/04/15 01:36:17 INFO  : one: Deleted
2025/04/15 01:36:17 DEBUG : Cache remote TestInternalCache:tidwcm1744680976: list ''
2025/04/15 01:36:17 DEBUG : : list: cold listing: 2025-04-14 19:36:17.169351245 +0000 UTC
2025/04/15 01:36:17 DEBUG : : list: read 0 from source
2025/04/15 01:36:17 DEBUG : : list: source entries: []
2025/04/15 01:36:17 DEBUG : : list: cached directories: 0
2025/04/15 01:36:17 DEBUG : : list: cached dir: 'tidwcm1744680976', cache ts: 2025-04-15 01:36:17.170564041 +0000 UTC m=+1.640981007
2025/04/15 01:36:17 DEBUG : removing 1 level 0 directories
2025/04/15 01:36:17 INFO  : Cache remote TestInternalCache:tidwcm1744680976: Removing directory
2025/04/15 01:36:17 DEBUG : Cache remote TestInternalCache:tidwcm1744680976: rmdir ''
2025/04/15 01:36:17 DEBUG : : rmdir: removed dir in source fs
2025/04/15 01:36:17 DEBUG : : rmdir: removed from cache
2025/04/15 01:36:17 INFO  : : rmdir: cache expired
2025/04/15 01:36:17 DEBUG : Cache remote TestInternalCache:tidwcm1744680976: Services stopped
--- PASS: TestInternalDoubleWrittenContentMatches (0.54s)
=== RUN   TestInternalCachedUpdatedContentMatches
2025/04/15 01:36:17 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2025/04/15 01:36:17 DEBUG : Creating backend with remote "TestInternalCache-local:/tmp/TestInternalCache-local/ticucm1744680977"
2025/04/15 01:36:17 DEBUG : TestInternalCache: wrapped TestInternalCache-local:/tmp/TestInternalCache-local/ticucm1744680977 at root ticucm1744680977
2025/04/15 01:36:17 INFO  : TestInternalCache: Cache DB path: /home/rclone/.cache/rclone/cache-backend/TestInternalCache.db
2025/04/15 01:36:17 INFO  : TestInternalCache: Cache chunk path: /home/rclone/.cache/rclone/cache-backend/TestInternalCache
2025/04/15 01:36:17 INFO  : TestInternalCache: Chunk Memory: true
2025/04/15 01:36:17 INFO  : TestInternalCache: Chunk Size: 5Mi
2025/04/15 01:36:17 INFO  : TestInternalCache: Chunk Total Size: 10Gi
2025/04/15 01:36:17 INFO  : TestInternalCache: Chunk Clean Interval: 1m0s
2025/04/15 01:36:17 INFO  : TestInternalCache: Workers: 4
2025/04/15 01:36:17 INFO  : TestInternalCache: File Age: 6h0m0s
2025/04/15 01:36:17 DEBUG : Waiting for deletions to finish
2025/04/15 01:36:17 DEBUG : Cache remote TestInternalCache:ticucm1744680977: list ''
2025/04/15 01:36:17 DEBUG : : list: error: couldn't open bucket (ticucm1744680977)
2025/04/15 01:36:17 ERROR : : error listing: directory not found
2025/04/15 01:36:17 DEBUG : Cache remote TestInternalCache:ticucm1744680977: list ''
2025/04/15 01:36:17 DEBUG : : list: error: couldn't open bucket (ticucm1744680977)
2025/04/15 01:36:17 ERROR : Cache remote TestInternalCache:ticucm1744680977: Failed to list "": directory not found
2025/04/15 01:36:17 DEBUG : removing 1 level 0 directories
2025/04/15 01:36:17 INFO  : Cache remote TestInternalCache:ticucm1744680977: Removing directory
2025/04/15 01:36:17 DEBUG : Cache remote TestInternalCache:ticucm1744680977: rmdir ''
2025/04/15 01:36:17 ERROR : : Failed to rmdir: stat /tmp/TestInternalCache-local/ticucm1744680977: no such file or directory
2025/04/15 01:36:17 DEBUG : Cache remote TestInternalCache:ticucm1744680977: mkdir ''
2025/04/15 01:36:17 DEBUG : : mkdir: created dir in source fs
2025/04/15 01:36:17 DEBUG : : mkdir: added to cache
2025/04/15 01:36:17 DEBUG : : cache: expired ticucm1744680977
2025/04/15 01:36:17 INFO  : : mkdir: cache expired
2025/04/15 01:36:17 DEBUG : Cache remote TestInternalCache:ticucm1744680977: put data at 'data.bin'
2025/04/15 01:36:17 DEBUG : data.bin: put: uploaded to remote fs
2025/04/15 01:36:17 DEBUG : data.bin: put: added to cache
2025/04/15 01:36:17 DEBUG : : cache: expired ticucm1744680977
2025/04/15 01:36:17 INFO  : : put: cache expired
2025/04/15 01:36:17 DEBUG : Cache remote TestInternalCache:ticucm1744680977: new object 'data.bin'
2025/04/15 01:36:17 DEBUG : data.bin: find: warm object: data.bin, expiring on: 2025-04-15 07:36:17.190102548 +0000 UTC
2025/04/15 01:36:17 DEBUG : data.bin: updating object contents with size 200
2025/04/15 01:36:17 DEBUG : Cache remote TestInternalCache:ticucm1744680977: new object 'data.bin'
2025/04/15 01:36:17 DEBUG : data.bin: find: warm object: data.bin, expiring on: 2025-04-15 07:36:17.194465439 +0000 UTC
2025/04/15 01:36:17 DEBUG : ticucm1744680977/data.bin: moving offset set from 0 to 0
2025/04/15 01:36:17 DEBUG : ticucm1744680977/data.bin: 0: chunk retry storage: 0
2025/04/15 01:36:17 DEBUG : worker-1 <data.bin>: partial downloaded chunk 0
2025/04/15 01:36:17 DEBUG : ticucm1744680977/data.bin: cache reader closed 200
2025/04/15 01:36:17 DEBUG : Waiting for deletions to finish
2025/04/15 01:36:17 DEBUG : Cache remote TestInternalCache:ticucm1744680977: list ''
2025/04/15 01:36:17 DEBUG : : list: cold listing: 2025-04-14 19:36:17.191746424 +0000 UTC
2025/04/15 01:36:17 DEBUG : : list: read 1 from source
2025/04/15 01:36:17 DEBUG : : list: source entries: [data.bin]
2025/04/15 01:36:17 DEBUG : : list: cached object: data.bin
2025/04/15 01:36:17 DEBUG : : list: cached directories: 0
2025/04/15 01:36:17 DEBUG : : list: cached dir: 'ticucm1744680977', cache ts: 2025-04-15 01:36:17.699458322 +0000 UTC m=+2.169875287
2025/04/15 01:36:17 DEBUG : data.bin: removing object
2025/04/15 01:36:17 DEBUG : : cache: expired ticucm1744680977
2025/04/15 01:36:17 INFO  : data.bin: Deleted
2025/04/15 01:36:17 DEBUG : Cache remote TestInternalCache:ticucm1744680977: list ''
2025/04/15 01:36:17 DEBUG : : list: cold listing: 2025-04-14 19:36:17.703525748 +0000 UTC
2025/04/15 01:36:17 DEBUG : : list: read 0 from source
2025/04/15 01:36:17 DEBUG : : list: source entries: []
2025/04/15 01:36:17 DEBUG : : list: cached directories: 0
2025/04/15 01:36:17 DEBUG : : list: cached dir: 'ticucm1744680977', cache ts: 2025-04-15 01:36:17.704984217 +0000 UTC m=+2.175401173
2025/04/15 01:36:17 DEBUG : removing 1 level 0 directories
2025/04/15 01:36:17 INFO  : Cache remote TestInternalCache:ticucm1744680977: Removing directory
2025/04/15 01:36:17 DEBUG : Cache remote TestInternalCache:ticucm1744680977: rmdir ''
2025/04/15 01:36:17 DEBUG : : rmdir: removed dir in source fs
2025/04/15 01:36:17 DEBUG : : rmdir: removed from cache
2025/04/15 01:36:17 INFO  : : rmdir: cache expired
2025/04/15 01:36:17 DEBUG : Cache remote TestInternalCache:ticucm1744680977: Services stopped
--- PASS: TestInternalCachedUpdatedContentMatches (0.53s)
=== RUN   TestInternalWrappedWrittenContentMatches
2025/04/15 01:36:17 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/04/15 01:36:17 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/04/15 01:36:17 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2025/04/15 01:36:17 DEBUG : Creating backend with remote "TestInternalCache-local:/tmp/TestInternalCache-local/tiwfcns1744680977"
2025/04/15 01:36:17 DEBUG : TestInternalCache: wrapped TestInternalCache-local:/tmp/TestInternalCache-local/tiwfcns1744680977 at root tiwfcns1744680977
2025/04/15 01:36:17 INFO  : TestInternalCache: Cache DB path: /home/rclone/.cache/rclone/cache-backend/TestInternalCache.db
2025/04/15 01:36:17 INFO  : TestInternalCache: Cache chunk path: /home/rclone/.cache/rclone/cache-backend/TestInternalCache
2025/04/15 01:36:17 INFO  : TestInternalCache: Chunk Memory: true
2025/04/15 01:36:17 INFO  : TestInternalCache: Chunk Size: 5Mi
2025/04/15 01:36:17 INFO  : TestInternalCache: Chunk Total Size: 10Gi
2025/04/15 01:36:17 INFO  : TestInternalCache: Chunk Clean Interval: 1m0s
2025/04/15 01:36:17 INFO  : TestInternalCache: Workers: 4
2025/04/15 01:36:17 INFO  : TestInternalCache: File Age: 6h0m0s
2025/04/15 01:36:17 DEBUG : Waiting for deletions to finish
2025/04/15 01:36:17 DEBUG : Cache remote TestInternalCache:tiwfcns1744680977: list ''
2025/04/15 01:36:17 DEBUG : : list: error: couldn't open bucket (tiwfcns1744680977)
2025/04/15 01:36:17 ERROR : : error listing: directory not found
2025/04/15 01:36:17 DEBUG : Cache remote TestInternalCache:tiwfcns1744680977: list ''
2025/04/15 01:36:17 DEBUG : : list: error: couldn't open bucket (tiwfcns1744680977)
2025/04/15 01:36:17 ERROR : Cache remote TestInternalCache:tiwfcns1744680977: Failed to list "": directory not found
2025/04/15 01:36:17 DEBUG : removing 1 level 0 directories
2025/04/15 01:36:17 INFO  : Cache remote TestInternalCache:tiwfcns1744680977: Removing directory
2025/04/15 01:36:17 DEBUG : Cache remote TestInternalCache:tiwfcns1744680977: rmdir ''
2025/04/15 01:36:17 ERROR : : Failed to rmdir: stat /tmp/TestInternalCache-local/tiwfcns1744680977: no such file or directory
2025/04/15 01:36:17 DEBUG : Cache remote TestInternalCache:tiwfcns1744680977: mkdir ''
2025/04/15 01:36:17 DEBUG : : mkdir: created dir in source fs
2025/04/15 01:36:17 DEBUG : : mkdir: added to cache
2025/04/15 01:36:17 DEBUG : : cache: expired tiwfcns1744680977
2025/04/15 01:36:17 INFO  : : mkdir: cache expired
2025/04/15 01:36:18 DEBUG : Cache remote TestInternalCache:tiwfcns1744680977: put data at 'data.bin'
2025/04/15 01:36:18 DEBUG : data.bin: put: uploaded to remote fs
2025/04/15 01:36:18 DEBUG : data.bin: put: added to cache
2025/04/15 01:36:18 DEBUG : : cache: expired tiwfcns1744680977
2025/04/15 01:36:18 INFO  : : put: cache expired
2025/04/15 01:36:18 DEBUG : Cache remote TestInternalCache:tiwfcns1744680977: new object 'data.bin'
2025/04/15 01:36:18 DEBUG : data.bin: find: warm object: data.bin, expiring on: 2025-04-15 07:36:18.246827009 +0000 UTC
2025/04/15 01:36:18 DEBUG : Cache remote TestInternalCache:tiwfcns1744680977: new object 'data.bin'
2025/04/15 01:36:18 DEBUG : data.bin: find: warm object: data.bin, expiring on: 2025-04-15 07:36:18.246827009 +0000 UTC
2025/04/15 01:36:18 NOTICE: original size: 23592960
2025/04/15 01:36:18 NOTICE: updated size: 12
2025/04/15 01:36:18 DEBUG : Cache remote TestInternalCache:tiwfcns1744680977: new object 'data.bin'
2025/04/15 01:36:18 DEBUG : data.bin: find: warm object: data.bin, expiring on: 2025-04-15 07:36:18.246827009 +0000 UTC
2025/04/15 01:36:18 DEBUG : Waiting for deletions to finish
2025/04/15 01:36:18 DEBUG : Cache remote TestInternalCache:tiwfcns1744680977: list ''
2025/04/15 01:36:18 DEBUG : : list: cold listing: 2025-04-14 19:36:18.249553709 +0000 UTC
2025/04/15 01:36:18 DEBUG : : list: read 1 from source
2025/04/15 01:36:18 DEBUG : : list: source entries: [data.bin]
2025/04/15 01:36:18 DEBUG : : list: cached object: data.bin
2025/04/15 01:36:18 DEBUG : : list: cached directories: 0
2025/04/15 01:36:18 DEBUG : : list: cached dir: 'tiwfcns1744680977', cache ts: 2025-04-15 01:36:18.258790532 +0000 UTC m=+2.729207498
2025/04/15 01:36:18 DEBUG : data.bin: removing object
2025/04/15 01:36:18 DEBUG : : cache: expired tiwfcns1744680977
2025/04/15 01:36:18 INFO  : data.bin: Deleted
2025/04/15 01:36:18 DEBUG : Cache remote TestInternalCache:tiwfcns1744680977: list ''
2025/04/15 01:36:18 DEBUG : : list: cold listing: 2025-04-14 19:36:18.261820371 +0000 UTC
2025/04/15 01:36:18 DEBUG : : list: read 0 from source
2025/04/15 01:36:18 DEBUG : : list: source entries: []
2025/04/15 01:36:18 DEBUG : : list: cached directories: 0
2025/04/15 01:36:18 DEBUG : : list: cached dir: 'tiwfcns1744680977', cache ts: 2025-04-15 01:36:18.266101329 +0000 UTC m=+2.736518275
2025/04/15 01:36:18 DEBUG : removing 1 level 0 directories
2025/04/15 01:36:18 INFO  : Cache remote TestInternalCache:tiwfcns1744680977: Removing directory
2025/04/15 01:36:18 DEBUG : Cache remote TestInternalCache:tiwfcns1744680977: rmdir ''
2025/04/15 01:36:18 DEBUG : : rmdir: removed dir in source fs
2025/04/15 01:36:18 DEBUG : : rmdir: removed from cache
2025/04/15 01:36:18 INFO  : : rmdir: cache expired
2025/04/15 01:36:18 DEBUG : Cache remote TestInternalCache:tiwfcns1744680977: Services stopped
--- PASS: TestInternalWrappedFsChangeNotSeen (0.56s)
=== RUN   TestInternalMoveWithNotify
2025/04/15 01:36:18 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2025/04/15 01:36:18 DEBUG : Creating backend with remote "TestInternalCache-local:/tmp/TestInternalCache-local/timwn1744680978"
2025/04/15 01:36:18 DEBUG : TestInternalCache: wrapped TestInternalCache-local:/tmp/TestInternalCache-local/timwn1744680978 at root timwn1744680978
2025/04/15 01:36:18 INFO  : TestInternalCache: Cache DB path: /home/rclone/.cache/rclone/cache-backend/TestInternalCache.db
2025/04/15 01:36:18 INFO  : TestInternalCache: Cache chunk path: /home/rclone/.cache/rclone/cache-backend/TestInternalCache
2025/04/15 01:36:18 INFO  : TestInternalCache: Chunk Memory: true
2025/04/15 01:36:18 INFO  : TestInternalCache: Chunk Size: 5Mi
2025/04/15 01:36:18 INFO  : TestInternalCache: Chunk Total Size: 10Gi
2025/04/15 01:36:18 INFO  : TestInternalCache: Chunk Clean Interval: 1m0s
2025/04/15 01:36:18 INFO  : TestInternalCache: Workers: 4
2025/04/15 01:36:18 INFO  : TestInternalCache: File Age: 6h0m0s
2025/04/15 01:36:18 DEBUG : Waiting for deletions to finish
2025/04/15 01:36:18 DEBUG : Cache remote TestInternalCache:timwn1744680978: list ''
2025/04/15 01:36:18 DEBUG : : list: error: couldn't open bucket (timwn1744680978)
2025/04/15 01:36:18 ERROR : : error listing: directory not found
2025/04/15 01:36:18 DEBUG : Cache remote TestInternalCache:timwn1744680978: list ''
2025/04/15 01:36:18 DEBUG : : list: error: couldn't open bucket (timwn1744680978)
2025/04/15 01:36:18 ERROR : Cache remote TestInternalCache:timwn1744680978: Failed to list "": directory not found
2025/04/15 01:36:18 DEBUG : removing 1 level 0 directories
2025/04/15 01:36:18 INFO  : Cache remote TestInternalCache:timwn1744680978: Removing directory
2025/04/15 01:36:18 DEBUG : Cache remote TestInternalCache:timwn1744680978: rmdir ''
2025/04/15 01:36:18 ERROR : : Failed to rmdir: stat /tmp/TestInternalCache-local/timwn1744680978: no such file or directory
2025/04/15 01:36:18 DEBUG : Cache remote TestInternalCache:timwn1744680978: mkdir ''
2025/04/15 01:36:18 DEBUG : : mkdir: created dir in source fs
2025/04/15 01:36:18 DEBUG : : mkdir: added to cache
2025/04/15 01:36:18 DEBUG : : cache: expired timwn1744680978
2025/04/15 01:36:18 INFO  : : mkdir: cache expired
    cache_internal_test.go:453: Not external
2025/04/15 01:36:18 DEBUG : Waiting for deletions to finish
2025/04/15 01:36:18 DEBUG : Cache remote TestInternalCache:timwn1744680978: list ''
2025/04/15 01:36:18 DEBUG : : list: cold listing: 2025-04-14 19:36:18.280936765 +0000 UTC
2025/04/15 01:36:18 DEBUG : : list: read 0 from source
2025/04/15 01:36:18 DEBUG : : list: source entries: []
2025/04/15 01:36:18 DEBUG : : list: cached directories: 0
2025/04/15 01:36:18 DEBUG : : list: cached dir: 'timwn1744680978', cache ts: 2025-04-15 01:36:18.282266011 +0000 UTC m=+2.752682936
2025/04/15 01:36:18 DEBUG : Cache remote TestInternalCache:timwn1744680978: list ''
2025/04/15 01:36:18 DEBUG : : list: empty listing
2025/04/15 01:36:18 DEBUG : : list: read 0 from source
2025/04/15 01:36:18 DEBUG : : list: source entries: []
2025/04/15 01:36:18 DEBUG : : list: cached directories: 0
2025/04/15 01:36:18 DEBUG : : list: cached dir: 'timwn1744680978', cache ts: 2025-04-15 01:36:18.283233378 +0000 UTC m=+2.753650303
2025/04/15 01:36:18 DEBUG : removing 1 level 0 directories
2025/04/15 01:36:18 INFO  : Cache remote TestInternalCache:timwn1744680978: Removing directory
2025/04/15 01:36:18 DEBUG : Cache remote TestInternalCache:timwn1744680978: rmdir ''
2025/04/15 01:36:18 DEBUG : : rmdir: removed dir in source fs
2025/04/15 01:36:18 DEBUG : : rmdir: removed from cache
2025/04/15 01:36:18 INFO  : : rmdir: cache expired
2025/04/15 01:36:18 DEBUG : Cache remote TestInternalCache:timwn1744680978: Services stopped
--- SKIP: TestInternalMoveWithNotify (0.01s)
=== RUN   TestInternalNotifyCreatesEmptyParts
2025/04/15 01:36:18 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2025/04/15 01:36:18 DEBUG : Creating backend with remote "TestInternalCache-local:/tmp/TestInternalCache-local/tincep1744680978"
2025/04/15 01:36:18 DEBUG : TestInternalCache: wrapped TestInternalCache-local:/tmp/TestInternalCache-local/tincep1744680978 at root tincep1744680978
2025/04/15 01:36:18 INFO  : TestInternalCache: Cache DB path: /home/rclone/.cache/rclone/cache-backend/TestInternalCache.db
2025/04/15 01:36:18 INFO  : TestInternalCache: Cache chunk path: /home/rclone/.cache/rclone/cache-backend/TestInternalCache
2025/04/15 01:36:18 INFO  : TestInternalCache: Chunk Memory: true
2025/04/15 01:36:18 INFO  : TestInternalCache: Chunk Size: 5Mi
2025/04/15 01:36:18 INFO  : TestInternalCache: Chunk Total Size: 10Gi
2025/04/15 01:36:18 INFO  : TestInternalCache: Chunk Clean Interval: 1m0s
2025/04/15 01:36:18 INFO  : TestInternalCache: Workers: 4
2025/04/15 01:36:18 INFO  : TestInternalCache: File Age: 6h0m0s
2025/04/15 01:36:18 DEBUG : Waiting for deletions to finish
2025/04/15 01:36:18 DEBUG : Cache remote TestInternalCache:tincep1744680978: list ''
2025/04/15 01:36:18 DEBUG : : list: error: couldn't open bucket (tincep1744680978)
2025/04/15 01:36:18 ERROR : : error listing: directory not found
2025/04/15 01:36:18 DEBUG : Cache remote TestInternalCache:tincep1744680978: list ''
2025/04/15 01:36:18 DEBUG : : list: error: couldn't open bucket (tincep1744680978)
2025/04/15 01:36:18 ERROR : Cache remote TestInternalCache:tincep1744680978: Failed to list "": directory not found
2025/04/15 01:36:18 DEBUG : removing 1 level 0 directories
2025/04/15 01:36:18 INFO  : Cache remote TestInternalCache:tincep1744680978: Removing directory
2025/04/15 01:36:18 DEBUG : Cache remote TestInternalCache:tincep1744680978: rmdir ''
2025/04/15 01:36:18 ERROR : : Failed to rmdir: stat /tmp/TestInternalCache-local/tincep1744680978: no such file or directory
2025/04/15 01:36:18 DEBUG : Cache remote TestInternalCache:tincep1744680978: mkdir ''
2025/04/15 01:36:18 DEBUG : : mkdir: created dir in source fs
2025/04/15 01:36:18 DEBUG : : mkdir: added to cache
2025/04/15 01:36:18 DEBUG : : cache: expired tincep1744680978
2025/04/15 01:36:18 INFO  : : mkdir: cache expired
    cache_internal_test.go:539: Not external
2025/04/15 01:36:18 DEBUG : Waiting for deletions to finish
2025/04/15 01:36:18 DEBUG : Cache remote TestInternalCache:tincep1744680978: list ''
2025/04/15 01:36:18 DEBUG : : list: cold listing: 2025-04-14 19:36:18.295896775 +0000 UTC
2025/04/15 01:36:18 DEBUG : : list: read 0 from source
2025/04/15 01:36:18 DEBUG : : list: source entries: []
2025/04/15 01:36:18 DEBUG : : list: cached directories: 0
2025/04/15 01:36:18 DEBUG : : list: cached dir: 'tincep1744680978', cache ts: 2025-04-15 01:36:18.297080748 +0000 UTC m=+2.767497683
2025/04/15 01:36:18 DEBUG : Cache remote TestInternalCache:tincep1744680978: list ''
2025/04/15 01:36:18 DEBUG : : list: empty listing
2025/04/15 01:36:18 DEBUG : : list: read 0 from source
2025/04/15 01:36:18 DEBUG : : list: source entries: []
2025/04/15 01:36:18 DEBUG : : list: cached directories: 0
2025/04/15 01:36:18 DEBUG : : list: cached dir: 'tincep1744680978', cache ts: 2025-04-15 01:36:18.298237911 +0000 UTC m=+2.768654846
2025/04/15 01:36:18 DEBUG : removing 1 level 0 directories
2025/04/15 01:36:18 INFO  : Cache remote TestInternalCache:tincep1744680978: Removing directory
2025/04/15 01:36:18 DEBUG : Cache remote TestInternalCache:tincep1744680978: rmdir ''
2025/04/15 01:36:18 DEBUG : : rmdir: removed dir in source fs
2025/04/15 01:36:18 DEBUG : : rmdir: removed from cache
2025/04/15 01:36:18 INFO  : : rmdir: cache expired
2025/04/15 01:36:18 DEBUG : Cache remote TestInternalCache:tincep1744680978: Services stopped
--- SKIP: TestInternalNotifyCreatesEmptyParts (0.02s)
=== RUN   TestInternalChangeSeenAfterDirCacheFlush
2025/04/15 01:36:18 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2025/04/15 01:36:18 DEBUG : Creating backend with remote "TestInternalCache-local:/tmp/TestInternalCache-local/ticsadcf1744680978"
2025/04/15 01:36:18 DEBUG : TestInternalCache: wrapped TestInternalCache-local:/tmp/TestInternalCache-local/ticsadcf1744680978 at root ticsadcf1744680978
2025/04/15 01:36:18 INFO  : TestInternalCache: Cache DB path: /home/rclone/.cache/rclone/cache-backend/TestInternalCache.db
2025/04/15 01:36:18 INFO  : TestInternalCache: Cache chunk path: /home/rclone/.cache/rclone/cache-backend/TestInternalCache
2025/04/15 01:36:18 INFO  : TestInternalCache: Chunk Memory: true
2025/04/15 01:36:18 INFO  : TestInternalCache: Chunk Size: 5Mi
2025/04/15 01:36:18 INFO  : TestInternalCache: Chunk Total Size: 10Gi
2025/04/15 01:36:18 INFO  : TestInternalCache: Chunk Clean Interval: 1m0s
2025/04/15 01:36:18 INFO  : TestInternalCache: Workers: 4
2025/04/15 01:36:18 INFO  : TestInternalCache: File Age: 6h0m0s
2025/04/15 01:36:18 DEBUG : Waiting for deletions to finish
2025/04/15 01:36:18 DEBUG : Cache remote TestInternalCache:ticsadcf1744680978: list ''
2025/04/15 01:36:18 DEBUG : : list: error: couldn't open bucket (ticsadcf1744680978)
2025/04/15 01:36:18 ERROR : : error listing: directory not found
2025/04/15 01:36:18 DEBUG : Cache remote TestInternalCache:ticsadcf1744680978: list ''
2025/04/15 01:36:18 DEBUG : : list: error: couldn't open bucket (ticsadcf1744680978)
2025/04/15 01:36:18 ERROR : Cache remote TestInternalCache:ticsadcf1744680978: Failed to list "": directory not found
2025/04/15 01:36:18 DEBUG : removing 1 level 0 directories
2025/04/15 01:36:18 INFO  : Cache remote TestInternalCache:ticsadcf1744680978: Removing directory
2025/04/15 01:36:18 DEBUG : Cache remote TestInternalCache:ticsadcf1744680978: rmdir ''
2025/04/15 01:36:18 ERROR : : Failed to rmdir: stat /tmp/TestInternalCache-local/ticsadcf1744680978: no such file or directory
2025/04/15 01:36:18 DEBUG : Cache remote TestInternalCache:ticsadcf1744680978: mkdir ''
2025/04/15 01:36:18 DEBUG : : mkdir: created dir in source fs
2025/04/15 01:36:18 DEBUG : : mkdir: added to cache
2025/04/15 01:36:18 DEBUG : : cache: expired ticsadcf1744680978
2025/04/15 01:36:18 INFO  : : mkdir: cache expired
2025/04/15 01:36:18 DEBUG : Cache remote TestInternalCache:ticsadcf1744680978: put data at 'data.bin'
2025/04/15 01:36:18 DEBUG : data.bin: put: uploaded to remote fs
2025/04/15 01:36:18 DEBUG : data.bin: put: added to cache
2025/04/15 01:36:18 DEBUG : : cache: expired ticsadcf1744680978
2025/04/15 01:36:18 INFO  : : put: cache expired
2025/04/15 01:36:18 DEBUG : Cache remote TestInternalCache:ticsadcf1744680978: new object 'data.bin'
2025/04/15 01:36:18 DEBUG : data.bin: find: warm object: data.bin, expiring on: 2025-04-15 07:36:18.824517742 +0000 UTC
2025/04/15 01:36:18 DEBUG : Cache remote TestInternalCache:ticsadcf1744680978: new object 'data.bin'
2025/04/15 01:36:18 DEBUG : data.bin: find: warm object: data.bin, expiring on: 2025-04-15 07:36:18.824517742 +0000 UTC
2025/04/15 01:36:18 DEBUG : Cache remote TestInternalCache:ticsadcf1744680978: new object 'data.bin'
2025/04/15 01:36:18 DEBUG : data.bin: find: error: couldn't open parent bucket for ticsadcf1744680978
2025/04/15 01:36:18 DEBUG : data.bin: find: cached object
2025/04/15 01:36:18 DEBUG : Waiting for deletions to finish
2025/04/15 01:36:18 DEBUG : Cache remote TestInternalCache:ticsadcf1744680978: list ''
2025/04/15 01:36:18 DEBUG : : list: error: missing cached dir: 
2025/04/15 01:36:18 DEBUG : : list: read 1 from source
2025/04/15 01:36:18 DEBUG : : list: source entries: [data.bin]
2025/04/15 01:36:18 DEBUG : : list: cached object: data.bin
2025/04/15 01:36:18 DEBUG : : list: cached directories: 0
2025/04/15 01:36:18 DEBUG : : list: cached dir: 'ticsadcf1744680978', cache ts: 2025-04-15 01:36:18.832179136 +0000 UTC m=+3.302596062
2025/04/15 01:36:18 DEBUG : data.bin: removing object
2025/04/15 01:36:18 DEBUG : : cache: expired ticsadcf1744680978
2025/04/15 01:36:18 INFO  : data.bin: Deleted
2025/04/15 01:36:18 DEBUG : Cache remote TestInternalCache:ticsadcf1744680978: list ''
2025/04/15 01:36:18 DEBUG : : list: cold listing: 2025-04-14 19:36:18.837664215 +0000 UTC
2025/04/15 01:36:18 DEBUG : : list: read 0 from source
2025/04/15 01:36:18 DEBUG : : list: source entries: []
2025/04/15 01:36:18 DEBUG : : list: cached directories: 0
2025/04/15 01:36:18 DEBUG : : list: cached dir: 'ticsadcf1744680978', cache ts: 2025-04-15 01:36:18.838819465 +0000 UTC m=+3.309236390
2025/04/15 01:36:18 DEBUG : removing 1 level 0 directories
2025/04/15 01:36:18 INFO  : Cache remote TestInternalCache:ticsadcf1744680978: Removing directory
2025/04/15 01:36:18 DEBUG : Cache remote TestInternalCache:ticsadcf1744680978: rmdir ''
2025/04/15 01:36:18 DEBUG : : rmdir: removed dir in source fs
2025/04/15 01:36:18 DEBUG : : rmdir: removed from cache
2025/04/15 01:36:18 INFO  : : rmdir: cache expired
2025/04/15 01:36:18 DEBUG : Cache remote TestInternalCache:ticsadcf1744680978: Services stopped
--- PASS: TestInternalChangeSeenAfterDirCacheFlush (0.54s)
=== RUN   TestInternalCacheWrites
2025/04/15 01:36:18 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2025/04/15 01:36:18 DEBUG : Creating backend with remote "TestInternalCache-local:/tmp/TestInternalCache-local/ticw"
2025/04/15 01:36:18 DEBUG : TestInternalCache: wrapped TestInternalCache-local:/tmp/TestInternalCache-local/ticw at root ticw
2025/04/15 01:36:18 INFO  : TestInternalCache: Cache DB path: /home/rclone/.cache/rclone/cache-backend/TestInternalCache.db
2025/04/15 01:36:18 INFO  : TestInternalCache: Cache chunk path: /home/rclone/.cache/rclone/cache-backend/TestInternalCache
2025/04/15 01:36:18 INFO  : TestInternalCache: Chunk Memory: true
2025/04/15 01:36:18 INFO  : TestInternalCache: Chunk Size: 5Mi
2025/04/15 01:36:18 INFO  : TestInternalCache: Chunk Total Size: 10Gi
2025/04/15 01:36:18 INFO  : TestInternalCache: Chunk Clean Interval: 1m0s
2025/04/15 01:36:18 INFO  : TestInternalCache: Workers: 4
2025/04/15 01:36:18 INFO  : TestInternalCache: File Age: 6h0m0s
2025/04/15 01:36:18 INFO  : TestInternalCache: Cache Writes: enabled
2025/04/15 01:36:18 DEBUG : Waiting for deletions to finish
2025/04/15 01:36:18 DEBUG : Cache remote TestInternalCache:ticw: list ''
2025/04/15 01:36:18 DEBUG : : list: error: couldn't open bucket (ticw)
2025/04/15 01:36:18 ERROR : : error listing: directory not found
2025/04/15 01:36:18 DEBUG : Cache remote TestInternalCache:ticw: list ''
2025/04/15 01:36:18 DEBUG : : list: error: couldn't open bucket (ticw)
2025/04/15 01:36:18 ERROR : Cache remote TestInternalCache:ticw: Failed to list "": directory not found
2025/04/15 01:36:18 DEBUG : removing 1 level 0 directories
2025/04/15 01:36:18 INFO  : Cache remote TestInternalCache:ticw: Removing directory
2025/04/15 01:36:18 DEBUG : Cache remote TestInternalCache:ticw: rmdir ''
2025/04/15 01:36:18 ERROR : : Failed to rmdir: stat /tmp/TestInternalCache-local/ticw: no such file or directory
2025/04/15 01:36:18 DEBUG : Cache remote TestInternalCache:ticw: mkdir ''
2025/04/15 01:36:18 DEBUG : : mkdir: created dir in source fs
2025/04/15 01:36:18 DEBUG : : mkdir: added to cache
2025/04/15 01:36:18 DEBUG : : cache: expired ticw
2025/04/15 01:36:18 INFO  : : mkdir: cache expired
2025/04/15 01:36:19 DEBUG : Cache remote TestInternalCache:ticw: put data at 'data.bin'
2025/04/15 01:36:19 DEBUG : data.bin: put: uploaded to remote fs and saved in cache
2025/04/15 01:36:19 DEBUG : data.bin: put: added to cache
2025/04/15 01:36:19 DEBUG : : cache: expired ticw
2025/04/15 01:36:19 INFO  : : put: cache expired
2025/04/15 01:36:19 DEBUG : Cache remote TestInternalCache:ticw: new object 'data.bin'
2025/04/15 01:36:19 DEBUG : data.bin: find: warm object: data.bin, expiring on: 2025-04-15 07:36:19.49637318 +0000 UTC
2025/04/15 01:36:19 DEBUG : Waiting for deletions to finish
2025/04/15 01:36:19 DEBUG : Cache remote TestInternalCache:ticw: list ''
2025/04/15 01:36:19 DEBUG : : list: cold listing: 2025-04-14 19:36:19.50589089 +0000 UTC
2025/04/15 01:36:19 DEBUG : : list: read 1 from source
2025/04/15 01:36:19 DEBUG : : list: source entries: [data.bin]
2025/04/15 01:36:19 DEBUG : : list: cached object: data.bin
2025/04/15 01:36:19 DEBUG : : list: cached directories: 0
2025/04/15 01:36:19 DEBUG : : list: cached dir: 'ticw', cache ts: 2025-04-15 01:36:19.508484189 +0000 UTC m=+3.978901154
2025/04/15 01:36:19 DEBUG : data.bin: removing object
2025/04/15 01:36:19 DEBUG : : cache: expired ticw
2025/04/15 01:36:19 INFO  : data.bin: Deleted
2025/04/15 01:36:19 DEBUG : Cache remote TestInternalCache:ticw: list ''
2025/04/15 01:36:19 DEBUG : : list: cold listing: 2025-04-14 19:36:19.522112218 +0000 UTC
2025/04/15 01:36:19 DEBUG : : list: read 0 from source
2025/04/15 01:36:19 DEBUG : : list: source entries: []
2025/04/15 01:36:19 DEBUG : : list: cached directories: 0
2025/04/15 01:36:19 DEBUG : : list: cached dir: 'ticw', cache ts: 2025-04-15 01:36:19.523350733 +0000 UTC m=+3.993767668
2025/04/15 01:36:19 DEBUG : removing 1 level 0 directories
2025/04/15 01:36:19 INFO  : Cache remote TestInternalCache:ticw: Removing directory
2025/04/15 01:36:19 DEBUG : Cache remote TestInternalCache:ticw: rmdir ''
2025/04/15 01:36:19 DEBUG : : rmdir: removed dir in source fs
2025/04/15 01:36:19 DEBUG : : rmdir: removed from cache
2025/04/15 01:36:19 INFO  : : rmdir: cache expired
2025/04/15 01:36:19 DEBUG : Cache remote TestInternalCache:ticw: Services stopped
--- PASS: TestInternalCacheWrites (0.69s)
=== RUN   TestInternalMaxChunkSizeRespected
2025/04/15 01:36:19 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2025/04/15 01:36:19 DEBUG : Creating backend with remote "TestInternalCache-local:/tmp/TestInternalCache-local/timcsr1744680979"
2025/04/15 01:36:19 DEBUG : TestInternalCache: wrapped TestInternalCache-local:/tmp/TestInternalCache-local/timcsr1744680979 at root timcsr1744680979
2025/04/15 01:36:19 INFO  : TestInternalCache: Cache DB path: /home/rclone/.cache/rclone/cache-backend/TestInternalCache.db
2025/04/15 01:36:19 INFO  : TestInternalCache: Cache chunk path: /home/rclone/.cache/rclone/cache-backend/TestInternalCache
2025/04/15 01:36:19 INFO  : TestInternalCache: Chunk Memory: true
2025/04/15 01:36:19 INFO  : TestInternalCache: Chunk Size: 5Mi
2025/04/15 01:36:19 INFO  : TestInternalCache: Chunk Total Size: 10Gi
2025/04/15 01:36:19 INFO  : TestInternalCache: Chunk Clean Interval: 1m0s
2025/04/15 01:36:19 INFO  : TestInternalCache: Workers: 1
2025/04/15 01:36:19 INFO  : TestInternalCache: File Age: 6h0m0s
2025/04/15 01:36:19 DEBUG : Waiting for deletions to finish
2025/04/15 01:36:19 DEBUG : Cache remote TestInternalCache:timcsr1744680979: list ''
2025/04/15 01:36:19 DEBUG : : list: error: couldn't open bucket (timcsr1744680979)
2025/04/15 01:36:19 ERROR : : error listing: directory not found
2025/04/15 01:36:19 DEBUG : Cache remote TestInternalCache:timcsr1744680979: list ''
2025/04/15 01:36:19 DEBUG : : list: error: couldn't open bucket (timcsr1744680979)
2025/04/15 01:36:19 ERROR : Cache remote TestInternalCache:timcsr1744680979: Failed to list "": directory not found
2025/04/15 01:36:19 DEBUG : removing 1 level 0 directories
2025/04/15 01:36:19 INFO  : Cache remote TestInternalCache:timcsr1744680979: Removing directory
2025/04/15 01:36:19 DEBUG : Cache remote TestInternalCache:timcsr1744680979: rmdir ''
2025/04/15 01:36:19 ERROR : : Failed to rmdir: stat /tmp/TestInternalCache-local/timcsr1744680979: no such file or directory
2025/04/15 01:36:19 DEBUG : Cache remote TestInternalCache:timcsr1744680979: mkdir ''
2025/04/15 01:36:19 DEBUG : : mkdir: created dir in source fs
2025/04/15 01:36:19 DEBUG : : mkdir: added to cache
2025/04/15 01:36:19 DEBUG : : cache: expired timcsr1744680979
2025/04/15 01:36:19 INFO  : : mkdir: cache expired
2025/04/15 01:36:21 DEBUG : Cache remote TestInternalCache:timcsr1744680979: put data at 'data.bin'
2025/04/15 01:36:21 DEBUG : data.bin: put: uploaded to remote fs
2025/04/15 01:36:21 DEBUG : data.bin: put: added to cache
2025/04/15 01:36:21 DEBUG : : cache: expired timcsr1744680979
2025/04/15 01:36:21 INFO  : : put: cache expired
2025/04/15 01:36:21 DEBUG : Cache remote TestInternalCache:timcsr1744680979: new object 'data.bin'
2025/04/15 01:36:21 DEBUG : data.bin: find: warm object: data.bin, expiring on: 2025-04-15 07:36:21.758004627 +0000 UTC
2025/04/15 01:36:21 DEBUG : Cache remote TestInternalCache:timcsr1744680979: new object 'data.bin'
2025/04/15 01:36:21 DEBUG : data.bin: find: warm object: data.bin, expiring on: 2025-04-15 07:36:21.758004627 +0000 UTC
2025/04/15 01:36:21 DEBUG : timcsr1744680979/data.bin: moving offset set from 0 to 0
2025/04/15 01:36:21 DEBUG : timcsr1744680979/data.bin: 0: chunk retry storage: 0
2025/04/15 01:36:21 DEBUG : worker-0 <data.bin>: downloaded chunk 0
2025/04/15 01:36:22 DEBUG : timcsr1744680979/data.bin: cache reader closed 5242880
2025/04/15 01:36:22 DEBUG : timcsr1744680979/data.bin: moving offset set from 0 to 5242880
2025/04/15 01:36:22 DEBUG : timcsr1744680979/data.bin: 5242880: chunk retry storage: 0
2025/04/15 01:36:22 DEBUG : worker-0 <data.bin>: downloaded chunk 5242880
2025/04/15 01:36:22 DEBUG : timcsr1744680979/data.bin: cache reader closed 10485760
2025/04/15 01:36:22 DEBUG : timcsr1744680979/data.bin: moving offset set from 0 to 10485760
2025/04/15 01:36:22 DEBUG : timcsr1744680979/data.bin: 10485760: chunk retry storage: 0
2025/04/15 01:36:22 DEBUG : worker-0 <data.bin>: downloaded chunk 10485760
2025/04/15 01:36:23 DEBUG : timcsr1744680979/data.bin: cache reader closed 15728640
2025/04/15 01:36:23 DEBUG : timcsr1744680979/data.bin: moving offset set from 0 to 15728640
2025/04/15 01:36:23 DEBUG : timcsr1744680979/data.bin: 15728640: chunk retry storage: 0
2025/04/15 01:36:23 DEBUG : worker-0 <data.bin>: downloaded chunk 15728640
2025/04/15 01:36:23 DEBUG : timcsr1744680979/data.bin: cache reader closed 20971520
2025/04/15 01:36:23 DEBUG : timcsr1744680979/data.bin: moving offset set from 0 to 20971520
2025/04/15 01:36:23 DEBUG : timcsr1744680979/data.bin: 20971520: chunk retry storage: 0
2025/04/15 01:36:23 DEBUG : worker-0 <data.bin>: downloaded chunk 20971520
2025/04/15 01:36:24 DEBUG : timcsr1744680979/data.bin: cache reader closed 26214400
2025/04/15 01:36:24 DEBUG : timcsr1744680979/data.bin: moving offset set from 0 to 26214400
2025/04/15 01:36:24 DEBUG : timcsr1744680979/data.bin: 26214400: chunk retry storage: 0
2025/04/15 01:36:24 DEBUG : worker-0 <data.bin>: downloaded chunk 26214400
2025/04/15 01:36:24 DEBUG : timcsr1744680979/data.bin: cache reader closed 31457280
2025/04/15 01:36:24 DEBUG : Waiting for deletions to finish
2025/04/15 01:36:24 DEBUG : Cache remote TestInternalCache:timcsr1744680979: list ''
2025/04/15 01:36:24 DEBUG : : list: cold listing: 2025-04-14 19:36:21.760492699 +0000 UTC
2025/04/15 01:36:24 DEBUG : : list: read 1 from source
2025/04/15 01:36:24 DEBUG : : list: source entries: [data.bin]
2025/04/15 01:36:24 DEBUG : : list: cached object: data.bin
2025/04/15 01:36:24 DEBUG : : list: cached directories: 0
2025/04/15 01:36:24 DEBUG : : list: cached dir: 'timcsr1744680979', cache ts: 2025-04-15 01:36:24.941269254 +0000 UTC m=+9.411686199
2025/04/15 01:36:24 DEBUG : data.bin: removing object
2025/04/15 01:36:24 DEBUG : : cache: expired timcsr1744680979
2025/04/15 01:36:24 INFO  : data.bin: Deleted
2025/04/15 01:36:24 DEBUG : Cache remote TestInternalCache:timcsr1744680979: list ''
2025/04/15 01:36:24 DEBUG : : list: cold listing: 2025-04-14 19:36:24.953438222 +0000 UTC
2025/04/15 01:36:24 DEBUG : : list: read 0 from source
2025/04/15 01:36:24 DEBUG : : list: source entries: []
2025/04/15 01:36:24 DEBUG : : list: cached directories: 0
2025/04/15 01:36:24 DEBUG : : list: cached dir: 'timcsr1744680979', cache ts: 2025-04-15 01:36:24.954420286 +0000 UTC m=+9.424837231
2025/04/15 01:36:24 DEBUG : removing 1 level 0 directories
2025/04/15 01:36:24 INFO  : Cache remote TestInternalCache:timcsr1744680979: Removing directory
2025/04/15 01:36:24 DEBUG : Cache remote TestInternalCache:timcsr1744680979: rmdir ''
2025/04/15 01:36:24 DEBUG : : rmdir: removed dir in source fs
2025/04/15 01:36:24 DEBUG : : rmdir: removed from cache
2025/04/15 01:36:24 INFO  : : rmdir: cache expired
2025/04/15 01:36:24 DEBUG : Cache remote TestInternalCache:timcsr1744680979: Services stopped
--- PASS: TestInternalMaxChunkSizeRespected (5.44s)
=== RUN   TestInternalExpiredEntriesRemoved
2025/04/15 01:36:24 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/04/15 01:36:24 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2025/04/15 01:36:24 DEBUG : Creating backend with remote "TestInternalCache-local:/tmp/TestInternalCache-local/tib21171744680984"
2025/04/15 01:36:24 DEBUG : TestInternalCache: wrapped TestInternalCache-local:/tmp/TestInternalCache-local/tib21171744680984 at root tib21171744680984
2025/04/15 01:36:24 INFO  : TestInternalCache: Cache DB path: /home/rclone/.cache/rclone/cache-backend/TestInternalCache.db
2025/04/15 01:36:24 INFO  : TestInternalCache: Cache chunk path: /home/rclone/.cache/rclone/cache-backend/TestInternalCache
2025/04/15 01:36:24 INFO  : TestInternalCache: Chunk Memory: true
2025/04/15 01:36:24 INFO  : TestInternalCache: Chunk Size: 5Mi
2025/04/15 01:36:24 INFO  : TestInternalCache: Chunk Total Size: 10Gi
2025/04/15 01:36:24 INFO  : TestInternalCache: Chunk Clean Interval: 15m0s
2025/04/15 01:36:24 INFO  : TestInternalCache: Workers: 4
2025/04/15 01:36:24 INFO  : TestInternalCache: File Age: 3d
2025/04/15 01:36:24 DEBUG : Waiting for deletions to finish
2025/04/15 01:36:24 DEBUG : Cache remote TestInternalCache:tib21171744680984: list ''
2025/04/15 01:36:24 DEBUG : : list: error: couldn't open bucket (tib21171744680984)
2025/04/15 01:36:24 ERROR : : error listing: directory not found
2025/04/15 01:36:24 DEBUG : Cache remote TestInternalCache:tib21171744680984: list ''
2025/04/15 01:36:24 DEBUG : : list: error: couldn't open bucket (tib21171744680984)
2025/04/15 01:36:24 ERROR : Cache remote TestInternalCache:tib21171744680984: Failed to list "": directory not found
2025/04/15 01:36:24 DEBUG : removing 1 level 0 directories
2025/04/15 01:36:24 INFO  : Cache remote TestInternalCache:tib21171744680984: Removing directory
2025/04/15 01:36:24 DEBUG : Cache remote TestInternalCache:tib21171744680984: rmdir ''
2025/04/15 01:36:24 ERROR : : Failed to rmdir: stat /tmp/TestInternalCache-local/tib21171744680984: no such file or directory
2025/04/15 01:36:24 DEBUG : Cache remote TestInternalCache:tib21171744680984: mkdir ''
2025/04/15 01:36:24 DEBUG : : mkdir: created dir in source fs
2025/04/15 01:36:24 DEBUG : : mkdir: added to cache
2025/04/15 01:36:24 DEBUG : : cache: expired tib21171744680984
2025/04/15 01:36:24 INFO  : : mkdir: cache expired
2025/04/15 01:36:24 DEBUG : Cache remote TestInternalCache:tib21171744680984: list 'test/dir1/dir2'
2025/04/15 01:36:24 DEBUG : test/dir1/dir2: list: error: couldn't open bucket (tib21171744680984/test/dir1/dir2)
2025/04/15 01:36:24 DEBUG : test/dir1/dir2: list: read 1 from source
2025/04/15 01:36:24 DEBUG : test/dir1/dir2: list: source entries: [test/dir1/dir2/test.txt]
2025/04/15 01:36:24 DEBUG : test/dir1/dir2: list: cached object: test/dir1/dir2/test.txt
2025/04/15 01:36:24 DEBUG : test/dir1/dir2: list: cached directories: 0
2025/04/15 01:36:24 DEBUG : test/dir1/dir2: list: cached dir: 'tib21171744680984/test/dir1/dir2', cache ts: 2025-04-15 01:36:24.991486252 +0000 UTC m=+9.461903177
2025/04/15 01:36:24 NOTICE: len: 1
2025/04/15 01:36:54 DEBUG : Cache remote TestInternalCache:tib21171744680984: list 'test/dir1/dir2'
2025/04/15 01:36:54 DEBUG : test/dir1/dir2: list: warm 1 from cache for: tib21171744680984/test/dir1/dir2, expiring on: 2025-04-18 01:36:24.991486252 +0000 UTC
2025/04/15 01:36:54 DEBUG : test/dir1/dir2: list: cached entries: [test/dir1/dir2/test.txt]
2025/04/15 01:36:54 NOTICE: len: 1
2025/04/15 01:36:54 DEBUG : Cache remote TestInternalCache:tib21171744680984: list 'test/dir1'
2025/04/15 01:36:54 DEBUG : test/dir1: list: error: missing cached dir: test/dir1
2025/04/15 01:36:54 DEBUG : test/dir1: list: read 4 from source
2025/04/15 01:36:54 DEBUG : test/dir1: list: source entries: [test/dir1/dir3 test/dir1/dir2 test/dir1/dir4 test/dir1/dir1]
2025/04/15 01:36:54 DEBUG : test/dir1: list: cached directories: 4
2025/04/15 01:36:54 DEBUG : test/dir1: list: cached dir: 'tib21171744680984/test/dir1', cache ts: 2025-04-15 01:36:54.995876233 +0000 UTC m=+39.466293188
2025/04/15 01:36:54 NOTICE: len: 4
2025/04/15 01:36:54 DEBUG : Cache remote TestInternalCache:tib21171744680984: list 'test'
2025/04/15 01:36:54 DEBUG : test: list: error: missing cached dir: test
2025/04/15 01:36:54 DEBUG : test: list: read 4 from source
2025/04/15 01:36:54 DEBUG : test: list: source entries: [test/dir3 test/dir2 test/dir4 test/dir1]
2025/04/15 01:36:54 DEBUG : test: list: cached directories: 4
2025/04/15 01:36:55 DEBUG : test: list: cached dir: 'tib21171744680984/test', cache ts: 2025-04-15 01:36:54.998950665 +0000 UTC m=+39.469367621
2025/04/15 01:36:55 NOTICE: len: 4
2025/04/15 01:36:55 DEBUG : Waiting for deletions to finish
2025/04/15 01:36:55 DEBUG : Cache remote TestInternalCache:tib21171744680984: list ''
2025/04/15 01:36:55 DEBUG : : list: cold listing: 2025-04-12 01:36:24.98304861 +0000 UTC
2025/04/15 01:36:55 DEBUG : : list: read 1 from source
2025/04/15 01:36:55 DEBUG : : list: source entries: [test]
2025/04/15 01:36:55 DEBUG : : list: cached directories: 1
2025/04/15 01:36:55 DEBUG : : list: cached dir: 'tib21171744680984', cache ts: 2025-04-15 01:36:55.001738189 +0000 UTC m=+39.472155155
2025/04/15 01:36:55 DEBUG : Cache remote TestInternalCache:tib21171744680984: list 'test'
2025/04/15 01:36:55 DEBUG : test: list: warm 4 from cache for: tib21171744680984/test, expiring on: 2025-04-18 01:36:55.000507589 +0000 UTC
2025/04/15 01:36:55 DEBUG : test: list: cached entries: [test/dir1 test/dir2 test/dir3 test/dir4]
2025/04/15 01:36:55 DEBUG : Cache remote TestInternalCache:tib21171744680984: list 'test/dir4'
2025/04/15 01:36:55 DEBUG : Cache remote TestInternalCache:tib21171744680984: list 'test/dir1'
2025/04/15 01:36:55 DEBUG : Cache remote TestInternalCache:tib21171744680984: list 'test/dir2'
2025/04/15 01:36:55 DEBUG : test/dir2: list: empty listing
2025/04/15 01:36:55 DEBUG : test/dir1: list: warm 4 from cache for: tib21171744680984/test/dir1, expiring on: 2025-04-18 01:36:54.997493599 +0000 UTC
2025/04/15 01:36:55 DEBUG : test/dir1: list: cached entries: [test/dir1/dir1 test/dir1/dir2 test/dir1/dir3 test/dir1/dir4]
2025/04/15 01:36:55 DEBUG : Cache remote TestInternalCache:tib21171744680984: list 'test/dir1/dir4'
2025/04/15 01:36:55 DEBUG : test/dir1/dir4: list: empty listing
2025/04/15 01:36:55 DEBUG : test/dir1/dir4: list: read 1 from source
2025/04/15 01:36:55 DEBUG : test/dir1/dir4: list: source entries: [test/dir1/dir4/test.txt]
2025/04/15 01:36:55 DEBUG : test/dir2: list: read 4 from source
2025/04/15 01:36:55 DEBUG : test/dir2: list: source entries: [test/dir2/dir3 test/dir2/dir2 test/dir2/dir4 test/dir2/dir1]
2025/04/15 01:36:55 DEBUG : Cache remote TestInternalCache:tib21171744680984: list 'test/dir3'
2025/04/15 01:36:55 DEBUG : test/dir3: list: empty listing
2025/04/15 01:36:55 DEBUG : Cache remote TestInternalCache:tib21171744680984: list 'test/dir1/dir1'
2025/04/15 01:36:55 DEBUG : test/dir3: list: read 4 from source
2025/04/15 01:36:55 DEBUG : test/dir3: list: source entries: [test/dir3/dir3 test/dir3/dir2 test/dir3/dir4 test/dir3/dir1]
2025/04/15 01:36:55 DEBUG : test/dir1/dir1: list: empty listing
2025/04/15 01:36:55 DEBUG : test/dir4: list: empty listing
2025/04/15 01:36:55 DEBUG : test/dir1/dir1: list: read 1 from source
2025/04/15 01:36:55 DEBUG : test/dir1/dir1: list: source entries: [test/dir1/dir1/test.txt]
2025/04/15 01:36:55 DEBUG : test/dir4: list: read 4 from source
2025/04/15 01:36:55 DEBUG : test/dir4: list: source entries: [test/dir4/dir3 test/dir4/dir2 test/dir4/dir4 test/dir4/dir1]
2025/04/15 01:36:55 DEBUG : Cache remote TestInternalCache:tib21171744680984: list 'test/dir1/dir2'
2025/04/15 01:36:55 DEBUG : Cache remote TestInternalCache:tib21171744680984: list 'test/dir1/dir3'
2025/04/15 01:36:55 DEBUG : test/dir1/dir3: list: empty listing
2025/04/15 01:36:55 DEBUG : test/dir1/dir2: list: warm 1 from cache for: tib21171744680984/test/dir1/dir2, expiring on: 2025-04-18 01:36:54.994008496 +0000 UTC
2025/04/15 01:36:55 DEBUG : test/dir1/dir2: list: cached entries: [test/dir1/dir2/test.txt]
2025/04/15 01:36:55 DEBUG : test/dir1/dir3: list: read 1 from source
2025/04/15 01:36:55 DEBUG : test/dir1/dir3: list: source entries: [test/dir1/dir3/test.txt]
2025/04/15 01:36:55 DEBUG : test/dir1/dir4: list: cached object: test/dir1/dir4/test.txt
2025/04/15 01:36:55 DEBUG : test/dir1/dir4: list: cached directories: 0
2025/04/15 01:36:55 DEBUG : test/dir1/dir4: list: cached dir: 'tib21171744680984/test/dir1/dir4', cache ts: 2025-04-15 01:36:55.004644526 +0000 UTC m=+39.475061451
2025/04/15 01:36:55 DEBUG : test/dir1/dir4/test.txt: removing object
2025/04/15 01:36:55 DEBUG : test/dir2: list: cached directories: 4
2025/04/15 01:36:55 DEBUG : test/dir3: list: cached directories: 4
2025/04/15 01:36:55 DEBUG : test/dir1/dir1: list: cached object: test/dir1/dir1/test.txt
2025/04/15 01:36:55 DEBUG : test/dir1/dir1: list: cached directories: 0
2025/04/15 01:36:55 DEBUG : test/dir4: list: cached directories: 4
2025/04/15 01:36:55 DEBUG : test/dir1/dir2/test.txt: removing object
2025/04/15 01:36:55 DEBUG : test/dir1/dir3: list: cached object: test/dir1/dir3/test.txt
2025/04/15 01:36:55 DEBUG : test/dir1/dir3: list: cached directories: 0
2025/04/15 01:36:55 DEBUG : test/dir2: list: cached dir: 'tib21171744680984/test/dir2', cache ts: 2025-04-15 01:36:55.00672382 +0000 UTC m=+39.477140776
2025/04/15 01:36:55 DEBUG : Cache remote TestInternalCache:tib21171744680984: list 'test/dir2/dir4'
2025/04/15 01:36:55 DEBUG : test/dir2/dir4: list: empty listing
2025/04/15 01:36:55 DEBUG : test/dir2/dir4: list: read 1 from source
2025/04/15 01:36:55 DEBUG : test/dir2/dir4: list: source entries: [test/dir2/dir4/test.txt]
2025/04/15 01:36:55 DEBUG : Cache remote TestInternalCache:tib21171744680984: list 'test/dir2/dir1'
2025/04/15 01:36:55 DEBUG : test/dir2/dir1: list: empty listing
2025/04/15 01:36:55 DEBUG : test/dir2/dir1: list: read 1 from source
2025/04/15 01:36:55 DEBUG : test/dir2/dir1: list: source entries: [test/dir2/dir1/test.txt]
2025/04/15 01:36:55 DEBUG : Cache remote TestInternalCache:tib21171744680984: list 'test/dir2/dir2'
2025/04/15 01:36:55 DEBUG : test/dir2/dir2: list: empty listing
2025/04/15 01:36:55 DEBUG : test/dir2/dir2: list: read 1 from source
2025/04/15 01:36:55 DEBUG : test/dir2/dir2: list: source entries: [test/dir2/dir2/test.txt]
2025/04/15 01:36:55 DEBUG : Cache remote TestInternalCache:tib21171744680984: list 'test/dir2/dir3'
2025/04/15 01:36:55 DEBUG : test/dir2/dir3: list: empty listing
2025/04/15 01:36:55 DEBUG : test/dir2/dir3: list: read 1 from source
2025/04/15 01:36:55 DEBUG : test/dir2/dir3: list: source entries: [test/dir2/dir3/test.txt]
2025/04/15 01:36:55 DEBUG : test/dir3: list: cached dir: 'tib21171744680984/test/dir3', cache ts: 2025-04-15 01:36:55.007802636 +0000 UTC m=+39.478219591
2025/04/15 01:36:55 DEBUG : Cache remote TestInternalCache:tib21171744680984: list 'test/dir3/dir1'
2025/04/15 01:36:55 DEBUG : test/dir3/dir1: list: empty listing
2025/04/15 01:36:55 DEBUG : test/dir3/dir1: list: read 1 from source
2025/04/15 01:36:55 DEBUG : test/dir3/dir1: list: source entries: [test/dir3/dir1/test.txt]
2025/04/15 01:36:55 DEBUG : test/dir1/dir1: list: cached dir: 'tib21171744680984/test/dir1/dir1', cache ts: 2025-04-15 01:36:55.008718897 +0000 UTC m=+39.479135852
2025/04/15 01:36:55 DEBUG : Cache remote TestInternalCache:tib21171744680984: list 'test/dir3/dir2'
2025/04/15 01:36:55 DEBUG : test/dir3/dir2: list: empty listing
2025/04/15 01:36:55 DEBUG : test/dir3/dir2: list: read 1 from source
2025/04/15 01:36:55 DEBUG : test/dir3/dir2: list: source entries: [test/dir3/dir2/test.txt]
2025/04/15 01:36:55 DEBUG : test/dir1/dir1/test.txt: removing object
2025/04/15 01:36:55 DEBUG : test/dir4: list: cached dir: 'tib21171744680984/test/dir4', cache ts: 2025-04-15 01:36:55.009788685 +0000 UTC m=+39.480205710
2025/04/15 01:36:55 DEBUG : Cache remote TestInternalCache:tib21171744680984: list 'test/dir3/dir3'
2025/04/15 01:36:55 DEBUG : test/dir3/dir3: list: empty listing
2025/04/15 01:36:55 DEBUG : test/dir3/dir3: list: read 1 from source
2025/04/15 01:36:55 DEBUG : test/dir3/dir3: list: source entries: [test/dir3/dir3/test.txt]
2025/04/15 01:36:55 DEBUG : test/dir1/dir3: list: cached dir: 'tib21171744680984/test/dir1/dir3', cache ts: 2025-04-15 01:36:55.011905549 +0000 UTC m=+39.482322505
2025/04/15 01:36:55 DEBUG : Cache remote TestInternalCache:tib21171744680984: list 'test/dir3/dir4'
2025/04/15 01:36:55 DEBUG : test/dir3/dir4: list: empty listing
2025/04/15 01:36:55 DEBUG : test/dir3/dir4: list: read 1 from source
2025/04/15 01:36:55 DEBUG : test/dir3/dir4: list: source entries: [test/dir3/dir4/test.txt]
2025/04/15 01:36:55 DEBUG : test/dir1/dir3/test.txt: removing object
2025/04/15 01:36:55 DEBUG : test/dir2/dir4: list: cached object: test/dir2/dir4/test.txt
2025/04/15 01:36:55 DEBUG : test/dir2/dir4: list: cached directories: 0
2025/04/15 01:36:55 DEBUG : test/dir2/dir1: list: cached object: test/dir2/dir1/test.txt
2025/04/15 01:36:55 DEBUG : test/dir2/dir1: list: cached directories: 0
2025/04/15 01:36:55 DEBUG : test/dir2/dir2: list: cached object: test/dir2/dir2/test.txt
2025/04/15 01:36:55 DEBUG : test/dir2/dir2: list: cached directories: 0
2025/04/15 01:36:55 DEBUG : test/dir2/dir3: list: cached object: test/dir2/dir3/test.txt
2025/04/15 01:36:55 DEBUG : test/dir2/dir3: list: cached directories: 0
2025/04/15 01:36:55 DEBUG : test/dir3/dir1: list: cached object: test/dir3/dir1/test.txt
2025/04/15 01:36:55 DEBUG : test/dir3/dir1: list: cached directories: 0
2025/04/15 01:36:55 DEBUG : test/dir3/dir2: list: cached object: test/dir3/dir2/test.txt
2025/04/15 01:36:55 DEBUG : test/dir3/dir2: list: cached directories: 0
2025/04/15 01:36:55 DEBUG : test/dir3/dir3: list: cached object: test/dir3/dir3/test.txt
2025/04/15 01:36:55 DEBUG : test/dir3/dir3: list: cached directories: 0
2025/04/15 01:36:55 DEBUG : test/dir3/dir4: list: cached object: test/dir3/dir4/test.txt
2025/04/15 01:36:55 DEBUG : test/dir3/dir4: list: cached directories: 0
2025/04/15 01:36:55 DEBUG : test/dir1/dir4: cache: expired tib21171744680984/test/dir1/dir4
2025/04/15 01:36:55 DEBUG : test/dir1/dir4: cache: expired tib21171744680984/test/dir1
2025/04/15 01:36:55 DEBUG : test/dir1/dir4: cache: expired tib21171744680984/test
2025/04/15 01:36:55 DEBUG : test/dir1/dir4: cache: expired tib21171744680984
2025/04/15 01:36:55 INFO  : test/dir1/dir4/test.txt: Deleted
2025/04/15 01:36:55 DEBUG : test/dir2/dir4: list: cached dir: 'tib21171744680984/test/dir2/dir4', cache ts: 2025-04-15 01:36:55.023641625 +0000 UTC m=+39.494058590
2025/04/15 01:36:55 DEBUG : Cache remote TestInternalCache:tib21171744680984: list 'test/dir4/dir1'
2025/04/15 01:36:55 DEBUG : test/dir4/dir1: list: empty listing
2025/04/15 01:36:55 DEBUG : test/dir2/dir4/test.txt: removing object
2025/04/15 01:36:55 DEBUG : test/dir4/dir1: list: read 1 from source
2025/04/15 01:36:55 DEBUG : test/dir4/dir1: list: source entries: [test/dir4/dir1/test.txt]
2025/04/15 01:36:55 DEBUG : test/dir2/dir1: list: cached dir: 'tib21171744680984/test/dir2/dir1', cache ts: 2025-04-15 01:36:55.024810379 +0000 UTC m=+39.495227334
2025/04/15 01:36:55 DEBUG : Cache remote TestInternalCache:tib21171744680984: list 'test/dir4/dir2'
2025/04/15 01:36:55 DEBUG : test/dir2/dir1/test.txt: removing object
2025/04/15 01:36:55 DEBUG : test/dir4/dir2: list: empty listing
2025/04/15 01:36:55 DEBUG : test/dir4/dir2: list: read 1 from source
2025/04/15 01:36:55 DEBUG : test/dir4/dir2: list: source entries: [test/dir4/dir2/test.txt]
2025/04/15 01:36:55 DEBUG : test/dir2/dir2: list: cached dir: 'tib21171744680984/test/dir2/dir2', cache ts: 2025-04-15 01:36:55.025931264 +0000 UTC m=+39.496348219
2025/04/15 01:36:55 DEBUG : Cache remote TestInternalCache:tib21171744680984: list 'test/dir4/dir3'
2025/04/15 01:36:55 DEBUG : test/dir4/dir3: list: empty listing
2025/04/15 01:36:55 DEBUG : test/dir2/dir2/test.txt: removing object
2025/04/15 01:36:55 DEBUG : test/dir4/dir3: list: read 1 from source
2025/04/15 01:36:55 DEBUG : test/dir4/dir3: list: source entries: [test/dir4/dir3/test.txt]
2025/04/15 01:36:55 DEBUG : test/dir2/dir3: list: cached dir: 'tib21171744680984/test/dir2/dir3', cache ts: 2025-04-15 01:36:55.027152296 +0000 UTC m=+39.497569252
2025/04/15 01:36:55 DEBUG : Cache remote TestInternalCache:tib21171744680984: list 'test/dir4/dir4'
2025/04/15 01:36:55 DEBUG : test/dir4/dir4: list: empty listing
2025/04/15 01:36:55 DEBUG : test/dir2/dir3/test.txt: removing object
2025/04/15 01:36:55 DEBUG : test/dir4/dir4: list: read 1 from source
2025/04/15 01:36:55 DEBUG : test/dir4/dir4: list: source entries: [test/dir4/dir4/test.txt]
2025/04/15 01:36:55 DEBUG : test/dir3/dir1: list: cached dir: 'tib21171744680984/test/dir3/dir1', cache ts: 2025-04-15 01:36:55.028352871 +0000 UTC m=+39.498769826
2025/04/15 01:36:55 DEBUG : test/dir3/dir1/test.txt: removing object
2025/04/15 01:36:55 DEBUG : test/dir3/dir2: list: cached dir: 'tib21171744680984/test/dir3/dir2', cache ts: 2025-04-15 01:36:55.029542545 +0000 UTC m=+39.499959500
2025/04/15 01:36:55 DEBUG : test/dir3/dir3: list: cached dir: 'tib21171744680984/test/dir3/dir3', cache ts: 2025-04-15 01:36:55.034403442 +0000 UTC m=+39.504820396
2025/04/15 01:36:55 DEBUG : test/dir1/dir2: cache: expired tib21171744680984/test/dir1/dir2
2025/04/15 01:36:55 DEBUG : test/dir1/dir2: cache: expired tib21171744680984/test/dir1
2025/04/15 01:36:55 DEBUG : test/dir1/dir2: cache: expired tib21171744680984/test
2025/04/15 01:36:55 DEBUG : test/dir1/dir2: cache: expired tib21171744680984
2025/04/15 01:36:55 INFO  : test/dir1/dir2/test.txt: Deleted
2025/04/15 01:36:55 DEBUG : test/dir3/dir2/test.txt: removing object
2025/04/15 01:36:55 DEBUG : test/dir3/dir4: list: cached dir: 'tib21171744680984/test/dir3/dir4', cache ts: 2025-04-15 01:36:55.034419111 +0000 UTC m=+39.504836066
2025/04/15 01:36:55 DEBUG : test/dir4/dir1: list: cached object: test/dir4/dir1/test.txt
2025/04/15 01:36:55 DEBUG : test/dir4/dir1: list: cached directories: 0
2025/04/15 01:36:55 DEBUG : test/dir4/dir2: list: cached object: test/dir4/dir2/test.txt
2025/04/15 01:36:55 DEBUG : test/dir4/dir2: list: cached directories: 0
2025/04/15 01:36:55 DEBUG : test/dir4/dir3: list: cached object: test/dir4/dir3/test.txt
2025/04/15 01:36:55 DEBUG : test/dir4/dir3: list: cached directories: 0
2025/04/15 01:36:55 DEBUG : test/dir4/dir4: list: cached object: test/dir4/dir4/test.txt
2025/04/15 01:36:55 DEBUG : test/dir4/dir4: list: cached directories: 0
2025/04/15 01:36:55 DEBUG : test/dir4/dir1: list: cached dir: 'tib21171744680984/test/dir4/dir1', cache ts: 2025-04-15 01:36:55.061032098 +0000 UTC m=+39.531449044
2025/04/15 01:36:55 DEBUG : test/dir1/dir1: cache: expired tib21171744680984/test/dir1/dir1
2025/04/15 01:36:55 DEBUG : test/dir1/dir1: cache: expired tib21171744680984/test/dir1
2025/04/15 01:36:55 DEBUG : test/dir1/dir1: cache: expired tib21171744680984/test
2025/04/15 01:36:55 DEBUG : test/dir1/dir1: cache: expired tib21171744680984
2025/04/15 01:36:55 INFO  : test/dir1/dir1/test.txt: Deleted
2025/04/15 01:36:55 DEBUG : test/dir3/dir3/test.txt: removing object
2025/04/15 01:36:55 DEBUG : test/dir4/dir2: list: cached dir: 'tib21171744680984/test/dir4/dir2', cache ts: 2025-04-15 01:36:55.064374966 +0000 UTC m=+39.534791920
2025/04/15 01:36:55 DEBUG : test/dir4/dir3: list: cached dir: 'tib21171744680984/test/dir4/dir3', cache ts: 2025-04-15 01:36:55.068348907 +0000 UTC m=+39.538765862
2025/04/15 01:36:55 DEBUG : test/dir4/dir4: list: cached dir: 'tib21171744680984/test/dir4/dir4', cache ts: 2025-04-15 01:36:55.071511885 +0000 UTC m=+39.541928841
2025/04/15 01:36:55 DEBUG : test/dir1/dir3: cache: expired tib21171744680984/test/dir1/dir3
2025/04/15 01:36:55 DEBUG : test/dir1/dir3: cache: expired tib21171744680984/test/dir1
2025/04/15 01:36:55 DEBUG : test/dir1/dir3: cache: expired tib21171744680984/test
2025/04/15 01:36:55 DEBUG : test/dir1/dir3: cache: expired tib21171744680984
2025/04/15 01:36:55 INFO  : test/dir1/dir3/test.txt: Deleted
2025/04/15 01:36:55 DEBUG : test/dir3/dir4/test.txt: removing object
2025/04/15 01:36:55 DEBUG : test/dir2/dir4: cache: expired tib21171744680984/test/dir2/dir4
2025/04/15 01:36:55 DEBUG : test/dir2/dir4: cache: expired tib21171744680984/test/dir2
2025/04/15 01:36:55 DEBUG : test/dir2/dir4: cache: expired tib21171744680984/test
2025/04/15 01:36:55 DEBUG : test/dir2/dir4: cache: expired tib21171744680984
2025/04/15 01:36:55 INFO  : test/dir2/dir4/test.txt: Deleted
2025/04/15 01:36:55 DEBUG : test/dir4/dir1/test.txt: removing object
2025/04/15 01:36:55 DEBUG : test/dir2/dir1: cache: expired tib21171744680984/test/dir2/dir1
2025/04/15 01:36:55 DEBUG : test/dir2/dir1: cache: expired tib21171744680984/test/dir2
2025/04/15 01:36:55 DEBUG : test/dir2/dir1: cache: expired tib21171744680984/test
2025/04/15 01:36:55 DEBUG : test/dir2/dir1: cache: expired tib21171744680984
2025/04/15 01:36:55 INFO  : test/dir2/dir1/test.txt: Deleted
2025/04/15 01:36:55 DEBUG : test/dir4/dir2/test.txt: removing object
2025/04/15 01:36:55 DEBUG : test/dir2/dir2: cache: expired tib21171744680984/test/dir2/dir2
2025/04/15 01:36:55 DEBUG : test/dir2/dir2: cache: expired tib21171744680984/test/dir2
2025/04/15 01:36:55 DEBUG : test/dir2/dir2: cache: expired tib21171744680984/test
2025/04/15 01:36:55 DEBUG : test/dir2/dir2: cache: expired tib21171744680984
2025/04/15 01:36:55 INFO  : test/dir2/dir2/test.txt: Deleted
2025/04/15 01:36:55 DEBUG : test/dir4/dir3/test.txt: removing object
2025/04/15 01:36:55 DEBUG : test/dir2/dir3: cache: expired tib21171744680984/test/dir2/dir3
2025/04/15 01:36:55 DEBUG : test/dir2/dir3: cache: expired tib21171744680984/test/dir2
2025/04/15 01:36:55 DEBUG : test/dir2/dir3: cache: expired tib21171744680984/test
2025/04/15 01:36:55 DEBUG : test/dir2/dir3: cache: expired tib21171744680984
2025/04/15 01:36:55 INFO  : test/dir2/dir3/test.txt: Deleted
2025/04/15 01:36:55 DEBUG : test/dir4/dir4/test.txt: removing object
2025/04/15 01:36:55 DEBUG : test/dir3/dir1: cache: expired tib21171744680984/test/dir3/dir1
2025/04/15 01:36:55 DEBUG : test/dir3/dir1: cache: expired tib21171744680984/test/dir3
2025/04/15 01:36:55 DEBUG : test/dir3/dir1: cache: expired tib21171744680984/test
2025/04/15 01:36:55 DEBUG : test/dir3/dir1: cache: expired tib21171744680984
2025/04/15 01:36:55 INFO  : test/dir3/dir1/test.txt: Deleted
2025/04/15 01:36:55 DEBUG : test/dir3/dir2: cache: expired tib21171744680984/test/dir3/dir2
2025/04/15 01:36:55 DEBUG : test/dir3/dir2: cache: expired tib21171744680984/test/dir3
2025/04/15 01:36:55 DEBUG : test/dir3/dir2: cache: expired tib21171744680984/test
2025/04/15 01:36:55 DEBUG : test/dir3/dir2: cache: expired tib21171744680984
2025/04/15 01:36:55 INFO  : test/dir3/dir2/test.txt: Deleted
2025/04/15 01:36:55 DEBUG : test/dir4/dir4: cache: expired tib21171744680984/test/dir4/dir4
2025/04/15 01:36:55 DEBUG : test/dir4/dir4: cache: expired tib21171744680984/test/dir4
2025/04/15 01:36:55 DEBUG : test/dir4/dir4: cache: expired tib21171744680984/test
2025/04/15 01:36:55 DEBUG : test/dir4/dir4: cache: expired tib21171744680984
2025/04/15 01:36:55 DEBUG : test/dir3/dir3: cache: expired tib21171744680984/test/dir3/dir3
2025/04/15 01:36:55 DEBUG : test/dir3/dir3: cache: expired tib21171744680984/test/dir3
2025/04/15 01:36:55 DEBUG : test/dir3/dir3: cache: expired tib21171744680984/test
2025/04/15 01:36:55 DEBUG : test/dir3/dir3: cache: expired tib21171744680984
2025/04/15 01:36:55 INFO  : test/dir4/dir4/test.txt: Deleted
2025/04/15 01:36:55 INFO  : test/dir3/dir3/test.txt: Deleted
2025/04/15 01:36:55 DEBUG : test/dir4/dir1: cache: expired tib21171744680984/test/dir4/dir1
2025/04/15 01:36:55 DEBUG : test/dir4/dir1: cache: expired tib21171744680984/test/dir4
2025/04/15 01:36:55 DEBUG : test/dir4/dir1: cache: expired tib21171744680984/test
2025/04/15 01:36:55 DEBUG : test/dir4/dir1: cache: expired tib21171744680984
2025/04/15 01:36:55 INFO  : test/dir4/dir1/test.txt: Deleted
2025/04/15 01:36:55 DEBUG : test/dir3/dir4: cache: expired tib21171744680984/test/dir3/dir4
2025/04/15 01:36:55 DEBUG : test/dir3/dir4: cache: expired tib21171744680984/test/dir3
2025/04/15 01:36:55 DEBUG : test/dir3/dir4: cache: expired tib21171744680984/test
2025/04/15 01:36:55 DEBUG : test/dir3/dir4: cache: expired tib21171744680984
2025/04/15 01:36:55 INFO  : test/dir3/dir4/test.txt: Deleted
2025/04/15 01:36:55 DEBUG : test/dir4/dir2: cache: expired tib21171744680984/test/dir4/dir2
2025/04/15 01:36:55 DEBUG : test/dir4/dir2: cache: expired tib21171744680984/test/dir4
2025/04/15 01:36:55 DEBUG : test/dir4/dir2: cache: expired tib21171744680984/test
2025/04/15 01:36:55 DEBUG : test/dir4/dir2: cache: expired tib21171744680984
2025/04/15 01:36:55 INFO  : test/dir4/dir2/test.txt: Deleted
2025/04/15 01:36:55 DEBUG : test/dir4/dir3: cache: expired tib21171744680984/test/dir4/dir3
2025/04/15 01:36:55 DEBUG : test/dir4/dir3: cache: expired tib21171744680984/test/dir4
2025/04/15 01:36:55 DEBUG : test/dir4/dir3: cache: expired tib21171744680984/test
2025/04/15 01:36:55 DEBUG : test/dir4/dir3: cache: expired tib21171744680984
2025/04/15 01:36:55 INFO  : test/dir4/dir3/test.txt: Deleted
2025/04/15 01:36:55 DEBUG : Cache remote TestInternalCache:tib21171744680984: list ''
2025/04/15 01:36:55 DEBUG : : list: cold listing: 2025-04-12 01:36:55.121594992 +0000 UTC
2025/04/15 01:36:55 DEBUG : : list: read 1 from source
2025/04/15 01:36:55 DEBUG : : list: source entries: [test]
2025/04/15 01:36:55 DEBUG : : list: cached directories: 0
2025/04/15 01:36:55 DEBUG : : list: cached dir: 'tib21171744680984', cache ts: 2025-04-15 01:36:55.127919747 +0000 UTC m=+39.598336733
2025/04/15 01:36:55 DEBUG : Cache remote TestInternalCache:tib21171744680984: list 'test'
2025/04/15 01:36:55 DEBUG : test: list: cold listing: 2025-04-12 01:36:55.121594992 +0000 UTC
2025/04/15 01:36:55 DEBUG : test: list: read 4 from source
2025/04/15 01:36:55 DEBUG : test: list: source entries: [test/dir3 test/dir2 test/dir4 test/dir1]
2025/04/15 01:36:55 DEBUG : test: list: cached directories: 0
2025/04/15 01:36:55 DEBUG : test: list: cached dir: 'tib21171744680984/test', cache ts: 2025-04-15 01:36:55.130356332 +0000 UTC m=+39.600773296
2025/04/15 01:36:55 DEBUG : Cache remote TestInternalCache:tib21171744680984: list 'test/dir2'
2025/04/15 01:36:55 DEBUG : test/dir2: list: cold listing: 2025-04-12 01:36:55.104019322 +0000 UTC
2025/04/15 01:36:55 DEBUG : test/dir2: list: read 4 from source
2025/04/15 01:36:55 DEBUG : test/dir2: list: source entries: [test/dir2/dir3 test/dir2/dir2 test/dir2/dir4 test/dir2/dir1]
2025/04/15 01:36:55 DEBUG : test/dir2: list: cached directories: 0
2025/04/15 01:36:55 DEBUG : Cache remote TestInternalCache:tib21171744680984: list 'test/dir3'
2025/04/15 01:36:55 DEBUG : Cache remote TestInternalCache:tib21171744680984: list 'test/dir1'
2025/04/15 01:36:55 DEBUG : test/dir3: list: cold listing: 2025-04-12 01:36:55.118535247 +0000 UTC
2025/04/15 01:36:55 DEBUG : test/dir1: list: cold listing: 2025-04-12 01:36:55.078083774 +0000 UTC
2025/04/15 01:36:55 DEBUG : test/dir3: list: read 4 from source
2025/04/15 01:36:55 DEBUG : test/dir3: list: source entries: [test/dir3/dir3 test/dir3/dir2 test/dir3/dir4 test/dir3/dir1]
2025/04/15 01:36:55 DEBUG : test/dir3: list: cached directories: 0
2025/04/15 01:36:55 DEBUG : test/dir1: list: read 4 from source
2025/04/15 01:36:55 DEBUG : test/dir1: list: source entries: [test/dir1/dir3 test/dir1/dir2 test/dir1/dir4 test/dir1/dir1]
2025/04/15 01:36:55 DEBUG : test/dir1: list: cached directories: 0
2025/04/15 01:36:55 DEBUG : Cache remote TestInternalCache:tib21171744680984: list 'test/dir4'
2025/04/15 01:36:55 DEBUG : test/dir4: list: cold listing: 2025-04-12 01:36:55.121594992 +0000 UTC
2025/04/15 01:36:55 DEBUG : test/dir4: list: read 4 from source
2025/04/15 01:36:55 DEBUG : test/dir4: list: source entries: [test/dir4/dir3 test/dir4/dir2 test/dir4/dir4 test/dir4/dir1]
2025/04/15 01:36:55 DEBUG : test/dir2: list: cached dir: 'tib21171744680984/test/dir2', cache ts: 2025-04-15 01:36:55.131895031 +0000 UTC m=+39.602311987
2025/04/15 01:36:55 DEBUG : Cache remote TestInternalCache:tib21171744680984: list 'test/dir2/dir4'
2025/04/15 01:36:55 DEBUG : test/dir2/dir4: list: cold listing: 2025-04-12 01:36:55.091442387 +0000 UTC
2025/04/15 01:36:55 DEBUG : test/dir2/dir4: list: read 0 from source
2025/04/15 01:36:55 DEBUG : Cache remote TestInternalCache:tib21171744680984: list 'test/dir2/dir1'
2025/04/15 01:36:55 DEBUG : Cache remote TestInternalCache:tib21171744680984: list 'test/dir2/dir3'
2025/04/15 01:36:55 DEBUG : Cache remote TestInternalCache:tib21171744680984: list 'test/dir2/dir2'
2025/04/15 01:36:55 DEBUG : test/dir2/dir3: list: cold listing: 2025-04-12 01:36:55.104019322 +0000 UTC
2025/04/15 01:36:55 DEBUG : test/dir2/dir3: list: read 0 from source
2025/04/15 01:36:55 DEBUG : test/dir2/dir3: list: source entries: []
2025/04/15 01:36:55 DEBUG : test/dir2/dir1: list: cold listing: 2025-04-12 01:36:55.096106534 +0000 UTC
2025/04/15 01:36:55 DEBUG : test/dir2/dir3: list: cached directories: 0
2025/04/15 01:36:55 DEBUG : test/dir2/dir2: list: cold listing: 2025-04-12 01:36:55.100073803 +0000 UTC
2025/04/15 01:36:55 DEBUG : test/dir2/dir2: list: read 0 from source
2025/04/15 01:36:55 DEBUG : test/dir2/dir1: list: read 0 from source
2025/04/15 01:36:55 DEBUG : test/dir2/dir2: list: source entries: []
2025/04/15 01:36:55 DEBUG : test/dir2/dir1: list: source entries: []
2025/04/15 01:36:55 DEBUG : test/dir2/dir2: list: cached directories: 0
2025/04/15 01:36:55 DEBUG : test/dir2/dir1: list: cached directories: 0
2025/04/15 01:36:55 DEBUG : test/dir2/dir4: list: source entries: []
2025/04/15 01:36:55 DEBUG : test/dir2/dir4: list: cached directories: 0
2025/04/15 01:36:55 DEBUG : test/dir4: list: cached directories: 0
2025/04/15 01:36:55 DEBUG : test/dir2/dir3: list: cached dir: 'tib21171744680984/test/dir2/dir3', cache ts: 2025-04-15 01:36:55.133392283 +0000 UTC m=+39.603809208
2025/04/15 01:36:55 DEBUG : test/dir2/dir1: list: cached dir: 'tib21171744680984/test/dir2/dir1', cache ts: 2025-04-15 01:36:55.133456974 +0000 UTC m=+39.603873939
2025/04/15 01:36:55 DEBUG : test/dir1: list: cached dir: 'tib21171744680984/test/dir1', cache ts: 2025-04-15 01:36:55.132582352 +0000 UTC m=+39.602999306
2025/04/15 01:36:55 DEBUG : Cache remote TestInternalCache:tib21171744680984: list 'test/dir1/dir4'
2025/04/15 01:36:55 DEBUG : test/dir1/dir4: list: cold listing: 2025-04-12 01:36:55.022356622 +0000 UTC
2025/04/15 01:36:55 DEBUG : test/dir1/dir4: list: read 0 from source
2025/04/15 01:36:55 DEBUG : test/dir1/dir4: list: source entries: []
2025/04/15 01:36:55 DEBUG : test/dir1/dir4: list: cached directories: 0
2025/04/15 01:36:55 DEBUG : Cache remote TestInternalCache:tib21171744680984: list 'test/dir1/dir2'
2025/04/15 01:36:55 DEBUG : Cache remote TestInternalCache:tib21171744680984: list 'test/dir1/dir3'
2025/04/15 01:36:55 DEBUG : test/dir1/dir2: list: cold listing: 2025-04-12 01:36:55.037478545 +0000 UTC
2025/04/15 01:36:55 DEBUG : test/dir1/dir3: list: cold listing: 2025-04-12 01:36:55.078083774 +0000 UTC
2025/04/15 01:36:55 DEBUG : test/dir1/dir3: list: read 0 from source
2025/04/15 01:36:55 DEBUG : test/dir1/dir3: list: source entries: []
2025/04/15 01:36:55 DEBUG : test/dir1/dir3: list: cached directories: 0
2025/04/15 01:36:55 DEBUG : test/dir1/dir2: list: read 0 from source
2025/04/15 01:36:55 DEBUG : test/dir1/dir2: list: source entries: []
2025/04/15 01:36:55 DEBUG : test/dir1/dir2: list: cached directories: 0
2025/04/15 01:36:55 DEBUG : Cache remote TestInternalCache:tib21171744680984: list 'test/dir1/dir1'
2025/04/15 01:36:55 DEBUG : test/dir1/dir1: list: cold listing: 2025-04-12 01:36:55.061039242 +0000 UTC
2025/04/15 01:36:55 DEBUG : test/dir1/dir1: list: read 0 from source
2025/04/15 01:36:55 DEBUG : test/dir1/dir1: list: source entries: []
2025/04/15 01:36:55 DEBUG : test/dir1/dir1: list: cached directories: 0
2025/04/15 01:36:55 DEBUG : test/dir1/dir4: list: cached dir: 'tib21171744680984/test/dir1/dir4', cache ts: 2025-04-15 01:36:55.136939592 +0000 UTC m=+39.607356517
2025/04/15 01:36:55 DEBUG : test/dir2/dir2: list: cached dir: 'tib21171744680984/test/dir2/dir2', cache ts: 2025-04-15 01:36:55.133454339 +0000 UTC m=+39.603871294
2025/04/15 01:36:55 DEBUG : test/dir3: list: cached dir: 'tib21171744680984/test/dir3', cache ts: 2025-04-15 01:36:55.132433452 +0000 UTC m=+39.602850407
2025/04/15 01:36:55 DEBUG : Cache remote TestInternalCache:tib21171744680984: list 'test/dir3/dir3'
2025/04/15 01:36:55 DEBUG : Cache remote TestInternalCache:tib21171744680984: list 'test/dir3/dir1'
2025/04/15 01:36:55 DEBUG : Cache remote TestInternalCache:tib21171744680984: list 'test/dir3/dir2'
2025/04/15 01:36:55 DEBUG : test/dir3/dir3: list: cold listing: 2025-04-12 01:36:55.113830182 +0000 UTC
2025/04/15 01:36:55 DEBUG : test/dir3/dir1: list: cold listing: 2025-04-12 01:36:55.108610832 +0000 UTC
2025/04/15 01:36:55 DEBUG : test/dir3/dir3: list: read 0 from source
2025/04/15 01:36:55 DEBUG : test/dir3/dir3: list: source entries: []
2025/04/15 01:36:55 DEBUG : test/dir3/dir3: list: cached directories: 0
2025/04/15 01:36:55 DEBUG : test/dir3/dir1: list: read 0 from source
2025/04/15 01:36:55 DEBUG : test/dir3/dir1: list: source entries: []
2025/04/15 01:36:55 DEBUG : test/dir3/dir1: list: cached directories: 0
2025/04/15 01:36:55 DEBUG : test/dir3/dir2: list: cold listing: 2025-04-12 01:36:55.110589999 +0000 UTC
2025/04/15 01:36:55 DEBUG : test/dir3/dir2: list: read 0 from source
2025/04/15 01:36:55 DEBUG : test/dir3/dir2: list: source entries: []
2025/04/15 01:36:55 DEBUG : test/dir3/dir2: list: cached directories: 0
2025/04/15 01:36:55 DEBUG : test/dir4: list: cached dir: 'tib21171744680984/test/dir4', cache ts: 2025-04-15 01:36:55.133555399 +0000 UTC m=+39.603972353
2025/04/15 01:36:55 DEBUG : Cache remote TestInternalCache:tib21171744680984: list 'test/dir3/dir4'
2025/04/15 01:36:55 DEBUG : test/dir3/dir4: list: cold listing: 2025-04-12 01:36:55.118535247 +0000 UTC
2025/04/15 01:36:55 DEBUG : test/dir3/dir4: list: read 0 from source
2025/04/15 01:36:55 DEBUG : test/dir3/dir4: list: source entries: []
2025/04/15 01:36:55 DEBUG : test/dir3/dir4: list: cached directories: 0
2025/04/15 01:36:55 DEBUG : test/dir2/dir4: list: cached dir: 'tib21171744680984/test/dir2/dir4', cache ts: 2025-04-15 01:36:55.133467203 +0000 UTC m=+39.603884158
2025/04/15 01:36:55 DEBUG : Cache remote TestInternalCache:tib21171744680984: list 'test/dir4/dir1'
2025/04/15 01:36:55 DEBUG : test/dir4/dir1: list: cold listing: 2025-04-12 01:36:55.115070691 +0000 UTC
2025/04/15 01:36:55 DEBUG : test/dir4/dir1: list: read 0 from source
2025/04/15 01:36:55 DEBUG : test/dir4/dir1: list: source entries: []
2025/04/15 01:36:55 DEBUG : test/dir4/dir1: list: cached directories: 0
2025/04/15 01:36:55 DEBUG : test/dir1/dir3: list: cached dir: 'tib21171744680984/test/dir1/dir3', cache ts: 2025-04-15 01:36:55.13716699 +0000 UTC m=+39.607583944
2025/04/15 01:36:55 DEBUG : Cache remote TestInternalCache:tib21171744680984: list 'test/dir4/dir2'
2025/04/15 01:36:55 DEBUG : test/dir4/dir2: list: cold listing: 2025-04-12 01:36:55.12070474 +0000 UTC
2025/04/15 01:36:55 DEBUG : test/dir4/dir2: list: read 0 from source
2025/04/15 01:36:55 DEBUG : test/dir4/dir2: list: source entries: []
2025/04/15 01:36:55 DEBUG : test/dir4/dir2: list: cached directories: 0
2025/04/15 01:36:55 DEBUG : test/dir1/dir2: list: cached dir: 'tib21171744680984/test/dir1/dir2', cache ts: 2025-04-15 01:36:55.13718826 +0000 UTC m=+39.607605214
2025/04/15 01:36:55 DEBUG : Cache remote TestInternalCache:tib21171744680984: list 'test/dir4/dir3'
2025/04/15 01:36:55 DEBUG : test/dir4/dir3: list: cold listing: 2025-04-12 01:36:55.121594992 +0000 UTC
2025/04/15 01:36:55 DEBUG : test/dir4/dir3: list: read 0 from source
2025/04/15 01:36:55 DEBUG : test/dir4/dir3: list: source entries: []
2025/04/15 01:36:55 DEBUG : test/dir4/dir3: list: cached directories: 0
2025/04/15 01:36:55 DEBUG : test/dir1/dir1: list: cached dir: 'tib21171744680984/test/dir1/dir1', cache ts: 2025-04-15 01:36:55.137300931 +0000 UTC m=+39.607717896
2025/04/15 01:36:55 DEBUG : Cache remote TestInternalCache:tib21171744680984: list 'test/dir4/dir4'
2025/04/15 01:36:55 DEBUG : test/dir4/dir4: list: cold listing: 2025-04-12 01:36:55.112668561 +0000 UTC
2025/04/15 01:36:55 DEBUG : test/dir4/dir4: list: read 0 from source
2025/04/15 01:36:55 DEBUG : test/dir4/dir4: list: source entries: []
2025/04/15 01:36:55 DEBUG : test/dir4/dir4: list: cached directories: 0
2025/04/15 01:36:55 DEBUG : test/dir3/dir3: list: cached dir: 'tib21171744680984/test/dir3/dir3', cache ts: 2025-04-15 01:36:55.140608221 +0000 UTC m=+39.611025176
2025/04/15 01:36:55 DEBUG : test/dir3/dir1: list: cached dir: 'tib21171744680984/test/dir3/dir1', cache ts: 2025-04-15 01:36:55.140663645 +0000 UTC m=+39.611080610
2025/04/15 01:36:55 DEBUG : test/dir3/dir2: list: cached dir: 'tib21171744680984/test/dir3/dir2', cache ts: 2025-04-15 01:36:55.140731582 +0000 UTC m=+39.611148548
2025/04/15 01:36:55 DEBUG : test/dir3/dir4: list: cached dir: 'tib21171744680984/test/dir3/dir4', cache ts: 2025-04-15 01:36:55.143144743 +0000 UTC m=+39.613561669
2025/04/15 01:36:55 DEBUG : test/dir4/dir1: list: cached dir: 'tib21171744680984/test/dir4/dir1', cache ts: 2025-04-15 01:36:55.143851791 +0000 UTC m=+39.614268746
2025/04/15 01:36:55 DEBUG : test/dir4/dir2: list: cached dir: 'tib21171744680984/test/dir4/dir2', cache ts: 2025-04-15 01:36:55.144049743 +0000 UTC m=+39.614466668
2025/04/15 01:36:55 DEBUG : test/dir4/dir3: list: cached dir: 'tib21171744680984/test/dir4/dir3', cache ts: 2025-04-15 01:36:55.145274301 +0000 UTC m=+39.615691227
2025/04/15 01:36:55 DEBUG : test/dir4/dir4: list: cached dir: 'tib21171744680984/test/dir4/dir4', cache ts: 2025-04-15 01:36:55.146354119 +0000 UTC m=+39.616771034
2025/04/15 01:36:55 DEBUG : removing 16 level 3 directories
2025/04/15 01:36:55 INFO  : test/dir2/dir4: Removing directory
2025/04/15 01:36:55 DEBUG : Cache remote TestInternalCache:tib21171744680984: rmdir 'test/dir2/dir4'
2025/04/15 01:36:55 DEBUG : test/dir2/dir4: rmdir: removed dir in source fs
2025/04/15 01:36:55 INFO  : test/dir1/dir4: Removing directory
2025/04/15 01:36:55 DEBUG : Cache remote TestInternalCache:tib21171744680984: rmdir 'test/dir1/dir4'
2025/04/15 01:36:55 DEBUG : test/dir1/dir4: rmdir: removed dir in source fs
2025/04/15 01:36:55 INFO  : test/dir1/dir2: Removing directory
2025/04/15 01:36:55 INFO  : test/dir1/dir1: Removing directory
2025/04/15 01:36:55 INFO  : test/dir1/dir3: Removing directory
2025/04/15 01:36:55 DEBUG : Cache remote TestInternalCache:tib21171744680984: rmdir 'test/dir1/dir1'
2025/04/15 01:36:55 DEBUG : Cache remote TestInternalCache:tib21171744680984: rmdir 'test/dir1/dir3'
2025/04/15 01:36:55 DEBUG : test/dir1/dir1: rmdir: removed dir in source fs
2025/04/15 01:36:55 INFO  : test/dir2/dir1: Removing directory
2025/04/15 01:36:55 INFO  : test/dir2/dir3: Removing directory
2025/04/15 01:36:55 DEBUG : Cache remote TestInternalCache:tib21171744680984: rmdir 'test/dir2/dir1'
2025/04/15 01:36:55 DEBUG : Cache remote TestInternalCache:tib21171744680984: rmdir 'test/dir2/dir3'
2025/04/15 01:36:55 DEBUG : test/dir2/dir1: rmdir: removed dir in source fs
2025/04/15 01:36:55 INFO  : test/dir2/dir2: Removing directory
2025/04/15 01:36:55 DEBUG : Cache remote TestInternalCache:tib21171744680984: rmdir 'test/dir2/dir2'
2025/04/15 01:36:55 DEBUG : test/dir1/dir3: rmdir: removed dir in source fs
2025/04/15 01:36:55 DEBUG : Cache remote TestInternalCache:tib21171744680984: rmdir 'test/dir1/dir2'
2025/04/15 01:36:55 DEBUG : test/dir2/dir3: rmdir: removed dir in source fs
2025/04/15 01:36:55 DEBUG : test/dir2/dir2: rmdir: removed dir in source fs
2025/04/15 01:36:55 DEBUG : test/dir1/dir2: rmdir: removed dir in source fs
2025/04/15 01:36:55 DEBUG : test/dir2/dir4: rmdir: removed from cache
2025/04/15 01:36:55 DEBUG : test/dir2: cache: expired tib21171744680984/test/dir2
2025/04/15 01:36:55 DEBUG : test/dir2: cache: expired tib21171744680984/test
2025/04/15 01:36:55 DEBUG : test/dir2: cache: expired tib21171744680984
2025/04/15 01:36:55 INFO  : test/dir2: rmdir: cache expired
2025/04/15 01:36:55 INFO  : test/dir3/dir1: Removing directory
2025/04/15 01:36:55 DEBUG : Cache remote TestInternalCache:tib21171744680984: rmdir 'test/dir3/dir1'
2025/04/15 01:36:55 DEBUG : test/dir3/dir1: rmdir: removed dir in source fs
2025/04/15 01:36:55 DEBUG : test/dir1/dir4: rmdir: removed from cache
2025/04/15 01:36:55 DEBUG : test/dir1/dir1: rmdir: removed from cache
2025/04/15 01:36:55 DEBUG : test/dir2/dir1: rmdir: removed from cache
2025/04/15 01:36:55 DEBUG : test/dir1/dir3: rmdir: removed from cache
2025/04/15 01:36:55 DEBUG : test/dir2/dir3: rmdir: removed from cache
2025/04/15 01:36:55 DEBUG : test/dir2/dir2: rmdir: removed from cache
2025/04/15 01:36:55 DEBUG : test/dir1/dir2: rmdir: removed from cache
2025/04/15 01:36:55 DEBUG : test/dir1: cache: expired tib21171744680984/test/dir1
2025/04/15 01:36:55 DEBUG : test/dir1: cache: expired tib21171744680984/test
2025/04/15 01:36:55 DEBUG : test/dir3/dir1: rmdir: removed from cache
2025/04/15 01:36:55 DEBUG : test/dir1: cache: expired tib21171744680984
2025/04/15 01:36:55 DEBUG : test/dir1: cache: expired tib21171744680984/test/dir1
2025/04/15 01:36:55 DEBUG : test/dir1: cache: expired tib21171744680984/test
2025/04/15 01:36:55 INFO  : test/dir1: rmdir: cache expired
2025/04/15 01:36:55 DEBUG : test/dir1: cache: expired tib21171744680984
2025/04/15 01:36:55 INFO  : test/dir3/dir2: Removing directory
2025/04/15 01:36:55 DEBUG : Cache remote TestInternalCache:tib21171744680984: rmdir 'test/dir3/dir2'
2025/04/15 01:36:55 DEBUG : test/dir3/dir2: rmdir: removed dir in source fs
2025/04/15 01:36:55 DEBUG : test/dir2: cache: expired tib21171744680984/test/dir2
2025/04/15 01:36:55 INFO  : test/dir1: rmdir: cache expired
2025/04/15 01:36:55 DEBUG : test/dir2: cache: expired tib21171744680984/test
2025/04/15 01:36:55 DEBUG : test/dir2: cache: expired tib21171744680984
2025/04/15 01:36:55 INFO  : test/dir3/dir3: Removing directory
2025/04/15 01:36:55 DEBUG : Cache remote TestInternalCache:tib21171744680984: rmdir 'test/dir3/dir3'
2025/04/15 01:36:55 DEBUG : test/dir3/dir3: rmdir: removed dir in source fs
2025/04/15 01:36:55 DEBUG : test/dir1: cache: expired tib21171744680984/test/dir1
2025/04/15 01:36:55 DEBUG : test/dir1: cache: expired tib21171744680984/test
2025/04/15 01:36:55 DEBUG : test/dir1: cache: expired tib21171744680984
2025/04/15 01:36:55 INFO  : test/dir2: rmdir: cache expired
2025/04/15 01:36:55 INFO  : test/dir3/dir4: Removing directory
2025/04/15 01:36:55 DEBUG : Cache remote TestInternalCache:tib21171744680984: rmdir 'test/dir3/dir4'
2025/04/15 01:36:55 DEBUG : test/dir3/dir4: rmdir: removed dir in source fs
2025/04/15 01:36:55 DEBUG : test/dir2: cache: expired tib21171744680984/test/dir2
2025/04/15 01:36:55 INFO  : test/dir1: rmdir: cache expired
2025/04/15 01:36:55 DEBUG : test/dir2: cache: expired tib21171744680984/test
2025/04/15 01:36:55 INFO  : test/dir4/dir1: Removing directory
2025/04/15 01:36:55 DEBUG : Cache remote TestInternalCache:tib21171744680984: rmdir 'test/dir4/dir1'
2025/04/15 01:36:55 DEBUG : test/dir2: cache: expired tib21171744680984
2025/04/15 01:36:55 DEBUG : test/dir4/dir1: rmdir: removed dir in source fs
2025/04/15 01:36:55 INFO  : test/dir2: rmdir: cache expired
2025/04/15 01:36:55 DEBUG : test/dir2: cache: expired tib21171744680984/test/dir2
2025/04/15 01:36:55 INFO  : test/dir4/dir2: Removing directory
2025/04/15 01:36:55 DEBUG : test/dir2: cache: expired tib21171744680984/test
2025/04/15 01:36:55 DEBUG : Cache remote TestInternalCache:tib21171744680984: rmdir 'test/dir4/dir2'
2025/04/15 01:36:55 DEBUG : test/dir2: cache: expired tib21171744680984
2025/04/15 01:36:55 DEBUG : test/dir4/dir2: rmdir: removed dir in source fs
2025/04/15 01:36:55 DEBUG : test/dir1: cache: expired tib21171744680984/test/dir1
2025/04/15 01:36:55 INFO  : test/dir2: rmdir: cache expired
2025/04/15 01:36:55 INFO  : test/dir4/dir3: Removing directory
2025/04/15 01:36:55 DEBUG : test/dir1: cache: expired tib21171744680984/test
2025/04/15 01:36:55 DEBUG : Cache remote TestInternalCache:tib21171744680984: rmdir 'test/dir4/dir3'
2025/04/15 01:36:55 DEBUG : test/dir1: cache: expired tib21171744680984
2025/04/15 01:36:55 DEBUG : test/dir4/dir3: rmdir: removed dir in source fs
2025/04/15 01:36:55 INFO  : test/dir1: rmdir: cache expired
2025/04/15 01:36:55 DEBUG : test/dir3: cache: expired tib21171744680984/test/dir3
2025/04/15 01:36:55 INFO  : test/dir4/dir4: Removing directory
2025/04/15 01:36:55 DEBUG : test/dir3: cache: expired tib21171744680984/test
2025/04/15 01:36:55 DEBUG : Cache remote TestInternalCache:tib21171744680984: rmdir 'test/dir4/dir4'
2025/04/15 01:36:55 DEBUG : test/dir3: cache: expired tib21171744680984
2025/04/15 01:36:55 DEBUG : test/dir4/dir4: rmdir: removed dir in source fs
2025/04/15 01:36:55 INFO  : test/dir3: rmdir: cache expired
2025/04/15 01:36:55 DEBUG : test/dir3/dir2: rmdir: removed from cache
2025/04/15 01:36:55 DEBUG : test/dir3/dir3: rmdir: removed from cache
2025/04/15 01:36:55 DEBUG : test/dir3/dir4: rmdir: removed from cache
2025/04/15 01:36:55 DEBUG : test/dir4/dir1: rmdir: removed from cache
2025/04/15 01:36:55 DEBUG : test/dir4/dir2: rmdir: removed from cache
2025/04/15 01:36:55 DEBUG : test/dir4/dir3: rmdir: removed from cache
2025/04/15 01:36:55 DEBUG : test/dir3: cache: expired tib21171744680984/test/dir3
2025/04/15 01:36:55 DEBUG : test/dir4/dir4: rmdir: removed from cache
2025/04/15 01:36:55 DEBUG : test/dir3: cache: expired tib21171744680984/test
2025/04/15 01:36:55 DEBUG : test/dir3: cache: expired tib21171744680984
2025/04/15 01:36:55 DEBUG : test/dir3: cache: expired tib21171744680984/test/dir3
2025/04/15 01:36:55 DEBUG : test/dir3: cache: expired tib21171744680984/test
2025/04/15 01:36:55 DEBUG : test/dir3: cache: expired tib21171744680984
2025/04/15 01:36:55 INFO  : test/dir3: rmdir: cache expired
2025/04/15 01:36:55 DEBUG : test/dir3: cache: expired tib21171744680984/test/dir3
2025/04/15 01:36:55 DEBUG : test/dir3: cache: expired tib21171744680984/test
2025/04/15 01:36:55 INFO  : test/dir3: rmdir: cache expired
2025/04/15 01:36:55 DEBUG : test/dir3: cache: expired tib21171744680984
2025/04/15 01:36:55 INFO  : test/dir3: rmdir: cache expired
2025/04/15 01:36:55 DEBUG : test/dir4: cache: expired tib21171744680984/test/dir4
2025/04/15 01:36:55 DEBUG : test/dir4: cache: expired tib21171744680984/test
2025/04/15 01:36:55 DEBUG : test/dir4: cache: expired tib21171744680984
2025/04/15 01:36:55 DEBUG : test/dir4: cache: expired tib21171744680984/test/dir4
2025/04/15 01:36:55 DEBUG : test/dir4: cache: expired tib21171744680984/test
2025/04/15 01:36:55 INFO  : test/dir4: rmdir: cache expired
2025/04/15 01:36:55 DEBUG : test/dir4: cache: expired tib21171744680984
2025/04/15 01:36:55 INFO  : test/dir4: rmdir: cache expired
2025/04/15 01:36:55 DEBUG : test/dir4: cache: expired tib21171744680984/test/dir4
2025/04/15 01:36:55 DEBUG : test/dir4: cache: expired tib21171744680984/test
2025/04/15 01:36:55 DEBUG : test/dir4: cache: expired tib21171744680984
2025/04/15 01:36:55 DEBUG : test/dir4: cache: expired tib21171744680984/test/dir4
2025/04/15 01:36:55 DEBUG : test/dir4: cache: expired tib21171744680984/test
2025/04/15 01:36:55 INFO  : test/dir4: rmdir: cache expired
2025/04/15 01:36:55 DEBUG : test/dir4: cache: expired tib21171744680984
2025/04/15 01:36:55 INFO  : test/dir4: rmdir: cache expired
2025/04/15 01:36:55 DEBUG : removing 4 level 2 directories
2025/04/15 01:36:55 INFO  : test/dir2: Removing directory
2025/04/15 01:36:55 DEBUG : Cache remote TestInternalCache:tib21171744680984: rmdir 'test/dir2'
2025/04/15 01:36:55 INFO  : test/dir1: Removing directory
2025/04/15 01:36:55 DEBUG : Cache remote TestInternalCache:tib21171744680984: rmdir 'test/dir1'
2025/04/15 01:36:55 DEBUG : test/dir2: rmdir: removed dir in source fs
2025/04/15 01:36:55 INFO  : test/dir4: Removing directory
2025/04/15 01:36:55 DEBUG : Cache remote TestInternalCache:tib21171744680984: rmdir 'test/dir4'
2025/04/15 01:36:55 INFO  : test/dir3: Removing directory
2025/04/15 01:36:55 DEBUG : test/dir4: rmdir: removed dir in source fs
2025/04/15 01:36:55 DEBUG : Cache remote TestInternalCache:tib21171744680984: rmdir 'test/dir3'
2025/04/15 01:36:55 DEBUG : test/dir1: rmdir: removed dir in source fs
2025/04/15 01:36:55 DEBUG : test/dir3: rmdir: removed dir in source fs
2025/04/15 01:36:55 DEBUG : test/dir2: rmdir: removed from cache
2025/04/15 01:36:55 DEBUG : test: cache: expired tib21171744680984/test
2025/04/15 01:36:55 DEBUG : test: cache: expired tib21171744680984
2025/04/15 01:36:55 INFO  : test: rmdir: cache expired
2025/04/15 01:36:55 DEBUG : test/dir4: rmdir: removed from cache
2025/04/15 01:36:55 DEBUG : test: cache: expired tib21171744680984/test
2025/04/15 01:36:55 DEBUG : test: cache: expired tib21171744680984
2025/04/15 01:36:55 INFO  : test: rmdir: cache expired
2025/04/15 01:36:55 DEBUG : test/dir1: rmdir: removed from cache
2025/04/15 01:36:55 DEBUG : test/dir3: rmdir: removed from cache
2025/04/15 01:36:55 DEBUG : test: cache: expired tib21171744680984/test
2025/04/15 01:36:55 DEBUG : test: cache: expired tib21171744680984
2025/04/15 01:36:55 INFO  : test: rmdir: cache expired
2025/04/15 01:36:55 DEBUG : test: cache: expired tib21171744680984/test
2025/04/15 01:36:55 DEBUG : test: cache: expired tib21171744680984
2025/04/15 01:36:55 INFO  : test: rmdir: cache expired
2025/04/15 01:36:55 DEBUG : removing 1 level 1 directories
2025/04/15 01:36:55 INFO  : test: Removing directory
2025/04/15 01:36:55 DEBUG : Cache remote TestInternalCache:tib21171744680984: rmdir 'test'
2025/04/15 01:36:55 DEBUG : test: rmdir: removed dir in source fs
2025/04/15 01:36:55 DEBUG : test: rmdir: removed from cache
2025/04/15 01:36:55 DEBUG : : cache: expired tib21171744680984
2025/04/15 01:36:55 INFO  : : rmdir: cache expired
2025/04/15 01:36:55 DEBUG : removing 1 level 0 directories
2025/04/15 01:36:55 INFO  : Cache remote TestInternalCache:tib21171744680984: Removing directory
2025/04/15 01:36:55 DEBUG : Cache remote TestInternalCache:tib21171744680984: rmdir ''
2025/04/15 01:36:55 DEBUG : : rmdir: removed dir in source fs
2025/04/15 01:36:55 DEBUG : : rmdir: removed from cache
2025/04/15 01:36:55 INFO  : : rmdir: cache expired
2025/04/15 01:36:55 DEBUG : Cache remote TestInternalCache:tib21171744680984: Services stopped
--- PASS: TestInternalBug2117 (30.25s)
=== RUN   TestIntegration
    fstests.go:438: Using remote "TestCache:"
2025/04/15 01:36:55 DEBUG : Creating backend with remote "TestCache:rclone-test-safemem9vejo"
2025/04/15 01:36:55 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2025/04/15 01:36:55 DEBUG : Setting cache db_wait_time="30m" from environment variable RCLONE_CACHE_DB_WAIT_TIME
2025/04/15 01:36:55 DEBUG : TestCache: detected overridden config - adding "{VDL3R}" suffix to name
2025/04/15 01:36:55 DEBUG : Setting cache db_wait_time="30m" from environment variable RCLONE_CACHE_DB_WAIT_TIME
2025/04/15 01:36:55 DEBUG : Creating backend with remote "/tmp/rclone_cache_test/rclone-test-safemem9vejo"
2025/04/15 01:36:55 DEBUG : TestCache{VDL3R}: wrapped local:/tmp/rclone_cache_test/rclone-test-safemem9vejo at root rclone-test-safemem9vejo
2025/04/15 01:36:55 INFO  : TestCache{VDL3R}: Cache DB path: /home/rclone/.cache/rclone/cache-backend/TestCache{VDL3R}.db
2025/04/15 01:36:55 INFO  : TestCache{VDL3R}: Cache chunk path: /home/rclone/.cache/rclone/cache-backend/TestCache{VDL3R}
2025/04/15 01:37:15 INFO  : Cache remote TestInternalCache:tionf1744680975: stopping cleanup
2025/04/15 01:37:15 INFO  : Cache remote TestInternalCache:ticwcm1744680975: stopping cleanup
2025/04/15 01:37:16 INFO  : Cache remote TestInternalCache:tidwcm1744680976: stopping cleanup
2025/04/15 01:37:17 INFO  : Cache remote TestInternalCache:ticucm1744680977: stopping cleanup
2025/04/15 01:37:17 INFO  : Cache remote TestInternalCache:tiwfcns1744680977: stopping cleanup
2025/04/15 01:37:18 INFO  : Cache remote TestInternalCache:timwn1744680978: stopping cleanup
2025/04/15 01:37:18 INFO  : Cache remote TestInternalCache:tincep1744680978: stopping cleanup
2025/04/15 01:37:18 INFO  : Cache remote TestInternalCache:ticsadcf1744680978: stopping cleanup
2025/04/15 01:37:18 INFO  : Cache remote TestInternalCache:ticw: stopping cleanup
2025/04/15 01:37:19 INFO  : Cache remote TestInternalCache:timcsr1744680979: stopping cleanup
2025/04/15 01:51:24 INFO  : Cache remote TestInternalCache:tib21171744680984: stopping cleanup
2025/04/15 02:06:55 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/04/15 02:06:55 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2025/04/15 02:06:55 DEBUG : Creating backend with remote "TestInternalCache-local:/tmp/TestInternalCache-local/tiutdc1744682815"
2025/04/15 02:06:55 DEBUG : TestInternalCache: wrapped TestInternalCache-local:/tmp/TestInternalCache-local/tiutdc1744682815 at root tiutdc1744682815
2025/04/15 02:06:55 INFO  : TestInternalCache: Cache DB path: /home/rclone/.cache/rclone/cache-backend/TestInternalCache.db
2025/04/15 02:06:55 INFO  : TestInternalCache: Cache chunk path: /home/rclone/.cache/rclone/cache-backend/TestInternalCache
2025/04/15 02:06:55 INFO  : TestInternalCache: Chunk Memory: true
2025/04/15 02:06:55 INFO  : TestInternalCache: Chunk Size: 5Mi
2025/04/15 02:06:55 INFO  : TestInternalCache: Chunk Total Size: 10Gi
2025/04/15 02:06:55 INFO  : TestInternalCache: Chunk Clean Interval: 1m0s
2025/04/15 02:06:55 INFO  : TestInternalCache: Workers: 4
2025/04/15 02:06:55 INFO  : TestInternalCache: File Age: 6h0m0s
2025/04/15 02:06:55 DEBUG : Creating backend with remote "/tmp/rclonecache-tmp4140236242/tiutdc1744682815"
2025/04/15 02:06:55 INFO  : TestInternalCache: Upload Temp Rest Time: 15s
2025/04/15 02:06:55 INFO  : TestInternalCache: Upload Temp FS: /tmp/rclonecache-tmp4140236242/tiutdc1744682815
2025/04/15 02:06:55 DEBUG : Waiting for deletions to finish
2025/04/15 02:06:55 DEBUG : Cache remote TestInternalCache:tiutdc1744682815: list ''
2025/04/15 02:06:55 DEBUG : : list: error: couldn't open bucket (tiutdc1744682815)
2025/04/15 02:06:55 DEBUG : : list: read 0 from temp fs
2025/04/15 02:06:55 DEBUG : : list: temp fs entries: []
2025/04/15 02:06:55 ERROR : : error listing: directory not found
2025/04/15 02:06:55 DEBUG : Cache remote TestInternalCache:tiutdc1744682815: list ''
2025/04/15 02:06:55 DEBUG : : list: error: couldn't open bucket (tiutdc1744682815)
2025/04/15 02:06:55 DEBUG : : list: read 0 from temp fs
2025/04/15 02:06:55 DEBUG : : list: temp fs entries: []
2025/04/15 02:06:55 ERROR : Cache remote TestInternalCache:tiutdc1744682815: Failed to list "": directory not found
2025/04/15 02:06:55 DEBUG : removing 1 level 0 directories
2025/04/15 02:06:55 INFO  : Cache remote TestInternalCache:tiutdc1744682815: Removing directory
2025/04/15 02:06:55 DEBUG : Cache remote TestInternalCache:tiutdc1744682815: rmdir ''
2025/04/15 02:06:56 DEBUG : : rmdir: read 0 from temp fs
2025/04/15 02:06:56 DEBUG : : rmdir: temp fs entries: []
2025/04/15 02:06:56 DEBUG : tiutdc1744682815: couldn't delete from cache: bucket not found
2025/04/15 02:06:56 DEBUG : : rmdir: removed from cache
2025/04/15 02:06:56 INFO  : : rmdir: cache expired
2025/04/15 02:06:56 DEBUG : Cache remote TestInternalCache:tiutdc1744682815: mkdir ''
2025/04/15 02:06:56 DEBUG : : mkdir: created dir in source fs
2025/04/15 02:06:56 DEBUG : : mkdir: added to cache
2025/04/15 02:06:56 DEBUG : : cache: expired tiutdc1744682815
2025/04/15 02:06:56 INFO  : : mkdir: cache expired
2025/04/15 02:06:56 DEBUG : Waiting for deletions to finish
2025/04/15 02:06:56 DEBUG : Cache remote TestInternalCache:tiutdc1744682815: list ''
2025/04/15 02:06:56 DEBUG : : list: cold listing: 2025-04-14 20:06:56.72556748 +0000 UTC
2025/04/15 02:06:56 DEBUG : : list: read 0 from temp fs
2025/04/15 02:06:56 DEBUG : : list: temp fs entries: []
2025/04/15 02:06:56 DEBUG : : list: read 0 from source
2025/04/15 02:06:56 DEBUG : : list: source entries: []
2025/04/15 02:06:56 DEBUG : : list: cached directories: 0
2025/04/15 02:06:56 DEBUG : : list: cached dir: 'tiutdc1744682815', cache ts: 2025-04-15 02:06:56.726997594 +0000 UTC m=+1841.197414548
2025/04/15 02:06:56 DEBUG : Cache remote TestInternalCache:tiutdc1744682815: list ''
2025/04/15 02:06:56 DEBUG : : list: empty listing
2025/04/15 02:06:56 DEBUG : : list: read 0 from temp fs
2025/04/15 02:06:56 DEBUG : : list: temp fs entries: []
2025/04/15 02:06:56 DEBUG : : list: read 0 from source
2025/04/15 02:06:56 DEBUG : : list: source entries: []
2025/04/15 02:06:56 DEBUG : : list: cached directories: 0
2025/04/15 02:06:56 DEBUG : : list: cached dir: 'tiutdc1744682815', cache ts: 2025-04-15 02:06:56.728168791 +0000 UTC m=+1841.198585756
2025/04/15 02:06:56 DEBUG : removing 1 level 0 directories
2025/04/15 02:06:56 INFO  : Cache remote TestInternalCache:tiutdc1744682815: Removing directory
2025/04/15 02:06:56 DEBUG : Cache remote TestInternalCache:tiutdc1744682815: rmdir ''
2025/04/15 02:06:57 DEBUG : : rmdir: removed dir in source fs
2025/04/15 02:06:57 DEBUG : : rmdir: read 0 from temp fs
2025/04/15 02:06:57 DEBUG : : rmdir: temp fs entries: []
2025/04/15 02:06:57 DEBUG : : rmdir: removed from cache
2025/04/15 02:06:57 INFO  : : rmdir: cache expired
2025/04/15 02:06:59 DEBUG : Cache remote TestInternalCache:tiutdc1744682815: Services stopped
--- PASS: TestInternalUploadTempDirCreated (4.02s)
=== RUN   TestInternalUploadQueueOneFileNoRest
2025/04/15 02:06:59 DEBUG : Using config file from "/home/rclone/.rclone.conf"
    cache_internal_test.go:858: Need remote (TestInternalCache) to exist
--- SKIP: TestInternalUploadQueueOneFileNoRest (0.01s)
=== RUN   TestInternalUploadQueueOneFileWithRest
2025/04/15 02:06:59 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/04/15 02:06:59 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/04/15 02:06:59 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/04/15 02:06:59 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/04/15 02:06:59 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/04/15 02:06:59 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.728s
"go test -v -timeout 1h0m0s -remote TestCache: -verbose" - Finished ERROR in 30m45.399676435s (try 1/5): exit status 1: Failed [TestIntegration]