Why my tmux was laggy: the status bar was forking a 1.2 GB server 24 times a second

My tmux had started to feel sluggish. Nothing was broken, it just felt heavy. It turned out the tmux server was using about a third of a CPU core all the time, and nearly all of that went on the status bar. Part of the cost came from the clock workaround in my previous post.

This post covers how I tracked it down, including two wrong guesses, and the fix, which brought the server from ~35% CPU to ~4% without restarting it.

The setup

This is a tmux server that had been running for 23 days:

• tmux 3.5a
• 26 sessions, 167 panes, many of them long-lived ssh sessions
• status-interval 1, so the clock ticks every second
• A status bar full of widgets: CPU, memory, pomodoro timer, API usage limits, a market quote and a clock

The status bar had already been optimized once. An earlier version ran 13 #() shell jobs every second, about 260 process spawns a second. A background daemon (status-daemon.sh) replaced that. It computes the widget values out of band and writes them to small files under ~/.cache/tmux-status/, which the status bar reads back with #(cat ...).

So I didn’t expect the status bar to be the problem.

Step 1: is tmux actually busy?

ps reports a process’s lifetime average CPU, which can be misleading, so sample the live value with top:

1

top -b -d1 -n5 -p "$(pgrep -o -x tmux)" | awk '/tmux/{print $9"% cpu, RES "$6}'

1
2
3
4
5

13.3% cpu, RES 1.2g
50.0% cpu, RES 1.2g
29.0% cpu, RES 1.2g
51.5% cpu, RES 1.2g
26.0% cpu, RES 1.2g

It was busy all the time, and resident memory was 1.2 GB. That memory figure turned out to matter later.

Step 2: suspects that didn’t pan out

Suspect 1: pane output

In tmux, every byte a pane prints is parsed by the server, even in windows you aren’t looking at. I compared capture-pane snapshots taken 3 seconds apart: 66 of 167 panes were changing. That looked like the answer.

Then I measured the actual bytes. My first strace traced only read, but libevent reads ptys with readv, so trace both:

1

timeout 5 strace -p <server-pid> -e trace=read,readv,write,writev,sendmsg -qq -o io.txt

Total pane input came to about 40 KB/s, spread at roughly 1 KB/s per pane. That’s nothing. Output volume wasn’t the problem.

Suspect 2: an 8 KB automatic-rename-format

strace also showed tmux opening /proc/<pid>/cmdline about 220 times a second. That’s tmux resolving #{pane_current_command}. My window-icons.conf sets an automatic-rename-format that maps command names to Nerd Font icons. It’s a single 8 KB nested ternary that references #{pane_current_command} about 200 times, and it gets re-evaluated whenever a window produces output.

It looked guilty, so I tested it directly:

No difference. Counting syscalls tells you what a process does, not what it spends its CPU on. For that you need a profiler.

Step 3: profile it

perf wasn’t installed, but eu-stack (from elfutils) was, and the tmux binary wasn’t stripped. A basic sampling profiler is just a loop:

1
2
3
4
5
6

pid=<server-pid>
for i in $(seq 1 120); do
  eu-stack -p "$pid" -1 2>/dev/null | awk '/^#/{print $NF}' | paste -sd';' >> stacks.txt
  sleep 0.1
done
grep -v '^__poll' stacks.txt | cut -d';' -f1-8 | sort | uniq -c | sort -rn

Samples whose top frame is __poll are tmux sitting idle in its event loop. Of 120 samples, 44 were busy, which fits the ~35% CPU. Nearly all of those 44 had the same shape:

1
2
3

22  _int_free;environ_free;job_run;format_expand1;format_replace;format_expand1;format_expand_time;status_redraw
 8  environ_RB_REMOVE;environ_free;job_run;format_expand1;...;status_redraw
 3  __libc_fork;job_run;format_expand1;...;status_redraw

About 95% of the server’s busy time was in job_run, the function that runs a status-bar #() command.

Don’t run strace and eu-stack at the same time. Both use ptrace, only one can attach to a process, and the other gets nothing back.

Why #() is expensive here

Each #(...) in a status format makes the tmux server:

1. fork itself, then
2. build an environment for the child and free it again in the parent.

Neither step is normally a big deal, but this process had a 1.2 GB heap after 23 days of uptime. Forking it means copying page tables for all of that memory. After the fork, the parent’s pages are shared copy-on-write with the child, so the parent’s next writes, such as the free() calls in environ_free, can trigger page faults. That fits the profile: the time shows up in _int_free and environ_RB_REMOVE, which are not normally expensive functions.

The cost of a job comes almost entirely from forking the server, not from the command being run. #(cat file) costs about the same as a heavy script.

This is what the live status bar was running each second, for each attached client:

1
2
3
4
5
6

status-left:   #(if test -f .../pom_start_time.txt; then ...; fi)   <- pomodoro colour
               #(cat ~/.cache/tmux-status/left_pom)
status-right:  #(cat ~/.cache/tmux-status/right)
               #(cat ~/.cache/tmux-status/quote)                    <- when enabled
               #(TZ=Asia/Tokyo date +%b%d)                          <- timezone workaround
               #(TZ=Asia/Tokyo date +%H:%M:%S)                      <- timezone workaround

With two clients attached, plus the daemon forcing refreshes with refresh-client -S, strace counted about 24 forks a second.

To confirm, I replaced both status formats with job-free versions for a few seconds:

(My first attempt at this test also showed ~38% with no jobs. I never worked out why, but a clean rerun and the profiler agreed with each other, so I trusted those.)

The timezone workaround was part of the cost

In the previous post, the system timezone changed to Asia/Tokyo after the tmux server had started, and the server kept formatting %H:%M:%S in the old timezone:

1
2
3

$ tmux display -p '%H:%M:%S'; date +%H:%M:%S
10:33:20
11:33:20

The workaround swapped the clock for #(TZ=Asia/Tokyo date ...). It fixed the time but added two more forks of the server per second per client. It was also only a runtime setting: .tmux.conf still used the built-in %H:%M:%S, so a prefix r reload would have brought the wrong time back.

The fix: one job per side

Every #() costs one fork of the big server, no matter what it runs. But the shell inside the job can fork as often as it likes, because it’s a small process. So merge each side of the status bar into a single job that runs a script.

~/.tmux/scripts/status-left.sh:

1
2
3
4
5
6
7
8
9

#!/bin/sh
# $1: session name
if [ -f "$HOME/.tmux/plugins/tmux-pom/data/pom_start_time.txt" ]; then
    printf '#[fg=black,bg=yellow,bold]'
else
    printf '#[fg=black,bg=blue,bold]'
fi
printf ' XPS:%s #[nobold,italics,nounderscore]' "$1"
cat "$HOME/.cache/tmux-status/left_pom" 2>/dev/null

~/.tmux/scripts/status-right.sh (Nerd Font icons left out here):

 1
 2
 3
 4
 5
 6
 7
 8
 9
10
11

#!/bin/sh
# $1: 1 to show the quote (the @quote_cond format), else 0
dir="$HOME/.cache/tmux-status"

cat "$dir/right" 2>/dev/null
if [ "$1" = 1 ]; then
    printf '#[fg=color244,bg=brightblack,noitalics]'
    cat "$dir/quote" 2>/dev/null
    printf ' '
fi
date '+#[fg=blue,bg=brightblack,noitalics,nounderscore] %b%d #[fg=blue,bg=brightblack]%H:%M:%S#[fg=cyan,bg=brightblack,nobold,noitalics,nounderscore]'

And in .tmux.conf:

1
2

set -g status-left  "#($HOME/.tmux/scripts/status-left.sh #{q:session_name})"
set -g status-right "#($HOME/.tmux/scripts/status-right.sh #{E:#{@quote_cond}})"

A few details that matter:

• tmux expands formats inside the job command before running it. #{q:session_name} passes the session name, shell-quoted, and #{E:#{@quote_cond}} passes the quote condition as 1 or 0. Anything that depends on the client or session goes in as an argument.

• Job output is not re-expanded as a format. Writing #S in the output wouldn’t work, which is why the session name comes in as an argument. #[...] style tags in the output are honored, so the colors still work.

• No %% escaping needed any more. tmux runs strftime over status formats before running the jobs, which is why the old inline version had to write date +%%H:%%M:%%S. Inside the script, date gets plain %H:%M:%S.

• The clock comes from date, not tmux’s %H:%M:%S. date reads the system timezone each time it runs, so the time is right on this old server and on any fresh one. The timezone workaround is no longer needed.

• Check for invisible characters. My first edit to the config failed because the old status-right line held two Nerd Font glyphs that didn’t show in the terminal. This shows them:

  1 2	grep '^set -g status-right' ~/.tmux.conf \ | perl -CSD -pe 's/([^\x00-\x7F])/sprintf("<U+%04X>",ord($1))/ge'

  Without that check, the calendar and clock icons would have silently disappeared from the bar.

Before switching, I compared the script output byte for byte with the old status line. Then I applied just those two options to the running server with tmux set -g, with no restart and no full config reload.

Results

Takeaways

1. Measure CPU, don’t infer it from syscalls. Both of my early suspects looked convincing in strace and made no measurable difference. A 30-second sampling loop with eu-stack found the real cause straight away.
2. In tmux, every #() is a fork of the server. On a server that’s been up for weeks with lots of scrollback, that’s expensive. Count your #()s and merge them. One job running a script is much cheaper than five jobs each running cat.
3. A long-running tmux server keeps the timezone it started with. Get the time from date inside a job you already run, rather than adding new jobs.
4. Restarting fixes both. A fresh server would shrink back to a small heap, which makes forks cheap, and pick up the current timezone. tmux kill-server also ends every session, though. With 167 panes of live ssh sessions I didn’t want to do that, and the fix above works without it.

References

• tmux manual: FORMATS, #() jobs and the q/E modifiers
• tmux source: format_job_get() and job_run()
• eu-stack (elfutils)