gum log performance prohibitively slow in some (all?) envs

[adamscybot]

Describe the bug
I am using gum log throughout my shell script and I notice that it is really quite slow to invoke. Here is a comparison of 100 invocations of it against /bin/echo (not echo built into shell so both still have extra process cost) just printing test.

As such, logging in any shell script using gum log makes everything feel tangibly slower and is essentially the bottleneck in my script.

I would of course, expect it to be slower than /bin/echo, so the comparison isn't entirely equal. But this much slower feels like a surprise and because of the use case of logging, its particularly a problem. Here it is with all output put into /dev/null:

Total execution time for 100 x /bin/echo: .046960733 seconds
Total execution time for 100 x gum log: 10.509139363 seconds

And here it is without suppressing the output:

Total execution time for 100 x /bin/echo: .048689755 seconds
Total execution time for 100 x gum log: 16.446838094 seconds

---

To Reproduce

Put this shell script somewhere:

#!/bin/bash

measure_time() {
    local command_name="$1"
    local command_exec="$2"
    local start_time=$(date +%s.%N)

    for i in {1..100}; do
        $command_exec > /dev/null 2>&1
    done

    local end_time=$(date +%s.%N)
    local elapsed_time=$(echo "$end_time - $start_time" | bc)
    echo "Total execution time for 100 x $command_name: $elapsed_time seconds"
}

measure_time "/bin/echo" "/bin/echo test"
measure_time "gum log" "gum log test"

Then execute it. This uses bash in the shebang but the shell used to execute it appears not to matter.

You can remove the > /dev/null 2>&1 if wanting to try with it printing visibly to console.

Expected behaviour
I would expect the gum log invocation time to be much cheaper.

Desktop (please complete the following information):

OS: Ubuntu 24.04.1 LTS on WSL2

Machine pretty cutting edge (9800X3D CPU).

Result of wsl --version:

WSL version: 2.3.26.0
Kernel version: 5.15.167.4-1
WSLg version: 1.0.65
MSRDC version: 1.2.5620
Direct3D version: 1.611.1-81528511
DXCore version: 10.0.26100.1-240331-1435.ge-release
Windows version: 10.0.26100.2894

Result of gum --version:

gum version v0.15.2 (d1fc051)

[adamscybot]

On native windows Windows, outside of WSL (using gum.exe), with this PowerShell script...

 Measure-Command {
         for ($i = 1; $i -le 100; $i++) {
             & .\gum.exe log test *> $null
         }
     }

Gives 2.7699517 seconds.

This is much better, but that will be because it's outside the WSL VM probably. Either because of the perf gains of that or that part of the problem is also linked to UNIX flows, or both.

Even this is still quite high I feel. There has to be some compute going on that makes the problem aggravated and especially visible on "weaker" envs.

Back to UNIX, There is an extremely high amount of voluntary context switches:

➜  ~ /usr/bin/time -v gum log test >/dev/null  
 test
        Command being timed: "gum log test"
        User time (seconds): 0.01
        System time (seconds): 0.02
        Percent of CPU this job got: 29%
        Elapsed (wall clock) time (h:mm:ss or m:ss): 0:00.15
        Average shared text size (kbytes): 0
        Average unshared data size (kbytes): 0
        Average stack size (kbytes): 0
        Average total size (kbytes): 0
        Maximum resident set size (kbytes): 24892
        Average resident set size (kbytes): 0
        Major (requiring I/O) page faults: 0
        Minor (reclaiming a frame) page faults: 1527
        Voluntary context switches: 1356
        Involuntary context switches: 1
        Swaps: 0
        File system inputs: 0
        File system outputs: 0
        Socket messages sent: 0
        Socket messages received: 0
        Signals delivered: 0
        Page size (bytes): 4096
        Exit status: 0

Consistently 150ms per invocation with console print. 100ms without.