Skip to content

Add messageId and requestId context to all mothership log messages#3770

Merged
TheodoreSpeaks merged 1 commit intostagingfrom
debug/add-mothership-logs
Mar 25, 2026
Merged

Add messageId and requestId context to all mothership log messages#3770
TheodoreSpeaks merged 1 commit intostagingfrom
debug/add-mothership-logs

Conversation

@TheodoreSpeaks
Copy link
Collaborator

Summary

We have some race condition happening between copilot and sim. Added logging to help debug, appending messageId and requestId as context

Type of Change

  • Bug fix
  • New feature
  • Breaking change
  • Documentation
  • Other: ___________

Testing

Validated logs exist and show correct message id.

Checklist

  • Code follows project style guidelines
  • Self-reviewed my changes
  • Tests added/updated and passing
  • No new warnings introduced
  • I confirm that I have read and agree to the terms outlined in the Contributor License Agreement (CLA)

Screenshots/Videos

@vercel
Copy link

vercel bot commented Mar 25, 2026

The latest updates on your projects. Learn more about Vercel for GitHub.

1 Skipped Deployment
Project Deployment Actions Updated (UTC)
docs Skipped Skipped Mar 25, 2026 9:22pm

Request Review

@cursor
Copy link

cursor bot commented Mar 25, 2026

PR Summary

Medium Risk
Moderate risk because it threads a new messageId through core copilot orchestration/tool execution paths and changes helper function signatures; while behavior is intended to be logging-only, any missed callsites could cause runtime or typing issues.

Overview
Adds a small logging utility (appendCopilotLogContext) and updates copilot/mothership API routes, streaming resume, orchestration loops, and server tool execution to consistently tag logs with requestId and a per-message messageId.

Plumbs messageId through request payload construction (buildIntegrationToolSchemas), orchestration context (ExecutionContext/ServerToolContext), title generation, and tool completion reporting (markToolComplete) so failures and races can be correlated end-to-end.

Written by Cursor Bugbot for commit 55c1a05. This will update automatically on new commits. Configure here.

@TheodoreSpeaks TheodoreSpeaks merged commit 87e8d3c into staging Mar 25, 2026
12 checks passed
@greptile-apps
Copy link
Contributor

greptile-apps bot commented Mar 25, 2026

Greptile Summary

This PR adds messageId and requestId context to all copilot/mothership log messages by introducing a new appendCopilotLogContext utility and propagating the IDs through 24 files. The goal is to correlate log entries across the copilot ↔ sim race condition that was difficult to debug previously.

Key changes:

  • New apps/sim/lib/copilot/logging.ts with a single appendCopilotLogContext(message, context) helper that appends [requestId:xxx messageId:yyy] as a string suffix.
  • ExecutionContext gains an optional messageId field so tool-executor and server-side tools can include it in their logs.
  • markToolComplete, reportCancelledTool, handleClientCompletion, and emitSyntheticToolResult all receive messageId as a new trailing parameter.
  • Routes that previously generated a fresh crypto.randomUUID() inline for messageId now capture the UUID in a variable first, so the same ID is used for both the orchestrator call and any associated log statements.
  • The test in handlers.test.ts is correctly updated to expect the messageId ('msg-1' from the beforeEach context) as the last argument to markToolComplete.

The implementation is mechanically consistent and correct. One style observation: the IDs are embedded into the message string rather than passed as structured log metadata (see inline comment), which may affect log aggregation/alerting depending on the team's observability tooling.

Confidence Score: 5/5

  • Safe to merge — purely additive logging changes with no behavioral impact on request handling.
  • All changes are confined to log statements and ID-propagation plumbing. No business logic, database queries, or API contracts are modified. The new markToolComplete/reportCancelledTool signatures add an optional trailing messageId parameter, so all existing callers without the argument continue to work. The test is updated correctly. The one style suggestion (structured metadata vs. message-string embedding) is non-blocking.
  • No files require special attention.

Important Files Changed

