refactor(logging): finalize phase 6 error contract and pretty output
This commit is contained in:
parent
f78d066434
commit
5de9069c20
20 changed files with 239 additions and 55 deletions
|
|
@ -52,6 +52,11 @@ const eslintConfig = [
|
|||
message:
|
||||
"Server logger calls must pass context + message: logger.<level>({ event, ...ctx }, 'message').",
|
||||
},
|
||||
{
|
||||
selector: `${SERVER_LOGGER_CALL_SELECTOR}[arguments.0.type!='ObjectExpression']`,
|
||||
message:
|
||||
"Server logger first argument must be an object with an event field.",
|
||||
},
|
||||
{
|
||||
selector: `${SERVER_LOGGER_CALL_SELECTOR}[arguments.0.type='Literal']`,
|
||||
message:
|
||||
|
|
@ -67,11 +72,36 @@ const eslintConfig = [
|
|||
message:
|
||||
"Server logger context object must include an event field.",
|
||||
},
|
||||
{
|
||||
selector: `${SERVER_LOGGER_CALL_SELECTOR}[arguments.1.type!='Literal'][arguments.1.type!='TemplateLiteral']`,
|
||||
message:
|
||||
"Server logger second argument must be a message string (literal or template literal).",
|
||||
},
|
||||
{
|
||||
selector: `${STATIC_LOGGER_CALL_SELECTOR}[callee.property.name='error']${LOGGER_RECEIVER_SELECTOR}[arguments.0.type='ObjectExpression']:not(:has(ObjectExpression > Property[key.name='error'])):not(:has(ObjectExpression > SpreadElement))`,
|
||||
message:
|
||||
"Error-level server logger calls must include nested `error` payload (prefer `error: errorToLog(...)`).",
|
||||
},
|
||||
{
|
||||
selector: `${SERVER_LOGGER_CALL_SELECTOR} > ObjectExpression:first-child > Property[key.name='detail']`,
|
||||
message:
|
||||
"Do not use top-level `detail` in server logger context; keep throwable text under `error.message`.",
|
||||
},
|
||||
{
|
||||
selector: `${SERVER_LOGGER_CALL_SELECTOR} > ObjectExpression:first-child > Property[key.name='err']`,
|
||||
message:
|
||||
"Use `error` (typically from errorToLog(...)) instead of `err` in server logs.",
|
||||
},
|
||||
{
|
||||
selector: `${SERVER_LOGGER_CALL_SELECTOR} > ObjectExpression:first-child > Property[key.name='error'][value.type='Literal']`,
|
||||
message:
|
||||
"Server logger `error` must be a structured object (prefer `errorToLog(...)`), not a literal.",
|
||||
},
|
||||
{
|
||||
selector: `${SERVER_LOGGER_CALL_SELECTOR} > ObjectExpression:first-child > Property[key.name='error'][value.type='TemplateLiteral']`,
|
||||
message:
|
||||
"Server logger `error` must be a structured object (prefer `errorToLog(...)`), not template text.",
|
||||
},
|
||||
],
|
||||
},
|
||||
},
|
||||
|
|
|
|||
|
|
@ -333,8 +333,13 @@ export async function POST(request: NextRequest) {
|
|||
if (!existingResult.settings) {
|
||||
serverLogger.error({
|
||||
event: 'audiobook.chapter.meta_settings.invalid',
|
||||
errorCode: 'AUDIOBOOK_CHAPTER_META_SETTINGS_INVALID',
|
||||
bookId,
|
||||
storageUserId,
|
||||
error: {
|
||||
name: 'AudiobookMetaSettingsInvalid',
|
||||
message: 'Invalid audiobook.meta.json settings payload',
|
||||
},
|
||||
}, 'Invalid audiobook.meta.json settings payload');
|
||||
return NextResponse.json({ error: 'Invalid audiobook metadata settings' }, { status: 500 });
|
||||
}
|
||||
|
|
|
|||
|
|
@ -269,10 +269,13 @@ export async function GET(req: NextRequest, ctx: { params: Promise<{ id: string
|
|||
if (closed) return;
|
||||
logger.warn({
|
||||
event: 'documents.parsed.events.db_resync_failed',
|
||||
errorCode: 'DOCUMENTS_PARSED_EVENTS_DB_RESYNC_FAILED',
|
||||
degraded: true,
|
||||
step: 'db_resync',
|
||||
documentId: id,
|
||||
storageUserIdHash,
|
||||
requestId,
|
||||
error: error instanceof Error ? error.message : String(error),
|
||||
error: errorToLog(error),
|
||||
}, 'SSE DB resync failed');
|
||||
controller.enqueue(encoder.encode(`event: error\ndata: ${JSON.stringify({ error: String(error) })}\n\n`));
|
||||
});
|
||||
|
|
@ -302,6 +305,8 @@ export async function GET(req: NextRequest, ctx: { params: Promise<{ id: string
|
|||
loggedMissingOpId = true;
|
||||
logger.warn({
|
||||
event: 'documents.parsed.events.missing_opid_non_terminal',
|
||||
degraded: true,
|
||||
step: 'poll_without_worker_op',
|
||||
documentId: id,
|
||||
storageUserIdHash,
|
||||
parseStatus: current.parseStatus,
|
||||
|
|
@ -339,13 +344,20 @@ export async function GET(req: NextRequest, ctx: { params: Promise<{ id: string
|
|||
if (closed) return;
|
||||
|
||||
if (!response.ok) {
|
||||
const detail = await response.text().catch(() => '');
|
||||
const upstreamResponseBody = await response.text().catch(() => '');
|
||||
logger.warn({
|
||||
event: 'documents.parsed.events.worker_stream_request_failed',
|
||||
errorCode: 'DOCUMENTS_PARSED_EVENTS_WORKER_STREAM_REQUEST_FAILED',
|
||||
degraded: true,
|
||||
step: 'worker_stream_request',
|
||||
documentId: id,
|
||||
opId: currentOpId,
|
||||
status: response.status,
|
||||
detail,
|
||||
upstreamResponseBody,
|
||||
error: {
|
||||
name: 'WorkerStreamRequestFailed',
|
||||
message: `Worker stream request failed with status ${response.status}`,
|
||||
},
|
||||
}, 'Worker stream request failed');
|
||||
await sleep(500);
|
||||
continue;
|
||||
|
|
@ -353,8 +365,15 @@ export async function GET(req: NextRequest, ctx: { params: Promise<{ id: string
|
|||
if (!response.body) {
|
||||
logger.warn({
|
||||
event: 'documents.parsed.events.worker_stream_missing_body',
|
||||
errorCode: 'DOCUMENTS_PARSED_EVENTS_WORKER_STREAM_MISSING_BODY',
|
||||
degraded: true,
|
||||
step: 'worker_stream_body',
|
||||
documentId: id,
|
||||
opId: currentOpId,
|
||||
error: {
|
||||
name: 'WorkerStreamMissingBody',
|
||||
message: 'Worker stream response missing body',
|
||||
},
|
||||
}, 'Worker stream response missing body');
|
||||
await sleep(500);
|
||||
continue;
|
||||
|
|
@ -455,6 +474,7 @@ export async function GET(req: NextRequest, ctx: { params: Promise<{ id: string
|
|||
logger.error({
|
||||
event: 'documents.parsed.events.worker_proxy_crashed',
|
||||
documentId: id,
|
||||
errorCode: 'DOCUMENTS_PARSED_EVENTS_WORKER_PROXY_CRASHED',
|
||||
error: errorToLog(error),
|
||||
}, 'Worker proxy crashed while streaming parse events');
|
||||
if (!closed) {
|
||||
|
|
@ -485,6 +505,7 @@ export async function GET(req: NextRequest, ctx: { params: Promise<{ id: string
|
|||
} catch (error) {
|
||||
logger.error({
|
||||
event: 'documents.parsed.events.route_failed',
|
||||
errorCode: 'DOCUMENTS_PARSED_EVENTS_ROUTE_FAILED',
|
||||
error: errorToLog(error),
|
||||
}, 'Parsed events route failed');
|
||||
return NextResponse.json({ error: 'Failed to stream parsed PDF progress' }, { status: 500 });
|
||||
|
|
|
|||
|
|
@ -220,9 +220,16 @@ export async function GET(req: NextRequest, ctx: { params: Promise<{ id: string
|
|||
}
|
||||
logger.warn({
|
||||
event: 'documents.parsed.requested_op_unavailable',
|
||||
errorCode: 'DOCUMENTS_PARSED_REQUESTED_OP_UNAVAILABLE',
|
||||
degraded: true,
|
||||
step: 'requested_op_lookup',
|
||||
documentId: id,
|
||||
userIdHash: hashForLog(row.userId),
|
||||
opId: requestedOpId,
|
||||
error: {
|
||||
name: 'RequestedOperationUnavailable',
|
||||
message: `Requested worker operation ${requestedOpId} was unavailable`,
|
||||
},
|
||||
}, 'Requested worker operation id was unavailable');
|
||||
}
|
||||
|
||||
|
|
@ -307,6 +314,7 @@ export async function GET(req: NextRequest, ctx: { params: Promise<{ id: string
|
|||
} catch (error) {
|
||||
logger.error({
|
||||
event: 'documents.parsed.get_failed',
|
||||
errorCode: 'DOCUMENTS_PARSED_GET_FAILED',
|
||||
error: errorToLog(error),
|
||||
}, 'Failed to read parsed PDF');
|
||||
return NextResponse.json({ error: 'Failed to read parsed PDF' }, { status: 500 });
|
||||
|
|
@ -387,6 +395,7 @@ export async function POST(req: NextRequest, ctx: { params: Promise<{ id: string
|
|||
} catch (error) {
|
||||
logger.error({
|
||||
event: 'documents.parsed.force_refresh_failed',
|
||||
errorCode: 'DOCUMENTS_PARSED_FORCE_REFRESH_FAILED',
|
||||
error: errorToLog(error),
|
||||
}, 'Failed to force PDF refresh');
|
||||
return NextResponse.json({ error: 'Failed to force PDF refresh' }, { status: 500 });
|
||||
|
|
|
|||
|
|
@ -52,6 +52,7 @@ export async function GET(request: NextRequest) {
|
|||
} catch (error) {
|
||||
logger.error({
|
||||
event: 'tts.segments.audio_fallback_failed',
|
||||
errorCode: 'TTS_SEGMENT_AUDIO_FALLBACK_FAILED',
|
||||
error: errorToLog(error),
|
||||
}, 'Failed to load segment audio from fallback route');
|
||||
return NextResponse.json({ error: 'Failed to load segment audio' }, { status: 500 });
|
||||
|
|
|
|||
|
|
@ -41,6 +41,7 @@ export async function POST(request: NextRequest) {
|
|||
} catch (error) {
|
||||
logger.error({
|
||||
event: 'tts.segments.clear_failed',
|
||||
errorCode: 'TTS_SEGMENTS_CLEAR_FAILED',
|
||||
error: errorToLog(error),
|
||||
}, 'Failed to clear TTS segment cache');
|
||||
return NextResponse.json({ error: 'Failed to clear TTS segment cache' }, { status: 500 });
|
||||
|
|
|
|||
|
|
@ -423,7 +423,10 @@ export async function POST(request: NextRequest) {
|
|||
documentId: parsed.documentId,
|
||||
segmentId: segment.segmentId,
|
||||
aborted,
|
||||
error: alignError instanceof Error ? alignError.message : String(alignError),
|
||||
errorCode: 'TTS_SEGMENT_ALIGNMENT_UNAVAILABLE',
|
||||
...(aborted ? {} : { degraded: true }),
|
||||
step: 'whisper_align',
|
||||
error: errorToLog(alignError),
|
||||
}, 'Self-heal alignment unavailable');
|
||||
alignment = null;
|
||||
}
|
||||
|
|
@ -665,7 +668,10 @@ export async function POST(request: NextRequest) {
|
|||
documentId: parsed.documentId,
|
||||
segmentId: segment.segmentId,
|
||||
aborted,
|
||||
error: alignError instanceof Error ? alignError.message : String(alignError),
|
||||
errorCode: 'TTS_SEGMENT_ALIGNMENT_UNAVAILABLE',
|
||||
...(aborted ? {} : { degraded: true }),
|
||||
step: 'whisper_align',
|
||||
error: errorToLog(alignError),
|
||||
}, 'Alignment unavailable');
|
||||
alignment = null;
|
||||
}
|
||||
|
|
@ -708,7 +714,7 @@ export async function POST(request: NextRequest) {
|
|||
status: 'completed',
|
||||
});
|
||||
} catch (error) {
|
||||
const detail = error instanceof Error ? error.message : 'Failed to generate segment';
|
||||
const errorMessage = error instanceof Error ? error.message : 'Failed to generate segment';
|
||||
const aborted = isAbortLikeError(error);
|
||||
const upstreamStatus = getUpstreamStatus(error);
|
||||
const retryAfterSeconds = upstreamStatus === 429
|
||||
|
|
@ -730,7 +736,7 @@ export async function POST(request: NextRequest) {
|
|||
stageTimings,
|
||||
aborted: true,
|
||||
errorCode,
|
||||
detail,
|
||||
error: errorToLog(error),
|
||||
completedSoFar: manifest.length,
|
||||
totalRequested: normalized.length,
|
||||
}, 'Stopping segment ensure after abort');
|
||||
|
|
@ -747,7 +753,6 @@ export async function POST(request: NextRequest) {
|
|||
upstreamStatus,
|
||||
retryAfterSeconds,
|
||||
errorCode,
|
||||
detail,
|
||||
error: errorToLog(error),
|
||||
}, 'TTS segment generation failed');
|
||||
}
|
||||
|
|
@ -757,8 +762,8 @@ export async function POST(request: NextRequest) {
|
|||
status: aborted ? 'pending' : 'error',
|
||||
error: aborted ? null : (
|
||||
upstreamStatus
|
||||
? `${errorCode}${retryAfterSeconds ? ` (retry after ${retryAfterSeconds}s)` : ''}: ${detail}`
|
||||
: detail
|
||||
? `${errorCode}${retryAfterSeconds ? ` (retry after ${retryAfterSeconds}s)` : ''}: ${errorMessage}`
|
||||
: errorMessage
|
||||
),
|
||||
updatedAt: Date.now(),
|
||||
})
|
||||
|
|
@ -781,7 +786,7 @@ export async function POST(request: NextRequest) {
|
|||
? null
|
||||
: {
|
||||
code: errorCode,
|
||||
detail,
|
||||
detail: errorMessage,
|
||||
...(typeof upstreamStatus === 'number' ? { upstreamStatus } : {}),
|
||||
...(typeof retryAfterSeconds === 'number' ? { retryAfterSeconds } : {}),
|
||||
},
|
||||
|
|
@ -799,6 +804,7 @@ export async function POST(request: NextRequest) {
|
|||
if (errorItems.length > 0) {
|
||||
logger.error({
|
||||
event: 'tts.segments.ensure.partial_result',
|
||||
errorCode: 'TTS_SEGMENT_PARTIAL_FAILURE',
|
||||
requestId,
|
||||
documentId: parsed.documentId,
|
||||
total: manifest.length,
|
||||
|
|
@ -806,6 +812,10 @@ export async function POST(request: NextRequest) {
|
|||
pendingCount,
|
||||
errorCount: errorItems.length,
|
||||
elapsedMs: Date.now() - requestStartedAt,
|
||||
error: {
|
||||
name: 'PartialSegmentFailure',
|
||||
message: `TTS segment ensure completed with ${errorItems.length} segment errors`,
|
||||
},
|
||||
errors: errorItems.slice(0, 5).map((item) => ({
|
||||
segmentId: item.segmentId,
|
||||
code: item.error?.code ?? null,
|
||||
|
|
@ -825,6 +835,7 @@ export async function POST(request: NextRequest) {
|
|||
} catch (error) {
|
||||
logger.error({
|
||||
event: 'tts.segments.ensure.route_failed',
|
||||
errorCode: 'TTS_SEGMENTS_ENSURE_ROUTE_FAILED',
|
||||
error: errorToLog(error),
|
||||
}, 'TTS segments ensure route failed');
|
||||
const response = NextResponse.json({ error: 'Failed to ensure TTS segments' }, { status: 500 });
|
||||
|
|
|
|||
|
|
@ -388,6 +388,7 @@ export async function GET(request: NextRequest) {
|
|||
} catch (error) {
|
||||
logger.error({
|
||||
event: 'tts.segments.manifest.list_failed',
|
||||
errorCode: 'TTS_SEGMENTS_MANIFEST_LIST_FAILED',
|
||||
error: errorToLog(error),
|
||||
}, 'Failed to list TTS segments');
|
||||
return NextResponse.json({ error: 'Failed to list TTS segments' }, { status: 500 });
|
||||
|
|
|
|||
|
|
@ -63,6 +63,7 @@ export async function syncAdminFlag(
|
|||
} catch (error) {
|
||||
serverLogger.warn({
|
||||
event: 'admin.email_sync.user_flag_update.failed',
|
||||
errorCode: 'ADMIN_EMAIL_SYNC_USER_FLAG_UPDATE_FAILED',
|
||||
userIdHash: hashForLog(userId),
|
||||
degraded: true,
|
||||
error: errorToLog(error),
|
||||
|
|
|
|||
|
|
@ -33,6 +33,7 @@ export async function ensureAdminSeed(): Promise<void> {
|
|||
seedPromise = runSeed().catch((error) => {
|
||||
serverLogger.warn({
|
||||
event: 'admin.seed.run.failed',
|
||||
errorCode: 'ADMIN_SEED_RUN_FAILED',
|
||||
degraded: true,
|
||||
error: errorToLog(error),
|
||||
}, 'Admin seed run failed');
|
||||
|
|
@ -65,6 +66,7 @@ async function seedDefaultAdminProvider(): Promise<void> {
|
|||
} catch (error) {
|
||||
serverLogger.warn({
|
||||
event: 'admin.seed.providers.check_failed',
|
||||
errorCode: 'ADMIN_SEED_PROVIDERS_CHECK_FAILED',
|
||||
degraded: true,
|
||||
error: errorToLog(error),
|
||||
}, 'Could not check admin_providers');
|
||||
|
|
@ -102,6 +104,7 @@ async function seedDefaultAdminProvider(): Promise<void> {
|
|||
} catch (fallbackError) {
|
||||
serverLogger.warn({
|
||||
event: 'admin.seed.restrict_user_api_keys.fallback_write_failed',
|
||||
errorCode: 'ADMIN_SEED_RESTRICT_USER_API_KEYS_FALLBACK_WRITE_FAILED',
|
||||
degraded: true,
|
||||
error: errorToLog(fallbackError),
|
||||
}, 'Failed to write restrictUserApiKeys fallback after encryption failure');
|
||||
|
|
@ -109,6 +112,7 @@ async function seedDefaultAdminProvider(): Promise<void> {
|
|||
}
|
||||
serverLogger.warn({
|
||||
event: 'admin.seed.provider_key_encrypt.failed',
|
||||
errorCode: 'ADMIN_SEED_PROVIDER_KEY_ENCRYPT_FAILED',
|
||||
degraded: true,
|
||||
error: errorToLog(error),
|
||||
}, 'Failed to encrypt default provider API key');
|
||||
|
|
@ -137,6 +141,7 @@ async function seedDefaultAdminProvider(): Promise<void> {
|
|||
} catch (error) {
|
||||
serverLogger.warn({
|
||||
event: 'admin.seed.provider_insert.failed',
|
||||
errorCode: 'ADMIN_SEED_PROVIDER_INSERT_FAILED',
|
||||
degraded: true,
|
||||
providerSlug: 'default-openai',
|
||||
error: errorToLog(error),
|
||||
|
|
@ -166,6 +171,7 @@ async function cleanupLegacyDefaultTtsProviderSeedRow(): Promise<void> {
|
|||
} catch (error) {
|
||||
serverLogger.warn({
|
||||
event: 'admin.seed.legacy_default_provider_cleanup.failed',
|
||||
errorCode: 'ADMIN_SEED_LEGACY_DEFAULT_PROVIDER_CLEANUP_FAILED',
|
||||
degraded: true,
|
||||
error: errorToLog(error),
|
||||
}, 'Failed to cleanup legacy defaultTtsProvider seed row');
|
||||
|
|
@ -180,6 +186,7 @@ async function cleanupLegacyDefaultTtsModelRows(): Promise<void> {
|
|||
} catch (error) {
|
||||
serverLogger.warn({
|
||||
event: 'admin.seed.legacy_default_model_cleanup.failed',
|
||||
errorCode: 'ADMIN_SEED_LEGACY_DEFAULT_MODEL_CLEANUP_FAILED',
|
||||
degraded: true,
|
||||
error: errorToLog(error),
|
||||
}, 'Failed to cleanup legacy defaultTtsModel rows');
|
||||
|
|
|
|||
|
|
@ -116,6 +116,7 @@ async function resolveImplicitDefaultTtsProvider(): Promise<string | undefined>
|
|||
} catch (error) {
|
||||
serverLogger.warn({
|
||||
event: 'admin.runtime_config.default_provider_lookup.failed',
|
||||
errorCode: 'ADMIN_RUNTIME_CONFIG_DEFAULT_PROVIDER_LOOKUP_FAILED',
|
||||
degraded: true,
|
||||
error: errorToLog(error),
|
||||
}, 'Implicit defaultTtsProvider lookup failed');
|
||||
|
|
@ -148,6 +149,7 @@ async function readAllRows(): Promise<Map<string, { value: unknown; source: stri
|
|||
} catch (error) {
|
||||
serverLogger.warn({
|
||||
event: 'admin.runtime_config.read.failed',
|
||||
errorCode: 'ADMIN_RUNTIME_CONFIG_READ_FAILED',
|
||||
degraded: true,
|
||||
error: errorToLog(error),
|
||||
}, 'Runtime config read failed');
|
||||
|
|
@ -308,6 +310,7 @@ export async function seedRuntimeConfigFromEnv(): Promise<{ seeded: RuntimeConfi
|
|||
} catch (error) {
|
||||
serverLogger.warn({
|
||||
event: 'admin.runtime_config.seed.failed',
|
||||
errorCode: 'ADMIN_RUNTIME_CONFIG_SEED_FAILED',
|
||||
degraded: true,
|
||||
key,
|
||||
error: errorToLog(error),
|
||||
|
|
|
|||
|
|
@ -96,6 +96,7 @@ const createAuth = () => betterAuth({
|
|||
} catch (error) {
|
||||
serverLogger.warn({
|
||||
event: 'auth.user_delete.storage_cleanup_failed',
|
||||
errorCode: 'AUTH_USER_DELETE_STORAGE_CLEANUP_FAILED',
|
||||
degraded: true,
|
||||
step: 'delete_user_storage',
|
||||
userIdHash: hashForLog(user.id),
|
||||
|
|
@ -179,6 +180,7 @@ const createAuth = () => betterAuth({
|
|||
} catch (error) {
|
||||
serverLogger.warn({
|
||||
event: 'auth.link_account.transfer.rate_limit.failed',
|
||||
errorCode: 'AUTH_LINK_ACCOUNT_TRANSFER_RATE_LIMIT_FAILED',
|
||||
degraded: true,
|
||||
step: 'transfer_rate_limit',
|
||||
anonymousUserIdHash: hashForLog(anonymousUser.user.id),
|
||||
|
|
@ -202,6 +204,7 @@ const createAuth = () => betterAuth({
|
|||
} catch (error) {
|
||||
serverLogger.warn({
|
||||
event: 'auth.link_account.transfer.audiobooks.failed',
|
||||
errorCode: 'AUTH_LINK_ACCOUNT_TRANSFER_AUDIOBOOKS_FAILED',
|
||||
degraded: true,
|
||||
step: 'transfer_audiobooks',
|
||||
anonymousUserIdHash: hashForLog(anonymousUser.user.id),
|
||||
|
|
@ -225,6 +228,7 @@ const createAuth = () => betterAuth({
|
|||
} catch (error) {
|
||||
serverLogger.warn({
|
||||
event: 'auth.link_account.transfer.documents.failed',
|
||||
errorCode: 'AUTH_LINK_ACCOUNT_TRANSFER_DOCUMENTS_FAILED',
|
||||
degraded: true,
|
||||
step: 'transfer_documents',
|
||||
anonymousUserIdHash: hashForLog(anonymousUser.user.id),
|
||||
|
|
@ -248,6 +252,7 @@ const createAuth = () => betterAuth({
|
|||
} catch (error) {
|
||||
serverLogger.warn({
|
||||
event: 'auth.link_account.transfer.preferences.failed',
|
||||
errorCode: 'AUTH_LINK_ACCOUNT_TRANSFER_PREFERENCES_FAILED',
|
||||
degraded: true,
|
||||
step: 'transfer_preferences',
|
||||
anonymousUserIdHash: hashForLog(anonymousUser.user.id),
|
||||
|
|
@ -271,6 +276,7 @@ const createAuth = () => betterAuth({
|
|||
} catch (error) {
|
||||
serverLogger.warn({
|
||||
event: 'auth.link_account.transfer.progress.failed',
|
||||
errorCode: 'AUTH_LINK_ACCOUNT_TRANSFER_PROGRESS_FAILED',
|
||||
degraded: true,
|
||||
step: 'transfer_progress',
|
||||
anonymousUserIdHash: hashForLog(anonymousUser.user.id),
|
||||
|
|
@ -282,6 +288,7 @@ const createAuth = () => betterAuth({
|
|||
} catch (error) {
|
||||
serverLogger.error({
|
||||
event: 'auth.link_account.failed',
|
||||
errorCode: 'AUTH_LINK_ACCOUNT_FAILED',
|
||||
error: errorToLog(error),
|
||||
}, 'onLinkAccount callback failed');
|
||||
// Don't throw here to prevent blocking the account linking process
|
||||
|
|
|
|||
|
|
@ -16,8 +16,10 @@ export async function fetchWorkerOperationState<Result>(
|
|||
} catch (error) {
|
||||
serverLogger.warn({
|
||||
event: 'compute.worker_op_state.config.invalid',
|
||||
errorCode: 'COMPUTE_WORKER_OP_STATE_CONFIG_INVALID',
|
||||
opId: normalized,
|
||||
degraded: true,
|
||||
step: 'read_worker_config',
|
||||
error: errorToLog(error),
|
||||
}, 'Worker client env missing/invalid');
|
||||
return null;
|
||||
|
|
@ -38,13 +40,19 @@ export async function fetchWorkerOperationState<Result>(
|
|||
});
|
||||
|
||||
if (!res.ok) {
|
||||
const detail = await res.text().catch(() => '');
|
||||
const upstreamResponseBody = await res.text().catch(() => '');
|
||||
serverLogger.warn({
|
||||
event: 'compute.worker_op_state.fetch.failed',
|
||||
errorCode: 'COMPUTE_WORKER_OP_STATE_FETCH_FAILED',
|
||||
opId: normalized,
|
||||
status: res.status,
|
||||
detail,
|
||||
upstreamResponseBody,
|
||||
degraded: true,
|
||||
step: 'fetch_worker_op',
|
||||
error: {
|
||||
name: 'WorkerOpStateFetchFailed',
|
||||
message: `Worker op request failed with status ${res.status}`,
|
||||
},
|
||||
}, 'Worker op request failed');
|
||||
return null;
|
||||
}
|
||||
|
|
@ -52,8 +60,10 @@ export async function fetchWorkerOperationState<Result>(
|
|||
if (!parsed || typeof parsed !== 'object' || parsed.opId !== normalized) {
|
||||
serverLogger.warn({
|
||||
event: 'compute.worker_op_state.response.invalid',
|
||||
errorCode: 'COMPUTE_WORKER_OP_STATE_RESPONSE_INVALID',
|
||||
opId: normalized,
|
||||
degraded: true,
|
||||
step: 'validate_worker_op_response',
|
||||
}, 'Worker op response invalid');
|
||||
return null;
|
||||
}
|
||||
|
|
@ -61,8 +71,10 @@ export async function fetchWorkerOperationState<Result>(
|
|||
} catch (error) {
|
||||
serverLogger.warn({
|
||||
event: 'compute.worker_op_state.fetch.error',
|
||||
errorCode: 'COMPUTE_WORKER_OP_STATE_FETCH_ERROR',
|
||||
opId: normalized,
|
||||
degraded: true,
|
||||
step: 'fetch_worker_op',
|
||||
error: errorToLog(error),
|
||||
}, 'Worker op request threw');
|
||||
return null;
|
||||
|
|
|
|||
|
|
@ -2,7 +2,7 @@ import { createHash, randomUUID } from 'node:crypto';
|
|||
import type { ComputeBackend, PdfLayoutInput, WhisperAlignInput, WhisperAlignResult } from '@/lib/server/compute/types';
|
||||
import { parseSseEventId, parseSsePayload } from '@openreader/compute-core';
|
||||
import { getWorkerClientWaitTimeoutMs } from '@openreader/compute-core';
|
||||
import { serverLogger } from '@/lib/server/logger';
|
||||
import { errorToLog, serverLogger } from '@/lib/server/logger';
|
||||
import type {
|
||||
PdfLayoutJobRequest,
|
||||
PdfLayoutJobResult,
|
||||
|
|
@ -44,22 +44,6 @@ function truncateForLog(value: string, maxChars = MAX_LOG_DETAIL_CHARS): string
|
|||
return `${value.slice(0, maxChars)}...`;
|
||||
}
|
||||
|
||||
function errorToLog(error: unknown): Record<string, unknown> {
|
||||
if (error instanceof WorkerHttpError) {
|
||||
return {
|
||||
name: error.name,
|
||||
message: error.message,
|
||||
status: error.status,
|
||||
retryAfterMs: error.retryAfterMs,
|
||||
stack: error.stack,
|
||||
};
|
||||
}
|
||||
if (error instanceof Error) {
|
||||
return { name: error.name, message: error.message, stack: error.stack };
|
||||
}
|
||||
return { message: String(error) };
|
||||
}
|
||||
|
||||
function logWorker(level: WorkerLogLevel, event: string, fields: Record<string, unknown>): void {
|
||||
if (!LOG_EVENTS.has(event)) return;
|
||||
if (level === 'error') {
|
||||
|
|
@ -316,6 +300,7 @@ export class WorkerComputeBackend implements ComputeBackend {
|
|||
return { alignments: final.result.alignments };
|
||||
}, ({ attempt, maxAttempts, willRetry, delayMs, error }) => {
|
||||
logWorker(willRetry ? 'warn' : 'error', 'align.request.attempt_error', {
|
||||
errorCode: 'COMPUTE_WORKER_ALIGN_REQUEST_ATTEMPT_ERROR',
|
||||
traceId,
|
||||
kind: 'whisper_align',
|
||||
opKeyHash,
|
||||
|
|
@ -336,6 +321,7 @@ export class WorkerComputeBackend implements ComputeBackend {
|
|||
return result;
|
||||
} catch (error) {
|
||||
logWorker('error', 'align.request.failed', {
|
||||
errorCode: 'COMPUTE_WORKER_ALIGN_REQUEST_FAILED',
|
||||
traceId,
|
||||
kind: 'whisper_align',
|
||||
opKeyHash,
|
||||
|
|
@ -414,6 +400,7 @@ export class WorkerComputeBackend implements ComputeBackend {
|
|||
throw new Error('PDF layout worker operation completed without parsed output');
|
||||
}, ({ attempt, maxAttempts, willRetry, delayMs, error }) => {
|
||||
logWorker(willRetry ? 'warn' : 'error', 'pdf_layout.request.attempt_error', {
|
||||
errorCode: 'COMPUTE_WORKER_PDF_LAYOUT_REQUEST_ATTEMPT_ERROR',
|
||||
traceId,
|
||||
kind: 'pdf_layout',
|
||||
opKeyHash,
|
||||
|
|
@ -436,6 +423,7 @@ export class WorkerComputeBackend implements ComputeBackend {
|
|||
return result;
|
||||
} catch (error) {
|
||||
logWorker('error', 'pdf_layout.request.failed', {
|
||||
errorCode: 'COMPUTE_WORKER_PDF_LAYOUT_REQUEST_FAILED',
|
||||
traceId,
|
||||
kind: 'pdf_layout',
|
||||
opKeyHash,
|
||||
|
|
@ -473,8 +461,14 @@ export class WorkerComputeBackend implements ComputeBackend {
|
|||
|
||||
if (!res.ok) {
|
||||
const retryAfterMs = parseRetryAfterMs(res.headers.get('retry-after'));
|
||||
const detail = await res.text().catch(() => '');
|
||||
const upstreamResponseBody = await res.text().catch(() => '');
|
||||
const requestError = new WorkerHttpError(
|
||||
`Worker request failed (${method} ${path}): ${res.status}${upstreamResponseBody ? ` ${upstreamResponseBody}` : ''}`,
|
||||
res.status,
|
||||
retryAfterMs,
|
||||
);
|
||||
logWorker(res.status >= 500 ? 'warn' : 'error', 'http.request.failed', {
|
||||
errorCode: 'COMPUTE_WORKER_HTTP_REQUEST_FAILED',
|
||||
...context,
|
||||
traceId,
|
||||
method,
|
||||
|
|
@ -482,13 +476,10 @@ export class WorkerComputeBackend implements ComputeBackend {
|
|||
status: res.status,
|
||||
retryAfterMs,
|
||||
durationMs: Date.now() - startedAt,
|
||||
detail: truncateForLog(detail),
|
||||
upstreamResponseBody: truncateForLog(upstreamResponseBody),
|
||||
error: errorToLog(requestError),
|
||||
});
|
||||
throw new WorkerHttpError(
|
||||
`Worker request failed (${method} ${path}): ${res.status}${detail ? ` ${detail}` : ''}`,
|
||||
res.status,
|
||||
retryAfterMs,
|
||||
);
|
||||
throw requestError;
|
||||
}
|
||||
|
||||
const parsed = await res.json() as T;
|
||||
|
|
@ -549,21 +540,24 @@ export class WorkerComputeBackend implements ComputeBackend {
|
|||
|
||||
if (!res.ok) {
|
||||
const retryAfterMs = parseRetryAfterMs(res.headers.get('retry-after'));
|
||||
const detail = await res.text().catch(() => '');
|
||||
const upstreamResponseBody = await res.text().catch(() => '');
|
||||
const requestError = new WorkerHttpError(
|
||||
`Worker request failed (GET /ops/${encodeURIComponent(opId)}/events): ${res.status}${upstreamResponseBody ? ` ${upstreamResponseBody}` : ''}`,
|
||||
res.status,
|
||||
retryAfterMs,
|
||||
);
|
||||
logWorker(res.status >= 500 ? 'warn' : 'error', 'sse.wait.http_failed', {
|
||||
errorCode: 'COMPUTE_WORKER_SSE_WAIT_HTTP_FAILED',
|
||||
...context,
|
||||
traceId,
|
||||
opId,
|
||||
status: res.status,
|
||||
retryAfterMs,
|
||||
durationMs: Date.now() - startedAt,
|
||||
detail: truncateForLog(detail),
|
||||
upstreamResponseBody: truncateForLog(upstreamResponseBody),
|
||||
error: errorToLog(requestError),
|
||||
});
|
||||
throw new WorkerHttpError(
|
||||
`Worker request failed (GET /ops/${encodeURIComponent(opId)}/events): ${res.status}${detail ? ` ${detail}` : ''}`,
|
||||
res.status,
|
||||
retryAfterMs,
|
||||
);
|
||||
throw requestError;
|
||||
}
|
||||
|
||||
if (!res.body) {
|
||||
|
|
@ -675,16 +669,22 @@ export class WorkerComputeBackend implements ComputeBackend {
|
|||
}
|
||||
|
||||
logWorker('error', 'sse.wait.ended_without_terminal', {
|
||||
errorCode: 'COMPUTE_WORKER_SSE_WAIT_ENDED_WITHOUT_TERMINAL',
|
||||
...context,
|
||||
traceId,
|
||||
opId,
|
||||
eventCount,
|
||||
latestStatus: latest?.status ?? null,
|
||||
durationMs: Date.now() - startedAt,
|
||||
error: {
|
||||
name: 'WorkerSseWaitEndedWithoutTerminal',
|
||||
message: `Operation stream ended before terminal state for op ${opId}`,
|
||||
},
|
||||
});
|
||||
throw new Error(`Operation stream ended before terminal state for op ${opId}`);
|
||||
} catch (error) {
|
||||
logWorker('error', 'sse.wait.failed', {
|
||||
errorCode: 'COMPUTE_WORKER_SSE_WAIT_FAILED',
|
||||
...context,
|
||||
traceId,
|
||||
opId,
|
||||
|
|
|
|||
|
|
@ -377,6 +377,7 @@ export async function ensureDocumentPreview(doc: PreviewSourceDocument, namespac
|
|||
} catch (error) {
|
||||
serverLogger.error({
|
||||
event: 'documents.preview.generate.failed',
|
||||
errorCode: 'DOCUMENTS_PREVIEW_GENERATE_FAILED',
|
||||
documentId: doc.id,
|
||||
documentType: doc.type,
|
||||
error: errorToLog(error),
|
||||
|
|
|
|||
|
|
@ -371,8 +371,6 @@ export async function parsePdfJob(input: UserPdfLayoutJobRequest): Promise<void>
|
|||
}
|
||||
} catch (error) {
|
||||
const message = error instanceof Error ? error.message : String(error);
|
||||
const stack = error instanceof Error ? error.stack : undefined;
|
||||
const cause = error instanceof Error ? error.cause : undefined;
|
||||
const parseStatus = 'failed';
|
||||
try {
|
||||
const scopedRows = await loadScopedRows(input);
|
||||
|
|
@ -392,6 +390,7 @@ export async function parsePdfJob(input: UserPdfLayoutJobRequest): Promise<void>
|
|||
} catch (statusError) {
|
||||
serverLogger.error({
|
||||
event: 'documents.parse.status_write.failed',
|
||||
errorCode: 'DOCUMENTS_PARSE_STATUS_WRITE_FAILED',
|
||||
documentId: input.documentId,
|
||||
parseStatus,
|
||||
error: errorToLog(statusError),
|
||||
|
|
@ -399,11 +398,10 @@ export async function parsePdfJob(input: UserPdfLayoutJobRequest): Promise<void>
|
|||
}
|
||||
serverLogger.error({
|
||||
event: 'documents.parse.job.failed',
|
||||
errorCode: 'DOCUMENTS_PARSE_JOB_FAILED',
|
||||
documentId: input.documentId,
|
||||
parseStatus,
|
||||
error: message,
|
||||
...(stack ? { stack } : {}),
|
||||
...(cause ? { cause: String(cause) } : {}),
|
||||
error: errorToLog(error),
|
||||
}, 'Parse job failed');
|
||||
} finally {
|
||||
running.delete(key);
|
||||
|
|
@ -417,6 +415,7 @@ export function enqueueParsePdfJob(input: UserPdfLayoutJobRequest): void {
|
|||
serverLogger.error({
|
||||
event: 'documents.parse.job.uncaught_error',
|
||||
documentId: input.documentId,
|
||||
errorCode: 'DOCUMENTS_PARSE_JOB_UNCAUGHT_ERROR',
|
||||
error: errorToLog(error),
|
||||
}, 'Parse job uncaught error');
|
||||
});
|
||||
|
|
|
|||
|
|
@ -33,6 +33,14 @@ export type ServerApiErrorBody = {
|
|||
details?: Record<string, unknown>;
|
||||
};
|
||||
|
||||
export type LoggedError = {
|
||||
name: string;
|
||||
message: string;
|
||||
code?: string;
|
||||
stack?: string;
|
||||
cause?: LoggedError | { message: string };
|
||||
};
|
||||
|
||||
const LOG_FORMAT = process.env.LOG_FORMAT?.trim().toLowerCase() || 'pretty';
|
||||
const LOG_LEVEL = process.env.LOG_LEVEL?.trim() || 'info';
|
||||
|
||||
|
|
@ -59,21 +67,80 @@ function createServerLogger(): ServerLogger {
|
|||
colorize: true,
|
||||
translateTime: 'SYS:standard',
|
||||
ignore: 'pid,hostname',
|
||||
errorLikeObjectKeys: ['error'],
|
||||
customPrettifiers: {
|
||||
error(value) {
|
||||
if (!value || typeof value !== 'object') return String(value);
|
||||
const error = value as Record<string, unknown>;
|
||||
const lines: string[] = [];
|
||||
if (typeof error.message === 'string' && error.message) lines.push(`error.message: ${error.message}`);
|
||||
if (typeof error.code === 'string' && error.code) lines.push(`error.code: ${error.code}`);
|
||||
if (typeof error.name === 'string' && error.name) lines.push(`error.name: ${error.name}`);
|
||||
if (typeof error.stack === 'string' && error.stack) lines.push(`error.stack:\n${error.stack}`);
|
||||
if (error.cause !== undefined) {
|
||||
const causeText = typeof error.cause === 'object'
|
||||
? JSON.stringify(error.cause)
|
||||
: String(error.cause);
|
||||
lines.push(`error.cause: ${causeText}`);
|
||||
}
|
||||
if (lines.length > 0) return lines.join('\n');
|
||||
return JSON.stringify(error);
|
||||
},
|
||||
},
|
||||
});
|
||||
return pino(config, prettyStream);
|
||||
}
|
||||
|
||||
export const serverLogger: ServerLogger = createServerLogger();
|
||||
|
||||
export function errorToLog(error: unknown): Record<string, unknown> {
|
||||
if (error instanceof Error) {
|
||||
function normalizeErrorCode(code: unknown): string | undefined {
|
||||
if (typeof code === 'string' && code.trim()) return code.trim();
|
||||
if (typeof code === 'number' && Number.isFinite(code)) return String(code);
|
||||
return undefined;
|
||||
}
|
||||
|
||||
function serializeErrorCause(cause: unknown, depth: number): LoggedError | { message: string } {
|
||||
if (depth >= 3) {
|
||||
return { message: String(cause) };
|
||||
}
|
||||
if (cause instanceof Error) {
|
||||
return errorToLog(cause, depth + 1);
|
||||
}
|
||||
if (cause && typeof cause === 'object') {
|
||||
const rec = cause as Record<string, unknown>;
|
||||
const message = typeof rec.message === 'string' ? rec.message : String(cause);
|
||||
const name = typeof rec.name === 'string' && rec.name ? rec.name : 'ErrorCause';
|
||||
const code = normalizeErrorCode(rec.code);
|
||||
const stack = typeof rec.stack === 'string' ? rec.stack : undefined;
|
||||
const nestedCause = rec.cause !== undefined ? serializeErrorCause(rec.cause, depth + 1) : undefined;
|
||||
return {
|
||||
name: error.name,
|
||||
message: error.message,
|
||||
stack: error.stack,
|
||||
name,
|
||||
message,
|
||||
...(code ? { code } : {}),
|
||||
...(stack ? { stack } : {}),
|
||||
...(nestedCause ? { cause: nestedCause } : {}),
|
||||
};
|
||||
}
|
||||
return { message: String(error) };
|
||||
return { message: String(cause) };
|
||||
}
|
||||
|
||||
export function errorToLog(error: unknown, depth = 0): LoggedError {
|
||||
if (error instanceof Error) {
|
||||
const rec = error as Error & { code?: unknown; cause?: unknown };
|
||||
const code = normalizeErrorCode(rec.code);
|
||||
const cause = rec.cause !== undefined ? serializeErrorCause(rec.cause, depth) : undefined;
|
||||
return {
|
||||
name: error.name || 'Error',
|
||||
message: error.message || 'Unknown error',
|
||||
...(code ? { code } : {}),
|
||||
...(error.stack ? { stack: error.stack } : {}),
|
||||
...(cause ? { cause } : {}),
|
||||
};
|
||||
}
|
||||
return {
|
||||
name: 'NonErrorThrowable',
|
||||
message: String(error),
|
||||
};
|
||||
}
|
||||
|
||||
export function apiErrorBody(
|
||||
|
|
|
|||
|
|
@ -68,6 +68,7 @@ export async function clearTtsSegmentCache(
|
|||
warning = error instanceof Error ? error.message : 'Failed deleting some audio objects';
|
||||
serverLogger.warn({
|
||||
event: 'tts.segments.cache.audio_cleanup_failed',
|
||||
errorCode: 'TTS_SEGMENTS_CACHE_AUDIO_CLEANUP_FAILED',
|
||||
degraded: true,
|
||||
step: 'delete_tts_audio_objects',
|
||||
documentId: input.documentId,
|
||||
|
|
|
|||
|
|
@ -195,6 +195,7 @@ async function fetchReplicateOpenApiSchema(apiKey: string, model: string): Promi
|
|||
}
|
||||
serverLogger.error({
|
||||
event: 'tts.voice_resolution.replicate_schema_fetch.failed',
|
||||
errorCode: 'TTS_VOICE_RESOLUTION_REPLICATE_SCHEMA_FETCH_FAILED',
|
||||
error: errorToLog(error),
|
||||
}, 'Failed fetching Replicate model schema');
|
||||
return null;
|
||||
|
|
@ -289,6 +290,7 @@ async function fetchDeepinfraVoices(apiKey: string): Promise<string[]> {
|
|||
}
|
||||
serverLogger.error({
|
||||
event: 'tts.voice_resolution.deepinfra_voices_fetch.failed',
|
||||
errorCode: 'TTS_VOICE_RESOLUTION_DEEPINFRA_VOICES_FETCH_FAILED',
|
||||
error: errorToLog(error),
|
||||
}, 'Failed fetching Deepinfra voices');
|
||||
return [];
|
||||
|
|
|
|||
|
|
@ -52,6 +52,7 @@ export async function deleteUserStorageData(
|
|||
} catch (error) {
|
||||
serverLogger.warn({
|
||||
event: 'user.data_cleanup.document_blob_delete.failed',
|
||||
errorCode: 'USER_DATA_CLEANUP_DOCUMENT_BLOB_DELETE_FAILED',
|
||||
degraded: true,
|
||||
step: 'delete_document_blob',
|
||||
documentId: doc.id,
|
||||
|
|
@ -65,6 +66,7 @@ export async function deleteUserStorageData(
|
|||
} catch (error) {
|
||||
serverLogger.warn({
|
||||
event: 'user.data_cleanup.document_preview_delete.failed',
|
||||
errorCode: 'USER_DATA_CLEANUP_DOCUMENT_PREVIEW_DELETE_FAILED',
|
||||
degraded: true,
|
||||
step: 'delete_document_preview_artifacts',
|
||||
documentId: doc.id,
|
||||
|
|
@ -80,6 +82,7 @@ export async function deleteUserStorageData(
|
|||
} catch (error) {
|
||||
serverLogger.warn({
|
||||
event: 'user.data_cleanup.document_preview_rows_delete.failed',
|
||||
errorCode: 'USER_DATA_CLEANUP_DOCUMENT_PREVIEW_ROWS_DELETE_FAILED',
|
||||
degraded: true,
|
||||
step: 'delete_document_preview_rows',
|
||||
documentId: doc.id,
|
||||
|
|
@ -106,6 +109,7 @@ export async function deleteUserStorageData(
|
|||
} catch (error) {
|
||||
serverLogger.warn({
|
||||
event: 'user.data_cleanup.audiobook_blobs_delete.failed',
|
||||
errorCode: 'USER_DATA_CLEANUP_AUDIOBOOK_BLOBS_DELETE_FAILED',
|
||||
degraded: true,
|
||||
step: 'delete_audiobook_prefix',
|
||||
bookId: book.id,
|
||||
|
|
@ -128,6 +132,7 @@ export async function deleteUserStorageData(
|
|||
} catch (error) {
|
||||
serverLogger.warn({
|
||||
event: 'user.data_cleanup.tts_segments_delete.failed',
|
||||
errorCode: 'USER_DATA_CLEANUP_TTS_SEGMENTS_DELETE_FAILED',
|
||||
degraded: true,
|
||||
step: 'delete_tts_segment_prefixes',
|
||||
userIdHash: hashForLog(userId),
|
||||
|
|
|
|||
Loading…
Reference in a new issue