"./operations.test -test.v -test.timeout 1h0m0s -remote TestOracleObjectStorage: -verbose" - Starting (try 1/5)
2025/06/29 01:20:09 DEBUG : Creating backend with remote "TestOracleObjectStorage:rclone-test-hegagis7kado"
2025/06/29 01:20:09 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2025/06/29 01:20:09 DEBUG : Creating backend with remote "/tmp/rclone1744522841"
=== RUN   TestDoMultiThreadCopy
--- PASS: TestDoMultiThreadCopy (0.00s)
=== RUN   TestMultithreadCalculateNumChunks
=== RUN   TestMultithreadCalculateNumChunks/{size:1_chunkSize:65536_wantNumChunks:1}
=== RUN   TestMultithreadCalculateNumChunks/{size:1048576_chunkSize:1_wantNumChunks:1048576}
=== RUN   TestMultithreadCalculateNumChunks/{size:1048576_chunkSize:2_wantNumChunks:524288}
=== RUN   TestMultithreadCalculateNumChunks/{size:1048577_chunkSize:2_wantNumChunks:524289}
=== RUN   TestMultithreadCalculateNumChunks/{size:1048575_chunkSize:2_wantNumChunks:524288}
--- PASS: TestMultithreadCalculateNumChunks (0.00s)
    --- PASS: TestMultithreadCalculateNumChunks/{size:1_chunkSize:65536_wantNumChunks:1} (0.00s)
    --- PASS: TestMultithreadCalculateNumChunks/{size:1048576_chunkSize:1_wantNumChunks:1048576} (0.00s)
    --- PASS: TestMultithreadCalculateNumChunks/{size:1048576_chunkSize:2_wantNumChunks:524288} (0.00s)
    --- PASS: TestMultithreadCalculateNumChunks/{size:1048577_chunkSize:2_wantNumChunks:524289} (0.00s)
    --- PASS: TestMultithreadCalculateNumChunks/{size:1048575_chunkSize:2_wantNumChunks:524288} (0.00s)
=== RUN   TestMultithreadCopy
    run.go:180: Remote "oos:bucket rclone-test-hegagis7kado", Local "Local file system at /tmp/rclone1744522841", Modify Window "1ms"
2025/06/29 01:20:09 INFO  : oos:bucket rclone-test-hegagis7kado: Bucket "rclone-test-hegagis7kado" created with accessType "NoPublicAccess"
2025/06/29 01:20:09 DEBUG : chunksize-probe: created new upload id: 8f0e76b8-3160-7f08-2f3b-ce23c94c4182
2025/06/29 01:20:09 DEBUG : chunksize-probe: open chunk writer: started multipart upload: 8f0e76b8-3160-7f08-2f3b-ce23c94c4182
2025/06/29 01:20:09 DEBUG : chunksize-probe: Cancelling multipart upload
2025/06/29 01:20:09 DEBUG : chunksize-probe: canceled and aborted multipart upload: 8f0e76b8-3160-7f08-2f3b-ce23c94c4182
=== RUN   TestMultithreadCopy/upload=false,size=10485759,streams=2
2025/06/29 01:20:10 DEBUG : test-multithread-copy-false-10485759-2: trying to read metadata test-multithread-copy-false-10485759-2
2025/06/29 01:20:11 DEBUG : test-multithread-copy-false-10485759-2: trying to read metadata test-multithread-copy-false-10485759-2
2025/06/29 01:20:11 DEBUG : test-multithread-copy-false-10485759-2: trying to read metadata test-multithread-copy-false-10485759-2
2025/06/29 01:20:11 DEBUG : test-multithread-copy-false-10485759-2: trying to read metadata test-multithread-copy-false-10485759-2
2025/06/29 01:20:11 DEBUG : test-multithread-copy-false-10485759-2: multi-thread copy: disabling buffering because destination uses OpenWriterAt
2025/06/29 01:20:11 DEBUG : test-multithread-copy-false-10485759-2: multi-thread copy: write buffer set to 131072
2025/06/29 01:20:11 DEBUG : test-multithread-copy-false-10485759-2: multi-thread copy: chunk size 64Mi was bigger than source file size 10.000Mi
2025/06/29 01:20:11 DEBUG : test-multithread-copy-false-10485759-2: multi-thread copy: using backend concurrency of 4 instead of --multi-thread-streams 2
2025/06/29 01:20:11 DEBUG : test-multithread-copy-false-10485759-2: multi-thread copy: number of streams 4 was bigger than number of chunks 1
2025/06/29 01:20:11 DEBUG : test-multithread-copy-false-10485759-2: Starting multi-thread copy with 1 chunks of size 10.000Mi with 1 parallel streams
2025/06/29 01:20:11 DEBUG : test-multithread-copy-false-10485759-2: multi-thread copy: chunk 1/1 (0-10485759) size 10.000Mi starting
2025/06/29 01:20:11 DEBUG : test-multithread-copy-false-10485759-2: writing chunk 0
2025/06/29 01:20:11 DEBUG : test-multithread-copy-false-10485759-2: multi-thread copy: chunk 1/1 (0-10485759) size 10.000Mi finished
2025/06/29 01:20:11 DEBUG : test-multithread-copy-false-10485759-2: trying to read metadata test-multithread-copy-false-10485759-2
2025/06/29 01:20:11 DEBUG : test-multithread-copy-false-10485759-2: Finished multi-thread copy with 1 parts of size 10.000Mi
2025/06/29 01:20:11 DEBUG : test-multithread-copy-false-10485759-2: trying to read metadata test-multithread-copy-false-10485759-2
2025/06/29 01:20:11 DEBUG : test-multithread-copy-false-10485759-2: trying to read metadata test-multithread-copy-false-10485759-2
=== RUN   TestMultithreadCopy/upload=false,size=10485760,streams=2
2025/06/29 01:20:13 DEBUG : test-multithread-copy-false-10485760-2: trying to read metadata test-multithread-copy-false-10485760-2
2025/06/29 01:20:13 DEBUG : test-multithread-copy-false-10485760-2: trying to read metadata test-multithread-copy-false-10485760-2
2025/06/29 01:20:13 DEBUG : test-multithread-copy-false-10485760-2: trying to read metadata test-multithread-copy-false-10485760-2
2025/06/29 01:20:13 DEBUG : test-multithread-copy-false-10485760-2: trying to read metadata test-multithread-copy-false-10485760-2
2025/06/29 01:20:13 DEBUG : test-multithread-copy-false-10485760-2: multi-thread copy: disabling buffering because destination uses OpenWriterAt
2025/06/29 01:20:13 DEBUG : test-multithread-copy-false-10485760-2: multi-thread copy: write buffer set to 131072
2025/06/29 01:20:13 DEBUG : test-multithread-copy-false-10485760-2: multi-thread copy: chunk size 64Mi was bigger than source file size 10Mi
2025/06/29 01:20:13 DEBUG : test-multithread-copy-false-10485760-2: multi-thread copy: using backend concurrency of 4 instead of --multi-thread-streams 2
2025/06/29 01:20:13 DEBUG : test-multithread-copy-false-10485760-2: multi-thread copy: number of streams 4 was bigger than number of chunks 1
2025/06/29 01:20:13 DEBUG : test-multithread-copy-false-10485760-2: Starting multi-thread copy with 1 chunks of size 10Mi with 1 parallel streams
2025/06/29 01:20:13 DEBUG : test-multithread-copy-false-10485760-2: multi-thread copy: chunk 1/1 (0-10485760) size 10Mi starting
2025/06/29 01:20:13 DEBUG : test-multithread-copy-false-10485760-2: writing chunk 0
2025/06/29 01:20:13 DEBUG : test-multithread-copy-false-10485760-2: multi-thread copy: chunk 1/1 (0-10485760) size 10Mi finished
2025/06/29 01:20:13 DEBUG : test-multithread-copy-false-10485760-2: trying to read metadata test-multithread-copy-false-10485760-2
2025/06/29 01:20:13 DEBUG : test-multithread-copy-false-10485760-2: Finished multi-thread copy with 1 parts of size 10Mi
2025/06/29 01:20:13 DEBUG : test-multithread-copy-false-10485760-2: trying to read metadata test-multithread-copy-false-10485760-2
2025/06/29 01:20:13 DEBUG : test-multithread-copy-false-10485760-2: trying to read metadata test-multithread-copy-false-10485760-2
=== RUN   TestMultithreadCopy/upload=false,size=10485761,streams=2
2025/06/29 01:20:15 DEBUG : test-multithread-copy-false-10485761-2: trying to read metadata test-multithread-copy-false-10485761-2
2025/06/29 01:20:15 DEBUG : test-multithread-copy-false-10485761-2: trying to read metadata test-multithread-copy-false-10485761-2
2025/06/29 01:20:15 DEBUG : test-multithread-copy-false-10485761-2: trying to read metadata test-multithread-copy-false-10485761-2
2025/06/29 01:20:15 DEBUG : test-multithread-copy-false-10485761-2: trying to read metadata test-multithread-copy-false-10485761-2
2025/06/29 01:20:15 DEBUG : test-multithread-copy-false-10485761-2: multi-thread copy: disabling buffering because destination uses OpenWriterAt
2025/06/29 01:20:15 DEBUG : test-multithread-copy-false-10485761-2: multi-thread copy: write buffer set to 131072
2025/06/29 01:20:15 DEBUG : test-multithread-copy-false-10485761-2: multi-thread copy: chunk size 64Mi was bigger than source file size 10.000Mi
2025/06/29 01:20:15 DEBUG : test-multithread-copy-false-10485761-2: multi-thread copy: using backend concurrency of 4 instead of --multi-thread-streams 2
2025/06/29 01:20:15 DEBUG : test-multithread-copy-false-10485761-2: multi-thread copy: number of streams 4 was bigger than number of chunks 1
2025/06/29 01:20:15 DEBUG : test-multithread-copy-false-10485761-2: Starting multi-thread copy with 1 chunks of size 10.000Mi with 1 parallel streams
2025/06/29 01:20:15 DEBUG : test-multithread-copy-false-10485761-2: multi-thread copy: chunk 1/1 (0-10485761) size 10.000Mi starting
2025/06/29 01:20:15 DEBUG : test-multithread-copy-false-10485761-2: writing chunk 0
2025/06/29 01:20:16 DEBUG : test-multithread-copy-false-10485761-2: multi-thread copy: chunk 1/1 (0-10485761) size 10.000Mi finished
2025/06/29 01:20:16 DEBUG : test-multithread-copy-false-10485761-2: trying to read metadata test-multithread-copy-false-10485761-2
2025/06/29 01:20:16 DEBUG : test-multithread-copy-false-10485761-2: Finished multi-thread copy with 1 parts of size 10.000Mi
2025/06/29 01:20:16 DEBUG : test-multithread-copy-false-10485761-2: trying to read metadata test-multithread-copy-false-10485761-2
2025/06/29 01:20:16 DEBUG : test-multithread-copy-false-10485761-2: trying to read metadata test-multithread-copy-false-10485761-2
=== RUN   TestMultithreadCopy/upload=true,size=10485759,streams=2
2025/06/29 01:20:18 DEBUG : test-multithread-copy-true-10485759-2: multi-thread copy: disabling buffering because source is local disk
2025/06/29 01:20:18 DEBUG : test-multithread-copy-true-10485759-2: created new upload id: d2723ae1-a744-f070-f482-2d5aaa1e86a9
2025/06/29 01:20:18 DEBUG : test-multithread-copy-true-10485759-2: open chunk writer: started multipart upload: d2723ae1-a744-f070-f482-2d5aaa1e86a9
2025/06/29 01:20:18 DEBUG : test-multithread-copy-true-10485759-2: multi-thread copy: using backend concurrency of 10 instead of --multi-thread-streams 2
2025/06/29 01:20:18 DEBUG : test-multithread-copy-true-10485759-2: multi-thread copy: number of streams 10 was bigger than number of chunks 2
2025/06/29 01:20:18 DEBUG : test-multithread-copy-true-10485759-2: Starting multi-thread copy with 2 chunks of size 5Mi with 2 parallel streams
2025/06/29 01:20:18 DEBUG : test-multithread-copy-true-10485759-2: multi-thread copy: chunk 2/2 (5242880-10485759) size 5.000Mi starting
2025/06/29 01:20:18 DEBUG : test-multithread-copy-true-10485759-2: multi-thread copy: chunk 1/2 (0-5242880) size 5Mi starting
2025/06/29 01:20:18 DEBUG : test-multithread-copy-true-10485759-2: Seek from 5242879 to 0
2025/06/29 01:20:18 DEBUG : test-multithread-copy-true-10485759-2: Seek from 5242880 to 0
2025/06/29 01:20:18 DEBUG : test-multithread-copy-true-10485759-2: multi-thread copy: chunk 2/2 (5242880-10485759) size 5.000Mi finished
2025/06/29 01:20:18 DEBUG : test-multithread-copy-true-10485759-2: multi-thread copy: chunk 1/2 (0-5242880) size 5Mi finished
2025/06/29 01:20:18 DEBUG : test-multithread-copy-true-10485759-2: multipart upload d2723ae1-a744-f070-f482-2d5aaa1e86a9 md5 matched: expecting SJCYbTLh+K0mLSGOhZKt8g==-2 and got SJCYbTLh+K0mLSGOhZKt8g==-2
2025/06/29 01:20:18 DEBUG : test-multithread-copy-true-10485759-2: trying to read metadata test-multithread-copy-true-10485759-2
2025/06/29 01:20:18 DEBUG : test-multithread-copy-true-10485759-2: Finished multi-thread copy with 2 parts of size 5Mi
2025/06/29 01:20:19 DEBUG : test-multithread-copy-true-10485759-2: Failed to read md5sum from metadata "SJCYbTLh+K0mLSGOhZKt8g==-2": illegal base64 data at input byte 24
2025/06/29 01:20:19 DEBUG : test-multithread-copy-true-10485759-2: trying to read metadata test-multithread-copy-true-10485759-2
2025/06/29 01:20:19 DEBUG : test-multithread-copy-true-10485759-2: trying to read metadata test-multithread-copy-true-10485759-2
=== RUN   TestMultithreadCopy/upload=true,size=10485760,streams=2
2025/06/29 01:20:20 DEBUG : test-multithread-copy-true-10485760-2: multi-thread copy: disabling buffering because source is local disk
2025/06/29 01:20:20 DEBUG : test-multithread-copy-true-10485760-2: created new upload id: 573af928-84ff-0859-cc40-3094f59d3659
2025/06/29 01:20:20 DEBUG : test-multithread-copy-true-10485760-2: open chunk writer: started multipart upload: 573af928-84ff-0859-cc40-3094f59d3659
2025/06/29 01:20:20 DEBUG : test-multithread-copy-true-10485760-2: multi-thread copy: using backend concurrency of 10 instead of --multi-thread-streams 2
2025/06/29 01:20:20 DEBUG : test-multithread-copy-true-10485760-2: multi-thread copy: number of streams 10 was bigger than number of chunks 2
2025/06/29 01:20:20 DEBUG : test-multithread-copy-true-10485760-2: Starting multi-thread copy with 2 chunks of size 5Mi with 2 parallel streams
2025/06/29 01:20:20 DEBUG : test-multithread-copy-true-10485760-2: multi-thread copy: chunk 2/2 (5242880-10485760) size 5Mi starting
2025/06/29 01:20:20 DEBUG : test-multithread-copy-true-10485760-2: multi-thread copy: chunk 1/2 (0-5242880) size 5Mi starting
2025/06/29 01:20:20 DEBUG : test-multithread-copy-true-10485760-2: Seek from 5242880 to 0
2025/06/29 01:20:20 DEBUG : test-multithread-copy-true-10485760-2: Seek from 5242880 to 0
2025/06/29 01:20:21 DEBUG : test-multithread-copy-true-10485760-2: multi-thread copy: chunk 1/2 (0-5242880) size 5Mi finished
2025/06/29 01:20:21 DEBUG : test-multithread-copy-true-10485760-2: multi-thread copy: chunk 2/2 (5242880-10485760) size 5Mi finished
2025/06/29 01:20:21 DEBUG : test-multithread-copy-true-10485760-2: multipart upload 573af928-84ff-0859-cc40-3094f59d3659 md5 matched: expecting 9tp0ThSNONwH5Neyq4fSrA==-2 and got 9tp0ThSNONwH5Neyq4fSrA==-2
2025/06/29 01:20:21 DEBUG : test-multithread-copy-true-10485760-2: trying to read metadata test-multithread-copy-true-10485760-2
2025/06/29 01:20:21 DEBUG : test-multithread-copy-true-10485760-2: Finished multi-thread copy with 2 parts of size 5Mi
2025/06/29 01:20:22 DEBUG : test-multithread-copy-true-10485760-2: Failed to read md5sum from metadata "9tp0ThSNONwH5Neyq4fSrA==-2": illegal base64 data at input byte 24
2025/06/29 01:20:22 DEBUG : test-multithread-copy-true-10485760-2: trying to read metadata test-multithread-copy-true-10485760-2
2025/06/29 01:20:22 DEBUG : test-multithread-copy-true-10485760-2: trying to read metadata test-multithread-copy-true-10485760-2
=== RUN   TestMultithreadCopy/upload=true,size=10485761,streams=2
2025/06/29 01:20:23 DEBUG : test-multithread-copy-true-10485761-2: multi-thread copy: disabling buffering because source is local disk
2025/06/29 01:20:23 DEBUG : test-multithread-copy-true-10485761-2: created new upload id: eb8864e5-e26a-3944-08b7-572563fdf6c1
2025/06/29 01:20:23 DEBUG : test-multithread-copy-true-10485761-2: open chunk writer: started multipart upload: eb8864e5-e26a-3944-08b7-572563fdf6c1
2025/06/29 01:20:23 DEBUG : test-multithread-copy-true-10485761-2: multi-thread copy: using backend concurrency of 10 instead of --multi-thread-streams 2
2025/06/29 01:20:23 DEBUG : test-multithread-copy-true-10485761-2: multi-thread copy: number of streams 10 was bigger than number of chunks 3
2025/06/29 01:20:23 DEBUG : test-multithread-copy-true-10485761-2: Starting multi-thread copy with 3 chunks of size 5Mi with 3 parallel streams
2025/06/29 01:20:23 DEBUG : test-multithread-copy-true-10485761-2: multi-thread copy: chunk 3/3 (10485760-10485761) size 1 starting
2025/06/29 01:20:23 DEBUG : test-multithread-copy-true-10485761-2: multi-thread copy: chunk 1/3 (0-5242880) size 5Mi starting
2025/06/29 01:20:23 DEBUG : test-multithread-copy-true-10485761-2: multi-thread copy: chunk 2/3 (5242880-10485760) size 5Mi starting
2025/06/29 01:20:23 DEBUG : test-multithread-copy-true-10485761-2: Seek from 1 to 0
2025/06/29 01:20:23 DEBUG : test-multithread-copy-true-10485761-2: Seek from 5242880 to 0
2025/06/29 01:20:23 DEBUG : test-multithread-copy-true-10485761-2: multi-thread copy: chunk 3/3 (10485760-10485761) size 1 finished
2025/06/29 01:20:23 DEBUG : test-multithread-copy-true-10485761-2: Seek from 5242880 to 0
2025/06/29 01:20:24 DEBUG : test-multithread-copy-true-10485761-2: multi-thread copy: chunk 2/3 (5242880-10485760) size 5Mi finished
2025/06/29 01:20:24 DEBUG : test-multithread-copy-true-10485761-2: multi-thread copy: chunk 1/3 (0-5242880) size 5Mi finished
2025/06/29 01:20:24 DEBUG : test-multithread-copy-true-10485761-2: multipart upload eb8864e5-e26a-3944-08b7-572563fdf6c1 md5 matched: expecting p5GXX1IVaLoKEwmm4m5OSg==-3 and got p5GXX1IVaLoKEwmm4m5OSg==-3
2025/06/29 01:20:24 DEBUG : test-multithread-copy-true-10485761-2: trying to read metadata test-multithread-copy-true-10485761-2
2025/06/29 01:20:24 DEBUG : test-multithread-copy-true-10485761-2: Finished multi-thread copy with 3 parts of size 5Mi
2025/06/29 01:20:25 DEBUG : test-multithread-copy-true-10485761-2: Failed to read md5sum from metadata "p5GXX1IVaLoKEwmm4m5OSg==-3": illegal base64 data at input byte 24
2025/06/29 01:20:25 DEBUG : test-multithread-copy-true-10485761-2: trying to read metadata test-multithread-copy-true-10485761-2
2025/06/29 01:20:25 DEBUG : test-multithread-copy-true-10485761-2: trying to read metadata test-multithread-copy-true-10485761-2
--- PASS: TestMultithreadCopy (16.24s)
    --- PASS: TestMultithreadCopy/upload=false,size=10485759,streams=2 (2.60s)
    --- PASS: TestMultithreadCopy/upload=false,size=10485760,streams=2 (2.31s)
    --- PASS: TestMultithreadCopy/upload=false,size=10485761,streams=2 (2.25s)
    --- PASS: TestMultithreadCopy/upload=true,size=10485759,streams=2 (2.81s)
    --- PASS: TestMultithreadCopy/upload=true,size=10485760,streams=2 (2.70s)
    --- PASS: TestMultithreadCopy/upload=true,size=10485761,streams=2 (2.97s)
=== RUN   TestMultithreadCopyAbort
    run.go:180: Remote "oos:bucket rclone-test-hegagis7kado", Local "Local file system at /tmp/rclone1744522841", Modify Window "1ms"
