Skip to content

listener: stop burning 9 % CPU while nothing is happening - #42

Open
porterchild wants to merge 1 commit into
acehoss:mainfrom
porterchild:fix/pump-sleep-rate
Open

porterchild wants to merge 1 commit into
acehoss:mainfrom
porterchild:fix/pump-sleep-rate

Conversation

@porterchild

Copy link
Copy Markdown

I was running the listener on a raspberry pi, and it was using enough cpu at idle to interfere with snappiness of other things running on the pi. Hence this optimization.
PR made with @porterchild 's supervision by Qwen 3.8 flash next (running locally, sovereign AI FTW):

A listener holding one idle session uses ~9% CPU and wakes ~100x/s while doing nothing. The main loop paces itself with helpers.SleepRate, but SleepRate.next_sleep_time() built the next wake time from a hard-coded 0.01 instead of self.target_period — the constructor argument was never read, so every SleepRate was a fixed 100 Hz clock. Both callers pass 0.01, which is why it went unnoticed: the knob only fails when you try to turn it.

Why pump_all() has to return something. listener.py already sleeps only when a pump pass sent nothing (if not await pump_all(): await sleeper.sleep_async()), but pump_all() returned None, so that was always true and the loop slept after every pass. At 100 Hz that is harmless; at 0.25 s it means one chunk per 0.25 s, and a send refused by a congested channel only gets retried once per pump pass — 55% of bulk throughput. Returning the flag is what makes throughput independent of the pump rate.

Pump period pump_all() returns Bulk, 274 KB
0.01 (HEAD) no 3.44–3.65 s
0.01 yes 3.44 s
0.25 no 5.49–5.70 s
0.25 yes 3.45–3.65 s

One idle session, interleaved A/B:

CPU Wake/s Session close
HEAD 9.37 % 99 3.56 s
This 1.17 % 14 3.75 s (+0.18)

Chatty session (5 lines/s): 10.7 % → 2.2 %. 0.25 s is the floor — the residue is CallbackSubprocess polling at 10 Hz, and 0.5 s measured identical close latency for no further gain. Worst case it adds is 250 ms before the first byte of output after a quiet gap.

rnsh/initiator.py also uses SleepRate(0.01) and is untouched; with the helper fixed, slowing it down later is a one-line change.

Alternatives considered:
-Event-based instead of polling mechanism. This was significantly more complex and not significantly more responsive or efficient.

Tests: 27 pass. test_rnsh.py fails identically before and after (6 pre-existing failures here), and test_protocol.py is uncollectable before and after (RNS.Channel.ChannelOutletBase).

SleepRate.next_sleep_time() built the next wake time from a hard-coded
0.01 rather than self.target_period, so the constructor argument was
never read and every SleepRate was a fixed 100 Hz clock. Both callers
pass 0.01, which is why it went unnoticed: the knob only fails once you
try to turn it. Use target_period, and pump the listener loop at 0.25s
instead of 0.01s.

pump_all() was written to report whether it sent anything, since
listener.py sleeps only when a pass sent nothing, but it returned None
under a `-> True` annotation. Return the flag. This is what keeps bulk
throughput independent of the pump period: a send refused by a congested
channel is otherwise retried once per pump pass, so without it 0.25s
costs ~55% of bulk throughput, while at 0.01s the flag changes nothing.

A listener holding one idle session goes from 9.4% CPU and 99 wakeups/s
to 1.2% and 14; a chatty session from 10.7% to 2.2%. Bulk is unchanged
(3.5s for 274KB), and session close latency costs +0.18s on a path that
already takes ~0.55s plus link RTT. 0.25s is the floor: the residue is
CallbackSubprocess polling at 10Hz, and 0.5s measured the same latency
for no further gain.
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

1 participant