mina-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Greg Thomas <greg.d.tho...@gmail.com>
Subject Re: Change in behaviour of CompressionFilter
Date Wed, 20 Mar 2019 08:23:17 GMT
Many thanks!

Greg

> On 20 Mar 2019, at 07:42, Emmanuel Lécharny <elecharny@gmail.com> wrote:
> 
> I can reproduce the issue with a much simpler application (using the 'chat' example).
> 
> I will try to get a fix asap.
> 
> 
>> On 19/03/2019 23:33, Emmanuel Lécharny wrote:
>> Ok, looking at the CompressionFilter, here is what I see:
>> 
>> 
>>     @Override
>>     protected Object doFilterWrite(NextFilter nextFilter, IoSession session, WriteRequest
writeRequest)
>>             throws IOException {
>>         ...
>>         IoBuffer inBuffer = (IoBuffer) writeRequest.getMessage();
>>         if (!inBuffer.hasRemaining()) {
>>             // Ignore empty buffers
>>             return null;
>>         } else {
>>             return deflater.deflate(inBuffer);
>>         }
>>     }
>> 
>> 
>> and
>> 
>> 
>>     public IoBuffer deflate(IoBuffer inBuffer) throws IOException {
>>         if (mode == MODE_INFLATER) {
>>             throw new IllegalStateException("not initialized as DEFLATER");
>>         }
>> 
>>         byte[] inBytes = new byte[inBuffer.remaining()];
>>         inBuffer.get(inBytes).flip();
>> 
>> 
>> and finally :
>> 
>> 
>>     public final IoBuffer flip() {
>>         buf().flip();
>>         mark = -1;
>>         return this;
>>     }
>> 
>> mark is now -1, so setting a position on it will produce the error you get.
>> 
>> 
>> Sounds like a bug to me...
>> 
>>> On 19/03/2019 23:04, Emmanuel Lécharny wrote:
>>> Hi Greg, Jonathan,
>>> 
>>> it was 3 years ago, and I don't remember what was the root cause of this change.
However, reading the diff, what I can tell is that the changed version assume that the original
message (ie the message the app is writing) may not be a IoBuffer, and in this case, we needed
to process it differently.
>>> 
>>> 
>>> Let me clarify.
>>> 
>>> When a message is written by an application, it can be anything ( a String, a
data structure, some byte[], whatever), but it means something for the application. Then it
goes through the filter chain, and it get encoded, encrypted, compressed, it all depends on
the filters in use. When it hits the bottom of the chain, it's a IoBuffer that has to be written
to the remote peer. When this IoBuffer has been fully written, we can send the MessageSend
event back to the IoHandler, and we do so by using the 'original' message (ie the message
before it get encoded/compressed/encrypted) to avoid having to decode/decrypt/decompress it
again. It's like :
>>> 
>>> 
>>> IoHandler write( <original message> ) -> [filter] --(origMsg, transformedMsg)-->
[filter] --(origMsg, transformedMsg)--> ...--(origMsg, transformedMsg)--> [Head]->
write transformed data to socket
>>> 
>>> when the data has been fully sent, we go back :
>>> 
>>> [Head] --(origMsg)--> [filter] --> ... --(origMsg)--> IoHandler "The
<origMsg> message has been fully sent"
>>> 
>>> This original message is likely not to be contained in a IoBuffer, so we have
to keep it as is. OTOH,  if it was a IoBuffer, its position has changed while being processed
in the filter chain, as ity has been read, so we need to reset its position to the very beginning.
>>> 
>>> 
>>> Anyway, looking at the exception you get, here is what I suspect : the buffer
has been flipped, or cleared, and the mark is now -1, which leads to the message you get when
trying top do a reset on it.
>>> 
>>> 
>>> Is there a way to see the code that get called when you get this error ?
>>> 
>>>> On 19/03/2019 18:18, Greg Thomas wrote:
>>>> Details from
>>>> https://gitbox.apache.org/repos/asf?p=mina.git;a=commit;h=44b58469f84ce991074cdc187b1c1f23b94cf445

>>>> 
>>>> Don't try to reset a message when it's not a IoBuffer
>>>> 
>>>> Emmanuel Lécharny <elecharny@symas.com>
>>>> 
>>>> Tue, 16 Feb 2016 14:38:14 +0000 (15:38 +0100)
>>>> 
>>>> Greg
>>>> 
>>>> On Tue, 19 Mar 2019 at 17:17, Jonathan Valliere <jon.valliere@emoten.com>
>>>> wrote:
>>>> 
>>>>> I’m trying to look it up in gitbox and it doesn’t show the ids. What
was
>>>>> the date / first few words of commit message?
>>>>> 
>>>>> On Tue, Mar 19, 2019 at 1:13 PM Greg Thomas <greg.d.thomas@gmail.com>
>>>>> wrote:
>>>>> 
>>>>>> So just to clarify;
>>>>>> 
>>>>>> If we run against 2.0.14, connections using the CompressionFilter
fail.
>>>>>> 
>>>>>> If I ...
>>>>>> 
>>>>>> $ git clone http://gitbox.apache.org/repos/asf/mina.git mina
>>>>>> $ cd mina
>>>>>> $ git checkout 2.0.14
>>>>>> $ git revert 44b58469f84ce991074cdc187b1c1f23b94cf445
>>>>>> $ mvn clean package
>>>>>> 
>>>>>> and use the JAR files from that, connections using the CompressionFilter
>>>>>> succeed.
>>>>>> 
>>>>>> So I'm pretty confident that commit
>>>>>> 44b58469f84ce991074cdc187b1c1f23b94cf445 is the culprit. I just don't
>>>>>> understand the code well enough to be able to suggest why/how to
fix it.
>>>>>> 
>>>>>> Greg
>>>>>> 
>>>>>> 
>>>>>> On Tue, 19 Mar 2019 at 14:39, Jonathan Valliere <johnnyv@apache.org>
>>>>>> wrote:
>>>>>> 
>>>>>>> Have you pulled a diff between 13 and 14 to try to narrow it
down?
>>>>> It’s
>>>>>>> always possible that there is a concurrency problem with compression
>>>>>> filter
>>>>>>> which is now exposed through other changes... like what we have
with
>>>>> SSL.
>>>>>>> On Tue, Mar 19, 2019 at 8:33 AM Greg Thomas <greg.d.thomas@gmail.com>
>>>>>>> wrote:
>>>>>>> 
>>>>>>>> Openfire - an XMPP server,
>>>>>>>> https://www.igniterealtime.org/projects/openfire/index.jsp
- makes
>>>>>> heavy
>>>>>>>> use of Apache MINA for it's I/O.
>>>>>>>> 
>>>>>>>> One of the things it uses is the CompressionFilter - if clients
>>>>> enable
>>>>>>> the
>>>>>>>> Compression XMPP option.
>>>>>>>> 
>>>>>>>> We've recently updated to a newer version of MINA, and with
no other
>>>>>> code
>>>>>>>> changes found that enabling compression (in XMPP clients)
fails. I've
>>>>>>>> narrowed it down to changes between MINA 2.0.13 (where it
works) and
>>>>>>> 2.0.14
>>>>>>>> through to 2.1.0 (where it doesn't) - with Openfire throwing
the
>>>>>>> following
>>>>>>>> stack trace:
>>>>>>>> 
>>>>>>>> java.nio.InvalidMarkException: null
>>>>>>>> at java.nio.Buffer.reset(Buffer.java:306) ~[?:1.8.0_162]
>>>>>>>> at
>>>>>>>> 
>>>>>>>> 
>>>>> org.apache.mina.core.buffer.AbstractIoBuffer.reset(AbstractIoBuffer.java:424)

>>>>>>>> ~[mina-core-2.0.14.jar:?]
>>>>>>>> at
>>>>>>>> 
>>>>>>>> 
>>>>> org.apache.mina.core.polling.AbstractPollingIoProcessor.writeBuffer(AbstractPollingIoProcessor.java:940)

>>>>>>>> ~[mina-core-2.0.14.jar:?]
>>>>>>>> at
>>>>>>>> 
>>>>>>>> 
>>>>> org.apache.mina.core.polling.AbstractPollingIoProcessor.flushNow(AbstractPollingIoProcessor.java:840)

>>>>>>>> ~[mina-core-2.0.14.jar:?]
>>>>>>>> at
>>>>>>>> 
>>>>>>>> 
>>>>> org.apache.mina.core.polling.AbstractPollingIoProcessor.flush(AbstractPollingIoProcessor.java:767)

>>>>>>>> ~[mina-core-2.0.14.jar:?]
>>>>>>>> at
>>>>>>>> 
>>>>>>>> 
>>>>> org.apache.mina.core.polling.AbstractPollingIoProcessor.access$700(AbstractPollingIoProcessor.java:68)

>>>>>>>> ~[mina-core-2.0.14.jar:?]
>>>>>>>> at
>>>>>>>> 
>>>>>>>> 
>>>>> org.apache.mina.core.polling.AbstractPollingIoProcessor$Processor.run(AbstractPollingIoProcessor.java:1125)

>>>>>>>> ~[mina-core-2.0.14.jar:?]
>>>>>>>> at
>>>>>>>> 
>>>>>>>> 
>>>>> org.apache.mina.util.NamePreservingRunnable.run(NamePreservingRunnable.java:64)

>>>>>>>> ~[mina-core-2.0.14.jar:?]
>>>>>>>> at
>>>>>>>> 
>>>>>>>> 
>>>>> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)

>>>>>>>> ~[?:1.8.0_162]
>>>>>>>> at
>>>>>>>> 
>>>>>>>> 
>>>>> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)