2025/06/29 01:20:25 DEBUG : chunksize-probe: created new upload id: 6f3e6c5d-f0c7-c17d-ea66-e911a29837a0
2025/06/29 01:20:25 DEBUG : chunksize-probe: open chunk writer: started multipart upload: 6f3e6c5d-f0c7-c17d-ea66-e911a29837a0
2025/06/29 01:20:25 DEBUG : chunksize-probe: Cancelling multipart upload
2025/06/29 01:20:25 DEBUG : chunksize-probe: canceled and aborted multipart upload: 6f3e6c5d-f0c7-c17d-ea66-e911a29837a0
2025/06/29 01:20:25 DEBUG : test-multithread-abort: trying to read metadata test-multithread-abort
2025/06/29 01:20:25 DEBUG : test-multithread-abort: trying to read metadata test-multithread-abort
2025/06/29 01:20:25 DEBUG : test-multithread-abort: trying to read metadata test-multithread-abort
2025/06/29 01:20:26 DEBUG : test-multithread-abort: multi-thread copy: disabling buffering because source is local disk
2025/06/29 01:20:26 DEBUG : test-multithread-abort: created new upload id: 4c17fcca-a082-4658-bbca-09da2282df40
2025/06/29 01:20:26 DEBUG : test-multithread-abort: open chunk writer: started multipart upload: 4c17fcca-a082-4658-bbca-09da2282df40
2025/06/29 01:20:26 DEBUG : test-multithread-abort: multi-thread copy: using backend concurrency of 10 instead of --multi-thread-streams 1
2025/06/29 01:20:26 DEBUG : test-multithread-abort: multi-thread copy: number of streams 10 was bigger than number of chunks 3
2025/06/29 01:20:26 DEBUG : test-multithread-abort: Starting multi-thread copy with 3 chunks of size 5Mi with 3 parallel streams
2025/06/29 01:20:26 DEBUG : test-multithread-abort: multi-thread copy: chunk 3/3 (10485760-10485761) size 1 starting
2025/06/29 01:20:26 DEBUG : Open with options = [RangeOption(10485760,10485760)]
2025/06/29 01:20:26 DEBUG : test-multithread-abort: multi-thread copy: chunk 1/3 (0-5242880) size 5Mi starting
2025/06/29 01:20:26 DEBUG : test-multithread-abort: multi-thread copy: chunk 2/3 (5242880-10485760) size 5Mi starting
2025/06/29 01:20:26 DEBUG : Open with options = [RangeOption(0,5242879)]
2025/06/29 01:20:26 DEBUG : Open with options = [RangeOption(5242880,10485759)]
2025/06/29 01:20:27 DEBUG : test-multithread-abort: Seek from 5242880 to 0
2025/06/29 01:20:27 DEBUG : Open with options = [RangeOption(0,5242879)]
2025/06/29 01:20:27 DEBUG : test-multithread-abort: Seek from 5242880 to 0
2025/06/29 01:20:27 DEBUG : Open with options = [RangeOption(5242880,10485759)]
2025/06/29 01:20:27 DEBUG : test-multithread-abort: multi-thread copy: chunk 2/3 (5242880-10485760) size 5Mi finished
2025/06/29 01:20:27 DEBUG : test-multithread-abort: multi-thread copy: chunk 1/3 (0-5242880) size 5Mi finished
2025/06/29 01:20:27 DEBUG : Returning error reader
2025/06/29 01:20:27 DEBUG : BOOM: simulated read failure
2025/06/29 01:20:27 DEBUG : test-multithread-abort: Reopening on read failure after offset 0 bytes: retry 1/10: BOOM: simulated read failure
2025/06/29 01:20:27 DEBUG : Open with options = [RangeOption(10485760,10485760)]
2025/06/29 01:20:28 DEBUG : Returning error reader
2025/06/29 01:20:28 DEBUG : BOOM: simulated read failure
2025/06/29 01:20:28 DEBUG : test-multithread-abort: Reopening on read failure after offset 0 bytes: retry 2/10: BOOM: simulated read failure
2025/06/29 01:20:28 DEBUG : Open with options = [RangeOption(10485760,10485760)]
2025/06/29 01:20:29 DEBUG : Returning error reader
2025/06/29 01:20:29 DEBUG : BOOM: simulated read failure
2025/06/29 01:20:29 DEBUG : test-multithread-abort: Reopening on read failure after offset 0 bytes: retry 3/10: BOOM: simulated read failure
2025/06/29 01:20:29 DEBUG : Open with options = [RangeOption(10485760,10485760)]
2025/06/29 01:20:30 DEBUG : Returning error reader
2025/06/29 01:20:30 DEBUG : BOOM: simulated read failure
2025/06/29 01:20:30 DEBUG : test-multithread-abort: Reopening on read failure after offset 0 bytes: retry 4/10: BOOM: simulated read failure
2025/06/29 01:20:30 DEBUG : Open with options = [RangeOption(10485760,10485760)]
2025/06/29 01:20:31 DEBUG : Returning error reader
2025/06/29 01:20:31 DEBUG : BOOM: simulated read failure
2025/06/29 01:20:31 DEBUG : test-multithread-abort: Reopening on read failure after offset 0 bytes: retry 5/10: BOOM: simulated read failure
2025/06/29 01:20:31 DEBUG : Open with options = [RangeOption(10485760,10485760)]
2025/06/29 01:20:32 DEBUG : Returning error reader
2025/06/29 01:20:32 DEBUG : BOOM: simulated read failure
2025/06/29 01:20:32 DEBUG : test-multithread-abort: Reopening on read failure after offset 0 bytes: retry 6/10: BOOM: simulated read failure
2025/06/29 01:20:32 DEBUG : Open with options = [RangeOption(10485760,10485760)]
2025/06/29 01:20:33 DEBUG : Returning error reader
2025/06/29 01:20:33 DEBUG : BOOM: simulated read failure
2025/06/29 01:20:33 DEBUG : test-multithread-abort: Reopening on read failure after offset 0 bytes: retry 7/10: BOOM: simulated read failure
2025/06/29 01:20:33 DEBUG : Open with options = [RangeOption(10485760,10485760)]
2025/06/29 01:20:34 DEBUG : Returning error reader
2025/06/29 01:20:34 DEBUG : BOOM: simulated read failure
2025/06/29 01:20:34 DEBUG : test-multithread-abort: Reopening on read failure after offset 0 bytes: retry 8/10: BOOM: simulated read failure
2025/06/29 01:20:34 DEBUG : Open with options = [RangeOption(10485760,10485760)]
2025/06/29 01:20:35 DEBUG : Returning error reader
2025/06/29 01:20:35 DEBUG : BOOM: simulated read failure
2025/06/29 01:20:35 DEBUG : test-multithread-abort: Reopening on read failure after offset 0 bytes: retry 9/10: BOOM: simulated read failure
2025/06/29 01:20:35 DEBUG : Open with options = [RangeOption(10485760,10485760)]
2025/06/29 01:20:36 DEBUG : Returning error reader
2025/06/29 01:20:36 DEBUG : BOOM: simulated read failure
2025/06/29 01:20:36 DEBUG : test-multithread-abort: Reopening on read failure after offset 0 bytes: retry 10/10: BOOM: simulated read failure
2025/06/29 01:20:36 DEBUG : test-multithread-abort: Reopen failed after offset 0 bytes read: failed to reopen: too many retries
2025/06/29 01:20:36 DEBUG : test-multithread-abort: multi-thread copy: chunk 3/3 failed: multi-thread copy: failed to write chunk: BOOM: simulated read failure
2025/06/29 01:20:36 DEBUG : test-multithread-abort: multi-thread copy: cancelling transfer on exit
2025/06/29 01:20:36 DEBUG : test-multithread-abort: Cancelling multipart upload
2025/06/29 01:20:36 DEBUG : test-multithread-abort: canceled and aborted multipart upload: 4c17fcca-a082-4658-bbca-09da2282df40
2025/06/29 01:20:37 DEBUG : test-multithread-abort: trying to read metadata test-multithread-abort
2025/06/29 01:20:37 DEBUG : test-multithread-abort: trying to read metadata test-multithread-abort
2025/06/29 01:20:37 DEBUG : test-multithread-abort: trying to read metadata test-multithread-abort
--- PASS: TestMultithreadCopyAbort (11.85s)
=== RUN   TestSizeDiffers
--- PASS: TestSizeDiffers (0.00s)
=== RUN   TestReOpen
=== RUN   TestReOpen/Normal
=== RUN   TestReOpen/Normal/Basics
2025/06/29 01:20:37 DEBUG : potato: Seek from 10 to 0
=== RUN   TestReOpen/Normal/ErrorAtStart
=== RUN   TestReOpen/Normal/WithErrors
2025/06/29 01:20:37 DEBUG : potato: Reopening on read failure after offset 2 bytes: retry 1/10: test error
2025/06/29 01:20:37 DEBUG : potato: Reopening on read failure after offset 3 bytes: retry 2/10: test error
2025/06/29 01:20:37 DEBUG : potato: Reopening on read failure after offset 6 bytes: retry 3/10: test error
=== RUN   TestReOpen/Normal/TooManyErrors
2025/06/29 01:20:37 DEBUG : potato: Reopening on read failure after offset 2 bytes: retry 1/3: test error
2025/06/29 01:20:37 DEBUG : potato: Reopening on read failure after offset 3 bytes: retry 2/3: test error
2025/06/29 01:20:37 DEBUG : potato: Reopening on read failure after offset 6 bytes: retry 3/3: test error
2025/06/29 01:20:37 DEBUG : potato: Reopen failed after offset 6 bytes read: failed to reopen: too many retries
=== RUN   TestReOpen/Normal/Seek
2025/06/29 01:20:37 DEBUG : potato: Reopening on read failure after offset 2 bytes: retry 0/10: test error
2025/06/29 01:20:37 DEBUG : potato: Reopening on read failure after offset 3 bytes: retry 1/10: test error
2025/06/29 01:20:37 DEBUG : potato: Seek from 5 to 2
=== RUN   TestReOpen/Normal/AccountRead
=== RUN   TestReOpen/Normal/AccountReadDelay
2025/06/29 01:20:37 DEBUG : potato: Seek from 10 to 0
2025/06/29 01:20:37 DEBUG : potato: Seek from 10 to 0
2025/06/29 01:20:37 DEBUG : potato: Seek from 10 to 0
=== RUN   TestReOpen/Normal/AccountReadError
=== RUN   TestReOpen/WithRangeOption
=== RUN   TestReOpen/WithRangeOption/Basics
2025/06/29 01:20:37 DEBUG : potato: Seek from 7 to 0
=== RUN   TestReOpen/WithRangeOption/ErrorAtStart
=== RUN   TestReOpen/WithRangeOption/WithErrors
2025/06/29 01:20:37 DEBUG : potato: Reopening on read failure after offset 2 bytes: retry 1/10: test error
2025/06/29 01:20:37 DEBUG : potato: Reopening on read failure after offset 3 bytes: retry 2/10: test error
2025/06/29 01:20:37 DEBUG : potato: Reopening on read failure after offset 6 bytes: retry 3/10: test error
=== RUN   TestReOpen/WithRangeOption/TooManyErrors
2025/06/29 01:20:37 DEBUG : potato: Reopening on read failure after offset 2 bytes: retry 1/3: test error
2025/06/29 01:20:37 DEBUG : potato: Reopening on read failure after offset 3 bytes: retry 2/3: test error
2025/06/29 01:20:37 DEBUG : potato: Reopening on read failure after offset 6 bytes: retry 3/3: test error
2025/06/29 01:20:37 DEBUG : potato: Reopen failed after offset 6 bytes read: failed to reopen: too many retries
=== RUN   TestReOpen/WithRangeOption/Seek
2025/06/29 01:20:37 DEBUG : potato: Reopening on read failure after offset 2 bytes: retry 0/10: test error
2025/06/29 01:20:37 DEBUG : potato: Reopening on read failure after offset 3 bytes: retry 1/10: test error
2025/06/29 01:20:37 DEBUG : potato: Seek from 5 to 2
2025/06/29 01:20:37 DEBUG : potato: Seek from 7 to 4
=== RUN   TestReOpen/WithRangeOption/AccountRead
=== RUN   TestReOpen/WithRangeOption/AccountReadDelay
2025/06/29 01:20:37 DEBUG : potato: Seek from 7 to 0
2025/06/29 01:20:37 DEBUG : potato: Seek from 7 to 0
2025/06/29 01:20:37 DEBUG : potato: Seek from 7 to 0
=== RUN   TestReOpen/WithRangeOption/AccountReadError
=== RUN   TestReOpen/WithSeekOption
=== RUN   TestReOpen/WithSeekOption/Basics
2025/06/29 01:20:37 DEBUG : potato: Seek from 8 to 0
=== RUN   TestReOpen/WithSeekOption/ErrorAtStart
=== RUN   TestReOpen/WithSeekOption/WithErrors
2025/06/29 01:20:37 DEBUG : potato: Reopening on read failure after offset 2 bytes: retry 1/10: test error
2025/06/29 01:20:37 DEBUG : potato: Reopening on read failure after offset 3 bytes: retry 2/10: test error
2025/06/29 01:20:37 DEBUG : potato: Reopening on read failure after offset 6 bytes: retry 3/10: test error
=== RUN   TestReOpen/WithSeekOption/TooManyErrors
2025/06/29 01:20:37 DEBUG : potato: Reopening on read failure after offset 2 bytes: retry 1/3: test error
2025/06/29 01:20:37 DEBUG : potato: Reopening on read failure after offset 3 bytes: retry 2/3: test error
2025/06/29 01:20:37 DEBUG : potato: Reopening on read failure after offset 6 bytes: retry 3/3: test error
2025/06/29 01:20:37 DEBUG : potato: Reopen failed after offset 6 bytes read: failed to reopen: too many retries
=== RUN   TestReOpen/WithSeekOption/Seek
2025/06/29 01:20:37 DEBUG : potato: Reopening on read failure after offset 2 bytes: retry 0/10: test error
2025/06/29 01:20:37 DEBUG : potato: Reopening on read failure after offset 3 bytes: retry 1/10: test error
2025/06/29 01:20:37 DEBUG : potato: Seek from 5 to 2
2025/06/29 01:20:37 DEBUG : potato: Seek from 7 to 5
=== RUN   TestReOpen/WithSeekOption/AccountRead
=== RUN   TestReOpen/WithSeekOption/AccountReadDelay
2025/06/29 01:20:37 DEBUG : potato: Seek from 8 to 0
2025/06/29 01:20:37 DEBUG : potato: Seek from 8 to 0
2025/06/29 01:20:37 DEBUG : potato: Seek from 8 to 0
=== RUN   TestReOpen/WithSeekOption/AccountReadError
=== RUN   TestReOpen/UnknownSize
=== RUN   TestReOpen/UnknownSize/Basics
2025/06/29 01:20:37 DEBUG : potato: Seek from 9 to 0
=== RUN   TestReOpen/UnknownSize/ErrorAtStart
=== RUN   TestReOpen/UnknownSize/WithErrors
2025/06/29 01:20:37 DEBUG : potato: Reopening on read failure after offset 2 bytes: retry 1/10: test error
2025/06/29 01:20:37 DEBUG : potato: Reopening on read failure after offset 3 bytes: retry 2/10: test error
2025/06/29 01:20:37 DEBUG : potato: Reopening on read failure after offset 6 bytes: retry 3/10: test error
=== RUN   TestReOpen/UnknownSize/TooManyErrors
2025/06/29 01:20:37 DEBUG : potato: Reopening on read failure after offset 2 bytes: retry 1/3: test error
2025/06/29 01:20:37 DEBUG : potato: Reopening on read failure after offset 3 bytes: retry 2/3: test error
2025/06/29 01:20:37 DEBUG : potato: Reopening on read failure after offset 6 bytes: retry 3/3: test error
2025/06/29 01:20:37 DEBUG : potato: Reopen failed after offset 6 bytes read: failed to reopen: too many retries
=== RUN   TestReOpen/UnknownSize/Seek
2025/06/29 01:20:37 DEBUG : potato: Reopening on read failure after offset 2 bytes: retry 0/10: test error
2025/06/29 01:20:37 DEBUG : potato: Reopening on read failure after offset 3 bytes: retry 1/10: test error
2025/06/29 01:20:37 DEBUG : potato: Seek from 5 to 2
2025/06/29 01:20:37 DEBUG : potato: Seek from 7 to 6
=== RUN   TestReOpen/UnknownSize/AccountRead
=== RUN   TestReOpen/UnknownSize/AccountReadDelay
2025/06/29 01:20:37 DEBUG : potato: Seek from 9 to 0
2025/06/29 01:20:37 DEBUG : potato: Seek from 9 to 0
2025/06/29 01:20:37 DEBUG : potato: Seek from 9 to 0
=== RUN   TestReOpen/UnknownSize/AccountReadError
--- PASS: TestReOpen (0.00s)
    --- PASS: TestReOpen/Normal (0.00s)
        --- PASS: TestReOpen/Normal/Basics (0.00s)
        --- PASS: TestReOpen/Normal/ErrorAtStart (0.00s)
        --- PASS: TestReOpen/Normal/WithErrors (0.00s)
        --- PASS: TestReOpen/Normal/TooManyErrors (0.00s)
        --- PASS: TestReOpen/Normal/Seek (0.00s)
        --- PASS: TestReOpen/Normal/AccountRead (0.00s)
        --- PASS: TestReOpen/Normal/AccountReadDelay (0.00s)
        --- PASS: TestReOpen/Normal/AccountReadError (0.00s)
    --- PASS: TestReOpen/WithRangeOption (0.00s)
        --- PASS: TestReOpen/WithRangeOption/Basics (0.00s)
        --- PASS: TestReOpen/WithRangeOption/ErrorAtStart (0.00s)
        --- PASS: TestReOpen/WithRangeOption/WithErrors (0.00s)
        --- PASS: TestReOpen/WithRangeOption/TooManyErrors (0.00s)
        --- PASS: TestReOpen/WithRangeOption/Seek (0.00s)
        --- PASS: TestReOpen/WithRangeOption/AccountRead (0.00s)
        --- PASS: TestReOpen/WithRangeOption/AccountReadDelay (0.00s)
        --- PASS: TestReOpen/WithRangeOption/AccountReadError (0.00s)
    --- PASS: TestReOpen/WithSeekOption (0.00s)
        --- PASS: TestReOpen/WithSeekOption/Basics (0.00s)
        --- PASS: TestReOpen/WithSeekOption/ErrorAtStart (0.00s)
        --- PASS: TestReOpen/WithSeekOption/WithErrors (0.00s)
        --- PASS: TestReOpen/WithSeekOption/TooManyErrors (0.00s)
        --- PASS: TestReOpen/WithSeekOption/Seek (0.00s)
        --- PASS: TestReOpen/WithSeekOption/AccountRead (0.00s)
        --- PASS: TestReOpen/WithSeekOption/AccountReadDelay (0.00s)
        --- PASS: TestReOpen/WithSeekOption/AccountReadError (0.00s)
    --- PASS: TestReOpen/UnknownSize (0.00s)
        --- PASS: TestReOpen/UnknownSize/Basics (0.00s)
        --- PASS: TestReOpen/UnknownSize/ErrorAtStart (0.00s)
        --- PASS: TestReOpen/UnknownSize/WithErrors (0.00s)
        --- PASS: TestReOpen/UnknownSize/TooManyErrors (0.00s)
        --- PASS: TestReOpen/UnknownSize/Seek (0.00s)
        --- PASS: TestReOpen/UnknownSize/AccountRead (0.00s)
        --- PASS: TestReOpen/UnknownSize/AccountReadDelay (0.00s)
        --- PASS: TestReOpen/UnknownSize/AccountReadError (0.00s)
=== RUN   TestCheck
    run.go:180: Remote "oos:bucket rclone-test-hegagis7kado", Local "Local file system at /tmp/rclone1744522841", Modify Window "1ms"
2025/06/29 01:20:37 DEBUG : rutabaga: trying to read metadata rutabaga
2025/06/29 01:20:37 DEBUG : rutabaga: trying to read metadata rutabaga
2025/06/29 01:20:37 DEBUG : rutabaga: trying to read metadata rutabaga
=== RUN   TestCheck/1
=== RUN   TestCheck/2
2025/06/29 01:20:37 DEBUG : empty space: trying to read metadata empty space
2025/06/29 01:20:37 DEBUG : empty space: trying to read metadata empty space
2025/06/29 01:20:38 DEBUG : empty space: trying to read metadata empty space
2025/06/29 01:20:38 DEBUG : rutabaga: trying to read metadata rutabaga
2025/06/29 01:20:38 DEBUG : rutabaga: trying to read metadata rutabaga
=== RUN   TestCheck/3
2025/06/29 01:20:38 DEBUG : pacer: low level retry 1/1 (error Error returned by ObjectStorage Service. Http Status Code: 503. Error Code: ServiceUnavailable. Opc request id: lhr-1:05oMdTWR0kGdfv-FYyHrceC2Fwhva30HFDLTZwpn5XZED2bgB4d9Nat9Zf7DTa6a. Message: the service is currently unavailable
Operation Name: PutObject
Timestamp: 2025-06-29 01:20:38 +0000 GMT
Client Version: Oracle-GoSDK/65.93.0
Request Endpoint: PUT https://objectstorage.uk-london-1.oraclecloud.com/n/lrqbljfginym/b/rclone-test-hegagis7kado/o/potato2
Troubleshooting Tips: See https://docs.oracle.com/iaas/Content/API/References/apierrors.htm#apierrors_503__503_serviceunavailable for more information about resolving this error.
Also see https://docs.oracle.com/iaas/api/#/en/objectstorage/20160918/Object/PutObject for details on this operation's requirements.
To get more info on the failing request, you can set OCI_GO_SDK_DEBUG env var to info or higher level to log the request/response details.
If you are unable to resolve this ObjectStorage issue, please contact Oracle support and provide them this full error message.. Unable to perform Retry on this request body type, which did not implement seek() interface)
2025/06/29 01:20:38 DEBUG : pacer: Rate limited, increasing sleep to 10ms
2025/06/29 01:20:38 ERROR : potato2: put object failed Error returned by ObjectStorage Service. Http Status Code: 503. Error Code: ServiceUnavailable. Opc request id: lhr-1:05oMdTWR0kGdfv-FYyHrceC2Fwhva30HFDLTZwpn5XZED2bgB4d9Nat9Zf7DTa6a. Message: the service is currently unavailable
Operation Name: PutObject
Timestamp: 2025-06-29 01:20:38 +0000 GMT
Client Version: Oracle-GoSDK/65.93.0
Request Endpoint: PUT https://objectstorage.uk-london-1.oraclecloud.com/n/lrqbljfginym/b/rclone-test-hegagis7kado/o/potato2
Troubleshooting Tips: See https://docs.oracle.com/iaas/Content/API/References/apierrors.htm#apierrors_503__503_serviceunavailable for more information about resolving this error.
Also see https://docs.oracle.com/iaas/api/#/en/objectstorage/20160918/Object/PutObject for details on this operation's requirements.
To get more info on the failing request, you can set OCI_GO_SDK_DEBUG env var to info or higher level to log the request/response details.
If you are unable to resolve this ObjectStorage issue, please contact Oracle support and provide them this full error message.. Unable to perform Retry on this request body type, which did not implement seek() interface
=== NAME  TestCheck
    run.go:281: Retry Put of "potato2" to oos:bucket rclone-test-hegagis7kado: 1/10 (Error returned by ObjectStorage Service. Http Status Code: 503. Error Code: ServiceUnavailable. Opc request id: lhr-1:05oMdTWR0kGdfv-FYyHrceC2Fwhva30HFDLTZwpn5XZED2bgB4d9Nat9Zf7DTa6a. Message: the service is currently unavailable
        Operation Name: PutObject
        Timestamp: 2025-06-29 01:20:38 +0000 GMT
        Client Version: Oracle-GoSDK/65.93.0
        Request Endpoint: PUT https://objectstorage.uk-london-1.oraclecloud.com/n/lrqbljfginym/b/rclone-test-hegagis7kado/o/potato2
        Troubleshooting Tips: See https://docs.oracle.com/iaas/Content/API/References/apierrors.htm#apierrors_503__503_serviceunavailable for more information about resolving this error.
        Also see https://docs.oracle.com/iaas/api/#/en/objectstorage/20160918/Object/PutObject for details on this operation's requirements.
        To get more info on the failing request, you can set OCI_GO_SDK_DEBUG env var to info or higher level to log the request/response details.
        If you are unable to resolve this ObjectStorage issue, please contact Oracle support and provide them this full error message.. Unable to perform Retry on this request body type, which did not implement seek() interface)
2025/06/29 01:20:40 DEBUG : pacer: Reducing sleep to 0s
2025/06/29 01:20:40 DEBUG : potato2: trying to read metadata potato2
2025/06/29 01:20:40 DEBUG : empty space: trying to read metadata empty space
2025/06/29 01:20:40 DEBUG : empty space: trying to read metadata empty space
2025/06/29 01:20:40 DEBUG : potato2: trying to read metadata potato2
2025/06/29 01:20:40 DEBUG : potato2: trying to read metadata potato2
2025/06/29 01:20:40 DEBUG : rutabaga: trying to read metadata rutabaga
2025/06/29 01:20:40 DEBUG : rutabaga: trying to read metadata rutabaga
=== RUN   TestCheck/4
=== RUN   TestCheck/5
2025/06/29 01:20:41 DEBUG : remotepotato: trying to read metadata remotepotato
2025/06/29 01:20:41 DEBUG : empty space: trying to read metadata empty space
2025/06/29 01:20:41 DEBUG : empty space: trying to read metadata empty space
2025/06/29 01:20:41 DEBUG : potato2: trying to read metadata potato2
2025/06/29 01:20:41 DEBUG : potato2: trying to read metadata potato2
2025/06/29 01:20:41 DEBUG : remotepotato: trying to read metadata remotepotato
2025/06/29 01:20:41 DEBUG : remotepotato: trying to read metadata remotepotato
2025/06/29 01:20:41 DEBUG : rutabaga: trying to read metadata rutabaga
2025/06/29 01:20:41 DEBUG : rutabaga: trying to read metadata rutabaga
=== RUN   TestCheck/6
=== RUN   TestCheck/7
--- PASS: TestCheck (4.53s)
    --- PASS: TestCheck/1 (0.10s)
    --- PASS: TestCheck/2 (0.10s)
    --- PASS: TestCheck/3 (0.09s)
    --- PASS: TestCheck/4 (0.12s)
    --- PASS: TestCheck/5 (0.10s)
    --- PASS: TestCheck/6 (0.12s)
    --- PASS: TestCheck/7 (0.09s)
=== RUN   TestCheckFsError
2025/06/29 01:20:41 DEBUG : Creating backend with remote "nonexistent"
2025/06/29 01:20:41 DEBUG : Creating backend with remote "nonexistent"
2025/06/29 01:20:41 DEBUG : Local file system at /home/rclone/go/src/github.com/rclone/rclone/fs/operations/nonexistent: Waiting for checks to finish
2025/06/29 01:20:41 ERROR : Local file system at /home/rclone/go/src/github.com/rclone/rclone/fs/operations/nonexistent: error reading source root directory: directory not found
2025/06/29 01:20:41 NOTICE: Local file system at /home/rclone/go/src/github.com/rclone/rclone/fs/operations/nonexistent: 2 differences found
2025/06/29 01:20:41 NOTICE: Local file system at /home/rclone/go/src/github.com/rclone/rclone/fs/operations/nonexistent: 2 errors while checking
--- PASS: TestCheckFsError (0.00s)
=== RUN   TestCheckDownload
    run.go:180: Remote "oos:bucket rclone-test-hegagis7kado", Local "Local file system at /tmp/rclone1744522841", Modify Window "1ms"
2025/06/29 01:20:41 DEBUG : rutabaga: trying to read metadata rutabaga
2025/06/29 01:20:42 DEBUG : rutabaga: trying to read metadata rutabaga
2025/06/29 01:20:42 DEBUG : rutabaga: trying to read metadata rutabaga
=== RUN   TestCheckDownload/1
=== RUN   TestCheckDownload/2
2025/06/29 01:20:42 DEBUG : empty space: trying to read metadata empty space
2025/06/29 01:20:42 DEBUG : empty space: trying to read metadata empty space
2025/06/29 01:20:42 DEBUG : empty space: trying to read metadata empty space
2025/06/29 01:20:42 DEBUG : rutabaga: trying to read metadata rutabaga
2025/06/29 01:20:42 DEBUG : rutabaga: trying to read metadata rutabaga
=== RUN   TestCheckDownload/3
2025/06/29 01:20:42 DEBUG : potato2: trying to read metadata potato2
2025/06/29 01:20:42 DEBUG : empty space: trying to read metadata empty space
2025/06/29 01:20:42 DEBUG : empty space: trying to read metadata empty space
2025/06/29 01:20:42 DEBUG : potato2: trying to read metadata potato2
2025/06/29 01:20:43 DEBUG : potato2: trying to read metadata potato2
2025/06/29 01:20:43 DEBUG : rutabaga: trying to read metadata rutabaga
2025/06/29 01:20:43 DEBUG : rutabaga: trying to read metadata rutabaga
=== RUN   TestCheckDownload/4
=== RUN   TestCheckDownload/5
2025/06/29 01:20:43 DEBUG : remotepotato: trying to read metadata remotepotato
2025/06/29 01:20:43 DEBUG : empty space: trying to read metadata empty space
2025/06/29 01:20:43 DEBUG : empty space: trying to read metadata empty space
2025/06/29 01:20:43 DEBUG : potato2: trying to read metadata potato2
2025/06/29 01:20:43 DEBUG : potato2: trying to read metadata potato2
2025/06/29 01:20:43 DEBUG : remotepotato: trying to read metadata remotepotato
2025/06/29 01:20:43 DEBUG : remotepotato: trying to read metadata remotepotato
2025/06/29 01:20:43 DEBUG : rutabaga: trying to read metadata rutabaga
2025/06/29 01:20:43 DEBUG : rutabaga: trying to read metadata rutabaga
=== RUN   TestCheckDownload/6
=== RUN   TestCheckDownload/7
--- PASS: TestCheckDownload (2.53s)
    --- PASS: TestCheckDownload/1 (0.11s)
    --- PASS: TestCheckDownload/2 (0.10s)
    --- PASS: TestCheckDownload/3 (0.11s)
    --- PASS: TestCheckDownload/4 (0.10s)
    --- PASS: TestCheckDownload/5 (0.09s)
    --- PASS: TestCheckDownload/6 (0.10s)
    --- PASS: TestCheckDownload/7 (0.09s)
=== RUN   TestCheckSizeOnly
    run.go:180: Remote "oos:bucket rclone-test-hegagis7kado", Local "Local file system at /tmp/rclone1744522841", Modify Window "1ms"
2025/06/29 01:20:44 DEBUG : rutabaga: trying to read metadata rutabaga
2025/06/29 01:20:44 DEBUG : rutabaga: trying to read metadata rutabaga
2025/06/29 01:20:44 DEBUG : rutabaga: trying to read metadata rutabaga
=== RUN   TestCheckSizeOnly/1
=== RUN   TestCheckSizeOnly/2
2025/06/29 01:20:44 DEBUG : empty space: trying to read metadata empty space
2025/06/29 01:20:44 DEBUG : empty space: trying to read metadata empty space
2025/06/29 01:20:44 DEBUG : empty space: trying to read metadata empty space
2025/06/29 01:20:44 DEBUG : rutabaga: trying to read metadata rutabaga
2025/06/29 01:20:44 DEBUG : rutabaga: trying to read metadata rutabaga
=== RUN   TestCheckSizeOnly/3
2025/06/29 01:20:45 DEBUG : potato2: trying to read metadata potato2
2025/06/29 01:20:45 DEBUG : empty space: trying to read metadata empty space
2025/06/29 01:20:45 DEBUG : empty space: trying to read metadata empty space
2025/06/29 01:20:45 DEBUG : potato2: trying to read metadata potato2
2025/06/29 01:20:45 DEBUG : potato2: trying to read metadata potato2
2025/06/29 01:20:45 DEBUG : rutabaga: trying to read metadata rutabaga
2025/06/29 01:20:45 DEBUG : rutabaga: trying to read metadata rutabaga
=== RUN   TestCheckSizeOnly/4
=== RUN   TestCheckSizeOnly/5
2025/06/29 01:20:45 DEBUG : remotepotato: trying to read metadata remotepotato
2025/06/29 01:20:45 DEBUG : empty space: trying to read metadata empty space
2025/06/29 01:20:45 DEBUG : empty space: trying to read metadata empty space
2025/06/29 01:20:45 DEBUG : potato2: trying to read metadata potato2
2025/06/29 01:20:45 DEBUG : potato2: trying to read metadata potato2
2025/06/29 01:20:45 DEBUG : remotepotato: trying to read metadata remotepotato
2025/06/29 01:20:45 DEBUG : remotepotato: trying to read metadata remotepotato
2025/06/29 01:20:45 DEBUG : rutabaga: trying to read metadata rutabaga
2025/06/29 01:20:45 DEBUG : rutabaga: trying to read metadata rutabaga
=== RUN   TestCheckSizeOnly/6
=== RUN   TestCheckSizeOnly/7
--- PASS: TestCheckSizeOnly (1.82s)
    --- PASS: TestCheckSizeOnly/1 (0.05s)
    --- PASS: TestCheckSizeOnly/2 (0.04s)
    --- PASS: TestCheckSizeOnly/3 (0.04s)
    --- PASS: TestCheckSizeOnly/4 (0.05s)
    --- PASS: TestCheckSizeOnly/5 (0.05s)
    --- PASS: TestCheckSizeOnly/6 (0.04s)
    --- PASS: TestCheckSizeOnly/7 (0.04s)
=== RUN   TestCheckEqualReaders
--- PASS: TestCheckEqualReaders (0.00s)
=== RUN   TestParseSumFile
    run.go:180: Remote "oos:bucket rclone-test-hegagis7kado", Local "Local file system at /tmp/rclone1744522841", Modify Window "1ms"
