https://bz.apache.org/bugzilla/show_bug.cgi?id=70126
Bug ID: 70126
Summary: permessage-deflate drops trailing bytes of inflated
frame
Product: Tomcat 9
Version: 9.0.118
Hardware: PC
OS: All
Status: NEW
Severity: normal
Priority: P2
Component: WebSocket
Assignee: [email protected]
Reporter: [email protected]
Target Milestone: -----
Created attachment 40190
--> https://bz.apache.org/bugzilla/attachment.cgi?id=40190&action=edit
A reproducible test case
Overview
--------
With permessage-deflate enabled, the last few bytes of a received frame appear
to be dropped when the message decompresses to a size that is a little larger
than the 8192-byte receive buffer (for example 8192 + 35 bytes). getMoreData()
seems to report END_OF_FRAME while some decompressed bytes are still buffered
inside the Inflater, so the application receives a message that is short by a
few bytes, with no error.
This looks closely related to bug 65317, which was about messages that
decompress to exactly n*8192 bytes; this report is about messages that
decompress to n*8192 + a few more bytes.
(We are not familiar with the Tomcat internals, so the analysis and suggested
fix further down are our best guess and may be wrong. The Steps to Reproduce /
Actual / Expected sections below are what we actually observed.)
Steps to Reproduce
------------------
We could only reproduce this at the unit-test level so far. A complete,
ready-to-run test is attached as TestPerMessageDeflate_additions.java (it
carries its own copy of TesterTransformation, so it compiles on its own); put
it in test/org/apache/tomcat/websocket/ and run it (alternatively the single
@Test method can be moved into the existing TestPerMessageDeflate, which
already has TesterTransformation). For every message size from 8193 to 8704
bytes inclusive, the test compresses a binary message, then decompresses it the
way WsFrameBase.processDataBinary does (an 8192-byte buffer, looping while the
result is OVERFLOW), and checks that each message comes back at its original
length; a range of sizes is scanned because which sizes are affected seems to
depend on the Deflater output. It reproduces every time for the affected sizes.
Actual Results
--------------
The test fails. Several sizes come back short by exactly the number of bytes by
which they exceed 8192:
java.lang.AssertionError: permessage-deflate dropped trailing bytes for:
[size=8227 recovered=8192, size=8228 recovered=8192, ...,
size=8257 recovered=8192]
Tests run: 1, Failures: 1
In our run, 31 of the 512 sizes from 8193 to 8704 bytes were affected, the
smallest being 8227 (= 8192 + 35): 8192 bytes were delivered and 35 were lost.
Expected Results
----------------
The test passes: every message is delivered at its original length (a message
that decompresses to 8227 bytes is received as 8227 bytes).
Build Date & Hardware
---------------------
Tomcat 9.0.118 (latest 9.0.x release at the time of writing). JRE: Amazon
Corretto 17.0.18 (OpenJDK 17), macOS / aarch64. The affected code is in
java/org/apache/tomcat/websocket/PerMessageDeflate.java (getMoreData).
Additional Builds and Platforms
-------------------------------
We only actually ran the test on 9.0.118. The getMoreData() code looks the same
to us on 10.1.x, 11.0.x and main, so we suspect those branches are affected as
well, but we have not verified that by running it.
The behaviour is independent of the OS (it is a buffering issue in the Java
code). The exact set of affected sizes may differ on a different JRE, because
it depends on the Deflater output; the test scans a range to stay robust to
that.
Additional Information
----------------------
[ The following is our analysis and a suggested fix. This part is speculation -
we may be misreading the code. The sections above are the observed facts. ]
Where we think the cause is
...........................
The relevant part of getMoreData() is roughly:
if (inflater.needsInput() && !usedEomBytes) {
readBuffer.clear();
TransformationResult nextResult =
next.getMoreData(opCode, fin, (rsv ^ RSV_BITMASK), readBuffer);
inflater.setInput(readBuffer.array(),
readBuffer.arrayOffset(), readBuffer.position());
if (dest.hasRemaining()) {
...
} else if (readBuffer.position() > 0) {
return TransformationResult.OVERFLOW;
} else if (fin) { // (A) dest is FULL here
inflater.setInput(EOM_BYTES);
usedEomBytes = true;
}
} else if (written == 0) { // (B)
if (fin && (...context takeover...)) {
inflater.reset();
}
return TransformationResult.END_OF_FRAME;
}
For a frame that decompresses to 8192 + alpha bytes (whole compressed payload
already given to the Inflater, fin == true), our reading is that: (1) inflate()
fills dest exactly (written == 8192, dest.remaining() == 0), and alpha bytes
are left buffered inside the Inflater; (2) inflater.needsInput() is true and
usedEomBytes is false, so the outer "if" is entered; (3) next.getMoreData(...)
returns END_OF_FRAME with readBuffer.position() == 0; (4) dest.hasRemaining()
is false, so branch (A) runs: fin is true, so EOM_BYTES are appended and
usedEomBytes becomes true, and the loop repeats; (5) inflate() returns 0
because dest is already full, so branch (B) returns END_OF_FRAME.
So the frame is reported as finished, but the alpha bytes from step 1 were
never written out. We wondered whether step 4 should have returned OVERFLOW
(dest is full and there is still data to come), like the readBuffer.position()
> 0 branch just above. When alpha == 0 there is nothing pending, so the same
path ends the frame correctly, which we think is why
testMessagePartThatFillsBuffer (bug 65317) passes.
It looks to us as if, once dest is full, the "frame complete vs more to come"
decision is based on dest.hasRemaining(), readBuffer.position() and fin,
without considering whether the Inflater still has output to give.
Possible relation to bug 65317
..............................
This seems to line up with commit 3e1a3928486ce4e39186330c54abbb44d9d5c690
("Fix BZ 65317. Fix permessage-deflate with payloads of n*8192 bytes"), which
added the "else if (fin) { setInput(EOM_BYTES); usedEomBytes = true; }" branch
and the "|| usedEomBytes" loop condition. Looking at a single getMoreData()
call into an 8192-byte buffer:
decompressed size before that commit current what we'd expect
----------------- ------------------ ------- ----------------
8192 (exact) OVERFLOW END_OF_FRAME END_OF_FRAME
16384 (n*8192) OVERFLOW OVERFLOW OVERFLOW
8227 (8192 + 35) OVERFLOW END_OF_FRAME OVERFLOW (35 left)
So it looks like the 65317 fix correctly changed the exact-multiple case, but
the same "is it finished?" decision now also fires for n*8192 + alpha. We are
aware a plain revert of that commit would just reintroduce bug 65317, so that
is not a fix.
A change that seemed to work for us (please check)
..................................................
We wondered whether the decision could take the Inflater's remaining output
into account: at branch (B), if dest is full but the Inflater has not consumed
all of its input yet (so it still has output to give), return OVERFLOW instead
of END_OF_FRAME.
} else if (written == 0) {
if (!dest.hasRemaining() && !inflater.needsInput()) {
// dest is full but the Inflater still has buffered output that
// could not be written; the frame is not complete yet.
return TransformationResult.OVERFLOW;
}
if (fin && (...context takeover...)) {
inflater.reset();
}
return TransformationResult.END_OF_FRAME;
}
Our reasoning is that for 8192 exact, after the EOM bytes are consumed
needsInput() is true (the Inflater is drained), so the new condition is false
and END_OF_FRAME is still returned (bug 65317 stays fixed); while for 8192 +
alpha there is no room to write the remaining bytes, so the EOM bytes are not
consumed and needsInput() is false, OVERFLOW is returned, and the remaining
bytes are delivered on the next call.
With this change applied to the 9.0.118 source, the test above passes, the
existing TestPerMessageDeflate (including testMessagePartThatFillsBuffer for
bug 65317) still passes, and every size from 8193 to 8704 bytes round-trips
intact in our checks. We would appreciate a second opinion, as we may be
missing a case.
How we ran into it
..................
We hit this in production: a server receiving a ~24 KB binary message followed
by more messages on the same (context-takeover) connection saw data corruption
that ended in the connection being closed. We could not reduce that
multi-message corruption to a unit test, but the single-frame data loss in the
test above looks like the underlying cause.
--
You are receiving this mail because:
You are the assignee for the bug.
---------------------------------------------------------------------
To unsubscribe, e-mail: [email protected]
For additional commands, e-mail: [email protected]
