Enquête détaillée sur l'exception de dépassement de délai WCF

Question

Nous avons une application qui a un service WCF (*.svc) fonctionnant sur IIS7 et plusieurs clients qui interrogent le service. Le serveur fonctionne sous Win 2008 Server. Les clients utilisent soit Windows 2008 Server, soit Windows 2003 Server. J'obtiens l'exception suivante, dont j'ai constaté qu'elle peut en fait être liée à un grand nombre de problèmes WCF potentiels.

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. 

J'ai augmenté le délai d'attente à 30 minutes et l'erreur est toujours présente. Cela m'indique que quelque chose d'autre est en jeu, car la quantité de données ne pourrait jamais prendre 30 minutes à charger ou à télécharger.

L'erreur va et vient. En ce moment, elle est plus fréquente. Peu importe que j'aie 3 clients en cours d'exécution simultanément ou 100, elle se produit toujours de temps en temps. La plupart du temps, il n'y a pas de délais d'attente, mais j'en ai quand même quelques-uns par heure. L'erreur provient de l'une des méthodes invoquées. L'une de ces méthodes n'a pas de paramètres et renvoie un peu de données. Une autre prend beaucoup de données en paramètre mais s'exécute de manière asynchrone. Les erreurs proviennent toujours du client et ne font jamais référence à un quelconque code sur le serveur dans la trace de la pile. Elle se termine toujours par :

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

Sur le serveur : J'ai essayé (et j'ai actuellement) les paramètres de liaison suivants :

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

Il ne semble pas avoir d'impact.

J'ai essayé (et j'ai actuellement) les paramètres d'étranglement suivants :

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

Il ne semble pas avoir d'impact.

J'ai actuellement les paramètres suivants pour le service WCF.

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

J'ai couru avec ConcurrencyMode.Multiple pendant un moment, et l'erreur se produisait toujours.

J'ai essayé de redémarrer IIS, de redémarrer mon serveur SQL sous-jacent, de redémarrer la machine. Toutes ces tentatives ne semblent pas avoir d'impact.

J'ai essayé de désactiver le pare-feu de Windows. Cela ne semble pas avoir d'impact.

Sur le client, j'ai ces paramètres :

maxReceivedMessageSize="2147483647"

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

Mon client ferme ses connexions :

var client = new MyClient();

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

J'ai modifié les paramètres du registre pour autoriser davantage de connexions sortantes :

MaxConnectionsPerServer=24, MaxConnectionsPer1_0Server=32.

Je viens d'essayer SvcTraceViewer.exe. J'ai réussi à attraper une exception du côté du client. Je vois que sa durée est de 1 minute. En regardant la trace côté serveur, je peux voir que le serveur n'est pas au courant de cette exception. La durée maximale que je peux voir est de 10 secondes.

J'ai examiné les connexions actives à la base de données en utilisant exec sp_who sur le serveur. Je n'en ai que quelques-uns (2-3). J'ai examiné les connexions TCP d'un client en utilisant TCPview. Elles sont généralement au nombre de 2-3 et j'en ai vu jusqu'à 5 ou 6.

Pour faire simple, je suis dans l'impasse. J'ai essayé tout ce que j'ai pu trouver, et je dois manquer quelque chose de très simple qu'un expert WCF serait capable de voir. J'ai l'impression que quelque chose bloque mes clients au niveau inférieur (TCP), avant que le serveur ne reçoive réellement le message et/ou que quelque chose met les messages en file d'attente au niveau du serveur et ne les laisse jamais se traiter.

Si vous avez des compteurs de performance que je devrais examiner, faites-le moi savoir. (veuillez indiquer quelles valeurs sont mauvaises, car certains de ces compteurs sont difficiles à décrypter). De même, comment pourrais-je enregistrer la taille des messages WCF ? Enfin, existe-t-il des outils qui me permettraient de tester le nombre de connexions que je peux établir entre mon client et mon serveur (indépendamment de mon application) ?

Merci pour votre temps !

Informations supplémentaires ajoutées le 20 juin :

Mon application WCF fait quelque chose de similaire à ce qui suit.

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

En utilisant WireShark, j'ai vu que lorsque l'erreur se produit, j'ai cinq retransmissions TCP suivies d'une réinitialisation TCP plus tard. Je pense que le RST provient de WCF qui coupe la connexion. Le rapport d'exception que je reçois provient de l'arrêt de l'étape 3.

J'ai découvert cela en regardant le flux tcp "tcp.stream eq 192". J'ai ensuite étendu mon filtre à "tcp.stream eq 192 and http and http.request.method eq POST" et j'ai vu 6 POSTs durant ce flux. Cela semblait étrange, j'ai donc vérifié avec un autre flux tel que tcp.stream eq 100. J'ai eu trois POST, ce qui semble un peu plus normal car je fais trois appels. Cependant, je ferme ma connexion après chaque appel WCF, donc je me serais attendu à un appel par flux (mais je ne connais pas beaucoup le TCP).

En enquêtant un peu plus, j'ai vidé la charge de paquets http sur le disque pour voir à quoi correspondaient ces six appels.

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

Je pense que deux clients simultanés utilisent la même connexion, c'est pourquoi j'ai vu des doublons. Cependant, j'ai encore quelques autres problèmes que je n'arrive pas à comprendre :

