none
HttpClient: Unerwartetes verhalten bei mehreren Instanzen. RRS feed

  • Frage

  • Hallo,
    wir entwickeln momentan ein Windows-Service, welches in mehreren Threads Daten aus einem EventStore liest. (www.geteventstore.com)
    Hier kommt es zu einem seltsamen Problem. Manchmal werden die Anfrage- und Antwort-Nachrichten von 2 HttpClients miteinander vertauscht. Zusätzlich ist bei der Analyse aufgefallen, dass auch ungültige Request-Daten übermittelt werden.
    Es sieht so aus als ob 2 HttpClient-Instanzen in den gleichen TCP-Stream schreiben.
    Wir haben momentan das Pipelining deaktiviert. Dadurch tritt das Problem nicht mehr auf.
    Gibt es etwa ein Problem mit Pipelining im Zusammenspiel mit Long-Polling Requests? Diese haben wir aktiviert.
    Oder ist hier wo ein Bug?

    Code-Ausschnitt:

    HttpClient _eventSliceClient = new HttpClient(new WebRequestHandler
    								{
    									Credentials = configuration.Credential,
    									CachePolicy = new HttpRequestCachePolicy(HttpRequestCacheLevel.NoCacheNoStore),
    								});
    _eventSliceClient.DefaultRequestHeaders.Accept.Add(new MediaTypeWithQualityHeaderValue("application/atom+xml"));
    ...
    while(!_cts.IsCancellationRequested)
    {
    	...
    	try
    	{
    		using (HttpResponseMessage response = await _eventSliceClient.GetAsync(streamUri, token).ConfigureAwait(false))
    		{
    			...
    			string sliceXmlData = await response.Content.ReadAsStringAsync().ConfigureAwait(false);
    			...
    		}
    	}
    	catch(...) {}
    	...
    }

    Montag, 1. Dezember 2014 16:00

Antworten

  • Hallo Sebastian,

    natürlich sollte das nicht passieren. Aber da gibt es leider mehr als eine mögliche Problemstelle. Das eine könnte eure asynchrone Verarbeitung sein, auch lokale statische Elemente können evtl. die Ursache darstellen, die serverseitige Anwendung eben auch. Letztendlich kommt sicher auch ein Bug in den Klassen des .NET Frameworks in Frage, ich würde aber davon ausgehen, dass das schon jemandem aufgefallen wäre, bislang konnte ich dazu aber noch nichts finden. Was aber natürlich nicht heißt, dass es keinen Bug diesbezüglich gibt.

    Daher kann ich meine Bitte nach einem Beispielprojekt, mit dem sich das Problem (wenn auch mit Zeitaufwand) nachstellen lässt, nur wiederholen.


    Gruß, Stefan
    Microsoft MVP - Visual Developer ASP/ASP.NET
    http://www.asp-solutions.de/ - Consulting, Development
    http://www.aspnetzone.de/ - ASP.NET Zone, die ASP.NET Community

    Donnerstag, 4. Dezember 2014 11:38
    Moderator
  • Hallo.

    Unter der Annahme, dass der Server korrekt funktioniert, dann probiert doch mal aus, statt HttpClient andere Klassen mit ähnlichem Umfang zu verwenden. So könnte man z.B. den (Http-)WebRequest verwenden.

    Vielleicht ist da auch sonst irgend wo ein anderer Fehler, der in der Bearbeitung beider gleichzeitiger Verbindungen einherrührt.


    (C) 2014 Thomas Roskop

    Samstag, 13. Dezember 2014 14:18

