2017-07-27 1 views
0

Ich benutze Jersey auf HTTP2. Wenn der Verkehr etwas zu hoch wird, wird die Ausnahme ausgelöst. Und ich habe den pcap gefunden Server FIN/ACK ohne FIN zu senden. Ich bin nicht sicher, dass es ein einzelner FIN ist, um die Verbindung von der Serverseite zu schließen. Oder einzelne FIN kombiniert ACK mit vorherigen Paketen. Es sieht Letzteres aus, weil der Kunde FIN nicht gesendet hat. Die Frage ist also, warum der Server FIN nur unter geringem Datenverkehr sendet. Und ich fand, dass rece_q und send_q sehr niedrig sind. CPU-Auslastung ist nicht so hoch. Ich habe bereits einige TCP-Parameter eingestellt und das Ergebnis ist das gleiche. Dieses Verhalten ist instabil, manchmal ist es in Ordnung, manchmal nicht in Ordnung. wenn ich weitere Anfragen (mit gleichem TPS) hinzufüge, dann nicht ok. Es sieht aus, als ob Server die Verbindung beendet hat, aber den genauen Grund nicht kennt. Bezieht es sich auf HTTP2. Haben wir einen Platz, um den genauen Grund zu sehen?HTTP2 Server senden FIN/ACK und dann RST ohne enormen Verkehr

Unten ist der pcap Schnappschuss.

pcap snapshot


aktualisieren 2017.07.30 Debug-Log:

Sun Jul 30, 2017 8:31:35.591 PM org.glassfish.grizzly.http2.Http2FrameCodec parse 
 
FINE: Rx [2]: connection=TCPNIOConnection{localSocketAddress={localhost/127.0.0.1:80}, peerSocketAddress={/127.0.0.1:57802}}, frame=DataFrame {streamId=277, type=0, flags=[none], length=42, data=BuffersBuffer (154351355) [pos=0 lim=42 cap=42 bufferSize=1 buffers=[HeapBuffer (165674143) [pos=0 lim=42 cap=8391], null, null, null]]} 
 
Sun Jul 30, 2017 8:31:35.673 PM org.glassfish.grizzly.http2.Http2BaseFilter processFrames 
 
FINE: Http2ConnectionException occurred on connection=TCPNIOConnection{localSocketAddress={localhost/127.0.0.1:80}, peerSocketAddress={/127.0.0.1:57802}} during Http2Frame processing 
 
Sun Jul 30, 2017 8:31:35.684 PM org.glassfish.grizzly.http2.Http2FrameCodec serializeAndRecycle 
 
