IIS 内的 dotnet 进程崩溃。如何确定原因并采取补救措施?
dotnet process inside IIS crashes. How can I determine cause and remediate?
我们正在测试一个 ASP.net 核心应用程序,当 运行 IIS 自动使用的 "reverse proxy" 系统内的 dotnet.exe 进程崩溃时,如果您安装了 IIS .net 核心托管选项到您的机器中。
一旦 dotnet 进程(在我们的例子中是五个)崩溃,所有请求 return 502 错误,并且 IIS 不会通过重新启动 dotnet 进程来恢复。
IIS 日志记录(在事件查看器中)没有任何内容表明池崩溃的原因,有时 IIS 管理员 UI 显示池是 "stopped" 有时它是"started",但在任务管理器中,所有 dotnet.exe 个进程都消失了。
我们将一分为二(从之前提交的代码中重建)直到我们将其隔离,但这个问题主要是关于 ISS 和 DotNet 反向代理:
- 除了事件查看器 (
eventvwr.msc
) 之外,是否还有其他任何地方可以包含 IIS 反向代理和 dotnet.exe 主机进程的相关日志记录?事件查看器中没有似乎相关的当前项目。除了我们发生崩溃的那几天,还有其他几天的消息,显示 WAS 正在启动和重新启动 IIS 池,但是 none dotnet 进程刚刚消失。
是否有已知的dotnet runtime bug导致崩溃,IIS不恢复重启进程?
我从 IIS 看到的唯一日志记录是 GET/POST 请求,C:\inetpub\logs\LogFiles\...
中没有有用的信息
更新:从今天开始,我现在可以看到一些相关的事件查看器条目:
Failed to start process with commandline '"dotnet" .\MyCompany.Authorization.Api.dll', ErrorCode = '0x80004005'.
from Source: IIS AspNetCore Module
在这种情况下似乎是 IIS 本身崩溃了,而不是我的应用程序池中的 dotnet 进程。我的证据是 C:\inetpub\logs\LogFiles\W3SVC1 中的日志文件显示了这一点,看起来 IIS 本身正在崩溃并正在重新启动。注意一些初始 bringup/startup 日志记录开头的“#”:
2016-08-03 13:30:09 W3SVC1 192.168.215.35 GET /api/v3/fhir/patient/311 - 80 - 192.168.215.164 HTTP/1.1 python-requests/2.10.0 - dev-html5.mycompany.biz 404 0 2 1405 1099 0
2016-08-03 13:31:19 W3SVC1 192.168.215.35 OPTIONS /api/v3/fhir/code _dc=1470231079494 80 - 192.168.225.119 HTTP/1.1 Mozilla/5.0+(Windows+NT+10.0;+Win64;+x64)+AppleWebKit/537.36+(KHTML,+like+Gecko)+Chrome/51.0.2704.103+Safari/537.36 http://localhost:8086/ dev-html5.mycompany.biz 200 0 0 206 544 109
2016-08-03 13:31:21 W3SVC1 192.168.215.35 OPTIONS /api/v3/fhir/imagingstudy/297 _dc=1470231081268 80 - 192.168.225.119 HTTP/1.1 Mozilla/5.0+(Windows+NT+10.0;+Win64;+x64)+AppleWebKit/537.36+(KHTML,+like+Gecko)+Chrome/51.0.2704.103+Safari/537.36 http://localhost:8086/ dev-html5.mycompany.biz 200 0 0 206 556 312
2016-08-03 13:31:33 W3SVC1 192.168.215.35 OPTIONS /api/v3/fhir/code _dc=1470231093098 80 - 192.168.225.119 HTTP/1.1 Mozilla/5.0+(Windows+NT+10.0;+Win64;+x64)+AppleWebKit/537.36+(KHTML,+like+Gecko)+Chrome/51.0.2704.103+Safari/537.36 http://localhost:8086/ dev-html5.mycompany.biz 200 0 0 206 544 53
2016-08-03 13:31:34 W3SVC1 192.168.215.35 OPTIONS /api/v3/fhir/imagingstudy/297 _dc=1470231094714 80 - 192.168.225.119 HTTP/1.1 Mozilla/5.0+(Windows+NT+10.0;+Win64;+x64)+AppleWebKit/537.36+(KHTML,+like+Gecko)+Chrome/51.0.2704.103+Safari/537.36 http://localhost:8086/ dev-html5.mycompany.biz 200 0 0 206 556 59
#Software: Microsoft Internet Information Services 8.5
#Version: 1.0
#Date: 2016-08-03 13:33:03
#Fields: date time s-sitename s-ip cs-method cs-uri-stem cs-uri-query s-port cs-username c-ip cs-version cs(User-Agent) cs(Referer) cs-host sc-status sc-substatus sc-win32-status sc-bytes cs-bytes time-taken
2016-08-03 13:33:03 W3SVC1 192.168.215.35 GET /api/v3/fhir/organization/1 - 80 - 192.168.215.35 HTTP/1.1 Mozilla/5.0+(Windows+NT+6.3;+WOW64)+AppleWebKit/537.36+(KHTML,+like+Gecko)+Chrome/51.0.2704.103+Safari/537.36 - dev-html5.mycompany.biz 502 5 0 1627 1255 519
2016-08-03 13:33:10 W3SVC1 192.168.215.35 GET /api/v3/authorize/login username=admin&password=mycompanyx 80 - 192.168.215.164 HTTP/1.1 python-requests/2.10.0 - dev-html5.mycompany.biz 502 5 0 1627 210 520
2016-08-03 13:33:23 W3SVC1 192.168.215.35 GET /api/v3/fhir/organization/1 - 80 - 192.168.215.35 HTTP/1.1 Mozilla/5.0+(Windows+NT+6.3;+WOW64)+AppleWebKit/537.36+(KHTML,+like+Gecko)+Chrome/51.0.2704.103+Safari/537.36 - dev-html5.mycompany.biz 502 5 0 1627 1255 523
#Software: Microsoft Internet Information Services 8.5
#Version: 1.0
#Date: 2016-08-03 13:34:06
#Fields: date time s-sitename s-ip cs-method cs-uri-stem cs-uri-query s-port cs-username c-ip cs-version cs(User-Agent) cs(Referer) cs-host sc-status sc-substatus sc-win32-status sc-bytes cs-bytes time-taken
2016-08-03 13:34:06 W3SVC1 192.168.215.35 OPTIONS /api/v3/fhir/linkage/patient/315 _dc=1470231246063 80 - 192.168.225.30 HTTP/1.1 Mozilla/5.0+(Windows+NT+10.0;+WOW64)+AppleWebKit/537.36+(KHTML,+like+Gecko)+Chrome/51.0.2704.103+Safari/537.36 http://localhost:8086/ dev-html5.mycompany.biz 502 5 0 1627 511 548
#Software: Microsoft Internet Information Services 8.5
#Version: 1.0
#Date: 2016-08-03 13:34:18
#Fields: date time s-sitename s-ip cs-method cs-uri-stem cs-uri-query s-port cs-username c-ip cs-version cs(User-Agent) cs(Referer) cs-host sc-status sc-substatus sc-win32-status sc-bytes cs-bytes time-taken
2016-08-03 13:34:18 W3SVC1 192.168.215.35 GET /api/v3/fhir/organization/1 - 80 - 192.168.215.35 HTTP/1.1 Mozilla/5.0+(Windows+NT+6.3;+WOW64)+AppleWebKit/537.36+(KHTML,+like+Gecko)+Chrome/51.0.2704.103+Safari/537.36 - dev-html5.mycompany.biz 502 5 0 1627 1255 531
2016-08-03 13:34:41 W3SVC1 192.168.215.35 GET /api/v3/authorize/login username=admin&password=mycompanyx 80 - 192.168.215.164 HTTP/1.1 python-requests/2.10.0 - dev-html5.mycompany.biz 502 5 0 1627 210 531
2016-08-03 13:34:46 W3SVC1 192.168.215.35 OPTIONS /api/v3/fhir/code _dc=1470231282672 80 - 192.168.225.119 HTTP/1.1 Mozilla/5.0+(Windows+NT+10.0;+Win64;+x64)+AppleWebKit/537.36+(KHTML,+like+Gecko)+Chrome/51.0.2704.103+Safari/537.36 http://localhost:8086/ dev-html5.mycompany.biz 502 5 0 1627 544 777
2016-08-03 13:34:46 W3SVC1 192.168.215.35 OPTIONS /api/v3/fhir/imagingstudy/297 _dc=1470231284575 80 - 192.168.225.119 HTTP/1.1 Mozilla/5.0+(Windows+NT+10.0;+Win64;+x64)+AppleWebKit/537.36+(KHTML,+like+Gecko)+Chrome/51.0.2704.103+Safari/537.36 http://localhost:8086/ dev-html5.mycompany.biz 502 5 0 1627 556 1037
2016-08-03 13:34:57 W3SVC1 192.168.215.35 GET /api/v3/fhir/organization/1 - 80 - 192.168.215.35 HTTP/1.1 Mozilla/5.0+(Windows+NT+6.3;+WOW64)+AppleWebKit/537.36+(KHTML,+like+Gecko)+Chrome/51.0.2704.103+Safari/537.36 - dev-html5.mycompany.biz 502 5 0 1627 1221 530
2016-08-03 13:35:00 W3SVC1 192.168.215.35 OPTIONS /api/v3/fhir/code _dc=1470231299728 80 - 192.168.225.119 HTTP/1.1 Mozilla/5.0+(Windows+NT+10.0;+Win64;+x64)+AppleWebKit/537.36+(KHTML,+like+Gecko)+Chrome/51.0.2704.103+Safari/537.36 http://localhost:8086/ dev-html5.mycompany.biz 502 5 0 1627 544 527
我将尝试制作一个可重现的测试基础,但目前这似乎与以下内容有关:
Windows Server 2012 R2 上的 IIS 安装了 dotnet IIS 托管更新,以及所有最新的 windows 更新。
IIS 在单个应用程序池中托管多个应用程序。由于已知问题(例如这个),Microsoft "not recommended" 决定(由我)在单个池中托管多个应用程序,但我会在获得更好的信息后更新此答案。
此外,当 IIS 崩溃时,IIS 失败请求跟踪 (FREB) 似乎也很有用。 See this article.
更新:我设置了一个 Azure VM 并且能够重现并向 Microsoft 提供详细信息。该研究的结果发布在 IISIntegration Github issue 245 here. 上。 Microsoft 的某个人向我建议了针对我遇到的特定问题的解决方法,解决方法的想法是:
在部署的 IIS dotnet 核心应用程序中将相对 web.config 启动文件名更改为绝对文件名,例如从 <aspNetCore processPath="dotnet" arguments=".\yourapp.dll" ... />
到 <aspNetCore processPath="dotnet" arguments="c:\full\path\to\yourapp.dll" ... />
,并进行代码更改Startup.cs 和 Program.cs 检查环境何时发布,如果是,始终将应用程序当前工作目录作为 Web 根目录,而不是提供的环境 Web 根目录。
在运行时,每次部署后,手动重新应用 web.config 更改,因为您无法修改项目中的 web.config 源(输入)文件,只能部署最终二进制内容(在执行 dotnet publish 之后)。
我们正在测试一个 ASP.net 核心应用程序,当 运行 IIS 自动使用的 "reverse proxy" 系统内的 dotnet.exe 进程崩溃时,如果您安装了 IIS .net 核心托管选项到您的机器中。
一旦 dotnet 进程(在我们的例子中是五个)崩溃,所有请求 return 502 错误,并且 IIS 不会通过重新启动 dotnet 进程来恢复。
IIS 日志记录(在事件查看器中)没有任何内容表明池崩溃的原因,有时 IIS 管理员 UI 显示池是 "stopped" 有时它是"started",但在任务管理器中,所有 dotnet.exe 个进程都消失了。
我们将一分为二(从之前提交的代码中重建)直到我们将其隔离,但这个问题主要是关于 ISS 和 DotNet 反向代理:
- 除了事件查看器 (
eventvwr.msc
) 之外,是否还有其他任何地方可以包含 IIS 反向代理和 dotnet.exe 主机进程的相关日志记录?事件查看器中没有似乎相关的当前项目。除了我们发生崩溃的那几天,还有其他几天的消息,显示 WAS 正在启动和重新启动 IIS 池,但是 none dotnet 进程刚刚消失。
是否有已知的dotnet runtime bug导致崩溃,IIS不恢复重启进程?
我从 IIS 看到的唯一日志记录是 GET/POST 请求,
C:\inetpub\logs\LogFiles\...
中没有有用的信息
更新:从今天开始,我现在可以看到一些相关的事件查看器条目:
Failed to start process with commandline '"dotnet" .\MyCompany.Authorization.Api.dll', ErrorCode = '0x80004005'.
from Source: IIS AspNetCore Module
在这种情况下似乎是 IIS 本身崩溃了,而不是我的应用程序池中的 dotnet 进程。我的证据是 C:\inetpub\logs\LogFiles\W3SVC1 中的日志文件显示了这一点,看起来 IIS 本身正在崩溃并正在重新启动。注意一些初始 bringup/startup 日志记录开头的“#”:
2016-08-03 13:30:09 W3SVC1 192.168.215.35 GET /api/v3/fhir/patient/311 - 80 - 192.168.215.164 HTTP/1.1 python-requests/2.10.0 - dev-html5.mycompany.biz 404 0 2 1405 1099 0
2016-08-03 13:31:19 W3SVC1 192.168.215.35 OPTIONS /api/v3/fhir/code _dc=1470231079494 80 - 192.168.225.119 HTTP/1.1 Mozilla/5.0+(Windows+NT+10.0;+Win64;+x64)+AppleWebKit/537.36+(KHTML,+like+Gecko)+Chrome/51.0.2704.103+Safari/537.36 http://localhost:8086/ dev-html5.mycompany.biz 200 0 0 206 544 109
2016-08-03 13:31:21 W3SVC1 192.168.215.35 OPTIONS /api/v3/fhir/imagingstudy/297 _dc=1470231081268 80 - 192.168.225.119 HTTP/1.1 Mozilla/5.0+(Windows+NT+10.0;+Win64;+x64)+AppleWebKit/537.36+(KHTML,+like+Gecko)+Chrome/51.0.2704.103+Safari/537.36 http://localhost:8086/ dev-html5.mycompany.biz 200 0 0 206 556 312
2016-08-03 13:31:33 W3SVC1 192.168.215.35 OPTIONS /api/v3/fhir/code _dc=1470231093098 80 - 192.168.225.119 HTTP/1.1 Mozilla/5.0+(Windows+NT+10.0;+Win64;+x64)+AppleWebKit/537.36+(KHTML,+like+Gecko)+Chrome/51.0.2704.103+Safari/537.36 http://localhost:8086/ dev-html5.mycompany.biz 200 0 0 206 544 53
2016-08-03 13:31:34 W3SVC1 192.168.215.35 OPTIONS /api/v3/fhir/imagingstudy/297 _dc=1470231094714 80 - 192.168.225.119 HTTP/1.1 Mozilla/5.0+(Windows+NT+10.0;+Win64;+x64)+AppleWebKit/537.36+(KHTML,+like+Gecko)+Chrome/51.0.2704.103+Safari/537.36 http://localhost:8086/ dev-html5.mycompany.biz 200 0 0 206 556 59
#Software: Microsoft Internet Information Services 8.5
#Version: 1.0
#Date: 2016-08-03 13:33:03
#Fields: date time s-sitename s-ip cs-method cs-uri-stem cs-uri-query s-port cs-username c-ip cs-version cs(User-Agent) cs(Referer) cs-host sc-status sc-substatus sc-win32-status sc-bytes cs-bytes time-taken
2016-08-03 13:33:03 W3SVC1 192.168.215.35 GET /api/v3/fhir/organization/1 - 80 - 192.168.215.35 HTTP/1.1 Mozilla/5.0+(Windows+NT+6.3;+WOW64)+AppleWebKit/537.36+(KHTML,+like+Gecko)+Chrome/51.0.2704.103+Safari/537.36 - dev-html5.mycompany.biz 502 5 0 1627 1255 519
2016-08-03 13:33:10 W3SVC1 192.168.215.35 GET /api/v3/authorize/login username=admin&password=mycompanyx 80 - 192.168.215.164 HTTP/1.1 python-requests/2.10.0 - dev-html5.mycompany.biz 502 5 0 1627 210 520
2016-08-03 13:33:23 W3SVC1 192.168.215.35 GET /api/v3/fhir/organization/1 - 80 - 192.168.215.35 HTTP/1.1 Mozilla/5.0+(Windows+NT+6.3;+WOW64)+AppleWebKit/537.36+(KHTML,+like+Gecko)+Chrome/51.0.2704.103+Safari/537.36 - dev-html5.mycompany.biz 502 5 0 1627 1255 523
#Software: Microsoft Internet Information Services 8.5
#Version: 1.0
#Date: 2016-08-03 13:34:06
#Fields: date time s-sitename s-ip cs-method cs-uri-stem cs-uri-query s-port cs-username c-ip cs-version cs(User-Agent) cs(Referer) cs-host sc-status sc-substatus sc-win32-status sc-bytes cs-bytes time-taken
2016-08-03 13:34:06 W3SVC1 192.168.215.35 OPTIONS /api/v3/fhir/linkage/patient/315 _dc=1470231246063 80 - 192.168.225.30 HTTP/1.1 Mozilla/5.0+(Windows+NT+10.0;+WOW64)+AppleWebKit/537.36+(KHTML,+like+Gecko)+Chrome/51.0.2704.103+Safari/537.36 http://localhost:8086/ dev-html5.mycompany.biz 502 5 0 1627 511 548
#Software: Microsoft Internet Information Services 8.5
#Version: 1.0
#Date: 2016-08-03 13:34:18
#Fields: date time s-sitename s-ip cs-method cs-uri-stem cs-uri-query s-port cs-username c-ip cs-version cs(User-Agent) cs(Referer) cs-host sc-status sc-substatus sc-win32-status sc-bytes cs-bytes time-taken
2016-08-03 13:34:18 W3SVC1 192.168.215.35 GET /api/v3/fhir/organization/1 - 80 - 192.168.215.35 HTTP/1.1 Mozilla/5.0+(Windows+NT+6.3;+WOW64)+AppleWebKit/537.36+(KHTML,+like+Gecko)+Chrome/51.0.2704.103+Safari/537.36 - dev-html5.mycompany.biz 502 5 0 1627 1255 531
2016-08-03 13:34:41 W3SVC1 192.168.215.35 GET /api/v3/authorize/login username=admin&password=mycompanyx 80 - 192.168.215.164 HTTP/1.1 python-requests/2.10.0 - dev-html5.mycompany.biz 502 5 0 1627 210 531
2016-08-03 13:34:46 W3SVC1 192.168.215.35 OPTIONS /api/v3/fhir/code _dc=1470231282672 80 - 192.168.225.119 HTTP/1.1 Mozilla/5.0+(Windows+NT+10.0;+Win64;+x64)+AppleWebKit/537.36+(KHTML,+like+Gecko)+Chrome/51.0.2704.103+Safari/537.36 http://localhost:8086/ dev-html5.mycompany.biz 502 5 0 1627 544 777
2016-08-03 13:34:46 W3SVC1 192.168.215.35 OPTIONS /api/v3/fhir/imagingstudy/297 _dc=1470231284575 80 - 192.168.225.119 HTTP/1.1 Mozilla/5.0+(Windows+NT+10.0;+Win64;+x64)+AppleWebKit/537.36+(KHTML,+like+Gecko)+Chrome/51.0.2704.103+Safari/537.36 http://localhost:8086/ dev-html5.mycompany.biz 502 5 0 1627 556 1037
2016-08-03 13:34:57 W3SVC1 192.168.215.35 GET /api/v3/fhir/organization/1 - 80 - 192.168.215.35 HTTP/1.1 Mozilla/5.0+(Windows+NT+6.3;+WOW64)+AppleWebKit/537.36+(KHTML,+like+Gecko)+Chrome/51.0.2704.103+Safari/537.36 - dev-html5.mycompany.biz 502 5 0 1627 1221 530
2016-08-03 13:35:00 W3SVC1 192.168.215.35 OPTIONS /api/v3/fhir/code _dc=1470231299728 80 - 192.168.225.119 HTTP/1.1 Mozilla/5.0+(Windows+NT+10.0;+Win64;+x64)+AppleWebKit/537.36+(KHTML,+like+Gecko)+Chrome/51.0.2704.103+Safari/537.36 http://localhost:8086/ dev-html5.mycompany.biz 502 5 0 1627 544 527
我将尝试制作一个可重现的测试基础,但目前这似乎与以下内容有关:
Windows Server 2012 R2 上的 IIS 安装了 dotnet IIS 托管更新,以及所有最新的 windows 更新。
IIS 在单个应用程序池中托管多个应用程序。由于已知问题(例如这个),Microsoft "not recommended" 决定(由我)在单个池中托管多个应用程序,但我会在获得更好的信息后更新此答案。
此外,当 IIS 崩溃时,IIS 失败请求跟踪 (FREB) 似乎也很有用。 See this article.
更新:我设置了一个 Azure VM 并且能够重现并向 Microsoft 提供详细信息。该研究的结果发布在 IISIntegration Github issue 245 here. 上。 Microsoft 的某个人向我建议了针对我遇到的特定问题的解决方法,解决方法的想法是:
在部署的 IIS dotnet 核心应用程序中将相对 web.config 启动文件名更改为绝对文件名,例如从
<aspNetCore processPath="dotnet" arguments=".\yourapp.dll" ... />
到<aspNetCore processPath="dotnet" arguments="c:\full\path\to\yourapp.dll" ... />
,并进行代码更改Startup.cs 和 Program.cs 检查环境何时发布,如果是,始终将应用程序当前工作目录作为 Web 根目录,而不是提供的环境 Web 根目录。在运行时,每次部署后,手动重新应用 web.config 更改,因为您无法修改项目中的 web.config 源(输入)文件,只能部署最终二进制内容(在执行 dotnet publish 之后)。