Files
cthulhu/internal/atspi/capture_diagnostics_test.go

91 lines
3.4 KiB
Go

// Copyright (c) 2026 Storm Dragon
// SPDX-License-Identifier: GPL-3.0-or-later
package atspi
import (
"bytes"
"context"
"encoding/json"
"log/slog"
"testing"
"time"
"git.stormux.org/storm/cthulhu/internal/logging"
)
func TestCaptureDiagnosticsTimeoutDuringNativeCall(t *testing.T) {
var output bytes.Buffer
logger := logging.New(&output, logging.Options{Level: slog.LevelDebug})
ctx, trace := new_capture_diagnostics(context.Background(), logger, NewObjectID(":1.7", "/focus"))
if capture_diagnostics(ctx) != trace {
t.Fatal("capture context lost its diagnostics")
}
root := NewObjectID(":1.7", "/window")
cell := NewObjectID(":1.7", "/cell")
trace.set_root(root, "window")
trace.begin_stage("queue-wait", root, "frame")
started, resume, done := make(chan struct{}), make(chan struct{}), make(chan struct{})
go func() {
defer close(done)
trace.begin_stage("visible-text", cell, "table cell")
trace.progress("table cell", 12, 3, 250)
close(started)
<-resume // The native operation is still running when its caller times out.
trace.begin_stage("child-count", cell, "table cell")
trace.progress("table cell", 13, 2, 400)
trace.set_root(NewObjectID(":1.7", "/late-root"), "desktop")
trace.finish(nil)
}()
<-started
trace.finish(context.DeadlineExceeded)
close(resume)
<-done
var record struct {
Error string `json:"error"`
Duration time.Duration `json:"duration"`
LastStage string `json:"last_stage"`
ObjectPath string `json:"object_path"`
Role string `json:"role"`
RootPath string `json:"root_path"`
RootScope string `json:"root_scope"`
CapturedNodes int `json:"captured_nodes"`
PendingNodes int `json:"pending_nodes"`
TextBytes int `json:"text_bytes"`
Stages []captureStageTiming `json:"stages"`
}
if err := json.Unmarshal(output.Bytes(), &record); err != nil {
t.Fatalf("expected one diagnostic record: %v: %s", err, output.Bytes())
}
if record.Error != context.DeadlineExceeded.Error() || record.LastStage != "visible-text" || record.ObjectPath != cell.Path || record.Role != "table cell" {
t.Fatalf("timeout lost the in-progress operation: %+v", record)
}
if record.RootPath != root.Path || record.RootScope != "window" || record.CapturedNodes != 12 || record.PendingNodes != 3 || record.TextBytes != 250 {
t.Fatalf("late native completion changed timeout metadata: %+v", record)
}
var total time.Duration
for _, stage := range record.Stages {
total += stage.Duration
if stage.Stage == "visible-text" && (stage.SlowestPath != cell.Path || stage.MaxDuration <= 0) {
t.Fatalf("slow operation identity missing: %+v", stage)
}
}
if total != record.Duration || total <= 0 {
t.Fatalf("stage durations %v do not cover capture duration %v", total, record.Duration)
}
}
func TestCaptureDiagnosticsRequiresDebugLogging(t *testing.T) {
ctx := context.Background()
for _, logger := range []*slog.Logger{nil, logging.New(nil, logging.Options{Level: slog.LevelInfo})} {
gotContext, trace := new_capture_diagnostics(ctx, logger, ObjectID{})
if gotContext != ctx || trace != nil {
t.Fatal("disabled diagnostics added capture state")
}
trace.begin_stage("snapshot", ObjectID{}, "")
trace.progress("", 0, 0, 0)
trace.set_root(ObjectID{}, "")
trace.finish(nil)
}
}