Skip to content

Commit 33ebf43

Browse files
nielsenkonielsenko
committed
test: Cover core Log dispatch and scoping contracts
Framework-level tests (no CLI rendering): - Level gating skips the entry factory below the threshold - Runtime logLevel changes take effect; isDebugEnabled tracks it - Writer errors are swallowed (dispatch is best-effort) - Writes serialize in invocation order even when earlier ones are slower - close() drops any further dispatches - Convenience methods map to the right level; error() attaches error + stack trace - Logs emitted outside any progress attach to the synthetic root scope - progress passes metadata through to the opened scope - LogScope parent/child: root has no parent; a child keeps its own id/label/metadata
1 parent 49a27bd commit 33ebf43

2 files changed

Lines changed: 247 additions & 0 deletions

File tree

‎packages/serverpod_logging/test/log_dispatch_test.dart‎

Lines changed: 198 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,198 @@
1+
import 'package:serverpod_logging/serverpod_logging.dart';
2+
import 'package:test/test.dart';
3+
4+
/// A writer whose [log] always throws, to exercise the best-effort contract.
5+
class _ThrowingWriter extends LogWriter {
6+
@override
7+
Future<void> log(LogEntry entry) async => throw StateError('writer boom');
8+
9+
@override
10+
Future<void> openScope(LogScope scope) async {}
11+
12+
@override
13+
Future<void> closeScope(
14+
LogScope scope, {
15+
required bool success,
16+
required Duration duration,
17+
Object? error,
18+
StackTrace? stackTrace,
19+
}) async {}
20+
}
21+
22+
/// A writer that records the order in which entries are actually written,
23+
/// after an artificial per-message delay.
24+
class _DelayedOrderWriter extends LogWriter {
25+
_DelayedOrderWriter(this.delayFor);
26+
27+
final Duration Function(String message) delayFor;
28+
final List<String> writeOrder = [];
29+
30+
@override
31+
Future<void> log(LogEntry entry) async {
32+
await Future<void>.delayed(delayFor(entry.message));
33+
writeOrder.add(entry.message);
34+
}
35+
36+
@override
37+
Future<void> openScope(LogScope scope) async {}
38+
39+
@override
40+
Future<void> closeScope(
41+
LogScope scope, {
42+
required bool success,
43+
required Duration duration,
44+
Object? error,
45+
StackTrace? stackTrace,
46+
}) async {}
47+
}
48+
49+
LogEntry _entry(LogLevel level, String message) => LogEntry(
50+
time: DateTime.now(),
51+
level: level,
52+
message: message,
53+
scope: LogScope.root('r'),
54+
);
55+
56+
void main() {
57+
group('Given a Log dispatching entries', () {
58+
test(
59+
'when the level is below logLevel, '
60+
'then the entry is dropped and the factory is never invoked', () async {
61+
final writer = TestLogWriter();
62+
final log = Log(writer, logLevel: LogLevel.warning);
63+
64+
var factoryInvoked = false;
65+
log(LogLevel.info, () {
66+
factoryInvoked = true;
67+
return _entry(LogLevel.info, 'x');
68+
});
69+
await log.flush();
70+
71+
expect(
72+
factoryInvoked,
73+
isFalse,
74+
reason: 'gated calls must short-circuit before the factory runs',
75+
);
76+
expect(writer.entries, isEmpty);
77+
});
78+
79+
test(
80+
'when the level meets logLevel, then the entry is forwarded',
81+
() async {
82+
final writer = TestLogWriter();
83+
final log = Log(writer, logLevel: LogLevel.warning);
84+
85+
log.warning('warn');
86+
await log.flush();
87+
88+
expect(writer.entries.single.message, 'warn');
89+
},
90+
);
91+
92+
test(
93+
'when logLevel is lowered at runtime, '
94+
'then newly-enabled levels start being forwarded', () async {
95+
final writer = TestLogWriter();
96+
final log = Log(writer, logLevel: LogLevel.warning);
97+
98+
log.info('dropped');
99+
log.logLevel = LogLevel.info;
100+
log.info('kept');
101+
await log.flush();
102+
103+
expect(writer.entries.map((e) => e.message), ['kept']);
104+
});
105+
106+
test(
107+
'when the logLevel is debug, '
108+
'then isDebugEnabled is true, otherwise false', () {
109+
final log = Log(TestLogWriter(), logLevel: LogLevel.info);
110+
expect(log.isDebugEnabled, isFalse);
111+
112+
log.logLevel = LogLevel.debug;
113+
expect(log.isDebugEnabled, isTrue);
114+
});
115+
116+
test(
117+
'when the writer throws, '
118+
'then dispatch is best-effort and the error is not surfaced', () async {
119+
final log = Log(_ThrowingWriter());
120+
121+
log.info('x');
122+
123+
await expectLater(log.flush(), completes);
124+
});
125+
126+
test(
127+
'when earlier writes are slower than later ones, '
128+
'then writes still complete in invocation order', () async {
129+
final writer = _DelayedOrderWriter(
130+
(m) => m == '1' ? const Duration(milliseconds: 40) : Duration.zero,
131+
);
132+
final log = Log(writer);
133+
134+
log.info('1');
135+
log.info('2');
136+
log.info('3');
137+
await log.flush();
138+
139+
expect(
140+
writer.writeOrder,
141+
['1', '2', '3'],
142+
reason: 'the _latest chain serializes writes in call order',
143+
);
144+
});
145+
146+
test(
147+
'when the log is closed, then subsequent dispatches are dropped',
148+
() async {
149+
final writer = TestLogWriter();
150+
final log = Log(writer);
151+
152+
log.info('before');
153+
await log.close();
154+
log.info('after');
155+
await log.flush();
156+
157+
expect(writer.entries.map((e) => e.message), ['before']);
158+
},
159+
);
160+
161+
group('convenience methods', () {
162+
test(
163+
'when each convenience method is called, '
164+
'then the entry carries the matching LogLevel', () async {
165+
final writer = TestLogWriter();
166+
final log = Log(writer, logLevel: LogLevel.debug);
167+
168+
log.debug('d');
169+
log.info('i');
170+
log.warning('w');
171+
log.error('e');
172+
await log.flush();
173+
174+
expect(writer.entries.map((e) => e.level), [
175+
LogLevel.debug,
176+
LogLevel.info,
177+
LogLevel.warning,
178+
LogLevel.error,
179+
]);
180+
});
181+
182+
test(
183+
'when error() is given an error and stack trace, '
184+
'then both are attached to the entry', () async {
185+
final writer = TestLogWriter();
186+
final log = Log(writer);
187+
final stackTrace = StackTrace.current;
188+
189+
log.error('boom', error: StateError('x'), stackTrace: stackTrace);
190+
await log.flush();
191+
192+
final entry = writer.entries.single;
193+
expect(entry.error, isA<StateError>());
194+
expect(entry.stackTrace, same(stackTrace));
195+
});
196+
});
197+
});
198+
}

