从 Service Fabric SDK 2.0.135 升级到 2.3.301 后,我们开始遇到 Service Fabric actor 或服务无法访问的情况,尽管在 Service Fabric Explorer 中显示为正常运行。一旦处于这种状态,通过 ActorProxy 或 ServiceProxy 对 Actor 或服务的任何调用都将挂起 5 分钟,然后最终给出 TimeoutException。一旦处于这种状态,参与者或服务就永远不会自行恢复——即使离开一个小时。唯一的解决方案是重置参与者或服务所在的节点、重新部署参与者或服务(完全相同的 EXE)、重置整个集群或重新启动所有集群计算机。
通常在部署或重新部署 SF 应用程序后进入此状态。
在使用 Service Fabric 的最后一年(自 SDK v1.3 起),我们从未遇到过此问题。它是在迁移到 2.3.301 后才开始的。
它似乎是随机且不一致地发生的。我们的解决方案中的 13 个 SF 应用程序中的哪一个受到影响也是随机的。
有人对我们如何解决这个问题有任何想法吗?这似乎是最新版本的 Service Fabric 中的一个错误,但也许我们做错了什么。
任何帮助表示赞赏。
下面是很多额外的信息,我希望这些信息有助于理解我们所面临的这个问题。
非常感谢
Steps
我确实没有步骤来一致地重现该问题。这就是我有时观察到的情况。
- 我从 Visual Studio 编译并重新部署了我的 SF 项目(调试 -> 启动而不调试)
- Visual Studio 表示已成功部署该项目
- Service Fabric Explorer 将我的所有服务显示为运行状况良好,包括数据绑定
- 所讨论的 SF 项目有 2 个参与者,它们是单个 EXE 的一部分。 Service Fabric Explorer 显示了在不同节点上运行的每个参与者。
- Windows 任务管理器显示了 EXE 的两个正在运行的副本,这是有道理的,因为有两个节点正在运行 EXE。
同样,我们的 QA 在直接使用 PowerShell 部署到 Azure 后也遇到了该问题。 (他不从 Visual Studio 进行部署。)
To recap
- Visual Studio 表示部署成功
- Service Fabric Explorer 显示一切正常
- 任务管理器显示 EXE 的两个正在运行的副本
当我看到失败时
我有一个 SF 服务使用 ServiceProxy 或 ActorProxy 类调用另一个 SF 服务。我们在整个解决方案中结合了 13 个不同的应用程序和大约 25 个不同的服务和参与者来做到这一点。自从我们于 2015 年 11 月开始使用 Service Fabric SDK v1.3 以来,它一直成功运行。
现在,升级到 2.3.301 后,我们会定期出现随机 Actor 或 Service 进入以下状态:当从 ServiceProxy 或 ActorProxy 调用时,它无法响应对方法的调用。挂起 5 分钟后,我们收到 System.Timeout 异常,并显示以下消息:
如果在服务繁忙或时间较长时消息被丢弃,则可能会发生这种情况
正在运行操作并花费比配置的操作更多的时间
暂停。
请注意,该服务并不繁忙,也没有执行长时间运行的操作。作为参与者,该服务根本不执行任何持续的操作。它只是公开其他服务可以使用的公共方法。从第一次调用开始就失败了。
事实上,跟踪告诉我们,即使是 actor 中方法的第一行never被叫。这就好像 Service Fabric 通信基础结构无法传递消息。
当这一切开始的时候
在过去的 12 个月里,我们从未见过这个问题。
现在,自上周升级 Service Fabric 以来,我们在各种情况下经常看到此问题。
我们升级到 Service Fabric SDK 2.3.301.9590 和 Service Fabric 5.3.301.9590。
起初,团队中的每个开发人员都独立遇到了这个问题,并且每个人都认为这是我们机器的暂时性问题。 Service Fabric 确实存在一些问题,因此我们只能接受并继续。但后来我们开始互相抱怨,并意识到我们都看到了这一点。甚至我们的质量保证人员也在我们即将投入生产的环境中的云中看到了它。
同样,这只是在我们上周升级到最新版本的 Service Fabric 时才开始的。
以前,我们运行的是 Service Fabric SDK 2.0.135。
我们通过安装 SDK v 2.3.301、打开每个解决方案并允许 Visual Studio 进行升级来升级我们的代码库。
环境
我正在具有 16 GB RAM 的 i7 上运行全新安装的 Windows 10 Enterprise(安装时间不到两周)。我全新安装了 Visual Studio 2015 Update 3 和 SF 2.3.301.9590。我把一切都安装干净了。没有升级。
我所有同事的机器(不同的年龄、配置和“新鲜度”)上也发生了这种情况。它偶尔会发生在我们每个人身上。
最重要的是,这种情况也发生在我们 Azure 上的 Service Fabric VM 上。这些是我们的 QA 大约一个月前使用 Azure 上 Service Fabric VM 的标准模板创建的计算机。它预装了 5.3.301.9590。他没有手动安装 Service Fabric 的任何更新。直到开发人员升级到新版本后,我们基于 SF 的应用程序才在 Azure(或我们自己的开发机器)上遇到此问题。
这不是我的机器的问题,也不仅仅与开发环境无关。对我们所有人来说唯一一致的变化是SF版本的更新。
原因
我们不知道是什么原因造成的。
它通常在部署新的 SF 应用程序后立即发生。是的,我们确实会等待 SF 在部署后通常需要 2 或 3 分钟来“弄清楚”。我们已经将其放置了一个小时或更长时间,但它根本不起作用。
有趣的是,我think我有一个 SF 服务,工作正常,然后突然停止工作,但这是在我们意识到存在问题之前,所以我没有寻找它。我不能确定。
解决方法
一旦 SF 服务处于“不可访问”状态,Service Fabric 将无法再次退出该状态。该应用程序完全无法使用。我们做了以下工作,取得了不同程度的成功:
- 重新部署无法访问的SF应用程序
- 重新启动节点(通过 Service Fabric Explorer 转至
节点,单击省略号按钮并单击“重新启动”选项)
托管无法访问的 SF 服务和演员
- 重新启动整个 SF 集群(停止然后启动)
- 重新启动运行 SF 节点的所有计算机
- 重置整个集群并重新部署所有内容(最后的手段,但它
已经需要好几次了)
有趣的是,使用任务管理器来终止有问题的进程并没有帮助。如果我终止有问题的进程,Service Fabric 会重新启动它(按预期),但它仍然不会响应消息。
因此,问题似乎在于 Service Fabric 本身,而不是 EXE。
当然,这些根本不是“解决方案”,因为它们使我们的整个应用程序无法访问,直到 SF 可以重新启动/重新平衡。即使重新启动一些节点也会导致大量内容脱机。
从本质上讲,这对我们来说是一场精彩的表演。如果 Service Fabric 表现出这样的行为,我们不可能将应用程序投入生产(甚至测试版)。
使用 Service Proxy 或 Actor Proxy 时的 C# 异常:
ActorProxy 或 ServicePRoxy 抛出的异常的 JSON 渲染
"exception": {
"ClassName": "System.TimeoutException",
"Message": "This can happen if message is dropped when service is busy or its long running operation and taking more time than configured Operation Timeout.",
"Data": null,
"InnerException": null,
"HelpURL": null,
"StackTraceString": " at Microsoft.ServiceFabric.Services.Communication.Client.ServicePartitionClient`1.<InvokeWithRetryAsync>d__7`1.MoveNext()\r\n--- End of stack trace from previous location where exception was thrown ---\r\n at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)\r\n at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)\r\n at Microsoft.ServiceFabric.Services.Remoting.Client.ServiceRemotingPartitionClient.<InvokeAsync>d__8.MoveNext()\r\n--- End of stack trace from previous location where exception was thrown ---\r\n at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)\r\n at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)\r\n at Microsoft.ServiceFabric.Services.Remoting.Builder.ProxyBase.<InvokeAsync>d__0.MoveNext()\r\n--- End of stack trace from previous location where exception was thrown ---\r\n at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)\r\n at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)\r\n at Microsoft.ServiceFabric.Services.Remoting.Builder.ProxyBase.<ContinueWithResult>d__7`1.MoveNext()\r\n--- End of stack trace from previous location where exception was thrown ---\r\n at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)\r\n at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)\r\n at System.Runtime.CompilerServices.TaskAwaiter`1.GetResult()\r\n at RenderingCachingEngine.RenderingCachingEngine.<Render>d__10.MoveNext() in C:\\Code\\Ink\\Dev\\Current\\Source\\Rendering Service Fabric\\RenderingCachingEngine\\RenderingCachingEngine.cs:line 381",
"RemoteStackTraceString": null,
"RemoteStackIndex": 0,
"ExceptionMethod": "8\nMoveNext\nMicrosoft.ServiceFabric.Services, Version=5.0.0.0, Culture=neutral, PublicKeyToken=31bf3856ad364e35\nMicrosoft.ServiceFabric.Services.Communication.Client.ServicePartitionClient`1+<InvokeWithRetryAsync>d__7`1\nVoid MoveNext()",
"HResult": -2146233083,
"Source": "Microsoft.ServiceFabric.Services",
"WatsonBuckets": null
}
以下是 Service Fabric 信息的 JSON 呈现:
"serviceFabricInfo": {
"serviceFabricServiceName": "fabric:/Rendering/RenderingCachingEngine",
"serviceFabricServiceTypeName": "RenderingCachingEngineType",
"serviceFabricReplicaId": 131225099453058851,
"serviceFabricPartitionId": "e400087d-8a08-4dab-bcdd-1f5ce82f374f",
"serviceFabricApplicationName": "fabric:/Rendering",
"serviceFabricApplicationTypeName": "RenderingType",
"serviceFabricNodeName": "_Node_4"
}
重新部署时事件查看器记录
Windows 事件查看器确实在“应用程序和服务日志 -> Microsoft-Service Fabric -> 管理”下显示了一些值得注意的日志。
当我重新部署应用程序的更新版本时,发生了以下日志(请注意,DataBinding.exe 是包含我的两个 SF Actor 的 EXE 的名称):
Log Name: Microsoft-ServiceFabric/Admin
Source: Microsoft-ServiceFabric
Date: 11/2/2016 2:38:53 PM
Event ID: 256
Task Category: Common
Level: Error
Keywords: Default
User: NETWORK SERVICE
Computer: shayward10.ovx.local
Description:
WriteNode failed. HRESULT=-2147467259, Output=CustomOutput
Event Xml:
<Event xmlns="http://schemas.microsoft.com/win/2004/08/events/event">
<System>
<Provider Name="Microsoft-ServiceFabric" Guid="{CBD93BC2-71E5-4566-B3A7-595D8EECA6E8}" />
<EventID>256</EventID>
<Version>0</Version>
<Level>2</Level>
<Task>1</Task>
<Opcode>0</Opcode>
<Keywords>0x8000000000000001</Keywords>
<TimeCreated SystemTime="2016-11-02T18:38:53.678587200Z" />
<EventRecordID>7620</EventRecordID>
<Correlation />
<Execution ProcessID="4440" ThreadID="7360" />
<Channel>Microsoft-ServiceFabric/Admin</Channel>
<Computer>shayward10.ovx.local</Computer>
<Security UserID="S-1-5-20" />
</System>
<EventData>
<Data Name="id">
</Data>
<Data Name="type">XmlLiteWriter</Data>
<Data Name="text">WriteNode failed. HRESULT=-2147467259, Output=CustomOutput</Data>
</EventData>
</Event>
Log Name: Microsoft-ServiceFabric/Admin
Source: Microsoft-ServiceFabric
Date: 11/2/2016 2:38:54 PM
Event ID: 23073
Task Category: Hosting
Level: Warning
Keywords: Default
User: SYSTEM
Computer: shayward10.ovx.local
Description:
ServiceHostProcess: DataBinding.exe for ApplicationId 805915c7-456c-49d3-af95-62cc44650664 terminated unexpectedly with exit code 3221225786 on node id bf865279ba277deb864a976fbf4c200e
Event Xml:
<Event xmlns="http://schemas.microsoft.com/win/2004/08/events/event">
<System>
<Provider Name="Microsoft-ServiceFabric" Guid="{CBD93BC2-71E5-4566-B3A7-595D8EECA6E8}" />
<EventID>23073</EventID>
<Version>0</Version>
<Level>3</Level>
<Task>90</Task>
<Opcode>0</Opcode>
<Keywords>0x8000000000000001</Keywords>
<TimeCreated SystemTime="2016-11-02T18:38:54.820567800Z" />
<EventRecordID>7621</EventRecordID>
<Correlation />
<Execution ProcessID="6944" ThreadID="3812" />
<Channel>Microsoft-ServiceFabric/Admin</Channel>
<Computer>shayward10.ovx.local</Computer>
<Security UserID="S-1-5-18" />
</System>
<EventData>
<Data Name="id">bf865279ba277deb864a976fbf4c200e</Data>
<Data Name="AppId">805915c7-456c-49d3-af95-62cc44650664</Data>
<Data Name="ReturnCode">3221225786</Data>
<Data Name="ProcessName">DataBinding.exe</Data>
</EventData>
</Event>
Log Name: Microsoft-ServiceFabric/Admin
Source: Microsoft-ServiceFabric
Date: 11/2/2016 2:38:56 PM
Event ID: 256
Task Category: Common
Level: Error
Keywords: Default
User: NETWORK SERVICE
Computer: shayward10.ovx.local
Description:
WriteNode failed. HRESULT=-2147467259, Output=CustomOutput
Event Xml:
<Event xmlns="http://schemas.microsoft.com/win/2004/08/events/event">
<System>
<Provider Name="Microsoft-ServiceFabric" Guid="{CBD93BC2-71E5-4566-B3A7-595D8EECA6E8}" />
<EventID>256</EventID>
<Version>0</Version>
<Level>2</Level>
<Task>1</Task>
<Opcode>0</Opcode>
<Keywords>0x8000000000000001</Keywords>
<TimeCreated SystemTime="2016-11-02T18:38:56.261857600Z" />
<EventRecordID>7627</EventRecordID>
<Correlation />
<Execution ProcessID="4440" ThreadID="8564" />
<Channel>Microsoft-ServiceFabric/Admin</Channel>
<Computer>shayward10.ovx.local</Computer>
<Security UserID="S-1-5-20" />
</System>
<EventData>
<Data Name="id">
</Data>
<Data Name="type">XmlLiteWriter</Data>
<Data Name="text">WriteNode failed. HRESULT=-2147467259, Output=CustomOutput</Data>
</EventData>
</Event>
事件查看器在超时时记录日志
一旦服务处于不可访问状态,尝试调用它会在每个请求上生成以下日志(等待 5 分钟后):
Log Name: Microsoft-ServiceFabric/Admin
Source: Microsoft-ServiceFabric
Date: 11/2/2016 2:44:55 PM
Event ID: 44289
Task Category: FabricTransport
Level: Warning
Keywords: Default
User: NETWORK SERVICE
Computer: shayward10.ovx.local
Description:
Error While Sending Message : FABRIC_E_TIMEOUT
Event Xml:
<Event xmlns="http://schemas.microsoft.com/win/2004/08/events/event">
<System>
<Provider Name="Microsoft-ServiceFabric" Guid="{CBD93BC2-71E5-4566-B3A7-595D8EECA6E8}" />
<EventID>44289</EventID>
<Version>0</Version>
<Level>3</Level>
<Task>173</Task>
<Opcode>0</Opcode>
<Keywords>0x8000000000000001</Keywords>
<TimeCreated SystemTime="2016-11-02T18:44:55.349048200Z" />
<EventRecordID>7629</EventRecordID>
<Correlation />
<Execution ProcessID="18600" ThreadID="8076" />
<Channel>Microsoft-ServiceFabric/Admin</Channel>
<Computer>shayward10.ovx.local</Computer>
<Security UserID="S-1-5-20" />
</System>
<EventData>
<Data Name="id">
</Data>
<Data Name="type">ServiceCommunicationClient</Data>
<Data Name="text">Error While Sending Message : FABRIC_E_TIMEOUT</Data>
</EventData>
</Event>