// 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) }