2025/06/29 01:20:46 DEBUG : test.sum: trying to read metadata test.sum
2025/06/29 01:20:46 DEBUG : test.sum: trying to read metadata test.sum
2025/06/29 01:20:46 NOTICE: test.sum: improperly formatted checksum line 4
2025/06/29 01:20:46 NOTICE: test.sum: improperly formatted checksum line 5
2025/06/29 01:20:46 NOTICE: test.sum: improperly formatted checksum line 6
2025/06/29 01:20:46 NOTICE: test.sum: 2 warning(s) suppressed...
2025/06/29 01:20:46 DEBUG : test.sum: trying to read metadata test.sum
2025/06/29 01:20:46 DEBUG : test.sum: trying to read metadata test.sum
2025/06/29 01:20:46 NOTICE: test.sum: improperly formatted checksum line 4
2025/06/29 01:20:46 NOTICE: test.sum: improperly formatted checksum line 5
2025/06/29 01:20:46 NOTICE: test.sum: improperly formatted checksum line 6
2025/06/29 01:20:46 NOTICE: test.sum: 2 warning(s) suppressed...
--- PASS: TestParseSumFile (0.59s)
=== RUN   TestCheckSum
    run.go:180: Remote "oos:bucket rclone-test-hegagis7kado", Local "Local file system at /tmp/rclone1744522841", Modify Window "1ms"
2025/06/29 01:20:46 DEBUG : Creating backend with remote "TestOracleObjectStorage:rclone-test-hegagis7kado/data"
2025/06/29 01:20:46 DEBUG : data: trying to read metadata data
2025/06/29 01:20:47 DEBUG : data/banana: trying to read metadata data/banana
2025/06/29 01:20:47 DEBUG : test.sum: trying to read metadata test.sum
2025/06/29 01:20:47 DEBUG : data/banana: trying to read metadata data/banana
2025/06/29 01:20:47 DEBUG : data/banana: trying to read metadata data/banana
2025/06/29 01:20:47 DEBUG : test.sum: trying to read metadata test.sum
2025/06/29 01:20:47 DEBUG : test.sum: trying to read metadata test.sum
=== RUN   TestCheckSum/subtest1
2025/06/29 01:20:47 DEBUG : data/potato: trying to read metadata data/potato
2025/06/29 01:20:47 DEBUG : test.sum: trying to read metadata test.sum
2025/06/29 01:20:47 DEBUG : data/banana: trying to read metadata data/banana
2025/06/29 01:20:48 DEBUG : data/banana: trying to read metadata data/banana
2025/06/29 01:20:48 DEBUG : data/potato: trying to read metadata data/potato
2025/06/29 01:20:48 DEBUG : data/potato: trying to read metadata data/potato
2025/06/29 01:20:48 DEBUG : test.sum: trying to read metadata test.sum
2025/06/29 01:20:48 DEBUG : test.sum: trying to read metadata test.sum
=== RUN   TestCheckSum/subtest2
2025/06/29 01:20:48 DEBUG : test.sum: trying to read metadata test.sum
2025/06/29 01:20:48 DEBUG : data/banana: trying to read metadata data/banana
2025/06/29 01:20:48 DEBUG : data/banana: trying to read metadata data/banana
2025/06/29 01:20:48 DEBUG : data/potato: trying to read metadata data/potato
2025/06/29 01:20:48 DEBUG : data/potato: trying to read metadata data/potato
2025/06/29 01:20:48 DEBUG : test.sum: trying to read metadata test.sum
2025/06/29 01:20:48 DEBUG : test.sum: trying to read metadata test.sum
=== RUN   TestCheckSum/subtest3
2025/06/29 01:20:48 DEBUG : test.sum: trying to read metadata test.sum
2025/06/29 01:20:48 DEBUG : data/banana: trying to read metadata data/banana
2025/06/29 01:20:49 DEBUG : data/banana: trying to read metadata data/banana
2025/06/29 01:20:49 DEBUG : data/potato: trying to read metadata data/potato
2025/06/29 01:20:49 DEBUG : data/potato: trying to read metadata data/potato
2025/06/29 01:20:49 DEBUG : test.sum: trying to read metadata test.sum
2025/06/29 01:20:49 DEBUG : test.sum: trying to read metadata test.sum
=== RUN   TestCheckSum/subtest4
2025/06/29 01:20:49 DEBUG : test.sum: trying to read metadata test.sum
2025/06/29 01:20:49 DEBUG : data/banana: trying to read metadata data/banana
2025/06/29 01:20:49 DEBUG : data/banana: trying to read metadata data/banana
2025/06/29 01:20:49 DEBUG : data/potato: trying to read metadata data/potato
2025/06/29 01:20:49 DEBUG : data/potato: trying to read metadata data/potato
2025/06/29 01:20:49 DEBUG : test.sum: trying to read metadata test.sum
2025/06/29 01:20:49 DEBUG : test.sum: trying to read metadata test.sum
=== RUN   TestCheckSum/subtest5
2025/06/29 01:20:49 DEBUG : test.sum: trying to read metadata test.sum
2025/06/29 01:20:50 DEBUG : data/banana: trying to read metadata data/banana
2025/06/29 01:20:50 DEBUG : data/banana: trying to read metadata data/banana
2025/06/29 01:20:50 DEBUG : data/potato: trying to read metadata data/potato
2025/06/29 01:20:50 DEBUG : data/potato: trying to read metadata data/potato
2025/06/29 01:20:50 DEBUG : test.sum: trying to read metadata test.sum
2025/06/29 01:20:50 DEBUG : test.sum: trying to read metadata test.sum
=== RUN   TestCheckSum/subtest6
2025/06/29 01:20:50 DEBUG : data/banana: trying to read metadata data/banana
2025/06/29 01:20:50 DEBUG : data/potato: trying to read metadata data/potato
2025/06/29 01:20:50 DEBUG : test.sum: trying to read metadata test.sum
2025/06/29 01:20:50 DEBUG : data/banana: trying to read metadata data/banana
2025/06/29 01:20:50 DEBUG : data/banana: trying to read metadata data/banana
2025/06/29 01:20:50 DEBUG : data/potato: trying to read metadata data/potato
2025/06/29 01:20:51 DEBUG : data/potato: trying to read metadata data/potato
2025/06/29 01:20:51 DEBUG : test.sum: trying to read metadata test.sum
2025/06/29 01:20:51 DEBUG : test.sum: trying to read metadata test.sum
=== RUN   TestCheckSum/subtest7
--- PASS: TestCheckSum (4.87s)
    --- PASS: TestCheckSum/subtest1 (0.18s)
    --- PASS: TestCheckSum/subtest2 (0.18s)
    --- PASS: TestCheckSum/subtest3 (0.23s)
    --- PASS: TestCheckSum/subtest4 (0.23s)
    --- PASS: TestCheckSum/subtest5 (0.23s)
    --- PASS: TestCheckSum/subtest6 (0.23s)
    --- PASS: TestCheckSum/subtest7 (0.28s)
=== RUN   TestCheckSumDownload
    run.go:180: Remote "oos:bucket rclone-test-hegagis7kado", Local "Local file system at /tmp/rclone1744522841", Modify Window "1ms"
2025/06/29 01:20:51 DEBUG : Creating backend with remote "TestOracleObjectStorage:rclone-test-hegagis7kado/data"
2025/06/29 01:20:51 DEBUG : data: trying to read metadata data
2025/06/29 01:20:51 DEBUG : data/banana: trying to read metadata data/banana
2025/06/29 01:20:52 DEBUG : test.sum: trying to read metadata test.sum
2025/06/29 01:20:52 DEBUG : data/banana: trying to read metadata data/banana
2025/06/29 01:20:52 DEBUG : data/banana: trying to read metadata data/banana
2025/06/29 01:20:52 DEBUG : test.sum: trying to read metadata test.sum
2025/06/29 01:20:52 DEBUG : test.sum: trying to read metadata test.sum
=== RUN   TestCheckSumDownload/subtest1
2025/06/29 01:20:52 DEBUG : data/potato: trying to read metadata data/potato
2025/06/29 01:20:52 DEBUG : test.sum: trying to read metadata test.sum
2025/06/29 01:20:52 DEBUG : data/banana: trying to read metadata data/banana
2025/06/29 01:20:52 DEBUG : data/banana: trying to read metadata data/banana
2025/06/29 01:20:52 DEBUG : data/potato: trying to read metadata data/potato
2025/06/29 01:20:52 DEBUG : data/potato: trying to read metadata data/potato
2025/06/29 01:20:52 DEBUG : test.sum: trying to read metadata test.sum
2025/06/29 01:20:52 DEBUG : test.sum: trying to read metadata test.sum
=== RUN   TestCheckSumDownload/subtest2
2025/06/29 01:20:53 DEBUG : test.sum: trying to read metadata test.sum
2025/06/29 01:20:53 DEBUG : data/banana: trying to read metadata data/banana
2025/06/29 01:20:53 DEBUG : data/banana: trying to read metadata data/banana
2025/06/29 01:20:53 DEBUG : data/potato: trying to read metadata data/potato
2025/06/29 01:20:53 DEBUG : data/potato: trying to read metadata data/potato
2025/06/29 01:20:53 DEBUG : test.sum: trying to read metadata test.sum
2025/06/29 01:20:53 DEBUG : test.sum: trying to read metadata test.sum
=== RUN   TestCheckSumDownload/subtest3
2025/06/29 01:20:53 DEBUG : test.sum: trying to read metadata test.sum
2025/06/29 01:20:53 DEBUG : data/banana: trying to read metadata data/banana
2025/06/29 01:20:53 DEBUG : data/banana: trying to read metadata data/banana
2025/06/29 01:20:53 DEBUG : data/potato: trying to read metadata data/potato
2025/06/29 01:20:53 DEBUG : data/potato: trying to read metadata data/potato
2025/06/29 01:20:53 DEBUG : test.sum: trying to read metadata test.sum
2025/06/29 01:20:53 DEBUG : test.sum: trying to read metadata test.sum
=== RUN   TestCheckSumDownload/subtest4
2025/06/29 01:20:54 DEBUG : test.sum: trying to read metadata test.sum
2025/06/29 01:20:54 DEBUG : data/banana: trying to read metadata data/banana
2025/06/29 01:20:54 DEBUG : data/banana: trying to read metadata data/banana
2025/06/29 01:20:54 DEBUG : data/potato: trying to read metadata data/potato
2025/06/29 01:20:54 DEBUG : data/potato: trying to read metadata data/potato
2025/06/29 01:20:54 DEBUG : test.sum: trying to read metadata test.sum
2025/06/29 01:20:54 DEBUG : test.sum: trying to read metadata test.sum
=== RUN   TestCheckSumDownload/subtest5
2025/06/29 01:20:54 DEBUG : test.sum: trying to read metadata test.sum
2025/06/29 01:20:54 DEBUG : data/banana: trying to read metadata data/banana
2025/06/29 01:20:54 DEBUG : data/banana: trying to read metadata data/banana
2025/06/29 01:20:54 DEBUG : data/potato: trying to read metadata data/potato
2025/06/29 01:20:54 DEBUG : data/potato: trying to read metadata data/potato
2025/06/29 01:20:54 DEBUG : test.sum: trying to read metadata test.sum
2025/06/29 01:20:54 DEBUG : test.sum: trying to read metadata test.sum
=== RUN   TestCheckSumDownload/subtest6
2025/06/29 01:20:55 DEBUG : data/banana: trying to read metadata data/banana
2025/06/29 01:20:55 DEBUG : data/potato: trying to read metadata data/potato
2025/06/29 01:20:55 DEBUG : test.sum: trying to read metadata test.sum
2025/06/29 01:20:55 DEBUG : data/banana: trying to read metadata data/banana
2025/06/29 01:20:55 DEBUG : data/banana: trying to read metadata data/banana
2025/06/29 01:20:55 DEBUG : data/potato: trying to read metadata data/potato
2025/06/29 01:20:55 DEBUG : data/potato: trying to read metadata data/potato
2025/06/29 01:20:55 DEBUG : test.sum: trying to read metadata test.sum
2025/06/29 01:20:55 DEBUG : test.sum: trying to read metadata test.sum
=== RUN   TestCheckSumDownload/subtest7
--- PASS: TestCheckSumDownload (4.55s)
    --- PASS: TestCheckSumDownload/subtest1 (0.18s)
    --- PASS: TestCheckSumDownload/subtest2 (0.18s)
    --- PASS: TestCheckSumDownload/subtest3 (0.22s)
    --- PASS: TestCheckSumDownload/subtest4 (0.21s)
    --- PASS: TestCheckSumDownload/subtest5 (0.18s)
    --- PASS: TestCheckSumDownload/subtest6 (0.23s)
    --- PASS: TestCheckSumDownload/subtest7 (0.18s)
=== RUN   TestApplyTransforms
2025/06/29 01:20:56 DEBUG : Creating backend with remote "TestOracleObjectStorage:rclone-test-jukiril0losu"
2025/06/29 01:20:56 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2025/06/29 01:20:56 DEBUG : Creating backend with remote "/tmp/rclone881677703"
    run.go:180: Remote "oos:bucket rclone-test-jukiril0losu", Local "Local file system at /tmp/rclone881677703", Modify Window "1ms"
2025/06/29 01:20:56 INFO  : oos:bucket rclone-test-jukiril0losu: Bucket "rclone-test-jukiril0losu" created with accessType "NoPublicAccess"
2025/06/29 01:20:56 DEBUG : hello, world!: trying to read metadata hello, world!
2025/06/29 01:20:56 DEBUG : oos:bucket rclone-test-jukiril0losu: listing: bucket : rclone-test-jukiril0losu, directory: 
upper checkfile vs. lower remote (without normalization)
2025/06/29 01:20:56 ERROR : hello, world!: sum not found
2025/06/29 01:20:56 ERROR : HELLO, WORLD!: file not in oos:bucket rclone-test-jukiril0losu
2025/06/29 01:20:56 NOTICE: oos:bucket rclone-test-jukiril0losu: 1 files missing
2025/06/29 01:20:56 NOTICE: 1 hashes missing
2025/06/29 01:20:56 NOTICE: oos:bucket rclone-test-jukiril0losu: 2 differences found
2025/06/29 01:20:56 NOTICE: oos:bucket rclone-test-jukiril0losu: 2 errors while checking
upper checkfile vs. lower remote (with normalization)
2025/06/29 01:20:56 DEBUG : hello, world!: md5 = 65a8e27d8879283831b664bd8b7f0ad4 OK
2025/06/29 01:20:56 NOTICE: oos:bucket rclone-test-jukiril0losu: 0 differences found
2025/06/29 01:20:56 NOTICE: oos:bucket rclone-test-jukiril0losu: 1 matching files
2025/06/29 01:20:56 DEBUG : Creating backend with remote "TestOracleObjectStorage:rclone-test-cayiduh7jitu"
2025/06/29 01:20:56 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2025/06/29 01:20:56 DEBUG : Creating backend with remote "/tmp/rclone1600136056"
    run.go:180: Remote "oos:bucket rclone-test-cayiduh7jitu", Local "Local file system at /tmp/rclone1600136056", Modify Window "1ms"
2025/06/29 01:20:57 INFO  : oos:bucket rclone-test-cayiduh7jitu: Bucket "rclone-test-cayiduh7jitu" created with accessType "NoPublicAccess"
2025/06/29 01:20:57 DEBUG : HELLO, WORLD!: trying to read metadata HELLO, WORLD!
2025/06/29 01:20:57 DEBUG : oos:bucket rclone-test-cayiduh7jitu: listing: bucket : rclone-test-cayiduh7jitu, directory: 
lower checkfile vs. upper remote (without normalization)
2025/06/29 01:20:57 ERROR : HELLO, WORLD!: sum not found
2025/06/29 01:20:57 ERROR : hello, world!: file not in oos:bucket rclone-test-cayiduh7jitu
2025/06/29 01:20:57 NOTICE: oos:bucket rclone-test-cayiduh7jitu: 1 files missing
2025/06/29 01:20:57 NOTICE: 1 hashes missing
2025/06/29 01:20:57 NOTICE: oos:bucket rclone-test-cayiduh7jitu: 2 differences found
2025/06/29 01:20:57 NOTICE: oos:bucket rclone-test-cayiduh7jitu: 2 errors while checking
lower checkfile vs. upper remote (with normalization)
2025/06/29 01:20:57 DEBUG : HELLO, WORLD!: md5 = 65a8e27d8879283831b664bd8b7f0ad4 OK
2025/06/29 01:20:57 NOTICE: oos:bucket rclone-test-cayiduh7jitu: 0 differences found
2025/06/29 01:20:57 NOTICE: oos:bucket rclone-test-cayiduh7jitu: 1 matching files
2025/06/29 01:20:57 DEBUG : Creating backend with remote "TestOracleObjectStorage:rclone-test-dobapir7juzi"
2025/06/29 01:20:57 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2025/06/29 01:20:57 DEBUG : Creating backend with remote "/tmp/rclone4087284452"
    run.go:180: Remote "oos:bucket rclone-test-dobapir7juzi", Local "Local file system at /tmp/rclone4087284452", Modify Window "1ms"
2025/06/29 01:20:57 INFO  : oos:bucket rclone-test-dobapir7juzi: Bucket "rclone-test-dobapir7juzi" created with accessType "NoPublicAccess"
2025/06/29 01:20:57 DEBUG : HeLlO, wOrLd!: trying to read metadata HeLlO, wOrLd!
2025/06/29 01:20:57 DEBUG : oos:bucket rclone-test-dobapir7juzi: listing: bucket : rclone-test-dobapir7juzi, directory: 
lower checkfile vs. upperlowermixed remote (without normalization)
2025/06/29 01:20:57 ERROR : HeLlO, wOrLd!: sum not found
2025/06/29 01:20:57 ERROR : hello, world!: file not in oos:bucket rclone-test-dobapir7juzi
2025/06/29 01:20:57 NOTICE: oos:bucket rclone-test-dobapir7juzi: 1 files missing
2025/06/29 01:20:57 NOTICE: 1 hashes missing
2025/06/29 01:20:57 NOTICE: oos:bucket rclone-test-dobapir7juzi: 2 differences found
2025/06/29 01:20:57 NOTICE: oos:bucket rclone-test-dobapir7juzi: 2 errors while checking
lower checkfile vs. upperlowermixed remote (with normalization)
2025/06/29 01:20:57 DEBUG : HeLlO, wOrLd!: md5 = 65a8e27d8879283831b664bd8b7f0ad4 OK
2025/06/29 01:20:57 NOTICE: oos:bucket rclone-test-dobapir7juzi: 0 differences found
2025/06/29 01:20:57 NOTICE: oos:bucket rclone-test-dobapir7juzi: 1 matching files
2025/06/29 01:20:57 DEBUG : Creating backend with remote "TestOracleObjectStorage:rclone-test-secanac0pino"
2025/06/29 01:20:57 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2025/06/29 01:20:57 DEBUG : Creating backend with remote "/tmp/rclone2818849054"
    run.go:180: Remote "oos:bucket rclone-test-secanac0pino", Local "Local file system at /tmp/rclone2818849054", Modify Window "1ms"
2025/06/29 01:20:58 INFO  : oos:bucket rclone-test-secanac0pino: Bucket "rclone-test-secanac0pino" created with accessType "NoPublicAccess"
2025/06/29 01:20:58 DEBUG : HELLO, WORLD!: trying to read metadata HELLO, WORLD!
2025/06/29 01:20:58 DEBUG : oos:bucket rclone-test-secanac0pino: listing: bucket : rclone-test-secanac0pino, directory: 
upperlowermixed checkfile vs. upper remote (without normalization)
2025/06/29 01:20:58 ERROR : HELLO, WORLD!: sum not found
2025/06/29 01:20:58 ERROR : HeLlO, wOrLd!: file not in oos:bucket rclone-test-secanac0pino
2025/06/29 01:20:58 NOTICE: oos:bucket rclone-test-secanac0pino: 1 files missing
2025/06/29 01:20:58 NOTICE: 1 hashes missing
2025/06/29 01:20:58 NOTICE: oos:bucket rclone-test-secanac0pino: 2 differences found
2025/06/29 01:20:58 NOTICE: oos:bucket rclone-test-secanac0pino: 2 errors while checking
upperlowermixed checkfile vs. upper remote (with normalization)
2025/06/29 01:20:58 DEBUG : HELLO, WORLD!: md5 = 65a8e27d8879283831b664bd8b7f0ad4 OK
2025/06/29 01:20:58 NOTICE: oos:bucket rclone-test-secanac0pino: 0 differences found
2025/06/29 01:20:58 NOTICE: oos:bucket rclone-test-secanac0pino: 1 matching files
2025/06/29 01:20:58 DEBUG : Creating backend with remote "TestOracleObjectStorage:rclone-test-wefoqif8cafe"
2025/06/29 01:20:58 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2025/06/29 01:20:58 DEBUG : Creating backend with remote "/tmp/rclone3112481718"
    run.go:180: Remote "oos:bucket rclone-test-wefoqif8cafe", Local "Local file system at /tmp/rclone3112481718", Modify Window "1ms"
2025/06/29 01:20:58 INFO  : oos:bucket rclone-test-wefoqif8cafe: Bucket "rclone-test-wefoqif8cafe" created with accessType "NoPublicAccess"
2025/06/29 01:20:58 DEBUG : 測試_Русский___ě_áñ: trying to read metadata 測試_Русский___ě_áñ
2025/06/29 01:20:58 DEBUG : oos:bucket rclone-test-wefoqif8cafe: listing: bucket : rclone-test-wefoqif8cafe, directory: 
NFD checkfile vs. NFC remote (without normalization)
2025/06/29 01:20:59 ERROR : 測試_Русский___ě_áñ: sum not found
2025/06/29 01:20:59 ERROR : 測試_Русский___ě_áñ: file not in oos:bucket rclone-test-wefoqif8cafe
2025/06/29 01:20:59 NOTICE: oos:bucket rclone-test-wefoqif8cafe: 1 files missing
2025/06/29 01:20:59 NOTICE: 1 hashes missing
2025/06/29 01:20:59 NOTICE: oos:bucket rclone-test-wefoqif8cafe: 2 differences found
2025/06/29 01:20:59 NOTICE: oos:bucket rclone-test-wefoqif8cafe: 2 errors while checking
NFD checkfile vs. NFC remote (with normalization)
2025/06/29 01:20:59 DEBUG : 測試_Русский___ě_áñ: md5 = 65a8e27d8879283831b664bd8b7f0ad4 OK
2025/06/29 01:20:59 NOTICE: oos:bucket rclone-test-wefoqif8cafe: 0 differences found
2025/06/29 01:20:59 NOTICE: oos:bucket rclone-test-wefoqif8cafe: 1 matching files
2025/06/29 01:20:59 DEBUG : Creating backend with remote "TestOracleObjectStorage:rclone-test-xujawen0wake"
2025/06/29 01:20:59 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2025/06/29 01:20:59 DEBUG : Creating backend with remote "/tmp/rclone1914506339"
    run.go:180: Remote "oos:bucket rclone-test-xujawen0wake", Local "Local file system at /tmp/rclone1914506339", Modify Window "1ms"
2025/06/29 01:20:59 INFO  : oos:bucket rclone-test-xujawen0wake: Bucket "rclone-test-xujawen0wake" created with accessType "NoPublicAccess"
2025/06/29 01:20:59 DEBUG : 測試_Русский___ě_áñ: trying to read metadata 測試_Русский___ě_áñ
2025/06/29 01:20:59 DEBUG : oos:bucket rclone-test-xujawen0wake: listing: bucket : rclone-test-xujawen0wake, directory: 
NFC checkfile vs. NFD remote (without normalization)
2025/06/29 01:20:59 ERROR : 測試_Русский___ě_áñ: sum not found
2025/06/29 01:20:59 ERROR : 測試_Русский___ě_áñ: file not in oos:bucket rclone-test-xujawen0wake
2025/06/29 01:20:59 NOTICE: oos:bucket rclone-test-xujawen0wake: 1 files missing
2025/06/29 01:20:59 NOTICE: 1 hashes missing
2025/06/29 01:20:59 NOTICE: oos:bucket rclone-test-xujawen0wake: 2 differences found
2025/06/29 01:20:59 NOTICE: oos:bucket rclone-test-xujawen0wake: 2 errors while checking
NFC checkfile vs. NFD remote (with normalization)
2025/06/29 01:20:59 DEBUG : 測試_Русский___ě_áñ: md5 = 65a8e27d8879283831b664bd8b7f0ad4 OK
2025/06/29 01:20:59 NOTICE: oos:bucket rclone-test-xujawen0wake: 0 differences found
2025/06/29 01:20:59 NOTICE: oos:bucket rclone-test-xujawen0wake: 1 matching files
2025/06/29 01:20:59 DEBUG : Creating backend with remote "TestOracleObjectStorage:rclone-test-towodod7tovi"
2025/06/29 01:20:59 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2025/06/29 01:20:59 DEBUG : Creating backend with remote "/tmp/rclone3928728444"
    run.go:180: Remote "oos:bucket rclone-test-towodod7tovi", Local "Local file system at /tmp/rclone3928728444", Modify Window "1ms"
2025/06/29 01:20:59 INFO  : oos:bucket rclone-test-towodod7tovi: Bucket "rclone-test-towodod7tovi" created with accessType "NoPublicAccess"
2025/06/29 01:21:00 DEBUG : 測試_Русский___ě_áñ測試_Русский___ě_áñ: trying to read metadata 測試_Русский___ě_áñ測試_Русский___ě_áñ
2025/06/29 01:21:00 DEBUG : oos:bucket rclone-test-towodod7tovi: listing: bucket : rclone-test-towodod7tovi, directory: 
NFDx2 checkfile vs. both remote (without normalization)
2025/06/29 01:21:00 ERROR : 測試_Русский___ě_áñ測試_Русский___ě_áñ: sum not found
2025/06/29 01:21:00 ERROR : 測試_Русский___ě_áñ測試_Русский___ě_áñ: file not in oos:bucket rclone-test-towodod7tovi
2025/06/29 01:21:00 NOTICE: oos:bucket rclone-test-towodod7tovi: 1 files missing
2025/06/29 01:21:00 NOTICE: 1 hashes missing
2025/06/29 01:21:00 NOTICE: oos:bucket rclone-test-towodod7tovi: 2 differences found
2025/06/29 01:21:00 NOTICE: oos:bucket rclone-test-towodod7tovi: 2 errors while checking
NFDx2 checkfile vs. both remote (with normalization)
2025/06/29 01:21:00 DEBUG : 測試_Русский___ě_áñ測試_Русский___ě_áñ: md5 = 65a8e27d8879283831b664bd8b7f0ad4 OK
2025/06/29 01:21:00 NOTICE: oos:bucket rclone-test-towodod7tovi: 0 differences found
2025/06/29 01:21:00 NOTICE: oos:bucket rclone-test-towodod7tovi: 1 matching files
2025/06/29 01:21:00 DEBUG : Creating backend with remote "TestOracleObjectStorage:rclone-test-lovicuz5dayi"
2025/06/29 01:21:00 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2025/06/29 01:21:00 DEBUG : Creating backend with remote "/tmp/rclone4013185490"
    run.go:180: Remote "oos:bucket rclone-test-lovicuz5dayi", Local "Local file system at /tmp/rclone4013185490", Modify Window "1ms"
