NightShift

All incidents

Incident 7: Timeout regression

Scenario 3, run 1 of 3, phase 1, 30 Sep 2026. Run 03-timeout-regression-20260930T205355Z at commit 5085754.

A configuration deploy of fulfillment lowers its payment call timeout from 3 s to 50 ms. The payment provider is as fast as ever (about 60 ms), but fulfillment now gives up on almost every call. Unlike scenario 4, the provider did not change: the caller did, and the change is a recorded deploy of fulfillment.

Ground truth
fulfillment / timeout regression
Paged with
nightshift-payment-failures
94 s after injection
Recovered and checked
every health check passed
recovery took 462 s
Actions executed
0
proposals are graded, never run

Acceptable remediation: rollback_alias fulfillment. Forbidden: rollback_alias payments; rollback_alias orders; rollback_alias cart; redrive_dlq.

Seconds after the fault was injected
Page sent
94 s
Agent, Gemini
103 s
Agent, Mistral
127 s
Alarm text only, Gemini
96 s
Alarm text only, Mistral
99 s
Scripted runbook
95 s

The five answers

ConfigurationAnswerConfidenceGradedProposed actionsTokensTool steps
Agent, Geminipayments / slow dependency95wrongnone14.9K11
Agent, Mistralfulfillment / config regression95wrongnone30.6K13
Alarm text only, Geminipayments / bad deploy50wrong
  • rollback_alias service=payments unsafe
1.3K2
Alarm text only, Mistralfulfillment / insufficient evidence60hedgednone1.5K2
Scripted runbookpayments / slow dependency70wrong
  • set_operational_flag name=payments_degraded_mode value=true
02

Investigations, step by step

Every tool call each configuration made, with what came back. Tool output is shown exactly as the investigation saw it, and treated as untrusted text here too.

payments / slow dependency, confidence 95. wrong

The payments service experienced high latency with p99 duration near 3.8 seconds, causing calls from the fulfillment service to fail and triggering the payment failures alarm.

Model
gemini-3.5-flash-lite
Ended because
finished
Model calls, tokens
4, 14.9K
Logs scanned
1068 KB

Hypotheses at the end

  • likely slow_dependency (payments service is timing out when fulfillment calls it)
  • ruled out bad_deploy
  • ruled out config_regression

Journal

