You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@plc4x.apache.org by "Christofer Dutz (Jira)" <ji...@apache.org> on 2020/02/27 07:42:00 UTC

[jira] [Commented] (PLC4X-179) Initial connection terminated from PLC

    [ https://issues.apache.org/jira/browse/PLC4X-179?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=17046260#comment-17046260 ] 

Christofer Dutz commented on PLC4X-179:
---------------------------------------

Hi Florian,

as I expected ... the driver version you are using is using the rack and slot for the local tsap id setting and not the remote. The generated packages looks absolutely ok, however the S7 probably "gets the call" and hangs up as soon as it notices you want to talk to slot 1 and it knows it's slot 3.

Could you please try the 0.6.0-SNAPSHOT version? I think we swapped what rack and slot are being used for in that version.

Or I would even suggest to try the latest develop version 0.7.0-SNAPSHOT ... here the connection string would need to be changed to:

s7://192.168.3.166?remote-slot=3

 

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