WCF超时异常详查

Posted

技术标签:

【中文标题】WCF超时异常详查【英文标题】:WCF timeout exception detailed investigation 【发布时间】:2010-11-02 03:52:10 【问题描述】:

我们有一个应用程序,它具有在 IIS7 上运行的 WCF 服务 (*.svc) 以及查询该服务的各种客户端。服务器正在运行 Win 2008 Server。客户端运行 Windows 2008 Server 或 Windows 2003 Server。我收到以下异常,我已经看到它实际上可能与大量潜在的 WCF 问题有关。

System.TimeoutException: The request channel timed out while waiting for a reply after 00:00:59.9320000. Increase the timeout value passed to the call to Request or increase the SendTimeout value on the Binding. The time allotted to this operation may have been a portion of a longer timeout. ---> System.TimeoutException: The HTTP request to 'http://www.domain.com/WebServices/myservice.svc/gzip' has exceeded the allotted timeout of 00:01:00. The time allotted to this operation may have been a portion of a longer timeout. 

我已将超时时间增加到 30 分钟,但仍然出现错误。这告诉我还有别的东西在起作用,因为上传或下载的数据量永远不会花费 30 分钟。

错误来来去去。目前,这种情况更为频繁。如果我同时运行 3 个客户端或 100 个客户端似乎并不重要,它仍然会偶尔发生。大多数时候,没有超时,但我仍然每小时有几个。错误来自任何被调用的方法。其中一种方法没有参数并返回一些数据。另一个接收大量数据作为参数,但异步执行。错误始终源自客户端,并且从不引用堆栈跟踪中服务器上的任何代码。它总是以:

结尾
 at System.Net.HttpWebRequest.GetResponse()
  at System.ServiceModel.Channels.HttpChannelFactory.HttpRequestChannel.HttpChannelRequest.WaitForReply(TimeSpan timeout)

在服务器上: 我已经尝试(并且目前拥有)以下绑定设置:

maxBufferSize="2147483647" maxReceivedMessageSize="2147483647" maxBufferPoolSize="2147483647"

似乎没有影响。

我已经尝试(并且目前拥有)以下限制设置:

<serviceThrottling maxConcurrentCalls="1500"   maxConcurrentInstances="1500"    maxConcurrentSessions="1500"/>

似乎没有影响。

我目前对 WCF 服务有以下设置。

[ServiceBehavior(InstanceContextMode = InstanceContextMode.Single, ConcurrencyMode = ConcurrencyMode.Single)]

我用ConcurrencyMode.Multiple跑了一会儿,还是出现了错误。

我试过重启 IIS,重启我的底层 SQL Server,重启机器。所有这些似乎都没有影响。

我已尝试禁用 Windows 防火墙。它似乎没有影响。

在客户端,我有这些设置:

maxReceivedMessageSize="2147483647"

<system.net>
    <connectionManagement>
    <add address="*" maxconnection="16"/>
</connectionManagement> 
</system.net>

我的客户端关闭了它的连接:

var client = new MyClient();

try

    return client.GetConfigurationOptions();

finally

    client.Close();

我已更改注册表设置以允许更多传出连接:

MaxConnectionsPerServer=24, MaxConnectionsPer1_0Server=32.

我最近刚刚尝试了 SvcTraceViewer.exe。我设法在客户端捕获了一个异常。我看到它的持续时间是 1 分钟。查看服务器端跟踪,我可以看到服务器没有意识到这个异常。我能看到的最长持续时间是 10 秒。

我查看了在服务器上使用exec sp_who 的活动数据库连接。我只有几个(2-3)。我使用 TCPview 查看了来自一个客户端的 TCP 连接。通常是 2-3 左右,我见过最多 5 或 6 个。

简单地说,我被难住了。我已经尝试了我能找到的所有东西,并且一定缺少 WCF 专家能够看到的非常简单的东西。我的直觉是,在服务器实际接收到消息之前,某些东西在低级别(TCP)阻塞了我的客户端,和/或某些东西正在服务器级别对消息进行排队,并且永远不会让它们处理。

如果您有任何我应该查看的性能计数器,请告诉我。 (请指出哪些值是错误的,因为其中一些计数器很难破译)。另外,我如何记录 WCF 消息大小?最后,我们那里有什么工具可以让我测试我可以在客户端和服务器之间建立多少连接(独立于我的应用程序)

感谢您的宝贵时间!

6 月 20 日添加的额外信息:

我的 WCF 应用程序执行与以下类似的操作。

