Несколько запросов (с некоторыми отмененными) из Chrome в Apache выдает net :: ERR_HTTP2_PROTOCOL_ERROR - PullRequest
Новая
       79

Несколько запросов (с некоторыми отмененными) из Chrome в Apache выдает net :: ERR_HTTP2_PROTOCOL_ERROR

1 голос
/ 21 октября 2019

У меня есть поисковый компонент, который работает следующим образом:

  1. Пользователь выполняет поиск, выбирая несколько поисков (от 1 до 25).
  2. Когда пользователь отправляет запросФорма поиска, фронт отправляет один HTTP-запрос к API для выбранного поиска. Интерфейс - это приложение Angular 8, а API - это Java API, работающий в Tomcat 9 за Apache 2 (с поддержкой HTTP2), действующий в качестве обратного прокси-сервера.
  3. Если пользователь отправляет форму поиска второй раз, каждыйнезаконченный запрос отменяется, и мы возвращаемся ко второму шагу.

Когда отправляется второй запрос, иногда выдается ошибка net::ERR_HTTP2_PROTOCOL_ERROR, случается только , если хотя быодин HTTP-запрос был отменен.

Я пытался изолировать проблему настолько, насколько мог. Следующая программа (размещенная в репозитории Gitlab) воспроизводит проблему с минимальным кодом: dorianm / apache2-http2-chrome-error

Содержит минимальную конфигурацию Apache 2 (только 43 строки): 

# [...]

DocumentRoot /usr/local/apache2/htdocs/
<Directory "/usr/local/apache2/htdocs/">
    Options ExecCGI
    AddHandler cgi-script .pl
    Require all granted
</Directory>

Protocols h2

SSLEngine on
SSLProtocol all -SSLv2 -SSLv3
SSLCipherSuite !EDH:!AECDH:!ADH:!DSS:!RC4:ECDSA:HIGH:+3DES
SSLHonorCipherOrder on
SSLCertificateFile /usr/local/apache2/conf/server.crt
SSLCertificateKeyFile /usr/local/apache2/conf/server.key

# [...]

Простой базовый CGI Perl-скрипт : 

#!/usr/bin/env perl

print "Content-Type: application/json\n\n";
print '[{ … }]'; # ~100kb of random JSON

И Javascript-скрипт , который вызываетскрипт CGI из запросов внешнего интерфейса / отмены /…: 

let runningQueries = [];
let intervalId;
const getIntervalTime = () => document.getElementById("intervalTime").value; // 50ms by default

setInterval(() => {
    fetch("https://localhost/cgi.pl?constant");
}, 200);

const searches = [];
for (let i = 1; i <= 10; i++) {
    searches.push(`https://localhost/cgi.pl?${i}`);
}

function start() {
    intervalId = setInterval(() => {
        runningQueries.forEach(controller => {
            controller.abort();
        });

        runningQueries = [];

        searches.forEach(url => {
            const controller = new AbortController();
            runningQueries.push(controller);
            fetch(url, {signal: controller.signal}).catch(err => {
                console.log(err);
            });
        });
    }, getIntervalTime());
}

function stop() {
    clearInterval(intervalId);
}

Две кнопки доступны спереди для выполнения функций start и stop. Благодаря этому коду я могу воспроизвести мою проблему:

Chrome issue

