"go test -v -timeout 1h0m0s -remote TestCache: -verbose" - Starting (try 1/5)
2025/04/22 01:50:51 NOTICE: Running with the following params: 
 remote: TestInternalCache
2025/04/22 01:50:51 NOTICE: Temp Upload Dir: /tmp/rclonecache-tmp3510924608
=== RUN   TestInternalListRootAndInnerRemotes
2025/04/22 01:50:51 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/22 01:50:51 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/22 01:50:51 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2025/04/22 01:50:51 NOTICE: WARNING: Cache backend is deprecated and may be removed in future. Please use VFS instead.
2025/04/22 01:50:51 DEBUG : Creating backend with remote "TestInternalCache-local:/tmp/TestInternalCache-local/tionf1745286651"
2025/04/22 01:50:51 DEBUG : TestInternalCache: wrapped TestInternalCache-local:/tmp/TestInternalCache-local/tionf1745286651 at root tionf1745286651
2025/04/22 01:50:51 INFO  : TestInternalCache: Cache DB path: /home/rclone/.cache/rclone/cache-backend/TestInternalCache.db
2025/04/22 01:50:51 INFO  : TestInternalCache: Cache chunk path: /home/rclone/.cache/rclone/cache-backend/TestInternalCache
2025/04/22 01:50:51 INFO  : TestInternalCache: Chunk Memory: true
2025/04/22 01:50:51 INFO  : TestInternalCache: Chunk Size: 5Mi
2025/04/22 01:50:51 INFO  : TestInternalCache: Chunk Total Size: 10Gi
2025/04/22 01:50:51 INFO  : TestInternalCache: Chunk Clean Interval: 1m0s
2025/04/22 01:50:51 INFO  : TestInternalCache: Workers: 4
2025/04/22 01:50:51 INFO  : TestInternalCache: File Age: 6h0m0s
2025/04/22 01:50:51 DEBUG : Waiting for deletions to finish
2025/04/22 01:50:51 DEBUG : Cache remote TestInternalCache:tionf1745286651: list ''
2025/04/22 01:50:51 DEBUG : : list: error: couldn't open bucket (tionf1745286651)
2025/04/22 01:50:51 ERROR : : error listing: directory not found
2025/04/22 01:50:51 DEBUG : Cache remote TestInternalCache:tionf1745286651: list ''
2025/04/22 01:50:51 DEBUG : : list: error: couldn't open bucket (tionf1745286651)
2025/04/22 01:50:51 ERROR : Cache remote TestInternalCache:tionf1745286651: Failed to list "": directory not found
2025/04/22 01:50:51 DEBUG : removing 1 level 0 directories
2025/04/22 01:50:51 INFO  : Cache remote TestInternalCache:tionf1745286651: Removing directory
2025/04/22 01:50:51 DEBUG : Cache remote TestInternalCache:tionf1745286651: rmdir ''
2025/04/22 01:50:51 ERROR : : Failed to rmdir: stat /tmp/TestInternalCache-local/tionf1745286651: no such file or directory
2025/04/22 01:50:51 DEBUG : Cache remote TestInternalCache:tionf1745286651: mkdir ''
2025/04/22 01:50:51 DEBUG : : mkdir: created dir in source fs
2025/04/22 01:50:51 DEBUG : : mkdir: added to cache
2025/04/22 01:50:51 DEBUG : : cache: expired tionf1745286651
2025/04/22 01:50:51 INFO  : : mkdir: cache expired
2025/04/22 01:50:51 DEBUG : Cache remote TestInternalCache:tionf1745286651: new object '404'
2025/04/22 01:50:51 DEBUG : 404: find: error: couldn't find object (404)
2025/04/22 01:50:51 DEBUG : find failed: not found in either local or remote fs
2025/04/22 01:50:51 DEBUG : Waiting for deletions to finish
2025/04/22 01:50:51 DEBUG : Cache remote TestInternalCache:tionf1745286651: list ''
2025/04/22 01:50:51 DEBUG : : list: cold listing: 2025-04-21 19:50:51.479028945 +0000 UTC
2025/04/22 01:50:51 DEBUG : : list: read 0 from source
2025/04/22 01:50:51 DEBUG : : list: source entries: []
2025/04/22 01:50:51 DEBUG : : list: cached directories: 0
2025/04/22 01:50:51 DEBUG : : list: cached dir: 'tionf1745286651', cache ts: 2025-04-22 01:50:51.480275886 +0000 UTC m=+0.021479314
2025/04/22 01:50:51 DEBUG : Cache remote TestInternalCache:tionf1745286651: list ''
2025/04/22 01:50:51 DEBUG : : list: empty listing
2025/04/22 01:50:51 DEBUG : : list: read 0 from source
2025/04/22 01:50:51 DEBUG : : list: source entries: []
2025/04/22 01:50:51 DEBUG : : list: cached directories: 0
2025/04/22 01:50:51 DEBUG : : list: cached dir: 'tionf1745286651', cache ts: 2025-04-22 01:50:51.48146658 +0000 UTC m=+0.022669998
2025/04/22 01:50:51 DEBUG : removing 1 level 0 directories
2025/04/22 01:50:51 INFO  : Cache remote TestInternalCache:tionf1745286651: Removing directory
2025/04/22 01:50:51 DEBUG : Cache remote TestInternalCache:tionf1745286651: rmdir ''
2025/04/22 01:50:51 DEBUG : : rmdir: removed dir in source fs
2025/04/22 01:50:51 DEBUG : : rmdir: removed from cache
2025/04/22 01:50:51 INFO  : : rmdir: cache expired
2025/04/22 01:50:51 DEBUG : Cache remote TestInternalCache:tionf1745286651: Services stopped
--- PASS: TestInternalObjNotFound (0.02s)
=== RUN   TestInternalCachedWrittenContentMatches
2025/04/22 01:50:51 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2025/04/22 01:50:51 DEBUG : Creating backend with remote "TestInternalCache-local:/tmp/TestInternalCache-local/ticwcm1745286651"
2025/04/22 01:50:51 DEBUG : TestInternalCache: wrapped TestInternalCache-local:/tmp/TestInternalCache-local/ticwcm1745286651 at root ticwcm1745286651
2025/04/22 01:50:51 INFO  : TestInternalCache: Cache DB path: /home/rclone/.cache/rclone/cache-backend/TestInternalCache.db
2025/04/22 01:50:51 INFO  : TestInternalCache: Cache chunk path: /home/rclone/.cache/rclone/cache-backend/TestInternalCache
2025/04/22 01:50:51 INFO  : TestInternalCache: Chunk Memory: true
2025/04/22 01:50:51 INFO  : TestInternalCache: Chunk Size: 5Mi
2025/04/22 01:50:51 INFO  : TestInternalCache: Chunk Total Size: 10Gi
2025/04/22 01:50:51 INFO  : TestInternalCache: Chunk Clean Interval: 1m0s
2025/04/22 01:50:51 INFO  : TestInternalCache: Workers: 4
2025/04/22 01:50:51 INFO  : TestInternalCache: File Age: 6h0m0s
2025/04/22 01:50:51 DEBUG : Waiting for deletions to finish
2025/04/22 01:50:51 DEBUG : Cache remote TestInternalCache:ticwcm1745286651: list ''
2025/04/22 01:50:51 DEBUG : : list: error: couldn't open bucket (ticwcm1745286651)
2025/04/22 01:50:51 ERROR : : error listing: directory not found
2025/04/22 01:50:51 DEBUG : Cache remote TestInternalCache:ticwcm1745286651: list ''
2025/04/22 01:50:51 DEBUG : : list: error: couldn't open bucket (ticwcm1745286651)
2025/04/22 01:50:51 ERROR : Cache remote TestInternalCache:ticwcm1745286651: Failed to list "": directory not found
2025/04/22 01:50:51 DEBUG : removing 1 level 0 directories
2025/04/22 01:50:51 INFO  : Cache remote TestInternalCache:ticwcm1745286651: Removing directory
2025/04/22 01:50:51 DEBUG : Cache remote TestInternalCache:ticwcm1745286651: rmdir ''
2025/04/22 01:50:51 ERROR : : Failed to rmdir: stat /tmp/TestInternalCache-local/ticwcm1745286651: no such file or directory
2025/04/22 01:50:51 DEBUG : Cache remote TestInternalCache:ticwcm1745286651: mkdir ''
2025/04/22 01:50:51 DEBUG : : mkdir: created dir in source fs
2025/04/22 01:50:51 DEBUG : : mkdir: added to cache
2025/04/22 01:50:51 DEBUG : : cache: expired ticwcm1745286651
2025/04/22 01:50:51 INFO  : : mkdir: cache expired
2025/04/22 01:50:52 DEBUG : Cache remote TestInternalCache:ticwcm1745286651: put data at 'data.bin'
2025/04/22 01:50:52 DEBUG : data.bin: put: uploaded to remote fs
2025/04/22 01:50:52 DEBUG : data.bin: put: added to cache
2025/04/22 01:50:52 DEBUG : : cache: expired ticwcm1745286651
2025/04/22 01:50:52 INFO  : : put: cache expired
2025/04/22 01:50:52 DEBUG : Cache remote TestInternalCache:ticwcm1745286651: new object 'data.bin'
2025/04/22 01:50:52 DEBUG : data.bin: find: warm object: data.bin, expiring on: 2025-04-22 07:50:52.050622 +0000 UTC
2025/04/22 01:50:52 DEBUG : Cache remote TestInternalCache:ticwcm1745286651: new object 'data.bin'
2025/04/22 01:50:52 DEBUG : data.bin: find: warm object: data.bin, expiring on: 2025-04-22 07:50:52.050622 +0000 UTC
2025/04/22 01:50:52 DEBUG : ticwcm1745286651/data.bin: moving offset set from 0 to 2621440
2025/04/22 01:50:52 DEBUG : ticwcm1745286651/data.bin: 0: chunk retry storage: 0
2025/04/22 01:50:52 DEBUG : worker-0 <data.bin>: downloaded chunk 0
2025/04/22 01:50:52 DEBUG : worker-3 <data.bin>: downloaded chunk 10485760
2025/04/22 01:50:52 DEBUG : worker-1 <data.bin>: downloaded chunk 15728640
2025/04/22 01:50:52 DEBUG : worker-2 <data.bin>: downloaded chunk 5242880
2025/04/22 01:50:52 DEBUG : ticwcm1745286651/data.bin: cache reader closed 5242880
2025/04/22 01:50:52 DEBUG : Waiting for deletions to finish
2025/04/22 01:50:52 DEBUG : Cache remote TestInternalCache:ticwcm1745286651: list ''
2025/04/22 01:50:52 DEBUG : : list: cold listing: 2025-04-21 19:50:52.052698388 +0000 UTC
2025/04/22 01:50:52 DEBUG : : list: read 1 from source
2025/04/22 01:50:52 DEBUG : : list: source entries: [data.bin]
2025/04/22 01:50:52 DEBUG : : list: cached object: data.bin
2025/04/22 01:50:52 DEBUG : : list: cached directories: 0
2025/04/22 01:50:52 DEBUG : : list: cached dir: 'ticwcm1745286651', cache ts: 2025-04-22 01:50:52.584054113 +0000 UTC m=+1.125257571
2025/04/22 01:50:52 DEBUG : data.bin: removing object
2025/04/22 01:50:52 DEBUG : : cache: expired ticwcm1745286651
2025/04/22 01:50:52 INFO  : data.bin: Deleted
2025/04/22 01:50:52 DEBUG : Cache remote TestInternalCache:ticwcm1745286651: list ''
2025/04/22 01:50:52 DEBUG : : list: cold listing: 2025-04-21 19:50:52.59638176 +0000 UTC
2025/04/22 01:50:52 DEBUG : : list: read 0 from source
2025/04/22 01:50:52 DEBUG : : list: source entries: []
2025/04/22 01:50:52 DEBUG : : list: cached directories: 0
2025/04/22 01:50:52 DEBUG : : list: cached dir: 'ticwcm1745286651', cache ts: 2025-04-22 01:50:52.597826862 +0000 UTC m=+1.139030301
2025/04/22 01:50:52 DEBUG : removing 1 level 0 directories
2025/04/22 01:50:52 INFO  : Cache remote TestInternalCache:ticwcm1745286651: Removing directory
2025/04/22 01:50:52 DEBUG : Cache remote TestInternalCache:ticwcm1745286651: rmdir ''
2025/04/22 01:50:52 DEBUG : : rmdir: removed dir in source fs
2025/04/22 01:50:52 DEBUG : : rmdir: removed from cache
2025/04/22 01:50:52 INFO  : : rmdir: cache expired
2025/04/22 01:50:52 DEBUG : Cache remote TestInternalCache:ticwcm1745286651: Services stopped
--- PASS: TestInternalCachedWrittenContentMatches (1.13s)
=== RUN   TestInternalDoubleWrittenContentMatches
2025/04/22 01:50:52 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2025/04/22 01:50:52 DEBUG : Creating backend with remote "TestInternalCache-local:/tmp/TestInternalCache-local/tidwcm1745286652"
2025/04/22 01:50:52 DEBUG : TestInternalCache: wrapped TestInternalCache-local:/tmp/TestInternalCache-local/tidwcm1745286652 at root tidwcm1745286652
2025/04/22 01:50:52 INFO  : TestInternalCache: Cache DB path: /home/rclone/.cache/rclone/cache-backend/TestInternalCache.db
2025/04/22 01:50:52 INFO  : TestInternalCache: Cache chunk path: /home/rclone/.cache/rclone/cache-backend/TestInternalCache
2025/04/22 01:50:52 INFO  : TestInternalCache: Chunk Memory: true
2025/04/22 01:50:52 INFO  : TestInternalCache: Chunk Size: 5Mi
2025/04/22 01:50:52 INFO  : TestInternalCache: Chunk Total Size: 10Gi
2025/04/22 01:50:52 INFO  : TestInternalCache: Chunk Clean Interval: 1m0s
2025/04/22 01:50:52 INFO  : TestInternalCache: Workers: 4
2025/04/22 01:50:52 INFO  : TestInternalCache: File Age: 6h0m0s
2025/04/22 01:50:52 DEBUG : Waiting for deletions to finish
2025/04/22 01:50:52 DEBUG : Cache remote TestInternalCache:tidwcm1745286652: list ''
2025/04/22 01:50:52 DEBUG : : list: error: couldn't open bucket (tidwcm1745286652)
2025/04/22 01:50:52 ERROR : : error listing: directory not found
2025/04/22 01:50:52 DEBUG : Cache remote TestInternalCache:tidwcm1745286652: list ''
2025/04/22 01:50:52 DEBUG : : list: error: couldn't open bucket (tidwcm1745286652)
2025/04/22 01:50:52 ERROR : Cache remote TestInternalCache:tidwcm1745286652: Failed to list "": directory not found
2025/04/22 01:50:52 DEBUG : removing 1 level 0 directories
2025/04/22 01:50:52 INFO  : Cache remote TestInternalCache:tidwcm1745286652: Removing directory
2025/04/22 01:50:52 DEBUG : Cache remote TestInternalCache:tidwcm1745286652: rmdir ''
2025/04/22 01:50:52 ERROR : : Failed to rmdir: stat /tmp/TestInternalCache-local/tidwcm1745286652: no such file or directory
2025/04/22 01:50:52 DEBUG : Cache remote TestInternalCache:tidwcm1745286652: mkdir ''
2025/04/22 01:50:52 DEBUG : : mkdir: created dir in source fs
2025/04/22 01:50:52 DEBUG : : mkdir: added to cache
2025/04/22 01:50:52 DEBUG : : cache: expired tidwcm1745286652
2025/04/22 01:50:52 INFO  : : mkdir: cache expired
2025/04/22 01:50:52 DEBUG : Cache remote TestInternalCache:tidwcm1745286652: put data at 'one'
2025/04/22 01:50:52 DEBUG : one: put: uploaded to remote fs
2025/04/22 01:50:52 DEBUG : one: put: added to cache
2025/04/22 01:50:52 DEBUG : : cache: expired tidwcm1745286652
2025/04/22 01:50:52 INFO  : : put: cache expired
2025/04/22 01:50:52 DEBUG : Cache remote TestInternalCache:tidwcm1745286652: new object 'one'
2025/04/22 01:50:52 DEBUG : one: find: warm object: one, expiring on: 2025-04-22 07:50:52.627214018 +0000 UTC
2025/04/22 01:50:52 DEBUG : Cache remote TestInternalCache:tidwcm1745286652: new object 'one'
2025/04/22 01:50:52 DEBUG : one: find: warm object: one, expiring on: 2025-04-22 07:50:52.627214018 +0000 UTC
2025/04/22 01:50:52 DEBUG : one: updating object contents with size 19
2025/04/22 01:50:52 DEBUG : Cache remote TestInternalCache:tidwcm1745286652: new object 'one'
2025/04/22 01:50:52 DEBUG : one: find: warm object: one, expiring on: 2025-04-22 07:50:52.632611037 +0000 UTC
2025/04/22 01:50:52 DEBUG : one: updating object contents with size 26
2025/04/22 01:50:52 DEBUG : Cache remote TestInternalCache:tidwcm1745286652: new object 'one'
2025/04/22 01:50:52 DEBUG : one: find: warm object: one, expiring on: 2025-04-22 07:50:52.635855848 +0000 UTC
2025/04/22 01:50:52 DEBUG : tidwcm1745286652/one: moving offset set from 0 to 0
2025/04/22 01:50:52 DEBUG : tidwcm1745286652/one: 0: chunk retry storage: 0
2025/04/22 01:50:52 DEBUG : worker-0 <one>: partial downloaded chunk 0
2025/04/22 01:50:53 DEBUG : tidwcm1745286652/one: cache reader closed 26
2025/04/22 01:50:53 DEBUG : Waiting for deletions to finish
2025/04/22 01:50:53 DEBUG : Cache remote TestInternalCache:tidwcm1745286652: list ''
2025/04/22 01:50:53 DEBUG : : list: cold listing: 2025-04-21 19:50:52.629356079 +0000 UTC
2025/04/22 01:50:53 DEBUG : : list: read 1 from source
2025/04/22 01:50:53 DEBUG : : list: source entries: [one]
2025/04/22 01:50:53 DEBUG : : list: cached object: one
2025/04/22 01:50:53 DEBUG : : list: cached directories: 0
2025/04/22 01:50:53 DEBUG : : list: cached dir: 'tidwcm1745286652', cache ts: 2025-04-22 01:50:53.140081955 +0000 UTC m=+1.681285464
2025/04/22 01:50:53 DEBUG : one: removing object
2025/04/22 01:50:53 DEBUG : : cache: expired tidwcm1745286652
2025/04/22 01:50:53 INFO  : one: Deleted
2025/04/22 01:50:53 DEBUG : Cache remote TestInternalCache:tidwcm1745286652: list ''
2025/04/22 01:50:53 DEBUG : : list: cold listing: 2025-04-21 19:50:53.142916265 +0000 UTC
2025/04/22 01:50:53 DEBUG : : list: read 0 from source
2025/04/22 01:50:53 DEBUG : : list: source entries: []
2025/04/22 01:50:53 DEBUG : : list: cached directories: 0
2025/04/22 01:50:53 DEBUG : : list: cached dir: 'tidwcm1745286652', cache ts: 2025-04-22 01:50:53.143874342 +0000 UTC m=+1.685077770
2025/04/22 01:50:53 DEBUG : removing 1 level 0 directories
2025/04/22 01:50:53 INFO  : Cache remote TestInternalCache:tidwcm1745286652: Removing directory
2025/04/22 01:50:53 DEBUG : Cache remote TestInternalCache:tidwcm1745286652: rmdir ''
2025/04/22 01:50:53 DEBUG : : rmdir: removed dir in source fs
2025/04/22 01:50:53 DEBUG : : rmdir: removed from cache
2025/04/22 01:50:53 INFO  : : rmdir: cache expired
2025/04/22 01:50:53 DEBUG : Cache remote TestInternalCache:tidwcm1745286652: Services stopped
--- PASS: TestInternalDoubleWrittenContentMatches (0.54s)
=== RUN   TestInternalCachedUpdatedContentMatches
2025/04/22 01:50:53 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2025/04/22 01:50:53 DEBUG : Creating backend with remote "TestInternalCache-local:/tmp/TestInternalCache-local/ticucm1745286653"
2025/04/22 01:50:53 DEBUG : TestInternalCache: wrapped TestInternalCache-local:/tmp/TestInternalCache-local/ticucm1745286653 at root ticucm1745286653
2025/04/22 01:50:53 INFO  : TestInternalCache: Cache DB path: /home/rclone/.cache/rclone/cache-backend/TestInternalCache.db
2025/04/22 01:50:53 INFO  : TestInternalCache: Cache chunk path: /home/rclone/.cache/rclone/cache-backend/TestInternalCache
2025/04/22 01:50:53 INFO  : TestInternalCache: Chunk Memory: true
2025/04/22 01:50:53 INFO  : TestInternalCache: Chunk Size: 5Mi
2025/04/22 01:50:53 INFO  : TestInternalCache: Chunk Total Size: 10Gi
2025/04/22 01:50:53 INFO  : TestInternalCache: Chunk Clean Interval: 1m0s
2025/04/22 01:50:53 INFO  : TestInternalCache: Workers: 4
2025/04/22 01:50:53 INFO  : TestInternalCache: File Age: 6h0m0s
2025/04/22 01:50:53 DEBUG : Waiting for deletions to finish
2025/04/22 01:50:53 DEBUG : Cache remote TestInternalCache:ticucm1745286653: list ''
2025/04/22 01:50:53 DEBUG : : list: error: couldn't open bucket (ticucm1745286653)
2025/04/22 01:50:53 ERROR : : error listing: directory not found
2025/04/22 01:50:53 DEBUG : Cache remote TestInternalCache:ticucm1745286653: list ''
2025/04/22 01:50:53 DEBUG : : list: error: couldn't open bucket (ticucm1745286653)
2025/04/22 01:50:53 ERROR : Cache remote TestInternalCache:ticucm1745286653: Failed to list "": directory not found
2025/04/22 01:50:53 DEBUG : removing 1 level 0 directories
2025/04/22 01:50:53 INFO  : Cache remote TestInternalCache:ticucm1745286653: Removing directory
2025/04/22 01:50:53 DEBUG : Cache remote TestInternalCache:ticucm1745286653: rmdir ''
2025/04/22 01:50:53 ERROR : : Failed to rmdir: stat /tmp/TestInternalCache-local/ticucm1745286653: no such file or directory
2025/04/22 01:50:53 DEBUG : Cache remote TestInternalCache:ticucm1745286653: mkdir ''
2025/04/22 01:50:53 DEBUG : : mkdir: created dir in source fs
2025/04/22 01:50:53 DEBUG : : mkdir: added to cache
2025/04/22 01:50:53 DEBUG : : cache: expired ticucm1745286653
2025/04/22 01:50:53 INFO  : : mkdir: cache expired
2025/04/22 01:50:53 DEBUG : Cache remote TestInternalCache:ticucm1745286653: put data at 'data.bin'
2025/04/22 01:50:53 DEBUG : data.bin: put: uploaded to remote fs
2025/04/22 01:50:53 DEBUG : data.bin: put: added to cache
2025/04/22 01:50:53 DEBUG : : cache: expired ticucm1745286653
2025/04/22 01:50:53 INFO  : : put: cache expired
2025/04/22 01:50:53 DEBUG : Cache remote TestInternalCache:ticucm1745286653: new object 'data.bin'
2025/04/22 01:50:53 DEBUG : data.bin: find: warm object: data.bin, expiring on: 2025-04-22 07:50:53.175945556 +0000 UTC
2025/04/22 01:50:53 DEBUG : data.bin: updating object contents with size 200
2025/04/22 01:50:53 DEBUG : Cache remote TestInternalCache:ticucm1745286653: new object 'data.bin'
2025/04/22 01:50:53 DEBUG : data.bin: find: warm object: data.bin, expiring on: 2025-04-22 07:50:53.190220637 +0000 UTC
2025/04/22 01:50:53 DEBUG : ticucm1745286653/data.bin: moving offset set from 0 to 0
2025/04/22 01:50:53 DEBUG : ticucm1745286653/data.bin: 0: chunk retry storage: 0
2025/04/22 01:50:53 DEBUG : worker-1 <data.bin>: partial downloaded chunk 0
2025/04/22 01:50:53 DEBUG : ticucm1745286653/data.bin: cache reader closed 200
2025/04/22 01:50:53 DEBUG : Waiting for deletions to finish
2025/04/22 01:50:53 DEBUG : Cache remote TestInternalCache:ticucm1745286653: list ''
2025/04/22 01:50:53 DEBUG : : list: cold listing: 2025-04-21 19:50:53.179407964 +0000 UTC
2025/04/22 01:50:53 DEBUG : : list: read 1 from source
2025/04/22 01:50:53 DEBUG : : list: source entries: [data.bin]
2025/04/22 01:50:53 DEBUG : : list: cached object: data.bin
2025/04/22 01:50:53 DEBUG : : list: cached directories: 0
2025/04/22 01:50:53 DEBUG : : list: cached dir: 'ticucm1745286653', cache ts: 2025-04-22 01:50:53.696407495 +0000 UTC m=+2.237610923
2025/04/22 01:50:53 DEBUG : data.bin: removing object
2025/04/22 01:50:53 DEBUG : : cache: expired ticucm1745286653
2025/04/22 01:50:53 INFO  : data.bin: Deleted
2025/04/22 01:50:53 DEBUG : Cache remote TestInternalCache:ticucm1745286653: list ''
2025/04/22 01:50:53 DEBUG : : list: cold listing: 2025-04-21 19:50:53.698807159 +0000 UTC
2025/04/22 01:50:53 DEBUG : : list: read 0 from source
2025/04/22 01:50:53 DEBUG : : list: source entries: []
2025/04/22 01:50:53 DEBUG : : list: cached directories: 0
2025/04/22 01:50:53 DEBUG : : list: cached dir: 'ticucm1745286653', cache ts: 2025-04-22 01:50:53.69959069 +0000 UTC m=+2.240794118
2025/04/22 01:50:53 DEBUG : removing 1 level 0 directories
2025/04/22 01:50:53 INFO  : Cache remote TestInternalCache:ticucm1745286653: Removing directory
2025/04/22 01:50:53 DEBUG : Cache remote TestInternalCache:ticucm1745286653: rmdir ''
2025/04/22 01:50:53 DEBUG : : rmdir: removed dir in source fs
2025/04/22 01:50:53 DEBUG : : rmdir: removed from cache
2025/04/22 01:50:53 INFO  : : rmdir: cache expired
2025/04/22 01:50:53 DEBUG : Cache remote TestInternalCache:ticucm1745286653: Services stopped
--- PASS: TestInternalCachedUpdatedContentMatches (0.56s)
=== RUN   TestInternalWrappedWrittenContentMatches
2025/04/22 01:50:53 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/22 01:50:53 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/22 01:50:53 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2025/04/22 01:50:53 DEBUG : Creating backend with remote "TestInternalCache-local:/tmp/TestInternalCache-local/tiwfcns1745286653"
2025/04/22 01:50:53 DEBUG : TestInternalCache: wrapped TestInternalCache-local:/tmp/TestInternalCache-local/tiwfcns1745286653 at root tiwfcns1745286653
2025/04/22 01:50:53 INFO  : TestInternalCache: Cache DB path: /home/rclone/.cache/rclone/cache-backend/TestInternalCache.db
2025/04/22 01:50:53 INFO  : TestInternalCache: Cache chunk path: /home/rclone/.cache/rclone/cache-backend/TestInternalCache
2025/04/22 01:50:53 INFO  : TestInternalCache: Chunk Memory: true
2025/04/22 01:50:53 INFO  : TestInternalCache: Chunk Size: 5Mi
2025/04/22 01:50:53 INFO  : TestInternalCache: Chunk Total Size: 10Gi
2025/04/22 01:50:53 INFO  : TestInternalCache: Chunk Clean Interval: 1m0s
2025/04/22 01:50:53 INFO  : TestInternalCache: Workers: 4
2025/04/22 01:50:53 INFO  : TestInternalCache: File Age: 6h0m0s
2025/04/22 01:50:53 DEBUG : Waiting for deletions to finish
2025/04/22 01:50:53 DEBUG : Cache remote TestInternalCache:tiwfcns1745286653: list ''
2025/04/22 01:50:53 DEBUG : : list: error: couldn't open bucket (tiwfcns1745286653)
2025/04/22 01:50:53 ERROR : : error listing: directory not found
2025/04/22 01:50:53 DEBUG : Cache remote TestInternalCache:tiwfcns1745286653: list ''
2025/04/22 01:50:53 DEBUG : : list: error: couldn't open bucket (tiwfcns1745286653)
2025/04/22 01:50:53 ERROR : Cache remote TestInternalCache:tiwfcns1745286653: Failed to list "": directory not found
2025/04/22 01:50:53 DEBUG : removing 1 level 0 directories
2025/04/22 01:50:53 INFO  : Cache remote TestInternalCache:tiwfcns1745286653: Removing directory
2025/04/22 01:50:53 DEBUG : Cache remote TestInternalCache:tiwfcns1745286653: rmdir ''
2025/04/22 01:50:53 ERROR : : Failed to rmdir: stat /tmp/TestInternalCache-local/tiwfcns1745286653: no such file or directory
2025/04/22 01:50:53 DEBUG : Cache remote TestInternalCache:tiwfcns1745286653: mkdir ''
2025/04/22 01:50:53 DEBUG : : mkdir: created dir in source fs
2025/04/22 01:50:53 DEBUG : : mkdir: added to cache
2025/04/22 01:50:53 DEBUG : : cache: expired tiwfcns1745286653
2025/04/22 01:50:53 INFO  : : mkdir: cache expired
2025/04/22 01:50:54 DEBUG : Cache remote TestInternalCache:tiwfcns1745286653: put data at 'data.bin'
2025/04/22 01:50:54 DEBUG : data.bin: put: uploaded to remote fs
2025/04/22 01:50:54 DEBUG : data.bin: put: added to cache
2025/04/22 01:50:54 DEBUG : : cache: expired tiwfcns1745286653
2025/04/22 01:50:54 INFO  : : put: cache expired
2025/04/22 01:50:54 DEBUG : Cache remote TestInternalCache:tiwfcns1745286653: new object 'data.bin'
2025/04/22 01:50:54 DEBUG : data.bin: find: warm object: data.bin, expiring on: 2025-04-22 07:50:54.314584802 +0000 UTC
2025/04/22 01:50:54 DEBUG : Cache remote TestInternalCache:tiwfcns1745286653: new object 'data.bin'
2025/04/22 01:50:54 DEBUG : data.bin: find: warm object: data.bin, expiring on: 2025-04-22 07:50:54.314584802 +0000 UTC
2025/04/22 01:50:54 NOTICE: original size: 23592960
2025/04/22 01:50:54 NOTICE: updated size: 12
2025/04/22 01:50:54 DEBUG : Cache remote TestInternalCache:tiwfcns1745286653: new object 'data.bin'
2025/04/22 01:50:54 DEBUG : data.bin: find: warm object: data.bin, expiring on: 2025-04-22 07:50:54.314584802 +0000 UTC
2025/04/22 01:50:54 DEBUG : Waiting for deletions to finish
2025/04/22 01:50:54 DEBUG : Cache remote TestInternalCache:tiwfcns1745286653: list ''
2025/04/22 01:50:54 DEBUG : : list: cold listing: 2025-04-21 19:50:54.348871423 +0000 UTC
2025/04/22 01:50:54 DEBUG : : list: read 1 from source
2025/04/22 01:50:54 DEBUG : : list: source entries: [data.bin]
2025/04/22 01:50:54 DEBUG : : list: cached object: data.bin
2025/04/22 01:50:54 DEBUG : : list: cached directories: 0
2025/04/22 01:50:54 DEBUG : : list: cached dir: 'tiwfcns1745286653', cache ts: 2025-04-22 01:50:54.376886374 +0000 UTC m=+2.918089801
2025/04/22 01:50:54 DEBUG : data.bin: removing object
2025/04/22 01:50:54 DEBUG : : cache: expired tiwfcns1745286653
2025/04/22 01:50:54 INFO  : data.bin: Deleted
2025/04/22 01:50:54 DEBUG : Cache remote TestInternalCache:tiwfcns1745286653: list ''
2025/04/22 01:50:54 DEBUG : : list: cold listing: 2025-04-21 19:50:54.420824588 +0000 UTC
2025/04/22 01:50:54 DEBUG : : list: read 0 from source
2025/04/22 01:50:54 DEBUG : : list: source entries: []
2025/04/22 01:50:54 DEBUG : : list: cached directories: 0
2025/04/22 01:50:54 DEBUG : : list: cached dir: 'tiwfcns1745286653', cache ts: 2025-04-22 01:50:54.429245984 +0000 UTC m=+2.970449412
2025/04/22 01:50:54 DEBUG : removing 1 level 0 directories
2025/04/22 01:50:54 INFO  : Cache remote TestInternalCache:tiwfcns1745286653: Removing directory
2025/04/22 01:50:54 DEBUG : Cache remote TestInternalCache:tiwfcns1745286653: rmdir ''
2025/04/22 01:50:54 DEBUG : : rmdir: removed dir in source fs
2025/04/22 01:50:54 DEBUG : : rmdir: removed from cache
2025/04/22 01:50:54 INFO  : : rmdir: cache expired
2025/04/22 01:50:54 DEBUG : Cache remote TestInternalCache:tiwfcns1745286653: Services stopped
--- PASS: TestInternalWrappedFsChangeNotSeen (0.76s)
=== RUN   TestInternalMoveWithNotify
2025/04/22 01:50:54 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2025/04/22 01:50:54 DEBUG : Creating backend with remote "TestInternalCache-local:/tmp/TestInternalCache-local/timwn1745286654"
2025/04/22 01:50:54 DEBUG : TestInternalCache: wrapped TestInternalCache-local:/tmp/TestInternalCache-local/timwn1745286654 at root timwn1745286654
2025/04/22 01:50:54 INFO  : TestInternalCache: Cache DB path: /home/rclone/.cache/rclone/cache-backend/TestInternalCache.db
2025/04/22 01:50:54 INFO  : TestInternalCache: Cache chunk path: /home/rclone/.cache/rclone/cache-backend/TestInternalCache
2025/04/22 01:50:54 INFO  : TestInternalCache: Chunk Memory: true
2025/04/22 01:50:54 INFO  : TestInternalCache: Chunk Size: 5Mi
2025/04/22 01:50:54 INFO  : TestInternalCache: Chunk Total Size: 10Gi
2025/04/22 01:50:54 INFO  : TestInternalCache: Chunk Clean Interval: 1m0s
2025/04/22 01:50:54 INFO  : TestInternalCache: Workers: 4
2025/04/22 01:50:54 INFO  : TestInternalCache: File Age: 6h0m0s
2025/04/22 01:50:54 DEBUG : Waiting for deletions to finish
2025/04/22 01:50:54 DEBUG : Cache remote TestInternalCache:timwn1745286654: list ''
2025/04/22 01:50:54 DEBUG : : list: error: couldn't open bucket (timwn1745286654)
2025/04/22 01:50:54 ERROR : : error listing: directory not found
2025/04/22 01:50:54 DEBUG : Cache remote TestInternalCache:timwn1745286654: list ''
2025/04/22 01:50:54 DEBUG : : list: error: couldn't open bucket (timwn1745286654)
2025/04/22 01:50:54 ERROR : Cache remote TestInternalCache:timwn1745286654: Failed to list "": directory not found
2025/04/22 01:50:54 DEBUG : removing 1 level 0 directories
2025/04/22 01:50:54 INFO  : Cache remote TestInternalCache:timwn1745286654: Removing directory
2025/04/22 01:50:54 DEBUG : Cache remote TestInternalCache:timwn1745286654: rmdir ''
2025/04/22 01:50:54 ERROR : : Failed to rmdir: stat /tmp/TestInternalCache-local/timwn1745286654: no such file or directory
2025/04/22 01:50:54 DEBUG : Cache remote TestInternalCache:timwn1745286654: mkdir ''
2025/04/22 01:50:54 DEBUG : : mkdir: created dir in source fs
2025/04/22 01:50:54 DEBUG : : mkdir: added to cache
2025/04/22 01:50:54 DEBUG : : cache: expired timwn1745286654
2025/04/22 01:50:54 INFO  : : mkdir: cache expired
    cache_internal_test.go:453: Not external
