记录异步调用的正确/常用方法

Posted 2023-03-13

【中文标题】记录异步调用的正确/常用方法

【英文标题】：A correct/common way to log async calls

【发布时间】：2017-04-13 14:08:08

【问题描述】：

假设我们有一个 IO 操作的异步调用，我们想要记录它。 最简单的方法如下所示：

async def f():
   logger.log('io was called')
   await call_some_io()

但是当我们运行 log() 函数时，我们显然会遇到这种情况，该函数会切换上下文并记录其他内容，并且仅在执行 call_some_io() 之后。

下一个方法看起来更健壮：

async def f():
   await call_some_io()
   logger.log('io was called')

我们正在等待 call_some_io() 并在它之后记录它。看起来在这种情况下我们有一致的调用。

但是还有第三种使用上下文管理器的方法：

async def f():
   with LoggingContext:
     await call_some_io()

这里的LoggingContext 是一些ContextManager，其中__exit__ 方法有一些日志调用。

所以问题是：哪种记录异步调用的方法最常见且最可靠？

【参考方案1】：

所有方法都是稳健的。上下文管理器可能不那么常见，但仍然很强大。

但是，示例 #1 和 #2 具有不同的语义。第一条日志消息应该是about to call io 而不是io was called，因为还没有发出调用。

LoggingContext 示例对开发人员来说相当方便，但在执行顺序方面与示例 #2 相同。

【讨论】：

我只能为自己说话，除非该操作需要很长时间，否则我会在执行操作后记录消息。

【参考方案2】：

在启动另一个协程的协程中使用日志记录是相对稳健的，因为正如您所注意到的，它可能会命中上下文切换。实际上只有两种情况：等待之前和之后以及几种可能的方法：登录协程、日志装饰器和日志上下文管理器。我相信这不是一份详尽的清单。

在 io 启动前登录协程以进行日志记录

async def coro():
   logger.log('Before io start')
   await call_some_io()

在 io 启动之前记录的装饰器

def logger(f):
    def warp(*arguments, **kwarguments):
        logging.log("Before io start")
        f(*arguments. **kwarguments)
    return wrap

@logger
async def coro():
    # Async logic...

在 io 启动之前记录的日志上下文管理器

class Logger(object):
     def __enter__(self):
        logging.log("Before io start")

     # Empty __exit__ ...

with Logger():
     await coro()

一个更棘手的装饰器示例，它在 io 调用后记录。

def logger(f):          
    async def wrapper():
        await f()       
        logging.log("After io start") 
    return wrapper

装饰器的包装器也必须是协程才能在 io 启动后记录异步调用。使用异步记录器记录异步调用绝对不可靠；）

in-coro 和上下文管理器方法很容易在调用后转换为日志记录，因此我将跳过示例。

所有这些示例都同样常见，因为 Python 非常具有艺术性，并且没有像 Java 那样的编程模式。所以所有的方法对我来说都像是 Pythonic 的方式。