Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

core: compile failures due to SSA race condition #4206

Open
scottfeldman opened this issue Mar 25, 2024 · 29 comments
Open

core: compile failures due to SSA race condition #4206

scottfeldman opened this issue Mar 25, 2024 · 29 comments
Labels
bug Something isn't working core

Comments

@scottfeldman
Copy link
Contributor

Several folks on the Slack TinyGo channel reported in-frequent compile failures with 0.31.2.

Here's some I've captured in my build logs. I would estimate it happens 1/40 compiles. A re-compile is the work-around.

#13 144.9 /usr/local/bin/tinygo build -target wioterminal -o ../../relays-wioterminal.uf2 -stack-size 8kb -size short /tmp/build-3411892484.go
#13 148.5 2024/03/14 07:35:32 Error generating UF2s: exit status 1: Basic Block in function '(*github.com/***/dean.mutex).islocked' does not have terminator!
#13 148.5 label %entry
#13 148.5 error: verification error after compiling package command-line-arguments
#14 141.8 /usr/local/bin/tinygo build -target wioterminal -o ../../relays-wioterminal.uf2 -stack-size 8kb -size short /tmp/build-1005049736.go
#14 145.2 2024/03/17 04:38:03 Error generating UF2s: exit status 1: Basic Block in function '(*struct{github.com/***/dean.Thing; github.com/***/device/target.Targets "json:\"-\""; ModelStruct string "json:\"-\""; github.com/***/device.WifiAuth "json:\"-\""; DialURLs string "json:\"-\""; DeployParams string; deployValues net/url.Values; github.com/***/device.ViewMode "json:\"-\""; WsScheme string "json:\"-\""; fs embed.FS; github.com/***/device.deviceOS}).TestFlag' does not have terminator!
#14 145.2 label %entry
#14 145.2 error: verification error after compiling package command-line-arguments
#13 197.4 /usr/local/bin/tinygo build -target wioterminal -o ../../relays-wioterminal.uf2 -stack-size 8kb -size short /tmp/build-3732778842.go
#13 200.7 2024/03/14 07:05:36 Error generating UF2s: exit status 2: SIGSEGV: segmentation violation
#13 200.7 PC=0x813d1c m=3 sigcode=18446744073709551610 addr=0x4a5
#13 200.7
#13 200.7 goroutine 110 gp=0xc017982e00 m=3 mp=0xc000051008 [running]:
#13 200.7 github.com/tinygo-org/tinygo/compiler.getPos({0x0, 0x0})
#13 200.7       /__w/tinygo/tinygo/compiler/compiler.go:1402 +0x1c fp=0xc0191b3198 sp=0xc0191b3168 pc=0x813d1c
#13 200.7 github.com/tinygo-org/tinygo/compiler.(*builder).createInstruction(0xc01811e900, {0x0, 0x0})
#13 200.7       /__w/tinygo/tinygo/compiler/compiler.go:1442 +0xd85 fp=0xc0191b32e0 sp=0xc0191b3198 pc=0x814f05
#13 200.7 github.com/tinygo-org/tinygo/compiler.(*builder).createFunction(0xc01811e900)
#13 200.7       /__w/tinygo/tinygo/compiler/compiler.go:1336 +0x915 fp=0xc0191b34d0 sp=0xc0191b32e0 pc=0x8134f5
#13 200.7 github.com/tinygo-org/tinygo/compiler.(*compilerContext).getFunction(0xc017c5a140, 0xc018086d00)
#13 200.7       /__w/tinygo/tinygo/compiler/symbol.go:222 +0xdaf fp=0xc0191b36b0 sp=0xc0191b34d0 pc=0x85472f
#13 200.7 github.com/tinygo-org/tinygo/compiler.(*compilerContext).getTypeMethodSet(0xc017c5a140, {0x605cf28, 0xc01367eb10})
#13 200.7       /__w/tinygo/tinygo/compiler/interface.go:619 +0x24d fp=0xc0191b3810 sp=0xc0191b36b0 pc=0x84166d
#13 200.7 github.com/tinygo-org/tinygo/compiler.(*compilerContext).getTypeCode(0xc017c5a140, {0x605cf28, 0xc01367eb10})
#13 200.7       /__w/tinygo/tinygo/compiler/interface.go:417 +0x3448 fp=0xc0191b3e00 sp=0xc0191b3810 pc=0x83dac8
#13 200.7 github.com/tinygo-org/tinygo/compiler.(*compilerContext).getTypeCode(0xc017c5a140, {0x605cf00, 0xc00426d0b0})
#13 200.7       /__w/tinygo/tinygo/compiler/interface.go:352 +0x2b33 fp=0xc0191b43f0 sp=0xc0191b3e00 pc=0x83d1b3
#13 200.7 github.com/tinygo-org/tinygo/compiler.(*compilerContext).getTypeCode(0xc017c5a140, {0x605ce10, 0xc010d37880})
#13 200.7       /__w/tinygo/tinygo/compiler/interface.go:292 +0x292d fp=0xc0191b49e0 sp=0xc0191b43f0 pc=0x83cfad
#13 200.7 github.com/tinygo-org/tinygo/compiler.(*compilerContext).getTypeCode(0xc017c5a140, {0x605cf28, 0xc00401b560})
#13 200.7       /__w/tinygo/tinygo/compiler/interface.go:322 +0x317e fp=0xc0191b4fd0 sp=0xc0191b49e0 pc=0x83d7fe
#13 200.7 github.com/tinygo-org/tinygo/compiler.(*builder).createMakeInterface(0xc017c7a180, {0x60607f8?}, {0x605cf28, 0xc00401b560}, 0x2?)
#13 200.7       /__w/tinygo/tinygo/compiler/interface.go:80 +0x6e fp=0xc0191b5020 sp=0xc0191b4fd0 pc=0x839bce
#13 200.7 github.com/tinygo-org/tinygo/compiler.(*builder).createExpr(0xc017c7a180, {0x60608d0, 0xc01780ea00})
#13 200.7       /__w/tinygo/tinygo/compiler/compiler.go:2209 +0x1d45 fp=0xc0191b54d0 sp=0xc0191b5020 pc=0x81ddc5
#13 200.7 github.com/tinygo-org/tinygo/compiler.(*builder).createInstruction(0xc017c7a180, {0x60619b0, 0xc01780ea00})
#13 200.7       /__w/tinygo/tinygo/compiler/compiler.go:1447 +0xa5e fp=0xc0191b5618 sp=0xc0191b54d0 pc=0x814bde
#13 200.7 github.com/tinygo-org/tinygo/compiler.(*builder).createFunction(0xc017c7a180)
#13 200.7       /__w/tinygo/tinygo/compiler/compiler.go:1336 +0x915 fp=0xc0191b5808 sp=0xc0191b5618 pc=0x8134f5
#13 200.7 github.com/tinygo-org/tinygo/compiler.(*compilerContext).createPackage(0xc017c5a140, {0xc0075ed040?}, 0xc003fe7280)
#13 200.7       /__w/tinygo/tinygo/compiler/compiler.go:888 +0x965 fp=0xc0191b5a68 sp=0xc0191b5808 pc=0x80d2a5
#13 200.7 github.com/tinygo-org/tinygo/compiler.CompilePackage({0xc00033fc40?, 0x53?}, 0xc0004274a0, 0xc003fe7280, {0xa1bad0e8a1cbdddb?}, 0x5fbafac?, 0x79?)
#13 200.7       /__w/tinygo/tinygo/compiler/compiler.go:311 +0x42a fp=0xc0191b5c28 sp=0xc0191b5a68 pc=0x805e4a
#13 200.7 github.com/tinygo-org/tinygo/builder.Build.func3(0xc017878720)
#13 200.7       /__w/tinygo/tinygo/builder/build.go:370 +0x205 fp=0xc0191b5f80 sp=0xc0191b5c28 pc=0x8b4845
#13 200.7 github.com/tinygo-org/tinygo/builder.runJob(0xc017878720, 0xc01782ac60)
#13 200.7       /__w/tinygo/tinygo/builder/jobs.go:222 +0x4d fp=0xc0191b5fc0 sp=0xc0191b5f80 pc=0x8c126d
#13 200.7 github.com/tinygo-org/tinygo/builder.runJobs.gowrap1()
#13 200.7       /__w/tinygo/tinygo/builder/jobs.go:123 +0x25 fp=0xc0191b5fe0 sp=0xc0191b5fc0 pc=0x8c0be5
#13 200.7 runtime.goexit({})
#13 200.7       /usr/local/go/src/runtime/asm_amd64.s:1695 +0x1 fp=0xc0191b5fe8 sp=0xc0191b5fe0 pc=0x578d01
#13 200.7 created by github.com/tinygo-org/tinygo/builder.runJobs in goroutine 1
#13 200.7       /__w/tinygo/tinygo/builder/jobs.go:123 +0x5bd
#13 200.7
<....cut...>
@scottfeldman scottfeldman changed the title Strange, in-frequent TinyGo compile failures Strange, infrequent TinyGo compile failures Mar 25, 2024
@rajatjindal
Copy link
Contributor

