justinmayer / virtualfish

Fish shell tool for managing Python virtual environments
MIT License
1.07k stars 101 forks source link

Shell startup is slow due to VirtualFish completions #243

Open MooseV2 opened 8 months ago

MooseV2 commented 8 months ago

Issue

I've been profiling my Fish shell startup time and have found the VirtualFish loading script to consume a significant chunk of time.

# Without "virtualfish-loader.fish" installed
$ time fish -c exit
________________________________________________________
Executed in   38.06 millis    fish           external
   usr time   30.62 millis    0.00 micros   30.62 millis
   sys time    8.52 millis  734.00 micros    7.79 millis

# With "virtualfish-loader.fish" installed
$ time fish -c exit
________________________________________________________
Executed in  188.56 millis    fish           external
   usr time  152.15 millis  727.00 micros  151.42 millis
   sys time   92.58 millis  313.00 micros   92.27 millis

After doing some investigation, I've found it to be directly caused by the __vfsupport_setup_autocomplete function, specifically the part that extracts the help text from all the VF functions.

Here's timing information with an without that specific function:

$ time source virtualfish-loader.fish
time source virtualfish-loader.fish
________________________________________________________
Executed in  150.11 millis    fish           external
   usr time  112.20 millis   16.33 millis   95.86 millis
   sys time   91.53 millis   15.33 millis   76.20 millis

# Removed "emit virtualfish_did_setup_plugins" so the function is not called in virtual.fish

$ time source virtualfish-loader.fish
________________________________________________________
Executed in   10.14 millis    fish           external
   usr time    8.00 millis    3.86 millis    4.14 millis
   sys time    2.25 millis    0.00 millis    2.25 millis

To further investigate, I've extracted that specific function to its own script and profiled it as follows (repeated parts reduced for clarity):

fish --profile=/tmp/vf-completion vfsupport_setup_autocomplete.fish
Time    Sum Command
7   7   > function __vfsupport_setup_autocomplete ...
26  111802  > __vfsupport_setup_autocomplete
2   2   -> function __vfcompletion_needs_command...
1   1   -> function __vfcompletion_using_command...
263 111685  -> for sc in (functions -a | sed -n '/__vf_/{s///g;p;}')...
3396    3396    --> functions -a | sed -n '/__vf_/{s///g;p;}'
246 10358   --> set -l helptext (functions "__vf_$sc" | grep -m1 "^function" | sed -E "s|.*'(.*)'.*|\1|")
1192    10112   ---> functions "__vf_$sc" | grep -m1 "^function" | sed -E "s|.*'(.*)'.*|\1|"
739 4739    ----> command /usr/bin/grep --color=auto $argv
69  69  --> complete -x -c vf -n '__vfcompletion_needs_command' -a $sc -d $helptext
365 5952    --> set -l helptext (functions "__vf_$sc" | grep -m1 "^function" | sed -E "s|.*'(.*)'.*|\1|")
978 5587    ---> functions "__vf_$sc" | grep -m1 "^function" | sed -E "s|.*'(.*)'.*|\1|"
4609    4609    ----> command /usr/bin/grep --color=auto $argv
65  65  --> complete -x -c vf -n '__vfcompletion_needs_command' -a $sc -d $helptext
120 5830    --> set -l helptext (functions "__vf_$sc" | grep -m1 "^function" | sed -E "s|.*'(.*)'.*|\1|")
879 5710    ---> functions "__vf_$sc" | grep -m1 "^function" | sed -E "s|.*'(.*)'.*|\1|"
4831    4831    ----> command /usr/bin/grep --color=auto $argv
                (...repeated 10+ times...)
