v0.22.0 => increased app startup time #1436

MartinVincent · 2022-11-19T20:56:04Z

First, thanks for this great piece of software, it truly is the best of the CLI Git clients!

Just want to make an observation regarding the 0.22 release: I really appreciate the update with the great new features (yes! (#1371)), but I noticed that there is now a significant delay on startup for relatively small repos (1500 Commits):

Launching gitui with an immediate quitting on that 1500 commit repo went from an average of : 0,094 (v0.21) up to 0,746 (v0.22).

Is that expected? (ie: the price to pay for the new features)

Thx!

The text was updated successfully, but these errors were encountered:

extrawurst · 2022-11-19T21:42:27Z

That’s an Intretesting observation. Gonna look into this

extrawurst · 2022-11-20T09:51:33Z

How did you make this exact measurement?

MartinVincent · 2022-11-20T15:59:48Z

Answer: I quickly scripted the following and I ran it with both versions and averaged them out:

❯ cat ~/bin/gitui_test.scp
#!/usr/bin/expect
set version [lindex $argv 0];
spawn ~/bin/gitui_$version         # ie: symlinks to 0.21.0 or 0.22.0
expect "Status"
send "q\r";


# BTW no guarantee that this is a valid speed test

Now, your question above prompted me to rerun my script on a fresh clone of gitui's own repo (with its more than 1700 commits), and this time I did get satisfactory results:

[master:b495425  ] ~/Code/gitui ❯ TIMEFORMAT="delta: %E";
[master:b495425  ] ~/Code/gitui ❯ # for  0.21.0
[master:b495425  ] ~/Code/gitui ❯ for i in $(seq 10); do time ~/bin/gitui_test.scp  0.21.0  >/dev/null; done
delta: 0,072
delta: 0,033
delta: 0,032
delta: 0,032
delta: 0,032
delta: 0,032
delta: 0,032
delta: 0,035
delta: 0,032
delta: 0,032
[master:b495425  ] ~/Code/gitui ❯ # for  0.22.0
[master:b495425  ] ~/Code/gitui ❯ for i in $(seq 10); do time ~/bin/gitui_test.scp  0.22.0  >/dev/null; done
delta: 0,046
delta: 0,048
delta: 0,048
delta: 0,046
delta: 0,047
delta: 0,047
delta: 0,048
delta: 0,048
delta: 0,047
delta: 0,046

Update, I just redid the test on my own repo (fresh clone) and now I get similar satisfactory results to gitui's repo.

so... Conclusion: not sure what is the problem with my older perso repo, but it looks like a fresh clone fixes the issue in my case.

MartinVincent · 2022-11-20T20:23:54Z

Update: the issue appears to be reproducible (and caused by the presence of a python .virtualenv directory)

In the code block below, we can see that:

test is started on a fresh clone of the gitui repo
initial startup time difference between 0.21.0 and 0.22.0 is small
the virtualenv is relatively small: only Ansible + its main dependencies are installed
- (I can also confirm that installing more python wheels in the virtualenv, increases even more the startup time)
the .virtualenv directory is correctly present in the .gitignore file
post-virtualenv installation,
- the startup time is constant for 0.21.0
- the startup time is multiplied by ~ 4 for 0.22.0

 [master:b495425  ] /tmp/gitui ❯ g status
On branch master
Your branch is up to date with 'origin/master'.

nothing to commit, working tree clean

 [master:b495425  ] /tmp/gitui ❯ for i in $(seq 10) ; do time  ~/bin/gitui_startup_test.scp 0.21.0 >/dev/null; done
delta: 0,077
delta: 0,034
delta: 0,032
delta: 0,034
delta: 0,032
delta: 0,033
delta: 0,034
delta: 0,035
delta: 0,034
delta: 0,034

 [master:b495425  ] /tmp/gitui ❯ for i in $(seq 10) ; do time  ~/bin/gitui_startup_test.scp 0.22.0 >/dev/null; done
delta: 0,049
delta: 0,048
delta: 0,047
delta: 0,047
delta: 0,046
delta: 0,045
delta: 0,047
delta: 0,046
delta: 0,047
delta: 0,045

 [master:b495425  ] /tmp/gitui ❯ virtualenv --python python3.8 ./.virtualenv; source ./.virtualenv/bin/activate
created virtual environment CPython3.8.10.final.0-64 in 146ms
  creator CPython3Posix(dest=/tmp/gitui/.virtualenv, clear=False, global=False)
  seeder FromAppData(download=False, pip=latest, setuptools=latest, wheel=latest, pkg_resources=latest, via=copy, app_data_dir=<my home dir>/.local/share/virtualenv/seed-app-data/v1.0.1.debian.1)
  activators BashActivator,CShellActivator,FishActivator,PowerShellActivator,PythonActivator,XonshActivator
(gitui:)  [master:b495425  ] /tmp/gitui ❯ pip3 install ansible
Looking in indexes: http://pypi:3141/root/ax-focal/+simple/
Collecting ansible
  Downloading http://pypi:3141/root/pypi/%2Bf/3c6/812e9af1c243b/ansible-6.6.0-py3-none-any.whl (42.3 MB)
     |████████████████████████████████| 42.3 MB 1.2 MB/s 
Collecting ansible-core~=2.13.6
  Downloading http://pypi:3141/root/pypi/%2Bf/e31/fd550a5ea9423/ansible_core-2.13.6-py3-none-any.whl (2.1 MB)
     |████████████████████████████████| 2.1 MB 3.0 MB/s 
Collecting PyYAML>=5.1
  Downloading http://pypi:3141/root/pypi/%2Bf/277/a0ef2981ca405/PyYAML-6.0-cp38-cp38-manylinux_2_5_x86_64.manylinux1_x86_64.manylinux_2_12_x86_64.manylinux2010_x86_64.whl (701 kB)
     |████████████████████████████████| 701 kB 4.9 MB/s 
Collecting jinja2>=3.0.0
  Downloading http://pypi:3141/root/pypi/%2Bf/608/8930bfe239f0e/Jinja2-3.1.2-py3-none-any.whl (133 kB)
     |████████████████████████████████| 133 kB 5.0 MB/s 
Collecting packaging
  Downloading http://pypi:3141/root/pypi/%2Bf/ef1/03e05f519cdc7/packaging-21.3-py3-none-any.whl (40 kB)
     |████████████████████████████████| 40 kB 8.3 MB/s 
Collecting cryptography
  Downloading http://pypi:3141/root/pypi/%2Bf/b1b/52c9e5f8aa2b8/cryptography-38.0.3-cp36-abi3-manylinux_2_17_x86_64.manylinux2014_x86_64.whl (4.2 MB)
     |████████████████████████████████| 4.2 MB 2.7 MB/s 
Collecting resolvelib<0.9.0,>=0.5.3
  Downloading http://pypi:3141/root/pypi/%2Bf/d9b/7907f055c3b3a/resolvelib-0.8.1-py2.py3-none-any.whl (16 kB)
Collecting MarkupSafe>=2.0
  Downloading http://pypi:3141/root/pypi/%2Bf/4b9/fe39a2ccc108a/MarkupSafe-2.1.1-cp38-cp38-manylinux_2_17_x86_64.manylinux2014_x86_64.whl (25 kB)
Collecting pyparsing!=3.0.5,>=2.0.2
  Downloading http://pypi:3141/root/pypi/%2Bf/502/6bae9a10eeaef/pyparsing-3.0.9-py3-none-any.whl (98 kB)
     |████████████████████████████████| 98 kB 4.0 MB/s 
Collecting cffi>=1.12
  Downloading http://pypi:3141/root/pypi/%2Bf/4f2/c9f67e9821cad/cffi-1.15.1-cp38-cp38-manylinux_2_17_x86_64.manylinux2014_x86_64.whl (442 kB)
     |████████████████████████████████| 442 kB 9.1 MB/s 
Collecting pycparser
  Downloading http://pypi:3141/root/pypi/%2Bf/8ee/45429555515e1/pycparser-2.21-py2.py3-none-any.whl (118 kB)
     |████████████████████████████████| 118 kB 3.6 MB/s 
Installing collected packages: PyYAML, MarkupSafe, jinja2, pyparsing, packaging, pycparser, cffi, cryptography, resolvelib, ansible-core, ansible
Successfully installed MarkupSafe-2.1.1 PyYAML-6.0 ansible-6.6.0 ansible-core-2.13.6 cffi-1.15.1 cryptography-38.0.3 jinja2-3.1.2 packaging-21.3 pycparser-2.21 pyparsing-3.0.9 resolvelib-0.8.1

(gitui:3.8.10)  [master:b495425 ∆  ] /tmp/gitui ❯ cat .gitignore  | grep virtual
.virtualenv


(gitui:3.8.10)  [master:b495425  ] /tmp/gitui ❯ for i in $(seq 10) ; do time  ~/bin/gitui_startup_test.scp 0.21.0 >/dev/null; done
delta: 0,050
delta: 0,035
delta: 0,034
delta: 0,036
delta: 0,032
delta: 0,034
delta: 0,037
delta: 0,034
delta: 0,035
delta: 0,034
(gitui:3.8.10)  [master:b495425  ] /tmp/gitui ❯ for i in $(seq 10) ; do time  ~/bin/gitui_startup_test.scp 0.22.0 >/dev/null; done
delta: 0,207
delta: 0,200
delta: 0,199
delta: 0,199
delta: 0,195
delta: 0,192
delta: 0,196
delta: 0,193
delta: 0,200
delta: 0,197

I hope this sheds some light on the issue.

extrawurst · 2022-11-20T21:12:45Z

can you do me a favour and compare this in a debug build and the -l arg to enable logging? this will generate entries in the log like these:

21:08:32 [TRACE] (1) scopetime: [scopetime/src/lib.rs:41] scopetime: 3 ms [asyncgit::sync::branch::get_branches_info] @asyncgit/src/sync/branch/mod.rs:118

the log on Mac can be found: ~/Library/Caches/gitui/gitui.log

my theory is that get_branches_info appears in there with the diff time while in 0.21 it does not on startup, can you verify?

if that's the case I assume the following commit is the offender: 216fad3

extrawurst · 2022-11-20T21:14:01Z

if we can validate that's the culprit we can fix it by making the waiting for the branches info async and have our fast(er) startup times again :)

extrawurst · 2022-11-20T21:14:32Z

@alexmaco maybe you wanna clean that up? :)

MartinVincent · 2022-11-21T02:23:28Z

Hum, I am no Rust programmer, but building (as per) [master:b495425], and then running the resulting binary with -l
yields:

 0 02:19:12 [TRACE] (6) mio::poll: [<my home dir>/.cargo/registry/src/github.jparrowsec.cn-1ecc6299db9ec823/mio-0.8.5/src/poll.rs:532] registering event source with poller: token=Token(0), interests=READABLE                                                                                                                                                                                                                                                                                                  
 1 02:19:12 [TRACE] (6) mio::poll: [<my home dir>/.cargo/registry/src/github.jparrowsec.cn-1ecc6299db9ec823/mio-0.8.5/src/poll.rs:532] registering event source with poller: token=Token(1), interests=READABLE
 2 02:19:12 [TRACE] (1) mio::poll: [<my home dir>/.cargo/registry/src/github.jparrowsec.cn-1ecc6299db9ec823/mio-0.8.5/src/poll.rs:532] registering event source with poller: token=Token(0), interests=READABLE
 3 02:19:15 [TRACE] (1) gitui::app: [<my home dir>/.cargo/registry/src/github.jparrowsec.cn-1ecc6299db9ec823/gitui-0.22.0/src/app.rs:119] open repo at: RefCell { value: Path(".") }
 4 02:19:15 [TRACE] (1) asyncgit::tags: [<my home dir>/.cargo/registry/src/github.jparrowsec.cn-1ecc6299db9ec823/asyncgit-0.22.0/src/tags.rs:67] request  
 5 02:19:15 [TRACE] (1) gitui::app: [<my home dir>/.cargo/registry/src/github.jparrowsec.cn-1ecc6299db9ec823/gitui-0.22.0/src/app.rs:475] update          
 6 02:19:15 [TRACE] (1) asyncgit::tags: [<my home dir>/.cargo/registry/src/github.jparrowsec.cn-1ecc6299db9ec823/asyncgit-0.22.0/src/tags.rs:67] request  
 7 02:19:15 [TRACE] (1) gitui::app: [<my home dir>/.cargo/registry/src/github.jparrowsec.cn-1ecc6299db9ec823/gitui-0.22.0/src/app.rs:494] update_async: Git(Tags)
 8 02:19:15 [TRACE] (1) asyncgit::tags: [<my home dir>/.cargo/registry/src/github.jparrowsec.cn-1ecc6299db9ec823/asyncgit-0.22.0/src/tags.rs:67] request  
 9 02:19:15 [TRACE] (1) gitui::app: [<my home dir>/.cargo/registry/src/github.jparrowsec.cn-1ecc6299db9ec823/gitui-0.22.0/src/app.rs:494] update_async: Git(Log)
10 02:19:15 [TRACE] (1) asyncgit::tags: [<my home dir>/.cargo/registry/src/github.jparrowsec.cn-1ecc6299db9ec823/asyncgit-0.22.0/src/tags.rs:67] request  
11 02:19:15 [TRACE] (1) gitui::app: [<my home dir>/.cargo/registry/src/github.jparrowsec.cn-1ecc6299db9ec823/gitui-0.22.0/src/app.rs:494] update_async: Git(Log)
12 02:19:15 [TRACE] (1) asyncgit::tags: [<my home dir>/.cargo/registry/src/github.jparrowsec.cn-1ecc6299db9ec823/asyncgit-0.22.0/src/tags.rs:67] request  
13 02:19:15 [TRACE] (1) gitui::app: [<my home dir>/.cargo/registry/src/github.jparrowsec.cn-1ecc6299db9ec823/gitui-0.22.0/src/app.rs:494] update_async: Git(Tags)
14 02:19:15 [TRACE] (1) asyncgit::tags: [<my home dir>/.cargo/registry/src/github.jparrowsec.cn-1ecc6299db9ec823/asyncgit-0.22.0/src/tags.rs:67] request  
15 02:19:17 [TRACE] (1) gitui::app: [<my home dir>/.cargo/registry/src/github.jparrowsec.cn-1ecc6299db9ec823/gitui-0.22.0/src/app.rs:380] event: Input(Key(KeyEvent { code: Char('q'), modifiers: NONE, kind: Press, state: NONE }))

Does this help?

extrawurst · 2022-11-21T07:02:07Z

no that is not a debug build, you can use make debug to build one

MartinVincent · 2022-11-21T12:33:27Z

Here are 2 trials:

in gitui's own cloned repo, with a .virtualenv directory
running :

 Running `target/debug/gitui -l`
(gitui:3.6.12)  [master:b495425  ] ~/Code/gitui ❯ make debug -l
RUST_BACKTRACE=true cargo run --features=timing -- -l
    Finished dev [unoptimized + debuginfo] target(s) in 0.06s
     Running `target/debug/gitui -l`

BTW: did you manage to reproduce the issue on your side?

1   tail: <my home dir>/.cache/gitui/gitui.log: file truncated                                                                                                                                                                                                                                                                                                                                                                                                                                          
  1 12:24:58 [TRACE] (6) mio::poll: [<my home dir>/.cargo/registry/src/github.jparrowsec.cn-1ecc6299db9ec823/mio-0.8.4/src/poll.rs:521] registering event source with poller: token=Token(0), interests=READABLE
  2 12:24:59 [TRACE] (6) mio::poll: [<my home dir>/.cargo/registry/src/github.jparrowsec.cn-1ecc6299db9ec823/mio-0.8.4/src/poll.rs:521] registering event source with poller: token=Token(1), interests=READABLE
  3 12:24:59 [TRACE] (1) mio::poll: [<my home dir>/.cargo/registry/src/github.jparrowsec.cn-1ecc6299db9ec823/mio-0.8.4/src/poll.rs:521] registering event source with poller: token=Token(0), interests=READABLE
  4 12:24:59 [TRACE] (1) gitui::app: [src/app.rs:119] open repo at: RefCell { value: Path(".") }                                                 
  5 12:24:59 [TRACE] (1) scopetime: [scopetime/src/lib.rs:41] scopetime: 0 ms [asyncgit::sync::commits_info::get_commits_info] @asyncgit/src/sync/commits_info.rs:73
  6 12:24:59 [TRACE] (1) asyncgit::tags: [asyncgit/src/tags.rs:67] request                                                                       
  7 12:24:59 [TRACE] (1) scopetime: [scopetime/src/lib.rs:41] scopetime: 2 ms [asyncgit::sync::branch::get_branches_info] @asyncgit/src/sync/branch/mod.rs:118
  8 12:24:59 [TRACE] (3) scopetime: [scopetime/src/lib.rs:41] scopetime: 2 ms [asyncgit::sync::tags::get_tags] @asyncgit/src/sync/tags.rs:58     
  9 12:24:59 [TRACE] (1) gitui::app: [src/app.rs:475] update                                                                                     
 10 12:24:59 [TRACE] (1) scopetime: [scopetime/src/lib.rs:41] scopetime: 0 ms [asyncgit::sync::utils::get_head_repo] @asyncgit/src/sync/utils.rs:82
 11 12:24:59 [TRACE] (1) scopetime: [scopetime/src/lib.rs:41] scopetime: 0 ms [asyncgit::sync::branch::get_branch_name_repo] @asyncgit/src/sync/branch/mod.rs:34
 12 12:24:59 [TRACE] (1) scopetime: [scopetime/src/lib.rs:41] scopetime: 0 ms [asyncgit::sync::utils::get_head_repo] @asyncgit/src/sync/utils.rs:82
 13 12:24:59 [TRACE] (1) scopetime: [scopetime/src/lib.rs:41] scopetime: 0 ms [asyncgit::sync::branch::get_branch_name_repo] @asyncgit/src/sync/branch/mod.rs:34
 14 12:24:59 [TRACE] (1) scopetime: [scopetime/src/lib.rs:41] scopetime: 0 ms [asyncgit::sync::commits_info::get_commits_info] @asyncgit/src/sync/commits_info.rs:73
 15 12:24:59 [TRACE] (1) asyncgit::tags: [asyncgit/src/tags.rs:67] request                                                                       
 16 12:24:59 [TRACE] (1) scopetime: [scopetime/src/lib.rs:41] scopetime: 2 ms [asyncgit::sync::branch::get_branches_info] @asyncgit/src/sync/branch/mod.rs:118
 17 12:24:59 [TRACE] (3) scopetime: [scopetime/src/lib.rs:41] scopetime: 3 ms [asyncgit::sync::tags::get_tags] @asyncgit/src/sync/tags.rs:58     
 18 12:24:59 [TRACE] (1) scopetime: [scopetime/src/lib.rs:41] scopetime: 13 ms [gitui::loop] @src/main.rs:212                                    
 19 12:24:59 [TRACE] (1) gitui::app: [src/app.rs:494] update_async: Git(Tags)                                                                    
 20 12:24:59 [TRACE] (1) scopetime: [scopetime/src/lib.rs:41] scopetime: 1 ms [asyncgit::sync::commits_info::get_commits_info] @asyncgit/src/sync/commits_info.rs:73
 21 12:24:59 [TRACE] (1) asyncgit::tags: [asyncgit/src/tags.rs:67] request                                                                       
 22 12:24:59 [TRACE] (1) scopetime: [scopetime/src/lib.rs:41] scopetime: 2 ms [asyncgit::sync::branch::get_branches_info] @asyncgit/src/sync/branch/mod.rs:118
 23 12:24:59 [TRACE] (1) scopetime: [scopetime/src/lib.rs:41] scopetime: 5 ms [gitui::loop] @src/main.rs:212                                     
 24 12:24:59 [TRACE] (1) gitui::app: [src/app.rs:494] update_async: Git(Tags)                                                                    
 25 12:24:59 [TRACE] (1) scopetime: [scopetime/src/lib.rs:41] scopetime: 0 ms [asyncgit::sync::commits_info::get_commits_info] @asyncgit/src/sync/commits_info.rs:73
 26 12:24:59 [TRACE] (1) asyncgit::tags: [asyncgit/src/tags.rs:67] request                                                                       
 27 12:24:59 [TRACE] (1) scopetime: [scopetime/src/lib.rs:41] scopetime: 2 ms [asyncgit::sync::branch::get_branches_info] @asyncgit/src/sync/branch/mod.rs:118
 28 12:24:59 [TRACE] (2) scopetime: [scopetime/src/lib.rs:41] scopetime: 28 ms [asyncgit::revlog::async::revlog] @asyncgit/src/revlog.rs:142     
 29 12:24:59 [TRACE] (1) scopetime: [scopetime/src/lib.rs:41] scopetime: 5 ms [gitui::loop] @src/main.rs:212                                     
 30 12:24:59 [TRACE] (1) gitui::app: [src/app.rs:494] update_async: Git(Log)                                                                     
 31 12:24:59 [TRACE] (1) scopetime: [scopetime/src/lib.rs:41] scopetime: 21 ms [asyncgit::sync::commits_info::get_commits_info] @asyncgit/src/sync/commits_info.rs:73
 32 12:24:59 [TRACE] (1) asyncgit::tags: [asyncgit/src/tags.rs:67] request                                                                       
 33 12:24:59 [TRACE] (1) scopetime: [scopetime/src/lib.rs:41] scopetime: 2 ms [asyncgit::sync::branch::get_branches_info] @asyncgit/src/sync/branch/mod.rs:118
 34 12:24:59 [TRACE] (1) scopetime: [scopetime/src/lib.rs:41] scopetime: 44 ms [gitui::loop] @src/main.rs:212                                    
 35 12:24:59 [TRACE] (1) gitui::app: [src/app.rs:494] update_async: Git(Log)                                                                     
 36 12:24:59 [TRACE] (1) asyncgit::tags: [asyncgit/src/tags.rs:67] request                                                                       
 37 12:24:59 [TRACE] (1) scopetime: [scopetime/src/lib.rs:41] scopetime: 2 ms [asyncgit::sync::branch::get_branches_info] @asyncgit/src/sync/branch/mod.rs:118
 38 12:24:59 [TRACE] (1) scopetime: [scopetime/src/lib.rs:41] scopetime: 9 ms [gitui::loop] @src/main.rs:212                                     
 39 12:25:02 [DEBUG] (9) gitui::watcher: notify events: 1                                                                                        
 40 12:25:02 [DEBUG] (9) gitui::watcher: notify [0]: DebouncedEvent { path: "<my home dir>/Code/gitui/.git/gitui", kind: Any }                   
 41 12:25:02 [TRACE] (1) gitui::app: [src/app.rs:475] update                                                                                     
 42 12:25:02 [TRACE] (1) scopetime: [scopetime/src/lib.rs:41] scopetime: 0 ms [asyncgit::sync::utils::get_head_repo] @asyncgit/src/sync/utils.rs:82
 43 12:25:02 [TRACE] (1) scopetime: [scopetime/src/lib.rs:41] scopetime: 0 ms [asyncgit::sync::utils::get_head_repo] @asyncgit/src/sync/utils.rs:82
 44 12:25:02 [TRACE] (1) asyncgit::tags: [asyncgit/src/tags.rs:67] request                                                                       
 45 12:25:02 [TRACE] (1) scopetime: [scopetime/src/lib.rs:41] scopetime: 3 ms [asyncgit::sync::branch::get_branches_info] @asyncgit/src/sync/branch/mod.rs:118
 46 12:25:02 [TRACE] (1) scopetime: [scopetime/src/lib.rs:41] scopetime: 15 ms [gitui::loop] @src/main.rs:212                                    
 47 12:25:06 [TRACE] (1) gitui::app: [src/app.rs:380] event: Input(Key(KeyEvent { code: Char('1'), modifiers: NONE, kind: Press, state: NONE })) 
 48 12:25:06 [TRACE] (1) scopetime: [scopetime/src/lib.rs:41] scopetime: 2 ms [asyncgit::sync::branch::get_branches_info] @asyncgit/src/sync/branch/mod.rs:118
 49 12:25:06 [TRACE] (1) scopetime: [scopetime/src/lib.rs:41] scopetime: 0 ms [asyncgit::sync::utils::get_head_repo] @asyncgit/src/sync/utils.rs:82
 50 12:25:06 [TRACE] (1) asyncgit::status: [asyncgit/src/status.rs:102] request: [hash: 8899781867415032480] (type: WorkingDir)                  
 51 12:25:06 [TRACE] (1) asyncgit::status: [asyncgit/src/status.rs:102] request: [hash: 6360984118397946275] (type: Stage)                       
 52 12:25:06 [TRACE] (1) scopetime: [scopetime/src/lib.rs:41] scopetime: 0 ms [asyncgit::sync::state::repo_state] @asyncgit/src/sync/state.rs:38 
 53 12:25:06 [TRACE] (3) scopetime: [scopetime/src/lib.rs:41] scopetime: 0 ms [asyncgit::sync::config::get_config_string_repo] @asyncgit/src/sync/config.rs:86
 54 12:25:06 [TRACE] (2) scopetime: [scopetime/src/lib.rs:41] scopetime: 0 ms [asyncgit::sync::config::get_config_string_repo] @asyncgit/src/sync/config.rs:86
 55 12:25:06 [TRACE] (3) scopetime: [scopetime/src/lib.rs:41] scopetime: 2 ms [asyncgit::sync::status::get_status] @asyncgit/src/sync/status.rs:135
 56 12:25:06 [TRACE] (3) asyncgit::status: [asyncgit/src/status.rs:160] status fetched: 6360984118397946275 (type: Stage)                        
 57 12:25:06 [TRACE] (1) scopetime: [scopetime/src/lib.rs:41] scopetime: 1 ms [asyncgit::sync::branch::branch_compare_upstream] @asyncgit/src/sync/branch/mod.rs:251
 58 12:25:06 [TRACE] (2) scopetime: [scopetime/src/lib.rs:41] scopetime: 3 ms [asyncgit::sync::status::get_status] @asyncgit/src/sync/status.rs:135
 59 12:25:06 [TRACE] (2) asyncgit::status: [asyncgit/src/status.rs:160] status fetched: 8899781867415032480 (type: WorkingDir)                   
 60 12:25:06 [TRACE] (1) scopetime: [scopetime/src/lib.rs:41] scopetime: 12 ms [gitui::loop] @src/main.rs:212                                    
 61 12:25:06 [TRACE] (1) gitui::app: [src/app.rs:494] update_async: Git(Status)                                                                  
 62 12:25:06 [TRACE] (1) scopetime: [scopetime/src/lib.rs:41] scopetime: 2 ms [asyncgit::sync::branch::get_branches_info] @asyncgit/src/sync/branch/mod.rs:118
 63 12:25:06 [TRACE] (1) scopetime: [scopetime/src/lib.rs:41] scopetime: 4 ms [gitui::loop] @src/main.rs:212                                     
 64 12:25:06 [TRACE] (1) gitui::app: [src/app.rs:494] update_async: Git(Status)                                                                  
 65 12:25:06 [TRACE] (1) scopetime: [scopetime/src/lib.rs:41] scopetime: 2 ms [asyncgit::sync::branch::get_branches_info] @asyncgit/src/sync/branch/mod.rs:118
 66 12:25:06 [TRACE] (1) scopetime: [scopetime/src/lib.rs:41] scopetime: 5 ms [gitui::loop] @src/main.rs:212                                     
 67 12:25:08 [TRACE] (1) gitui::app: [src/app.rs:380] event: Input(Key(KeyEvent { code: Char('q'), modifiers: NONE, kind: Press, state: NONE })) 
 68 12:25:08 [TRACE] (1) scopetime: [scopetime/src/lib.rs:41] scopetime: 1 ms [gitui::loop] @src/main.rs:212

1   tail: <my home dir>/.cache/gitui/gitui.log: file truncated                                                                                                                                                                                                                                                                                                                                                                                                                                          
  1 12:28:14 [TRACE] (6) mio::poll: [<my home dir>/.cargo/registry/src/github.jparrowsec.cn-1ecc6299db9ec823/mio-0.8.4/src/poll.rs:521] registering event source with poller: token=Token(0), interests=READABLE
  2 12:28:14 [TRACE] (6) mio::poll: [<my home dir>/.cargo/registry/src/github.jparrowsec.cn-1ecc6299db9ec823/mio-0.8.4/src/poll.rs:521] registering event source with poller: token=Token(1), interests=READABLE
  3 12:28:14 [TRACE] (1) mio::poll: [<my home dir>/.cargo/registry/src/github.jparrowsec.cn-1ecc6299db9ec823/mio-0.8.4/src/poll.rs:521] registering event source with poller: token=Token(0), interests=READABLE
  4 12:28:14 [TRACE] (1) gitui::app: [src/app.rs:119] open repo at: RefCell { value: Path(".") }                                                 
  5 12:28:14 [TRACE] (1) scopetime: [scopetime/src/lib.rs:41] scopetime: 2 ms [asyncgit::sync::branch::get_branches_info] @asyncgit/src/sync/branch/mod.rs:118
  6 12:28:14 [TRACE] (1) scopetime: [scopetime/src/lib.rs:41] scopetime: 0 ms [asyncgit::sync::utils::get_head_repo] @asyncgit/src/sync/utils.rs:82
  7 12:28:14 [TRACE] (1) scopetime: [scopetime/src/lib.rs:41] scopetime: 0 ms [asyncgit::sync::branch::get_branch_name_repo] @asyncgit/src/sync/branch/mod.rs:34
  8 12:28:14 [TRACE] (1) asyncgit::status: [asyncgit/src/status.rs:102] request: [hash: 16996878335589222437] (type: WorkingDir)                 
  9 12:28:14 [TRACE] (1) asyncgit::status: [asyncgit/src/status.rs:102] request: [hash: 175302263854643909] (type: Stage)                        
 10 12:28:14 [TRACE] (2) scopetime: [scopetime/src/lib.rs:41] scopetime: 0 ms [asyncgit::sync::config::get_config_string_repo] @asyncgit/src/sync/config.rs:86
 11 12:28:14 [TRACE] (3) scopetime: [scopetime/src/lib.rs:41] scopetime: 0 ms [asyncgit::sync::config::get_config_string_repo] @asyncgit/src/sync/config.rs:86
 12 12:28:14 [TRACE] (1) scopetime: [scopetime/src/lib.rs:41] scopetime: 0 ms [asyncgit::sync::state::repo_state] @asyncgit/src/sync/state.rs:38 
 13 12:28:14 [TRACE] (3) scopetime: [scopetime/src/lib.rs:41] scopetime: 2 ms [asyncgit::sync::status::get_status] @asyncgit/src/sync/status.rs:135
 14 12:28:14 [TRACE] (3) asyncgit::status: [asyncgit/src/status.rs:160] status fetched: 175302263854643909 (type: Stage)                         
 15 12:28:14 [TRACE] (1) scopetime: [scopetime/src/lib.rs:41] scopetime: 1 ms [asyncgit::sync::branch::branch_compare_upstream] @asyncgit/src/sync/branch/mod.rs:251
 16 12:28:14 [TRACE] (2) scopetime: [scopetime/src/lib.rs:41] scopetime: 3 ms [asyncgit::sync::status::get_status] @asyncgit/src/sync/status.rs:135
 17 12:28:14 [TRACE] (2) asyncgit::status: [asyncgit/src/status.rs:160] status fetched: 16996878335589222437 (type: WorkingDir)                  
 18 12:28:14 [TRACE] (1) gitui::app: [src/app.rs:475] update                                                                                     
 19 12:28:14 [TRACE] (1) scopetime: [scopetime/src/lib.rs:41] scopetime: 0 ms [asyncgit::sync::utils::get_head_repo] @asyncgit/src/sync/utils.rs:82
 20 12:28:14 [TRACE] (1) scopetime: [scopetime/src/lib.rs:41] scopetime: 0 ms [asyncgit::sync::branch::get_branch_name_repo] @asyncgit/src/sync/branch/mod.rs:34
 21 12:28:14 [TRACE] (1) scopetime: [scopetime/src/lib.rs:41] scopetime: 0 ms [asyncgit::sync::utils::get_head_repo] @asyncgit/src/sync/utils.rs:82
 22 12:28:14 [TRACE] (1) asyncgit::status: [asyncgit/src/status.rs:102] request: [hash: 16820291148087560183] (type: WorkingDir)                 
 23 12:28:14 [TRACE] (1) asyncgit::status: [asyncgit/src/status.rs:102] request: [hash: 11729092214781967683] (type: Stage)                      
 24 12:28:14 [TRACE] (2) scopetime: [scopetime/src/lib.rs:41] scopetime: 0 ms [asyncgit::sync::config::get_config_string_repo] @asyncgit/src/sync/config.rs:86
 25 12:28:14 [TRACE] (3) scopetime: [scopetime/src/lib.rs:41] scopetime: 0 ms [asyncgit::sync::config::get_config_string_repo] @asyncgit/src/sync/config.rs:86
 26 12:28:14 [TRACE] (1) scopetime: [scopetime/src/lib.rs:41] scopetime: 0 ms [asyncgit::sync::state::repo_state] @asyncgit/src/sync/state.rs:38 
 27 12:28:14 [TRACE] (3) scopetime: [scopetime/src/lib.rs:41] scopetime: 2 ms [asyncgit::sync::status::get_status] @asyncgit/src/sync/status.rs:135
 28 12:28:14 [TRACE] (3) asyncgit::status: [asyncgit/src/status.rs:160] status fetched: 11729092214781967683 (type: Stage)                       
 29 12:28:14 [TRACE] (1) scopetime: [scopetime/src/lib.rs:41] scopetime: 1 ms [asyncgit::sync::branch::branch_compare_upstream] @asyncgit/src/sync/branch/mod.rs:251
 30 12:28:14 [TRACE] (2) scopetime: [scopetime/src/lib.rs:41] scopetime: 3 ms [asyncgit::sync::status::get_status] @asyncgit/src/sync/status.rs:135
 31 12:28:14 [TRACE] (2) asyncgit::status: [asyncgit/src/status.rs:160] status fetched: 16820291148087560183 (type: WorkingDir)                  
 32 12:28:14 [TRACE] (1) scopetime: [scopetime/src/lib.rs:41] scopetime: 11 ms [gitui::loop] @src/main.rs:212                                    
 33 12:28:14 [TRACE] (1) gitui::app: [src/app.rs:494] update_async: Git(Status)                                                                  
 34 12:28:14 [TRACE] (1) scopetime: [scopetime/src/lib.rs:41] scopetime: 2 ms [asyncgit::sync::branch::get_branches_info] @asyncgit/src/sync/branch/mod.rs:118
 35 12:28:14 [TRACE] (1) scopetime: [scopetime/src/lib.rs:41] scopetime: 4 ms [gitui::loop] @src/main.rs:212                                     
 36 12:28:14 [TRACE] (1) gitui::app: [src/app.rs:494] update_async: Git(Status)                                                                  
 37 12:28:14 [TRACE] (1) scopetime: [scopetime/src/lib.rs:41] scopetime: 2 ms [asyncgit::sync::branch::get_branches_info] @asyncgit/src/sync/branch/mod.rs:118
 38 12:28:14 [TRACE] (1) scopetime: [scopetime/src/lib.rs:41] scopetime: 4 ms [gitui::loop] @src/main.rs:212                                     
 39 12:28:14 [TRACE] (1) gitui::app: [src/app.rs:494] update_async: Git(Status)                                                                  
 40 12:28:14 [TRACE] (1) scopetime: [scopetime/src/lib.rs:41] scopetime: 2 ms [asyncgit::sync::branch::get_branches_info] @asyncgit/src/sync/branch/mod.rs:118
 41 12:28:14 [TRACE] (1) scopetime: [scopetime/src/lib.rs:41] scopetime: 4 ms [gitui::loop] @src/main.rs:212                                     
 42 12:28:14 [TRACE] (1) gitui::app: [src/app.rs:494] update_async: Git(Status)                                                                  
 43 12:28:14 [TRACE] (1) scopetime: [scopetime/src/lib.rs:41] scopetime: 2 ms [asyncgit::sync::branch::get_branches_info] @asyncgit/src/sync/branch/mod.rs:118
 44 12:28:14 [TRACE] (1) scopetime: [scopetime/src/lib.rs:41] scopetime: 4 ms [gitui::loop] @src/main.rs:212                                     
 45 12:28:17 [DEBUG] (9) gitui::watcher: notify events: 1                                                                                        
 46 12:28:17 [DEBUG] (9) gitui::watcher: notify [0]: DebouncedEvent { path: "<my home dir>/Code/gitui/.git/gitui", kind: Any }                   
 47 12:28:17 [TRACE] (1) gitui::app: [src/app.rs:475] update                                                                                     
 48 12:28:17 [TRACE] (1) scopetime: [scopetime/src/lib.rs:41] scopetime: 0 ms [asyncgit::sync::utils::get_head_repo] @asyncgit/src/sync/utils.rs:82
 49 12:28:17 [TRACE] (1) scopetime: [scopetime/src/lib.rs:41] scopetime: 0 ms [asyncgit::sync::utils::get_head_repo] @asyncgit/src/sync/utils.rs:82
 50 12:28:17 [TRACE] (1) asyncgit::status: [asyncgit/src/status.rs:102] request: [hash: 10107808578477458434] (type: WorkingDir)                 
 51 12:28:17 [TRACE] (1) asyncgit::status: [asyncgit/src/status.rs:102] request: [hash: 14443303713589150085] (type: Stage)                      
 52 12:28:17 [TRACE] (1) scopetime: [scopetime/src/lib.rs:41] scopetime: 0 ms [asyncgit::sync::state::repo_state] @asyncgit/src/sync/state.rs:38 
 53 12:28:17 [TRACE] (2) scopetime: [scopetime/src/lib.rs:41] scopetime: 0 ms [asyncgit::sync::config::get_config_string_repo] @asyncgit/src/sync/config.rs:86
 54 12:28:17 [TRACE] (3) scopetime: [scopetime/src/lib.rs:41] scopetime: 0 ms [asyncgit::sync::config::get_config_string_repo] @asyncgit/src/sync/config.rs:86
 55 12:28:17 [TRACE] (3) scopetime: [scopetime/src/lib.rs:41] scopetime: 2 ms [asyncgit::sync::status::get_status] @asyncgit/src/sync/status.rs:135
 56 12:28:17 [TRACE] (3) asyncgit::status: [asyncgit/src/status.rs:160] status fetched: 14443303713589150085 (type: Stage)                       
 57 12:28:17 [TRACE] (1) scopetime: [scopetime/src/lib.rs:41] scopetime: 1 ms [asyncgit::sync::branch::branch_compare_upstream] @asyncgit/src/sync/branch/mod.rs:251
 58 12:28:17 [TRACE] (2) scopetime: [scopetime/src/lib.rs:41] scopetime: 3 ms [asyncgit::sync::status::get_status] @asyncgit/src/sync/status.rs:135
 59 12:28:17 [TRACE] (2) asyncgit::status: [asyncgit/src/status.rs:160] status fetched: 10107808578477458434 (type: WorkingDir)                  
 60 12:28:17 [TRACE] (1) scopetime: [scopetime/src/lib.rs:41] scopetime: 12 ms [gitui::loop] @src/main.rs:212                                    
 61 12:28:17 [TRACE] (1) gitui::app: [src/app.rs:494] update_async: Git(Status)                                                                  
 62 12:28:17 [TRACE] (1) scopetime: [scopetime/src/lib.rs:41] scopetime: 2 ms [asyncgit::sync::branch::get_branches_info] @asyncgit/src/sync/branch/mod.rs:118
 63 12:28:17 [TRACE] (1) scopetime: [scopetime/src/lib.rs:41] scopetime: 4 ms [gitui::loop] @src/main.rs:212                                     
 64 12:28:17 [TRACE] (1) gitui::app: [src/app.rs:494] update_async: Git(Status)                                                                  
 65 12:28:17 [TRACE] (1) scopetime: [scopetime/src/lib.rs:41] scopetime: 2 ms [asyncgit::sync::branch::get_branches_info] @asyncgit/src/sync/branch/mod.rs:118
 66 12:28:17 [TRACE] (1) scopetime: [scopetime/src/lib.rs:41] scopetime: 4 ms [gitui::loop] @src/main.rs:212                                     
 67 12:28:23 [TRACE] (1) gitui::app: [src/app.rs:380] event: Input(Key(KeyEvent { code: Char('q'), modifiers: NONE, kind: Press, state: NONE })) 
 68 12:28:23 [TRACE] (1) scopetime: [scopetime/src/lib.rs:41] scopetime: 6 ms [gitui::loop] @src/main.rs:212

numToStr · 2022-11-21T12:42:03Z

I am also getting consistent delay (1s - 3s) in startup. My work repository also have >2k commits. Although I didn't get chance to fully debug the behaviour.

extrawurst · 2022-11-21T12:45:54Z

1s is super long. Can you build with timing like I mentioned above and share the log to figure out where the culprit lies?

numToStr · 2022-11-21T12:57:09Z

Can you build with timing like I mentioned above and share the log to figure out where the culprit lies?

Sure. I'll paste the logs once done.

extrawurst · 2022-11-21T13:51:32Z

@MartinVincent can you do your checks again with current master (3fee481) and check if

the problem persists and
what the logs give us, because it logs out the exact startup times now into the logs (basically the duration of the first render)

MartinVincent · 2022-11-21T14:34:19Z

ok, so I did:

~/Code/gitui ❯ g pull                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                  
From https://github.com/extrawurst/gitui                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                  
   b495425..3667db3  master                             -> origin/master                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                  
 * [new branch]      dependabot/cargo/rayon-core-1.10.1 -> origin/dependabot/cargo/rayon-core-1.10.1                                                                                                                                                                                                                                                                                                                                                                                                                                                                                      
Updating b495425..3667db3                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                 
Fast-forward                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                              
 README.md   | 2 ++                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                       
 src/main.rs | 6 ++++++                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                   
 2 files changed, 8 insertions(+)                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                         
Current branch master is up to date.

then : make debug with the .virtualenv dir present:

14:24:53 [TRACE] (1) gitui::app: [<my home dir>/.cargo/registry/src/github.jparrowsec.cn-1ecc6299db9ec823/gitui-0.22.0/src/app.rs:380] event: Input(Key(KeyEvent { code: Char('q'), modifiers: NONE, kind: Press, state: NONE }))                                                                                                                                                                                                                                                                                                                                                                  
tail: <my home dir>/.cache/gitui/gitui.log: file truncated                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                               
14:25:11 [TRACE] (6) mio::poll: [<my home dir>/.cargo/registry/src/github.jparrowsec.cn-1ecc6299db9ec823/mio-0.8.4/src/poll.rs:521] registering event source with poller: token=Token(0), interests=READABLE                                                                                                                                                                                                                                                                                                                                                                                       
14:25:11 [TRACE] (6) mio::poll: [<my home dir>/.cargo/registry/src/github.jparrowsec.cn-1ecc6299db9ec823/mio-0.8.4/src/poll.rs:521] registering event source with poller: token=Token(1), interests=READABLE                                                                                                                                                                                                                                                                                                                                                                                       
14:25:11 [TRACE] (1) mio::poll: [<my home dir>/.cargo/registry/src/github.jparrowsec.cn-1ecc6299db9ec823/mio-0.8.4/src/poll.rs:521] registering event source with poller: token=Token(0), interests=READABLE                                                                                                                                                                                                                                                                                                                                                                                       
14:25:12 [TRACE] (1) gitui::app: [src/app.rs:119] open repo at: RefCell { value: Path(".") }                                                                                                                                                                                                                                                                                                                                                                                                                                                                                              
14:25:12 [TRACE] (1) scopetime: [scopetime/src/lib.rs:41] scopetime: 1 ms [asyncgit::sync::commits_info::get_commits_info] @asyncgit/src/sync/commits_info.rs:73                                                                                                                                                                                                                                                                                                                                                                                                                          
14:25:12 [TRACE] (1) asyncgit::tags: [asyncgit/src/tags.rs:67] request                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                    
14:25:12 [TRACE] (1) scopetime: [scopetime/src/lib.rs:41] scopetime: 3 ms [asyncgit::sync::branch::get_branches_info] @asyncgit/src/sync/branch/mod.rs:118                                                                                                                                                                                                                                                                                                                                                                                                                                
14:25:12 [TRACE] (3) scopetime: [scopetime/src/lib.rs:41] scopetime: 3 ms [asyncgit::sync::tags::get_tags] @asyncgit/src/sync/tags.rs:58                                                                                                                                                                                                                                                                                                                                                                                                                                                  
14:25:12 [TRACE] (1) gitui: [src/main.rs:195] app start: 625 ms                                                <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<                                                                                                                                                                                                                                                                                                                                                                                                                                          
14:25:12 [TRACE] (1) gitui::app: [src/app.rs:475] update                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                  
14:25:12 [TRACE] (1) scopetime: [scopetime/src/lib.rs:41] scopetime: 0 ms [asyncgit::sync::utils::get_head_repo] @asyncgit/src/sync/utils.rs:82                                                                                                                                                                                                                                                                                                                                                                                                                                           
14:25:12 [TRACE] (1) scopetime: [scopetime/src/lib.rs:41] scopetime: 0 ms [asyncgit::sync::branch::get_branch_name_repo] @asyncgit/src/sync/branch/mod.rs:34                                                                                                                                                                                                                                                                                                                                                                                                                              
14:25:12 [TRACE] (1) scopetime: [scopetime/src/lib.rs:41] scopetime: 0 ms [asyncgit::sync::utils::get_head_repo] @asyncgit/src/sync/utils.rs:82                                                                                                                                                                                                                                                                                                                                                                                                                                           
14:25:12 [TRACE] (1) scopetime: [scopetime/src/lib.rs:41] scopetime: 0 ms [asyncgit::sync::branch::get_branch_name_repo] @asyncgit/src/sync/branch/mod.rs:34                                                                                                                                                                                                                                                                                                                                                                                                                              
14:25:12 [TRACE] (1) scopetime: [scopetime/src/lib.rs:41] scopetime: 0 ms [asyncgit::sync::commits_info::get_commits_info] @asyncgit/src/sync/commits_info.rs:73                                                                                                                                                                                                                                                                                                                                                                                                                          
14:25:12 [TRACE] (1) asyncgit::tags: [asyncgit/src/tags.rs:67] request                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                    
14:25:12 [TRACE] (1) scopetime: [scopetime/src/lib.rs:41] scopetime: 3 ms [asyncgit::sync::branch::get_branches_info] @asyncgit/src/sync/branch/mod.rs:118                                                                                                                                                                                                                                                                                                                                                                                                                                
14:25:12 [TRACE] (3) scopetime: [scopetime/src/lib.rs:41] scopetime: 3 ms [asyncgit::sync::tags::get_tags] @asyncgit/src/sync/tags.rs:58                                                                                                                                                                                                                                                                                                                                                                                                                                                  
14:25:12 [TRACE] (1) scopetime: [scopetime/src/lib.rs:41] scopetime: 13 ms [gitui::loop] @src/main.rs:218                                                                                                                                                                                                                                                                                                                                                                                                                                                                                 
14:25:12 [TRACE] (1) gitui::app: [src/app.rs:494] update_async: Git(Tags)                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                 
14:25:12 [TRACE] (1) scopetime: [scopetime/src/lib.rs:41] scopetime: 1 ms [asyncgit::sync::commits_info::get_commits_info] @asyncgit/src/sync/commits_info.rs:73                                                                                                                                                                                                                                                                                                                                                                                                                          
14:25:12 [TRACE] (1) asyncgit::tags: [asyncgit/src/tags.rs:67] request                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                    
14:25:12 [TRACE] (1) scopetime: [scopetime/src/lib.rs:41] scopetime: 2 ms [asyncgit::sync::branch::get_branches_info] @asyncgit/src/sync/branch/mod.rs:118                                                                                                                                                                                                                                                                                                                                                                                                                                
14:25:12 [TRACE] (1) scopetime: [scopetime/src/lib.rs:41] scopetime: 6 ms [gitui::loop] @src/main.rs:218                                                                                                                                                                                                                                                                                                                                                                                                                                                                                  
14:25:12 [TRACE] (1) gitui::app: [src/app.rs:494] update_async: Git(Tags)                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                 
14:25:12 [TRACE] (2) scopetime: [scopetime/src/lib.rs:41] scopetime: 28 ms [asyncgit::revlog::async::revlog] @asyncgit/src/revlog.rs:142                                                                                                                                                                                                                                                                                                                                                                                                                                                  
14:25:12 [TRACE] (1) scopetime: [scopetime/src/lib.rs:41] scopetime: 22 ms [asyncgit::sync::commits_info::get_commits_info] @asyncgit/src/sync/commits_info.rs:73                                                                                                                                                                                                                                                                                                                                                                                                                         
14:25:12 [TRACE] (1) asyncgit::tags: [asyncgit/src/tags.rs:67] request                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                    
14:25:12 [TRACE] (1) scopetime: [scopetime/src/lib.rs:41] scopetime: 2 ms [asyncgit::sync::branch::get_branches_info] @asyncgit/src/sync/branch/mod.rs:118                                                                                                                                                                                                                                                                                                                                                                                                                                
14:25:12 [TRACE] (1) scopetime: [scopetime/src/lib.rs:41] scopetime: 43 ms [gitui::loop] @src/main.rs:218                                                                                                                                                                                                                                                                                                                                                                                                                                                                                 
14:25:12 [TRACE] (1) gitui::app: [src/app.rs:494] update_async: Git(Log)                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                  
14:25:12 [TRACE] (1) asyncgit::tags: [asyncgit/src/tags.rs:67] request                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                    
14:25:12 [TRACE] (1) scopetime: [scopetime/src/lib.rs:41] scopetime: 2 ms [asyncgit::sync::branch::get_branches_info] @asyncgit/src/sync/branch/mod.rs:118                                                                                                                                                                                                                                                                                                                                                                                                                                
14:25:12 [TRACE] (1) scopetime: [scopetime/src/lib.rs:41] scopetime: 10 ms [gitui::loop] @src/main.rs:218                                                                                                                                                                                                                                                                                                                                                                                                                                                                                 
14:25:12 [TRACE] (1) gitui::app: [src/app.rs:494] update_async: Git(Log)                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                  
14:25:12 [TRACE] (1) asyncgit::tags: [asyncgit/src/tags.rs:67] request                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                    
14:25:12 [TRACE] (1) scopetime: [scopetime/src/lib.rs:41] scopetime: 2 ms [asyncgit::sync::branch::get_branches_info] @asyncgit/src/sync/branch/mod.rs:118                                                                                                                                                                                                                                                                                                                                                                                                                                
14:25:12 [TRACE] (1) scopetime: [scopetime/src/lib.rs:41] scopetime: 8 ms [gitui::loop] @src/main.rs:218                                                                                                                                                                                                                                                                                                                                                                                                                                                                                  
14:25:14 [DEBUG] (9) gitui::watcher: notify events: 1                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                     
14:25:14 [DEBUG] (9) gitui::watcher: notify [0]: DebouncedEvent { path: "<my home dir>/Code/gitui/.git/gitui", kind: Any }                                                                                                                                                                                                                                                                                                                                                                                                                                                               
14:25:14 [TRACE] (1) gitui::app: [src/app.rs:475] update                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                  
14:25:14 [TRACE] (1) scopetime: [scopetime/src/lib.rs:41] scopetime: 0 ms [asyncgit::sync::utils::get_head_repo] @asyncgit/src/sync/utils.rs:82                                                                                                                                                                                                                                                                                                                                                                                                                                           
14:25:14 [TRACE] (1) scopetime: [scopetime/src/lib.rs:41] scopetime: 0 ms [asyncgit::sync::utils::get_head_repo] @asyncgit/src/sync/utils.rs:82                                                                                                                                                                                                                                                                                                                                                                                                                                           
14:25:14 [TRACE] (1) asyncgit::tags: [asyncgit/src/tags.rs:67] request                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                    
14:25:14 [TRACE] (1) scopetime: [scopetime/src/lib.rs:41] scopetime: 3 ms [asyncgit::sync::branch::get_branches_info] @asyncgit/src/sync/branch/mod.rs:118                                                                                                                                                                                                                                                                                                                                                                                                                                
14:25:14 [TRACE] (1) scopetime: [scopetime/src/lib.rs:41] scopetime: 19 ms [gitui::loop] @src/main.rs:218                                                                                                                                                                                                                                                                                                                                                                                                                                                                                 
14:25:25 [TRACE] (1) gitui::app: [src/app.rs:380] event: Input(Key(KeyEvent { code: Char('q'), modifiers: NONE, kind: Press, state: NONE }))                                                                                                                                                                                                                                                                                                                                                                                                                                              
14:25:25 [TRACE] (1) scopetime: [scopetime/src/lib.rs:41] scopetime: 7 ms [gitui::loop] @src/main.rs:218

then : make debug with the .virtualenv dir absent:

tail: <my home dir>/.cache/gitui/gitui.log: file truncated                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                               
14:26:58 [TRACE] (6) mio::poll: [<my home dir>/.cargo/registry/src/github.jparrowsec.cn-1ecc6299db9ec823/mio-0.8.4/src/poll.rs:521] registering event source with poller: token=Token(0), interests=READABLE                                                                                                                                                                                                                                                                                                                                                                                       
14:26:58 [TRACE] (6) mio::poll: [<my home dir>.cargo/registry/src/github.jparrowsec.cn-1ecc6299db9ec823/mio-0.8.4/src/poll.rs:521] registering event source with poller: token=Token(1), interests=READABLE                                                                                                                                                                                                                                                                                                                                                                                       
14:26:58 [TRACE] (1) mio::poll: [<my home dir>.cargo/registry/src/github.jparrowsec.cn-1ecc6299db9ec823/mio-0.8.4/src/poll.rs:521] registering event source with poller: token=Token(0), interests=READABLE                                                                                                                                                                                                                                                                                                                                                                                       
14:26:58 [TRACE] (1) gitui::app: [src/app.rs:119] open repo at: RefCell { value: Path(".") }                                                                                                                                                                                                                                                                                                                                                                                                                                                                                              
14:26:58 [TRACE] (1) scopetime: [scopetime/src/lib.rs:41] scopetime: 0 ms [asyncgit::sync::commits_info::get_commits_info] @asyncgit/src/sync/commits_info.rs:73                                                                                                                                                                                                                                                                                                                                                                                                                          
14:26:58 [TRACE] (1) asyncgit::tags: [asyncgit/src/tags.rs:67] request                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                    
14:26:58 [TRACE] (1) scopetime: [scopetime/src/lib.rs:41] scopetime: 3 ms [asyncgit::sync::branch::get_branches_info] @asyncgit/src/sync/branch/mod.rs:118                                                                                                                                                                                                                                                                                                                                                                                                                                
14:26:58 [TRACE] (1) gitui: [src/main.rs:195] app start: 89 ms                               <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<                                                                  
14:26:58 [TRACE] (1) gitui::app: [src/app.rs:475] update                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                  
14:26:58 [TRACE] (3) scopetime: [scopetime/src/lib.rs:41] scopetime: 6 ms [asyncgit::sync::tags::get_tags] @asyncgit/src/sync/tags.rs:58                                                                                                                                                                                                                                                                                                                                                                                                                                                  
14:26:58 [TRACE] (1) scopetime: [scopetime/src/lib.rs:41] scopetime: 0 ms [asyncgit::sync::utils::get_head_repo] @asyncgit/src/sync/utils.rs:82                                                                                                                                                                                                                                                                                                                                                                                                                                           
14:26:58 [TRACE] (1) scopetime: [scopetime/src/lib.rs:41] scopetime: 0 ms [asyncgit::sync::branch::get_branch_name_repo] @asyncgit/src/sync/branch/mod.rs:34                                                                                                                                                                                                                                                                                                                                                                                                                              
14:26:58 [TRACE] (1) scopetime: [scopetime/src/lib.rs:41] scopetime: 0 ms [asyncgit::sync::utils::get_head_repo] @asyncgit/src/sync/utils.rs:82                                                                                                                                                                                                                                                                                                                                                                                                                                           
14:26:58 [TRACE] (1) scopetime: [scopetime/src/lib.rs:41] scopetime: 0 ms [asyncgit::sync::branch::get_branch_name_repo] @asyncgit/src/sync/branch/mod.rs:34                                                                                                                                                                                                                                                                                                                                                                                                                              
14:26:58 [TRACE] (1) scopetime: [scopetime/src/lib.rs:41] scopetime: 0 ms [asyncgit::sync::commits_info::get_commits_info] @asyncgit/src/sync/commits_info.rs:73                                                                                                                                                                                                                                                                                                                                                                                                                          
14:26:58 [TRACE] (1) asyncgit::tags: [asyncgit/src/tags.rs:67] request                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                    
14:26:58 [TRACE] (1) scopetime: [scopetime/src/lib.rs:41] scopetime: 3 ms [asyncgit::sync::branch::get_branches_info] @asyncgit/src/sync/branch/mod.rs:118                                                                                                                                                                                                                                                                                                                                                                                                                                
14:26:58 [TRACE] (3) scopetime: [scopetime/src/lib.rs:41] scopetime: 3 ms [asyncgit::sync::tags::get_tags] @asyncgit/src/sync/tags.rs:58                                                                                                                                                                                                                                                                                                                                                                                                                                                  
14:26:58 [TRACE] (1) scopetime: [scopetime/src/lib.rs:41] scopetime: 14 ms [gitui::loop] @src/main.rs:218                                                                                                                                                                                                                                                                                                                                                                                                                                                                                 
14:26:58 [TRACE] (1) gitui::app: [src/app.rs:494] update_async: Git(Tags)                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                 
14:26:58 [TRACE] (1) scopetime: [scopetime/src/lib.rs:41] scopetime: 0 ms [asyncgit::sync::commits_info::get_commits_info] @asyncgit/src/sync/commits_info.rs:73                                                                                                                                                                                                                                                                                                                                                                                                                          
14:26:58 [TRACE] (1) asyncgit::tags: [asyncgit/src/tags.rs:67] request                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                    
14:26:58 [TRACE] (1) scopetime: [scopetime/src/lib.rs:41] scopetime: 2 ms [asyncgit::sync::branch::get_branches_info] @asyncgit/src/sync/branch/mod.rs:118                                                                                                                                                                                                                                                                                                                                                                                                                                
14:26:58 [TRACE] (1) scopetime: [scopetime/src/lib.rs:41] scopetime: 5 ms [gitui::loop] @src/main.rs:218                                                                                                                                                                                                                                                                                                                                                                                                                                                                                  
14:26:58 [TRACE] (1) gitui::app: [src/app.rs:494] update_async: Git(Tags)                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                 
14:26:58 [TRACE] (1) scopetime: [scopetime/src/lib.rs:41] scopetime: 0 ms [asyncgit::sync::commits_info::get_commits_info] @asyncgit/src/sync/commits_info.rs:73                                                                                                                                                                                                                                                                                                                                                                                                                          
14:26:58 [TRACE] (1) asyncgit::tags: [asyncgit/src/tags.rs:67] request                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                    
14:26:58 [TRACE] (1) scopetime: [scopetime/src/lib.rs:41] scopetime: 2 ms [asyncgit::sync::branch::get_branches_info] @asyncgit/src/sync/branch/mod.rs:118                                                                                                                                                                                                                                                                                                                                                                                                                                
14:26:58 [TRACE] (1) scopetime: [scopetime/src/lib.rs:41] scopetime: 4 ms [gitui::loop] @src/main.rs:218                                                                                                                                                                                                                                                                                                                                                                                                                                                                                  
14:26:58 [TRACE] (1) gitui::app: [src/app.rs:494] update_async: Git(Log)                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                  
14:26:58 [TRACE] (2) scopetime: [scopetime/src/lib.rs:41] scopetime: 31 ms [asyncgit::revlog::async::revlog] @asyncgit/src/revlog.rs:142                                                                                                                                                                                                                                                                                                                                                                                                                                                  
14:26:58 [TRACE] (1) scopetime: [scopetime/src/lib.rs:41] scopetime: 21 ms [asyncgit::sync::commits_info::get_commits_info] @asyncgit/src/sync/commits_info.rs:73                                                                                                                                                                                                                                                                                                                                                                                                                         
14:26:58 [TRACE] (1) asyncgit::tags: [asyncgit/src/tags.rs:67] request                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                    
14:26:58 [TRACE] (1) scopetime: [scopetime/src/lib.rs:41] scopetime: 2 ms [asyncgit::sync::branch::get_branches_info] @asyncgit/src/sync/branch/mod.rs:118                                                                                                                                                                                                                                                                                                                                                                                                                                
14:26:58 [TRACE] (1) scopetime: [scopetime/src/lib.rs:41] scopetime: 40 ms [gitui::loop] @src/main.rs:218                                                                                                                                                                                                                                                                                                                                                                                                                                                                                 
14:26:58 [TRACE] (1) gitui::app: [src/app.rs:494] update_async: Git(Log)                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                  
14:26:58 [TRACE] (1) asyncgit::tags: [asyncgit/src/tags.rs:67] request                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                    
14:26:58 [TRACE] (1) scopetime: [scopetime/src/lib.rs:41] scopetime: 2 ms [asyncgit::sync::branch::get_branches_info] @asyncgit/src/sync/branch/mod.rs:118                                                                                                                                                                                                                                                                                                                                                                                                                                
14:26:58 [TRACE] (1) scopetime: [scopetime/src/lib.rs:41] scopetime: 9 ms [gitui::loop] @src/main.rs:218                                                                                                                                                                                                                                                                                                                                                                                                                                                                                  
14:27:01 [DEBUG] (9) gitui::watcher: notify events: 1                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                     
14:27:01 [DEBUG] (9) gitui::watcher: notify [0]: DebouncedEvent { path: "<my home dir>/Code/gitui/.git/gitui", kind: Any }                                                                                                                                                                                                                                                                                                                                                                                                                                                               
14:27:01 [TRACE] (1) gitui::app: [src/app.rs:475] update                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                  
14:27:01 [TRACE] (1) scopetime: [scopetime/src/lib.rs:41] scopetime: 0 ms [asyncgit::sync::utils::get_head_repo] @asyncgit/src/sync/utils.rs:82                                                                                                                                                                                                                                                                                                                                                                                                                                           
14:27:01 [TRACE] (1) scopetime: [scopetime/src/lib.rs:41] scopetime: 0 ms [asyncgit::sync::utils::get_head_repo] @asyncgit/src/sync/utils.rs:82                                                                                                                                                                                                                                                                                                                                                                                                                                           
14:27:01 [TRACE] (1) asyncgit::tags: [asyncgit/src/tags.rs:67] request                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                    
14:27:01 [TRACE] (1) scopetime: [scopetime/src/lib.rs:41] scopetime: 10 ms [asyncgit::sync::branch::get_branches_info] @asyncgit/src/sync/branch/mod.rs:118                                                                                                                                                                                                                                                                                                                                                                                                                               
14:27:01 [TRACE] (1) scopetime: [scopetime/src/lib.rs:41] scopetime: 40 ms [gitui::loop] @src/main.rs:218                                                                                                                                                                                                                                                                                                                                                                                                                                                                                 
14:27:01 [TRACE] (1) gitui::app: [src/app.rs:380] event: Input(Key(KeyEvent { code: Char('q'), modifiers: NONE, kind: Press, state: NONE }))                                                                                                                                                                                                                                                                                                                                                                                                                                              
14:27:01 [TRACE] (1) scopetime: [scopetime/src/lib.rs:41] scopetime: 8 ms [gitui::loop] @src/main.rs:218

extrawurst · 2022-11-21T15:21:52Z

ok wow 600ms inside the appstart sequense. this is crazy.
can you please run make profile from current master. it should generate a flamegraph file.

extrawurst · 2022-11-21T16:07:31Z

new theory: cf9ce9d is the culprit and the filesystem watcher takes ages if there is a ton of files generated for this .virtualenv. newest master (8cdb023) has explicit scope timing in the logs for the watcher initialisation.

MartinVincent · 2022-11-21T16:10:15Z

Approx 40000 files in .virtualenv:

 ~/Code/gitui ❯  git pull
From https://github.com/extrawurst/gitui
   3667db3..8cdb023  master     -> origin/master
Updating 3667db3..8cdb023
Fast-forward
 asyncgit/src/branches.rs      | 77 +++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++
 asyncgit/src/lib.rs           |  4 ++++
 src/components/branchlist.rs  |  2 +-
 src/components/changes.rs     | 14 ++++++++++++++
 src/components/status_tree.rs |  2 ++
 src/tabs/revlog.rs            | 36 ++++++++++++++++++++++++++++--------
 src/tabs/status.rs            | 32 +++++++++++++++++++++++++-------
 src/watcher.rs                |  3 +++
 8 files changed, 154 insertions(+), 16 deletions(-)
 create mode 100644 asyncgit/src/branches.rs
 
 
 
 
  ~/Code/gitui ❯ make profile

and make debug for 8cdb023:

 44 16:15:04 [TRACE] (6) mio::poll: [<my home dir>/.cargo/registry/src/github.jparrowsec.cn-1ecc6299db9ec823/mio-0.8.4/src/poll.rs:521] registering event source with poller: token=Token(0), interests=READABLE 
 43 16:15:04 [TRACE] (6) mio::poll: [<my home dir>/.cargo/registry/src/github.jparrowsec.cn-1ecc6299db9ec823/mio-0.8.4/src/poll.rs:521] registering event source with poller: token=Token(1), interests=READABLE 
 42 16:15:04 [TRACE] (1) mio::poll: [<my home dir>/.cargo/registry/src/github.jparrowsec.cn-1ecc6299db9ec823/mio-0.8.4/src/poll.rs:521] registering event source with poller: token=Token(0), interests=READABLE 
 41 16:15:06 [TRACE] (1) scopetime: [scopetime/src/lib.rs:41] scopetime: 2274 ms [gitui::watcher::RepoWatcher::new] @src/watcher.rs:20           
 40 16:15:06 [TRACE] (1) gitui::app: [src/app.rs:119] open repo at: RefCell { value: Path(".") }                                                 
 39 16:15:06 [TRACE] (2) scopetime: [scopetime/src/lib.rs:41] scopetime: 2 ms [asyncgit::sync::branch::get_branches_info] @asyncgit/src/sync/branch/mod.rs:118
 38 16:15:06 [TRACE] (1) scopetime: [scopetime/src/lib.rs:41] scopetime: 1 ms [asyncgit::sync::commits_info::get_commits_info] @asyncgit/src/sync/commits_info.rs:73
 37 16:15:06 [TRACE] (1) asyncgit::tags: [asyncgit/src/tags.rs:67] request                                                                       
 36 16:15:06 [TRACE] (1) gitui: [src/main.rs:195] app start: 2299 ms                                                                             
 35 16:15:06 [TRACE] (1) gitui::app: [src/app.rs:475] update                                                                                     
 34 16:15:06 [TRACE] (1) scopetime: [scopetime/src/lib.rs:41] scopetime: 0 ms [asyncgit::sync::utils::get_head_repo] @asyncgit/src/sync/utils.rs:82
 33 16:15:06 [TRACE] (1) scopetime: [scopetime/src/lib.rs:41] scopetime: 0 ms [asyncgit::sync::branch::get_branch_name_repo] @asyncgit/src/sync/branch/mod.rs:34
 32 16:15:06 [TRACE] (2) scopetime: [scopetime/src/lib.rs:41] scopetime: 3 ms [asyncgit::sync::tags::get_tags] @asyncgit/src/sync/tags.rs:58     
 31 16:15:06 [TRACE] (1) scopetime: [scopetime/src/lib.rs:41] scopetime: 0 ms [asyncgit::sync::utils::get_head_repo] @asyncgit/src/sync/utils.rs:82
 30 16:15:06 [TRACE] (1) scopetime: [scopetime/src/lib.rs:41] scopetime: 0 ms [asyncgit::sync::branch::get_branch_name_repo] @asyncgit/src/sync/branch/mod.rs:34
 29 16:15:06 [TRACE] (1) scopetime: [scopetime/src/lib.rs:41] scopetime: 0 ms [asyncgit::sync::commits_info::get_commits_info] @asyncgit/src/sync/commits_info.rs:73
 28 16:15:06 [TRACE] (1) asyncgit::tags: [asyncgit/src/tags.rs:67] request                                                                       
 27 16:15:06 [TRACE] (2) scopetime: [scopetime/src/lib.rs:41] scopetime: 2 ms [asyncgit::sync::tags::get_tags] @asyncgit/src/sync/tags.rs:58     
 26 16:15:06 [TRACE] (1) scopetime: [scopetime/src/lib.rs:41] scopetime: 11 ms [gitui::loop] @src/main.rs:218                                    
 25 16:15:06 [TRACE] (1) gitui::app: [src/app.rs:494] update_async: Git(Branches)                                                                
 24 16:15:06 [INFO] branches: 1                                                                                                                  
 23 16:15:06 [TRACE] (1) scopetime: [scopetime/src/lib.rs:41] scopetime: 0 ms [asyncgit::sync::commits_info::get_commits_info] @asyncgit/src/sync/commits_info.rs:73
 22 16:15:06 [TRACE] (1) asyncgit::tags: [asyncgit/src/tags.rs:67] request                                                                       
 21 16:15:06 [TRACE] (2) scopetime: [scopetime/src/lib.rs:41] scopetime: 2 ms [asyncgit::sync::branch::get_branches_info] @asyncgit/src/sync/branch/mod.rs:118
 20 16:15:06 [TRACE] (1) scopetime: [scopetime/src/lib.rs:41] scopetime: 3 ms [gitui::loop] @src/main.rs:218                                     
 19 16:15:06 [TRACE] (1) gitui::app: [src/app.rs:494] update_async: Git(Tags)                                                                    
 18 16:15:06 [TRACE] (1) scopetime: [scopetime/src/lib.rs:41] scopetime: 0 ms [asyncgit::sync::commits_info::get_commits_info] @asyncgit/src/sync/commits_info.rs:73
 17 16:15:06 [TRACE] (1) asyncgit::tags: [asyncgit/src/tags.rs:67] request                                                                       
 16 16:15:06 [TRACE] (1) scopetime: [scopetime/src/lib.rs:41] scopetime: 3 ms [gitui::loop] @src/main.rs:218                                     
 15 16:15:06 [TRACE] (1) gitui::app: [src/app.rs:494] update_async: Git(Tags)                                                                    
 14 16:15:06 [TRACE] (1) scopetime: [scopetime/src/lib.rs:41] scopetime: 0 ms [asyncgit::sync::commits_info::get_commits_info] @asyncgit/src/sync/commits_info.rs:73
 13 16:15:06 [TRACE] (1) asyncgit::tags: [asyncgit/src/tags.rs:67] request                                                                       
 12 16:15:06 [TRACE] (1) scopetime: [scopetime/src/lib.rs:41] scopetime: 3 ms [gitui::loop] @src/main.rs:218                                     
 11 16:15:06 [TRACE] (1) gitui::app: [src/app.rs:494] update_async: Git(Branches)                                                                
 10 16:15:06 [TRACE] (1) scopetime: [scopetime/src/lib.rs:4] scopetime: 1 ms [gitui::loop] @src/main.rs:218                                      
  9 16:15:06 [TRACE] (1) gitui::app: [src/app.rs:494] update_async: Git(Log)                                                                     
  8 16:15:06 [TRACE] (3) scopetime: [scopetime/src/lib.rs:41] scopetime: 40 ms [asyncgit::revlog::async::revlog] @asyncgit/src/revlog.rs:142     
  7 16:15:06 [TRACE] (1) scopetime: [scopetime/src/lib.rs:41] scopetime: 20 ms [asyncgit::sync::commits_info::get_commits_info] @asyncgit/src/sync/commits_info.rs:73
  6 16:15:06 [TRACE] (1) asyncgit::tags: [asyncgit/src/tags.rs:67] request                                                                       
  5 16:15:06 [TRACE] (1) scopetime: [scopetime/src/lib.rs:41] scopetime: 41 ms [gitui::loop] @src/main.rs:218                                    
  4 16:15:06 [TRACE] (1) gitui::app: [src/app.rs:494] update_async: Git(Log)                                                                     
  3 16:15:06 [TRACE] (1) asyncgit::tags: [asyncgit/src/tags.rs:67] request                                                                       
  2 16:15:06 [TRACE] (1) scopetime: [scopetime/src/lib.rs:41] scopetime: 9 ms [gitui::loop] @src/main.rs:218                                     
  1 16:15:08 [DEBUG] (9) gitui::watcher: notify events: 1                                                                                        
45  16:15:08 [DEBUG] (9) gitui::watcher: notify [0]: DebouncedEvent { path: "<my home dir>/Code/gitui/.git/gitui", kind: Any }                                                                                                                                                                                                                                                                                                                                                                                                                                                            
  1 16:15:08 [TRACE] (1) gitui::app: [src/app.rs:475] update                                                                                     
  2 16:15:08 [TRACE] (1) scopetime: [scopetime/src/lib.rs:41] scopetime: 0 ms [asyncgit::sync::utils::get_head_repo] @asyncgit/src/sync/utils.rs:82
  3 16:15:08 [TRACE] (1) scopetime: [scopetime/src/lib.rs:41] scopetime: 0 ms [asyncgit::sync::utils::get_head_repo] @asyncgit/src/sync/utils.rs:82
  4 16:15:08 [TRACE] (1) asyncgit::tags: [asyncgit/src/tags.rs:67] request                                                                       
  5 16:15:08 [TRACE] (1) scopetime: [scopetime/src/lib.rs:41] scopetime: 9 ms [gitui::loop] @src/main.rs:218                                     
  6 16:15:08 [TRACE] (1) gitui::app: [src/app.rs:380] event: Input(Key(KeyEvent { code: Char('q'), modifiers: NONE, kind: Press, state: NONE })) 
  7 16:15:08 [TRACE] (1) scopetime: [scopetime/src/lib.rs:41] scopetime: 7 ms [gitui::loop] @src/main.rs:218

new argument `polling` allows to force watcher to use polling instead of file system events. this should address the issue in #1436 and maybe even #1437

extrawurst · 2022-11-21T17:12:00Z

ok theory confirmed, its the file watcher initialisation - holy moly is that slow.
enjoy recent master: bbcadcb - should fix the problem. please confirm

MartinVincent · 2022-11-21T17:25:45Z

it (following a make install) looks very good, in fact even faster than 0.21.0 :) according to my simple tests!

