improvement(webhooks): decompose dispatch latency into phase timings + executor-start metric

The "Webhook dispatch latency" line now carries preprocessMs/loadsMs/
providerConfigMs/formatInputMs, and a one-shot onBlockStart callback logs
"Webhook executor started" with the true trigger age when the first block
runs — the moment that decides a trigger_id-bound provider's 3s race,
which the existing metric (emitted before executeWorkflowCore) undercounts.

Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>

Author: icecrasher321

apps/sim/background/webhook-execution.ts

@@ -493,6 +493,7 @@ async function executeWebhookJobInternal(
   )
   loggingSession.setExecutionDeadlineAt(getExecutionDeadlineAt(timeoutController.signal))
 
+  const preprocessStartedAt = Date.now()
   const preprocessResult = await preprocessExecution({
     workflowId: payload.workflowId,
     userId: payload.userId,
@@ -509,6 +510,7 @@ async function executeWebhookJobInternal(
     executionType: 'async',
     executionDeadlineAt: getExecutionDeadlineAt(timeoutController.signal)?.getTime(),
   })
+  const preprocessEndedAt = Date.now()
 
   if (!preprocessResult.success) {
     throw new Error(preprocessResult.error?.message || 'Preprocessing failed in background job')
@@ -564,6 +566,7 @@ async function executeWebhookJobInternal(
         ? resolveCredentialAccountUserId(payload.credentialId)
         : Promise.resolve(undefined),
     ])
+    const loadsEndedAt = Date.now()
     const credentialAccountUserId = resolvedCredentialUserId
     if (payload.credentialId && !credentialAccountUserId) {
       logger.warn(
@@ -626,6 +629,7 @@ async function executeWebhookJobInternal(
         },
       }
     )
+    const providerConfigEndedAt = Date.now()
 
     if (handler.formatInput) {
       const result = await handler.formatInput({
@@ -642,6 +646,7 @@ async function executeWebhookJobInternal(
     } else {
       input = payload.body as Record<string, unknown> | null
     }
+    const formatInputEndedAt = Date.now()
 
     if (!input && handler.handleEmptyInput) {
       const skipResult = handler.handleEmptyInput(requestId)
@@ -791,6 +796,10 @@ async function executeWebhookJobInternal(
           payload.webhookReceivedAt !== undefined ? now - payload.webhookReceivedAt : undefined,
         triggerAgeMs:
           payload.triggerTimestampMs !== undefined ? now - payload.triggerTimestampMs : undefined,
+        preprocessMs: preprocessEndedAt - preprocessStartedAt,
+        loadsMs: loadsEndedAt - preprocessEndedAt,
+        providerConfigMs: providerConfigEndedAt - loadsEndedAt,
+        formatInputMs: formatInputEndedAt - providerConfigEndedAt,
       })
     }
 
@@ -802,9 +811,33 @@ async function executeWebhookJobInternal(
       []
     )
 
+    /**
+     * The dispatch-latency line above fires before executeWorkflowCore, so it cannot
+     * see the core's own setup (custom-block gate, env resolution, logging start,
+     * serialization). This logs once, when the first block actually starts — the
+     * moment that decides a trigger_id-bound provider's race against its expiry.
+     */
+    let executorStartLogged = false
+    const logExecutorStart = async () => {
+      if (executorStartLogged) return
+      executorStartLogged = true
+      if (payload.webhookReceivedAt === undefined && payload.triggerTimestampMs === undefined) {
+        return
+      }
+      const now = Date.now()
+      logger.info(`[${requestId}] Webhook executor started`, {
+        workflowId: payload.workflowId,
+        provider: payload.provider,
+        executorStartLatencyMs:
+          payload.webhookReceivedAt !== undefined ? now - payload.webhookReceivedAt : undefined,
+        executorStartTriggerAgeMs:
+          payload.triggerTimestampMs !== undefined ? now - payload.triggerTimestampMs : undefined,
+      })
+    }
+
     const executionResult = await executeWorkflowCore({
       snapshot,
-      callbacks: {},
+      callbacks: { onBlockStart: logExecutorStart },
       loggingSession,
       trustedInitialResolvedSecretTraceProvenance:
         resolvedSecretTraceRegistry.exportProvenanceForValue(triggerInput),