Case study
Idle CPUs, 60-second queries: a global lock in ClickHouse 23.8
How a dashboard widget that needed two numbers took a ClickHouse cluster down for 48 minutes, and why the fix was a cheaper query rather than more hardware.
TL;DR
- A widget was switched from PostgreSQL to ClickHouse 23.8. For 48 minutes the cluster rejected queries with TOO_MANY_SIMULTANEOUS_QUERIES, including other teams' queries, while 65 of 80 cores per node sat idle.
- The bottleneck was a global mutex in the query Context. Each node handled about 56–59K acquisitions per second; past that, every query waits in line. The widget's call cost 6,849 acquisitions.
- One metric explained the incident and pointed at the fix: lock acquisitions per query. The widget moved to a dedicated count() query costing about 230 acquisitions, 30 times less. The upstream fix exists, but never reached 23.8 LTS.
The symptom
A customer-facing dashboard had a widget showing two counters: items ready to be handed over, in total and today. Over a year earlier the counters had been added to an existing report function, so the widget called the full report with a page size of one and read the counters from the result. On PostgreSQL this cost about 10 ms per call, and nobody noticed.
In the morning the widget was switched to a ClickHouse cluster: two replicas, 80 cores each. Within a minute:
- queries started failing with TOO_MANY_SIMULTANEOUS_QUERIES (code 202) at the limit of 500 concurrent queries;
- 58% of the widget's requests were rejected; the ones that got through took about 60 seconds (max 66);
- other consumers suffered too: about 20,000 of their queries were rejected, one report's median latency went from 1 second to 60, another's from 33 ms to 13 seconds;
- meanwhile, about 15 of 80 cores were busy, with no I/O wait and flat memory.
The widget was rolled back after 48 minutes. Idle CPU with everything timing out is the signature of a lock, not of load.
The mechanism
In ClickHouse 23.8, the shared part of the query Context is protected by a single global mutex. A query takes it when it creates a context for a subquery, reads settings, and so on. A simple query takes it a handful of times. A view with dozens of subqueries takes it thousands of times. With the old query analyzer, each scalar subquery in a global WITH is recomputed at every nesting level where it is used.
Below the mutex's ceiling, waiting is close to zero. Above it, every query on the node stands in one line, regardless of free CPU. On these nodes the ceiling was about 56–59K acquisitions per second.
Measuring it
ClickHouse counts lock acquisitions and lock wait per query. This query finds the most expensive query shapes:
SELECT
normalized_query_hash,
count() AS calls,
round(avg(query_duration_ms)) AS avg_ms,
round(avg(ProfileEvents['ContextLock'])) AS locks_per_call,
round(avg(ProfileEvents['ContextLockWaitMicroseconds']) / 1000) AS lock_wait_ms,
round(avg(ProfileEvents['OSCPUVirtualTimeMicroseconds']) / 1000) AS cpu_ms
FROM system.query_log
WHERE type = 'QueryFinish' AND event_time > now() - INTERVAL 1 HOUR
GROUP BY normalized_query_hash
ORDER BY sum(ProfileEvents['ContextLock']) DESC
LIMIT 20;
If lock wait is close to the query duration while CPU time is small, you are looking at this problem.
For the node as a whole, system.metric_log gives acquisitions per second and the average number of threads waiting on the lock. During the incident there were about 545 waiting threads for 500 running queries:
SELECT
toStartOfMinute(event_time) AS minute,
round(sum(ProfileEvent_ContextLock) / 60) AS locks_per_second,
round(sum(ProfileEvent_ContextLockWaitMicroseconds) / 60e6, 1) AS avg_waiting_threads
FROM system.metric_log
WHERE event_time > now() - INTERVAL 3 HOUR
GROUP BY minute
ORDER BY minute;
System tables are per node, so run both on every replica.
What queries cost
| Query | Context lock acquisitions per call |
|---|---|
SELECT 1 |
6–19 |
count() with FINAL over 26 parts, one parameter |
~230 |
| The report view with a page size of one (29 subqueries, 388 scalar-subquery cache misses, ~0.9 s CPU) | 6,849 |
| A pending change to the same report, as first written | 44,000–67,000 |
| The same change after rework | 4,000–5,200 |
At about one request per second, the change in the last two rows would have consumed three quarters of the lock on its own. The rework made it more than ten times cheaper.
One formula
When the lock is saturated:
latency ≈ concurrent queries × lock acquisitions per query ÷ ceiling
500 × 6,849 ÷ 58,000 ≈ 59 seconds. The observed median was 60.
The same numbers give capacity: 58,000 ÷ 6,849 ≈ 8.5 calls per second per node. The widget sent about 43 per second across two nodes, two and a half times the ceiling.
The formula also shows why raising max_concurrent_queries would not help: throughput stays the same, and latency grows with concurrency (1,000 slots ≈ 120 seconds), while more threads and memory are held.
Versions: the fix exists, just not in 23.8
The upstream fix, "Context lock contention fix" (ClickHouse#55121), was merged in October 2023 and backported to 23.9. The cherry-pick to 23.8 (#55236) was closed without merging. 23.8 is an LTS release.
I reproduced the incident on a 16-core Docker stand: synthetic data with the same 26-part layout, 300 concurrent callers.
| Setup | Throughput | Median latency | Notes |
|---|---|---|---|
| 23.8, original view | 4.0 QPS | 68 s | 72 s of lock wait per query |
| 24.3, old analyzer | 6.0 QPS | 42 s | lock wait 9 ms: the lock is gone, the query is now CPU-bound (2.3 s per call) |
| 25.3, new analyzer | 25 QPS | 9.9 s | scalar subqueries computed once (388 → 10 cache misses), 0.53 s CPU per call |
| 23.8, rewritten view | 22 QPS | — | same version, no upgrade |
any version, dedicated count() |
40–64 QPS | — | 0.2–0.3 s CPU per call |
24.3 removes the lock. With the new analyzer the original view failed, so we ran it with the old one. Only 25.3 with the new analyzer also stops recomputing scalar subqueries. On 80-core production nodes the absolute numbers are higher, but the ratios hold. Under load, CPU per query was 2–2.5 times the single-run figure.
What fixed it
- A counter is not a report. The widget came back the same day on a direct
count()query: about 230 acquisitions per call instead of 6,849. It served up to ~50 requests per second with a median of 45–53 ms and no errors. A dedicated counter view was then load-tested at 400 requests per second per cluster without errors. - Fewer subqueries in the report itself. Move counters into the final SELECT, avoid scalar subqueries in a global WITH, use IN instead of building arrays, compute related counters in one pass. The rewritten view returned byte-identical results and was 3.5–5 times cheaper on the same version.
- Limits per consumer.
max_concurrent_queries_for_userandmax_execution_timestop one consumer from taking all 500 slots and starving everyone else. - An upgrade with a measured case. 24.3 or later for the lock, 25.3 or later with the new analyzer for repeated scalar subqueries.
Takeaways
- Idle CPU plus timeouts means a lock or a queue, not load. Look at wait metrics before adding hardware.
- Measure the cost of a query in the scarce resource. Here it was global lock acquisitions, not CPU or rows. Capacity is the ceiling divided by the cost per call.
- Give every high-frequency consumer its own cheap query. Reusing a full report for a counter works until the traffic changes.
- Raising concurrency limits on a saturated lock makes things worse.
- "LTS" does not mean the fix you need is there. Check backports for your exact version.
All writing · A similar problem? contact@ivanblinov.com