"go test -v -timeout 1h0m0s -remote TestCache: -verbose" - Starting (try 1/5)
2025/01/21 03:37:39 NOTICE: Running with the following params: 
 remote: TestInternalCache
2025/01/21 03:37:39 NOTICE: Temp Upload Dir: /tmp/rclonecache-tmp2620681130
=== RUN   TestInternalListRootAndInnerRemotes
2025/01/21 03:37:39 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/01/21 03:37:39 DEBUG : Using config file from "/home/rclone/.rclone.conf"
    cache_internal_test.go:858: Need remote (TestInternalCache) to exist
--- SKIP: TestInternalObjWrapFsFound (0.02s)
=== RUN   TestInternalObjNotFound
2025/01/21 03:37:39 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2025/01/21 03:37:39 NOTICE: WARNING: Cache backend is deprecated and may be removed in future. Please use VFS instead.
2025/01/21 03:37:39 DEBUG : Creating backend with remote "TestInternalCache-local:/tmp/TestInternalCache-local/tionf1737430659"
2025/01/21 03:37:39 DEBUG : TestInternalCache: wrapped TestInternalCache-local:/tmp/TestInternalCache-local/tionf1737430659 at root tionf1737430659
2025/01/21 03:37:39 INFO  : TestInternalCache: Cache DB path: /home/rclone/.cache/rclone/cache-backend/TestInternalCache.db
2025/01/21 03:37:39 INFO  : TestInternalCache: Cache chunk path: /home/rclone/.cache/rclone/cache-backend/TestInternalCache
2025/01/21 03:37:39 INFO  : TestInternalCache: Chunk Memory: true
2025/01/21 03:37:39 INFO  : TestInternalCache: Chunk Size: 5Mi
2025/01/21 03:37:39 INFO  : TestInternalCache: Chunk Total Size: 10Gi
2025/01/21 03:37:39 INFO  : TestInternalCache: Chunk Clean Interval: 1m0s
2025/01/21 03:37:39 INFO  : TestInternalCache: Workers: 4
2025/01/21 03:37:39 INFO  : TestInternalCache: File Age: 6h0m0s
2025/01/21 03:37:39 DEBUG : Waiting for deletions to finish
2025/01/21 03:37:39 DEBUG : Cache remote TestInternalCache:tionf1737430659: list ''
2025/01/21 03:37:39 DEBUG : : list: error: couldn't open bucket (tionf1737430659)
2025/01/21 03:37:39 ERROR : : error listing: directory not found
2025/01/21 03:37:39 DEBUG : Cache remote TestInternalCache:tionf1737430659: list ''
2025/01/21 03:37:39 DEBUG : : list: error: couldn't open bucket (tionf1737430659)
2025/01/21 03:37:39 ERROR : Cache remote TestInternalCache:tionf1737430659: Failed to list "": directory not found
2025/01/21 03:37:39 DEBUG : removing 1 level 0 directories
2025/01/21 03:37:39 INFO  : Cache remote TestInternalCache:tionf1737430659: Removing directory
2025/01/21 03:37:39 DEBUG : Cache remote TestInternalCache:tionf1737430659: rmdir ''
2025/01/21 03:37:39 ERROR : : Failed to rmdir: stat /tmp/TestInternalCache-local/tionf1737430659: no such file or directory
2025/01/21 03:37:39 DEBUG : Cache remote TestInternalCache:tionf1737430659: mkdir ''
2025/01/21 03:37:39 DEBUG : : mkdir: created dir in source fs
2025/01/21 03:37:39 DEBUG : : mkdir: added to cache
2025/01/21 03:37:39 DEBUG : : cache: expired tionf1737430659
2025/01/21 03:37:39 INFO  : : mkdir: cache expired
2025/01/21 03:37:39 DEBUG : Cache remote TestInternalCache:tionf1737430659: new object '404'
2025/01/21 03:37:39 DEBUG : 404: find: error: couldn't find object (404)
2025/01/21 03:37:39 DEBUG : find failed: not found in either local or remote fs
2025/01/21 03:37:39 DEBUG : Waiting for deletions to finish
2025/01/21 03:37:39 DEBUG : Cache remote TestInternalCache:tionf1737430659: list ''
2025/01/21 03:37:39 DEBUG : : list: cold listing: 2025-01-20 21:37:39.388091872 +0000 UTC
2025/01/21 03:37:39 DEBUG : : list: read 0 from source
2025/01/21 03:37:39 DEBUG : : list: source entries: []
2025/01/21 03:37:39 DEBUG : : list: cached directories: 0
2025/01/21 03:37:39 DEBUG : : list: cached dir: 'tionf1737430659', cache ts: 2025-01-21 03:37:39.389262152 +0000 UTC m=+0.049078178
2025/01/21 03:37:39 DEBUG : Cache remote TestInternalCache:tionf1737430659: list ''
2025/01/21 03:37:39 DEBUG : : list: empty listing
2025/01/21 03:37:39 DEBUG : : list: read 0 from source
2025/01/21 03:37:39 DEBUG : : list: source entries: []
2025/01/21 03:37:39 DEBUG : : list: cached directories: 0
2025/01/21 03:37:39 DEBUG : : list: cached dir: 'tionf1737430659', cache ts: 2025-01-21 03:37:39.390551845 +0000 UTC m=+0.050367860
2025/01/21 03:37:39 DEBUG : removing 1 level 0 directories
2025/01/21 03:37:39 INFO  : Cache remote TestInternalCache:tionf1737430659: Removing directory
2025/01/21 03:37:39 DEBUG : Cache remote TestInternalCache:tionf1737430659: rmdir ''
2025/01/21 03:37:39 DEBUG : : rmdir: removed dir in source fs
2025/01/21 03:37:39 DEBUG : : rmdir: removed from cache
2025/01/21 03:37:39 INFO  : : rmdir: cache expired
2025/01/21 03:37:39 DEBUG : Cache remote TestInternalCache:tionf1737430659: Services stopped
--- PASS: TestInternalObjNotFound (0.03s)
=== RUN   TestInternalCachedWrittenContentMatches
2025/01/21 03:37:39 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2025/01/21 03:37:39 DEBUG : Creating backend with remote "TestInternalCache-local:/tmp/TestInternalCache-local/ticwcm1737430659"
2025/01/21 03:37:39 DEBUG : TestInternalCache: wrapped TestInternalCache-local:/tmp/TestInternalCache-local/ticwcm1737430659 at root ticwcm1737430659
2025/01/21 03:37:39 INFO  : TestInternalCache: Cache DB path: /home/rclone/.cache/rclone/cache-backend/TestInternalCache.db
2025/01/21 03:37:39 INFO  : TestInternalCache: Cache chunk path: /home/rclone/.cache/rclone/cache-backend/TestInternalCache
2025/01/21 03:37:39 INFO  : TestInternalCache: Chunk Memory: true
2025/01/21 03:37:39 INFO  : TestInternalCache: Chunk Size: 5Mi
2025/01/21 03:37:39 INFO  : TestInternalCache: Chunk Total Size: 10Gi
2025/01/21 03:37:39 INFO  : TestInternalCache: Chunk Clean Interval: 1m0s
2025/01/21 03:37:39 INFO  : TestInternalCache: Workers: 4
2025/01/21 03:37:39 INFO  : TestInternalCache: File Age: 6h0m0s
2025/01/21 03:37:39 DEBUG : Waiting for deletions to finish
2025/01/21 03:37:39 DEBUG : Cache remote TestInternalCache:ticwcm1737430659: list ''
2025/01/21 03:37:39 DEBUG : : list: error: couldn't open bucket (ticwcm1737430659)
2025/01/21 03:37:39 ERROR : : error listing: directory not found
2025/01/21 03:37:39 DEBUG : Cache remote TestInternalCache:ticwcm1737430659: list ''
2025/01/21 03:37:39 DEBUG : : list: error: couldn't open bucket (ticwcm1737430659)
2025/01/21 03:37:39 ERROR : Cache remote TestInternalCache:ticwcm1737430659: Failed to list "": directory not found
2025/01/21 03:37:39 DEBUG : removing 1 level 0 directories
2025/01/21 03:37:39 INFO  : Cache remote TestInternalCache:ticwcm1737430659: Removing directory
2025/01/21 03:37:39 DEBUG : Cache remote TestInternalCache:ticwcm1737430659: rmdir ''
2025/01/21 03:37:39 ERROR : : Failed to rmdir: stat /tmp/TestInternalCache-local/ticwcm1737430659: no such file or directory
2025/01/21 03:37:39 DEBUG : Cache remote TestInternalCache:ticwcm1737430659: mkdir ''
2025/01/21 03:37:39 DEBUG : : mkdir: created dir in source fs
2025/01/21 03:37:39 DEBUG : : mkdir: added to cache
2025/01/21 03:37:39 DEBUG : : cache: expired ticwcm1737430659
2025/01/21 03:37:39 INFO  : : mkdir: cache expired
2025/01/21 03:37:39 DEBUG : Cache remote TestInternalCache:ticwcm1737430659: put data at 'data.bin'
2025/01/21 03:37:39 DEBUG : data.bin: put: uploaded to remote fs
2025/01/21 03:37:39 DEBUG : data.bin: put: added to cache
2025/01/21 03:37:39 DEBUG : : cache: expired ticwcm1737430659
2025/01/21 03:37:39 INFO  : : put: cache expired
2025/01/21 03:37:39 DEBUG : Cache remote TestInternalCache:ticwcm1737430659: new object 'data.bin'
2025/01/21 03:37:39 DEBUG : data.bin: find: warm object: data.bin, expiring on: 2025-01-21 09:37:39.985889385 +0000 UTC
2025/01/21 03:37:39 DEBUG : Cache remote TestInternalCache:ticwcm1737430659: new object 'data.bin'
2025/01/21 03:37:39 DEBUG : data.bin: find: warm object: data.bin, expiring on: 2025-01-21 09:37:39.985889385 +0000 UTC
2025/01/21 03:37:39 DEBUG : ticwcm1737430659/data.bin: moving offset set from 0 to 2621440
2025/01/21 03:37:39 DEBUG : ticwcm1737430659/data.bin: 0: chunk retry storage: 0
2025/01/21 03:37:39 DEBUG : worker-3 <data.bin>: downloaded chunk 15728640
2025/01/21 03:37:39 DEBUG : worker-0 <data.bin>: downloaded chunk 0
2025/01/21 03:37:40 DEBUG : worker-2 <data.bin>: downloaded chunk 5242880
2025/01/21 03:37:40 DEBUG : worker-1 <data.bin>: downloaded chunk 10485760
2025/01/21 03:37:40 DEBUG : ticwcm1737430659/data.bin: cache reader closed 5242880
2025/01/21 03:37:40 DEBUG : Waiting for deletions to finish
2025/01/21 03:37:40 DEBUG : Cache remote TestInternalCache:ticwcm1737430659: list ''
2025/01/21 03:37:40 DEBUG : : list: cold listing: 2025-01-20 21:37:39.988519066 +0000 UTC
2025/01/21 03:37:40 DEBUG : : list: read 1 from source
2025/01/21 03:37:40 DEBUG : : list: source entries: [data.bin]
2025/01/21 03:37:40 DEBUG : : list: cached object: data.bin
2025/01/21 03:37:40 DEBUG : : list: cached directories: 0
2025/01/21 03:37:40 DEBUG : : list: cached dir: 'ticwcm1737430659', cache ts: 2025-01-21 03:37:40.505463318 +0000 UTC m=+1.165279335
2025/01/21 03:37:40 DEBUG : data.bin: removing object
2025/01/21 03:37:40 DEBUG : : cache: expired ticwcm1737430659
2025/01/21 03:37:40 INFO  : data.bin: Deleted
2025/01/21 03:37:40 DEBUG : Cache remote TestInternalCache:ticwcm1737430659: list ''
2025/01/21 03:37:40 DEBUG : : list: cold listing: 2025-01-20 21:37:40.513827989 +0000 UTC
2025/01/21 03:37:40 DEBUG : : list: read 0 from source
2025/01/21 03:37:40 DEBUG : : list: source entries: []
2025/01/21 03:37:40 DEBUG : : list: cached directories: 0
2025/01/21 03:37:40 DEBUG : : list: cached dir: 'ticwcm1737430659', cache ts: 2025-01-21 03:37:40.515086423 +0000 UTC m=+1.174902439
2025/01/21 03:37:40 DEBUG : removing 1 level 0 directories
2025/01/21 03:37:40 INFO  : Cache remote TestInternalCache:ticwcm1737430659: Removing directory
2025/01/21 03:37:40 DEBUG : Cache remote TestInternalCache:ticwcm1737430659: rmdir ''
2025/01/21 03:37:40 DEBUG : : rmdir: removed dir in source fs
2025/01/21 03:37:40 DEBUG : : rmdir: removed from cache
2025/01/21 03:37:40 INFO  : : rmdir: cache expired
2025/01/21 03:37:40 DEBUG : Cache remote TestInternalCache:ticwcm1737430659: Services stopped
--- PASS: TestInternalCachedWrittenContentMatches (1.13s)
=== RUN   TestInternalDoubleWrittenContentMatches
2025/01/21 03:37:40 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2025/01/21 03:37:40 DEBUG : Creating backend with remote "TestInternalCache-local:/tmp/TestInternalCache-local/tidwcm1737430660"
2025/01/21 03:37:40 DEBUG : TestInternalCache: wrapped TestInternalCache-local:/tmp/TestInternalCache-local/tidwcm1737430660 at root tidwcm1737430660
2025/01/21 03:37:40 INFO  : TestInternalCache: Cache DB path: /home/rclone/.cache/rclone/cache-backend/TestInternalCache.db
2025/01/21 03:37:40 INFO  : TestInternalCache: Cache chunk path: /home/rclone/.cache/rclone/cache-backend/TestInternalCache
2025/01/21 03:37:40 INFO  : TestInternalCache: Chunk Memory: true
2025/01/21 03:37:40 INFO  : TestInternalCache: Chunk Size: 5Mi
2025/01/21 03:37:40 INFO  : TestInternalCache: Chunk Total Size: 10Gi
2025/01/21 03:37:40 INFO  : TestInternalCache: Chunk Clean Interval: 1m0s
2025/01/21 03:37:40 INFO  : TestInternalCache: Workers: 4
2025/01/21 03:37:40 INFO  : TestInternalCache: File Age: 6h0m0s
2025/01/21 03:37:40 DEBUG : Waiting for deletions to finish
2025/01/21 03:37:40 DEBUG : Cache remote TestInternalCache:tidwcm1737430660: list ''
2025/01/21 03:37:40 DEBUG : : list: error: couldn't open bucket (tidwcm1737430660)
2025/01/21 03:37:40 ERROR : : error listing: directory not found
2025/01/21 03:37:40 DEBUG : Cache remote TestInternalCache:tidwcm1737430660: list ''
2025/01/21 03:37:40 DEBUG : : list: error: couldn't open bucket (tidwcm1737430660)
2025/01/21 03:37:40 ERROR : Cache remote TestInternalCache:tidwcm1737430660: Failed to list "": directory not found
2025/01/21 03:37:40 DEBUG : removing 1 level 0 directories
2025/01/21 03:37:40 INFO  : Cache remote TestInternalCache:tidwcm1737430660: Removing directory
2025/01/21 03:37:40 DEBUG : Cache remote TestInternalCache:tidwcm1737430660: rmdir ''
2025/01/21 03:37:40 ERROR : : Failed to rmdir: stat /tmp/TestInternalCache-local/tidwcm1737430660: no such file or directory
2025/01/21 03:37:40 DEBUG : Cache remote TestInternalCache:tidwcm1737430660: mkdir ''
2025/01/21 03:37:40 DEBUG : : mkdir: created dir in source fs
2025/01/21 03:37:40 DEBUG : : mkdir: added to cache
2025/01/21 03:37:40 DEBUG : : cache: expired tidwcm1737430660
2025/01/21 03:37:40 INFO  : : mkdir: cache expired
2025/01/21 03:37:40 DEBUG : Cache remote TestInternalCache:tidwcm1737430660: put data at 'one'
2025/01/21 03:37:40 DEBUG : one: put: uploaded to remote fs
2025/01/21 03:37:40 DEBUG : one: put: added to cache
2025/01/21 03:37:40 DEBUG : : cache: expired tidwcm1737430660
2025/01/21 03:37:40 INFO  : : put: cache expired
2025/01/21 03:37:40 DEBUG : Cache remote TestInternalCache:tidwcm1737430660: new object 'one'
2025/01/21 03:37:40 DEBUG : one: find: warm object: one, expiring on: 2025-01-21 09:37:40.544865181 +0000 UTC
2025/01/21 03:37:40 DEBUG : Cache remote TestInternalCache:tidwcm1737430660: new object 'one'
2025/01/21 03:37:40 DEBUG : one: find: warm object: one, expiring on: 2025-01-21 09:37:40.544865181 +0000 UTC
2025/01/21 03:37:40 DEBUG : one: updating object contents with size 19
2025/01/21 03:37:40 DEBUG : Cache remote TestInternalCache:tidwcm1737430660: new object 'one'
2025/01/21 03:37:40 DEBUG : one: find: warm object: one, expiring on: 2025-01-21 09:37:40.553543648 +0000 UTC
2025/01/21 03:37:40 DEBUG : one: updating object contents with size 26
2025/01/21 03:37:40 DEBUG : Cache remote TestInternalCache:tidwcm1737430660: new object 'one'
2025/01/21 03:37:40 DEBUG : one: find: warm object: one, expiring on: 2025-01-21 09:37:40.556883047 +0000 UTC
2025/01/21 03:37:40 DEBUG : tidwcm1737430660/one: moving offset set from 0 to 0
2025/01/21 03:37:40 DEBUG : tidwcm1737430660/one: 0: chunk retry storage: 0
2025/01/21 03:37:40 DEBUG : worker-0 <one>: partial downloaded chunk 0
2025/01/21 03:37:41 DEBUG : tidwcm1737430660/one: cache reader closed 26
2025/01/21 03:37:41 DEBUG : Waiting for deletions to finish
2025/01/21 03:37:41 DEBUG : Cache remote TestInternalCache:tidwcm1737430660: list ''
2025/01/21 03:37:41 DEBUG : : list: cold listing: 2025-01-20 21:37:40.550334895 +0000 UTC
2025/01/21 03:37:41 DEBUG : : list: read 1 from source
2025/01/21 03:37:41 DEBUG : : list: source entries: [one]
2025/01/21 03:37:41 DEBUG : : list: cached object: one
2025/01/21 03:37:41 DEBUG : : list: cached directories: 0
2025/01/21 03:37:41 DEBUG : : list: cached dir: 'tidwcm1737430660', cache ts: 2025-01-21 03:37:41.061619589 +0000 UTC m=+1.721435625
2025/01/21 03:37:41 DEBUG : one: removing object
2025/01/21 03:37:41 DEBUG : : cache: expired tidwcm1737430660
2025/01/21 03:37:41 INFO  : one: Deleted
2025/01/21 03:37:41 DEBUG : Cache remote TestInternalCache:tidwcm1737430660: list ''
2025/01/21 03:37:41 DEBUG : : list: cold listing: 2025-01-20 21:37:41.067124138 +0000 UTC
2025/01/21 03:37:41 DEBUG : : list: read 0 from source
2025/01/21 03:37:41 DEBUG : : list: source entries: []
2025/01/21 03:37:41 DEBUG : : list: cached directories: 0
2025/01/21 03:37:41 DEBUG : : list: cached dir: 'tidwcm1737430660', cache ts: 2025-01-21 03:37:41.069581956 +0000 UTC m=+1.729397992
2025/01/21 03:37:41 DEBUG : removing 1 level 0 directories
2025/01/21 03:37:41 INFO  : Cache remote TestInternalCache:tidwcm1737430660: Removing directory
2025/01/21 03:37:41 DEBUG : Cache remote TestInternalCache:tidwcm1737430660: rmdir ''
2025/01/21 03:37:41 DEBUG : : rmdir: removed dir in source fs
2025/01/21 03:37:41 DEBUG : : rmdir: removed from cache
2025/01/21 03:37:41 INFO  : : rmdir: cache expired
2025/01/21 03:37:41 DEBUG : Cache remote TestInternalCache:tidwcm1737430660: Services stopped
--- PASS: TestInternalDoubleWrittenContentMatches (0.55s)
=== RUN   TestInternalCachedUpdatedContentMatches
2025/01/21 03:37:41 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2025/01/21 03:37:41 DEBUG : Creating backend with remote "TestInternalCache-local:/tmp/TestInternalCache-local/ticucm1737430661"
2025/01/21 03:37:41 DEBUG : TestInternalCache: wrapped TestInternalCache-local:/tmp/TestInternalCache-local/ticucm1737430661 at root ticucm1737430661
2025/01/21 03:37:41 INFO  : TestInternalCache: Cache DB path: /home/rclone/.cache/rclone/cache-backend/TestInternalCache.db
2025/01/21 03:37:41 INFO  : TestInternalCache: Cache chunk path: /home/rclone/.cache/rclone/cache-backend/TestInternalCache
2025/01/21 03:37:41 INFO  : TestInternalCache: Chunk Memory: true
2025/01/21 03:37:41 INFO  : TestInternalCache: Chunk Size: 5Mi
2025/01/21 03:37:41 INFO  : TestInternalCache: Chunk Total Size: 10Gi
2025/01/21 03:37:41 INFO  : TestInternalCache: Chunk Clean Interval: 1m0s
2025/01/21 03:37:41 INFO  : TestInternalCache: Workers: 4
2025/01/21 03:37:41 INFO  : TestInternalCache: File Age: 6h0m0s
2025/01/21 03:37:41 DEBUG : Waiting for deletions to finish
2025/01/21 03:37:41 DEBUG : Cache remote TestInternalCache:ticucm1737430661: list ''
2025/01/21 03:37:41 DEBUG : : list: error: couldn't open bucket (ticucm1737430661)
2025/01/21 03:37:41 ERROR : : error listing: directory not found
2025/01/21 03:37:41 DEBUG : Cache remote TestInternalCache:ticucm1737430661: list ''
2025/01/21 03:37:41 DEBUG : : list: error: couldn't open bucket (ticucm1737430661)
2025/01/21 03:37:41 ERROR : Cache remote TestInternalCache:ticucm1737430661: Failed to list "": directory not found
2025/01/21 03:37:41 DEBUG : removing 1 level 0 directories
2025/01/21 03:37:41 INFO  : Cache remote TestInternalCache:ticucm1737430661: Removing directory
2025/01/21 03:37:41 DEBUG : Cache remote TestInternalCache:ticucm1737430661: rmdir ''
2025/01/21 03:37:41 ERROR : : Failed to rmdir: stat /tmp/TestInternalCache-local/ticucm1737430661: no such file or directory
2025/01/21 03:37:41 DEBUG : Cache remote TestInternalCache:ticucm1737430661: mkdir ''
2025/01/21 03:37:41 DEBUG : : mkdir: created dir in source fs
2025/01/21 03:37:41 DEBUG : : mkdir: added to cache
2025/01/21 03:37:41 DEBUG : : cache: expired ticucm1737430661
2025/01/21 03:37:41 INFO  : : mkdir: cache expired
2025/01/21 03:37:41 DEBUG : Cache remote TestInternalCache:ticucm1737430661: put data at 'data.bin'
2025/01/21 03:37:41 DEBUG : data.bin: put: uploaded to remote fs
2025/01/21 03:37:41 DEBUG : data.bin: put: added to cache
2025/01/21 03:37:41 DEBUG : : cache: expired ticucm1737430661
2025/01/21 03:37:41 INFO  : : put: cache expired
2025/01/21 03:37:41 DEBUG : Cache remote TestInternalCache:ticucm1737430661: new object 'data.bin'
2025/01/21 03:37:41 DEBUG : data.bin: find: warm object: data.bin, expiring on: 2025-01-21 09:37:41.092406432 +0000 UTC
2025/01/21 03:37:41 DEBUG : data.bin: updating object contents with size 200
2025/01/21 03:37:41 DEBUG : Cache remote TestInternalCache:ticucm1737430661: new object 'data.bin'
2025/01/21 03:37:41 DEBUG : data.bin: find: warm object: data.bin, expiring on: 2025-01-21 09:37:41.099585003 +0000 UTC
2025/01/21 03:37:41 DEBUG : ticucm1737430661/data.bin: moving offset set from 0 to 0
2025/01/21 03:37:41 DEBUG : ticucm1737430661/data.bin: 0: chunk retry storage: 0
2025/01/21 03:37:41 DEBUG : worker-0 <data.bin>: partial downloaded chunk 0
2025/01/21 03:37:41 DEBUG : ticucm1737430661/data.bin: cache reader closed 200
2025/01/21 03:37:41 DEBUG : Waiting for deletions to finish
2025/01/21 03:37:41 DEBUG : Cache remote TestInternalCache:ticucm1737430661: list ''
2025/01/21 03:37:41 DEBUG : : list: cold listing: 2025-01-20 21:37:41.095104289 +0000 UTC
2025/01/21 03:37:41 DEBUG : : list: read 1 from source
2025/01/21 03:37:41 DEBUG : : list: source entries: [data.bin]
2025/01/21 03:37:41 DEBUG : : list: cached object: data.bin
2025/01/21 03:37:41 DEBUG : : list: cached directories: 0
2025/01/21 03:37:41 DEBUG : : list: cached dir: 'ticucm1737430661', cache ts: 2025-01-21 03:37:41.604748593 +0000 UTC m=+2.264564649
2025/01/21 03:37:41 DEBUG : data.bin: removing object
2025/01/21 03:37:41 DEBUG : : cache: expired ticucm1737430661
2025/01/21 03:37:41 INFO  : data.bin: Deleted
2025/01/21 03:37:41 DEBUG : Cache remote TestInternalCache:ticucm1737430661: list ''
2025/01/21 03:37:41 DEBUG : : list: cold listing: 2025-01-20 21:37:41.610283981 +0000 UTC
2025/01/21 03:37:41 DEBUG : : list: read 0 from source
2025/01/21 03:37:41 DEBUG : : list: source entries: []
2025/01/21 03:37:41 DEBUG : : list: cached directories: 0
2025/01/21 03:37:41 DEBUG : : list: cached dir: 'ticucm1737430661', cache ts: 2025-01-21 03:37:41.612199434 +0000 UTC m=+2.272015480
2025/01/21 03:37:41 DEBUG : removing 1 level 0 directories
2025/01/21 03:37:41 INFO  : Cache remote TestInternalCache:ticucm1737430661: Removing directory
2025/01/21 03:37:41 DEBUG : Cache remote TestInternalCache:ticucm1737430661: rmdir ''
2025/01/21 03:37:41 DEBUG : : rmdir: removed dir in source fs
2025/01/21 03:37:41 DEBUG : : rmdir: removed from cache
2025/01/21 03:37:41 INFO  : : rmdir: cache expired
2025/01/21 03:37:41 DEBUG : Cache remote TestInternalCache:ticucm1737430661: Services stopped
--- PASS: TestInternalCachedUpdatedContentMatches (0.56s)
=== RUN   TestInternalWrappedWrittenContentMatches
2025/01/21 03:37:41 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/01/21 03:37:41 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/01/21 03:37:41 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2025/01/21 03:37:41 DEBUG : Creating backend with remote "TestInternalCache-local:/tmp/TestInternalCache-local/tiwfcns1737430661"
2025/01/21 03:37:41 DEBUG : TestInternalCache: wrapped TestInternalCache-local:/tmp/TestInternalCache-local/tiwfcns1737430661 at root tiwfcns1737430661
2025/01/21 03:37:41 INFO  : TestInternalCache: Cache DB path: /home/rclone/.cache/rclone/cache-backend/TestInternalCache.db
2025/01/21 03:37:41 INFO  : TestInternalCache: Cache chunk path: /home/rclone/.cache/rclone/cache-backend/TestInternalCache
2025/01/21 03:37:41 INFO  : TestInternalCache: Chunk Memory: true
2025/01/21 03:37:41 INFO  : TestInternalCache: Chunk Size: 5Mi
2025/01/21 03:37:41 INFO  : TestInternalCache: Chunk Total Size: 10Gi
2025/01/21 03:37:41 INFO  : TestInternalCache: Chunk Clean Interval: 1m0s
2025/01/21 03:37:41 INFO  : TestInternalCache: Workers: 4
2025/01/21 03:37:41 INFO  : TestInternalCache: File Age: 6h0m0s
2025/01/21 03:37:41 DEBUG : Waiting for deletions to finish
2025/01/21 03:37:41 DEBUG : Cache remote TestInternalCache:tiwfcns1737430661: list ''
2025/01/21 03:37:41 DEBUG : : list: error: couldn't open bucket (tiwfcns1737430661)
2025/01/21 03:37:41 ERROR : : error listing: directory not found
2025/01/21 03:37:41 DEBUG : Cache remote TestInternalCache:tiwfcns1737430661: list ''
2025/01/21 03:37:41 DEBUG : : list: error: couldn't open bucket (tiwfcns1737430661)
2025/01/21 03:37:41 ERROR : Cache remote TestInternalCache:tiwfcns1737430661: Failed to list "": directory not found
2025/01/21 03:37:41 DEBUG : removing 1 level 0 directories
2025/01/21 03:37:41 INFO  : Cache remote TestInternalCache:tiwfcns1737430661: Removing directory
2025/01/21 03:37:41 DEBUG : Cache remote TestInternalCache:tiwfcns1737430661: rmdir ''
2025/01/21 03:37:41 ERROR : : Failed to rmdir: stat /tmp/TestInternalCache-local/tiwfcns1737430661: no such file or directory
2025/01/21 03:37:41 DEBUG : Cache remote TestInternalCache:tiwfcns1737430661: mkdir ''
2025/01/21 03:37:41 DEBUG : : mkdir: created dir in source fs
2025/01/21 03:37:41 DEBUG : : mkdir: added to cache
2025/01/21 03:37:41 DEBUG : : cache: expired tiwfcns1737430661
2025/01/21 03:37:41 INFO  : : mkdir: cache expired
2025/01/21 03:37:42 DEBUG : Cache remote TestInternalCache:tiwfcns1737430661: put data at 'data.bin'
2025/01/21 03:37:42 DEBUG : data.bin: put: uploaded to remote fs
2025/01/21 03:37:42 DEBUG : data.bin: put: added to cache
2025/01/21 03:37:42 DEBUG : : cache: expired tiwfcns1737430661
2025/01/21 03:37:42 INFO  : : put: cache expired
2025/01/21 03:37:42 DEBUG : Cache remote TestInternalCache:tiwfcns1737430661: new object 'data.bin'
2025/01/21 03:37:42 DEBUG : data.bin: find: warm object: data.bin, expiring on: 2025-01-21 09:37:42.225888871 +0000 UTC
2025/01/21 03:37:42 DEBUG : Cache remote TestInternalCache:tiwfcns1737430661: new object 'data.bin'
2025/01/21 03:37:42 DEBUG : data.bin: find: warm object: data.bin, expiring on: 2025-01-21 09:37:42.225888871 +0000 UTC
2025/01/21 03:37:42 NOTICE: original size: 23592960
2025/01/21 03:37:42 NOTICE: updated size: 12
2025/01/21 03:37:42 DEBUG : Cache remote TestInternalCache:tiwfcns1737430661: new object 'data.bin'
2025/01/21 03:37:42 DEBUG : data.bin: find: warm object: data.bin, expiring on: 2025-01-21 09:37:42.225888871 +0000 UTC
2025/01/21 03:37:42 DEBUG : Waiting for deletions to finish
2025/01/21 03:37:42 DEBUG : Cache remote TestInternalCache:tiwfcns1737430661: list ''
2025/01/21 03:37:42 DEBUG : : list: cold listing: 2025-01-20 21:37:42.229344025 +0000 UTC
2025/01/21 03:37:42 DEBUG : : list: read 1 from source
2025/01/21 03:37:42 DEBUG : : list: source entries: [data.bin]
2025/01/21 03:37:42 DEBUG : : list: cached object: data.bin
2025/01/21 03:37:42 DEBUG : : list: cached directories: 0
2025/01/21 03:37:42 DEBUG : : list: cached dir: 'tiwfcns1737430661', cache ts: 2025-01-21 03:37:42.236922897 +0000 UTC m=+2.896738913
2025/01/21 03:37:42 DEBUG : data.bin: removing object
2025/01/21 03:37:42 DEBUG : : cache: expired tiwfcns1737430661
2025/01/21 03:37:42 INFO  : data.bin: Deleted
2025/01/21 03:37:42 DEBUG : Cache remote TestInternalCache:tiwfcns1737430661: list ''
2025/01/21 03:37:42 DEBUG : : list: cold listing: 2025-01-20 21:37:42.241305907 +0000 UTC
2025/01/21 03:37:42 DEBUG : : list: read 0 from source
2025/01/21 03:37:42 DEBUG : : list: source entries: []
2025/01/21 03:37:42 DEBUG : : list: cached directories: 0
2025/01/21 03:37:42 DEBUG : : list: cached dir: 'tiwfcns1737430661', cache ts: 2025-01-21 03:37:42.242666813 +0000 UTC m=+2.902482830
2025/01/21 03:37:42 DEBUG : removing 1 level 0 directories
2025/01/21 03:37:42 INFO  : Cache remote TestInternalCache:tiwfcns1737430661: Removing directory
2025/01/21 03:37:42 DEBUG : Cache remote TestInternalCache:tiwfcns1737430661: rmdir ''
2025/01/21 03:37:42 DEBUG : : rmdir: removed dir in source fs
2025/01/21 03:37:42 DEBUG : : rmdir: removed from cache
2025/01/21 03:37:42 INFO  : : rmdir: cache expired
2025/01/21 03:37:42 DEBUG : Cache remote TestInternalCache:tiwfcns1737430661: Services stopped
--- PASS: TestInternalWrappedFsChangeNotSeen (0.62s)
=== RUN   TestInternalMoveWithNotify
2025/01/21 03:37:42 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2025/01/21 03:37:42 DEBUG : Creating backend with remote "TestInternalCache-local:/tmp/TestInternalCache-local/timwn1737430662"
2025/01/21 03:37:42 DEBUG : TestInternalCache: wrapped TestInternalCache-local:/tmp/TestInternalCache-local/timwn1737430662 at root timwn1737430662
2025/01/21 03:37:42 INFO  : TestInternalCache: Cache DB path: /home/rclone/.cache/rclone/cache-backend/TestInternalCache.db
2025/01/21 03:37:42 INFO  : TestInternalCache: Cache chunk path: /home/rclone/.cache/rclone/cache-backend/TestInternalCache
2025/01/21 03:37:42 INFO  : TestInternalCache: Chunk Memory: true
2025/01/21 03:37:42 INFO  : TestInternalCache: Chunk Size: 5Mi
2025/01/21 03:37:42 INFO  : TestInternalCache: Chunk Total Size: 10Gi
2025/01/21 03:37:42 INFO  : TestInternalCache: Chunk Clean Interval: 1m0s
2025/01/21 03:37:42 INFO  : TestInternalCache: Workers: 4
2025/01/21 03:37:42 INFO  : TestInternalCache: File Age: 6h0m0s
2025/01/21 03:37:42 DEBUG : Waiting for deletions to finish
2025/01/21 03:37:42 DEBUG : Cache remote TestInternalCache:timwn1737430662: list ''
2025/01/21 03:37:42 DEBUG : : list: error: couldn't open bucket (timwn1737430662)
2025/01/21 03:37:42 ERROR : : error listing: directory not found
2025/01/21 03:37:42 DEBUG : Cache remote TestInternalCache:timwn1737430662: list ''
2025/01/21 03:37:42 DEBUG : : list: error: couldn't open bucket (timwn1737430662)
2025/01/21 03:37:42 ERROR : Cache remote TestInternalCache:timwn1737430662: Failed to list "": directory not found
2025/01/21 03:37:42 DEBUG : removing 1 level 0 directories
2025/01/21 03:37:42 INFO  : Cache remote TestInternalCache:timwn1737430662: Removing directory
2025/01/21 03:37:42 DEBUG : Cache remote TestInternalCache:timwn1737430662: rmdir ''
2025/01/21 03:37:42 ERROR : : Failed to rmdir: stat /tmp/TestInternalCache-local/timwn1737430662: no such file or directory
2025/01/21 03:37:42 DEBUG : Cache remote TestInternalCache:timwn1737430662: mkdir ''
2025/01/21 03:37:42 DEBUG : : mkdir: created dir in source fs
2025/01/21 03:37:42 DEBUG : : mkdir: added to cache
2025/01/21 03:37:42 DEBUG : : cache: expired timwn1737430662
2025/01/21 03:37:42 INFO  : : mkdir: cache expired
    cache_internal_test.go:453: Not external
