Apache 2.4 + HTTP2 náhodně ukončí spojení

[lj2017]

Zdravim,

mam Debian 9 v konfiguracii Apache 2.4 (http2) a PHP-FPM. Spustam na nom pre testovacie ucely tento kod:

Kód: [Vybrat]

<?php
for( $i= 0 ; $i <= 300 ; $i++ ){
  echo $i."s<br />";
  flush();
  sleep(1);
}
echo "konec";
?>
Ak to spustim cez HTTP/2 tak nacitavanie nahodne spadne. Niekedy skonci hned, pri dalsom pokuse sa nacita cely alebo nahodne padne po sekundu alebo po 200 sekundach. V logu mam hlasku:

Kód: [Vybrat]

FastCGI: client stopped connection before send body completed
Ak nacitavam cez HTTP/1.0, tak script vzdy dobehne do konca a nikdy sa neprerusi.

Ma niekto tusenie v com moze byt problem a preco HTTP/2 modul toto spojenie nahodne ukonci?

Dakujem.

[Reklama]

[Miroslav Šilhavý]

Zkuste do chrome přidat Rozšíření HTTP/2 and SPDY indicator, přes něj se dá něco odchytit. Třeba to napoví.

[lj2017]

Dobry den, dakujem za radu. Takto to vyzera v logu:

Kód: [Vybrat]

...
t=1246545 [st=147015]  HTTP2_SESSION_RECV_DATA
                       --> fin = false
                       --> size = 10
                       --> stream_id = 1
t=1246545 [st=147015]  HTTP2_SESSION_UPDATE_RECV_WINDOW
                       --> delta = -10
                       --> window_size = 15728630
t=1246546 [st=147016]  HTTP2_SESSION_UPDATE_RECV_WINDOW
                       --> delta = 10
                       --> window_size = 15728640
t=1247545 [st=148015]  HTTP2_SESSION_RECV_DATA
                       --> fin = false
                       --> size = 10
                       --> stream_id = 1
t=1247545 [st=148015]  HTTP2_SESSION_UPDATE_RECV_WINDOW
                       --> delta = -10
                       --> window_size = 15728630
t=1247546 [st=148016]  HTTP2_SESSION_UPDATE_RECV_WINDOW
                       --> delta = 10
                       --> window_size = 15728640
t=1248545 [st=149015]  HTTP2_SESSION_RECV_DATA
                       --> fin = false
                       --> size = 10
                       --> stream_id = 1
t=1248545 [st=149015]  HTTP2_SESSION_UPDATE_RECV_WINDOW
                       --> delta = -10
                       --> window_size = 15728630
t=1248546 [st=149016]  HTTP2_SESSION_UPDATE_RECV_WINDOW
                       --> delta = 10
                       --> window_size = 15728640
t=1249545 [st=150015]  HTTP2_SESSION_RECV_DATA
                       --> fin = false
                       --> size = 10
                       --> stream_id = 1
t=1249545 [st=150015]  HTTP2_SESSION_UPDATE_RECV_WINDOW
                       --> delta = -10
                       --> window_size = 15728630
t=1249547 [st=150017]  HTTP2_SESSION_UPDATE_RECV_WINDOW
                       --> delta = 10
                       --> window_size = 15728640
t=1250548 [st=151018]  HTTP2_SESSION_RECV_DATA
                       --> fin = false
                       --> size = 10
                       --> stream_id = 1
t=1250548 [st=151018]  HTTP2_SESSION_UPDATE_RECV_WINDOW
                       --> delta = -10
                       --> window_size = 15728630
t=1250549 [st=151019]  HTTP2_SESSION_UPDATE_RECV_WINDOW
                       --> delta = 10
                       --> window_size = 15728640
t=1251545 [st=152015]  HTTP2_SESSION_RECV_DATA
                       --> fin = false
                       --> size = 10
                       --> stream_id = 1
t=1251545 [st=152015]  HTTP2_SESSION_UPDATE_RECV_WINDOW
                       --> delta = -10
                       --> window_size = 15728630
t=1251547 [st=152017]  HTTP2_SESSION_UPDATE_RECV_WINDOW
                       --> delta = 10
                       --> window_size = 15728640
t=1252546 [st=153016]  HTTP2_SESSION_RECV_DATA
                       --> fin = false
                       --> size = 10
                       --> stream_id = 1
t=1252546 [st=153016]  HTTP2_SESSION_UPDATE_RECV_WINDOW
                       --> delta = -10
                       --> window_size = 15728630
t=1252547 [st=153017]  HTTP2_SESSION_UPDATE_RECV_WINDOW
                       --> delta = 10
                       --> window_size = 15728640
t=1253546 [st=154016]  HTTP2_SESSION_RECV_DATA
                       --> fin = false
                       --> size = 10
                       --> stream_id = 1
