nvpy freezing hard when typing intial characters in search on acct with over 1500 notes, makes searching very difficult.
Opened this issue · 26 comments
As soon as I start to type anything or remove any characters in the search box. It starts searching immediately and nvpy freezes for up to 30s with the rest of the ui being unusable until the search is complete.
The first character is the worst, it freezes until the first character has been "searched", and there is another lesser delay on the second character, and less of a delay but still slow for the third. After about the third character, it speeds up significantly with almost no lag(less to search at that point).
So it takes up to a minute to even type the word "test" in the search box, with the application trying to search again every time a character is typed.
Gstyles or regexp both have this issue.
Pasting a full word or partial word above three characters is much faster, almost immediately gives results. Pasting "test" searches test with no freeze or lag.
Have installed and reinstalled the latest version, deleted notes and done full resync, replaced cfg, etc.
Anything I am missing to make this faster?
I don't remember this being the case a few versions back, and I had a similar volume of notes.
If there is no easy fix, I propose a 1 sec delay to be added after characters start to be modified in the search box, so that by the time nvpy starts to search, there are likely already 3+ characters and no hang up ever begins.
Thanks!
Is it a Windows environment?
Poor performance on Windows is a known issue. See #213. I am planning a fix in the next milestone.
nvpy freezes for up to 30s with the rest of the ui being unusable until the search is complete.
30 seconds!? On my Windows environment, I can use nvPY with 1500+ active notes. The response is slow but doesn't freeze for 30 seconds.
Could you take a performance profile by following the steps below?
- Append
use_profiler = truetonvpy.cfg. - Start nvPY.
- Perform the search operation several times.
- Exit nvPY. nvPY will generate
nvpy-profile-*.txtfile under the nvpy data directory (Usually%HOMEDRIVE%%HOMEPATH%/.nvpy/). - Send the first 50 lines of
nvpy-profile-*.txtto this issue. - Delete
use_profiler = truefromnvpy.cfg.
Thanks for responding! It's not a windows environment. Yes, it can be anywhere from 13-30 seconds per character 1 and <15 for character 2. Deleting characters under the 3 character range takes even more time for some reason.
Here's the log:
583151 function calls (571165 primitive calls) in 51.074 seconds
Ordered by: internal time, cumulative time, call count
ncalls tottime percall cumtime percall filename:lineno(function)
38903/38534 43.534 0.001 43.560 0.001 {method 'call' of '_tkinter.tkapp' objects}
1 4.560 4.560 48.822 48.822 {method 'mainloop' of '_tkinter.tkapp' objects}
1 0.893 0.893 0.893 0.893 {built-in method _tkinter.create}
3672 0.307 0.000 36.024 0.010 /home/garnet/.local/pipx/venvs/nvpy/lib/python3.11/site-packages/nvpy/view.py:515(append)
10 0.087 0.009 43.694 4.369 /home/garnet/.local/pipx/venvs/nvpy/lib/python3.11/site-packages/nvpy/view.py:2099(set_notes)
1789 0.087 0.000 0.087 0.000 /usr/lib/python3.11/json/decoder.py:343(raw_decode)
3672 0.078 0.000 0.078 0.000 {method 'strftime' of 'datetime.date' objects}
7562 0.071 0.000 0.102 0.000 /usr/lib/python3.11/tkinter/__init__.py:1524(_options)
7461 0.070 0.000 0.570 0.000 /usr/lib/python3.11/tkinter/__init__.py:1682(_configure)
39052 0.067 0.000 0.067 0.000 {method 'format' of 'str' objects}
15047 0.067 0.000 0.102 0.000 /usr/lib/python3.11/tkinter/__init__.py:102(_cnfmerge)
3672 0.066 0.000 0.066 0.000 {method 'splitlines' of 'str' objects}
19557 0.065 0.000 34.185 0.002 /usr/lib/python3.11/tkinter/__init__.py:3893(tag_add)
3672 0.060 0.000 0.198 0.000 /home/garnet/.local/pipx/venvs/nvpy/lib/python3.11/site-packages/nvpy/utils.py:54(human_date)
1798 0.059 0.000 0.059 0.000 {built-in method io.open}
10 0.055 0.005 0.114 0.011 /home/garnet/.local/pipx/venvs/nvpy/lib/python3.11/site-packages/nvpy/notes_db.py:538(filter_notes_gstyle)
11193 0.045 0.000 0.571 0.000 /home/garnet/.local/pipx/venvs/nvpy/lib/python3.11/site-packages/nvpy/tk.py:56(insert)
3672 0.040 0.000 0.040 0.000 {built-in method fromtimestamp}
69798 0.040 0.000 0.040 0.000 {method 'get' of 'dict' objects}
9628 0.038 0.000 0.038 0.000 {method 'match' of 're.Pattern' objects}
11193 0.034 0.000 0.526 0.000 /usr/lib/python3.11/tkinter/__init__.py:3806(insert)
1 0.032 0.032 0.412 0.412 /home/garnet/.local/pipx/venvs/nvpy/lib/python3.11/site-packages/nvpy/notes_db.py:300(__init__)
47798 0.032 0.000 0.032 0.000 {built-in method builtins.isinstance}
1789 0.030 0.000 0.030 0.000 {method 'read' of '_io.BufferedReader' objects}
11227/17 0.028 0.000 44.505 2.618 /home/garnet/.local/pipx/venvs/nvpy/lib/python3.11/site-packages/nvpy/tk.py:32(wrapper)
3672 0.025 0.000 0.059 0.000 /home/garnet/.local/pipx/venvs/nvpy/lib/python3.11/site-packages/nvpy/utils.py:26(get_note_title)
5 0.021 0.004 0.030 0.006 /home/garnet/.local/pipx/venvs/nvpy/lib/python3.11/site-packages/nvpy/notes_db.py:822(sync_to_server_threaded)
5 0.021 0.004 0.038 0.008 /home/garnet/.local/pipx/venvs/nvpy/lib/python3.11/site-packages/nvpy/notes_db.py:793(save_threaded)
7426 0.019 0.000 0.563 0.000 /usr/lib/python3.11/tkinter/__init__.py:1695(configure)
1797 0.018 0.000 0.018 0.000 {method '__exit__' of '_io._IOBase' objects}
8945 0.017 0.000 0.017 0.000 /home/garnet/.local/pipx/venvs/nvpy/lib/python3.11/site-packages/nvpy/notes_db.py:1292(need_save)
1789 0.017 0.000 0.164 0.000 /usr/lib/python3.11/json/__init__.py:299(loads)
1789 0.017 0.000 0.118 0.000 /usr/lib/python3.11/json/decoder.py:332(decode)
14969 0.017 0.000 0.017 0.000 {built-in method _tkinter._flatten}
6868 0.015 0.000 0.015 0.000 /home/garnet/.local/pipx/venvs/nvpy/lib/python3.11/site-packages/nvpy/notes_db.py:530(<genexpr>)
1789 0.015 0.000 0.209 0.000 /usr/lib/python3.11/json/__init__.py:274(load)
19567 0.015 0.000 0.015 0.000 {method 'start' of 're.Match' objects}
3683 0.014 0.000 0.284 0.000 /home/garnet/.local/pipx/venvs/nvpy/lib/python3.11/site-packages/nvpy/view.py:656(disable_text)
7352 0.014 0.000 0.019 0.000 /home/garnet/.local/pipx/venvs/nvpy/lib/python3.11/site-packages/nvpy/utils.py:83(note_pinned)
3672 0.014 0.000 0.014 0.000 {built-in method now}
3682 0.014 0.000 0.279 0.000 /home/garnet/.local/pipx/venvs/nvpy/lib/python3.11/site-packages/nvpy/view.py:659(enable_text)
1789 0.014 0.000 0.021 0.000 /usr/lib/python3.11/json/__init__.py:244(detect_encoding)
11016 0.014 0.000 0.041 0.000 /home/garnet/.local/pipx/venvs/nvpy/lib/python3.11/site-packages/nvpy/notes_db.py:149(<genexpr>)
3672 0.013 0.000 0.055 0.000 /home/garnet/.local/pipx/venvs/nvpy/lib/python3.11/site-packages/nvpy/notes_db.py:148(__call__)
4340 0.012 0.000 0.032 0.000 /home/garnet/.local/pipx/venvs/nvpy/lib/python3.11/site-packages/nvpy/notes_db.py:516(_helper_gstyle_mswordmatch)
The part of I am giving attention:
ncalls tottime percall cumtime percall filename:lineno(function)
38903/38534 43.534 0.001 43.560 0.001 {method 'call' of '_tkinter.tkapp' objects}
3672 0.307 0.000 36.024 0.010 /home/garnet/.local/pipx/venvs/nvpy/lib/python3.11/site-packages/nvpy/view.py:515(append)
10 0.087 0.009 43.694 4.369 /home/garnet/.local/pipx/venvs/nvpy/lib/python3.11/site-packages/nvpy/view.py:2099(set_notes)
19557 0.065 0.000 34.185 0.002 /usr/lib/python3.11/tkinter/__init__.py:3893(tag_add)
Tk operation proceeded 39k times, and the tag_add proceeded 20k times in 51 seconds. I suspect that text highlighting causes significant performance down.
@wrathofthomas Are you displaying very long text with nvPY? Do you see a lot of highlights in the notes list when you type a few characters into the search box?
Re displaying long text, I would say no. My notes aren't any longer probably than most people's
Re the highlighting. Yes, nvpy is highlighting the searched character(s) in both the list and the body of the visible note.
How can it turn it off to test?
Thanks for your reply.
How can it turn it off to test?
No option provided to turn off highlighting. It needs to edit the source code.
Just remove for loop that calls tag_add() method in NotesList.append() and View.activate_search_string_highlights().
In view.py of ~/.local/pipx/venvs/nvpy/lib/python3.11/site-packages/nvpy? Remove those three quoted sections?
Yes, that's right.
Yep that's it. It's immediately responsive now. How do we keep the highlighting feature, and avoid the delay? Maybe only highlight in body?
I think that you should keep the highlight process in View.activate_search_string_highlights().
Lines 1816 to 1826 in 7fa6ab6
If i leave lines 1816-1826 in and delete the first to sections. The searching is still immediate with no delays but highlighting is kept in body.
Nice :)
So how to fix the highlighting in the list?
The update process of the Notes List was the cause of nvPY slowdown. Adding highlighting to the Notes List made the performance problem worse.
Plans to fix the root cause are listed in the Ideas to improve performance section of #213 (comment).
ok! thanks!
tag_add is 159x faster, even using 9 years old desktop CPU (Core i5-4460). It suggests that other factors exist.
Your result: tag_add takes 1748 us/call.
ncalls tottime percall cumtime percall filename:lineno(function)
38903/38534 43.534 0.001 43.560 0.001 {method 'call' of '_tkinter.tkapp' objects}
3672 0.307 0.000 36.024 0.010 /home/garnet/.local/pipx/venvs/nvpy/lib/python3.11/site-packages/nvpy/view.py:515(append)
10 0.087 0.009 43.694 4.369 /home/garnet/.local/pipx/venvs/nvpy/lib/python3.11/site-packages/nvpy/view.py:2099(set_notes)
19557 0.065 0.000 34.185 0.002 /usr/lib/python3.11/tkinter/__init__.py:3893(tag_add)
My result: tag_add takes 11 us/call.
ncalls tottime percall cumtime percall filename:lineno(function)
216481/184862 3.613 0.000 3.649 0.000 {method 'call' of '_tkinter.tkapp' objects}
10877 0.319 0.000 1.987 0.000 /home/yuuki/repo/github.com/cpbotha/nvpy/nvpy/view.py:515(append)
7 0.086 0.012 2.223 0.318 /home/yuuki/repo/github.com/cpbotha/nvpy/nvpy/view.py:2099(set_notes)
106991 0.065 0.000 1.167 0.000 /usr/lib/python3.11/tkinter/__init__.py:3892(tag_add)
Could it be the venv?
Yes. nvPY runs inside a venv managed by pipx.
Note that the nvpy module installed with editable mode because I'm developer.
Would you like me to try to install and run this outside the venv and send you another log?
I cannot figure out how to do this. If you have any guidance let me know. Thanks!
Are the Python loads the Tkinter module from the system global area? The Tkinter module is part of the Python Standard Library. So, it should not be affected by venv/pipx.
You can check it with the command below:
$ ( . ~/.local/pipx/venvs/nvpy/bin/activate && python3 )
Python 3.11.6 (main, Oct 8 2023, 05:06:43) [GCC 13.2.0] on linux
Type "help", "copyright", "credits" or "license" for more information.
>>> import tkinter, _tkinter
>>> tkinter
<module 'tkinter' from '/usr/lib/python3.11/tkinter/__init__.py'>
>>> _tkinter
<module '_tkinter' from '/usr/lib/python3.11/lib-dynload/_tkinter.cpython-311-x86_64-linux-gnu.so'>
This is what I got.
>>> tkinter
<module 'tkinter' from '/usr/lib/python3.11/tkinter/__init__.py'>
>>> _tkinter
<module '_tkinter' from '/usr/lib/python3.11/lib-dynload/_tkinter.cpython-311-x86_64-linux-gnu.so'>
Looks the same as yours
The location that makes tag_add() slow is the UI library (_tkinter, libtk, and libtcl), or further lower layers. We will need to narrow down the suspect area with perf.
A quick check in my debian environment gave me harsh results. The reason is that libtk does not have debugging symbols and most lines were displayed with hexadecimal addresses. You may need to build libtk and libtcl with the -g compile option.
I am not sure how to build libtk and libtcl with the -g compile option, but happy to do it if you give me some instructions!
See https://github.com/cpbotha/nvpy/blob/master/docs/ucs-4.rst. This documentation was written 3 years ago for other purpose, but it will still be helpful.
The documentation describes build procedure for older version. You are better off building the latest version. The procedure will be almost the same.
Build artifacts will be placed on /opt/nvpy/. The LD_LIBRARY_PATH environment variable is probably required to start the self-built python.
Will give this a try and let you know if I am successful