Investigação detalhada da exceção de tempo limite do WCF

94

Temos um aplicativo que possui um serviço WCF (* .svc) em execução no IIS7 e vários clientes que consultam o serviço. O servidor está executando o Win 2008 Server. Os clientes estão executando o Windows 2008 Server ou o Windows 2003 Server. Estou recebendo a seguinte exceção, que percebi que pode, na verdade, estar relacionada a um grande número de possíveis problemas do 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. 

Aumentei o tempo limite para 30 minutos e o erro ainda ocorreu. Isso me diz que algo mais está em jogo, porque a quantidade de dados nunca levaria 30 minutos para ser carregada ou baixada.

O erro vem e vai. No momento, é mais frequente. Não parece importar se eu tenho 3 clientes rodando simultaneamente ou 100, ainda ocorre de vez em quando. Na maioria das vezes, não há limites de tempo, mas ainda consigo alguns por hora. O erro vem de qualquer um dos métodos invocados. Um desses métodos não possui parâmetros e retorna alguns dados. Outro recebe muitos dados como parâmetro, mas executa de forma assíncrona. Os erros sempre se originam do cliente e nunca fazem referência a nenhum código no servidor no rastreamento da pilha. Sempre termina com:

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

No servidor: Tentei (e atualmente tenho) as seguintes configurações de ligação:

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

Não parece ter impacto.

Eu tentei (e atualmente tenho) as seguintes configurações de limitação:

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

Não parece ter impacto.

Atualmente, tenho as seguintes configurações para o serviço WCF.

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

Eu corri com ConcurrencyMode.Multiple um pouco e o erro ainda ocorreu.

Tentei reiniciar o IIS, reiniciar meu SQL Server subjacente, reiniciar a máquina. Tudo isso parece não ter impacto.

Tentei desativar o firewall do Windows. Não parece ter impacto.

No cliente, tenho estas configurações:

maxReceivedMessageSize="2147483647"

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

Meu cliente fecha suas conexões:

var client = new MyClient();

try
{
    return client.GetConfigurationOptions();
}
finally
{
    client.Close();
}

Mudei as configurações do registro para permitir mais conexões de saída:

MaxConnectionsPerServer=24, MaxConnectionsPer1_0Server=32.

Tentei recentemente o SvcTraceViewer.exe. Consegui pegar uma exceção no lado do cliente. Vejo que sua duração é de 1 minuto. Olhando para o rastreamento do lado do servidor, posso ver que o servidor não está ciente dessa exceção. A duração máxima que consigo ver é de 10 segundos.

Eu olhei para conexões de banco de dados ativas usando exec sp_who no servidor. Eu só tenho alguns (2-3). Eu olhei para conexões TCP de um cliente usando TCPview. Geralmente é cerca de 2-3 e eu vi até 5 ou 6.

Simplificando, estou perplexo. Tentei tudo o que pude encontrar e deve estar faltando algo muito simples que um especialista WCF seria capaz de ver. Tenho a sensação de que algo está bloqueando meus clientes no baixo nível (TCP), antes que o servidor realmente receba a mensagem e / ou que algo está enfileirando as mensagens no nível do servidor e nunca permitindo que sejam processadas.

Se você tiver quaisquer contadores de desempenho que eu deva examinar, entre em contato. (indique quais valores são ruins, pois alguns desses contadores são difíceis de decifrar). Além disso, como posso registrar o tamanho da mensagem WCF? Finalmente, existem ferramentas disponíveis que me permitiriam testar quantas conexões posso estabelecer entre meu cliente e servidor (independentemente de meu aplicativo)

Obrigado pelo seu tempo!

Informações extras adicionadas em 20 de junho:

Meu aplicativo WCF faz algo semelhante ao seguinte.

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

Usando o WireShark, vi que, quando o erro ocorre, tenho cinco retransmissões de TCP seguidas por uma redefinição de TCP posteriormente. Meu palpite é que o RST está vindo do WCF interrompendo a conexão. O relatório de exceção que recebo é do tempo limite da Etapa 3.

Eu descobri isso olhando para o fluxo tcp "tcp.stream eq 192". Em seguida, expandi meu filtro para "tcp.stream eq 192 e http e http.request.method eq POST" e vi 6 POSTs durante esse fluxo. Isso parecia estranho, então verifiquei com outro stream, como tcp.stream eq 100. Tive três POSTs, o que parece um pouco mais normal porque estou fazendo três chamadas. No entanto, eu fecho minha conexão após cada chamada do WCF, então eu esperava uma chamada por fluxo (mas não sei muito sobre TCP).

