You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@hc.apache.org by "Oleg Kalnichevski (Jira)" <ji...@apache.org> on 2022/02/02 21:30:00 UTC
[jira] [Commented] (HTTPCLIENT-2201) Exchange handler is null
[ https://issues.apache.org/jira/browse/HTTPCLIENT-2201?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=17486112#comment-17486112 ]
Oleg Kalnichevski commented on HTTPCLIENT-2201:
-----------------------------------------------
[~avasilev] HTTP/2 protocol details are missing in the log. Could you please run the test with the following categories set to DEBUG?
{noformat}
<Logger name="org.apache.hc.client5.http2" level="debug"/>
<Logger name="org.apache.hc.client5.http2.frame.payload" level="debug"/>
{noformat}
The log should look something like that.
{noformat}
2022-02-02 22:22:07,482 DEBUG ex-0000000001 endpoint lease request (3 MINUTES) [route: {}->https://nghttp2.org:443][total available: 0; route allocated: 0 of 5; total allocated: 0 of 25]
2022-02-02 22:22:07,494 DEBUG ex-0000000001 endpoint leased [route: {}->https://nghttp2.org:443][total available: 0; route allocated: 1 of 5; total allocated: 1 of 25]
2022-02-02 22:22:07,495 DEBUG ex-0000000001 acquired ep-0000000000
2022-02-02 22:22:07,495 DEBUG ep-0000000000 connecting endpoint to https://nghttp2.org:443 (3 MINUTES)
2022-02-02 22:22:07,496 DEBUG nghttp2.org resolving remote address
2022-02-02 22:22:07,497 DEBUG nghttp2.org resolved to [nghttp2.org/139.162.123.134, nghttp2.org/2400:8902:0:0:f03c:91ff:fe69:a454]
2022-02-02 22:22:07,498 DEBUG nghttp2.org:443 connecting null->nghttp2.org/139.162.123.134:443 (3 MINUTES)
2022-02-02 22:22:08,604 DEBUG c-0000000000[ACTIVE][rc:c] protocol upgrade class org.apache.hc.core5.http2.impl.nio.ClientHttpProtocolNegotiator
2022-02-02 22:22:08,605 DEBUG nghttp2.org:443 connected null->nghttp2.org/139.162.123.134:443 as c-0000000000
2022-02-02 22:22:08,610 DEBUG c-0000000000 start TLS
2022-02-02 22:22:08,636 DEBUG Enabled protocols: [TLSv1.2]
2022-02-02 22:22:08,636 DEBUG Enabled cipher suites:[TLS_ECDHE_ECDSA_WITH_AES_256_GCM_SHA384, TLS_ECDHE_ECDSA_WITH_AES_128_GCM_SHA256, TLS_ECDHE_RSA_WITH_AES_256_GCM_SHA384, TLS_DHE_RSA_WITH_AES_256_GCM_SHA384, TLS_DHE_DSS_WITH_AES_256_GCM_SHA384, TLS_ECDHE_RSA_WITH_AES_128_GCM_SHA256, TLS_DHE_RSA_WITH_AES_128_GCM_SHA256, TLS_DHE_DSS_WITH_AES_128_GCM_SHA256]
2022-02-02 22:22:08,636 DEBUG Starting handshake (3 MINUTES)
2022-02-02 22:22:08,656 DEBUG c-0000000000[ACTIVE][rw:c][ACTIVE][r][NEED_UNWRAP][0][0][236] Event cleared [c]
2022-02-02 22:22:15,732 DEBUG Secure session established
2022-02-02 22:22:15,732 DEBUG negotiated protocol: TLSv1.2
2022-02-02 22:22:15,732 DEBUG negotiated cipher suite: TLS_ECDHE_ECDSA_WITH_AES_256_GCM_SHA384
2022-02-02 22:22:15,733 DEBUG peer principal: CN=nghttp2.org
2022-02-02 22:22:15,733 DEBUG peer alternative names: [nghttp2.org, www.nghttp2.org]
2022-02-02 22:22:15,733 DEBUG issuer principal: CN=R3, O=Let's Encrypt, C=US
2022-02-02 22:22:15,734 DEBUG c-0000000000[ACTIVE][rw:r][ACTIVE][rw][NOT_HANDSHAKING][62][0][0] Event set [w]
2022-02-02 22:22:15,735 DEBUG c-0000000000[ACTIVE][rw:r][ACTIVE][rw][NOT_HANDSHAKING][62][0][53] 24 bytes written
2022-02-02 22:22:15,735 DEBUG c-0000000000[ACTIVE][rw:r][ACTIVE][r][NOT_HANDSHAKING][62][0][53] Event cleared [w]
2022-02-02 22:22:15,748 DEBUG c-0000000000[ACTIVE][rw:r][ACTIVE][r][NOT_HANDSHAKING][62][0][53] protocol upgrade class org.apache.hc.core5.http2.impl.nio.ClientH2IOEventHandler
2022-02-02 22:22:15,750 DEBUG c-0000000000 >> stream 0 frame: SETTINGS (0x4); flags: (0x0); length: 36
2022-02-02 22:22:15,751 DEBUG c-0000000000 >> HEADER_TABLE_SIZE: 8192
2022-02-02 22:22:15,751 DEBUG c-0000000000 >> ENABLE_PUSH: 1
2022-02-02 22:22:15,751 DEBUG c-0000000000 >> MAX_CONCURRENT_STREAMS: 250
2022-02-02 22:22:15,751 DEBUG c-0000000000 >> INITIAL_WINDOW_SIZE: 65535
2022-02-02 22:22:15,751 DEBUG c-0000000000 >> MAX_FRAME_SIZE: 65536
2022-02-02 22:22:15,751 DEBUG c-0000000000 >> MAX_HEADER_LIST_SIZE: 16777215
2022-02-02 22:22:15,751 DEBUG c-0000000000[ACTIVE][rw:r][ACTIVE][r][NOT_HANDSHAKING][62][0][53] 0 bytes written
2022-02-02 22:22:15,751 DEBUG c-0000000000[ACTIVE][rw:r][ACTIVE][rw][NOT_HANDSHAKING][62][0][53] Event set [w]
2022-02-02 22:22:15,752 DEBUG c-0000000000[ACTIVE][rw:r][ACTIVE][rw][NOT_HANDSHAKING][62][0][53] Event set [w]
2022-02-02 22:22:15,752 DEBUG c-0000000000 << stream 0 flow control 2147418112 -> 2147483647
2022-02-02 22:22:15,752 DEBUG c-0000000000 << stream 0 flow control 2147483647 -> 2147483647
2022-02-02 22:22:15,752 DEBUG c-0000000000 >> stream 0 flow control 65535 -> 65535
2022-02-02 22:22:15,752 DEBUG ep-0000000000 connected c-0000000000
2022-02-02 22:22:15,754 DEBUG ex-0000000002 executing message exchange ep-0000000000
2022-02-02 22:22:15,754 DEBUG ep-0000000000 executing exchange ex-0000000002 over c-0000000000
2022-02-02 22:22:15,755 DEBUG c-0000000000 RequestExecutionCommand with NORMAL priority
2022-02-02 22:22:15,755 DEBUG c-0000000000[ACTIVE][rw:r][ACTIVE][rw][NOT_HANDSHAKING][62][0][53] Enqueued RequestExecutionCommand with priority IMMEDIATE
2022-02-02 22:22:15,756 DEBUG c-0000000000 << stream 0 frame: SETTINGS (0x4); flags: (0x0); length: 24
2022-02-02 22:22:15,756 DEBUG c-0000000000 << MAX_CONCURRENT_STREAMS: 100
2022-02-02 22:22:15,756 DEBUG c-0000000000 << INITIAL_WINDOW_SIZE: 1048576
2022-02-02 22:22:15,756 DEBUG c-0000000000 << 0x8: 1
2022-02-02 22:22:15,756 DEBUG c-0000000000 << HEADER_TABLE_SIZE: 8192
2022-02-02 22:22:15,756 DEBUG c-0000000000[ACTIVE][rw:r][ACTIVE][rw][NOT_HANDSHAKING][62][33][53] Event set [w]
2022-02-02 22:22:15,757 DEBUG c-0000000000[ACTIVE][rw:r][ACTIVE][rw][NOT_HANDSHAKING][62][33][53] 0 bytes read
2022-02-02 22:22:15,757 DEBUG c-0000000000[ACTIVE][rw:r][ACTIVE][rw][NOT_HANDSHAKING][0][0][53] 0 bytes written
2022-02-02 22:22:15,760 DEBUG c-0000000000 << stream 1 flow control 65535 -> 65535
2022-02-02 22:22:15,760 DEBUG c-0000000000 >> stream 1 flow control 1048576 -> 1048576
2022-02-02 22:22:15,761 DEBUG ex-0000000002 send request POST /httpbin/post HTTP/1.1, entity len 5
2022-02-02 22:22:15,763 DEBUG c-0000000000 >> :method: POST
2022-02-02 22:22:15,763 DEBUG c-0000000000 >> :scheme: https
2022-02-02 22:22:15,763 DEBUG c-0000000000 >> :authority: nghttp2.org
2022-02-02 22:22:15,763 DEBUG c-0000000000 >> :path: /httpbin/post
2022-02-02 22:22:15,763 DEBUG c-0000000000 >> content-type: text/plain; charset=ISO-8859-1
2022-02-02 22:22:15,763 DEBUG c-0000000000 >> user-agent: Apache-HttpAsyncClient/5.1.3 (Java/1.8.0_282)
2022-02-02 22:22:15,766 DEBUG c-0000000000[ACTIVE][rw:r][ACTIVE][rw][NOT_HANDSHAKING][0][0][53] Event set [w]
2022-02-02 22:22:15,766 DEBUG ex-0000000002: produce request data
2022-02-02 22:22:15,767 DEBUG ex-0000000002: produce request data, len 5 bytes
2022-02-02 22:22:15,767 DEBUG c-0000000000[ACTIVE][rw:w][ACTIVE][rw][NOT_HANDSHAKING][0][0][74] 45 bytes written
2022-02-02 22:22:15,768 DEBUG c-0000000000 >> stream 0 frame: WINDOW_UPDATE (0x8); flags: (0x0); length: 4
2022-02-02 22:22:15,768 DEBUG c-0000000000 >> Increment 2147418112
2022-02-02 22:22:15,768 DEBUG c-0000000000[ACTIVE][rw:w][ACTIVE][rw][NOT_HANDSHAKING][0][0][74] 0 bytes written
2022-02-02 22:22:15,768 DEBUG ex-0000000002: produce request data
2022-02-02 22:22:15,768 DEBUG ex-0000000002: produce request data, len 5 bytes
2022-02-02 22:22:15,768 DEBUG c-0000000000[ACTIVE][rw:w][ACTIVE][rw][NOT_HANDSHAKING][0][0][42] 13 bytes written
2022-02-02 22:22:15,768 DEBUG c-0000000000 >> stream 0 frame: SETTINGS (0x4); flags: ACK (0x1); length: 0
2022-02-02 22:22:15,768 DEBUG c-0000000000[ACTIVE][rw:w][ACTIVE][rw][NOT_HANDSHAKING][0][0][42] 0 bytes written
2022-02-02 22:22:15,769 DEBUG ex-0000000002: produce request data
2022-02-02 22:22:15,769 DEBUG ex-0000000002: produce request data, len 5 bytes
2022-02-02 22:22:15,769 DEBUG c-0000000000[ACTIVE][rw:w][ACTIVE][rw][NOT_HANDSHAKING][0][0][38] 9 bytes written
2022-02-02 22:22:15,769 DEBUG c-0000000000 >> stream 1 frame: HEADERS (0x1); flags: END_HEADERS (0x4); length: 83
2022-02-02 22:22:15,769 DEBUG c-0000000000 >> ..A..i......D.bt 83 87 41 88 aa 69 d2 9a c4 b9 ec 9b 44 89 62 74
2022-02-02 22:22:15,769 DEBUG c-0000000000 >> ...S.. _.I|..... a6 b8 cd 53 15 9d 09 5f 96 49 7c a5 8a e8 19 aa
2022-02-02 22:22:15,769 DEBUG c-0000000000 >> .P....0d..g.m..z fb 50 93 8e c4 15 30 64 dd a9 67 9e 6d f5 83 7a
2022-02-02 22:22:15,769 DEBUG c-0000000000 >> ....r..)..z...1j a2 86 b1 92 72 ad 8d 29 ae 14 7a a8 97 a8 31 6a
2022-02-02 22:22:15,769 DEBUG c-0000000000 >> K ...S..>.`+..". 4b 0d ae 15 d9 53 fa ca 3e e3 60 2b bc b8 22 13
2022-02-02 22:22:15,769 DEBUG c-0000000000 >> ... c2 fe ff
2022-02-02 22:22:15,769 DEBUG c-0000000000[ACTIVE][rw:w][ACTIVE][rw][NOT_HANDSHAKING][0][0][38] 0 bytes written
2022-02-02 22:22:15,770 DEBUG ex-0000000002: produce request data
2022-02-02 22:22:15,770 DEBUG ex-0000000002: produce request data, len 5 bytes
2022-02-02 22:22:15,770 DEBUG c-0000000000[ACTIVE][rw:w][ACTIVE][rw][NOT_HANDSHAKING][0][0][121] 92 bytes written
2022-02-02 22:22:15,770 DEBUG ex-0000000002: produce request data
2022-02-02 22:22:15,770 DEBUG ex-0000000002: produce request data, len 5 bytes
2022-02-02 22:22:15,770 DEBUG c-0000000000 >> stream 1 frame: DATA (0x0); flags: (0x0); length: 5
2022-02-02 22:22:15,770 DEBUG c-0000000000 >> stuff 73 74 75 66 66
2022-02-02 22:22:15,770 DEBUG c-0000000000 >> stream 0 flow control -5 -> 65530
2022-02-02 22:22:15,770 DEBUG c-0000000000 >> stream 1 flow control -5 -> 1048571
2022-02-02 22:22:15,770 DEBUG c-0000000000[ACTIVE][rw:w][ACTIVE][rw][NOT_HANDSHAKING][0][0][121] 0 bytes written
2022-02-02 22:22:15,771 DEBUG c-0000000000[ACTIVE][rw:w][ACTIVE][rw][NOT_HANDSHAKING][0][0][121] Event set [w]
2022-02-02 22:22:15,771 DEBUG ex-0000000002: end of request data
2022-02-02 22:22:15,771 DEBUG c-0000000000[ACTIVE][rw:w][ACTIVE][rw][NOT_HANDSHAKING][0][0][121] Event set [w]
2022-02-02 22:22:15,771 DEBUG c-0000000000[ACTIVE][rw:w][ACTIVE][rw][NOT_HANDSHAKING][0][0][43] 14 bytes written
2022-02-02 22:22:15,771 DEBUG c-0000000000 >> stream 1 frame: DATA (0x0); flags: END_STREAM (0x1); length: 0
2022-02-02 22:22:15,771 DEBUG c-0000000000[ACTIVE][rw:w][ACTIVE][rw][NOT_HANDSHAKING][0][0][43] 0 bytes written
2022-02-02 22:22:15,772 DEBUG c-0000000000[ACTIVE][rw:w][ACTIVE][rw][NOT_HANDSHAKING][0][0][38] 9 bytes written
2022-02-02 22:22:15,772 DEBUG c-0000000000[ACTIVE][rw:w][ACTIVE][r][NOT_HANDSHAKING][0][0][38] Event cleared [w]
2022-02-02 22:22:16,138 DEBUG c-0000000000 << stream 0 frame: SETTINGS (0x4); flags: ACK (0x1); length: 0
2022-02-02 22:22:16,138 DEBUG c-0000000000[ACTIVE][rw:r][ACTIVE][rw][NOT_HANDSHAKING][38][9][0] Event set [w]
2022-02-02 22:22:16,138 DEBUG c-0000000000[ACTIVE][rw:r][ACTIVE][rw][NOT_HANDSHAKING][38][9][0] 0 bytes read
2022-02-02 22:22:16,142 DEBUG c-0000000000 << stream 1 frame: HEADERS (0x1); flags: END_HEADERS (0x4); length: 247
2022-02-02 22:22:16,142 DEBUG c-0000000000 << ?.?.a..Y>....X.. 3f e1 3f 88 61 96 e4 59 3e 94 00 94 c2 58 d4 10
2022-02-02 22:22:16,143 DEBUG c-0000000000 << .%.......-.._. u 04 25 04 1b 82 15 c0 be a6 2d 1b ff 5f 8b 1d 75
2022-02-02 22:22:16,143 DEBUG c-0000000000 << .b &=LtA.. .369T d0 62 0d 26 3d 4c 74 41 ea 0f 0d 03 33 36 39 54
2022-02-02 22:22:16,143 DEBUG c-0000000000 << .*@...T!b ..z. . 01 2a 40 96 19 08 54 21 62 1e a4 d8 7a 16 1d 14
2022-02-02 22:22:16,144 DEBUG c-0000000000 << .......t#.M..@. 1f c2 c4 b0 b2 16 a4 98 74 23 83 4d 96 97 40 8f
2022-02-02 22:22:16,144 DEBUG c-0000000000 << ..c'R."..r...J. f2 b4 63 27 52 d5 22 d3 94 72 16 c5 ac 4a 7f 86
2022-02-02 22:22:16,144 DEBUG c-0000000000 << ...L..x..~V .... 02 e0 03 4c 89 df 78 8c a4 7e 56 1c c5 81 90 b6
2022-02-02 22:22:16,145 DEBUG c-0000000000 << ...?v..i....@. cb 80 00 3f 76 86 aa 69 d2 9a fc ff 40 85 1d 09
2022-02-02 22:22:16,145 DEBUG c-0000000000 << Y ....?..4....#. 59 1d c9 a1 9d 98 3f 9b 8d 34 cf f3 f6 a5 23 81
2022-02-02 22:22:16,145 DEBUG c-0000000000 << ....'ea?..q...~. 97 00 0f a5 27 65 61 3f 07 f3 71 a6 99 fe 7e d4
2022-02-02 22:22:16,146 DEBUG c-0000000000 << .p2..|. .R..Jk.@ a4 70 32 e0 01 7c 88 0a e1 52 a9 a7 4a 6b f3 40
2022-02-02 22:22:16,146 DEBUG c-0000000000 << .......z.c...... 8b f2 b4 b6 0e 92 ac 7a d2 63 d4 8f 89 dd 0e 8c
2022-02-02 22:22:16,146 DEBUG c-0000000000 << .....O@....!j.:J 1a b6 e4 c5 93 4f 40 8c f2 b7 94 21 6a ec 3a 4a
2022-02-02 22:22:16,147 DEBUG c-0000000000 << D.......B. .'_@ 44 98 f5 7f 8a 0f da 94 9e 42 c1 1d 07 27 5f 40
2022-02-02 22:22:16,147 DEBUG c-0000000000 << ....RKRVO....I.R 90 f2 b1 0f 52 4b 52 56 4f aa ca b1 eb 49 8f 52
2022-02-02 22:22:16,147 DEBUG c-0000000000 << ?...... 3f 85 a8 e8 a8 d2 cb
2022-02-02 22:22:16,149 DEBUG c-0000000000 << :status: 200
2022-02-02 22:22:16,150 DEBUG c-0000000000 << date: Wed, 02 Feb 2022 21:22:19 GMT
2022-02-02 22:22:16,150 DEBUG c-0000000000 << content-type: application/json
2022-02-02 22:22:16,150 DEBUG c-0000000000 << content-length: 369
2022-02-02 22:22:16,150 DEBUG c-0000000000 << access-control-allow-origin: *
2022-02-02 22:22:16,151 DEBUG c-0000000000 << access-control-allow-credentials: true
2022-02-02 22:22:16,151 DEBUG c-0000000000 << x-backend-header-rtt: 0.004327
2022-02-02 22:22:16,151 DEBUG c-0000000000 << strict-transport-security: max-age=31536000
2022-02-02 22:22:16,152 DEBUG c-0000000000 << server: nghttpx
2022-02-02 22:22:16,152 DEBUG c-0000000000 << alt-svc: h3=":443"; ma=3600, h3-29=":443"; ma=3600
2022-02-02 22:22:16,152 DEBUG c-0000000000 << via: 1.1 nghttpx
2022-02-02 22:22:16,153 DEBUG c-0000000000 << x-frame-options: SAMEORIGIN
2022-02-02 22:22:16,153 DEBUG c-0000000000 << x-xss-protection: 1; mode=block
2022-02-02 22:22:16,153 DEBUG c-0000000000 << x-content-type-options: nosniff
2022-02-02 22:22:16,160 DEBUG ex-0000000002: consume response HTTP/2.0 200 OK, entity len -1
2022-02-02 22:22:16,166 DEBUG c-0000000000 << stream 1 frame: DATA (0x0); flags: END_STREAM (0x1); length: 369
2022-02-02 22:22:16,166 DEBUG c-0000000000 << { "args": {}, 7b 0a 20 20 22 61 72 67 73 22 3a 20 7b 7d 2c 20
2022-02-02 22:22:16,166 DEBUG c-0000000000 << "data": "stuf 0a 20 20 22 64 61 74 61 22 3a 20 22 73 74 75 66
2022-02-02 22:22:16,166 DEBUG c-0000000000 << f", "files": 66 22 2c 20 0a 20 20 22 66 69 6c 65 73 22 3a 20
2022-02-02 22:22:16,167 DEBUG c-0000000000 << {}, "form": { 7b 7d 2c 20 0a 20 20 22 66 6f 72 6d 22 3a 20 7b
2022-02-02 22:22:16,167 DEBUG c-0000000000 << }, "headers": 7d 2c 20 0a 20 20 22 68 65 61 64 65 72 73 22 3a
2022-02-02 22:22:16,167 DEBUG c-0000000000 << { "Content- 20 7b 0a 20 20 20 20 22 43 6f 6e 74 65 6e 74 2d
2022-02-02 22:22:16,167 DEBUG c-0000000000 << Type": "text/pla 54 79 70 65 22 3a 20 22 74 65 78 74 2f 70 6c 61
2022-02-02 22:22:16,167 DEBUG c-0000000000 << in; charset=ISO- 69 6e 3b 20 63 68 61 72 73 65 74 3d 49 53 4f 2d
2022-02-02 22:22:16,167 DEBUG c-0000000000 << 8859-1", "H 38 38 35 39 2d 31 22 2c 20 0a 20 20 20 20 22 48
2022-02-02 22:22:16,168 DEBUG c-0000000000 << ost": "nghttp2.o 6f 73 74 22 3a 20 22 6e 67 68 74 74 70 32 2e 6f
2022-02-02 22:22:16,168 DEBUG c-0000000000 << rg", "Trans 72 67 22 2c 20 0a 20 20 20 20 22 54 72 61 6e 73
2022-02-02 22:22:16,168 DEBUG c-0000000000 << fer-Encoding": " 66 65 72 2d 45 6e 63 6f 64 69 6e 67 22 3a 20 22
2022-02-02 22:22:16,168 DEBUG c-0000000000 << chunked", " 63 68 75 6e 6b 65 64 22 2c 20 0a 20 20 20 20 22
2022-02-02 22:22:16,168 DEBUG c-0000000000 << User-Agent": "Ap 55 73 65 72 2d 41 67 65 6e 74 22 3a 20 22 41 70
2022-02-02 22:22:16,168 DEBUG c-0000000000 << ache-HttpAsyncCl 61 63 68 65 2d 48 74 74 70 41 73 79 6e 63 43 6c
2022-02-02 22:22:16,169 DEBUG c-0000000000 << ient/5.1.3 (Java 69 65 6e 74 2f 35 2e 31 2e 33 20 28 4a 61 76 61
2022-02-02 22:22:16,169 DEBUG c-0000000000 << /1.8.0_282)" } 2f 31 2e 38 2e 30 5f 32 38 32 29 22 0a 20 20 7d
2022-02-02 22:22:16,169 DEBUG c-0000000000 << , "json": nul 2c 20 0a 20 20 22 6a 73 6f 6e 22 3a 20 6e 75 6c
2022-02-02 22:22:16,169 DEBUG c-0000000000 << l, "origin": 6c 2c 20 0a 20 20 22 6f 72 69 67 69 6e 22 3a 20
2022-02-02 22:22:16,169 DEBUG c-0000000000 << "213.55.224.115" 22 32 31 33 2e 35 35 2e 32 32 34 2e 31 31 35 22
2022-02-02 22:22:16,169 DEBUG c-0000000000 << , "url": "htt 2c 20 0a 20 20 22 75 72 6c 22 3a 20 22 68 74 74
2022-02-02 22:22:16,170 DEBUG c-0000000000 << ps://nghttp2.org 70 73 3a 2f 2f 6e 67 68 74 74 70 32 2e 6f 72 67
2022-02-02 22:22:16,170 DEBUG c-0000000000 << /httpbin/post" } 2f 68 74 74 70 62 69 6e 2f 70 6f 73 74 22 0a 7d
2022-02-02 22:22:16,170 DEBUG c-0000000000 << 0a
2022-02-02 22:22:16,170 DEBUG c-0000000000 << stream 1 flow control -369 -> 65166
2022-02-02 22:22:16,170 DEBUG c-0000000000 << stream 0 flow control -369 -> 2147483278
2022-02-02 22:22:16,171 DEBUG ex-0000000002: consume response data, len 369 bytes
2022-02-02 22:22:16,171 DEBUG ex-0000000002: end of response data
2022-02-02 22:22:16,171 DEBUG ep-0000000000 releasing endpoint
2022-02-02 22:22:16,172 DEBUG ep-0000000000 connection c-0000000000 can be kept alive indefinitely
2022-02-02 22:22:16,173 DEBUG ep-0000000000 connection released [route: {}->https://nghttp2.org:443][total available: 1; route allocated: 1 of 5; total allocated: 1 of 25]
2022-02-02 22:22:16,174 DEBUG c-0000000000[ACTIVE][rw:r][ACTIVE][rw][NOT_HANDSHAKING][701][634][0] Event set [w]
2022-02-02 22:22:16,174 DEBUG c-0000000000[ACTIVE][rw:r][ACTIVE][rw][NOT_HANDSHAKING][701][634][0] 0 bytes read
2022-02-02 22:22:16,174 DEBUG c-0000000000[ACTIVE][r:r][ACTIVE][r][NOT_HANDSHAKING][0][0][0] Event cleared [w]
2022-02-02 22:22:16,174 DEBUG Shutdown GRACEFUL
2022-02-02 22:22:16,177 DEBUG c-0000000000[ACTIVE][rw:r][ACTIVE][rw][NOT_HANDSHAKING][0][0][0] Enqueued ShutdownCommand with priority NORMAL
2022-02-02 22:22:16,177 DEBUG c-0000000000[ACTIVE][r:w][ACTIVE][r][NOT_HANDSHAKING][0][0][0] Event cleared [w]
2022-02-02 22:22:16,178 DEBUG c-0000000000 >> stream 0 frame: GOAWAY (0x7); flags: (0x0); length: 25
2022-02-02 22:22:16,178 DEBUG c-0000000000 >> Last stream 0
2022-02-02 22:22:16,179 DEBUG c-0000000000 >> Code NO_ERROR
2022-02-02 22:22:16,179 DEBUG c-0000000000 >> Graceful shutdown
2022-02-02 22:22:16,179 DEBUG c-0000000000[ACTIVE][r:w][ACTIVE][r][NOT_HANDSHAKING][0][0][63] 34 bytes written
2022-02-02 22:22:16,179 DEBUG c-0000000000[ACTIVE][rw:w][ACTIVE][rw][NOT_HANDSHAKING][0][0][63] Event set [w]
2022-02-02 22:22:16,180 DEBUG c-0000000000[ACTIVE][rw:w][ACTIVE][rw][NOT_HANDSHAKING][0][0][63] Close GRACEFUL
{noformat}
Oleg
> Exchange handler is null
> ------------------------
>
> Key: HTTPCLIENT-2201
> URL: https://issues.apache.org/jira/browse/HTTPCLIENT-2201
> Project: HttpComponents HttpClient
> Issue Type: Bug
> Components: HttpClient (async)
> Affects Versions: 5.2-alpha1
> Reporter: Andrei Vasilev
> Priority: Major
> Attachments: app.log
>
>
> I am running into an issue with line 156 of ClientPushH2StreamHandler. The method updateInputCapacity() is being called and exchangeHandler is null, resulting in an IllegalStateException.
> This logic is quite deep in the HttpClient so I have no idea what I am dealing with. Any possible ideas on why this would happen? I see that the exchangeHandler is initialized in consumePromise, but updateInputCapacity is being called before that resulting in the field being null still.
> I can potentially provide a project to reproduce the issue, but that would take some effort because this is happening deep within my own company's product, and so I would have to take some time to determine what minimal amount of logic is needed to actually cause the issue.
> I was hoping maybe someone can provide some initial insight into the issue before I do that.
> https://github.com/apache/httpcomponents-core/blob/master/httpcore5-h2/src/main/java/org/apache/hc/core5/http2/impl/nio/ClientPushH2StreamHandler.java
--
This message was sent by Atlassian Jira
(v8.20.1#820001)
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@hc.apache.org
For additional commands, e-mail: dev-help@hc.apache.org