2025/01/21 03:37:42 DEBUG : Waiting for deletions to finish
2025/01/21 03:37:42 DEBUG : Cache remote TestInternalCache:timwn1737430662: list ''
2025/01/21 03:37:42 DEBUG : : list: cold listing: 2025-01-20 21:37:42.270232169 +0000 UTC
2025/01/21 03:37:42 DEBUG : : list: read 0 from source
2025/01/21 03:37:42 DEBUG : : list: source entries: []
2025/01/21 03:37:42 DEBUG : : list: cached directories: 0
2025/01/21 03:37:42 DEBUG : : list: cached dir: 'timwn1737430662', cache ts: 2025-01-21 03:37:42.272591353 +0000 UTC m=+2.932407369
2025/01/21 03:37:42 DEBUG : Cache remote TestInternalCache:timwn1737430662: list ''
2025/01/21 03:37:42 DEBUG : : list: empty listing
2025/01/21 03:37:42 DEBUG : : list: read 0 from source
2025/01/21 03:37:42 DEBUG : : list: source entries: []
2025/01/21 03:37:42 DEBUG : : list: cached directories: 0
2025/01/21 03:37:42 DEBUG : : list: cached dir: 'timwn1737430662', cache ts: 2025-01-21 03:37:42.275812711 +0000 UTC m=+2.935628737
2025/01/21 03:37:42 DEBUG : removing 1 level 0 directories
2025/01/21 03:37:42 INFO  : Cache remote TestInternalCache:timwn1737430662: Removing directory
2025/01/21 03:37:42 DEBUG : Cache remote TestInternalCache:timwn1737430662: rmdir ''
2025/01/21 03:37:42 DEBUG : : rmdir: removed dir in source fs
2025/01/21 03:37:42 DEBUG : : rmdir: removed from cache
2025/01/21 03:37:42 INFO  : : rmdir: cache expired
2025/01/21 03:37:42 DEBUG : Cache remote TestInternalCache:timwn1737430662: Services stopped
--- SKIP: TestInternalMoveWithNotify (0.03s)
=== RUN   TestInternalNotifyCreatesEmptyParts
2025/01/21 03:37:42 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2025/01/21 03:37:42 DEBUG : Creating backend with remote "TestInternalCache-local:/tmp/TestInternalCache-local/tincep1737430662"
2025/01/21 03:37:42 DEBUG : TestInternalCache: wrapped TestInternalCache-local:/tmp/TestInternalCache-local/tincep1737430662 at root tincep1737430662
2025/01/21 03:37:42 INFO  : TestInternalCache: Cache DB path: /home/rclone/.cache/rclone/cache-backend/TestInternalCache.db
2025/01/21 03:37:42 INFO  : TestInternalCache: Cache chunk path: /home/rclone/.cache/rclone/cache-backend/TestInternalCache
2025/01/21 03:37:42 INFO  : TestInternalCache: Chunk Memory: true
2025/01/21 03:37:42 INFO  : TestInternalCache: Chunk Size: 5Mi
2025/01/21 03:37:42 INFO  : TestInternalCache: Chunk Total Size: 10Gi
2025/01/21 03:37:42 INFO  : TestInternalCache: Chunk Clean Interval: 1m0s
2025/01/21 03:37:42 INFO  : TestInternalCache: Workers: 4
2025/01/21 03:37:42 INFO  : TestInternalCache: File Age: 6h0m0s
2025/01/21 03:37:42 DEBUG : Waiting for deletions to finish
2025/01/21 03:37:42 DEBUG : Cache remote TestInternalCache:tincep1737430662: list ''
2025/01/21 03:37:42 DEBUG : : list: error: couldn't open bucket (tincep1737430662)
2025/01/21 03:37:42 ERROR : : error listing: directory not found
2025/01/21 03:37:42 DEBUG : Cache remote TestInternalCache:tincep1737430662: list ''
2025/01/21 03:37:42 DEBUG : : list: error: couldn't open bucket (tincep1737430662)
2025/01/21 03:37:42 ERROR : Cache remote TestInternalCache:tincep1737430662: Failed to list "": directory not found
2025/01/21 03:37:42 DEBUG : removing 1 level 0 directories
2025/01/21 03:37:42 INFO  : Cache remote TestInternalCache:tincep1737430662: Removing directory
2025/01/21 03:37:42 DEBUG : Cache remote TestInternalCache:tincep1737430662: rmdir ''
2025/01/21 03:37:42 ERROR : : Failed to rmdir: stat /tmp/TestInternalCache-local/tincep1737430662: no such file or directory
2025/01/21 03:37:42 DEBUG : Cache remote TestInternalCache:tincep1737430662: mkdir ''
2025/01/21 03:37:42 DEBUG : : mkdir: created dir in source fs
2025/01/21 03:37:42 DEBUG : : mkdir: added to cache
2025/01/21 03:37:42 DEBUG : : cache: expired tincep1737430662
2025/01/21 03:37:42 INFO  : : mkdir: cache expired
    cache_internal_test.go:539: Not external
