Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Add a testing log handler proposal #316

Open
wants to merge 3 commits into
base: main
Choose a base branch
from
Open
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
7 changes: 6 additions & 1 deletion Package.swift
Original file line number Diff line number Diff line change
Expand Up @@ -19,15 +19,20 @@ let package = Package(
name: "swift-log",
products: [
.library(name: "Logging", targets: ["Logging"]),
.library(name: "LoggingTestKit", targets: ["LoggingTestKit"]),
],
targets: [
.target(
name: "Logging",
dependencies: []
),
.target(
name: "LoggingTestKit",
dependencies: ["Logging"]
),
.testTarget(
name: "LoggingTests",
dependencies: ["Logging"]
dependencies: ["Logging", "LoggingTestKit"]
),
]
)
320 changes: 320 additions & 0 deletions Sources/LoggingTestKit/TestLogHandler.swift
Original file line number Diff line number Diff line change
@@ -0,0 +1,320 @@
//===----------------------------------------------------------------------===//
//
// This source file is part of the Swift Logging API open source project
//
// Copyright (c) 2024 Apple Inc. and the Swift Logging API project authors
// Licensed under Apache License v2.0
//
// See LICENSE.txt for license information
// See CONTRIBUTORS.txt for the list of Swift Logging API project authors
//
// SPDX-License-Identifier: Apache-2.0
//
//===----------------------------------------------------------------------===//

import Foundation
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Can we avoid the Foundation import here. We normally try to stay clear of foundation in those lower level packages. We can do the data formatting without foundation as well.

import Logging

#if os(Linux)
import Glibc
#else
import Darwin.C
#endif

public struct CapturedLogMessage: CustomStringConvertible {
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I would suggest a slightly different name

Suggested change
public struct CapturedLogMessage: CustomStringConvertible {
public struct RecordedLogMessage: CustomStringConvertible {

We also need to make this type Sendable. Should we make it Equatable and Hashable as well?

private static let timestampFormat = createTimestampFormat()

private static func createTimestampFormat() -> DateFormatter {
let dateFormatter = DateFormatter()
dateFormatter.dateFormat = "yyyy-MM-dd'T'HH:mm:ss.SSS'Z'"
return dateFormatter
}

public var timestamp: Date
public var label: String

public var level: Logger.Level
public var message: Logger.Message
public var metadata: Logger.Metadata
public var source: String

public var file: String
public var function: String
public var line: UInt
Comment on lines +33 to +43
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Can we add some doc comments to all of those public properties


public var prettyMetadata: String {
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Do we need to expose this publicly?

metadata.sorted(by: {
$0.key < $1.key
}).map {
"\($0)=\($1)"
}.joined(separator: " ")
}

public var description: String {
"\(Self.timestampFormat.string(from: timestamp)) \(level) \(label) :\(prettyMetadata) [\(source)] \(message)"
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

We should probably format the timestamp once in the init to make this a bit more performant even if it is only in test code.

}

public init(
timestamp: Date = Date(),
label: String = "nil",
level: Logger.Level = .info,
message: Logger.Message = .init(stringLiteral: ""),
metadata: Logger.Metadata = [:],
source: String = "nil",
file: String = "nil",
function: String = "nil",
line: UInt = 0
) {
self.timestamp = timestamp
self.label = label
self.level = level
self.message = message
self.metadata = metadata
self.source = source
self.file = file
self.function = function
self.line = line
}

// Easily check if log message matches certain characteristics:
@available(macOS 13.0, *)
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Is this availability constraint because of regex? Two things:

