footnote fontify causing massive slowdown

footnote fontify causing massive slowdown

[Derek Feichtinger]

While diagnosing a server condition, I was listing parts of a system log
via a babel expression. The 130 lines in the babel output are wrapped in
an example block. This block caused massive slowdown of scrolling and
other operations.

Using the emacs profiler I see:

- redisplay_internal (C function) 8232  88%
  - jit-lock-function 8226  88%
   - jit-lock-fontify-now 8226  88%
    - funcall 8226  88%
     - #<compiled 0x1cc274f>                                      8226  88%
      - run-hook-with-args 8226  88%
       - font-lock-fontify-region 8226  88%
        - font-lock-default-fontify-region 8226  88%
         - font-lock-fontify-keywords-region 8226  88%
          - org-activate-footnote-links 8158  87%
           - org-footnote-next-reference-or-definition 8158  87%
            - byte-code 8158  87%
             - org-footnote-at-reference-p 4114  44%
              - org-footnote-in-valid-context-p 4106  44%
               + org-inside-LaTeX-fragment-p 2380  25%
               + org-in-block-p 1563  16%
               + org-in-verbatim-emphasis 159   1%
                 org-at-comment-p 4   0%

Checking for footnote pattern matches (org-footnote-re) in the wrapped 
block, I see that
every line matches based on the very simple and trivial pattern of
number enclosed in angular brackets, so all the process numbers
following the "sshd" in these lines like "sshd[1234]" do match and cause 
load.

#################
     /var/log/secure-20151129:Nov 23 02:25:36 some-host sshd[20089]: 
Rhosts authentication refused for userXYZ: bad ownership or modes for 
home directory.
     /var/log/secure-20151129:Nov 23 02:25:36 some-host sshd[20089]: 
Rhosts authentication refused for userXYZ: bad ownership or modes for 
home directory.
     /var/log/secure-20151129:Nov 23 02:25:41 some-host sshd[20089]: 
pam_ldap: error trying to bind as user "xxxxx" (Invalid credentials)
#################

Since this kind of pattern is so common in logs and 130 lines are really 
not a large number, it makes it hard to use
org for this purpose. Can this be turned off selectively, or can it be
prevented in example blocks?

Using [8.3.2 (8.3.2-37-gd45217-elpaplus @ 
/home/dfeich/.emacs.d/elpa/org-plus-contrib-20151116/)] with GNU Emacs 
24.5.1.

Best regards,
Derek




-- 
Paul Scherrer Institut
Dr. Derek Feichtinger                   Phone:   +41 56 310 47 33
Section Head Scientific Computing       Email: derek.feichtinger@psi.ch
Building/Room No. WHGA/U126
CH-5232 Villigen PSI

footnote fontify causing massive slowdown

[Derek Feichtinger]

While diagnosing a server condition, I was listing parts of a system log
via a babel expression. The 130 lines in the babel output are wrapped in
an example block. This block caused massive slowdown of scrolling and
other operations.

Using the emacs profiler I see:

- redisplay_internal (C function) 8232  88%
 - jit-lock-function 8226  88%
  - jit-lock-fontify-now 8226  88%
   - funcall 8226  88%
    - #<compiled 0x1cc274f>                                      8226  88%
     - run-hook-with-args 8226  88%
      - font-lock-fontify-region 8226  88%
       - font-lock-default-fontify-region 8226  88%
        - font-lock-fontify-keywords-region 8226  88%
         - org-activate-footnote-links 8158  87%
          - org-footnote-next-reference-or-definition 8158  87%
           - byte-code 8158  87%
            - org-footnote-at-reference-p 4114  44%
             - org-footnote-in-valid-context-p 4106  44%
              + org-inside-LaTeX-fragment-p 2380  25%
              + org-in-block-p 1563  16%
              + org-in-verbatim-emphasis 159   1%
                org-at-comment-p 4   0%