Investigando um pouco mais, eu despejei a carga do pacote http no disco para ver o que essas seis chamadas eram.

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

Meu palpite é que dois clientes simultâneos estão usando a mesma conexão, por isso vi duplicatas. No entanto, ainda tenho mais alguns problemas que não consigo compreender:

a) Por que o pacote está corrompido? Acaso aleatório da rede - talvez? A carga é compactada usando este código de amostra: http://msdn.microsoft.com/en-us/library/ms751458.aspx - O código pode apresentar erros de vez em quando quando usado simultaneamente? Devo testar sem a biblioteca gzip.

b) Por que eu veria as etapas 1 e 2 em execução APÓS o tempo limite da operação corrompida expirar? Parece-me que essas operações não deveriam ter ocorrido. Talvez eu não esteja olhando para o fluxo certo porque minha compreensão do TCP é falha. Tenho outros streams que ocorrem ao mesmo tempo. Devo investigar outros fluxos - uma rápida olhada nos fluxos 190-194 mostra que o POST do Step3 tem dados de carga útil adequados (não corrompidos). Me empurrando para olhar para a biblioteca gzip novamente.

Jason Kealey
fonte
Jason - você já resolveu esse problema? Era a configuração DefaultConnectionLimit?
SFun 28 de
2
@JasonKealey - Em contraste com muitas outras perguntas, você não pode ser acusado de não tentar por si mesmo antes de postar a pergunta :) Adoro que sua pergunta seja tão detalhada e inclua todos os detalhes importantes. Os sintomas que você descreve são muito parecidos com os meus, então espero que a solução seja a mesma também :)
Øyvind Bråthen

Respostas:

51

Se você estiver usando um cliente .Net, você pode não ter definido

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

aqui está a pergunta original e a resposta Limitação de serviço WCF

Atualizar :

Esta configuração vai para o aplicativo cliente .Net pode estar na inicialização ou a qualquer hora, mas antes de iniciar seus testes.

Além disso, você pode tê-lo no arquivo app.config, bem como seguir

<system.net>
    <connectionManagement>
      <add maxconnection = "200" address ="*" />
    </connectionManagement>
  </system.net>
Mubashar
fonte
Isso parece promissor. Eu incluí isso para ser testado durante meu próximo teste de escalabilidade. Parece exatamente com o tipo de configuração aleatória que faria com que travasse :) Obrigado pelo ponteiro.
Jason Kealey,
1
@Jason: Se você é programador de servidores, sabe o quanto é importante manter a escalabilidade do servidor em suas mãos e também aquele que está atualmente sofrendo de problema de concorrência mesmo após o uso acima. Por favor, se você pode olhar para a seguinte questão stackoverflow.com/questions/2637175/wcf-network-cost em suma, estou sofrendo com latência de 31 ms entre cliente e servidor e preciso reduzi-la.
Mubashar
3
Demorou apenas um ano, mas finalmente executei outro teste de estresse no aplicativo com este sinalizador definido. O problema parece resolvido, então estou lhe dando a melhor resposta. Eu não ficaria surpreso que esta fosse a última peça do quebra-cabeça exigida, mas todos os outros elementos precisavam estar no lugar para garantir que o erro não acontecesse. Muito obrigado!
Jason Kealey
2
@Aris: No aplicativo cliente .net, na inicialização ou onde quer que você defina sua configuração global, se quiser mantê-la configurável, você pode adicioná-la no arquivo de configuração assim como este <system.net> <connectionManagement> <add maxconnection = "200" address = "*" /> </connectionManagement> </system.net>
Mubashar
3

Se você ainda não tentou, encapsule suas operações WCF do lado do servidor em blocos try / finally e adicione o log para garantir que eles estejam realmente retornando.

Se eles mostrarem que as operações estão sendo concluídas, minha próxima etapa seria ir para um nível inferior e examinar a camada de transporte real.

O Wireshark ou outra ferramenta de captura de pacote semelhante pode ser bastante útil neste ponto. Presumo que seja executado em HTTP na porta 80 padrão.

Execute o Wireshark no cliente. Em Opções ao iniciar a captura, defina o filtro de captura paratcp http and host service.example.com - isso reduzirá a quantidade de tráfego irrelevante.