2025/04/22 01:50:54 DEBUG : Waiting for deletions to finish
2025/04/22 01:50:54 DEBUG : Cache remote TestInternalCache:timwn1745286654: list ''
2025/04/22 01:50:54 DEBUG : : list: cold listing: 2025-04-21 19:50:54.508833077 +0000 UTC
2025/04/22 01:50:54 DEBUG : : list: read 0 from source
2025/04/22 01:50:54 DEBUG : : list: source entries: []
2025/04/22 01:50:54 DEBUG : : list: cached directories: 0
2025/04/22 01:50:54 DEBUG : : list: cached dir: 'timwn1745286654', cache ts: 2025-04-22 01:50:54.514803492 +0000 UTC m=+3.056006910
2025/04/22 01:50:54 DEBUG : Cache remote TestInternalCache:timwn1745286654: list ''
2025/04/22 01:50:54 DEBUG : : list: empty listing
2025/04/22 01:50:54 DEBUG : : list: read 0 from source
2025/04/22 01:50:54 DEBUG : : list: source entries: []
2025/04/22 01:50:54 DEBUG : : list: cached directories: 0
2025/04/22 01:50:54 DEBUG : : list: cached dir: 'timwn1745286654', cache ts: 2025-04-22 01:50:54.522004959 +0000 UTC m=+3.063208387
2025/04/22 01:50:54 DEBUG : removing 1 level 0 directories
2025/04/22 01:50:54 INFO  : Cache remote TestInternalCache:timwn1745286654: Removing directory
2025/04/22 01:50:54 DEBUG : Cache remote TestInternalCache:timwn1745286654: rmdir ''
2025/04/22 01:50:54 DEBUG : : rmdir: removed dir in source fs
2025/04/22 01:50:54 DEBUG : : rmdir: removed from cache
2025/04/22 01:50:54 INFO  : : rmdir: cache expired
2025/04/22 01:50:54 DEBUG : Cache remote TestInternalCache:timwn1745286654: Services stopped
--- SKIP: TestInternalMoveWithNotify (0.06s)
=== RUN   TestInternalNotifyCreatesEmptyParts
2025/04/22 01:50:54 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2025/04/22 01:50:54 DEBUG : Creating backend with remote "TestInternalCache-local:/tmp/TestInternalCache-local/tincep1745286654"
2025/04/22 01:50:54 DEBUG : TestInternalCache: wrapped TestInternalCache-local:/tmp/TestInternalCache-local/tincep1745286654 at root tincep1745286654
2025/04/22 01:50:54 INFO  : TestInternalCache: Cache DB path: /home/rclone/.cache/rclone/cache-backend/TestInternalCache.db
2025/04/22 01:50:54 INFO  : TestInternalCache: Cache chunk path: /home/rclone/.cache/rclone/cache-backend/TestInternalCache
2025/04/22 01:50:54 INFO  : TestInternalCache: Chunk Memory: true
2025/04/22 01:50:54 INFO  : TestInternalCache: Chunk Size: 5Mi
2025/04/22 01:50:54 INFO  : TestInternalCache: Chunk Total Size: 10Gi
2025/04/22 01:50:54 INFO  : TestInternalCache: Chunk Clean Interval: 1m0s
2025/04/22 01:50:54 INFO  : TestInternalCache: Workers: 4
2025/04/22 01:50:54 INFO  : TestInternalCache: File Age: 6h0m0s
2025/04/22 01:50:54 DEBUG : Cache remote TestInternalCache:tincep1745286654: list ''
2025/04/22 01:50:54 DEBUG : : list: error: couldn't open bucket (tincep1745286654)
2025/04/22 01:50:54 ERROR : : error listing: directory not found
2025/04/22 01:50:54 DEBUG : Waiting for deletions to finish
2025/04/22 01:50:54 DEBUG : Cache remote TestInternalCache:tincep1745286654: list ''
2025/04/22 01:50:54 DEBUG : : list: error: couldn't open bucket (tincep1745286654)
2025/04/22 01:50:54 ERROR : Cache remote TestInternalCache:tincep1745286654: Failed to list "": directory not found
2025/04/22 01:50:54 DEBUG : removing 1 level 0 directories
2025/04/22 01:50:54 INFO  : Cache remote TestInternalCache:tincep1745286654: Removing directory
2025/04/22 01:50:54 DEBUG : Cache remote TestInternalCache:tincep1745286654: rmdir ''
2025/04/22 01:50:54 ERROR : : Failed to rmdir: stat /tmp/TestInternalCache-local/tincep1745286654: no such file or directory
2025/04/22 01:50:54 DEBUG : Cache remote TestInternalCache:tincep1745286654: mkdir ''
2025/04/22 01:50:54 DEBUG : : mkdir: created dir in source fs
2025/04/22 01:50:54 DEBUG : : mkdir: added to cache
2025/04/22 01:50:54 DEBUG : : cache: expired tincep1745286654
2025/04/22 01:50:54 INFO  : : mkdir: cache expired
    cache_internal_test.go:539: Not external
