Re: Excessive redisplay from lots of process output

[Spencer Baugh]

On Fri, Feb 17, 2023 at 11:06 AM Eli Zaretskii <eliz@gnu.org> wrote:
>
> > From: Spencer Baugh <sbaugh@janestreet.com>
> > Cc: azeng@janestreet.com
> > Date: Fri, 17 Feb 2023 10:16:11 -0500
> >
> > Emacs calls redisplay every time it reads process output.  This causes
> > Emacs to become painfully slow when these two conditions are met:
> >
> > - When redisplay is expensive (e.g. when using ssh X forwarding)
> >
> > - And when there is frequent process output, say hundreds or thousands
> >   of times a second (e.g. ERC receiving network traffic, shells
> >   running commands which log heavily, other things which run in the
> >   background)
>
> This cannot be the whole story, because usually redisplay exits almost
> immediately after being called, having determined that nothing needs
> to be changed on display.
>
> So the important part of your situation that you didn't disclose is:
> why does Emacs in your case perform the expensive redisplay each time
> redisplay is entered?  Can you figure that out by stepping through
> redisplay_internal?  (Let me know if you need guidance.)

Actually, I'm looking a bit more into it, and I think there is still
some issue causing excessive X traffic when there's lots of process
output to be read.  On emacs -Q with Emacs 28, flush_frame/XFlush is
called on every redisplay, and does seem to be actually writing X
requests on the X socket every time.

Here's a backtrace of where flush_frame/XFlush is being called from:

#0  0x00007ffff4abc5c0 in XFlush () at /lib64/libX11.so.6
#1  0x00000000004d23d6 in x_flush (f=<optimized out>) at xterm.c:250
#2  0x00000000004d2416 in x_flip_and_flush (f=0xf956d0) at xterm.c:246
#3  0x00000000004d2416 in x_flip_and_flush (f=0xf956d0) at xterm.c:1230
#4  0x0000000000461374 in redisplay_preserve_echo_area (f=<optimized
out>) at frame.h:1700
#5  0x0000000000461374 in redisplay_preserve_echo_area
(from_where=from_where@entry=12) at xdisp.c:16527
#6  0x00000000005bee33 in wait_reading_process_output
(time_limit=time_limit@entry=0, nsecs=nsecs@entry=0,
read_kbd=read_kbd@entry=-1, do_display=true,
wait_for_cell=wait_for_cell@entry=0x0, wait_proc=wait_proc@entry=0x0,
just_wait_proc=just_wait_proc@entry=0) at process.c:5808
#7  0x000000000050aea4 in read_char (end_time=0x0,
used_mouse_menu=0x7fffffffda5b, kbp=<synthetic pointer>) at
keyboard.c:3926
#8  0x000000000050aea4 in read_char (used_mouse_menu=<optimized out>,
local_getcjmp=<optimized out>, end_time=<optimized out>) at
keyboard.c:2198
#9  0x000000000050aea4 in read_char (used_mouse_menu=<optimized out>,
prev_event=<optimized out>, local_getcjmp=<optimized out>,
end_time=<optimized out>) at keyboard.c:2261
#10 0x000000000050aea4 in read_char (commandflag=commandflag@entry=1,
map=map@entry=0x127fed3, prev_event=<optimized out>,
used_mouse_menu=used_mouse_menu@entry=0x7fffffffda5b,
end_time=end_time@entry=0x0) at keyboard.c:2892
#11 0x000000000050cc5e in read_key_sequence
(keybuf=keybuf@entry=0x7fffffffdb60, prompt=prompt@entry=0x0,
dont_downcase_last=dont_downcase_last@entry=false,
can_return_switch_frame=can_return_switch_frame@entry=true,
fix_current_buffer=fix_current_buffer@entry=true,
prevent_redisplay=prevent_redisplay@entry=false) at keyboard.c:9635
#12 0x000000000050e390 in command_loop_1 () at keyboard.c:1392
#13 0x0000000000578754 in internal_condition_case
(bfun=bfun@entry=0x50e180 <command_loop_1>,
handlers=handlers@entry=0x90, hfun=hfun@entry=0x504990 <cmd_error>) at
eval.c:1450
#14 0x00000000004ff4aa in command_loop_2
(handlers=handlers@entry=0x90) at keyboard.c:1133
#15 0x0000000000578704 in internal_catch (tag=tag@entry=0xe850,
func=func@entry=0x4ff490 <command_loop_2>, arg=arg@entry=0x90) at
eval.c:1181
#16 0x00000000004ff46a in command_loop () at keyboard.c:1111
#17 0x00000000005045cb in recursive_edit_1 () at keyboard.c:720
#18 0x00000000005048e5 in Frecursive_edit () at keyboard.c:803
#19 0x000000000041e909 in main (argc=4, argv=<optimized out>) at emacs.c:2361

What could be causing this?