TestFSCK flaking

[decentral1se]

TestFSCK flaking

[KyleMaas]

Well, it took about 1000 runs to get it, but I finally got it to fail:

2023/02/03 02:16:40 [margaret/indexes/badger] overwrote batch limit 0
=== RUN   TestFSCK
=== RUN   TestFSCK/correct
2023/02/03 02:16:40 saved identity @9A+51JUjeradjH0rTFSpFhnPJiAk487iFtx8bfriMII=.ed25519 to testrun/TestFSCK/correct/secrets/one
2023/02/03 02:16:40 saved identity ssb:feed/gabbygrove-v1/3fi4G5PLadj-Mu2__Z6EyPcpNAbJgGxWWFKXZGxNVSg= to testrun/TestFSCK/correct/secrets/two
2023/02/03 02:16:40 saved identity @fiDyrCO/uPUWzevaEtPkisT13Mzhd53k+cW01TFXAlU=.ed25519 to testrun/TestFSCK/correct/secret
    fsck_test.go:83:
                Error Trace:    /home/go-ssb/go-ssb/sbot/fsck_test.go:83
                Error:          Received unexpected error:
                                ssb/consistency error: message sequence missmatch for feed @fiDyrCO/uPUWzevaEtPkisT13Mzhd53k+cW01TFXAlU=.ed25519 Stored:31 Logical:31
                Test:           TestFSCK/correct
=== RUN   TestFSCK/double
2023/02/03 02:16:40 saved identity @kd3E4wyfiebigUGqB0UBAsub242FN7hQR7HML2j+vRc=.ed25519 to testrun/TestFSCK/double/secrets/one
2023/02/03 02:16:40 saved identity ssb:feed/gabbygrove-v1/8rehMsZlPaRci8aJKefo_kgVXUQCJEInrcHfB9GBnaw= to testrun/TestFSCK/double/secrets/two
2023/02/03 02:16:40 saved identity @sWXXLJuGpaCg4oU7+TrkrtT11s9jzrOSvzXJZE/LUaI=.ed25519 to testrun/TestFSCK/double/secret
    fsck_test.go:123: doubled: 32
    fsck_test.go:123: doubled: 33
    fsck_test.go:123: doubled: 34
    fsck_test.go:123: doubled: 35
    fsck_test.go:123: doubled: 36
    fsck_test.go:123: doubled: 37
    fsck_test.go:123: doubled: 38
    fsck_test.go:123: doubled: 39
    fsck_test.go:123: doubled: 40
    fsck_test.go:123: doubled: 41
    fsck_test.go:123: doubled: 42
    fsck_test.go:123: doubled: 43
    fsck_test.go:123: doubled: 44
    fsck_test.go:123: doubled: 45
    fsck_test.go:123: doubled: 46
    fsck_test.go:123: doubled: 47
    fsck_test.go:123: doubled: 48
    fsck_test.go:123: doubled: 49
    fsck_test.go:123: doubled: 50
    fsck_test.go:123: doubled: 51
    fsck_test.go:123: doubled: 52
    fsck_test.go:123: doubled: 53
    fsck_test.go:123: doubled: 54
    fsck_test.go:123: doubled: 55
    fsck_test.go:123: doubled: 56
    fsck_test.go:123: doubled: 57
    fsck_test.go:123: doubled: 58
    fsck_test.go:123: doubled: 59
    fsck_test.go:123: doubled: 60
    fsck_test.go:123: doubled: 61
    fsck_test.go:123: doubled: 62
    fsck_test.go:123: doubled: 63
level=info t=89.93099ms unit=theBot event="heal repo" msg="trying to null all broken feeds" feeds=1 messages=96
level=debug t=91.138008ms unit=theBot event="heal repo" feed="@sWXXLJuGpaCg4oU7+TrkrtT11s9jzrOSvzXJZE/LUaI=.ed25519"
level=debug t=91.922602ms unit=theBot event="sbot closing" msg="waited for indexes to close"
level=info t=103.643524ms unit=theBot event="sbot closing" msg="closers closed"
=== RUN   TestFSCK/multipleFeeds
2023/02/03 02:16:41 saved identity @dz7ENobHhDTfRLDDb/B6tuwEu/fD5R2+gycrAtZuLso=.ed25519 to testrun/TestFSCK/multipleFeeds/secrets/one
2023/02/03 02:16:41 saved identity ssb:feed/gabbygrove-v1/Rd6YJ5sTYYwGj8R0VuRtq2DO1qkW-J7dNjKZhff2xAc= to testrun/TestFSCK/multipleFeeds/secrets/two
2023/02/03 02:16:41 saved identity @S4237hQpzmLARMjaLmEVTF1vl8NnZ7Jx9DbnkNMrHMw=.ed25519 to testrun/TestFSCK/multipleFeeds/secret
    fsck_test.go:216: doubled: <@dz7E.ed25519> 37
    fsck_test.go:216: doubled: <@dz7E.ed25519> 38
    fsck_test.go:216: doubled: <@Rd6Y.gabbygrove-v1> 39
    fsck_test.go:216: doubled: <@Rd6Y.gabbygrove-v1> 40
    fsck_test.go:216: doubled: <@Rd6Y.gabbygrove-v1> 41
level=info t=52.674368ms unit=theBot event="heal repo" msg="trying to null all broken feeds" feeds=2 messages=10
level=debug t=53.056595ms unit=theBot event="heal repo" feed="@dz7ENobHhDTfRLDDb/B6tuwEu/fD5R2+gycrAtZuLso=.ed25519"
level=debug t=53.477291ms unit=theBot event="heal repo" feed="ssb:feed/gabbygrove-v1/Rd6YJ5sTYYwGj8R0VuRtq2DO1qkW-J7dNjKZhff2xAc="
level=debug t=56.117895ms unit=theBot event="sbot closing" msg="waited for indexes to close"
level=info t=65.93615ms unit=theBot event="sbot closing" msg="closers closed"
--- FAIL: TestFSCK (0.22s)
    --- FAIL: TestFSCK/correct (0.05s)
    --- PASS: TestFSCK/double (0.10s)
    --- PASS: TestFSCK/multipleFeeds (0.07s)
FAIL
FAIL    github.com/ssbc/go-ssb/sbot     0.241s
FAIL

[KyleMaas]

I think we probably fixed this one by making Publish synchronous. Will see if I can get it to fail.