2025/04/22 01:50:54 DEBUG : Waiting for deletions to finish
2025/04/22 01:50:54 DEBUG : Cache remote TestInternalCache:tincep1745286654: list ''
2025/04/22 01:50:54 DEBUG : : list: cold listing: 2025-04-21 19:50:54.534955945 +0000 UTC
2025/04/22 01:50:54 DEBUG : : list: read 0 from source
2025/04/22 01:50:54 DEBUG : : list: source entries: []
2025/04/22 01:50:54 DEBUG : : list: cached directories: 0
2025/04/22 01:50:54 DEBUG : : list: cached dir: 'tincep1745286654', cache ts: 2025-04-22 01:50:54.536123267 +0000 UTC m=+3.077326695
2025/04/22 01:50:54 DEBUG : Cache remote TestInternalCache:tincep1745286654: list ''
2025/04/22 01:50:54 DEBUG : : list: empty listing
2025/04/22 01:50:54 DEBUG : : list: read 0 from source
2025/04/22 01:50:54 DEBUG : : list: source entries: []
2025/04/22 01:50:54 DEBUG : : list: cached directories: 0
2025/04/22 01:50:54 DEBUG : : list: cached dir: 'tincep1745286654', cache ts: 2025-04-22 01:50:54.537448304 +0000 UTC m=+3.078651723
2025/04/22 01:50:54 DEBUG : removing 1 level 0 directories
2025/04/22 01:50:54 INFO  : Cache remote TestInternalCache:tincep1745286654: Removing directory
2025/04/22 01:50:54 DEBUG : Cache remote TestInternalCache:tincep1745286654: rmdir ''
2025/04/22 01:50:54 DEBUG : : rmdir: removed dir in source fs
2025/04/22 01:50:54 DEBUG : : rmdir: removed from cache
2025/04/22 01:50:54 INFO  : : rmdir: cache expired
2025/04/22 01:50:54 DEBUG : Cache remote TestInternalCache:tincep1745286654: Services stopped
--- SKIP: TestInternalNotifyCreatesEmptyParts (0.01s)
=== RUN   TestInternalChangeSeenAfterDirCacheFlush
2025/04/22 01:50:54 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2025/04/22 01:50:54 DEBUG : Creating backend with remote "TestInternalCache-local:/tmp/TestInternalCache-local/ticsadcf1745286654"
2025/04/22 01:50:54 DEBUG : TestInternalCache: wrapped TestInternalCache-local:/tmp/TestInternalCache-local/ticsadcf1745286654 at root ticsadcf1745286654
2025/04/22 01:50:54 INFO  : TestInternalCache: Cache DB path: /home/rclone/.cache/rclone/cache-backend/TestInternalCache.db
2025/04/22 01:50:54 INFO  : TestInternalCache: Cache chunk path: /home/rclone/.cache/rclone/cache-backend/TestInternalCache
2025/04/22 01:50:54 INFO  : TestInternalCache: Chunk Memory: true
2025/04/22 01:50:54 INFO  : TestInternalCache: Chunk Size: 5Mi
2025/04/22 01:50:54 INFO  : TestInternalCache: Chunk Total Size: 10Gi
2025/04/22 01:50:54 INFO  : TestInternalCache: Chunk Clean Interval: 1m0s
2025/04/22 01:50:54 INFO  : TestInternalCache: Workers: 4
2025/04/22 01:50:54 INFO  : TestInternalCache: File Age: 6h0m0s
2025/04/22 01:50:54 DEBUG : Waiting for deletions to finish
2025/04/22 01:50:54 DEBUG : Cache remote TestInternalCache:ticsadcf1745286654: list ''
2025/04/22 01:50:54 DEBUG : : list: error: couldn't open bucket (ticsadcf1745286654)
2025/04/22 01:50:54 ERROR : : error listing: directory not found
2025/04/22 01:50:54 DEBUG : Cache remote TestInternalCache:ticsadcf1745286654: list ''
2025/04/22 01:50:54 DEBUG : : list: error: couldn't open bucket (ticsadcf1745286654)
2025/04/22 01:50:54 ERROR : Cache remote TestInternalCache:ticsadcf1745286654: Failed to list "": directory not found
2025/04/22 01:50:54 DEBUG : removing 1 level 0 directories
2025/04/22 01:50:54 INFO  : Cache remote TestInternalCache:ticsadcf1745286654: Removing directory
2025/04/22 01:50:54 DEBUG : Cache remote TestInternalCache:ticsadcf1745286654: rmdir ''
2025/04/22 01:50:54 ERROR : : Failed to rmdir: stat /tmp/TestInternalCache-local/ticsadcf1745286654: no such file or directory
2025/04/22 01:50:54 DEBUG : Cache remote TestInternalCache:ticsadcf1745286654: mkdir ''
2025/04/22 01:50:54 DEBUG : : mkdir: created dir in source fs
2025/04/22 01:50:54 DEBUG : : mkdir: added to cache
2025/04/22 01:50:54 DEBUG : : cache: expired ticsadcf1745286654
2025/04/22 01:50:54 INFO  : : mkdir: cache expired
2025/04/22 01:50:55 DEBUG : Cache remote TestInternalCache:ticsadcf1745286654: put data at 'data.bin'
2025/04/22 01:50:55 DEBUG : data.bin: put: uploaded to remote fs
2025/04/22 01:50:55 DEBUG : data.bin: put: added to cache
2025/04/22 01:50:55 DEBUG : : cache: expired ticsadcf1745286654
2025/04/22 01:50:55 INFO  : : put: cache expired
2025/04/22 01:50:55 DEBUG : Cache remote TestInternalCache:ticsadcf1745286654: new object 'data.bin'
2025/04/22 01:50:55 DEBUG : data.bin: find: warm object: data.bin, expiring on: 2025-04-22 07:50:55.08892294 +0000 UTC
2025/04/22 01:50:55 DEBUG : Cache remote TestInternalCache:ticsadcf1745286654: new object 'data.bin'
2025/04/22 01:50:55 DEBUG : data.bin: find: warm object: data.bin, expiring on: 2025-04-22 07:50:55.08892294 +0000 UTC
2025/04/22 01:50:55 DEBUG : Cache remote TestInternalCache:ticsadcf1745286654: new object 'data.bin'
2025/04/22 01:50:55 DEBUG : data.bin: find: error: couldn't open parent bucket for ticsadcf1745286654
2025/04/22 01:50:55 DEBUG : data.bin: find: cached object
2025/04/22 01:50:55 DEBUG : Waiting for deletions to finish
2025/04/22 01:50:55 DEBUG : Cache remote TestInternalCache:ticsadcf1745286654: list ''
2025/04/22 01:50:55 DEBUG : : list: error: missing cached dir: 
2025/04/22 01:50:55 DEBUG : : list: read 1 from source
2025/04/22 01:50:55 DEBUG : : list: source entries: [data.bin]
2025/04/22 01:50:55 DEBUG : : list: cached object: data.bin
2025/04/22 01:50:55 DEBUG : : list: cached directories: 0
2025/04/22 01:50:55 DEBUG : : list: cached dir: 'ticsadcf1745286654', cache ts: 2025-04-22 01:50:55.119785554 +0000 UTC m=+3.660988982
2025/04/22 01:50:55 DEBUG : data.bin: removing object
2025/04/22 01:50:55 DEBUG : : cache: expired ticsadcf1745286654
2025/04/22 01:50:55 INFO  : data.bin: Deleted
2025/04/22 01:50:55 DEBUG : Cache remote TestInternalCache:ticsadcf1745286654: list ''
2025/04/22 01:50:55 DEBUG : : list: cold listing: 2025-04-21 19:50:55.12838818 +0000 UTC
2025/04/22 01:50:55 DEBUG : : list: read 0 from source
2025/04/22 01:50:55 DEBUG : : list: source entries: []
2025/04/22 01:50:55 DEBUG : : list: cached directories: 0
2025/04/22 01:50:55 DEBUG : : list: cached dir: 'ticsadcf1745286654', cache ts: 2025-04-22 01:50:55.12957139 +0000 UTC m=+3.670774819
2025/04/22 01:50:55 DEBUG : removing 1 level 0 directories
2025/04/22 01:50:55 INFO  : Cache remote TestInternalCache:ticsadcf1745286654: Removing directory
2025/04/22 01:50:55 DEBUG : Cache remote TestInternalCache:ticsadcf1745286654: rmdir ''
2025/04/22 01:50:55 DEBUG : : rmdir: removed dir in source fs
2025/04/22 01:50:55 DEBUG : : rmdir: removed from cache
2025/04/22 01:50:55 INFO  : : rmdir: cache expired
2025/04/22 01:50:55 DEBUG : Cache remote TestInternalCache:ticsadcf1745286654: Services stopped
--- PASS: TestInternalChangeSeenAfterDirCacheFlush (0.61s)
=== RUN   TestInternalCacheWrites
2025/04/22 01:50:55 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2025/04/22 01:50:55 DEBUG : Creating backend with remote "TestInternalCache-local:/tmp/TestInternalCache-local/ticw"
2025/04/22 01:50:55 DEBUG : TestInternalCache: wrapped TestInternalCache-local:/tmp/TestInternalCache-local/ticw at root ticw
2025/04/22 01:50:55 INFO  : TestInternalCache: Cache DB path: /home/rclone/.cache/rclone/cache-backend/TestInternalCache.db
2025/04/22 01:50:55 INFO  : TestInternalCache: Cache chunk path: /home/rclone/.cache/rclone/cache-backend/TestInternalCache
2025/04/22 01:50:55 INFO  : TestInternalCache: Chunk Memory: true
2025/04/22 01:50:55 INFO  : TestInternalCache: Chunk Size: 5Mi
2025/04/22 01:50:55 INFO  : TestInternalCache: Chunk Total Size: 10Gi
2025/04/22 01:50:55 INFO  : TestInternalCache: Chunk Clean Interval: 1m0s
2025/04/22 01:50:55 INFO  : TestInternalCache: Workers: 4
2025/04/22 01:50:55 INFO  : TestInternalCache: File Age: 6h0m0s
2025/04/22 01:50:55 INFO  : TestInternalCache: Cache Writes: enabled
2025/04/22 01:50:55 DEBUG : Waiting for deletions to finish
2025/04/22 01:50:55 DEBUG : Cache remote TestInternalCache:ticw: list ''
2025/04/22 01:50:55 DEBUG : : list: error: couldn't open bucket (ticw)
2025/04/22 01:50:55 ERROR : : error listing: directory not found
2025/04/22 01:50:55 DEBUG : Cache remote TestInternalCache:ticw: list ''
2025/04/22 01:50:55 DEBUG : : list: error: couldn't open bucket (ticw)
2025/04/22 01:50:55 ERROR : Cache remote TestInternalCache:ticw: Failed to list "": directory not found
2025/04/22 01:50:55 DEBUG : removing 1 level 0 directories
2025/04/22 01:50:55 INFO  : Cache remote TestInternalCache:ticw: Removing directory
2025/04/22 01:50:55 DEBUG : Cache remote TestInternalCache:ticw: rmdir ''
2025/04/22 01:50:55 ERROR : : Failed to rmdir: stat /tmp/TestInternalCache-local/ticw: no such file or directory
2025/04/22 01:50:55 DEBUG : Cache remote TestInternalCache:ticw: mkdir ''
2025/04/22 01:50:55 DEBUG : : mkdir: created dir in source fs
2025/04/22 01:50:55 DEBUG : : mkdir: added to cache
2025/04/22 01:50:55 DEBUG : : cache: expired ticw
2025/04/22 01:50:55 INFO  : : mkdir: cache expired
2025/04/22 01:50:55 DEBUG : Cache remote TestInternalCache:ticw: put data at 'data.bin'
2025/04/22 01:50:55 DEBUG : data.bin: put: uploaded to remote fs and saved in cache
2025/04/22 01:50:55 DEBUG : data.bin: put: added to cache
2025/04/22 01:50:55 DEBUG : : cache: expired ticw
2025/04/22 01:50:55 INFO  : : put: cache expired
2025/04/22 01:50:55 DEBUG : Cache remote TestInternalCache:ticw: new object 'data.bin'
2025/04/22 01:50:55 DEBUG : data.bin: find: warm object: data.bin, expiring on: 2025-04-22 07:50:55.893075995 +0000 UTC
2025/04/22 01:50:55 DEBUG : Waiting for deletions to finish
2025/04/22 01:50:55 DEBUG : Cache remote TestInternalCache:ticw: list ''
2025/04/22 01:50:55 DEBUG : : list: cold listing: 2025-04-21 19:50:55.89865178 +0000 UTC
2025/04/22 01:50:55 DEBUG : : list: read 1 from source
2025/04/22 01:50:55 DEBUG : : list: source entries: [data.bin]
2025/04/22 01:50:55 DEBUG : : list: cached object: data.bin
2025/04/22 01:50:55 DEBUG : : list: cached directories: 0
2025/04/22 01:50:55 DEBUG : : list: cached dir: 'ticw', cache ts: 2025-04-22 01:50:55.901048728 +0000 UTC m=+4.442252156
2025/04/22 01:50:55 DEBUG : data.bin: removing object
2025/04/22 01:50:55 DEBUG : : cache: expired ticw
2025/04/22 01:50:55 INFO  : data.bin: Deleted
2025/04/22 01:50:55 DEBUG : Cache remote TestInternalCache:ticw: list ''
2025/04/22 01:50:55 DEBUG : : list: cold listing: 2025-04-21 19:50:55.907196698 +0000 UTC
2025/04/22 01:50:55 DEBUG : : list: read 0 from source
2025/04/22 01:50:55 DEBUG : : list: source entries: []
2025/04/22 01:50:55 DEBUG : : list: cached directories: 0
2025/04/22 01:50:55 DEBUG : : list: cached dir: 'ticw', cache ts: 2025-04-22 01:50:55.908315898 +0000 UTC m=+4.449519326
2025/04/22 01:50:55 DEBUG : removing 1 level 0 directories
2025/04/22 01:50:55 INFO  : Cache remote TestInternalCache:ticw: Removing directory
2025/04/22 01:50:55 DEBUG : Cache remote TestInternalCache:ticw: rmdir ''
2025/04/22 01:50:55 DEBUG : : rmdir: removed dir in source fs
2025/04/22 01:50:55 DEBUG : : rmdir: removed from cache
2025/04/22 01:50:55 INFO  : : rmdir: cache expired
2025/04/22 01:50:55 DEBUG : Cache remote TestInternalCache:ticw: Services stopped
--- PASS: TestInternalCacheWrites (0.77s)
=== RUN   TestInternalMaxChunkSizeRespected
2025/04/22 01:50:55 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2025/04/22 01:50:55 DEBUG : Creating backend with remote "TestInternalCache-local:/tmp/TestInternalCache-local/timcsr1745286655"
2025/04/22 01:50:55 DEBUG : TestInternalCache: wrapped TestInternalCache-local:/tmp/TestInternalCache-local/timcsr1745286655 at root timcsr1745286655
2025/04/22 01:50:55 INFO  : TestInternalCache: Cache DB path: /home/rclone/.cache/rclone/cache-backend/TestInternalCache.db
2025/04/22 01:50:55 INFO  : TestInternalCache: Cache chunk path: /home/rclone/.cache/rclone/cache-backend/TestInternalCache
2025/04/22 01:50:55 INFO  : TestInternalCache: Chunk Memory: true
2025/04/22 01:50:55 INFO  : TestInternalCache: Chunk Size: 5Mi
2025/04/22 01:50:55 INFO  : TestInternalCache: Chunk Total Size: 10Gi
2025/04/22 01:50:55 INFO  : TestInternalCache: Chunk Clean Interval: 1m0s
2025/04/22 01:50:55 INFO  : TestInternalCache: Workers: 1
2025/04/22 01:50:55 INFO  : TestInternalCache: File Age: 6h0m0s
2025/04/22 01:50:55 DEBUG : Waiting for deletions to finish
2025/04/22 01:50:55 DEBUG : Cache remote TestInternalCache:timcsr1745286655: list ''
2025/04/22 01:50:55 DEBUG : : list: error: couldn't open bucket (timcsr1745286655)
2025/04/22 01:50:55 ERROR : : error listing: directory not found
2025/04/22 01:50:55 DEBUG : Cache remote TestInternalCache:timcsr1745286655: list ''
2025/04/22 01:50:55 DEBUG : : list: error: couldn't open bucket (timcsr1745286655)
2025/04/22 01:50:55 ERROR : Cache remote TestInternalCache:timcsr1745286655: Failed to list "": directory not found
2025/04/22 01:50:55 DEBUG : removing 1 level 0 directories
2025/04/22 01:50:55 INFO  : Cache remote TestInternalCache:timcsr1745286655: Removing directory
2025/04/22 01:50:55 DEBUG : Cache remote TestInternalCache:timcsr1745286655: rmdir ''
2025/04/22 01:50:55 ERROR : : Failed to rmdir: stat /tmp/TestInternalCache-local/timcsr1745286655: no such file or directory
2025/04/22 01:50:55 DEBUG : Cache remote TestInternalCache:timcsr1745286655: mkdir ''
2025/04/22 01:50:55 DEBUG : : mkdir: created dir in source fs
2025/04/22 01:50:55 DEBUG : : mkdir: added to cache
2025/04/22 01:50:55 DEBUG : : cache: expired timcsr1745286655
2025/04/22 01:50:55 INFO  : : mkdir: cache expired
2025/04/22 01:50:58 DEBUG : Cache remote TestInternalCache:timcsr1745286655: put data at 'data.bin'
2025/04/22 01:50:58 DEBUG : data.bin: put: uploaded to remote fs
2025/04/22 01:50:58 DEBUG : data.bin: put: added to cache
2025/04/22 01:50:58 DEBUG : : cache: expired timcsr1745286655
2025/04/22 01:50:58 INFO  : : put: cache expired
2025/04/22 01:50:58 DEBUG : Cache remote TestInternalCache:timcsr1745286655: new object 'data.bin'
2025/04/22 01:50:58 DEBUG : data.bin: find: warm object: data.bin, expiring on: 2025-04-22 07:50:58.166912508 +0000 UTC
2025/04/22 01:50:58 DEBUG : Cache remote TestInternalCache:timcsr1745286655: new object 'data.bin'
2025/04/22 01:50:58 DEBUG : data.bin: find: warm object: data.bin, expiring on: 2025-04-22 07:50:58.166912508 +0000 UTC
2025/04/22 01:50:58 DEBUG : timcsr1745286655/data.bin: moving offset set from 0 to 0
2025/04/22 01:50:58 DEBUG : timcsr1745286655/data.bin: 0: chunk retry storage: 0
2025/04/22 01:50:58 DEBUG : worker-0 <data.bin>: downloaded chunk 0
2025/04/22 01:50:58 DEBUG : timcsr1745286655/data.bin: cache reader closed 5242880
2025/04/22 01:50:58 DEBUG : timcsr1745286655/data.bin: moving offset set from 0 to 5242880
2025/04/22 01:50:58 DEBUG : timcsr1745286655/data.bin: 5242880: chunk retry storage: 0
2025/04/22 01:50:58 DEBUG : worker-0 <data.bin>: downloaded chunk 5242880
2025/04/22 01:50:59 DEBUG : timcsr1745286655/data.bin: cache reader closed 10485760
2025/04/22 01:50:59 DEBUG : timcsr1745286655/data.bin: moving offset set from 0 to 10485760
2025/04/22 01:50:59 DEBUG : timcsr1745286655/data.bin: 10485760: chunk retry storage: 0
2025/04/22 01:50:59 DEBUG : worker-0 <data.bin>: downloaded chunk 10485760
2025/04/22 01:50:59 DEBUG : timcsr1745286655/data.bin: cache reader closed 15728640
2025/04/22 01:50:59 DEBUG : timcsr1745286655/data.bin: moving offset set from 0 to 15728640
2025/04/22 01:50:59 DEBUG : timcsr1745286655/data.bin: 15728640: chunk retry storage: 0
2025/04/22 01:50:59 DEBUG : worker-0 <data.bin>: downloaded chunk 15728640
2025/04/22 01:51:00 DEBUG : timcsr1745286655/data.bin: cache reader closed 20971520
2025/04/22 01:51:00 DEBUG : timcsr1745286655/data.bin: moving offset set from 0 to 20971520
2025/04/22 01:51:00 DEBUG : timcsr1745286655/data.bin: 20971520: chunk retry storage: 0
2025/04/22 01:51:00 DEBUG : worker-0 <data.bin>: downloaded chunk 20971520
2025/04/22 01:51:00 DEBUG : timcsr1745286655/data.bin: cache reader closed 26214400
2025/04/22 01:51:00 DEBUG : timcsr1745286655/data.bin: moving offset set from 0 to 26214400
2025/04/22 01:51:00 DEBUG : timcsr1745286655/data.bin: 26214400: chunk retry storage: 0
2025/04/22 01:51:00 DEBUG : worker-0 <data.bin>: downloaded chunk 26214400
2025/04/22 01:51:01 DEBUG : timcsr1745286655/data.bin: cache reader closed 31457280
2025/04/22 01:51:01 DEBUG : Waiting for deletions to finish
2025/04/22 01:51:01 DEBUG : Cache remote TestInternalCache:timcsr1745286655: list ''
2025/04/22 01:51:01 DEBUG : : list: cold listing: 2025-04-21 19:50:58.169478714 +0000 UTC
2025/04/22 01:51:01 DEBUG : : list: read 1 from source
2025/04/22 01:51:01 DEBUG : : list: source entries: [data.bin]
2025/04/22 01:51:01 DEBUG : : list: cached object: data.bin
2025/04/22 01:51:01 DEBUG : : list: cached directories: 0
2025/04/22 01:51:01 DEBUG : : list: cached dir: 'timcsr1745286655', cache ts: 2025-04-22 01:51:01.333111873 +0000 UTC m=+9.874315311
2025/04/22 01:51:01 DEBUG : data.bin: removing object
2025/04/22 01:51:01 DEBUG : : cache: expired timcsr1745286655
2025/04/22 01:51:01 INFO  : data.bin: Deleted
2025/04/22 01:51:01 DEBUG : Cache remote TestInternalCache:timcsr1745286655: list ''
2025/04/22 01:51:01 DEBUG : : list: cold listing: 2025-04-21 19:51:01.3545085 +0000 UTC
2025/04/22 01:51:01 DEBUG : : list: read 0 from source
2025/04/22 01:51:01 DEBUG : : list: source entries: []
2025/04/22 01:51:01 DEBUG : : list: cached directories: 0
2025/04/22 01:51:01 DEBUG : : list: cached dir: 'timcsr1745286655', cache ts: 2025-04-22 01:51:01.355925099 +0000 UTC m=+9.897128527
2025/04/22 01:51:01 DEBUG : removing 1 level 0 directories
2025/04/22 01:51:01 INFO  : Cache remote TestInternalCache:timcsr1745286655: Removing directory
2025/04/22 01:51:01 DEBUG : Cache remote TestInternalCache:timcsr1745286655: rmdir ''
2025/04/22 01:51:01 DEBUG : : rmdir: removed dir in source fs
2025/04/22 01:51:01 DEBUG : : rmdir: removed from cache
2025/04/22 01:51:01 INFO  : : rmdir: cache expired
2025/04/22 01:51:01 DEBUG : Cache remote TestInternalCache:timcsr1745286655: Services stopped
--- PASS: TestInternalMaxChunkSizeRespected (5.47s)
=== RUN   TestInternalExpiredEntriesRemoved
2025/04/22 01:51:01 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/22 01:51:01 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2025/04/22 01:51:01 DEBUG : Creating backend with remote "TestInternalCache-local:/tmp/TestInternalCache-local/tib21171745286661"
2025/04/22 01:51:01 DEBUG : TestInternalCache: wrapped TestInternalCache-local:/tmp/TestInternalCache-local/tib21171745286661 at root tib21171745286661
2025/04/22 01:51:01 INFO  : TestInternalCache: Cache DB path: /home/rclone/.cache/rclone/cache-backend/TestInternalCache.db
2025/04/22 01:51:01 INFO  : TestInternalCache: Cache chunk path: /home/rclone/.cache/rclone/cache-backend/TestInternalCache
2025/04/22 01:51:01 INFO  : TestInternalCache: Chunk Memory: true
2025/04/22 01:51:01 INFO  : TestInternalCache: Chunk Size: 5Mi
2025/04/22 01:51:01 INFO  : TestInternalCache: Chunk Total Size: 10Gi
2025/04/22 01:51:01 INFO  : TestInternalCache: Chunk Clean Interval: 15m0s
2025/04/22 01:51:01 INFO  : TestInternalCache: Workers: 4
2025/04/22 01:51:01 INFO  : TestInternalCache: File Age: 3d
2025/04/22 01:51:01 DEBUG : Waiting for deletions to finish
2025/04/22 01:51:01 DEBUG : Cache remote TestInternalCache:tib21171745286661: list ''
2025/04/22 01:51:01 DEBUG : : list: error: couldn't open bucket (tib21171745286661)
2025/04/22 01:51:01 ERROR : : error listing: directory not found
2025/04/22 01:51:01 DEBUG : Cache remote TestInternalCache:tib21171745286661: list ''
2025/04/22 01:51:01 DEBUG : : list: error: couldn't open bucket (tib21171745286661)
2025/04/22 01:51:01 ERROR : Cache remote TestInternalCache:tib21171745286661: Failed to list "": directory not found
2025/04/22 01:51:01 DEBUG : removing 1 level 0 directories
2025/04/22 01:51:01 INFO  : Cache remote TestInternalCache:tib21171745286661: Removing directory
2025/04/22 01:51:01 DEBUG : Cache remote TestInternalCache:tib21171745286661: rmdir ''
2025/04/22 01:51:01 ERROR : : Failed to rmdir: stat /tmp/TestInternalCache-local/tib21171745286661: no such file or directory
2025/04/22 01:51:01 DEBUG : Cache remote TestInternalCache:tib21171745286661: mkdir ''
2025/04/22 01:51:01 DEBUG : : mkdir: created dir in source fs
2025/04/22 01:51:01 DEBUG : : mkdir: added to cache
2025/04/22 01:51:01 DEBUG : : cache: expired tib21171745286661
2025/04/22 01:51:01 INFO  : : mkdir: cache expired
2025/04/22 01:51:01 DEBUG : Cache remote TestInternalCache:tib21171745286661: list 'test/dir1/dir2'
2025/04/22 01:51:01 DEBUG : test/dir1/dir2: list: error: couldn't open bucket (tib21171745286661/test/dir1/dir2)
2025/04/22 01:51:01 DEBUG : test/dir1/dir2: list: read 1 from source
2025/04/22 01:51:01 DEBUG : test/dir1/dir2: list: source entries: [test/dir1/dir2/test.txt]
2025/04/22 01:51:01 DEBUG : test/dir1/dir2: list: cached object: test/dir1/dir2/test.txt
2025/04/22 01:51:01 DEBUG : test/dir1/dir2: list: cached directories: 0
2025/04/22 01:51:01 DEBUG : test/dir1/dir2: list: cached dir: 'tib21171745286661/test/dir1/dir2', cache ts: 2025-04-22 01:51:01.405767135 +0000 UTC m=+9.946970563
2025/04/22 01:51:01 NOTICE: len: 1
2025/04/22 01:51:31 DEBUG : Cache remote TestInternalCache:tib21171745286661: list 'test/dir1/dir2'
2025/04/22 01:51:31 DEBUG : test/dir1/dir2: list: warm 1 from cache for: tib21171745286661/test/dir1/dir2, expiring on: 2025-04-25 01:51:01.405767135 +0000 UTC
2025/04/22 01:51:31 DEBUG : test/dir1/dir2: list: cached entries: [test/dir1/dir2/test.txt]
2025/04/22 01:51:31 NOTICE: len: 1
2025/04/22 01:51:31 DEBUG : Cache remote TestInternalCache:tib21171745286661: list 'test/dir1'
2025/04/22 01:51:31 DEBUG : test/dir1: list: error: missing cached dir: test/dir1
2025/04/22 01:51:31 DEBUG : test/dir1: list: read 4 from source
2025/04/22 01:51:31 DEBUG : test/dir1: list: source entries: [test/dir1/dir3 test/dir1/dir2 test/dir1/dir4 test/dir1/dir1]
2025/04/22 01:51:31 DEBUG : test/dir1: list: cached directories: 4
2025/04/22 01:51:31 DEBUG : test/dir1: list: cached dir: 'tib21171745286661/test/dir1', cache ts: 2025-04-22 01:51:31.411121992 +0000 UTC m=+39.952325450
2025/04/22 01:51:31 NOTICE: len: 4
2025/04/22 01:51:31 DEBUG : Cache remote TestInternalCache:tib21171745286661: list 'test'
2025/04/22 01:51:31 DEBUG : test: list: error: missing cached dir: test
2025/04/22 01:51:31 DEBUG : test: list: read 4 from source
2025/04/22 01:51:31 DEBUG : test: list: source entries: [test/dir3 test/dir2 test/dir4 test/dir1]
2025/04/22 01:51:31 DEBUG : test: list: cached directories: 4
2025/04/22 01:51:31 DEBUG : test: list: cached dir: 'tib21171745286661/test', cache ts: 2025-04-22 01:51:31.414116993 +0000 UTC m=+39.955320451
2025/04/22 01:51:31 NOTICE: len: 4
2025/04/22 01:51:31 DEBUG : Waiting for deletions to finish
2025/04/22 01:51:31 DEBUG : Cache remote TestInternalCache:tib21171745286661: list ''
2025/04/22 01:51:31 DEBUG : : list: cold listing: 2025-04-19 01:51:01.401785442 +0000 UTC
2025/04/22 01:51:31 DEBUG : : list: read 1 from source
2025/04/22 01:51:31 DEBUG : : list: source entries: [test]
2025/04/22 01:51:31 DEBUG : : list: cached directories: 1
2025/04/22 01:51:31 DEBUG : : list: cached dir: 'tib21171745286661', cache ts: 2025-04-22 01:51:31.416783668 +0000 UTC m=+39.957987137
2025/04/22 01:51:31 DEBUG : Cache remote TestInternalCache:tib21171745286661: list 'test'
2025/04/22 01:51:31 DEBUG : test: list: warm 4 from cache for: tib21171745286661/test, expiring on: 2025-04-25 01:51:31.415581472 +0000 UTC
2025/04/22 01:51:31 DEBUG : test: list: cached entries: [test/dir1 test/dir2 test/dir3 test/dir4]
2025/04/22 01:51:31 DEBUG : Cache remote TestInternalCache:tib21171745286661: list 'test/dir4'
2025/04/22 01:51:31 DEBUG : test/dir4: list: empty listing
2025/04/22 01:51:31 DEBUG : Cache remote TestInternalCache:tib21171745286661: list 'test/dir2'
2025/04/22 01:51:31 DEBUG : test/dir4: list: read 4 from source
2025/04/22 01:51:31 DEBUG : test/dir4: list: source entries: [test/dir4/dir3 test/dir4/dir2 test/dir4/dir4 test/dir4/dir1]
2025/04/22 01:51:31 DEBUG : test/dir2: list: empty listing
2025/04/22 01:51:31 DEBUG : test/dir2: list: read 4 from source
2025/04/22 01:51:31 DEBUG : test/dir2: list: source entries: [test/dir2/dir3 test/dir2/dir2 test/dir2/dir4 test/dir2/dir1]
2025/04/22 01:51:31 DEBUG : Cache remote TestInternalCache:tib21171745286661: list 'test/dir1'
2025/04/22 01:51:31 DEBUG : test/dir1: list: warm 4 from cache for: tib21171745286661/test/dir1, expiring on: 2025-04-25 01:51:31.41273484 +0000 UTC
2025/04/22 01:51:31 DEBUG : test/dir1: list: cached entries: [test/dir1/dir1 test/dir1/dir2 test/dir1/dir3 test/dir1/dir4]
2025/04/22 01:51:31 DEBUG : Cache remote TestInternalCache:tib21171745286661: list 'test/dir1/dir4'
2025/04/22 01:51:31 DEBUG : test/dir1/dir4: list: empty listing
2025/04/22 01:51:31 DEBUG : test/dir1/dir4: list: read 1 from source
2025/04/22 01:51:31 DEBUG : test/dir1/dir4: list: source entries: [test/dir1/dir4/test.txt]
2025/04/22 01:51:31 DEBUG : Cache remote TestInternalCache:tib21171745286661: list 'test/dir1/dir1'
2025/04/22 01:51:31 DEBUG : test/dir1/dir1: list: empty listing
2025/04/22 01:51:31 DEBUG : test/dir1/dir1: list: read 1 from source
2025/04/22 01:51:31 DEBUG : test/dir1/dir1: list: source entries: [test/dir1/dir1/test.txt]
2025/04/22 01:51:31 DEBUG : Cache remote TestInternalCache:tib21171745286661: list 'test/dir1/dir2'
2025/04/22 01:51:31 DEBUG : test/dir1/dir2: list: warm 1 from cache for: tib21171745286661/test/dir1/dir2, expiring on: 2025-04-25 01:51:31.408166605 +0000 UTC
2025/04/22 01:51:31 DEBUG : test/dir1/dir2: list: cached entries: [test/dir1/dir2/test.txt]
2025/04/22 01:51:31 DEBUG : Cache remote TestInternalCache:tib21171745286661: list 'test/dir1/dir3'
2025/04/22 01:51:31 DEBUG : test/dir1/dir3: list: empty listing
2025/04/22 01:51:31 DEBUG : test/dir1/dir3: list: read 1 from source
2025/04/22 01:51:31 DEBUG : test/dir1/dir3: list: source entries: [test/dir1/dir3/test.txt]
2025/04/22 01:51:31 DEBUG : Cache remote TestInternalCache:tib21171745286661: list 'test/dir3'
2025/04/22 01:51:31 DEBUG : test/dir3: list: empty listing
2025/04/22 01:51:31 DEBUG : test/dir3: list: read 4 from source
2025/04/22 01:51:31 DEBUG : test/dir3: list: source entries: [test/dir3/dir3 test/dir3/dir2 test/dir3/dir4 test/dir3/dir1]
2025/04/22 01:51:31 DEBUG : test/dir4: list: cached directories: 4
2025/04/22 01:51:31 DEBUG : test/dir4: list: cached dir: 'tib21171745286661/test/dir4', cache ts: 2025-04-22 01:51:31.420386961 +0000 UTC m=+39.961590429
2025/04/22 01:51:31 DEBUG : Cache remote TestInternalCache:tib21171745286661: list 'test/dir4/dir3'
2025/04/22 01:51:31 DEBUG : test/dir4/dir3: list: empty listing
2025/04/22 01:51:31 DEBUG : test/dir4/dir3: list: read 1 from source
2025/04/22 01:51:31 DEBUG : test/dir4/dir3: list: source entries: [test/dir4/dir3/test.txt]
2025/04/22 01:51:31 DEBUG : Cache remote TestInternalCache:tib21171745286661: list 'test/dir4/dir1'
2025/04/22 01:51:31 DEBUG : test/dir4/dir1: list: empty listing
2025/04/22 01:51:31 DEBUG : test/dir4/dir1: list: read 1 from source
2025/04/22 01:51:31 DEBUG : test/dir4/dir1: list: source entries: [test/dir4/dir1/test.txt]
2025/04/22 01:51:31 DEBUG : Cache remote TestInternalCache:tib21171745286661: list 'test/dir4/dir2'
2025/04/22 01:51:31 DEBUG : test/dir4/dir2: list: empty listing
2025/04/22 01:51:31 DEBUG : test/dir4/dir2: list: read 1 from source
2025/04/22 01:51:31 DEBUG : test/dir4/dir2: list: source entries: [test/dir4/dir2/test.txt]
2025/04/22 01:51:31 DEBUG : test/dir2: list: cached directories: 4
2025/04/22 01:51:31 DEBUG : test/dir1/dir4: list: cached object: test/dir1/dir4/test.txt
2025/04/22 01:51:31 DEBUG : test/dir1/dir4: list: cached directories: 0
2025/04/22 01:51:31 DEBUG : test/dir1/dir1: list: cached object: test/dir1/dir1/test.txt
2025/04/22 01:51:31 DEBUG : test/dir1/dir1: list: cached directories: 0
2025/04/22 01:51:31 DEBUG : test/dir1/dir2/test.txt: removing object
2025/04/22 01:51:31 DEBUG : test/dir1/dir3: list: cached object: test/dir1/dir3/test.txt
2025/04/22 01:51:31 DEBUG : test/dir1/dir3: list: cached directories: 0
2025/04/22 01:51:31 DEBUG : test/dir3: list: cached directories: 4
2025/04/22 01:51:31 DEBUG : test/dir4/dir3: list: cached object: test/dir4/dir3/test.txt
2025/04/22 01:51:31 DEBUG : test/dir4/dir3: list: cached directories: 0
2025/04/22 01:51:31 DEBUG : test/dir4/dir1: list: cached object: test/dir4/dir1/test.txt
2025/04/22 01:51:31 DEBUG : test/dir4/dir1: list: cached directories: 0
2025/04/22 01:51:31 DEBUG : test/dir4/dir2: list: cached object: test/dir4/dir2/test.txt
2025/04/22 01:51:31 DEBUG : test/dir4/dir2: list: cached directories: 0
2025/04/22 01:51:31 DEBUG : test/dir2: list: cached dir: 'tib21171745286661/test/dir2', cache ts: 2025-04-22 01:51:31.423914391 +0000 UTC m=+39.965117849
2025/04/22 01:51:31 DEBUG : Cache remote TestInternalCache:tib21171745286661: list 'test/dir4/dir4'
2025/04/22 01:51:31 DEBUG : test/dir4/dir4: list: empty listing
2025/04/22 01:51:31 DEBUG : test/dir4/dir4: list: read 1 from source
2025/04/22 01:51:31 DEBUG : test/dir4/dir4: list: source entries: [test/dir4/dir4/test.txt]
2025/04/22 01:51:31 DEBUG : test/dir1/dir4: list: cached dir: 'tib21171745286661/test/dir1/dir4', cache ts: 2025-04-22 01:51:31.425397494 +0000 UTC m=+39.966600963
2025/04/22 01:51:31 DEBUG : Cache remote TestInternalCache:tib21171745286661: list 'test/dir2/dir1'
2025/04/22 01:51:31 DEBUG : test/dir2/dir1: list: empty listing
2025/04/22 01:51:31 DEBUG : test/dir2/dir1: list: read 1 from source
2025/04/22 01:51:31 DEBUG : test/dir2/dir1: list: source entries: [test/dir2/dir1/test.txt]
2025/04/22 01:51:31 DEBUG : test/dir1/dir4/test.txt: removing object
2025/04/22 01:51:31 DEBUG : test/dir1/dir1: list: cached dir: 'tib21171745286661/test/dir1/dir1', cache ts: 2025-04-22 01:51:31.426925282 +0000 UTC m=+39.968128740
2025/04/22 01:51:31 DEBUG : Cache remote TestInternalCache:tib21171745286661: list 'test/dir2/dir2'
2025/04/22 01:51:31 DEBUG : test/dir2/dir2: list: empty listing
2025/04/22 01:51:31 DEBUG : test/dir2/dir2: list: read 1 from source
2025/04/22 01:51:31 DEBUG : test/dir2/dir2: list: source entries: [test/dir2/dir2/test.txt]
2025/04/22 01:51:31 DEBUG : test/dir1/dir1/test.txt: removing object
2025/04/22 01:51:31 DEBUG : test/dir1/dir3: list: cached dir: 'tib21171745286661/test/dir1/dir3', cache ts: 2025-04-22 01:51:31.429895277 +0000 UTC m=+39.971098745
2025/04/22 01:51:31 DEBUG : Cache remote TestInternalCache:tib21171745286661: list 'test/dir2/dir3'
2025/04/22 01:51:31 DEBUG : test/dir2/dir3: list: empty listing
2025/04/22 01:51:31 DEBUG : test/dir2/dir3: list: read 1 from source
2025/04/22 01:51:31 DEBUG : test/dir2/dir3: list: source entries: [test/dir2/dir3/test.txt]
2025/04/22 01:51:31 DEBUG : test/dir1/dir3/test.txt: removing object
2025/04/22 01:51:31 DEBUG : test/dir3: list: cached dir: 'tib21171745286661/test/dir3', cache ts: 2025-04-22 01:51:31.43126114 +0000 UTC m=+39.972464598
2025/04/22 01:51:31 DEBUG : Cache remote TestInternalCache:tib21171745286661: list 'test/dir2/dir4'
2025/04/22 01:51:31 DEBUG : test/dir2/dir4: list: empty listing
2025/04/22 01:51:31 DEBUG : test/dir2/dir4: list: read 1 from source
2025/04/22 01:51:31 DEBUG : test/dir2/dir4: list: source entries: [test/dir2/dir4/test.txt]
2025/04/22 01:51:31 DEBUG : test/dir4/dir3: list: cached dir: 'tib21171745286661/test/dir4/dir3', cache ts: 2025-04-22 01:51:31.432731601 +0000 UTC m=+39.973935058
2025/04/22 01:51:31 DEBUG : Cache remote TestInternalCache:tib21171745286661: list 'test/dir3/dir1'
2025/04/22 01:51:31 DEBUG : test/dir3/dir1: list: empty listing
2025/04/22 01:51:31 DEBUG : test/dir3/dir1: list: read 1 from source
2025/04/22 01:51:31 DEBUG : test/dir3/dir1: list: source entries: [test/dir3/dir1/test.txt]
2025/04/22 01:51:31 DEBUG : test/dir4/dir3/test.txt: removing object
2025/04/22 01:51:31 DEBUG : test/dir4/dir1: list: cached dir: 'tib21171745286661/test/dir4/dir1', cache ts: 2025-04-22 01:51:31.435372777 +0000 UTC m=+39.976576235
2025/04/22 01:51:31 DEBUG : Cache remote TestInternalCache:tib21171745286661: list 'test/dir3/dir2'
2025/04/22 01:51:31 DEBUG : test/dir3/dir2: list: empty listing
2025/04/22 01:51:31 DEBUG : test/dir3/dir2: list: read 1 from source
2025/04/22 01:51:31 DEBUG : test/dir3/dir2: list: source entries: [test/dir3/dir2/test.txt]
2025/04/22 01:51:31 DEBUG : test/dir4/dir1/test.txt: removing object
2025/04/22 01:51:31 DEBUG : test/dir4/dir2: list: cached dir: 'tib21171745286661/test/dir4/dir2', cache ts: 2025-04-22 01:51:31.435655037 +0000 UTC m=+39.976858495
2025/04/22 01:51:31 DEBUG : Cache remote TestInternalCache:tib21171745286661: list 'test/dir3/dir3'
2025/04/22 01:51:31 DEBUG : test/dir3/dir3: list: empty listing
2025/04/22 01:51:31 DEBUG : test/dir3/dir3: list: read 1 from source
2025/04/22 01:51:31 DEBUG : test/dir3/dir3: list: source entries: [test/dir3/dir3/test.txt]
2025/04/22 01:51:31 DEBUG : test/dir4/dir2/test.txt: removing object
2025/04/22 01:51:31 DEBUG : test/dir4/dir4: list: cached object: test/dir4/dir4/test.txt
2025/04/22 01:51:31 DEBUG : test/dir4/dir4: list: cached directories: 0
2025/04/22 01:51:31 DEBUG : test/dir2/dir1: list: cached object: test/dir2/dir1/test.txt
2025/04/22 01:51:31 DEBUG : test/dir2/dir1: list: cached directories: 0
2025/04/22 01:51:31 DEBUG : test/dir2/dir2: list: cached object: test/dir2/dir2/test.txt
2025/04/22 01:51:31 DEBUG : test/dir2/dir2: list: cached directories: 0
2025/04/22 01:51:31 DEBUG : test/dir2/dir3: list: cached object: test/dir2/dir3/test.txt
2025/04/22 01:51:31 DEBUG : test/dir2/dir3: list: cached directories: 0
2025/04/22 01:51:31 DEBUG : test/dir2/dir4: list: cached object: test/dir2/dir4/test.txt
2025/04/22 01:51:31 DEBUG : test/dir2/dir4: list: cached directories: 0
2025/04/22 01:51:31 DEBUG : test/dir3/dir1: list: cached object: test/dir3/dir1/test.txt
2025/04/22 01:51:31 DEBUG : test/dir3/dir1: list: cached directories: 0
2025/04/22 01:51:31 DEBUG : test/dir3/dir2: list: cached object: test/dir3/dir2/test.txt
2025/04/22 01:51:31 DEBUG : test/dir3/dir2: list: cached directories: 0
2025/04/22 01:51:31 DEBUG : test/dir3/dir3: list: cached object: test/dir3/dir3/test.txt
2025/04/22 01:51:31 DEBUG : test/dir3/dir3: list: cached directories: 0
2025/04/22 01:51:31 DEBUG : test/dir4/dir4: list: cached dir: 'tib21171745286661/test/dir4/dir4', cache ts: 2025-04-22 01:51:31.448772686 +0000 UTC m=+39.989976144
2025/04/22 01:51:31 DEBUG : Cache remote TestInternalCache:tib21171745286661: list 'test/dir3/dir4'
2025/04/22 01:51:31 DEBUG : test/dir3/dir4: list: empty listing
2025/04/22 01:51:31 DEBUG : test/dir3/dir4: list: read 1 from source
2025/04/22 01:51:31 DEBUG : test/dir3/dir4: list: source entries: [test/dir3/dir4/test.txt]
2025/04/22 01:51:31 DEBUG : test/dir4/dir4/test.txt: removing object
2025/04/22 01:51:31 DEBUG : test/dir2/dir1: list: cached dir: 'tib21171745286661/test/dir2/dir1', cache ts: 2025-04-22 01:51:31.450008647 +0000 UTC m=+39.991212115
2025/04/22 01:51:31 DEBUG : test/dir1/dir2: cache: expired tib21171745286661/test/dir1/dir2
2025/04/22 01:51:31 DEBUG : test/dir2/dir2: list: cached dir: 'tib21171745286661/test/dir2/dir2', cache ts: 2025-04-22 01:51:31.453149642 +0000 UTC m=+39.994353100
2025/04/22 01:51:31 DEBUG : test/dir1/dir2: cache: expired tib21171745286661/test/dir1
2025/04/22 01:51:31 DEBUG : test/dir1/dir2: cache: expired tib21171745286661/test
2025/04/22 01:51:31 DEBUG : test/dir1/dir2: cache: expired tib21171745286661
2025/04/22 01:51:31 INFO  : test/dir1/dir2/test.txt: Deleted
2025/04/22 01:51:31 DEBUG : test/dir2/dir1/test.txt: removing object
2025/04/22 01:51:31 DEBUG : test/dir2/dir3: list: cached dir: 'tib21171745286661/test/dir2/dir3', cache ts: 2025-04-22 01:51:31.45645761 +0000 UTC m=+39.997661068
2025/04/22 01:51:31 DEBUG : test/dir2/dir4: list: cached dir: 'tib21171745286661/test/dir2/dir4', cache ts: 2025-04-22 01:51:31.458894454 +0000 UTC m=+40.000097921
2025/04/22 01:51:31 DEBUG : test/dir3/dir1: list: cached dir: 'tib21171745286661/test/dir3/dir1', cache ts: 2025-04-22 01:51:31.459941899 +0000 UTC m=+40.001145358
2025/04/22 01:51:31 DEBUG : test/dir3/dir2: list: cached dir: 'tib21171745286661/test/dir3/dir2', cache ts: 2025-04-22 01:51:31.461983481 +0000 UTC m=+40.003186940
2025/04/22 01:51:31 DEBUG : test/dir3/dir3: list: cached dir: 'tib21171745286661/test/dir3/dir3', cache ts: 2025-04-22 01:51:31.464168281 +0000 UTC m=+40.005371739
2025/04/22 01:51:31 DEBUG : test/dir3/dir4: list: cached object: test/dir3/dir4/test.txt
2025/04/22 01:51:31 DEBUG : test/dir3/dir4: list: cached directories: 0
2025/04/22 01:51:31 DEBUG : test/dir1/dir4: cache: expired tib21171745286661/test/dir1/dir4
2025/04/22 01:51:31 DEBUG : test/dir1/dir4: cache: expired tib21171745286661/test/dir1
2025/04/22 01:51:31 DEBUG : test/dir1/dir4: cache: expired tib21171745286661/test
2025/04/22 01:51:31 DEBUG : test/dir1/dir4: cache: expired tib21171745286661
2025/04/22 01:51:31 INFO  : test/dir1/dir4/test.txt: Deleted
2025/04/22 01:51:31 DEBUG : test/dir2/dir2/test.txt: removing object
2025/04/22 01:51:31 DEBUG : test/dir3/dir4: list: cached dir: 'tib21171745286661/test/dir3/dir4', cache ts: 2025-04-22 01:51:31.476046926 +0000 UTC m=+40.017250384
2025/04/22 01:51:31 DEBUG : test/dir1/dir1: cache: expired tib21171745286661/test/dir1/dir1
2025/04/22 01:51:31 DEBUG : test/dir1/dir1: cache: expired tib21171745286661/test/dir1
2025/04/22 01:51:31 DEBUG : test/dir1/dir1: cache: expired tib21171745286661/test
2025/04/22 01:51:31 DEBUG : test/dir1/dir1: cache: expired tib21171745286661
2025/04/22 01:51:31 INFO  : test/dir1/dir1/test.txt: Deleted
2025/04/22 01:51:31 DEBUG : test/dir2/dir3/test.txt: removing object
2025/04/22 01:51:31 DEBUG : test/dir1/dir3: cache: expired tib21171745286661/test/dir1/dir3
2025/04/22 01:51:31 DEBUG : test/dir1/dir3: cache: expired tib21171745286661/test/dir1
2025/04/22 01:51:31 DEBUG : test/dir1/dir3: cache: expired tib21171745286661/test
2025/04/22 01:51:31 DEBUG : test/dir1/dir3: cache: expired tib21171745286661
2025/04/22 01:51:31 INFO  : test/dir1/dir3/test.txt: Deleted
2025/04/22 01:51:31 DEBUG : test/dir2/dir4/test.txt: removing object
2025/04/22 01:51:31 DEBUG : test/dir4/dir3: cache: expired tib21171745286661/test/dir4/dir3
2025/04/22 01:51:31 DEBUG : test/dir4/dir3: cache: expired tib21171745286661/test/dir4
2025/04/22 01:51:31 DEBUG : test/dir4/dir3: cache: expired tib21171745286661/test
2025/04/22 01:51:31 DEBUG : test/dir4/dir3: cache: expired tib21171745286661
2025/04/22 01:51:31 INFO  : test/dir4/dir3/test.txt: Deleted
2025/04/22 01:51:31 DEBUG : test/dir3/dir1/test.txt: removing object
2025/04/22 01:51:31 DEBUG : test/dir4/dir1: cache: expired tib21171745286661/test/dir4/dir1
2025/04/22 01:51:31 DEBUG : test/dir4/dir1: cache: expired tib21171745286661/test/dir4
2025/04/22 01:51:31 DEBUG : test/dir4/dir1: cache: expired tib21171745286661/test
2025/04/22 01:51:31 DEBUG : test/dir4/dir1: cache: expired tib21171745286661
2025/04/22 01:51:31 INFO  : test/dir4/dir1/test.txt: Deleted
2025/04/22 01:51:31 DEBUG : test/dir3/dir2/test.txt: removing object
2025/04/22 01:51:31 DEBUG : test/dir4/dir2: cache: expired tib21171745286661/test/dir4/dir2
2025/04/22 01:51:31 DEBUG : test/dir4/dir2: cache: expired tib21171745286661/test/dir4
2025/04/22 01:51:31 DEBUG : test/dir4/dir2: cache: expired tib21171745286661/test
2025/04/22 01:51:31 DEBUG : test/dir4/dir2: cache: expired tib21171745286661
2025/04/22 01:51:31 INFO  : test/dir4/dir2/test.txt: Deleted
2025/04/22 01:51:31 DEBUG : test/dir3/dir3/test.txt: removing object
2025/04/22 01:51:31 DEBUG : test/dir4/dir4: cache: expired tib21171745286661/test/dir4/dir4
2025/04/22 01:51:31 DEBUG : test/dir4/dir4: cache: expired tib21171745286661/test/dir4
2025/04/22 01:51:31 DEBUG : test/dir4/dir4: cache: expired tib21171745286661/test
2025/04/22 01:51:31 DEBUG : test/dir4/dir4: cache: expired tib21171745286661
2025/04/22 01:51:31 INFO  : test/dir4/dir4/test.txt: Deleted
2025/04/22 01:51:31 DEBUG : test/dir3/dir4/test.txt: removing object
2025/04/22 01:51:31 DEBUG : test/dir2/dir1: cache: expired tib21171745286661/test/dir2/dir1
2025/04/22 01:51:31 DEBUG : test/dir2/dir1: cache: expired tib21171745286661/test/dir2
2025/04/22 01:51:31 DEBUG : test/dir2/dir1: cache: expired tib21171745286661/test
2025/04/22 01:51:31 DEBUG : test/dir2/dir1: cache: expired tib21171745286661
2025/04/22 01:51:31 INFO  : test/dir2/dir1/test.txt: Deleted
2025/04/22 01:51:31 DEBUG : test/dir2/dir2: cache: expired tib21171745286661/test/dir2/dir2
2025/04/22 01:51:31 DEBUG : test/dir2/dir2: cache: expired tib21171745286661/test/dir2
2025/04/22 01:51:31 DEBUG : test/dir2/dir2: cache: expired tib21171745286661/test
2025/04/22 01:51:31 DEBUG : test/dir2/dir2: cache: expired tib21171745286661
2025/04/22 01:51:31 INFO  : test/dir2/dir2/test.txt: Deleted
2025/04/22 01:51:31 DEBUG : test/dir2/dir3: cache: expired tib21171745286661/test/dir2/dir3
2025/04/22 01:51:31 DEBUG : test/dir2/dir3: cache: expired tib21171745286661/test/dir2
2025/04/22 01:51:31 DEBUG : test/dir2/dir3: cache: expired tib21171745286661/test
2025/04/22 01:51:31 DEBUG : test/dir2/dir3: cache: expired tib21171745286661
2025/04/22 01:51:31 INFO  : test/dir2/dir3/test.txt: Deleted
2025/04/22 01:51:31 DEBUG : test/dir2/dir4: cache: expired tib21171745286661/test/dir2/dir4
2025/04/22 01:51:31 DEBUG : test/dir2/dir4: cache: expired tib21171745286661/test/dir2
2025/04/22 01:51:31 DEBUG : test/dir2/dir4: cache: expired tib21171745286661/test
2025/04/22 01:51:31 DEBUG : test/dir2/dir4: cache: expired tib21171745286661
2025/04/22 01:51:31 INFO  : test/dir2/dir4/test.txt: Deleted
2025/04/22 01:51:31 DEBUG : test/dir3/dir1: cache: expired tib21171745286661/test/dir3/dir1
2025/04/22 01:51:31 DEBUG : test/dir3/dir1: cache: expired tib21171745286661/test/dir3
2025/04/22 01:51:31 DEBUG : test/dir3/dir1: cache: expired tib21171745286661/test
2025/04/22 01:51:31 DEBUG : test/dir3/dir1: cache: expired tib21171745286661
2025/04/22 01:51:31 INFO  : test/dir3/dir1/test.txt: Deleted
2025/04/22 01:51:31 DEBUG : test/dir3/dir2: cache: expired tib21171745286661/test/dir3/dir2
2025/04/22 01:51:31 DEBUG : test/dir3/dir2: cache: expired tib21171745286661/test/dir3
2025/04/22 01:51:31 DEBUG : test/dir3/dir2: cache: expired tib21171745286661/test
2025/04/22 01:51:31 DEBUG : test/dir3/dir2: cache: expired tib21171745286661
2025/04/22 01:51:31 INFO  : test/dir3/dir2/test.txt: Deleted
2025/04/22 01:51:31 DEBUG : test/dir3/dir3: cache: expired tib21171745286661/test/dir3/dir3
2025/04/22 01:51:31 DEBUG : test/dir3/dir3: cache: expired tib21171745286661/test/dir3
2025/04/22 01:51:31 DEBUG : test/dir3/dir3: cache: expired tib21171745286661/test
2025/04/22 01:51:31 DEBUG : test/dir3/dir3: cache: expired tib21171745286661
2025/04/22 01:51:31 INFO  : test/dir3/dir3/test.txt: Deleted
2025/04/22 01:51:31 DEBUG : test/dir3/dir4: cache: expired tib21171745286661/test/dir3/dir4
2025/04/22 01:51:31 DEBUG : test/dir3/dir4: cache: expired tib21171745286661/test/dir3
2025/04/22 01:51:31 DEBUG : test/dir3/dir4: cache: expired tib21171745286661/test
2025/04/22 01:51:31 DEBUG : test/dir3/dir4: cache: expired tib21171745286661
2025/04/22 01:51:31 INFO  : test/dir3/dir4/test.txt: Deleted
2025/04/22 01:51:31 DEBUG : Cache remote TestInternalCache:tib21171745286661: list ''
2025/04/22 01:51:31 DEBUG : : list: cold listing: 2025-04-19 01:51:31.521666137 +0000 UTC
2025/04/22 01:51:31 DEBUG : : list: read 1 from source
2025/04/22 01:51:31 DEBUG : : list: source entries: [test]
2025/04/22 01:51:31 DEBUG : : list: cached directories: 0
2025/04/22 01:51:31 DEBUG : : list: cached dir: 'tib21171745286661', cache ts: 2025-04-22 01:51:31.5229574 +0000 UTC m=+40.064160859
2025/04/22 01:51:31 DEBUG : Cache remote TestInternalCache:tib21171745286661: list 'test'
2025/04/22 01:51:31 DEBUG : test: list: cold listing: 2025-04-19 01:51:31.521666137 +0000 UTC
2025/04/22 01:51:31 DEBUG : test: list: read 4 from source
2025/04/22 01:51:31 DEBUG : test: list: source entries: [test/dir3 test/dir2 test/dir4 test/dir1]
2025/04/22 01:51:31 DEBUG : test: list: cached directories: 0
2025/04/22 01:51:31 DEBUG : test: list: cached dir: 'tib21171745286661/test', cache ts: 2025-04-22 01:51:31.524115924 +0000 UTC m=+40.065319383
2025/04/22 01:51:31 DEBUG : Cache remote TestInternalCache:tib21171745286661: list 'test/dir1'
2025/04/22 01:51:31 DEBUG : test/dir1: list: cold listing: 2025-04-19 01:51:31.485334408 +0000 UTC
2025/04/22 01:51:31 DEBUG : test/dir1: list: read 4 from source
2025/04/22 01:51:31 DEBUG : test/dir1: list: source entries: [test/dir1/dir3 test/dir1/dir2 test/dir1/dir4 test/dir1/dir1]
2025/04/22 01:51:31 DEBUG : test/dir1: list: cached directories: 0
2025/04/22 01:51:31 DEBUG : test/dir1: list: cached dir: 'tib21171745286661/test/dir1', cache ts: 2025-04-22 01:51:31.525379126 +0000 UTC m=+40.066582584
2025/04/22 01:51:31 DEBUG : Cache remote TestInternalCache:tib21171745286661: list 'test/dir2'
2025/04/22 01:51:31 DEBUG : test/dir2: list: cold listing: 2025-04-19 01:51:31.513823086 +0000 UTC
2025/04/22 01:51:31 DEBUG : test/dir2: list: read 4 from source
2025/04/22 01:51:31 DEBUG : test/dir2: list: source entries: [test/dir2/dir3 test/dir2/dir2 test/dir2/dir4 test/dir2/dir1]
2025/04/22 01:51:31 DEBUG : test/dir2: list: cached directories: 0
2025/04/22 01:51:31 DEBUG : test/dir2: list: cached dir: 'tib21171745286661/test/dir2', cache ts: 2025-04-22 01:51:31.526795764 +0000 UTC m=+40.067999222
2025/04/22 01:51:31 DEBUG : Cache remote TestInternalCache:tib21171745286661: list 'test/dir3'
2025/04/22 01:51:31 DEBUG : test/dir3: list: cold listing: 2025-04-19 01:51:31.521666137 +0000 UTC
2025/04/22 01:51:31 DEBUG : test/dir3: list: read 4 from source
2025/04/22 01:51:31 DEBUG : test/dir3: list: source entries: [test/dir3/dir3 test/dir3/dir2 test/dir3/dir4 test/dir3/dir1]
2025/04/22 01:51:31 DEBUG : test/dir3: list: cached directories: 0
2025/04/22 01:51:31 DEBUG : Cache remote TestInternalCache:tib21171745286661: list 'test/dir4'
2025/04/22 01:51:31 DEBUG : Cache remote TestInternalCache:tib21171745286661: list 'test/dir1/dir1'
2025/04/22 01:51:31 DEBUG : test/dir4: list: cold listing: 2025-04-19 01:51:31.500031622 +0000 UTC
2025/04/22 01:51:31 DEBUG : test/dir1/dir1: list: cold listing: 2025-04-19 01:51:31.480432758 +0000 UTC
2025/04/22 01:51:31 DEBUG : test/dir4: list: read 4 from source
2025/04/22 01:51:31 DEBUG : test/dir4: list: source entries: [test/dir4/dir3 test/dir4/dir2 test/dir4/dir4 test/dir4/dir1]
2025/04/22 01:51:31 DEBUG : test/dir1/dir1: list: read 0 from source
2025/04/22 01:51:31 DEBUG : test/dir1/dir1: list: source entries: []
2025/04/22 01:51:31 DEBUG : test/dir1/dir1: list: cached directories: 0
2025/04/22 01:51:31 DEBUG : test/dir4: list: cached directories: 0
2025/04/22 01:51:31 DEBUG : Cache remote TestInternalCache:tib21171745286661: list 'test/dir1/dir3'
2025/04/22 01:51:31 DEBUG : test/dir1/dir3: list: cold listing: 2025-04-19 01:51:31.485334408 +0000 UTC
2025/04/22 01:51:31 DEBUG : Cache remote TestInternalCache:tib21171745286661: list 'test/dir1/dir2'
2025/04/22 01:51:31 DEBUG : test/dir1/dir3: list: read 0 from source
2025/04/22 01:51:31 DEBUG : test/dir1/dir3: list: source entries: []
2025/04/22 01:51:31 DEBUG : test/dir1/dir3: list: cached directories: 0
2025/04/22 01:51:31 DEBUG : test/dir1/dir2: list: cold listing: 2025-04-19 01:51:31.455190291 +0000 UTC
2025/04/22 01:51:31 DEBUG : Cache remote TestInternalCache:tib21171745286661: list 'test/dir1/dir4'
2025/04/22 01:51:31 DEBUG : test/dir1/dir4: list: cold listing: 2025-04-19 01:51:31.470035093 +0000 UTC
2025/04/22 01:51:31 DEBUG : test/dir1/dir2: list: read 0 from source
2025/04/22 01:51:31 DEBUG : test/dir1/dir4: list: read 0 from source
2025/04/22 01:51:31 DEBUG : test/dir1/dir4: list: source entries: []
2025/04/22 01:51:31 DEBUG : test/dir1/dir4: list: cached directories: 0
2025/04/22 01:51:31 DEBUG : test/dir1/dir2: list: source entries: []
2025/04/22 01:51:31 DEBUG : test/dir1/dir2: list: cached directories: 0
2025/04/22 01:51:31 DEBUG : Cache remote TestInternalCache:tib21171745286661: list 'test/dir2/dir2'
2025/04/22 01:51:31 DEBUG : Cache remote TestInternalCache:tib21171745286661: list 'test/dir2/dir1'
2025/04/22 01:51:31 DEBUG : test/dir2/dir2: list: cold listing: 2025-04-19 01:51:31.509344952 +0000 UTC
2025/04/22 01:51:31 DEBUG : test/dir2/dir2: list: read 0 from source
2025/04/22 01:51:31 DEBUG : test/dir2/dir2: list: source entries: []
2025/04/22 01:51:31 DEBUG : test/dir2/dir1: list: cold listing: 2025-04-19 01:51:31.505508481 +0000 UTC
2025/04/22 01:51:31 DEBUG : test/dir2/dir2: list: cached directories: 0
2025/04/22 01:51:31 DEBUG : test/dir2/dir1: list: read 0 from source
2025/04/22 01:51:31 DEBUG : test/dir2/dir1: list: source entries: []
2025/04/22 01:51:31 DEBUG : test/dir2/dir1: list: cached directories: 0
2025/04/22 01:51:31 DEBUG : test/dir3: list: cached dir: 'tib21171745286661/test/dir3', cache ts: 2025-04-22 01:51:31.528329062 +0000 UTC m=+40.069532520
2025/04/22 01:51:31 DEBUG : Cache remote TestInternalCache:tib21171745286661: list 'test/dir2/dir3'
2025/04/22 01:51:31 DEBUG : test/dir2/dir3: list: cold listing: 2025-04-19 01:51:31.511741309 +0000 UTC
2025/04/22 01:51:31 DEBUG : test/dir2/dir3: list: read 0 from source
2025/04/22 01:51:31 DEBUG : test/dir2/dir3: list: source entries: []
2025/04/22 01:51:31 DEBUG : test/dir2/dir3: list: cached directories: 0
2025/04/22 01:51:31 DEBUG : test/dir2/dir3: list: cached dir: 'tib21171745286661/test/dir2/dir3', cache ts: 2025-04-22 01:51:31.530534411 +0000 UTC m=+40.071737869
2025/04/22 01:51:31 DEBUG : Cache remote TestInternalCache:tib21171745286661: list 'test/dir2/dir4'
2025/04/22 01:51:31 DEBUG : test/dir2/dir4: list: cold listing: 2025-04-19 01:51:31.513823086 +0000 UTC
2025/04/22 01:51:31 DEBUG : test/dir2/dir4: list: read 0 from source
2025/04/22 01:51:31 DEBUG : test/dir2/dir4: list: source entries: []
2025/04/22 01:51:31 DEBUG : test/dir2/dir4: list: cached directories: 0
2025/04/22 01:51:31 DEBUG : test/dir1/dir1: list: cached dir: 'tib21171745286661/test/dir1/dir1', cache ts: 2025-04-22 01:51:31.529325483 +0000 UTC m=+40.070528921
2025/04/22 01:51:31 DEBUG : Cache remote TestInternalCache:tib21171745286661: list 'test/dir3/dir1'
2025/04/22 01:51:31 DEBUG : test/dir3/dir1: list: cold listing: 2025-04-19 01:51:31.515829883 +0000 UTC
2025/04/22 01:51:31 DEBUG : test/dir3/dir1: list: read 0 from source
2025/04/22 01:51:31 DEBUG : test/dir3/dir1: list: source entries: []
2025/04/22 01:51:31 DEBUG : test/dir3/dir1: list: cached directories: 0
2025/04/22 01:51:31 DEBUG : test/dir4: list: cached dir: 'tib21171745286661/test/dir4', cache ts: 2025-04-22 01:51:31.52933458 +0000 UTC m=+40.070538037
2025/04/22 01:51:31 DEBUG : Cache remote TestInternalCache:tib21171745286661: list 'test/dir3/dir2'
2025/04/22 01:51:31 DEBUG : test/dir3/dir2: list: cold listing: 2025-04-19 01:51:31.517845827 +0000 UTC
2025/04/22 01:51:31 DEBUG : test/dir3/dir2: list: read 0 from source
2025/04/22 01:51:31 DEBUG : test/dir3/dir2: list: source entries: []
2025/04/22 01:51:31 DEBUG : test/dir3/dir2: list: cached directories: 0
2025/04/22 01:51:31 DEBUG : test/dir1/dir3: list: cached dir: 'tib21171745286661/test/dir1/dir3', cache ts: 2025-04-22 01:51:31.529440739 +0000 UTC m=+40.070644196
2025/04/22 01:51:31 DEBUG : Cache remote TestInternalCache:tib21171745286661: list 'test/dir3/dir3'
2025/04/22 01:51:31 DEBUG : test/dir3/dir3: list: cold listing: 2025-04-19 01:51:31.519768736 +0000 UTC
2025/04/22 01:51:31 DEBUG : test/dir3/dir3: list: read 0 from source
2025/04/22 01:51:31 DEBUG : test/dir3/dir3: list: source entries: []
2025/04/22 01:51:31 DEBUG : test/dir3/dir3: list: cached directories: 0
2025/04/22 01:51:31 DEBUG : test/dir1/dir2: list: cached dir: 'tib21171745286661/test/dir1/dir2', cache ts: 2025-04-22 01:51:31.529545425 +0000 UTC m=+40.070748863
2025/04/22 01:51:31 DEBUG : Cache remote TestInternalCache:tib21171745286661: list 'test/dir3/dir4'
2025/04/22 01:51:31 DEBUG : test/dir3/dir4: list: cold listing: 2025-04-19 01:51:31.521666137 +0000 UTC
2025/04/22 01:51:31 DEBUG : test/dir3/dir4: list: read 0 from source
2025/04/22 01:51:31 DEBUG : test/dir3/dir4: list: source entries: []
2025/04/22 01:51:31 DEBUG : test/dir3/dir4: list: cached directories: 0
2025/04/22 01:51:31 DEBUG : test/dir1/dir4: list: cached dir: 'tib21171745286661/test/dir1/dir4', cache ts: 2025-04-22 01:51:31.529536188 +0000 UTC m=+40.070739646
2025/04/22 01:51:31 DEBUG : Cache remote TestInternalCache:tib21171745286661: list 'test/dir4/dir1'
2025/04/22 01:51:31 DEBUG : test/dir4/dir1: list: cold listing: 2025-04-19 01:51:31.492553537 +0000 UTC
2025/04/22 01:51:31 DEBUG : test/dir4/dir1: list: read 0 from source
2025/04/22 01:51:31 DEBUG : test/dir4/dir1: list: source entries: []
2025/04/22 01:51:31 DEBUG : test/dir4/dir1: list: cached directories: 0
2025/04/22 01:51:31 DEBUG : test/dir2/dir2: list: cached dir: 'tib21171745286661/test/dir2/dir2', cache ts: 2025-04-22 01:51:31.529641806 +0000 UTC m=+40.070845264
2025/04/22 01:51:31 DEBUG : Cache remote TestInternalCache:tib21171745286661: list 'test/dir4/dir2'
2025/04/22 01:51:31 DEBUG : test/dir4/dir2: list: cold listing: 2025-04-19 01:51:31.497619665 +0000 UTC
2025/04/22 01:51:31 DEBUG : test/dir4/dir2: list: read 0 from source
2025/04/22 01:51:31 DEBUG : test/dir4/dir2: list: source entries: []
2025/04/22 01:51:31 DEBUG : test/dir4/dir2: list: cached directories: 0
2025/04/22 01:51:31 DEBUG : test/dir2/dir1: list: cached dir: 'tib21171745286661/test/dir2/dir1', cache ts: 2025-04-22 01:51:31.529681129 +0000 UTC m=+40.070884567
2025/04/22 01:51:31 DEBUG : Cache remote TestInternalCache:tib21171745286661: list 'test/dir4/dir3'
2025/04/22 01:51:31 DEBUG : test/dir4/dir3: list: cold listing: 2025-04-19 01:51:31.488737464 +0000 UTC
2025/04/22 01:51:31 DEBUG : test/dir4/dir3: list: read 0 from source
2025/04/22 01:51:31 DEBUG : test/dir4/dir3: list: source entries: []
2025/04/22 01:51:31 DEBUG : test/dir4/dir3: list: cached directories: 0
2025/04/22 01:51:31 DEBUG : test/dir2/dir4: list: cached dir: 'tib21171745286661/test/dir2/dir4', cache ts: 2025-04-22 01:51:31.532539134 +0000 UTC m=+40.073742602
2025/04/22 01:51:31 DEBUG : Cache remote TestInternalCache:tib21171745286661: list 'test/dir4/dir4'
2025/04/22 01:51:31 DEBUG : test/dir4/dir4: list: cold listing: 2025-04-19 01:51:31.500031622 +0000 UTC
2025/04/22 01:51:31 DEBUG : test/dir4/dir4: list: read 0 from source
2025/04/22 01:51:31 DEBUG : test/dir4/dir4: list: source entries: []
2025/04/22 01:51:31 DEBUG : test/dir4/dir4: list: cached directories: 0
2025/04/22 01:51:31 DEBUG : test/dir3/dir1: list: cached dir: 'tib21171745286661/test/dir3/dir1', cache ts: 2025-04-22 01:51:31.534465499 +0000 UTC m=+40.075668967
2025/04/22 01:51:31 DEBUG : test/dir3/dir2: list: cached dir: 'tib21171745286661/test/dir3/dir2', cache ts: 2025-04-22 01:51:31.535071326 +0000 UTC m=+40.076274795
2025/04/22 01:51:31 DEBUG : test/dir3/dir3: list: cached dir: 'tib21171745286661/test/dir3/dir3', cache ts: 2025-04-22 01:51:31.53596317 +0000 UTC m=+40.077166629
2025/04/22 01:51:31 DEBUG : test/dir3/dir4: list: cached dir: 'tib21171745286661/test/dir3/dir4', cache ts: 2025-04-22 01:51:31.53674124 +0000 UTC m=+40.077944699
2025/04/22 01:51:31 DEBUG : test/dir4/dir1: list: cached dir: 'tib21171745286661/test/dir4/dir1', cache ts: 2025-04-22 01:51:31.538528635 +0000 UTC m=+40.079732093
2025/04/22 01:51:31 DEBUG : test/dir4/dir2: list: cached dir: 'tib21171745286661/test/dir4/dir2', cache ts: 2025-04-22 01:51:31.539409909 +0000 UTC m=+40.080613367
2025/04/22 01:51:31 DEBUG : test/dir4/dir3: list: cached dir: 'tib21171745286661/test/dir4/dir3', cache ts: 2025-04-22 01:51:31.540682076 +0000 UTC m=+40.081885534
2025/04/22 01:51:31 DEBUG : test/dir4/dir4: list: cached dir: 'tib21171745286661/test/dir4/dir4', cache ts: 2025-04-22 01:51:31.541871078 +0000 UTC m=+40.083074536
2025/04/22 01:51:31 DEBUG : removing 16 level 3 directories
2025/04/22 01:51:31 INFO  : test/dir2/dir4: Removing directory
2025/04/22 01:51:31 DEBUG : Cache remote TestInternalCache:tib21171745286661: rmdir 'test/dir2/dir4'
2025/04/22 01:51:31 DEBUG : test/dir2/dir4: rmdir: removed dir in source fs
2025/04/22 01:51:31 INFO  : test/dir2/dir2: Removing directory
2025/04/22 01:51:31 DEBUG : Cache remote TestInternalCache:tib21171745286661: rmdir 'test/dir2/dir2'
2025/04/22 01:51:31 DEBUG : test/dir2/dir2: rmdir: removed dir in source fs
2025/04/22 01:51:31 INFO  : test/dir2/dir3: Removing directory
2025/04/22 01:51:31 INFO  : test/dir2/dir1: Removing directory
2025/04/22 01:51:31 DEBUG : Cache remote TestInternalCache:tib21171745286661: rmdir 'test/dir2/dir1'
2025/04/22 01:51:31 DEBUG : Cache remote TestInternalCache:tib21171745286661: rmdir 'test/dir2/dir3'
2025/04/22 01:51:31 DEBUG : test/dir2/dir1: rmdir: removed dir in source fs
2025/04/22 01:51:31 INFO  : test/dir1/dir2: Removing directory
2025/04/22 01:51:31 DEBUG : Cache remote TestInternalCache:tib21171745286661: rmdir 'test/dir1/dir2'
2025/04/22 01:51:31 DEBUG : test/dir2/dir3: rmdir: removed dir in source fs
2025/04/22 01:51:31 DEBUG : test/dir1/dir2: rmdir: removed dir in source fs
2025/04/22 01:51:31 INFO  : test/dir1/dir3: Removing directory
2025/04/22 01:51:31 DEBUG : Cache remote TestInternalCache:tib21171745286661: rmdir 'test/dir1/dir3'
2025/04/22 01:51:31 INFO  : test/dir1/dir1: Removing directory
2025/04/22 01:51:31 DEBUG : Cache remote TestInternalCache:tib21171745286661: rmdir 'test/dir1/dir1'
2025/04/22 01:51:31 DEBUG : test/dir1/dir3: rmdir: removed dir in source fs
2025/04/22 01:51:31 DEBUG : test/dir1/dir1: rmdir: removed dir in source fs
2025/04/22 01:51:31 INFO  : test/dir1/dir4: Removing directory
2025/04/22 01:51:31 DEBUG : Cache remote TestInternalCache:tib21171745286661: rmdir 'test/dir1/dir4'
2025/04/22 01:51:31 DEBUG : test/dir1/dir4: rmdir: removed dir in source fs
2025/04/22 01:51:31 DEBUG : test/dir2/dir4: rmdir: removed from cache
2025/04/22 01:51:31 DEBUG : test/dir2: cache: expired tib21171745286661/test/dir2
2025/04/22 01:51:31 DEBUG : test/dir2: cache: expired tib21171745286661/test
2025/04/22 01:51:31 DEBUG : test/dir2: cache: expired tib21171745286661
2025/04/22 01:51:31 INFO  : test/dir2: rmdir: cache expired
2025/04/22 01:51:31 INFO  : test/dir3/dir1: Removing directory
2025/04/22 01:51:31 DEBUG : Cache remote TestInternalCache:tib21171745286661: rmdir 'test/dir3/dir1'
2025/04/22 01:51:31 DEBUG : test/dir3/dir1: rmdir: removed dir in source fs
2025/04/22 01:51:31 DEBUG : test/dir2/dir2: rmdir: removed from cache
2025/04/22 01:51:31 DEBUG : test/dir2/dir1: rmdir: removed from cache
2025/04/22 01:51:31 DEBUG : test/dir2/dir3: rmdir: removed from cache
2025/04/22 01:51:31 DEBUG : test/dir1/dir2: rmdir: removed from cache
2025/04/22 01:51:31 DEBUG : test/dir1/dir3: rmdir: removed from cache
2025/04/22 01:51:31 DEBUG : test/dir1/dir1: rmdir: removed from cache
2025/04/22 01:51:31 DEBUG : test/dir1/dir4: rmdir: removed from cache
2025/04/22 01:51:31 DEBUG : test/dir2: cache: expired tib21171745286661/test/dir2
2025/04/22 01:51:31 DEBUG : test/dir2: cache: expired tib21171745286661/test
2025/04/22 01:51:31 DEBUG : test/dir2: cache: expired tib21171745286661
2025/04/22 01:51:31 DEBUG : test/dir3/dir1: rmdir: removed from cache
2025/04/22 01:51:31 DEBUG : test/dir2: cache: expired tib21171745286661/test/dir2
2025/04/22 01:51:31 DEBUG : test/dir2: cache: expired tib21171745286661/test
2025/04/22 01:51:31 DEBUG : test/dir2: cache: expired tib21171745286661
2025/04/22 01:51:31 INFO  : test/dir2: rmdir: cache expired
2025/04/22 01:51:31 INFO  : test/dir3/dir2: Removing directory
2025/04/22 01:51:31 DEBUG : Cache remote TestInternalCache:tib21171745286661: rmdir 'test/dir3/dir2'
2025/04/22 01:51:31 DEBUG : test/dir3/dir2: rmdir: removed dir in source fs
2025/04/22 01:51:31 DEBUG : test/dir2: cache: expired tib21171745286661/test/dir2
2025/04/22 01:51:31 DEBUG : test/dir2: cache: expired tib21171745286661/test
2025/04/22 01:51:31 DEBUG : test/dir2: cache: expired tib21171745286661
2025/04/22 01:51:31 INFO  : test/dir2: rmdir: cache expired
2025/04/22 01:51:31 INFO  : test/dir3/dir3: Removing directory
2025/04/22 01:51:31 DEBUG : Cache remote TestInternalCache:tib21171745286661: rmdir 'test/dir3/dir3'
2025/04/22 01:51:31 DEBUG : test/dir3/dir3: rmdir: removed dir in source fs
2025/04/22 01:51:31 DEBUG : test/dir1: cache: expired tib21171745286661/test/dir1
2025/04/22 01:51:31 DEBUG : test/dir1: cache: expired tib21171745286661/test
2025/04/22 01:51:31 DEBUG : test/dir1: cache: expired tib21171745286661
2025/04/22 01:51:31 INFO  : test/dir2: rmdir: cache expired
2025/04/22 01:51:31 INFO  : test/dir3/dir4: Removing directory
2025/04/22 01:51:31 DEBUG : Cache remote TestInternalCache:tib21171745286661: rmdir 'test/dir3/dir4'
2025/04/22 01:51:31 DEBUG : test/dir3/dir4: rmdir: removed dir in source fs
2025/04/22 01:51:31 DEBUG : test/dir1: cache: expired tib21171745286661/test/dir1
2025/04/22 01:51:31 DEBUG : test/dir1: cache: expired tib21171745286661/test
2025/04/22 01:51:31 DEBUG : test/dir1: cache: expired tib21171745286661
2025/04/22 01:51:31 INFO  : test/dir1: rmdir: cache expired
2025/04/22 01:51:31 INFO  : test/dir4/dir1: Removing directory
2025/04/22 01:51:31 DEBUG : Cache remote TestInternalCache:tib21171745286661: rmdir 'test/dir4/dir1'
2025/04/22 01:51:31 DEBUG : test/dir4/dir1: rmdir: removed dir in source fs
2025/04/22 01:51:31 DEBUG : test/dir1: cache: expired tib21171745286661/test/dir1
2025/04/22 01:51:31 DEBUG : test/dir1: cache: expired tib21171745286661/test
2025/04/22 01:51:31 DEBUG : test/dir1: cache: expired tib21171745286661
2025/04/22 01:51:31 INFO  : test/dir1: rmdir: cache expired
2025/04/22 01:51:31 INFO  : test/dir4/dir2: Removing directory
2025/04/22 01:51:31 DEBUG : Cache remote TestInternalCache:tib21171745286661: rmdir 'test/dir4/dir2'
2025/04/22 01:51:31 DEBUG : test/dir4/dir2: rmdir: removed dir in source fs
2025/04/22 01:51:31 DEBUG : test/dir1: cache: expired tib21171745286661/test/dir1
2025/04/22 01:51:31 DEBUG : test/dir1: cache: expired tib21171745286661/test
2025/04/22 01:51:31 DEBUG : test/dir1: cache: expired tib21171745286661
2025/04/22 01:51:31 INFO  : test/dir1: rmdir: cache expired
2025/04/22 01:51:31 INFO  : test/dir4/dir3: Removing directory
2025/04/22 01:51:31 DEBUG : Cache remote TestInternalCache:tib21171745286661: rmdir 'test/dir4/dir3'
2025/04/22 01:51:31 DEBUG : test/dir4/dir3: rmdir: removed dir in source fs
2025/04/22 01:51:31 DEBUG : test/dir3: cache: expired tib21171745286661/test/dir3
2025/04/22 01:51:31 DEBUG : test/dir3: cache: expired tib21171745286661/test
2025/04/22 01:51:31 DEBUG : test/dir3: cache: expired tib21171745286661
2025/04/22 01:51:31 INFO  : test/dir1: rmdir: cache expired
2025/04/22 01:51:31 INFO  : test/dir4/dir4: Removing directory
2025/04/22 01:51:31 DEBUG : Cache remote TestInternalCache:tib21171745286661: rmdir 'test/dir4/dir4'
2025/04/22 01:51:31 DEBUG : test/dir4/dir4: rmdir: removed dir in source fs
2025/04/22 01:51:31 INFO  : test/dir3: rmdir: cache expired
2025/04/22 01:51:31 DEBUG : test/dir3/dir2: rmdir: removed from cache
2025/04/22 01:51:31 DEBUG : test/dir3/dir3: rmdir: removed from cache
2025/04/22 01:51:31 DEBUG : test/dir3/dir4: rmdir: removed from cache
2025/04/22 01:51:31 DEBUG : test/dir4/dir1: rmdir: removed from cache
2025/04/22 01:51:31 DEBUG : test/dir4/dir2: rmdir: removed from cache
2025/04/22 01:51:31 DEBUG : test/dir4/dir3: rmdir: removed from cache
2025/04/22 01:51:31 DEBUG : test/dir3: cache: expired tib21171745286661/test/dir3
2025/04/22 01:51:31 DEBUG : test/dir3: cache: expired tib21171745286661/test
2025/04/22 01:51:31 DEBUG : test/dir3: cache: expired tib21171745286661
2025/04/22 01:51:31 DEBUG : test/dir4/dir4: rmdir: removed from cache
2025/04/22 01:51:31 DEBUG : test/dir3: cache: expired tib21171745286661/test/dir3
2025/04/22 01:51:31 DEBUG : test/dir3: cache: expired tib21171745286661/test
2025/04/22 01:51:31 DEBUG : test/dir3: cache: expired tib21171745286661
2025/04/22 01:51:31 INFO  : test/dir3: rmdir: cache expired
2025/04/22 01:51:31 DEBUG : test/dir3: cache: expired tib21171745286661/test/dir3
2025/04/22 01:51:31 DEBUG : test/dir3: cache: expired tib21171745286661/test
2025/04/22 01:51:31 DEBUG : test/dir3: cache: expired tib21171745286661
2025/04/22 01:51:31 INFO  : test/dir3: rmdir: cache expired
2025/04/22 01:51:31 DEBUG : test/dir4: cache: expired tib21171745286661/test/dir4
2025/04/22 01:51:31 DEBUG : test/dir4: cache: expired tib21171745286661/test
2025/04/22 01:51:31 DEBUG : test/dir4: cache: expired tib21171745286661
2025/04/22 01:51:31 INFO  : test/dir3: rmdir: cache expired
2025/04/22 01:51:31 DEBUG : test/dir4: cache: expired tib21171745286661/test/dir4
2025/04/22 01:51:31 INFO  : test/dir4: rmdir: cache expired
2025/04/22 01:51:31 DEBUG : test/dir4: cache: expired tib21171745286661/test
2025/04/22 01:51:31 DEBUG : test/dir4: cache: expired tib21171745286661
2025/04/22 01:51:31 DEBUG : test/dir4: cache: expired tib21171745286661/test/dir4
2025/04/22 01:51:31 DEBUG : test/dir4: cache: expired tib21171745286661/test
2025/04/22 01:51:31 DEBUG : test/dir4: cache: expired tib21171745286661
2025/04/22 01:51:31 DEBUG : test/dir4: cache: expired tib21171745286661/test/dir4
2025/04/22 01:51:31 DEBUG : test/dir4: cache: expired tib21171745286661/test
2025/04/22 01:51:31 DEBUG : test/dir4: cache: expired tib21171745286661
2025/04/22 01:51:31 INFO  : test/dir4: rmdir: cache expired
2025/04/22 01:51:31 INFO  : test/dir4: rmdir: cache expired
2025/04/22 01:51:31 INFO  : test/dir4: rmdir: cache expired
2025/04/22 01:51:31 DEBUG : removing 4 level 2 directories
2025/04/22 01:51:31 INFO  : test/dir4: Removing directory
2025/04/22 01:51:31 DEBUG : Cache remote TestInternalCache:tib21171745286661: rmdir 'test/dir4'
2025/04/22 01:51:31 DEBUG : test/dir4: rmdir: removed dir in source fs
2025/04/22 01:51:31 INFO  : test/dir1: Removing directory
2025/04/22 01:51:31 DEBUG : Cache remote TestInternalCache:tib21171745286661: rmdir 'test/dir1'
2025/04/22 01:51:31 INFO  : test/dir3: Removing directory
2025/04/22 01:51:31 DEBUG : Cache remote TestInternalCache:tib21171745286661: rmdir 'test/dir3'
2025/04/22 01:51:31 DEBUG : test/dir1: rmdir: removed dir in source fs
2025/04/22 01:51:31 DEBUG : test/dir3: rmdir: removed dir in source fs
2025/04/22 01:51:31 INFO  : test/dir2: Removing directory
2025/04/22 01:51:31 DEBUG : Cache remote TestInternalCache:tib21171745286661: rmdir 'test/dir2'
2025/04/22 01:51:31 DEBUG : test/dir2: rmdir: removed dir in source fs
2025/04/22 01:51:31 DEBUG : test/dir4: rmdir: removed from cache
2025/04/22 01:51:31 DEBUG : test/dir1: rmdir: removed from cache
2025/04/22 01:51:31 DEBUG : test: cache: expired tib21171745286661/test
2025/04/22 01:51:31 DEBUG : test: cache: expired tib21171745286661
2025/04/22 01:51:31 INFO  : test: rmdir: cache expired
2025/04/22 01:51:31 DEBUG : test/dir3: rmdir: removed from cache
2025/04/22 01:51:31 DEBUG : test: cache: expired tib21171745286661/test
2025/04/22 01:51:31 DEBUG : test: cache: expired tib21171745286661
2025/04/22 01:51:31 DEBUG : test/dir2: rmdir: removed from cache
2025/04/22 01:51:31 DEBUG : test: cache: expired tib21171745286661/test
2025/04/22 01:51:31 DEBUG : test: cache: expired tib21171745286661
2025/04/22 01:51:31 INFO  : test: rmdir: cache expired
2025/04/22 01:51:31 DEBUG : test: cache: expired tib21171745286661/test
2025/04/22 01:51:31 DEBUG : test: cache: expired tib21171745286661
2025/04/22 01:51:31 INFO  : test: rmdir: cache expired
2025/04/22 01:51:31 INFO  : test: rmdir: cache expired
2025/04/22 01:51:31 DEBUG : removing 1 level 1 directories
2025/04/22 01:51:31 INFO  : test: Removing directory
2025/04/22 01:51:31 DEBUG : Cache remote TestInternalCache:tib21171745286661: rmdir 'test'
2025/04/22 01:51:31 DEBUG : test: rmdir: removed dir in source fs
2025/04/22 01:51:31 DEBUG : test: rmdir: removed from cache
2025/04/22 01:51:31 DEBUG : : cache: expired tib21171745286661
2025/04/22 01:51:31 INFO  : : rmdir: cache expired
2025/04/22 01:51:31 DEBUG : removing 1 level 0 directories
2025/04/22 01:51:31 INFO  : Cache remote TestInternalCache:tib21171745286661: Removing directory
2025/04/22 01:51:31 DEBUG : Cache remote TestInternalCache:tib21171745286661: rmdir ''
2025/04/22 01:51:31 DEBUG : : rmdir: removed dir in source fs
2025/04/22 01:51:31 DEBUG : : rmdir: removed from cache
2025/04/22 01:51:31 INFO  : : rmdir: cache expired
2025/04/22 01:51:31 DEBUG : Cache remote TestInternalCache:tib21171745286661: Services stopped
--- PASS: TestInternalBug2117 (30.22s)
=== RUN   TestIntegration
    fstests.go:438: Using remote "TestCache:"
