Excessive redisplay from lots of process output

Excessive redisplay from lots of process output

[Spencer Baugh]

Hi emacs-devel,

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)

Does Emacs really need to redisplay on every process output?  I've
installed the following change in my Emacs, which has radically
reduced the amount of redisplay performed and improved performance,
and I haven't noticed any adverse effects:

--- a/src/process.c
+++ b/src/process.c
@@ -5804,8 +5804,6 @@ wait_reading_process_output (intmax_t time_limit,
 		  FD_ZERO (&Available);
 		  last_read_channel = channel;
 
-		  if (do_display)
-		    redisplay_preserve_echo_area (12);
 		}
 	      else if (nread == -1 && would_block (errno))
 		;
-- 


I realize that reading process output can trigger filters which can
change window and frame configurations, which in turn means redisplay
needs to happen.  But isn't there some way we could improve this
situation?  Right now these redisplays are causing serious
user-visible performance degradation.

One idea: Could we allow Lisp code to mark a process as not wanting
redisplay after Emacs reads output?  Then packages which receive heavy
amounts of process output could mark their processes in this way.  If
they do rarely need to perform user-visible changes, they could
explicitly call (redisplay) themselves.

Thoughts on this problem and any potential solutions for it?

Thanks,
Spencer Baugh

Re: Excessive redisplay from lots of process output

[Eli Zaretskii]

> 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.)

Not sure here is the right place for this kind of discussion, btw.  It
might be better to submit a bug report with all the relevant details,
and discuss this on the bug tracker.

> I realize that reading process output can trigger filters which can
> change window and frame configurations, which in turn means redisplay
> needs to happen.  But isn't there some way we could improve this
> situation?  Right now these redisplays are causing serious
> user-visible performance degradation.

There are many variables and flags Emacs uses to decide when something
changed that needs the display to be updated.  Those should generally
prevent Emacs from running the expensive parts of redisplay if they
are unnecessary.  The question is why this doesn't work in your case.

IOW, it is better to consider this as some specific failure in some
particular situation, and find why it happens, instead of considering
this as some general failure of the Emacs design.  Design-wise, things
are fine; it's something in your specific case that could fail the
existing mechanisms, and the question is: what is that and why it
fails?

> One idea: Could we allow Lisp code to mark a process as not wanting
> redisplay after Emacs reads output?  Then packages which receive heavy
> amounts of process output could mark their processes in this way.  If
> they do rarely need to perform user-visible changes, they could
> explicitly call (redisplay) themselves.

You are thinking in the wrong direction.  You assume that if redisplay
is called frequently, it will necessarily slow down Emacs.  That
assumption is false: redisplay works very hard to avoid expensive
processing when it can.  So reducing the frequency of calls to
redisplay is not the right direction to make progress in your and
other similar cases.

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.)

Oh, this was the key information for me to realize what was *really*
going on.  In Emacs 27, in-progress key sequences get replayed each
time there is process output to read, see bug#32922. This causes
redisplay to have actual work to do each time it reads process output.
But this only happens mid key-sequence, so it's not really a general
issue with Emacs performance, but it *does* cause the X server to get
swamped and therefore slows down X in general, including the window
manager and other X clients.

But fortunately that key-sequence replaying behavior was deleted in
Emacs 28, just as a general cleanup, see bug#5803.  Which helpfully
means that redisplay is once again always cheap, so the bad X
performance of having lots of process output disappears.

Sorry, a mix of upgrading to Emacs 28 and also applying this patch
made it not clear what was helping performance.  But now it is clear.

> Not sure here is the right place for this kind of discussion, btw.  It
> might be better to submit a bug report with all the relevant details,
> and discuss this on the bug tracker.
>
> > I realize that reading process output can trigger filters which can
> > change window and frame configurations, which in turn means redisplay
> > needs to happen.  But isn't there some way we could improve this
> > situation?  Right now these redisplays are causing serious
> > user-visible performance degradation.
>
> There are many variables and flags Emacs uses to decide when something
> changed that needs the display to be updated.  Those should generally
> prevent Emacs from running the expensive parts of redisplay if they
> are unnecessary.  The question is why this doesn't work in your case.
>
> IOW, it is better to consider this as some specific failure in some
> particular situation, and find why it happens, instead of considering
> this as some general failure of the Emacs design.  Design-wise, things
> are fine; it's something in your specific case that could fail the
> existing mechanisms, and the question is: what is that and why it
> fails?

Oh yes, that makes sense, now I see, thanks for the explanation.

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?

Re: Excessive redisplay from lots of process output

[Eli Zaretskii]

> From: Spencer Baugh <sbaugh@janestreet.com>
> Date: Fri, 24 Feb 2023 14:14:55 -0500
> Cc: emacs-devel@gnu.org,
>   azeng@janestreet.com
> 
> 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?

