Как правильно сделать Http2 с Apache HttpCient-5 Beta - PullRequest
0 голосов
/ 06 февраля 2019

HI Я пытаюсь написать клиент, который отправляет запрос http2 на несколько серверов (который уже поддерживает http2).до сих пор я написал эту автономную программу, которая прекрасно работает, и я вижу, что все запросы проходят через одно и то же tcp-соединение (проверено с помощью wireshark).Я использую Apache Httpclient 5 с concerypt для поддержки ALPN в jdk8 (jdk8 - это мое требование, я не могу перейти на jdk9 или более позднюю версию)

Основной блок выглядит так:

try {
    TrustManager[] trustAllCerts = new TrustManager[]{
        new X509TrustManager(){
            public X509Certificate[] getAcceptedIssuers(){ return null; }
            public void checkClientTrusted(X509Certificate[] certs, String authType) {}
            public void checkServerTrusted(X509Certificate[] certs, String authType) {}
        }
    };
    Provider provider = Conscrypt.newProvider();

    SSLContext sslContext = SSLContext.getInstance("TLSv1.3", provider);
    sslContext.init(null, trustAllCerts, new SecureRandom());

    client = Http2AsyncClientBuilder.create().setTlsStrategy(new ConscryptClientTlsStrategy(sslContext)).setH2Config(H2Config.DEFAULT).build();
    client.start();

    ThreadPoolExecutor tpe = (ThreadPoolExecutor)Executors.newFixedThreadPool(50);
    for (int i=0; i < 50; i++) {
        Runnable worker = new WorkerClass(client, i);
        tpe.execute(worker);
    }
} catch (Exception e) {
    e.printStackTrace();
}

Выполнение выполняетсянапример,

static class WorkerClass implements Runnable {
    CloseableHttpAsyncClient client = null;
    int i = 0;
    WorkerClass(CloseableHttpAsyncClient client, int i) {
        this.client = client;
        this.i = i;
    }
    public void run() {
        RequestConfig requestConfig = RequestConfig.custom()
                .setConnectTimeout(Timeout.of(15, TimeUnit.SECONDS))//Determines the timeout until a new connection is fully established.
                .setConnectionRequestTimeout(Timeout.of(60, TimeUnit.SECONDS))//Returns the connection lease request timeout used when requesting a connection from the connection manager.
                .setResponseTimeout(Timeout.of(60, TimeUnit.SECONDS))//Determines the timeout until arrival of a response from the opposite endpoint.
                .build();

        String url = "https://localhost:8081/myagent/getOutput?"+System.currentTimeMillis();
        String cachedXMLRequest = "<?xml version=\"1.0\" standalone=\"no\"?><My XML REQUEST GOES HERE>";
        SimpleHttpRequest request= SimpleHttpRequests.POST.create(url);         
        request.setBodyText(cachedXMLRequest, ContentType.APPLICATION_JSON);
        request.setConfig(requestConfig);           
        final CountDownLatch latch = new CountDownLatch(1);         
        client.execute(request, new FutureCallback<SimpleHttpResponse>() {
            @Override
            public void cancelled() {
                System.out.println("Cancelled");
                latch.countDown();
            }

            @Override
            public void completed(SimpleHttpResponse arg0) {
                System.out.println("Completed "+arg0.getBodyText());
                latch.countDown();
            }

            @Override
            public void failed(Exception exception) {
                System.out.println("Failed ");
                exception.printStackTrace();
                latch.countDown();
            }
        });

        try {
            latch.await(60, TimeUnit.SECONDS);
        } catch (InterruptedException e) {
            // TODO Auto-generated catch block
            e.printStackTrace();
        }
    }
}

