[
https://issues.apache.org/jira/browse/PLC4X-179?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=17046669#comment-17046669
]
Christofer Dutz commented on PLC4X-179:
---------------------------------------
Hi Florian,
Happy rewriting the entire driver gave us the chance to fix some things ;)
could you perhaps attach another WireShark dump for this?
Chris
> Initial connection terminated from PLC
> --------------------------------------
>
> Key: PLC4X-179
> URL: https://issues.apache.org/jira/browse/PLC4X-179
> Project: Apache PLC4X
> Issue Type: Bug
> Components: Driver-S7
> Affects Versions: 0.5.0
> Environment: Windows 10, jdk1.8.0_91-win64, jdk11.0.6.10
> Reporter: Florian Probst
> Assignee: Christofer Dutz
> Priority: Major
> Attachments: responseTimeout.txt, s7_400_connectionTerminated.pcapng
>
>
> When trying to connect our S7-400 PLC the PLC terminates the connection after
> the first message sent. I tried the following URLs:
> * s7://192.168.3.166/0/3
> * s7://192.168.3.166/0/3?controller-type=S7_400
> Here is the full log that has been logged while capturing the attached
> wireshark trace:
> {noformat}
> 16:50:40.134 [main] INFO org.apache.plc4x.java.PlcDriverManager -
> Instantiating new PLC Driver Manager with class loader
> sun.misc.Launcher$AppClassLoader@73d16e93
> 16:50:40.149 [main] INFO org.apache.plc4x.java.PlcDriverManager - Registering
> available drivers...
> 16:50:40.154 [main] INFO org.apache.plc4x.java.PlcDriverManager - Registering
> driver for Protocol s7 (Siemens S7 (Basic))
> 16:50:40.171 [main] DEBUG
> io.netty.util.internal.logging.InternalLoggerFactory - Using SLF4J as the
> default logging framework
> 16:50:40.174 [main] DEBUG io.netty.util.ResourceLeakDetector -
> -Dio.netty.leakDetection.level: simple
> 16:50:40.175 [main] DEBUG io.netty.util.ResourceLeakDetector -
> -Dio.netty.leakDetection.targetRecords: 4
> 16:50:40.194 [main] DEBUG io.netty.util.internal.PlatformDependent -
> Platform: Windows
> 16:50:40.196 [main] DEBUG io.netty.util.internal.PlatformDependent0 -
> -Dio.netty.noUnsafe: false
> 16:50:40.196 [main] DEBUG io.netty.util.internal.PlatformDependent0 - Java
> version: 8
> 16:50:40.198 [main] DEBUG io.netty.util.internal.PlatformDependent0 -
> sun.misc.Unsafe.theUnsafe: available
> 16:50:40.199 [main] DEBUG io.netty.util.internal.PlatformDependent0 -
> sun.misc.Unsafe.copyMemory: available
> 16:50:40.199 [main] DEBUG io.netty.util.internal.PlatformDependent0 -
> java.nio.Buffer.address: available
> 16:50:40.200 [main] DEBUG io.netty.util.internal.PlatformDependent0 - direct
> buffer constructor: available
> 16:50:40.201 [main] DEBUG io.netty.util.internal.PlatformDependent0 -
> java.nio.Bits.unaligned: available, true
> 16:50:40.201 [main] DEBUG io.netty.util.internal.PlatformDependent0 -
> jdk.internal.misc.Unsafe.allocateUninitializedArray(int): unavailable prior
> to Java9
> 16:50:40.201 [main] DEBUG io.netty.util.internal.PlatformDependent0 -
> java.nio.DirectByteBuffer.<init>(long, int): available
> 16:50:40.201 [main] DEBUG io.netty.util.internal.PlatformDependent -
> sun.misc.Unsafe: available
> 16:50:40.202 [main] DEBUG io.netty.util.internal.PlatformDependent -
> -Dio.netty.tmpdir: C:\Users\fp\AppData\Local\Temp (java.io.tmpdir)
> 16:50:40.202 [main] DEBUG io.netty.util.internal.PlatformDependent -
> -Dio.netty.bitMode: 64 (sun.arch.data.model)
> 16:50:40.203 [main] DEBUG io.netty.util.internal.PlatformDependent -
> -Dio.netty.maxDirectMemory: 3784310784 bytes
> 16:50:40.203 [main] DEBUG io.netty.util.internal.PlatformDependent -
> -Dio.netty.uninitializedArrayAllocationThreshold: -1
> 16:50:40.204 [main] DEBUG io.netty.util.internal.CleanerJava6 -
> java.nio.ByteBuffer.cleaner(): available
> 16:50:40.204 [main] DEBUG io.netty.util.internal.PlatformDependent -
> -Dio.netty.noPreferDirect: false
> 16:50:40.205 [main] DEBUG io.netty.util.ResourceLeakDetectorFactory - Loaded
> default ResourceLeakDetector: io.netty.util.ResourceLeakDetector@136432db
> 16:50:40.214 [main] DEBUG io.netty.util.internal.PlatformDependent -
> org.jctools-core.MpscChunkedArrayQueue: available
> 16:50:40.302 [main] INFO org.apache.plc4x.java.s7.connection.S7PlcConnection
> - Setting up S7 Connection with: host-name 192.168.3.166, rack 0, slot 3,
> pdu-size 1024, max-amq-caller 8, max-amq-callee 8
> 16:50:40.316 [main] DEBUG io.netty.channel.MultithreadEventLoopGroup -
> -Dio.netty.eventLoopThreads: 16
> 16:50:40.337 [main] DEBUG io.netty.util.internal.InternalThreadLocalMap -
> -Dio.netty.threadLocalMap.stringBuilder.initialSize: 1024
> 16:50:40.337 [main] DEBUG io.netty.util.internal.InternalThreadLocalMap -
> -Dio.netty.threadLocalMap.stringBuilder.maxSize: 4096
> 16:50:40.342 [main] DEBUG io.netty.channel.nio.NioEventLoop -
> -Dio.netty.noKeySetOptimization: false
> 16:50:40.342 [main] DEBUG io.netty.channel.nio.NioEventLoop -
> -Dio.netty.selectorAutoRebuildThreshold: 512
> 16:50:40.394 [main] DEBUG io.netty.channel.DefaultChannelId -
> -Dio.netty.processId: 7020 (auto-detected)
> 16:50:40.396 [main] DEBUG io.netty.util.NetUtil - -Djava.net.preferIPv4Stack:
> false
> 16:50:40.396 [main] DEBUG io.netty.util.NetUtil -
> -Djava.net.preferIPv6Addresses: false
> 16:50:41.030 [main] DEBUG io.netty.util.NetUtil - Loopback interface: lo
> (Software Loopback Interface 1, 127.0.0.1)
> 16:50:41.031 [main] DEBUG io.netty.util.NetUtil - Failed to get SOMAXCONN
> from sysctl and file \proc\sys\net\core\somaxconn. Default: 200
> 16:50:41.690 [main] DEBUG io.netty.channel.DefaultChannelId -
> -Dio.netty.machineId: 00:50:b6:ff:fe:26:ae:1f (auto-detected)
> 16:50:41.722 [main] DEBUG io.netty.buffer.PooledByteBufAllocator -
> -Dio.netty.allocator.numHeapArenas: 16
> 16:50:41.723 [main] DEBUG io.netty.buffer.PooledByteBufAllocator -
> -Dio.netty.allocator.numDirectArenas: 16
> 16:50:41.723 [main] DEBUG io.netty.buffer.PooledByteBufAllocator -
> -Dio.netty.allocator.pageSize: 8192
> 16:50:41.723 [main] DEBUG io.netty.buffer.PooledByteBufAllocator -
> -Dio.netty.allocator.maxOrder: 11
> 16:50:41.723 [main] DEBUG io.netty.buffer.PooledByteBufAllocator -
> -Dio.netty.allocator.chunkSize: 16777216
> 16:50:41.723 [main] DEBUG io.netty.buffer.PooledByteBufAllocator -
> -Dio.netty.allocator.tinyCacheSize: 512
> 16:50:41.723 [main] DEBUG io.netty.buffer.PooledByteBufAllocator -
> -Dio.netty.allocator.smallCacheSize: 256
> 16:50:41.723 [main] DEBUG io.netty.buffer.PooledByteBufAllocator -
> -Dio.netty.allocator.normalCacheSize: 64
> 16:50:41.723 [main] DEBUG io.netty.buffer.PooledByteBufAllocator -
> -Dio.netty.allocator.maxCachedBufferCapacity: 32768
> 16:50:41.723 [main] DEBUG io.netty.buffer.PooledByteBufAllocator -
> -Dio.netty.allocator.cacheTrimInterval: 8192
> 16:50:41.723 [main] DEBUG io.netty.buffer.PooledByteBufAllocator -
> -Dio.netty.allocator.cacheTrimIntervalMillis: 0
> 16:50:41.723 [main] DEBUG io.netty.buffer.PooledByteBufAllocator -
> -Dio.netty.allocator.useCacheForAllThreads: true
> 16:50:41.723 [main] DEBUG io.netty.buffer.PooledByteBufAllocator -
> -Dio.netty.allocator.maxCachedByteBuffersPerChunk: 1023
> 16:50:41.729 [main] DEBUG io.netty.buffer.ByteBufUtil -
> -Dio.netty.allocator.type: pooled
> 16:50:41.729 [main] DEBUG io.netty.buffer.ByteBufUtil -
> -Dio.netty.threadLocalDirectBufferSize: 0
> 16:50:41.729 [main] DEBUG io.netty.buffer.ByteBufUtil -
> -Dio.netty.maxThreadLocalCharBufferSize: 16384
> 16:50:41.777 [nioEventLoopGroup-2-1] DEBUG
> org.apache.plc4x.java.isotp.protocol.IsoTPProtocol - ISO Transport Protocol
> Sending Connection Request
> 16:50:41.786 [nioEventLoopGroup-2-1] DEBUG io.netty.buffer.AbstractByteBuf -
> -Dio.netty.buffer.checkAccessible: true
> 16:50:41.786 [nioEventLoopGroup-2-1] DEBUG io.netty.buffer.AbstractByteBuf -
> -Dio.netty.buffer.checkBounds: true
> 16:50:41.786 [nioEventLoopGroup-2-1] DEBUG
> io.netty.util.ResourceLeakDetectorFactory - Loaded default
> ResourceLeakDetector: io.netty.util.ResourceLeakDetector@1e25211c
> 16:50:41.793 [nioEventLoopGroup-2-1] DEBUG io.netty.util.Recycler -
> -Dio.netty.recycler.maxCapacityPerThread: 4096
> 16:50:41.793 [nioEventLoopGroup-2-1] DEBUG io.netty.util.Recycler -
> -Dio.netty.recycler.maxSharedCapacityFactor: 2
> 16:50:41.793 [nioEventLoopGroup-2-1] DEBUG io.netty.util.Recycler -
> -Dio.netty.recycler.linkCapacity: 16
> 16:50:41.793 [nioEventLoopGroup-2-1] DEBUG io.netty.util.Recycler -
> -Dio.netty.recycler.ratio: 8
> 16:50:41.798 [nioEventLoopGroup-2-1] DEBUG
> org.apache.plc4x.java.isoontcp.protocol.IsoOnTcpProtocol - ISO on TCP Message
> sent
> 16:50:41.805 [nioEventLoopGroup-2-1] WARN
> io.netty.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.
> java.io.IOException: Eine vorhandene Verbindung wurde vom Remotehost
> geschlossen
> at sun.nio.ch.SocketDispatcher.read0(Native Method)
> at sun.nio.ch.SocketDispatcher.read(SocketDispatcher.java:43)
> at sun.nio.ch.IOUtil.readIntoNativeBuffer(IOUtil.java:223)
> at sun.nio.ch.IOUtil.read(IOUtil.java:192)
> at sun.nio.ch.SocketChannelImpl.read(SocketChannelImpl.java:380)
> at io.netty.buffer.PooledByteBuf.setBytes(PooledByteBuf.java:247)
> at io.netty.buffer.AbstractByteBuf.writeBytes(AbstractByteBuf.java:1140)
> at
> io.netty.channel.socket.nio.NioSocketChannel.doReadBytes(NioSocketChannel.java:347)
> at
> io.netty.channel.nio.AbstractNioByteChannel$NioByteUnsafe.read(AbstractNioByteChannel.java:148)
> at
> io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:697)
> at
> io.netty.channel.nio.NioEventLoop.processSelectedKeysOptimized(NioEventLoop.java:632)
> at
> io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:549)
> at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:511)
> at
> io.netty.util.concurrent.SingleThreadEventExecutor$5.run(SingleThreadEventExecutor.java:918)
> at
> io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74)
> at
> io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
> at java.lang.Thread.run(Thread.java:745)
> org.apache.plc4x.java.api.exceptions.PlcConnectionException:
> java.util.concurrent.ExecutionException:
> org.apache.plc4x.java.api.exceptions.PlcIoException: Connection terminated by
> remote
> at
> org.apache.plc4x.java.base.connection.NettyPlcConnection.connect(NettyPlcConnection.java:88)
> at
> org.apache.plc4x.java.PlcDriverManager.getConnection(PlcDriverManager.java:73)
> at test.ReadValue.main(ReadValue.java:21)
> Caused by: java.util.concurrent.ExecutionException:
> org.apache.plc4x.java.api.exceptions.PlcIoException: Connection terminated by
> remote
> at
> java.util.concurrent.CompletableFuture.reportGet(CompletableFuture.java:357)
> at
> java.util.concurrent.CompletableFuture.get(CompletableFuture.java:1895)
> at
> org.apache.plc4x.java.base.connection.NettyPlcConnection.connect(NettyPlcConnection.java:79)
> ... 2 more
> Caused by: org.apache.plc4x.java.api.exceptions.PlcIoException: Connection
> terminated by remote
> at
> org.apache.plc4x.java.base.connection.NettyPlcConnection.lambda$connect$0(NettyPlcConnection.java:70)
> at
> io.netty.util.concurrent.DefaultPromise.notifyListener0(DefaultPromise.java:500)
> at
> io.netty.util.concurrent.DefaultPromise.notifyListenersNow(DefaultPromise.java:474)
> at
> io.netty.util.concurrent.DefaultPromise.notifyListeners(DefaultPromise.java:413)
> at
> io.netty.util.concurrent.DefaultPromise.setValue0(DefaultPromise.java:538)
> at
> io.netty.util.concurrent.DefaultPromise.setSuccess0(DefaultPromise.java:527)
> at
> io.netty.util.concurrent.DefaultPromise.trySuccess(DefaultPromise.java:98)
> at
> io.netty.channel.DefaultChannelPromise.trySuccess(DefaultChannelPromise.java:84)
> at
> io.netty.channel.AbstractChannel$CloseFuture.setClosed(AbstractChannel.java:1156)
> at
> io.netty.channel.AbstractChannel$AbstractUnsafe.doClose0(AbstractChannel.java:758)
> at
> io.netty.channel.AbstractChannel$AbstractUnsafe.close(AbstractChannel.java:734)
> at
> io.netty.channel.AbstractChannel$AbstractUnsafe.close(AbstractChannel.java:605)
> at
> io.netty.channel.nio.AbstractNioByteChannel$NioByteUnsafe.closeOnRead(AbstractNioByteChannel.java:105)
> at
> io.netty.channel.nio.AbstractNioByteChannel$NioByteUnsafe.handleReadException(AbstractNioByteChannel.java:127)
> at
> io.netty.channel.nio.AbstractNioByteChannel$NioByteUnsafe.read(AbstractNioByteChannel.java:174)
> at
> io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:697)
> at
> io.netty.channel.nio.NioEventLoop.processSelectedKeysOptimized(NioEventLoop.java:632)
> at
> io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:549)
> at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:511)
> at
> io.netty.util.concurrent.SingleThreadEventExecutor$5.run(SingleThreadEventExecutor.java:918)
> at
> io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74)
> at
> io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
> at java.lang.Thread.run(Thread.java:745)
> {noformat}
--
This message was sent by Atlassian Jira
(v8.3.4#803005)