a) Pourquoi le paquet est-il corrompu ? Un hasard du réseau - peut-être ? Le chargement est gzippé en utilisant cet exemple de code : http://msdn.microsoft.com/en-us/library/ms751458.aspx - Le code pourrait-il être bogué de temps en temps lorsqu'il est utilisé simultanément ? Je devrais tester sans la bibliothèque gzip.

b) Pourquoi l'étape 1 et l'étape 2 s'exécutent-elles APRÈS la fin de l'opération corrompue ? Il me semble que ces opérations n'auraient pas dû avoir lieu. Peut-être que je ne regarde pas le bon flux parce que ma compréhension du TCP est imparfaite. J'ai d'autres flux qui se produisent en même temps. Je devrais examiner d'autres flux - un coup d'œil rapide aux flux 190-194 montre que le POST Step3 a des données utiles correctes (non corrompues). Cela me pousse à regarder à nouveau la bibliothèque gzip.

Answer 1

Si vous utilisez un client .Net, il se peut que vous n'ayez pas configuré l'option

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

Voici la question et la réponse originales Throttling de service WCF

Mise à jour :

Cette configuration doit être placée dans l'application client .Net, au démarrage ou à tout moment, mais avant de lancer vos tests.

De plus, vous pouvez l'avoir dans le fichier app.config comme suit

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

Answer 2

Si vous ne l'avez pas déjà essayé - encapsulez vos opérations WCF côté serveur dans des blocs try/finally, et ajoutez la journalisation pour assurer qu'ils retournent réellement.

S'ils montrent que les opérations se terminent, l'étape suivante consisterait à passer à un niveau inférieur et à examiner la couche de transport proprement dite.

Wireshark ou un autre outil similaire de capture de paquets peut être très utile à ce stade. Je suppose que cela fonctionne sur HTTP sur le port standard 80.

Exécutez Wireshark sur le client. Dans les Options, lorsque vous lancez la capture, définissez le filtre de capture sur tcp http and host service.example.com - cela réduira la quantité de trafic non pertinent.

Si vous le pouvez, modifiez votre client pour qu'il vous indique l'heure exacte de début de l'appel et l'heure à laquelle le délai d'attente s'est produit. Ou alors, surveillez-le de près.

Lorsque vous obtenez une erreur, vous pouvez alors parcourir les journaux de Wireshark pour trouver le début de l'appel. Cliquez avec le bouton droit de la souris sur le premier paquet sur lequel votre client appelle (cela devrait être quelque chose comme GET /service.svc ou POST /service.svc) et sélectionnez Follow TCP Stream.

Wireshark décodera la Conversation HTTP entière, ainsi vous pouvez assurer que WCF renvoie réellement des réponses.

Answer 3

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

Pour éviter cette erreur de délai, nous devons de configurer le OperationTimeout pour Proxy dans le client WCF du client WCF. Cette configuration est quelque chose de nouvelle contrairement aux autres configurations telles que comme Send Timeout, Receive Timeout etc, dont j'ai parlé au début de cet article. Pour définir cette configuration de la propriété nous devons transformer notre proxy en IContextChannel dans l'application client WCF avant d'appeler les méthodes du contrat d'opération.

Answer 4

J'ai un problème très similaire. Dans le passé, cela a été lié à des problèmes de sérialisation. Si vous rencontrez toujours ce problème, pouvez-vous vérifier que vous pouvez sérialiser correctement les objets que vous renvoyez. Plus précisément, si vous utilisez des objets Linq-To-Sql qui ont des relations, il y a des problèmes de sérialisation connus si vous mettez une référence arrière sur un objet enfant à l'objet parent et marquez cette référence arrière comme un DataMember.

Vous pouvez vérifier la sérialisation en écrivant une application console qui sérialise et désérialise vos objets en utilisant le DataContractSerializer côté serveur et les méthodes de sérialisation utilisées par votre client. Par exemple, dans notre application actuelle, nous avons des clients WPF et Compact Framework. J'ai écrit une application console pour vérifier que je peux sérialiser en utilisant un DataContractSerializer et désérialiser en utilisant un XmlDesserializer. Vous pouvez essayer.

De même, si vous renvoyez des objets Linq-To-Sql qui ont des collections enfant, vous pouvez vous assurer que vous les avez chargés de manière avide côté serveur. Parfois, en raison du chargement paresseux, les objets renvoyés ne sont pas remplis et peuvent provoquer le comportement que vous observez, à savoir que la requête est envoyée plusieurs fois à la méthode de service.

Si vous avez résolu ce problème, j'aimerais savoir comment, car je suis également coincé avec ce problème. J'ai vérifié que le problème n'est pas lié à la sérialisation, donc je suis perdu.

MISE À JOUR : Je ne sais pas si cela peut vous aider, mais l'outil Service Trace Viewer vient de résoudre mon problème après 5 jours d'expérience très similaire à la vôtre. En configurant le traçage et en examinant ensuite le XML brut, j'ai trouvé les exceptions à l'origine de mes problèmes de sérialisation. Il s'agissait d'objets Linq-to-SQL qui avaient parfois plus d'objets enfants que ce qui pouvait être sérialisé avec succès. L'ajout des éléments suivants à votre fichier web.config devrait activer le suivi :

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

Le fichier résultant peut être ouvert avec l'outil Service Trace Viewer ou simplement dans IE pour examiner les résultats.

Answer 5

Est-ce que vous fermez la connexion au service WCF entre les requêtes ? Si vous ne le faites pas, vous verrez ce timeout exact (éventuellement).