for additional context, here is the link to the msg in slack where we started this conversation: https://gophers.slack.com/archives/CDJD3SUP6/p1711334267168799

@scottfeldman
Copy link
Contributor Author

I tried reproducing by calling TinyGo build in a loop, but no luck so far. It's gone over 600 iterations. I'll keep trying. The suggestion was to restrict TinyGo build to one CPU using taskset -c 0 tinygo build ..., but right now I'm just trying to get it to fail in a loop without taskset...

However, just in my normal GitHub workflow build, I did get another one:

#14 171.4 /usr/local/bin/tinygo build -target wioterminal -o ../../skeleton-wioterminal.uf2 -stack-size 8kb -size short /tmp/build-770892309.go
#14 174.9 2024/03/26 05:37:41 Error generating UF2s: exit status 1: Basic Block in function '(*github.com/***/dean.mutex).setlock' does not have terminator!
#14 174.9 label %gep.next
#14 174.9 error: verification error after compiling package command-line-arguments

I've noticed that all of the failures I've posted to this Issue are with -target=wioterminal, but I'm pretty sure I've seen if fail with other targets.

@dkegel-fastly
Copy link
Contributor

dkegel-fastly commented Mar 29, 2024

It just hit me. Oddly, this was just after I did "brew upgrade".

Here's the error:

 tinygo: "Basic Block in function '(*math/big.nat).sticky' does not have terminator!\nlabel %entry\nBasic Block in function '(*math/big.nat).sticky' does not have terminator!\nlabel %entry\nerror: verification error after compiling package crypto/ecdsa\n": exit status 1

