bug#11822: 24.1; emacsclient terminal mode captures escape characters as text

unofficial mirror of bug-gnu-emacs@gnu.org 
 help / color / mirror / code / Atom feed

* bug#11822: 24.1; emacsclient terminal mode captures escape characters as text
@ 2012-06-30  0:08 Ken Raeburn
  2012-06-30  5:55 ` Eli Zaretskii
  0 siblings, 1 reply; 64+ messages in thread
From: Ken Raeburn @ 2012-06-30  0:08 UTC (permalink / raw)
  To: 11822

I've been using Emacs in daemon mode and starting X11 frames for most of
my editing, and setting $EDITOR to point to a script that invokes
"emacsclient -t" so programs launching an editor get Emacs using the
program's original window (under gnome-terminal).

Often, Emacs seems to suffer a couple of problems when $EDITOR gets
invoked:

1) After Emacs takes over the terminal window (which can take several
seconds), it displays one of my pre-existing buffers for several seconds
before switching to the new file to be edited.  The file to be edited in
these cases is typically living in NFS and kind of large (over 24KB this
last time), so it's possible that reading the file is slow.  It's a bit
distracting to have this other file displayed for so long though.  I see
code in server-create-tty-frame to explicitly select the *scratch*
buffer, but it doesn't seem to be doing it.

2) After Emacs displays the file to be edited, some text from an escape
sequence gets inserted; view-lossage shows this sequence:
   ESC [ > 1 ; 2 4 0 3 ; 0 c
The buffer itself now contains the part starting with "1".

One time so far, though I think it was with a pretest version before
24.1, I even had Emacs take over the terminal window from which some
program launched $EDITOR, but then the file to be edited got displayed
in one of my already existing X11 windows.  I haven't had it happen
again, though I haven't tried to figure out how to reproduce it either.
(Maybe I clicked on the X11 window during one of those delays described
above and that confused Emacs?)

I have no idea what the "error during redisplay" messages shown below
are about; I hadn't even noticed them until skimming this report.


In GNU Emacs 24.1.1 (x86_64-unknown-linux-gnu, X toolkit, Xaw3d scroll bars)
 of 2012-06-11 on just-testing.permabit.com
Windowing system distributor `The X.Org Foundation', version 11.0.10707000
Configured using:
 `configure
 '--prefix=/permabit/user/raeburn/I64/install/emacs-24.1.squeeze'
 '--with-x-toolkit=lucid''

Important settings:
  value of $LC_ALL: nil
  value of $LC_COLLATE: nil
  value of $LC_CTYPE: nil
  value of $LC_MESSAGES: nil
  value of $LC_MONETARY: nil
  value of $LC_NUMERIC: nil
  value of $LC_TIME: nil
  value of $LANG: C
  value of $XMODIFIERS: nil
  locale-coding-system: nil
  default enable-multibyte-characters: t

Major mode: C/l

Minor modes in effect:
  diff-auto-refine-mode: t
  eldoc-mode: t
  rcirc-track-minor-mode: t
  whitespace-mode: t
  desktop-save-mode: t
  jabber-activity-mode: t
  display-time-mode: t
  which-function-mode: t
  icomplete-mode: t
  shell-dirtrack-mode: t
  tooltip-mode: t
  mouse-wheel-mode: t
  file-name-shadow-mode: t
  global-font-lock-mode: t
  font-lock-mode: t
  auto-composition-mode: t
  auto-encryption-mode: t
  auto-compression-mode: t
  line-number-mode: t
  transient-mark-mode: t
  abbrev-mode: t

Recent input:
<mouse-5> <down-mouse-1> <mouse-movement> <mouse-1> 
<M-backspace> <M-backspace> w h e t h e r C-x C-s ESC 
[ > 1 ; 2 4 0 3 ; 0 c ESC DEL ESC DEL ESC DEL C-f C-x 
C-s C-x C-c <down-mouse-1> <mouse-movement> <mouse-1> 
M-x e m a c s - v e r s i o n <return> C-x m C-x k 
<return> M-x e m a c s - b u g <tab> <M-backspace> 
<M-backspace> r e p o r t - e m <tab> <return>

Recent messages:
Error during redisplay: (wrong-type-argument arrayp nil) [4 times]
When done with a buffer, type C-x #
Error during redisplay: (wrong-type-argument arrayp nil) [2 times]
Saving file /permabit/user/raeburn/workspace/timeout/.git/COMMIT_EDITMSG...
Wrote /permabit/user/raeburn/workspace/timeout/.git/COMMIT_EDITMSG
Error during redisplay: (wrong-type-argument arrayp nil)
(No files need saving)
Error during redisplay: (wrong-type-argument arrayp nil) [17 times]
GNU Emacs 24.1.1 (x86_64-unknown-linux-gnu, X toolkit, Xaw3d scroll bars) of 2012-06-11 on just-testing.permabit.com
Error during redisplay: (wrong-type-argument arrayp nil) [23 times]

Load-path shadows:
None found.

Features:
(pcmpl-gnu diff-mode vc ediff-merg ediff-diff ediff-wind ediff-help
ediff-util ediff-mult ediff-init ediff vc-dispatcher dired-aux
face-remap apropos find-dired sgml-mode asm-mode conf-mode pcmpl-unix
debug nxml-uchnm rng-xsd xsd-regexp rng-cmpct rng-nxml rng-valid rng-loc
rng-uri rng-parse nxml-parse rng-match rng-dt rng-util rng-pttrn nxml-ns
nxml-mode nxml-outln nxml-rap nxml-util nxml-glyph nxml-enc xmltok
arc-mode archive-mode doc-view image-mode dired python-21 python novice
noutline outline objdump ielm tramp-sh tramp-cache gnus-cite qp
gnus-async gnus-bcklg gnus-ml disp-table nndraft nnmh nnfolder utf-7
gnus-agent gnus-srvr gnus-score score-mode nnvirtual gnus-cache align
copyright pp tabify man grep gnutls mailalias smtpmail cus-edit
jka-compr find-func multi-isearch add-log newcomment shadow sort
mail-extr gnus-msg network-stream url-cache url-http url-gw url-auth url
url-proxy url-privacy url-expand url-methods url-history url-cookie
url-util url-parse url-vars emacsbug sendmail goto-addr thingatpt
jabber-keepalive jabber-bookmarks jabber-private sasl-digest hmac-md5
hex-util help-mode view mule-util server autorevert make-mode sh-script
executable vc-git c-eldoc eldoc rcirc whitespace desktop cus-start
cus-load jabber jabber-awesome jabber-osd jabber-wmii jabber-xmessage
jabber-festival jabber-sawfish jabber-ratpoison jabber-screen
jabber-socks5 jabber-ft-server jabber-si-server jabber-ft-client
jabber-ft-common jabber-si-client jabber-si-common jabber-feature-neg
jabber-truncate jabber-time jabber-autoaway jabber-vcard-avatars
jabber-chatstates jabber-events jabber-vcard jabber-avatar
jabber-activity jabber-watch jabber-modeline easy-mmode
jabber-ahc-presence jabber-ahc jabber-version jabber-ourversion
jabber-muc-nick-completion hippie-exp jabber-browse jabber-search
jabber-register jabber-roster edmacro kmacro jabber-presence jabber-muc
jabber-newdisco jabber-widget jabber-disco jabber-chat ewoc
jabber-history jabber-chatbuffer jabber-alert jabber-iq jabber-keymap
jabber-core jabber-sasl sasl sasl-anonymous sasl-login sasl-plain fsm
jabber-logon jabber-conn srv dns starttls jabber-xml jabber-menu
jabber-autoloads jabber-util cl idutils compile cperl-mode p4 timeclock
time cc-mode cc-fonts cc-guess cc-menus cc-cmds cc-styles cc-align
cc-engine cc-vars cc-defs warnings which-func imenu icomplete kr-stuff
ses unsafep nnimap parse-time tls utf7 netrc browse-url edit-server
gnus-demon nntp gnus-art mm-uu mml2015 epg-config mm-view mml-smime
smime dig mailcap gnus-sum nnoo gnus-group gnus-undo nnmail mail-source
gnus-start gnus-spec gnus-int gnus-range message rfc822 mml easymenu
mml-sec mm-decode mm-bodies mm-encode mail-parse rfc2231 rfc2047 rfc2045
ietf-drums mailabbrev gmm-utils mailheader gnus-win gnus gnus-ems
nnheader mail-utils wid-edit iso-transl notifications dbus xml tramp
tramp-compat auth-source eieio byte-opt bytecomp byte-compile cconv
macroexp assoc gnus-util time-date mm-util mail-prsvr password-cache
format-spec tramp-loaddefs ssh shell pcomplete comint regexp-opt
ansi-color ring uniquify advice help-fns advice-preload tooltip
ediff-hook vc-hooks lisp-float-type mwheel x-win x-dnd tool-bar dnd
fontset image fringe lisp-mode register page menu-bar rfn-eshadow timer
select scroll-bar mouse jit-lock font-lock syntax facemenu font-core
frame cham georgian utf-8-lang misc-lang vietnamese tibetan thai
tai-viet lao korean japanese hebrew greek romanian slovak czech european
ethiopic indian cyrillic chinese case-table epa-hook jka-cmpr-hook help
simple abbrev minibuffer loaddefs button faces cus-face files
text-properties overlay sha1 md5 base64 format env code-pages mule
custom widget hashtable-print-readable backquote make-network-process
dbusbind dynamic-setting font-render-setting x-toolkit x multi-tty
emacs)





^ permalink raw reply	[flat|nested] 64+ messages in thread

* bug#11822: 24.1; emacsclient terminal mode captures escape characters as text
  2012-06-30  0:08 bug#11822: 24.1; emacsclient terminal mode captures escape characters as text Ken Raeburn
@ 2012-06-30  5:55 ` Eli Zaretskii
  2012-07-31 21:06   ` Ken Raeburn
  0 siblings, 1 reply; 64+ messages in thread
From: Eli Zaretskii @ 2012-06-30  5:55 UTC (permalink / raw)
  To: Ken Raeburn; +Cc: 11822

> From: Ken Raeburn <raeburn@permabit.com>
> Date: Fri, 29 Jun 2012 20:08:40 -0400
> 
> I have no idea what the "error during redisplay" messages shown below
> are about

They come from safe_eval_handler, called by safe_eval when the Lisp
expression it evaluates signals an error.  This is done because
signaling an error in the usual way in this situation will re-renter
redisplay, which will then again signal an error, etc.

Can you find out which form causes this error?  This should be
something like :eval form in something the display engine needs to
evaluate, perhaps some part of the mode line.

^ permalink raw reply	[flat|nested] 64+ messages in thread

* bug#11822: 24.1; emacsclient terminal mode captures escape characters as text
  2012-06-30  5:55 ` Eli Zaretskii
@ 2012-07-31 21:06   ` Ken Raeburn
  2012-08-08  3:13     ` Ken Raeburn
  0 siblings, 1 reply; 64+ messages in thread
From: Ken Raeburn @ 2012-07-31 21:06 UTC (permalink / raw)
  To: Eli Zaretskii; +Cc: 11822

On 06/30/12 01:55, Eli Zaretskii wrote:
>> From: Ken Raeburn<raeburn@permabit.com>
>> Date: Fri, 29 Jun 2012 20:08:40 -0400
>>
>> I have no idea what the "error during redisplay" messages shown below
>> are about
>>      
> They come from safe_eval_handler, called by safe_eval when the Lisp
> expression it evaluates signals an error.  This is done because
> signaling an error in the usual way in this situation will re-renter
> redisplay, which will then again signal an error, etc.
>
> Can you find out which form causes this error?  This should be
> something like :eval form in something the display engine needs to
> evaluate, perhaps some part of the mode line.
>    

I finally ran into this one again, and tracked it down... in C mode I 
set header-line-format to hold:

   (which-func-mode ("" which-func-format))

and which-func-format uses which-func-current which evaluates

   (gethash (selected-window) which-func-table which-func-unknown)

but when my cursor is outside a function, which-func-table does contain 
an entry for the selected window, and the associated value is nil, which 
is not allowed at this point.  If I redefine which-func-current to use

   (or (gethash (selected-window) which-func-table nil)
         which-func-unknown)

then it displays "[???]" in my header line (which-func-unknown being set 
to "???"), as it should.  I don't know if it's intended that the window 
be listed in the hash with a nil value or not.

I still have not seen another occurrence of the original problem I 
reported, the control-sequence response winding up in the current buffer 
when I use emacsclient in terminal mode... I'll keep watching for it though.

Ken

^ permalink raw reply	[flat|nested] 64+ messages in thread

* bug#11822: 24.1; emacsclient terminal mode captures escape characters as text
  2012-07-31 21:06   ` Ken Raeburn
@ 2012-08-08  3:13     ` Ken Raeburn
  2012-08-08  4:52       ` Dan Nicolaescu
  0 siblings, 1 reply; 64+ messages in thread
From: Ken Raeburn @ 2012-08-08  3:13 UTC (permalink / raw)
  To: 11822

On 07/31/12 17:06, I wrote:
> I still have not seen another occurrence of the original problem I 
> reported, the control-sequence response winding up in the current 
> buffer when I use emacsclient in terminal mode... I'll keep watching 
> for it though.

The problem just occurred again.  I'm running with the fix I posted 
before, so it's not busy logging errors trying to redisplay the header line.

I was able to trigger it a second time, with emacsclient -t and no 
filename, and got "1;2403;0c" dumped in my scratch buffer after 
displaying my previously-current buffer in the terminal for a few 
seconds.  Another attempt (emacsclient -t with a filename) got me a few 
seconds of the previously-current buffer and then my file, but no extra 
characters.

I did have a window up on a remote display at the time.  I have since 
closed that window and now the startup delay and wrong-buffer display 
using emacsclient isn't happening.  I suspect they're related; I'll see 
if I can dig into that a little more....

Ken

^ permalink raw reply	[flat|nested] 64+ messages in thread

* bug#11822: 24.1; emacsclient terminal mode captures escape characters as text
  2012-08-08  3:13     ` Ken Raeburn
@ 2012-08-08  4:52       ` Dan Nicolaescu
  2012-08-08  9:26         ` Ken Raeburn
  0 siblings, 1 reply; 64+ messages in thread
From: Dan Nicolaescu @ 2012-08-08  4:52 UTC (permalink / raw)
  To: Ken Raeburn; +Cc: 11822

Ken Raeburn <raeburn@permabit.com> writes:

> On 07/31/12 17:06, I wrote:
>> I still have not seen another occurrence of the original problem I
>> reported, the control-sequence response winding up in the current
>> buffer when I use emacsclient in terminal mode... I'll keep watching
>> for it though.
>
> The problem just occurred again.  I'm running with the fix I posted
> before, so it's not busy logging errors trying to redisplay the header
> line.
>
> I was able to trigger it a second time, with emacsclient -t and no
> filename, and got "1;2403;0c" dumped in my scratch buffer after
> displaying my previously-current buffer in the terminal for a few
> seconds.  Another attempt (emacsclient -t with a filename) got me a
> few seconds of the previously-current buffer and then my file, but no
> extra characters.
>
> I did have a window up on a remote display at the time.  I have since
> closed that window and now the startup delay and wrong-buffer display
> using emacsclient isn't happening.  I suspect they're related; I'll
> see if I can dig into that a little more....

This might be the test for xterm capabilities.
You can try customizing `xterm-extra-capabilities' and see if you still
see the problem.





^ permalink raw reply	[flat|nested] 64+ messages in thread

* bug#11822: 24.1; emacsclient terminal mode captures escape characters as text
  2012-08-08  4:52       ` Dan Nicolaescu
@ 2012-08-08  9:26         ` Ken Raeburn
  2012-08-09 21:12           ` Ken Raeburn
  0 siblings, 1 reply; 64+ messages in thread
From: Ken Raeburn @ 2012-08-08  9:26 UTC (permalink / raw)
  To: Dan Nicolaescu; +Cc: 11822

On Aug 8, 2012, at 00:52, Dan Nicolaescu wrote:
> This might be the test for xterm capabilities.
> You can try customizing `xterm-extra-capabilities' and see if you still
> see the problem.

Ah, yes, it does look like that's the cause of the escape sequence reply.  Thanks for the pointer!  Customizing xterm-extra-capabilities might be one way to deal with it.

I think it's still of interest why it times out after a couple of seconds, when the response ought to be pretty quick.  If it were a distant remote login session, I could see it being slow, but this was in a local xterm (or some similar terminal emulator) window, and the system wasn't unusually loaded.

Ken

^ permalink raw reply	[flat|nested] 64+ messages in thread

* bug#11822: 24.1; emacsclient terminal mode captures escape characters as text
  2012-08-08  9:26         ` Ken Raeburn
@ 2012-08-09 21:12           ` Ken Raeburn
  2012-08-10  6:16             ` Eli Zaretskii
  0 siblings, 1 reply; 64+ messages in thread
From: Ken Raeburn @ 2012-08-09 21:12 UTC (permalink / raw)
  To: 11822

I've chased the sluggishness down a little further.

I'm using

   emacsclient -c -a "" -n

to pop up a new frame.

If I attach the Emacs process under GDB during the delay while I wait 
for the new frame to be fully displayed, the call stack tends to look 
like this:

#0  0x00007fa626cc18d8 in poll () from /lib/libc.so.6
#1  0x00007fa6265d98ca in ?? () from /usr/lib/libxcb.so.1
#2  0x00007fa6265dbc0c in xcb_wait_for_reply () from /usr/lib/libxcb.so.1
#3  0x00007fa62a0a7613 in _XReply () from /usr/lib/libX11.so.6
#4  0x00007fa62a0831a5 in XAllocColor () from /usr/lib/libX11.so.6
#5  0x00000000004b621c in x_alloc_nearest_color_1 (dpy=0x7fff726fdc40, 
cmap=1, color=0xffffffffffffffff) at xterm.c:1730
#6  0x00000000004cb023 in x_defined_color (f=0x52fff50, 
color_name=<optimized out>, color=0x7fff726fde70, alloc_p=1) at xfns.c:613
#7  0x00000000004a9adc in load_color (f=0x7fff726fdc40, face=0x53e7b70, 
name=102599361, target_index=LFACE_FOREGROUND_INDEX) at xfaces.c:1336
#8  0x00000000004abc53 in load_face_colors (attrs=<optimized out>, 
face=<optimized out>, f=<optimized out>) at xfaces.c:1422
#9  realize_x_face (attrs=<optimized out>, cache=<optimized out>) at 
xfaces.c:5629
#10 realize_face (cache=0x3e3ec30, attrs=0x7fff726fdfe0, 
former_face_id=<optimized out>) at xfaces.c:5501
#11 0x00000000004b0eed in realize_named_face (f=<optimized out>, 
symbol=<optimized out>, id=7) at xfaces.c:5473
#12 0x00000000004b1145 in realize_basic_faces (f=0x52fff50) at xfaces.c:5295
#13 0x00000000004b17cd in recompute_basic_faces (f=0x52fff50) at 
xfaces.c:839
#14 0x000000000043938d in init_iterator (it=0x7fff726fe1e0, w=0x56d0850, 
charpos=-1, bytepos=-1, row=0x0, base_face_id=DEFAULT_FACE_ID) at 
xdisp.c:2618
#15 0x000000000044962b in x_consider_frame_title (frame=<optimized out>) 
at xdisp.c:10972
#16 0x0000000000449774 in prepare_menu_bars () at xdisp.c:11031
#17 0x0000000000455b95 in redisplay_internal () at xdisp.c:12944
#18 0x0000000000456575 in redisplay_preserve_echo_area 
(from_where=1919933504) at xdisp.c:13560
#19 0x00000000005b3288 in Fdelete_process (process=69478117) at 
process.c:796
#20 0x000000000056c9fc in Ffuncall (nargs=<optimized out>, 
args=<optimized out>) at eval.c:3002
#21 0x00000000005a6ef5 in exec_byte_code (bytestr=<optimized out>, 
vector=<optimized out>, maxdepth=<optimized out>, 
args_template=<optimized out>, nargs=104812360, args=0x33a5) at 
bytecode.c:785
...

Lisp Backtrace:
"delete-process" (0x72700b50)
"server-delete-client" (0x72700ce0)
0x4c33b60 PVEC_COMPILED
"funcall" (0x72700e40)
0x4bde3c0 PVEC_COMPILED
"funcall" (0x72701260)
"server-execute" (0x727016b8)
0x4e59700 PVEC_COMPILED
0x4a72ac0 PVEC_COMPILED
"funcall" (0x72701970)
"server-execute-continuation" (0x72701de8)
...

Sometimes it's XParseColor instead of XAllocColor.

When I pop up a new frame, it appears that recompute_basic_faces is 
called three times for the new frame, and once for each existing one:

Breakpoint 3, recompute_basic_faces (f=0x4d75e00) at xfaces.c:835
835    {
(gdb) c
Continuing.

Breakpoint 3, recompute_basic_faces (f=0x4d75e00) at xfaces.c:835
835    {
(gdb)
Continuing.

Breakpoint 3, recompute_basic_faces (f=0x4d75e00) at xfaces.c:835
835    {
(gdb)
Continuing.

Breakpoint 3, recompute_basic_faces (f=0x61a7090) at xfaces.c:835
835    {
(gdb)
Continuing.

Breakpoint 3, recompute_basic_faces (f=0x698a7c0) at xfaces.c:835
835    {
(gdb)
Continuing.

...

I also noticed that the remote frame (in this case, 0x52fff50, which 
happens to be the one shown in the C stack trace above, is displayed 
over SSH + VPN + a slow net connection) takes quite a bit longer to 
process before moving on to the next recompute_basic_faces call.  I've 
been using this Emacs process actively today, including creating a few 
new frames, but haven't touched the frame displayed remotely since at 
least last night, possibly longer.  Yet this recompute_basic_faces work 
still gets done each time.


If I try creating a new tty frame, the stack trace is a bit different:

#0  0x00007fa626cc18d8 in poll () from /lib/libc.so.6
#1  0x00007fa6265d98ca in ?? () from /usr/lib/libxcb.so.1
#2  0x00007fa6265dbc0c in xcb_wait_for_reply () from /usr/lib/libxcb.so.1
#3  0x00007fa62a0a7613 in _XReply () from /usr/lib/libX11.so.6
#4  0x00007fa62a08fb11 in XParseColor () from /usr/lib/libX11.so.6
#5  0x00000000004cafa4 in x_defined_color (f=0x52fff50, 
color_name=<optimized out>, color=0x7fff726fe430, alloc_p=1) at xfns.c:611
#6  0x00000000004a9adc in load_color (f=0x7fff726fe210, face=0x4b738f0, 
name=102599489, target_index=LFACE_BACKGROUND_INDEX) at xfaces.c:1336
#7  0x00000000004abc38 in load_face_colors (attrs=<optimized out>, 
face=<optimized out>, f=<optimized out>) at xfaces.c:1421
#8  realize_x_face (attrs=<optimized out>, cache=<optimized out>) at 
xfaces.c:5629
#9  realize_face (cache=0x3e3ec30, attrs=0x7fff726fe5a0, 
former_face_id=<optimized out>) at xfaces.c:5501
#10 0x00000000004b0eed in realize_named_face (f=<optimized out>, 
symbol=<optimized out>, id=10) at xfaces.c:5473
#11 0x00000000004b1181 in realize_basic_faces (f=0x52fff50) at xfaces.c:5298
#12 0x00000000004b17cd in recompute_basic_faces (f=0x52fff50) at 
xfaces.c:839
#13 0x000000000043938d in init_iterator (it=0x7fff726fe7a0, w=0x56d0850, 
charpos=-1, bytepos=-1, row=0x0, base_face_id=DEFAULT_FACE_ID) at 
xdisp.c:2618
#14 0x000000000044962b in x_consider_frame_title (frame=<optimized out>) 
at xdisp.c:10972
#15 0x0000000000449774 in prepare_menu_bars () at xdisp.c:11031
#16 0x0000000000455b95 in redisplay_internal () at xdisp.c:12944
#17 0x0000000000503359 in read_char (commandflag=<optimized out>, 
nmaps=<optimized out>, maps=0x0, prev_event=<optimized out>, 
used_mouse_menu=<optimized out>, end_time=<optimized out>) at 
keyboard.c:2448
#18 0x000000000059416c in read_filtered_event (no_switch_frame=0, 
ascii_required=0, error_nonascii=0, input_method=0, seconds=<optimized 
out>) at lread.c:621
#19 0x000000000056c9d9 in Ffuncall (nargs=<optimized out>, 
args=<optimized out>) at eval.c:3009
#20 0x00000000005a6ef5 in exec_byte_code (bytestr=<optimized out>, 
vector=<optimized out>, maxdepth=<optimized out>, 
args_template=<optimized out>, nargs=104812360, args=0x33a5) at 
bytecode.c:785
...

Lisp Backtrace:
"read-event" (0x727014a8)
"terminal-init-xterm" (0x72701688)
"tty-run-terminal-initialization" (0x72701848)
"tty-create-frame-with-faces" (0x72701a08)
"make-frame" (0x72701bf0)
"server-create-tty-frame" (0x72701df0)
0x5f64d20 PVEC_COMPILED
...

But either way, we get into the display code and it thinks it's got to 
do the color/face setup all over again for the remote display.

That seems to be where the delay is coming from.  If, in fact, the Lisp 
code supporting the xterm type is sending its escape sequence before all 
of this is triggered, that would certainly explain why it times out and 
the response sequence winds up added to the buffer content.

Ken





^ permalink raw reply	[flat|nested] 64+ messages in thread

* bug#11822: 24.1; emacsclient terminal mode captures escape characters as text
  2012-08-09 21:12           ` Ken Raeburn
@ 2012-08-10  6:16             ` Eli Zaretskii
  2012-08-10  7:27               ` Ken Raeburn
  0 siblings, 1 reply; 64+ messages in thread
From: Eli Zaretskii @ 2012-08-10  6:16 UTC (permalink / raw)
  To: Ken Raeburn; +Cc: 11822

> Date: Thu, 09 Aug 2012 17:12:50 -0400
> From: Ken Raeburn <raeburn@permabit.com>
> 
> I've chased the sluggishness down a little further.
> 
> I'm using
> 
>    emacsclient -c -a "" -n
> 
> to pop up a new frame.
> 
> If I attach the Emacs process under GDB during the delay while I wait 
> for the new frame to be fully displayed, the call stack tends to look 
> like this:
> 
> #0  0x00007fa626cc18d8 in poll () from /lib/libc.so.6
> #1  0x00007fa6265d98ca in ?? () from /usr/lib/libxcb.so.1
> #2  0x00007fa6265dbc0c in xcb_wait_for_reply () from /usr/lib/libxcb.so.1
> #3  0x00007fa62a0a7613 in _XReply () from /usr/lib/libX11.so.6
> #4  0x00007fa62a0831a5 in XAllocColor () from /usr/lib/libX11.so.6
> #5  0x00000000004b621c in x_alloc_nearest_color_1 (dpy=0x7fff726fdc40, 
> cmap=1, color=0xffffffffffffffff) at xterm.c:1730
> #6  0x00000000004cb023 in x_defined_color (f=0x52fff50, 
> color_name=<optimized out>, color=0x7fff726fde70, alloc_p=1) at xfns.c:613
> #7  0x00000000004a9adc in load_color (f=0x7fff726fdc40, face=0x53e7b70, 
> name=102599361, target_index=LFACE_FOREGROUND_INDEX) at xfaces.c:1336
> #8  0x00000000004abc53 in load_face_colors (attrs=<optimized out>, 
> face=<optimized out>, f=<optimized out>) at xfaces.c:1422
> #9  realize_x_face (attrs=<optimized out>, cache=<optimized out>) at 
> xfaces.c:5629
> #10 realize_face (cache=0x3e3ec30, attrs=0x7fff726fdfe0, 
> former_face_id=<optimized out>) at xfaces.c:5501
> #11 0x00000000004b0eed in realize_named_face (f=<optimized out>, 
> symbol=<optimized out>, id=7) at xfaces.c:5473
> #12 0x00000000004b1145 in realize_basic_faces (f=0x52fff50) at xfaces.c:5295
> #13 0x00000000004b17cd in recompute_basic_faces (f=0x52fff50) at 
> xfaces.c:839
> #14 0x000000000043938d in init_iterator (it=0x7fff726fe1e0, w=0x56d0850, 
> charpos=-1, bytepos=-1, row=0x0, base_face_id=DEFAULT_FACE_ID) at 
> xdisp.c:2618
> #15 0x000000000044962b in x_consider_frame_title (frame=<optimized out>) 
> at xdisp.c:10972
> #16 0x0000000000449774 in prepare_menu_bars () at xdisp.c:11031
> #17 0x0000000000455b95 in redisplay_internal () at xdisp.c:12944
> #18 0x0000000000456575 in redisplay_preserve_echo_area 
> (from_where=1919933504) at xdisp.c:13560
> #19 0x00000000005b3288 in Fdelete_process (process=69478117) at 
> process.c:796
> #20 0x000000000056c9fc in Ffuncall (nargs=<optimized out>, 
> args=<optimized out>) at eval.c:3002
> #21 0x00000000005a6ef5 in exec_byte_code (bytestr=<optimized out>, 
> vector=<optimized out>, maxdepth=<optimized out>, 
> args_template=<optimized out>, nargs=104812360, args=0x33a5) at 
> bytecode.c:785
> ...
> 
> Lisp Backtrace:
> "delete-process" (0x72700b50)
> "server-delete-client" (0x72700ce0)
> 0x4c33b60 PVEC_COMPILED
> "funcall" (0x72700e40)
> 0x4bde3c0 PVEC_COMPILED
> "funcall" (0x72701260)
> "server-execute" (0x727016b8)
> 0x4e59700 PVEC_COMPILED
> 0x4a72ac0 PVEC_COMPILED
> "funcall" (0x72701970)
> "server-execute-continuation" (0x72701de8)
> ...
> 
> Sometimes it's XParseColor instead of XAllocColor.
> 
> When I pop up a new frame, it appears that recompute_basic_faces is 
> called three times for the new frame, and once for each existing one:

Actually, recompute_basic_faces can be potentially called once for
every _window_.  That's because the GUI redisplay is window-based,
i.e. it starts anew for every window that is visible.  These calls
come from here:

  /* If realized faces have been removed, e.g. because of face
     attribute changes of named faces, recompute them.  When running
     in batch mode, the face cache of the initial frame is null.  If
     we happen to get called, make a dummy face cache.  */
  if (FRAME_FACE_CACHE (it->f) == NULL)
    init_frame_faces (it->f);
  if (FRAME_FACE_CACHE (it->f)->used == 0)
    recompute_basic_faces (it->f);

Normally, the frame's face cache is not removed during redisplay of
frame's windows, so you get one call per frame.  For new frames, the
cache is empty, so you get 3 calls for each window on the new frame,
which are: the frame's selected window, the menu bar, and the tool bar
(the last two are displayed in a special kinds of window).  For
example, the backtrace above comes from displaying the menu bar.

> But either way, we get into the display code and it thinks it's got to 
> do the color/face setup all over again for the remote display.

If the face cache is empty, what else can it do?





^ permalink raw reply	[flat|nested] 64+ messages in thread

* bug#11822: 24.1; emacsclient terminal mode captures escape characters as text
  2012-08-10  6:16             ` Eli Zaretskii
@ 2012-08-10  7:27               ` Ken Raeburn
  2012-08-10  7:46                 ` Eli Zaretskii
  0 siblings, 1 reply; 64+ messages in thread
From: Ken Raeburn @ 2012-08-10  7:27 UTC (permalink / raw)
  To: Eli Zaretskii; +Cc: 11822

On Aug 10, 2012, at 02:16, Eli Zaretskii wrote:
> Normally, the frame's face cache is not removed during redisplay of
> frame's windows, so you get one call per frame.  For new frames, the
> cache is empty, so you get 3 calls for each window on the new frame,
> which are: the frame's selected window, the menu bar, and the tool bar
> (the last two are displayed in a special kinds of window).  For
> example, the backtrace above comes from displaying the menu bar.

Ah, that's interesting.  It's especially interesting considering I have menu bar and tool bar displays turned off.  The one frame (X11 window) I have on the remote display is subdivided into four Emacs windows (top vs bottom, then each of those split into left and right).  And there's the minibuffer, of course.  Currently three of those four windows have header lines, but there is no tool bar or menu bar.

