"./bisync.test -test.v -test.timeout 1h0m0s -remote TestOneDriveBusiness: -verbose" - Starting (try 1/5) 2026/04/02 01:01:16 DEBUG : Creating backend with remote "TestOneDriveBusiness:rclone-test-qidofiw2huve" 2026/04/02 01:01:16 DEBUG : Using config file from "/home/rclone/.rclone.conf" 2026/04/02 01:01:17 DEBUG : Creating backend with remote "/tmp/rclone3477012624" === RUN TestLockfileIsExpired_UnreadableWithMaxLock 2026/04/02 01:01:17 INFO : /tmp/TestLockfileIsExpired_UnreadableWithMaxLock2985528340/001/test.lck: Lock file is unreadable (decode error: invalid character 'o' in literal null (expecting 'u')) and --max-lock is set. Treating as expired. --- PASS: TestLockfileIsExpired_UnreadableWithMaxLock (0.00s) === RUN TestLockfileIsExpired_UnreadableWithoutMaxLock 2026/04/02 01:01:17 ERROR : /tmp/TestLockfileIsExpired_UnreadableWithoutMaxLock780615677/001/test.lck: Lock file exists, but contents are unreadable. (decode error: invalid character 'o' in literal null (expecting 'u')) --- PASS: TestLockfileIsExpired_UnreadableWithoutMaxLock (0.00s) === RUN TestLockfileIsExpired_ValidExpired 2026/04/02 01:01:17 INFO : /tmp/TestLockfileIsExpired_ValidExpired2094695747/001/test.lck: Lock file found, but it expired at 2026-04-02 00:56:17.928366266 +0000 UTC. Will delete it and proceed. --- PASS: TestLockfileIsExpired_ValidExpired (0.00s) === RUN TestLockfileIsExpired_ValidNotExpired 2026/04/02 01:01:17 INFO : /tmp/TestLockfileIsExpired_ValidNotExpired1894232159/001/test.lck: Valid lock file found. Expires at 2026-04-02 01:11:17.929073891 +0000 UTC. (10m0s from now) 2026/04/02 01:01:17 INFO : Lockfile info: { "Session": "test", "PID": "12345", "TimeRenewed": "2026-04-02T01:01:17.929073801Z", "TimeExpires": "2026-04-02T01:11:17.929073891Z" } --- PASS: TestLockfileIsExpired_ValidNotExpired (0.00s) === RUN TestBisyncRemoteLocal 2026/04/02 01:01:17 DEBUG : Creating backend with remote "TestOneDriveBusiness:rclone-test-zocuwub1xugo" 2026/04/02 01:01:19 NOTICE: remote: TestOneDriveBusiness:rclone-test-zocuwub1xugo === RUN TestBisyncRemoteLocal/all_changed 2026/04/02 01:01:19 DEBUG : Creating backend with remote "TestOneDriveBusiness:rclone-test-zocuwub1xugo/010119bi" 2026/04/02 01:01:20 INFO : path1: Making directory 2026/04/02 01:01:22 DEBUG : Creating backend with remote "TestOneDriveBusiness:rclone-test-zocuwub1xugo/010119bi/all_changed/path1" 2026/04/02 01:01:25 DEBUG : Creating backend with remote "/tmp/010119bi" 2026/04/02 01:01:25 DEBUG : Creating backend with remote "/tmp/010119bi/all_changed/path2" 2026/04/02 01:01:25 DEBUG : Creating backend with remote "/home/rclone/go/src/github.com/rclone/rclone/cmd/bisync/testdata/test_all_changed/initial" 2026/04/02 01:01:25 DEBUG : Creating backend with remote "/tmp/010119bi/initdir/test_all_changed-wikojoh0" 2026/04/02 01:01:25 DEBUG : RCLONE_TEST: Need to transfer - File not found at Destination 2026/04/02 01:01:25 DEBUG : file1.copy1.txt: Need to transfer - File not found at Destination 2026/04/02 01:01:25 DEBUG : file1.copy2.txt: Need to transfer - File not found at Destination 2026/04/02 01:01:25 DEBUG : file1.copy3.txt: Need to transfer - File not found at Destination 2026/04/02 01:01:25 DEBUG : file1.copy4.txt: Need to transfer - File not found at Destination 2026/04/02 01:01:25 DEBUG : file1.copy5.txt: Need to transfer - File not found at Destination 2026/04/02 01:01:25 DEBUG : file1.txt: Need to transfer - File not found at Destination 2026/04/02 01:01:25 DEBUG : subdir: Making directory with metadata 2026/04/02 01:01:25 INFO : subdir: Made directory with metadata (mtime=2021-11-02T05:00:07Z) 2026/04/02 01:01:25 DEBUG : Added delayed dir = "subdir", newDst=subdir 2026/04/02 01:01:25 DEBUG : subdir/file20.txt: Need to transfer - File not found at Destination 2026/04/02 01:01:25 DEBUG : Local file system at /tmp/010119bi/initdir/test_all_changed-wikojoh0: Waiting for checks to finish 2026/04/02 01:01:25 DEBUG : file1.copy1.txt.21b8fa2b.partial: size = 0 OK 2026/04/02 01:01:25 DEBUG : RCLONE_TEST.abb09051.partial: size = 109 OK 2026/04/02 01:01:25 DEBUG : Local file system at /tmp/010119bi/initdir/test_all_changed-wikojoh0: Waiting for transfers to finish 2026/04/02 01:01:25 DEBUG : file1.copy1.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2026/04/02 01:01:25 DEBUG : file1.copy1.txt.21b8fa2b.partial: renamed to: file1.copy1.txt 2026/04/02 01:01:25 DEBUG : file1.copy3.txt.d0285540.partial: size = 0 OK 2026/04/02 01:01:25 INFO : file1.copy1.txt: Copied (new) 2026/04/02 01:01:25 DEBUG : file1.copy2.txt.455881d5.partial: size = 0 OK 2026/04/02 01:01:25 DEBUG : file1.copy3.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2026/04/02 01:01:25 DEBUG : RCLONE_TEST: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK 2026/04/02 01:01:25 DEBUG : RCLONE_TEST.abb09051.partial: renamed to: RCLONE_TEST 2026/04/02 01:01:25 INFO : RCLONE_TEST: Copied (new) 2026/04/02 01:01:25 DEBUG : file1.copy3.txt.d0285540.partial: renamed to: file1.copy3.txt 2026/04/02 01:01:25 INFO : file1.copy3.txt: Copied (new) 2026/04/02 01:01:25 DEBUG : file1.copy4.txt.8c987629.partial: size = 0 OK 2026/04/02 01:01:25 DEBUG : file1.copy5.txt.19e8a2bc.partial: size = 0 OK 2026/04/02 01:01:25 DEBUG : file1.copy4.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2026/04/02 01:01:25 DEBUG : file1.copy2.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2026/04/02 01:01:25 DEBUG : file1.copy2.txt.455881d5.partial: renamed to: file1.copy2.txt 2026/04/02 01:01:25 DEBUG : file1.txt.56d0d699.partial: size = 0 OK 2026/04/02 01:01:25 DEBUG : file1.copy5.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2026/04/02 01:01:25 DEBUG : file1.copy4.txt.8c987629.partial: renamed to: file1.copy4.txt 2026/04/02 01:01:25 DEBUG : file1.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2026/04/02 01:01:25 INFO : file1.copy4.txt: Copied (new) 2026/04/02 01:01:25 DEBUG : file1.copy5.txt.19e8a2bc.partial: renamed to: file1.copy5.txt 2026/04/02 01:01:25 INFO : file1.copy5.txt: Copied (new) 2026/04/02 01:01:25 INFO : file1.copy2.txt: Copied (new) 2026/04/02 01:01:25 DEBUG : file1.txt.56d0d699.partial: renamed to: file1.txt 2026/04/02 01:01:25 INFO : file1.txt: Copied (new) 2026/04/02 01:01:25 DEBUG : subdir/file20.txt.1ac3db2f.partial: size = 0 OK 2026/04/02 01:01:25 DEBUG : subdir/file20.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2026/04/02 01:01:25 DEBUG : subdir/file20.txt.1ac3db2f.partial: renamed to: subdir/file20.txt 2026/04/02 01:01:25 INFO : subdir/file20.txt: Copied (new) 2026/04/02 01:01:25 INFO : subdir: Set directory modification time (using SetModTime) 2026/04/02 01:01:25 DEBUG : Waiting for deletions to finish 2026/04/02 01:01:25 ERROR : error listing: directory not found 2026/04/02 01:01:25 ERROR : Local file system at /tmp/010119bi/all_changed/path2: Failed to list "": directory not found 2026/04/02 01:01:25 DEBUG : removing 1 level 0 directories 2026/04/02 01:01:25 INFO : Local file system at /tmp/010119bi/all_changed/path2: Removing directory 2026/04/02 01:01:25 ERROR : Failed to rmdir: stat /tmp/010119bi/all_changed/path2: no such file or directory 2026/04/02 01:01:25 ERROR : error listing: directory not found 2026/04/02 01:01:25 ERROR : error listing: directory not found 2026/04/02 01:01:25 NOTICE: checking initFs Local file system at /tmp/010119bi/initdir/test_all_changed-wikojoh0 2026/04/02 01:01:26 DEBUG : file1.copy1.txt: Need to transfer - File not found at Destination 2026/04/02 01:01:26 DEBUG : file1.copy2.txt: Need to transfer - File not found at Destination 2026/04/02 01:01:26 DEBUG : file1.copy3.txt: Need to transfer - File not found at Destination 2026/04/02 01:01:26 DEBUG : file1.copy4.txt: Need to transfer - File not found at Destination 2026/04/02 01:01:26 DEBUG : file1.copy5.txt: Need to transfer - File not found at Destination 2026/04/02 01:01:26 DEBUG : file1.txt: Need to transfer - File not found at Destination 2026/04/02 01:01:26 DEBUG : RCLONE_TEST: Need to transfer - File not found at Destination 2026/04/02 01:01:26 DEBUG : subdir: Making directory with metadata 2026/04/02 01:01:27 DEBUG : file1.copy3.txt: Starting singlepart upload 2026/04/02 01:01:27 DEBUG : file1.copy1.txt: Starting singlepart upload 2026/04/02 01:01:27 DEBUG : file1.copy2.txt: Starting singlepart upload 2026/04/02 01:01:27 DEBUG : file1.copy4.txt: Starting singlepart upload 2026/04/02 01:01:28 DEBUG : subdir: setting time 2021-11-02 05:00:07 +0000 UTC 2026/04/02 01:01:28 INFO : subdir: Made directory with metadata (mtime=2021-11-02T05:00:07Z) 2026/04/02 01:01:28 DEBUG : subdir/file20.txt: Need to transfer - File not found at Destination 2026/04/02 01:01:28 DEBUG : OneDrive root 'rclone-test-zocuwub1xugo/010119bi/all_changed/path1': Waiting for checks to finish 2026/04/02 01:01:28 DEBUG : OneDrive root 'rclone-test-zocuwub1xugo/010119bi/all_changed/path1': Waiting for transfers to finish 2026/04/02 01:01:29 DEBUG : file1.copy4.txt: size = 0 OK 2026/04/02 01:01:29 DEBUG : file1.copy4.txt: quickxor = 0000000000000000000000000000000000000000 OK 2026/04/02 01:01:29 INFO : file1.copy4.txt: Copied (new) 2026/04/02 01:01:29 DEBUG : file1.copy5.txt: Starting singlepart upload 2026/04/02 01:01:29 DEBUG : file1.copy3.txt: size = 0 OK 2026/04/02 01:01:29 DEBUG : file1.copy3.txt: quickxor = 0000000000000000000000000000000000000000 OK 2026/04/02 01:01:29 INFO : file1.copy3.txt: Copied (new) 2026/04/02 01:01:29 DEBUG : file1.txt: Starting singlepart upload 2026/04/02 01:01:29 DEBUG : file1.copy2.txt: size = 0 OK 2026/04/02 01:01:29 DEBUG : file1.copy2.txt: quickxor = 0000000000000000000000000000000000000000 OK 2026/04/02 01:01:29 INFO : file1.copy2.txt: Copied (new) 2026/04/02 01:01:29 DEBUG : RCLONE_TEST: Starting multipart upload 2026/04/02 01:01:29 DEBUG : file1.copy1.txt: size = 0 OK 2026/04/02 01:01:29 DEBUG : file1.copy1.txt: quickxor = 0000000000000000000000000000000000000000 OK 2026/04/02 01:01:29 INFO : file1.copy1.txt: Copied (new) 2026/04/02 01:01:29 DEBUG : subdir/file20.txt: Starting singlepart upload 2026/04/02 01:01:30 DEBUG : RCLONE_TEST: Uploading segment 0/109 size 109 2026/04/02 01:01:30 DEBUG : file1.txt: size = 0 OK 2026/04/02 01:01:30 DEBUG : file1.copy5.txt: size = 0 OK 2026/04/02 01:01:30 DEBUG : file1.txt: quickxor = 0000000000000000000000000000000000000000 OK 2026/04/02 01:01:30 INFO : file1.txt: Copied (new) 2026/04/02 01:01:30 DEBUG : file1.copy5.txt: quickxor = 0000000000000000000000000000000000000000 OK 2026/04/02 01:01:30 INFO : file1.copy5.txt: Copied (new) 2026/04/02 01:01:30 DEBUG : subdir/file20.txt: size = 0 OK 2026/04/02 01:01:30 DEBUG : subdir/file20.txt: quickxor = 0000000000000000000000000000000000000000 OK 2026/04/02 01:01:30 INFO : subdir/file20.txt: Copied (new) 2026/04/02 01:01:49 DEBUG : pacer: low level retry 1/10 (error HTTP error 503 (503 Service Unavailable) returned body: "
This is a temporary issue, so try again in a few minutes.
Technical details:>
Ref A: 79B657A6A4A346A2ABBED3B4F85B5980 Ref B: FRA261071506062 Ref C: 2026-04-02T01:01:30Z