runtimeanalyz.ing

← Runtime Analysis

What recording costs, and the settings that change it

Recording takes CPU on every call, memory for every distinct route through your code, and disk for what it writes. This page gives the measured cost of each and the settings that lower it.

Every figure on this page was measured on 5 October 2026, using Ruby 3.4 with no JIT, on an Apple M-series laptop running macOS. The scripts that produced them are in the gem's benchmark directory, and how these were measured describes the runs.

A large suite

Redmine's test suite is 5,917 tests in one process. Recording its app and lib directories wraps 11,382 methods, and the suite calls them 20.2 million times.

Time to run the suite, in seconds of CPU
Not recording 97 s
Tier 1 112 s +15.9%
Tier 2 111 s +14.5%
Tier 3 117 s +21.1%
Tier 4 117 s +20.4%
Tier 4, adaptive 109 s +12.3%

The grey part of each bar is the suite itself and the coloured part is the recorder. The thin line is the spread between the fastest and slowest of 3 runs. Recording at tier 1 used 15.9% more CPU than not recording, and tier 4 used 20.4% more. Measured by wall clock, the suite took 6.3% more time at tier 1 and 7.5% more at tier 4. The two measures differ because the suite spends about half its time waiting, and because the recorder writes on a thread of its own, so part of its CPU time is spent on a second core.

Peak memory of the process
Not recording 457 MB
Tier 1 540 MB +83 MB
Tier 2 518 MB +61 MB
Tier 3 552 MB +94 MB
Tier 4 527 MB +70 MB
Tier 4, adaptive 555 MB +98 MB

The process peaked at 457 MB with no recorder and at 540 MB recording at tier 1, which is 83 MB more. The difference between one tier and another, or between adaptive mode and recording every call, is smaller than the difference between two runs of the same configuration. Memory follows the number of distinct routes, which the memory section explains.

Size of the recording on disk
Tier 1 551 MB 20.6 million rows
Tier 2 586 MB 20.7 million rows
Tier 3 1,420 MB 40.9 million rows
Tier 4 1,420 MB 40.9 million rows
Tier 4, adaptive 53 MB 1.4 million rows

The settings change disk use more than they change CPU or memory. Tier 1 wrote 551 MB, tier 4 wrote 1.4 GB, and tier 4 in adaptive mode wrote 53 MB.

Redmine CPU time Range Wall clock Peak memory On disk Rows
Not recording 97.0 s 219.1 s 457 MB
Tier 1 +15.9% +13.8 to +16.1% +6.3% 540 MB 551 MB 20.6M
Tier 2 +14.5% +14.3 to +16.4% +5.5% 518 MB 586 MB 20.7M
Tier 3 +21.1% +20.0 to +21.2% +7.7% 552 MB 1.4 GB 40.9M
Tier 4 +20.4% +20.4 to +21.3% +7.5% 527 MB 1.4 GB 40.9M
Tier 4, adaptive +12.3% +11.9 to +12.4% +5.1% 555 MB 53 MB 1.4M

Every recorded run passed and failed the same tests as the unrecorded suite. One tier 2 run of 3 dropped 1 of its 20.7 million rows, and the other runs dropped none.

A small suite, and the same suite with its gems

Campfire, the Rails chat application from 37signals, has 407 tests, which make 28,728 calls into its app and lib. Recording them added between 0.3% and 1.3% to the suite's CPU time, which is about as much as two runs of the same configuration differ by.

The same suite can also be recorded with every gem in its bundle, Rails included, by starting the recorder before Rails loads. That is 13.4 million calls, on about 3.3 million distinct routes, and it costs much more in CPU and in memory than recording the application's own code.

