A quadratic loop hid in our observability agent

PHP has no background thread. A worker handling a request cannot run a
timer, and everything it learned dies when the request ends — so an agent that
wants to report aggregated numbers has two bad options and one reasonable one.

The bad options are sending a payload per request, which at 800 requests a
second is 800 HTTP calls a second to report data whose entire point was that it
had been aggregated, and keeping nothing, which is not an option at all.

The reasonable one is shared memory. Each request writes its window into APCu
under a key of its own; one request per interval collects them all, merges them
and sends a single payload. The merge is lossless — DDSketches union exactly —
so the percentiles are what a single process measuring everything would have
reported.

That design was right. The implementation had a hole in it.

The cap that cost more than what it capped

A collector that has been unreachable for an hour must not fill the shared
memory segment the application's own cache lives in, so the buffer has a
ceiling. Enforcing it looked like this:

$count = 0;
foreach (new APCUIterator('/^sixty:w:/', APC_ITER_KEY) as $ignored) {
    if (++$count >= self::MAX_PENDING) {
        return false;
    }
}

Read that with the flush interval in mind. Every request counts every pending
window. The number of pending windows is the number of requests since the last
flush. The work per request therefore grows with the traffic between flushes,
and the total work between flushes grows with its square.

At ten pending windows it is invisible. We measured it at two thousand:

pending windows	cost per request
10	~12µs
2,000	168µs

Nothing about this shows up in a test suite. Every unit test has an empty
buffer. Every manual check has a handful of requests. It only appears on a busy
service — which is to say, on the service that installed a performance agent
because it cared about this.

The fix is four lines

$pending = apcu_inc(self::PENDING, 1, $created);
if ($pending !== false && $pending > self::MAX_PENDING) {
    apcu_dec(self::PENDING, 1);
    return false;
}

apcu_inc is atomic, so two workers finishing in the same microsecond cannot
lose each other's increment — which was the reason the count was being derived
from the keys in the first place. Deriving state is a good instinct. It is a bad
one when deriving it is O(n) and the n is your traffic.

What we changed after that

The same benchmark found two more, both in the flush:

The merge was superlinear. It folded sketches pairwise — decode the
accumulated blob, merge the next one in, encode it again — so merging N windows
performed N encodes of a sketch that was itself growing. 112µs per window at two
hundred. Decoding each blob once, accumulating into objects and encoding at the
end made it linear, and keeping the first window's bytes as a string until a
second window turns up skips the round trip entirely for operations that appear
only once.

The sketch codec was the hottest code in the agent, at 2.6µs to encode. A
method call per varint and six pack() calls for the header, ten times a
request. Inlined, and packed in one call, it is 1.2µs — with a test comparing
the bytes to fixtures written by the JavaScript implementation, so "identical"
is not an opinion.

Where it ended up

	before	after
measuring a 4-span request	13.0µs	11.4µs
draining it to a payload	22.0µs	15.9µs
its share of the interval flush	35.0µs	17.0µs
total per request	71µs	44µs

All of it CPU time from getrusage rather than wall clock, because the
machine was busy and wall clock would have measured the machine.

Of that, 11µs happens before the response is sent. The rest runs after
fastcgi_finish_request(), when the reader already has their page.

The part worth keeping

We did not find any of this by reading the code. We found it by writing a
benchmark that measured the whole path, including the parts that only run once
per interval, and then ablating it until each microsecond had a name.

One hypothesis we tested was wrong in a useful way: buffering Sketch objects
instead of base64 strings, on the theory that PHP's serializer is C and our
varint codec is userland. It is ten times worse — apcu_store of an object
is 11µs against 1.1µs for the encoded array, because PHP writes 402 bytes of
class metadata where the sketch is 76. That measurement took four minutes and
saved a day of building the wrong thing.