A kernel bug froze my machine: Debugging an async-profiler deadlock

Great article! Just yesterday I watched a Devoxx talk by Andrei Pangin [1], the creator of async-profiler where I learned about the new heatmap support. To many folks it might not sound that exciting, until you realise that these heatmaps make it much easier to see patterns over time. If you’re interested there’s a solid blog post [2] from Netflix that walks through the format and why it can be incredibly useful.

[1]: https://www.youtube.com/watch?v=u7-S-Hn-7Do

[2]: https://netflixtechblog.com/netflix-flamescope-a57ca19d47bb

▲

jerrinot 21 hours ago | parent | next [-]

Thanks for the kind words!

Heatmaps are amazing for pattern spotting. I also use them when hunting irregular hiccups or outliers. More people should know about this feature.

	▲	kreelman 16 hours ago \| parent [-]
		That was a neat article. Great that you had the time to be curious and dig into what was going on. QEMU is quite an amazing tool. I'm kind of surprised there isn't a fairly robust kernel test around this issue, since it locks the machine down and I think the fix was to prevent a stuck CPU last time as well? It's also vaguely surprising that this hasn't been encountered more often, particularly by the https://news.ycombinator.com/user?id=everlier talking in links to this HN post about "20-30 containers" running simultaneously and occasionally locking up the machine. If you're still thinking about the bug a little, you could look over how other kernel tests work and implement a failing test around it....? I imagine the tests have some way of detecting a locked up kernel... I don't know exactly how they'd do it, but they probably have a technique. Most likely since the kernel is literally in a loop it won't respond to anything.. so starting any process, something as simple as creating any process, even one as simple as printing "Hello World!!" would fail and indicate the machine is locked. Perhaps this is one of those cases where something like UserModeLinux would allow a test to be easily put together, rather than spawning complete VMs via some kind of VM software. Again, would be interesting to know what Linux does with this kind of test.

▲

pjmlp 7 hours ago | parent | prev [-]

As someone that also has Java on the toolbox, thanks for the links.

▲

ChuckMcM 21 hours ago | parent | prev | next [-]

Question, isn't this a bug? static enum hrtimer_restart perf_swevent_hrtimer(struct hrtimer *hrtimer) { - if (event->state != PERF_EVENT_STATE_ACTIVE) + if (event->state != PERF_EVENT_STATE_ACTIVE || + event->hw.state & PERF_HES_STOPPED) return HRTIMER_NORESTART;

The bug being that the precedence of || is higher than the precedence of != ? Consider writing it if ((event->state != PERF_EVENT_STATE_ACTIVE) || (event->hw_state & PERF_HES_STOPPED))

This coming from a person who has too many scars from not parenthesizing my expressions in conditionals to ensure they work the way I meant them to work.

▲

jerrinot 21 hours ago | parent | next [-]

Wow, someone is actually reading the article in detail, that's a good feeling! In C, the != operator has higher precedence than the || operator. That said, extra parentheses never hurt readability.

▲

unsnap_biceps 20 hours ago | parent | prev [-]

Which language(s?) have || before !=/==?

	▲	anematode 19 hours ago \| parent [-]
		Likely they're confusing it with bitwise OR, since in C, a \| b == c parses as a \| (b == c), causing widespread pain.

▲

everlier 20 hours ago | parent | prev | next [-]

I'm glad to hear I'm not alone. Due to the nature of what I do, I'm often accumulating ~800-900GB of Docker images and volumes on my machine, sometimes running 20-30 containers at once starting/stopping them concurrently. Somehow, very rarely, but still quite often (once every couple of weeks) - it leads to a complete deadlock somewhere inside of the kernel due to some crazy race condition that I'm absolutely in no way able to reliably reproduce.

	▲	jerrinot 20 hours ago \| parent [-]
		It's much tougher when it's so hard to reproduce. Perhaps the NMI watchdog could help? https://docs.kernel.org/admin-guide/lockup-watchdogs.html

▲

Artoooooor 9 hours ago | parent | prev | next [-]

Ah, this is the bug that froze the system when Minecraft was running with Spark profiler mod!

▲

broken_broken_ 11 hours ago | parent | prev | next [-]

Nice article, thank you. Did you also consider using bpftrace while debugging?

I do not have much experience with it, but I think you can see the kernel call stack with it and I know you can also see the return value (in eax). That would be less effort than qemu + gdb + disabling kernel aslr, etc.

	▲	jerrinot 10 hours ago \| parent [-]
		I have no practical experience with bpftrace, so it did not occur to me. I'll give it a try and perhaps there's gonna be a 2nd part of this investigation.

▲

bluuewhale 17 hours ago | parent | prev | next [-]

Great write-up.

This kind of "debugging journey" post is gold.

▲

jerrinot 21 hours ago | parent | prev | next [-]

Author here. I've always been kernel-curious despite never having worked on one myself. Consider this either a collection of impractical party tricks or a hands-on way to get a feel for kernel internals.

▲

snvzz 20 hours ago | parent | prev [-]

Great debugging effort.

Now, with the complexity (MLoCs!) of the Linux kernel, this is definitely not the only bug to be found in there.

This is why Linux is just an interim kernel for these use cases in which we still cannot use seL4[0].

0. https://sel4.systems/

▲

themafia 16 hours ago | parent [-]

> Linux is just an interim kernel

35 years of "interim" status. Is there a roadmap?

	▲	kreelman 16 hours ago \| parent [-]
		:-) LOL !