"./gitannex.test -test.v -test.timeout 1h0m0s -remote TestS3: -verbose" - Starting (try 1/5) 2025/03/12 01:00:28 DEBUG : Creating backend with remote "TestS3:rclone-test-padezul5qoyi" 2025/03/12 01:00:28 DEBUG : Using config file from "/home/rclone/.rclone.conf" 2025/03/12 01:00:28 DEBUG : Creating backend with remote "/tmp/rclone3720125593" === RUN TestEndToEnd e2e_test.go:189: Skipping because fstest remote was specified. --- SKIP: TestEndToEnd (0.00s) === RUN TestEndToEndMigration e2e_test.go:189: Skipping because fstest remote was specified. --- SKIP: TestEndToEndMigration (0.00s) === RUN TestEndToEndRepoLayoutCompat e2e_test.go:189: Skipping because fstest remote was specified. --- SKIP: TestEndToEndRepoLayoutCompat (0.00s) === RUN TestFixArgsForSymlinkIdentity --- PASS: TestFixArgsForSymlinkIdentity (0.00s) === RUN TestFixArgsForSymlinkCorrectName --- PASS: TestFixArgsForSymlinkCorrectName (0.00s) === RUN TestMessageParser === RUN TestMessageParser/OneParam === PAUSE TestMessageParser/OneParam === RUN TestMessageParser/TwoParams === PAUSE TestMessageParser/TwoParams === RUN TestMessageParser/TwoParamsNoTrailingNewline === PAUSE TestMessageParser/TwoParamsNoTrailingNewline === RUN TestMessageParser/ThreeParamsWhereFinalParamContainsSpaces === PAUSE TestMessageParser/ThreeParamsWhereFinalParamContainsSpaces === RUN TestMessageParser/OneLongFinalParameter === PAUSE TestMessageParser/OneLongFinalParameter === RUN TestMessageParser/MultipleSpaces === PAUSE TestMessageParser/MultipleSpaces === RUN TestMessageParser/StartsWithSpace === PAUSE TestMessageParser/StartsWithSpace === CONT TestMessageParser/OneParam === CONT TestMessageParser/MultipleSpaces === CONT TestMessageParser/StartsWithSpace === CONT TestMessageParser/ThreeParamsWhereFinalParamContainsSpaces === CONT TestMessageParser/OneLongFinalParameter === RUN TestMessageParser/OneLongFinalParameter/lineEnding === RUN TestMessageParser/OneLongFinalParameter/lineEnding0a === RUN TestMessageParser/OneLongFinalParameter/lineEnding0d === RUN TestMessageParser/OneLongFinalParameter/lineEnding0d0a === RUN TestMessageParser/OneLongFinalParameter/lineEnding0a0d === CONT TestMessageParser/TwoParamsNoTrailingNewline === CONT TestMessageParser/TwoParams --- PASS: TestMessageParser (0.00s) --- PASS: TestMessageParser/OneParam (0.00s) --- PASS: TestMessageParser/MultipleSpaces (0.00s) --- PASS: TestMessageParser/StartsWithSpace (0.00s) --- PASS: TestMessageParser/ThreeParamsWhereFinalParamContainsSpaces (0.00s) --- PASS: TestMessageParser/OneLongFinalParameter (0.00s) --- PASS: TestMessageParser/OneLongFinalParameter/lineEnding (0.00s) --- PASS: TestMessageParser/OneLongFinalParameter/lineEnding0a (0.00s) --- PASS: TestMessageParser/OneLongFinalParameter/lineEnding0d (0.00s) --- PASS: TestMessageParser/OneLongFinalParameter/lineEnding0d0a (0.00s) --- PASS: TestMessageParser/OneLongFinalParameter/lineEnding0a0d (0.00s) --- PASS: TestMessageParser/TwoParamsNoTrailingNewline (0.00s) --- PASS: TestMessageParser/TwoParams (0.00s) === RUN TestConfigDefinitionOneName --- PASS: TestConfigDefinitionOneName (0.00s) === RUN TestConfigDefinitionTwoNames --- PASS: TestConfigDefinitionTwoNames (0.00s) === RUN TestConfigDefinitionThreeNames --- PASS: TestConfigDefinitionThreeNames (0.00s) === RUN TestWindowsFilepathRelQuirk gitannex_test.go:342: --- SKIP: TestWindowsFilepathRelQuirk (0.00s) === RUN TestGitAnnexFstestBackendCases === RUN TestGitAnnexFstestBackendCases/HandlesInit run.go:180: Remote "S3 bucket rclone-test-padezul5qoyi", Local "Local file system at /tmp/rclone3720125593", Modify Window "1ns" === RUN TestGitAnnexFstestBackendCases/HandlesListConfigs run.go:180: Remote "S3 bucket rclone-test-padezul5qoyi", Local "Local file system at /tmp/rclone3720125593", Modify Window "1ns" === RUN TestGitAnnexFstestBackendCases/HandlesPrepare run.go:180: Remote "S3 bucket rclone-test-padezul5qoyi", Local "Local file system at /tmp/rclone3720125593", Modify Window "1ns" === RUN TestGitAnnexFstestBackendCases/HandlesPrepareWithNonexistentRemote run.go:180: Remote "S3 bucket rclone-test-padezul5qoyi", Local "Local file system at /tmp/rclone3720125593", Modify Window "1ns" === RUN TestGitAnnexFstestBackendCases/HandlesPrepareWithPathAsRemote run.go:180: Remote "S3 bucket rclone-test-padezul5qoyi", Local "Local file system at /tmp/rclone3720125593", Modify Window "1ns" === RUN TestGitAnnexFstestBackendCases/HandlesPrepareWithNonexistentBackendAsRemote run.go:180: Remote "S3 bucket rclone-test-padezul5qoyi", Local "Local file system at /tmp/rclone3720125593", Modify Window "1ns" === RUN TestGitAnnexFstestBackendCases/HandlesPrepareWithBackendAsRemote run.go:180: Remote "S3 bucket rclone-test-padezul5qoyi", Local "Local file system at /tmp/rclone3720125593", Modify Window "1ns" === RUN TestGitAnnexFstestBackendCases/HandlesPrepareWithBackendMissingTrailingColonAsRemote run.go:180: Remote "S3 bucket rclone-test-padezul5qoyi", Local "Local file system at /tmp/rclone3720125593", Modify Window "1ns" === RUN TestGitAnnexFstestBackendCases/HandlesPrepareWithBackendContainingOptionsAsRemote run.go:180: Remote "S3 bucket rclone-test-padezul5qoyi", Local "Local file system at /tmp/rclone3720125593", Modify Window "1ns" === RUN TestGitAnnexFstestBackendCases/HandlesPrepareWithBackendContainingOptionsAndIllegalPathAsRemote run.go:180: Remote "S3 bucket rclone-test-padezul5qoyi", Local "Local file system at /tmp/rclone3720125593", Modify Window "1ns" === RUN TestGitAnnexFstestBackendCases/HandlesPrepareWithSynonyms run.go:180: Remote "S3 bucket rclone-test-padezul5qoyi", Local "Local file system at /tmp/rclone3720125593", Modify Window "1ns" === RUN TestGitAnnexFstestBackendCases/HandlesPrepareAndDoesNotTrimWhitespaceFromValue run.go:180: Remote "S3 bucket rclone-test-padezul5qoyi", Local "Local file system at /tmp/rclone3720125593", Modify Window "1ns" === RUN TestGitAnnexFstestBackendCases/HandlesEarlyError run.go:180: Remote "S3 bucket rclone-test-padezul5qoyi", Local "Local file system at /tmp/rclone3720125593", Modify Window "1ns" === RUN TestGitAnnexFstestBackendCases/ConfigFail run.go:180: Remote "S3 bucket rclone-test-padezul5qoyi", Local "Local file system at /tmp/rclone3720125593", Modify Window "1ns" === RUN TestGitAnnexFstestBackendCases/TransferStoreEmptyPath run.go:180: Remote "S3 bucket rclone-test-padezul5qoyi", Local "Local file system at /tmp/rclone3720125593", Modify Window "1ns" === RUN TestGitAnnexFstestBackendCases/ExtensionsCompound run.go:180: Remote "S3 bucket rclone-test-padezul5qoyi", Local "Local file system at /tmp/rclone3720125593", Modify Window "1ns" === RUN TestGitAnnexFstestBackendCases/ExtensionsIdempotent run.go:180: Remote "S3 bucket rclone-test-padezul5qoyi", Local "Local file system at /tmp/rclone3720125593", Modify Window "1ns" === RUN TestGitAnnexFstestBackendCases/ExtensionsSupportsMultiple run.go:180: Remote "S3 bucket rclone-test-padezul5qoyi", Local "Local file system at /tmp/rclone3720125593", Modify Window "1ns" === RUN TestGitAnnexFstestBackendCases/TransferStoreAbsolute run.go:180: Remote "S3 bucket rclone-test-padezul5qoyi", Local "Local file system at /tmp/rclone3720125593", Modify Window "1ns" 2025/03/12 01:00:30 DEBUG : Creating backend with remote "TestS3:rclone-test-padezul5qoyi" 2025/03/12 01:00:30 DEBUG : Creating backend with remote "/tmp/rclone3720125593" 2025/03/12 01:00:30 DEBUG : file.txt: Need to transfer - File not found at Destination 2025/03/12 01:00:31 INFO : S3 bucket rclone-test-padezul5qoyi: Bucket "rclone-test-padezul5qoyi" created with ACL "" 2025/03/12 01:00:31 DEBUG : file.txt: md5 = eb61eead90e3b899c6bcbe27ac581660 OK 2025/03/12 01:00:31 INFO : file.txt: Copied (new) to: KeyAbsolute fstest.go:292: Sleeping for 1s for list eventual consistency: 1/3 fstest.go:292: Sleeping for 2s for list eventual consistency: 2/3 fstest.go:292: Sleeping for 4s for list eventual consistency: 3/3 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/fstest/fstest.go:344 /home/rclone/go/src/github.com/rclone/rclone/fstest/run.go:340 /home/rclone/go/src/github.com/rclone/rclone/cmd/gitannex/gitannex_test.go:912 /home/rclone/go/src/github.com/rclone/rclone/cmd/gitannex/gitannex_test.go:1330 Error: Should be true Test: TestGitAnnexFstestBackendCases/TransferStoreAbsolute Messages: listing wrong, want KeyAbsolute (5) got fstest.go:197: Not found "KeyAbsolute" 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/fstest/fstest.go:344 /home/rclone/go/src/github.com/rclone/rclone/fstest/run.go:340 /home/rclone/go/src/github.com/rclone/rclone/cmd/gitannex/gitannex_test.go:912 /home/rclone/go/src/github.com/rclone/rclone/cmd/gitannex/gitannex_test.go:1330 Error: Not equal: expected: 0 actual : 1 Test: TestGitAnnexFstestBackendCases/TransferStoreAbsolute Messages: 1 objects not found 2025/03/12 01:00:38 DEBUG : file.txt: Need to transfer - File not found at Destination 2025/03/12 01:00:38 DEBUG : file.txt: md5 = eb61eead90e3b899c6bcbe27ac581660 OK 2025/03/12 01:00:38 INFO : file.txt: Copied (new) to: KeyAbsolute2 fstest.go:292: Sleeping for 1s for list eventual consistency: 1/3 fstest.go:292: Sleeping for 2s for list eventual consistency: 2/3 fstest.go:292: Sleeping for 4s for list eventual consistency: 3/3 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/fstest/fstest.go:344 /home/rclone/go/src/github.com/rclone/rclone/fstest/run.go:340 /home/rclone/go/src/github.com/rclone/rclone/cmd/gitannex/gitannex_test.go:920 /home/rclone/go/src/github.com/rclone/rclone/cmd/gitannex/gitannex_test.go:1330 Error: Should be true Test: TestGitAnnexFstestBackendCases/TransferStoreAbsolute Messages: listing wrong, want KeyAbsolute (5), KeyAbsolute2 (5) got fstest.go:197: Not found "KeyAbsolute" fstest.go:197: Not found "KeyAbsolute2" 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/fstest/fstest.go:344 /home/rclone/go/src/github.com/rclone/rclone/fstest/run.go:340 /home/rclone/go/src/github.com/rclone/rclone/cmd/gitannex/gitannex_test.go:920 /home/rclone/go/src/github.com/rclone/rclone/cmd/gitannex/gitannex_test.go:1330 Error: Not equal: expected: 0 actual : 2 Test: TestGitAnnexFstestBackendCases/TransferStoreAbsolute Messages: 2 objects not found gitannex_test.go:283: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/cmd/gitannex/gitannex_test.go:283 /home/rclone/go/src/github.com/rclone/rclone/cmd/gitannex/gitannex_test.go:923 /home/rclone/go/src/github.com/rclone/rclone/cmd/gitannex/gitannex_test.go:1330 Error: Not equal: expected: "CHECKPRESENT-SUCCESS KeyAbsolute2\n" actual : "CHECKPRESENT-FAILURE KeyAbsolute2\n" Diff: --- Expected +++ Actual @@ -1,2 +1,2 @@ -CHECKPRESENT-SUCCESS KeyAbsolute2 +CHECKPRESENT-FAILURE KeyAbsolute2 Test: TestGitAnnexFstestBackendCases/TransferStoreAbsolute panic: test timed out after 1h0m0s running tests: TestGitAnnexFstestBackendCases (1h0m0s) TestGitAnnexFstestBackendCases/TransferStoreAbsolute (59m59s) goroutine 171 [running]: testing.(*M).startAlarm.func1() /home/rclone/go/pkg/mod/golang.org/toolchain@v0.0.1-go1.23.0.linux-amd64/src/testing/testing.go:2373 +0x385 created by time.goFunc /home/rclone/go/pkg/mod/golang.org/toolchain@v0.0.1-go1.23.0.linux-amd64/src/time/sleep.go:215 +0x2d goroutine 1 [chan receive, 60 minutes]: testing.(*T).Run(0xc000742820, {0x267380b?, 0x0?}, 0x27864d8) /home/rclone/go/pkg/mod/golang.org/toolchain@v0.0.1-go1.23.0.linux-amd64/src/testing/testing.go:1751 +0x3ab testing.runTests.func1(0xc000742820) /home/rclone/go/pkg/mod/golang.org/toolchain@v0.0.1-go1.23.0.linux-amd64/src/testing/testing.go:2168 +0x37 testing.tRunner(0xc000742820, 0xc000763c18) /home/rclone/go/pkg/mod/golang.org/toolchain@v0.0.1-go1.23.0.linux-amd64/src/testing/testing.go:1690 +0xf4 testing.runTests(0xc00068b170, {0x3d953a0, 0xb, 0xb}, {0x3dcdba0?, 0x1?, 0x3dcdba0?}) /home/rclone/go/pkg/mod/golang.org/toolchain@v0.0.1-go1.23.0.linux-amd64/src/testing/testing.go:2166 +0x43d testing.(*M).Run(0xc00042a320) /home/rclone/go/pkg/mod/golang.org/toolchain@v0.0.1-go1.23.0.linux-amd64/src/testing/testing.go:2034 +0x64a github.com/rclone/rclone/fstest.TestMain(0xc00042a320) /home/rclone/go/src/github.com/rclone/rclone/fstest/run.go:69 +0xa5 github.com/rclone/rclone/cmd/gitannex.TestMain(...) /home/rclone/go/src/github.com/rclone/rclone/cmd/gitannex/gitannex_test.go:1286 main.main() _testmain.go:67 +0xa9 goroutine 39 [syscall, 60 minutes]: os/signal.signal_recv() /home/rclone/go/pkg/mod/golang.org/toolchain@v0.0.1-go1.23.0.linux-amd64/src/runtime/sigqueue.go:152 +0x29 os/signal.loop() /home/rclone/go/pkg/mod/golang.org/toolchain@v0.0.1-go1.23.0.linux-amd64/src/os/signal/signal_unix.go:23 +0x13 created by os/signal.Notify.func1.1 in goroutine 1 /home/rclone/go/pkg/mod/golang.org/toolchain@v0.0.1-go1.23.0.linux-amd64/src/os/signal/signal.go:151 +0x1f goroutine 40 [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 +0xa7 goroutine 75 [chan receive, 59 minutes]: testing.(*T).Run(0xc000811040, {0x2651e38?, 0xf?}, 0xc000c07a10) /home/rclone/go/pkg/mod/golang.org/toolchain@v0.0.1-go1.23.0.linux-amd64/src/testing/testing.go:1751 +0x3ab github.com/rclone/rclone/cmd/gitannex.TestGitAnnexFstestBackendCases(0xc000811040) /home/rclone/go/src/github.com/rclone/rclone/cmd/gitannex/gitannex_test.go:1293 +0x67 testing.tRunner(0xc000811040, 0x27864d8) /home/rclone/go/pkg/mod/golang.org/toolchain@v0.0.1-go1.23.0.linux-amd64/src/testing/testing.go:1690 +0xf4 created by testing.(*T).Run in goroutine 1 /home/rclone/go/pkg/mod/golang.org/toolchain@v0.0.1-go1.23.0.linux-amd64/src/testing/testing.go:1743 +0x390 goroutine 148 [semacquire, 59 minutes]: sync.runtime_Semacquire(0xc000d3bb18?) /home/rclone/go/pkg/mod/golang.org/toolchain@v0.0.1-go1.23.0.linux-amd64/src/runtime/sema.go:71 +0x25 sync.(*WaitGroup).Wait(0xc000385880?) /home/rclone/go/pkg/mod/golang.org/toolchain@v0.0.1-go1.23.0.linux-amd64/src/sync/waitgroup.go:118 +0x48 runtime.Goexit() /home/rclone/go/pkg/mod/golang.org/toolchain@v0.0.1-go1.23.0.linux-amd64/src/runtime/panic.go:629 +0x5e testing.(*common).FailNow(0xc00078c9c0) /home/rclone/go/pkg/mod/golang.org/toolchain@v0.0.1-go1.23.0.linux-amd64/src/testing/testing.go:1006 +0x4a github.com/stretchr/testify/require.Equal({0x2a52230, 0xc00078c9c0}, {0x2095ec0, 0xc00081a430}, {0x2095ec0, 0xc00081a460}, {0x0, 0x0, 0x0}) /home/rclone/go/pkg/mod/github.com/stretchr/testify@v1.10.0/require/require.go:162 +0xff github.com/rclone/rclone/cmd/gitannex.(*testState).requireReadLineExact(0xc000c02910, {0x267f568, 0x21}) /home/rclone/go/src/github.com/rclone/rclone/cmd/gitannex/gitannex_test.go:283 +0xc8 github.com/rclone/rclone/cmd/gitannex.init.func27(0xc00078c9c0, 0xc000c02910) /home/rclone/go/src/github.com/rclone/rclone/cmd/gitannex/gitannex_test.go:923 +0x677 github.com/rclone/rclone/cmd/gitannex.TestGitAnnexFstestBackendCases.func1(0xc00078c9c0) /home/rclone/go/src/github.com/rclone/rclone/cmd/gitannex/gitannex_test.go:1330 +0x39a testing.tRunner(0xc00078c9c0, 0xc000c07a10) /home/rclone/go/pkg/mod/golang.org/toolchain@v0.0.1-go1.23.0.linux-amd64/src/testing/testing.go:1690 +0xf4 created by testing.(*T).Run in goroutine 75 /home/rclone/go/pkg/mod/golang.org/toolchain@v0.0.1-go1.23.0.linux-amd64/src/testing/testing.go:1743 +0x390 goroutine 149 [select, 59 minutes]: io.(*pipe).read(0xc000c611a0, {0xc000c73000, 0x1000, 0x0?}) /home/rclone/go/pkg/mod/golang.org/toolchain@v0.0.1-go1.23.0.linux-amd64/src/io/pipe.go:57 +0xa5 io.(*PipeReader).Read(0xc000d033e0?, {0xc000c73000?, 0xc000db1d00?, 0xc000c33110?}) /home/rclone/go/pkg/mod/golang.org/toolchain@v0.0.1-go1.23.0.linux-amd64/src/io/pipe.go:134 +0x1a bufio.(*Reader).fill(0xc000c61260) /home/rclone/go/pkg/mod/golang.org/toolchain@v0.0.1-go1.23.0.linux-amd64/src/bufio/bufio.go:110 +0x103 bufio.(*Reader).ReadSlice(0xc000c61260, 0xa) /home/rclone/go/pkg/mod/golang.org/toolchain@v0.0.1-go1.23.0.linux-amd64/src/bufio/bufio.go:376 +0x29 bufio.(*Reader).collectFragments(0xc000c61260, 0xa) /home/rclone/go/pkg/mod/golang.org/toolchain@v0.0.1-go1.23.0.linux-amd64/src/bufio/bufio.go:451 +0x70 bufio.(*Reader).ReadString(0x26205d1?, 0x5?) /home/rclone/go/pkg/mod/golang.org/toolchain@v0.0.1-go1.23.0.linux-amd64/src/bufio/bufio.go:498 +0x1f github.com/rclone/rclone/cmd/gitannex.(*server).getMsg(0xc000c02960) /home/rclone/go/src/github.com/rclone/rclone/cmd/gitannex/gitannex.go:176 +0x27 github.com/rclone/rclone/cmd/gitannex.(*server).run(0xc000c02960) /home/rclone/go/src/github.com/rclone/rclone/cmd/gitannex/gitannex.go:199 +0x32 github.com/rclone/rclone/cmd/gitannex.TestGitAnnexFstestBackendCases.func1.2() /home/rclone/go/src/github.com/rclone/rclone/cmd/gitannex/gitannex_test.go:1318 +0x36 created by github.com/rclone/rclone/cmd/gitannex.TestGitAnnexFstestBackendCases.func1 in goroutine 148 /home/rclone/go/src/github.com/rclone/rclone/cmd/gitannex/gitannex_test.go:1317 +0x348 goroutine 156 [select]: github.com/rclone/rclone/fs/accounting.(*StatsInfo).averageLoop(0xc000ac2000) /home/rclone/go/src/github.com/rclone/rclone/fs/accounting/stats.go:339 +0x13d created by github.com/rclone/rclone/fs/accounting.(*StatsInfo)._startAverageLoop in goroutine 149 /home/rclone/go/src/github.com/rclone/rclone/fs/accounting/stats.go:404 +0xb6 "./gitannex.test -test.v -test.timeout 1h0m0s -remote TestS3: -verbose" - Finished ERROR in 1h0m0.204899092s (try 1/5): exit status 2: Failed []