RuntimeError after upgrading from 1.2.2 #244

gnugnug · 2021-02-08T10:05:23Z

After upgrading from version 1.2.2 to 1.2.4 we receive the following error when trying to start the controller:

Traceback (most recent call last):
  File "<stdin>", line 1, in <module>
  File "/usr/local/lib/python3.6/site-packages/aiosmtpd/controller.py", line 165, in start
    raise RuntimeError("Unknown Error, failed to init SMTP server")
RuntimeError: Unknown Error, failed to init SMTP server

This error can even be triggered by running the sample code from the documentation:

import asyncio
class ExampleHandler:
  async def handle_RCPT(self, server, session, envelope, address, rcpt_options):
    return '250 OK'

from aiosmtpd.controller import Controller
controller = Controller(ExampleHandler())
controller.start()

After executing "controller.start()" the RuntimeError from above appears.

Python version is 3.6.8
OS is Red Hat 7.9
aiosmtpd was installed with pip3. After downgrading via "sudo pip3 install aiosmtpd=1.2.2" everything works again and aiosmtpd receives and processes emails without problems.

The text was updated successfully, but these errors were encountered:

pepoluan · 2021-02-08T18:35:15Z

I've just released 1.3.0, can you try with that?

pepoluan · 2021-02-08T18:45:59Z

TBH I tried checking out 1.2.4 on Ubuntu 18.04, ran the code snippet you gave [simplification from the docs], and I couldn't replicate the error.

Asciinema Recording: https://asciinema.org/a/Fih5rZOm5QGlIboe4JWysSdSX

pepoluan · 2021-02-09T05:47:04Z

Update: I've just spun up a CentOS 7 instance, installed python3, created a new virtualenv, and also cannot replicate the error.

Asciinema Recording: https://asciinema.org/a/6k5vSAI4lX5oyOn2OiwRYZNdM

gnugnug · 2021-02-09T10:28:58Z

Thank you for the quick reply! I tried 1.3.0 but the problem remains:

$ sudo pip3 install aiosmtpd==1.3.0
WARNING: Running pip install with root privileges is generally not a good idea. Try `pip3 install --user` instead.
Collecting aiosmtpd==1.3.0
  Downloading https://mirror/api/pypi/pypi-remote/packages/packages/8b/41/0b7693c4509c9442cb1098c1c0c9d50effdad29e36323a5e611f20a28681/aiosmtpd-1.3.0.tar.gz (103kB)
    100% |████████████████████████████████| 112kB 5.5MB/s
Requirement already satisfied: atpublic in /usr/local/lib/python3.6/site-packages (from aiosmtpd==1.3.0)
Collecting attrs (from aiosmtpd==1.3.0)
  Downloading https://mirror/api/pypi/pypi-remote/packages/packages/c3/aa/cb45262569fcc047bf070b5de61813724d6726db83259222cd7b4c79821a/attrs-20.3.0-py2.py3-none-any.whl (49kB)
    100% |████████████████████████████████| 51kB 10.9MB/s
Requirement already satisfied: typing_extensions in /usr/local/lib/python3.6/site-packages (from atpublic->aiosmtpd==1.3.0)
Installing collected packages: attrs, aiosmtpd
  Found existing installation: aiosmtpd 1.2.2
    Uninstalling aiosmtpd-1.2.2:
      Successfully uninstalled aiosmtpd-1.2.2
  Running setup.py install for aiosmtpd ... done
Successfully installed aiosmtpd-1.3.0 attrs-20.3.0

$ python3
Python 3.6.8 (default, Aug 13 2020, 07:46:32)
[GCC 4.8.5 20150623 (Red Hat 4.8.5-39)] on linux
Type "help", "copyright", "credits" or "license" for more information.
>>> class ExampleHandler:
...   async def handle_RCPT(self, server, session, envelope, address, rcpt_options):
...     return "250 OK"
...
>>>
>>> from aiosmtpd.controller import Controller
>>> cont = Controller(ExampleHandler())
>>> cont.start()
Traceback (most recent call last):
  File "<stdin>", line 1, in <module>
  File "/usr/local/lib/python3.6/site-packages/aiosmtpd/controller.py", line 177, in start
    raise RuntimeError("Unknown Error, failed to init SMTP server")
RuntimeError: Unknown Error, failed to init SMTP server
>>>

I tried it on another Red Hat 7.9 server and there the same code works. Is there any way how I can find out what exactly is failing?

pepoluan · 2021-02-09T15:37:56Z

I tried it on another Red Hat 7.9 server and there the same code works.

Oookay, that's ... strange.

