# Postmortem: O11Y-2328599

> Workspace: `ws-1775365141488-ca92b0b5d`
> Date: 2026-04-07
> Reviewer: lingtao.li

## Issue Summary

| Field | Value |
|-------|-------|
| Issue ID | O11Y-2328599 |
| Alert Type | TiDBExpensiveQueryCntGt500AndIncreaseFor10m |
| Cluster ID | 10754652599988043412 |
| Cluster Type | dedicated |
| TiDB Version | v8.5.4 |
| Time Window | 2026-04-05 03:01 - 04:01 UTC |

**Issue Description**: 500+ expensive queries (>60s) detected with 3x increase in 10 minutes, caused by a slow JOIN query on `dh_message_setting` / `dh_message_setting_ext` tables hitting a TiKV-19 hotspot.

## Actual Root Cause

Table `dh_message_setting_ext` (alias `c`) lacked a proper index for the `tag_id` filter used in a high-frequency JOIN query. The `IndexLookUp` on table `c` scanned 303,713 rows and took 15 minutes per execution, causing TiKV-19 to become a hotspot node (3.66x average CPU). This triggered cascading `server_is_busy` errors and expensive query accumulation across the cluster.

The ANALYZE operations running concurrently were a contributing factor (adding load to TiKV-19) but not the primary root cause.

## Agent Diagnosis Summary

The Agent's initial unguided diagnosis (message #3 + #7) concluded:
- Root cause: "TiKV-19 overloaded by ANALYZE statistics collection operations, causing Coprocessor latency up to 83.47s"
- Identified `dh_message_setting` JOIN query as the most frequent expensive query (38/50 occurrences)
- Correctly found TiKV-19 as the bottleneck node via gRPC latency metrics
- **Missed**: Did not query TopSQL, did not check SlowQuery execution plans, attributed root cause to ANALYZE rather than the application query

## Scores

| Dimension | Score (1-5) | Notes |
|-----------|-------------|-------|
| Root Cause Accuracy | 2 | Identified ANALYZE as root cause instead of the application query's missing index on table c |
| Evidence Completeness | 2 | Skipped TopSQL entirely; did not query SlowQuery plan; no instance-level breakdown |
| Causal Chain | 3 | Found TiKV-19 bottleneck and linked it to expensive queries, but wrong causal direction (ANALYZE -> slow, not bad-index query -> slow) |
| Actionability | 2 | Recommended "schedule ANALYZE during off-peak" and "SQL binding" but did not specify which SQL or which table/index to fix |
| Efficiency | 2 | 30 tool calls in first round; 10 calls wasted finding clinic-auth.sh path; multiple retry loops |
| **Overall** | **2.2** | |

## Human Guidance Log

### Intervention 1: Trigger TopSQL analysis

- **Round**: #4
- **User said**: "From TopSQL what did you find?"
- **Agent's mistake**: First diagnosis round completely skipped TopSQL. Only used Metrics + Loki logs + expensive_query logs.
- **Correct behavior**: TopSQL should be a mandatory step in the standard diagnostic flow (Node A), queried alongside SlowQuery.
- **Skill**: `tidb-clinic-diagnosis`
- **Deficiency type**: FLOW

### Intervention 2: TopSQL query used wrong columns

- **Round**: #5 (Agent self-corrected after failures)
- **User said**: (Agent attempted TopSQL on its own after prompt)
- **Agent's mistake**: First TopSQL query used non-existent `timestamp` and `cluster_id` columns. Required 4 retries to get working SQL.
- **Correct behavior**: Should use `date` for partition filter, `timestamps` for time window, `clusterId` in API parameter (not SQL WHERE).
- **Skill**: `tidb-clinic-diagnosis` / `clinic-api`
- **Deficiency type**: TEMPLATE

### Intervention 3: Refocus on application queries, not ANALYZE

- **Round**: #10
- **User said**: "ANALYZE is customer behavior, focus on slowquery. Give evidence chain from metric, log, event and slowquery."
- **Agent's mistake**: Attributed root cause to ANALYZE operations based on Coprocessor metrics showing `analyze_full_sampling` latency. Did not investigate whether application queries independently caused the problem.
- **Correct behavior**: Should not conclude root cause from a single signal. Must cross-reference with TopSQL/SlowQuery to verify whether ANALYZE or application queries are the primary load driver.
- **Skill**: `tidb-clinic-diagnosis`
- **Deficiency type**: REASONING

