了解 asyncio set_result 的行为，因为它与 slow_callback_duration 相关

问题描述

我正在尝试调试正在运行的生产 python web 服务的性能，该服务构建在 tornado 之上，使用 uvloop 作为 asyncio 事件循环。在尝试提高并发性的过程中，我希望找到正在执行阻止事件循环的同步代码的地方。为此，我通过服务配置了调试和slow_callback_duration 如下：

    uvloop.install()
    loop = asyncio.get_event_loop()
    loop.set_debug(True)
    loop.slow_callback_duration = 0.05
    server()

启用此代码后，我看到大量慢速回调日志行，如下所示：

[W 210217 18:12:24.052 asyncio:199] Executing <Handle <TaskWakeupMethWrapper object at 0x7fad2e3cd6a8> created at /usr/local/lib/python3.7/asyncio/tasks.py:711> took 0.105 seconds
[W 210217 18:12:24.164 asyncio:199] Executing <Handle <TaskWakeupMethWrapper object at 0x7fad4d14f768> created at /usr/local/lib/python3.7/asyncio/tasks.py:711> took 0.060 seconds
[W 210217 18:12:24.255 asyncio:199] Executing <Handle <TaskWakeupMethWrapper object at 0x7fad705e2618> created at /usr/local/lib/python3.7/asyncio/tasks.py:711> took 0.083 seconds
[W 210217 18:12:24.387 asyncio:199] Executing <Handle <TaskWakeupMethWrapper object at 0x7fad9b08dd68> created at /usr/local/lib/python3.7/asyncio/tasks.py:711> took 0.077 seconds
[W 210217 18:12:24.682 asyncio:199] Executing <Handle <TaskWakeupMethWrapper object at 0x7fad3716f4c8> created at /usr/local/lib/python3.7/asyncio/tasks.py:711> took 0.058 seconds
[W 210217 18:12:24.899 asyncio:199] Executing <Handle <TaskWakeupMethWrapper object at 0x7fad9b08d528> created at /usr/local/lib/python3.7/asyncio/tasks.py:711> took 0.191 seconds
[W 210217 18:12:24.970 asyncio:199] Executing <Handle <TaskWakeupMethWrapper object at 0x7fad3706ad68> created at /usr/local/lib/python3.7/asyncio/tasks.py:711> took 0.063 seconds
[W 210217 18:12:25.117 asyncio:199] Executing <Handle <TaskWakeupMethWrapper object at 0x7fad2e57c3a8> created at /usr/local/lib/python3.7/asyncio/tasks.py:711> took 0.088 seconds

在我的特定 python 构建中，该 /tasks.py:711 行是指 __done__callback 的 gather 中的此调用：

            if outer._cancel_requested:
                # If gather is being cancelled we must propagate the
                # cancellation regardless of *return_exceptions* argument.
                # See issue 32684.
                outer.set_exception(futures.CancelledError())
            else:
                outer.set_result(results) <--- This line

我想更好地理解这个调试日志行实际代表什么。从我对缓慢回调行为的（有限的）理解来看，似乎 set_result 在 wrapping future 上的实际执行需要很长时间才能执行，但这似乎有点疯狂。有没有办法从此调试日志中获取更多详细信息和/或确定事件循环在报告缓慢回调时实际运行的代码？

解决方法

暂无找到可以解决该程序问题的有效方法，小编努力寻找整理中！

如果你已经找到好的解决方法，欢迎将解决方案带上本链接一起发送给小编。

小编邮箱:dio#foxmail.com (将#修改为@）