[.NET] WCF Service timeout, wat gebeurt er nou echt?

[Contagion]

Ik heb een client die via simpleHTTP connect met een IIS server die een WCF service host. Deze service verwacht objecten die soms 'groot' zijn (zeg 1 MB) en sommige van onze clients zitten op trage internetlijnen.

Het volgende lijkt te gebeuren:

• De client roept de 'remote method' aan en stuurt daarbij het grote object naar de IIS hosted WCF service
• De timeout van 1 minuut verstrijkt en de client onderschept de 'timeout' exception en gaat verder met het volgende object.

Op de server echter vindt geen timeout plaats en deze ontvangt alsnog het COMPLETE object die door de client als timed-out bestempeld was.

Ik vraag me af hoe dat kan. Ik kan op internet geen passsend antwoord vinden, behalve 'verhoog de timeout' maar dat is geen uitleg van de oorzaak van het fenomeen .

Wat ik vooral vreemd vind is dat als een client een timeout geeft na 1 minuut hij direct door gaat met het volgende object wat hij moet verzenden. Ik kan begrijpen dat als de IIS server meer processing time neemt dan dat het kost om een bepaalde actie te doen, dat deze timeout resulteert op de client en dat de server (onwetend van deze timeout) toch doorgaat met zijn actie en dat hij alleen zijn antwoord niet meer kan terugzenden (want de client was al verdwenen). Wat ik niet begrijp is dat een timeout (hier trouwens bestempeld als 'operation timeout' eigenlijk geen 'operation timeout' is maar een 'message transfer timeout') resulteert in het doorgaan van de client met het volgende object maar dat het zo lijkt te zijn dat in de achtergrond de transfer door de client alsnog wordt afgemaakt parallel (??) met het volgende object waar hij inmiddels al aan begonnen is.

Ik verwacht dat als het je als client niet lukt om de parameters voor een remote method op tijd te verzenden, je dan bij een timeout ook NIET doorgaat met het verzenden van deze data!

Wat nu dus gebeurt is dat een client aanneemt 'timeout: dus data niet verzonden' en de server uiteindelijk de data wel volledig krijgt maar het antwoord 'klaar: true, ik heb alles gehad' niet meer terug kan zenden.

[Korben]

Lijkt me dat je client doorgaat met het volgende object is omdat je exceptions afvangt. Voor zover ik weet wordt er gewoon een exception gegooid die je zult moeten afhandelen.

Ook is het zo dat inderdaad de time-outs en limits aan de server-kant heel anders kunnen zijn dan aan de client.

Wat bedoel je trouwens met 'simpleHTTP'? Als je daarmee geen 'BasicHttp' bedoelt maar één of andere third party binding, dan lijkt het me dat de oorzaak van het feit dat je client een time-out krijgt en je server niet, daar ligt.

[CodeCaster]

Korben schreef op dinsdag 19 oktober 2010 @ 16:47:
Lijkt me dat je client doorgaat met het volgende object is omdat je exceptions afvangt. Voor zover ik weet wordt er gewoon een exception gegooid die je zult moeten afhandelen.

Ook is het zo dat inderdaad de time-outs en limits aan de server-kant heel anders kunnen zijn dan aan de client.

Zijn probleem is dus dat er, na het verlopen van de client-timeout, blijkbaar nog data wordt verstuurd.

Ik zou er een Wireshark tegenaan gooien.

[Contagion]

Ik bedoel inderdaad basicHTTP, foutje dat was blijven staan in de post. Ik ben inderdaad al aan het kijken met Wireshark maar heb nog geen handig filter uit de hoeveelheid data die wij ontvangen hebben waar duplicaten van objecten tussen zitten.

Maar waardoor ik het idee heb dat de client toch in de achtergrond de transfer afmaakt is dat wij nu 2300 duplicaat objecten hebben gekregen die afkomstig waren van 1 client die 1 object moest zenden. Als ik deze objecten vervolgens binair vergelijk, dan zijn ze ze ook 100% identiek.

Ik zou verwachten dat als de transfer echt een timeout geeft en stopt, dat de verkregen objecten dan niet alle 2300 identiek zouden zijn omdat er soms een bytje meer of minder binnen komt. Daarbij zou ik dan ook verwachten dat de onze 'remote method' helemaal niet zou moeten zijn aangeroepen omdat hij slechts een incompleet object ontvangen heeft... Niet het geval dus; we hebben het hele object binnen ook al zei de client 'Timeout' na 1 minuut.

Dit levert als bijproduct een compleet verzadigde internetpijp bij onze klant op, want na zo'n 10 minuten zal de client opnieuw -volgens hem- niet-verzonden objecten gaan sturen, terwijl hij in de achtergrond wellicht nog bezig was met het verzenden van een object waar hij al een exception op gegeven had?!

[sig69]

Contagion schreef op dinsdag 19 oktober 2010 @ 17:14:
IMaar waardoor ik het idee heb dat de client toch in de achtergrond de transfer afmaakt is dat wij nu 2300 duplicaat objecten hebben gekregen die afkomstig waren van 1 client die 1 object moest zenden. Als ik deze objecten vervolgens binair vergelijk, dan zijn ze ze ook 100% identiek.

Als de client timeout op 1 minuut staat, wil hij volgens mij binnen een minuut een response hebben. Als het verzenden dus bijvoorbeel 59 seconden duurt, is het hele bericht wel aangekomen op de server maar is de kans groot dat het response niet op tijd terug is (weet niet wat er op de server allemaal aan processing gedaan wordt), de clieng gooit dan een timeout. Is het geen optie om de timeout op de client wat omhoog te gooien.

Ik weet overigens niet of de client begint met het bijhouden van tijd op het moment dat hij begint met versturen, of op het moment dat het versturen afgerond is. Het is allemaal een beetje roestig dus pin me er niet op vast...