Alle Antworten

  • Hallo,
    wir entwickeln momentan ein Windows-Service, welches in mehreren Threads Daten aus einem EventStore liest. (www.geteventstore.com)
    Hier kommt es zu einem seltsamen Problem. Manchmal werden die Anfrage- und Antwort-Nachrichten von 2 HttpClients miteinander vertauscht. Zusätzlich ist bei der Analyse aufgefallen, dass auch ungültige Request-Daten übermittelt werden.
    Es sieht so aus als ob 2 HttpClient-Instanzen in den gleichen TCP-Stream schreiben.
    Wir haben momentan das Pipelining deaktiviert. Dadurch tritt das Problem nicht mehr auf.
    Gibt es etwa ein Problem mit Pipelining im Zusammenspiel mit Long-Polling Requests? Diese haben wir aktiviert.
    Oder ist hier wo ein Bug?

    Code-Ausschnitt:

    HttpClient _eventSliceClient = new HttpClient(new WebRequestHandler
    								{
    									Credentials = configuration.Credential,
    									CachePolicy = new HttpRequestCachePolicy(HttpRequestCacheLevel.NoCacheNoStore),
    								});
    _eventSliceClient.DefaultRequestHeaders.Accept.Add(new MediaTypeWithQualityHeaderValue("application/atom+xml"));
    ...
    while(!_cts.IsCancellationRequested)
    {
    	...
    	try
    	{
    		using (HttpResponseMessage response = await _eventSliceClient.GetAsync(streamUri, token).ConfigureAwait(false))
    		{
    			...
    			string sliceXmlData = await response.Content.ReadAsStringAsync().ConfigureAwait(false);
    			...
    		}
    	}
    	catch(...) {}
    	...
    }

    Zusätzliche Informationen

    Die Hostnamen und IP-Adressen wurden anonymisiert.

    Konversationslog in Wireshark

    No. Time Source Destination Protocol Length Info

    96 15:31:44.556491000 192.168.0.2 192.168.0.3 HTTP 287 GET /streams/%24all/00000000084EA94400000000084EA944/forward/20 HTTP/1.1 
    97 15:31:44.563802000 192.168.0.3 192.168.0.2 TCP 1514 [TCP segment of a reassembled PDU]
    98 15:31:44.564082000 192.168.0.3 192.168.0.2 TCP 1514 [TCP segment of a reassembled PDU]
    99 15:31:44.564233000 192.168.0.3 192.168.0.2 TCP 1514 [TCP segment of a reassembled PDU]
    100 15:31:44.564366000 192.168.0.3 192.168.0.2 TCP 1514 [TCP segment of a reassembled PDU]
    101 15:31:44.564480000 192.168.0.3 192.168.0.2 TCP 1514 [TCP segment of a reassembled PDU]
    102 15:31:44.564577000 192.168.0.3 192.168.0.2 TCP 1514 [TCP segment of a reassembled PDU]
    103 15:31:44.564735000 192.168.0.3 192.168.0.2 TCP 1514 [TCP segment of a reassembled PDU]
    104 15:31:44.564827000 192.168.0.3 192.168.0.2 HTTP 966 HTTP/1.1 200 OK  (application/atom+xml)
    105 15:31:44.565123000 192.168.0.2 192.168.0.3 TCP 54 57893 > hsl-storm [ACK] Seq=2962 Ack=72342 Win=65536 Len=0
    106 15:31:44.565128000 192.168.0.2 192.168.0.3 TCP 54 57893 > hsl-storm [ACK] Seq=2962 Ack=75262 Win=65536 Len=0
    107 15:31:44.565132000 192.168.0.2 192.168.0.3 TCP 54 57893 > hsl-storm [ACK] Seq=2962 Ack=78182 Win=65536 Len=0
    108 15:31:44.565135000 192.168.0.2 192.168.0.3 TCP 54 57893 > hsl-storm [ACK] Seq=2962 Ack=80554 Win=65536 Len=0
    109 15:31:44.597226000 192.168.0.2 192.168.0.3 HTTP 244 GET /streams/%24ce-xxxx.corid/149700/forward/20 HTTP/1.1 Continuation or non-HTTP traffic
    110 15:31:44.625281000 192.168.0.3 192.168.0.2 TCP 1514 [TCP segment of a reassembled PDU]
    111 15:31:44.625554000 192.168.0.3 192.168.0.2 TCP 1514 [TCP segment of a reassembled PDU]
    112 15:31:44.625728000 192.168.0.3 192.168.0.2 TCP 1514 [TCP segment of a reassembled PDU]
    113 15:31:44.625841000 192.168.0.3 192.168.0.2 TCP 1514 [TCP segment of a reassembled PDU]
    114 15:31:44.626018000 192.168.0.3 192.168.0.2 TCP 1514 [TCP segment of a reassembled PDU]
    115 15:31:44.626127000 192.168.0.3 192.168.0.2 TCP 1514 [TCP segment of a reassembled PDU]
    116 15:31:44.626240000 192.168.0.3 192.168.0.2 TCP 1514 [TCP segment of a reassembled PDU]
    117 15:31:44.626354000 192.168.0.3 192.168.0.2 TCP 1514 [TCP segment of a reassembled PDU]
    118 15:31:44.626460000 192.168.0.3 192.168.0.2 TCP 1514 [TCP segment of a reassembled PDU]
    119 15:31:44.626578000 192.168.0.3 192.168.0.2 HTTP 237 HTTP/1.1 200 OK  (application/atom+xml)
    120 15:31:44.629291000 192.168.0.2 192.168.0.3 TCP 54 57893 > hsl-storm [ACK] Seq=3152 Ack=83474 Win=65536 Len=0
    121 15:31:44.629785000 192.168.0.2 192.168.0.3 TCP 54 57893 > hsl-storm [ACK] Seq=3152 Ack=86394 Win=65536 Len=0
    122 15:31:44.630172000 192.168.0.2 192.168.0.3 TCP 54 57893 > hsl-storm [ACK] Seq=3152 Ack=89314 Win=65536 Len=0
    123 15:31:44.630181000 192.168.0.2 192.168.0.3 TCP 54 57893 > hsl-storm [ACK] Seq=3152 Ack=92234 Win=65536 Len=0
    124 15:31:44.630788000 192.168.0.2 192.168.0.3 TCP 54 57893 > hsl-storm [ACK] Seq=3152 Ack=93877 Win=65536 Len=0
    125 15:31:44.632877000 192.168.0.3 192.168.0.2 HTTP 559 HTTP/1.1 400 Bad Request  (text/html)
    126 15:31:44.692966000 192.168.0.2 192.168.0.3 TCP 54 57893 > hsl-storm [RST, ACK] Seq=3152 Ack=94382 Win=0 Len=0

    Detailausschnitt der Konversation wo der Fehler auftritt.
    Die ersten beiden Request- und Response-Nachrichten funktionieren.
    Bei der 3. GET-Nachricht werden die ungültigen Daten übermittelt.

    GET /streams/%24all/00000000084EA94400000000084EA944/forward/20 HTTP/1.1
    Accept: application/atom+xml
    Host: hostname.org.xxxx.at:2113
    Cache-Control: no-store,no-cache
    Pragma: no-cache

    HTTP/1.1 401 Unauthorized
    Content-Length: 0
    Content-Type: text/plain; charset=utf-8
    Server: Microsoft-HTTPAPI/2.0
    Access-Control-Allow-Methods: GET, GET, OPTIONS
    Access-Control-Allow-Headers: Content-Type, X-Requested-With, X-PINGOTHER, Authorization, ES-LongPoll, ES-ExpectedVersion, ES-EventId, ES-EventType, ES-RequiresMaster, ES-HardDelete, ES-ResolveLinkTo, ES-ExpectedVersion
    Access-Control-Allow-Origin: *
    Access-Control-Expose-Headers: Location, ES-Position
    WWW-Authenticate: Basic realm="ES",Basic realm="ES"
    Date: Fri, 28 Nov 2014 15:31:43 GMT

    GET /streams/%24all/00000000084EA94400000000084EA944/forward/20 HTTP/1.1
    Accept: application/atom+xml
    Authorization: Basic YWRtaW46Y2hhbmdlaXQ=
    Host: hostname.org.xxxx.at:2113
    Cache-Control: no-store,no-cache
    Pragma: no-cache

    HTTP/1.1 200 OK
    Cache-Control: max-age=31536000, private
    Content-Length: 10559
    Content-Type: application/atom+xml; charset=utf-8
    Vary: Accept
    Server: Microsoft-HTTPAPI/2.0
    Access-Control-Allow-Methods: GET, GET, OPTIONS
    Access-Control-Allow-Headers: Content-Type, X-Requested-With, X-PINGOTHER, Authorization, ES-LongPoll, ES-ExpectedVersion, ES-EventId, ES-EventType, ES-RequiresMaster, ES-HardDelete, ES-ResolveLinkTo, ES-ExpectedVersion
    Access-Control-Allow-Origin: *
    Access-Control-Expose-Headers: Location, ES-Position
    Date: Fri, 28 Nov 2014 15:31:43 GMT
    <?xml version="1.0" encoding="utf-8"?><feed >data ...</feed>

    GET /streams/%24ce-xxxx.corid/149700/forward/20 HTTP/1.1
    Accept: application/atom+xml
    Host: hostname.org.xxxx.at:2113
    Cache-Control: no-store,no-cache
    Pragma: no-cache

    ma: no-cache

    HTTP/1.1 200 OK
    Cache-Control: max-age=31536000, public
    Content-Length: 12756
    Content-Type: application/atom+xml; charset=utf-8
    Vary: Accept
    Server: Microsoft-HTTPAPI/2.0
    Access-Control-Allow-Methods: GET, OPTIONS
    Access-Control-Allow-Headers: Content-Type, X-Requested-With, X-PINGOTHER, Authorization, ES-LongPoll, ES-ExpectedVersion, ES-EventId, ES-EventType, ES-RequiresMaster, ES-HardDelete, ES-ResolveLinkTo, ES-ExpectedVersion
    Access-Control-Allow-Origin: *
    Access-Control-Expose-Headers: Location, ES-Position
    Date: Fri, 28 Nov 2014 15:31:43 GMT
    <?xml version="1.0" encoding="utf-8"?><feed >data ...</feed>

    HTTP/1.1 400 Bad Request
    Content-Type: text/html; charset=us-ascii
    Server: Microsoft-HTTPAPI/2.0
    Date: Fri, 28 Nov 2014 15:31:43 GMT
    Connection: close
    Content-Length: 326
    <!DOCTYPE HTML PUBLIC "-//W3C//DTD HTML 4.01//EN""http://www.w3.org/TR/html4/strict.dtd">
    <HTML><HEAD><TITLE>Bad Request</TITLE>
    <META HTTP-EQUIV="Content-Type" Content="text/html; charset=us-ascii"></HEAD>
    <BODY><h2>Bad Request - Invalid Verb</h2>
    <hr><p>HTTP Error 400. The request verb is invalid.</p>
    </BODY></HTML>

    Hex-Dump des fehlerhaften Get-Paketes

    0000   00 00 0c 07 ac 00 6c 3b e5 16 f8 1c 08 00 45 00  ......l;......E.
    0010   00 e6 4b 36 40 00 80 06 00 00 0a 41 9a 9d 0a 42  ..K6@......A...B
    0020   3a a3 e2 25 08 41 55 14 9b 28 b0 2c 9b d1 50 18  :..%.AU..(.,..P.
    0030   01 00 ea 9b 00 00 47 45 54 20 2f 73 74 72 65 61  ......GET /strea
    0040   6d 73 2f 25 32 34 63 65 2d 78 78 78 78 2e 63 6f  ms/%24ce-xxxx.co
    0050   72 69 64 2f 31 34 39 37 30 30 2f 66 6f 72 77 61  rid/149700/forwa
    0060   72 64 2f 32 30 20 48 54 54 50 2f 31 2e 31 0d 0a  rd/20 HTTP/1.1..
    0070   41 63 63 65 70 74 3a 20 61 70 70 6c 69 63 61 74  Accept: applicat
    0080   69 6f 6e 2f 61 74 6f 6d 2b 78 6d 6c 0d 0a 48 6f  ion/atom+xml..Ho
    0090   73 74 3a 20 61 73 31 31 34 37 38 2e 6f 72 67 2e  st: as11478.org.
    00a0   78 78 78 78 2e 61 74 3a 32 31 31 33 0d 0a 43 61  xxxx.at:2113..Ca
    00b0   63 68 65 2d 43 6f 6e 74 72 6f 6c 3a 20 6e 6f 2d  che-Control: no-
    00c0   73 74 6f 72 65 2c 6e 6f 2d 63 61 63 68 65 0d 0a  store,no-cache..
    00d0   50 72 61 67 6d 61 3a 20 6e 6f 2d 63 61 63 68 65  Pragma: no-cache
    00e0   0d 0a 0d 0a 6d 61 3a 20 6e 6f 2d 63 61 63 68 65  ....ma: no-cache
    00f0   0d 0a 0d 0a                                      ....

    Montag, 1. Dezember 2014 16:02
  • Hi,

    es ist nicht auszuschließen, dass das an der Serveranwendung liegt. Solcherlei Probleme gibt es bspw. recht häugif bei Verwendung statischer Eigenschaften in ASP.NET Webanwendungen. (Wird aber bei anderen Technologien nicht anders sein).

    Um dein Problem nachstellen zu können, bräuchten wir aber ein aufs absolut notwendigste beschränktes Beispielprojekt. Wenn Du das bitte erstellen und hier posten könntest, wäre das prima.


    Gruß, Stefan
    Microsoft MVP - Visual Developer ASP/ASP.NET
    http://www.asp-solutions.de/ - Consulting, Development
    http://www.aspnetzone.de/ - ASP.NET Zone, die ASP.NET Community

    Dienstag, 2. Dezember 2014 19:40
    Moderator
  • Hi!

    Ich arbeite im selben Team wie Roland. Wir müssen unsere Tests mindestens 30-60min ausführen, bis das Problem zum ersten mal auftritt, danach tritt es dann tendenziell öfter auf. Wir gingen bisher nicht davon aus, dass der Server die Probleme verursachen könnte, da wir in Wireshark klar sehen können, wie von einem Moment auf den anderen zwei HttpClient Instanzen auf die gleiche TCP Connection zugreifen. Soweit wir wissen, sollte das nie passieren, oder täuschen wir uns da?

    Danke, mfG

    Sebastian

    Donnerstag, 4. Dezember 2014 07:12
  • Hallo Sebastian,

    natürlich sollte das nicht passieren. Aber da gibt es leider mehr als eine mögliche Problemstelle. Das eine könnte eure asynchrone Verarbeitung sein, auch lokale statische Elemente können evtl. die Ursache darstellen, die serverseitige Anwendung eben auch. Letztendlich kommt sicher auch ein Bug in den Klassen des .NET Frameworks in Frage, ich würde aber davon ausgehen, dass das schon jemandem aufgefallen wäre, bislang konnte ich dazu aber noch nichts finden. Was aber natürlich nicht heißt, dass es keinen Bug diesbezüglich gibt.

    Daher kann ich meine Bitte nach einem Beispielprojekt, mit dem sich das Problem (wenn auch mit Zeitaufwand) nachstellen lässt, nur wiederholen.


    Gruß, Stefan
    Microsoft MVP - Visual Developer ASP/ASP.NET
    http://www.asp-solutions.de/ - Consulting, Development
    http://www.aspnetzone.de/ - ASP.NET Zone, die ASP.NET Community

    Donnerstag, 4. Dezember 2014 11:38
    Moderator
  • Hallo Roland,

    Hat sich eine Lösung herausgestellt? Hat die Serveranwendung auf dieses Verhalten Bezug, worauf Stefan aufmerksam gemacht hat?

    Gruß,
    Dimitar


    Bitte haben Sie Verständnis dafür, dass im Rahmen dieses Forums, welches auf dem Community-Prinzip „IT-Pros helfen IT-Pros“ beruht, kein technischer Support geleistet werden kann oder sonst welche garantierten Maßnahmen seitens Microsoft zugesichert werden können.

    Freitag, 12. Dezember 2014 09:28
    Moderator
  • Hallo.

    Unter der Annahme, dass der Server korrekt funktioniert, dann probiert doch mal aus, statt HttpClient andere Klassen mit ähnlichem Umfang zu verwenden. So könnte man z.B. den (Http-)WebRequest verwenden.

    Vielleicht ist da auch sonst irgend wo ein anderer Fehler, der in der Bearbeitung beider gleichzeitiger Verbindungen einherrührt.


    (C) 2014 Thomas Roskop

    Samstag, 13. Dezember 2014 14:18
  • Hallo Roland,

    Ich gehe davon aus, dass Stefans und Thomas’ Antworten Dir weitergeholfen haben. Solltest Du noch Rückfragen dazu haben, gib uns bitte Bescheid.

    Grüße,
    Dimitar


    Bitte haben Sie Verständnis dafür, dass im Rahmen dieses Forums, welches auf dem Community-Prinzip „IT-Pros helfen IT-Pros“ beruht, kein technischer Support geleistet werden kann oder sonst welche garantierten Maßnahmen seitens Microsoft zugesichert werden können.

    Montag, 22. Dezember 2014 07:21
    Moderator