> 
>> But either way, we get into the display code and it thinks it's got to 
>> do the color/face setup all over again for the remote display.
> 
> If the face cache is empty, what else can it do?

I haven't really looked at the redisplay code much, but shouldn't a cache be, I don't know, caching this stuff it keeps looking up over and over?  According to the code you quoted, it's a "face cache", and all I see is color-processing calls, but if we're not building faces, why do we need the color processing, and if we are building them, why aren't we caching them?

Oh, hmm… the code you quoted ensures that the indicated frame has a face cache, and conditionally calls recompute_basic_faces; that function checks that there is a face cache, and if so, calls clear_face_cache and then realize_basic_faces.  But clear_face_cache clears caches of all frames.  So if I understand correctly, if that function you quoted (init_iterator) is given a frame with no cache (which I assume is the state a new frame is in?), or if the cache "used" flag is clear, it'll wipe out all cached faces from all frames, so the higher-level iteration over all the frames (or windows?) will have to rebuild the faces, even if they had indeed been cached.  Is that correct?

Is there a reason recompute_basic_faces can't just clear the cache for its own frame and leave the others alone?

Ken

^ permalink raw reply	[flat|nested] 64+ messages in thread

* bug#11822: 24.1; emacsclient terminal mode captures escape characters as text
  2012-08-10  7:27               ` Ken Raeburn
@ 2012-08-10  7:46                 ` Eli Zaretskii
  2012-08-10  8:08                   ` Eli Zaretskii
  0 siblings, 1 reply; 64+ messages in thread
From: Eli Zaretskii @ 2012-08-10  7:46 UTC (permalink / raw)
  To: Ken Raeburn; +Cc: 11822

> From: Ken Raeburn <raeburn@permabit.com>
> Date: Fri, 10 Aug 2012 03:27:04 -0400
> Cc: 11822@debbugs.gnu.org
> 
> On Aug 10, 2012, at 02:16, Eli Zaretskii wrote:
> > Normally, the frame's face cache is not removed during redisplay of
> > frame's windows, so you get one call per frame.  For new frames, the
> > cache is empty, so you get 3 calls for each window on the new frame,
> > which are: the frame's selected window, the menu bar, and the tool bar
> > (the last two are displayed in a special kinds of window).  For
> > example, the backtrace above comes from displaying the menu bar.
> 
> Ah, that's interesting.  It's especially interesting considering I have menu bar and tool bar displays turned off.

Not really relevant at this point, since the traceback shows Emacs was
displaying the frame title.

The code in prepare_menu_bars is computing the menu-bar items, it does
not display them.

> I haven't really looked at the redisplay code much, but shouldn't a cache be, I don't know, caching this stuff it keeps looking up over and over?

It caches them when it can, AFAIK.  But I'm not the expert on that
part.

> According to the code you quoted, it's a "face cache", and all I see is color-processing calls, but if we're not building faces, why do we need the color processing, and if we are building them, why aren't we caching them?

There are no colors in Emacs except as face attributes.  If you need
to colorize some parts of display, you need to realize a corresponding
face.

> Oh, hmm… the code you quoted ensures that the indicated frame has a face cache, and conditionally calls recompute_basic_faces; that function checks that there is a face cache, and if so, calls clear_face_cache and then realize_basic_faces.  But clear_face_cache clears caches of all frames.  So if I understand correctly, if that function you quoted (init_iterator) is given a frame with no cache (which I assume is the state a new frame is in?), or if the cache "used" flag is clear, it'll wipe out all cached faces from all frames, so the higher-level iteration over all the frames (or windows?) will have to rebuild the faces, even if they had indeed been cached.  Is that correct?

I think so, yes.

> Is there a reason recompute_basic_faces can't just clear the cache for its own frame and leave the others alone?

Are you saying that the used flag of the frame's cache is not a
sufficient condition for clearing the face caches?






^ permalink raw reply	[flat|nested] 64+ messages in thread

* bug#11822: 24.1; emacsclient terminal mode captures escape characters as text
  2012-08-10  7:46                 ` Eli Zaretskii
@ 2012-08-10  8:08                   ` Eli Zaretskii
  2015-09-07 21:09                     ` Ken Raeburn
  0 siblings, 1 reply; 64+ messages in thread
From: Eli Zaretskii @ 2012-08-10  8:08 UTC (permalink / raw)
  To: raeburn; +Cc: 11822

> Date: Fri, 10 Aug 2012 10:46:23 +0300
> From: Eli Zaretskii <eliz@gnu.org>
> Cc: 11822@debbugs.gnu.org
> 
> > Is there a reason recompute_basic_faces can't just clear the cache for its own frame and leave the others alone?
> 
> Are you saying that the used flag of the frame's cache is not a
> sufficient condition for clearing the face caches?

According to my reading of the code: The used flag being zero means
there are no cached faces in the cache.  So clearing the cache in that
case doesn't sound like we are losing anything.

Moreover, clear_face_cache does not necessarily clear all the caches
of all frames, it does that only conditionally on this test:

  if (clear_fonts_p
      || ++clear_font_table_count == CLEAR_FONT_TABLE_COUNT)

Otherwise, it only clears the GC of each face:

  else
    {
      /* Clear GCs of realized faces.  */
      FOR_EACH_FRAME (tail, frame)
	{
	  struct frame *f = XFRAME (frame);
	  if (FRAME_WINDOW_P (f))
	      clear_face_gcs (FRAME_FACE_CACHE (f));
	}
      clear_image_caches (Qnil);
    }

Which of these happens for you?  Also, can you show the backtraces of
each call to recompute_basic_faces?

In any case, it is only worth our while to talk about the call to
recompute_basic_faces if you time these calls and see that they indeed
take a significant amount of time.  Do they?

^ permalink raw reply	[flat|nested] 64+ messages in thread

* bug#11822: 24.1; emacsclient terminal mode captures escape characters as text
  2012-08-10  8:08                   ` Eli Zaretskii
@ 2015-09-07 21:09                     ` Ken Raeburn
  2015-09-08  1:29                       ` Stefan Monnier
  2015-09-08  4:48                       ` Eli Zaretskii
  0 siblings, 2 replies; 64+ messages in thread
From: Ken Raeburn @ 2015-09-07 21:09 UTC (permalink / raw)
  To: 11822

After dropping the ball on this about three years ago, I’ve started digging into it again with version 24.5.

A recap of the problem: When I’ve got X11 frames up on the local display on my system at work, and one or more X11 frames displayed remotely over a slow-ish connection (ping round trip time 30-40ms, ssh + VPN may contribute a teeny bit more) creating a new frame causes a delay of several seconds. If I’m starting an X11 frame, even back on the local display at the office, a blank window pops up and doesn’t fill in for a few seconds. If it’s a tty frame via emacsclient, the setup code for terminal type “xterm” sends an escape sequence to the xterm to get some information but then times out reading the response, causing the response sequence to be inserted into the file being edited, which is where this bug report started. Tracing (strace, tcpdump) shows a lot of X11 network activity during the several-second delay.

In my tests to analyze this activity, I’m using two ssh connections to a test machine, each forwarding X11 connections. I start Emacs over one session (display localhost:10) with arguments telling it to invoke server-start, then I de-select Emacs’s window, wait for X11 activity to stop, and then use “emacsclient -c -n” to start an X11 frame over the other session (localhost:11). The test account has no .emacs file, and the display has only a few X resources loaded that could affect Emacs — background color, maybe foreground color.

I’m using a fast network for some of these tests, but with gdb breakpoints I can monitor the activity on the two X connections while creating the second frame. One visible issue is that there are a lot of calls to _XReply happening. This is an Xlib routine that flushes the current buffer going to the server and waits for a reply to a query just sent. By setting a breakpoint in _XReply and examining stack traces, I found that there are over 160 calls to _XReply to the first display alone, while it’s creating the new frame on the second display. Multiply by a 30-40 millisecond RTT for my VPN case and we’d be looking at about 5-6 seconds worth of delay caused by talking to the display I’m *not* trying to use at that moment. And at least some of the delay is per slow-connection frame, not per slow connection.

The biggest offenders in terms of waiting for round trips seem to be in two areas.

The first is the tool bar. Almost 100 of the _XReply calls come from within XQueryColors, called indirectly from x_disable_image. If I disable the tool bar, this set of calls goes away. I normally disable the tool bar, so I’ve mostly focused elsewhere, but I think this deserves some attention too.

The other area is 28 calls via this call stack: _XReply « XParseColor « x_defined_color « defined_color « load_color2 « load_face_colors « realize_x_face « realize_face « realize_named_face « realize_basic_faces « recompute_basic_faces « init_iterator « x_consider_frame_title « prepare_menu_bars « redisplay_internal …; plus 28 calls to XAllocColor also tracing back to x_defined_color.

Just those 56 round-trips, at 35ms RTT, would still be nearly 2 seconds of delay caused by talking to not-the-active-display.

I now believe it’s happening this way, at least in part: During frame creation, the variable face_change_count is incremented from various places. For example, Fx_create_frame ensures that various parameters are set to defaults if not set explicitly, including screenGamma; the handler for screenGamma, x_set_screen_gamma, calls Fclear_face_cache, which in addition to calling clear_face_cache (which as Eli pointed out only sometimes actually clears the cache, and doesn’t seem to be in my case), also increments face_change_count. If face_change_count is nonzero, init_iterator (which gets called on every frame, thanks to prepare_menu_bars calling x_consider_frame_title, and perhaps other ways) will call free_all_realized_faces(Qnil) which iterates over all frames, clearing the face caches; later init_iterator will call recompute_basic_faces which does all these color calls.

So…

1) For a new frame, I doubt any cache clearing is needed when setting screenGamma or other frame parameters; if there’s anything cached before we’ve finished computing the parameters, we may have computed the cached thing too early.

2) When changing screenGamma or another frame parameter does require clearing some cached values that were based on the old parameter settings, it still shouldn’t affect other frames.

3) When frames on the same display have the same relevant frame parameters, as I expect is by far the most common case, can we share info between them, so these lookups and delays will be per-display instead of per-frame?

4) If something else (changing a face attribute?) requires potentially updating all frames, maybe we can immediately do just the current frame, or the visible frames on the current display (and maybe tty frames?), and delay updates to other frames/displays briefly — say until an idle timer expires or the frame receives input, whichever happens first — so that we can give priority to user interaction on the selected frame/display?

5) Even better, can we do the other-display updates in small increments, so that once we start doing those updates we don’t have a block of 160*RTT seconds where we’re unresponsive to new user input?

6) Using XAllocNamedColor for color names not starting with “#” (i.e., for color names for which XParseColor would have to talk to the server) instead of XParseColor+XAllocColor may reduce some of the round-trip counts. Caching of color values might help too.


Previously Eli asked about how long calls to recompute_basic_faces were taking and where it was getting called from; I’ve got that data below. I did another test run under gdb with recompute_basic_faces slightly hacked to measure the time taken. Using a gdb breakpoint the time taken is shown (in the argument list — a floating-point number of seconds), and the frame’s display is shown (pointer and display-name string) if there is one, then the stack trace. In this test, both displays were over the VPN (two different ssh connections), so they’re both slow.

The first six calls are during startup of Emacs, creating the initial frame. Three of them took about two seconds each, the other three finished immediately. The last three calls are during the creation of a second frame via emacsclient on the second “display”; one against the new display that took no time, one against the new display taking 2s, and one against the old display taking 2s.

Ken

(gdb) run 
Starting program: /permabit/user/raeburn/tmp/b/src/emacs -Q -g 80x24+0+0 -e server-start
[Thread debugging using libthread_db enabled]
[New Thread 0x7fffee7fa700 (LWP 10734)]

