From d30685d2e6fb4403b7c43e899de70abe1b09d7b1 Mon Sep 17 00:00:00 2001 From: "Graciliano M. P." Date: Tue, 11 Aug 2026 21:21:00 -0300 Subject: [PATCH] perf: ~2.9x faster request dispatch, and add a benchmark suite MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit 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) --- CHANGELOG.md | 40 ++++++ benchmark/README.md | 57 ++++++++ benchmark/bones_api_benchmark.dart | 211 +++++++++++++++++++++++++++++ benchmark/src/bench_runner.dart | 161 ++++++++++++++++++++++ lib/src/bones_api_base.dart | 36 ++++- lib/src/bones_api_logging.dart | 53 +++++++- lib/src/bones_api_module.dart | 22 ++- lib/src/bones_api_server.dart | 4 +- pubspec.yaml | 2 +- test/bones_api_logging_test.dart | 74 +++++++++- 10 files changed, 645 insertions(+), 15 deletions(-) create mode 100644 benchmark/README.md create mode 100644 benchmark/bones_api_benchmark.dart create mode 100644 benchmark/src/bench_runner.dart diff --git a/CHANGELOG.md b/CHANGELOG.md index 48671b2..0653d69 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -1,3 +1,43 @@ +## 1.15.0 + +- Faster request dispatch. A logged route call is **~2.9x** faster + (measured in-process, `APIRoot.call` on a trivial route: 2.76us -> 0.90us). + + - `LoggerHandler` no longer builds the formatted log message when nothing + would consume it. Every record reaching the root listener was fully + formatted — timestamp, padded/truncated isolate and logger names, plus a + `Zone` lookup for the current `APIRequest` id — and then discarded when no + destination (`logAllTo`/`logErrorTo`/`logDbTo`/console) was configured, + which is the default. This was ~1us per record, and a route call emits two + (`CALL>` and `RESPONSE>`). + - `APIRouteHandler` caches its `CALL>` message and `RESPONSE>` prefix. Both + are fixed once a route is registered, but were re-interpolated per request + (including stringifying the declared `parameters` `Map`). + - `APIRoot._callImpl` no longer copies the path parts list just to read the + first one. + - `APIServer.toAPIRequest` no longer copies the query-parameters `Map` a + second time. + +- The `routes` builder now accepts `config:` on `any`/`get`/`post`/`put`/ + `delete`/`patch`/`head`, matching `APIModule.addRoute`. Previously an + `APIRouteConfig` could only be set through `addRoute`, so per-route logging + could not be turned off through the usual API: + + ```dart + routes.get('ping', handler, config: const APIRouteConfig(log: false)); + ``` + + Route logging is on by default and costs roughly 4x the rest of a trivial + dispatch, so this is worth setting on hot routes. + +- New `benchmark/` suite covering the request path, with a layered breakdown so + a regression can be attributed rather than just observed. See + `benchmark/README.md`. + + ``` + dart run benchmark/bones_api_benchmark.dart + ``` + ## 1.14.0 - New `DBSQLiteAdapter`: an embedded SQLite DB adapter, backed by the diff --git a/benchmark/README.md b/benchmark/README.md new file mode 100644 index 0000000..9ca244a --- /dev/null +++ b/benchmark/README.md @@ -0,0 +1,57 @@ +# Benchmarks + +In-process benchmarks for the request path: building an `APIRequest`, resolving +the module/route, dispatching through `APIRoot.call`, and serializing the +response payload. No socket and no HTTP client are involved, so what is +measured is the framework's own overhead. + +```bash +dart run benchmark/bones_api_benchmark.dart +``` + +To compare a change, record a baseline on your machine first — throughput is +hardware- and load-specific, so numbers are only meaningful relative to a run +on the same machine: + +```bash +# 1. before the change +dart run benchmark/bones_api_benchmark.dart --emit-baseline + +# 2. paste the emitted map into `_baseline` in bones_api_benchmark.dart + +# 3. after the change +dart run benchmark/bones_api_benchmark.dart +``` + +The report then gains a `VS BASE` column. + +## Reading the results + +The suite is deliberately layered, so a regression can be attributed instead of +just observed at the top: + +| Layer | What it isolates | +|---|---| +| `APIRequest.get: *` | Path splitting, parameters, `requestedUri` | +| `APIRequest.pathParts` / `pathPart(0)` | Path accessors used on every dispatch | +| `APIRoot.getModuleByRequest`, `APIModule.getRouteHandlerByRequest` | Routing table lookups | +| `APIResponse.ok(String)` | Response construction | +| `APIRouteHandler.call (direct)` | A route call without the module/root layers | +| `APIModule.call (direct)` | Adds module resolution and security checks | +| `APIRoot.call: *` | Full dispatch, including the per-call `Zone` | + +Each `APIRoot.call` benchmark builds a fresh `APIRequest`, so subtract the +matching `APIRequest.get` cost to isolate the dispatch itself. + +## Note on route logging + +`APIRouteConfig.log` defaults to `true`, and the `CALL>` / `RESPONSE>` records +it emits are a large share of the cost of an otherwise trivial route. The suite +measures both, as `APIRoot.call: ping (empty payload)` and +`APIRoot.call: ping [route log off]`, so the trade-off stays visible. + +Disable it per route when throughput matters more than the audit trail: + +```dart +routes.get('ping', handler, config: const APIRouteConfig(log: false)); +``` diff --git a/benchmark/bones_api_benchmark.dart b/benchmark/bones_api_benchmark.dart new file mode 100644 index 0000000..b6f0c54 --- /dev/null +++ b/benchmark/bones_api_benchmark.dart @@ -0,0 +1,211 @@ +import 'dart:convert' as dart_convert; +import 'dart:io'; + +import 'package:bones_api/bones_api.dart'; + +import 'src/bench_runner.dart'; + +/// Benchmarks for the request path: building an [APIRequest], resolving the +/// module/route, dispatching through [APIRoot.call] and serializing the +/// response payload. +/// +/// Run with: +/// ``` +/// dart run benchmark/bones_api_benchmark.dart +/// ``` +/// +/// These are all in-process: they measure the framework's own overhead, +/// without a socket or an HTTP client in the way. +Future main(List args) async { + var api = BenchmarkAPI(); + await api.ensureInitialized(); + + var runner = BenchRunner(); + + // --------------------------------------------------------------------- + // `APIRequest` construction: path splitting, parameters, `requestedUri`. + // --------------------------------------------------------------------- + + runner.run( + 'APIRequest.get: simple path', + () => APIRequest.get('/bench/ping'), + ); + + runner.run( + 'APIRequest.get: deep path', + () => APIRequest.get('/bench/a/b/c/d/e/f'), + ); + + runner.run( + 'APIRequest.get: with parameters', + () => APIRequest.get( + '/bench/echo', + parameters: {'a': '1', 'b': '2', 'c': '3'}, + ), + ); + + // --------------------------------------------------------------------- + // Path accessors, called on every dispatch. + // --------------------------------------------------------------------- + + var pathRequest = APIRequest.get('/bench/a/b/c/d/e/f'); + + runner.run('APIRequest.pathParts', () => pathRequest.pathParts); + runner.run('APIRequest.pathPart(0)', () => pathRequest.pathPart(0)); + + // --------------------------------------------------------------------- + // Routing: module lookup and route-handler resolution. + // --------------------------------------------------------------------- + + var routeRequest = APIRequest.get('/bench/ping'); + + runner.run( + 'APIRoot.getModuleByRequest', + () => api.getModuleByRequest(routeRequest), + ); + + var module = api.getModuleByRequest(routeRequest)!; + + runner.run( + 'APIModule.getRouteHandlerByRequest', + () => module.getRouteHandlerByRequest(routeRequest), + ); + + runner.run('APIRoot.acceptsRequest', () => api.acceptsRequest(routeRequest)); + + // --------------------------------------------------------------------- + // Dispatch breakdown: each layer measured on its own, so a regression can + // be attributed instead of just observed at the top. + // --------------------------------------------------------------------- + + runner.run('APIResponse.ok(String)', () => APIResponse.ok('pong')); + + var handler = module.getRouteHandlerByRequest(routeRequest)!; + + await runner.runAsync( + 'APIRouteHandler.call (direct)', + () => handler.call(APIRequest.get('/bench/ping')), + ); + + await runner.runAsync( + 'APIModule.call (direct)', + () => module.call(APIRequest.get('/bench/ping')), + ); + + // --------------------------------------------------------------------- + // Full in-process dispatch. + // --------------------------------------------------------------------- + + await runner.runAsync( + 'APIRoot.call: ping (empty payload)', + () => api.call(APIRequest.get('/bench/ping')), + ); + + await runner.runAsync( + 'APIRoot.call: echo (parameters)', + () => api.call( + APIRequest.get('/bench/echo', parameters: {'a': '1', 'b': '2'}), + ), + ); + + await runner.runAsync( + 'APIRoot.call: json (entity payload)', + () => api.call(APIRequest.get('/bench/json')), + ); + + await runner.runAsync( + 'APIRoot.call: 404 (unmatched route)', + () => api.call(APIRequest.get('/bench/nope')), + ); + + // Route logging is on by default (`APIRouteConfig.log`), and dominates the + // cost of an otherwise trivial route. Measured side by side so the trade-off + // is visible rather than surprising. + await runner.runAsync( + 'APIRoot.call: ping [route log off]', + () => api.call(APIRequest.get('/bench/quiet')), + ); + + // --------------------------------------------------------------------- + // Response payload serialization. + // --------------------------------------------------------------------- + + var payload = _samplePayload(); + var jsonResponse = APIResponse.ok(payload); + + runner.run( + 'APIResponse.payload -> JSON', + () => dart_convert.json.encode(jsonResponse.payload), + ); + + runner.report(baseline: _baseline); + + if (args.contains('--emit-baseline')) { + print('const _baseline = {'); + runner.asBaseline().forEach((k, v) { + print(" '$k': ${v.toStringAsFixed(0)},"); + }); + print('};'); + } + + api.close(); + + // An initialized `APIRoot` keeps the isolate alive (shared stores, log + // queue, timers), so a benchmark run would otherwise hang after reporting. + exit(0); +} + +Map _samplePayload() => { + 'id': 12345, + 'name': 'Joe Smith', + 'email': 'joe@example.com', + 'enabled': true, + 'score': 98.6, + 'tags': ['alpha', 'beta', 'gamma'], + 'address': { + 'street': '123 Main St', + 'city': 'Springfield', + 'state': 'NY', + 'zip': '12345', + }, +}; + +/// Reference numbers to compare a run against, shown as a `VS BASE` column. +/// +/// Left empty on purpose: throughput is hardware- and load-specific, so a +/// baseline recorded on one machine would only produce misleading deltas on +/// another. To compare a change, record a baseline on *your* machine first: +/// +/// ``` +/// dart run benchmark/bones_api_benchmark.dart --emit-baseline +/// ``` +/// +/// then paste the emitted map here, apply the change, and run again. +const _baseline = {}; + +class BenchmarkModule extends APIModule { + BenchmarkModule(APIRoot apiRoot) : super(apiRoot, 'bench'); + + @override + void configure() { + routes.get('ping', (request) => APIResponse.ok('pong')); + + routes.get('echo', (request) => APIResponse.ok(request.parameters)); + + routes.get('json', (request) => APIResponse.ok(_samplePayload())); + + // Same work as `ping`, with the per-route call/response logging disabled. + routes.get( + 'quiet', + (request) => APIResponse.ok('pong'), + config: const APIRouteConfig(log: false), + ); + } +} + +class BenchmarkAPI extends APIRoot { + BenchmarkAPI() : super('benchmark', '1.0'); + + @override + Set loadModules() => {BenchmarkModule(this)}; +} diff --git a/benchmark/src/bench_runner.dart b/benchmark/src/bench_runner.dart new file mode 100644 index 0000000..23c271c --- /dev/null +++ b/benchmark/src/bench_runner.dart @@ -0,0 +1,161 @@ +import 'dart:async'; + +/// A minimal benchmark runner. +/// +/// Deliberately dependency-free: `bones_api` ships `benchmark/` inside the +/// published package, so adding a benchmarking dependency would push it onto +/// every consumer. +class BenchRunner { + /// Time each benchmark is measured for, after warm-up. + final Duration measure; + + /// Time each benchmark runs before any measurement, to let the JIT settle. + final Duration warmup; + + final List _results = []; + + BenchRunner({ + this.measure = const Duration(seconds: 2), + this.warmup = const Duration(milliseconds: 500), + }); + + List get results => List.unmodifiable(_results); + + /// Runs a synchronous [body] and records its throughput. + /// + /// [body] must return something derived from the work, which is accumulated + /// into a sink so the optimizer can't eliminate the call. + BenchResult run(String name, Object? Function() body) { + _consume(_loopSync(body, warmup)); + + var (ops, elapsed, sink) = _loopSync(body, measure); + _consume(sink); + + var result = BenchResult(name, ops, elapsed); + _results.add(result); + print(result); + return result; + } + + /// Runs an asynchronous [body] and records its throughput. + Future runAsync( + String name, + FutureOr Function() body, + ) async { + _consume(await _loopAsync(body, warmup)); + + var (ops, elapsed, sink) = await _loopAsync(body, measure); + _consume(sink); + + var result = BenchResult(name, ops, elapsed); + _results.add(result); + print(result); + return result; + } + + static (int, Duration, int) _loopSync( + Object? Function() body, + Duration duration, + ) { + var sink = 0; + var ops = 0; + var chronometer = Stopwatch()..start(); + + // Checking the clock every iteration would dominate a cheap body: + while (chronometer.elapsed < duration) { + for (var i = 0; i < 64; ++i) { + sink ^= body().hashCode; + } + ops += 64; + } + + chronometer.stop(); + return (ops, chronometer.elapsed, sink); + } + + static Future<(int, Duration, int)> _loopAsync( + FutureOr Function() body, + Duration duration, + ) async { + var sink = 0; + var ops = 0; + var chronometer = Stopwatch()..start(); + + while (chronometer.elapsed < duration) { + for (var i = 0; i < 16; ++i) { + sink ^= (await body()).hashCode; + } + ops += 16; + } + + chronometer.stop(); + return (ops, chronometer.elapsed, sink); + } + + /// Keeps the accumulated value observable, so the body can't be optimized + /// away as dead code. + static int blackHole = 0; + + static void _consume(Object? o) { + if (o is (int, Duration, int)) { + blackHole ^= o.$3; + } else if (o is int) { + blackHole ^= o; + } + } + + /// Prints a summary table, and a comparison against [baseline] if given. + void report({Map? baseline}) { + if (_results.isEmpty) return; + + var nameWidth = _results + .map((e) => e.name.length) + .reduce((a, b) => a > b ? a : b); + + print(''); + print( + '${'BENCHMARK'.padRight(nameWidth)} ${'OPS/SEC'.padLeft(12)} ' + '${'US/OP'.padLeft(10)}${baseline != null ? ' ${'VS BASE'.padLeft(9)}' : ''}', + ); + print('-' * (nameWidth + (baseline != null ? 38 : 27))); + + for (var r in _results) { + var line = + '${r.name.padRight(nameWidth)} ' + '${r.opsPerSecond.toStringAsFixed(0).padLeft(12)} ' + '${r.microsecondsPerOp.toStringAsFixed(3).padLeft(10)}'; + + var base = baseline?[r.name]; + if (base != null && base > 0) { + var delta = ((r.opsPerSecond / base) - 1) * 100; + var sign = delta >= 0 ? '+' : ''; + line += ' ${'$sign${delta.toStringAsFixed(1)}%'.padLeft(9)}'; + } + + print(line); + } + print(''); + } + + /// The results as a `name: opsPerSecond` map, to be pasted as a baseline. + Map asBaseline() => { + for (var r in _results) r.name: r.opsPerSecond, + }; +} + +class BenchResult { + final String name; + final int operations; + final Duration elapsed; + + BenchResult(this.name, this.operations, this.elapsed); + + double get opsPerSecond => operations / (elapsed.inMicroseconds / 1000000); + + double get microsecondsPerOp => elapsed.inMicroseconds / operations; + + @override + String toString() => + '-- $name: ${opsPerSecond.toStringAsFixed(0)} ops/sec ' + '(${microsecondsPerOp.toStringAsFixed(3)} us/op)'; +} diff --git a/lib/src/bones_api_base.dart b/lib/src/bones_api_base.dart index 65d8ca7..3567eff 100644 --- a/lib/src/bones_api_base.dart +++ b/lib/src/bones_api_base.dart @@ -48,7 +48,7 @@ typedef APILogger = /// Bones API Library class. class BonesAPI { // ignore: constant_identifier_names - static const String VERSION = '1.14.0'; + static const String VERSION = '1.15.0'; static bool _boot = false; @@ -738,7 +738,9 @@ abstract class APIRoot with Initializable, Closable { APIRequest apiRequest, APISecurity? apiSecurity, ) { - var pathPartRoot = apiRequest.pathParts[0]; + // `pathParts` copies the backing list on every read; this only needs the + // first part. + var pathPartRoot = apiRequest.pathPartFirst; if (pathPartRoot == 'API-INFO') { var info = apiInfo(apiRequest); @@ -1073,6 +1075,31 @@ abstract class APIRouteHandler { ); } + Map? _logMessagesParameters; + String? _callLogMessage; + String? _responseLogPrefix; + + /// The `CALL>` log message, built once per handler. + /// + /// [module], [routeName] and [parameters] are fixed once a route is + /// registered, so interpolating this on every request (which includes + /// stringifying the [parameters] `Map`) was pure per-request cost. Rebuilt + /// if [parameters] is replaced; an in-place mutation of that `Map` is not + /// tracked, and would only stale this log line. + String get _callLogMessageCached { + var params = parameters; + var cached = _callLogMessage; + if (cached != null && identical(params, _logMessagesParameters)) { + return cached; + } + _logMessagesParameters = params; + _responseLogPrefix = null; + return _callLogMessage = "CALL> ${module.name}.$routeName( $params )"; + } + + String get _responseLogPrefixCached => + _responseLogPrefix ??= "RESPONSE> ${module.name}.$routeName: "; + /// Calls this route. FutureOr> call(APIRequest request) { request._routeHandler = this; @@ -1088,7 +1115,7 @@ abstract class APIRouteHandler { } if (config.log && _log.isLoggable(logging.Level.INFO)) { - _log.info("CALL> ${module.name}.$routeName( $parameters )"); + _log.info(_callLogMessageCached); } final initTime = DateTime.now(); @@ -1110,7 +1137,8 @@ abstract class APIRouteHandler { ); } else { _log.info( - "RESPONSE> ${module.name}.$routeName: ${response.status.name} (${time.inMilliseconds} ms)", + "$_responseLogPrefixCached${response.status.name} " + "(${time.inMilliseconds} ms)", ); } } diff --git a/lib/src/bones_api_logging.dart b/lib/src/bones_api_logging.dart index ff69cab..8b8ea3f 100644 --- a/lib/src/bones_api_logging.dart +++ b/lib/src/bones_api_logging.dart @@ -248,11 +248,47 @@ abstract class LoggerHandler { return max; } + /// Whether any destination could consume a record with these properties. + /// + /// Deliberately conservative: it may answer `true` and let the dispatch + /// below decide, but must never answer `false` while a destination exists. + bool _hasLogDestination( + logging.Level level, + bool isDBLog, + bool isFromDBLogger, + ) { + if (_logToConsole) return true; + + if (_allMessageLogger != null && + (!isDBLog || _allMessageLoggerIncludeDBLogs)) { + return true; + } + + if (level >= logging.Level.SEVERE && _resolveErrorMessageLogger() != null) { + return true; + } + + if ((isDBLog || isFromDBLogger) && _resolveDBMessageLogger() != null) { + return true; + } + + return false; + } + void _logRootMsg(logging.LogRecord msg) { var level = msg.level; - var logMsg = _buildMsg(msg); var isDBLog = msg.object is DBLog; + var isFromDBLogger = !isDBLog && isDbLoggerName(msg.loggerName); + + // `_buildMsg` is comparatively costly — it formats the timestamp, pads and + // truncates the isolate/logger names, and looks the current `APIRequest` + // up in the record's `Zone`. By default no destination is configured, so + // building it here would be pure waste on every logged call. + if (!_hasLogDestination(level, isDBLog, isFromDBLogger)) return; + + var logMsg = _buildMsg(msg); + if (!isDBLog || _allMessageLoggerIncludeDBLogs) { logAllMessage(level, logMsg); } @@ -266,11 +302,8 @@ abstract class LoggerHandler { if (level < logging.Level.WARNING) { return; } - } else { - var isFromDBLogger = isDbLoggerName(msg.loggerName); - if (isFromDBLogger) { - logDBMessage(level, logMsg); - } + } else if (isFromDBLogger) { + logDBMessage(level, logMsg); } if (_logToConsole) { @@ -450,7 +483,7 @@ abstract class LoggerHandler { } } - void logErrorMessage(logging.Level level, String message) { + MessageLogger? _resolveErrorMessageLogger() { var messageLogger = _errorMessageLogger; if (messageLogger == null) { @@ -459,6 +492,12 @@ abstract class LoggerHandler { messageLogger ??= LoggerHandler.root._errorMessageLogger; } + return messageLogger; + } + + void logErrorMessage(logging.Level level, String message) { + var messageLogger = _resolveErrorMessageLogger(); + if (messageLogger != null) { messageLogger(level, message); } diff --git a/lib/src/bones_api_module.dart b/lib/src/bones_api_module.dart index 64aed24..d23bc88 100644 --- a/lib/src/bones_api_module.dart +++ b/lib/src/bones_api_module.dart @@ -395,7 +395,15 @@ class APIRouteBuilder { APIRouteFunction function, { Map? parameters, Iterable? rules, - }) => add(null, name, function, parameters: parameters, rules: rules); + APIRouteConfig? config, + }) => add( + null, + name, + function, + parameters: parameters, + rules: rules, + config: config, + ); /// Adds a route of [name] with [handler] for `GET` request method. APIModule get( @@ -403,12 +411,14 @@ class APIRouteBuilder { APIRouteFunction function, { Map? parameters, Iterable? rules, + APIRouteConfig? config, }) => add( APIRequestMethod.GET, name, function, parameters: parameters, rules: rules, + config: config, ); /// Adds a route of [name] with [handler] for `POST` request method. @@ -417,12 +427,14 @@ class APIRouteBuilder { APIRouteFunction function, { Map? parameters, Iterable? rules, + APIRouteConfig? config, }) => add( APIRequestMethod.POST, name, function, parameters: parameters, rules: rules, + config: config, ); /// Adds a route of [name] with [handler] for `PUT` request method. @@ -431,12 +443,14 @@ class APIRouteBuilder { APIRouteFunction function, { Map? parameters, Iterable? rules, + APIRouteConfig? config, }) => add( APIRequestMethod.PUT, name, function, parameters: parameters, rules: rules, + config: config, ); /// Adds a route of [name] with [handler] for `DELETE` request method. @@ -445,12 +459,14 @@ class APIRouteBuilder { APIRouteFunction function, { Map? parameters, Iterable? rules, + APIRouteConfig? config, }) => add( APIRequestMethod.DELETE, name, function, parameters: parameters, rules: rules, + config: config, ); /// Adds a route of [name] with [handler] for `PATCH` request method. @@ -459,12 +475,14 @@ class APIRouteBuilder { APIRouteFunction function, { Map? parameters, Iterable? rules, + APIRouteConfig? config, }) => add( APIRequestMethod.PATCH, name, function, parameters: parameters, rules: rules, + config: config, ); /// Adds a route of [name] with [handler] for `HEAD` request method. @@ -473,12 +491,14 @@ class APIRouteBuilder { APIRouteFunction function, { Map? parameters, Iterable? rules, + APIRouteConfig? config, }) => add( APIRequestMethod.HEAD, name, function, parameters: parameters, rules: rules, + config: config, ); /// Adds a route of [name] with [handler] for the request [method]. diff --git a/lib/src/bones_api_server.dart b/lib/src/bones_api_server.dart index caf6c74..4c96786 100644 --- a/lib/src/bones_api_server.dart +++ b/lib/src/bones_api_server.dart @@ -1440,7 +1440,9 @@ class APIServer extends _APIServerBase { payload = null; mimeType = null; } else { - parametersResolved = Map.from(parameters); + // `parameters` was just built by this method and is not shared, so + // there is nothing to defend against by copying it again. + parametersResolved = parameters; } var req = APIRequest( diff --git a/pubspec.yaml b/pubspec.yaml index 740a1e1..795943f 100644 --- a/pubspec.yaml +++ b/pubspec.yaml @@ -1,6 +1,6 @@ name: bones_api description: Bones_API - A powerful API backend framework for Dart. It comes with a built-in HTTP Server, route handler, entity handler, SQL translator, and DB adapters. -version: 1.14.0 +version: 1.15.0 homepage: https://github.com/Colossus-Services/bones_api environment: diff --git a/test/bones_api_logging_test.dart b/test/bones_api_logging_test.dart index 46fa578..874c973 100644 --- a/test/bones_api_logging_test.dart +++ b/test/bones_api_logging_test.dart @@ -1,10 +1,75 @@ -import 'package:test/test.dart'; import 'package:bones_api/bones_api.dart'; import 'package:bones_api/bones_api_logging.dart'; +import 'package:logging/logging.dart' as logging; +import 'package:test/test.dart'; import 'bones_api_test_modules.dart'; +/// Lets the `Logger.onRecord` broadcast stream deliver. +Future _pump() => Future.delayed(Duration(milliseconds: 5)); + void main() { + // `_logRootMsg` skips building the formatted message when no destination + // would consume it. These pin the routing that guard depends on: a dropped + // message would otherwise be a silent regression. + group('LoggerHandler destinations', () { + setUp(() { + LoggerHandler.disableLogQueue(); + _clearDestinations(); + }); + + tearDown(_clearDestinations); + + test('logAllTo receives a logged message', () async { + var all = []; + logAllTo(messageLogger: (l, m) => all.add(m.toString())); + + logging.Logger('test.logging.all').info('hello-all-destination'); + await _pump(); + + expect( + all.where((m) => m.contains('hello-all-destination')), + isNotEmpty, + reason: '`logAllTo` did not receive the message', + ); + }); + + test('logErrorTo receives a SEVERE message', () async { + var errors = []; + logErrorTo(messageLogger: (l, m) => errors.add(m.toString())); + + logging.Logger('test.logging.error').severe('hello-severe-destination'); + await _pump(); + + expect( + errors.where((m) => m.contains('hello-severe-destination')), + isNotEmpty, + reason: '`logErrorTo` did not receive the SEVERE message', + ); + }); + + test('logAllTo still receives while other destinations are null', () async { + var all = []; + logAllTo(messageLogger: (l, m) => all.add(m.toString())); + + logging.Logger('test.logging.mixed').warning('hello-warning'); + logging.Logger('test.logging.mixed').severe('hello-severe'); + await _pump(); + + expect(all.where((m) => m.contains('hello-warning')), isNotEmpty); + expect(all.where((m) => m.contains('hello-severe')), isNotEmpty); + }); + + test('no destination configured: nothing is delivered', () async { + var all = []; + + logging.Logger('test.logging.none').info('hello-nowhere'); + await _pump(); + + expect(all, isEmpty); + }); + }); + group('logging', () { test('apiConfig', () async { var logAll = []; @@ -36,3 +101,10 @@ void main() { }); }); } + +void _clearDestinations() { + logAllTo(messageLogger: null); + logErrorTo(messageLogger: null); + logDbTo(messageLogger: null); + logToConsole(enabled: false); +}