Tracking down a rogue kernel_task

I'm one of the lucky ones who have the pleasure of working on a 2014 Mac Pro (yes, the trash can) every day. I love it to bits. It's blazingly fast, never misses a beat and no matter what I feel like doing, resources are never a constraint. However, my particular Mac Pro has been a bit wonky from the start. Ever so often (somewhere between once a week and three times a day), the kernel will start spinning out of control on one of the cores. As a side effect, applications will start hanging, and the system basically becomes useless until I force a reboot (once the kernel finds itself in an endless loop, a graceful shutdown goes out the window — the best you can do is try to issue a sync to make sure the file system will come back up in a reasonable state, but with HFS+, you never really know.)

The dreaded kernel_task at 100 % CPU usage

The usual remedies haven't helped. Reset this, reset that, full reinstall and so on. For the longest time, then, I've just ignored the issue. It wasn't sufficiently annoying to warrant working from my laptop for however long it would take to fix the issue. However, after a series of all too frequent incidents in the last couple of weeks, I decided to take affair. Given that I haven't been able to isolate the trigger of the problem, I decided to try and gather as much data as I could, as searches on the matter of kernel_task running at 100 % yielded so many different explanations, none of which seemed directly applicable to my situation. Giving Apple's support a call and saying "I occasionally get kernel_task stuck on a core" would probably not be of much use to anyone, then. What I needed to do, was to figure out exactly what was going on in the kernel at these times.

Luckily, Mac OS X ships with every developer's wet dream, dtrace. Even better, Brendan Gregg made a simple Perl script back in 2006 to sample calls in the kernel using dtrace, which almost works today. Given the "almost" part, and the fact that I like more readable output for debugging, I decided to whip up a quick improvement in Go, osxkerneltracer, which I've been using for the past couple of weeks to gather evidence whenever this problem occurred.

On my machine in its normal state, the output looks something like this, after sampling for 5 seconds:

Module            | Method                                                 | Calls |      Share
------------------+--------------------------------------------------------+-------+-----------
kernel            | machine_idle+0x1fd                                     | 49756 |  98.4819 %
kernel            | 0xffffff801cd52880+0x313                               |   240 |   0.4750 %
kernel            | processor_idle+0xc5                                    |   101 |   0.1999 %
kernel            | processor_idle+0xb4                                    |    41 |   0.0812 %
kernel            | do_mfence+0x3                                          |    27 |   0.0534 %
kernel            | dcache_incoherent_io_store64+0xab                      |    23 |   0.0455 %
kernel            | ipc_mqueue_post+0x227                                  |    18 |   0.0356 %
kernel            | machine_idle+0x1ff                                     |    18 |   0.0356 %
kernel            | 0xffffff801cd52880+0x3bf                               |    17 |   0.0336 %
kernel            | processor_idle+0xd9                                    |    10 |   0.0198 %
kernel            | processor_idle+0xab                                    |     7 |   0.0139 %
kernel            | user_trap+0x9f                                         |     7 |   0.0139 %
kernel            | wait_queue_wakeup_all+0xb9                             |     7 |   0.0139 %
AMD7000Controller | _OSReadInt32(void const volatile*, unsigned long)+0x1a |     6 |   0.0119 %
kernel            | thread_block_reason+0xbe                               |     6 |   0.0119 %
kernel            | processor_idle+0xbb                                    |     5 |   0.0099 %
kernel            | 0xffffff801cd6acc0+0x2d0                               |     4 |   0.0079 %
kernel            | __bzero+0xb                                            |     4 |   0.0079 %
[...]

This is basically what you'd expect from a system at almost idle; most of the time in the kernel is spent in an idle function — in this case, the kernel's machine_idle function (as a side note, for a kick, read up on how this actually works.) When things go awry, it's always the same thing that happens. That innocent 32 bit read function to the AMD 7000 controller you can see in the call trace above suddenly represents roughly 6.25 % of the calls traced — the full share of one of the 16 hyper-threaded cores on this machine. In other words, the kernel seems stuck in an endless loop trying to read data from the graphics controller.

With this data in hand, I've now contacted Apple support, who immediately bumped the issue to a guy who understood what not only a kernel is, but also knew that dtrace existed (in other words: data expedites support when dealing with intermittent issues.) I agreed to ship a bunch of logs for them to look at before taking the next step of actually taking the machine in, and I'm now waiting to see what they come back with.

If you're experiencing similar, intermittent issues, I suggest you do the same thing. It'll save you and probably also the immediate support staff a lot of time fumbling in the dark and will much more easily get your issue bumped to the right level, if it's actually Apple's problem.

November 11, 2014 | Permalink


Source code optimization

For some reason, I wound up reading about compilers' use of vectorization in optimizing code yesterday, and I came across Felix von Leitner's pretty interesting presentation from 2009, "Source Code Optimization".

While I knew that compilers are generally good at optimizing these days, I had no clue just how good they've become. This basically also means that a lot of the "general wisdom" I came up with when writing C and C++ no longer really applies, and even more so, that more readable code often seems to produce equally good or even more optimized code than most attempts at being clever. For C(++) code then, this means that we not only can but almost have to mentally shift from being "clever" to being concise when writing code – a development that's been helped greatly by C11 and C++11.

