"go test -v -timeout 1h0m0s -remote TestCache: -verbose" - Starting (try 1/5)
2025/04/20 03:57:59 NOTICE: Running with the following params: 
 remote: TestInternalCache
2025/04/20 03:57:59 NOTICE: Temp Upload Dir: /tmp/rclonecache-tmp2733279096
=== RUN   TestInternalListRootAndInnerRemotes
2025/04/20 03:57:59 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/20 03:57:59 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/20 03:57:59 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2025/04/20 03:57:59 NOTICE: WARNING: Cache backend is deprecated and may be removed in future. Please use VFS instead.
2025/04/20 03:57:59 DEBUG : Creating backend with remote "TestInternalCache-local:/tmp/TestInternalCache-local/tionf1745121479"
2025/04/20 03:57:59 DEBUG : TestInternalCache: wrapped TestInternalCache-local:/tmp/TestInternalCache-local/tionf1745121479 at root tionf1745121479
2025/04/20 03:57:59 INFO  : TestInternalCache: Cache DB path: /home/rclone/.cache/rclone/cache-backend/TestInternalCache.db
2025/04/20 03:57:59 INFO  : TestInternalCache: Cache chunk path: /home/rclone/.cache/rclone/cache-backend/TestInternalCache
2025/04/20 03:57:59 INFO  : TestInternalCache: Chunk Memory: true
2025/04/20 03:57:59 INFO  : TestInternalCache: Chunk Size: 5Mi
2025/04/20 03:57:59 INFO  : TestInternalCache: Chunk Total Size: 10Gi
2025/04/20 03:57:59 INFO  : TestInternalCache: Chunk Clean Interval: 1m0s
2025/04/20 03:57:59 INFO  : TestInternalCache: Workers: 4
2025/04/20 03:57:59 INFO  : TestInternalCache: File Age: 6h0m0s
2025/04/20 03:57:59 DEBUG : Waiting for deletions to finish
2025/04/20 03:57:59 DEBUG : Cache remote TestInternalCache:tionf1745121479: list ''
2025/04/20 03:57:59 DEBUG : : list: error: couldn't open bucket (tionf1745121479)
2025/04/20 03:57:59 ERROR : : error listing: directory not found
2025/04/20 03:57:59 DEBUG : Cache remote TestInternalCache:tionf1745121479: list ''
2025/04/20 03:57:59 DEBUG : : list: error: couldn't open bucket (tionf1745121479)
2025/04/20 03:57:59 ERROR : Cache remote TestInternalCache:tionf1745121479: Failed to list "": directory not found
2025/04/20 03:57:59 DEBUG : removing 1 level 0 directories
2025/04/20 03:57:59 INFO  : Cache remote TestInternalCache:tionf1745121479: Removing directory
2025/04/20 03:57:59 DEBUG : Cache remote TestInternalCache:tionf1745121479: rmdir ''
2025/04/20 03:57:59 ERROR : : Failed to rmdir: stat /tmp/TestInternalCache-local/tionf1745121479: no such file or directory
2025/04/20 03:57:59 DEBUG : Cache remote TestInternalCache:tionf1745121479: mkdir ''
2025/04/20 03:57:59 DEBUG : : mkdir: created dir in source fs
2025/04/20 03:57:59 DEBUG : : mkdir: added to cache
2025/04/20 03:57:59 DEBUG : : cache: expired tionf1745121479
2025/04/20 03:57:59 INFO  : : mkdir: cache expired
2025/04/20 03:57:59 DEBUG : Cache remote TestInternalCache:tionf1745121479: new object '404'
2025/04/20 03:57:59 DEBUG : 404: find: error: couldn't find object (404)
2025/04/20 03:57:59 DEBUG : find failed: not found in either local or remote fs
2025/04/20 03:57:59 DEBUG : Waiting for deletions to finish
2025/04/20 03:57:59 DEBUG : Cache remote TestInternalCache:tionf1745121479: list ''
2025/04/20 03:57:59 DEBUG : : list: cold listing: 2025-04-19 21:57:59.353516055 +0000 UTC
2025/04/20 03:57:59 DEBUG : : list: read 0 from source
2025/04/20 03:57:59 DEBUG : : list: source entries: []
2025/04/20 03:57:59 DEBUG : : list: cached directories: 0
2025/04/20 03:57:59 DEBUG : : list: cached dir: 'tionf1745121479', cache ts: 2025-04-20 03:57:59.35478096 +0000 UTC m=+0.060072412
2025/04/20 03:57:59 DEBUG : Cache remote TestInternalCache:tionf1745121479: list ''
2025/04/20 03:57:59 DEBUG : : list: empty listing
2025/04/20 03:57:59 DEBUG : : list: read 0 from source
2025/04/20 03:57:59 DEBUG : : list: source entries: []
2025/04/20 03:57:59 DEBUG : : list: cached directories: 0
2025/04/20 03:57:59 DEBUG : : list: cached dir: 'tionf1745121479', cache ts: 2025-04-20 03:57:59.355902063 +0000 UTC m=+0.061193496
2025/04/20 03:57:59 DEBUG : removing 1 level 0 directories
2025/04/20 03:57:59 INFO  : Cache remote TestInternalCache:tionf1745121479: Removing directory
2025/04/20 03:57:59 DEBUG : Cache remote TestInternalCache:tionf1745121479: rmdir ''
2025/04/20 03:57:59 DEBUG : : rmdir: removed dir in source fs
2025/04/20 03:57:59 DEBUG : : rmdir: removed from cache
2025/04/20 03:57:59 INFO  : : rmdir: cache expired
2025/04/20 03:57:59 DEBUG : Cache remote TestInternalCache:tionf1745121479: Services stopped
--- PASS: TestInternalObjNotFound (0.05s)
=== RUN   TestInternalCachedWrittenContentMatches
2025/04/20 03:57:59 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2025/04/20 03:57:59 DEBUG : Creating backend with remote "TestInternalCache-local:/tmp/TestInternalCache-local/ticwcm1745121479"
2025/04/20 03:57:59 DEBUG : TestInternalCache: wrapped TestInternalCache-local:/tmp/TestInternalCache-local/ticwcm1745121479 at root ticwcm1745121479
2025/04/20 03:57:59 INFO  : TestInternalCache: Cache DB path: /home/rclone/.cache/rclone/cache-backend/TestInternalCache.db
2025/04/20 03:57:59 INFO  : TestInternalCache: Cache chunk path: /home/rclone/.cache/rclone/cache-backend/TestInternalCache
2025/04/20 03:57:59 INFO  : TestInternalCache: Chunk Memory: true
2025/04/20 03:57:59 INFO  : TestInternalCache: Chunk Size: 5Mi
2025/04/20 03:57:59 INFO  : TestInternalCache: Chunk Total Size: 10Gi
2025/04/20 03:57:59 INFO  : TestInternalCache: Chunk Clean Interval: 1m0s
2025/04/20 03:57:59 INFO  : TestInternalCache: Workers: 4
2025/04/20 03:57:59 INFO  : TestInternalCache: File Age: 6h0m0s
2025/04/20 03:57:59 DEBUG : Waiting for deletions to finish
2025/04/20 03:57:59 DEBUG : Cache remote TestInternalCache:ticwcm1745121479: list ''
2025/04/20 03:57:59 DEBUG : : list: error: couldn't open bucket (ticwcm1745121479)
2025/04/20 03:57:59 ERROR : : error listing: directory not found
2025/04/20 03:57:59 DEBUG : Cache remote TestInternalCache:ticwcm1745121479: list ''
2025/04/20 03:57:59 DEBUG : : list: error: couldn't open bucket (ticwcm1745121479)
2025/04/20 03:57:59 ERROR : Cache remote TestInternalCache:ticwcm1745121479: Failed to list "": directory not found
2025/04/20 03:57:59 DEBUG : removing 1 level 0 directories
2025/04/20 03:57:59 INFO  : Cache remote TestInternalCache:ticwcm1745121479: Removing directory
2025/04/20 03:57:59 DEBUG : Cache remote TestInternalCache:ticwcm1745121479: rmdir ''
2025/04/20 03:57:59 ERROR : : Failed to rmdir: stat /tmp/TestInternalCache-local/ticwcm1745121479: no such file or directory
2025/04/20 03:57:59 DEBUG : Cache remote TestInternalCache:ticwcm1745121479: mkdir ''
2025/04/20 03:57:59 DEBUG : : mkdir: created dir in source fs
2025/04/20 03:57:59 DEBUG : : mkdir: added to cache
2025/04/20 03:57:59 DEBUG : : cache: expired ticwcm1745121479
2025/04/20 03:57:59 INFO  : : mkdir: cache expired
2025/04/20 03:57:59 DEBUG : Cache remote TestInternalCache:ticwcm1745121479: put data at 'data.bin'
2025/04/20 03:57:59 DEBUG : data.bin: put: uploaded to remote fs
2025/04/20 03:57:59 DEBUG : data.bin: put: added to cache
2025/04/20 03:57:59 DEBUG : : cache: expired ticwcm1745121479
2025/04/20 03:57:59 INFO  : : put: cache expired
2025/04/20 03:57:59 DEBUG : Cache remote TestInternalCache:ticwcm1745121479: new object 'data.bin'
2025/04/20 03:57:59 DEBUG : data.bin: find: warm object: data.bin, expiring on: 2025-04-20 09:57:59.893842109 +0000 UTC
2025/04/20 03:57:59 DEBUG : Cache remote TestInternalCache:ticwcm1745121479: new object 'data.bin'
2025/04/20 03:57:59 DEBUG : data.bin: find: warm object: data.bin, expiring on: 2025-04-20 09:57:59.893842109 +0000 UTC
2025/04/20 03:57:59 DEBUG : ticwcm1745121479/data.bin: moving offset set from 0 to 2621440
2025/04/20 03:57:59 DEBUG : ticwcm1745121479/data.bin: 0: chunk retry storage: 0
2025/04/20 03:57:59 DEBUG : worker-0 <data.bin>: downloaded chunk 0
2025/04/20 03:57:59 DEBUG : worker-2 <data.bin>: downloaded chunk 5242880
2025/04/20 03:57:59 DEBUG : worker-3 <data.bin>: downloaded chunk 10485760
2025/04/20 03:57:59 DEBUG : worker-1 <data.bin>: downloaded chunk 15728640
2025/04/20 03:58:00 DEBUG : ticwcm1745121479/data.bin: cache reader closed 5242880
2025/04/20 03:58:00 DEBUG : Waiting for deletions to finish
2025/04/20 03:58:00 DEBUG : Cache remote TestInternalCache:ticwcm1745121479: list ''
2025/04/20 03:58:00 DEBUG : : list: cold listing: 2025-04-19 21:57:59.897046574 +0000 UTC
2025/04/20 03:58:00 DEBUG : : list: read 1 from source
2025/04/20 03:58:00 DEBUG : : list: source entries: [data.bin]
2025/04/20 03:58:00 DEBUG : : list: cached object: data.bin
2025/04/20 03:58:00 DEBUG : : list: cached directories: 0
2025/04/20 03:58:00 DEBUG : : list: cached dir: 'ticwcm1745121479', cache ts: 2025-04-20 03:58:00.419931913 +0000 UTC m=+1.125223375
2025/04/20 03:58:00 DEBUG : data.bin: removing object
2025/04/20 03:58:00 DEBUG : : cache: expired ticwcm1745121479
2025/04/20 03:58:00 INFO  : data.bin: Deleted
2025/04/20 03:58:00 DEBUG : Cache remote TestInternalCache:ticwcm1745121479: list ''
2025/04/20 03:58:00 DEBUG : : list: cold listing: 2025-04-19 21:58:00.430771528 +0000 UTC
2025/04/20 03:58:00 DEBUG : : list: read 0 from source
2025/04/20 03:58:00 DEBUG : : list: source entries: []
2025/04/20 03:58:00 DEBUG : : list: cached directories: 0
2025/04/20 03:58:00 DEBUG : : list: cached dir: 'ticwcm1745121479', cache ts: 2025-04-20 03:58:00.432190802 +0000 UTC m=+1.137482274
2025/04/20 03:58:00 DEBUG : removing 1 level 0 directories
2025/04/20 03:58:00 INFO  : Cache remote TestInternalCache:ticwcm1745121479: Removing directory
2025/04/20 03:58:00 DEBUG : Cache remote TestInternalCache:ticwcm1745121479: rmdir ''
2025/04/20 03:58:00 DEBUG : : rmdir: removed dir in source fs
2025/04/20 03:58:00 DEBUG : : rmdir: removed from cache
2025/04/20 03:58:00 INFO  : : rmdir: cache expired
2025/04/20 03:58:00 DEBUG : Cache remote TestInternalCache:ticwcm1745121479: Services stopped
--- PASS: TestInternalCachedWrittenContentMatches (1.09s)
=== RUN   TestInternalDoubleWrittenContentMatches
2025/04/20 03:58:00 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2025/04/20 03:58:00 DEBUG : Creating backend with remote "TestInternalCache-local:/tmp/TestInternalCache-local/tidwcm1745121480"
2025/04/20 03:58:00 DEBUG : TestInternalCache: wrapped TestInternalCache-local:/tmp/TestInternalCache-local/tidwcm1745121480 at root tidwcm1745121480
2025/04/20 03:58:00 INFO  : TestInternalCache: Cache DB path: /home/rclone/.cache/rclone/cache-backend/TestInternalCache.db
2025/04/20 03:58:00 INFO  : TestInternalCache: Cache chunk path: /home/rclone/.cache/rclone/cache-backend/TestInternalCache
2025/04/20 03:58:00 INFO  : TestInternalCache: Chunk Memory: true
2025/04/20 03:58:00 INFO  : TestInternalCache: Chunk Size: 5Mi
2025/04/20 03:58:00 INFO  : TestInternalCache: Chunk Total Size: 10Gi
2025/04/20 03:58:00 INFO  : TestInternalCache: Chunk Clean Interval: 1m0s
2025/04/20 03:58:00 INFO  : TestInternalCache: Workers: 4
2025/04/20 03:58:00 INFO  : TestInternalCache: File Age: 6h0m0s
2025/04/20 03:58:00 DEBUG : Waiting for deletions to finish
2025/04/20 03:58:00 DEBUG : Cache remote TestInternalCache:tidwcm1745121480: list ''
2025/04/20 03:58:00 DEBUG : : list: error: couldn't open bucket (tidwcm1745121480)
2025/04/20 03:58:00 ERROR : : error listing: directory not found
2025/04/20 03:58:00 DEBUG : Cache remote TestInternalCache:tidwcm1745121480: list ''
2025/04/20 03:58:00 DEBUG : : list: error: couldn't open bucket (tidwcm1745121480)
2025/04/20 03:58:00 ERROR : Cache remote TestInternalCache:tidwcm1745121480: Failed to list "": directory not found
2025/04/20 03:58:00 DEBUG : removing 1 level 0 directories
2025/04/20 03:58:00 INFO  : Cache remote TestInternalCache:tidwcm1745121480: Removing directory
2025/04/20 03:58:00 DEBUG : Cache remote TestInternalCache:tidwcm1745121480: rmdir ''
2025/04/20 03:58:00 ERROR : : Failed to rmdir: stat /tmp/TestInternalCache-local/tidwcm1745121480: no such file or directory
2025/04/20 03:58:00 DEBUG : Cache remote TestInternalCache:tidwcm1745121480: mkdir ''
2025/04/20 03:58:00 DEBUG : : mkdir: created dir in source fs
2025/04/20 03:58:00 DEBUG : : mkdir: added to cache
2025/04/20 03:58:00 DEBUG : : cache: expired tidwcm1745121480
2025/04/20 03:58:00 INFO  : : mkdir: cache expired
2025/04/20 03:58:00 DEBUG : Cache remote TestInternalCache:tidwcm1745121480: put data at 'one'
2025/04/20 03:58:00 DEBUG : one: put: uploaded to remote fs
2025/04/20 03:58:00 DEBUG : one: put: added to cache
2025/04/20 03:58:00 DEBUG : : cache: expired tidwcm1745121480
2025/04/20 03:58:00 INFO  : : put: cache expired
2025/04/20 03:58:00 DEBUG : Cache remote TestInternalCache:tidwcm1745121480: new object 'one'
2025/04/20 03:58:00 DEBUG : one: find: warm object: one, expiring on: 2025-04-20 09:58:00.458955637 +0000 UTC
2025/04/20 03:58:00 DEBUG : Cache remote TestInternalCache:tidwcm1745121480: new object 'one'
2025/04/20 03:58:00 DEBUG : one: find: warm object: one, expiring on: 2025-04-20 09:58:00.458955637 +0000 UTC
2025/04/20 03:58:00 DEBUG : one: updating object contents with size 19
2025/04/20 03:58:00 DEBUG : Cache remote TestInternalCache:tidwcm1745121480: new object 'one'
2025/04/20 03:58:00 DEBUG : one: find: warm object: one, expiring on: 2025-04-20 09:58:00.464941091 +0000 UTC
2025/04/20 03:58:00 DEBUG : one: updating object contents with size 26
2025/04/20 03:58:00 DEBUG : Cache remote TestInternalCache:tidwcm1745121480: new object 'one'
2025/04/20 03:58:00 DEBUG : one: find: warm object: one, expiring on: 2025-04-20 09:58:00.469012063 +0000 UTC
2025/04/20 03:58:00 DEBUG : tidwcm1745121480/one: moving offset set from 0 to 0
2025/04/20 03:58:00 DEBUG : tidwcm1745121480/one: 0: chunk retry storage: 0
2025/04/20 03:58:00 DEBUG : worker-0 <one>: partial downloaded chunk 0
2025/04/20 03:58:00 DEBUG : tidwcm1745121480/one: cache reader closed 26
2025/04/20 03:58:00 DEBUG : Waiting for deletions to finish
2025/04/20 03:58:00 DEBUG : Cache remote TestInternalCache:tidwcm1745121480: list ''
2025/04/20 03:58:00 DEBUG : : list: cold listing: 2025-04-19 21:58:00.461070787 +0000 UTC
2025/04/20 03:58:00 DEBUG : : list: read 1 from source
2025/04/20 03:58:00 DEBUG : : list: source entries: [one]
2025/04/20 03:58:00 DEBUG : : list: cached object: one
2025/04/20 03:58:00 DEBUG : : list: cached directories: 0
2025/04/20 03:58:00 DEBUG : : list: cached dir: 'tidwcm1745121480', cache ts: 2025-04-20 03:58:00.979279489 +0000 UTC m=+1.684570951
2025/04/20 03:58:00 DEBUG : one: removing object
2025/04/20 03:58:00 DEBUG : : cache: expired tidwcm1745121480
2025/04/20 03:58:00 INFO  : one: Deleted
2025/04/20 03:58:00 DEBUG : Cache remote TestInternalCache:tidwcm1745121480: list ''
2025/04/20 03:58:00 DEBUG : : list: cold listing: 2025-04-19 21:58:00.982751094 +0000 UTC
2025/04/20 03:58:00 DEBUG : : list: read 0 from source
2025/04/20 03:58:00 DEBUG : : list: source entries: []
2025/04/20 03:58:00 DEBUG : : list: cached directories: 0
2025/04/20 03:58:00 DEBUG : : list: cached dir: 'tidwcm1745121480', cache ts: 2025-04-20 03:58:00.984045754 +0000 UTC m=+1.689337217
2025/04/20 03:58:00 DEBUG : removing 1 level 0 directories
2025/04/20 03:58:00 INFO  : Cache remote TestInternalCache:tidwcm1745121480: Removing directory
2025/04/20 03:58:00 DEBUG : Cache remote TestInternalCache:tidwcm1745121480: rmdir ''
2025/04/20 03:58:00 DEBUG : : rmdir: removed dir in source fs
2025/04/20 03:58:00 DEBUG : : rmdir: removed from cache
2025/04/20 03:58:00 INFO  : : rmdir: cache expired
2025/04/20 03:58:00 DEBUG : Cache remote TestInternalCache:tidwcm1745121480: Services stopped
--- PASS: TestInternalDoubleWrittenContentMatches (0.55s)
=== RUN   TestInternalCachedUpdatedContentMatches
2025/04/20 03:58:00 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2025/04/20 03:58:01 DEBUG : Creating backend with remote "TestInternalCache-local:/tmp/TestInternalCache-local/ticucm1745121480"
2025/04/20 03:58:01 DEBUG : TestInternalCache: wrapped TestInternalCache-local:/tmp/TestInternalCache-local/ticucm1745121480 at root ticucm1745121480
2025/04/20 03:58:01 INFO  : TestInternalCache: Cache DB path: /home/rclone/.cache/rclone/cache-backend/TestInternalCache.db
2025/04/20 03:58:01 INFO  : TestInternalCache: Cache chunk path: /home/rclone/.cache/rclone/cache-backend/TestInternalCache
2025/04/20 03:58:01 INFO  : TestInternalCache: Chunk Memory: true
2025/04/20 03:58:01 INFO  : TestInternalCache: Chunk Size: 5Mi
2025/04/20 03:58:01 INFO  : TestInternalCache: Chunk Total Size: 10Gi
2025/04/20 03:58:01 INFO  : TestInternalCache: Chunk Clean Interval: 1m0s
2025/04/20 03:58:01 INFO  : TestInternalCache: Workers: 4
2025/04/20 03:58:01 INFO  : TestInternalCache: File Age: 6h0m0s
2025/04/20 03:58:01 DEBUG : Waiting for deletions to finish
2025/04/20 03:58:01 DEBUG : Cache remote TestInternalCache:ticucm1745121480: list ''
2025/04/20 03:58:01 DEBUG : : list: error: couldn't open bucket (ticucm1745121480)
2025/04/20 03:58:01 ERROR : : error listing: directory not found
2025/04/20 03:58:01 DEBUG : Cache remote TestInternalCache:ticucm1745121480: list ''
2025/04/20 03:58:01 DEBUG : : list: error: couldn't open bucket (ticucm1745121480)
2025/04/20 03:58:01 ERROR : Cache remote TestInternalCache:ticucm1745121480: Failed to list "": directory not found
2025/04/20 03:58:01 DEBUG : removing 1 level 0 directories
2025/04/20 03:58:01 INFO  : Cache remote TestInternalCache:ticucm1745121480: Removing directory
2025/04/20 03:58:01 DEBUG : Cache remote TestInternalCache:ticucm1745121480: rmdir ''
2025/04/20 03:58:01 ERROR : : Failed to rmdir: stat /tmp/TestInternalCache-local/ticucm1745121480: no such file or directory
2025/04/20 03:58:01 DEBUG : Cache remote TestInternalCache:ticucm1745121480: mkdir ''
2025/04/20 03:58:01 DEBUG : : mkdir: created dir in source fs
2025/04/20 03:58:01 DEBUG : : mkdir: added to cache
2025/04/20 03:58:01 DEBUG : : cache: expired ticucm1745121480
2025/04/20 03:58:01 INFO  : : mkdir: cache expired
2025/04/20 03:58:01 DEBUG : Cache remote TestInternalCache:ticucm1745121480: put data at 'data.bin'
2025/04/20 03:58:01 DEBUG : data.bin: put: uploaded to remote fs
2025/04/20 03:58:01 DEBUG : data.bin: put: added to cache
2025/04/20 03:58:01 DEBUG : : cache: expired ticucm1745121480
2025/04/20 03:58:01 INFO  : : put: cache expired
2025/04/20 03:58:01 DEBUG : Cache remote TestInternalCache:ticucm1745121480: new object 'data.bin'
2025/04/20 03:58:01 DEBUG : data.bin: find: warm object: data.bin, expiring on: 2025-04-20 09:58:01.007363089 +0000 UTC
2025/04/20 03:58:01 DEBUG : data.bin: updating object contents with size 200
2025/04/20 03:58:01 DEBUG : Cache remote TestInternalCache:ticucm1745121480: new object 'data.bin'
2025/04/20 03:58:01 DEBUG : data.bin: find: warm object: data.bin, expiring on: 2025-04-20 09:58:01.015037804 +0000 UTC
2025/04/20 03:58:01 DEBUG : ticucm1745121480/data.bin: moving offset set from 0 to 0
2025/04/20 03:58:01 DEBUG : ticucm1745121480/data.bin: 0: chunk retry storage: 0
2025/04/20 03:58:01 DEBUG : worker-0 <data.bin>: partial downloaded chunk 0
2025/04/20 03:58:01 DEBUG : ticucm1745121480/data.bin: cache reader closed 200
2025/04/20 03:58:01 DEBUG : Waiting for deletions to finish
2025/04/20 03:58:01 DEBUG : Cache remote TestInternalCache:ticucm1745121480: list ''
2025/04/20 03:58:01 DEBUG : : list: cold listing: 2025-04-19 21:58:01.010603441 +0000 UTC
2025/04/20 03:58:01 DEBUG : : list: read 1 from source
2025/04/20 03:58:01 DEBUG : : list: source entries: [data.bin]
2025/04/20 03:58:01 DEBUG : : list: cached object: data.bin
2025/04/20 03:58:01 DEBUG : : list: cached directories: 0
2025/04/20 03:58:01 DEBUG : : list: cached dir: 'ticucm1745121480', cache ts: 2025-04-20 03:58:01.520343888 +0000 UTC m=+2.225635360
2025/04/20 03:58:01 DEBUG : data.bin: removing object
2025/04/20 03:58:01 DEBUG : : cache: expired ticucm1745121480
2025/04/20 03:58:01 INFO  : data.bin: Deleted
2025/04/20 03:58:01 DEBUG : Cache remote TestInternalCache:ticucm1745121480: list ''
2025/04/20 03:58:01 DEBUG : : list: cold listing: 2025-04-19 21:58:01.523969593 +0000 UTC
2025/04/20 03:58:01 DEBUG : : list: read 0 from source
2025/04/20 03:58:01 DEBUG : : list: source entries: []
2025/04/20 03:58:01 DEBUG : : list: cached directories: 0
2025/04/20 03:58:01 DEBUG : : list: cached dir: 'ticucm1745121480', cache ts: 2025-04-20 03:58:01.525243274 +0000 UTC m=+2.230534747
2025/04/20 03:58:01 DEBUG : removing 1 level 0 directories
2025/04/20 03:58:01 INFO  : Cache remote TestInternalCache:ticucm1745121480: Removing directory
2025/04/20 03:58:01 DEBUG : Cache remote TestInternalCache:ticucm1745121480: rmdir ''
2025/04/20 03:58:01 DEBUG : : rmdir: removed dir in source fs
2025/04/20 03:58:01 DEBUG : : rmdir: removed from cache
2025/04/20 03:58:01 INFO  : : rmdir: cache expired
2025/04/20 03:58:01 DEBUG : Cache remote TestInternalCache:ticucm1745121480: Services stopped
--- PASS: TestInternalCachedUpdatedContentMatches (0.54s)
=== RUN   TestInternalWrappedWrittenContentMatches
2025/04/20 03:58:01 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/20 03:58:01 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/20 03:58:01 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2025/04/20 03:58:01 DEBUG : Creating backend with remote "TestInternalCache-local:/tmp/TestInternalCache-local/tiwfcns1745121481"
2025/04/20 03:58:01 DEBUG : TestInternalCache: wrapped TestInternalCache-local:/tmp/TestInternalCache-local/tiwfcns1745121481 at root tiwfcns1745121481
2025/04/20 03:58:01 INFO  : TestInternalCache: Cache DB path: /home/rclone/.cache/rclone/cache-backend/TestInternalCache.db
2025/04/20 03:58:01 INFO  : TestInternalCache: Cache chunk path: /home/rclone/.cache/rclone/cache-backend/TestInternalCache
2025/04/20 03:58:01 INFO  : TestInternalCache: Chunk Memory: true
2025/04/20 03:58:01 INFO  : TestInternalCache: Chunk Size: 5Mi
2025/04/20 03:58:01 INFO  : TestInternalCache: Chunk Total Size: 10Gi
2025/04/20 03:58:01 INFO  : TestInternalCache: Chunk Clean Interval: 1m0s
2025/04/20 03:58:01 INFO  : TestInternalCache: Workers: 4
2025/04/20 03:58:01 INFO  : TestInternalCache: File Age: 6h0m0s
2025/04/20 03:58:01 DEBUG : Waiting for deletions to finish
2025/04/20 03:58:01 DEBUG : Cache remote TestInternalCache:tiwfcns1745121481: list ''
2025/04/20 03:58:01 DEBUG : : list: error: couldn't open bucket (tiwfcns1745121481)
2025/04/20 03:58:01 ERROR : : error listing: directory not found
2025/04/20 03:58:01 DEBUG : Cache remote TestInternalCache:tiwfcns1745121481: list ''
2025/04/20 03:58:01 DEBUG : : list: error: couldn't open bucket (tiwfcns1745121481)
2025/04/20 03:58:01 ERROR : Cache remote TestInternalCache:tiwfcns1745121481: Failed to list "": directory not found
2025/04/20 03:58:01 DEBUG : removing 1 level 0 directories
2025/04/20 03:58:01 INFO  : Cache remote TestInternalCache:tiwfcns1745121481: Removing directory
2025/04/20 03:58:01 DEBUG : Cache remote TestInternalCache:tiwfcns1745121481: rmdir ''
2025/04/20 03:58:01 ERROR : : Failed to rmdir: stat /tmp/TestInternalCache-local/tiwfcns1745121481: no such file or directory
2025/04/20 03:58:01 DEBUG : Cache remote TestInternalCache:tiwfcns1745121481: mkdir ''
2025/04/20 03:58:01 DEBUG : : mkdir: created dir in source fs
2025/04/20 03:58:01 DEBUG : : mkdir: added to cache
2025/04/20 03:58:01 DEBUG : : cache: expired tiwfcns1745121481
2025/04/20 03:58:01 INFO  : : mkdir: cache expired
2025/04/20 03:58:02 DEBUG : Cache remote TestInternalCache:tiwfcns1745121481: put data at 'data.bin'
2025/04/20 03:58:02 DEBUG : data.bin: put: uploaded to remote fs
2025/04/20 03:58:02 DEBUG : data.bin: put: added to cache
2025/04/20 03:58:02 DEBUG : : cache: expired tiwfcns1745121481
2025/04/20 03:58:02 INFO  : : put: cache expired
2025/04/20 03:58:02 DEBUG : Cache remote TestInternalCache:tiwfcns1745121481: new object 'data.bin'
2025/04/20 03:58:02 DEBUG : data.bin: find: warm object: data.bin, expiring on: 2025-04-20 09:58:02.13139597 +0000 UTC
2025/04/20 03:58:02 DEBUG : Cache remote TestInternalCache:tiwfcns1745121481: new object 'data.bin'
2025/04/20 03:58:02 DEBUG : data.bin: find: warm object: data.bin, expiring on: 2025-04-20 09:58:02.13139597 +0000 UTC
2025/04/20 03:58:02 NOTICE: original size: 23592960
2025/04/20 03:58:02 NOTICE: updated size: 12
2025/04/20 03:58:02 DEBUG : Cache remote TestInternalCache:tiwfcns1745121481: new object 'data.bin'
2025/04/20 03:58:02 DEBUG : data.bin: find: warm object: data.bin, expiring on: 2025-04-20 09:58:02.13139597 +0000 UTC
2025/04/20 03:58:02 DEBUG : Waiting for deletions to finish
2025/04/20 03:58:02 DEBUG : Cache remote TestInternalCache:tiwfcns1745121481: list ''
2025/04/20 03:58:02 DEBUG : : list: cold listing: 2025-04-19 21:58:02.133851739 +0000 UTC
2025/04/20 03:58:02 DEBUG : : list: read 1 from source
2025/04/20 03:58:02 DEBUG : : list: source entries: [data.bin]
2025/04/20 03:58:02 DEBUG : : list: cached object: data.bin
2025/04/20 03:58:02 DEBUG : : list: cached directories: 0
2025/04/20 03:58:02 DEBUG : : list: cached dir: 'tiwfcns1745121481', cache ts: 2025-04-20 03:58:02.13905225 +0000 UTC m=+2.844343682
2025/04/20 03:58:02 DEBUG : data.bin: removing object
2025/04/20 03:58:02 DEBUG : : cache: expired tiwfcns1745121481
2025/04/20 03:58:02 INFO  : data.bin: Deleted
2025/04/20 03:58:02 DEBUG : Cache remote TestInternalCache:tiwfcns1745121481: list ''
2025/04/20 03:58:02 DEBUG : : list: cold listing: 2025-04-19 21:58:02.141921314 +0000 UTC
2025/04/20 03:58:02 DEBUG : : list: read 0 from source
2025/04/20 03:58:02 DEBUG : : list: source entries: []
2025/04/20 03:58:02 DEBUG : : list: cached directories: 0
2025/04/20 03:58:02 DEBUG : : list: cached dir: 'tiwfcns1745121481', cache ts: 2025-04-20 03:58:02.143104486 +0000 UTC m=+2.848395917
2025/04/20 03:58:02 DEBUG : removing 1 level 0 directories
2025/04/20 03:58:02 INFO  : Cache remote TestInternalCache:tiwfcns1745121481: Removing directory
2025/04/20 03:58:02 DEBUG : Cache remote TestInternalCache:tiwfcns1745121481: rmdir ''
2025/04/20 03:58:02 DEBUG : : rmdir: removed dir in source fs
2025/04/20 03:58:02 DEBUG : : rmdir: removed from cache
2025/04/20 03:58:02 INFO  : : rmdir: cache expired
2025/04/20 03:58:02 DEBUG : Cache remote TestInternalCache:tiwfcns1745121481: Services stopped
--- PASS: TestInternalWrappedFsChangeNotSeen (0.61s)
=== RUN   TestInternalMoveWithNotify
2025/04/20 03:58:02 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2025/04/20 03:58:02 DEBUG : Creating backend with remote "TestInternalCache-local:/tmp/TestInternalCache-local/timwn1745121482"
2025/04/20 03:58:02 DEBUG : TestInternalCache: wrapped TestInternalCache-local:/tmp/TestInternalCache-local/timwn1745121482 at root timwn1745121482
2025/04/20 03:58:02 INFO  : TestInternalCache: Cache DB path: /home/rclone/.cache/rclone/cache-backend/TestInternalCache.db
2025/04/20 03:58:02 INFO  : TestInternalCache: Cache chunk path: /home/rclone/.cache/rclone/cache-backend/TestInternalCache
2025/04/20 03:58:02 INFO  : TestInternalCache: Chunk Memory: true
2025/04/20 03:58:02 INFO  : TestInternalCache: Chunk Size: 5Mi
2025/04/20 03:58:02 INFO  : TestInternalCache: Chunk Total Size: 10Gi
2025/04/20 03:58:02 INFO  : TestInternalCache: Chunk Clean Interval: 1m0s
2025/04/20 03:58:02 INFO  : TestInternalCache: Workers: 4
2025/04/20 03:58:02 INFO  : TestInternalCache: File Age: 6h0m0s
2025/04/20 03:58:02 DEBUG : Waiting for deletions to finish
2025/04/20 03:58:02 DEBUG : Cache remote TestInternalCache:timwn1745121482: list ''
2025/04/20 03:58:02 DEBUG : : list: error: couldn't open bucket (timwn1745121482)
2025/04/20 03:58:02 ERROR : : error listing: directory not found
2025/04/20 03:58:02 DEBUG : Cache remote TestInternalCache:timwn1745121482: list ''
2025/04/20 03:58:02 DEBUG : : list: error: couldn't open bucket (timwn1745121482)
2025/04/20 03:58:02 ERROR : Cache remote TestInternalCache:timwn1745121482: Failed to list "": directory not found
2025/04/20 03:58:02 DEBUG : removing 1 level 0 directories
2025/04/20 03:58:02 INFO  : Cache remote TestInternalCache:timwn1745121482: Removing directory
2025/04/20 03:58:02 DEBUG : Cache remote TestInternalCache:timwn1745121482: rmdir ''
2025/04/20 03:58:02 ERROR : : Failed to rmdir: stat /tmp/TestInternalCache-local/timwn1745121482: no such file or directory
2025/04/20 03:58:02 DEBUG : Cache remote TestInternalCache:timwn1745121482: mkdir ''
2025/04/20 03:58:02 DEBUG : : mkdir: created dir in source fs
2025/04/20 03:58:02 DEBUG : : mkdir: added to cache
2025/04/20 03:58:02 DEBUG : : cache: expired timwn1745121482
2025/04/20 03:58:02 INFO  : : mkdir: cache expired
    cache_internal_test.go:453: Not external
