async nlog 如何与 IIS 中托管的 webapi 一起工作？

Posted 2023-04-13

【中文标题】async nlog 如何与 IIS 中托管的 webapi 一起工作？

【英文标题】：How async nlog works with webapi hosted in IIS?

【发布时间】：2021-09-19 07:27:53

【问题描述】：

我在 write every request logs to database with nlog 的 IIS 中托管了 web api。它按预期工作。我们的 db 与其他项目共享，最近在 db 中看到了一些争用 - 这导致我们的一些 web api 调用需要更长的时间或超时。 （当前超时时间为 20 秒，不能增加超时时间）

我正在考虑使用nlog's async functionality，它有助于在单独的线程上异步写入日志。

在将调用返回给客户端后，IIS 将如何处理这些长时间运行的进程？ 任何形式的见解都会有所帮助。

【问题讨论】：

您可以随时查看源代码：github.com/NLog/NLog/blob/…。它使用专用队列和计时器在后台线程上刷新队列。它与用户的上下文完全分离，因此如果您将消息写入日志，请确保在记录之前从上下文中捕获所需的所有内容。

【参考方案1】：

首先，让我们抛开 IIS，只讨论应用程序（不仅是 webapi）和 SQL 之间的异步使用。无论你使用 NLog 的异步还是其他，它的工作原理都是一样的。

当用户单击按钮并且应用程序将日志写入数据库时​​。 这需要多个较小的任务，例如读取和填充数据 在内部对象中，建立与 SQL 的连接并保存它。

由于 SQL 在网络中的另一台机器上运行并在不同的环境下运行 过程，这可能很耗时，可能需要更长的时间。

因此，如果应用程序在单个线程上运行，那么屏幕将 在所有任务完成之前处于挂起状态，这是非常糟糕的 用户体验。

已经看到，在执行请求时，大约 70-80% 的时间在等待相关任务时被浪费了。因此，异步编程可以最大限度地利用它，一旦将任务传递给另一个进程（比如 SQL），当前线程就会保存状态并可以接受另一个任务。当 SQL 任务完成任何空闲的线程时，可以进一步占用它。

现在，让我们讨论一下 IIS 如何处理异步。 IIS 本身不拥有任何线程池，而是使用 CLR 线程池。 当 IIS 接收到请求时，它会从 CLR 线程池中获取一个线程并分配给它以进一步处理该请求。所以 IIS 只是分配线程，CLR 线程池决定何时添加或删除线程。

CLR 线程池包含工作线程和 I/O 完成端口或 IOCP 线程。当您在应用程序中进行异步 I/O 调用，或者您的应用程序访问文件系统、数据库、Web 服务等时，运行时会使用 IOCP 线程。

【讨论】：

为了确认这一点：我（客户）发起了一次服务调用，该调用写入了 50K 日志消息。我看到客户端得到了响应，并且 async nlog 仍在向 db 写入消息。

【参考方案2】：

使用NLog AsyncWrapper，那么应用程序线程将只有 NLog 自动捕获相关线程上下文（基于目标 NLog 目标，例如 $threadid）并推送到 ConcurrentQueue 的开销。因此应用程序线程不会受到 20 秒（或更多）的数据库超时的影响。

NLog AsyncWrapper 使用 CLR ThreadPool 中的后台线程（由 Timer 触发）从其 ConcurrentQueue 写入待处理的 LogEvent。如果应用程序线程的日志记录非常快并且后台线程无法跟上（因为数据库超时），那么默认情况下它将开始丢弃 LogEvents（避免内存不足问题或阻塞应用程序线程）。