You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@plc4x.apache.org by "Mirko Pohland (Jira)" <ji...@apache.org> on 2020/08/29 20:17:00 UTC
[jira] [Commented] (PLC4X-207) No registered handler found for
message TPKTPacket[], , using default decode method - Communication with S7
and Modbus device hangs
[ https://issues.apache.org/jira/browse/PLC4X-207?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=17187101#comment-17187101 ]
Mirko Pohland commented on PLC4X-207:
-------------------------------------
I have the same issue in production. I think this is a short overflow in the tpduReference of the S7 Response. The error always comes up when the tpduReference of the request is 65536 (unsigned short + 1) . The tpdureference of the reponse comes back with 0. This is why the response can not be mapped to the respective request. After this, every request seems to time out also after a reconnection. I will add some logging tomorrow since I am using my phone to write this.
> No registered handler found for message TPKTPacket[], , using default decode method - Communication with S7 and Modbus device hangs
> -----------------------------------------------------------------------------------------------------------------------------------
>
> Key: PLC4X-207
> URL: https://issues.apache.org/jira/browse/PLC4X-207
> Project: Apache PLC4X
> Issue Type: Bug
> Components: API, Driver-Modbus, Driver-S7
> Affects Versions: 0.8.0
> Reporter: Anton Engman
> Assignee: Julian Feinauer
> Priority: Major
>
> I am using PLC4X to poll 29 signals from a Siemens S7-300 device, all the signals are of
> data type REAL. Every second I send a request to the PLC asking for the values and then printing one of the values to the console:
>
> {code:java}
> PlcConnection conn = driverManager.getConnection("s7:tcp://<IP>?remote-rack=0&remote-slot=1&controller-type=S7_300");
> PlcReadRequest.Builder builder = conn.readRequestBuilder();
> builder.addItem("value1", "DB.50.DBD0:REAL");
> .
> .
> .
> builder.addItem("value29", "DB.50.DBD116:REAL");
> PlcReadRequest readRequest = builder.build();
> while(true)
> {
> PlcReadResponse r = readRequest.execute().get();
> System.out.println(r.getObject("value1"));
> Thread.sleep(1000);
> }
> {code}
>
> Everything works fine for some time, but after >50K requests or 8-12 hours with the current
> polling rate at 1 second the code waits forever at the return value from PlcReadResponse r
> = readRequest.execute().get() and doesn't continue. I enabled Trace logging to see what's
> happening and every time this error occurs I get the following error message:
> {code:java}
> 12:56:48.107 [nioEventLoopGroup-2-1] TRACE o.a.plc4x.java.spi.Plc4xNettyWrapper - Checking
> handler HandlerRegistration#65120 for Object of type TPKTPacket
> 12:56:48.107 [nioEventLoopGroup-2-1] TRACE o.a.plc4x.java.spi.Plc4xNettyWrapper - Handler
> HandlerRegistration#65120 has right expected type TPKTPacket, checking condition
> 12:56:48.107 [nioEventLoopGroup-2-1] TRACE o.a.plc4x.java.spi.Plc4xNettyWrapper - Registration
> HandlerRegistration#65120 does not match object TPKTPacket (currently wrapped to S7MessageResponseData)
> 12:56:48.107 [nioEventLoopGroup-2-1] TRACE o.a.plc4x.java.spi.Plc4xNettyWrapper - Checking
> handler HandlerRegistration#65119 for Object of type TPKTPacket
> 12:56:48.107 [nioEventLoopGroup-2-1] TRACE o.a.plc4x.java.spi.Plc4xNettyWrapper - Handler
> HandlerRegistration#65119 has right expected type TPKTPacket, checking condition
> 12:56:48.107 [nioEventLoopGroup-2-1] TRACE o.a.plc4x.java.spi.Plc4xNettyWrapper - Registration
> HandlerRegistration#65119 does not match object TPKTPacket (currently wrapped to S7MessageResponseData)
> 12:56:48.107 [nioEventLoopGroup-2-1] TRACE o.a.plc4x.java.spi.Plc4xNettyWrapper - No registered
> handler found for message TPKTPacket[payload=COTPPacketData[parameters={},payload=S7MessageResponseData[tpduReference=0,parameter=S7ParameterReadVarResponse[numItems=19],payload=S7PayloadReadVarResponse[items={S7VarPayloadDataItem[returnCode=OK,transportSize=REAL,dataLength=4,data={66,61,-103,-102}],S7VarPayloadDataItem[returnCode=OK,transportSize=REAL,dataLength=4,data={66,65,51,51}],S7VarPayloadDataItem[returnCode=OK,transportSize=REAL,dataLength=4,data={65,-104,0,0}],S7VarPayloadDataItem[returnCode=OK,transportSize=REAL,dataLength=4,data={65,-120,0,0}],S7VarPayloadDataItem[returnCode=OK,transportSize=REAL,dataLength=4,data={65,-103,-103,-102}],S7VarPayloadDataItem[returnCode=OK,transportSize=REAL,dataLength=4,data={65,-127,-103,-102}],S7VarPayloadDataItem[returnCode=OK,transportSize=REAL,dataLength=4,data={65,-106,102,103}],S7VarPayloadDataItem[returnCode=OK,transportSize=REAL,dataLength=4,data={65,-96,0,0}],S7VarPayloadDataItem[returnCode=OK,transportSize=REAL,dataLength=4,data={66,-8,-26,-124}],S7VarPayloadDataItem[returnCode=OK,transportSize=REAL,dataLength=4,data={63,101,-95,48}],S7VarPayloadDataItem[returnCode=OK,transportSize=REAL,dataLength=4,data={0,0,0,0}],S7VarPayloadDataItem[returnCode=OK,transportSize=REAL,dataLength=4,data={63,-101,-114,57}],S7VarPayloadDataItem[returnCode=OK,transportSize=REAL,dataLength=4,data={68,122,0,0}],S7VarPayloadDataItem[returnCode=OK,transportSize=REAL,dataLength=4,data={65,-102,102,103}],S7VarPayloadDataItem[returnCode=OK,transportSize=REAL,dataLength=4,data={-66,109,9,123}],S7VarPayloadDataItem[returnCode=OK,transportSize=REAL,dataLength=4,data={0,0,0,0}],S7VarPayloadDataItem[returnCode=OK,transportSize=REAL,dataLength=4,data={-71,-67,-96,0}],S7VarPayloadDataItem[returnCode=OK,transportSize=REAL,dataLength=4,data={0,0,0,0}],S7VarPayloadDataItem[returnCode=OK,transportSize=REAL,dataLength=4,data={0,0,0,0}]}],errorClass=0,errorCode=0],eot=true,tpduRef=0]],
> using default decode method{code}
> And this error message is the last thing that is printed to my console, it's like the code
> is going into an infinite loop or something.
> I used Wireshark to look at the packets coming from the PLC, I thought that maybe there's
> a malformed packet or something that's causing the error message above, but the packet looks
> exactly the same as the packets which are decoded successfully. I have also experimented with
> the connection string, using with and without the controller-type parameter, but without any
> difference.
> I've also tried to increase the polling rate, requesting the values every 100ms, and that
> will cause the above error to appear after 1-2 hours so it seems like the error appears based
> on the number of requests rather than some time interval.
> I have also tried to only poll for 1 signal instead of 29 but the same error still appears
> after >50K requests.
> I have a stable connection to my PLC during the entire time using an Ethernet cable without
> any significant delay.
>
> I also discovered that this bug affect Modbus devices and it seems as if the number of request necessary to produce this problem on a Modbus device is even lower, only about 10k requests. Here is the error log when the problem occurs while on Modbus:
>
> {code:java}
> 11:27:47.570 [nioEventLoopGroup-2-1] DEBUG o.a.plc4x.java.spi.Plc4xNettyWrapper - Forwarding request to plc ModbusTcpADU[transactionIdentifier=11266,unitIdentifier=1,pdu=ModbusPDUReadHoldingRegistersRequest[startingAddress=19000,quantity=2]]
> 11:27:47.570 [nioEventLoopGroup-2-1] DEBUG o.a.p.j.s.GeneratedDriverByteToMessageCodec - Sending bytes to PLC for message ModbusTcpADU[transactionIdentifier=11266,unitIdentifier=1,pdu=ModbusPDUReadHoldingRegistersRequest[startingAddress=19000,quantity=2]] as data 2c020000000601034a380002
> 11:27:48.662 [nioEventLoopGroup-2-1] TRACE o.a.p.j.s.GeneratedDriverByteToMessageCodec - Receiving bytes, trying to decode Message...
> 11:27:48.662 [nioEventLoopGroup-2-1] TRACE o.a.plc4x.java.spi.Plc4xNettyWrapper - Decoding ModbusTcpADU[transactionIdentifier=11266,unitIdentifier=1,pdu=ModbusPDUReadHoldingRegistersResponse[value={67,106,19,29}]]
> 11:27:48.662 [nioEventLoopGroup-2-1] DEBUG o.a.plc4x.java.spi.Plc4xNettyWrapper - Removing HandlerRegistration#11256 as its timed out (was set till 2020-07-07T09:27:48.570431800Z)
> 11:27:48.773 [nioEventLoopGroup-2-1] TRACE o.a.plc4x.java.spi.Plc4xNettyWrapper - No registered handler found for message ModbusTcpADU[transactionIdentifier=11266,unitIdentifier=1,pdu=ModbusPDUReadHoldingRegistersResponse[value={67,106,19,29}]], using default decode method
> {code}
>
--
This message was sent by Atlassian Jira
(v8.3.4#803005)