Highlighting in REPL (performance)

[timlod]

Hi,
I've been using emacs-tree-sitter for Python highlighting for a couple of months now, and am very happy with it - thanks!
I develop a lot with org-babel and emacs-jupyter, keeping an org-file and REPL open side-by-side, sending code back and forth.
I use the following to get tree-sitter highlighting in the REPL:

(add-to-list 'tree-sitter-major-mode-language-alist '(jupyter-repl-mode . python))
(add-to-list 'tree-sitter-major-mode-language-alist '(inferior-python-mode . python))
(add-hook 'tree-sitter-after-on-hook #'tree-sitter-hl-mode)

I notice that as the REPL buffer grows in length, everything slows down proportionally, the reason for which is tree-sitter. Obviously only a fraction of the output in the REPL is actually code that can be parsed and should be semantically highlighted (although I don't mind the highlighting that is produced even for output).

Occasionally clearing the buffer helps, but would there be an option to make this more performant?

[shackra]

keeping an org-file and REPL open side-by-side

It is known that org-mode highlights works by opening a hidden buffer, pasting the code there, and getting back the text with the highlights (this comes from the Q&A at EmacsConf about tree-sitter) so it is bound to get slower the more you add to it.

I think the workaround for this is to turn off emacs-tree-sitter on your org-mode file. The solution to the performance problem is having org-mode integrate emacs-tree-sitter for their syntax highlight.

[timlod]

Actually the issue is less with org-mode, and more with the REPL.
The org files are fast enough, there is not that much code in them. You could reproduce this without using org-mode at all.
The REPL session has lots of output, and executes a lot more code than is finally written to the org file. Since I hooked tree-sitter to the REPL-mode, I think tree-sitter tries to parse the entire buffer as Python, which must slow it down. It would help already if I could somehow distinguish code from output and parse only that, perhaps occasionally clearing the buffer.

[ubolonton]

This is an interesting use of tree-sitter-hl!

In theory, it should only re-parse the parts that have changed. Maybe jupyter-repl-mode or inferior-python-mode are doing something special with text changes.

Does it happen when you navigate around the buffer, when you type something, or when you send the code to the buffer?

What are the minor modes enabled in the REPL buffer?

Is it easily reproducible with some Python fragments? For example, would it be enough to repeatedly paste a large piece of Python code?

If not, there are several things you can try to troubleshoot it yourself:

1. M-x profiler-start, use it for a while, M-x profiler-stop.
2. Trace the parsing and highlighting functions:

   ;; To see whether it parses from scratch too often (last arg is nil).
   (trace-function #'tsc-parse-chunks)
   
   ;; To see whether it parses incrementally, but with regions that are
   ;; too large (the difference between 3rd and 4th args).
   (trace-function #'tsc-edit-tree)
   
   ;; To see whether it highlights regions that are too large.
   (trace-function #'tree-sitter-hl--highlight-region)

3. Add logging advices to parsing and highlighting functions, if the above is too noisy:

   (define-advice tsc-parse-chunks (:before (_parser _input_fn old-tree) log-full-parse)
     (unless old-tree
       (message "[%s] tsc-parse-chunks full" (buffer-name))))
   
   (define-advice tsc-edit-tree (:before (_tree _beg-byte old-end-byte new-end-byte &rest _) log-edit-size)
     (message "[%s] tsc-edit-tree %s %s" (buffer-name) (- old-end-byte beg-byte) (- new-end-byte beg-byte)))
   
   (define-advice tree-sitter-hl--highlight-region (:before (beg end &rest _) log-hl-size)
     (message "[%s] tree-sitter-hl--highlight-region %s" (buffer-name) (- end beg)))

[timlod]

Thanks for the detailed response! I do like the fact that in theory, I can get great syntax highlighting inside the Jupyter REPL with just a hook - and actually bypass a font-lock bug with emacs-jupyter in the process (emacs-jupyter/jupyter#219) [this issue has a fix that disables traditional font-lock in the REPL buffer, but ts brings it back better].

I have the following modes enabled:

Auto-Compression Auto-Encryption Beacon Column-Number Company Counsel Eldoc
Electric-Indent File-Name-Shadow Font-Lock Global-Eldoc Global-Flycheck
Global-Font-Lock Global-Git-Commit Global-Hl-Line Global-Tree-Sitter
Global-Visual-Line Ivy Ivy-Rich Jupyter-Repl-Interaction
Jupyter-Repl-Persistent Line-Number Magit-Auto-Revert Mouse-Wheel
Override-Global Pdf-Occur-Global Projectile Savehist Shell-Dirtrack Show-Paren
Smartparens Smartparens-Global Transient-Mark Tree-Sitter Tree-Sitter-Hl
Visual-Line Which-Key Winner

That's a lot, but I can isolate the slowdown to tree-sitter.

I just did some more checks, and find that so far I can actually only reproduce this with Jupyter-REPL when dealing with large pandas DataFrames.
To reproduce, I load a simply load a big DataFrame and return it, ie.:

First, separately:

import pandas as pd
df = pd.read_csv("many_rows.csv")

Now:

df

Every time I execute df again, displaying the output takes longer.
After doing this a couple of times, even simple things like python 1+1 will display with delay. Turning tree-sitter-mode off makes it fast again.

I think the lag mainly accumulates when my functions/executions return DataFrame output. (Note that tree-sitter does not actually highlight the output in the Jupyter REPL, just the code)

The behaviour is different in the normal inferior Python shell: executing the code is instantaneous, tree-sitter highlights the output as if it was Python code, and repeating this many times slows down that buffer in general. (vs. just the apparent execution inside Jupyter-REPL). Again though, turning tree-sitter off makes the buffer speedy again.

I don't have time to trace this myself right now, but hope to get to that still this week.

[timlod]

Hi, sorry it took me a long time to get to this! I've done some profiling now with the code from above (making a large pandas dataframe and repeatedly printing it).

I believe the main problem is that tree-sitter-do-parse is called many times. Here a chunk of the profiler report:

- jupyter-repl-insert-prompt                 232  15%
    - tree-sitter--after-change                 156  10%
        - tree-sitter--do-parse                    156  10%

Note that there are many (intermediate?) actions done by the jupyter REPL that cause tree-sitter to parse:

Almost every jupyter-repl call there leads to a parse (I didn't unfold everything, but you get the gist).

The trace of parse-chunks (trace-function #'tsc-parse-chunks) resulted in 16 individual outputs (I'm not familiar with tracing so I may not properly describe this). 8 when I send press RET to execute the line which will result in printing the dataframe, and another 8 when the dataframe has been printed:

1 -> (tsc-parse-chunks #<user-ptr ptr=0x5606bb9feee0 finalizer=0x7fa35c71a600> tsc--buffer-input #<user-ptr ptr=0x5606c53039e0 finalizer=0x7fa35c71a910>)
1 <- tsc-parse-chunks: #<user-ptr ptr=0x5606b7726ef0 finalizer=0x7fa35c71a910>

Tracing the edit tree does the same (16 outputs), with output like this:

1 -> (tsc-edit-tree #<user-ptr ptr=0x5606b8b927d0 finalizer=0x7fa35c71a910> 42295 42295 42296 #1=(794 . 58) #1# (795 . 0))
1 <- tsc-edit-tree: nil

The highlight-region trace has output such as this, again many entries:

1 -> (tree-sitter-hl--highlight-region 54381 54439 nil)
1 <- tree-sitter-hl--highlight-region: (jit-lock-bounds 54282 . 54609)

Other than the profile report, which leads me to believe that too many REPL actions trigger re-parsing, I don't know how to interpret the output.

[ubolonton]

I believe the main problem is that tree-sitter-do-parse is called many times.

Yes, it can be a problem. It also depends on whether these parses are from-scratch or incremental (and if incremental, whether the region to re-parse is too large). The third approach of advising the parsing and highlighting functions would help getting more data on this.

Here a chunk of the profiler report:

- jupyter-repl-insert-prompt                 232  15%
    - tree-sitter--after-change                 156  10%
        - tree-sitter--do-parse                    156  10%

Would it be possible for you to copy the whole profiler report, as text?

making a large pandas dataframe and repeatedly printing it

How large should this be? If you have a CSV file, I can try reproducing this myself.

[timlod]

I will do this soon and also prepare a test case with which you can reproduce the issue!

[timlod]

Here's the full profiler report:
https://gist.github.com/timlod/6111d2f96357f55b1d2cc1976ac9740f

The advice output is:

[*jupyter-repl[python 3.8.6]-env*] tree-sitter-hl--highlight-region 3
Error during redisplay: (jit-lock-function 53070) signaled (wrong-type-argument number-or-marker-p nil)
[*jupyter-repl[python 3.8.6]-env*] tree-sitter-hl--highlight-region 500 [7 times]
[*jupyter-repl[python 3.8.6]-env*] tree-sitter-hl--highlight-region 203

Now, to reproduce, you can use the following:

1. Open http://download.geonames.org/export/dump/countryInfo.txt
2. Copy all text starting at ISO ISO3 ISO-Numeric fips ... (do not include the leading # on that line) and write it to a file, e.g. test.tsv
3. Open a REPL and import pandas as pd
4. Load the file as df = pd.read_table("test.tsv")
5. Just display df many times (just type df + RET, maybe 20 or so times)

You should notice the REPL slowing down - at first you may see no delay, later the cell indicator on the left will show a brief [*] before displaying. The slowdown is starker with bigger and varied dataframes, but you should be able to notice it with this test case.

Let me know if this helps!

[ubolonton]

Thanks, I'll check it out.