bug#45898: 27.1; wedged in redisplay again

[Eli Zaretskii]

> Cc: larsi@gnus.org, Emacs-hacker2018@jovi.net, 45898@debbugs.gnu.org
> Date: Tue, 14 Jun 2022 15:45:36 +0300
> From: Eli Zaretskii <eliz@gnu.org>
> 
> > Date: Tue, 14 Jun 2022 10:40:47 +1200
> > From: Phil Sainty <psainty@orcon.net.nz>
> > Cc: Lars Ingebrigtsen <larsi@gnus.org>, Emacs-hacker2018@jovi.net,
> >  45898@debbugs.gnu.org
> > 
> > My standard example is this file:
> > https://github.com/Wilfred/ReVo-utilities/blob/a4bdc40dd2656c496defc461fc19c403c8306d9f/revo-export/dictionary.json?raw=true
> > 
> > and which is ~19MB in a single line of JSON (which normally freezes
> > Emacs for several minutes on quite fast hardware by simply visiting the
> > file), and which comes from this question:
> > https://emacs.stackexchange.com/questions/598/how-do-i-prevent-extremely-long-lines-making-emacs-slow
> > 
> > I've also used cut-down versions of that file in testing.  I'm attaching
> > a ~300K extract from that which is more than enough to make things 
> > painful
> > at the end of the line (or slow-yet-manageable with so-long enabled).
> > 
> > And here's an XML file of similar size and effect:
> > wget -O long-line.xml 
> > https://updates.drupal.org/release-history/drupal/current
> 
> Thanks, this is very useful.

As I keep working on this, I find several surprising reasons for slow
redisplay, some of which are almost entirely unrelated to display code
per se.

One surprising finding is that sometimes syntactic fontifications
(triggered via jit-lock.el as part of rendering the buffer) seem to
run amok: jit-lock asks the mode's fontification to fontify a
1500-character block, but that results in parse-partial-sexp being
called to parse the entire humongous file, BOB to EOB.  I attach below
a backtrace where I captured one such situation, when trying to
display the 19MB single-line JSON file mentioned above.  As you see,
this happens on the very first entry to the display code, when Emacs
needs to figure out the face to use for the very first character of
the file.  The data shows that jit-lock asked for fontification of
buffer positions 1..1501, but parse-partial-sexp was (eventually)
called for the entire buffer, positions 1..18922366.

Adding Stefan to the CC list.

Stefan, any idea why would js.el's syntactic fontifications cause this
exceptional situation?  (I know how to avoid wedging Emacs even in
this pathological case, and already have code to do that, but I think
we should try to avoid such situations wherever we can regardless.)

