Our product search runs on Elasticsearch, a single node on a VPS. One morning the item picker was taking over four seconds per search, and chatbot searches were hitting our 15-second timeout whenever three or four ran at once.

So I did what you do. I profiled the query.

A day of real fixes to the wrong problem

The query had plenty wrong with it. Fuzzy terms were being re-expanded across the whole index dozens of times per search, and a set of coverage clauses scored the same constant for every hit. I cut both, and a 28-search benchmark went from 86.6s to 57.7s, a third faster with identical results.

It was still slow. The node looked CPU-bound: no disk reads under load, no GC pauses, no container CPU quota. I started writing a message asking for more cores and a sharded index.

The numbers were too round

Then I sent the same tiny query twenty times. It needs about 5ms of work. The timings came back:

598 299 99 98 100 177 102 205 98 100 99 102 102 5 99 199 201 101 4 99

Real work doesn't land on 100, 200 and 300. Waiting does. Linux hands out CPU in 100ms periods, and when you're over your limit you sit out the rest of the period. Every query was spending most of its life waiting for its next slice.

Elasticsearch couldn't see it because the limit wasn't on its container. It was on the whole machine. 

one 5ms query, two machinesunthrottled   █                                   5ms
throttled     █·········|█·········|█·········|   ~300ms
                        └── each 100ms period, the box runs out of CPU and waits

The host was rationing us

The VPS panel had a banner: your server's CPU is temporarily limited. Shared hosting runs on CPU credits. Burn too much for too long and the host caps the whole box until you calm down.

Something had been burning. The top process wasn't Elasticsearch. It was Logstash, which came with the stock ELK docker setup. Nothing of ours sends it a single log line. 

restarts=41687 policy=unless-stopped

Its container memory limit was 512MiB, and so was its JVM heap. Heap plus everything else a JVM needs doesn't fit in the heap size, so the kernel killed it on every boot. Docker restarted it, it booted again at about two and a half cores of CPU, and got killed again, 41,687 times.

The query wasn't slow, the machine was rationed. A runaway process I'd never looked at had spent the server's CPU credits, and every request on the box paid for it.

The fix was one line in a compose file

I commented out the service and deleted the container.

  • Elasticsearch CPU: 904% → 60%
  • the 5ms query: 99-598ms → 4-6ms
  • item picker search: ~4.2s → ~300ms
  • time per Elasticsearch call: 1-2s → 64-87ms

The query work wasn't wasted, but the sharding plan went in the bin.

What I'd check first next time

If latency moves in neat steps of 100ms, stop reading query plans. You are being throttled, and the cause can be anything else on the box.

  • Look at the host's usage page and docker stats before you touch a line of code.
  • Check restart counts. A container that restarts forever never shows up as "down".
  • Don't run the parts of a stack template you don't use. On a shared box, one runaway process slows everything else.