Skip to content

Commit d4fc895

Browse files
christerswahnchristerswahn
authored
fix: Report exceptions during database start and healthcheck operations (serverpod#3373)
1 parent ff89d4a commit d4fc895

File tree

3 files changed

+152
-41
lines changed

3 files changed

+152
-41
lines changed

‎packages/serverpod/lib/src/server/health_check_manager.dart

+43-15
Original file line numberDiff line numberDiff line change
@@ -33,9 +33,12 @@ class HealthCheckManager {
3333
_running = true;
3434
try {
3535
await SystemResources.init();
36-
} catch (e) {
37-
stderr.writeln(
38-
'CPU and memory usage metrics are not supported on this platform.',
36+
} catch (e, stackTrace) {
37+
_reportException(
38+
e,
39+
stackTrace,
40+
message:
41+
'CPU and memory usage metrics are not supported on this platform.',
3942
);
4043
}
4144
_scheduleNextCheck();
@@ -56,14 +59,10 @@ class HealthCheckManager {
5659
await _innerPerformHealthCheck();
5760
completer.complete();
5861
} catch (e, stackTrace) {
59-
_pod.internalSubmitEvent(
60-
ExceptionEvent(e, stackTrace, message: 'Error in health check'),
61-
space: OriginSpace.framework,
62-
context: DiagnosticEventContext(
63-
serverId: _pod.serverId,
64-
serverRunMode: _pod.commandLineArgs.role.name,
65-
serverName: '',
66-
),
62+
_reportException(
63+
e,
64+
stackTrace,
65+
message: 'Error in health check',
6766
);
6867
completer.completeError(e, stackTrace);
6968
}
@@ -139,8 +138,11 @@ class HealthCheckManager {
139138
'UPDATE serverpod_session_log SET "isOpen" = FALSE WHERE "isOpen" = TRUE AND "touched" < $threeMinutesAgo';
140139
await session.db.unsafeQuery(closeQuery);
141140
} catch (e, stackTrace) {
142-
stderr.writeln('Failed to cleanup closed sessions: $e');
143-
stderr.write('$stackTrace');
141+
_reportException(
142+
e,
143+
stackTrace,
144+
message: 'Failed to cleanup closed sessions',
145+
);
144146
}
145147
}
146148

@@ -179,8 +181,11 @@ class HealthCheckManager {
179181
);
180182
}
181183
} catch (e, stackTrace) {
182-
_pod.logVerbose(e.toString());
183-
_pod.logVerbose(stackTrace.toString());
184+
_reportException(
185+
e,
186+
stackTrace,
187+
message: 'Failed to optimize health check data',
188+
);
184189
}
185190
}
186191

@@ -364,6 +369,29 @@ class HealthCheckManager {
364369

365370
return true;
366371
}
372+
373+
void _reportException(
374+
Object e,
375+
StackTrace stackTrace, {
376+
String? message,
377+
}) {
378+
var now = DateTime.now().toUtc();
379+
if (message != null) {
380+
stderr.writeln('$now ERROR: $message');
381+
}
382+
stderr.writeln('$now ERROR: $e');
383+
stderr.writeln('$stackTrace');
384+
385+
_pod.internalSubmitEvent(
386+
ExceptionEvent(e, stackTrace, message: message),
387+
space: OriginSpace.framework,
388+
context: DiagnosticEventContext(
389+
serverId: _pod.serverId,
390+
serverRunMode: _pod.commandLineArgs.role.name,
391+
serverName: '',
392+
),
393+
);
394+
}
367395
}
368396

369397
Duration _timeUntilNextMinute() {

‎packages/serverpod/lib/src/server/serverpod.dart

+30-26
Original file line numberDiff line numberDiff line change
@@ -235,7 +235,9 @@ class Serverpod {
235235
if (settings != null) {
236236
_updateLogSettings(settings);
237237
}
238-
} catch (_) {
238+
} catch (e, stackTrace) {
239+
const message = 'Failed to reload runtime settings.';
240+
_reportException(e, stackTrace, message: message);
239241
return;
240242
}
241243
}
@@ -252,9 +254,12 @@ class Serverpod {
252254
settings.id = oldRuntimeSettings.id;
253255
await internal.RuntimeSettings.db.updateRow(internalSession, settings);
254256
}
255-
} catch (error, stackTrace) {
256-
logVerbose(error.toString());
257-
logVerbose(stackTrace.toString());
257+
} catch (e, stackTrace) {
258+
_reportException(
259+
e,
260+
stackTrace,
261+
message: 'Failed to store runtime settings',
262+
);
258263
}
259264
}
260265

@@ -612,8 +617,10 @@ class Serverpod {
612617
session: internalSession,
613618
maxAttempts: maxAttempts,
614619
);
615-
} catch (e) {
616-
throw ExitException(1, 'Failed to connect to the database: $e');
620+
} catch (e, stackTrace) {
621+
const message = 'Failed to connect to the database.';
622+
_reportException(e, stackTrace, message: message);
623+
throw ExitException(1, '$message: $e');
617624
}
618625

