ssl.SSLWantReadError not being handled

[GrantEdwards]

Any time I receive messages with a body longer than a few dozen bytes, I get a failure that looks like this (I've add a bit of extra info to the normal log messages in smtp_server.py):

2018-01-17 21:38:59,100 smtpfwd[2144]:    INFO: _accept_subprocess(): smtp connection accepted within subprocess: (<socket._socketobject object at 0x7f5acd080d00>, ('nnn.nnn.nnn.nnn', 33114)).
2018-01-17 21:38:59,138 smtpfwd[2144]:    INFO: _accept_subprocess(): starting asyncore within subprocess. map={10: <secure_smtpd.smtp_channel.SMTPChannel connected nnn.nnn.nnn.nnn:33114 at 0x7f5acd04f710>}
2018-01-17 21:38:59,342 smtpfwd[2144]:    INFO: login by [elided] OK
2018-01-17 21:38:59,458 smtpfwd[2144]:   ERROR: _accept_subprocess(): asyncore loop exited.

AFAICT, in this failure case my message handler is never being called at all.

How do I find out what the problem is?

Shorter messages seem to work fine and the log looks like this:

2018-01-17 21:23:10,748 smtpfwd[1804]:    INFO: _accept_subprocess(): starting asyncore within subprocess. map={9: <secure_smtpd.smtp_channel.SMTPChannel connected 209.85.223.176nnn.nnn.nnn.nnn:44329 at 0x7f2c4e795b90>}
2018-01-17 21:23:10,938 smtpfwd[1804]:    INFO: login by [elided] OK
[... status messages from my message handler ...]
2018-01-17 21:23:12,301 smtpfwd[1804]:    INFO: _accept_subprocess(): smtp channel terminated asyncore.

[GrantEdwards]

Sometimes, when running in the foreground, I seen an ssl read error message:

2018-01-17 22:34:42,501 smtpfwd[3659]:    INFO: _accept_subprocess(): smtp connection accepted within subprocess: (<socket._socketobject object at 0x7f6f220f9600>, ('nnn.nnn.nnn.nnn', 39846)).
2018-01-17 22:34:42,538 smtpfwd[3659]:    INFO: _accept_subprocess(): starting asyncore within subprocess. map={9: <secure_smtpd.smtp_channel.SMTPChannel connected nnn.nnn.nnn.nnn:39846 at 0x7f6f220b3bd8>}
2018-01-17 22:34:42,728 smtpfwd[3659]:    INFO: login by [elided] OK
error: uncaptured python exception, closing channel <secure_smtpd.smtp_channel.SMTPChannel connected nnn.nnn.nnn.nnn:39846 at 0x7f6f220b3bd8> (<class 'ssl.SSLWantReadError'>:The operation did not complete (read) (_ssl.c:1858) [/usr/lib64/python2.7/asynchat.py|handle_read|115] [/opt/smtpfwd/asyncore.py|recv|392] [/usr/lib64/python2.7/ssl.py|recv|766] [/usr/lib64/python2.7/ssl.py|read|653])
2018-01-17 22:34:42,844 smtpfwd[3659]:   ERROR: _accept_subprocess(): asyncore loop exited. map={}

[GrantEdwards]

FWIW, the client is a gmail server that's configured to deliver mail via an outside SMTP server (the one that I'm troubleshooting).

[GrantEdwards]

If I add a couple print statements to the asyncore loop() function's while loop, it seems to work a lot better. There are still some ssl.SSLWantReadError failures, but some of the messages that gmail has been repeatedly trying and failing to deliver have now been received successfully.

[GrantEdwards]

I don't see how you can expect asyncore/asynchat to work with a non-blocking ssl-wrapped socket when there is no handling for ssl.SSLWantReadError and ssl.SSLWantWriteError anywhere in either one.

A non-blocking ssl-wrapped socket may be indicated as readable via select/poll, but that doesn't mean there's actual user-data that can be read. If there isn't any user-data to be read, the recv() call may raise SSLWantReadError to indicate that there is no user-data and you must wait until the underlying socket again becomes readable then retry the recv() call. Likewise, a call to recv() may raise SSLWantWriteError to indicate that you should wait until the underlying socket is writable, then retry the recv() call. Calls to send() might also raise either exception and require retrying when the underlying socket has become readable or writable.

The converse case must also be handled: calls to select/poll may indicate that the socket is not readable even though there is user data available to be read by the recv() call.

[GrantEdwards]

I've spent a several hours studying asyncore/asynchat and have come to the conclusion that they were designed based on fundamental assumptions that are just not true for non-blocking ssl-wrapped sockets. Making them work with ssl would require replacing or wrapping quite a few methods in the asyncore dispatcher and would rely on knowing implementation details that users aren't supposed to depend on.

So I'm giving up on getting secure-smtpd's SSL support working and am instead relying on an external instance of stunnel to provide encryption support. It's a bit clumsy, but it works reliably.

Perhaps somebody more expert than I in the internals of asyncore or asynchat can figure it out...