Итак, я смоделировал это автономное приложение в моем клиенте, которое асинхронно вызывает несколько серверов для опроса, используя вышеуказанную логику.Но здесь я вижу одно tcp-соединение на запрос, и соединение закрывается в конце запроса (хотя заголовок ответа возвращается как HTTP / 2.0).Я использую код основного блока для инициализации клиента при запуске моего приложения (за исключением части пула потоков, поскольку он используется для имитации многопоточной среды в автономном режиме), а также для создания объектов url, request и response и одновременного выполнения каждого запроса в поточной модели.(Асинхронное мультиплексирование).Мое требование - использовать одно tcp-соединение на домен и использовать его в течение длительного времени для обработки большого количества запросов.Что мне здесь не хватает?

Или кто-то помогает мне правильно обращаться с http2 с помощью httpclient 5

Кинди проливает свет на это.

Отредактировано :

Есть две вещи, которые я отследил на предмет аварийного закрытия соединения:

1.Соединение закрывается после каждого отдельного запроса

Причина: вызвано этой строкой

RequestConfig requestConfig = RequestConfig.custom (). setConnectTimeout (Timeout.of (15, TimeUnit.SECONDS)) ...

Этот setConnectTimeout должен быть на уровне запроса, но через 15 секунд простоя он закрывает само соединение tcp, я не знаю, является ли это ошибкой или ожидаемойповедение этой конфигурации для инкапсуляции элементов запроса согласно документации .

Удаление этой строки позволяет поддерживать соединение tcp более чем на запрос.

2.Из-за недопустимого фрейма HEADERS / протокола ERROR / INTERNAL ERROR

я вижу эти исключения в журнале проводов именно там, где мое tcp-соединение закрывается (оно закрывается случайным образом), я не мог поделиться всеми журналами, так каких слишком много, я просто публикую часть исключения

0x0] [0x1] [0x0] [0x0] [0x4] [0xffffffc9] "

2019-02-07 16:05: 08,666 DEBUG - i / o-0000001B << поток 0 кадр: WINDOW_UPDATE (0x8); флаги: (0x0); длина: 4 </p>

2019-02-07 16: 05: 08,666 DEBUG - i /o-0000001B << Увеличение 1225 </p>

2019-02-07 16: 05: 08,666 DEBUG - i / o-0000001B >> Управление потоком 0 1225 -> 65535

2019-02-07 16: 05: 08,666 DEBUG - i / o-0000001B << поток 1 кадр: WINDOW_UPDATE (0x8); флаги: (0x0); длина: 4 </p>

2019-02-07 16: 05: 08,666 DEBUG- i / o-0000001B << Инкремент 1225 </p>

2019-02-07 16: 05: 08,666 DEBUG - i / o-0000001B >> Управление потоком 1 потока 1225 -> 65535

2019-02-07 16: 05: 08,827 DEBUG - i / o-0000001B << "[0x0] [0x0] [0x1d] [0x1] [0x4][0x0] [0x0] [0x0] [0x5]? [0xffffffe1]? [0xffffff88] [0x1F] [0x12] [0xffffff96] [0xffffffdf] = [0xffffffbf] J [0x1] [0xffffffd5] 0 [0xffffff96] 5 [0x4] [0x0] [0xffffffbe] [0xffffffa0] Aq [0xffffff91] [0x10] [0xffffff94] [0xffffffc5] [0xffffffa3] [0x0] [0x3] E [0x0] [0x1] [0x0] [0x0] [0x0] [0x5] [\ n] "</p>

2019-02-07 16: 05: 08,827 DEBUG - i / o-0000001B <<" [\ n] "</p>

2019-02-07 16:05: 08,827 DEBUG - i / o-0000001B << "" </p>

2019-02-07 16: 05: 08,827 DEBUG - i / o-0000001B << поток 5, кадр: HEADERS (0x1);флаги: END_HEADERS (0x4);длина: 29 </p>

2019-02-07 16: 05: 08,828 DEBUG - i / o-0000001B <<?.?.... =. J..0.5 3f e1 3f 88 1f 12 96 df 3d bf 4a 01 d5 30 96 35 </p>

2019-02-07 16: 05: 08,828 DEBUG - i / o-0000001B << .... Aq ..... 04 00 be a0 41 71 91 5c 10 94 c5 a3 7f </p>

