tox3 30s delay caused by DNSServiceCreateConnection on macos

[ssbarnea]

More than an year after #1735 was closed and locked, I was able to find what was causing it.

It happens on MacOS only when tox.ini file was modified, so if you run it again, it will not be affected by that undesired 30s delay, which is extremely annoying as it applies even for tox -l commands.

Here is the culprit from MacOS Console:

default	08:08:07.717039+0000	mDNSResponder	[R1351382] DNSServiceCreateConnection START PID[53961](python3.10)
default	08:08:07.717132+0000	mDNSResponder	[R1351383] DNSServiceQueryRecord(1D000, 0, <mask.hash: 'W4U2JyNMP4qPLaREUfA9Aw=='>, Addr) START PID[53961](python3.10)
default	08:08:07.717885+0000	mDNSResponder	[R1351384] DNSServiceQueryRecord(1D000, 0, <mask.hash: 'W4U2JyNMP4qPLaREUfA9Aw=='>, AAAA) START PID[53961](python3.10)
default	08:08:07.718398+0000	mDNSResponder	[R1351383] DNSServiceQueryRecord(1D000, 0, <mask.hash: 'AxiCO2kN2tb6f+xUNi2KVQ=='>, Addr) STOP PID[53961](python3.10)
default	08:08:07.718460+0000	mDNSResponder	[R1351384] DNSServiceQueryRecord(1D000, 0, <mask.hash: 'AxiCO2kN2tb6f+xUNi2KVQ=='>, AAAA) STOP PID[53961](python3.10)
default	08:08:07.719293+0000	mDNSResponder	[R1351385] DNSServiceQueryRecord(15000, 0, <mask.hash: 'BbGOo0pN8UoXPv6jtlO7tg=='>, PTR) START PID[53961](python3.10)
default	08:08:37.720264+0000	mDNSResponder	[R1351385] DNSServiceQueryRecord(15000, 0, <mask.hash: 'lubOf0RtXl5C9ERWs7ZGfQ=='>, PTR) STOP PID[53961](python3.10)
default	08:08:37.745626+0000	mDNSResponder	[R1351382] DNSServiceCreateConnection STOP PID[53961](python3.10)

I am not sure what is causing it. I should mention that I do have a full dual IPv4 and IPv6 connectivity on that machine, something that is still not very common. You current stack status can easily be verified with a site like https://ipv6-test.com/

Reference: https://bugs.python.org/issue35164

[ssbarnea]

After bit more debugging, I was able to find a way to enable the logging of the effective dns queries and I found the culprit, the attempt to do the reverse hostname check.

It is even visible on my example, the DNS query that takes 30s is the PTR one. The other 2 queries are resolving current hostname to IPv4 and IPv6, which works instantly.

Why tox really needs to do this and why it seems to be doing it when tox.ini is touched are two other interesting questions.

Still, I am able to confirm that the Python call that causes this is socket.getfqdn():

$ time python -c "import socket; socket.getfqdn()"
python -c "import socket; socket.getfqdn()"  0.05s user 0.04s system 0% cpu 31.168 total

I do suspect that this comes from

tox/src/tox/logs/result.py

Line 25 in 7aa1303

"host": os.getenv(str("HOSTNAME")) or socket.getfqdn(),

as the other two places are inside tests.

Interestingly I could define HOSTNAME env var to bypass the issue locally which is very useful info to have and I can confirm that the workaround seems to be working.

Do we really need that getfqdn() call in tox?

[ssbarnea]

@gaborbernat Considering that the Python bugs was not fixed in 4 years and I doubt it will, how are you feeling about replacing the socket.getfqdn() with socket.gethostname() which is not affected by that problem?

As the bug is specific to macos, we could add wrapper function and make it use full one for non macos and return short/fast one on macos.

[gaborbernat]

@gaborbernat Considering that the Python bugs was not fixed in 4 years and I doubt it will, how are you feeling about replacing the socket.getfqdn() with socket.gethostname() which is not affected by that problem?

Sounds good 👍

[frankgu968]

Just discovered this thread while googling for a separate issue. Perhaps this is also related: https://apple.stackexchange.com/questions/175320/why-is-my-hostname-resolution-taking-so-long