Thx!

(gitui:3.8.10)  [master:bbcadcb  ] ~/Code/gitui ❯ for i in $(seq 10) ; do time  ~/bin/gitui_startup_test.scp 0.21.0 >/dev/null; done
delta: 0,042
delta: 0,045
delta: 0,043
delta: 0,043
delta: 0,043
delta: 0,042
delta: 0,043
delta: 0,043
delta: 0,043
delta: 0,040
(gitui:3.8.10)  [master:bbcadcb  ] ~/Code/gitui ❯ for i in $(seq 10) ; do time  ~/bin/gitui_startup_test.scp 0.22.1_beta >/dev/null; done
delta: 0,038
delta: 0,037
delta: 0,038
delta: 0,038
delta: 0,034
delta: 0,039
delta: 0,033
delta: 0,035
delta: 0,034
delta: 0,035

extrawurst · 2022-11-21T17:28:19Z

yeah lol I also cleaned up the slight delay that got introduced by #1371 in 92f63d1. so that shaved off a few ms aswell. consider this fixed then! thanks for all the support!

extrawurst · 2022-11-21T17:28:31Z

closed via bbcadcb

new argument `polling` allows to force watcher to use polling instead of file system events. this should address the issue in gitui-org#1436 and maybe even gitui-org#1437