619626
try {
@@ -654,34 +661,31 @@ class Serverpod {
654661

655662
logVerbose('Verifying database integrity.');
656663
await migrationManager.verifyDatabaseIntegrity(internalSession);
657-
} catch (e) {
664+
} catch (e, stackTrace) {
658665
_exitCode = 1;
659-
stderr.writeln(
660-
'Failed to apply database migrations. $e',
661-
);
666+
const message = 'Failed to apply database migrations.';
667+
_reportException(e, stackTrace, message: message);
662668
}
663669

664670
logVerbose('Loading runtime settings.');
665671
try {
666672
_runtimeSettings =
667673
await internal.RuntimeSettings.db.findFirstRow(internalSession);
668-
} catch (e) {
674+
} catch (e, stackTrace) {
669675
_exitCode = 1;
670-
stderr.writeln(
671-
'Failed to load runtime settings. $e',
672-
);
676+
const message = 'Failed to load runtime settings.';
677+
_reportException(e, stackTrace, message: message);
673678
}
674679

675680
if (_runtimeSettings == null) {
676681
logVerbose('Runtime settings not found, creating default settings.');
677682
try {
678683
_runtimeSettings = await RuntimeSettings.db
679684
.insertRow(internalSession, _defaultRuntimeSettings);
680-
} catch (e) {
685+
} catch (e, stackTrace) {
681686
_exitCode = 1;
682-
stderr.writeln(
683-
'Failed to store runtime settings. $e',
684-
);
687+
const message = 'Failed to store runtime settings.';
688+
_reportException(e, stackTrace, message: message);
685689
}
686690
} else {
687691
logVerbose('Runtime settings loaded.');
@@ -942,11 +946,11 @@ class Serverpod {
942946
StackTrace stackTrace, {
943947
String? message,
944948
}) {
949+
var now = DateTime.now().toUtc();
945950
if (message != null) {
946-
message = '${DateTime.now().toUtc()} $message';
947-
stderr.writeln(message);
951+
stderr.writeln('$now ERROR: $message');
948952
}
949-
stderr.writeln('$e');
953+
stderr.writeln('$now ERROR: $e');
950954
stderr.writeln('$stackTrace');
951955

952956
internalSubmitEvent(
@@ -973,11 +977,11 @@ class Serverpod {
973977
try {
974978
await session.db.testConnection();
975979
return session;
976-
} catch (e) {
977-
// Write connection error to stderr.
978-
stderr.writeln(
979-
'Failed to connect to the database. Retrying in 10 seconds. $e',
980-
);
980+
} catch (e, stackTrace) {
981+
const message = 'Failed to connect to the database.';
982+
_reportException(e, stackTrace, message: message);
983+
984+
stderr.writeln('Retrying to connect to the database in 10 seconds.');
981985
if (!printedDatabaseConnectionError) {
982986
stderr.writeln('Database configuration:');
983987
stderr.writeln(config.database.toString());

‎tests/serverpod_test_server/test_integration/diagnostics/diagnostic_events_test.dart

+79
Original file line numberDiff line numberDiff line change
@@ -281,4 +281,83 @@ void main() {
281281
expect(record.context, isA<WebCallOpContext>());
282282
});
283283
});
284+
285+
group(
286+
'Given a serverpod server with a diagnostic event handler and a missing database, '
287+
'when starting serverpod', () {
288+
var exceptionHandler = TestExceptionHandler();
289+
late Serverpod pod;
290+
late DiagnosticEventRecord<ExceptionEvent> record;
291+
292+
setUpAll(() async {
293+
exceptionHandler = TestExceptionHandler();
294+
295+
final config = ServerpodConfig(
296+
database: DatabaseConfig(
297+
host: 'localhost',
298+
port: 9999,
299+
user: 'postgres',
300+
password: 'postgres',
301+
name: 'postgres',
302+
),
303+
apiServer: ServerConfig(
304+
port: 8080,
305+
publicHost: 'localhost',
306+
publicPort: 8080,
307+
publicScheme: 'http',
308+
),
309+
);
310+
pod = IntegrationTestServer.create(
311+
config: config,
312+
experimentalFeatures: ExperimentalFeatures(
313+
diagnosticEventHandlers: [exceptionHandler],
314+
),
315+
);
316+
final result = pod
317+
.start(runInGuardedZone: false)
318+
.timeout(const Duration(seconds: 2));
319+
await expectLater(result, throwsA(isA<TimeoutException>()));
320+
record = await exceptionHandler.events.first.timeout(timeout);
321+
});
322+
323+
tearDownAll(() async {
324+
await pod.shutdown(exitProcess: false);
325+
exceptionHandler.eventsStreamController.close();
326+
});
327+
328+
test('then the diagnostic event handler gets called with a Exception',
329+
() async {
330+
expect(record.event.exception, isA<SocketException>());
331+
});
332+
333+
test('then the diagnostic event exception message is correct', () async {
334+
expect((record.event.exception as SocketException).message,
335+
contains('Connection refused'));
336+
});
337+
338+
test('then the diagnostic event message is correct', () async {
339+
expect(record.event.message,
340+
startsWith('Failed to connect to the database'));
341+
});
342+
343+
test('then the diagnostic event space is framework', () async {
344+
expect(record.space, equals(OriginSpace.framework));
345+
});
346+
347+
test('then the diagnostic event context is a DiagnosticEventContext',
348+
() async {
349+
expect(record.context.runtimeType, DiagnosticEventContext);
350+
});
351+
352+
test('then the diagnostic event context has the expected content',
353+
() async {
354+
expect(
355+
record.context.toJson(),
356+
allOf([
357+
containsPair('serverId', 'default'),
358+
containsPair('serverName', ''),
359+
containsPair('serverRunMode', 'production'),
360+
]));
361+
});
362+
});
284363
}

0 commit comments

Comments
 (0)