perf(api): report per-phase Server-Timing for the Mine inbox snapshot

Adds closed, content-free Server-Timing phases to GET
/api/companies/:companyId/inbox/mine (access, issues, parents, failures,
failure_context, and each svc.list lookup under issues_*), so the slow
phase is visible in DevTools without telemetry or spans.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
This commit is contained in:
DottaandClaude Opus 5.5 committed 2026-11-09 17:18:25 -06:00
1 parent 09241442ea
commit 18c3f4ef7b
5 files changed
+89 -26

No files matched your search

@@ -105,6 +105,16 @@ describeEmbeddedPostgres("Mine inbox snapshot routes", () => {
expect(snapshot.contextIssues.find(row => row.id === resolvedTask.id)?.interruption).toMatchObject({ state: "resolved", canRetry: false });
expect(snapshot.failureRuns.map(run => run.agentId)).not.toContain(supersededAgent.id);
expect(snapshotResponse.headers["cache-control"]).toBe("private, no-store");
const timingPhases = new Map((snapshotResponse.headers["server-timing"] ?? "").split(", ").map((entry: string) => {
const match = /^([a-z_]+);dur=(\d+\.\d)$/.exec(entry);
expect(match, entry).not.toBeNull();
return [match![1]!, Number(match![2])] as const;
}));
for (const phase of [
"paperclip_inbox", "inbox_access", "inbox_issues", "inbox_parents", "inbox_failures", "inbox_failure_context",
"inbox_issues_query", "inbox_issues_labels", "inbox_issues_user_stats", "inbox_issues_read_stats",
"inbox_issues_last_activity", "inbox_issues_archives", "inbox_issues_live_descendants",
]) expect(timingPhases.get(phase), phase).toBeGreaterThanOrEqual(0);
expect(snapshot).not.toHaveProperty("failureError");
expect(snapshot).not.toHaveProperty("contextError");
});
+14 -9
View File
@@ -41,6 +41,7 @@ import { setIssueTitle } from "../services/issue-title.js";
import { setIssueTitleSchema } from "@paperclipai/shared";
import { resolveConfirmationFromComment } from "../services/confirmation-comment-resolution.js";
import { createIssueReadTiming } from "../services/issue-read-timing.js";
import { createInboxMineTiming } from "../services/inbox-mine-timing.js";
import { isNativeWorkspaceExportRepairCause } from "@paperclipai/shared";
import { resumeNativeWorkspaceAfterOwnerStop } from "../services/native-runtime/native-workspace-owner-recovery.js";
import { confirmNativeControllerStopped, NATIVE_CONTROLLER_HOST_UNVERIFIED } from "../services/native-runtime/native-controller-host-recovery.js";
@@ -226,6 +227,7 @@ import {
issueService,
type ActivityPublication,
type IssueFilters,
type IssueListOptions,
clampIssueListLimit,
documentService,
documentAnnotationService,
@@ -8706,7 +8708,7 @@ export function issueRoutes(
companyId: string,
listFilters: IssueFilters,
view: string | undefined,
options: { reportPagination?: boolean } = {},
options: { reportPagination?: boolean; listOptions?: IssueListOptions } = {},
): Promise<IssueListPreparedResponse> {
const compactView = view === "compact" || view === "index" || view === "rows";
const canReadCompanyScope = await actorCanReadCompanyScope(req, companyId);
@@ -8720,6 +8722,7 @@ export function issueRoutes(
const probedResult = await svc.list(
companyId,
pageLimit === null ? listFilters : { ...listFilters, limit: pageLimit + 1 },
options.listOptions,
);
const hasMore = pageLimit !== null && probedResult.length > pageLimit;
const rawResult = hasMore ? probedResult.slice(0, pageLimit!) : probedResult;
@@ -8816,6 +8819,7 @@ export function issueRoutes(
router.get("/companies/:companyId/inbox/mine", async (req, res) => {
const startedAt = Date.now();
const timing = createInboxMineTiming();
const companyId = req.params.companyId as string;
assertBoard(req);
assertCompanyAccess(req, companyId);
@@ -8825,15 +8829,15 @@ export function issueRoutes(
}
const userId = req.actor.userId;
if (!userId) throw new HttpError(401, "A signed-in board user is required");
const readCondition = await issueReadSqlCondition(db, req.actor);
const readCondition = await timing.time("access", () => issueReadSqlCondition(db, req.actor));
const listFilters: IssueFilters = {
readCondition, touchedByUserId: userId, inboxArchivedByUserId: userId,
status: INBOX_MINE_ISSUE_STATUS_FILTER, listProjection: "index",
sortField: "updated", sortDir: "desc", limit: 100,
includeRoutineExecutions: true, includeLiveDescendantSummary: true,
};
const readCompact = async (filters: IssueFilters, projection: "index" | "rows") => {
const prepared = await prepareIssueListForActor(req, companyId, filters, projection);
const readCompact = async (filters: IssueFilters, projection: "index" | "rows", listOptions?: IssueListOptions) => {
const prepared = await prepareIssueListForActor(req, companyId, filters, projection, { listOptions });
if (prepared.kind !== "compact") throw new Error("Expected compact inbox rows");
return prepared.body;
};
@@ -8843,17 +8847,17 @@ export function issueRoutes(
compute: async () => ({
kind: "inbox",
body: { userId, ...await readInboxMine({
loadIssues: () => readCompact(listFilters, "index"),
loadFailures: async () => {
loadIssues: () => timing.time("issues", () => readCompact(listFilters, "index", { timePhase: timing.listPhases })),
loadFailures: () => timing.time("failures", async () => {
const permission = await access.decide({ actor: req.actor, action: "company_scope:read", resource: { type: "company", companyId } });
if (!permission.allowed) throw new HttpError(403, "Run telemetry is outside this actor's authorization boundary");
const runs = latestFailedRunsByAgent(await heartbeat.list(companyId, undefined, 200, { summary: true }));
const decisions = await getHeartbeatRunReadDecisions(db, access, req.actor, runs);
return runRedactions.redactForRuns(companyId, runs.map((run, index) => decisions[index] ? run : redactHeartbeatRunListRow(run)), getActorInfo(req).actorId);
},
loadContext: (ids, projection) => readCompact({
}),
loadContext: (ids, projection) => timing.time(projection === "index" ? "parents" : "failure_context", () => readCompact({
readCondition, issueIds: ids, listProjection: projection, limit: 100, includeRoutineExecutions: true,
}, projection),
}, projection)),
sourceError: (error, source) => {
logger.warn({ err: error, companyId, source }, "inbox source read failed");
return {
@@ -8867,6 +8871,7 @@ export function issueRoutes(
});
res.setHeader("Cache-Control", "private, no-store");
res.setHeader("X-Paperclip-Request-Cache", coordinated.cacheStatus);
res.setHeader("Server-Timing", timing.header());
if (!coordinated.response) {
res.setHeader("Retry-After", String(coordinated.retryAfterSeconds ?? 1));
res.status(429).json({ error: "Too many concurrent issue-list requests for this actor/client", retryAfterSeconds: coordinated.retryAfterSeconds ?? 1 });
+32
View File
@@ -0,0 +1,32 @@
import type { IssueListPhase } from "./issues.js";
// Closed, content-free phase names for the Mine snapshot. This is a response
// header only (inspectable in DevTools); it emits no telemetry or spans.
export type InboxMinePhase =
| "access" | "issues" | "parents" | "failures" | "failure_context"
| `issues_${IssueListPhase}`;
export function createInboxMineTiming() {
const start = performance.now();
const durations = new Map<InboxMinePhase, number>();
const time = async <T>(phase: InboxMinePhase, read: () => Promise<T>): Promise<T> => {
const phaseStart = performance.now();
try {
return await read();
} finally {
// Batched reads (context loads in chunks) accumulate into one phase.
durations.set(phase, (durations.get(phase) ?? 0) + performance.now() - phaseStart);
}
};
return {
time,
/** Adapts the timer to the issue list's internal phases under an `issues_` prefix. */
listPhases: <T>(phase: IssueListPhase, read: () => Promise<T>) => time(`issues_${phase}`, read),
header() {
return [
`paperclip_inbox;dur=${(performance.now() - start).toFixed(1)}`,
...[...durations].map(([phase, duration]) => `inbox_${phase};dur=${duration.toFixed(1)}`),
].join(", ");
},
};
}
+1
View File
@@ -40,6 +40,7 @@ export {
ISSUE_LIST_MAX_LIMIT,
issueService,
type IssueFilters,
type IssueListOptions,
} from "./issues.js";
export { issueThreadInteractionService } from "./issue-thread-interactions.js";
export { githubConnectionEventService, type GitHubConnectionEventPollResult } from "./github-connection-events.js";
+32 -17
View File
@@ -1865,6 +1865,18 @@ export function parseStatusFilter(
.filter(Boolean);
}
/** Closed, content-free phases of `issueService.list`, for response timing headers. */
export type IssueListPhase =
| "query" | "labels" | "active_runs" | "user_stats" | "read_stats" | "last_activity"
| "archives" | "blocked_by" | "live_descendants" | "attention";
export interface IssueListOptions {
/** Wraps each internal read so callers can report per-phase timing. */
timePhase?: <T>(phase: IssueListPhase, read: () => Promise<T>) => Promise<T>;
}
const untimedIssueListPhase = <T>(_phase: IssueListPhase, read: () => Promise<T>) => read();
export interface IssueFilters {
attention?: "blocked";
status?: string | readonly string[];
@@ -8272,7 +8284,8 @@ export function issueService(db: Db) {
)).then((unread) => unread.map((row) => row.id));
},
list: async (companyId: string, filters?: IssueFilters) => {
list: async (companyId: string, filters?: IssueFilters, options?: IssueListOptions) => {
const timePhase = options?.timePhase ?? untimedIssueListPhase;
if (filters?.sortField === "id" && filters.attention) {
throw unprocessable("ID ordering is not supported for blocked attention lists");
}
@@ -8499,15 +8512,15 @@ export function issueService(db: Db) {
: limit === undefined
? baseQuery
: baseQuery.limit(limit);
const rows = (await pageQuery).map((row) => ({
const rows = (await timePhase("query", async () => pageQuery)).map((row) => ({
...row,
description: decodeDatabaseTextPreview(
row.description,
ISSUE_LIST_DESCRIPTION_MAX_CHARS,
),
}));
const withLabels = await withIssueLabels(db, rows);
const runMap = filters?.listProjection === "index" ? new Map() : await activeRunMapForIssues(db, withLabels);
const withLabels = await timePhase("labels", () => withIssueLabels(db, rows));
const runMap = filters?.listProjection === "index" ? new Map() : await timePhase("active_runs", () => activeRunMapForIssues(db, withLabels));
const withRuns = withActiveRuns(withLabels, runMap);
if (withRuns.length === 0) {
return withRuns;
@@ -8523,20 +8536,20 @@ export function issueService(db: Db) {
liveDescendantCountByIssueId,
] = await Promise.all([
contextUserId
? userCommentStatsForIssues(db, companyId, contextUserId, issueIds)
? timePhase("user_stats", () => userCommentStatsForIssues(db, companyId, contextUserId, issueIds))
: Promise.resolve([]),
contextUserId
? userReadStatsForIssues(db, companyId, contextUserId, issueIds)
? timePhase("read_stats", () => userReadStatsForIssues(db, companyId, contextUserId, issueIds))
: Promise.resolve([]),
lastActivityStatsForIssues(db, companyId, issueIds),
timePhase("last_activity", () => lastActivityStatsForIssues(db, companyId, issueIds)),
contextUserId
? inboxArchiveRowsForIssues(db, companyId, contextUserId, issueIds)
? timePhase("archives", () => inboxArchiveRowsForIssues(db, companyId, contextUserId, issueIds))
: Promise.resolve([]),
includeBlockedBy
? blockedByMapForIssues(db, companyId, issueIds)
? timePhase("blocked_by", () => blockedByMapForIssues(db, companyId, issueIds))
: Promise.resolve(new Map<string, IssueRelationIssueSummary[]>()),
includeLiveDescendantSummary
? liveDescendantCountMapForIssues(db, companyId, issueIds)
? timePhase("live_descendants", () => liveDescendantCountMapForIssues(db, companyId, issueIds))
: Promise.resolve(new Map<string, number>()),
]);
const statsByIssueId = new Map(
@@ -8552,13 +8565,15 @@ export function issueService(db: Db) {
blockerAttentionByIssueId,
reviewAttentionByIssueId,
blockedInboxAttentionByIssueId,
] = await Promise.all([
filters?.listProjection === "index" ? Promise.resolve(new Map<string, IssueBlockerAttention>()) : listIssueBlockerAttentionMap(db, companyId, withRuns),
filters?.listProjection === "index" ? Promise.resolve(new Map<string, IssueReviewAttention>()) : listIssueReviewAttentionMap(db, companyId, withRuns),
includeBlockedInboxAttention
? listIssueBlockedInboxAttentionMap(db, companyId, withRuns)
: Promise.resolve(new Map<string, IssueBlockedInboxAttention>()),
]);
] = filters?.listProjection === "index" && !includeBlockedInboxAttention
? [new Map<string, IssueBlockerAttention>(), new Map<string, IssueReviewAttention>(), new Map<string, IssueBlockedInboxAttention>()]
: await timePhase("attention", () => Promise.all([
filters?.listProjection === "index" ? Promise.resolve(new Map<string, IssueBlockerAttention>()) : listIssueBlockerAttentionMap(db, companyId, withRuns),
filters?.listProjection === "index" ? Promise.resolve(new Map<string, IssueReviewAttention>()) : listIssueReviewAttentionMap(db, companyId, withRuns),
includeBlockedInboxAttention
? listIssueBlockedInboxAttentionMap(db, companyId, withRuns)
: Promise.resolve(new Map<string, IssueBlockedInboxAttention>()),
]));
if (!contextUserId) {
return withRuns.map((row) => {