python asyncio.open_connection()超时时的不一致行为

Question

我使用带有asyncio的python 3.7来创建与本地网络上某些硬件的TCP连接，与所有硬件一样，这些硬件可能会断开连接或简单地关闭。

在硬件断开连接的情况下，我注意到使用asyncio.open_connection()大约需要3秒才能引发OSError:

import asyncio
import logging
logging.basicConfig(level='INFO', format='%(asctime)s %(message)s')
async def main(host, port):
while True:
try:
logging.info('trying to connect to %s:%d', host, port)
r, w = await asyncio.open_connection(host, port)
logging.info('connected')
break
except Exception as error:
logging.error('error: %r', error)
asyncio.run(main('cryoctrl01', 5000))

带输出：

$ python test.py
2020-05-05 18:31:04,983 trying to connect to cryoctrl01:5000
2020-05-05 18:31:08,039 error: OSError(113, "Connect call failed ('192.168.1.12', 5000)")
2020-05-05 18:31:08,039 trying to connect to cryoctrl01:5000
2020-05-05 18:31:11,111 error: OSError(113, "Connect call failed ('192.168.1.12', 5000)")
2020-05-05 18:31:11,111 trying to connect to cryoctrl01:5000
2020-05-05 18:31:14,183 error: OSError(113, "Connect call failed ('192.168.1.12', 5000)")
...

正如我所知，我在本地网络上，我想减少这段时间，所以我把代码包装在asyncio.wait_for()上，如下所示：

import asyncio
import logging
logging.basicConfig(level='INFO', format='%(asctime)s %(message)s')
async def main(host, port, timeout):
while True:
try:
logging.info('trying to connect to %s:%d', host, port)
coro = asyncio.open_connection(host, port)
r, w = await asyncio.wait_for(coro, timeout)
logging.info('connected')
break
except Exception as error:
logging.error('error: %r', error)
asyncio.run(main('cryoctrl01', 5000, 0.5))

但现在我有一个不一致的行为：有时我会得到预期的Timeout错误，但有时我会得到OSError：

$ python test.py
2020-05-05 18:56:18,035 trying to connect to cryoctrl01:5000
2020-05-05 18:56:18,537 error: TimeoutError()
2020-05-05 18:56:18,537 trying to connect to cryoctrl01:5000
2020-05-05 18:56:19,038 error: TimeoutError()
2020-05-05 18:56:19,038 trying to connect to cryoctrl01:5000
2020-05-05 18:56:19,540 error: TimeoutError()
2020-05-05 18:56:19,540 trying to connect to cryoctrl01:5000
2020-05-05 18:56:20,042 error: TimeoutError()
2020-05-05 18:56:20,043 trying to connect to cryoctrl01:5000
2020-05-05 18:56:20,545 error: TimeoutError()
2020-05-05 18:56:20,545 trying to connect to cryoctrl01:5000
2020-05-05 18:56:21,047 error: TimeoutError()
2020-05-05 18:56:21,047 trying to connect to cryoctrl01:5000
2020-05-05 18:56:21,095 error: OSError(113, "Connect call failed ('192.168.1.12', 5000)")
2020-05-05 18:56:21,095 trying to connect to cryoctrl01:5000
2020-05-05 18:56:21,597 error: TimeoutError()
2020-05-05 18:56:21,597 trying to connect to cryoctrl01:5000
2020-05-05 18:56:22,098 error: TimeoutError()
2020-05-05 18:56:22,098 trying to connect to cryoctrl01:5000
2020-05-05 18:56:22,600 error: TimeoutError()
2020-05-05 18:56:22,600 trying to connect to cryoctrl01:5000
2020-05-05 18:56:23,102 error: TimeoutError()
2020-05-05 18:56:23,102 trying to connect to cryoctrl01:5000
2020-05-05 18:56:23,604 error: TimeoutError()
2020-05-05 18:56:23,604 trying to connect to cryoctrl01:5000
2020-05-05 18:56:24,106 error: TimeoutError()
2020-05-05 18:56:24,106 trying to connect to cryoctrl01:5000
2020-05-05 18:56:24,167 error: OSError(113, "Connect call failed ('192.168.1.12', 5000)")
2020-05-05 18:56:24,167 trying to connect to cryoctrl01:5000
2020-05-05 18:56:24,669 error: TimeoutError()
2020-05-05 18:56:24,669 trying to connect to cryoctrl01:5000

我注意到这种情况似乎也发生在每3分左右。这种行为是来自操作系统吗？我应该如何更改代码以获得一致的行为？

Answer 1

您只能在实际超时时获得TimeoutErrr。如果你观察启动连接和非超时错误之间的时间差，你会发现它们发生在不到0.5秒的超时时间内。检查超时并不能保护您免受其他网络错误的影响，所以您不能期望一致性——您只需要处理这两种情况。

如果使用%s而不是%r打印错误，您将看到来自系统的错误消息。Errno 113可能是"没有到主机的路由"，这可能表明您一侧出现了短暂的网络故障。您需要捕获OSError并决定如何处理它们，典型的方法是在适当的延迟后重试连接。