Campfire: time to run the suite, in seconds of CPU
Not recording 30.3 s
Tier 1 30.5 s +0.3%
Tier 4 30.4 s +0.8%
Tier 4, adaptive 30.5 s +1.3%
Tier 1, gems too 63.6 s +110.7%
Tier 4, gems too 82.3 s +171.8%
Tier 4, adaptive, gems too 68.9 s +128.2%
Campfire: peak memory of the process
Not recording 272 MB
Tier 1 301 MB +29 MB
Tier 4 300 MB +28 MB
Tier 4, adaptive 288 MB +16 MB
Tier 1, gems too 859 MB +587 MB
Tier 4, gems too 908 MB +636 MB
Tier 4, adaptive, gems too 942 MB +670 MB
Campfire CPU time Range Wall clock Peak memory On disk Rows
Not recording 30.3 s 31.7 s 272 MB
Tier 1 +0.3% −0.1 to +1.7% +0.8% 301 MB 0.9 MB 38,052
Tier 4 +0.8% +0.1 to +1.2% +1.0% 300 MB 1.9 MB 68,311
Tier 4, adaptive +1.3% +0.4 to +1.7% +6.0% 288 MB 0.4 MB 11,207
Tier 1, gems too +110.7% +105.4 to +111.3% +91.2% 859 MB 563 MB 16.8M
Tier 4, gems too +171.8% +165.9 to +176.3% +151.3% 908 MB 1.1 GB 30.3M
Tier 4, adaptive, gems too +128.2% +127.4 to +128.6% +113.7% 942 MB 416 MB 10.3M

Recording the gems is off by default and is meant for when you need to see inside one. It costs this much because nearly every fourth call is on a route the recorder has not seen before, and those calls go through Ruby. The memory section has the detail.

A server under traffic

A test suite runs as many routes as it can, once or twice each, and stops. A server runs most of its routes in its first minutes and then repeats them, so a suite overstates what adaptive mode costs a server. To measure a server, Redmine ran in production mode under Puma, as one process with five threads, on a database containing two years of a tracker's history: 300 projects, 19,836 issues, 27,411 changes to them and 3,157 wiki pages.

A script sent it 8 actions a second for 15 minutes, each at its scheduled time whether or not the server had answered the earlier ones. The 7,200 actions are a fixed list drawn in advance: issue pages, filtered lists, edits, new issues, searches, the wiki and the JSON API, with most of the activity on a few projects, issues and people. To serve them, an unrecorded Redmine used 38% of one core and made 98.7 million calls into its app and lib.

Distinct routes the server had seen

Minutes into the run. Routes.

These figures as a table
Minute Tier 4
0:30 20,642
1:00 22,171
1:30 25,366
2:00 26,300
2:30 26,499
3:00 26,825
3:30 26,864
4:00 26,942
4:30 26,950
5:00 26,959
5:30 26,987
6:00 27,005
6:30 27,213
7:00 27,227
7:30 27,227
8:00 27,229
8:30 27,272
9:00 27,280
9:30 27,314
10:00 27,328
10:30 27,328
11:00 27,328
11:30 27,331
12:00 27,332
12:30 27,332
13:00 27,332
13:30 27,498
14:00 27,498
14:30 27,499
15:00 27,499

The server had seen 22,171 routes after one minute, 26,959 after five and 27,499 after 15 minutes. The memory that recording adds grows with the number of routes. Over the last five minutes the recorded server used about 104 MB more than the unrecorded one at tier 4 and 35 MB more in adaptive mode, and neither figure grew after the fifth minute. Redmine's own memory grew through the whole run, from 327 MB to 630 MB unrecorded.

Adaptive mode: calls kept each second

Minutes into the run. Calls kept a second.

These figures as a table
Minute Tier 4, adaptive
0:30 2,810
1:00 1,665
1:30 1,890
2:00 1,637
2:30 1,709
3:00 1,652
3:30 1,690
4:00 1,733
4:30 1,593
5:00 1,784
5:30 1,607
6:00 1,658
6:30 1,757
7:00 1,726
7:30 1,637
8:00 1,814
8:30 1,811
9:00 1,768
9:30 1,729
10:00 1,564
10:30 1,674
11:00 1,725
11:30 1,662
12:00 1,744
12:30 1,873
13:00 1,670
13:30 1,658
14:00 1,663
14:30 1,795
15:00 1,563

The server made about 109,000 calls a second throughout. Recording every call kept all of them. Adaptive mode kept 2,810 a second over the first half minute and 1,703 a second over the last five minutes, which is one call in 64. Its recording took 115 MB on disk, and the full one 6.9 GB.

