Possible bug on Master RTU over TCP ?
-
We noticed what may be a bug in the TcpMaster encapsulated (ie. RTU over TCP).
We setup a master as:IpParameters ip = new IpParameters(); ip.setHost("192.168.15.30"); ip.setEncapsulated(true); ip.setPort(4001); ModbusFactory factory = new ModbusFactory(); ModbusMaster master = factory.createTcpMaster(ip, true); master.setTimeout(timeout); master.setRetries(retries); master.init();
and try to read constant register from a RTU slave, (over a Serial-Ethernet converter by MOXA).
The test we run compares the received values with the known and expected constant ones.
Many com.serotonin.messaging.WaitingRoomException are reported in the log,
and there are silent and random corruptions of registers values, with value of some register returned as for another
(ie. value of register n report value of register n-1). See dumps later in the post.The same slave in TCP mode, read in pure master TCP with:
ip.setHost("192.168.12.98"); ip.setEncapsulated(false); ip.setPort(502);
works fine, and either returns the right value or reports error, but never shuffles values over registers.
Rising the timeout reduces or solves the problem (but there is no warranty, and we can not set a too high timeout value).
It seems a problem related to this bug:http://mango.serotoninsoftware.com/forum/posts/list/532.page
We tried also modbus4j from mango 1.25.5 and from CVS on sourceforge, but they seem to behave the same way.
There is another secondary problem too: is there a way to suppress the stack trace of the com.serotonin.messaging.WaitingRoomException?
As we are running into a webapp, it may cause problems with log's growth.Also, are the seroUtils.jar open source too? As it seems the problem is in there, not having the source code available is quite a problem.
Thank in advance.
RTU over TCP (encapsulated), timeout 100ms, retries 2
Gives many
com.serotonin.messaging.WaitingRoomException: No recipient was found waiting for response for key com.serotonin.modbus4j.ip.xa.XaWaitingRoomKey@8384
at com.serotonin.messaging.WaitingRoom.response(WaitingRoom.java:69)
at com.serotonin.messaging.MessageControl.data(MessageControl.java:153)
at com.serotonin.messaging.InputStreamListener.run(InputStreamListener.java:76)
at java.lang.Thread.run(Thread.java:662)and some registers get silently corrupted in ramdon way:
Request #0 sent.
1234 (class java.lang.Integer)
5678 (class java.lang.Integer)
12 (class java.lang.Integer)
34 (class java.lang.Integer)
56 (class java.lang.Integer)
78 (class java.lang.Integer)
90 (class java.lang.Integer)
!!! EXPECTED 12.34, received 1.102074E-39
!!! EXPECTED 56.789, received 5.142897E-39
2244 (class java.lang.Integer)
5577 (class java.lang.Integer)
!!! EXPECTED 11, received 2244
!!! EXPECTED 33, received 5577
!!! EXPECTED 55, received com.serotonin.modbus4j.ExceptionResult@2be9cb75
!!! EXPECTED 77, received com.serotonin.modbus4j.ExceptionResult@22c84d9
!!! EXPECTED 99, received com.serotonin.modbus4j.ExceptionResult@38c5c3ac
22.33 (class java.lang.Float)
44.5566 (class java.lang.Float)
true (class java.lang.Boolean)
false (class java.lang.Boolean)
true (class java.lang.Boolean)
false (class java.lang.Boolean)
false (class java.lang.Boolean)
true (class java.lang.Boolean)
false (class java.lang.Boolean)
true (class java.lang.Boolean)
Request #0 received.Request #1 sent.
1234 (class java.lang.Integer)
5678 (class java.lang.Integer)
!!! EXPECTED 12, received 1234
!!! EXPECTED 34, received 5678
!!! EXPECTED 56, received com.serotonin.modbus4j.ExceptionResult@75786e64
!!! EXPECTED 78, received com.serotonin.modbus4j.ExceptionResult@3597a37c
!!! EXPECTED 90, received com.serotonin.modbus4j.ExceptionResult@766e3d60
!!! EXPECTED 12.34, received 1.102074E-39
!!! EXPECTED 56.789, received 5.142897E-39
2244 (class java.lang.Integer)
5577 (class java.lang.Integer)
11 (class java.lang.Integer)
33 (class java.lang.Integer)
55 (class java.lang.Integer)
77 (class java.lang.Integer)
99 (class java.lang.Integer)
22.33 (class java.lang.Float)
44.5566 (class java.lang.Float)
true (class java.lang.Boolean)
false (class java.lang.Boolean)
true (class java.lang.Boolean)
false (class java.lang.Boolean)
false (class java.lang.Boolean)
true (class java.lang.Boolean)
false (class java.lang.Boolean)
true (class java.lang.Boolean)
Request #1 received.TCP, timeout 15ms, retries 2
Gives may com.serotonin.messaging.WaitingRoomException,
but all register either are read correctly, or an exception message is reported.
!!! EXPECTED 1234, received com.serotonin.modbus4j.exception.ModbusTransportException: com.serotonin.messaging.TimeoutException: request=com.serotonin.modbus4j.ip.xa.XaMessageRequest@23174b07
!!! EXPECTED 5678, received com.serotonin.modbus4j.exception.ModbusTransportException: com.serotonin.messaging.TimeoutException: request=com.serotonin.modbus4j.ip.xa.XaMessageRequest@23174b07
12 (class java.lang.Integer)
34 (class java.lang.Integer)
56 (class java.lang.Integer)
78 (class java.lang.Integer)
90 (class java.lang.Integer)
!!! EXPECTED 12.34, received com.serotonin.modbus4j.exception.ModbusTransportException: com.serotonin.messaging.TimeoutException: request=com.serotonin.modbus4j.ip.xa.XaMessageRequest@31d520c4
!!! EXPECTED 56.789, received com.serotonin.modbus4j.exception.ModbusTransportException: com.serotonin.messaging.TimeoutException: request=com.serotonin.modbus4j.ip.xa.XaMessageRequest@31d520c4
2244 (class java.lang.Integer)
5577 (class java.lang.Integer)
!!! EXPECTED 11, received com.serotonin.modbus4j.exception.ModbusTransportException: com.serotonin.messaging.TimeoutException: request=com.serotonin.modbus4j.ip.xa.XaMessageRequest@5d764be1
!!! EXPECTED 33, received com.serotonin.modbus4j.exception.ModbusTransportException: com.serotonin.messaging.TimeoutException: request=com.serotonin.modbus4j.ip.xa.XaMessageRequest@5d764be1
!!! EXPECTED 55, received com.serotonin.modbus4j.exception.ModbusTransportException: com.serotonin.messaging.TimeoutException: request=com.serotonin.modbus4j.ip.xa.XaMessageRequest@5d764be1
!!! EXPECTED 77, received com.serotonin.modbus4j.exception.ModbusTransportException: com.serotonin.messaging.TimeoutException: request=com.serotonin.modbus4j.ip.xa.XaMessageRequest@5d764be1
!!! EXPECTED 99, received com.serotonin.modbus4j.exception.ModbusTransportException: com.serotonin.messaging.TimeoutException: request=com.serotonin.modbus4j.ip.xa.XaMessageRequest@5d764be1
!!! EXPECTED 22.33, received com.serotonin.modbus4j.exception.ModbusTransportException: com.serotonin.messaging.TimeoutException: request=com.serotonin.modbus4j.ip.xa.XaMessageRequest@53ef9f1d
!!! EXPECTED 44.5566, received com.serotonin.modbus4j.exception.ModbusTransportException: com.serotonin.messaging.TimeoutException: request=com.serotonin.modbus4j.ip.xa.XaMessageRequest@53ef9f1d
!!! EXPECTED true, received com.serotonin.modbus4j.exception.ModbusTransportException: com.serotonin.messaging.TimeoutException: request=com.serotonin.modbus4j.ip.xa.XaMessageRequest@9f436f5
!!! EXPECTED false, received com.serotonin.modbus4j.exception.ModbusTransportException: com.serotonin.messaging.TimeoutException: request=com.serotonin.modbus4j.ip.xa.XaMessageRequest@9f436f5
!!! EXPECTED true, received com.serotonin.modbus4j.exception.ModbusTransportException: com.serotonin.messaging.TimeoutException: request=com.serotonin.modbus4j.ip.xa.XaMessageRequest@9f436f5
!!! EXPECTED false, received com.serotonin.modbus4j.exception.ModbusTransportException: com.serotonin.messaging.TimeoutException: request=com.serotonin.modbus4j.ip.xa.XaMessageRequest@9f436f5
false (class java.lang.Boolean)
true (class java.lang.Boolean)
false (class java.lang.Boolean)
true (class java.lang.Boolean)TCP, timeout 50ms, retries 2
Gives many com.serotonin.messaging.WaitingRoomException: No recipient was found waiting for response for key com.serotonin.modbus4j.ip.xa.XaWaitingRoomKey@8384
but all registers are read correctly.
1234 (class java.lang.Integer)
5678 (class java.lang.Integer)
12 (class java.lang.Integer)
34 (class java.lang.Integer)
56 (class java.lang.Integer)
78 (class java.lang.Integer)
90 (class java.lang.Integer)
12.34 (class java.lang.Float)
56.789 (class java.lang.Float)
2244 (class java.lang.Integer)
5577 (class java.lang.Integer)
11 (class java.lang.Integer)
33 (class java.lang.Integer)
55 (class java.lang.Integer)
77 (class java.lang.Integer)
99 (class java.lang.Integer)
22.33 (class java.lang.Float)
44.5566 (class java.lang.Float)
true (class java.lang.Boolean)
false (class java.lang.Boolean)
true (class java.lang.Boolean)
false (class java.lang.Boolean)
false (class java.lang.Boolean)
true (class java.lang.Boolean)
false (class java.lang.Boolean)
true (class java.lang.Boolean) -
If you can provide I/O logs of the traffic, the episodes can be simulated and we can check if there are changes to the software that may make the behaviour better. If you can create such logs with different timeouts, that would be ideal. See ModbusMaster.setIoLog.
-
Thanks for your reply.
The original test was compiled against version 1.1, which does not have ioLog, so we rewrote against the current CSV version.
The new test can reproduce the problem too.The first tests were made over VPN, and the problem occurred more often.
Working on local LAN, the timeout has less impact, but lowering timeout to around 200ms with serial connection make the problem arise.We also tried with slave tcp and master tcp, both with encapsulate == true, and the problem occurs with timeout ~50ms.
So it looks like the problem is not related to serial, or serial/ethernet, but to the RTU encapsulation.Using pure tcp (encapsulate == false) all seems to work ok.
Here are the logs from ioLog():
Master TCP started (300ms) ** RTU over TCP with serial device, this work ok
Request #0 sent.
1234 (class java.lang.Integer)
5678 (class java.lang.Integer)
12 (class java.lang.Integer)
34 (class java.lang.Integer)
56 (class java.lang.Integer)
78 (class java.lang.Integer)
90 (class java.lang.Integer)
12.34 (class java.lang.Float)
56.789 (class java.lang.Float)
2244 (class java.lang.Integer)
5577 (class java.lang.Integer)
11 (class java.lang.Integer)
33 (class java.lang.Integer)
55 (class java.lang.Integer)
77 (class java.lang.Integer)
99 (class java.lang.Integer)
22.33 (class java.lang.Float)
44.5566 (class java.lang.Float)
true (class java.lang.Boolean)
false (class java.lang.Boolean)
true (class java.lang.Boolean)
false (class java.lang.Boolean)
false (class java.lang.Boolean)
true (class java.lang.Boolean)
false (class java.lang.Boolean)
true (class java.lang.Boolean)
Request #0 received.1367509107448 O 01040000000271cb
1367509107637 I 01040404d2162ed4f1
1367509107646 O 0104000a0005100b
1367509107847 I 01040a000c00220038004e005ac796
1367509107847 O 010400140004b1cd
1367509108049 I 010408414570a4426327f0700e
1367509108050 O 010300000002c40b
1367509108250 I 01030408c415c97768
1367509108251 O 0103000a0005a5cb
1367509108451 I 01030a000b00210037004d0063437e
1367509108452 O 010300140004040d
1367509108652 I 01030841b2a3d7423239f5c901
1367509108653 O 01020000000479c9
1367509108853 I 0102010a218f
1367509108854 O 0101000000043dc9
1367509109054 I 01010105918b
Request #0 sent. (200 ms) ** RTU over TCP with serial device, has problem
com.serotonin.messaging.WaitingRoomException: No recipient was found waiting for response for key com.serotonin.modbus4j.ip.encap.EncapWaitingRoomKeyFactory$EncapWaitingRoomKey@43e
at com.serotonin.messaging.WaitingRoom.response(WaitingRoom.java:96)
at com.serotonin.messaging.MessageControl.data(MessageControl.java:201)
at com.serotonin.messaging.InputStreamListener.run(InputStreamListener.java:76)
at java.lang.Thread.run(Thread.java:662)
com.serotonin.messaging.WaitingRoomException: No recipient was found waiting for response for key com.serotonin.modbus4j.ip.encap.EncapWaitingRoomKeyFactory$EncapWaitingRoomKey@43e
at com.serotonin.messaging.WaitingRoom.response(WaitingRoom.java:96)
at com.serotonin.messaging.MessageControl.data(MessageControl.java:201)
at com.serotonin.messaging.InputStreamListener.run(InputStreamListener.java:76)
at java.lang.Thread.run(Thread.java:662)
1234 (class java.lang.Integer)
5678 (class java.lang.Integer)
!!! EXPECTED 12, received com.serotonin.modbus4j.exception.ModbusTransportException: com.serotonin.messaging.TimeoutException: request=com.serotonin.modbus4j.ip.encap.EncapMessageRequest@5e8fce95
!!! EXPECTED 34, received com.serotonin.modbus4j.exception.ModbusTransportException: com.serotonin.messaging.TimeoutException: request=com.serotonin.modbus4j.ip.encap.EncapMessageRequest@5e8fce95
!!! EXPECTED 56, received com.serotonin.modbus4j.exception.ModbusTransportException: com.serotonin.messaging.TimeoutException: request=com.serotonin.modbus4j.ip.encap.EncapMessageRequest@5e8fce95
!!! EXPECTED 78, received com.serotonin.modbus4j.exception.ModbusTransportException: com.serotonin.messaging.TimeoutException: request=com.serotonin.modbus4j.ip.encap.EncapMessageRequest@5e8fce95
!!! EXPECTED 90, received com.serotonin.modbus4j.exception.ModbusTransportException: com.serotonin.messaging.TimeoutException: request=com.serotonin.modbus4j.ip.encap.EncapMessageRequest@5e8fce95
!!! EXPECTED 12.34, received 1.102074E-39
!!! EXPECTED 56.789, received 5.142897E-39
!!! EXPECTED 2244, received com.serotonin.modbus4j.exception.ModbusTransportException: com.serotonin.messaging.TimeoutException: request=com.serotonin.modbus4j.ip.encap.EncapMessageRequest@272d7a10
!!! EXPECTED 5577, received com.serotonin.modbus4j.exception.ModbusTransportException: com.serotonin.messaging.TimeoutException: request=com.serotonin.modbus4j.ip.encap.EncapMessageRequest@272d7a10
!!! EXPECTED 11, received com.serotonin.modbus4j.exception.ModbusTransportException: com.serotonin.messaging.TimeoutException: request=com.serotonin.modbus4j.ip.encap.EncapMessageRequest@3dfeca64
!!! EXPECTED 33, received com.serotonin.modbus4j.exception.ModbusTransportException: com.serotonin.messaging.TimeoutException: request=com.serotonin.modbus4j.ip.encap.EncapMessageRequest@3dfeca64
!!! EXPECTED 55, received com.serotonin.modbus4j.exception.ModbusTransportException: com.serotonin.messaging.TimeoutException: request=com.serotonin.modbus4j.ip.encap.EncapMessageRequest@3dfeca64
!!! EXPECTED 77, received com.serotonin.modbus4j.exception.ModbusTransportException: com.serotonin.messaging.TimeoutException: request=com.serotonin.modbus4j.ip.encap.EncapMessageRequest@3dfeca64
!!! EXPECTED 99, received com.serotonin.modbus4j.exception.ModbusTransportException: com.serotonin.messaging.TimeoutException: request=com.serotonin.modbus4j.ip.encap.EncapMessageRequest@3dfeca64
!!! EXPECTED 22.33, received com.serotonin.modbus4j.exception.ModbusTransportException: com.serotonin.messaging.TimeoutException: request=com.serotonin.modbus4j.ip.encap.EncapMessageRequest@e76cbf7
!!! EXPECTED 44.5566, received com.serotonin.modbus4j.exception.ModbusTransportException: com.serotonin.messaging.TimeoutException: request=com.serotonin.modbus4j.ip.encap.EncapMessageRequest@e76cbf7
!!! EXPECTED true, received com.serotonin.modbus4j.exception.ModbusTransportException: com.serotonin.messaging.TimeoutException: request=com.serotonin.modbus4j.ip.encap.EncapMessageRequest@2352544e
!!! EXPECTED false, received com.serotonin.modbus4j.exception.ModbusTransportException: com.serotonin.messaging.TimeoutException: request=com.serotonin.modbus4j.ip.encap.EncapMessageRequest@2352544e
!!! EXPECTED true, received com.serotonin.modbus4j.exception.ModbusTransportException: com.serotonin.messaging.TimeoutException: request=com.serotonin.modbus4j.ip.encap.EncapMessageRequest@2352544e
!!! EXPECTED false, received com.serotonin.modbus4j.exception.ModbusTransportException: com.serotonin.messaging.TimeoutException: request=com.serotonin.modbus4j.ip.encap.EncapMessageRequest@2352544e
!!! EXPECTED false, received com.serotonin.modbus4j.exception.ModbusTransportException: com.serotonin.messaging.TimeoutException: request=com.serotonin.modbus4j.ip.encap.EncapMessageRequest@7a6d084b
!!! EXPECTED true, received com.serotonin.modbus4j.exception.ModbusTransportException: com.serotonin.messaging.TimeoutException: request=com.serotonin.modbus4j.ip.encap.EncapMessageRequest@7a6d084b
!!! EXPECTED false, received com.serotonin.modbus4j.exception.ModbusTransportException: com.serotonin.messaging.TimeoutException: request=com.serotonin.modbus4j.ip.encap.EncapMessageRequest@7a6d084b
!!! EXPECTED true, received com.serotonin.modbus4j.exception.ModbusTransportException: com.serotonin.messaging.TimeoutException: request=com.serotonin.modbus4j.ip.encap.EncapMessageRequest@7a6d084b
Request #0 received.1367508608989 O 01040000000271cb
1367508609176 I 01040404d2162ed4f1
1367508609185 O 0104000a0005100b
1367508609385 I 01040a000c00220038004e005ac796
1367508609389 O 0104000a0005100b
1367508609589 I 01040a000c00220038004e005ac796
1367508609590 O 010400140004b1cd
1367508609590 O 010300000002c40b
1367508609690 I 010408414570a4426327f0700e
1367508609794 O 010300000002c40b
1367508609995 O 0103000a0005a5cb
1367508610199 O 0103000a0005a5cb
1367508610400 O 010300140004040d
1367508610605 O 010300140004040d
1367508610805 O 01020000000479c9
1367508611010 O 01020000000479c9
1367508611211 O 0101000000043dc9
1367508611415 O 0101000000043dc9
run:
Master TCP started (200 ms) ** RTU over TCP with serial device, has problem
Request #0 sent.
com.serotonin.messaging.WaitingRoomException: No recipient was found waiting for response for key com.serotonin.modbus4j.ip.encap.EncapWaitingRoomKeyFactory$EncapWaitingRoomKey@43e
at com.serotonin.messaging.WaitingRoom.response(WaitingRoom.java:96)
at com.serotonin.messaging.MessageControl.data(MessageControl.java:201)
at com.serotonin.messaging.InputStreamListener.run(InputStreamListener.java:76)
at java.lang.Thread.run(Thread.java:662)
com.serotonin.messaging.WaitingRoomException: No recipient was found waiting for response for key com.serotonin.modbus4j.ip.encap.EncapWaitingRoomKeyFactory$EncapWaitingRoomKey@43e
at com.serotonin.messaging.WaitingRoom.response(WaitingRoom.java:96)
at com.serotonin.messaging.MessageControl.data(MessageControl.java:201)
at com.serotonin.messaging.InputStreamListener.run(InputStreamListener.java:76)
at java.lang.Thread.run(Thread.java:662)
com.serotonin.messaging.WaitingRoomException: No recipient was found waiting for response for key com.serotonin.modbus4j.ip.encap.EncapWaitingRoomKeyFactory$EncapWaitingRoomKey@43e
at com.serotonin.messaging.WaitingRoom.response(WaitingRoom.java:96)
at com.serotonin.messaging.MessageControl.data(MessageControl.java:201)
at com.serotonin.messaging.InputStreamListener.run(InputStreamListener.java:76)
at java.lang.Thread.run(Thread.java:662)
1234 (class java.lang.Integer)
5678 (class java.lang.Integer)
!!! EXPECTED 12, received com.serotonin.modbus4j.exception.ModbusTransportException: com.serotonin.messaging.TimeoutException: request=com.serotonin.modbus4j.ip.encap.EncapMessageRequest@5e8fce95
!!! EXPECTED 34, received com.serotonin.modbus4j.exception.ModbusTransportException: com.serotonin.messaging.TimeoutException: request=com.serotonin.modbus4j.ip.encap.EncapMessageRequest@5e8fce95
!!! EXPECTED 56, received com.serotonin.modbus4j.exception.ModbusTransportException: com.serotonin.messaging.TimeoutException: request=com.serotonin.modbus4j.ip.encap.EncapMessageRequest@5e8fce95
!!! EXPECTED 78, received com.serotonin.modbus4j.exception.ModbusTransportException: com.serotonin.messaging.TimeoutException: request=com.serotonin.modbus4j.ip.encap.EncapMessageRequest@5e8fce95
!!! EXPECTED 90, received com.serotonin.modbus4j.exception.ModbusTransportException: com.serotonin.messaging.TimeoutException: request=com.serotonin.modbus4j.ip.encap.EncapMessageRequest@5e8fce95
!!! EXPECTED 12.34, received com.serotonin.modbus4j.exception.ModbusTransportException: com.serotonin.messaging.TimeoutException: request=com.serotonin.modbus4j.ip.encap.EncapMessageRequest@272d7a10
!!! EXPECTED 56.789, received com.serotonin.modbus4j.exception.ModbusTransportException: com.serotonin.messaging.TimeoutException: request=com.serotonin.modbus4j.ip.encap.EncapMessageRequest@272d7a10
!!! EXPECTED 2244, received com.serotonin.modbus4j.exception.ModbusTransportException: com.serotonin.messaging.TimeoutException: request=com.serotonin.modbus4j.ip.encap.EncapMessageRequest@3dfeca64
!!! EXPECTED 5577, received com.serotonin.modbus4j.exception.ModbusTransportException: com.serotonin.messaging.TimeoutException: request=com.serotonin.modbus4j.ip.encap.EncapMessageRequest@3dfeca64
!!! EXPECTED 11, received 2244
!!! EXPECTED 33, received 5577
!!! EXPECTED 55, received com.serotonin.modbus4j.ExceptionResult@3dac2f9c
!!! EXPECTED 77, received com.serotonin.modbus4j.ExceptionResult@7369ca65
!!! EXPECTED 99, received com.serotonin.modbus4j.ExceptionResult@2666e815
!!! EXPECTED 22.33, received 1.010237E-39
!!! EXPECTED 44.5566, received 5.05106E-39
!!! EXPECTED true, received com.serotonin.modbus4j.exception.ModbusTransportException: com.serotonin.messaging.TimeoutException: request=com.serotonin.modbus4j.ip.encap.EncapMessageRequest@2352544e
!!! EXPECTED false, received com.serotonin.modbus4j.exception.ModbusTransportException: com.serotonin.messaging.TimeoutException: request=com.serotonin.modbus4j.ip.encap.EncapMessageRequest@2352544e
!!! EXPECTED true, received com.serotonin.modbus4j.exception.ModbusTransportException: com.serotonin.messaging.TimeoutException: request=com.serotonin.modbus4j.ip.encap.EncapMessageRequest@2352544e
!!! EXPECTED false, received com.serotonin.modbus4j.exception.ModbusTransportException: com.serotonin.messaging.TimeoutException: request=com.serotonin.modbus4j.ip.encap.EncapMessageRequest@2352544e
!!! EXPECTED false, received com.serotonin.modbus4j.exception.ModbusTransportException: com.serotonin.messaging.TimeoutException: request=com.serotonin.modbus4j.ip.encap.EncapMessageRequest@7a6d084b
!!! EXPECTED true, received com.serotonin.modbus4j.exception.ModbusTransportException: com.serotonin.messaging.TimeoutException: request=com.serotonin.modbus4j.ip.encap.EncapMessageRequest@7a6d084b
!!! EXPECTED false, received com.serotonin.modbus4j.exception.ModbusTransportException: com.serotonin.messaging.TimeoutException: request=com.serotonin.modbus4j.ip.encap.EncapMessageRequest@7a6d084b
!!! EXPECTED true, received com.serotonin.modbus4j.exception.ModbusTransportException: com.serotonin.messaging.TimeoutException: request=com.serotonin.modbus4j.ip.encap.EncapMessageRequest@7a6d084b
Request #0 received.1367509204952 O 01040000000271cb
1367509205142 I 01040404d2162ed4f1
1367509205151 O 0104000a0005100b
1367509205352 I 01040a000c00220038004e005ac796
1367509205356 O 0104000a0005100b
1367509205556 I 01040a000c00220038004e005ac796
1367509205556 O 010400140004b1cd
1367509205760 O 010400140004b1cd
1367509205960 I 010408414570a4426327f0700e
1367509205960 O 010300000002c40b
1367509206164 O 010300000002c40b
1367509206365 O 0103000a0005a5cb
1367509206365 I 01030408c415c97768
1367509206367 O 010300140004040d
1367509206465 I 01030a000b00210037004d0063437e
1367509206466 O 01020000000479c9
1367509206671 O 01020000000479c9
1367509206871 O 0101000000043dc9
1367509207076 O 0101000000043dc9Master TCP stopped
run:
Master TCP started (190 ms) ** RTU over TCP with serial device, has the problem
Request #0 sent.
com.serotonin.messaging.WaitingRoomException: No recipient was found waiting for response for key com.serotonin.modbus4j.ip.encap.EncapWaitingRoomKeyFactory$EncapWaitingRoomKey@43e
at com.serotonin.messaging.WaitingRoom.response(WaitingRoom.java:96)
at com.serotonin.messaging.MessageControl.data(MessageControl.java:201)
at com.serotonin.messaging.InputStreamListener.run(InputStreamListener.java:76)
at java.lang.Thread.run(Thread.java:662)
!!! EXPECTED 1234, received com.serotonin.modbus4j.exception.ModbusTransportException: com.serotonin.messaging.TimeoutException: request=com.serotonin.modbus4j.ip.encap.EncapMessageRequest@5e8fce95
!!! EXPECTED 5678, received com.serotonin.modbus4j.exception.ModbusTransportException: com.serotonin.messaging.TimeoutException: request=com.serotonin.modbus4j.ip.encap.EncapMessageRequest@5e8fce95
!!! EXPECTED 12, received 1234
!!! EXPECTED 34, received 5678
!!! EXPECTED 56, received com.serotonin.modbus4j.ExceptionResult@7ecec0c5
!!! EXPECTED 78, received com.serotonin.modbus4j.ExceptionResult@37d2068d
!!! EXPECTED 90, received com.serotonin.modbus4j.ExceptionResult@3dac2f9c
!!! EXPECTED 12.34, received 1.102074E-39
!!! EXPECTED 56.789, received 5.142897E-39
!!! EXPECTED 2244, received com.serotonin.modbus4j.exception.ModbusTransportException: com.serotonin.messaging.TimeoutException: request=com.serotonin.modbus4j.ip.encap.EncapMessageRequest@3dfeca64
!!! EXPECTED 5577, received com.serotonin.modbus4j.exception.ModbusTransportException: com.serotonin.messaging.TimeoutException: request=com.serotonin.modbus4j.ip.encap.EncapMessageRequest@3dfeca64
!!! EXPECTED 11, received com.serotonin.modbus4j.exception.ModbusTransportException: com.serotonin.messaging.TimeoutException: request=com.serotonin.modbus4j.ip.encap.EncapMessageRequest@e76cbf7
!!! EXPECTED 33, received com.serotonin.modbus4j.exception.ModbusTransportException: com.serotonin.messaging.TimeoutException: request=com.serotonin.modbus4j.ip.encap.EncapMessageRequest@e76cbf7
!!! EXPECTED 55, received com.serotonin.modbus4j.exception.ModbusTransportException: com.serotonin.messaging.TimeoutException: request=com.serotonin.modbus4j.ip.encap.EncapMessageRequest@e76cbf7
!!! EXPECTED 77, received com.serotonin.modbus4j.exception.ModbusTransportException: com.serotonin.messaging.TimeoutException: request=com.serotonin.modbus4j.ip.encap.EncapMessageRequest@e76cbf7
!!! EXPECTED 99, received com.serotonin.modbus4j.exception.ModbusTransportException: com.serotonin.messaging.TimeoutException: request=com.serotonin.modbus4j.ip.encap.EncapMessageRequest@e76cbf7
!!! EXPECTED 22.33, received com.serotonin.modbus4j.exception.ModbusTransportException: com.serotonin.messaging.TimeoutException: request=com.serotonin.modbus4j.ip.encap.EncapMessageRequest@7a6d084b
!!! EXPECTED 44.5566, received com.serotonin.modbus4j.exception.ModbusTransportException: com.serotonin.messaging.TimeoutException: request=com.serotonin.modbus4j.ip.encap.EncapMessageRequest@7a6d084b
!!! EXPECTED true, received com.serotonin.modbus4j.exception.ModbusTransportException: com.serotonin.messaging.TimeoutException: request=com.serotonin.modbus4j.ip.encap.EncapMessageRequest@457471e0
!!! EXPECTED false, received com.serotonin.modbus4j.exception.ModbusTransportException: com.serotonin.messaging.TimeoutException: request=com.serotonin.modbus4j.ip.encap.EncapMessageRequest@457471e0
!!! EXPECTED true, received com.serotonin.modbus4j.exception.ModbusTransportException: com.serotonin.messaging.TimeoutException: request=com.serotonin.modbus4j.ip.encap.EncapMessageRequest@457471e0
!!! EXPECTED false, received com.serotonin.modbus4j.exception.ModbusTransportException: com.serotonin.messaging.TimeoutException: request=com.serotonin.modbus4j.ip.encap.EncapMessageRequest@457471e0
!!! EXPECTED false, received com.serotonin.modbus4j.exception.ModbusTransportException: com.serotonin.messaging.TimeoutException: request=com.serotonin.modbus4j.ip.encap.EncapMessageRequest@2352544e
!!! EXPECTED true, received com.serotonin.modbus4j.exception.ModbusTransportException: com.serotonin.messaging.TimeoutException: request=com.serotonin.modbus4j.ip.encap.EncapMessageRequest@2352544e
!!! EXPECTED false, received com.serotonin.modbus4j.exception.ModbusTransportException: com.serotonin.messaging.TimeoutException: request=com.serotonin.modbus4j.ip.encap.EncapMessageRequest@2352544e
!!! EXPECTED true, received com.serotonin.modbus4j.exception.ModbusTransportException: com.serotonin.messaging.TimeoutException: request=com.serotonin.modbus4j.ip.encap.EncapMessageRequest@2352544e
Request #0 received.1367509393293 O 01040000000271cb
1367509393483 I 01040404d2162ed4f1
1367509393494 O 01040000000271cb
1367509393685 O 0104000a0005100b
1367509393695 I 01040404d2162ed4f1
1367509393697 O 010400140004b1cd
1367509393795 I 01040a000c00220038004e005ac796
1367509393796 O 010300000002c40b
1367509393991 O 010300000002c40b
1367509394181 O 0103000a0005a5cb
1367509394376 O 0103000a0005a5cb
1367509394566 O 010300140004040d
1367509394761 O 010300140004040d
1367509394951 O 01020000000479c9
1367509395146 O 01020000000479c9
1367509395337 O 0101000000043dc9
1367509395531 O 0101000000043dc9Master TCP stopped
run:
Master TCP started (50ms, tcp rtu -> tcp rtu) ** TCP, both master and slave encapsulated, no serial device, still has the problem
Request #0 sent.
com.serotonin.messaging.WaitingRoomException: No recipient was found waiting for response for key com.serotonin.modbus4j.ip.encap.EncapWaitingRoomKeyFactory$EncapWaitingRoomKey@43e
at com.serotonin.messaging.WaitingRoom.response(WaitingRoom.java:96)
at com.serotonin.messaging.MessageControl.data(MessageControl.java:201)
at com.serotonin.messaging.InputStreamListener.run(InputStreamListener.java:76)
at java.lang.Thread.run(Thread.java:662)
com.serotonin.messaging.WaitingRoomException: No recipient was found waiting for response for key com.serotonin.modbus4j.ip.encap.EncapWaitingRoomKeyFactory$EncapWaitingRoomKey@43e
at com.serotonin.messaging.WaitingRoom.response(WaitingRoom.java:96)
at com.serotonin.messaging.MessageControl.data(MessageControl.java:201)
at com.serotonin.messaging.InputStreamListener.run(InputStreamListener.java:76)
at java.lang.Thread.run(Thread.java:662)
com.serotonin.messaging.WaitingRoomException: No recipient was found waiting for response for key com.serotonin.modbus4j.ip.encap.EncapWaitingRoomKeyFactory$EncapWaitingRoomKey@41f
at com.serotonin.messaging.WaitingRoom.response(WaitingRoom.java:96)
at com.serotonin.messaging.MessageControl.data(MessageControl.java:201)
at com.serotonin.messaging.InputStreamListener.run(InputStreamListener.java:76)
at java.lang.Thread.run(Thread.java:662)
com.serotonin.messaging.WaitingRoomException: No recipient was found waiting for response for key com.serotonin.modbus4j.ip.encap.EncapWaitingRoomKeyFactory$EncapWaitingRoomKey@400
at com.serotonin.messaging.WaitingRoom.response(WaitingRoom.java:96)1234 (class java.lang.Integer)
at com.serotonin.messaging.MessageControl.data(MessageControl.java:201)
at com.serotonin.messaging.InputStreamListener.run(InputStreamListener.java:76)
at java.lang.Thread.run(Thread.java:662)
5678 (class java.lang.Integer)
12 (class java.lang.Integer)
34 (class java.lang.Integer)
56 (class java.lang.Integer)
78 (class java.lang.Integer)
90 (class java.lang.Integer)
!!! EXPECTED 12.34, received com.serotonin.modbus4j.exception.ModbusTransportException: com.serotonin.messaging.TimeoutException: request=com.serotonin.modbus4j.ip.encap.EncapMessageRequest@5e8fce95
!!! EXPECTED 56.789, received com.serotonin.modbus4j.exception.ModbusTransportException: com.serotonin.messaging.TimeoutException: request=com.serotonin.modbus4j.ip.encap.EncapMessageRequest@5e8fce95
!!! EXPECTED 2244, received com.serotonin.modbus4j.exception.ModbusTransportException: com.serotonin.messaging.TimeoutException: request=com.serotonin.modbus4j.ip.encap.EncapMessageRequest@272d7a10
!!! EXPECTED 5577, received com.serotonin.modbus4j.exception.ModbusTransportException: com.serotonin.messaging.TimeoutException: request=com.serotonin.modbus4j.ip.encap.EncapMessageRequest@272d7a10
!!! EXPECTED 11, received 2244
!!! EXPECTED 33, received 5577
!!! EXPECTED 55, received com.serotonin.modbus4j.ExceptionResult@457471e0
!!! EXPECTED 77, received com.serotonin.modbus4j.ExceptionResult@5fe04cbf
!!! EXPECTED 99, received com.serotonin.modbus4j.ExceptionResult@7ecec0c5
!!! EXPECTED 22.33, received 1.010237E-39
!!! EXPECTED 44.5566, received 5.05106E-39
true (class java.lang.Boolean)
false (class java.lang.Boolean)
true (class java.lang.Boolean)
false (class java.lang.Boolean)
!!! EXPECTED false, received com.serotonin.modbus4j.exception.ModbusTransportException: com.serotonin.messaging.TimeoutException: request=com.serotonin.modbus4j.ip.encap.EncapMessageRequest@e76cbf7
!!! EXPECTED true, received com.serotonin.modbus4j.exception.ModbusTransportException: com.serotonin.messaging.TimeoutException: request=com.serotonin.modbus4j.ip.encap.EncapMessageRequest@e76cbf7
!!! EXPECTED false, received com.serotonin.modbus4j.exception.ModbusTransportException: com.serotonin.messaging.TimeoutException: request=com.serotonin.modbus4j.ip.encap.EncapMessageRequest@e76cbf7
!!! EXPECTED true, received com.serotonin.modbus4j.exception.ModbusTransportException: com.serotonin.messaging.TimeoutException: request=com.serotonin.modbus4j.ip.encap.EncapMessageRequest@e76cbf7
Request #0 received.1367519752071 O 01040000000271cb
1367519752110 I 01040404d2162ed4f1
1367519752115 O 0104000a0005100b
1367519752165 I 01040a000c00220038004e005ac796
1367519752166 O 010400140004b1cd
1367519752216 I 010408414570a4426327f0700e
1367519752218 O 010400140004b1cd
1367519752268 I 010408414570a4426327f0700e
1367519752268 O 010300000002c40b
1367519752320 O 010300000002c40b
1367519752370 I 01030408c415c97768
1367519752370 O 0103000a0005a5cb
1367519752372 O 010300140004040d
1367519752421 I 01030a000b00210037004d0063437e
1367519752421 O 01020000000479c9
1367519752471 I 01030841b2a3d7423239f5c901
1367519752473 O 01020000000479c9
1367519752523 I 0102010a218f
1367519752523 O 0101000000043dc9
1367519752523 I 01010105918bMaster TCP stopped
BUILD SUCCESSFUL (total time: 0 seconds)
run:
Master TCP started (tcp -> tcp, 50 ms) ** this is TCP without encapsulation, works correctly
Request #0 sent.
com.serotonin.messaging.WaitingRoomException: No recipient was found waiting for response for key com.serotonin.modbus4j.ip.xa.XaWaitingRoomKeyFactory$XaWaitingRoomKey@7fc5
at com.serotonin.messaging.WaitingRoom.response(WaitingRoom.java:96)
at com.serotonin.messaging.MessageControl.data(MessageControl.java:201)
at com.serotonin.messaging.InputStreamListener.run(InputStreamListener.java:76)
at java.lang.Thread.run(Thread.java:662)
com.serotonin.messaging.WaitingRoomException: No recipient was found waiting for response for key com.serotonin.modbus4j.ip.xa.XaWaitingRoomKeyFactory$XaWaitingRoomKey@7fc5
at com.serotonin.messaging.WaitingRoom.response(WaitingRoom.java:96)
at com.serotonin.messaging.MessageControl.data(MessageControl.java:201)
at com.serotonin.messaging.InputStreamListener.run(InputStreamListener.java:76)
at java.lang.Thread.run(Thread.java:662)
com.serotonin.messaging.WaitingRoomException: No recipient was found waiting for response for key com.serotonin.modbus4j.ip.xa.XaWaitingRoomKeyFactory$XaWaitingRoomKey@7fc6
at com.serotonin.messaging.WaitingRoom.response(WaitingRoom.java:96)
at com.serotonin.messaging.MessageControl.data(MessageControl.java:201)
at com.serotonin.messaging.InputStreamListener.run(InputStreamListener.java:76)
at java.lang.Thread.run(Thread.java:662)
com.serotonin.messaging.WaitingRoomException: No recipient was found waiting for response for key com.serotonin.modbus4j.ip.xa.XaWaitingRoomKeyFactory$XaWaitingRoomKey@7c06
at com.serotonin.messaging.WaitingRoom.response(WaitingRoom.java:96)
at com.serotonin.messaging.MessageControl.data(MessageControl.java:201)
at com.serotonin.messaging.InputStreamListener.run(InputStreamListener.java:76)
at java.lang.Thread.run(Thread.java:662)
com.serotonin.messaging.WaitingRoomException: No recipient was found waiting for response for key com.serotonin.modbus4j.ip.xa.XaWaitingRoomKeyFactory$XaWaitingRoomKey@7846
at com.serotonin.messaging.WaitingRoom.response(WaitingRoom.java:96)
at com.serotonin.messaging.MessageControl.data(MessageControl.java:201)
at com.serotonin.messaging.InputStreamListener.run(InputStreamListener.java:76)
at java.lang.Thread.run(Thread.java:662)
1234 (class java.lang.Integer)
5678 (class java.lang.Integer)
12 (class java.lang.Integer)
34 (class java.lang.Integer)
56 (class java.lang.Integer)
78 (class java.lang.Integer)
90 (class java.lang.Integer)
12.34 (class java.lang.Float)
56.789 (class java.lang.Float)
2244 (class java.lang.Integer)
5577 (class java.lang.Integer)
!!! EXPECTED 11, received com.serotonin.modbus4j.exception.ModbusTransportException: com.serotonin.messaging.TimeoutException: request=com.serotonin.modbus4j.ip.xa.XaMessageRequest@3343c8b3
!!! EXPECTED 33, received com.serotonin.modbus4j.exception.ModbusTransportException: com.serotonin.messaging.TimeoutException: request=com.serotonin.modbus4j.ip.xa.XaMessageRequest@3343c8b3
!!! EXPECTED 55, received com.serotonin.modbus4j.exception.ModbusTransportException: com.serotonin.messaging.TimeoutException: request=com.serotonin.modbus4j.ip.xa.XaMessageRequest@3343c8b3
!!! EXPECTED 77, received com.serotonin.modbus4j.exception.ModbusTransportException: com.serotonin.messaging.TimeoutException: request=com.serotonin.modbus4j.ip.xa.XaMessageRequest@3343c8b3
!!! EXPECTED 99, received com.serotonin.modbus4j.exception.ModbusTransportException: com.serotonin.messaging.TimeoutException: request=com.serotonin.modbus4j.ip.xa.XaMessageRequest@3343c8b3
!!! EXPECTED 22.33, received com.serotonin.modbus4j.exception.ModbusTransportException: com.serotonin.messaging.TimeoutException: request=com.serotonin.modbus4j.ip.xa.XaMessageRequest@1aa8c488
!!! EXPECTED 44.5566, received com.serotonin.modbus4j.exception.ModbusTransportException: com.serotonin.messaging.TimeoutException: request=com.serotonin.modbus4j.ip.xa.XaMessageRequest@1aa8c488
!!! EXPECTED true, received com.serotonin.modbus4j.exception.ModbusTransportException: com.serotonin.messaging.TimeoutException: request=com.serotonin.modbus4j.ip.xa.XaMessageRequest@1948cc8c
!!! EXPECTED false, received com.serotonin.modbus4j.exception.ModbusTransportException: com.serotonin.messaging.TimeoutException: request=com.serotonin.modbus4j.ip.xa.XaMessageRequest@1948cc8c
!!! EXPECTED true, received com.serotonin.modbus4j.exception.ModbusTransportException: com.serotonin.messaging.TimeoutException: request=com.serotonin.modbus4j.ip.xa.XaMessageRequest@1948cc8c
!!! EXPECTED false, received com.serotonin.modbus4j.exception.ModbusTransportException: com.serotonin.messaging.TimeoutException: request=com.serotonin.modbus4j.ip.xa.XaMessageRequest@1948cc8c
!!! EXPECTED false, received com.serotonin.modbus4j.exception.ModbusTransportException: com.serotonin.messaging.TimeoutException: request=com.serotonin.modbus4j.ip.xa.XaMessageRequest@22998b08
!!! EXPECTED true, received com.serotonin.modbus4j.exception.ModbusTransportException: com.serotonin.messaging.TimeoutException: request=com.serotonin.modbus4j.ip.xa.XaMessageRequest@22998b08
!!! EXPECTED false, received com.serotonin.modbus4j.exception.ModbusTransportException: com.serotonin.messaging.TimeoutException: request=com.serotonin.modbus4j.ip.xa.XaMessageRequest@22998b08
!!! EXPECTED true, received com.serotonin.modbus4j.exception.ModbusTransportException: com.serotonin.messaging.TimeoutException: request=com.serotonin.modbus4j.ip.xa.XaMessageRequest@22998b08
Request #0 received.1367520378172 O 000000000006010400000002
1367520378212 I 00000000000701040404d2162e
1367520378221 O 0001000000060104000a0005
1367520378271 I 00010000000d01040a000c00220038004e005a
1367520378271 O 000200000006010400140004
1367520378321 I 00020000000b010408414570a4426327f0
1367520378322 O 000300000006010300000002
1367520378371 I 00030000000701030408c415c9
1367520378372 O 0004000000060103000a0005
1367520378422 I 00040000000d01030a000b00210037004d0063
1367520378424 O 0004000000060103000a0005
1367520378474 I 00040000000d01030a000b00210037004d0063
1367520378475 O 000500000006010300140004
1367520378526 O 000500000006010300140004
1367520378576 I 00050000000b01030841b2a3d7423239f5
1367520378577 O 000600000006010200000004
1367520378628 O 000600000006010200000004
1367520378679 I 0006000000040102010a
1367520378679 O 000700000006010100000004
1367520378731 O 000700000006010100000004
1367520378784 I 00070000000401010105Master TCP stopped
-
Sorry for the delayed response. This appears to be entirely an issue with timeout.
When compare the IO output from the first and second tests, the first is successful because the responses were completed in less than 300ms. (e.g. 1367509107637 - 1367509107448 = 189ms). The first few requests in the second test were ok. They only started to fail when the responses came back after the timeout. So, the system behaved correctly. (It's difficult to correlate the IO log with your program output because it's not obvious how many values were returned from each request.)
The fact that any request in any test was successful indicates that the encoding is likely ok. If you can determine from the IO log that this is not the case, please let me know.
-
Thanks for the answer, and sorry for the even more delayed reply too :)
The timeout is the first cause of the issue.
But imho the problem here is that, after the timeout expires and it is correctly identified, subsequent read commands receive wrong values even if successful, as if they used the previous response which timed out instead of waiting for their response.
At least, this is the final result (see red lines).
This is quite a subtle issue, as some read commands give no errors, but return silently a wrong value.Sounds no like and encoding problem, but as a mismatch in assigning the response to the request (someway it uses the timed out response instead of dropping it, when finally it arrives), even if only occurs with RTU encapsulated.
We could not trace down the problem, as it seems to generate into the closed source seroUtils jar.
We'll try to investigate further on the io logs.Regards
-
Is there a way to exactly correlate a response with the original request? I recall that modbus TCP has a transaction id, but i'm not sure if it applies in this case.
-
I'm not sure too.
But notice that the test with tcp to tcp, with rtu encapsulation enabled, has the same problem even if there is no real serial device, and only tcp is involed (see the 3rd post in the thread):
run:
Master TCP started (50ms, tcp rtu -> tcp rtu) ** TCP, both master and slave encapsulated, no serial device, still has the problemMay it me something related to this: http://mango.serotoninsoftware.com/forum/posts/list/532.page ?
The only solution we can figure out (to be tested yet), is to close the TpcMaster on receiving a timeout exception, and create a new TcpMaster.
This involves issuing only single commands and not using batch.Regards