← Back to blog
Solution 4 min read 炬鲸团队

Debugging Slow Queries in Payment Systems: Tracing Down to the Exact SQL

The hard part of a slow payment path is narrowing "the whole chain is slow" down to "which SQL is slow." This case study shows how tracing plus log correlation pinpoints the exact statement and its parameters.

A typical slow-query case in payments

During a promotion, a payment system's order endpoint saw its P99 jump from 300ms to 2s. The latency alert fired first — the error rate was flat, but latency crossed the threshold. Opening the slow-SQL monitor, average database time looked normal, yet users still felt the slowness. Average-latency metrics are misleading precisely because they hide outliers, and this case is a textbook example: the mean stayed healthy while the worst few percent of requests were quietly timing out.

This "normal DB average but slow end-to-end" pattern usually means the problem isn't in the database itself but somewhere in the middle of the call chain — connection-pool waits, serialization, or an occasional heavy query. To find it, you have to look along the entire chain, not at any single hop in isolation. Each service's own dashboard may look fine while the aggregate request is slow.

Read the trace first, find the slow segment

In Observe's tracing, take the trace_id of a slow order request and expand the call tree:

POST /order/create                2000ms
├── auth-service /verify          45ms
├── inventory-service /lock       380ms
│   └── SELECT ... FOR UPDATE     360ms  ← here
└── pay-service /pay              1500ms
    ├── DB: INSERT INTO ...       60ms
    └── DB: SELECT ... FOR UPDATE 1400ms  ← and here

Two spans stand out: one SELECT ... FOR UPDATE held a lock for 360ms, another for 1400ms. Lock onto those two spans and the problem shrinks from "the whole chain is slow" to "two SQL statements are slow." The trace gives you what a dashboard never can: the exact parent-child structure and per-hop latency, so you stop guessing which service to blame.

Drill into the exact SQL and parameters

Click the slow span and you'll see the bound SQL template and its parameters:

SELECT * FROM inventory WHERE sku_id = ? FOR UPDATE
-- params: sku_id = 100234

Compare it with the database's execution plan for this statement and you find it's doing a full table scan — the index on sku_id was accidentally dropped during a change just before the promotion. That's the root cause. Having the actual parameters (not just the template) matters, because a query can be fine for most inputs and pathological for one specific SKU. Without the parameters, the slow query looks identical to thousands of fast ones.

Correlate logs for context

The SQL alone isn't enough; you need what happened around this request. Jump from the span to the logs it emitted:

[order-service] 10:32:11.034 WARN  pool=inventory-ds active=20 max=20
[order-service] 10:32:11.040 WARN  pool=inventory-ds getConnection timeout

The logs show the connection pool exhausted and getConnection timing out — the full table scan slowed every statement, and the slow statements filled the pool, forming a vicious cycle. Logs and traces together tell the full story: the trace points to the slow SQL, and the logs explain the collateral damage (pool exhaustion) that amplified it. Either signal alone would leave the picture half-finished.

A repeatable playbook

This class of problem follows a fixed playbook — memorize it and most slow-payment incidents stop being a hunt and become a checklist:

  1. Use error/latency alerts to scope the problem first — don't start digging in the database.
  2. Expand the slow request into a call tree via the trace and find the abnormally slow spans.
  3. Open the span to see the SQL template and parameters and get the concrete statement.
  4. Correlate logs for context to confirm side effects like connection pools, locks and GC.
  5. Re-run the same trace after the fix to confirm P99 has dropped back.

After rebuilding the index, the endpoint's P99 returned under 300ms. The whole diagnosis took less than half an hour — thanks to the linkage between tracing and logs, not to sifting through a database slow-query log. The index drop itself was a one-line mistake; the expensive part was never finding the slow query, but knowing where to look. A slow-query log would have surfaced the SQL eventually, but it wouldn't have shown which user-facing request it belonged to, or that the connection pool was the amplifier — that context only comes from tracing and logs together.