Breakpoint 3, record_run_time_for_recompute_basic_faces (f=0x113aea8, call_time=1.9999999999999999e-06) at ../../emacs-test/src/xfaces.c:736
736	{
$1 = (Display *) 0x1375060
$2 = 0x1349d30 "localhost:10.0"
#0  record_run_time_for_recompute_basic_faces (f=0x113aea8, call_time=1.9999999999999999e-06) at ../../emacs-test/src/xfaces.c:736
#1  0x00000000004b6b57 in recompute_basic_faces (f=0x113aea8) at ../../emacs-test/src/xfaces.c:750
#2  0x0000000000422783 in x_set_font (f=0x113aea8, arg=13701857, oldval=12065650) at ../../emacs-test/src/frame.c:3353
#3  0x0000000000422c5e in x_set_frame_parameters (f=<value optimized out>, alist=<value optimized out>) at ../../emacs-test/src/frame.c:2889
#4  0x00000000004235db in x_default_parameter (f=0x113aea8, alist=<value optimized out>, prop=12283506, deflt=18067765, xprop=<value optimized out>, xclass=<value optimized out>, type=RES_TYPE_STRING) at ../../emacs-test/src/frame.c:4041
#5  0x00000000004c7863 in x_default_font_parameter (f=0x113aea8, parms=15703094) at ../../emacs-test/src/xfns.c:2832
#6  0x00000000004ceb37 in Fx_create_frame (parms=15703094) at ../../emacs-test/src/xfns.c:3049
#7  0x0000000000557132 in Ffuncall (nargs=<value optimized out>, args=<value optimized out>) at ../../emacs-test/src/eval.c:2811
#8  0x000000000058bfed in exec_byte_code (bytestr=<value optimized out>, vector=<value optimized out>, maxdepth=<value optimized out>, args_template=28, nargs=0, args=0x0) at ../../emacs-test/src/bytecode.c:916
#9  0x0000000000556bd6 in funcall_lambda (fun=9132341, nargs=<value optimized out>, arg_vector=<value optimized out>) at ../../emacs-test/src/eval.c:3044
#10 0x0000000000556ef4 in Ffuncall (nargs=<value optimized out>, args=0x8b5930) at ../../emacs-test/src/eval.c:2872
#11 0x000000000058bfed in exec_byte_code (bytestr=<value optimized out>, vector=<value optimized out>, maxdepth=<value optimized out>, args_template=185, nargs=0, args=0x0) at ../../emacs-test/src/bytecode.c:916
#12 0x0000000000556bd6 in funcall_lambda (fun=9781885, nargs=<value optimized out>, arg_vector=<value optimized out>) at ../../emacs-test/src/eval.c:3044
#13 0x0000000000556ef4 in Ffuncall (nargs=<value optimized out>, args=0x954278) at ../../emacs-test/src/eval.c:2872
#14 0x000000000058bfed in exec_byte_code (bytestr=<value optimized out>, vector=<value optimized out>, maxdepth=<value optimized out>, args_template=40, nargs=0, args=0x0) at ../../emacs-test/src/bytecode.c:916
#15 0x0000000000556bd6 in funcall_lambda (fun=9777005, nargs=<value optimized out>, arg_vector=<value optimized out>) at ../../emacs-test/src/eval.c:3044
#16 0x0000000000556ef4 in Ffuncall (nargs=<value optimized out>, args=0x952f68) at ../../emacs-test/src/eval.c:2872
#17 0x000000000058bfed in exec_byte_code (bytestr=<value optimized out>, vector=<value optimized out>, maxdepth=<value optimized out>, args_template=61, nargs=0, args=0x7fffffffe5b8) at ../../emacs-test/src/bytecode.c:916
#18 0x0000000000556ef4 in Ffuncall (nargs=<value optimized out>, args=0x8bf2f8) at ../../emacs-test/src/eval.c:2872
#19 0x000000000058bfed in exec_byte_code (bytestr=<value optimized out>, vector=<value optimized out>, maxdepth=<value optimized out>, args_template=35, nargs=0, args=0x7fffffffe6a0) at ../../emacs-test/src/bytecode.c:916
#20 0x000000000055600b in apply_lambda (fun=9168229, args=<value optimized out>, count=<value optimized out>) at ../../emacs-test/src/eval.c:2919
#21 0x00000000005562ca in eval_sub (form=<value optimized out>) at ../../emacs-test/src/eval.c:2256
#22 0x000000000055816a in Feval (form=12353302, lexical=<value optimized out>) at ../../emacs-test/src/eval.c:1996
#23 0x0000000000555b5b in internal_condition_case (bfun=<value optimized out>, handlers=<value optimized out>, hfun=<value optimized out>) at ../../emacs-test/src/eval.c:1348
#24 0x00000000004eb666 in top_level_1 (ignore=<value optimized out>) at ../../emacs-test/src/keyboard.c:1195
#25 0x0000000000555ca8 in internal_catch (tag=12112706, func=<value optimized out>, arg=<value optimized out>) at ../../emacs-test/src/eval.c:1112
#26 0x00000000004ebc12 in command_loop () at ../../emacs-test/src/keyboard.c:1156
#27 recursive_edit_1 () at ../../emacs-test/src/keyboard.c:778
#28 0x00000000004ebd6d in Frecursive_edit () at ../../emacs-test/src/keyboard.c:849
#29 0x00000000004e1047 in main (argc=6, argv=0x7fffffffea58) at ../../emacs-test/src/emacs.c:1642

Lisp Backtrace:
"x-create-frame" (0xffffdf30)
"x-create-frame-with-faces" (0xffffe0d0)
"make-frame" (0xffffe270)
"frame-initialize" (0xffffe420)
"command-line" (0xffffe5b8)
"normal-top-level" (0xffffe6a0)

Breakpoint 3, record_run_time_for_recompute_basic_faces (f=0xb95348, call_time=0.000173) at ../../emacs-test/src/xfaces.c:736
736	{
output_data is null
#0  record_run_time_for_recompute_basic_faces (f=0xb95348, call_time=0.000173) at ../../emacs-test/src/xfaces.c:736
#1  0x00000000004b6b57 in recompute_basic_faces (f=0xb95348) at ../../emacs-test/src/xfaces.c:750
#2  0x000000000044f295 in init_iterator (it=0x7fffffffce60, w=0xb95718, charpos=1, bytepos=1, row=0x0, base_face_id=DEFAULT_FACE_ID) at ../../emacs-test/src/xdisp.c:2892
#3  0x00000000004514ae in resize_mini_window (w=0xb95718, exact_p=1) at ../../emacs-test/src/xdisp.c:10940
#4  0x0000000000421594 in do_switch_frame (frame=18067117, track=<value optimized out>, for_deletion=<value optimized out>, norecord=<value optimized out>) at ../../emacs-test/src/frame.c:851
#5  0x0000000000470559 in run_window_configuration_change_hook (f=0x113aea8) at ../../emacs-test/src/window.c:3373
#6  0x00000000004198a2 in change_frame_size_1 (f=0x113aea8, new_width=<value optimized out>, new_height=<value optimized out>, pretend=false, delay=<value optimized out>, safe=<value optimized out>, pixelwise=true) at ../../emacs-test/src/dispnew.c:5654
#7  0x000000000041a11d in change_frame_size (safe=false) at ../../emacs-test/src/dispnew.c:5518
#8  do_pending_window_change (safe=false) at ../../emacs-test/src/dispnew.c:5479
#9  0x000000000041f612 in x_set_scroll_bar_width (f=0x113aea8, arg=<value optimized out>, oldval=<value optimized out>) at ../../emacs-test/src/frame.c:3607
#10 0x0000000000422db3 in x_set_frame_parameters (f=0x7ffff7ffb771, alist=<value optimized out>) at ../../emacs-test/src/frame.c:2938
#11 0x00000000004235db in x_default_parameter (f=0x113aea8, alist=<value optimized out>, prop=12236914, deflt=12065650, xprop=<value optimized out>, xclass=<value optimized out>, type=RES_TYPE_NUMBER) at ../../emacs-test/src/frame.c:4041
#12 0x00000000004cf27d in Fx_create_frame (parms=15703094) at ../../emacs-test/src/xfns.c:3215
#13 0x0000000000557132 in Ffuncall (nargs=<value optimized out>, args=<value optimized out>) at ../../emacs-test/src/eval.c:2811
#14 0x000000000058bfed in exec_byte_code (bytestr=<value optimized out>, vector=<value optimized out>, maxdepth=<value optimized out>, args_template=28, nargs=4528, args=0x0) at ../../emacs-test/src/bytecode.c:916
#15 0x0000000000556bd6 in funcall_lambda (fun=9132341, nargs=<value optimized out>, arg_vector=<value optimized out>) at ../../emacs-test/src/eval.c:3044
#16 0x0000000000556ef4 in Ffuncall (nargs=<value optimized out>, args=0x8b5930) at ../../emacs-test/src/eval.c:2872
#17 0x000000000058bfed in exec_byte_code (bytestr=<value optimized out>, vector=<value optimized out>, maxdepth=<value optimized out>, args_template=185, nargs=4528, args=0x0) at ../../emacs-test/src/bytecode.c:916
#18 0x0000000000556bd6 in funcall_lambda (fun=9781885, nargs=<value optimized out>, arg_vector=<value optimized out>) at ../../emacs-test/src/eval.c:3044
#19 0x0000000000556ef4 in Ffuncall (nargs=<value optimized out>, args=0x954278) at ../../emacs-test/src/eval.c:2872
#20 0x000000000058bfed in exec_byte_code (bytestr=<value optimized out>, vector=<value optimized out>, maxdepth=<value optimized out>, args_template=40, nargs=4528, args=0x0) at ../../emacs-test/src/bytecode.c:916
#21 0x0000000000556bd6 in funcall_lambda (fun=9777005, nargs=<value optimized out>, arg_vector=<value optimized out>) at ../../emacs-test/src/eval.c:3044
#22 0x0000000000556ef4 in Ffuncall (nargs=<value optimized out>, args=0x952f68) at ../../emacs-test/src/eval.c:2872
#23 0x000000000058bfed in exec_byte_code (bytestr=<value optimized out>, vector=<value optimized out>, maxdepth=<value optimized out>, args_template=61, nargs=4528, args=0x7fffffffe5b8) at ../../emacs-test/src/bytecode.c:916
#24 0x0000000000556ef4 in Ffuncall (nargs=<value optimized out>, args=0x8bf2f8) at ../../emacs-test/src/eval.c:2872
#25 0x000000000058bfed in exec_byte_code (bytestr=<value optimized out>, vector=<value optimized out>, maxdepth=<value optimized out>, args_template=35, nargs=4528, args=0x7fffffffe6a0) at ../../emacs-test/src/bytecode.c:916
#26 0x000000000055600b in apply_lambda (fun=9168229, args=<value optimized out>, count=<value optimized out>) at ../../emacs-test/src/eval.c:2919
#27 0x00000000005562ca in eval_sub (form=<value optimized out>) at ../../emacs-test/src/eval.c:2256
#28 0x000000000055816a in Feval (form=12353302, lexical=<value optimized out>) at ../../emacs-test/src/eval.c:1996
#29 0x0000000000555b5b in internal_condition_case (bfun=<value optimized out>, handlers=<value optimized out>, hfun=<value optimized out>) at ../../emacs-test/src/eval.c:1348
#30 0x00000000004eb666 in top_level_1 (ignore=<value optimized out>) at ../../emacs-test/src/keyboard.c:1195
#31 0x0000000000555ca8 in internal_catch (tag=12112706, func=<value optimized out>, arg=<value optimized out>) at ../../emacs-test/src/eval.c:1112
#32 0x00000000004ebc12 in command_loop () at ../../emacs-test/src/keyboard.c:1156
#33 recursive_edit_1 () at ../../emacs-test/src/keyboard.c:778
#34 0x00000000004ebd6d in Frecursive_edit () at ../../emacs-test/src/keyboard.c:849
#35 0x00000000004e1047 in main (argc=6, argv=0x7fffffffea58) at ../../emacs-test/src/emacs.c:1642

Lisp Backtrace:
"x-create-frame" (0xffffdf30)
"x-create-frame-with-faces" (0xffffe0d0)
"make-frame" (0xffffe270)
"frame-initialize" (0xffffe420)
"command-line" (0xffffe5b8)
"normal-top-level" (0xffffe6a0)

Breakpoint 3, record_run_time_for_recompute_basic_faces (f=0x113aea8, call_time=1.9987090000000001) at ../../emacs-test/src/xfaces.c:736
736	{
$3 = (Display *) 0x1375060
$4 = 0x1349d30 "localhost:10.0"
#0  record_run_time_for_recompute_basic_faces (f=0x113aea8, call_time=1.9987090000000001) at ../../emacs-test/src/xfaces.c:736
#1  0x00000000004b6b57 in recompute_basic_faces (f=0x113aea8) at ../../emacs-test/src/xfaces.c:750
#2  0x000000000044f295 in init_iterator (it=0x7fffffffce70, w=0x113c070, charpos=1, bytepos=1, row=0x0, base_face_id=DEFAULT_FACE_ID) at ../../emacs-test/src/xdisp.c:2892
#3  0x00000000004514ae in resize_mini_window (w=0x113c070, exact_p=1) at ../../emacs-test/src/xdisp.c:10940
#4  0x0000000000421594 in do_switch_frame (frame=12145485, track=<value optimized out>, for_deletion=<value optimized out>, norecord=<value optimized out>) at ../../emacs-test/src/frame.c:851
#5  0x0000000000554b0e in unbind_to (count=<value optimized out>, value=12065650) at ../../emacs-test/src/eval.c:3304
#6  0x00000000004198a2 in change_frame_size_1 (f=0x113aea8, new_width=<value optimized out>, new_height=<value optimized out>, pretend=false, delay=<value optimized out>, safe=<value optimized out>, pixelwise=true) at ../../emacs-test/src/dispnew.c:5654
#7  0x000000000041a11d in change_frame_size (safe=false) at ../../emacs-test/src/dispnew.c:5518
#8  do_pending_window_change (safe=false) at ../../emacs-test/src/dispnew.c:5479
#9  0x000000000041f612 in x_set_scroll_bar_width (f=0x113aea8, arg=<value optimized out>, oldval=<value optimized out>) at ../../emacs-test/src/frame.c:3607
#10 0x0000000000422db3 in x_set_frame_parameters (f=0x7ffff7ffb771, alist=<value optimized out>) at ../../emacs-test/src/frame.c:2938
#11 0x00000000004235db in x_default_parameter (f=0x113aea8, alist=<value optimized out>, prop=12236914, deflt=12065650, xprop=<value optimized out>, xclass=<value optimized out>, type=RES_TYPE_NUMBER) at ../../emacs-test/src/frame.c:4041
#12 0x00000000004cf27d in Fx_create_frame (parms=15703094) at ../../emacs-test/src/xfns.c:3215
#13 0x0000000000557132 in Ffuncall (nargs=<value optimized out>, args=<value optimized out>) at ../../emacs-test/src/eval.c:2811
#14 0x000000000058bfed in exec_byte_code (bytestr=<value optimized out>, vector=<value optimized out>, maxdepth=<value optimized out>, args_template=28, nargs=20406984, args=0x0) at ../../emacs-test/src/bytecode.c:916
#15 0x0000000000556bd6 in funcall_lambda (fun=9132341, nargs=<value optimized out>, arg_vector=<value optimized out>) at ../../emacs-test/src/eval.c:3044
#16 0x0000000000556ef4 in Ffuncall (nargs=<value optimized out>, args=0x8b5930) at ../../emacs-test/src/eval.c:2872
#17 0x000000000058bfed in exec_byte_code (bytestr=<value optimized out>, vector=<value optimized out>, maxdepth=<value optimized out>, args_template=185, nargs=20406984, args=0x0) at ../../emacs-test/src/bytecode.c:916
#18 0x0000000000556bd6 in funcall_lambda (fun=9781885, nargs=<value optimized out>, arg_vector=<value optimized out>) at ../../emacs-test/src/eval.c:3044
#19 0x0000000000556ef4 in Ffuncall (nargs=<value optimized out>, args=0x954278) at ../../emacs-test/src/eval.c:2872
#20 0x000000000058bfed in exec_byte_code (bytestr=<value optimized out>, vector=<value optimized out>, maxdepth=<value optimized out>, args_template=40, nargs=20406984, args=0x0) at ../../emacs-test/src/bytecode.c:916
#21 0x0000000000556bd6 in funcall_lambda (fun=9777005, nargs=<value optimized out>, arg_vector=<value optimized out>) at ../../emacs-test/src/eval.c:3044
#22 0x0000000000556ef4 in Ffuncall (nargs=<value optimized out>, args=0x952f68) at ../../emacs-test/src/eval.c:2872
#23 0x000000000058bfed in exec_byte_code (bytestr=<value optimized out>, vector=<value optimized out>, maxdepth=<value optimized out>, args_template=61, nargs=20406984, args=0x7fffffffe5b8) at ../../emacs-test/src/bytecode.c:916
#24 0x0000000000556ef4 in Ffuncall (nargs=<value optimized out>, args=0x8bf2f8) at ../../emacs-test/src/eval.c:2872
#25 0x000000000058bfed in exec_byte_code (bytestr=<value optimized out>, vector=<value optimized out>, maxdepth=<value optimized out>, args_template=35, nargs=20406984, args=0x7fffffffe6a0) at ../../emacs-test/src/bytecode.c:916
#26 0x000000000055600b in apply_lambda (fun=9168229, args=<value optimized out>, count=<value optimized out>) at ../../emacs-test/src/eval.c:2919
#27 0x00000000005562ca in eval_sub (form=<value optimized out>) at ../../emacs-test/src/eval.c:2256
#28 0x000000000055816a in Feval (form=12353302, lexical=<value optimized out>) at ../../emacs-test/src/eval.c:1996
#29 0x0000000000555b5b in internal_condition_case (bfun=<value optimized out>, handlers=<value optimized out>, hfun=<value optimized out>) at ../../emacs-test/src/eval.c:1348
#30 0x00000000004eb666 in top_level_1 (ignore=<value optimized out>) at ../../emacs-test/src/keyboard.c:1195
#31 0x0000000000555ca8 in internal_catch (tag=12112706, func=<value optimized out>, arg=<value optimized out>) at ../../emacs-test/src/eval.c:1112
#32 0x00000000004ebc12 in command_loop () at ../../emacs-test/src/keyboard.c:1156
#33 recursive_edit_1 () at ../../emacs-test/src/keyboard.c:778
#34 0x00000000004ebd6d in Frecursive_edit () at ../../emacs-test/src/keyboard.c:849
#35 0x00000000004e1047 in main (argc=6, argv=0x7fffffffea58) at ../../emacs-test/src/emacs.c:1642

Lisp Backtrace:
"x-create-frame" (0xffffdf30)
"x-create-frame-with-faces" (0xffffe0d0)
"make-frame" (0xffffe270)
"frame-initialize" (0xffffe420)
"command-line" (0xffffe5b8)
"normal-top-level" (0xffffe6a0)

Breakpoint 3, record_run_time_for_recompute_basic_faces (f=0xb95348, call_time=8.2000000000000001e-05) at ../../emacs-test/src/xfaces.c:736
736	{
output_data is null
#0  record_run_time_for_recompute_basic_faces (f=0xb95348, call_time=8.2000000000000001e-05) at ../../emacs-test/src/xfaces.c:736
#1  0x00000000004b6b57 in recompute_basic_faces (f=0xb95348) at ../../emacs-test/src/xfaces.c:750
#2  0x000000000044f295 in init_iterator (it=0x7fffffffd170, w=0xb95718, charpos=1, bytepos=1, row=0x0, base_face_id=DEFAULT_FACE_ID) at ../../emacs-test/src/xdisp.c:2892
#3  0x00000000004514ae in resize_mini_window (w=0xb95718, exact_p=1) at ../../emacs-test/src/xdisp.c:10940
#4  0x0000000000421594 in do_switch_frame (frame=18067117, track=<value optimized out>, for_deletion=<value optimized out>, norecord=<value optimized out>) at ../../emacs-test/src/frame.c:851
#5  0x00000000005571aa in Ffuncall (nargs=<value optimized out>, args=<value optimized out>) at ../../emacs-test/src/eval.c:2814
#6  0x000000000058bfed in exec_byte_code (bytestr=<value optimized out>, vector=<value optimized out>, maxdepth=<value optimized out>, args_template=8, nargs=4528, args=0x7fffffffe0d0) at ../../emacs-test/src/bytecode.c:916
#7  0x0000000000556ef4 in Ffuncall (nargs=<value optimized out>, args=0x924b18) at ../../emacs-test/src/eval.c:2872
#8  0x000000000058bfed in exec_byte_code (bytestr=<value optimized out>, vector=<value optimized out>, maxdepth=<value optimized out>, args_template=185, nargs=4528, args=0x0) at ../../emacs-test/src/bytecode.c:916
#9  0x0000000000556bd6 in funcall_lambda (fun=9781885, nargs=<value optimized out>, arg_vector=<value optimized out>) at ../../emacs-test/src/eval.c:3044
#10 0x0000000000556ef4 in Ffuncall (nargs=<value optimized out>, args=0x954278) at ../../emacs-test/src/eval.c:2872
#11 0x000000000058bfed in exec_byte_code (bytestr=<value optimized out>, vector=<value optimized out>, maxdepth=<value optimized out>, args_template=40, nargs=4528, args=0x0) at ../../emacs-test/src/bytecode.c:916
#12 0x0000000000556bd6 in funcall_lambda (fun=9777005, nargs=<value optimized out>, arg_vector=<value optimized out>) at ../../emacs-test/src/eval.c:3044
#13 0x0000000000556ef4 in Ffuncall (nargs=<value optimized out>, args=0x952f68) at ../../emacs-test/src/eval.c:2872
#14 0x000000000058bfed in exec_byte_code (bytestr=<value optimized out>, vector=<value optimized out>, maxdepth=<value optimized out>, args_template=61, nargs=4528, args=0x7fffffffe5b8) at ../../emacs-test/src/bytecode.c:916
#15 0x0000000000556ef4 in Ffuncall (nargs=<value optimized out>, args=0x8bf2f8) at ../../emacs-test/src/eval.c:2872
#16 0x000000000058bfed in exec_byte_code (bytestr=<value optimized out>, vector=<value optimized out>, maxdepth=<value optimized out>, args_template=35, nargs=4528, args=0x7fffffffe6a0) at ../../emacs-test/src/bytecode.c:916
#17 0x000000000055600b in apply_lambda (fun=9168229, args=<value optimized out>, count=<value optimized out>) at ../../emacs-test/src/eval.c:2919
#18 0x00000000005562ca in eval_sub (form=<value optimized out>) at ../../emacs-test/src/eval.c:2256
#19 0x000000000055816a in Feval (form=12353302, lexical=<value optimized out>) at ../../emacs-test/src/eval.c:1996
#20 0x0000000000555b5b in internal_condition_case (bfun=<value optimized out>, handlers=<value optimized out>, hfun=<value optimized out>) at ../../emacs-test/src/eval.c:1348
#21 0x00000000004eb666 in top_level_1 (ignore=<value optimized out>) at ../../emacs-test/src/keyboard.c:1195
#22 0x0000000000555ca8 in internal_catch (tag=12112706, func=<value optimized out>, arg=<value optimized out>) at ../../emacs-test/src/eval.c:1112
#23 0x00000000004ebc12 in command_loop () at ../../emacs-test/src/keyboard.c:1156
#24 recursive_edit_1 () at ../../emacs-test/src/keyboard.c:778
#25 0x00000000004ebd6d in Frecursive_edit () at ../../emacs-test/src/keyboard.c:849
#26 0x00000000004e1047 in main (argc=6, argv=0x7fffffffea58) at ../../emacs-test/src/emacs.c:1642

Lisp Backtrace:
"select-frame" (0xffffdf88)
"normal-erase-is-backspace-setup-frame" (0xffffe0d0)
"make-frame" (0xffffe270)
"frame-initialize" (0xffffe420)
"command-line" (0xffffe5b8)
"normal-top-level" (0xffffe6a0)

Breakpoint 3, record_run_time_for_recompute_basic_faces (f=0x113aea8, call_time=2.256821) at ../../emacs-test/src/xfaces.c:736
736	{
$5 = (Display *) 0x1375060
$6 = 0x1349d30 "localhost:10.0"
#0  record_run_time_for_recompute_basic_faces (f=0x113aea8, call_time=2.256821) at ../../emacs-test/src/xfaces.c:736
#1  0x00000000004b6b57 in recompute_basic_faces (f=0x113aea8) at ../../emacs-test/src/xfaces.c:750
#2  0x000000000044f295 in init_iterator (it=0x7fffffffcf10, w=0x113c070, charpos=1, bytepos=1, row=0x0, base_face_id=DEFAULT_FACE_ID) at ../../emacs-test/src/xdisp.c:2892
#3  0x00000000004514ae in resize_mini_window (w=0x113c070, exact_p=1) at ../../emacs-test/src/xdisp.c:10940
#4  0x0000000000421594 in do_switch_frame (frame=12145485, track=<value optimized out>, for_deletion=<value optimized out>, norecord=<value optimized out>) at ../../emacs-test/src/frame.c:851
#5  0x00000000005571aa in Ffuncall (nargs=<value optimized out>, args=<value optimized out>) at ../../emacs-test/src/eval.c:2814
#6  0x000000000058bfed in exec_byte_code (bytestr=<value optimized out>, vector=<value optimized out>, maxdepth=<value optimized out>, args_template=11, nargs=20406984, args=0x7fffffffde38) at ../../emacs-test/src/bytecode.c:916
#7  0x0000000000556ef4 in Ffuncall (nargs=<value optimized out>, args=0x11a7748) at ../../emacs-test/src/eval.c:2872
#8  0x0000000000556762 in eval_sub (form=<value optimized out>) at ../../emacs-test/src/eval.c:2154
#9  0x0000000000556945 in Fprogn (body=<value optimized out>) at ../../emacs-test/src/eval.c:462
#10 0x0000000000554b0e in unbind_to (count=<value optimized out>, value=12065650) at ../../emacs-test/src/eval.c:3304
#11 0x000000000058c03f in exec_byte_code (bytestr=<value optimized out>, vector=<value optimized out>, maxdepth=<value optimized out>, args_template=101, nargs=20406984, args=0x7fffffffe0d0) at ../../emacs-test/src/bytecode.c:938
#12 0x0000000000556ef4 in Ffuncall (nargs=<value optimized out>, args=0x924b18) at ../../emacs-test/src/eval.c:2872
#13 0x000000000058bfed in exec_byte_code (bytestr=<value optimized out>, vector=<value optimized out>, maxdepth=<value optimized out>, args_template=185, nargs=20406984, args=0x0) at ../../emacs-test/src/bytecode.c:916
#14 0x0000000000556bd6 in funcall_lambda (fun=9781885, nargs=<value optimized out>, arg_vector=<value optimized out>) at ../../emacs-test/src/eval.c:3044
#15 0x0000000000556ef4 in Ffuncall (nargs=<value optimized out>, args=0x954278) at ../../emacs-test/src/eval.c:2872
#16 0x000000000058bfed in exec_byte_code (bytestr=<value optimized out>, vector=<value optimized out>, maxdepth=<value optimized out>, args_template=40, nargs=20406984, args=0x0) at ../../emacs-test/src/bytecode.c:916
#17 0x0000000000556bd6 in funcall_lambda (fun=9777005, nargs=<value optimized out>, arg_vector=<value optimized out>) at ../../emacs-test/src/eval.c:3044
#18 0x0000000000556ef4 in Ffuncall (nargs=<value optimized out>, args=0x952f68) at ../../emacs-test/src/eval.c:2872
#19 0x000000000058bfed in exec_byte_code (bytestr=<value optimized out>, vector=<value optimized out>, maxdepth=<value optimized out>, args_template=61, nargs=20406984, args=0x7fffffffe5b8) at ../../emacs-test/src/bytecode.c:916
#20 0x0000000000556ef4 in Ffuncall (nargs=<value optimized out>, args=0x8bf2f8) at ../../emacs-test/src/eval.c:2872
#21 0x000000000058bfed in exec_byte_code (bytestr=<value optimized out>, vector=<value optimized out>, maxdepth=<value optimized out>, args_template=35, nargs=20406984, args=0x7fffffffe6a0) at ../../emacs-test/src/bytecode.c:916
#22 0x000000000055600b in apply_lambda (fun=9168229, args=<value optimized out>, count=<value optimized out>) at ../../emacs-test/src/eval.c:2919
#23 0x00000000005562ca in eval_sub (form=<value optimized out>) at ../../emacs-test/src/eval.c:2256
#24 0x000000000055816a in Feval (form=12353302, lexical=<value optimized out>) at ../../emacs-test/src/eval.c:1996
#25 0x0000000000555b5b in internal_condition_case (bfun=<value optimized out>, handlers=<value optimized out>, hfun=<value optimized out>) at ../../emacs-test/src/eval.c:1348
#26 0x00000000004eb666 in top_level_1 (ignore=<value optimized out>) at ../../emacs-test/src/keyboard.c:1195
#27 0x0000000000555ca8 in internal_catch (tag=12112706, func=<value optimized out>, arg=<value optimized out>) at ../../emacs-test/src/eval.c:1112
#28 0x00000000004ebc12 in command_loop () at ../../emacs-test/src/keyboard.c:1156
#29 recursive_edit_1 () at ../../emacs-test/src/keyboard.c:778
#30 0x00000000004ebd6d in Frecursive_edit () at ../../emacs-test/src/keyboard.c:849
#31 0x00000000004e1047 in main (argc=6, argv=0x7fffffffea58) at ../../emacs-test/src/emacs.c:1642

Lisp Backtrace:
"select-frame" (0xffffdd10)
0x11a7748 PVEC_COMPILED
"funcall" (0xffffde30)
"normal-erase-is-backspace-setup-frame" (0xffffe0d0)
"make-frame" (0xffffe270)
"frame-initialize" (0xffffe420)
"command-line" (0xffffe5b8)
"normal-top-level" (0xffffe6a0)

Breakpoint 3, record_run_time_for_recompute_basic_faces (f=0x113aea8, call_time=2.2144699999999999) at ../../emacs-test/src/xfaces.c:736
736	{
$7 = (Display *) 0x1375060
$8 = 0x1349d30 "localhost:10.0"
#0  record_run_time_for_recompute_basic_faces (f=0x113aea8, call_time=2.2144699999999999) at ../../emacs-test/src/xfaces.c:736
#1  0x00000000004b6b57 in recompute_basic_faces (f=0x113aea8) at ../../emacs-test/src/xfaces.c:750
#2  0x000000000044f295 in init_iterator (it=0x7fffffffd190, w=0x113c070, charpos=1, bytepos=1, row=0x0, base_face_id=DEFAULT_FACE_ID) at ../../emacs-test/src/xdisp.c:2892
#3  0x00000000004514ae in resize_mini_window (w=0x113c070, exact_p=0) at ../../emacs-test/src/xdisp.c:10940
#4  0x0000000000457af0 in display_echo_area_1 (a1=18067112, a2=<value optimized out>) at ../../emacs-test/src/xdisp.c:10834
#5  0x0000000000447c84 in with_echo_area_buffer (w=0x113c070, which=<value optimized out>, fn=<value optimized out>, a1=<value optimized out>, a2=12065650) at ../../emacs-test/src/xdisp.c:10624
#6  0x00000000004595a5 in display_echo_area (update_frame_p=1) at ../../emacs-test/src/xdisp.c:10804
#7  echo_area_display (update_frame_p=1) at ../../emacs-test/src/xdisp.c:11296
#8  0x0000000000459966 in message3_nolog (m=12745281) at ../../emacs-test/src/xdisp.c:10299
#9  0x0000000000459b9e in message3 (m=12745281) at ../../emacs-test/src/xdisp.c:10241
#10 0x0000000000551c4b in Fmessage (nargs=<value optimized out>, args=<value optimized out>) at ../../emacs-test/src/editfns.c:3452
#11 0x0000000000556ff4 in Ffuncall (nargs=<value optimized out>, args=<value optimized out>) at ../../emacs-test/src/eval.c:2792
#12 0x000000000058bfed in exec_byte_code (bytestr=<value optimized out>, vector=<value optimized out>, maxdepth=<value optimized out>, args_template=52, nargs=20406984, args=0x7fffffffe268) at ../../emacs-test/src/bytecode.c:916
#13 0x0000000000556ef4 in Ffuncall (nargs=<value optimized out>, args=0x8c51d0) at ../../emacs-test/src/eval.c:2872
#14 0x000000000058bfed in exec_byte_code (bytestr=<value optimized out>, vector=<value optimized out>, maxdepth=<value optimized out>, args_template=1, nargs=20406984, args=0x7fffffffe420) at ../../emacs-test/src/bytecode.c:916
#15 0x0000000000556ef4 in Ffuncall (nargs=<value optimized out>, args=0x8c5600) at ../../emacs-test/src/eval.c:2872
#16 0x000000000058bfed in exec_byte_code (bytestr=<value optimized out>, vector=<value optimized out>, maxdepth=<value optimized out>, args_template=162, nargs=20406984, args=0x7fffffffe5b8) at ../../emacs-test/src/bytecode.c:916
#17 0x0000000000556ef4 in Ffuncall (nargs=<value optimized out>, args=0x8bf2f8) at ../../emacs-test/src/eval.c:2872
#18 0x000000000058bfed in exec_byte_code (bytestr=<value optimized out>, vector=<value optimized out>, maxdepth=<value optimized out>, args_template=35, nargs=20406984, args=0x7fffffffe6a0) at ../../emacs-test/src/bytecode.c:916
#19 0x000000000055600b in apply_lambda (fun=9168229, args=<value optimized out>, count=<value optimized out>) at ../../emacs-test/src/eval.c:2919
#20 0x00000000005562ca in eval_sub (form=<value optimized out>) at ../../emacs-test/src/eval.c:2256
#21 0x000000000055816a in Feval (form=12353302, lexical=<value optimized out>) at ../../emacs-test/src/eval.c:1996
#22 0x0000000000555b5b in internal_condition_case (bfun=<value optimized out>, handlers=<value optimized out>, hfun=<value optimized out>) at ../../emacs-test/src/eval.c:1348
#23 0x00000000004eb666 in top_level_1 (ignore=<value optimized out>) at ../../emacs-test/src/keyboard.c:1195
#24 0x0000000000555ca8 in internal_catch (tag=12112706, func=<value optimized out>, arg=<value optimized out>) at ../../emacs-test/src/eval.c:1112
#25 0x00000000004ebc12 in command_loop () at ../../emacs-test/src/keyboard.c:1156
#26 recursive_edit_1 () at ../../emacs-test/src/keyboard.c:778
#27 0x00000000004ebd6d in Frecursive_edit () at ../../emacs-test/src/keyboard.c:849
#28 0x00000000004e1047 in main (argc=6, argv=0x7fffffffea58) at ../../emacs-test/src/emacs.c:1642

Lisp Backtrace:
"message" (0xffffe120)
"display-startup-echo-area-message" (0xffffe268)
"command-line-1" (0xffffe420)
"command-line" (0xffffe5b8)
"normal-top-level" (0xffffe6a0)

~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
creating new frame on new display via emacsclient:

Breakpoint 3, record_run_time_for_recompute_basic_faces (f=0x1187368, call_time=1.9999999999999999e-06) at ../../emacs-test/src/xfaces.c:736
736	{
$9 = (Display *) 0xcc6e30
$10 = 0xc1fe30 "localhost:11.0"
#0  record_run_time_for_recompute_basic_faces (f=0x1187368, call_time=1.9999999999999999e-06) at ../../emacs-test/src/xfaces.c:736
#1  0x00000000004b6b57 in recompute_basic_faces (f=0x1187368) at ../../emacs-test/src/xfaces.c:750
#2  0x0000000000422783 in x_set_font (f=0x1187368, arg=13397377, oldval=12065650) at ../../emacs-test/src/frame.c:3353
#3  0x0000000000422c5e in x_set_frame_parameters (f=<value optimized out>, alist=<value optimized out>) at ../../emacs-test/src/frame.c:2889
#4  0x00000000004235db in x_default_parameter (f=0x1187368, alist=<value optimized out>, prop=12283506, deflt=18388085, xprop=<value optimized out>, xclass=<value optimized out>, type=RES_TYPE_STRING) at ../../emacs-test/src/frame.c:4041
#5  0x00000000004c7863 in x_default_font_parameter (f=0x1187368, parms=12170678) at ../../emacs-test/src/xfns.c:2832
#6  0x00000000004ceb37 in Fx_create_frame (parms=12170678) at ../../emacs-test/src/xfns.c:3049
#7  0x0000000000557132 in Ffuncall (nargs=<value optimized out>, args=<value optimized out>) at ../../emacs-test/src/eval.c:2811
#8  0x000000000058bfed in exec_byte_code (bytestr=<value optimized out>, vector=<value optimized out>, maxdepth=<value optimized out>, args_template=28, nargs=0, args=0x0) at ../../emacs-test/src/bytecode.c:916
#9  0x0000000000556bd6 in funcall_lambda (fun=9132341, nargs=<value optimized out>, arg_vector=<value optimized out>) at ../../emacs-test/src/eval.c:3044
#10 0x0000000000556ef4 in Ffuncall (nargs=<value optimized out>, args=0x8b5930) at ../../emacs-test/src/eval.c:2872
#11 0x000000000058bfed in exec_byte_code (bytestr=<value optimized out>, vector=<value optimized out>, maxdepth=<value optimized out>, args_template=185, nargs=0, args=0x0) at ../../emacs-test/src/bytecode.c:916
#12 0x0000000000556bd6 in funcall_lambda (fun=9781885, nargs=<value optimized out>, arg_vector=<value optimized out>) at ../../emacs-test/src/eval.c:3044
#13 0x0000000000556ef4 in Ffuncall (nargs=<value optimized out>, args=0x954278) at ../../emacs-test/src/eval.c:2872
#14 0x000000000058bfed in exec_byte_code (bytestr=<value optimized out>, vector=<value optimized out>, maxdepth=<value optimized out>, args_template=12065650, nargs=0, args=0x0) at ../../emacs-test/src/bytecode.c:916
#15 0x0000000000556bd6 in funcall_lambda (fun=9780181, nargs=<value optimized out>, arg_vector=<value optimized out>) at ../../emacs-test/src/eval.c:3044
#16 0x0000000000556ef4 in Ffuncall (nargs=<value optimized out>, args=0x953bd0) at ../../emacs-test/src/eval.c:2872
#17 0x000000000058bfed in exec_byte_code (bytestr=<value optimized out>, vector=<value optimized out>, maxdepth=<value optimized out>, args_template=86, nargs=0, args=0x7fffffffc348) at ../../emacs-test/src/bytecode.c:916
#18 0x0000000000556ef4 in Ffuncall (nargs=<value optimized out>, args=0x117b518) at ../../emacs-test/src/eval.c:2872
#19 0x000000000058bfed in exec_byte_code (bytestr=<value optimized out>, vector=<value optimized out>, maxdepth=<value optimized out>, args_template=72, nargs=0, args=0x7fffffffc4d8) at ../../emacs-test/src/bytecode.c:916
#20 0x0000000000556ef4 in Ffuncall (nargs=<value optimized out>, args=0x1186640) at ../../emacs-test/src/eval.c:2872
#21 0x0000000000556762 in eval_sub (form=<value optimized out>) at ../../emacs-test/src/eval.c:2154
#22 0x00000000005591c9 in internal_lisp_condition_case (var=13695362, bodyform=<value optimized out>, handlers=<value optimized out>) at ../../emacs-test/src/eval.c:1317
#23 0x000000000058dbe1 in exec_byte_code (bytestr=<value optimized out>, vector=<value optimized out>, maxdepth=<value optimized out>, args_template=107, nargs=0, args=0x7fffffffc7b8) at ../../emacs-test/src/bytecode.c:1162
#24 0x0000000000556ef4 in Ffuncall (nargs=<value optimized out>, args=0x1185500) at ../../emacs-test/src/eval.c:2872
#25 0x0000000000556762 in eval_sub (form=<value optimized out>) at ../../emacs-test/src/eval.c:2154
#26 0x0000000000555ca8 in internal_catch (tag=13695266, func=<value optimized out>, arg=<value optimized out>) at ../../emacs-test/src/eval.c:1112
#27 0x000000000058da03 in exec_byte_code (bytestr=<value optimized out>, vector=<value optimized out>, maxdepth=<value optimized out>, args_template=2, nargs=0, args=0x7fffffffca28) at ../../emacs-test/src/bytecode.c:1097
#28 0x0000000000556ef4 in Ffuncall (nargs=<value optimized out>, args=0x1193758) at ../../emacs-test/src/eval.c:2872
#29 0x0000000000558c0c in Fapply (nargs=<value optimized out>, args=0x7fffffffcad0) at ../../emacs-test/src/eval.c:2350
#30 0x0000000000558e50 in apply1 (fn=13694242, arg=<value optimized out>) at ../../emacs-test/src/eval.c:2584
#31 0x0000000000555a45 in internal_condition_case_1 (bfun=<value optimized out>, arg=<value optimized out>, handlers=<value optimized out>, hfun=<value optimized out>) at ../../emacs-test/src/eval.c:1372
#32 0x0000000000590fd4 in read_and_dispose_of_process_output (proc=<value optimized out>, channel=<value optimized out>) at ../../emacs-test/src/process.c:5180
#33 read_process_output (proc=<value optimized out>, channel=<value optimized out>) at ../../emacs-test/src/process.c:5089
#34 0x0000000000594c3f in wait_reading_process_output (time_limit=<value optimized out>, nsecs=<value optimized out>, read_kbd=<value optimized out>, do_display=<value optimized out>, wait_for_cell=<value optimized out>, wait_proc=0x0, just_wait_proc=0) at ../../emacs-test/src/process.c:4811
#35 0x00000000004ed706 in kbd_buffer_get_event (end_time=0x0, local_getcjmp=<value optimized out>, prev_event=<value optimized out>, used_mouse_menu=<value optimized out>) at ../../emacs-test/src/keyboard.c:3907
#36 read_event_from_main_queue (end_time=0x0, local_getcjmp=<value optimized out>, prev_event=<value optimized out>, used_mouse_menu=<value optimized out>) at ../../emacs-test/src/keyboard.c:2247
#37 read_decoded_event_from_main_queue (end_time=0x0, local_getcjmp=<value optimized out>, prev_event=<value optimized out>, used_mouse_menu=<value optimized out>) at ../../emacs-test/src/keyboard.c:2311
#38 0x00000000004ef1c8 in read_char (commandflag=<value optimized out>, map=<value optimized out>, prev_event=<value optimized out>, used_mouse_menu=<value optimized out>, end_time=<value optimized out>) at ../../emacs-test/src/keyboard.c:2896
#39 0x00000000004f0d23 in read_key_sequence (keybuf=<value optimized out>, prompt=<value optimized out>, dont_downcase_last=<value optimized out>, can_return_switch_frame=<value optimized out>, fix_current_buffer=<value optimized out>, prevent_redisplay=<value optimized out>, bufsize=<value optimized out>) at ../../emacs-test/src/keyboard.c:9089
#40 0x00000000004f21a2 in command_loop_1 () at ../../emacs-test/src/keyboard.c:1453
#41 0x0000000000555b5b in internal_condition_case (bfun=<value optimized out>, handlers=<value optimized out>, hfun=<value optimized out>) at ../../emacs-test/src/eval.c:1348
#42 0x00000000004eb42e in command_loop_2 (ignore=<value optimized out>) at ../../emacs-test/src/keyboard.c:1178
#43 0x0000000000555ca8 in internal_catch (tag=12112706, func=<value optimized out>, arg=<value optimized out>) at ../../emacs-test/src/eval.c:1112
#44 0x00000000004ebc2a in command_loop () at ../../emacs-test/src/keyboard.c:1157
#45 recursive_edit_1 () at ../../emacs-test/src/keyboard.c:778
#46 0x00000000004ebd6d in Frecursive_edit () at ../../emacs-test/src/keyboard.c:849
#47 0x00000000004e1047 in main (argc=6, argv=0x7fffffffea58) at ../../emacs-test/src/emacs.c:1642

Lisp Backtrace:
"x-create-frame" (0xffffbc70)
"x-create-frame-with-faces" (0xffffbe10)
"make-frame" (0xffffbfb0)
"make-frame-on-display" (0xffffc188)
"server-create-window-system-frame" (0xffffc348)
0x1186640 PVEC_COMPILED
"funcall" (0xffffc4d0)
0x1185500 PVEC_COMPILED
"funcall" (0xffffc7b0)
"server-process-filter" (0xffffca28)

Breakpoint 3, record_run_time_for_recompute_basic_faces (f=0x1187368, call_time=2.189079) at ../../emacs-test/src/xfaces.c:736
736	{
$11 = (Display *) 0xcc6e30
$12 = 0xc1fe30 "localhost:11.0"
#0  record_run_time_for_recompute_basic_faces (f=0x1187368, call_time=2.189079) at ../../emacs-test/src/xfaces.c:736
#1  0x00000000004b6b57 in recompute_basic_faces (f=0x1187368) at ../../emacs-test/src/xfaces.c:750
#2  0x000000000044f295 in init_iterator (it=0x7fffffff8bd0, w=0x1188378, charpos=-1, bytepos=-1, row=0x0, base_face_id=DEFAULT_FACE_ID) at ../../emacs-test/src/xdisp.c:2892
#3  0x000000000044fcdf in x_consider_frame_title (frame=<value optimized out>) at ../../emacs-test/src/xdisp.c:11650
#4  0x000000000045889e in prepare_menu_bars () at ../../emacs-test/src/xdisp.c:11752
#5  redisplay_internal () at ../../emacs-test/src/xdisp.c:13610
#6  0x0000000000459400 in redisplay_preserve_echo_area (from_where=18379624) at ../../emacs-test/src/xdisp.c:14206
#7  0x0000000000593aa4 in Fdelete_process (process=<value optimized out>) at ../../emacs-test/src/process.c:897
#8  0x0000000000557132 in Ffuncall (nargs=<value optimized out>, args=<value optimized out>) at ../../emacs-test/src/eval.c:2811
#9  0x000000000058bfed in exec_byte_code (bytestr=<value optimized out>, vector=<value optimized out>, maxdepth=<value optimized out>, args_template=194, nargs=20406984, args=0x7fffffffb628) at ../../emacs-test/src/bytecode.c:916
#10 0x0000000000556ef4 in Ffuncall (nargs=<value optimized out>, args=0x1130140) at ../../emacs-test/src/eval.c:2872
#11 0x000000000058bfed in exec_byte_code (bytestr=<value optimized out>, vector=<value optimized out>, maxdepth=<value optimized out>, args_template=76, nargs=20406984, args=0x7fffffffb758) at ../../emacs-test/src/bytecode.c:916
#12 0x0000000000556ef4 in Ffuncall (nargs=<value optimized out>, args=0x1104528) at ../../emacs-test/src/eval.c:2872
#13 0x0000000000556762 in eval_sub (form=<value optimized out>) at ../../emacs-test/src/eval.c:2154
#14 0x00000000005591c9 in internal_lisp_condition_case (var=13695602, bodyform=<value optimized out>, handlers=<value optimized out>) at ../../emacs-test/src/eval.c:1317
#15 0x000000000058dbe1 in exec_byte_code (bytestr=<value optimized out>, vector=<value optimized out>, maxdepth=<value optimized out>, args_template=0, nargs=20406984, args=0x7fffffffba58) at ../../emacs-test/src/bytecode.c:1162
#16 0x0000000000556ef4 in Ffuncall (nargs=<value optimized out>, args=0x11af968) at ../../emacs-test/src/eval.c:2872
#17 0x0000000000556762 in eval_sub (form=<value optimized out>) at ../../emacs-test/src/eval.c:2154
#18 0x00000000005591c9 in internal_lisp_condition_case (var=13695554, bodyform=<value optimized out>, handlers=<value optimized out>) at ../../emacs-test/src/eval.c:1317
#19 0x000000000058dbe1 in exec_byte_code (bytestr=<value optimized out>, vector=<value optimized out>, maxdepth=<value optimized out>, args_template=7, nargs=20406984, args=0x7fffffffbd80) at ../../emacs-test/src/bytecode.c:1162
#20 0x0000000000556ef4 in Ffuncall (nargs=<value optimized out>, args=0x117e648) at ../../emacs-test/src/eval.c:2872
#21 0x000000000058bfed in exec_byte_code (bytestr=<value optimized out>, vector=<value optimized out>, maxdepth=<value optimized out>, args_template=24, nargs=20406984, args=0x7fffffffbed0) at ../../emacs-test/src/bytecode.c:916
#22 0x0000000000556ef4 in Ffuncall (nargs=<value optimized out>, args=0x10fe338) at ../../emacs-test/src/eval.c:2872
#23 0x000000000058bfed in exec_byte_code (bytestr=<value optimized out>, vector=<value optimized out>, maxdepth=<value optimized out>, args_template=0, nargs=20406984, args=0x7fffffffbfe8) at ../../emacs-test/src/bytecode.c:916
#24 0x0000000000556ef4 in Ffuncall (nargs=<value optimized out>, args=0xb8a808) at ../../emacs-test/src/eval.c:2872
#25 0x0000000000556762 in eval_sub (form=<value optimized out>) at ../../emacs-test/src/eval.c:2154
#26 0x00000000005591c9 in internal_lisp_condition_case (var=13695218, bodyform=<value optimized out>, handlers=<value optimized out>) at ../../emacs-test/src/eval.c:1317
#27 0x000000000058dbe1 in exec_byte_code (bytestr=<value optimized out>, vector=<value optimized out>, maxdepth=<value optimized out>, args_template=38, nargs=20406984, args=0x7fffffffc340) at ../../emacs-test/src/bytecode.c:1162
#28 0x0000000000556ef4 in Ffuncall (nargs=<value optimized out>, args=0x117c610) at ../../emacs-test/src/eval.c:2872
#29 0x000000000058bfed in exec_byte_code (bytestr=<value optimized out>, vector=<value optimized out>, maxdepth=<value optimized out>, args_template=140, nargs=20406984, args=0x7fffffffc4d8) at ../../emacs-test/src/bytecode.c:916
#30 0x0000000000556ef4 in Ffuncall (nargs=<value optimized out>, args=0x1186640) at ../../emacs-test/src/eval.c:2872
#31 0x0000000000556762 in eval_sub (form=<value optimized out>) at ../../emacs-test/src/eval.c:2154
#32 0x00000000005591c9 in internal_lisp_condition_case (var=13695362, bodyform=<value optimized out>, handlers=<value optimized out>) at ../../emacs-test/src/eval.c:1317
#33 0x000000000058dbe1 in exec_byte_code (bytestr=<value optimized out>, vector=<value optimized out>, maxdepth=<value optimized out>, args_template=107, nargs=20406984, args=0x7fffffffc7b8) at ../../emacs-test/src/bytecode.c:1162
#34 0x0000000000556ef4 in Ffuncall (nargs=<value optimized out>, args=0x1185500) at ../../emacs-test/src/eval.c:2872
#35 0x0000000000556762 in eval_sub (form=<value optimized out>) at ../../emacs-test/src/eval.c:2154
#36 0x0000000000555ca8 in internal_catch (tag=13695266, func=<value optimized out>, arg=<value optimized out>) at ../../emacs-test/src/eval.c:1112
#37 0x000000000058da03 in exec_byte_code (bytestr=<value optimized out>, vector=<value optimized out>, maxdepth=<value optimized out>, args_template=2, nargs=20406984, args=0x7fffffffca28) at ../../emacs-test/src/bytecode.c:1097
#38 0x0000000000556ef4 in Ffuncall (nargs=<value optimized out>, args=0x1193758) at ../../emacs-test/src/eval.c:2872
#39 0x0000000000558c0c in Fapply (nargs=<value optimized out>, args=0x7fffffffcad0) at ../../emacs-test/src/eval.c:2350
#40 0x0000000000558e50 in apply1 (fn=13694242, arg=<value optimized out>) at ../../emacs-test/src/eval.c:2584
#41 0x0000000000555a45 in internal_condition_case_1 (bfun=<value optimized out>, arg=<value optimized out>, handlers=<value optimized out>, hfun=<value optimized out>) at ../../emacs-test/src/eval.c:1372
#42 0x0000000000590fd4 in read_and_dispose_of_process_output (proc=<value optimized out>, channel=<value optimized out>) at ../../emacs-test/src/process.c:5180
#43 read_process_output (proc=<value optimized out>, channel=<value optimized out>) at ../../emacs-test/src/process.c:5089
#44 0x0000000000594c3f in wait_reading_process_output (time_limit=<value optimized out>, nsecs=<value optimized out>, read_kbd=<value optimized out>, do_display=<value optimized out>, wait_for_cell=<value optimized out>, wait_proc=0x0, just_wait_proc=0) at ../../emacs-test/src/process.c:4811
#45 0x00000000004ed706 in kbd_buffer_get_event (end_time=0x0, local_getcjmp=<value optimized out>, prev_event=<value optimized out>, used_mouse_menu=<value optimized out>) at ../../emacs-test/src/keyboard.c:3907
#46 read_event_from_main_queue (end_time=0x0, local_getcjmp=<value optimized out>, prev_event=<value optimized out>, used_mouse_menu=<value optimized out>) at ../../emacs-test/src/keyboard.c:2247
#47 read_decoded_event_from_main_queue (end_time=0x0, local_getcjmp=<value optimized out>, prev_event=<value optimized out>, used_mouse_menu=<value optimized out>) at ../../emacs-test/src/keyboard.c:2311
#48 0x00000000004ef1c8 in read_char (commandflag=<value optimized out>, map=<value optimized out>, prev_event=<value optimized out>, used_mouse_menu=<value optimized out>, end_time=<value optimized out>) at ../../emacs-test/src/keyboard.c:2896
#49 0x00000000004f0d23 in read_key_sequence (keybuf=<value optimized out>, prompt=<value optimized out>, dont_downcase_last=<value optimized out>, can_return_switch_frame=<value optimized out>, fix_current_buffer=<value optimized out>, prevent_redisplay=<value optimized out>, bufsize=<value optimized out>) at ../../emacs-test/src/keyboard.c:9089
#50 0x00000000004f21a2 in command_loop_1 () at ../../emacs-test/src/keyboard.c:1453
#51 0x0000000000555b5b in internal_condition_case (bfun=<value optimized out>, handlers=<value optimized out>, hfun=<value optimized out>) at ../../emacs-test/src/eval.c:1348
#52 0x00000000004eb42e in command_loop_2 (ignore=<value optimized out>) at ../../emacs-test/src/keyboard.c:1178
#53 0x0000000000555ca8 in internal_catch (tag=12112706, func=<value optimized out>, arg=<value optimized out>) at ../../emacs-test/src/eval.c:1112
#54 0x00000000004ebc2a in command_loop () at ../../emacs-test/src/keyboard.c:1157
#55 recursive_edit_1 () at ../../emacs-test/src/keyboard.c:778
#56 0x00000000004ebd6d in Frecursive_edit () at ../../emacs-test/src/keyboard.c:849
#57 0x00000000004e1047 in main (argc=6, argv=0x7fffffffea58) at ../../emacs-test/src/emacs.c:1642

Lisp Backtrace:
"redisplay_internal (C function)" (0xb757e8)
"delete-process" (0xffffb4b8)
"server-delete-client" (0xffffb628)
0x1104528 PVEC_COMPILED
"funcall" (0xffffb750)
0x11af968 PVEC_COMPILED
"funcall" (0xffffba50)
"server-execute" (0xffffbd80)
0x10fe338 PVEC_COMPILED
0xb8a808 PVEC_COMPILED
"funcall" (0xffffbfe0)
"server-execute-continuation" (0xffffc340)
0x1186640 PVEC_COMPILED
"funcall" (0xffffc4d0)
0x1185500 PVEC_COMPILED
"funcall" (0xffffc7b0)
"server-process-filter" (0xffffca28)

Breakpoint 3, record_run_time_for_recompute_basic_faces (f=0x113aea8, call_time=2.2545190000000002) at ../../emacs-test/src/xfaces.c:736
736	{
$13 = (Display *) 0x1375060
$14 = 0x1349d30 "localhost:10.0"
#0  record_run_time_for_recompute_basic_faces (f=0x113aea8, call_time=2.2545190000000002) at ../../emacs-test/src/xfaces.c:736
#1  0x00000000004b6b57 in recompute_basic_faces (f=0x113aea8) at ../../emacs-test/src/xfaces.c:750
#2  0x000000000044f295 in init_iterator (it=0x7fffffff8bd0, w=0x113beb8, charpos=-1, bytepos=-1, row=0x0, base_face_id=DEFAULT_FACE_ID) at ../../emacs-test/src/xdisp.c:2892
#3  0x000000000044fcdf in x_consider_frame_title (frame=<value optimized out>) at ../../emacs-test/src/xdisp.c:11650
#4  0x000000000045889e in prepare_menu_bars () at ../../emacs-test/src/xdisp.c:11752
#5  redisplay_internal () at ../../emacs-test/src/xdisp.c:13610
#6  0x0000000000459400 in redisplay_preserve_echo_area (from_where=18067112) at ../../emacs-test/src/xdisp.c:14206
#7  0x0000000000593aa4 in Fdelete_process (process=<value optimized out>) at ../../emacs-test/src/process.c:897
#8  0x0000000000557132 in Ffuncall (nargs=<value optimized out>, args=<value optimized out>) at ../../emacs-test/src/eval.c:2811
#9  0x000000000058bfed in exec_byte_code (bytestr=<value optimized out>, vector=<value optimized out>, maxdepth=<value optimized out>, args_template=194, nargs=20406984, args=0x7fffffffb628) at ../../emacs-test/src/bytecode.c:916
#10 0x0000000000556ef4 in Ffuncall (nargs=<value optimized out>, args=0x1130140) at ../../emacs-test/src/eval.c:2872
#11 0x000000000058bfed in exec_byte_code (bytestr=<value optimized out>, vector=<value optimized out>, maxdepth=<value optimized out>, args_template=76, nargs=20406984, args=0x7fffffffb758) at ../../emacs-test/src/bytecode.c:916
#12 0x0000000000556ef4 in Ffuncall (nargs=<value optimized out>, args=0x1104528) at ../../emacs-test/src/eval.c:2872
#13 0x0000000000556762 in eval_sub (form=<value optimized out>) at ../../emacs-test/src/eval.c:2154
#14 0x00000000005591c9 in internal_lisp_condition_case (var=13695602, bodyform=<value optimized out>, handlers=<value optimized out>) at ../../emacs-test/src/eval.c:1317
#15 0x000000000058dbe1 in exec_byte_code (bytestr=<value optimized out>, vector=<value optimized out>, maxdepth=<value optimized out>, args_template=0, nargs=20406984, args=0x7fffffffba58) at ../../emacs-test/src/bytecode.c:1162
#16 0x0000000000556ef4 in Ffuncall (nargs=<value optimized out>, args=0x11af968) at ../../emacs-test/src/eval.c:2872
#17 0x0000000000556762 in eval_sub (form=<value optimized out>) at ../../emacs-test/src/eval.c:2154
#18 0x00000000005591c9 in internal_lisp_condition_case (var=13695554, bodyform=<value optimized out>, handlers=<value optimized out>) at ../../emacs-test/src/eval.c:1317
#19 0x000000000058dbe1 in exec_byte_code (bytestr=<value optimized out>, vector=<value optimized out>, maxdepth=<value optimized out>, args_template=7, nargs=20406984, args=0x7fffffffbd80) at ../../emacs-test/src/bytecode.c:1162
#20 0x0000000000556ef4 in Ffuncall (nargs=<value optimized out>, args=0x117e648) at ../../emacs-test/src/eval.c:2872
#21 0x000000000058bfed in exec_byte_code (bytestr=<value optimized out>, vector=<value optimized out>, maxdepth=<value optimized out>, args_template=24, nargs=20406984, args=0x7fffffffbed0) at ../../emacs-test/src/bytecode.c:916
#22 0x0000000000556ef4 in Ffuncall (nargs=<value optimized out>, args=0x10fe338) at ../../emacs-test/src/eval.c:2872
#23 0x000000000058bfed in exec_byte_code (bytestr=<value optimized out>, vector=<value optimized out>, maxdepth=<value optimized out>, args_template=0, nargs=20406984, args=0x7fffffffbfe8) at ../../emacs-test/src/bytecode.c:916
#24 0x0000000000556ef4 in Ffuncall (nargs=<value optimized out>, args=0xb8a808) at ../../emacs-test/src/eval.c:2872
#25 0x0000000000556762 in eval_sub (form=<value optimized out>) at ../../emacs-test/src/eval.c:2154
#26 0x00000000005591c9 in internal_lisp_condition_case (var=13695218, bodyform=<value optimized out>, handlers=<value optimized out>) at ../../emacs-test/src/eval.c:1317
#27 0x000000000058dbe1 in exec_byte_code (bytestr=<value optimized out>, vector=<value optimized out>, maxdepth=<value optimized out>, args_template=38, nargs=20406984, args=0x7fffffffc340) at ../../emacs-test/src/bytecode.c:1162
#28 0x0000000000556ef4 in Ffuncall (nargs=<value optimized out>, args=0x117c610) at ../../emacs-test/src/eval.c:2872
#29 0x000000000058bfed in exec_byte_code (bytestr=<value optimized out>, vector=<value optimized out>, maxdepth=<value optimized out>, args_template=140, nargs=20406984, args=0x7fffffffc4d8) at ../../emacs-test/src/bytecode.c:916
#30 0x0000000000556ef4 in Ffuncall (nargs=<value optimized out>, args=0x1186640) at ../../emacs-test/src/eval.c:2872
#31 0x0000000000556762 in eval_sub (form=<value optimized out>) at ../../emacs-test/src/eval.c:2154
#32 0x00000000005591c9 in internal_lisp_condition_case (var=13695362, bodyform=<value optimized out>, handlers=<value optimized out>) at ../../emacs-test/src/eval.c:1317
#33 0x000000000058dbe1 in exec_byte_code (bytestr=<value optimized out>, vector=<value optimized out>, maxdepth=<value optimized out>, args_template=107, nargs=20406984, args=0x7fffffffc7b8) at ../../emacs-test/src/bytecode.c:1162
#34 0x0000000000556ef4 in Ffuncall (nargs=<value optimized out>, args=0x1185500) at ../../emacs-test/src/eval.c:2872
#35 0x0000000000556762 in eval_sub (form=<value optimized out>) at ../../emacs-test/src/eval.c:2154
#36 0x0000000000555ca8 in internal_catch (tag=13695266, func=<value optimized out>, arg=<value optimized out>) at ../../emacs-test/src/eval.c:1112
#37 0x000000000058da03 in exec_byte_code (bytestr=<value optimized out>, vector=<value optimized out>, maxdepth=<value optimized out>, args_template=2, nargs=20406984, args=0x7fffffffca28) at ../../emacs-test/src/bytecode.c:1097
#38 0x0000000000556ef4 in Ffuncall (nargs=<value optimized out>, args=0x1193758) at ../../emacs-test/src/eval.c:2872
#39 0x0000000000558c0c in Fapply (nargs=<value optimized out>, args=0x7fffffffcad0) at ../../emacs-test/src/eval.c:2350
#40 0x0000000000558e50 in apply1 (fn=13694242, arg=<value optimized out>) at ../../emacs-test/src/eval.c:2584
#41 0x0000000000555a45 in internal_condition_case_1 (bfun=<value optimized out>, arg=<value optimized out>, handlers=<value optimized out>, hfun=<value optimized out>) at ../../emacs-test/src/eval.c:1372
#42 0x0000000000590fd4 in read_and_dispose_of_process_output (proc=<value optimized out>, channel=<value optimized out>) at ../../emacs-test/src/process.c:5180
#43 read_process_output (proc=<value optimized out>, channel=<value optimized out>) at ../../emacs-test/src/process.c:5089
#44 0x0000000000594c3f in wait_reading_process_output (time_limit=<value optimized out>, nsecs=<value optimized out>, read_kbd=<value optimized out>, do_display=<value optimized out>, wait_for_cell=<value optimized out>, wait_proc=0x0, just_wait_proc=0) at ../../emacs-test/src/process.c:4811
#45 0x00000000004ed706 in kbd_buffer_get_event (end_time=0x0, local_getcjmp=<value optimized out>, prev_event=<value optimized out>, used_mouse_menu=<value optimized out>) at ../../emacs-test/src/keyboard.c:3907
#46 read_event_from_main_queue (end_time=0x0, local_getcjmp=<value optimized out>, prev_event=<value optimized out>, used_mouse_menu=<value optimized out>) at ../../emacs-test/src/keyboard.c:2247
#47 read_decoded_event_from_main_queue (end_time=0x0, local_getcjmp=<value optimized out>, prev_event=<value optimized out>, used_mouse_menu=<value optimized out>) at ../../emacs-test/src/keyboard.c:2311
#48 0x00000000004ef1c8 in read_char (commandflag=<value optimized out>, map=<value optimized out>, prev_event=<value optimized out>, used_mouse_menu=<value optimized out>, end_time=<value optimized out>) at ../../emacs-test/src/keyboard.c:2896
#49 0x00000000004f0d23 in read_key_sequence (keybuf=<value optimized out>, prompt=<value optimized out>, dont_downcase_last=<value optimized out>, can_return_switch_frame=<value optimized out>, fix_current_buffer=<value optimized out>, prevent_redisplay=<value optimized out>, bufsize=<value optimized out>) at ../../emacs-test/src/keyboard.c:9089
#50 0x00000000004f21a2 in command_loop_1 () at ../../emacs-test/src/keyboard.c:1453
#51 0x0000000000555b5b in internal_condition_case (bfun=<value optimized out>, handlers=<value optimized out>, hfun=<value optimized out>) at ../../emacs-test/src/eval.c:1348
#52 0x00000000004eb42e in command_loop_2 (ignore=<value optimized out>) at ../../emacs-test/src/keyboard.c:1178
#53 0x0000000000555ca8 in internal_catch (tag=12112706, func=<value optimized out>, arg=<value optimized out>) at ../../emacs-test/src/eval.c:1112
#54 0x00000000004ebc2a in command_loop () at ../../emacs-test/src/keyboard.c:1157
#55 recursive_edit_1 () at ../../emacs-test/src/keyboard.c:778
#56 0x00000000004ebd6d in Frecursive_edit () at ../../emacs-test/src/keyboard.c:849
#57 0x00000000004e1047 in main (argc=6, argv=0x7fffffffea58) at ../../emacs-test/src/emacs.c:1642

Lisp Backtrace:
"redisplay_internal (C function)" (0xb757e8)
"delete-process" (0xffffb4b8)
"server-delete-client" (0xffffb628)
0x1104528 PVEC_COMPILED
"funcall" (0xffffb750)
0x11af968 PVEC_COMPILED
"funcall" (0xffffba50)
"server-execute" (0xffffbd80)
0x10fe338 PVEC_COMPILED
0xb8a808 PVEC_COMPILED
"funcall" (0xffffbfe0)
"server-execute-continuation" (0xffffc340)
0x1186640 PVEC_COMPILED
"funcall" (0xffffc4d0)
0x1185500 PVEC_COMPILED
"funcall" (0xffffc7b0)
"server-process-filter" (0xffffca28)






^ permalink raw reply	[flat|nested] 64+ messages in thread

* bug#11822: 24.1; emacsclient terminal mode captures escape characters as text
  2015-09-07 21:09                     ` Ken Raeburn
@ 2015-09-08  1:29                       ` Stefan Monnier
  2015-09-08  4:29                         ` Eli Zaretskii
  2015-09-08  6:53                         ` Ken Raeburn
  2015-09-08  4:48                       ` Eli Zaretskii
  1 sibling, 2 replies; 64+ messages in thread
From: Stefan Monnier @ 2015-09-08  1:29 UTC (permalink / raw)
  To: Ken Raeburn; +Cc: 11822

> increments face_change_count. If face_change_count is nonzero, init_iterator
> (which gets called on every frame, thanks to prepare_menu_bars calling
> x_consider_frame_title, and perhaps other ways) will call

I think here we should arrange to only call init_iterator on those
frames that are being redisplayed.

IIUC this refreshes all frames because

  bool all_windows = windows_or_buffers_changed || update_mode_lines;

sets all_windows to true.  Can you check the actual value of
windows_or_buffers_changed and update_mode_lines to see which one causes
it to be true, and where it was set (each place they're set uses
a different value).  Then we can see if this place where it's set can be
modified so it explicitly marks the few frames/windows that actually
need to be refreshed, rather than asking for a "global" redisplay.

        Stefan

^ permalink raw reply	[flat|nested] 64+ messages in thread

* bug#11822: 24.1; emacsclient terminal mode captures escape characters as text
  2015-09-08  1:29                       ` Stefan Monnier
@ 2015-09-08  4:29                         ` Eli Zaretskii
  2015-09-08  6:53                         ` Ken Raeburn
  1 sibling, 0 replies; 64+ messages in thread
From: Eli Zaretskii @ 2015-09-08  4:29 UTC (permalink / raw)
  To: Stefan Monnier; +Cc: raeburn, 11822

> From: Stefan Monnier <monnier@iro.umontreal.ca>
> Date: Mon, 07 Sep 2015 21:29:48 -0400
> Cc: 11822@debbugs.gnu.org
> 
> > increments face_change_count. If face_change_count is nonzero, init_iterator
> > (which gets called on every frame, thanks to prepare_menu_bars calling
> > x_consider_frame_title, and perhaps other ways) will call
> 
> I think here we should arrange to only call init_iterator on those
> frames that are being redisplayed.

What do you mean by "being displayed"?  Do you mean those that
redisplay decided to redisplay?

Anyway, don't forget that init_iterator can also be called as part of
functions that simulate display, like vertical-motion and such likes.





^ permalink raw reply	[flat|nested] 64+ messages in thread

* bug#11822: 24.1; emacsclient terminal mode captures escape characters as text
  2015-09-07 21:09                     ` Ken Raeburn
  2015-09-08  1:29                       ` Stefan Monnier
@ 2015-09-08  4:48                       ` Eli Zaretskii
  2015-09-08 10:15                         ` Ken Raeburn
                                           ` (2 more replies)
  1 sibling, 3 replies; 64+ messages in thread
From: Eli Zaretskii @ 2015-09-08  4:48 UTC (permalink / raw)
  To: Ken Raeburn; +Cc: 11822

> From: Ken Raeburn <raeburn@permabit.com>
> Date: Mon, 7 Sep 2015 17:09:23 -0400
> 
> After dropping the ball on this about three years ago, I’ve started digging into it again with version 24.5.

Thanks for the footwork and the data.  I will study it and see what I
can come up with.  For now, just a couple of quick comments:

> 1) For a new frame, I doubt any cache clearing is needed when setting screenGamma or other frame parameters; if there’s anything cached before we’ve finished computing the parameters, we may have computed the cached thing too early.

The face cache of a new frame should start out empty, so clearing it
is a no-op.  But maybe you mean something else, I didn't yet have a
good look at the backtraces.

> 2) When changing screenGamma or another frame parameter does require clearing some cached values that were based on the old parameter settings, it still shouldn’t affect other frames.

The face cache is per-frame, so indeed, there should be no effect on
other frames.  If the backtraces indicate otherwise, I'd be surprised.

> 3) When frames on the same display have the same relevant frame parameters, as I expect is by far the most common case, can we share info between them, so these lookups and delays will be per-display instead of per-frame?

Faces are per frame, so it's hard to share them without a lot of
management code (which would be needed to maintain the illusion of
frame-specific face definitions).

> 4) If something else (changing a face attribute?) requires potentially updating all frames, maybe we can immediately do just the current frame, or the visible frames on the current display (and maybe tty frames?), and delay updates to other frames/displays briefly — say until an idle timer expires or the frame receives input, whichever happens first — so that we can give priority to user interaction on the selected frame/display?

We should have optimizations in the redisplay code that don't
redisplay all frames just because faces on one particular frame need
to be recomputed.

There's a tricky part about this: the display engine is prepared to be
called for a frame or window that only potentially need redisplay.
For starters, it should be clear that deciding which frames need
redisplay involves iterating through all the frames, checking for some
telltale signs.  It just could be (I didn't yet look at your data)
that some of this iteration somehow calls init_iterator, for the
purposes of testing whether a frame needs redisplay.

IOW, I think redisplay optimizations don't assume that just
recomputing the basic faces could be a bottleneck, so it's possible
that we don't try too hard to avoid that.

> 5) Even better, can we do the other-display updates in small increments, so that once we start doing those updates we don’t have a block of 160*RTT seconds where we’re unresponsive to new user input?

Not sure I understand the idea; please elaborate about the increments
you had in mind.

Thanks.

^ permalink raw reply	[flat|nested] 64+ messages in thread

* bug#11822: 24.1; emacsclient terminal mode captures escape characters as text
  2015-09-08  1:29                       ` Stefan Monnier
  2015-09-08  4:29                         ` Eli Zaretskii
@ 2015-09-08  6:53                         ` Ken Raeburn
  2015-09-08 13:03                           ` Stefan Monnier
  2015-09-08 13:11                           ` Stefan Monnier
  1 sibling, 2 replies; 64+ messages in thread
From: Ken Raeburn @ 2015-09-08  6:53 UTC (permalink / raw)
  To: Stefan Monnier; +Cc: 11822

> On Sep 7, 2015, at 21:29, Stefan Monnier <monnier@iro.umontreal.ca> wrote:
> 
>> increments face_change_count. If face_change_count is nonzero, init_iterator
>> (which gets called on every frame, thanks to prepare_menu_bars calling
>> x_consider_frame_title, and perhaps other ways) will call
> 
> I think here we should arrange to only call init_iterator on those
> frames that are being redisplayed.
> 
> IIUC this refreshes all frames because
> 
>  bool all_windows = windows_or_buffers_changed || update_mode_lines;
> 
> sets all_windows to true.  Can you check the actual value of
> windows_or_buffers_changed and update_mode_lines to see which one causes
> it to be true, and where it was set (each place they're set uses
> a different value).  Then we can see if this place where it's set can be
> modified so it explicitly marks the few frames/windows that actually
> need to be refreshed, rather than asking for a "global" redisplay.

When I created a frame on a second display, there were some calls to prepare_menu_bars where both variables were zero, but one call had windows_or_buffers_changed=13, update_mode_lines=24.

With a hardware watchpoint I see windows_or_buffers_changed getting set to 2 (wset_redisplay calls redisplay_other_windows), 30 (apply_window_adjustment), 19 (clear_image_cache because some images were freed — I had the tool bar displayed this time), 53 (Fclear_face_cache), 54 (Finternal_make_lisp_face, possible inheritance), 59 (x_set_menu_bar_lines), 60 (x_set_tool_bar_lines), 54, 56 (Finternal_set_lisp_face_attribute, possible inheritance), 54 (many times back and forth between those two), 47 (redisplay_internal, because face_change_count was nonzero), 13 (redraw_frame), 58 (free_realized_faces), 60, and finally 0 (redisplay_internal); the value of update_mode_lines changed just a few times, 0 to 2 (bset_update_mode_line) to 24 (status_notify, in case process status is used in a mode line for a buffer that might be visible in one or more windows) to 0 (redisplay_internal).

All of that was just in the process of creating the second frame via emacsclient, the server interaction being responsible for the status_notify call.

It appears that init_iterator is getting called a total of 35 times during the creation of the second frame. I don’t have the details on how many for each frame, but one of the calls specifies base_face_id as MODE_LINE_INACTIVE_FACE_ID, which looks like it’s going to update the mode line coloring, at least, on the frame on the first display, which I hadn’t thought about before. So even if not all frames need updating, the previously-selected frame does.

Ken

^ permalink raw reply	[flat|nested] 64+ messages in thread

* bug#11822: 24.1; emacsclient terminal mode captures escape characters as text
  2015-09-08  4:48                       ` Eli Zaretskii
@ 2015-09-08 10:15                         ` Ken Raeburn
  2015-09-08 13:35                           ` Stefan Monnier
  2015-09-08 17:33                           ` Eli Zaretskii
  2015-09-08 13:22                         ` Stefan Monnier
  2015-09-08 17:36                         ` Eli Zaretskii
  2 siblings, 2 replies; 64+ messages in thread
From: Ken Raeburn @ 2015-09-08 10:15 UTC (permalink / raw)
  To: Eli Zaretskii; +Cc: 11822

> On Sep 8, 2015, at 00:48, Eli Zaretskii <eliz@gnu.org> wrote:
> 
>> From: Ken Raeburn <raeburn@permabit.com>
>> Date: Mon, 7 Sep 2015 17:09:23 -0400
>> 
>> After dropping the ball on this about three years ago, I’ve started digging into it again with version 24.5.
> 
> Thanks for the footwork and the data.  I will study it and see what I
> can come up with.  For now, just a couple of quick comments:
> 
>> 1) For a new frame, I doubt any cache clearing is needed when setting screenGamma or other frame parameters; if there’s anything cached before we’ve finished computing the parameters, we may have computed the cached thing too early.
> 
> The face cache of a new frame should start out empty, so clearing it
> is a no-op.  But maybe you mean something else, I didn't yet have a
> good look at the backtraces.

Since there’s nothing to clear out on that frame, there should be no need to make the call. But we make it, and the call we make forces the clearing of all caches, not just the one for that frame.

>> 2) When changing screenGamma or another frame parameter does require clearing some cached values that were based on the old parameter settings, it still shouldn’t affect other frames.
> 
> The face cache is per-frame, so indeed, there should be no effect on
> other frames.  If the backtraces indicate otherwise, I'd be surprised.

Unfortunately Fclear_face_cache (and global variables like face_change_count or windows_or_buffers_changed) isn’t frame-specific. So — I expect but haven’t tested — changing screenGamma on an existing frame will probably also force faces to be recomputed on every frame.

> 
>> 3) When frames on the same display have the same relevant frame parameters, as I expect is by far the most common case, can we share info between them, so these lookups and delays will be per-display instead of per-frame?
> 
> Faces are per frame, so it's hard to share them without a lot of
> management code (which would be needed to maintain the illusion of
> frame-specific face definitions).

Yeah, I imagine it would take some work… A cache of X11 color info could probably be buried in the X-specific display info structure though; that could probably be more localized in terms of code changes, and probably a piece I can bite off without a much deeper understanding of redisplay than I have so far.

> 
>> 4) If something else (changing a face attribute?) requires potentially updating all frames, maybe we can immediately do just the current frame, or the visible frames on the current display (and maybe tty frames?), and delay updates to other frames/displays briefly — say until an idle timer expires or the frame receives input, whichever happens first — so that we can give priority to user interaction on the selected frame/display?
> 
> We should have optimizations in the redisplay code that don't
> redisplay all frames just because faces on one particular frame need
> to be recomputed.
> 
> There's a tricky part about this: the display engine is prepared to be
> called for a frame or window that only potentially need redisplay.
> For starters, it should be clear that deciding which frames need
> redisplay involves iterating through all the frames, checking for some
> telltale signs.  It just could be (I didn't yet look at your data)
> that some of this iteration somehow calls init_iterator, for the
> purposes of testing whether a frame needs redisplay.
> 
> IOW, I think redisplay optimizations don't assume that just
> recomputing the basic faces could be a bottleneck, so it's possible
> that we don't try too hard to avoid that.

I think that’s probably true, and if most people are using local displays most of the time, they may not be much of a bottleneck. I did a couple experiments with a local X server and got about half a millisecond round-trip time to the server to answer some queries. Even multiplying by 160 queries, that’s still under a tenth of a second of wasted time (though I think there are other wasted round-trips in the color queries too). I think you’d have to get off the local network neighborhood to even notice; maybe in such cases people just chalk it up to slow networks, when actually Emacs could be doing better.

>> 5) Even better, can we do the other-display updates in small increments, so that once we start doing those updates we don’t have a block of 160*RTT seconds where we’re unresponsive to new user input?
> 
> Not sure I understand the idea; please elaborate about the increments
> you had in mind.

In realize_basic_faces we call realize_named_face 14 times and realize_default_face once. For a display that’s not the one the user appears to be using (selected frame is elsewhere, no X events received), I’m wondering if we can have Emacs check for events (user input on any frame, subprocess output, etc), if there are none, realize one face, check for events again, etc., and when all of the faces are done, do any needed updates to the frame. Give priority to user interaction as much as possible, both in terms of handling input events and prioritizing updates to certain frames over others. Of course, if we get events associated with that other frame/display, or a call is made to force redisplay, we’d want to get things updated right away.

That’s probably a lot of work. :-) But maybe there are some smaller changes that could be made. Do we have to realize all 15 right away? If it’s not the selected frame, perhaps it doesn’t need the (active) mode line face, and if there are no tool bar or scroll bars, it doesn’t need those faces either. Maybe they could be processed later as (or if) needed?

I do see some references to the possibility of the colormap filling up. I don’t know if that’s a real concern on modern platforms (vs X10/early X11 servers), but I suppose that might be one reason for ensuring that a standard set of faces get processed before any others….

Ken

^ permalink raw reply	[flat|nested] 64+ messages in thread

* bug#11822: 24.1; emacsclient terminal mode captures escape characters as text
  2015-09-08  6:53                         ` Ken Raeburn
@ 2015-09-08 13:03                           ` Stefan Monnier
  2015-09-08 13:11                           ` Stefan Monnier
  1 sibling, 0 replies; 64+ messages in thread
From: Stefan Monnier @ 2015-09-08 13:03 UTC (permalink / raw)
  To: Ken Raeburn; +Cc: 11822

> When I created a frame on a second display, there were some calls to
> prepare_menu_bars where both variables were zero, but one call had
> windows_or_buffers_changed=13, update_mode_lines=24.

I was actually a bit confused, the problem is not that all_windows is
true, but that it's true *and* some_windows is false.

But yes, if windows_or_buffers_changed and update_mode_lines are both
0 then things are fine (we'll only redisplay the selected window),
whereas if they're set to 13/24 then we'll redisplay all windows/frames.

So the problem is the case where windows_or_buffers_changed=13 and
update_mode_lines=24.

> With a hardware watchpoint I see windows_or_buffers_changed getting set to
> 2 (wset_redisplay calls redisplay_other_windows),

This is a good setting: the value 2 is the special value which means
"only redisplay those windows which have the `redisplay' flag set
(either in the window, its frame, or its buffer)".

> 30 (apply_window_adjustment), 19 (clear_image_cache because some
> images were freed — I had the tool bar displayed this time), 53
> (Fclear_face_cache), 54 (Finternal_make_lisp_face, possible
> inheritance), 59 (x_set_menu_bar_lines), 60 (x_set_tool_bar_lines),
> 54, 56 (Finternal_set_lisp_face_attribute, possible inheritance), 54
> (many times back and forth between those two), 47 (redisplay_internal,
> because face_change_count was nonzero), 13 (redraw_frame), 58
> (free_realized_faces), 60,

Hmm... so we'd need to fix *all* those places to be more discriminating
(use wset_redisplay or equivalent) in order to avoid the global redisplay.

> the value of update_mode_lines changed just a few
> times, 0 to 2 (bset_update_mode_line)

Same as before: the value 2 is a good one.

> to 24 (status_notify, in case process status is used in a mode line
> for a buffer that might be visible in one or more windows) to
> 0 (redisplay_internal).

And this one *also* has to be fixed before the other fixes let us
avoid the global redisplay.  I installed the patch below which
should fix this part of the problem.

> It appears that init_iterator is getting called a total of 35 times during
> the creation of the second frame. I don’t have the details on how many for
> each frame, but one of the calls specifies base_face_id as
> MODE_LINE_INACTIVE_FACE_ID, which looks like it’s going to update the mode
> line coloring, at least, on the frame on the first display, which I hadn’t
> thought about before. So even if not all frames need updating, the
> previously-selected frame does.

Yes, but that's a simple update which shouldn't (meaning here "in
theory") need tons of round-trips to allocate new colors and stuff.


        Stefan


diff --git a/src/process.c b/src/process.c
index f4613be..26f26c3 100644
--- a/src/process.c
+++ b/src/process.c
@@ -6694,10 +6694,12 @@ status_notify (struct Lisp_Process *deleting_process,
 	  p->update_tick = p->tick;
 	  /* Now output the message suitably.  */
 	  exec_sentinel (proc, msg);
+	  if (BUFFERP (p->buffer))
+	    /* In case it uses %s in mode-line-format.  */
+	    bset_update_mode_line (XBUFFER (p->buffer));
 	}
     } /* end for */
 
-  update_mode_lines = 24;  /* In case buffers use %s in mode-line-format.  */
   return got_some_output;
 }
 





^ permalink raw reply related	[flat|nested] 64+ messages in thread

* bug#11822: 24.1; emacsclient terminal mode captures escape characters as text
  2015-09-08  6:53                         ` Ken Raeburn
  2015-09-08 13:03                           ` Stefan Monnier
@ 2015-09-08 13:11                           ` Stefan Monnier
  2015-09-08 17:21                             ` Eli Zaretskii
  1 sibling, 1 reply; 64+ messages in thread
From: Stefan Monnier @ 2015-09-08 13:11 UTC (permalink / raw)
  To: Ken Raeburn; +Cc: 11822

> freed — I had the tool bar displayed this time), 53 (Fclear_face_cache), 54

clear-face-cache is defined as affecting all frames, so to fix this
part, we'll need to refine it so the caller can specify a particular
frame; and then we'll need to find the callers that need to use this
new functionality.


        Stefan





^ permalink raw reply	[flat|nested] 64+ messages in thread

* bug#11822: 24.1; emacsclient terminal mode captures escape characters as text
  2015-09-08  4:48                       ` Eli Zaretskii
  2015-09-08 10:15                         ` Ken Raeburn
@ 2015-09-08 13:22                         ` Stefan Monnier
  2015-09-08 17:25                           ` Eli Zaretskii
  2015-09-08 17:36                         ` Eli Zaretskii
  2 siblings, 1 reply; 64+ messages in thread
From: Stefan Monnier @ 2015-09-08 13:22 UTC (permalink / raw)
  To: Eli Zaretskii; +Cc: Ken Raeburn, 11822

>> 5) Even better, can we do the other-display updates in small increments,
>> so that once we start doing those updates we don’t have a block of 160*RTT
>> seconds where we’re unresponsive to new user input?

We could potentially do something like:
- arrange for redisplay to first redisplays the selected frame.
- check for input (and abort redisplay if applicable) between each frame.

But the redisplay of each frame (or at the very least each window) can't
be cut into small increments, as the code currently stands.

Of course, I'd really happy if someone were to come and change the
redisplay so that each frame gets redisplayed from its own thread,
concurrently with the main Elisp loop.

I think parallelising the redisplay (i.e. one thread per terminal or
per frame or per window) shouldn't be too difficult.  But making the
redisplay concurrent with the main Elisp loop is likely to be a fair
amount of work.

"Fair amount of work" doesn't mean impossible, tho.

        Stefan

^ permalink raw reply	[flat|nested] 64+ messages in thread

* bug#11822: 24.1; emacsclient terminal mode captures escape characters as text
  2015-09-08 10:15                         ` Ken Raeburn
@ 2015-09-08 13:35                           ` Stefan Monnier
  2015-09-08 17:33                           ` Eli Zaretskii
  1 sibling, 0 replies; 64+ messages in thread
From: Stefan Monnier @ 2015-09-08 13:35 UTC (permalink / raw)
  To: Ken Raeburn; +Cc: 11822

> Unfortunately Fclear_face_cache (and global variables like face_change_count
> or windows_or_buffers_changed) isn’t frame-specific. So — I expect but
> haven’t tested — changing screenGamma on an existing frame will probably
> also force faces to be recomputed on every frame.

As explained in my other message, while windows_or_buffers_changed is
a global var, this part of the system can be more discriminating (using
[wfb]set_redisplay), thanks to the `redisplay' field of
relevant structures.

Those `redisplay' fields could completely replace the
windows_or_buffers_changed variable, but when I introduced those fields,
I kept the global var to ease the change.

I used the redisplay--*-cause variables (arrays where element I gets
incremented every time the corresponding global var was found to have
value I upon redisplay) to find which assignment to
windows_or_buffers_changed caused a particular global redisplay and
tried to figure out how to replace that global assignment by appropriate
calls to [wfb]set_redisplay.

We could similarly move face_change_count to the frame structure (or add such
a field in the frame structure).

> I think that’s probably true, and if most people are using local displays
> most of the time, they may not be much of a bottleneck. I did a couple
> experiments with a local X server and got about half a millisecond
> round-trip time to the server to answer some queries. Even multiplying by
> 160 queries, that’s still under a tenth of a second of wasted time (though
> I think there are other wasted round-trips in the color queries
> too). I think you’d have to get off the local network neighborhood to even
> notice; maybe in such cases people just chalk it up to slow networks, when
> actually Emacs could be doing better.

Hmm... what if you have 20-100 frames (which I often do).
I do find the frame creation to be slow (and I always display locally).

        Stefan

^ permalink raw reply	[flat|nested] 64+ messages in thread

* bug#11822: 24.1; emacsclient terminal mode captures escape characters as text
  2015-09-08 13:11                           ` Stefan Monnier
@ 2015-09-08 17:21                             ` Eli Zaretskii
  0 siblings, 0 replies; 64+ messages in thread
From: Eli Zaretskii @ 2015-09-08 17:21 UTC (permalink / raw)
  To: Stefan Monnier; +Cc: raeburn, 11822

> From: Stefan Monnier <monnier@iro.umontreal.ca>
> Date: Tue, 08 Sep 2015 09:11:47 -0400
> Cc: 11822@debbugs.gnu.org
> 
> > freed — I had the tool bar displayed this time), 53 (Fclear_face_cache), 54
> 
> clear-face-cache is defined as affecting all frames, so to fix this
> part, we'll need to refine it so the caller can specify a particular
> frame

Yes, I think we should make the face_change flag per-frame, and only
clear the face cache on the frame whose flag is set.

> and then we'll need to find the callers that need to use this new
> functionality.

I think all of them do.





^ permalink raw reply	[flat|nested] 64+ messages in thread

* bug#11822: 24.1; emacsclient terminal mode captures escape characters as text
  2015-09-08 13:22                         ` Stefan Monnier
@ 2015-09-08 17:25                           ` Eli Zaretskii
  2015-09-08 18:52                             ` Stefan Monnier
  0 siblings, 1 reply; 64+ messages in thread
From: Eli Zaretskii @ 2015-09-08 17:25 UTC (permalink / raw)
  To: Stefan Monnier; +Cc: raeburn, 11822

> From: Stefan Monnier <monnier@iro.umontreal.ca>
> Cc: Ken Raeburn <raeburn@permabit.com>,  11822@debbugs.gnu.org
> Date: Tue, 08 Sep 2015 09:22:59 -0400
> 
> >> 5) Even better, can we do the other-display updates in small increments,
> >> so that once we start doing those updates we don’t have a block of 160*RTT
> >> seconds where we’re unresponsive to new user input?
> 
> We could potentially do something like:
> - arrange for redisplay to first redisplays the selected frame.
> - check for input (and abort redisplay if applicable) between each frame.

That's what redisplay-dont-pause did, and we removed that.

In any case, I think the issue at hand is that more than one frame is
being redisplayed when only one should suffice.  So we want redisplay
to realize that other frames don't need to be redisplayed, instead of
aborting.





^ permalink raw reply	[flat|nested] 64+ messages in thread

* bug#11822: 24.1; emacsclient terminal mode captures escape characters as text
  2015-09-08 10:15                         ` Ken Raeburn
  2015-09-08 13:35                           ` Stefan Monnier
@ 2015-09-08 17:33                           ` Eli Zaretskii
  2015-09-08 19:54                             ` Ken Raeburn
  1 sibling, 1 reply; 64+ messages in thread
From: Eli Zaretskii @ 2015-09-08 17:33 UTC (permalink / raw)
  To: Ken Raeburn; +Cc: 11822

> From: Ken Raeburn <raeburn@permabit.com>
> Date: Tue, 8 Sep 2015 06:15:47 -0400
> Cc: 11822@debbugs.gnu.org
> 
> > The face cache of a new frame should start out empty, so clearing it
> > is a no-op.  But maybe you mean something else, I didn't yet have a
> > good look at the backtraces.
> 
> Since there’s nothing to clear out on that frame, there should be no need to make the call. But we make it, and the call we make forces the clearing of all caches, not just the one for that frame.

Therefore, we should prevent the effect of that on other frames.  I
see no need for this effect, since faces are frame-local.

> > The face cache is per-frame, so indeed, there should be no effect on
> > other frames.  If the backtraces indicate otherwise, I'd be surprised.
> 
> Unfortunately Fclear_face_cache (and global variables like face_change_count or windows_or_buffers_changed) isn’t frame-specific. So — I expect but haven’t tested — changing screenGamma on an existing frame will probably also force faces to be recomputed on every frame.

Then we should make them part of the frame structure, and only clear
the face cache of a single frame at a time -- the frame on which a
change to faces requires that.

> >> 5) Even better, can we do the other-display updates in small increments, so that once we start doing those updates we don’t have a block of 160*RTT seconds where we’re unresponsive to new user input?
> > 
> > Not sure I understand the idea; please elaborate about the increments
> > you had in mind.
> 
> In realize_basic_faces we call realize_named_face 14 times and realize_default_face once. For a display that’s not the one the user appears to be using (selected frame is elsewhere, no X events received), I’m wondering if we can have Emacs check for events (user input on any frame, subprocess output, etc), if there are none, realize one face, check for events again, etc., and when all of the faces are done, do any needed updates to the frame. Give priority to user interaction as much as possible, both in terms of handling input events and prioritizing updates to certain frames over others. Of course, if we get events associated with that other frame/display, or a call is made to force redisplay, we’d want to get things updated right away.

I'm still not following you: what do input events have to do with the
need to redisplay or not redisplay some frame(s)?

> That’s probably a lot of work. :-) But maybe there are some smaller changes that could be made. Do we have to realize all 15 right away?

The way the code is written, it expects the basic faces to be
realized, yes.

> If it’s not the selected frame, perhaps it doesn’t need the (active) mode line face

As you see from your backtraces, Emacs changes the selected frame many
times behind your back, so this is not true.

Anyway, I think preventing frames from being unnecessarily redisplayed
will bring larger benefits than just avoiding realization of some
faces.

> and if there are no tool bar or scroll bars, it doesn’t need those faces either. Maybe they could be processed later as (or if) needed?

We would need flags to manage that.  Once again, I don't think the
basic faces are the main problem as long as they are rtealized only
for the frame(s) that really need them to be recomputed.





^ permalink raw reply	[flat|nested] 64+ messages in thread

* bug#11822: 24.1; emacsclient terminal mode captures escape characters as text
  2015-09-08  4:48                       ` Eli Zaretskii
  2015-09-08 10:15                         ` Ken Raeburn
  2015-09-08 13:22                         ` Stefan Monnier
@ 2015-09-08 17:36                         ` Eli Zaretskii
  2 siblings, 0 replies; 64+ messages in thread
From: Eli Zaretskii @ 2015-09-08 17:36 UTC (permalink / raw)
  To: raeburn; +Cc: 11822

> Date: Tue, 08 Sep 2015 07:48:07 +0300
> From: Eli Zaretskii <eliz@gnu.org>
> Cc: 11822@debbugs.gnu.org
> 
> > From: Ken Raeburn <raeburn@permabit.com>
> > Date: Mon, 7 Sep 2015 17:09:23 -0400
> > 
> > After dropping the ball on this about three years ago, I’ve started digging into it again with version 24.5.
> 
> Thanks for the footwork and the data.  I will study it and see what I
> can come up with.

Did that now.  What I don't quite understand is why we keep
recomputing basic faces in init_iterator for the same frame during the
same operation?  The variable face_change is indeed global, but once
init_iterator frees the face caches, it resets it to 'false', so when
it later recomputes the basic faces, there should not be any reason to
do that again for the same frame.  So some code must be setting
face_change to 'true' again.  Can you see which code does that in the
scenarios you traced through?

^ permalink raw reply	[flat|nested] 64+ messages in thread

* bug#11822: 24.1; emacsclient terminal mode captures escape characters as text
  2015-09-08 17:25                           ` Eli Zaretskii
@ 2015-09-08 18:52                             ` Stefan Monnier
  2015-09-08 19:08                               ` Eli Zaretskii
  0 siblings, 1 reply; 64+ messages in thread
From: Stefan Monnier @ 2015-09-08 18:52 UTC (permalink / raw)
  To: Eli Zaretskii; +Cc: raeburn, 11822

> In any case, I think the issue at hand is that more than one frame is
> being redisplayed when only one should suffice.

Agreed (tho it's probably 2 instead, but the other one's redisplay
should be fairly simple and efficient: just redraw the modeline to
reflect its new non-selected status).


        Stefan





^ permalink raw reply	[flat|nested] 64+ messages in thread

* bug#11822: 24.1; emacsclient terminal mode captures escape characters as text
  2015-09-08 18:52                             ` Stefan Monnier
@ 2015-09-08 19:08                               ` Eli Zaretskii
  2015-09-08 20:37                                 ` Stefan Monnier
  0 siblings, 1 reply; 64+ messages in thread
From: Eli Zaretskii @ 2015-09-08 19:08 UTC (permalink / raw)
  To: Stefan Monnier; +Cc: raeburn, 11822

> From: Stefan Monnier <monnier@iro.umontreal.ca>
> Cc: raeburn@permabit.com,  11822@debbugs.gnu.org
> Date: Tue, 08 Sep 2015 14:52:22 -0400
> 
> > In any case, I think the issue at hand is that more than one frame is
> > being redisplayed when only one should suffice.
> 
> Agreed (tho it's probably 2 instead, but the other one's redisplay
> should be fairly simple and efficient: just redraw the modeline to
> reflect its new non-selected status).

Perhaps so, but note that this particular use case (i.e. a client
frame displayed via a slow network) gives a rather new meaning to
"redisplay optimizations": where normally we mainly try to avoid
redrawing the parts of any window that didn't change, here we need to
try to avoid even considering those parts, or at least minimize the X
calls while we consider them.  I think until now the assumption was
that the most expensive parts of redisplay are those that regenerate
glyph matrices and those that actually send data to the glass; here
the expensive parts are elsewhere.

So if redrawing the mode line involves recomputing all the basic
faces, it might still be too expensive over a slow network.  We need
to avoid that recomputation where possible.

^ permalink raw reply	[flat|nested] 64+ messages in thread

* bug#11822: 24.1; emacsclient terminal mode captures escape characters as text
  2015-09-08 17:33                           ` Eli Zaretskii
@ 2015-09-08 19:54                             ` Ken Raeburn
  2015-09-09 14:16                               ` Eli Zaretskii
  0 siblings, 1 reply; 64+ messages in thread
From: Ken Raeburn @ 2015-09-08 19:54 UTC (permalink / raw)
  To: Eli Zaretskii; +Cc: 11822

Eli Zaretskii <eliz@gnu.org> writes:
> I'm still not following you: what do input events have to do with the
> need to redisplay or not redisplay some frame(s)?

If we don't need to update a frame, that's great. But I'm also thinking
about cases where a frame does need updating but isn't on the
currently-used display. Though for it to be important in this context,
updating text probably don't matter much(?), just cases where we
actually need to stop and wait for a reply, which probably means changes
to face definitions like updating the foreground color. Would changing
sizes for a face cause the face to be recomputed from scratch? That's
something I sometimes do with buffers that I may well have visible on
multiple displays.

Giving updates to a remote display that's not the currently-active one
lower priority than dealing with input on the active display could let
us be more responsive on the active display, but at the risk of leaving
the other display slightly out of date in occasional cases where it
might matter (a second person working at the second display at the same
time, both displays mapping to the same physical display via multiple
ssh connections, etc).

> Anyway, I think preventing frames from being unnecessarily redisplayed
> will bring larger benefits than just avoiding realization of some
> faces.

Perhaps so. I think we've got inefficiencies at multiple levels:
updating frames that don't need it; updating faces that don't need it
(on frames where something does or may need updating); redundant color
queries to a display; probably some issues around image handling. Fixing
any of them would be an improvement, but addressing more than one is
probably better still.

Ken

^ permalink raw reply	[flat|nested] 64+ messages in thread

* bug#11822: 24.1; emacsclient terminal mode captures escape characters as text
  2015-09-08 19:08                               ` Eli Zaretskii
@ 2015-09-08 20:37                                 ` Stefan Monnier
  0 siblings, 0 replies; 64+ messages in thread
From: Stefan Monnier @ 2015-09-08 20:37 UTC (permalink / raw)
  To: Eli Zaretskii; +Cc: raeburn, 11822

> So if redrawing the mode line involves recomputing all the basic
> faces, it might still be too expensive over a slow network.  We need
> to avoid that recomputation where possible.

That's right.  I was assuming that C-x o (which requires the same kind
of mode-line updates) normally doesn't trigger a recomputation of the
basic faces, but I don't actually know if that's the case.


        Stefan





