aio-libs / aiosmtpd

A reimplementation of the Python stdlib smtpd.py based on asyncio.
https://aiosmtpd.aio-libs.org
Apache License 2.0
319 stars 96 forks source link

1.4.4: TestTLSEnding.test_eof_received fails #365

Closed dvzrv closed 1 year ago

dvzrv commented 1 year ago

Hi! When trying to package 1.4.4 for Arch Linux I ran into issues with TestTLSEnding.test_eof_received:

=================================== FAILURES ===================================
_______________________ TestTLSEnding.test_eof_received ________________________

self = <aiosmtpd.tests.test_starttls.TestTLSEnding object at 0x7fb7dec8bb20>
tls_controller = <aiosmtpd.controller.Controller object at 0x7fb7deb21720>
client = <smtplib.SMTP object at 0x7fb7deb231f0>

    @handler_data(class_=EOFingHandler)
    def test_eof_received(self, tls_controller, client):
        # I don't like this. It's too intimately involved with the innards of the SMTP
        # class. But for the life of me, I can't figure out why coverage there fail
        # intermittently.
        #
        # I suspect it's a race condition, but with what, and how to prevent that from
        # happening, that's ... a mystery.

        # Entering portion of code where hang is possible (upon assertion fail), so
        # we must wrap with "try..finally".
        try:
            code, mesg = client.ehlo("example.com")
            assert code == 250
            resp = client.starttls()
            assert resp == S.S220_READY_TLS
            # Need this to make SMTP update its internal session variable
            code, mesg = client.ehlo("example.com")
            assert code == 250
            sess: Sess_ = tls_controller.smtpd.session
>           assert sess.ssl_context is not None
E           AttributeError: 'Session' object has no attribute 'ssl_context'

aiosmtpd/tests/test_starttls.py:232: AttributeError
------------------------------ Captured log setup ------------------------------
INFO     mail.log:smtp.py:407 Available AUTH mechanisms: LOGIN(builtin) PLAIN(builtin)
INFO     mail.log:smtp.py:519 Peer: ('::1', 50290, 0, 0)
INFO     mail.log:smtp.py:601 ('::1', 50290, 0, 0) handling connection
DEBUG    mail.log:smtp.py:587 ('::1', 50290, 0, 0) << b'220 hmbx Python SMTP 1.4.4'
INFO     mail.log:smtp.py:539 ('::1', 50290, 0, 0) EOF received
INFO     mail.log:smtp.py:746 ('::1', 50290, 0, 0) Connection lost during _handle_client()
INFO     mail.log:smtp.py:525 ('::1', 50290, 0, 0) connection lost
INFO     mail.log:smtp.py:407 Available AUTH mechanisms: LOGIN(builtin) PLAIN(builtin)
INFO     mail.log:smtp.py:519 Peer: ('::1', 50292, 0, 0)
INFO     mail.log:smtp.py:601 ('::1', 50292, 0, 0) handling connection
DEBUG    mail.log:smtp.py:587 ('::1', 50292, 0, 0) << b'220 hmbx Python SMTP 1.4.4'
------------------------------ Captured log call -------------------------------
DEBUG    mail.log:smtp.py:286 _handle_client readline: b'ehlo example.com\r\n'
INFO     mail.log:smtp.py:286 ('::1', 50292, 0, 0) >> b'ehlo example.com'
DEBUG    mail.log:smtp.py:587 ('::1', 50292, 0, 0) << b'250-hmbx'
DEBUG    mail.log:smtp.py:587 ('::1', 50292, 0, 0) << b'250-SIZE 33554432'
DEBUG    mail.log:smtp.py:587 ('::1', 50292, 0, 0) << b'250-SMTPUTF8'
DEBUG    mail.log:smtp.py:587 ('::1', 50292, 0, 0) << b'250-STARTTLS'
DEBUG    mail.log:smtp.py:587 ('::1', 50292, 0, 0) << b'250 HELP'
DEBUG    mail.log:smtp.py:286 _handle_client readline: b'STARTTLS\r\n'
INFO     mail.log:smtp.py:286 ('::1', 50292, 0, 0) >> b'STARTTLS'
DEBUG    mail.log:smtp.py:587 ('::1', 50292, 0, 0) << b'220 Ready to start TLS'
DEBUG    mail.log:smtp.py:286 _handle_client readline: b'ehlo example.com\r\n'
INFO     mail.log:smtp.py:286 ('::1', 50292, 0, 0) >> b'ehlo example.com'
DEBUG    mail.log:smtp.py:587 ('::1', 50292, 0, 0) << b'250-hmbx'
DEBUG    mail.log:smtp.py:587 ('::1', 50292, 0, 0) << b'250-SIZE 33554432'
DEBUG    mail.log:smtp.py:587 ('::1', 50292, 0, 0) << b'250-SMTPUTF8'
DEBUG    mail.log:smtp.py:587 ('::1', 50292, 0, 0) << b'250-AUTH LOGIN PLAIN'
DEBUG    mail.log:smtp.py:587 ('::1', 50292, 0, 0) << b'250 HELP'
INFO     mail.log:smtp.py:746 ('::1', 50292, 0, 0) Connection lost during _handle_client()
=========================== short test summary info ============================
FAILED aiosmtpd/tests/test_starttls.py::TestTLSEnding::test_eof_received - At...
======================== 1 failed, 555 passed in 53.08s ========================

python-aiosmtpd-1.4.4-1-x86_64-build.log python-aiosmtpd-1.4.4-1-x86_64-check.log

This is a regression from 1.4.3, where the test does work!

pepoluan commented 1 year ago

Hmmm, strange...

Why didn't GitHub Actions catch that?

Everything runs successfully here: https://github.com/aio-libs/aiosmtpd/actions/runs/3938435294

But if I take a look at the code, indeed ssl_context should have been just ssl

I'll do some investigation on this.

pepoluan commented 1 year ago

Also to add: Since this affects only testing but does not affect usage, I will likely release a "post-release" version, e.g. 1.4.4.post1 rather than bumping it to 1.4.5.

pepoluan commented 1 year ago

SOLVED

Omigosh, apparently I made edits that I forgot to shelf before I create the release!

Totally my bad. I will release the 1.4.4.post1 today.

pepoluan commented 1 year ago

Okay, um, things happened accidentally.

So PyPI has 1.4.4.post1 currently. With fixed test. This one actually got released 'accidentally'.

I'll ... uh ... try to fix things in the proper way for 1.4.5