Se possível, modifique seu cliente para notificá-lo da hora exata de início da chamada e a hora em que o tempo limite ocorreu. Ou apenas monitore de perto.

Ao obter um erro, você pode vasculhar os registros do Wireshark para encontrar o início da chamada. Clique com o botão direito no primeiro pacote que tem seu cliente chamando-o (deve ser algo como GET /service.svc ou POST /service.svc) e selecione Seguir fluxo TCP.

O Wireshark decodificará toda a conversação HTTP, para que você possa garantir que o WCF está realmente enviando respostas.


fonte
Eu tenho logado no servidor - não há nenhum erro nessa extremidade. Estou executando o WireShark agora para ver o que posso encontrar. Dado o alto volume de tráfego, será difícil analisar, mas informarei se conseguir encontrar alguma coisa.
Jason Kealey
Eu rodei o WireShark nas últimas seis horas e coletei cerca de 60k frames. Apenas uma exceção foi relatada por este cliente hoje. Eu vi uma conexão TCP marcada como RST (reset), aparentemente depois de enviar o e-mail de erro, que provavelmente é o WCF que está encerrando a conexão. Salvei a carga útil (525k) no disco. Verifiquei que havia 87 outras invocações com cargas úteis de tamanho semelhante. Eu vi algumas retransmissões TCP, mas também vi algumas em outras chamadas (que não falharam). Começando a me perguntar sobre meu hardware de rede + cabos.
Jason Kealey
Mesmo em uma rede local, a presença de um TCP Retransmits não é necessariamente ruim. Se for possível conectar fisicamente dois dos pontos finais a um único switch, talvez valha a pena tentar, mas não tenho esperança de que isso conserte. Se você puder - crie um aplicativo cliente muito básico que apenas passe parte do tráfego para o servidor e para trás, e nada mais. Isso pode ajudar a eliminar qualquer problema em seu aplicativo que possa estar causando tempos limite.
Além disso, você mencionou ter visto o pacote TCP Reset - o servidor entregou algum tipo de resposta naquele ponto (ou talvez estivesse esperando por mais dados)? Houve um atraso considerável entre o RST e o pacote anterior?
O servidor é remoto. Estou planejando criar um ambiente de teste localmente para ver se isso ajuda. Já o RST foi enviado 34 segundos após a última das cinco Retransmissões TCP. (Intervalos de 1 a 8 segundos entre as retransmissões). Isso te dá alguma pista?
Jason Kealey
2

de: http://www.codeproject.com/KB/WCF/WCF_Operation_Timeout_.aspx

Para evitar esse erro de tempo limite, precisamos configurar a propriedade OperationTimeout para Proxy no código do cliente WCF. Essa configuração é algo novo, ao contrário de outras configurações, como Tempo limite de envio, Tempo limite de recebimento etc., que discuti no início do artigo. Para definir essa configuração de propriedade de tempo limite de operação, temos que lançar nosso proxy para IContextChannel no aplicativo cliente WCF antes de chamar os métodos de contrato de operação.

Joel Martinez
fonte
Eu tentei isso. Independentemente do tempo limite que coloquei, ele ainda atinge o tempo limite, mas isso não faz sentido porque a operação não é tão longa e porque todos os outros clientes que fazem as mesmas consultas funcionam durante esse tempo.
Jason Kealey
Meus testes provaram que OperationTimeout simplesmente substitui o ReceiveTimeout da configuração. Portanto, é inútil.
dudeNumber4
2

Estou tendo um problema muito parecido. No passado, isso estava relacionado a problemas de serialização. Se você ainda estiver tendo esse problema, verifique se consegue serializar corretamente os objetos que está retornando. Especificamente, se você estiver usando objetos Linq-To-Sql que têm relacionamentos, haverá problemas de serialização conhecidos se você colocar uma referência anterior em um objeto filho para o objeto pai e marcar essa referência anterior como um DataMember.

Você pode verificar a serialização escrevendo um aplicativo de console que serializa e desserializa seus objetos usando o DataContractSerializer no lado do servidor e quaisquer métodos de serialização que seu cliente use. Por exemplo, em nosso aplicativo atual, temos clientes WPF e Compact Framework. Eu escrevi um aplicativo de console para verificar se posso serializar usando um DataContractSerializer e desserializar usando um XmlDesserializer. Você pode tentar isso.

Além disso, se você estiver retornando objetos Linq-To-Sql que possuem coleções filho, você pode tentar garantir que os carregou antecipadamente no lado do servidor. Às vezes, devido ao carregamento lento, os objetos retornados não são preenchidos e podem causar o comportamento que você está vendo, quando a solicitação é enviada ao método de serviço várias vezes.

