"./bisync.test -test.v -test.timeout 1h0m0s -remote TestPikPak: -verbose -test.run '^TestBisyncLocalRemote$/^nomodtime$|^TestBisyncRemoteLocal$/^nomodtime$'" - Starting (try 2/5) 2024/12/13 05:35:18 DEBUG : Creating backend with remote "TestPikPak:rclone-test-beditos0kuqo" 2024/12/13 05:35:18 DEBUG : Using config file from "/home/rclone/.rclone.conf" 2024/12/13 05:35:19 DEBUG : Creating backend with remote "/tmp/rclone2737530826" === RUN TestBisyncRemoteLocal 2024/12/13 05:35:19 DEBUG : Creating backend with remote "TestPikPak:rclone-test-gohirin9kelu" 2024/12/13 05:35:21 NOTICE: remote: TestPikPak:rclone-test-gohirin9kelu === RUN TestBisyncRemoteLocal/nomodtime 2024/12/13 05:35:21 DEBUG : Creating backend with remote "TestPikPak:rclone-test-gohirin9kelu/053521ya" 2024/12/13 05:35:21 DEBUG : Using config file from "/home/rclone/.rclone.conf" 2024/12/13 05:35:23 DEBUG : path1: Making directory 2024/12/13 05:35:24 DEBUG : Creating backend with remote "TestPikPak:rclone-test-gohirin9kelu/053521ya/nomodtime/path1" 2024/12/13 05:35:26 DEBUG : Creating backend with remote "/tmp/053521ya" 2024/12/13 05:35:26 DEBUG : Creating backend with remote "/tmp/053521ya/nomodtime/path2" 2024/12/13 05:35:26 DEBUG : Creating backend with remote "/home/rclone/go/src/github.com/rclone/rclone/cmd/bisync/testdata/test_nomodtime/initial" 2024/12/13 05:35:26 DEBUG : Creating backend with remote "/tmp/053521ya/initdir/test_nomodtime-qulecaz6" 2024/12/13 05:35:26 DEBUG : RCLONE_TEST: Need to transfer - File not found at Destination 2024/12/13 05:35:26 DEBUG : file1.txt: Need to transfer - File not found at Destination 2024/12/13 05:35:26 DEBUG : file2.txt: Need to transfer - File not found at Destination 2024/12/13 05:35:26 DEBUG : file3.txt: Need to transfer - File not found at Destination 2024/12/13 05:35:26 DEBUG : file4.txt: Need to transfer - File not found at Destination 2024/12/13 05:35:26 DEBUG : file5.txt: Need to transfer - File not found at Destination 2024/12/13 05:35:26 DEBUG : file6.txt: Need to transfer - File not found at Destination 2024/12/13 05:35:26 DEBUG : file7.txt: Need to transfer - File not found at Destination 2024/12/13 05:35:26 DEBUG : file8.txt: Need to transfer - File not found at Destination 2024/12/13 05:35:26 DEBUG : Local file system at /tmp/053521ya/initdir/test_nomodtime-qulecaz6: Waiting for checks to finish 2024/12/13 05:35:26 DEBUG : Local file system at /tmp/053521ya/initdir/test_nomodtime-qulecaz6: Waiting for transfers to finish 2024/12/13 05:35:26 DEBUG : RCLONE_TEST: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK 2024/12/13 05:35:26 DEBUG : RCLONE_TEST.cf9a93ac.partial: renamed to: RCLONE_TEST 2024/12/13 05:35:26 INFO : RCLONE_TEST: Copied (new) 2024/12/13 05:35:26 DEBUG : file3.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2024/12/13 05:35:26 DEBUG : file3.txt.5028a97.partial: renamed to: file3.txt 2024/12/13 05:35:26 INFO : file3.txt: Copied (new) 2024/12/13 05:35:26 DEBUG : file4.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2024/12/13 05:35:26 DEBUG : file4.txt.5028a97.partial: renamed to: file4.txt 2024/12/13 05:35:26 INFO : file4.txt: Copied (new) 2024/12/13 05:35:26 DEBUG : file5.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2024/12/13 05:35:26 DEBUG : file5.txt.5028a97.partial: renamed to: file5.txt 2024/12/13 05:35:26 INFO : file5.txt: Copied (new) 2024/12/13 05:35:26 DEBUG : file6.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2024/12/13 05:35:26 DEBUG : file6.txt.5028a97.partial: renamed to: file6.txt 2024/12/13 05:35:26 INFO : file6.txt: Copied (new) 2024/12/13 05:35:26 DEBUG : file2.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2024/12/13 05:35:26 DEBUG : file7.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2024/12/13 05:35:26 DEBUG : file2.txt.5028a97.partial: renamed to: file2.txt 2024/12/13 05:35:26 INFO : file2.txt: Copied (new) 2024/12/13 05:35:26 DEBUG : file1.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2024/12/13 05:35:26 DEBUG : file1.txt.5028a97.partial: renamed to: file1.txt 2024/12/13 05:35:26 INFO : file1.txt: Copied (new) 2024/12/13 05:35:26 DEBUG : file7.txt.5028a97.partial: renamed to: file7.txt 2024/12/13 05:35:26 INFO : file7.txt: Copied (new) 2024/12/13 05:35:26 DEBUG : file8.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2024/12/13 05:35:26 DEBUG : file8.txt.5028a97.partial: renamed to: file8.txt 2024/12/13 05:35:26 INFO : file8.txt: Copied (new) 2024/12/13 05:35:26 DEBUG : Creating backend with remote "/home/rclone/go/src/github.com/rclone/rclone/cmd/bisync/testdata/test_nomodtime/modfiles" 2024/12/13 05:35:26 DEBUG : Creating backend with remote "/tmp/053521ya/datadir/test_nomodtime-ciyapad1" 2024/12/13 05:35:26 DEBUG : file1.txt: Need to transfer - File not found at Destination 2024/12/13 05:35:26 DEBUG : file10.txt: Need to transfer - File not found at Destination 2024/12/13 05:35:26 DEBUG : file11.txt: Need to transfer - File not found at Destination 2024/12/13 05:35:26 DEBUG : file2.txt: Need to transfer - File not found at Destination 2024/12/13 05:35:26 DEBUG : file5L.txt: Need to transfer - File not found at Destination 2024/12/13 05:35:26 DEBUG : file5R.txt: Need to transfer - File not found at Destination 2024/12/13 05:35:26 DEBUG : file6.txt: Need to transfer - File not found at Destination 2024/12/13 05:35:26 DEBUG : file7.txt: Need to transfer - File not found at Destination 2024/12/13 05:35:26 DEBUG : Local file system at /tmp/053521ya/datadir/test_nomodtime-ciyapad1: Waiting for checks to finish 2024/12/13 05:35:26 DEBUG : Local file system at /tmp/053521ya/datadir/test_nomodtime-ciyapad1: Waiting for transfers to finish 2024/12/13 05:35:26 DEBUG : file10.txt: md5 = 7fe98ed88552b828777d8630900346b8 OK 2024/12/13 05:35:26 DEBUG : file10.txt.7d45770.partial: renamed to: file10.txt 2024/12/13 05:35:26 INFO : file10.txt: Copied (new) 2024/12/13 05:35:26 DEBUG : file1.txt: md5 = 7fe98ed88552b828777d8630900346b8 OK 2024/12/13 05:35:26 DEBUG : file1.txt.7d45770.partial: renamed to: file1.txt 2024/12/13 05:35:26 INFO : file1.txt: Copied (new) 2024/12/13 05:35:26 DEBUG : file11.txt: md5 = 7fe98ed88552b828777d8630900346b8 OK 2024/12/13 05:35:26 DEBUG : file2.txt: md5 = fb3ecfb2800400fb01b0bfd39903e9fb OK 2024/12/13 05:35:26 DEBUG : file11.txt.7d45770.partial: renamed to: file11.txt 2024/12/13 05:35:26 INFO : file11.txt: Copied (new) 2024/12/13 05:35:26 DEBUG : file2.txt.21f2ec7f.partial: renamed to: file2.txt 2024/12/13 05:35:26 INFO : file2.txt: Copied (new) 2024/12/13 05:35:26 DEBUG : file5R.txt: md5 = 979a803b15d27df0c31ad7d29006d10b OK 2024/12/13 05:35:26 DEBUG : file5L.txt: md5 = 0860a03592626642f8fd6c8bfb447d2a OK 2024/12/13 05:35:26 DEBUG : file5R.txt.9ed658ed.partial: renamed to: file5R.txt 2024/12/13 05:35:26 INFO : file5R.txt: Copied (new) 2024/12/13 05:35:26 DEBUG : file5L.txt.9ed658ed.partial: renamed to: file5L.txt 2024/12/13 05:35:26 INFO : file5L.txt: Copied (new) 2024/12/13 05:35:26 DEBUG : file7.txt: md5 = 7fe98ed88552b828777d8630900346b8 OK 2024/12/13 05:35:26 DEBUG : file6.txt: md5 = 7fe98ed88552b828777d8630900346b8 OK 2024/12/13 05:35:26 DEBUG : file7.txt.7d45770.partial: renamed to: file7.txt 2024/12/13 05:35:26 INFO : file7.txt: Copied (new) 2024/12/13 05:35:26 DEBUG : file6.txt.7d45770.partial: renamed to: file6.txt 2024/12/13 05:35:26 INFO : file6.txt: Copied (new) 2024/12/13 05:35:26 ERROR : : error listing: directory not found 2024/12/13 05:35:26 ERROR : : error listing: directory not found 2024/12/13 05:35:26 NOTICE: checking initFs Local file system at /tmp/053521ya/initdir/test_nomodtime-qulecaz6 2024/12/13 05:35:27 DEBUG : RCLONE_TEST: Need to transfer - File not found at Destination 2024/12/13 05:35:27 DEBUG : file1.txt: Need to transfer - File not found at Destination 2024/12/13 05:35:27 DEBUG : file2.txt: Need to transfer - File not found at Destination 2024/12/13 05:35:27 DEBUG : file3.txt: Need to transfer - File not found at Destination 2024/12/13 05:35:27 DEBUG : file4.txt: Need to transfer - File not found at Destination 2024/12/13 05:35:27 DEBUG : file5.txt: Need to transfer - File not found at Destination 2024/12/13 05:35:27 DEBUG : file6.txt: Need to transfer - File not found at Destination 2024/12/13 05:35:27 DEBUG : file7.txt: Need to transfer - File not found at Destination 2024/12/13 05:35:27 DEBUG : file8.txt: Need to transfer - File not found at Destination 2024/12/13 05:35:27 DEBUG : PikPak root 'rclone-test-gohirin9kelu/053521ya/nomodtime/path1': Waiting for checks to finish 2024/12/13 05:35:27 DEBUG : PikPak root 'rclone-test-gohirin9kelu/053521ya/nomodtime/path1': Waiting for transfers to finish 2024/12/13 05:35:28 DEBUG : file2.txt: gcid = DA39A3EE5E6B4B0D3255BFEF95601890AFD80709 2024/12/13 05:35:28 DEBUG : file3.txt: gcid = DA39A3EE5E6B4B0D3255BFEF95601890AFD80709 2024/12/13 05:35:28 DEBUG : file1.txt: gcid = DA39A3EE5E6B4B0D3255BFEF95601890AFD80709 2024/12/13 05:35:29 DEBUG : file3.txt: Dst hash empty - aborting Src hash check 2024/12/13 05:35:29 INFO : file3.txt: Copied (new) 2024/12/13 05:35:29 DEBUG : file1.txt: Dst hash empty - aborting Src hash check 2024/12/13 05:35:29 INFO : file1.txt: Copied (new) 2024/12/13 05:35:29 DEBUG : file4.txt: gcid = DA39A3EE5E6B4B0D3255BFEF95601890AFD80709 2024/12/13 05:35:29 DEBUG : file5.txt: gcid = DA39A3EE5E6B4B0D3255BFEF95601890AFD80709 2024/12/13 05:35:29 DEBUG : file4.txt: Dst hash empty - aborting Src hash check 2024/12/13 05:35:29 INFO : file4.txt: Copied (new) 2024/12/13 05:35:29 DEBUG : pacer: low level retry 1/10 (error Error "captcha_invalid" (9): Verification code is invalid) 2024/12/13 05:35:29 DEBUG : pacer: Rate limited, increasing sleep to 200ms 2024/12/13 05:35:30 DEBUG : pacer: Reducing sleep to 150ms 2024/12/13 05:35:30 DEBUG : RCLONE_TEST: gcid = 8BF352601041F4EA59E99D4A6D11888FA9F0E58E 2024/12/13 05:35:30 DEBUG : Couldn't decode error response: invalid character '<' looking for beginning of value 2024/12/13 05:35:30 DEBUG : pacer: Reducing sleep to 112.5ms 2024/12/13 05:35:30 ERROR : file2.txt: Failed to copy: failed to create a new file: couldn't get captcha token: failed to retrieve captcha token from api: Error "502 Bad Gateway" (502) 2024/12/13 05:35:30 ERROR : Cancelling sync due to fatal error: failed to create a new file: couldn't get captcha token: failed to retrieve captcha token from api: Error "502 Bad Gateway" (502) 2024/12/13 05:35:30 DEBUG : pacer: low level retry 1/10 (error Error "captcha_invalid" (9): Verification code is invalid) 2024/12/13 05:35:30 DEBUG : pacer: Rate limited, increasing sleep to 225ms 2024/12/13 05:35:30 DEBUG : pacer: Reducing sleep to 168.75ms 2024/12/13 05:35:30 ERROR : file6.txt: Failed to copy: couldn't list files: Get "https://api-drive.mypikpak.com/drive/v1/files?filters=%7B%22phase%22%3A%7B%22eq%22%3A%22PHASE_TYPE_COMPLETE%22%7D%2C%22trashed%22%3A%7B%22eq%22%3Afalse%7D%2C%22kind%22%3A%7B%22eq%22%3A%22drive%23file%22%7D%7D&limit=500&page_token=&parent_id=VODyVwd_WNriqQM_pMyZL4pIo1&thumbnail_size=SIZE_MEDIUM&with_audit=true": context canceled 2024/12/13 05:35:31 DEBUG : Saving config "captcha_token" in section "TestPikPak" of the config file 2024/12/13 05:35:31 DEBUG : pacer: Reducing sleep to 126.5625ms 2024/12/13 05:35:31 ERROR : RCLONE_TEST: Failed to copy: failed to create a new file: Post "https://api-drive.mypikpak.com/drive/v1/files": context canceled 2024/12/13 05:35:31 DEBUG : pacer: Reducing sleep to 100ms 2024/12/13 05:35:31 ERROR : file5.txt: Failed to copy: failed to create a new file: Post "https://api-drive.mypikpak.com/drive/v1/files": context canceled bisync_test.go:1932: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/cmd/bisync/bisync_test.go:1932 /home/rclone/go/src/github.com/rclone/rclone/cmd/bisync/bisync_test.go:456 /home/rclone/go/src/github.com/rclone/rclone/cmd/bisync/bisync_test.go:356 Error: Received unexpected error: failed to create a new file: couldn't get captcha token: failed to retrieve captcha token from api: Error "502 Bad Gateway" (502) Test: TestBisyncRemoteLocal/nomodtime Messages: setting up path1 2024/12/13 05:35:31 NOTICE: checking Path1 PikPak root 'rclone-test-gohirin9kelu/053521ya/nomodtime/path1' fstest.go:292: Sleeping for 1s for list eventual consistency: 1/3 fstest.go:295: Flushing the directory cache fstest.go:292: Sleeping for 2s for list eventual consistency: 2/3 fstest.go:295: Flushing the directory cache fstest.go:292: Sleeping for 4s for list eventual consistency: 3/3 fstest.go:295: Flushing the directory cache fstest.go:299: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:299 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:332 /home/rclone/go/src/github.com/rclone/rclone/cmd/bisync/bisync_test.go:458 /home/rclone/go/src/github.com/rclone/rclone/cmd/bisync/bisync_test.go:356 Error: Should be true Test: TestBisyncRemoteLocal/nomodtime Messages: listing wrong, want RCLONE_TEST (109), file1.txt (0), file2.txt (0), file3.txt (0), file4.txt (0), file5.txt (0), file6.txt (0), file7.txt (0), file8.txt (0) got file1.txt (0), file3.txt (0), file4.txt (0) fstest.go:197: Not found "RCLONE_TEST" fstest.go:197: Not found "file2.txt" fstest.go:197: Not found "file5.txt" fstest.go:197: Not found "file6.txt" fstest.go:197: Not found "file7.txt" fstest.go:197: Not found "file8.txt" fstest.go:200: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:200 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:304 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:332 /home/rclone/go/src/github.com/rclone/rclone/cmd/bisync/bisync_test.go:458 /home/rclone/go/src/github.com/rclone/rclone/cmd/bisync/bisync_test.go:356 Error: Not equal: expected: 0 actual : 6 Test: TestBisyncRemoteLocal/nomodtime Messages: 6 objects not found 2024/12/13 05:35:41 DEBUG : RCLONE_TEST: Need to transfer - File not found at Destination 2024/12/13 05:35:41 DEBUG : file1.txt: Need to transfer - File not found at Destination 2024/12/13 05:35:41 DEBUG : file2.txt: Need to transfer - File not found at Destination 2024/12/13 05:35:41 DEBUG : file3.txt: Need to transfer - File not found at Destination 2024/12/13 05:35:41 DEBUG : file4.txt: Need to transfer - File not found at Destination 2024/12/13 05:35:41 DEBUG : file5.txt: Need to transfer - File not found at Destination 2024/12/13 05:35:41 DEBUG : file6.txt: Need to transfer - File not found at Destination 2024/12/13 05:35:41 DEBUG : file7.txt: Need to transfer - File not found at Destination 2024/12/13 05:35:41 DEBUG : file8.txt: Need to transfer - File not found at Destination 2024/12/13 05:35:41 DEBUG : Local file system at /tmp/053521ya/nomodtime/path2: Waiting for checks to finish 2024/12/13 05:35:41 DEBUG : Local file system at /tmp/053521ya/nomodtime/path2: Waiting for transfers to finish 2024/12/13 05:35:41 DEBUG : file2.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2024/12/13 05:35:41 DEBUG : file1.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2024/12/13 05:35:41 DEBUG : file3.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2024/12/13 05:35:41 DEBUG : file1.txt.5028a97.partial: renamed to: file1.txt 2024/12/13 05:35:41 INFO : file1.txt: Copied (new) 2024/12/13 05:35:41 DEBUG : file2.txt.5028a97.partial: renamed to: file2.txt 2024/12/13 05:35:41 INFO : file2.txt: Copied (new) 2024/12/13 05:35:41 DEBUG : file3.txt.5028a97.partial: renamed to: file3.txt 2024/12/13 05:35:41 INFO : file3.txt: Copied (new) 2024/12/13 05:35:41 DEBUG : file4.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2024/12/13 05:35:41 DEBUG : file4.txt.5028a97.partial: renamed to: file4.txt 2024/12/13 05:35:41 DEBUG : file5.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2024/12/13 05:35:41 INFO : file4.txt: Copied (new) 2024/12/13 05:35:41 DEBUG : file5.txt.5028a97.partial: renamed to: file5.txt 2024/12/13 05:35:41 INFO : file5.txt: Copied (new) 2024/12/13 05:35:41 DEBUG : file6.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2024/12/13 05:35:41 DEBUG : file7.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2024/12/13 05:35:41 DEBUG : RCLONE_TEST: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK 2024/12/13 05:35:41 DEBUG : file8.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2024/12/13 05:35:41 DEBUG : file6.txt.5028a97.partial: renamed to: file6.txt 2024/12/13 05:35:41 INFO : file6.txt: Copied (new) 2024/12/13 05:35:41 DEBUG : file7.txt.5028a97.partial: renamed to: file7.txt 2024/12/13 05:35:41 INFO : file7.txt: Copied (new) 2024/12/13 05:35:41 DEBUG : RCLONE_TEST.cf9a93ac.partial: renamed to: RCLONE_TEST 2024/12/13 05:35:41 INFO : RCLONE_TEST: Copied (new) 2024/12/13 05:35:41 DEBUG : file8.txt.5028a97.partial: renamed to: file8.txt 2024/12/13 05:35:41 INFO : file8.txt: Copied (new) 2024/12/13 05:35:41 NOTICE: checking path2 Local file system at /tmp/053521ya/nomodtime/path2 2024/12/13 05:35:41 NOTICE: (01) : test changes 2024/12/13 05:35:41 NOTICE: (02) : test initial bisync 2024/12/13 05:35:41 NOTICE: (03) : bisync resync nomodtime panic: test timed out after 1h0m0s running tests: TestBisyncRemoteLocal (1h0m0s) TestBisyncRemoteLocal/nomodtime (59m58s) goroutine 1536 [running]: testing.(*M).startAlarm.func1() /usr/local/go/src/testing/testing.go:2366 +0x385 created by time.goFunc /usr/local/go/src/time/sleep.go:177 +0x2d goroutine 1 [chan receive, 60 minutes]: testing.(*T).Run(0xc000542340, {0x247a760?, 0x0?}, 0x25a5688) /usr/local/go/src/testing/testing.go:1750 +0x3ab testing.runTests.func1(0xc000542340) /usr/local/go/src/testing/testing.go:2161 +0x37 testing.tRunner(0xc000542340, 0xc000845c00) /usr/local/go/src/testing/testing.go:1689 +0xfb testing.runTests(0xc000422618, {0x3a78c20, 0x3, 0x3}, {0x3b192f8?, 0xc000845c48?, 0x3ab59a0?}) /usr/local/go/src/testing/testing.go:2159 +0x445 testing.(*M).Run(0xc0004ed2c0) /usr/local/go/src/testing/testing.go:2027 +0x68b github.com/rclone/rclone/fstest.TestMain(0xc0004ed2c0) /home/rclone/go/src/github.com/rclone/rclone/fstest/run.go:69 +0xa5 github.com/rclone/rclone/cmd/bisync_test.TestMain(...) /home/rclone/go/src/github.com/rclone/rclone/cmd/bisync/bisync_test.go:227 main.main() _testmain.go:55 +0x196 goroutine 8 [select]: go.opencensus.io/stats/view.(*worker).start(0xc000460d00) /home/rclone/go/pkg/mod/go.opencensus.io@v0.24.0/stats/view/worker.go:292 +0x9f created by go.opencensus.io/stats/view.init.0 in goroutine 1 /home/rclone/go/pkg/mod/go.opencensus.io@v0.24.0/stats/view/worker.go:34 +0x8d goroutine 12 [syscall, 60 minutes]: os/signal.signal_recv() /usr/local/go/src/runtime/sigqueue.go:152 +0x29 os/signal.loop() /usr/local/go/src/os/signal/signal_unix.go:23 +0x13 created by os/signal.Notify.func1.1 in goroutine 1 /usr/local/go/src/os/signal/signal.go:151 +0x1f goroutine 13 [chan receive, 60 minutes]: github.com/rclone/rclone/fs/accounting.(*tokenBucket).startSignalHandler.func1() /home/rclone/go/src/github.com/rclone/rclone/fs/accounting/accounting_unix.go:24 +0x27 created by github.com/rclone/rclone/fs/accounting.(*tokenBucket).startSignalHandler in goroutine 1 /home/rclone/go/src/github.com/rclone/rclone/fs/accounting/accounting_unix.go:21 +0xab goroutine 53 [chan receive, 60 minutes]: testing.(*T).Run(0xc0005424e0, {0xc0005c9d25?, 0x2838a10?}, 0xc0008ef0e0) /usr/local/go/src/testing/testing.go:1750 +0x3ab github.com/rclone/rclone/cmd/bisync_test.testBisync(0xc0005424e0, {0xc00032a0f0, 0x23}, {0x0, 0x0}) /home/rclone/go/src/github.com/rclone/rclone/cmd/bisync/bisync_test.go:349 +0x967 github.com/rclone/rclone/cmd/bisync_test.TestBisyncRemoteLocal(0xc0005424e0) /home/rclone/go/src/github.com/rclone/rclone/cmd/bisync/bisync_test.go:239 +0x16a testing.tRunner(0xc0005424e0, 0x25a5688) /usr/local/go/src/testing/testing.go:1689 +0xfb created by testing.(*T).Run in goroutine 1 /usr/local/go/src/testing/testing.go:1742 +0x390 goroutine 74 [chan receive, 60 minutes]: github.com/rclone/rclone/fs/accounting.(*tokenBucket).startSignalHandler.func1() /home/rclone/go/src/github.com/rclone/rclone/fs/accounting/accounting_unix.go:24 +0x27 created by github.com/rclone/rclone/fs/accounting.(*tokenBucket).startSignalHandler in goroutine 53 /home/rclone/go/src/github.com/rclone/rclone/fs/accounting/accounting_unix.go:21 +0xab goroutine 60 [chan receive, 60 minutes]: github.com/rclone/rclone/lib/atexit.Register.func1.1() /home/rclone/go/src/github.com/rclone/rclone/lib/atexit/atexit.go:45 +0x29 created by github.com/rclone/rclone/lib/atexit.Register.func1 in goroutine 53 /home/rclone/go/src/github.com/rclone/rclone/lib/atexit/atexit.go:44 +0x68 goroutine 61 [semacquire, 39 minutes]: sync.runtime_Semacquire(0xa859fe?) /usr/local/go/src/runtime/sema.go:62 +0x25 sync.(*WaitGroup).Wait(0xc0008efa07?) /usr/local/go/src/sync/waitgroup.go:116 +0x48 github.com/rclone/rclone/fs/sync.(*syncCopyMove).stopTransfers(0xc000893408) /home/rclone/go/src/github.com/rclone/rclone/fs/sync/sync.go:539 +0x75 github.com/rclone/rclone/fs/sync.(*syncCopyMove).run(0xc000893408) /home/rclone/go/src/github.com/rclone/rclone/fs/sync/sync.go:974 +0x332 github.com/rclone/rclone/fs/sync.runSyncCopyMove({0x286d528, 0xc000745980}, {0x2882568, 0xc0006ea1e0}, {0x2882d48, 0xc000390300}, 0x0, 0x0, 0x0, 0x0) /home/rclone/go/src/github.com/rclone/rclone/fs/sync/sync.go:1361 +0x20e github.com/rclone/rclone/fs/sync.CopyDir(...) /home/rclone/go/src/github.com/rclone/rclone/fs/sync/sync.go:1372 github.com/rclone/rclone/cmd/bisync.(*bisyncRun).resyncDir(0xc000390b00, {0x286d528?, 0xc000850570?}, {0x2882d48, 0xc000390300}, {0x2882568, 0xc0006ea1e0}) /home/rclone/go/src/github.com/rclone/rclone/cmd/bisync/queue.go:294 +0x9b github.com/rclone/rclone/cmd/bisync.(*bisyncRun).resync(0xc000390b00, {0x286d528?, 0xc000850000?}, {0x286d528, 0xc000850000}) /home/rclone/go/src/github.com/rclone/rclone/cmd/bisync/resync.go:126 +0x892 github.com/rclone/rclone/cmd/bisync.(*bisyncRun).runLocked(0xc000390b00, {0x286d528, 0xc000850000}) /home/rclone/go/src/github.com/rclone/rclone/cmd/bisync/operations.go:265 +0x23b4 github.com/rclone/rclone/cmd/bisync.Bisync({0x286d528, 0xc000850000}, {0x2882d48, 0xc000390300}, {0x2882568, 0xc0006ea1e0}, 0xc00006b2a0) /home/rclone/go/src/github.com/rclone/rclone/cmd/bisync/operations.go:172 +0x759 github.com/rclone/rclone/cmd/bisync_test.(*bisyncTest).runBisync.func3() /home/rclone/go/src/github.com/rclone/rclone/cmd/bisync/bisync_test.go:1148 +0x38 github.com/rclone/rclone/cmd/bisync/bilib.CaptureOutput(0xc00006b3b8) /home/rclone/go/src/github.com/rclone/rclone/cmd/bisync/bilib/output.go:18 +0x9a github.com/rclone/rclone/cmd/bisync_test.(*bisyncTest).runBisync(0xc000583c00, {0x286d480?, 0x3b18da0?}, {0xc000798310, 0x2, 0x0?}) /home/rclone/go/src/github.com/rclone/rclone/cmd/bisync/bisync_test.go:1147 +0xf7b github.com/rclone/rclone/cmd/bisync_test.(*bisyncTest).runTestStep(0xc000583c00, {0x286d480, 0x3b18da0}, {0xc00034c270, 0x17}) /home/rclone/go/src/github.com/rclone/rclone/cmd/bisync/bisync_test.go:745 +0x3b2 github.com/rclone/rclone/cmd/bisync_test.(*bisyncTest).runTestCase(0xc000583c00, {0x286d480, 0x3b18da0}, 0x603?, {0xc0005c9d25?, 0x340eb70?}) /home/rclone/go/src/github.com/rclone/rclone/cmd/bisync/bisync_test.go:492 +0x152e github.com/rclone/rclone/cmd/bisync_test.testBisync.func4(0xc000542b60) /home/rclone/go/src/github.com/rclone/rclone/cmd/bisync/bisync_test.go:356 +0x225 testing.tRunner(0xc000542b60, 0xc0008ef0e0) /usr/local/go/src/testing/testing.go:1689 +0xfb created by testing.(*T).Run in goroutine 53 /usr/local/go/src/testing/testing.go:1742 +0x390 goroutine 811 [chan receive, 59 minutes]: github.com/rclone/rclone/fs/march.(*March).Run.func2() /home/rclone/go/src/github.com/rclone/rclone/fs/march/march.go:211 +0x3c created by github.com/rclone/rclone/fs/march.(*March).Run in goroutine 61 /home/rclone/go/src/github.com/rclone/rclone/fs/march/march.go:209 +0x378 goroutine 799 [select]: net/http.(*Transport).getConn(0xc0004a97c0, 0xc0006c2040, {{}, 0x0, {0xc00097a700, 0x5}, {0xc0002fa020, 0x1d}, 0x0}) /usr/local/go/src/net/http/transport.go:1406 +0x5a5 net/http.(*Transport).roundTrip(0xc0004a97c0, 0xc0005ac6c0) /usr/local/go/src/net/http/transport.go:595 +0x73a net/http.(*Transport).RoundTrip(...) /usr/local/go/src/net/http/roundtrip.go:17 github.com/rclone/rclone/fs/fshttp.(*Transport).RoundTrip(0xc0003d44d0, 0xc0005ac6c0) /home/rclone/go/src/github.com/rclone/rclone/fs/fshttp/http.go:352 +0x345 golang.org/x/oauth2.(*Transport).RoundTrip(0xc000498fa0, 0xc0002c8000) /home/rclone/go/pkg/mod/golang.org/x/oauth2@v0.24.0/transport.go:55 +0x3de net/http.send(0xc0002c8000, {0x284b0a0, 0xc000498fa0}, {0x1?, 0x3b18da0?, 0x0?}) /usr/local/go/src/net/http/client.go:259 +0x5e4 net/http.(*Client).send(0xc000704cf0, 0xc0002c8000, {0x0?, 0x0?, 0x0?}) /usr/local/go/src/net/http/client.go:180 +0x98 net/http.(*Client).do(0xc000704cf0, 0xc0002c8000) /usr/local/go/src/net/http/client.go:724 +0x8dc net/http.(*Client).Do(...) /usr/local/go/src/net/http/client.go:590 github.com/rclone/rclone/backend/pikpak.(*Object).httpResponse.func1() /home/rclone/go/src/github.com/rclone/rclone/backend/pikpak/pikpak.go:1720 +0x52 github.com/rclone/rclone/fs.pacerInvoker(0xa, 0xa, 0x2848160?) /home/rclone/go/src/github.com/rclone/rclone/fs/pacer.go:88 +0x32 github.com/rclone/rclone/lib/pacer.(*Pacer).call(0xc00070c1e0, 0xc000638140, 0xa) /home/rclone/go/src/github.com/rclone/rclone/lib/pacer/pacer.go:197 +0x7c github.com/rclone/rclone/lib/pacer.(*Pacer).Call(0xc00070c1e0, 0xc000638140) /home/rclone/go/src/github.com/rclone/rclone/lib/pacer/pacer.go:216 +0x92 github.com/rclone/rclone/backend/pikpak.(*Object).httpResponse(0xc000954b40, {0x286d560, 0xc0008efb30}, {0xc00097a700, 0x33a}, {0x244f978, 0x3}, {0xc000016210, 0x1, 0x1}) /home/rclone/go/src/github.com/rclone/rclone/backend/pikpak/pikpak.go:1719 +0x2af github.com/rclone/rclone/backend/pikpak.(*Object).open(0xc000954b40?, {0x286d560?, 0xc0008efb30?}, {0xc00097a700?, 0x10?}, {0xc000016210?, 0xc000016210?, 0x0?}) /home/rclone/go/src/github.com/rclone/rclone/backend/pikpak/pikpak.go:1731 +0x4f github.com/rclone/rclone/backend/pikpak.(*Object).Open(0xc000954b40, {0x286d560, 0xc0008efb30}, {0xc000016210, 0x1, 0x1}) /home/rclone/go/src/github.com/rclone/rclone/backend/pikpak/pikpak.go:1750 +0x131 github.com/rclone/rclone/fs/operations.(*ReOpen).open(0xc000a26000) /home/rclone/go/src/github.com/rclone/rclone/fs/operations/reopen.go:147 +0x109 github.com/rclone/rclone/fs/operations.NewReOpen({0x286d560, 0xc0008efb30}, {0x2882db8, 0xc000954b40}, 0xa, {0xc000016200, 0x1, 0x1}) /home/rclone/go/src/github.com/rclone/rclone/fs/operations/reopen.go:102 +0x50b github.com/rclone/rclone/fs/operations.Open({0x286d560, 0xc0008efb30}, {0x2882db8, 0xc000954b40}, {0xc000016200, 0x1, 0x1}) /home/rclone/go/src/github.com/rclone/rclone/fs/operations/reopen.go:124 +0x6b github.com/rclone/rclone/fs/operations.(*copy).manualCopy(0xc00011c5a0, {0x286d560, 0xc0008efb30}) /home/rclone/go/src/github.com/rclone/rclone/fs/operations/copy.go:261 +0x4e5 github.com/rclone/rclone/fs/operations.(*copy).copy(0xc00011c5a0, {0x286d560, 0xc0008efb30}) /home/rclone/go/src/github.com/rclone/rclone/fs/operations/copy.go:310 +0x176 github.com/rclone/rclone/fs/operations.Copy({0x286d560, 0xc0008efb30}, {0x2882568, 0xc0006ea1e0}, {0x28825d8, 0xc00070d560}, {0xc0007916c0, 0xb}, {0x2882db8, 0xc000954b40}) /home/rclone/go/src/github.com/rclone/rclone/fs/operations/copy.go:412 +0x493 github.com/rclone/rclone/fs/sync.(*syncCopyMove).pairCopyOrMove(0xc000893408, {0x286d560, 0xc0008efb30}, 0xc0008efa90, {0x2882568, 0xc0006ea1e0}, 0x0, 0x0?) /home/rclone/go/src/github.com/rclone/rclone/fs/sync/sync.go:501 +0x205 created by github.com/rclone/rclone/fs/sync.(*syncCopyMove).startTransfers in goroutine 61 /home/rclone/go/src/github.com/rclone/rclone/fs/sync/sync.go:531 +0x6b goroutine 1535 [select]: net.(*netFD).connect.func2() /usr/local/go/src/net/fd_unix.go:118 +0x7a created by net.(*netFD).connect in goroutine 1574 /usr/local/go/src/net/fd_unix.go:117 +0x37c goroutine 1574 [IO wait]: internal/poll.runtime_pollWait(0x7f37c1553b18, 0x77) /usr/local/go/src/runtime/netpoll.go:345 +0x85 internal/poll.(*pollDesc).wait(0xc000626400?, 0x0?, 0x0) /usr/local/go/src/internal/poll/fd_poll_runtime.go:84 +0x27 internal/poll.(*pollDesc).waitWrite(...) /usr/local/go/src/internal/poll/fd_poll_runtime.go:93 internal/poll.(*FD).WaitWrite(...) /usr/local/go/src/internal/poll/fd_unix.go:683 net.(*netFD).connect(0xc000626400, {0x286d5d0, 0xc0002f0150}, {0xc00064b198?, 0x413fdb?}, {0x2847d20?, 0xc000736200?}) /usr/local/go/src/net/fd_unix.go:141 +0x70b net.(*netFD).dial(0xc000626400, {0x286d5d0, 0xc0002f0150}, {0x2873c18?, 0x0?}, {0x2873c18, 0xc000792540}, 0x90?) /usr/local/go/src/net/sock_posix.go:124 +0x3bc net.socket({0x286d5d0, 0xc0002f0150}, {0x244f95a, 0x3}, 0x2, 0x1, 0x41cefe?, 0x0, {0x2873c18, 0x0}, ...) /usr/local/go/src/net/sock_posix.go:70 +0x29b net.internetSocket({0x286d5d0, 0xc0002f0150}, {0x244f95a, 0x3}, {0x2873c18, 0x0}, {0x2873c18, 0xc000792540}, 0x1, 0x0, ...) /usr/local/go/src/net/ipsock_posix.go:154 +0xf8 net.(*sysDialer).doDialTCPProto(0xc0006ea280, {0x286d5d0, 0xc0002f0150}, 0x0, 0xc000792540, 0x0) /usr/local/go/src/net/tcpsock_posix.go:85 +0xec net.(*sysDialer).doDialTCP(...) /usr/local/go/src/net/tcpsock_posix.go:75 net.(*sysDialer).dialTCP(0x10?, {0x286d5d0?, 0xc0002f0150?}, 0xc00064b4a0?, 0x53b47b?) /usr/local/go/src/net/tcpsock_posix.go:71 +0x65 net.(*sysDialer).dialSingle(0xc0006ea280, {0x286d5d0, 0xc0002f0150}, {0x285a720, 0xc000792540}) /usr/local/go/src/net/dial.go:651 +0x27d net.(*sysDialer).dialSerial(0xc0006ea280, {0x286d5d0, 0xc000464070}, {0xc0009742c0?, 0x3, 0xc0009742c0?}) /usr/local/go/src/net/dial.go:616 +0x24e net.(*sysDialer).dialParallel(0xc000974280?, {0x286d5d0?, 0xc000464070?}, {0xc0009742c0?, 0xc000464070?, 0x245048b?}, {0x0?, 0x244f95a?, 0xc000680018?}) /usr/local/go/src/net/dial.go:517 +0x3b4 net.(*Dialer).DialContext(0xc0001d8080, {0x286d560, 0xc0008efb30}, {0x244f95a, 0x3}, {0xc0002fa020, 0x1d}) /usr/local/go/src/net/dial.go:508 +0x69a github.com/rclone/rclone/fs/fshttp.(*Dialer).DialContext(0xc0001d8080, {0x286d560, 0xc0008efb30}, {0x244f95a?, 0x60?}, {0xc0002fa020, 0x1d}) /home/rclone/go/src/github.com/rclone/rclone/fs/fshttp/dialer.go:62 +0x125 github.com/rclone/rclone/fs/fshttp.NewTransportCustom.func1({0x286d560, 0xc0008efb30}, {0x244f95a, 0x3}, {0xc0002fa020, 0x1d}) /home/rclone/go/src/github.com/rclone/rclone/fs/fshttp/http.go:109 +0x65 net/http.(*Transport).dial(0x2?, {0x286d560?, 0xc0008efb30?}, {0x244f95a?, 0x5?}, {0xc0002fa020?, 0x0?}) /usr/local/go/src/net/http/transport.go:1187 +0xd2 net/http.(*Transport).dialConn(0xc0004a97c0, {0x286d560, 0xc0008efb30}, {{}, 0x0, {0xc00097a700, 0x5}, {0xc0002fa020, 0x1d}, 0x0}) /usr/local/go/src/net/http/transport.go:1647 +0x7e8 net/http.(*Transport).dialConnFor(0xc0004a97c0, 0xc0004900b0) /usr/local/go/src/net/http/transport.go:1484 +0xca created by net/http.(*Transport).queueForDial in goroutine 799 /usr/local/go/src/net/http/transport.go:1449 +0x3c9 "./bisync.test -test.v -test.timeout 1h0m0s -remote TestPikPak: -verbose -test.run '^TestBisyncLocalRemote$/^nomodtime$|^TestBisyncRemoteLocal$/^nomodtime$'" - Finished ERROR in 1h0m1.531096994s (try 2/5): exit status 2: Failed [TestBisyncRemoteLocal/nomodtime TestBisyncLocalRemote/nomodtime]