"./operations.test -test.v -test.timeout 1h0m0s -remote TestSMBKerberosCcache:rclone -verbose -test.run '^(TestCheck|TestCheckDownload|TestCheckSizeOnly|TestCheckSum|TestCheckSumDownload|TestMultithreadCopyAbort|TestParseSumFile)$|^TestMultithreadCopy$/^(upload=false,size=134217728,streams=2|upload=false,size=134217729,streams=2)$'" - Starting (try 2/5) 2025/10/11 04:12:43 DEBUG : Creating backend with remote "TestSMBKerberosCcache:rclone/rclone-test-kehesuv4xefi" 2025/10/11 04:12:43 DEBUG : Using config file from "/home/rclone/.rclone.conf" 2025/10/11 04:12:43 DEBUG : Setting type="smb" for "TestSMBKerberosCcache" from environment variable RCLONE_CONFIG_TESTSMBKERBEROSCCACHE_TYPE 2025/10/11 04:12:43 DEBUG : Setting host="localhost" for "TestSMBKerberosCcache" from environment variable RCLONE_CONFIG_TESTSMBKERBEROSCCACHE_HOST 2025/10/11 04:12:43 DEBUG : Setting port="28637" for "TestSMBKerberosCcache" from environment variable RCLONE_CONFIG_TESTSMBKERBEROSCCACHE_PORT 2025/10/11 04:12:43 DEBUG : Setting use_kerberos="true" for "TestSMBKerberosCcache" from environment variable RCLONE_CONFIG_TESTSMBKERBEROSCCACHE_USE_KERBEROS 2025/10/11 04:12:43 DEBUG : Setting kerberos_ccache="/tmp/rclone_krb5_ccache/ccache" for "TestSMBKerberosCcache" from environment variable RCLONE_CONFIG_TESTSMBKERBEROSCCACHE_KERBEROS_CCACHE 2025/10/11 04:12:43 DEBUG : TestSMBKerberosCcache: detected overridden config - adding "{LaD7k}" suffix to name 2025/10/11 04:12:43 DEBUG : Setting host="localhost" for "TestSMBKerberosCcache" from environment variable RCLONE_CONFIG_TESTSMBKERBEROSCCACHE_HOST 2025/10/11 04:12:43 DEBUG : Setting port="28637" for "TestSMBKerberosCcache" from environment variable RCLONE_CONFIG_TESTSMBKERBEROSCCACHE_PORT 2025/10/11 04:12:43 DEBUG : Setting use_kerberos="true" for "TestSMBKerberosCcache" from environment variable RCLONE_CONFIG_TESTSMBKERBEROSCCACHE_USE_KERBEROS 2025/10/11 04:12:43 DEBUG : Setting kerberos_ccache="/tmp/rclone_krb5_ccache/ccache" for "TestSMBKerberosCcache" from environment variable RCLONE_CONFIG_TESTSMBKERBEROSCCACHE_KERBEROS_CCACHE 2025/10/11 04:12:43 DEBUG : Creating backend with remote "/tmp/rclone3110737893" === RUN TestMultithreadCopy run.go:180: Remote "smb://rclone@localhost:28637/rclone/rclone-test-kehesuv4xefi", Local "Local file system at /tmp/rclone3110737893", Modify Window "1ms" === RUN TestMultithreadCopy/upload=false,size=134217728,streams=2 2025/10/11 04:12:51 DEBUG : test-multithread-copy-false-134217728-2: multi-thread copy: disabling buffering because destination uses OpenWriterAt 2025/10/11 04:12:51 DEBUG : test-multithread-copy-false-134217728-2: multi-thread copy: write buffer set to 131072 2025/10/11 04:12:51 DEBUG : test-multithread-copy-false-134217728-2: multi-thread copy: using backend concurrency of 4 instead of --multi-thread-streams 2 2025/10/11 04:12:51 DEBUG : test-multithread-copy-false-134217728-2: multi-thread copy: number of streams 4 was bigger than number of chunks 2 2025/10/11 04:12:51 DEBUG : test-multithread-copy-false-134217728-2: Starting multi-thread copy with 2 chunks of size 64Mi with 2 parallel streams 2025/10/11 04:12:51 DEBUG : test-multithread-copy-false-134217728-2: multi-thread copy: chunk 1/2 (0-67108864) size 64Mi starting 2025/10/11 04:12:51 DEBUG : test-multithread-copy-false-134217728-2: multi-thread copy: chunk 2/2 (67108864-134217728) size 64Mi starting 2025/10/11 04:12:51 DEBUG : test-multithread-copy-false-134217728-2: writing chunk 0 2025/10/11 04:12:51 DEBUG : test-multithread-copy-false-134217728-2: writing chunk 1 2025/10/11 04:12:52 DEBUG : test-multithread-copy-false-134217728-2: multi-thread copy: chunk 2/2 (67108864-134217728) size 64Mi finished 2025/10/11 04:12:52 DEBUG : test-multithread-copy-false-134217728-2: multi-thread copy: chunk 1/2 (0-67108864) size 64Mi finished 2025/10/11 04:12:52 DEBUG : test-multithread-copy-false-134217728-2: Finished multi-thread copy with 2 parts of size 64Mi === RUN TestMultithreadCopy/upload=false,size=134217729,streams=2 2025/10/11 04:13:06 DEBUG : test-multithread-copy-false-134217729-2: multi-thread copy: disabling buffering because destination uses OpenWriterAt 2025/10/11 04:13:06 DEBUG : test-multithread-copy-false-134217729-2: multi-thread copy: write buffer set to 131072 2025/10/11 04:13:06 DEBUG : test-multithread-copy-false-134217729-2: multi-thread copy: using backend concurrency of 4 instead of --multi-thread-streams 2 2025/10/11 04:13:06 DEBUG : test-multithread-copy-false-134217729-2: multi-thread copy: number of streams 4 was bigger than number of chunks 3 2025/10/11 04:13:06 DEBUG : test-multithread-copy-false-134217729-2: Starting multi-thread copy with 3 chunks of size 64Mi with 3 parallel streams 2025/10/11 04:13:06 DEBUG : test-multithread-copy-false-134217729-2: multi-thread copy: chunk 3/3 (134217728-134217729) size 1 starting 2025/10/11 04:13:06 DEBUG : test-multithread-copy-false-134217729-2: multi-thread copy: chunk 1/3 (0-67108864) size 64Mi starting 2025/10/11 04:13:06 DEBUG : test-multithread-copy-false-134217729-2: multi-thread copy: chunk 2/3 (67108864-134217728) size 64Mi starting 2025/10/11 04:13:06 DEBUG : test-multithread-copy-false-134217729-2: writing chunk 2 2025/10/11 04:13:06 DEBUG : test-multithread-copy-false-134217729-2: writing chunk 0 2025/10/11 04:13:06 DEBUG : test-multithread-copy-false-134217729-2: multi-thread copy: chunk 3/3 (134217728-134217729) size 1 finished 2025/10/11 04:13:06 DEBUG : test-multithread-copy-false-134217729-2: writing chunk 1 2025/10/11 04:13:07 DEBUG : test-multithread-copy-false-134217729-2: multi-thread copy: chunk 1/3 (0-67108864) size 64Mi finished 2025/10/11 04:13:07 DEBUG : test-multithread-copy-false-134217729-2: multi-thread copy: chunk 2/3 (67108864-134217728) size 64Mi finished 2025/10/11 04:13:07 DEBUG : test-multithread-copy-false-134217729-2: Finished multi-thread copy with 3 parts of size 64Mi --- PASS: TestMultithreadCopy (30.31s) --- PASS: TestMultithreadCopy/upload=false,size=134217728,streams=2 (15.12s) --- PASS: TestMultithreadCopy/upload=false,size=134217729,streams=2 (15.19s) === RUN TestMultithreadCopyAbort run.go:180: Remote "smb://rclone@localhost:28637/rclone/rclone-test-kehesuv4xefi", Local "Local file system at /tmp/rclone3110737893", Modify Window "1ms" 2025/10/11 04:13:27 DEBUG : test-multithread-abort: multi-thread copy: disabling buffering because destination uses OpenWriterAt 2025/10/11 04:13:27 DEBUG : test-multithread-abort: multi-thread copy: write buffer set to 131072 2025/10/11 04:13:27 DEBUG : test-multithread-abort: multi-thread copy: using backend concurrency of 4 instead of --multi-thread-streams 1 2025/10/11 04:13:27 DEBUG : test-multithread-abort: multi-thread copy: number of streams 4 was bigger than number of chunks 3 2025/10/11 04:13:27 DEBUG : test-multithread-abort: Starting multi-thread copy with 3 chunks of size 64Mi with 3 parallel streams 2025/10/11 04:13:27 DEBUG : test-multithread-abort: multi-thread copy: chunk 3/3 (134217728-134217729) size 1 starting 2025/10/11 04:13:27 DEBUG : test-multithread-abort: multi-thread copy: chunk 1/3 (0-67108864) size 64Mi starting 2025/10/11 04:13:27 DEBUG : Open with options = [RangeOption(0,67108863)] 2025/10/11 04:13:27 DEBUG : test-multithread-abort: multi-thread copy: chunk 2/3 (67108864-134217728) size 64Mi starting 2025/10/11 04:13:27 DEBUG : Open with options = [RangeOption(67108864,134217727)] 2025/10/11 04:13:27 DEBUG : test-multithread-abort: writing chunk 0 2025/10/11 04:13:27 DEBUG : test-multithread-abort: writing chunk 1 2025/10/11 04:13:27 DEBUG : Open with options = [RangeOption(134217728,134217728)] 2025/10/11 04:13:28 DEBUG : test-multithread-abort: multi-thread copy: chunk 2/3 (67108864-134217728) size 64Mi finished 2025/10/11 04:13:28 DEBUG : test-multithread-abort: multi-thread copy: chunk 1/3 (0-67108864) size 64Mi finished 2025/10/11 04:13:28 DEBUG : Returning error reader 2025/10/11 04:13:28 DEBUG : test-multithread-abort: writing chunk 2 2025/10/11 04:13:28 DEBUG : BOOM: simulated read failure 2025/10/11 04:13:28 DEBUG : test-multithread-abort: Reopening on read failure after offset 0 bytes: retry 1/10: BOOM: simulated read failure 2025/10/11 04:13:28 DEBUG : Open with options = [RangeOption(134217728,134217728)] 2025/10/11 04:13:29 DEBUG : Returning error reader 2025/10/11 04:13:29 DEBUG : BOOM: simulated read failure 2025/10/11 04:13:29 DEBUG : test-multithread-abort: Reopening on read failure after offset 0 bytes: retry 2/10: BOOM: simulated read failure 2025/10/11 04:13:29 DEBUG : Open with options = [RangeOption(134217728,134217728)] 2025/10/11 04:13:30 DEBUG : Returning error reader 2025/10/11 04:13:30 DEBUG : BOOM: simulated read failure 2025/10/11 04:13:30 DEBUG : test-multithread-abort: Reopening on read failure after offset 0 bytes: retry 3/10: BOOM: simulated read failure 2025/10/11 04:13:30 DEBUG : Open with options = [RangeOption(134217728,134217728)] 2025/10/11 04:13:31 DEBUG : Returning error reader 2025/10/11 04:13:31 DEBUG : BOOM: simulated read failure 2025/10/11 04:13:31 DEBUG : test-multithread-abort: Reopening on read failure after offset 0 bytes: retry 4/10: BOOM: simulated read failure 2025/10/11 04:13:31 DEBUG : Open with options = [RangeOption(134217728,134217728)] 2025/10/11 04:13:32 DEBUG : Returning error reader 2025/10/11 04:13:32 DEBUG : BOOM: simulated read failure 2025/10/11 04:13:32 DEBUG : test-multithread-abort: Reopening on read failure after offset 0 bytes: retry 5/10: BOOM: simulated read failure 2025/10/11 04:13:32 DEBUG : Open with options = [RangeOption(134217728,134217728)] 2025/10/11 04:13:33 DEBUG : Returning error reader 2025/10/11 04:13:33 DEBUG : BOOM: simulated read failure 2025/10/11 04:13:33 DEBUG : test-multithread-abort: Reopening on read failure after offset 0 bytes: retry 6/10: BOOM: simulated read failure 2025/10/11 04:13:33 DEBUG : Open with options = [RangeOption(134217728,134217728)] 2025/10/11 04:13:34 DEBUG : Returning error reader 2025/10/11 04:13:34 DEBUG : BOOM: simulated read failure 2025/10/11 04:13:34 DEBUG : test-multithread-abort: Reopening on read failure after offset 0 bytes: retry 7/10: BOOM: simulated read failure 2025/10/11 04:13:34 DEBUG : Open with options = [RangeOption(134217728,134217728)] 2025/10/11 04:13:35 DEBUG : Returning error reader 2025/10/11 04:13:35 DEBUG : BOOM: simulated read failure 2025/10/11 04:13:35 DEBUG : test-multithread-abort: Reopening on read failure after offset 0 bytes: retry 8/10: BOOM: simulated read failure 2025/10/11 04:13:35 DEBUG : Open with options = [RangeOption(134217728,134217728)] 2025/10/11 04:13:36 DEBUG : Returning error reader 2025/10/11 04:13:36 DEBUG : BOOM: simulated read failure 2025/10/11 04:13:36 DEBUG : test-multithread-abort: Reopening on read failure after offset 0 bytes: retry 9/10: BOOM: simulated read failure 2025/10/11 04:13:36 DEBUG : Open with options = [RangeOption(134217728,134217728)] 2025/10/11 04:13:37 DEBUG : Returning error reader 2025/10/11 04:13:37 DEBUG : BOOM: simulated read failure 2025/10/11 04:13:37 DEBUG : test-multithread-abort: Reopening on read failure after offset 0 bytes: retry 10/10: BOOM: simulated read failure 2025/10/11 04:13:37 DEBUG : test-multithread-abort: Reopen failed after offset 0 bytes read: failed to reopen: too many retries 2025/10/11 04:13:37 DEBUG : test-multithread-abort: multi-thread copy: chunk 3/3 failed: multi-thread copy: failed to write chunk: BOOM: simulated read failure 2025/10/11 04:13:37 DEBUG : test-multithread-abort: multi-thread copy: cancelling transfer on exit --- PASS: TestMultithreadCopyAbort (23.70s) === RUN TestCheck run.go:180: Remote "smb://rclone@localhost:28637/rclone/rclone-test-kehesuv4xefi", Local "Local file system at /tmp/rclone3110737893", Modify Window "1ms" === RUN TestCheck/1 === RUN TestCheck/2 === RUN TestCheck/3 === RUN TestCheck/4 === RUN TestCheck/5 === RUN TestCheck/6 === RUN TestCheck/7 --- PASS: TestCheck (0.09s) --- PASS: TestCheck/1 (0.00s) --- PASS: TestCheck/2 (0.00s) --- PASS: TestCheck/3 (0.00s) --- PASS: TestCheck/4 (0.00s) --- PASS: TestCheck/5 (0.00s) --- PASS: TestCheck/6 (0.00s) --- PASS: TestCheck/7 (0.00s) === RUN TestCheckDownload run.go:180: Remote "smb://rclone@localhost:28637/rclone/rclone-test-kehesuv4xefi", Local "Local file system at /tmp/rclone3110737893", Modify Window "1ms" === RUN TestCheckDownload/1 === RUN TestCheckDownload/2 === RUN TestCheckDownload/3 === RUN TestCheckDownload/4 === RUN TestCheckDownload/5 === RUN TestCheckDownload/6 === RUN TestCheckDownload/7 --- PASS: TestCheckDownload (0.12s) --- PASS: TestCheckDownload/1 (0.01s) --- PASS: TestCheckDownload/2 (0.01s) --- PASS: TestCheckDownload/3 (0.01s) --- PASS: TestCheckDownload/4 (0.01s) --- PASS: TestCheckDownload/5 (0.01s) --- PASS: TestCheckDownload/6 (0.01s) --- PASS: TestCheckDownload/7 (0.01s) === RUN TestCheckSizeOnly run.go:180: Remote "smb://rclone@localhost:28637/rclone/rclone-test-kehesuv4xefi", Local "Local file system at /tmp/rclone3110737893", Modify Window "1ms" === RUN TestCheckSizeOnly/1 === RUN TestCheckSizeOnly/2 === RUN TestCheckSizeOnly/3 === RUN TestCheckSizeOnly/4 === RUN TestCheckSizeOnly/5 === RUN TestCheckSizeOnly/6 === RUN TestCheckSizeOnly/7 --- PASS: TestCheckSizeOnly (0.10s) --- PASS: TestCheckSizeOnly/1 (0.00s) --- PASS: TestCheckSizeOnly/2 (0.00s) --- PASS: TestCheckSizeOnly/3 (0.00s) --- PASS: TestCheckSizeOnly/4 (0.00s) --- PASS: TestCheckSizeOnly/5 (0.00s) --- PASS: TestCheckSizeOnly/6 (0.00s) --- PASS: TestCheckSizeOnly/7 (0.00s) === RUN TestParseSumFile run.go:180: Remote "smb://rclone@localhost:28637/rclone/rclone-test-kehesuv4xefi", Local "Local file system at /tmp/rclone3110737893", Modify Window "1ms" 2025/10/11 04:13:38 NOTICE: test.sum: improperly formatted checksum line 4 2025/10/11 04:13:38 NOTICE: test.sum: improperly formatted checksum line 5 2025/10/11 04:13:38 NOTICE: test.sum: improperly formatted checksum line 6 2025/10/11 04:13:38 NOTICE: test.sum: 2 warning(s) suppressed... 2025/10/11 04:13:38 NOTICE: test.sum: improperly formatted checksum line 4 2025/10/11 04:13:38 NOTICE: test.sum: improperly formatted checksum line 5 2025/10/11 04:13:38 NOTICE: test.sum: improperly formatted checksum line 6 2025/10/11 04:13:38 NOTICE: test.sum: 2 warning(s) suppressed... --- PASS: TestParseSumFile (0.03s) === RUN TestCheckSum run.go:180: Remote "smb://rclone@localhost:28637/rclone/rclone-test-kehesuv4xefi", Local "Local file system at /tmp/rclone3110737893", Modify Window "1ms" 2025/10/11 04:13:38 DEBUG : Creating backend with remote "TestSMBKerberosCcache:rclone/rclone-test-kehesuv4xefi/data" 2025/10/11 04:13:38 DEBUG : Setting type="smb" for "TestSMBKerberosCcache" from environment variable RCLONE_CONFIG_TESTSMBKERBEROSCCACHE_TYPE 2025/10/11 04:13:38 DEBUG : Setting host="localhost" for "TestSMBKerberosCcache" from environment variable RCLONE_CONFIG_TESTSMBKERBEROSCCACHE_HOST 2025/10/11 04:13:38 DEBUG : Setting port="28637" for "TestSMBKerberosCcache" from environment variable RCLONE_CONFIG_TESTSMBKERBEROSCCACHE_PORT 2025/10/11 04:13:38 DEBUG : Setting use_kerberos="true" for "TestSMBKerberosCcache" from environment variable RCLONE_CONFIG_TESTSMBKERBEROSCCACHE_USE_KERBEROS 2025/10/11 04:13:38 DEBUG : Setting kerberos_ccache="/tmp/rclone_krb5_ccache/ccache" for "TestSMBKerberosCcache" from environment variable RCLONE_CONFIG_TESTSMBKERBEROSCCACHE_KERBEROS_CCACHE 2025/10/11 04:13:38 DEBUG : TestSMBKerberosCcache: detected overridden config - adding "{LaD7k}" suffix to name 2025/10/11 04:13:38 DEBUG : Setting host="localhost" for "TestSMBKerberosCcache" from environment variable RCLONE_CONFIG_TESTSMBKERBEROSCCACHE_HOST 2025/10/11 04:13:38 DEBUG : Setting port="28637" for "TestSMBKerberosCcache" from environment variable RCLONE_CONFIG_TESTSMBKERBEROSCCACHE_PORT 2025/10/11 04:13:38 DEBUG : Setting use_kerberos="true" for "TestSMBKerberosCcache" from environment variable RCLONE_CONFIG_TESTSMBKERBEROSCCACHE_USE_KERBEROS 2025/10/11 04:13:38 DEBUG : Setting kerberos_ccache="/tmp/rclone_krb5_ccache/ccache" for "TestSMBKerberosCcache" from environment variable RCLONE_CONFIG_TESTSMBKERBEROSCCACHE_KERBEROS_CCACHE check_test.go:350: smb://rclone@localhost:28637/rclone/rclone-test-kehesuv4xefi/data lacks md5, skipping --- SKIP: TestCheckSum (0.08s) === RUN TestCheckSumDownload run.go:180: Remote "smb://rclone@localhost:28637/rclone/rclone-test-kehesuv4xefi", Local "Local file system at /tmp/rclone3110737893", Modify Window "1ms" 2025/10/11 04:13:38 DEBUG : Creating backend with remote "TestSMBKerberosCcache:rclone/rclone-test-kehesuv4xefi/data" 2025/10/11 04:13:38 DEBUG : Setting type="smb" for "TestSMBKerberosCcache" from environment variable RCLONE_CONFIG_TESTSMBKERBEROSCCACHE_TYPE 2025/10/11 04:13:38 DEBUG : Setting host="localhost" for "TestSMBKerberosCcache" from environment variable RCLONE_CONFIG_TESTSMBKERBEROSCCACHE_HOST 2025/10/11 04:13:38 DEBUG : Setting port="28637" for "TestSMBKerberosCcache" from environment variable RCLONE_CONFIG_TESTSMBKERBEROSCCACHE_PORT 2025/10/11 04:13:38 DEBUG : Setting use_kerberos="true" for "TestSMBKerberosCcache" from environment variable RCLONE_CONFIG_TESTSMBKERBEROSCCACHE_USE_KERBEROS 2025/10/11 04:13:38 DEBUG : Setting kerberos_ccache="/tmp/rclone_krb5_ccache/ccache" for "TestSMBKerberosCcache" from environment variable RCLONE_CONFIG_TESTSMBKERBEROSCCACHE_KERBEROS_CCACHE 2025/10/11 04:13:38 DEBUG : TestSMBKerberosCcache: detected overridden config - adding "{LaD7k}" suffix to name 2025/10/11 04:13:38 DEBUG : Setting host="localhost" for "TestSMBKerberosCcache" from environment variable RCLONE_CONFIG_TESTSMBKERBEROSCCACHE_HOST 2025/10/11 04:13:38 DEBUG : Setting port="28637" for "TestSMBKerberosCcache" from environment variable RCLONE_CONFIG_TESTSMBKERBEROSCCACHE_PORT 2025/10/11 04:13:38 DEBUG : Setting use_kerberos="true" for "TestSMBKerberosCcache" from environment variable RCLONE_CONFIG_TESTSMBKERBEROSCCACHE_USE_KERBEROS 2025/10/11 04:13:38 DEBUG : Setting kerberos_ccache="/tmp/rclone_krb5_ccache/ccache" for "TestSMBKerberosCcache" from environment variable RCLONE_CONFIG_TESTSMBKERBEROSCCACHE_KERBEROS_CCACHE === RUN TestCheckSumDownload/subtest1 === RUN TestCheckSumDownload/subtest2 === RUN TestCheckSumDownload/subtest3 === RUN TestCheckSumDownload/subtest4 === RUN TestCheckSumDownload/subtest5 === RUN TestCheckSumDownload/subtest6 === RUN TestCheckSumDownload/subtest7 --- PASS: TestCheckSumDownload (0.30s) --- PASS: TestCheckSumDownload/subtest1 (0.01s) --- PASS: TestCheckSumDownload/subtest2 (0.01s) --- PASS: TestCheckSumDownload/subtest3 (0.07s) --- PASS: TestCheckSumDownload/subtest4 (0.01s) --- PASS: TestCheckSumDownload/subtest5 (0.01s) --- PASS: TestCheckSumDownload/subtest6 (0.01s) --- PASS: TestCheckSumDownload/subtest7 (0.01s) PASS 2025/10/11 04:13:38 DEBUG : smb://rclone@localhost:28637/rclone/rclone-test-kehesuv4xefi: Purge dir "" "./operations.test -test.v -test.timeout 1h0m0s -remote TestSMBKerberosCcache:rclone -verbose -test.run '^(TestCheck|TestCheckDownload|TestCheckSizeOnly|TestCheckSum|TestCheckSumDownload|TestMultithreadCopyAbort|TestParseSumFile)$|^TestMultithreadCopy$/^(upload=false,size=134217728,streams=2|upload=false,size=134217729,streams=2)$'" - Finished OK in 54.906976244s (try 2/5)