Here's the backtrace I promised.  It can easily be obtained by setting
inside scan_sexps_forward a breakpoint conditioned on FROM being a
small value (I used "from < 1000") and END being a very large value (I
used "and > 18000000").

    Thread 1 hit Breakpoint 2, scan_sexps_forward (state=0x827598, from=1, 
from_byte=1, end=18922366, targetdepth=-9223372036854775808, stopbefore=false, 
commentstop=-1) at syntax.c:3181
    3181      struct level *curlevel = levelstart;
    (gdb) bt
    #0  scan_sexps_forward (state=0x827598, from=1, from_byte=1, end=18922366,
        targetdepth=-9223372036854775808, stopbefore=false, commentstop=-1)
        at syntax.c:3181
    #1  0x012e3903 in Fparse_partial_sexp (from=make_fixnum(1),
        to=make_fixnum(18922366), targetdepth=XIL(0), stopbefore=XIL(0),
        oldstate=XIL(0xc00000000821af80), commentstop=XIL(0xf3f0))
        at syntax.c:3604
    #2  0x0127209c in eval_sub (form=XIL(0xc000000007a2aae0)) at eval.c:2475
    #3  0x01269e91 in Fsetq (args=XIL(0xc000000007a2aad0)) at eval.c:498
    #4  0x012719dc in eval_sub (form=XIL(0xc000000007a2aac0)) at eval.c:2409
    #5  0x01269b6d in Fprogn (body=XIL(0)) at eval.c:451
    #6  0x01269bbd in prog_ignore (body=XIL(0xc000000007a2ab90)) at eval.c:462
    #7  0x0126cb48 in Fwhile (args=XIL(0xc000000007a30cb0)) at eval.c:1058
    #8  0x012719dc in eval_sub (form=XIL(0xc000000007a30ca0)) at eval.c:2409
    #9  0x01269b6d in Fprogn (body=XIL(0)) at eval.c:451
    #10 0x0126ca4d in Flet (args=XIL(0xc000000007a30e00)) at eval.c:1037
    #11 0x012719dc in eval_sub (form=XIL(0xc000000007a30e10)) at eval.c:2409
    #12 0x01269b6d in Fprogn (body=XIL(0)) at eval.c:451
    #13 0x012719dc in eval_sub (form=XIL(0xc000000007a2a1d0)) at eval.c:2409
    #14 0x0126d5f1 in Funwind_protect (args=XIL(0xc000000007a30e40))
        at eval.c:1312
    #15 0x012719dc in eval_sub (form=XIL(0xc000000007a30e30)) at eval.c:2409
    #16 0x01269b6d in Fprogn (body=XIL(0)) at eval.c:451
    #17 0x0126ca4d in Flet (args=XIL(0xc000000007a30f00)) at eval.c:1037
    #18 0x012719dc in eval_sub (form=XIL(0xc000000007a30f10)) at eval.c:2409
    #19 0x01269b6d in Fprogn (body=XIL(0)) at eval.c:451
    #20 0x012751f5 in funcall_lambda (fun=XIL(0xc000000007a30fc0), nargs=3,
        arg_vector=0x828570) at eval.c:3192
    #21 0x012748ac in apply_lambda (fun=XIL(0xc000000007a30fd0),
        args=XIL(0xc000000007a1a420), count=1408) at eval.c:3062
    #22 0x01272876 in eval_sub (form=XIL(0xc000000007a1a410)) at eval.c:2546
    #23 0x01269b6d in Fprogn (body=XIL(0)) at eval.c:451
    #24 0x0126987e in Fif (args=XIL(0xc0000000079dada0)) at eval.c:407
    #25 0x012719dc in eval_sub (form=XIL(0xc0000000079dadb0)) at eval.c:2409
    #26 0x01269b6d in Fprogn (body=XIL(0xc0000000079da950)) at eval.c:451
    #27 0x012719dc in eval_sub (form=XIL(0xc0000000079db060)) at eval.c:2409
    #28 0x0126d5f1 in Funwind_protect (args=XIL(0xc0000000079da980))
        at eval.c:1312
    #29 0x012719dc in eval_sub (form=XIL(0xc0000000079da970)) at eval.c:2409
    #30 0x01269b6d in Fprogn (body=XIL(0)) at eval.c:451
    #31 0x0126ca4d in Flet (args=XIL(0xc0000000079daa40)) at eval.c:1037
    #32 0x012719dc in eval_sub (form=XIL(0xc0000000079daa50)) at eval.c:2409
    #33 0x01269b6d in Fprogn (body=XIL(0)) at eval.c:451
    #34 0x012719dc in eval_sub (form=XIL(0xc0000000079daa60)) at eval.c:2409
    #35 0x0126d5f1 in Funwind_protect (args=XIL(0xc0000000079daa90))
        at eval.c:1312
    #36 0x012719dc in eval_sub (form=XIL(0xc0000000079daa80)) at eval.c:2409
    #37 0x01269b6d in Fprogn (body=XIL(0)) at eval.c:451
    #38 0x0126c3b6 in FletX (args=XIL(0xc0000000079da470)) at eval.c:969
    #39 0x012719dc in eval_sub (form=XIL(0xc0000000079da480)) at eval.c:2409
    #40 0x01269b6d in Fprogn (body=XIL(0)) at eval.c:451
    #41 0x0126ca4d in Flet (args=XIL(0xc0000000079da4a0)) at eval.c:1037
    #42 0x012719dc in eval_sub (form=XIL(0xc0000000079da4b0)) at eval.c:2409
    #43 0x01269b6d in Fprogn (body=XIL(0)) at eval.c:451
    #44 0x012751f5 in funcall_lambda (fun=XIL(0xc0000000079da550), nargs=3,
        arg_vector=0x829988) at eval.c:3192
    #45 0x01273da9 in funcall_general (fun=XIL(0xc0000000079da560), numargs=3,
        args=0x829988) at eval.c:2915
    #46 0x01273f6e in Ffuncall (nargs=4, args=0x829980) at eval.c:2953
    #47 0x01271c16 in eval_sub (form=XIL(0xc0000000067e6790)) at eval.c:2428
    #48 0x01269b6d in Fprogn (body=XIL(0)) at eval.c:451
    #49 0x0125cbc0 in Fsave_restriction (body=XIL(0xc0000000067e66d0))
        at editfns.c:2826
    #50 0x012719dc in eval_sub (form=XIL(0xc0000000067e66c0)) at eval.c:2409
    #51 0x01269b6d in Fprogn (body=XIL(0)) at eval.c:451
    #52 0x012751f5 in funcall_lambda (fun=XIL(0xc0000000067e6070), nargs=2,
        arg_vector=0x6870230) at eval.c:3192
    #53 0x01273da9 in funcall_general (fun=XIL(0xc0000000067e6080), numargs=2,
        args=0x6870230) at eval.c:2915
    #54 0x012e6f83 in exec_byte_code (fun=XIL(0xa000000008202898),
        args_template=257, nargs=1, args=0x68701d0) at bytecode.c:811
    #55 0x012746fd in fetch_and_exec_byte_code (fun=XIL(0xa000000008202898),
        args_template=257, nargs=1, args=0x68701c8) at eval.c:3040
    #56 0x01274c5c in funcall_lambda (fun=XIL(0xa000000008202898), nargs=1,
        arg_vector=0x68701c8) at eval.c:3112
    #57 0x01273c12 in funcall_general (fun=XIL(0xa000000008202898), numargs=1,
        args=0x68701c8) at eval.c:2903
    #58 0x01273f6e in Ffuncall (nargs=2, args=0x68701c0) at eval.c:2953
    #59 0x0127305a in run_hook_wrapped_funcall (nargs=2, args=0x68701c0)
        at eval.c:2731
    #60 0x01273511 in run_hook_with_args (nargs=2, args=0x68701c0,
        funcall=0x1273012 <run_hook_wrapped_funcall>) at eval.c:2812
    #61 0x012730a9 in Frun_hook_wrapped (nargs=2, args=0x68701c0) at eval.c:2746
    #62 0x012745ae in funcall_subr (subr=0x1745e40 <Srun_hook_wrapped>,
        numargs=2, args=0x68701c0) at eval.c:3018
    #63 0x012e6f4f in exec_byte_code (fun=XIL(0xa000000005db0e54),
        args_template=514, nargs=2, args=0x68700f8) at bytecode.c:809
    #64 0x012746fd in fetch_and_exec_byte_code (fun=XIL(0xa000000005db0824),
        args_template=257, nargs=1, args=0x82acb8) at eval.c:3040
    #65 0x01274c5c in funcall_lambda (fun=XIL(0xa000000005db0824), nargs=1,
        arg_vector=0x82acb8) at eval.c:3112
    #66 0x01273c12 in funcall_general (fun=XIL(0xa000000005db0824), numargs=1,
        args=0x82acb8) at eval.c:2903
    #67 0x01273f6e in Ffuncall (nargs=2, args=0x82acb0) at eval.c:2953
    #68 0x0126e681 in internal_condition_case_n (bfun=0x1273e4b <Ffuncall>,
        nargs=2, args=0x82acb0, handlers=XIL(0x30),
        hfun=0x1042523 <safe_eval_handler>) at eval.c:1565
    #69 0x01042756 in safe__call (inhibit_quit=false, nargs=2,
        func=XIL(0x45233b4), ap=0x82ad74 "") at xdisp.c:3015
    #70 0x010427cf in safe_call (nargs=2, func=XIL(0x45233b4)) at xdisp.c:3030
    #71 0x01042823 in safe_call1 (fn=XIL(0x45233b4), arg=make_fixnum(1))
        at xdisp.c:3041
    #72 0x01046576 in handle_fontified_prop (it=0x82aff8) at xdisp.c:4361
    #73 0x01044e1d in handle_stop (it=0x82aff8) at xdisp.c:3877
    #74 0x01051a36 in reseat (it=0x82aff8, pos=..., force_p=true) at 
