// Package logging configures component-scoped zerowrap logging. package logging import ( "context" "fmt" "io" "os" "path/filepath" runtimedebug "runtime/debug" "sort" "strings" "sync" "time" "github.com/bnema/zerowrap" "github.com/rs/zerolog" "github.com/rs/zerolog/diode" "golang.org/x/term" ) var components = map[string]bool{ "core": true, "wayland": true, "input": true, "drm": true, "seat": true, "render": true, "sync": true, "config": true, "app": true, "screensaver": true, "powerkey": true, "sched": true, } // categories are debug switches narrower than a component, only on when // named: "all" leaves them off. input-motion logs every pointer motion, // input-keys every key (typed text), drm-flip every frame and commit // completion with its timing, wayland-damage every fresh client commit with // its damage rects, render-damage every rendered frame with its redrawn // area. Naming one turns on debug for its component. var categories = map[string]string{ "input-motion": "input", "input-keys": "input", "drm-flip": "drm", "wayland-damage": "wayland", "render-damage": "render", } type debugKey struct{} type levelKey struct{} type dirKey struct{} type debugSet map[string]bool func ParseDebug(value string) (map[string]bool, error) { selected := make(debugSet) if value == "" { return selected, nil } for _, name := range strings.Split(value, ",") { if name == "all" { selected[name] = true continue } if _, ok := categories[name]; !components[name] && !ok { return nil, fmt.Errorf("invalid debug component %q", name) } selected[name] = true } return selected, nil } // keepRuns is how many per-run log files Open retains. const keepRuns = 20 // Open creates runs//.log, points latest.log in that // directory at it, prunes old runs of that backend and attaches the logger // to ctx. Each backend keeps its own runs: headless test runs never rotate // a DRM session's log away. // The caller must invoke close after all logging is complete; crashed // keeps the crash file for a panic about to be re-raised. func Open(ctx context.Context, backend, level, debug string) (context.Context, func(crashed bool) error, error) { selected, err := ParseDebug(debug) if err != nil { return nil, nil, err } state := os.Getenv("XDG_STATE_HOME") if state == "" { home, err := os.UserHomeDir() if err != nil { return nil, nil, err } state = filepath.Join(home, ".local", "state") } dir := filepath.Join(state, "neferwl", "runs", backend) if err := os.MkdirAll(dir, 0o700); err != nil { return nil, nil, err } name := time.Now().Format("20060102-150405.000") + ".log" file, err := os.OpenFile(filepath.Join(dir, name), os.O_CREATE|os.O_EXCL|os.O_WRONLY, 0o600) if err != nil { return nil, nil, err } latest := filepath.Join(dir, "latest.log") _ = os.Remove(latest) if err := os.Symlink(name, latest); err != nil { _ = file.Close() return nil, nil, err } // Queued entries are lost on a fatal crash: the runtime's own report // (panic and every stack) goes to its own file, besides stderr. A clean // Close removes it while still empty. Created before pruneRuns so // crash files rotate like logs. crashPath := filepath.Join(dir, strings.TrimSuffix(name, ".log")+".crash") if crash, err := os.OpenFile(crashPath, os.O_CREATE|os.O_EXCL|os.O_WRONLY, 0o600); err == nil { _ = runtimedebug.SetCrashOutput(crash, runtimedebug.CrashOptions{}) _ = crash.Close() // SetCrashOutput keeps its own duplicate } else { crashPath = "" } pruneRuns(dir) // Hide Close from the diode: asyncWriter closes the file once. var sink io.Writer = struct{ io.Writer }{file} if term.IsTerminal(int(os.Stderr.Fd())) { sink = &consoleAndFile{file: file} } w := newAsyncWriter(sink, file, crashPath) ctx = zerowrap.WithCtx(ctx, zerowrap.New(zerowrap.Config{Level: level, Format: "json", Output: w})) ctx = context.WithValue(ctx, debugKey{}, debugSet(selected)) ctx = context.WithValue(ctx, levelKey{}, level) ctx = context.WithValue(ctx, dirKey{}, dir) return ctx, func(crashed bool) error { if !crashed { w.Clean() } return w.Close() }, nil } // logQueue is how many entries may wait for the disk. Past it, entries are // dropped (and counted on stderr) rather than blocking the logging // goroutine: input, outputs and the display must never wait on a slow disk. const logQueue = 8192 // newAsyncWriter writes entries to w from its own goroutine. Close drains // what is queued, then closes c. func newAsyncWriter(w io.Writer, c io.Closer, crashPath string) *asyncWriter { d := diode.NewWriter(w, logQueue, 0, func(missed int) { fmt.Fprintf(os.Stderr, "neferwl: %d log entries dropped: disk too slow\n", missed) }) return &asyncWriter{Writer: d, closer: c, crashPath: crashPath} } type asyncWriter struct { diode.Writer closer io.Closer crashPath string once sync.Once err error } // Close drains the queue and closes the file once. func (a *asyncWriter) Close() error { a.once.Do(func() { _ = a.Writer.Close() // drains the queue a.err = a.closer.Close() }) return a.err } // Clean ends a run that did not crash: the crash output is released and // the crash file removed while still empty. func (a *asyncWriter) Clean() { if a.crashPath == "" { return } _ = runtimedebug.SetCrashOutput(nil, runtimedebug.CrashOptions{}) if fi, err := os.Stat(a.crashPath); err == nil && fi.Size() == 0 { _ = os.Remove(a.crashPath) } } func pruneRuns(dir string) { // Watchdog stall dumps (stall-