2025/04/22 01:51:31 DEBUG : Creating backend with remote "TestCache:rclone-test-gijupad8fiso"
2025/04/22 01:51:31 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2025/04/22 01:51:31 DEBUG : Setting cache db_wait_time="30m" from environment variable RCLONE_CACHE_DB_WAIT_TIME
2025/04/22 01:51:31 DEBUG : TestCache: detected overridden config - adding "{VDL3R}" suffix to name
2025/04/22 01:51:31 DEBUG : Setting cache db_wait_time="30m" from environment variable RCLONE_CACHE_DB_WAIT_TIME
2025/04/22 01:51:31 DEBUG : Creating backend with remote "/tmp/rclone_cache_test/rclone-test-gijupad8fiso"
2025/04/22 01:51:31 DEBUG : TestCache{VDL3R}: wrapped local:/tmp/rclone_cache_test/rclone-test-gijupad8fiso at root rclone-test-gijupad8fiso
2025/04/22 01:51:31 INFO  : TestCache{VDL3R}: Cache DB path: /home/rclone/.cache/rclone/cache-backend/TestCache{VDL3R}.db
2025/04/22 01:51:31 INFO  : TestCache{VDL3R}: Cache chunk path: /home/rclone/.cache/rclone/cache-backend/TestCache{VDL3R}
2025/04/22 01:51:51 INFO  : Cache remote TestInternalCache:tionf1745286651: stopping cleanup
2025/04/22 01:51:51 INFO  : Cache remote TestInternalCache:ticwcm1745286651: stopping cleanup
2025/04/22 01:51:52 INFO  : Cache remote TestInternalCache:tidwcm1745286652: stopping cleanup
2025/04/22 01:51:53 INFO  : Cache remote TestInternalCache:ticucm1745286653: stopping cleanup
2025/04/22 01:51:53 INFO  : Cache remote TestInternalCache:tiwfcns1745286653: stopping cleanup
2025/04/22 01:51:54 INFO  : Cache remote TestInternalCache:timwn1745286654: stopping cleanup
2025/04/22 01:51:54 INFO  : Cache remote TestInternalCache:tincep1745286654: stopping cleanup
2025/04/22 01:51:54 INFO  : Cache remote TestInternalCache:ticsadcf1745286654: stopping cleanup
2025/04/22 01:51:55 INFO  : Cache remote TestInternalCache:ticw: stopping cleanup
2025/04/22 01:51:55 INFO  : Cache remote TestInternalCache:timcsr1745286655: stopping cleanup
2025/04/22 02:06:01 INFO  : Cache remote TestInternalCache:tib21171745286661: stopping cleanup
2025/04/22 02:21:31 ERROR : /home/rclone/.cache/rclone/cache-backend/TestCache{VDL3R}.db: Error opening storage cache. Is there another rclone running on the same remote? failed to open a cache connection to "/home/rclone/.cache/rclone/cache-backend/TestCache{VDL3R}.db": timeout
    fstests.go:462: 
        	Error Trace:	/home/rclone/go/src/github.com/rclone/rclone/fstest/fstests/fstests.go:462
        	            				/home/rclone/go/src/github.com/rclone/rclone/backend/cache/cache_test.go:17
        	Error:      	Received unexpected error:
        	            	failed to start cache db: failed to open a cache connection to "/home/rclone/.cache/rclone/cache-backend/TestCache{VDL3R}.db": timeout
        	Test:       	TestIntegration
        	Messages:   	unexpected error: failed to start cache db: failed to open a cache connection to "/home/rclone/.cache/rclone/cache-backend/TestCache{VDL3R}.db": timeout
