"./operations.test -test.v -test.timeout 1h0m0s -remote TestCompressDrive: -verbose" - Starting (try 1/5) 2022/04/15 05:32:21 DEBUG : Creating backend with remote "TestCompressDrive:rclone-test-zefocac9wijidas2dixiqik0" 2022/04/15 05:32:21 DEBUG : Using config file from "/home/rclone/.rclone.conf" 2022/04/15 05:32:22 DEBUG : Creating backend with remote "/tmp/rclone760555521" === RUN TestDoMultiThreadCopy --- PASS: TestDoMultiThreadCopy (0.00s) === RUN TestMultithreadCalculateChunks === RUN TestMultithreadCalculateChunks/{size:1_streams:10_wantPartSize:65536_wantStreams:1} === RUN TestMultithreadCalculateChunks/{size:1048576_streams:1_wantPartSize:1048576_wantStreams:1} === RUN TestMultithreadCalculateChunks/{size:1048576_streams:2_wantPartSize:524288_wantStreams:2} === RUN TestMultithreadCalculateChunks/{size:1048577_streams:2_wantPartSize:589824_wantStreams:2} === RUN TestMultithreadCalculateChunks/{size:1048575_streams:2_wantPartSize:524288_wantStreams:2} --- PASS: TestMultithreadCalculateChunks (0.00s) --- PASS: TestMultithreadCalculateChunks/{size:1_streams:10_wantPartSize:65536_wantStreams:1} (0.00s) --- PASS: TestMultithreadCalculateChunks/{size:1048576_streams:1_wantPartSize:1048576_wantStreams:1} (0.00s) --- PASS: TestMultithreadCalculateChunks/{size:1048576_streams:2_wantPartSize:524288_wantStreams:2} (0.00s) --- PASS: TestMultithreadCalculateChunks/{size:1048577_streams:2_wantPartSize:589824_wantStreams:2} (0.00s) --- PASS: TestMultithreadCalculateChunks/{size:1048575_streams:2_wantPartSize:524288_wantStreams:2} (0.00s) === RUN TestMultithreadCopy run.go:181: Remote "Compressed: TestCompressDrive:rclone-test-zefocac9wijidas2dixiqik0", Local "Local file system at /tmp/rclone760555521", Modify Window "1ms" === RUN TestMultithreadCopy/{size:131071_streams:2} 2022/04/15 05:32:23 DEBUG : pacer: low level retry 1/10 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded) 2022/04/15 05:32:23 DEBUG : pacer: Rate limited, increasing sleep to 1.716635432s 2022/04/15 05:32:23 DEBUG : pacer: Reducing sleep to 0s 2022/04/15 05:32:31 DEBUG : file1: Starting multi-thread copy with 2 parts of size 64Ki 2022/04/15 05:32:31 DEBUG : file1: multi-thread copy: stream 2/2 (65536-131071) size 63.999Ki starting 2022/04/15 05:32:31 DEBUG : file1: multi-thread copy: stream 1/2 (0-65536) size 64Ki starting 2022/04/15 05:32:31 DEBUG : file1.__8BAAAAAAA.gz: ChunkedReader.RangeSeek from -1 to 10 length -1 2022/04/15 05:32:31 DEBUG : file1.__8BAAAAAAA.gz: ChunkedReader.Read at -1 length 4096 chunkOffset 0 chunkSize 262144 2022/04/15 05:32:31 DEBUG : file1.__8BAAAAAAA.gz: ChunkedReader.openRange at 0 length 262144 2022/04/15 05:32:31 DEBUG : file1.__8BAAAAAAA.gz: ChunkedReader.Read at -1 length 4096 chunkOffset 10 chunkSize 262144 2022/04/15 05:32:31 DEBUG : file1.__8BAAAAAAA.gz: ChunkedReader.openRange at 10 length 262144 2022/04/15 05:32:31 DEBUG : file1.__8BAAAAAAA.gz: ChunkedReader.Read at 4096 length 4096 chunkOffset 0 chunkSize 262144 2022/04/15 05:32:31 DEBUG : file1.__8BAAAAAAA.gz: ChunkedReader.Read at 8192 length 4096 chunkOffset 0 chunkSize 262144 2022/04/15 05:32:31 DEBUG : file1.__8BAAAAAAA.gz: ChunkedReader.Read at 12288 length 4096 chunkOffset 0 chunkSize 262144 2022/04/15 05:32:31 DEBUG : file1.__8BAAAAAAA.gz: ChunkedReader.Read at 16384 length 4096 chunkOffset 0 chunkSize 262144 2022/04/15 05:32:31 DEBUG : file1.__8BAAAAAAA.gz: ChunkedReader.Read at 20480 length 4096 chunkOffset 0 chunkSize 262144 2022/04/15 05:32:31 DEBUG : file1.__8BAAAAAAA.gz: ChunkedReader.Read at 24576 length 4096 chunkOffset 0 chunkSize 262144 2022/04/15 05:32:31 DEBUG : file1.__8BAAAAAAA.gz: ChunkedReader.Read at 28672 length 4096 chunkOffset 0 chunkSize 262144 2022/04/15 05:32:31 DEBUG : file1.__8BAAAAAAA.gz: ChunkedReader.Read at 32768 length 4096 chunkOffset 0 chunkSize 262144 2022/04/15 05:32:31 DEBUG : file1.__8BAAAAAAA.gz: ChunkedReader.Read at 36864 length 4096 chunkOffset 0 chunkSize 262144 2022/04/15 05:32:31 DEBUG : file1.__8BAAAAAAA.gz: ChunkedReader.Read at 40960 length 4096 chunkOffset 0 chunkSize 262144 2022/04/15 05:32:31 DEBUG : file1.__8BAAAAAAA.gz: ChunkedReader.Read at 45056 length 4096 chunkOffset 0 chunkSize 262144 2022/04/15 05:32:31 DEBUG : file1.__8BAAAAAAA.gz: ChunkedReader.Read at 49152 length 4096 chunkOffset 0 chunkSize 262144 2022/04/15 05:32:31 DEBUG : file1.__8BAAAAAAA.gz: ChunkedReader.Read at 53248 length 4096 chunkOffset 0 chunkSize 262144 2022/04/15 05:32:31 DEBUG : file1.__8BAAAAAAA.gz: ChunkedReader.Read at 57344 length 4096 chunkOffset 0 chunkSize 262144 2022/04/15 05:32:31 DEBUG : file1.__8BAAAAAAA.gz: ChunkedReader.Read at 61440 length 4096 chunkOffset 0 chunkSize 262144 2022/04/15 05:32:31 DEBUG : file1.__8BAAAAAAA.gz: ChunkedReader.Read at 65536 length 4096 chunkOffset 0 chunkSize 262144 2022/04/15 05:32:31 DEBUG : file1.__8BAAAAAAA.gz: ChunkedReader.Read at 69632 length 4096 chunkOffset 0 chunkSize 262144 2022/04/15 05:32:31 DEBUG : file1.__8BAAAAAAA.gz: ChunkedReader.Read at 73728 length 4096 chunkOffset 0 chunkSize 262144 2022/04/15 05:32:31 DEBUG : file1.__8BAAAAAAA.gz: ChunkedReader.Read at 77824 length 4096 chunkOffset 0 chunkSize 262144 2022/04/15 05:32:31 DEBUG : file1: multi-thread copy: stream 1/2 (0-65536) size 64Ki finished 2022/04/15 05:32:32 DEBUG : file1.__8BAAAAAAA.gz: ChunkedReader.Read at 4106 length 4096 chunkOffset 10 chunkSize 262144 2022/04/15 05:32:32 DEBUG : file1.__8BAAAAAAA.gz: ChunkedReader.Read at 8202 length 4096 chunkOffset 10 chunkSize 262144 2022/04/15 05:32:32 DEBUG : file1.__8BAAAAAAA.gz: ChunkedReader.Read at 12298 length 4096 chunkOffset 10 chunkSize 262144 2022/04/15 05:32:32 DEBUG : file1.__8BAAAAAAA.gz: ChunkedReader.Read at 16394 length 4096 chunkOffset 10 chunkSize 262144 2022/04/15 05:32:32 DEBUG : file1.__8BAAAAAAA.gz: ChunkedReader.Read at 20490 length 4096 chunkOffset 10 chunkSize 262144 2022/04/15 05:32:32 DEBUG : file1.__8BAAAAAAA.gz: ChunkedReader.Read at 24586 length 4096 chunkOffset 10 chunkSize 262144 2022/04/15 05:32:32 DEBUG : file1.__8BAAAAAAA.gz: ChunkedReader.Read at 28682 length 4096 chunkOffset 10 chunkSize 262144 2022/04/15 05:32:32 DEBUG : file1.__8BAAAAAAA.gz: ChunkedReader.Read at 32778 length 4096 chunkOffset 10 chunkSize 262144 2022/04/15 05:32:32 DEBUG : file1.__8BAAAAAAA.gz: ChunkedReader.Read at 36874 length 4096 chunkOffset 10 chunkSize 262144 2022/04/15 05:32:32 DEBUG : file1.__8BAAAAAAA.gz: ChunkedReader.Read at 40970 length 4096 chunkOffset 10 chunkSize 262144 2022/04/15 05:32:32 DEBUG : file1.__8BAAAAAAA.gz: ChunkedReader.Read at 45066 length 4096 chunkOffset 10 chunkSize 262144 2022/04/15 05:32:32 DEBUG : file1.__8BAAAAAAA.gz: ChunkedReader.Read at 49162 length 4096 chunkOffset 10 chunkSize 262144 2022/04/15 05:32:32 DEBUG : file1.__8BAAAAAAA.gz: ChunkedReader.Read at 53258 length 4096 chunkOffset 10 chunkSize 262144 2022/04/15 05:32:32 DEBUG : file1.__8BAAAAAAA.gz: ChunkedReader.Read at 57354 length 4096 chunkOffset 10 chunkSize 262144 2022/04/15 05:32:32 DEBUG : file1.__8BAAAAAAA.gz: ChunkedReader.Read at 61450 length 4096 chunkOffset 10 chunkSize 262144 2022/04/15 05:32:32 DEBUG : file1.__8BAAAAAAA.gz: ChunkedReader.Read at 65546 length 4096 chunkOffset 10 chunkSize 262144 2022/04/15 05:32:32 DEBUG : file1.__8BAAAAAAA.gz: ChunkedReader.Read at 69642 length 4096 chunkOffset 10 chunkSize 262144 2022/04/15 05:32:32 DEBUG : file1.__8BAAAAAAA.gz: ChunkedReader.Read at 73738 length 4096 chunkOffset 10 chunkSize 262144 2022/04/15 05:32:32 DEBUG : file1.__8BAAAAAAA.gz: ChunkedReader.Read at 77834 length 4096 chunkOffset 10 chunkSize 262144 2022/04/15 05:32:32 DEBUG : file1: multi-thread copy: stream 2/2 (65536-131071) size 63.999Ki finished 2022/04/15 05:32:32 DEBUG : file1: Finished multi-thread copy with 2 parts of size 64Ki === RUN TestMultithreadCopy/{size:131072_streams:2} 2022/04/15 05:32:35 DEBUG : pacer: low level retry 1/1 (error googleapi: Error 403: User Rate Limit Exceeded. Rate of requests for user exceed configured project quota. You may consider re-evaluating expected per-user traffic to the API and adjust project quota limits accordingly. You may monitor aggregate quota usage and adjust limits in the API Console: https://console.developers.google.com/apis/api/drive.googleapis.com/quotas?project=847840889997, userRateLimitExceeded) 2022/04/15 05:32:35 DEBUG : pacer: Rate limited, increasing sleep to 1.781539553s 2022/04/15 05:32:35 DEBUG : pacer: Reducing sleep to 0s --- FAIL: TestMultithreadCopy (14.46s) --- PASS: TestMultithreadCopy/{size:131071_streams:2} (9.18s) --- FAIL: TestMultithreadCopy/{size:131072_streams:2} (5.28s) panic: runtime error: invalid memory address or nil pointer dereference [recovered] panic: runtime error: invalid memory address or nil pointer dereference [signal SIGSEGV: segmentation violation code=0x1 addr=0x0 pc=0xb82067] goroutine 123 [running]: testing.tRunner.func1.2({0x16a41e0, 0x2a28620}) /usr/local/go/src/testing/testing.go:1209 +0x24e testing.tRunner.func1() /usr/local/go/src/testing/testing.go:1212 +0x218 panic({0x16a41e0, 0x2a28620}) /usr/local/go/src/runtime/panic.go:1038 +0x215 github.com/rclone/rclone/backend/compress.(*Object).Update(0xc000968a50, {0x1d4ca30, 0xc000042058}, {0x1d13fc0, 0xc000963ef0}, {0x1d64ca0, 0xc000968960}, {0x0, 0x0, 0x0}) /home/rclone/go/src/github.com/rclone/rclone/backend/compress/compress.go:1099 +0x2e7 github.com/rclone/rclone/backend/compress.(*Fs).Put(0xc000174100, {0x1d4ca30, 0xc000042058}, {0x1d13fc0, 0xc000963ef0}, {0x1d64ca0, 0xc000968960}, {0x0, 0x0, 0x0}) /home/rclone/go/src/github.com/rclone/rclone/backend/compress/compress.go:698 +0x175 github.com/rclone/rclone/fstest.(*Run).WriteObjectTo(0xc0003abd50, {0x1d4ca30, 0xc000042058}, {0x1d7c518, 0xc000174100}, {0x1965d49, 0x5}, {0xc0008ba000, 0x20000}, {0x1dcd64ff, ...}, ...) /home/rclone/go/src/github.com/rclone/rclone/fstest/run.go:277 +0x432 github.com/rclone/rclone/fstest.(*Run).WriteObject(...) /home/rclone/go/src/github.com/rclone/rclone/fstest/run.go:294 github.com/rclone/rclone/fs/operations.TestMultithreadCopy.func1(0xc000508000) /home/rclone/go/src/github.com/rclone/rclone/fs/operations/multithread_test.go:127 +0x1ba testing.tRunner(0xc000508000, 0xc000963e60) /usr/local/go/src/testing/testing.go:1259 +0x102 created by testing.(*T).Run /usr/local/go/src/testing/testing.go:1306 +0x35a "./operations.test -test.v -test.timeout 1h0m0s -remote TestCompressDrive: -verbose" - Finished ERROR in 15.496433447s (try 1/5): exit status 2: Failed [TestMultithreadCopy/{size:131072_streams:2}]