https://bz.apache.org/bugzilla/show_bug.cgi?id=66076
Bug ID: 66076
Summary: Final block of encrypted response payload not being
sent occasionally over TLS
Product: Tomcat 9
Version: 9.0.60
Hardware: PC
OS: Linux
Status: NEW
Severity: major
Priority: P2
Component: Catalina
Assignee: dev@tomcat.apache.org
Reporter: pil...@yahoo.com
Target Milestone: -----
Created attachment 38291
--> https://bz.apache.org/bugzilla/attachment.cgi?id=38291&action=edit
server-side tcpdump
We're occasionally encountering a problem where the last encrypted block of an
outbound websocket payload is not being sent over TLS.
This looks very similar to bug 65448, but this is not simulating blocking and
this is not when sending a file. It's async I/O over NIO for outbound
websocket traffic.
Most of the time it works, but occasionally it does not. We can usually
reproduce the problem in a few hours when sending a request every 2 seconds.
The problem only occurs over TLS, not over unencrypted channels. It reproduces
with both openssl (via tomcat native) and Java's TLS impl.
The outbound payload being sent in this test is 105493 bytes (encrypted).
I've attached a tcpdump that shows the behavior, but I'll copy a bit of it
here....
Here's an example of a working request/response (I have removed the client acks
for brevity, but they can be seen in the attachment)...
# Begin Request 3
16:42:43.728300 IP 10.132.54.95.58275 > 10.63.72.78.8444: Flags [P.], seq
4338:4390, ack 4052, win 8210, length 52
# Begin Response 3 (success) Full response is 105493 bytes
16:42:43.735921 IP 10.63.72.78.8444 > 10.132.54.95.58275: Flags [.], seq
4052:6972, ack 4390, win 311, length 2920
16:42:43.735936 IP 10.63.72.78.8444 > 10.132.54.95.58275: Flags [.], seq
6972:9892, ack 4390, win 311, length 2920
16:42:43.735947 IP 10.63.72.78.8444 > 10.132.54.95.58275: Flags [.], seq
9892:12812, ack 4390, win 311, length 2920
16:42:43.735954 IP 10.63.72.78.8444 > 10.132.54.95.58275: Flags [.], seq
12812:15732, ack 4390, win 311, length 2920
16:42:43.735962 IP 10.63.72.78.8444 > 10.132.54.95.58275: Flags [.], seq
15732:18652, ack 4390, win 311, length 2920
16:42:43.736675 IP 10.63.72.78.8444 > 10.132.54.95.58275: Flags [.], seq
18652:24492, ack 4390, win 311, length 5840
16:42:43.736695 IP 10.63.72.78.8444 > 10.132.54.95.58275: Flags [.], seq
24492:30332, ack 4390, win 311, length 5840
16:42:43.736702 IP 10.63.72.78.8444 > 10.132.54.95.58275: Flags [.], seq
30332:36172, ack 4390, win 311, length 5840
16:42:43.736720 IP 10.63.72.78.8444 > 10.132.54.95.58275: Flags [.], seq
36172:44932, ack 4390, win 311, length 8760
16:42:43.737386 IP 10.63.72.78.8444 > 10.132.54.95.58275: Flags [.], seq
44932:58072, ack 4390, win 311, length 13140
16:42:43.737457 IP 10.63.72.78.8444 > 10.132.54.95.58275: Flags [.], seq
58072:72672, ack 4390, win 311, length 14600
16:42:43.738146 IP 10.63.72.78.8444 > 10.132.54.95.58275: Flags [.], seq
72672:82892, ack 4390, win 311, length 10220
16:42:43.738187 IP 10.63.72.78.8444 > 10.132.54.95.58275: Flags [.], seq
82892:100412, ack 4390, win 311, length 17520
16:42:43.738926 IP 10.63.72.78.8444 > 10.132.54.95.58275: Flags [P.], seq
100412:109545, ack 4390, win 311, length 9133
# End Response 3 (all 105493 bytes sent and acknowledged)
And here is an example of a response that demonstrates the problem (again with
client acks removed)...
# Begin Request 4
16:42:45.750396 IP 10.132.54.95.58275 > 10.63.72.78.8444: Flags [P.], seq
4390:4442, ack 109545, win 8212, length 52
# Begin Response 4 (failure) Full response is 105493 bytes
16:42:45.757878 IP 10.63.72.78.8444 > 10.132.54.95.58275: Flags [P.], seq
109545:125958, ack 4442, win 311, length 16413
16:42:45.757953 IP 10.63.72.78.8444 > 10.132.54.95.58275: Flags [P.], seq
125958:142371, ack 4442, win 311, length 16413
16:42:45.758108 IP 10.63.72.78.8444 > 10.132.54.95.58275: Flags [.], seq
142371:146751, ack 4442, win 311, length 4380
16:42:45.758765 IP 10.63.72.78.8444 > 10.132.54.95.58275: Flags [.], seq
146751:165731, ack 4442, win 311, length 18980
16:42:45.758832 IP 10.63.72.78.8444 > 10.132.54.95.58275: Flags [.], seq
165731:181791, ack 4442, win 311, length 16060
16:42:45.759519 IP 10.63.72.78.8444 > 10.132.54.95.58275: Flags [.], seq
181791:197851, ack 4442, win 311, length 16060
16:42:45.759635 IP 10.63.72.78.8444 > 10.132.54.95.58275: Flags [P.], seq
197851:210991, ack 4442, win 311, length 13140
########### START OF PROBLEM ###########
# Only 101446 bytes sent so far. This last block of 4047 bytes is not sent
until the connection begins closing over a minute after the previous block was
sent.
16:44:21.222056 IP 10.63.72.78.8444 > 10.132.54.95.58275: Flags [P.], seq
210991:215038, ack 4442, win 311, length 4047
# End Response 4 (all 105493 bytes sent and acknowledged)
########### END OF PROBLEM #############
# Begin closing handshake
16:44:21.222117 IP 10.63.72.78.8444 > 10.132.54.95.58275: Flags [P.], seq
215038:215119, ack 4442, win 311, length 81
16:44:21.222812 IP 10.132.54.95.58275 > 10.63.72.78.8444: Flags [.], ack
215119, win 8212, length 0
16:44:21.237321 IP 10.132.54.95.58275 > 10.63.72.78.8444: Flags [P.], seq
4442:4527, ack 215119, win 8212, length 85
16:44:21.237428 IP 10.132.54.95.58275 > 10.63.72.78.8444: Flags [P.], seq
4527:4558, ack 215119, win 8212, length 31
16:44:21.237503 IP 10.132.54.95.58275 > 10.63.72.78.8444: Flags [F.], seq 4558,
ack 215119, win 8212, length 0
16:44:21.237786 IP 10.63.72.78.8444 > 10.132.54.95.58275: Flags [.], ack 4559,
win 311, length 0
16:44:21.239201 IP 10.63.72.78.8444 > 10.132.54.95.58275: Flags [P.], seq
215119:215150, ack 4559, win 311, length 31
16:44:21.239234 IP 10.63.72.78.8444 > 10.132.54.95.58275: Flags [F.], seq
215150, ack 4559, win 311, length 0
16:44:21.240606 IP 10.132.54.95.58275 > 10.63.72.78.8444: Flags [R.], seq 4559,
ack 215150, win 0, length 0
Unfortunately, I do not have a simple reproducible project yet, but I'm hoping
you might have an idea where to look, since this looks very similar to bug
65448
--
You are receiving this mail because:
You are the assignee for the bug.
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscr...@tomcat.apache.org
For additional commands, e-mail: dev-h...@tomcat.apache.org
