fix(module): ignore control lines of non-interactive modules, warn once per run on oversize ones
- commit
- 2742b07d2a36bae0805c5dec91b267b944fad8b1
- author
- brice · · 2026-10-09 06:34 UTC
- parent
- 616b0de
- signature
- GPG Verified
CD88F9E564E0102646FB6077A1A07C7C7C3E349D· arch-gpg Verified for the committer email
2 files · +64 -8
M internal/module/control_test.go +46 -5
| @@ -1,11 +1,20 @@ | |||
| 1 | 1 | package module | |
| 2 | 2 | ||
| 3 | 3 | import ( | |
| 4 | + | "bytes" | |
| 4 | 5 | "fmt" | |
| 6 | + | "log/slog" | |
| 5 | 7 | "strings" | |
| 6 | 8 | "testing" | |
| 7 | 9 | ) | |
| 8 | 10 | ||
| 11 | + | // newInteractive is newTest for a module that may send control lines. | |
| 12 | + | func newInteractive() (*Module, chan struct{}) { | |
| 13 | + | m, wake := newTest() | |
| 14 | + | m.Interactive = true | |
| 15 | + | return m, wake | |
| 16 | + | } | |
| 17 | + | ||
| 9 | 18 | func TestParseControlValid(t *testing.T) { | |
| 10 | 19 | c, err := ParseControl([]byte(`{"type":"tooltip","col":2,"width":1,"title":"Steam","body":"line1\nline2"}`)) | |
| 11 | 20 | if err != nil || c.Type != ControlTooltip || c.Col != 2 || c.Width != 1 || c.Title != "Steam" || c.Body != "line1\nline2" { | |
| @@ -99,7 +108,7 @@ func TestParseControlCleansText(t *testing.T) { | |||
| 99 | 108 | } | |
| 100 | 109 | ||
| 101 | 110 | func TestControlLineBetweenFramesLeavesBothIntact(t *testing.T) { | |
| 102 | - | m, _ := newTest() | |
| 111 | + | m, _ := newInteractive() | |
| 103 | 112 | m.readFrames(strings.NewReader("one\n\x1b]777;neferbar;{\"type\":\"close\"}\x07\ntwo\n")) | |
| 104 | 113 | got, changed, _ := m.Take(nil) | |
| 105 | 114 | if !changed || string(got) != "two" { | |
| @@ -114,7 +123,7 @@ func TestControlLineBetweenFramesLeavesBothIntact(t *testing.T) { | |||
| 114 | 123 | } | |
| 115 | 124 | ||
| 116 | 125 | // The control line alone never becomes a frame. | |
| 117 | - | m, _ = newTest() | |
| 126 | + | m, _ = newInteractive() | |
| 118 | 127 | m.readFrames(strings.NewReader("one\n")) | |
| 119 | 128 | m.Take(nil) | |
| 120 | 129 | m.readFrames(strings.NewReader("\x1b]777;neferbar;{\"type\":\"close\"}\x07\n")) | |
| @@ -124,7 +133,7 @@ func TestControlLineBetweenFramesLeavesBothIntact(t *testing.T) { | |||
| 124 | 133 | } | |
| 125 | 134 | ||
| 126 | 135 | func TestUnterminatedControlIsAFrame(t *testing.T) { | |
| 127 | - | m, _ := newTest() | |
| 136 | + | m, _ := newInteractive() | |
| 128 | 137 | m.readFrames(strings.NewReader("\x1b]777;neferbar;{bad\n")) | |
| 129 | 138 | if _, ok := m.TakeControl(); ok { | |
| 130 | 139 | t.Fatal("a line without BEL is not a control line") | |
| @@ -136,7 +145,7 @@ func TestUnterminatedControlIsAFrame(t *testing.T) { | |||
| 136 | 145 | } | |
| 137 | 146 | ||
| 138 | 147 | func TestOversizeControlIsDropped(t *testing.T) { | |
| 139 | - | m, _ := newTest() | |
| 148 | + | m, _ := newInteractive() | |
| 140 | 149 | m.readFrames(strings.NewReader("a\n\x1b]777;neferbar;" + strings.Repeat("x", MaxControl) + "\x07\nb\n")) | |
| 141 | 150 | if _, ok := m.TakeControl(); ok { | |
| 142 | 151 | t.Fatal("an oversize control line must be dropped") | |
| @@ -147,7 +156,7 @@ func TestOversizeControlIsDropped(t *testing.T) { | |||
| 147 | 156 | } | |
| 148 | 157 | ||
| 149 | 158 | func TestControlQueueDropsWhenFull(t *testing.T) { | |
| 150 | - | m, wake := newTest() | |
| 159 | + | m, wake := newInteractive() | |
| 151 | 160 | var in strings.Builder | |
| 152 | 161 | for range 20 { | |
| 153 | 162 | in.WriteString("\x1b]777;neferbar;{\"type\":\"close\"}\x07\n") | |
| @@ -164,3 +173,35 @@ func TestControlQueueDropsWhenFull(t *testing.T) { | |||
| 164 | 173 | t.Fatalf("queued %d (want 8), wake %d", n, len(wake)) | |
| 165 | 174 | } | |
| 166 | 175 | } | |
| 176 | + | ||
| 177 | + | func TestControlLinesOfANonInteractiveModuleAreDropped(t *testing.T) { | |
| 178 | + | m, wake := newTest() | |
| 179 | + | m.readFrames(strings.NewReader("one\n\x1b]777;neferbar;{\"type\":\"close\"}\x07\ntwo\n")) | |
| 180 | + | if _, ok := m.TakeControl(); ok { | |
| 181 | + | t.Fatal("a non-interactive module queued a control line") | |
| 182 | + | } | |
| 183 | + | if got, _, _ := m.Take(nil); string(got) != "two" { | |
| 184 | + | t.Fatalf("frame = %q, want two (the control line is still not a frame)", got) | |
| 185 | + | } | |
| 186 | + | if len(wake) != 1 { // from the frames only | |
| 187 | + | t.Fatalf("wake = %d", len(wake)) | |
| 188 | + | } | |
| 189 | + | } | |
| 190 | + | ||
| 191 | + | func TestOversizeControlWarnsOncePerRun(t *testing.T) { | |
| 192 | + | var logs bytes.Buffer | |
| 193 | + | m, _ := newInteractive() | |
| 194 | + | m.log = slog.New(slog.NewTextHandler(&logs, &slog.HandlerOptions{Level: slog.LevelDebug})) | |
| 195 | + | big := "\x1b]777;neferbar;" + strings.Repeat("x", MaxControl) + "\x07\n" | |
| 196 | + | m.readFrames(strings.NewReader(big + big + big)) | |
| 197 | + | warns := func() int { return strings.Count(logs.String(), "level=WARN") } | |
| 198 | + | if warns() != 1 || strings.Count(logs.String(), "level=DEBUG") != 2 { | |
| 199 | + | t.Fatalf("want 1 warning and 2 debug lines:\n%s", logs.String()) | |
| 200 | + | } | |
| 201 | + | // A new run of the script warns again; runOnce resets the flag. | |
| 202 | + | m.overLogged = false | |
| 203 | + | m.readFrames(strings.NewReader(big)) | |
| 204 | + | if warns() != 2 { | |
| 205 | + | t.Fatalf("a new run must warn again:\n%s", logs.String()) | |
| 206 | + | } | |
| 207 | + | } | |
| @@ -1,11 +1,20 @@ | |||||
| 1 | package module | 1 | package module | ||
| 2 | 2 | ||||
| 3 | import ( | 3 | import ( | ||
| 4 | + | "bytes" | |||
| 4 | "fmt" | 5 | "fmt" | ||
| 6 | + | "log/slog" | |||
| 5 | "strings" | 7 | "strings" | ||
| 6 | "testing" | 8 | "testing" | ||
| 7 | ) | 9 | ) | ||
| 8 | 10 | ||||
| 11 | + | // newInteractive is newTest for a module that may send control lines. | |||
| 12 | + | func newInteractive() (*Module, chan struct{}) { | |||
| 13 | + | m, wake := newTest() | |||
| 14 | + | m.Interactive = true | |||
| 15 | + | return m, wake | |||
| 16 | + | } | |||
| 17 | + | ||||
| 9 | func TestParseControlValid(t *testing.T) { | 18 | func TestParseControlValid(t *testing.T) { | ||
| 10 | c, err := ParseControl([]byte(`{"type":"tooltip","col":2,"width":1,"title":"Steam","body":"line1\nline2"}`)) | 19 | c, err := ParseControl([]byte(`{"type":"tooltip","col":2,"width":1,"title":"Steam","body":"line1\nline2"}`)) | ||
| 11 | if err != nil || c.Type != ControlTooltip || c.Col != 2 || c.Width != 1 || c.Title != "Steam" || c.Body != "line1\nline2" { | 20 | if err != nil || c.Type != ControlTooltip || c.Col != 2 || c.Width != 1 || c.Title != "Steam" || c.Body != "line1\nline2" { | ||
| @@ -99,7 +108,7 @@ func TestParseControlCleansText(t *testing.T) { | |||||
| 99 | } | 108 | } | ||
| 100 | 109 | ||||
| 101 | func TestControlLineBetweenFramesLeavesBothIntact(t *testing.T) { | 110 | func TestControlLineBetweenFramesLeavesBothIntact(t *testing.T) { | ||
| 102 | - | m, _ := newTest() | 111 | + | m, _ := newInteractive() |
| 103 | m.readFrames(strings.NewReader("one\n\x1b]777;neferbar;{\"type\":\"close\"}\x07\ntwo\n")) | 112 | m.readFrames(strings.NewReader("one\n\x1b]777;neferbar;{\"type\":\"close\"}\x07\ntwo\n")) | ||
| 104 | got, changed, _ := m.Take(nil) | 113 | got, changed, _ := m.Take(nil) | ||
| 105 | if !changed || string(got) != "two" { | 114 | if !changed || string(got) != "two" { | ||
| @@ -114,7 +123,7 @@ func TestControlLineBetweenFramesLeavesBothIntact(t *testing.T) { | |||||
| 114 | } | 123 | } | ||
| 115 | 124 | ||||
| 116 | // The control line alone never becomes a frame. | 125 | // The control line alone never becomes a frame. | ||
| 117 | - | m, _ = newTest() | 126 | + | m, _ = newInteractive() |
| 118 | m.readFrames(strings.NewReader("one\n")) | 127 | m.readFrames(strings.NewReader("one\n")) | ||
| 119 | m.Take(nil) | 128 | m.Take(nil) | ||
| 120 | m.readFrames(strings.NewReader("\x1b]777;neferbar;{\"type\":\"close\"}\x07\n")) | 129 | m.readFrames(strings.NewReader("\x1b]777;neferbar;{\"type\":\"close\"}\x07\n")) | ||
| @@ -124,7 +133,7 @@ func TestControlLineBetweenFramesLeavesBothIntact(t *testing.T) { | |||||
| 124 | } | 133 | } | ||
| 125 | 134 | ||||
| 126 | func TestUnterminatedControlIsAFrame(t *testing.T) { | 135 | func TestUnterminatedControlIsAFrame(t *testing.T) { | ||
| 127 | - | m, _ := newTest() | 136 | + | m, _ := newInteractive() |
| 128 | m.readFrames(strings.NewReader("\x1b]777;neferbar;{bad\n")) | 137 | m.readFrames(strings.NewReader("\x1b]777;neferbar;{bad\n")) | ||
| 129 | if _, ok := m.TakeControl(); ok { | 138 | if _, ok := m.TakeControl(); ok { | ||
| 130 | t.Fatal("a line without BEL is not a control line") | 139 | t.Fatal("a line without BEL is not a control line") | ||
| @@ -136,7 +145,7 @@ func TestUnterminatedControlIsAFrame(t *testing.T) { | |||||
| 136 | } | 145 | } | ||
| 137 | 146 | ||||
| 138 | func TestOversizeControlIsDropped(t *testing.T) { | 147 | func TestOversizeControlIsDropped(t *testing.T) { | ||
| 139 | - | m, _ := newTest() | 148 | + | m, _ := newInteractive() |
| 140 | m.readFrames(strings.NewReader("a\n\x1b]777;neferbar;" + strings.Repeat("x", MaxControl) + "\x07\nb\n")) | 149 | m.readFrames(strings.NewReader("a\n\x1b]777;neferbar;" + strings.Repeat("x", MaxControl) + "\x07\nb\n")) | ||
| 141 | if _, ok := m.TakeControl(); ok { | 150 | if _, ok := m.TakeControl(); ok { | ||
| 142 | t.Fatal("an oversize control line must be dropped") | 151 | t.Fatal("an oversize control line must be dropped") | ||
| @@ -147,7 +156,7 @@ func TestOversizeControlIsDropped(t *testing.T) { | |||||
| 147 | } | 156 | } | ||
| 148 | 157 | ||||
| 149 | func TestControlQueueDropsWhenFull(t *testing.T) { | 158 | func TestControlQueueDropsWhenFull(t *testing.T) { | ||
| 150 | - | m, wake := newTest() | 159 | + | m, wake := newInteractive() |
| 151 | var in strings.Builder | 160 | var in strings.Builder | ||
| 152 | for range 20 { | 161 | for range 20 { | ||
| 153 | in.WriteString("\x1b]777;neferbar;{\"type\":\"close\"}\x07\n") | 162 | in.WriteString("\x1b]777;neferbar;{\"type\":\"close\"}\x07\n") | ||
| @@ -164,3 +173,35 @@ func TestControlQueueDropsWhenFull(t *testing.T) { | |||||
| 164 | t.Fatalf("queued %d (want 8), wake %d", n, len(wake)) | 173 | t.Fatalf("queued %d (want 8), wake %d", n, len(wake)) | ||
| 165 | } | 174 | } | ||
| 166 | } | 175 | } | ||
| 176 | + | ||||
| 177 | + | func TestControlLinesOfANonInteractiveModuleAreDropped(t *testing.T) { | |||
| 178 | + | m, wake := newTest() | |||
| 179 | + | m.readFrames(strings.NewReader("one\n\x1b]777;neferbar;{\"type\":\"close\"}\x07\ntwo\n")) | |||
| 180 | + | if _, ok := m.TakeControl(); ok { | |||
| 181 | + | t.Fatal("a non-interactive module queued a control line") | |||
| 182 | + | } | |||
| 183 | + | if got, _, _ := m.Take(nil); string(got) != "two" { | |||
| 184 | + | t.Fatalf("frame = %q, want two (the control line is still not a frame)", got) | |||
| 185 | + | } | |||
| 186 | + | if len(wake) != 1 { // from the frames only | |||
| 187 | + | t.Fatalf("wake = %d", len(wake)) | |||
| 188 | + | } | |||
| 189 | + | } | |||
| 190 | + | ||||
| 191 | + | func TestOversizeControlWarnsOncePerRun(t *testing.T) { | |||
| 192 | + | var logs bytes.Buffer | |||
| 193 | + | m, _ := newInteractive() | |||
| 194 | + | m.log = slog.New(slog.NewTextHandler(&logs, &slog.HandlerOptions{Level: slog.LevelDebug})) | |||
| 195 | + | big := "\x1b]777;neferbar;" + strings.Repeat("x", MaxControl) + "\x07\n" | |||
| 196 | + | m.readFrames(strings.NewReader(big + big + big)) | |||
| 197 | + | warns := func() int { return strings.Count(logs.String(), "level=WARN") } | |||
| 198 | + | if warns() != 1 || strings.Count(logs.String(), "level=DEBUG") != 2 { | |||
| 199 | + | t.Fatalf("want 1 warning and 2 debug lines:\n%s", logs.String()) | |||
| 200 | + | } | |||
| 201 | + | // A new run of the script warns again; runOnce resets the flag. | |||
| 202 | + | m.overLogged = false | |||
| 203 | + | m.readFrames(strings.NewReader(big)) | |||
| 204 | + | if warns() != 2 { | |||
| 205 | + | t.Fatalf("a new run must warn again:\n%s", logs.String()) | |||
| 206 | + | } | |||
| 207 | + | } | |||
M internal/module/module.go +18 -3
| @@ -63,6 +63,10 @@ type Module struct { | |||
| 63 | 63 | control chan []byte // control lines of the script, see TakeControl | |
| 64 | 64 | gen atomic.Uint64 // counts script starts; see Gen | |
| 65 | 65 | ||
| 66 | + | // overLogged: an oversize control line was already logged at Warn in this | |
| 67 | + | // run of the script. Touched by runOnce and readFrames, which never overlap. | |
| 68 | + | overLogged bool | |
| 69 | + | ||
| 66 | 70 | wake chan<- struct{} | |
| 67 | 71 | log *slog.Logger | |
| 68 | 72 | ||
| @@ -193,6 +197,7 @@ func (m *Module) Run(ctx context.Context) { | |||
| 193 | 197 | ||
| 194 | 198 | func (m *Module) runOnce(ctx context.Context) error { | |
| 195 | 199 | m.gen.Add(1) | |
| 200 | + | m.overLogged = false // readFrames of the previous run has ended | |
| 196 | 201 | cmd := exec.CommandContext(ctx, "/bin/sh", "-c", m.Exec) | |
| 197 | 202 | cmd.Stderr = &logWriter{log: m.log, name: m.Name} | |
| 198 | 203 | cmd.SysProcAttr = &syscall.SysProcAttr{Setpgid: true, Pdeathsig: syscall.SIGTERM} | |
| @@ -284,9 +289,13 @@ func (m *Module) TakeControl() ([]byte, bool) { | |||
| 284 | 289 | } | |
| 285 | 290 | } | |
| 286 | 291 | ||
| 287 | - | // queueControl keeps a copy of the JSON of a control line. A full queue drops | |
| 288 | - | // the line: the bar is not draining it. | |
| 292 | + | // queueControl keeps a copy of the JSON of a control line of an interactive | |
| 293 | + | // module. A full queue drops the | |
| 294 | + | // line: the bar is not draining it. | |
| 289 | 295 | func (m *Module) queueControl(json []byte) { | |
| 296 | + | if !m.Interactive { | |
| 297 | + | return // only interactive modules open popups: do not keep or parse the line | |
| 298 | + | } | |
| 290 | 299 | select { | |
| 291 | 300 | case m.control <- append([]byte(nil), json...): | |
| 292 | 301 | m.signal() | |
| @@ -300,7 +309,13 @@ func (m *Module) line(line []byte, over bool) { | |||
| 300 | 309 | if bytes.HasPrefix(line, []byte(controlPrefix)) { | |
| 301 | 310 | switch { | |
| 302 | 311 | case over: | |
| 303 | - | m.log.Warn("module control line too long; dropped", "module", m.Name, "max", MaxControl) | |
| 312 | + | // A script can repeat this at will: say it once per run. | |
| 313 | + | if !m.overLogged { | |
| 314 | + | m.overLogged = true | |
| 315 | + | m.log.Warn("module control line too long; dropped (shown once per run)", "module", m.Name, "max", MaxControl) | |
| 316 | + | } else { | |
| 317 | + | m.log.Debug("module control line too long; dropped", "module", m.Name, "max", MaxControl) | |
| 318 | + | } | |
| 304 | 319 | return | |
| 305 | 320 | case len(line) > 0 && line[len(line)-1] == controlEnd: | |
| 306 | 321 | m.queueControl(line[len(controlPrefix) : len(line)-1]) | |
| @@ -63,6 +63,10 @@ type Module struct { | |||||
| 63 | control chan []byte // control lines of the script, see TakeControl | 63 | control chan []byte // control lines of the script, see TakeControl | ||
| 64 | gen atomic.Uint64 // counts script starts; see Gen | 64 | gen atomic.Uint64 // counts script starts; see Gen | ||
| 65 | 65 | ||||
| 66 | + | // overLogged: an oversize control line was already logged at Warn in this | |||
| 67 | + | // run of the script. Touched by runOnce and readFrames, which never overlap. | |||
| 68 | + | overLogged bool | |||
| 69 | + | ||||
| 66 | wake chan<- struct{} | 70 | wake chan<- struct{} | ||
| 67 | log *slog.Logger | 71 | log *slog.Logger | ||
| 68 | 72 | ||||
| @@ -193,6 +197,7 @@ func (m *Module) Run(ctx context.Context) { | |||||
| 193 | 197 | ||||
| 194 | func (m *Module) runOnce(ctx context.Context) error { | 198 | func (m *Module) runOnce(ctx context.Context) error { | ||
| 195 | m.gen.Add(1) | 199 | m.gen.Add(1) | ||
| 200 | + | m.overLogged = false // readFrames of the previous run has ended | |||
| 196 | cmd := exec.CommandContext(ctx, "/bin/sh", "-c", m.Exec) | 201 | cmd := exec.CommandContext(ctx, "/bin/sh", "-c", m.Exec) | ||
| 197 | cmd.Stderr = &logWriter{log: m.log, name: m.Name} | 202 | cmd.Stderr = &logWriter{log: m.log, name: m.Name} | ||
| 198 | cmd.SysProcAttr = &syscall.SysProcAttr{Setpgid: true, Pdeathsig: syscall.SIGTERM} | 203 | cmd.SysProcAttr = &syscall.SysProcAttr{Setpgid: true, Pdeathsig: syscall.SIGTERM} | ||
| @@ -284,9 +289,13 @@ func (m *Module) TakeControl() ([]byte, bool) { | |||||
| 284 | } | 289 | } | ||
| 285 | } | 290 | } | ||
| 286 | 291 | ||||
| 287 | - | // queueControl keeps a copy of the JSON of a control line. A full queue drops | 292 | + | // queueControl keeps a copy of the JSON of a control line of an interactive |
| 288 | - | // the line: the bar is not draining it. | 293 | + | // module. A full queue drops the |
| 294 | + | // line: the bar is not draining it. | |||
| 289 | func (m *Module) queueControl(json []byte) { | 295 | func (m *Module) queueControl(json []byte) { | ||
| 296 | + | if !m.Interactive { | |||
| 297 | + | return // only interactive modules open popups: do not keep or parse the line | |||
| 298 | + | } | |||
| 290 | select { | 299 | select { | ||
| 291 | case m.control <- append([]byte(nil), json...): | 300 | case m.control <- append([]byte(nil), json...): | ||
| 292 | m.signal() | 301 | m.signal() | ||
| @@ -300,7 +309,13 @@ func (m *Module) line(line []byte, over bool) { | |||||
| 300 | if bytes.HasPrefix(line, []byte(controlPrefix)) { | 309 | if bytes.HasPrefix(line, []byte(controlPrefix)) { | ||
| 301 | switch { | 310 | switch { | ||
| 302 | case over: | 311 | case over: | ||
| 303 | - | m.log.Warn("module control line too long; dropped", "module", m.Name, "max", MaxControl) | 312 | + | // A script can repeat this at will: say it once per run. |
| 313 | + | if !m.overLogged { | |||
| 314 | + | m.overLogged = true | |||
| 315 | + | m.log.Warn("module control line too long; dropped (shown once per run)", "module", m.Name, "max", MaxControl) | |||
| 316 | + | } else { | |||
| 317 | + | m.log.Debug("module control line too long; dropped", "module", m.Name, "max", MaxControl) | |||
| 318 | + | } | |||
| 304 | return | 319 | return | ||
| 305 | case len(line) > 0 && line[len(line)-1] == controlEnd: | 320 | case len(line) > 0 && line[len(line)-1] == controlEnd: | ||
| 306 | m.queueControl(line[len(controlPrefix) : len(line)-1]) | 321 | m.queueControl(line[len(controlPrefix) : len(line)-1]) | ||