bug#5924: 23.1; accept-process-output switching current-buffer

bug#5924: 23.1; accept-process-output switching current-buffer

[Uday S Reddy]

Reading the elisp manual doesn't indicate anywhere that a call such as 

   (accept-process-output process)

should change the current-buffer.  But it is happening.  It led to
some hairy asynchronous errors that took me an entire week to track
down.  Finally, I found an instance that was sort of reproducible, and
tested it with a code fragment such as this:

   (let ((wait nil) (buffer-x (current-buffer)))
     ...
     (if (not (equal (current-buffer) buffer-x))
        (debug nil wait))
     (setq wait t)
     (accept-process-output process)
     (if (not (equal (current-buffer) buffer-x))
        (debug nil wait))
     (setq wait nil)
     ...
   )

If the debugger is entered with the argument 't' that means that the
call to accept-process-output changed the 'current-buffer'.  The
following backtrace was obtained:

Debugger entered: (t)
  vm-imap-read-object(#<process IMAP<1>> t)
  vm-imap-read-object(#<process IMAP<1>>)
  vm-imap-read-response(#<process IMAP<1>>)
  vm-imap-read-response-and-verify(#<process IMAP<1>> "FLAGS FETCH")
  vm-imap-get-message-data-list(#<process IMAP<1>> 1 3672)
  vm-imap-retrieve-uid-and-flags-data()
  vm-imap-get-synchronization-data(t)
  vm-imap-synchronize-folder(t nil t t t t)
  vm-get-spooled-mail(t)
  vm-get-new-mail(nil)
  call-interactively(vm-get-new-mail nil nil)

The full file containing the code, VM's IMAP client, is attached.
The misbehaving accept-process-output call is in the
vm-imap-read-object function.

My theory of what happened here is as follows: VM ended an existing
IMAP session (#<process IMAP>) by sending a LOGOUT command, and
created a new one (#<process IMAP<1>>).  While it was working with the
second session, in the process-buffer, the server must have sent back
some response to the first session, which would have been accepted
during a call to accept-process-output.  This caused the
current-buffer to change to the process-buffer of the original
session. 

I found the problem orignally in Emacs 22.2, but checking it with 23.1
shows that the problem is still present in the current version.

Cheers,
Uday

-----

In GNU Emacs 23.1.1 (i386-mingw-nt5.1.2600)
 of 2009-07-30 on SOFT-MJASON
Windowing system distributor `Microsoft Corp.', version 5.1.2600
configured using `configure --with-gcc (4.4)'

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.UTF-8
  value of $XMODIFIERS: nil
  locale-coding-system: cp1252
  default-enable-multibyte-characters: t

Major mode: VM Summary

Minor modes in effect:
  savehist-mode: t
  tooltip-mode: t
  mouse-wheel-mode: t
  menu-bar-mode: t
  file-name-shadow-mode: t
  global-font-lock-mode: t
  font-lock-mode: t
  blink-cursor-mode: t
  global-auto-composition-mode: t
  auto-encryption-mode: t
  line-number-mode: t
  transient-mark-mode: t

Recent input:
<return> g C-p C-p C-SPC C-n C-n C-n C-n C-n C-n C-n 
C-n C-n C-n C-n C-n C-x C-k C-x C-f d : / g n u SPC 
v m SPC t r u SPC / SPC e m SPC <backspace> <backspace> 
b u SPC SPC SPC SPC <backspace> - e m a c s 2 3 . t 
x t <return> C-y C-x , C-x C-s <help-echo> <down-mouse-1> 
<mouse-1> C-h i m e l SPC <return> SPC C-s p r o c 
e s s C-a m <return> SPC m o u t p u t SPC SPC <return> 
<down-mouse-1> <mouse-1> <wheel-down> <wheel-down> 
<double-wheel-down> <help-echo> <down-mouse-1> <mouse-1> 
<down-mouse-2> <mouse-2> <down-mouse-1> <mouse-1> <wheel-down> 
<wheel-down> <wheel-down> <down-mouse-1> <mouse-1> 
<wheel-up> <double-wheel-up> <wheel-down> <wheel-up> 
<wheel-up> <wheel-down> <wheel-down> <wheel-down> <wheel-up> 
<double-wheel-up> <triple-wheel-up> <triple-wheel-up> 
<triple-wheel-up> <down-mouse-1> <mouse-1> <wheel-down> 
<double-wheel-down> <wheel-up> <double-wheel-up> <triple-wheel-up> 
<wheel-up> <double-wheel-up> <triple-wheel-up> <down-mouse-1> 
<mouse-1> C-x b <return> q C-x , q C-x u C-n C-n C-n 
C-n C-n C-n C-n C-n C-n C-n C-n C-n C-k C-x C-s C-x 
b * B SPC <return> q C-x m C-x k <return> M-x v m <backspace> 
<backspace> r e p o r t - e m SPC SPC <return>

Recent messages:
Composing main Info directory...done
Mark saved where search started
Mark set
Undo!
Saving file d:/gnu/vm/trunk/bug-accept-process-output-emacs23.txt...
Wrote d:/gnu/vm/trunk/bug-accept-process-output-emacs23.txt
Back to top level.
Parsing d:/Home/udr/.mailrc...
Parsing y:/dotfiles/.mailrc... done
Parsing d:/Home/udr/.mailrc... done

------

[ATTACHMENT d:/gnu/vm/trunk23/lisp/vm-imap.el, text/plain]

bug#5924: 23.1; accept-process-output switching current-buffer

[Stefan Monnier]

> Reading the elisp manual doesn't indicate anywhere that a call such as 
>    (accept-process-output process)
> should change the current-buffer.

That depends on the code run during the wait.  I.e. it depends on the
code run by the process filters, sentinels, timers, ...

We've already fixed several bugs where process filters changed
current-buffer, but I think we should fix it not in the process filters
but in the code that run them.  At least, unless someone can come up
with a scenario where a process filter, sentinel, or timer would need
to change current-buffer.


        Stefan

bug#5924: 23.1; accept-process-output switching current-buffer

[Uday S Reddy]

Stefan Monnier writes:

> > Reading the elisp manual doesn't indicate anywhere that a call such as 
> >    (accept-process-output process)
> > should change the current-buffer.
> 
> That depends on the code run during the wait.  I.e. it depends on the
> code run by the process filters, sentinels, timers, ...

Yes, indeed!  If there is code being run during accept-process-output
then the state can be changed by that code.  But in the example that I
witnessed, there was *no code* being run.

Looking at the manual again, it says in "Accepting Output from
Processes":

    "There are *two ways* to receive the output that a subprocess
    writes to its standard output stream.  The output can be inserted
    in a buffer, which is called the associated buffer of the process,
    or a function called the "filter function" can be called to act on
    the output."

In the second "way" that is being talked about, we can reasonably
expect that current-buffer might change during the execution of the
filter function.  But in the first "way", where Emacs is doing all the
work of accepting the process output, I don't think it should change
the current-buffer.  

> We've already fixed several bugs where process filters changed
> current-buffer, but I think we should fix it not in the process filters
> but in the code that run them.  At least, unless someone can come up
> with a scenario where a process filter, sentinel, or timer would need
> to change current-buffer.

I don't fully understand this, but let me say that I am just talking
about problem with the Elisp semantics, not Emacs libraries.  If a
filter function changed the current-buffer, one would regard it as
buggy.  But if Elisp itself changes the current-buffer...?

The other thing that concerns me is that the same behaviour persisted
even if I set the JUST-THIS-ONE flag to t.  In that case, one would
expect that Elisp would ignore the output from all other processes.
So, it should have no reason to change the current-buffer to the other
process.  But it did.  I am not sure if the JUST-THIS-ONE flag is
doing anything at all.

Cheers,
Uday

PS I have been looking at the emacs-developers list lately.  It is
quite amazing how much the guys talk, RMS included!  

bug#5924: 23.1; accept-process-output switching current-buffer

[Stefan Monnier]

>> > Reading the elisp manual doesn't indicate anywhere that a call such as 
>> >    (accept-process-output process)
>> > should change the current-buffer.
>> That depends on the code run during the wait.  I.e. it depends on the
>> code run by the process filters, sentinels, timers, ...
> Yes, indeed!  If there is code being run during accept-process-output
> then the state can be changed by that code.  But in the example that I
> witnessed, there was *no code* being run.

That's very odd: both the sentinel and the filter code are careful to
preserve the current_buffer when there's no sentinel or no filter set.

I've just installed a change in the Emacs Bzr trunk so that the
current-buffer is preserved when running the Elisp code of process
filters and sentinels.  If you can try this code (or try the patch
below) to see if it fixes your problem, it would be helpful.

> In the second "way" that is being talked about, we can reasonably
> expect that current-buffer might change during the execution of the
> filter function.  But in the first "way", where Emacs is doing all the
> work of accepting the process output, I don't think it should change
> the current-buffer.

Indeed and it shouldn't.  And with my new changes, even when running
Elisp it shouldn't change current-buffer either.

> I don't fully understand this, but let me say that I am just talking
> about problem with the Elisp semantics, not Emacs libraries.  If a
> filter function changed the current-buffer, one would regard it as
> buggy.  But if Elisp itself changes the current-buffer...?

Given that it's code run asynchronously, letting it change
current-buffer is asking for trouble.

> The other thing that concerns me is that the same behaviour persisted
> even if I set the JUST-THIS-ONE flag to t.  In that case, one would
> expect that Elisp would ignore the output from all other processes.

Indeed, that's what it means.

> So, it should have no reason to change the current-buffer to the other
> process.  But it did.  I am not sure if the JUST-THIS-ONE flag is
> doing anything at all.

I don't know of a bug in this regard, so if you have evidence that
JUST-THIS-ONE doesn't prevent reading other process's output, please
report it.


        Stefan


=== modified file 'src/process.c'
--- src/process.c	2010-04-02 03:10:33 +0000
+++ src/process.c	2010-04-11 16:15:09 +0000
@@ -5314,6 +5314,8 @@
   struct coding_system *coding = proc_decode_coding_system[channel];
   int carryover = p->decoding_carryover;
   int readmax = 4096;
+  int count = SPECPDL_INDEX ();
+  Lisp_Object odeactivate;
 
   chars = (char *) alloca (carryover + readmax);
   if (carryover)
@@ -5386,15 +5388,16 @@
   /* Now set NBYTES how many bytes we must decode.  */
   nbytes += carryover;
 
+  odeactivate = Vdeactivate_mark;
+  /* There's no good reason to let process filters change the current
+     buffer, and many callers of accept-process-output, sit-for, and
+     friends don't expect current-buffer to be changed from under them.  */
+  record_unwind_protect (Fset_buffer, Fcurrent_buffer ());
+
   /* Read and dispose of the process output.  */
   outstream = p->filter;
   if (!NILP (outstream))
     {
-      /* We inhibit quit here instead of just catching it so that
-	 hitting ^G when a filter happens to be running won't screw
-	 it up.  */
-      int count = SPECPDL_INDEX ();
-      Lisp_Object odeactivate;
       Lisp_Object obuffer, okeymap;
       Lisp_Object text;
       int outer_running_asynch_code = running_asynch_code;
@@ -5402,10 +5405,12 @@
 
       /* No need to gcpro these, because all we do with them later
 	 is test them for EQness, and none of them should be a string.  */
-      odeactivate = Vdeactivate_mark;
       XSETBUFFER (obuffer, current_buffer);
       okeymap = current_buffer->keymap;
 
+      /* We inhibit quit here instead of just catching it so that
+	 hitting ^G when a filter happens to be running won't screw
+	 it up.  */
       specbind (Qinhibit_quit, Qt);
       specbind (Qlast_nonmenu_event, Qt);
 
@@ -5474,9 +5479,6 @@
       restore_search_regs ();
       running_asynch_code = outer_running_asynch_code;
 
-      /* Handling the process output should not deactivate the mark.  */
-      Vdeactivate_mark = odeactivate;
-
       /* Restore waiting_for_user_input_p as it was
 	 when we were called, in case the filter clobbered it.  */
       waiting_for_user_input_p = waiting;
@@ -5492,27 +5494,19 @@
 	   cause trouble (for example it would make sit_for return).  */
 	if (waiting_for_user_input_p == -1)
 	  record_asynch_buffer_change ();
-
-      unbind_to (count, Qnil);
-      return nbytes;
     }
 
   /* If no filter, write into buffer if it isn't dead.  */
-  if (!NILP (p->buffer) && !NILP (XBUFFER (p->buffer)->name))
+  else if (!NILP (p->buffer) && !NILP (XBUFFER (p->buffer)->name))
     {
       Lisp_Object old_read_only;
       int old_begv, old_zv;
       int old_begv_byte, old_zv_byte;
-      Lisp_Object odeactivate;
       int before, before_byte;
       int opoint_byte;
       Lisp_Object text;
       struct buffer *b;
-      int count = SPECPDL_INDEX ();
 
-      odeactivate = Vdeactivate_mark;
-
-      record_unwind_protect (Fset_buffer, Fcurrent_buffer ());
       Fset_buffer (p->buffer);
       opoint = PT;
       opoint_byte = PT_BYTE;
@@ -5610,13 +5604,14 @@
       if (old_begv != BEGV || old_zv != ZV)
 	Fnarrow_to_region (make_number (old_begv), make_number (old_zv));
 
-      /* Handling the process output should not deactivate the mark.  */
-      Vdeactivate_mark = odeactivate;
 
       current_buffer->read_only = old_read_only;
       SET_PT_BOTH (opoint, opoint_byte);
-      unbind_to (count, Qnil);
     }
+  /* Handling the process output should not deactivate the mark.  */
+  Vdeactivate_mark = odeactivate;
+
+  unbind_to (count, Qnil);
   return nbytes;
 }
 
@@ -6845,6 +6840,11 @@
   XSETBUFFER (obuffer, current_buffer);
   okeymap = current_buffer->keymap;
 
+  /* There's no good reason to let sentinels change the current
+     buffer, and many callers of accept-process-output, sit-for, and
+     friends don't expect current-buffer to be changed from under them.  */
+  record_unwind_protect (Fset_buffer, Fcurrent_buffer ());
+
   sentinel = p->sentinel;
   if (NILP (sentinel))
     return;

bug#5924: 23.1; accept-process-output switching current-buffer

[Uday S Reddy]

Stefan Monnier writes:

> I've just installed a change in the Emacs Bzr trunk so that the
> current-buffer is preserved when running the Elisp code of process
> filters and sentinels.  If you can try this code (or try the patch
> below) to see if it fixes your problem, it would be helpful.

Hi Stephan, thanks very much for the quick action on this.  I am a bit
embarrassed because I have never done a build of Emacs.  And, I am
going to be away for a few days.  So, it will take me a while to try
it out.  Hope you don't mind.

The trick I use for these kinds of asynchronous errors is to set error
traps that log entries whenever the unexpected situations occur.  Of
course, it is not easy to figure out what to log and several repeated
trials may be necessary to get enough diagnostic information.

> > So, it should have no reason to change the current-buffer to the other
> > process.  But it did.  I am not sure if the JUST-THIS-ONE flag is
> > doing anything at all.
> 
> I don't know of a bug in this regard, so if you have evidence that
> JUST-THIS-ONE doesn't prevent reading other process's output, please
> report it.

OK, I defined a wrappe around accept-process-output function as follows:

(defsubst vm-accept-process-output (process)
  (let ((buf (current-buffer))
	(old-point-max (save-excursion
			 (switch-to-buffer candidate-buf)
			 (point-max))))
    (accept-process-output process nil nil t)
    (if (not (equal buf (current-buffer)))
	(if (and (equal (current-buffer) candidate-buf)
		 (not (= old-point-max (point-max))))
	    (debug "found output sent to %s: %s to %s"
		   (current-buffer) old-point-max (point-max))
	  (debug "found buffer changed to %s" (current-buffer))))))

Since the JUST-THIS-ONE flag is passed in as t, it shouldn't insert
anything anything in 'candidate-buf' (which was my guess as to where
it would go).  But the backtrace shows that it went there.

Debugger entered: ("found output sent to %s: %s to %s" #<buffer saved IMAP localhost 19:59:10> 1019 1086)
  vm-imap-read-object(#<process IMAP<1>>)
  vm-imap-read-response(#<process IMAP<1>>)
  vm-imap-read-response-and-verify(#<process IMAP<1>> "size FETCH")
  vm-imap-get-message-size(#<process IMAP<1>> 3698)
  byte-code(...)
  vm-imap-synchronize-folder(t nil t t t t)
  vm-get-spooled-mail(t)
  vm-get-new-mail(nil)
  call-interactively(vm-get-new-mail nil nil)

Cheers,
Uday

bug#5924: 23.1; accept-process-output switching current-buffer

[Stefan Monnier]

>> I've just installed a change in the Emacs Bzr trunk so that the
>> current-buffer is preserved when running the Elisp code of process
>> filters and sentinels.  If you can try this code (or try the patch
>> below) to see if it fixes your problem, it would be helpful.
> Hi Stephan, thanks very much for the quick action on this.  I am a bit
> embarrassed because I have never done a build of Emacs.  And, I am
> going to be away for a few days.  So, it will take me a while to try
> it out.  Hope you don't mind.

No problem, of course.

> (defsubst vm-accept-process-output (process)
>   (let ((buf (current-buffer))
> 	(old-point-max (save-excursion
> 			 (switch-to-buffer candidate-buf)
> 			 (point-max))))
>     (accept-process-output process nil nil t)
>     (if (not (equal buf (current-buffer)))
> 	(if (and (equal (current-buffer) candidate-buf)
> 		 (not (= old-point-max (point-max))))
> 	    (debug "found output sent to %s: %s to %s"
> 		   (current-buffer) old-point-max (point-max))
> 	  (debug "found buffer changed to %s" (current-buffer))))))

[ Side note: please, please, pretty please, don't use switch-to-buffer:
the above code is not supposed to mess with windows, so you want to use
`set-buffer' instead, and actually in this case (with-current-buffer
candidate-buf (point-max)) is really the right way to write it since you
do not need to save any point&mark but only the current buffer. ]

> Since the JUST-THIS-ONE flag is passed in as t, it shouldn't insert
> anything anything in 'candidate-buf' (which was my guess as to where
> it would go).  But the backtrace shows that it went there.

Hmm... will have to dig into this one as well.


        Stefan

bug#5924: 23.1; accept-process-output switching current-buffer

[Uday S Reddy]

Stefan Monnier writes:

> That's very odd: both the sentinel and the filter code are careful to
> preserve the current_buffer when there's no sentinel or no filter set.

I might also mention that the processes I am dealing with are created
by open-network-stream.  Perhaps this primitive is creating
filters/sentinels which are creating interference.  You can find my
full code at the URL below if you want to check further.

  http://bazaar.launchpad.net/~vm/vm/trunk/annotate/head:/lisp/vm-imap.el

The comment blocks give the signatures of the functions which you can
use to perhaps locate the interesting bits.  

----

I also realized lately that in the normal operation of VM, this
problem doesn't show up much because it is rare to deal with multiple
IMAP sessions concurrently.  However, for the sake of development
work, I have turned on tracing/logging, which is preserving the old
process-buffers.  So, this problem, which is luckily repeatable,
occurs immediately after one IMAP session has been closed and another
begun, because the IMAP server sends some random closing message to
the old session while the new session is going on, and we get the
interference that I have observed.

Cheers,
Uday

bug#5924: 23.1; accept-process-output switching current-buffer

[Uday S Reddy]

[-- Attachment #1: message body text --]
[-- Type: text/plain, Size: 4600 bytes --]

Stefan Monnier writes:

> I've just installed a change in the Emacs Bzr trunk so that the
> current-buffer is preserved when running the Elisp code of process
> filters and sentinels.  If you can try this code (or try the patch
> below) to see if it fixes your problem, it would be helpful.

Hi Stephan, Sorry for the delay in getting back to you.  I have now
compiled and tried the latest bzr version (revno 100368).  But, it
seems to that the problem persists.

Here is my current proxy for accept-process-output:

  (defsubst vm-accept-process-output (process)
    "Accept output from PROCESS.  The variable `vm-imap-server-timeout'
  specifies how many seconds to wait before timing out.  If a timeout
  occurs, typically VM cannot proceed."
    ;; protect against possible buffer change due to bug in Emacs
    (let ((buf (current-buffer))
	  (got-output (accept-process-output process vm-imap-server-timeout)))
      (if got-output
	  (when (not (equal (current-buffer) buf))
	    (if (string-lessp "24" emacs-version)
		;; the Emacs bug should have been fixed
		(message 
		 "Emacs process output error: Buffer changed to %s" 
		 (current-buffer)))
	    ;; recover from the bug
	    (set-buffer buf))
	(vm-imap-protocol-error "No response from the IMAP server"))))

and the error came up pretty much the first time I tried it:

  Emacs process output error: Buffer changed to saved IMAP mailhost.c 10:31:09

The current-buffer should have been "IMAP mailhost.c 10:31.40".  But
it switched to the "IMAP mailhost.c 10:31:09" (call it the "old
buffer") because its process sent some output.

I am attaching the contents of the old buffer.  I think the last line
would have been output while the current accept-process-output was
done.  (Note that this line came in a few seconds after the current
process got started.)

So, there appears to be some deeper problem than originally thought.

Cheers,
Uday

3RhcnRpbmcgSU1BUCBzZXNzaW9uIFRodSBNYXkgMjAgMTA6MzE6MDkgMjAxMA0KY29ubmVjdGlu
ZyB0byBtYWlsaG9zdC5jcy5iaGFtLmFjLnVrOjE0Mw0KY29ubmVjdGVkIGZvciBmZXRjaA0KKiBP
SyBJTUFQNCBSZWFkeSBpbWFwIDAwMDFjZGYzDQ0KVk0gQ0FQQUJJTElUWQ0NCiogQ0FQQUJJTElU
WSBJTUFQNCBJTUFQNFJFVjENDQpWTSBPSyBDQVBBQklMSVRZDQ0KVk0gTE9HSU4gPHBhcmFtZXRl
cnMgb21pdHRlZD4NDQpWTSBPSyBMb2dnZWQgaW4uDQ0KVk0gU0VMRUNUICJJTkJPWCINDQoqIEZM
QUdTIChcQW5zd2VyZWQgXEZsYWdnZWQgXERlbGV0ZWQgXFNlZW4gXERyYWZ0IGZvcndhcmRlZCBm
aWxlZCByZWRpc3RyaWJ1dGVkICEgJEZvcndhcmRlZCA3MzUwIDczNTQgNzM5MSBzaWduZWQgKiBh
Y2NlcHQgYWN0aW9uIHBsYWdpYXJpc20gSnVuayBOb25KdW5rICFAKQ0NCiogT0sgW1BFUk1BTkVO
VEZMQUdTIChcQW5zd2VyZWQgXEZsYWdnZWQgXERlbGV0ZWQgXFNlZW4gXERyYWZ0IGZvcndhcmRl
ZCBmaWxlZCByZWRpc3RyaWJ1dGVkICEgJEZvcndhcmRlZCA3MzUwIDczNTQgNzM5MSBzaWduZWQg
KiBhY2NlcHQgYWN0aW9uIHBsYWdpYXJpc20gSnVuayBOb25KdW5rICFAIFwqKV0gRmxhZ3MgcGVy
bWl0dGVkLg0NCiogMjY0OCBFWElTVFMNDQoqIDAgUkVDRU5UDQ0KKiBPSyBbVUlEVkFMSURJVFkg
MTIxNzI0MzE0Nl0gVUlEcyB2YWxpZA0NCiogT0sgW1VJRE5FWFQgMjY2MDBdIFByZWRpY3RlZCBu
ZXh0IFVJRA0NClZNIE9LIFtSRUFELVdSSVRFXSBTZWxlY3QgY29tcGxldGVkLg0NClZNIFVJRCBG
RVRDSCAyNjQ3MToyNjQ3MSAoUkZDODIyLlNJWkUpDQ0KKiAyNTk0IEZFVENIIChSRkM4MjIuU0la
RSA1ODE3NSBVSUQgMjY0NzEpDQ0KVk0gT0sgRmV0Y2ggY29tcGxldGVkLg0NClZNIFVJRCBGRVRD
SCAyNjQ3MToyNjQ3MSAoQk9EWS5QRUVLW10pDQ0KKiAyNTk0IEZFVENIIChVSUQgMjY0NzEgQk9E
WVtdIHs1ODE3NX0NDQopDQ0KVk0gT0sgRmV0Y2ggY29tcGxldGVkLg0NClZNIE5PT1ANDQpWTSBP
SyBOT09QIGNvbXBsZXRlZC4NDQpWTSBVSUQgRkVUQ0ggMjY1ODI6MjY1ODIgKFJGQzgyMi5TSVpF
KQ0NCiogMjYzOCBGRVRDSCAoUkZDODIyLlNJWkUgMjE4MSBVSUQgMjY1ODIpDQ0KVk0gT0sgRmV0
Y2ggY29tcGxldGVkLg0NClZNIFVJRCBGRVRDSCAyNjU4MjoyNjU4MiAoQk9EWS5QRUVLW10pDQ0K
KiAyNjM4IEZFVENIIChVSUQgMjY1ODIgQk9EWVtdIHsyMTgxfQ0NCikNDQpWTSBPSyBGZXRjaCBj
b21wbGV0ZWQuDQ0KVk0gTk9PUA0NClZNIE9LIE5PT1AgY29tcGxldGVkLg0NClZNIFVJRCBGRVRD
SCAyNjQ3MToyNjQ3MSAoUkZDODIyLlNJWkUpDQ0KKiAyNTk0IEZFVENIIChSRkM4MjIuU0laRSA1
ODE3NSBVSUQgMjY0NzEpDQ0KVk0gT 0sgRmV0Y2ggY29tcGxldGVkLg0NClZNIFVJRCBGRVRDSCAy
NjQ3MToyNjQ3MSAoQk9EWS5QRUVLW10pDQ0KKiAyNTk0IEZFVENIIChVSUQgMjY0NzEgQk9EWVtd
IHs1ODE3NX0NDQopDQ0KVk0gT0sgRmV0Y2ggY29tcGxldGVkLg0NClZNIE5PT1ANDQpWTSBPSyBO
T09QIGNvbXBsZXRlZC4NDQpWTSBVSUQgRkVUQ0ggMjY1Nzg6MjY1NzggKFJGQzgyMi5TSVpFKQ0N
CiogMjYzNSBGRVRDSCAoUkZDODIyLlNJWkUgNTIzODggVUlEIDI2NTc4KQ0NClZNIE9LIEZldGNo
IGNvbXBsZXRlZC4NDQpWTSBVSUQgRkVUQ0ggMjY1Nzg6MjY1NzggKEJPRFkuUEVFS1tdKQ0NCiog
MjYzNSBGRVRDSCAoVUlEIDI2NTc4IEJPRFlbXSB7NTIzODh9DQ0KKQ0NClZNIE9LIEZldGNoIGNv
bXBsZXRlZC4NDQpWTSBMT0dPVVQNDQoqIEJZRSBMb2dnaW5nIG91dA0NClZNIE9LIExvZ291dCBj
b21wbGV0ZWQuDQ0KDQpQcm9jZXNzIElNQVA8Mj4gY29ubmVjdGlvbiBicm9rZW4gYnkgcmVtb3Rl
IHBlZXINCmVuZGluZyBJTUFQIHNlc3Npb24gVGh1IE1heSAyMCAxMDozMTo0MyAyMDEw\r

[-- Attachment #2: contents of IMAP mailhost.c 10:31:09 --]
[-- Type: text/plain, Size: 1932 bytes --]

starting IMAP session Thu May 20 10:31:09 2010
connecting to mailhost.cs.bham.ac.uk:143
connected for fetch
* OK IMAP4 Ready imap 0001cdf3
VM CAPABILITY
* CAPABILITY IMAP4 IMAP4REV1
VM OK CAPABILITY
VM LOGIN <parameters omitted>
VM OK Logged in.
VM SELECT "INBOX"
* FLAGS (\Answered \Flagged \Deleted \Seen \Draft forwarded filed redistributed ! $Forwarded 7350 7354 7391 signed * accept action plagiarism Junk NonJunk !@)
* OK [PERMANENTFLAGS (\Answered \Flagged \Deleted \Seen \Draft forwarded filed redistributed ! $Forwarded 7350 7354 7391 signed * accept action plagiarism Junk NonJunk !@ \*)] Flags permitted.
* 2648 EXISTS
* 0 RECENT
* OK [UIDVALIDITY 1217243146] UIDs valid
* OK [UIDNEXT 26600] Predicted next UID
VM OK [READ-WRITE] Select completed.
VM UID FETCH 26471:26471 (RFC822.SIZE)
* 2594 FETCH (RFC822.SIZE 58175 UID 26471)
VM OK Fetch completed.
VM UID FETCH 26471:26471 (BODY.PEEK[])
* 2594 FETCH (UID 26471 BODY[] {58175}
)
VM OK Fetch completed.
VM NOOP
VM OK NOOP completed.
VM UID FETCH 26582:26582 (RFC822.SIZE)
* 2638 FETCH (RFC822.SIZE 2181 UID 26582)
VM OK Fetch completed.
VM UID FETCH 26582:26582 (BODY.PEEK[])
* 2638 FETCH (UID 26582 BODY[] {2181}
)
VM OK Fetch completed.
VM NOOP
VM OK NOOP completed.
VM UID FETCH 26471:26471 (RFC822.SIZE)
* 2594 FETCH (RFC822.SIZE 58175 UID 26471)
VM OK Fetch completed.
VM UID FETCH 26471:26471 (BODY.PEEK[])
* 2594 FETCH (UID 26471 BODY[] {58175}
)
VM OK Fetch completed.
VM NOOP
VM OK NOOP completed.
VM UID FETCH 26578:26578 (RFC822.SIZE)
* 2635 FETCH (RFC822.SIZE 52388 UID 26578)
VM OK Fetch completed.
VM UID FETCH 26578:26578 (BODY.PEEK[])
* 2635 FETCH (UID 26578 BODY[] {52388}
)
VM OK Fetch completed.
VM LOGOUT
* BYE Logging out
VM OK Logout completed.

Process IMAP<2> connection broken by remote peer
ending IMAP session Thu May 20 10:31:43 2010

bug#5924: 23.1; accept-process-output switching current-buffer

[Uday S Reddy]

Dear Stefan,

I have now tried this with the Windows build that was published today:
emacs-20100523.  The same problem occurs.  (Of course, there was no
reason to expect that anything would be different.)

Even though I am able to protect the spurious buffer-change inside VM
using my wrapper for accept-process-output, I can't do anything if
some other process is invoked and the VM process interferes with it.
This is now regularly occurring with smtpmail.  In the middle of
smtpmail, the buffer is changing to VM's IMAP process buffer (invoked
for an FCC to an IMAP folder), and smtpmail fails.  Sometimes the smtp
has gone through and sometimes it hasn't.  This is getting to be an
annoyance.

I am repeating my previous message again below, because it got
MIME-encoded in a strange way last time:

----

Here is my current proxy for accept-process-output:

  (defsubst vm-accept-process-output (process)
    "Accept output from PROCESS.  The variable `vm-imap-server-timeout'
  specifies how many seconds to wait before timing out.  If a timeout
  occurs, typically VM cannot proceed."
    ;; protect against possible buffer change due to bug in Emacs
    (let ((buf (current-buffer))
	  (got-output (accept-process-output process vm-imap-server-timeout)))
      (if got-output
	  (when (not (equal (current-buffer) buf))
	    (if (string-lessp "24" emacs-version)
		;; the Emacs bug should have been fixed
		(message 
		 "Emacs process output error: Buffer changed to %s" 
		 (current-buffer)))
	    ;; recover from the bug
	    (set-buffer buf))
	(vm-imap-protocol-error "No response from the IMAP server"))))

and the error came up pretty much the first time I tried it:

  Emacs process output error: Buffer changed to saved IMAP mailhost.c 10:31:09

The current-buffer should have been "IMAP mailhost.c 10:31.40".  But
it switched to the "IMAP mailhost.c 10:31:09" (call it the "old
buffer") because its process sent some output.

I am attaching the contents of the old buffer.  I think the last line
would have been output while the current accept-process-output was
done.  (Note that this line came in a few seconds after the current
process got started.)

-----

starting IMAP session Thu May 20 10:31:09 2010
connecting to mailhost.cs.bham.ac.uk:143
connected for fetch
* OK IMAP4 Ready imap 0001cdf3
VM CAPABILITY
* CAPABILITY IMAP4 IMAP4REV1
VM OK CAPABILITY
VM LOGIN <parameters omitted>
VM OK Logged in.
VM SELECT "INBOX"
* FLAGS (\Answered \Flagged \Deleted \Seen \Draft forwarded filed redistributed
! $Forwarded 7350 7354 7391 signed * accept action plagiarism Junk NonJunk !@)
* OK [PERMANENTFLAGS (\Answered \Flagged \Deleted \Seen \Draft forwarded filed
redistributed ! $Forwarded 7350 7354 7391 signed * accept action plagiarism
Junk NonJunk !@ \*)] Flags permitted.
* 2648 EXISTS
* 0 RECENT
* OK [UIDVALIDITY 1217243146] UIDs valid
* OK [UIDNEXT 26600] Predicted next UID
VM OK [READ-WRITE] Select completed.
VM UID FETCH 26471:26471 (RFC822.SIZE)
* 2594 FETCH (RFC822.SIZE 58175 UID 26471)
VM OK Fetch completed.
VM UID FETCH 26471:26471 (BODY.PEEK[])
* 2594 FETCH (UID 26471 BODY[] {58175}
)
VM OK Fetch completed.
VM NOOP
VM OK NOOP completed.
VM UID FETCH 26582:26582 (RFC822.SIZE)
* 2638 FETCH (RFC822.SIZE 2181 UID 26582)
VM OK Fetch completed.
VM UID FETCH 26582:26582 (BODY.PEEK[])
* 2638 FETCH (UID 26582 BODY[] {2181}
)
VM OK Fetch completed.
VM NOOP
VM OK NOOP completed.
VM UID FETCH 26471:26471 (RFC822.SIZE)
* 2594 FETCH (RFC822.SIZE 58175 UID 26471)
VM OK Fetch completed.
VM UID FETCH 26471:26471 (BODY.PEEK[])
* 2594 FETCH (UID 26471 BODY[] {58175}
)
VM OK Fetch completed.
VM NOOP
VM OK NOOP completed.
VM UID FETCH 26578:26578 (RFC822.SIZE)
* 2635 FETCH (RFC822.SIZE 52388 UID 26578)
VM OK Fetch completed.
VM UID FETCH 26578:26578 (BODY.PEEK[])
* 2635 FETCH (UID 26578 BODY[] {52388}
)
VM OK Fetch completed.
VM LOGOUT
* BYE Logging out
VM OK Logout completed.

Process IMAP<2> connection broken by remote peer
ending IMAP session Thu May 20 10:31:43 2010

---

Cheers,
Uday

bug#5924: 23.1; accept-process-output switching current-buffer

[Uday S Reddy]

Dear Stefan,

I should take back my last couple of messages.  I had a timer task
running (after 2 second delay) which was changing buffers.
Unfortunately, this was getting scheduled to run during the other
process's accept-process-output.  So, I had mistakenly put the blame
on accept-process-output.

This means that the reproducible version of the problem was due to my
own misconfigured timer task.  I will now go and hunt for the
asynchronous versions of the problem to see if they are fixed by your
patch.  

Sorry for the hassle.

Cheers,
Uday

bug#5924: 23.1; accept-process-output switching current-buffer

[Stefan Monnier]

> I should take back my last couple of messages.  I had a timer task
> running (after 2 second delay) which was changing buffers.
> Unfortunately, this was getting scheduled to run during the other
> process's accept-process-output.  So, I had mistakenly put the blame
> on accept-process-output.

Thanks for the heads up.  BTW, could you try the patch below (including
byte-compiling the file and re-dumping Emacs since it's a preloaded
file), to see if it would have fixed your problem, even with the
offending timer?


        Stefan


PS: BTW, I recommend to stay away from set-buffer and always use
with-current-buffer instead ;-)


=== modified file 'lisp/emacs-lisp/timer.el'
--- lisp/emacs-lisp/timer.el	2010-01-13 08:35:10 +0000
+++ lisp/emacs-lisp/timer.el	2010-07-23 22:32:44 +0000
@@ -321,7 +321,11 @@
 	  ;; We do this after rescheduling so that the handler function
 	  ;; can cancel its own timer successfully with cancel-timer.
 	  (condition-case nil
-	      (apply (timer--function timer) (timer--args timer))
+              ;; Timer functions should not change the current buffer.
+              ;; If they do, all kinds of nasty surprises can happen,
+              ;; and it can be hellish to track down their source.
+              (save-current-buffer
+                (apply (timer--function timer) (timer--args timer)))
 	    (error nil))
 	  (if retrigger
 	      (setf (timer--triggered timer) nil)))

bug#5924: 23.1; accept-process-output switching current-buffer

[Lars Magne Ingebrigtsen]

Stefan Monnier <monnier@IRO.UMontreal.CA> writes:

>> I should take back my last couple of messages.  I had a timer task
>> running (after 2 second delay) which was changing buffers.
>> Unfortunately, this was getting scheduled to run during the other
>> process's accept-process-output.  So, I had mistakenly put the blame
>> on accept-process-output.
>
> Thanks for the heads up.  BTW, could you try the patch below (including
> byte-compiling the file and re-dumping Emacs since it's a preloaded
> file), to see if it would have fixed your problem, even with the
> offending timer?

There was no response here last year, but the patch was apparently
applied, so I'm closing this report.  If this bug still persists, please
reopen this report.

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