asyncio hides who called your slow query. Datadog's profiler fix: memcpy and a SIGSEGV handler

// the short version

A sampling profiler takes a snapshot of each thread's call stack every few milliseconds, and the function on top of the most snapshots is where the CPU time goes. In asyncio code that stops being enough: every task has a stack of its own, so a flame graph can show time spent in a Cassandra query without the request that led to it.

// what to take away

• A sampling profiler copies each thread's call stack many times a second, but in asyncio every task has a stack of its own, so Datadog's profiler tracks which task is awaiting which and places each task's frames on top of the task waiting on it.
• Reading every task through process_vm_readv cost a system call per small object, and with a task per request the profiler throttled itself down to one sample a second.
• Because the profiler runs inside the process, it now copies with memcpy under a SIGSEGV handler armed only during the copy: a rare fault jumps back and drops one sample, and overhead fell more than 60% across Datadog's own services.

// transcript

Datadog made its Python profiler cheaper by letting it segfault. A profiler is the tool that tells you which functions your service is spending its CPU on, so when a deploy makes everything slower, you know exactly which one to fix. Many times a second it takes a snapshot of the call stack, the list of functions that are running right now, and whichever function shows up in the most snapshots is where the time is going. It runs in production beside your code the whole time, so every bit of CPU it burns is CPU your service doesn't get, and that cost is its overhead. Datadog's trouble started with asyncio, where one request is split across many small tasks, and every task keeps a call stack of its own. A snapshot could show time going to a database query without showing which request asked for it, so Datadog taught the profiler to follow which task is waiting on which, and stitch the pieces back into one stack. To do that it has to read every task's memory on every snapshot, and it was reading through a system call, a request to the kernel that returns an error, instead of crashing, if Python has already freed that memory. Each call is a trip into the kernel, though, and a busy server holds a task for every request, so the profiler got expensive enough that it throttled itself down to one snapshot a second, which tells you almost nothing. The profiler lives inside the same process as your code, so it can skip the kernel and copy those bytes directly, which is far cheaper, with one catch, if Python frees the memory halfway through the copy, the whole service dies with a segfault. So Datadog lets it happen and catches it, with a handler for that crash signal that jumps back to just before the copy, the copy reports that it failed, and the profiler throws away that one snapshot and carries on. Faults are rare, because the memory lives far longer than the instant a copy takes, and with two smaller fixes, the profiler's overhead on Datadog's own services fell by more than 60%. It used to pay on every read to prevent a crash that almost never comes, and now it only pays when one does.