sleep() won't let me sleep - how I fix accurate timer counter in my code

Post by **bbfox** » Sun Aug 09, 2026 9:41 am

TL;DR — In CE Lua, sleep(1) and sleep(10) cost exactly the same 15.47 ms. If your timeout loop counts iterations and calls it milliseconds, your "10 second" timeout is really ~ 155 seconds. Below is how I found it, how to measure it yourself, the numbers on my box, the CE-freeze half of the story, and what n to actually put in sleep(n) if you just want a poll loop and don't want to think about any of this.

All numbers here are measured, not estimated. Conditions: CE 7.7 (getCEVersion() = 7.70), Windows 11 26200, 100 iterations per row, pumped with processMessagesPaintOnly() every 10 iterations. Your mileage may vary but probably won't — see "Root Cause".

1. How I found it: the 10000 x sleep(1) loop

I have a Lua script that pokes a mailbox in an injected DLL and waits for the DLL to answer. Standard shape, everybody writes this:

Code: Select all

-- The ORIGINAL code. Looks fine. Is not fine.
local MAX_ITERS = 10000          -- "10 seconds", right? 10000 x 1 ms. Right??
local iters = 0

while readBytes(mailbox + STATUS_OFF, 1, true) ~= 1 do
  sleep(1)
  iters = iters + 1
  if iters >= MAX_ITERS then
    print('timeout after 10 s')  -- LOL no
    return
  end
end

Then one day the DLL did not answer, and instead of the 10-second timeout I designed, CE sat there like a brick for over two and a half minutes. Title bar went "Not Responding", window went white, the whole thing. I killed it twice before I got suspicious.

Repro is 3 lines. Paste into CE Lua Engine, Execute, then go make coffee:

Code: Select all

local t0 = getTickCount()
for i = 1, 10000 do sleep(1) end
print(getTickCount() - t0)      -- expect ~ 10000.  Actual: ~ 154700

~ 155 seconds for a loop I costed at 10. That is 15.5x. Not a rounding error, not "scheduler jitter", not my machine being busy. It is deterministic and it reproduces every time.

FYI, the same run also demonstrates symptom #2 — CE is frozen the whole time. Two separate bugs riding in the same loop. More on that in §5.

2. Root Cause

Two facts, and neither of them is Lua's fault:

sleep is not standard Lua. Stock Lua has no sleep at all — verified on Lua 5.4.6, type(sleep) is nil, no luasocket, no FFI. CE registers its own (lua_sleep in LuaHandler.pas), which is a thin wrapper over FPC sleep() → Win32 sleep().
Win32 sleep() is quantised to the system timer tick, which by default is ~ 15.625 ms (64 Hz). Any request smaller than one tick still costs one whole tick. You cannot buy a shorter nap than the OS sells.

So sleep(1) does not sleep 1 ms. It sleeps until the next tick. 10000 of those = 10000 x 15.47 = ~ 154.7 s. Mystery solved, and the culprit is Windows, as usual.

Two corollaries people get wrong:

sleep(0) measures 0.000 ms. sleep(0) yields the remaining timeslice — it does not pause. Don't use it as a "tiny sleep", it is a different API contract.
There is no "Sleep never returns early" guarantee. Microsoft's own synchapi.h Remarks:
if the value is less than the clock resolution the thread may sleep less; if it is between one and two ticks the wait can land anywhere in between. So it is a band, not a constant. That bites in §4.

This also means the quantisation belongs to Win32, not to CE and not to Lua. Any language sitting on that API is on the same grid. C# Thread.Sleep is literally the same call — I used that fact later to settle an argument, see §4.

3. Detect it yourself + the numbers (sleep(n) x 1000)

Detection is easy once you know to look. Time a back-to-back loop and compare sleep(1) against sleep(10) — if they are the same, you have found the floor:

Code: Select all

local ITERS = 100
local function measure(n)
  local a = getTickCount()
  for i = 1, ITERS do sleep(n) end
  return (getTickCount() - a) / ITERS
end
print(string.format('sleep(1)=%.3f  sleep(10)=%.3f', measure(1), measure(10)))
-- => sleep(1)=15.470  sleep(10)=15.470     <-- same price. You get no discount.