t=1253546 [st=154016]  HTTP2_SESSION_UPDATE_RECV_WINDOW
                       --> delta = -10
                       --> window_size = 15728630
t=1253547 [st=154017]  HTTP2_SESSION_UPDATE_RECV_WINDOW
                       --> delta = 10
                       --> window_size = 15728640
t=1254546 [st=155016]  HTTP2_SESSION_RECV_DATA
                       --> fin = false
                       --> size = 10
                       --> stream_id = 1
t=1254546 [st=155016]  HTTP2_SESSION_UPDATE_RECV_WINDOW
                       --> delta = -10
                       --> window_size = 15728630
t=1254547 [st=155017]  HTTP2_SESSION_UPDATE_RECV_WINDOW
                       --> delta = 10
                       --> window_size = 15728640
t=1255546 [st=156016]  HTTP2_SESSION_RECV_DATA
                       --> fin = false
                       --> size = 10
                       --> stream_id = 1
t=1255546 [st=156016]  HTTP2_SESSION_UPDATE_RECV_WINDOW
                       --> delta = -10
                       --> window_size = 15728630
t=1255547 [st=156017]  HTTP2_SESSION_UPDATE_RECV_WINDOW
                       --> delta = 10
                       --> window_size = 15728640
t=1256446 [st=156916]  HTTP2_SESSION_RECV_DATA
                       --> fin = false
                       --> size = 21
                       --> stream_id = 1
t=1256446 [st=156916]  HTTP2_SESSION_UPDATE_RECV_WINDOW
                       --> delta = -21
                       --> window_size = 15728619
t=1256446 [st=156916]  HTTP2_SESSION_RECV_DATA
                       --> fin = true
                       --> size = 0
                       --> stream_id = 1
t=1256446 [st=156916]  HTTP2_SESSION_UPDATE_RECV_WINDOW
                       --> delta = 21
                       --> window_size = 15728640
t=1256502 [st=156972]  HTTP2_SESSION_SEND_HEADERS
                       --> exclusive = true
                       --> fin = true
                       --> has_priority = true
                       --> :method: GET
                           :authority: www.example.com
                           :scheme: https
                           :path: /favicon.ico
                           pragma: no-cache
                           cache-control: no-cache
                           user-agent: Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Ubuntu Chromium/63.0.3239.84 Chrome/63.0.3239.84 Safari/537.36
                           accept: image/webp,image/apng,image/*,*/*;q=0.8
                           referer: https://www.example.com/autovia/test.php
                           accept-encoding: gzip, deflate, br
                           accept-language: en-US,en;q=0.9
                           cookie: [303 bytes were stripped]
                       --> parent_stream_id = 0
                       --> source_dependency = 116790 (HTTP_STREAM_JOB)
                       --> stream_id = 3
                       --> weight = 220
t=1256509 [st=156979]  HTTP2_SESSION_RECV_HEADERS
                       --> fin = false
                       --> :status: 200
                           date: Fri, 15 Dec 2017 18:06:27 GMT
                           server: Apache
                           last-modified: Wed, 29 Feb 2012 07:02:20 GMT
                           etag: "47e-4ba14ecb15700"
                           accept-ranges: bytes
                           content-length: 1150
                           cache-control: max-age=864000
                           expires: Mon, 25 Dec 2017 18:06:27 GMT
                           content-type: image/vnd.microsoft.icon
                       --> stream_id = 3
t=1256510 [st=156980]  HTTP2_SESSION_RECV_DATA
                       --> fin = false
                       --> size = 1150
                       --> stream_id = 3
t=1256510 [st=156980]  HTTP2_SESSION_UPDATE_RECV_WINDOW
                       --> delta = -1150
                       --> window_size = 15727490
t=1256510 [st=156980]  HTTP2_SESSION_RECV_DATA
                       --> fin = true
                       --> size = 0
                       --> stream_id = 3
t=1256510 [st=156980]  HTTP2_SESSION_UPDATE_RECV_WINDOW
                       --> delta = 1150
                       --> window_size = 15728640
t=1271523 [st=171993]  HTTP2_SESSION_RECV_GOAWAY
                       --> active_streams = 0
                       --> debug_data = "timeout"
                       --> error_code = "0 (NO_ERROR)"
                       --> last_accepted_stream_id = 3
                       --> unclaimed_streams = 0
t=1271523 [st=171993]  HTTP2_SESSION_CLOSE
                       --> description = "Finished going away"
                       --> net_error = 0 (?)
t=1271523 [st=171993]  HTTP2_SESSION_POOL_REMOVE_SESSION
t=1271523 [st=171993] -HTTP2_SESSION

[lj2017]

Pardon, zly vypis. V predoslom prispevku to akurat zbehlo cele korektne.

 

[lj2017]

Takto to vyzera ak sa to nahodne prerusi:

Kód: [Vybrat]

