bug#11536: 23.4; frequent spurious auto-save while typing

bug#11536: 23.4; frequent spurious auto-save while typing

[Jim Paris]

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)

bug#11536: 23.4; frequent spurious auto-save while typing

[Chong Yidong]

Jim Paris <jim@jtan.com> writes:

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

Thanks for the bug report and the analysis.  I couldn't reproduce the
problem, but off the top of my head the analysis is correct, so I've
made the change you suggested in trunk.

bug#11536: 23.4; frequent spurious auto-save while typing

[Lars Ingebrigtsen]

Jim Paris <jim@jtan.com> writes:

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

[...]

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

(I'm going through old bug reports that unfortunately weren't resolved
at the time.)

I seem to remember there being some work done in this area over the last
few years, so this may be fixed by now.  Are you still seeing this issue
in recent Emacs versions?

-- 
(domestic pets only, the antidote for overdose, milk.)
   bloggy blog: http://lars.ingebrigtsen.no

bug#11536: 23.4; frequent spurious auto-save while typing

[Lars Ingebrigtsen]

Lars Ingebrigtsen <larsi@gnus.org> writes:

> I seem to remember there being some work done in this area over the last
> few years, so this may be fixed by now.  Are you still seeing this issue
> in recent Emacs versions?

More information was requested, but no response was given within a
month, so I'm closing this bug report.  If the problem still exists,
please respond to this email and we'll reopen the bug report.

-- 
(domestic pets only, the antidote for overdose, milk.)
   bloggy blog: http://lars.ingebrigtsen.no