Is there any way how I can find out what exactly is failing?

The lines that raised that exception are these lines.

It's very hard to reach that line, as can be seen in the amount of acrobatics I have to do in the relevant test.

Because even if the factory() method returned None, the _factory_invoker() method should catch that and raise an Exception.

But I wonder ...

Can you try this:

from aiosmtpd.controller import Controller
from aiosmtpd.handlers import Sink
cont = Controller(Sink())
s1 = cont.factory()
print(repr(s1))
print(s1.hostname)

gnugnug · 2021-02-09T16:24:08Z

Ok I believe we get one step further. The following tests where performed with aiosmtpd==1.3.0:

Output of the code you requested to be run:

$ python3
Python 3.6.8 (default, Aug 13 2020, 07:46:32)
[GCC 4.8.5 20150623 (Red Hat 4.8.5-39)] on linux
Type "help", "copyright", "credits" or "license" for more information.
>>> from aiosmtpd.controller import Controller
>>> from aiosmtpd.handlers import Sink
>>> cont = Controller(Sink())
>>> s1 = cont.factory()
>>> print(repr(s1))
<aiosmtpd.smtp.SMTP object at 0x7fda740d0f28>
>>> print(s1.hostname)
myhostname...

Then I modified /usr/local/lib/python3.6/site-packages/aiosmtpd/controller.py and put some debug statements at the beginning of factory() and _factory_invoker().

>>> class ExampleHandler:
...   async def handle_RCPT(self, server, session, envelope, address, rcpt_options):
...     return "250 OK"
...
>>> from aiosmtpd.controller import Controller
>>> cont = Controller(ExampleHandler())
>>> cont.factory()
DEBUG: In factory()
<aiosmtpd.smtp.SMTP object at 0x7f7f56cf09b0>
>>> cont._factory_invoker()
DEBUG: In _factory_invoker()
DEBUG: In factory()
<aiosmtpd.smtp.SMTP object at 0x7f7f562d1e10>

As expected executing factory() returns its debug output, whereas executing _factory_invoker() calls both _factory_invoker() as well as factory().
However as you can see below when executing start(), neither the debug output at the beginning of factory() nor of _factory_invoker() appears. I can't tell if this is because _factory_invoker() never gets called, or if it runs asynchronously and its output doesn't reach STDOUT. But I know that if I run the same code on another server, I see the debug lines.

>>> class ExampleHandler:
...   async def handle_RCPT(self, server, session, envelope, address, rcpt_options):
...     return "250 OK"
...
>>> from aiosmtpd.controller import Controller
>>> cont = Controller(ExampleHandler())
>>> cont.start()
Traceback (most recent call last):
  File "<stdin>", line 1, in <module>
  File "/usr/local/lib/python3.6/site-packages/aiosmtpd/controller.py", line 181, in start
    raise RuntimeError("Unknown Error, failed to init SMTP server")
RuntimeError: Unknown Error, failed to init SMTP server
>>> # No DEBUG output seen

If I explicitely call _factory_invoker() first, then start() doesn't produce a RuntimeError:

>>> class ExampleHandler:
...   async def handle_RCPT(self, server, session, envelope, address, rcpt_options):
...     return "250 OK"
...
>>> from aiosmtpd.controller import Controller
>>> cont = Controller(ExampleHandler())
>>> cont._factory_invoker()
<aiosmtpd.smtp.SMTP object at 0x7f79b4ea3550>
>>> cont.start()
>>>

pepoluan · 2021-02-09T19:51:37Z

Interesting!

At first glance, it seems that on the failing machine, Python's threading library works differently.

