TestReplicate is flaky

[decentral1se]

During #259, it failed on https://github.com/ssbc/go-ssb/actions/runs/3725019672/jobs/6317560947:

2022/12/18 13:20:07 [margaret/indexes/badger] overwrote batch limit 0
2022/12/18 13:20:07 saved identity @kRgzANjqLkqoSgL5C0sk+zhSAuAK050E4xkylPYh+4U=.ed25519 to /tmp/TestReplicate3922500462/secret
2022/12/18 13:20:07 saved identity @kPdM/hp+ZdgH3SvkUgkfSPpBGRSNDUXEdK+ViGEuhHc=.ed25519 to /tmp/TestReplicate2514830284/secret
level=info node=dst/bob event=blobs.get ref=<&Ss8L.sha256> msg=stored ref=<&Ss8L.sha256> sz=10
level=error ts=2022-12-18T13:20:27.995566816Z unit=muxrpc remote="pipe|@kRgzANjqLkqoSgL5C0sk+zhSAuAK050E4xkylPYh+4U=.ed25519" event=closed handleErr="muxrpc: failed to get error body for closing of req: 2 (len:4): pkt-codec: failed to read full body" closeErr=null
panic: test timed out after 5m0s

goroutine 54 [running]:
testing.(*M).startAlarm.func1()
/opt/hostedtoolcache/go/1.19.4/x64/src/testing/testing.go:2036 +0x8e
created by time.goFunc
/opt/hostedtoolcache/go/1.19.4/x64/src/time/sleep.go:176 +0x32

goroutine 1 [chan receive, 5 minutes]:
testing.(*T).Run(0xc000007d40, {0xa02ff1?, 0x51a7a5?}, 0xa3fb80)
/opt/hostedtoolcache/go/1.19.4/x64/src/testing/testing.go:1494 +0x37a
testing.runTests.func1(0xc000007d40?)
/opt/hostedtoolcache/go/1.19.4/x64/src/testing/testing.go:1846 +0x6e
testing.tRunner(0xc000007d40, 0xc002327cd8)
/opt/hostedtoolcache/go/1.19.4/x64/src/testing/testing.go:1446 +0x10b
testing.runTests(0xc0000b8b40?, {0xe3e770, 0x1, 0x1}, {0x7f8307c505b8?, 0x40?, 0xe52c40?})
/opt/hostedtoolcache/go/1.19.4/x64/src/testing/testing.go:1844 +0x456
testing.(*M).Run(0xc0000b8b40)
/opt/hostedtoolcache/go/1.19.4/x64/src/testing/testing.go:1726 +0x5d9
main.main()
_testmain.go:47 +0x1aa

goroutine 19 [chan receive]:
github.com/golang/glog.(*loggingT).flushDaemon(0x0?)
/home/runner/go/pkg/mod/github.com/golang/[email protected]/glog.go:882 +0x6a
created by github.com/golang/glog.init.0
/home/runner/go/pkg/mod/github.com/golang/[email protected]/glog.go:410 +0x1bf

goroutine 22 [chan receive, 5 minutes]:
github.com/ssbc/go-ssb/plugins/blobs.TestReplicate(0xc0001a04e0)
/home/runner/work/go-ssb/go-ssb/plugins/blobs/handler_test.go:120 +0xe76
testing.tRunner(0xc0001a04e0, 0xa3fb80)
/opt/hostedtoolcache/go/1.19.4/x64/src/testing/testing.go:1446 +0x10b
created by testing.(*T).Run
/opt/hostedtoolcache/go/1.19.4/x64/src/testing/testing.go:1493 +0x35f

goroutine 23 [chan receive, 5 minutes]:
github.com/ssbc/go-ssb/blobstore.(*WantManager).replicateLoop(0xc0000b8c80)
/home/runner/work/go-ssb/go-ssb/blobstore/wants.go:94 +0x57
created by github.com/ssbc/go-ssb/blobstore.NewWantManager
/home/runner/work/go-ssb/go-ssb/blobstore/wants.go:60 +0x316

goroutine 24 [chan receive, 5 minutes]:
github.com/ssbc/go-ssb/blobstore.(*WantManager).replicateLoop(0xc0000b8dc0)
/home/runner/work/go-ssb/go-ssb/blobstore/wants.go:94 +0x57
created by github.com/ssbc/go-ssb/blobstore.NewWantManager
/home/runner/work/go-ssb/go-ssb/blobstore/wants.go:60 +0x316

goroutine 51 [chan send, 5 minutes]:
github.com/ssbc/go-muxrpc/v2.(*ByteSink).CloseWithError.func1()
/home/runner/go/pkg/mod/github.com/ssbc/go-muxrpc/[email protected]/stream2_sink.go:118 +0x55
created by github.com/ssbc/go-muxrpc/v2.(*ByteSink).CloseWithError
/home/runner/go/pkg/mod/github.com/ssbc/go-muxrpc/[email protected]/stream2_sink.go:117 +0x38d

goroutine 33 [chan send, 5 minutes]:
github.com/ssbc/go-muxrpc/v2.(*ByteSink).CloseWithError.func1()
/home/runner/go/pkg/mod/github.com/ssbc/go-muxrpc/[email protected]/stream2_sink.go:118 +0x55
created by github.com/ssbc/go-muxrpc/v2.(*ByteSink).CloseWithError
/home/runner/go/pkg/mod/github.com/ssbc/go-muxrpc/[email protected]/stream2_sink.go:117 +0x38d

goroutine 49 [chan send, 5 minutes]:
github.com/ssbc/go-muxrpc/v2.(*ByteSink).CloseWithError.func1()
/home/runner/go/pkg/mod/github.com/ssbc/go-muxrpc/[email protected]/stream2_sink.go:118 +0x55
created by github.com/ssbc/go-muxrpc/v2.(*ByteSink).CloseWithError
/home/runner/go/pkg/mod/github.com/ssbc/go-muxrpc/[email protected]/stream2_sink.go:117 +0x38d

goroutine 48 [chan send, 5 minutes]:
github.com/ssbc/go-muxrpc/v2.(*ByteSink).CloseWithError.func1()
/home/runner/go/pkg/mod/github.com/ssbc/go-muxrpc/[email protected]/stream2_sink.go:118 +0x55
created by github.com/ssbc/go-muxrpc/v2.(*ByteSink).CloseWithError
/home/runner/go/pkg/mod/github.com/ssbc/go-muxrpc/[email protected]/stream2_sink.go:117 +0x38d
FAIL github.com/ssbc/go-ssb/plugins/blobs 300.037s
FAIL
make: *** [Makefile:22: test] Error 1
Error: Process completed with exit code 2.

[decentral1se]

Unable to get this one to fail once more 🤔 will take another look at it tomorrow.

[KyleMaas]

I don't think I know enough about replication to be able to effectively debug this one, especially if the failure is not reliably reproducible.