cthulhu/internal/atspi/capture_diagnostics.go

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