^ permalink raw reply	[flat|nested] 64+ messages in thread

* bug#11822: 24.1; emacsclient terminal mode captures escape characters as text
  2015-09-08 19:54                             ` Ken Raeburn
@ 2015-09-09 14:16                               ` Eli Zaretskii
  2015-09-10  6:59                                 ` Ken Raeburn
  0 siblings, 1 reply; 64+ messages in thread
From: Eli Zaretskii @ 2015-09-09 14:16 UTC (permalink / raw)
  To: Ken Raeburn; +Cc: 11822

> From: Ken Raeburn <raeburn@permabit.com>
> Cc: 11822@debbugs.gnu.org
> Date: Tue, 08 Sep 2015 15:54:49 -0400
> 
> > I'm still not following you: what do input events have to do with the
> > need to redisplay or not redisplay some frame(s)?
> 
> If we don't need to update a frame, that's great. But I'm also thinking
> about cases where a frame does need updating but isn't on the
> currently-used display. Though for it to be important in this context,
> updating text probably don't matter much(?), just cases where we
> actually need to stop and wait for a reply, which probably means changes
> to face definitions like updating the foreground color.

I don't follow: what replies did you have in mind?  Replies from whom
or what?

Emacs redraws windows on frames that require redrawing because
something happened that affects how the visible portion of the windows
look on the glass.  Emacs doesn't consider some changes more important
than others, nor waits for any replies, when it decides that changes
to buffers or strings require redisplay of some window.

I don't think the idea of holding off some display updates for
whatever reasons will fly, because users rightfully expect the display
to be up to date, unless Emacs is busy computing something.

> Would changing sizes for a face cause the face to be recomputed from
> scratch?

It doesn't in my testing (I tried "C-x C-+").  You can easily try that
yourself: put a breakpoint on recompute_basic_faces, and see if it
breaks when you change the face size.

> Giving updates to a remote display that's not the currently-active one
> lower priority than dealing with input on the active display could let
> us be more responsive on the active display, but at the risk of leaving
> the other display slightly out of date in occasional cases where it
> might matter (a second person working at the second display at the same
> time, both displays mapping to the same physical display via multiple
> ssh connections, etc).

I'm not sure I understand the practical meaning of "lower priority".
When the display engine decides that more than one window needs to be
redisplayed, it iterates through all the frames, one by one, and on
each frame iterates through all of its windows.  The order of the
frame traversal is independent of their displays, and it is
sequential.

Given this general description, what would "lower priority" mean in
practice?

And anyway, I don't think we should do anything that could produce
frames that are not up to date, because we will be crucified by users.
I can easily envision a use case where frames on the
currently-inactive display are actively watched by a user, perhaps
even the same user who types at the currently-active display.

We can justify partially outdated display when Emacs has something to
do, but we cannot justify that when Emacs is idle.

However, Emacs should refrain from redrawing iconified frames, so one
possible method of saving some time should be to leave frames on the
inactive display iconified.  Did you try that, and if so, did that
help?

> > Anyway, I think preventing frames from being unnecessarily redisplayed
> > will bring larger benefits than just avoiding realization of some
> > faces.
> 
> Perhaps so. I think we've got inefficiencies at multiple levels:
> updating frames that don't need it; updating faces that don't need it
> (on frames where something does or may need updating); redundant color
> queries to a display; probably some issues around image handling. Fixing
> any of them would be an improvement, but addressing more than one is
> probably better still.

My reading of the discussion and your backtraces indicate that all of
that stems from a single problem: when we create or update faces, we
set a global flag that causes faces to be recomputed on all frames.
This then snowballs into the need to reload colors and redraw all
frames.

So the actual inefficiency, according to my analysis, is just one: we
are too conservative in the effect that is caused by a change in
faces.  We should limit that effect to the frame whose faces are being
changed.  This should eliminate at least some of the unnecessary X
requests, hopefully a lot of them.  (I say "hopefully" because some of
the face changes are global, i.e. are intended to affect all the
frames, and for those we won't be able to avoid recomputing faces on
all the frames and then redrawing them all.)

^ permalink raw reply	[flat|nested] 64+ messages in thread

* bug#11822: 24.1; emacsclient terminal mode captures escape characters as text
  2015-09-09 14:16                               ` Eli Zaretskii