### Intervention 4: TopSQL query documentation gap

- **Round**: #14-18
- **User said**: "What TopSQL command did you run?" / "What's the difference vs clinic-api docs?"
- **Agent's mistake**: Acknowledged that its TopSQL SQL diverged from the clinic-api skill documentation. Used `timestamp` (wrong) instead of `timestamps` (correct).
- **Correct behavior**: Skill should provide copy-paste-ready TopSQL SQL templates with correct column names.
- **Skill**: `clinic-api` (TopSQL subskill)
- **Deficiency type**: KNOWLEDGE

### Intervention 5: Use timestamps + date for time filtering

- **Round**: #22
- **User said**: "Use timestamps + date to pull TopSQL around the incident time"
- **Agent's mistake**: Did not know how to use the `timestamps` column for time-window filtering in TopSQL.
- **Correct behavior**: `WHERE date = 'YYYY-MM-DD' AND timestamps BETWEEN {start_epoch} AND {end_epoch}`.
- **Skill**: `clinic-api` (TopSQL subskill)
- **Deficiency type**: KNOWLEDGE

### Intervention 6: Switch component to tikv

- **Round**: #26
- **User said**: "Change component to tikv"
- **Agent's mistake**: Only queried TopSQL with `component='tidb'`. Since the bottleneck was TiKV-19, TiKV-side CPU data was critical.
- **Correct behavior**: When Metrics show a TiKV bottleneck, TopSQL must be queried for BOTH `component='tidb'` AND `component='tikv'`.
- **Skill**: `tidb-clinic-diagnosis`
- **Deficiency type**: FLOW

### Intervention 7: Add instance dimension

- **Round**: #30
- **User said**: "You didn't include instance"
- **Agent's mistake**: TopSQL query only aggregated by `sql_digest` globally. Could not see per-node distribution.
- **Correct behavior**: When a specific TiKV node is identified as bottleneck (TiKV-19), all subsequent TopSQL/SlowQuery queries MUST include `instance` in GROUP BY or WHERE.
- **Skill**: `tidb-clinic-diagnosis`
- **Deficiency type**: FLOW

### Intervention 8: Cross-reference with SlowQuery

- **Round**: #32
- **User said**: "Check slowquery, find execution info for this query, see if it can be quickly optimized"
- **Agent's mistake**: Had TopSQL results showing `dh_message_setting` as top CPU consumer but did not proactively query SlowQuery for execution details (plan, index usage, actual rows).
- **Correct behavior**: TopSQL finding -> must cross-reference SlowQuery for execution plan details. This is a mandatory cross-validation step.
- **Skill**: `tidb-clinic-diagnosis`
- **Deficiency type**: CROSS-REF

### Intervention 9: Actually query the execution plan

- **Round**: #34
- **User said**: "Did you actually query the plan?"
- **Agent's mistake**: Queried SlowQuery but only looked at aggregate stats (avg time, count). Did not fetch `plan` or `decoded_plan` fields.
- **Correct behavior**: SlowQuery analysis MUST include: (1) aggregate stats, (2) actual `plan` field, (3) quantitative comparison of operator execution times.
- **Skill**: `tidb-clinic-diagnosis`
- **Deficiency type**: TEMPLATE

### Intervention 10: Correct table identification

- **Round**: #36
- **User said**: "It's actually table c's problem, see how to optimize it"
- **Agent's mistake**: After reading the execution plan, focused on table `a` using PRIMARY KEY full scan. Missed that table `c` (`dh_message_setting_ext`) had `IndexLookUp` taking 15m0.5s (83% of total time).
- **Correct behavior**: When analyzing execution plans, sort all operators by `rootBasicExecInfo.time` to find the actual bottleneck. Do not assume the most "obvious" issue (PRIMARY KEY scan) is the biggest one.
- **Skill**: `tidb-clinic-diagnosis`
- **Deficiency type**: REASONING

## Skill Deficiencies

### D1: TopSQL not mandatory in diagnostic flow

- **Type**: FLOW
- **Skill**: `tidb-clinic-diagnosis`
- **Current behavior**: Node A lists TopSQL as step A4 but Agent skipped it entirely in the first diagnosis round
- **Expected behavior**: TopSQL should be a MUST-DO step at the same priority level as SlowQuery (A3), with explicit text: "MANDATORY: query TopSQL for both component='tidb' AND component='tikv'"
- **Suggested fix**: In Node A, promote A4 to same status as A3 with bold MANDATORY marker. Add rule: "If Metrics show a TiKV hotspot node, you MUST query TopSQL with component='tikv' AND group by instance"
- **Priority**: P0-critical
- **Status**: open

