One other note, is I can switch to h2c, and it still fails, and a packet
capture shows the entire JSON is delivered to Tomcat, and when I put the
JSON from the packet inspection together (Packets 10199 --> 10208) and
compare it to what the browser says was sent, they are identical. There are
no signs of TCP retransmissions or other things you might expect to see if
there was a networking related issue.

1048 2.473101 sourceip destinationip TCP 71 58116 → 18443 [PSH, ACK] Seq=1
Ack=1 Win=8212 Len=17
1049 2.473232 sourceip destinationip TCP 1514 58116 → 18443 [ACK] Seq=18
Ack=1 Win=8212 Len=1460
1050 2.473232 sourceip destinationip TCP 1155 58116 → 18443 [PSH, ACK]
Seq=1478 Ack=1 Win=8212 Len=1101
1053 2.484659 sourceip destinationip TCP 60 58116 → 18443 [ACK] Seq=2579
Ack=18 Win=8212 Len=0
1055 2.487967 sourceip destinationip TCP 71 58116 → 18443 [PSH, ACK]
Seq=2579 Ack=35 Win=8212 Len=17
10199 22.689703 sourceip destinationip TCP 1514 58116 → 18443 [ACK]
Seq=2596 Ack=147 Win=8211 Len=1460
10200 22.689703 sourceip destinationip TCP 1514 58116 → 18443 [ACK]
Seq=4056 Ack=147 Win=8211 Len=1460
10201 22.689703 sourceip destinationip TCP 1514 58116 → 18443 [ACK]
Seq=5516 Ack=147 Win=8211 Len=1460
10202 22.689703 sourceip destinationip TCP 1514 58116 → 18443 [ACK]
Seq=6976 Ack=147 Win=8211 Len=1460
10203 22.689703 sourceip destinationip TCP 1514 58116 → 18443 [ACK]
Seq=8436 Ack=147 Win=8211 Len=1460
10204 22.689703 sourceip destinationip TCP 1514 58116 → 18443 [ACK]
Seq=9896 Ack=147 Win=8211 Len=1460
10205 22.689703 sourceip destinationip TCP 1514 58116 → 18443 [ACK]
Seq=11356 Ack=147 Win=8211 Len=1460
10206 22.689703 sourceip destinationip TCP 1514 58116 → 18443 [ACK]
Seq=12816 Ack=147 Win=8211 Len=1460
10207 22.689703 sourceip destinationip TCP 1514 58116 → 18443 [ACK]
Seq=14276 Ack=147 Win=8211 Len=1460
10208 22.689703 sourceip destinationip TCP 873 58116 → 18443 [PSH, ACK]
Seq=15736 Ack=147 Win=8211 Len=819
10212 22.691800 sourceip destinationip TCP 60 58116 → 18443 [ACK] Seq=16555
Ack=177 Win=8211 Len=0
10216 22.701706 sourceip destinationip TCP 60 58116 → 18443 [ACK] Seq=16555
Ack=190 Win=8211 Len=0

1. There is a significant time gap between the packets indexed at 1055 and
10199. The timestamp jumps from 2.487967 to 22.689703, a difference of
about 20 seconds, which matches up with the timeout of 20 seconds.

2. The acknowledgement number (Ack) remains constant at 147 from packet
10199 to 10208, which may suggest that the recipient has not yet
acknowledged receipt of these packets. Then it increases to 177 at packet
10212, and to 190 at 10216, suggesting acknowledgements were received for
those packets.

3. Packets 10199 --> 10208 contain the full contents of the JSON.


Thanks,

Dan

On Tue, Jul 11, 2023 at 11:43 AM Dan McLaughlin <d...@danshome.net> wrote:

