WCF超时异常详细调查

94

我们有一个应用程序,在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 and http and http.request.method eq POST”,并在此流中看到了6个 POST。这似乎很奇怪,所以我检查了另一个流,如 tcp.stream eq 100。我有三个 POSTs,这似乎更正常,因为我正在进行三个调用。但是,我在每次 WCF 调用之后关闭连接,所以我期望每个流只有一个调用(但我不知道 TCP 太多)。
再进一步调查,我将 HTTP 数据包转储到磁盘上,以查看这六个调用的内容。
1) Step3
2) Step1
3) Step2
4) Step3 - corrupted
5) Step1
6) Step2

我猜测可能有两个并发客户端在使用同一连接,这就是为什么我看到了重复的东西。但是,我仍然有一些问题无法理解:

a)为什么数据包会损坏?可能是随机网络故障吗?负载是使用此示例代码进行压缩的:http://msdn.microsoft.com/en-us/library/ms751458.aspx - 并发使用该代码时是否会出现错误?我应该在没有gzip库的情况下进行测试。

b)为什么在操作超时后我还能看到步骤1和步骤2在运行?我认为这些操作不应该发生。也许我没有查看正确的流,因为我对TCP的理解有误。我有其他同时发生的流。我应该调查其他流——快速浏览流190-194表明Step3 POST具有正确的有效负载数据(不是损坏的)。这推动我再次关注gzip库。


Jason - 你解决了这个问题吗?是DefaultConnectionLimit设置的问题吗? - Suraj
2
@JasonKealey - 与许多其他问题不同的是,您在发布问题之前已经进行了尝试,因此不会被指责没有自己尝试。我喜欢您的问题非常详细,并包含所有重要细节。您描述的症状非常像我的,因此我希望解决方案也相同 :) - Øyvind Bråthen
11个回答

52

如果您正在使用.Net客户端,则可能未设置

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

以下是原始问题和答案:WCF服务限流

更新:

这个配置应该放在.NET客户端应用程序中,可以在启动测试之前的任何时间设置。

此外,您还可以像以下示例一样将其保存在app.config文件中。

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

这看起来很有前途。我已经将其包含在我的下一个可扩展性测试中进行测试。它看起来正是那种可能会导致崩溃的随机设置 :) 感谢您的指引。 - Jason Kealey
1
@Jason:如果你是服务器程序员,你知道在你手中维护服务器的可扩展性有多重要,而且即使使用以上方法仍然遇到并发问题的人也很多。请看一下以下问题:http://stackoverflow.com/questions/2637175/wcf-network-cost。简而言之,我正在遭受客户端和服务器之间31毫秒的延迟问题,需要减少它。 - Mubashar
3
只用了一年时间,但我终于又运行了一个设置了这个标志的应力测试。问题似乎已经解决,所以我会给你最佳答案。我不会感到惊讶,如果这是所需的最后一块拼图,但所有其他元素都需要齐全才能确保不会发生错误。非常感谢! - Jason Kealey
2
@Aris:在 .net 客户端应用程序中,在启动或任何设置全局配置的地方,如果您想保持其可配置性,也可以将其添加到配置文件中,如下所示:<system.net> <connectionManagement> <add maxconnection = "200" address ="*" /> </connectionManagement> </system.net> - Mubashar

3

如果你还没有尝试过,那么请在服务器端的WCF操作中加入try/finally块,并添加日志以确保它们确实返回了。

如果这些操作已完成,请进一步检查底层传输层。此时Wireshark或其他类似的数据包捕获工具可帮助解决问题。我假设它是在标准端口80上通过HTTP运行的。

在客户端上运行Wireshark,在启动捕获时的选项中,将捕获过滤器设置为tcp http and host service.example.com - 这样可以减少无关流量。

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

当出现错误时,您可以浏览Wireshark日志以找到调用的开始。右键单击第一个包(应该是GET /service.svc或POST /service.svc)并选择跟随TCP流。

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


我已经在服务器上记录了日志 - 那一端没有错误。我现在正在运行WireShark,看看我能找到什么。鉴于高流量,分析会很困难,但如果我发现了任何问题,我会报告。 - Jason Kealey
我在过去的六个小时内运行了WireShark并收集了大约60k帧。今天这个客户端只报告了一个异常。我确实看到了一个标记为RST(重置)的TCP连接,显然是在发送错误电子邮件后,可能是WCF终止了连接。我将有效载荷(525k)保存到磁盘中。我验证了还有87个其他调用具有类似大小的有效载荷。我确实看到了一些TCP重传,但在其他调用中也看到了一些(没有失败)。开始怀疑我的网络硬件+电缆。 - Jason Kealey
即使在本地网络上,TCP重传的存在也不一定是坏事。如果可以将两个端点物理连接到单个交换机,则可能值得一试,但我不会抱有希望认为这样做会解决问题。如果可以,请创建一个非常基本的客户端应用程序,只需来回传递一些流量到您的服务器,什么都不需要。这可以帮助消除您的应用程序可能导致超时的任何问题。 - user111013
此外,您提到看到 TCP 复位数据包 - 此时服务器是否已经发送任何响应(或者等待更多数据)?在 RST 数据包和之前的数据包之间是否有明显的延迟? - user111013
服务器是远程的。我计划在本地创建一个测试环境,看看是否有所帮助。至于RST,在五次TCP重传的最后一次之后34秒被发送。(重传之间间隔1到8秒)。这能给您提供任何线索吗? - Jason Kealey
因此,如果服务器在连续5次重传且没有收到确认后发送RST数据包,则似乎您的客户端正在丢弃数据包(由于某种原因)。我肯定会创建一个独立的客户端,即使它直接与常规服务器通信。可能有许多问题导致客户端丢失数据包(其他线程阻塞执行,其他应用程序占用资源,硬件故障,网络,防火墙等)。 - user111013