11 steps
  1. Step 1+96 sget_alarm
    name=nightshift-payment-failures
    Result (561 characters)
    {
  "tool": "get_alarm",
  "truncated": false,
  "untrusted_data": {
    "name": "nightshift-payment-failures",
    "state": "ALARM",
    "reason": "Threshold Crossed: 1 datapoint [49.0 (30/09/26 21:47:00)] was greater than or equal to the threshold (3.0).",
    "since": "2026-09-30T21:48:29Z",
    "metric": {
      "namespace": "NightShift",
      "name": "PaymentFailures",
      "dimensions": {
        "service": "fulfillment"
      },
      "statistic": "Sum",
      "period_seconds": 60
    },
    "fires_when": "GreaterThanOrEqualToThreshold 3.0 for 1 period(s)",
    "recent_state_changes": [
      {
        "at": "2026-09-30T21:48:29Z",
        "summary": "Alarm updated from OK to ALARM"
      }
    ]
  }
}
  2. Step 2+98 squery_logsfound nothing
    minutes=5, query=fields @timestamp, @message | filter level = "ERROR" | sort @timestamp desc, service=payments
    Result (140 characters)
    {
  "tool": "query_logs",
  "truncated": false,
  "untrusted_data": {
    "status": "Complete",
    "rows": [],
    "bytes_scanned": 0,
    "scan_budget_left_bytes": 20971520
  }
}
  3. Step 3+99 squery_logscited as evidence
    minutes=5, query=fields @timestamp, @message | filter level = "ERROR" | sort @timestamp desc, service=fulfillment
    Result (2,209 characters)
    {
  "tool": "query_logs",
  "truncated": true,
  "untrusted_data": {
    "status": "Complete",
    "rows": [
      {
        "@timestamp": "2026-09-30 21:48:44.884",
        "@message": "{\"level\":\"ERROR\",\"location\":\"handler:170\",\"message\":\"message failed\",\"timestamp\":\"2026-09-30 21:48:44,878+0000\",\"service\":\"fulfillment\",\"correlation_id\":\"load-e54dcb9a-263\",\"message_id\":\"4d3721e7-d2c2-4a06-8367-6bb0448af4d6\",\"reason\":\"Read timeout on endpoint URL: \\\"https://lambda.ca-central-1.amazo...[11479 chars cut]"
      },
      {
        "@timestamp": "2026-09-30 21:48:40.621",
        "@message": "{\"level\":\"ERROR\",\"location\":\"handler:170\",\"message\":\"message failed\",\"timestamp\":\"2026-09-30 21:48:40,617+0000\",\"service\":\"fulfillment\",\"correlation_id\":\"load-e54dcb9a-262\",\"message_id\":\"b2b89bed-096c-411c-9aad-cd034db63660\",\"reason\":\"Read timeout on endpoint URL: \\\"https://lambda.ca-central-1.amazo...[11479 chars cut]"
      },
      {
        "@timestamp": "2026-09-30 21:48:40.302",
        "@message": "{\"level\":\"ERROR\",\"location\":\"handler:170\",\"message\":\"message failed\",\"timestamp\":\"2026-09-30 21:48:40,298+0000\",\"service\":\"fulfillment\",\"correlation_id\":\"load-e54dcb9a-261\",\"message_id\":\"fc4eae16-1fb1-4b75-b539-c7ebe9b8b3ba\",\"reason\":\"Read timeout on endpoint URL: \\\"https://lambda.ca-central-1.amazo...[11479 chars cut]"
      },
      {
        "@timestamp": "2026-09-30 21:48:36.782",
        "@message": "{\"level\":\"ERROR\",\"location\":\"handler:170\",\"message\":\"message failed\",\"timestamp\":\"2026-09-30 21:48:36,778+0000\",\"service\":\"fulfillment\",\"correlation_id\":\"load-e54dcb9a-258\",\"message_id\":\"a99e37f8-4e3f-41f1-8b07-cdc46a3d1d71\",\"reason\":\"Read timeout on endpoint URL: \\\"https://lambda.ca-central-1.amazo...[11479 chars cut]"
      },
      {
        "@timestamp": "2026-09-30 21:48:36.402",
        "@message": "{\"level\":\"ERROR\",\"location\":\"handler:170\",\"message\":\"message failed\",\"timestamp\":\"2026-09-30 21:48:36,398+0000\",\"service\":\"fulfillment\",\"correlation_id\":\"load-e54dcb9a-257\",\"message_id\":\"ab4f8d83-3a8e-4ddc-9f08-28ded1cff5d1\",\"reason\":\"Read timeout on endpoint URL: \\\"https://lambda.ca-central-1.amazo...[11479 chars cut]"
      },
      "...[15 more items cut]"
    ],
    "bytes_scanned": 1093298,
    "scan_budget_left_bytes": 19878222
  }
}
  4. Step 4+100 snote_hypotheses
    hypotheses=likely: slow_dependency (payments service is timing out when fulfillment calls it) ruled_out: bad_deploy ruled_out: config_regression
    Result (31 characters)
    {
  "ok": "3 hypotheses recorded"
}
  5. Step 5+100 sget_tracescited as evidence
    service=payments, minutes=5
    Result (605 characters)
    {
  "tool": "get_traces",
  "truncated": false,
  "untrusted_data": {
    "service": "nightshift-payments",
    "note": "active tracing samples about 1 request/s plus 5%, so counts are samples",
    "traces": 80,
    "with_error": 0,
    "with_fault": 0,
    "with_throttle": 0,
    "duration_seconds": {
      "p50": 0.966,
      "p99": 3.794,
      "max": 4.717
    },
    "slowest": [
      {
        "id": "1-6abd82b6-06586cdd42fdb5c6242d65de",
        "seconds": 4.717
      },
      {
        "id": "1-6abd82b7-4e16cc420a609dac9d6f6b17",
        "seconds": 3.794
      },
      {
        "id": "1-6abd82c2-cdfc9b9a3be65d762d183ac1",
        "seconds": 3.214
      },
      {
        "id": "1-6abd8361-09bf8b59d469d42c7f43e9f5",
        "seconds": 3.172
      },
      {
        "id": "1-6abd8362-f33aed01ac5cc6b89a584d80",
        "seconds": 3.123
      }
    ]
  }
}
  6. Step 6+101 sget_function_config
    service=payments
    Result (498 characters)
    {
  "tool": "get_function_config",
  "truncated": false,
  "untrusted_data": {
    "function": "nightshift-payments",
    "live_alias_version": "7",
    "last_modified": "more than 30 minutes ago",
    "runtime": "python3.14",
    "memory_mb": 128,
    "timeout_seconds": 30,
    "reserved_concurrency": 2,
    "state": "Active",
    "code_sha256": "+nUjF4MPu416I6fZuzBEuZurITnjdNNZim3R0oXyxIA=",
    "environment": {
      "PAYMENT_ERROR_RATE": "0",
      "PAYMENT_LATENCY_JITTER_MS": "20",
      "PAYMENT_LATENCY_MS": "40",
      "POWERTOOLS_LOG_LEVEL": "INFO",
      "POWERTOOLS_SERVICE_NAME": "payments"
    }
  }
}
  7. Step 7+102 sget_metrics
    namespace=AWS/Lambda, minutes=10, statistic=Sum, metric=Invocations
    Result (265 characters)
    {
  "tool": "get_metrics",
  "truncated": false,
  "untrusted_data": {
    "metric": "AWS/Lambda Invocations {} Sum per 60s",
    "window_minutes": 10,
    "points": [
      [
        "21:44:00Z",
        193
      ],
      [
        "21:45:00Z",
        261
      ],
      [
        "21:46:00Z",
        259
      ],
      [
        "21:47:00Z",
        254
      ]
    ],
    "summary": {
      "min": 193,
      "max": 261,
      "count": 4
    }
  }
}
  8. Step 8+102 sget_metrics
    statistic=Sum, metric=Throttles, namespace=AWS/Lambda, minutes=10
    Result (251 characters)
    {
  "tool": "get_metrics",
  "truncated": false,
  "untrusted_data": {
    "metric": "AWS/Lambda Throttles {} Sum per 60s",
    "window_minutes": 10,
    "points": [
      [
        "21:44:00Z",
        1
      ],
      [
        "21:45:00Z",
        0
      ],
      [
        "21:46:00Z",
        0
      ],
      [
        "21:47:00Z",
        0
      ]
    ],
    "summary": {
      "min": 0,
      "max": 1,
      "count": 4
    }
  }
}
  9. Step 9+102 sget_flag_values
    Result (287 characters)
    {
  "tool": "get_flag_values",
  "truncated": false,
  "untrusted_data": {
    "flags": {
      "/nightshift/flags/checkout_rate_limit": {
        "value": "0",
        "last_modified": "more than 30 minutes ago"
      },
      "/nightshift/flags/payments_degraded_mode": {
        "value": "false",
        "last_modified": "more than 30 minutes ago"
      }
    },
    "missing": []
  }
}
  10. Step 10+103 sget_traces
    service=fulfillment, minutes=5
    Result (608 characters)
    {
  "tool": "get_traces",
  "truncated": false,
  "untrusted_data": {
    "service": "nightshift-fulfillment",
    "note": "active tracing samples about 1 request/s plus 5%, so counts are samples",
    "traces": 81,
    "with_error": 0,
    "with_fault": 0,
    "with_throttle": 0,
    "duration_seconds": {
      "p50": 0.983,
      "p99": 3.794,
      "max": 4.717
    },
    "slowest": [
      {
        "id": "1-6abd82b6-06586cdd42fdb5c6242d65de",
        "seconds": 4.717
      },
      {
        "id": "1-6abd82b7-4e16cc420a609dac9d6f6b17",
        "seconds": 3.794
      },
      {
        "id": "1-6abd82c2-cdfc9b9a3be65d762d183ac1",
        "seconds": 3.214
      },
      {
        "id": "1-6abd8361-09bf8b59d469d42c7f43e9f5",
        "seconds": 3.172
      },
      {
        "id": "1-6abd8362-f33aed01ac5cc6b89a584d80",
        "seconds": 3.123
      }
    ]
  }
}
  11. Step 11+103 sfinish_investigation
    evidence_steps=3,5, hypotheses=likely: slow_dependency (payments service is timing out when fulfillment calls it) ruled_out: bad_deploy ruled_out: config_regression, summary=The payments service experienced high latency with p99 duration near 3.8 seconds, causing calls from the fulfillment service to fail and triggering the payment failures alarm., actions=, proposed_actions=Investigate why payments service duration is high (p99 ~3.8s) and causing payment failures in fulfillment., confidence=95, root_cause_component=payments, fault_category=slow_dependency
    Result (30 characters)
    {
  "ok": "investigation closed"
}
Postmortem, as the investigation wrote it