extrawurst added a commit that referenced this issue Nov 21, 2022

threaded watcher creation and arg for config

bbcadcb

new argument `polling` allows to force watcher to use polling instead of file system events. this should address the issue in #1436 and maybe even #1437

extrawurst added the bug Something isn't working label Nov 21, 2022

extrawurst added this to the v0.22.1 milestone Nov 21, 2022

extrawurst mentioned this issue Nov 21, 2022

make git tree file fetch async #734

Closed

extrawurst closed this as completed Nov 21, 2022

MartinVincent closed this as completed Nov 21, 2022

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

v0.22.0 => increased app startup time #1436

v0.22.0 => increased app startup time #1436

MartinVincent commented Nov 19, 2022

extrawurst commented Nov 19, 2022

extrawurst commented Nov 20, 2022

MartinVincent commented Nov 20, 2022

MartinVincent commented Nov 20, 2022 •

edited

Loading

extrawurst commented Nov 20, 2022

extrawurst commented Nov 20, 2022

extrawurst commented Nov 20, 2022

MartinVincent commented Nov 21, 2022

extrawurst commented Nov 21, 2022

MartinVincent commented Nov 21, 2022

numToStr commented Nov 21, 2022 •

edited

Loading

extrawurst commented Nov 21, 2022

numToStr commented Nov 21, 2022