Filename Overview
apps/sim/lib/copilot/logging.ts New utility file that appends requestId and messageId as a formatted suffix to log message strings; works correctly but embeds context into the message string rather than structured log metadata.
apps/sim/app/api/copilot/chat/route.ts All log calls updated to include requestId/messageId context; error catch block correctly uses pendingChatStreamID as a fallback messageId (since userMessageIdToUse is scoped inside the try block).
apps/sim/app/api/mothership/chat/route.ts Clean pattern: declares userMessageIdForLogs outside the try block so it's accessible in the catch handler; all log calls updated consistently.
apps/sim/app/api/mothership/execute/route.ts messageId is now generated once (crypto.randomUUID()) before the parallel operations and reused for both buildIntegrationToolSchemas and orchestrateCopilotStream, which is correct.
apps/sim/lib/copilot/orchestrator/index.ts messageId is extracted once from requestPayload (with UUID fallback) and set on execContext; withLogContext helper reduces repetition; many new operational log points added for orchestration lifecycle.
apps/sim/lib/copilot/orchestrator/sse/handlers/handlers.ts handleClientCompletion and emitSyntheticToolResult signatures updated to accept StreamingContext for messageId propagation; all markToolComplete calls pass messageId correctly.
apps/sim/lib/copilot/orchestrator/sse/handlers/handlers.test.ts Test correctly updated to expect 'msg-1' (context.messageId from beforeEach setup) as the new last argument to markToolComplete.
apps/sim/lib/copilot/orchestrator/tool-executor/index.ts markToolComplete signature extended with optional messageId parameter; messageId passed from ExecutionContext through executeServerToolDirect and all call sites; all log calls updated consistently.
apps/sim/lib/copilot/orchestrator/types.ts messageId added as optional field to ExecutionContext interface, enabling context propagation through the tool execution chain.
apps/sim/lib/copilot/chat-streaming.ts messageId derived from requestPayload.messageId (falling back to streamId) and propagated into all log calls; requestChatTitle now also receives messageId.
apps/sim/lib/copilot/orchestrator/sse/handlers/tool-execution.ts reportCancelledTool signature updated with messageId parameter; all call sites correctly pass context.messageId; all log calls updated consistently.

Sequence Diagram

sequenceDiagram
    participant Client
    participant ChatRoute as copilot/chat route
    participant Orchestrator as orchestrateCopilotStream
    participant SSEHandlers as SSE Handlers
    participant ToolExec as executeToolAndReport
    participant GoBackend as Go Agent Backend

    Client->>ChatRoute: POST /api/copilot/chat (messageId?)
    Note over ChatRoute: userMessageIdToUse = messageId || uuid()
    ChatRoute->>ChatRoute: log("Received chat POST" [requestId messageId])
    ChatRoute->>Orchestrator: orchestrateCopilotStream(payload{messageId})
    Note over Orchestrator: messageId = payload.messageId || uuid()<br/>execContext.messageId = messageId
    Orchestrator->>Orchestrator: log("Starting copilot orchestration" [requestId messageId])
    Orchestrator->>GoBackend: SSE stream request
    GoBackend-->>SSEHandlers: tool_call event
    Note over SSEHandlers: context.messageId propagated
    SSEHandlers->>ToolExec: executeToolAndReport(toolCallId, context)
    ToolExec->>ToolExec: log("Tool execution started" [messageId])
    ToolExec->>GoBackend: markToolComplete(toolCallId, ..., messageId)
    GoBackend-->>SSEHandlers: stream_end
    Orchestrator->>ChatRoute: OrchestratorResult
    ChatRoute->>Client: JSON response
Loading

Reviews (1): Last reviewed commit: "Add messageId and requestId context to a..." | Re-trigger Greptile

return message
}

return `${message} [${suffixParts.join(' ')}]`
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

P2 Consider structured metadata over message-string embedding

appendCopilotLogContext appends requestId and messageId directly into the log message string (e.g. "Tool execution started [requestId:abc messageId:xyz]"). Many structured log systems (Datadog, CloudWatch Insights, etc.) index on the raw message text, meaning each unique ID combination creates a new distinct log "fingerprint." This can make template-based alerting harder and increase log cardinality in the index.

A common alternative is to pass the IDs as structured metadata alongside the message:

// Instead of:
logger.info(appendCopilotLogContext('Tool execution started', { requestId, messageId }), { toolCallId })

// Consider:
logger.info('Tool execution started', { requestId, messageId, toolCallId })

This keeps the message template stable while still making both IDs searchable. If the current log aggregation pipeline works better with IDs in the message text (e.g. for plain-text grep), this is fine to keep as-is — just worth flagging for awareness.

Note: If this suggestion doesn't match your team's coding style, reply to this and let me know. I'll remember it for next time!

@waleedlatif1 waleedlatif1 deleted the debug/add-mothership-logs branch March 25, 2026 23:12
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

1 participant