Skip to content

Commit

Permalink
improve logging (#141)
Browse files Browse the repository at this point in the history
  • Loading branch information
xlc authored Oct 3, 2024
1 parent 7c3fa54 commit e9d5e6c
Show file tree
Hide file tree
Showing 5 changed files with 134 additions and 5 deletions.
6 changes: 5 additions & 1 deletion Blockchain/Sources/Blockchain/Blockchain.swift
Original file line number Diff line number Diff line change
Expand Up @@ -29,12 +29,14 @@ public final class Blockchain: ServiceBase, @unchecked Sendable {
}

public func importBlock(_ block: BlockRef) async throws {
logger.debug("importing block: \(block.hash)")

try await withSpan("importBlock") { span in
span.attributes.blockHash = block.hash.description

let runtime = Runtime(config: config)
let parent = try await dataProvider.getState(hash: block.header.parentHash)
let timeslot = timeProvider.getTime() / UInt32(config.value.slotPeriodSeconds)
let timeslot = timeProvider.getTimeslot()
let state = try runtime.apply(block: block, state: parent, context: .init(timeslot: timeslot))

try await dataProvider.blockImported(block: block, state: state)
Expand All @@ -44,6 +46,8 @@ public final class Blockchain: ServiceBase, @unchecked Sendable {
}

public func finalize(hash: Data32) async throws {
logger.debug("finalizing block: \(hash)")

// TODO: purge forks
try await dataProvider.setFinalizedHead(hash: hash)

Expand Down
Original file line number Diff line number Diff line change
@@ -1,5 +1,8 @@
import TracingUtils
import Utils

private let logger = Logger(label: "BlockchainDataProvider")

private struct BlockchainStorage: Sendable {
var bestHead: Data32?
var bestHeadTimeslot: TimeslotIndex?
Expand Down Expand Up @@ -50,6 +53,8 @@ public final class BlockchainDataProvider {
storage.bestHeadTimeslot = block.header.timeslot
}
}

logger.debug("block imported: \(block.hash)")
}
}

Expand Down
4 changes: 2 additions & 2 deletions Blockchain/Sources/Blockchain/Validator/BlockAuthor.swift
Original file line number Diff line number Diff line change
Expand Up @@ -206,7 +206,7 @@ public final class BlockAuthor: ServiceBase2, @unchecked Sendable {
if timeslot <= now {
continue
}
logger.info("Scheduling new block task at timeslot \(timeslot))")
logger.debug("Scheduling new block task at timeslot \(timeslot))")
schedule(at: timeslot) { [weak self] in
if let self {
await newBlock(claim: .left(claim))
Expand All @@ -222,7 +222,7 @@ public final class BlockAuthor: ServiceBase2, @unchecked Sendable {
if timeslot <= now {
continue
}
logger.info("Scheduling new block task at timeslot \(timeslot))")
logger.debug("Scheduling new block task at timeslot \(timeslot))")
schedule(at: timeslot) { [weak self] in
if let self {
await newBlock(claim: .right(pubkey))
Expand Down
113 changes: 113 additions & 0 deletions Boka/Sources/LogFragment.swift
Original file line number Diff line number Diff line change
@@ -0,0 +1,113 @@
import ConsoleKit
import Logging
import Utils

private struct SourceLocationFragment: LoggerFragment {
public func write(_ record: inout LogRecord, to output: inout FragmentOutput) {
output += "(\(record.file):\(record.line))".consoleText(ConsoleStyle(color: .brightBlack))
output.needsSeparator = true
}
}

private struct InnerFragment: LoggerFragment {
func write(_ record: inout LogRecord, to output: inout FragmentOutput) {
output += "\(levelName(record.level))".consoleText(levelStyle(record.level))
output += "\t| "
output += record.label.consoleText(ConsoleStyle(color: .brightBlack))
output += "\t|"
output.needsSeparator = true
}

private func levelStyle(_ level: Logger.Level) -> ConsoleStyle {
switch level {
case .trace: ConsoleStyle(color: .brightBlack)
case .debug: .plain
case .info, .notice: .info
case .warning: .warning
case .error: .error
case .critical: ConsoleStyle(color: .brightRed)
}
}

private func levelName(_ level: Logger.Level) -> String {
switch level {
case .trace: "TRACE"
case .debug: "DEBUG"
case .info: "INFO"
case .notice: "NOTICE"
case .warning: "WARN"
case .error: "ERROR"
case .critical: "CRITIC"
}
}
}

public final class LogFragment: LoggerFragment {
private let defaultLevel: Logger.Level
private let filters: ThreadSafeContainer<[String: Logger.Level]>
private let inner: LoggerFragment

public init(defaultLevel: Logger.Level = .info, filters: [String: Logger.Level] = [:]) {
self.defaultLevel = defaultLevel
self.filters = .init(filters)
inner = TimestampFragment()
.and(InnerFragment().separated(" "))
.and(MessageFragment().separated(" "))
.and(MetadataFragment().separated(" "))
.and(SourceLocationFragment().separated(" ").maxLevel(.debug))
}

public func levelFor(label: String) -> Logger.Level {
let level: Logger.Level? = filters.read { filters in filters[label] }
if let level {
return level
}

let defaultLevel = defaultLevel
return filters.mutate { filters in
for (key, value) in filters where label.hasPrefix(key) {
filters[label] = value
return value
}
filters[label] = defaultLevel
return defaultLevel
}
}

public func hasContent(record: inout LogRecord) -> Bool {
let level = levelFor(label: record.label)
return record.level > level
}

public func write(_ record: inout LogRecord, to: inout FragmentOutput) {
let level = levelFor(label: record.label)
if record.level < level {
return
}
inner.write(&record, to: &to)
}

public static func parse(from: String) -> (LogFragment, Logger.Level)? {
var defaultLevel: Logger.Level?
var lowestLevel = Logger.Level.critical
var filters: [String: Logger.Level] = [:]
let parts = from.split(separator: ",")
for part in parts {
let entry = part.split(separator: "=")
switch entry.count {
case 1:
defaultLevel = Logger.Level(String(entry[0]))
case 2:
guard let level = Logger.Level(String(entry[1])) else {
return nil
}
filters[String(entry[0])] = level
lowestLevel = min(lowestLevel, level)
default:
return nil
}
}

return (Self(defaultLevel: defaultLevel ?? .info, filters: filters), min(lowestLevel, defaultLevel ?? .critical))
}
}
11 changes: 9 additions & 2 deletions Boka/Sources/Tracing.swift
Original file line number Diff line number Diff line change
@@ -1,16 +1,23 @@
import ConsoleKit
import Foundation
import OTel
import OTLPGRPC
import ServiceLifecycle
import TracingUtils

public enum Tracing {
public static func bootstrap(_ serviceName: String, loggerOnly: Bool = false) async throws -> [Service] {
let env = ProcessInfo.processInfo.environment
let (logFragment, level) = LogFragment.parse(from: env["LOG_LEVEL"] ?? "") ?? {
print("Invalid LOG_LEVEL, using default")
return (LogFragment(defaultLevel: .info), .info)
}()

// Bootstrap the logging backend with the OTel metadata provider which includes span IDs in logging messages.
LoggingSystem.bootstrap(
fragment: timestampDefaultLoggerFragment(),
fragment: logFragment,
console: Terminal(),
level: .trace,
level: level,
metadataProvider: .otel
)

Expand Down

0 comments on commit e9d5e6c

Please sign in to comment.