nvpy freezing hard when typing intial characters in search on acct with over 1500 notes, makes searching very difficult. #233

wrathofthomas · 2023-10-13T01:02:45Z

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!

yuuki0xff · 2023-10-13T02:32:52Z

Is it a Windows environment?

Poor performance on Windows is a known issue. See #213. I am planning a fix in the next milestone.

yuuki0xff · 2023-10-13T02:43:46Z

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 = true to nvpy.cfg.
Start nvPY.
Perform the search operation several times.
Exit nvPY. nvPY will generate nvpy-profile-*.txt file under the nvpy data directory (Usually %HOMEDRIVE%%HOMEPATH%/.nvpy/).
Send the first 50 lines of nvpy-profile-*.txt to this issue.
Delete use_profiler = true from nvpy.cfg.

wrathofthomas · 2023-10-13T14:08:50Z

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)

yuuki0xff · 2023-10-13T14:52:38Z

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?

wrathofthomas · 2023-10-13T15:22:52Z

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?

yuuki0xff · 2023-10-13T15:33:38Z

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().

nvpy/nvpy/view.py

Lines 547 to 551 in 7fa6ab6

    
           if config.match_regexp: 
        
               for mo in config.match_regexp.finditer(title): 
        
                   start = '{}.{}'.format(line_number, min(mo.start(), title_length - 1)) 
        
                   end = '{}.{}'.format(line_number, min(mo.end(), title_length - 1)) 
        
                   self.text.tag_add('title-highlight', start, end)

nvpy/nvpy/view.py

Lines 570 to 574 in 7fa6ab6

    
           if config.match_regexp: 
        
               for mo in config.match_regexp.finditer(title): 
        
                   start = '{}.{}'.format(line_number, mo.start()) 
        
                   end = '{}.{}'.format(line_number, mo.end()) 
        
                   self.text.tag_add('title-highlight', start, end)

nvpy/nvpy/view.py

Lines 1816 to 1826 in 7fa6ab6

    
           for mo in pat.finditer(t.get('1.0', 'end')): 
        
               # start creating a new tkinter text tag 
        
               tag = 'search-%d' % (len(self.text_tags_search), ) 
        
               t.tag_config(tag, background=self.config.colors.highlight_background) 
        
               # mo.start(), mo.end() or mo.span() in one go 
        
               t.tag_add(tag, '1.0+%dc' % (mo.start(), ), '1.0+%dc' % (mo.end(), )) 
        
               # record the tag name so we can delete it later 
        
               self.text_tags_search.append(tag)

wrathofthomas · 2023-10-13T15:37:24Z

In view.py of ~/.local/pipx/venvs/nvpy/lib/python3.11/site-packages/nvpy? Remove those three quoted sections?

yuuki0xff · 2023-10-13T15:38:29Z

Yes, that's right.

wrathofthomas · 2023-10-13T15:41:33Z

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?

yuuki0xff · 2023-10-13T15:45:59Z

I think that you should keep the highlight process in View.activate_search_string_highlights().

nvpy/nvpy/view.py

Lines 1816 to 1826 in 7fa6ab6

    
           for mo in pat.finditer(t.get('1.0', 'end')): 
        
               # start creating a new tkinter text tag 
        
               tag = 'search-%d' % (len(self.text_tags_search), ) 
        
               t.tag_config(tag, background=self.config.colors.highlight_background) 
        
               # mo.start(), mo.end() or mo.span() in one go 
        
               t.tag_add(tag, '1.0+%dc' % (mo.start(), ), '1.0+%dc' % (mo.end(), )) 
        
               # record the tag name so we can delete it later 
        
               self.text_tags_search.append(tag)

wrathofthomas · 2023-10-13T15:46:18Z

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.

wrathofthomas · 2023-10-13T15:46:50Z

Nice :)

wrathofthomas · 2023-10-13T15:47:32Z

So how to fix the highlighting in the list?

yuuki0xff · 2023-10-13T15:56:29Z

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).

wrathofthomas · 2023-10-13T16:01:21Z

ok! thanks!

yuuki0xff · 2023-10-13T16:57:50Z

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)

wrathofthomas · 2023-10-13T20:33:03Z

Could it be the venv?

yuuki0xff · 2023-10-14T08:56:50Z

Yes. nvPY runs inside a venv managed by pipx.

Note that the nvpy module installed with editable mode because I'm developer.

wrathofthomas · 2023-10-14T16:35:53Z

Would you like me to try to install and run this outside the venv and send you another log?