Yet your last experiment, in which you "pre-initialize" the SMTP object (because that's what _factory_invoker() actually do), threading works!

For some reasons, the spawned thread seems to be unable to write back to the main thread, and that's why cont.smtpd in the main thread remained None ...

Hmm... I don't have a quick answer for this. Please allow me some time to study this interesting situation.

PS: This "unable to modify main thread's behavior" totally reminds me of how multiprocessing behaves. Not trying to hint about anything, just something that popped into my mind and mildly interesting enough to share....

gnugnug · 2021-02-11T09:31:57Z

Unfortunately I don't know enough about Pythons threading to debug this alone.
I added time.sleep(3) to run() before the self.smtpd == None check, but the RuntimeError still appeared. So it doesn't seem to be a timing issue.

pepoluan · 2021-02-12T08:36:18Z

Unfortunately I don't know enough about Pythons threading to debug this alone.
I added time.sleep(3) to run() before the self.smtpd == None check, but the RuntimeError still appeared. So it doesn't seem to be a timing issue.

I suddenly have an inspiration:

Within the Controller.run() method, right after this block:

        if self._thread_exception is not None:  # pragma: on-wsl
            # See comment about WSL1.0 in the _run() method
            assert self._thread is not None  # Stupid LGTM.com; see github/codeql#4918
            raise self._thread_exception

can you insert the lines:

        if not ready_event.is_set():
            raise RuntimeError("Server not ready within alotted time.")

(The if statement of the inserted line must be on the same indentation level as the if statement on if self._thread_exception)

It won't fix the problem, but at least we'll get another control point to observe the behavior. If a RuntimeError gets raised there, we can narrow down the problem.

Inspired by aio-libs#244

gnugnug · 2021-02-15T10:13:34Z

Hello @pepoluan
I added the following lines inside of Controller.start()

        if not ready_event.is_set():
            raise RuntimeError("Server not ready within alotted time.")
        print("checkpoint")

This resulted in the following output:

>>> class ExampleHandler:
...   async def handle_RCPT(self, server, session, envelope, address, rcpt_options):
...     return "250 OK"
...
>>>
>>> from aiosmtpd.controller import Controller
>>> cont = Controller(ExampleHandler())
>>> cont.start()
checkpoint
Traceback (most recent call last):
  File "<stdin>", line 1, in <module>
  File "/usr/local/lib/python3.6/site-packages/aiosmtpd/controller.py", line 180, in start
    raise RuntimeError("Unknown Error, failed to init SMTP server")
RuntimeError: Unknown Error, failed to init SMTP server

So unfortunately still the same error.

pepoluan · 2021-02-15T17:24:55Z

Okay, so at least we know it was not caused by timeout.

Let's add another check point.

In the middle of these lines:

        try:
            self._testconn()
        except Exception:
            # We totally don't care of exceptions experienced by _testconn,
            # which _will_ happen if factory() experienced problems.
            pass
        if self._thread_exception is not None:
            raise self._thread_exception

Please add time.sleep(0.2) right before the test for self._thread_exception, so it looks like this:

        try:
            self._testconn()
        except Exception:
            # We totally don't care of exceptions experienced by _testconn,
            # which _will_ happen if factory() experienced problems.
            pass
        time.sleep(0.5)
        if self._thread_exception is not None:
            raise self._thread_exception

We try giving additional time for create_server to finish initialization.

Also inspired by aio-libs#244 We add another threading.Event to wait until _factory_invoker() completes. Plus a test case to test this timeout.

Version higher than 1.2.2 cause the server start to fail. See aio-libs/aiosmtpd#244 for more info.

gnugnug · 2021-02-16T09:01:28Z

Apparently someone else is running into the same issue, so at least it's not some messed up setting only on my servers.

I added the following to Controller.start(), which is very similar to what I tried in #244 (comment)

        try:
            self._testconn()
        except Exception:
            # We totally don't care of exceptions experienced by _testconn,
            # which _will_ happen if factory() experienced problems.
            pass
        time.sleep(0.5)
        print("checkpoint2")

However the output is unchanged:

>>> class ExampleHandler:
...   async def handle_RCPT(self, server, session, envelope, address, rcpt_options):
...     return "250 OK"
...
>>> from aiosmtpd.controller import Controller
>>> cont = Controller(ExampleHandler())
>>> cont.start()
checkpoint2
Traceback (most recent call last):
  File "<stdin>", line 1, in <module>
  File "/usr/local/lib/python3.6/site-packages/aiosmtpd/controller.py", line 180, in start
    raise RuntimeError("Unknown Error, failed to init SMTP server")
RuntimeError: Unknown Error, failed to init SMTP server

pepoluan · 2021-02-16T09:19:32Z

Apparently someone else is running into the same issue, so at least it's not some messed up setting only on my servers.

This is seriously strange. The test suite -- which does test the Controller lots of times -- never failed in lots of OSes. Windows, Ubuntu, OpenSUSE, FreeBSD ... they all pass with flying colors.

However the output is unchanged:

Okay let's replace the short-ish delay with a longer one. I'm more and more convinced that the problem lies between _factory_invoker and factory. I'd like you to do the following four changes:

At the end of Controller.__init__, add the line:

self._factory_invoked = threading.Event()  # earlier it was .Thread(), and that's a typo

At the end of Controller._factory_invoker, add the line:

finally:
    self._factory_invoked.set()

At the beginning of Controller.start, insert the line:

self._factory_invoked.clear()

Finally, replace the time.sleep(0.5) you added earlier with this one:

if not self._factory_invoked.wait(5.0):
    raise TimeoutError("SMTP server not responding within allotted time")

I have a feeling that now we'll see TimeoutError being raised.

gnugnug · 2021-02-16T11:19:03Z

I applied the diff at the end to /usr/local/lib/python3.6/site-packages/aiosmtpd/controller.py, but receive the error messages:

>>> cont.start()
Traceback (most recent call last):
  File "<stdin>", line 1, in <module>
  File "/usr/local/lib/python3.6/site-packages/aiosmtpd/controller.py", line 156, in start
    self._factory_invoked.clear()
AttributeError: 'Thread' object has no attribute 'clear'

or if I remove clear

>>> cont.start()
Traceback (most recent call last):
  File "<stdin>", line 1, in <module>
  File "/usr/local/lib/python3.6/site-packages/aiosmtpd/controller.py", line 177, in start
    if not self._factory_invoked.wait(5.0):
AttributeError: 'Thread' object has no attribute 'wait'

Diff:

@@ -84,6 +84,7 @@
         # It actually conflicts with SMTP class's default, but the reasoning is
         # discussed in the docs.
         self.SMTP_kwargs.setdefault("enable_SMTPUTF8", True)
+        self._factory_invoked = threading.Thread()

     def factory(self):
         """Allow subclasses to customize the handler/server creation."""
@@ -101,6 +102,8 @@
         except Exception as err:
             self._thread_exception = err
             return _FakeServer(self.loop)
+        finally:
+            self._factory_invoked.set()

     def _run(self, ready_event):
         asyncio.set_event_loop(self.loop)
@@ -150,6 +153,7 @@
             _ = s.recv(1024)

     def start(self):
+        self._factory_invoked.clear()
         assert self._thread is None, "SMTP daemon already running"
         ready_event = threading.Event()
         self._thread = threading.Thread(target=self._run, args=(ready_event,))
@@ -170,6 +174,8 @@
             # We totally don't care of exceptions experienced by _testconn,
             # which _will_ happen if factory() experienced problems.
             pass
+        if not self._factory_invoked.wait(5.0):
+            raise TimeoutError("SMTP server not responding within allotted time")
         if self._thread_exception is not None:
             raise self._thread_exception
         # Defensive

LeoVerto · 2021-02-16T15:55:29Z

Hey, someone else here!

I've been getting this issue with Python 3.9 in both alpine-based docker images and on my dev machine running Arch Linux, in both cases using a fresh virtualenv created by pipenv.

To reproduce this, clone my repository at this commit and replace line 90 in app.py with config = {} to avoid having to set all the config environment variables. Next run pipenv install and finally pipenv run python app.py to start the application.

pepoluan · 2021-02-16T17:38:55Z

I applied the diff at the end to /usr/local/lib/python3.6/site-packages/aiosmtpd/controller.py, but receive the error messages:
>>> cont.start()
Traceback (most recent call last):
  File "<stdin>", line 1, in <module>
  File "/usr/local/lib/python3.6/site-packages/aiosmtpd/controller.py", line 156, in start
    self._factory_invoked.clear()
AttributeError: 'Thread' object has no attribute 'clear'

Auuugh, that's a typo by me 😭

Sorry, should have been threading.Event() not threading. Thread()

Got a brainfreeze when typing that line...

pepoluan · 2021-02-16T17:41:04Z

Hey, someone else here!

I've been getting this issue with Python 3.9 in both alpine-based docker images and on my dev machine running Arch Linux, in both cases using a fresh virtualenv created by pipenv.

To reproduce this, clone my repository at this commit and replace line 90 in app.py with config = {} to avoid having to set all the config environment variables. Next run pipenv install and finally pipenv run python app.py to start the application.

Nice, hopefully we can nail what's going on. I'm cloning it right now...

pepoluan · 2021-02-16T19:05:29Z

OOOOKAY so, thanks to @LeoVerto I managed to nail down the problem (I think).

Try editing the controller.py file and do the following changes:

In _testconn(self), add the following lines before the with ExitStack line:

hostname = self.hostname or "localhost"
print(hostname) # Can delete this if everything works
In start(self) change the passtoraise` (there should be only one "pass" in that method)

Try doing the two above changes and tell me if it now works.

If this works, I'm going to push an urgent bugfix.

pepoluan · 2021-02-16T19:41:49Z

I suspect this is what happened:

% python
Python 3.6.9 (default, Jul 17 2020, 12:50:27)
[GCC 8.4.0] on linux
Type "help", "copyright", "credits" or "license" for more information.
>>> from aiosmtpd.controller import Controller
>>> from aiosmtpd.handlers import Sink
>>> cont = Controller(Sink())
>>> cont.start()
>>> cont.stop()
>>> cont = Controller(Sink(), hostname="")
>>> cont.start()
Traceback (most recent call last):
  File "<stdin>", line 1, in <module>
  File "/home/pepoluan/projects/aiosmtpd/aiosmtpd/controller.py", line 177, in start
    raise RuntimeError("Unknown Error, failed to init SMTP server")
RuntimeError: Unknown Error, failed to init SMTP server
>>> cont.stop()

pepoluan · 2021-02-17T04:40:11Z

v1.3.1 is marinating, to be released tomorrow.

Definitely will fix @LeoVerto 's issue.

Not sure if it will fix @gnugnug 's issue, but at least 1.3.1 has more control points that can give more visibility into what's going on.

gnugnug · 2021-02-17T13:10:54Z

Ok so here we go. Just for completeness I tried the suggestions from #244 (comment) again, this time with self._factory_invoked = threading.**Event**() and Controller.start() does now run into the TimeoutError

>>> cont.start()
Traceback (most recent call last):
  File "<stdin>", line 1, in <module>
  File "/usr/local/lib/python3.6/site-packages/aiosmtpd/controller.py", line 178, in start
    raise TimeoutError("SMTP server not responding within allotted time")
TimeoutError: SMTP server not responding within allotted time

But now it gets interesting: When changing pass to raise within Controller.start() and printing out the hostname I receive:

>>> class ExampleHandler:
...   async def handle_RCPT(self, server, session, envelope, address, rcpt_options):
...     return "250 OK"
...
>>> from aiosmtpd.controller import Controller
>>> cont = Controller(ExampleHandler())
>>> cont.start()
::1
Traceback (most recent call last):
  File "<stdin>", line 1, in <module>
  File "/usr/local/lib/python3.6/site-packages/aiosmtpd/controller.py", line 170, in start
    self._testconn()
  File "/usr/local/lib/python3.6/site-packages/aiosmtpd/controller.py", line 149, in _testconn
    s = stk.enter_context(create_connection((self.hostname, self.port), 1.0))
  File "/usr/lib64/python3.6/socket.py", line 724, in create_connection
    raise err
  File "/usr/lib64/python3.6/socket.py", line 708, in create_connection
    sock = socket(af, socktype, proto)
  File "/usr/lib64/python3.6/socket.py", line 144, in __init__
    _socket.socket.__init__(self, family, type, proto, fileno)
OSError: [Errno 97] Address family not supported by protocol

This doesn't fix the problem but shows the cause: The servers are not dual stack, ::1 is unknown to them.

And indeed the following doesn't produce an error anymore with aiosmtpd==1.3.0:

>>> cont = Controller(ExampleHandler(), hostname="0.0.0.0")
>>> cont.start()
>>>

Leaving out hostname or passing hostname="" both produce the dreaded RuntimeError.
However I don't understand why cont = Controller(ExampleHandler(), hostname="") works with version 1.2.2 on the same server and binds to 0.0.0.0:8025.

pepoluan · 2021-02-17T14:15:52Z

But now it gets interesting: When changing pass to raise within Controller.start() and printing out the hostname I receive:

>>> class ExampleHandler:
...   async def handle_RCPT(self, server, session, envelope, address, rcpt_options):
...     return "250 OK"
...
>>> from aiosmtpd.controller import Controller
>>> cont = Controller(ExampleHandler())
>>> cont.start()
::1
Traceback (most recent call last):
  File "<stdin>", line 1, in <module>
  File "/usr/local/lib/python3.6/site-packages/aiosmtpd/controller.py", line 170, in start
    self._testconn()
  File "/usr/local/lib/python3.6/site-packages/aiosmtpd/controller.py", line 149, in _testconn
    s = stk.enter_context(create_connection((self.hostname, self.port), 1.0))
  File "/usr/lib64/python3.6/socket.py", line 724, in create_connection
    raise err
  File "/usr/lib64/python3.6/socket.py", line 708, in create_connection
    sock = socket(af, socktype, proto)
  File "/usr/lib64/python3.6/socket.py", line 144, in __init__
    _socket.socket.__init__(self, family, type, proto, fileno)
OSError: [Errno 97] Address family not supported by protocol

This doesn't fix the problem but shows the cause: The servers are not dual stack, ::1 is unknown to them.

And indeed the following doesn't produce an error anymore with aiosmtpd==1.3.0:

>>> cont = Controller(ExampleHandler(), hostname="0.0.0.0")
>>> cont.start()
>>>

Awesome! So at least we found out what's going on, why SMTP was not initialized properly.

Or, to be more exact, why triggering SMTP does not work.

Leaving out hostname or passing hostname="" both produce the dreaded RuntimeError.
However I don't understand why cont = Controller(ExampleHandler(), hostname="") works with version 1.2.2 on the same server and binds to 0.0.0.0:8025.

Version 1.2.2 gave hostname & port only to asyncio.loop.create_server, which seems to have the superpower of translating "::1" into "127.0.0.1" (or similar).

Version 1.2.4 added the capability to detect if SMTP instantiation resulted in an error. And due to how asyncio.loop.create_server works, SMTP doesn't get instantiated until someone attempted to make a connection to the bound host:port. To do this, I use socket.create_connection which apparently is stricter w.r.t. address family (i.e., no automatic fallback to, say, "127.0.0.1").

Problem is, all my test systems are apparently dual-stack, so I did not caught this behavior, as socket.create_connection will happily try to connect to "::1"

Anyways, glad to figure out what's wrong with your experiment ... now I need to step back and do some deep thought + research on how to fully stomp out this issue...

#244) * Implement _factory_invoked Event * Suppress only socket.timeout exception Other exceptions should bubble up, no longer hidden * Enforce ready_timeout * Floatify AIOSMTPD_CONTROLLER_TIMEOUT value * Update docs & NEWS * Version bump * Add a smarter* way to determine localhost addr * Add test for hostname not specified

pepoluan · 2021-02-18T07:05:53Z

I will release v1.3.1 soon; waiting for GA to validate the squamerging to master

pepoluan · 2021-02-18T08:01:23Z

Hi @gnugnug & @LeoVerto , I've released 1.3.1 to PyPI.

Would be swell if you can verify it has fixed this issue.

gnugnug · 2021-02-18T15:37:08Z

Hello @pepoluan thank you very much! Looks very good, except that on my system the error 97 is thrown:

>>> from aiosmtpd.controller import Controller
>>> cont = Controller(ExampleHandler())
Traceback (most recent call last):
  File "<stdin>", line 1, in <module>
  File "/usr/local/lib/python3.6/site-packages/aiosmtpd/controller.py", line 107, in __init__
    self.hostname = get_localhost() if hostname is None else hostname
  File "/usr/local/lib/python3.6/site-packages/aiosmtpd/controller.py", line 41, in get_localhost
    with makesock(AF_INET6, SOCK_STREAM) as sock:
  File "/usr/lib64/python3.6/socket.py", line 144, in __init__
    _socket.socket.__init__(self, family, type, proto, fileno)
OSError: [Errno 97] Address family not supported by protocol

Errno 97 translates to errno.EAFNOSUPPORT, however get_localhost() is catching errno.EADDRNOTAVAIL. If I replace errno.EADDRNOTAVAIL with errno.EAFNOSUPPORT, version 1.3.1 works!

pepoluan · 2021-02-18T15:47:07Z

Hello @pepoluan thank you very much! Looks very good, except that on my system the error 97 is thrown:

>>> from aiosmtpd.controller import Controller
>>> cont = Controller(ExampleHandler())
Traceback (most recent call last):
  File "<stdin>", line 1, in <module>
  File "/usr/local/lib/python3.6/site-packages/aiosmtpd/controller.py", line 107, in __init__
    self.hostname = get_localhost() if hostname is None else hostname
  File "/usr/local/lib/python3.6/site-packages/aiosmtpd/controller.py", line 41, in get_localhost
    with makesock(AF_INET6, SOCK_STREAM) as sock:
  File "/usr/lib64/python3.6/socket.py", line 144, in __init__
    _socket.socket.__init__(self, family, type, proto, fileno)
OSError: [Errno 97] Address family not supported by protocol

Errno 97 translates to errno.EAFNOSUPPORT, however get_localhost() is catching errno.EADDRNOTAVAIL. If I replace errno.EADDRNOTAVAIL with errno.EAFNOSUPPORT, version 1.3.1 works!

Thanks!

Hmm... seems like different errors for different systems? I'll just change the == to in some_set, and push another bugfix tomorrow.

gnugnug · 2021-02-18T16:47:21Z

I never received errno 99 (EADDRNOTAVAIL). Only errno 97. Maybe in the environment of @LeoVerto errno 99 was seen?

pepoluan · 2021-02-18T17:14:51Z

I never received errno 99 (EADDRNOTAVAIL). Only errno 97. Maybe in the environment of @LeoVerto errno 99 was seen?

In my test system I got EADDRNOTAVAIL, that's why the equality test was against EADDRNOTAVAIL.

I've changed it so it's if e.errno in {EADDRNOTAVAIL, EAFNOSUPPORT}, so we'll be good any which way.

Edit: After some thinking, I think the difference is because on my test systems I disabled IPv6 using sysctl, so the IPv6 modules are still loaded in the kernel, hence EADDRNOTAVAIL ("you want IPv6 address? Sure I can give you that but I'm currently on vacation.") Your kernel probably didn't load the IPv6 module at all, thus EAFNOSUPPORT ("You want what? Nobody here provides what you want.")

LeoVerto · 2021-02-18T18:24:41Z

This has fixed the issue for me, thank you so much for the quick debugging and fix, @pepoluan!

msztolcman · 2021-03-05T13:07:46Z

Hello,
I have similar problem. My project msztolcman/sendria is using aiosmtpd to handle incoming smtp connections. It works fine with aiosmtps 1.2.2, but after upgrade to 1.4.1 I have:

% sendria --db db.sqlite -d -a
2021-03-05T12:36:02.487786Z no PID file specified; runnning in foreground
2021-03-05T12:36:02.487885Z starting Sendria               db=/Users/mysz/Projects/sendria/db.sqlite debug=enabled foreground=true pidfile=None
2021-03-05T12:36:02.491769Z DB initialized
2021-03-05T12:36:02.492011Z webhooks disabled
Traceback (most recent call last):
  File "/Users/mysz/Projects/sendria/.venv/bin/sendria", line 33, in <module>
    sys.exit(load_entry_point('sendria', 'console_scripts', 'sendria')())
  File "/Users/mysz/Projects/sendria/sendria/cli.py", line 296, in main
    run_sendria_servers(loop, args)
  File "/Users/mysz/Projects/sendria/sendria/cli.py", line 176, in run_sendria_servers
    smtp.run(args.smtp_ip, args.smtp_port, args.smtp_auth, args.smtp_ident, args.debug)
  File "/Users/mysz/Projects/sendria/sendria/smtp.py", line 69, in run
    controller.start()
  File "/Users/mysz/Projects/sendria/.venv/lib/python3.9/site-packages/aiosmtpd/controller.py", line 225, in start
    raise TimeoutError("SMTP server not responding within allotted time")
TimeoutError: SMTP server not responding within allotted time

% python --version
Python 3.9.1
% uname -s
Darwin

pepoluan · 2021-03-05T13:17:26Z

Hello,
I have similar problem. My project msztolcman/sendria is using aiosmtpd to handle incoming smtp connections. It works fine with aiosmtps 1.2.2, but after upgrade to 1.4.1 I have:

Hi, can you create a new issue instead of replying here?

That way we can actually track which issues have been fixed, and by which PR. Would go a long way towards ease of troubleshooting as we can bisect.

Because this seems to be caused by a different bug from the 1.3.x issues.

msztolcman · 2021-03-05T13:27:14Z

Hi, sure. I was thinking it can be similar one :)
New one opened.

pepoluan added a commit to pepoluan/aiosmtpd that referenced this issue Feb 12, 2021

Test newly-implemented TimeoutError

c08fac7

Inspired by aio-libs#244

pepoluan mentioned this issue Feb 12, 2021

Implement Unix Socket Controller #247

Merged

11 tasks

pepoluan added a commit to pepoluan/aiosmtpd that referenced this issue Feb 15, 2021

Wait until factory _is_ invoked

d757ebd

Also inspired by aio-libs#244 We add another threading.Event to wait until _factory_invoker() completes. Plus a test case to test this timeout.

LeoVerto added a commit to LeoVerto/email2signal that referenced this issue Feb 16, 2021

Pin aiosmtpd to latest working version

294fc9a

Version higher than 1.2.2 cause the server start to fail. See aio-libs/aiosmtpd#244 for more info.

pepoluan mentioned this issue Feb 17, 2021

Fix Controller Bug on hostname="" or IPv6 not available #248

Merged

9 tasks

pepoluan added bug pr-available labels Feb 17, 2021

pepoluan self-assigned this Feb 17, 2021

pepoluan closed this as completed in #248 Feb 18, 2021

pepoluan reopened this Feb 18, 2021

pepoluan mentioned this issue Feb 18, 2021

Fix ipv6 detection #250

Merged

11 tasks

pepoluan added this to the 1.3.post milestone Feb 19, 2021

pepoluan closed this as completed in #250 Feb 19, 2021

Astranox mentioned this issue Apr 3, 2023

FreeBSD jail raises OSError[errno.EPROTONOSUPPORT] in get_localhost() if IPv6 support is missing #373

Open

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

RuntimeError after upgrading from 1.2.2 #244

RuntimeError after upgrading from 1.2.2 #244

gnugnug commented Feb 8, 2021

pepoluan commented Feb 8, 2021

pepoluan commented Feb 8, 2021 •

edited

Loading

pepoluan commented Feb 9, 2021

gnugnug commented Feb 9, 2021

pepoluan commented Feb 9, 2021 •

edited

Loading

gnugnug commented Feb 9, 2021

pepoluan commented Feb 9, 2021 •

edited

Loading

gnugnug commented Feb 11, 2021

pepoluan commented Feb 12, 2021 •

edited

Loading

gnugnug commented Feb 15, 2021

pepoluan commented Feb 15, 2021 •

edited

Loading

gnugnug commented Feb 16, 2021

pepoluan commented Feb 16, 2021 •

edited

Loading

gnugnug commented Feb 16, 2021 •

edited

Loading

LeoVerto commented Feb 16, 2021 •

edited

Loading

pepoluan commented Feb 16, 2021

pepoluan commented Feb 16, 2021 •

edited

Loading

pepoluan commented Feb 16, 2021 •

edited

Loading

pepoluan commented Feb 16, 2021

pepoluan commented Feb 17, 2021

gnugnug commented Feb 17, 2021

pepoluan commented Feb 17, 2021

pepoluan commented Feb 18, 2021

pepoluan commented Feb 18, 2021

gnugnug commented Feb 18, 2021 •

edited

Loading

pepoluan commented Feb 18, 2021

gnugnug commented Feb 18, 2021

pepoluan commented Feb 18, 2021 •

edited

Loading

LeoVerto commented Feb 18, 2021

msztolcman commented Mar 5, 2021

pepoluan commented Mar 5, 2021 •

edited

Loading

msztolcman commented Mar 5, 2021

RuntimeError after upgrading from 1.2.2 #244

RuntimeError after upgrading from 1.2.2 #244

Comments

gnugnug commented Feb 8, 2021

pepoluan commented Feb 8, 2021

pepoluan commented Feb 8, 2021 • edited Loading

pepoluan commented Feb 9, 2021

gnugnug commented Feb 9, 2021

pepoluan commented Feb 9, 2021 • edited Loading

gnugnug commented Feb 9, 2021

pepoluan commented Feb 9, 2021 • edited Loading

gnugnug commented Feb 11, 2021

pepoluan commented Feb 12, 2021 • edited Loading

gnugnug commented Feb 15, 2021

pepoluan commented Feb 15, 2021 • edited Loading

gnugnug commented Feb 16, 2021

pepoluan commented Feb 16, 2021 • edited Loading

gnugnug commented Feb 16, 2021 • edited Loading

LeoVerto commented Feb 16, 2021 • edited Loading

pepoluan commented Feb 16, 2021

pepoluan commented Feb 16, 2021 • edited Loading

pepoluan commented Feb 16, 2021 • edited Loading

pepoluan commented Feb 16, 2021

pepoluan commented Feb 17, 2021

gnugnug commented Feb 17, 2021

pepoluan commented Feb 17, 2021

pepoluan commented Feb 18, 2021

pepoluan commented Feb 18, 2021

gnugnug commented Feb 18, 2021 • edited Loading

pepoluan commented Feb 18, 2021

gnugnug commented Feb 18, 2021

pepoluan commented Feb 18, 2021 • edited Loading

LeoVerto commented Feb 18, 2021

msztolcman commented Mar 5, 2021

pepoluan commented Mar 5, 2021 • edited Loading

msztolcman commented Mar 5, 2021

pepoluan commented Feb 8, 2021 •

edited

Loading

pepoluan commented Feb 9, 2021 •

edited

Loading

pepoluan commented Feb 9, 2021 •

edited

Loading

pepoluan commented Feb 12, 2021 •

edited

Loading

pepoluan commented Feb 15, 2021 •

edited

Loading

pepoluan commented Feb 16, 2021 •

edited

Loading

gnugnug commented Feb 16, 2021 •

edited

Loading

LeoVerto commented Feb 16, 2021 •

edited

Loading

pepoluan commented Feb 16, 2021 •

edited

Loading

pepoluan commented Feb 16, 2021 •

edited

Loading

gnugnug commented Feb 18, 2021 •

edited

Loading

pepoluan commented Feb 18, 2021 •

edited

Loading

pepoluan commented Mar 5, 2021 •

edited

Loading