You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@plc4x.apache.org by "Florian Probst (Jira)" <ji...@apache.org> on 2020/02/27 07:27:00 UTC
[jira] [Updated] (PLC4X-179) Initial connection terminated from PLC
[ https://issues.apache.org/jira/browse/PLC4X-179?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Florian Probst updated PLC4X-179:
---------------------------------
Environment: Windows 10, jdk1.8.0_91-win64, jdk11.0.6.10 (was: Windows 10, jdk1.8.0_91-win64)
> 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
> Priority: Major
> 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)