Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Improve Startup Performance #1

Closed
jtrv opened this issue Aug 23, 2022 · 3 comments
Closed

Improve Startup Performance #1

jtrv opened this issue Aug 23, 2022 · 3 comments

Comments

@jtrv
Copy link

jtrv commented Aug 23, 2022

Kakoune was taking ~1.0s to open a blank buffer so I used this script to profile my config and see what was causing the delay.

kak -debug 'profile|shell' -e 'b *debug*'

and I found this:

----
shell execution took 456969 us (spawn: 88, wait: 456844)
hook 'GlobalSetOption(plug_plugins=... caksoylar/kakoune-focus )' took 0 us
command set-option took 11 us
hook 'GlobalSetOption(focus_separator={Whitespace}────────────────────────────────────────────────────────────────────────────────)' took 0 us
command declare-option took 9 us
hook 'GlobalSetOption(focus_context_lines=1)' took 0 us
command declare-option took 5 us
command declare-option took 1 us
command declare-option took 1 us
command declare-option took 1 us
command define-command took 4 us
command define-command took 1 us
command define-command took 1 us
command define-command took 1 us
command define-command took 3 us
command alias took 1 us
command alias took 0 us
sourcing '/home/sugimoto/.config/kak/plugins/plug.kak/..//kakoune-focus/focus.kak' took 95 us
command source took 102 us
command map took 4 us
command try took 10 us
sourcing '/home/sugimoto/.config/kak/plugins/plug.kak/..//.build/kakoune-focus/config' took 38 us
command source took 43 us
hook 'GlobalSetOption(plug_loaded_plugins=andreyorst/plug.kak JacobTravers/kampliment nojhan/kalolo evanrelf/number-toggle.kak JacobTravers/kak-rainbower kak-lsp/kak-lsp alexherbo2/window.kak alexherbo2/indent.kak andreyorst/smarttab.kak alexherbo2/alacritty.kak alexherbo2/auto-pairs.kak lePerdu/kakboard eburghar/kakpipe https://gitlab.com/Screwtapello/kakoune-repl-buffer JacobTravers/kakoune-sudo-write delapouite/kakoune-auto-percent eburghar/kakship natasky/kakoune-multi-file delapouite/kakoune-buffers delapouite/kakoune-cd caksoylar/kakoune-focus )' took 0 us
command set-option took 5 us
command evaluate-commands took 186 us
command try took 457186 us
command plug took 457190 us
shell:

        # $kak_client
        # $kak_config
        # $kak_opt_plug_always_ensure
        # $kak_opt_plug_git_domain
        # $kak_opt_plug_install_dir
        # $kak_opt_plug_loaded_plugins
        # $kak_opt_plug_max_active_downloads
        # $kak_opt_plug_plugin
        # $kak_opt_plug_plugins
        # $kak_opt_plug_profile
        # $kak_opt_plug_block_ui
        # $kak_opt_plug_report_conf_errors
        # $kak_opt_plug_conf_errors
        # $kak_session

        . "${kak_opt_plug_sh_source}"
        plug "$@"
    
----

this is considerably longer than any other plugin I have installed, for example here is kak-lsp