2025/06/29 01:21:00 INFO  : oos:bucket rclone-test-lovicuz5dayi: Bucket "rclone-test-lovicuz5dayi" created with accessType "NoPublicAccess"
2025/06/29 01:21:00 DEBUG : 測試_Русский___ě_áñ測試_Русский___ě_áñ: trying to read metadata 測試_Русский___ě_áñ測試_Русский___ě_áñ
2025/06/29 01:21:00 DEBUG : oos:bucket rclone-test-lovicuz5dayi: listing: bucket : rclone-test-lovicuz5dayi, directory: 
NFCx2 checkfile vs. both remote (without normalization)
2025/06/29 01:21:00 ERROR : 測試_Русский___ě_áñ測試_Русский___ě_áñ: sum not found
2025/06/29 01:21:00 ERROR : 測試_Русский___ě_áñ測試_Русский___ě_áñ: file not in oos:bucket rclone-test-lovicuz5dayi
2025/06/29 01:21:00 NOTICE: oos:bucket rclone-test-lovicuz5dayi: 1 files missing
2025/06/29 01:21:00 NOTICE: 1 hashes missing
2025/06/29 01:21:00 NOTICE: oos:bucket rclone-test-lovicuz5dayi: 2 differences found
2025/06/29 01:21:00 NOTICE: oos:bucket rclone-test-lovicuz5dayi: 2 errors while checking
NFCx2 checkfile vs. both remote (with normalization)
2025/06/29 01:21:00 DEBUG : 測試_Русский___ě_áñ測試_Русский___ě_áñ: md5 = 65a8e27d8879283831b664bd8b7f0ad4 OK
2025/06/29 01:21:00 NOTICE: oos:bucket rclone-test-lovicuz5dayi: 0 differences found
2025/06/29 01:21:00 NOTICE: oos:bucket rclone-test-lovicuz5dayi: 1 matching files
2025/06/29 01:21:00 DEBUG : Creating backend with remote "TestOracleObjectStorage:rclone-test-fotelaz3ruwu"
2025/06/29 01:21:00 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2025/06/29 01:21:00 DEBUG : Creating backend with remote "/tmp/rclone2912161929"
    run.go:180: Remote "oos:bucket rclone-test-fotelaz3ruwu", Local "Local file system at /tmp/rclone2912161929", Modify Window "1ms"
2025/06/29 01:21:01 INFO  : oos:bucket rclone-test-fotelaz3ruwu: Bucket "rclone-test-fotelaz3ruwu" created with accessType "NoPublicAccess"
2025/06/29 01:21:01 DEBUG : 測試_Русский___ě_áñ測試_Русский___ě_áñ: trying to read metadata 測試_Русский___ě_áñ測試_Русский___ě_áñ
2025/06/29 01:21:01 DEBUG : oos:bucket rclone-test-fotelaz3ruwu: listing: bucket : rclone-test-fotelaz3ruwu, directory: 
both checkfile vs. NFDx2 remote (without normalization)
2025/06/29 01:21:01 ERROR : 測試_Русский___ě_áñ測試_Русский___ě_áñ: sum not found
2025/06/29 01:21:01 ERROR : 測試_Русский___ě_áñ測試_Русский___ě_áñ: file not in oos:bucket rclone-test-fotelaz3ruwu
2025/06/29 01:21:01 NOTICE: oos:bucket rclone-test-fotelaz3ruwu: 1 files missing
2025/06/29 01:21:01 NOTICE: 1 hashes missing
2025/06/29 01:21:01 NOTICE: oos:bucket rclone-test-fotelaz3ruwu: 2 differences found
2025/06/29 01:21:01 NOTICE: oos:bucket rclone-test-fotelaz3ruwu: 2 errors while checking
both checkfile vs. NFDx2 remote (with normalization)
2025/06/29 01:21:01 DEBUG : 測試_Русский___ě_áñ測試_Русский___ě_áñ: md5 = 65a8e27d8879283831b664bd8b7f0ad4 OK
2025/06/29 01:21:01 NOTICE: oos:bucket rclone-test-fotelaz3ruwu: 0 differences found
2025/06/29 01:21:01 NOTICE: oos:bucket rclone-test-fotelaz3ruwu: 1 matching files
2025/06/29 01:21:01 DEBUG : Creating backend with remote "TestOracleObjectStorage:rclone-test-zivomoh6jopa"
2025/06/29 01:21:01 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2025/06/29 01:21:01 DEBUG : Creating backend with remote "/tmp/rclone3085618569"
    run.go:180: Remote "oos:bucket rclone-test-zivomoh6jopa", Local "Local file system at /tmp/rclone3085618569", Modify Window "1ms"
2025/06/29 01:21:01 INFO  : oos:bucket rclone-test-zivomoh6jopa: Bucket "rclone-test-zivomoh6jopa" created with accessType "NoPublicAccess"
2025/06/29 01:21:01 DEBUG : 測試_Русский___ě_áñ測試_Русский___ě_áñ: trying to read metadata 測試_Русский___ě_áñ測試_Русский___ě_áñ
2025/06/29 01:21:01 DEBUG : oos:bucket rclone-test-zivomoh6jopa: listing: bucket : rclone-test-zivomoh6jopa, directory: 
both checkfile vs. NFCx2 remote (without normalization)
2025/06/29 01:21:01 ERROR : 測試_Русский___ě_áñ測試_Русский___ě_áñ: sum not found
2025/06/29 01:21:01 ERROR : 測試_Русский___ě_áñ測試_Русский___ě_áñ: file not in oos:bucket rclone-test-zivomoh6jopa
2025/06/29 01:21:01 NOTICE: oos:bucket rclone-test-zivomoh6jopa: 1 files missing
2025/06/29 01:21:01 NOTICE: 1 hashes missing
2025/06/29 01:21:01 NOTICE: oos:bucket rclone-test-zivomoh6jopa: 2 differences found
2025/06/29 01:21:01 NOTICE: oos:bucket rclone-test-zivomoh6jopa: 2 errors while checking
both checkfile vs. NFCx2 remote (with normalization)
2025/06/29 01:21:01 DEBUG : 測試_Русский___ě_áñ測試_Русский___ě_áñ: md5 = 65a8e27d8879283831b664bd8b7f0ad4 OK
2025/06/29 01:21:01 NOTICE: oos:bucket rclone-test-zivomoh6jopa: 0 differences found
2025/06/29 01:21:01 NOTICE: oos:bucket rclone-test-zivomoh6jopa: 1 matching files
2025/06/29 01:21:01 DEBUG : oos:bucket rclone-test-zivomoh6jopa: Purge object "測試_Русский___ě_áñ測試_Русский___ě_áñ"
2025/06/29 01:21:02 DEBUG : oos:bucket rclone-test-zivomoh6jopa: Purge dir ""
2025/06/29 01:21:04 INFO  : oos:bucket rclone-test-zivomoh6jopa: Bucket "rclone-test-zivomoh6jopa" deleted
2025/06/29 01:21:04 DEBUG : oos:bucket rclone-test-fotelaz3ruwu: Purge object "測試_Русский___ě_áñ測試_Русский___ě_áñ"
2025/06/29 01:21:04 DEBUG : oos:bucket rclone-test-fotelaz3ruwu: Purge dir ""
2025/06/29 01:21:06 INFO  : oos:bucket rclone-test-fotelaz3ruwu: Bucket "rclone-test-fotelaz3ruwu" deleted
2025/06/29 01:21:06 DEBUG : oos:bucket rclone-test-lovicuz5dayi: Purge object "測試_Русский___ě_áñ測試_Русский___ě_áñ"
2025/06/29 01:21:06 DEBUG : oos:bucket rclone-test-lovicuz5dayi: Purge dir ""
2025/06/29 01:21:08 INFO  : oos:bucket rclone-test-lovicuz5dayi: Bucket "rclone-test-lovicuz5dayi" deleted
2025/06/29 01:21:08 DEBUG : oos:bucket rclone-test-towodod7tovi: Purge object "測試_Русский___ě_áñ測試_Русский___ě_áñ"
2025/06/29 01:21:08 DEBUG : oos:bucket rclone-test-towodod7tovi: Purge dir ""
2025/06/29 01:21:10 INFO  : oos:bucket rclone-test-towodod7tovi: Bucket "rclone-test-towodod7tovi" deleted
2025/06/29 01:21:10 DEBUG : oos:bucket rclone-test-xujawen0wake: Purge object "測試_Русский___ě_áñ"
2025/06/29 01:21:10 DEBUG : oos:bucket rclone-test-xujawen0wake: Purge dir ""
2025/06/29 01:21:12 INFO  : oos:bucket rclone-test-xujawen0wake: Bucket "rclone-test-xujawen0wake" deleted
2025/06/29 01:21:12 DEBUG : oos:bucket rclone-test-wefoqif8cafe: Purge object "測試_Русский___ě_áñ"
2025/06/29 01:21:12 DEBUG : oos:bucket rclone-test-wefoqif8cafe: Purge dir ""
2025/06/29 01:21:14 INFO  : oos:bucket rclone-test-wefoqif8cafe: Bucket "rclone-test-wefoqif8cafe" deleted
2025/06/29 01:21:15 DEBUG : oos:bucket rclone-test-secanac0pino: Purge object "HELLO, WORLD!"
2025/06/29 01:21:15 DEBUG : oos:bucket rclone-test-secanac0pino: Purge dir ""
2025/06/29 01:21:17 INFO  : oos:bucket rclone-test-secanac0pino: Bucket "rclone-test-secanac0pino" deleted
2025/06/29 01:21:17 DEBUG : oos:bucket rclone-test-dobapir7juzi: Purge object "HeLlO, wOrLd!"
2025/06/29 01:21:17 DEBUG : oos:bucket rclone-test-dobapir7juzi: Purge dir ""
2025/06/29 01:21:19 INFO  : oos:bucket rclone-test-dobapir7juzi: Bucket "rclone-test-dobapir7juzi" deleted
2025/06/29 01:21:19 DEBUG : oos:bucket rclone-test-cayiduh7jitu: Purge object "HELLO, WORLD!"
2025/06/29 01:21:19 DEBUG : oos:bucket rclone-test-cayiduh7jitu: Purge dir ""
2025/06/29 01:21:21 INFO  : oos:bucket rclone-test-cayiduh7jitu: Bucket "rclone-test-cayiduh7jitu" deleted
2025/06/29 01:21:21 DEBUG : oos:bucket rclone-test-jukiril0losu: Purge object "hello, world!"
2025/06/29 01:21:21 DEBUG : oos:bucket rclone-test-jukiril0losu: Purge dir ""
2025/06/29 01:21:23 INFO  : oos:bucket rclone-test-jukiril0losu: Bucket "rclone-test-jukiril0losu" deleted
--- PASS: TestApplyTransforms (27.45s)
=== RUN   TestTruncateString
--- PASS: TestTruncateString (0.00s)
=== RUN   TestCopyFile
    run.go:180: Remote "oos:bucket rclone-test-hegagis7kado", Local "Local file system at /tmp/rclone1744522841", Modify Window "1ms"
2025/06/29 01:21:23 DEBUG : sub/file2: trying to read metadata sub/file2
2025/06/29 01:21:23 DEBUG : file1: Need to transfer - File not found at Destination
2025/06/29 01:21:23 DEBUG : sub/file2: trying to read metadata sub/file2
2025/06/29 01:21:23 DEBUG : file1: md5 = 0ef726ce9b1a7692357ff70dd321d595 OK
2025/06/29 01:21:23 INFO  : file1: Copied (new) to: sub/file2
2025/06/29 01:21:23 DEBUG : sub/file2: trying to read metadata sub/file2
2025/06/29 01:21:23 DEBUG : sub/file2: trying to read metadata sub/file2
2025/06/29 01:21:23 DEBUG : sub/file2: trying to read metadata sub/file2
2025/06/29 01:21:23 DEBUG : sub/file2: trying to read metadata sub/file2
2025/06/29 01:21:23 DEBUG : file1: Size and modification time the same (differ by 0s, within tolerance 1ms)
2025/06/29 01:21:23 DEBUG : file1: Unchanged skipping
2025/06/29 01:21:24 DEBUG : sub/file2: trying to read metadata sub/file2
2025/06/29 01:21:24 DEBUG : sub/file2: trying to read metadata sub/file2
2025/06/29 01:21:24 DEBUG : oos:bucket rclone-test-hegagis7kado: don't need to copy/move sub/file2, it is already at target location
2025/06/29 01:21:24 DEBUG : sub/file2: trying to read metadata sub/file2
2025/06/29 01:21:24 DEBUG : sub/file2: trying to read metadata sub/file2
--- PASS: TestCopyFile (0.67s)
=== RUN   TestCopyLongFile
    run.go:180: Remote "oos:bucket rclone-test-hegagis7kado", Local "Local file system at /tmp/rclone1744522841", Modify Window "1ms"
    copy_test.go:153: Test only runs on local
--- SKIP: TestCopyLongFile (0.09s)
=== RUN   TestCopyFileBackupDir
    run.go:180: Remote "oos:bucket rclone-test-hegagis7kado", Local "Local file system at /tmp/rclone1744522841", Modify Window "1ms"
2025/06/29 01:21:24 DEBUG : dst/file1: trying to read metadata dst/file1
2025/06/29 01:21:24 DEBUG : dst/file1: trying to read metadata dst/file1
2025/06/29 01:21:24 DEBUG : dst/file1: trying to read metadata dst/file1
2025/06/29 01:21:24 DEBUG : dst/file1: trying to read metadata dst/file1
2025/06/29 01:21:24 DEBUG : Creating backend with remote "TestOracleObjectStorage:rclone-test-hegagis7kado/backup"
2025/06/29 01:21:24 DEBUG : backup: trying to read metadata backup
2025/06/29 01:21:24 DEBUG : dst/file1: Sizes differ (src 14 vs dst 18)
2025/06/29 01:21:24 DEBUG : dst/file1: trying to read metadata dst/file1
2025/06/29 01:21:26 DEBUG : dst/file1: trying to read metadata dst/file1
2025/06/29 01:21:26 DEBUG : dst/file1: md5 = 05164b153084ba910184c26e561a7c18 OK
2025/06/29 01:21:26 INFO  : dst/file1: Copied (server-side copy)
2025/06/29 01:21:26 INFO  : dst/file1: Deleted
2025/06/29 01:21:26 DEBUG : dst/file1: trying to read metadata dst/file1
2025/06/29 01:21:26 DEBUG : dst/file1: md5 = 0ef726ce9b1a7692357ff70dd321d595 OK
2025/06/29 01:21:26 INFO  : dst/file1: Copied (new)
2025/06/29 01:21:26 DEBUG : backup/dst/file1: trying to read metadata backup/dst/file1
2025/06/29 01:21:26 DEBUG : backup/dst/file1: trying to read metadata backup/dst/file1
2025/06/29 01:21:26 DEBUG : dst/file1: trying to read metadata dst/file1
2025/06/29 01:21:26 DEBUG : dst/file1: trying to read metadata dst/file1
--- PASS: TestCopyFileBackupDir (2.73s)
=== RUN   TestCopyFileCompareDest
    run.go:180: Remote "oos:bucket rclone-test-hegagis7kado", Local "Local file system at /tmp/rclone1744522841", Modify Window "1ms"
2025/06/29 01:21:27 DEBUG : Creating backend with remote "TestOracleObjectStorage:rclone-test-hegagis7kado/dst"
2025/06/29 01:21:27 DEBUG : dst: trying to read metadata dst
2025/06/29 01:21:27 DEBUG : one: trying to read metadata one
2025/06/29 01:21:27 DEBUG : Creating backend with remote "TestOracleObjectStorage:rclone-test-hegagis7kado/CompareDest"
2025/06/29 01:21:27 DEBUG : CompareDest: trying to read metadata CompareDest
2025/06/29 01:21:27 DEBUG : one: Need to transfer - File not found at Destination
2025/06/29 01:21:27 DEBUG : one: trying to read metadata one
2025/06/29 01:21:27 DEBUG : one: trying to read metadata one
2025/06/29 01:21:27 DEBUG : one: md5 = f97c5d29941bfb1b2fdab0874906ab82 OK
2025/06/29 01:21:27 INFO  : one: Copied (new)
2025/06/29 01:21:27 DEBUG : dst/one: trying to read metadata dst/one
2025/06/29 01:21:27 DEBUG : dst/one: trying to read metadata dst/one
2025/06/29 01:21:27 DEBUG : dst/one: trying to read metadata dst/one
2025/06/29 01:21:27 DEBUG : dst/one: trying to read metadata dst/one
2025/06/29 01:21:27 DEBUG : one: trying to read metadata one
2025/06/29 01:21:28 DEBUG : one: Sizes differ (src 5 vs dst 3)
2025/06/29 01:21:28 DEBUG : one: trying to read metadata one
2025/06/29 01:21:28 DEBUG : one: trying to read metadata one
2025/06/29 01:21:28 DEBUG : one: md5 = 07912d142f5d63ee918b34796b5a2432 OK
2025/06/29 01:21:28 INFO  : one: Copied (replaced existing)
2025/06/29 01:21:28 DEBUG : dst/one: trying to read metadata dst/one
2025/06/29 01:21:28 DEBUG : dst/one: trying to read metadata dst/one
2025/06/29 01:21:28 DEBUG : dst/one: trying to read metadata dst/one
2025/06/29 01:21:28 DEBUG : CompareDest/one: trying to read metadata CompareDest/one
2025/06/29 01:21:28 DEBUG : CompareDest/one: trying to read metadata CompareDest/one
2025/06/29 01:21:28 DEBUG : CompareDest/one: trying to read metadata CompareDest/one
2025/06/29 01:21:28 DEBUG : dst/one: trying to read metadata dst/one
2025/06/29 01:21:28 DEBUG : dst/one: trying to read metadata dst/one
2025/06/29 01:21:28 DEBUG : one: trying to read metadata one
2025/06/29 01:21:28 DEBUG : one: Sizes differ (src 5 vs dst 3)
2025/06/29 01:21:28 DEBUG : one: trying to read metadata one
2025/06/29 01:21:28 DEBUG : one: trying to read metadata one
2025/06/29 01:21:28 DEBUG : one: Size and modification time the same (differ by 0s, within tolerance 1ms)
2025/06/29 01:21:28 DEBUG : one: Destination found in --compare-dest, skipping
2025/06/29 01:21:28 DEBUG : CompareDest/one: trying to read metadata CompareDest/one
2025/06/29 01:21:28 DEBUG : CompareDest/one: trying to read metadata CompareDest/one
2025/06/29 01:21:28 DEBUG : dst/one: trying to read metadata dst/one
2025/06/29 01:21:28 DEBUG : dst/one: trying to read metadata dst/one
2025/06/29 01:21:29 DEBUG : CompareDest/two: trying to read metadata CompareDest/two
2025/06/29 01:21:29 DEBUG : CompareDest/one: trying to read metadata CompareDest/one
2025/06/29 01:21:29 DEBUG : CompareDest/one: trying to read metadata CompareDest/one
2025/06/29 01:21:29 DEBUG : CompareDest/two: trying to read metadata CompareDest/two
2025/06/29 01:21:29 DEBUG : CompareDest/two: trying to read metadata CompareDest/two
2025/06/29 01:21:29 DEBUG : dst/one: trying to read metadata dst/one
2025/06/29 01:21:29 DEBUG : dst/one: trying to read metadata dst/one
2025/06/29 01:21:29 DEBUG : two: trying to read metadata two
2025/06/29 01:21:29 DEBUG : two: Need to transfer - File not found at Destination
2025/06/29 01:21:29 DEBUG : two: trying to read metadata two
2025/06/29 01:21:29 DEBUG : two: trying to read metadata two
2025/06/29 01:21:29 DEBUG : two: Size and modification time the same (differ by 0s, within tolerance 1ms)
2025/06/29 01:21:29 DEBUG : two: Destination found in --compare-dest, skipping
2025/06/29 01:21:29 DEBUG : CompareDest/one: trying to read metadata CompareDest/one
2025/06/29 01:21:29 DEBUG : CompareDest/one: trying to read metadata CompareDest/one
2025/06/29 01:21:29 DEBUG : CompareDest/two: trying to read metadata CompareDest/two
2025/06/29 01:21:29 DEBUG : CompareDest/two: trying to read metadata CompareDest/two
2025/06/29 01:21:29 DEBUG : dst/one: trying to read metadata dst/one
2025/06/29 01:21:29 DEBUG : dst/one: trying to read metadata dst/one
2025/06/29 01:21:29 DEBUG : two: trying to read metadata two
2025/06/29 01:21:29 DEBUG : two: Need to transfer - File not found at Destination
2025/06/29 01:21:29 DEBUG : two: trying to read metadata two
2025/06/29 01:21:29 DEBUG : two: trying to read metadata two
2025/06/29 01:21:29 DEBUG : two: Size and modification time the same (differ by 0s, within tolerance 1ms)
2025/06/29 01:21:29 DEBUG : two: Destination found in --compare-dest, skipping
2025/06/29 01:21:29 DEBUG : CompareDest/one: trying to read metadata CompareDest/one
2025/06/29 01:21:29 DEBUG : CompareDest/one: trying to read metadata CompareDest/one
2025/06/29 01:21:29 DEBUG : CompareDest/two: trying to read metadata CompareDest/two
2025/06/29 01:21:29 DEBUG : CompareDest/two: trying to read metadata CompareDest/two
2025/06/29 01:21:29 DEBUG : dst/one: trying to read metadata dst/one
2025/06/29 01:21:29 DEBUG : dst/one: trying to read metadata dst/one
2025/06/29 01:21:29 DEBUG : CompareDest/one: trying to read metadata CompareDest/one
2025/06/29 01:21:29 DEBUG : CompareDest/one: trying to read metadata CompareDest/one
2025/06/29 01:21:29 DEBUG : CompareDest/two: trying to read metadata CompareDest/two
2025/06/29 01:21:30 DEBUG : CompareDest/two: trying to read metadata CompareDest/two
2025/06/29 01:21:30 DEBUG : dst/one: trying to read metadata dst/one
2025/06/29 01:21:30 DEBUG : dst/one: trying to read metadata dst/one
2025/06/29 01:21:30 DEBUG : two: trying to read metadata two
2025/06/29 01:21:30 DEBUG : two: Need to transfer - File not found at Destination
2025/06/29 01:21:30 DEBUG : two: trying to read metadata two
2025/06/29 01:21:30 DEBUG : two: Sizes differ (src 5 vs dst 3)
2025/06/29 01:21:30 DEBUG : two: trying to read metadata two
2025/06/29 01:21:30 DEBUG : two: md5 = 2379e4ce8c3380e996ab0509f17069ad OK
2025/06/29 01:21:30 INFO  : two: Copied (new)
2025/06/29 01:21:30 DEBUG : CompareDest/one: trying to read metadata CompareDest/one
2025/06/29 01:21:30 DEBUG : CompareDest/one: trying to read metadata CompareDest/one
2025/06/29 01:21:30 DEBUG : CompareDest/two: trying to read metadata CompareDest/two
2025/06/29 01:21:30 DEBUG : CompareDest/two: trying to read metadata CompareDest/two
2025/06/29 01:21:30 DEBUG : dst/one: trying to read metadata dst/one
2025/06/29 01:21:30 DEBUG : dst/one: trying to read metadata dst/one
2025/06/29 01:21:30 DEBUG : dst/two: trying to read metadata dst/two
2025/06/29 01:21:30 DEBUG : dst/two: trying to read metadata dst/two
--- PASS: TestCopyFileCompareDest (3.67s)
=== RUN   TestCopyFileCopyDest
    run.go:180: Remote "oos:bucket rclone-test-hegagis7kado", Local "Local file system at /tmp/rclone1744522841", Modify Window "1ms"
