Profiling the Program I Wrote
I was certain my parser spent its time converting decimal numbers. Certainty is a useful indication that I should profile before touching anything.
The tools include a real-time sampling profiler named 6prof. Despite the name, it also understands the other supported architectures. The interface is still moving, so this is a note about the weekly release on my desk rather than scripture.
I let the profiler start the real program:
$ 6prof ./logsum
46.8% bytes.(*Buffer).Write
21.1% runtime.memmove
8.7% parseNumber
On Linux/amd64 I can ask it to write pprof data, provided the program was linked with 6l -e:
$ 6prof -P cpu.prof ./logsum
The exact output format varies, but the result was unambiguous. My “efficient” reporting path repeatedly grew a byte buffer. Number parsing was visible and not remotely the first problem.
Preallocating a reasonable output buffer removed most growth and copies. Runtime dropped by roughly a third on the same input. Replacing the decimal parser with a clever version afterward produced noise-sized improvement, so I reverted it. Clever code that cannot beat measurement is just decorative risk.
Sampling has limits. A short run may not gather enough samples, and compiler optimization can make line attribution odd. This profiler samples threads while they are running, asleep, or waiting for I/O, so a hot entry may be telling me about waiting rather than arithmetic. I feed several seconds of representative data and repeat runs. I also keep wall-clock timing around the complete operation because users do not experience percentages.
Input matters just as much. A profile from the tiny sample used by unit tests mostly measures startup and can confidently direct optimization toward irrelevant code. I use a captured workload large enough to reach steady behavior.
The young runtime itself appears in profiles. Garbage collection, allocation, copying, and scheduler work are part of the program’s cost, even if I did not type those function names. They should not automatically be dismissed as profiler clutter. Often they point back to an allocation pattern I control.
Now I reproduce, time, profile, change one thing, and time again. This lacks the emotional satisfaction of immediately rewriting the function I dislike. Annoyingly, it makes the program faster.