尽管处理了 RoleEnvironment.Changing 事件并将 Cancel 设置为 false，但 Azure webroles 在配置更改后回收答案

【问题标题】：Azure webroles recycle after configuration change despite handling the RoleEnvironment.Changing event and setting Cancel to false尽管处理了 RoleEnvironment.Changing 事件并将 Cancel 设置为 false，但 Azure webroles 在配置更改后回收
【发布时间】：2017-05-25 14:22:33
【问题描述】：

更改 webrole 的某些配置设置时，会触发 RoleEnvironment.Changing 事件。据我了解，如果在 RoleEnvironmentChangingEventArgs 中将 Cancel 设置为 false，则角色不应回收，并且更改会被接受，并且应在 RoleEnvironment.Changed 事件触发后立即应用。

但是，尽管将 Cancel 设置为 false，我们的角色仍在回收。

这是事件处理程序的内容：

public static void onRoleEnvironmentChanging(object sender, 
RoleEnvironmentChangingEventArgs e)
{
    try
    {
        List<RoleEnvironmentConfigurationSettingChange> configurationChanges = e.Changes.OfType<RoleEnvironmentConfigurationSettingChange>().ToList();
        e.Cancel = configurationChanges.Any(c => (c.ConfigurationSettingName == "settingThatShouldRecycleRole")))
    }
    catch (Exception)
    {
        e.Cancel = false;
    }
}

为了确定，我在这里添加了 try catch，但据我所知，它从未被触发过。

触发 e.Cancel = true 的设置没有改变。我已经记录了这个事件处理程序的最终结果，即使 e.Cancel 设置为 false，角色也会回收。

不幸的是，检查角色的日志并没有找到回收的原因。

根据这篇旧博文，如果事件没有及时响应，事情可能会出错：https://alexandrebrisebois.wordpress.com/2013/09/29/handling-cloud-service-role-configuration-changes-in-windows-azure/

但是，我无法想象这段代码需要很长时间才能执行。测量它产生了大约 150 毫秒，这相当慢，但这包括将时间记录到表存储的代码。据我所知，处理事件对时间敏感的说法也没有记录在其他任何地方。

编辑： WaHostBootstrapper.log相关内容

12:27:26.254, INFO ] Getting status from client WaIISHost.exe (2728).
12:27:26.254, INFO ] Client reported status 0.
12:27:26.254, INFO ] Getting status from client w3wp.exe (3424).
12:27:26.254, INFO ] Client reported status 0.
12:27:30.183, INFO ] Sending update notification to client WaIISHost.exe (2728).
12:27:30.183, INFO ] Sending update notification to client w3wp.exe (3424).
12:27:30.261, INFO ] Sending update completion notification to client WaIISHost.exe (2728).
12:27:30.293, INFO ] Sending update completion notification to client w3wp.exe (3424).
12:27:41.271, INFO ] Getting status from client WaIISHost.exe (2728).
12:27:41.271, INFO ] Client reported status 0.
12:27:41.271, INFO ] Getting status from client w3wp.exe (3424).
12:27:41.271, ERROR] Failed to connect to client w3wp.exe (3424).
12:27:41.271, ERROR] <- CRuntimeClient::OnRoleStatusCallback(0x000000A1B6E0E3C0) =0x800706ba
12:27:41.271, INFO ] Removing disconnected client: w3wp.exe (3424).
12:27:56.279, INFO ] Getting status from client WaIISHost.exe (2728).
12:27:56.279, INFO ] Client reported status 0.
12:28:11.284, INFO ] Getting status from client WaIISHost.exe (2728).
12:28:11.284, INFO ] Client reported status 0.
12:28:26.296, INFO ] Getting status from client WaIISHost.exe (2728).
12:28:26.296, INFO ] Client reported status 0.
12:28:35.683, INFO ] Registering client with PID 2964.
12:28:35.683, INFO ] Client w3wp.exe (2964) registered.
12:28:41.464, INFO ] Getting status from client WaIISHost.exe (2728).
12:28:41.464, INFO ] Client reported status 0.
12:28:41.464, INFO ] Getting status from client w3wp.exe (2964).
12:28:41.480, INFO ] Client reported status 0.
12:28:56.499, INFO ] Getting status from client

