Skip to content

Commit a919ca7

Browse files
authored
fix(logging): keep the daemon log per-user and out of its own content (#1523)
1 parent 03e708a commit a919ca7

13 files changed

Lines changed: 512 additions & 20 deletions

File tree

docs/CLI.md

Lines changed: 11 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -1533,6 +1533,17 @@ systemd user unit on Linux; where the Linux unit is written, what it contains,
15331533
and what happens on a machine booted by another init system are in
15341534
[LINUX_SETUP.md](LINUX_SETUP.md#systemd-user-service).
15351535
1536+
The macOS agent leaves the daemon's standard output alone — the rotated log file
1537+
already holds every log line — and sends its standard error to
1538+
`~/Library/Logs/neru/daemon.err.log`, beside that log file, where a crash or a
1539+
failure raised before the log file is open ends up. Both stay inside the user's
1540+
own log directory; neither goes to a shared path.
1541+
1542+
An agent installed by an earlier version wrote those two streams to `/tmp`
1543+
instead, and installing over it is refused rather than silently rewritten. To
1544+
move an existing one, run `neru services uninstall && neru services install`,
1545+
then delete the files it left behind at `/tmp/neru.log` and `/tmp/neru.err.log`.
1546+
15361547
`status` reports a machine where the service was never installed as exactly
15371548
that, rather than failing.
15381549

internal/adapter/logger/logger_path.go

Lines changed: 15 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -9,6 +9,20 @@ import (
99
// defaultLogFilePath returns the platform default neru log file path when
1010
// [logging].log_file is empty.
1111
func defaultLogFilePath() (string, error) {
12+
logDir, err := DefaultLogDir()
13+
if err != nil {
14+
return "", err
15+
}
16+
17+
return filepath.Join(logDir, "app.log"), nil
18+
}
19+
20+
// DefaultLogDir returns the per-user directory neru writes its logs to. It is
21+
// exported because the daemon's log file is not the only thing that belongs
22+
// there: a service definition redirecting the daemon's stderr needs the same
23+
// directory, and a second spelling of it would be a second answer to where
24+
// neru's logs live.
25+
func DefaultLogDir() (string, error) {
1226
homeDir, err := os.UserHomeDir()
1327
if err != nil {
1428
return "", err
@@ -38,5 +52,5 @@ func defaultLogFilePath() (string, error) {
3852
logDir = filepath.Join(stateHome, "neru", "log")
3953
}
4054

41-
return filepath.Join(logDir, "app.log"), nil
55+
return logDir, nil
4256
}

internal/app/config.go

Lines changed: 4 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -73,9 +73,12 @@ func (a *App) SetConfigField(ctx context.Context, key, value string) error {
7373
"config set at runtime but failed to persist (the change will not survive a restart)")
7474
}
7575

76+
// Only the key: it names a schema field. The value is what the user typed,
77+
// and the log is not a place config content goes — the same rule the IPC
78+
// controller states in handleConfigSetInMemory.
7679
a.logger.Info("Config field updated at runtime",
7780
zap.String("key", key),
78-
zap.String("value", value),
81+
zap.Int("value_length", len(value)),
7982
)
8083

8184
return nil

internal/app/sequence/executor.go

Lines changed: 22 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -2,6 +2,7 @@ package sequence
22

33
import (
44
"context"
5+
"errors"
56
"os/exec"
67
"strings"
78

@@ -341,11 +342,17 @@ func (e *Executor) shell(ctx context.Context, source, actionStr string) error {
341342

342343
commandOutput, commandErr := command.CombinedOutput()
343344
if commandErr != nil {
345+
// The command string and its output are the two things this must not
346+
// write down: the command is config content, and the output is whatever
347+
// the user's own shell printed. Their sizes and the exit code say as
348+
// much about the failure as the log is entitled to know — matching the
349+
// success path below, and the caller still receives the wrapped error.
344350
e.logger.Error(
345351
"exec step failed",
346352
zap.String("source", source),
347-
zap.String("cmd", cmdString),
348-
zap.ByteString("output", commandOutput),
353+
zap.Int("cmd_length", len(cmdString)),
354+
zap.Int("output_bytes", len(commandOutput)),
355+
zap.Int("exit_code", exitCodeOf(commandErr)),
349356
zap.Error(commandErr),
350357
)
351358

@@ -362,6 +369,19 @@ func (e *Executor) shell(ctx context.Context, source, actionStr string) error {
362369
return nil
363370
}
364371

372+
// exitCodeOf reports the exit status behind a failed command, or -1 when the
373+
// command never ran far enough to have one (a missing shell, a timeout, a
374+
// signal). It exists so the failure log can be specific about *how* the step
375+
// failed without quoting anything the command said.
376+
func exitCodeOf(commandErr error) int {
377+
var exitErr *exec.ExitError
378+
if errors.As(commandErr, &exitErr) {
379+
return exitErr.ExitCode()
380+
}
381+
382+
return -1
383+
}
384+
365385
// stepContext builds the context each step of a sequence runs under: the base
366386
// context, so shutdown releases a step that blocks, carrying the next depth.
367387
func (e *Executor) stepContext(depth int) context.Context {
Lines changed: 240 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,240 @@
1+
package architecture_test
2+
3+
import (
4+
"go/ast"
5+
"go/parser"
6+
"go/token"
7+
"os"
8+
"strconv"
9+
"strings"
10+
"testing"
11+
)
12+
13+
// visibleLogLevels are the zap logger methods that write at or above the
14+
// default threshold, which is info. A daemon logging at its defaults emits
15+
// every one of these, so what they carry reaches a file on disk on a machine
16+
// nobody configured.
17+
//
18+
// Debug is deliberately absent: it is opt-in, and the rule this file pins is
19+
// about what a default install writes down.
20+
var visibleLogLevels = map[string]bool{
21+
"Info": true, "Warn": true, "Error": true,
22+
"DPanic": true, "Panic": true, "Fatal": true,
23+
}
24+
25+
// contentFieldNames are the zap field names that mean "the thing itself" rather
26+
// than a fact about it: a config value the user typed, a shell command line
27+
// from their configuration, or what that command printed. AGENTS.md forbids all
28+
// three — counts, durations, IDs and booleans are what a log is entitled to.
29+
//
30+
// The match is on the exact name, which is what leaves the correct idiom
31+
// spelling itself: cmd_length and output_bytes say the same thing about the
32+
// same data and pass, because a length is not the content.
33+
var contentFieldNames = map[string]bool{
34+
"cmd": true, "command": true, "output": true, "value": true,
35+
}
36+
37+
// TestNoVisibleLogFieldNamesConfigValuesOrCommandOutput pins the half of the
38+
// privacy contract a reviewer cannot hold on their own.
39+
//
40+
// Every field here was correct once. The failure path of an exec step logged
41+
// the command line and its combined output at Error while the success path
42+
// three lines below logged only their sizes, and two config-set paths logged
43+
// the value beside the key while the IPC controller beside them explained in a
44+
// comment why it must not. The regression is invisible in review precisely
45+
// because each site reads like helpful diagnostics.
46+
//
47+
// This reads the call, not the data: a field constructed elsewhere and passed
48+
// in by variable is not caught. That is the trade for a check with no false
49+
// positives — the shape it does catch is the shape every one of these
50+
// regressions took.
51+
func TestNoVisibleLogFieldNamesConfigValuesOrCommandOutput(t *testing.T) {
52+
var offenders []string
53+
54+
fset := token.NewFileSet()
55+
inspected := 0
56+
57+
for _, file := range goFiles(t) {
58+
parsed, parseErr := parser.ParseFile(fset, file.absPath, nil, 0)
59+
if parseErr != nil {
60+
t.Fatalf("ParseFile(%s) error = %v", file.relPath, parseErr)
61+
}
62+
63+
ast.Inspect(parsed, func(node ast.Node) bool {
64+
call, isCall := node.(*ast.CallExpr)
65+
if !isCall {
66+
return true
67+
}
68+
69+
selector, isSelector := call.Fun.(*ast.SelectorExpr)
70+
if !isSelector || !visibleLogLevels[selector.Sel.Name] {
71+
return true
72+
}
73+
74+
names := zapFieldNames(call.Args)
75+
if len(names) == 0 {
76+
return true
77+
}
78+
79+
inspected++
80+
81+
for _, name := range names {
82+
if !contentFieldNames[name] {
83+
continue
84+
}
85+
86+
offenders = append(offenders,
87+
fset.Position(call.Pos()).String()+"\t"+
88+
selector.Sel.Name+"("+strconv.Quote(name)+")")
89+
}
90+
91+
return true
92+
})
93+
}
94+
95+
assertWalkedAtLeast(t, "log calls above debug level", inspected, bulkWalkFloor)
96+
97+
reportOffenders(t, offenders,
98+
"log call names the content itself rather than a fact about it; "+
99+
"log a length, a count or an exit code instead, and let the error "+
100+
"returned to the caller carry the detail")
101+
}
102+
103+
// outputRedirectMarkers are the ways this repository decides where the daemon's
104+
// standard output and standard error go: the two launchd plist keys, and the
105+
// detached launch the macOS installer offers. A file naming one of them is a
106+
// file that answers "where does the daemon's output land".
107+
var outputRedirectMarkers = []string{
108+
"StandardOutPath", "StandardErrorPath", "nohup",
109+
}
110+
111+
// sharedTempPaths are the directories every local user can read and write.
112+
// macOS mounts /tmp mode 1777 and shares it across users, unlike the per-user
113+
// $TMPDIR, so a log parked there is readable by anyone logged in and its name
114+
// is plantable by anyone who gets there first.
115+
var sharedTempPaths = []string{"/tmp/", "/var/tmp/"}
116+
117+
// TestNoServiceDefinitionWritesDaemonOutputToASharedPath keeps the daemon's
118+
// output in the user's own log directory.
119+
//
120+
// The service definitions are written four times over — the plist the CLI
121+
// generates, the plist template shipped for a hand install, the installer
122+
// script's detached launch, and the Nix modules — so the answer to where a log
123+
// goes is only as good as the copy nobody remembered to change. This judges
124+
// every file that decides it, whatever language it is written in.
125+
//
126+
// A file that redirects nothing drops out of the subject set, which is the
127+
// intended behavior: it has no answer to be wrong about, and adding a redirect
128+
// back puts it under this rule again.
129+
func TestNoServiceDefinitionWritesDaemonOutputToASharedPath(t *testing.T) {
130+
subjects := 0
131+
132+
walkRepoFiles(t, findRepoRoot(t), func(file repoFile) {
133+
// This package's own files name the markers to describe the rule.
134+
if file.dir == architecturePackageDir {
135+
return
136+
}
137+
138+
// A test file installs no service. One of them asserts that the plist
139+
// it renders names no shared directory, which means quoting the
140+
// directory — a subject set that judged it would be judging the rule's
141+
// own statement of itself.
142+
if strings.HasSuffix(file.name, "_test.go") {
143+
return
144+
}
145+
146+
// The walk hands over symlinks without following them, and one of them
147+
// points at a directory (.claude/skills), which is not a file to read.
148+
info, statErr := os.Lstat(file.abs)
149+
if statErr != nil {
150+
t.Fatalf("Lstat(%s) error = %v", file.rel, statErr)
151+
}
152+
153+
if !info.Mode().IsRegular() {
154+
return
155+
}
156+
157+
content, readErr := os.ReadFile(file.abs)
158+
if readErr != nil {
159+
t.Fatalf("ReadFile(%s) error = %v", file.rel, readErr)
160+
}
161+
162+
text := string(content)
163+
164+
if !containsAny(text, outputRedirectMarkers) {
165+
return
166+
}
167+
168+
subjects++
169+
170+
for _, shared := range sharedTempPaths {
171+
if !strings.Contains(text, shared) {
172+
continue
173+
}
174+
175+
t.Errorf(
176+
"%s decides where the daemon's output goes and names %s, which "+
177+
"every local user can read and plant a symlink in; use the "+
178+
"per-user log directory the logger already resolves",
179+
file.rel, shared,
180+
)
181+
}
182+
})
183+
184+
assertWalkedAtLeast(t, "files redirecting daemon output", subjects, serviceDefinitionFloor)
185+
}
186+
187+
// serviceDefinitionFloor is the fewest files expected to redirect the daemon's
188+
// output. Four do today — the generated plist, the shipped template, the
189+
// installer script and the home-manager module — so three catches a check that
190+
// has stopped recognizing them without firing when one legitimately stops
191+
// redirecting.
192+
const serviceDefinitionFloor = 3
193+
194+
// containsAny reports whether text contains any of the needles.
195+
func containsAny(text string, needles []string) bool {
196+
for _, needle := range needles {
197+
if strings.Contains(text, needle) {
198+
return true
199+
}
200+
}
201+
202+
return false
203+
}
204+
205+
// zapFieldNames returns the field names of the zap.X("name", …) constructors
206+
// among args, which is how every structured log call in this tree is written.
207+
func zapFieldNames(args []ast.Expr) []string {
208+
var names []string
209+
210+
for _, arg := range args {
211+
call, isCall := arg.(*ast.CallExpr)
212+
if !isCall || len(call.Args) == 0 {
213+
continue
214+
}
215+
216+
selector, isSelector := call.Fun.(*ast.SelectorExpr)
217+
if !isSelector {
218+
continue
219+
}
220+
221+
pkg, isIdent := selector.X.(*ast.Ident)
222+
if !isIdent || pkg.Name != "zap" {
223+
continue
224+
}
225+
226+
literal, isLiteral := call.Args[0].(*ast.BasicLit)
227+
if !isLiteral || literal.Kind != token.STRING {
228+
continue
229+
}
230+
231+
name, unquoteErr := strconv.Unquote(literal.Value)
232+
if unquoteErr != nil {
233+
continue
234+
}
235+
236+
names = append(names, name)
237+
}
238+
239+
return names
240+
}

internal/architecture/doc.go

Lines changed: 2 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -27,6 +27,8 @@
2727
// chain rather than recomputed at its reader.
2828
// - config_example_test.go — the pairing between the config schema and the
2929
// example TOML shipped with it.
30+
// - daemon_log_test.go — the daemon's log carries facts rather than content,
31+
// and every service definition sends its output to a per-user path.
3032
// - darwin_entry_point_headers_test.go — every non-static Neru* entry point
3133
// the darwin bridge defines is declared in its own subsystem's header.
3234
// - dependency_boundary_test.go — the darwin One Rule: only darwin-tagged

0 commit comments

Comments
 (0)