I tried to convert the bytes from the broken message to string:


00 -> ??
00 -> ??
00 -> ??
02 -> ??
00 -> ??
00 -> ??
00 -> ??
36 -> 6
AC -> ¬
ED -> í
00 -> ??
05 -> ??
73 -> s
72 -> r
01 -> ??
00 -> ??
0E -> ??
6A -> j
61 -> a
76 -> v
61 -> a
2E -> .
6C -> l
61 -> a
6E -> n
67 -> g
2E -> .
4C -> L
6F -> o
6E -> n
67 -> g
78 -> x
72 -> r
01 -> ??
00 -> ??
10 -> ??
6A -> j
61 -> a
76 -> v
61 -> a
2E -> .
6C -> l
61 -> a
6E -> n
67 -> g
2E -> .
4E -> N
75 -> u
6D -> m
62 -> b
65 -> e
72 -> r
78 -> x
70 -> p
00 -> ??
00 -> ??
00 -> ??
00 -> ??
01 -> ??
8F -> ??
B7 -> ·
E1 -> á
00 -> ??
00 -> ??
00 -> ??
36 -> 6
AC -> ¬
ED -> í
00 -> ??
05 -> ??
73 -> s
72 -> r
01 -> ??
00 -> ??
0E -> ??
6A -> j
61 -> a
76 -> v
61 -> a
2E -> .
6C -> l
61 -> a
6E -> n
67 -> g
2E -> .
4C -> L
6F -> o
6E -> n
67 -> g
78 -> x
72 -> r
01 -> ??
00 -> ??
10 -> ??
6A -> j
61 -> a
76 -> v
61 -> a
2E -> .
6C -> l
61 -> a
6E -> n
67 -> g
2E -> .
4E -> N
75 -> u
6D -> m
62 -> b
65 -> e
72 -> r
78 -> x
70 -> p
00 -> ??
00 -> ??
00 -> ??
00 -> ??
00 -> ??
1A -> ??
CB -> Ë
18 -> ??

looks like serialization?! java.lang.Number and java.lang.Long.....

Indeed I'm using serialization. On each method das is invoked with my RPC mechanism, the method arguments are serialized through

IoBuffer.putObject(...)

See: http://dev.root1.de/projects/simon/repository/entry/tags/1.3.0/src/main/java/de/root1/simon/codec/base/MsgInvokeEncoder.java#L64

