bug#57207: 29.0.50; Fontification is slow after e7b5912b23 (Improvements to long lines handling)

[Ihor Radchenko <yantar92@gmail.com>]

Eli Zaretskii <eliz@gnu.org> writes:

>> (b) Setting long-line-threshold to nil makes the slowdown disappear.
>> Increasing long-line-threshold to 100000 made Emacs hang. I had to kill
>> it using kill -9.
>
> When it hangs, can you attach a debugger to it and try to figure out
> where it loops?  The instructions to do so are in etc/DEBUG, under "If
> the symptom of the bug is that Emacs fails to respond".  If that
> procedure is more than you can afford, at least post the results of
> "thread apply all bt" after attaching the debugger to a "hung" Emacs.

Emacs with debugging support is generally slow on my large Org file, but
I think that I managed to get some kind of backtrace with the default
value of long-line-threshold.

I typed C-z in GDB shell right after triggering the slow operation (it
is headline unfolding in my testing).

(I did confirm that setting long-line-threshold to nil makes the
unfolding instant)

The GDB log is below. Hope it gives some clues.

^Z
Thread 1 "emacs" received signal SIGTSTP, Stopped (user).
0x00005555557e4840 in buf_bytepos_to_charpos (b=0x5555602f5ff0, bytepos=11098754) at marker.c:353
353	     CONSIDER (tail->bytepos, tail->charpos);
(gdb) step
358	     if (best_above - bytepos < distance
(gdb) finish
Run till exit from #0  buf_bytepos_to_charpos (b=0x5555602f5ff0, bytepos=11098754) at marker.c:358
BYTE_TO_CHAR (bytepos=11098754) at /home/yantar92/Git/emacs/src/buffer.h:1053
1053	}
Value returned is $1 = 10568710
(gdb) finish
Run till exit from #0  BYTE_TO_CHAR (bytepos=11098754) at /home/yantar92/Git/emacs/src/buffer.h:1053
0x000055555581da55 in find_newline1 (start=10568693, start_byte=11098737, end=19968614, end_byte=20651065, count=0, counted=0x7fffffff9480, bytepos=0x0, allow_quit=true) at search.c:3260
3260			 return BYTE_TO_CHAR (lim_byte + next);
Value returned is $2 = 10568710
(gdb) finish
Run till exit from #0  0x000055555581da55 in find_newline1 (start=10568693, start_byte=11098737, end=19968614, end_byte=20651065, count=0, 
    counted=0x7fffffff9480, bytepos=0x0, allow_quit=true) at search.c:3260
0x0000555555610b5b in redisplay_window (window=XIL(0x5555564fed05), just_this_one_p=true) at xdisp.c:19594
19594		 next = find_newline1 (cur, CHAR_TO_BYTE (cur), 0, -1, 1,
Value returned is $3 = 10568710
(gdb) finish
Run till exit from #0  0x0000555555610b5b in redisplay_window (window=XIL(0x5555564fed05), just_this_one_p=true) at xdisp.c:19594
redisplay_window_1 (window=XIL(0x5555564fed05)) at xdisp.c:17502
17502	 return Qnil;
(gdb) finish
Run till exit from #0  redisplay_window_1 (window=XIL(0x5555564fed05)) at xdisp.c:17502
0x000055555587bb83 in internal_condition_case_1 (bfun=0x5555556086f9 <redisplay_window_1>, arg=XIL(0x5555564fed05), handlers=XIL(0x7ffff1b8da2b), hfun=0x555555608402 <redisplay_window_error>) at eval.c:1521
1521	     Lisp_Object val = bfun (arg);
Value returned is $4 = XIL(0)
(gdb) finish
Run till exit from #0  0x000055555587bb83 in internal_condition_case_1 (bfun=0x5555556086f9 <redisplay_window_1>, arg=XIL(0x5555564fed05), 
    handlers=XIL(0x7ffff1b8da2b), hfun=0x555555608402 <redisplay_window_error>) at eval.c:1521
redisplay_internal () at xdisp.c:17044
17044	     if (update_miniwindow_p)
Value returned is $5 = XIL(0)
(gdb) finish
Run till exit from #0  redisplay_internal () at xdisp.c:17044
redisplay () at xdisp.c:16104
16104	}
(gdb) finish
Run till exit from #0  redisplay () at xdisp.c:16104
read_char (commandflag=1, map=XIL(0x55556c00a123), prev_event=XIL(0), used_mouse_menu=0x7fffffffd3dd, end_time=0x0) at keyboard.c:2645
2645		 if (!input_pending)
(gdb) finish
Run till exit from #0  read_char (commandflag=1, map=XIL(0x55556c00a123), prev_event=XIL(0), used_mouse_menu=0x7fffffffd3dd, end_time=0x0)
    at keyboard.c:2645
