[Bug]: RequestTransactionManager does not contain a transaction in runningRequests when endRequest is called

[korni128]

What happened?

When I try to run the following simple test with Plc4xServer, an IllegalArgumentException is thrown and displayed in the log due to an empty ConcurrentHashMap of runningRequests in the RequestTransactionManager.
Apart from the exception that is displayed in the log, the test runs successfully.

It seems that the transaction was not previously added to the runningRequests.

My test code:

import static org.assertj.core.api.Assertions.assertThat;
import org.apache.plc4x.java.DefaultPlcDriverManager;
import org.apache.plc4x.java.api.PlcConnection;
import org.apache.plc4x.java.api.PlcConnectionManager;
import org.apache.plc4x.java.api.messages.PlcWriteRequest;
import org.apache.plc4x.java.api.messages.PlcWriteResponse;
import org.apache.plc4x.java.api.types.PlcResponseCode;
import org.apache.plc4x.java.tools.plc4xserver.Plc4xServer;
import org.junit.jupiter.api.Test;

public class BasicTest {

  @Test
  void basicPlc4xServerTest() throws Exception {
    Plc4xServer plc4xServer = new Plc4xServer();
    plc4xServer.start();

    String connectionStringTemplate = "plc4x://localhost:%d?remote-connection-string=%s";
    String connectionStringSimulatedTemplate = "simulated%3A%2F%2Flocalhost";
    String connectionUrl = String.format(connectionStringTemplate, plc4xServer.getPort(), connectionStringSimulatedTemplate);

    PlcConnectionManager connectionManager = new DefaultPlcDriverManager().getConnectionManager();
    final PlcWriteResponse response;
    try (PlcConnection connection = connectionManager.getConnection(connectionUrl)) {
      final PlcWriteRequest request = connection.writeRequestBuilder().addTagAddress("foo", "STATE/foo:DINT", 42).build();
      response = request.execute().get();
    }
    assertThat(response.getResponseCode("foo")).isEqualTo(PlcResponseCode.OK);
  }

}

The log output.

[nioEventLoopGroup-4-1] WARN  i.n.channel.DefaultChannelPipeline - An exceptionCaught() event was fired, and it reached at the tail of the pipeline. It usually means the last handler in the pipeline did not handle the exception.
io.netty.handler.codec.DecoderException: java.lang.IllegalArgumentException: Unknown Transaction or Transaction already finished!
	at io.netty.handler.codec.MessageToMessageDecoder.channelRead(MessageToMessageDecoder.java:98)
	at io.netty.handler.codec.MessageToMessageCodec.channelRead(MessageToMessageCodec.java:111)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:442)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:420)
	at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:412)
	at io.netty.handler.codec.ByteToMessageDecoder.fireChannelRead(ByteToMessageDecoder.java:346)
	at io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:318)
	at io.netty.handler.codec.ByteToMessageCodec.channelRead(ByteToMessageCodec.java:103)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:442)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:420)
	at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:412)
	at io.netty.channel.DefaultChannelPipeline$HeadContext.channelRead(DefaultChannelPipeline.java:1410)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:440)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:420)
	at io.netty.channel.DefaultChannelPipeline.fireChannelRead(DefaultChannelPipeline.java:919)
	at io.netty.channel.nio.AbstractNioByteChannel$NioByteUnsafe.read(AbstractNioByteChannel.java:166)
	at io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:788)
	at io.netty.channel.nio.NioEventLoop.processSelectedKeysOptimized(NioEventLoop.java:724)
	at io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:650)
	at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:562)
	at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:997)
	at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74)
	at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
	at java.base/java.lang.Thread.run(Thread.java:1583)
Caused by: java.lang.IllegalArgumentException: Unknown Transaction or Transaction already finished!
	at org.apache.plc4x.java.spi.transaction.RequestTransactionManager.endRequest(RequestTransactionManager.java:146)
	at org.apache.plc4x.java.spi.transaction.RequestTransactionManager$RequestTransaction.endRequest(RequestTransactionManager.java:177)
	at org.apache.plc4x.java.plc4x.protocol.Plc4xProtocolLogic.lambda$13(Plc4xProtocolLogic.java:170)
	at java.base/java.util.function.Consumer.lambda$andThen$0(Consumer.java:65)
	at org.apache.plc4x.java.spi.Plc4xNettyWrapper.decode(Plc4xNettyWrapper.java:178)
	at io.netty.handler.codec.MessageToMessageCodec$2.decode(MessageToMessageCodec.java:81)
	at io.netty.handler.codec.MessageToMessageDecoder.channelRead(MessageToMessageDecoder.java:88)
	... 23 common frames omitted

Version

v0.12.0

Programming Languages

• plc4j
• plc4go
• plc4c
• plc4net

Protocols

• AB-Ethernet
• ADS /AMS
• BACnet/IP
• CANopen
• DeltaV
• DF1
• EtherNet/IP
• Firmata
• KNXnet/IP
• Modbus
• OPC-UA
• S7

[splatch]

Hello @korni128, is this issue remain reproducible in your environment?

[korni128]

Hello @splatch, the issue is present in version 0.12.0, but has become irrelevant for me because I found out that it is really difficult or not possible to simulate S7 string values with the Plc4XServer/simulation protocol. I have now a different approach for my use case. FYI the snippet I have provided does not seem to work at all with the current snapshot version 0.13.0-20240405.095431-1