Many thanks! Greg
> On 20 Mar 2019, at 07:42, Emmanuel Lécharny <[email protected]> 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 <[email protected]> >>>> >>>> Tue, 16 Feb 2016 14:38:14 +0000 (15:38 +0100) >>>> >>>> Greg >>>> >>>> On Tue, 19 Mar 2019 at 17:17, Jonathan Valliere <[email protected]> >>>> 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 <[email protected]> >>>>> 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 <[email protected]> >>>>>> 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 <[email protected]> >>>>>>> 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. >>>>>
