* nnimap versus tls @ 2003-05-19 13:32 Gaute B Strokkenes 2003-07-02 23:46 ` Gaute B Strokkenes 2003-07-04 18:24 ` Kai Großjohann 0 siblings, 2 replies; 25+ messages in thread From: Gaute B Strokkenes @ 2003-05-19 13:32 UTC (permalink / raw) I didn't have much luck with this request in gnu.emacs.gnus; perhaps someone here can help me? I have one nnimap server and two imap mail-sources (one of which is the same server as the nnimap server). Everything works hunky-dory until I add :stream tls to either or both of the imap mail-sources. Everything works fine for a while, but eventually I get an error with a backtrace that looks like this: --8<-- Debugger entered--Lisp error: (error "Selecting deleted buffer") imap-arrival-filter(#<process imap<1>> "* BYE kern.srcf.societies.cam.ac.uk IMAP4rev1 server terminating connection^M\n6 OK LOGOUT completed^M\n*** Received corrupted data(-9) - server has terminated the connection abnormally\n") delete-process(#<process imap<2>>) imap-close(#<buffer *imap source*>) mail-source-fetch-imap((imap :server "imap.hermes.cam.ac.uk" :mailbox "mail/limbo" :predicate "UNDELETED" :password "xxx" :stream tls) #[(file orig-file) "B.CD. .?...E F\"G%." [file orig-file nnmail-split-incoming nnml-save-mail nil nnmail-get-split-gr.oup (imap :server "imap.hermes.cam.ac.uk" :mailbox "mail/limbo" :predicate "UNDELETED" :password "xxx" :stream tls) nnml-active-number] 7]) mail-source-fetch((imap :server "imap.hermes.cam.ac.uk" :mailbox "mail/limbo" :predicate "UNDELETED" :password "xxx" :stream tls) #[(file orig-file) "B.CD. .?...E F\"G%." [file orig-file nnmail-split-incoming nnml-save-mail nil nnmail-get-split-g.roup (.imap :server "imap.hermes.cam.ac.uk" :mailbox "mail/limbo" :predicate "UNDELETED" :password "xxx" :stream tls) nnml-active-number] 7]) nnmail-get-new-mail(nnml nnml-save-nov "~/Mail/" nil) nnml-request-scan(nil "") gnus-request-scan(nil (nnml "")) gnus-read-active-file-1((nnml "") nil) gnus-read-active-file() gnus-group-get-new-news(nil) call-interactively(gnus-group-get-new-news) --8<-- [Note that I have replaced my password with "xxx" in the backtrace.] [The backtrace also contains control characters/whatnot, these will be likely be munged when I post.] I really don't know how to debug this at all, so I'm hoping someone can help me... -- Big Gaute http://www.srcf.ucam.org/~gs234/ I think my CAREER is RUINED!! ^ permalink raw reply [flat|nested] 25+ messages in thread
* Re: nnimap versus tls 2003-05-19 13:32 nnimap versus tls Gaute B Strokkenes @ 2003-07-02 23:46 ` Gaute B Strokkenes 2003-07-04 18:24 ` Kai Großjohann 1 sibling, 0 replies; 25+ messages in thread From: Gaute B Strokkenes @ 2003-07-02 23:46 UTC (permalink / raw) On 19 mai 2003, gs234@cam.ac.uk wrote: > I didn't have much luck with this request in gnu.emacs.gnus; perhaps > someone here can help me? > > I have one nnimap server and two imap mail-sources (one of which is > the same server as the nnimap server). Everything works hunky-dory > until I add :stream tls to either or both of the imap mail-sources. > Everything works fine for a while, but eventually I get an error > with a backtrace that looks like this: > > --8<-- > Debugger entered--Lisp error: (error "Selecting deleted buffer") [Snip] > I really don't know how to debug this at all, so I'm hoping someone > can help me... I haven't been able to get any further with this since May. Surely there is someone who can at least give some advice on how to debug this? -- Big Gaute http://www.srcf.ucam.org/~gs234/ YOU!! Give me the CUTEST, PINKEST, most charming little VICTORIAN DOLLHOUSE you can find!! An make it SNAPPY!! ^ permalink raw reply [flat|nested] 25+ messages in thread
* Re: nnimap versus tls 2003-05-19 13:32 nnimap versus tls Gaute B Strokkenes 2003-07-02 23:46 ` Gaute B Strokkenes @ 2003-07-04 18:24 ` Kai Großjohann 2003-07-05 8:44 ` Gaute B Strokkenes 1 sibling, 1 reply; 25+ messages in thread From: Kai Großjohann @ 2003-07-04 18:24 UTC (permalink / raw) Gaute B Strokkenes <gs234@cam.ac.uk> writes: > --8<-- > Debugger entered--Lisp error: (error "Selecting deleted buffer") > imap-arrival-filter(#<process imap<1>> "* BYE kern.srcf.societies.cam.ac.uk IMAP4rev1 server terminating connection^M\n6 OK LOGOUT completed^M\n*** Received corrupted data(-9) - server has terminated the connection abnormally\n") > delete-process(#<process imap<2>>) It seems that Gnus isn't expecting the server to close the connection, err, unexpectedly. Or am I misinterpreting this? -- ~/.signature ^ permalink raw reply [flat|nested] 25+ messages in thread
* Re: nnimap versus tls 2003-07-04 18:24 ` Kai Großjohann @ 2003-07-05 8:44 ` Gaute B Strokkenes 2003-07-05 12:53 ` Kai Großjohann 0 siblings, 1 reply; 25+ messages in thread From: Gaute B Strokkenes @ 2003-07-05 8:44 UTC (permalink / raw) On 4 jul 2003, kai.grossjohann@gmx.net wrote: > Gaute B Strokkenes <gs234@cam.ac.uk> writes: > >> --8<-- Debugger entered--Lisp error: (error "Selecting deleted >> buffer") imap-arrival-filter(#<process imap<1>> "* BYE >> kern.srcf.societies.cam.ac.uk IMAP4rev1 server terminating >> connection^M\n6 OK LOGOUT completed^M\n*** Received corrupted >> data(-9) - server has terminated the connection abnormally\n") >> delete-process(#<process imap<2>>) > > It seems that Gnus isn't expecting the server to close the > connection, err, unexpectedly. > > Or am I misinterpreting this? I wouldn't know. This is a cut-and-past of the relevant portions of *imap-log*. I haven't changed anything, other than to replace my password with something else. Connecting to '131.111.179.82:993'... Resolving 'imap.srcf.ucam.org'... - Certificate type: X.509 - Certificate info: # Certificate is valid since: Wed Aug 14 14:17:00 BST 2002 # Certificate expires: Thu Aug 14 14:17:00 BST 2003 # Certificate fingerprint: 0e 51 8a 6b c3 e0 c3 bf d1 54 1e 1b af ab ac cf # Certificate serial number: 00 # Certificate version: #3 # Certificate public key algorithm: RSA # Modulus: 1024 bits # CN=imap.srcf.ucam.org,E=sysadmins@srcf.ucam.org,OU=Student-Run Computing Facility,O=University of Cambridge,L=Cambridge,ST=Cambridgeshire,C=UK # Certificate Issuer's info: # CN=imap.srcf.ucam.org,E=sysadmins@srcf.ucam.org,OU=Student-Run Computing Facility,O=University of Cambridge,L=Cambridge,ST=Cambridgeshire,C=UK - Peer's certificate is NOT trusted - Version: TLS 1.0 - Key Exchange: RSA - Cipher: ARCFOUR 128 - MAC: SHA - Compression: NULL - Handshake was completed - Simple Client Mode: * OK [CAPABILITY IMAP4REV1 X-NETSCAPE LOGIN-REFERRALS STARTTLS AUTH=LOGIN] localhost IMAP4rev1 2001.315 at Sat, 5 Jul 2003 09:22:10 +0100 (BST) 1 CAPABILITY * CAPABILITY IMAP4REV1 X-NETSCAPE NAMESPACE MAILBOX-REFERRALS SCAN SORT THREAD=REFERENCES THREAD=ORDEREDSUBJECT MULTIAPPEND LOGIN-REFERRALS STARTTLS AUTH=LOGIN 1 OK CAPABILITY completed 2 LOGIN "gs234" "I'm not telling you..." 2 OK [CAPABILITY IMAP4REV1 X-NETSCAPE NAMESPACE MAILBOX-REFERRALS SCAN SORT THREAD=REFERENCES THREAD=ORDEREDSUBJECT MULTIAPPEND] User gs234 authenticated 3 SELECT "INBOX" * 3 EXISTS * 0 RECENT * OK [UIDVALIDITY 1056494962] UID validity status * OK [UIDNEXT 43763] Predicted next UID * FLAGS (\Answered \Flagged \Deleted \Draft \Seen) * OK [PERMANENTFLAGS (\* \Answered \Flagged \Deleted \Draft \Seen)] Permanent flags 3 OK [READ-WRITE] SELECT completed 4 UID SEARCH UNSEEN UNDELETED * SEARCH 4 OK UID SEARCH completed 5 CLOSE 5 OK CLOSE completed 6 LOGOUT And this is what I get by setting debug-on-error to t: Debugger entered--Lisp error: (error "Selecting deleted buffer") imap-arrival-filter(#<process imap<1>> "* BYE kern.srcf.societies.cam.ac.uk IMAP4rev1 server terminating connection\r\n6 OK LOGOUT completed\r\n*** Received corrupted data(-9) - server has terminated the connection abnormally\n") By comparision, this is what I get in *imap-log* on one of those occasions when the error does not occur: [snip] 5 OK UID FETCH completed 6 UID STORE 43765 +FLAGS (\Deleted) * 4 FETCH (FLAGS (\Recent \Deleted) UID 43765) 6 OK UID STORE completed 7 CLOSE 7 OK CLOSE completed 8 LOGOUT * BYE kern.srcf.societies.cam.ac.uk IMAP4rev1 server terminating connection 8 OK LOGOUT completed *** Received corrupted data(-9) - server has terminated the connection abnormally Note the similarities here. It seems that the "*** Received corrupted data"... etc. is just gnutls complaining about the other end hanging up--but that is what it is supposed to do, given that we've gone through the normal IMAP logout sequence. So, the problem is that imap-arrival-filter and "Selecting deleted buffer", whatever that means. I do not at all know how this stuff works, but I see that imap-arrival-filter does a (with-current-buffer (process-buffer proc) ... So it seems that the process buffer dies unexpectedly. But my elisp skills are insufficiently 1337 to handle this. -- Big Gaute http://www.srcf.ucam.org/~gs234/ I want EARS! I want two ROUND BLACK EARS to make me feel warm 'n secure!! ^ permalink raw reply [flat|nested] 25+ messages in thread
* Re: nnimap versus tls 2003-07-05 8:44 ` Gaute B Strokkenes @ 2003-07-05 12:53 ` Kai Großjohann 2003-07-06 12:56 ` Gaute B Strokkenes 0 siblings, 1 reply; 25+ messages in thread From: Kai Großjohann @ 2003-07-05 12:53 UTC (permalink / raw) Gaute B Strokkenes <gs234@cam.ac.uk> writes: > And this is what I get by setting debug-on-error to t: > > Debugger entered--Lisp error: (error "Selecting deleted buffer") > imap-arrival-filter(#<process imap<1>> "* BYE kern.srcf.societies.cam.ac.uk IMAP4rev1 server terminating connection\n6 OK LOGOUT completed\n*** Received corrupted data(-9) - server has terminated the connection abnormally\n") Okay, imap.el was sending the LOGOUT command, so that explains why the connection was taken down. And I think you correctly diagnosed the "abnormally" part. There are only two places in imap.el where a buffer is killed. This happens when imap.el tries more than one stream to open a connection to the remote end. I wonder if that is the problem? Can you follow things on opening the connection to see if this is the cause? -- ~/.signature ^ permalink raw reply [flat|nested] 25+ messages in thread
* Re: nnimap versus tls 2003-07-05 12:53 ` Kai Großjohann @ 2003-07-06 12:56 ` Gaute B Strokkenes 2003-07-06 15:54 ` Kai Großjohann 0 siblings, 1 reply; 25+ messages in thread From: Gaute B Strokkenes @ 2003-07-06 12:56 UTC (permalink / raw) On 5 jul 2003, kai.grossjohann@gmx.net wrote: > There are only two places in imap.el where a buffer is killed. This > happens when imap.el tries more than one stream to open a connection > to the remote end. I wonder if that is the problem? Can you follow > things on opening the connection to see if this is the cause? I tried the following: Index: lisp/imap.el =================================================================== RCS file: /usr/local/cvsroot/gnus/lisp/imap.el,v retrieving revision 6.52 diff -u -r6.52 imap.el --- lisp/imap.el 20 Apr 2003 13:44:27 -0000 6.52 +++ lisp/imap.el 6 Jul 2003 12:34:36 -0000 @@ -995,12 +995,14 @@ (if (null (let ((imap-stream stream)) (imap-open-1 (current-buffer)))) (progn + (message "kb1: killing buffer `%s'" (current-buffer)) (kill-buffer (current-buffer)) (message "imap: Reconnecting with stream `%s'...failed" stream)) ;; We're done, kill the first connection (imap-close buffer) + (message "kb2: killing buffer `%s'" buffer) (kill-buffer buffer) (rename-buffer buffer) (message "imap: Reconnecting with stream `%s'...done" @@ -1739,6 +1741,7 @@ tag))) (defun imap-wait-for-tag (tag &optional buffer) + (message "imap: waiting for tag `%s'" tag) (with-current-buffer (or buffer (current-buffer)) (let (imap-have-messaged) (while (and (null imap-continuation) @@ -1758,9 +1761,11 @@ (message "")) (and (memq (process-status imap-process) '(open run)) (or (assq tag imap-failed-tags) - (if imap-continuation - 'INCOMPLETE - 'OK)))))) + (progn + (message "imap: done waiting for tag `%s'" tag) + (if imap-continuation + 'INCOMPLETE + 'OK))))))) (defun imap-sentinel (process string) (delete-process process)) @@ -1780,6 +1785,9 @@ (defun imap-arrival-filter (proc string) "IMAP process filter." + (message "IAF: trying to grab buffer `%s', proc `%s'" + (process-buffer proc) + proc) (with-current-buffer (process-buffer proc) (goto-char (point-max)) (insert string) I set message-log-max to an insanely large number and waited for the bug to trigger. However, no such message appears in the *Message* buffer. Reading active file via nnml... nnml: Reading incoming mail from imap... imap: Connecting to imap.srcf.ucam.org... Opening TLS connection to `imap.srcf.ucam.org'... Opening TLS connection with `gnutls-cli -p %p %h'...done Opening TLS connection to `imap.srcf.ucam.org'...done Waiting for response from imap.srcf.ucam.org...done imap: waiting for tag `1' imap: done waiting for tag `1' imap: Authenticating to `imap.srcf.ucam.org' using `login'... imap: Plaintext authentication... imap: waiting for tag `2' imap: done waiting for tag `2' imap: Authenticating to `imap.srcf.ucam.org' using `login'...done imap: waiting for tag `3' imap: done waiting for tag `3' imap: waiting for tag `4' imap: done waiting for tag `4' imap: waiting for tag `5' imap: done waiting for tag `5' imap: waiting for tag `6' Notice how we never get "done waiting for tag `6'" nnml: Reading incoming mail from file... nnml: Reading incoming mail (no new mail)...done Reading active file via nnml...done Reading active file from news.gmane.org via nntp... Opening nntp server on news.gmane.org...done Reading active file from archive via nnfolder...done Checking new news...done (No changes need to be saved) IAF: trying to grab buffer `#<killed buffer>', proc `imap<1>' Loading debug...done Entering debugger... [2 times] Mark set [3 times] Having thought about this for a bit, I suspect that this is some sort of timing problem. I think that when gnus sends the LOGOUT command it does not hang around and wait for the server to say goodbye, but closes the connection of its own accord. If gnus kills the connection by first killing (process-buffer proc) and _then_ removes the process proper (and the filter, imap-arrival-filter) then the possibility exists that the final bit of chit-chat from the imap server ends up being processed after the buffer has been killed, but before the filter has been removed. This would cause the filter to throw an error, like we see. The timing dependence would also account for the intermittent nature of this bug. Now, looking at the above it seems that the filter does not get to process anything until after all the other processing that happens when I hit `g' in the group buffer is done. I can imagine one slight complication here--I have more than one imap process running. That is, I keep most of my mail on a secondary nnimap server, in addition to which I use an imap mail-source (well, actually I use fetchmail ATM but I would like to use gnus) to get mail from another account (which I use for mailing lists and such). I have explicitly set the imap mail-source to use :stream tls, but I have not done this for the nnimap server. Moreover, when I comment out the imap mail-source and set the nnimap server to :stream tls I find it difficult to reproduce this bug. Thus, one possible twist on my hypothesis could be that imap.el, when handling my nnimap server, accidentally deletes a buffer that pertains to my imap mail-source. I don't know how the emacs process stuff works, and I don't really understand how imap.el works either. Unfortunately. One other thing I should mention is that I do not seem to meet with succes when I try to use (message "foo") to print debugging messages in imap-arrival-filter; I'm _sure_ I see message flicker onto my screen, but I cannot find them in the *Message* buffer afterwards. Possibly this is just more magick that I am not familiar with. -- Gaute Strokkenes http://www.srcf.ucam.org/~gs234/ I can't decide which WRONG TURN to make first!! I wonder if BOB GUCCIONE has these problems! ^ permalink raw reply [flat|nested] 25+ messages in thread
* Re: nnimap versus tls 2003-07-06 12:56 ` Gaute B Strokkenes @ 2003-07-06 15:54 ` Kai Großjohann 2003-07-06 21:53 ` Gaute B Strokkenes 0 siblings, 1 reply; 25+ messages in thread From: Kai Großjohann @ 2003-07-06 15:54 UTC (permalink / raw) Gaute B Strokkenes <gs234@cam.ac.uk> writes: > Having thought about this for a bit, I suspect that this is some sort > of timing problem. I think that when gnus sends the LOGOUT command it > does not hang around and wait for the server to say goodbye, but > closes the connection of its own accord. If gnus kills the connection > by first killing (process-buffer proc) and _then_ removes the process > proper (and the filter, imap-arrival-filter) then the possibility > exists that the final bit of chit-chat from the imap server ends up > being processed after the buffer has been killed, but before the > filter has been removed. This would cause the filter to throw an > error, like we see. The timing dependence would also account for the > intermittent nature of this bug. Very good analysis, IMHO. There are two instances of (imap-send-command "LOGOUT") in imap.el -- should they be (imap-send-command-wait "LOGOUT") instead? Do you want to try to see if that helps? -- ~/.signature ^ permalink raw reply [flat|nested] 25+ messages in thread
* Re: nnimap versus tls 2003-07-06 15:54 ` Kai Großjohann @ 2003-07-06 21:53 ` Gaute B Strokkenes 2003-07-07 6:08 ` Kai Großjohann 0 siblings, 1 reply; 25+ messages in thread From: Gaute B Strokkenes @ 2003-07-06 21:53 UTC (permalink / raw) On 6 jul 2003, kai.grossjohann@gmx.net wrote: > Gaute B Strokkenes <gs234@cam.ac.uk> writes: > >> Having thought about this for a bit, I suspect that this is some >> sort of timing problem. I think that when gnus sends the LOGOUT >> command it does not hang around and wait for the server to say >> goodbye, but closes the connection of its own accord. If gnus >> kills the connection by first killing (process-buffer proc) and >> _then_ removes the process proper (and the filter, >> imap-arrival-filter) then the possibility exists that the final bit >> of chit-chat from the imap server ends up being processed after the >> buffer has been killed, but before the filter has been removed. >> This would cause the filter to throw an error, like we see. The >> timing dependence would also account for the intermittent nature of >> this bug. > > Very good analysis, IMHO. There are two instances of > (imap-send-command "LOGOUT") in imap.el -- should they be > (imap-send-command-wait "LOGOUT") instead? > > Do you want to try to see if that helps? I looked at that, but it seems like a dead end. Those instances are only called when trying/failing to use other streams. However, I added lots of debugging goop to imap.el: Index: imap.el =================================================================== RCS file: /usr/local/cvsroot/gnus/lisp/imap.el,v retrieving revision 6.52 diff -u -r6.52 imap.el --- imap.el 20 Apr 2003 13:44:27 -0000 6.52 +++ imap.el 6 Jul 2003 21:39:57 -0000 @@ -136,6 +136,14 @@ ;;; Code: +(defun gs234-debug (str) + (with-current-buffer (get-buffer-create imap-log-buffer) + (imap-disable-multibyte) + (buffer-disable-undo) + (goto-char (point-max)) + (insert str) + (insert "\n"))) + (eval-when-compile (require 'cl)) (eval-and-compile (autoload 'base64-decode-string "base64") @@ -529,7 +537,10 @@ (not (string-match "failed" response)))) (setq done process) (if (memq (process-status process) '(open run)) - (imap-send-command "LOGOUT")) + (progn + (gs234-debug (format "async close!")) + (imap-send-command "LOGOUT"))) +; (imap-send-command-wait "LOGOUT"))) (delete-process process) nil))))) done)) @@ -593,7 +604,10 @@ (not (string-match "failed" response)))) (setq done process) (if (memq (process-status process) '(open run)) - (imap-send-command "LOGOUT")) + (progn + (gs234-debug "async close!") + (imap-send-command "LOGOUT"))) +; (imap-send-command-wait "LOGOUT"))) (delete-process process) nil))))) done)) @@ -995,12 +1009,15 @@ (if (null (let ((imap-stream stream)) (imap-open-1 (current-buffer)))) (progn + (gs234-debug (format "kb1: killing buffer `%s'" + (current-buffer))) (kill-buffer (current-buffer)) (message "imap: Reconnecting with stream `%s'...failed" stream)) ;; We're done, kill the first connection (imap-close buffer) + (gs234-debug (format "kb2: killing buffer `%s'" buffer)) (kill-buffer buffer) (rename-buffer buffer) (message "imap: Reconnecting with stream `%s'...done" @@ -1071,10 +1088,15 @@ (with-current-buffer (or buffer (current-buffer)) (when (imap-opened) (condition-case nil - (imap-send-command-wait "LOGOUT") + (progn + (gs234-debug "imap: closing...") + (imap-send-command-wait "LOGOUT") + (gs234-debug "imap: ...closing now done")) (quit nil))) (when (and imap-process (memq (process-status imap-process) '(open run))) + (gs234-debug (format "imap: post-closure deletion of process `%s'" + imap-process)) (delete-process imap-process)) (setq imap-current-mailbox nil imap-current-message nil @@ -1739,11 +1761,16 @@ tag))) (defun imap-wait-for-tag (tag &optional buffer) +; (message "imap: waiting for tag `%s'" tag) (with-current-buffer (or buffer (current-buffer)) + (gs234-debug (format "imap: START wait for tag `%s'" tag)) + (gs234-debug (format "imap: imap-reached-tag is already: `%s'" + imap-reached-tag)) (let (imap-have-messaged) (while (and (null imap-continuation) (memq (process-status imap-process) '(open run)) (< imap-reached-tag tag)) + (gs234-debug "imap: going through body of loop") (let ((len (/ (point-max) 1024)) message-log-max) (unless (< len 10) @@ -1756,11 +1783,17 @@ 1000))))) (when imap-have-messaged (message "")) + (gs234-debug (format "imap: END wait for tag `%s'" tag)) + (gs234-debug (format "imap: imap-reached-tag is now: `%s'" imap-reached-tag)) + (gs234-debug (format "imap: imap-continuation is now: `%s'" imap-continuation)) + (gs234-debug (format "imap: (process-status imap-process) is now: `%s'" + (process-status imap-process))) (and (memq (process-status imap-process) '(open run)) (or (assq tag imap-failed-tags) - (if imap-continuation - 'INCOMPLETE - 'OK)))))) + (progn + (if imap-continuation + 'INCOMPLETE + 'OK))))))) (defun imap-sentinel (process string) (delete-process process)) @@ -1780,6 +1813,9 @@ (defun imap-arrival-filter (proc string) "IMAP process filter." + (gs234-debug (format "IAF: trying to grab buffer `%s', proc `%s'\n" + (process-buffer proc) + proc)) (with-current-buffer (process-buffer proc) (goto-char (point-max)) (insert string) @@ -1796,6 +1832,7 @@ (narrow-to-region (point-min) end) (delete-backward-char (length imap-server-eol)) (goto-char (point-min)) + (gs234-debug (format "IAF: imap-state is `%s'" imap-state)) (unwind-protect (cond ((eq imap-state 'initial) (imap-parse-greeting)) @@ -1803,6 +1840,7 @@ (eq imap-state 'nonauth) (eq imap-state 'selected) (eq imap-state 'examine)) + (gs234-debug "IAF: punting on imap-parse-response...") (imap-parse-response)) (t (message "Unknown state %s in arrival filter" A typical snippet from *imap-log* : imap: closing... 6 LOGOUT imap: START wait for tag `6' imap: imap-reached-tag is already: `5' imap: going through body of loop imap: going through body of loop imap: going through body of loop imap: going through body of loop imap: going through body of loop imap: going through body of loop imap: END wait for tag `6' imap: imap-reached-tag is now: `5' imap: imap-continuation is now: `nil' imap: (process-status imap-process) is now: `exit' imap: ...closing now done IAF: trying to grab buffer `#<killed buffer>', proc `imap<1>' I think the problem is that imap-wait-for-tag is not doing its job properly in all circumstances. Specifically looking at the loop in imap-wait-for-tag, we loop until we get the tag we're waiting for, or until (process-status imap-process) is neither 'run nor 'open (or imap-continuation is non-nil, whatever that is...). Inside the loop, we call accept-process-output to take care of business. I believe that what is going on is that in one iteration of the loop, we receive the server's last bit of output after accept-process-output has returned, but before we test the loop condition. That way, (process-status imap-process) will be 'exit; but there will still be output waiting for us that we haven't taken care of yet. Everything will appear to work swimmingly until Emacs is about to idle, and it checks for process output again. Or so I think. Unless I'm missing something, the documentation in the elisp manual is not too specific about the semantics of subprocesses... -- Gaute Strokkenes http://www.srcf.ucam.org/~gs234/ My BIOLOGICAL ALARM CLOCK just went off.. It has noiseless DOZE FUNCTION and full kitchen!! ^ permalink raw reply [flat|nested] 25+ messages in thread
* Re: nnimap versus tls 2003-07-06 21:53 ` Gaute B Strokkenes @ 2003-07-07 6:08 ` Kai Großjohann 2003-07-07 7:26 ` Gaute B Strokkenes 0 siblings, 1 reply; 25+ messages in thread From: Kai Großjohann @ 2003-07-07 6:08 UTC (permalink / raw) Gaute B Strokkenes <gs234@cam.ac.uk> writes: > I believe that what is going on is that in one iteration of the loop, > we receive the server's last bit of output after accept-process-output > has returned, but before we test the loop condition. That way, > (process-status imap-process) will be 'exit; but there will still be > output waiting for us that we haven't taken care of yet. Everything > will appear to work swimmingly until Emacs is about to idle, and it > checks for process output again. Okay, then another accept-process-output after the loop ought to take care of it. Right? Gnah. I feel so silly with this stupid kind of advice :-/ I wished I grokked this. -- ~/.signature ^ permalink raw reply [flat|nested] 25+ messages in thread
* Re: nnimap versus tls 2003-07-07 6:08 ` Kai Großjohann @ 2003-07-07 7:26 ` Gaute B Strokkenes 2003-07-07 9:46 ` Gaute B Strokkenes 0 siblings, 1 reply; 25+ messages in thread From: Gaute B Strokkenes @ 2003-07-07 7:26 UTC (permalink / raw) On 7 jul 2003, kai.grossjohann@gmx.net wrote: > Gaute B Strokkenes <gs234@cam.ac.uk> writes: > >> I believe that what is going on is that in one iteration of the >> loop, we receive the server's last bit of output after >> accept-process-output has returned, but before we test the loop >> condition. That way, (process-status imap-process) will be 'exit; >> but there will still be output waiting for us that we haven't taken >> care of yet. Everything will appear to work swimmingly until Emacs >> is about to idle, and it checks for process output again. > > Okay, then another accept-process-output after the loop ought to > take care of it. Right? > > Gnah. I feel so silly with this stupid kind of advice :-/ > I wished I grokked this. As do I. However, your advice seems to work. With the following imap-wait-for-tag: (defun imap-wait-for-tag (tag &optional buffer) ; (message "imap: waiting for tag `%s'" tag) (with-current-buffer (or buffer (current-buffer)) (gs234-debug (format "imap: START wait for tag `%s'" tag)) (gs234-debug (format "imap: imap-reached-tag is already: `%s'" imap-reached-tag)) (let (imap-have-messaged) (while (and (null imap-continuation) (memq (process-status imap-process) '(open run)) (< imap-reached-tag tag)) (gs234-debug "imap: going through body of loop") (let ((len (/ (point-max) 1024)) message-log-max) (unless (< len 10) (setq imap-have-messaged t) (message "imap read: %dk" len)) (accept-process-output imap-process (truncate imap-read-timeout) (truncate (* (- imap-read-timeout (truncate imap-read-timeout)) 1000))))) (when (and (null imap-continuation) (< imap-reached-tag tag)) (gs234-debug "imap: accepting a bit extra...") (accept-process-output imap-process (truncate imap-read-timeout) (truncate (* (- imap-read-timeout (truncate imap-read-timeout)) 1000))) (gs234-debug "imap: ...done accepting a bit extra")) (when imap-have-messaged (message "")) (gs234-debug (format "imap: END wait for tag `%s'" tag)) (gs234-debug (format "imap: imap-reached-tag is now: `%s'" imap-reached-tag)) (gs234-debug (format "imap: imap-continuation is now: `%s'" imap-continuation)) (gs234-debug (format "imap: (process-status imap-process) is now: `%s'" (process-status imap-process))) (and (memq (process-status imap-process) '(open run)) (or (assq tag imap-failed-tags) (progn (if imap-continuation 'INCOMPLETE 'OK))))))) I get: 6 LOGOUT imap: START wait for tag `6' imap: imap-reached-tag is already: `5' imap: going through body of loop imap: going through body of loop imap: going through body of loop imap: going through body of loop imap: going through body of loop imap: going through body of loop imap: going through body of loop imap: accepting a bit extra... IAF: trying to grab buffer ` *imap source*', proc `imap<1>' * BYE kern.srcf.societies.cam.ac.uk IMAP4rev1 server terminating connection 6 OK LOGOUT completed *** Received corrupted data(-9) - server has terminated the connection abnormally IAF: imap-state is `auth' IAF: punting on imap-parse-response... IAF: imap-state is `auth' IAF: punting on imap-parse-response... imap: ...done accepting a bit extra imap: END wait for tag `6' imap: imap-reached-tag is now: `6' imap: imap-continuation is now: `nil' imap: (process-status imap-process) is now: `exit' imap: ...closing now done So we seem to have guessed correctly at last. ^_^ I'll prepare a (nicer-looking) patch... -- Big Gaute http://www.srcf.ucam.org/~gs234/ Is something VIOLENT going to happen to a GARBAGE CAN? ^ permalink raw reply [flat|nested] 25+ messages in thread
* Re: nnimap versus tls 2003-07-07 7:26 ` Gaute B Strokkenes @ 2003-07-07 9:46 ` Gaute B Strokkenes 2003-07-07 15:35 ` Kai Großjohann 2003-07-07 15:38 ` Kai Großjohann 0 siblings, 2 replies; 25+ messages in thread From: Gaute B Strokkenes @ 2003-07-07 9:46 UTC (permalink / raw) On 7 jul 2003, gs234@cam.ac.uk wrote: > On 7 jul 2003, kai.grossjohann@gmx.net wrote: >> Gaute B Strokkenes <gs234@cam.ac.uk> writes: >> >>> I believe that what is going on is that in one iteration of the >>> loop, we receive the server's last bit of output after >>> accept-process-output has returned, but before we test the loop >>> condition. That way, (process-status imap-process) will be 'exit; >>> but there will still be output waiting for us that we haven't >>> taken care of yet. Everything will appear to work swimmingly >>> until Emacs is about to idle, and it checks for process output >>> again. >> >> Okay, then another accept-process-output after the loop ought to >> take care of it. Right? >> >> Gnah. I feel so silly with this stupid kind of advice :-/ >> I wished I grokked this. [snip] > So we seem to have guessed correctly at last. ^_^ > > I'll prepare a (nicer-looking) patch... Well, I now have _two_ patches. The first one is the stripped down version of what you've already seen: Index: imap.el =================================================================== RCS file: /usr/local/cvsroot/gnus/lisp/imap.el,v retrieving revision 6.52 diff -u -r6.52 imap.el --- imap.el 20 Apr 2003 13:44:27 -0000 6.52 +++ imap.el 7 Jul 2003 09:16:34 -0000 @@ -1754,6 +1754,13 @@ (truncate (* (- imap-read-timeout (truncate imap-read-timeout)) 1000))))) + (when (and (null imap-continuation) + (< imap-reached-tag tag)) + (accept-process-output imap-process + (truncate imap-read-timeout) + (truncate (* (- imap-read-timeout + (truncate imap-read-timeout)) + 1000)))) (when imap-have-messaged (message "")) (and (memq (process-status imap-process) '(open run)) Basically, if we quit the loop due to (process-status imap-process) no longer being open or run, then we do the accept-process-output thingie again. This isn't very pretty, but it's the minimally-intrusive, maximally safe fix. The other version: Index: imap.el =================================================================== RCS file: /usr/local/cvsroot/gnus/lisp/imap.el,v retrieving revision 6.52 diff -u -r6.52 imap.el --- imap.el 20 Apr 2003 13:44:27 -0000 6.52 +++ imap.el 7 Jul 2003 09:18:30 -0000 @@ -1740,15 +1740,19 @@ (defun imap-wait-for-tag (tag &optional buffer) (with-current-buffer (or buffer (current-buffer)) - (let (imap-have-messaged) + (let (imap-have-messaged + (imap-more-coming t)) (while (and (null imap-continuation) - (memq (process-status imap-process) '(open run)) + imap-more-coming +; (memq (process-status imap-process) '(open run)) (< imap-reached-tag tag)) (let ((len (/ (point-max) 1024)) message-log-max) (unless (< len 10) (setq imap-have-messaged t) (message "imap read: %dk" len)) + (setq imap-more-coming + (memq (process-status imap-process) '(open run))) (accept-process-output imap-process (truncate imap-read-timeout) (truncate (* (- imap-read-timeout The idea was to have a flag that tells us when there's no more data coming out of imap-process. By only updating the flag just before we do an accept-process-output, we ensure that we have always read all that there is to read before we stop. And this works. At least, half the time it does. The other half Gnus seems to hang while EXAMINE-ing my nnimap:mail/received folder. I can't quite figure out what's going wrong, since setting debug-on-quit to t and/or adding trivial debug code seems to cause the hang to go away. I vaguely suspect that this is some sort of bad timing/scheduling interaction between Emacs and gnutls-cli, but I have no idea how to test that hypothesis. In any case, I believe we've found the bug. I'll leave it to someone who understands what's going on to actually fix it... -- Gaute Strokkenes http://www.srcf.ucam.org/~gs234/ TAPPING? You POLITICIANS! Don't you realize that the END of the ``Wash Cycle'' is a TREASURED MOMENT for most people?! ^ permalink raw reply [flat|nested] 25+ messages in thread
* Re: nnimap versus tls 2003-07-07 9:46 ` Gaute B Strokkenes @ 2003-07-07 15:35 ` Kai Großjohann 2003-07-08 22:20 ` Gaute B Strokkenes 2003-07-07 15:38 ` Kai Großjohann 1 sibling, 1 reply; 25+ messages in thread From: Kai Großjohann @ 2003-07-07 15:35 UTC (permalink / raw) Gaute B Strokkenes <gs234@cam.ac.uk> writes: > (while (and (null imap-continuation) > - (memq (process-status imap-process) '(open run)) > + imap-more-coming > +; (memq (process-status imap-process) '(open run)) > (< imap-reached-tag tag)) > (let ((len (/ (point-max) 1024)) > message-log-max) > (unless (< len 10) > (setq imap-have-messaged t) > (message "imap read: %dk" len)) > + (setq imap-more-coming > + (memq (process-status imap-process) '(open run))) > (accept-process-output imap-process > (truncate imap-read-timeout) > (truncate (* (- imap-read-timeout Here is another idea: (setq imap-more-coming (or (memq (process-status imap-process) '(open run)) (accept-process-output ...))) This means that it will do one more round of the loop if it got some output last time -- accept-process-output returns non-nil iff some output was read from the process. But maybe it is better to just use the first, uglier, version: it makes it very clear what is happening, and thus people will not be confused. -- ~/.signature ^ permalink raw reply [flat|nested] 25+ messages in thread
* Re: nnimap versus tls 2003-07-07 15:35 ` Kai Großjohann @ 2003-07-08 22:20 ` Gaute B Strokkenes 2003-07-09 19:46 ` Kai Großjohann ` (2 more replies) 0 siblings, 3 replies; 25+ messages in thread From: Gaute B Strokkenes @ 2003-07-08 22:20 UTC (permalink / raw) On 7 jul 2003, kai.grossjohann@gmx.net wrote: > Gaute B Strokkenes <gs234@cam.ac.uk> writes: > >> (while (and (null imap-continuation) >> - (memq (process-status imap-process) '(open run)) >> + imap-more-coming >> +; (memq (process-status imap-process) '(open run)) >> (< imap-reached-tag tag)) >> (let ((len (/ (point-max) 1024)) >> message-log-max) >> (unless (< len 10) >> (setq imap-have-messaged t) >> (message "imap read: %dk" len)) >> + (setq imap-more-coming >> + (memq (process-status imap-process) '(open run))) >> (accept-process-output imap-process >> (truncate imap-read-timeout) >> (truncate (* (- imap-read-timeout > > Here is another idea: > > (setq imap-more-coming > (or (memq (process-status imap-process) '(open run)) > (accept-process-output ...))) > > This means that it will do one more round of the loop if it got some > output last time -- accept-process-output returns non-nil iff some > output was read from the process. Uhm, I don't quite see why that would help. Imaging that in one iteration we receive nothing before we timeout. Then we received the server's last gasp, and the status changes to exit. Then we will miss the last gasp. Granted it's a small window of opportunity, but so is the one that we're already looking at. > But maybe it is better to just use the first, uglier, version: it > makes it very clear what is happening, and thus people will not be > confused. Well, there was a problem with the prettier version--while it fixed the problem discussed, but seemed to cause another problem, where the imap connection would seemingly hang indefinitely. After much wailing, gnashing of teeth and debugging (running emacs and gnutls-cli under strace, modifying source to add debug output etc...) I determined that the problem seems to lie in gnutls-cli. I have solved this for the moment by using openssl instead. (I might try to debug gnutls-cli, but I am not in the mood right now.) However, the fix as it stands is not complete. Consider the following (parital) backtrace: Debugger entered--Lisp error: (error "Selecting deleted buffer") imap-arrival-filter(#<process imap<1>> "*** Received corrupted data(-9) - server has terminated the connection abnormally\n") delete-process(#<process imap<2>>) imap-close(#<buffer *imap source*>) See? gnutls-cli likes to spit out that line "*** Received corrupted"... after the connection is closed. If emacs (and thus imap-arrival-filter) receives that line separately from the previous one, then there is a chance that that lone line will still be awaiting processing after imap-close returns, and so we loose. Similarly openssl seems to like to write out "read:errno=0" when the connection goes down. I still think we should do the extra accept-process-output (it's obviously the correct thing to do) but this is not enough to protect us from imap-arrival-filter barfing. So I suggest that we do what the emacs lisp manual recommends and wrap the body of imap-arrival-filter in (when (process-buffer proc) ...). Index: lisp/imap.el =================================================================== RCS file: /usr/local/cvsroot/gnus/lisp/imap.el,v retrieving revision 6.53 diff -u -r6.53 imap.el --- lisp/imap.el 7 Jul 2003 18:44:13 -0000 6.53 +++ lisp/imap.el 8 Jul 2003 21:55:26 -0000 @@ -1754,15 +1754,13 @@ (truncate (* (- imap-read-timeout (truncate imap-read-timeout)) 1000))))) - ;; Maybe the process has died, but the remote end wants to send - ;; some more stuff. + ;; A process can die _before_ we have processed everything it + ;; has to say. Moreover, this can happen in between the call to + ;; accept-process-output and the call to process-status in an + ;; iteration of the loop above. (when (and (null imap-continuation) (< imap-reached-tag tag)) - (accept-process-output imap-process - (truncate imap-read-timeout) - (truncate (* (- imap-read-timeout - (truncate imap-read-timeout)) - 1000)))) + (accept-process-output imap-process 0 0)) (when imap-have-messaged (message "")) (and (memq (process-status imap-process) '(open run)) @@ -1789,34 +1787,35 @@ (defun imap-arrival-filter (proc string) "IMAP process filter." - (with-current-buffer (process-buffer proc) - (goto-char (point-max)) - (insert string) - (and imap-log - (with-current-buffer (get-buffer-create imap-log-buffer) - (imap-disable-multibyte) - (buffer-disable-undo) - (goto-char (point-max)) - (insert string))) - (let (end) - (goto-char (point-min)) - (while (setq end (imap-find-next-line)) - (save-restriction - (narrow-to-region (point-min) end) - (delete-backward-char (length imap-server-eol)) - (goto-char (point-min)) - (unwind-protect - (cond ((eq imap-state 'initial) - (imap-parse-greeting)) - ((or (eq imap-state 'auth) - (eq imap-state 'nonauth) - (eq imap-state 'selected) - (eq imap-state 'examine)) - (imap-parse-response)) - (t - (message "Unknown state %s in arrival filter" - imap-state))) - (delete-region (point-min) (point-max)))))))) + (when (process-buffer proc) + (with-current-buffer (process-buffer proc) + (goto-char (point-max)) + (insert string) + (and imap-log + (with-current-buffer (get-buffer-create imap-log-buffer) + (imap-disable-multibyte) + (buffer-disable-undo) + (goto-char (point-max)) + (insert string))) + (let (end) + (goto-char (point-min)) + (while (setq end (imap-find-next-line)) + (save-restriction + (narrow-to-region (point-min) end) + (delete-backward-char (length imap-server-eol)) + (goto-char (point-min)) + (unwind-protect + (cond ((eq imap-state 'initial) + (imap-parse-greeting)) + ((or (eq imap-state 'auth) + (eq imap-state 'nonauth) + (eq imap-state 'selected) + (eq imap-state 'examine)) + (imap-parse-response)) + (t + (message "Unknown state %s in arrival filter" + imap-state))) + (delete-region (point-min) (point-max))))))))) \f ;; Imap parser. However, I still feel uneasy about this. Switching to openssl seems to trip up the various corner cases I've been talking about a lot less; I suppose it might be more mature implementation and so causes much less surprises (gnutls-cli seems to like to write out individual lines at a time, for instance). A consequence of my switch is that I can't really test out this stuff. I think we really need to run this by someone who understands how this process stuff and imap.el works (is the original author still around?) and gain their approval. I think it's clear that you and I do not understand precisely how this is supposed to work. For instance, why does imap-arrival-filter run within delete-process? The elisp manual states that process output is only accepted when when emacs is polling for input, or when we explicitly ask for it. Here is describe-function has to say about delete-process: delete-process is a built-in function. (delete-process PROCESS) Delete PROCESS: kill it and forget about it immediately. PROCESS may be a process, a buffer, the name of a process or buffer, or nil, indicating the current buffer's process. I find this very unintuitive. Also, why do we get an error at all? The elisp manual says: If an error happens during execution of a filter function, it is caught automatically, so that it doesn't stop the execution of whatever program was running when the filter function was started. However, if `debug-on-error' is non-`nil', the error-catching is turned off. This makes it possible to use the Lisp debugger to debug the filter function. *Note Debugger::. So why does this error halt gnus? Granted I've been running with debug-on-error set to t most of the time while debugging this, but then why did I see this problem in the first place? (Maybe gnus does something special to catch errors when getting mail, (I'm thinking about that "do you want to continue" message that one gets), I do not know). -- Gaute Strokkenes http://www.srcf.ucam.org/~gs234/ Oh my GOD -- the SUN just fell into YANKEE STADIUM!! ^ permalink raw reply [flat|nested] 25+ messages in thread
* Re: nnimap versus tls 2003-07-08 22:20 ` Gaute B Strokkenes @ 2003-07-09 19:46 ` Kai Großjohann 2003-07-10 0:03 ` Gaute B Strokkenes 2003-07-09 19:52 ` Kai Großjohann 2003-07-10 7:49 ` Simon Josefsson 2 siblings, 1 reply; 25+ messages in thread From: Kai Großjohann @ 2003-07-09 19:46 UTC (permalink / raw) Gaute B Strokkenes <gs234@cam.ac.uk> writes: > However, the fix as it stands is not complete. Consider the following > (parital) backtrace: > > Debugger entered--Lisp error: (error "Selecting deleted buffer") > imap-arrival-filter(#<process imap<1>> "*** Received corrupted data(-9) - server has terminated the connection abnormally\n") > delete-process(#<process imap<2>>) > imap-close(#<buffer *imap source*>) > > See? gnutls-cli likes to spit out that line "*** Received > corrupted"... after the connection is closed. If emacs (and thus > imap-arrival-filter) receives that line separately from the previous > one, then there is a chance that that lone line will still be awaiting > processing after imap-close returns, and so we loose. Argh. What happens with (while (accept-process-output ...))? That means we keep reading stuff until it's enough. Probably you already tried it, though. -- ~/.signature ^ permalink raw reply [flat|nested] 25+ messages in thread
* Re: nnimap versus tls 2003-07-09 19:46 ` Kai Großjohann @ 2003-07-10 0:03 ` Gaute B Strokkenes 0 siblings, 0 replies; 25+ messages in thread From: Gaute B Strokkenes @ 2003-07-10 0:03 UTC (permalink / raw) On 9 jul 2003, kai.grossjohann@gmx.net wrote: > Gaute B Strokkenes <gs234@cam.ac.uk> writes: > >> However, the fix as it stands is not complete. Consider the >> following (parital) backtrace: >> >> Debugger entered--Lisp error: (error "Selecting deleted buffer") >> imap-arrival-filter(#<process imap<1>> "*** Received corrupted data(-9) - server has terminated the connection abnormally\n") >> delete-process(#<process imap<2>>) >> imap-close(#<buffer *imap source*>) >> >> See? gnutls-cli likes to spit out that line "*** Received >> corrupted"... after the connection is closed. If emacs (and thus >> imap-arrival-filter) receives that line separately from the >> previous one, then there is a chance that that lone line will still >> be awaiting processing after imap-close returns, and so we loose. > > Argh. What happens with (while (accept-process-output ...))? That > means we keep reading stuff until it's enough. The thing is, the a subprocess is allowed to give us its output in however small or large pieces that it feels like, timed in whatever fashion it fells like. gnutls-cli seems to like to feed us things line-by-line; thus the scenario is eminently possible: gnutls-cli feeds us "6 OK LOGOUT completed" we read "6 OK LOGOUT completed" with accept-process-output, which returns non-nil. Since it returned non-nil, we call accept-process-output again, which returns nil. gnutls-cli feeds us "*** Received corrupted data blah-blah", and then dies. We check (process-status imap-process) and find that it is dead, and so return immediately. Using such a loop would probably make the problem much less likely to occur, but it _could_ still happen. And anyway, since it's easy to do the right thing in all cases, there is no reason not do. > Probably you already tried it, though. -- Big Gaute http://www.srcf.ucam.org/~gs234/ I left my WALLET in the BATHROOM!! ^ permalink raw reply [flat|nested] 25+ messages in thread
* Re: nnimap versus tls 2003-07-08 22:20 ` Gaute B Strokkenes 2003-07-09 19:46 ` Kai Großjohann @ 2003-07-09 19:52 ` Kai Großjohann 2003-07-10 1:25 ` Gaute B Strokkenes 2003-07-10 7:49 ` Simon Josefsson 2 siblings, 1 reply; 25+ messages in thread From: Kai Großjohann @ 2003-07-09 19:52 UTC (permalink / raw) Gaute B Strokkenes <gs234@cam.ac.uk> writes: > However, I still feel uneasy about this. Switching to openssl seems > to trip up the various corner cases I've been talking about a lot > less; I suppose it might be more mature implementation and so causes > much less surprises (gnutls-cli seems to like to write out individual > lines at a time, for instance). A consequence of my switch is that I > can't really test out this stuff. Anyhoo. I committed this. Thanks for the good work! I'm sure somebody will see it, somewhen. -- ~/.signature ^ permalink raw reply [flat|nested] 25+ messages in thread
* Re: nnimap versus tls 2003-07-09 19:52 ` Kai Großjohann @ 2003-07-10 1:25 ` Gaute B Strokkenes 2003-07-10 7:24 ` Kai Großjohann 0 siblings, 1 reply; 25+ messages in thread From: Gaute B Strokkenes @ 2003-07-10 1:25 UTC (permalink / raw) On 9 jul 2003, kai.grossjohann@gmx.net wrote: > Gaute B Strokkenes <gs234@cam.ac.uk> writes: > >> However, I still feel uneasy about this. Switching to openssl >> seems to trip up the various corner cases I've been talking about a >> lot less; I suppose it might be more mature implementation and so >> causes much less surprises (gnutls-cli seems to like to write out >> individual lines at a time, for instance). A consequence of my >> switch is that I can't really test out this stuff. > > Anyhoo. I committed this. Thanks for the good work! > > I'm sure somebody will see it, somewhen. I feel stupid now. I just got the following backtrace: Debugger entered--Lisp error: (error "Selecting deleted buffer") imap-arrival-filter(#<process imap> "read:errno=0\n") (process-buffer proc) evaluates to #<killed buffer>. Which is to say, non-nil. Viz. the emacs manual: A filter function that writes the output into the buffer of the process should check whether the buffer is still alive. If it tries to insert into a dead buffer, it will get an error. The expression `(buffer-name (process-buffer PROCESS))' returns `nil' if the buffer is dead. So we need to change the `when' to `buffer-name'. -- Big Gaute http://www.srcf.ucam.org/~gs234/ I have seen these EGG EXTENDERS in my Supermarket.. .. I have read the INSTRUCTIONS... ^ permalink raw reply [flat|nested] 25+ messages in thread
* Re: nnimap versus tls 2003-07-10 1:25 ` Gaute B Strokkenes @ 2003-07-10 7:24 ` Kai Großjohann 2003-07-10 10:32 ` Gaute B Strokkenes 0 siblings, 1 reply; 25+ messages in thread From: Kai Großjohann @ 2003-07-10 7:24 UTC (permalink / raw) Gaute B Strokkenes <gs234@cam.ac.uk> writes: > So we need to change the `when' to `buffer-name'. That won't work, but saying (when (buffer-name (process-buffer...))...) ought to do the trick. Right? -- ~/.signature ^ permalink raw reply [flat|nested] 25+ messages in thread
* Re: nnimap versus tls 2003-07-10 7:24 ` Kai Großjohann @ 2003-07-10 10:32 ` Gaute B Strokkenes 0 siblings, 0 replies; 25+ messages in thread From: Gaute B Strokkenes @ 2003-07-10 10:32 UTC (permalink / raw) On 10 jul 2003, kai.grossjohann@gmx.net wrote: > Gaute B Strokkenes <gs234@cam.ac.uk> writes: > >> So we need to change the `when' to `buffer-name'. > > That won't work, but saying (when (buffer-name > (process-buffer...))...) ought to do the trick. Right? Argh. Yes, off course you're right. -- Big Gaute http://www.srcf.ucam.org/~gs234/ We are now enjoying total mutual interaction in an imaginary hot tub... ^ permalink raw reply [flat|nested] 25+ messages in thread
* Re: nnimap versus tls 2003-07-08 22:20 ` Gaute B Strokkenes 2003-07-09 19:46 ` Kai Großjohann 2003-07-09 19:52 ` Kai Großjohann @ 2003-07-10 7:49 ` Simon Josefsson 2003-07-10 11:42 ` Gaute B Strokkenes 2 siblings, 1 reply; 25+ messages in thread From: Simon Josefsson @ 2003-07-10 7:49 UTC (permalink / raw) Gaute B Strokkenes <gs234@cam.ac.uk> writes: > Debugger entered--Lisp error: (error "Selecting deleted buffer") > imap-arrival-filter(#<process imap<1>> "*** Received corrupted data(-9) - server has terminated the connection abnormally\n") > delete-process(#<process imap<2>>) > imap-close(#<buffer *imap source*>) > > See? gnutls-cli likes to spit out that line "*** Received > corrupted"... after the connection is closed. IMHO, gnutls-cli should print this to stderr instead of stdout. > Similarly openssl seems to like to write out "read:errno=0" when the > connection goes down. To stdout? When -quiet is used? Then I'd consider this a bug too, it should go to stderr. Of course, nnimap should not misbehave even when the tunnel application print junk to stderr, so your work and patches are still useful to have. Thanks. ^ permalink raw reply [flat|nested] 25+ messages in thread
* Re: nnimap versus tls 2003-07-10 7:49 ` Simon Josefsson @ 2003-07-10 11:42 ` Gaute B Strokkenes 2003-07-10 12:13 ` Simon Josefsson 0 siblings, 1 reply; 25+ messages in thread From: Gaute B Strokkenes @ 2003-07-10 11:42 UTC (permalink / raw) On 10 jul 2003, jas@extundo.com wrote: > Gaute B Strokkenes <gs234@cam.ac.uk> writes: > >> Debugger entered--Lisp error: (error "Selecting deleted buffer") >> imap-arrival-filter(#<process imap<1>> "*** Received corrupted >> data(-9) - server has terminated the connection abnormally\n") >> delete-process(#<process imap<2>>) imap-close(#<buffer *imap >> source*>) >> >> See? gnutls-cli likes to spit out that line "*** Received >> corrupted"... after the connection is closed. > > IMHO, gnutls-cli should print this to stderr instead of stdout. It does. It doesn't make a difference: the elisp manual states that stderr and stdout of subprocesses can't be separated without using shell redirection or something similar, and unless I misread the code, we do no such thing. >> Similarly openssl seems to like to write out "read:errno=0" when >> the connection goes down. > > To stdout? When -quiet is used? Then I'd consider this a bug too, > it should go to stderr. It does go to stderr, but as above it makes no difference. > Of course, nnimap should not misbehave even when the tunnel > application print junk to stderr, I'd like to point out that this is not the only problem case that these patches correct. There was a race in imap-wait-for-tag, in which if the process dies we would not necessarily process everything it output. This lead to a similar error, but with the tail end of the imapd's BYE response prepended to "*** Receved...". I fixed that by adding a final call to accept-process output, called only when imap-wait-for-tag ends its loop due to the process exiting. However, that didn't the problem of the server outputting extra junk--imap-wait-for-tag can return as soon as it gets all of the response to the LOGOUT command, leaving the junk unprocessed (if the timing is right.) Looking at imap.el, there are lots of places where 'run and 'close seem to be used synonymously as process statuses. I don't think that's quite correct--a network connection will remain open until you've read everything the other end has sent you, but a subprocess will not necessarily stay alive until you've read everything it has to say. (Or at least, that's the best estimation of the semantics that I can make based on my observations; the emacs lisp manual is annoyingly vague on this particular topic.) > so your work and patches are still useful to have. Thanks. -- Gaute Strokkenes http://www.srcf.ucam.org/~gs234/ You mean you don't want to watch WRESTLING from ATLANTA? ^ permalink raw reply [flat|nested] 25+ messages in thread
* Re: nnimap versus tls 2003-07-10 11:42 ` Gaute B Strokkenes @ 2003-07-10 12:13 ` Simon Josefsson 2003-07-10 13:16 ` Matthias Andree 0 siblings, 1 reply; 25+ messages in thread From: Simon Josefsson @ 2003-07-10 12:13 UTC (permalink / raw) Gaute B Strokkenes <gs234@cam.ac.uk> writes: >> IMHO, gnutls-cli should print this to stderr instead of stdout. > > It does. It doesn't make a difference: the elisp manual states that > stderr and stdout of subprocesses can't be separated without using > shell redirection or something similar, and unless I misread the code, > we do no such thing. Should we add a '2>/dev/null' to the imap-*-program variables then? On the other hand, we need the initial stuff (like 'Client authentication finished') to notice authentication status, and that is probably printed to stderr. Ouch. ^ permalink raw reply [flat|nested] 25+ messages in thread
* Re: nnimap versus tls 2003-07-10 12:13 ` Simon Josefsson @ 2003-07-10 13:16 ` Matthias Andree 0 siblings, 0 replies; 25+ messages in thread From: Matthias Andree @ 2003-07-10 13:16 UTC (permalink / raw) Simon Josefsson <jas@extundo.com> writes: > Gaute B Strokkenes <gs234@cam.ac.uk> writes: > >>> IMHO, gnutls-cli should print this to stderr instead of stdout. >> >> It does. It doesn't make a difference: the elisp manual states that >> stderr and stdout of subprocesses can't be separated without using >> shell redirection or something similar, and unless I misread the code, >> we do no such thing. > > Should we add a '2>/dev/null' to the imap-*-program variables then? Nope. /dev/null doesn't show up in debug or IMAP buffers, and the stderr output of these openssl or gnutls-cli or whatever stream encoders might give indispensable help what the user did wrong. > On the other hand, we need the initial stuff (like 'Client > authentication finished') to notice authentication status, and that is > probably printed to stderr. Ouch. See :-) -- Matthias Andree ^ permalink raw reply [flat|nested] 25+ messages in thread
* Re: nnimap versus tls 2003-07-07 9:46 ` Gaute B Strokkenes 2003-07-07 15:35 ` Kai Großjohann @ 2003-07-07 15:38 ` Kai Großjohann 2003-07-07 19:37 ` Gaute B Strokkenes 1 sibling, 1 reply; 25+ messages in thread From: Kai Großjohann @ 2003-07-07 15:38 UTC (permalink / raw) Gaute B Strokkenes <gs234@cam.ac.uk> writes: > Well, I now have _two_ patches. The first one is the stripped down > version of what you've already seen: Does it also work to set the timeout to 0 for the new accept-process-output? If it works, that would be nice. -- ~/.signature ^ permalink raw reply [flat|nested] 25+ messages in thread
* Re: nnimap versus tls 2003-07-07 15:38 ` Kai Großjohann @ 2003-07-07 19:37 ` Gaute B Strokkenes 0 siblings, 0 replies; 25+ messages in thread From: Gaute B Strokkenes @ 2003-07-07 19:37 UTC (permalink / raw) On 7 jul 2003, kai.grossjohann@gmx.net wrote: > Gaute B Strokkenes <gs234@cam.ac.uk> writes: > >> Well, I now have _two_ patches. The first one is the stripped down >> version of what you've already seen: > > Does it also work to set the timeout to 0 for the new > accept-process-output? If it works, that would be nice. Seems to work. I'm testing it now. -- Big Gaute http://www.srcf.ucam.org/~gs234/ Hey, wait a minute!! I want a divorce!!.. you're not Clint Eastwood!! ^ permalink raw reply [flat|nested] 25+ messages in thread
end of thread, other threads:[~2003-07-10 13:16 UTC | newest] Thread overview: 25+ messages (download: mbox.gz / follow: Atom feed) -- links below jump to the message on this page -- 2003-05-19 13:32 nnimap versus tls Gaute B Strokkenes 2003-07-02 23:46 ` Gaute B Strokkenes 2003-07-04 18:24 ` Kai Großjohann 2003-07-05 8:44 ` Gaute B Strokkenes 2003-07-05 12:53 ` Kai Großjohann 2003-07-06 12:56 ` Gaute B Strokkenes 2003-07-06 15:54 ` Kai Großjohann 2003-07-06 21:53 ` Gaute B Strokkenes 2003-07-07 6:08 ` Kai Großjohann 2003-07-07 7:26 ` Gaute B Strokkenes 2003-07-07 9:46 ` Gaute B Strokkenes 2003-07-07 15:35 ` Kai Großjohann 2003-07-08 22:20 ` Gaute B Strokkenes 2003-07-09 19:46 ` Kai Großjohann 2003-07-10 0:03 ` Gaute B Strokkenes 2003-07-09 19:52 ` Kai Großjohann 2003-07-10 1:25 ` Gaute B Strokkenes 2003-07-10 7:24 ` Kai Großjohann 2003-07-10 10:32 ` Gaute B Strokkenes 2003-07-10 7:49 ` Simon Josefsson 2003-07-10 11:42 ` Gaute B Strokkenes 2003-07-10 12:13 ` Simon Josefsson 2003-07-10 13:16 ` Matthias Andree 2003-07-07 15:38 ` Kai Großjohann 2003-07-07 19:37 ` Gaute B Strokkenes
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 NNTP newsgroup(s).