FINE: Tx: connection=TCPNIOConnection{localSocketAddress={localhost/127.0.0.1:80}, peerSocketAddress={/127.0.0.1:57802}}, frame=GoAwayFrame {streamId=0, type=7, flags=[none], length=64{lastStreamId=199, errorCode=REFUSED_STREAM}

Und der Strom 277 in pcap Snapshot

pcap contains stream 277 from No 270,271 and 272

Es ist ein Einstellungspaket in 269-Paket. Ist es normal in der Mitte des Transportes SETTINGS zu senden? Und nach 269 gibt es drei Pakete 270, 271 und 272, die Dampf 277 verwenden.

Es ist seltsam, dass um 8: 31: 35,684 ich GOWAY-Paket nicht gefunden habe. Aber nur in 8: 31: 36,035 wird RST/ACK gesendet. An der Rundenzeit ist das Debug-Protokoll wie folgt:

Sun Jul 30, 2017 8:31:36.020 PM org.glassfish.grizzly.http2.Http2FrameCodec parse 
 
FINE: Rx [2]: connection=TCPNIOConnection{localSocketAddress={localhost/127.0.0.1:80}, peerSocketAddress={/127.0.0.1:57802}}, frame=DataFrame {streamId=465, type=0, flags=[END_STREAM], length=0, data=ByteBufferWrapper (1101850112) [visible=[java.nio.HeapByteBuffer[pos=0 lim=0 cap=0]]]} 
 
Sun Jul 30, 2017 8:31:36.023 PM org.glassfish.grizzly.http2.Http2BaseFilter processDataFrame 
 
FINE: Data frame received for non-existent stream: connection=TCPNIOConnection{localSocketAddress={localhost/127.0.0.1:80}, peerSocketAddress={/127.0.0.1:57802}}, frame=DataFrame {streamId=277, type=0, flags=[END_STREAM], length=0, data=ByteBufferWrapper (1101850112) [visible=[java.nio.HeapByteBuffer[pos=0 lim=0 cap=0]]]}, stream=277 
 
Sun Jul 30, 2017 8:31:36.024 PM org.glassfish.grizzly.http2.Http2BaseFilter processFrames 
 
FINE: Http2StreamException occurred on connection=TCPNIOConnection{localSocketAddress={localhost/127.0.0.1:80}, peerSocketAddress={/127.0.0.1:57802}} during Http2Frame processing 
 
Sun Jul 30, 2017 8:31:36.025 PM org.glassfish.grizzly.http2.Http2BaseFilter processFrames 
 
FINE: Http2ConnectionException occurred on connection=TCPNIOConnection{localSocketAddress={localhost/127.0.0.1:80}, peerSocketAddress={/127.0.0.1:57802}} during Http2Frame processing

Das Protokoll zeigte erhält einen nicht vorhandenen Strom 277. Dieser Strom ist genau das im ersten Protokoll protokollierte Strom. Nicht sicher, dass dieser Dampf 277 RST/ACK in den nächsten mehreren Millisekunden verursacht. Ich denke, es sollte ein Problem mit dem Paket hat 269 ~ 272 und Strom 277.

BTW, diesmal gibt es keine FIN/ACK hat.

+0

Log-Zeile bei 8: 31: 35.591 scheint anzuzeigen, dass der 'HEADERS'-Frame irgendwie für Stream 277 geparst wurde, aber anscheinend nicht erfolgreich war, was den' GOAWAY' verursacht. Hast du den "FINEST" Logging-Level ausprobiert? Vielleicht hat es mehr Hinweise darauf, was schief gelaufen ist. Haben Sie auch eine andere Implementierung wie Jetty HTTP/2 versucht (Haftungsausschluss, ich bin der Jetty HTTP/2 Maintainer)? – sbordet

+0

Eigentlich kann ich nicht Jetty HTTP/2 auf Jersey injizieren und konfigurieren. Ich kann nur sehr begrenzte HTTP/2 Container-Nutzung auf Jersey finden. Anerkannt, wenn Sie mehr Informationen dazu liefern können. Vielen Dank. – user3675334

+0

Ich habe das Protokoll auf FINEST gesetzt, sieht gleich aus, Prozessfehler und sende dann GoAwayFrame. Und am pcap wird RST/ACK zuletzt gesendet. Aber eine andere seltsame Sache, die ich in der heutigen pcap bemerkt habe, und ich fand auch in Yesterday's pcap. Die Server-Ausbeute reagierte nicht, bis RST/ACK gesendet wurde, und auch die Antwort ist eine große, aber nicht alle erwarteten Antworten. Der gestrige PCAP hatte sogar keine Antwort außer einem RST/ACK-Paket an den Client. – user3675334

Antwort

0

Die pcap zeigt eine abnormale Beendigung auf dem Server.

sollten Sie die Protokolle Server überprüfen, um weitere Informationen, warum das passiert ist.

Eine mögliche Ursache ist ein Serverfehler.

Eine andere mögliche Ursache ist, dass der Client einen ungültigen HEADERS Rahmen an Paket 14 gesendet wird; Trotzdem sollte der Server einen GOAWAY Frame senden und nicht nur die Verbindung schließen.

Die RST bei Paket 17 ist normal, da der Client einen HEADERS Rahmen an Paket 16 vor der Verarbeitung die FIN gesendet, so dass der Server antwortet mit einem RST anzeigt, dass die gesendeten Daten nicht zu dem Benutzercode Schicht ausgefüllt.

Die Serverprotokolle (vielleicht auf DEBUG-Ebene) sollten Ihnen mehr darüber erzählen, was passiert ist.

+0

Ich werde es versuchen und später zu dir zurück. – user3675334

+0

Ich habe mit Debug-Log und einige Befunde aktualisiert. Könntest du mir helfen zu schauen? Vielen Dank. – user3675334