This says that Emacs have read some stuff from the sub-process.  When
that happens, we always perform a relatively-thorough redisplay, which
is what you see.

This is normal.

If the problem is that flush_frame causes too much X traffic across
the network, perhaps some tuning of your X connection is in order.  Or
maybe some X expert (I'm not) could suggest something else.

Re: Excessive redisplay from lots of process output

[Spencer Baugh]

On Fri, Feb 24, 2023 at 2:34 PM Eli Zaretskii <eliz@gnu.org> wrote:
>
> > From: Spencer Baugh <sbaugh@janestreet.com>
> > Date: Fri, 24 Feb 2023 14:14:55 -0500
> > Cc: emacs-devel@gnu.org,
> >   azeng@janestreet.com
> >
> > 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?
>
> This says that Emacs have read some stuff from the sub-process.  When
> that happens, we always perform a relatively-thorough redisplay, which
> is what you see.
>
> This is normal.

Just to make sure I understand, you said earlier:

>There are many variables and flags Emacs uses to decide when something
>changed that needs the display to be updated.  Those should generally
>prevent Emacs from running the expensive parts of redisplay if they
>are unnecessary.  The question is why this doesn't work in your case.

Are you saying this does not apply in the case of reading from
process output? That after reading process output, we always do
an expensive redisplay?

If so, it seems to me that this could be substantially improved.
Why do we always do an expensive redisplay after reading process
output, even if nothing has been changed to make it necessary?

I would like to improve this so that my Emacs does not do
expensive redisplay whenever it reads process output, which is
substantially hurting performance for me when there's lots of
process output to read.

Re: Excessive redisplay from lots of process output

[Eli Zaretskii]

> From: Spencer Baugh <sbaugh@janestreet.com>
> Date: Fri, 24 Feb 2023 15:08:17 -0500
> Cc: emacs-devel@gnu.org,
>   azeng@janestreet.com
> 
> > This is normal.
> 
> Just to make sure I understand, you said earlier:
> 
> >There are many variables and flags Emacs uses to decide when something
> >changed that needs the display to be updated.  Those should generally
> >prevent Emacs from running the expensive parts of redisplay if they
> >are unnecessary.  The question is why this doesn't work in your case.
> 
> Are you saying this does not apply in the case of reading from
> process output? That after reading process output, we always do
> an expensive redisplay?

Whether redisplay is expensive or not depends on many factors.  But we
always flush the frame in that case, yes.

> If so, it seems to me that this could be substantially improved.
> Why do we always do an expensive redisplay after reading process
> output, even if nothing has been changed to make it necessary?

We don't always do an expensive redisplay, but we always call XFlush.

> I would like to improve this so that my Emacs does not do
> expensive redisplay whenever it reads process output, which is
> substantially hurting performance for me when there's lots of
> process output to read.

AFAIU, what is problematic for you is the X traffic causes by XFlush.

Re: Excessive redisplay from lots of process output

[Spencer Baugh]

On Fri, Feb 24, 2023 at 3:19 PM Eli Zaretskii <eliz@gnu.org> wrote:
>
> > From: Spencer Baugh <sbaugh@janestreet.com>
> > Date: Fri, 24 Feb 2023 15:08:17 -0500
> > Cc: emacs-devel@gnu.org,
> >   azeng@janestreet.com
> >
> > > This is normal.
> >
> > Just to make sure I understand, you said earlier:
> >
> > >There are many variables and flags Emacs uses to decide when something
> > >changed that needs the display to be updated.  Those should generally
> > >prevent Emacs from running the expensive parts of redisplay if they
> > >are unnecessary.  The question is why this doesn't work in your case.
> >
> > Are you saying this does not apply in the case of reading from
> > process output? That after reading process output, we always do
> > an expensive redisplay?
>
> Whether redisplay is expensive or not depends on many factors.  But we
> always flush the frame in that case, yes.

Why? It seems unnecessary if nothing has changed.

> > If so, it seems to me that this could be substantially improved.
> > Why do we always do an expensive redisplay after reading process
> > output, even if nothing has been changed to make it necessary?
>
> We don't always do an expensive redisplay, but we always call XFlush.
>
> > I would like to improve this so that my Emacs does not do
> > expensive redisplay whenever it reads process output, which is
> > substantially hurting performance for me when there's lots of
> > process output to read.
>
> AFAIU, what is problematic for you is the X traffic causes by XFlush.

I think that is problematic for anyone running with a slow X server; it
gives the X server a lot to process.  The fact that my X server is
across the network just makes my X server seem artificially slow.

In other words, I think XFlush should be considered "expensive" and
avoided where possible.

Re: Excessive redisplay from lots of process output

[Eli Zaretskii]

> From: Spencer Baugh <sbaugh@janestreet.com>
> Date: Fri, 24 Feb 2023 15:33:52 -0500
> Cc: emacs-devel@gnu.org,
>   azeng@janestreet.com
> 
> On Fri, Feb 24, 2023 at 3:19 PM Eli Zaretskii <eliz@gnu.org> wrote:
> >
> > > From: Spencer Baugh <sbaugh@janestreet.com>
> > > Date: Fri, 24 Feb 2023 15:08:17 -0500
> > > Cc: emacs-devel@gnu.org,
> > >   azeng@janestreet.com
> > >
> > > > This is normal.
> > >
> > > Just to make sure I understand, you said earlier:
> > >
> > > >There are many variables and flags Emacs uses to decide when something
> > > >changed that needs the display to be updated.  Those should generally
> > > >prevent Emacs from running the expensive parts of redisplay if they
> > > >are unnecessary.  The question is why this doesn't work in your case.
> > >
> > > Are you saying this does not apply in the case of reading from
> > > process output? That after reading process output, we always do
> > > an expensive redisplay?
> >
> > Whether redisplay is expensive or not depends on many factors.  But we
> > always flush the frame in that case, yes.
> 
> Why? It seems unnecessary if nothing has changed.

I'm not sure we know that nothing has changed.  I'm also not sure I
understand why XFlush is so expensive when nothing or almost nothing
has changed on display.  Maybe Po Lu could comment.

> > AFAIU, what is problematic for you is the X traffic causes by XFlush.
> 
> I think that is problematic for anyone running with a slow X server; it
> gives the X server a lot to process.

Are you sure?  What exactly does XFlush send to the X server if
nothing was changed on display?

> In other words, I think XFlush should be considered "expensive" and
> avoided where possible.

If that is possible, I agree.

Re: Excessive redisplay from lots of process output

[Po Lu]

XFlush is not so expensive, as it simply makes requests that are already in the output buffer happen.  An implicit flush happens before XNextEvent, XEventsQueued, and XPending.

What is expensive is _XReply, so I would guess that is the source or Spencer's problems.  I removed most unnecessary calls from Emacs 29.  If that is still slow, then please tell me where the call is.  Emacs should not call _XReply just to redisplay!


On February 25, 2023 4:51:19 AM GMT+08:00, Eli Zaretskii <eliz@gnu.org> wrote:
>> From: Spencer Baugh <sbaugh@janestreet.com>
>> Date: Fri, 24 Feb 2023 15:33:52 -0500
>> Cc: emacs-devel@gnu.org,
>>   azeng@janestreet.com
>> 
>> On Fri, Feb 24, 2023 at 3:19 PM Eli Zaretskii <eliz@gnu.org> wrote:
>> >
>> > > From: Spencer Baugh <sbaugh@janestreet.com>
>> > > Date: Fri, 24 Feb 2023 15:08:17 -0500
>> > > Cc: emacs-devel@gnu.org,
>> > >   azeng@janestreet.com
>> > >
>> > > > This is normal.
>> > >
>> > > Just to make sure I understand, you said earlier:
>> > >
>> > > >There are many variables and flags Emacs uses to decide when something
>> > > >changed that needs the display to be updated.  Those should generally
>> > > >prevent Emacs from running the expensive parts of redisplay if they
>> > > >are unnecessary.  The question is why this doesn't work in your case.
>> > >
>> > > Are you saying this does not apply in the case of reading from
>> > > process output? That after reading process output, we always do
>> > > an expensive redisplay?
>> >
>> > Whether redisplay is expensive or not depends on many factors.  But we
>> > always flush the frame in that case, yes.
>> 
>> Why? It seems unnecessary if nothing has changed.
>
>I'm not sure we know that nothing has changed.  I'm also not sure I
>understand why XFlush is so expensive when nothing or almost nothing
>has changed on display.  Maybe Po Lu could comment.
>
>> > AFAIU, what is problematic for you is the X traffic causes by XFlush.
>> 
>> I think that is problematic for anyone running with a slow X server; it
>> gives the X server a lot to process.
>
>Are you sure?  What exactly does XFlush send to the X server if
>nothing was changed on display?
>
>> In other words, I think XFlush should be considered "expensive" and
>> avoided where possible.
>
>If that is possible, I agree.
>

Re: Excessive redisplay from lots of process output

[Po Lu]

XFlush is not too expensive if not many requests have been generated.  What is expensive is _XReply, which waits for a reply from the X server on the other side of the connection.

Anyway, please give Emacs 29 a try.  I tried to reduce the number of locations where Emacs waits for replies, which makes it much more usable over a network connection.

Also, try using a no toolkit build.  GTK has a bug where changing the scroll bar waits for replies from the X server.

If the problem is still there in Emacs 29, please run Emacs under xscope, and tell which request(s) are being made.  Emacs should not make X requests when nothing on the display has actually changed.


On February 25, 2023 3:14:55 AM GMT+08:00, Spencer Baugh <sbaugh@janestreet.com> wrote:
>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?
>

Re: Excessive redisplay from lots of process output

[Eli Zaretskii]

> Date: Sat, 25 Feb 2023 07:10:24 +0800
> From: Po Lu <Luangruo@yahoo.com>
> 
> If the problem is still there in Emacs 29, please run Emacs under xscope, and tell which request(s) are being made.  Emacs should not make X requests when nothing on the display has actually changed.

The backtrace posted by Spencer tells us that Emacs called
redisplay_preserve_echo_area:

>#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

And redisplay_preserve_echo_area calls flush_frame unconditionally for
the selected frame:

  void
  redisplay_preserve_echo_area (int from_where)
  {
    redisplay_trace ("redisplay_preserve_echo_area (%d)\n", from_where);

    block_input ();
    specpdl_ref count = SPECPDL_INDEX ();
    record_unwind_protect_void (unwind_redisplay_preserve_echo_area);
    block_buffer_flips ();
    unblock_input ();

    if (!NILP (echo_area_buffer[1]))
      {
	/* We have a previously displayed message, but no current
	   message.  Redisplay the previous message.  */
	display_last_displayed_message_p = true;
	redisplay_internal ();
	display_last_displayed_message_p = false;
      }
    else
      redisplay_internal ();

    flush_frame (SELECTED_FRAME ());  <<<<<<<<<<<<<<<<<<<<<<<<<<<<
    unbind_to (count, Qnil);
  }

How can we avoid this call to flush_frame "when nothing on the display
has actually changed"?  We don't have any mechanism for update_frame
and/or redisplay_internal to tell back whether anything was changed on
display.  There's a lot that _can_ change:

  . text-area of the windows
  . mode lines, header lines, and tab-lines
  . menu bar, tool bar, and tab bar
  . fringes
  . scroll bars
  . frame's title
  . new frames and windows, including tooltips

We currently don't have any indication for whether any of those have
changed.

Where do we call _XReply and for what purpose?  I don't see it in our
sources anywhere.

Re: Excessive redisplay from lots of process output

[Po Lu]

Eli Zaretskii <eliz@gnu.org> writes:

> The backtrace posted by Spencer tells us that Emacs called
> redisplay_preserve_echo_area:
>
>>#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
>
> And redisplay_preserve_echo_area calls flush_frame unconditionally for
> the selected frame:
>
>   void
>   redisplay_preserve_echo_area (int from_where)
>   {
>     redisplay_trace ("redisplay_preserve_echo_area (%d)\n", from_where);
>
>     block_input ();
>     specpdl_ref count = SPECPDL_INDEX ();
>     record_unwind_protect_void (unwind_redisplay_preserve_echo_area);
>     block_buffer_flips ();
>     unblock_input ();
>
>     if (!NILP (echo_area_buffer[1]))
>       {
> 	/* We have a previously displayed message, but no current
> 	   message.  Redisplay the previous message.  */
> 	display_last_displayed_message_p = true;
> 	redisplay_internal ();
> 	display_last_displayed_message_p = false;
>       }
>     else
>       redisplay_internal ();
>
>     flush_frame (SELECTED_FRAME ());  <<<<<<<<<<<<<<<<<<<<<<<<<<<<
>     unbind_to (count, Qnil);
>   }
>
> How can we avoid this call to flush_frame "when nothing on the display
> has actually changed"?  We don't have any mechanism for update_frame
> and/or redisplay_internal to tell back whether anything was changed on
> display.  There's a lot that _can_ change:

XFlush (called by flush_frame) is the function which avoids doing
anything if nothing on the display has changed, as it makes no requests
itself.  Calling flush_frame after a redisplay which does nothing is
harmless; all the OP is experiencing tells us is that XFlush is not to
blame, but most likely some other X protocol request calling _XReply.

> Where do we call _XReply and for what purpose?  I don't see it in our
> sources anywhere.

_XReply is the function called with Xlib whenever you make an X protocol
request that has a reply, such as XGetWindowProperty:

  dpyinfo = FRAME_DISPLAY_INFO (f);

  if (XGetWindowProperty (FRAME_X_DISPLAY (f), FRAME_OUTER_WINDOW (f),
			  dpyinfo->Xatom_wm_state, 0, 2, False,
			  AnyPropertyType, &type, &format, &nitems,
			  &bytes_after, &data) != Success)
    return;

  if (!data || nitems != 2 || format != 32)
    {

This is expensive because it involves sending a request to the X server
and waiting for a response, which easily takes hundereds of ms over a
slow network connection.

Fortunately, Emacs 29 should not call XSync as much as Emacs 28 did.
Which is why I asked Spencer to try it out.