IIS 应用程序池在中间件记录 OperationCancelledException 后大约 20 秒崩溃

Question

在我们的生产服务器上，全天断断续续地，我们看到这样的记录：

A process serving application pool 'MyApi' suffered a fatal communication error with the Windows Process Activation Service. The process id was '29568'. The data field contains the error number.

我看到了解决这个问题的建议，比如在 IIS 中设置一些 32 位的东西，但我无法在生产级别控制 IIS。此外，我的公司运行有几十个应用程序池，只有我正在调查的那个有这个问题。所以我已经排除了某种 IIS 配置问题。

我有运行通过 DebugDiag 的故障转储，这是报告的内容：

In w3wp.exe.18080.dmp the assembly instruction at iiscore!W3_CONTEXT_BASE::GetIsLastNotification+62 in C:\Windows\System32\inetsrv\iiscore.dll from Microsoft Corporation has caused an access violation exception (0xC0000005) when trying to read from memory location 0xd7f76008 on thread 94

我尝试使用谷歌搜索 GetIsLastNotification 并找到 this in the MS docs:

Do not use PreSendRequestHeaders with managed modules that implement IHttpModule. Setting these properties can cause issues with asynchronous requests. The combination of Application Requested Routing (ARR) and websockets might lead to access violation exceptions that can cause w3wp to crash. For example, iiscore!W3_CONTEXT_BASE::GetIsLastNotification+68 in iiscore.dll has caused an access violation exception (0xC0000005).

它说不要将 PreSendRequestHeaders 与实现 IHttpModule 的模块一起使用。 我已验证整个应用程序没有代码执行此操作。我还验证了我们公司所有库中的代码都没有这样做。

这里有一些非常有趣和不寻常的东西。每次应用程序池崩溃前大约 20 秒，我看到这个被记录：System.OperationCanceledException: The operation was canceled.

我确定此错误来自某些 Owin 中间件。在应用程序的 Startup.cs 文件中，我们注册了一个 class 来执行一些日志记录。由于此代码，它会记录此 OperationCanceledException：

// This class inherits from OwinMiddleware

public override async Task Invoke(IOwinContext context)
{
  try
  {
    await this.Next.Invoke(context);
  }
  catch (Exception ex)
  {
    // log stuff
  }
}

这里发生的所有事情是当一个 http 请求被取消时，await.this.Next.Invoke(context) 抛出异常，因为这是它应该做的。这看起来没什么大不了的，但问题归结为：取消请求如何导致应用程序池在 20 秒后崩溃？

Answer 1

经过巨大的努力，找到了这个问题的答案。标题中提到的“20 秒”最终由于一些延迟的日志记录而成为转移注意力的原因。但以下是应用程序池崩溃的原因。

在应用程序的 Startup.cs 文件中，我们注册了一些 Owin 中间件。中间件看起来像这样：

public override async Task Invoke(IOwinContext context)
{      
  try
  {
    await Next.Invoke(context);
  }
  catch (Exception ex)
  {
    // log the error and return a 500 response
    await LogAndRespond(context, ex);
  }
}

问题在于，当调用此 api 的客户端取消请求时，Next.Invoke(context) 会抛出 OperationCanceledException。在 catch 块中，我们记录了这个错误，但更重要的是，我们返回了对已取消请求的响应。

我不完全理解为什么这会导致整个应用程序池崩溃。我猜中间件试图响应关闭的连接导致了内存访问冲突。无论如何，解决方案是不发送响应。最终代码看起来像这样。

public override async Task Invoke(IOwinContext context)
{
  try
  {
    await Next.Invoke(context);
  }
  catch (OperationCanceledException)
  {
    // Log the canceled request as info, but do NOT send it a response
    _logger.LogInformation("Request has been canceled: {Url}", context.Request.Uri);
  }
  catch (Exception ex)
  {
    // log the error and return a 500 response
    await LogAndRespond(context, ex);
  }
}

IIS 应用程序池在中间件记录 OperationCancelledException 后大约 20 秒崩溃

IIS App Pool crashes about 20 seconds after an OperationCancelledException is logged by middleware

c#

asp.net

.net

iis

owin