Double check your ruler first, otherwise you are measuring the wrong thing:

Code: Select all

local t0, t1, spins = getTickCount(), nil, 0
t1 = t0
while t1 == t0 do t1 = getTickCount(); spins = spins + 1 end
print(string.format('timer tick: %.3f ms (after %d spins)', t1 - t0, spins))
-- => timer tick: 16.000 ms (observed after 164096 spins)

Note that: getTickCount() is itself tick-granular. It is good enough to catch a 15x error, and useless for anything finer. Remember this, it comes back in §4.

The table

Measured per call, then x1000 so you can see what a 1000-iteration loop actually costs. (x1000 column is the measured per-call value scaled, not a separate 1000-iteration run.)

sleep(n)	measured / call	x1000 = actual	you budgeted	overshoot
sleep(0)	0.000 ms	0.0 s	0 s	N/A — yield, not a pause
sleep(1)	15.470 ms	15.5 s	1 s	15.5x
sleep(2)	15.460 ms	15.5 s	2 s	7.7x
sleep(5)	15.470 ms	15.5 s	5 s	3.1x
sleep(10)	15.470 ms	15.5 s	10 s	1.55x
sleep(15)	19.690 ms	19.7 s	15 s	1.31x — unstable, see below
sleep(16)	30.160 ms	30.2 s	16 s	1.89x
sleep(20)	30.940 ms	30.9 s	20 s	1.55x
sleep(30)	31.560 ms	31.6 s	30 s	1.05x
sleep(250)	261.880 ms	261.9 s	250 s	1.05x

Three things worth staring at:

The flat floor, sleep(1) through sleep(10), all 15.47. Asking for less does not get you less. If you wrote sleep(1) for "fast polling", congratulations, you have been polling at 64 Hz this whole time and paying full price.
sleep(15) -> sleep(16) jumps 10 ms for 1 ms more requested. 15.625 is the tick, so 15 sits right on the edge and jitters between one and two ticks (that is why its row reads 19.69 instead of a clean 15.47 — some iterations took two ticks). 16 is over the line and always pays two ticks.
sleep(250) = 261.88 ms. 250 is exactly 16 ticks, and it is the worst row in the table. This one cost me a code change: I had picked 250 as a pump-slice constant precisely because it was a whole number of ticks, on the theory that it would introduce no quantisation. The measurement says the reasoning was backwards — sitting exactly on a tick edge means any jitter at all costs a whole extra tick. Compare sleep(20) and sleep(30): both land mid-band, both within 0.2 ms of prediction. I changed the constant to 242. Landing mid-band is strictly better.

4. Warning: the table above is the special case

Everything above is a back-to-back loop — each sleep() wakes on a tick edge and immediately sleeps again, so the phase is pinned near 0 and you get clean tick multiples.

A real call site is not like that. Real code does work between the waits (an aobscan, a readBytes(), a "mr.Active = true"), and that work takes an arbitrary amount of time, which scrambles the phase. Then sleep(n) is spread over [n, n + one tick], mean near the middle:

n	mean	observed range	[n, n+tick]	back-to-back	n + tick/2
5	13.111	[5.101, 20.557]	[5, 20.625]	15.625	12.813
30	38.114	[30.125, 45.618]	[30, 45.625]	31.250	37.813
100	108.374	[100.152, 115.528]	[100, 115.625]	109.375	107.813

Total error: back-to-back model 10.38 ms, n + tick/2 model 1.16 ms. The give-away is the range, not the mean — the observed min/max land exactly on [n, n + one tick], and a uniform distribution over that interval has mean n + tick/2.

How I had to measure this, and why it matters to you: I could not settle it inside CE. CE's only clock is getTickCount, which IS the ~ 15.6 ms tick I was trying to resolve, and a busy-spin waiting on it can only ever exit on a tick edge — so the phase cannot be scrambled from inside CE at all. I "confirmed" the wrong model twice off a broken instrument before noticing. Since CE sleep() → Win32 Sleep() → same API as C# Thread.Sleep, I moved the probe out to a small C# program with QueryPerformanceCounter (100 ns) and 400 samples per row, and it separated the two models on the first run — 10x difference in error.

