FTR, I have all the test passwing with my committed changes, but one :
SslFilterTest.testMessageSentIsCalled_With_SSL. I get this stack trace :
`
javax.net.ssl.SSLException: bad record MAC
at sun.security.ssl.Alerts.getSSLException(Alerts.java:208)
at sun.security.ssl.SSLSocketImpl.fatal(SSLSocketImpl.java:1946)
at sun.security.ssl.SSLSocketImpl.readRecord(SSLSocketImpl.java:1022)
at
sun.security.ssl.SSLSocketImpl.performInitialHandshake(SSLSocketImpl.java:1367)
at sun.security.ssl.SSLSocketImpl.writeRecord(SSLSocketImpl.java:750)
at sun.security.ssl.AppOutputStream.write(AppOutputStream.java:123)
at java.io.OutputStream.write(OutputStream.java:75)
at
org.apache.mina.example.echoserver.ssl.SslFilterTest.writeMessage(SslFilterTest.java:137)
at
org.apache.mina.example.echoserver.ssl.SslFilterTest.testMessageSentIsCalled(SslFilterTest.java:100)
at
org.apache.mina.example.echoserver.ssl.SslFilterTest.testMessageSentIsCalled_With_SSL(SslFilterTest.java:76)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at
org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:50)
at
org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12)
at
org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:47)
at
org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17)
at
org.junit.internal.runners.statements.RunBefores.evaluate(RunBefores.java:26)
at
org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.java:27)
at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:325)
at
org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:78)
at
org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:57)
at org.junit.runners.ParentRunner$3.run(ParentRunner.java:290)
at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:71)
at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:288)
at org.junit.runners.ParentRunner.access$000(ParentRunner.java:58)
at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:268)
at org.junit.runners.ParentRunner.run(ParentRunner.java:363)
at
org.eclipse.jdt.internal.junit4.runner.JUnit4TestReference.run(JUnit4TestReference.java:89)
at
org.eclipse.jdt.internal.junit.runner.TestExecution.run(TestExecution.java:41)
at
org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.runTests(RemoteTestRunner.java:541)
at
org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.runTests(RemoteTestRunner.java:763)
at
org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.run(RemoteTestRunner.java:463)
at
org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.main(RemoteTestRunner.java:209)
Caused by: javax.crypto.BadPaddingException: bad record MAC
at sun.security.ssl.InputRecord.decrypt(InputRecord.java:219)
at sun.security.ssl.SSLSocketImpl.readRecord(SSLSocketImpl.java:1017)
... 32 more
I'm investigating this one. Most certainly a buffer issue (the test
passes in 2.0.20).
On 25/03/2019 02:10, Jonathan Valliere wrote:
I’m going to look at this starting Tuesday. Emmanuel do you mind creating
a branch for this Jira issue so I can track what you’re working on?
On Sun, Mar 24, 2019 at 3:54 AM Emmanuel Lécharny <elecha...@gmail.com>
wrote:
Things are complicated :/
Ok, after two days of investigation, my take is that the original sin
was to use a IoBuffer to propagate a message across the filters.
IoBuffers can be consumed (ie, when you read them, their position
change) making it very complex not to abuse them when writing a filter.
Typical problem arose in SslFilter, ProtocolCodecFilter, LoggingFilter,
CompressionFilter (and probably some more). Lets see what happens for
those filters.
LoggingFilter: actually, nothing is logged for filterWrite ! That kind
of 'fix' the issue, by ignoring it. OTOH, it's not consistent: we may
want to know what is being written...
SslFilter: it's pretty obvious that the incoming filter will be fully
consumed, and a new buffer will be produced. The interesting thing is
that the SslEngine use ByteBuffer to encrypt/decrypt data. Anyway, we
consume the incoming buffer, no matter what, and it's a side effect.
ProtocolCodecFilter: it also consume the incoming message, which can be
any kind of data structure. It doesn't matter because the factory is
application specific (or it's one of the on the shelf factories). The
special case is when the incoming message is an IoBuffer (not really
frequently the case...)
CompressionFilter: it takes a IoBuffer as input and produce a new one,
having consumed the incoming IoBuffer.
etc, etc.
So when we have fully written the message, any IoBuffer than have been
created in the filters - or any IoBBuffer that was passed by the
application - would have been consumed. If we want to propagate a
messageSent event, we need to have kept a track of the original message,
and if it was a IoBuffer, that would mean duplicating it, or flip it
before calling messageSent() just after having written it fully...
Now, why are we using IoBuffer at all ? For three reasons:
- ByteBuffer are immutable. It's valuable to be able to 'grow' a
IoBuffer, typically when we inflate a message
- SslEngine is using ByteBuffer, IoBuffer encapsulate one
- Ultimately, writing into a channel is done using a ByteBuffer, so not
having to create one when calling write on a channel saves some copy.
But this is really when we have an app that has no filter modifying the
IoBuffer. A rare corner case.
So my take is that using an IoBuffer is a premature optimization. Just
because channels require ByteBuffer does not lmean we shiould use
ByteBuffer acorss the filters, except for the SslBuffer - which should
always be the first filter in the chain anyway. We should also always
keep a track of the original message, unmodified, so that the
messageSent eveent can be propagated properly. Obviously, if the
original message is an IoBuffer, and is never modified by any filteer,
duplicating it before sending it just because we want to keep it intact
for the messageSent event is a waste, but OTOH, it's very unlikely to be
a frequent use case...
I'm currently working on implementing that, and so far, it's going well.
I'll keep the list informed.
On 22/03/2019 13:35, Emmanuel Lécharny wrote:
Ok, I have a version that works better with the CompressionFilter.
Here is what I have changed :
- the session.write( <message> ) method will inject the original
message into the WriteRequest
- any filterWrite filter that is going to create a new version of the
message will store it in the same writeRequest, into a modifiedMessage
field. (The WriteRequest impl thus holds 2 versions of the message,
the odiginal one and the modified one)
- when the modified message is written to the remote peer (it's now an
IoBuffer), messageSent will be called with the original message, or
with the written IoBuffer flipped if the original message was a
IoBuffer and was never modified.
The first test I did with the chat example seems to work pretty well.
It's going through a TextLineCodecFactory codec filter, a
CompressionFilter. I have to test it with the LoginFilter and the
SslFilter.
All in all, the MINA code is much simpler and should be faster too, as
we spare spurious calls to messageSent and filterWrite with an Empty
message.
More to come soon.
On 22/03/2019 04:58, Emmanuel Lécharny wrote:
Hmmpphhhh....
I have traced the calls when a session.write( <blah> ) is done.
It's all a kind of a hack.
In order to be able to send the messageSent() event, the
protocolFilter will call the nextFilter.filterWrite() method twice :
public void filterWrite(NextFilter nextFilter, IoSession session,
WriteRequest writeRequest) throws Exception {
Object message = writeRequest.getMessage();
...
// Write all the encoded messages now
while (!bufferQueue.isEmpty()) {
Object encodedMessage = bufferQueue.poll();
// Flush only when the buffer has remaining.
if (!(encodedMessage instanceof IoBuffer) ||
((IoBuffer) encodedMessage).hasRemaining()) {
SocketAddress destination =
writeRequest.getDestination();
WriteRequest encodedWriteRequest = new
EncodedWriteRequest(encodedMessage, null, destination);
nextFilter.filterWrite(session,
encodedWriteRequest);
}
}
// Call the next filter
nextFilter.filterWrite(session, new
MessageWriteRequest(writeRequest));
The first call we go down the chain with an IoBuffer containing the
encoded message, the second call will use th e original message
wrapped in a specific MessageWriteRequest instance, which will always
return an empty IoBuffer when a getMessage() is called on it :
private static class MessageWriteRequest extends
WriteRequestWrapper {
@Override
public Object getMessage() {
return EMPTY_BUFFER;
}
It goes down the chain to the HeadFilter where it gets stacked to be
written. But as it's an empty buffer, the flush() method will do
nothing but initiate a call to messageSent() which will pop up to the
handler. Actually, the messageSent() event will be issued twice, once
with the encoded message, and it will be swallowed silently by the
ProtocolCodecFilter :
public void messageSent(NextFilter nextFilter, IoSession session,
WriteRequest writeRequest) throws Exception {
if (writeRequest instanceof EncodedWriteRequest) {
return;
and a second time with the EMPTY buffer, which will bubble up to the
IoHandler, with the original message.
This is overly complex, and leads to spurious CPU being consumed. It
would be way smarter to encapsulate the original message in a
WriteRequest instance, go though the filters with that, up to the
encoder filter to feed a IoBuffer into this WriteRequest, which will
be written to the remote peer, and when done, a messageSent event
will be generated using the original message. If th eoriginal message
is a IoBuffer that does not require encoding, then it's enough to
keep the encoded message to null, up to the HeadFilter to find out
that the original was never transformed so that it can write it, and
let the IoProcessor generate a messageSent event after having flipped
the original message to rest it back to its original position and
limit. No reset, no mark, just a flip.
