classification
Title: smtplib is glitchy after receive server code 500
Type: crash Stage:
Components: email Versions: Python 3.7
process
Status: open Resolution:
Dependencies: Superseder:
Assigned To: Nosy List: barry, izomiac, pepoluan, r.david.murray
Priority: normal Keywords:

Created on 2020-11-29 05:30 by izomiac, last changed 2021-01-05 19:01 by izomiac.

Files
File name Uploaded Description Edit
debug output.txt izomiac, 2020-11-29 05:30 Connection logs
Messages (3)
msg382038 - (view) Author: izomiac (izomiac) Date: 2020-11-29 05:30
I use a custom e-mail server and noticed I wasn't getting e-mails from FreeNAS.  I tracked the bug down to Python's smtplib.  My home internet can't do outbound port 25, so I use a port forwarding script that I've since learned injects "PROXY TCP4 <client ip> <server ip> <client port> <server port>\r\n".  This isn't a basic SMTP command, so my server responds with "500 Syntax error, command unrecognized\r\n".  

The first glitch in smtplib is that it assumes the server has precognition and upon receiving the syntax error assumes that the *next* command smtplib sends is invalid.  This happens to be "ehlo". After assuming "ehlo" got an error it backs down to "helo".  My server didn't like clients to send two greetings so it responded with "503 Bad sequence of commands", but allowed the connection to proceed anyway after the mild scolding.  smtplib proceeds to issue a "mail FROM" command, then a "rset" command and disconnects in shame after reflecting upon its actions for a while.

So, I modified my server to be a bit more laid back and just accept two greetings.  smtplib proceeds to issue "mail FROM", "rcpt TO", and "data" commands before crashing (raising an "SMTPDataError" in the traceback).

I then modified my server to ignore "PROXY" commands rather than send a syntax error and everything worked perfectly.  I don't code in python, and obviously my SMTP server is a one-off creation, but I figured I ought to let you all know in case you want to make some improvements to smtplib to better follow the SMTP spec and not crash with a cryptic error message three commands later after receiving a non-fatal error message.
msg384373 - (view) Author: Pandu E POLUAN (pepoluan) * Date: 2021-01-05 08:03
The "problem" is that smtplib.SMTP does the following, in essence:

1. Open connection to server
2. Send EHLO
3. Read server response

The PROXY injection causes a response from the server, but the response gets "cached" in the incoming TCP buffer. The injection script likely does not consume this buffer, resulting in Step 3 above reading this "cached" response. 

So from the point of view of smtplib.SMTP, the "503" message arrives _after_ EHLO is sent, while in actuality the "503" arrives before EHLO is sent.

I suggest rewriting the port forwarding script so that it consumes the response from the server first before transferring to smtplib.SMTP
msg384426 - (view) Author: izomiac (izomiac) Date: 2021-01-05 19:01
I agree, it's my suspicion that the server's error message and python's outbound command are sent so close to each other that buffering ensures they disagree about the exact sequence of commands/responses.

As for my server, it was HAProxy doing the injection and I rewrote the server to both ignore PROXY commands and to listen on multiple ports so a proxy is not necessary. 

So this issue no longer exists for me, but I know that I'm not the only one who uses HAProxy to forward SMTP requests (residential ISPs block port 25), and Python was relatively unique in its intolerance of this behavior.  (Python uses lower case commands, which are easy to recognize on server logs to determine which clients are using it.)  It's certainly not a critical issue affecting thousands, but in my experience glitchy behavior is a good indicator that the code is buggy in general.  Plus, buffering errors scare me because there are so many potential security exploits associated with them (on top of being a pain to debug.)  But, yeah, this is more of a courtesy bug to let you know about a tricky glitch I encountered.
History
Date User Action Args
2021-01-05 19:01:17izomiacsetmessages: + msg384426
2021-01-05 08:03:18pepoluansetnosy: + pepoluan
messages: + msg384373
2020-11-29 05:30:35izomiaccreate