AppAgentRuntime.log 的相关内容（略有删节）

12:27:30.313, INFO ] The role can handle the config change without recycle.     
12:27:30.355, INFO ] Firewall configuration was not found for X.X.X.X. Creating new configuration for X.X.X.X
12:27:30.355, INFO ] Firewall configuration was not found for Y.Y.Y.Y. Creating new configuration for Y.Y.Y.Y
12:27:30.355, INFO ] Creating additional rule for Internal Endpoint.
12:27:30.355, INFO ] Creating additional rule for Internal Endpoint.
12:27:30.355, INFO ] Creating additional rule for Internal Endpoint.
12:27:30.355, INFO ] Setting firewall rule : -REDACTED-
12:27:30.355, INFO ] Firewall rule -REDACTED-
-Repeated 10+ times with different rule guids-
12:27:30.560, INFO ] Cleanup base filters for group NT SERVICE:
12:27:30.560, WARN ] BaseFilterRemoveStealthModeFilters not implemented     
12:27:30.560, INFO ] Add stealth-mode filters if requested for group NT SERVICE:
12:27:30.560, INFO ] Deleting firewall rules...     
12:27:31.011, INFO ] Deleted 14 rules. hr: 0x0      
12:27:31.011, WARN ] BaseFilterRemoveStealthModeFilters not implemented     
12:27:31.011, INFO ] Deleting URLACL : Url = http://X.X.X.X:XXX/        
12:27:31.011, WARN ] Warning: Unable to delete URLACL : URL = http://X.X.X.X:XXX/. Error code - 0x2
12:27:31.011, INFO ] Deleting URLACL : Url = https://X.X.X.X:XXX/
12:27:31.011, INFO ] Successfully created URLACL : URL = https://X.X.X.X:XXX/, SDDL = D:(A;;GX;;;S-1-5-20).
12:27:31.011, INFO ] AgentpUpdateConfigWorker Returning
    00000000.
12:27:31.011, INFO ] <<<<_Context_Ends: {-REDACTED-}    Return value = 00000000. 
12:27:31.011, WARN ] <- AgentMonitoringObject::EventEnd(0x00007FFF616577E0) =0x80070015
12:27:31.011, INFO ] <<<<_Context_Ends: {-REDACTED-}    Return value = 00000000.

这看起来很可疑，为什么要更新一堆防火墙规则？

WaAppAgent.log 的内容：