2019-02-07 16: 05: 08,828 DEBUG - i / o-0000001B >> кадр потока 0: GOAWAY (0x7);флаги: (0x0);длина: 29

2019-02-07 16: 05: 08,828 DEBUG - i / o-0000001B >> Последний поток 0

2019-02-07 16: 05: 08,829 DEBUG - i/ o-0000001B >> Код PROTOCOL_ERROR

2019-02-07 16: 05: 08,829 DEBUG - i / o-0000001B >> Рамка незаконных заголовков

2019-02-07 16:05: 08,829 DEBUG - i / o-0000001B >> "[0x0] [0x0] [0x1d] [0x7] [0x0] [0x0] [0x0] [0x0] [0x0] [0x0] [0x0] [0x0] [0x0] [0x0] [0x0] [0x0] [0x1] Недопустимый кадр HEADERS "

2019-02-07 16: 05: 10,401 DEBUG - ex-0000018D: подготовка запроса на исполнение

и,

2019-02-07 16: 17: 17,519 ОТЛАДКА - i / o-0000000C << поток 0 кадр: WINDOW_UPDATE (0x8);флаги: (0x0);длина: 4 </p>

2019-02-07 16: 17: 17 519 DEBUG - i / o-0000000C << Увеличение 1208 </p>

2019-02-07 16: 17: 17 519 DEBUG - i /o-0000000C >> поток 0, управление потоком 1208 -> 65535

2019-02-07 16: 17: 17,519 DEBUG - i / o-0000000C << поток 1 кадр: WINDOW_UPDATE (0x8);флаги: (0x0);длина: 4 </p>

2019-02-07 16: 17: 17 519 DEBUG - i / o-0000000C << Увеличение 1208 </p>

2019-02-07 16: 17: 17 519 DEBUG - i /o-0000000C >> управление потоком потока 1 1208 -> 65535

2019-02-07 16: 17: 17 569 DEBUG - i / o-0000000C << "[0x0] [0x0] [0x4] [0x3] [0x0] [0x0] [0x0] [0x0] [0x3] [0x0] [0x0] [0x0] [0x2] "</p>

2019-02-07 16: 17: 17,569 DEBUG - ввод / вывод-0000000C << кадр 3 потока: RST_STREAM (0x3);флаги: (0x0);длина: 4 </p>

2019-02-07 16: 17: 17 569 DEBUG - i / o-0000000C << Код INTERNAL_ERROR </p>

2019-02-07 16: 17: 17 569 DEBUG - i /o-0000000C >> поток 0 кадр: GOAWAY (0x7);флаги: (0x0);длина: 31

2019-02-07 16: 17: 17 569 DEBUG - i / o-0000000C >> Последний поток 0

2019-02-07 16: 17: 17 569 DEBUG - i/ o-0000000C >> Код PROTOCOL_ERROR

2019-02-07 16: 17: 17,569 DEBUG - i / o-0000000C >> Неожиданный идентификатор потока: 3

Я не знаюЯ не знаю, что вызывает эти исключения. Я пытался использовать как статические, так и динамические данные тела сообщения, и оба ведут себя одинаково

Полные журналы сеансов :

https://drive.google.com/open?id=12y8HnaMTrPo-NBeLaoCYpK6zklJBL56T

https://drive.google.com/open?id=16KHgqLWrwz3Z3ls3Yvpp58zOI3SUNATM

Клиент : Tomcat 9.0x, Jdk 1.8.x (с concerypt для поддержки ALPN, и мы подключаем его через TLSv1.3) в Ubuntu 16.x

Сервер : Tomcat 9.0x (с реализацией openssl, разъемом NIO, поддержкой http2), Openssl 1.1.1 для поддержки TLSv1.3, JDK 10.0.2 в ubuntu 14.x

Любая помощь будет оценена

TIA

1 Ответ

0 голосов
/ 07 февраля 2019