2025/01/21 03:37:42 DEBUG : Waiting for deletions to finish
2025/01/21 03:37:42 DEBUG : Cache remote TestInternalCache:tincep1737430662: list ''
2025/01/21 03:37:42 DEBUG : : list: cold listing: 2025-01-20 21:37:42.297671169 +0000 UTC
2025/01/21 03:37:42 DEBUG : : list: read 0 from source
2025/01/21 03:37:42 DEBUG : : list: source entries: []
2025/01/21 03:37:42 DEBUG : : list: cached directories: 0
2025/01/21 03:37:42 DEBUG : : list: cached dir: 'tincep1737430662', cache ts: 2025-01-21 03:37:42.30013596 +0000 UTC m=+2.959951966
2025/01/21 03:37:42 DEBUG : Cache remote TestInternalCache:tincep1737430662: list ''
2025/01/21 03:37:42 DEBUG : : list: empty listing
2025/01/21 03:37:42 DEBUG : : list: read 0 from source
2025/01/21 03:37:42 DEBUG : : list: source entries: []
2025/01/21 03:37:42 DEBUG : : list: cached directories: 0
2025/01/21 03:37:42 DEBUG : : list: cached dir: 'tincep1737430662', cache ts: 2025-01-21 03:37:42.301929396 +0000 UTC m=+2.961745412
2025/01/21 03:37:42 DEBUG : removing 1 level 0 directories
2025/01/21 03:37:42 INFO  : Cache remote TestInternalCache:tincep1737430662: Removing directory
2025/01/21 03:37:42 DEBUG : Cache remote TestInternalCache:tincep1737430662: rmdir ''
2025/01/21 03:37:42 DEBUG : : rmdir: removed dir in source fs
2025/01/21 03:37:42 DEBUG : : rmdir: removed from cache
2025/01/21 03:37:42 INFO  : : rmdir: cache expired
2025/01/21 03:37:42 DEBUG : Cache remote TestInternalCache:tincep1737430662: Services stopped
--- SKIP: TestInternalNotifyCreatesEmptyParts (0.03s)
=== RUN   TestInternalChangeSeenAfterDirCacheFlush
2025/01/21 03:37:42 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2025/01/21 03:37:42 DEBUG : Creating backend with remote "TestInternalCache-local:/tmp/TestInternalCache-local/ticsadcf1737430662"
2025/01/21 03:37:42 DEBUG : TestInternalCache: wrapped TestInternalCache-local:/tmp/TestInternalCache-local/ticsadcf1737430662 at root ticsadcf1737430662
2025/01/21 03:37:42 INFO  : TestInternalCache: Cache DB path: /home/rclone/.cache/rclone/cache-backend/TestInternalCache.db
2025/01/21 03:37:42 INFO  : TestInternalCache: Cache chunk path: /home/rclone/.cache/rclone/cache-backend/TestInternalCache
2025/01/21 03:37:42 INFO  : TestInternalCache: Chunk Memory: true
2025/01/21 03:37:42 INFO  : TestInternalCache: Chunk Size: 5Mi
2025/01/21 03:37:42 INFO  : TestInternalCache: Chunk Total Size: 10Gi
2025/01/21 03:37:42 INFO  : TestInternalCache: Chunk Clean Interval: 1m0s
2025/01/21 03:37:42 INFO  : TestInternalCache: Workers: 4
2025/01/21 03:37:42 INFO  : TestInternalCache: File Age: 6h0m0s
2025/01/21 03:37:42 DEBUG : Waiting for deletions to finish
2025/01/21 03:37:42 DEBUG : Cache remote TestInternalCache:ticsadcf1737430662: list ''
2025/01/21 03:37:42 DEBUG : : list: error: couldn't open bucket (ticsadcf1737430662)
2025/01/21 03:37:42 ERROR : : error listing: directory not found
2025/01/21 03:37:42 DEBUG : Cache remote TestInternalCache:ticsadcf1737430662: list ''
2025/01/21 03:37:42 DEBUG : : list: error: couldn't open bucket (ticsadcf1737430662)
2025/01/21 03:37:42 ERROR : Cache remote TestInternalCache:ticsadcf1737430662: Failed to list "": directory not found
2025/01/21 03:37:42 DEBUG : removing 1 level 0 directories
2025/01/21 03:37:42 INFO  : Cache remote TestInternalCache:ticsadcf1737430662: Removing directory
2025/01/21 03:37:42 DEBUG : Cache remote TestInternalCache:ticsadcf1737430662: rmdir ''
2025/01/21 03:37:42 ERROR : : Failed to rmdir: stat /tmp/TestInternalCache-local/ticsadcf1737430662: no such file or directory
2025/01/21 03:37:42 DEBUG : Cache remote TestInternalCache:ticsadcf1737430662: mkdir ''
2025/01/21 03:37:42 DEBUG : : mkdir: created dir in source fs
2025/01/21 03:37:42 DEBUG : : mkdir: added to cache
2025/01/21 03:37:42 DEBUG : : cache: expired ticsadcf1737430662
2025/01/21 03:37:42 INFO  : : mkdir: cache expired
2025/01/21 03:37:42 DEBUG : Cache remote TestInternalCache:ticsadcf1737430662: put data at 'data.bin'
2025/01/21 03:37:42 DEBUG : data.bin: put: uploaded to remote fs
2025/01/21 03:37:42 DEBUG : data.bin: put: added to cache
2025/01/21 03:37:42 DEBUG : : cache: expired ticsadcf1737430662
2025/01/21 03:37:42 INFO  : : put: cache expired
2025/01/21 03:37:42 DEBUG : Cache remote TestInternalCache:ticsadcf1737430662: new object 'data.bin'
2025/01/21 03:37:42 DEBUG : data.bin: find: warm object: data.bin, expiring on: 2025-01-21 09:37:42.885013018 +0000 UTC
2025/01/21 03:37:42 DEBUG : Cache remote TestInternalCache:ticsadcf1737430662: new object 'data.bin'
2025/01/21 03:37:42 DEBUG : data.bin: find: warm object: data.bin, expiring on: 2025-01-21 09:37:42.885013018 +0000 UTC
2025/01/21 03:37:42 DEBUG : Cache remote TestInternalCache:ticsadcf1737430662: new object 'data.bin'
2025/01/21 03:37:42 DEBUG : data.bin: find: error: couldn't open parent bucket for ticsadcf1737430662
2025/01/21 03:37:42 DEBUG : data.bin: find: cached object
2025/01/21 03:37:42 DEBUG : Cache remote TestInternalCache:ticsadcf1737430662: list ''
2025/01/21 03:37:42 DEBUG : : list: error: missing cached dir: 
2025/01/21 03:37:42 DEBUG : : list: read 1 from source
2025/01/21 03:37:42 DEBUG : : list: source entries: [data.bin]
2025/01/21 03:37:42 DEBUG : Waiting for deletions to finish
2025/01/21 03:37:42 DEBUG : : list: cached object: data.bin
2025/01/21 03:37:42 DEBUG : : list: cached directories: 0
2025/01/21 03:37:42 DEBUG : : list: cached dir: 'ticsadcf1737430662', cache ts: 2025-01-21 03:37:42.895552778 +0000 UTC m=+3.555368805
2025/01/21 03:37:42 DEBUG : data.bin: removing object
2025/01/21 03:37:42 DEBUG : : cache: expired ticsadcf1737430662
2025/01/21 03:37:42 INFO  : data.bin: Deleted
2025/01/21 03:37:42 DEBUG : Cache remote TestInternalCache:ticsadcf1737430662: list ''
2025/01/21 03:37:42 DEBUG : : list: cold listing: 2025-01-20 21:37:42.903718927 +0000 UTC
2025/01/21 03:37:42 DEBUG : : list: read 0 from source
2025/01/21 03:37:42 DEBUG : : list: source entries: []
2025/01/21 03:37:42 DEBUG : : list: cached directories: 0
2025/01/21 03:37:42 DEBUG : : list: cached dir: 'ticsadcf1737430662', cache ts: 2025-01-21 03:37:42.905224725 +0000 UTC m=+3.565040751
2025/01/21 03:37:42 DEBUG : removing 1 level 0 directories
2025/01/21 03:37:42 INFO  : Cache remote TestInternalCache:ticsadcf1737430662: Removing directory
2025/01/21 03:37:42 DEBUG : Cache remote TestInternalCache:ticsadcf1737430662: rmdir ''
2025/01/21 03:37:42 DEBUG : : rmdir: removed dir in source fs
2025/01/21 03:37:42 DEBUG : : rmdir: removed from cache
2025/01/21 03:37:42 INFO  : : rmdir: cache expired
2025/01/21 03:37:42 DEBUG : Cache remote TestInternalCache:ticsadcf1737430662: Services stopped
--- PASS: TestInternalChangeSeenAfterDirCacheFlush (0.60s)
=== RUN   TestInternalCacheWrites
2025/01/21 03:37:42 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2025/01/21 03:37:42 DEBUG : Creating backend with remote "TestInternalCache-local:/tmp/TestInternalCache-local/ticw"
2025/01/21 03:37:42 DEBUG : TestInternalCache: wrapped TestInternalCache-local:/tmp/TestInternalCache-local/ticw at root ticw
2025/01/21 03:37:42 INFO  : TestInternalCache: Cache DB path: /home/rclone/.cache/rclone/cache-backend/TestInternalCache.db
2025/01/21 03:37:42 INFO  : TestInternalCache: Cache chunk path: /home/rclone/.cache/rclone/cache-backend/TestInternalCache
2025/01/21 03:37:42 INFO  : TestInternalCache: Chunk Memory: true
2025/01/21 03:37:42 INFO  : TestInternalCache: Chunk Size: 5Mi
2025/01/21 03:37:42 INFO  : TestInternalCache: Chunk Total Size: 10Gi
2025/01/21 03:37:42 INFO  : TestInternalCache: Chunk Clean Interval: 1m0s
2025/01/21 03:37:42 INFO  : TestInternalCache: Workers: 4
2025/01/21 03:37:42 INFO  : TestInternalCache: File Age: 6h0m0s
2025/01/21 03:37:42 INFO  : TestInternalCache: Cache Writes: enabled
2025/01/21 03:37:42 DEBUG : Waiting for deletions to finish
2025/01/21 03:37:42 DEBUG : Cache remote TestInternalCache:ticw: list ''
2025/01/21 03:37:42 DEBUG : : list: error: couldn't open bucket (ticw)
2025/01/21 03:37:42 ERROR : : error listing: directory not found
2025/01/21 03:37:42 DEBUG : Cache remote TestInternalCache:ticw: list ''
2025/01/21 03:37:42 DEBUG : : list: error: couldn't open bucket (ticw)
2025/01/21 03:37:42 ERROR : Cache remote TestInternalCache:ticw: Failed to list "": directory not found
2025/01/21 03:37:42 DEBUG : removing 1 level 0 directories
2025/01/21 03:37:42 INFO  : Cache remote TestInternalCache:ticw: Removing directory
2025/01/21 03:37:42 DEBUG : Cache remote TestInternalCache:ticw: rmdir ''
2025/01/21 03:37:42 ERROR : : Failed to rmdir: stat /tmp/TestInternalCache-local/ticw: no such file or directory
2025/01/21 03:37:42 DEBUG : Cache remote TestInternalCache:ticw: mkdir ''
2025/01/21 03:37:42 DEBUG : : mkdir: created dir in source fs
2025/01/21 03:37:42 DEBUG : : mkdir: added to cache
2025/01/21 03:37:42 DEBUG : : cache: expired ticw
2025/01/21 03:37:42 INFO  : : mkdir: cache expired
2025/01/21 03:37:43 DEBUG : Cache remote TestInternalCache:ticw: put data at 'data.bin'
2025/01/21 03:37:43 DEBUG : data.bin: put: uploaded to remote fs and saved in cache
2025/01/21 03:37:43 DEBUG : data.bin: put: added to cache
2025/01/21 03:37:43 DEBUG : : cache: expired ticw
2025/01/21 03:37:43 INFO  : : put: cache expired
2025/01/21 03:37:43 DEBUG : Cache remote TestInternalCache:ticw: new object 'data.bin'
2025/01/21 03:37:43 DEBUG : data.bin: find: warm object: data.bin, expiring on: 2025-01-21 09:37:43.460414908 +0000 UTC
2025/01/21 03:37:43 DEBUG : Waiting for deletions to finish
2025/01/21 03:37:43 DEBUG : Cache remote TestInternalCache:ticw: list ''
2025/01/21 03:37:43 DEBUG : : list: cold listing: 2025-01-20 21:37:43.469500937 +0000 UTC
2025/01/21 03:37:43 DEBUG : : list: read 1 from source
2025/01/21 03:37:43 DEBUG : : list: source entries: [data.bin]
2025/01/21 03:37:43 DEBUG : : list: cached object: data.bin
2025/01/21 03:37:43 DEBUG : : list: cached directories: 0
2025/01/21 03:37:43 DEBUG : : list: cached dir: 'ticw', cache ts: 2025-01-21 03:37:43.47235104 +0000 UTC m=+4.132167086
2025/01/21 03:37:43 DEBUG : data.bin: removing object
2025/01/21 03:37:43 DEBUG : : cache: expired ticw
2025/01/21 03:37:43 INFO  : data.bin: Deleted
2025/01/21 03:37:43 DEBUG : Cache remote TestInternalCache:ticw: list ''
2025/01/21 03:37:43 DEBUG : : list: cold listing: 2025-01-20 21:37:43.482028607 +0000 UTC
2025/01/21 03:37:43 DEBUG : : list: read 0 from source
2025/01/21 03:37:43 DEBUG : : list: source entries: []
2025/01/21 03:37:43 DEBUG : : list: cached directories: 0
2025/01/21 03:37:43 DEBUG : : list: cached dir: 'ticw', cache ts: 2025-01-21 03:37:43.483376899 +0000 UTC m=+4.143192956
2025/01/21 03:37:43 DEBUG : removing 1 level 0 directories
2025/01/21 03:37:43 INFO  : Cache remote TestInternalCache:ticw: Removing directory
2025/01/21 03:37:43 DEBUG : Cache remote TestInternalCache:ticw: rmdir ''
2025/01/21 03:37:43 DEBUG : : rmdir: removed dir in source fs
2025/01/21 03:37:43 DEBUG : : rmdir: removed from cache
2025/01/21 03:37:43 INFO  : : rmdir: cache expired
2025/01/21 03:37:43 DEBUG : Cache remote TestInternalCache:ticw: Services stopped
--- PASS: TestInternalCacheWrites (0.58s)
=== RUN   TestInternalMaxChunkSizeRespected
2025/01/21 03:37:43 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2025/01/21 03:37:43 DEBUG : Creating backend with remote "TestInternalCache-local:/tmp/TestInternalCache-local/timcsr1737430663"
2025/01/21 03:37:43 DEBUG : TestInternalCache: wrapped TestInternalCache-local:/tmp/TestInternalCache-local/timcsr1737430663 at root timcsr1737430663
2025/01/21 03:37:43 INFO  : TestInternalCache: Cache DB path: /home/rclone/.cache/rclone/cache-backend/TestInternalCache.db
2025/01/21 03:37:43 INFO  : TestInternalCache: Cache chunk path: /home/rclone/.cache/rclone/cache-backend/TestInternalCache
2025/01/21 03:37:43 INFO  : TestInternalCache: Chunk Memory: true
2025/01/21 03:37:43 INFO  : TestInternalCache: Chunk Size: 5Mi
2025/01/21 03:37:43 INFO  : TestInternalCache: Chunk Total Size: 10Gi
2025/01/21 03:37:43 INFO  : TestInternalCache: Chunk Clean Interval: 1m0s
2025/01/21 03:37:43 INFO  : TestInternalCache: Workers: 1
2025/01/21 03:37:43 INFO  : TestInternalCache: File Age: 6h0m0s
2025/01/21 03:37:43 DEBUG : Waiting for deletions to finish
2025/01/21 03:37:43 DEBUG : Cache remote TestInternalCache:timcsr1737430663: list ''
2025/01/21 03:37:43 DEBUG : : list: error: couldn't open bucket (timcsr1737430663)
2025/01/21 03:37:43 ERROR : : error listing: directory not found
2025/01/21 03:37:43 DEBUG : Cache remote TestInternalCache:timcsr1737430663: list ''
2025/01/21 03:37:43 DEBUG : : list: error: couldn't open bucket (timcsr1737430663)
2025/01/21 03:37:43 ERROR : Cache remote TestInternalCache:timcsr1737430663: Failed to list "": directory not found
2025/01/21 03:37:43 DEBUG : removing 1 level 0 directories
2025/01/21 03:37:43 INFO  : Cache remote TestInternalCache:timcsr1737430663: Removing directory
2025/01/21 03:37:43 DEBUG : Cache remote TestInternalCache:timcsr1737430663: rmdir ''
2025/01/21 03:37:43 ERROR : : Failed to rmdir: stat /tmp/TestInternalCache-local/timcsr1737430663: no such file or directory
2025/01/21 03:37:43 DEBUG : Cache remote TestInternalCache:timcsr1737430663: mkdir ''
2025/01/21 03:37:43 DEBUG : : mkdir: created dir in source fs
2025/01/21 03:37:43 DEBUG : : mkdir: added to cache
2025/01/21 03:37:43 DEBUG : : cache: expired timcsr1737430663
2025/01/21 03:37:43 INFO  : : mkdir: cache expired
2025/01/21 03:37:45 DEBUG : Cache remote TestInternalCache:timcsr1737430663: put data at 'data.bin'
2025/01/21 03:37:45 DEBUG : data.bin: put: uploaded to remote fs
2025/01/21 03:37:45 DEBUG : data.bin: put: added to cache
2025/01/21 03:37:45 DEBUG : : cache: expired timcsr1737430663
2025/01/21 03:37:45 INFO  : : put: cache expired
2025/01/21 03:37:45 DEBUG : Cache remote TestInternalCache:timcsr1737430663: new object 'data.bin'
2025/01/21 03:37:45 DEBUG : data.bin: find: warm object: data.bin, expiring on: 2025-01-21 09:37:45.807457322 +0000 UTC
2025/01/21 03:37:45 DEBUG : Cache remote TestInternalCache:timcsr1737430663: new object 'data.bin'
2025/01/21 03:37:45 DEBUG : data.bin: find: warm object: data.bin, expiring on: 2025-01-21 09:37:45.807457322 +0000 UTC
2025/01/21 03:37:45 DEBUG : timcsr1737430663/data.bin: moving offset set from 0 to 0
2025/01/21 03:37:45 DEBUG : timcsr1737430663/data.bin: 0: chunk retry storage: 0
2025/01/21 03:37:45 DEBUG : worker-0 <data.bin>: downloaded chunk 0
2025/01/21 03:37:46 DEBUG : timcsr1737430663/data.bin: cache reader closed 5242880
2025/01/21 03:37:46 DEBUG : timcsr1737430663/data.bin: moving offset set from 0 to 5242880
2025/01/21 03:37:46 DEBUG : timcsr1737430663/data.bin: 5242880: chunk retry storage: 0
2025/01/21 03:37:46 DEBUG : worker-0 <data.bin>: downloaded chunk 5242880
2025/01/21 03:37:46 DEBUG : timcsr1737430663/data.bin: cache reader closed 10485760
2025/01/21 03:37:46 DEBUG : timcsr1737430663/data.bin: moving offset set from 0 to 10485760
2025/01/21 03:37:46 DEBUG : timcsr1737430663/data.bin: 10485760: chunk retry storage: 0
2025/01/21 03:37:46 DEBUG : worker-0 <data.bin>: downloaded chunk 10485760
2025/01/21 03:37:47 DEBUG : timcsr1737430663/data.bin: cache reader closed 15728640
2025/01/21 03:37:47 DEBUG : timcsr1737430663/data.bin: moving offset set from 0 to 15728640
2025/01/21 03:37:47 DEBUG : timcsr1737430663/data.bin: 15728640: chunk retry storage: 0
2025/01/21 03:37:47 DEBUG : worker-0 <data.bin>: downloaded chunk 15728640
2025/01/21 03:37:47 DEBUG : timcsr1737430663/data.bin: cache reader closed 20971520
2025/01/21 03:37:47 DEBUG : timcsr1737430663/data.bin: moving offset set from 0 to 20971520
2025/01/21 03:37:47 DEBUG : timcsr1737430663/data.bin: 20971520: chunk retry storage: 0
2025/01/21 03:37:47 DEBUG : worker-0 <data.bin>: downloaded chunk 20971520
2025/01/21 03:37:48 DEBUG : timcsr1737430663/data.bin: cache reader closed 26214400
2025/01/21 03:37:48 DEBUG : timcsr1737430663/data.bin: moving offset set from 0 to 26214400
2025/01/21 03:37:48 DEBUG : timcsr1737430663/data.bin: 26214400: chunk retry storage: 0
2025/01/21 03:37:48 DEBUG : worker-0 <data.bin>: downloaded chunk 26214400
2025/01/21 03:37:48 DEBUG : timcsr1737430663/data.bin: cache reader closed 31457280
2025/01/21 03:37:48 DEBUG : Waiting for deletions to finish
2025/01/21 03:37:48 DEBUG : Cache remote TestInternalCache:timcsr1737430663: list ''
2025/01/21 03:37:48 DEBUG : : list: cold listing: 2025-01-20 21:37:45.811983531 +0000 UTC
2025/01/21 03:37:48 DEBUG : : list: read 1 from source
2025/01/21 03:37:48 DEBUG : : list: source entries: [data.bin]
2025/01/21 03:37:48 DEBUG : : list: cached object: data.bin
2025/01/21 03:37:48 DEBUG : : list: cached directories: 0
2025/01/21 03:37:49 DEBUG : : list: cached dir: 'timcsr1737430663', cache ts: 2025-01-21 03:37:48.999534848 +0000 UTC m=+9.659350894
2025/01/21 03:37:49 DEBUG : data.bin: removing object
2025/01/21 03:37:49 DEBUG : : cache: expired timcsr1737430663
2025/01/21 03:37:49 INFO  : data.bin: Deleted
2025/01/21 03:37:49 DEBUG : Cache remote TestInternalCache:timcsr1737430663: list ''
2025/01/21 03:37:49 DEBUG : : list: cold listing: 2025-01-20 21:37:49.012059122 +0000 UTC
2025/01/21 03:37:49 DEBUG : : list: read 0 from source
2025/01/21 03:37:49 DEBUG : : list: source entries: []
2025/01/21 03:37:49 DEBUG : : list: cached directories: 0
2025/01/21 03:37:49 DEBUG : : list: cached dir: 'timcsr1737430663', cache ts: 2025-01-21 03:37:49.013924051 +0000 UTC m=+9.673740077
2025/01/21 03:37:49 DEBUG : removing 1 level 0 directories
2025/01/21 03:37:49 INFO  : Cache remote TestInternalCache:timcsr1737430663: Removing directory
2025/01/21 03:37:49 DEBUG : Cache remote TestInternalCache:timcsr1737430663: rmdir ''
2025/01/21 03:37:49 DEBUG : : rmdir: removed dir in source fs
2025/01/21 03:37:49 DEBUG : : rmdir: removed from cache
2025/01/21 03:37:49 INFO  : : rmdir: cache expired
2025/01/21 03:37:49 DEBUG : Cache remote TestInternalCache:timcsr1737430663: Services stopped
--- PASS: TestInternalMaxChunkSizeRespected (5.53s)
=== RUN   TestInternalExpiredEntriesRemoved
2025/01/21 03:37:49 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/01/21 03:37:49 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2025/01/21 03:37:49 DEBUG : Creating backend with remote "TestInternalCache-local:/tmp/TestInternalCache-local/tib21171737430669"
2025/01/21 03:37:49 DEBUG : TestInternalCache: wrapped TestInternalCache-local:/tmp/TestInternalCache-local/tib21171737430669 at root tib21171737430669
2025/01/21 03:37:49 INFO  : TestInternalCache: Cache DB path: /home/rclone/.cache/rclone/cache-backend/TestInternalCache.db
2025/01/21 03:37:49 INFO  : TestInternalCache: Cache chunk path: /home/rclone/.cache/rclone/cache-backend/TestInternalCache
2025/01/21 03:37:49 INFO  : TestInternalCache: Chunk Memory: true
2025/01/21 03:37:49 INFO  : TestInternalCache: Chunk Size: 5Mi
2025/01/21 03:37:49 INFO  : TestInternalCache: Chunk Total Size: 10Gi
2025/01/21 03:37:49 INFO  : TestInternalCache: Chunk Clean Interval: 15m0s
2025/01/21 03:37:49 INFO  : TestInternalCache: Workers: 4
2025/01/21 03:37:49 INFO  : TestInternalCache: File Age: 3d
2025/01/21 03:37:49 DEBUG : Waiting for deletions to finish
2025/01/21 03:37:49 DEBUG : Cache remote TestInternalCache:tib21171737430669: list ''
2025/01/21 03:37:49 DEBUG : : list: error: couldn't open bucket (tib21171737430669)
2025/01/21 03:37:49 ERROR : : error listing: directory not found
2025/01/21 03:37:49 DEBUG : Cache remote TestInternalCache:tib21171737430669: list ''
2025/01/21 03:37:49 DEBUG : : list: error: couldn't open bucket (tib21171737430669)
2025/01/21 03:37:49 ERROR : Cache remote TestInternalCache:tib21171737430669: Failed to list "": directory not found
2025/01/21 03:37:49 DEBUG : removing 1 level 0 directories
2025/01/21 03:37:49 INFO  : Cache remote TestInternalCache:tib21171737430669: Removing directory
2025/01/21 03:37:49 DEBUG : Cache remote TestInternalCache:tib21171737430669: rmdir ''
2025/01/21 03:37:49 ERROR : : Failed to rmdir: stat /tmp/TestInternalCache-local/tib21171737430669: no such file or directory
2025/01/21 03:37:49 DEBUG : Cache remote TestInternalCache:tib21171737430669: mkdir ''
2025/01/21 03:37:49 DEBUG : : mkdir: created dir in source fs
2025/01/21 03:37:49 DEBUG : : mkdir: added to cache
2025/01/21 03:37:49 DEBUG : : cache: expired tib21171737430669
2025/01/21 03:37:49 INFO  : : mkdir: cache expired
2025/01/21 03:37:49 DEBUG : Cache remote TestInternalCache:tib21171737430669: list 'test/dir1/dir2'
2025/01/21 03:37:49 DEBUG : test/dir1/dir2: list: error: couldn't open bucket (tib21171737430669/test/dir1/dir2)
2025/01/21 03:37:49 DEBUG : test/dir1/dir2: list: read 1 from source
2025/01/21 03:37:49 DEBUG : test/dir1/dir2: list: source entries: [test/dir1/dir2/test.txt]
2025/01/21 03:37:49 DEBUG : test/dir1/dir2: list: cached object: test/dir1/dir2/test.txt
2025/01/21 03:37:49 DEBUG : test/dir1/dir2: list: cached directories: 0
2025/01/21 03:37:49 DEBUG : test/dir1/dir2: list: cached dir: 'tib21171737430669/test/dir1/dir2', cache ts: 2025-01-21 03:37:49.041516608 +0000 UTC m=+9.701332624
2025/01/21 03:37:49 NOTICE: len: 1
2025/01/21 03:38:19 DEBUG : Cache remote TestInternalCache:tib21171737430669: list 'test/dir1/dir2'
2025/01/21 03:38:19 DEBUG : test/dir1/dir2: list: warm 1 from cache for: tib21171737430669/test/dir1/dir2, expiring on: 2025-01-24 03:37:49.041516608 +0000 UTC
2025/01/21 03:38:19 DEBUG : test/dir1/dir2: list: cached entries: [test/dir1/dir2/test.txt]
2025/01/21 03:38:19 NOTICE: len: 1
2025/01/21 03:38:19 DEBUG : Cache remote TestInternalCache:tib21171737430669: list 'test/dir1'
2025/01/21 03:38:19 DEBUG : test/dir1: list: error: missing cached dir: test/dir1
2025/01/21 03:38:19 DEBUG : test/dir1: list: read 4 from source
2025/01/21 03:38:19 DEBUG : test/dir1: list: source entries: [test/dir1/dir3 test/dir1/dir2 test/dir1/dir4 test/dir1/dir1]
2025/01/21 03:38:19 DEBUG : test/dir1: list: cached directories: 4
2025/01/21 03:38:19 DEBUG : test/dir1: list: cached dir: 'tib21171737430669/test/dir1', cache ts: 2025-01-21 03:38:19.072193538 +0000 UTC m=+39.732009555
2025/01/21 03:38:19 NOTICE: len: 4
2025/01/21 03:38:19 DEBUG : Cache remote TestInternalCache:tib21171737430669: list 'test'
2025/01/21 03:38:19 DEBUG : test: list: error: missing cached dir: test
2025/01/21 03:38:19 DEBUG : test: list: read 4 from source
2025/01/21 03:38:19 DEBUG : test: list: source entries: [test/dir3 test/dir2 test/dir4 test/dir1]
2025/01/21 03:38:19 DEBUG : test: list: cached directories: 4
2025/01/21 03:38:19 DEBUG : test: list: cached dir: 'tib21171737430669/test', cache ts: 2025-01-21 03:38:19.075941141 +0000 UTC m=+39.735757147
2025/01/21 03:38:19 NOTICE: len: 4
2025/01/21 03:38:19 DEBUG : Waiting for deletions to finish
2025/01/21 03:38:19 DEBUG : Cache remote TestInternalCache:tib21171737430669: list ''
2025/01/21 03:38:19 DEBUG : : list: cold listing: 2025-01-18 03:37:49.031240952 +0000 UTC
2025/01/21 03:38:19 DEBUG : : list: read 1 from source
2025/01/21 03:38:19 DEBUG : : list: source entries: [test]
2025/01/21 03:38:19 DEBUG : : list: cached directories: 1
2025/01/21 03:38:19 DEBUG : : list: cached dir: 'tib21171737430669', cache ts: 2025-01-21 03:38:19.078615565 +0000 UTC m=+39.738431571
2025/01/21 03:38:19 DEBUG : Cache remote TestInternalCache:tib21171737430669: list 'test'
2025/01/21 03:38:19 DEBUG : test: list: warm 4 from cache for: tib21171737430669/test, expiring on: 2025-01-24 03:38:19.077588533 +0000 UTC
2025/01/21 03:38:19 DEBUG : test: list: cached entries: [test/dir1 test/dir2 test/dir3 test/dir4]
2025/01/21 03:38:19 DEBUG : Cache remote TestInternalCache:tib21171737430669: list 'test/dir4'
2025/01/21 03:38:19 DEBUG : test/dir4: list: empty listing
2025/01/21 03:38:19 DEBUG : test/dir4: list: read 4 from source
2025/01/21 03:38:19 DEBUG : test/dir4: list: source entries: [test/dir4/dir3 test/dir4/dir2 test/dir4/dir4 test/dir4/dir1]
2025/01/21 03:38:19 DEBUG : Cache remote TestInternalCache:tib21171737430669: list 'test/dir2'
2025/01/21 03:38:19 DEBUG : test/dir2: list: empty listing
2025/01/21 03:38:19 DEBUG : test/dir2: list: read 4 from source
2025/01/21 03:38:19 DEBUG : test/dir2: list: source entries: [test/dir2/dir3 test/dir2/dir2 test/dir2/dir4 test/dir2/dir1]
2025/01/21 03:38:19 DEBUG : Cache remote TestInternalCache:tib21171737430669: list 'test/dir1'
2025/01/21 03:38:19 DEBUG : test/dir1: list: warm 4 from cache for: tib21171737430669/test/dir1, expiring on: 2025-01-24 03:38:19.074688036 +0000 UTC
2025/01/21 03:38:19 DEBUG : test/dir1: list: cached entries: [test/dir1/dir1 test/dir1/dir2 test/dir1/dir3 test/dir1/dir4]
2025/01/21 03:38:19 DEBUG : Cache remote TestInternalCache:tib21171737430669: list 'test/dir1/dir4'
2025/01/21 03:38:19 DEBUG : test/dir1/dir4: list: empty listing
2025/01/21 03:38:19 DEBUG : Cache remote TestInternalCache:tib21171737430669: list 'test/dir3'
2025/01/21 03:38:19 DEBUG : test/dir1/dir4: list: read 1 from source
2025/01/21 03:38:19 DEBUG : test/dir1/dir4: list: source entries: [test/dir1/dir4/test.txt]
2025/01/21 03:38:19 DEBUG : Cache remote TestInternalCache:tib21171737430669: list 'test/dir1/dir1'
2025/01/21 03:38:19 DEBUG : test/dir1/dir1: list: empty listing
2025/01/21 03:38:19 DEBUG : test/dir3: list: empty listing
2025/01/21 03:38:19 DEBUG : test/dir1/dir1: list: read 1 from source
2025/01/21 03:38:19 DEBUG : test/dir1/dir1: list: source entries: [test/dir1/dir1/test.txt]
2025/01/21 03:38:19 DEBUG : Cache remote TestInternalCache:tib21171737430669: list 'test/dir1/dir2'
2025/01/21 03:38:19 DEBUG : test/dir1/dir2: list: warm 1 from cache for: tib21171737430669/test/dir1/dir2, expiring on: 2025-01-24 03:38:19.070031463 +0000 UTC
2025/01/21 03:38:19 DEBUG : test/dir1/dir2: list: cached entries: [test/dir1/dir2/test.txt]
2025/01/21 03:38:19 DEBUG : Cache remote TestInternalCache:tib21171737430669: list 'test/dir1/dir3'
2025/01/21 03:38:19 DEBUG : test/dir1/dir3: list: empty listing
2025/01/21 03:38:19 DEBUG : test/dir3: list: read 4 from source
2025/01/21 03:38:19 DEBUG : test/dir3: list: source entries: [test/dir3/dir3 test/dir3/dir2 test/dir3/dir4 test/dir3/dir1]
2025/01/21 03:38:19 DEBUG : test/dir1/dir3: list: read 1 from source
2025/01/21 03:38:19 DEBUG : test/dir1/dir3: list: source entries: [test/dir1/dir3/test.txt]
2025/01/21 03:38:19 DEBUG : test/dir4: list: cached directories: 4
2025/01/21 03:38:19 DEBUG : test/dir4: list: cached dir: 'tib21171737430669/test/dir4', cache ts: 2025-01-21 03:38:19.08148886 +0000 UTC m=+39.741304876
2025/01/21 03:38:19 DEBUG : Cache remote TestInternalCache:tib21171737430669: list 'test/dir4/dir3'
2025/01/21 03:38:19 DEBUG : Cache remote TestInternalCache:tib21171737430669: list 'test/dir4/dir1'
2025/01/21 03:38:19 DEBUG : test/dir4/dir1: list: empty listing
2025/01/21 03:38:19 DEBUG : test/dir4/dir3: list: empty listing
2025/01/21 03:38:19 DEBUG : test/dir4/dir1: list: read 1 from source
2025/01/21 03:38:19 DEBUG : test/dir4/dir3: list: read 1 from source
2025/01/21 03:38:19 DEBUG : test/dir4/dir1: list: source entries: [test/dir4/dir1/test.txt]
2025/01/21 03:38:19 DEBUG : test/dir4/dir3: list: source entries: [test/dir4/dir3/test.txt]
2025/01/21 03:38:19 DEBUG : Cache remote TestInternalCache:tib21171737430669: list 'test/dir4/dir2'
2025/01/21 03:38:19 DEBUG : test/dir4/dir2: list: empty listing
2025/01/21 03:38:19 DEBUG : test/dir4/dir2: list: read 1 from source
2025/01/21 03:38:19 DEBUG : test/dir4/dir2: list: source entries: [test/dir4/dir2/test.txt]
2025/01/21 03:38:19 DEBUG : test/dir2: list: cached directories: 4
2025/01/21 03:38:19 DEBUG : test/dir1/dir4: list: cached object: test/dir1/dir4/test.txt
2025/01/21 03:38:19 DEBUG : test/dir1/dir4: list: cached directories: 0
2025/01/21 03:38:19 DEBUG : test/dir1/dir1: list: cached object: test/dir1/dir1/test.txt
2025/01/21 03:38:19 DEBUG : test/dir1/dir1: list: cached directories: 0
2025/01/21 03:38:19 DEBUG : test/dir1/dir2/test.txt: removing object
2025/01/21 03:38:19 DEBUG : test/dir1/dir3: list: cached object: test/dir1/dir3/test.txt
2025/01/21 03:38:19 DEBUG : test/dir1/dir3: list: cached directories: 0
2025/01/21 03:38:19 DEBUG : test/dir3: list: cached directories: 4
2025/01/21 03:38:19 DEBUG : test/dir4/dir1: list: cached object: test/dir4/dir1/test.txt
2025/01/21 03:38:19 DEBUG : test/dir4/dir1: list: cached directories: 0
2025/01/21 03:38:19 DEBUG : test/dir4/dir3: list: cached object: test/dir4/dir3/test.txt
2025/01/21 03:38:19 DEBUG : test/dir4/dir3: list: cached directories: 0
2025/01/21 03:38:19 DEBUG : test/dir4/dir2: list: cached object: test/dir4/dir2/test.txt
2025/01/21 03:38:19 DEBUG : test/dir4/dir2: list: cached directories: 0
2025/01/21 03:38:19 DEBUG : test/dir2: list: cached dir: 'tib21171737430669/test/dir2', cache ts: 2025-01-21 03:38:19.084279581 +0000 UTC m=+39.744095607
2025/01/21 03:38:19 DEBUG : Cache remote TestInternalCache:tib21171737430669: list 'test/dir4/dir4'
2025/01/21 03:38:19 DEBUG : test/dir4/dir4: list: empty listing
2025/01/21 03:38:19 DEBUG : test/dir4/dir4: list: read 1 from source
2025/01/21 03:38:19 DEBUG : test/dir4/dir4: list: source entries: [test/dir4/dir4/test.txt]
2025/01/21 03:38:19 DEBUG : test/dir1/dir4: list: cached dir: 'tib21171737430669/test/dir1/dir4', cache ts: 2025-01-21 03:38:19.085408093 +0000 UTC m=+39.745224119
2025/01/21 03:38:19 DEBUG : Cache remote TestInternalCache:tib21171737430669: list 'test/dir2/dir1'
2025/01/21 03:38:19 DEBUG : test/dir2/dir1: list: empty listing
2025/01/21 03:38:19 DEBUG : test/dir2/dir1: list: read 1 from source
2025/01/21 03:38:19 DEBUG : test/dir2/dir1: list: source entries: [test/dir2/dir1/test.txt]
2025/01/21 03:38:19 DEBUG : test/dir1/dir4/test.txt: removing object
2025/01/21 03:38:19 DEBUG : test/dir1/dir1: list: cached dir: 'tib21171737430669/test/dir1/dir1', cache ts: 2025-01-21 03:38:19.08688135 +0000 UTC m=+39.746697426
2025/01/21 03:38:19 DEBUG : Cache remote TestInternalCache:tib21171737430669: list 'test/dir2/dir2'
2025/01/21 03:38:19 DEBUG : test/dir2/dir2: list: empty listing
2025/01/21 03:38:19 DEBUG : test/dir2/dir2: list: read 1 from source
2025/01/21 03:38:19 DEBUG : test/dir2/dir2: list: source entries: [test/dir2/dir2/test.txt]
2025/01/21 03:38:19 DEBUG : test/dir1/dir1/test.txt: removing object
2025/01/21 03:38:19 DEBUG : test/dir1/dir3: list: cached dir: 'tib21171737430669/test/dir1/dir3', cache ts: 2025-01-21 03:38:19.089386847 +0000 UTC m=+39.749202964
2025/01/21 03:38:19 DEBUG : Cache remote TestInternalCache:tib21171737430669: list 'test/dir2/dir3'
2025/01/21 03:38:19 DEBUG : test/dir2/dir3: list: empty listing
2025/01/21 03:38:19 DEBUG : test/dir2/dir3: list: read 1 from source
2025/01/21 03:38:19 DEBUG : test/dir2/dir3: list: source entries: [test/dir2/dir3/test.txt]
2025/01/21 03:38:19 DEBUG : test/dir1/dir3/test.txt: removing object
2025/01/21 03:38:19 DEBUG : test/dir3: list: cached dir: 'tib21171737430669/test/dir3', cache ts: 2025-01-21 03:38:19.090795133 +0000 UTC m=+39.750611149
2025/01/21 03:38:19 DEBUG : Cache remote TestInternalCache:tib21171737430669: list 'test/dir2/dir4'
2025/01/21 03:38:19 DEBUG : test/dir2/dir4: list: empty listing
2025/01/21 03:38:19 DEBUG : test/dir2/dir4: list: read 1 from source
2025/01/21 03:38:19 DEBUG : test/dir2/dir4: list: source entries: [test/dir2/dir4/test.txt]
2025/01/21 03:38:19 DEBUG : test/dir4/dir1: list: cached dir: 'tib21171737430669/test/dir4/dir1', cache ts: 2025-01-21 03:38:19.092353077 +0000 UTC m=+39.752169204
2025/01/21 03:38:19 DEBUG : Cache remote TestInternalCache:tib21171737430669: list 'test/dir3/dir1'
2025/01/21 03:38:19 DEBUG : test/dir3/dir1: list: empty listing
2025/01/21 03:38:19 DEBUG : test/dir3/dir1: list: read 1 from source
2025/01/21 03:38:19 DEBUG : test/dir3/dir1: list: source entries: [test/dir3/dir1/test.txt]
2025/01/21 03:38:19 DEBUG : test/dir4/dir1/test.txt: removing object
2025/01/21 03:38:19 DEBUG : test/dir4/dir3: list: cached dir: 'tib21171737430669/test/dir4/dir3', cache ts: 2025-01-21 03:38:19.093599189 +0000 UTC m=+39.753415215
2025/01/21 03:38:19 DEBUG : Cache remote TestInternalCache:tib21171737430669: list 'test/dir3/dir2'
2025/01/21 03:38:19 DEBUG : test/dir3/dir2: list: empty listing
2025/01/21 03:38:19 DEBUG : test/dir3/dir2: list: read 1 from source
2025/01/21 03:38:19 DEBUG : test/dir3/dir2: list: source entries: [test/dir3/dir2/test.txt]
2025/01/21 03:38:19 DEBUG : test/dir4/dir3/test.txt: removing object
2025/01/21 03:38:19 DEBUG : test/dir4/dir2: list: cached dir: 'tib21171737430669/test/dir4/dir2', cache ts: 2025-01-21 03:38:19.094845762 +0000 UTC m=+39.754661868
2025/01/21 03:38:19 DEBUG : Cache remote TestInternalCache:tib21171737430669: list 'test/dir3/dir3'
2025/01/21 03:38:19 DEBUG : test/dir3/dir3: list: empty listing
2025/01/21 03:38:19 DEBUG : test/dir3/dir3: list: read 1 from source
2025/01/21 03:38:19 DEBUG : test/dir3/dir3: list: source entries: [test/dir3/dir3/test.txt]
2025/01/21 03:38:19 DEBUG : test/dir4/dir2/test.txt: removing object
2025/01/21 03:38:19 DEBUG : test/dir4/dir4: list: cached object: test/dir4/dir4/test.txt
2025/01/21 03:38:19 DEBUG : test/dir4/dir4: list: cached directories: 0
2025/01/21 03:38:19 DEBUG : test/dir2/dir1: list: cached object: test/dir2/dir1/test.txt
2025/01/21 03:38:19 DEBUG : test/dir2/dir1: list: cached directories: 0
2025/01/21 03:38:19 DEBUG : test/dir2/dir2: list: cached object: test/dir2/dir2/test.txt
2025/01/21 03:38:19 DEBUG : test/dir2/dir2: list: cached directories: 0
2025/01/21 03:38:19 DEBUG : test/dir2/dir3: list: cached object: test/dir2/dir3/test.txt
2025/01/21 03:38:19 DEBUG : test/dir2/dir3: list: cached directories: 0
2025/01/21 03:38:19 DEBUG : test/dir2/dir4: list: cached object: test/dir2/dir4/test.txt
2025/01/21 03:38:19 DEBUG : test/dir2/dir4: list: cached directories: 0
2025/01/21 03:38:19 DEBUG : test/dir3/dir1: list: cached object: test/dir3/dir1/test.txt
2025/01/21 03:38:19 DEBUG : test/dir3/dir1: list: cached directories: 0
2025/01/21 03:38:19 DEBUG : test/dir3/dir2: list: cached object: test/dir3/dir2/test.txt
2025/01/21 03:38:19 DEBUG : test/dir3/dir2: list: cached directories: 0
2025/01/21 03:38:19 DEBUG : test/dir3/dir3: list: cached object: test/dir3/dir3/test.txt
2025/01/21 03:38:19 DEBUG : test/dir3/dir3: list: cached directories: 0
2025/01/21 03:38:19 DEBUG : test/dir4/dir4: list: cached dir: 'tib21171737430669/test/dir4/dir4', cache ts: 2025-01-21 03:38:19.107860263 +0000 UTC m=+39.767676299
2025/01/21 03:38:19 DEBUG : Cache remote TestInternalCache:tib21171737430669: list 'test/dir3/dir4'
2025/01/21 03:38:19 DEBUG : test/dir3/dir4: list: empty listing
2025/01/21 03:38:19 DEBUG : test/dir3/dir4: list: read 1 from source
2025/01/21 03:38:19 DEBUG : test/dir3/dir4: list: source entries: [test/dir3/dir4/test.txt]
2025/01/21 03:38:19 DEBUG : test/dir4/dir4/test.txt: removing object
2025/01/21 03:38:19 DEBUG : test/dir2/dir1: list: cached dir: 'tib21171737430669/test/dir2/dir1', cache ts: 2025-01-21 03:38:19.114307896 +0000 UTC m=+39.774123932
2025/01/21 03:38:19 DEBUG : test/dir1/dir2: cache: expired tib21171737430669/test/dir1/dir2
2025/01/21 03:38:19 DEBUG : test/dir1/dir2: cache: expired tib21171737430669/test/dir1
2025/01/21 03:38:19 DEBUG : test/dir2/dir2: list: cached dir: 'tib21171737430669/test/dir2/dir2', cache ts: 2025-01-21 03:38:19.117792555 +0000 UTC m=+39.777608592
2025/01/21 03:38:19 DEBUG : test/dir1/dir2: cache: expired tib21171737430669/test
2025/01/21 03:38:19 DEBUG : test/dir1/dir2: cache: expired tib21171737430669
2025/01/21 03:38:19 INFO  : test/dir1/dir2/test.txt: Deleted
2025/01/21 03:38:19 DEBUG : test/dir2/dir1/test.txt: removing object
2025/01/21 03:38:19 DEBUG : test/dir2/dir3: list: cached dir: 'tib21171737430669/test/dir2/dir3', cache ts: 2025-01-21 03:38:19.122074627 +0000 UTC m=+39.781890643
2025/01/21 03:38:19 DEBUG : test/dir2/dir4: list: cached dir: 'tib21171737430669/test/dir2/dir4', cache ts: 2025-01-21 03:38:19.125642022 +0000 UTC m=+39.785458058
2025/01/21 03:38:19 DEBUG : test/dir3/dir1: list: cached dir: 'tib21171737430669/test/dir3/dir1', cache ts: 2025-01-21 03:38:19.126953466 +0000 UTC m=+39.786769502
2025/01/21 03:38:19 DEBUG : test/dir3/dir2: list: cached dir: 'tib21171737430669/test/dir3/dir2', cache ts: 2025-01-21 03:38:19.129421545 +0000 UTC m=+39.789237580
2025/01/21 03:38:19 DEBUG : test/dir3/dir3: list: cached dir: 'tib21171737430669/test/dir3/dir3', cache ts: 2025-01-21 03:38:19.13311757 +0000 UTC m=+39.792933605
2025/01/21 03:38:19 DEBUG : test/dir3/dir4: list: cached object: test/dir3/dir4/test.txt
2025/01/21 03:38:19 DEBUG : test/dir3/dir4: list: cached directories: 0
2025/01/21 03:38:19 DEBUG : test/dir1/dir4: cache: expired tib21171737430669/test/dir1/dir4
2025/01/21 03:38:19 DEBUG : test/dir1/dir4: cache: expired tib21171737430669/test/dir1
2025/01/21 03:38:19 DEBUG : test/dir1/dir4: cache: expired tib21171737430669/test
2025/01/21 03:38:19 DEBUG : test/dir1/dir4: cache: expired tib21171737430669
2025/01/21 03:38:19 INFO  : test/dir1/dir4/test.txt: Deleted
2025/01/21 03:38:19 DEBUG : test/dir2/dir2/test.txt: removing object
2025/01/21 03:38:19 DEBUG : test/dir3/dir4: list: cached dir: 'tib21171737430669/test/dir3/dir4', cache ts: 2025-01-21 03:38:19.159964591 +0000 UTC m=+39.819780606
2025/01/21 03:38:19 DEBUG : test/dir1/dir1: cache: expired tib21171737430669/test/dir1/dir1
2025/01/21 03:38:19 DEBUG : test/dir1/dir1: cache: expired tib21171737430669/test/dir1
2025/01/21 03:38:19 DEBUG : test/dir1/dir1: cache: expired tib21171737430669/test
2025/01/21 03:38:19 DEBUG : test/dir1/dir1: cache: expired tib21171737430669
2025/01/21 03:38:19 INFO  : test/dir1/dir1/test.txt: Deleted
2025/01/21 03:38:19 DEBUG : test/dir2/dir3/test.txt: removing object
2025/01/21 03:38:19 DEBUG : test/dir1/dir3: cache: expired tib21171737430669/test/dir1/dir3
2025/01/21 03:38:19 DEBUG : test/dir1/dir3: cache: expired tib21171737430669/test/dir1
2025/01/21 03:38:19 DEBUG : test/dir1/dir3: cache: expired tib21171737430669/test
2025/01/21 03:38:19 DEBUG : test/dir1/dir3: cache: expired tib21171737430669
2025/01/21 03:38:19 INFO  : test/dir1/dir3/test.txt: Deleted
2025/01/21 03:38:19 DEBUG : test/dir2/dir4/test.txt: removing object
2025/01/21 03:38:19 DEBUG : test/dir4/dir1: cache: expired tib21171737430669/test/dir4/dir1
2025/01/21 03:38:19 DEBUG : test/dir4/dir1: cache: expired tib21171737430669/test/dir4
2025/01/21 03:38:19 DEBUG : test/dir4/dir1: cache: expired tib21171737430669/test
2025/01/21 03:38:19 DEBUG : test/dir4/dir1: cache: expired tib21171737430669
2025/01/21 03:38:19 INFO  : test/dir4/dir1/test.txt: Deleted
2025/01/21 03:38:19 DEBUG : test/dir3/dir1/test.txt: removing object
2025/01/21 03:38:19 DEBUG : test/dir4/dir3: cache: expired tib21171737430669/test/dir4/dir3
2025/01/21 03:38:19 DEBUG : test/dir4/dir3: cache: expired tib21171737430669/test/dir4
2025/01/21 03:38:19 DEBUG : test/dir4/dir3: cache: expired tib21171737430669/test
2025/01/21 03:38:19 DEBUG : test/dir4/dir3: cache: expired tib21171737430669
2025/01/21 03:38:19 INFO  : test/dir4/dir3/test.txt: Deleted
2025/01/21 03:38:19 DEBUG : test/dir3/dir2/test.txt: removing object
2025/01/21 03:38:19 DEBUG : test/dir4/dir2: cache: expired tib21171737430669/test/dir4/dir2
2025/01/21 03:38:19 DEBUG : test/dir4/dir2: cache: expired tib21171737430669/test/dir4
2025/01/21 03:38:19 DEBUG : test/dir4/dir2: cache: expired tib21171737430669/test
2025/01/21 03:38:19 DEBUG : test/dir4/dir2: cache: expired tib21171737430669
2025/01/21 03:38:19 INFO  : test/dir4/dir2/test.txt: Deleted
2025/01/21 03:38:19 DEBUG : test/dir3/dir3/test.txt: removing object
2025/01/21 03:38:19 DEBUG : test/dir4/dir4: cache: expired tib21171737430669/test/dir4/dir4
2025/01/21 03:38:19 DEBUG : test/dir4/dir4: cache: expired tib21171737430669/test/dir4
2025/01/21 03:38:19 DEBUG : test/dir4/dir4: cache: expired tib21171737430669/test
2025/01/21 03:38:19 DEBUG : test/dir4/dir4: cache: expired tib21171737430669
2025/01/21 03:38:19 INFO  : test/dir4/dir4/test.txt: Deleted
2025/01/21 03:38:19 DEBUG : test/dir3/dir4/test.txt: removing object
2025/01/21 03:38:19 DEBUG : test/dir2/dir1: cache: expired tib21171737430669/test/dir2/dir1
2025/01/21 03:38:19 DEBUG : test/dir2/dir1: cache: expired tib21171737430669/test/dir2
2025/01/21 03:38:19 DEBUG : test/dir2/dir1: cache: expired tib21171737430669/test
2025/01/21 03:38:19 DEBUG : test/dir2/dir1: cache: expired tib21171737430669
2025/01/21 03:38:19 INFO  : test/dir2/dir1/test.txt: Deleted
2025/01/21 03:38:19 DEBUG : test/dir2/dir2: cache: expired tib21171737430669/test/dir2/dir2
2025/01/21 03:38:19 DEBUG : test/dir2/dir2: cache: expired tib21171737430669/test/dir2
2025/01/21 03:38:19 DEBUG : test/dir2/dir2: cache: expired tib21171737430669/test
2025/01/21 03:38:19 DEBUG : test/dir2/dir2: cache: expired tib21171737430669
2025/01/21 03:38:19 INFO  : test/dir2/dir2/test.txt: Deleted
2025/01/21 03:38:19 DEBUG : test/dir2/dir3: cache: expired tib21171737430669/test/dir2/dir3
2025/01/21 03:38:19 DEBUG : test/dir2/dir3: cache: expired tib21171737430669/test/dir2
2025/01/21 03:38:19 DEBUG : test/dir2/dir3: cache: expired tib21171737430669/test
2025/01/21 03:38:19 DEBUG : test/dir2/dir3: cache: expired tib21171737430669
2025/01/21 03:38:19 INFO  : test/dir2/dir3/test.txt: Deleted
2025/01/21 03:38:19 DEBUG : test/dir2/dir4: cache: expired tib21171737430669/test/dir2/dir4
2025/01/21 03:38:19 DEBUG : test/dir2/dir4: cache: expired tib21171737430669/test/dir2
2025/01/21 03:38:19 DEBUG : test/dir2/dir4: cache: expired tib21171737430669/test
2025/01/21 03:38:19 DEBUG : test/dir2/dir4: cache: expired tib21171737430669
2025/01/21 03:38:19 INFO  : test/dir2/dir4/test.txt: Deleted
2025/01/21 03:38:19 DEBUG : test/dir3/dir1: cache: expired tib21171737430669/test/dir3/dir1
2025/01/21 03:38:19 DEBUG : test/dir3/dir1: cache: expired tib21171737430669/test/dir3
2025/01/21 03:38:19 DEBUG : test/dir3/dir1: cache: expired tib21171737430669/test
2025/01/21 03:38:19 DEBUG : test/dir3/dir1: cache: expired tib21171737430669
2025/01/21 03:38:19 INFO  : test/dir3/dir1/test.txt: Deleted
2025/01/21 03:38:19 DEBUG : test/dir3/dir2: cache: expired tib21171737430669/test/dir3/dir2
2025/01/21 03:38:19 DEBUG : test/dir3/dir2: cache: expired tib21171737430669/test/dir3
2025/01/21 03:38:19 DEBUG : test/dir3/dir2: cache: expired tib21171737430669/test
2025/01/21 03:38:19 DEBUG : test/dir3/dir2: cache: expired tib21171737430669
2025/01/21 03:38:19 INFO  : test/dir3/dir2/test.txt: Deleted
2025/01/21 03:38:19 DEBUG : test/dir3/dir3: cache: expired tib21171737430669/test/dir3/dir3
2025/01/21 03:38:19 DEBUG : test/dir3/dir3: cache: expired tib21171737430669/test/dir3
2025/01/21 03:38:19 DEBUG : test/dir3/dir3: cache: expired tib21171737430669/test
2025/01/21 03:38:19 DEBUG : test/dir3/dir3: cache: expired tib21171737430669
2025/01/21 03:38:19 INFO  : test/dir3/dir3/test.txt: Deleted
2025/01/21 03:38:19 DEBUG : test/dir3/dir4: cache: expired tib21171737430669/test/dir3/dir4
2025/01/21 03:38:19 DEBUG : test/dir3/dir4: cache: expired tib21171737430669/test/dir3
2025/01/21 03:38:19 DEBUG : test/dir3/dir4: cache: expired tib21171737430669/test
2025/01/21 03:38:19 DEBUG : test/dir3/dir4: cache: expired tib21171737430669
2025/01/21 03:38:19 INFO  : test/dir3/dir4/test.txt: Deleted
2025/01/21 03:38:19 DEBUG : Cache remote TestInternalCache:tib21171737430669: list ''
2025/01/21 03:38:19 DEBUG : : list: cold listing: 2025-01-18 03:38:19.207829547 +0000 UTC
2025/01/21 03:38:19 DEBUG : : list: read 1 from source
2025/01/21 03:38:19 DEBUG : : list: source entries: [test]
2025/01/21 03:38:19 DEBUG : : list: cached directories: 0
2025/01/21 03:38:19 DEBUG : : list: cached dir: 'tib21171737430669', cache ts: 2025-01-21 03:38:19.209512326 +0000 UTC m=+39.869328352
2025/01/21 03:38:19 DEBUG : Cache remote TestInternalCache:tib21171737430669: list 'test'
2025/01/21 03:38:19 DEBUG : test: list: cold listing: 2025-01-18 03:38:19.207829547 +0000 UTC
2025/01/21 03:38:19 DEBUG : test: list: read 4 from source
2025/01/21 03:38:19 DEBUG : test: list: source entries: [test/dir3 test/dir2 test/dir4 test/dir1]
2025/01/21 03:38:19 DEBUG : test: list: cached directories: 0
2025/01/21 03:38:19 DEBUG : test: list: cached dir: 'tib21171737430669/test', cache ts: 2025-01-21 03:38:19.21087721 +0000 UTC m=+39.870693236
2025/01/21 03:38:19 DEBUG : Cache remote TestInternalCache:tib21171737430669: list 'test/dir4'
2025/01/21 03:38:19 DEBUG : Cache remote TestInternalCache:tib21171737430669: list 'test/dir2'
2025/01/21 03:38:19 DEBUG : test/dir2: list: cold listing: 2025-01-18 03:38:19.19582658 +0000 UTC
2025/01/21 03:38:19 DEBUG : test/dir2: list: read 4 from source
2025/01/21 03:38:19 DEBUG : test/dir2: list: source entries: [test/dir2/dir3 test/dir2/dir2 test/dir2/dir4 test/dir2/dir1]
2025/01/21 03:38:19 DEBUG : test/dir2: list: cached directories: 0
2025/01/21 03:38:19 DEBUG : Cache remote TestInternalCache:tib21171737430669: list 'test/dir1'
2025/01/21 03:38:19 DEBUG : Cache remote TestInternalCache:tib21171737430669: list 'test/dir3'
2025/01/21 03:38:19 DEBUG : test/dir1: list: cold listing: 2025-01-18 03:38:19.169540276 +0000 UTC
2025/01/21 03:38:19 DEBUG : test/dir1: list: read 4 from source
2025/01/21 03:38:19 DEBUG : test/dir1: list: source entries: [test/dir1/dir3 test/dir1/dir2 test/dir1/dir4 test/dir1/dir1]
2025/01/21 03:38:19 DEBUG : test/dir3: list: cold listing: 2025-01-18 03:38:19.207829547 +0000 UTC
2025/01/21 03:38:19 DEBUG : test/dir1: list: cached directories: 0
2025/01/21 03:38:19 DEBUG : test/dir3: list: read 4 from source
2025/01/21 03:38:19 DEBUG : test/dir3: list: source entries: [test/dir3/dir3 test/dir3/dir2 test/dir3/dir4 test/dir3/dir1]
2025/01/21 03:38:19 DEBUG : test/dir3: list: cached directories: 0
2025/01/21 03:38:19 DEBUG : test/dir4: list: cold listing: 2025-01-18 03:38:19.183345698 +0000 UTC
2025/01/21 03:38:19 DEBUG : test/dir4: list: read 4 from source
2025/01/21 03:38:19 DEBUG : test/dir4: list: source entries: [test/dir4/dir3 test/dir4/dir2 test/dir4/dir4 test/dir4/dir1]
2025/01/21 03:38:19 DEBUG : test/dir4: list: cached directories: 0
2025/01/21 03:38:19 DEBUG : test/dir2: list: cached dir: 'tib21171737430669/test/dir2', cache ts: 2025-01-21 03:38:19.212329497 +0000 UTC m=+39.872145523
2025/01/21 03:38:19 DEBUG : Cache remote TestInternalCache:tib21171737430669: list 'test/dir2/dir4'
2025/01/21 03:38:19 DEBUG : test/dir2/dir4: list: cold listing: 2025-01-18 03:38:19.19582658 +0000 UTC
2025/01/21 03:38:19 DEBUG : test/dir2/dir4: list: read 0 from source
2025/01/21 03:38:19 DEBUG : test/dir2/dir4: list: source entries: []
2025/01/21 03:38:19 DEBUG : test/dir2/dir4: list: cached directories: 0
2025/01/21 03:38:19 DEBUG : Cache remote TestInternalCache:tib21171737430669: list 'test/dir2/dir2'
2025/01/21 03:38:19 DEBUG : Cache remote TestInternalCache:tib21171737430669: list 'test/dir2/dir3'
2025/01/21 03:38:19 DEBUG : test/dir2/dir2: list: cold listing: 2025-01-18 03:38:19.190294949 +0000 UTC
2025/01/21 03:38:19 DEBUG : test/dir2/dir3: list: cold listing: 2025-01-18 03:38:19.192903309 +0000 UTC
2025/01/21 03:38:19 DEBUG : test/dir2/dir2: list: read 0 from source
2025/01/21 03:38:19 DEBUG : test/dir2/dir2: list: source entries: []
2025/01/21 03:38:19 DEBUG : test/dir2/dir2: list: cached directories: 0
2025/01/21 03:38:19 DEBUG : test/dir2/dir3: list: read 0 from source
2025/01/21 03:38:19 DEBUG : test/dir2/dir3: list: source entries: []
2025/01/21 03:38:19 DEBUG : test/dir2/dir3: list: cached directories: 0
2025/01/21 03:38:19 DEBUG : Cache remote TestInternalCache:tib21171737430669: list 'test/dir2/dir1'
2025/01/21 03:38:19 DEBUG : test/dir2/dir1: list: cold listing: 2025-01-18 03:38:19.18800712 +0000 UTC
2025/01/21 03:38:19 DEBUG : test/dir2/dir1: list: read 0 from source
2025/01/21 03:38:19 DEBUG : test/dir2/dir1: list: source entries: []
2025/01/21 03:38:19 DEBUG : test/dir2/dir1: list: cached directories: 0
2025/01/21 03:38:19 DEBUG : test/dir2/dir4: list: cached dir: 'tib21171737430669/test/dir2/dir4', cache ts: 2025-01-21 03:38:19.213645469 +0000 UTC m=+39.873461506
2025/01/21 03:38:19 DEBUG : test/dir1: list: cached dir: 'tib21171737430669/test/dir1', cache ts: 2025-01-21 03:38:19.21267831 +0000 UTC m=+39.872494346
2025/01/21 03:38:19 DEBUG : Cache remote TestInternalCache:tib21171737430669: list 'test/dir1/dir3'
2025/01/21 03:38:19 DEBUG : Cache remote TestInternalCache:tib21171737430669: list 'test/dir1/dir1'
2025/01/21 03:38:19 DEBUG : Cache remote TestInternalCache:tib21171737430669: list 'test/dir1/dir2'
2025/01/21 03:38:19 DEBUG : test/dir1/dir2: list: cold listing: 2025-01-18 03:38:19.120444328 +0000 UTC
2025/01/21 03:38:19 DEBUG : test/dir1/dir1: list: cold listing: 2025-01-18 03:38:19.164595786 +0000 UTC
2025/01/21 03:38:19 DEBUG : test/dir1/dir2: list: read 0 from source
2025/01/21 03:38:19 DEBUG : test/dir1/dir2: list: source entries: []
2025/01/21 03:38:19 DEBUG : test/dir1/dir2: list: cached directories: 0
2025/01/21 03:38:19 DEBUG : test/dir1/dir1: list: read 0 from source
2025/01/21 03:38:19 DEBUG : test/dir1/dir1: list: source entries: []
2025/01/21 03:38:19 DEBUG : test/dir1/dir1: list: cached directories: 0
2025/01/21 03:38:19 DEBUG : test/dir1/dir3: list: cold listing: 2025-01-18 03:38:19.169540276 +0000 UTC
2025/01/21 03:38:19 DEBUG : test/dir1/dir3: list: read 0 from source
2025/01/21 03:38:19 DEBUG : test/dir1/dir3: list: source entries: []
2025/01/21 03:38:19 DEBUG : test/dir1/dir3: list: cached directories: 0
2025/01/21 03:38:19 DEBUG : test/dir3: list: cached dir: 'tib21171737430669/test/dir3', cache ts: 2025-01-21 03:38:19.212762246 +0000 UTC m=+39.872578253
2025/01/21 03:38:19 DEBUG : Cache remote TestInternalCache:tib21171737430669: list 'test/dir1/dir4'
2025/01/21 03:38:19 DEBUG : test/dir1/dir4: list: cold listing: 2025-01-18 03:38:19.141600922 +0000 UTC
2025/01/21 03:38:19 DEBUG : test/dir1/dir4: list: read 0 from source
2025/01/21 03:38:19 DEBUG : test/dir1/dir4: list: source entries: []
2025/01/21 03:38:19 DEBUG : test/dir1/dir4: list: cached directories: 0
2025/01/21 03:38:19 DEBUG : test/dir4: list: cached dir: 'tib21171737430669/test/dir4', cache ts: 2025-01-21 03:38:19.21294582 +0000 UTC m=+39.872761856
2025/01/21 03:38:19 DEBUG : Cache remote TestInternalCache:tib21171737430669: list 'test/dir3/dir1'
2025/01/21 03:38:19 DEBUG : test/dir3/dir1: list: cold listing: 2025-01-18 03:38:19.201002333 +0000 UTC
2025/01/21 03:38:19 DEBUG : test/dir3/dir1: list: read 0 from source
2025/01/21 03:38:19 DEBUG : test/dir3/dir1: list: source entries: []
2025/01/21 03:38:19 DEBUG : test/dir3/dir1: list: cached directories: 0
2025/01/21 03:38:19 DEBUG : test/dir2/dir2: list: cached dir: 'tib21171737430669/test/dir2/dir2', cache ts: 2025-01-21 03:38:19.213855141 +0000 UTC m=+39.873671158
2025/01/21 03:38:19 DEBUG : Cache remote TestInternalCache:tib21171737430669: list 'test/dir3/dir2'
2025/01/21 03:38:19 DEBUG : test/dir3/dir2: list: cold listing: 2025-01-18 03:38:19.203010101 +0000 UTC
2025/01/21 03:38:19 DEBUG : test/dir3/dir2: list: read 0 from source
2025/01/21 03:38:19 DEBUG : test/dir3/dir2: list: source entries: []
2025/01/21 03:38:19 DEBUG : test/dir3/dir2: list: cached directories: 0
2025/01/21 03:38:19 DEBUG : test/dir2/dir3: list: cached dir: 'tib21171737430669/test/dir2/dir3', cache ts: 2025-01-21 03:38:19.213881611 +0000 UTC m=+39.873697647
2025/01/21 03:38:19 DEBUG : Cache remote TestInternalCache:tib21171737430669: list 'test/dir3/dir3'
2025/01/21 03:38:19 DEBUG : test/dir3/dir3: list: cold listing: 2025-01-18 03:38:19.205609023 +0000 UTC
2025/01/21 03:38:19 DEBUG : test/dir3/dir3: list: read 0 from source
2025/01/21 03:38:19 DEBUG : test/dir3/dir3: list: source entries: []
2025/01/21 03:38:19 DEBUG : test/dir3/dir3: list: cached directories: 0
2025/01/21 03:38:19 DEBUG : test/dir2/dir1: list: cached dir: 'tib21171737430669/test/dir2/dir1', cache ts: 2025-01-21 03:38:19.214014279 +0000 UTC m=+39.873830305
2025/01/21 03:38:19 DEBUG : Cache remote TestInternalCache:tib21171737430669: list 'test/dir3/dir4'
2025/01/21 03:38:19 DEBUG : test/dir3/dir4: list: cold listing: 2025-01-18 03:38:19.207829547 +0000 UTC
2025/01/21 03:38:19 DEBUG : test/dir3/dir4: list: read 0 from source
2025/01/21 03:38:19 DEBUG : test/dir3/dir4: list: source entries: []
2025/01/21 03:38:19 DEBUG : test/dir3/dir4: list: cached directories: 0
2025/01/21 03:38:19 DEBUG : test/dir1/dir2: list: cached dir: 'tib21171737430669/test/dir1/dir2', cache ts: 2025-01-21 03:38:19.216313472 +0000 UTC m=+39.876129487
2025/01/21 03:38:19 DEBUG : Cache remote TestInternalCache:tib21171737430669: list 'test/dir4/dir1'
2025/01/21 03:38:19 DEBUG : test/dir4/dir1: list: cold listing: 2025-01-18 03:38:19.173515836 +0000 UTC
2025/01/21 03:38:19 DEBUG : test/dir4/dir1: list: read 0 from source
2025/01/21 03:38:19 DEBUG : test/dir4/dir1: list: source entries: []
2025/01/21 03:38:19 DEBUG : test/dir4/dir1: list: cached directories: 0
2025/01/21 03:38:19 DEBUG : test/dir1/dir1: list: cached dir: 'tib21171737430669/test/dir1/dir1', cache ts: 2025-01-21 03:38:19.216354768 +0000 UTC m=+39.876170794
2025/01/21 03:38:19 DEBUG : Cache remote TestInternalCache:tib21171737430669: list 'test/dir4/dir2'
2025/01/21 03:38:19 DEBUG : test/dir4/dir2: list: cold listing: 2025-01-18 03:38:19.180237932 +0000 UTC
2025/01/21 03:38:19 DEBUG : test/dir4/dir2: list: read 0 from source
2025/01/21 03:38:19 DEBUG : test/dir4/dir2: list: source entries: []
2025/01/21 03:38:19 DEBUG : test/dir4/dir2: list: cached directories: 0
2025/01/21 03:38:19 DEBUG : test/dir1/dir3: list: cached dir: 'tib21171737430669/test/dir1/dir3', cache ts: 2025-01-21 03:38:19.216549864 +0000 UTC m=+39.876365890
2025/01/21 03:38:19 DEBUG : Cache remote TestInternalCache:tib21171737430669: list 'test/dir4/dir3'
2025/01/21 03:38:19 DEBUG : test/dir4/dir3: list: cold listing: 2025-01-18 03:38:19.176920625 +0000 UTC
2025/01/21 03:38:19 DEBUG : test/dir4/dir3: list: read 0 from source
2025/01/21 03:38:19 DEBUG : test/dir4/dir3: list: source entries: []
2025/01/21 03:38:19 DEBUG : test/dir4/dir3: list: cached directories: 0
2025/01/21 03:38:19 DEBUG : test/dir3/dir1: list: cached dir: 'tib21171737430669/test/dir3/dir1', cache ts: 2025-01-21 03:38:19.219239625 +0000 UTC m=+39.879055651
2025/01/21 03:38:19 DEBUG : Cache remote TestInternalCache:tib21171737430669: list 'test/dir4/dir4'
2025/01/21 03:38:19 DEBUG : test/dir4/dir4: list: cold listing: 2025-01-18 03:38:19.183345698 +0000 UTC
2025/01/21 03:38:19 DEBUG : test/dir4/dir4: list: read 0 from source
2025/01/21 03:38:19 DEBUG : test/dir4/dir4: list: source entries: []
2025/01/21 03:38:19 DEBUG : test/dir4/dir4: list: cached directories: 0
2025/01/21 03:38:19 DEBUG : test/dir1/dir4: list: cached dir: 'tib21171737430669/test/dir1/dir4', cache ts: 2025-01-21 03:38:19.217433397 +0000 UTC m=+39.877249423
2025/01/21 03:38:19 DEBUG : test/dir3/dir2: list: cached dir: 'tib21171737430669/test/dir3/dir2', cache ts: 2025-01-21 03:38:19.220573251 +0000 UTC m=+39.880389287
2025/01/21 03:38:19 DEBUG : test/dir3/dir3: list: cached dir: 'tib21171737430669/test/dir3/dir3', cache ts: 2025-01-21 03:38:19.221995943 +0000 UTC m=+39.881811969
2025/01/21 03:38:19 DEBUG : test/dir3/dir4: list: cached dir: 'tib21171737430669/test/dir3/dir4', cache ts: 2025-01-21 03:38:19.22310032 +0000 UTC m=+39.882916346
2025/01/21 03:38:19 DEBUG : test/dir4/dir1: list: cached dir: 'tib21171737430669/test/dir4/dir1', cache ts: 2025-01-21 03:38:19.224111451 +0000 UTC m=+39.883927477
2025/01/21 03:38:19 DEBUG : test/dir4/dir2: list: cached dir: 'tib21171737430669/test/dir4/dir2', cache ts: 2025-01-21 03:38:19.22608808 +0000 UTC m=+39.885904106
2025/01/21 03:38:19 DEBUG : test/dir4/dir3: list: cached dir: 'tib21171737430669/test/dir4/dir3', cache ts: 2025-01-21 03:38:19.226373304 +0000 UTC m=+39.886189340
2025/01/21 03:38:19 DEBUG : test/dir4/dir4: list: cached dir: 'tib21171737430669/test/dir4/dir4', cache ts: 2025-01-21 03:38:19.228859294 +0000 UTC m=+39.888675320
2025/01/21 03:38:19 DEBUG : removing 16 level 3 directories
2025/01/21 03:38:19 INFO  : test/dir2/dir4: Removing directory
2025/01/21 03:38:19 DEBUG : Cache remote TestInternalCache:tib21171737430669: rmdir 'test/dir2/dir4'
2025/01/21 03:38:19 DEBUG : test/dir2/dir4: rmdir: removed dir in source fs
2025/01/21 03:38:19 INFO  : test/dir1/dir4: Removing directory
2025/01/21 03:38:19 DEBUG : Cache remote TestInternalCache:tib21171737430669: rmdir 'test/dir1/dir4'
2025/01/21 03:38:19 DEBUG : test/dir1/dir4: rmdir: removed dir in source fs
2025/01/21 03:38:19 INFO  : test/dir1/dir1: Removing directory
2025/01/21 03:38:19 DEBUG : Cache remote TestInternalCache:tib21171737430669: rmdir 'test/dir1/dir1'
2025/01/21 03:38:19 DEBUG : test/dir1/dir1: rmdir: removed dir in source fs
2025/01/21 03:38:19 INFO  : test/dir1/dir2: Removing directory
2025/01/21 03:38:19 DEBUG : Cache remote TestInternalCache:tib21171737430669: rmdir 'test/dir1/dir2'
2025/01/21 03:38:19 DEBUG : test/dir1/dir2: rmdir: removed dir in source fs
2025/01/21 03:38:19 INFO  : test/dir1/dir3: Removing directory
2025/01/21 03:38:19 DEBUG : Cache remote TestInternalCache:tib21171737430669: rmdir 'test/dir1/dir3'
2025/01/21 03:38:19 DEBUG : test/dir1/dir3: rmdir: removed dir in source fs
2025/01/21 03:38:19 INFO  : test/dir2/dir2: Removing directory
2025/01/21 03:38:19 DEBUG : Cache remote TestInternalCache:tib21171737430669: rmdir 'test/dir2/dir2'
2025/01/21 03:38:19 DEBUG : test/dir2/dir2: rmdir: removed dir in source fs
2025/01/21 03:38:19 INFO  : test/dir2/dir1: Removing directory
2025/01/21 03:38:19 DEBUG : Cache remote TestInternalCache:tib21171737430669: rmdir 'test/dir2/dir1'
2025/01/21 03:38:19 DEBUG : test/dir2/dir1: rmdir: removed dir in source fs
2025/01/21 03:38:19 INFO  : test/dir2/dir3: Removing directory
2025/01/21 03:38:19 DEBUG : Cache remote TestInternalCache:tib21171737430669: rmdir 'test/dir2/dir3'
2025/01/21 03:38:19 DEBUG : test/dir2/dir3: rmdir: removed dir in source fs
2025/01/21 03:38:19 DEBUG : test/dir2/dir4: rmdir: removed from cache
2025/01/21 03:38:19 DEBUG : test/dir2: cache: expired tib21171737430669/test/dir2
2025/01/21 03:38:19 DEBUG : test/dir2: cache: expired tib21171737430669/test
2025/01/21 03:38:19 DEBUG : test/dir2: cache: expired tib21171737430669
2025/01/21 03:38:19 INFO  : test/dir2: rmdir: cache expired
2025/01/21 03:38:19 INFO  : test/dir3/dir1: Removing directory
2025/01/21 03:38:19 DEBUG : Cache remote TestInternalCache:tib21171737430669: rmdir 'test/dir3/dir1'
2025/01/21 03:38:19 DEBUG : test/dir3/dir1: rmdir: removed dir in source fs
2025/01/21 03:38:19 DEBUG : test/dir1/dir4: rmdir: removed from cache
2025/01/21 03:38:19 DEBUG : test/dir1/dir1: rmdir: removed from cache
2025/01/21 03:38:19 DEBUG : test/dir1/dir2: rmdir: removed from cache
2025/01/21 03:38:19 DEBUG : test/dir1/dir3: rmdir: removed from cache
2025/01/21 03:38:19 DEBUG : test/dir2/dir2: rmdir: removed from cache
2025/01/21 03:38:19 DEBUG : test/dir2/dir1: rmdir: removed from cache
2025/01/21 03:38:19 DEBUG : test/dir2/dir3: rmdir: removed from cache
2025/01/21 03:38:19 DEBUG : test/dir3/dir1: rmdir: removed from cache
2025/01/21 03:38:19 DEBUG : test/dir1: cache: expired tib21171737430669/test/dir1
2025/01/21 03:38:19 DEBUG : test/dir1: cache: expired tib21171737430669/test
2025/01/21 03:38:19 DEBUG : test/dir1: cache: expired tib21171737430669
2025/01/21 03:38:19 INFO  : test/dir1: rmdir: cache expired
2025/01/21 03:38:19 DEBUG : test/dir1: cache: expired tib21171737430669/test/dir1
2025/01/21 03:38:19 DEBUG : test/dir1: cache: expired tib21171737430669/test
2025/01/21 03:38:19 DEBUG : test/dir1: cache: expired tib21171737430669
2025/01/21 03:38:19 INFO  : test/dir3/dir2: Removing directory
2025/01/21 03:38:19 DEBUG : Cache remote TestInternalCache:tib21171737430669: rmdir 'test/dir3/dir2'
2025/01/21 03:38:19 DEBUG : test/dir3/dir2: rmdir: removed dir in source fs
2025/01/21 03:38:19 INFO  : test/dir1: rmdir: cache expired
2025/01/21 03:38:19 DEBUG : test/dir1: cache: expired tib21171737430669/test/dir1
2025/01/21 03:38:19 DEBUG : test/dir1: cache: expired tib21171737430669/test
2025/01/21 03:38:19 INFO  : test/dir3/dir3: Removing directory
2025/01/21 03:38:19 DEBUG : Cache remote TestInternalCache:tib21171737430669: rmdir 'test/dir3/dir3'
2025/01/21 03:38:19 DEBUG : test/dir1: cache: expired tib21171737430669
2025/01/21 03:38:19 DEBUG : test/dir3/dir3: rmdir: removed dir in source fs
2025/01/21 03:38:19 INFO  : test/dir1: rmdir: cache expired
2025/01/21 03:38:19 DEBUG : test/dir1: cache: expired tib21171737430669/test/dir1
2025/01/21 03:38:19 INFO  : test/dir3/dir4: Removing directory
2025/01/21 03:38:19 DEBUG : test/dir1: cache: expired tib21171737430669/test
2025/01/21 03:38:19 DEBUG : Cache remote TestInternalCache:tib21171737430669: rmdir 'test/dir3/dir4'
2025/01/21 03:38:19 DEBUG : test/dir1: cache: expired tib21171737430669
2025/01/21 03:38:19 DEBUG : test/dir3/dir4: rmdir: removed dir in source fs
2025/01/21 03:38:19 INFO  : test/dir1: rmdir: cache expired
2025/01/21 03:38:19 DEBUG : test/dir2: cache: expired tib21171737430669/test/dir2
2025/01/21 03:38:19 INFO  : test/dir4/dir1: Removing directory
2025/01/21 03:38:19 DEBUG : test/dir2: cache: expired tib21171737430669/test
2025/01/21 03:38:19 DEBUG : Cache remote TestInternalCache:tib21171737430669: rmdir 'test/dir4/dir1'
2025/01/21 03:38:19 DEBUG : test/dir2: cache: expired tib21171737430669
2025/01/21 03:38:19 DEBUG : test/dir4/dir1: rmdir: removed dir in source fs
2025/01/21 03:38:19 DEBUG : test/dir2: cache: expired tib21171737430669/test/dir2
2025/01/21 03:38:19 DEBUG : test/dir2: cache: expired tib21171737430669/test
2025/01/21 03:38:19 DEBUG : test/dir2: cache: expired tib21171737430669
2025/01/21 03:38:19 INFO  : test/dir2: rmdir: cache expired
2025/01/21 03:38:19 INFO  : test/dir4/dir2: Removing directory
2025/01/21 03:38:19 DEBUG : Cache remote TestInternalCache:tib21171737430669: rmdir 'test/dir4/dir2'
2025/01/21 03:38:19 DEBUG : test/dir4/dir2: rmdir: removed dir in source fs
2025/01/21 03:38:19 DEBUG : test/dir2: cache: expired tib21171737430669/test/dir2
2025/01/21 03:38:19 INFO  : test/dir2: rmdir: cache expired
2025/01/21 03:38:19 DEBUG : test/dir2: cache: expired tib21171737430669/test
2025/01/21 03:38:19 INFO  : test/dir4/dir3: Removing directory
2025/01/21 03:38:19 DEBUG : test/dir2: cache: expired tib21171737430669
2025/01/21 03:38:19 DEBUG : Cache remote TestInternalCache:tib21171737430669: rmdir 'test/dir4/dir3'
2025/01/21 03:38:19 DEBUG : test/dir4/dir3: rmdir: removed dir in source fs
2025/01/21 03:38:19 DEBUG : test/dir3: cache: expired tib21171737430669/test/dir3
2025/01/21 03:38:19 INFO  : test/dir2: rmdir: cache expired
2025/01/21 03:38:19 DEBUG : test/dir3: cache: expired tib21171737430669/test
2025/01/21 03:38:19 INFO  : test/dir4/dir4: Removing directory
2025/01/21 03:38:19 DEBUG : Cache remote TestInternalCache:tib21171737430669: rmdir 'test/dir4/dir4'
2025/01/21 03:38:19 DEBUG : test/dir3: cache: expired tib21171737430669
2025/01/21 03:38:19 DEBUG : test/dir4/dir4: rmdir: removed dir in source fs
2025/01/21 03:38:19 INFO  : test/dir3: rmdir: cache expired
2025/01/21 03:38:19 DEBUG : test/dir3/dir2: rmdir: removed from cache
2025/01/21 03:38:19 DEBUG : test/dir3/dir3: rmdir: removed from cache
2025/01/21 03:38:19 DEBUG : test/dir3/dir4: rmdir: removed from cache
2025/01/21 03:38:19 DEBUG : test/dir4/dir1: rmdir: removed from cache
2025/01/21 03:38:19 DEBUG : test/dir4/dir2: rmdir: removed from cache
2025/01/21 03:38:19 DEBUG : test/dir4/dir3: rmdir: removed from cache
2025/01/21 03:38:19 DEBUG : test/dir3: cache: expired tib21171737430669/test/dir3
2025/01/21 03:38:19 DEBUG : test/dir3: cache: expired tib21171737430669/test
2025/01/21 03:38:19 DEBUG : test/dir3: cache: expired tib21171737430669
2025/01/21 03:38:19 DEBUG : test/dir4/dir4: rmdir: removed from cache
2025/01/21 03:38:19 DEBUG : test/dir3: cache: expired tib21171737430669/test/dir3
2025/01/21 03:38:19 DEBUG : test/dir3: cache: expired tib21171737430669/test
2025/01/21 03:38:19 DEBUG : test/dir3: cache: expired tib21171737430669
2025/01/21 03:38:19 INFO  : test/dir3: rmdir: cache expired
2025/01/21 03:38:19 DEBUG : test/dir3: cache: expired tib21171737430669/test/dir3
2025/01/21 03:38:19 DEBUG : test/dir3: cache: expired tib21171737430669/test
2025/01/21 03:38:19 DEBUG : test/dir3: cache: expired tib21171737430669
2025/01/21 03:38:19 INFO  : test/dir3: rmdir: cache expired
2025/01/21 03:38:19 DEBUG : test/dir4: cache: expired tib21171737430669/test/dir4
2025/01/21 03:38:19 DEBUG : test/dir4: cache: expired tib21171737430669/test
2025/01/21 03:38:19 DEBUG : test/dir4: cache: expired tib21171737430669
2025/01/21 03:38:19 INFO  : test/dir3: rmdir: cache expired
2025/01/21 03:38:19 DEBUG : test/dir4: cache: expired tib21171737430669/test/dir4
2025/01/21 03:38:19 DEBUG : test/dir4: cache: expired tib21171737430669/test
2025/01/21 03:38:19 INFO  : test/dir4: rmdir: cache expired
2025/01/21 03:38:19 DEBUG : test/dir4: cache: expired tib21171737430669
2025/01/21 03:38:19 DEBUG : test/dir4: cache: expired tib21171737430669/test/dir4
2025/01/21 03:38:19 DEBUG : test/dir4: cache: expired tib21171737430669/test
2025/01/21 03:38:19 DEBUG : test/dir4: cache: expired tib21171737430669
2025/01/21 03:38:19 INFO  : test/dir4: rmdir: cache expired
2025/01/21 03:38:19 DEBUG : test/dir4: cache: expired tib21171737430669/test/dir4
2025/01/21 03:38:19 DEBUG : test/dir4: cache: expired tib21171737430669/test
2025/01/21 03:38:19 DEBUG : test/dir4: cache: expired tib21171737430669
2025/01/21 03:38:19 INFO  : test/dir4: rmdir: cache expired
2025/01/21 03:38:19 INFO  : test/dir4: rmdir: cache expired
2025/01/21 03:38:19 DEBUG : removing 4 level 2 directories
2025/01/21 03:38:19 INFO  : test/dir4: Removing directory
2025/01/21 03:38:19 DEBUG : Cache remote TestInternalCache:tib21171737430669: rmdir 'test/dir4'
2025/01/21 03:38:19 INFO  : test/dir2: Removing directory
2025/01/21 03:38:19 DEBUG : Cache remote TestInternalCache:tib21171737430669: rmdir 'test/dir2'
2025/01/21 03:38:19 INFO  : test/dir1: Removing directory
2025/01/21 03:38:19 DEBUG : Cache remote TestInternalCache:tib21171737430669: rmdir 'test/dir1'
2025/01/21 03:38:19 INFO  : test/dir3: Removing directory
2025/01/21 03:38:19 DEBUG : Cache remote TestInternalCache:tib21171737430669: rmdir 'test/dir3'
2025/01/21 03:38:19 DEBUG : test/dir2: rmdir: removed dir in source fs
2025/01/21 03:38:19 DEBUG : test/dir1: rmdir: removed dir in source fs
2025/01/21 03:38:19 DEBUG : test/dir3: rmdir: removed dir in source fs
2025/01/21 03:38:19 DEBUG : test/dir4: rmdir: removed dir in source fs
2025/01/21 03:38:19 DEBUG : test/dir2: rmdir: removed from cache
2025/01/21 03:38:19 DEBUG : test: cache: expired tib21171737430669/test
2025/01/21 03:38:19 DEBUG : test: cache: expired tib21171737430669
2025/01/21 03:38:19 INFO  : test: rmdir: cache expired
2025/01/21 03:38:19 DEBUG : test/dir1: rmdir: removed from cache
2025/01/21 03:38:19 DEBUG : test/dir3: rmdir: removed from cache
2025/01/21 03:38:19 DEBUG : test: cache: expired tib21171737430669/test
2025/01/21 03:38:19 DEBUG : test: cache: expired tib21171737430669
2025/01/21 03:38:19 DEBUG : test/dir4: rmdir: removed from cache
2025/01/21 03:38:19 INFO  : test: rmdir: cache expired
2025/01/21 03:38:19 DEBUG : test: cache: expired tib21171737430669/test
2025/01/21 03:38:19 DEBUG : test: cache: expired tib21171737430669
2025/01/21 03:38:19 DEBUG : test: cache: expired tib21171737430669/test
2025/01/21 03:38:19 DEBUG : test: cache: expired tib21171737430669
2025/01/21 03:38:19 INFO  : test: rmdir: cache expired
2025/01/21 03:38:19 INFO  : test: rmdir: cache expired
2025/01/21 03:38:19 DEBUG : removing 1 level 1 directories
2025/01/21 03:38:19 INFO  : test: Removing directory
2025/01/21 03:38:19 DEBUG : Cache remote TestInternalCache:tib21171737430669: rmdir 'test'
2025/01/21 03:38:19 DEBUG : test: rmdir: removed dir in source fs
2025/01/21 03:38:19 DEBUG : test: rmdir: removed from cache
2025/01/21 03:38:19 DEBUG : : cache: expired tib21171737430669
2025/01/21 03:38:19 INFO  : : rmdir: cache expired
2025/01/21 03:38:19 DEBUG : removing 1 level 0 directories
2025/01/21 03:38:19 INFO  : Cache remote TestInternalCache:tib21171737430669: Removing directory
2025/01/21 03:38:19 DEBUG : Cache remote TestInternalCache:tib21171737430669: rmdir ''
2025/01/21 03:38:19 DEBUG : : rmdir: removed dir in source fs
2025/01/21 03:38:19 DEBUG : : rmdir: removed from cache
2025/01/21 03:38:19 INFO  : : rmdir: cache expired
2025/01/21 03:38:19 DEBUG : Cache remote TestInternalCache:tib21171737430669: Services stopped
--- PASS: TestInternalBug2117 (30.27s)
=== RUN   TestIntegration
    fstests.go:442: Using remote "TestCache:"