### D2: TopSQL query template incorrect/incomplete

- **Type**: TEMPLATE
- **Skill**: `tidb-clinic-diagnosis`
- **Current behavior**: The TopSQL example SQL in the skill uses correct `date` and `component` filters, but the Agent still fabricated `timestamp` and `cluster_id` columns
- **Expected behavior**: Provide explicit "CORRECT columns" vs "DO NOT USE" table. Add `timestamps` (Unix seconds) for time-window filtering. Add `instance` for per-node analysis.
- **Suggested fix**: Add a reference table in the TopSQL section:
  ```
  CORRECT: date, timestamps, component, instance, sql_digest, normalized_sql, topsql_cpu_time_ms
  DO NOT USE in SQL: cluster_id (use API clusterId param), timestamp (column is named timestamps)
  MUST include: WHERE date = 'YYYY-MM-DD' AND component = 'tidb' (or 'tikv')
  SHOULD include: AND timestamps BETWEEN {start} AND {end}  -- for time-window filtering
  SHOULD include: GROUP BY instance  -- when investigating per-node hotspots
  ```
- **Priority**: P0-critical
- **Status**: open

### D3: No "hotspot node -> drill down" decision rule

- **Type**: FLOW
- **Skill**: `tidb-clinic-diagnosis`
- **Current behavior**: After Metrics identify a hotspot node (TiKV-19), Agent does not automatically add `instance` dimension to subsequent queries
- **Expected behavior**: Explicit rule in Node C/D: "If Metrics reveal a single-node anomaly, ALL subsequent TopSQL and SlowQuery queries MUST filter or group by instance to isolate that node's workload"
- **Suggested fix**: Add decision rule after Node B: "If any TiKV instance shows >2x average latency/CPU, set HOTSPOT_INSTANCE=<instance> and include it in all subsequent TopSQL/SlowQuery queries"
- **Priority**: P0-critical
- **Status**: open

### D4: SlowQuery analysis missing execution plan parsing

- **Type**: TEMPLATE
- **Skill**: `tidb-clinic-diagnosis`
- **Current behavior**: SlowQuery section in the skill only shows aggregate queries (GROUP BY digest). No guidance to fetch and parse `plan`/`decoded_plan` fields.
- **Expected behavior**: Two-phase SlowQuery analysis: (1) aggregate to find top digests, (2) fetch `plan` for the top digest, (3) parse operator tree and sort by execution time
- **Suggested fix**: Add to Node D "Query Tuning Guideline":
  ```
  Step 1: Aggregate slow queries to find top digest (existing A3 query)
  Step 2: Fetch plan for top digest:
    SELECT plan, decoded_plan FROM slow_query_logs
    WHERE date = '...' AND digest = '{top_digest}' LIMIT 1
  Step 3: Parse plan - sort operators by rootBasicExecInfo.time DESC
  Step 4: The operator with the highest time IS the bottleneck (not the one with the "worst-looking" index)
  ```
- **Priority**: P1-high
- **Status**: open

### D5: Missing cross-reference enforcement

- **Type**: CROSS-REF
- **Skill**: `tidb-clinic-diagnosis`
- **Current behavior**: Agent can conclude after a single data source without cross-validation
- **Expected behavior**: Node E should enforce: "Your conclusion is INVALID unless you have evidence from at least 2 independent data sources (e.g., Metrics + TopSQL, TopSQL + SlowQuery)"
- **Suggested fix**: Add to Node E preamble: "Before writing Root Cause, verify: (1) Metrics evidence, (2) TopSQL/SlowQuery evidence, (3) Log evidence. Missing any = go back and collect."
- **Priority**: P1-high
- **Status**: open

### D6: TopSQL schema documentation incomplete in clinic-api

- **Type**: KNOWLEDGE
- **Skill**: `clinic-api` (data-proxy subskill)
- **Current behavior**: The TopSQL table section in clinic-api does not document the `timestamps` column semantics or the `instance` column
- **Expected behavior**: Full column reference including `timestamps` (int, Unix epoch seconds, sampling timestamp), `instance` (string, component instance identifier), `component` (enum: 'tidb'/'tikv')
- **Suggested fix**: Add TopSQL schema reference to the data-proxy SUBSKILL.md with example queries for time-window and per-instance analysis
- **Priority**: P1-high
- **Status**: open