Either puffer is not cleared properly, or something is wrong with serialization :-(


Switching to a more simple (and maybe faster) cumulative protocolcodec is on the roadmap, but not for now.


br,

Alex


Am 11.07.2016 um 02:21 schrieb Emmanuel Lécharny:
Le 07/07/16 à 07:49, Alexander Christian a écrit :
Am 03.07.2016 um 07:52 schrieb Emmanuel Lécharny:
Le 30/06/16 à 10:58, Alexander Christian a écrit :
Any update on this?
You didn't sent me the decoder code, just the test.
Indeed. I will quote myself:

Attached you will find the complete reproducer project (maven based).
The dependency "de.root1.simon" is the RPC library I was talking about.
Code &Source can be downloaded via maven, or you can have a look at
it here: http://dev.root1.de/projects/simon/repository/show/tags/1.3.0

I have now attached the sources-jar to this mail. So you don't have to
search&download it..


Sorry for the delay...


I had a loo, at the code, and ran the test. Here is teh traces I get on
the client side :


[1468194420983] task started: size(100)
[1468194421076] task started: size(100)
....[1468194421129] task started: size(100)
.....[1468194421182] task started: size(100)
..........[1468194421235] task started: size(100)
..........[1468194421288] task started: size(100)
..........[1468194421343] task started: size(100)
.............[1468194421397] task started: size(100)
..............[1468194421450] task started: size(100)
.................[1468194421504] task started: size(100)
..................[1468194421557] task started: size(100)
.......................[1468194421610] task started: size(100)
.....................[1468194421663] task started: size(100)
...................[1468194421716] task started: size(100)
........................[1468194421769] task started: size(100)
.............................[1468194421821] task started: size(100)
............................[1468194421877] task started: size(100)
...............................[1468194421930] task started: size(100)
......................................[1468194421983] task started:
size(100)
...................................[1468194422035] task started: size(100)
...............................................[1468194422088] task
started: size(100)
.......................................[1468194422141] task started:
size(100)
.......................................[1468194422193] task started:
size(100)
..........................................[1468194422247] task started:
size(100)
.......................................[1468194422300] task started:
size(100)
.......................................................[1468194422353]
task started: size(100)
.................................................[1468194422407] task
started: size(100)
..............................................[1468194422461] task
started: size(100)
......................................................[1468194422513]
task started: size(100)
.........................................................[1468194422566]
task started: size(100)
................................................................[1468194422620]
task started: size(100)
...................................................................[1468194422674]
task started: size(100)
......................................................[1468194422726]
task started: size(100)
.................................................................[1468194422778]
task started: size(100)
............................................................[1468194422831]
task started: size(100)
...............................................................................[1468194422884]
task started: size(100)
.............................................................................[1468194422936]
task started: size(100)
...........................................................................[1468194422990]
task started: size(100)
..........................................................................[1468194423043]
task started: size(100)
...........................................................................[1468194423095]
task started: size(100)
.................................................................................[1468194423149]
task started: size(100)
................................................................................[1468194423202]
task started: size(100)
..........................................................................................[1468194423255]
task started: size(100)
...........................................................................................[1468194423308]
task started: size(100)
...............................................................................[1468194423361]
task started: size(100)
...................................................................................................[1468194423414]
task started: size(100)
..............................................................................................[1468194423466]
task started: size(100)
.............................................................................................[1468194423519]
task started: size(100)
................................................................................................[1468194423571]
task started: size(100)
..................................................................................................[1468194423624]
task started: size(100)
.........................................................................................................[1468194423677]
task started: size(100)
..................................................................................................[1468194423730]
task started: size(100)
..........................................
[1468194421129] task finished: success(true)
....................................................
[1468194421076] task finished: success(true)
....................[1468194423782] task started: size(100)
...........................................................................................................[1468194423834]
task started: size(100)
....
[1468194421397] task finished: success(true)
............
[1468194421450] task finished: success(true)
...................................................
[1468194421182] task finished: success(true)
..........................................[1468194423887] task started:
size(100)
...........................
[1468194421235] task finished: success(true)
................
[1468194420983] task finished: success(true)
....................................................[1468194423939] task
started: size(100)
............................................................................................[1468194423992]
task started: size(100)
.......
[1468194421288] task finished: success(true)
...................................................................................[1468194424045]
task started: size(100)
.............................................
[1468194421504] task finished: success(true)
...............................................[1468194424097] task
started: size(100)
..................................................................................................[1468194424151]
task started: size(100)
..............................................................................................[1468194424203]
task started: size(100)
..........................................................................................................
[1468194421343] task finished: success(true)
.[1468194424256] task started: size(100)
......................................................................................................[1468194424309]
task started: size(100)
..............................................................................................[1468194424361]
task started: size(100)
............................................
[1468194421557] task finished: success(true)
............................
[1468194421877] task finished: success(true)
................
[1468194421716] task finished: success(true)
..............
[1468194421821] task finished: success(true)
.............[1468194424414] task started: size(100)
.................................Jul 11, 2016 1:47:07 AM
de.root1.simon.Dispatcher exceptionCaught
SEVERE: 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 05 73 72 01 00 0E 6A
61 76 61 2E 6C 61 6E 67 2E 4C 6F 6E 67 78 72 01 00 10 6A 61 76 61 2E 6C
61 6E 67 2E 4E 75 6D 62 65 72 78 70 00 00 01 55 D7 35 01 A2 00 00 00 36
AC ED 00 05 73 72 01 00 0E 6A 61 76 61 2E 6C 61 6E 67 2E 4C 6F 6E 67 78
72 01 00 10 6A 61 76 61 2E 6C 61 6E 67 2E 4E 75 6D 62 65 72 78 70 00 00
00 00 00 00 00 31 15 00 00 0F CC 00 00 00 7D 00 7B 53 69 6D 6F 6E 52 65
6D 6F 74 65 49 6E 73 74 61 6E 63 65 5B 64 65 2E 72 6F 6F 74 31 2E 73 69
6D 6F 6E 2E 74 65 73 74 2E 43 6C 69 65 6E 74 24 4D 6F 6E 69 74 6F 72 7C
69 70 3D 6C 6F 63 61 6C 68 6F 73 74 2F 31 32 37 2E 30 2E 30 2E 31 3A 35
35 35 35 35 3B 73 65 73 73 69 6F 6E 49 44 3D 31 3B 72 65 6D 6F 74 65 4F
62 6A 65 63 74 48 61 73 68 3D 37 32 38 35 39 38 37 35 37 5D 15 00 00 0F
CD 00 00 00 7D 00 7B 53 69 6D 6F 6E 52 65 6D 6F 74 65 49 6E 73 74 61 6E
63 65 5B 64 65 2E 72 6F 6F 74 31 2E 73 69 6D 6F 6E 2E 74 65 73 74 2E 43
6C 69 65 6E 74 24 4D 6F 6E 69 74 6F 72 7C 69 70 3D 6C 6F 63 61 6C 68 6F
73 74 2F 31 32 37 2E 30 2E 30 2E 31 3A 35 35 35 35 35 3B 73 65 73 73 69
6F 6E 49 44 3D 31 3B 72 65 6D 6F 74 65 4F 62 6A 65 63 74 48 61 73 68 3D
37 32 38 35 39 38 37 35 37 5D 15 00 00 0F CE 00 00 00 7D 00 7B 53 69 6D
6F 6E 52 65 6D 6F 74 65 49 6E 73 74 61 6E 63 65 5B 64 65 2E 72 6F 6F 74
31 2E 73 69 6D 6F 6E 2E 74 65 73 74 2E 43 6C 69 65 6E 74 24 4D 6F 6E 69
74 6F 72 7C 69 70 3D 6C 6F 63 61 6C 68 6F 73 74 2F 31 32 37 2E 30 2E 30
2E 31 3A 35 35 35 35 35 3B 73 65 73 73 69 6F 6E 49 44 3D 31 3B 72 65 6D
6F 74 65 4F 62 6A 65 63 74 48 61 73 68 3D 37 32 38 35 39 38 37 35 37 5D
(Hexdump: 00 00 00 02 00 00 00 36 AC ED 00 05 73 72 01 00 0E 6A 61 76 61
2E 6C 61 6E 67 2E 4C 6F 6E 67 78 72 01 00 10 6A 61 76 61 2E 6C 61 6E 67
2E 4E 75 6D 62 65 72 78 70 00 00 01 55 D7 35 01 A2 00 00 00 36 AC ED 00
05 73 72 01 00 0E 6A 61 76 61 2E 6C 61 6E 67 2E 4C 6F 6E 67 78 72 01 00
10 6A 61 76 61 2E 6C 61 6E 67 2E 4E 75 6D 62 65 72 78 70 00 00 00 00 00
00 00 31 15 00 00 0F CC 00 00 00 7D 00 7B 53 69 6D 6F 6E 52 65 6D 6F 74
65 49 6E 73 74 61 6E 63 65 5B 64 65 2E 72 6F 6F 74 31 2E 73 69 6D 6F 6E
2E 74 65 73 74 2E 43 6C 69 65 6E 74 24 4D 6F 6E 69 74 6F 72 7C 69 70 3D
6C 6F 63 61 6C 68 6F 73 74 2F 31 32 37 2E 30 2E 30 2E 31 3A 35 35 35 35
35 3B 73 65 73 73 69 6F 6E 49 44 3D 31 3B 72 65 6D 6F 74 65 4F 62 6A 65
63 74 48 61 73 68 3D 37 32 38 35 39 38 37 35 37 5D 15 00 00 0F CD 00 00
00 7D 00 7B 53 69 6D 6F 6E 52 65 6D 6F 74 65 49 6E 73 74 61 6E 63 65 5B
64 65 2E 72 6F 6F 74 31 2E 73 69 6D 6F 6E 2E 74 65 73 74 2E 43 6C 69 65
6E 74 24 4D 6F 6E 69 74 6F 72 7C 69 70 3D 6C 6F 63 61 6C 68 6F 73 74 2F
31 32 37 2E 30 2E 30 2E 31 3A 35 35 35 35 35 3B 73 65 73 73 69 6F 6E 49
44 3D 31 3B 72 65 6D 6F 74 65 4F 62 6A 65 63 74 48 61 73 68 3D 37 32 38
35 39 38 37 35 37 5D 15 00 00 0F CE 00 00 00 7D 00 7B 53 69 6D 6F 6E 52
65 6D 6F 74 65 49 6E 73 74 61 6E 63 65 5B 64 65 2E 72 6F 6F 74 31 2E 73
69 6D 6F 6E 2E 74 65 73 74 2E 43 6C 69 65 6E 74 24 4D 6F 6E 69 74 6F 72
7C 69 70 3D 6C 6F 63 61 6C 68 6F 73 74 2F 31 32 37 2E 30 2E 30 2E 31 3A
35 35 35 35 35 3B 73 65 73 73 69 6F 6E 49 44 3D 31 3B 72 65 6D 6F 74 65
4F 62 6A 65 63 74 48 61 73 68 3D 37 32 38 35 39 38 37 35 37 5D)
     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:1145)
     at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
     at java.lang.Thread.run(Thread.java:745)

