Re: [milo-dev] ChunkDecoder#decode() error message

[Kevin Herron <kevinherron@xxxxxxxxx>]

I've seen that error before and never figured out if it was actually a bug in Milo (I've looked many times) or the sequence numbers on each chunk and the required check for continuity doing its job: i.e. a chunk was lost due to a dropped packet or some other error scenario in the vast amount of networking abstractions sitting below Milo.

Starting in 0.2.0 the chunk handling was refactored - it might be worth seeing if the same error happens there as well.

On Tue, Feb 13, 2018 at 6:04 PM, Shigeru Ishida <ishida_shigeru@xxxxxxxxxxx> wrote:

Hi Kevin,

I may have asked a similar question before. Sometimes ChunkDecoder#decode()
error message is output when running the server.

These servers are developed using Milo 0.1.6, and connected clients are also
created using 0.1.6. To these servers, 5-6 clients are connected at the same time
and reading data.

1) Lightweight server without Apache Felix
  Continuous running exceeded 35 days, and 13 error logs have been output so far.

2) Lightweight server with Apache Felix 5.6.10 (latest)
  Continuous running exceeded 22 days and error log was output three times so far.

In addition, 1) servers have more clients connected than 2). 1), in reality,
more than 6 clients, including clients from other companies, are connected.
In addition, data acquisition from clients of other companies is not frequent.

2), only clients created in Milo 0.1.6 are connected.

Sample error logs are as follows. The error log that is output is of this type only.
---
2018-02-12 00:03:03,571+JST 重大 org.eclipse.milo.opcua.stack.core.channel.ChunkDecoder decode - expected sequence number 3693718 but received 3693719
2018-02-12 00:03:03,573+JST 重大 org.eclipse.milo.opcua.stack.core.channel.ChunkDecoder decode - 4d5347467200000008000000e0250000975c3800a388db0001003a0305000020000000e5bdbdadf74e1d7c2ba375bd155b4c5cf3b6939ff1478ebdb41954cef6f4acee00c49b8349a3d3016e84db0000000000ffffffffa8610000000000020000001900000006fa51001900000007fa5100
2018-02-12 00:03:03,574+JST 重大 org.eclipse.milo.opcua.stack.server.handlers.UaTcpServerSymmetricHandler lambda$1 - Error decoding symmetric message: expected sequence number 3693718 but received 3693719
UaException: status=Bad_SecurityChecksFailed, message=expected sequence number 3693718 but received 3693719
        at org.eclipse.milo.opcua.stack.core.channel.ChunkDecoder.decode(ChunkDecoder.java:137)
        at org.eclipse.milo.opcua.stack.core.channel.ChunkDecoder.decodeSymmetric(ChunkDecoder.java:80)
        at org.eclipse.milo.opcua.stack.server.handlers.UaTcpServerSymmetricHandler.lambda$1(UaTcpServerSymmetricHandler.java:177)
        at org.eclipse.milo.opcua.stack.core.channel.SerializationQueue.lambda$1(SerializationQueue.java:58)
        at org.eclipse.milo.opcua.stack.core.util.ExecutionQueue$PollAndExecute.run(ExecutionQueue.java:107)
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
        at java.util.concurrent.FutureTask.run(FutureTask.java:266)
        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:748)
---

Although the server is running continuously, it is worrisome because the log level
is ERROR.

Previously, I was explained that this type of error log may be related to memory leak.

I do not think there is urgency, but if there is a hint of how to deal with something,
I am glad that you tell me helpful information. I will refer to it and consider
future countermeasures.

Regards,

--Shigeru
_______________________________________________
milo-dev mailing list
milo-dev@xxxxxxxxxxx
To change your delivery options, retrieve your password, or unsubscribe from this list, visit
https://dev.eclipse.org/mailman/listinfo/milo-dev