Documentation
¶
Overview ¶
Package logging pkg/logging/broadcaster.go c0-com-log
Package logging pkg/logging/formatter.go c0-com-log
Package logging pkg/logging/formatter_istty_native.go c0-com-log
Package logging pkg/logging/hooks.go c0-com-log
Package logging pkg/logging/logger.go c0-com-log
Package logging provides application logging utilities ¶
Package logging pkg/logging/logging.go c0-com-log
Package logging pkg/logging/panics.go c0-com-log
Process-wide accounting for RECOVERED panics.
An unrecovered panic is already captured: the visor points debug.SetCrashOutput at local/log/skywire-crash.log, so the full traceback survives the crash. A RECOVERED one has no such coverage — it is handled, the process keeps running, and the only trace is whatever the recovering site chose to log. That is a hole in two directions:
- The recovery sites disagree about what to log. Some attach debug.Stack(), most log only the panic value, so even when the line is found it often cannot say where the panic came from.
- On js/wasm there is frequently nowhere to find that line at all: no stderr, the log server is off by default, the log file is not reachable from the page, and both the browser console and the exec output ring roll within minutes. A recovered panic there is simply invisible.
A recovered panic is still a defect — a recovered panic in an RPC handler drops that request — so a visor panicking steadily should not report itself healthy on every diagnostic surface. This records a count and a small ring of the most recent ones so `visor state --select diag` can show them.
Cost is confined to the panicking path: nothing here runs in the absence of a panic.
Package logging pkg/logging/ring.go c0-com-log
Per-app ring buffer on top of the Broadcaster hook.
The Broadcaster is already the single logrus hook the visor installs on its master logger, so its Fire sees every entry. In addition to fanning entries out to live subscribers (the `--verbose` gRPC stream), it records the most recent app-scoped entries into a small bounded ring keyed by app name. This lets a consumer (the proxy status page, `cli proxy log`) read back the recent route/transport events and app log lines for one app WITHOUT having held a subscription open the whole time — reusing the exact same tap the verbose stream uses rather than adding a second log sink.
Two buckets per app:
- events: layered router / route-group / transport / setup / mux entries that happen on behalf of the app (tagged app_name=<n> by the router's scopedLog / RouteGroup.SetAppName). These are the "[router] …" / "[RouteGroup …] …" lines.
- logs: the app's own output (_module=proc:<app>:<key> / app:<app>).
Both are bounded (ringPerApp) and the number of tracked apps is capped (ringMaxApps, LRU-evicted) so memory never grows unbounded.
Package logging pkg/logging/ringbuffer.go c0-com-log
Package logging pkg/logging/stdlog.go c0-com-log
Adapter that lets third-party libraries which only accept a stdlib *log.Logger (e.g. armon/go-socks5's Config.Logger) funnel their output through logrus, so their lines get the same timestamp format, colors, and hooks as the rest of skywire instead of being written raw to stdout.
Index ¶
- Constants
- func AddHook(hook logrus.Hook)
- func DebugEnabled() bool
- func Disable()
- func DisableColors()
- func EnableColors()
- func GetLevel() logrus.Level
- func HookLevel(def logrus.Level) logrus.Level
- func LevelFromString(s string) (logrus.Level, error)
- func LevelsUpTo(level logrus.Level) []logrus.Level
- func LogRecovered(log *Logger, site string, v interface{})
- func NewStdLogger(log logrus.FieldLogger) *stdlog.Logger
- func NewStdLoggerLevel(log logrus.FieldLogger, maxLevel logrus.Level) *stdlog.Logger
- func RecordPanic(site string, v interface{}, stack []byte)
- func Recover(log *Logger, site string)
- func ResetPanicStats()
- func SetLevel(level logrus.Level)
- func SetOutputTo(w io.Writer)
- func Trace(l logrus.FieldLogger, msg string)
- func TraceEnabled() bool
- type Broadcaster
- func (b *Broadcaster) Fire(e *logrus.Entry) error
- func (b *Broadcaster) Levels() []logrus.Level
- func (b *Broadcaster) RecentByApp(app string, minLevel logrus.Level) (events, logs []Record)
- func (b *Broadcaster) RecentMerged(app string, minLevel logrus.Level) []Record
- func (b *Broadcaster) SetRingCapture(enabled bool)
- func (b *Broadcaster) Subscribe(f Filter, capacity int) (<-chan *logrus.Entry, func() uint64)
- type ColorScheme
- type Filter
- type Logger
- type MasterLogger
- type PanicEntry
- type Record
- type RingBuffer
- type TextFormatter
- type WriteHook
Constants ¶
const DefaultHookLevel = logrus.InfoLevel
DefaultHookLevel is the most verbose level a capture hook accepts unless the caller asks for something else.
It is deliberately not logrus.AllLevels. A capture hook is a SECOND complete formatting pass over every entry it accepts: WriteHook.Fire below runs TextFormatter.Format into a fresh buffer for each entry, on top of the pass the logger already did for stdout. Measured on a production dmsg-server running at debug: ~67k lines/min reached the hook, ~10 MB/min of formatted output poured into a 256 KiB RingBuffer (DefaultRingBufferBytes). That is ~1.5 seconds of retained history on the /debug/log endpoint the ring feeds, bought by doubling the formatting cost of every log line in the process.
Info and above is what /debug/log is actually read for, and the services default to info anyway (skyenv.LogLevel), so this changes nothing about what the endpoint returns at the normal level — it only keeps the debug/trace firehose out of the second formatter.
const DefaultRingBufferBytes = 256 * 1024
DefaultRingBufferBytes is the default capacity of a RingBuffer.
const HookLevelEnv = "SKYWIRE_LOG_HOOK_LEVEL"
HookLevelEnv names the environment variable an operator sets to change the levels the capture hooks accept, e.g. SKYWIRE_LOG_HOOK_LEVEL=debug to put debug lines back into /debug/log for a debugging session. Accepted values are the ones LevelFromString takes; anything unparseable is ignored.
const PanicRingSize = 8
PanicRingSize is how many recent recovered panics are retained. Small on purpose: each entry carries a full stack trace, and the count — not the ring — is what says whether this is happening a lot.
Variables ¶
This section is empty.
Functions ¶
func DebugEnabled ¶
func DebugEnabled() bool
DebugEnabled reports whether the master logger emits at debug level or below. Use it to skip building log fields on a hot path: logrus's WithField allocates a new Entry and copies the field map whether or not the level is enabled, so an ungated WithField chain costs the same when the line is never printed.
func HookLevel ¶
HookLevel returns def, or the level named by HookLevelEnv when that variable is set to something LevelFromString understands. Capture hooks that want the operator override use this to resolve their level.
func LevelFromString ¶
LevelFromString returns a logrus.Level from a string identifier.
An unrecognized (or empty) identifier returns logrus.InfoLevel along with an error naming the offending string. It used to fall back to DebugLevel, which meant a missing or misspelled "log_level" silently ran a service at debug in production for callers that logged the error and carried on.
func LevelsUpTo ¶
LevelsUpTo returns the logrus levels at least as severe as level, i.e. the slice a logrus.Hook returns from Levels() to be fired only for those.
func LogRecovered ¶
LogRecovered records and logs a panic that the caller has ALREADY recovered. Use it from inside a deferred function that has other cleanup to do as well, which is the common shape:
defer func() {
if rec := recover(); rec != nil {
logging.LogRecovered(log, "router RPC handler", rec)
}
conn.Close()
}()
The stack is captured here rather than taken from the caller, so every site gets one without having to remember debug.Stack(). log may be nil, in which case the panic is recorded but not logged.
func NewStdLogger ¶
func NewStdLogger(log logrus.FieldLogger) *stdlog.Logger
NewStdLogger returns a stdlib *log.Logger that routes every line it receives through the given logrus logger (level auto-detected from a leading "[ERR]"/"[WARN]"/"[DEBUG]" tag, defaulting to info). Hand it to libraries that insist on *log.Logger so their output matches skywire's log format instead of writing uncolored lines straight to stdout.
func NewStdLoggerLevel ¶
NewStdLoggerLevel is like NewStdLogger but caps severity: no line is logged more severe than `maxLevel`. Use it for libraries (e.g. a SOCKS proxy serving external clients) whose "[ERR]" lines are routine, client-driven conditions rather than faults of this process.
func RecordPanic ¶
RecordPanic files a recovered panic. site names the recovering location; v is the value recover() returned; stack is the traceback, which may be nil to have one captured here (callers that already hold one should pass it, as a stack taken at the recover point is the useful one).
Safe to call from any goroutine.
func Recover ¶
Recover is the whole-defer form, for a site whose deferred function does nothing but recover:
defer logging.Recover(log, "dmsg read loop")
It deliberately does NOT re-panic. A site that wants the panic to propagate should not be recovering in the first place.
func ResetPanicStats ¶
func ResetPanicStats()
ResetPanicStats clears the count and the ring. For tests.
func SetOutputTo ¶
SetOutputTo sets the logger's output to an io.Writer
func Trace ¶
func Trace(l logrus.FieldLogger, msg string)
Trace emits msg at trace level through a logrus.FieldLogger, whose interface omits the Trace methods (see Logger.Tracef). Callers on a hot path must guard it with TraceEnabled: reaching the entry allocates.
func TraceEnabled ¶
func TraceEnabled() bool
TraceEnabled reports whether the master logger emits at trace level. Same rationale as DebugEnabled; trace carries the per-stream and per-frame diagnostics that are useless in aggregate and expensive to format at volume.
Types ¶
type Broadcaster ¶
type Broadcaster struct {
// contains filtered or unexported fields
}
Broadcaster is a logrus.Hook that fans out entries to a set of subscriber channels. Subscribers register a Filter; only entries that pass the filter are delivered.
The hook is on the hot logging path, so delivery is non-blocking: each subscriber owns a bounded channel, and entries are dropped on full rather than back-pressuring the producer. Drops are counted per-subscriber so the consumer can tell how lossy its window was.
func NewBroadcaster ¶
func NewBroadcaster() *Broadcaster
NewBroadcaster constructs an empty Broadcaster.
func (*Broadcaster) Fire ¶
func (b *Broadcaster) Fire(e *logrus.Entry) error
Fire delivers e to every subscriber whose filter matches. Never blocks on a slow consumer: full subscriber channels increment a drop counter and continue.
The hook is installed on the visor's master logger at AllLevels, so Fire runs on every entry the process emits — measured at ~67k lines/min on a busy node. Both halves are therefore short-circuited: the subscriber fan-out is skipped entirely (no RWMutex acquire, no map range) when nothing is subscribed, which is the steady state, and the ring capture is skipped when it has been turned off. Only when one of them is actually live does an entry pay for field resolution or allocation.
func (*Broadcaster) Levels ¶
func (b *Broadcaster) Levels() []logrus.Level
Levels reports all logrus levels — Broadcaster does its own level filtering per-subscriber so the hook itself runs on every level.
func (*Broadcaster) RecentByApp ¶
func (b *Broadcaster) RecentByApp(app string, minLevel logrus.Level) (events, logs []Record)
RecentByApp returns copies of the recent events and logs captured for app, filtered to entries at least as severe as minLevel, oldest first. Returns nil, nil when nothing has been captured for the app.
func (*Broadcaster) RecentMerged ¶
func (b *Broadcaster) RecentMerged(app string, minLevel logrus.Level) []Record
RecentMerged returns events+logs for app merged into a single time-ordered slice (oldest first), filtered by minLevel. This is the "reading the log" view `cli proxy log` prints.
func (*Broadcaster) SetRingCapture ¶
func (b *Broadcaster) SetRingCapture(enabled bool)
SetRingCapture turns the bounded per-app ring on or off. It is on by default; a process that never reads the ring back (nothing calls RecentByApp / RecentMerged) can turn it off so Fire returns on a single atomic load, before any field resolution or Record allocation.
type ColorScheme ¶
type ColorScheme struct {
InfoLevelStyle string
WarnLevelStyle string
ErrorLevelStyle string
FatalLevelStyle string
PanicLevelStyle string
DebugLevelStyle string
TraceLevelStyle string
PrefixStyle string
TimestampStyle string
CallContextStyle string
CriticalStyle string
}
ColorScheme configures the logging output colors
type Filter ¶
Filter selects which entries reach a subscriber.
AppName, when set, matches entries whose _module equals AppName OR whose "app" or "app_name" field equals AppName. The launcher and proc-manager tag their per-app calls with app_name=<n>, and each app's stdout/stderr is field-tagged _module=<n> by the proc-spawning code, so AppName-only mode picks up everything that is genuinely scoped to the named app.
Module is matched as a prefix on the _module field (e.g. "router" matches "router", "router_setup", "router/foo"). Multiple modules are OR'd together. Empty Modules means "no module-prefix match"; AppName is the only path to acceptance.
AppName + Modules are OR-merged: an entry passes if either the app match fires or one of the module prefixes matches. With Modules non-empty the filter is a firehose for those modules — the visor has no per-app tagging on router/transport/AR entries, so prefix-matching them is "show me anything from layer X" rather than "show me what layer X is doing for app Y".
MinLevel is inclusive — entries strictly less severe than MinLevel are dropped. logrus levels descend from Panic (0) to Trace (6), so "less severe" means "higher numerically".
type Logger ¶
type Logger struct {
logrus.FieldLogger
}
Logger wraps logrus.FieldLogger
func MustGetLogger ¶
MustGetLogger returns a package-aware logger from the master logger
func ScopedLogger ¶
ScopedLogger returns a package-aware logger derived from the global master logger whose minimum level is independent of it. See MasterLogger.ScopedLogger.
func (*Logger) Critical ¶
func (logger *Logger) Critical() logrus.FieldLogger
Critical adds special critical-level fields for specially highlighted logging, since logrus lacks a distinct critical field and does not have configurable log levels
func (*Logger) Level ¶
Level reports the minimum level this logger emits at. Loggers built by PackageLogger or ScopedLogger report their own master's level; anything else falls back to the process-global level.
func (*Logger) Tracef ¶
Tracef logs at trace level (below Debug). The embedded logrus.FieldLogger interface omits the Trace methods, so a *Logger otherwise can't emit at trace without reaching through WithField; this forwards through the entry. Used to keep low-value diagnostics (e.g. the CLI's CXO fetch-chain hit/miss notes) off ordinary stdout, since the CLI's package logger runs at Debug.
func (*Logger) WithAppName ¶
WithAppName returns a derived Logger that attaches app_name=<name> to every entry. Empty name is a no-op (returns the receiver). Used by router-side scoping so 'cli proxy start --verbose' can match on the field.
type MasterLogger ¶
MasterLogger wraps logrus.Logger and is able to create new package-aware loggers
func NewMasterLogger ¶
func NewMasterLogger() *MasterLogger
NewMasterLogger creates a new package-aware logger with formatting string
func (*MasterLogger) DisableColors ¶
func (logger *MasterLogger) DisableColors()
DisableColors disables colored logging
func (*MasterLogger) EnableColors ¶
func (logger *MasterLogger) EnableColors()
EnableColors enables colored logging
func (*MasterLogger) PackageLogger ¶
func (logger *MasterLogger) PackageLogger(moduleName string) *Logger
PackageLogger instantiates a package-aware logger
func (*MasterLogger) ScopedLogger ¶
func (logger *MasterLogger) ScopedLogger(module string, level logrus.Level) *Logger
ScopedLogger returns a package-aware logger whose minimum level is independent of this master logger's, so setting it cannot change what any other logger in the process emits.
Output and formatter are shared with the parent; hooks are copied as of this call. A scoped logger therefore still writes where everything else writes — only the level is its own. Hooks installed on the parent afterwards do not reach it, which is fine for the one caller that needs this: services install their hooks (syslog) at startup, before any service builds its logger.
type PanicEntry ¶
type PanicEntry struct {
// Time is when the panic was recovered.
Time time.Time `json:"time"`
// Site names the recovering location, e.g. "router RPC handler". It is
// supplied by the caller rather than derived, because by the time a
// deferred recover runs the panicking frames are already gone.
Site string `json:"site"`
// Value is the panic value, formatted with %v.
Value string `json:"value"`
// Stack is the traceback captured at recovery time.
Stack string `json:"stack,omitempty"`
}
PanicEntry is one recovered panic.
func PanicStats ¶
func PanicStats() (count uint64, last []PanicEntry)
PanicStats reports the total number of recovered panics since start and the most recent PanicRingSize of them, oldest first. The count keeps rising after the ring has wrapped, which is the point: it says whether what the ring shows is the whole story.
type Record ¶
type Record struct {
Time time.Time
Level logrus.Level
Module string
Message string
Fields map[string]string
// IsEvent is true for a layered route/transport event (events bucket),
// false for the app's own log output (logs bucket).
IsEvent bool
}
Record is a value-copy snapshot of a logrus entry captured into the ring. The entry pointer itself must never be retained — logrus pools and reuses Entry values after Fire returns — so the fields we care about are copied out at capture time.
type RingBuffer ¶
type RingBuffer struct {
// contains filtered or unexported fields
}
RingBuffer is a thread-safe, fixed-capacity io.Writer that retains the most recent bytes written (oldest dropped, trimmed to a line boundary). It exists so a service can expose its recent log output over a debug endpoint without writing to disk: attach it with AddHook(NewWriteHook(rb)) and serve rb.Bytes().
The backing store is a single pre-allocated ring of `max` bytes: Write copies into it in place and never allocates or grows. (The previous append/re-slice implementation reallocated the whole buffer roughly every `max` bytes of log output; fired on EVERY log line of every service, that was a top allocation source and a needless GC driver on busy services like dmsg-discovery.)
func NewRingBuffer ¶
func NewRingBuffer(maxBytes int) *RingBuffer
NewRingBuffer returns a RingBuffer holding up to maxBytes (DefaultRingBufferBytes when maxBytes <= 0).
func (*RingBuffer) Bytes ¶
func (rb *RingBuffer) Bytes() []byte
Bytes returns a copy of the current buffer contents, oldest first. Once the ring has wrapped (is full) the result is trimmed to the next line boundary so it never starts mid-line — matching the original append-based behavior.
type TextFormatter ¶
type TextFormatter struct {
// Set to true to bypass checking for a TTY before outputting colors.
ForceColors bool
// Force disabling colors. For a TTY colors are enabled by default.
DisableColors bool
// Force formatted layout, even for non-TTY output.
ForceFormatting bool
// Disable timestamp logging. useful when output is redirected to logging
// system that already adds timestamps.
DisableTimestamp bool
// Disable the conversion of the log levels to uppercase
DisableUppercase bool
// Enable logging the full timestamp when a TTY is attached instead of just
// the time passed since beginning of execution.
FullTimestamp bool
// Timestamp format to use for display when a full timestamp is printed.
TimestampFormat string
// The fields are sorted by default for a consistent output. For applications
// that log extremely frequently and don't use the JSON formatter this may not
// be desired.
DisableSorting bool
// Wrap empty fields in quotes if true.
QuoteEmptyFields bool
// Can be set to the override the default quoting character "
// with something else. For example: ', or `.
QuoteCharacter string
// Pad msg field with spaces on the right for display.
// The value for this parameter will be the size of padding.
// Its default value is zero, which means no padding will be applied for msg.
SpacePadding int
// Always use quotes for string values (except for empty fields)
AlwaysQuoteStrings bool
sync.Once
// contains filtered or unexported fields
}
TextFormatter formats log output
func (*TextFormatter) Format ¶
func (f *TextFormatter) Format(entry *logrus.Entry) ([]byte, error)
Format formats a logrus.Entry
func (*TextFormatter) SetColorScheme ¶
func (f *TextFormatter) SetColorScheme(colorScheme *ColorScheme)
SetColorScheme sets the TextFormatter's color scheme configuration
type WriteHook ¶
type WriteHook struct {
// contains filtered or unexported fields
}
WriteHook is a logrus.Hook that logs to an io.Writer
func NewWriteHook ¶
NewWriteHook returns a new WriteHook accepting DefaultHookLevel and above, or the level named by HookLevelEnv when the operator has set it.
func NewWriteHookLevel ¶
NewWriteHookLevel returns a new WriteHook that fires only for entries at least as severe as level. Use it when the call site knows what it wants to capture; NewWriteHook is the operator-configurable default.
Source Files