2025/04/20 03:58:02 DEBUG : Waiting for deletions to finish
2025/04/20 03:58:02 DEBUG : Cache remote TestInternalCache:timwn1745121482: list ''
2025/04/20 03:58:02 DEBUG : : list: cold listing: 2025-04-19 21:58:02.157430073 +0000 UTC
2025/04/20 03:58:02 DEBUG : : list: read 0 from source
2025/04/20 03:58:02 DEBUG : : list: source entries: []
2025/04/20 03:58:02 DEBUG : : list: cached directories: 0
2025/04/20 03:58:02 DEBUG : : list: cached dir: 'timwn1745121482', cache ts: 2025-04-20 03:58:02.15878171 +0000 UTC m=+2.864073182
2025/04/20 03:58:02 DEBUG : Cache remote TestInternalCache:timwn1745121482: list ''
2025/04/20 03:58:02 DEBUG : : list: empty listing
2025/04/20 03:58:02 DEBUG : : list: read 0 from source
2025/04/20 03:58:02 DEBUG : : list: source entries: []
2025/04/20 03:58:02 DEBUG : : list: cached directories: 0
2025/04/20 03:58:02 DEBUG : : list: cached dir: 'timwn1745121482', cache ts: 2025-04-20 03:58:02.160070139 +0000 UTC m=+2.865361600
2025/04/20 03:58:02 DEBUG : removing 1 level 0 directories
2025/04/20 03:58:02 INFO  : Cache remote TestInternalCache:timwn1745121482: Removing directory
2025/04/20 03:58:02 DEBUG : Cache remote TestInternalCache:timwn1745121482: rmdir ''
2025/04/20 03:58:02 DEBUG : : rmdir: removed dir in source fs
2025/04/20 03:58:02 DEBUG : : rmdir: removed from cache
2025/04/20 03:58:02 INFO  : : rmdir: cache expired
2025/04/20 03:58:02 DEBUG : Cache remote TestInternalCache:timwn1745121482: Services stopped
--- SKIP: TestInternalMoveWithNotify (0.02s)
=== RUN   TestInternalNotifyCreatesEmptyParts
2025/04/20 03:58:02 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2025/04/20 03:58:02 DEBUG : Creating backend with remote "TestInternalCache-local:/tmp/TestInternalCache-local/tincep1745121482"
2025/04/20 03:58:02 DEBUG : TestInternalCache: wrapped TestInternalCache-local:/tmp/TestInternalCache-local/tincep1745121482 at root tincep1745121482
2025/04/20 03:58:02 INFO  : TestInternalCache: Cache DB path: /home/rclone/.cache/rclone/cache-backend/TestInternalCache.db
2025/04/20 03:58:02 INFO  : TestInternalCache: Cache chunk path: /home/rclone/.cache/rclone/cache-backend/TestInternalCache
2025/04/20 03:58:02 INFO  : TestInternalCache: Chunk Memory: true
2025/04/20 03:58:02 INFO  : TestInternalCache: Chunk Size: 5Mi
2025/04/20 03:58:02 INFO  : TestInternalCache: Chunk Total Size: 10Gi
2025/04/20 03:58:02 INFO  : TestInternalCache: Chunk Clean Interval: 1m0s
2025/04/20 03:58:02 INFO  : TestInternalCache: Workers: 4
2025/04/20 03:58:02 INFO  : TestInternalCache: File Age: 6h0m0s
2025/04/20 03:58:02 DEBUG : Waiting for deletions to finish
2025/04/20 03:58:02 DEBUG : Cache remote TestInternalCache:tincep1745121482: list ''
2025/04/20 03:58:02 DEBUG : : list: error: couldn't open bucket (tincep1745121482)
2025/04/20 03:58:02 ERROR : : error listing: directory not found
2025/04/20 03:58:02 DEBUG : Cache remote TestInternalCache:tincep1745121482: list ''
2025/04/20 03:58:02 DEBUG : : list: error: couldn't open bucket (tincep1745121482)
2025/04/20 03:58:02 ERROR : Cache remote TestInternalCache:tincep1745121482: Failed to list "": directory not found
2025/04/20 03:58:02 DEBUG : removing 1 level 0 directories
2025/04/20 03:58:02 INFO  : Cache remote TestInternalCache:tincep1745121482: Removing directory
2025/04/20 03:58:02 DEBUG : Cache remote TestInternalCache:tincep1745121482: rmdir ''
2025/04/20 03:58:02 ERROR : : Failed to rmdir: stat /tmp/TestInternalCache-local/tincep1745121482: no such file or directory
2025/04/20 03:58:02 DEBUG : Cache remote TestInternalCache:tincep1745121482: mkdir ''
2025/04/20 03:58:02 DEBUG : : mkdir: created dir in source fs
2025/04/20 03:58:02 DEBUG : : mkdir: added to cache
2025/04/20 03:58:02 DEBUG : : cache: expired tincep1745121482
2025/04/20 03:58:02 INFO  : : mkdir: cache expired
    cache_internal_test.go:539: Not external
