// Cthulhu screen reader. // Copyright (c) 2026 Storm Dragon // Authors: Storm Dragon, Angus Kola // // This program is free software: you can redistribute it and/or modify // it under the terms of the GNU General Public License as published by // the Free Software Foundation, either version 3 of the License, or // (at your option) any later version. // // This program is distributed in the hope that it will be useful, but WITHOUT // ANY WARRANTY; without even the implied warranty of MERCHANTABILITY or // FITNESS FOR A PARTICULAR PURPOSE. See the GNU General Public License for // more details. // // You should have received a copy of the GNU General Public License along with // this program. If not, see . package logging import ( "bytes" "context" "encoding/json" "errors" "fmt" "io" "log/slog" "os" "path/filepath" "strings" "sync" "testing" "time" ) type controlledWriter struct { mutex sync.Mutex output bytes.Buffer started chan struct{} startOnce sync.Once release chan struct{} canceled chan struct{} cancelOnce sync.Once writeError error autoRelease bool closed bool } func newControlledWriter() *controlledWriter { return &controlledWriter{ started: make(chan struct{}), release: make(chan struct{}, 1), canceled: make(chan struct{}), } } func (writer *controlledWriter) Write(data []byte) (int, error) { writer.startOnce.Do(func() { close(writer.started) }) select { case <-writer.release: case <-writer.canceled: return 0, errors.New("diagnostics writer canceled") } if writer.autoRelease { select { case writer.release <- struct{}{}: default: } } writer.mutex.Lock() defer writer.mutex.Unlock() if writer.writeError != nil { return 0, writer.writeError } return writer.output.Write(data) } func (writer *controlledWriter) Cancel() error { writer.cancelOnce.Do(func() { close(writer.canceled) }) return nil } func (writer *controlledWriter) Close() error { writer.mutex.Lock() defer writer.mutex.Unlock() writer.closed = true return nil } func (writer *controlledWriter) releaseWrites(count int) { for index := 0; index < count; index++ { writer.release <- struct{}{} } } func (writer *controlledWriter) lines() []string { writer.mutex.Lock() defer writer.mutex.Unlock() return strings.Split(strings.TrimSpace(writer.output.String()), "\n") } func messageNames(t *testing.T, lines []string) []string { t.Helper() messages := make([]string, 0, len(lines)) for _, line := range lines { if line == "" { continue } var record map[string]any if err := json.Unmarshal([]byte(line), &record); err != nil { t.Fatalf("invalid diagnostics JSON %q: %v", line, err) } messages = append(messages, fmt.Sprint(record["message"])) } return messages } func TestAsyncLoggingDoesNotBlockOnBlockedWriter(t *testing.T) { writer := newControlledWriter() diagnostics := NewAsync(writer, AsyncOptions{Options: Options{Level: slog.LevelDebug}, Capacity: 4, StopTimeout: 100 * time.Millisecond, CancelGrace: 10 * time.Millisecond}) logger := diagnostics.Logger() completed := make(chan struct{}) go func() { logger.Debug("accessibility event") close(completed) }() select { case <-completed: case <-time.After(time.Second): t.Fatal("slog call blocked on diagnostics writer") } if diagnostics.Dropped() != 0 { t.Fatalf("dropped messages = %d, want 0", diagnostics.Dropped()) } writer.Cancel() if err := diagnostics.Stop(context.Background()); err == nil || !strings.Contains(err.Error(), "diagnostics writer canceled") { t.Fatalf("Stop error = %v, want canceled writer error", err) } } func TestAsyncLoggingFlushesInOrder(t *testing.T) { writer := newControlledWriter() diagnostics := NewAsync(writer, AsyncOptions{Capacity: 8, StopTimeout: time.Second, CancelGrace: 10 * time.Millisecond}) logger := diagnostics.Logger() for _, message := range []string{"first", "second", "third", "fourth"} { logger.Info(message) } writer.releaseWrites(4) if err := diagnostics.Stop(context.Background()); err != nil { t.Fatalf("Stop: %v", err) } got := messageNames(t, writer.lines()) want := []string{"first", "second", "third", "fourth"} if fmt.Sprint(got) != fmt.Sprint(want) { t.Fatalf("messages = %v, want %v", got, want) } } func TestAsyncLoggingSaturationKeepsCriticalMessagesAndReportsDrops(t *testing.T) { writer := newControlledWriter() writer.autoRelease = true diagnostics := NewAsync(writer, AsyncOptions{Options: Options{Level: slog.LevelDebug}, Capacity: 2, StopTimeout: time.Second, CancelGrace: 10 * time.Millisecond}) logger := diagnostics.Logger() logger.Debug("debug 1") select { case <-writer.started: case <-time.After(time.Second): t.Fatal("diagnostics writer did not start") } logger.Debug("debug 2") logger.Debug("debug 3") logger.Error("critical message") writer.releaseWrites(1) if err := diagnostics.Stop(context.Background()); err != nil { t.Fatalf("Stop: %v", err) } messages := messageNames(t, writer.lines()) joined := strings.Join(messages, "\n") if !strings.Contains(joined, "critical message") { t.Fatalf("critical message was dropped: %q", joined) } if strings.Contains(joined, "debug 2") { t.Fatalf("oldest queued debug message was retained: %q", joined) } if !strings.Contains(joined, "diagnostics queue overflow") { t.Fatalf("overflow report missing: %q", joined) } if diagnostics.Dropped() == 0 { t.Fatal("drop count was not observable") } } func TestAsyncLoggingNoncriticalRecordCannotEvictCriticalRecords(t *testing.T) { writer := newControlledWriter() writer.autoRelease = true diagnostics := NewAsync(writer, AsyncOptions{Options: Options{Level: slog.LevelDebug}, Capacity: 2, StopTimeout: time.Second, CancelGrace: 10 * time.Millisecond}) logger := diagnostics.Logger() logger.Debug("active writer") select { case <-writer.started: case <-time.After(time.Second): t.Fatal("diagnostics writer did not start") } logger.Warn("warning 1") logger.Error("error 2") logger.Debug("discarded debug") writer.releaseWrites(1) if err := diagnostics.Stop(context.Background()); err != nil { t.Fatalf("Stop: %v", err) } joined := strings.Join(messageNames(t, writer.lines()), "\n") for _, message := range []string{"warning 1", "error 2", "diagnostics queue overflow"} { if !strings.Contains(joined, message) { t.Fatalf("%q missing from diagnostics: %q", message, joined) } } if strings.Contains(joined, "discarded debug") { t.Fatalf("noncritical record displaced a critical record: %q", joined) } } type failingWriter struct{} func (failingWriter) Write([]byte) (int, error) { return 0, errors.New("write failed") } func (failingWriter) Cancel() error { return nil } func (failingWriter) Close() error { return nil } func TestAsyncStopReportsWriteFailure(t *testing.T) { diagnostics := NewAsync(failingWriter{}, AsyncOptions{Capacity: 4, StopTimeout: time.Second, CancelGrace: 10 * time.Millisecond}) diagnostics.Logger().Error("critical message") err := diagnostics.Stop(context.Background()) if err == nil || !strings.Contains(err.Error(), "write diagnostics: write failed") { t.Fatalf("Stop error = %v, want write failure", err) } if err := diagnostics.Stop(context.Background()); err == nil || !strings.Contains(err.Error(), "write failed") { t.Fatalf("repeated Stop error = %v, want preserved write failure", err) } } type timeoutWriter struct { release chan struct{} } func (writer *timeoutWriter) Write([]byte) (int, error) { <-writer.release return 0, nil } func (writer *timeoutWriter) Cancel() error { return nil } func (writer *timeoutWriter) Close() error { return nil } func TestAsyncStopTimeoutIsPreservedAndRepeatedStopJoins(t *testing.T) { writer := &timeoutWriter{release: make(chan struct{})} diagnostics := NewAsync(writer, AsyncOptions{Capacity: 4, StopTimeout: 40 * time.Millisecond, CancelGrace: 10 * time.Millisecond}) diagnostics.Logger().Info("blocked message") ctx, cancel := context.WithTimeout(context.Background(), 80*time.Millisecond) defer cancel() firstError := diagnostics.Stop(ctx) if !errors.Is(firstError, context.DeadlineExceeded) { t.Fatalf("first Stop error = %v, want deadline exceeded", firstError) } writer.release <- struct{}{} secondError := diagnostics.Stop(context.Background()) if !errors.Is(secondError, context.DeadlineExceeded) { t.Fatalf("second Stop error = %v, want preserved deadline exceeded", secondError) } } func TestAsyncRepeatedStopAfterSuccess(t *testing.T) { var output bytes.Buffer diagnostics := NewAsync(NewPassthroughWriter(&output), AsyncOptions{Capacity: 4, StopTimeout: time.Second, CancelGrace: 10 * time.Millisecond}) diagnostics.Logger().Info("message") if err := diagnostics.Stop(context.Background()); err != nil { t.Fatalf("first Stop: %v", err) } if err := diagnostics.Stop(context.Background()); err != nil { t.Fatalf("second Stop: %v", err) } if !strings.Contains(output.String(), "message") { t.Fatalf("flushed output = %q", output.String()) } } func TestOpenFileIsAppendOnlyOwnerRestrictedAndCancellable(t *testing.T) { path := filepath.Join(t.TempDir(), "diagnostics.log") writer, err := OpenFile(path, nil) if err != nil { t.Fatalf("OpenFile: %v", err) } if _, err := writer.Write([]byte("first\n")); err != nil { t.Fatalf("Write: %v", err) } if err := writer.Close(); err != nil { t.Fatalf("Close: %v", err) } info, err := os.Stat(path) if err != nil { t.Fatal(err) } if info.Mode().Perm() != 0o600 { t.Fatalf("file mode = %o, want 0600", info.Mode().Perm()) } writer, err = OpenFile(path, nil) if err != nil { t.Fatalf("reopen: %v", err) } if _, err := writer.Write([]byte("second\n")); err != nil { t.Fatalf("append: %v", err) } if err := writer.Cancel(); err != nil { t.Fatalf("Cancel: %v", err) } data, err := os.ReadFile(path) if err != nil { t.Fatal(err) } if string(data) != "first\nsecond\n" { t.Fatalf("file contents = %q, want append-only data", string(data)) } } var _ io.Writer = (*controlledWriter)(nil)