"Server closed connection.." error may be due to HTTP/2 parser problem
- Dominant language
- C++
- Stars
- 2k
- Forks
- 874
- Avg merge
- 6d 15h
- Merged PRs (30d)
- 46
Description
I have quite many "Server closed connection.." errors in logs and one of them I pinned and explored.
Entry in log:
```
Server closed connection while reading response header. (origin deepwiki.com/squid-cache/squid)
```
Corresponding diagnostics:
```
[Jun 25 19:03:15.153] [TS_MAIN] NOTE: traffic server running
[Jun 25 19:03:15.185] [ET_NET 3] NOTE: recovery clearing offsets of Stripe /usr/local/var/trafficserver/cache.db 16384:32766 : [249151488, 257540096] sync_serial 2977 next 2978
[Jun 25 19:03:15.189] [ET_NET 2] NOTE: hosting.config loading ...
[Jun 25 19:03:15.189] [ET_NET 2] NOTE: hosting.config finished loading
[Jun 25 19:03:15.190] [ET_NET 2] NOTE: cache enabled
[Jun 25 19:03:15.190] [ET_NET 2] NOTE: Traffic Server is fully initialized.
[Jun 25 19:03:19.459] [ET_NET 2] ERROR: HTTP/2 stream error code=0x01 client_ip=76.76.21.21 session_id=195931873744250880 stream_id=3 recv headers malformed request
[Jun 25 19:03:19.525] [ET_NET 2] ERROR: HTTP/2 stream error code=0x01 client_ip=76.76.21.21 session_id=195931873744250880 stream_id=5 recv headers malformed request
[Jun 25 19:03:19.584] [ET_NET 2] ERROR: HTTP/2 stream error code=0x01 client_ip=76.76.21.21 session_id=195931873744250880 stream_id=7 recv headers malformed request
[Jun 25 19:03:19.674] [ET_NET 2] ERROR: HTTP/2 stream error code=0x01 client_ip=76.76.21.21 session_id=195931873744250880 stream_id=9 recv headers malformed request
```
Packet dumps:
```
No. Time Source Destination Protocol Length Info
1 0.000000 89.125.138.120 76.76.21.21 TCP 74 41008 → 443 [SYN] Seq=0 Win=65535 Len=0 MSS=1460 WS=64 SACK_PERM TSval=205403789 TSecr=0
2 0.001531 76.76.21.21 89.125.138.120 TCP 66 443 → 41008 [SYN, ACK] Seq=0 Ack=1 Win=65535 Len=0 MSS=1460 WS=128 SACK_PERM
3 0.001562 89.125.138.120 76.76.21.21 TCP 54 41008 → 443 [ACK] Seq=1 Ack=1 Win=65728 Len=0
4 0.001923 89.125.138.120 76.76.21.21 TLSv1.3 583 Client Hello (SNI=deepwiki.com)
5 0.003226 76.76.21.21 89.125.138.120 TCP 54 443 → 41008 [ACK] Seq=1 Ack=530 Win=66688 Len=0
6 0.008569 76.76.21.21 89.125.138.120 TLSv1.3 432 Server Hello, Change Cipher Spec, Application Data, Application Data, Application Data
7 0.009014 89.125.138.120 76.76.21.21 TLSv1.3 118 Change Cipher Spec, Application Data
8 0.010189 89.125.138.120 76.76.21.21 TLSv1.3 440 Application Data
9 0.011497 76.76.21.21 89.125.138.120 TCP 54 443 → 41008 [ACK] Seq=379 Ack=980 Win=67712 Len=0
10 0.012561 76.76.21.21 89.125.138.120 TLSv1.3 115 Application Data
...
No. Time Source Destination Protocol Length Info
353 0.261363 76.76.21.21 89.125.138.120 TCP 1514 443 → 41008 [ACK] Seq=259014 Ack=1707 Win=67712 Len=1460 [TCP PDU reassembled in 357]
354 0.261450 76.76.21.21 89.125.138.120 TCP 1514 443 → 41008 [ACK] Seq=260474 Ack=1707 Win=67712 Len=1460 [TCP PDU reassembled in 357]
355 0.261461 89.125.138.120 76.76.21.21 TCP 54 41008 → 443 [ACK] Seq=1847 Ack=261934 Win=220288 Len=0
356 0.261466 76.76.21.21 89.125.138.120 TCP 1514 443 → 41008 [ACK] Seq=261934 Ack=1707 Win=67712 Len=1460 [TCP PDU reassembled in 357]
357 0.261469 76.76.21.21 89.125.138.120 TLSv1.3 1001 Application Data, Application Data
358 0.261480 89.125.138.120 76.76.21.21 TCP 54 41008 → 443 [ACK] Seq=1847 Ack=264341 Win=217920 Len=0
359 0.261570 89.125.138.120 76.76.21.21 TLSv1.3 89 Application Data
360 0.262203 76.76.21.21 89.125.138.120 TCP 54 443 → 41008 [ACK] Seq=264341 Ack=1742 Win=67712 Len=0
361 0.262553 76.76.21.21 89.125.138.120 TCP 54 443 → 41008 [ACK] Seq=264341 Ack=1777 Win=67712 Len=0
362 0.262710 76.76.21.21 89.125.138.120 TCP 54 443 → 41008 [ACK] Seq=264341 Ack=1812 Win=67712 Len=0
363 0.262863 76.76.21.21 89.125.138.120 TCP 54 443 → 41008 [ACK] Seq=264341 Ack=1847 Win=67712 Len=0
364 0.263265 76.76.21.21 89.125.138.120 TCP 54 443 → 41008 [ACK] Seq=264341 Ack=1882 Win=67712 Len=0
```
Note that TCP session ended nothing. No FIN, RST etc.
I understand that the most interesting thing is the data itself but I don't now how to extract it from TLS stream.
deepwiki.com site seems to be stable producer of this error via ATS interaction. Meanwhile it opened well in a browsers but does browser use HTTP/2 or HTTP/1.1 I can't figure out.
P.S. ATS 10.2.x, FreeBSD 14-STABLE
Contributor guide
Assessment
This issue has not been assessed yet.