Le 24/06/16 à 13:10, Alexander Christian a écrit :
> Hi there,
>
> I developed an RPC library called "SIMON", based on Apache MINA
> 2.0.13, using ProtocolCodecFactory. This is working fine since many
> years now.
>
> Today I faced an issue, which I - at the moment - would say is caused
> by MINA. I'll try to explain:
First, what has changed recently ? Java version ? Faster computer ?
>
> After running the problematic example code that makes use of my lib,
> it takes some time until client AND server prints the following message:
>
> -----
> M�r 17, 2016 3:52:31 PM
> org.apache.mina.core.polling.AbstractPollingIoProcessor$Processor run
> WARNUNG: Create a new selector. Selected is 0, delta = 0
This is a workaround. at some point, dur to a bug in the JVM, the
select() call returns immediately but with 0 selected keys. Obviously,
that will loop consuming 100% CPU. In this case, we simply ditch the
selector, recreate a new one and register all the selectionKeys to this
new selector.
One user has suggested that it *may* happen when you have reached the
maximum open files. Can you check that ?
> -----
>
>
> The longer the application runs, the more often (maybe just a feeling)
> this messages is logged. And the more ofthen this message is logged,
> the closer we're getting to this exception:
>
> SCHWERWIEGEND: exception Caught. thread=NioProcessor-2
> session=0x00000001. Exception:
> org.apache.mina.filter.codec.ProtocolDecoderException: No
> appropriate message decoder: 00 00 00 02 00 00 00 36 AC ED 00 <a lot
> more bytes>)
> at
> org.apache.mina.filter.codec.demux.DemuxingProtocolDecoder.doDecode(DemuxingProtocolDecoder.java:176)
> at
> org.apache.mina.filter.codec.CumulativeProtocolDecoder.decode(CumulativeProtocolDecoder.java:176)
> at
> org.apache.mina.filter.codec.ProtocolCodecFilter.messageReceived(ProtocolCodecFilter.java:230)
> at
> org.apache.mina.core.filterchain.DefaultIoFilterChain.callNextMessageReceived(DefaultIoFilterChain.java:542)
> at
> org.apache.mina.core.filterchain.DefaultIoFilterChain.access$1300(DefaultIoFilterChain.java:48)
> at
> org.apache.mina.core.filterchain.DefaultIoFilterChain$EntryImpl$1.messageReceived(DefaultIoFilterChain.java:943)
> at
> org.apache.mina.core.filterchain.IoFilterAdapter.messageReceived(IoFilterAdapter.java:109)
> at
> org.apache.mina.core.filterchain.DefaultIoFilterChain.callNextMessageReceived(DefaultIoFilterChain.java:542)
> at
> org.apache.mina.core.filterchain.DefaultIoFilterChain.fireMessageReceived(DefaultIoFilterChain.java:535)
> at
> org.apache.mina.core.polling.AbstractPollingIoProcessor.read(AbstractPollingIoProcessor.java:697)
> at
> org.apache.mina.core.polling.AbstractPollingIoProcessor.process(AbstractPollingIoProcessor.java:651)
> at
> org.apache.mina.core.polling.AbstractPollingIoProcessor.process(AbstractPollingIoProcessor.java:640)
> at
> org.apache.mina.core.polling.AbstractPollingIoProcessor.access$600(AbstractPollingIoProcessor.java:68)
> at
> org.apache.mina.core.polling.AbstractPollingIoProcessor$Processor.run(AbstractPollingIoProcessor.java:1097)
> at
> org.apache.mina.util.NamePreservingRunnable.run(NamePreservingRunnable.java:64)
> at
> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
> at
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
> at java.lang.Thread.run(Thread.java:745)
>
> This is what the example application does:
>
> // send a "LOOKUP" Message to the server, which responds with a
> "LOOPUK_RETURN" message
> remoteHandler = (Handler)
> nameLookup.lookup(Handler.class.getCanonicalName());
>
> -----------------
> for (;;) {
> // This sends a single message to the server ("INVOKE").
> // The server executes the requested method (trigger())
> // The trigger() method will send a single message (which
> get's answered by client), 100 messages with an delay of 1..100ms
> between each (also answered by client) and another single message to
> the client (also answered by client). In sum 102 messages
> server->client and 102 answers client->server.
> // After that, the remotly invoked method returns and server
> sends an messages back to the client, before the method returns an
> "INVOKE_RETURN" message to the client
> remoteHandler.trigger(monitor, System.currentTimeMillis());
>
> Thread.sleep(100);
> }
> -------------------
>
> The longer the sleep times on client and in trigger() method on server
> is, the longer it takes to get this MINA messages and the longer it
> takes until the exception occurs.
>
> Of course it would be great to have an simple reproducer-example
> without the code-overhead with my lib and this error producing sample
> application. But I was not yet abe to track down the problem to create
> such a simple, minimalistic reproducer.
>
> My current thoughts:
>
> 1) I figured out, that the message logged by MINA is related to an
> selector() issue. In that case, the selector is dropped and replaced
> with a new one. For me it looks like there is an sync-issue with
> creating this new instance. That could confuse the stream, so that a
> few bytes are missing and the codec cannot continue it's work. But I
> did not find this kind of sync-gap...
I woudl say, unlikely. The select() is waken up ony when some event to
be handled. In this case, the select() woudl return something different
than 0.
>
> 2) The reported message is ALWAYS the same. At least the first 15
> bytes are always the same.
At this point, I would question the decoder.
>
> 3) The issue does not always happen at the same time. It really differs.
Well, MINA is fully asynchronous, so you can't expect to behave in a
deterministic way.
>
> 4) If I skip the 100 messages from server back to client while
> invoking the remote method, the issue is gone.
Again, check teh decoder, or the encoder.
>
> 5) But in general, this is not a problem. I have tons of code using
> this mechanism without any issue. But the timing is different...
>
> 6) Tested with MINA 2.0.9, 2.0.13 as well as with Win7/64bit/Java8 and
> Ubuntu Linux, also with Java8.
I would need teh code, or at least a complete description of the protocol.
>
>
>
> I would be very glad if someone can give me a hint...
> If someone wants to debug this: I can give you an example project that
> uses my library (which uses MINA2.0.13).
Okie. That would probably be a good idea, because here, it's like
pulling information out of thin air...