### D7: clinic-auth.sh path discovery wastes 10 tool calls

- **Type**: TEMPLATE
- **Skill**: `tidb-clinic-diagnosis`
- **Current behavior**: Agent spent 10 tool calls (steps 7-16 in message #3) searching the filesystem for `clinic-auth.sh`
- **Expected behavior**: The auth script path should be deterministic. Agent should know the exact path without filesystem traversal.
- **Suggested fix**: Hardcode the auth path in the skill: `source $HOME/.opencode/skills/nutshell-skills/platform/clinic-api/scripts/clinic-auth.sh && get_clinic_auth`. Or better: use the workspace-relative path that's always `~/.opencode/skills/...`
- **Priority**: P2-medium
- **Status**: open

### D8: Premature conclusion from single signal

- **Type**: REASONING
- **Skill**: `tidb-clinic-diagnosis`
- **Current behavior**: Agent saw ANALYZE operations in Coprocessor metrics and immediately concluded it was the root cause, without checking application query load
- **Expected behavior**: Never conclude root cause from one signal. The skill's Node E "NOT acceptable" section lists this but Agent still violated it.
- **Suggested fix**: Strengthen Node B/C with: "ANALYZE/DDL/internal operations are NEVER the root cause unless you have confirmed that no application query is contributing. Always check TopSQL application query CPU% first."
- **Priority**: P1-high
- **Status**: open

### D9: Execution plan analysis focuses on qualitative not quantitative

- **Type**: REASONING
- **Skill**: `tidb-clinic-diagnosis`
- **Current behavior**: Agent sees "PRIMARY KEY" in plan and concludes it's the problem, ignoring that table a's execution time was 0s while table c was 15 minutes
- **Expected behavior**: Quantitative-first analysis: sort operators by time, identify the top-time operator, then analyze why
- **Suggested fix**: In Query Tuning Guideline, rewrite step 2 "Analyze execution plans" to start with: "FIRST: identify the operator with the largest `time` in execution info. This is your bottleneck. THEN analyze why."
- **Priority**: P1-high
- **Status**: open

## Key Queries

### TopSQL - TiKV component with instance and time window

```bash
source ~/.opencode/skills/nutshell-skills/platform/clinic-api/scripts/clinic-auth.sh && get_clinic_auth

CLUSTER_ID="10754652599988043412"

curl -s -X POST https://clinic.pingcap.com/data-proxy/query \
  -H "Authorization: Bearer ${CLINIC_API_KEY}" \
  -H 'Content-Type: application/json' \
  -d "{
  \"sql\": \"SELECT instance, sql_digest, any_value(normalized_sql) AS sample_sql, SUM(topsql_cpu_time_ms) AS total_cpu_ms FROM clinic_data_proxy.topsql WHERE date = '2026-04-05' AND component = 'tikv' AND timestamps BETWEEN 1775365260 AND 1775368860 GROUP BY instance, sql_digest ORDER BY total_cpu_ms DESC LIMIT 30\",
  \"clusterId\": \"${CLUSTER_ID}\",
  \"timeout\": 120
}"
```

### SlowQuery - fetch execution plan for top digest

```bash
curl -s -X POST https://clinic.pingcap.com/data-proxy/query \
  -H "Authorization: Bearer ${CLINIC_API_KEY}" \
  -H 'Content-Type: application/json' \
  -d "{
  \"sql\": \"SELECT digest, query_time, process_time, cop_proc_avg, plan FROM clinic_data_proxy.slow_query_logs WHERE date = '20260405' AND digest = '61b692432...' ORDER BY query_time DESC LIMIT 1\",
  \"clusterId\": \"${CLUSTER_ID}\",
  \"timeout\": 60
}"
```

## Lessons Learned

- **TopSQL is essential for CPU attribution** - without it, Agent can only guess which queries are consuming resources based on log frequency, which is misleading (ANALYZE appeared in logs but wasn't the primary CPU consumer)
- **Instance-level granularity is critical for hotspot diagnosis** - global aggregation hides the fact that one node bears disproportionate load
- **Execution plan analysis must be quantitative** - "uses PRIMARY KEY" is a qualitative observation; "table c takes 15m vs table a takes 0s" is the quantitative truth that points to the real fix
- **Cross-referencing data sources prevents premature conclusions** - Metrics alone suggested ANALYZE was the problem; TopSQL + SlowQuery revealed the application query was the real driver