extrawurst commented Nov 21, 2022 •

edited

Loading

MartinVincent commented Nov 21, 2022 •

edited

Loading

extrawurst commented Nov 21, 2022

extrawurst commented Nov 21, 2022

MartinVincent commented Nov 21, 2022 •

edited

Loading

extrawurst commented Nov 21, 2022

MartinVincent commented Nov 21, 2022 •

edited

Loading

extrawurst commented Nov 21, 2022

extrawurst commented Nov 21, 2022 •

edited

Loading

v0.22.0 => increased app startup time #1436

v0.22.0 => increased app startup time #1436

Comments

MartinVincent commented Nov 19, 2022

extrawurst commented Nov 19, 2022

extrawurst commented Nov 20, 2022

MartinVincent commented Nov 20, 2022

MartinVincent commented Nov 20, 2022 • edited Loading

extrawurst commented Nov 20, 2022

extrawurst commented Nov 20, 2022

extrawurst commented Nov 20, 2022

MartinVincent commented Nov 21, 2022

extrawurst commented Nov 21, 2022

MartinVincent commented Nov 21, 2022

numToStr commented Nov 21, 2022 • edited Loading

extrawurst commented Nov 21, 2022

numToStr commented Nov 21, 2022

extrawurst commented Nov 21, 2022 • edited Loading

MartinVincent commented Nov 21, 2022 • edited Loading

extrawurst commented Nov 21, 2022

extrawurst commented Nov 21, 2022

MartinVincent commented Nov 21, 2022 • edited Loading

extrawurst commented Nov 21, 2022

MartinVincent commented Nov 21, 2022 • edited Loading

extrawurst commented Nov 21, 2022

extrawurst commented Nov 21, 2022 • edited Loading

MartinVincent commented Nov 20, 2022 •

edited

Loading

numToStr commented Nov 21, 2022 •

edited

Loading

extrawurst commented Nov 21, 2022 •

edited

Loading

MartinVincent commented Nov 21, 2022 •

edited

Loading

MartinVincent commented Nov 21, 2022 •

edited

Loading

MartinVincent commented Nov 21, 2022 •

edited

Loading

extrawurst commented Nov 21, 2022 •

edited

Loading