bug#34821: discard_input_tty does not discard pending input, resulting in garbage inserted into the buffer

bug#34821: discard_input_tty does not discard pending input, resulting in garbage inserted into the buffer

[Platon Pronko]

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

Hi!

Steps to reproduce:

1. Add dummy autosave file (needed for additional delay when starting and reliable bug reproduction):
$ touch /tmp/#test.txt#

2. Launch daemon:
./src/emacs -Q --fg-daemon

3. Start the client:
./lib-src/emacsclient -t /tmp/test.txt

4. type 'a' while emacsclient is starting

5. observe "65;5403;1c" inserted at the start of the new file.

I hunted for the bug and traced it down to terminal-init-xterm and xterm--query. It makes a "Secondary Device Attributes" query, and expects a response with a specific prefix - but if there were characters waiting in input buffer the handler will never see that prefix, and all the bytes will be sent directly to default keyboard handler and inserted into the buffer.

To mitigate the problem xterm--query calls discard-input before sending the query, however for some reason the bytes are still there when read_char is called.

I added a workaround in xterm--query, simple `(while (read-event nil nil 0.01))` (see patch attached). Setting `(setq xterm-query-timeout nil)` switches querying to async mode and also helps (the typed character is not discarded that way, which is even better).

However, I suspect that the real problem lurks in the discard_tty_input, that for some reason does not actually discard the input - but I'm not sure how to debug it.

System details below:

In GNU Emacs 27.0.50 (build 27, x86_64-pc-linux-gnu, GTK+ Version 3.24.5)
  of 2019-03-12 built on the-big-maker
Repository revision: d2270d8fc93b5fb0b82fec4d85d122ea4e38dff3
Repository branch: master
System Description: Arch Linux

Recent messages:
Starting Emacs daemon.
test.txt has auto save data; consider M-x recover-this-file
When done with a buffer, type C-x #
Quit
completing-read-default: Command attempted to use minibuffer while in minibuffer

Configured features:
XPM JPEG TIFF GIF PNG RSVG IMAGEMAGICK SOUND GPM DBUS GSETTINGS GLIB
NOTIFY INOTIFY ACL GNUTLS LIBXML2 FREETYPE M17N_FLT LIBOTF XFT ZLIB
TOOLKIT_SCROLL_BARS GTK3 X11 XDBE XIM THREADS LIBSYSTEMD JSON PDUMPER
LCMS2 GMP

Important settings:
   value of $LC_TIME: en_SE.UTF-8
   value of $LANG: en_US.UTF-8
   locale-coding-system: utf-8-unix

Major mode: Text

Minor modes in effect:
   tooltip-mode: t
   global-eldoc-mode: t
   electric-indent-mode: t
   mouse-wheel-mode: t
   tool-bar-mode: t
   menu-bar-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

Load-path shadows:
None found.

Features:
(shadow sort mail-extr emacsbug message rmc puny seq byte-opt gv
bytecomp byte-compile cconv dired dired-loaddefs format-spec rfc822 mml
easymenu mml-sec password-cache epa derived epg epg-config gnus-util
rmail rmail-loaddefs time-date mm-decode mm-bodies mm-encode mail-parse
rfc2231 mailabbrev gmm-utils mailheader cl-loaddefs cl-lib sendmail
rfc2047 rfc2045 ietf-drums mm-util mail-prsvr mail-utils term/xterm
xterm server elec-pair mule-util tooltip eldoc electric uniquify
ediff-hook vc-hooks lisp-float-type mwheel term/x-win x-win
term/common-win x-dnd tool-bar dnd fontset image regexp-opt fringe
tabulated-list replace newcomment text-mode elisp-mode lisp-mode
prog-mode register page menu-bar rfn-eshadow isearch timer select
scroll-bar mouse jit-lock font-lock syntax facemenu font-core
term/tty-colors frame cl-generic cham georgian utf-8-lang misc-lang
vietnamese tibetan thai tai-viet lao korean japanese eucjp-ms cp51932
hebrew greek romanian slovak czech european ethiopic indian cyrillic
chinese composite charscript charprop case-table epa-hook jka-cmpr-hook
help simple abbrev obarray minibuffer cl-preloaded nadvice loaddefs
button faces cus-face macroexp files text-properties overlay sha1 md5
base64 format env code-pages mule custom widget hashtable-print-readable
backquote threads dbusbind inotify lcms2 dynamic-setting
system-font-setting font-render-setting move-toolbar gtk x-toolkit x
multi-tty make-network-process emacs)

