Files
Nathan Harris 90244e327b Refactor Logging implementation
Motivation:

The original implementation of Logging was done in more haste than should have been, without proper attention given to the semantic requirements.

As the Swift ecosystem has matured a bit, lessons have been learned on handling metadata and passing of external context into internal subcomponents.

A mixture of the "protocol-based context passing" and "explicit context passing" patterns have been adopted.

Both patterns are more fully described in the Swift forum discussion: https://forums.swift.org/t/the-context-passing-problem/39162

Modifications:

- Add: `RedisLogging` namespace with references to static keys and labels that are used for Logging throughout the library
- Add: `Logger` static computed properties to access the Logger prototypes used in connection and connection pools
- Add: `RedisClientWithUserContext` protocol and `UserContextRedisClient` types to assist with wrapping client types for custom logger contexts
- Remove: `logger` property from `RedisClient` requirements
- Change: Many log statements to have higher or lower log levels for their appropriate context
- Change: `RedisConnection` and `RedisConnectionPool` to conform to `RedisClientWithUserContext`
- Change: `logging(to:)` protocol requirement to return a `RedisClient` existential
- Change: ConnectionPool to explicitly pass a logger instance around for pooling methods

Result:

Logging in RediStack will now have a stronger contract of where and how logs will be generated and which context will be used.

Fixes #79 and #74
2020-08-31 22:07:59 -07:00

3.3 KiB

RediStack Logging

Subsystem logging is a form of art, where the proper balance of logging too much is weighed against the need for specific information to not be lost to developers.

Sometimes, a subsystem log is what turns a 3 hour debug session into a 5 minute one.

Categories of Logs

RediStack approaches logging with the mindset of "user-space" versus "system-space" logs.

  • system-space being logs that are triggered from static contexts
    • examples include trace statements or precondition failures
  • user-space being logs that are triggered by a user event
    • examples include requesting a pool connection or sending a Redis command

From this mindset, the design is impacted in two ways:

  1. Connections (and pools) have a "static" logger instance for their entire lifetime to log in system-space
  2. Regular user-driven events can provide a custom logger instance that is tied to the lifetime of the event, hence user-space

In both cases, the logger can be provided by a developer to have a custom label and attached metadata for each log statement.

However, in the first case the logger is configured once at initialization and is bound to the lifetime of the pool or individual connection.

In order to cut down on the verbosity of both the definitions of methods and at the call site, RediStack employs the use of a pattern referred to as Protocol-based Context Passing.

// example code, may not reflect current implementation

private struct CustomLoggingRedisClient: RedisClient {
    // a client that this object will act as a context proxy for
    private let client: RedisClient
    private let logger: Logger
    /* conformance to RedisClient protocol */
}

extension RedisClient {
    public func logging(to logger: Logger) -> RedisClient {
        return CustomLoggingRedisClient(client: self, logger: logger)
    }
}

let myCustomLogger = ...
let connection = ...
connection
    .logging(to: myCustomLogger) // will use this logger for all 'user-space' logs for any requests made
    .ping()

Log Guidelines

  1. Prefer logging at trace levels
  2. Prefer debug for any log that contains metadata, especially complex ones like structs or classes
  • exceptions to this guideline may include metadata such as object IDs that are triggering the logs
  1. Dynamic values should be attached as metadata rather than string interpolated
  2. All log metadata keys should be added to the RedisLogging namespace
  3. Log messages should be in all lowercase, with no punctuation preferred
  • if a Redis command keyword (such as QUIT) is in the log message, it should be in all caps
  1. Log a critical message before any precondition failure
  2. Prefer single locations of error messages
  • for example, only the top level send command on RedisConnection should log the error returned from Redis or from a failed EventLoopFuture
  1. warning logs should be reserved for situations that could lead to critical conditions
  • this may include leaks or bad state

Metadata

  1. All keys should have the rdstk prefix to avoid collisions
  2. Public metadata keys should be 16 characters or less to avoid as many String allocations as possible
  3. Keys should be computed properties to avoid memory costs