12:27:23.86] [HEART] WindowsAzureGuestAgent Heartbeat.
12:27:23.86] [INFO]  Role current state: Started.
12:27:23.86] [INFO]  Recieved goal state information.
12:27:23.86] [INFO]  Execution status: UpdateSucceeded.
12:27:23.86] [INFO]  Role -REDACTED- is reporting state Ready.
12:27:24.32] [INFO]  Role -REDACTED- has current state Started, desired state Started, and goal state execution status UpdateSucceeded.
12:27:28.87] [HEART] WindowsAzureGuestAgent Heartbeat.
12:27:28.87] [INFO]  Role current state: Started.
12:27:28.87] [INFO]  Recieved goal state information.
12:27:28.87] [INFO]  Execution status: UpdateSucceeded.
12:27:28.87] [INFO]  Role -REDACTED- is reporting state Ready.
12:27:28.87] [INFO]  Goal state 43 received.
12:27:28.87] [INFO]  Received stop role deadline hint: 300000. ExpectedState: Started
12:27:28.87] [INFO]  Goal state being updated.
12:27:28.87] [INFO]  Deleting all user accounts.
12:27:28.87] [INFO]  Role -REDACTED- is being updated.
12:27:28.87] [INFO]  Role -REDACTED- has goal state Started.
12:27:28.87] [INFO]  Extension Plugins Found.
12:27:28.95] [INFO]  Goal state execution started for role -REDACTED-.
12:27:28.95] [INFO]  Driving role -REDACTED- to goal state Started from current state Started.
12:27:29.98] [INFO]  Found role root. roleId:  tagFileName:  tagPatternUsed: *.tag root: E:\
12:27:29.98] [INFO]  Acled the directory E:\base.
12:27:29.98] [INFO]  Acled the directory E:\base\x64.
12:27:29.98] [INFO]  Acled the directory E:\base\x86.
12:27:29.98] [INFO]  Acled the directory D:\Packages.
12:27:29.98] [INFO]  Acled the directory D:\Packages\GuestAgent.
12:27:29.98] [INFO]  Acled the directory D:\Packages\GuestAgent\GuestAgent.
12:27:29.98] [INFO]  Acled the directory D:\Packages\GuestAgent\GuestAgent\LegacyRuntime.
12:27:29.98] [INFO]  Acled the directory D:\Packages\GuestAgent\GuestAgent\LegacyRuntime\x64.
12:27:29.98] [INFO]  Acled the directory D:\Packages\GuestAgent\GuestAgent\LegacyRuntime\x86.
12:27:29.98] [INFO]  Acled the directory D:\Packages\GuestAgent\Telemetry.
12:27:29.98] [INFO]  Acled the directory D:\Packages\Plugins.
12:27:29.98] [INFO]  Acled the directory D:\Packages\Plugins\Microsoft.Azure.Diagnostics.PaaSDiagnostics.
12:27:29.98] [INFO]  Acled the directory D:\Packages\Plugins\Microsoft.Azure.Diagnostics.PaaSDiagnostics\1.8.1.0.
12:27:29.98] [INFO]  Acled the directory D:\Packages\Plugins\Microsoft.Azure.Diagnostics.PaaSDiagnostics\1.8.1.0\Monitor.
12:27:29.98] [INFO]  Acled the directory D:\Packages\Plugins\Microsoft.Azure.Diagnostics.PaaSDiagnostics\1.8.1.0\Monitor\x64.
12:27:29.98] [INFO]  Acled the directory D:\Packages\Plugins\Microsoft.Azure.Diagnostics.PaaSDiagnostics\1.8.1.0\Monitor\x64\Extensions.
12:27:29.98] [INFO]  Acled the directory D:\Packages\Plugins\Microsoft.Azure.Diagnostics.PaaSDiagnostics\1.8.1.0\Monitor\x64\Extensions\ApplicationInsightsExtension.
12:27:29.98] [INFO]  Acled the directory D:\Packages\Plugins\Microsoft.Azure.Diagnostics.PaaSDiagnostics\1.8.1.0\Monitor\x64\Extensions\ApplicationInsightsExtension\Resources.
12:27:29.98] [INFO]  Acled the directory D:\Packages\Plugins\Microsoft.Azure.Diagnostics.PaaSDiagnostics\1.8.1.0\Monitor\x64\schema.
12:27:29.98] [INFO]  Acled the directory D:\Packages\Plugins\Microsoft.Azure.Diagnostics.PaaSDiagnostics\1.8.1.0\Monitor\x64\schema\1.0.
12:27:29.98] [INFO]  Acled the directory D:\Packages\Plugins\Microsoft.Azure.Diagnostics.PaaSDiagnostics\1.8.1.0\Monitor\x64\schema\2.0.
12:27:29.98] [INFO]  Acled the directory D:\Packages\Plugins\Microsoft.Azure.Diagnostics.PaaSDiagnostics\1.8.1.0\RuntimeSettings.
12:27:29.98] [INFO]  Acled the directory D:\Packages\Plugins\Microsoft.Azure.Diagnostics.PaaSDiagnostics\1.8.1.0\schema.
12:27:29.98] [INFO]  Acled the directory D:\Packages\Plugins\Microsoft.Azure.Diagnostics.PaaSDiagnostics\1.8.1.0\Status.
12:27:29.98] [INFO]  Acled the directory D:\Packages\Plugins\Microsoft.Azure.Diagnostics.PaaSDiagnostics\1.8.1.0\StatusMonitor.
12:27:29.98] [INFO]  Acled the directory D:\Packages\Plugins\Microsoft.Windows.Azure.Extensions.RDP.
12:27:29.98] [INFO]  Acled the directory D:\Packages\Plugins\Microsoft.Windows.Azure.Extensions.RDP\1.2.1.
12:27:29.98] [INFO]  Acled the directory D:\Packages\Plugins\Microsoft.Windows.Azure.Extensions.RDP\1.2.1\RuntimeSettings.
12:27:29.98] [INFO]  Acled the directory D:\Packages\Plugins\Microsoft.Windows.Azure.Extensions.RDP\1.2.1\Status.
12:27:30.08] [INFO]  Found role root. roleId: -REDACTED-
12:27:30.08] [INFO]  Sending new config file: -REDACTED-.
12:27:30.08] [INFO]  Starting installation of plugins. Incarnation: 43 Plugin size: 2
12:27:30.08] [INFO]  Downloading version manifest for plugin Microsoft.Azure.Diagnostics.PaaSDiagnostics from -REDACTED-
12:27:30.13] [INFO]  Getting plugin locations for plugin 'Microsoft.Azure.Diagnostics.PaaSDiagnostics'. Current Version: '1.8.1.0', Requested Version: '1.8.1.0'
12:27:30.13] [INFO]  Auto-Upgrade mode. Highest public version for plugin 'Microsoft.Azure.Diagnostics.PaaSDiagnostics' with requested version: '1.8.1.0', is: '1.8.1.0'
12:27:30.13] [INFO]  Updating plugin 'Microsoft.Azure.Diagnostics.PaaSDiagnostics' to version '1.8.1.0'
12:27:30.14] [INFO]  No plugin settings received. Setting nothing for plugin: Microsoft.Azure.Diagnostics.PaaSDiagnostics version: 1.8.1.0
12:27:30.14] [INFO]  Downloading version manifest for plugin Microsoft.Windows.Azure.Extensions.RDP from -REDACTED-
12:27:30.15] [INFO]  Getting plugin locations for plugin 'Microsoft.Windows.Azure.Extensions.RDP'. Current Version: '1.2.1', Requested Version: '1.2.1'
12:27:30.15] [INFO]  Auto-Upgrade mode. Highest public version for plugin 'Microsoft.Windows.Azure.Extensions.RDP' with requested version: '1.2.1', is: '1.2.1'
12:27:30.15] [INFO]  Updating plugin 'Microsoft.Windows.Azure.Extensions.RDP' to version '1.2.1'
12:27:30.15] [INFO]  No plugin settings received. Setting nothing for plugin: Microsoft.Windows.Azure.Extensions.RDP version: 1.2.1
12:27:30.15] [INFO]  Processing plugin Microsoft.Windows.Azure.Extensions.RDP version 1.2.1, state: enabled, autoupgrade: True, isJson: False
12:27:30.15] [INFO]  Plug-in Microsoft.Windows.Azure.Extensions.RDP 1.2.1 found in cache.
12:27:30.15] [INFO]  Extracting plug-in zip file to folder. Zip file: D:\Packages\Plugins\Microsoft.Windows.Azure.Extensions.RDP\1.2.1\Microsoft.Windows.Azure.Extensions.RDP_1.2.1.zip
12:27:30.16] [INFO]  Xml manifest file D:\Packages\Plugins\Microsoft.Windows.Azure.Extensions.RDP\1.2.1\PluginManifest.xml found corresponding to the plugin Microsoft.Windows.Azure.Extensions.RDP
12:27:30.16] [INFO]  Install command of plugin Microsoft.Windows.Azure.Extensions.RDP: D:\Packages\Plugins\Microsoft.Windows.Azure.Extensions.RDP\1.2.1\RemoteAccessPluginLauncher.exe
12:27:30.16] [INFO]  Beginning installation of plugin Microsoft.Windows.Azure.Extensions.RDP 1.2.1.
12:27:30.16] [INFO]  Processing plugin Microsoft.Azure.Diagnostics.PaaSDiagnostics version 1.8.1.0, state: enabled, autoupgrade: True, isJson: False
12:27:30.16] [INFO]  Plug-in Microsoft.Azure.Diagnostics.PaaSDiagnostics 1.8.1.0 found in cache.
12:27:30.16] [INFO]  Extracting plug-in zip file to folder. Zip file: D:\Packages\Plugins\Microsoft.Azure.Diagnostics.PaaSDiagnostics\1.8.1.0\Microsoft.Azure.Diagnostics.PaaSDiagnostics_1.8.1.0.zip
12:27:30.21] [WARN]  Package extraction failed. D:\Packages\Plugins\Microsoft.Azure.Diagnostics.PaaSDiagnostics\1.8.1.0\Microsoft.Azure.Diagnostics.PaaSDiagnostics_1.8.1.0.zip D:\Packages\Plugins\Microsoft.Azure.Diagnostics.PaaSDiagnostics\1.8.1.0 HR = '0x8007026A' from PackageExpand, Code: 1005
12:27:30.21] [INFO]  Xml manifest file D:\Packages\Plugins\Microsoft.Azure.Diagnostics.PaaSDiagnostics\1.8.1.0\PluginManifest.xml found corresponding to the plugin Microsoft.Azure.Diagnostics.PaaSDiagnostics
12:27:30.21] [INFO]  Install command of plugin Microsoft.Azure.Diagnostics.PaaSDiagnostics: D:\Packages\Plugins\Microsoft.Azure.Diagnostics.PaaSDiagnostics\1.8.1.0\diagnosticspluginlauncher.exe
12:27:30.21] [INFO]  Beginning installation of plugin Microsoft.Azure.Diagnostics.PaaSDiagnostics 1.8.1.0.
12:27:30.26] [INFO]  Found role root. roleId: {-REDACTED-} tagFileName: -REDACTED-.cssx tagPatternUsed: -REDACTED-.cssx.tag root: E:\
12:27:30.26] [WARN]  Environment variable RoleRoot already exists with old value: E:\. Replacing it with new value: E:\
12:27:30.26] [INFO]  Waiting for command of plugin Microsoft.Windows.Azure.Extensions.RDP to finish...
12:27:30.40] [INFO]  Found role root. roleId: {-REDACTED-} tagFileName: -REDACTED-.cssx tagPatternUsed: -REDACTED-.cssx.tag root: E:\
12:27:30.40] [WARN]  Environment variable RoleRoot already exists with old value: E:\. Replacing it with new value: E:\
12:27:30.40] [INFO]  Waiting for command of plugin Microsoft.Azure.Diagnostics.PaaSDiagnostics to finish...
12:27:31.01] [INFO]  Role -REDACTED- was updated.
12:27:31.01] [INFO]  1 events queued for role -REDACTED-.
12:27:33.56] [INFO]  Successfully installed plugin Microsoft.Windows.Azure.Extensions.RDP 1.2.1.
12:27:33.56] [INFO]  Plugin enabled (name: Microsoft.Windows.Azure.Extensions.RDP, version: 1.2.1)., Code: 0
12:27:35.00] [HEART] WindowsAzureGuestAgent Heartbeat.
12:27:35.00] [INFO]  Role current state: Started.
12:27:35.00] [INFO]  Recieved goal state information.
12:27:35.00] [INFO]  Execution status: UpdateSucceeded.
12:27:35.00] [INFO]  Role -REDACTED- is reporting queued event [NotReady, Starting, Role was updated successfully. @05/26/2017 12:27:31.01].
12:27:35.00] [INFO]  Generating substatus from system events.
12:27:35.00] [INFO]  Substatus is Role was updated successfully. System is initializing. [2017-05-26T12:27:28Z]
12:27:35.00] [INFO]  Role -REDACTED- is reporting state NotReady with sub-status Starting and details Role was updated successfully. System is initializing. [2017-05-26T12:27:28Z].
12:27:36.02] [INFO]  Role -REDACTED- has current state Started, desired state Started, and goal state execution status UpdateSucceeded.
12:27:40.03] [HEART] WindowsAzureGuestAgent Heartbeat.
12:27:40.03] [INFO]  Role current state: Started.
12:27:40.03] [INFO]  Recieved goal state information.
12:27:40.03] [INFO]  Execution status: UpdateSucceeded.
12:27:40.03] [INFO]  Role -REDACTED- is reporting state Ready.
12:27:41.03] [INFO]  Role -REDACTED- has current state Started, desired state Started, and goal state execution status UpdateSucceeded.
12:27:45.05] [HEART] WindowsAzureGuestAgent Heartbeat.
12:27:45.05] [INFO]  Role current state: Started.
12:27:45.05] [INFO]  Recieved goal state information.
12:27:45.05] [INFO]  Execution status: UpdateSucceeded.
12:27:45.05] [INFO]  Role -REDACTED- is reporting state Ready.
12:27:46.07] [INFO]  Role -REDACTED- has current state Started, desired state Started, and goal state execution status UpdateSucceeded.

