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

Posted by bluestreak 18 hours ago

Counter106Comment18OpenOriginal

Comments

Comment by SerCe 17 hours ago

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

Comment by jerrinot 17 hours ago

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.

Comment by kreelman 12 hours ago

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.

Comment by pjmlp 2 hours ago

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

Comment by ChuckMcM 17 hours ago

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.

Comment by jerrinot 16 hours ago

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.

Comment by unsnap_biceps 16 hours ago

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

Comment by anematode 15 hours ago

Likely they're confusing it with bitwise OR, since in C, a | b == c parses as a | (b == c), causing widespread pain.

Comment by Artoooooor 5 hours ago

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

Comment by everlier 16 hours ago

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.

Comment by jerrinot 15 hours ago

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

Comment by broken_broken_ 7 hours ago

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.

Comment by jerrinot 6 hours ago

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.

Comment by bluuewhale 13 hours ago

Great write-up.

This kind of "debugging journey" post is gold.

Comment by jerrinot 17 hours ago

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.

Comment by snvzz 16 hours ago

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/

Comment by themafia 12 hours ago

> Linux is just an interim kernel

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

Comment by kreelman 12 hours ago

:-) LOL !