CPU time added by recording, in each minute
  • Tier 4 12.0% at the end
  • Tier 4, adaptive 3.3% at the end

Minutes into the run.

These figures as a table
Minute Tier 4Tier 4, adaptive
1:00 12.86.9
2:00 10.34.6
3:00 9.25.0
4:00 11.45.2
5:00 9.72.8
6:00 6.81.7
7:00 9.53.5
8:00 8.83.0
9:00 5.00.9
10:00 7.33.2
11:00 11.14.5
12:00 8.63.3
13:00 7.93.5
14:00 10.03.9
15:00 12.03.3

The first minute includes starting the server, when the recorder wraps Redmine's methods, and the calls on which most routes are seen for the first time. In that minute recording added 12.8% to CPU time at tier 4 and 6.9% in adaptive mode. The three runs of each differ more in that minute than in any other: +12.2 to +22.3% and +5.1 to +16.8%. Over the last five minutes it added 9.7% and 3.9%.

After the routes are known, adaptive mode still runs the wrapper in front of each method on every call it skips. A skipped call cost about 135 nanoseconds here, and a call recorded at tier 4 cost 338. No setting lowers the cost of a skipped call. Removing the wrappers would, and that is planned.

Time to answer an action: the slowest in a hundred, in each half minute
  • Not recording 186 ms at the end
  • Tier 4 196 ms at the end
  • Tier 4, adaptive 182 ms at the end

Minutes into the run.

These figures as a table
Minute Not recordingTier 4Tier 4, adaptive
0:30 148216180
1:00 151154149
1:30 153202156
2:00 161158157
2:30 159155159
3:00 152154152
3:30 167167172
4:00 192221208
4:30 180181171
5:00 179177188
5:30 194196180
6:00 183175183
6:30 156163177
7:00 155300178
7:30 166185183
8:00 142172144
8:30 179229175
9:00 167184172
9:30 176187181
10:00 176179173
10:30 179210178
11:00 191204206
11:30 186170181
12:00 148150153
12:30 174193185
13:00 175202191
13:30 146148154
14:00 171280225
14:30 169199175
15:00 186196182
Redmine, 15 minutes CPU time Range Last five minutes Peak memory On disk Median answer Slowest in 100
Not recording 339 s 631 MB 43 ms 170 ms
Tier 4 +8.7% +8.5 to +12.2% +9.7% 754 MB 6.9 GB 45 ms 185 ms
Tier 4, adaptive +3.1% +3.0 to +5.7% +3.9% 685 MB 115 MB 44 ms 178 ms

Each figure is the median of 3 runs. Every run answered the same requests with the same statuses, and no run dropped a row.

The settings

Five settings change what recording costs. The table gives the effect of each on CPU, memory and disk, and what you give up by using it. Configuring what gets recorded lists every setting.

Setting CPU Memory Disk What you give up
A lower tier Less: +15.9% at tier 1 against +20.4% at tier 4 on Redmine About the same A tier 1 recording is 2.6 times smaller than a tier 4 one Argument classes below tier 2, object ids and returns below tier 3, raises below tier 4
adaptive Less: +12.3% against +20.4% at tier 4 on Redmine About the same 27 times smaller on Redmine at tier 4 Call counts. A route is recorded the first time and then once in 64
A narrower included Less, in step with the calls left out Less, in step with the routes left out Less The calls into what you left out
rotate and retain None None Capped at what you set The oldest files, once the cap is reached
RuntimeAnalysis.finish! Recording stops Stays as it is Stops growing Everything after the call

The tier: what is written for each call

A tier adds to what the tier below it writes. On Redmine's suite the recording comes to 29 bytes for each call at tier 1 and 74 at tier 4.

Tier Adds What reads it
1 One row a call: who called what, and from which line Call graphs, dead code, coupling, which specs reach a method
2 The class of each argument, and a row for keywords What a method receives
3 An object id for the receiver and each argument, and a row for each return Types for the editor, duck types, where a nil came from
4 A row when a call raises: the class and where it was raised Where a nil caused an error

Most of the added cost comes at the step from tier 2 to tier 3, because tier 3 writes a second row for every call and reads an object id for every value. Tier 2 costs about what tier 1 does, and tier 4 about what tier 3 does, since most calls take no keywords and few raise.

