diff --git a/.gitignore b/.gitignore index 51f40cf..5633774 100644 --- a/.gitignore +++ b/.gitignore @@ -17,3 +17,10 @@ __pycache__/ /distro-packages/Arch-Linux/cthulhu-git/*/ /cmd/cthulhu/cthulhu + +# Local tooling output and debug artifacts (never fixtures) +/graphify-out/ +/*.log +*.duckdb +*.duckdb.wal +/test.db* diff --git a/AGENTS.md b/AGENTS.md index da69dfc..cfe0351 100644 --- a/AGENTS.md +++ b/AGENTS.md @@ -22,10 +22,12 @@ Use Go 1.24+ with CGO and development libraries listed by the Arch `PKGBUILD`. - `go build -o build/cthulhu ./cmd/cthulhu`: build the reader. - `go build -tags brlapi -o build/cthulhu-braille ./cmd/cthulhu-braille`: build the Braille helper. +- `go build -tags duckdb -o build/cthulhu ./cmd/cthulhu`: build the reader with `--debug-db` DuckDB debug-log support (needs duckdb headers at build time only; libduckdb is dlopen'ed at runtime and is an optional package dependency; test with `go test -tags duckdb ./internal/logging/ ./cmd/cthulhu/`). - `go build -o build/cthulhu-input-helper ./cmd/cthulhu-input-helper`: build the remote input helper; install it beside the reader for incoming keyboard control. - `go test ./... -count=1`: run default tests; native cases may skip. - `go test -tags brlapi ./... -count=1`: run packaging checks. - `go vet ./...`: check common Go errors. +- `golangci-lint run ./...`: run the configured lint gate (`.golangci.yml`, v2 schema; build tags brlapi/duckdb set there; keep the linter built with a Go at least as new as the project toolchain or it reports typecheck garbage). - `go run ./cmd/parityledger validate testdata/parity-ledger.csv`: validate parity records. - `./build/cthulhu --check-config`: validate settings; `./build/cthulhu` starts the reader. diff --git a/README.md b/README.md index e6e16dd..75df1d7 100644 --- a/README.md +++ b/README.md @@ -355,7 +355,58 @@ existing announcement behavior. Debug logging with `--debug-file PATH` replaces any existing log at that path. Add `--append` to preserve earlier sessions, for example `cthulhu --debug-file /tmp/cthulhu.log --append`. -`--append` requires `--debug-file`. A log can still grow during a long session. +`--append` requires `--debug-file` or `--debug-db`. A log can still grow during a long session. + +Builds compiled with `-tags duckdb` (needs the DuckDB headers at build time; +the packaged Arch build is one) also accept `--debug-db PATH`, which writes +the same redacted debug records to a DuckDB database instead of, or in +addition to, the NDJSON file. `libduckdb` is loaded only when the flag is +used, so it is an optional runtime dependency (an Arch `optdepends`); the +reader runs normally without it, and `--debug-db` reports that the `duckdb` +package must be installed: +`cthulhu --debug-db /tmp/cthulhu.duckdb`. Passing both flags writes both +sinks. Without `--append` an existing database at the path is replaced; with +`--append` each run adds a row to the `sessions` table (`session_id`, +`started_at`, `pid`) and its records to the `logs` table. `logs` has typed +columns `seq` (per-session record order), `session_id`, `ts` (timestamptz), +`level`, `message`, `source`, and `function`, plus typed columns for the +record attributes real logs show are frequent and type-stable (such as +`role`, `application`, `focused`, `snapshot_duration`, and `error`; run +`DESCRIBE logs` for the full list). Every field, promoted or not, is also +preserved in the `attrs` JSON column, so nested and rare attributes remain +available. Databases written by the first schema version gain the promoted +columns automatically on the next `--append` open. This makes agent and +script queries cheap SQL instead of a full scan of a large JSON file, for +example: + +```sh +duckdb -readonly /tmp/cthulhu.duckdb +``` + +```sql +SELECT seq, ts, message, error +FROM logs +WHERE level IN ('WARN', 'ERROR') + AND session_id = (SELECT session_id FROM sessions ORDER BY started_at DESC LIMIT 1) +ORDER BY seq; + +SELECT role, count(*), round(avg(snapshot_duration) / 1e6, 2) AS avg_snapshot_ms +FROM logs WHERE snapshot_duration IS NOT NULL GROUP BY role ORDER BY 2 DESC; + +SELECT message, count(*) FROM logs GROUP BY message ORDER BY 2 DESC LIMIT 20; +``` + +The database file and its write-ahead log are restricted to the owner +(`0600`), like the debug file, and need the same review before sharing: +records can contain spoken page text. Routine records are buffered briefly +(flushed at least once a second while records flow, and immediately for +warnings and errors), so a hard crash can lose the last few hundred routine +records from the database; the NDJSON file writes every record immediately. +While the reader is running it holds DuckDB's write lock, so inspect a copy +of the database and its `.wal` file, or query after the reader stops. +In builds without the `duckdb` tag, +`--debug-db` fails at startup with an explanation instead of silently +writing nothing. For browser bug reports, start Cthulhu with `--debug-file /tmp/cthulhu-browser.log` and reproduce the affected navigation. The startup record includes the release diff --git a/cmd/cthulhu/main.go b/cmd/cthulhu/main.go index a8fb3ee..f5bdfd2 100644 --- a/cmd/cthulhu/main.go +++ b/cmd/cthulhu/main.go @@ -27,6 +27,7 @@ import ( "os" "os/signal" "os/user" + "path/filepath" "syscall" "time" @@ -80,8 +81,9 @@ func run(ctx context.Context, arguments []string, stdout, stderr io.Writer) (res clipboardWatch := options.Bool("clipboard-watch", false, "run the internal clipboard change helper (private pipe protocol)") ocrCapture := options.Bool("ocr-capture", false, "run the internal OCR capture helper (private pipe protocol)") ocrConfirm := options.Bool("ocr-confirm", false, "run the internal OCR click confirmation helper") - appendLog := options.Bool("append", false, "preserve existing debug log contents (requires --debug-file)") + appendLog := options.Bool("append", false, "preserve existing debug log contents (requires --debug-file or --debug-db)") debugFile := options.String("debug-file", "", "enable debug logging only to this file, replacing existing contents") + debugDB := options.String("debug-db", "", "enable debug logging only to this DuckDB database, replacing existing contents") speechSocket := options.String( "speech-socket", "", @@ -127,8 +129,11 @@ func run(ctx context.Context, arguments []string, stdout, stderr io.Writer) (res if options.NArg() != 0 { return fmt.Errorf("unexpected argument %q", options.Arg(0)) } - if *appendLog && *debugFile == "" { - return errors.New("--append requires --debug-file") + if *appendLog && *debugFile == "" && *debugDB == "" { + return errors.New("--append requires --debug-file or --debug-db") + } + if *debugFile != "" && *debugDB != "" && sameDestination(*debugFile, *debugDB) { + return errors.New("--debug-file and --debug-db must be different files") } if *showVersion || *shortVersion { fmt.Fprintln(stdout, version.Details( @@ -181,12 +186,36 @@ func run(ctx context.Context, arguments []string, stdout, stderr io.Writer) (res } } logger := slog.New(slog.DiscardHandler) - if *debugFile != "" { - fileWriter, err := logging.OpenFile(*debugFile, nil, *appendLog) - if err != nil { - return fmt.Errorf("open debug log: %w", err) + if *debugFile != "" || *debugDB != "" { + // Open the database first: its routine failure modes (libduckdb not + // installed, foreign file) must not destroy an existing debug log + // by truncating it before the run even starts. + var databaseWriter, fileWriter logging.DiagnosticsWriter + if *debugDB != "" { + var err error + databaseWriter, err = logging.OpenDuckDB(*debugDB, *appendLog, os.Getpid()) + if err != nil { + return fmt.Errorf("open debug database: %w", err) + } } - diagnostics := logging.NewAsync(fileWriter, logging.AsyncOptions{ + if *debugFile != "" { + var err error + fileWriter, err = logging.OpenFile(*debugFile, nil, *appendLog) + if err != nil { + if databaseWriter != nil { + _ = databaseWriter.Close() + } + return fmt.Errorf("open debug log: %w", err) + } + } + sinks := make([]logging.DiagnosticsWriter, 0, 2) + if fileWriter != nil { + sinks = append(sinks, fileWriter) + } + if databaseWriter != nil { + sinks = append(sinks, databaseWriter) + } + diagnostics := logging.NewAsync(logging.NewMultiWriter(sinks...), logging.AsyncOptions{ Options: logging.Options{Level: slog.LevelDebug, AddSource: true}, }) defer func() { @@ -261,3 +290,18 @@ func run(ctx context.Context, arguments []string, stdout, stderr io.Writer) (res } return err } + +// sameDestination reports whether two sink paths name the same file, via +// cleaned absolute paths or, when both exist, file identity (symlink and +// ./ aliases). Sharing one file between the NDJSON and DuckDB sinks would +// corrupt both. +func sameDestination(a, b string) bool { + absA, errA := filepath.Abs(a) + absB, errB := filepath.Abs(b) + if errA == nil && errB == nil && absA == absB { + return true + } + infoA, errA := os.Stat(a) + infoB, errB := os.Stat(b) + return errA == nil && errB == nil && os.SameFile(infoA, infoB) +} diff --git a/cmd/cthulhu/main_duckdb_native_test.go b/cmd/cthulhu/main_duckdb_native_test.go new file mode 100644 index 0000000..3359ca3 --- /dev/null +++ b/cmd/cthulhu/main_duckdb_native_test.go @@ -0,0 +1,78 @@ +//go:build duckdb && cgo + +// 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 main + +import ( + "bytes" + "context" + "os" + "os/exec" + "path/filepath" + "strings" + "testing" +) + +// --debug-db and --debug-file together must both receive the session: the +// NDJSON file stays available for existing tooling while the database gets +// the same records in queryable form. +func TestDebugDBAndFileBothReceiveRecords(t *testing.T) { + directory := t.TempDir() + databasePath := filepath.Join(directory, "debug.duckdb") + logPath := filepath.Join(directory, "debug.log") + configPath := filepath.Join(directory, "absent.toml") + var stdout, stderr bytes.Buffer + if err := run(context.Background(), []string{ + "--check-config", "--config", configPath, + "--debug-file", logPath, "--debug-db", databasePath, + }, &stdout, &stderr); err != nil { + t.Fatal(err) + } + if stderr.Len() != 0 { + t.Fatalf("debug sinks wrote to terminal: %q", stderr.String()) + } + logData, err := os.ReadFile(logPath) + if err != nil { + t.Fatal(err) + } + if !strings.Contains(string(logData), `"starting Cthulhu"`) { + t.Fatalf("debug file missing startup record: %s", logData) + } + + cli, err := exec.LookPath("duckdb") + if err != nil { + t.Skip("duckdb CLI not installed; cannot verify database contents") + } + output, err := exec.Command(cli, "-readonly", "-noheader", "-list", databasePath, + "-c", "SELECT message || '|' || (attrs->>'$.pid' IS NOT NULL) FROM logs WHERE seq = 1").CombinedOutput() + if err != nil { + t.Fatalf("duckdb query: %v\n%s", err, output) + } + if got := strings.TrimSpace(string(output)); got != "starting Cthulhu|true" { + t.Fatalf("first database record = %q", got) + } +} + +func TestDebugDBOpenFailure(t *testing.T) { + var output bytes.Buffer + err := run(context.Background(), []string{"--debug-db", t.TempDir()}, &output, &output) + if err == nil || !strings.Contains(err.Error(), "open debug database") { + t.Fatalf("error = %v", err) + } +} diff --git a/cmd/cthulhu/main_duckdb_unavailable_test.go b/cmd/cthulhu/main_duckdb_unavailable_test.go new file mode 100644 index 0000000..5d86da0 --- /dev/null +++ b/cmd/cthulhu/main_duckdb_unavailable_test.go @@ -0,0 +1,56 @@ +//go:build !duckdb || !cgo + +// 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 main + +import ( + "bytes" + "context" + "errors" + "path/filepath" + "strings" + "testing" + + "git.stormux.org/storm/cthulhu/internal/logging" +) + +func TestDebugDBUnavailableWithoutBuildTag(t *testing.T) { + databasePath := filepath.Join(t.TempDir(), "debug.duckdb") + var output bytes.Buffer + err := run(context.Background(), []string{"--debug-db", databasePath}, &output, &output) + if !errors.Is(err, logging.ErrDuckDBUnavailable) { + t.Fatalf("error = %v, want ErrDuckDBUnavailable", err) + } + if !strings.Contains(err.Error(), "open debug database") { + t.Fatalf("error = %v, want open context", err) + } +} + +func TestAppendAcceptsDebugDBAsSink(t *testing.T) { + databasePath := filepath.Join(t.TempDir(), "debug.duckdb") + var output bytes.Buffer + err := run(context.Background(), []string{"--append", "--debug-db", databasePath}, &output, &output) + if err != nil && strings.Contains(err.Error(), "--append requires") { + t.Fatalf("--append rejected --debug-db as its sink: %v", err) + } + // In this build the run then fails opening the database instead. + if !errors.Is(err, logging.ErrDuckDBUnavailable) { + t.Fatalf("error = %v, want ErrDuckDBUnavailable", err) + } +} diff --git a/cmd/cthulhu/main_test.go b/cmd/cthulhu/main_test.go index cffabd0..1208382 100644 --- a/cmd/cthulhu/main_test.go +++ b/cmd/cthulhu/main_test.go @@ -301,14 +301,29 @@ func TestStandaloneDebugFlagRejected(t *testing.T) { } } -func TestAppendRequiresDebugFile(t *testing.T) { +func TestAppendRequiresDebugSink(t *testing.T) { var output bytes.Buffer err := run(context.Background(), []string{"--append"}, &output, &output) - if err == nil || err.Error() != "--append requires --debug-file" { + if err == nil || err.Error() != "--append requires --debug-file or --debug-db" { t.Fatalf("error = %v", err) } } +func TestDebugFileAndDBSameFileRejected(t *testing.T) { + shared := filepath.Join(t.TempDir(), "debug.out") + alias := filepath.Dir(shared) + string(filepath.Separator) + "." + string(filepath.Separator) + "debug.out" + for _, arguments := range [][]string{ + {"--debug-file", shared, "--debug-db", shared}, + {"--debug-file", shared, "--debug-db", alias}, + } { + var output bytes.Buffer + err := run(context.Background(), arguments, &output, &output) + if err == nil || !strings.Contains(err.Error(), "must be different files") { + t.Fatalf("arguments %v: error = %v", arguments, err) + } + } +} + func TestDebugFileStartsFresh(t *testing.T) { logPath := filepath.Join(t.TempDir(), "debug.log") configPath := filepath.Join(t.TempDir(), "absent.toml") diff --git a/distro-packages/Arch-Linux/cthulhu-git/PKGBUILD b/distro-packages/Arch-Linux/cthulhu-git/PKGBUILD index 96ecb28..cd914eb 100644 --- a/distro-packages/Arch-Linux/cthulhu-git/PKGBUILD +++ b/distro-packages/Arch-Linux/cthulhu-git/PKGBUILD @@ -5,7 +5,7 @@ pkgbase=cthulhu-git pkgname=cthulhu-git _pkgname=cthulhu pkgver=2026.10.31.r588.g9680b58 -pkgrel=2 +pkgrel=3 pkgdesc="Desktop-agnostic screen reader with speech, Braille, and Tentacle support" url="https://git.stormux.org/storm/cthulhu" arch=(x86_64 aarch64 armv7h) @@ -45,6 +45,7 @@ optdepends=( 'git: Discover and update Tentacle repositories' 'tesseract: OCR engine for text recognition' 'tesseract-data-eng: English OCR language data' + 'duckdb: DuckDB debug database logging with --debug-db' ) optdepends_x86_64=( # Wine accessibility helpers are supported on x86_64. @@ -54,6 +55,8 @@ makedepends=( git go pkgconf + # Headers only: libduckdb is dlopen'ed at runtime when --debug-db is used. + duckdb ) options=(!debug !lto) source=("${_pkgname}::git+https://git.stormux.org/storm/${_pkgname}.git#branch=master") @@ -82,7 +85,7 @@ build() { export GOCACHE="${GOCACHE:-${srcdir}/go-build}" export GOFLAGS="-buildmode=pie -trimpath -ldflags=-linkmode=external -mod=readonly -modcacherw" - go build -o build/cthulhu ./cmd/cthulhu + go build -tags duckdb -o build/cthulhu ./cmd/cthulhu go build -tags brlapi -o build/cthulhu-braille ./cmd/cthulhu-braille # Include the helper once incoming Remote keyboard support reaches master. if [[ -d cmd/cthulhu-input-helper ]]; then @@ -95,7 +98,7 @@ check() { export CGO_ENABLED=1 export GOPATH="${srcdir}/go" export GOCACHE="${GOCACHE:-${srcdir}/go-build}" - go test -tags brlapi ./... -count=1 + go test -tags 'brlapi duckdb' ./... -count=1 } package() { diff --git a/internal/logging/duckdb.go b/internal/logging/duckdb.go new file mode 100644 index 0000000..a095664 --- /dev/null +++ b/internal/logging/duckdb.go @@ -0,0 +1,381 @@ +// 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" + "encoding/json" + "errors" + "fmt" + "io" + "strings" + "time" +) + +// ErrDuckDBUnavailable reports that DuckDB debug logging cannot be used in +// this build or on this system: either the build was compiled without +// -tags duckdb, or libduckdb could not be loaded at runtime. +var ErrDuckDBUnavailable = errors.New("duckdb debug logging unavailable (requires a -tags duckdb build and an installed libduckdb)") + +// Debug database schema. The fields Handler.format emits for every record +// become typed columns, and so do the record attributes listed in +// promotedAttrs: keys that real logs show are frequent, scalar, and +// type-stable, which makes them honest filter and aggregate dimensions for +// SQL (real types, column statistics, no JSON extraction). Everything else +// is preserved verbatim in the attrs JSON column, promoted keys included, +// because the full key set is open-ended (over 100 keys, nested objects +// and arrays, occasional type changes), so one column per key is not +// viable. Promoted columns follow attrs so a v1 database upgrades in +// place by appending them. +const ( + duckDBSchemaVersion = "2" + duckDBSchemaVersionV1 = "1" + + duckDBCreateMeta = `CREATE TABLE IF NOT EXISTS meta ( + key VARCHAR PRIMARY KEY, + value VARCHAR NOT NULL + )` + duckDBCreateSessions = `CREATE TABLE IF NOT EXISTS sessions ( + session_id VARCHAR PRIMARY KEY, + started_at TIMESTAMPTZ NOT NULL, + pid BIGINT NOT NULL + )` +) + +// Column order here is the appender order in duckdb_native.go. +var duckDBCreateLogs = buildLogsDDL() + +func buildLogsDDL() string { + var ddl strings.Builder + ddl.WriteString(`CREATE TABLE IF NOT EXISTS logs ( + seq BIGINT NOT NULL, + session_id VARCHAR NOT NULL, + ts TIMESTAMPTZ NOT NULL, + level VARCHAR NOT NULL, + message VARCHAR NOT NULL, + source VARCHAR, + function VARCHAR, + attrs JSON NOT NULL`) + for _, attr := range promotedAttrs { + fmt.Fprintf(&ddl, ",\n\t\t\"%s\" %s", attr.key, attr.sqlType()) + } + ddl.WriteString("\n\t)") + return ddl.String() +} + +type promotedKind int + +const ( + promotedText promotedKind = iota + promotedInt + promotedBool +) + +type promotedAttr struct { + key string + kind promotedKind +} + +func (attr promotedAttr) sqlType() string { + switch attr.kind { + case promotedInt: + return "BIGINT" + case promotedBool: + return "BOOLEAN" + default: + return "VARCHAR" + } +} + +// promotedAttrs was derived by profiling real debug sessions: every key +// here is scalar and single-typed (null aside) at meaningful frequency, or +// carries errors. Free-text payloads (utterance, speech_text) stay in +// attrs only; they are content, not dimensions. +var promotedAttrs = []promotedAttr{ + {key: "role", kind: promotedText}, + {key: "type", kind: promotedText}, + {key: "bus", kind: promotedText}, + {key: "source_path", kind: promotedText}, + {key: "application", kind: promotedText}, + {key: "window_path", kind: promotedText}, + {key: "native_type", kind: promotedText}, + {key: "origin_path", kind: promotedText}, + {key: "window_bus", kind: promotedText}, + {key: "focus_outside_document", kind: promotedText}, + {key: "radio_group_name", kind: promotedText}, + {key: "editable_root", kind: promotedText}, + {key: "read_only_combo", kind: promotedText}, + {key: "key", kind: promotedText}, + {key: "cause", kind: promotedText}, + {key: "reason", kind: promotedText}, + {key: "command", kind: promotedText}, + {key: "object_path", kind: promotedText}, + {key: "capture_reason", kind: promotedText}, + {key: "error", kind: promotedText}, + {key: "component", kind: promotedText}, + {key: "service", kind: promotedText}, + + {key: "window_recovered", kind: promotedBool}, + {key: "focused", kind: promotedBool}, + {key: "browser_tab", kind: promotedBool}, + {key: "selected", kind: promotedBool}, + {key: "checked", kind: promotedBool}, + {key: "prompt_message_present", kind: promotedBool}, + {key: "editable", kind: promotedBool}, + {key: "autocomplete", kind: promotedBool}, + {key: "autocomplete_popup", kind: promotedBool}, + {key: "native_caret_known", kind: promotedBool}, + {key: "input_repeat", kind: promotedBool}, + {key: "append", kind: promotedBool}, + {key: "interrupt_previous", kind: promotedBool}, + {key: "character", kind: promotedBool}, + {key: "custom_echo", kind: promotedBool}, + {key: "moved", kind: promotedBool}, + {key: "has_offset", kind: promotedBool}, + + {key: "snapshot_duration", kind: promotedInt}, + {key: "event_detail1", kind: promotedInt}, + {key: "native_caret_offset", kind: promotedInt}, + {key: "native_line_start", kind: promotedInt}, + {key: "character_count", kind: promotedInt}, + {key: "selection_start", kind: promotedInt}, + {key: "selection_end", kind: promotedInt}, + {key: "input_timestamp", kind: promotedInt}, + {key: "recent", kind: promotedInt}, + {key: "input_keycode", kind: promotedInt}, + {key: "read_all_index", kind: promotedInt}, + {key: "capture_duration", kind: promotedInt}, + {key: "speech_style", kind: promotedInt}, + {key: "unit", kind: promotedInt}, + {key: "offset", kind: promotedInt}, + {key: "elapsed", kind: promotedInt}, + {key: "duration", kind: promotedInt}, + {key: "stage_duration", kind: promotedInt}, + {key: "captured_nodes", kind: promotedInt}, + {key: "pending_nodes", kind: promotedInt}, + {key: "text_bytes", kind: promotedInt}, +} + +// promotedValue is one promotedAttrs entry decoded from a record. valid is +// false when the key is absent, JSON null, or holds a different type than +// the column; the value still survives in attrs in every case. +type promotedValue struct { + text string + integer int64 + boolean bool + valid bool +} + +func decodePromoted(kind promotedKind, raw json.RawMessage) promotedValue { + if string(raw) == "null" { + return promotedValue{} + } + switch kind { + case promotedText: + var value string + if json.Unmarshal(raw, &value) == nil { + return promotedValue{text: value, valid: true} + } + case promotedInt: + var value int64 + if json.Unmarshal(raw, &value) == nil { + return promotedValue{integer: value, valid: true} + } + case promotedBool: + var value bool + if json.Unmarshal(raw, &value) == nil { + return promotedValue{boolean: value, valid: true} + } + } + return promotedValue{} +} + +// parsedRecord is one formatted log line split into typed columns and the +// remaining attributes as JSON object text. +type parsedRecord struct { + timestamp time.Time + level string + message string + source string + function string + attrs string + promoted []promotedValue +} + +// parseLogRecord splits one NDJSON line produced by Handler.format. The +// formatter emits message, level, source and function first, then any +// record attributes, and time last of all. An attribute may reuse one of +// those names (for example an integer "level" attribute), so the leading +// fields are owned by their first occurrence and time by its last; +// superseded duplicates fall through to attrs. ok is false for lines that +// do not match the formatter's shape, in which case the caller stores the +// raw line instead of dropping it. +func parseLogRecord(line []byte) (record parsedRecord, ok bool) { + decoder := json.NewDecoder(bytes.NewReader(line)) + token, err := decoder.Token() + if err != nil { + return parsedRecord{}, false + } + if delim, isDelim := token.(json.Delim); !isDelim || delim != '{' { + return parsedRecord{}, false + } + attrs := map[string]json.RawMessage{} + seen := map[string]bool{} + var timeRaw json.RawMessage + for decoder.More() { + keyToken, err := decoder.Token() + if err != nil { + return parsedRecord{}, false + } + key, isString := keyToken.(string) + if !isString { + return parsedRecord{}, false + } + var raw json.RawMessage + if err := decoder.Decode(&raw); err != nil { + return parsedRecord{}, false + } + if key == "time" { + // The formatter's timestamp comes last; any earlier "time" + // attribute is demoted to attrs when the real one arrives. + if timeRaw != nil { + attrs["time"] = timeRaw + } + timeRaw = raw + continue + } + if isReservedLogKey(key) && !seen[key] { + seen[key] = true + if !record.setReserved(key, raw) { + return parsedRecord{}, false + } + continue + } + attrs[key] = raw + } + if _, err := decoder.Token(); err != nil { // closing brace + return parsedRecord{}, false + } + if _, err := decoder.Token(); err != io.EOF { // trailing newline only + return parsedRecord{}, false + } + if !seen["message"] || !seen["level"] || timeRaw == nil { + return parsedRecord{}, false + } + var timeText string + if err := json.Unmarshal(timeRaw, &timeText); err != nil { + return parsedRecord{}, false + } + parsedTime, err := time.Parse(time.RFC3339Nano, timeText) + if err != nil { + return parsedRecord{}, false + } + record.timestamp = parsedTime + if len(attrs) == 0 { + record.attrs = "{}" + } else { + encoded, err := json.Marshal(attrs) + if err != nil { + return parsedRecord{}, false + } + record.attrs = string(encoded) + } + record.promoted = make([]promotedValue, len(promotedAttrs)) + for i, attr := range promotedAttrs { + if raw, present := attrs[attr.key]; present { + record.promoted[i] = decodePromoted(attr.kind, raw) + } + } + return record, true +} + +func isReservedLogKey(key string) bool { + switch key { + case "message", "level", "source", "function": + return true + } + return false +} + +func (record *parsedRecord) setReserved(key string, raw json.RawMessage) bool { + var text string + if err := json.Unmarshal(raw, &text); err != nil { + return false + } + switch key { + case "message": + record.message = text + case "level": + record.level = text + case "source": + record.source = text + case "function": + record.function = text + } + return true +} + +// multiWriter fans each formatted record out to every sink, for example the +// NDJSON file and the DuckDB database at the same time. A failing sink does +// not starve the others; errors are joined and reported to the diagnostics +// loop, which records them like any other write error. +type multiWriter struct { + writers []DiagnosticsWriter +} + +func NewMultiWriter(writers ...DiagnosticsWriter) DiagnosticsWriter { + live := make([]DiagnosticsWriter, 0, len(writers)) + for _, writer := range writers { + if writer != nil { + live = append(live, writer) + } + } + switch len(live) { + case 0: + return NewPassthroughWriter(nil) + case 1: + return live[0] + } + return &multiWriter{writers: live} +} + +func (writer *multiWriter) Write(data []byte) (int, error) { + var joined error + for _, sink := range writer.writers { + if _, err := sink.Write(data); err != nil { + joined = errors.Join(joined, err) + } + } + return len(data), joined +} + +func (writer *multiWriter) Cancel() error { + var joined error + for _, sink := range writer.writers { + joined = errors.Join(joined, sink.Cancel()) + } + return joined +} + +func (writer *multiWriter) Close() error { + var joined error + for _, sink := range writer.writers { + joined = errors.Join(joined, sink.Close()) + } + return joined +} diff --git a/internal/logging/duckdb_native.go b/internal/logging/duckdb_native.go new file mode 100644 index 0000000..39c81b8 --- /dev/null +++ b/internal/logging/duckdb_native.go @@ -0,0 +1,648 @@ +//go:build duckdb && cgo + +// 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 + +/* +#cgo LDFLAGS: -ldl +#include +#include +#include +#include + +// libduckdb is an optional runtime dependency (an Arch optdepend): the +// reader must start and run on systems without it, so the library is +// dlopen'ed only when --debug-db is actually used instead of being linked. +// The header is still needed at build time; the pointers below take their +// types from it, so calls through them are checked against the installed +// header exactly like direct calls would be. + +#define CTH_DUCK_PTR(name) static __typeof__(&name) cth_p_##name +CTH_DUCK_PTR(duckdb_create_config); +CTH_DUCK_PTR(duckdb_set_config); +CTH_DUCK_PTR(duckdb_destroy_config); +CTH_DUCK_PTR(duckdb_open_ext); +CTH_DUCK_PTR(duckdb_free); +CTH_DUCK_PTR(duckdb_connect); +CTH_DUCK_PTR(duckdb_query); +CTH_DUCK_PTR(duckdb_result_error); +CTH_DUCK_PTR(duckdb_destroy_result); +CTH_DUCK_PTR(duckdb_row_count); +CTH_DUCK_PTR(duckdb_value_varchar); +CTH_DUCK_PTR(duckdb_appender_create); +CTH_DUCK_PTR(duckdb_appender_error); +CTH_DUCK_PTR(duckdb_appender_begin_row); +CTH_DUCK_PTR(duckdb_append_int64); +CTH_DUCK_PTR(duckdb_append_varchar_length); +CTH_DUCK_PTR(duckdb_create_timestamp_tz); +CTH_DUCK_PTR(duckdb_append_value); +CTH_DUCK_PTR(duckdb_destroy_value); +CTH_DUCK_PTR(duckdb_append_null); +CTH_DUCK_PTR(duckdb_append_bool); +CTH_DUCK_PTR(duckdb_appender_end_row); +CTH_DUCK_PTR(duckdb_appender_flush); +CTH_DUCK_PTR(duckdb_appender_close); +CTH_DUCK_PTR(duckdb_appender_destroy); +CTH_DUCK_PTR(duckdb_disconnect); +CTH_DUCK_PTR(duckdb_close); + +// cth_duckdb_load resolves every symbol the sink uses from the library at +// path. It returns NULL on success or a diagnostic string (dlerror output or +// a string literal; neither must be freed) on failure. +static const char *cth_duckdb_load(const char *path) { + void *handle = dlopen(path, RTLD_NOW | RTLD_LOCAL); + if (!handle) return dlerror(); +#define CTH_DUCK_SYM(name) do { \ + *(void **)(&cth_p_##name) = dlsym(handle, #name); \ + if (!cth_p_##name) return "missing symbol " #name; \ + } while (0) + CTH_DUCK_SYM(duckdb_create_config); + CTH_DUCK_SYM(duckdb_set_config); + CTH_DUCK_SYM(duckdb_destroy_config); + CTH_DUCK_SYM(duckdb_open_ext); + CTH_DUCK_SYM(duckdb_free); + CTH_DUCK_SYM(duckdb_connect); + CTH_DUCK_SYM(duckdb_query); + CTH_DUCK_SYM(duckdb_result_error); + CTH_DUCK_SYM(duckdb_destroy_result); + CTH_DUCK_SYM(duckdb_row_count); + CTH_DUCK_SYM(duckdb_value_varchar); + CTH_DUCK_SYM(duckdb_appender_create); + CTH_DUCK_SYM(duckdb_appender_error); + CTH_DUCK_SYM(duckdb_appender_begin_row); + CTH_DUCK_SYM(duckdb_append_int64); + CTH_DUCK_SYM(duckdb_append_varchar_length); + CTH_DUCK_SYM(duckdb_create_timestamp_tz); + CTH_DUCK_SYM(duckdb_append_value); + CTH_DUCK_SYM(duckdb_destroy_value); + CTH_DUCK_SYM(duckdb_append_null); + CTH_DUCK_SYM(duckdb_append_bool); + CTH_DUCK_SYM(duckdb_appender_end_row); + CTH_DUCK_SYM(duckdb_appender_flush); + CTH_DUCK_SYM(duckdb_appender_close); + CTH_DUCK_SYM(duckdb_appender_destroy); + CTH_DUCK_SYM(duckdb_disconnect); + CTH_DUCK_SYM(duckdb_close); +#undef CTH_DUCK_SYM + return NULL; +} + +static duckdb_state cth_duckdb_create_config(duckdb_config *out) { + return cth_p_duckdb_create_config(out); +} +static duckdb_state cth_duckdb_set_config(duckdb_config config, const char *name, const char *option) { + return cth_p_duckdb_set_config(config, name, option); +} +static void cth_duckdb_destroy_config(duckdb_config *config) { + cth_p_duckdb_destroy_config(config); +} +static duckdb_state cth_duckdb_open_ext(const char *path, duckdb_database *out, duckdb_config config, char **err) { + return cth_p_duckdb_open_ext(path, out, config, err); +} +static void cth_duckdb_free(void *pointer) { + cth_p_duckdb_free(pointer); +} +static duckdb_state cth_duckdb_connect(duckdb_database database, duckdb_connection *out) { + return cth_p_duckdb_connect(database, out); +} +static duckdb_state cth_duckdb_query(duckdb_connection connection, const char *query, duckdb_result *out) { + return cth_p_duckdb_query(connection, query, out); +} +static const char *cth_duckdb_result_error(duckdb_result *result) { + return cth_p_duckdb_result_error(result); +} +static void cth_duckdb_destroy_result(duckdb_result *result) { + cth_p_duckdb_destroy_result(result); +} +static idx_t cth_duckdb_row_count(duckdb_result *result) { + return cth_p_duckdb_row_count(result); +} +static char *cth_duckdb_value_varchar(duckdb_result *result, idx_t column, idx_t row) { + return cth_p_duckdb_value_varchar(result, column, row); +} +static duckdb_state cth_duckdb_appender_create(duckdb_connection connection, const char *schema, const char *table, duckdb_appender *out) { + return cth_p_duckdb_appender_create(connection, schema, table, out); +} +static const char *cth_duckdb_appender_error(duckdb_appender appender) { + return cth_p_duckdb_appender_error(appender); +} +static duckdb_state cth_duckdb_appender_begin_row(duckdb_appender appender) { + return cth_p_duckdb_appender_begin_row(appender); +} +static duckdb_state cth_duckdb_append_int64(duckdb_appender appender, int64_t value) { + return cth_p_duckdb_append_int64(appender, value); +} +static duckdb_state cth_duckdb_append_varchar_length(duckdb_appender appender, const char *text, idx_t length) { + return cth_p_duckdb_append_varchar_length(appender, text, length); +} +static duckdb_value cth_duckdb_create_timestamp_tz(duckdb_timestamp input) { + return cth_p_duckdb_create_timestamp_tz(input); +} +static duckdb_state cth_duckdb_append_value(duckdb_appender appender, duckdb_value value) { + return cth_p_duckdb_append_value(appender, value); +} +static void cth_duckdb_destroy_value(duckdb_value *value) { + cth_p_duckdb_destroy_value(value); +} +static duckdb_state cth_duckdb_append_null(duckdb_appender appender) { + return cth_p_duckdb_append_null(appender); +} +static duckdb_state cth_duckdb_append_bool(duckdb_appender appender, bool value) { + return cth_p_duckdb_append_bool(appender, value); +} +static duckdb_state cth_duckdb_appender_end_row(duckdb_appender appender) { + return cth_p_duckdb_appender_end_row(appender); +} +static duckdb_state cth_duckdb_appender_flush(duckdb_appender appender) { + return cth_p_duckdb_appender_flush(appender); +} +static duckdb_state cth_duckdb_appender_close(duckdb_appender appender) { + return cth_p_duckdb_appender_close(appender); +} +static void cth_duckdb_appender_destroy(duckdb_appender *appender) { + cth_p_duckdb_appender_destroy(appender); +} +static void cth_duckdb_disconnect(duckdb_connection *connection) { + cth_p_duckdb_disconnect(connection); +} +static void cth_duckdb_close(duckdb_database *database) { + cth_p_duckdb_close(database); +} +*/ +import "C" + +import ( + "crypto/rand" + "errors" + "fmt" + "io/fs" + "os" + "strings" + "sync" + "sync/atomic" + "time" + "unsafe" +) + +// This sink uses the system libduckdb C API directly instead of the duckdb-go +// driver: duckdb-go bundles its own engine build, which can write a storage +// format the system duckdb CLI (the tool agents query logs with) cannot +// read, and it inflates the binary by tens of megabytes plus dozens of +// module dependencies for a debug-only sink. The system library always +// matches the same system's CLI, and loading it with dlopen keeps it an +// optional runtime dependency: builds need the duckdb headers (hence the +// duckdb build tag, mirroring brlapi), but the resulting reader starts and +// runs normally on systems without libduckdb, and only --debug-db fails. + +// Rows are buffered in the appender only briefly: a flush happens at +// duckDBFlushRows, on the first record at least duckDBFlushInterval after +// the previous flush, and immediately for WARN and ERROR records so crash +// diagnostics reach the database. A hard crash can still lose the rows +// buffered since the last flush, unlike the file sink, which writes every +// record straight away; the database otherwise trails live activity by +// about a second, so it can be inspected (from a file copy, while the +// reader holds the write lock) during a session. +const ( + duckDBFlushRows = 512 + duckDBFlushInterval = time.Second +) + +var emptyDuckText = C.CString("") + +// Runtime packages install a versioned soname; the unversioned name is the +// development symlink (present in Arch's duckdb package, absent from some +// other distributions' runtime packages). +var duckLibraryCandidates = []string{"libduckdb.so.1", "libduckdb.so"} + +var ( + duckLoadOnce sync.Once + duckLoadErr error +) + +func loadDuckDBLibrary() error { + duckLoadOnce.Do(func() { + var failures []string + for _, candidate := range duckLibraryCandidates { + cname := C.CString(candidate) + message := C.cth_duckdb_load(cname) + C.free(unsafe.Pointer(cname)) + if message == nil { + return + } + failures = append(failures, candidate+": "+C.GoString(message)) + } + duckLoadErr = fmt.Errorf( + "%w: cannot load libduckdb (%s); install the duckdb package to use --debug-db", + ErrDuckDBUnavailable, strings.Join(failures, "; ")) + }) + return duckLoadErr +} + +type duckDBWriter struct { + path string + database C.duckdb_database + conn C.duckdb_connection + appender C.duckdb_appender + sessionID string + seq int64 + pending int + lastFlush time.Time + + mutex sync.Mutex + closeOnce sync.Once + closed bool + writeErr error + closeErr error + cancelled atomic.Bool +} + +// OpenDuckDB opens a DuckDB database at path as a diagnostics sink. Without +// appendExisting, any existing database at path is replaced, mirroring +// OpenFile. With it, existing sessions are kept and this run is recorded as +// a new session row. The sink receives the same redacted NDJSON records as +// the file sink, so redaction in Handler.format protects both. +func OpenDuckDB(path string, appendExisting bool, pid int) (DiagnosticsWriter, error) { + if path == "" || path == "." || path == ".." { + return nil, errors.New("invalid diagnostics database path") + } + // Load before touching the filesystem: without the library we must not + // delete an existing database we then cannot replace. + if err := loadDuckDBLibrary(); err != nil { + return nil, err + } + if info, err := os.Stat(path); err == nil && info.IsDir() { + return nil, fmt.Errorf("diagnostics database path is a directory: %s", path) + } + if !appendExisting { + for _, target := range []string{path, path + ".wal"} { + if err := os.Remove(target); err != nil && !errors.Is(err, fs.ErrNotExist) { + return nil, fmt.Errorf("replace diagnostics database: %w", err) + } + } + } + + sessionID, err := newSessionID() + if err != nil { + return nil, err + } + writer := &duckDBWriter{path: path, sessionID: sessionID} + if err := writer.open(pid); err != nil { + return nil, err + } + return writer, nil +} + +func (writer *duckDBWriter) open(pid int) (err error) { + // Every failure past a successful open must release the handles already + // acquired and leave the writer in the closed state. + defer func() { + if err != nil { + writer.closed = true + writer.teardown() + } + }() + + var config C.duckdb_config + if C.cth_duckdb_create_config(&config) == C.DuckDBError { + return errors.New("create duckdb config") + } + threads := C.CString("threads") + one := C.CString("1") + setState := C.cth_duckdb_set_config(config, threads, one) + C.free(unsafe.Pointer(threads)) + C.free(unsafe.Pointer(one)) + if setState == C.DuckDBError { + C.cth_duckdb_destroy_config(&config) + return errors.New("configure duckdb threads") + } + + cpath := C.CString(writer.path) + var openErr *C.char + state := C.cth_duckdb_open_ext(cpath, &writer.database, config, &openErr) + C.free(unsafe.Pointer(cpath)) + C.cth_duckdb_destroy_config(&config) + if state == C.DuckDBError { + message := C.GoString(openErr) + C.cth_duckdb_free(unsafe.Pointer(openErr)) + return fmt.Errorf("open diagnostics database: %s", message) + } + + // DuckDB creates the file with process umask permissions and rejects a + // pre-created empty file, so restrict it immediately: debug records can + // contain spoken text and the file sink creates its log at 0600. + if chmodErr := os.Chmod(writer.path, 0o600); chmodErr != nil { + return fmt.Errorf("restrict diagnostics database permissions: %w", chmodErr) + } + + if C.cth_duckdb_connect(writer.database, &writer.conn) == C.DuckDBError { + return errors.New("connect diagnostics database") + } + for _, statement := range []string{duckDBCreateMeta, duckDBCreateSessions, duckDBCreateLogs} { + if execErr := duckExec(writer.conn, statement); execErr != nil { + return execErr + } + } + version, found, queryErr := duckQueryVarchar(writer.conn, + "SELECT value FROM meta WHERE key = 'schema_version'") + if queryErr != nil { + return queryErr + } + if found && version == duckDBSchemaVersionV1 { + // v1 stored every attribute in attrs only. Append the promoted + // columns (existing rows read NULL there; nothing is lost because + // attrs is complete) and restamp the version. + for _, attr := range promotedAttrs { + statement := fmt.Sprintf("ALTER TABLE logs ADD COLUMN IF NOT EXISTS \"%s\" %s", attr.key, attr.sqlType()) + if execErr := duckExec(writer.conn, statement); execErr != nil { + return execErr + } + } + if execErr := duckExec(writer.conn, + "UPDATE meta SET value = '"+duckDBSchemaVersion+"' WHERE key = 'schema_version'"); execErr != nil { + return execErr + } + } else if found && version != duckDBSchemaVersion { + return fmt.Errorf("unsupported diagnostics database schema version %q (want %q); use a new file or omit --append", + version, duckDBSchemaVersion) + } + if !found { + for _, statement := range []string{ + "INSERT INTO meta VALUES ('format', 'cthulhu-debug-log') ON CONFLICT DO NOTHING", + "INSERT INTO meta VALUES ('schema_version', '" + duckDBSchemaVersion + "') ON CONFLICT DO NOTHING", + } { + if execErr := duckExec(writer.conn, statement); execErr != nil { + return execErr + } + } + } + // sessionID is generated by newSessionID from random bytes (hex and + // dashes only) and the timestamp is RFC3339, so both are safe SQL + // literal content. + insertSession := fmt.Sprintf( + "INSERT INTO sessions VALUES ('%s', TIMESTAMPTZ '%s', %d)", + writer.sessionID, time.Now().UTC().Format(time.RFC3339Nano), pid) + if execErr := duckExec(writer.conn, insertSession); execErr != nil { + return execErr + } + + table := C.CString("logs") + state = C.cth_duckdb_appender_create(writer.conn, nil, table, &writer.appender) + C.free(unsafe.Pointer(table)) + if state == C.DuckDBError { + return fmt.Errorf("create diagnostics appender: %s", duckAppenderError(writer.appender)) + } + writer.lastFlush = time.Now() + // Schema and session setup already wrote through the WAL; restrict it + // now rather than waiting for the first flush. + _ = os.Chmod(writer.path+".wal", 0o600) + return nil +} + +func (writer *duckDBWriter) Write(data []byte) (int, error) { + writer.mutex.Lock() + defer writer.mutex.Unlock() + if writer.closed || writer.cancelled.Load() { + return 0, fmt.Errorf("write diagnostics database: %w", fs.ErrClosed) + } + if writer.writeErr != nil { + return 0, writer.writeErr + } + record, ok := parseLogRecord(data) + if !ok { + // The formatter is the only producer, so this should not happen; + // keep the raw record rather than silently dropping it. + record = parsedRecord{ + timestamp: time.Now(), + level: "UNKNOWN", + message: strings.TrimRight(string(data), "\n"), + attrs: "{}", + } + } + if err := writer.appendRecord(record); err != nil { + writer.writeErr = err + return 0, err + } + writer.pending++ + if writer.pending >= duckDBFlushRows || record.level == "WARN" || record.level == "ERROR" || + time.Since(writer.lastFlush) >= duckDBFlushInterval { + if err := writer.flushLocked(); err != nil { + writer.writeErr = err + return 0, err + } + } + return len(data), nil +} + +// appendRecord appends one row in logs table column order. +func (writer *duckDBWriter) appendRecord(record parsedRecord) error { + writer.seq++ + app := writer.appender + if C.cth_duckdb_appender_begin_row(app) == C.DuckDBError { + return writer.appendError("begin row") + } + if C.cth_duckdb_append_int64(app, C.int64_t(writer.seq)) == C.DuckDBError { + return writer.appendError("append seq") + } + if duckAppendText(app, writer.sessionID) == C.DuckDBError { + return writer.appendError("append session_id") + } + timestamp := C.duckdb_timestamp{micros: C.int64_t(record.timestamp.UnixMicro())} + value := C.cth_duckdb_create_timestamp_tz(timestamp) + state := C.cth_duckdb_append_value(app, value) + C.cth_duckdb_destroy_value(&value) + if state == C.DuckDBError { + return writer.appendError("append ts") + } + for _, field := range []struct { + name string + text string + }{ + {"level", record.level}, + {"message", record.message}, + } { + if duckAppendText(app, field.text) == C.DuckDBError { + return writer.appendError("append " + field.name) + } + } + for _, field := range []struct { + name string + text string + }{ + {"source", record.source}, + {"function", record.function}, + } { + if field.text == "" { + if C.cth_duckdb_append_null(app) == C.DuckDBError { + return writer.appendError("append " + field.name) + } + continue + } + if duckAppendText(app, field.text) == C.DuckDBError { + return writer.appendError("append " + field.name) + } + } + if duckAppendText(app, record.attrs) == C.DuckDBError { + return writer.appendError("append attrs") + } + for i, attr := range promotedAttrs { + var value promotedValue + if i < len(record.promoted) { + value = record.promoted[i] + } + if !value.valid { + if C.cth_duckdb_append_null(app) == C.DuckDBError { + return writer.appendError("append " + attr.key) + } + continue + } + var state C.duckdb_state + switch attr.kind { + case promotedText: + state = duckAppendText(app, value.text) + case promotedInt: + state = C.cth_duckdb_append_int64(app, C.int64_t(value.integer)) + case promotedBool: + state = C.cth_duckdb_append_bool(app, C.bool(value.boolean)) + } + if state == C.DuckDBError { + return writer.appendError("append " + attr.key) + } + } + if C.cth_duckdb_appender_end_row(app) == C.DuckDBError { + return writer.appendError("end row") + } + return nil +} + +func (writer *duckDBWriter) appendError(step string) error { + return fmt.Errorf("write diagnostics database (%s): %s", step, duckAppenderError(writer.appender)) +} + +func (writer *duckDBWriter) flushLocked() error { + if C.cth_duckdb_appender_flush(writer.appender) == C.DuckDBError { + return fmt.Errorf("flush diagnostics database: %s", duckAppenderError(writer.appender)) + } + writer.pending = 0 + writer.lastFlush = time.Now() + // The write-ahead log holds recent records until checkpoint; restrict it + // too whenever it exists. Best effort: DuckDB may not have created it. + _ = os.Chmod(writer.path+".wal", 0o600) + return nil +} + +// Cancel flags the sink cancelled and returns immediately. Diagnostics.Stop +// calls Cancel synchronously while enforcing its deadline, so it must never +// wait for an in-flight appender call or run the closing flush/checkpoint; +// that teardown belongs to Close, which the diagnostics writer goroutine +// calls after its queue drains. This mirrors fileWriter, whose Cancel is a +// bare file close that never waits for an in-flight Write. +func (writer *duckDBWriter) Cancel() error { + writer.cancelled.Store(true) + return nil +} + +func (writer *duckDBWriter) Close() error { + writer.closeOnce.Do(func() { + writer.mutex.Lock() + defer writer.mutex.Unlock() + writer.closed = true + if writer.appender != nil && C.cth_duckdb_appender_close(writer.appender) == C.DuckDBError { + writer.closeErr = fmt.Errorf("close diagnostics appender: %s", + duckAppenderError(writer.appender)) + } + writer.teardown() + }) + return writer.closeErr +} + +// teardown releases any handles still held, in reverse acquisition order. +// Callers outside open must hold the mutex. +func (writer *duckDBWriter) teardown() { + if writer.appender != nil { + C.cth_duckdb_appender_destroy(&writer.appender) + } + if writer.conn != nil { + C.cth_duckdb_disconnect(&writer.conn) + } + if writer.database != nil { + C.cth_duckdb_close(&writer.database) + } +} + +func duckExec(conn C.duckdb_connection, sql string) error { + csql := C.CString(sql) + defer C.free(unsafe.Pointer(csql)) + var result C.duckdb_result + if C.cth_duckdb_query(conn, csql, &result) == C.DuckDBError { + message := C.GoString(C.cth_duckdb_result_error(&result)) + C.cth_duckdb_destroy_result(&result) + return fmt.Errorf("diagnostics database statement: %s", message) + } + C.cth_duckdb_destroy_result(&result) + return nil +} + +func duckQueryVarchar(conn C.duckdb_connection, sql string) (string, bool, error) { + csql := C.CString(sql) + defer C.free(unsafe.Pointer(csql)) + var result C.duckdb_result + if C.cth_duckdb_query(conn, csql, &result) == C.DuckDBError { + message := C.GoString(C.cth_duckdb_result_error(&result)) + C.cth_duckdb_destroy_result(&result) + return "", false, fmt.Errorf("diagnostics database query: %s", message) + } + defer C.cth_duckdb_destroy_result(&result) + if C.cth_duckdb_row_count(&result) == 0 { + return "", false, nil + } + text := C.cth_duckdb_value_varchar(&result, 0, 0) + value := C.GoString(text) + C.cth_duckdb_free(unsafe.Pointer(text)) + return value, true, nil +} + +func duckAppendText(app C.duckdb_appender, text string) C.duckdb_state { + if len(text) == 0 { + return C.cth_duckdb_append_varchar_length(app, emptyDuckText, 0) + } + // The length variant preserves embedded NUL bytes that JSON decoding can + // legitimately produce ("\u0000"); the NUL-terminated variant truncates. + state := C.cth_duckdb_append_varchar_length( + app, (*C.char)(unsafe.Pointer(unsafe.StringData(text))), C.idx_t(len(text))) + // StringData must stay live across the call above. + _ = text + return state +} + +func duckAppenderError(app C.duckdb_appender) string { + if app == nil { + return "unknown error" + } + return C.GoString(C.cth_duckdb_appender_error(app)) +} + +func newSessionID() (string, error) { + var raw [16]byte + if _, err := rand.Read(raw[:]); err != nil { + return "", fmt.Errorf("generate diagnostics session id: %w", err) + } + raw[6] = raw[6]&0x0f | 0x40 + raw[8] = raw[8]&0x3f | 0x80 + return fmt.Sprintf("%x-%x-%x-%x-%x", raw[0:4], raw[4:6], raw[6:8], raw[8:10], raw[10:16]), nil +} diff --git a/internal/logging/duckdb_native_test.go b/internal/logging/duckdb_native_test.go new file mode 100644 index 0000000..95681d2 --- /dev/null +++ b/internal/logging/duckdb_native_test.go @@ -0,0 +1,318 @@ +//go:build duckdb && cgo + +// 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 ( + "errors" + "io/fs" + "os" + "os/exec" + "path/filepath" + "strings" + "testing" + "time" +) + +const ( + duckTestLineInfo = `{"message":"starting Cthulhu","level":"INFO","source":"/srv/cthulhu/cmd/cthulhu/main.go:201","function":"main.run","pid":42,"time":"2026-11-04T03:58:47.316096257-05:00"}` + "\n" + duckTestLineDup = `{"message":"document navigation completed","level":"DEBUG","source":"/srv/cthulhu/internal/app/document_review.go:319","function":"example.present","level":3,"role":"heading","time":"2026-11-04T04:01:02.5-05:00"}` + "\n" + duckTestLineErr = `{"message":"speech delivery failed","level":"ERROR","source":"/srv/cthulhu/internal/app/speech.go:9","function":"example.deliver","error":"socket closed","time":"2026-11-04T04:02:03-05:00"}` + "\n" +) + +func duckQuery(t *testing.T, path, query string) string { + t.Helper() + cli, err := exec.LookPath("duckdb") + if err != nil { + t.Skip("duckdb CLI not installed; cannot verify queryability") + } + output, err := exec.Command(cli, "-readonly", "-noheader", "-list", path, "-c", query).CombinedOutput() + if err != nil { + t.Fatalf("duckdb query %q: %v\n%s", query, err, output) + } + return strings.TrimSpace(string(output)) +} + +func TestDuckDBSinkStoresQueryableRecords(t *testing.T) { + path := filepath.Join(t.TempDir(), "debug.duckdb") + writer, err := OpenDuckDB(path, false, 4242) + if err != nil { + t.Fatal(err) + } + for _, line := range []string{duckTestLineInfo, duckTestLineDup, duckTestLineErr, "not a formatted record\n"} { + if _, err := writer.Write([]byte(line)); err != nil { + t.Fatalf("Write %q: %v", line, err) + } + } + if err := writer.Close(); err != nil { + t.Fatal(err) + } + if _, err := writer.Write([]byte(duckTestLineInfo)); !errors.Is(err, fs.ErrClosed) { + t.Fatalf("write after close error = %v, want fs.ErrClosed", err) + } + info, err := os.Stat(path) + if err != nil { + t.Fatal(err) + } + if info.Mode().Perm() != 0o600 { + t.Fatalf("database permissions = %o, want 600", info.Mode().Perm()) + } + + if got := duckQuery(t, path, "SELECT count(*) FROM logs"); got != "4" { + t.Fatalf("log rows = %s, want 4", got) + } + if got := duckQuery(t, path, + "SELECT level FROM logs WHERE message = 'document navigation completed'"); got != "DEBUG" { + t.Fatalf("typed level = %s, want DEBUG", got) + } + if got := duckQuery(t, path, + "SELECT attrs->>'$.level' FROM logs WHERE message = 'document navigation completed'"); got != "3" { + t.Fatalf("attrs level = %s, want 3", got) + } + if got := duckQuery(t, path, + "SELECT attrs->>'$.error' FROM logs WHERE level = 'ERROR'"); got != "socket closed" { + t.Fatalf("attrs error = %s", got) + } + // The unformatted line must be preserved, not dropped. + if got := duckQuery(t, path, "SELECT message FROM logs WHERE level = 'UNKNOWN'"); got != "not a formatted record" { + t.Fatalf("fallback message = %q", got) + } + if got := duckQuery(t, path, + "SELECT count(DISTINCT session_id) || '|' || min(seq) || '|' || max(seq) FROM logs"); got != "1|1|4" { + t.Fatalf("session/seq = %s, want 1|1|4", got) + } + if got := duckQuery(t, path, "SELECT pid FROM sessions"); got != "4242" { + t.Fatalf("session pid = %s", got) + } + if got := duckQuery(t, path, "SELECT value FROM meta WHERE key = 'schema_version'"); got != duckDBSchemaVersion { + t.Fatalf("schema_version = %s", got) + } + // Timestamps are real TIMESTAMPTZ values that support range filters. + if got := duckQuery(t, path, + "SELECT count(*) FROM logs WHERE level != 'UNKNOWN' AND ts >= TIMESTAMPTZ '2026-11-04 04:00:00-05:00'"); got != "2" { + t.Fatalf("range-filtered rows = %s, want 2", got) + } +} + +func TestDuckDBSinkAppendsSessionsAndReplaces(t *testing.T) { + path := filepath.Join(t.TempDir(), "debug.duckdb") + write := func(appendExisting bool, line string) { + t.Helper() + writer, err := OpenDuckDB(path, appendExisting, 7) + if err != nil { + t.Fatal(err) + } + if _, err := writer.Write([]byte(line)); err != nil { + t.Fatal(err) + } + if err := writer.Close(); err != nil { + t.Fatal(err) + } + } + + write(false, duckTestLineInfo) + write(true, duckTestLineErr) + if got := duckQuery(t, path, "SELECT count(*) || '|' || count(DISTINCT session_id) FROM logs"); got != "2|2" { + t.Fatalf("after append rows|sessions = %s, want 2|2", got) + } + // Each session restarts its own sequence. + if got := duckQuery(t, path, "SELECT count(*) FROM logs WHERE seq = 1"); got != "2" { + t.Fatalf("seq=1 rows = %s, want 2", got) + } + + write(false, duckTestLineDup) + if got := duckQuery(t, path, "SELECT count(*) || '|' || count(DISTINCT session_id) FROM logs"); got != "1|1" { + t.Fatalf("after replace rows|sessions = %s, want 1|1", got) + } +} + +func TestDuckDBSinkRejectsDirectoryAndForeignFile(t *testing.T) { + if _, err := OpenDuckDB(t.TempDir(), false, 1); err == nil { + t.Fatal("directory path accepted") + } + foreign := filepath.Join(t.TempDir(), "foreign.duckdb") + if err := os.WriteFile(foreign, []byte("not a duckdb database"), 0o600); err != nil { + t.Fatal(err) + } + if _, err := OpenDuckDB(foreign, true, 1); err == nil { + t.Fatal("foreign file accepted in append mode") + } + // Replace mode discards the foreign file, mirroring OpenFile truncation. + writer, err := OpenDuckDB(foreign, false, 1) + if err != nil { + t.Fatal(err) + } + if err := writer.Close(); err != nil { + t.Fatal(err) + } +} + +// At idle record rates the row-count threshold alone would leave the +// database empty for minutes; a record arriving after the flush interval +// must flush everything buffered so far. +func TestDuckDBSinkFlushesAfterInterval(t *testing.T) { + path := filepath.Join(t.TempDir(), "debug.duckdb") + sink, err := OpenDuckDB(path, false, 7) + if err != nil { + t.Fatal(err) + } + writer := sink.(*duckDBWriter) + if wal, err := os.Stat(path + ".wal"); err == nil && wal.Mode().Perm() != 0o600 { + t.Fatalf("wal permissions at open = %o, want 600", wal.Mode().Perm()) + } + if _, err := writer.Write([]byte(duckTestLineInfo)); err != nil { + t.Fatal(err) + } + if writer.pending != 1 { + t.Fatalf("pending after one INFO record = %d, want 1 (buffered)", writer.pending) + } + writer.lastFlush = time.Now().Add(-2 * duckDBFlushInterval) + if _, err := writer.Write([]byte(duckTestLineDup)); err != nil { + t.Fatal(err) + } + if writer.pending != 0 { + t.Fatalf("pending after interval record = %d, want 0 (flushed)", writer.pending) + } + if err := writer.Close(); err != nil { + t.Fatal(err) + } + if got := duckQuery(t, path, "SELECT count(*) FROM logs"); got != "2" { + t.Fatalf("log rows = %s, want 2", got) + } +} + +func duckExecCLI(t *testing.T, path, statement string) { + t.Helper() + cli, err := exec.LookPath("duckdb") + if err != nil { + t.Skip("duckdb CLI not installed; cannot prepare fixture database") + } + if output, err := exec.Command(cli, path, "-c", statement).CombinedOutput(); err != nil { + t.Fatalf("duckdb exec %q: %v\n%s", statement, err, output) + } +} + +// Promoted attributes must land in typed columns (queryable without JSON +// extraction or casts) while remaining in attrs. +func TestDuckDBSinkPromotedColumns(t *testing.T) { + path := filepath.Join(t.TempDir(), "debug.duckdb") + writer, err := OpenDuckDB(path, false, 7) + if err != nil { + t.Fatal(err) + } + for _, line := range []string{duckTestLineInfo, duckTestLineDup, duckTestLineErr} { + if _, err := writer.Write([]byte(line)); err != nil { + t.Fatal(err) + } + } + if err := writer.Close(); err != nil { + t.Fatal(err) + } + if got := duckQuery(t, path, + "SELECT role FROM logs WHERE message = 'document navigation completed'"); got != "heading" { + t.Fatalf("promoted role = %s, want heading", got) + } + if got := duckQuery(t, path, + "SELECT error FROM logs WHERE level = 'ERROR'"); got != "socket closed" { + t.Fatalf("promoted error = %s, want socket closed", got) + } + if got := duckQuery(t, path, + "SELECT count(*) FROM logs WHERE role IS NULL"); got != "2" { + t.Fatalf("null-role rows = %s, want 2", got) + } + // Column types are honest SQL types, not text. + if got := duckQuery(t, path, + "SELECT data_type FROM information_schema.columns WHERE table_name = 'logs' AND column_name = 'snapshot_duration'"); got != "BIGINT" { + t.Fatalf("snapshot_duration type = %s, want BIGINT", got) + } + if got := duckQuery(t, path, + "SELECT data_type FROM information_schema.columns WHERE table_name = 'logs' AND column_name = 'focused'"); got != "BOOLEAN" { + t.Fatalf("focused type = %s, want BOOLEAN", got) + } +} + +// A v1 database (envelope columns and attrs only) must upgrade in place on +// append: existing rows keep their attrs and read NULL in the new columns. +func TestDuckDBSinkUpgradesV1Database(t *testing.T) { + path := filepath.Join(t.TempDir(), "debug.duckdb") + duckExecCLI(t, path, ` + CREATE TABLE meta (key VARCHAR PRIMARY KEY, value VARCHAR NOT NULL); + INSERT INTO meta VALUES ('format', 'cthulhu-debug-log'), ('schema_version', '1'); + CREATE TABLE sessions (session_id VARCHAR PRIMARY KEY, started_at TIMESTAMPTZ NOT NULL, pid BIGINT NOT NULL); + INSERT INTO sessions VALUES ('old-session', TIMESTAMPTZ '2026-11-04 03:58:47-05:00', 99); + CREATE TABLE logs (seq BIGINT NOT NULL, session_id VARCHAR NOT NULL, ts TIMESTAMPTZ NOT NULL, + level VARCHAR NOT NULL, message VARCHAR NOT NULL, source VARCHAR, function VARCHAR, attrs JSON NOT NULL); + INSERT INTO logs VALUES (1, 'old-session', TIMESTAMPTZ '2026-11-04 03:58:47-05:00', + 'DEBUG', 'document navigation completed', NULL, NULL, '{"role":"heading"}'); + `) + writer, err := OpenDuckDB(path, true, 7) + if err != nil { + t.Fatal(err) + } + if _, err := writer.Write([]byte(duckTestLineDup)); err != nil { + t.Fatal(err) + } + if err := writer.Close(); err != nil { + t.Fatal(err) + } + if got := duckQuery(t, path, "SELECT value FROM meta WHERE key = 'schema_version'"); got != duckDBSchemaVersion { + t.Fatalf("schema_version after upgrade = %s, want %s", got, duckDBSchemaVersion) + } + if got := duckQuery(t, path, + "SELECT role || '|' || (attrs->>'$.role') FROM logs WHERE session_id != 'old-session'"); got != "heading|heading" { + t.Fatalf("new row role column|attrs = %s", got) + } + if got := duckQuery(t, path, + "SELECT (role IS NULL) || '|' || (attrs->>'$.role') FROM logs WHERE session_id = 'old-session'"); got != "true|heading" { + t.Fatalf("old row role-null|attrs = %s, want true|heading", got) + } +} + +// Cancel is called synchronously by Diagnostics.Stop while it enforces its +// deadline, so it must only flag cancellation and return at once; records +// already appended are still flushed by the Close that follows. +func TestDuckDBSinkCancelIsNonBlocking(t *testing.T) { + path := filepath.Join(t.TempDir(), "debug.duckdb") + writer, err := OpenDuckDB(path, false, 7) + if err != nil { + t.Fatal(err) + } + if _, err := writer.Write([]byte(duckTestLineInfo)); err != nil { + t.Fatal(err) + } + done := make(chan error, 1) + go func() { done <- writer.Cancel() }() + select { + case err := <-done: + if err != nil { + t.Fatal(err) + } + case <-time.After(5 * time.Second): + t.Fatal("Cancel blocked") + } + if _, err := writer.Write([]byte(duckTestLineDup)); !errors.Is(err, fs.ErrClosed) { + t.Fatalf("write after cancel error = %v, want fs.ErrClosed", err) + } + if err := writer.Close(); err != nil { + t.Fatal(err) + } + if got := duckQuery(t, path, "SELECT count(*) FROM logs"); got != "1" { + t.Fatalf("log rows = %s, want 1 (pre-cancel record flushed by Close)", got) + } +} diff --git a/internal/logging/duckdb_test.go b/internal/logging/duckdb_test.go new file mode 100644 index 0000000..f1b580a --- /dev/null +++ b/internal/logging/duckdb_test.go @@ -0,0 +1,228 @@ +// 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 ( + "encoding/json" + "errors" + "strings" + "testing" + "time" +) + +func TestParseLogRecordSplitsTypedColumnsAndAttrs(t *testing.T) { + line := []byte(`{"message":"starting Cthulhu","level":"INFO","source":"/srv/cthulhu/cmd/cthulhu/main.go:201","function":"main.run","pid":259626,"build":{"go_version":"go1.27"},"x11_display_available":true,"time":"2026-11-04T03:58:47.316096257-05:00"}` + "\n") + + record, ok := parseLogRecord(line) + if !ok { + t.Fatal("record did not parse") + } + if record.message != "starting Cthulhu" || record.level != "INFO" { + t.Fatalf("message/level = %q/%q", record.message, record.level) + } + if record.source != "/srv/cthulhu/cmd/cthulhu/main.go:201" || record.function != "main.run" { + t.Fatalf("source/function = %q/%q", record.source, record.function) + } + wantTime, err := time.Parse(time.RFC3339Nano, "2026-11-04T03:58:47.316096257-05:00") + if err != nil { + t.Fatal(err) + } + if !record.timestamp.Equal(wantTime) { + t.Fatalf("timestamp = %v, want %v", record.timestamp, wantTime) + } + var attrs map[string]json.RawMessage + if err := json.Unmarshal([]byte(record.attrs), &attrs); err != nil { + t.Fatalf("attrs is not a JSON object: %v (%s)", err, record.attrs) + } + if string(attrs["pid"]) != "259626" || string(attrs["build"]) != `{"go_version":"go1.27"}` || + string(attrs["x11_display_available"]) != "true" { + t.Fatalf("attrs = %s", record.attrs) + } + for _, reserved := range []string{"message", "level", "source", "function", "time"} { + if _, present := attrs[reserved]; present { + t.Fatalf("reserved key %q leaked into attrs: %s", reserved, record.attrs) + } + } +} + +// Some records carry an attribute that reuses a reserved name with a +// different type (an integer heading "level", for example). The formatter +// emits its own level first, so the typed column keeps the string level and +// the attribute lands in attrs. +func TestParseLogRecordDuplicateReservedAttrGoesToAttrs(t *testing.T) { + line := []byte(`{"message":"document navigation completed","level":"DEBUG","source":"/srv/cthulhu/internal/app/document_review.go:319","function":"example.present","level":3,"role":"heading","time":"2026-11-04T04:01:02.5-05:00"}` + "\n") + + record, ok := parseLogRecord(line) + if !ok { + t.Fatal("record did not parse") + } + if record.level != "DEBUG" { + t.Fatalf("level = %q, want DEBUG", record.level) + } + var attrs map[string]json.RawMessage + if err := json.Unmarshal([]byte(record.attrs), &attrs); err != nil { + t.Fatal(err) + } + if string(attrs["level"]) != "3" || string(attrs["role"]) != `"heading"` { + t.Fatalf("attrs = %s", record.attrs) + } +} + +func TestParseLogRecordRejectsMalformedLines(t *testing.T) { + for name, line := range map[string]string{ + "empty": "", + "not json": "starting Cthulhu\n", + "array": `[{"message":"m"}]` + "\n", + "missing time": `{"message":"m","level":"INFO"}` + "\n", + "missing message": `{"level":"INFO","time":"2026-11-04T03:58:47Z"}` + "\n", + "numeric level": `{"message":"m","level":1,"time":"2026-11-04T03:58:47Z"}` + "\n", + "bad time": `{"message":"m","level":"INFO","time":"not-a-time"}` + "\n", + "trailing garbage": `{"message":"m","level":"INFO","time":"2026-11-04T03:58:47Z"} extra` + "\n", + "unclosed": `{"message":"m","level":"INFO"` + "\n", + } { + if _, ok := parseLogRecord([]byte(line)); ok { + t.Errorf("%s: parsed unexpectedly", name) + } + } +} + +func promotedByKey(record parsedRecord, key string) promotedValue { + for i, attr := range promotedAttrs { + if attr.key == key && i < len(record.promoted) { + return record.promoted[i] + } + } + return promotedValue{} +} + +func TestParseLogRecordPromotesTypedAttrs(t *testing.T) { + line := []byte(`{"message":"received accessibility event","level":"DEBUG","source":"s:1","function":"f","role":"heading","snapshot_duration":12345,"focused":true,"error":null,"selection_start":"3","custom_thing":{"nested":1},"time":"2026-11-04T03:58:47Z"}` + "\n") + + record, ok := parseLogRecord(line) + if !ok { + t.Fatal("record did not parse") + } + if got := promotedByKey(record, "role"); !got.valid || got.text != "heading" { + t.Fatalf("role = %+v", got) + } + if got := promotedByKey(record, "snapshot_duration"); !got.valid || got.integer != 12345 { + t.Fatalf("snapshot_duration = %+v", got) + } + if got := promotedByKey(record, "focused"); !got.valid || !got.boolean { + t.Fatalf("focused = %+v", got) + } + // JSON null and wrong-typed values stay out of the typed columns but + // remain in attrs. + if got := promotedByKey(record, "error"); got.valid { + t.Fatalf("error = %+v, want invalid for null", got) + } + if got := promotedByKey(record, "selection_start"); got.valid { + t.Fatalf("selection_start = %+v, want invalid for string in int column", got) + } + if got := promotedByKey(record, "application"); got.valid { + t.Fatalf("application = %+v, want invalid when absent", got) + } + var attrs map[string]json.RawMessage + if err := json.Unmarshal([]byte(record.attrs), &attrs); err != nil { + t.Fatal(err) + } + if string(attrs["selection_start"]) != `"3"` || string(attrs["custom_thing"]) != `{"nested":1}` || + string(attrs["role"]) != `"heading"` { + t.Fatalf("attrs lost data: %s", record.attrs) + } +} + +// The formatter emits its timestamp last, after record attributes. An +// attribute also named "time" must land in attrs and never steal the ts +// column or sink the whole record to the fallback row. +func TestParseLogRecordTimeAttrDoesNotStealTimestamp(t *testing.T) { + for name, attr := range map[string]string{ + "numeric attr": `123`, + "rfc3339 attr": `"1999-01-01T00:00:00Z"`, + "garbage attr": `"not-a-time"`, + } { + line := []byte(`{"message":"m","level":"INFO","source":"s:1","function":"f","time":` + attr + + `,"role":"heading","time":"2026-11-04T03:58:47Z"}` + "\n") + record, ok := parseLogRecord(line) + if !ok { + t.Fatalf("%s: record did not parse", name) + } + want, err := time.Parse(time.RFC3339Nano, "2026-11-04T03:58:47Z") + if err != nil { + t.Fatal(err) + } + if !record.timestamp.Equal(want) { + t.Fatalf("%s: timestamp = %v, want %v", name, record.timestamp, want) + } + var attrs map[string]json.RawMessage + if err := json.Unmarshal([]byte(record.attrs), &attrs); err != nil { + t.Fatal(err) + } + if string(attrs["time"]) != attr { + t.Fatalf("%s: attrs time = %s, want %s", name, attrs["time"], attr) + } + if got := promotedByKey(record, "role"); !got.valid || got.text != "heading" { + t.Fatalf("%s: promoted role = %+v", name, got) + } + } +} + +type recordingSink struct { + writes [][]byte + writeErr error + cancels int + closes int +} + +func (sink *recordingSink) Write(data []byte) (int, error) { + sink.writes = append(sink.writes, append([]byte(nil), data...)) + return len(data), sink.writeErr +} + +func (sink *recordingSink) Cancel() error { sink.cancels++; return nil } +func (sink *recordingSink) Close() error { sink.closes++; return nil } + +func TestMultiWriterFansOutDespiteFailure(t *testing.T) { + failing := &recordingSink{writeErr: errors.New("sink failed")} + healthy := &recordingSink{} + writer := NewMultiWriter(failing, healthy) + + line := []byte("{\"message\":\"m\"}\n") + if _, err := writer.Write(line); err == nil || !strings.Contains(err.Error(), "sink failed") { + t.Fatalf("Write error = %v", err) + } + if len(failing.writes) != 1 || len(healthy.writes) != 1 { + t.Fatalf("writes = %d/%d, want both sinks served", len(failing.writes), len(healthy.writes)) + } + if err := writer.Close(); err != nil { + t.Fatal(err) + } + if failing.closes != 1 || healthy.closes != 1 { + t.Fatalf("closes = %d/%d", failing.closes, healthy.closes) + } +} + +func TestMultiWriterPassesThroughSingleSink(t *testing.T) { + sink := &recordingSink{} + if got := NewMultiWriter(sink); got != DiagnosticsWriter(sink) { + t.Fatalf("single sink wrapped: %T", got) + } + if got := NewMultiWriter(); got == nil { + t.Fatal("empty multi writer is nil") + } +} diff --git a/internal/logging/duckdb_unavailable.go b/internal/logging/duckdb_unavailable.go new file mode 100644 index 0000000..77a1a4a --- /dev/null +++ b/internal/logging/duckdb_unavailable.go @@ -0,0 +1,25 @@ +//go:build !duckdb || !cgo + +// 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 + +// OpenDuckDB is provided by duckdb_native.go in builds with -tags duckdb. +func OpenDuckDB(_ string, _ bool, _ int) (DiagnosticsWriter, error) { + return nil, ErrDuckDBUnavailable +} diff --git a/internal/logging/duckdb_unavailable_test.go b/internal/logging/duckdb_unavailable_test.go new file mode 100644 index 0000000..7407eaa --- /dev/null +++ b/internal/logging/duckdb_unavailable_test.go @@ -0,0 +1,36 @@ +//go:build !duckdb || !cgo + +// 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 ( + "errors" + "path/filepath" + "testing" +) + +func TestOpenDuckDBUnavailableWithoutBuildTag(t *testing.T) { + writer, err := OpenDuckDB(filepath.Join(t.TempDir(), "debug.duckdb"), false, 1) + if writer != nil { + t.Fatalf("writer = %v, want nil", writer) + } + if !errors.Is(err, ErrDuckDBUnavailable) { + t.Fatalf("error = %v, want ErrDuckDBUnavailable", err) + } +}