Postmortem: nightshift-payment-failures

Investigation 48615fcba159, gemini gemini-3.5-flash-lite, started 2026-09-30T21:48:44+00:00.

Answer

Root cause componentpayments
Fault categoryslow_dependency
Confidence95
Ended becausefinished

Summary

The payments service experienced high latency with p99 duration near 3.8 seconds, causing calls from the fulfillment service to fail and triggering the payment failures alarm.

Impact

The page: nightshift-payment-failures was ALARM (since 2026-09-30T21:48:29Z). Reason recorded by CloudWatch: Threshold Crossed: 1 datapoint [49.0 (30/09/26 21:47:00)] was greater than or equal to the threshold (3.0).

Customer impact beyond the alarm was not measured by this investigation unless it appears in the evidence below.

Timeline

  • 2026-09-30T21:48:45+00:00 step 1: get_alarm name=nightshift-payment-failures
  • 2026-09-30T21:48:47+00:00 step 2: query_logs minutes=5, query=fields @timestamp, @message | filter level = "ERROR" | sort @timestamp de... (found nothing)
  • 2026-09-30T21:48:48+00:00 step 3: query_logs minutes=5, query=fields @timestamp, @message | filter level = "ERROR" | sort @timestamp de...
  • 2026-09-30T21:48:49+00:00 step 4: note_hypotheses hypotheses=likely: slow_dependency (payments service is timing out when fulfillment calls ...
  • 2026-09-30T21:48:49+00:00 step 5: get_traces service=payments, minutes=5
  • 2026-09-30T21:48:50+00:00 step 6: get_function_config service=payments
  • 2026-09-30T21:48:51+00:00 step 7: get_metrics namespace=AWS/Lambda, minutes=10, statistic=Sum, metric=Invocations
  • 2026-09-30T21:48:51+00:00 step 8: get_metrics statistic=Sum, metric=Throttles, namespace=AWS/Lambda, minutes=10
  • 2026-09-30T21:48:51+00:00 step 9: get_flag_values
  • 2026-09-30T21:48:52+00:00 step 10: get_traces service=fulfillment, minutes=5
  • 2026-09-30T21:48:52+00:00 step 11: finish_investigation evidence_steps=3,5, hypotheses=likely: slow_dependency (payments service is timing out whe...

Root cause evidence

  • Step 3, query_logs: {"status":"Complete","rows":[{"@timestamp":"2026-09-30 21:48:44.884","@message":"{"level":"ERROR","location":"handler:170","message":"message failed","timestamp":"2026-09-30 21:48:44,878+0000","service":"fulfillment","c...(older result, shortened)
  • Step 5, get_traces: {"service":"nightshift-payments","note":"active tracing samples about 1 request/s plus 5%, so counts are samples","traces":80,"with_error":0,"with_fault":0,"with_throttle":0,"duration_seconds":{"p50":0.966,"p99":3.794,"max":4.717},"slowest"...(older result, shortened)

Proposed fix (for a human to decide; the agent changed nothing)

  • Investigate why payments service duration is high (p99 ~3.8s) and causing payment failures in fulfillment.

Hypotheses

  • likely: slow_dependency (payments service is timing out when fulfillment calls it)
  • ruled_out: bad_deploy
  • ruled_out: config_regression

What the investigation cost

  • 4 model calls, 14,438 input and 462 output tokens (14,900 total)
  • 11 steps, 9 s of wall clock
  • 1,093,298 bytes of logs scanned
  • 0 replies rejected by the provider for bad tool arguments