ContentsThe library

Reading a Profile Honestly

The Function Holding Ninety Per Cent of the Time Does Nothing, and the One Doing the Work Holds Four Per Cent

Last timeHow Many Samples Is Enough

A profile has two time columns and they answer different questions. Reading the wrong one sends you to a function that is innocent or to one that cannot be fixed.

The two columns

Every profiler prints two numbers against each function and they are routinely

confused, so it is worth stating each one precisely.

Self time is the number of samples in which this function was the one actually

executing. Its own instructions, not anything it called.

Total time is the number of samples in which this function appeared anywhere on

the call stack, whether it was running or waiting for something it called to

return. Total time includes self time, and for a function that mostly calls

other things it is much larger.

FIG 1One profile, both columns
self time, per centtotal time, per cent
handle_request194
process_batch291
transform_record488
normalise_text7171
write_output1212
read_config89
The two marked cells are the two answers the profile offers. The function at the top of the total column has one per cent of its own time and nothing in it worth changing: it is a coordinator. The function doing the work is fourth in the total column and first by a wide margin in the self column. A reader looking at only one of these columns goes to the wrong place, and which wrong place depends on which column.

When self time is the answer

The self column answers one question: which function is spending the most time

executing its own code. When the fix is to rewrite some code, this is the

column that finds it.

FIG 2Where the time sits in a call tree
The totals do not add to anything meaningful because each level counts everything below it. Reading downwards until self and total diverge, then looking at what sits under the divergence, is the single most useful habit when reading a tree.

The condition to check alongside a high self time is the call count. A function

with seventy per cent of self time and a thousand calls is genuinely expensive

per call, and the loop inside it is worth examining. The same seventy per cent

over fifty million calls is a different finding entirely, which brings us to

the other column.

The lesson stops here

4 more paragraphs to go

You have read the opening. The rest of the argument, the problems that check whether it landed, and the lines worth keeping at the end all come with a plan.

The first lesson of every course in the library reads the whole way through, free, so you can see exactly what the rest of them are.

See the planThe contents

This is the reading half

Starting the course gives you your own copy of it. Every idea on every page has problems standing under it, marked with a reason rather than a tick, and any sentence you do not believe can be opened and argued with. None of that can happen on a page nobody owns.

The contents

The rest of this course

  1. 01It Is Slow Is Not a Measurement, and Profiling Before You Have One Wastes the Week
  2. 02One Profiler Interrupts a Thousand Times a Second and Guesses, the Other Watches Every Call and Changes the Answeropening only
  3. 03The Function at Number Seven Received Nine Samples, Which Means You Know Almost Nothing About Itopening only
  4. 04The Function Holding Ninety Per Cent of the Time Does Nothing, and the One Doing the Work Holds Four Per Centyou are here
  5. 05The Same Function Is Cheap in Two Places and Ruinous in the Third, and the Flat List Shows One Numberopening only
  6. 06Three and a Half of the Four Seconds Are Invisible, Because the Profiler Only Looks When the Program Is Runningopening only
  7. 07The Sample Landed Three Instructions After the One That Was Slow, and the Function It Blames Does Not Exist Any Moreopening only
  8. 08The New Version Is Eight Per Cent Faster, and So Is the Old One If You Run It Enough Timesopening only

Read alongside