2025/06/29 01:21:30 DEBUG : Creating backend with remote "TestOracleObjectStorage:rclone-test-hegagis7kado/dst"
2025/06/29 01:21:30 DEBUG : dst: trying to read metadata dst
2025/06/29 01:21:30 DEBUG : one: trying to read metadata one
2025/06/29 01:21:31 DEBUG : Creating backend with remote "TestOracleObjectStorage:rclone-test-hegagis7kado/CopyDest"
2025/06/29 01:21:31 DEBUG : CopyDest: trying to read metadata CopyDest
2025/06/29 01:21:31 DEBUG : one: Need to transfer - File not found at Destination
2025/06/29 01:21:31 DEBUG : one: trying to read metadata one
2025/06/29 01:21:31 DEBUG : one: trying to read metadata one
2025/06/29 01:21:31 DEBUG : one: md5 = f97c5d29941bfb1b2fdab0874906ab82 OK
2025/06/29 01:21:31 INFO  : one: Copied (new)
2025/06/29 01:21:31 DEBUG : dst/one: trying to read metadata dst/one
2025/06/29 01:21:31 DEBUG : dst/one: trying to read metadata dst/one
2025/06/29 01:21:31 DEBUG : dst/one: trying to read metadata dst/one
2025/06/29 01:21:31 DEBUG : dst/one: trying to read metadata dst/one
2025/06/29 01:21:31 DEBUG : one: trying to read metadata one
2025/06/29 01:21:31 DEBUG : one: Sizes differ (src 5 vs dst 3)
2025/06/29 01:21:31 DEBUG : one: trying to read metadata one
2025/06/29 01:21:31 DEBUG : one: trying to read metadata one
2025/06/29 01:21:31 DEBUG : one: md5 = 07912d142f5d63ee918b34796b5a2432 OK
2025/06/29 01:21:31 INFO  : one: Copied (replaced existing)
2025/06/29 01:21:31 DEBUG : dst/one: trying to read metadata dst/one
2025/06/29 01:21:32 DEBUG : dst/one: trying to read metadata dst/one
2025/06/29 01:21:32 DEBUG : dst/one: trying to read metadata dst/one
2025/06/29 01:21:32 DEBUG : CopyDest/one: trying to read metadata CopyDest/one
2025/06/29 01:21:32 DEBUG : CopyDest/one: trying to read metadata CopyDest/one
2025/06/29 01:21:32 DEBUG : CopyDest/one: trying to read metadata CopyDest/one
2025/06/29 01:21:32 DEBUG : dst/one: trying to read metadata dst/one
2025/06/29 01:21:32 DEBUG : dst/one: trying to read metadata dst/one
2025/06/29 01:21:32 DEBUG : one: trying to read metadata one
2025/06/29 01:21:32 DEBUG : Creating backend with remote "TestOracleObjectStorage:rclone-test-hegagis7kado/BackupDir"
2025/06/29 01:21:32 DEBUG : BackupDir: trying to read metadata BackupDir
2025/06/29 01:21:32 DEBUG : one: Sizes differ (src 5 vs dst 3)
2025/06/29 01:21:32 DEBUG : one: trying to read metadata one
2025/06/29 01:21:32 DEBUG : one: trying to read metadata one
2025/06/29 01:21:32 DEBUG : one: Size and modification time the same (differ by 0s, within tolerance 1ms)
2025/06/29 01:21:32 DEBUG : one: Sizes differ (src 5 vs dst 3)
2025/06/29 01:21:32 DEBUG : one: trying to read metadata one
2025/06/29 01:21:33 DEBUG : one: trying to read metadata one
2025/06/29 01:21:33 DEBUG : one: md5 = f97c5d29941bfb1b2fdab0874906ab82 OK
2025/06/29 01:21:33 INFO  : one: Copied (server-side copy)
2025/06/29 01:21:33 INFO  : one: Deleted
2025/06/29 01:21:34 DEBUG : one: trying to read metadata one
2025/06/29 01:21:34 DEBUG : one: md5 = 07912d142f5d63ee918b34796b5a2432 OK
2025/06/29 01:21:34 INFO  : one: Copied (server-side copy)
2025/06/29 01:21:34 DEBUG : one: Destination found in --copy-dest, using server-side copy
2025/06/29 01:21:35 DEBUG : BackupDir/one: trying to read metadata BackupDir/one
2025/06/29 01:21:35 DEBUG : BackupDir/one: trying to read metadata BackupDir/one
2025/06/29 01:21:35 DEBUG : CopyDest/one: trying to read metadata CopyDest/one
2025/06/29 01:21:35 DEBUG : CopyDest/one: trying to read metadata CopyDest/one
2025/06/29 01:21:35 DEBUG : dst/one: trying to read metadata dst/one
2025/06/29 01:21:35 DEBUG : dst/one: trying to read metadata dst/one
2025/06/29 01:21:35 DEBUG : CopyDest/two: trying to read metadata CopyDest/two
2025/06/29 01:21:35 DEBUG : BackupDir/one: trying to read metadata BackupDir/one
2025/06/29 01:21:35 DEBUG : BackupDir/one: trying to read metadata BackupDir/one
2025/06/29 01:21:35 DEBUG : CopyDest/one: trying to read metadata CopyDest/one
2025/06/29 01:21:35 DEBUG : CopyDest/one: trying to read metadata CopyDest/one
2025/06/29 01:21:35 DEBUG : CopyDest/two: trying to read metadata CopyDest/two
2025/06/29 01:21:35 DEBUG : CopyDest/two: trying to read metadata CopyDest/two
2025/06/29 01:21:35 DEBUG : dst/one: trying to read metadata dst/one
2025/06/29 01:21:35 DEBUG : dst/one: trying to read metadata dst/one
2025/06/29 01:21:35 DEBUG : two: trying to read metadata two
2025/06/29 01:21:35 DEBUG : two: Need to transfer - File not found at Destination
2025/06/29 01:21:35 DEBUG : two: trying to read metadata two
2025/06/29 01:21:35 DEBUG : two: trying to read metadata two
2025/06/29 01:21:35 DEBUG : two: Size and modification time the same (differ by 0s, within tolerance 1ms)
2025/06/29 01:21:36 DEBUG : two: trying to read metadata two
2025/06/29 01:21:36 DEBUG : two: md5 = b8a9f715dbb64fd5c56e7783c6820a61 OK
2025/06/29 01:21:36 INFO  : two: Copied (server-side copy)
2025/06/29 01:21:36 DEBUG : two: Destination found in --copy-dest, using server-side copy
2025/06/29 01:21:36 DEBUG : BackupDir/one: trying to read metadata BackupDir/one
2025/06/29 01:21:36 DEBUG : BackupDir/one: trying to read metadata BackupDir/one
2025/06/29 01:21:36 DEBUG : CopyDest/one: trying to read metadata CopyDest/one
2025/06/29 01:21:36 DEBUG : CopyDest/one: trying to read metadata CopyDest/one
2025/06/29 01:21:36 DEBUG : CopyDest/two: trying to read metadata CopyDest/two
2025/06/29 01:21:36 DEBUG : CopyDest/two: trying to read metadata CopyDest/two
2025/06/29 01:21:36 DEBUG : dst/one: trying to read metadata dst/one
2025/06/29 01:21:36 DEBUG : dst/one: trying to read metadata dst/one
2025/06/29 01:21:36 DEBUG : dst/two: trying to read metadata dst/two
2025/06/29 01:21:36 DEBUG : dst/two: trying to read metadata dst/two
2025/06/29 01:21:36 DEBUG : two: trying to read metadata two
2025/06/29 01:21:36 DEBUG : two: trying to read metadata two
2025/06/29 01:21:36 DEBUG : two: Size and modification time the same (differ by 0s, within tolerance 1ms)
2025/06/29 01:21:36 DEBUG : two: Unchanged skipping
2025/06/29 01:21:36 DEBUG : BackupDir/one: trying to read metadata BackupDir/one
2025/06/29 01:21:36 DEBUG : BackupDir/one: trying to read metadata BackupDir/one
2025/06/29 01:21:36 DEBUG : CopyDest/one: trying to read metadata CopyDest/one
2025/06/29 01:21:36 DEBUG : CopyDest/one: trying to read metadata CopyDest/one
2025/06/29 01:21:36 DEBUG : CopyDest/two: trying to read metadata CopyDest/two
2025/06/29 01:21:37 DEBUG : CopyDest/two: trying to read metadata CopyDest/two
2025/06/29 01:21:37 DEBUG : dst/one: trying to read metadata dst/one
2025/06/29 01:21:37 DEBUG : dst/one: trying to read metadata dst/one
2025/06/29 01:21:37 DEBUG : dst/two: trying to read metadata dst/two
2025/06/29 01:21:37 DEBUG : dst/two: trying to read metadata dst/two
2025/06/29 01:21:37 DEBUG : CopyDest/three: trying to read metadata CopyDest/three
2025/06/29 01:21:37 DEBUG : BackupDir/one: trying to read metadata BackupDir/one
2025/06/29 01:21:37 DEBUG : BackupDir/one: trying to read metadata BackupDir/one
2025/06/29 01:21:37 DEBUG : CopyDest/one: trying to read metadata CopyDest/one
2025/06/29 01:21:37 DEBUG : CopyDest/one: trying to read metadata CopyDest/one
2025/06/29 01:21:37 DEBUG : CopyDest/three: trying to read metadata CopyDest/three
2025/06/29 01:21:37 DEBUG : CopyDest/three: trying to read metadata CopyDest/three
2025/06/29 01:21:37 DEBUG : CopyDest/two: trying to read metadata CopyDest/two
2025/06/29 01:21:37 DEBUG : CopyDest/two: trying to read metadata CopyDest/two
2025/06/29 01:21:37 DEBUG : dst/one: trying to read metadata dst/one
2025/06/29 01:21:37 DEBUG : dst/one: trying to read metadata dst/one
2025/06/29 01:21:37 DEBUG : dst/two: trying to read metadata dst/two
2025/06/29 01:21:37 DEBUG : dst/two: trying to read metadata dst/two
2025/06/29 01:21:37 DEBUG : three: trying to read metadata three
2025/06/29 01:21:37 DEBUG : three: Need to transfer - File not found at Destination
2025/06/29 01:21:37 DEBUG : three: trying to read metadata three
2025/06/29 01:21:37 DEBUG : three: Sizes differ (src 7 vs dst 5)
2025/06/29 01:21:37 DEBUG : three: Destination not found in --copy-dest
2025/06/29 01:21:37 DEBUG : three: trying to read metadata three
2025/06/29 01:21:38 DEBUG : three: md5 = 1bccb9dccb3e9f6a3f9d2a8bdb54b7f5 OK
2025/06/29 01:21:38 INFO  : three: Copied (new)
2025/06/29 01:21:38 DEBUG : BackupDir/one: trying to read metadata BackupDir/one
2025/06/29 01:21:38 DEBUG : BackupDir/one: trying to read metadata BackupDir/one
2025/06/29 01:21:38 DEBUG : CopyDest/one: trying to read metadata CopyDest/one
2025/06/29 01:21:38 DEBUG : CopyDest/one: trying to read metadata CopyDest/one
2025/06/29 01:21:38 DEBUG : CopyDest/three: trying to read metadata CopyDest/three
2025/06/29 01:21:38 DEBUG : CopyDest/three: trying to read metadata CopyDest/three
2025/06/29 01:21:38 DEBUG : CopyDest/two: trying to read metadata CopyDest/two
2025/06/29 01:21:38 DEBUG : CopyDest/two: trying to read metadata CopyDest/two
2025/06/29 01:21:38 DEBUG : dst/one: trying to read metadata dst/one
2025/06/29 01:21:38 DEBUG : dst/one: trying to read metadata dst/one
2025/06/29 01:21:38 DEBUG : dst/three: trying to read metadata dst/three
2025/06/29 01:21:38 DEBUG : dst/three: trying to read metadata dst/three
2025/06/29 01:21:38 DEBUG : dst/two: trying to read metadata dst/two
2025/06/29 01:21:38 DEBUG : dst/two: trying to read metadata dst/two
--- PASS: TestCopyFileCopyDest (8.13s)
=== RUN   TestCopyInplace
    run.go:180: Remote "oos:bucket rclone-test-hegagis7kado", Local "Local file system at /tmp/rclone1744522841", Modify Window "1ms"
    copy_test.go:370: Partial uploads not supported
--- SKIP: TestCopyInplace (0.09s)
=== RUN   TestCopyLongFileName
    run.go:180: Remote "oos:bucket rclone-test-hegagis7kado", Local "Local file system at /tmp/rclone1744522841", Modify Window "1ms"
    copy_test.go:403: Partial uploads not supported
--- SKIP: TestCopyLongFileName (0.09s)
=== RUN   TestCopyFileMaxTransfer
    run.go:180: Remote "oos:bucket rclone-test-hegagis7kado", Local "Local file system at /tmp/rclone1744522841", Modify Window "1ms"
2025/06/29 01:21:39 DEBUG : TestCopyFileMaxTransfer/file1: trying to read metadata TestCopyFileMaxTransfer/file1
2025/06/29 01:21:39 DEBUG : TestCopyFileMaxTransfer/file1: Need to transfer - File not found at Destination
2025/06/29 01:21:39 DEBUG : TestCopyFileMaxTransfer/file1: trying to read metadata TestCopyFileMaxTransfer/file1
2025/06/29 01:21:39 DEBUG : TestCopyFileMaxTransfer/file1: md5 = 0ef726ce9b1a7692357ff70dd321d595 OK
2025/06/29 01:21:39 INFO  : TestCopyFileMaxTransfer/file1: Copied (new)
2025/06/29 01:21:39 DEBUG : TestCopyFileMaxTransfer/file1: trying to read metadata TestCopyFileMaxTransfer/file1
2025/06/29 01:21:39 DEBUG : TestCopyFileMaxTransfer/file1: trying to read metadata TestCopyFileMaxTransfer/file1
2025/06/29 01:21:39 DEBUG : TestCopyFileMaxTransfer/file2: trying to read metadata TestCopyFileMaxTransfer/file2
2025/06/29 01:21:39 DEBUG : TestCopyFileMaxTransfer/file2: Need to transfer - File not found at Destination
2025/06/29 01:21:39 ERROR : TestCopyFileMaxTransfer/file2: put object failed Put "https://objectstorage.uk-london-1.oraclecloud.com/n/lrqbljfginym/b/rclone-test-hegagis7kado/o/TestCopyFileMaxTransfer/file2": max transfer limit reached as set by --max-transfer
2025/06/29 01:21:39 ERROR : TestCopyFileMaxTransfer/file2: Failed to copy: Put "https://objectstorage.uk-london-1.oraclecloud.com/n/lrqbljfginym/b/rclone-test-hegagis7kado/o/TestCopyFileMaxTransfer/file2": max transfer limit reached as set by --max-transfer
2025/06/29 01:21:39 DEBUG : TestCopyFileMaxTransfer/file1: trying to read metadata TestCopyFileMaxTransfer/file1
2025/06/29 01:21:39 DEBUG : TestCopyFileMaxTransfer/file1: trying to read metadata TestCopyFileMaxTransfer/file1
2025/06/29 01:21:39 DEBUG : TestCopyFileMaxTransfer/file3: trying to read metadata TestCopyFileMaxTransfer/file3
2025/06/29 01:21:39 DEBUG : TestCopyFileMaxTransfer/file3: Need to transfer - File not found at Destination
2025/06/29 01:21:39 DEBUG : TestCopyFileMaxTransfer/file1: trying to read metadata TestCopyFileMaxTransfer/file1
2025/06/29 01:21:39 DEBUG : TestCopyFileMaxTransfer/file1: trying to read metadata TestCopyFileMaxTransfer/file1
2025/06/29 01:21:39 DEBUG : TestCopyFileMaxTransfer/file4: trying to read metadata TestCopyFileMaxTransfer/file4
2025/06/29 01:21:39 DEBUG : TestCopyFileMaxTransfer/file4: Need to transfer - File not found at Destination
2025/06/29 01:21:40 DEBUG : TestCopyFileMaxTransfer/file4: trying to read metadata TestCopyFileMaxTransfer/file4
2025/06/29 01:21:40 DEBUG : TestCopyFileMaxTransfer/file4: md5 = 48835e103c921c8aa43c77cbe6562bdc OK
2025/06/29 01:21:40 INFO  : TestCopyFileMaxTransfer/file4: Copied (new)
2025/06/29 01:21:40 DEBUG : TestCopyFileMaxTransfer/file1: trying to read metadata TestCopyFileMaxTransfer/file1
2025/06/29 01:21:40 DEBUG : TestCopyFileMaxTransfer/file1: trying to read metadata TestCopyFileMaxTransfer/file1
2025/06/29 01:21:40 DEBUG : TestCopyFileMaxTransfer/file4: trying to read metadata TestCopyFileMaxTransfer/file4
2025/06/29 01:21:40 DEBUG : TestCopyFileMaxTransfer/file4: trying to read metadata TestCopyFileMaxTransfer/file4
--- PASS: TestCopyFileMaxTransfer (1.29s)
=== RUN   TestDeduplicateInteractive
    run.go:180: Remote "oos:bucket rclone-test-hegagis7kado", Local "Local file system at /tmp/rclone1744522841", Modify Window "1ms"
    dedupe_test.go:24: Can't test deduplicate - no duplicate files possible
--- SKIP: TestDeduplicateInteractive (0.09s)
=== RUN   TestDeduplicateSkip
    run.go:180: Remote "oos:bucket rclone-test-hegagis7kado", Local "Local file system at /tmp/rclone1744522841", Modify Window "1ms"
    dedupe_test.go:24: Can't test deduplicate - no duplicate files possible
--- SKIP: TestDeduplicateSkip (0.09s)
=== RUN   TestDeduplicateSizeOnly
    run.go:180: Remote "oos:bucket rclone-test-hegagis7kado", Local "Local file system at /tmp/rclone1744522841", Modify Window "1ms"
    dedupe_test.go:24: Can't test deduplicate - no duplicate files possible
--- SKIP: TestDeduplicateSizeOnly (0.09s)
=== RUN   TestDeduplicateFirst
    run.go:180: Remote "oos:bucket rclone-test-hegagis7kado", Local "Local file system at /tmp/rclone1744522841", Modify Window "1ms"
    dedupe_test.go:24: Can't test deduplicate - no duplicate files possible
--- SKIP: TestDeduplicateFirst (0.09s)
=== RUN   TestDeduplicateNewest
    run.go:180: Remote "oos:bucket rclone-test-hegagis7kado", Local "Local file system at /tmp/rclone1744522841", Modify Window "1ms"
    dedupe_test.go:24: Can't test deduplicate - no duplicate files possible
--- SKIP: TestDeduplicateNewest (0.09s)
=== RUN   TestDeduplicateNewestByHash
    run.go:180: Remote "oos:bucket rclone-test-hegagis7kado", Local "Local file system at /tmp/rclone1744522841", Modify Window "1ms"
2025/06/29 01:21:40 DEBUG : one: trying to read metadata one
2025/06/29 01:21:41 DEBUG : also/one: trying to read metadata also/one
2025/06/29 01:21:41 DEBUG : another: trying to read metadata another
2025/06/29 01:21:41 DEBUG : not-one: trying to read metadata not-one
2025/06/29 01:21:41 DEBUG : also/one: trying to read metadata also/one
2025/06/29 01:21:41 DEBUG : also/one: trying to read metadata also/one
2025/06/29 01:21:41 DEBUG : another: trying to read metadata another
2025/06/29 01:21:41 DEBUG : another: trying to read metadata another
2025/06/29 01:21:41 DEBUG : not-one: trying to read metadata not-one
2025/06/29 01:21:41 DEBUG : not-one: trying to read metadata not-one
2025/06/29 01:21:41 DEBUG : one: trying to read metadata one
2025/06/29 01:21:41 DEBUG : one: trying to read metadata one
2025/06/29 01:21:41 INFO  : oos:bucket rclone-test-hegagis7kado: Looking for duplicate md5 hashes using newest mode.
2025/06/29 01:21:41 DEBUG : also/one: trying to read metadata also/one
2025/06/29 01:21:41 DEBUG : another: trying to read metadata another
2025/06/29 01:21:41 DEBUG : not-one: trying to read metadata not-one
2025/06/29 01:21:41 DEBUG : one: trying to read metadata one
2025/06/29 01:21:41 NOTICE: d7059930c75b84594538e04a36312fa1: Found 3 files with duplicate md5 hashes
2025/06/29 01:21:41 DEBUG : another: trying to read metadata another
2025/06/29 01:21:41 DEBUG : also/one: trying to read metadata also/one
2025/06/29 01:21:41 DEBUG : one: trying to read metadata one
2025/06/29 01:21:41 DEBUG : another: trying to read metadata another
2025/06/29 01:21:41 DEBUG : one: trying to read metadata one
2025/06/29 01:21:41 DEBUG : also/one: trying to read metadata also/one
2025/06/29 01:21:41 INFO  : one: Deleted
2025/06/29 01:21:41 INFO  : also/one: Deleted
2025/06/29 01:21:41 NOTICE: d7059930c75b84594538e04a36312fa1: Deleted 2 extra copies
2025/06/29 01:21:41 DEBUG : another: trying to read metadata another
2025/06/29 01:21:42 DEBUG : another: trying to read metadata another
2025/06/29 01:21:42 DEBUG : not-one: trying to read metadata not-one
2025/06/29 01:21:42 DEBUG : not-one: trying to read metadata not-one
--- PASS: TestDeduplicateNewestByHash (1.42s)
=== RUN   TestDeduplicateOldest
    run.go:180: Remote "oos:bucket rclone-test-hegagis7kado", Local "Local file system at /tmp/rclone1744522841", Modify Window "1ms"
    dedupe_test.go:24: Can't test deduplicate - no duplicate files possible
--- SKIP: TestDeduplicateOldest (0.09s)
=== RUN   TestDeduplicateLargest
    run.go:180: Remote "oos:bucket rclone-test-hegagis7kado", Local "Local file system at /tmp/rclone1744522841", Modify Window "1ms"
    dedupe_test.go:24: Can't test deduplicate - no duplicate files possible
--- SKIP: TestDeduplicateLargest (0.09s)
=== RUN   TestDeduplicateSmallest
    run.go:180: Remote "oos:bucket rclone-test-hegagis7kado", Local "Local file system at /tmp/rclone1744522841", Modify Window "1ms"
    dedupe_test.go:24: Can't test deduplicate - no duplicate files possible
--- SKIP: TestDeduplicateSmallest (0.09s)
=== RUN   TestDeduplicateRename
    run.go:180: Remote "oos:bucket rclone-test-hegagis7kado", Local "Local file system at /tmp/rclone1744522841", Modify Window "1ms"
    dedupe_test.go:24: Can't test deduplicate - no duplicate files possible
--- SKIP: TestDeduplicateRename (0.09s)
=== RUN   TestMergeDirs
    run.go:180: Remote "oos:bucket rclone-test-hegagis7kado", Local "Local file system at /tmp/rclone1744522841", Modify Window "1ms"
    dedupe_test.go:256: Can't merge directories
--- SKIP: TestMergeDirs (0.09s)
=== RUN   TestListDirSorted
    run.go:180: Remote "oos:bucket rclone-test-hegagis7kado", Local "Local file system at /tmp/rclone1744522841", Modify Window "1ms"
2025/06/29 01:21:42 DEBUG : a.txt: trying to read metadata a.txt
2025/06/29 01:21:42 DEBUG : zend.txt: trying to read metadata zend.txt
2025/06/29 01:21:43 DEBUG : sub dir/hello world: trying to read metadata sub dir/hello world
2025/06/29 01:21:43 DEBUG : sub dir/hello world2: trying to read metadata sub dir/hello world2
2025/06/29 01:21:43 DEBUG : sub dir/ignore dir/.ignore: trying to read metadata sub dir/ignore dir/.ignore
2025/06/29 01:21:43 DEBUG : sub dir/ignore dir/should be ignored: trying to read metadata sub dir/ignore dir/should be ignored
2025/06/29 01:21:43 DEBUG : sub dir/sub sub dir/hello world3: trying to read metadata sub dir/sub sub dir/hello world3
2025/06/29 01:21:43 DEBUG : a.txt: trying to read metadata a.txt
2025/06/29 01:21:43 DEBUG : a.txt: trying to read metadata a.txt
2025/06/29 01:21:43 DEBUG : sub dir/hello world: trying to read metadata sub dir/hello world
2025/06/29 01:21:43 DEBUG : sub dir/hello world: trying to read metadata sub dir/hello world
2025/06/29 01:21:43 DEBUG : sub dir/hello world2: trying to read metadata sub dir/hello world2
2025/06/29 01:21:43 DEBUG : sub dir/hello world2: trying to read metadata sub dir/hello world2
2025/06/29 01:21:43 DEBUG : sub dir/ignore dir/.ignore: trying to read metadata sub dir/ignore dir/.ignore
2025/06/29 01:21:43 DEBUG : sub dir/ignore dir/.ignore: trying to read metadata sub dir/ignore dir/.ignore
2025/06/29 01:21:43 DEBUG : sub dir/ignore dir/should be ignored: trying to read metadata sub dir/ignore dir/should be ignored
2025/06/29 01:21:43 DEBUG : sub dir/ignore dir/should be ignored: trying to read metadata sub dir/ignore dir/should be ignored
2025/06/29 01:21:43 DEBUG : sub dir/sub sub dir/hello world3: trying to read metadata sub dir/sub sub dir/hello world3
2025/06/29 01:21:43 DEBUG : sub dir/sub sub dir/hello world3: trying to read metadata sub dir/sub sub dir/hello world3
2025/06/29 01:21:43 DEBUG : zend.txt: trying to read metadata zend.txt
2025/06/29 01:21:43 DEBUG : zend.txt: trying to read metadata zend.txt
2025/06/29 01:21:43 DEBUG : oos:bucket rclone-test-hegagis7kado: listing: bucket : rclone-test-hegagis7kado, directory: 
2025/06/29 01:21:44 DEBUG : oos:bucket rclone-test-hegagis7kado: listing: bucket : rclone-test-hegagis7kado, directory: 
2025/06/29 01:21:44 DEBUG : a.txt: Excluded (Size Filter)
2025/06/29 01:21:44 DEBUG : a.txt: Excluded
2025/06/29 01:21:44 DEBUG : oos:bucket rclone-test-hegagis7kado: listing: bucket : rclone-test-hegagis7kado, directory: sub dir
2025/06/29 01:21:44 DEBUG : oos:bucket rclone-test-hegagis7kado: listing: bucket : rclone-test-hegagis7kado, directory: sub dir
2025/06/29 01:21:44 DEBUG : sub dir/hello world: Excluded (Size Filter)
2025/06/29 01:21:44 DEBUG : sub dir/hello world: Excluded
2025/06/29 01:21:44 DEBUG : sub dir/hello world2: Excluded (Size Filter)
2025/06/29 01:21:44 DEBUG : sub dir/hello world2: Excluded
2025/06/29 01:21:44 DEBUG : oos:bucket rclone-test-hegagis7kado: listing: bucket : rclone-test-hegagis7kado, directory: sub dir
2025/06/29 01:21:44 DEBUG : sub dir/ignore dir/.ignore: trying to read metadata sub dir/ignore dir/.ignore
2025/06/29 01:21:44 DEBUG : sub dir/ignore dir: Excluded
2025/06/29 01:21:44 DEBUG : sub dir/sub sub dir/.ignore: trying to read metadata sub dir/sub sub dir/.ignore
2025/06/29 01:21:44 DEBUG : sub dir/hello world: Excluded (Size Filter)
2025/06/29 01:21:44 DEBUG : sub dir/hello world: Excluded
2025/06/29 01:21:44 DEBUG : sub dir/hello world2: Excluded (Size Filter)
2025/06/29 01:21:44 DEBUG : sub dir/hello world2: Excluded
2025/06/29 01:21:44 DEBUG : oos:bucket rclone-test-hegagis7kado: listing: bucket : rclone-test-hegagis7kado, directory: sub dir/ignore dir
2025/06/29 01:21:44 DEBUG : sub dir/ignore dir: Excluded
2025/06/29 01:21:44 DEBUG : oos:bucket rclone-test-hegagis7kado: listing: bucket : rclone-test-hegagis7kado, directory: sub dir/ignore dir
2025/06/29 01:21:44 DEBUG : oos:bucket rclone-test-hegagis7kado: listing: bucket : rclone-test-hegagis7kado, directory: sub dir/ignore dir
--- PASS: TestListDirSorted (2.25s)
=== RUN   TestListDirSortedFn
    run.go:180: Remote "oos:bucket rclone-test-hegagis7kado", Local "Local file system at /tmp/rclone1744522841", Modify Window "1ms"
2025/06/29 01:21:45 DEBUG : a.txt: trying to read metadata a.txt
2025/06/29 01:21:45 DEBUG : zend.txt: trying to read metadata zend.txt
2025/06/29 01:21:45 DEBUG : sub dir/hello world: trying to read metadata sub dir/hello world
2025/06/29 01:21:45 DEBUG : sub dir/hello world2: trying to read metadata sub dir/hello world2
2025/06/29 01:21:45 DEBUG : sub dir/ignore dir/.ignore: trying to read metadata sub dir/ignore dir/.ignore
2025/06/29 01:21:45 DEBUG : sub dir/ignore dir/should be ignored: trying to read metadata sub dir/ignore dir/should be ignored
2025/06/29 01:21:45 DEBUG : sub dir/sub sub dir/hello world3: trying to read metadata sub dir/sub sub dir/hello world3
2025/06/29 01:21:45 DEBUG : a.txt: trying to read metadata a.txt
2025/06/29 01:21:45 DEBUG : a.txt: trying to read metadata a.txt
2025/06/29 01:21:45 DEBUG : sub dir/hello world: trying to read metadata sub dir/hello world
2025/06/29 01:21:46 DEBUG : sub dir/hello world: trying to read metadata sub dir/hello world
2025/06/29 01:21:46 DEBUG : sub dir/hello world2: trying to read metadata sub dir/hello world2
2025/06/29 01:21:46 DEBUG : sub dir/hello world2: trying to read metadata sub dir/hello world2
2025/06/29 01:21:46 DEBUG : sub dir/ignore dir/.ignore: trying to read metadata sub dir/ignore dir/.ignore
2025/06/29 01:21:46 DEBUG : sub dir/ignore dir/.ignore: trying to read metadata sub dir/ignore dir/.ignore
2025/06/29 01:21:46 DEBUG : sub dir/ignore dir/should be ignored: trying to read metadata sub dir/ignore dir/should be ignored
2025/06/29 01:21:46 DEBUG : sub dir/ignore dir/should be ignored: trying to read metadata sub dir/ignore dir/should be ignored
2025/06/29 01:21:46 DEBUG : sub dir/sub sub dir/hello world3: trying to read metadata sub dir/sub sub dir/hello world3
2025/06/29 01:21:46 DEBUG : sub dir/sub sub dir/hello world3: trying to read metadata sub dir/sub sub dir/hello world3
2025/06/29 01:21:46 DEBUG : zend.txt: trying to read metadata zend.txt
2025/06/29 01:21:46 DEBUG : zend.txt: trying to read metadata zend.txt
2025/06/29 01:21:46 DEBUG : oos:bucket rclone-test-hegagis7kado: listing: bucket : rclone-test-hegagis7kado, directory: 
2025/06/29 01:21:46 DEBUG : oos:bucket rclone-test-hegagis7kado: listing: bucket : rclone-test-hegagis7kado, directory: 
2025/06/29 01:21:46 DEBUG : a.txt: Excluded (Size Filter)
2025/06/29 01:21:46 DEBUG : a.txt: Excluded
2025/06/29 01:21:46 DEBUG : oos:bucket rclone-test-hegagis7kado: listing: bucket : rclone-test-hegagis7kado, directory: sub dir
2025/06/29 01:21:46 DEBUG : oos:bucket rclone-test-hegagis7kado: listing: bucket : rclone-test-hegagis7kado, directory: sub dir
2025/06/29 01:21:46 DEBUG : sub dir/hello world: Excluded (Size Filter)
2025/06/29 01:21:46 DEBUG : sub dir/hello world: Excluded
2025/06/29 01:21:46 DEBUG : sub dir/hello world2: Excluded (Size Filter)
2025/06/29 01:21:46 DEBUG : sub dir/hello world2: Excluded
2025/06/29 01:21:46 DEBUG : oos:bucket rclone-test-hegagis7kado: listing: bucket : rclone-test-hegagis7kado, directory: sub dir
2025/06/29 01:21:46 DEBUG : sub dir/ignore dir/.ignore: trying to read metadata sub dir/ignore dir/.ignore
2025/06/29 01:21:46 DEBUG : sub dir/ignore dir: Excluded
2025/06/29 01:21:46 DEBUG : sub dir/sub sub dir/.ignore: trying to read metadata sub dir/sub sub dir/.ignore
2025/06/29 01:21:46 DEBUG : sub dir/hello world: Excluded (Size Filter)
2025/06/29 01:21:46 DEBUG : sub dir/hello world: Excluded
2025/06/29 01:21:46 DEBUG : sub dir/hello world2: Excluded (Size Filter)
2025/06/29 01:21:46 DEBUG : sub dir/hello world2: Excluded
2025/06/29 01:21:46 DEBUG : oos:bucket rclone-test-hegagis7kado: listing: bucket : rclone-test-hegagis7kado, directory: sub dir/ignore dir
2025/06/29 01:21:46 DEBUG : sub dir/ignore dir: Excluded
2025/06/29 01:21:46 DEBUG : oos:bucket rclone-test-hegagis7kado: listing: bucket : rclone-test-hegagis7kado, directory: sub dir/ignore dir
2025/06/29 01:21:46 DEBUG : oos:bucket rclone-test-hegagis7kado: listing: bucket : rclone-test-hegagis7kado, directory: sub dir/ignore dir
--- PASS: TestListDirSortedFn (2.26s)
=== RUN   TestListJSON
    run.go:180: Remote "oos:bucket rclone-test-hegagis7kado", Local "Local file system at /tmp/rclone1744522841", Modify Window "1ms"
