Slowness with LP_ENABLE_GIT=1

[FedericoStra]

Shell: 5.1.8(1)-release

Liquidprompt version: v2.0.3

Operating system:

[:~] $ uname -a
Linux xps15 5.16.5-200.fc35.x86_64 #1 SMP PREEMPT Tue Feb 1 21:37:11 UTC 2022 x86_64 x86_64 x86_64 GNU/Linux
[:~] $ cat /proc/version 
Linux version 5.16.5-200.fc35.x86_64 ([email protected]) (gcc (GCC) 11.2.1 20211203 (Red Hat 11.2.1-7), GNU ld version 2.37-10.fc35) #1 SMP PREEMPT Tue Feb 1 21:37:11 UTC 2022
[:~] $ cat /etc/*release
Fedora release 35 (Thirty Five)
NAME="Fedora Linux"
VERSION="35 (Workstation Edition)"
ID=fedora
VERSION_ID=35
VERSION_CODENAME=""
PLATFORM_ID="platform:f35"
PRETTY_NAME="Fedora Linux 35 (Workstation Edition)"
ANSI_COLOR="0;38;2;60;110;180"
LOGO=fedora-logo-icon
CPE_NAME="cpe:/o:fedoraproject:fedora:35"
HOME_URL="https://fedoraproject.org/"
DOCUMENTATION_URL="https://docs.fedoraproject.org/en-US/fedora/f35/system-administrators-guide/"
SUPPORT_URL="https://ask.fedoraproject.org/"
BUG_REPORT_URL="https://bugzilla.redhat.com/"
REDHAT_BUGZILLA_PRODUCT="Fedora"
REDHAT_BUGZILLA_PRODUCT_VERSION=35
REDHAT_SUPPORT_PRODUCT="Fedora"
REDHAT_SUPPORT_PRODUCT_VERSION=35
PRIVACY_POLICY_URL="https://fedoraproject.org/wiki/Legal:PrivacyPolicy"
VARIANT="Workstation Edition"
VARIANT_ID=workstation
Fedora release 35 (Thirty Five)
Fedora release 35 (Thirty Five)

Steps to Reproduce

1. Have LP_ENABLE_GIT=1 set in .config/liquidpromptrc
2. cd to a Git repository

Expected Behavior

Nothing special, just the prompt promptly appearing.

Current Behavior

The prompt takes around 1 second to display.

For instance, if I cd ~/.liquidprompt (which is a Git repo) and just press Enter in the terminal, each of the following lines takes approximately 1 second to appear:

[:~/.liquidprompt] stable ± 
[:~/.liquidprompt] stable ± 
[:~/.liquidprompt] stable ± 
[:~/.liquidprompt] stable ±

Possible Solution

My suspicion is that some of the _lp_git_* functions take a long time to execute, but I haven't been able to figure out which.

[Rycieos]

There have not been many changes to the Git features since v2.0, but if you could, could you please test on the latest master branch just to make sure?

Without more details, this won't be possible to debug. Can you run some timings, and post their output?

time git --help >/dev/null
time _lp_vcs_details_color
time _lp_git_active
time _lp_git_branch
time _lp_git_commit_id
time _lp_git_head_status
time _lp_git_commits_off_remote
time _lp_git_unstaged_lines

For comparison, here are some of my values:

~/dev/liquidprompt:
$ time git --help >/dev/null
real   	0m0.004s
user   	0m0.001s
sys    	0m0.003s

$ time _lp_git_active
real   	0m0.005s
user   	0m0.002s
sys    	0m0.003s

$ time _lp_git_unstaged_lines
real   	0m0.007s
user   	0m0.002s
sys    	0m0.005s

My guess is that your filesystem is slow, and either the git binary takes a long time to start up, or accessing many small files like in a Git repo is taking too long.

[FedericoStra]

I'm testing with the latest commit 0447efe. The filesystem shouldn't be particularly slow as it's a decent SSD.

[:~/.liquidprompt] master ± time git --help >/dev/null
time _lp_vcs_details_color
time _lp_git_active
time _lp_git_branch
time _lp_git_commit_id
time _lp_git_head_status
time _lp_git_commits_off_remote
time _lp_git_unstaged_lines

real	0m0,005s
user	0m0,000s
sys	0m0,005s

real	0m0,326s
user	0m0,023s
sys	0m0,023s

real	0m0,001s
user	0m0,000s
sys	0m0,001s

real	0m0,002s
user	0m0,001s
sys	0m0,001s

real	0m0,002s
user	0m0,002s
sys	0m0,000s

real	0m0,000s
user	0m0,000s
sys	0m0,000s

real	0m0,002s
user	0m0,000s
sys	0m0,002s

real	0m0,003s
user	0m0,001s
sys	0m0,001s

The culprit seems to be _lp_vcs_details_color, which I hadn't timed because I just focused on _lq_git_*.

I tried to investigate a bit and I noticed that _lp_vcs_details_color calls _lp_vcs_bookmark. This in turn should probably call _lp_git_bookmark, which however does not exist. For some reason bash takes ~0.3s to produce the error:

[:~/.liquidprompt] master ± time _lp_vcs_bookmark

real	0m0,303s
user	0m0,010s
sys	0m0,009s
[:~/.liquidprompt] master 127 ± time _lp_git_bookmark
bash: _lp_git_bookmark: command not found...

real	0m0,305s
user	0m0,016s
sys	0m0,010s

If I define it as _lp_git_bookmark() { :; }, then the prompt becomes much quicker.

[Rycieos]

I tried to investigate a bit and I noticed that _lp_vcs_details_color calls _lp_vcs_bookmark. This in turn should probably call _lp_git_bookmark, which however does not exist. For some reason bash takes ~0.3s to produce the error:

Ah, then I bet I know what the problem is. Similar to in #690, do you have the function command_not_found_handle set? What is the output of:

type command_not_found_handle

If so, it probably does some sort of a lookup to see if it is a valid command in some remote package, which is what is taking so long.

There isn't a good reason for Liquidprompt to keep the function undefined, so if that is the problem, I can add empty definitions for all not implemented data functions (like you did) which should fix the issue.

[FedericoStra]

Oh my God you are a Bash wizard! 😄
I never knew about command_not_found_handle and set -x. Indeed I have the function defined as

[:~] $ type command_not_found_handle
command_not_found_handle is a function
command_not_found_handle () 
{ 
    local runcnf=1;
    local retval=127;
    [[ $- == *"i"* ]] || runcnf=0;
    [[ ! -S /run/dbus/system_bus_socket ]] && runcnf=0;
    [[ ! -x '/usr/libexec/packagekitd' ]] && runcnf=0;
    [[ -n ${COMP_CWORD-} ]] && runcnf=0;
    [[ ! -x '/usr/libexec/pk-command-not-found' ]] && runcnf=0;
    if [ $runcnf -eq 1 ]; then
        '/usr/libexec/pk-command-not-found' "$@";
        retval=$?;
    else
        if [[ -n "${BASH_VERSION-}" ]]; then
            printf 'bash: %scommand not found\n' "${1:+$1: }" 1>&2;
        fi;
    fi;
    return $retval
}

There isn't a good reason for Liquidprompt to keep the function undefined, so if that is the problem, I can add empty definitions for all not implemented data functions (like you did) which should fix the issue.

I already patched my local version of Liquidprompt. If you don't want to add this empty function (and maybe others?) it's fine for me, I can keep patching my local version. Apparently nobody else complained about this somehow.

[Rycieos]

Apparently nobody else complained about this somehow.

I'm not sure why that is, but others are likely to complain in the future. It also just makes sense from a speed perspective even when command_not_found_handle is not defined:

$ test() {
  for ((i = 0; i < 10000; i++)); do
    test_fuction_not_real 2>/dev/null
  done
}
$ time test
real   	0m7.998s
user   	0m2.840s
sys    	0m5.357s

$ test_fuction_not_real() { :; }
$ time test
real   	0m0.169s
user   	0m0.128s
sys    	0m0.038s

So I see no good reason not to add empty functions, and lots of good ones to do it. So thanks for teaching me something new 😄

I'll both patch this on master and backport to stable in v2.0.4.