> I was already using the latest Amazon Corretto 20, so I tried moving to
> the latest OpenJDK 20, which made no difference.  So I'm now using the
> latest Apache HTTPD 2.4, Tomcat 10.1, and JDK20.
>
> So it's either some configuration in Apache or Tomcat that needs to be
> tweaked, an issue with our app (but moving back to mod_jk over AJP works),
> or it's a bug in either mod_http2 or Tomcat 10.1.
>
> If someone at Apache thinks this might be a bug let me know and I'll open
> a bug report, I just need to know if you think the issue might be with
> mod_http2 or Tomcat, and I honestly don't know how to tell at this point.
> So some guidance from someone that knows the code might be of some help at
> this point.
>
> In case it helps any, here are the logs from mod_http2 that match with the
> failed POST that match the tomcat logs that I posted earlier in this thread
> if it helps point in at Apache or Tomcat as the source of the problem...
>
> One thing to point out is that at the time Tomcat says:
>
> "11-Jul-2023 08:27:31.166 FINE [https-openssl-nio-x.x.x.x-18443-exec-8]
> org.apache.coyote.http2.Stream$StandardStreamInputBuffer.doRead The Stream
> input buffer is empty. Waiting for more data"
>
> Apache repeatedly logs:
>
> [Tue Jul 11 08:27:31.061803 2023] [proxy_http2:trace3] [pid 14776:tid
> 5676] h2_proxy_session.c(1047): (11)Resource temporarily unavailable:
> [remote x.x.x.x:18443] h2_proxy_session(499): read from conn
> [Tue Jul 11 08:27:31.061803 2023] [proxy_http2:debug] [pid 14776:tid 5676]
> h2_proxy_session.c(1201): [remote x.x.x.x:18443] AH03345:
> h2_proxy_session(499): transit [BUSY] -- no io --> [WAIT]
>
> Here is the full log from Apache...
>
> [Tue Jul 11 08:27:31.048120 2023] [proxy:trace2] [pid 14776:tid 5676]
> mod_proxy.c(884): [remote x.x.x.x:63451] AH03461: attempting to match URI
> path '/MyApp/rest/savejson' against prefix '/MyApp' for proxying, referer:
> https://myapp.mydomain.com/MyApp/app/reporting/report/424243
> [Tue Jul 11 08:27:31.048793 2023] [proxy:trace1] [pid 14776:tid 5676]
> mod_proxy.c(1005): [remote x.x.x.x:63451] AH03464: URI path
> '/MyApp/rest/savejson' matches proxy handler
> 'proxy:h2://as01:18443/MyApp/rest/savejson', referer:
> https://myapp.mydomain.com/MyApp/app/reporting/report/424243
> [Tue Jul 11 08:27:31.049791 2023] [proxy_http2:trace1] [pid 14776:tid
> 5676] mod_proxy_http2.c(130): [remote x.x.x.x:63451] HTTP2: canonicalising
> URL //as01:18443/MyApp/rest/savejson, referer:
> https://myapp.mydomain.com/MyApp/app/reporting/report/424243
> [Tue Jul 11 08:27:31.049791 2023] [proxy:trace2] [pid 14776:tid 5676]
> proxy_util.c(2370): [remote x.x.x.x:63451] h2: found worker
> h2://as01:18443/MyApp for h2://as01:18443/MyApp/rest/savejson, referer:
> https://myapp.mydomain.com/MyApp/app/reporting/report/424243
> [Tue Jul 11 08:27:31.049791 2023] [proxy:debug] [pid 14776:tid 5676]
> mod_proxy.c(1511): [remote x.x.x.x:63451] AH01143: Running scheme h2
> handler (attempt 0), referer:
> https://myapp.mydomain.com/MyApp/app/reporting/report/424243
> [Tue Jul 11 08:27:31.049791 2023] [proxy_http2:trace1] [pid 14776:tid
> 5676] mod_proxy_http2.c(366): [remote x.x.x.x:63451] H2: serving URL
> h2://as01:18443/MyApp/rest/savejson, referer:
> https://myapp.mydomain.com/MyApp/app/reporting/report/424243
> [Tue Jul 11 08:27:31.049791 2023] [proxy:debug] [pid 14776:tid 5676]
> proxy_util.c(2568): AH00942: H2: has acquired connection for (as01:18443)
> [Tue Jul 11 08:27:31.049791 2023] [proxy:debug] [pid 14776:tid 5676]
> proxy_util.c(2626): [remote x.x.x.x:63451] AH00944: connecting
> h2://as01:18443/MyApp/rest/savejson to as01:18443, referer:
> https://myapp.mydomain.com/MyApp/app/reporting/report/424243
> [Tue Jul 11 08:27:31.049791 2023] [proxy:debug] [pid 14776:tid 5676]
> proxy_util.c(2849): [remote x.x.x.x:63451] AH00947: connected
> /MyApp/rest/savejson to as01:18443, referer:
> https://myapp.mydomain.com/MyApp/app/reporting/report/424243
> [Tue Jul 11 08:27:31.049791 2023] [proxy:trace2] [pid 14776:tid 5676]
> proxy_util.c(3131): H2: reusing backend connection
> x.x.x.x:55549<>x.x.x.x:18443
> [Tue Jul 11 08:27:31.049791 2023] [proxy_http2:debug] [pid 14776:tid 5676]
> mod_proxy_http2.c(267): [remote x.x.x.x:63451] AH03373: eng(499): run
> session 499
> [Tue Jul 11 08:27:31.049791 2023] [proxy_http2:debug] [pid 14776:tid 5676]
> h2_proxy_session.c(1078): [remote x.x.x.x:63451] AH03381: process
> stream(0): POST myapp.mydomain.com/MyApp/rest/savejson, original: POST
> /MyApp/rest/savejson HTTP/2.0, referer:
> https://myapp.mydomain.com/MyApp/app/reporting/report/424243
> [Tue Jul 11 08:27:31.049791 2023] [proxy_http2:debug] [pid 14776:tid 5676]
> h2_proxy_session.c(946): [remote x.x.x.x:18443] AH03363:
> h2_proxy_session(499): submit myapp.mydomain.com/MyApp/rest/savejson -> 23
> [Tue Jul 11 08:27:31.049791 2023] [proxy_http2:trace2] [pid 14776:tid
> 5676] h2_proxy_session.c(1534): [remote x.x.x.x:18443]
> h2_proxy_session(499): process
> [Tue Jul 11 08:27:31.049791 2023] [proxy_http2:debug] [pid 14776:tid 5676]
> h2_proxy_session.c(346): [remote x.x.x.x:18443] AH03343:
> h2_proxy_session(499): sent FRAME[PING[length=8, ack=0, stream=0]]
> [Tue Jul 11 08:27:31.049791 2023] [proxy_http2:trace1] [pid 14776:tid
> 5676] h2_proxy_session.c(247): [remote x.x.x.x:18443]
> h2_proxy_sesssion(499): raw_send 17 bytes, flush=1
> [Tue Jul 11 08:27:31.049791 2023] [proxy_http2:debug] [pid 14776:tid 5676]
> h2_proxy_session.c(346): [remote x.x.x.x:18443] AH03343:
> h2_proxy_session(499): sent FRAME[HEADERS[length=2196, hend=1, stream=23,
> eos=0]]
> [Tue Jul 11 08:27:31.050783 2023] [proxy_http2:trace1] [pid 14776:tid
> 5676] h2_proxy_session.c(247): [remote x.x.x.x:18443]
> h2_proxy_sesssion(499): raw_send 2205 bytes, flush=1
> [Tue Jul 11 08:27:31.050783 2023] [proxy_http2:trace2] [pid 14776:tid
> 5676] h2_proxy_session.c(687): (11)Resource temporarily unavailable:
> [remote x.x.x.x:63451] h2_proxy_stream(499-23): suspending, referer:
> https://myapp.mydomain.com/MyApp/app/reporting/report/424243
> [Tue Jul 11 08:27:31.050783 2023] [proxy_http2:trace3] [pid 14776:tid
> 5676] h2_proxy_session.c(1047): (11)Resource temporarily unavailable:
> [remote x.x.x.x:18443] h2_proxy_session(499): read from conn
> [Tue Jul 11 08:27:31.050783 2023] [proxy_http2:trace2] [pid 14776:tid
> 5676] h2_proxy_session.c(1534): [remote x.x.x.x:18443]
> h2_proxy_session(499): process
> [Tue Jul 11 08:27:31.050783 2023] [proxy_http2:trace3] [pid 14776:tid
> 5676] h2_proxy_session.c(1047): (11)Resource temporarily unavailable:
> [remote x.x.x.x:18443] h2_proxy_session(499): read from conn
> [Tue Jul 11 08:27:31.050783 2023] [proxy_http2:debug] [pid 14776:tid 5676]
> h2_proxy_session.c(1201): [remote x.x.x.x:18443] AH03345:
> h2_proxy_session(499): transit [BUSY] -- no io --> [WAIT]
> [Tue Jul 11 08:27:31.051779 2023] [proxy_http2:trace3] [pid 14776:tid
> 5676] h2_proxy_session.c(1047): [remote x.x.x.x:18443]
> h2_proxy_session(499): read from conn
> [Tue Jul 11 08:27:31.051779 2023] [proxy_http2:trace1] [pid 14776:tid
> 5676] h2_proxy_session.c(990): [remote x.x.x.x:18443]
> h2_proxy_session(499): feeding 9 bytes -> 9
> [Tue Jul 11 08:27:31.051779 2023] [proxy_http2:trace1] [pid 14776:tid
> 5676] h2_proxy_session.c(1010): [remote x.x.x.x:18443]
> h2_proxy_session(499): fed 9 bytes of input to session
> [Tue Jul 11 08:27:31.051779 2023] [proxy_http2:debug] [pid 14776:tid 5676]
> h2_proxy_session.c(1201): [remote x.x.x.x:18443] AH03345:
> h2_proxy_session(499): transit [WAIT] -- data read --> [BUSY]
> [Tue Jul 11 08:27:31.051779 2023] [proxy_http2:trace2] [pid 14776:tid
> 5676] h2_proxy_session.c(1534): [remote x.x.x.x:18443]
> h2_proxy_session(499): process
> [Tue Jul 11 08:27:31.051779 2023] [proxy_http2:trace3] [pid 14776:tid
> 5676] h2_proxy_session.c(1047): [remote x.x.x.x:18443]
> h2_proxy_session(499): read from conn
> [Tue Jul 11 08:27:31.051779 2023] [proxy_http2:debug] [pid 14776:tid 5676]
> h2_proxy_session.c(268): [remote x.x.x.x:18443] AH03341:
> h2_proxy_session(499): recv FRAME[PING[length=8, ack=1, stream=0]]
> [Tue Jul 11 08:27:31.051779 2023] [proxy_http2:debug] [pid 14776:tid 5676]
> h2_proxy_session.c(1706): [remote x.x.x.x:18443] AH03470:
> h2_proxy_session(499): ping arrived, unblocking streams
> [Tue Jul 11 08:27:31.051779 2023] [proxy_http2:trace2] [pid 14776:tid
> 5676] h2_proxy_session.c(1091): [remote x.x.x.x:18443]
> h2_proxy_stream(499-23): resuming
> [Tue Jul 11 08:27:31.051779 2023] [proxy_http2:trace1] [pid 14776:tid
> 5676] h2_proxy_session.c(990): [remote x.x.x.x:18443]
> h2_proxy_session(499): feeding 8 bytes -> 8
> [Tue Jul 11 08:27:31.051779 2023] [proxy_http2:trace1] [pid 14776:tid
> 5676] h2_proxy_session.c(1010): [remote x.x.x.x:18443]
> h2_proxy_session(499): fed 8 bytes of input to session
> [Tue Jul 11 08:27:31.051779 2023] [proxy_http2:trace2] [pid 14776:tid
> 5676] h2_proxy_session.c(1534): [remote x.x.x.x:18443]
> h2_proxy_session(499): process
> [Tue Jul 11 08:27:31.051779 2023] [proxy_http2:trace2] [pid 14776:tid
> 5676] h2_proxy_session.c(634): (11)Resource temporarily unavailable:
> [remote x.x.x.x:63451] h2_proxy_stream(499-23): request body read, referer:
> https://myapp.mydomain.com/MyApp/app/reporting/report/424243
> [Tue Jul 11 08:27:31.051779 2023] [proxy_http2:trace2] [pid 14776:tid
> 5676] h2_proxy_session.c(687): (11)Resource temporarily unavailable:
> [remote x.x.x.x:63451] h2_proxy_stream(499-23): suspending, referer:
> https://myapp.mydomain.com/MyApp/app/reporting/report/424243
> [Tue Jul 11 08:27:31.051779 2023] [proxy_http2:trace3] [pid 14776:tid
> 5676] h2_proxy_session.c(1047): (11)Resource temporarily unavailable:
> [remote x.x.x.x:18443] h2_proxy_session(499): read from conn
> [Tue Jul 11 08:27:31.051779 2023] [proxy_http2:trace2] [pid 14776:tid
> 5676] h2_proxy_session.c(1534): [remote x.x.x.x:18443]
> h2_proxy_session(499): process
> [Tue Jul 11 08:27:31.051779 2023] [proxy_http2:trace3] [pid 14776:tid
> 5676] h2_proxy_session.c(1047): (11)Resource temporarily unavailable:
> [remote x.x.x.x:18443] h2_proxy_session(499): read from conn
> [Tue Jul 11 08:27:31.051779 2023] [proxy_http2:debug] [pid 14776:tid 5676]
> h2_proxy_session.c(1201): [remote x.x.x.x:18443] AH03345:
> h2_proxy_session(499): transit [BUSY] -- no io --> [WAIT]
> [Tue Jul 11 08:27:31.060786 2023] [proxy_http2:trace3] [pid 14776:tid
> 5676] h2_proxy_session.c(1047): [remote x.x.x.x:18443]
> h2_proxy_session(499): read from conn
> [Tue Jul 11 08:27:31.061803 2023] [proxy_http2:trace1] [pid 14776:tid
> 5676] h2_proxy_session.c(990): [remote x.x.x.x:18443]
> h2_proxy_session(499): feeding 9 bytes -> 9
> [Tue Jul 11 08:27:31.061803 2023] [proxy_http2:trace1] [pid 14776:tid
> 5676] h2_proxy_session.c(1010): [remote x.x.x.x:18443]
> h2_proxy_session(499): fed 9 bytes of input to session
> [Tue Jul 11 08:27:31.061803 2023] [proxy_http2:trace3] [pid 14776:tid
> 5676] h2_proxy_session.c(1597): [remote x.x.x.x:18443] AH03365:
> h2_proxy_session(499): WAIT read, timeout=0.025000ms
> [Tue Jul 11 08:27:31.061803 2023] [proxy_http2:debug] [pid 14776:tid 5676]
> h2_proxy_session.c(1201): [remote x.x.x.x:18443] AH03345:
> h2_proxy_session(499): transit [WAIT] -- data read --> [BUSY]
> [Tue Jul 11 08:27:31.061803 2023] [proxy_http2:trace2] [pid 14776:tid
> 5676] h2_proxy_session.c(1534): [remote x.x.x.x:18443]
> h2_proxy_session(499): process
> [Tue Jul 11 08:27:31.061803 2023] [proxy_http2:trace3] [pid 14776:tid
> 5676] h2_proxy_session.c(1047): [remote x.x.x.x:18443]
> h2_proxy_session(499): read from conn
> [Tue Jul 11 08:27:31.061803 2023] [proxy_http2:debug] [pid 14776:tid 5676]
> h2_proxy_session.c(268): [remote x.x.x.x:18443] AH03341:
> h2_proxy_session(499): recv FRAME[PING[length=8, ack=0, stream=0]]
> [Tue Jul 11 08:27:31.061803 2023] [proxy_http2:trace1] [pid 14776:tid
> 5676] h2_proxy_session.c(990): [remote x.x.x.x:18443]
> h2_proxy_session(499): feeding 8 bytes -> 8
> [Tue Jul 11 08:27:31.061803 2023] [proxy_http2:trace1] [pid 14776:tid
> 5676] h2_proxy_session.c(1010): [remote x.x.x.x:18443]
> h2_proxy_session(499): fed 8 bytes of input to session
> [Tue Jul 11 08:27:31.061803 2023] [proxy_http2:trace2] [pid 14776:tid
> 5676] h2_proxy_session.c(1534): [remote x.x.x.x:18443]
> h2_proxy_session(499): process
> [Tue Jul 11 08:27:31.061803 2023] [proxy_http2:debug] [pid 14776:tid 5676]
> h2_proxy_session.c(346): [remote x.x.x.x:18443] AH03343:
> h2_proxy_session(499): sent FRAME[PING[length=8, ack=1, stream=0]]
> [Tue Jul 11 08:27:31.061803 2023] [proxy_http2:trace1] [pid 14776:tid
> 5676] h2_proxy_session.c(247): [remote x.x.x.x:18443]
> h2_proxy_sesssion(499): raw_send 17 bytes, flush=1
> [Tue Jul 11 08:27:31.061803 2023] [proxy_http2:trace3] [pid 14776:tid
> 5676] h2_proxy_session.c(1047): (11)Resource temporarily unavailable:
> [remote x.x.x.x:18443] h2_proxy_session(499): read from conn
> [Tue Jul 11 08:27:31.061803 2023] [proxy_http2:trace2] [pid 14776:tid
> 5676] h2_proxy_session.c(1534): [remote x.x.x.x:18443]
> h2_proxy_session(499): process
> [Tue Jul 11 08:27:31.061803 2023] [proxy_http2:trace3] [pid 14776:tid
> 5676] h2_proxy_session.c(1047): (11)Resource temporarily unavailable:
> [remote x.x.x.x:18443] h2_proxy_session(499): read from conn
> [Tue Jul 11 08:27:31.061803 2023] [proxy_http2:debug] [pid 14776:tid 5676]
> h2_proxy_session.c(1201): [remote x.x.x.x:18443] AH03345:
> h2_proxy_session(499): transit [BUSY] -- no io --> [WAIT]
> [Tue Jul 11 08:27:51.180369 2023] [proxy_http2:trace3] [pid 14776:tid
> 5676] h2_proxy_session.c(1047): [remote x.x.x.x:18443]
> h2_proxy_session(499): read from conn
> [Tue Jul 11 08:27:51.180369 2023] [proxy_http2:trace1] [pid 14776:tid
> 5676] h2_proxy_session.c(990): [remote x.x.x.x:18443]
> h2_proxy_session(499): feeding 9 bytes -> 9
> [Tue Jul 11 08:27:51.180369 2023] [proxy_http2:trace1] [pid 14776:tid
> 5676] h2_proxy_session.c(1010): [remote x.x.x.x:18443]
> h2_proxy_session(499): fed 9 bytes of input to session
> [Tue Jul 11 08:27:51.180369 2023] [proxy_http2:trace3] [pid 14776:tid
> 5676] h2_proxy_session.c(1597): [remote x.x.x.x:18443] AH03365:
> h2_proxy_session(499): WAIT read, timeout=0.025000ms
> [Tue Jul 11 08:27:51.180369 2023] [proxy_http2:debug] [pid 14776:tid 5676]
> h2_proxy_session.c(1201): [remote x.x.x.x:18443] AH03345:
> h2_proxy_session(499): transit [WAIT] -- data read --> [BUSY]
> [Tue Jul 11 08:27:51.180369 2023] [proxy_http2:trace2] [pid 14776:tid
> 5676] h2_proxy_session.c(1534): [remote x.x.x.x:18443]
> h2_proxy_session(499): process
> [Tue Jul 11 08:27:51.181359 2023] [proxy_http2:trace3] [pid 14776:tid
> 5676] h2_proxy_session.c(1047): [remote x.x.x.x:18443]
> h2_proxy_session(499): read from conn
> [Tue Jul 11 08:27:51.181359 2023] [proxy_http2:trace2] [pid 14776:tid
> 5676] h2_proxy_session.c(404): [remote x.x.x.x:18443]
> h2_proxy_stream(499-23): got status 400
> [Tue Jul 11 08:27:51.181359 2023] [proxy_http2:trace2] [pid 14776:tid
> 5676] h2_proxy_session.c(416): [remote x.x.x.x:18443]
> h2_proxy_stream(499-23): on_header cache-control: no-cache, no-store,
> must-revalidate, max-age=0
> [Tue Jul 11 08:27:51.181359 2023] [proxy_http2:trace2] [pid 14776:tid
> 5676] h2_proxy_session.c(428): [remote x.x.x.x:18443]
> h2_proxy_stream(499-23): got header Cache-Control: no-cache, no-store,
> must-revalidate, max-age=0
> [Tue Jul 11 08:27:51.181359 2023] [proxy_http2:trace2] [pid 14776:tid
> 5676] h2_proxy_session.c(416): [remote x.x.x.x:18443]
> h2_proxy_stream(499-23): on_header expires: 0
> [Tue Jul 11 08:27:51.181359 2023] [proxy_http2:trace2] [pid 14776:tid
> 5676] h2_proxy_session.c(428): [remote x.x.x.x:18443]
> h2_proxy_stream(499-23): got header Expires: 0
> [Tue Jul 11 08:27:51.181359 2023] [proxy_http2:trace2] [pid 14776:tid
> 5676] h2_proxy_session.c(416): [remote x.x.x.x:18443]
> h2_proxy_stream(499-23): on_header set-cookie:
> XSRF-TOKEN=bc8fe837-fbf7-46e5-8541-0f2c04c0ac73; Path=/MyApp; Secure;
> SameSite=Lax
> [Tue Jul 11 08:27:51.181359 2023] [proxy_http2:trace2] [pid 14776:tid
> 5676] h2_proxy_session.c(428): [remote x.x.x.x:18443]
> h2_proxy_stream(499-23): got header Set-Cookie:
> XSRF-TOKEN=bc8fe837-fbf7-46e5-8541-0f2c04c0ac73; Path=/MyApp; Secure;
> SameSite=Lax
> [Tue Jul 11 08:27:51.181359 2023] [proxy_http2:trace2] [pid 14776:tid
> 5676] h2_proxy_session.c(416): [remote x.x.x.x:18443]
> h2_proxy_stream(499-23): on_header content-length: 0
> [Tue Jul 11 08:27:51.181359 2023] [proxy_http2:trace2] [pid 14776:tid
> 5676] h2_proxy_session.c(428): [remote x.x.x.x:18443]
> h2_proxy_stream(499-23): got header Content-Length: 0
> [Tue Jul 11 08:27:51.181359 2023] [proxy_http2:trace2] [pid 14776:tid
> 5676] h2_proxy_session.c(416): [remote x.x.x.x:18443]
> h2_proxy_stream(499-23): on_header date: Tue, 11 Jul 2023 13:27:51 GMT
> [Tue Jul 11 08:27:51.181359 2023] [proxy_http2:trace2] [pid 14776:tid
> 5676] h2_proxy_session.c(428): [remote x.x.x.x:18443]
> h2_proxy_stream(499-23): got header Date: Tue, 11 Jul 2023 13:27:51 GMT
> [Tue Jul 11 08:27:51.181359 2023] [proxy_http2:debug] [pid 14776:tid 5676]
> h2_proxy_session.c(268): [remote x.x.x.x:18443] AH03341:
> h2_proxy_session(499): recv FRAME[HEADERS[length=103, hend=1, stream=23,
> eos=0]]
> [Tue Jul 11 08:27:51.181359 2023] [proxy_http2:trace2] [pid 14776:tid
> 5676] h2_proxy_session.c(1091): [remote x.x.x.x:18443]
> h2_proxy_stream(499-23): resuming
> [Tue Jul 11 08:27:51.181359 2023] [proxy_http2:trace1] [pid 14776:tid
> 5676] h2_proxy_session.c(990): [remote x.x.x.x:18443]
> h2_proxy_session(499): feeding 103 bytes -> 103
> [Tue Jul 11 08:27:51.181359 2023] [proxy_http2:trace1] [pid 14776:tid
> 5676] h2_proxy_session.c(1010): [remote x.x.x.x:18443]
> h2_proxy_session(499): fed 103 bytes of input to session
> [Tue Jul 11 08:27:51.181359 2023] [proxy_http2:trace2] [pid 14776:tid
> 5676] h2_proxy_session.c(1534): [remote x.x.x.x:18443]
> h2_proxy_session(499): process
> [Tue Jul 11 08:27:51.181359 2023] [proxy_http2:trace2] [pid 14776:tid
> 5676] h2_proxy_session.c(634): [remote x.x.x.x:63451]
> h2_proxy_stream(499-23): request body read, referer:
> https://myapp.mydomain.com/MyApp/app/reporting/report/424243
> [Tue Jul 11 08:27:51.181359 2023] [proxy_http2:debug] [pid 14776:tid 5676]
> h2_proxy_session.c(673): [remote x.x.x.x:63451] AH03468:
> h2_proxy_stream(23): request DATA 13878, 13878 total, flags=1, referer:
> https://myapp.mydomain.com/MyApp/app/reporting/report/424243
> [Tue Jul 11 08:27:51.181359 2023] [proxy_http2:trace1] [pid 14776:tid
> 5676] h2_proxy_session.c(247): [remote x.x.x.x:18443]
> h2_proxy_sesssion(499): raw_send 13887 bytes, flush=1
> [Tue Jul 11 08:27:51.181359 2023] [proxy_http2:trace3] [pid 14776:tid
> 5676] h2_proxy_session.c(1047): (11)Resource temporarily unavailable:
> [remote x.x.x.x:18443] h2_proxy_session(499): read from conn
> [Tue Jul 11 08:27:51.181359 2023] [proxy_http2:trace2] [pid 14776:tid
> 5676] h2_proxy_session.c(1534): [remote x.x.x.x:18443]
> h2_proxy_session(499): process
> [Tue Jul 11 08:27:51.181359 2023] [proxy_http2:trace3] [pid 14776:tid
> 5676] h2_proxy_session.c(1047): (11)Resource temporarily unavailable:
> [remote x.x.x.x:18443] h2_proxy_session(499): read from conn
> [Tue Jul 11 08:27:51.181359 2023] [proxy_http2:debug] [pid 14776:tid 5676]
> h2_proxy_session.c(1201): [remote x.x.x.x:18443] AH03345:
> h2_proxy_session(499): transit [BUSY] -- no io --> [WAIT]
> [Tue Jul 11 08:27:51.183358 2023] [proxy_http2:trace3] [pid 14776:tid
> 5676] h2_proxy_session.c(1047): [remote x.x.x.x:18443]
> h2_proxy_session(499): read from conn
> [Tue Jul 11 08:27:51.183358 2023] [proxy_http2:debug] [pid 14776:tid 5676]
> h2_proxy_session.c(268): [remote x.x.x.x:18443] AH03341:
> h2_proxy_session(499): recv FRAME[RST_STREAM[length=4, flags=0, stream=23]]
> [Tue Jul 11 08:27:51.183358 2023] [proxy_http2:debug] [pid 14776:tid 5676]
> h2_proxy_session.c(566): [remote x.x.x.x:18443] AH03360:
> h2_proxy_session(499): stream=23, closed, err=11
> [Tue Jul 11 08:27:51.183358 2023] [proxy_http2:debug] [pid 14776:tid 5676]
> h2_proxy_session.c(1372): [remote x.x.x.x:18443] AH03364:
> h2_proxy_sesssion(499): stream(23) closed (touched=1, error=11)
> [Tue Jul 11 08:27:51.184357 2023] [proxy_http2:trace1] [pid 14776:tid
> 5676] mod_proxy_http2.c(233): (22)Invalid argument: [remote x.x.x.x:63451]
> h2_proxy_session(499): request done, touched=1
> [Tue Jul 11 08:27:51.184357 2023] [proxy_http2:trace1] [pid 14776:tid
> 5676] h2_proxy_session.c(990): [remote x.x.x.x:18443]
> h2_proxy_session(499): feeding 13 bytes -> 13
> [Tue Jul 11 08:27:51.184357 2023] [proxy_http2:trace1] [pid 14776:tid
> 5676] h2_proxy_session.c(1010): [remote x.x.x.x:18443]
> h2_proxy_session(499): fed 13 bytes of input to session
> [Tue Jul 11 08:27:51.184357 2023] [proxy_http2:debug] [pid 14776:tid 5676]
> h2_proxy_session.c(1201): [remote x.x.x.x:18443] AH03345:
> h2_proxy_session(499): transit [WAIT] -- data read --> [BUSY]
> [Tue Jul 11 08:27:51.184357 2023] [proxy:debug] [pid 14776:tid 5676]
> proxy_util.c(2584): AH00943: H2: has released connection for (as01:18443)
> [Tue Jul 11 08:27:51.184357 2023] [proxy_http2:debug] [pid 14776:tid 5676]
> mod_proxy_http2.c(458): [remote x.x.x.x:63451] AH03377: leaving handler
>
>
> --
>
> Thanks,
>
> Dan
>
> On Tue, Jul 11, 2023 at 11:00 AM Dan McLaughlin <d...@danshome.net> wrote:
>
>> I just upgraded to Tomcat 10.1.11, and it still fails.  A comparison of
>> the logs between a failed POST on 10.1.10 and 10.1.11 look slightly
>> different, but it still fails for the same reason.  I'm going to try
>> updating the JDK and see if that helps.
>>
>> --
>>
>> Thanks,
>>
>> Dan
>>
>> On Tue, Jul 11, 2023 at 10:32 AM Dan McLaughlin <d...@danshome.net> wrote:
>>
>>> @markt
>>>
>>> I was looking over the latest release notes for 10.1.11. Any chance
>>> either of these changes could be related...
>>>
>>>
>>>    - [image: Fix:] Refactor blocking reads and writes for the NIO
>>>    connector to remove code paths that could allow a notification from the
>>>    Poller to be missed resuting in a timeout rather than the expected read 
>>> or
>>>    write. (markt)
>>>    - [image: Fix:] Refactor waiting for an HTTP/2 stream or connection
>>>    window update to handle spurious wake-ups during the wait. (markt)
>>>
>>>
>>> --
>>>
>>> Thanks,
>>>
>>> Dan
>>>
>>> On Tue, Jul 11, 2023 at 9:43 AM Dan McLaughlin <d...@danshome.net> wrote:
>>>
>>>> We have many Angular applications, and we currently use Angular 15. I'm
>>>> using Apache 2.4.57 and Tomcat 10.1.10/JDK20 on Windows 2019 (don't ask).
>>>>
>>>> For several years now, I've used the following configuration without
>>>> issues.
>>>>
>>>> Angular <-H2-> Apache <-MOD_JK/AJP 1.3--> Tomcat
>>>>
>>>> This week I've been working on replacing mod_jk with mod_http2, and for
>>>> the most part, things are working, but I'm running into issues where we do
>>>> HTTP POSTs of JSON to Rest APIs. We are using Spring Framework 6.0.10. The
>>>> only things I have yet to try are upgrading to Tomcat 10.1.11 and
>>>> updating to the latest JDK20 release.  We are using Amazon Corretto.
>>>>
>>>> Angular <-H2-> Apache <-MOD_HTTP2/H2--> Tomcat
>>>>
>>>> Everything seems to be working fine except for places in our apps where
>>>> we do things like a POST of JSON to a Rest API.  To debug what's going on,
>>>> I've enabled dumpio on Apache, and I can see the entire JSON getting
>>>> posted. I've installed Wireshark on the backend where Tomcat is running,
>>>> and I've captured the TCP packets containing the JSON, and I can see that
>>>> the entire JSON is making it to Tomcat. When I compare the JSON in a diff
>>>> tool, the JSON is the same, so I know it's making it intact. So I enabled
>>>> FINE logging for HTTP2 on Tomcat, and I see everything looks to come
>>>> through to Tomcat fine until it hits...
>>>>
>>>> org.apache.coyote.http2.Stream$StandardStreamInputBuffer.doRead The
>>>> Stream input buffer is empty. Waiting for more data
>>>>
>>>> At this point, things hang for 20 seconds until a timeout occurs, and
>>>> Tomcat closes the connection.
>>>>
>>>> Here's the odd thing, the same post doesn't always fail. In about 1 out
>>>> of 10 attempts, the POST will succeed. When it does succeed and I compare
>>>> the HTTP2 logs in Tomcat, everything looks the same until the end of the
>>>> connection.  Here are the logs showing a POST that succeeds vs. one that
>>>> fails.  Is there something we should be doing in our Angular apps
>>>> differently when HTTP2 is used in place of AJP, or is this potentially a
>>>> bug?
>>>>
>>>> Success...
>>>>
>>>> 11-Jul-2023 08:51:45.427 FINE [https-openssl-nio-exec-15]
>>>> org.apache.coyote.http2.Http2UpgradeHandler.updateOverheadCount Connection
>>>> [18], Stream [0], Frame type [HEADERS] resulted in new overhead count of
>>>> [-260]
>>>> 11-Jul-2023 08:51:45.427 FINE [https-openssl-nio-exec-15]
>>>> org.apache.coyote.http2.Http2Parser.validateFrame Connection [18], Stream
>>>> [0], Frame type [PING], Flags [1], Payload size [8]
>>>> 11-Jul-2023 08:51:45.427 FINE [https-openssl-nio-exec-15]
>>>> org.apache.coyote.http2.Http2UpgradeHandler$PingManager.receivePing
>>>> Connection [18] Round trip time measured as [11,769,300]ns
>>>> 11-Jul-2023 08:51:45.427 FINE [https-openssl-nio-exec-15]
>>>> org.apache.coyote.http2.Http2Parser.validateFrame Connection [18], Stream
>>>> [13], Frame type [DATA], Flags [0], Payload size [8000]
>>>> 11-Jul-2023 08:51:45.427 FINE [https-openssl-nio-exec-15]
>>>> org.apache.coyote.http2.Http2Parser.readDataFrame Connection [18], Stream
>>>> [13], Data length [8000], Padding length [none]
>>>> 11-Jul-2023 08:51:45.427 FINE [https-openssl-nio-exec-15]
>>>> org.apache.coyote.http2.Http2UpgradeHandler.updateOverheadCount Connection
>>>> [18], Stream [0], Frame type [DATA] resulted in new overhead count of 
>>>> [-280]
>>>> 11-Jul-2023 08:51:45.428 FINE [https-openssl-nio-exec-15]
>>>> org.apache.coyote.http2.Http2UpgradeHandler.startRequestBodyFrame
>>>> Connection [18], Stream [13] startRequestBodyFrame returned
>>>> [java.nio.HeapByteBuffer[pos=0 lim=65535 cap=65535]]
>>>> 11-Jul-2023 08:51:45.428 FINE [https-openssl-nio-exec-15]
>>>> org.apache.coyote.http2.Stream$StandardStreamInputBuffer.onDataAvailable
>>>> Data added to inBuffer when read thread is waiting. Signalling that thread
>>>> to continue
>>>> 11-Jul-2023 08:51:45.428 FINE [https-openssl-nio-exec-15]
>>>> org.apache.coyote.http2.Http2Parser.validateFrame Connection [18], Stream
>>>> [13], Frame type [DATA], Flags [1], Payload size [5878]
>>>> 11-Jul-2023 08:51:45.428 FINE [https-openssl-nio-exec-15]
>>>> org.apache.coyote.http2.Http2Parser.readDataFrame Connection [18], Stream
>>>> [13], Data length [5878], Padding length [none]
>>>> 11-Jul-2023 08:51:45.428 FINE [https-openssl-nio-exec-15]
>>>> org.apache.coyote.http2.Http2UpgradeHandler.updateOverheadCount Connection
>>>> [18], Stream [0], Frame type [DATA] resulted in new overhead count of 
>>>> [-300]
>>>> 11-Jul-2023 08:51:45.428 FINE [https-openssl-nio-exec-15]
>>>> org.apache.coyote.http2.Http2UpgradeHandler.startRequestBodyFrame
>>>> Connection [18], Stream [13] startRequestBodyFrame returned
>>>> [java.nio.HeapByteBuffer[pos=8000 lim=65535 cap=65535]]
>>>> 11-Jul-2023 08:51:45.428 FINE [https-openssl-nio-exec-15]
>>>> org.apache.coyote.http2.StreamStateMachine.stateChange Connection [18],
>>>> Stream [13], State changed from [OPEN] to [HALF_CLOSED_REMOTE]
>>>> 11-Jul-2023 08:51:45.428 FINE [https-openssl-nio-exec-15]
>>>> org.apache.coyote.http2.Stream$StandardStreamInputBuffer.onDataAvailable
>>>> Data added to inBuffer when read thread is waiting. Signalling that thread
>>>> to continue
>>>> 11-Jul-2023 08:51:45.428 FINE [https-openssl-nio-exec-15]
>>>> org.apache.coyote.http2.Http2UpgradeHandler.upgradeDispatch Exit,
>>>> Connection [18], SocketState [ASYNC_IO]
>>>> 11-Jul-2023 08:51:45.474 FINE [https-openssl-nio-exec-5]
>>>> org.apache.coyote.http2.Stream$StandardStreamInputBuffer.doRead Copying
>>>> [13878] bytes from inBuffer to outBuffer
>>>> 11-Jul-2023 08:51:45.474 FINE [https-openssl-nio-exec-5]
>>>> org.apache.coyote.http2.Http2AsyncUpgradeHandler.writeWindowUpdate
>>>> Connection [18], Sent window update to client increasing window by [13,878]
>>>> bytes
>>>> 11-Jul-2023 08:51:45.474 FINE [https-openssl-nio-exec-5]
>>>> org.apache.coyote.http2.Http2AsyncUpgradeHandler.writeWindowUpdate
>>>> Connection [18], Stream [0], Sent window update to client increasing window
>>>> by [13,878] bytes
>>>> 11-Jul-2023 08:51:45.964 FINE [https-openssl-nio-exec-5]
>>>> org.apache.coyote.http2.Http2UpgradeHandler.doWriteHeaders Connection [18],
>>>> Stream [13], Writing the headers, EndOfStream [false]
>>>> 11-Jul-2023 08:51:45.964 FINE [https-openssl-nio-exec-5]
>>>> org.apache.coyote.http2.HpackEncoder.encode Encoding header [:status] with
>>>> value [200]
>>>> 11-Jul-2023 08:51:45.964 FINE [https-openssl-nio-exec-5]
>>>> org.apache.coyote.http2.HpackEncoder.encode Encoding header [cache-control]
>>>> with value [no-cache, no-store, must-revalidate, max-age=0]
>>>> 11-Jul-2023 08:51:45.964 FINE [https-openssl-nio-exec-5]
>>>> org.apache.coyote.http2.HpackEncoder.encode Encoding header [expires] with
>>>> value [0]
>>>> 11-Jul-2023 08:51:45.965 FINE [https-openssl-nio-exec-5]
>>>> org.apache.coyote.http2.HpackEncoder.encode Encoding header [set-cookie]
>>>> with value [XSRF-TOKEN=e6da128f-8fee-48de-bccf-101cb81f7247; Path=/MyApp;
>>>> Secure; SameSite=Lax]
>>>> 11-Jul-2023 08:51:45.965 FINE [https-openssl-nio-exec-5]
>>>> org.apache.coyote.http2.HpackEncoder.encode Encoding header [content-type]
>>>> with value [application/json]
>>>> 11-Jul-2023 08:51:45.965 FINE [https-openssl-nio-exec-5]
>>>> org.apache.coyote.http2.HpackEncoder.encode Encoding header [date] with
>>>> value [Tue, 11 Jul 2023 13:51:45 GMT]
>>>> 11-Jul-2023 08:51:45.965 FINE [https-openssl-nio-exec-5]
>>>> org.apache.coyote.http2.Http2UpgradeHandler.doWriteHeaders 100 bytes
>>>> 11-Jul-2023 08:51:45.965 FINE [https-openssl-nio-exec-5]
>>>> org.apache.coyote.http2.Stream$StreamOutputBuffer.flush Connection [18],
>>>> Stream [13], flushing output with buffer at position [8192],
>>>> writeInProgress [true] and closed [false]
>>>> 11-Jul-2023 08:51:45.965 FINE [https-openssl-nio-exec-5]
>>>> org.apache.coyote.http2.AbstractStream.decrementWindowSize Connection [18],
>>>> Stream [13], reduce flow control window by [8192] to [24575]
>>>> 11-Jul-2023 08:51:45.966 FINE [https-openssl-nio-exec-5]
>>>> org.apache.coyote.http2.AbstractStream.decrementWindowSize Connection [18],
>>>> Stream [0], reduce flow control window by [8192] to [1065196529]
>>>> 11-Jul-2023 08:51:45.966 FINE [https-openssl-nio-exec-5]
>>>> org.apache.coyote.http2.Http2AsyncUpgradeHandler.writeBody Connection [18],
>>>> Stream [13], Data length [8192], EndOfStream [false]
>>>> 11-Jul-2023 08:51:45.966 FINE [https-openssl-nio-exec-5]
>>>> org.apache.coyote.http2.Stream$StreamOutputBuffer.flush Connection [18],
>>>> Stream [13], flushing output with buffer at position [5059],
>>>> writeInProgress [false] and closed [false]
>>>> 11-Jul-2023 08:51:45.966 FINE [https-openssl-nio-exec-5]
>>>> org.apache.coyote.http2.AbstractStream.decrementWindowSize Connection [18],
>>>> Stream [13], reduce flow control window by [5059] to [19516]
>>>> 11-Jul-2023 08:51:45.966 FINE [https-openssl-nio-exec-5]
>>>> org.apache.coyote.http2.AbstractStream.decrementWindowSize Connection [18],
>>>> Stream [0], reduce flow control window by [5059] to [1065191470]
>>>> 11-Jul-2023 08:51:45.966 FINE [https-openssl-nio-exec-5]
>>>> org.apache.coyote.http2.Http2AsyncUpgradeHandler.writeBody Connection [18],
>>>> Stream [13], Data length [5059], EndOfStream [false]
>>>> 11-Jul-2023 08:51:45.966 FINE [https-openssl-nio-exec-5]
>>>> org.apache.coyote.http2.Stream$StreamOutputBuffer.flush Connection [18],
>>>> Stream [13], flushing output with buffer at position [0], writeInProgress
>>>> [false] and closed [false]
>>>> 11-Jul-2023 08:51:45.967 FINE [https-openssl-nio-exec-5]
>>>> org.apache.coyote.http2.Stream$StreamOutputBuffer.flush Connection [18],
>>>> Stream [13], flushing output with buffer at position [0], writeInProgress
>>>> [false] and closed [false]
>>>> 11-Jul-2023 08:51:45.967 FINE [https-openssl-nio-exec-5]
>>>> org.apache.coyote.http2.Stream$StreamOutputBuffer.flush Connection [18],
>>>> Stream [13], flushing output with buffer at position [0], writeInProgress
>>>> [false] and closed [false]
>>>> 11-Jul-2023 08:51:45.969 FINE [https-openssl-nio-exec-5]
>>>> org.apache.coyote.http2.Stream$StreamOutputBuffer.flush Connection [18],
>>>> Stream [13], flushing output with buffer at position [0], writeInProgress
>>>> [false] and closed [true]
>>>> 11-Jul-2023 08:51:45.969 FINE [https-openssl-nio-exec-5]
>>>> org.apache.coyote.http2.Http2AsyncUpgradeHandler.writeBody Connection [18],
>>>> Stream [13], Data length [0], EndOfStream [true]
>>>> 11-Jul-2023 08:51:45.969 FINE [https-openssl-nio-exec-5]
>>>> org.apache.coyote.http2.StreamStateMachine.stateChange Connection [18],
>>>> Stream [13], State changed from [HALF_CLOSED_REMOTE] to [CLOSED_TX]
>>>> 11-Jul-2023 08:51:45.970 FINE [https-openssl-nio-exec-5]
>>>> org.apache.coyote.AbstractProcessorLight.process Socket:
>>>> [org.apache.tomcat.util.net.NioEndpoint$NioSocketWrapper@6fbdbb24
>>>> :org.apache.tomcat.util.net.SecureNioChannel@1108a252:java.nio.channels.SocketChannel[connected
>>>> local=/x.x.x.x:18443 remote=/x.x.x.x:57063]], Status in: [OPEN_READ], State
>>>> out: [CLOSED]
>>>>
>>>> Failure...
>>>>
>>>> 11-Jul-2023 08:27:31.051 FINE [https-openssl-nio-x.x.x.x-18443-exec-9]
>>>> org.apache.coyote.http2.Http2UpgradeHandler.updateOverheadCount Connection
>>>> [b], Stream [0], Frame type [HEADERS] resulted in new overhead count of
>>>> [-460]
>>>> 11-Jul-2023 08:27:31.051 FINE [https-openssl-nio-x.x.x.x-18443-exec-9]
>>>> org.apache.coyote.http2.Http2UpgradeHandler.upgradeDispatch Entry,
>>>> Connection [b], SocketStatus [OPEN_READ]
>>>> 11-Jul-2023 08:27:31.051 FINE [https-openssl-nio-x.x.x.x-18443-exec-9]
>>>> org.apache.coyote.http2.Http2UpgradeHandler.init Connection [b], State
>>>> [CONNECTED]
>>>> 11-Jul-2023 08:27:31.052 FINE [https-openssl-nio-x.x.x.x-18443-exec-9]
>>>> org.apache.coyote.http2.Http2UpgradeHandler.upgradeDispatch Exit,
>>>> Connection [b], SocketState [ASYNC_IO]
>>>> 11-Jul-2023 08:27:31.053 FINE [https-openssl-nio-x.x.x.x-18443-exec-10]
>>>> org.apache.coyote.http2.Http2Parser.validateFrame Connection [b], Stream
>>>> [0], Frame type [PING], Flags [1], Payload size [8]
>>>> 11-Jul-2023 08:27:31.053 FINE [https-openssl-nio-x.x.x.x-18443-exec-10]
>>>> org.apache.coyote.http2.Http2UpgradeHandler$PingManager.receivePing
>>>> Connection [b] Round trip time measured as [1,480,000]ns
>>>> 11-Jul-2023 08:27:31.053 FINE [https-openssl-nio-x.x.x.x-18443-exec-10]
>>>> org.apache.coyote.http2.Http2UpgradeHandler.upgradeDispatch Entry,
>>>> Connection [b], SocketStatus [OPEN_READ]
>>>> 11-Jul-2023 08:27:31.053 FINE [https-openssl-nio-x.x.x.x-18443-exec-10]
>>>> org.apache.coyote.http2.Http2UpgradeHandler.init Connection [b], State
>>>> [CONNECTED]
>>>> 11-Jul-2023 08:27:31.053 FINE [https-openssl-nio-x.x.x.x-18443-exec-10]
>>>> org.apache.coyote.http2.Http2UpgradeHandler.upgradeDispatch Exit,
>>>> Connection [b], SocketState [ASYNC_IO]
>>>> 11-Jul-2023 08:27:31.166 FINE [https-openssl-nio-x.x.x.x-18443-exec-8]
>>>> org.apache.coyote.http2.Stream$StandardStreamInputBuffer.doRead The Stream
>>>> input buffer is empty. Waiting for more data
>>>> 11-Jul-2023 08:27:51.170 FINE [https-openssl-nio-x.x.x.x-18443-exec-8]
>>>> org.apache.coyote.http2.Http2UpgradeHandler.doWriteHeaders Connection [b],
>>>> Stream [23], Writing the headers, EndOfStream [false]
>>>> 11-Jul-2023 08:27:51.170 FINE [https-openssl-nio-x.x.x.x-18443-exec-8]
>>>> org.apache.coyote.http2.HpackEncoder.encode Encoding header [:status] with
>>>> value [400]
>>>> 11-Jul-2023 08:27:51.170 FINE [https-openssl-nio-x.x.x.x-18443-exec-8]
>>>> org.apache.coyote.http2.HpackEncoder.encode Encoding header [cache-control]
>>>> with value [no-cache, no-store, must-revalidate, max-age=0]
>>>> 11-Jul-2023 08:27:51.170 FINE [https-openssl-nio-x.x.x.x-18443-exec-8]
>>>> org.apache.coyote.http2.HpackEncoder.encode Encoding header [expires] with
>>>> value [0]
>>>> 11-Jul-2023 08:27:51.170 FINE [https-openssl-nio-x.x.x.x-18443-exec-8]
>>>> org.apache.coyote.http2.HpackEncoder.encode Encoding header [set-cookie]
>>>> with value [XSRF-TOKEN=bc8fe837-fbf7-46e5-8541-0f2c04c0ac73; Path=/MyApp;
>>>> Secure; SameSite=Lax]
>>>> 11-Jul-2023 08:27:51.170 FINE [https-openssl-nio-x.x.x.x-18443-exec-8]
>>>> org.apache.coyote.http2.HpackEncoder.encode Encoding header
>>>> [content-length] with value [0]
>>>> 11-Jul-2023 08:27:51.170 FINE [https-openssl-nio-x.x.x.x-18443-exec-8]
>>>> org.apache.coyote.http2.HpackEncoder.encode Encoding header [date] with
>>>> value [Tue, 11 Jul 2023 13:27:51 GMT]
>>>> 11-Jul-2023 08:27:51.170 FINE [https-openssl-nio-x.x.x.x-18443-exec-8]
>>>> org.apache.coyote.http2.Http2UpgradeHandler.doWriteHeaders 103 bytes
>>>> 11-Jul-2023 08:27:51.171 FINE [https-openssl-nio-x.x.x.x-18443-exec-8]
>>>> org.apache.coyote.AbstractProcessor.setErrorState Error state [CLOSE_NOW]
>>>> reported while processing request
>>>> org.apache.coyote.CloseNowException:
>>>> org.apache.coyote.http2.StreamException: Timeout waiting to read data from
>>>> client
>>>> at
>>>> org.apache.coyote.http2.Stream$StreamOutputBuffer.end(Stream.java:1064)
>>>> at
>>>> org.apache.coyote.http2.Http2OutputBuffer.end(Http2OutputBuffer.java:69)
>>>> at
>>>> org.apache.coyote.http2.StreamProcessor.finishResponse(StreamProcessor.java:234)
>>>> at
>>>> org.apache.coyote.AbstractProcessor.action(AbstractProcessor.java:386)
>>>> at org.apache.coyote.Response.action(Response.java:208)
>>>> at
>>>> org.apache.catalina.connector.OutputBuffer.close(OutputBuffer.java:256)
>>>> at
>>>> org.apache.catalina.connector.Response.finishResponse(Response.java:413)
>>>> at
>>>> org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:370)
>>>> at
>>>> org.apache.coyote.http2.StreamProcessor.service(StreamProcessor.java:426)
>>>> at
>>>> org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:63)
>>>> at
>>>> org.apache.coyote.http2.StreamProcessor.process(StreamProcessor.java:86)
>>>> at org.apache.coyote.http2.StreamRunnable.run(StreamRunnable.java:35)
>>>> at
>>>> org.apache.tomcat.util.threads.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1191)
>>>> at
>>>> org.apache.tomcat.util.threads.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:659)
>>>> at
>>>> org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
>>>> at java.base/java.lang.Thread.run(Thread.java:1623)
>>>> Caused by: org.apache.coyote.http2.StreamException: Timeout waiting to
>>>> read data from client
>>>> at
>>>> org.apache.coyote.http2.Stream$StandardStreamInputBuffer.doRead(Stream.java:1194)
>>>> at org.apache.coyote.Request.doRead(Request.java:635)
>>>> at
>>>> org.apache.catalina.connector.InputBuffer.realReadBytes(InputBuffer.java:313)
>>>> at
>>>> org.apache.catalina.connector.InputBuffer.checkByteBufferEof(InputBuffer.java:596)
>>>> at
>>>> org.apache.catalina.connector.InputBuffer.readByte(InputBuffer.java:326)
>>>> at
>>>> org.apache.catalina.connector.CoyoteInputStream.read(CoyoteInputStream.java:85)
>>>> at java.base/java.io.FilterInputStream.read(FilterInputStream.java:71)
>>>> at
>>>> java.base/java.io.PushbackInputStream.read(PushbackInputStream.java:150)
>>>> at
>>>> org.springframework.web.servlet.mvc.method.annotation.AbstractMessageConverterMethodArgumentResolver$EmptyBodyCheckingHttpInputMessage.<init>(AbstractMessageConverterMethodArgumentResolver.java:331)
>>>> at
>>>> org.springframework.web.servlet.mvc.method.annotation.AbstractMessageConverterMethodArgumentResolver.readWithMessageConverters(AbstractMessageConverterMethodArgumentResolver.java:172)
>>>> at
>>>> org.springframework.web.servlet.mvc.method.annotation.RequestResponseBodyMethodProcessor.readWithMessageConverters(RequestResponseBodyMethodProcessor.java:163)
>>>> at
>>>> org.springframework.web.servlet.mvc.method.annotation.RequestResponseBodyMethodProcessor.resolveArgument(RequestResponseBodyMethodProcessor.java:136)
>>>> at
>>>> org.springframework.web.method.support.HandlerMethodArgumentResolverComposite.resolveArgument(HandlerMethodArgumentResolverComposite.java:122)
>>>> at
>>>> org.springframework.web.method.support.InvocableHandlerMethod.getMethodArgumentValues(InvocableHandlerMethod.java:181)
>>>> at
>>>> org.springframework.web.method.support.InvocableHandlerMethod.invokeForRequest(InvocableHandlerMethod.java:148)
>>>> at
>>>> org.springframework.web.servlet.mvc.method.annotation.ServletInvocableHandlerMethod.invokeAndHandle(ServletInvocableHandlerMethod.java:118)
>>>> at
>>>> org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.invokeHandlerMethod(RequestMappingHandlerAdapter.java:884)
>>>> at
>>>> org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.handleInternal(RequestMappingHandlerAdapter.java:797)
>>>> at
>>>> org.springframework.web.servlet.mvc.method.AbstractHandlerMethodAdapter.handle(AbstractHandlerMethodAdapter.java:87)
>>>> at
>>>> org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:1081)
>>>> at
>>>> org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:974)
>>>> at
>>>> org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:1011)
>>>> at
>>>> org.springframework.web.servlet.FrameworkServlet.doPost(FrameworkServlet.java:914)
>>>> at jakarta.servlet.http.HttpServlet.service(HttpServlet.java:590)
>>>> at
>>>> org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:885)
>>>> at jakarta.servlet.http.HttpServlet.service(HttpServlet.java:658)
>>>> at
>>>> org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:205)
>>>> at
>>>> org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:149)
>>>> at
>>>> org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:51)
>>>> at
>>>> org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:174)
>>>> at
>>>> org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:149)
>>>> at
>>>> net.bull.javamelody.MonitoringFilter.doFilter(MonitoringFilter.java:236)
>>>> at
>>>> net.bull.javamelody.MonitoringFilter.doFilter(MonitoringFilter.java:212)
>>>> at
>>>> org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:174)
>>>> at
>>>> org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:149)
>>>> at
>>>> com.myapp.common.authz.filter.AuthzFilter.doFilter(AuthzFilter.java:458)
>>>> at
>>>> org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:174)
>>>> at
>>>> org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:149)
>>>> at com.myapp.common.csrf.filter.CsrfFilter.doFilter(CsrfFilter.java:112)
>>>> at
>>>> org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:174)
>>>> at
>>>> org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:149)
>>>> at
>>>> com.avlesh.web.filter.responseheaderfilter.ResponseHeaderFilter.doFilter(ResponseHeaderFilter.java:196)
>>>> at
>>>> org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:174)
>>>> at
>>>> org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:149)
>>>> at
>>>> org.apache.logging.log4j.web.Log4jServletFilter.doFilter(Log4jServletFilter.java:71)
>>>> at
>>>> org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:174)
>>>> at
>>>> org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:149)
>>>> at
>>>> org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:154)
>>>> at
>>>> org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:90)
>>>> at
>>>> org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:482)
>>>> at
>>>> org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:115)
>>>> at
>>>> org.apache.catalina.ha.session.JvmRouteBinderValve.invoke(JvmRouteBinderValve.java:183)
>>>> at
>>>> org.apache.catalina.ha.tcp.ReplicationValve.invoke(ReplicationValve.java:329)
>>>> at
>>>> org.apache.catalina.valves.AbstractAccessLogValve.invoke(AbstractAccessLogValve.java:676)
>>>> at
>>>> org.apache.catalina.valves.LoadBalancerDrainingValve.invoke(LoadBalancerDrainingValve.java:230)
>>>> at
>>>> org.apache.catalina.valves.AbstractAccessLogValve.invoke(AbstractAccessLogValve.java:676)
>>>> at
>>>> org.apache.catalina.valves.RemoteIpValve.invoke(RemoteIpValve.java:738)
>>>> at org.apache.catalina.valves.SSLValve.invoke(SSLValve.java:193)
>>>> at
>>>> org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:74)
>>>> at
>>>> org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:341)
>>>> ... 8 more
>>>> 11-Jul-2023 08:27:51.173 FINE [https-openssl-nio-x.x.x.x-18443-exec-6]
>>>> org.apache.coyote.http2.Http2Parser.validateFrame Connection [b], Stream
>>>> [23], Frame type [DATA], Flags [1], Payload size [13878]
>>>> 11-Jul-2023 08:27:51.173 FINE [https-openssl-nio-x.x.x.x-18443-exec-8]
>>>> org.apache.coyote.AbstractProcessor.setErrorState Error state [CLOSE_NOW]
>>>> reported while processing request
>>>> org.apache.coyote.CloseNowException:
>>>> org.apache.coyote.http2.StreamException: Timeout waiting to read data from
>>>> client
>>>> at
>>>> org.apache.coyote.http2.Stream$StreamOutputBuffer.end(Stream.java:1064)
>>>> at
>>>> org.apache.coyote.http2.Http2OutputBuffer.end(Http2OutputBuffer.java:69)
>>>> at
>>>> org.apache.coyote.http2.StreamProcessor.finishResponse(StreamProcessor.java:234)
>>>> at
>>>> org.apache.coyote.AbstractProcessor.action(AbstractProcessor.java:386)
>>>> at
>>>> org.apache.coyote.http2.StreamProcessor.service(StreamProcessor.java:443)
>>>> at
>>>> org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:63)
>>>> at
>>>> org.apache.coyote.http2.StreamProcessor.process(StreamProcessor.java:86)
>>>> at org.apache.coyote.http2.StreamRunnable.run(StreamRunnable.java:35)
>>>> at
>>>> org.apache.tomcat.util.threads.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1191)
>>>> at
>>>> org.apache.tomcat.util.threads.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:659)
>>>> at
>>>> org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
>>>> at java.base/java.lang.Thread.run(Thread.java:1623)
>>>> Caused by: org.apache.coyote.http2.StreamException: Timeout waiting to
>>>> read data from client
>>>> at
>>>> org.apache.coyote.http2.Stream$StandardStreamInputBuffer.doRead(Stream.java:1194)
>>>> at org.apache.coyote.Request.doRead(Request.java:635)
>>>> at
>>>> org.apache.catalina.connector.InputBuffer.realReadBytes(InputBuffer.java:313)
>>>> at
>>>> org.apache.catalina.connector.InputBuffer.checkByteBufferEof(InputBuffer.java:596)
>>>> at
>>>> org.apache.catalina.connector.InputBuffer.readByte(InputBuffer.java:326)
>>>> at
>>>> org.apache.catalina.connector.CoyoteInputStream.read(CoyoteInputStream.java:85)
>>>> at java.base/java.io.FilterInputStream.read(FilterInputStream.java:71)
>>>> at
>>>> java.base/java.io.PushbackInputStream.read(PushbackInputStream.java:150)
>>>> at
>>>> org.springframework.web.servlet.mvc.method.annotation.AbstractMessageConverterMethodArgumentResolver$EmptyBodyCheckingHttpInputMessage.<init>(AbstractMessageConverterMethodArgumentResolver.java:331)
>>>> at
>>>> org.springframework.web.servlet.mvc.method.annotation.AbstractMessageConverterMethodArgumentResolver.readWithMessageConverters(AbstractMessageConverterMethodArgumentResolver.java:172)
>>>> at
>>>> org.springframework.web.servlet.mvc.method.annotation.RequestResponseBodyMethodProcessor.readWithMessageConverters(RequestResponseBodyMethodProcessor.java:163)
>>>> at
>>>> org.springframework.web.servlet.mvc.method.annotation.RequestResponseBodyMethodProcessor.resolveArgument(RequestResponseBodyMethodProcessor.java:136)
>>>> at
>>>> org.springframework.web.method.support.HandlerMethodArgumentResolverComposite.resolveArgument(HandlerMethodArgumentResolverComposite.java:122)
>>>> at
>>>> org.springframework.web.method.support.InvocableHandlerMethod.getMethodArgumentValues(InvocableHandlerMethod.java:181)
>>>> at
>>>> org.springframework.web.method.support.InvocableHandlerMethod.invokeForRequest(InvocableHandlerMethod.java:148)
>>>> at
>>>> org.springframework.web.servlet.mvc.method.annotation.ServletInvocableHandlerMethod.invokeAndHandle(ServletInvocableHandlerMethod.java:118)
>>>> at
>>>> org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.invokeHandlerMethod(RequestMappingHandlerAdapter.java:884)
>>>> at
>>>> org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.handleInternal(RequestMappingHandlerAdapter.java:797)
>>>> at
>>>> org.springframework.web.servlet.mvc.method.AbstractHandlerMethodAdapter.handle(AbstractHandlerMethodAdapter.java:87)
>>>> at
>>>> org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:1081)
>>>> at
>>>> org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:974)
>>>> at
>>>> org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:1011)
>>>> at
>>>> org.springframework.web.servlet.FrameworkServlet.doPost(FrameworkServlet.java:914)
>>>> at jakarta.servlet.http.HttpServlet.service(HttpServlet.java:590)
>>>> at
>>>> org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:885)
>>>> at jakarta.servlet.http.HttpServlet.service(HttpServlet.java:658)
>>>> at
>>>> org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:205)
>>>> at
>>>> org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:149)
>>>> at
>>>> org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:51)
>>>> at
>>>> org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:174)
>>>> at
>>>> org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:149)
>>>> at
>>>> net.bull.javamelody.MonitoringFilter.doFilter(MonitoringFilter.java:236)
>>>> at
>>>> net.bull.javamelody.MonitoringFilter.doFilter(MonitoringFilter.java:212)
>>>> at
>>>> org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:174)
>>>> at
>>>> org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:149)
>>>> at
>>>> com.myapp.common.authz.filter.AuthzFilter.doFilter(AuthzFilter.java:458)
>>>> at
>>>> org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:174)
>>>> at
>>>> org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:149)
>>>> at com.myapp.common.csrf.filter.CsrfFilter.doFilter(CsrfFilter.java:112)
>>>> at
>>>> org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:174)
>>>> at
>>>> org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:149)
>>>> at
>>>> com.avlesh.web.filter.responseheaderfilter.ResponseHeaderFilter.doFilter(ResponseHeaderFilter.java:196)
>>>> at
>>>> org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:174)
>>>> at
>>>> org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:149)
>>>> at
>>>> org.apache.logging.log4j.web.Log4jServletFilter.doFilter(Log4jServletFilter.java:71)
>>>> at
>>>> org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:174)
>>>> at
>>>> org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:149)
>>>> at
>>>> org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:154)
>>>> at
>>>> org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:90)
>>>> at
>>>> org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:482)
>>>> at
>>>> org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:115)
>>>> at
>>>> org.apache.catalina.ha.session.JvmRouteBinderValve.invoke(JvmRouteBinderValve.java:183)
>>>> at
>>>> org.apache.catalina.ha.tcp.ReplicationValve.invoke(ReplicationValve.java:329)
>>>> at
>>>> org.apache.catalina.valves.AbstractAccessLogValve.invoke(AbstractAccessLogValve.java:676)
>>>> at
>>>> org.apache.catalina.valves.LoadBalancerDrainingValve.invoke(LoadBalancerDrainingValve.java:230)
>>>> at
>>>> org.apache.catalina.valves.AbstractAccessLogValve.invoke(AbstractAccessLogValve.java:676)
>>>> at
>>>> org.apache.catalina.valves.RemoteIpValve.invoke(RemoteIpValve.java:738)
>>>> at org.apache.catalina.valves.SSLValve.invoke(SSLValve.java:193)
>>>> at
>>>> org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:74)
>>>> at
>>>> org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:341)
>>>> at
>>>> org.apache.coyote.http2.StreamProcessor.service(StreamProcessor.java:426)
>>>> ... 7 more
>>>> 11-Jul-2023 08:27:51.173 FINE [https-openssl-nio-x.x.x.x-18443-exec-6]
>>>> org.apache.coyote.http2.Http2Parser.readDataFrame Connection [b], Stream
>>>> [23], Data length [13878], Padding length [none]
>>>> 11-Jul-2023 08:27:51.174 FINE [https-openssl-nio-x.x.x.x-18443-exec-8]
>>>> org.apache.coyote.AbstractProcessorLight.process Socket:
>>>> [org.apache.tomcat.util.net.NioEndpoint$NioSocketWrapper@6189bb2c
>>>> :org.apache.tomcat.util.net.SecureNioChannel@101e2d78:java.nio.channels.SocketChannel[connected
>>>> local=/x.x.x.x:18443 remote=/x.x.x.x:55549]], Status in: [OPEN_READ], State
>>>> out: [CLOSED]
>>>> 11-Jul-2023 08:27:51.174 FINE [https-openssl-nio-x.x.x.x-18443-exec-8]
>>>> org.apache.coyote.http2.Stream.close Connection [b], Stream [23], Reset
>>>> sent due to [ENHANCE_YOUR_CALM]
>>>> 11-Jul-2023 08:27:51.174 FINE [https-openssl-nio-x.x.x.x-18443-exec-8]
>>>> org.apache.coyote.http2.Http2AsyncUpgradeHandler.sendStreamReset Connection
>>>> [b], Stream [23], Error [ENHANCE_YOUR_CALM], Message [Timeout waiting to
>>>> read data from client],  RST (closing stream)
>>>> 11-Jul-2023 08:27:51.174 FINE [https-openssl-nio-x.x.x.x-18443-exec-8]
>>>> org.apache.coyote.http2.StreamStateMachine.stateChange Connection [b],
>>>> Stream [23], State changed from [OPEN] to [CLOSED_RST_TX]
>>>> 11-Jul-2023 08:27:51.174 FINE [https-openssl-nio-x.x.x.x-18443-exec-6]
>>>> org.apache.coyote.http2.Http2UpgradeHandler.updateOverheadCount Connection
>>>> [b], Stream [0], Frame type [DATA] resulted in new overhead count of [-480]
>>>> 11-Jul-2023 08:27:51.174 FINE [https-openssl-nio-x.x.x.x-18443-exec-6]
>>>> org.apache.coyote.http2.Http2UpgradeHandler.startRequestBodyFrame
>>>> Connection [b], Stream [23] startRequestBodyFrame returned
>>>> [java.nio.HeapByteBuffer[pos=0 lim=65535 cap=65535]]
>>>> 11-Jul-2023 08:27:51.174 FINE [https-openssl-nio-x.x.x.x-18443-exec-6]
>>>> org.apache.coyote.http2.Stream$StandardStreamInputBuffer.onDataAvailable
>>>> Data added to inBuffer when read thread is waiting. Signalling that thread
>>>> to continue
>>>> 11-Jul-2023 08:27:51.174 FINE [https-openssl-nio-x.x.x.x-18443-exec-8]
>>>> org.apache.coyote.http2.WindowAllocationManager.notify Connection [b],
>>>> Stream [23], Waiting type [0], Notify type [3]
>>>> 11-Jul-2023 08:27:51.174 FINE [https-openssl-nio-x.x.x.x-18443-exec-6]
>>>> org.apache.coyote.http2.Http2UpgradeHandler.upgradeDispatch Entry,
>>>> Connection [b], SocketStatus [OPEN_READ]
>>>> 11-Jul-2023 08:27:51.174 FINE [https-openssl-nio-x.x.x.x-18443-exec-6]
>>>> org.apache.coyote.http2.Http2UpgradeHandler.init Connection [b], State
>>>> [CONNECTED]
>>>> 11-Jul-2023 08:27:51.174 FINE [https-openssl-nio-x.x.x.x-18443-exec-8]
>>>> org.apache.coyote.http2.Stream$StandardStreamInputBuffer.swallowUnread
>>>> Swallowing [13,878] bytes previously read into input stream buffer
>>>> 11-Jul-2023 08:27:51.175 FINE [https-openssl-nio-x.x.x.x-18443-exec-8]
>>>> org.apache.coyote.http2.Http2AsyncUpgradeHandler.writeWindowUpdate
>>>> Connection [b], Sent window update to client increasing window by [13,878]
>>>> bytes
>>>> 11-Jul-2023 08:27:51.175 FINE [https-openssl-nio-x.x.x.x-18443-exec-6]
>>>> org.apache.coyote.http2.Http2UpgradeHandler.upgradeDispatch Exit,
>>>> Connection [b], SocketState [ASYNC_IO]
>>>> 11-Jul-2023 08:27:51.175 FINE [https-openssl-nio-x.x.x.x-18443-exec-8]
>>>> org.apache.coyote.http2.Stream.recycle Connection [b], Stream [23] has been
>>>> recycled
>>>>
>>>> What do you think?  Is there a bug here somewhere, or do we need to
>>>> tweak an H2 config setting in Apache or Tomcat?
>>>>
>>>> --
>>>>
>>>> Thanks,
>>>>
>>>> Dan
>>>>
>>>

-- 








*NOTICE:* This e-mail message and all attachments transmitted with 
it are for the sole use of the intended recipient(s) and may contain 
confidential and privileged information. Any unauthorized review, use, 
disclosure, ​or distribution is strictly prohibited. The contents of this 
e-mail are confidential and may be subject to work product privileges. If 
you are not the intended recipient, please contact the sender by reply 
e-mail and destroy all copies of the original message.



Reply via email to