2025/06/29 01:21:47 DEBUG : file1: trying to read metadata file1
2025/06/29 01:21:47 DEBUG : sub/file2: trying to read metadata sub/file2
2025/06/29 01:21:47 DEBUG : file1: trying to read metadata file1
2025/06/29 01:21:47 DEBUG : file1: trying to read metadata file1
2025/06/29 01:21:47 DEBUG : sub/file2: trying to read metadata sub/file2
2025/06/29 01:21:47 DEBUG : sub/file2: trying to read metadata sub/file2
=== RUN   TestListJSON/Default
2025/06/29 01:21:47 DEBUG : oos:bucket rclone-test-hegagis7kado: listing: bucket : rclone-test-hegagis7kado, directory: 
2025/06/29 01:21:47 DEBUG : file1: trying to read metadata file1
2025/06/29 01:21:47 DEBUG : file1: trying to read metadata file1
=== RUN   TestListJSON/FilesOnly
2025/06/29 01:21:47 DEBUG : oos:bucket rclone-test-hegagis7kado: listing: bucket : rclone-test-hegagis7kado, directory: 
2025/06/29 01:21:47 DEBUG : file1: trying to read metadata file1
2025/06/29 01:21:47 DEBUG : file1: trying to read metadata file1
=== RUN   TestListJSON/DirsOnly
2025/06/29 01:21:47 DEBUG : oos:bucket rclone-test-hegagis7kado: listing: bucket : rclone-test-hegagis7kado, directory: 
=== RUN   TestListJSON/Recurse
2025/06/29 01:21:47 DEBUG : file1: trying to read metadata file1
2025/06/29 01:21:47 DEBUG : file1: trying to read metadata file1
2025/06/29 01:21:47 DEBUG : sub/file2: trying to read metadata sub/file2
2025/06/29 01:21:47 DEBUG : sub/file2: trying to read metadata sub/file2
=== RUN   TestListJSON/SubDir
2025/06/29 01:21:47 DEBUG : oos:bucket rclone-test-hegagis7kado: listing: bucket : rclone-test-hegagis7kado, directory: sub
2025/06/29 01:21:48 DEBUG : sub/file2: trying to read metadata sub/file2
2025/06/29 01:21:48 DEBUG : sub/file2: trying to read metadata sub/file2
=== RUN   TestListJSON/NoModTime
2025/06/29 01:21:48 DEBUG : oos:bucket rclone-test-hegagis7kado: listing: bucket : rclone-test-hegagis7kado, directory: 
2025/06/29 01:21:48 DEBUG : file1: trying to read metadata file1
=== RUN   TestListJSON/NoMimeType
2025/06/29 01:21:48 DEBUG : oos:bucket rclone-test-hegagis7kado: listing: bucket : rclone-test-hegagis7kado, directory: 
2025/06/29 01:21:48 DEBUG : file1: trying to read metadata file1
=== RUN   TestListJSON/ShowHash
2025/06/29 01:21:48 DEBUG : oos:bucket rclone-test-hegagis7kado: listing: bucket : rclone-test-hegagis7kado, directory: 
2025/06/29 01:21:48 DEBUG : file1: trying to read metadata file1
2025/06/29 01:21:48 DEBUG : file1: trying to read metadata file1
=== RUN   TestListJSON/HashTypes
2025/06/29 01:21:48 DEBUG : oos:bucket rclone-test-hegagis7kado: listing: bucket : rclone-test-hegagis7kado, directory: 
2025/06/29 01:21:48 DEBUG : file1: trying to read metadata file1
2025/06/29 01:21:48 DEBUG : file1: trying to read metadata file1
=== RUN   TestListJSON/Metadata
2025/06/29 01:21:48 DEBUG : oos:bucket rclone-test-hegagis7kado: listing: bucket : rclone-test-hegagis7kado, directory: 
2025/06/29 01:21:48 DEBUG : file1: trying to read metadata file1
2025/06/29 01:21:48 DEBUG : file1: trying to read metadata file1
--- PASS: TestListJSON (1.48s)
    --- PASS: TestListJSON/Default (0.10s)
    --- PASS: TestListJSON/FilesOnly (0.09s)
    --- PASS: TestListJSON/DirsOnly (0.05s)
    --- PASS: TestListJSON/Recurse (0.13s)
    --- PASS: TestListJSON/SubDir (0.09s)
    --- PASS: TestListJSON/NoModTime (0.09s)
    --- PASS: TestListJSON/NoMimeType (0.08s)
    --- PASS: TestListJSON/ShowHash (0.09s)
    --- PASS: TestListJSON/HashTypes (0.09s)
    --- PASS: TestListJSON/Metadata (0.09s)
=== RUN   TestStatJSON
    run.go:180: Remote "oos:bucket rclone-test-hegagis7kado", Local "Local file system at /tmp/rclone1744522841", Modify Window "1ms"
2025/06/29 01:21:48 DEBUG : file1: trying to read metadata file1
2025/06/29 01:21:48 DEBUG : sub/file2: trying to read metadata sub/file2
2025/06/29 01:21:49 DEBUG : file1: trying to read metadata file1
2025/06/29 01:21:49 DEBUG : file1: trying to read metadata file1
2025/06/29 01:21:49 DEBUG : sub/file2: trying to read metadata sub/file2
2025/06/29 01:21:49 DEBUG : sub/file2: trying to read metadata sub/file2
=== RUN   TestStatJSON/Root
2025/06/29 01:21:49 DEBUG : oos:bucket rclone-test-hegagis7kado: listing: bucket : rclone-test-hegagis7kado, directory: 
=== RUN   TestStatJSON/RootFilesOnly
=== RUN   TestStatJSON/RootDirsOnly
2025/06/29 01:21:49 DEBUG : oos:bucket rclone-test-hegagis7kado: listing: bucket : rclone-test-hegagis7kado, directory: 
=== RUN   TestStatJSON/Dir
2025/06/29 01:21:49 DEBUG : sub: trying to read metadata sub
2025/06/29 01:21:49 DEBUG : oos:bucket rclone-test-hegagis7kado: listing: bucket : rclone-test-hegagis7kado, directory: 
=== RUN   TestStatJSON/DirWithTrailingSlash
2025/06/29 01:21:49 DEBUG : oos:bucket rclone-test-hegagis7kado: listing: bucket : rclone-test-hegagis7kado, directory: 
=== RUN   TestStatJSON/File
2025/06/29 01:21:49 DEBUG : file1: trying to read metadata file1
2025/06/29 01:21:49 DEBUG : file1: trying to read metadata file1
2025/06/29 01:21:49 DEBUG : file1: trying to read metadata file1
=== RUN   TestStatJSON/NotFound
2025/06/29 01:21:49 DEBUG : notfound: trying to read metadata notfound
2025/06/29 01:21:49 DEBUG : oos:bucket rclone-test-hegagis7kado: listing: bucket : rclone-test-hegagis7kado, directory: 
=== RUN   TestStatJSON/DirFilesOnly
2025/06/29 01:21:49 DEBUG : sub: trying to read metadata sub
=== RUN   TestStatJSON/FileFilesOnly
2025/06/29 01:21:49 DEBUG : file1: trying to read metadata file1
2025/06/29 01:21:49 DEBUG : file1: trying to read metadata file1
2025/06/29 01:21:49 DEBUG : file1: trying to read metadata file1
=== RUN   TestStatJSON/NotFoundFilesOnly
2025/06/29 01:21:49 DEBUG : notfound: trying to read metadata notfound
=== RUN   TestStatJSON/DirDirsOnly
2025/06/29 01:21:49 DEBUG : oos:bucket rclone-test-hegagis7kado: listing: bucket : rclone-test-hegagis7kado, directory: 
=== RUN   TestStatJSON/FileDirsOnly
2025/06/29 01:21:49 DEBUG : oos:bucket rclone-test-hegagis7kado: listing: bucket : rclone-test-hegagis7kado, directory: 
=== RUN   TestStatJSON/NotFoundDirsOnly
2025/06/29 01:21:49 DEBUG : oos:bucket rclone-test-hegagis7kado: listing: bucket : rclone-test-hegagis7kado, directory: 
=== RUN   TestStatJSON/RootNotFound
2025/06/29 01:21:49 DEBUG : Creating backend with remote "TestOracleObjectStorage:rclone-test-hegagis7kado/notfound"
2025/06/29 01:21:49 DEBUG : notfound: trying to read metadata notfound
2025/06/29 01:21:50 DEBUG : oos:bucket rclone-test-hegagis7kado, path notfound: listing: bucket : rclone-test-hegagis7kado, directory: 
--- PASS: TestStatJSON (1.60s)
    --- PASS: TestStatJSON/Root (0.06s)
    --- PASS: TestStatJSON/RootFilesOnly (0.00s)
    --- PASS: TestStatJSON/RootDirsOnly (0.04s)
    --- PASS: TestStatJSON/Dir (0.09s)
    --- PASS: TestStatJSON/DirWithTrailingSlash (0.05s)
    --- PASS: TestStatJSON/File (0.05s)
    --- PASS: TestStatJSON/NotFound (0.09s)
    --- PASS: TestStatJSON/DirFilesOnly (0.04s)
    --- PASS: TestStatJSON/FileFilesOnly (0.04s)
    --- PASS: TestStatJSON/NotFoundFilesOnly (0.04s)
    --- PASS: TestStatJSON/DirDirsOnly (0.04s)
    --- PASS: TestStatJSON/FileDirsOnly (0.04s)
    --- PASS: TestStatJSON/NotFoundDirsOnly (0.04s)
    --- PASS: TestStatJSON/RootNotFound (0.34s)
=== RUN   TestMkdir
    run.go:180: Remote "oos:bucket rclone-test-hegagis7kado", Local "Local file system at /tmp/rclone1744522841", Modify Window "1ms"
2025/06/29 01:21:50 INFO  : oos:bucket rclone-test-hegagis7kado: Making directory
2025/06/29 01:21:50 INFO  : oos:bucket rclone-test-hegagis7kado: Making directory
--- PASS: TestMkdir (0.17s)
=== RUN   TestLsd
    run.go:180: Remote "oos:bucket rclone-test-hegagis7kado", Local "Local file system at /tmp/rclone1744522841", Modify Window "1ms"
2025/06/29 01:21:50 DEBUG : sub dir/hello world: trying to read metadata sub dir/hello world
2025/06/29 01:21:50 DEBUG : sub dir/hello world: trying to read metadata sub dir/hello world
2025/06/29 01:21:50 DEBUG : sub dir/hello world: trying to read metadata sub dir/hello world
2025/06/29 01:21:50 DEBUG : oos:bucket rclone-test-hegagis7kado: listing: bucket : rclone-test-hegagis7kado, directory: 
--- PASS: TestLsd (0.43s)
=== RUN   TestLs
    run.go:180: Remote "oos:bucket rclone-test-hegagis7kado", Local "Local file system at /tmp/rclone1744522841", Modify Window "1ms"
2025/06/29 01:21:50 DEBUG : potato2: trying to read metadata potato2
2025/06/29 01:21:51 DEBUG : empty space: trying to read metadata empty space
2025/06/29 01:21:51 DEBUG : empty space: trying to read metadata empty space
2025/06/29 01:21:51 DEBUG : empty space: trying to read metadata empty space
2025/06/29 01:21:51 DEBUG : potato2: trying to read metadata potato2
2025/06/29 01:21:51 DEBUG : potato2: trying to read metadata potato2
--- PASS: TestLs (0.61s)
=== RUN   TestLsWithFilesFrom
    run.go:180: Remote "oos:bucket rclone-test-hegagis7kado", Local "Local file system at /tmp/rclone1744522841", Modify Window "1ms"
2025/06/29 01:21:51 DEBUG : potato2: trying to read metadata potato2
2025/06/29 01:21:51 DEBUG : empty space: trying to read metadata empty space
2025/06/29 01:21:51 DEBUG : empty space: trying to read metadata empty space
2025/06/29 01:21:51 DEBUG : empty space: trying to read metadata empty space
2025/06/29 01:21:51 DEBUG : potato2: trying to read metadata potato2
2025/06/29 01:21:51 DEBUG : potato2: trying to read metadata potato2
2025/06/29 01:21:51 DEBUG : oos:bucket rclone-test-hegagis7kado: listing: bucket : rclone-test-hegagis7kado, directory: 
2025/06/29 01:21:51 DEBUG : empty space: Excluded (FilesFrom Filter)
2025/06/29 01:21:51 DEBUG : empty space: Excluded
2025/06/29 01:21:51 DEBUG : potato2: trying to read metadata potato2
2025/06/29 01:21:51 DEBUG : notfound: trying to read metadata notfound
--- PASS: TestLsWithFilesFrom (0.74s)
=== RUN   TestLsLong
    run.go:180: Remote "oos:bucket rclone-test-hegagis7kado", Local "Local file system at /tmp/rclone1744522841", Modify Window "1ms"
2025/06/29 01:21:52 DEBUG : potato2: trying to read metadata potato2
2025/06/29 01:21:52 DEBUG : empty space: trying to read metadata empty space
2025/06/29 01:21:52 DEBUG : empty space: trying to read metadata empty space
2025/06/29 01:21:52 DEBUG : empty space: trying to read metadata empty space
2025/06/29 01:21:52 DEBUG : potato2: trying to read metadata potato2
2025/06/29 01:21:52 DEBUG : potato2: trying to read metadata potato2
2025/06/29 01:21:52 DEBUG : empty space: trying to read metadata empty space
2025/06/29 01:21:52 DEBUG : potato2: trying to read metadata potato2
--- PASS: TestLsLong (0.71s)
=== RUN   TestHashSums
    run.go:180: Remote "oos:bucket rclone-test-hegagis7kado", Local "Local file system at /tmp/rclone1744522841", Modify Window "1ms"
2025/06/29 01:21:53 DEBUG : potato2: trying to read metadata potato2
2025/06/29 01:21:53 DEBUG : empty space: trying to read metadata empty space
2025/06/29 01:21:53 DEBUG : empty space: trying to read metadata empty space
2025/06/29 01:21:53 DEBUG : empty space: trying to read metadata empty space
2025/06/29 01:21:53 DEBUG : potato2: trying to read metadata potato2
2025/06/29 01:21:53 DEBUG : potato2: trying to read metadata potato2
=== RUN   TestHashSums/Md5
2025/06/29 01:21:53 DEBUG : potato2: trying to read metadata potato2
2025/06/29 01:21:53 DEBUG : empty space: trying to read metadata empty space
=== RUN   TestHashSums/Md5Download
--- PASS: TestHashSums (0.98s)
    --- PASS: TestHashSums/Md5 (0.18s)
    --- PASS: TestHashSums/Md5Download (0.12s)
=== RUN   TestHashSumsWithErrors
2025/06/29 01:21:53 DEBUG : Creating backend with remote ":memory:"
2025/06/29 01:21:53 DEBUG : Config file has changed externally - reloading
2025/06/29 01:21:53 ERROR : file1: hash unsupported: hash type not supported
--- PASS: TestHashSumsWithErrors (0.00s)
=== RUN   TestHashStream
2025/06/29 01:21:53 DEBUG : Creating md5 hash of 0 bytes read from input stream
2025/06/29 01:21:53 DEBUG : Creating md5 hash of 0 bytes read from input stream
2025/06/29 01:21:53 DEBUG : Creating sha1 hash of 0 bytes read from input stream
2025/06/29 01:21:53 DEBUG : Creating sha1 hash of 0 bytes read from input stream
2025/06/29 01:21:53 DEBUG : Creating md5 hash of 12 bytes read from input stream
2025/06/29 01:21:53 DEBUG : Creating md5 hash of 12 bytes read from input stream
2025/06/29 01:21:53 DEBUG : Creating sha1 hash of 12 bytes read from input stream
2025/06/29 01:21:53 DEBUG : Creating sha1 hash of 12 bytes read from input stream
--- PASS: TestHashStream (0.00s)
=== RUN   TestSuffixName
--- PASS: TestSuffixName (0.00s)
=== RUN   TestCount
    run.go:180: Remote "oos:bucket rclone-test-hegagis7kado", Local "Local file system at /tmp/rclone1744522841", Modify Window "1ms"
2025/06/29 01:21:54 DEBUG : potato2: trying to read metadata potato2
2025/06/29 01:21:54 DEBUG : empty space: trying to read metadata empty space
2025/06/29 01:21:54 DEBUG : sub dir/potato3: trying to read metadata sub dir/potato3
2025/06/29 01:21:54 DEBUG : empty space: trying to read metadata empty space
2025/06/29 01:21:54 DEBUG : empty space: trying to read metadata empty space
2025/06/29 01:21:54 DEBUG : potato2: trying to read metadata potato2
2025/06/29 01:21:54 DEBUG : potato2: trying to read metadata potato2
2025/06/29 01:21:54 DEBUG : sub dir/potato3: trying to read metadata sub dir/potato3
2025/06/29 01:21:54 DEBUG : sub dir/potato3: trying to read metadata sub dir/potato3
2025/06/29 01:21:54 DEBUG : oos:bucket rclone-test-hegagis7kado: listing: bucket : rclone-test-hegagis7kado, directory: 
--- PASS: TestCount (0.85s)
=== RUN   TestDelete
    run.go:180: Remote "oos:bucket rclone-test-hegagis7kado", Local "Local file system at /tmp/rclone1744522841", Modify Window "1ms"
2025/06/29 01:21:54 DEBUG : small: trying to read metadata small
2025/06/29 01:21:55 DEBUG : medium: trying to read metadata medium
2025/06/29 01:21:55 DEBUG : large: trying to read metadata large
2025/06/29 01:21:55 DEBUG : large: trying to read metadata large
2025/06/29 01:21:55 DEBUG : large: trying to read metadata large
2025/06/29 01:21:55 DEBUG : medium: trying to read metadata medium
2025/06/29 01:21:55 DEBUG : medium: trying to read metadata medium
2025/06/29 01:21:55 DEBUG : small: trying to read metadata small
2025/06/29 01:21:55 DEBUG : small: trying to read metadata small
2025/06/29 01:21:55 DEBUG : Waiting for deletions to finish
2025/06/29 01:21:55 DEBUG : large: Excluded (Size Filter)
2025/06/29 01:21:55 INFO  : small: Deleted
2025/06/29 01:21:55 INFO  : medium: Deleted
2025/06/29 01:21:55 DEBUG : large: trying to read metadata large
2025/06/29 01:21:55 DEBUG : large: trying to read metadata large
--- PASS: TestDelete (0.90s)
=== RUN   TestMaxDelete
    run.go:180: Remote "oos:bucket rclone-test-hegagis7kado", Local "Local file system at /tmp/rclone1744522841", Modify Window "1ms"
2025/06/29 01:21:55 DEBUG : small: trying to read metadata small
2025/06/29 01:21:55 DEBUG : medium: trying to read metadata medium
2025/06/29 01:21:56 DEBUG : large: trying to read metadata large
2025/06/29 01:21:56 DEBUG : large: trying to read metadata large
2025/06/29 01:21:56 DEBUG : large: trying to read metadata large
2025/06/29 01:21:56 DEBUG : medium: trying to read metadata medium
2025/06/29 01:21:56 DEBUG : medium: trying to read metadata medium
2025/06/29 01:21:56 DEBUG : small: trying to read metadata small
2025/06/29 01:21:56 DEBUG : small: trying to read metadata small
2025/06/29 01:21:56 DEBUG : Waiting for deletions to finish
2025/06/29 01:21:56 ERROR : small: Got fatal error on delete: --max-delete threshold reached
2025/06/29 01:21:56 INFO  : medium: Deleted
2025/06/29 01:21:56 INFO  : large: Deleted
--- PASS: TestMaxDelete (0.93s)
=== RUN   TestMaxDeleteSizeLargeFile
    run.go:180: Remote "oos:bucket rclone-test-hegagis7kado", Local "Local file system at /tmp/rclone1744522841", Modify Window "1ms"
2025/06/29 01:21:56 DEBUG : small: trying to read metadata small
2025/06/29 01:21:56 DEBUG : medium: trying to read metadata medium
2025/06/29 01:21:56 DEBUG : large: trying to read metadata large
2025/06/29 01:21:57 DEBUG : large: trying to read metadata large
2025/06/29 01:21:57 DEBUG : large: trying to read metadata large
2025/06/29 01:21:57 DEBUG : medium: trying to read metadata medium
2025/06/29 01:21:57 DEBUG : medium: trying to read metadata medium
2025/06/29 01:21:57 DEBUG : small: trying to read metadata small
2025/06/29 01:21:57 DEBUG : small: trying to read metadata small
2025/06/29 01:21:57 DEBUG : Waiting for deletions to finish
2025/06/29 01:21:57 ERROR : large: Got fatal error on delete: --max-delete-size threshold reached
2025/06/29 01:21:57 INFO  : small: Deleted
2025/06/29 01:21:57 INFO  : medium: Deleted
2025/06/29 01:21:57 DEBUG : large: trying to read metadata large
2025/06/29 01:21:57 DEBUG : large: trying to read metadata large
--- PASS: TestMaxDeleteSizeLargeFile (1.00s)
=== RUN   TestMaxDeleteSize
    run.go:180: Remote "oos:bucket rclone-test-hegagis7kado", Local "Local file system at /tmp/rclone1744522841", Modify Window "1ms"
2025/06/29 01:21:57 DEBUG : small: trying to read metadata small
2025/06/29 01:21:57 DEBUG : medium: trying to read metadata medium
2025/06/29 01:21:57 DEBUG : large: trying to read metadata large
2025/06/29 01:21:58 DEBUG : large: trying to read metadata large
2025/06/29 01:21:58 DEBUG : large: trying to read metadata large
2025/06/29 01:21:58 DEBUG : medium: trying to read metadata medium
2025/06/29 01:21:58 DEBUG : medium: trying to read metadata medium
2025/06/29 01:21:58 DEBUG : small: trying to read metadata small
2025/06/29 01:21:58 DEBUG : small: trying to read metadata small
2025/06/29 01:21:58 DEBUG : Waiting for deletions to finish
2025/06/29 01:21:58 ERROR : small: Got fatal error on delete: --max-delete-size threshold reached
2025/06/29 01:21:58 INFO  : medium: Deleted
2025/06/29 01:21:58 INFO  : large: Deleted
--- PASS: TestMaxDeleteSize (0.97s)
=== RUN   TestReadFile
    run.go:180: Remote "oos:bucket rclone-test-hegagis7kado", Local "Local file system at /tmp/rclone1744522841", Modify Window "1ms"
2025/06/29 01:21:58 DEBUG : ReadFile: trying to read metadata ReadFile
2025/06/29 01:21:58 DEBUG : ReadFile: trying to read metadata ReadFile
2025/06/29 01:21:58 DEBUG : ReadFile: trying to read metadata ReadFile
2025/06/29 01:21:58 DEBUG : ReadFile: trying to read metadata ReadFile
--- PASS: TestReadFile (0.53s)
=== RUN   TestRetry
2025/06/29 01:21:59 DEBUG : Received error: Wrapped EOF is retriable: EOF - low level retry 1/5
2025/06/29 01:21:59 DEBUG : Received error: Wrapped EOF is retriable: EOF - low level retry 2/5
2025/06/29 01:21:59 DEBUG : Sleeping for 10ms (as indicated by the server) to obey Retry-After error: BANG: trying again in 10ms
2025/06/29 01:21:59 DEBUG : Sleeping for 10ms (as indicated by the server) to obey Retry-After error: BANG: trying again in 10ms
2025/06/29 01:21:59 DEBUG : Sleeping for 10ms (as indicated by the server) to obey Retry-After error: BANG: trying again in 10ms
2025/06/29 01:21:59 DEBUG : Sleeping for 10ms (as indicated by the server) to obey Retry-After error: BANG: trying again in 10ms
2025/06/29 01:21:59 DEBUG : Sleeping for 10ms (as indicated by the server) to obey Retry-After error: BANG: trying again in 10ms
--- PASS: TestRetry (0.05s)
=== RUN   TestCat
    run.go:180: Remote "oos:bucket rclone-test-hegagis7kado", Local "Local file system at /tmp/rclone1744522841", Modify Window "1ms"
2025/06/29 01:21:59 DEBUG : file1: trying to read metadata file1
2025/06/29 01:21:59 DEBUG : file2: trying to read metadata file2
2025/06/29 01:21:59 DEBUG : file1: trying to read metadata file1
2025/06/29 01:21:59 DEBUG : file1: trying to read metadata file1
2025/06/29 01:21:59 DEBUG : file2: trying to read metadata file2
2025/06/29 01:21:59 DEBUG : file2: trying to read metadata file2
--- PASS: TestCat (1.28s)
=== RUN   TestPurge
2025/06/29 01:22:00 DEBUG : Creating backend with remote "TestOracleObjectStorage:rclone-test-mibevoy8xoli"
2025/06/29 01:22:00 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2025/06/29 01:22:00 DEBUG : Creating backend with remote "/tmp/rclone3523971417"
    run.go:180: Remote "oos:bucket rclone-test-mibevoy8xoli", Local "Local file system at /tmp/rclone3523971417", Modify Window "1ms"
2025/06/29 01:22:00 INFO  : oos:bucket rclone-test-mibevoy8xoli: Bucket "rclone-test-mibevoy8xoli" created with accessType "NoPublicAccess"
2025/06/29 01:22:00 DEBUG : A1/B1/C1/one: trying to read metadata A1/B1/C1/one
2025/06/29 01:22:00 INFO  : A2: Making directory
2025/06/29 01:22:00 INFO  : A1/B2: Making directory
2025/06/29 01:22:00 INFO  : A1/B2/C2: Making directory
2025/06/29 01:22:00 INFO  : A1/B1/C3: Making directory
2025/06/29 01:22:00 INFO  : A3: Making directory
2025/06/29 01:22:00 INFO  : A3/B3: Making directory
2025/06/29 01:22:00 INFO  : A3/B3/C4: Making directory
2025/06/29 01:22:00 DEBUG : A1/two: trying to read metadata A1/two
    fstest.go:247: Filtering empty directory "A2"
    fstest.go:247: Filtering empty directory "A1/B2"
    fstest.go:247: Filtering empty directory "A1/B2/C2"
    fstest.go:247: Filtering empty directory "A1/B1/C3"
    fstest.go:247: Filtering empty directory "A3"
    fstest.go:247: Filtering empty directory "A3/B3"
    fstest.go:247: Filtering empty directory "A3/B3/C4"
