Subject: 23.4; frequent spurious auto-save while typing

From: Jim Paris <[email-masked]>
Date: Mon, 21 May 2012 17:22:17 -0400

Hi,

I've had a recurring problem with various versions of emacs over the
years: as I type into a buffer, "Auto-saving...done" flashes repeatedly
in the minibuffer.  On some systems, it happens every few characters
that I type, while on other systems, it is less frequent (but still more
frequent than my auto-save-interval of 300 characters, or my
auto-save-timeout value of 30 seconds).

Setting auto-save-timeout to 0 makes the problem go away, so it is a
problem with the measuring of elapsed time.

I'm running "emacs -nw" in an xterm, and the frequency of the problem
has always varied quite a bit with my version of X server, Linux kernel,
emacs, etc, so I've long suspected that there is a race condition.  The
way I usually reproduce it is:
- run xterm
- run "emacs -nw foo.txt"
- hold down a key and notice how you see "auto-save" flashing
  occasionally even though you haven't hit 300 characters or been idle
  for 30 seconds.

I finally got around to looking for the bug, and think I may have
tracked it down as follows: (I'm unfamiliar with the emacs code, so
please forgive me if I'm stating the obvious or get something wrong)

Auto-save due to timeout interval is controlled by keyboard.c:read_char.
read_char calls dispnew.c:sit_for with the auto_save_timeout of e.g. 30
seconds.  If sit_for returns Qt (no input pending), then the autosave
happens.

sit_for works by calling process.c:wait_reading_process_output with the
same timeout.  After wait_reading_process_output returns, it returns
Qt if no input was pending.

So the auto-save problem that I'm seeing would occur if:
  - wait_reading_process_output returns before the timeout has expired
  - no input was received

I believe that this happens due to a race condition with SIGIO delivery
inside wait_reading_process_output, as follows.  Line numbers are from
process.c in debian's emacs23-23.4+1.  The pseudocode is roughly:

4707: while(1)
4737:    set &timeout to the remaining timeout
4739:    if time expired, break
4811:    set_waiting_for_input(&timeout)
4986:    select(..., &timeout)
5007:    if (time_limit && nfds == 0 && ! timeout_reduced_for_timers)
5008:      /* We wanted the full specified time, so return now.  */
5009:      break;
5010:    if (nfds < 0)
5011:      ...
5129:    if (no_avail || nfds == 0)
5130:      continue;

(I think the comment in 5008 is a typo and meant "We _waited_...")

The call to keyboard.c:set_waiting_for_input is essentially telling the
keyboard.c:input_available_signal handler to reset &timeout to zero in
the case of SIGIO.  However, consider what happens if a key is pressed
and SIGIO is received between set_waiting_for_input and select.
Then timeout will have been set to zero, and select will return
immediately with nfds == 0.  The check in 5007 will then break the
while loop, causing wait_reading_process_output to return immediately
without any data having been read -- triggering the auto-save back
in keyboard.c:read_char.

I've verified with systemtap that select() is indeed being called with a
timeout of 0, so I'm pretty sure that this is the problem.

It seems the fix is simple: remove lines 5007-5009.  It's a small
optimization that isn't necessary, because the later check at line 5129
already covers the case where nfds == 0.  Continuing the loop is fine,
because the top of the loop checks for an expired timeout and returns.
Alternately, the "break" in 5009 could be replaced with a "continue"
which would still go back up to double-check that the timeout was really
hit.

Removing the 5007-5009 check fixes the problem on all the systems I've
tried.

-jim

If Emacs crashed, and you have the Emacs process in the gdb debugger,
please include the output from the following gdb commands:
    `bt full' and `xbacktrace'.
For information about debugging Emacs, please read the file
/usr/share/emacs/23.4/etc/DEBUG.

In GNU Emacs 23.4.1 (x86_64-pc-linux-gnu, GTK+ Version 2.24.10)
 of 2012-04-07 on trouble, modified by Debian
configured using `configure  '--build' 'x86_64-linux-gnu' '--build' 'x86_64-linux-gnu' '--prefix=/usr' '--sharedstatedir=/var/lib' '--libexecdir=/usr/lib' '--localstatedir=/var/lib' '--infodir=/usr/share/info' '--mandir=/usr/share/man' '--with-pop=yes' '--enable-locallisppath=/etc/emacs23:/etc/emacs:/usr/local/share/emacs/23.4/site-lisp:/usr/local/share/emacs/site-lisp:/usr/share/emacs/23.4/site-lisp:/usr/share/emacs/site-lisp' '--with-crt-dir=/usr/lib/x86_64-linux-gnu' '--with-x=yes' '--with-x-toolkit=gtk' '--with-toolkit-scroll-bars' 'build_alias=x86_64-linux-gnu' 'CFLAGS=-g -O2 -fstack-protector --param=ssp-buffer-size=4 -Wformat -Wformat-security -Werror=format-security -Wall -DDEBIAN -O2' 'CPPFLAGS=-D_FORTIFY_SOURCE=2''

Important settings:
  value of $LC_ALL: nil
  value of $LC_COLLATE: nil
  value of $LC_CTYPE: en_US.UTF-8
  value of $LC_MESSAGES: en_US
  value of $LC_MONETARY: nil
  value of $LC_NUMERIC: nil
  value of $LC_TIME: nil
  value of $LANG: POSIX
  value of $XMODIFIERS: nil
  locale-coding-system: utf-8-unix
  default enable-multibyte-characters: t

Major mode: Text

Minor modes in effect:
  tooltip-mode: t
  mouse-wheel-mode: t
  tool-bar-mode: t
  file-name-shadow-mode: t
  global-font-lock-mode: t
  font-lock-mode: t
  auto-encryption-mode: t
  auto-compression-mode: t
  column-number-mode: t
  line-number-mode: t
  transient-mark-mode: t

Recent input:
ESC x r e p o r t - e m a c s - b u g RET

Recent messages:
Loading /etc/emacs/site-start.d/50octave3.2-emacsen.el (source)...done
Loading /etc/emacs/site-start.d/50psvn.el (source)...done
Loading /etc/emacs/site-start.d/70jim.el (source)...
Toggling menu-bar-mode off; better pass an explicit argument.
Ready.
Loading /etc/emacs/site-start.d/70jim.el (source)...done
Loading quail/latin-ltx...done
Loading /home/jim/.emacs.d/systemtap-mode.el (source)...done
Ready.
call-interactively: Text is read-only

Load-path shadows:
/usr/share/emacs/23.4/site-lisp/cmake/cmake-mode hides /usr/share/emacs/23.4/site-lisp/cmake-data/cmake-mode
/usr/share/emacs/23.4/site-lisp/cmake/cmake-mode hides /usr/share/emacs/site-lisp/cmake-mode
/usr/share/emacs/23.4/site-lisp/debian-startup hides /usr/share/emacs/site-lisp/debian-startup
/usr/share/emacs23/site-lisp/dictionaries-common/flyspell hides /usr/share/emacs/23.4/lisp/textmodes/flyspell
/usr/share/emacs23/site-lisp/dictionaries-common/ispell hides /usr/share/emacs/23.4/lisp/textmodes/ispell
/usr/share/emacs/23.4/site-lisp/octave3.2-emacsen/octave-inf hides /usr/share/emacs/23.4/lisp/progmodes/octave-inf
/usr/share/emacs/23.4/site-lisp/octave3.2-emacsen/octave-mod hides /usr/share/emacs/23.4/lisp/progmodes/octave-mod

Features:
(shadow sort mail-extr message sendmail ecomplete rfc822 mml mml-sec
password-cache mm-decode mm-bodies mm-encode mailcap mail-parse rfc2231
rfc2047 rfc2045 qp ietf-drums mailabbrev nnheader gnus-util netrc
time-date mm-util mail-prsvr gmm-utils wid-edit mailheader canlock sha1
hex-util hashcash mail-utils emacsbug systemtap-mode byte-opt bytecomp
byte-compile cc-awk cc-langs cl cl-19 cc-mode cc-fonts cc-menus cc-cmds
cc-styles cc-align cc-engine cc-vars cc-defs regexp-opt quail help-mode
easymenu view emacs-goodies-el emacs-goodies-custom
emacs-goodies-loaddefs easy-mmode tooltip ediff-hook vc-hooks
lisp-float-type mwheel x-win x-dnd font-setting tool-bar dnd fontset
image fringe lisp-mode register page menu-bar rfn-eshadow timer select
scroll-bar mldrag 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 loaddefs button minibuffer faces cus-face files
text-properties overlay md5 base64 format env code-pages mule custom
widget hashtable-print-readable backquote make-network-process dbusbind
system-font-setting font-render-setting gtk x-toolkit x multi-tty emacs)