chore(perf): add AO_PERF-gated instrumentation for dashboard load
Temporary tracing added to diagnose 15-20s dashboard terminal load on Mac and Windows. Gated on AO_PERF=1 (server) and NEXT_PUBLIC_AO_PERF=1 (client) so production paths stay untouched. To be removed once the bottleneck is fixed. Wrap points: - core/perf.ts: perfMark / perfTime helpers + perfCid - web /api/sessions/[id]: per-stage timings (getServices, sm.get, audit, enrichMetadata, total) - core/session-manager: runtime.isAlive, agent.getActivityState, agent.getSessionInfo, ensureHandleAndEnrich - agent-codex: findCodexSessionFile (scanned/opened/matched counts) + cache hit marker - runtime-process/pty-client: connect outcome + isAlive (split connectMs vs statusMs) - web/lib/serialize: enrich legs (agentSummary vs issueTitle) timed independently while still running concurrently - web/sessions/[id]/page.tsx: client.fetch.start/end with cid header forwarded for end-to-end correlation - web/MuxProvider: ws.open + ws.firstByte per terminal
This commit is contained in:
parent
d16a4f3e63
commit
b3f522f9d9
|
|
@ -8,6 +8,9 @@
|
|||
// Types — everything plugins and consumers need
|
||||
export * from "./types.js";
|
||||
|
||||
// Perf tracing — temporary, AO_PERF=1 gated
|
||||
export { PERF_ON, perfMark, perfTime, perfTimeSync, perfCid } from "./perf.js";
|
||||
|
||||
// Config — YAML loader + validation
|
||||
export {
|
||||
loadConfig,
|
||||
|
|
|
|||
|
|
@ -0,0 +1,56 @@
|
|||
/**
|
||||
* Lightweight perf tracing, gated on AO_PERF=1.
|
||||
*
|
||||
* Temporary diagnostic — added to trace dashboard load slowness across
|
||||
* client → API → session-manager → plugins. Remove once the bottleneck is
|
||||
* fixed. Greppable by `[ao-perf]`.
|
||||
*/
|
||||
|
||||
export const PERF_ON = process.env.AO_PERF === "1";
|
||||
|
||||
export function perfMark(
|
||||
cid: string,
|
||||
stage: string,
|
||||
ms: number,
|
||||
extra?: Record<string, unknown>,
|
||||
): void {
|
||||
if (!PERF_ON) return;
|
||||
const tail = extra ? " " + JSON.stringify(extra) : "";
|
||||
// eslint-disable-next-line no-console
|
||||
console.log(`[ao-perf] cid=${cid} ${stage}=${ms}ms${tail}`);
|
||||
}
|
||||
|
||||
export async function perfTime<T>(
|
||||
cid: string,
|
||||
stage: string,
|
||||
fn: () => Promise<T>,
|
||||
extra?: Record<string, unknown>,
|
||||
): Promise<T> {
|
||||
if (!PERF_ON) return fn();
|
||||
const t = Date.now();
|
||||
try {
|
||||
return await fn();
|
||||
} finally {
|
||||
perfMark(cid, stage, Date.now() - t, extra);
|
||||
}
|
||||
}
|
||||
|
||||
export function perfTimeSync<T>(
|
||||
cid: string,
|
||||
stage: string,
|
||||
fn: () => T,
|
||||
extra?: Record<string, unknown>,
|
||||
): T {
|
||||
if (!PERF_ON) return fn();
|
||||
const t = Date.now();
|
||||
try {
|
||||
return fn();
|
||||
} finally {
|
||||
perfMark(cid, stage, Date.now() - t, extra);
|
||||
}
|
||||
}
|
||||
|
||||
/** Random 6-char correlation id, used when caller didn't supply one. */
|
||||
export function perfCid(): string {
|
||||
return Math.random().toString(36).slice(2, 8);
|
||||
}
|
||||
|
|
@ -50,6 +50,7 @@ import {
|
|||
type CanonicalSessionLifecycle,
|
||||
PR_STATE,
|
||||
} from "./types.js";
|
||||
import { perfTime } from "./perf.js";
|
||||
import {
|
||||
readMetadataRaw,
|
||||
writeMetadata,
|
||||
|
|
@ -1025,7 +1026,10 @@ export function createSessionManager(deps: SessionManagerDeps): OpenCodeSessionM
|
|||
session.status !== "spawning"
|
||||
) {
|
||||
try {
|
||||
const alive = await plugins.runtime.isAlive(session.runtimeHandle);
|
||||
const alive = await perfTime(`sm:${session.id}`, "sm.runtime.isAlive", () =>
|
||||
plugins.runtime!.isAlive(session.runtimeHandle!),
|
||||
{ runtime: session.runtimeHandle.runtimeName },
|
||||
);
|
||||
if (!alive) {
|
||||
session.lifecycle.runtime.state = "missing";
|
||||
session.lifecycle.runtime.reason =
|
||||
|
|
@ -1068,7 +1072,10 @@ export function createSessionManager(deps: SessionManagerDeps): OpenCodeSessionM
|
|||
session.activitySignal = createActivitySignal("unavailable");
|
||||
if (plugins.agent) {
|
||||
try {
|
||||
const detected = await plugins.agent.getActivityState(session, config.readyThresholdMs);
|
||||
const detected = await perfTime(`sm:${session.id}`, "sm.agent.getActivityState", () =>
|
||||
plugins.agent!.getActivityState(session, config.readyThresholdMs),
|
||||
{ agent: session.agent ?? "unknown" },
|
||||
);
|
||||
if (detected !== null) {
|
||||
session.activitySignal = classifyActivitySignal(detected, "native");
|
||||
session.activity = detected.state;
|
||||
|
|
@ -1088,7 +1095,10 @@ export function createSessionManager(deps: SessionManagerDeps): OpenCodeSessionM
|
|||
// Enrich with live agent session info (summary, cost).
|
||||
let info: Awaited<ReturnType<Agent["getSessionInfo"]>>;
|
||||
try {
|
||||
info = await plugins.agent.getSessionInfo(session);
|
||||
info = await perfTime(`sm:${session.id}`, "sm.agent.getSessionInfo", () =>
|
||||
plugins.agent!.getSessionInfo(session),
|
||||
{ agent: session.agent ?? "unknown" },
|
||||
);
|
||||
} catch {
|
||||
// Can't get session info — keep existing values
|
||||
info = null;
|
||||
|
|
@ -2063,13 +2073,15 @@ export function createSessionManager(deps: SessionManagerDeps): OpenCodeSessionM
|
|||
const selection = resolveSelectionForSession(project, sessionId, repaired.raw);
|
||||
const effectiveAgentName = selection.agentName;
|
||||
const plugins = resolvePlugins(project, effectiveAgentName);
|
||||
await ensureHandleAndEnrich(
|
||||
session,
|
||||
sessionId,
|
||||
sessionsDir,
|
||||
project,
|
||||
effectiveAgentName,
|
||||
plugins,
|
||||
await perfTime(`sm:${sessionId}`, "sm.ensureHandleAndEnrich", () =>
|
||||
ensureHandleAndEnrich(
|
||||
session,
|
||||
sessionId,
|
||||
sessionsDir,
|
||||
project,
|
||||
effectiveAgentName,
|
||||
plugins,
|
||||
),
|
||||
);
|
||||
|
||||
return session;
|
||||
|
|
|
|||
|
|
@ -9,6 +9,7 @@ import {
|
|||
getActivityFallbackState,
|
||||
recordTerminalActivity,
|
||||
isWindows,
|
||||
perfMark,
|
||||
type Agent,
|
||||
type AgentSessionInfo,
|
||||
type AgentLaunchConfig,
|
||||
|
|
@ -228,14 +229,26 @@ async function sessionFileMatchesCwd(filePath: string, workspacePath: string): P
|
|||
* Returns the path to the most recently modified matching file, or null.
|
||||
*/
|
||||
async function findCodexSessionFile(workspacePath: string): Promise<string | null> {
|
||||
const t0 = Date.now();
|
||||
const jsonlFiles = await collectJsonlFiles(CODEX_SESSIONS_DIR);
|
||||
if (jsonlFiles.length === 0) return null;
|
||||
const collectMs = Date.now() - t0;
|
||||
if (jsonlFiles.length === 0) {
|
||||
perfMark(`codex:${workspacePath}`, "codex.findSessionFile", Date.now() - t0, {
|
||||
scanned: 0,
|
||||
matched: 0,
|
||||
});
|
||||
return null;
|
||||
}
|
||||
|
||||
let bestMatch: { path: string; mtime: number } | null = null;
|
||||
let openedFiles = 0;
|
||||
let matchedFiles = 0;
|
||||
|
||||
for (const filePath of jsonlFiles) {
|
||||
openedFiles++;
|
||||
const matches = await sessionFileMatchesCwd(filePath, workspacePath);
|
||||
if (matches) {
|
||||
matchedFiles++;
|
||||
try {
|
||||
const s = await stat(filePath);
|
||||
if (!bestMatch || s.mtimeMs > bestMatch.mtime) {
|
||||
|
|
@ -247,6 +260,13 @@ async function findCodexSessionFile(workspacePath: string): Promise<string | nul
|
|||
}
|
||||
}
|
||||
|
||||
perfMark(`codex:${workspacePath}`, "codex.findSessionFile", Date.now() - t0, {
|
||||
scanned: jsonlFiles.length,
|
||||
opened: openedFiles,
|
||||
matched: matchedFiles,
|
||||
collectMs,
|
||||
found: bestMatch ? 1 : 0,
|
||||
});
|
||||
return bestMatch?.path ?? null;
|
||||
}
|
||||
|
||||
|
|
@ -497,6 +517,7 @@ const sessionFileCache = new Map<string, { path: string | null; expiry: number }
|
|||
async function findCodexSessionFileCached(workspacePath: string): Promise<string | null> {
|
||||
const cached = sessionFileCache.get(workspacePath);
|
||||
if (cached && Date.now() < cached.expiry) {
|
||||
perfMark(`codex:${workspacePath}`, "codex.findSessionFile.cache", 0, { hit: 1 });
|
||||
return cached.path;
|
||||
}
|
||||
const result = await findCodexSessionFile(workspacePath);
|
||||
|
|
|
|||
|
|
@ -9,6 +9,7 @@
|
|||
*/
|
||||
|
||||
import { connect, type Socket } from "node:net";
|
||||
import { perfMark } from "@aoagents/ao-core";
|
||||
import {
|
||||
MSG_TERMINAL_INPUT,
|
||||
MSG_TERMINAL_DATA,
|
||||
|
|
@ -60,6 +61,7 @@ export function getPipePath(sessionId: string): string {
|
|||
export function connectPtyHost(pipePath: string, timeoutMs = 3000): Promise<Socket> {
|
||||
return new Promise<Socket>((resolve, reject) => {
|
||||
let settled = false;
|
||||
const t0 = Date.now();
|
||||
|
||||
const sock = connect(pipePath);
|
||||
|
||||
|
|
@ -67,6 +69,7 @@ export function connectPtyHost(pipePath: string, timeoutMs = 3000): Promise<Sock
|
|||
if (settled) return;
|
||||
settled = true;
|
||||
sock.destroy();
|
||||
perfMark(`pty:${pipePath}`, "pty.connect", Date.now() - t0, { outcome: "timeout" });
|
||||
reject(new Error(`Timed out connecting to pty-host at ${pipePath} (${timeoutMs}ms)`));
|
||||
}, timeoutMs);
|
||||
|
||||
|
|
@ -74,6 +77,7 @@ export function connectPtyHost(pipePath: string, timeoutMs = 3000): Promise<Sock
|
|||
if (settled) return;
|
||||
settled = true;
|
||||
clearTimeout(timer);
|
||||
perfMark(`pty:${pipePath}`, "pty.connect", Date.now() - t0, { outcome: "ok" });
|
||||
resolve(sock);
|
||||
});
|
||||
|
||||
|
|
@ -81,6 +85,7 @@ export function connectPtyHost(pipePath: string, timeoutMs = 3000): Promise<Sock
|
|||
if (settled) return;
|
||||
settled = true;
|
||||
clearTimeout(timer);
|
||||
perfMark(`pty:${pipePath}`, "pty.connect", Date.now() - t0, { outcome: "error" });
|
||||
reject(err);
|
||||
});
|
||||
});
|
||||
|
|
@ -218,12 +223,15 @@ export async function ptyHostGetOutput(pipePath: string, lines = 50): Promise<st
|
|||
* Returns false if the pipe is unreachable (host has exited).
|
||||
*/
|
||||
export async function ptyHostIsAlive(pipePath: string): Promise<boolean> {
|
||||
const t0 = Date.now();
|
||||
let sock: Socket;
|
||||
try {
|
||||
sock = await connectPtyHost(pipePath, 2000);
|
||||
} catch {
|
||||
perfMark(`pty:${pipePath}`, "pty.isAlive", Date.now() - t0, { outcome: "connect_fail" });
|
||||
return false;
|
||||
}
|
||||
const tConnected = Date.now();
|
||||
|
||||
return new Promise<boolean>((resolve) => {
|
||||
let settled = false;
|
||||
|
|
@ -233,6 +241,11 @@ export async function ptyHostIsAlive(pipePath: string): Promise<boolean> {
|
|||
settled = true;
|
||||
clearTimeout(timer);
|
||||
sock.destroy();
|
||||
perfMark(`pty:${pipePath}`, "pty.isAlive", Date.now() - t0, {
|
||||
outcome: result ? "alive" : "dead",
|
||||
connectMs: tConnected - t0,
|
||||
statusMs: Date.now() - tConnected,
|
||||
});
|
||||
resolve(result);
|
||||
};
|
||||
|
||||
|
|
|
|||
|
|
@ -1,5 +1,10 @@
|
|||
import { type NextRequest } from "next/server";
|
||||
import { getProjectSessionsDir, readAgentReportAuditTrailAsync } from "@aoagents/ao-core";
|
||||
import {
|
||||
getProjectSessionsDir,
|
||||
readAgentReportAuditTrailAsync,
|
||||
perfMark,
|
||||
perfTime,
|
||||
} from "@aoagents/ao-core";
|
||||
import { getServices } from "@/lib/services";
|
||||
import {
|
||||
sessionToDashboard,
|
||||
|
|
@ -18,10 +23,11 @@ export async function GET(_request: NextRequest, { params }: { params: Promise<{
|
|||
const startedAt = Date.now();
|
||||
try {
|
||||
const { id } = await params;
|
||||
const { config, registry, sessionManager } = await getServices();
|
||||
const { config, registry, sessionManager } = await perfTime(correlationId, "server.getServices", () => getServices());
|
||||
|
||||
const coreSession = await sessionManager.get(id);
|
||||
const coreSession = await perfTime(correlationId, "server.sm.get", () => sessionManager.get(id), { id });
|
||||
if (!coreSession) {
|
||||
perfMark(correlationId, "server.total", Date.now() - startedAt, { outcome: "404" });
|
||||
return jsonWithCorrelation({ error: "Session not found" }, { status: 404 }, correlationId);
|
||||
}
|
||||
|
||||
|
|
@ -32,19 +38,22 @@ export async function GET(_request: NextRequest, { params }: { params: Promise<{
|
|||
const auditPromise = readAgentReportAuditTrailAsync(sessionsDir, coreSession.id).then((audit) => {
|
||||
dashboardSession.agentReportAudit = audit;
|
||||
});
|
||||
await settlesWithin(auditPromise, AGENT_REPORT_AUDIT_TIMEOUT_MS);
|
||||
await perfTime(correlationId, "server.audit", () => settlesWithin(auditPromise, AGENT_REPORT_AUDIT_TIMEOUT_MS));
|
||||
}
|
||||
|
||||
// Enrich metadata (issue labels, agent summaries, issue titles)
|
||||
await settlesWithin(
|
||||
enrichSessionsMetadata([coreSession], [dashboardSession], config, registry),
|
||||
METADATA_ENRICH_TIMEOUT_MS,
|
||||
await perfTime(correlationId, "server.enrichMetadata", () =>
|
||||
settlesWithin(
|
||||
enrichSessionsMetadata([coreSession], [dashboardSession], config, registry, correlationId),
|
||||
METADATA_ENRICH_TIMEOUT_MS,
|
||||
),
|
||||
);
|
||||
|
||||
// Enrich PR from session metadata (written by CLI lifecycle)
|
||||
if (coreSession.pr) {
|
||||
enrichSessionPR(dashboardSession);
|
||||
}
|
||||
perfMark(correlationId, "server.total", Date.now() - startedAt, { outcome: "200" });
|
||||
|
||||
recordApiObservation({
|
||||
config,
|
||||
|
|
|
|||
|
|
@ -493,10 +493,21 @@ export default function SessionPage() {
|
|||
|
||||
// Fetch session data (memoized to avoid recreating on every render)
|
||||
const fetchSession = useCallback(async () => {
|
||||
if (fetchingSessionRef.current) return;
|
||||
if (fetchingSessionRef.current) {
|
||||
// eslint-disable-next-line no-console
|
||||
if (process.env.NEXT_PUBLIC_AO_PERF === "1") console.log(`[ao-perf] cid=client client.fetch.skip-inflight id=${id}`);
|
||||
return;
|
||||
}
|
||||
fetchingSessionRef.current = true;
|
||||
const controller = new AbortController();
|
||||
sessionFetchControllerRef.current = controller;
|
||||
const perfOn = process.env.NEXT_PUBLIC_AO_PERF === "1";
|
||||
const cid = Math.random().toString(36).slice(2, 8);
|
||||
const t0 = Date.now();
|
||||
if (perfOn) {
|
||||
// eslint-disable-next-line no-console
|
||||
console.log(`[ao-perf] cid=${cid} client.fetch.start id=${id}`);
|
||||
}
|
||||
try {
|
||||
const data = await fetchJsonWithTimeout<DashboardSession | { error: string }>(
|
||||
`/api/sessions/${encodeURIComponent(id)}`,
|
||||
|
|
@ -504,13 +515,23 @@ export default function SessionPage() {
|
|||
signal: controller.signal,
|
||||
timeoutMs: SESSION_FETCH_TIMEOUT_MS,
|
||||
timeoutMessage: `Session request timed out after ${SESSION_FETCH_TIMEOUT_MS}ms`,
|
||||
headers: { "x-correlation-id": cid },
|
||||
},
|
||||
);
|
||||
if (perfOn) {
|
||||
// eslint-disable-next-line no-console
|
||||
console.log(`[ao-perf] cid=${cid} client.fetch.end=${Date.now() - t0}ms outcome=ok`);
|
||||
}
|
||||
setSession(data as DashboardSession);
|
||||
setRouteError(null);
|
||||
setSessionMissing(false);
|
||||
hasLoadedSessionRef.current = true;
|
||||
} catch (err) {
|
||||
if (perfOn) {
|
||||
const reason = err instanceof Error ? err.message : "unknown";
|
||||
// eslint-disable-next-line no-console
|
||||
console.log(`[ao-perf] cid=${cid} client.fetch.end=${Date.now() - t0}ms outcome=error reason=${JSON.stringify(reason)}`);
|
||||
}
|
||||
if (pageUnloadingRef.current || controller.signal.aborted || isAbortLikeError(err)) {
|
||||
return;
|
||||
}
|
||||
|
|
|
|||
|
|
@ -17,6 +17,7 @@ import {
|
|||
type ProjectConfig,
|
||||
type OrchestratorConfig,
|
||||
type PluginRegistry,
|
||||
perfMark,
|
||||
} from "@aoagents/ao-core";
|
||||
import {
|
||||
type DashboardSession,
|
||||
|
|
@ -565,7 +566,9 @@ export async function enrichSessionsMetadata(
|
|||
dashboardSessions: DashboardSession[],
|
||||
config: OrchestratorConfig,
|
||||
registry: PluginRegistry,
|
||||
cid?: string,
|
||||
): Promise<void> {
|
||||
const traceCid = cid ?? "enrich";
|
||||
const { projects, summaryPromises } = prepareSessionMetadataEnrichment(
|
||||
coreSessions,
|
||||
dashboardSessions,
|
||||
|
|
@ -584,7 +587,20 @@ export async function enrichSessionsMetadata(
|
|||
return enrichSessionIssueTitle(dashboardSessions[i], tracker, project);
|
||||
});
|
||||
|
||||
await Promise.allSettled([...summaryPromises, ...issueTitlePromises]);
|
||||
// Time each leg independently while still running them concurrently.
|
||||
const t0 = Date.now();
|
||||
const timed = <T>(label: string, ps: Promise<T>[]): Promise<PromiseSettledResult<T>[]> => {
|
||||
const start = Date.now();
|
||||
return Promise.allSettled(ps).then((r) => {
|
||||
perfMark(traceCid, label, Date.now() - start, { count: ps.length });
|
||||
return r;
|
||||
});
|
||||
};
|
||||
await Promise.all([
|
||||
timed("enrich.agentSummary", summaryPromises),
|
||||
timed("enrich.issueTitle", issueTitlePromises),
|
||||
]);
|
||||
perfMark(traceCid, "enrich.total", Date.now() - t0, { sessions: coreSessions.length });
|
||||
}
|
||||
|
||||
/** Compute dashboard stats from a list of sessions. */
|
||||
|
|
|
|||
|
|
@ -108,15 +108,22 @@ export function MuxProvider({ children }: { children: ReactNode }) {
|
|||
try {
|
||||
const url = buildMuxWsUrl(runtimeConfigRef.current);
|
||||
console.log("[MuxProvider] Connecting to", url);
|
||||
const perfOn = process.env.NEXT_PUBLIC_AO_PERF === "1";
|
||||
const wsT0 = Date.now();
|
||||
const ws = new WebSocket(url);
|
||||
// Assign immediately so cleanup can close it even during CONNECTING state
|
||||
wsRef.current = ws;
|
||||
const firstDataPerTerminal = new Set<string>();
|
||||
|
||||
ws.addEventListener("open", () => {
|
||||
if (isDestroyedRef.current) {
|
||||
ws.close();
|
||||
return;
|
||||
}
|
||||
if (perfOn) {
|
||||
// eslint-disable-next-line no-console
|
||||
console.log(`[ao-perf] cid=ws ws.open=${Date.now() - wsT0}ms`);
|
||||
}
|
||||
console.log("[MuxProvider] Connected");
|
||||
setStatus("connected");
|
||||
reconnectAttempt.current = 0;
|
||||
|
|
@ -148,6 +155,11 @@ export function MuxProvider({ children }: { children: ReactNode }) {
|
|||
if (msg.ch === "terminal") {
|
||||
const key = terminalKey(msg.id, "projectId" in msg ? msg.projectId : undefined);
|
||||
if (msg.type === "data") {
|
||||
if (perfOn && !firstDataPerTerminal.has(key)) {
|
||||
firstDataPerTerminal.add(key);
|
||||
// eslint-disable-next-line no-console
|
||||
console.log(`[ao-perf] cid=ws ws.firstByte=${Date.now() - wsT0}ms id=${msg.id}`);
|
||||
}
|
||||
// Push to subscribers
|
||||
const subs = subscribersRef.current.get(key);
|
||||
if (subs) {
|
||||
|
|
|
|||
Loading…
Reference in New Issue