If you write any C or C++ on a regular basis, I strongly suggest you add this presentation to your list of annual reminders.

October 19, 2014 | Permalink


The ultimate ops job

I don't often care to broadcast anyone's job openings. Most of the time, it's someone looking for the stealth Japanese warrior equivalent of the coding Albert Einstein anyway. But, if you're in Europe and have a knack for ops, what might just be the ultimate ops job has just opened up at my previous employer and good friends, 23.

Back when I was working at 23 a little over two years ago, they were already among the larger Northern European Web outfits on pure traffic and volume. It was a challenge to develop and run even back then – a challenge, I learned a heck of a lot from. Since then, they've grown significantly while keeping a pretty impressive product edge over the competition, which means that the person to take over ops at 23 is being served one hell of an awesome challenge in the most non-corporate of environments (I got away with flip flops for a long time), working alongside the product people.

The challenges aside, I can personally vouch for the fact that the person to take the job will be working alongside an awesome bunch of people. From your quintessential hipster dad through to your creative Polish accountant, the whole lot is both lovely and ambitious, with a culture most companies should be envious of.

So, allow me to make an exception here: if you're looking for an ops job that's going to teach you a hell of a lot about running Web software at scale and throw challenges at you every day while getting to work alongside a brilliant bunch, you should seriously have a chat with the guys at 23. The only downside? You might be exposed to something I built years ago. It probably isn't pretty. Don't say you weren't warned.

October 10, 2014 | Permalink


Smart working

Startup culture is awash with the heroisation of burning the mythical midnight oil with the 60 or 70 hour work week being a badge of honor — the road to success. Slowly, however, that trend is changing — at least among people who've actually done those stupid hours — and while I'm embarrassingly still working way too many hours than is any kind of good, evidence keeps indicating that I really need to stop. Not only evidence in terms of feeling unproductive at times, but actual sort of scientific evidence.

I came across one such piece of evidence today in CamMi Pham's post "7 Things You Need To Stop Doing To Be More Productive, Backed By Science". For the post, she has done a couple of very tangible charts (which seem to correlate well with other data I've found) showing the effective productivity of weeks of working 50 and 60 hours respectively. Truth be told, the numbers are scary — if the charts are to be taken at face value, the productivity gain from a 50 or 60 hour work week evaporate after only 9 and 8 weeks respectively:

Productivity over overworking duration - by CamMi Pham

I probably need to be smart and go home "early."

July 30, 2014 | Permalink


Please admit defeat

A year and a half ago, I wrote about just how unimpressive and uninteresting HTTP 2.0 is. At that time, I called out the IETF on the decision to just repackage SPDY, and while I got a bit of flak from a few of the people involved, nothing really seemed to change. Since then, not much has happened, to be honest. The working group is mostly still just bickering about exactly what HTTP 2.0 is supposed to be, rather than coming up with any concrete solutions.

However, it seems like the working group is slowly starting to feel the pressure of releasing something, as Mark Nottingham today posted a very interesting entry to the mailing list:

The overwhelming preference expressed in the WG so far has been to work to a tight schedule. HTTP/3 has already been discussed a bit, because we acknowledge that we may not get everything right in HTTP/2, and there are some things we haven’t been able to do yet. As long as the negotiation mechanisms work out OK, that should be fine.

In other words, the working group seems to be realising that they've gotten nowhere in years. But, rather than admitting that they're stuck and need to start from scratch, they're just moving to push on through with a new HTTP standard that's subpar at best, and then fix it in a newer version. While I generally applaud people taking incremental steps, HTTP 2.0 is not only nowhere near incremental, but HTTP is also no laughing matter. HTTP 1.0 has been in active use since 1996 – it's superset, HTTP 1.1, since 1999 – so to think that we can just push through and adopt a crummy version 2.0 and then fix it later is absurdly naïve at best. I'm rendered virtually speechless by the fact that the supposedly best people in the industry to undertake this task can have such a short sighted stance on HTTP – they, of all people, should know just how bad technical debt is for the industry to be lugging around.

Luckily, there's at least one person on the mailing list who maintains an actual implementation of HTTP; Poul-Henning Kamp. While Kamp has been a general opponent of a lot of parts of HTTP 2.0 for the last couple of years, Nottingham's post finally prompted Kamp to call the working group out on their crummy job:

So what exactly do we gain by continuing?

Wouldn't we get a better result from taking a much deeper look at the current cryptographic and privacy situation, rather than publish a protocol with a cryptographic band-aid which doesn't solve the problems and gets in the way in many applications?

Isn't publishing HTTP/2.0 as a "place-holder" is just a waste of everybody's time, and a needless code churn, leading to increased risk of security exposures and failure for no significant gains?

The rhetorical nature of the wording aside, Kamp hits the nail on the head. Going down the path that Nottingham seems to be indicating would mean nothing but pain for the entire industry as a whole. So, I can only echo the ending words of Kamp:

Please admit defeat, and Do The Right Thing.

May 26, 2014 | Permalink