Checking for footnote pattern matches (org-footnote-re) in the wrapped
block, I see that
every line matches based on the very simple and trivial pattern of
number enclosed in angular brackets, so all the process numbers
following the "sshd" in these lines like "sshd[1234]" do match and cause load.

#################
    /var/log/secure-20151129:Nov 23 02:25:36 some-host sshd[20089]: Rhosts
authentication refused for userXYZ: bad ownership or modes for home directory.
    /var/log/secure-20151129:Nov 23 02:25:36 some-host sshd[20089]: Rhosts
authentication refused for userXYZ: bad ownership or modes for home directory.
    /var/log/secure-20151129:Nov 23 02:25:41 some-host sshd[20089]:
pam_ldap: error trying to bind as user "xxxxx" (Invalid credentials)
#################

Since this kind of pattern is so common in logs and 130 lines are really not
a large number, it makes it hard to use
org for this purpose. Can this be turned off selectively, or can it be
prevented in example blocks?

Using [8.3.2 (8.3.2-37-gd45217-elpaplus @
/home/dfeich/.emacs.d/elpa/org-plus-contrib-20151116/)] with GNU Emacs 24.5.1.

Best regards,
Derek

Re: footnote fontify causing massive slowdown

[Nicolas Goaziou]

Hello,

Derek Feichtinger <derek.feichtinger@psi.ch> writes:

> While diagnosing a server condition, I was listing parts of a system log
> via a babel expression. The 130 lines in the babel output are wrapped in
> an example block. This block caused massive slowdown of scrolling and
> other operations.
>
> Using the emacs profiler I see:
>
> - redisplay_internal (C function) 8232  88%
>  - jit-lock-function 8226  88%
>   - jit-lock-fontify-now 8226  88%
>    - funcall 8226  88%
>     - #<compiled 0x1cc274f>                                      8226  88%
>      - run-hook-with-args 8226  88%
>       - font-lock-fontify-region 8226  88%
>        - font-lock-default-fontify-region 8226  88%
>         - font-lock-fontify-keywords-region 8226  88%
>          - org-activate-footnote-links 8158  87%
>           - org-footnote-next-reference-or-definition 8158  87%
>            - byte-code 8158  87%
>             - org-footnote-at-reference-p 4114  44%
>              - org-footnote-in-valid-context-p 4106  44%
>               + org-inside-LaTeX-fragment-p 2380  25%
>               + org-in-block-p 1563  16%
>               + org-in-verbatim-emphasis 159   1%
>                 org-at-comment-p 4   0%
>
> Checking for footnote pattern matches (org-footnote-re) in the wrapped
> block, I see that
> every line matches based on the very simple and trivial pattern of
> number enclosed in angular brackets, so all the process numbers
> following the "sshd" in these lines like "sshd[1234]" do match and cause load.
>
> #################
>     /var/log/secure-20151129:Nov 23 02:25:36 some-host sshd[20089]: Rhosts
> authentication refused for userXYZ: bad ownership or modes for home directory.
>     /var/log/secure-20151129:Nov 23 02:25:36 some-host sshd[20089]: Rhosts
> authentication refused for userXYZ: bad ownership or modes for home directory.
>     /var/log/secure-20151129:Nov 23 02:25:41 some-host sshd[20089]:
> pam_ldap: error trying to bind as user "xxxxx" (Invalid credentials)
> #################
>
> Since this kind of pattern is so common in logs and 130 lines are really not
> a large number, it makes it hard to use
> org for this purpose. Can this be turned off selectively, or can it be
> prevented in example blocks?

This is a limitation of our current way to fontify a buffer. Changing it
implies some serious work, which I'd rather spend on switching to
syntax-based (instead of regexp-based) fontification.

However, this report raises an interesting question about footnotes:
should we still support plain (e.g., "[1]") footnotes in Org documents?

The pattern is very common an regularly introduces false positives.
Also, IIRC, it was introduced for non-Org buffers (e.g., in Message mode
buffers), to provide some common features with "footnote.el" library.

