John Gallagher

Debugging With Pipes

November 2020

Some debuggers have interfaces built around pipes, much like Bash and many other shells do. In these debuggers, as in shells, a sequence of output values from one command can be fed via a pipe, denoted by |, into a subsequent command for further processing. A number of commands can be strung together in this way to form a pipeline. Examples of debuggers which use this paradigm include Solaris/illumos's MDB and, for Linux, the new SDB written by some of my colleagues at Delphix.

There are a couple features of pipelines that make them well suited to be the interface for debugging tools:

Composition: to build a pipeline is to compose new, special-purpose command out of basic, general-purpose building blocks. Since debugging often amounts to the task of answering ad hoc questions about the state of a system, the ability to build construct commands on the fly to answer these questions is handy.
Streams: The values moved through the pipeline form a stream which can be filtered, processed, and aggregated. This makes it easy to deal with large amounts of information, as when answering queries that require, for instance, traversing large data structures.

With many other debuggers, answering such questions is often impractical. In many graphical debuggers, each dereference requires a mouse click, making it infeasible to answer questions when constructing the answer involves combing through tens or hundreds of thousands of pieces of state. The same is true for command-line debuggers which have simple expression-oriented interfaces without any sort of looping or aggregation functionality.

There are some non-piped debuggers which can be used to answer such questions, though. For instance, in GDB, users can write and execute Python scripts, which can contain arbitrary logic for examining and aggregating the in-memory state of a process. It's even possible to get an interactive Python session within GDB.

But I typically prefer a piped debugger to GDB's Python scripting when examining a process, for much the same reasons that I prefer to be dropped into a Bash shell instead of Python REPL when I log in to a troublesome machine which I need to begin debugging. Pipelines are more suited to the ad hoc tasks which arise when debugging; one-liners built from left to right are ideal for constructing queries incrementally and experimentally. The readability and error-handing facilities of a more general-purpose language are dropped in favor of making it easy to write throw-away queries of the sort written continually when investigating a thorny problem.

Example

The strengths of a piped debugger were nicely illustrated when I recently found myself using MDB to try to understand why a process was unable to allocate a 128K buffer via malloc, causing the process to panic. For reasons not relevant, the process was unable to grow its heap, but I could see from the core dump that there was still plenty of space in the existing heap available to the memory allocator (in this case illumos's libumem); only ~1.4G of the >2G heap was in use:

> ::vmem
ADDR             NAME                        INUSE        TOTAL   SUCCEED  FAIL
fffffd7ffe1da6c0 sbrk_top               1456545792   2143137792   1932229 21495
fffffd7ffe1db2c8   sbrk_heap            1456545792   1456545792   1932229     0
fffffd7ffe1dbed0     vmem_internal       444039168    444039168     52763     0
fffffd7ffe1dcad8       vmem_seg          431939584    431939584     52727     0
fffffd7ffe1dd6e0       vmem_hash          12059648     12062720        31     0
fffffd7ffe1de2e8       vmem_vmem             46200        55344        15     0
0000000000411000     umem_internal       439447680    439451648    262495     0
0000000000412000       umem_cache            90480       118784        58     0
0000000000413000       umem_hash          12891648     12902400       143     0
0000000000414000     umem_log                    0            0         0     0

I suspected that the allocation had failed because the free space in the heap was fragmented such that there was no contiguous 128K chunk of memory available. To confirm this suspicion, I wanted to get a mental picture of the free space in the heap (in particular, the free segments in the arena, to use libumem's terminology). There isn't a built-in MDB command to extract this information from a corefile, but it was fairly straight forward to roll one of my own. I started by taking the address of the struct vmem_t representing top-level arena, as displayed by the ::vmem command above, and then printing the member of the struct which represented the arena's list of free segments. The free list is represented as a struct of type vmem_freelist_t:

> fffffd7ffe1da6c0::print vmem_t vm_freelist[0]
vm_freelist[0] = {
    vm_freelist[0].vs_start = 0
    vm_freelist[0].vs_end = 0x1
    vm_freelist[0].vs_knext = libumem.so.1`vmem0+0x398
    vm_freelist[0].vs_kprev = 0
}

Next, I used the ::list command to walk over the free list. It takes the vmem_freelist_t produced by the last command and walks over the list by iteratively dereferencing the vs_knext member of the struct. The output of this part of the pipeline is a list of addresses:

> fffffd7ffe1da6c0::print vmem_t vm_freelist[0] | ::list vmem_freelist_t vs_knext
...
fffffd7ffe1daa58
fffffd7ffe1daa78
fffffd7ffe1daa98
fffffd7ffe1daab8
fffffd7ffe1daad8
fffffd7ffe1daaf8
fffffd7ffe1dab18
fffffd7ffe1dab38
...

Each of these addresses points to a vmem_seg_t representing a single free segment. I used the ::print command again to tell MDB to cast the pointers to that type, and then print out the members of the struct representing the starting and ending addresses of the free segment, formatted as decimal numbers, one segment per line.

> fffffd7ffe1da6c0::print vmem_t vm_freelist[0] | ::list vmem_freelist_t vs_knext | ::printf "%d %d\n" vmem_seg_t vs_start vs_end
...
974807040 974811136
1610952704 1610956800
930967552 930971648
848445440 848449536
1298153472 1298157568
...

Finally, I used ! to switch to Bash and do some aggregation. Everything after the ! is delegated to a Bash shell, and the output of the previous command is fed to the shell via an OS pipe. Here, I filtered out the fake segments with starting address of 0 which are used as special markers, used some awk to calculate the segment size in kilobytes, and then counted up how many segments of each size there are. The right column of the output is the size of a free segment in kilobytes, and the left column represents the number of segments of the corresponding size.

> fffffd7ffe1da6c0::print vmem_t vm_freelist[0] | ::list vmem_freelist_t vs_knext | ::printf "%d %d\n" vmem_seg_t vs_start vs_end ! grep -v '^0' | awk '{ print ($2 - $1) / 1024 }' | sort -n | uniq -c
    432 4
   4177 8
   3694 12
   3371 16
   4699 20
  13098 24
   1989 28
    460 32
    350 36
    272 40
    204 44
    165 48
     98 52
    128 56
     42 60
      8 64
     21 68
     15 72

This matched my expectations: in the 654M of free space, there were no chunks large enough to accommodate a 128K allocation. My suspicions confirmed, I was able to move on with the investigation.

Conclusion

When it comes to debugging, a piped debugger isn't a silver bullet. I still had to figure out which question to ask, and had to learn enough about libumem's inner workings to know where in its data structures I could find the information I needed.

But once I had decided what information I wanted and had figured out where to find it, MDB allowed me to extract it easily, even though it involved examining a data structure containing thousands of items. It may not be particularly elegant (I find switching back and forth between MDB pipelines and Bash pipelines particularly awkward) but it is convenient and powerful, and when in the debugging trenches, I find those traits more valuable.