Как правильно сделать Http2 с Apache HttpCient-5 Beta

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();
}

Runnable идет как,

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. Из-за кадра незаконных заголовков / протокола ошибки / внутренней ошибки

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

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

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

2019-02-07 16: 05: 08,666 DEBUG - I / O-0000001B << Инкремент 1225

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

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

2019-02-07 16: 05: 08,666 DEBUG - I / O-0000001B << Инкремент 1225

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]"

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

2019-02-07 16: 05: 08,827 DEBUG - I / O-0000001B << ""

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

2019-02-07 16:05:08,828 DEBUG - i/o-0000001B <

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

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 ОТЛАДКА - 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] Кадр незаконных заголовков "

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

а также,

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

2019-02-07 16: 17: 17,519 DEBUG - I / O-0000000C << Приращение 1208

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

2019-02-07 16: 17: 17,519 DEBUG - I / O-0000000C << Приращение 1208

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]"

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

2019-02-07 16: 17: 17 569 DEBUG - I / O-0000000C << Код INTERNAL_ERROR

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

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

ТИА

Источник

1 ответ

Случай 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.

Источник
Другие вопросы по тегам