I think we could remove this kind of footnotes, and yet preserve
`org-footnote-normalize' to change Org footnotes into these ones, for
foreign documents.

WDYT?


Regards,

-- 
Nicolas Goaziou

Re: footnote fontify causing massive slowdown

[Aaron Ecay]

Hi Nicolas,

2015ko abenudak 5an, Nicolas Goaziou-ek idatzi zuen:
> 
> This is a limitation of our current way to fontify a buffer. Changing it
> implies some serious work, which I'd rather spend on switching to
> syntax-based (instead of regexp-based) fontification.

Indeed.  However, this code was needlessly slow because it failed to
take advantage of short-circuit evaluation.  I pushed a fix in 046310d.

> 
> However, this report raises an interesting question about footnotes:
> should we still support plain (e.g., "[1]") footnotes in Org documents?
> 
> The pattern is very common an regularly introduces false positives.
> Also, IIRC, it was introduced for non-Org buffers (e.g., in Message mode
> buffers), to provide some common features with "footnote.el" library.
> 
> I think we could remove this kind of footnotes, and yet preserve
> `org-footnote-normalize' to change Org footnotes into these ones, for
> foreign documents.
> 
> WDYT?

Do [1]-type footnotes present other performance problems today?  I’d
rather see if simple solutions to those can be effective before going
for a breaking change to syntax.  Then there’s the fact that syntax
fontification (incl. org-elements cache) is going to have such different
performance characteristics I’m not sure we can predict where the
bottlenecks will be.

-- 
Aaron Ecay

Re: footnote fontify causing massive slowdown

[Nicolas Goaziou]

Hello,

Aaron Ecay <aaronecay@gmail.com> writes:

> Indeed.  However, this code was needlessly slow because it failed to
> take advantage of short-circuit evaluation.

According to the profile report, I don't understand the logic of your
patch.

>>>              - org-footnote-in-valid-context-p 4106  44%
>>>               + org-inside-LaTeX-fragment-p 2380  25%
>>>               + org-in-block-p 1563  16%
>>>               + org-in-verbatim-emphasis 159   1%

ISTM that `org-in-block-p' is marginally slower (15%) than
`org-inside-LaTeX-fragment-p' (9%).

Of course, in OP's report, `org-in-block-p' is the test returning early,
so pushing it earlier is faster since you don't call
`org-inside-LaTeX-fragment-p', but this is only a very specific
optimization made at the expense of other cases (and contradicts your
commit message). Am I missing something?

I don't understand either the benefit of adding `not' calls all over the
place. I generally use de Morgan's law the other way and save a few
primcalls.

> Do [1]-type footnotes present other performance problems today?

The main problem of plain footnotes isn't really their performance, but
false positives'. Anytime something looks like a footnote in a buffer,
you get a performance hit. This happens much more often with plain
footnotes than with other footnote types.

Moreover, false positives can introduce not-so-subtle problems during
export (see for example 2c66e40c).