2
我遇到了非常类似的问题。过去,这与序列化问题有关。如果您仍然遇到此问题,请验证您是否可以正确地序列化返回的对象。特别是,如果您正在使用具有关系的Linq-To-Sql对象,则已知如果在子对象上放置对父对象的反向引用并将该反向引用标记为DataMember,则存在序列化问题。
您可以编写一个控制台应用程序,在服务器端使用DataContractSerializer对对象进行序列化和反序列化,并使用客户端使用的任何序列化方法来验证序列化。例如,在我们当前的应用程序中,我们有WPF和Compact Framework客户端。我编写了一个控制台应用程序来验证我可以使用DataContractSerializer进行序列化并使用XmlDesserializer进行反序列化。您可以尝试一下。
另外,如果您返回具有子集合的Linq-To-Sql对象,请尝试确保您已经在服务器端上急切地加载它们。有时,由于惰性加载,返回的对象未被填充,可能会导致您看到请求多次发送到服务方法的行为。
如果您解决了此问题,我很想听听您的解决方案,因为我也遇到了同样的问题。我已经验证过我的问题不是序列化问题,所以我感到困惑。
更新:我不确定它是否会对您有所帮助,但Service Trace Viewer工具刚刚在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>

生成的文件可以使用Service Trace Viewer工具打开,也可以在IE中打开以检查结果。

2

您是否在请求之间关闭了与WCF服务的连接?如果没有关闭,最终您将看到这个确切的超时错误。


2

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

为了避免这种超时错误,我们需要在WCF客户端代码中为代理配置OperationTimeout属性。与其他配置(如发送超时、接收超时等)不同的是,这个配置是新的。在本文早期我已经讨论过其他配置。要设置此操作超时属性配置,我们必须在调用操作契约方法之前将代理转换为IContextChannel。


我已经尝试过了。无论我设置多长的超时时间,它仍然会超时,但这毫无意义,因为该操作并不那么耗时,并且在此期间执行相同查询的所有其他客户端都能正常运行。 - Jason Kealey
我的测试证明,OperationTimeout 只是覆盖了配置中的 ReceiveTimeout。因此,它完全没有用处。 - dudeNumber4

0

我刚刚解决了这个问题。我发现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>

确认在节点<security>中的配置,属性"mode"的值为"None"。如果您的值为"Transport",则会出现错误。


这难道不会影响安全性吗?如果是这样,那么对于大多数实际应用程序来说,这可能不是一个解决方案。 - Veverke

0

看起来这个异常信息相当通用,可能由于各种原因而收到。我们在部署客户端到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>

0
你试过使用 clientVia 来查看消息发送情况了吗?可以使用 SOAP toolkit 或类似工具,这有助于确定错误是来自客户端本身还是其他地方。

你知道有哪些比过时的SOAP工具包更新的工具,可以让我更容易地记录WCF调用中的信息吗? - Jason Kealey
SOAP Toolkit 已经被*弃用*。 - Kiquenet

0

我不是WCF专家,但我想知道你是否在IIS上遇到了DDOS保护问题。

我知道从经验上讲,如果你从单个客户端向服务器运行大量同时连接,那么在某些时候,服务器会停止响应调用,因为它怀疑是DDOS攻击。它还会保持连接打开直到超时,以便减缓客户端的攻击速度。

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

在这篇MSDN文章中有更多信息:

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

请查看MaxConcurrentSession属性。


我觉得这就是正在发生的事情,从我所看到的一切来看,但是我在服务器上有以下设置: <serviceThrottling maxConcurrentCalls="150" maxConcurrentInstances="150" maxConcurrentSessions="150"/> <serviceDebug includeExceptionDetailInFaults="true" />是否有任何性能监视器或IIS日志可以监视以查看是否发生了这种情况? - Jason Kealey

0

你有检查WCF的跟踪吗?WCF有一个吞噬异常并仅返回最后一个异常的倾向,这就是你得到超时的原因,因为终结点没有返回任何有意义的内容。


我尝试了SvcTraceViewer,它唯一报告的异常是超时(在客户端)。服务器上没有任何报告。 - Jason Kealey
打开跟踪中的所有选项,您可能没有打开所有跟踪选项。此外,请检查事件跟踪和消息跟踪文件。 - Miki Watts

网页内容由stack overflow 提供, 点击上面的
可以查看英文原文,
原文链接