Skip to content

Instantly share code, notes, and snippets.

@EliW

EliW/2026-01-12-im-needing-to-investigate-some-errors-that-happen.txt

Created January 12, 2026 22:14
Show Gist options

  • Select an option

    Learn more about clone URLs
  • Save EliW/5bd4356b60a15849a78644913bf96d9d to your computer and use it in GitHub Desktop.

Select an option

Learn more about clone URLs
Save EliW/5bd4356b60a15849a78644913bf96d9d to your computer and use it in GitHub Desktop.
Download ZIP
Raw
2026-01-12-im-needing-to-investigate-some-errors-that-happen.txt
▐▛███▜▌ Claude Code v2.1.5
▝▜█████▛▘ Opus 4.5 · Claude Team
▘▘ ▝▝ ~/Documents/Projects/thrivemagento
❯ I'm needing to investigate some errors that happened in New Relic and I
don't have all the context that I need. So to start, we had alerts
happening today at 3:27pm for the 'auth-service' having high P99 latency.
Here is the query that showed it:
SELECT percentile(duration.ms, 99)
FROM Span
WHERE service.name = 'auth-service'
AND deployment.environment = 'dev'
AND span.kind = 'server' TIMESERIES 1 MINUTE SINCE '2026-01-12 15:19:17
-05:00' UNTIL '2026-01-12 15:42:54 -05:00'
Can you check and confirm you can see this in the data?
⏺ I'll use the New Relic skill to query and verify this latency data for you.
⏺ Skill(newrelic)
⎿  Successfully loaded skill
⏺ Let me run that NRQL query to verify the P99 latency data.
⏺ Bash(newrelic nrql query --query "SELECT percentile(duration.ms, 99) FROM Span
WHERE service.name = 'auth-service' AND deployment.environment = 'dev'
AND span.kind =…)
⎿  [
{
"beginTimeSeconds": 1768249194,
… +160 lines (ctrl+o to expand)
⏺ Yes, I can confirm the data is visible in New Relic. Here's what I see for the auth-service P99 latency during that timeframe:
Significant latency spike confirmed:
┌───────────────┬───────────────────────────────┐
│ Time (approx) │ P99 Latency │
├───────────────┼───────────────────────────────┤
│ 15:19 │ 41,606 ms (~42 seconds) │
├───────────────┼───────────────────────────────┤
│ 15:20 │ 30,984 ms (~31 seconds) │
├───────────────┼───────────────────────────────┤
│ 15:21 │ 13,097 ms (~13 seconds) │
├───────────────┼───────────────────────────────┤
│ 15:22 │ 143 ms │
├───────────────┼───────────────────────────────┤
│ 15:23 │ 155 ms │
├───────────────┼───────────────────────────────┤
│ 15:24 │ 3,703 ms (~3.7 seconds) │
├───────────────┼───────────────────────────────┤
│ 15:25 │ 151 ms │
├───────────────┼───────────────────────────────┤
│ 15:26-15:42 │ Gradually decreasing to ~4 ms │
└───────────────┴───────────────────────────────┘
Summary: There was a major latency incident starting around 15:19-15:21 with P99 latencies exceeding 40 seconds at peak, followed by a secondary smaller spike around 15:24. The service recovered to normal latency levels (under 100ms) by approximately 15:26 and continued improving to ~4ms by the end of the window.
Would you like me to dig deeper into what caused these spikes? I can look at:
- Error spans during this timeframe
- Specific slow spans/traces
- Logs from that time period
- Which specific endpoints were affected
❯ Yes I would like to see errors happening during that time if any
⏺ Bash(newrelic nrql query --query "SELECT count(*) FROM Span WHERE service.name
= 'auth-service' AND deployment.environment = 'dev' AND otel.status_code
= 'ERROR' TIM…)
⎿  [
{
"beginTimeSeconds": 1768249194,
… +114 lines (ctrl+o to expand)
⏺ Bash(newrelic nrql query --query "SELECT * FROM Span WHERE service.name =
'auth-service' AND deployment.environment = 'dev' AND otel.status_code =
'ERROR' SINCE '202…)
⎿  []
⏺ No errors with otel.status_code = 'ERROR' during that timeframe. Let me check for HTTP error status codes and also look at the slow spans directly to understand what was happening.
⏺ Bash(newrelic nrql query --query "SELECT count(*) FROM Span WHERE service.name
= 'auth-service' AND deployment.environment = 'dev' AND
http.response.status_code >= 4…)
⎿  []
⏺ Bash(newrelic nrql query --query "SELECT name, duration.ms, http.route,
http.response.status_code, trace.id FROM Span WHERE service.name =
'auth-service' AND deploym…)
⎿  [
{
"duration.ms": 3702.638893,
… +159 lines (ctrl+o to expand)
⏺ Bash(newrelic nrql query --query "SELECT * FROM Log WHERE service.name =
'auth-service' AND deployment.environment = 'dev' AND severity.text IN
('ERROR', 'WARN') SIN…)
⎿  []
⏺ This is very revealing. Here's what I found:
No actual errors occurred - no HTTP error codes, no error logs, and no spans with error status.
All slow requests were health checks - every slow span (>1 second) was GET /auth/v1/health:
┌───────────┬──────────┬──────────────────────────────────┐
│ Time │ Duration │ Trace ID │
├───────────┼──────────┼──────────────────────────────────┤
│ ~15:19:04 │ 41.6 sec │ 890f5f5d15958dc1d95a99a7249b5c1a │
├───────────┼──────────┼──────────────────────────────────┤
│ ~15:19:04 │ 26.9 sec │ bf0b5e509307937b1c50afb0b0a17f84 │
├───────────┼──────────┼──────────────────────────────────┤
│ ~15:19:04 │ 26.7 sec │ 8c1ceafde707f9a108f7cd6a45b70214 │
├───────────┼──────────┼──────────────────────────────────┤
│ ~15:20:15 │ 31.0 sec │ 70b4cc2038b568ee715a95d79062281f │
├───────────┼──────────┼──────────────────────────────────┤
│ ~15:21:11 │ 15.1 sec │ 9fab7180ba2520fbf3eb11de6534f63b │
├───────────┼──────────┼──────────────────────────────────┤
│ ~15:21:11 │ 15.0 sec │ 6007aad62bffbaf023589a583cce6e72 │
├───────────┼──────────┼──────────────────────────────────┤
│ ~15:22:21 │ 12.4 sec │ multiple traces │
└───────────┴──────────┴──────────────────────────────────┘
This pattern (health checks being slow with no errors) typically indicates service startup or pod initialization. Let me check for pod restarts or infrastructure events.
⏺ Bash(newrelic nrql query --query "SELECT uniques(k8s.pod.name), min(timestamp)
as firstSeen FROM Span WHERE service.name = 'auth-service' AND
deployment.environment…)
⎿  [
{
"facet": "auth-service-7956b6c7bf-57xnd",
… +31 lines (ctrl+o to expand)
⏺ Bash(newrelic nrql query --query "SELECT * FROM Log WHERE service.name =
'auth-service' AND deployment.environment = 'dev' AND message LIKE
'%start%' SINCE '2026-01-…)
⎿  []
⏺ Bash(newrelic nrql query --query "SELECT count(*) FROM Span WHERE service.name
= 'auth-service' AND deployment.environment = 'dev' FACET k8s.pod.name
TIMESERIES 1 MI…)
⎿  Error: Exit code 1
level=fatal msg="json: cannot unmarshal array into Go struct field
NRDBResultContainer.data.Actor.Account.NRQL.otherResult of type
nrdb.NRDBResult"
⏺ I found something significant. Looking at the pod first-seen times:
Pod: auth-service-7956b6c7bf-5fx6x
First Seen (epoch): 1768248600169
Converted Time (approx): ~15:10
────────────────────────────────────────
Pod: auth-service-7956b6c7bf-57xnd
First Seen (epoch): 1768248601480
Converted Time (approx): ~15:10
────────────────────────────────────────
Pod: auth-service-7956b6c7bf-krrr5
First Seen (epoch): 1768248603232
Converted Time (approx): ~15:10
────────────────────────────────────────
Pod: auth-service-7956b6c7bf-wlnpw
First Seen (epoch): 1768249081523
Converted Time (approx): ~15:17-15:18
A new pod wlnpw appeared just 1-2 minutes before the latency spike started. Let me check which pod was serving the slow requests.
⏺ Bash(newrelic nrql query --query "SELECT k8s.pod.name, duration.ms, timestamp
FROM Span WHERE service.name = 'auth-service' AND deployment.environment =
'dev' AND sp…)
⎿  [
{
"duration.ms": 3702.638893,
… +129 lines (ctrl+o to expand)
⏺ Bash(newrelic nrql query --query "SELECT count(*) FROM Span WHERE service.name
= 'auth-service' AND deployment.environment = 'dev' AND span.kind =
'server' AND durat…)
⎿  [
{
"count": 26,
… +4 lines (ctrl+o to expand)
⏺ Root cause identified: Cold start on new pod
All 26 slow requests (>1 second) came from a single pod: auth-service-7956b6c7bf-wlnpw
Timeline:
- ~15:17-15:18 - New pod wlnpw started (first seen at epoch 1768249081)
- ~15:19:17 - Pod began receiving health check traffic while still initializing
- ~15:19:04 - Peak latency hit 41.6 seconds on health checks
- ~15:26+ - Pod finished warming up, latency returned to normal (~4ms)
Summary:
This was a cold start / pod initialization issue, not an error condition. The new pod was added to the service before it was fully warmed up, causing health checks to be extremely slow during initialization. No actual errors occurred - requests just took a long time while the service was starting up (likely warming caches, establishing database/Redis connections, JIT compilation, etc.).
Potential improvements to consider:
1. Readiness probe tuning - Delay marking the pod as "ready" until it's fully warmed up
2. Startup probe - Use a Kubernetes startup probe with longer initial delay
3. Pre-warming - Add application-level warmup before accepting traffic
4. Health check timeout - The health endpoint itself may be doing too much work during startup
Would you like me to investigate what the health check endpoint does, or look at the Kubernetes deployment configuration?
✻ Baked for 1m 10s
❯ How many 'pods' were running beforehand?
⏺ Bash(newrelic nrql query --query "SELECT uniqueCount(k8s.pod.name) FROM Span
WHERE service.name = 'auth-service' AND deployment.environment = 'dev'
SINCE '2026-01-12…)
⎿  [
{
"uniqueCount.k8s.pod.name": 3
… +2 lines (ctrl+o to expand)
⏺ Bash(newrelic nrql query --query "SELECT uniques(k8s.pod.name) FROM Span WHERE
service.name = 'auth-service' AND deployment.environment = 'dev' SINCE
'2026-01-12 15:…)
⎿  [
{
"uniques.k8s.pod.name": [
… +6 lines (ctrl+o to expand)
⏺ 3 pods were running before the incident:
1. auth-service-7956b6c7bf-5fx6x
2. auth-service-7956b6c7bf-57xnd
3. auth-service-7956b6c7bf-krrr5
Then pod auth-service-7956b6c7bf-wlnpw was added as a 4th pod around 15:17-15:18, likely due to:
- HPA scale-up (autoscaler responding to increased load), or
- Manual scaling, or
- Pod replacement (though the other 3 pods stayed active)
Would you like me to check if there was increased traffic or load that might have triggered a scale-up event?
❯ yes
⏺ Bash(newrelic nrql query --query "SELECT count(*) FROM Span WHERE service.name
= 'auth-service' AND deployment.environment = 'dev' AND span.kind =
'server' TIMESERIE…)
⎿  [
{
"beginTimeSeconds": 1768247400,
… +199 lines (ctrl+o to expand)
⏺ Bash(newrelic nrql query --query "SELECT rate(count(*), 1 minute) FROM Span
WHERE service.name = 'auth-service' AND deployment.environment = 'dev' AND
span.kind = 's…)
⎿  [
{
"beginTimeSeconds": 1768247400,
… +199 lines (ctrl+o to expand)
⏺ Bash(newrelic nrql query --query "SELECT average(duration.ms),
percentile(duration.ms, 95) FROM Span WHERE service.name = 'auth-service'
AND deployment.environment =…)
⎿  [
{
"average.duration.ms": 2.823402152777778,
… +319 lines (ctrl+o to expand)
⏺ This is very revealing. Look at the traffic pattern:
┌───────────────┬──────────────┬─────────────┬───────────────────────────┐
│ Time (approx) │ Requests/min │ Avg Latency │ Notes │
├───────────────┼──────────────┼─────────────┼───────────────────────────┤
│ 14:50 - 15:11 │ 72 │ ~2.7ms │ Normal (3 pods) │
├───────────────┼──────────────┼─────────────┼───────────────────────────┤
│ 15:12 - 15:17 │ 48 │ ~3.0ms │ Traffic dropped 33% │
├───────────────┼──────────────┼─────────────┼───────────────────────────┤
│ 15:18+ │ 71-76 │ Spiked │ 4th pod added, cold start │
└───────────────┴──────────────┴─────────────┴───────────────────────────┘
Key finding: Traffic actually dropped before the new pod was added, not increased. Let me check if a pod was lost during that low-traffic window.
⏺ Bash(newrelic nrql query --query "SELECT uniques(k8s.pod.name) FROM Span WHERE
service.name = 'auth-service' AND deployment.environment = 'dev' SINCE
'2026-01-12 15:…)
⎿  [
{
"uniques.k8s.pod.name": [
… +5 lines (ctrl+o to expand)
⏺ Bash(newrelic nrql query --query "SELECT max(timestamp) as lastSeen FROM Span
WHERE service.name = 'auth-service' AND deployment.environment = 'dev' AND
k8s.pod.name…)
⎿  [
{
"facet": "auth-service-7956b6c7bf-krrr5",
… +14 lines (ctrl+o to expand)
⏺ Found the root cause sequence:
Pod auth-service-7956b6c7bf-5fx6x died around 15:11-15:12
- Last seen: epoch 1768248715 (~15:11:55)
- This caused traffic to drop from 72 → 48 req/min (3 pods → 2 pods)
During 15:12-15:17, only 2 pods were serving traffic:
- auth-service-7956b6c7bf-57xnd
- auth-service-7956b6c7bf-krrr5
Replacement pod wlnpw was created around 15:17-15:18
- Kubernetes detected the lost pod and scheduled a replacement
- New pod started receiving traffic while still initializing → cold start latency spike
---
Summary: This was a pod replacement, not a scale-up.
┌──────────────┬──────────────────────────────────────────────────────┐
│ Time │ Event │
├──────────────┼──────────────────────────────────────────────────────┤
│ ~15:11-15:12 │ Pod 5fx6x terminated/died │
├──────────────┼──────────────────────────────────────────────────────┤
│ 15:12-15:17 │ Only 2 pods serving traffic (33% capacity reduction) │
├──────────────┼──────────────────────────────────────────────────────┤
│ ~15:17-15:18 │ Replacement pod wlnpw created │
├──────────────┼──────────────────────────────────────────────────────┤
│ 15:19-15:26 │ Cold start latency spike (up to 42 seconds) │
├──────────────┼──────────────────────────────────────────────────────┤
│ 15:26+ │ Pod warmed up, normal operation resumed │
└──────────────┴──────────────────────────────────────────────────────┘
Would you like me to investigate why pod 5fx6x died? I can check for OOM kills, eviction events, or other termination reasons in the logs.
✻ Baked for 44s
❯ double-check that auth-service-7956b6c7bf-5fx6x really died, and can you
figure out the reason
⏺ Bash(newrelic nrql query --query "SELECT count(*) FROM Span WHERE service.name
= 'auth-service' AND deployment.environment = 'dev' AND k8s.pod.name =
'auth-service-7…)
⎿  [
{
"beginTimeSeconds": 1768248000,
… +149 lines (ctrl+o to expand)
⏺ Bash(newrelic nrql query --query "SELECT * FROM Log WHERE k8s.pod.name =
'auth-service-7956b6c7bf-5fx6x' SINCE '2026-01-12 15:05:00 -05:00' UNTIL
'2026-01-12 15:20:0…)
⎿  []
⏺ Bash(newrelic nrql query --query "SELECT * FROM Log WHERE service.name =
'auth-service' AND deployment.environment = 'dev' AND (message LIKE
'%kill%' OR message LIKE…)
⎿  []
⏺ Confirmed - pod 5fx6x definitely died. The span data shows:
- 15:10-15:11: 72 spans (normal)
- 15:11-15:12: 54 spans (dropping)
- 15:12 onwards: 0 spans (dead)
No application logs found for that pod. Let me check Kubernetes events and infrastructure data.
⏺ Bash(newrelic nrql query --query "SELECT * FROM InfrastructureEvent WHERE
k8s.podName LIKE '%auth-service%' OR podName LIKE '%auth-service%' SINCE
'2026-01-12 15:05:…)
⎿  []
⏺ Bash(newrelic nrql query --query "SELECT * FROM K8sContainerSample WHERE
podName LIKE '%auth-service%' AND clusterName LIKE '%dev%' SINCE
'2026-01-12 15:05:00 -05:00…)
⎿  [
{
"agentName": "Infrastructure",
… +2539 lines (ctrl+o to expand)
⏺ Bash(newrelic nrql query --query "SELECT * FROM K8sPodSample WHERE podName
LIKE '%auth-service%' SINCE '2026-01-12 15:05:00 -05:00' UNTIL '2026-01-12
15:20:00 -05:00…)
⎿  [
{
"agentName": "Infrastructure",
… +1725 lines (ctrl+o to expand)
⏺ Let me query specifically for pod 5fx6x to find its termination details.
⏺ Bash(newrelic nrql query --query "SELECT * FROM K8sContainerSample WHERE
podName = 'auth-service-7956b6c7bf-5fx6x' SINCE '2026-01-12 15:05:00
-05:00' UNTIL '2026-01-…)
⎿  [
{
"agentName": "Infrastructure",
… +859 lines (ctrl+o to expand)
⏺ Bash(newrelic nrql query --query "SELECT timestamp, podName, status, reason,
restartCount, isReady FROM K8sPodSample WHERE podName LIKE
'%auth-service-7956b6c7bf%' A…)
⎿  [
{
"isReady": 1,
… +399 lines (ctrl+o to expand)
⏺ Bash(newrelic nrql query --query "SELECT timestamp, containerName, podName,
status, reason, restartCount, restartCountDelta FROM K8sContainerSample
WHERE podName LIK…)
⎿  [
{
"containerName": "auth-service",
… +449 lines (ctrl+o to expand)
⏺ Excellent findings! Two important discoveries:
1. Pod 5fx6x confirmed dead:
- Last K8sPodSample: timestamp 1768248722000 (~15:12:02)
- Then completely disappears - no termination reason captured in New Relic
2. Replacement pod wlnpw was crashing repeatedly:
┌───────────┬──────────────┬───────────────────┬───────────────┐
│ Timestamp │ restartCount │ restartCountDelta │ isReady │
├───────────┼──────────────┼───────────────────┼───────────────┤
│ ~15:17:36 │ 1 │ 0 │ 0 (not ready) │
├───────────┼──────────────┼───────────────────┼───────────────┤
│ ~15:18:46 │ 3 │ 2 │ 0 (not ready) │
├───────────┼──────────────┼───────────────────┼───────────────┤
│ ~15:18:48 │ 3 │ 0 │ 1 (ready) │
└───────────┴──────────────┴───────────────────┴───────────────┘
The new pod restarted 3 times before stabilizing! Let me check for OOM events or crash reasons.
⏺ Bash(newrelic nrql query --query "SELECT timestamp, podName,
containerMemoryUsageBytes, memoryUsedBytes, memoryLimitBytes,
containerOOMEventsDelta, cpuUsedCores, cpu…)
⎿  [
{
"containerMemoryUsageBytes": null,
… +155 lines (ctrl+o to expand)
⏺ Bash(newrelic nrql query --query "SELECT timestamp, podName,
containerMemoryUsageBytes, memoryUsedBytes, memoryLimitBytes,
containerOOMEventsDelta, status, reason FR…)
⎿  [
{
"containerMemoryUsageBytes": null,
… +149 lines (ctrl+o to expand)
⏺ Bash(newrelic nrql query --query "SELECT * FROM K8sContainerSample WHERE
podName = 'auth-service-7956b6c7bf-5fx6x' AND clusterName = 'dev-eks' AND
timestamp > 176824…)
⎿  []
⏺ Interesting findings:
Pod 5fx6x - final sample anomaly:
- Last sample at ~15:12:02 shows memoryUsedBytes: 0 (suspicious - was ~71MB before)
- No OOM events recorded
- Memory suddenly dropped to 0 suggests container was already terminating
Pod wlnpw - no OOM:
- Memory well within limits: ~60MB used / 512MB limit
- No containerOOMEventsDelta events
- CPU spikes during startup but within limits
The restarts weren't OOM-related. Let me check for node events or liveness probe failures.
⏺ Bash(newrelic nrql query --query "SELECT * FROM K8sContainerSample WHERE
podName = 'auth-service-7956b6c7bf-5fx6x' AND timestamp >= 1768248700000
AND timestamp <= 17…)
⎿  []
⏺ Bash(newrelic nrql query --query "SELECT uniques(eventType) FROM
K8sContainerSample, K8sPodSample, InfrastructureEvent, Log WHERE
k8s.pod.name LIKE '%auth-service%'…)
⎿  [
{
"uniques.eventType": []
… +2 lines (ctrl+o to expand)
⏺ Bash(newrelic nrql query --query "SELECT * FROM K8sNodeSample WHERE nodeName =
'i-051d6aa8d279ca741' SINCE '2026-01-12 15:05:00 -05:00' UNTIL
'2026-01-12 15:15:00 -0…)
⎿  [
{
"agentName": "Infrastructure",
… +599 lines (ctrl+o to expand)
⏺ The node i-051d6aa8d279ca741 was healthy - no memory/disk pressure, all conditions ready. It's a Karpenter-managed node.
Let me check for deployment or rollout events around that time.
⏺ Bash(newrelic nrql query --query "SELECT * FROM K8sDeploymentSample WHERE
deploymentName = 'auth-service' AND clusterName = 'dev-eks' SINCE
'2026-01-12 15:00:00 -05:…)
⎿  []
⏺ Bash(newrelic nrql query --query "SELECT * FROM K8sReplicaSetSample WHERE
deploymentName = 'auth-service' AND clusterName = 'dev-eks' SINCE
'2026-01-12 15:00:00 -05:…)
⎿  []
⏺ Bash(newrelic nrql query --query "SELECT eventType, count(*) FROM
K8sDeploymentSample, K8sReplicaSetSample, K8sContainerSample, K8sPodSample
WHERE clusterName = 'dev…)
⎿  Error: Exit code 1
level=fatal msg="Value must be constant in its context: Id{name='eventType',
isQuoted=false}"
⏺ Read(~/.claude/projects/-Users-eliwhite-Documents-Projects-thrivemagento/22189
650-60c0-4ffa-a886-854bdbe59589/tool-results/toolu_01MtxZgBe5TdMDPuhMwATBk
S.txt)
⎿  Read 100 lines
⏺ Found key information in the container sample for pod 5fx6x:
"lastTerminatedExitCode": 0,
"lastTerminatedExitReason": "None",
"label.rollouts-pod-template-hash": "7956b6c7bf"
Exit code 0 with reason "None" = graceful shutdown, not a crash. And I notice this uses Argo Rollouts (rollouts-pod-template-hash label).
Let me check if there was a rollout or if the new pod wlnpw has a different template hash.
⏺ Bash(newrelic nrql query --query "SELECT timestamp, podName,
label.rollouts-pod-template-hash as templateHash, containerImage FROM
K8sContainerSample WHERE podName L…)
⎿ [
{
"containerImage":
"904233098208.dkr.ecr.us-east-1.amazonaws.com/aut
… +139 lines (ctrl+o to expand)
⏺ Bash(newrelic nrql query --query "SELECT
uniques(label.rollouts-pod-template-hash), uniques(containerImage) FROM
K8sContainerSample WHERE deploymentName = 'auth-serv…)
⎿  [
{
"uniques.containerImage": [
… +6 lines (ctrl+o to expand)
⏺ All pods use the same container image (sha-b551186b1f14d41eb2883223a45e5f3fe31b97a5) - so this was not a deployment rollout.
---
Summary of Investigation
What we know for certain:
1. Pod 5fx6x was gracefully terminated (~15:12)
- Exit code: 0
- Reason: "None" (not OOM, not crash)
- Node was healthy
- No new image deployed
2. Replacement pod wlnpw had startup issues (~15:17-15:19)
- Restarted 3 times before becoming healthy
- Caused P99 latency to spike to 42 seconds
- Not OOM (memory well under limits)
Most likely cause of pod 5fx6x termination:
Given the evidence (graceful exit, healthy node, Karpenter-managed infrastructure, no deployment), the probable causes are:
Probability: High
Cause: Karpenter node consolidation - Karpenter may have been consolidating
nodes and evicted the pod
────────────────────────────────────────
Probability: Medium
Cause: Voluntary pod disruption (PDB-compliant eviction)
────────────────────────────────────────
Probability: Low
Cause: Manual deletion
Why the replacement pod restarted 3 times:
The restarts were likely caused by failed liveness probes during cold start - the health endpoint was taking 10-40+ seconds to respond, which would exceed typical liveness probe timeouts.
Recommendations:
1. Check Karpenter logs for consolidation events around 15:10-15:12
2. Review liveness probe configuration (consider using startup probes)
3. Investigate why the health check takes so long during startup
Would you like me to check anything else?
✻ Churned for 2m 7s
❯ was there actually a spike of requests?
⏺ Good question - let me re-examine the request volume data more carefully. Looking back at what I collected earlier:
┌───────────────┬──────────────┬───────────────────────┐
│ Time │ Requests/min │ Pods │
├───────────────┼──────────────┼───────────────────────┤
│ 14:50 - 15:11 │ 72 │ 3 │
├───────────────┼──────────────┼───────────────────────┤
│ 15:12 - 15:17 │ 48 │ 2 (pod died) │
├───────────────┼──────────────┼───────────────────────┤
│ 15:18+ │ 71-76 │ 3 (replacement added) │
└───────────────┴──────────────┴───────────────────────┘
No spike. Request volume was flat at ~72/min, dropped to 48 when a pod died, then returned to ~72 when the replacement came online.
Let me verify by checking a wider time window to see if there was any traffic increase before the incident.
⏺ Bash(newrelic nrql query --query "SELECT count(*) FROM Span WHERE service.name
= 'auth-service' AND deployment.environment = 'dev' AND span.kind =
'server' TIMESERIE…)
⎿  [
{
"beginTimeSeconds": 1768244400,
… +119 lines (ctrl+o to expand)
⏺ No spike at all. The traffic was remarkably flat:
┌───────────────┬───────────────┬─────────────────────┐
│ Time Window │ Requests/5min │ Req/min │
├───────────────┼───────────────┼─────────────────────┤
│ 14:00 - 15:10 │ 360 │ 72 (constant) │
├───────────────┼───────────────┼─────────────────────┤
│ 15:10 - 15:15 │ 282 │ 56 (pod died) │
├───────────────┼───────────────┼─────────────────────┤
│ 15:15 - 15:20 │ 283 │ 57 (2 pods only) │
├───────────────┼───────────────┼─────────────────────┤
│ 15:20 - 15:25 │ 355 │ 71 (recovering) │
├───────────────┼───────────────┼─────────────────────┤
│ 15:25 - 16:00 │ 360 │ 72 (back to normal) │
└───────────────┴───────────────┴─────────────────────┘
The traffic was perfectly flat at exactly 72 requests/minute for the entire 2-hour window - no increase whatsoever.
Notably, 72 req/min = exactly 1.2 req/sec, which looks like synthetic/scheduled traffic (health checks, monitoring probes, or synthetic monitoring) rather than organic user traffic.
Bottom line: The latency spike was not caused by a traffic increase. It was purely caused by:
1. Pod 5fx6x being terminated (gracefully)
2. Replacement pod wlnpw having slow cold starts and 3 restarts
❯ Why would this service need to reboot 3 times, and take 10min to come
online? That's a long warmup window
⏺ That's a great question - 3 restarts and ~10 minutes to stabilize is excessive. Let me investigate what was happening during those restart cycles.
⏺ Bash(newrelic nrql query --query "SELECT timestamp, restartCount,
restartCountDelta, isReady, status FROM K8sContainerSample WHERE podName =
'auth-service-7956b6c7bf…)
⎿  [
{
"isReady": 1,
… +160 lines (ctrl+o to expand)
⏺ Bash(newrelic nrql query --query "SELECT name, duration.ms, timestamp FROM
Span WHERE service.name = 'auth-service' AND deployment.environment =
'dev' AND k8s.pod.na…)
⎿  [
{
"duration.ms": 0.01563,
… +249 lines (ctrl+o to expand)
⏺ This is worse than I thought! The pod actually restarted 6 times, not 3:
┌────────────┬──────────────┬───────────────────┬─────────┬─────────────────┐
│ Timestamp │ restartCount │ restartCountDelta │ isReady │ Event │
├────────────┼──────────────┼───────────────────┼─────────┼─────────────────┤
│ ~15:17:36 │ 1 │ 0 │ 0 │ First attempt │
├────────────┼──────────────┼───────────────────┼─────────┼─────────────────┤
│ ~15:18:46 │ 3 │ +2 │ 0 │ 2 more crashes │
├────────────┼──────────────┼───────────────────┼─────────┼─────────────────┤
│ ~15:19:28 │ 3 │ 0 │ 1 │ Briefly ready │
├────────────┼──────────────┼───────────────────┼─────────┼─────────────────┤
│ ~15:20:07 │ 4 │ +1 │ 0 │ Crashed again │
├────────────┼──────────────┼───────────────────┼─────────┼─────────────────┤
│ ~15:20:28 │ 4 │ 0 │ 1 │ Briefly ready │
├────────────┼──────────────┼───────────────────┼─────────┼─────────────────┤
│ ~15:21:31 │ 4 │ 0 │ 0 │ Lost readiness │
├────────────┼──────────────┼───────────────────┼─────────┼─────────────────┤
│ ~15:21:58 │ 5 │ +1 │ 1 │ Another restart │
├────────────┼──────────────┼───────────────────┼─────────┼─────────────────┤
│ ~15:23:28 │ 6 │ +1 │ 1 │ Final restart │
├────────────┼──────────────┼───────────────────┼─────────┼─────────────────┤
│ ~15:23:30+ │ 6 │ 0 │ 1 │ Finally stable │
└────────────┴──────────────┴───────────────────┴─────────┴─────────────────┘
Pattern identified: The pod keeps becoming ready, then crashing again. This is the classic liveness probe killing slow-starting containers.
Let me check what the health endpoint is actually doing during startup.
⏺ Bash(newrelic nrql query --query "SELECT name, duration.ms, timestamp FROM
Span WHERE service.name = 'auth-service' AND deployment.environment =
'dev' AND k8s.pod.na…)
⎿  [
{
"duration.ms": 114.282359,
… +249 lines (ctrl+o to expand)
⏺ Bash(newrelic nrql query --query "SELECT name, count(*), average(duration.ms),
max(duration.ms) FROM Span WHERE service.name = 'auth-service' AND
deployment.environm…)
⎿  Error: Exit code 1
level=fatal msg="Value must be constant in its context: Id{name='name',
isQuoted=false}"
⏺ Now I can see the restart cycle pattern clearly. Each restart shows a warmup period where health checks are extremely slow:
Restart cycle pattern (health check latencies):
┌───────────┬─────────┬──────────────────────┐
│ Time │ Latency │ Event │
├───────────┼─────────┼──────────────────────┤
│ ~15:19:37 │ 8.8 sec │ Container start #1-3 │
├───────────┼─────────┼──────────────────────┤
│ ~15:19:44 │ 42 sec │ Still warming │
├───────────┼─────────┼──────────────────────┤
│ ~15:20:15 │ 31 sec │ Peak latency │
├───────────┼─────────┼──────────────────────┤
│ ~15:21:11 │ 15 sec │ Getting better │
├───────────┼─────────┼──────────────────────┤
│ ~15:21:27 │ 3 sec │ Almost there... │
├───────────┼─────────┼──────────────────────┤
│ ~15:21:41 │ 175 ms │ Looks ready │
├───────────┼─────────┼──────────────────────┤
│ ~15:22:22 │ 12 sec │ CRASHED & RESTARTED │
├───────────┼─────────┼──────────────────────┤
│ ~15:22:48 │ 4.7 sec │ New warmup cycle │
├───────────┼─────────┼──────────────────────┤
│ ~15:23:14 │ 140 ms │ Stabilizing │
├───────────┼─────────┼──────────────────────┤
│ ~15:24:22 │ 140 ms │ Still ~140ms │
├───────────┼─────────┼──────────────────────┤
│ ~15:26:18 │ 2 ms │ Finally fast │
└───────────┴─────────┴──────────────────────┘
Root cause: The health endpoint is doing expensive work during startup (likely database connections, connection pools, or dependency checks). The liveness probe has a timeout shorter than the warmup time, so it keeps killing the container.
The restart loop:
1. Container starts
2. Health check takes 10-40 seconds
3. Liveness probe times out (likely ~10-30 sec timeout)
4. Kubernetes kills container → restart count +1
5. Container starts again, repeat...
6. Eventually gets lucky and warmup completes before timeout
Why did it eventually stabilize?
- Possibly filesystem/DNS caches warming up on the node
- Or exponential backoff giving it more time between restarts
Recommendations:
1. Add a startup probe - Kubernetes 1.16+ supports startup probes with longer timeouts for slow-starting containers
2. Make health endpoint lightweight - Return 200 immediately, don't check dependencies
3. Separate liveness from readiness - Liveness = "am I alive?", Readiness = "can I serve traffic?"
4. Increase liveness probe timeout - If startup probe isn't an option
Would you like me to look at what the health endpoint is actually checking in the codebase?
✻ Cooked for 57s
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment