cpu.sh loads twice

[RafalLukawiecki]

I wonder if this is intended or an issue, but it looks like I have two cpu.sh running:

On another note, feels like all of this should be achievable without having to run so many shells. :) Just an idea for future consideration... On my dev server I saw 29 shells (for just one user) all spawned by the status plug-ins. I will investigate a bit more.

[samoshkin]

I've investigated the issue.

Here is a sysdig trace of what bash child processes are spawned by tmux process:

$ pgrep tmux 
  23956
  23958
$ sudo sysdig -p "%evt.time.s | %proc.args %proc.pid" 'proc.name=bash and evt.type=execve and evt.dir = < and proc.ppid=23958'

18:45:51 | /home/alexeys/.tmux/plugins/tmux-plugin-sysstat/scripts/loadavg.sh 32511
18:45:51 | /home/alexeys/.tmux/plugins/tmux-online-status/scripts/online_status_icon.sh 32513
18:45:51 | /home/alexeys/.tmux/plugins/tmux-plugin-sysstat/scripts/mem.sh 32510
18:45:51 | /home/alexeys/.tmux/plugins/tmux-plugin-sysstat/scripts/cpu.sh 32621

18:45:55 | /home/alexeys/.tmux/plugins/tmux-plugin-sysstat/scripts/mem.sh 32677
18:45:55 | /home/alexeys/.tmux/plugins/tmux-plugin-sysstat/scripts/loadavg.sh 32678
18:45:55 | /home/alexeys/.tmux/plugins/tmux-online-status/scripts/online_status_icon.sh 32680
18:45:55 | /home/alexeys/.tmux/plugins/tmux-plugin-sysstat/scripts/cpu.sh 32676

18:45:56 | /home/alexeys/.tmux/plugins/tmux-plugin-sysstat/scripts/loadavg.sh 341
18:45:56 | /home/alexeys/.tmux/plugins/tmux-plugin-sysstat/scripts/mem.sh 340

18:45:59 | /home/alexeys/.tmux/plugins/tmux-plugin-sysstat/scripts/mem.sh 454
18:45:59 | /home/alexeys/.tmux/plugins/tmux-plugin-sysstat/scripts/loadavg.sh 455
18:45:59 | /home/alexeys/.tmux/plugins/tmux-plugin-sysstat/scripts/cpu.sh 453

18:46:01 | /home/alexeys/.tmux/plugins/tmux-plugin-sysstat/scripts/loadavg.sh 582
18:46:01 | /home/alexeys/.tmux/plugins/tmux-plugin-sysstat/scripts/mem.sh 581

18:46:03 | /home/alexeys/.tmux/plugins/tmux-plugin-sysstat/scripts/mem.sh 696
18:46:03 | /home/alexeys/.tmux/plugins/tmux-plugin-sysstat/scripts/loadavg.sh 697
18:46:03 | /home/alexeys/.tmux/plugins/tmux-plugin-sysstat/scripts/cpu.sh 695

You can see that the bunch of status bar processes (loadavg, onlinestatus, mem, cpu) are started on 18:45:51. Status refresh interval is set to 5 seconds, so the next round is expected on 18:45:56, but instead we see 2 rounds: 18:45:55, followed by 18:45:56. Apparently, 5 seconds interval execution pattern is broken.

Besides that, from the trace you can see that cpu.sh is executed once per 4 seconds strictly (without any duplication), and instead we have more frequent execution of mem and loadavg scripts.

Reasons for such behavior:

• cpu.sh script is different from others scripts, because it's a long running process (4 seconds = 1 second less than status var refresh interval) to collect CPU value for given interval period, rather than pick the average since the system startup.
• tmux's status bar does not wait for such long running processes, and displays the last available value it has immediately.
• When cpu.sh exits after 4 seconds, status bar displays new value, and additionally refreshes other metrics/scripts. That's why you see mem and loadavg executed after 4 seconds, instead of 5. This is internal tmux behavior, it refreshes status bar whenever it decides the best time, and refresh interval settings is just a hint, not a strict rule. Read more here: https://github.com/tmux/tmux/issues/797#issuecomment-283269499