Exception in thread "Simon.Dispatcher.WorkerPool.#2"
de.root1.simon.exceptions.SimonException: An error occured while reading
a message for remote object
'SimonRemoteInstance[de.root1.simon.test.Client$Monitor|ip=localhost/127.0.0.1:55555;sessionID=1;remoteObjectHash=728598757]'.
Error message: Error while decoding invoke request
     at
de.root1.simon.ProcessMessageRunnable.processError(ProcessMessageRunnable.java:741)
     at
de.root1.simon.ProcessMessageRunnable.run(ProcessMessageRunnable.java:161)
     at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
     at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
     at java.lang.Thread.run(Thread.java:745)
Caused by: java.lang.NullPointerException
     at de.root1.simon.LookupTable.getMethod(LookupTable.java:383)
     at
de.root1.simon.codec.base.MsgInvokeDecoder.decodeBody(MsgInvokeDecoder.java:67)
     at
de.root1.simon.codec.base.AbstractMessageDecoder.decode(AbstractMessageDecoder.java:97)
     at
org.apache.mina.filter.codec.demux.DemuxingProtocolDecoder.doDecode(DemuxingProtocolDecoder.java:188)
     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)
     ... 3 more
Exception in thread "main" de.root1.simon.exceptions.SessionException:
Cannot handle method call "public abstract void
de.root1.simon.tests.interfaces.Handler.trigger(de.root1.simon.tests.interfaces.ProgressInterface,long)"
on already closed Dispatcher for Session 0x00000001.
     at de.root1.simon.Dispatcher.checkForInvalidState(Dispatcher.java:691)
     at de.root1.simon.Dispatcher.invokeMethod(Dispatcher.java:309)
     at de.root1.simon.SimonProxy.invoke(SimonProxy.java:159)
     at com.sun.proxy.$Proxy0.trigger(Unknown Source)
     at de.root1.simon.test.Client.main(Client.java:40)


As you can see, I have the same error, but I don't have any selector
being recreated.


There is something fishy somwhere, but I can't tell. Your code is quite
big, and from what I saw, nothing jumped to my eyes.


FTR, I would not have implemented the decoder the way you did. Do you
really need a DemuxingProtocolDecoder ? All in all, one single byte is
enough for you to determinate the message type, and that would ddeserve
a switch(type) in a simple cumulative protocol decoder. Teh way teh
Demux decoder works is not exactly beautiful : it loops on all the
registred decoders, returning OK when it can decode one message, so you
have to check all the decoder for *every* message. Not that it shouldn't
be fixed in MINA (that would deserver a JIRA for sure), but at some
point, simplicity is teh key.


Now, the error is systematic. It seems like the buffer is not correctly
processed, at least in the test. I would suggest you chack that the
buffer is emptied after each read.


Sadly, it would require me more than a few hours to understand exactly
what your code is doing, so I can't point on any places to start. Maybe
ading a Logger filter would help.


Reply via email to