while (true)

   Step1GetConfigurationSettingsFromServerViaWCF(); // can change between calls
   Step2GetWorkUnitFromServerViaWCF();
   DoWorkLocally(); // takes 5-15minutes. 
   Step3SendBackResultsToServerViaWCF();

使用 WireShark,我确实看到当错误发生时,我有五次 TCP 重新传输,然后是 TCP 重置。我的猜测是 RST 来自 WCF 终止连接。我得到的异常报告来自 Step3 超时。

我通过查看 tcp 流“tcp.stream eq 192”发现了这一点。然后,我将过滤器扩展到“tcp.stream eq 192 和 http 和 http.request.method eq POST”,并在此流中看到 6 个 POST。这看起来很奇怪,所以我检查了另一个流,例如 tcp.stream eq 100。我有三个 POST,这似乎更正常一些,因为我正在进行三个调用。但是,我在每次 WCF 调用后都会关闭我的连接,所以我希望每个流调用一次(但我对 TCP 了解不多)。

再调查一下,我将 http 数据包负载转储到磁盘上,看看这六个在哪里调用。

1) Step3
2) Step1
3) Step2
4) Step3 - corrupted
5) Step1
6) Step2

我的猜测是两个并发客户端使用相同的连接,这就是我看到重复的原因。但是,我还有一些我无法理解的问题:

a) 为什么数据包损坏了?随机网络侥幸——也许吧?使用此示例代码对负载进行 gzip 压缩:http://msdn.microsoft.com/en-us/library/ms751458.aspx - 代码在同时使用时会偶尔出现错误吗?我应该在没有 gzip 库的情况下进行测试。

b) 为什么在损坏的操作超时后我会看到第 1 步和第 2 步正在运行?在我看来,这些操作似乎不应该发生。也许我没有看到正确的流,因为我对 TCP 的理解是有缺陷的。我有其他同时发生的流。我应该调查其他流 - 快速浏览流 190-194 表明 Step3 POST 具有正确的有效负载数据(未损坏)。促使我再次查看 gzip 库。

【问题讨论】:

Jason - 你解决过这个问题吗?是 DefaultConnectionLimit 设置吗? @JasonKealey - 与许多其他问题相比,不能指责您在发布问题之前没有自己尝试 :) 我喜欢您的问题如此详细,并包含所有重要细节。您描述的症状看起来很像我,所以我希望解决方案也一样:) 【参考方案1】:

如果您使用的是 .Net 客户端,那么您可能没有设置

//This says how many outgoing connection you can make to a single endpoint. Default Value is 2
System.Net.ServicePointManager.DefaultConnectionLimit = 200;

这里是原始问答WCF Service Throttling

更新

.Net 客户端应用程序中的此配置可能在启动时或任何时候但在开始测试之前。

此外,您还可以将它放在 app.config 文件中,也可以像下面一样

<system.net>
    <connectionManagement>
      <add maxconnection = "200" address ="*" />
    </connectionManagement>
  </system.net>

【讨论】:

这看起来很有希望。我已将其包括在我的下一次可扩展性测试中进行测试。它看起来完全像那种会使其崩溃的随机设置 :) 感谢您的指点。 @Jason:如果您是服务器程序员,您就会知道维护手中服务器的可伸缩性是多么重要,并且即使在使用上述方法后,您也知道目前正在遭受并发问题的困扰。如果您可以查看以下问题***.com/questions/2637175/wcf-network-cost,简而言之,我正在遭受客户端和服务器之间 31 毫秒的延迟,需要减少它。 只花了一年的时间,但我终于用这个标志对应用程序进行了另一次压力测试。问题似乎解决了,所以我给你最好的答案。我不会感到惊讶,这是所需的最后一块拼图,但所有其他元素都需要到位以确保错误不会发生。非常感谢! @Aris:在 .net 客户端应用程序中,在启动时或您设置全局配置的任何位置,如果您想保持可配置,您可以像这样将其添加到配置文件中 【参考方案2】:

如果您还没有尝试过 - 将您的服务器端 WCF 操作封装在 try/finally 块中,并添加日志记录以确保它们实际返回。

如果这些显示操作正在完成,那么我的下一步将是进入较低级别,并查看实际的传输层。

此时,Wireshark 或其他类似的数据包捕获工具可能会很有帮助。我假设这是在标准端口 80 上通过 HTTP 运行的。

在客户端上运行 Wireshark。在开始捕获时的选项中,将捕获过滤器设置为tcp http and host service.example.com - 这将减少不相关的流量。

如果可以,请修改您的客户端以通知您调用的确切开始时间,以及发生超时的时间。或者只是密切监视它。

