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.

Benchmark Before After
APIRouteHandler.call (direct) 2.128 µs 0.524 µs 4.1×
APIRoot.call: ping 2.758 µs 0.901 µs 3.1×
APIRoot.call: echo (parameters) 3.057 µs 1.203 µs 2.5×
APIRoot.call: json (entity payload) 3.081 µs 1.222 µs 2.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 parameters Map — 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: const APIRouteConfig(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.

Gate Result
dart test --exclude-tags docker 783 passed
dart analyze --fatal-infos --fatal-warnings . clean
dart format -o none --set-exit-if-changed . clean
dart pub publish --dry-run 0 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

codecov Bot 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     
Flag Coverage Δ
unittests 68.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 master Aug 12, 2026
5 checks passed
Sign up for free to 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