2025/01/21 03:38:19 DEBUG : Creating backend with remote "TestCache:rclone-test-hamekex8rono"
2025/01/21 03:38:19 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2025/01/21 03:38:19 DEBUG : Setting cache db_wait_time="30m" from environment variable RCLONE_CACHE_DB_WAIT_TIME
2025/01/21 03:38:19 DEBUG : TestCache: detected overridden config - adding "{VDL3R}" suffix to name
2025/01/21 03:38:19 DEBUG : Setting cache db_wait_time="30m" from environment variable RCLONE_CACHE_DB_WAIT_TIME
2025/01/21 03:38:19 DEBUG : Creating backend with remote "/tmp/rclone_cache_test/rclone-test-hamekex8rono"
2025/01/21 03:38:19 DEBUG : TestCache{VDL3R}: wrapped local:/tmp/rclone_cache_test/rclone-test-hamekex8rono at root rclone-test-hamekex8rono
2025/01/21 03:38:19 INFO  : TestCache{VDL3R}: Cache DB path: /home/rclone/.cache/rclone/cache-backend/TestCache{VDL3R}.db
2025/01/21 03:38:19 INFO  : TestCache{VDL3R}: Cache chunk path: /home/rclone/.cache/rclone/cache-backend/TestCache{VDL3R}
2025/01/21 03:38:39 INFO  : Cache remote TestInternalCache:tionf1737430659: stopping cleanup
2025/01/21 03:38:39 INFO  : Cache remote TestInternalCache:ticwcm1737430659: stopping cleanup
2025/01/21 03:38:40 INFO  : Cache remote TestInternalCache:tidwcm1737430660: stopping cleanup
2025/01/21 03:38:41 INFO  : Cache remote TestInternalCache:ticucm1737430661: stopping cleanup
2025/01/21 03:38:41 INFO  : Cache remote TestInternalCache:tiwfcns1737430661: stopping cleanup
2025/01/21 03:38:42 INFO  : Cache remote TestInternalCache:timwn1737430662: stopping cleanup
2025/01/21 03:38:42 INFO  : Cache remote TestInternalCache:tincep1737430662: stopping cleanup
2025/01/21 03:38:42 INFO  : Cache remote TestInternalCache:ticsadcf1737430662: stopping cleanup
2025/01/21 03:38:42 INFO  : Cache remote TestInternalCache:ticw: stopping cleanup
2025/01/21 03:38:43 INFO  : Cache remote TestInternalCache:timcsr1737430663: stopping cleanup
2025/01/21 03:52:49 INFO  : Cache remote TestInternalCache:tib21171737430669: stopping cleanup
2025/01/21 04:08:19 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:466: 
        	Error Trace:	/home/rclone/go/src/github.com/rclone/rclone/fstest/fstests/fstests.go:466
        	            				/home/rclone/go/src/github.com/rclone/rclone/backend/cache/cache_test.go:17
        	Error:      	Received unexpected error:
        	            	failed to start cache db: failed to open a cache connection to "/home/rclone/.cache/rclone/cache-backend/TestCache{VDL3R}.db": timeout
        	Test:       	TestIntegration
        	Messages:   	unexpected error: failed to start cache db: failed to open a cache connection to "/home/rclone/.cache/rclone/cache-backend/TestCache{VDL3R}.db": timeout
