feat: add performance metrics logging to SR worker

Restore structured performance metrics logging that was present in
the original echo worker, enabling E2E latency tracking and component
breakdown analysis in CloudWatch.

Implementation matches the original echo/index.ts pattern from PR #18:
- SR worker collects timing metrics and logs 'Performance metrics'
- Handler returns syncResponseMs and asyncResponseMs
- Worker calculates E2E, queue wait, and total duration
- Metrics logged for both success and failure cases

Performance metrics fields:
- totalE2eMs: API Gateway → final response (end-to-end)
- workerDurationMs: Lambda execution time
- queueWaitMs: Time message spent in SQS (calculated)
- syncResponseMs: Sync Slack response time (from handler)
- asyncResponseMs: Async Slack response time (from handler)
- component: 'sr-worker' for CloudWatch filtering
- correlationId, command, success, errorType, errorMessage

Changes:
- Removed artificial 2-second sleep delay from echo handler
- Echo handler now returns HandlerResult with timing metrics
- SR worker logs structured metrics via logWorkerMetrics()

This restores server-side metrics collection after the quadrant-based
refactor, enabling performance test analysis scripts to work correctly.

Author: llama90

applications/chatops/slack-bot/src/workers/handlers/echo.ts

@@ -5,12 +5,28 @@ import { logger } from '../../shared/logger';
 import { sendSlackResponse } from '../../shared/slack-client';
 import { WorkerMessage } from '../../shared/types';
 
+/**
+ * Handler result with performance metrics
+ */
+interface HandlerResult {
+  syncResponseMs?: number;
+  asyncResponseMs?: number;
+}
+
 /**
  * Handle echo command
  * Sends synchronous and asynchronous responses to Slack
+ *
+ * @param message - Worker message from SQS
+ * @param messageId - SQS message ID
+ * @returns Performance metrics for the worker to log
  */
-export async function handleEcho(message: WorkerMessage, messageId: string): Promise<void> {
-  const startTime = Date.now();
+export async function handleEcho(
+  message: WorkerMessage,
+  messageId: string
+): Promise<HandlerResult> {
+  let syncResponseMs: number | undefined;
+  let asyncResponseMs: number | undefined;
 
   // Create child logger with correlation ID for request tracing
   const messageLogger = logger.child(message.correlation_id || messageId, {
@@ -44,15 +60,12 @@ export async function handleEcho(message: WorkerMessage, messageId: string): Pro
       response_type: 'in_channel',
       text: `sync ${message.text}`,
     });
-    const syncDuration = Date.now() - syncStart;
+    syncResponseMs = Date.now() - syncStart;
 
     messageLogger.info('Sync response sent', {
-      duration: syncDuration,
+      duration: syncResponseMs,
     });
 
-    // Simulate some async work
-    await new Promise((resolve) => setTimeout(resolve, 2000));
-
     // Send asynchronous response
     const asyncStart = Date.now();
     await sendSlackResponse(message.response_url, {
@@ -77,19 +90,21 @@ export async function handleEcho(message: WorkerMessage, messageId: string): Pro
         },
       ],
     });
-    const asyncDuration = Date.now() - asyncStart;
+    asyncResponseMs = Date.now() - asyncStart;
 
     messageLogger.info('Async response sent', {
-      duration: asyncDuration,
+      duration: asyncResponseMs,
     });
 
     subsegment?.close();
 
-    const totalDuration = Date.now() - startTime;
+    messageLogger.info('Echo command processed successfully');
 
-    messageLogger.info('Echo command processed successfully', {
-      totalDuration,
-    });
+    // Return performance metrics for the worker to log
+    return {
+      syncResponseMs,
+      asyncResponseMs,
+    };
   } catch (error) {
     subsegment?.addError(error as Error);
     subsegment?.close();

applications/chatops/slack-bot/src/workers/sr/index.ts

@@ -9,11 +9,43 @@ import { handleEcho } from '../handlers/echo';
 // import { handleStatus } from '../handlers/status';
 // import { handleHelp } from '../handlers/help';
 
+/**
+ * Log worker performance metrics for monitoring and analysis
+ */
+function logWorkerMetrics(params: {
+  correlationId?: string;
+  command?: string;
+  totalE2eMs?: number;
+  workerDurationMs: number;
+  queueWaitMs?: number;
+  syncResponseMs?: number;
+  asyncResponseMs?: number;
+  success: boolean;
+  errorType?: string;
+  errorMessage?: string;
+}) {
+  logger.info('Performance metrics', {
+    ...params,
+    component: 'sr-worker', // Add component identifier for filtering
+  });
+}
+
+/**
+ * Handler result with performance metrics
+ */
+interface HandlerResult {
+  syncResponseMs?: number;
+  asyncResponseMs?: number;
+}
+
 /**
  * Command handler registry
  * Maps command names to their handler functions
  */
-const COMMAND_HANDLERS: Record<string, (message: WorkerMessage, messageId: string) => Promise<void>> = {
+const COMMAND_HANDLERS: Record<
+  string,
+  (message: WorkerMessage, messageId: string) => Promise<HandlerResult>
+> = {
   '/echo': handleEcho,
   // Add new short-read commands here (no infrastructure changes needed!)
   // '/status': handleStatus,
@@ -35,10 +67,11 @@ export async function handler(event: SQSEvent): Promise<SQSBatchResponse> {
   for (const record of event.Records) {
     const startTime = Date.now();
     let messageLogger = logger;
+    let correlationId: string | undefined;
 
     try {
       const message: WorkerMessage = JSON.parse(record.body);
-      const correlationId = message.correlation_id;
+      correlationId = message.correlation_id;
 
       // Create child logger with correlation ID for request tracing
       messageLogger = logger.child(correlationId || record.messageId, {
@@ -70,23 +103,50 @@ export async function handler(event: SQSEvent): Promise<SQSBatchResponse> {
         throw new Error(errorMsg);
       }
 
-      // Execute handler
-      await handler(message, record.messageId);
+      // Execute handler and get performance metrics
+      const handlerResult = await handler(message, record.messageId);
+
+      const totalDuration = Date.now() - startTime;
+      const e2eDuration = message.api_gateway_start_time
+        ? Date.now() - message.api_gateway_start_time
+        : undefined;
+
+      // Log structured performance metrics for CloudWatch Insights analysis
+      logWorkerMetrics({
+        correlationId,
+        command: message.command,
+        totalE2eMs: e2eDuration,
+        workerDurationMs: totalDuration,
+        queueWaitMs: e2eDuration ? Math.max(0, e2eDuration - totalDuration) : undefined,
+        syncResponseMs: handlerResult.syncResponseMs,
+        asyncResponseMs: handlerResult.asyncResponseMs,
+        success: true,
+      });
 
-      const duration = Date.now() - startTime;
       messageLogger.info('Command processed successfully', {
         command: message.command,
-        duration,
+        duration: totalDuration,
+        e2eDuration,
       });
 
     } catch (error) {
       const duration = Date.now() - startTime;
+      const err = error as Error;
 
-      messageLogger.error('Failed to process command', error as Error, {
+      messageLogger.error('Failed to process command', err, {
         messageId: record.messageId,
         duration,
       });
 
+      // Log performance metrics even for failures
+      logWorkerMetrics({
+        correlationId,
+        workerDurationMs: duration,
+        success: false,
+        errorType: err.name,
+        errorMessage: err.message,
+      });
+
       // Add to failed items for retry
       batchItemFailures.push({ itemIdentifier: record.messageId });
     }