Lesson, free of charge: when your measuring instrument is coarser than the effect you are measuring, it will happily tell you whatever you want to hear. My model flipped three times before I changed rulers. Root Cause: instrument, not physics.

Sanity check that the two environments are on the same grid: the C# back-to-back numbers match the CE ones — 15.58 vs 15.47, 31.14 vs 30.94, 259.7 vs 261.9. Same tick, same behavior.

5. The other half: why CE freezes, and which paint function to use

Issue: CE's sleep is a bare sleep(). It pumps nothing. No paint, no messages, nothing. Your GUI thread is just gone for the duration. Windows greys the window out at roughly the 5-second mark and stamps "Not Responding" on it. CE is not crashed — it just isn't pumping.

You have two pumps, and they are not interchangeable:

pump	cost per call	dispatches	can it re-enter your code?
processMessagesPaintOnly()	~ 0.00 ms (below measurement)	repaint only	No
processMessages()	~ 20.30 ms	mouse + keyboard + timers, can run other Lua	Yes

Measured side by side, same machine, same session, pump every 10 iterations:

pump	floor (sleep(1))	sleep(20)	sleep(30)
processMessagesPaintOnly	15.470	30.940	32.190
processMessages (fallback)	19.220	34.380	35.620

CE's own celua.txt calls processMessages() "not recommended". Now you have a measured reason on top of the documented one — it is not free, and the backlog grows with the time since the last pump, so the longer you go between pumps the more it costs when you finally call it. (Note: in a tight loop with no sleeping, the "no sleep" row reads 0.000 for both — no backlog to dispatch, nothing to pay for.)

The trade-off nobody mentions

With paint-only you cannot move the CE window. No dragging the title bar, no clicking buttons, no keyboard. It repaints, so it looks alive and Windows won't grey it out — but it is non-interactive for the whole wait. That is the deal:

processMessagesPaintOnly → CE looks alive, stays responsive-looking, cannot be moved or clicked, and cannot re-enter your handler. Free.
processMessages → CE is fully interactive, you can drag the window and click things — and the user can click the same button again and re-enter you mid-run. If you use this you need a re-entrancy latch, or your toggle ends up half-on-half-off. Costs ₂₀ ms a call.

For a background wait, paint-only is the right default. For a long batch apply where the user might reasonably want to cancel, processMessages() + a busy latch is defensible. Please align on one and don't mix.

Detection: feature-test, NEVER version-gate

Code: Select all

-- CORRECT. An undefined global in Lua is nil, not an error, so old CE degrades quietly.
local _pump = (type(processMessagesPaintOnly) == 'function')
              and processMessagesPaintOnly
              or  processMessages

Code: Select all

-- WRONG. Do not do this.
local _pump = (getCEVersion() >= 7.7) and processMessagesPaintOnly or processMessages

Why: processMessagesPaintOnly is absent from the entire CE 7.5 public source tree, yet present and working in the 7.7 binary. So the introducing version is genuinely unknown (7.6?), and any threshold you pick is a guess. Worse — the public source lags the release, so "I grepped the source and it isn't there" does not prove "it isn't in the build you're running". I got burned by exactly that three times in one session. type(x) == 'function' tests the thing itself. Just test the thing itself.

6. The actual fix I did: stop counting iterations, use a real deadline

Iteration counting is the bug. The sleep duration is not a constant you control, so any loop that multiplies "iterations x assumed ms" is wrong by construction. Measure real elapsed time:

Code: Select all

local TIMEOUT_MS = 10000
local _pump = (type(processMessagesPaintOnly) == 'function') and processMessagesPaintOnly or processMessages
local _tick = (type(getTickCount) == 'function') and getTickCount or nil

local _deadline = _tick and (_tick() + TIMEOUT_MS) or nil
local _iters, MAX_ITERS = 0, 4000            -- fallback only, for a CE with no getTickCount
local timedOut = false

while readBytes(mailbox + STATUS_OFF, 1, true) ~= 1 do
  if _pump then _pump() end                  -- CE's sleep pumps nothing. This line is not optional.
  sleep(10)                                  -- see §7 for why 10 and not 1
  _iters = _iters + 1
  if (_deadline and _tick() >= _deadline) or (not _deadline and _iters >= MAX_ITERS) then
    timedOut = true
    break
  end
end