So, all this stuff is rather complicated, but the root cause is the long-running tmux-plugin-sysstat/cpu.sh script, which does 2 things: collect CPU metric for given period, and prints it to show in status bar. I'm going to create a separate issue in https://github.com/samoshkin/tmux-plugin-sysstat repo, and redesign cpu.sh script to eliminate long-running nature.

[samoshkin]

The reason why you see two cpu.sh processes in your ps -A output, might be due to how new processes are spawned by Linux kernel. For example, when cpu.sh runs awk or sed or any other sub-command, kernel clones cpu.sh process, and then loads command code (awk) into newly cloned process. You can see 2 cpu.sh processes within a short interval after kernel clones process but before it execs new command.

What is more likely is the usage of user-defined functions, which obey the same cloning logic. So ps output shows 2 cpu.sh processes: 1st is the root process, and 2nd dedicated to run a function.

[samoshkin]

I've redesigned behavior of tmux-plugin-sysstat cpu.sh. See https://github.com/samoshkin/tmux-plugin-sysstat/issues/4#issuecomment-351129368.

Now, from a sysdig trace, we can ensure, that cpu.sh, mem.sh, loadavg.sh are run strictly once per $status-refresh-interval.

19:43:46 | /home/alexeys/.tmux/plugins/tmux-plugin-sysstat/scripts/mem.sh 13638
19:43:46 | /home/alexeys/.tmux/plugins/tmux-plugin-sysstat/scripts/loadavg.sh 13639
19:43:46 | /home/alexeys/.tmux/plugins/tmux-online-status/scripts/online_status_icon.sh 13641
19:43:46 | /home/alexeys/.tmux/plugins/tmux-plugin-sysstat/scripts/cpu.sh 13637

19:43:51 | /home/alexeys/.tmux/plugins/tmux-plugin-sysstat/scripts/mem.sh 13786
19:43:51 | /home/alexeys/.tmux/plugins/tmux-plugin-sysstat/scripts/loadavg.sh 13787
19:43:51 | /home/alexeys/.tmux/plugins/tmux-online-status/scripts/online_status_icon.sh 13789
19:43:51 | /home/alexeys/.tmux/plugins/tmux-plugin-sysstat/scripts/cpu.sh 13785

19:43:56 | /home/alexeys/.tmux/plugins/tmux-plugin-sysstat/scripts/mem.sh 13934
19:43:56 | /home/alexeys/.tmux/plugins/tmux-plugin-sysstat/scripts/loadavg.sh 13935
19:43:56 | /home/alexeys/.tmux/plugins/tmux-online-status/scripts/online_status_icon.sh 13937
19:43:56 | /home/alexeys/.tmux/plugins/tmux-plugin-sysstat/scripts/cpu.sh 13933

For you local installation, you need to remove tmux-plugin-sysstat and reinstall it to catch up with changes.

rm -rf ~/.tmux/plugins/tmux-plugin-sysstat
cd /path/to/your/tmux-config
./install.sh

[samoshkin]

@RafalLukawiecki Could you please also check if I haven't broken things for FreeBSD regarding CPU calculation. I don't have FreeBSD installation right here. Especially this code: https://github.com/samoshkin/tmux-plugin-sysstat/blob/master/scripts/cpu_collect.sh#L34-L37 https://github.com/samoshkin/tmux-plugin-sysstat/blob/master/scripts/cpu_collect.sh#L26-L28

And it looks like you don't specify interval for how often to take samples, when using top.

top -d"$samples_count" \
        | sed -u -nr '/CPU:/s/.*,[[:space:]]*([0-9]+[.,][0-9]*)%[[:space:]]*id.*/\1/p' \
        | stdbuf -o0 awk '{ print 100-$0 }'

Better to align it with $status-refresh-interval, otherwise I guess it takes new sample per second. Something like this works:

vmstat -n "$refresh_interval" -c "$samples_count" \
        | stdbuf -o0 awk 'NR>2 {print 100-$(NF-0)}'