8   48  --> complete -x -c vf -n '__vfcompletion_needs_command' -a $sc -d $helptext
32  32  -> complete -x -c vf -n '__vfcompletion_using_command activate' -a "(vf ls)"
21  21  -> complete -x -c vf -n '__vfcompletion_using_command connect' -a "(vf ls)"
17  17  -> complete -x -c vf -n '__vfcompletion_using_command rm' -a "(vf ls)"
18  18  -> complete -x -c vf -n '__vfcompletion_using_command upgrade' -a "(vf ls)"
23  70  > __vfsupport_remove_env_on_deactivate_or_exit PROCESS_EXIT 436514 0
3   47  -> if begin; set -q _VF_TEMPORARY_ENV; and [ $_VF_TEMPORARY_ENV = (basename $VIRTUAL_ENV) ]; end...
32  44  --> begin...
12  12  ---> set -q _VF_TEMPORARY_ENV

As you can see, the for sc in (functions ...) loop is taking the majority of the time (>100ms), and this is almost entirely attributed to every invokation of grep taking ~5ms.

Possible Solutions

Since the completions don't often change, it might be better to generate them once and cache them. Here's a working example that can replace the __vfsupport_setup_autocomplete function in virtual.fish:

function __vfsupport_initialize_autocomplete
    # Source the completion file if it exists. 
    set -q XDG_CACHE_HOME; or set XDG_CACHE_HOME $HOME/.cache
    if test -f $XDG_CACHE_HOME/fish/virtualfish_complete.fish
        source $XDG_CACHE_HOME/fish/virtualfish_complete.fish
    else
        # If not, create it and source it.
        mkdir -p $XDG_CACHE_HOME/fish

        # add completion for subcommands
        for sc in (functions -a | sed -n '/__vf_/{s///g;p;}')
            set -l helptext (functions "__vf_$sc" | grep -m1 "^function" | sed -E "s|.*'(.*)'.*|\1|")
            echo complete -x -c vf -n '__vfcompletion_needs_command' -a \'$sc\' -d \'$helptext\' >> $XDG_CACHE_HOME/fish/virtualfish_complete.fish
        end

        echo 'complete -x -c vf -n \'__vfcompletion_using_command activate\' -a "(vf ls)"' >> $XDG_CACHE_HOME/fish/virtualfish_complete.fish
        echo 'complete -x -c vf -n \'__vfcompletion_using_command connect\' -a "(vf ls)"' >> $XDG_CACHE_HOME/fish/virtualfish_complete.fish
        echo 'complete -x -c vf -n \'__vfcompletion_using_command rm\' -a "(vf ls)"' >> $XDG_CACHE_HOME/fish/virtualfish_complete.fish
        echo 'complete -x -c vf -n \'__vfcompletion_using_command upgrade\' -a "(vf ls)"' >> $XDG_CACHE_HOME/fish/virtualfish_complete.fish
        source $XDG_CACHE_HOME/fish/virtualfish_complete.fish
    end
end

function __vfsupport_setup_autocomplete 
    function __vfcompletion_needs_command
        set cmd (commandline -opc)
            if test (count $cmd) -eq 1 -a $cmd[1] = 'vf'
            return 0
        end
        return 1
    end

    function __vfcompletion_using_command
        set cmd (commandline -opc)
        if test (count $cmd) -gt 1
            if test $argv[1] = $cmd[2]
                return 0
            end
        end
        return 1
    end

    __vfsupport_initialize_autocomplete
end

This function takes ~120ms upon the first run, but subsequent runs take <2ms, representing a significant speedup!

justinmayer commented 8 months ago

Many thanks for the detailed report, Anthony. It is rare and refreshing to see not only a detailed report, but also some concrete ideas and code regarding how the issue might be resolved. Bravo!

As you accurately point out, VirtualFish completions rarely change, which makes me wonder whether we need to generate the completions (even in cached form) on every shell startup. Perhaps we could install the completions as part of the vf install process? Maybe with a separate vf install --completions flag that only generates the completions, to be used to update completions in case they have changed?

After reviewing where to put completions, perhaps they should go in ~/.local/share/fish/vendor_completions.d?

Looking forward to your thoughts. Once again, much appreciated!