Florian Probst created PLC4X-179:
------------------------------------
Summary: 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
Reporter: Florian Probst
Attachments: 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)