Se você já resolveu esse problema, adoraria saber como, porque também estou preso a ele. Eu verifiquei que meu problema não é a serialização, então estou perdido.

ATUALIZAÇÃO: Não tenho certeza se isso irá ajudá-lo, mas a ferramenta Service Trace Viewer apenas resolveu meu problema após 5 dias de experiência muito semelhante à sua. Configurando o rastreamento e examinando o XML bruto, encontrei as exceções que estavam causando meus problemas de serialização. Ele estava relacionado a objetos Linq para SQL que ocasionalmente tinham mais objetos filho do que poderiam ser serializados com êxito. Adicionar o seguinte ao seu arquivo web.config deve permitir o rastreamento:

<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>

O arquivo resultante pode ser aberto com a ferramenta Service Trace Viewer ou apenas no IE para examinar os resultados.

Brett Bim
fonte
2

Você está fechando a conexão com o serviço WCF entre as solicitações? Caso contrário, você verá esse tempo limite exato (eventualmente).

aridlehoover
fonte
2

Acabei de resolver o problema. Descobri que os nós no arquivo App.config foram configurados incorretamente.

<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>

Confirme sua configuração no nó <security>, o valor do atributo "modo" é "Nenhum". Se o seu valor for "Transporte", o erro ocorre.

alexanderlc
fonte
Isso não afeta a segurança? Se for assim, pode não ser uma solução para a maioria das aplicações reais
Veverke,
0

Você tentou usar clientVia para ver a mensagem enviada, usando o kit de ferramentas SOAP ou algo parecido? Isso pode ajudar a ver se o erro está vindo do próprio cliente ou de outro lugar.

Philippe
fonte
Você conhece alguma ferramenta mais recente do que o kit de ferramentas SOAP obsoleto que tornaria mais fácil para mim registrar essas informações em chamadas WCF?
Jason Kealey
O SOAP Toolkit édeprecated
Kiquenet
0

Você verificou os traços do WCF? O WCF tem a tendência de engolir exceções e retornar apenas a última exceção, que é o tempo limite que você está obtendo, uma vez que o ponto final não retornou nada significativo.

Miki Watts
fonte
Tentei o SvcTraceViewer e a única exceção relatada foi o tempo limite (no cliente). Nada foi relatado no servidor.
Jason Kealey
Abra todas as opções no rastreamento; você pode não ter todas as opções de rastreamento abertas. Além disso, verifique os arquivos de rastreamento de eventos e de mensagens.
Miki Watts
0

Você também receberá esse erro se estiver passando um objeto de volta para o cliente que contém uma propriedade do tipo enum que não é definida por padrão e que enum não tem um valor que mapeia para 0. ie enum MyEnum{ a=1, b=2};

tim
fonte
0

Parece que esta mensagem de exceção é bastante genérica e pode ser recebida por vários motivos. Corremos para isso durante a implantação do cliente em máquinas Windows 8.1. Nosso cliente WCF é executado dentro de um serviço do Windows e pesquisa continuamente o serviço WCF. O serviço do Windows é executado em um usuário não administrador. O problema foi corrigido definindo o clientCredentialType como "Windows" na configuração do WCF para permitir a passagem de autenticação, como a seguir:

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

Não sou um especialista em WCF, mas gostaria de saber se você não está executando uma proteção DDOS no IIS. Sei por experiência própria que se você executar várias conexões simultâneas de um único cliente para um servidor em algum ponto, o servidor para de responder às chamadas, pois suspeita de um ataque DDOS. Ele também manterá as conexões abertas até que o tempo limite seja atingido, a fim de diminuir a velocidade do cliente em seus ataques.

No entanto, várias conexões provenientes de máquinas / IPs diferentes não devem ser um problema.

Há mais informações nesta postagem do MSDN:

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

Verifique a sproperty MaxConcurrentSession.

Jurgenb
fonte
Sinto que isso é o que está acontecendo, de tudo o que vi, porém, eu tenho (no servidor): <serviceThrottling maxConcurrentCalls = "150" maxConcurrentInstances = "150" maxConcurrentSessions = "150" /> <serviceDebug includeExceptionDetailInFaults = "true" /> Haveria algum monitor de desempenho ou log do IIS que eu pudesse monitorar para ver se isso está acontecendo?
Jason Kealey