@ 2015-09-10  6:59                                 ` Ken Raeburn
  2015-09-10 15:36                                   ` Eli Zaretskii
  0 siblings, 1 reply; 64+ messages in thread
From: Ken Raeburn @ 2015-09-10  6:59 UTC (permalink / raw)
  To: Eli Zaretskii; +Cc: 11822

Eli Zaretskii <eliz@gnu.org> writes:

>> From: Ken Raeburn <raeburn@permabit.com>
>> Cc: 11822@debbugs.gnu.org
>> Date: Tue, 08 Sep 2015 15:54:49 -0400
>> 
>> > I'm still not following you: what do input events have to do with the
>> > need to redisplay or not redisplay some frame(s)?
>> 
>> If we don't need to update a frame, that's great. But I'm also thinking
>> about cases where a frame does need updating but isn't on the
>> currently-used display. Though for it to be important in this context,
>> updating text probably don't matter much(?), just cases where we
>> actually need to stop and wait for a reply, which probably means changes
>> to face definitions like updating the foreground color.
>
> I don't follow: what replies did you have in mind?  Replies from whom
> or what?

Replies from the X server to LookupColor or AllocColor requests.

That's when the round-trip time and the number of round trips become
important. If we're just sending text-drawing requests, and if there's
enough bandwidth or socket buffer space (neither of which is actually
guaranteed), we shouldn't need to wait, and it shouldn't cause any
significant delay for updates to other frames. So once the
global-variable aspects are addressed, the sort of delay I'm dealing
with should only come up for things like changes to colors in faces that
are used on multiple displays.

> Emacs redraws windows on frames that require redrawing because
> something happened that affects how the visible portion of the windows
> look on the glass.  Emacs doesn't consider some changes more important
> than others, nor waits for any replies, when it decides that changes
> to buffers or strings require redisplay of some window.
>
> I don't think the idea of holding off some display updates for
> whatever reasons will fly, because users rightfully expect the display
> to be up to date, unless Emacs is busy computing something.

I didn't mean having them seconds or minutes out of date. What I'm
thinking of -- assuming for the sake of argument that we're still
concerned about types of changes that'll still require changes on
multiple frames even after the global-variable issues are addressed,
like changing the default face's foreground color -- would be something
like updating faces and then content on one frame, then going on to the
next and updating faces and then content, but preempting the rest ASAP
if user input is received. If recompute_basic_faces is called, since it
triggers a lot of round trips, at least one or two possible preemption
points in the middle of that sequence.

Plus more intelligent ordering of frames for updating (see below). And
image handling probably fits in there too somewhere.

If there's no input received during the process, or after the input is
dealt with, all the face computations and display updates should proceed
normally and all frames should become up-to-date.

I was thinking in terms of delays or idle timers (e.g., wait for "idle"
time of 0.0001s then do this next update increment) as a possible simple
and stupid way to implement that, driven by the input-handling part of
the program, but reviewing what I'm learning about Emacs redisplay, it
doesn't really make sense.

>> Would changing sizes for a face cause the face to be recomputed from
>> scratch?
>
> It doesn't in my testing (I tried "C-x C-+").  You can easily try that
> yourself: put a breakpoint on recompute_basic_faces, and see if it
> breaks when you change the face size.

I tried it in the scratch buffer in a new Emacs process. It doesn't call
recompute_basic_faces, but it did call realize_face twice, and
XParseColor and x_alloc_nearest_color_1 each four times. So that's eight
round trips that seem unnecessary as we should already have the color
definitions and allocated color cells.

>> Giving updates to a remote display that's not the currently-active one
>> lower priority than dealing with input on the active display could let
>> us be more responsive on the active display, but at the risk of leaving
>> the other display slightly out of date in occasional cases where it
>> might matter (a second person working at the second display at the same
>> time, both displays mapping to the same physical display via multiple
>> ssh connections, etc).
>
> I'm not sure I understand the practical meaning of "lower priority".
> When the display engine decides that more than one window needs to be
> redisplayed, it iterates through all the frames, one by one, and on
> each frame iterates through all of its windows.  The order of the
> frame traversal is independent of their displays, and it is
> sequential.
>
> Given this general description, what would "lower priority" mean in
> practice?

Reorder the frame traversal. If in some circumstances a full redisplay
process updating multiple frames can be slow (fewer such circumstances
after the work Stefan outlined and has started gets done, but I expect
some cases will remain), and if user input can preempt completion of
redisplay (I see comments indicating it can but don't know precisely how
or how well it works with X), which frames do we want updated first or
more often? Near as I can tell, it's done by the age of the frame, from
newest to oldest, because newer ones are added to Vframe_list at the
front. My comments about the current display vs other displays vs tty
frames are just ideas of what a better heuristic might look like.

If we effectively do face recomputation across all frames needing it as
a separate pass before doing screen updates, though, it might not help.
(For face updates, at least... I haven't traced through the image
handling.)

> And anyway, I don't think we should do anything that could produce
> frames that are not up to date, because we will be crucified by users.
> I can easily envision a use case where frames on the
> currently-inactive display are actively watched by a user, perhaps
> even the same user who types at the currently-active display.

Yep, that's why they should all get updated ASAP if some input doesn't
preempt redisplay. It doesn't argue for order-of-creation processing
though.

> We can justify partially outdated display when Emacs has something to
> do, but we cannot justify that when Emacs is idle.
>
> However, Emacs should refrain from redrawing iconified frames, so one
> possible method of saving some time should be to leave frames on the
> inactive display iconified.  Did you try that, and if so, did that
> help?

I haven't. I tried remotely iconifying it via Lisp code, but Emacs still
thought it was visible. Now that I'm at home, I'll try to leave it
iconified before heading back to work.

>> > Anyway, I think preventing frames from being unnecessarily redisplayed
>> > will bring larger benefits than just avoiding realization of some
>> > faces.
>> 
>> Perhaps so. I think we've got inefficiencies at multiple levels:
>> updating frames that don't need it; updating faces that don't need it
>> (on frames where something does or may need updating); redundant color
>> queries to a display; probably some issues around image handling. Fixing
>> any of them would be an improvement, but addressing more than one is
>> probably better still.
>
> My reading of the discussion and your backtraces indicate that all of
> that stems from a single problem: when we create or update faces, we
> set a global flag that causes faces to be recomputed on all frames.
> This then snowballs into the need to reload colors and redraw all
> frames.

I think that's the worst part for my new-frame-with-multiple-displays
case, but I don't think it's the only area of the code that could be
improved.

I took a look at the calls to x_alloc_nearest_color_1. In creating an
initial frame with "emacs -Q", I get over two hundred calls, and every
one requires a round-trip to the server. But there were only 13 distinct
RGB color values passed. The most popular values passed were these:

     88 x_alloc_nearest_color_1(0000/0000/0000) (white)
     71 x_alloc_nearest_color_1(ffff/ffff/ffff) (black)
     15 x_alloc_nearest_color_1(bfbf/bfbf/bfbf) (grey75)

Then there's XParseColor; over 2300 calls, but only about 9% require
round-trips to the server, the rest using the "#RRGGBB" syntax that gets
parsed locally. I haven't traced which part of the program accounts for
what fraction of the calls.

Eliminating unnecessary cache clearing might reduce these, maybe by a
factor of two or more, but that's still excessive; and 100 round trips
with a 30ms RTT would still contribute 3 seconds to the time needed to
finish setting up the initial frame. Now, if instead we had just *one*
call to XAllocNamedColor for "white", and one for "black", etc....

Ken

^ permalink raw reply	[flat|nested] 64+ messages in thread

* bug#11822: 24.1; emacsclient terminal mode captures escape characters as text
  2015-09-10  6:59                                 ` Ken Raeburn
@ 2015-09-10 15:36                                   ` Eli Zaretskii
  2015-09-10 17:56                                     ` Stefan Monnier
  2015-09-11  6:54                                     ` Ken Raeburn
  0 siblings, 2 replies; 64+ messages in thread
From: Eli Zaretskii @ 2015-09-10 15:36 UTC (permalink / raw)
  To: Ken Raeburn; +Cc: 11822

> From: Ken Raeburn <raeburn@permabit.com>
> Cc: 11822@debbugs.gnu.org
> Date: Thu, 10 Sep 2015 02:59:06 -0400
> 
> > I don't think the idea of holding off some display updates for
> > whatever reasons will fly, because users rightfully expect the display
> > to be up to date, unless Emacs is busy computing something.
> 
> I didn't mean having them seconds or minutes out of date. What I'm
> thinking of -- assuming for the sake of argument that we're still
> concerned about types of changes that'll still require changes on
> multiple frames even after the global-variable issues are addressed,
> like changing the default face's foreground color -- would be something
> like updating faces and then content on one frame, then going on to the
> next and updating faces and then content, but preempting the rest ASAP
> if user input is received. If recompute_basic_faces is called, since it
> triggers a lot of round trips, at least one or two possible preemption
> points in the middle of that sequence.

We had this ability in the past, but we all but deleted it, as it
seemed not to make redisplay more responsive.  The comment which was
left when this was done says:

  /* Contrary to expectations, a value of "false" can be detrimental to
     responsiveness since aborting a redisplay throws away some of the
     work already performed.  It's usually more efficient (and gives
     more prompt feedback to the user) to let the redisplay terminate,
     and just completely skip the next command's redisplay (which is
     done regardless of this setting if there's pending input at the
     beginning of the next redisplay).  */

But it could be that we didn't look at the effect of this when frames
are displayed via X over slow networks.  So please try experimenting
with an Emacs before the deletion (I think 24.4 is old enough), and
see if setting redisplay-dont-pause to nil helps in your case.  If it
doesn't, then what you suggest above is probably not an idea that will
yield tangible benefits.

> >> Would changing sizes for a face cause the face to be recomputed from
> >> scratch?
> >
> > It doesn't in my testing (I tried "C-x C-+").  You can easily try that
> > yourself: put a breakpoint on recompute_basic_faces, and see if it
> > breaks when you change the face size.
> 
> I tried it in the scratch buffer in a new Emacs process. It doesn't call
> recompute_basic_faces, but it did call realize_face twice, and
> XParseColor and x_alloc_nearest_color_1 each four times. So that's eight
> round trips that seem unnecessary as we should already have the color
> definitions and allocated color cells.

For how many frames were XParseColor and x_alloc_nearest_color_1
called?  If only for the single frame where you've changed the face,
then it's expected.

If you are suggesting to be more selective wrt what exactly needs to
be recomputed during face update, then this will need some analysis
regarding which parts are more expensive than others, and introduction
of corresponding flags to signal which face aspects need to be
recomputed.  Assuming this is even possible without a more or less
complete rewrite of face-related code (which currently just throws
away a face and realizes it anew), the relative cost (in terms of
time) of recomputing each aspects will most probably be different for
different display back-ends, perhaps even for different network
bandwidths.  Someone™ should do this research and publish the results,
before we could start designing a good solution.

> > Given this general description, what would "lower priority" mean in
> > practice?
> 
> Reorder the frame traversal.

Since the goal is to limit redisplay to a single frame, the current
one, I think this is a moot point.

> > My reading of the discussion and your backtraces indicate that all of
> > that stems from a single problem: when we create or update faces, we
> > set a global flag that causes faces to be recomputed on all frames.
> > This then snowballs into the need to reload colors and redraw all
> > frames.
> 
> I think that's the worst part for my new-frame-with-multiple-displays
> case, but I don't think it's the only area of the code that could be
> improved.

We should see about that once the global face recalculation is gone.

> I took a look at the calls to x_alloc_nearest_color_1. In creating an
> initial frame with "emacs -Q", I get over two hundred calls, and every
> one requires a round-trip to the server. But there were only 13 distinct
> RGB color values passed. The most popular values passed were these:
> 
>      88 x_alloc_nearest_color_1(0000/0000/0000) (white)
>      71 x_alloc_nearest_color_1(ffff/ffff/ffff) (black)
>      15 x_alloc_nearest_color_1(bfbf/bfbf/bfbf) (grey75)
> 
> Then there's XParseColor; over 2300 calls, but only about 9% require
> round-trips to the server, the rest using the "#RRGGBB" syntax that gets
> parsed locally. I haven't traced which part of the program accounts for
> what fraction of the calls.