xdisp.c:7338
    #75 0x01044081 in init_iterator (it=0x82aff8, w=0x75cff98, charpos=1,
        bytepos=1, row=0x6813110, base_face_id=DEFAULT_FACE_ID) at xdisp.c:3478
    #76 0x01044119 in start_display (it=0x82aff8, w=0x75cff98, pos=...)
        at xdisp.c:3494
    #77 0x0107b6fb in try_window (window=XIL(0xa0000000075cff98), pos=...,
        flags=1) at xdisp.c:20158
    #78 0x0107836d in redisplay_window (window=XIL(0xa0000000075cff98),
        just_this_one_p=false) at xdisp.c:19571
    #79 0x0106f9b9 in redisplay_window_0 (window=XIL(0xa0000000075cff98))
        at xdisp.c:17157
    #80 0x0126e491 in internal_condition_case_1 (
        bfun=0x106f961 <redisplay_window_0>, arg=XIL(0xa0000000075cff98),
        handlers=XIL(0xc0000000060fffec), hfun=0x106f91e 
<redisplay_window_error>)      at eval.c:1509
    #81 0x0106f8e0 in redisplay_windows (window=XIL(0xa0000000075cff98))
        at xdisp.c:17137
    #82 0x0106e0e3 in redisplay_internal () at xdisp.c:16599
    #83 0x0106b8a5 in redisplay () at xdisp.c:15803
    #84 0x01171aa1 in read_char (commandflag=1, map=XIL(0xc0000000081e43c0),
        prev_event=XIL(0), used_mouse_menu=0x82f45f, end_time=0x0)
        at keyboard.c:2587
    #85 0x0118b944 in read_key_sequence (keybuf=0x82f730, prompt=XIL(0),
        dont_downcase_last=false, can_return_switch_frame=true,
        fix_current_buffer=true, prevent_redisplay=false) at keyboard.c:9970
    #86 0x0116d527 in command_loop_1 () at keyboard.c:1391
    #87 0x0126e3a7 in internal_condition_case (bfun=0x116cdfc <command_loop_1>,
        handlers=XIL(0x90), hfun=0x116bdca <cmd_error>) at eval.c:1485
    #88 0x0116c869 in command_loop_2 (handlers=XIL(0x90)) at keyboard.c:1132
    #89 0x0126d22e in internal_catch (tag=XIL(0xfdb0),
        func=0x116c832 <command_loop_2>, arg=XIL(0x90)) at eval.c:1208
    #90 0x0116c7d4 in command_loop () at keyboard.c:1110
    #91 0x0116b82a in recursive_edit_1 () at keyboard.c:719
    #92 0x0116bac8 in Frecursive_edit () at keyboard.c:802
    #93 0x01166a32 in main (argc=2, argv=0xa42910) at emacs.c:2511

    Lisp Backtrace:
    "parse-partial-sexp" (0x8276a0)
    "setq" (0x8278f0)
    "while" (0x827b30)
    "let" (0x827dd0)
    "progn" (0x827f90)
    "unwind-protect" (0x828150)
    "let" (0x8283e0)
    "font-lock-fontify-syntactically-region" (0x828570)
    "if" (0x8288c0)
    "progn" (0x828a80)
    "unwind-protect" (0x828c40)
    "let" (0x828ed0)
    "progn" (0x829090)
    "unwind-protect" (0x829250)
    "let*" (0x8294a0)
    "let" (0x829730)
    "font-lock-default-fontify-region" (0x829988)
    "funcall" (0x829980)
    "save-restriction" (0x829c40)
    "font-lock-fontify-region" (0x6870230)
    0x8202898 PVEC_COMPILED
    "run-hook-wrapped" (0x68701c0)
    "jit-lock--run-functions" (0x68700e8)
    "jit-lock-fontify-now" (0x6870048)
    "jit-lock-function" (0x82acb8)
    "redisplay_internal (C function)" (0x0)
    (gdb) fr 46
    #46 0x01273f6e in Ffuncall (nargs=4, args=0x829980) at eval.c:2953
    2953      Lisp_Object val = funcall_general (args[0], nargs - 1, args + 1);
    (gdb) p args[0]
    $1 = XIL(0x471ed74)
    (gdb) xtype
    Lisp_Symbol
    (gdb) xsym
    xsymbol      xsymname     xsymwithpos
    (gdb) xsymbol
    $2 = (struct Lisp_Symbol *) 0x5fac1b4
    "font-lock-default-fontify-region"
    (gdb) p args[1]
    $3 = make_fixnum(1)
    (gdb) p args[2]
    $4 = make_fixnum(1501)
    (gdb) fr 20
    #20 0x012751f5 in funcall_lambda (fun=XIL(0xc000000007a30fc0), nargs=3,
        arg_vector=0x828570) at eval.c:3192
    3192        val = Fprogn (XCDR (XCDR (fun)));
    (gdb) p arg_vector[0]
    $5 = make_fixnum(1)
    (gdb) p arg_vector[1]
    $6 = make_fixnum(18922366)
    (gdb) fr 44
    #44 0x012751f5 in funcall_lambda (fun=XIL(0xc0000000079da550), nargs=3,
        arg_vector=0x829988) at eval.c:3192
    3192        val = Fprogn (XCDR (XCDR (fun)));
    (gdb) p arg_vector[0]
    $7 = make_fixnum(1)
    (gdb) p arg_vector[1]
    $8 = make_fixnum(1501)
    (gdb) fr 20
    #20 0x012751f5 in funcall_lambda (fun=XIL(0xc000000007a30fc0), nargs=3,
        arg_vector=0x828570) at eval.c:3192
    3192        val = Fprogn (XCDR (XCDR (fun)));
    (gdb) p fun
    $9 = XIL(0xc000000007a30fc0)
    (gdb) xtype
    Lisp_Cons
    (gdb) pp fun
    ((jit-lock-end jit-lock-start font-lock-end font-lock-beg lazy-lock-mode 
fast-lock-mode t) (start end &optional loudly) "Put proper face on each string 
and comment between START and END.
    START should be at the beginning of a line." (syntax-propertize end) (let 
((table (syntax-table)) (buffer (current-buffer))) (unwind-protect (progn 
(set-syntax-table (or syntax-ppss-table (syntax-table))) (if (and comment-start 
(not comment-end-skip)) (progn (comment-normalize-vars))) (let ((state (if (or 
syntax-ppss-table (not font-lock--syntax-table-affects-ppss)) (syntax-ppss 
start) (parse-partial-sexp (point-min) start))) face beg) (if loudly (message 
"Fontifying %s... (syntactically...)" (buffer-name))) (while (progn (if (or 
(nth 3 state) (nth 4 state)) (progn (setq face (funcall 
font-lock-syntactic-face-function state)) (setq beg (max (nth 8 state) start)) 
(setq state (parse-partial-sexp (point) end nil nil state 'syntax-table)) (if 
face (progn (put-text-property beg (point) 'face face))) (if (and (eq face 
'font-lock-comment-face) (or font-lock-comment-start-skip comment-start-skip)) 
(progn (save-excursion (goto-char beg) (if (looking-at (or 
font-lock-comment-start-skip comment-start-skip)) (put-text-property beg 
(match-end 0) 'face font-lock-comment-delimiter-face))) (if (looking-back (or 
font-lock-comment-end-skip comment-end-skip) (point-at-bol) t) 
(put-text-property (match-beginning 0) (point) 'face 
font-lock-comment-delimiter-face)))))) (< (point) end)) (setq state 
(parse-partial-sexp (point) end nil nil state 'syntax-table))))) 
(save-current-buffer (set-buffer buffer) (set-syntax-table table)))))
    (gdb)