  1. We need to expand the availability to full range of platforms that we support?
  2. Can we think of a way for a match method that also works on previous platforms?

Lastly, is this method really beneficial if one uses swift-testing? Testing has great support to show the diff when using #expect of exactly what's off. That's probably a primary problem when debugging tests with this since one little thing is probably off. Basically, I am asking if this method is carrying its weight when using Testing.

public func match(
label: String? = nil,
level: Logger.Level? = nil,
message: Regex<AnyRegexOutput>? = nil,
metadata: [(Logger.Metadata.Element) -> Bool] = [],
source: Regex<AnyRegexOutput>? = nil,
file: Regex<AnyRegexOutput>? = nil,
function: String? = nil,
line: UInt? = nil
) -> Bool {
if let label,
self.label != label
{
return false
}
if let level,
self.level != level
{
return false
}
if let message,
!self.message.description.contains(message)
{
return false
}
for predicate in metadata {
if !self.metadata.contains(where: predicate) {
return false
}
}
if let source,
!self.source.contains(source)
{
return false
}
if let file,
!self.file.contains(file)
{
return false
}
if let function,
self.function != function
{
return false
}
if let line,
self.line != line
{
return false
}

return true
}
}

public struct TestLogHandler: LogHandler, Sendable {
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Can we split the two types into separate files please and add some doc comments to this type.

public typealias Filter = (CapturedLogMessage) -> Bool
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

We normally try to avoid typealiasis since they are often surfaced badly in tooling. Can we just avoid this?


public final class Container: @unchecked Sendable {
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I am not yet convinced that we need this type or concept. The thing that I am most worried about is that the container is a reference type. I can understand that after a test you would want to filter all the logged messages by a predicate and then assert on top of the filtered messages but this type is live-updated.

How strongly do you think that this type is needed?

// Guarded by queue:
private var _messages: [CapturedLogMessage] = []

private let queue: DispatchQueue

private let filter: Filter

init(_ filter: @escaping Filter) {
self.filter = filter
queue = DispatchQueue(label: "TestLogHandler.Container:\(type(of: filter))")
}

public var messages: [CapturedLogMessage] {
var result: [CapturedLogMessage] = []
queue.sync {
result = self._messages
}
return result
}

public func append(_ message: CapturedLogMessage) -> Bool {
if filter(message) {
queue.sync {
_messages.append(message)
}
return true
}
return false
}

public func reset() {
queue.sync {
self._messages = []
}
}

public var factory: (String) -> TestLogHandler {
{ label in
TestLogHandler(label: label, container: self)
}
}
}

private static let queue = DispatchQueue(label: "TestLogHandler")
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Can we instead use a lock to protect this state here? I don't recall of this project contains a locked value box but that or the Mutex from the stdlib would be preferable


// Guarded by queue:
private static var isInitialized = false
// Guarded by queue:
private static var logLevel: Logger.Level = .info
// Guarded by queue:
private static var _containers: [Weak<Container>] = []

public static func bootstrap() {
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I am leaning towards not offering this method and rather let the user in their tests do this. If they already have code that accepts a logger we just need to make the init public and they should be able to avoid bootstrapping completely.

queue.sync {
if !isInitialized {
isInitialized = true
LoggingSystem.bootstrap(Self.init)
}
}
}

// Call in order to create a container of log messages which will only
// contain messages that match the filter.
public static func container(_ filter: @escaping Filter) -> Container {
let container = Container(filter)
queue.sync {
Self._containers.append(Weak(container))
}
return container
}

// Override the default global log level (defaults to .info)
public static func setLevel(_ level: Logger.Level) {
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Instead of a method can we expose the property publicly instead

queue.sync {
logLevel = level
}
}

// Introspect containers
public static var containers: [Container] {
var copy: [Weak<Container>]!
queue.sync {
copy = Self._containers
}
return copy.compactMap(\.value)
}

private let label: String
private var _logLevel: Logger.Level? = nil
private let container: Container?

// Defined in LogHandler protocol:
public var metadata: Logger.Metadata = [:]
public var logLevel: Logger.Level {
// ALWAYS return .trace to ensure our log() method will be called. The
// effectiveLogLevel is then used for if we should print to stderr:
get { .trace }
set {
_logLevel = newValue
}
}

public var effectiveLogLevel: Logger.Level {
if let level = _logLevel {
return level
} else {
var level: Logger.Level!
Self.queue.sync {
level = Self.logLevel
}
return level
}
}

public init(label: String) {
self.label = label
self.container = nil
}

private init(label: String, container: Container) {
self.label = label
self.container = container
}

public func log(
level: Logger.Level,
message: Logger.Message,
metadata: Logger.Metadata?,
source: String,
file: String,
function: String,
line: UInt
) {
var metadata = metadata ?? [:]
metadata.merge(self.metadata, uniquingKeysWith: { left, _ in left })

let message = CapturedLogMessage(
label: label,
level: level,
message: message,
metadata: metadata,
source: source,
file: file,
function: function,
line: line
)
var inContainer = false
if let container = self.container {
if container.append(message) {
inContainer = true
}
} else {
for container in Self.containers {
if container.append(message) {
inContainer = true
}
}
}
if !inContainer, effectiveLogLevel <= level {
FileHandle.standardError.write(Data(message.description.utf8))
FileHandle.standardError.write(Data("\n".utf8))
fflush(stderr)
}
}

public subscript(metadataKey metadataKey: String) -> Logger.Metadata.Value? {
get {
metadata[metadataKey]
}
set {
metadata[metadataKey] = newValue
}
}
}

private class Weak<T: AnyObject> {
weak var value: T?
init(_ value: T) {
self.value = value
}
}
Loading