2025/06/29 01:22:01 DEBUG : A1/B1/C1/one: trying to read metadata A1/B1/C1/one
2025/06/29 01:22:01 DEBUG : A1/B1/C1/one: trying to read metadata A1/B1/C1/one
2025/06/29 01:22:01 DEBUG : A1/two: trying to read metadata A1/two
2025/06/29 01:22:01 DEBUG : A1/two: trying to read metadata A1/two
2025/06/29 01:22:01 DEBUG : Waiting for deletions to finish
2025/06/29 01:22:01 INFO  : A1/B1/C1/one: Deleted
2025/06/29 01:22:01 DEBUG : oos:bucket rclone-test-mibevoy8xoli: listing: bucket : rclone-test-mibevoy8xoli, directory: A1/B1
2025/06/29 01:22:01 DEBUG : removing 1 level 2 directories
2025/06/29 01:22:01 INFO  : A1/B1: Removing directory
    fstest.go:247: Filtering empty directory "A2"
    fstest.go:247: Filtering empty directory "A1/B2"
    fstest.go:247: Filtering empty directory "A1/B2/C2"
    fstest.go:247: Filtering empty directory "A3"
    fstest.go:247: Filtering empty directory "A3/B3"
    fstest.go:247: Filtering empty directory "A3/B3/C4"
2025/06/29 01:22:01 DEBUG : A1/two: trying to read metadata A1/two
2025/06/29 01:22:01 DEBUG : A1/two: trying to read metadata A1/two
2025/06/29 01:22:01 DEBUG : Waiting for deletions to finish
2025/06/29 01:22:01 INFO  : A1/two: Deleted
2025/06/29 01:22:01 DEBUG : oos:bucket rclone-test-mibevoy8xoli: listing: bucket : rclone-test-mibevoy8xoli, directory: 
2025/06/29 01:22:01 DEBUG : removing 1 level 0 directories
2025/06/29 01:22:01 INFO  : oos:bucket rclone-test-mibevoy8xoli: Removing directory
2025/06/29 01:22:03 INFO  : oos:bucket rclone-test-mibevoy8xoli: Bucket "rclone-test-mibevoy8xoli" deleted
2025/06/29 01:22:03 DEBUG : oos:bucket rclone-test-mibevoy8xoli: Purge dir ""
2025/06/29 01:22:03 NOTICE: purge failed to rmdir "": bucket already deleted
2025/06/29 01:22:03 NOTICE: purge failed: directory not found
--- PASS: TestPurge (3.16s)
=== RUN   TestRmdirsNoLeaveRoot
    run.go:180: Remote "oos:bucket rclone-test-hegagis7kado", Local "Local file system at /tmp/rclone1744522841", Modify Window "1ms"
2025/06/29 01:22:03 DEBUG : A1/B1/C1/one: trying to read metadata A1/B1/C1/one
2025/06/29 01:22:03 INFO  : A2: Making directory
2025/06/29 01:22:03 INFO  : A1/B2: Making directory
2025/06/29 01:22:03 INFO  : A1/B2/C2: Making directory
2025/06/29 01:22:03 INFO  : A1/B1/C3: Making directory
2025/06/29 01:22:03 INFO  : A3: Making directory
2025/06/29 01:22:03 INFO  : A3/B3: Making directory
2025/06/29 01:22:03 INFO  : A3/B3/C4: Making directory
2025/06/29 01:22:03 DEBUG : A1/two: trying to read metadata A1/two
    fstest.go:247: Filtering empty directory "A2"
    fstest.go:247: Filtering empty directory "A1/B2"
    fstest.go:247: Filtering empty directory "A1/B2/C2"
    fstest.go:247: Filtering empty directory "A1/B1/C3"
    fstest.go:247: Filtering empty directory "A3"
    fstest.go:247: Filtering empty directory "A3/B3"
    fstest.go:247: Filtering empty directory "A3/B3/C4"
2025/06/29 01:22:03 DEBUG : A1/B1/C1/one: trying to read metadata A1/B1/C1/one
2025/06/29 01:22:03 DEBUG : A1/B1/C1/one: trying to read metadata A1/B1/C1/one
2025/06/29 01:22:03 DEBUG : A1/two: trying to read metadata A1/two
2025/06/29 01:22:04 DEBUG : A1/two: trying to read metadata A1/two
2025/06/29 01:22:04 DEBUG : oos:bucket rclone-test-hegagis7kado: listing: bucket : rclone-test-hegagis7kado, directory: A3/B3/C4
2025/06/29 01:22:04 DEBUG : removing 1 level 3 directories
2025/06/29 01:22:04 INFO  : A3/B3/C4: Removing directory
    fstest.go:247: Filtering empty directory "A2"
    fstest.go:247: Filtering empty directory "A1/B2"
    fstest.go:247: Filtering empty directory "A1/B2/C2"
    fstest.go:247: Filtering empty directory "A1/B1/C3"
    fstest.go:247: Filtering empty directory "A3"
    fstest.go:247: Filtering empty directory "A3/B3"
2025/06/29 01:22:04 DEBUG : A1/B1/C1/one: trying to read metadata A1/B1/C1/one
2025/06/29 01:22:04 DEBUG : A1/B1/C1/one: trying to read metadata A1/B1/C1/one
2025/06/29 01:22:04 DEBUG : A1/two: trying to read metadata A1/two
2025/06/29 01:22:04 DEBUG : A1/two: trying to read metadata A1/two
2025/06/29 01:22:04 DEBUG : oos:bucket rclone-test-hegagis7kado: listing: bucket : rclone-test-hegagis7kado, directory: 
2025/06/29 01:22:04 DEBUG : oos:bucket rclone-test-hegagis7kado: listing: bucket : rclone-test-hegagis7kado, directory: A1
2025/06/29 01:22:04 DEBUG : oos:bucket rclone-test-hegagis7kado: listing: bucket : rclone-test-hegagis7kado, directory: A1/B1
2025/06/29 01:22:04 DEBUG : oos:bucket rclone-test-hegagis7kado: listing: bucket : rclone-test-hegagis7kado, directory: A1/B1/C1
2025/06/29 01:22:04 DEBUG : A1/B1/C1/one: trying to read metadata A1/B1/C1/one
2025/06/29 01:22:04 DEBUG : A1/B1/C1/one: trying to read metadata A1/B1/C1/one
2025/06/29 01:22:04 DEBUG : A1/two: trying to read metadata A1/two
2025/06/29 01:22:04 DEBUG : A1/two: trying to read metadata A1/two
2025/06/29 01:22:04 DEBUG : A1/B1/C1/one: trying to read metadata A1/B1/C1/one
2025/06/29 01:22:04 DEBUG : A1/two: trying to read metadata A1/two
2025/06/29 01:22:04 DEBUG : oos:bucket rclone-test-hegagis7kado: listing: bucket : rclone-test-hegagis7kado, directory: 
2025/06/29 01:22:04 DEBUG : removing 1 level 0 directories
2025/06/29 01:22:04 INFO  : oos:bucket rclone-test-hegagis7kado: Removing directory
2025/06/29 01:22:06 INFO  : oos:bucket rclone-test-hegagis7kado: Bucket "rclone-test-hegagis7kado" deleted
--- PASS: TestRmdirsNoLeaveRoot (3.26s)
=== RUN   TestRmdirsLeaveRoot
    run.go:180: Remote "oos:bucket rclone-test-hegagis7kado", Local "Local file system at /tmp/rclone1744522841", Modify Window "1ms"
2025/06/29 01:22:06 INFO  : oos:bucket rclone-test-hegagis7kado: Bucket "rclone-test-hegagis7kado" created with accessType "NoPublicAccess"
2025/06/29 01:22:06 INFO  : A1: Making directory
2025/06/29 01:22:06 INFO  : A1/B1: Making directory
2025/06/29 01:22:06 INFO  : A1/B1/C1: Making directory
    fstest.go:247: Filtering empty directory "A1"
    fstest.go:247: Filtering empty directory "A1/B1"
    fstest.go:247: Filtering empty directory "A1/B1/C1"
2025/06/29 01:22:07 DEBUG : oos:bucket rclone-test-hegagis7kado: listing: bucket : rclone-test-hegagis7kado, directory: A1
    fstest.go:247: Filtering empty directory "A1"
--- PASS: TestRmdirsLeaveRoot (0.33s)
=== RUN   TestRmdirsWithFilter
    run.go:180: Remote "oos:bucket rclone-test-hegagis7kado", Local "Local file system at /tmp/rclone1744522841", Modify Window "1ms"
2025/06/29 01:22:07 INFO  : A1: Making directory
2025/06/29 01:22:07 INFO  : A1/B1: Making directory
2025/06/29 01:22:07 INFO  : A1/B1/C1: Making directory
    fstest.go:247: Filtering empty directory "A1"
    fstest.go:247: Filtering empty directory "A1/B1"
    fstest.go:247: Filtering empty directory "A1/B1/C1"
2025/06/29 01:22:07 DEBUG : oos:bucket rclone-test-hegagis7kado: listing: bucket : rclone-test-hegagis7kado, directory: 
    fstest.go:247: Filtering empty directory "A1"
--- PASS: TestRmdirsWithFilter (0.23s)
=== RUN   TestCopyURL
    run.go:180: Remote "oos:bucket rclone-test-hegagis7kado", Local "Local file system at /tmp/rclone1744522841", Modify Window "1ms"
2025/06/29 01:22:07 DEBUG : file1: trying to read metadata file1
2025/06/29 01:22:07 DEBUG : file1: trying to read metadata file1
2025/06/29 01:22:07 DEBUG : file1: trying to read metadata file1
2025/06/29 01:22:07 DEBUG : file1: trying to read metadata file1
2025/06/29 01:22:07 DEBUG : filename.txt: File name found in url
2025/06/29 01:22:07 DEBUG : filename.txt: trying to read metadata filename.txt
2025/06/29 01:22:07 DEBUG : headerfilename.txt: filename found in Content-Disposition header.
2025/06/29 01:22:08 DEBUG : headerfilename.txt: trying to read metadata headerfilename.txt
2025/06/29 01:22:08 DEBUG : file2: trying to read metadata file2
2025/06/29 01:22:08 DEBUG : file1: trying to read metadata file1
2025/06/29 01:22:08 DEBUG : file1: trying to read metadata file1
2025/06/29 01:22:08 DEBUG : file2: trying to read metadata file2
2025/06/29 01:22:08 DEBUG : file2: trying to read metadata file2
2025/06/29 01:22:08 DEBUG : filename.txt: trying to read metadata filename.txt
2025/06/29 01:22:08 DEBUG : filename.txt: trying to read metadata filename.txt
2025/06/29 01:22:08 DEBUG : headerfilename.txt: trying to read metadata headerfilename.txt
2025/06/29 01:22:08 DEBUG : headerfilename.txt: trying to read metadata headerfilename.txt
--- PASS: TestCopyURL (1.28s)
=== RUN   TestCopyURLToWriter
--- PASS: TestCopyURLToWriter (0.00s)
=== RUN   TestMoveFile
    run.go:180: Remote "oos:bucket rclone-test-hegagis7kado", Local "Local file system at /tmp/rclone1744522841", Modify Window "1ms"
2025/06/29 01:22:08 DEBUG : sub/file2: trying to read metadata sub/file2
2025/06/29 01:22:08 DEBUG : file1: Need to transfer - File not found at Destination
2025/06/29 01:22:08 DEBUG : sub/file2: trying to read metadata sub/file2
2025/06/29 01:22:08 DEBUG : file1: md5 = 0ef726ce9b1a7692357ff70dd321d595 OK
2025/06/29 01:22:08 INFO  : file1: Copied (new) to: sub/file2
2025/06/29 01:22:08 INFO  : file1: Deleted
2025/06/29 01:22:08 DEBUG : sub/file2: trying to read metadata sub/file2
2025/06/29 01:22:08 DEBUG : sub/file2: trying to read metadata sub/file2
2025/06/29 01:22:08 DEBUG : sub/file2: trying to read metadata sub/file2
2025/06/29 01:22:09 DEBUG : sub/file2: trying to read metadata sub/file2
2025/06/29 01:22:09 DEBUG : file1: Size and modification time the same (differ by 0s, within tolerance 1ms)
2025/06/29 01:22:09 DEBUG : file1: Unchanged skipping
2025/06/29 01:22:09 INFO  : file1: Deleted
2025/06/29 01:22:09 DEBUG : sub/file2: trying to read metadata sub/file2
2025/06/29 01:22:09 DEBUG : sub/file2: trying to read metadata sub/file2
2025/06/29 01:22:09 DEBUG : oos:bucket rclone-test-hegagis7kado: don't need to copy/move sub/file2, it is already at target location
2025/06/29 01:22:09 DEBUG : sub/file2: trying to read metadata sub/file2
2025/06/29 01:22:09 DEBUG : sub/file2: trying to read metadata sub/file2
--- PASS: TestMoveFile (0.64s)
=== RUN   TestMoveFileWithIgnoreExisting
    run.go:180: Remote "oos:bucket rclone-test-hegagis7kado", Local "Local file system at /tmp/rclone1744522841", Modify Window "1ms"
2025/06/29 01:22:09 DEBUG : file1: trying to read metadata file1
2025/06/29 01:22:09 DEBUG : file1: Need to transfer - File not found at Destination
2025/06/29 01:22:09 DEBUG : file1: trying to read metadata file1
2025/06/29 01:22:09 DEBUG : file1: md5 = 0ef726ce9b1a7692357ff70dd321d595 OK
2025/06/29 01:22:09 INFO  : file1: Copied (new)
2025/06/29 01:22:09 INFO  : file1: Deleted
2025/06/29 01:22:09 DEBUG : file1: trying to read metadata file1
2025/06/29 01:22:09 DEBUG : file1: trying to read metadata file1
2025/06/29 01:22:09 DEBUG : file1: trying to read metadata file1
2025/06/29 01:22:09 DEBUG : file1: Destination exists, skipping
2025/06/29 01:22:09 DEBUG : file1: Not removing source file as destination file exists and --ignore-existing is set
2025/06/29 01:22:09 DEBUG : file1: trying to read metadata file1
2025/06/29 01:22:09 DEBUG : file1: trying to read metadata file1
--- PASS: TestMoveFileWithIgnoreExisting (0.56s)
=== RUN   TestCaseInsensitiveMoveFile
    run.go:180: Remote "oos:bucket rclone-test-hegagis7kado", Local "Local file system at /tmp/rclone1744522841", Modify Window "1ms"
--- PASS: TestCaseInsensitiveMoveFile (0.09s)
=== RUN   TestCaseInsensitiveMoveFileDryRun
    run.go:180: Remote "oos:bucket rclone-test-hegagis7kado", Local "Local file system at /tmp/rclone1744522841", Modify Window "1ms"
--- PASS: TestCaseInsensitiveMoveFileDryRun (0.09s)
=== RUN   TestMoveFileBackupDir
    run.go:180: Remote "oos:bucket rclone-test-hegagis7kado", Local "Local file system at /tmp/rclone1744522841", Modify Window "1ms"
2025/06/29 01:22:10 DEBUG : dst/file1: trying to read metadata dst/file1
2025/06/29 01:22:10 DEBUG : dst/file1: trying to read metadata dst/file1
2025/06/29 01:22:10 DEBUG : dst/file1: trying to read metadata dst/file1
2025/06/29 01:22:10 DEBUG : dst/file1: trying to read metadata dst/file1
2025/06/29 01:22:10 DEBUG : Creating backend with remote "TestOracleObjectStorage:rclone-test-hegagis7kado/backup"
2025/06/29 01:22:10 DEBUG : backup: trying to read metadata backup
2025/06/29 01:22:10 DEBUG : dst/file1: Sizes differ (src 14 vs dst 18)
2025/06/29 01:22:10 DEBUG : dst/file1: trying to read metadata dst/file1
2025/06/29 01:22:12 DEBUG : dst/file1: trying to read metadata dst/file1
2025/06/29 01:22:12 DEBUG : dst/file1: md5 = 05164b153084ba910184c26e561a7c18 OK
2025/06/29 01:22:12 INFO  : dst/file1: Copied (server-side copy)
2025/06/29 01:22:12 INFO  : dst/file1: Deleted
2025/06/29 01:22:12 DEBUG : dst/file1: trying to read metadata dst/file1
2025/06/29 01:22:12 DEBUG : dst/file1: md5 = 0ef726ce9b1a7692357ff70dd321d595 OK
2025/06/29 01:22:12 INFO  : dst/file1: Copied (new)
2025/06/29 01:22:12 INFO  : dst/file1: Deleted
2025/06/29 01:22:12 DEBUG : backup/dst/file1: trying to read metadata backup/dst/file1
2025/06/29 01:22:12 DEBUG : backup/dst/file1: trying to read metadata backup/dst/file1
2025/06/29 01:22:12 DEBUG : dst/file1: trying to read metadata dst/file1
2025/06/29 01:22:12 DEBUG : dst/file1: trying to read metadata dst/file1
--- PASS: TestMoveFileBackupDir (2.70s)
=== RUN   TestSameConfig
--- PASS: TestSameConfig (0.00s)
=== RUN   TestSame
--- PASS: TestSame (0.00s)
=== RUN   TestOverlappingFilterCheckWithoutFilter
--- PASS: TestOverlappingFilterCheckWithoutFilter (0.00s)
=== RUN   TestOverlappingFilterCheckWithFilter
--- PASS: TestOverlappingFilterCheckWithFilter (0.00s)
=== RUN   TestListFormat
--- PASS: TestListFormat (0.00s)
=== RUN   TestDirMove
    run.go:180: Remote "oos:bucket rclone-test-hegagis7kado", Local "Local file system at /tmp/rclone1744522841", Modify Window "1ms"
2025/06/29 01:22:12 DEBUG : A1/one: trying to read metadata A1/one
2025/06/29 01:22:13 DEBUG : A1/two: trying to read metadata A1/two
2025/06/29 01:22:13 DEBUG : A1/B1/three: trying to read metadata A1/B1/three
2025/06/29 01:22:13 DEBUG : A1/B1/C1/four: trying to read metadata A1/B1/C1/four
2025/06/29 01:22:13 DEBUG : A1/B1/C2/five: trying to read metadata A1/B1/C2/five
2025/06/29 01:22:13 INFO  : A1/B2: Making directory
2025/06/29 01:22:13 INFO  : A1/B1/C3: Making directory
    fstest.go:247: Filtering empty directory "A1/B2"
    fstest.go:247: Filtering empty directory "A1/B1/C3"
2025/06/29 01:22:13 DEBUG : A1/B1/C1/four: trying to read metadata A1/B1/C1/four
2025/06/29 01:22:13 DEBUG : A1/B1/C1/four: trying to read metadata A1/B1/C1/four
2025/06/29 01:22:13 DEBUG : A1/B1/C2/five: trying to read metadata A1/B1/C2/five
2025/06/29 01:22:13 DEBUG : A1/B1/C2/five: trying to read metadata A1/B1/C2/five
2025/06/29 01:22:13 DEBUG : A1/B1/three: trying to read metadata A1/B1/three
2025/06/29 01:22:13 DEBUG : A1/B1/three: trying to read metadata A1/B1/three
2025/06/29 01:22:13 DEBUG : A1/one: trying to read metadata A1/one
2025/06/29 01:22:13 DEBUG : A1/one: trying to read metadata A1/one
2025/06/29 01:22:13 DEBUG : A1/two: trying to read metadata A1/two
2025/06/29 01:22:13 DEBUG : A1/two: trying to read metadata A1/two
2025/06/29 01:22:13 DEBUG : A2/B1/three: trying to read metadata A2/B1/three
2025/06/29 01:22:13 DEBUG : A2/one: trying to read metadata A2/one
2025/06/29 01:22:13 DEBUG : A2/two: trying to read metadata A2/two
2025/06/29 01:22:13 DEBUG : A2/B1/C1/four: trying to read metadata A2/B1/C1/four
2025/06/29 01:22:13 DEBUG : A2/B1/C2/five: trying to read metadata A2/B1/C2/five
2025/06/29 01:22:14 DEBUG : A2/B1/three: trying to read metadata A2/B1/three
2025/06/29 01:22:14 DEBUG : A1/B1/three: trying to read metadata A1/B1/three
2025/06/29 01:22:14 DEBUG : A1/B1/three: md5 = 35d6d33467aae9a2e3dccb4b6b027878 OK
2025/06/29 01:22:14 INFO  : A1/B1/three: Copied (server-side copy) to: A2/B1/three
2025/06/29 01:22:14 INFO  : A1/B1/three: Deleted
2025/06/29 01:22:14 DEBUG : A2/two: trying to read metadata A2/two
2025/06/29 01:22:14 DEBUG : A2/B1/C1/four: trying to read metadata A2/B1/C1/four
2025/06/29 01:22:14 DEBUG : A2/one: trying to read metadata A2/one
2025/06/29 01:22:14 DEBUG : A1/two: trying to read metadata A1/two
2025/06/29 01:22:14 DEBUG : A1/B1/C1/four: trying to read metadata A1/B1/C1/four
2025/06/29 01:22:14 DEBUG : A1/one: trying to read metadata A1/one
2025/06/29 01:22:14 DEBUG : A1/two: md5 = b8a9f715dbb64fd5c56e7783c6820a61 OK
2025/06/29 01:22:14 INFO  : A1/two: Copied (server-side copy) to: A2/two
2025/06/29 01:22:14 DEBUG : A1/B1/C1/four: md5 = 8cbad96aced40b3838dd9f07f6ef5772 OK
2025/06/29 01:22:14 INFO  : A1/B1/C1/four: Copied (server-side copy) to: A2/B1/C1/four
2025/06/29 01:22:14 DEBUG : A1/one: md5 = f97c5d29941bfb1b2fdab0874906ab82 OK
2025/06/29 01:22:14 INFO  : A1/one: Copied (server-side copy) to: A2/one
2025/06/29 01:22:14 INFO  : A1/two: Deleted
2025/06/29 01:22:14 INFO  : A1/B1/C1/four: Deleted
2025/06/29 01:22:14 INFO  : A1/one: Deleted
2025/06/29 01:22:15 DEBUG : A2/B1/C2/five: trying to read metadata A2/B1/C2/five
2025/06/29 01:22:15 DEBUG : A1/B1/C2/five: trying to read metadata A1/B1/C2/five
2025/06/29 01:22:15 DEBUG : A1/B1/C2/five: md5 = 30056e1cab7a61d256fc8edd970d14f5 OK
2025/06/29 01:22:15 INFO  : A1/B1/C2/five: Copied (server-side copy) to: A2/B1/C2/five
2025/06/29 01:22:15 INFO  : A1/B1/C2/five: Deleted
    fstest.go:247: Filtering empty directory "A2/B2"
    fstest.go:247: Filtering empty directory "A2/B1/C3"
2025/06/29 01:22:15 DEBUG : A2/B1/C1/four: trying to read metadata A2/B1/C1/four
2025/06/29 01:22:16 DEBUG : A2/B1/C1/four: trying to read metadata A2/B1/C1/four
2025/06/29 01:22:16 DEBUG : A2/B1/C2/five: trying to read metadata A2/B1/C2/five
2025/06/29 01:22:16 DEBUG : A2/B1/C2/five: trying to read metadata A2/B1/C2/five
2025/06/29 01:22:16 DEBUG : A2/B1/three: trying to read metadata A2/B1/three
2025/06/29 01:22:16 DEBUG : A2/B1/three: trying to read metadata A2/B1/three
2025/06/29 01:22:16 DEBUG : A2/one: trying to read metadata A2/one
2025/06/29 01:22:16 DEBUG : A2/one: trying to read metadata A2/one
2025/06/29 01:22:16 DEBUG : A2/two: trying to read metadata A2/two
2025/06/29 01:22:16 DEBUG : A2/two: trying to read metadata A2/two
2025/06/29 01:22:16 DEBUG : A3/B1/C1/four: trying to read metadata A3/B1/C1/four
2025/06/29 01:22:16 DEBUG : A3/B1/C2/five: trying to read metadata A3/B1/C2/five
2025/06/29 01:22:16 DEBUG : A3/B1/three: trying to read metadata A3/B1/three
2025/06/29 01:22:16 DEBUG : A3/two: trying to read metadata A3/two
2025/06/29 01:22:16 DEBUG : A3/one: trying to read metadata A3/one
2025/06/29 01:22:17 DEBUG : A3/B1/C2/five: trying to read metadata A3/B1/C2/five
2025/06/29 01:22:17 DEBUG : A3/two: trying to read metadata A3/two
2025/06/29 01:22:17 DEBUG : A3/B1/three: trying to read metadata A3/B1/three
2025/06/29 01:22:17 DEBUG : A3/one: trying to read metadata A3/one
2025/06/29 01:22:17 DEBUG : A3/B1/C1/four: trying to read metadata A3/B1/C1/four
2025/06/29 01:22:17 DEBUG : A2/B1/C2/five: trying to read metadata A2/B1/C2/five
2025/06/29 01:22:17 DEBUG : A2/two: trying to read metadata A2/two
2025/06/29 01:22:17 DEBUG : A2/B1/three: trying to read metadata A2/B1/three
2025/06/29 01:22:17 DEBUG : A2/one: trying to read metadata A2/one
2025/06/29 01:22:17 DEBUG : A2/B1/C1/four: trying to read metadata A2/B1/C1/four
2025/06/29 01:22:17 DEBUG : A2/B1/C2/five: md5 = 30056e1cab7a61d256fc8edd970d14f5 OK
2025/06/29 01:22:17 INFO  : A2/B1/C2/five: Copied (server-side copy) to: A3/B1/C2/five
2025/06/29 01:22:17 DEBUG : A2/two: md5 = b8a9f715dbb64fd5c56e7783c6820a61 OK
2025/06/29 01:22:17 INFO  : A2/two: Copied (server-side copy) to: A3/two
2025/06/29 01:22:17 DEBUG : A2/B1/C1/four: md5 = 8cbad96aced40b3838dd9f07f6ef5772 OK
2025/06/29 01:22:17 INFO  : A2/B1/C1/four: Copied (server-side copy) to: A3/B1/C1/four
2025/06/29 01:22:17 DEBUG : A2/one: md5 = f97c5d29941bfb1b2fdab0874906ab82 OK
2025/06/29 01:22:17 INFO  : A2/one: Copied (server-side copy) to: A3/one
2025/06/29 01:22:17 DEBUG : A2/B1/three: md5 = 35d6d33467aae9a2e3dccb4b6b027878 OK
2025/06/29 01:22:17 INFO  : A2/B1/three: Copied (server-side copy) to: A3/B1/three
2025/06/29 01:22:17 INFO  : A2/B1/C2/five: Deleted
2025/06/29 01:22:17 INFO  : A2/two: Deleted
2025/06/29 01:22:17 INFO  : A2/one: Deleted
2025/06/29 01:22:17 INFO  : A2/B1/C1/four: Deleted
2025/06/29 01:22:17 INFO  : A2/B1/three: Deleted
    fstest.go:247: Filtering empty directory "A3/B2"
    fstest.go:247: Filtering empty directory "A3/B1/C3"
