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.
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.
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.
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 | 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.
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.
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.
- 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 4 | Tier 4, adaptive |
|---|---|---|
| 1:00 | 12.8 | 6.9 |
| 2:00 | 10.3 | 4.6 |
| 3:00 | 9.2 | 5.0 |
| 4:00 | 11.4 | 5.2 |
| 5:00 | 9.7 | 2.8 |
| 6:00 | 6.8 | 1.7 |
| 7:00 | 9.5 | 3.5 |
| 8:00 | 8.8 | 3.0 |
| 9:00 | 5.0 | 0.9 |
| 10:00 | 7.3 | 3.2 |
| 11:00 | 11.1 | 4.5 |
| 12:00 | 8.6 | 3.3 |
| 13:00 | 7.9 | 3.5 |
| 14:00 | 10.0 | 3.9 |
| 15:00 | 12.0 | 3.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.
- 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 recording | Tier 4 | Tier 4, adaptive |
|---|---|---|---|
| 0:30 | 148 | 216 | 180 |
| 1:00 | 151 | 154 | 149 |
| 1:30 | 153 | 202 | 156 |
| 2:00 | 161 | 158 | 157 |
| 2:30 | 159 | 155 | 159 |
| 3:00 | 152 | 154 | 152 |
| 3:30 | 167 | 167 | 172 |
| 4:00 | 192 | 221 | 208 |
| 4:30 | 180 | 181 | 171 |
| 5:00 | 179 | 177 | 188 |
| 5:30 | 194 | 196 | 180 |
| 6:00 | 183 | 175 | 183 |
| 6:30 | 156 | 163 | 177 |
| 7:00 | 155 | 300 | 178 |
| 7:30 | 166 | 185 | 183 |
| 8:00 | 142 | 172 | 144 |
| 8:30 | 179 | 229 | 175 |
| 9:00 | 167 | 184 | 172 |
| 9:30 | 176 | 187 | 181 |
| 10:00 | 176 | 179 | 173 |
| 10:30 | 179 | 210 | 178 |
| 11:00 | 191 | 204 | 206 |
| 11:30 | 186 | 170 | 181 |
| 12:00 | 148 | 150 | 153 |
| 12:30 | 174 | 193 | 185 |
| 13:00 | 175 | 202 | 191 |
| 13:30 | 146 | 148 | 154 |
| 14:00 | 171 | 280 | 225 |
| 14:30 | 169 | 199 | 175 |
| 15:00 | 186 | 196 | 182 |
| 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_goesandwhats_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.
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.
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 recorddoes 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_afterset, wrappers are installed during boot with recording switched off, and recording is switched on some minutes later. -
record_share = 0.1hashes 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.