Note that suggesting to not use them (the default value, actually, per
`org-footnote-auto-label') doesn't help, since false positives are the
problem, not real footnotes.

Eventually, removing them doesn't remove any feature to Org. Of course,
this is an incompatible change, and some users will need to update
documents using plain footnotes. We can provide a function for that, and
use `org-lint' to check for obsolete footnotes. The benefit is to avoid
a whole class of problems.


Regards,

-- 
Nicolas Goaziou

Re: footnote fontify causing massive slowdown

[Aaron Ecay]

Hi Nicolas,

2015ko abenudak 5an, Nicolas Goaziou-ek idatzi zuen:
> 
> Hello,
> 
> Aaron Ecay <aaronecay@gmail.com> writes:
> 
>> Indeed.  However, this code was needlessly slow because it failed to
>> take advantage of short-circuit evaluation.
> 
> According to the profile report, I don't understand the logic of your
> patch.
> 
>>>> - org-footnote-in-valid-context-p 4106  44%
>>>> + org-inside-LaTeX-fragment-p 2380  25%
>>>> + org-in-block-p 1563  16%
>>>> + org-in-verbatim-emphasis 159   1%
> 
> ISTM that `org-in-block-p' is marginally slower (15%) than
> `org-inside-LaTeX-fragment-p' (9%).

I’m not sure where 15 and 9 come from.  The way I read the report,
org-footnote-in-valid-context-p takes 44% of the cumulative time, which
is composed of org-inside-LaTeX-fragment-p (25%) + org-in-block-p (16%)
+ other stuff (3%).  So org-inside-LaTeX-fragment-p accounts for >50% of
the time spent in org-footnote-in-valid-context-p.

> 
> Of course, in OP's report, `org-in-block-p' is the test returning early,
> so pushing it earlier is faster since you don't call
> `org-inside-LaTeX-fragment-p', but this is only a very specific
> optimization made at the expense of other cases (and contradicts your
> commit message). Am I missing something?

...no, you’re not missing anything.  I looked at my patch again, and it
seems completely dumb.  I should not write code before finishing my
morning cup of tea.  I reverted in a198d81.

> 
> I don't understand either the benefit of adding `not' calls all over the
> place. I generally use de Morgan's law the other way and save a few
> primcalls.
> 
>> Do [1]-type footnotes present other performance problems today?
> 
> The main problem of plain footnotes isn't really their performance, but
> false positives'. Anytime something looks like a footnote in a buffer,
> you get a performance hit. This happens much more often with plain
> footnotes than with other footnote types.
> 
> Moreover, false positives can introduce not-so-subtle problems during
> export (see for example 2c66e40c).
> 
> Note that suggesting to not use them (the default value, actually, per
> `org-footnote-auto-label') doesn't help, since false positives are the
> problem, not real footnotes.
> 
> Eventually, removing them doesn't remove any feature to Org. Of course,
> this is an incompatible change, and some users will need to update
> documents using plain footnotes. We can provide a function for that, and
> use `org-lint' to check for obsolete footnotes. The benefit is to avoid
> a whole class of problems.

I see.  Eventually it sounds like a good idea, indeed.  Maybe we should
use something a bit stronger than org-lint to warn of the deprecation.
What if opening a document with plain footnotes generated a warning?

Thanks,

-- 
Aaron Ecay

Re: footnote fontify causing massive slowdown

[Alan L Tyree]

On 05/12/15 23:58, Nicolas Goaziou wrote:
> Hello,
>
> Derek Feichtinger <derek.feichtinger@psi.ch> writes:
>
>> While diagnosing a server condition, I was listing parts of a system log
>> via a babel expression. The 130 lines in the babel output are wrapped in
>> an example block. This block caused massive slowdown of scrolling and
>> other operations.
>>
>> Using the emacs profiler I see:
>>
>> - redisplay_internal (C function) 8232  88%
>>   - jit-lock-function 8226  88%
>>    - jit-lock-fontify-now 8226  88%
>>     - funcall 8226  88%
>>      - #<compiled 0x1cc274f>                                      8226  88%
>>       - run-hook-with-args 8226  88%
>>        - font-lock-fontify-region 8226  88%
>>         - font-lock-default-fontify-region 8226  88%
>>          - font-lock-fontify-keywords-region 8226  88%
>>           - org-activate-footnote-links 8158  87%
>>            - org-footnote-next-reference-or-definition 8158  87%
>>             - byte-code 8158  87%
>>              - org-footnote-at-reference-p 4114  44%
>>               - org-footnote-in-valid-context-p 4106  44%
>>                + org-inside-LaTeX-fragment-p 2380  25%
>>                + org-in-block-p 1563  16%
>>                + org-in-verbatim-emphasis 159   1%
>>                  org-at-comment-p 4   0%
>>
>> Checking for footnote pattern matches (org-footnote-re) in the wrapped
>> block, I see that
>> every line matches based on the very simple and trivial pattern of
>> number enclosed in angular brackets, so all the process numbers
>> following the "sshd" in these lines like "sshd[1234]" do match and cause load.
>>
>> #################
>>      /var/log/secure-20151129:Nov 23 02:25:36 some-host sshd[20089]: Rhosts
>> authentication refused for userXYZ: bad ownership or modes for home directory.
>>      /var/log/secure-20151129:Nov 23 02:25:36 some-host sshd[20089]: Rhosts
>> authentication refused for userXYZ: bad ownership or modes for home directory.
>>      /var/log/secure-20151129:Nov 23 02:25:41 some-host sshd[20089]:
>> pam_ldap: error trying to bind as user "xxxxx" (Invalid credentials)
>> #################
>>
>> Since this kind of pattern is so common in logs and 130 lines are really not
>> a large number, it makes it hard to use
>> org for this purpose. Can this be turned off selectively, or can it be
>> prevented in example blocks?
> This is a limitation of our current way to fontify a buffer. Changing it
> implies some serious work, which I'd rather spend on switching to
> syntax-based (instead of regexp-based) fontification.
>
> However, this report raises an interesting question about footnotes:
> should we still support plain (e.g., "[1]") footnotes in Org documents?
>
> The pattern is very common an regularly introduces false positives.
> Also, IIRC, it was introduced for non-Org buffers (e.g., in Message mode
> buffers), to provide some common features with "footnote.el" library.
>
> I think we could remove this kind of footnotes, and yet preserve
> `org-footnote-normalize' to change Org footnotes into these ones, for
> foreign documents.
>
> WDYT?
>
>
> Regards,
>
I would be delighted to see the 'plain' footnote format abolished. I use 
org for writing legal text which often has things like Bank of New South 
Wales v Laing [1954] AC 135. Rasmus helped me with a patch to ignore 
these kinds of references, but they remain a nuisance.

Special case, I know, but +1 for getting rid of the things.

Cheers,
Alan

-- 
Alan L Tyree                    http://www2.austlii.edu.au/~alan
Tel:  04 2748 6206              sip:typhoon@iptel.org

Re: footnote fontify causing massive slowdown

[Matt Lundin]

Alan L Tyree <alantyree@gmail.com> writes:
> I would be delighted to see the 'plain' footnote format abolished. I
> use org for writing legal text which often has things like Bank of New
> South Wales v Laing [1954] AC 135. Rasmus helped me with a patch to
> ignore these kinds of references, but they remain a nuisance.
>
> Special case, I know, but +1 for getting rid of the things.

+1 here as well. A lot of text I clip from the web has numbers in
brackets.

Matt

Re: footnote fontify causing massive slowdown

[Rasmus]

Nicolas Goaziou <mail@nicolasgoaziou.fr> writes:

> However, this report raises an interesting question about footnotes:
> should we still support plain (e.g., "[1]") footnotes in Org documents?
>
> The pattern is very common an regularly introduces false positives.
> Also, IIRC, it was introduced for non-Org buffers (e.g., in Message mode
> buffers), to provide some common features with "footnote.el" library.
>
> I think we could remove this kind of footnotes, and yet preserve
> `org-footnote-normalize' to change Org footnotes into these ones, for
> foreign documents.
>
> WDYT?

I'd be happy to kill [n] style footnotes.  I've had issues with them in
the past.

Rasmus

-- 
Not everything that goes around comes back around, you know

Re: footnote fontify causing massive slowdown

[Samuel Wales]

as with others, i am ok with nixing those [1] footnotes if nobody objects.

on the other hand, i strongly want inline footnotes to work again with
multiple paragraphs, including in fontifying.  i know export is
incompatible with post-8.0 paragraphs and will accept a filter or
something if needed as long as it isn't too kludgy.

Re: footnote fontify causing massive slowdown

[William Denton]

[-- Attachment #1: Type: TEXT/PLAIN, Size: 760 bytes --]

On 5 December 2015, Nicolas Goaziou wrote:

> However, this report raises an interesting question about footnotes:
> should we still support plain (e.g., "[1]") footnotes in Org documents?
>
> The pattern is very common an regularly introduces false positives.
> Also, IIRC, it was introduced for non-Org buffers (e.g., in Message mode
> buffers), to provide some common features with "footnote.el" library.
>
> I think we could remove this kind of footnotes, and yet preserve
> `org-footnote-normalize' to change Org footnotes into these ones, for
> foreign documents.

+1.  The false positives are a common problem for me, and [fn:1] works cleanly 
and clearly.

Bill
-- 
William Denton ↔  Toronto, Canada ↔  https://www.miskatonic.org/

Re: footnote fontify causing massive slowdown

[Thomas S. Dye]

William Denton <wtd@pobox.com> writes:

> On 5 December 2015, Nicolas Goaziou wrote:
>
>> However, this report raises an interesting question about footnotes:
>> should we still support plain (e.g., "[1]") footnotes in Org documents?
>>
>> The pattern is very common an regularly introduces false positives.
>> Also, IIRC, it was introduced for non-Org buffers (e.g., in Message mode
>> buffers), to provide some common features with "footnote.el" library.
>>
>> I think we could remove this kind of footnotes, and yet preserve
>> `org-footnote-normalize' to change Org footnotes into these ones, for
>> foreign documents.
>
> +1.  The false positives are a common problem for me, and [fn:1] works cleanly 
> and clearly.

Same here. +1.

All the best,
Tom

-- 
Thomas S. Dye
http://www.tsdye.com

Re: footnote fontify causing massive slowdown

[Nicolas Goaziou]

Hello,

Aaron Ecay <aaronecay@gmail.com> writes:

> The way I read the report, org-footnote-in-valid-context-p takes 44%
> of the cumulative time, which is composed of
> org-inside-LaTeX-fragment-p (25%) + org-in-block-p (16%) + other stuff
> (3%). So org-inside-LaTeX-fragment-p accounts for >50% of the time
> spent in org-footnote-in-valid-context-p.

Interesting. 

I thought that percents were cumulative, so `org-in-block-p' accounted
for 16% - 1% and `org-inside-LaTeX-fragment-p' 25% - 16% of the total
time.

> I see.  Eventually it sounds like a good idea, indeed.  Maybe we should
> use something a bit stronger than org-lint to warn of the deprecation.
> What if opening a document with plain footnotes generated a warning?

Generate a warning about plain footnotes deprecation ? How do you turn
it off ? Do you require the user to set some variable to a non-nil value
before Org's initialization ? IIRC Magit did that at some point and
I found it annoying.

Note that we cannot turn it off automatically due to false positives
(i.e., we cannot decide if there are obsolete footnotes in the document
or something looking like them and yet perfectly valid in the document).


Regards,

-- 
Nicolas Goaziou

Re: footnote fontify causing massive slowdown

[Nicolas Goaziou]

Hello,

Thomas S. Dye <tsd@tsdye.com> writes:

> William Denton <wtd@pobox.com> writes:
>
>> On 5 December 2015, Nicolas Goaziou wrote:
>>
>>> However, this report raises an interesting question about footnotes:
>>> should we still support plain (e.g., "[1]") footnotes in Org documents?
>>>
>>> The pattern is very common an regularly introduces false positives.
>>> Also, IIRC, it was introduced for non-Org buffers (e.g., in Message mode
>>> buffers), to provide some common features with "footnote.el" library.
>>>
>>> I think we could remove this kind of footnotes, and yet preserve
>>> `org-footnote-normalize' to change Org footnotes into these ones, for
>>> foreign documents.
>>
>> +1.  The false positives are a common problem for me, and [fn:1] works cleanly 
>> and clearly.
>
> Same here. +1.

Thanks for the feedback. I'll send a patch to the ML by the end of the
next week.

Regards,

-- 
Nicolas Goaziou