Once again, it is necessary to figure out which portions of these
calls is on behalf of frames other than the one being created.  Those
calls should all but go away after the global effect of face updating
is eliminated.  Only after that we will see how much of this problem
remains.

> Eliminating unnecessary cache clearing might reduce these, maybe by a
> factor of two or more, but that's still excessive

What is the estimation of "factor of two or more" is based on?  Why
not by an order of magnitude, for example?

> Now, if instead we had just *one* call to XAllocNamedColor for
> "white", and one for "black", etc....

Why do you think we will have more than that?

^ permalink raw reply	[flat|nested] 64+ messages in thread

* bug#11822: 24.1; emacsclient terminal mode captures escape characters as text
  2015-09-10 15:36                                   ` Eli Zaretskii
@ 2015-09-10 17:56                                     ` Stefan Monnier
  2015-09-10 18:06                                       ` Eli Zaretskii
  2015-09-11  6:54                                     ` Ken Raeburn
  1 sibling, 1 reply; 64+ messages in thread
From: Stefan Monnier @ 2015-09-10 17:56 UTC (permalink / raw)
  To: Eli Zaretskii; +Cc: Ken Raeburn, 11822

>   /* Contrary to expectations, a value of "false" can be detrimental to
>      responsiveness since aborting a redisplay throws away some of the
>      work already performed.

But that's because the effect was different from what is being
discussed here (at least in theory): interrupting redisplay between
windows wouldn't throw away work, AFAIK.

The problem with the redisplay-dont-pause was that it would abort
redisplay after building the matrices but before painting the result, so
the work of building the matrices was largely wasted.

This said, I'm not sure the current code would be happy to interrupt
redisplay after having handled some windows but not all.  E.g. I'm not
sure it would correctly keep track of "what's changed since last
redisplay" for a buffer that's displayed in several windows, some of
which have been redisplayed during the last redisplay cycle but not all.

        Stefan

^ permalink raw reply	[flat|nested] 64+ messages in thread

* bug#11822: 24.1; emacsclient terminal mode captures escape characters as text
  2015-09-10 17:56                                     ` Stefan Monnier
@ 2015-09-10 18:06                                       ` Eli Zaretskii
  2015-09-11 12:56                                         ` Stefan Monnier
  0 siblings, 1 reply; 64+ messages in thread
From: Eli Zaretskii @ 2015-09-10 18:06 UTC (permalink / raw)
  To: Stefan Monnier; +Cc: raeburn, 11822

> From: Stefan Monnier <monnier@iro.umontreal.ca>
> Cc: Ken Raeburn <raeburn@permabit.com>,  11822@debbugs.gnu.org
> Date: Thu, 10 Sep 2015 13:56:54 -0400
> 
> >   /* Contrary to expectations, a value of "false" can be detrimental to
> >      responsiveness since aborting a redisplay throws away some of the
> >      work already performed.
> 
> But that's because the effect was different from what is being
> discussed here (at least in theory): interrupting redisplay between
> windows wouldn't throw away work, AFAIK.

What Ken suggests is not an interruption between windows, it's
interruption in the middle of recomputing faces.  That's much worse.





^ permalink raw reply	[flat|nested] 64+ messages in thread

* bug#11822: 24.1; emacsclient terminal mode captures escape characters as text
  2015-09-10 15:36                                   ` Eli Zaretskii
  2015-09-10 17:56                                     ` Stefan Monnier
@ 2015-09-11  6:54                                     ` Ken Raeburn
  2015-09-11  7:22                                       ` Eli Zaretskii
  2015-09-11 13:39                                       ` Stefan Monnier
  1 sibling, 2 replies; 64+ messages in thread
From: Ken Raeburn @ 2015-09-11  6:54 UTC (permalink / raw)
  To: Eli Zaretskii; +Cc: 11822

Eli Zaretskii <eliz@gnu.org> writes:

>> [...preempting redisplay...]
> We had this ability in the past, but we all but deleted it, as it
> seemed not to make redisplay more responsive. [...]

> But it could be that we didn't look at the effect of this when frames
> are displayed via X over slow networks.  So please try experimenting
> with an Emacs before the deletion (I think 24.4 is old enough), and
> see if setting redisplay-dont-pause to nil helps in your case.  If it
> doesn't, then what you suggest above is probably not an idea that will
> yield tangible benefits.

Interesting.

Hmm... looking at the code (24.3.93 is what I have handy), it looks like
update_frame is the interesting point where this is checked, which is
called from redisplay_internal after the point where prepare_menu_bars
currently triggers recompute_basic_faces calls across the frames.

So if I understand this right, enabling this preemption (setting
redisplay-dont-pause to nil) would let new user input preempt redisplay
of some frames, but only after prepare_menu_bars has already caused the
color-related round-trips to happen. That seems to be the slow part, so
I'm not sure what I should expect to see happen differently.

>> >> Would changing sizes for a face cause the face to be recomputed from
>> >> scratch?
>> >
>> > It doesn't in my testing (I tried "C-x C-+").  You can easily try that
>> > yourself: put a breakpoint on recompute_basic_faces, and see if it
>> > breaks when you change the face size.
>> 
>> I tried it in the scratch buffer in a new Emacs process. It doesn't call
>> recompute_basic_faces, but it did call realize_face twice, and
>> XParseColor and x_alloc_nearest_color_1 each four times. So that's eight
>> round trips that seem unnecessary as we should already have the color
>> definitions and allocated color cells.
>
> For how many frames were XParseColor and x_alloc_nearest_color_1
> called?  If only for the single frame where you've changed the face,
> then it's expected.

In that test I had only one frame.

If I create a second frame also showing *scratch* and shrink the text
size, both frames need updating, and I do see twice as many calls.

If I create a second frame, load a text file into one frame, with no
font-lock highlighting, and shrink the text size for the text file, I
see two pairs of calls (one for white, one for black).

Those are as I'd expect -- once per frame showing that buffer, and only
for the faces affected. So it's only a smaller waste of time, but the
calls are still redundant with information we've already retrieved.

I've read that a tenth of a second is a good rough threshold on response
time between the user feeling that the program is responding immediately
and feeling that it isn't. With a RTT of 30ms, four round trips will
exceed that.

>
> If you are suggesting to be more selective wrt what exactly needs to
> be recomputed during face update, then this will need some analysis
> regarding which parts are more expensive than others, and introduction
> of corresponding flags to signal which face aspects need to be
> recomputed.  Assuming this is even possible without a more or less
> complete rewrite of face-related code (which currently just throws
> away a face and realizes it anew), the relative cost (in terms of
> time) of recomputing each aspects will most probably be different for
> different display back-ends, perhaps even for different network
> bandwidths.  Someone™ should do this research and publish the results,
> before we could start designing a good solution.

I don't think I'd try anything that fancy. Realizing faces from scratch
is probably fine as long as that can be made fast enough in most
reasonable cases.

>> > Given this general description, what would "lower priority" mean in
>> > practice?
>> 
>> Reorder the frame traversal.
>
> Since the goal is to limit redisplay to a single frame, the current
> one, I think this is a moot point.

Limiting redisplay to one frame when possible will go a long way. There
will still be cases that need to update multiple frames (like changing
faces used on multiple frames), but they may be infrequent enough that
we don't need to worry about it.

>> > My reading of the discussion and your backtraces indicate that all of
>> > that stems from a single problem: when we create or update faces, we
>> > set a global flag that causes faces to be recomputed on all frames.
>> > This then snowballs into the need to reload colors and redraw all
>> > frames.
>> 
>> I think that's the worst part for my new-frame-with-multiple-displays
>> case, but I don't think it's the only area of the code that could be
>> improved.
>
> We should see about that once the global face recalculation is gone.
>
>> I took a look at the calls to x_alloc_nearest_color_1. In creating an
>> initial frame with "emacs -Q", I get over two hundred calls, and every
>> one requires a round-trip to the server. But there were only 13 distinct
>> RGB color values passed. The most popular values passed were these:
>> 
>>      88 x_alloc_nearest_color_1(0000/0000/0000) (white)
>>      71 x_alloc_nearest_color_1(ffff/ffff/ffff) (black)
>>      15 x_alloc_nearest_color_1(bfbf/bfbf/bfbf) (grey75)
>> 
>> Then there's XParseColor; over 2300 calls, but only about 9% require
>> round-trips to the server, the rest using the "#RRGGBB" syntax that gets
>> parsed locally. I haven't traced which part of the program accounts for
>> what fraction of the calls.
>
> Once again, it is necessary to figure out which portions of these
> calls is on behalf of frames other than the one being created.  Those
> calls should all but go away after the global effect of face updating
> is eliminated.  Only after that we will see how much of this problem
> remains.

In case I wasn't clear, the numbers above were for creating the initial
frame; there was no other to act on behalf of. Emacs startup and
handling of the initial frame may be special in some ways compared to
creating additional frames once Emacs is up and running, but the startup
speed contributes to the user experience too. I know I'm sort of jumping
around between use cases here, but different use cases are impacted
differently by different aspects of the network handling here.

I've hit other cases that don't involve multiple frames. Tooltip window
popups involves way too many round trips, and highlighting and
un-highlighting parts of the mode line as the mouse is moved through it
can sometimes (not sure what the circumstances are) trigger color
queries on every change.

>> Eliminating unnecessary cache clearing might reduce these, maybe by a
>> factor of two or more, but that's still excessive
>
> What is the estimation of "factor of two or more" is based on?  Why
> not by an order of magnitude, for example?

My email a few days ago with the gdb stack traces showed three expensive
calls to recompute_basic_faces (plus three very cheap ones) in setting
up the initial frame. If that's caused by needlessly deciding twice that
we have to recompute faces we've already computed for the one and only
frame, and that those cases can be identified and fixed, that would
presumably eliminate two of the three sets of LookupColor and AllocColor
requests being issued because of recompute_basic_faces. There are
additional requests coming via other paths (e.g., setting mouse color),
so I don't think we'd get a full factor of three unless they're affected
in exactly the same way. Though, it's possible they could be worse
offenders, too. Three might be a better estimate than two, but I would
be very surprised (but pleased) to get much more than that this way.

There's no other frame at this point for there to be queries generated
for, so any code changes from "recompute on all frames" to "recompute on
the current frame" probably won't change this.

I was also thinking of the round-trips involved in the image (tool-bar
icon) handling, where x_disable_image caused a lot of round trips, but
that's not actually XParseColor and XAllocColor, it's XQueryColors, and
I haven't looked at whether there's redundant work there. Given that
there were nearly 100 round trips, I hope there is, since then we might
be able to eliminate some of them.

>
>> Now, if instead we had just *one* call to XAllocNamedColor for
>> "white", and one for "black", etc....
>
> Why do you think we will have more than that?

The color lookups are currently done for each face independently. If
multiple faces use the same colors, we'll have multiple requests to the
X server for those colors.

Consider: 15 faces times at least 2 colors per face (foreground and
background, plus maybe box, underline, overline, and strike-through),
times 2 round trips per color (LookupColor, assuming not a hex RGB
value, and AllocColor), is at least 60 round trips. At 30 ms per round
trip that's 1.8 seconds. Using XAllocNamedColor instead of
XParseColor+XAllocColor would cut that in half, but it would still be
very noticeable.

Ken

^ permalink raw reply	[flat|nested] 64+ messages in thread

* bug#11822: 24.1; emacsclient terminal mode captures escape characters as text
  2015-09-11  6:54                                     ` Ken Raeburn
@ 2015-09-11  7:22                                       ` Eli Zaretskii
  2015-09-11 23:11                                         ` Ken Raeburn
  2015-09-11 13:39                                       ` Stefan Monnier
  1 sibling, 1 reply; 64+ messages in thread
From: Eli Zaretskii @ 2015-09-11  7:22 UTC (permalink / raw)
  To: Ken Raeburn; +Cc: 11822

> From: Ken Raeburn <raeburn@permabit.com>
> Cc: 11822@debbugs.gnu.org
> Date: Fri, 11 Sep 2015 02:54:06 -0400
> 
> Eli Zaretskii <eliz@gnu.org> writes:
> 
> >> [...preempting redisplay...]
> > We had this ability in the past, but we all but deleted it, as it
> > seemed not to make redisplay more responsive. [...]
> 
> > But it could be that we didn't look at the effect of this when frames
> > are displayed via X over slow networks.  So please try experimenting
> > with an Emacs before the deletion (I think 24.4 is old enough), and
> > see if setting redisplay-dont-pause to nil helps in your case.  If it
> > doesn't, then what you suggest above is probably not an idea that will
> > yield tangible benefits.
> 
> Interesting.
> 
> Hmm... looking at the code (24.3.93 is what I have handy), it looks like
> update_frame is the interesting point where this is checked, which is
> called from redisplay_internal after the point where prepare_menu_bars
> currently triggers recompute_basic_faces calls across the frames.
> 
> So if I understand this right, enabling this preemption (setting
> redisplay-dont-pause to nil) would let new user input preempt redisplay
> of some frames, but only after prepare_menu_bars has already caused the
> color-related round-trips to happen. That seems to be the slow part, so
> I'm not sure what I should expect to see happen differently.

It should avoid redisplaying other frames when input is available
after redisplaying the first one.  Your original complaint was (and
still is, as far as I'm concerned) that Emacs was unnecessarily trying
to redisplay frames on another display, which caused undue network
round-trips for communicating with X.  Setting that variable to nil
should at most only redraw the selected frame when user input is
available.  If you perform this experiment when the frame(s) in need
of network communications are on the inactive display, you should see
whether the effect is tangible.  If it isn't, trying to refrain from
displaying frames on other displays, per one of your suggestions, will
not be very effective, perhaps not at all, and we need to look for
other ways to optimize this use case.

> >> >> Would changing sizes for a face cause the face to be recomputed from
> >> >> scratch?
> >> >
> >> > It doesn't in my testing (I tried "C-x C-+").  You can easily try that
> >> > yourself: put a breakpoint on recompute_basic_faces, and see if it
> >> > breaks when you change the face size.
> >> 
> >> I tried it in the scratch buffer in a new Emacs process. It doesn't call
> >> recompute_basic_faces, but it did call realize_face twice, and
> >> XParseColor and x_alloc_nearest_color_1 each four times. So that's eight
> >> round trips that seem unnecessary as we should already have the color
> >> definitions and allocated color cells.
> >
> > For how many frames were XParseColor and x_alloc_nearest_color_1
> > called?  If only for the single frame where you've changed the face,
> > then it's expected.
> 
> In that test I had only one frame.

Then these calls cannot be avoided with the current design of face
realization.  IOW, creating a single frame where communications with X
are over a slow network will always be slow, unless we radically
change the design and implementation of faces.

> > If you are suggesting to be more selective wrt what exactly needs to
> > be recomputed during face update, then this will need some analysis
> > regarding which parts are more expensive than others, and introduction
> > of corresponding flags to signal which face aspects need to be
> > recomputed.  Assuming this is even possible without a more or less
> > complete rewrite of face-related code (which currently just throws
> > away a face and realizes it anew), the relative cost (in terms of
> > time) of recomputing each aspects will most probably be different for
> > different display back-ends, perhaps even for different network
> > bandwidths.  Someone™ should do this research and publish the results,
> > before we could start designing a good solution.
> 
> I don't think I'd try anything that fancy. Realizing faces from scratch
> is probably fine as long as that can be made fast enough in most
> reasonable cases.

??? Doesn't this contradict with your measurements above, where X
calls for even a single frame take too long?  How can we make this
faster without changing how faces are realized?  What am I missing?

> >> > Given this general description, what would "lower priority" mean in
> >> > practice?
> >> 
> >> Reorder the frame traversal.
> >
> > Since the goal is to limit redisplay to a single frame, the current
> > one, I think this is a moot point.
> 
> Limiting redisplay to one frame when possible will go a long way. There
> will still be cases that need to update multiple frames (like changing
> faces used on multiple frames), but they may be infrequent enough that
> we don't need to worry about it.

I learned the hard way to solve problems one at a time, starting with
the one that gives the most benefit.

> >> I took a look at the calls to x_alloc_nearest_color_1. In creating an
> >> initial frame with "emacs -Q", I get over two hundred calls, and every
> >> one requires a round-trip to the server. But there were only 13 distinct
> >> RGB color values passed. The most popular values passed were these:
> >> 
> >>      88 x_alloc_nearest_color_1(0000/0000/0000) (white)
> >>      71 x_alloc_nearest_color_1(ffff/ffff/ffff) (black)
> >>      15 x_alloc_nearest_color_1(bfbf/bfbf/bfbf) (grey75)
> >> 
> >> Then there's XParseColor; over 2300 calls, but only about 9% require
> >> round-trips to the server, the rest using the "#RRGGBB" syntax that gets
> >> parsed locally. I haven't traced which part of the program accounts for
> >> what fraction of the calls.
> >
> > Once again, it is necessary to figure out which portions of these
> > calls is on behalf of frames other than the one being created.  Those
> > calls should all but go away after the global effect of face updating
> > is eliminated.  Only after that we will see how much of this problem
> > remains.
> 
> In case I wasn't clear, the numbers above were for creating the initial
> frame

Then please help me understand why creating a single frame needs so
many color-related calls on X.  I know very little about X GUI
performance, and the person who was our X expert is no longer on
board, sadly.

> I've hit other cases that don't involve multiple frames. Tooltip window
> popups involves way too many round trips, and highlighting and
> un-highlighting parts of the mode line as the mouse is moved through it
> can sometimes (not sure what the circumstances are) trigger color
> queries on every change.

Please tell which calls take the lion's share of time in these
scenarios, and please show the backtraces for those calls.

> >> Eliminating unnecessary cache clearing might reduce these, maybe by a
> >> factor of two or more, but that's still excessive
> >
> > What is the estimation of "factor of two or more" is based on?  Why
> > not by an order of magnitude, for example?
> 
> My email a few days ago with the gdb stack traces showed three expensive
> calls to recompute_basic_faces (plus three very cheap ones) in setting
> up the initial frame.

I asked back then why there are multiple calls, since the first call
resets the face_change flag.  I asked you to try to figure out which
code sets the flag again.  I'd still appreciate the answer to that.

> Three might be a better estimate than two, but I would be very
> surprised (but pleased) to get much more than that this way.
> 
> There's no other frame at this point for there to be queries generated
> for, so any code changes from "recompute on all frames" to "recompute on
> the current frame" probably won't change this.

You forget that setting the face_change flag also causes a complete
redrawing of a frame, so avoiding that might produce more benefits.

IOW, until we really measure the difference, we will never know what
is the factor.  It could even be (a disappointing) 1.1.

> I was also thinking of the round-trips involved in the image (tool-bar
> icon) handling, where x_disable_image caused a lot of round trips, but
> that's not actually XParseColor and XAllocColor, it's XQueryColors, and
> I haven't looked at whether there's redundant work there. Given that
> there were nearly 100 round trips, I hope there is, since then we might
> be able to eliminate some of them.

Please show the relevant data.  Images are also cached, AFAIR, so I'd
expect not to see unnecessary calls.

> The color lookups are currently done for each face independently. If
> multiple faces use the same colors, we'll have multiple requests to the
> X server for those colors.

That should be part of redesigning how faces are realized.  But you
rejected the idea, so how do you expect this to happen?

> Consider: 15 faces times at least 2 colors per face (foreground and
> background, plus maybe box, underline, overline, and strike-through),
> times 2 round trips per color (LookupColor, assuming not a hex RGB
> value, and AllocColor), is at least 60 round trips. At 30 ms per round
> trip that's 1.8 seconds. Using XAllocNamedColor instead of
> XParseColor+XAllocColor would cut that in half, but it would still be
> very noticeable.

Out of curiosity: is this all true for the Cairo build as well?  Or
does that build save us these round-trips?





^ permalink raw reply	[flat|nested] 64+ messages in thread

* bug#11822: 24.1; emacsclient terminal mode captures escape characters as text
  2015-09-10 18:06                                       ` Eli Zaretskii
@ 2015-09-11 12:56                                         ` Stefan Monnier
  2015-09-11 13:53                                           ` Eli Zaretskii
  0 siblings, 1 reply; 64+ messages in thread
From: Stefan Monnier @ 2015-09-11 12:56 UTC (permalink / raw)
  To: Eli Zaretskii; +Cc: raeburn, 11822

>> >   /* Contrary to expectations, a value of "false" can be detrimental to
>> >      responsiveness since aborting a redisplay throws away some of the
>> >      work already performed.
>> But that's because the effect was different from what is being
>> discussed here (at least in theory): interrupting redisplay between
>> windows wouldn't throw away work, AFAIK.
> What Ken suggests is not an interruption between windows, it's
> interruption in the middle of recomputing faces.  That's much worse.

I think he suggests several things.

One of them is to redisplay frame-by-frame, starting with the selected
frame and checking for pending input between each frame.

Another is to do decompose the redisplay of a given window into
chunks (e.g. cut at those points where we're waiting for a reply from
the X server) that can be interrupted.  IIUC by "interrupted" he doesn't
mean to abort what we're doing, but only to suspend it.

What we need to remember from redisplay-dont-pause is that we need to
avoid doing work and throwing it away before the result is shown on
the display.  In the case of redisplay-dont-pause, the reason it's
thrown away is that by the time we got back, the work we'd done
(refreshing the matrices) often/usually needed to be redone.

If we only interrupt after refreshing the display of a window and before
starting to recompute the glyph matrices of the next, then I think we
avoid this risk.

        Stefan

^ permalink raw reply	[flat|nested] 64+ messages in thread

* bug#11822: 24.1; emacsclient terminal mode captures escape characters as text
  2015-09-11  6:54                                     ` Ken Raeburn
  2015-09-11  7:22                                       ` Eli Zaretskii
@ 2015-09-11 13:39                                       ` Stefan Monnier
  2015-09-11 14:01                                         ` Eli Zaretskii
  1 sibling, 1 reply; 64+ messages in thread
From: Stefan Monnier @ 2015-09-11 13:39 UTC (permalink / raw)
  To: Ken Raeburn; +Cc: 11822

> speed contributes to the user experience too. I know I'm sort of jumping
> around between use cases here, but different use cases are impacted
> differently by different aspects of the network handling here.

Right.  I think we should take one case at a time.
E.g. let's first try and make sure that opening a new frame on a new
display doesn't force a heavy redisplay of all other frames (it'll
necessarily force a minor redisplay in the previously selected frame,
but that should be OK).


        Stefan





^ permalink raw reply	[flat|nested] 64+ messages in thread

* bug#11822: 24.1; emacsclient terminal mode captures escape characters as text
  2015-09-11 12:56                                         ` Stefan Monnier
@ 2015-09-11 13:53                                           ` Eli Zaretskii
  2015-09-11 16:53                                             ` Stefan Monnier
  0 siblings, 1 reply; 64+ messages in thread
From: Eli Zaretskii @ 2015-09-11 13:53 UTC (permalink / raw)
  To: Stefan Monnier; +Cc: raeburn, 11822

> From: Stefan Monnier <monnier@iro.umontreal.ca>
> Cc: raeburn@permabit.com,  11822@debbugs.gnu.org
> Date: Fri, 11 Sep 2015 08:56:58 -0400
> 
> >> >   /* Contrary to expectations, a value of "false" can be detrimental to
> >> >      responsiveness since aborting a redisplay throws away some of the
> >> >      work already performed.
> >> But that's because the effect was different from what is being
> >> discussed here (at least in theory): interrupting redisplay between
> >> windows wouldn't throw away work, AFAIK.
> > What Ken suggests is not an interruption between windows, it's
> > interruption in the middle of recomputing faces.  That's much worse.
> 
> I think he suggests several things.

Yes.  IMO, the discussion is not focused enough.

> Another is to do decompose the redisplay of a given window into
> chunks (e.g. cut at those points where we're waiting for a reply from
> the X server) that can be interrupted.  IIUC by "interrupted" he doesn't
> mean to abort what we're doing, but only to suspend it.

We don't have any infrastructure for suspending redisplay.

> What we need to remember from redisplay-dont-pause is that we need to
> avoid doing work and throwing it away before the result is shown on
> the display.  In the case of redisplay-dont-pause, the reason it's
> thrown away is that by the time we got back, the work we'd done
> (refreshing the matrices) often/usually needed to be redone.

Isn't that going to be the same with the proposed suspension?

> If we only interrupt after refreshing the display of a window and before
> starting to recompute the glyph matrices of the next, then I think we
> avoid this risk.

That would immediately exclude text-mode frames, where the updates are
always to the entire frame.

It would also exclude situations where more redisplaying a window
affects another window.  We will have to detect those cases somehow.

In short, I'm not sure this direction is worthy pursuing.  I think we
should first stop updating irrelevant frames due to face changes, and
then see about minimizing the color-related X calls when faces of a
frame do need to be recomputed.  All the rest can wait until after
that.





^ permalink raw reply	[flat|nested] 64+ messages in thread

* bug#11822: 24.1; emacsclient terminal mode captures escape characters as text
  2015-09-11 13:39                                       ` Stefan Monnier
@ 2015-09-11 14:01                                         ` Eli Zaretskii
  0 siblings, 0 replies; 64+ messages in thread
From: Eli Zaretskii @ 2015-09-11 14:01 UTC (permalink / raw)
  To: Stefan Monnier; +Cc: raeburn, 11822

> From: Stefan Monnier <monnier@iro.umontreal.ca>
> Cc: Eli Zaretskii <eliz@gnu.org>,  11822@debbugs.gnu.org
> Date: Fri, 11 Sep 2015 09:39:13 -0400
> 
> E.g. let's first try and make sure that opening a new frame on a new
> display doesn't force a heavy redisplay of all other frames

Indeed.  I'll try to push a test branch in a couple of days that
attempts to achieve that.





^ permalink raw reply	[flat|nested] 64+ messages in thread

* bug#11822: 24.1; emacsclient terminal mode captures escape characters as text
  2015-09-11 13:53                                           ` Eli Zaretskii
@ 2015-09-11 16:53                                             ` Stefan Monnier
  0 siblings, 0 replies; 64+ messages in thread
From: Stefan Monnier @ 2015-09-11 16:53 UTC (permalink / raw)
  To: Eli Zaretskii; +Cc: raeburn, 11822

>> Another is to do decompose the redisplay of a given window into
>> chunks (e.g. cut at those points where we're waiting for a reply from
>> the X server) that can be interrupted.  IIUC by "interrupted" he doesn't
>> mean to abort what we're doing, but only to suspend it.
> We don't have any infrastructure for suspending redisplay.

Agreed, which I think is the more serious obstacle to this suggestion.

>> What we need to remember from redisplay-dont-pause is that we need to
>> avoid doing work and throwing it away before the result is shown on
>> the display.  In the case of redisplay-dont-pause, the reason it's
>> thrown away is that by the time we got back, the work we'd done
>> (refreshing the matrices) often/usually needed to be redone.
> Isn't that going to be the same with the proposed suspension?

It could be, indeed.  Tho if we assume that modifications to
non-selected frames are infrequent and the suspension is only used
for the redisplay of the non-selected frame, then there's a good chance
that when we come back to the redisplay the suspended work can be
continued rather than having to start over.

In any case, as you pointed out above, allowing such suspension would
require a fair bit of work on the redisplay (and probably even in more
places).

My guess is that making redisplay concurrent (i.e. take place while the
main Elisp thread is running) won't be that much more work, and it'd
bring a lot more benefits.

>> If we only interrupt after refreshing the display of a window and before
>> starting to recompute the glyph matrices of the next, then I think we
>> avoid this risk.
> That would immediately exclude text-mode frames, where the updates are
> always to the entire frame.

Then replace "window" with "frame" above.

> It would also exclude situations where more redisplaying a window
> affects another window.

Hmmm... I don't know what you're referring to here.

> In short, I'm not sure this direction is worthy pursuing.  I think we
> should first stop updating irrelevant frames due to face changes, and
> then see about minimizing the color-related X calls when faces of a
> frame do need to be recomputed.  All the rest can wait until after
> that.

100% agreement.


        Stefan





^ permalink raw reply	[flat|nested] 64+ messages in thread

* bug#11822: 24.1; emacsclient terminal mode captures escape characters as text
  2015-09-11  7:22                                       ` Eli Zaretskii
@ 2015-09-11 23:11                                         ` Ken Raeburn
  2015-09-12  0:51                                           ` Stefan Monnier
  2015-09-12  7:30                                           ` Eli Zaretskii
  0 siblings, 2 replies; 64+ messages in thread
From: Ken Raeburn @ 2015-09-11 23:11 UTC (permalink / raw)
  To: Eli Zaretskii; +Cc: 11822

Eli Zaretskii <eliz@gnu.org> writes:

>> >> [...preempting redisplay...]
>> > We had this ability in the past, but we all but deleted it, as it
>> > seemed not to make redisplay more responsive. [...]
>> 
>> > But it could be that we didn't look at the effect of this when frames
>> > are displayed via X over slow networks.  So please try experimenting
>> > with an Emacs before the deletion (I think 24.4 is old enough), and
>> > see if setting redisplay-dont-pause to nil helps in your case.  If it
>> > doesn't, then what you suggest above is probably not an idea that will
>> > yield tangible benefits.
>> 
>> Interesting.
>> 
>> Hmm... looking at the code (24.3.93 is what I have handy), it looks like
>> update_frame is the interesting point where this is checked, which is
>> called from redisplay_internal after the point where prepare_menu_bars
>> currently triggers recompute_basic_faces calls across the frames.
>> 
>> So if I understand this right, enabling this preemption (setting
>> redisplay-dont-pause to nil) would let new user input preempt redisplay
>> of some frames, but only after prepare_menu_bars has already caused the
>> color-related round-trips to happen. That seems to be the slow part, so
>> I'm not sure what I should expect to see happen differently.
>
> It should avoid redisplaying other frames when input is available
> after redisplaying the first one.  Your original complaint was (and
> still is, as far as I'm concerned) that Emacs was unnecessarily trying
> to redisplay frames on another display, which caused undue network
> round-trips for communicating with X.  Setting that variable to nil
> should at most only redraw the selected frame when user input is
> available.  If you perform this experiment when the frame(s) in need
> of network communications are on the inactive display, you should see
> whether the effect is tangible.  If it isn't, trying to refrain from
> displaying frames on other displays, per one of your suggestions, will
> not be very effective, perhaps not at all, and we need to look for
> other ways to optimize this use case.

Well... if by "redisplay" we include both the face realization and text
drawing, yes, that's my complaint, but no, I don't think the flag will
avoid *all* of the redisplay mechanism for frames after the first, only
the text-drawing part. If we get as far as redrawing text on any of the
frames, including the selected one, it looks to me like by that point
we've already updated faces on any frames for which we think we need to,
and that's the part that makes it slow.

So I'd expect it to possibly "save" an unnoticeable amount of time
during which it previously would've sent off text updates to other
frames without waiting for any X server replies.

(Also: Iconifying the remote frame doesn't seem to help. In
prepare_menu_bars, when all_windows is set but some_windows is not, the
call to x_consider_frame_title, which can trigger face realization, *is*
called for iconified frames.)

>> >> >> Would changing sizes for a face cause the face to be recomputed from
>> >> >> scratch?
>> >> >
>> >> > It doesn't in my testing (I tried "C-x C-+").  You can easily try that
>> >> > yourself: put a breakpoint on recompute_basic_faces, and see if it
>> >> > breaks when you change the face size.
>> >> 
>> >> I tried it in the scratch buffer in a new Emacs process. It doesn't call
>> >> recompute_basic_faces, but it did call realize_face twice, and
>> >> XParseColor and x_alloc_nearest_color_1 each four times. So that's eight
>> >> round trips that seem unnecessary as we should already have the color
>> >> definitions and allocated color cells.
>> >
>> > For how many frames were XParseColor and x_alloc_nearest_color_1
>> > called?  If only for the single frame where you've changed the face,
>> > then it's expected.
>> 
>> In that test I had only one frame.
>
> Then these calls cannot be avoided with the current design of face
> realization.  IOW, creating a single frame where communications with X
> are over a slow network will always be slow, unless we radically
> change the design and implementation of faces.

We can reduce the number of round trips. If we only ever use 13 distinct
named colors, in an ideal world we could make do with 13 round trips to
allocate them in the colormap. But then we need an additional level of
reference counting or garbage collection on the client (Emacs) side.

>> > If you are suggesting to be more selective wrt what exactly needs to
>> > be recomputed during face update, then this will need some analysis
>> > regarding which parts are more expensive than others, and introduction
>> > of corresponding flags to signal which face aspects need to be
>> > recomputed.  Assuming this is even possible without a more or less
>> > complete rewrite of face-related code (which currently just throws
>> > away a face and realizes it anew), the relative cost (in terms of
>> > time) of recomputing each aspects will most probably be different for
>> > different display back-ends, perhaps even for different network
>> > bandwidths.  Someone™ should do this research and publish the results,
>> > before we could start designing a good solution.
>> 
>> I don't think I'd try anything that fancy. Realizing faces from scratch
>> is probably fine as long as that can be made fast enough in most
>> reasonable cases.
>
> ??? Doesn't this contradict with your measurements above, where X
> calls for even a single frame take too long?  How can we make this
> faster without changing how faces are realized?  What am I missing?

Sorry, bad editing job. I initially wrote "I don't think I'd try
anything that fancy at first." Start with reducing unnecessary frame
updates and face cache invalidations (reducing the number of face
realization calls), and redundant color lookups (which could make
realizing any single face anew faster), and only if that's not enough
should we consider more complicated stuff like the above.

>
>> >> > Given this general description, what would "lower priority" mean in
>> >> > practice?
>> >> 
>> >> Reorder the frame traversal.
>> >
>> > Since the goal is to limit redisplay to a single frame, the current
>> > one, I think this is a moot point.
>> 
>> Limiting redisplay to one frame when possible will go a long way. There
>> will still be cases that need to update multiple frames (like changing
>> faces used on multiple frames), but they may be infrequent enough that
>> we don't need to worry about it.
>
> I learned the hard way to solve problems one at a time, starting with
> the one that gives the most benefit.

I think you're right... I see multiple types of behavior that are more
sluggish than I'd like, and what look like multiple possible
optimization areas, but some of them are overlapping (not all, I think),
and it's just adding confusion by mixing them all up in the discussion
at once. I should just keep a list of things to revisit later, or at
least as separate issues not linked to this bug report. (New bug
reports? Emacs-devel threads?)

>> >> [over 200 color-allocation calls]
>> In case I wasn't clear, the numbers above were for creating the initial
>> frame
>
> Then please help me understand why creating a single frame needs so
> many color-related calls on X.  I know very little about X GUI
> performance, and the person who was our X expert is no longer on
> board, sadly.

I don't know yet, but it's on my list. :-)

I'm no X performance expert either, but some of the relevant bits I
remember from looking at X11 in the past:

 * Many requests, including text drawing, need no reply. The client
   sends the request and continues about its business. Maybe an error
   response comes back later, maybe not. A "Sync" request is available
   if the client needs to know that the server has completed everything.

   So text updates, unless they're big enough to fill socket buffers, or
   cause so much work for the server that they hold up processing of
   later requests the client needs responses to, aren't dependent on
   network latency. The client can send "draw these strings at these
   positions" and then go off and do something else.

 * Some requests do require replies from the server, like color lookup
   (return RGB data from server-side database) or color cell allocation
   (return pixel ID), and the library is not generally designed to allow
   for pipelining of these requests; it'll wait for the reply before
   returning control to the application.

 * Color allocations on the server are reference-counted. Multiple
   allocations for the same color will (likely) return the same pixel
   value, and require multiple "free" requests to make it considered
   unused again.

 * Some types of displays are limited in the number of colors they can
   show, so being a good X neighbor involves freeing colors (the correct
   number of times) if you're done with them and not about to shut down
   the connection, unless you're using a private colormap, in which case
   the only foot you might shoot is your own. I'm not sure if these
   display types are at all common any more.

For a local X server, the round trip time is cheap enough that it's
probably good enough to generate all the extra traffic and accept the
(very brief) waits for replies, and just let the X server deal with
maintaining the reference counts on color cells.

>> I've hit other cases that don't involve multiple frames. Tooltip window
>> popups involves way too many round trips, and highlighting and
>> un-highlighting parts of the mode line as the mouse is moved through it
>> can sometimes (not sure what the circumstances are) trigger color
>> queries on every change.
>
> Please tell which calls take the lion's share of time in these
> scenarios, and please show the backtraces for those calls.

Also on my list.

>> >> Eliminating unnecessary cache clearing might reduce these, maybe by a
>> >> factor of two or more, but that's still excessive
>> >
>> > What is the estimation of "factor of two or more" is based on?  Why
>> > not by an order of magnitude, for example?
>> 
>> My email a few days ago with the gdb stack traces showed three expensive
>> calls to recompute_basic_faces (plus three very cheap ones) in setting
>> up the initial frame.
>
> I asked back then why there are multiple calls, since the first call
> resets the face_change flag.  I asked you to try to figure out which
> code sets the flag again.  I'd still appreciate the answer to that.

Sorry, I must have overlooked that.

>> Three might be a better estimate than two, but I would be very
>> surprised (but pleased) to get much more than that this way.
>> 
>> There's no other frame at this point for there to be queries generated
>> for, so any code changes from "recompute on all frames" to "recompute on
>> the current frame" probably won't change this.
>
> You forget that setting the face_change flag also causes a complete
> redrawing of a frame, so avoiding that might produce more benefits.
>
> IOW, until we really measure the difference, we will never know what
> is the factor.  It could even be (a disappointing) 1.1.

Yes, I was just guessing at those numbers.

>> I was also thinking of the round-trips involved in the image (tool-bar
>> icon) handling, where x_disable_image caused a lot of round trips, but
>> that's not actually XParseColor and XAllocColor, it's XQueryColors, and
>> I haven't looked at whether there's redundant work there. Given that
>> there were nearly 100 round trips, I hope there is, since then we might
>> be able to eliminate some of them.
>
> Please show the relevant data.  Images are also cached, AFAIR, so I'd
> expect not to see unnecessary calls.

That's why overall I'd expect to see a poorer-than-3 reduction in round
trips. I originally erred in conflating this with color-handling
requests specifically.

>> The color lookups are currently done for each face independently. If
>> multiple faces use the same colors, we'll have multiple requests to the
>> X server for those colors.
>
> That should be part of redesigning how faces are realized.  But you
> rejected the idea, so how do you expect this to happen?

Let the generic face code continue to process each face independently.
It doesn't need to know that the X11 layer is providing the information
out of a cache in "struct x_display_info". Such a cache might also help
with lookups from image-processing code too.

>> Consider: 15 faces times at least 2 colors per face (foreground and
>> background, plus maybe box, underline, overline, and strike-through),
>> times 2 round trips per color (LookupColor, assuming not a hex RGB
>> value, and AllocColor), is at least 60 round trips. At 30 ms per round
>> trip that's 1.8 seconds. Using XAllocNamedColor instead of
>> XParseColor+XAllocColor would cut that in half, but it would still be
>> very noticeable.
>
> Out of curiosity: is this all true for the Cairo build as well?  Or
> does that build save us these round-trips?

I've no idea; I'll have to look into that.

Ken

^ permalink raw reply	[flat|nested] 64+ messages in thread

* bug#11822: 24.1; emacsclient terminal mode captures escape characters as text
  2015-09-11 23:11                                         ` Ken Raeburn
@ 2015-09-12  0:51                                           ` Stefan Monnier
  2015-09-12  1:34                                             ` Ken Raeburn
  2015-09-15 14:29                                             ` Eli Zaretskii
  2015-09-12  7:30                                           ` Eli Zaretskii
  1 sibling, 2 replies; 64+ messages in thread
From: Stefan Monnier @ 2015-09-12  0:51 UTC (permalink / raw)
  To: Ken Raeburn; +Cc: 11822

> (Also: Iconifying the remote frame doesn't seem to help. In
> prepare_menu_bars, when all_windows is set but some_windows is not, the
> call to x_consider_frame_title, which can trigger face realization, *is*
> called for iconified frames.)

Maybe instead of doing

  prepare_menu_bars:
    (forall frames (compute-title-and-stuff))
  later:
    (forall frames (recompute-glyph-matrices-and-then-display))

we should do

  (forall frames
    (compute-title-and-stuff)
    (recompute-glyph-matrices-and-then-display))

>  * Some requests do require replies from the server, like color lookup
>    (return RGB data from server-side database) or color cell allocation
>    (return pixel ID), and the library is not generally designed to allow
>    for pipelining of these requests; it'll wait for the reply before
>    returning control to the application.

BTW, IIUC while Xlib is not designed for that, the newer Xcb library
exposes the underlying wire protocol more directly, making it possible
to send several color requests before waiting for the replies.

>  * Some types of displays are limited in the number of colors they can
>    show, so being a good X neighbor involves freeing colors (the correct
>    number of times) if you're done with them and not about to shut down
>    the connection, unless you're using a private colormap, in which case
>    the only foot you might shoot is your own. I'm not sure if these
>    display types are at all common any more.

FWIW, I've used 8bit-deep framebuffers not that long ago.
But they're probably rare by now, indeed.

> For a local X server, the round trip time is cheap enough that it's
> probably good enough to generate all the extra traffic and accept the
> (very brief) waits for replies, and just let the X server deal with
> maintaining the reference counts on color cells.

As mentioned earlier, I think this is not true if we repeat it per-frame
since we can have 100 frames, at which point the delay can become
significant even locally.


        Stefan





^ permalink raw reply	[flat|nested] 64+ messages in thread

* bug#11822: 24.1; emacsclient terminal mode captures escape characters as text
  2015-09-12  0:51                                           ` Stefan Monnier
@ 2015-09-12  1:34                                             ` Ken Raeburn
  2015-09-15 14:29                                             ` Eli Zaretskii
  1 sibling, 0 replies; 64+ messages in thread
From: Ken Raeburn @ 2015-09-12  1:34 UTC (permalink / raw)
  To: Stefan Monnier; +Cc: 11822

> Maybe instead of doing
> 
>  prepare_menu_bars:
>    (forall frames (compute-title-and-stuff))
>  later:
>    (forall frames (recompute-glyph-matrices-and-then-display))
> 
> we should do
> 
>  (forall frames
>    (compute-title-and-stuff)
>    (recompute-glyph-matrices-and-then-display))

I think that would probably help, yes.

> BTW, IIUC while Xlib is not designed for [pipelining requests we need to
> receive responses for], the newer Xcb library
> exposes the underlying wire protocol more directly, making it possible
> to send several color requests before waiting for the replies.

That’s good news. Taking full advantage of it would probably require changes to the generic face code, if we want to send all the color names for multiple faces and then wait to collect the responses. But on a smaller scale, doing it for all colors used in defining one face would be a start.

> FWIW, I've used 8bit-deep framebuffers not that long ago.
> But they're probably rare by now, indeed.

So we should probably still support them, I expect. But it may be worth optimizing for the more common case; for example, we could try allocating new colors as they’re requested, when they’re not cached, and if we fail to allocate, then maybe we go clean out the cache of colors no longer in use. (Or after a timeout of several seconds of idle time or something like that, to help us play nicer with the neighbors.)

> As mentioned earlier, I think this is not true if we repeat it per-frame
> since we can have 100 frames, at which point the delay can become
> significant even locally.

Yes. I expect the work you’ve started should help a great deal in that area.

Ken

^ permalink raw reply	[flat|nested] 64+ messages in thread

* bug#11822: 24.1; emacsclient terminal mode captures escape characters as text
  2015-09-11 23:11                                         ` Ken Raeburn
  2015-09-12  0:51                                           ` Stefan Monnier
@ 2015-09-12  7:30                                           ` Eli Zaretskii
  1 sibling, 0 replies; 64+ messages in thread
From: Eli Zaretskii @ 2015-09-12  7:30 UTC (permalink / raw)
  To: Ken Raeburn; +Cc: 11822

> From: Ken Raeburn <raeburn@permabit.com>
> Cc: 11822@debbugs.gnu.org
> Date: Fri, 11 Sep 2015 19:11:30 -0400
> 
> > [redisplay-dont-pause] should avoid redisplaying other frames
> > when input is available after redisplaying the first one.  Your
> > original complaint was (and still is, as far as I'm concerned)
> > that Emacs was unnecessarily trying to redisplay frames on another
> > display, which caused undue network round-trips for communicating
> > with X.  Setting that variable to nil should at most only redraw
> > the selected frame when user input is available.  If you perform
> > this experiment when the frame(s) in need of network
> > communications are on the inactive display, you should see whether
> > the effect is tangible.  If it isn't, trying to refrain from
> > displaying frames on other displays, per one of your suggestions,
> > will not be very effective, perhaps not at all, and we need to
> > look for other ways to optimize this use case.
> 
> Well... if by "redisplay" we include both the face realization and text
> drawing, yes, that's my complaint, but no, I don't think the flag will
> avoid *all* of the redisplay mechanism for frames after the first, only
> the text-drawing part. If we get as far as redrawing text on any of the
> frames, including the selected one, it looks to me like by that point
> we've already updated faces on any frames for which we think we need to,
> and that's the part that makes it slow.

Please look at the code (as it was before what I describe was
deleted): We have a loop over all frames.  Each iteration through the
loop, we first compute the glyph matrices for all the windows on that
frame (by calling redisplay_windows), which includes recalculating all
the faces when we think they changed.  Then we call update_frame for
that frame, which delivers the changes to the glass.  If update_frame
returns non-zero, _we_abort_the_loop_, i.e. we don't proceed doing
anything for the remaining frames.  And update_frame returns non-zero
if it sees input available and redisplay-dont-pause is nil.

Therefore, when input becomes available during displaying the first
frame, at most that one frame should be redrawn, and then Emacs should
abandon redisplay.  It should continue abandoning it for as long as
there's input to process.

At some point, we removed the code that broke out of the frame
displaying loop in that scenario, so now what happens is indeed what
you describe.  We even had a more elaborate code that aborted the loop
based on measuring the time it took to redisplay the first frames; it
was also deleted.

We could reinstate all that, but given that we deleted it several
releases ago, this begs the question how far are we prepared to go for
catering to such rare use cases?

> So I'd expect it to possibly "save" an unnoticeable amount of time
> during which it previously would've sent off text updates to other
> frames without waiting for any X server replies.

Do you still think so, after what I explained above?

> (Also: Iconifying the remote frame doesn't seem to help. In
> prepare_menu_bars, when all_windows is set but some_windows is not, the
> call to x_consider_frame_title, which can trigger face realization, *is*
> called for iconified frames.)

Something else to optimize, I guess.

> > Then these calls cannot be avoided with the current design of face
> > realization.  IOW, creating a single frame where communications with X
> > are over a slow network will always be slow, unless we radically
> > change the design and implementation of faces.
> 
> We can reduce the number of round trips. If we only ever use 13 distinct
> named colors, in an ideal world we could make do with 13 round trips to
> allocate them in the colormap. But then we need an additional level of
> reference counting or garbage collection on the client (Emacs) side.

I said "unless we radically change the design and implementation of
faces".  We must work on our communications skills, because otherwise
I cannot see how what you say contradicts what I said.

> Start with reducing unnecessary frame updates and face cache
> invalidations (reducing the number of face realization calls), and
> redundant color lookups (which could make realizing any single face
> anew faster), and only if that's not enough should we consider more
> complicated stuff like the above.

I will leave the color look up stuff out of the initial attempt to
optimize this use case, primarily because I think it's a separate
step, which logically belongs to changing how faces are realized, and
also because I'd like to see how much of the problem is removed by
that initial attempt.

> >> The color lookups are currently done for each face independently. If
> >> multiple faces use the same colors, we'll have multiple requests to the
> >> X server for those colors.
> >
> > That should be part of redesigning how faces are realized.  But you
> > rejected the idea, so how do you expect this to happen?
> 
> Let the generic face code continue to process each face independently.
> It doesn't need to know that the X11 layer is providing the information
> out of a cache in "struct x_display_info". Such a cache might also help
> with lookups from image-processing code too.

Patches to the relevant parts of the X display back-end to do this are
welcome.

Thanks.

^ permalink raw reply	[flat|nested] 64+ messages in thread

* bug#11822: 24.1; emacsclient terminal mode captures escape characters as text
  2015-09-12  0:51                                           ` Stefan Monnier
  2015-09-12  1:34                                             ` Ken Raeburn
@ 2015-09-15 14:29                                             ` Eli Zaretskii
  2015-09-15 16:14                                               ` Stefan Monnier
  1 sibling, 1 reply; 64+ messages in thread
From: Eli Zaretskii @ 2015-09-15 14:29 UTC (permalink / raw)
  To: Stefan Monnier; +Cc: raeburn, 11822

> From: Stefan Monnier <monnier@iro.umontreal.ca>
> Cc: Eli Zaretskii <eliz@gnu.org>,  11822@debbugs.gnu.org
> Date: Fri, 11 Sep 2015 20:51:46 -0400
> 
> > (Also: Iconifying the remote frame doesn't seem to help. In
> > prepare_menu_bars, when all_windows is set but some_windows is not, the
> > call to x_consider_frame_title, which can trigger face realization, *is*
> > called for iconified frames.)
> 
> Maybe instead of doing
> 
>   prepare_menu_bars:
>     (forall frames (compute-title-and-stuff))
>   later:
>     (forall frames (recompute-glyph-matrices-and-then-display))
> 
> we should do
> 
>   (forall frames
>     (compute-title-and-stuff)
>     (recompute-glyph-matrices-and-then-display))

But what we do now is not exactly what's outlined above.  Instead,
it's something like

  prepare_menu_bars:
    if (windows_or_buffers_changed)
      (forall frames (compute-title-and-stuff))
  later:
    if (windows_or_buffers_changed)
      (forall frames (recompute-glyph-matrices-and-then-display))
    else
      (for selected-frame (recompute-glyph-matrices-and-then-display))

So the problematic calls to face realization are once again triggered
by the face_change flag, which in turns assigns a non-zero value to
windows_or_buffers_changed, which then causes the loop in
prepare_menu_bars.  IOW, making face_change a frame-local flag should
solve this issue as well.





^ permalink raw reply	[flat|nested] 64+ messages in thread

* bug#11822: 24.1; emacsclient terminal mode captures escape characters as text
  2015-09-15 14:29                                             ` Eli Zaretskii
@ 2015-09-15 16:14                                               ` Stefan Monnier
  2015-09-18 14:19                                                 ` Eli Zaretskii
  0 siblings, 1 reply; 64+ messages in thread
From: Stefan Monnier @ 2015-09-15 16:14 UTC (permalink / raw)
  To: Eli Zaretskii; +Cc: raeburn, 11822

> But what we do now is not exactly what's outlined above.

Indeed.

> IOW, making face_change a frame-local flag should solve this issue
> as well.

Yes, that's the most important step to take right now, I think.


        Stefan





^ permalink raw reply	[flat|nested] 64+ messages in thread

* bug#11822: 24.1; emacsclient terminal mode captures escape characters as text
  2015-09-15 16:14                                               ` Stefan Monnier
@ 2015-09-18 14:19                                                 ` Eli Zaretskii
  2015-09-21  9:23                                                   ` Ken Raeburn
  0 siblings, 1 reply; 64+ messages in thread
From: Eli Zaretskii @ 2015-09-18 14:19 UTC (permalink / raw)
  To: Stefan Monnier; +Cc: raeburn, 11822

> From: Stefan Monnier <monnier@IRO.UMontreal.CA>
> Cc: raeburn@permabit.com, 11822@debbugs.gnu.org
> Date: Tue, 15 Sep 2015 12:14:53 -0400
> 
> > But what we do now is not exactly what's outlined above.
> 
> Indeed.
> 
> > IOW, making face_change a frame-local flag should solve this issue
> > as well.
> 
> Yes, that's the most important step to take right now, I think.

I've pushed a scratch/face-realization branch to Savannah.  Ken, can
you try that and see if there are any tangible gains (or bugs) in your
configuration?  I'm particularly interested to know whether this
eliminates unnecessary calls to realize faces on frames that are on
another display.  If you see such calls, please show backtraces.

Thanks.





^ permalink raw reply	[flat|nested] 64+ messages in thread

* bug#11822: 24.1; emacsclient terminal mode captures escape characters as text
  2015-09-18 14:19                                                 ` Eli Zaretskii
@ 2015-09-21  9:23                                                   ` Ken Raeburn
  2015-09-21  9:44                                                     ` Eli Zaretskii
  0 siblings, 1 reply; 64+ messages in thread
From: Ken Raeburn @ 2015-09-21  9:23 UTC (permalink / raw)
  To: Eli Zaretskii; +Cc: 11822


> On Sep 18, 2015, at 10:19, Eli Zaretskii <eliz@gnu.org> wrote:
> 
> 
> I've pushed a scratch/face-realization branch to Savannah.  Ken, can
> you try that and see if there are any tangible gains (or bugs) in your
> configuration?  I'm particularly interested to know whether this
> eliminates unnecessary calls to realize faces on frames that are on
> another display.  If you see such calls, please show backtraces.
> 
> Thanks.

Sorry it took a little while, but I got a chance this weekend to try it out.

It worked great! According to my _XReply breakpoint, there were only four times it stopped to wait for data from the first X server (2x XGetSelectionOwner, 2x XQueryColors), and no hits on face realization breakpoints for the first display. No obvious bugs with it, but I’ll try to test it out a bit more at work this week.

Ken




^ permalink raw reply	[flat|nested] 64+ messages in thread

* bug#11822: 24.1; emacsclient terminal mode captures escape characters as text
  2015-09-21  9:23                                                   ` Ken Raeburn
@ 2015-09-21  9:44                                                     ` Eli Zaretskii
  2015-09-23 17:27                                                       ` Ken Raeburn
  0 siblings, 1 reply; 64+ messages in thread
From: Eli Zaretskii @ 2015-09-21  9:44 UTC (permalink / raw)
  To: Ken Raeburn; +Cc: 11822

> From: Ken Raeburn <raeburn@permabit.com>
> Date: Mon, 21 Sep 2015 05:23:20 -0400
> Cc: Stefan Monnier <monnier@IRO.UMontreal.CA>,
>  11822@debbugs.gnu.org
> 
> > I've pushed a scratch/face-realization branch to Savannah.  Ken, can
> > you try that and see if there are any tangible gains (or bugs) in your
> > configuration?  I'm particularly interested to know whether this
> > eliminates unnecessary calls to realize faces on frames that are on
> > another display.  If you see such calls, please show backtraces.
> > 
> > Thanks.
> 
> Sorry it took a little while, but I got a chance this weekend to try it out.
> 
> It worked great! According to my _XReply breakpoint, there were only four times it stopped to wait for data from the first X server (2x XGetSelectionOwner, 2x XQueryColors), and no hits on face realization breakpoints for the first display. No obvious bugs with it, but I’ll try to test it out a bit more at work this week.

Thanks for testing.  Barring any bugs in your additional testing, I
will merge this branch to master, when you report back.





^ permalink raw reply	[flat|nested] 64+ messages in thread

* bug#11822: 24.1; emacsclient terminal mode captures escape characters as text
  2015-09-21  9:44                                                     ` Eli Zaretskii
@ 2015-09-23 17:27                                                       ` Ken Raeburn
  2015-09-23 18:04                                                         ` martin rudalics
  2015-09-23 19:17                                                         ` Eli Zaretskii
  0 siblings, 2 replies; 64+ messages in thread
From: Ken Raeburn @ 2015-09-23 17:27 UTC (permalink / raw)
  To: Eli Zaretskii; +Cc: Stefan Monnier, 11822

[-- Attachment #1: Type: text/plain, Size: 3624 bytes --]

So far my testing is going smoothly. (Well, except for some unrelated
issues like the desktop save file format changing and making it hard to go
back to the older version.) And as far as I can tell, creating a new frame
on the local display at work is not doing anything that stops to wait for
communication with the remote display. It's much faster now.

It's still not what I would call "fast", though, usually taking a couple of
seconds... but a cursory investigation is so far pointing the finger at
garbage collection being triggered during frame creation, more often than
not. If I raise gc-cons-threshold by a factor of 10, frame creation and
display is fairly quick (presumably only 90-95% of the time). The C stack
traces from the garbage collection calls are pretty boring (maybe_gc gets
called from Ffuncall which gets called from exec_byte_code etc); the Lisp
backtraces point the finger mostly at internal-face-x-get-resource as the
function being entered when GC gets invoked.

Lisp Backtrace:
"internal-face-x-get-resource" (0x1910fb80)
"set-face-attribute-from-resource" (0x1910fd80)
"set-face-attributes-from-resources" (0x1910ff80)
"make-face-x-resource-internal" (0x19110170)
"face-spec-recalc" (0x19110360)
"face-set-after-frame-default" (0x19110560)
"x-create-frame-with-faces" (0x19110758)
0x121eac8 PVEC_COMPILED
"apply" (0x19110a10)
"frame-creation-function" (0x19110c10)
"make-frame" (0x19110dc0)
"make-frame-on-display" (0x19110f88)
"server-create-window-system-frame" (0x191111b8)
"server-process-filter" (0x19111398)

A memory profile report of frame creation via emacsclient includes this
breakdown:

- server-process-filter                                     2,898,676   2%
 - server-create-window-system-frame                        1,526,354   1%
  - make-frame-on-display                                   1,522,279   1%
   - make-frame                                             1,522,279   1%
    - frame-creation-function                               1,509,219   1%
     - apply                                                1,509,219   1%
      - #<compiled 0x487ab3>                                1,509,219   1%
       - x-create-frame-with-faces                          1,509,219   1%
        - face-set-after-frame-default                        372,148   0%
         - face-spec-recalc                                   371,868   0%
          - make-face-x-resource-internal                     368,460   0%
             set-face-attributes-from-resources               368,460   0%
          + face-spec-choose                                    2,384   0%
          + face-spec-set-2                                     1,024   0%
      normal-erase-is-backspace-setup-frame                    13,036   0%
    + run-hook-with-args                                           24   0%
    window-system-for-display                                   1,024   0%
 - server-execute-continuation                              1,355,452   1%
  - #<compiled 0x175dd37>                                   1,355,452   1%
   - server-execute                                         1,349,604   1%
      switch-to-buffer                                      1,269,569   1%
    + server-delete-client                                     36,910   0%

However, I'm skeptical of the numbers since the report also indicated that
read-from-minibuffer (but not things it called) used 100M (bytes? cells?)
in those few seconds. (Hence the >2MB shown here being such a tiny
percentage.) And the numbers vary a lot from one attempt to another, though
the proportions seem to be fairly consistent.

Ken

[-- Attachment #2: Type: text/html, Size: 4770 bytes --]

^ permalink raw reply	[flat|nested] 64+ messages in thread

* bug#11822: 24.1; emacsclient terminal mode captures escape characters as text
  2015-09-23 17:27                                                       ` Ken Raeburn
@ 2015-09-23 18:04                                                         ` martin rudalics
  2015-09-23 20:59                                                           ` Ken Raeburn
  2015-09-23 19:17                                                         ` Eli Zaretskii
  1 sibling, 1 reply; 64+ messages in thread
From: martin rudalics @ 2015-09-23 18:04 UTC (permalink / raw)
  To: Ken Raeburn, Eli Zaretskii; +Cc: Stefan Monnier, 11822

 > It's still not what I would call "fast", though, usually taking a couple of
 > seconds... but a cursory investigation is so far pointing the finger at
 > garbage collection being triggered during frame creation, more often than
 > not. If I raise gc-cons-threshold by a factor of 10, frame creation and
 > display is fairly quick (presumably only 90-95% of the time). The C stack
 > traces from the garbage collection calls are pretty boring (maybe_gc gets
 > called from Ffuncall which gets called from exec_byte_code etc); the Lisp
 > backtraces point the finger mostly at internal-face-x-get-resource as the
 > function being entered when GC gets invoked.

See also

http://lists.gnu.org/archive/html/emacs-devel/2015-07/msg00426.html

martin





^ permalink raw reply	[flat|nested] 64+ messages in thread

* bug#11822: 24.1; emacsclient terminal mode captures escape characters as text
  2015-09-23 17:27                                                       ` Ken Raeburn
  2015-09-23 18:04                                                         ` martin rudalics
@ 2015-09-23 19:17                                                         ` Eli Zaretskii
  2015-09-24  8:52                                                           ` Ken Raeburn
  1 sibling, 1 reply; 64+ messages in thread
From: Eli Zaretskii @ 2015-09-23 19:17 UTC (permalink / raw)
  To: Ken Raeburn; +Cc: monnier, 11822

> Date: Wed, 23 Sep 2015 13:27:26 -0400
> From: Ken Raeburn <raeburn@permabit.com>
> Cc: Stefan Monnier <monnier@iro.umontreal.ca>, 11822@debbugs.gnu.org
> 
> So far my testing is going smoothly. (Well, except for some unrelated issues
> like the desktop save file format changing and making it hard to go back to the
> older version.) And as far as I can tell, creating a new frame on the local
> display at work is not doing anything that stops to wait for communication with
> the remote display. It's much faster now.
> 
> It's still not what I would call "fast", though, usually taking a couple of
> seconds... but a cursory investigation is so far pointing the finger at garbage
> collection being triggered during frame creation, more often than not. If I
> raise gc-cons-threshold by a factor of 10, frame creation and display is fairly
> quick (presumably only 90-95% of the time).

Let me know when you are satisfied with your testing, so I could merge
the branch onto master.

> The C stack traces from the garbage collection calls are pretty
> boring (maybe_gc gets called from Ffuncall which gets called from
> exec_byte_code etc); the Lisp backtraces point the finger mostly at
> internal-face-x-get-resource as the function being entered when GC
> gets invoked.

The function that triggers GC is not necessarily the main culprit for
GC.  In http://lists.gnu.org/archive/html/emacs-devel/2015-08/msg00081.html
I described how I went about tracking the worst offenders, so I suggest
you do something similar.  Once you have the data based on a watchpoint
put on consing_since_gc, you can analyze it to see which code is
responsible for most of the consing.  With that data in hand, we could
see if there's something we can do about that.

> A memory profile report of frame creation via emacsclient includes this
> breakdown:

The so-called "memory profile" is not profiling memory, at least not
in the useful sense applicable to the issue at hand.  In its current
implementation, it doesn't present useful data for debugging
Lisp-level data memory allocations.





^ permalink raw reply	[flat|nested] 64+ messages in thread

* bug#11822: 24.1; emacsclient terminal mode captures escape characters as text
  2015-09-23 18:04                                                         ` martin rudalics
@ 2015-09-23 20:59                                                           ` Ken Raeburn
  0 siblings, 0 replies; 64+ messages in thread
From: Ken Raeburn @ 2015-09-23 20:59 UTC (permalink / raw)
  To: martin rudalics; +Cc: Stefan Monnier, 11822

martin rudalics <rudalics@gmx.at> writes:

>> It's still not what I would call "fast", though, usually taking a couple of
>> seconds... but a cursory investigation is so far pointing the finger at
>> garbage collection being triggered during frame creation, more often than
>> not. If I raise gc-cons-threshold by a factor of 10, frame creation and
>> display is fairly quick (presumably only 90-95% of the time). The C stack
>> traces from the garbage collection calls are pretty boring (maybe_gc gets
>> called from Ffuncall which gets called from exec_byte_code etc); the Lisp
>> backtraces point the finger mostly at internal-face-x-get-resource as the
>> function being entered when GC gets invoked.
>
> See also
>
> http://lists.gnu.org/archive/html/emacs-devel/2015-07/msg00426.html

Ah, useful info on the profiler, thanks! I'm working on a 64-bit system,
so the WIDE_INT issues shouldn't be a factor, but if it's counting the
non-GC-able memory we're allocating, it's less useful than I was hoping.
Eli's suggestion of a watchpoint on consing_since_gc looks more useful.
I'll give that a try and see what comes up.

It sounds like your tooltip GC issue and my regular-frame GC issue are
probably the same or very nearly....

Ken





^ permalink raw reply	[flat|nested] 64+ messages in thread

* bug#11822: 24.1; emacsclient terminal mode captures escape characters as text
  2015-09-23 19:17                                                         ` Eli Zaretskii
@ 2015-09-24  8:52                                                           ` Ken Raeburn
  2015-09-24 18:46                                                             ` Eli Zaretskii
  2015-09-25  6:50                                                             ` Eli Zaretskii
  0 siblings, 2 replies; 64+ messages in thread
From: Ken Raeburn @ 2015-09-24  8:52 UTC (permalink / raw)
  To: Eli Zaretskii; +Cc: monnier, 11822

> The function that triggers GC is not necessarily the main culprit for
> GC.  In http://lists.gnu.org/archive/html/emacs-devel/2015-08/msg00081.html
> I described how I went about tracking the worst offenders, so I suggest
> you do something similar.  Once you have the data based on a watchpoint
> put on consing_since_gc, you can analyze it to see which code is
> responsible for most of the consing.  With that data in hand, we could
> see if there's something we can do about that.

I printed out stack traces when consing_since_gc changed. That turns out to be a lot of raw data :-) … it took 5.5 CPU hours under gdb to get the frame created and the data recorded. It’s over 120MB of text, so I’m working on distilling it down to something that might be useful. Some highlights so far:

In this run, I recorded over 601000 bytes being allocated; about 60% of that (~364000) was done from things called by parse_single_submenu; about half of that (~185000), in turn, was via larger_vector called from ensure_menu_items. The largest of those was a single allocation of 62000 bytes. There were several more of these calls, with smaller sizes, and varying in the nesting depth of single_menu_item and friends.

The next couple paths resulting in the most bytes allocated were list creations from Lisp code:

39104 bytes across 2444 allocations with the Lisp backtrace: set-face-attribute apply face-spec-reset-face face-spec-recalc face-set-after-frame-default x-create-frame-with-faces PVEC_COMPILED@0x121eac8 apply frame-creation-function make-frame make-frame-command funcall-interactively call-interactively command-execute

36288 bytes across 2268 allocations with the Lisp backtrace: append apply face-spec-reset-face [… as above]

58320 bytes across 3645 allocations via mapcar or the function mapcar applies, called from face-spec-reset-face

There were also 54360 bytes allocated along various paths from directory-files, which as far as I can tell is only used to test for the existence of any file in ~/.emacs.d/auto-save-list with a name starting with “.saves-”. If any exist, the “Recover Crashed Session” menu item is enabled. But I know of no way to do just the pattern matching and existence test without fetching all the other data. The amount of wasted allocations are dependent on the content of my directory, of course.

This stuff described above is all during the execution of “make-frame-command” invoked via C-x 5 2. After that command completes, there are more allocations driven out of redisplay_internal or timers — enough that garbage collection ran a second time — but I’m not sure which are normal parts of the create-and-display-frame sequence (loading image files) and which may be artifacts of how I did the test or how I was using the machine (e.g., random X events caused by my moving other windows around to get real work done over the span of a few hours).

Ken

^ permalink raw reply	[flat|nested] 64+ messages in thread

* bug#11822: 24.1; emacsclient terminal mode captures escape characters as text
  2015-09-24  8:52                                                           ` Ken Raeburn
@ 2015-09-24 18:46                                                             ` Eli Zaretskii
  2015-09-24 20:08                                                               ` Ken Raeburn
  2015-09-25  6:50                                                             ` Eli Zaretskii
  1 sibling, 1 reply; 64+ messages in thread
From: Eli Zaretskii @ 2015-09-24 18:46 UTC (permalink / raw)
  To: Ken Raeburn; +Cc: monnier, 11822

> In this run, I recorded over 601000 bytes being allocated; about 60% of that (~364000) was done from things called by parse_single_submenu; about half of that (~185000), in turn, was via larger_vector called from ensure_menu_items. The largest of those was a single allocation of 62000 bytes. There were several more of these calls, with smaller sizes, and varying in the nesting depth of single_menu_item and friends.

Can you show the backtrace from the 62000-byte allocation?

> 39104 bytes across 2444 allocations with the Lisp backtrace: set-face-attribute apply face-spec-reset-face face-spec-recalc face-set-after-frame-default x-create-frame-with-faces PVEC_COMPILED@0x121eac8 apply frame-creation-function make-frame make-frame-command funcall-interactively call-interactively command-execute
> 
> 36288 bytes across 2268 allocations with the Lisp backtrace: append apply face-spec-reset-face [… as above]
> 
> 58320 bytes across 3645 allocations via mapcar or the function mapcar applies, called from face-spec-reset-face

This face recalculation dance indeed conses a lot.  It was the worst
offender in my testing.

Anyway, I think this is a separate issue, unrelated to the one that is
the subject of this bug report.





^ permalink raw reply	[flat|nested] 64+ messages in thread

* bug#11822: 24.1; emacsclient terminal mode captures escape characters as text
  2015-09-24 18:46                                                             ` Eli Zaretskii
@ 2015-09-24 20:08                                                               ` Ken Raeburn
  2015-09-25  6:49                                                                 ` Eli Zaretskii
  0 siblings, 1 reply; 64+ messages in thread
From: Ken Raeburn @ 2015-09-24 20:08 UTC (permalink / raw)
  To: Eli Zaretskii; +Cc: Stefan Monnier, 11822

[-- Attachment #1: Type: text/plain, Size: 8045 bytes --]

On Thu, Sep 24, 2015 at 2:46 PM, Eli Zaretskii <eliz@gnu.org> wrote:

> > In this run, I recorded over 601000 bytes being allocated; about 60% of
> that (~364000) was done from things called by parse_single_submenu; about
> half of that (~185000), in turn, was via larger_vector called from
> ensure_menu_items. The largest of those was a single allocation of 62000
> bytes. There were several more of these calls, with smaller sizes, and
> varying in the nesting depth of single_menu_item and friends.
>
> Can you show the backtrace from the 62000-byte allocation?
>


Hardware watchpoint 3: consing_since_gc

Old value = 236408
New value = 298408
allocate_vectorlike (len=7749) at ../../src/alloc.c:3129
3129      vector_cells_consed += len;
#0  allocate_vectorlike (len=7749) at ../../src/alloc.c:3129
#1  0x000000000053c358 in XUNTAG (type=<optimized out>, a=<optimized out>)
at ../../src/lisp.h:839
#2  XVECTOR (a=<optimized out>) at ../../src/lisp.h:969
#3  allocate_vectorlike (len=7749) at ../../src/alloc.c:3097
#4  allocate_vector (len=7749) at ../../src/alloc.c:3148
#5  0x000000000055febd in larger_vector (vec=20730845, incr_min=<optimized
out>, nitems_max=<optimized out>) at ../../src/fns.c:3619
#6  0x0000000000463c18 in ensure_menu_items (items=<optimized out>) at
../../src/menu.c:172
#7  0x0000000000463dbe in push_menu_item (name=8891140, enable=44016,
key=7152208, def=4131552, equiv=0, type=0, selected=0, help=0) at
../../src/menu.c:242
#8  0x00000000004640ae in single_menu_item (skp_v=0x7fffffffcbf0,
key=7152208, item=<optimized out>, dummy=<optimized out>) at
../../src/menu.c:424
#9  single_menu_item (key=7152208, item=<optimized out>, dummy=<optimized
out>, skp_v=0x7fffffffcbf0) at ../../src/menu.c:322
#10 0x00000000004f468a in map_keymap_item (data=0x7fffffffcbf0,
val=<optimized out>, key=<optimized out>, args=0, fun=0x463ea0
<single_menu_item>) at ../../src/keymap.c:547
#11 map_keymap_internal (map=19459395, fun=0x463ea0 <single_menu_item>,
args=0, data=0x7fffffffcbf0) at ../../src/keymap.c:584
#12 0x0000000000463d18 in single_keymap_panes (keymap=16111731,
pane_name=<optimized out>, prefix=<optimized out>, maxdepth=8) at
../../src/menu.c:298
#13 0x0000000000464124 in single_menu_item (skp_v=0x7fffffffcd50,
key=5159696, item=<optimized out>, dummy=<optimized out>) at
../../src/menu.c:437
#14 single_menu_item (key=5159696, item=<optimized out>, dummy=<optimized
out>, skp_v=0x7fffffffcd50) at ../../src/menu.c:322
#15 0x00000000004f468a in map_keymap_item (data=0x7fffffffcd50,
val=<optimized out>, key=<optimized out>, args=0, fun=0x463ea0
<single_menu_item>) at ../../src/keymap.c:547
#16 map_keymap_internal (map=19467347, fun=0x463ea0 <single_menu_item>,
args=0, data=0x7fffffffcd50) at ../../src/keymap.c:584
#17 0x0000000000463d18 in single_keymap_panes (keymap=19716755,
pane_name=<optimized out>, prefix=<optimized out>, maxdepth=9) at
../../src/menu.c:298
#18 0x0000000000464124 in single_menu_item (skp_v=0x7fffffffceb0,
key=8138816, item=<optimized out>, dummy=<optimized out>) at
../../src/menu.c:437
#19 single_menu_item (key=8138816, item=<optimized out>, dummy=<optimized
out>, skp_v=0x7fffffffceb0) at ../../src/menu.c:322
#20 0x00000000004f468a in map_keymap_item (data=0x7fffffffceb0,
val=<optimized out>, key=<optimized out>, args=0, fun=0x463ea0
<single_menu_item>) at ../../src/keymap.c:547
#21 map_keymap_internal (map=19488483, fun=0x463ea0 <single_menu_item>,
args=0, data=0x7fffffffceb0) at ../../src/keymap.c:584
#22 0x0000000000463d18 in single_keymap_panes (keymap=19750115,
pane_name=<optimized out>, prefix=<optimized out>, maxdepth=10) at
../../src/menu.c:298
#23 0x00000000004652c8 in parse_single_submenu (item_key=8191056,
item_name=9330724, maps=<optimized out>) at ../../src/menu.c:566
#24 0x0000000000466a9f in set_frame_menubar (f=0x122a940,
first_time=<optimized out>, deep_p=<optimized out>) at ../../src/xmenu.c:797
#25 0x00000000004d0038 in Fx_create_frame (parms=13618675) at
../../src/xfns.c:3307
#26 0x0000000000555600 in Ffuncall (nargs=<optimized out>,
args=0x7fffffffd2e8) at ../../src/eval.c:2650
#27 0x0000000000589d4d in exec_byte_code (bytestr=13263568, vector=48,
maxdepth=0, args_template=140737488343792, nargs=2, args=0x2000000) at
../../src/bytecode.c:880
#28 0x000000000055501a in funcall_lambda (fun=9182501, nargs=<optimized
out>, arg_vector=0x7fffffffd4e8) at ../../src/eval.c:2876
#29 0x0000000000555364 in Ffuncall (nargs=<optimized out>,
args=0x7fffffffd4e0) at ../../src/eval.c:2711
#30 0x0000000000589d4d in exec_byte_code (bytestr=13263568, vector=48,
maxdepth=0, args_template=1030, nargs=2, args=0x2000000) at
../../src/bytecode.c:880
#31 0x0000000000555364 in Ffuncall (nargs=<optimized out>,
args=0x7fffffffd7a0) at ../../src/eval.c:2711
#32 0x0000000000556527 in Fapply (nargs=2, args=0x7fffffffd7a0) at
../../src/eval.c:2235
#33 0x0000000000555462 in Ffuncall (nargs=<optimized out>,
args=0x7fffffffd798) at ../../src/eval.c:2630
#34 0x0000000000589d4d in exec_byte_code (bytestr=13263568, vector=48,
maxdepth=0, args_template=41, nargs=3, args=0x2000000) at
../../src/bytecode.c:880
#35 0x0000000000555364 in Ffuncall (nargs=<optimized out>,
args=0x7fffffffd998) at ../../src/eval.c:2711
#36 0x0000000000589d4d in exec_byte_code (bytestr=13263568, vector=48,
maxdepth=0, args_template=158, nargs=2, args=0x2000000) at
../../src/bytecode.c:880
#37 0x0000000000555364 in Ffuncall (nargs=<optimized out>,
args=0x7fffffffdb38) at ../../src/eval.c:2711
#38 0x0000000000589d4d in exec_byte_code (bytestr=13263568, vector=48,
maxdepth=0, args_template=8, nargs=1, args=0x2000000) at
../../src/bytecode.c:880
#39 0x0000000000555364 in Ffuncall (nargs=<optimized out>,
args=0x7fffffffdea8) at ../../src/eval.c:2711
#40 0x0000000000551229 in Ffuncall_interactively (nargs=1,
args=0x7fffffffdea8) at ../../src/callint.c:250
#41 0x0000000000555462 in Ffuncall (nargs=<optimized out>,
args=0x7fffffffdea0) at ../../src/eval.c:2630
#42 0x00000000005563fd in Fapply (nargs=3, args=0x7fffffffdea0) at
../../src/eval.c:2231
#43 0x00000000005515c7 in Fcall_interactively (function=7970864,
record_flag=0, keys=12382133) at ../../src/callint.c:387
#44 0x00000000005555dc in Ffuncall (nargs=<optimized out>,
args=0x7fffffffdfe8) at ../../src/eval.c:2657
#45 0x0000000000589d4d in exec_byte_code (bytestr=13263568, vector=48,
maxdepth=0, args_template=115, nargs=4, args=0x2000000) at
../../src/bytecode.c:880
#46 0x0000000000555364 in Ffuncall (nargs=<optimized out>,
args=0x7fffffffe180) at ../../src/eval.c:2711
#47 0x00000000005557ba in call1 (fn=<optimized out>, arg1=<optimized out>)
at ../../src/eval.c:2509
#48 0x00000000004f013b in command_loop_1 () at ../../src/keyboard.c:1460
#49 0x0000000000553a14 in internal_condition_case (bfun=0x4efda0
<command_loop_1>, handlers=<optimized out>, hfun=0x4e6030 <cmd_error>) at
../../src/eval.c:1309
#50 0x00000000004e463c in command_loop_2 (ignore=<optimized out>) at
../../src/keyboard.c:1088
#51 0x0000000000553928 in internal_catch (tag=0, func=0x4e4620
<command_loop_2>, arg=0) at ../../src/eval.c:1073
#52 0x00000000004e458c in command_loop () at ../../src/keyboard.c:1067
#53 0x00000000004e5c16 in recursive_edit_1 () at ../../src/keyboard.c:673
#54 0x00000000004e5f55 in Frecursive_edit () at ../../src/keyboard.c:744
#55 0x00000000004123a3 in main (argc=2, argv=0x7fffffffe5a8) at
../../src/emacs.c:1643

Lisp Backtrace:
"x-create-frame" (0xffffd2f0)
"x-create-frame-with-faces" (0xffffd4e8)
0x121eac8 PVEC_COMPILED
"apply" (0xffffd7a0)
"frame-creation-function" (0xffffd9a0)
"make-frame" (0xffffdb40)
"make-frame-command" (0xffffdeb0)
"funcall-interactively" (0xffffdea8)
"call-interactively" (0xffffdff0)
"command-execute" (0xffffe188)

Anyway, I think this is a separate issue, unrelated to the one that is
> the subject of this bug report.
>

Agreed. Nothing about this is specific to remote frames or slow
connections. Should I open a new ticket, or follow up on emacs-devel?

I'm still seeing no display problems with the test branch; I'm fine with
closing out this ticket now.

Ken

[-- Attachment #2: Type: text/html, Size: 10060 bytes --]

^ permalink raw reply	[flat|nested] 64+ messages in thread

* bug#11822: 24.1; emacsclient terminal mode captures escape characters as text
  2015-09-24 20:08                                                               ` Ken Raeburn
@ 2015-09-25  6:49                                                                 ` Eli Zaretskii
  2015-09-25 12:07                                                                   ` Stefan Monnier
  2015-09-26  7:01                                                                   ` Eli Zaretskii
  0 siblings, 2 replies; 64+ messages in thread
From: Eli Zaretskii @ 2015-09-25  6:49 UTC (permalink / raw)
  To: Ken Raeburn; +Cc: monnier, 11822

> Date: Thu, 24 Sep 2015 16:08:04 -0400
> From: Ken Raeburn <raeburn@permabit.com>
> Cc: Stefan Monnier <monnier@iro.umontreal.ca>, 11822@debbugs.gnu.org
> 
>     > In this run, I recorded over 601000 bytes being allocated; about 60% of
>     that (~364000) was done from things called by parse_single_submenu; about
>     half of that (~185000), in turn, was via larger_vector called from
>     ensure_menu_items. The largest of those was a single allocation of 62000
>     bytes. There were several more of these calls, with smaller sizes, and
>     varying in the nesting depth of single_menu_item and friends.
>     
>     Can you show the backtrace from the 62000-byte allocation?
>     
> 
> Hardware watchpoint 3: consing_since_gc
> 
> Old value = 236408
> New value = 298408
> allocate_vectorlike (len=7749) at ../../src/alloc.c:3129
> 3129 vector_cells_consed += len;
> #0 allocate_vectorlike (len=7749) at ../../src/alloc.c:3129
> #1 0x000000000053c358 in XUNTAG (type=<optimized out>, a=<optimized out>) at .
> ./../src/lisp.h:839
> #2 XVECTOR (a=<optimized out>) at ../../src/lisp.h:969
> #3 allocate_vectorlike (len=7749) at ../../src/alloc.c:3097
> #4 allocate_vector (len=7749) at ../../src/alloc.c:3148
> #5 0x000000000055febd in larger_vector (vec=20730845, incr_min=<optimized out>,
> nitems_max=<optimized out>) at ../../src/fns.c:3619
> #6 0x0000000000463c18 in ensure_menu_items (items=<optimized out>) at .
> ./../src/menu.c:172
> #7 0x0000000000463dbe in push_menu_item (name=8891140, enable=44016,
> key=7152208, def=4131552, equiv=0, type=0, selected=0, help=0) at .
> ./../src/menu.c:242
> #8 0x00000000004640ae in single_menu_item (skp_v=0x7fffffffcbf0, key=7152208,
> item=<optimized out>, dummy=<optimized out>) at ../../src/menu.c:424
> #9 single_menu_item (key=7152208, item=<optimized out>, dummy=<optimized out>,
> skp_v=0x7fffffffcbf0) at ../../src/menu.c:322
> #10 0x00000000004f468a in map_keymap_item (data=0x7fffffffcbf0, val=<optimized
> out>, key=<optimized out>, args=0, fun=0x463ea0 <single_menu_item>) at .
> ./../src/keymap.c:547
> #11 map_keymap_internal (map=19459395, fun=0x463ea0 <single_menu_item>, args=0,
> data=0x7fffffffcbf0) at ../../src/keymap.c:584
> #12 0x0000000000463d18 in single_keymap_panes (keymap=16111731,
> pane_name=<optimized out>, prefix=<optimized out>, maxdepth=8) at .
> ./../src/menu.c:298
> #13 0x0000000000464124 in single_menu_item (skp_v=0x7fffffffcd50, key=5159696,
> item=<optimized out>, dummy=<optimized out>) at ../../src/menu.c:437
> #14 single_menu_item (key=5159696, item=<optimized out>, dummy=<optimized out>,
> skp_v=0x7fffffffcd50) at ../../src/menu.c:322
> #15 0x00000000004f468a in map_keymap_item (data=0x7fffffffcd50, val=<optimized
> out>, key=<optimized out>, args=0, fun=0x463ea0 <single_menu_item>) at .
> ./../src/keymap.c:547
> #16 map_keymap_internal (map=19467347, fun=0x463ea0 <single_menu_item>, args=0,
> data=0x7fffffffcd50) at ../../src/keymap.c:584
> #17 0x0000000000463d18 in single_keymap_panes (keymap=19716755,
> pane_name=<optimized out>, prefix=<optimized out>, maxdepth=9) at .
> ./../src/menu.c:298
> #18 0x0000000000464124 in single_menu_item (skp_v=0x7fffffffceb0, key=8138816,
> item=<optimized out>, dummy=<optimized out>) at ../../src/menu.c:437
> #19 single_menu_item (key=8138816, item=<optimized out>, dummy=<optimized out>,
> skp_v=0x7fffffffceb0) at ../../src/menu.c:322
> #20 0x00000000004f468a in map_keymap_item (data=0x7fffffffceb0, val=<optimized
> out>, key=<optimized out>, args=0, fun=0x463ea0 <single_menu_item>) at .
> ./../src/keymap.c:547
> #21 map_keymap_internal (map=19488483, fun=0x463ea0 <single_menu_item>, args=0,
> data=0x7fffffffceb0) at ../../src/keymap.c:584
> #22 0x0000000000463d18 in single_keymap_panes (keymap=19750115,
> pane_name=<optimized out>, prefix=<optimized out>, maxdepth=10) at .
> ./../src/menu.c:298
> #23 0x00000000004652c8 in parse_single_submenu (item_key=8191056,
> item_name=9330724, maps=<optimized out>) at ../../src/menu.c:566
> #24 0x0000000000466a9f in set_frame_menubar (f=0x122a940, first_time=<optimized
> out>, deep_p=<optimized out>) at ../../src/xmenu.c:797
> #25 0x00000000004d0038 in Fx_create_frame (parms=13618675) at .
> ./../src/xfns.c:3307

Looks like some deeply recursive keymap?  Can you show the values of
relevant variables, so that we could have an idea which keymap is that?

> I'm still seeing no display problems with the test branch; I'm fine with
> closing out this ticket now.

Great, I will merge the branch soon.

Thanks.





^ permalink raw reply	[flat|nested] 64+ messages in thread

* bug#11822: 24.1; emacsclient terminal mode captures escape characters as text
  2015-09-24  8:52                                                           ` Ken Raeburn
  2015-09-24 18:46                                                             ` Eli Zaretskii
@ 2015-09-25  6:50                                                             ` Eli Zaretskii
  2015-09-25 12:09                                                               ` Stefan Monnier
  1 sibling, 1 reply; 64+ messages in thread
From: Eli Zaretskii @ 2015-09-25  6:50 UTC (permalink / raw)
  To: Ken Raeburn; +Cc: monnier, 11822

> From: Ken Raeburn <raeburn@permabit.com>
> Date: Thu, 24 Sep 2015 04:52:18 -0400
> Cc: monnier@iro.umontreal.ca,
>  11822@debbugs.gnu.org
> 
> There were also 54360 bytes allocated along various paths from directory-files, which as far as I can tell is only used to test for the existence of any file in ~/.emacs.d/auto-save-list with a name starting with “.saves-”. If any exist, the “Recover Crashed Session” menu item is enabled. But I know of no way to do just the pattern matching and existence test without fetching all the other data. The amount of wasted allocations are dependent on the content of my directory, of course.

Did you look at that directory lately?  It should be cleaned from time
to time, to avoid having there auto-save files from years ago.





^ permalink raw reply	[flat|nested] 64+ messages in thread

* bug#11822: 24.1; emacsclient terminal mode captures escape characters as text
  2015-09-25  6:49                                                                 ` Eli Zaretskii
@ 2015-09-25 12:07                                                                   ` Stefan Monnier
  2015-09-26  7:01                                                                   ` Eli Zaretskii
  1 sibling, 0 replies; 64+ messages in thread
From: Stefan Monnier @ 2015-09-25 12:07 UTC (permalink / raw)
  To: Eli Zaretskii; +Cc: Ken Raeburn, 11822

>> #24 0x0000000000466a9f in set_frame_menubar (f=0x122a940, first_time=<optimized
out> , deep_p=<optimized out>) at ../../src/xmenu.c:797
>> #25 0x00000000004d0038 in Fx_create_frame (parms=13618675) at .
>> ./../src/xfns.c:3307
> Looks like some deeply recursive keymap?  Can you show the values of
> relevant variables, so that we could have an idea which keymap is that?

BTW, for x_create_frame, we ideally shouldn't need to create/traverse
the whole menu bar in depth.  IIRC there's some code to limit the
traversal to the "top-level" needed to find the set of menus we need to
display, but it's not always used.


        Stefan





^ permalink raw reply	[flat|nested] 64+ messages in thread

* bug#11822: 24.1; emacsclient terminal mode captures escape characters as text
  2015-09-25  6:50                                                             ` Eli Zaretskii
@ 2015-09-25 12:09                                                               ` Stefan Monnier
  2015-09-25 13:29                                                                 ` Eli Zaretskii
  0 siblings, 1 reply; 64+ messages in thread
From: Stefan Monnier @ 2015-09-25 12:09 UTC (permalink / raw)
  To: Eli Zaretskii; +Cc: Ken Raeburn, 11822

>> But I know of no way to do just the pattern matching and
>> existence test without fetching all the other data. The amount of wasted
>> allocations are dependent on the content of my directory, of course.

> Did you look at that directory lately?  It should be cleaned from time
> to time, to avoid having there auto-save files from years ago.

Arguable, Emacs should fins a way to do it automatically for you.


        Stefan





^ permalink raw reply	[flat|nested] 64+ messages in thread

* bug#11822: 24.1; emacsclient terminal mode captures escape characters as text
  2015-09-25 12:09                                                               ` Stefan Monnier
@ 2015-09-25 13:29                                                                 ` Eli Zaretskii
  2015-09-25 15:18                                                                   ` Stefan Monnier
  0 siblings, 1 reply; 64+ messages in thread
From: Eli Zaretskii @ 2015-09-25 13:29 UTC (permalink / raw)
  To: Stefan Monnier; +Cc: raeburn, 11822

> From: Stefan Monnier <monnier@iro.umontreal.ca>
> Cc: Ken Raeburn <raeburn@permabit.com>,  11822@debbugs.gnu.org
> Date: Fri, 25 Sep 2015 08:09:55 -0400
> 
> >> But I know of no way to do just the pattern matching and
> >> existence test without fetching all the other data. The amount of wasted
> >> allocations are dependent on the content of my directory, of course.
> 
> > Did you look at that directory lately?  It should be cleaned from time
> > to time, to avoid having there auto-save files from years ago.
> 
> Arguable, Emacs should fins a way to do it automatically for you.

Do what? clean up that directory?  That's not the issue here.

The issue is that startup.el wants to know whether there are _any_
auto-save files, so that it could suggest recover-session.  But the
only way of doing that is call directory-files and look at the length
of the list it returns, which ends up consing a long list that's
thrown away.  I thought of proposing to expose to Lisp an fnmatch-like
function for this purpose, but it sounds like manually cleaning up
that directory is a much easier solution.

^ permalink raw reply	[flat|nested] 64+ messages in thread

* bug#11822: 24.1; emacsclient terminal mode captures escape characters as text
  2015-09-25 13:29                                                                 ` Eli Zaretskii
@ 2015-09-25 15:18                                                                   ` Stefan Monnier
  0 siblings, 0 replies; 64+ messages in thread
From: Stefan Monnier @ 2015-09-25 15:18 UTC (permalink / raw)
  To: Eli Zaretskii; +Cc: raeburn, 11822

>> >> But I know of no way to do just the pattern matching and
>> >> existence test without fetching all the other data. The amount of wasted
>> >> allocations are dependent on the content of my directory, of course.
>> > Did you look at that directory lately?  It should be cleaned from time
>> > to time, to avoid having there auto-save files from years ago.
>> Arguable, Emacs should fins a way to do it automatically for you.
> Do what? clean up that directory?  That's not the issue here.

Indirectly it is one of the issues.  Regardless of this consing problem,
having too many of those files accumulate is just not a good idea, and
asking the user to do it manually is OK but not ideal.

We can solve the consing problem some other way, but solving this
problem would also help solve the consing problem.

> The issue is that startup.el wants to know whether there are _any_
> auto-save files, so that it could suggest recover-session.

Yet we don't do this computation merely at startup, but every time we
refresh the menu (i.e. very often).
So another way to attack the problem is to avoid recomputing it all
the time.

        Stefan

^ permalink raw reply	[flat|nested] 64+ messages in thread

* bug#11822: 24.1; emacsclient terminal mode captures escape characters as text
  2015-09-25  6:49                                                                 ` Eli Zaretskii
  2015-09-25 12:07                                                                   ` Stefan Monnier
@ 2015-09-26  7:01                                                                   ` Eli Zaretskii
  1 sibling, 0 replies; 64+ messages in thread
From: Eli Zaretskii @ 2015-09-26  7:01 UTC (permalink / raw)
  To: raeburn; +Cc: monnier, 11822-done

> Date: Fri, 25 Sep 2015 09:49:04 +0300
> From: Eli Zaretskii <eliz@gnu.org>
> Cc: monnier@iro.umontreal.ca, 11822@debbugs.gnu.org
> 
> > I'm still seeing no display problems with the test branch; I'm fine with
> > closing out this ticket now.
> 
> Great, I will merge the branch soon.

Done.





^ permalink raw reply	[flat|nested] 64+ messages in thread

end of thread, other threads:[~2015-09-26  7:01 UTC | newest]

Thread overview: 64+ messages (download: mbox.gz follow: Atom feed
-- links below jump to the message on this page --
2012-06-30  0:08 bug#11822: 24.1; emacsclient terminal mode captures escape characters as text Ken Raeburn
2012-06-30  5:55 ` Eli Zaretskii
2012-07-31 21:06   ` Ken Raeburn
2012-08-08  3:13     ` Ken Raeburn
2012-08-08  4:52       ` Dan Nicolaescu
2012-08-08  9:26         ` Ken Raeburn
2012-08-09 21:12           ` Ken Raeburn
2012-08-10  6:16             ` Eli Zaretskii
2012-08-10  7:27               ` Ken Raeburn
2012-08-10  7:46                 ` Eli Zaretskii
2012-08-10  8:08                   ` Eli Zaretskii
2015-09-07 21:09                     ` Ken Raeburn
2015-09-08  1:29                       ` Stefan Monnier
2015-09-08  4:29                         ` Eli Zaretskii
2015-09-08  6:53                         ` Ken Raeburn
2015-09-08 13:03                           ` Stefan Monnier
2015-09-08 13:11                           ` Stefan Monnier
2015-09-08 17:21                             ` Eli Zaretskii
2015-09-08  4:48                       ` Eli Zaretskii
2015-09-08 10:15                         ` Ken Raeburn
2015-09-08 13:35                           ` Stefan Monnier
2015-09-08 17:33                           ` Eli Zaretskii
2015-09-08 19:54                             ` Ken Raeburn
2015-09-09 14:16                               ` Eli Zaretskii
2015-09-10  6:59                                 ` Ken Raeburn
2015-09-10 15:36                                   ` Eli Zaretskii
2015-09-10 17:56                                     ` Stefan Monnier
2015-09-10 18:06                                       ` Eli Zaretskii
2015-09-11 12:56                                         ` Stefan Monnier
2015-09-11 13:53                                           ` Eli Zaretskii
2015-09-11 16:53                                             ` Stefan Monnier
2015-09-11  6:54                                     ` Ken Raeburn
2015-09-11  7:22                                       ` Eli Zaretskii
2015-09-11 23:11                                         ` Ken Raeburn
2015-09-12  0:51                                           ` Stefan Monnier
2015-09-12  1:34                                             ` Ken Raeburn
2015-09-15 14:29                                             ` Eli Zaretskii
2015-09-15 16:14                                               ` Stefan Monnier
2015-09-18 14:19                                                 ` Eli Zaretskii
2015-09-21  9:23                                                   ` Ken Raeburn
2015-09-21  9:44                                                     ` Eli Zaretskii
2015-09-23 17:27                                                       ` Ken Raeburn
2015-09-23 18:04                                                         ` martin rudalics
2015-09-23 20:59                                                           ` Ken Raeburn
2015-09-23 19:17                                                         ` Eli Zaretskii
2015-09-24  8:52                                                           ` Ken Raeburn
2015-09-24 18:46                                                             ` Eli Zaretskii
2015-09-24 20:08                                                               ` Ken Raeburn
2015-09-25  6:49                                                                 ` Eli Zaretskii
2015-09-25 12:07                                                                   ` Stefan Monnier
2015-09-26  7:01                                                                   ` Eli Zaretskii
2015-09-25  6:50                                                             ` Eli Zaretskii
2015-09-25 12:09                                                               ` Stefan Monnier
2015-09-25 13:29                                                                 ` Eli Zaretskii
2015-09-25 15:18                                                                   ` Stefan Monnier
2015-09-12  7:30                                           ` Eli Zaretskii
2015-09-11 13:39                                       ` Stefan Monnier
2015-09-11 14:01                                         ` Eli Zaretskii
2015-09-08 13:22                         ` Stefan Monnier
2015-09-08 17:25                           ` Eli Zaretskii
2015-09-08 18:52                             ` Stefan Monnier
2015-09-08 19:08                               ` Eli Zaretskii
2015-09-08 20:37                                 ` Stefan Monnier
2015-09-08 17:36                         ` Eli Zaretskii

Code repositories for project(s) associated with this public inbox

	https://git.savannah.gnu.org/cgit/emacs.git

This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for read-only IMAP folder(s) and NNTP newsgroup(s).