wrathofthomas · 2023-10-14T17:14:43Z

I cannot figure out how to do this. If you have any guidance let me know. Thanks!

yuuki0xff · 2023-10-14T23:54:08Z

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'>

wrathofthomas · 2023-10-15T18:33:54Z

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

yuuki0xff · 2023-10-16T17:40:33Z

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.

wrathofthomas · 2023-10-17T00:27:33Z

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!

yuuki0xff · 2023-10-17T17:09:40Z

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.

wrathofthomas · 2023-10-22T15:21:27Z

Will give this a try and let you know if I am successful

yuuki0xff self-assigned this Oct 13, 2023

yuuki0xff added duplicate enhancement labels Oct 13, 2023

yuuki0xff added the investigating label Oct 13, 2023

yuuki0xff added this to the v2.4.0 milestone Oct 13, 2023

yuuki0xff removed the investigating label Oct 13, 2023

yuuki0xff removed the duplicate label Oct 16, 2023

yuuki0xff added the investigating label Oct 16, 2023

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

nvpy freezing hard when typing intial characters in search on acct with over 1500 notes, makes searching very difficult. #233

nvpy freezing hard when typing intial characters in search on acct with over 1500 notes, makes searching very difficult. #233

wrathofthomas commented Oct 13, 2023

yuuki0xff commented Oct 13, 2023

yuuki0xff commented Oct 13, 2023

wrathofthomas commented Oct 13, 2023 •

edited by yuuki0xff

Loading

yuuki0xff commented Oct 13, 2023

wrathofthomas commented Oct 13, 2023

yuuki0xff commented Oct 13, 2023

wrathofthomas commented Oct 13, 2023

yuuki0xff commented Oct 13, 2023

wrathofthomas commented Oct 13, 2023

yuuki0xff commented Oct 13, 2023

wrathofthomas commented Oct 13, 2023

wrathofthomas commented Oct 13, 2023

wrathofthomas commented Oct 13, 2023

yuuki0xff commented Oct 13, 2023

wrathofthomas commented Oct 13, 2023

yuuki0xff commented Oct 13, 2023 •

edited

Loading

wrathofthomas commented Oct 13, 2023

yuuki0xff commented Oct 14, 2023

wrathofthomas commented Oct 14, 2023

wrathofthomas commented Oct 14, 2023

yuuki0xff commented Oct 14, 2023

wrathofthomas commented Oct 15, 2023 •

edited by yuuki0xff

Loading

yuuki0xff commented Oct 16, 2023

wrathofthomas commented Oct 17, 2023

yuuki0xff commented Oct 17, 2023

wrathofthomas commented Oct 22, 2023

nvpy freezing hard when typing intial characters in search on acct with over 1500 notes, makes searching very difficult. #233

nvpy freezing hard when typing intial characters in search on acct with over 1500 notes, makes searching very difficult. #233

Comments

wrathofthomas commented Oct 13, 2023

yuuki0xff commented Oct 13, 2023

yuuki0xff commented Oct 13, 2023

wrathofthomas commented Oct 13, 2023 • edited by yuuki0xff Loading

yuuki0xff commented Oct 13, 2023

wrathofthomas commented Oct 13, 2023

yuuki0xff commented Oct 13, 2023

wrathofthomas commented Oct 13, 2023

yuuki0xff commented Oct 13, 2023

wrathofthomas commented Oct 13, 2023

yuuki0xff commented Oct 13, 2023

wrathofthomas commented Oct 13, 2023

wrathofthomas commented Oct 13, 2023

wrathofthomas commented Oct 13, 2023

yuuki0xff commented Oct 13, 2023

wrathofthomas commented Oct 13, 2023

yuuki0xff commented Oct 13, 2023 • edited Loading

wrathofthomas commented Oct 13, 2023

yuuki0xff commented Oct 14, 2023

wrathofthomas commented Oct 14, 2023

wrathofthomas commented Oct 14, 2023

yuuki0xff commented Oct 14, 2023

wrathofthomas commented Oct 15, 2023 • edited by yuuki0xff Loading

yuuki0xff commented Oct 16, 2023

wrathofthomas commented Oct 17, 2023

yuuki0xff commented Oct 17, 2023

wrathofthomas commented Oct 22, 2023

wrathofthomas commented Oct 13, 2023 •

edited by yuuki0xff

Loading

yuuki0xff commented Oct 13, 2023 •

edited

Loading

wrathofthomas commented Oct 15, 2023 •

edited by yuuki0xff

Loading