bug#45898: 27.1; wedged in redisplay again

[Eli Zaretskii]

Ping?

Stefan, can you chime in on this?  This aspect is basically the only
reason I didn't yet land the feature on master.

> Cc: psainty@orcon.net.nz, Emacs-hacker2018@jovi.net, 45898@debbugs.gnu.org
> Date: Sat, 18 Jun 2022 11:01:24 +0300
> From: Eli Zaretskii <eliz@gnu.org>
> 
> > 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)
> 
> 
> 
> 
> 
>