Случай 1: сервер отправляет HEADERS из последовательности.

ОБНОВЛЕНИЕ

Случай 2: сервер отправляет RST_STREAM для незанятого потока

Это похоже на ошибку в Tomcat.Вот журнал сеанса для одного соединения с только содержимым DATA фрейма для краткости

2019-02-07 16:15:47,389 DEBUG - i/o-00000003 >> stream 0 frame: SETTINGS (0x4); flags: (0x0); length: 36
2019-02-07 16:15:47,389 DEBUG - i/o-00000003 >> HEADER_TABLE_SIZE: 8192
2019-02-07 16:15:47,389 DEBUG - i/o-00000003 >> ENABLE_PUSH: 0
2019-02-07 16:15:47,389 DEBUG - i/o-00000003 >> MAX_CONCURRENT_STREAMS: 100
2019-02-07 16:15:47,389 DEBUG - i/o-00000003 >> INITIAL_WINDOW_SIZE: 65535
2019-02-07 16:15:47,389 DEBUG - i/o-00000003 >> MAX_FRAME_SIZE: 65536
2019-02-07 16:15:47,389 DEBUG - i/o-00000003 >> MAX_HEADER_LIST_SIZE: 16777215
2019-02-07 16:15:47,389 DEBUG - i/o-00000003 >> "[0x0][0x0]$[0x4][0x0][0x0][0x0][0x0][0x0][0x0][0x1][0x0][0x0] [0x0][0x0][0x2][0x0][0x0][0x0][0x0][0x0][0x3][0x0][0x0][0x0]d[0x0][0x4][0x0][0x0][0xffffffff][0xffffffff][0x0][0x5][0x0][0x1][0x0][0x0][0x0][0x6][0x0][0xffffffff][0xffffffff][0xffffffff]"
2019-02-07 16:15:47,393 DEBUG - i/o-00000003 << "[0x0][0x0][0x6][0x4][0x0][0x0][0x0][0x0][0x0][0x0][0x3][0x0][0x0][0x0][0xffffffc8][0x0][0x0][0x0][0x4][0x1][0x0][0x0][0x0][0x0][0x0][0x0][0x8][0x6][0x0][0x0][0x0][0x0][0x0][0x0][0x0][0x0][0x0][0x0][0x0][0x0][0x1]"
2019-02-07 16:15:47,393 DEBUG - i/o-00000003 << stream 0 frame: SETTINGS (0x4); flags: (0x0); length: 6
2019-02-07 16:15:47,393 DEBUG - i/o-00000003 << MAX_CONCURRENT_STREAMS: 200
2019-02-07 16:15:47,393 DEBUG - i/o-00000003 >> stream 0 frame: SETTINGS (0x4); flags: ACK (0x1); length: 0
2019-02-07 16:15:47,393 DEBUG - i/o-00000003 >> "[0x0][0x0][0x0][0x4][0x1][0x0][0x0][0x0][0x0]"
2019-02-07 16:15:47,393 DEBUG - i/o-00000003 << stream 0 frame: SETTINGS (0x4); flags: ACK (0x1); length: 0
2019-02-07 16:15:47,393 DEBUG - i/o-00000003 << stream 0 frame: PING (0x6); flags: (0x0); length: 8
2019-02-07 16:15:47,393 DEBUG - i/o-00000003 << ........          00 00 00 00 00 00 00 01
2019-02-07 16:15:47,393 DEBUG - i/o-00000003 >> stream 0 frame: PING (0x6); flags: ACK (0x1); length: 8
2019-02-07 16:15:47,393 DEBUG - i/o-00000003 >> ........          00 00 00 00 00 00 00 01
2019-02-07 16:15:47,393 DEBUG - i/o-00000003 >> "[0x0][0x0][0x8][0x6][0x1][0x0][0x0][0x0][0x0][0x0][0x0][0x0][0x0][0x0][0x0][0x0][0x1]"
2019-02-07 16:15:47,393 DEBUG - i/o-00000003 >> :method: POST
2019-02-07 16:15:47,393 DEBUG - i/o-00000003 >> :scheme: https
2019-02-07 16:15:47,393 DEBUG - i/o-00000003 >> :authority: 172.21.170.214:8999
2019-02-07 16:15:47,393 DEBUG - i/o-00000003 >> :path: /monitoragent/getdcoutput?1000000004286_1520339351002_1549536347382
2019-02-07 16:15:47,393 DEBUG - i/o-00000003 >> user-agent: Apache-HttpAsyncClient/5.0-beta3 (Java/1.8.0_162)
2019-02-07 16:15:47,393 DEBUG - i/o-00000003 >> content-type: application/json; charset=UTF-8
2019-02-07 16:15:47,393 DEBUG - i/o-00000003 >> stream 1 frame: HEADERS (0x1); flags: END_HEADERS (0x4); length: 130
...
2019-02-07 16:15:47,394 DEBUG - i/o-00000003 >> stream 1 frame: DATA (0x0); flags: (0x0); length: 1208
...
2019-02-07 16:15:47,394 DEBUG - i/o-00000003 >> stream 0 flow control -1208 -> 64327
2019-02-07 16:15:47,394 DEBUG - i/o-00000003 >> stream 1 flow control -1208 -> 64327
...
2019-02-07 16:15:47,394 DEBUG - i/o-00000003 >> stream 1 frame: DATA (0x0); flags: END_STREAM (0x1); length: 0
2019-02-07 16:15:47,394 DEBUG - i/o-00000003 >> "[0x0][0x0][0x0][0x0][0x1][0x0][0x0][0x0][0x1]"
2019-02-07 16:15:47,395 DEBUG - i/o-00000003 >> :method: POST
2019-02-07 16:15:47,395 DEBUG - i/o-00000003 >> :scheme: https
2019-02-07 16:15:47,395 DEBUG - i/o-00000003 >> :authority: 172.21.170.214:8999
2019-02-07 16:15:47,395 DEBUG - i/o-00000003 >> :path: /monitoragent/getdcoutput?1000000004286_1520339351002_1549536347382
2019-02-07 16:15:47,395 DEBUG - i/o-00000003 >> user-agent: Apache-HttpAsyncClient/5.0-beta3 (Java/1.8.0_162)
2019-02-07 16:15:47,395 DEBUG - i/o-00000003 >> content-type: application/json; charset=UTF-8
2019-02-07 16:15:47,395 DEBUG - i/o-00000003 >> stream 3 frame: HEADERS (0x1); flags: END_HEADERS (0x4); length: 6
2019-02-07 16:15:47,395 DEBUG - i/o-00000003 >> ......            83 87 c1 c0 bf be
2019-02-07 16:15:47,395 DEBUG - i/o-00000003 >> "[0x0][0x0][0x6][0x1][0x4][0x0][0x0][0x0][0x3][0xffffff83][0xffffff87][0xffffffc1][0xffffffc0][0xffffffbf][0xffffffbe]"
...
2019-02-07 16:15:47,395 DEBUG - i/o-00000003 >> stream 0 flow control -1208 -> 63119
2019-02-07 16:15:47,395 DEBUG - i/o-00000003 >> stream 3 flow control -1208 -> 64327
...
2019-02-07 16:15:47,396 DEBUG - i/o-00000003 >> stream 3 frame: DATA (0x0); flags: END_STREAM (0x1); length: 0
2019-02-07 16:15:47,396 DEBUG - i/o-00000003 >> "[0x0][0x0][0x0][0x0][0x1][0x0][0x0][0x0][0x3]"
2019-02-07 16:15:47,399 DEBUG - i/o-00000003 << "[0x0][0x0][0x4][0x8][0x0][0x0][0x0][0x0][0x0][0x0][0x0][0x4][0xffffffb8][0x0][0x0][0x4][0x8][0x0][0x0][0x0][0x0][0x3][0x0][0x0][0x4][0xffffffb8]"
2019-02-07 16:15:47,399 DEBUG - i/o-00000003 << stream 0 frame: WINDOW_UPDATE (0x8); flags: (0x0); length: 4
2019-02-07 16:15:47,399 DEBUG - i/o-00000003 << Increment 1208
2019-02-07 16:15:47,399 DEBUG - i/o-00000003 >> stream 0 flow control 1208 -> 64327
2019-02-07 16:15:47,399 DEBUG - i/o-00000003 << stream 3 frame: WINDOW_UPDATE (0x8); flags: (0x0); length: 4
2019-02-07 16:15:47,399 DEBUG - i/o-00000003 << Increment 1208
2019-02-07 16:15:47,399 DEBUG - i/o-00000003 >> stream 3 flow control 1208 -> 65535
2019-02-07 16:15:47,399 DEBUG - i/o-00000003 << "[0x0][0x0][0x4][0x8][0x0][0x0][0x0][0x0][0x0][0x0][0x0][0x4][0xffffffb8][0x0][0x0][0x4][0x8][0x0][0x0][0x0][0x0][0x1][0x0][0x0][0x4][0xffffffb8]"
2019-02-07 16:15:47,399 DEBUG - i/o-00000003 << stream 0 frame: WINDOW_UPDATE (0x8); flags: (0x0); length: 4
2019-02-07 16:15:47,399 DEBUG - i/o-00000003 << Increment 1208
2019-02-07 16:15:47,399 DEBUG - i/o-00000003 >> stream 0 flow control 1208 -> 65535
2019-02-07 16:15:47,399 DEBUG - i/o-00000003 << stream 1 frame: WINDOW_UPDATE (0x8); flags: (0x0); length: 4
2019-02-07 16:15:47,399 DEBUG - i/o-00000003 << Increment 1208
2019-02-07 16:15:47,399 DEBUG - i/o-00000003 >> stream 1 flow control 1208 -> 65535
2019-02-07 16:15:47,503 DEBUG - i/o-00000003 << "[0x0][0x0][0x4][0x3][0x0][0x0][0x0][0x0]3[0x0][0x0][0x0][0x2]"
2019-02-07 16:15:47,503 DEBUG - i/o-00000003 << stream 51 frame: RST_STREAM (0x3); flags: (0x0); length: 4
2019-02-07 16:15:47,503 DEBUG - i/o-00000003 << Code INTERNAL_ERROR
2019-02-07 16:15:47,503 DEBUG - i/o-00000003 >> stream 0 frame: GOAWAY (0x7); flags: (0x0); length: 32
2019-02-07 16:15:47,503 DEBUG - i/o-00000003 >> Last stream 0
2019-02-07 16:15:47,503 DEBUG - i/o-00000003 >> Code PROTOCOL_ERROR
2019-02-07 16:15:47,503 DEBUG - i/o-00000003 >> Unexpected stream id: 51
2019-02-07 16:15:47,504 DEBUG - i/o-00000003 >> "[0x0][0x0] [0x7][0x0][0x0][0x0][0x0][0x0][0x0][0x0][0x0][0x0][0x0][0x0][0x0][0x1]Unexpected stream id: 51"  

В конце обмена сообщениями сервер отправляет RST_STREAM для потока 51. Поток 51 не былоБыли потоки 1 и 3, оба из которых были правильно закрыты.Затем по какой-либо причине сервер решает прекратить свободный поток 51. Клиент рассматривает такое действие как серьезное нарушение протокола согласно RFC 7540, section 6.4

RST_STREAM frames MUST NOT be sent for a stream in the "idle" state.
If a RST_STREAM frame identifying an idle stream is received, the
recipient MUST treat this as a connection error (Section 5.4.1) of
type PROTOCOL_ERROR.

Пожалуйста, обновите до последней версии Tomcat 9 иПроблема не устранена. Сообщите об этом разработчикам Tomcat.

...