Investigating a SIGBUS in a Go program
I have been happily using Gokrazy on an old Raspberry Pi.
Go(ing)krazy on a Raspberry Pi (Model B)
One of the package that I use is a time series database called VictoriaMetrics (similar to Prometheus).
This setup runs pretty well and it gathers every minute:
- temperature in every room (via the FRITZ!DECT 301)
- electricity on some appliances (via Shelly Plug S)
- Internet connectivity statistics (via FRITZ!Box)
However, when I repeatedly looked at some metrics (using Grafana), VictoriaMetrics sometimes encountered a fatal error:
The program restarted automatically and the next metric retrieval was fine. So there was a bug, but I could live with it (and I did for a time).
Digging into the code
The panicking part of the code looks at all elements of a slice of []float64 and checks if all of them are Not a Number (NaN). The panic happens in the math.IsNaN function, which is a one-liner: return f != f
Reading a bit about SIGBUS, it means
that a process is trying to access memory that the CPU cannot physically address
Bus error on Wikipedia (CC BY-SA 4.0)
printf() debugging
Looking up on the Internet, I saw no reported bug that looked like mine and decided to dig further. I made a clone of the VictoriaMetrics repo and tried "The most effective debugging tool" from Brian Kernighan, "Unix for Beginners" (1979).
The most effective debugging tool is still careful thought, coupled with judiciously placed print statements.
Adding a defer statement did not work, trying to print the value of the float64 also crashed before having the chance to have the value printed.
I also printed the address of the float64: it worked, but I didn't see anything suspect (the address looked legit).
core dump analysis
Since the bug appeared to be low-level, I thought of generating a core dump. It wasn't trivial, because, by default, Gokrazy does not provide shell access out of the box. After installing breakglass and busybox, I was able to get a core dump, by running:
The hard part was analyzing the core dump. I couldn't easily install a debugger on my Raspberry Pi, so I transferred it to my main machine.
- Opening it with delve (the debugger of choice for go) did not work, since ARM6 (32 bits) is not a supported platform.
- Opening it with gdb did not work as well, because of the platform difference
- Opening it with gdb-multiarch did work! (Thanks to the Arch User Repository for an easy installation)
Looking at the stack traces and register values, I wasn't able to find anything interesting (it was even disturbing that the stack trace was not similar to the one printed during the panic).
dmesg reading
The next day, it occurred to me that the Linux kernel might have more information regarding the crash. I ran dmesg and got a message looking like this (reconstructed from various Internet reports):
I then understood what was going on: the alignment exception was complaining about the address 0x2eb4dbb, which is 48975291 in decimal.
This number looks odd (pun intended), because a float64 is 8 bytes large, and its address should be a multiple of 8 (which 48975291 is obviously not).
I checked again using printf() debugging and sure enough the panic only happened when the float64 address was not a multiple of 8 (i.e., was misaligned).
golang digging
Now that the bug was identified, I had to understand how it could be that a float64 was misaligned. The Go Specification is very clear, that float64 are guaranteed to be aligned by 8. So I thought that I had found a bug in the Go compiler, how exciting!
Size and alignment guarantees (The Go Programming Language Specification)
I prepared a detailed bug report and looked around for similar issues. I quickly found another issue for a sigbus fault on ARM.
cmd/link: sigbus/segfault on ARM using AzCopy · Issue #38331
At the end of my bug report, I added a link to this issue and wanted to add a reason why my report was different. I inspected closely the issue and saw that they were using unsafe pointers. Upon writing something like "related issue #38331: unsafe pointers are used", I thought that I should better check that my program wasn't using unsafe pointers...
VictoriaMetrics debugging
I then saw that the []float64 slice was being constructed using unsafe pointers! It was quite sad that I didn't find a bug in the Go compiler, but I was quite happy that I could solve the issue myself. I adjusted the code to perform alignment adjustments in case of misalignment, and everything has been running smoothly since then!
Pull request to fix the alignment panic in VictoriaMetrics
Conclusion
Next time that I debug a low-level issue, I will remember to look at the kernel messages first (dmesg). It would have spared me a lot of trouble with generating and inspecting core dumps (which didn't help me in the resolution).
And remember to be extra careful when using the unsafe package (as the name helpfully reminds everyone).
📆 2023-03-09