Я экспортирую журналы Chrome (из chrome: // net-export / tools): 

t=5644 [st=194]     +HTTP_TRANSACTION_SEND_REQUEST  [dt=9]
t=5644 [st=194]        HTTP_TRANSACTION_HTTP2_SEND_REQUEST_HEADERS
                       --> :method: GET
                           :authority: localhost
                           :scheme: https
                           :path: /cgi.pl?constant
                           authorization: [30 bytes were stripped]
                           sec-fetch-mode: cors
                           user-agent: Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/77.0.3865.90 Safari/537.36
                           accept: */*
                           sec-fetch-site: same-origin
                           referer: https://localhost/index.html
                           accept-encoding: gzip, deflate, br
                           accept-language: fr,en;q=0.9,de;q=0.8,it;q=0.7
                           cookie: [1585 bytes were stripped]
t=5653 [st=203]     -HTTP_TRANSACTION_SEND_REQUEST
t=5653 [st=203]     +HTTP_TRANSACTION_READ_HEADERS  [dt=180]
t=5833 [st=383]        HTTP2_STREAM_ERROR
                       --> description = "Server reset stream."
                       --> net_error = "ERR_HTTP2_PROTOCOL_ERROR"
                       --> stream_id = 2945
t=5833 [st=383]     -HTTP_TRANSACTION_READ_HEADERS
                     --> net_error = -337 (ERR_HTTP2_PROTOCOL_ERROR)
t=5833 [st=383]   -URL_REQUEST_START_JOB
                   --> net_error = -337 (ERR_HTTP2_PROTOCOL_ERROR)
t=5833 [st=383]    URL_REQUEST_DELEGATE_RESPONSE_STARTED  [dt=0]
t=5833 [st=383] -REQUEST_ALIVE
                 --> net_error = -337 (ERR_HTTP2_PROTOCOL_ERROR)

И я изменяю журналы Apache на уровень трассировки. Единственная интересная часть заключается в следующем: 

[Fri Oct 18 09:59:34.120151 2019] [http2:debug] [pid 10:tid 139649980819200] h2_session.c(593): [client 192.168.192.1:36934] AH03068: h2_session(128,BUSY,11): sent FRAME[RST_STREAM[length=4, flags=0, stream=1839]], frames=1895/2902 (r/s)
[Fri Oct 18 09:59:34.120168 2019] [http2:debug] [pid 10:tid 139649980819200] h2_session.c(593): [client 192.168.192.1:36934] AH03068: h2_session(128,BUSY,11): sent FRAME[RST_STREAM[length=4, flags=0, stream=1841]], frames=1895/2903 (r/s)
[Fri Oct 18 09:59:34.120186 2019] [http2:debug] [pid 10:tid 139649980819200] h2_session.c(593): [client 192.168.192.1:36934] AH03068: h2_session(128,BUSY,11): sent FRAME[RST_STREAM[length=4, flags=0, stream=1843]], frames=1895/2904 (r/s)
[Fri Oct 18 09:59:34.120194 2019] [authz_core:debug] [pid 10:tid 139650130171648] mod_authz_core.c(820): [client 192.168.192.1:36934] AH01626: authorization result of Require all granted: granted, referer: https://localhost/index.html
[Fri Oct 18 09:59:34.120202 2019] [http2:debug] [pid 10:tid 139649980819200] h2_session.c(593): [client 192.168.192.1:36934] AH03068: h2_session(128,BUSY,11): sent FRAME[RST_STREAM[length=4, flags=0, stream=1845]], frames=1895/2905 (r/s)
[Fri Oct 18 09:59:34.120212 2019] [authz_core:debug] [pid 10:tid 139650130171648] mod_authz_core.c(820): [client 192.168.192.1:36934] AH01626: authorization result of <RequireAny>: granted, referer: https://localhost/index.html
[Fri Oct 18 09:59:34.120220 2019] [http2:debug] [pid 10:tid 139649980819200] h2_session.c(593): [client 192.168.192.1:36934] AH03068: h2_session(128,BUSY,11): sent FRAME[RST_STREAM[length=4, flags=0, stream=1847]], frames=1895/2906 (r/s)
[Fri Oct 18 09:59:34.120235 2019] [http2:debug] [pid 10:tid 139649980819200] h2_session.c(593): [client 192.168.192.1:36934] AH03068: h2_session(128,BUSY,11): sent FRAME[RST_STREAM[length=4, flags=0, stream=1849]], frames=1895/2907 (r/s)
[Fri Oct 18 09:59:34.120248 2019] [http2:debug] [pid 10:tid 139649980819200] h2_session.c(593): [client 192.168.192.1:36934] AH03068: h2_session(128,BUSY,11): sent FRAME[RST_STREAM[length=4, flags=0, stream=1851]], frames=1895/2908 (r/s)
[Fri Oct 18 09:59:34.120286 2019] [http2:debug] [pid 10:tid 139649980819200] h2_session.c(593): [client 192.168.192.1:36934] AH03068: h2_session(128,BUSY,11): sent FRAME[RST_STREAM[length=4, flags=0, stream=1853]], frames=1895/2909 (r/s)
[Fri Oct 18 09:59:34.120303 2019] [http2:debug] [pid 10:tid 139649980819200] h2_session.c(593): [client 192.168.192.1:36934] AH03068: h2_session(128,BUSY,11): sent FRAME[RST_STREAM[length=4, flags=0, stream=1855]], frames=1895/2910 (r/s)
[Fri Oct 18 09:59:34.120311 2019] [ssl:debug] [pid 10:tid 139650146973440] ssl_engine_kernel.c(383): [client 192.168.192.1:36934] AH02034: Subsequent (No.2) HTTPS request received for child 554050783019 (server localhost:443), referer: https://localhost/index.html
[Fri Oct 18 09:59:34.120320 2019] [http2:debug] [pid 10:tid 139649980819200] h2_session.c(593): [client 192.168.192.1:36934] AH03068: h2_session(128,BUSY,11): sent FRAME[RST_STREAM[length=4, flags=0, stream=1857]], frames=1895/2911 (r/s)
[Fri Oct 18 09:59:34.120337 2019] [http2:debug] [pid 10:tid 139649980819200] h2_session.c(593): [client 192.168.192.1:36934] AH03068: h2_session(128,BUSY,11): sent FRAME[RST_STREAM[length=4, flags=0, stream=1859]], frames=1895/2912 (r/s)
[Fri Oct 18 09:59:34.120354 2019] [http2:debug] [pid 10:tid 139649980819200] h2_session.c(593): [client 192.168.192.1:36934] AH03068: h2_session(128,BUSY,11): sent FRAME[RST_STREAM[length=4, flags=0, stream=1861]], frames=1895/2913 (r/s)
[Fri Oct 18 09:59:34.120363 2019] [authz_core:debug] [pid 10:tid 139650146973440] mod_authz_core.c(820): [client 192.168.192.1:36934] AH01626: authorization result of Require all granted: granted, referer: https://localhost/index.html
[Fri Oct 18 09:59:34.120378 2019] [authz_core:debug] [pid 10:tid 139650146973440] mod_authz_core.c(820): [client 192.168.192.1:36934] AH01626: authorization result of <RequireAny>: granted, referer: https://localhost/index.html
[Fri Oct 18 09:59:34.120378 2019] [http2:debug] [pid 10:tid 139649980819200] h2_session.c(593): [client 192.168.192.1:36934] AH03068: h2_session(128,BUSY,11): sent FRAME[RST_STREAM[length=4, flags=0, stream=1863]], frames=1895/2914 (r/s)
[Fri Oct 18 09:59:34.122672 2019] [http2:debug] [pid 10:tid 139649980819200] h2_session.c(593): [client 192.168.192.1:36934] AH03068: h2_session(128,BUSY,11): sent FRAME[RST_STREAM[length=4, flags=0, stream=1865]], frames=1895/2915 (r/s)
[Fri Oct 18 09:59:34.122922 2019] [http2:debug] [pid 10:tid 139649980819200] h2_session.c(593): [client 192.168.192.1:36934] AH03068: h2_session(128,BUSY,11): sent FRAME[RST_STREAM[length=4, flags=0, stream=1867]], frames=1895/2916 (r/s)
[Fri Oct 18 09:59:34.122960 2019] [http2:debug] [pid 10:tid 139649980819200] h2_session.c(593): [client 192.168.192.1:36934] AH03068: h2_session(128,BUSY,11): sent FRAME[RST_STREAM[length=4, flags=0, stream=1869]], frames=1895/2917 (r/s)
[Fri Oct 18 09:59:34.122979 2019] [http2:debug] [pid 10:tid 139649980819200] h2_session.c(593): [client 192.168.192.1:36934] AH03068: h2_session(128,BUSY,11): sent FRAME[RST_STREAM[length=4, flags=0, stream=1871]], frames=1895/2918 (r/s)
[Fri Oct 18 09:59:34.123018 2019] [http2:debug] [pid 10:tid 139649980819200] h2_session.c(593): [client 192.168.192.1:36934] AH03068: h2_session(128,BUSY,11): sent FRAME[RST_STREAM[length=4, flags=0, stream=1873]], frames=1895/2919 (r/s)
[Fri Oct 18 09:59:34.123030 2019] [http2:debug] [pid 10:tid 139649980819200] h2_session.c(593): [client 192.168.192.1:36934] AH03068: h2_session(128,BUSY,11): sent FRAME[RST_STREAM[length=4, flags=0, stream=1875]], frames=1895/2920 (r/s)
[Fri Oct 18 09:59:34.123047 2019] [http2:debug] [pid 10:tid 139649980819200] h2_session.c(593): [client 192.168.192.1:36934] AH03068: h2_session(128,BUSY,11): sent FRAME[RST_STREAM[length=4, flags=0, stream=1877]], frames=1895/2921 (r/s)
[Fri Oct 18 09:59:34.123064 2019] [http2:debug] [pid 10:tid 139649980819200] h2_session.c(593): [client 192.168.192.1:36934] AH03068: h2_session(128,BUSY,11): sent FRAME[RST_STREAM[length=4, flags=0, stream=1879]], frames=1895/2922 (r/s)
[Fri Oct 18 09:59:34.123081 2019] [http2:debug] [pid 10:tid 139649980819200] h2_session.c(593): [client 192.168.192.1:36934] AH03068: h2_session(128,BUSY,11): sent FRAME[RST_STREAM[length=4, flags=0, stream=1881]], frames=1895/2923 (r/s)
[Fri Oct 18 09:59:34.123097 2019] [http2:debug] [pid 10:tid 139649980819200] h2_session.c(593): [client 192.168.192.1:36934] AH03068: h2_session(128,BUSY,11): sent FRAME[RST_STREAM[length=4, flags=0, stream=1883]], frames=1895/2924 (r/s)
[Fri Oct 18 09:59:34.123114 2019] [http2:debug] [pid 10:tid 139649980819200] h2_session.c(593): [client 192.168.192.1:36934] AH03068: h2_session(128,BUSY,11): sent FRAME[RST_STREAM[length=4, flags=0, stream=1885]], frames=1895/2925 (r/s)
[Fri Oct 18 09:59:34.123195 2019] [http2:debug] [pid 10:tid 139649980819200] h2_session.c(593): [client 192.168.192.1:36934] AH03068: h2_session(128,BUSY,11): sent FRAME[RST_STREAM[length=4, flags=0, stream=1887]], frames=1895/2926 (r/s)
[Fri Oct 18 09:59:34.123216 2019] [http2:debug] [pid 10:tid 139649980819200] h2_session.c(593): [client 192.168.192.1:36934] AH03068: h2_session(128,BUSY,11): sent FRAME[RST_STREAM[length=4, flags=0, stream=1889]], frames=1895/2927 (r/s)
[Fri Oct 18 09:59:34.123233 2019] [http2:debug] [pid 10:tid 139649980819200] h2_session.c(593): [client 192.168.192.1:36934] AH03068: h2_session(128,BUSY,11): sent FRAME[RST_STREAM[length=4, flags=0, stream=1809]], frames=1895/2928 (r/s)
[Fri Oct 18 09:59:34.123276 2019] [http2:debug] [pid 10:tid 139649980819200] h2_session.c(267): [client 192.168.192.1:36934] AH03065: h2_stream(128-1809,CLOSED): closing with err=1 protocol error

Последняя строка сообщает h2_stream(128-1809,CLOSED): closing with err=1 protocol.

Я проверяю это в следующей среде:

  • Chrome Version77.0.3865.120 (Официальная сборка) (64-разрядная версия) в macOS Catalina 10.15
  • Apache 2.4.41 в контейнере Docker (изображение httpd: последняя )

Чего мне не хватает? Может быть, это ошибка Apache? Ошибка Chrome? Плохая конфигурация Apache?

Заранее спасибо.

...