mirror of
https://github.com/paperclipai/paperclip.git
synced 2026-11-11 05:11:49 +01:00
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:
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.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(snapshot.failureRuns.map(run => run.agentId)).not.toContain(supersededAgent.id);
|
||||||
expect(snapshotResponse.headers["cache-control"]).toBe("private, no-store");
|
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("failureError");
|
||||||
expect(snapshot).not.toHaveProperty("contextError");
|
expect(snapshot).not.toHaveProperty("contextError");
|
||||||
});
|
});
|
||||||
|
|||||||
@@ -41,6 +41,7 @@ import { setIssueTitle } from "../services/issue-title.js";
|
|||||||
import { setIssueTitleSchema } from "@paperclipai/shared";
|
import { setIssueTitleSchema } from "@paperclipai/shared";
|
||||||
import { resolveConfirmationFromComment } from "../services/confirmation-comment-resolution.js";
|
import { resolveConfirmationFromComment } from "../services/confirmation-comment-resolution.js";
|
||||||
import { createIssueReadTiming } from "../services/issue-read-timing.js";
|
import { createIssueReadTiming } from "../services/issue-read-timing.js";
|
||||||
|
import { createInboxMineTiming } from "../services/inbox-mine-timing.js";
|
||||||
import { isNativeWorkspaceExportRepairCause } from "@paperclipai/shared";
|
import { isNativeWorkspaceExportRepairCause } from "@paperclipai/shared";
|
||||||
import { resumeNativeWorkspaceAfterOwnerStop } from "../services/native-runtime/native-workspace-owner-recovery.js";
|
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";
|
import { confirmNativeControllerStopped, NATIVE_CONTROLLER_HOST_UNVERIFIED } from "../services/native-runtime/native-controller-host-recovery.js";
|
||||||
@@ -226,6 +227,7 @@ import {
|
|||||||
issueService,
|
issueService,
|
||||||
type ActivityPublication,
|
type ActivityPublication,
|
||||||
type IssueFilters,
|
type IssueFilters,
|
||||||
|
type IssueListOptions,
|
||||||
clampIssueListLimit,
|
clampIssueListLimit,
|
||||||
documentService,
|
documentService,
|
||||||
documentAnnotationService,
|
documentAnnotationService,
|
||||||
@@ -8706,7 +8708,7 @@ export function issueRoutes(
|
|||||||
companyId: string,
|
companyId: string,
|
||||||
listFilters: IssueFilters,
|
listFilters: IssueFilters,
|
||||||
view: string | undefined,
|
view: string | undefined,
|
||||||
options: { reportPagination?: boolean } = {},
|
options: { reportPagination?: boolean; listOptions?: IssueListOptions } = {},
|
||||||
): Promise<IssueListPreparedResponse> {
|
): Promise<IssueListPreparedResponse> {
|
||||||
const compactView = view === "compact" || view === "index" || view === "rows";
|
const compactView = view === "compact" || view === "index" || view === "rows";
|
||||||
const canReadCompanyScope = await actorCanReadCompanyScope(req, companyId);
|
const canReadCompanyScope = await actorCanReadCompanyScope(req, companyId);
|
||||||
@@ -8720,6 +8722,7 @@ export function issueRoutes(
|
|||||||
const probedResult = await svc.list(
|
const probedResult = await svc.list(
|
||||||
companyId,
|
companyId,
|
||||||
pageLimit === null ? listFilters : { ...listFilters, limit: pageLimit + 1 },
|
pageLimit === null ? listFilters : { ...listFilters, limit: pageLimit + 1 },
|
||||||
|
options.listOptions,
|
||||||
);
|
);
|
||||||
const hasMore = pageLimit !== null && probedResult.length > pageLimit;
|
const hasMore = pageLimit !== null && probedResult.length > pageLimit;
|
||||||
const rawResult = hasMore ? probedResult.slice(0, pageLimit!) : probedResult;
|
const rawResult = hasMore ? probedResult.slice(0, pageLimit!) : probedResult;
|
||||||
@@ -8816,6 +8819,7 @@ export function issueRoutes(
|
|||||||
|
|
||||||
router.get("/companies/:companyId/inbox/mine", async (req, res) => {
|
router.get("/companies/:companyId/inbox/mine", async (req, res) => {
|
||||||
const startedAt = Date.now();
|
const startedAt = Date.now();
|
||||||
|
const timing = createInboxMineTiming();
|
||||||
const companyId = req.params.companyId as string;
|
const companyId = req.params.companyId as string;
|
||||||
assertBoard(req);
|
assertBoard(req);
|
||||||
assertCompanyAccess(req, companyId);
|
assertCompanyAccess(req, companyId);
|
||||||
@@ -8825,15 +8829,15 @@ export function issueRoutes(
|
|||||||
}
|
}
|
||||||
const userId = req.actor.userId;
|
const userId = req.actor.userId;
|
||||||
if (!userId) throw new HttpError(401, "A signed-in board user is required");
|
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 = {
|
const listFilters: IssueFilters = {
|
||||||
readCondition, touchedByUserId: userId, inboxArchivedByUserId: userId,
|
readCondition, touchedByUserId: userId, inboxArchivedByUserId: userId,
|
||||||
status: INBOX_MINE_ISSUE_STATUS_FILTER, listProjection: "index",
|
status: INBOX_MINE_ISSUE_STATUS_FILTER, listProjection: "index",
|
||||||
sortField: "updated", sortDir: "desc", limit: 100,
|
sortField: "updated", sortDir: "desc", limit: 100,
|
||||||
includeRoutineExecutions: true, includeLiveDescendantSummary: true,
|
includeRoutineExecutions: true, includeLiveDescendantSummary: true,
|
||||||
};
|
};
|
||||||
const readCompact = async (filters: IssueFilters, projection: "index" | "rows") => {
|
const readCompact = async (filters: IssueFilters, projection: "index" | "rows", listOptions?: IssueListOptions) => {
|
||||||
const prepared = await prepareIssueListForActor(req, companyId, filters, projection);
|
const prepared = await prepareIssueListForActor(req, companyId, filters, projection, { listOptions });
|
||||||
if (prepared.kind !== "compact") throw new Error("Expected compact inbox rows");
|
if (prepared.kind !== "compact") throw new Error("Expected compact inbox rows");
|
||||||
return prepared.body;
|
return prepared.body;
|
||||||
};
|
};
|
||||||
@@ -8843,17 +8847,17 @@ export function issueRoutes(
|
|||||||
compute: async () => ({
|
compute: async () => ({
|
||||||
kind: "inbox",
|
kind: "inbox",
|
||||||
body: { userId, ...await readInboxMine({
|
body: { userId, ...await readInboxMine({
|
||||||
loadIssues: () => readCompact(listFilters, "index"),
|
loadIssues: () => timing.time("issues", () => readCompact(listFilters, "index", { timePhase: timing.listPhases })),
|
||||||
loadFailures: async () => {
|
loadFailures: () => timing.time("failures", async () => {
|
||||||
const permission = await access.decide({ actor: req.actor, action: "company_scope:read", resource: { type: "company", companyId } });
|
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");
|
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 runs = latestFailedRunsByAgent(await heartbeat.list(companyId, undefined, 200, { summary: true }));
|
||||||
const decisions = await getHeartbeatRunReadDecisions(db, access, req.actor, runs);
|
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);
|
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,
|
readCondition, issueIds: ids, listProjection: projection, limit: 100, includeRoutineExecutions: true,
|
||||||
}, projection),
|
}, projection)),
|
||||||
sourceError: (error, source) => {
|
sourceError: (error, source) => {
|
||||||
logger.warn({ err: error, companyId, source }, "inbox source read failed");
|
logger.warn({ err: error, companyId, source }, "inbox source read failed");
|
||||||
return {
|
return {
|
||||||
@@ -8867,6 +8871,7 @@ export function issueRoutes(
|
|||||||
});
|
});
|
||||||
res.setHeader("Cache-Control", "private, no-store");
|
res.setHeader("Cache-Control", "private, no-store");
|
||||||
res.setHeader("X-Paperclip-Request-Cache", coordinated.cacheStatus);
|
res.setHeader("X-Paperclip-Request-Cache", coordinated.cacheStatus);
|
||||||
|
res.setHeader("Server-Timing", timing.header());
|
||||||
if (!coordinated.response) {
|
if (!coordinated.response) {
|
||||||
res.setHeader("Retry-After", String(coordinated.retryAfterSeconds ?? 1));
|
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 });
|
res.status(429).json({ error: "Too many concurrent issue-list requests for this actor/client", retryAfterSeconds: coordinated.retryAfterSeconds ?? 1 });
|
||||||
|
|||||||
@@ -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(", ");
|
||||||
|
},
|
||||||
|
};
|
||||||
|
}
|
||||||
@@ -40,6 +40,7 @@ export {
|
|||||||
ISSUE_LIST_MAX_LIMIT,
|
ISSUE_LIST_MAX_LIMIT,
|
||||||
issueService,
|
issueService,
|
||||||
type IssueFilters,
|
type IssueFilters,
|
||||||
|
type IssueListOptions,
|
||||||
} from "./issues.js";
|
} from "./issues.js";
|
||||||
export { issueThreadInteractionService } from "./issue-thread-interactions.js";
|
export { issueThreadInteractionService } from "./issue-thread-interactions.js";
|
||||||
export { githubConnectionEventService, type GitHubConnectionEventPollResult } from "./github-connection-events.js";
|
export { githubConnectionEventService, type GitHubConnectionEventPollResult } from "./github-connection-events.js";
|
||||||
|
|||||||
@@ -1865,6 +1865,18 @@ export function parseStatusFilter(
|
|||||||
.filter(Boolean);
|
.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 {
|
export interface IssueFilters {
|
||||||
attention?: "blocked";
|
attention?: "blocked";
|
||||||
status?: string | readonly string[];
|
status?: string | readonly string[];
|
||||||
@@ -8272,7 +8284,8 @@ export function issueService(db: Db) {
|
|||||||
)).then((unread) => unread.map((row) => row.id));
|
)).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) {
|
if (filters?.sortField === "id" && filters.attention) {
|
||||||
throw unprocessable("ID ordering is not supported for blocked attention lists");
|
throw unprocessable("ID ordering is not supported for blocked attention lists");
|
||||||
}
|
}
|
||||||
@@ -8499,15 +8512,15 @@ export function issueService(db: Db) {
|
|||||||
: limit === undefined
|
: limit === undefined
|
||||||
? baseQuery
|
? baseQuery
|
||||||
: baseQuery.limit(limit);
|
: baseQuery.limit(limit);
|
||||||
const rows = (await pageQuery).map((row) => ({
|
const rows = (await timePhase("query", async () => pageQuery)).map((row) => ({
|
||||||
...row,
|
...row,
|
||||||
description: decodeDatabaseTextPreview(
|
description: decodeDatabaseTextPreview(
|
||||||
row.description,
|
row.description,
|
||||||
ISSUE_LIST_DESCRIPTION_MAX_CHARS,
|
ISSUE_LIST_DESCRIPTION_MAX_CHARS,
|
||||||
),
|
),
|
||||||
}));
|
}));
|
||||||
const withLabels = await withIssueLabels(db, rows);
|
const withLabels = await timePhase("labels", () => withIssueLabels(db, rows));
|
||||||
const runMap = filters?.listProjection === "index" ? new Map() : await activeRunMapForIssues(db, withLabels);
|
const runMap = filters?.listProjection === "index" ? new Map() : await timePhase("active_runs", () => activeRunMapForIssues(db, withLabels));
|
||||||
const withRuns = withActiveRuns(withLabels, runMap);
|
const withRuns = withActiveRuns(withLabels, runMap);
|
||||||
if (withRuns.length === 0) {
|
if (withRuns.length === 0) {
|
||||||
return withRuns;
|
return withRuns;
|
||||||
@@ -8523,20 +8536,20 @@ export function issueService(db: Db) {
|
|||||||
liveDescendantCountByIssueId,
|
liveDescendantCountByIssueId,
|
||||||
] = await Promise.all([
|
] = await Promise.all([
|
||||||
contextUserId
|
contextUserId
|
||||||
? userCommentStatsForIssues(db, companyId, contextUserId, issueIds)
|
? timePhase("user_stats", () => userCommentStatsForIssues(db, companyId, contextUserId, issueIds))
|
||||||
: Promise.resolve([]),
|
: Promise.resolve([]),
|
||||||
contextUserId
|
contextUserId
|
||||||
? userReadStatsForIssues(db, companyId, contextUserId, issueIds)
|
? timePhase("read_stats", () => userReadStatsForIssues(db, companyId, contextUserId, issueIds))
|
||||||
: Promise.resolve([]),
|
: Promise.resolve([]),
|
||||||
lastActivityStatsForIssues(db, companyId, issueIds),
|
timePhase("last_activity", () => lastActivityStatsForIssues(db, companyId, issueIds)),
|
||||||
contextUserId
|
contextUserId
|
||||||
? inboxArchiveRowsForIssues(db, companyId, contextUserId, issueIds)
|
? timePhase("archives", () => inboxArchiveRowsForIssues(db, companyId, contextUserId, issueIds))
|
||||||
: Promise.resolve([]),
|
: Promise.resolve([]),
|
||||||
includeBlockedBy
|
includeBlockedBy
|
||||||
? blockedByMapForIssues(db, companyId, issueIds)
|
? timePhase("blocked_by", () => blockedByMapForIssues(db, companyId, issueIds))
|
||||||
: Promise.resolve(new Map<string, IssueRelationIssueSummary[]>()),
|
: Promise.resolve(new Map<string, IssueRelationIssueSummary[]>()),
|
||||||
includeLiveDescendantSummary
|
includeLiveDescendantSummary
|
||||||
? liveDescendantCountMapForIssues(db, companyId, issueIds)
|
? timePhase("live_descendants", () => liveDescendantCountMapForIssues(db, companyId, issueIds))
|
||||||
: Promise.resolve(new Map<string, number>()),
|
: Promise.resolve(new Map<string, number>()),
|
||||||
]);
|
]);
|
||||||
const statsByIssueId = new Map(
|
const statsByIssueId = new Map(
|
||||||
@@ -8552,13 +8565,15 @@ export function issueService(db: Db) {
|
|||||||
blockerAttentionByIssueId,
|
blockerAttentionByIssueId,
|
||||||
reviewAttentionByIssueId,
|
reviewAttentionByIssueId,
|
||||||
blockedInboxAttentionByIssueId,
|
blockedInboxAttentionByIssueId,
|
||||||
] = await Promise.all([
|
] = filters?.listProjection === "index" && !includeBlockedInboxAttention
|
||||||
filters?.listProjection === "index" ? Promise.resolve(new Map<string, IssueBlockerAttention>()) : listIssueBlockerAttentionMap(db, companyId, withRuns),
|
? [new Map<string, IssueBlockerAttention>(), new Map<string, IssueReviewAttention>(), new Map<string, IssueBlockedInboxAttention>()]
|
||||||
filters?.listProjection === "index" ? Promise.resolve(new Map<string, IssueReviewAttention>()) : listIssueReviewAttentionMap(db, companyId, withRuns),
|
: await timePhase("attention", () => Promise.all([
|
||||||
includeBlockedInboxAttention
|
filters?.listProjection === "index" ? Promise.resolve(new Map<string, IssueBlockerAttention>()) : listIssueBlockerAttentionMap(db, companyId, withRuns),
|
||||||
? listIssueBlockedInboxAttentionMap(db, companyId, withRuns)
|
filters?.listProjection === "index" ? Promise.resolve(new Map<string, IssueReviewAttention>()) : listIssueReviewAttentionMap(db, companyId, withRuns),
|
||||||
: Promise.resolve(new Map<string, IssueBlockedInboxAttention>()),
|
includeBlockedInboxAttention
|
||||||
]);
|
? listIssueBlockedInboxAttentionMap(db, companyId, withRuns)
|
||||||
|
: Promise.resolve(new Map<string, IssueBlockedInboxAttention>()),
|
||||||
|
]));
|
||||||
|
|
||||||
if (!contextUserId) {
|
if (!contextUserId) {
|
||||||
return withRuns.map((row) => {
|
return withRuns.map((row) => {
|
||||||
|
|||||||
Reference in new issue
Block a user