Memory information:
((conses 16 50376 6377)
  (symbols 48 6051 1)
  (strings 32 15598 1886)
  (string-bytes 1 511783)
  (vectors 16 7797)
  (vector-slots 8 77209 12548)
  (floats 8 28 256)
  (intervals 56 175 0)
  (buffers 992 13))


[-- Attachment #2: xterm--query_discard.patch --]
[-- Type: text/x-patch, Size: 445 bytes --]

diff --git a/lisp/term/xterm.el b/lisp/term/xterm.el
index c4b0a8fb6e..30919988e9 100644
--- a/lisp/term/xterm.el
+++ b/lisp/term/xterm.el
@@ -804,6 +804,7 @@ xterm--query
       ;; Pending input can be mistakenly returned by the calls to
       ;; read-event below: discard it.
       (discard-input)
+      (while (read-event nil nil 0.01))
       (send-string-to-terminal query)
       (while handlers
         (let ((handler (pop handlers))

bug#34821: discard_input_tty does not discard pending input, resulting in garbage inserted into the buffer

[Platon Pronko]

Found two problems with current workarounds.

1. Simply reading and discarding events before xterm--query call still leaves small timing window while single typed character breaks response parsing and garbage still ends up in the buffer.

2. Thus async querying is prefererrable, and it works most of the time, but sometimes "65;5403;1c" ends up in input buffer (even if no characters are typed at all).

bug#34821: discard_input_tty does not discard pending input, resulting in garbage inserted into the buffer

[Platon Pronko]

I decided to go with async approach, since it is the one that is at least theoretically fool-proof. Currently I am trying to debug the problem of "[>65;5600;1c" appearing sporadically (10%) of the times in the input buffer. The test case is below:

1. Start the daemon and set it to use async term query:
$ ./src/emacs -Q --fg-daemon --eval "(setq xterm-query-timeout nil)"

2. Launch emacsclient:
$ ./lib-src/emacsclient -t /tmp/test.txt

3. About 1 in 10 times, observe "[>65;5600;1c" appearing in the buffer.


I tracked the problem to src/keyboard.c:read_key_sequence() function. In normal case, the following happens:

1. read_ke_sequence() is called for the first time.
2. Current input_decode_map is copied:

indec.map =  indec.map = indec.parent = KVAR (current_kboard, Vinput_decode_map);

3. It calls read_char() and blocks.
4. When emacsclient is invoked, read_char() returns the "buffer" object as per this comment:

/* When switching to a new tty (with a new keyboard),
   read_char returns the new buffer, rather than -2
   (Bug#5095).  This is because `terminal-init-xterm'
   calls read-char, which eats the wrong_kboard_jmpbuf
   return.  Any better way to fix this? -- cyd */

5. `interrupted_kboard != current_kboard` condition is triggered, this read_char() result is discarded and we jump to replay_entire_sequence.
6. read_char() is called again.
7. (terminal-init-xterm) function is invoked.
8. (xterm-query) registeres a handlers for "\e[?" and "\e[>" escape sequences.
9. read_char() returns the "buffer" object the second time.
10. That read_char() result triggers `interrupted_kboard != current_kboard` condition again, and we jump to replay_entire_sequence again.
11. Immediately after that jump, we reset the input map: `indec.map =  indec.map = indec.parent = KVAR (current_kboard, Vinput_decode_map);`, thus pulling in handlers from step 8.
12. The subsequent read_char() calls return the next SDA response characters, match is found in indec.map and xterm--verision-handler is executed.


For a situation when bug manifests steps 1-8 are the same, however at step 9 the difference happens - read_char() does not return a buffer, instead it returns the first character of the response (0x1b). `interrupted_kboard != current_kboard` is still true at that moment, thus this character is discarded. Subsequent SDA response characters (0x5b, 0x3e) fail to find a prefix match in input_decode_map, and are inserted into the buffer as-is.

I tried changing condition `interrupted_kboard != current_kboard` to `interrupted_kboard != current_kboard && BUFFERP(key)`, but that does not trigger `goto replay_entire_sequence` and thus new handlers are not pulled in from Vinput_decode_map, and so the characters are still inserted into the buffer.

Can somebody please advise me about the right course of action in this case? Should I figure out a way to load Vinput_decode_map when new character arrives and `interrupted_kboard != current_kboard`? Or should I look into why read_char() does not return a buffer the second time?

bug#34821: discard_input_tty does not discard pending input, resulting in garbage inserted into the buffer

[Eli Zaretskii]

> From: Platon Pronko <platon7pronko@gmail.com>
> Date: Sun, 7 Apr 2019 19:06:52 +0300
> 
> Can somebody please advise me about the right course of action in this case? Should I figure out a way to load Vinput_decode_map when new character arrives and `interrupted_kboard != current_kboard`? Or should I look into why read_char() does not return a buffer the second time?

The latter, I think.  But I'm far from being an expert on this, so
caveat emptor.

Thanks for looking into this tricky problem.

bug#34821: discard_input_tty does not discard pending input, resulting in garbage inserted into the buffer

[Platon Pronko]

I guess that something in (terminal-init-xterm) hooks results in some buffer switch event being fired, that triggers the second return from read_char(). But since (terminal-init-xterm) and read_key_sequence() run concurrently, we have a race condition - if the terminal responds quickly enough, second buffer switch does not trigger quick enough and this problem happens.

I verified this by adding (sleep-for 0.1) to (defun xterm--query) or (defun terminal-init-xterm) - this resulted in 100% reproduction of the bug (thanks for the directions, by the way - my hands already hurt after trying to trigger that 1-in-10 bug so many times).

Maybe trying to rely on terminal being slow with the response is not the best solution? Even if I find a cause of the buffer switch event, we won't have a way to ensure that it always arrives before the response to SDA query (because multithreading).

bug#34821: discard_input_tty does not discard pending input, resulting in garbage inserted into the buffer

[Eli Zaretskii]

> From: Platon Pronko <platon7pronko@gmail.com>
> Date: Sun, 7 Apr 2019 20:14:21 +0300
> 
> I guess that something in (terminal-init-xterm) hooks results in some buffer switch event being fired, that triggers the second return from read_char(). But since (terminal-init-xterm) and read_key_sequence() run concurrently, we have a race condition - if the terminal responds quickly enough, second buffer switch does not trigger quick enough and this problem happens.

What do you mean by "run concurrently"?  Emacs is pretty much a single
threaded program, and there's only one Lisp thread running at any
given time, which will execute both calls.

> Maybe trying to rely on terminal being slow with the response is not the best solution? Even if I find a cause of the buffer switch event, we won't have a way to ensure that it always arrives before the response to SDA query (because multithreading).

You may be right, but my reasoning was that without knowing why
there's a second buffer-switch event sometimes, we will be unable to
devise a good solution.  IOW, I think we need to understand the issue
better before we are ready to discuss a solution.

bug#34821: discard_input_tty does not discard pending input, resulting in garbage inserted into the buffer

[Platon Pronko]

> What do you mean by "run concurrently"?  Emacs is pretty much a single
> threaded program, and there's only one Lisp thread running at any
> given time, which will execute both calls.

My knowledge of Emacs internals is pretty thin indeed. But since adding sleep-for results in reordering of events, I thought that there are at least different threads that compete for execution (concurrent, maybe not parallel). Also I noticed that for example read_char() calls can block for quite a lot of time, while Lisp code continues to run. Perhaps there is one Lisp thread and some other background C threads?

> You may be right, but my reasoning was that without knowing why
> there's a second buffer-switch event sometimes, we will be unable to
> devise a good solution.  IOW, I think we need to understand the issue
> better before we are ready to discuss a solution.
I agree. I'll look at what causes that second event, I'm quite interested in the mechanics of it anyway.

bug#34821: discard_input_tty does not discard pending input, resulting in garbage inserted into the buffer

[Eli Zaretskii]

> From: Platon Pronko <platon7pronko@gmail.com>
> Date: Sun, 7 Apr 2019 22:06:23 +0300
> 
> > What do you mean by "run concurrently"?  Emacs is pretty much a single
> > threaded program, and there's only one Lisp thread running at any
> > given time, which will execute both calls.
> 
> My knowledge of Emacs internals is pretty thin indeed. But since adding sleep-for results in reordering of events, I thought that there are at least different threads that compete for execution (concurrent, maybe not parallel). Also I noticed that for example read_char() calls can block for quite a lot of time, while Lisp code continues to run. Perhaps there is one Lisp thread and some other background C threads?

No, there's just one thread.  The only other one I can think of is the
code of xterm itself.

bug#34821: discard_input_tty does not discard pending input, resulting in garbage inserted into the buffer

[Platon Pronko]

I am unable to reproduce the issue with the latest build (28.0.50). I think this issue can be closed now.

Thanks to the developers for their work!

bug#34821: discard_input_tty does not discard pending input, resulting in garbage inserted into the buffer

[Stefan Kangas]

Platon Pronko <platon7pronko@gmail.com> writes:

> I am unable to reproduce the issue with the latest build (28.0.50). I
> think this issue can be closed now.

Thanks, I'm closing the bug with this email.

Best regards,
Stefan Kangas