"./bisync.test -test.v -test.timeout 1h0m0s -remote TestOneDrive: -verbose -test.run '^TestBisyncLocalRemote$/^(filters|max_delete_path2_force)$'" - Starting (try 2/5) 2026/01/28 02:29:16 DEBUG : Creating backend with remote "TestOneDrive:rclone-test-miluguv3bavo" 2026/01/28 02:29:16 DEBUG : Using config file from "/home/rclone/.rclone.conf" 2026/01/28 02:29:16 DEBUG : TestOneDrive: Set overridden config ["user_agent"] for backend startup 2026/01/28 02:29:17 DEBUG : Creating backend with remote "/tmp/rclone1992311513" === RUN TestBisyncLocalRemote 2026/01/28 02:29:17 DEBUG : Creating backend with remote "TestOneDrive:rclone-test-totamak2lodo" 2026/01/28 02:29:17 DEBUG : TestOneDrive: Set overridden config ["user_agent"] for backend startup 2026/01/28 02:29:19 NOTICE: remote: TestOneDrive:rclone-test-totamak2lodo === RUN TestBisyncLocalRemote/filters 2026/01/28 02:29:19 DEBUG : Creating backend with remote "/tmp/022919ve" 2026/01/28 02:29:19 DEBUG : Creating backend with remote "/tmp/022919ve/filters/path1" 2026/01/28 02:29:19 DEBUG : Creating backend with remote "TestOneDrive:rclone-test-totamak2lodo/022919ve" 2026/01/28 02:29:19 DEBUG : TestOneDrive: Set overridden config ["user_agent"] for backend startup 2026/01/28 02:29:22 INFO : path2: Making directory bisync_test.go:2013: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/cmd/bisync/bisync_test.go:2013 /home/rclone/go/src/github.com/rclone/rclone/cmd/bisync/bisync_test.go:639 /home/rclone/go/src/github.com/rclone/rclone/cmd/bisync/bisync_test.go:433 /home/rclone/go/src/github.com/rclone/rclone/cmd/bisync/bisync_test.go:405 Error: Received unexpected error: failed to make directory: itemNotFound: Item not found Test: TestBisyncLocalRemote/filters Messages: Mkdir path2 2026/01/28 02:29:24 DEBUG : Creating backend with remote "TestOneDrive:rclone-test-totamak2lodo/022919ve/filters/path2" 2026/01/28 02:29:24 DEBUG : TestOneDrive: Set overridden config ["user_agent"] for backend startup 2026/01/28 02:29:26 DEBUG : Creating backend with remote "/home/rclone/go/src/github.com/rclone/rclone/cmd/bisync/testdata/test_filters/initial" 2026/01/28 02:29:26 DEBUG : Creating backend with remote "/tmp/022919ve/initdir/test_filters-yuboxup0" 2026/01/28 02:29:26 DEBUG : RCLONE_TEST: Need to transfer - File not found at Destination 2026/01/28 02:29:26 DEBUG : file1.txt: Need to transfer - File not found at Destination 2026/01/28 02:29:26 DEBUG : file2.txt: Need to transfer - File not found at Destination 2026/01/28 02:29:26 DEBUG : file3.txt: Need to transfer - File not found at Destination 2026/01/28 02:29:26 DEBUG : file4.txt: Need to transfer - File not found at Destination 2026/01/28 02:29:26 DEBUG : file5.txt: Need to transfer - File not found at Destination 2026/01/28 02:29:26 DEBUG : file6.txt: Need to transfer - File not found at Destination 2026/01/28 02:29:26 DEBUG : file7.txt: Need to transfer - File not found at Destination 2026/01/28 02:29:26 DEBUG : subdir: Making directory with metadata 2026/01/28 02:29:26 INFO : subdir: Made directory with metadata (mtime=2021-11-02T05:00:07Z) 2026/01/28 02:29:26 DEBUG : Added delayed dir = "subdir", newDst=subdir 2026/01/28 02:29:26 DEBUG : subdir/file20.txt: Need to transfer - File not found at Destination 2026/01/28 02:29:26 DEBUG : file1.txt.56d0d699.partial: size = 0 OK 2026/01/28 02:29:26 DEBUG : file2.txt.3230ad67.partial: size = 0 OK 2026/01/28 02:29:26 DEBUG : file1.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2026/01/28 02:29:26 DEBUG : file2.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2026/01/28 02:29:26 DEBUG : Local file system at /tmp/022919ve/initdir/test_filters-yuboxup0: Waiting for checks to finish 2026/01/28 02:29:26 DEBUG : file3.txt.a74079f2.partial: size = 0 OK 2026/01/28 02:29:26 DEBUG : file1.txt.56d0d699.partial: renamed to: file1.txt 2026/01/28 02:29:26 INFO : file1.txt: Copied (new) 2026/01/28 02:29:26 DEBUG : file2.txt.3230ad67.partial: renamed to: file2.txt 2026/01/28 02:29:26 INFO : file2.txt: Copied (new) 2026/01/28 02:29:26 DEBUG : Local file system at /tmp/022919ve/initdir/test_filters-yuboxup0: Waiting for transfers to finish 2026/01/28 02:29:26 DEBUG : file3.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2026/01/28 02:29:26 DEBUG : file5.txt.6e808e0e.partial: size = 0 OK 2026/01/28 02:29:26 DEBUG : file5.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2026/01/28 02:29:26 DEBUG : file4.txt.fbf05a9b.partial: size = 0 OK 2026/01/28 02:29:26 DEBUG : file3.txt.a74079f2.partial: renamed to: file3.txt 2026/01/28 02:29:26 DEBUG : file4.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2026/01/28 02:29:26 DEBUG : file5.txt.6e808e0e.partial: renamed to: file5.txt 2026/01/28 02:29:26 INFO : file5.txt: Copied (new) 2026/01/28 02:29:26 INFO : file3.txt: Copied (new) 2026/01/28 02:29:26 DEBUG : file4.txt.fbf05a9b.partial: renamed to: file4.txt 2026/01/28 02:29:26 INFO : file4.txt: Copied (new) 2026/01/28 02:29:26 DEBUG : RCLONE_TEST.abb09051.partial: size = 109 OK 2026/01/28 02:29:26 DEBUG : RCLONE_TEST: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK 2026/01/28 02:29:26 DEBUG : RCLONE_TEST.abb09051.partial: renamed to: RCLONE_TEST 2026/01/28 02:29:26 INFO : RCLONE_TEST: Copied (new) 2026/01/28 02:29:26 DEBUG : file7.txt.9f102165.partial: size = 0 OK 2026/01/28 02:29:26 DEBUG : file6.txt.0a60f5f0.partial: size = 0 OK 2026/01/28 02:29:26 DEBUG : subdir/file20.txt.1ac3db2f.partial: size = 0 OK 2026/01/28 02:29:26 DEBUG : file6.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2026/01/28 02:29:26 DEBUG : subdir/file20.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2026/01/28 02:29:26 DEBUG : file7.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2026/01/28 02:29:26 DEBUG : file6.txt.0a60f5f0.partial: renamed to: file6.txt 2026/01/28 02:29:26 INFO : file6.txt: Copied (new) 2026/01/28 02:29:26 DEBUG : subdir/file20.txt.1ac3db2f.partial: renamed to: subdir/file20.txt 2026/01/28 02:29:26 INFO : subdir/file20.txt: Copied (new) 2026/01/28 02:29:26 DEBUG : file7.txt.9f102165.partial: renamed to: file7.txt 2026/01/28 02:29:26 INFO : file7.txt: Copied (new) 2026/01/28 02:29:26 INFO : subdir: Set directory modification time (using SetModTime) 2026/01/28 02:29:26 DEBUG : Creating backend with remote "/home/rclone/go/src/github.com/rclone/rclone/cmd/bisync/testdata/test_filters/modfiles" 2026/01/28 02:29:26 DEBUG : Creating backend with remote "/tmp/022919ve/datadir/test_filters-jorepid4" 2026/01/28 02:29:26 DEBUG : fileZ.txt: Need to transfer - File not found at Destination 2026/01/28 02:29:26 DEBUG : filtersfile.flt: Need to transfer - File not found at Destination 2026/01/28 02:29:26 DEBUG : Local file system at /tmp/022919ve/datadir/test_filters-jorepid4: Waiting for checks to finish 2026/01/28 02:29:26 DEBUG : Local file system at /tmp/022919ve/datadir/test_filters-jorepid4: Waiting for transfers to finish 2026/01/28 02:29:26 DEBUG : fileZ.txt.64882095.partial: size = 19 OK 2026/01/28 02:29:26 DEBUG : fileZ.txt: md5 = 7fe98ed88552b828777d8630900346b8 OK 2026/01/28 02:29:26 DEBUG : fileZ.txt.64882095.partial: renamed to: fileZ.txt 2026/01/28 02:29:26 INFO : fileZ.txt: Copied (new) 2026/01/28 02:29:26 DEBUG : filtersfile.flt.e46c0e4d.partial: size = 254 OK 2026/01/28 02:29:26 DEBUG : filtersfile.flt: md5 = 1cec24a8ae7c33c49693a14d53fd6a96 OK 2026/01/28 02:29:26 DEBUG : filtersfile.flt.e46c0e4d.partial: renamed to: filtersfile.flt 2026/01/28 02:29:26 INFO : filtersfile.flt: Copied (new) 2026/01/28 02:29:26 DEBUG : Waiting for deletions to finish 2026/01/28 02:29:26 ERROR : error listing: directory not found 2026/01/28 02:29:26 ERROR : Local file system at /tmp/022919ve/filters/path1: Failed to list "": directory not found 2026/01/28 02:29:26 DEBUG : removing 1 level 0 directories 2026/01/28 02:29:26 INFO : Local file system at /tmp/022919ve/filters/path1: Removing directory 2026/01/28 02:29:26 ERROR : Failed to rmdir: stat /tmp/022919ve/filters/path1: no such file or directory 2026/01/28 02:29:27 ERROR : error listing: directory not found 2026/01/28 02:29:28 ERROR : error listing: directory not found 2026/01/28 02:29:28 NOTICE: checking initFs Local file system at /tmp/022919ve/initdir/test_filters-yuboxup0 2026/01/28 02:29:28 DEBUG : RCLONE_TEST: Need to transfer - File not found at Destination 2026/01/28 02:29:28 DEBUG : file1.txt: Need to transfer - File not found at Destination 2026/01/28 02:29:28 DEBUG : file2.txt: Need to transfer - File not found at Destination 2026/01/28 02:29:28 DEBUG : file3.txt: Need to transfer - File not found at Destination 2026/01/28 02:29:28 DEBUG : file4.txt: Need to transfer - File not found at Destination 2026/01/28 02:29:28 DEBUG : file5.txt: Need to transfer - File not found at Destination 2026/01/28 02:29:28 DEBUG : file6.txt: Need to transfer - File not found at Destination 2026/01/28 02:29:28 DEBUG : file7.txt: Need to transfer - File not found at Destination 2026/01/28 02:29:28 DEBUG : subdir: Making directory with metadata 2026/01/28 02:29:28 INFO : subdir: Made directory with metadata (mtime=2021-11-02T05:00:07Z) 2026/01/28 02:29:28 DEBUG : Added delayed dir = "subdir", newDst=subdir 2026/01/28 02:29:28 DEBUG : file1.txt.56d0d699.partial: size = 0 OK 2026/01/28 02:29:28 DEBUG : file1.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2026/01/28 02:29:28 DEBUG : subdir/file20.txt: Need to transfer - File not found at Destination 2026/01/28 02:29:28 DEBUG : file1.txt.56d0d699.partial: renamed to: file1.txt 2026/01/28 02:29:28 INFO : file1.txt: Copied (new) 2026/01/28 02:29:28 DEBUG : Local file system at /tmp/022919ve/filters/path1: Waiting for checks to finish 2026/01/28 02:29:28 DEBUG : file2.txt.3230ad67.partial: size = 0 OK 2026/01/28 02:29:28 DEBUG : Local file system at /tmp/022919ve/filters/path1: Waiting for transfers to finish 2026/01/28 02:29:28 DEBUG : file2.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2026/01/28 02:29:28 DEBUG : file2.txt.3230ad67.partial: renamed to: file2.txt 2026/01/28 02:29:28 INFO : file2.txt: Copied (new) 2026/01/28 02:29:28 DEBUG : file3.txt.a74079f2.partial: size = 0 OK 2026/01/28 02:29:28 DEBUG : file4.txt.fbf05a9b.partial: size = 0 OK 2026/01/28 02:29:28 DEBUG : RCLONE_TEST.abb09051.partial: size = 109 OK 2026/01/28 02:29:28 DEBUG : file5.txt.6e808e0e.partial: size = 0 OK 2026/01/28 02:29:28 DEBUG : file3.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2026/01/28 02:29:28 DEBUG : RCLONE_TEST: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK 2026/01/28 02:29:28 DEBUG : file5.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2026/01/28 02:29:28 DEBUG : file3.txt.a74079f2.partial: renamed to: file3.txt 2026/01/28 02:29:28 DEBUG : RCLONE_TEST.abb09051.partial: renamed to: RCLONE_TEST 2026/01/28 02:29:28 INFO : file3.txt: Copied (new) 2026/01/28 02:29:28 INFO : RCLONE_TEST: Copied (new) 2026/01/28 02:29:28 DEBUG : file5.txt.6e808e0e.partial: renamed to: file5.txt 2026/01/28 02:29:28 INFO : file5.txt: Copied (new) 2026/01/28 02:29:28 DEBUG : file7.txt.9f102165.partial: size = 0 OK 2026/01/28 02:29:28 DEBUG : subdir/file20.txt.1ac3db2f.partial: size = 0 OK 2026/01/28 02:29:28 DEBUG : subdir/file20.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2026/01/28 02:29:28 DEBUG : file7.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2026/01/28 02:29:28 DEBUG : file4.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2026/01/28 02:29:28 DEBUG : subdir/file20.txt.1ac3db2f.partial: renamed to: subdir/file20.txt 2026/01/28 02:29:28 INFO : subdir/file20.txt: Copied (new) 2026/01/28 02:29:28 DEBUG : file6.txt.0a60f5f0.partial: size = 0 OK 2026/01/28 02:29:28 DEBUG : file7.txt.9f102165.partial: renamed to: file7.txt 2026/01/28 02:29:28 INFO : file7.txt: Copied (new) 2026/01/28 02:29:28 DEBUG : file6.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2026/01/28 02:29:28 DEBUG : file6.txt.0a60f5f0.partial: renamed to: file6.txt 2026/01/28 02:29:28 INFO : file6.txt: Copied (new) 2026/01/28 02:29:28 DEBUG : file4.txt.fbf05a9b.partial: renamed to: file4.txt 2026/01/28 02:29:28 INFO : file4.txt: Copied (new) 2026/01/28 02:29:28 INFO : subdir: Set directory modification time (using SetModTime) 2026/01/28 02:29:28 NOTICE: checking Path1 Local file system at /tmp/022919ve/filters/path1 2026/01/28 02:29:28 DEBUG : file1.txt: Need to transfer - File not found at Destination 2026/01/28 02:29:28 DEBUG : file2.txt: Need to transfer - File not found at Destination 2026/01/28 02:29:28 DEBUG : file3.txt: Need to transfer - File not found at Destination 2026/01/28 02:29:28 DEBUG : file4.txt: Need to transfer - File not found at Destination 2026/01/28 02:29:28 DEBUG : file5.txt: Need to transfer - File not found at Destination 2026/01/28 02:29:28 DEBUG : file6.txt: Need to transfer - File not found at Destination 2026/01/28 02:29:28 DEBUG : file7.txt: Need to transfer - File not found at Destination 2026/01/28 02:29:28 DEBUG : RCLONE_TEST: Need to transfer - File not found at Destination 2026/01/28 02:29:28 DEBUG : subdir: Making directory with metadata 2026/01/28 02:29:32 DEBUG : subdir/file20.txt: Need to transfer - File not found at Destination 2026/01/28 02:29:32 DEBUG : OneDrive root 'rclone-test-totamak2lodo/022919ve/filters/path2': Waiting for checks to finish 2026/01/28 02:29:32 DEBUG : OneDrive root 'rclone-test-totamak2lodo/022919ve/filters/path2': Waiting for transfers to finish 2026/01/28 02:29:33 ERROR : file1.txt: Failed to copy: invalidRequest: The provided drive id appears to be malformed, or does not represent a valid drive. 2026/01/28 02:29:34 ERROR : file2.txt: Failed to copy: failed to make directory: itemNotFound: Item not found 2026/01/28 02:29:36 ERROR : file3.txt: Failed to copy: invalidRequest: The provided drive id appears to be malformed, or does not represent a valid drive. 2026/01/28 02:29:38 DEBUG : file7.txt: Starting singlepart upload 2026/01/28 02:29:38 DEBUG : file4.txt: Starting singlepart upload 2026/01/28 02:29:38 DEBUG : file5.txt: Starting singlepart upload 2026/01/28 02:29:38 DEBUG : file6.txt: Starting singlepart upload 2026/01/28 02:29:39 DEBUG : file5.txt: size = 0 OK 2026/01/28 02:29:39 DEBUG : file5.txt: quickxor = 0000000000000000000000000000000000000000 OK 2026/01/28 02:29:39 INFO : file5.txt: Copied (new) 2026/01/28 02:29:39 DEBUG : RCLONE_TEST: Starting multipart upload 2026/01/28 02:29:40 DEBUG : info from Update error: null 2026/01/28 02:29:40 ERROR : file7.txt: Failed to copy: invalidRequest: The provided drive id appears to be malformed, or does not represent a valid drive. 2026/01/28 02:29:40 DEBUG : info from Update error: null 2026/01/28 02:29:40 ERROR : file6.txt: Failed to copy: failed to fetch and update metadata: invalidRequest: The provided drive id appears to be malformed, or does not represent a valid drive. 2026/01/28 02:29:40 ERROR : subdir/file20.txt: Failed to copy: failed to make directory: itemNotFound: Item not found 2026/01/28 02:29:40 DEBUG : RCLONE_TEST: Uploading segment 0/109 size 109 2026/01/28 02:29:41 DEBUG : file4.txt: size = 0 OK 2026/01/28 02:29:41 DEBUG : file4.txt: quickxor = 0000000000000000000000000000000000000000 OK 2026/01/28 02:29:41 INFO : file4.txt: Copied (new) 2026/01/28 02:29:41 DEBUG : RCLONE_TEST: size = 109 OK 2026/01/28 02:29:41 DEBUG : RCLONE_TEST: quickxor = d3ed6bdc9f8d10e5b3b59d8fcc99acce82169035 OK 2026/01/28 02:29:41 INFO : RCLONE_TEST: Copied (new) bisync_test.go:2013: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/cmd/bisync/bisync_test.go:2013 /home/rclone/go/src/github.com/rclone/rclone/cmd/bisync/bisync_test.go:509 /home/rclone/go/src/github.com/rclone/rclone/cmd/bisync/bisync_test.go:405 Error: Received unexpected error: failed to make directory: itemNotFound: Item not found Test: TestBisyncLocalRemote/filters Messages: setting up path2 2026/01/28 02:29:41 NOTICE: checking path2 OneDrive root 'rclone-test-totamak2lodo/022919ve/filters/path2' fstest.go:298: Sleeping for 1s for list eventual consistency: 1/3 fstest.go:301: Flushing the directory cache 2026/01/28 02:29:44 ERROR : error listing: invalidRequest: The provided drive id appears to be malformed, or does not represent a valid drive. fstest.go:282: Error listing: invalidRequest: The provided drive id appears to be malformed, or does not represent a valid drive. === RUN TestBisyncLocalRemote/max_delete_path2_force 2026/01/28 02:29:44 DEBUG : Creating backend with remote "/tmp/022919ve/max_delete_path2_force/path1" 2026/01/28 02:29:44 INFO : path2: Making directory bisync_test.go:2013: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/cmd/bisync/bisync_test.go:2013 /home/rclone/go/src/github.com/rclone/rclone/cmd/bisync/bisync_test.go:639 /home/rclone/go/src/github.com/rclone/rclone/cmd/bisync/bisync_test.go:433 /home/rclone/go/src/github.com/rclone/rclone/cmd/bisync/bisync_test.go:405 Error: Received unexpected error: invalidRequest: The provided drive id appears to be malformed, or does not represent a valid drive. Test: TestBisyncLocalRemote/max_delete_path2_force Messages: Mkdir path2 2026/01/28 02:29:45 DEBUG : Creating backend with remote "TestOneDrive:rclone-test-totamak2lodo/022919ve/max_delete_path2_force/path2" 2026/01/28 02:29:45 DEBUG : TestOneDrive: Set overridden config ["user_agent"] for backend startup 2026/01/28 02:29:48 DEBUG : Creating backend with remote "/home/rclone/go/src/github.com/rclone/rclone/cmd/bisync/testdata/test_max_delete_path2_force/initial" 2026/01/28 02:29:48 DEBUG : Creating backend with remote "/tmp/022919ve/initdir/test_max_delete_path2_force-becucim6" 2026/01/28 02:29:48 DEBUG : file1.txt: Need to transfer - File not found at Destination 2026/01/28 02:29:48 DEBUG : file2.txt: Need to transfer - File not found at Destination 2026/01/28 02:29:48 DEBUG : file3.txt: Need to transfer - File not found at Destination 2026/01/28 02:29:48 DEBUG : file4.txt: Need to transfer - File not found at Destination 2026/01/28 02:29:48 DEBUG : file5.txt: Need to transfer - File not found at Destination 2026/01/28 02:29:48 DEBUG : file6.txt: Need to transfer - File not found at Destination 2026/01/28 02:29:48 DEBUG : file7.txt: Need to transfer - File not found at Destination 2026/01/28 02:29:48 DEBUG : file8.txt: Need to transfer - File not found at Destination 2026/01/28 02:29:48 DEBUG : file9.txt: Need to transfer - File not found at Destination 2026/01/28 02:29:48 DEBUG : file1.txt.56d0d699.partial: size = 0 OK 2026/01/28 02:29:48 DEBUG : Local file system at /tmp/022919ve/initdir/test_max_delete_path2_force-becucim6: Waiting for checks to finish 2026/01/28 02:29:48 DEBUG : file3.txt.a74079f2.partial: size = 0 OK 2026/01/28 02:29:48 DEBUG : Local file system at /tmp/022919ve/initdir/test_max_delete_path2_force-becucim6: Waiting for transfers to finish 2026/01/28 02:29:48 DEBUG : file2.txt.3230ad67.partial: size = 0 OK 2026/01/28 02:29:48 DEBUG : file1.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2026/01/28 02:29:48 DEBUG : file4.txt.fbf05a9b.partial: size = 0 OK 2026/01/28 02:29:48 DEBUG : file2.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2026/01/28 02:29:48 DEBUG : file4.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2026/01/28 02:29:48 DEBUG : file1.txt.56d0d699.partial: renamed to: file1.txt 2026/01/28 02:29:48 INFO : file1.txt: Copied (new) 2026/01/28 02:29:48 DEBUG : file3.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2026/01/28 02:29:48 DEBUG : file2.txt.3230ad67.partial: renamed to: file2.txt 2026/01/28 02:29:48 INFO : file2.txt: Copied (new) 2026/01/28 02:29:48 DEBUG : file4.txt.fbf05a9b.partial: renamed to: file4.txt 2026/01/28 02:29:48 INFO : file4.txt: Copied (new) 2026/01/28 02:29:48 DEBUG : file6.txt.0a60f5f0.partial: size = 0 OK 2026/01/28 02:29:48 DEBUG : file3.txt.a74079f2.partial: renamed to: file3.txt 2026/01/28 02:29:48 INFO : file3.txt: Copied (new) 2026/01/28 02:29:48 DEBUG : file7.txt.9f102165.partial: size = 0 OK 2026/01/28 02:29:48 DEBUG : file6.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2026/01/28 02:29:48 DEBUG : file8.txt.b300b322.partial: size = 0 OK 2026/01/28 02:29:48 DEBUG : file7.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2026/01/28 02:29:48 DEBUG : file8.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2026/01/28 02:29:48 DEBUG : file6.txt.0a60f5f0.partial: renamed to: file6.txt 2026/01/28 02:29:48 INFO : file6.txt: Copied (new) 2026/01/28 02:29:48 DEBUG : file7.txt.9f102165.partial: renamed to: file7.txt 2026/01/28 02:29:48 INFO : file7.txt: Copied (new) 2026/01/28 02:29:48 DEBUG : file5.txt.6e808e0e.partial: size = 0 OK 2026/01/28 02:29:48 DEBUG : file5.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2026/01/28 02:29:48 DEBUG : file8.txt.b300b322.partial: renamed to: file8.txt 2026/01/28 02:29:48 INFO : file8.txt: Copied (new) 2026/01/28 02:29:48 DEBUG : file5.txt.6e808e0e.partial: renamed to: file5.txt 2026/01/28 02:29:48 INFO : file5.txt: Copied (new) 2026/01/28 02:29:48 DEBUG : file9.txt.84a50ab9.partial: size = 109 OK 2026/01/28 02:29:48 DEBUG : file9.txt: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK 2026/01/28 02:29:48 DEBUG : file9.txt.84a50ab9.partial: renamed to: file9.txt 2026/01/28 02:29:48 INFO : file9.txt: Copied (new) 2026/01/28 02:29:48 DEBUG : Creating backend with remote "/home/rclone/go/src/github.com/rclone/rclone/cmd/bisync/testdata/test_max_delete_path2_force/modfiles" 2026/01/28 02:29:48 DEBUG : Creating backend with remote "/tmp/022919ve/datadir/test_max_delete_path2_force-xusejej1" 2026/01/28 02:29:48 DEBUG : hold.txt: Need to transfer - File not found at Destination 2026/01/28 02:29:48 DEBUG : Local file system at /tmp/022919ve/datadir/test_max_delete_path2_force-xusejej1: Waiting for checks to finish 2026/01/28 02:29:48 DEBUG : Local file system at /tmp/022919ve/datadir/test_max_delete_path2_force-xusejej1: Waiting for transfers to finish 2026/01/28 02:29:48 DEBUG : hold.txt.83686dab.partial: size = 59 OK 2026/01/28 02:29:48 DEBUG : hold.txt: md5 = 628c2241b6ba4e313ef08bdfcf1cd964 OK 2026/01/28 02:29:48 DEBUG : hold.txt.83686dab.partial: renamed to: hold.txt 2026/01/28 02:29:48 INFO : hold.txt: Copied (new) 2026/01/28 02:29:48 DEBUG : Waiting for deletions to finish 2026/01/28 02:29:48 ERROR : error listing: directory not found 2026/01/28 02:29:48 ERROR : Local file system at /tmp/022919ve/max_delete_path2_force/path1: Failed to list "": directory not found 2026/01/28 02:29:48 DEBUG : removing 1 level 0 directories 2026/01/28 02:29:48 INFO : Local file system at /tmp/022919ve/max_delete_path2_force/path1: Removing directory 2026/01/28 02:29:48 ERROR : Failed to rmdir: stat /tmp/022919ve/max_delete_path2_force/path1: no such file or directory 2026/01/28 02:29:49 ERROR : error listing: directory not found 2026/01/28 02:29:49 ERROR : error listing: directory not found 2026/01/28 02:29:49 NOTICE: checking initFs Local file system at /tmp/022919ve/initdir/test_max_delete_path2_force-becucim6 2026/01/28 02:29:49 DEBUG : file1.txt: Need to transfer - File not found at Destination 2026/01/28 02:29:49 DEBUG : file2.txt: Need to transfer - File not found at Destination 2026/01/28 02:29:49 DEBUG : file3.txt: Need to transfer - File not found at Destination 2026/01/28 02:29:49 DEBUG : file4.txt: Need to transfer - File not found at Destination 2026/01/28 02:29:49 DEBUG : file5.txt: Need to transfer - File not found at Destination 2026/01/28 02:29:49 DEBUG : file6.txt: Need to transfer - File not found at Destination 2026/01/28 02:29:49 DEBUG : file7.txt: Need to transfer - File not found at Destination 2026/01/28 02:29:49 DEBUG : file8.txt: Need to transfer - File not found at Destination 2026/01/28 02:29:49 DEBUG : file9.txt: Need to transfer - File not found at Destination 2026/01/28 02:29:49 DEBUG : Local file system at /tmp/022919ve/max_delete_path2_force/path1: Waiting for checks to finish 2026/01/28 02:29:49 DEBUG : file1.txt.56d0d699.partial: size = 0 OK 2026/01/28 02:29:49 DEBUG : Local file system at /tmp/022919ve/max_delete_path2_force/path1: Waiting for transfers to finish 2026/01/28 02:29:49 DEBUG : file1.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2026/01/28 02:29:49 DEBUG : file2.txt.3230ad67.partial: size = 0 OK 2026/01/28 02:29:49 DEBUG : file2.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2026/01/28 02:29:49 DEBUG : file1.txt.56d0d699.partial: renamed to: file1.txt 2026/01/28 02:29:49 INFO : file1.txt: Copied (new) 2026/01/28 02:29:49 DEBUG : file3.txt.a74079f2.partial: size = 0 OK 2026/01/28 02:29:49 DEBUG : file4.txt.fbf05a9b.partial: size = 0 OK 2026/01/28 02:29:49 DEBUG : file2.txt.3230ad67.partial: renamed to: file2.txt 2026/01/28 02:29:49 INFO : file2.txt: Copied (new) 2026/01/28 02:29:49 DEBUG : file3.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2026/01/28 02:29:49 DEBUG : file4.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2026/01/28 02:29:49 DEBUG : file5.txt.6e808e0e.partial: size = 0 OK 2026/01/28 02:29:49 DEBUG : file5.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2026/01/28 02:29:49 DEBUG : file6.txt.0a60f5f0.partial: size = 0 OK 2026/01/28 02:29:49 DEBUG : file4.txt.fbf05a9b.partial: renamed to: file4.txt 2026/01/28 02:29:49 INFO : file4.txt: Copied (new) 2026/01/28 02:29:49 DEBUG : file5.txt.6e808e0e.partial: renamed to: file5.txt 2026/01/28 02:29:49 DEBUG : file6.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2026/01/28 02:29:49 INFO : file5.txt: Copied (new) 2026/01/28 02:29:49 DEBUG : file6.txt.0a60f5f0.partial: renamed to: file6.txt 2026/01/28 02:29:49 INFO : file6.txt: Copied (new) 2026/01/28 02:29:49 DEBUG : file7.txt.9f102165.partial: size = 0 OK 2026/01/28 02:29:49 DEBUG : file3.txt.a74079f2.partial: renamed to: file3.txt 2026/01/28 02:29:49 DEBUG : file7.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2026/01/28 02:29:49 INFO : file3.txt: Copied (new) 2026/01/28 02:29:49 DEBUG : file8.txt.b300b322.partial: size = 0 OK 2026/01/28 02:29:49 DEBUG : file7.txt.9f102165.partial: renamed to: file7.txt 2026/01/28 02:29:49 DEBUG : file8.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2026/01/28 02:29:49 INFO : file7.txt: Copied (new) 2026/01/28 02:29:49 DEBUG : file8.txt.b300b322.partial: renamed to: file8.txt 2026/01/28 02:29:49 INFO : file8.txt: Copied (new) 2026/01/28 02:29:49 DEBUG : file9.txt.84a50ab9.partial: size = 109 OK 2026/01/28 02:29:49 DEBUG : file9.txt: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK 2026/01/28 02:29:49 DEBUG : file9.txt.84a50ab9.partial: renamed to: file9.txt 2026/01/28 02:29:49 INFO : file9.txt: Copied (new) 2026/01/28 02:29:49 NOTICE: checking Path1 Local file system at /tmp/022919ve/max_delete_path2_force/path1 2026/01/28 02:29:50 DEBUG : file1.txt: Need to transfer - File not found at Destination 2026/01/28 02:29:50 DEBUG : file2.txt: Need to transfer - File not found at Destination 2026/01/28 02:29:50 DEBUG : file3.txt: Need to transfer - File not found at Destination 2026/01/28 02:29:50 DEBUG : file4.txt: Need to transfer - File not found at Destination 2026/01/28 02:29:50 DEBUG : file5.txt: Need to transfer - File not found at Destination 2026/01/28 02:29:50 DEBUG : file6.txt: Need to transfer - File not found at Destination 2026/01/28 02:29:50 DEBUG : file7.txt: Need to transfer - File not found at Destination 2026/01/28 02:29:50 DEBUG : file8.txt: Need to transfer - File not found at Destination 2026/01/28 02:29:50 DEBUG : file9.txt: Need to transfer - File not found at Destination 2026/01/28 02:29:50 DEBUG : OneDrive root 'rclone-test-totamak2lodo/022919ve/max_delete_path2_force/path2': Waiting for checks to finish 2026/01/28 02:29:50 DEBUG : OneDrive root 'rclone-test-totamak2lodo/022919ve/max_delete_path2_force/path2': Waiting for transfers to finish 2026/01/28 02:29:54 DEBUG : file2.txt: Starting singlepart upload 2026/01/28 02:29:54 DEBUG : file1.txt: Starting singlepart upload 2026/01/28 02:29:54 DEBUG : file3.txt: Starting singlepart upload 2026/01/28 02:29:54 DEBUG : file4.txt: Starting singlepart upload 2026/01/28 02:29:54 DEBUG : info from Update error: null 2026/01/28 02:29:54 ERROR : file1.txt: Failed to copy: invalidRequest: The provided drive id appears to be malformed, or does not represent a valid drive. 2026/01/28 02:29:54 DEBUG : file5.txt: Starting singlepart upload 2026/01/28 02:29:54 DEBUG : info from Update error: null 2026/01/28 02:29:54 ERROR : file5.txt: Failed to copy: invalidRequest: The provided drive id appears to be malformed, or does not represent a valid drive. 2026/01/28 02:29:54 DEBUG : file6.txt: Starting singlepart upload 2026/01/28 02:29:55 DEBUG : file2.txt: size = 0 OK 2026/01/28 02:29:55 DEBUG : file2.txt: quickxor = 0000000000000000000000000000000000000000 OK 2026/01/28 02:29:55 INFO : file2.txt: Copied (new) 2026/01/28 02:29:55 DEBUG : file7.txt: Starting singlepart upload 2026/01/28 02:29:55 DEBUG : info from Update error: null 2026/01/28 02:29:55 ERROR : file3.txt: Failed to copy: failed to fetch and update metadata: invalidRequest: The provided drive id appears to be malformed, or does not represent a valid drive. 2026/01/28 02:29:55 DEBUG : file8.txt: Starting singlepart upload 2026/01/28 02:29:55 DEBUG : file4.txt: size = 0 OK 2026/01/28 02:29:55 DEBUG : file4.txt: quickxor = 0000000000000000000000000000000000000000 OK 2026/01/28 02:29:55 INFO : file4.txt: Copied (new) 2026/01/28 02:29:55 DEBUG : file9.txt: Starting multipart upload 2026/01/28 02:29:56 DEBUG : file6.txt: size = 0 OK 2026/01/28 02:29:56 DEBUG : file6.txt: quickxor = 0000000000000000000000000000000000000000 OK 2026/01/28 02:29:56 INFO : file6.txt: Copied (new) 2026/01/28 02:29:56 DEBUG : file9.txt: Uploading segment 0/109 size 109 2026/01/28 02:29:57 DEBUG : file9.txt: size = 109 OK 2026/01/28 02:29:57 DEBUG : file9.txt: quickxor = d3ed6bdc9f8d10e5b3b59d8fcc99acce82169035 OK 2026/01/28 02:29:57 INFO : file9.txt: Copied (new) 2026/01/28 02:29:57 DEBUG : file7.txt: size = 0 OK 2026/01/28 02:29:57 DEBUG : file7.txt: quickxor = 0000000000000000000000000000000000000000 OK 2026/01/28 02:29:57 INFO : file7.txt: Copied (new) 2026/01/28 02:29:57 DEBUG : file8.txt: size = 0 OK 2026/01/28 02:29:57 DEBUG : file8.txt: quickxor = 0000000000000000000000000000000000000000 OK 2026/01/28 02:29:57 INFO : file8.txt: Copied (new) bisync_test.go:2013: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/cmd/bisync/bisync_test.go:2013 /home/rclone/go/src/github.com/rclone/rclone/cmd/bisync/bisync_test.go:509 /home/rclone/go/src/github.com/rclone/rclone/cmd/bisync/bisync_test.go:405 Error: Received unexpected error: failed to fetch and update metadata: invalidRequest: The provided drive id appears to be malformed, or does not represent a valid drive. Test: TestBisyncLocalRemote/max_delete_path2_force Messages: setting up path2 2026/01/28 02:29:57 NOTICE: checking path2 OneDrive root 'rclone-test-totamak2lodo/022919ve/max_delete_path2_force/path2' fstest.go:298: Sleeping for 1s for list eventual consistency: 1/3 fstest.go:301: Flushing the directory cache 2026/01/28 02:30:01 ERROR : error listing: invalidRequest: The provided drive id appears to be malformed, or does not represent a valid drive. fstest.go:282: Error listing: invalidRequest: The provided drive id appears to be malformed, or does not represent a valid drive. 2026/01/28 02:30:01 DEBUG : OneDrive root 'rclone-test-totamak2lodo': Purge remote --- FAIL: TestBisyncLocalRemote (45.60s) --- FAIL: TestBisyncLocalRemote/filters (24.74s) --- FAIL: TestBisyncLocalRemote/max_delete_path2_force (16.81s) FAIL 2026/01/28 02:30:03 DEBUG : OneDrive root 'rclone-test-miluguv3bavo': Purge remote 2026/01/28 02:30:03 NOTICE: purge failed: directory not found "./bisync.test -test.v -test.timeout 1h0m0s -remote TestOneDrive: -verbose -test.run '^TestBisyncLocalRemote$/^(filters|max_delete_path2_force)$'" - Finished ERROR in 47.125482632s (try 2/5): exit status 1: Failed [TestBisyncLocalRemote/filters TestBisyncLocalRemote/max_delete_path2_force]