0

我正在尝试调试正在运行的生产 python web 服务的性能,该服务建立在 tornado 之上,使用 uvloop 作为 asyncio 事件循环。在尝试提高并发性时,我正在寻找正在执行同步代码的地方,这些地方会阻塞事件循环。为此,我已经通过服务配置了 debug 和 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__callbackof 中的这个调用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需要很长时间才能执行,但这似乎有点疯狂。有没有办法从此调试日志中获取更多详细信息和/或确定事件循环在报告缓慢回调时实际运行的代码?

4

0 回答 0