And here's the program I was compiling:

package main

import (
        "context"
        "fmt"

        "github.com/fastly/compute-sdk-go/fsthttp"
)

func main() {
        fsthttp.ServeFunc(func(ctx context.Context, w fsthttp.ResponseWriter, r *fsthttp.Request) {
                fmt.Fprintf(w, "Hello, %s!\n", r.RemoteAddr)
        })
}

Options included -opt=2 -target=wasi -gc=leaking and probably a few others.

@scottfeldman
Copy link
Contributor Author

I hit it again today, this time on -target nano-rp2040 and with a different failure signature:

#14 77.46 /usr/local/bin/tinygo build -target nano-rp2040 -o ../../garage-nano-rp2040.uf2 -stack-size 8kb -size short /tmp/build-2321174789.go
#14 81.12 2024/04/04 19:15:09 Error generating UF2s: exit status 2: panic: runtime error: index out of range [0] with length 0
#14 81.12 
#14 81.12 goroutine 296 [running]:
#14 81.12 github.com/tinygo-org/tinygo/compiler.(*builder).createFunctionStart(0xc012ecbb00, 0x0)
#14 81.12 	/__w/tinygo/tinygo/compiler/compiler.go:1206 +0x11cf
#14 81.12 github.com/tinygo-org/tinygo/compiler.(*builder).createFunction(0xc012ecbb00)
#14 81.12 	/__w/tinygo/tinygo/compiler/compiler.go:1295 +0x2c
#14 81.12 github.com/tinygo-org/tinygo/compiler.(*compilerContext).getFunction(0xc0155a2780, 0xc0130c84e0)
#14 81.12 	/__w/tinygo/tinygo/compiler/symbol.go:222 +0xdaf
#14 81.12 github.com/tinygo-org/tinygo/compiler.(*compilerContext).getTypeMethodSet(0xc0155a2780, {0x605b928, 0xc00c80a580})
#14 81.12 	/__w/tinygo/tinygo/compiler/interface.go:619 +0x24d
#14 81.12 github.com/tinygo-org/tinygo/compiler.(*compilerContext).getTypeCode(0xc0155a2780, {0x605b928, 0xc00c80a580})
#14 81.12 	/__w/tinygo/tinygo/compiler/interface.go:417 +0x3448
#14 81.12 github.com/tinygo-org/tinygo/compiler.(*compilerContext).getTypeCode(0xc0155a2780, {0x605b900, 0xc00bbd4c00})
#14 81.12 	/__w/tinygo/tinygo/compiler/interface.go:352 +0x2b33
#14 81.12 github.com/tinygo-org/tinygo/compiler.(*compilerContext).getTypeCode(0xc0155a2780, {0x605b810, 0xc0112d7730})
#14 81.12 	/__w/tinygo/tinygo/compiler/interface.go:292 +0x292d
#14 81.12 github.com/tinygo-org/tinygo/compiler.(*compilerContext).getTypeCode(0xc0155a2780, {0x605b928, 0xc0118d74c0})
#14 81.12 	/__w/tinygo/tinygo/compiler/interface.go:322 +0x317e
#14 81.12 github.com/tinygo-org/tinygo/compiler.(*compilerContext).getTypeCode(0xc0155a2780, {0x605b900, 0xc00be1ac30})
#14 81.12 	/__w/tinygo/tinygo/compiler/interface.go:394 +0x3d68
#14 81.12 github.com/tinygo-org/tinygo/compiler.(*compilerContext).getTypeCode(0xc0155a2780, {0x605b810, 0xc0112d7b90})
#14 81.12 	/__w/tinygo/tinygo/compiler/interface.go:292 +0x292d
#14 81.12 github.com/tinygo-org/tinygo/compiler.(*compilerContext).getTypeCode(0xc0155a2780, {0x605b928, 0xc0118d7630})
#14 81.12 	/__w/tinygo/tinygo/compiler/interface.go:322 +0x317e
#14 81.12 github.com/tinygo-org/tinygo/compiler.(*builder).createMakeInterface(0xc0165c7380, {0x605f208?}, {0x605b928, 0xc0118d7630}, 0x2?)
#14 81.12 	/__w/tinygo/tinygo/compiler/interface.go:80 +0x6e
#14 81.12 github.com/tinygo-org/tinygo/compiler.(*builder).createExpr(0xc0165c7380, {0x605f2e0, 0xc017803810})
#14 81.12 	/__w/tinygo/tinygo/compiler/compiler.go:2209 +0x1d45
#14 81.12 github.com/tinygo-org/tinygo/compiler.(*builder).createInstruction(0xc0165c7380, {0x60603c0, 0xc017803810})
#14 81.12 	/__w/tinygo/tinygo/compiler/compiler.go:1447 +0xa5e
#14 81.12 github.com/tinygo-org/tinygo/compiler.(*builder).createFunction(0xc0165c7380)
#14 81.12 	/__w/tinygo/tinygo/compiler/compiler.go:1336 +0x915
#14 81.12 github.com/tinygo-org/tinygo/compiler.(*compilerContext).createPackage(0xc0155a2780, {0xc003fb11e0?}, 0xc003871080)
#14 81.12 	/__w/tinygo/tinygo/compiler/compiler.go:888 +0x965
#14 81.12 github.com/tinygo-org/tinygo/compiler.CompilePackage({0xc0002d1cc0?, 0x53?}, 0xc000361860, 0xc003871080, {0xc01288e4d0?}, 0x5fb9fac?, 0x68?)
#14 81.12 	/__w/tinygo/tinygo/compiler/compiler.go:311 +0x42a
#14 81.12 github.com/tinygo-org/tinygo/builder.Build.func3(0xc015c61260)
#14 81.12 	/__w/tinygo/tinygo/builder/build.go:370 +0x205
#14 81.12 github.com/tinygo-org/tinygo/builder.runJob(0xc015c61260, 0xc0125ab620)
#14 81.12 	/__w/tinygo/tinygo/builder/jobs.go:222 +0x4d
#14 81.12 created by github.com/tinygo-org/tinygo/builder.runJobs in goroutine 1
#14 81.12 	/__w/tinygo/tinygo/builder/jobs.go:123 +0x5bd
#14 81.12 
#14 81.12 exit status 1
#14 81.12 cmd/gen-uf2/main.go:10: running "go": exit status 1
#14 ERROR: process "/bin/sh -c go generate ./cmd/gen-uf2/" did not complete successfully: exit code: 1

