diff --git a/supabase/config.toml b/supabase/config.toml index 2163d1f8..c55c2714 100644 --- a/supabase/config.toml +++ b/supabase/config.toml @@ -47,6 +47,9 @@ verify_jwt = true [functions.process-selective-approval] verify_jwt = false +[functions.process-selective-rejection] +verify_jwt = false + [functions.send-escalation-notification] verify_jwt = true diff --git a/supabase/functions/process-selective-approval/index.ts b/supabase/functions/process-selective-approval/index.ts index 2e1bec25..7035160e 100644 --- a/supabase/functions/process-selective-approval/index.ts +++ b/supabase/functions/process-selective-approval/index.ts @@ -2,6 +2,7 @@ import { serve } from 'https://deno.land/std@0.168.0/http/server.ts'; import { createClient } from 'https://esm.sh/@supabase/supabase-js@2.57.4'; import { corsHeaders } from './cors.ts'; import { rateLimiters, withRateLimit } from '../_shared/rateLimiter.ts'; +import { edgeLogger, startRequest, endRequest, type RequestTracking } from '../_shared/logger.ts'; const SUPABASE_URL = Deno.env.get('SUPABASE_URL') || 'https://api.thrillwiki.com'; const SUPABASE_ANON_KEY = Deno.env.get('SUPABASE_ANON_KEY')!; @@ -22,8 +23,9 @@ const handler = async (req: Request) => { }); } - // Generate request ID for tracking - const requestId = crypto.randomUUID(); + // Start request tracking + const tracking: RequestTracking = startRequest(); + const requestId = tracking.requestId; try { // STEP 1: Authentication @@ -47,6 +49,11 @@ const handler = async (req: Request) => { const { data: { user }, error: authError } = await supabase.auth.getUser(); if (authError || !user) { + edgeLogger.warn('Authentication failed', { + requestId, + error: authError?.message, + action: 'process_approval' + }); return new Response( JSON.stringify({ error: 'Unauthorized' }), { @@ -59,13 +66,24 @@ const handler = async (req: Request) => { ); } - console.log(`[${requestId}] Approval request from moderator ${user.id}`); + edgeLogger.info('Approval request received', { + requestId, + moderatorId: user.id, + action: 'process_approval' + }); // STEP 2: Parse request const body: ApprovalRequest = await req.json(); const { submissionId, itemIds, idempotencyKey } = body; if (!submissionId || !itemIds || itemIds.length === 0) { + edgeLogger.warn('Invalid request payload', { + requestId, + hasSubmissionId: !!submissionId, + hasItemIds: !!itemIds, + itemCount: itemIds?.length || 0, + action: 'process_approval' + }); return new Response( JSON.stringify({ error: 'Missing required fields: submissionId, itemIds' }), { @@ -78,6 +96,13 @@ const handler = async (req: Request) => { ); } + edgeLogger.info('Request validated', { + requestId, + submissionId, + itemCount: itemIds.length, + action: 'process_approval' + }); + // STEP 3: Idempotency check const { data: existingKey } = await supabase .from('submission_idempotency_keys') @@ -86,7 +111,12 @@ const handler = async (req: Request) => { .single(); if (existingKey?.status === 'completed') { - console.log(`[${requestId}] Idempotency key already processed, returning cached result`); + edgeLogger.info('Idempotency cache hit', { + requestId, + idempotencyKey, + cached: true, + action: 'process_approval' + }); return new Response( JSON.stringify(existingKey.result_data), { @@ -108,7 +138,12 @@ const handler = async (req: Request) => { .single(); if (submissionError || !submission) { - console.error(`[${requestId}] Submission not found:`, submissionError); + edgeLogger.error('Submission not found', { + requestId, + submissionId, + error: submissionError?.message, + action: 'process_approval' + }); return new Response( JSON.stringify({ error: 'Submission not found' }), { @@ -123,7 +158,13 @@ const handler = async (req: Request) => { // STEP 5: Verify moderator can approve this submission if (submission.assigned_to && submission.assigned_to !== user.id) { - console.error(`[${requestId}] Submission locked by another moderator`); + edgeLogger.warn('Lock conflict', { + requestId, + submissionId, + lockedBy: submission.assigned_to, + attemptedBy: user.id, + action: 'process_approval' + }); return new Response( JSON.stringify({ error: 'Submission is locked by another moderator' }), { @@ -137,7 +178,13 @@ const handler = async (req: Request) => { } if (!['pending', 'partially_approved'].includes(submission.status)) { - console.error(`[${requestId}] Invalid submission status: ${submission.status}`); + edgeLogger.warn('Invalid submission status', { + requestId, + submissionId, + currentStatus: submission.status, + expectedStatuses: ['pending', 'partially_approved'], + action: 'process_approval' + }); return new Response( JSON.stringify({ error: 'Submission already processed' }), { @@ -160,7 +207,12 @@ const handler = async (req: Request) => { }); } - console.log(`[${requestId}] Calling process_approval_transaction RPC`); + edgeLogger.info('Calling approval transaction RPC', { + requestId, + submissionId, + itemCount: itemIds.length, + action: 'process_approval' + }); // ============================================================================ // STEP 7: Call RPC function with deadlock retry logic @@ -194,12 +246,23 @@ const handler = async (req: Request) => { if (rpcError.code === '40P01' || rpcError.code === '40001') { retryCount++; if (retryCount > MAX_DEADLOCK_RETRIES) { - console.error(`[${requestId}] Max deadlock retries exceeded`); + edgeLogger.error('Max deadlock retries exceeded', { + requestId, + submissionId, + attempt: retryCount, + action: 'process_approval' + }); break; } const backoffMs = 100 * Math.pow(2, retryCount); - console.log(`[${requestId}] Deadlock detected, retrying in ${backoffMs}ms (attempt ${retryCount}/${MAX_DEADLOCK_RETRIES})`); + edgeLogger.warn('Deadlock detected, retrying', { + requestId, + attempt: retryCount, + maxAttempts: MAX_DEADLOCK_RETRIES, + backoffMs, + action: 'process_approval' + }); await new Promise(r => setTimeout(r, backoffMs)); continue; } @@ -210,7 +273,16 @@ const handler = async (req: Request) => { if (rpcError) { // Transaction failed - EVERYTHING rolled back automatically by PostgreSQL - console.error(`[${requestId}] Approval transaction failed:`, rpcError); + const duration = endRequest(tracking); + edgeLogger.error('Transaction failed', { + requestId, + duration, + submissionId, + error: rpcError.message, + errorCode: rpcError.code, + retries: retryCount, + action: 'process_approval' + }); // Update idempotency key to failed try { @@ -223,7 +295,13 @@ const handler = async (req: Request) => { }) .eq('idempotency_key', idempotencyKey); } catch (updateError) { - console.error(`[${requestId}] Failed to update idempotency key to failed:`, updateError); + edgeLogger.warn('Failed to update idempotency key', { + requestId, + idempotencyKey, + status: 'failed', + error: updateError instanceof Error ? updateError.message : String(updateError), + action: 'process_approval' + }); // Non-blocking - continue with error response even if idempotency update fails } @@ -244,7 +322,16 @@ const handler = async (req: Request) => { ); } - console.log(`[${requestId}] Transaction completed successfully:`, result); + const duration = endRequest(tracking); + edgeLogger.info('Transaction completed successfully', { + requestId, + duration, + submissionId, + itemCount: itemIds.length, + retries: retryCount, + newStatus: result?.status, + action: 'process_approval' + }); // STEP 8: Success - update idempotency key try { @@ -257,7 +344,13 @@ const handler = async (req: Request) => { }) .eq('idempotency_key', idempotencyKey); } catch (updateError) { - console.error(`[${requestId}] Failed to update idempotency key to completed:`, updateError); + edgeLogger.warn('Failed to update idempotency key', { + requestId, + idempotencyKey, + status: 'completed', + error: updateError instanceof Error ? updateError.message : String(updateError), + action: 'process_approval' + }); // Non-blocking - transaction succeeded, so continue with success response } @@ -274,7 +367,14 @@ const handler = async (req: Request) => { ); } catch (error) { - console.error(`[${requestId}] Unexpected error:`, error); + const duration = endRequest(tracking); + edgeLogger.error('Unexpected error', { + requestId, + duration, + error: error instanceof Error ? error.message : String(error), + stack: error instanceof Error ? error.stack : undefined, + action: 'process_approval' + }); return new Response( JSON.stringify({ error: 'Internal server error', diff --git a/supabase/functions/process-selective-rejection/index.ts b/supabase/functions/process-selective-rejection/index.ts index 6cf548b5..b32d11d5 100644 --- a/supabase/functions/process-selective-rejection/index.ts +++ b/supabase/functions/process-selective-rejection/index.ts @@ -2,6 +2,7 @@ import { serve } from 'https://deno.land/std@0.168.0/http/server.ts'; import { createClient } from 'https://esm.sh/@supabase/supabase-js@2.57.4'; import { corsHeaders } from './cors.ts'; import { rateLimiters, withRateLimit } from '../_shared/rateLimiter.ts'; +import { edgeLogger, startRequest, endRequest, type RequestTracking } from '../_shared/logger.ts'; const SUPABASE_URL = Deno.env.get('SUPABASE_URL') || 'https://api.thrillwiki.com'; const SUPABASE_ANON_KEY = Deno.env.get('SUPABASE_ANON_KEY')!; @@ -23,8 +24,9 @@ const handler = async (req: Request) => { }); } - // Generate request ID for tracking - const requestId = crypto.randomUUID(); + // Start request tracking + const tracking: RequestTracking = startRequest(); + const requestId = tracking.requestId; try { // STEP 1: Authentication @@ -48,6 +50,11 @@ const handler = async (req: Request) => { const { data: { user }, error: authError } = await supabase.auth.getUser(); if (authError || !user) { + edgeLogger.warn('Authentication failed', { + requestId, + error: authError?.message, + action: 'process_rejection' + }); return new Response( JSON.stringify({ error: 'Unauthorized' }), { @@ -60,13 +67,25 @@ const handler = async (req: Request) => { ); } - console.log(`[${requestId}] Rejection request from moderator ${user.id}`); + edgeLogger.info('Rejection request received', { + requestId, + moderatorId: user.id, + action: 'process_rejection' + }); // STEP 2: Parse request const body: RejectionRequest = await req.json(); const { submissionId, itemIds, rejectionReason, idempotencyKey } = body; if (!submissionId || !itemIds || itemIds.length === 0 || !rejectionReason) { + edgeLogger.warn('Invalid request payload', { + requestId, + hasSubmissionId: !!submissionId, + hasItemIds: !!itemIds, + itemCount: itemIds?.length || 0, + hasReason: !!rejectionReason, + action: 'process_rejection' + }); return new Response( JSON.stringify({ error: 'Missing required fields: submissionId, itemIds, rejectionReason' }), { @@ -79,6 +98,13 @@ const handler = async (req: Request) => { ); } + edgeLogger.info('Request validated', { + requestId, + submissionId, + itemCount: itemIds.length, + action: 'process_rejection' + }); + // STEP 3: Idempotency check const { data: existingKey } = await supabase .from('submission_idempotency_keys') @@ -87,7 +113,12 @@ const handler = async (req: Request) => { .single(); if (existingKey?.status === 'completed') { - console.log(`[${requestId}] Idempotency key already processed, returning cached result`); + edgeLogger.info('Idempotency cache hit', { + requestId, + idempotencyKey, + cached: true, + action: 'process_rejection' + }); return new Response( JSON.stringify(existingKey.result_data), { @@ -109,7 +140,12 @@ const handler = async (req: Request) => { .single(); if (submissionError || !submission) { - console.error(`[${requestId}] Submission not found:`, submissionError); + edgeLogger.error('Submission not found', { + requestId, + submissionId, + error: submissionError?.message, + action: 'process_rejection' + }); return new Response( JSON.stringify({ error: 'Submission not found' }), { @@ -124,7 +160,13 @@ const handler = async (req: Request) => { // STEP 5: Verify moderator can reject this submission if (submission.assigned_to && submission.assigned_to !== user.id) { - console.error(`[${requestId}] Submission locked by another moderator`); + edgeLogger.warn('Lock conflict', { + requestId, + submissionId, + lockedBy: submission.assigned_to, + attemptedBy: user.id, + action: 'process_rejection' + }); return new Response( JSON.stringify({ error: 'Submission is locked by another moderator' }), { @@ -138,7 +180,13 @@ const handler = async (req: Request) => { } if (!['pending', 'partially_approved'].includes(submission.status)) { - console.error(`[${requestId}] Invalid submission status: ${submission.status}`); + edgeLogger.warn('Invalid submission status', { + requestId, + submissionId, + currentStatus: submission.status, + expectedStatuses: ['pending', 'partially_approved'], + action: 'process_rejection' + }); return new Response( JSON.stringify({ error: 'Submission already processed' }), { @@ -161,7 +209,12 @@ const handler = async (req: Request) => { }); } - console.log(`[${requestId}] Calling process_rejection_transaction RPC`); + edgeLogger.info('Calling rejection transaction RPC', { + requestId, + submissionId, + itemCount: itemIds.length, + action: 'process_rejection' + }); // ============================================================================ // STEP 7: Call RPC function with deadlock retry logic @@ -195,12 +248,23 @@ const handler = async (req: Request) => { if (rpcError.code === '40P01' || rpcError.code === '40001') { retryCount++; if (retryCount > MAX_DEADLOCK_RETRIES) { - console.error(`[${requestId}] Max deadlock retries exceeded`); + edgeLogger.error('Max deadlock retries exceeded', { + requestId, + submissionId, + attempt: retryCount, + action: 'process_rejection' + }); break; } const backoffMs = 100 * Math.pow(2, retryCount); - console.log(`[${requestId}] Deadlock detected, retrying in ${backoffMs}ms (attempt ${retryCount}/${MAX_DEADLOCK_RETRIES})`); + edgeLogger.warn('Deadlock detected, retrying', { + requestId, + attempt: retryCount, + maxAttempts: MAX_DEADLOCK_RETRIES, + backoffMs, + action: 'process_rejection' + }); await new Promise(r => setTimeout(r, backoffMs)); continue; } @@ -211,7 +275,16 @@ const handler = async (req: Request) => { if (rpcError) { // Transaction failed - EVERYTHING rolled back automatically by PostgreSQL - console.error(`[${requestId}] Rejection transaction failed:`, rpcError); + const duration = endRequest(tracking); + edgeLogger.error('Transaction failed', { + requestId, + duration, + submissionId, + error: rpcError.message, + errorCode: rpcError.code, + retries: retryCount, + action: 'process_rejection' + }); // Update idempotency key to failed try { @@ -224,7 +297,13 @@ const handler = async (req: Request) => { }) .eq('idempotency_key', idempotencyKey); } catch (updateError) { - console.error(`[${requestId}] Failed to update idempotency key to failed:`, updateError); + edgeLogger.warn('Failed to update idempotency key', { + requestId, + idempotencyKey, + status: 'failed', + error: updateError instanceof Error ? updateError.message : String(updateError), + action: 'process_rejection' + }); // Non-blocking - continue with error response even if idempotency update fails } @@ -245,7 +324,16 @@ const handler = async (req: Request) => { ); } - console.log(`[${requestId}] Transaction completed successfully:`, result); + const duration = endRequest(tracking); + edgeLogger.info('Transaction completed successfully', { + requestId, + duration, + submissionId, + itemCount: itemIds.length, + retries: retryCount, + newStatus: result?.status, + action: 'process_rejection' + }); // STEP 8: Success - update idempotency key try { @@ -258,7 +346,13 @@ const handler = async (req: Request) => { }) .eq('idempotency_key', idempotencyKey); } catch (updateError) { - console.error(`[${requestId}] Failed to update idempotency key to completed:`, updateError); + edgeLogger.warn('Failed to update idempotency key', { + requestId, + idempotencyKey, + status: 'completed', + error: updateError instanceof Error ? updateError.message : String(updateError), + action: 'process_rejection' + }); // Non-blocking - transaction succeeded, so continue with success response } @@ -275,7 +369,14 @@ const handler = async (req: Request) => { ); } catch (error) { - console.error(`[${requestId}] Unexpected error:`, error); + const duration = endRequest(tracking); + edgeLogger.error('Unexpected error', { + requestId, + duration, + error: error instanceof Error ? error.message : String(error), + stack: error instanceof Error ? error.stack : undefined, + action: 'process_rejection' + }); return new Response( JSON.stringify({ error: 'Internal server error',