2025/06/29 01:22:17 DEBUG : A3/B1/C1/four: trying to read metadata A3/B1/C1/four
2025/06/29 01:22:17 DEBUG : A3/B1/C1/four: trying to read metadata A3/B1/C1/four
2025/06/29 01:22:17 DEBUG : A3/B1/C2/five: trying to read metadata A3/B1/C2/five
2025/06/29 01:22:17 DEBUG : A3/B1/C2/five: trying to read metadata A3/B1/C2/five
2025/06/29 01:22:17 DEBUG : A3/B1/three: trying to read metadata A3/B1/three
2025/06/29 01:22:17 DEBUG : A3/B1/three: trying to read metadata A3/B1/three
2025/06/29 01:22:17 DEBUG : A3/one: trying to read metadata A3/one
2025/06/29 01:22:17 DEBUG : A3/one: trying to read metadata A3/one
2025/06/29 01:22:17 DEBUG : A3/two: trying to read metadata A3/two
2025/06/29 01:22:17 DEBUG : A3/two: trying to read metadata A3/two
2025/06/29 01:22:17 INFO  : oos:bucket rclone-test-hegagis7kado: Can't DirMove - falling back to file moves: can't move directory - incompatible remotes
2025/06/29 01:22:17 DEBUG : A4/B1/C1/four: trying to read metadata A4/B1/C1/four
2025/06/29 01:22:17 DEBUG : A4/B1/C2/five: trying to read metadata A4/B1/C2/five
2025/06/29 01:22:17 DEBUG : A4/B1/three: trying to read metadata A4/B1/three
2025/06/29 01:22:17 DEBUG : A4/one: trying to read metadata A4/one
2025/06/29 01:22:17 DEBUG : A4/two: trying to read metadata A4/two
2025/06/29 01:22:17 DEBUG : A4/B1/C1/four: trying to read metadata A4/B1/C1/four
2025/06/29 01:22:17 DEBUG : A4/one: trying to read metadata A4/one
2025/06/29 01:22:18 DEBUG : A3/B1/C1/four: trying to read metadata A3/B1/C1/four
2025/06/29 01:22:18 DEBUG : A3/one: trying to read metadata A3/one
2025/06/29 01:22:18 DEBUG : A3/B1/C1/four: md5 = 8cbad96aced40b3838dd9f07f6ef5772 OK
2025/06/29 01:22:18 INFO  : A3/B1/C1/four: Copied (server-side copy) to: A4/B1/C1/four
2025/06/29 01:22:18 DEBUG : A3/one: md5 = f97c5d29941bfb1b2fdab0874906ab82 OK
2025/06/29 01:22:18 INFO  : A3/one: Copied (server-side copy) to: A4/one
2025/06/29 01:22:18 INFO  : A3/B1/C1/four: Deleted
2025/06/29 01:22:18 INFO  : A3/one: Deleted
2025/06/29 01:22:18 DEBUG : A4/two: trying to read metadata A4/two
2025/06/29 01:22:18 DEBUG : A4/B1/C2/five: trying to read metadata A4/B1/C2/five
2025/06/29 01:22:18 DEBUG : A3/two: trying to read metadata A3/two
2025/06/29 01:22:18 DEBUG : A3/B1/C2/five: trying to read metadata A3/B1/C2/five
2025/06/29 01:22:18 DEBUG : A4/B1/three: trying to read metadata A4/B1/three
2025/06/29 01:22:18 DEBUG : A3/two: md5 = b8a9f715dbb64fd5c56e7783c6820a61 OK
2025/06/29 01:22:18 INFO  : A3/two: Copied (server-side copy) to: A4/two
2025/06/29 01:22:18 DEBUG : A3/B1/three: trying to read metadata A3/B1/three
2025/06/29 01:22:18 DEBUG : A3/B1/C2/five: md5 = 30056e1cab7a61d256fc8edd970d14f5 OK
2025/06/29 01:22:18 INFO  : A3/B1/C2/five: Copied (server-side copy) to: A4/B1/C2/five
2025/06/29 01:22:18 INFO  : A3/two: Deleted
2025/06/29 01:22:18 DEBUG : A3/B1/three: md5 = 35d6d33467aae9a2e3dccb4b6b027878 OK
2025/06/29 01:22:18 INFO  : A3/B1/three: Copied (server-side copy) to: A4/B1/three
2025/06/29 01:22:18 INFO  : A3/B1/C2/five: Deleted
2025/06/29 01:22:18 INFO  : A3/B1/three: Deleted
    fstest.go:247: Filtering empty directory "A4/B2"
    fstest.go:247: Filtering empty directory "A4/B1/C3"
2025/06/29 01:22:18 DEBUG : A4/B1/C1/four: trying to read metadata A4/B1/C1/four
2025/06/29 01:22:18 DEBUG : A4/B1/C1/four: trying to read metadata A4/B1/C1/four
2025/06/29 01:22:18 DEBUG : A4/B1/C2/five: trying to read metadata A4/B1/C2/five
2025/06/29 01:22:18 DEBUG : A4/B1/C2/five: trying to read metadata A4/B1/C2/five
2025/06/29 01:22:18 DEBUG : A4/B1/three: trying to read metadata A4/B1/three
2025/06/29 01:22:18 DEBUG : A4/B1/three: trying to read metadata A4/B1/three
2025/06/29 01:22:18 DEBUG : A4/one: trying to read metadata A4/one
2025/06/29 01:22:18 DEBUG : A4/one: trying to read metadata A4/one
2025/06/29 01:22:18 DEBUG : A4/two: trying to read metadata A4/two
2025/06/29 01:22:18 DEBUG : A4/two: trying to read metadata A4/two
--- PASS: TestDirMove (6.43s)
=== RUN   TestGetFsInfo
    run.go:180: Remote "oos:bucket rclone-test-hegagis7kado", Local "Local file system at /tmp/rclone1744522841", Modify Window "1ms"
--- PASS: TestGetFsInfo (0.09s)
=== RUN   TestRcat
=== RUN   TestRcat/withChecksum=false,ignoreChecksum=false
    run.go:180: Remote "oos:bucket rclone-test-hegagis7kado", Local "Local file system at /tmp/rclone1744522841", Modify Window "1ms"
2025/06/29 01:22:19 DEBUG : oos:bucket rclone-test-hegagis7kado: File to upload is small (34 bytes), uploading instead of streaming
2025/06/29 01:22:19 DEBUG : no_checksum_small_file_from_pipe: trying to read metadata no_checksum_small_file_from_pipe
2025/06/29 01:22:19 DEBUG : no_checksum_small_file_from_pipe: md5 = 4c762bc6ec18f21b23fcae426c7863b5 OK
2025/06/29 01:22:19 DEBUG : no_checksum_small_file_from_pipe: Size and md5 of src and dst objects identical
2025/06/29 01:22:19 NOTICE: oos:bucket rclone-test-hegagis7kado: Streaming uploads using chunk size 5Mi will have maximum file size of 48.828Gi
2025/06/29 01:22:19 DEBUG : no_checksum_big_file_from_pipe: created new upload id: 77b270dd-020c-43d7-ed7c-7c8e4bc76cb2
2025/06/29 01:22:19 DEBUG : no_checksum_big_file_from_pipe: open chunk writer: started multipart upload: 77b270dd-020c-43d7-ed7c-7c8e4bc76cb2
2025/06/29 01:22:19 DEBUG : no_checksum_big_file_from_pipe: multipart upload: starting chunk 0 size 100.001Ki offset 0/off
2025/06/29 01:22:19 DEBUG : no_checksum_big_file_from_pipe: multipart upload 77b270dd-020c-43d7-ed7c-7c8e4bc76cb2 md5 matched: expecting u+7gLGCMboVzazXlNvunGQ==-1 and got u+7gLGCMboVzazXlNvunGQ==-1
2025/06/29 01:22:19 DEBUG : no_checksum_big_file_from_pipe: trying to read metadata no_checksum_big_file_from_pipe
2025/06/29 01:22:19 DEBUG : no_checksum_big_file_from_pipe: trying to read metadata no_checksum_big_file_from_pipe
2025/06/29 01:22:19 DEBUG : no_checksum_big_file_from_pipe: Dst hash empty - aborting Src hash check
2025/06/29 01:22:19 DEBUG : no_checksum_big_file_from_pipe: Size of src and dst objects identical
2025/06/29 01:22:19 DEBUG : no_checksum_big_file_from_pipe: Failed to read md5sum from metadata "u+7gLGCMboVzazXlNvunGQ==-1": illegal base64 data at input byte 24
2025/06/29 01:22:19 DEBUG : no_checksum_big_file_from_pipe: trying to read metadata no_checksum_big_file_from_pipe
2025/06/29 01:22:19 DEBUG : no_checksum_big_file_from_pipe: trying to read metadata no_checksum_big_file_from_pipe
2025/06/29 01:22:19 DEBUG : no_checksum_small_file_from_pipe: trying to read metadata no_checksum_small_file_from_pipe
2025/06/29 01:22:19 DEBUG : no_checksum_small_file_from_pipe: trying to read metadata no_checksum_small_file_from_pipe
2025/06/29 01:22:19 DEBUG : no_checksum_big_file_from_pipe: Failed to read md5sum from metadata "u+7gLGCMboVzazXlNvunGQ==-1": illegal base64 data at input byte 24
=== RUN   TestRcat/withChecksum=true,ignoreChecksum=false
    run.go:180: Remote "oos:bucket rclone-test-hegagis7kado", Local "Local file system at /tmp/rclone1744522841", Modify Window "1ms"
2025/06/29 01:22:20 DEBUG : oos:bucket rclone-test-hegagis7kado: File to upload is small (34 bytes), uploading instead of streaming
2025/06/29 01:22:20 DEBUG : with_checksum_small_file_from_pipe: trying to read metadata with_checksum_small_file_from_pipe
2025/06/29 01:22:20 DEBUG : with_checksum_small_file_from_pipe: md5 = 4c762bc6ec18f21b23fcae426c7863b5 OK
2025/06/29 01:22:20 DEBUG : with_checksum_small_file_from_pipe: Size and md5 of src and dst objects identical
2025/06/29 01:22:20 DEBUG : with_checksum_big_file_from_pipe: created new upload id: f6c9bed1-8d6f-ceab-df61-3709f3b4e002
2025/06/29 01:22:20 DEBUG : with_checksum_big_file_from_pipe: open chunk writer: started multipart upload: f6c9bed1-8d6f-ceab-df61-3709f3b4e002
2025/06/29 01:22:20 DEBUG : with_checksum_big_file_from_pipe: multipart upload: starting chunk 0 size 100.001Ki offset 0/off
2025/06/29 01:22:20 DEBUG : with_checksum_big_file_from_pipe: multipart upload f6c9bed1-8d6f-ceab-df61-3709f3b4e002 md5 matched: expecting u+7gLGCMboVzazXlNvunGQ==-1 and got u+7gLGCMboVzazXlNvunGQ==-1
2025/06/29 01:22:20 DEBUG : with_checksum_big_file_from_pipe: trying to read metadata with_checksum_big_file_from_pipe
2025/06/29 01:22:20 DEBUG : with_checksum_big_file_from_pipe: trying to read metadata with_checksum_big_file_from_pipe
2025/06/29 01:22:20 DEBUG : with_checksum_big_file_from_pipe: Dst hash empty - aborting Src hash check
2025/06/29 01:22:20 DEBUG : with_checksum_big_file_from_pipe: Size of src and dst objects identical
2025/06/29 01:22:20 DEBUG : with_checksum_big_file_from_pipe: Failed to read md5sum from metadata "u+7gLGCMboVzazXlNvunGQ==-1": illegal base64 data at input byte 24
2025/06/29 01:22:20 DEBUG : with_checksum_big_file_from_pipe: trying to read metadata with_checksum_big_file_from_pipe
2025/06/29 01:22:20 DEBUG : with_checksum_big_file_from_pipe: trying to read metadata with_checksum_big_file_from_pipe
2025/06/29 01:22:20 DEBUG : with_checksum_small_file_from_pipe: trying to read metadata with_checksum_small_file_from_pipe
2025/06/29 01:22:20 DEBUG : with_checksum_small_file_from_pipe: trying to read metadata with_checksum_small_file_from_pipe
2025/06/29 01:22:20 DEBUG : with_checksum_big_file_from_pipe: Failed to read md5sum from metadata "u+7gLGCMboVzazXlNvunGQ==-1": illegal base64 data at input byte 24
=== RUN   TestRcat/withChecksum=false,ignoreChecksum=true
    run.go:180: Remote "oos:bucket rclone-test-hegagis7kado", Local "Local file system at /tmp/rclone1744522841", Modify Window "1ms"
2025/06/29 01:22:20 DEBUG : oos:bucket rclone-test-hegagis7kado: File to upload is small (34 bytes), uploading instead of streaming
2025/06/29 01:22:21 DEBUG : ignore_checksum_small_file_from_pipe: trying to read metadata ignore_checksum_small_file_from_pipe
2025/06/29 01:22:21 DEBUG : ignore_checksum_small_file_from_pipe: trying to read metadata ignore_checksum_small_file_from_pipe
2025/06/29 01:22:21 DEBUG : ignore_checksum_small_file_from_pipe: Size and modification time the same (differ by 0s, within tolerance 1ms)
2025/06/29 01:22:21 DEBUG : ignore_checksum_big_file_from_pipe: created new upload id: 9e4e217d-e4a1-cda1-b443-31f93658935e
2025/06/29 01:22:21 DEBUG : ignore_checksum_big_file_from_pipe: open chunk writer: started multipart upload: 9e4e217d-e4a1-cda1-b443-31f93658935e
2025/06/29 01:22:21 DEBUG : ignore_checksum_big_file_from_pipe: multipart upload: starting chunk 0 size 100.001Ki offset 0/off
2025/06/29 01:22:21 DEBUG : ignore_checksum_big_file_from_pipe: multipart upload 9e4e217d-e4a1-cda1-b443-31f93658935e md5 matched: expecting u+7gLGCMboVzazXlNvunGQ==-1 and got u+7gLGCMboVzazXlNvunGQ==-1
2025/06/29 01:22:21 DEBUG : ignore_checksum_big_file_from_pipe: trying to read metadata ignore_checksum_big_file_from_pipe
2025/06/29 01:22:21 DEBUG : ignore_checksum_big_file_from_pipe: trying to read metadata ignore_checksum_big_file_from_pipe
2025/06/29 01:22:21 DEBUG : ignore_checksum_big_file_from_pipe: Size and modification time the same (differ by 0s, within tolerance 1ms)
2025/06/29 01:22:21 DEBUG : ignore_checksum_big_file_from_pipe: Failed to read md5sum from metadata "u+7gLGCMboVzazXlNvunGQ==-1": illegal base64 data at input byte 24
2025/06/29 01:22:21 DEBUG : ignore_checksum_big_file_from_pipe: trying to read metadata ignore_checksum_big_file_from_pipe
2025/06/29 01:22:21 DEBUG : ignore_checksum_big_file_from_pipe: trying to read metadata ignore_checksum_big_file_from_pipe
2025/06/29 01:22:21 DEBUG : ignore_checksum_small_file_from_pipe: trying to read metadata ignore_checksum_small_file_from_pipe
2025/06/29 01:22:21 DEBUG : ignore_checksum_small_file_from_pipe: trying to read metadata ignore_checksum_small_file_from_pipe
2025/06/29 01:22:21 DEBUG : ignore_checksum_big_file_from_pipe: Failed to read md5sum from metadata "u+7gLGCMboVzazXlNvunGQ==-1": illegal base64 data at input byte 24
=== RUN   TestRcat/withChecksum=true,ignoreChecksum=true
    run.go:180: Remote "oos:bucket rclone-test-hegagis7kado", Local "Local file system at /tmp/rclone1744522841", Modify Window "1ms"
2025/06/29 01:22:21 DEBUG : oos:bucket rclone-test-hegagis7kado: File to upload is small (34 bytes), uploading instead of streaming
2025/06/29 01:22:21 DEBUG : ignore_checksum_small_file_from_pipe: trying to read metadata ignore_checksum_small_file_from_pipe
2025/06/29 01:22:21 DEBUG : ignore_checksum_small_file_from_pipe: Src hash empty - aborting Dst hash check
2025/06/29 01:22:21 DEBUG : ignore_checksum_small_file_from_pipe: Size of src and dst objects identical
2025/06/29 01:22:21 DEBUG : ignore_checksum_big_file_from_pipe: created new upload id: c1ba267f-6f8f-778a-b808-12f7c49fd15a
2025/06/29 01:22:21 DEBUG : ignore_checksum_big_file_from_pipe: open chunk writer: started multipart upload: c1ba267f-6f8f-778a-b808-12f7c49fd15a
2025/06/29 01:22:21 DEBUG : ignore_checksum_big_file_from_pipe: multipart upload: starting chunk 0 size 100.001Ki offset 0/off
2025/06/29 01:22:21 DEBUG : ignore_checksum_big_file_from_pipe: multipart upload c1ba267f-6f8f-778a-b808-12f7c49fd15a md5 matched: expecting u+7gLGCMboVzazXlNvunGQ==-1 and got u+7gLGCMboVzazXlNvunGQ==-1
2025/06/29 01:22:21 DEBUG : ignore_checksum_big_file_from_pipe: trying to read metadata ignore_checksum_big_file_from_pipe
2025/06/29 01:22:22 DEBUG : ignore_checksum_big_file_from_pipe: trying to read metadata ignore_checksum_big_file_from_pipe
2025/06/29 01:22:22 DEBUG : ignore_checksum_big_file_from_pipe: Dst hash empty - aborting Src hash check
2025/06/29 01:22:22 DEBUG : ignore_checksum_big_file_from_pipe: Src hash empty - aborting Dst hash check
2025/06/29 01:22:22 DEBUG : ignore_checksum_big_file_from_pipe: Size of src and dst objects identical
2025/06/29 01:22:22 DEBUG : ignore_checksum_big_file_from_pipe: Failed to read md5sum from metadata "u+7gLGCMboVzazXlNvunGQ==-1": illegal base64 data at input byte 24
2025/06/29 01:22:22 DEBUG : ignore_checksum_big_file_from_pipe: trying to read metadata ignore_checksum_big_file_from_pipe
2025/06/29 01:22:22 DEBUG : ignore_checksum_big_file_from_pipe: trying to read metadata ignore_checksum_big_file_from_pipe
2025/06/29 01:22:22 DEBUG : ignore_checksum_small_file_from_pipe: trying to read metadata ignore_checksum_small_file_from_pipe
2025/06/29 01:22:22 DEBUG : ignore_checksum_small_file_from_pipe: trying to read metadata ignore_checksum_small_file_from_pipe
2025/06/29 01:22:22 DEBUG : ignore_checksum_big_file_from_pipe: Failed to read md5sum from metadata "u+7gLGCMboVzazXlNvunGQ==-1": illegal base64 data at input byte 24
--- PASS: TestRcat (3.02s)
    --- PASS: TestRcat/withChecksum=false,ignoreChecksum=false (0.83s)
    --- PASS: TestRcat/withChecksum=true,ignoreChecksum=false (0.76s)
    --- PASS: TestRcat/withChecksum=false,ignoreChecksum=true (0.72s)
    --- PASS: TestRcat/withChecksum=true,ignoreChecksum=true (0.71s)
=== RUN   TestRcatMetadata
    run.go:180: Remote "oos:bucket rclone-test-hegagis7kado", Local "Local file system at /tmp/rclone1744522841", Modify Window "1ms"
    operations_test.go:1532: Skipping as destination doesn't support user metadata
--- SKIP: TestRcatMetadata (0.08s)
=== RUN   TestRcatSize
    run.go:180: Remote "oos:bucket rclone-test-hegagis7kado", Local "Local file system at /tmp/rclone1744522841", Modify Window "1ms"
2025/06/29 01:22:22 DEBUG : potato1: trying to read metadata potato1
2025/06/29 01:22:22 DEBUG : oos:bucket rclone-test-hegagis7kado: File to upload is small (60 bytes), uploading instead of streaming
2025/06/29 01:22:22 DEBUG : potato2: trying to read metadata potato2
2025/06/29 01:22:22 DEBUG : potato2: md5 = d6548b156ea68a4e003e786df99eee76 OK
2025/06/29 01:22:22 DEBUG : potato2: Size and md5 of src and dst objects identical
2025/06/29 01:22:22 DEBUG : potato1: trying to read metadata potato1
2025/06/29 01:22:22 DEBUG : potato1: trying to read metadata potato1
2025/06/29 01:22:22 DEBUG : potato2: trying to read metadata potato2
2025/06/29 01:22:22 DEBUG : potato2: trying to read metadata potato2
--- PASS: TestRcatSize (0.56s)
=== RUN   TestRcatSizeMetadata
    run.go:180: Remote "oos:bucket rclone-test-hegagis7kado", Local "Local file system at /tmp/rclone1744522841", Modify Window "1ms"
    operations_test.go:1613: Skipping as destination doesn't support user metadata
--- SKIP: TestRcatSizeMetadata (0.14s)
=== RUN   TestTouchDir
    run.go:180: Remote "oos:bucket rclone-test-hegagis7kado", Local "Local file system at /tmp/rclone1744522841", Modify Window "1ms"
2025/06/29 01:22:23 DEBUG : potato2: trying to read metadata potato2
2025/06/29 01:22:23 DEBUG : empty space: trying to read metadata empty space
2025/06/29 01:22:23 DEBUG : sub dir/potato3: trying to read metadata sub dir/potato3
2025/06/29 01:22:23 DEBUG : empty space: trying to read metadata empty space
2025/06/29 01:22:23 DEBUG : empty space: trying to read metadata empty space
2025/06/29 01:22:23 DEBUG : potato2: trying to read metadata potato2
2025/06/29 01:22:23 DEBUG : potato2: trying to read metadata potato2
2025/06/29 01:22:23 DEBUG : sub dir/potato3: trying to read metadata sub dir/potato3
2025/06/29 01:22:23 DEBUG : sub dir/potato3: trying to read metadata sub dir/potato3
2025/06/29 01:22:23 DEBUG : oos:bucket rclone-test-hegagis7kado: Touching "sub dir/potato3"
2025/06/29 01:22:23 DEBUG : sub dir/potato3: trying to read metadata sub dir/potato3
2025/06/29 01:22:23 DEBUG : oos:bucket rclone-test-hegagis7kado: Touching "empty space"
2025/06/29 01:22:23 DEBUG : empty space: trying to read metadata empty space
2025/06/29 01:22:23 DEBUG : oos:bucket rclone-test-hegagis7kado: Touching "potato2"
2025/06/29 01:22:23 DEBUG : potato2: trying to read metadata potato2
2025/06/29 01:22:24 DEBUG : empty space: trying to read metadata empty space
2025/06/29 01:22:24 DEBUG : sub dir/potato3: trying to read metadata sub dir/potato3
2025/06/29 01:22:24 DEBUG : potato2: trying to read metadata potato2
2025/06/29 01:22:24 DEBUG : empty space: trying to read metadata empty space
2025/06/29 01:22:24 DEBUG : empty space: trying to read metadata empty space
2025/06/29 01:22:24 DEBUG : potato2: trying to read metadata potato2
2025/06/29 01:22:24 DEBUG : potato2: trying to read metadata potato2
2025/06/29 01:22:24 DEBUG : sub dir/potato3: trying to read metadata sub dir/potato3
2025/06/29 01:22:24 DEBUG : sub dir/potato3: trying to read metadata sub dir/potato3
--- PASS: TestTouchDir (2.06s)
=== RUN   TestMkdirMetadata
    run.go:180: Remote "oos:bucket rclone-test-hegagis7kado", Local "Local file system at /tmp/rclone1744522841", Modify Window "1ms"
    operations_test.go:1703: Skipping test as remote does not support MkdirMetadata
--- SKIP: TestMkdirMetadata (0.08s)
=== RUN   TestMkdirModTime
    run.go:180: Remote "oos:bucket rclone-test-hegagis7kado", Local "Local file system at /tmp/rclone1744522841", Modify Window "1ms"
    operations_test.go:1722: Skipping test as remote does not support DirSetModTime or MkdirMetadata
--- SKIP: TestMkdirModTime (0.08s)
=== RUN   TestCopyDirMetadata
    run.go:180: Remote "oos:bucket rclone-test-hegagis7kado", Local "Local file system at /tmp/rclone1744522841", Modify Window "1ms"
    operations_test.go:1743: Skipping test as remote does not support WriteDirMetadata or MkdirMetadata
--- SKIP: TestCopyDirMetadata (0.09s)
=== RUN   TestSetDirModTime
    run.go:180: Remote "oos:bucket rclone-test-hegagis7kado", Local "Local file system at /tmp/rclone1744522841", Modify Window "1ms"
    operations_test.go:1779: Skipping test as remote does not support DirSetModTime or WriteDirSetModTime
--- SKIP: TestSetDirModTime (0.08s)
=== RUN   TestDirsEqual
    run.go:180: Remote "oos:bucket rclone-test-hegagis7kado", Local "Local file system at /tmp/rclone1744522841", Modify Window "1ms"
    operations_test.go:1823: Skipping test as remote does not support WriteDirMetadata or MkdirMetadata
--- SKIP: TestDirsEqual (0.08s)
=== RUN   TestRemoveExisting
    run.go:180: Remote "oos:bucket rclone-test-hegagis7kado", Local "Local file system at /tmp/rclone1744522841", Modify Window "1ms"
    operations_test.go:1892: Skipping as remote can't Move
--- SKIP: TestRemoveExisting (0.09s)
=== RUN   TestRcAbout
    rc_test.go:30: Skipping test on non local remote
--- SKIP: TestRcAbout (0.00s)
=== RUN   TestRcCleanup
    rc_test.go:30: Skipping test on non local remote
--- SKIP: TestRcCleanup (0.00s)
=== RUN   TestRcCopyfile
    rc_test.go:30: Skipping test on non local remote
--- SKIP: TestRcCopyfile (0.00s)
=== RUN   TestRcCopyurl
    rc_test.go:30: Skipping test on non local remote
--- SKIP: TestRcCopyurl (0.00s)
=== RUN   TestRcDelete
    rc_test.go:30: Skipping test on non local remote
--- SKIP: TestRcDelete (0.00s)
=== RUN   TestRcDeletefile
    rc_test.go:30: Skipping test on non local remote
--- SKIP: TestRcDeletefile (0.00s)
=== RUN   TestRcList
    rc_test.go:30: Skipping test on non local remote
--- SKIP: TestRcList (0.00s)
=== RUN   TestRcStat
    rc_test.go:30: Skipping test on non local remote
--- SKIP: TestRcStat (0.00s)
=== RUN   TestRcSetTier
    rc_test.go:30: Skipping test on non local remote
--- SKIP: TestRcSetTier (0.00s)
=== RUN   TestRcSetTierFile
    rc_test.go:30: Skipping test on non local remote
--- SKIP: TestRcSetTierFile (0.00s)
=== RUN   TestRcMkdir
    rc_test.go:30: Skipping test on non local remote
--- SKIP: TestRcMkdir (0.00s)
=== RUN   TestRcMovefile
    rc_test.go:30: Skipping test on non local remote
--- SKIP: TestRcMovefile (0.00s)
=== RUN   TestRcPurge
    rc_test.go:30: Skipping test on non local remote
--- SKIP: TestRcPurge (0.00s)
=== RUN   TestRcRmdir
    rc_test.go:30: Skipping test on non local remote
--- SKIP: TestRcRmdir (0.00s)
=== RUN   TestRcRmdirs
    rc_test.go:30: Skipping test on non local remote
--- SKIP: TestRcRmdirs (0.00s)
=== RUN   TestRcSize
    rc_test.go:30: Skipping test on non local remote
--- SKIP: TestRcSize (0.00s)
=== RUN   TestRcPublicLink
    rc_test.go:30: Skipping test on non local remote
--- SKIP: TestRcPublicLink (0.00s)
=== RUN   TestRcFsInfo
    rc_test.go:30: Skipping test on non local remote
--- SKIP: TestRcFsInfo (0.00s)
=== RUN   TestUploadFile
    rc_test.go:30: Skipping test on non local remote
--- SKIP: TestUploadFile (0.00s)
=== RUN   TestRcCommand
    rc_test.go:30: Skipping test on non local remote
--- SKIP: TestRcCommand (0.00s)
=== RUN   TestRcDu
    rc_test.go:30: Skipping test on non local remote
--- SKIP: TestRcDu (0.00s)
=== RUN   TestRcCheck
    rc_test.go:30: Skipping test on non local remote
--- SKIP: TestRcCheck (0.00s)
=== RUN   TestRcHashsum
    rc_test.go:30: Skipping test on non local remote
--- SKIP: TestRcHashsum (0.00s)
=== RUN   TestRcHashsumFile
    rc_test.go:30: Skipping test on non local remote
--- SKIP: TestRcHashsumFile (0.00s)
PASS
2025/06/29 01:22:25 DEBUG : oos:bucket rclone-test-hegagis7kado: Purge dir ""
2025/06/29 01:22:27 INFO  : oos:bucket rclone-test-hegagis7kado: Bucket "rclone-test-hegagis7kado" deleted
"./operations.test -test.v -test.timeout 1h0m0s -remote TestOracleObjectStorage: -verbose" - Finished OK in 2m18.644806499s (try 1/5)