--- FAIL: TestIntegration (1799.98s)
=== RUN   TestInternalUploadTempDirCreated
2025/04/22 02:21:31 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2025/04/22 02:21:31 DEBUG : Creating backend with remote "TestInternalCache-local:/tmp/TestInternalCache-local/tiutdc1745288491"
2025/04/22 02:21:31 DEBUG : TestInternalCache: wrapped TestInternalCache-local:/tmp/TestInternalCache-local/tiutdc1745288491 at root tiutdc1745288491
2025/04/22 02:21:31 INFO  : TestInternalCache: Cache DB path: /home/rclone/.cache/rclone/cache-backend/TestInternalCache.db
2025/04/22 02:21:31 INFO  : TestInternalCache: Cache chunk path: /home/rclone/.cache/rclone/cache-backend/TestInternalCache
2025/04/22 02:21:31 INFO  : TestInternalCache: Chunk Memory: true
2025/04/22 02:21:31 INFO  : TestInternalCache: Chunk Size: 5Mi
2025/04/22 02:21:31 INFO  : TestInternalCache: Chunk Total Size: 10Gi
2025/04/22 02:21:31 INFO  : TestInternalCache: Chunk Clean Interval: 1m0s
2025/04/22 02:21:31 INFO  : TestInternalCache: Workers: 4
2025/04/22 02:21:31 INFO  : TestInternalCache: File Age: 6h0m0s
2025/04/22 02:21:31 DEBUG : Creating backend with remote "/tmp/rclonecache-tmp3510924608/tiutdc1745288491"
2025/04/22 02:21:31 INFO  : TestInternalCache: Upload Temp Rest Time: 15s
2025/04/22 02:21:31 INFO  : TestInternalCache: Upload Temp FS: /tmp/rclonecache-tmp3510924608/tiutdc1745288491
2025/04/22 02:21:31 DEBUG : Waiting for deletions to finish
2025/04/22 02:21:31 DEBUG : Cache remote TestInternalCache:tiutdc1745288491: list ''
2025/04/22 02:21:31 DEBUG : : list: error: couldn't open bucket (tiutdc1745288491)
2025/04/22 02:21:31 DEBUG : : list: read 0 from temp fs
2025/04/22 02:21:31 DEBUG : : list: temp fs entries: []
2025/04/22 02:21:31 ERROR : : error listing: directory not found
2025/04/22 02:21:31 DEBUG : Cache remote TestInternalCache:tiutdc1745288491: list ''
2025/04/22 02:21:31 DEBUG : : list: error: couldn't open bucket (tiutdc1745288491)
2025/04/22 02:21:31 DEBUG : : list: read 0 from temp fs
2025/04/22 02:21:31 DEBUG : : list: temp fs entries: []
2025/04/22 02:21:31 ERROR : Cache remote TestInternalCache:tiutdc1745288491: Failed to list "": directory not found
2025/04/22 02:21:31 DEBUG : removing 1 level 0 directories
2025/04/22 02:21:31 INFO  : Cache remote TestInternalCache:tiutdc1745288491: Removing directory
2025/04/22 02:21:31 DEBUG : Cache remote TestInternalCache:tiutdc1745288491: rmdir ''
2025/04/22 02:21:32 DEBUG : : rmdir: read 0 from temp fs
2025/04/22 02:21:32 DEBUG : : rmdir: temp fs entries: []
2025/04/22 02:21:32 DEBUG : tiutdc1745288491: couldn't delete from cache: bucket not found
2025/04/22 02:21:32 DEBUG : : rmdir: removed from cache
2025/04/22 02:21:32 INFO  : : rmdir: cache expired
2025/04/22 02:21:33 DEBUG : Cache remote TestInternalCache:tiutdc1745288491: mkdir ''
2025/04/22 02:21:33 DEBUG : : mkdir: created dir in source fs
2025/04/22 02:21:33 DEBUG : : mkdir: added to cache
2025/04/22 02:21:33 DEBUG : : cache: expired tiutdc1745288491
2025/04/22 02:21:33 INFO  : : mkdir: cache expired
2025/04/22 02:21:33 DEBUG : Waiting for deletions to finish
2025/04/22 02:21:33 DEBUG : Cache remote TestInternalCache:tiutdc1745288491: list ''
2025/04/22 02:21:33 DEBUG : : list: cold listing: 2025-04-21 20:21:33.129755019 +0000 UTC
2025/04/22 02:21:33 DEBUG : : list: read 0 from temp fs
2025/04/22 02:21:33 DEBUG : : list: temp fs entries: []
2025/04/22 02:21:33 DEBUG : : list: read 0 from source
2025/04/22 02:21:33 DEBUG : : list: source entries: []
2025/04/22 02:21:33 DEBUG : : list: cached directories: 0
2025/04/22 02:21:33 DEBUG : : list: cached dir: 'tiutdc1745288491', cache ts: 2025-04-22 02:21:33.13087909 +0000 UTC m=+1841.672082519
2025/04/22 02:21:33 DEBUG : Cache remote TestInternalCache:tiutdc1745288491: list ''
2025/04/22 02:21:33 DEBUG : : list: empty listing
2025/04/22 02:21:33 DEBUG : : list: read 0 from temp fs
2025/04/22 02:21:33 DEBUG : : list: temp fs entries: []
2025/04/22 02:21:33 DEBUG : : list: read 0 from source
2025/04/22 02:21:33 DEBUG : : list: source entries: []
2025/04/22 02:21:33 DEBUG : : list: cached directories: 0
2025/04/22 02:21:33 DEBUG : : list: cached dir: 'tiutdc1745288491', cache ts: 2025-04-22 02:21:33.131900939 +0000 UTC m=+1841.673104367
2025/04/22 02:21:33 DEBUG : removing 1 level 0 directories
2025/04/22 02:21:33 INFO  : Cache remote TestInternalCache:tiutdc1745288491: Removing directory
2025/04/22 02:21:33 DEBUG : Cache remote TestInternalCache:tiutdc1745288491: rmdir ''
2025/04/22 02:21:34 DEBUG : : rmdir: removed dir in source fs
2025/04/22 02:21:34 DEBUG : : rmdir: read 0 from temp fs
2025/04/22 02:21:34 DEBUG : : rmdir: temp fs entries: []
2025/04/22 02:21:34 DEBUG : : rmdir: removed from cache
2025/04/22 02:21:34 INFO  : : rmdir: cache expired
2025/04/22 02:21:35 DEBUG : Cache remote TestInternalCache:tiutdc1745288491: Services stopped
--- PASS: TestInternalUploadTempDirCreated (4.05s)
=== RUN   TestInternalUploadQueueOneFileNoRest
2025/04/22 02:21:35 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/22 02:21:35 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/22 02:21:35 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/22 02:21:35 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/22 02:21:35 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/22 02:21:35 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/22 02:21:35 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	1844.198s
"go test -v -timeout 1h0m0s -remote TestCache: -verbose" - Finished ERROR in 30m45.472820851s (try 1/5): exit status 1: Failed [TestIntegration]