if timedOut then
  print('mailbox timeout - DLL did not respond')
  return                                     -- a timeout IS an error. Do not fall through.
end

Notes on that shape, all of them learned the hard way:

getTickCount() deadline, iteration count only as a fallback. getTickCount exists in every CE that matters, but the fallback errs long (~ 22 s instead of 10 s if the fallback pump is processMessages()) rather than short, which is the safe direction.* Pump before the sleep, i.e. as the first statement of the loop body, so the repaint happens before you go dark rather than after.
A timeout is an error path. return, don't break into your success handling. And if your script auto-closes the Lua Engine window on success, make that close unreachable from every error path — otherwise the window that would have shown the user what went wrong closes itself. Ask me how I know.
If your protocol distinguishes failure modes, read them instead of guessing. In my case status 0 = the DLL never picked the command up (usually a stale mailbox address) and 0xFF = it took the command and wedged. Two completely different bugs, one useless "timeout" message.

7. "I don't care, just tell me what number to put in sleep()"

Fair. Here is the cheat sheet.

Default answer: sleep(10). (easy to remember)

Rationale, since the number looks arbitrary:

Anything from sleep(1) to sleep(14) costs the same one tick (~ 15.5 ms). sleep(1) is not faster than sleep(10), it is only more dishonest. Write the number you are actually paying.
10 keeps ₅ ms of margin below the 15.625 tick edge, so it will not randomly jitter up to two ticks the way sleep(15) does.
₁₅.5 ms per poll = ~ 64 Hz. For reference, my DLL mailbox round-trips complete in 0–55 ms, so a 15.5 ms polling granularity adds at most one tick of latency. Anything finer is imaginary anyway.

If you want to poll gentler (long waits, don't want to spin the pump 64 times a second), pick a mid-band value, not a tick multiple:

want	use	actual	why
~ 64 Hz	sleep(10)	~ 15.5 ms	1 tick, mid-band
~ 32 Hz	sleep(24)	~ 31.3 ms	2 ticks, mid-band
~ 21 Hz	sleep(40)	~ 46.9 ms	3 ticks, mid-band
chunking a long wait	sleep(242)	~ 250 ms	mid-band; not 250, which measures 262

Avoid these — they sit on or next to a tick boundary and will jitter a whole extra tick: 15, 16, 31, 32, 46, 47, 62, 63, 250. The tick multiples are 15.625, 31.25, 46.875, 62.5, 78.125, 93.75, 109.375, 125 ... anything within a millisecond or two of those is a bad pick.

And regardless of which n you choose:

Never count iterations as a time budget. getTickCount() deadline, always.
Always pump inside the loop, or CE goes white and the user kills it.
Feature-test the pump, don't version-gate it.

Or, use formula: n_k = round(15.625 × k − 7.8125) k = 1, 2, 3 ...

k	sleep(n)	actural	pooling freq	condition
1	8	15.6 ms	64 Hz	memory pooling for response like shared mem
2	23	31.3 ms	32 Hz	general pooling
3	39	46.9 ms	21 Hz	i.e. waiting for DLL response
4	55	62.5 ms	16 Hz	background jobs
5	70	78.1 ms	12.8 Hz
6	86	93.8 ms	10.7 Hz
7	102	109.4 ms	9.1 Hz
8	117	125.0 ms	8 Hz	long wait, UI heartbeat
9	133	140.6 ms	7.1 Hz
10	148	156.3 ms	6.4 Hz	slow pooling

or calc yourself. for example round(15.625 * 16 − 7.8125) = 242

8. Summary

Issue:       "10 second" Lua timeout actually took ~ 155 s, and froze CE while doing it. Root Cause: CE sleep() -> FPC Sleep() -> Win32 Sleep(), 
             quantised to the ~ 15.625 ms system tick. Every sub-tick request costs one whole tick. Also, sleep() pumps no messages at all.
Action Item: (1) replace iteration counting with a getTickCount() deadline
             (2) pump every iteration, prefer processMessagesPaintOnly, feature-tested
             (3) use sleep(10) as the poll step; avoid exact tick multiples
             (4) treat timeout as an error path, not a fall-through
Status:      Fixed. Every emitted script in my project now uses the same shape.
ETA:         N/A, already shipped.