即使我对更改后的设置不做任何事情，它也会这样做：

RoleEnvironment.Changing += onRoleEnvironmentChanging;
RoleEnvironment.Changed += onRoleEnvironmentChanged;

public static void onRoleEnvironmentChanging(object sender, RoleEnvironmentChangingEventArgs e)
{
  e.Cancel = false;
}

private static void onRoleEnvironmentChanged(object sender, RoleEnvironmentChangedEventArgs e)
{
}

Edit2：已修复

禁用应用程序洞察解决了问题。

有关删除应用程序洞察力的信息，请参阅此问题： Remove Application Insight from application on Visual Studio 2013)

此外，我禁用了向 Application Insights 发送诊断数据：见disable send diagnostics data to application insights on publish settings

最后，在角色上启用了 Windows Azure 诊断扩展，该角色还将诊断上传到 Application Insights。必须通过门户删除此扩展程序。

【问题讨论】：

标签： azure azure-web-roles

【解决方案1】：

VM 上运行的任何挂接到服务运行时的进程都可以触发回收。检查 WaHostBootstrapper 日志以查看导致回收的进程。您可以从 https://blogs.msdn.microsoft.com/kwill/2013/08/09/windows-azure-paas-compute-diagnostics-data/ 开始，并特别关注那些谈论 WaHostBootstrapper 的人。

