[stunnel-users] Stunnel 4.33 last one to work with VM & IMAP

Sun Dec 4 20:53:32 CET 2011

> [Michal Trojnara]
> On Tue, 29 Nov 2011 14:35:35 -0500, Drew McDermott wrote:
> > I am running VM 8.1, the Emacs mail reader, connecting via imap to
> > gmail.  It can be made to work with stunnel 4.33 providing the
> > encryption, but any version after that causes VM to choke when
> > fetching messages, generating the following error message:
> >
> > vm-imap-protocol-error: IMAP protocol error: "unexpected char (10)"
> 
> You may wish to investigate this solution:
> https://bugs.launchpad.net/ubuntu/+source/vm/+bug/321438

It doesn't seem to address my problem.

> Otherwise please send us stunnel logs and stunnel configuration files.

I have no stunnel configuration file.  What should go in it?

Before I could produce the logs, our sysadmin and Unix wizard, Mark
Wogahn, kindly did the experiment for me.  Here is the relevant part
of his note:

... Here is
some output from a failed connection, stunnel 4.35, and then a
successful connection, stunnel 4.33.

[Failed connection with 4.35 starts here]

11/30/11 2:34:13 PM	stunnel[24216]	LOG5[24216:140735081020608]:
Reading configuration from file
/var/folders/G5/G5qCNNmoFgyLcXq2c-9-9+++7nQ/-Tmp-/vm170612634
11/30/11 2:34:13 PM	stunnel[24216]	LOG5[24216:140735081020608]:
Configuration successful
11/30/11 2:34:13 PM	stunnel[24216]	LOG5[24216:140735081020608]:
Clients allowed=125
11/30/11 2:34:13 PM	stunnel[24216]	LOG5[24216:140735081020608]:
stunnel 4.35 on i386-apple-darwin10.8.0 with OpenSSL 1.0.0e 6 Sep 2011
11/30/11 2:34:13 PM	stunnel[24216]	LOG5[24216:140735081020608]:
Threading:PTHREAD SSL:ENGINE Sockets:SELECT,IPv6 Auth:LIBWRAP
11/30/11 2:34:13 PM	stunnel[24216]	LOG5[24216:140735081020608]:
connect_blocking: connected 74.125.45.109:993
11/30/11 2:34:13 PM	stunnel[24216]	LOG5[24216:140735081020608]:
Service stunnel connected remote server from 128.36.229.5:52251
11/30/11 2:34:13 PM	stunnel[24216]	LOG5[24216:140735081020608]: Error
detected on socket (read) file descriptor: Socket operation on
non-socket (38)
11/30/11 2:34:13 PM	stunnel[24216]	LOG5[24216:140735081020608]:
Connection reset: 0 bytes sent to SSL, 68 bytes sent to socket
11/30/11 2:34:27 PM	login[24217]	USER_PROCESS: 24217 ttys003

[Successful connection using 4.33 starts here]

11/30/11 2:40:23 PM	stunnel[24298]	LOG5[24298:140735081020608]:
Reading configuration from file
/var/folders/G5/G5qCNNmoFgyLcXq2c-9-9+++7nQ/-Tmp-/vm188660870
11/30/11 2:40:23 PM	stunnel[24298]	LOG5[24298:140735081020608]:
Configuration successful
11/30/11 2:40:23 PM	stunnel[24298]	LOG5[24298:140735081020608]:
Clients allowed=125
11/30/11 2:40:23 PM	stunnel[24298]	LOG5[24298:140735081020608]:
stunnel 4.33 on i386-apple-darwin10.8.0 with OpenSSL 0.9.8r 8 Feb 2011
11/30/11 2:40:23 PM	stunnel[24298]	LOG5[24298:140735081020608]:
Threading:PTHREAD SSL:ENGINE Sockets:SELECT,IPv6 Auth:LIBWRAP
11/30/11 2:40:23 PM	stunnel[24298]	LOG5[24298:140735081020608]:
connect_blocking: connected 74.125.65.108:993
11/30/11 2:40:23 PM	stunnel[24298]	LOG5[24298:140735081020608]:
Service stunnel connected remote server from 128.36.229.5:52277
11/30/11 2:40:23 PM	stunnel[24298]	LOG5[24298:140735081020608]:
Connection closed: 120 bytes sent to SSL, 1208 bytes sent to socket

<End of Wogahn message>

This and some other experiences have convinced me that the "unexpected
char (10)" bug is just the surface manifestation of the real problem,
which is for versions of stunnel after 4.33, (a) the process created
by VM to talk to the IMAP server is dying during the preliminary set
up phase for unknown reasons; and (b) when it dies, it produces output
that doesn't respect the Windows-newline convention VM expects.  The
"unexpected char" message masks the more serious generation of a
vm-imap-protocol-error with message "IMAP process xxx's buffer has
been killed," which would have been signalled if the characters hadn't
gotten in the way (I think).

I don't know how robust this bug is across different versions of VM,
and I don't know why a change in stunnel suddenly brought it out.
Even in version 4.33, the following kind of situation throws VM for a
loop: If I put the laptop to sleep by shutting its lid, when I later
come back to it if it doesn't wake up and reestablish communnication
with the mail server fast enough, the process dies as far as VM is
concerned, but what VM sees is the unexpected-character bug.  This is
especially annoying when traveling, and using those complimentary wifi
systems that require you to pledge not to do evil every time you
connect to them.  You have to remember, every time the computer wakes
from a sleep longer than a few minutes,  to create a new browser
window and click that you Agree to their terms and conditions.  
If you fail to do this, any software system the tries to connect to
the internet will spin its wheels endlessly.  Or get a timeout
exception, which in the case of VM becomes (you guessed it) an
unexpected-character-10 error.  VM will work, but you have to be
careful not to touch Emacs until you have visited the browser and
genuflected before the wifi lawyers.

I've tried some simple repairs of this bug, such as ignoring 10s or
treating them newlines, but that doesn't seem to work.  VM is
expecting a breakdown of the process it's talking to occur in a very
particular way, which seems awfully fussy of it.

                                             -- Drew McDermott
                                                Professor of Computer Science
                                                Yale Computer Science Department