[Contagion]

Ik denk niet dat het zo kritisch komt, dan zou van die 2300x het wellicht 1x goed moeten zijn gegaan of minder keren fout. Het bericht is waarschijnlijk 'zo groot' dat verzenden een minuut of 5 zal duren.

Natuurlijk kan de client timeout omhoog , maar dat is niet echt een oplossing, timeout * 5 geeft bij objectsize * 5 hetzeklde probleem natuurlijk. Ik verbaas me alleen over de uitkomst en vind het zo onlogisch dat ik me afvroeg of er een structurele oorzaak/oplossing voor is.

Ik zal ook niet de eerste/enige zijn met dit effect lijkt me, zeker niet op Tweakers .

EDIT: Het gaat trouwens om een wsHttpBinding en niet om een basicHttpBinding

[ Voor 6% gewijzigd door Contagion op 19-10-2010 18:50 ]

[sig69]

Misschien zou je een met de Service Trace Viewer kunnen kijken wat er onderhouds allemaal gebeurd. Heeft mij in het verleden wel geholpen.

[DigiK-oz]

Kan het niet gewoon zo zijn dat de server de volledige data prima ontvangt (en binnen de timeout), maar domweg geen ack naar de client stuurt? Dan zal de service de data dus gewoon verwerken aangezien alles binnen is, en de client zal blijven versturen omdat hij denkt dat de data niet (geheel) is ontvangen.

Misschien heb je hier wat aan?

[ Voor 18% gewijzigd door DigiK-oz op 19-10-2010 19:15 ]

[CodeCaster]

DigiK-oz schreef op dinsdag 19 oktober 2010 @ 19:11:
en de client zal blijven versturen omdat hij denkt dat de data niet (geheel) is ontvangen.

Nee, want de client klapt er met een exception uit op het moment dat de clientside ingestelde timeout is verstreken.

[Contagion]

Ik zal eens kijken naar die Trace Viewer en ik ga ook verder monitoren met Wireshark wat er gebeurt als de minuut verstreken is.

Dat de server alles ontvangt maar niet ACKt is niet waarschijnlijk. Het probleem is reproduceerbaar bij 'grote objecten' bij de klant met trage uplink en we hebben een object zelfs al 1200+ keer ontvangen, steeds intact maar met de client ge-timed-out. Daarbij hoeft de sever eigenlijk niks te processen met de ontvangen data, behalve het in een tabelletje mikken, iets wat bij grotere data nauwelijks meer tijd zal kosten (geen seconden, tientallen seconden, minutuen). Ik zal de timestamps ook controleren morgen, maar ik verwacht dat zodra de client 'timeout' meldt dat pas tientallen seconden later of misschien zelfs minuten later er een melding op de server verschijnt als 'object ontvangen'. Het topic waar je naar verwijst spreekt over 'This may be because the service is still processing the operation or because the service was unable to send a reply message.' maar ik weet in ons geval zeker dat het juist de cllient is die nog aan het uploaden is naar de server, nog voor de server de methode moet uitvoeren.

Codecaster: klopt, je was deze reply voor

[Contagion]

Even getest met Wireshark. Dit heeft dus geen enkele zin:

code:

using (var s = new Service1Client())
{
 try
 {
  s.SendLargeDataPortion(c); // Waarbij C een object is met een een property byte[] van een aardige lengte er in
 }
 catch (Exception ex)
 {
  Console.Writeline(ex.Message);
 }
}

De exception verschijnt in beeld, de 'main thread' gaat rustig door met een nieuwe taak maar ergens in de achtergrond blijft de client data zenden naar onze server/service. Ik heb nog niet veel verder getest, maar bijvoorbeeld in de catch 's.ChannelFactory.Abort();' of 's.Close()' invoegen haalt ook niks uit. De transfer wordt afgemaakt (of misschien niet afgemaakt, maar loopt in elk geval nog heel lang door na de Timeout exception).

Edit:

Toevoegen van de volgende regels in de 'catch' hebben ook geen effect. Er is kennelijk een threadpool thread die toch blijft doorgaan, want als ik net na de throw de debugger pauzeer staat er nog een ~ regeltje bij de s.SendLargeDataPortion(c). Eind van je 'synchronous request' dus en die verandert dan ineens in een asynchroon draaiend spook die 'to completion' het werk afmaakt?!

code:

 s.Abort();
 s.Close();
 s.ChannelFactory.Abort();
 s.ChannelFactory.Close();
 s.InnerChannel.Abort();
 s.InnerChannel.Close();

[ Voor 27% gewijzigd door Contagion op 20-10-2010 00:56 ]

[CodeCaster]

Hoe groot zijn de maxBufferPoolSize en maxBufferSize op je client? En ik zou dan gaan kijken naar MTOM.

[Contagion]

De maxBufferPoolSize stond eerst op de default van 524288 bytes. Omdat ik verwachtte dat de transfer misschien in elk geval dat aantal bytes verstuurt heb ik die op 4096 gezet, maar dan nog gaat de client in de achtergrond door. de maxBufferSize staat op 65536 maar dat is wel kleiner dan de hele message. Het probleem lijkt voor zo ver op te treden bij zowel 'text' als 'mtom' encoding.

Ik had zelf ook al bedacht http compression aan te zetten, maar dat schijnt nog niet zo eenvoudig te zijn met IIS als host, of dat ik na zelf mijn object te hebben geserialized, deze in te pakken met bzip2 en die dan als binary array aan te bieden. Ik zal eens kijken naar de gzip als compression channel zoals genoemd in het artikel (dat is ook netter dan zelf een binary object aanbieden aan je methodes).

Het blijft echter geen oplossing voor het probleem.