You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@plc4x.apache.org by "Christofer Dutz (Jira)" <ji...@apache.org> on 2020/09/16 12:14:00 UTC
[jira] [Resolved] (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:all-tabpanel ]
Christofer Dutz resolved PLC4X-207.
-----------------------------------
Resolution: Fixed
Should be fixed now
> 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.7.0
> Reporter: Anton Engman
> Assignee: Christofer Dutz
> Priority: Major
> Fix For: 0.8.0
>
>
> 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)