Skip to content

Profiling

Where the CPU goes on the hot paths, and what holds a running service's memory.

Memory: heap profiles

With jemalloc's own profiler and jeprof; nothing of IOLake's. Every service binary's allocator, jemalloc, is built with its profiler, which stays off. Start a process with it on, and jemalloc writes heap dumps itself:

mkdir -p /tmp/jeprof
_RJEM_MALLOC_CONF=prof:true,lg_prof_interval:30,prof_final:true,prof_prefix:/tmp/jeprof/osd \
    iolake-osd ...
  • prof:true: the profiler on; it records the stack of about one allocation in every 512 KiB allocated (lg_prof_sample:19, the default).
  • lg_prof_interval:30: a dump every 2^30 bytes (1 GiB) allocated; prof_final:true one more at exit. prof_gdump:true dumps whenever the heap reaches a new high instead.
  • _RJEM_: the binaries' jemalloc is prefixed (tikv-jemallocator), so the variable is _RJEM_MALLOC_CONF, not MALLOC_CONF.

jeprof (Debian and Ubuntu: libjemalloc-dev; it needs binutils) reads a dump against the binary that wrote it, at the path that process ran it from:

jeprof --text --cum /usr/local/bin/iolake-osd /tmp/jeprof/osd.<pid>.<n>.i<n>.heap
jeprof --svg /usr/local/bin/iolake-osd /tmp/jeprof/osd.<pid>.<n>.i<n>.heap > osd.svg   # call graph
jeprof --text --base=first.heap /usr/local/bin/iolake-osd last.heap                  # what grew

A dump counts what the program asked jemalloc for, scaled up from the samples. Resident memory (process_resident_memory_bytes) also counts what jemalloc keeps but no longer uses, the page cache of mapped files, stacks and code, so the two differ; a dump that grows is a program that grows.

For example, a release aio of 6 OSDs under 64 KiB PUTs: 1 GB live, of which redb's page cache held about 700 MB while the OSDs checkpointed their index (DiskIndex::flush_frozen into redb's commit).

The soak (deploy/chaos) records every service's resident memory in each 5-minute progress line (rss_mb), and each service's peak over the run in summary.json. A soak VM has 3 GiB: a service that leaks shows there long before the kernel kills it, and the run to repeat with the profiler on is the one whose peak climbs.

What the profiler costs while off. Measured on the lab host (one NVMe host, a release aio of 6 OSDs at 4+2, 64 KiB objects, 64 in flight, 20,000 PUTs then their GETs; the builds alternated, two runs each):

Build PUT/s GET/s Peak resident
jemalloc 5.3.0, no profiler (before the profiler was built in) 710, 717 9,660, 11,190 6.6, 6.7 GB
jemalloc 5.3.1, profiler built in, off 715, 715 11,060, 10,600 6.3, 6.3 GB

No difference beyond the runs' own spread.

CPU

Measured on dedicated cloud machines (iolake-infra: ./bench profile records a running service with perf and brings back a flamegraph). Each pass ends in fixes or roadmap rows.

Pass 1: 64 KiB PUTs, six Azure VMs, 2026-10-07

Set-up: the six-VM cluster of the performance page (Arm, 4 vCPUs each), warp sending 64 KiB PUTs at 64 concurrent requests. On one storage node, the OSD and the gateway, and the meta leader, each recorded for 30 s at 499 Hz (perf record -g). Percentages are of that process's samples, inclusive unless marked self.

Before

Process Where Share
gateway compiling a regex for the Authorization header, on every request (auth_middleware::parse_authorization_header) 27%
gateway MD5 of the body, for the ETag (self) 3%
OSD GetStatus scanning every ObjectMeta it holds to count objects at risk (UsageTracker::safety), on every gateway's poll 20%
OSD its metadata store: WAL appends, the small-object path's batch of shard and metadata, checkpoints 49% (including the scan)
meta redb commits and reads, its Raft log about 25%

Fixed

  • The regex: the SigV4 header is parsed by hand, by one parser in iolake-auth. Policy wildcards, also turned into a regex per evaluation (and wrongly: +, (, [ and | were read as regex syntax), are matched by a glob matcher.
  • The scan: each OSD keeps its count of objects at risk and counts again only after a minute, or when the nodes up change; one count at a time. Every gateway polls every OSD every 30 s (every 5 s with quotas): the scan grew with the objects held and would, at millions of objects an OSD, never stop.

Throughput on a fresh cluster, before → after both fixes: GET 4 KiB +23%, GET 64 KiB +16%, PUT 4 KiB +14% (p99 262 → 80 ms), PUT 64 KiB +10%; 4 MiB unchanged (bound by network and drives).

After

Process Where Share
gateway the PUT itself (put_object), erasure coding 4% 20%
gateway MD5 for the ETag (self; in software on Arm) 4.5%
OSD the small-object batch (store_with_small_shard): WAL append and its fsync 24%
OSD checkpoints: the memtable into the index file 15%
meta redb commits 8%, Raft log appends 7%, applies 5% about 25%

No single hotspot is left outside the storage engines: the OSD's metadata store is the next place to gain, which is what putting the OSD's engines behind interfaces (MetaIndex, and an alternative behind it) is for.

Next

  • The OSD's metadata store behind MetaIndex: the same profile with another MetaIndex implementation.
  • MD5 on Arm: an implementation with Arm instructions, or ETags that don't need it where S3 allows.
  • The same pass for GETs, a drive's rebuild and listings.