Adaptive mode: record a route once, then sample it

RuntimeAnalysis.configure do |c|
  c.tier = 4
  c.adaptive = true
end

A route is the path from the root of the current call tree to the call being made. In adaptive mode a route seen for the first time is recorded in full, and a repeat of it is recorded once in every 64. On Redmine's suite that kept 571,906 calls of 20.2 million and skipped the rest. A skipped call still goes through the wrapper, which costs about 76 nanoseconds.

The largest saving is on disk, where adaptive mode wrote 27 times less on Redmine's suite at tier 4. It also took less CPU there than recording every call, +12.3% against +20.4%. It saves no memory, because a route is remembered whether or not its calls are kept.

Adaptive mode has these limits:

  • Repeated routes are undercounted, so use a full recording for the tools that rank by how often something ran, such as where_time_goes and whats_looping.
  • Each process starts with nothing seen, so every new process records its first pass in full.
  • Two adaptive runs of the same code can differ, because what is kept depends on the order the routes appeared in.

For a suite started by ra record, set RUNTIME_ANALYSIS_ADAPTIVE=1 to turn it on.

What is recorded

By default the recorder wraps the methods defined under app and lib. excluded and excluded_files leave directories and files out, which helps when one hot loop accounts for most of a recording. include_gems records your calls into a gem, to a depth you choose.

Time and disk follow the number of calls recorded and memory follows the number of distinct routes, which is why gems are recorded only when you ask for them. A method outside what is included has no wrapper and costs nothing.

Rotation and retention: a cap on disk

RuntimeAnalysis.configure do |c|
  c.rotate = { max_bytes: "64MB", max_age: 3600 }
  c.retain = "1GB"
end

With no rotate set, each thread's file grows for as long as the process runs. rotate starts a new file by size, age or number of call trees, and retain deletes the oldest closed files once the total passes the cap. A long-running process needs both, and a test suite usually needs neither.

Stopping

RuntimeAnalysis.finish! stops recording in a running process. The wrappers stay in place and pass each call through, and the memory the recorder took is not released.

Where the cost comes from

CPU: a fixed cost on each call

The recorder puts a C function in front of each method it records. For a call it has seen before, on the same route and from the same line, that function writes the row without running any Ruby. A fixed cost on each call is largest relative to a method that does nothing, so the worst case was measured with a loop of one-line methods, 1.0 million calls in 38 milliseconds unrecorded.

Nanoseconds added to each call of a one-line method
Tier 1 98 ns 3.6 times the unrecorded loop
Tier 2 114 ns 4.1 times the unrecorded loop
Tier 3 168 ns 5.5 times the unrecorded loop
Tier 3, adaptive 76 ns 3.0 times the unrecorded loop

A method that runs a query or renders a template does far more work than this on each call, so the same 98 to 168 nanoseconds is a much smaller share of it. This is why recording multiplies the time of this loop and adds a percentage to the time of a test suite.

A call the recorder has not seen before goes through Ruby once, which costs 3 to 5 microseconds and allocates. So does the first call of each tree, a method of an included gem, and a method_missing. On Redmine's suite 19.7 million of 20.2 million calls were written from C.

At 98 nanoseconds each, those calls account for about 1.9 seconds of the 15.4 that tier 1 added to Redmine's suite. The rest is the calls that went through Ruby, the wrapping of each method as it is defined, and the writer thread. We have not measured how it divides between them.

Memory: what is kept for each route

A route is the path from the root of a call tree down to one call. The recorder keeps every distinct route it has seen, so that each row can refer to its route by one number. Memory grows with the number of distinct routes, and further calls on a route already seen add nothing to it.

A program with 270,400 distinct routes, run three times over
Not recording 32 MB
Recording 130 MB the same after each of the three passes

Recording took about 380 bytes for each route, all of it allocated the first time the route was seen. Recording 32.0 million calls on three routes took 45 MB and did not grow. Of the 380 bytes:

  • About 109 bytes is the route itself: four integers, and its entries in the two tables used to look it up.
  • About 47 bytes is the wrapper's table of the calls it can write without Ruby.
  • The rest is Ruby's heap and memory the allocator has reserved and not reused. The first call on a route is recorded through Ruby and allocates, and the process keeps that memory afterwards.

