diff --git a/.github/workflows/ci.yaml b/.github/workflows/ci.yaml index b5e9d4962f..c894ac25db 100644 --- a/.github/workflows/ci.yaml +++ b/.github/workflows/ci.yaml @@ -1069,9 +1069,6 @@ jobs: - name: 💾 Validate OpenBao snapshot fetch run: go test ./scripts/tests/vault-snapshot-fetch - - name: 🔎 Validate finite runtime-log evidence - run: go test ./scripts/analyze-cri-logs - - name: 🛑 Validate inactive ARC staging boundaries run: go test ./scripts/tests/arc-staging diff --git a/AGENTS.md b/AGENTS.md index f8a39ffd0d..e56c0ce527 100644 --- a/AGENTS.md +++ b/AGENTS.md @@ -83,7 +83,7 @@ ksail cluster list # existing Talos clusters ## Validation -The repository has static manifest checks, Go tests and linters, and MegaLinter. **Never run a cluster for maintenance.** For Go changes, run the affected packages' tests from the repository root (for example, `go test ./scripts/analyze-cri-logs`) and the relevant offline script regressions. The unconditional required `validate-go-regressions` job in [`.github/workflows/ci.yaml`](.github/workflows/ci.yaml) checks every tracked module with `bash scripts/check-go-modules-tidy.sh` before running the complete root-module Go suite. Its offline controls are `bash scripts/tests/test-go-modules-tidy.sh`. The guard leaves module files unchanged and names the module needing `go mod tidy`; it also refuses failed or empty discovery. The organization's required Go workflow (`validate-go-project.yaml` in devantler-tech/.github) applies whenever GitHub detects this repository's language as Go, and Go and Shell are within a few kilobytes of each other, so enrolment can flip with any change. Keep the repository passing that workflow whichever language is detected: its golangci-lint, dead-code, test, race-coverage and whole-repository MegaLinter jobs (#5852). MegaLinter's scope and dispositions live in [`.mega-linter.yml`](.mega-linter.yml). For manifest changes, validate with: +The repository has static manifest checks, Go tests and linters, and MegaLinter. **Never run a cluster for maintenance.** For Go changes, run the affected packages' tests from the repository root (for example, `go test ./scripts/validate-eks-ci-role-policy`) and the relevant offline script regressions. The unconditional required `validate-go-regressions` job in [`.github/workflows/ci.yaml`](.github/workflows/ci.yaml) checks every tracked module with `bash scripts/check-go-modules-tidy.sh` before running the complete root-module Go suite. Its offline controls are `bash scripts/tests/test-go-modules-tidy.sh`. The guard leaves module files unchanged and names the module needing `go mod tidy`; it also refuses failed or empty discovery. The organization's required Go workflow (`validate-go-project.yaml` in devantler-tech/.github) applies whenever GitHub detects this repository's language as Go, and Go and Shell are within a few kilobytes of each other, so enrolment can flip with any change. Keep the repository passing that workflow whichever language is detected: its golangci-lint, dead-code, test, race-coverage and whole-repository MegaLinter jobs (#5852). MegaLinter's scope and dispositions live in [`.mega-linter.yml`](.mega-linter.yml). For manifest changes, validate with: ```bash # Preferred when KSail is installed: schema-aware validation with Flux variable @@ -121,11 +121,6 @@ in the build of the layer that includes it. `flux check` and other cluster-dependent checks require a running cluster — they are **not** part of static validation and should not be run during maintenance. -For finite read-only runtime investigations, use the opt-in offline diagnostic in -[`docs/runtime-log-diagnosis.md`](docs/runtime-log-diagnosis.md). Its regressions -run with `go test ./scripts/analyze-cri-logs`; no cluster or credential is needed. -Timing evidence alone does not establish Coroot request attribution or recovery. - CI runs **static manifest validation** on PRs that touch k8s-related paths (`k8s/**`, `ksail*.yaml`, `.sops.yaml`, `talos*/**`, the naming configuration `.github/manifest-naming.yaml`, the validation scripts `scripts/validate-embedded-json/` / `scripts/validate-embedded-json.sh` / `scripts/generate-kubescape-exceptions/`, or `ci.yaml` — the authoritative list is the `k8s` filter in `.github/workflows/ci.yaml`) — the `validate` job in `.github/workflows/ci.yaml` first json-parses every registered embedded-JSON ConfigMap key via [`scripts/validate-embedded-json.sh`](scripts/validate-embedded-json.sh) (keys listed in the Go command's `registeredKeys` or ending in `.json` — schema validation treats such blobs as opaque strings, so a stray comma would otherwise ship silently; run `bash scripts/validate-embedded-json.sh` locally when touching one, from any directory via the script's absolute path), then runs `ksail workload validate` for both the local and prod overlays plus a Kubescape scan (`scripts/generate-kubescape-exceptions` converts the `ClusterSecurityException` CRs into Kubescape's exceptions format, then `ksail workload scan --framework nsa,mitre --exceptions --compliance-threshold ` gates on the combined score — the exact floor lives in `ci.yaml`). It is fast, needs no secrets (so it runs on fork PRs too), and starts no cluster. PRs touching `talos/**` or `talos-local/**` additionally run the `validate-talos` job: it renders the machine config with every patch applied (placeholder values stand in for env-expanded secrets like `${WG_SERVER_PRIVATE_KEY}`) and `talosctl validate`s the result, so a broken patch or an empty env expansion fails the PR event instead of the merge group's deploy (#2477). There is **no longer a full-cluster system test**: the local Docker cluster is a thin manual test-bed (see [Local Development Cluster](#local-development-cluster)), not a CI prod stand-in. The complete cluster-policy fixtures and offline regressions run in fixed suites of the `validate-cluster-policies` PR matrix, under the existing `k8s` path selection. At most three suites run concurrently in isolated checkouts; every regression step selects exactly one declared suite. The publication-generator regressions, repository guards and independent guards run in three independent required jobs. Both guard jobs retain unconditional steps; required CI and production deployment wait for all three. The independent guard job runs the native gateway receiver proof alongside the complete Go regression job, retaining its original command, container controls and deadline. Eleven independent manifest regressions run in the read-only `validate-manifest-regressions` PR matrix with the same pinned tools and inputs, alongside manifest validation. Its `contracts` and `native` groups use two isolated runners with fail-fast disabled; setting `max-parallel` to one retains an equivalent serial diagnostic path. The rollout fixture's independent mutation families use two isolated workers, retaining all cases, assertions and deadlines; foreground cases and shared-input changes wait for them. Required CI refuses an unsuccessful or unexpectedly skipped selected family. Run `bash scripts/tests/test-policy-ci-job.sh` for routing and result-boundary controls and `bash scripts/tests/test-fixture-workers.sh` for worker failure and completion controls; see the [partition decision](docs/adr/ci-regression-partitions.md). Policy evaluation uses the shared Kyverno CLI version from `.github/scripts/kyverno-version.sh` and needs no cluster or secrets. diff --git a/docs/runtime-log-diagnosis.md b/docs/runtime-log-diagnosis.md deleted file mode 100644 index 56949bd264..0000000000 --- a/docs/runtime-log-diagnosis.md +++ /dev/null @@ -1,100 +0,0 @@ -# Finite runtime-log diagnosis - -`scripts/analyze-cri-logs` is an offline operator diagnostic for containerd CRI -logs. It pairs `RunPodSandbox` and `PullImage` starts/results within each input -stream, reports slow pairs, and exposes evidence gaps. It does not collect logs, -contact a cluster, retrieve credentials, or change a workload. The experimental -gate is off by default; reassess it by 2026-10-09 after operator use, tracked in -[#4350](https://github.com/devantler-tech/platform/issues/4350). - -## Collect a finite private sample - -Use an existing authorized Talos reader context. Choose the node targets from a -fresh read-only Kubernetes node snapshot and retain that snapshot privately; -an input label is an operator assertion, not verified node identity. Preserve the -exact requested context, target, command, capture start/end, exit code and stderr -alongside each log. Recheck node identities after collection if an operation is -being joined to a live workload. Do not use an admin fallback or retrieve a new -credential to make the diagnostic work. - -For each selected node, collect a finite tail with the normal reader: - -```bash -umask 077 -talosctl --context "$READER_CONTEXT" --nodes "$NODE_ADDRESS" \ - logs cri --tail 10000 > "$PRIVATE_LOG" 2> "$PRIVATE_STDERR" -``` - -Record the command's exit code immediately. A failed read must remain a failed -capture, rather than an empty log interpreted as clearance. Use a fresh private -directory; stop a stalled capture rather than starting another watcher. Retain -only the minimum bounded sample needed for the investigation. Never publish raw -logs, roster files, workload identities, registry URLs or detailed reports. - -## Analyze the captured files - -The command requires explicit opt-in, a window of at most seven days, at least -one unique opaque node label, and a new output file. Use RFC3339 timestamps. -Input files must be private regular files (no group/world permissions or final -symlinks). Limits are 20 files, 8 MiB per file, 64 MiB total, and 1 MiB per line. -The report is created exclusively with mode `0600`; existing output is preserved. - -```bash -go run ./scripts/analyze-cri-logs --experimental \ - --from 2026-10-02T10:00:00Z --to 2026-10-02T11:00:00Z \ - --input node-1="$PRIVATE_LOG_1" --input node-2="$PRIVATE_LOG_2" \ - --slow 5s --output "$NEW_PRIVATE_REPORT" -``` - -`--slow` controls which pairs appear in the sample, with a default of 500 ms. -It is not an SLO setting and changes no alert threshold. Successful and failed -pair totals cover the entire input; `WindowPairs` and `SlowPairs` count returns -inside the requested inclusive window. Starts preceding the window are retained -for pairing. At most 1,000 slow/failed samples are included; truncation is explicit -and full pair counts are preserved. Targets are hashed rather than emitted as -raw messages or image references. Sandbox samples include their Pod UID for -private correlation; verify the exact Pod UID and each controller-owner UID when -joining to a Job or CronJob. A name prefix is insufficient. - -Exit codes are: - -| Code | Meaning | -| --- | --- | -| 0 | Finite supported records processed without the reported pairing/format/range gaps. | -| 1 | Report written, with gaps or sample truncation. Examine every node's counts. | -| 2 | Analysis refused or input/output failed; no new report is retained. | - -JSON envelopes and `time=... level=... msg="..."` logfmt records are supported, -including Talos's node-address prefix. Mixed node prefixes or mixed prefixed and -unprefixed envelopes in one file are refused. A timestamp found only inside a -message does not count. Unrecognized records, known unsupported CRI methods, overlapping -identities, unmatched results/starts and timestamp regressions are counted. -Overlapping requests remain ambiguous until every outstanding result drains; -the analyzer never guesses FIFO ordering. A clock regression invalidates all -pending starts. Malformed records or unrecognized records for the pairable -methods also invalidate pending starts; timings cannot bridge those gaps. Their -identities remain quarantined for the rest of that input, with later starts -counted as `QuarantinedStarts` and results as ambiguous. A retry cannot absorb -the delayed result of an earlier invalidated request. Use a new independent -finite capture for fresh evidence rather than clearing this uncertainty. -Retries after a completed pair can form new independent pairs. The known CRI -method inventory is explicit in the parser; an otherwise structured message -outside that inventory is not classified as a CRI operation. - -`Earliest`/`Latest` and `WindowBracketed` describe observed envelope timestamps. -Even a bracketed window does not establish complete capture, absence of dropped -logs, or complete request coverage. Input SHA256 digests bind the report to the -captured bytes, not to an authoritative live node or incident. - -## Evaluate as an operator - -Compare the finite report with an independent sample or known synthetic timing -before using it to select a repair. A slow CRI RPC is not necessarily the HTTP -request measured by Coroot. Every report therefore states -`CorootAttribution: UNPROVEN`, including an otherwise complete analysis. Request -identity, dependency attribution, the cause, and recovery against the existing -objective require separate evidence. Do not mark an incident resolved, adjust -its objective, or tune runtime configuration based solely on these timings. - -Run the regressions with `go test ./scripts/analyze-cri-logs`; required CI runs -the same tests on PR and merge-group revisions. diff --git a/scripts/analyze-cri-logs/main.go b/scripts/analyze-cri-logs/main.go deleted file mode 100644 index c664f5bfce..0000000000 --- a/scripts/analyze-cri-logs/main.go +++ /dev/null @@ -1,407 +0,0 @@ -// Command analyze-cri-logs is the opt-in offline diagnostic for finite CRI -// log records: it reports request pairing and slow-window counts without -// establishing Coroot request attribution or recovery. -package main - -import ( - "bufio" - "crypto/sha256" - "encoding/hex" - "encoding/json" - "errors" - "flag" - "fmt" - "io" - "os" - "regexp" - "sort" - "strconv" - "strings" - "syscall" - "time" -) - -const ( - maxFileBytes = 8 << 20 - maxTotalBytes = 64 << 20 - maxLineBytes = 1 << 20 - maxPending = 10000 - maxSamples = 1000 -) - -type inputs []string - -func (v *inputs) String() string { return "private node-label=path inputs" } -func (v *inputs) Set(s string) error { *v = append(*v, s); return nil } - -type nodeStats struct { - Label string - Lines, Parsed, Malformed, Unsupported, Starts, Returns, Pairs, FailedPairs int - OverlappingStarts, AmbiguousReturns, OrphanReturns, PendingStarts, OrderingGaps int - QuarantinedStarts int - OutsideWindow, WindowPairs, SlowPairs int - Earliest, Latest string - WindowBracketed bool - SHA256 string -} -type sample struct { - Node, Method, TargetHash, PodUID, Outcome string - Start, End time.Time - Milliseconds int64 -} -type report struct { - Status, Scope, CorootAttribution string - From, To time.Time - SlowThreshold string - Nodes []nodeStats - Samples []sample - SamplesTruncated bool -} -type operation struct{ method, key, uid, stage string } -type pendingCall struct { - start time.Time - count int - ambiguous bool - op operation -} - -var ( - labelPattern = regexp.MustCompile(`^[A-Za-z0-9_-]{1,48}$`) - logTime = regexp.MustCompile(`^time=("(?:\\.|[^"\\])*"|[^\s]+)`) - logMessage = regexp.MustCompile(`(?:^|\s)msg=("(?:\\.|[^"\\])*")`) - pullPattern = regexp.MustCompile(`^PullImage ("(?:\\.|[^"\\])*")(.*)$`) - uidPattern = regexp.MustCompile(`(?:\buid:"|\bUid:)([a-fA-F0-9]{8}-[a-fA-F0-9]{4}-[a-fA-F0-9]{4}-[a-fA-F0-9]{4}-[a-fA-F0-9]{12})`) - criPattern = regexp.MustCompile(`^(?:Version|RunPodSandbox|StopPodSandbox|RemovePodSandbox|PodSandboxStatus|ListPodSandbox|CreateContainer|StartContainer|StopContainer|RemoveContainer|ListContainers|ContainerStatus|UpdateContainerResources|ReopenContainerLog|ExecSync|Exec|Attach|PortForward|ContainerStats|ListContainerStats|PodSandboxStats|ListPodSandboxStats|UpdateRuntimeConfig|Status|CheckpointContainer|GetContainerEvents|ListMetricDescriptors|ListPodSandboxMetrics|RuntimeConfig|UpdatePodSandboxResources|ListImages|ImageStatus|PullImage|RemoveImage|ImageFsInfo)\b`) -) - -func envelope(raw string) (string, string) { - raw = strings.TrimSpace(raw) - if strings.HasPrefix(raw, "{") || strings.HasPrefix(raw, "time=") { - return "", raw - } - if prefix, rest, ok := strings.Cut(raw, ": "); ok && (strings.HasPrefix(rest, "{") || strings.HasPrefix(rest, "time=")) { - return prefix, rest - } - return "", raw -} - -// Only structured envelope timestamps count. A timestamp in a message cannot -// turn a malformed record into timing evidence. -func parseLine(raw string) (time.Time, string, error) { - _, raw = envelope(raw) - var stamp, msg string - if strings.HasPrefix(raw, "{") { - var fields struct{ Time, Msg string } - if err := json.Unmarshal([]byte(raw), &fields); err != nil { - return time.Time{}, "", errors.New("malformed JSON") - } - stamp, msg = fields.Time, fields.Msg - } else { - t, m := logTime.FindStringSubmatch(raw), logMessage.FindStringSubmatch(raw) - if len(t) != 2 || len(m) != 2 { - return time.Time{}, "", errors.New("unrecognized structured envelope") - } - stamp = t[1] - var err error - if strings.HasPrefix(stamp, `"`) { - stamp, err = strconv.Unquote(stamp) - if err != nil { - return time.Time{}, "", err - } - } - msg, err = strconv.Unquote(m[1]) - if err != nil { - return time.Time{}, "", err - } - } - t, err := time.Parse(time.RFC3339Nano, stamp) - if err != nil || msg == "" { - return time.Time{}, "", errors.New("missing or invalid envelope fields") - } - return t, msg, nil -} - -func parseOperation(msg string) (operation, bool) { - var op operation - var suffix string - if m := pullPattern.FindStringSubmatch(msg); len(m) == 3 { - op.method, op.key, suffix = "PullImage", "PullImage "+m[1], m[2] - } else if strings.HasPrefix(msg, "RunPodSandbox for ") { - op.method = "RunPodSandbox" - key := msg - for _, marker := range []string{" returns", " failed", " error"} { - if i := strings.Index(key, marker); i >= 0 { - suffix, key = key[i:], key[:i] - } - } - uid := uidPattern.FindStringSubmatch(key) - if len(uid) != 2 { - return operation{}, false - } - op.key, op.uid = key, uid[1] - } else { - return operation{}, false - } - switch { - case suffix == "": - op.stage = "start" - case strings.HasPrefix(suffix, " failed"), strings.HasPrefix(suffix, " error"), strings.HasPrefix(suffix, " returns error"): - op.stage = "failure" - case op.method == "RunPodSandbox" && strings.HasPrefix(suffix, " returns sandbox id "), - op.method == "PullImage" && strings.HasPrefix(suffix, " returns image reference "): - op.stage = "success" - default: - return operation{}, false - } - return op, true -} - -func analyze(label string, data io.Reader, from, to time.Time, slow time.Duration, r *report) (nodeStats, error) { - n := nodeStats{Label: label} - pending := map[string]pendingCall{} - quarantined := map[string]bool{} - invalidate := func() { - for key, p := range pending { - n.PendingStarts += p.count - quarantined[key] = true - } - clear(pending) - } - var earliest, latest, previous time.Time - var nodePrefix string - var havePrefix bool - scanner := bufio.NewScanner(data) - scanner.Buffer(make([]byte, 65536), maxLineBytes) - for scanner.Scan() { - n.Lines++ - when, msg, err := parseLine(scanner.Text()) - if err != nil { - n.Malformed++ - invalidate() - continue - } - prefix, _ := envelope(scanner.Text()) - if havePrefix && prefix != nodePrefix { - return n, errors.New("mixed node prefixes or envelope styles") - } - nodePrefix, havePrefix = prefix, true - n.Parsed++ - if earliest.IsZero() || when.Before(earliest) { - earliest = when - } - if latest.IsZero() || when.After(latest) { - latest = when - } - if !previous.IsZero() && when.Before(previous) { - n.OrderingGaps++ - invalidate() - } - previous = when - inWindow := !when.Before(from) && !when.After(to) - if !inWindow { - n.OutsideWindow++ - } - op, ok := parseOperation(msg) - if !ok { - if criPattern.MatchString(msg) { - n.Unsupported++ - } - // An unrecognized record for a pairable method may be a lost - // terminal or retry start; do not pair across that uncertainty. - if strings.HasPrefix(msg, "RunPodSandbox ") || strings.HasPrefix(msg, "PullImage ") { - invalidate() - } - continue - } - p := pending[op.key] - if op.stage == "start" { - n.Starts++ - if quarantined[op.key] { - n.QuarantinedStarts++ - continue - } - if p.count == 0 { - p = pendingCall{start: when, op: op} - } else { - n.OverlappingStarts++ - p.ambiguous = true - } - p.count++ - pending[op.key] = p - if len(pending)+len(quarantined) > maxPending || p.count > maxPending { - return n, errors.New("pending-operation limit exceeded") - } - continue - } - n.Returns++ - if quarantined[op.key] { - n.AmbiguousReturns++ - continue - } - if p.count == 0 { - n.OrphanReturns++ - continue - } - if p.ambiguous { - n.AmbiguousReturns++ - p.count-- - if p.count == 0 { - delete(pending, op.key) - } else { - pending[op.key] = p - } - continue - } - delete(pending, op.key) - if op.stage == "failure" { - n.FailedPairs++ - } else { - n.Pairs++ - } - if inWindow { - n.WindowPairs++ - d := when.Sub(p.start) - if d >= slow { - n.SlowPairs++ - } - if d >= slow || op.stage == "failure" { - if len(r.Samples) < maxSamples { - h := sha256.Sum256([]byte(op.key)) - outcome := "success" - if op.stage == "failure" { - outcome = "failure" - } - r.Samples = append(r.Samples, sample{Node: label, Method: op.method, TargetHash: hex.EncodeToString(h[:]), PodUID: op.uid, Outcome: outcome, Start: p.start.UTC(), End: when.UTC(), Milliseconds: d.Milliseconds()}) - } else { - r.SamplesTruncated = true - } - } - } - } - if err := scanner.Err(); err != nil { - return n, errors.New("log line or read limit exceeded") - } - for _, p := range pending { - n.PendingStarts += p.count - } - if !earliest.IsZero() { - n.Earliest, n.Latest = earliest.UTC().Format(time.RFC3339Nano), latest.UTC().Format(time.RFC3339Nano) - n.WindowBracketed = !earliest.After(from) && !latest.Before(to) - } - return n, nil -} - -func hasGaps(n nodeStats) bool { - return n.Malformed+n.Unsupported+n.OverlappingStarts+n.AmbiguousReturns+n.OrphanReturns+n.PendingStarts+n.OrderingGaps+n.QuarantinedStarts > 0 || !n.WindowBracketed -} - -func run(args []string, stdout io.Writer) int { - fail := func(message string) int { _, _ = fmt.Fprintln(stdout, "ANALYSIS=REFUSED "+message); return 2 } - fs := flag.NewFlagSet("analyze-cri-logs", flag.ContinueOnError) - fs.SetOutput(io.Discard) // Flag errors can contain raw paths or values. - var logs inputs - var experimental bool - var start, end, output string - var slow time.Duration - fs.BoolVar(&experimental, "experimental", false, "explicitly enable this offline diagnostic") - fs.StringVar(&start, "from", "", "window start RFC3339") - fs.StringVar(&end, "to", "", "window end RFC3339") - fs.StringVar(&output, "output", "", "new private report file") - fs.DurationVar(&slow, "slow", 500*time.Millisecond, "sample threshold, not an SLO") - fs.Var(&logs, "input", "repeat node-label=private-log-path") - if err := fs.Parse(args); err != nil || fs.NArg() != 0 { - return fail("invalid arguments") - } - if !experimental { - return fail("experimental opt-in required") - } - from, err1 := time.Parse(time.RFC3339Nano, start) - to, err2 := time.Parse(time.RFC3339Nano, end) - if err1 != nil || err2 != nil || !to.After(from) || to.Sub(from) > 7*24*time.Hour || slow <= 0 || output == "" || len(logs) == 0 || len(logs) > 20 { - return fail("invalid window, threshold, output or input count") - } - targets := map[string]string{} - for _, entry := range logs { - label, path, ok := strings.Cut(entry, "=") - if !ok || !labelPattern.MatchString(label) || path == "" || targets[label] != "" { - return fail("invalid or duplicate node label") - } - targets[label] = path - } - labels := make([]string, 0, len(targets)) - for label := range targets { - labels = append(labels, label) - } - sort.Strings(labels) - r := report{Status: "COMPLETE", Scope: "finite CRI records; not complete request coverage", CorootAttribution: "UNPROVEN", From: from.UTC(), To: to.UTC(), SlowThreshold: slow.String(), Nodes: []nodeStats{}, Samples: []sample{}} - var total int64 - for _, label := range labels { - // Nonblocking/no-follow avoids hanging on a FIFO or following an input - // symlink before we can verify the opened file. Operators use macOS/Linux. - f, err := os.OpenFile(targets[label], os.O_RDONLY|syscall.O_NONBLOCK|syscall.O_NOFOLLOW, 0) - if err != nil { - return fail("cannot open private input " + label) - } - before, err := f.Stat() - if err != nil || !before.Mode().IsRegular() || before.Mode().Perm()&0077 != 0 || before.Size() > maxFileBytes { - _ = f.Close() - return fail("input must be a private bounded regular file: " + label) - } - total += before.Size() - if total > maxTotalBytes { - _ = f.Close() - return fail("total input limit exceeded") - } - h := sha256.New() - limited := &io.LimitedReader{R: f, N: maxFileBytes + 1} - n, analyzeErr := analyze(label, io.TeeReader(limited, h), from, to, slow, &r) - after, statErr := f.Stat() - closeErr := f.Close() - if analyzeErr != nil { - return fail("input analysis refused: " + label + " (" + analyzeErr.Error() + ")") - } - if statErr != nil || closeErr != nil || limited.N == 0 { - return fail("input analysis failed or exceeded its limit: " + label) - } - if before.Size() != after.Size() || !before.ModTime().Equal(after.ModTime()) { - return fail("input changed during analysis: " + label) - } - n.SHA256 = hex.EncodeToString(h.Sum(nil)) - if hasGaps(n) { - r.Status = "GAPS" - } - r.Nodes = append(r.Nodes, n) - } - if r.SamplesTruncated { - r.Status = "GAPS" - } - b, err := json.MarshalIndent(r, "", " ") - if err != nil { - return fail("report encoding failed") - } - f, err := os.OpenFile(output, os.O_WRONLY|os.O_CREATE|os.O_EXCL, 0600) - if err != nil { - return fail("output must be a new private file") - } - _, writeErr := f.Write(append(b, '\n')) - closeErr := f.Close() - if writeErr != nil || closeErr != nil { - _ = os.Remove(output) - return fail("report write failed") - } - var pairs, slowPairs, failures int - for _, n := range r.Nodes { - pairs += n.Pairs - slowPairs += n.SlowPairs - failures += n.FailedPairs - } - if _, err := fmt.Fprintf(stdout, "ANALYSIS=%s nodes=%d successful_pairs=%d slow_window_pairs=%d failed_pairs=%d coroot_attribution=UNPROVEN\n", r.Status, len(r.Nodes), pairs, slowPairs, failures); err != nil { - return 2 - } - if r.Status == "GAPS" { - return 1 - } - return 0 -} - -func main() { os.Exit(run(os.Args[1:], os.Stdout)) } diff --git a/scripts/analyze-cri-logs/main_test.go b/scripts/analyze-cri-logs/main_test.go deleted file mode 100644 index d8c6266e79..0000000000 --- a/scripts/analyze-cri-logs/main_test.go +++ /dev/null @@ -1,371 +0,0 @@ -package main - -import ( - "bytes" - "encoding/json" - "fmt" - "os" - "path/filepath" - "strings" - "syscall" - "testing" - "time" -) - -type testNode struct { - Label string - Lines, Parsed, Malformed, Unsupported, Starts, Returns, Pairs, FailedPairs int - OverlappingStarts, AmbiguousReturns, OrphanReturns, PendingStarts, OrderingGaps int - OutsideWindow, WindowPairs, SlowPairs int - Earliest, Latest string - WindowBracketed bool - SHA256 string -} -type testSample struct { - Node, Method, TargetHash, PodUID, Outcome string - Milliseconds int64 -} -type testReport struct { - Status, Scope, CorootAttribution string - Nodes []testNode - Samples []testSample - SamplesTruncated bool -} - -const uid = "11111111-2222-3333-4444-555555555555" -const sandbox = "RunPodSandbox for &PodSandboxMetadata{Name:example,Uid:" + uid + ",Namespace:example,Attempt:0,}" - -func jsonLine(stamp, message string) string { - b, _ := json.Marshal(map[string]string{"time": stamp, "msg": message, "level": "info"}) - return string(b) + "\n" -} -func logfmtLine(stamp, message string) string { - return fmt.Sprintf("time=%q level=info msg=%q\n", stamp, message) -} - -func invoke(t *testing.T, inputs map[string]string, extra ...string) (int, string, testReport, string) { - t.Helper() - d := t.TempDir() - output := filepath.Join(d, "report.json") - args := []string{"--experimental", "--from", "2026-10-02T10:00:00Z", "--to", "2026-10-02T10:01:00Z", "--output", output} - for label, data := range inputs { - path := filepath.Join(d, label+".log") - if err := os.WriteFile(path, []byte(data), 0600); err != nil { - t.Fatal(err) - } - args = append(args, "--input", label+"="+path) - } - args = append(args, extra...) - var stdout bytes.Buffer - code := run(args, &stdout) - var report testReport - if b, err := os.ReadFile(output); err == nil { - if err = json.Unmarshal(b, &report); err != nil { - t.Fatalf("invalid report: %v", err) - } - } - return code, stdout.String(), report, output -} - -func TestPairBothFormatsAndDoNotLeakTargets(t *testing.T) { - secret := "https://registry.example/image?token=DO-NOT-EMIT" - data := jsonLine("2026-10-02T09:59:59Z", "ready") + - jsonLine("2026-10-02T10:00:00Z", sandbox) + jsonLine("2026-10-02T10:00:06Z", sandbox+" returns sandbox id abc") + - logfmtLine("2026-10-02T10:00:07Z", fmt.Sprintf("PullImage %q", secret)) + - logfmtLine("2026-10-02T10:00:10Z", fmt.Sprintf("PullImage %q returns image reference abc", secret)) + - jsonLine("2026-10-02T10:01:01Z", "ready") - code, stdout, r, output := invoke(t, map[string]string{"node-1": data}) - if code != 0 || len(r.Nodes) != 1 { - t.Fatalf("code=%d stdout=%s report=%+v", code, stdout, r) - } - n := r.Nodes[0] - if n.Pairs != 2 || n.SlowPairs != 2 || n.WindowPairs != 2 || !n.WindowBracketed || n.SHA256 == "" { - t.Fatalf("wrong evidence: %+v", n) - } - if len(r.Samples) != 2 || r.Samples[0].Milliseconds != 6000 || r.Samples[0].PodUID != uid || r.Samples[1].Milliseconds != 3000 { - t.Fatalf("wrong samples: %+v", r.Samples) - } - if r.CorootAttribution != "UNPROVEN" || r.Scope != "finite CRI records; not complete request coverage" { - t.Fatalf("missing scope: %+v", r) - } - b, _ := os.ReadFile(output) - if strings.Contains(string(b)+stdout, secret) || strings.Contains(string(b)+stdout, "DO-NOT-EMIT") { - t.Fatal("raw target leaked") - } - info, _ := os.Stat(output) - if info.Mode().Perm() != 0600 { - t.Fatalf("report permissions %v", info.Mode()) - } -} - -func TestOverlapsRemainAmbiguousUntilAllReturnsDrain(t *testing.T) { - data := jsonLine("2026-10-02T09:59:59Z", "ready") - for _, item := range []struct{ stamp, msg string }{ - {"10:00:00", sandbox}, {"10:00:01", sandbox}, {"10:00:02", sandbox + " returns sandbox id a"}, - {"10:00:03", sandbox + " returns sandbox id b"}, {"10:00:04", sandbox}, {"10:00:05", sandbox + " returns sandbox id c"}, - } { - data += jsonLine("2026-10-02T"+item.stamp+"Z", item.msg) - } - data += jsonLine("2026-10-02T10:01:01Z", "ready") - code, _, r, _ := invoke(t, map[string]string{"node-1": data}) - if code != 1 || len(r.Nodes) != 1 { - t.Fatalf("code=%d report=%+v", code, r) - } - n := r.Nodes[0] - if n.OverlappingStarts != 1 || n.AmbiguousReturns != 2 || n.Pairs != 1 || n.PendingStarts != 0 { - t.Fatalf("overlap fabricated a pair: %+v", n) - } -} - -func TestNeverPairAcrossNodesAndReportOrphans(t *testing.T) { - code, _, r, _ := invoke(t, map[string]string{ - "node-1": jsonLine("2026-10-02T10:00:00Z", sandbox), - "node-2": jsonLine("2026-10-02T10:00:05Z", sandbox+" returns sandbox id a"), - }) - if code != 1 || len(r.Nodes) != 2 { - t.Fatalf("code=%d report=%+v", code, r) - } - if r.Nodes[0].PendingStarts != 1 || r.Nodes[1].OrphanReturns != 1 || len(r.Samples) != 0 { - t.Fatalf("cross-node pairing: %+v", r) - } -} - -func TestReportMalformedUnsupportedFailureAndRetention(t *testing.T) { - data := "not a structured record\n" + jsonLine("2026-10-02T10:00:01Z", "CreateContainer for unknown") + - jsonLine("2026-10-02T10:00:02Z", sandbox) + jsonLine("2026-10-02T10:00:04Z", sandbox+" failed: rpc error") - code, _, r, _ := invoke(t, map[string]string{"node-1": data}) - if code != 1 || len(r.Nodes) != 1 { - t.Fatalf("code=%d report=%+v", code, r) - } - n := r.Nodes[0] - if n.Malformed != 1 || n.Unsupported != 1 || n.FailedPairs != 1 || n.Pairs != 0 || n.WindowBracketed { - t.Fatalf("missing gap: %+v", n) - } - if len(r.Samples) != 1 || r.Samples[0].Outcome != "failure" { - t.Fatalf("failure hidden: %+v", r.Samples) - } -} - -func TestClockRegressionInvalidatesOutstandingStarts(t *testing.T) { - data := jsonLine("2026-10-02T10:00:02Z", sandbox) + jsonLine("2026-10-02T10:00:01Z", "ready") + - jsonLine("2026-10-02T10:00:03Z", sandbox+" returns sandbox id a") - code, _, r, _ := invoke(t, map[string]string{"node-1": data}) - if code != 1 || len(r.Nodes) != 1 || r.Nodes[0].OrderingGaps != 1 || r.Nodes[0].Pairs != 0 || r.Nodes[0].PendingStarts != 1 { - t.Fatalf("clock regression hidden: code=%d %+v", code, r) - } -} - -func TestPairStartsBeforeWindowButCountOnlyReturnsInside(t *testing.T) { - data := jsonLine("2026-10-02T09:59:58Z", sandbox) + jsonLine("2026-10-02T10:00:01Z", sandbox+" returns sandbox id a") + - jsonLine("2026-10-02T10:01:02Z", "ready") - code, _, r, _ := invoke(t, map[string]string{"node-1": data}) - if code != 0 || len(r.Nodes) != 1 || r.Nodes[0].WindowPairs != 1 || r.Nodes[0].OutsideWindow != 2 || r.Samples[0].Milliseconds != 3000 { - t.Fatalf("window incorrectly dropped start: code=%d %+v", code, r) - } -} - -func TestDefaultOffDoesNotOpenInputsOrWriteReport(t *testing.T) { - d := t.TempDir() - output := filepath.Join(d, "report.json") - var stdout bytes.Buffer - code := run([]string{"--input", "node-1=/missing", "--output", output}, &stdout) - if code != 2 || !strings.Contains(stdout.String(), "experimental opt-in required") { - t.Fatalf("default not off: %d %s", code, stdout.String()) - } - if _, err := os.Stat(output); !os.IsNotExist(err) { - t.Fatal("default-off wrote report") - } -} - -func TestRefuseUnsafeInputsAndExistingOutput(t *testing.T) { - for _, extra := range [][]string{{"--from", "bad"}, {"--to", "2026-10-02T09:00:00Z"}, {"--slow", "0s"}, {"--input", "node-1=/another"}} { - code, _, _, output := invoke(t, map[string]string{"node-1": ""}, extra...) - if code != 2 { - t.Fatalf("invalid args accepted: %v code=%d", extra, code) - } - if _, err := os.Stat(output); !os.IsNotExist(err) { - t.Fatalf("invalid input wrote report: %v", extra) - } - } - d := t.TempDir() - path := filepath.Join(d, "log") - output := filepath.Join(d, "out") - if err := os.WriteFile(path, []byte(""), 0644); err != nil { - t.Fatal(err) - } - args := []string{"--experimental", "--from", "2026-10-02T10:00:00Z", "--to", "2026-10-02T10:01:00Z", "--input", "node-1=" + path, "--output", output} - var stdout bytes.Buffer - if run(args, &stdout) != 2 { - t.Fatal("public input accepted") - } - if err := os.Chmod(path, 0600); err != nil { - t.Fatal(err) - } - if err := os.WriteFile(output, []byte("preserve"), 0600); err != nil { - t.Fatal(err) - } - if run(args, &stdout) != 2 { - t.Fatal("existing output overwritten") - } - b, _ := os.ReadFile(output) - if string(b) != "preserve" { - t.Fatal("foreign report changed") - } -} - -func TestRejectOversizeLineAndDoNotEchoIt(t *testing.T) { - code, stdout, _, output := invoke(t, map[string]string{"node-1": strings.Repeat("SECRET", 200000)}) - if code != 2 || strings.Contains(stdout, "SECRET") { - t.Fatalf("oversize input mishandled: %d", code) - } - if _, err := os.Stat(output); !os.IsNotExist(err) { - t.Fatal("oversize analysis wrote success report") - } -} - -func TestObservedProtobufFormatPreservesNanoSeconds(t *testing.T) { - metadata := `RunPodSandbox for name:"example-job" uid:"` + uid + `" namespace:"example"` - data := "192.0.2.10: " + jsonLine("2026-10-02T09:59:59Z", "ready") + - "192.0.2.10: " + jsonLine("2026-10-02T10:00:00.100000001Z", metadata) + - "192.0.2.10: " + jsonLine("2026-10-02T10:00:12.200000001Z", metadata+` returns sandbox id "abc"`) + - "192.0.2.10: " + jsonLine("2026-10-02T10:01:01Z", "ready") - code, _, r, _ := invoke(t, map[string]string{"node-1": data}) - if code != 0 || len(r.Samples) != 1 || r.Samples[0].Milliseconds != 12100 || r.Samples[0].PodUID != uid { - t.Fatalf("observed protobuf format lost: %d %+v", code, r) - } -} - -func TestTimestampInsideMessageIsNotAnEnvelope(t *testing.T) { - data := fmt.Sprintf("level=info msg=%q\n", "time=2026-10-02T10:00:00Z "+sandbox) - code, _, r, _ := invoke(t, map[string]string{"node-1": data}) - if code != 1 || len(r.Nodes) != 1 || r.Nodes[0].Malformed != 1 || r.Nodes[0].Starts != 0 { - t.Fatalf("message manufactured evidence: %d %+v", code, r) - } -} - -func TestConcurrentPullsAreNotMatchedFIFO(t *testing.T) { - key := `PullImage "registry.example/image:tag"` - data := jsonLine("2026-10-02T10:00:00Z", key) + jsonLine("2026-10-02T10:00:01Z", key) + - jsonLine("2026-10-02T10:00:02Z", key+" returns image reference a") + - jsonLine("2026-10-02T10:00:03Z", key+" returns image reference b") - code, _, r, _ := invoke(t, map[string]string{"node-1": data}) - if code != 1 || len(r.Nodes) != 1 || r.Nodes[0].AmbiguousReturns != 2 || r.Nodes[0].Pairs != 0 { - t.Fatalf("concurrent pull mispaired: %d %+v", code, r) - } -} - -func TestExplicitSampleCapPreservesPairCounts(t *testing.T) { - var data strings.Builder - data.WriteString(jsonLine("2026-10-02T09:59:59Z", "ready")) - base := time.Date(2026, 10, 2, 10, 0, 0, 0, time.UTC) - for i := 0; i < 1002; i++ { - data.WriteString(jsonLine(base.Add(time.Duration(i*2)*time.Microsecond).Format(time.RFC3339Nano), sandbox)) - data.WriteString(jsonLine(base.Add(time.Duration(i*2+1)*time.Microsecond).Format(time.RFC3339Nano), sandbox+" returns sandbox id a")) - } - data.WriteString(jsonLine("2026-10-02T10:01:01Z", "ready")) - code, _, r, _ := invoke(t, map[string]string{"node-1": data.String()}, "--slow", "1ns") - if code != 1 || !r.SamplesTruncated || len(r.Samples) != 1000 || len(r.Nodes) != 1 || r.Nodes[0].Pairs != 1002 { - t.Fatalf("sample cap silently dropped evidence: %d %+v", code, r.Nodes) - } -} - -func TestBoundedRegularInputAndNoSymlinkFollowing(t *testing.T) { - d := t.TempDir() - input := filepath.Join(d, "input") - output := filepath.Join(d, "report") - args := []string{"--experimental", "--from", "2026-10-02T10:00:00Z", "--to", "2026-10-02T10:01:00Z", "--input", "node-1=" + input, "--output", output} - var stdout bytes.Buffer - if err := syscall.Mkfifo(input, 0600); err != nil { - t.Fatal(err) - } - if code := run(args, &stdout); code != 2 { - t.Fatalf("FIFO accepted: %d", code) - } - if err := os.Remove(input); err != nil { - t.Fatal(err) - } - actual := filepath.Join(d, "actual") - if err := os.WriteFile(actual, nil, 0600); err != nil { - t.Fatal(err) - } - if err := os.Symlink(actual, input); err != nil { - t.Fatal(err) - } - if code := run(args, &stdout); code != 2 { - t.Fatalf("symlink followed: %d", code) - } - if err := os.Remove(input); err != nil { - t.Fatal(err) - } - f, err := os.OpenFile(input, os.O_CREATE|os.O_WRONLY, 0600) - if err != nil { - t.Fatal(err) - } - if err = f.Truncate(8<<20 + 1); err != nil { - t.Fatal(err) - } - if err = f.Close(); err != nil { - t.Fatal(err) - } - if code := run(args, &stdout); code != 2 { - t.Fatalf("oversize file accepted: %d", code) - } - if _, err := os.Stat(output); !os.IsNotExist(err) { - t.Fatal("refused file wrote report") - } -} - -func TestRejectMultiplexedNodePrefixes(t *testing.T) { - data := "192.0.2.10: " + jsonLine("2026-10-02T10:00:00Z", sandbox) + - "192.0.2.11: " + jsonLine("2026-10-02T10:00:05Z", sandbox+" returns sandbox id a") - code, _, _, output := invoke(t, map[string]string{"node-1": data}) - if code != 2 { - t.Fatalf("cross-node timing accepted: %d", code) - } - if _, err := os.Stat(output); !os.IsNotExist(err) { - t.Fatal("mixed node stream wrote report") - } -} - -func TestMalformedGapInvalidatesPendingCalls(t *testing.T) { - data := jsonLine("2026-10-02T09:59:59Z", "ready") + jsonLine("2026-10-02T10:00:00Z", sandbox) + - "truncated terminal and lost retry start\n" + jsonLine("2026-10-02T10:00:15Z", sandbox+" returns sandbox id a") + - jsonLine("2026-10-02T10:01:01Z", "ready") - code, _, r, _ := invoke(t, map[string]string{"node-1": data}) - if code != 1 || len(r.Nodes) != 1 || r.Nodes[0].Pairs != 0 || len(r.Samples) != 0 || r.Nodes[0].PendingStarts != 1 || r.Nodes[0].AmbiguousReturns != 1 { - t.Fatalf("pair manufactured across loss: %d %+v", code, r) - } -} - -func TestPreviouslyOmittedCRIMethodsCountAsUnsupported(t *testing.T) { - data := jsonLine("2026-10-02T09:59:59Z", "ready") + jsonLine("2026-10-02T10:00:00Z", "ExecSync for container abc") + - jsonLine("2026-10-02T10:00:01Z", "PodSandboxStatus for sandbox abc") + jsonLine("2026-10-02T10:00:02Z", "ListPodSandbox with filter") + - jsonLine("2026-10-02T10:01:01Z", "ready") - code, _, r, _ := invoke(t, map[string]string{"node-1": data}) - if code != 1 || len(r.Nodes) != 1 || r.Nodes[0].Unsupported != 3 { - t.Fatalf("unsupported CRI silently omitted: %d %+v", code, r) - } -} - -func TestUnrecognizedPairableRecordInvalidatesPendingCalls(t *testing.T) { - data := jsonLine("2026-10-02T09:59:59Z", "ready") + jsonLine("2026-10-02T10:00:00Z", sandbox) + - jsonLine("2026-10-02T10:00:01Z", "RunPodSandbox for missing-identity returns error") + - jsonLine("2026-10-02T10:00:15Z", sandbox+" returns sandbox id a") + jsonLine("2026-10-02T10:01:01Z", "ready") - code, _, r, _ := invoke(t, map[string]string{"node-1": data}) - if code != 1 || len(r.Nodes) != 1 || r.Nodes[0].Pairs != 0 || r.Nodes[0].PendingStarts != 1 || r.Nodes[0].Unsupported != 1 { - t.Fatalf("pair manufactured across unknown operation: %d %+v", code, r) - } -} - -func TestRetryCannotStealDelayedResultAfterInvalidation(t *testing.T) { - key := `PullImage "registry.example/image:tag"` - for _, gap := range []string{"malformed record\n", jsonLine("2026-10-02T10:00:01Z", "PullImage unrecognized terminal"), jsonLine("2026-10-02T09:59:59Z", "clock regressed")} { - data := jsonLine("2026-10-02T09:59:58Z", "ready") + jsonLine("2026-10-02T10:00:00Z", key) + gap + - jsonLine("2026-10-02T10:00:02Z", key) + jsonLine("2026-10-02T10:00:03Z", key+" returns image reference a") + - jsonLine("2026-10-02T10:00:04Z", key+" returns image reference b") + jsonLine("2026-10-02T10:01:01Z", "ready") - code, _, r, _ := invoke(t, map[string]string{"node-1": data}) - if code != 1 || len(r.Nodes) != 1 || r.Nodes[0].Pairs != 0 || len(r.Samples) != 0 || r.Nodes[0].AmbiguousReturns != 2 { - t.Fatalf("retry stole delayed result after gap: %d %+v", code, r) - } - } -}