>>>>>>>> ~[?:1.8.0_162]
>>>>>>>> at java.lang.Thread.run(Thread.java:748) [?:1.8.0_162]
>>>>>>>> 
>>>>>>>> Narrowing down even further the commit at
>>>>>>>> 
>>>>>>>> 
>>>>> https://gitbox.apache.org/repos/asf?p=mina.git;a=commit;h=44b58469f84ce991074cdc187b1c1f23b94cf445

>>>>>>>> seems
>>>>>>>> to be the culprit.
>>>>>>>> 
>>>>>>>> At this point, I'm drawing a blank.
>>>>>>>> 
>>>>>>>> It's possible Openfire is using the CompressionFilter wrongly,
which
>>>>>> was
>>>>>>>> being masked until the above commit.
>>>>>>>> 
>>>>>>>> It's possible the above commit doesn't do what was intended,
but I
>>>>>> don't
>>>>>>>> pretend to understand what it is/should be doing.
>>>>>>>> 
>>>>>>>> It's possible I've got the wrong end of the stick, and it's
something
>>>>>>> else
>>>>>>>> between MINA 2.0.13 and 2.0.14 that changed that is causing
the
>>>>>> problem.
>>>>>>>> But at this point, I don't know where to start, so would
appreciate
>>>>> any
>>>>>>>> pointers!
>>>>>>>> 
>>>>>>>> Thanks,
>>>>>>>> 
>>>>>>>> Greg
>>>>>>>> 
>>>>> -- 
>>>>> 
>>>>> CONFIDENTIALITY NOTICE: The contents of this email message and any
>>>>> attachments are intended solely for the addressee(s) and may contain
>>>>> confidential and/or privileged information and may be legally protected
>>>>> from disclosure.
>>>>> 

Mime
View raw message