2025/04/20 03:58:02 DEBUG : Waiting for deletions to finish
2025/04/20 03:58:02 DEBUG : Cache remote TestInternalCache:tincep1745121482: list ''
2025/04/20 03:58:02 DEBUG : : list: cold listing: 2025-04-19 21:58:02.175477226 +0000 UTC
2025/04/20 03:58:02 DEBUG : : list: read 0 from source
2025/04/20 03:58:02 DEBUG : : list: source entries: []
2025/04/20 03:58:02 DEBUG : : list: cached directories: 0
2025/04/20 03:58:02 DEBUG : : list: cached dir: 'tincep1745121482', cache ts: 2025-04-20 03:58:02.176943789 +0000 UTC m=+2.882235251
2025/04/20 03:58:02 DEBUG : Cache remote TestInternalCache:tincep1745121482: list ''
2025/04/20 03:58:02 DEBUG : : list: empty listing
2025/04/20 03:58:02 DEBUG : : list: read 0 from source
2025/04/20 03:58:02 DEBUG : : list: source entries: []
2025/04/20 03:58:02 DEBUG : : list: cached directories: 0
2025/04/20 03:58:02 DEBUG : : list: cached dir: 'tincep1745121482', cache ts: 2025-04-20 03:58:02.178273665 +0000 UTC m=+2.883565097
2025/04/20 03:58:02 DEBUG : removing 1 level 0 directories
2025/04/20 03:58:02 INFO  : Cache remote TestInternalCache:tincep1745121482: Removing directory
2025/04/20 03:58:02 DEBUG : Cache remote TestInternalCache:tincep1745121482: rmdir ''
2025/04/20 03:58:02 DEBUG : : rmdir: removed dir in source fs
2025/04/20 03:58:02 DEBUG : : rmdir: removed from cache
2025/04/20 03:58:02 INFO  : : rmdir: cache expired
2025/04/20 03:58:02 DEBUG : Cache remote TestInternalCache:tincep1745121482: Services stopped
--- SKIP: TestInternalNotifyCreatesEmptyParts (0.01s)
=== RUN   TestInternalChangeSeenAfterDirCacheFlush
2025/04/20 03:58:02 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2025/04/20 03:58:02 DEBUG : Creating backend with remote "TestInternalCache-local:/tmp/TestInternalCache-local/ticsadcf1745121482"
2025/04/20 03:58:02 DEBUG : TestInternalCache: wrapped TestInternalCache-local:/tmp/TestInternalCache-local/ticsadcf1745121482 at root ticsadcf1745121482
2025/04/20 03:58:02 INFO  : TestInternalCache: Cache DB path: /home/rclone/.cache/rclone/cache-backend/TestInternalCache.db
2025/04/20 03:58:02 INFO  : TestInternalCache: Cache chunk path: /home/rclone/.cache/rclone/cache-backend/TestInternalCache
2025/04/20 03:58:02 INFO  : TestInternalCache: Chunk Memory: true
2025/04/20 03:58:02 INFO  : TestInternalCache: Chunk Size: 5Mi
2025/04/20 03:58:02 INFO  : TestInternalCache: Chunk Total Size: 10Gi
2025/04/20 03:58:02 INFO  : TestInternalCache: Chunk Clean Interval: 1m0s
2025/04/20 03:58:02 INFO  : TestInternalCache: Workers: 4
2025/04/20 03:58:02 INFO  : TestInternalCache: File Age: 6h0m0s
2025/04/20 03:58:02 DEBUG : Waiting for deletions to finish
2025/04/20 03:58:02 DEBUG : Cache remote TestInternalCache:ticsadcf1745121482: list ''
2025/04/20 03:58:02 DEBUG : : list: error: couldn't open bucket (ticsadcf1745121482)
2025/04/20 03:58:02 ERROR : : error listing: directory not found
2025/04/20 03:58:02 DEBUG : Cache remote TestInternalCache:ticsadcf1745121482: list ''
2025/04/20 03:58:02 DEBUG : : list: error: couldn't open bucket (ticsadcf1745121482)
2025/04/20 03:58:02 ERROR : Cache remote TestInternalCache:ticsadcf1745121482: Failed to list "": directory not found
2025/04/20 03:58:02 DEBUG : removing 1 level 0 directories
2025/04/20 03:58:02 INFO  : Cache remote TestInternalCache:ticsadcf1745121482: Removing directory
2025/04/20 03:58:02 DEBUG : Cache remote TestInternalCache:ticsadcf1745121482: rmdir ''
2025/04/20 03:58:02 ERROR : : Failed to rmdir: stat /tmp/TestInternalCache-local/ticsadcf1745121482: no such file or directory
2025/04/20 03:58:02 DEBUG : Cache remote TestInternalCache:ticsadcf1745121482: mkdir ''
2025/04/20 03:58:02 DEBUG : : mkdir: created dir in source fs
2025/04/20 03:58:02 DEBUG : : mkdir: added to cache
2025/04/20 03:58:02 DEBUG : : cache: expired ticsadcf1745121482
2025/04/20 03:58:02 INFO  : : mkdir: cache expired
2025/04/20 03:58:02 DEBUG : Cache remote TestInternalCache:ticsadcf1745121482: put data at 'data.bin'
2025/04/20 03:58:02 DEBUG : data.bin: put: uploaded to remote fs
2025/04/20 03:58:02 DEBUG : data.bin: put: added to cache
2025/04/20 03:58:02 DEBUG : : cache: expired ticsadcf1745121482
2025/04/20 03:58:02 INFO  : : put: cache expired
2025/04/20 03:58:02 DEBUG : Cache remote TestInternalCache:ticsadcf1745121482: new object 'data.bin'
2025/04/20 03:58:02 DEBUG : data.bin: find: warm object: data.bin, expiring on: 2025-04-20 09:58:02.711664582 +0000 UTC
2025/04/20 03:58:02 DEBUG : Cache remote TestInternalCache:ticsadcf1745121482: new object 'data.bin'
2025/04/20 03:58:02 DEBUG : data.bin: find: warm object: data.bin, expiring on: 2025-04-20 09:58:02.711664582 +0000 UTC
2025/04/20 03:58:02 DEBUG : Cache remote TestInternalCache:ticsadcf1745121482: new object 'data.bin'
2025/04/20 03:58:02 DEBUG : data.bin: find: error: couldn't open parent bucket for ticsadcf1745121482
2025/04/20 03:58:02 DEBUG : data.bin: find: cached object
2025/04/20 03:58:02 DEBUG : Waiting for deletions to finish
2025/04/20 03:58:02 DEBUG : Cache remote TestInternalCache:ticsadcf1745121482: list ''
2025/04/20 03:58:02 DEBUG : : list: error: missing cached dir: 
2025/04/20 03:58:02 DEBUG : : list: read 1 from source
2025/04/20 03:58:02 DEBUG : : list: source entries: [data.bin]
2025/04/20 03:58:02 DEBUG : : list: cached object: data.bin
2025/04/20 03:58:02 DEBUG : : list: cached directories: 0
2025/04/20 03:58:02 DEBUG : : list: cached dir: 'ticsadcf1745121482', cache ts: 2025-04-20 03:58:02.719006792 +0000 UTC m=+3.424298255
2025/04/20 03:58:02 DEBUG : data.bin: removing object
2025/04/20 03:58:02 DEBUG : : cache: expired ticsadcf1745121482
2025/04/20 03:58:02 INFO  : data.bin: Deleted
2025/04/20 03:58:02 DEBUG : Cache remote TestInternalCache:ticsadcf1745121482: list ''
2025/04/20 03:58:02 DEBUG : : list: cold listing: 2025-04-19 21:58:02.729190737 +0000 UTC
2025/04/20 03:58:02 DEBUG : : list: read 0 from source
2025/04/20 03:58:02 DEBUG : : list: source entries: []
2025/04/20 03:58:02 DEBUG : : list: cached directories: 0
2025/04/20 03:58:02 DEBUG : : list: cached dir: 'ticsadcf1745121482', cache ts: 2025-04-20 03:58:02.730435153 +0000 UTC m=+3.435726625
2025/04/20 03:58:02 DEBUG : removing 1 level 0 directories
2025/04/20 03:58:02 INFO  : Cache remote TestInternalCache:ticsadcf1745121482: Removing directory
2025/04/20 03:58:02 DEBUG : Cache remote TestInternalCache:ticsadcf1745121482: rmdir ''
2025/04/20 03:58:02 DEBUG : : rmdir: removed dir in source fs
2025/04/20 03:58:02 DEBUG : : rmdir: removed from cache
2025/04/20 03:58:02 INFO  : : rmdir: cache expired
2025/04/20 03:58:02 DEBUG : Cache remote TestInternalCache:ticsadcf1745121482: Services stopped
--- PASS: TestInternalChangeSeenAfterDirCacheFlush (0.55s)
=== RUN   TestInternalCacheWrites
2025/04/20 03:58:02 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2025/04/20 03:58:02 DEBUG : Creating backend with remote "TestInternalCache-local:/tmp/TestInternalCache-local/ticw"
2025/04/20 03:58:02 DEBUG : TestInternalCache: wrapped TestInternalCache-local:/tmp/TestInternalCache-local/ticw at root ticw
2025/04/20 03:58:02 INFO  : TestInternalCache: Cache DB path: /home/rclone/.cache/rclone/cache-backend/TestInternalCache.db
2025/04/20 03:58:02 INFO  : TestInternalCache: Cache chunk path: /home/rclone/.cache/rclone/cache-backend/TestInternalCache
2025/04/20 03:58:02 INFO  : TestInternalCache: Chunk Memory: true
2025/04/20 03:58:02 INFO  : TestInternalCache: Chunk Size: 5Mi
2025/04/20 03:58:02 INFO  : TestInternalCache: Chunk Total Size: 10Gi
2025/04/20 03:58:02 INFO  : TestInternalCache: Chunk Clean Interval: 1m0s
2025/04/20 03:58:02 INFO  : TestInternalCache: Workers: 4
2025/04/20 03:58:02 INFO  : TestInternalCache: File Age: 6h0m0s
2025/04/20 03:58:02 INFO  : TestInternalCache: Cache Writes: enabled
2025/04/20 03:58:02 DEBUG : Waiting for deletions to finish
2025/04/20 03:58:02 DEBUG : Cache remote TestInternalCache:ticw: list ''
2025/04/20 03:58:02 DEBUG : : list: error: couldn't open bucket (ticw)
2025/04/20 03:58:02 ERROR : : error listing: directory not found
2025/04/20 03:58:02 DEBUG : Cache remote TestInternalCache:ticw: list ''
2025/04/20 03:58:02 DEBUG : : list: error: couldn't open bucket (ticw)
2025/04/20 03:58:02 ERROR : Cache remote TestInternalCache:ticw: Failed to list "": directory not found
2025/04/20 03:58:02 DEBUG : removing 1 level 0 directories
2025/04/20 03:58:02 INFO  : Cache remote TestInternalCache:ticw: Removing directory
2025/04/20 03:58:02 DEBUG : Cache remote TestInternalCache:ticw: rmdir ''
2025/04/20 03:58:02 ERROR : : Failed to rmdir: stat /tmp/TestInternalCache-local/ticw: no such file or directory
2025/04/20 03:58:02 DEBUG : Cache remote TestInternalCache:ticw: mkdir ''
2025/04/20 03:58:02 DEBUG : : mkdir: created dir in source fs
2025/04/20 03:58:02 DEBUG : : mkdir: added to cache
2025/04/20 03:58:02 DEBUG : : cache: expired ticw
2025/04/20 03:58:02 INFO  : : mkdir: cache expired
2025/04/20 03:58:03 DEBUG : Cache remote TestInternalCache:ticw: put data at 'data.bin'
2025/04/20 03:58:03 DEBUG : data.bin: put: uploaded to remote fs and saved in cache
2025/04/20 03:58:03 DEBUG : data.bin: put: added to cache
2025/04/20 03:58:03 DEBUG : : cache: expired ticw
2025/04/20 03:58:03 INFO  : : put: cache expired
2025/04/20 03:58:03 DEBUG : Cache remote TestInternalCache:ticw: new object 'data.bin'
2025/04/20 03:58:03 DEBUG : data.bin: find: warm object: data.bin, expiring on: 2025-04-20 09:58:03.296588833 +0000 UTC
2025/04/20 03:58:03 DEBUG : Waiting for deletions to finish
2025/04/20 03:58:03 DEBUG : Cache remote TestInternalCache:ticw: list ''
2025/04/20 03:58:03 DEBUG : : list: cold listing: 2025-04-19 21:58:03.305874221 +0000 UTC
2025/04/20 03:58:03 DEBUG : : list: read 1 from source
2025/04/20 03:58:03 DEBUG : : list: source entries: [data.bin]
2025/04/20 03:58:03 DEBUG : : list: cached object: data.bin
2025/04/20 03:58:03 DEBUG : : list: cached directories: 0
2025/04/20 03:58:03 DEBUG : : list: cached dir: 'ticw', cache ts: 2025-04-20 03:58:03.308869252 +0000 UTC m=+4.014160714
2025/04/20 03:58:03 DEBUG : data.bin: removing object
2025/04/20 03:58:03 DEBUG : : cache: expired ticw
2025/04/20 03:58:03 INFO  : data.bin: Deleted
2025/04/20 03:58:03 DEBUG : Cache remote TestInternalCache:ticw: list ''
2025/04/20 03:58:03 DEBUG : : list: cold listing: 2025-04-19 21:58:03.319956702 +0000 UTC
2025/04/20 03:58:03 DEBUG : : list: read 0 from source
2025/04/20 03:58:03 DEBUG : : list: source entries: []
2025/04/20 03:58:03 DEBUG : : list: cached directories: 0
2025/04/20 03:58:03 DEBUG : : list: cached dir: 'ticw', cache ts: 2025-04-20 03:58:03.321476645 +0000 UTC m=+4.026768108
2025/04/20 03:58:03 DEBUG : removing 1 level 0 directories
2025/04/20 03:58:03 INFO  : Cache remote TestInternalCache:ticw: Removing directory
2025/04/20 03:58:03 DEBUG : Cache remote TestInternalCache:ticw: rmdir ''
2025/04/20 03:58:03 DEBUG : : rmdir: removed dir in source fs
2025/04/20 03:58:03 DEBUG : : rmdir: removed from cache
2025/04/20 03:58:03 INFO  : : rmdir: cache expired
2025/04/20 03:58:03 DEBUG : Cache remote TestInternalCache:ticw: Services stopped
--- PASS: TestInternalCacheWrites (0.59s)
=== RUN   TestInternalMaxChunkSizeRespected
2025/04/20 03:58:03 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2025/04/20 03:58:03 DEBUG : Creating backend with remote "TestInternalCache-local:/tmp/TestInternalCache-local/timcsr1745121483"
2025/04/20 03:58:03 DEBUG : TestInternalCache: wrapped TestInternalCache-local:/tmp/TestInternalCache-local/timcsr1745121483 at root timcsr1745121483
2025/04/20 03:58:03 INFO  : TestInternalCache: Cache DB path: /home/rclone/.cache/rclone/cache-backend/TestInternalCache.db
2025/04/20 03:58:03 INFO  : TestInternalCache: Cache chunk path: /home/rclone/.cache/rclone/cache-backend/TestInternalCache
2025/04/20 03:58:03 INFO  : TestInternalCache: Chunk Memory: true
2025/04/20 03:58:03 INFO  : TestInternalCache: Chunk Size: 5Mi
2025/04/20 03:58:03 INFO  : TestInternalCache: Chunk Total Size: 10Gi
2025/04/20 03:58:03 INFO  : TestInternalCache: Chunk Clean Interval: 1m0s
2025/04/20 03:58:03 INFO  : TestInternalCache: Workers: 1
2025/04/20 03:58:03 INFO  : TestInternalCache: File Age: 6h0m0s
2025/04/20 03:58:03 DEBUG : Waiting for deletions to finish
2025/04/20 03:58:03 DEBUG : Cache remote TestInternalCache:timcsr1745121483: list ''
2025/04/20 03:58:03 DEBUG : : list: error: couldn't open bucket (timcsr1745121483)
2025/04/20 03:58:03 ERROR : : error listing: directory not found
2025/04/20 03:58:03 DEBUG : Cache remote TestInternalCache:timcsr1745121483: list ''
2025/04/20 03:58:03 DEBUG : : list: error: couldn't open bucket (timcsr1745121483)
2025/04/20 03:58:03 ERROR : Cache remote TestInternalCache:timcsr1745121483: Failed to list "": directory not found
2025/04/20 03:58:03 DEBUG : removing 1 level 0 directories
2025/04/20 03:58:03 INFO  : Cache remote TestInternalCache:timcsr1745121483: Removing directory
2025/04/20 03:58:03 DEBUG : Cache remote TestInternalCache:timcsr1745121483: rmdir ''
2025/04/20 03:58:03 ERROR : : Failed to rmdir: stat /tmp/TestInternalCache-local/timcsr1745121483: no such file or directory
2025/04/20 03:58:03 DEBUG : Cache remote TestInternalCache:timcsr1745121483: mkdir ''
2025/04/20 03:58:03 DEBUG : : mkdir: created dir in source fs
2025/04/20 03:58:03 DEBUG : : mkdir: added to cache
2025/04/20 03:58:03 DEBUG : : cache: expired timcsr1745121483
2025/04/20 03:58:03 INFO  : : mkdir: cache expired
2025/04/20 03:58:05 DEBUG : Cache remote TestInternalCache:timcsr1745121483: put data at 'data.bin'
2025/04/20 03:58:05 DEBUG : data.bin: put: uploaded to remote fs
2025/04/20 03:58:05 DEBUG : data.bin: put: added to cache
2025/04/20 03:58:05 DEBUG : : cache: expired timcsr1745121483
2025/04/20 03:58:05 INFO  : : put: cache expired
2025/04/20 03:58:05 DEBUG : Cache remote TestInternalCache:timcsr1745121483: new object 'data.bin'
2025/04/20 03:58:05 DEBUG : data.bin: find: warm object: data.bin, expiring on: 2025-04-20 09:58:05.517565331 +0000 UTC
2025/04/20 03:58:05 DEBUG : Cache remote TestInternalCache:timcsr1745121483: new object 'data.bin'
2025/04/20 03:58:05 DEBUG : data.bin: find: warm object: data.bin, expiring on: 2025-04-20 09:58:05.517565331 +0000 UTC
2025/04/20 03:58:05 DEBUG : timcsr1745121483/data.bin: moving offset set from 0 to 0
2025/04/20 03:58:05 DEBUG : timcsr1745121483/data.bin: 0: chunk retry storage: 0
2025/04/20 03:58:05 DEBUG : worker-0 <data.bin>: downloaded chunk 0
2025/04/20 03:58:06 DEBUG : timcsr1745121483/data.bin: cache reader closed 5242880
2025/04/20 03:58:06 DEBUG : timcsr1745121483/data.bin: moving offset set from 0 to 5242880
2025/04/20 03:58:06 DEBUG : timcsr1745121483/data.bin: 5242880: chunk retry storage: 0
2025/04/20 03:58:06 DEBUG : worker-0 <data.bin>: downloaded chunk 5242880
2025/04/20 03:58:06 DEBUG : timcsr1745121483/data.bin: cache reader closed 10485760
2025/04/20 03:58:06 DEBUG : timcsr1745121483/data.bin: moving offset set from 0 to 10485760
2025/04/20 03:58:06 DEBUG : timcsr1745121483/data.bin: 10485760: chunk retry storage: 0
2025/04/20 03:58:06 DEBUG : worker-0 <data.bin>: downloaded chunk 10485760
2025/04/20 03:58:07 DEBUG : timcsr1745121483/data.bin: cache reader closed 15728640
2025/04/20 03:58:07 DEBUG : timcsr1745121483/data.bin: moving offset set from 0 to 15728640
2025/04/20 03:58:07 DEBUG : timcsr1745121483/data.bin: 15728640: chunk retry storage: 0
2025/04/20 03:58:07 DEBUG : worker-0 <data.bin>: downloaded chunk 15728640
2025/04/20 03:58:07 DEBUG : timcsr1745121483/data.bin: cache reader closed 20971520
2025/04/20 03:58:07 DEBUG : timcsr1745121483/data.bin: moving offset set from 0 to 20971520
2025/04/20 03:58:07 DEBUG : timcsr1745121483/data.bin: 20971520: chunk retry storage: 0
2025/04/20 03:58:07 DEBUG : worker-0 <data.bin>: downloaded chunk 20971520
2025/04/20 03:58:08 DEBUG : timcsr1745121483/data.bin: cache reader closed 26214400
2025/04/20 03:58:08 DEBUG : timcsr1745121483/data.bin: moving offset set from 0 to 26214400
2025/04/20 03:58:08 DEBUG : timcsr1745121483/data.bin: 26214400: chunk retry storage: 0
2025/04/20 03:58:08 DEBUG : worker-0 <data.bin>: downloaded chunk 26214400
2025/04/20 03:58:08 DEBUG : timcsr1745121483/data.bin: cache reader closed 31457280
2025/04/20 03:58:08 DEBUG : Waiting for deletions to finish
2025/04/20 03:58:08 DEBUG : Cache remote TestInternalCache:timcsr1745121483: list ''
2025/04/20 03:58:08 DEBUG : : list: cold listing: 2025-04-19 21:58:05.519461229 +0000 UTC
2025/04/20 03:58:08 DEBUG : : list: read 1 from source
2025/04/20 03:58:08 DEBUG : : list: source entries: [data.bin]
2025/04/20 03:58:08 DEBUG : : list: cached object: data.bin
2025/04/20 03:58:08 DEBUG : : list: cached directories: 0
2025/04/20 03:58:08 DEBUG : : list: cached dir: 'timcsr1745121483', cache ts: 2025-04-20 03:58:08.756750467 +0000 UTC m=+9.462041930
2025/04/20 03:58:08 DEBUG : data.bin: removing object
2025/04/20 03:58:08 DEBUG : : cache: expired timcsr1745121483
2025/04/20 03:58:08 INFO  : data.bin: Deleted
2025/04/20 03:58:08 DEBUG : Cache remote TestInternalCache:timcsr1745121483: list ''
2025/04/20 03:58:08 DEBUG : : list: cold listing: 2025-04-19 21:58:08.770431076 +0000 UTC
2025/04/20 03:58:08 DEBUG : : list: read 0 from source
2025/04/20 03:58:08 DEBUG : : list: source entries: []
2025/04/20 03:58:08 DEBUG : : list: cached directories: 0
2025/04/20 03:58:08 DEBUG : : list: cached dir: 'timcsr1745121483', cache ts: 2025-04-20 03:58:08.771988028 +0000 UTC m=+9.477279480
2025/04/20 03:58:08 DEBUG : removing 1 level 0 directories
2025/04/20 03:58:08 INFO  : Cache remote TestInternalCache:timcsr1745121483: Removing directory
2025/04/20 03:58:08 DEBUG : Cache remote TestInternalCache:timcsr1745121483: rmdir ''
2025/04/20 03:58:08 DEBUG : : rmdir: removed dir in source fs
2025/04/20 03:58:08 DEBUG : : rmdir: removed from cache
2025/04/20 03:58:08 INFO  : : rmdir: cache expired
2025/04/20 03:58:08 DEBUG : Cache remote TestInternalCache:timcsr1745121483: Services stopped
--- PASS: TestInternalMaxChunkSizeRespected (5.46s)
=== RUN   TestInternalExpiredEntriesRemoved
2025/04/20 03:58:08 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/20 03:58:08 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2025/04/20 03:58:08 DEBUG : Creating backend with remote "TestInternalCache-local:/tmp/TestInternalCache-local/tib21171745121488"
2025/04/20 03:58:08 DEBUG : TestInternalCache: wrapped TestInternalCache-local:/tmp/TestInternalCache-local/tib21171745121488 at root tib21171745121488
2025/04/20 03:58:08 INFO  : TestInternalCache: Cache DB path: /home/rclone/.cache/rclone/cache-backend/TestInternalCache.db
2025/04/20 03:58:08 INFO  : TestInternalCache: Cache chunk path: /home/rclone/.cache/rclone/cache-backend/TestInternalCache
2025/04/20 03:58:08 INFO  : TestInternalCache: Chunk Memory: true
2025/04/20 03:58:08 INFO  : TestInternalCache: Chunk Size: 5Mi
2025/04/20 03:58:08 INFO  : TestInternalCache: Chunk Total Size: 10Gi
2025/04/20 03:58:08 INFO  : TestInternalCache: Chunk Clean Interval: 15m0s
2025/04/20 03:58:08 INFO  : TestInternalCache: Workers: 4
2025/04/20 03:58:08 INFO  : TestInternalCache: File Age: 3d
2025/04/20 03:58:08 DEBUG : Waiting for deletions to finish
2025/04/20 03:58:08 DEBUG : Cache remote TestInternalCache:tib21171745121488: list ''
2025/04/20 03:58:08 DEBUG : : list: error: couldn't open bucket (tib21171745121488)
2025/04/20 03:58:08 ERROR : : error listing: directory not found
2025/04/20 03:58:08 DEBUG : Cache remote TestInternalCache:tib21171745121488: list ''
2025/04/20 03:58:08 DEBUG : : list: error: couldn't open bucket (tib21171745121488)
2025/04/20 03:58:08 ERROR : Cache remote TestInternalCache:tib21171745121488: Failed to list "": directory not found
2025/04/20 03:58:08 DEBUG : removing 1 level 0 directories
2025/04/20 03:58:08 INFO  : Cache remote TestInternalCache:tib21171745121488: Removing directory
2025/04/20 03:58:08 DEBUG : Cache remote TestInternalCache:tib21171745121488: rmdir ''
2025/04/20 03:58:08 ERROR : : Failed to rmdir: stat /tmp/TestInternalCache-local/tib21171745121488: no such file or directory
2025/04/20 03:58:08 DEBUG : Cache remote TestInternalCache:tib21171745121488: mkdir ''
2025/04/20 03:58:08 DEBUG : : mkdir: created dir in source fs
2025/04/20 03:58:08 DEBUG : : mkdir: added to cache
2025/04/20 03:58:08 DEBUG : : cache: expired tib21171745121488
2025/04/20 03:58:08 INFO  : : mkdir: cache expired
2025/04/20 03:58:08 DEBUG : Cache remote TestInternalCache:tib21171745121488: list 'test/dir1/dir2'
2025/04/20 03:58:08 DEBUG : test/dir1/dir2: list: error: couldn't open bucket (tib21171745121488/test/dir1/dir2)
2025/04/20 03:58:08 DEBUG : test/dir1/dir2: list: read 1 from source
2025/04/20 03:58:08 DEBUG : test/dir1/dir2: list: source entries: [test/dir1/dir2/test.txt]
2025/04/20 03:58:08 DEBUG : test/dir1/dir2: list: cached object: test/dir1/dir2/test.txt
2025/04/20 03:58:08 DEBUG : test/dir1/dir2: list: cached directories: 0
2025/04/20 03:58:08 DEBUG : test/dir1/dir2: list: cached dir: 'tib21171745121488/test/dir1/dir2', cache ts: 2025-04-20 03:58:08.799066601 +0000 UTC m=+9.504358043
2025/04/20 03:58:08 NOTICE: len: 1
2025/04/20 03:58:38 DEBUG : Cache remote TestInternalCache:tib21171745121488: list 'test/dir1/dir2'
2025/04/20 03:58:38 DEBUG : test/dir1/dir2: list: warm 1 from cache for: tib21171745121488/test/dir1/dir2, expiring on: 2025-04-23 03:58:08.799066601 +0000 UTC
2025/04/20 03:58:38 DEBUG : test/dir1/dir2: list: cached entries: [test/dir1/dir2/test.txt]
2025/04/20 03:58:38 NOTICE: len: 1
2025/04/20 03:58:38 DEBUG : Cache remote TestInternalCache:tib21171745121488: list 'test/dir1'
2025/04/20 03:58:38 DEBUG : test/dir1: list: error: missing cached dir: test/dir1
2025/04/20 03:58:38 DEBUG : test/dir1: list: read 4 from source
2025/04/20 03:58:38 DEBUG : test/dir1: list: source entries: [test/dir1/dir3 test/dir1/dir2 test/dir1/dir4 test/dir1/dir1]
2025/04/20 03:58:38 DEBUG : test/dir1: list: cached directories: 4
2025/04/20 03:58:38 DEBUG : test/dir1: list: cached dir: 'tib21171745121488/test/dir1', cache ts: 2025-04-20 03:58:38.802863961 +0000 UTC m=+39.508155403
2025/04/20 03:58:38 NOTICE: len: 4
2025/04/20 03:58:38 DEBUG : Cache remote TestInternalCache:tib21171745121488: list 'test'
2025/04/20 03:58:38 DEBUG : test: list: error: missing cached dir: test
2025/04/20 03:58:38 DEBUG : test: list: read 4 from source
2025/04/20 03:58:38 DEBUG : test: list: source entries: [test/dir3 test/dir2 test/dir4 test/dir1]
2025/04/20 03:58:38 DEBUG : test: list: cached directories: 4
2025/04/20 03:58:38 DEBUG : test: list: cached dir: 'tib21171745121488/test', cache ts: 2025-04-20 03:58:38.806012389 +0000 UTC m=+39.511303831
2025/04/20 03:58:38 NOTICE: len: 4
2025/04/20 03:58:38 DEBUG : Waiting for deletions to finish
2025/04/20 03:58:38 DEBUG : Cache remote TestInternalCache:tib21171745121488: list ''
2025/04/20 03:58:38 DEBUG : : list: cold listing: 2025-04-17 03:58:08.794951017 +0000 UTC
2025/04/20 03:58:38 DEBUG : : list: read 1 from source
2025/04/20 03:58:38 DEBUG : : list: source entries: [test]
2025/04/20 03:58:38 DEBUG : : list: cached directories: 1
2025/04/20 03:58:38 DEBUG : : list: cached dir: 'tib21171745121488', cache ts: 2025-04-20 03:58:38.808893497 +0000 UTC m=+39.514184948
2025/04/20 03:58:38 DEBUG : Cache remote TestInternalCache:tib21171745121488: list 'test'
2025/04/20 03:58:38 DEBUG : test: list: warm 4 from cache for: tib21171745121488/test, expiring on: 2025-04-23 03:58:38.80744594 +0000 UTC
2025/04/20 03:58:38 DEBUG : test: list: cached entries: [test/dir1 test/dir2 test/dir3 test/dir4]
2025/04/20 03:58:38 DEBUG : Cache remote TestInternalCache:tib21171745121488: list 'test/dir4'
2025/04/20 03:58:38 DEBUG : test/dir4: list: empty listing
2025/04/20 03:58:38 DEBUG : test/dir4: list: read 4 from source
2025/04/20 03:58:38 DEBUG : test/dir4: list: source entries: [test/dir4/dir3 test/dir4/dir2 test/dir4/dir4 test/dir4/dir1]
2025/04/20 03:58:38 DEBUG : Cache remote TestInternalCache:tib21171745121488: list 'test/dir2'
2025/04/20 03:58:38 DEBUG : Cache remote TestInternalCache:tib21171745121488: list 'test/dir3'
2025/04/20 03:58:38 DEBUG : Cache remote TestInternalCache:tib21171745121488: list 'test/dir1'
2025/04/20 03:58:38 DEBUG : test/dir2: list: empty listing
2025/04/20 03:58:38 DEBUG : test/dir3: list: empty listing
2025/04/20 03:58:38 DEBUG : test/dir1: list: warm 4 from cache for: tib21171745121488/test/dir1, expiring on: 2025-04-23 03:58:38.804372532 +0000 UTC
2025/04/20 03:58:38 DEBUG : test/dir1: list: cached entries: [test/dir1/dir1 test/dir1/dir2 test/dir1/dir3 test/dir1/dir4]
2025/04/20 03:58:38 DEBUG : test/dir2: list: read 4 from source
2025/04/20 03:58:38 DEBUG : test/dir2: list: source entries: [test/dir2/dir3 test/dir2/dir2 test/dir2/dir4 test/dir2/dir1]
2025/04/20 03:58:38 DEBUG : Cache remote TestInternalCache:tib21171745121488: list 'test/dir1/dir4'
2025/04/20 03:58:38 DEBUG : test/dir3: list: read 4 from source
2025/04/20 03:58:38 DEBUG : test/dir1/dir4: list: empty listing
2025/04/20 03:58:38 DEBUG : test/dir3: list: source entries: [test/dir3/dir3 test/dir3/dir2 test/dir3/dir4 test/dir3/dir1]
2025/04/20 03:58:38 DEBUG : Cache remote TestInternalCache:tib21171745121488: list 'test/dir1/dir2'
2025/04/20 03:58:38 DEBUG : test/dir1/dir2: list: warm 1 from cache for: tib21171745121488/test/dir1/dir2, expiring on: 2025-04-23 03:58:38.801221026 +0000 UTC
2025/04/20 03:58:38 DEBUG : test/dir1/dir4: list: read 1 from source
2025/04/20 03:58:38 DEBUG : test/dir1/dir2: list: cached entries: [test/dir1/dir2/test.txt]
2025/04/20 03:58:38 DEBUG : test/dir1/dir4: list: source entries: [test/dir1/dir4/test.txt]
2025/04/20 03:58:38 DEBUG : Cache remote TestInternalCache:tib21171745121488: list 'test/dir1/dir3'
2025/04/20 03:58:38 DEBUG : Cache remote TestInternalCache:tib21171745121488: list 'test/dir1/dir1'
2025/04/20 03:58:38 DEBUG : test/dir1/dir1: list: empty listing
2025/04/20 03:58:38 DEBUG : test/dir1/dir3: list: empty listing
2025/04/20 03:58:38 DEBUG : test/dir1/dir1: list: read 1 from source
2025/04/20 03:58:38 DEBUG : test/dir1/dir1: list: source entries: [test/dir1/dir1/test.txt]
2025/04/20 03:58:38 DEBUG : test/dir1/dir3: list: read 1 from source
2025/04/20 03:58:38 DEBUG : test/dir1/dir3: list: source entries: [test/dir1/dir3/test.txt]
2025/04/20 03:58:38 DEBUG : test/dir4: list: cached directories: 4
2025/04/20 03:58:38 DEBUG : test/dir4: list: cached dir: 'tib21171745121488/test/dir4', cache ts: 2025-04-20 03:58:38.811989939 +0000 UTC m=+39.517281381
2025/04/20 03:58:38 DEBUG : Cache remote TestInternalCache:tib21171745121488: list 'test/dir4/dir3'
2025/04/20 03:58:38 DEBUG : test/dir4/dir3: list: empty listing
2025/04/20 03:58:38 DEBUG : test/dir4/dir3: list: read 1 from source
2025/04/20 03:58:38 DEBUG : test/dir4/dir3: list: source entries: [test/dir4/dir3/test.txt]
2025/04/20 03:58:38 DEBUG : Cache remote TestInternalCache:tib21171745121488: list 'test/dir4/dir1'
2025/04/20 03:58:38 DEBUG : test/dir4/dir1: list: empty listing
2025/04/20 03:58:38 DEBUG : test/dir4/dir1: list: read 1 from source
2025/04/20 03:58:38 DEBUG : test/dir4/dir1: list: source entries: [test/dir4/dir1/test.txt]
2025/04/20 03:58:38 DEBUG : Cache remote TestInternalCache:tib21171745121488: list 'test/dir4/dir2'
2025/04/20 03:58:38 DEBUG : test/dir4/dir2: list: empty listing
2025/04/20 03:58:38 DEBUG : test/dir4/dir2: list: read 1 from source
2025/04/20 03:58:38 DEBUG : test/dir4/dir2: list: source entries: [test/dir4/dir2/test.txt]
2025/04/20 03:58:38 DEBUG : test/dir2: list: cached directories: 4
2025/04/20 03:58:38 DEBUG : test/dir3: list: cached directories: 4
2025/04/20 03:58:38 DEBUG : test/dir1/dir4: list: cached object: test/dir1/dir4/test.txt
2025/04/20 03:58:38 DEBUG : test/dir1/dir4: list: cached directories: 0
2025/04/20 03:58:38 DEBUG : test/dir1/dir2/test.txt: removing object
2025/04/20 03:58:38 DEBUG : test/dir1/dir1: list: cached object: test/dir1/dir1/test.txt
2025/04/20 03:58:38 DEBUG : test/dir1/dir1: list: cached directories: 0
2025/04/20 03:58:38 DEBUG : test/dir1/dir3: list: cached object: test/dir1/dir3/test.txt
2025/04/20 03:58:38 DEBUG : test/dir1/dir3: list: cached directories: 0
2025/04/20 03:58:38 DEBUG : test/dir4/dir3: list: cached object: test/dir4/dir3/test.txt
2025/04/20 03:58:38 DEBUG : test/dir4/dir3: list: cached directories: 0
2025/04/20 03:58:38 DEBUG : test/dir4/dir1: list: cached object: test/dir4/dir1/test.txt
2025/04/20 03:58:38 DEBUG : test/dir4/dir1: list: cached directories: 0
2025/04/20 03:58:38 DEBUG : test/dir4/dir2: list: cached object: test/dir4/dir2/test.txt
2025/04/20 03:58:38 DEBUG : test/dir4/dir2: list: cached directories: 0
2025/04/20 03:58:38 DEBUG : test/dir2: list: cached dir: 'tib21171745121488/test/dir2', cache ts: 2025-04-20 03:58:38.81469738 +0000 UTC m=+39.519988822
2025/04/20 03:58:38 DEBUG : Cache remote TestInternalCache:tib21171745121488: list 'test/dir4/dir4'
2025/04/20 03:58:38 DEBUG : test/dir4/dir4: list: empty listing
2025/04/20 03:58:38 DEBUG : test/dir4/dir4: list: read 1 from source
2025/04/20 03:58:38 DEBUG : test/dir4/dir4: list: source entries: [test/dir4/dir4/test.txt]
2025/04/20 03:58:38 DEBUG : test/dir3: list: cached dir: 'tib21171745121488/test/dir3', cache ts: 2025-04-20 03:58:38.8160612 +0000 UTC m=+39.521352662
2025/04/20 03:58:38 DEBUG : Cache remote TestInternalCache:tib21171745121488: list 'test/dir2/dir1'
2025/04/20 03:58:38 DEBUG : test/dir2/dir1: list: empty listing
2025/04/20 03:58:38 DEBUG : test/dir2/dir1: list: read 1 from source
2025/04/20 03:58:38 DEBUG : test/dir2/dir1: list: source entries: [test/dir2/dir1/test.txt]
2025/04/20 03:58:38 DEBUG : test/dir1/dir4: list: cached dir: 'tib21171745121488/test/dir1/dir4', cache ts: 2025-04-20 03:58:38.817231686 +0000 UTC m=+39.522523129
2025/04/20 03:58:38 DEBUG : Cache remote TestInternalCache:tib21171745121488: list 'test/dir2/dir2'
2025/04/20 03:58:38 DEBUG : test/dir2/dir2: list: empty listing
2025/04/20 03:58:38 DEBUG : test/dir2/dir2: list: read 1 from source
2025/04/20 03:58:38 DEBUG : test/dir2/dir2: list: source entries: [test/dir2/dir2/test.txt]
2025/04/20 03:58:38 DEBUG : test/dir1/dir4/test.txt: removing object
2025/04/20 03:58:38 DEBUG : test/dir1/dir1: list: cached dir: 'tib21171745121488/test/dir1/dir1', cache ts: 2025-04-20 03:58:38.819515804 +0000 UTC m=+39.524807246
2025/04/20 03:58:38 DEBUG : Cache remote TestInternalCache:tib21171745121488: list 'test/dir2/dir3'
2025/04/20 03:58:38 DEBUG : test/dir2/dir3: list: empty listing
2025/04/20 03:58:38 DEBUG : test/dir2/dir3: list: read 1 from source
2025/04/20 03:58:38 DEBUG : test/dir2/dir3: list: source entries: [test/dir2/dir3/test.txt]
2025/04/20 03:58:38 DEBUG : test/dir1/dir1/test.txt: removing object
2025/04/20 03:58:38 DEBUG : test/dir1/dir3: list: cached dir: 'tib21171745121488/test/dir1/dir3', cache ts: 2025-04-20 03:58:38.820663328 +0000 UTC m=+39.525954770
2025/04/20 03:58:38 DEBUG : Cache remote TestInternalCache:tib21171745121488: list 'test/dir2/dir4'
2025/04/20 03:58:38 DEBUG : test/dir2/dir4: list: empty listing
2025/04/20 03:58:38 DEBUG : test/dir1/dir3/test.txt: removing object
2025/04/20 03:58:38 DEBUG : test/dir2/dir4: list: read 1 from source
2025/04/20 03:58:38 DEBUG : test/dir2/dir4: list: source entries: [test/dir2/dir4/test.txt]
2025/04/20 03:58:38 DEBUG : test/dir4/dir3: list: cached dir: 'tib21171745121488/test/dir4/dir3', cache ts: 2025-04-20 03:58:38.821709301 +0000 UTC m=+39.527000743
2025/04/20 03:58:38 DEBUG : Cache remote TestInternalCache:tib21171745121488: list 'test/dir3/dir1'
2025/04/20 03:58:38 DEBUG : test/dir3/dir1: list: empty listing
2025/04/20 03:58:38 DEBUG : test/dir3/dir1: list: read 1 from source
2025/04/20 03:58:38 DEBUG : test/dir3/dir1: list: source entries: [test/dir3/dir1/test.txt]
2025/04/20 03:58:38 DEBUG : test/dir4/dir3/test.txt: removing object
2025/04/20 03:58:38 DEBUG : test/dir4/dir1: list: cached dir: 'tib21171745121488/test/dir4/dir1', cache ts: 2025-04-20 03:58:38.82291309 +0000 UTC m=+39.528204543
2025/04/20 03:58:38 DEBUG : Cache remote TestInternalCache:tib21171745121488: list 'test/dir3/dir2'
2025/04/20 03:58:38 DEBUG : test/dir3/dir2: list: empty listing
2025/04/20 03:58:38 DEBUG : test/dir3/dir2: list: read 1 from source
2025/04/20 03:58:38 DEBUG : test/dir3/dir2: list: source entries: [test/dir3/dir2/test.txt]
2025/04/20 03:58:38 DEBUG : test/dir4/dir1/test.txt: removing object
2025/04/20 03:58:38 DEBUG : test/dir4/dir2: list: cached dir: 'tib21171745121488/test/dir4/dir2', cache ts: 2025-04-20 03:58:38.82395741 +0000 UTC m=+39.529248852
2025/04/20 03:58:38 DEBUG : Cache remote TestInternalCache:tib21171745121488: list 'test/dir3/dir3'
2025/04/20 03:58:38 DEBUG : test/dir3/dir3: list: empty listing
2025/04/20 03:58:38 DEBUG : test/dir3/dir3: list: read 1 from source
2025/04/20 03:58:38 DEBUG : test/dir3/dir3: list: source entries: [test/dir3/dir3/test.txt]
2025/04/20 03:58:38 DEBUG : test/dir4/dir2/test.txt: removing object
2025/04/20 03:58:38 DEBUG : test/dir4/dir4: list: cached object: test/dir4/dir4/test.txt
2025/04/20 03:58:38 DEBUG : test/dir4/dir4: list: cached directories: 0
2025/04/20 03:58:38 DEBUG : test/dir2/dir1: list: cached object: test/dir2/dir1/test.txt
2025/04/20 03:58:38 DEBUG : test/dir2/dir1: list: cached directories: 0
2025/04/20 03:58:38 DEBUG : test/dir2/dir2: list: cached object: test/dir2/dir2/test.txt
2025/04/20 03:58:38 DEBUG : test/dir2/dir2: list: cached directories: 0
2025/04/20 03:58:38 DEBUG : test/dir2/dir3: list: cached object: test/dir2/dir3/test.txt
2025/04/20 03:58:38 DEBUG : test/dir2/dir3: list: cached directories: 0
2025/04/20 03:58:38 DEBUG : test/dir2/dir4: list: cached object: test/dir2/dir4/test.txt
2025/04/20 03:58:38 DEBUG : test/dir2/dir4: list: cached directories: 0
2025/04/20 03:58:38 DEBUG : test/dir3/dir1: list: cached object: test/dir3/dir1/test.txt
2025/04/20 03:58:38 DEBUG : test/dir3/dir1: list: cached directories: 0
2025/04/20 03:58:38 DEBUG : test/dir3/dir2: list: cached object: test/dir3/dir2/test.txt
2025/04/20 03:58:38 DEBUG : test/dir3/dir2: list: cached directories: 0
2025/04/20 03:58:38 DEBUG : test/dir3/dir3: list: cached object: test/dir3/dir3/test.txt
2025/04/20 03:58:38 DEBUG : test/dir3/dir3: list: cached directories: 0
2025/04/20 03:58:38 DEBUG : test/dir4/dir4: list: cached dir: 'tib21171745121488/test/dir4/dir4', cache ts: 2025-04-20 03:58:38.83699454 +0000 UTC m=+39.542285982
2025/04/20 03:58:38 DEBUG : Cache remote TestInternalCache:tib21171745121488: list 'test/dir3/dir4'
2025/04/20 03:58:38 DEBUG : test/dir4/dir4/test.txt: removing object
2025/04/20 03:58:38 DEBUG : test/dir3/dir4: list: empty listing
2025/04/20 03:58:38 DEBUG : test/dir3/dir4: list: read 1 from source
2025/04/20 03:58:38 DEBUG : test/dir3/dir4: list: source entries: [test/dir3/dir4/test.txt]
2025/04/20 03:58:38 DEBUG : test/dir2/dir1: list: cached dir: 'tib21171745121488/test/dir2/dir1', cache ts: 2025-04-20 03:58:38.838139409 +0000 UTC m=+39.543430851
2025/04/20 03:58:38 DEBUG : test/dir1/dir2: cache: expired tib21171745121488/test/dir1/dir2
2025/04/20 03:58:38 DEBUG : test/dir1/dir2: cache: expired tib21171745121488/test/dir1
2025/04/20 03:58:38 DEBUG : test/dir1/dir2: cache: expired tib21171745121488/test
2025/04/20 03:58:38 DEBUG : test/dir1/dir2: cache: expired tib21171745121488
2025/04/20 03:58:38 DEBUG : test/dir2/dir2: list: cached dir: 'tib21171745121488/test/dir2/dir2', cache ts: 2025-04-20 03:58:38.839351353 +0000 UTC m=+39.544642806
2025/04/20 03:58:38 INFO  : test/dir1/dir2/test.txt: Deleted
2025/04/20 03:58:38 DEBUG : test/dir2/dir1/test.txt: removing object
2025/04/20 03:58:38 DEBUG : test/dir2/dir3: list: cached dir: 'tib21171745121488/test/dir2/dir3', cache ts: 2025-04-20 03:58:38.842509693 +0000 UTC m=+39.547801144
2025/04/20 03:58:38 DEBUG : test/dir2/dir4: list: cached dir: 'tib21171745121488/test/dir2/dir4', cache ts: 2025-04-20 03:58:38.84591872 +0000 UTC m=+39.551210172
2025/04/20 03:58:38 DEBUG : test/dir3/dir1: list: cached dir: 'tib21171745121488/test/dir3/dir1', cache ts: 2025-04-20 03:58:38.846989078 +0000 UTC m=+39.552280521
2025/04/20 03:58:38 DEBUG : test/dir3/dir2: list: cached dir: 'tib21171745121488/test/dir3/dir2', cache ts: 2025-04-20 03:58:38.849190431 +0000 UTC m=+39.554481882
2025/04/20 03:58:38 DEBUG : test/dir3/dir3: list: cached dir: 'tib21171745121488/test/dir3/dir3', cache ts: 2025-04-20 03:58:38.851257501 +0000 UTC m=+39.556548953
2025/04/20 03:58:38 DEBUG : test/dir3/dir4: list: cached object: test/dir3/dir4/test.txt
2025/04/20 03:58:38 DEBUG : test/dir3/dir4: list: cached directories: 0
2025/04/20 03:58:38 DEBUG : test/dir1/dir4: cache: expired tib21171745121488/test/dir1/dir4
2025/04/20 03:58:38 DEBUG : test/dir1/dir4: cache: expired tib21171745121488/test/dir1
2025/04/20 03:58:38 DEBUG : test/dir1/dir4: cache: expired tib21171745121488/test
2025/04/20 03:58:38 DEBUG : test/dir1/dir4: cache: expired tib21171745121488
2025/04/20 03:58:38 INFO  : test/dir1/dir4/test.txt: Deleted
2025/04/20 03:58:38 DEBUG : test/dir2/dir2/test.txt: removing object
2025/04/20 03:58:38 DEBUG : test/dir3/dir4: list: cached dir: 'tib21171745121488/test/dir3/dir4', cache ts: 2025-04-20 03:58:38.868999089 +0000 UTC m=+39.574290552
2025/04/20 03:58:38 DEBUG : test/dir1/dir1: cache: expired tib21171745121488/test/dir1/dir1
2025/04/20 03:58:38 DEBUG : test/dir1/dir1: cache: expired tib21171745121488/test/dir1
2025/04/20 03:58:38 DEBUG : test/dir1/dir1: cache: expired tib21171745121488/test
2025/04/20 03:58:38 DEBUG : test/dir1/dir1: cache: expired tib21171745121488
2025/04/20 03:58:38 INFO  : test/dir1/dir1/test.txt: Deleted
2025/04/20 03:58:38 DEBUG : test/dir2/dir3/test.txt: removing object
2025/04/20 03:58:38 DEBUG : test/dir1/dir3: cache: expired tib21171745121488/test/dir1/dir3
2025/04/20 03:58:38 DEBUG : test/dir1/dir3: cache: expired tib21171745121488/test/dir1
2025/04/20 03:58:38 DEBUG : test/dir1/dir3: cache: expired tib21171745121488/test
2025/04/20 03:58:38 DEBUG : test/dir1/dir3: cache: expired tib21171745121488
2025/04/20 03:58:38 INFO  : test/dir1/dir3/test.txt: Deleted
2025/04/20 03:58:38 DEBUG : test/dir2/dir4/test.txt: removing object
2025/04/20 03:58:38 DEBUG : test/dir4/dir3: cache: expired tib21171745121488/test/dir4/dir3
2025/04/20 03:58:38 DEBUG : test/dir4/dir3: cache: expired tib21171745121488/test/dir4
2025/04/20 03:58:38 DEBUG : test/dir4/dir3: cache: expired tib21171745121488/test
2025/04/20 03:58:38 DEBUG : test/dir4/dir3: cache: expired tib21171745121488
2025/04/20 03:58:38 INFO  : test/dir4/dir3/test.txt: Deleted
2025/04/20 03:58:38 DEBUG : test/dir3/dir1/test.txt: removing object
2025/04/20 03:58:38 DEBUG : test/dir4/dir1: cache: expired tib21171745121488/test/dir4/dir1
2025/04/20 03:58:38 DEBUG : test/dir4/dir1: cache: expired tib21171745121488/test/dir4
2025/04/20 03:58:38 DEBUG : test/dir4/dir1: cache: expired tib21171745121488/test
2025/04/20 03:58:38 DEBUG : test/dir4/dir1: cache: expired tib21171745121488
2025/04/20 03:58:38 INFO  : test/dir4/dir1/test.txt: Deleted
2025/04/20 03:58:38 DEBUG : test/dir3/dir2/test.txt: removing object
2025/04/20 03:58:38 DEBUG : test/dir4/dir2: cache: expired tib21171745121488/test/dir4/dir2
2025/04/20 03:58:38 DEBUG : test/dir4/dir2: cache: expired tib21171745121488/test/dir4
2025/04/20 03:58:38 DEBUG : test/dir4/dir2: cache: expired tib21171745121488/test
2025/04/20 03:58:38 DEBUG : test/dir4/dir2: cache: expired tib21171745121488
2025/04/20 03:58:38 INFO  : test/dir4/dir2/test.txt: Deleted
2025/04/20 03:58:38 DEBUG : test/dir3/dir3/test.txt: removing object
2025/04/20 03:58:38 DEBUG : test/dir4/dir4: cache: expired tib21171745121488/test/dir4/dir4
2025/04/20 03:58:38 DEBUG : test/dir4/dir4: cache: expired tib21171745121488/test/dir4
2025/04/20 03:58:38 DEBUG : test/dir4/dir4: cache: expired tib21171745121488/test
2025/04/20 03:58:38 DEBUG : test/dir4/dir4: cache: expired tib21171745121488
2025/04/20 03:58:38 INFO  : test/dir4/dir4/test.txt: Deleted
2025/04/20 03:58:38 DEBUG : test/dir3/dir4/test.txt: removing object
2025/04/20 03:58:38 DEBUG : test/dir2/dir1: cache: expired tib21171745121488/test/dir2/dir1
2025/04/20 03:58:38 DEBUG : test/dir2/dir1: cache: expired tib21171745121488/test/dir2
2025/04/20 03:58:38 DEBUG : test/dir2/dir1: cache: expired tib21171745121488/test
2025/04/20 03:58:38 DEBUG : test/dir2/dir1: cache: expired tib21171745121488
2025/04/20 03:58:38 INFO  : test/dir2/dir1/test.txt: Deleted
2025/04/20 03:58:38 DEBUG : test/dir2/dir2: cache: expired tib21171745121488/test/dir2/dir2
2025/04/20 03:58:38 DEBUG : test/dir2/dir2: cache: expired tib21171745121488/test/dir2
2025/04/20 03:58:38 DEBUG : test/dir2/dir2: cache: expired tib21171745121488/test
2025/04/20 03:58:38 DEBUG : test/dir2/dir2: cache: expired tib21171745121488
2025/04/20 03:58:38 INFO  : test/dir2/dir2/test.txt: Deleted
2025/04/20 03:58:38 DEBUG : test/dir2/dir3: cache: expired tib21171745121488/test/dir2/dir3
2025/04/20 03:58:38 DEBUG : test/dir2/dir3: cache: expired tib21171745121488/test/dir2
2025/04/20 03:58:38 DEBUG : test/dir2/dir3: cache: expired tib21171745121488/test
2025/04/20 03:58:38 DEBUG : test/dir2/dir3: cache: expired tib21171745121488
2025/04/20 03:58:38 INFO  : test/dir2/dir3/test.txt: Deleted
2025/04/20 03:58:38 DEBUG : test/dir2/dir4: cache: expired tib21171745121488/test/dir2/dir4
2025/04/20 03:58:38 DEBUG : test/dir2/dir4: cache: expired tib21171745121488/test/dir2
2025/04/20 03:58:38 DEBUG : test/dir2/dir4: cache: expired tib21171745121488/test
2025/04/20 03:58:38 DEBUG : test/dir2/dir4: cache: expired tib21171745121488
2025/04/20 03:58:38 INFO  : test/dir2/dir4/test.txt: Deleted
2025/04/20 03:58:38 DEBUG : test/dir3/dir1: cache: expired tib21171745121488/test/dir3/dir1
2025/04/20 03:58:38 DEBUG : test/dir3/dir1: cache: expired tib21171745121488/test/dir3
2025/04/20 03:58:38 DEBUG : test/dir3/dir1: cache: expired tib21171745121488/test
2025/04/20 03:58:38 DEBUG : test/dir3/dir1: cache: expired tib21171745121488
2025/04/20 03:58:38 INFO  : test/dir3/dir1/test.txt: Deleted
2025/04/20 03:58:38 DEBUG : test/dir3/dir3: cache: expired tib21171745121488/test/dir3/dir3
2025/04/20 03:58:38 DEBUG : test/dir3/dir3: cache: expired tib21171745121488/test/dir3
2025/04/20 03:58:38 DEBUG : test/dir3/dir3: cache: expired tib21171745121488/test
2025/04/20 03:58:38 DEBUG : test/dir3/dir3: cache: expired tib21171745121488
2025/04/20 03:58:38 INFO  : test/dir3/dir3/test.txt: Deleted
2025/04/20 03:58:38 DEBUG : test/dir3/dir2: cache: expired tib21171745121488/test/dir3/dir2
2025/04/20 03:58:38 DEBUG : test/dir3/dir2: cache: expired tib21171745121488/test/dir3
2025/04/20 03:58:38 DEBUG : test/dir3/dir2: cache: expired tib21171745121488/test
2025/04/20 03:58:38 DEBUG : test/dir3/dir2: cache: expired tib21171745121488
2025/04/20 03:58:38 INFO  : test/dir3/dir2/test.txt: Deleted
2025/04/20 03:58:38 DEBUG : test/dir3/dir4: cache: expired tib21171745121488/test/dir3/dir4
2025/04/20 03:58:38 DEBUG : test/dir3/dir4: cache: expired tib21171745121488/test/dir3
2025/04/20 03:58:38 DEBUG : test/dir3/dir4: cache: expired tib21171745121488/test
2025/04/20 03:58:38 DEBUG : test/dir3/dir4: cache: expired tib21171745121488
2025/04/20 03:58:38 INFO  : test/dir3/dir4/test.txt: Deleted
2025/04/20 03:58:38 DEBUG : Cache remote TestInternalCache:tib21171745121488: list ''
2025/04/20 03:58:38 DEBUG : : list: cold listing: 2025-04-17 03:58:38.927347245 +0000 UTC
2025/04/20 03:58:38 DEBUG : : list: read 1 from source
2025/04/20 03:58:38 DEBUG : : list: source entries: [test]
2025/04/20 03:58:38 DEBUG : : list: cached directories: 0
2025/04/20 03:58:38 DEBUG : : list: cached dir: 'tib21171745121488', cache ts: 2025-04-20 03:58:38.928848332 +0000 UTC m=+39.634139774
2025/04/20 03:58:38 DEBUG : Cache remote TestInternalCache:tib21171745121488: list 'test'
2025/04/20 03:58:38 DEBUG : test: list: cold listing: 2025-04-17 03:58:38.927347245 +0000 UTC
2025/04/20 03:58:38 DEBUG : test: list: read 4 from source
2025/04/20 03:58:38 DEBUG : test: list: source entries: [test/dir3 test/dir2 test/dir4 test/dir1]
2025/04/20 03:58:38 DEBUG : test: list: cached directories: 0
2025/04/20 03:58:38 DEBUG : test: list: cached dir: 'tib21171745121488/test', cache ts: 2025-04-20 03:58:38.930439198 +0000 UTC m=+39.635730690
2025/04/20 03:58:38 DEBUG : Cache remote TestInternalCache:tib21171745121488: list 'test/dir4'
2025/04/20 03:58:38 DEBUG : Cache remote TestInternalCache:tib21171745121488: list 'test/dir3'
2025/04/20 03:58:38 DEBUG : test/dir4: list: cold listing: 2025-04-17 03:58:38.8952922 +0000 UTC
2025/04/20 03:58:38 DEBUG : test/dir3: list: cold listing: 2025-04-17 03:58:38.927347245 +0000 UTC
2025/04/20 03:58:38 DEBUG : test/dir4: list: read 4 from source
2025/04/20 03:58:38 DEBUG : test/dir4: list: source entries: [test/dir4/dir3 test/dir4/dir2 test/dir4/dir4 test/dir4/dir1]
2025/04/20 03:58:38 DEBUG : test/dir3: list: read 4 from source
2025/04/20 03:58:38 DEBUG : test/dir3: list: source entries: [test/dir3/dir3 test/dir3/dir2 test/dir3/dir4 test/dir3/dir1]
2025/04/20 03:58:38 DEBUG : test/dir4: list: cached directories: 0
2025/04/20 03:58:38 DEBUG : test/dir3: list: cached directories: 0
2025/04/20 03:58:38 DEBUG : Cache remote TestInternalCache:tib21171745121488: list 'test/dir1'
2025/04/20 03:58:38 DEBUG : test/dir1: list: cold listing: 2025-04-17 03:58:38.877196207 +0000 UTC
2025/04/20 03:58:38 DEBUG : test/dir1: list: read 4 from source
2025/04/20 03:58:38 DEBUG : test/dir1: list: source entries: [test/dir1/dir3 test/dir1/dir2 test/dir1/dir4 test/dir1/dir1]
2025/04/20 03:58:38 DEBUG : test/dir1: list: cached directories: 0
2025/04/20 03:58:38 DEBUG : Cache remote TestInternalCache:tib21171745121488: list 'test/dir2'
2025/04/20 03:58:38 DEBUG : test/dir2: list: cold listing: 2025-04-17 03:58:38.917670262 +0000 UTC
2025/04/20 03:58:38 DEBUG : test/dir2: list: read 4 from source
2025/04/20 03:58:38 DEBUG : test/dir2: list: source entries: [test/dir2/dir3 test/dir2/dir2 test/dir2/dir4 test/dir2/dir1]
2025/04/20 03:58:38 DEBUG : test/dir2: list: cached directories: 0
2025/04/20 03:58:38 DEBUG : test/dir4: list: cached dir: 'tib21171745121488/test/dir4', cache ts: 2025-04-20 03:58:38.932073365 +0000 UTC m=+39.637364827
2025/04/20 03:58:38 DEBUG : Cache remote TestInternalCache:tib21171745121488: list 'test/dir4/dir4'
2025/04/20 03:58:38 DEBUG : Cache remote TestInternalCache:tib21171745121488: list 'test/dir4/dir2'
2025/04/20 03:58:38 DEBUG : test/dir4/dir4: list: cold listing: 2025-04-17 03:58:38.8952922 +0000 UTC
2025/04/20 03:58:38 DEBUG : test/dir4/dir2: list: cold listing: 2025-04-17 03:58:38.890255898 +0000 UTC
2025/04/20 03:58:38 DEBUG : test/dir4/dir4: list: read 0 from source
2025/04/20 03:58:38 DEBUG : test/dir4/dir2: list: read 0 from source
2025/04/20 03:58:38 DEBUG : test/dir4/dir4: list: source entries: []
2025/04/20 03:58:38 DEBUG : test/dir4/dir2: list: source entries: []
2025/04/20 03:58:38 DEBUG : test/dir4/dir2: list: cached directories: 0
2025/04/20 03:58:38 DEBUG : test/dir4/dir4: list: cached directories: 0
2025/04/20 03:58:38 DEBUG : Cache remote TestInternalCache:tib21171745121488: list 'test/dir4/dir3'
2025/04/20 03:58:38 DEBUG : Cache remote TestInternalCache:tib21171745121488: list 'test/dir4/dir1'
2025/04/20 03:58:38 DEBUG : test/dir4/dir3: list: cold listing: 2025-04-17 03:58:38.880588112 +0000 UTC
2025/04/20 03:58:38 DEBUG : test/dir4/dir1: list: cold listing: 2025-04-17 03:58:38.884426116 +0000 UTC
2025/04/20 03:58:38 DEBUG : test/dir4/dir3: list: read 0 from source
2025/04/20 03:58:38 DEBUG : test/dir4/dir3: list: source entries: []
2025/04/20 03:58:38 DEBUG : test/dir4/dir1: list: read 0 from source
2025/04/20 03:58:38 DEBUG : test/dir4/dir3: list: cached directories: 0
2025/04/20 03:58:38 DEBUG : test/dir4/dir1: list: source entries: []
2025/04/20 03:58:38 DEBUG : test/dir4/dir1: list: cached directories: 0
2025/04/20 03:58:38 DEBUG : test/dir3: list: cached dir: 'tib21171745121488/test/dir3', cache ts: 2025-04-20 03:58:38.932101068 +0000 UTC m=+39.637392541
2025/04/20 03:58:38 DEBUG : Cache remote TestInternalCache:tib21171745121488: list 'test/dir3/dir2'
2025/04/20 03:58:38 DEBUG : test/dir3/dir2: list: cold listing: 2025-04-17 03:58:38.925088365 +0000 UTC
2025/04/20 03:58:38 DEBUG : Cache remote TestInternalCache:tib21171745121488: list 'test/dir3/dir1'
2025/04/20 03:58:38 DEBUG : test/dir3/dir1: list: cold listing: 2025-04-17 03:58:38.9203757 +0000 UTC
2025/04/20 03:58:38 DEBUG : test/dir3/dir1: list: read 0 from source
2025/04/20 03:58:38 DEBUG : test/dir3/dir1: list: source entries: []
2025/04/20 03:58:38 DEBUG : test/dir3/dir1: list: cached directories: 0
2025/04/20 03:58:38 DEBUG : test/dir3/dir2: list: read 0 from source
2025/04/20 03:58:38 DEBUG : test/dir3/dir2: list: source entries: []
2025/04/20 03:58:38 DEBUG : test/dir3/dir2: list: cached directories: 0
2025/04/20 03:58:38 DEBUG : test/dir1: list: cached dir: 'tib21171745121488/test/dir1', cache ts: 2025-04-20 03:58:38.932376455 +0000 UTC m=+39.637667927
2025/04/20 03:58:38 DEBUG : Cache remote TestInternalCache:tib21171745121488: list 'test/dir3/dir3'
2025/04/20 03:58:38 DEBUG : test/dir3/dir3: list: cold listing: 2025-04-17 03:58:38.922929694 +0000 UTC
2025/04/20 03:58:38 DEBUG : test/dir3/dir3: list: read 0 from source
2025/04/20 03:58:38 DEBUG : test/dir3/dir3: list: source entries: []
2025/04/20 03:58:38 DEBUG : test/dir3/dir3: list: cached directories: 0
2025/04/20 03:58:38 DEBUG : test/dir3/dir3: list: cached dir: 'tib21171745121488/test/dir3/dir3', cache ts: 2025-04-20 03:58:38.936351645 +0000 UTC m=+39.641643108
2025/04/20 03:58:38 DEBUG : Cache remote TestInternalCache:tib21171745121488: list 'test/dir3/dir4'
2025/04/20 03:58:38 DEBUG : test/dir3/dir4: list: cold listing: 2025-04-17 03:58:38.927347245 +0000 UTC
2025/04/20 03:58:38 DEBUG : test/dir3/dir4: list: read 0 from source
2025/04/20 03:58:38 DEBUG : test/dir3/dir4: list: source entries: []
2025/04/20 03:58:38 DEBUG : test/dir3/dir4: list: cached directories: 0
2025/04/20 03:58:38 DEBUG : test/dir2: list: cached dir: 'tib21171745121488/test/dir2', cache ts: 2025-04-20 03:58:38.932923412 +0000 UTC m=+39.638214874
2025/04/20 03:58:38 DEBUG : Cache remote TestInternalCache:tib21171745121488: list 'test/dir1/dir1'
2025/04/20 03:58:38 DEBUG : test/dir1/dir1: list: cold listing: 2025-04-17 03:58:38.872426233 +0000 UTC
2025/04/20 03:58:38 DEBUG : test/dir1/dir1: list: read 0 from source
2025/04/20 03:58:38 DEBUG : test/dir1/dir1: list: source entries: []
2025/04/20 03:58:38 DEBUG : test/dir1/dir1: list: cached directories: 0
2025/04/20 03:58:38 DEBUG : test/dir4/dir2: list: cached dir: 'tib21171745121488/test/dir4/dir2', cache ts: 2025-04-20 03:58:38.933468714 +0000 UTC m=+39.638760177
2025/04/20 03:58:38 DEBUG : Cache remote TestInternalCache:tib21171745121488: list 'test/dir1/dir2'
2025/04/20 03:58:38 DEBUG : test/dir1/dir2: list: cold listing: 2025-04-17 03:58:38.841436027 +0000 UTC
2025/04/20 03:58:38 DEBUG : test/dir1/dir2: list: read 0 from source
2025/04/20 03:58:38 DEBUG : test/dir1/dir2: list: source entries: []
2025/04/20 03:58:38 DEBUG : test/dir1/dir2: list: cached directories: 0
2025/04/20 03:58:38 DEBUG : test/dir4/dir4: list: cached dir: 'tib21171745121488/test/dir4/dir4', cache ts: 2025-04-20 03:58:38.933486758 +0000 UTC m=+39.638778220
2025/04/20 03:58:38 DEBUG : Cache remote TestInternalCache:tib21171745121488: list 'test/dir1/dir3'
2025/04/20 03:58:38 DEBUG : test/dir1/dir3: list: cold listing: 2025-04-17 03:58:38.877196207 +0000 UTC
2025/04/20 03:58:38 DEBUG : test/dir1/dir3: list: read 0 from source
2025/04/20 03:58:38 DEBUG : test/dir1/dir3: list: source entries: []
2025/04/20 03:58:38 DEBUG : test/dir1/dir3: list: cached directories: 0
2025/04/20 03:58:38 DEBUG : test/dir4/dir3: list: cached dir: 'tib21171745121488/test/dir4/dir3', cache ts: 2025-04-20 03:58:38.933567279 +0000 UTC m=+39.638858741
2025/04/20 03:58:38 DEBUG : Cache remote TestInternalCache:tib21171745121488: list 'test/dir1/dir4'
2025/04/20 03:58:38 DEBUG : test/dir1/dir4: list: cold listing: 2025-04-17 03:58:38.861031907 +0000 UTC
2025/04/20 03:58:38 DEBUG : test/dir1/dir4: list: read 0 from source
2025/04/20 03:58:38 DEBUG : test/dir1/dir4: list: source entries: []
2025/04/20 03:58:38 DEBUG : test/dir1/dir4: list: cached directories: 0
2025/04/20 03:58:38 DEBUG : test/dir4/dir1: list: cached dir: 'tib21171745121488/test/dir4/dir1', cache ts: 2025-04-20 03:58:38.933575474 +0000 UTC m=+39.638866937
2025/04/20 03:58:38 DEBUG : Cache remote TestInternalCache:tib21171745121488: list 'test/dir2/dir1'
2025/04/20 03:58:38 DEBUG : test/dir2/dir1: list: cold listing: 2025-04-17 03:58:38.898289947 +0000 UTC
2025/04/20 03:58:38 DEBUG : test/dir2/dir1: list: read 0 from source
2025/04/20 03:58:38 DEBUG : test/dir2/dir1: list: source entries: []
2025/04/20 03:58:38 DEBUG : test/dir2/dir1: list: cached directories: 0
2025/04/20 03:58:38 DEBUG : test/dir3/dir1: list: cached dir: 'tib21171745121488/test/dir3/dir1', cache ts: 2025-04-20 03:58:38.93568253 +0000 UTC m=+39.640973992
2025/04/20 03:58:38 DEBUG : Cache remote TestInternalCache:tib21171745121488: list 'test/dir2/dir2'
2025/04/20 03:58:38 DEBUG : test/dir2/dir2: list: cold listing: 2025-04-17 03:58:38.904820475 +0000 UTC
2025/04/20 03:58:38 DEBUG : test/dir2/dir2: list: read 0 from source
2025/04/20 03:58:38 DEBUG : test/dir2/dir2: list: source entries: []
2025/04/20 03:58:38 DEBUG : test/dir2/dir2: list: cached directories: 0
2025/04/20 03:58:38 DEBUG : test/dir3/dir2: list: cached dir: 'tib21171745121488/test/dir3/dir2', cache ts: 2025-04-20 03:58:38.935887235 +0000 UTC m=+39.641178697
2025/04/20 03:58:38 DEBUG : Cache remote TestInternalCache:tib21171745121488: list 'test/dir2/dir3'
2025/04/20 03:58:38 DEBUG : test/dir2/dir3: list: cold listing: 2025-04-17 03:58:38.914640837 +0000 UTC
2025/04/20 03:58:38 DEBUG : test/dir2/dir3: list: read 0 from source
2025/04/20 03:58:38 DEBUG : test/dir2/dir3: list: source entries: []
2025/04/20 03:58:38 DEBUG : test/dir2/dir3: list: cached directories: 0
2025/04/20 03:58:38 DEBUG : test/dir3/dir4: list: cached dir: 'tib21171745121488/test/dir3/dir4', cache ts: 2025-04-20 03:58:38.938364814 +0000 UTC m=+39.643656256
2025/04/20 03:58:38 DEBUG : Cache remote TestInternalCache:tib21171745121488: list 'test/dir2/dir4'
2025/04/20 03:58:38 DEBUG : test/dir2/dir4: list: cold listing: 2025-04-17 03:58:38.917670262 +0000 UTC
2025/04/20 03:58:38 DEBUG : test/dir2/dir4: list: read 0 from source
2025/04/20 03:58:38 DEBUG : test/dir2/dir4: list: source entries: []
2025/04/20 03:58:38 DEBUG : test/dir2/dir4: list: cached directories: 0
2025/04/20 03:58:38 DEBUG : test/dir1/dir1: list: cached dir: 'tib21171745121488/test/dir1/dir1', cache ts: 2025-04-20 03:58:38.939387534 +0000 UTC m=+39.644678976
2025/04/20 03:58:38 DEBUG : test/dir1/dir2: list: cached dir: 'tib21171745121488/test/dir1/dir2', cache ts: 2025-04-20 03:58:38.940356542 +0000 UTC m=+39.645647984
2025/04/20 03:58:38 DEBUG : test/dir1/dir3: list: cached dir: 'tib21171745121488/test/dir1/dir3', cache ts: 2025-04-20 03:58:38.941634561 +0000 UTC m=+39.646926003
2025/04/20 03:58:38 DEBUG : test/dir1/dir4: list: cached dir: 'tib21171745121488/test/dir1/dir4', cache ts: 2025-04-20 03:58:38.94270488 +0000 UTC m=+39.647996332
2025/04/20 03:58:38 DEBUG : test/dir2/dir1: list: cached dir: 'tib21171745121488/test/dir2/dir1', cache ts: 2025-04-20 03:58:38.943789246 +0000 UTC m=+39.649080688
2025/04/20 03:58:38 DEBUG : test/dir2/dir2: list: cached dir: 'tib21171745121488/test/dir2/dir2', cache ts: 2025-04-20 03:58:38.945130764 +0000 UTC m=+39.650422206
2025/04/20 03:58:38 DEBUG : test/dir2/dir3: list: cached dir: 'tib21171745121488/test/dir2/dir3', cache ts: 2025-04-20 03:58:38.946251256 +0000 UTC m=+39.651542698
2025/04/20 03:58:38 DEBUG : test/dir2/dir4: list: cached dir: 'tib21171745121488/test/dir2/dir4', cache ts: 2025-04-20 03:58:38.947268525 +0000 UTC m=+39.652559987
2025/04/20 03:58:38 DEBUG : removing 16 level 3 directories
2025/04/20 03:58:38 INFO  : test/dir2/dir4: Removing directory
2025/04/20 03:58:38 DEBUG : Cache remote TestInternalCache:tib21171745121488: rmdir 'test/dir2/dir4'
2025/04/20 03:58:38 DEBUG : test/dir2/dir4: rmdir: removed dir in source fs
2025/04/20 03:58:38 INFO  : test/dir1/dir2: Removing directory
2025/04/20 03:58:38 DEBUG : Cache remote TestInternalCache:tib21171745121488: rmdir 'test/dir1/dir2'
2025/04/20 03:58:38 DEBUG : test/dir1/dir2: rmdir: removed dir in source fs
2025/04/20 03:58:38 INFO  : test/dir1/dir1: Removing directory
2025/04/20 03:58:38 DEBUG : Cache remote TestInternalCache:tib21171745121488: rmdir 'test/dir1/dir1'
2025/04/20 03:58:38 DEBUG : test/dir1/dir1: rmdir: removed dir in source fs
2025/04/20 03:58:38 INFO  : test/dir2/dir3: Removing directory
2025/04/20 03:58:38 DEBUG : Cache remote TestInternalCache:tib21171745121488: rmdir 'test/dir2/dir3'
2025/04/20 03:58:38 DEBUG : test/dir2/dir3: rmdir: removed dir in source fs
2025/04/20 03:58:38 INFO  : test/dir1/dir3: Removing directory
2025/04/20 03:58:38 DEBUG : Cache remote TestInternalCache:tib21171745121488: rmdir 'test/dir1/dir3'
2025/04/20 03:58:38 INFO  : test/dir2/dir2: Removing directory
2025/04/20 03:58:38 DEBUG : test/dir1/dir3: rmdir: removed dir in source fs
2025/04/20 03:58:38 DEBUG : Cache remote TestInternalCache:tib21171745121488: rmdir 'test/dir2/dir2'
2025/04/20 03:58:38 INFO  : test/dir2/dir1: Removing directory
2025/04/20 03:58:38 DEBUG : Cache remote TestInternalCache:tib21171745121488: rmdir 'test/dir2/dir1'
2025/04/20 03:58:38 DEBUG : test/dir2/dir1: rmdir: removed dir in source fs
2025/04/20 03:58:38 DEBUG : test/dir2/dir2: rmdir: removed dir in source fs
2025/04/20 03:58:38 INFO  : test/dir1/dir4: Removing directory
2025/04/20 03:58:38 DEBUG : Cache remote TestInternalCache:tib21171745121488: rmdir 'test/dir1/dir4'
2025/04/20 03:58:38 DEBUG : test/dir1/dir4: rmdir: removed dir in source fs
2025/04/20 03:58:38 DEBUG : test/dir2/dir4: rmdir: removed from cache
2025/04/20 03:58:38 DEBUG : test/dir1/dir2: rmdir: removed from cache
2025/04/20 03:58:38 DEBUG : test/dir1: cache: expired tib21171745121488/test/dir1
2025/04/20 03:58:38 DEBUG : test/dir1: cache: expired tib21171745121488/test
2025/04/20 03:58:38 DEBUG : test/dir1: cache: expired tib21171745121488
2025/04/20 03:58:38 INFO  : test/dir1: rmdir: cache expired
2025/04/20 03:58:38 INFO  : test/dir3/dir1: Removing directory
2025/04/20 03:58:38 DEBUG : Cache remote TestInternalCache:tib21171745121488: rmdir 'test/dir3/dir1'
2025/04/20 03:58:38 DEBUG : test/dir3/dir1: rmdir: removed dir in source fs
2025/04/20 03:58:38 DEBUG : test/dir1/dir1: rmdir: removed from cache
2025/04/20 03:58:38 DEBUG : test/dir2/dir3: rmdir: removed from cache
2025/04/20 03:58:38 DEBUG : test/dir1/dir3: rmdir: removed from cache
2025/04/20 03:58:38 DEBUG : test/dir2/dir1: rmdir: removed from cache
2025/04/20 03:58:38 DEBUG : test/dir2/dir2: rmdir: removed from cache
2025/04/20 03:58:38 DEBUG : test/dir2: cache: expired tib21171745121488/test/dir2
2025/04/20 03:58:38 DEBUG : test/dir2: cache: expired tib21171745121488/test
2025/04/20 03:58:38 DEBUG : test/dir2: cache: expired tib21171745121488
2025/04/20 03:58:38 DEBUG : test/dir1/dir4: rmdir: removed from cache
2025/04/20 03:58:38 INFO  : test/dir2: rmdir: cache expired
2025/04/20 03:58:38 INFO  : test/dir3/dir2: Removing directory
2025/04/20 03:58:38 DEBUG : Cache remote TestInternalCache:tib21171745121488: rmdir 'test/dir3/dir2'
2025/04/20 03:58:38 DEBUG : test/dir3/dir2: rmdir: removed dir in source fs
2025/04/20 03:58:38 DEBUG : test/dir1: cache: expired tib21171745121488/test/dir1
2025/04/20 03:58:38 DEBUG : test/dir1: cache: expired tib21171745121488/test
2025/04/20 03:58:38 DEBUG : test/dir1: cache: expired tib21171745121488
2025/04/20 03:58:38 DEBUG : test/dir3/dir1: rmdir: removed from cache
2025/04/20 03:58:38 DEBUG : test/dir2: cache: expired tib21171745121488/test/dir2
2025/04/20 03:58:38 DEBUG : test/dir2: cache: expired tib21171745121488/test
2025/04/20 03:58:38 DEBUG : test/dir2: cache: expired tib21171745121488
2025/04/20 03:58:38 INFO  : test/dir1: rmdir: cache expired
2025/04/20 03:58:38 INFO  : test/dir3/dir3: Removing directory
2025/04/20 03:58:38 DEBUG : Cache remote TestInternalCache:tib21171745121488: rmdir 'test/dir3/dir3'
2025/04/20 03:58:38 DEBUG : test/dir3/dir3: rmdir: removed dir in source fs
2025/04/20 03:58:38 DEBUG : test/dir1: cache: expired tib21171745121488/test/dir1
2025/04/20 03:58:38 DEBUG : test/dir1: cache: expired tib21171745121488/test
2025/04/20 03:58:38 DEBUG : test/dir1: cache: expired tib21171745121488
2025/04/20 03:58:38 INFO  : test/dir2: rmdir: cache expired
2025/04/20 03:58:38 INFO  : test/dir3/dir4: Removing directory
2025/04/20 03:58:38 DEBUG : Cache remote TestInternalCache:tib21171745121488: rmdir 'test/dir3/dir4'
2025/04/20 03:58:38 DEBUG : test/dir3/dir4: rmdir: removed dir in source fs
2025/04/20 03:58:38 INFO  : test/dir1: rmdir: cache expired
2025/04/20 03:58:38 INFO  : test/dir4/dir1: Removing directory
2025/04/20 03:58:38 DEBUG : Cache remote TestInternalCache:tib21171745121488: rmdir 'test/dir4/dir1'
2025/04/20 03:58:38 DEBUG : test/dir4/dir1: rmdir: removed dir in source fs
2025/04/20 03:58:38 DEBUG : test/dir2: cache: expired tib21171745121488/test/dir2
2025/04/20 03:58:38 DEBUG : test/dir2: cache: expired tib21171745121488/test
2025/04/20 03:58:38 DEBUG : test/dir2: cache: expired tib21171745121488
2025/04/20 03:58:38 INFO  : test/dir2: rmdir: cache expired
2025/04/20 03:58:38 INFO  : test/dir4/dir2: Removing directory
2025/04/20 03:58:38 DEBUG : Cache remote TestInternalCache:tib21171745121488: rmdir 'test/dir4/dir2'
2025/04/20 03:58:38 DEBUG : test/dir4/dir2: rmdir: removed dir in source fs
2025/04/20 03:58:38 DEBUG : test/dir2: cache: expired tib21171745121488/test/dir2
2025/04/20 03:58:38 DEBUG : test/dir2: cache: expired tib21171745121488/test
2025/04/20 03:58:38 DEBUG : test/dir2: cache: expired tib21171745121488
2025/04/20 03:58:38 INFO  : test/dir2: rmdir: cache expired
2025/04/20 03:58:38 INFO  : test/dir4/dir3: Removing directory
2025/04/20 03:58:38 DEBUG : Cache remote TestInternalCache:tib21171745121488: rmdir 'test/dir4/dir3'
2025/04/20 03:58:38 DEBUG : test/dir4/dir3: rmdir: removed dir in source fs
2025/04/20 03:58:38 DEBUG : test/dir1: cache: expired tib21171745121488/test/dir1
2025/04/20 03:58:38 DEBUG : test/dir1: cache: expired tib21171745121488/test
2025/04/20 03:58:38 DEBUG : test/dir1: cache: expired tib21171745121488
2025/04/20 03:58:38 INFO  : test/dir1: rmdir: cache expired
2025/04/20 03:58:38 INFO  : test/dir4/dir4: Removing directory
2025/04/20 03:58:38 DEBUG : Cache remote TestInternalCache:tib21171745121488: rmdir 'test/dir4/dir4'
2025/04/20 03:58:38 DEBUG : test/dir4/dir4: rmdir: removed dir in source fs
2025/04/20 03:58:38 DEBUG : test/dir3: cache: expired tib21171745121488/test/dir3
2025/04/20 03:58:38 DEBUG : test/dir3: cache: expired tib21171745121488/test
2025/04/20 03:58:38 DEBUG : test/dir3: cache: expired tib21171745121488
2025/04/20 03:58:38 DEBUG : test/dir3/dir2: rmdir: removed from cache
2025/04/20 03:58:38 INFO  : test/dir3: rmdir: cache expired
2025/04/20 03:58:38 DEBUG : test/dir3/dir3: rmdir: removed from cache
2025/04/20 03:58:38 DEBUG : test/dir3/dir4: rmdir: removed from cache
2025/04/20 03:58:38 DEBUG : test/dir4/dir1: rmdir: removed from cache
2025/04/20 03:58:38 DEBUG : test/dir4/dir2: rmdir: removed from cache
2025/04/20 03:58:38 DEBUG : test/dir4/dir3: rmdir: removed from cache
2025/04/20 03:58:38 DEBUG : test/dir4/dir4: rmdir: removed from cache
2025/04/20 03:58:38 DEBUG : test/dir3: cache: expired tib21171745121488/test/dir3
2025/04/20 03:58:38 DEBUG : test/dir3: cache: expired tib21171745121488/test
2025/04/20 03:58:38 DEBUG : test/dir3: cache: expired tib21171745121488
2025/04/20 03:58:38 INFO  : test/dir3: rmdir: cache expired
2025/04/20 03:58:38 DEBUG : test/dir3: cache: expired tib21171745121488/test/dir3
2025/04/20 03:58:38 DEBUG : test/dir3: cache: expired tib21171745121488/test
2025/04/20 03:58:38 DEBUG : test/dir3: cache: expired tib21171745121488
2025/04/20 03:58:38 INFO  : test/dir3: rmdir: cache expired
2025/04/20 03:58:38 DEBUG : test/dir3: cache: expired tib21171745121488/test/dir3
2025/04/20 03:58:38 DEBUG : test/dir3: cache: expired tib21171745121488/test
2025/04/20 03:58:38 DEBUG : test/dir3: cache: expired tib21171745121488
2025/04/20 03:58:38 DEBUG : test/dir4: cache: expired tib21171745121488/test/dir4
2025/04/20 03:58:38 DEBUG : test/dir4: cache: expired tib21171745121488/test
2025/04/20 03:58:38 DEBUG : test/dir4: cache: expired tib21171745121488
2025/04/20 03:58:38 INFO  : test/dir3: rmdir: cache expired
2025/04/20 03:58:38 INFO  : test/dir4: rmdir: cache expired
2025/04/20 03:58:38 DEBUG : test/dir4: cache: expired tib21171745121488/test/dir4
2025/04/20 03:58:38 DEBUG : test/dir4: cache: expired tib21171745121488/test
2025/04/20 03:58:38 DEBUG : test/dir4: cache: expired tib21171745121488
2025/04/20 03:58:38 INFO  : test/dir4: rmdir: cache expired
2025/04/20 03:58:38 DEBUG : test/dir4: cache: expired tib21171745121488/test/dir4
2025/04/20 03:58:39 DEBUG : test/dir4: cache: expired tib21171745121488/test
2025/04/20 03:58:39 DEBUG : test/dir4: cache: expired tib21171745121488
2025/04/20 03:58:39 INFO  : test/dir4: rmdir: cache expired
2025/04/20 03:58:39 DEBUG : test/dir4: cache: expired tib21171745121488/test/dir4
2025/04/20 03:58:39 DEBUG : test/dir4: cache: expired tib21171745121488/test
2025/04/20 03:58:39 DEBUG : test/dir4: cache: expired tib21171745121488
2025/04/20 03:58:39 INFO  : test/dir4: rmdir: cache expired
2025/04/20 03:58:39 DEBUG : removing 4 level 2 directories
2025/04/20 03:58:39 INFO  : test/dir4: Removing directory
2025/04/20 03:58:39 INFO  : test/dir3: Removing directory
2025/04/20 03:58:39 DEBUG : Cache remote TestInternalCache:tib21171745121488: rmdir 'test/dir3'
2025/04/20 03:58:39 DEBUG : Cache remote TestInternalCache:tib21171745121488: rmdir 'test/dir4'
2025/04/20 03:58:39 DEBUG : test/dir3: rmdir: removed dir in source fs
2025/04/20 03:58:39 DEBUG : test/dir4: rmdir: removed dir in source fs
2025/04/20 03:58:39 INFO  : test/dir2: Removing directory
2025/04/20 03:58:39 DEBUG : Cache remote TestInternalCache:tib21171745121488: rmdir 'test/dir2'
2025/04/20 03:58:39 DEBUG : test/dir2: rmdir: removed dir in source fs
2025/04/20 03:58:39 INFO  : test/dir1: Removing directory
2025/04/20 03:58:39 DEBUG : Cache remote TestInternalCache:tib21171745121488: rmdir 'test/dir1'
2025/04/20 03:58:39 DEBUG : test/dir1: rmdir: removed dir in source fs
2025/04/20 03:58:39 DEBUG : test/dir3: rmdir: removed from cache
2025/04/20 03:58:39 DEBUG : test: cache: expired tib21171745121488/test
2025/04/20 03:58:39 DEBUG : test: cache: expired tib21171745121488
2025/04/20 03:58:39 INFO  : test: rmdir: cache expired
2025/04/20 03:58:39 DEBUG : test/dir2: rmdir: removed from cache
2025/04/20 03:58:39 DEBUG : test: cache: expired tib21171745121488/test
2025/04/20 03:58:39 DEBUG : test: cache: expired tib21171745121488
2025/04/20 03:58:39 INFO  : test: rmdir: cache expired
2025/04/20 03:58:39 DEBUG : test/dir1: rmdir: removed from cache
2025/04/20 03:58:39 DEBUG : test/dir4: rmdir: removed from cache
2025/04/20 03:58:39 DEBUG : test: cache: expired tib21171745121488/test
2025/04/20 03:58:39 DEBUG : test: cache: expired tib21171745121488
2025/04/20 03:58:39 INFO  : test: rmdir: cache expired
2025/04/20 03:58:39 DEBUG : test: cache: expired tib21171745121488/test
2025/04/20 03:58:39 DEBUG : test: cache: expired tib21171745121488
2025/04/20 03:58:39 INFO  : test: rmdir: cache expired
2025/04/20 03:58:39 DEBUG : removing 1 level 1 directories
2025/04/20 03:58:39 INFO  : test: Removing directory
2025/04/20 03:58:39 DEBUG : Cache remote TestInternalCache:tib21171745121488: rmdir 'test'
2025/04/20 03:58:39 DEBUG : test: rmdir: removed dir in source fs
2025/04/20 03:58:39 DEBUG : test: rmdir: removed from cache
2025/04/20 03:58:39 DEBUG : : cache: expired tib21171745121488
2025/04/20 03:58:39 INFO  : : rmdir: cache expired
2025/04/20 03:58:39 DEBUG : removing 1 level 0 directories
2025/04/20 03:58:39 INFO  : Cache remote TestInternalCache:tib21171745121488: Removing directory
2025/04/20 03:58:39 DEBUG : Cache remote TestInternalCache:tib21171745121488: rmdir ''
2025/04/20 03:58:39 DEBUG : : rmdir: removed dir in source fs
2025/04/20 03:58:39 DEBUG : : rmdir: removed from cache
2025/04/20 03:58:39 INFO  : : rmdir: cache expired
2025/04/20 03:58:39 DEBUG : Cache remote TestInternalCache:tib21171745121488: Services stopped
--- PASS: TestInternalBug2117 (30.23s)
=== RUN   TestIntegration
    fstests.go:438: Using remote "TestCache:"
