From f40614544598475138cb9d9a0f91bbb09eb7bef3 Mon Sep 17 00:00:00 2001 From: Franz Busch Date: Mon, 18 Aug 2025 10:02:44 +0300 Subject: [PATCH] Add new best practices for structured logging and accepting loggers --- .../BestPractices/001-ChoosingLogLevels.md | 28 ++--- .../BestPractices/002-StructuredLogging.md | 96 +++++++++++++++++ .../BestPractices/003-AcceptingLoggers.md | 100 ++++++++++++++++++ .../Logging/Docs.docc/LoggingBestPractices.md | 2 + 4 files changed, 212 insertions(+), 14 deletions(-) create mode 100644 Sources/Logging/Docs.docc/BestPractices/002-StructuredLogging.md create mode 100644 Sources/Logging/Docs.docc/BestPractices/003-AcceptingLoggers.md diff --git a/Sources/Logging/Docs.docc/BestPractices/001-ChoosingLogLevels.md b/Sources/Logging/Docs.docc/BestPractices/001-ChoosingLogLevels.md index 788ccaa..b20cdd8 100644 --- a/Sources/Logging/Docs.docc/BestPractices/001-ChoosingLogLevels.md +++ b/Sources/Logging/Docs.docc/BestPractices/001-ChoosingLogLevels.md @@ -1,7 +1,6 @@ # 001: Choosing log levels -Best practice for selecting appropriate log levels in applications and -libraries. +Select appropriate log levels in applications and libraries. ## Overview @@ -39,29 +38,30 @@ its logging environment. #### For libraries -Libraries should use **info level or lower** (info, debug, trace). Each level -serves different purposes: +Libraries should use **info level or lower** (info, debug, trace). Libraries **should not** log information on **warning or more severe levels**, unless it is a one-time (for example during startup) warning, that cannot lead to overwhelming log outputs. +Each level serves different purposes: + ##### Trace Level -- **Usage**: Log everything needed to diagnose hard-to-reproduce bugs -- **Performance**: May impact performance; assume it won't be used in production -- **Content**: Internal state, detailed operation flows, diagnostic information +- **Usage**: Log everything needed to diagnose hard-to-reproduce bugs. +- **Performance**: May impact performance; assume it won't be used in production. +- **Content**: Internal state, detailed operation flows, diagnostic information. ##### Debug Level -- **Usage**: May be enabled in some production deployments -- **Performance**: Should not significantly undermine production performance -- **Content**: High-level operation overview, connection events, major decisions +- **Usage**: May be enabled in some production deployments. +- **Performance**: Should not significantly undermine production performance. +- **Content**: High-level operation overview, connection events, major decisions. ##### Info Level - **Usage**: Reserved for things that went wrong but can't be communicated -through other means like throwing from a method +through other means, like throwing from a method. - **Examples**: Connection retry attempts, fallback mechanisms, recoverable - failures -- **Guideline**: Use sparingly - not for normal successful operations + failures. +- **Guideline**: Use sparingly - Don't use for normal successful operations. #### For applications @@ -133,6 +133,6 @@ logger.info("Response sent") // ✅ Good: Use appropriate levels instead logger.debug("Processing request", metadata: ["path": "\(path)"]) -logger.trace("Query", , metadata: ["path": "\(query)"]) +logger.trace("Query", metadata: ["sql": "\(query)"]) logger.debug("Request completed", metadata: ["status": "\(status)"]) ``` diff --git a/Sources/Logging/Docs.docc/BestPractices/002-StructuredLogging.md b/Sources/Logging/Docs.docc/BestPractices/002-StructuredLogging.md new file mode 100644 index 0000000..869326d --- /dev/null +++ b/Sources/Logging/Docs.docc/BestPractices/002-StructuredLogging.md @@ -0,0 +1,96 @@ +# 002: Structured logging + +Use metadata to create machine-readable, searchable log entries. + +## Overview + +Structured logging uses metadata to separate human-readable messages from +machine-readable data. This practice makes logs easier to search, filter, and +analyze programmatically while maintaining readability. + +### Motivation + +Traditional string-based logging embeds all information in the message text, +making it more difficult for automated tools to parse and extract. +Structured logging separates these concerns; messages provide human readable +context while metadata provides structured data for tooling. + +### Example + +#### Recommended: Structured logging + +```swift +// ✅ Structured - message provides context, metadata provides data +logger.info( + "Accepted connection", + metadata: [ + "connection.id": "\(id)", + "connection.peer": "\(peer)", + "connections.total": "\(count)" + ] +) + +logger.error( + "Database query failed", + metadata: [ + "query.retries": "\(retries)", + "query.error": "\(error)", + "query.duration": "\(duration)" + ] +) +``` + +### Advanced: Nested metadata for complex data + +```swift +// ✅ Complex structured data +logger.trace( + "HTTP request started", + metadata: [ + "request.id": "\(requestId)", + "request.method": "GET", + "request.path": "/api/users", + "request.headers": [ + "user-agent": "\(userAgent)" + ], + "client.ip": "\(clientIP)", + "client.country": "\(country)" + ] +) +``` + +#### Avoid: Unstructured logging + +```swift +// ❌ Not structured - hard to parse programmatically +logger.info("Accepted connection \(id) from \(peer), total: \(count)") +logger.error("Database query failed after \(retries) retries: \(error)") +``` + +### Metadata key conventions + +Use hierarchical dot-notation for related fields: + +```swift +// ✅ Good: Hierarchical keys +logger.debug( + "Database operation completed", + metadata: [ + "db.operation": "SELECT", + "db.table": "users", + "db.duration": "\(duration)", + "db.rows": "\(rowCount)" + ] +) + +// ✅ Good: Consistent prefixing +logger.info( + "HTTP response", + metadata: [ + "http.method": "POST", + "http.status": "201", + "http.path": "/api/users", + "http.duration": "\(duration)" + ] +) +``` diff --git a/Sources/Logging/Docs.docc/BestPractices/003-AcceptingLoggers.md b/Sources/Logging/Docs.docc/BestPractices/003-AcceptingLoggers.md new file mode 100644 index 0000000..a8c5741 --- /dev/null +++ b/Sources/Logging/Docs.docc/BestPractices/003-AcceptingLoggers.md @@ -0,0 +1,100 @@ +# 003: Accepting loggers in libraries + +Accept loggers through method parameters to ensure proper metadata propagation. + +## Overview + +Libraries should accept logger instances through method parameters rather than +storing them as instance variables. This practice ensures metadata (such as +correlation IDs) is properly propagated down the call stack, while giving +applications control over logging configuration. + +### Motivation + +When libraries accept loggers as method parameters, they enable automatic +propagation of contextual metadata attached to the logger instance. This is +especially important for distributed systems where correlation IDs must flow +through the entire request processing pipeline. + +### Example + +#### Recommended: Accept logger through method parameters + +```swift +// ✅ Good: Pass the logger through method parameters. +struct RequestProcessor { + func processRequest(_ request: HTTPRequest, logger: Logger) async throws -> HTTPResponse { + // Add structured metadata that every log statement should contain. + var logger = logger + logger[metadataKey: "request.method"] = "\(request.method)" + logger[metadataKey: "request.path"] = "\(request.path)" + logger[metadataKey: "request.id"] = "\(request.id)" + + logger.debug("Processing request") + + // Pass the logger down to maintain metadata context. + let validatedData = try validateRequest(request, logger: logger) + let result = try await executeBusinessLogic(validatedData, logger: logger) + + logger.debug("Request processed successfully") + return result + } + + private func validateRequest(_ request: HTTPRequest, logger: Logger) throws -> ValidatedRequest { + logger.debug("Validating request parameters") + // Include validation logic that uses the same logger context. + return ValidatedRequest(request) + } + + private func executeBusinessLogic(_ data: ValidatedRequest, logger: Logger) async throws -> HTTPResponse { + logger.debug("Executing business logic") + + // Further propagate the logger to other services. + let dbResult = try await databaseService.query(data.query, logger: logger) + + logger.debug("Business logic completed") + return HTTPResponse(data: dbResult) + } +} +``` + +#### Alternative: Accept logger through initializer when appropriate + +```swift +// ✅ Acceptable: Logger through initializer for long-lived components +final class BackgroundJobProcessor { + private let logger: Logger + + init(logger: Logger) { + self.logger = logger + } + + func run() async { + // Execute some long running work + logger.debug("Update about long running work") + // Execute some more long running work + } +} +``` + +#### Avoid: Libraries creating their own loggers + +Libraries might create their own loggers; however, this leads to two problems. +First, users of the library can't inject their own loggers which means they have +no control in customizing the log level or log handler. Secondly, it breaks the +metadata propagation since users can't pass in a logger with already attached +metadata. + +```swift +// ❌ Bad: Library creates its own logger +final class MyLibrary { + private let logger = Logger(label: "MyLibrary") // Loses all context +} + +// ✅ Good: Library accepts logger from caller +final class MyLibrary { + func operation(logger: Logger) { + // Maintains caller's context and metadata + } +} +``` diff --git a/Sources/Logging/Docs.docc/LoggingBestPractices.md b/Sources/Logging/Docs.docc/LoggingBestPractices.md index 64aacd1..227e0bb 100644 --- a/Sources/Logging/Docs.docc/LoggingBestPractices.md +++ b/Sources/Logging/Docs.docc/LoggingBestPractices.md @@ -39,3 +39,5 @@ practice includes: ## Topics - +- +-