当您遇到错误时,您可以浏览 Wireshark 日志以找到调用的开始。右键单击客户端调用的第一个数据包(应该类似于 GET /service.svc 或 POST /service.svc),然后选择 Follow TCP Stream。

Wireshark 将对整个 HTTP 对话进行解码,因此您可以确保 WCF 实际上正在发回响应。

【讨论】:

我已登录服务器 - 没有错误。我现在正在运行 WireShark,看看我能找到什么。鉴于流量很大,分析起来会很痛苦,但如果我能找到任何东西,我会回来报告。 我在过去六个小时内运行了 WireShark,收集了大约 60k 帧。该客户今天只报告了一个异常。我确实看到了一个标记为 RST(重置)的 TCP 连接,显然是在发送错误电子邮件之后,这可能是正在终止连接的 WCF。我将有效负载(525k)保存到磁盘。我验证了有 87 个其他调用具有类似大小的有效负载。我确实看到了一些 TCP 重传,但在其他调用中也看到了一些(没有失败)。开始怀疑我的网络硬件 + 电缆。 即使在本地网络上,TCP Retransmits 的存在也不一定是坏事。如果可以将两个端点物理连接​​到一个交换机,那么这可能值得一试,但我不希望能解决它。如果可以 - 创建一个非常基本的客户端应用程序,它只是将一些流量来回传递到您的服务器,而不是其他任何东西。这有助于消除您的应用程序中可能导致超时的任何问题。 另外,您提到看到 TCP 重置数据包——当时服务器是否发送了任何类型的响应(或者它是否正在等待更多数据)? RST 和前一个数据包之间是否存在明显的延迟? 服务器是远程的。我计划在本地创建一个测试环境,看看是否有帮助。至于 RST,它是在五次 TCP 重传中的最后一次后 34 秒发送的。 (重传之间的间隔为 1 到 8 秒)。这给你任何线索吗?【参考方案3】:

来自:http://www.codeproject.com/KB/WCF/WCF_Operation_Timeout_.aspx

为了避免这个超时错误,我们需要 配置 OperationTimeout WCF 客户端中代理的属性 代码。这个配置有点意思 新的不同于其他配置,例如 如发送超时、接收超时等, 我在早期讨论过 文章。设置此操作超时 属性配置,我们要 将我们的代理转换为 IContextChannel 调用之前的 WCF 客户端应用程序 操作合约方法。

【讨论】:

我试过这个。不管我设置了多少超时,它仍然会超时,但这没有任何意义,因为操作并没有那么长,而且所有其他执行相同查询的客户端都在这段时间内运行。 我的测试证明 OperationTimeout 只是覆盖了配置中的 ReceiveTimeout。因此,它没有任何用处。【参考方案4】:

我有一个非常相似的问题。在过去,这与序列化问题有关。如果您仍然遇到此问题,您能否验证您是否可以正确序列化您返回的对象。具体来说,如果您使用的是具有关系的 Linq-To-Sql 对象,那么如果您将子对象上的反向引用放在父对象上并将该反向引用标记为 DataMember,则会出现已知的序列化问题。

您可以通过编写一个控制台应用程序来验证序列化,该应用程序使用服务器端的 DataContractSerializer 以及您的客户端使用的任何序列化方法对您的对象进行序列化和反序列化。例如,在我们当前的应用程序中,我们同时拥有 WPF 和 Compact Framework 客户端。我编写了一个控制台应用程序来验证我可以使用 DataContractSerializer 进行序列化并使用 XmlDesserializer 进行反序列化。你可以试试。

此外,如果您要返回具有子集合的 Linq-To-Sql 对象,您可能会尝试确保已在服务器端急切地加载它们。有时,由于延迟加载,返回的对象未填充,可能会导致您看到多次将请求发送到服务方法的行为。

如果您已经解决了这个问题,我很想听听如何解决,因为我也被它困住了。我已经验证我的问题不是序列化,所以我很茫然。

更新:我不确定它是否会对您有所帮助,但服务跟踪查看器工具在与您的体验非常相似的 5 天后刚刚解决了我的问题。通过设置跟踪然后查看原始 XML,我发现了导致我的序列化问题的异常。它与 Linq-to-SQL 对象有关,这些对象有时具有比成功序列化更多的子对象。将以下内容添加到您的 web.config 文件应该启用跟踪:

<sharedListeners>
    <add name="sharedListener"
         type="System.Diagnostics.XmlWriterTraceListener"
         initializeData="c:\Temp\servicetrace.svclog" />
  </sharedListeners>
  <sources>
    <source name="System.ServiceModel" switchValue="Verbose, ActivityTracing" >
      <listeners>
        <add name="sharedListener" />
      </listeners>
    </source>
    <source name="System.ServiceModel.MessageLogging" switchValue="Verbose">
      <listeners>
        <add name="sharedListener" />
      </listeners>
    </source>
  </sources>

