Skip to content

Commit

Permalink
refactor: Restructure log manager responsibility. (serverpod#2434)
Browse files Browse the repository at this point in the history
  • Loading branch information
@Isakdl
Isakdl authored Jul 8, 2024
1 parent 9f9f04f commit 0fab702
Show file tree
Hide file tree
Showing 5 changed files with 155 additions and 116 deletions.
33 changes: 6 additions & 27 deletions packages/serverpod/lib/src/database/adapters/postgres/database_connection.dart
View file
Original file line number Diff line number Diff line change
Expand Up @@ -506,40 +506,19 @@ class DatabaseConnection {
exception,
StackTrace? trace,
}) {
// Check if this query should be logged.
var logSettings =
session.serverpod.logManager.settings.getLogSettingsForSession(
session,
);
var duration =
DateTime.now().difference(startTime).inMicroseconds / 1000000.0;
var slow = duration >= logSettings.slowQueryDuration;
var shouldLog = session.serverpod.logManager.shouldLogQuery(
session: session,
slow: slow,
failed: exception != null,
);

if (!shouldLog) {
return;
}
var duration = DateTime.now().difference(startTime);

// Use the current stack trace if there is no exception.
trace ??= StackTrace.current;

// Log the query.
var entry = QueryLogEntry(
sessionLogId: session.sessionLogs.temporarySessionId,
serverId: session.server.serverId,
session.serverpod.logManager.logQuery(
session,
query: query,
duration: duration,
numRows: numRowsAffected,
error: exception?.toString(),
stackTrace: trace.toString(),
slow: slow,
order: session.sessionLogs.createLogOrderId,
numRowsAffected: numRowsAffected,
error: exception.toString(),
stackTrace: trace,
);
session.serverpod.logManager.logQuery(session, entry);
}

/// For most cases use the corresponding method in [Database] instead.
Expand Down
147 changes: 120 additions & 27 deletions packages/serverpod/lib/src/server/log_manager/log_manager.dart
View file
Original file line number Diff line number Diff line change
Expand Up @@ -8,6 +8,8 @@ import 'package:synchronized/synchronized.dart';
import '../../../server.dart';
import '../../generated/protocol.dart';

const double _microNormalizer = 1000 * 1000;

/// The [LogManager] handles logging and logging settings. Typically only used
/// internally by Serverpod.
class LogManager {
Expand All @@ -22,6 +24,8 @@ class LogManager {

final List<SessionLogEntryCache> _openSessionLogs = [];

final String _serverId;

int _nextTemporarySessionId = -1;

/// Returns a new unique temporary session id. The id will be negative, and
Expand All @@ -33,8 +37,12 @@ class LogManager {
}

/// Creates a new [LogManager] from [RuntimeSettings].
LogManager(this.runtimeSettings, LogWriter logWriter)
: _logWriter = logWriter,
LogManager(
this.runtimeSettings,
LogWriter logWriter, {
required String serverId,
}) : _logWriter = logWriter,
_serverId = serverId,
settings = LogSettingsManager(runtimeSettings);

/// Initializes the logging for a session, automatically called when a session
Expand All @@ -46,10 +54,7 @@ class LogManager {
return logEntry;
}

/// Returns true if a query should be logged based on the current session and
/// its duration and if it failed.
@internal
bool shouldLogQuery({
bool _shouldLogQuery({
required Session session,
required bool slow,
required bool failed,
Expand All @@ -67,9 +72,7 @@ class LogManager {
return false;
}

/// Returns true if a log entry should be stored for the provided session.
@internal
bool shouldLogEntry({
bool _shouldLogEntry({
required Session session,
required LogEntry entry,
}) {
Expand All @@ -79,9 +82,7 @@ class LogManager {
return entry.logLevel.index >= serverLogLevel.index;
}

/// Returns true if a message should be logged for the provided session.
@internal
bool shouldLogMessage({
bool _shouldLogMessage({
required Session session,
required String endpoint,
required bool slow,
Expand All @@ -106,11 +107,39 @@ class LogManager {
session.sessionLogId! >= 0;

/// Logs an entry, depending on the session type it will be logged directly
/// to the database or stored in the temporary cache until the session is
/// closed. Call [shouldLogEntry] to check if the entry should be logged
/// before calling this method. This method can be called asynchronously.
/// or stored in the temporary cache until the session is closed.
/// This method can be called asynchronously.
@internal
Future<void> logEntry(Session session, LogEntry entry) async {
Future<void> logEntry(
Session session, {
int? messageId,
LogLevel? level,
required String message,
String? error,
StackTrace? stackTrace,
}) async {
var entry = LogEntry(
sessionLogId: session.sessionLogs.temporarySessionId,
serverId: _serverId,
messageId: messageId,
logLevel: level ?? LogLevel.info,
message: message,
time: DateTime.now(),
error: error,
stackTrace: stackTrace?.toString(),
order: session.sessionLogs.createLogOrderId,
);

if (session.serverpod.runMode == ServerpodRunMode.development) {
stdout.writeln('${entry.logLevel.name.toUpperCase()}: ${entry.message}');
if (entry.error != null) stdout.writeln(entry.error);
if (entry.stackTrace != null) stdout.writeln(entry.stackTrace);
}

if (!_shouldLogEntry(session: session, entry: entry)) {
return;
}

await _internalLogger(
'ENTRY',
session,
Expand All @@ -122,11 +151,42 @@ class LogManager {
}

/// Logs a query, depending on the session type it will be logged directly
/// to the database or stored in the temporary cache until the session is
/// closed. Call [shouldLogQuery] to check if the entry should be logged
/// before calling this method. This method can be called asynchronously.
/// or stored in the temporary cache until the session is closed.
/// This method can be called asynchronously.
@internal
Future<void> logQuery(Session session, QueryLogEntry entry) async {
Future<void> logQuery(
Session session, {
required String query,
required Duration duration,
required int? numRowsAffected,
required String? error,
required StackTrace stackTrace,
}) async {
var executionTime = duration.inMicroseconds / _microNormalizer;

var logSettings = settings.getLogSettingsForSession(session);

var slow = executionTime >= logSettings.slowQueryDuration;
var shouldLog = _shouldLogQuery(
session: session,
slow: slow,
failed: error != null,
);

if (!shouldLog) return;

var entry = QueryLogEntry(
sessionLogId: session.sessionLogs.temporarySessionId,
serverId: _serverId,
query: query,
duration: executionTime,
numRows: numRowsAffected,
error: error,
stackTrace: stackTrace.toString(),
slow: slow,
order: session.sessionLogs.createLogOrderId,
);

await _internalLogger(
'QUERY',
session,
Expand All @@ -138,12 +198,45 @@ class LogManager {
}

/// Logs a message from a stream, depending on the session type it will be
/// logged directly to the database or stored in the temporary cache until the
/// session is closed. Call [shouldLogMessage] to check if the entry should be
/// logged before calling this method. This method can be called
/// asynchronously.
/// logged directly or stored in the temporary cache until the session is
/// closed. This method can be called asynchronously.
@internal
Future<void> logMessage(Session session, MessageLogEntry entry) async {
Future<void> logMessage(
Session session, {
required String endpointName,
required String messageName,
required int messageId,
required Duration duration,
required String? error,
required StackTrace? stackTrace,
}) async {
var executionTime = duration.inMicroseconds / _microNormalizer;

var slow = executionTime >=
settings.getLogSettingsForSession(session).slowSessionDuration;

var shouldLog = _shouldLogMessage(
session: session,
endpoint: endpointName,
slow: slow,
failed: error != null,
);

if (!shouldLog) return;

var entry = MessageLogEntry(
sessionLogId: session.sessionLogs.temporarySessionId,
serverId: _serverId,
messageId: messageId,
endpoint: endpointName,
messageName: messageName,
duration: executionTime,
order: session.sessionLogs.createLogOrderId,
error: error,
stackTrace: stackTrace?.toString(),
slow: slow,
);

await _internalLogger(
'MESSAGE',
session,
Expand Down Expand Up @@ -208,7 +301,7 @@ class LogManager {
var now = DateTime.now();

var sessionLogEntry = SessionLogEntry(
serverId: session.server.serverId,
serverId: _serverId,
time: now,
touched: now,
endpoint: _endpointForSession(session),
Expand Down Expand Up @@ -288,7 +381,7 @@ class LogManager {
var now = DateTime.now();

var sessionLogEntry = SessionLogEntry(
serverId: session.server.serverId,
serverId: _serverId,
time: now,
touched: now,
endpoint: _endpointForSession(session),
Expand Down
11 changes: 8 additions & 3 deletions packages/serverpod/lib/src/server/serverpod.dart
View file
Original file line number Diff line number Diff line change
Expand Up @@ -195,7 +195,7 @@ class Serverpod {
/// Updates the runtime settings and writes the new settings to the database.
Future<void> updateRuntimeSettings(internal.RuntimeSettings settings) async {
_runtimeSettings = settings;
_logManager = LogManager(settings, _logWriter);
_logManager = LogManager(settings, _logWriter, serverId: serverId);
if (Features.enablePersistentLogging) {
await _storeRuntimeSettings(settings);
}
Expand All @@ -215,7 +215,7 @@ class Serverpod {
var settings = await internal.RuntimeSettings.db.findFirstRow(session);
if (settings != null) {
_runtimeSettings = settings;
_logManager = LogManager(settings, _logWriter);
_logManager = LogManager(settings, _logWriter, serverId: serverId);
}
await session.close();
} catch (e, stackTrace) {
Expand Down Expand Up @@ -312,7 +312,11 @@ class Serverpod {

// Create a temporary log manager with default settings, until we have
// loaded settings from the database.
_logManager = LogManager(_defaultRuntimeSettings, _logWriter);
_logManager = LogManager(
_defaultRuntimeSettings,
_logWriter,
serverId: serverId,
);

// Setup database
var databaseConfiguration = this.config.database;
Expand Down Expand Up @@ -440,6 +444,7 @@ class Serverpod {
_logManager = LogManager(
_runtimeSettings ?? _defaultRuntimeSettings,
_logWriter,
serverId: serverId,
);

// Connect to Redis
Expand Down
38 changes: 11 additions & 27 deletions packages/serverpod/lib/src/server/session.dart
View file
Original file line number Diff line number Diff line change
Expand Up @@ -8,7 +8,6 @@ import 'package:serverpod/src/server/features.dart';
import 'package:serverpod/src/server/log_manager/log_writer.dart';
import '../cache/caches.dart';
import '../database/database.dart';
import '../generated/protocol.dart';

/// When a call is made to the [Server] a [Session] object is created. It
/// contains all data associated with the current connection and provides
Expand Down Expand Up @@ -177,40 +176,25 @@ abstract class Session {
dynamic exception,
StackTrace? stackTrace,
}) {
assert(
!_closed,
'Session is closed, and logging can no longer be performed.',
);
if (_closed) {
throw StateError(
'Session is closed, and logging can no longer be performed.',
);
}

int? messageId;
if (this is StreamingSession) {
messageId = (this as StreamingSession).currentMessageId;
}

var entry = LogEntry(
sessionLogId: sessionLogs.temporarySessionId,
serverId: server.serverId,
messageId: messageId,
logLevel: level ?? LogLevel.info,
serverpod.logManager.logEntry(
this,
message: message,
time: DateTime.now(),
error: exception != null ? '$exception' : null,
stackTrace: stackTrace != null ? '$stackTrace' : null,
order: sessionLogs.createLogOrderId,
messageId: messageId,
level: level ?? LogLevel.info,
error: exception?.toString(),
stackTrace: stackTrace,
);

if (serverpod.runMode == ServerpodRunMode.development) {
stdout.writeln('${entry.logLevel.name.toUpperCase()}: ${entry.message}');
if (entry.error != null) stdout.writeln(entry.error);
if (entry.stackTrace != null) stdout.writeln(entry.stackTrace);
}

if (!serverpod.logManager.shouldLogEntry(session: this, entry: entry)) {
return;
}

// Called asynchronously.
serverpod.logManager.logEntry(this, entry);
}
}

Expand Down
Loading

0 comments on commit 0fab702

Please sign in to comment.