Skip to content

perf: ~2.9x faster request dispatch, and add a benchmark suite - #150

Merged
gmpassos merged 1 commit into
masterfrom
perf/request-optimizations
Aug 12, 2026
Merged

perf: ~2.9x faster request dispatch, and add a benchmark suite#150
gmpassos merged 1 commit into
masterfrom
perf/request-optimizations

Conversation

@gmpassos

Copy link
Copy Markdown
Contributor

Adds benchmark/ — an in-process suite for the request path — and fixes the costs it exposed.

BenchmarkBeforeAfter
APIRouteHandler.call (direct)2.128 µs0.524 µs4.1×
APIRoot.call: ping2.758 µs0.901 µs3.1×
APIRoot.call: echo (parameters)3.057 µs1.203 µs2.5×
APIRoot.call: json (entity payload)3.081 µs1.222 µs2.5×

Measured back-to-back on one machine (dart run benchmark/bones_api_benchmark.dart). In-process — no socket, no HTTP client — so this is framework overhead only.

Findings, in order of impact

1. Log messages were formatted even when nothing consumed them.

LoggerHandler._logRootMsg called _buildMsg on every record before deciding whether any destination wanted it. _buildMsg renders the timestamp, pads and truncates the isolate and logger names, and looks the current APIRequest up in the record's Zone. The result was then discarded whenever no destination (logAllTo/logErrorTo/logDbTo/console) was configured — which is the default. That is ~1 µs per record, and a route call emits two (CALL> and RESPONSE>).

Now guarded by _hasLogDestination, which is deliberately conservative: it may answer true and let the existing dispatch decide, but never false while a destination exists.

2. APIRouteHandler re-interpolated its CALL> message per request — including stringifying the declared parametersMap — although module, routeName and parameters are fixed once a route is registered. Now built once, rebuilt only if parameters is replaced. Same for the RESPONSE> prefix.

3. APIRoot._callImpl read pathParts[0], and pathParts copies the backing list on every access. Uses pathPartFirst.

4. APIServer.toAPIRequest copied the query-parameters Map twice — it had just built it.

Being straight about magnitudes: #1 is essentially the whole win. #3 and #4 measured ~2% together, at the edge of run-to-run noise on this machine; I kept them because they are strictly less work, not because they move the number. #2 helps most on routes that declare parameters (the benchmark routes declare none, so it barely shows there).

API addition

The routes builder now forwards config: on any/get/post/put/delete/patch/head, matching APIModule.addRoute:

routes.get('ping', handler, config:constAPIRouteConfig(log:false));

An APIRouteConfig was previously only reachable through addRoute, so per-route logging could not be turned off through the usual API. That matters: route logging still costs roughly 4× the rest of a trivial dispatch even after this PR (0.901 µs with logging vs 0.717 µs without). The suite measures both paths side by side so the trade-off stays visible.

Benchmarks

dart run benchmark/bones_api_benchmark.dart
dart run benchmark/bones_api_benchmark.dart --emit-baseline # to compare a change

Layered by design — request construction, path accessors, routing, handler, module, root — so a regression can be attributed rather than just observed at the top. Dependency-free on purpose: benchmark/ ships inside the published package, so a benchmarking dependency would land on every consumer. _baseline is intentionally left empty, since throughput is hardware-specific; see benchmark/README.md.

Testing

bones_api_logging_test.dart had no coverage of destination routing — exactly what change #1 touches. Added four tests for it, and verified they are real: forcing the new guard to drop everything makes 3 of them fail.

GateResult
dart test --exclude-tags docker783 passed
dart analyze --fatal-infos --fatal-warnings .clean
dart format -o none --set-exit-if-changed .clean
dart pub publish --dry-run0 warnings

Docker-tagged suites not run locally (no daemon).

Version bumped to 1.15.0 with a CHANGELOG entry — drop that commit hunk if you'd rather release separately.

🤖 Generated with Claude Code

Adds `benchmark/`, an in-process suite for the request path, and fixes the
costs it exposed. On a trivial route, `APIRoot.call` goes from 2.76us to
0.90us; `APIRouteHandler.call` on its own from 2.13us to 0.52us.
The suite is layered (request construction / path accessors / routing /
handler / module / root) so a regression can be attributed rather than just
observed at the top. Dependency-free on purpose: `benchmark/` ships inside the
published package, so a benchmarking dependency would land on every consumer.
Findings, in order of impact:
- `LoggerHandler._logRootMsg` formatted every record before deciding whether
anything wanted it. `_buildMsg` renders the timestamp, pads and truncates the
isolate and logger names, and looks the current `APIRequest` up in the
record's `Zone` — then the result was discarded whenever no destination
(`logAllTo`/`logErrorTo`/`logDbTo`/console) was configured, which is the
default. ~1us per record, and a route call emits two (`CALL>`, `RESPONSE>`).
Now guarded by `_hasLogDestination`, which is deliberately conservative: it
may answer `true` and let the existing dispatch decide, but never `false`
while a destination exists.
- `APIRouteHandler` re-interpolated its `CALL>` message on every request,
including stringifying the declared `parameters` `Map`, although `module`,
`routeName` and `parameters` are fixed once a route is registered. Now built
once and rebuilt only if `parameters` is replaced. Same for the `RESPONSE>`
prefix.
- `APIRoot._callImpl` read `pathParts[0]`, and `pathParts` copies the backing
list on every access. Uses `pathPartFirst`.
- `APIServer.toAPIRequest` copied the query-parameters `Map` a second time,
having just built it.
The last two are ~2% on their own — kept because they are strictly less work,
not because they move the number.
Also: the `routes` builder now forwards `config:` on `any`/`get`/`post`/`put`/
`delete`/`patch`/`head`, matching `APIModule.addRoute`. An `APIRouteConfig`
was previously only reachable through `addRoute`, so per-route logging could
not be disabled through the usual API — which matters, since route logging
costs roughly 4x the rest of a trivial dispatch. The suite measures both paths
side by side.
Tests: `bones_api_logging_test.dart` gains coverage for destination routing,
which had none. Verified they fail (3 of them) when the new guard is forced to
drop everything, so they are a real guard and not decoration.
Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
@codecov

codecovBot commented Aug 12, 2026

Copy link
Copy Markdown

Codecov Report

✅ All modified and coverable lines are covered by tests.
✅ Project coverage is 68.15%. Comparing base (ed1a703) to head (d30685d).

Additional details and impacted files
@@ Coverage Diff @@## master #150 +/- ##
==========================================
+ Coverage 68.13% 68.15% +0.02% 
==========================================
Files 66 66 Lines 22114 22129 +15 ==========================================
+ Hits 15067 15083 +16 + Misses 7047 7046 -1 
FlagCoverage Δ
unittests68.15% <100.00%> (+0.02%)⬆️

Flags with carried forward coverage won't be shown. Click here to find out more.

☔ View full report in Codecov by Harness.
📢 Have feedback on the report? Share it here.

🚀 New features to boost your workflow:
  • ❄️ Test Analytics: Detect flaky tests, report on failures, and find test suite problems.

@gmpassos
gmpassos merged commit f169496 into masterAug 12, 2026
5 checks passed
Sign up for freeto join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

1 participant

@gmpassos