Reset master to testing content

internal/atspi/capture_diagnostics.go

@@ -0,0 +1,153 @@
+// Copyright (c) 2026 Storm Dragon
+// SPDX-License-Identifier: GPL-3.0-or-later
+
+package atspi
+
+import (
+	"context"
+	"log/slog"
+	"sync"
+	"time"
+)
+
+type captureDiagnosticKey struct{}
+
+type captureStageTiming struct {
+	Stage       string        `json:"stage"`
+	Calls       int           `json:"calls"`
+	Duration    time.Duration `json:"duration"`
+	MaxDuration time.Duration `json:"max_duration"`
+	SlowestBus  string        `json:"slowest_bus"`
+	SlowestPath string        `json:"slowest_path"`
+	SlowestRole string        `json:"slowest_role"`
+}
+
+// One request owns these copied diagnostics. The caller can finish them while
+// the GLib thread is still inside a native call; no native references cross
+// threads. A finished trace ignores later updates from that call.
+type captureDiagnostics struct {
+	mutex         sync.Mutex
+	logger        *slog.Logger
+	kind          string
+	started       time.Time
+	stageStarted  time.Time
+	stage         string
+	object        ObjectID
+	role          string
+	root          ObjectID
+	rootScope     string
+	capturedNodes int
+	pendingNodes  int
+	textBytes     int
+	textIssues    map[TextCaptureIssue]int
+	timings       []captureStageTiming
+	finished      bool
+}
+
+func (trace *captureDiagnostics) text_issue(issue TextCaptureIssue) {
+	if trace == nil {
+		return
+	}
+	trace.mutex.Lock()
+	defer trace.mutex.Unlock()
+	if !trace.finished {
+		if trace.textIssues == nil {
+			trace.textIssues = make(map[TextCaptureIssue]int)
+		}
+		trace.textIssues[issue]++
+	}
+}
+
+func new_capture_diagnostics(ctx context.Context, logger *slog.Logger, focus ObjectID) (context.Context, *captureDiagnostics) {
+	if logger == nil || !logger.Enabled(ctx, slog.LevelDebug) {
+		return ctx, nil
+	}
+	now := time.Now()
+	trace := &captureDiagnostics{logger: logger, started: now, stageStarted: now, stage: "request-lock", object: focus}
+	return context.WithValue(ctx, captureDiagnosticKey{}, trace), trace
+}
+
+func capture_diagnostics(ctx context.Context) *captureDiagnostics {
+	trace, _ := ctx.Value(captureDiagnosticKey{}).(*captureDiagnostics)
+	return trace
+}
+
+func (trace *captureDiagnostics) record_stage(now time.Time) {
+	duration := now.Sub(trace.stageStarted)
+	index := 0
+	for index < len(trace.timings) && trace.timings[index].Stage != trace.stage {
+		index++
+	}
+	if index == len(trace.timings) {
+		trace.timings = append(trace.timings, captureStageTiming{Stage: trace.stage})
+	}
+	timing := &trace.timings[index]
+	timing.Calls++
+	timing.Duration += duration
+	if duration > timing.MaxDuration {
+		timing.MaxDuration = duration
+		timing.SlowestBus, timing.SlowestPath, timing.SlowestRole = trace.object.BusName, trace.object.Path, trace.role
+	}
+}
+
+func (trace *captureDiagnostics) begin_stage(stage string, object ObjectID, role string) {
+	if trace == nil {
+		return
+	}
+	trace.mutex.Lock()
+	defer trace.mutex.Unlock()
+	if trace.finished {
+		return
+	}
+	now := time.Now()
+	trace.record_stage(now)
+	trace.stage, trace.object, trace.role, trace.stageStarted = stage, object, role, now
+}
+
+func (trace *captureDiagnostics) set_root(root ObjectID, scope string) {
+	if trace == nil {
+		return
+	}
+	trace.mutex.Lock()
+	defer trace.mutex.Unlock()
+	if !trace.finished {
+		trace.root, trace.rootScope = root, scope
+	}
+}
+
+func (trace *captureDiagnostics) progress(role string, capturedNodes, pendingNodes, textBytes int) {
+	if trace == nil {
+		return
+	}
+	trace.mutex.Lock()
+	defer trace.mutex.Unlock()
+	if !trace.finished {
+		trace.role = role
+		trace.capturedNodes, trace.pendingNodes, trace.textBytes = capturedNodes, pendingNodes, textBytes
+	}
+}
+
+func (trace *captureDiagnostics) finish(err error) {
+	if trace == nil {
+		return
+	}
+	trace.mutex.Lock()
+	defer trace.mutex.Unlock()
+	if trace.finished {
+		return
+	}
+	now := time.Now()
+	trace.record_stage(now)
+	trace.finished = true
+	message := "flat review capture timing"
+	if trace.kind != "" {
+		message = trace.kind + " capture timing"
+	}
+	trace.logger.Debug(message, "duration", now.Sub(trace.started), "error", err,
+		"last_stage", trace.stage, "stage_duration", now.Sub(trace.stageStarted),
+		"bus", trace.object.BusName, "object_path", trace.object.Path, "role", trace.role,
+		"root_bus", trace.root.BusName, "root_path", trace.root.Path, "root_scope", trace.rootScope,
+		"captured_nodes", trace.capturedNodes, "pending_nodes", trace.pendingNodes, "text_bytes", trace.textBytes,
+		"text_issues", trace.textIssues,
+		"stages", trace.timings)
+}