可以使用服务跟踪查看器工具打开生成的文件,或者仅在 IE 中打开以检查结果。

【讨论】:

【参考方案5】:

您是否在请求之间关闭与 WCF 服务的连接?如果你不这样做,你会看到这个确切的超时(最终)。

【讨论】:

【参考方案6】:

您是否尝试使用clientVia 查看发送的消息,使用SOAP toolkit 或类似的方式?这有助于查看错误是来自客户端本身还是来自其他地方。

【讨论】:

您是否知道比已弃用的 SOAP 工具包更新的工具可以让我更轻松地在 WCF 调用中记录此信息? SOAP 工具包deprecated【参考方案7】:

您检查过 WCF 跟踪吗? WCF 倾向于吞下异常并且只返回最后一个异常,这是您得到的超时,因为端点没有返回任何有意义的东西。

【讨论】:

我尝试了 SvcTraceViewer,它报告的唯一异常是超时(在客户端)。服务器上没有报告任何内容。 打开跟踪上的所有选项,您可能没有打开所有跟踪选项。另外,检查事件跟踪和消息跟踪文件。【参考方案8】:

刚刚解决了问题,发现App.config文件中的节点配置错误。

<client>
<endpoint name="WCF_QtrwiseSalesService" binding="wsHttpBinding" bindingConfiguration="ws" address="http://cntgbs1131:9005/MyService/TGE.ISupplierClientManager" contract="*">
</endpoint>
</client>

<bindings>
    <wsHttpBinding>
        <binding name="ws" maxBufferPoolSize="2147483647" maxReceivedMessageSize="2147483647" messageEncoding="Text">
            <readerQuotas maxDepth="2147483647" maxStringContentLength="2147483647" maxArrayLength="2147483647" maxBytesPerRead="2147483647" maxNameTableCharCount="2147483647"/>
            <**security mode="None">**
                <transport clientCredentialType="None"></transport>
            </security>
        </binding>
    </wsHttpBinding>
</bindings>

在节点&lt;security&gt;中确认你的配置,属性“mode”的值为“None”。如果您的值为“Transport”,则会发生错误。

【讨论】:

这不会影响安全吗?如果是这样,这可能不是大多数实际应用程序的解决方案【参考方案9】:

如果您将一个对象传递回客户端,该对象包含默认情况下未设置的枚举类型属性并且该枚举没有映射到 0 的值,您也会收到此错误。即enum MyEnum a=1, b=2;

【讨论】:

【参考方案10】:

看起来这个异常消息很笼统,可能由于各种原因而被接收。我们在 Windows 8.1 机器上部署客户端时遇到了这个问题。我们的 WCF 客户端在 Windows 服务内部运行并不断轮询 WCF 服务。 Windows 服务在非管理员用户下运行。通过在 WCF 配置中将 clientCredentialType 设置为“Windows”以允许身份验证通过,该问题已得到解决,如下所示:

      <security mode="None">
        <transport clientCredentialType="Windows" proxyCredentialType="None"
          realm="" />
        <message clientCredentialType="UserName" algorithmSuite="Default" />
      </security>

【讨论】:

【参考方案11】:

我不是 WCF 专家,但我想知道您是否没有在 IIS 上遇到 DDOS 保护。 我从经验中知道,如果您在某个时候从单个客户端到服务器运行一堆同时连接,则服务器会停止响应调用,因为它怀疑受到 DDOS 攻击。 它还将保持连接打开,直到它们超时,以减慢客户端的攻击速度。

但是,来自不同机器/IP 的多个连接应该不是问题。

此 MSDN 帖子中有更多信息:

http://msdn.microsoft.com/en-us/library/bb463275.aspx

查看 MaxConcurrentSession 属性。

【讨论】:

我觉得这是正在发生的事情,从我所看到的一切来看,但是我有(在服务器上): 是否有任何性能监视器或 IIS 日志可供我监视以查看是否发生这种情况?

以上是关于WCF超时异常详查的主要内容,如果未能解决你的问题,请参考以下文章

WCF:OneWay OperationContract 上的异常处理

操作已超时 WCF Rest

wcf wsdualhttpbinding超时问题

mysql 视图中的 WCF 数据服务超时问题

打开操作未在分配的 00:01:00 超时内完成 - AX 2012 使用 AIF/WCF

服务端增加WCF服务全局异常处理机制