nip/src/nimpak/logging.nim

330 lines
10 KiB
Nim

# SPDX-License-Identifier: LSL-1.0
# Copyright (c) 2026 Markus Maiwald
# Stewardship: Self Sovereign Society Foundation
#
# This file is part of the Nexus Sovereign Core.
# See legal/LICENSE_SOVEREIGN.md for license terms.
## NimPak Structured Logging
##
## Comprehensive logging system for the NimPak package manager.
## Provides structured logging with multiple output formats and levels.
## Task 38: Add comprehensive logging.
import std/[times, json, strformat, strutils, os, terminal, tables, locks]
type
LogLevel* = enum
Trace = 0, ## Detailed tracing (development only)
Debug = 1, ## Debug information
Info = 2, ## General information
Warn = 3, ## Warnings (potential issues)
Error = 4, ## Errors (operation failed)
Fatal = 5, ## Fatal errors (application cannot continue)
Audit = 6 ## Audit log (security-relevant events)
LogOutput* = enum
Console, ## Console (stdout/stderr)
File, ## Log file
Json, ## JSON structured log
Syslog ## System log (future)
LogEntry* = object
timestamp*: DateTime
level*: LogLevel
component*: string
message*: string
context*: Table[string, string]
duration*: float ## Operation duration in ms (if applicable)
Logger* = object
minLevel*: LogLevel
outputs*: set[LogOutput]
logFile*: string
jsonFile*: string
useColors*: bool
component*: string
fileHandle: File
jsonHandle: File
lock: Lock
const
LevelColors: array[LogLevel, ForegroundColor] = [
fgWhite, # Trace
fgCyan, # Debug
fgGreen, # Info
fgYellow, # Warn
fgRed, # Error
fgMagenta, # Fatal
fgBlue # Audit
]
LevelNames: array[LogLevel, string] = [
"TRACE", "DEBUG", "INFO", "WARN", "ERROR", "FATAL", "AUDIT"
]
var
globalLogger: Logger
loggerInitialized = false
# ############################################################################
# Logger Initialization
# ############################################################################
proc initLogger*(component: string = "nip",
minLevel: LogLevel = Info,
outputs: set[LogOutput] = {Console},
logFile: string = "",
jsonFile: string = "",
useColors: bool = true): Logger =
## Initialize a new logger
result = Logger(
minLevel: minLevel,
outputs: outputs,
logFile: logFile,
jsonFile: jsonFile,
useColors: useColors and isatty(stdout),
component: component
)
initLock(result.lock)
if logFile.len > 0 and File in outputs:
createDir(logFile.parentDir)
result.fileHandle = open(logFile, fmAppend)
if jsonFile.len > 0 and Json in outputs:
createDir(jsonFile.parentDir)
result.jsonHandle = open(jsonFile, fmAppend)
proc initGlobalLogger*(component: string = "nip",
minLevel: LogLevel = Info,
outputs: set[LogOutput] = {Console},
logFile: string = "",
jsonFile: string = "") =
## Initialize the global logger
globalLogger = initLogger(component, minLevel, outputs, logFile, jsonFile)
loggerInitialized = true
proc closeLogger*(logger: var Logger) =
## Close logger file handles
if logger.logFile.len > 0 and Console in logger.outputs:
logger.fileHandle.close()
if logger.jsonFile.len > 0 and Json in logger.outputs:
logger.jsonHandle.close()
deinitLock(logger.lock)
# ############################################################################
# Log Formatting
# ############################################################################
proc formatConsole(entry: LogEntry, useColors: bool): string =
## Format log entry for console output
let timeStr = entry.timestamp.format("HH:mm:ss")
let levelStr = LevelNames[entry.level]
if useColors:
let colorCode = ord(LevelColors[entry.level])
result = fmt"[\e[90m{timeStr}\e[0m] \e[{colorCode}m{levelStr:5}\e[0m [{entry.component}] {entry.message}"
else:
result = fmt"[{timeStr}] {levelStr:5} [{entry.component}] {entry.message}"
# Add context if present
if entry.context.len > 0:
result.add " {"
var first = true
for key, value in entry.context:
if not first: result.add ", "
result.add fmt"{key}={value}"
first = false
result.add "}"
# Add duration if present
if entry.duration > 0:
result.add fmt" ({entry.duration:.2f}ms)"
proc formatJson(entry: LogEntry): string =
## Format log entry as JSON
let obj = %*{
"timestamp": entry.timestamp.format("yyyy-MM-dd'T'HH:mm:ss'Z'"),
"level": $entry.level,
"component": entry.component,
"message": entry.message
}
if entry.context.len > 0:
var ctx = newJObject()
for key, value in entry.context:
ctx[key] = %value
obj["context"] = ctx
if entry.duration > 0:
obj["duration_ms"] = %entry.duration
result = $obj
proc formatFile(entry: LogEntry): string =
## Format log entry for file output (plain text with full timestamp)
let timeStr = entry.timestamp.format("yyyy-MM-dd HH:mm:ss")
let levelStr = LevelNames[entry.level]
result = fmt"[{timeStr}] {levelStr:5} [{entry.component}] {entry.message}"
if entry.context.len > 0:
for key, value in entry.context:
result.add fmt"\n {key}: {value}"
# ############################################################################
# Logging Functions
# ############################################################################
proc log*(logger: var Logger, level: LogLevel, message: string,
context: Table[string, string] = initTable[string, string](),
duration: float = 0.0) =
## Log a message with the given level
if level < logger.minLevel:
return
let entry = LogEntry(
timestamp: now(),
level: level,
component: logger.component,
message: message,
context: context,
duration: duration
)
acquire(logger.lock)
defer: release(logger.lock)
if Console in logger.outputs:
let formatted = formatConsole(entry, logger.useColors)
if level >= Error:
stderr.writeLine(formatted)
else:
stdout.writeLine(formatted)
if File in logger.outputs and logger.logFile.len > 0:
logger.fileHandle.writeLine(formatFile(entry))
logger.fileHandle.flushFile()
if Json in logger.outputs and logger.jsonFile.len > 0:
logger.jsonHandle.writeLine(formatJson(entry))
logger.jsonHandle.flushFile()
# Convenience functions for global logger
proc log*(level: LogLevel, message: string,
context: Table[string, string] = initTable[string, string]()) =
if loggerInitialized:
globalLogger.log(level, message, context)
proc trace*(message: string, context: Table[string, string] = initTable[string, string]()) =
log(Trace, message, context)
proc debug*(message: string, context: Table[string, string] = initTable[string, string]()) =
log(Debug, message, context)
proc info*(message: string, context: Table[string, string] = initTable[string, string]()) =
log(Info, message, context)
proc warn*(message: string, context: Table[string, string] = initTable[string, string]()) =
log(Warn, message, context)
proc error*(message: string, context: Table[string, string] = initTable[string, string]()) =
log(Error, message, context)
proc fatal*(message: string, context: Table[string, string] = initTable[string, string]()) =
log(Fatal, message, context)
proc audit*(message: string, context: Table[string, string] = initTable[string, string]()) =
log(Audit, message, context)
# ############################################################################
# Performance Metrics Logging
# ############################################################################
type
Timer* = object
startTime: float
name: string
logger: ptr Logger
proc startTimer*(logger: var Logger, name: string): Timer =
## Start a performance timer
result = Timer(
startTime: epochTime(),
name: name,
logger: addr logger
)
proc stop*(timer: Timer): float =
## Stop timer and log the duration
result = (epochTime() - timer.startTime) * 1000.0 # Convert to ms
var ctx = initTable[string, string]()
ctx["operation"] = timer.name
timer.logger[].log(Debug, fmt"Operation '{timer.name}' completed", ctx, result)
template timed*(logger: var Logger, name: string, body: untyped) =
## Execute body and log duration
let timer = logger.startTimer(name)
body
discard timer.stop()
# ############################################################################
# Audit Logging
# ############################################################################
proc auditEvent*(logger: var Logger, event: string, user: string = "",
resource: string = "", action: string = "", success: bool = true) =
## Log an audit event
var ctx = initTable[string, string]()
if user.len > 0: ctx["user"] = user
if resource.len > 0: ctx["resource"] = resource
if action.len > 0: ctx["action"] = action
ctx["success"] = $success
logger.log(Audit, event, ctx)
proc auditPackageOp*(logger: var Logger, operation: string, packageName: string,
version: string = "", success: bool = true) =
## Log a package operation audit event
var ctx = initTable[string, string]()
ctx["package"] = packageName
if version.len > 0: ctx["version"] = version
ctx["operation"] = operation
ctx["success"] = $success
logger.log(Audit, fmt"Package {operation}: {packageName}", ctx)
proc auditCasOp*(logger: var Logger, operation: string, hash: string,
format: string = "", success: bool = true) =
## Log a CAS operation audit event
var ctx = initTable[string, string]()
ctx["hash"] = hash[0..min(20, hash.len-1)]
if format.len > 0: ctx["format"] = format
ctx["operation"] = operation
ctx["success"] = $success
logger.log(Audit, fmt"CAS {operation}", ctx)
# ############################################################################
# Log Level Parsing
# ############################################################################
proc parseLogLevel*(s: string): LogLevel =
## Parse log level from string
case s.toLowerAscii():
of "trace": Trace
of "debug": Debug
of "info": Info
of "warn", "warning": Warn
of "error": Error
of "fatal": Fatal
of "audit": Audit
else: Info
proc setLogLevel*(logger: var Logger, level: LogLevel) =
logger.minLevel = level
proc setLogLevel*(level: LogLevel) =
if loggerInitialized:
globalLogger.minLevel = level