[
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)
