Format short daemon events with slog

A shared handler writes the event and ordered attributes, with the error
cause last. Journal lines carry a syslog priority and terminal lines
carry the time and level, so each output keeps short, readable events.

diff --git a/daemon_log.go b/daemon_log.go
new file mode 100644 (file)
index 0000000..15426bc
--- /dev/null
+++ b/daemon_log.go
@@ -0,0 +1,143 @@
+package main
+
+import (
+       "context"
+       "fmt"
+       "io"
+       "log/slog"
+       "strings"
+       "sync"
+)
+
+// DaemonLogHandler writes short event lines with ordered attributes. Copies
+// share the writer lock. The err attribute follows all other attributes as a
+// cause. Journal lines carry a syslog priority instead of a time and level.
+type DaemonLogHandler struct {
+       out     io.Writer
+       prefix  string
+       journal bool
+       mutex   *sync.Mutex
+       attrs   []slog.Attr
+       group   string
+}
+
+func (h *DaemonLogHandler) Enabled(_ context.Context, _ slog.Level) bool {
+       return true
+}
+
+func (h *DaemonLogHandler) Handle(_ context.Context, record slog.Record) error {
+       var line strings.Builder
+
+       if h.journal {
+               priority := 7
+               switch {
+               case record.Level >= slog.LevelError:
+                       priority = 3
+               case record.Level >= slog.LevelWarn:
+                       priority = 4
+               case record.Level >= slog.LevelInfo:
+                       priority = 6
+               }
+
+               fmt.Fprintf(&line, "<%d>", priority)
+       } else {
+               line.WriteString(record.Time.Format("2006/01/02 15:04:05"))
+               line.WriteByte(' ')
+               line.WriteString(record.Level.String())
+               line.WriteByte(' ')
+       }
+
+       line.WriteString(h.prefix)
+       line.WriteString(record.Message)
+
+       var cause string
+
+       for _, attr := range h.attrs {
+               daemonLogAttr(&line, "", attr, &cause)
+       }
+
+       record.Attrs(func(attr slog.Attr) bool {
+               daemonLogAttr(&line, h.group, attr, &cause)
+
+               return true
+       })
+
+       if cause != "" {
+               line.WriteString(": ")
+               line.WriteString(cause)
+       }
+
+       line.WriteByte('\n')
+       h.mutex.Lock()
+       defer h.mutex.Unlock()
+
+       _, err := io.WriteString(h.out, line.String())
+       if err != nil {
+               return fmt.Errorf("write daemon log: %w", err)
+       }
+
+       return nil
+}
+
+func (h *DaemonLogHandler) WithAttrs(attrs []slog.Attr) slog.Handler {
+       clone := *h
+       clone.attrs = append([]slog.Attr(nil), h.attrs...)
+       for _, attr := range attrs {
+               if h.group != "" {
+                       attr = slog.Group(strings.TrimSuffix(h.group, "."), attr)
+               }
+
+               clone.attrs = append(clone.attrs, attr)
+       }
+
+       return &clone
+}
+
+func (h *DaemonLogHandler) WithGroup(name string) slog.Handler {
+       clone := *h
+       if name != "" {
+               clone.group += name + "."
+       }
+
+       return &clone
+}
+
+// daemonLogAttr resolves and writes one attribute, or keeps its cause for the
+// end of the line. Groups flatten into dotted keys and empty attributes produce
+// no text.
+func daemonLogAttr(line *strings.Builder, group string, attr slog.Attr, cause *string) {
+       attr.Value = attr.Value.Resolve()
+       if attr.Equal(slog.Attr{}) {
+               return
+       }
+
+       if attr.Value.Kind() == slog.KindGroup {
+               if attr.Key != "" {
+                       group += attr.Key + "."
+               }
+
+               for _, child := range attr.Value.Group() {
+                       daemonLogAttr(line, group, child, cause)
+               }
+
+               return
+       }
+
+       if attr.Key == "err" {
+               if attr.Value.Any() != nil {
+                       *cause = fmt.Sprint(attr.Value.Any())
+               }
+
+               return
+       }
+
+       line.WriteByte(' ')
+       line.WriteString(group + attr.Key)
+       line.WriteByte('=')
+
+       if attr.Value.Kind() == slog.KindDuration {
+               line.WriteString(durationText(attr.Value.Duration()))
+       } else {
+               fmt.Fprint(line, attr.Value.Any())
+       }
+}