2025/04/20 03:58:39 DEBUG : Creating backend with remote "TestCache:rclone-test-fuvehot2keya"
2025/04/20 03:58:39 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2025/04/20 03:58:39 DEBUG : Setting cache db_wait_time="30m" from environment variable RCLONE_CACHE_DB_WAIT_TIME
2025/04/20 03:58:39 DEBUG : TestCache: detected overridden config - adding "{VDL3R}" suffix to name
2025/04/20 03:58:39 DEBUG : Setting cache db_wait_time="30m" from environment variable RCLONE_CACHE_DB_WAIT_TIME
2025/04/20 03:58:39 DEBUG : Creating backend with remote "/tmp/rclone_cache_test/rclone-test-fuvehot2keya"
2025/04/20 03:58:39 DEBUG : TestCache{VDL3R}: wrapped local:/tmp/rclone_cache_test/rclone-test-fuvehot2keya at root rclone-test-fuvehot2keya
2025/04/20 03:58:39 INFO  : TestCache{VDL3R}: Cache DB path: /home/rclone/.cache/rclone/cache-backend/TestCache{VDL3R}.db
2025/04/20 03:58:39 INFO  : TestCache{VDL3R}: Cache chunk path: /home/rclone/.cache/rclone/cache-backend/TestCache{VDL3R}
2025/04/20 03:58:59 INFO  : Cache remote TestInternalCache:tionf1745121479: stopping cleanup
2025/04/20 03:58:59 INFO  : Cache remote TestInternalCache:ticwcm1745121479: stopping cleanup
2025/04/20 03:59:00 INFO  : Cache remote TestInternalCache:tidwcm1745121480: stopping cleanup
2025/04/20 03:59:01 INFO  : Cache remote TestInternalCache:ticucm1745121480: stopping cleanup
2025/04/20 03:59:01 INFO  : Cache remote TestInternalCache:tiwfcns1745121481: stopping cleanup
2025/04/20 03:59:02 INFO  : Cache remote TestInternalCache:timwn1745121482: stopping cleanup
2025/04/20 03:59:02 INFO  : Cache remote TestInternalCache:tincep1745121482: stopping cleanup
2025/04/20 03:59:02 INFO  : Cache remote TestInternalCache:ticsadcf1745121482: stopping cleanup
2025/04/20 03:59:02 INFO  : Cache remote TestInternalCache:ticw: stopping cleanup
2025/04/20 03:59:03 INFO  : Cache remote TestInternalCache:timcsr1745121483: stopping cleanup
2025/04/20 04:13:08 INFO  : Cache remote TestInternalCache:tib21171745121488: stopping cleanup
2025/04/20 04:28:38 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.96s)
=== RUN   TestInternalUploadTempDirCreated
2025/04/20 04:28:38 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2025/04/20 04:28:38 DEBUG : Creating backend with remote "TestInternalCache-local:/tmp/TestInternalCache-local/tiutdc1745123318"
2025/04/20 04:28:38 DEBUG : TestInternalCache: wrapped TestInternalCache-local:/tmp/TestInternalCache-local/tiutdc1745123318 at root tiutdc1745123318
2025/04/20 04:28:38 INFO  : TestInternalCache: Cache DB path: /home/rclone/.cache/rclone/cache-backend/TestInternalCache.db
2025/04/20 04:28:38 INFO  : TestInternalCache: Cache chunk path: /home/rclone/.cache/rclone/cache-backend/TestInternalCache
2025/04/20 04:28:38 INFO  : TestInternalCache: Chunk Memory: true
2025/04/20 04:28:38 INFO  : TestInternalCache: Chunk Size: 5Mi
2025/04/20 04:28:38 INFO  : TestInternalCache: Chunk Total Size: 10Gi
2025/04/20 04:28:38 INFO  : TestInternalCache: Chunk Clean Interval: 1m0s
2025/04/20 04:28:38 INFO  : TestInternalCache: Workers: 4
2025/04/20 04:28:38 INFO  : TestInternalCache: File Age: 6h0m0s
2025/04/20 04:28:38 DEBUG : Creating backend with remote "/tmp/rclonecache-tmp2733279096/tiutdc1745123318"
2025/04/20 04:28:38 INFO  : TestInternalCache: Upload Temp Rest Time: 15s
2025/04/20 04:28:38 INFO  : TestInternalCache: Upload Temp FS: /tmp/rclonecache-tmp2733279096/tiutdc1745123318
2025/04/20 04:28:38 DEBUG : Waiting for deletions to finish
2025/04/20 04:28:38 DEBUG : Cache remote TestInternalCache:tiutdc1745123318: list ''
2025/04/20 04:28:38 DEBUG : : list: error: couldn't open bucket (tiutdc1745123318)
2025/04/20 04:28:38 DEBUG : : list: read 0 from temp fs
2025/04/20 04:28:38 DEBUG : : list: temp fs entries: []
2025/04/20 04:28:38 ERROR : : error listing: directory not found
2025/04/20 04:28:38 DEBUG : Cache remote TestInternalCache:tiutdc1745123318: list ''
2025/04/20 04:28:38 DEBUG : : list: error: couldn't open bucket (tiutdc1745123318)
2025/04/20 04:28:38 DEBUG : : list: read 0 from temp fs
2025/04/20 04:28:38 DEBUG : : list: temp fs entries: []
2025/04/20 04:28:38 ERROR : Cache remote TestInternalCache:tiutdc1745123318: Failed to list "": directory not found
2025/04/20 04:28:38 DEBUG : removing 1 level 0 directories
2025/04/20 04:28:38 INFO  : Cache remote TestInternalCache:tiutdc1745123318: Removing directory
2025/04/20 04:28:38 DEBUG : Cache remote TestInternalCache:tiutdc1745123318: rmdir ''
2025/04/20 04:28:39 DEBUG : : rmdir: read 0 from temp fs
2025/04/20 04:28:39 DEBUG : : rmdir: temp fs entries: []
2025/04/20 04:28:39 DEBUG : tiutdc1745123318: couldn't delete from cache: bucket not found
2025/04/20 04:28:39 DEBUG : : rmdir: removed from cache
2025/04/20 04:28:39 INFO  : : rmdir: cache expired
2025/04/20 04:28:40 DEBUG : Cache remote TestInternalCache:tiutdc1745123318: mkdir ''
2025/04/20 04:28:40 DEBUG : : mkdir: created dir in source fs
2025/04/20 04:28:40 DEBUG : : mkdir: added to cache
2025/04/20 04:28:40 DEBUG : : cache: expired tiutdc1745123318
2025/04/20 04:28:40 INFO  : : mkdir: cache expired
2025/04/20 04:28:40 DEBUG : Waiting for deletions to finish
2025/04/20 04:28:40 DEBUG : Cache remote TestInternalCache:tiutdc1745123318: list ''
2025/04/20 04:28:40 DEBUG : : list: cold listing: 2025-04-19 22:28:40.491590939 +0000 UTC
2025/04/20 04:28:40 DEBUG : : list: read 0 from temp fs
2025/04/20 04:28:40 DEBUG : : list: temp fs entries: []
2025/04/20 04:28:40 DEBUG : : list: read 0 from source
2025/04/20 04:28:40 DEBUG : : list: source entries: []
2025/04/20 04:28:40 DEBUG : : list: cached directories: 0
2025/04/20 04:28:40 DEBUG : : list: cached dir: 'tiutdc1745123318', cache ts: 2025-04-20 04:28:40.493175843 +0000 UTC m=+1841.198467315
2025/04/20 04:28:40 DEBUG : Cache remote TestInternalCache:tiutdc1745123318: list ''
2025/04/20 04:28:40 DEBUG : : list: empty listing
2025/04/20 04:28:40 DEBUG : : list: read 0 from temp fs
2025/04/20 04:28:40 DEBUG : : list: temp fs entries: []
2025/04/20 04:28:40 DEBUG : : list: read 0 from source
2025/04/20 04:28:40 DEBUG : : list: source entries: []
2025/04/20 04:28:40 DEBUG : : list: cached directories: 0
2025/04/20 04:28:40 DEBUG : : list: cached dir: 'tiutdc1745123318', cache ts: 2025-04-20 04:28:40.494542598 +0000 UTC m=+1841.199834061
2025/04/20 04:28:40 DEBUG : removing 1 level 0 directories
2025/04/20 04:28:40 INFO  : Cache remote TestInternalCache:tiutdc1745123318: Removing directory
2025/04/20 04:28:40 DEBUG : Cache remote TestInternalCache:tiutdc1745123318: rmdir ''
2025/04/20 04:28:41 DEBUG : : rmdir: removed dir in source fs
2025/04/20 04:28:41 DEBUG : : rmdir: read 0 from temp fs
2025/04/20 04:28:41 DEBUG : : rmdir: temp fs entries: []
2025/04/20 04:28:41 DEBUG : : rmdir: removed from cache
2025/04/20 04:28:41 INFO  : : rmdir: cache expired
2025/04/20 04:28:42 DEBUG : Cache remote TestInternalCache:tiutdc1745123318: Services stopped
--- PASS: TestInternalUploadTempDirCreated (4.01s)
=== RUN   TestInternalUploadQueueOneFileNoRest
2025/04/20 04:28:42 DEBUG : Using config file from "/home/rclone/.rclone.conf"
    cache_internal_test.go:858: Need remote (TestInternalCache) to exist
--- SKIP: TestInternalUploadQueueOneFileNoRest (0.00s)
=== RUN   TestInternalUploadQueueOneFileWithRest
2025/04/20 04:28:42 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/20 04:28:42 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/20 04:28:43 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/20 04:28:43 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/20 04:28:43 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/20 04:28:43 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.722s
"go test -v -timeout 1h0m0s -remote TestCache: -verbose" - Finished ERROR in 30m44.929058965s (try 1/5): exit status 1: Failed [TestIntegration]