Block statistics

[shwestrick]

Tracking global block usage statistics in the block allocator, by assigning a purpose to each block and keeping track of how many blocks have been allocated/freed for that purpose.

enum BlockPurpose {
  BLOCK_FOR_HEAP_CHUNK,
  BLOCK_FOR_REMEMBERED_SET,
  BLOCK_FOR_FORGOTTEN_SET,
  BLOCK_FOR_HH_ALLOCATOR,
  BLOCK_FOR_UF_ALLOCATOR,
  BLOCK_FOR_GC_WORKLIST,
  BLOCK_FOR_UNKNOWN_PURPOSE,
  ...
}

Command-line args

To see block usage statistics at runtime, you can do this:

$ <program> @mpl procs <N> log-level block-allocator:info -- <args>

The default is to sample every 1 second and log the output. To control the sample rate, use the block-usage-sample-interval parameter:

$ <program> @mpl procs <N> log-level block-allocator:info block-usage-sample-interval <T> -- <args>

Here, we pass a time T, which has a time unit suffix: s for seconds, m for milliseconds, u for microseconds, and n for nanoseconds. For example, 150m will sample every 150 milliseconds, 2500u will sample every 2500 microseconds, etc.

Logging control. This mechanism currently reuses the existing logger. Note that it can be helpful to use @mpl log-file <FILENAME> -- to output to a file rather than interleaving log messages with normal output.

Example and output description

Example output with log-level block-allocator:info block-usage-sample-interval 200m which samples every 200 milliseconds:

INFO   [P07|logCurrentBlockUsage]: block-allocator(7.200003685)
  currently mapped           167794 (= 167794 - 0)
  BLOCK_FOR_HEAP_CHUNK       111422 (66%) (= 501652 - 390230)
  BLOCK_FOR_REMEMBERED_SET   590 (0%) (= 32146 - 31556)
  BLOCK_FOR_FORGOTTEN_SET    0 (0%) (= 29892 - 29892)
  BLOCK_FOR_HH_ALLOCATOR     352 (0%) (= 352 - 0)
  BLOCK_FOR_UF_ALLOCATOR     44 (0%) (= 44 - 0)
  BLOCK_FOR_GC_WORKLIST      0 (0%) (= 458 - 458)
  BLOCK_FOR_UNKNOWN_PURPOSE  7 (0%) (= 7601 - 7594)

Timestamp. The log message begins with block-allocator(T) where T is the elapsed time (in seconds) since the beginning of the program. In this example, 7.2 seconds have elapsed so far.

Current num blocks mapped. The second line shows how many blocks are currently mapped from the OS; this number increases and decreases as blocks are mapped and unmapped. The format is <num currently mapped> (= <cumulative mapped> - <cumulative unmapped>); when blocks are released back to the OS, this will be shown in the cumulative unmapped count.

Blocks allocated/freed. The remaining lines each have the form:
<purpose> <count> <percent of currently mapped> (= <cumulative allocated> - <cumulative freed>)
For example, in the above log, there are currently ~111K blocks in use for heap chunks, which is 66% of all blocks currently mapped from the OS; cumulatively, the program has allocated ~502K blocks for heap chunks and has freed 390K of those.

Other notes

This PR includes a general-purpose "sampler" mechanism which allows for running an arbitrary function periodically. It was very helpful for sampling block usage statistics, and seems really nice in general. I think we could start using it for other purposes.

The implementation strategy is lock-free wait-free, and relies on hijacking failed limit checks (to enter the runtime system).

See runtime/gc/sampler.{c,h} for more info.

[shwestrick]

I added tracking for suspect sets and EBR. This now seems to cover all blocks in the system; I no longer see blocks allocated and freed for an unknown purpose.