t=2348734 [st=557248]  HTTP2_SESSION_UPDATE_RECV_WINDOW
                       --> delta = -21
                       --> window_size = 15728619
t=2348734 [st=557248]  HTTP2_SESSION_RECV_DATA
                       --> fin = true
                       --> size = 0
                       --> stream_id = 11
t=2348734 [st=557248]  HTTP2_SESSION_UPDATE_RECV_WINDOW
                       --> delta = 21
                       --> window_size = 15728640
t=2363747 [st=572261]  HTTP2_SESSION_RECV_GOAWAY
                       --> active_streams = 0
                       --> debug_data = "timeout"
                       --> error_code = "0 (NO_ERROR)"
                       --> last_accepted_stream_id = 17
                       --> unclaimed_streams = 0
t=2363748 [st=572262]  HTTP2_SESSION_CLOSE
                       --> description = "Finished going away"
                       --> net_error = 0 (?)
t=2363748 [st=572262]  HTTP2_SESSION_POOL_REMOVE_SESSION
t=2363748 [st=572262] -HTTP2_SESSION

[Reklama]

[Jan Forman]

Spíš jestli to nezlobilo i před tím, http/2 je docela háklivé narozdíl od normálního http.
Protože si to žene jen přes pár spojení, takže rozpad je vidět okamžitě, zatímco v normálním http se celkem i ztratí.

Zdravim,

mam Debian 9 v konfiguracii Apache 2.4 (http2) a PHP-FPM. Spustam na nom pre testovacie ucely tento kod:

Kód: [Vybrat]

<?php
for( $i= 0 ; $i <= 300 ; $i++ ){
  echo $i."s<br />";
  flush();
  sleep(1);
}
echo "konec";
?>
Ak to spustim cez HTTP/2 tak nacitavanie nahodne spadne. Niekedy skonci hned, pri dalsom pokuse sa nacita cely alebo nahodne padne po sekundu alebo po 200 sekundach. V logu mam hlasku:

Kód: [Vybrat]

FastCGI: client stopped connection before send body completed
Ak nacitavam cez HTTP/1.0, tak script vzdy dobehne do konca a nikdy sa neprerusi.

Ma niekto tusenie v com moze byt problem a preco HTTP/2 modul toto spojenie nahodne ukonci?

Dakujem.

[lj2017]

Na HTTP/1 sa mi snad z 20 pokusov nerozpadlo ani jedno spojenie, kdezeto na HTTP/2 mi mozno az 90% spojeni spadne.

Kód: [Vybrat]

t=655526 [st=249188]  HTTP2_SESSION_RECV_GOAWAY
                      --> active_streams = 1
                      --> debug_data = ""
                      --> error_code = "0 (NO_ERROR)"
                      --> last_accepted_stream_id = 2147483647
                      --> unclaimed_streams = 0
t=656360 [st=250022]  HTTP2_SESSION_CLOSE
                      --> description = "Connection closed"
                      --> net_error = -100 (ERR_CONNECTION_CLOSED)
t=656360 [st=250022]  HTTP2_SESSION_POOL_REMOVE_SESSION
t=656360 [st=250022] -HTTP2_SESSION

[Jan Forman]

Nebude to klientem?
On ten protokol je hodně složitý používám to jen na nginx, ale tam někde ve fóru vývojáři konstatovali, že je to fakt hodně obludné a že to taky nějak ještě přepíšou.
Stejný problém asi řeší i vývojáři prohlížečů a spol.

Ze začátku mi každý prohlížeč zlobil jinak. Dneska už to ale celkem chodí, přesto některá spojení se chovají hůř.
Typicky ty z mobilních zařízení, protože to běží jen přes pár spojení, umření jakéhokoliv znamená smrt přenosu.
Tam se paradoxně http1 chová lépe - prostě se sem tam něco nenačte. http/2 umře celé.

Na HTTP/1 sa mi snad z 20 pokusov nerozpadlo ani jedno spojenie, kdezeto na HTTP/2 mi mozno az 90% spojeni spadne.

Kód: [Vybrat]

t=655526 [st=249188]  HTTP2_SESSION_RECV_GOAWAY
                      --> active_streams = 1
                      --> debug_data = ""
                      --> error_code = "0 (NO_ERROR)"
                      --> last_accepted_stream_id = 2147483647
                      --> unclaimed_streams = 0
t=656360 [st=250022]  HTTP2_SESSION_CLOSE
                      --> description = "Connection closed"
                      --> net_error = -100 (ERR_CONNECTION_CLOSED)
t=656360 [st=250022]  HTTP2_SESSION_POOL_REMOVE_SESSION
t=656360 [st=250022] -HTTP2_SESSION

[lj2017]

Testoval som to voci localhostu s pouzitim curl-u a wget-u. wget pri http/1.0 dobehne vzdy dokonca, curl pri http/2 vzdy nahodne spadne. Z poslednych pokusov to nedobehla do konca ani raz.