@deadprogram
Copy link
Member

@aykevl any clues on this?

@dkegel-fastly
Copy link
Contributor

I think dgryski suggested building with race detection on to see if that catches anything, and ayke had a couple suggestions on top of that: https://gophers.slack.com/archives/CN4R2DQV7/p1711749220916969

@aykevl
Copy link
Member

aykevl commented Apr 8, 2024

Is there anybody able to provide a reproducer?

If you try to reproduce, here are a few ways to increase success:

  • Remove cached files between runs: rm ~/.cache/tinygo/obj-* (or tinygo clean but that's slower)
  • Do it in a loop (something like while true; do tinygo xxx; rm ~/.cache/tinygo/obj-*; done )
  • Don't change the number of cores, use all of the available ones. It's unlikely to reproduce when you limit tinygo to a single core (there wouldn't be a race condition on a single core).

@deadprogram
Copy link
Member

Pretty sure I have seen this occur in CI builds as well.

@scottfeldman
Copy link
Contributor Author

If you try to reproduce, here are a few ways to increase success:

  • Remove cached files between runs: rm ~/.cache/tinygo/obj-* (or tinygo clean but that's slower)
  • Do it in a loop (something like while true; do tinygo xxx; rm ~/.cache/tinygo/obj-*; done )
  • Don't change the number of cores, use all of the available ones. It's unlikely to reproduce when you limit tinygo to a single core (there wouldn't be a race condition on a single core).

I've added this step to my project's CI, after each TinyGo build cmd. So far I haven't seen anything, but I'll keep an eye on it.

@scottfeldman
Copy link
Contributor Author

Hit another one tonight. And this is with rm .cache files after each TinyGo build per @aykevl's suggestion.

12.19 /usr/local/bin/tinygo build -target nano-rp2040 -o ../../garage-nano-rp2040.uf2 -stack-size 8kb -size short /tmp/build-2086407574.go
22.97 2024/04/10 08:06:34 Error generating UF2s: exit status 1: go: downloading tinygo.org/x/drivers v0.27.0
22.97 Basic Block in function '(struct{*bufio.Reader; *bufio.Writer}).writeBuf' does not have terminator!
22.97 label %entry

@rockwotj
Copy link
Contributor

I am also seeing this

@rockwotj
Copy link
Contributor

rockwotj commented Apr 16, 2024

Duplicate of #3062?

@dkegel-fastly
Copy link
Contributor

I will admit, this bug is remarkably similar to #4206

@rockwotj
Copy link
Contributor

Ugh clearly haven't had my coffee yet - I copied the wrong issue number: #3062

rockwotj added a commit to rockwotj/redpanda that referenced this issue Apr 16, 2024
Tinygo has some race/bugs where it fails due to
tinygo-org/tinygo#4206

Add retries to mitigate.

Signed-off-by: Tyler Rockwood <[email protected]>
rockwotj added a commit to rockwotj/redpanda that referenced this issue Apr 16, 2024
Tinygo has some race/bugs where it fails due to
tinygo-org/tinygo#4206

Add retries to mitigate.

Signed-off-by: Tyler Rockwood <[email protected]>
@aykevl
Copy link
Member

aykevl commented Apr 17, 2024

Yes it is similar in the sense that it is a race of some sort, but for #3062 we found a specific cause that we fixed in #3920. The current issue seems to be a different problem.

@aykevl
Copy link
Member

aykevl commented Apr 17, 2024

To all the people reporting crashes: please provide a reproducer. I can't debug this without a reproducer, I have to see the crash happening on my own system. Getting more crash logs is near-useless, what I need is:

  • the source code (enough that I can build the exact same binary you're building)
  • the full compiler command, with all flags
  • the environment (OS, architecture, TinyGo version, etc) - use tinygo version.

@aykevl
Copy link
Member

aykevl commented Apr 17, 2024

For the record, apparently this command failed at some point in CI (CC @dkegel-fastly):

tinygo build -size short -o test.hex -target=nano-rp2040         examples/rtcinterrupt

EDIT: this doesn't seem to reproduce on my system even after many attempts. Or maybe I should leave it to run for a longer time...

@rockwotj
Copy link
Contributor

On the note of it being rare, I have seen it crop up on the order of ~1/10000 builds based on our CI stats.

@deadprogram deadprogram added bug Something isn't working core labels Apr 22, 2024
@deadprogram
Copy link
Member

via CI https://github.com/tinygo-org/drivers/actions/runs/8812492890/job/24189343381#step:8:503

tinygo build -size short -o ./build/test.hex -target=challenger-rp2040 ./examples/net/ntpclient/
Basic Block in function '(*time.Time).Second' does not have terminator!
usage: go run ./smoketest.go smoketest.txt
label %entry
  -xtensa
error: verification error after compiling package context
    	Enable Xtensa tests (default true)
exit status 1
make: *** [Makefile:13: smoke-test] Error 1

@deadprogram
Copy link
Member

I think the race condition pretty consistently appears in this check https://github.com/tinygo-org/tinygo/blob/dev/builder/build.go#L384-L386

Is it perhaps because the IR for pkg.ImportPath is not yet fully written when some other package also needs it as a dependency, and then also tries to write it?

@aykevl
Copy link
Member

aykevl commented Apr 27, 2024

I've found a reliable reproducer! Run this in the fish shell in ./tests/os/smoke:

while true; rm ~/.cache/tinygo/pkg-*; tinygo test -c -target=pybadge; end

I think the race condition pretty consistently appears in this check https://github.com/tinygo-org/tinygo/blob/dev/builder/build.go#L384-L386

VerifyModule probably isn't the problem (in fact it should only read the module), most likely the problem is introduced earlier and only detected when verifying the module.

@aykevl
Copy link
Member

aykevl commented Apr 27, 2024

Found a race condition!
I don't know whether it's the big one (edit: it's not) but it's a race so should be fixed: #4243

@aykevl
Copy link
Member

aykevl commented Apr 27, 2024

So now I have a reliable reproducer, I found that the bug does not reproduce with -race 😭 only without that flag.
My next suspect is golang.org/x/tools so I'm testing an older version now to see whether it still occurs there.

@aykevl
Copy link
Member

aykevl commented Apr 27, 2024

golang.org/x/tools seems to be the culprit, I'm bisecting between v0.14.0 and v0.15.0.

@aykevl
Copy link
Member

aykevl commented Apr 27, 2024

I think it's this commit: golang/tools@75ff53b
Almost done bisecting, I'll let this run a while to be sure (it may take a while for the bug to appear).

@aykevl
Copy link
Member

aykevl commented Apr 27, 2024

Here is the upstream bug report: golang/go#67079

@deadprogram
Copy link
Member

Here is our latest example of this bug doing its thing 🐛
https://github.com/tinygo-org/tinygo/actions/runs/8880740326/job/24381494362?pr=4252#step:14:28

@deadprogram deadprogram changed the title Strange, infrequent TinyGo compile failures core: compile failures due to SSA race condition Apr 29, 2024
@deadprogram
Copy link
Member

the go tools change in question is https://go-review.googlesource.com/c/tools/+/538358/7

@aykevl
Copy link
Member

aykevl commented May 13, 2024

Currently down to this set of packages that when compiled together leads to a race:

source_filename = "internal/testlog"
source_filename = "encoding"
source_filename = "sync"
source_filename = "context"
source_filename = "time"

Interestingly, this doesn't seem to include any reflection? (Though I haven't investigated the packages deeply).

(Still figuring stuff out, I plan on sharing my findings once I know exactly which packages are the culprit).

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
bug Something isn't working core
Projects
None yet
Development

No branches or pull requests

6 participants