‎packages/serverpod_logging/test/log_scope_test.dart‎

Lines changed: 49 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,49 @@
1+
import 'package:serverpod_logging/serverpod_logging.dart';
2+
import 'package:test/test.dart';
3+
4+
void main() {
5+
group('Given Log scoping', () {
6+
test(
7+
'when a log is emitted outside any progress scope, '
8+
'then it attaches to the synthetic root scope', () async {
9+
final writer = TestLogWriter();
10+
final log = Log(writer);
11+
12+
log.info('orphan');
13+
await log.flush();
14+
15+
expect(writer.entries.single.scope.label, 'unknown');
16+
});
17+
18+
test(
19+
'when progress is given metadata, '
20+
'then the opened scope carries it', () async {
21+
final writer = TestLogWriter();
22+
final log = Log(writer);
23+
24+
await log.progress('op', () async => true, metadata: {'k': 'v'});
25+
26+
expect(writer.openedScopes.single.metadata, {'k': 'v'});
27+
});
28+
});
29+
30+
group('Given a LogScope', () {
31+
test('when a root scope is created, then it has no parent', () {
32+
expect(LogScope.root('root').parent, isNull);
33+
});
34+
35+
test(
36+
'when a child scope is created, '
37+
'then it references its parent and keeps its own id, label and metadata',
38+
() {
39+
final root = LogScope.root('root');
40+
final child = root.child(id: 'c1', label: 'child', metadata: {'a': 1});
41+
42+
expect(child.parent, same(root));
43+
expect(child.id, 'c1');
44+
expect(child.label, 'child');
45+
expect(child.metadata, {'a': 1});
46+
},
47+
);
48+
});
49+
}

0 commit comments

Comments
 (0)