font-latex extremely slow

[Reiner Steib]

Hi,

I'm editing a 250k LaTeX document. Once in a while, `font-latex' is
getting extremely slow. My impression is that it might be triggered
by jumping around in the file and doing some edition at various
places.

Below is some (bad) result from ELP. Note that this results are on an
AMD Athlon 3500+ which should really be fast enough for font-lock.

[Ralf Angeli]

Post by Reiner Steib
I'm editing a 250k LaTeX document. Once in a while, `font-latex' is
getting extremely slow. My impression is that it might be triggered
by jumping around in the file and doing some edition at various
places.

[...]

Post by Reiner Steib
As I don't know if modifications in my document or changes in
`font-latex' trigger the slow down, I would like to ask if someone
(maybe Ralf) has an idea which revisions of `font-latex' I should
compare.
In other words: Is there a change which might be suspect to slow down
`font-latex-match-*' (especially
`font-latex-match-command-with-arguments') dramatically?

Hm, I made a change in latex.el which could negatively impact
fontification performance:

2005-03-09 Ralf Angeli <***@iwi.uni-sb.de>

* tex.el (TeX-comment-prefix): New function.

* latex.el (LaTeX-current-environment, LaTeX-find-matching-end)
(LaTeX-find-matching-begin): Rather than using the start or end of
a commented region as a boundary, look further for other commented
regions with the same prefix possibly containing an environment
start or end respectively.
(LaTeX-mode-menu): An empty help string is useless and may lead to
an empty tooltip.

Maybe profiling the related LaTeX-* functions besides the font-latex-*
function reveals the culprit?

[Ralf Angeli]

Post by Ralf Angeli

Post by Reiner Steib
I'm editing a 250k LaTeX document. Once in a while, `font-latex' is
getting extremely slow. My impression is that it might be triggered
by jumping around in the file and doing some edition at various
places.

[...]

Post by Reiner Steib
As I don't know if modifications in my document or changes in
`font-latex' trigger the slow down, I would like to ask if someone
(maybe Ralf) has an idea which revisions of `font-latex' I should
compare.
In other words: Is there a change which might be suspect to slow down
`font-latex-match-*' (especially
`font-latex-match-command-with-arguments') dramatically?

Hm, I made a change in latex.el which could negatively impact

What I just wrote was probably total nonsense because the mentioned
patch affected filling and not fontification. D'oh.

Well, anyway. I looked more closely at the profiling results and I
cannot see a significant difference in average execution time for the
functions in concern. But the call count in the cases you describe as
bad is much higher. Did you do exactly the same in exactly the same
time span when you generated the profiling data?

[Reiner Steib]

I looked more closely at the profiling results and I cannot see a
significant difference in average execution time for the functions
in concern. But the call count in the cases you describe as bad is
much higher. Did you do exactly the same in exactly the same time
span when you generated the profiling data?

No, I'm doing some corrections and additions at various places in that
document. This includes jumping around a lot in the document, editing
here and there. I cannot reproduce it. Maybe it is only triggered
when I enter a specific macro argument or environment. When the
problem appears, it doesn't go away until I disable font-lock or
restart the Emacs session.

I forgot to mention that I already noticed this several months ago
(IIRC back in December), but I didn't have time to debug it. And
maybe it is triggered by the document.

I will test some revisions of `font-latex.el'. Maybe I can identify a
specific change. I don't know any details how font-lock works, so
further hints are very welcome.

Bye, Reiner.

[Ralf Angeli]

Post by Reiner Steib
I forgot to mention that I already noticed this several months ago
(IIRC back in December), but I didn't have time to debug it. And
maybe it is triggered by the document.

That's very likely. I have a 350k document here and don't have any
problems with it. Maybe profiling some font-lock-* functions helps to
identify the problem.

Post by Reiner Steib
I will test some revisions of `font-latex.el'. Maybe I can identify a
specific change. I don't know any details how font-lock works, so
further hints are very welcome.

There is a description of how font locking works at the start of
font-lock.el.

[Reiner Steib]

Maybe profiling some font-lock-* functions helps to identify the
problem.

I have added profiling of font-lock. I still couldn't trigger it with
Emacs 21 (see font_latex_21-3_okay_NN.elp in [1]; NN=13,14 including
font-lock profiling). Switching to Emacs CVS, a noticeable slow down
appeared after some minutes of editing (font_latex_Emacs-CVS_21.elp in
[1]; after approx. 5 minutes: 21:05-21:10). Not much later
(font_latex_Emacs-CVS_22.elp in [1]; 21:16), it became extremely slow.
After inserting a SPC, I had to wait around 15 seconds until it is
displayed. :-/

Here are only the first few lines, see [1] for the details.

font_latex_Emacs-CVS_21.elp:

--8<---------------cut here---------------start------------->8---
Function Name Call Count Elapsed Time Average Time
======================================== ========== ============ ============
font-lock-fontify-region 538 16.933772000 0.0314754126
font-lock-default-fontify-region 538 16.887768999 0.0313899052
font-lock-fontify-keywords-region 538 14.968205000 0.0278219423
re-search-forward 138543 4.2191800000 3.045...e-05
font-latex-match-command-with-arguments 36534 3.9586750000 0.0001083559
font-latex-match-reference 13455 1.9381599999 0.0001440475
font-lock-append-text-property 140540 1.9180019999 1.364...e-05
font-latex-match-function 14334 1.6565669999 0.0001155690
font-lock-fontify-syntactically-region 521 1.6261800000 0.0031212667
font-latex-commented-outp 27982 0.6558939999 2.343...e-05
--8<---------------cut here---------------end--------------->8---

font_latex_Emacs-CVS_22.elp:

--8<---------------cut here---------------start------------->8---
Function Name Call Count Elapsed Time Average Time
======================================== ========== ============ ============
font-lock-fontify-region 404 265.28239 0.6566395792
font-lock-default-fontify-region 404 265.27944099 0.6566322797
font-lock-fontify-keywords-region 404 243.64648800 0.6030853663
font-latex-match-command-with-arguments 443965 59.318243999 0.0001336101
re-search-forward 2015961 56.760200000 2.815...e-05
font-latex-match-function 222502 32.803950000 0.0001474321
font-lock-append-text-property 2214326 32.698966999 1.476...e-05
font-latex-match-reference 179086 25.588266999 0.0001428825
font-lock-fontify-syntactically-region 404 17.151850000 0.0424550742
font-latex-find-matching-close 390242 12.066891999 3.092...e-05
font-latex-commented-outp 419038 8.3206519999 1.985...e-05
--8<---------------cut here---------------end--------------->8---

Post by Reiner Steib
I will test some revisions of `font-latex.el'. Maybe I can identify a
specific change.

(I didn't do this upto now.)

Bye, Reiner.

[1] http://theotp1.physik.uni-ulm.de/~ste/comp/emacs/auctex/elp/

[Ralf Angeli]

Post by Reiner Steib
Not much later
(font_latex_Emacs-CVS_22.elp in [1]; 21:16), it became extremely slow.
After inserting a SPC, I had to wait around 15 seconds until it is
displayed. :-/

Hm, did it get better after you typed SPC or something else? I am
asking because jit-lock stealthily fontifies parts of the file not
seen in the current window when Emacs is left idle for
`jit-lock-stealth-time' seconds. But as soon as one carries out some
action, it should stop with this again. Of course it can also be
fontification of the currently visible area which is taking a lot of
processing time.

Post by Reiner Steib
Here are only the first few lines, see [1] for the details.
--8<---------------cut here---------------start------------->8---
Function Name Call Count Elapsed Time Average Time
======================================== ========== ============ ============
font-lock-fontify-region 538 16.933772000 0.0314754126
font-lock-default-fontify-region 538 16.887768999 0.0313899052
font-lock-fontify-keywords-region 538 14.968205000 0.0278219423
re-search-forward 138543 4.2191800000 3.045...e-05

[...]

Post by Reiner Steib
--8<---------------cut here---------------start------------->8---
Function Name Call Count Elapsed Time Average Time
======================================== ========== ============ ============
font-lock-fontify-region 404 265.28239 0.6566395792
font-lock-default-fontify-region 404 265.27944099 0.6566322797
font-lock-fontify-keywords-region 404 243.64648800 0.6030853663
font-latex-match-command-with-arguments 443965 59.318243999 0.0001336101
re-search-forward 2015961 56.760200000 2.815...e-05

Again, this is the pure amount of matched keywords which kicks in.

What you could try to do in order to better debug the problem is
disabling `global-font-lock-mode' and calling
`font-lock-fontify-keywords-region' manually.

[Reiner Steib]

Post by Ralf Angeli

Not much later (font_latex_Emacs-CVS_22.elp in [1]; 21:16), it
became extremely slow. After inserting a SPC, I had to wait around
15 seconds until it is displayed. :-/

Hm, did it get better after you typed SPC or something else?

Not at all. When it happens, Emacs stays unresponsive until I switch
off font-lock. By "unresponsive" I mean, that the insertion and
cursor moves take several seconds until they are visible.

Bye, Reiner.

[Ralf Angeli]

Post by Reiner Steib

Post by Ralf Angeli

Not much later (font_latex_Emacs-CVS_22.elp in [1]; 21:16), it
became extremely slow. After inserting a SPC, I had to wait around
15 seconds until it is displayed. :-/

Hm, did it get better after you typed SPC or something else?

Not at all. When it happens, Emacs stays unresponsive until I switch
off font-lock. By "unresponsive" I mean, that the insertion and
cursor moves take several seconds until they are visible.

Another idea, because font locking just freaked out for me in
preview.dtx: Do you have a construct in your LaTeX source code which
could be interpreted as an opening tag without a closing one? A
quotation mark, a guillemet or stuff like (from preview.dtx)
"\item[|[|]"?