【讨论】：

谢谢。我一直在查看这些日志，但我很难理解它们（请参阅我更新的帖子）。如果您能看一看，将不胜感激。
要回收查看旧的 WaHostBootstrapper 日志之一（即 WaHostBootstrapper.log.001）。 WaHostBootstrapper.log 只是 Azure 尝试运行应用程序的当前迭代，因此它不会显示之前发生的回收。每次角色实例回收时，活动的 WaHostBootstrapper.log 都会归档到 .001、.002 等文件中。
您可以在此处分享您的日志，或者随时通过门户打开支持事件，支持团队可以直接与您合作解决此问题。
也许我误解了回收的含义，但是从上面发布的 WaHostBootstrapper.log 文件中可以明显看出问题。 “删除断开连接的客户端：w3wp.exe (3424)”行。这就是我要说的。据我了解，该进程是角色代码的容器，它会不必要地重新启动。
这不是角色回收。角色回收是指角色主机进程（WaWorkerHost 或 WaIISHost）关闭，然后 Azure（Azure 来宾代理）再次执行整个初始化过程。您所看到的只是 w3wp.exe 关闭，这可能由于多种原因而发生，但不是该实例的完全回收和重新初始化。您在使用 Application Insights 吗？目前 AI 的行为是在配置更改时重新安装，这会导致 w3wp 回收。我们正在研究一个长期解决方案，但目前您可以根据需要禁用 AI。