diff --git a/daemon_log_test.go b/daemon_log_test.go
new file mode 100644 (file)
index 0000000..31a3278
--- /dev/null
+++ b/daemon_log_test.go
@@ -0,0 +1,136 @@
+package main
+
+import (
+       "context"
+       "errors"
+       "io"
+       "log/slog"
+       "strings"
+       "sync"
+       "testing"
+       "time"
+
+       "github.com/stretchr/testify/require"
+)
+
+func TestDaemonLogFormatsLevelsAndPrefixes(t *testing.T) {
+       testCases := []struct {
+               name     string
+               level    slog.Level
+               prefix   string
+               priority string
+       }{
+               {
+                       name:     "error names the failed part",
+                       level:    slog.LevelError,
+                       prefix:   "onechat: ",
+                       priority: "3",
+               },
+               {
+                       name:     "warning names the retried part",
+                       level:    slog.LevelWarn,
+                       prefix:   "telegram: ",
+                       priority: "4",
+               },
+               {
+                       name:     "info names the connected part",
+                       level:    slog.LevelInfo,
+                       prefix:   "whatsapp: ",
+                       priority: "6",
+               },
+               {
+                       name:     "debug has its own priority",
+                       level:    slog.LevelDebug,
+                       prefix:   "onechat: ",
+                       priority: "7",
+               },
+       }
+
+       for _, tc := range testCases {
+               t.Run(tc.name, func(t *testing.T) {
+                       for _, journal := range []bool{false, true} {
+                               var out strings.Builder
+
+                               handler := &DaemonLogHandler{
+                                       out:     &out,
+                                       prefix:  tc.prefix,
+                                       journal: journal,
+                                       mutex:   &sync.Mutex{},
+                               }
+
+                               record := slog.NewRecord(time.Date(2026, 1, 2, 3, 4, 5, 0, time.UTC), tc.level, "ready", 0)
+                               require.True(t, handler.Enabled(t.Context(), tc.level))
+                               require.NoError(t, handler.Handle(t.Context(), record))
+
+                               expected := "2026/01/02 03:04:05 " + tc.level.String() + " " + tc.prefix + "ready\n"
+                               if journal {
+                                       expected = "<" + tc.priority + ">" + tc.prefix + "ready\n"
+                               }
+
+                               require.Equal(t, expected, out.String())
+                       }
+               })
+       }
+}
+
+func TestDaemonLogKeepsAttributesInOrderAndCauseLast(t *testing.T) {
+       var out strings.Builder
+
+       handler := &DaemonLogHandler{
+               out:     &out,
+               prefix:  "telegram: ",
+               journal: true,
+               mutex:   &sync.Mutex{},
+       }
+
+       logger := slog.New(handler).With("first", "two words", slog.Attr{})
+       logger.Warn("receive failed", "err", errors.New("502 Bad Gateway"), "retry", 2040*time.Millisecond, "count", 3, "short", 1500*time.Microsecond)
+       require.Equal(t, "<4>telegram: receive failed first=two words retry=2s count=3 short=2ms: 502 Bad Gateway\n", out.String())
+}
+
+func TestDaemonLogOmitsEmptyAttributesAndNilCause(t *testing.T) {
+       var out strings.Builder
+
+       handler := &DaemonLogHandler{
+               out:     &out,
+               prefix:  "onechat: ",
+               journal: true,
+               mutex:   &sync.Mutex{},
+       }
+
+       slog.New(handler).Info("ready", slog.Attr{}, slog.Group("empty"), "err", nil)
+       require.Equal(t, "<6>onechat: ready\n", out.String())
+}
+
+func TestDaemonLogGroupsDoNotChangeOtherLoggers(t *testing.T) {
+       var out strings.Builder
+
+       handler := &DaemonLogHandler{
+               out:     &out,
+               journal: true,
+               mutex:   &sync.Mutex{},
+       }
+
+       logger := slog.New(handler)
+       grouped := logger.With("before", 1).WithGroup("outer").With("saved", 2).WithGroup("inner")
+       grouped.Info("done", slog.Group("", "count", 3))
+       logger.Info("ready")
+       require.Equal(t, "<6>done before=1 outer.saved=2 outer.inner.count=3\n<6>ready\n", out.String())
+}
+
+func TestDaemonLogReturnsWriteFailure(t *testing.T) {
+       handler := &DaemonLogHandler{
+               out:   DaemonLogBrokenWriter{},
+               mutex: &sync.Mutex{},
+       }
+
+       err := handler.Handle(context.Background(), slog.NewRecord(time.Now(), slog.LevelInfo, "ready", 0))
+       require.ErrorIs(t, err, io.ErrClosedPipe)
+       require.ErrorContains(t, err, "write daemon log")
+}
+
+type DaemonLogBrokenWriter struct{}
+
+func (w DaemonLogBrokenWriter) Write(_ []byte) (int, error) {
+       return 0, io.ErrClosedPipe
+}