--- FAIL: TestIntegration (1799.96s)
=== RUN   TestInternalUploadTempDirCreated
2025/01/21 04:08:19 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2025/01/21 04:08:19 DEBUG : Creating backend with remote "TestInternalCache-local:/tmp/TestInternalCache-local/tiutdc1737432499"
2025/01/21 04:08:19 DEBUG : TestInternalCache: wrapped TestInternalCache-local:/tmp/TestInternalCache-local/tiutdc1737432499 at root tiutdc1737432499
2025/01/21 04:08:19 INFO  : TestInternalCache: Cache DB path: /home/rclone/.cache/rclone/cache-backend/TestInternalCache.db
2025/01/21 04:08:19 INFO  : TestInternalCache: Cache chunk path: /home/rclone/.cache/rclone/cache-backend/TestInternalCache
2025/01/21 04:08:19 INFO  : TestInternalCache: Chunk Memory: true
2025/01/21 04:08:19 INFO  : TestInternalCache: Chunk Size: 5Mi
2025/01/21 04:08:19 INFO  : TestInternalCache: Chunk Total Size: 10Gi
2025/01/21 04:08:19 INFO  : TestInternalCache: Chunk Clean Interval: 1m0s
2025/01/21 04:08:19 INFO  : TestInternalCache: Workers: 4
2025/01/21 04:08:19 INFO  : TestInternalCache: File Age: 6h0m0s
2025/01/21 04:08:19 DEBUG : Creating backend with remote "/tmp/rclonecache-tmp2620681130/tiutdc1737432499"
2025/01/21 04:08:19 INFO  : TestInternalCache: Upload Temp Rest Time: 15s
2025/01/21 04:08:19 INFO  : TestInternalCache: Upload Temp FS: /tmp/rclonecache-tmp2620681130/tiutdc1737432499
2025/01/21 04:08:19 DEBUG : Waiting for deletions to finish
2025/01/21 04:08:19 DEBUG : Cache remote TestInternalCache:tiutdc1737432499: list ''
2025/01/21 04:08:19 DEBUG : : list: error: couldn't open bucket (tiutdc1737432499)
2025/01/21 04:08:19 DEBUG : : list: read 0 from temp fs
2025/01/21 04:08:19 DEBUG : : list: temp fs entries: []
2025/01/21 04:08:19 ERROR : : error listing: directory not found
2025/01/21 04:08:19 DEBUG : Cache remote TestInternalCache:tiutdc1737432499: list ''
2025/01/21 04:08:19 DEBUG : : list: error: couldn't open bucket (tiutdc1737432499)
2025/01/21 04:08:19 DEBUG : : list: read 0 from temp fs
2025/01/21 04:08:19 DEBUG : : list: temp fs entries: []
2025/01/21 04:08:19 ERROR : Cache remote TestInternalCache:tiutdc1737432499: Failed to list "": directory not found
2025/01/21 04:08:19 DEBUG : removing 1 level 0 directories
2025/01/21 04:08:19 INFO  : Cache remote TestInternalCache:tiutdc1737432499: Removing directory
2025/01/21 04:08:19 DEBUG : Cache remote TestInternalCache:tiutdc1737432499: rmdir ''
2025/01/21 04:08:20 DEBUG : : rmdir: read 0 from temp fs
2025/01/21 04:08:20 DEBUG : : rmdir: temp fs entries: []
2025/01/21 04:08:20 DEBUG : tiutdc1737432499: couldn't delete from cache: bucket not found
2025/01/21 04:08:20 DEBUG : : rmdir: removed from cache
2025/01/21 04:08:20 INFO  : : rmdir: cache expired
2025/01/21 04:08:20 DEBUG : Cache remote TestInternalCache:tiutdc1737432499: mkdir ''
2025/01/21 04:08:20 DEBUG : : mkdir: created dir in source fs
2025/01/21 04:08:20 DEBUG : : mkdir: added to cache
2025/01/21 04:08:20 DEBUG : : cache: expired tiutdc1737432499
2025/01/21 04:08:20 INFO  : : mkdir: cache expired
2025/01/21 04:08:20 DEBUG : Waiting for deletions to finish
2025/01/21 04:08:20 DEBUG : Cache remote TestInternalCache:tiutdc1737432499: list ''
2025/01/21 04:08:20 DEBUG : : list: cold listing: 2025-01-20 22:08:20.764909624 +0000 UTC
2025/01/21 04:08:20 DEBUG : : list: read 0 from temp fs
2025/01/21 04:08:20 DEBUG : : list: temp fs entries: []
2025/01/21 04:08:20 DEBUG : : list: read 0 from source
2025/01/21 04:08:20 DEBUG : : list: source entries: []
2025/01/21 04:08:20 DEBUG : : list: cached directories: 0
2025/01/21 04:08:20 DEBUG : : list: cached dir: 'tiutdc1737432499', cache ts: 2025-01-21 04:08:20.766749904 +0000 UTC m=+1841.426565951
2025/01/21 04:08:20 DEBUG : Cache remote TestInternalCache:tiutdc1737432499: list ''
2025/01/21 04:08:20 DEBUG : : list: empty listing
2025/01/21 04:08:20 DEBUG : : list: read 0 from temp fs
2025/01/21 04:08:20 DEBUG : : list: temp fs entries: []
2025/01/21 04:08:20 DEBUG : : list: read 0 from source
2025/01/21 04:08:20 DEBUG : : list: source entries: []
2025/01/21 04:08:20 DEBUG : : list: cached directories: 0
2025/01/21 04:08:20 DEBUG : : list: cached dir: 'tiutdc1737432499', cache ts: 2025-01-21 04:08:20.768246474 +0000 UTC m=+1841.428062510
2025/01/21 04:08:20 DEBUG : removing 1 level 0 directories
2025/01/21 04:08:20 INFO  : Cache remote TestInternalCache:tiutdc1737432499: Removing directory
2025/01/21 04:08:20 DEBUG : Cache remote TestInternalCache:tiutdc1737432499: rmdir ''
2025/01/21 04:08:21 DEBUG : : rmdir: removed dir in source fs
2025/01/21 04:08:21 DEBUG : : rmdir: read 0 from temp fs
2025/01/21 04:08:21 DEBUG : : rmdir: temp fs entries: []
2025/01/21 04:08:21 DEBUG : : rmdir: removed from cache
2025/01/21 04:08:21 INFO  : : rmdir: cache expired
2025/01/21 04:08:23 DEBUG : Cache remote TestInternalCache:tiutdc1737432499: Services stopped
--- PASS: TestInternalUploadTempDirCreated (4.02s)
=== RUN   TestInternalUploadQueueOneFileNoRest
2025/01/21 04:08:23 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/01/21 04:08:23 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/01/21 04:08:23 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/01/21 04:08:23 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/01/21 04:08:23 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/01/21 04:08:23 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/01/21 04:08:23 DEBUG : Using config file from "/home/rclone/.rclone.conf"
    cache_internal_test.go:858: Need remote (TestInternalCache) to exist
--- SKIP: TestInternalUploadUploadingFileOperations (0.00s)
FAIL
exit status 1
FAIL	github.com/rclone/rclone/backend/cache	1843.955s
"go test -v -timeout 1h0m0s -remote TestCache: -verbose" - Finished ERROR in 30m45.606117526s (try 1/5): exit status 1: Failed [TestIntegration]