0x00005555557a4ec1 in read_key_sequence (keybuf=0x7fffffffd5d0, prompt=XIL(0), dont_downcase_last=false, can_return_switch_frame=true, fix_current_buffer=true, prevent_redisplay=false) at keyboard.c:10045
10045		   key = read_char (prevent_redisplay ? -2 : NILP (prompt),
Value returned is $6 = make_fixnum(106)
(gdb) c
Continuing.
^Z
Thread 1 "emacs" received signal SIGTSTP, Stopped (user).
0x00005555557e4873 in buf_bytepos_to_charpos (b=0x5555602f5ff0, bytepos=10121474) at marker.c:353
353	     CONSIDER (tail->bytepos, tail->charpos);
(gdb) step
358	     if (best_above - bytepos < distance
(gdb) finish
Run till exit from #0  buf_bytepos_to_charpos (b=0x5555602f5ff0, bytepos=10121474) at marker.c:358
BYTE_TO_CHAR (bytepos=10121474) at /home/yantar92/Git/emacs/src/buffer.h:1053
1053	}
Value returned is $7 = 9679581
(gdb) finish
Run till exit from #0  BYTE_TO_CHAR (bytepos=10121474) at /home/yantar92/Git/emacs/src/buffer.h:1053
0x000055555581da55 in find_newline1 (start=9679550, start_byte=10121431, end=19968614, end_byte=20651065, count=0, counted=0x7fffffff9480, bytepos=0x0, allow_quit=true) at search.c:3260
3260			 return BYTE_TO_CHAR (lim_byte + next);
Value returned is $8 = 9679581
(gdb) finish
Run till exit from #0  0x000055555581da55 in find_newline1 (start=9679550, start_byte=10121431, end=19968614, end_byte=20651065, count=0, 
    counted=0x7fffffff9480, bytepos=0x0, allow_quit=true) at search.c:3260
0x0000555555610b5b in redisplay_window (window=XIL(0x5555564fed05), just_this_one_p=true) at xdisp.c:19594
19594		 next = find_newline1 (cur, CHAR_TO_BYTE (cur), 0, -1, 1,
Value returned is $9 = 9679581
(gdb) finish
Run till exit from #0  0x0000555555610b5b in redisplay_window (window=XIL(0x5555564fed05), just_this_one_p=true) at xdisp.c:19594
redisplay_window_1 (window=XIL(0x5555564fed05)) at xdisp.c:17502
17502	 return Qnil;
(gdb) finish
Run till exit from #0  redisplay_window_1 (window=XIL(0x5555564fed05)) at xdisp.c:17502
0x000055555587bb83 in internal_condition_case_1 (bfun=0x5555556086f9 <redisplay_window_1>, arg=XIL(0x5555564fed05), handlers=XIL(0x7ffff1b8da2b), hfun=0x555555608402 <redisplay_window_error>) at eval.c:1521
1521	     Lisp_Object val = bfun (arg);
Value returned is $10 = XIL(0)
(gdb) finish
Run till exit from #0  0x000055555587bb83 in internal_condition_case_1 (bfun=0x5555556086f9 <redisplay_window_1>, arg=XIL(0x5555564fed05), 
    handlers=XIL(0x7ffff1b8da2b), hfun=0x555555608402 <redisplay_window_error>) at eval.c:1521
redisplay_internal () at xdisp.c:17044
17044	     if (update_miniwindow_p)
Value returned is $11 = XIL(0)
(gdb) finish
Run till exit from #0  redisplay_internal () at xdisp.c:17044
redisplay () at xdisp.c:16104
16104	}
(gdb) finish
Run till exit from #0  redisplay () at xdisp.c:16104
read_char (commandflag=1, map=XIL(0x55556c7b89c3), prev_event=XIL(0), used_mouse_menu=0x7fffffffd3dd, end_time=0x0) at keyboard.c:2645
2645		 if (!input_pending)
(gdb) c
Continuing.
[Detaching after vfork from child process 4901]
[Detaching after vfork from child process 4902]
[Detaching after vfork from child process 4903]
[Detaching after vfork from child process 4904]
[Detaching after vfork from child process 4905]
[Detaching after vfork from child process 4906]
[Thread 0x7fffeb7fe640 (LWP 32537) exited]
[Thread 0x7fffebfff640 (LWP 32536) exited]
[Thread 0x7ffff0cc4640 (LWP 32535) exited]
[Inferior 1 (process 32532) exited normally]
(gdb) q

-- 
Ihor Radchenko,
Org mode contributor,
Learn more about Org mode at https://orgmode.org/.
Support Org development at https://liberapay.com/org-mode,
or support my work at https://liberapay.com/yantar92