Redmine's suite has 268,294 routes, and recording added 83 MB to its peak memory. Campfire with its gems has about 3.3 million, and its process went from 272 MB to 859 MB. At that many routes the wrapper's table reaches its limit, and 4.7 million of 13.4 million calls went through Ruby.

Garbage collection takes about as long either way. Over Redmine's suite the collector ran for 6.5 seconds unrecorded and 7.3 seconds recorded at tier 1.

No setting puts a limit on the number of routes. A narrower included reduces it, and adaptive mode leaves it unchanged.

Disk: one line of text for each row

A recording is text, one JSON array of integers a row. Names are written once for each file as a dictionary and referred to by number, and so is each route. A tier 1 call is about 29 bytes. The recorder writes the files uncompressed, and they compress well if you need to keep or move a recording.

When the recorder drops rows

Each thread passes its rows to a writer thread through a ring buffer of 8 MB, which is about 170,000 tier 1 calls. The buffer takes up memory only as far as the writer has fallen behind. The writer formats and writes a row in less time than the recorder takes to make one, so it keeps up, and what the buffer has to absorb is a single write that the operating system delays for a few milliseconds.

When the buffer is full, the row is dropped and counted, and the thread that made the call does not wait. RuntimeAnalysis.stats reports the count as dropped, next to how many calls adaptive mode recorded and skipped. Of the 11 recorded configurations on this page, each run 3 times, 2 had a run that dropped rows: 1 in one run at tier 2, and 66,109 in one run at tier 4, gems too. A loop that does nothing but call recorded methods, on several threads at once, can drop far more.

A nearly full disk makes dropped rows much more likely, because writes to it stall for longer. With 6 GB free of 460, the loop of one-line methods dropped rows in 8 runs of 12 at tier 3. With 23 GB free it dropped rows in 1 of 24. How the recorder works inside your process has the detail.

How these were measured

  • Each suite ran in one process, serially, 3 times in every configuration. A round runs every configuration once in a shuffled order, so that no configuration always runs first against a cold disk cache. A recorded run is compared with the unrecorded run of its own round. The percentages are the median of those ratios, and the range is the smallest and largest.
  • CPU time is user plus system time for the whole process, which includes the writer threads. Peak memory is the largest resident size the system reported for the process.
  • Redmine was recorded the way ra record does it, with nothing added to the project. Campfire has the gem in its Gemfile.
  • The server under traffic ran 3 times in each configuration, in rounds shuffled the same way, each run on a fresh copy of the database. Its CPU time counts from when the process started, so it includes starting the server. A thread in the server sampled it every five seconds, and each point on a chart is the median of the runs at that moment. An action's time is measured from the moment it was due, so it includes any wait for a free connection.
  • No JIT was running in any of these. Rails turns YJIT off in the test environment, and the Ruby that served the traffic was built without it. On a server that has run long enough for a JIT to compile its hot paths, the wrapper could be a larger share of each call than these figures show. We have not measured that on this version.

The commands to run them yourself are in gem/benchmark/README.md in the repository.

Planned: backing off after a deploy

Nothing in this section is built, and the setting names may change. The aim is a recorder that a production server runs for a short time after a deploy.

  • With start_after set, wrappers are installed during boot with recording switched off, and recording is switched on some minutes later.
  • record_share = 0.1 hashes the hostname, process id and deploy SHA, so about one process in ten records and the choice changes with each deploy. The other processes remove their wrappers before they serve a request.
  • Recording stops by itself at the first of a maximum duration, a quiet period in which adaptive mode has kept nothing new, a row or byte budget, or a kill.
  • A process uninstalls its wrappers by removing each wrapper method from its prepended module, which sends calls to the original method. In a standalone script a call cost 20.2 nanoseconds never wrapped and 20.7 with the wrapper removed.
  • Adaptive mode gets a finer test of what is new: each caller and callee pair as well as each route, a budget for each part of the tree, and a class that arrives at a call site for the first time counted as new.