----
shell execution took 14917 us (spawn: 124, wait: 14737)
hook 'GlobalSetOption(plug_plugins=... kak-lsp/kak-lsp )' took 0 us
command set-option took 6 us
hook 'GlobalSetOption(lsp_cmd=kak-lsp -s 2748945)' took 0 us
command declare-option took 6 us
command set-face took 2 us
command set-face took 1 us
command set-face took 0 us
command set-face took 0 us
command set-face took 0 us
command set-face took 5 us
command set-face took 0 us
command set-face took 0 us
command set-face took 0 us
command set-face took 0 us
command set-face took 0 us
command set-face took 0 us
command set-face took 0 us
command set-face took 0 us
command set-face took 0 us
command declare-option took 1 us
hook 'GlobalSetOption(lsp_completion_trigger=execute-keys '<a-h><a-k>\S.\z<ret>')' took 0 us
command declare-option took 5 us
hook 'GlobalSetOption(lsp_completion_fragment_start=execute-keys "<esc><a-h>s\$?[\w%opt{lsp_extra_word_chars}]+.\z<ret>")' took 0 us
command declare-option took 5 us
command declare-option took 1 us
command hook took 5 us
hook 'GlobalSetOption(lsp_hover_insert_mode_trigger=execute-keys '<a-f>(s\A[^)]+[)]?\z<ret>')' took 0 us
command declare-option took 5 us
hook 'GlobalSetOption(lsp_insert_spaces=true)' took 0 us
command declare-option took 4 us
command declare-option took 1 us
command declare-option took 7 us
hook 'GlobalSetOption(lsp_hover_max_lines=20)' took 0 us
command declare-option took 8 us
command declare-option took 1 us
command add-highlighter took 12 us
command try took 17 us
command declare-option took 2 us
command declare-option took 1 us
hook 'GlobalSetOption(lsp_diagnostic_line_error_sign=*)' took 0 us
command declare-option took 5 us
hook 'GlobalSetOption(lsp_diagnostic_line_hint_sign=-)' took 0 us
command declare-option took 4 us
hook 'GlobalSetOption(lsp_diagnostic_line_info_sign=i)' took 0 us
command declare-option took 13 us
hook 'GlobalSetOption(lsp_diagnostic_line_warning_sign=!)' took 0 us
command declare-option took 4 us
hook 'GlobalSetOption(lsp_code_lens_sign=>)' took 0 us
command declare-option took 4 us
hook 'GlobalSetOption(lsp_inlay_diagnostic_sign=■)' took 0 us
command declare-option took 4 us
hook 'GlobalSetOption(lsp_inlay_diagnostic_gap=     )' took 0 us
command declare-option took 4 us
hook 'GlobalSetOption(lsp_show_hover_format=
info=$lsp_info \
    diagnostics=$lsp_diagnostics \
    code_lenses=$lsp_code_lenses \
    awk 'BEGIN {
        info = ENVIRON["info"]
        diagnostics = ENVIRON["diagnostics"];
        code_lenses = ENVIRON["code_lenses"];
        max_lines = ENVIRON["kak_opt_lsp_hover_max_lines"];

        r = ""
        lines = 0
        if (diagnostics) {
            r = r "{+b@InfoDefault}Diagnostics{InfoDefault} (shortcut e):\n" diagnostics "\n"
            diagnostics_lines = split(diagnostics, _, /\n/)
            lines += 1 + diagnostics_lines
        }
        if (code_lenses) {
            r = r "Code Lenses available (shortcut l)\n"
            lines++
        }
        if (ENVIRON["kak_opt_lsp_modeline_code_actions"]) {
            r = r "Code Actions available (shortcut a)\n"
            lines++
        }

        info_lines = split(info, info_line, /\n/)
        for (i = 1; i <= info_lines && (max_lines <= 0 || i+lines+2 <= max_lines); i++)
            print info_line[i]
        if (i < info_lines || r)
            printf "\n"
        if (i < info_lines)
            printf "{+i@InfoDefault}Hover info truncated, use lsp-hover-buffer (shortcut H) for full info\n"
        printf "%s", r
    }'
)' took 0 us
command declare-option took 11 us
hook 'GlobalSetOption(lsp_location_format=...)' took 0 us
command declare-option took 13 us
command define-command took 6 us
command declare-option took 1 us
command declare-option took 0 us
command set-register took 0 us
command evaluate-commands took 23 us
shell:

        buffer_basename="${kak_buffile##*/}"
        buffer_dirname=$(dirname "${kak_buffile}")

        if [ -f "${kak_buffile}" ]; then
            newer=$(find "${buffer_dirname}"/".${buffer_basename}.kak."* -newer "${kak_buffile}" -exec ls -1t {} + 2>/dev/null | head -n 1)
            older=$(find "${buffer_dirname}"/".${buffer_basename}.kak."* \! -newer "${kak_buffile}" -exec ls -1t {} + 2>/dev/null | head -n 1)
        else
            # New buffers that were never written to disk.
            newer=$(ls -1t "${buffer_dirname}"/".${buffer_basename}.kak."* 2>/dev/null | head -n 1)
            older=""
        fi

        if [ -z "${newer}" ]; then
            if [ -n "${older}" ]; then
                printf %s\\n "
                    echo -debug Old backup file(s) found: will not restore ${older} .
                "
            fi
            exit
        fi

        printf %s\\n "
            ## Replace the content of the buffer with the content of the backup file
            echo -debug Restoring file: ${newer}

            execute-keys -draft %{%d!cat<space>\"${newer}\"<ret>jd}

            ## If the backup file has to be removed, issue the command once
            ## the current buffer has been saved
            ## If the autorestore_purge_restored option has been unset right after the
            ## buffer was restored, do not remove the backup
            hook -group autorestore buffer BufWritePost '${kak_buffile}' %{
                nop %sh{
                    if [ \"\${kak_opt_autorestore_purge_restored}\" = true ];
                    then
                        rm -f \"${buffer_dirname}/.${buffer_basename}.kak.\"*
                    fi
                }
            }
        "
    
----

here is how I have kakoune-focus in my config

plug "caksoylar/kakoune-focus" branch "kak-master" config %{
  map global normal : -docstring "narrow"   ':focus-toggle <ret>'
}

Commenting this section gives me ~700ms reduction in startup time when tested with this script.

hyperfine -i "kak -e \"exec 'gj:q<ret>'\""
@caksoylar
Copy link
Owner

caksoylar commented Aug 23, 2022

That's surprising to me, I can think of only a few possibilities:

  1. Adding a branch spec like branch "kak-master" takes significantly longer than omitting it; do you have other plugins with such a spec?
  2. Could the problem be with a different plugin? I'd have to check plug.kak source but I am not sure the first snippet you have includes only kakoune-focus related loading.

All kakoune-focus does on load is to define a few options, doesn't even execute %sh blocks unless you call the defined commands. Here is my testing on a Kakoune without user config loaded (-n) where there is basically no difference:

❯ hyperfine -i "kak -ne \"source dotfiles/kak/plugins/kakoune-focus/focus.kak; map global normal : -docstring \"narrow\"   ':focus-toggle <ret>'; quit!'\"" "kak -ne quit!"
Benchmark 1: kak -ne "source dotfiles/kak/plugins/kakoune-focus/focus.kak; map global normal : -docstring "narrow"   ':focus-toggle <ret>'; quit!'"
  Time (mean ± σ):       1.3 ms ±   0.3 ms    [User: 1.3 ms, System: 0.1 ms]
  Range (min … max):     0.8 ms …   2.5 ms    1337 runs

  Warning: Command took less than 5 ms to complete. Results might be inaccurate.
  Warning: Ignoring non-zero exit code.

Benchmark 2: kak -ne quit!
  Time (mean ± σ):       1.3 ms ±   0.3 ms    [User: 1.3 ms, System: 0.1 ms]
  Range (min … max):     0.9 ms …   4.3 ms    1446 runs

  Warning: Command took less than 5 ms to complete. Results might be inaccurate.
  Warning: Ignoring non-zero exit code.
  Warning: Statistical outliers were detected. Consider re-running this benchmark on a quiet PC without any interferences from other programs. It might help to use the '--warmup' or '--prepare' options.

Summary
  'kak -ne "source dotfiles/kak/plugins/kakoune-focus/focus.kak; map global normal : -docstring "narrow"   ':focus-toggle <ret>'; quit!'"' ran
    1.02 ± 0.30 times faster than 'kak -ne quit!'

@jtrv
Copy link
Author

jtrv commented Aug 23, 2022

Ah sorry to bother you, I believe you are right. I should have considered that, it looks like the branch spec adds ~300ms when testing in hyperfine and the profile script shows a significant decrease after removing it. I'll close this and open an issue in the plug.kak repo.

----
shell execution took 8898 us (spawn: 66, wait: 8766)
hook 'GlobalSetOption(plug_plugins=... caksoylar/kakoune-focus )' took 0 us
command set-option took 8 us
hook 'GlobalSetOption(focus_separator={Whitespace}────────────────────────────────────────────────────────────────────────────────)' took 0 us
command declare-option took 12 us
hook 'GlobalSetOption(focus_context_lines=1)' took 0 us
command declare-option took 5 us
command declare-option took 1 us
command declare-option took 1 us
command declare-option took 1 us
command define-command took 3 us
command define-command took 3 us
command define-command took 1 us
command define-command took 1 us
command define-command took 2 us
command alias took 0 us
command alias took 0 us
sourcing '/home/sugimoto/.config/kak/plugins/plug.kak/..//kakoune-focus/focus.kak' took 102 us
command source took 111 us
command map took 3 us
command try took 7 us
sourcing '/home/sugimoto/.config/kak/plugins/plug.kak/..//.build/kakoune-focus/config' took 30 us
command source took 35 us
hook 'GlobalSetOption(plug_loaded_plugins=andreyorst/plug.kak JacobTravers/kampliment gustavo-hms/luar nojhan/kalolo evanrelf/number-toggle.kak JacobTravers/kak-rainbower kak-lsp/kak-lsp alexherbo2/window.kak alexherbo2/indent.kak andreyorst/smarttab.kak alexherbo2/alacritty.kak alexherbo2/auto-pairs.kak lePerdu/kakboard eburghar/kakpipe https://gitlab.com/Screwtapello/kakoune-repl-buffer JacobTravers/kakoune-sudo-write delapouite/kakoune-auto-percent eburghar/kakship natasky/kakoune-multi-file useredsa/dynamic-matching.kak gustavo-hms/peneira delapouite/kakoune-buffers delapouite/kakoune-cd danr/kakoune-easymotion caksoylar/kakoune-focus )' took 0 us
command set-option took 6 us
command evaluate-commands took 180 us
command try took 9102 us
command plug took 9107 us
shell:

        # $kak_client
        # $kak_config
        # $kak_opt_plug_always_ensure
        # $kak_opt_plug_git_domain
        # $kak_opt_plug_install_dir
        # $kak_opt_plug_loaded_plugins
        # $kak_opt_plug_max_active_downloads
        # $kak_opt_plug_plugin
        # $kak_opt_plug_plugins
        # $kak_opt_plug_profile
        # $kak_opt_plug_block_ui
        # $kak_opt_plug_report_conf_errors
        # $kak_opt_plug_conf_errors
        # $kak_session

        . "${kak_opt_plug_sh_source}"
        plug "$@"
    
----

@jtrv jtrv closed this as completed Aug 23, 2022
@caksoylar
Copy link
Owner

No worries! I tested and get about a 5ms improvement by commenting out my plug block which has the same branch statement, but git performance can vary quite a lot depending on the file system so I wouldn't be surprised.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

2 participants