You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@plc4x.apache.org by Stefano Bossi <st...@gmail.com> on 2020/11/26 22:16:09 UTC
Test on plc4x-pool2
Hi Julian,
I have tried to integrate in my code the new pool library you wrote but
without success, I have probably did something wrong.
I am started trying to work with the HelloPlc4x
||PlcDriverManager manager = new PlcDriverManager(); PlcDriverManager
cached = new CachedDriverManager(connectionString, () -> { try { return
manager.getConnection(connectionString); } catch (PlcConnectionException
e) { e.printStackTrace(); } return null; }); PlcConnection plcConnection
= cached.getConnection(connectionString); // Check if this connection
support reading of data. if (!plcConnection.getMetadata().canRead()) {
logger.error("This connection doesn't support reading."); return; }| |
|integrate When the code reach the line |||plcConnection.getMetadata().canRead()||
|integrate| an exception is rised:
bash-3.2$ /Users/fox/.jenv/versions/openjdk64-13.0.2/bin/java -agentlib:jdwp=transport=dt_socket,server=n,suspend=y,address=localhost:51806 -ea -Dfile.encoding=UTF-8 @/var/folders/p1/lb5grfpn3tncxdtrptqq9fw40000gp/T/cp_dkqa6x1i5h7yfdha7mxc6sn5h.argfile it.fox.datapicker.HelloPlc4x
2020-11-26 23:09:30,677 main DEBUG Apache Log4j Core 2.14.0 initializing configuration XmlConfiguration[location=/Users/fox/Documents/workspace/2020-06-30 - HelloPlc4x/bin/main/log4j2.xml]
2020-11-26 23:09:30,684 main DEBUG Installed 1 script engine
Warning: Nashorn engine is planned to be removed from a future JDK release
2020-11-26 23:09:30,885 main DEBUG Oracle Nashorn version: 13.0.2, language: ECMAScript, threading: Not Thread Safe, compile: true, names: [nashorn, Nashorn, js, JS, JavaScript, javascript, ECMAScript, ecmascript], factory class: jdk.nashorn.api.scripting.NashornScriptEngineFactory
2020-11-26 23:09:30,885 main DEBUG PluginManager 'Core' found 122 plugins
2020-11-26 23:09:30,885 main DEBUG PluginManager 'Level' found 0 plugins
2020-11-26 23:09:30,889 main DEBUG PluginManager 'Lookup' found 16 plugins
2020-11-26 23:09:30,890 main DEBUG Building Plugin[name=layout, class=org.apache.logging.log4j.core.layout.PatternLayout].
2020-11-26 23:09:30,899 main DEBUG PluginManager 'TypeConverter' found 26 plugins
2020-11-26 23:09:30,911 main DEBUG PatternLayout$Builder(pattern="[%-5level] %d{HH:mm:ss.SSS} %logger{36}.%M() - %msg%n", PatternSelector=null, Configuration(/Users/fox/Documents/workspace/2020-06-30 - HelloPlc4x/bin/main/log4j2.xml), Replace=null, charset="null", alwaysWriteExceptions="null", disableAnsi="null", noConsoleNoAnsi="null", header="null", footer="null")
2020-11-26 23:09:30,911 main DEBUG PluginManager 'Converter' found 44 plugins
2020-11-26 23:09:30,912 main DEBUG Building Plugin[name=appender, class=org.apache.logging.log4j.core.appender.ConsoleAppender].
2020-11-26 23:09:30,917 main DEBUG ConsoleAppender$Builder(target="SYSTEM_OUT", follow="null", direct="null", bufferedIo="null", bufferSize="null", immediateFlush="null", ignoreExceptions="null", PatternLayout([%-5level] %d{HH:mm:ss.SSS} %logger{36}.%M() - %msg%n), name="Console", Configuration(/Users/fox/Documents/workspace/2020-06-30 - HelloPlc4x/bin/main/log4j2.xml), Filter=null, ={})
2020-11-26 23:09:30,919 main DEBUG Starting OutputStreamManager SYSTEM_OUT.false.false
2020-11-26 23:09:30,919 main DEBUG Building Plugin[name=appenders, class=org.apache.logging.log4j.core.config.AppendersPlugin].
2020-11-26 23:09:30,922 main DEBUG createAppenders(={Console})
2020-11-26 23:09:30,922 main DEBUG Building Plugin[name=AppenderRef, class=org.apache.logging.log4j.core.config.AppenderRef].
2020-11-26 23:09:30,926 main DEBUG createAppenderRef(ref="Console", level="TRACE", Filter=null)
2020-11-26 23:09:30,926 main DEBUG Building Plugin[name=root, class=org.apache.logging.log4j.core.config.LoggerConfig$RootLogger].
2020-11-26 23:09:30,927 main DEBUG createLogger(additivity="false", level="DEBUG", includeLocation="null", ={Console}, ={}, Configuration(/Users/fox/Documents/workspace/2020-06-30 - HelloPlc4x/bin/main/log4j2.xml), Filter=null)
2020-11-26 23:09:30,929 main DEBUG Building Plugin[name=loggers, class=org.apache.logging.log4j.core.config.LoggersPlugin].
2020-11-26 23:09:30,930 main DEBUG createLoggers(={root})
2020-11-26 23:09:30,931 main DEBUG Configuration XmlConfiguration[location=/Users/fox/Documents/workspace/2020-06-30 - HelloPlc4x/bin/main/log4j2.xml] initialized
2020-11-26 23:09:30,932 main DEBUG Starting configuration XmlConfiguration[location=/Users/fox/Documents/workspace/2020-06-30 - HelloPlc4x/bin/main/log4j2.xml]
2020-11-26 23:09:30,932 main DEBUG Started configuration XmlConfiguration[location=/Users/fox/Documents/workspace/2020-06-30 - HelloPlc4x/bin/main/log4j2.xml] OK.
2020-11-26 23:09:30,933 main DEBUG Shutting down OutputStreamManager SYSTEM_OUT.false.false-1
2020-11-26 23:09:30,933 main DEBUG OutputStream closed
2020-11-26 23:09:30,933 main DEBUG Shut down OutputStreamManager SYSTEM_OUT.false.false-1, all resources released: true
2020-11-26 23:09:30,934 main DEBUG Appender DefaultConsole-1 stopped with status true
2020-11-26 23:09:30,934 main DEBUG Stopped org.apache.logging.log4j.core.config.DefaultConfiguration@6cc4c815 OK
2020-11-26 23:09:30,989 main DEBUG Registering MBean org.apache.logging.log4j2:type=55054057
2020-11-26 23:09:30,992 main DEBUG Registering MBean org.apache.logging.log4j2:type=55054057,component=StatusLogger
2020-11-26 23:09:30,993 main DEBUG Registering MBean org.apache.logging.log4j2:type=55054057,component=ContextSelector
2020-11-26 23:09:30,994 main DEBUG Registering MBean org.apache.logging.log4j2:type=55054057,component=Loggers,name=
2020-11-26 23:09:30,995 main DEBUG Registering MBean org.apache.logging.log4j2:type=55054057,component=Appenders,name=Console
2020-11-26 23:09:30,997 main DEBUG org.apache.logging.log4j.core.util.SystemClock supports precise timestamps.
2020-11-26 23:09:30,997 main DEBUG Reconfiguration complete for context[name=55054057] at URI /Users/fox/Documents/workspace/2020-06-30 - HelloPlc4x/bin/main/log4j2.xml (org.apache.logging.log4j.core.LoggerContext@2ca26d77) with optional ClassLoader: null
2020-11-26 23:09:30,997 main DEBUG Shutdown hook enabled. Registering a new one.
2020-11-26 23:09:30,998 main DEBUG LoggerContext[name=55054057, org.apache.logging.log4j.core.LoggerContext@2ca26d77] started OK.
[INFO ] 23:09:31.011 it.fox.datapicker.HelloPlc4x.main() - start
[INFO ] 23:09:31.014 org.apache.plc4x.java.PlcDriverManager.<init>() - Instantiating new PLC Driver Manager with class loader jdk.internal.loader.ClassLoaders$AppClassLoader@55054057
[INFO ] 23:09:31.014 org.apache.plc4x.java.PlcDriverManager.<init>() - Registering available drivers...
[INFO ] 23:09:31.018 org.apache.plc4x.java.PlcDriverManager.<init>() - Registering driver for Protocol s7 (Siemens S7 (Basic))
[INFO ] 23:09:31.020 org.apache.plc4x.java.PlcDriverManager.<init>() - Registering driver for Protocol mock (Mock Protocol Implementation)
[INFO ] 23:09:31.021 org.apache.plc4x.java.PlcDriverManager.<init>() - Instantiating new PLC Driver Manager with class loader jdk.internal.loader.ClassLoaders$AppClassLoader@55054057
[INFO ] 23:09:31.022 org.apache.plc4x.java.PlcDriverManager.<init>() - Registering available drivers...
[INFO ] 23:09:31.023 org.apache.plc4x.java.PlcDriverManager.<init>() - Registering driver for Protocol s7 (Siemens S7 (Basic))
[INFO ] 23:09:31.023 org.apache.plc4x.java.PlcDriverManager.<init>() - Registering driver for Protocol mock (Mock Protocol Implementation)
[INFO ] 23:09:31.025 org.pragmaticindustries.cockpit.plc.pool2.CachedDriverManager.<init>() - Creating new cached Connection for url s7://192.168.1.192 with timeout 1000 ms
[DEBUG] 23:09:31.025 org.pragmaticindustries.cockpit.plc.pool2.CachedDriverManager.getConnection_() - Connection was requested but no connection is active, trying to establish a Connection
[DEBUG] 23:09:31.026 org.pragmaticindustries.cockpit.plc.pool2.CachedDriverManager.lambda$getConnection_$0() - Starting to establish Connection
[DEBUG] 23:09:31.097 io.netty.util.internal.logging.InternalLoggerFactory.newDefaultFactory() - Using SLF4J as the default logging framework
[DEBUG] 23:09:31.101 io.netty.util.ResourceLeakDetector.<clinit>() - -Dio.netty.leakDetection.level: simple
[DEBUG] 23:09:31.101 io.netty.util.ResourceLeakDetector.<clinit>() - -Dio.netty.leakDetection.targetRecords: 4
[DEBUG] 23:09:31.105 io.netty.util.ResourceLeakDetectorFactory.newResourceLeakDetector() - Loaded default ResourceLeakDetector: io.netty.util.ResourceLeakDetector@16dc2e81
[DEBUG] 23:09:31.117 io.netty.util.internal.PlatformDependent.isOsx0() - Platform: MacOS
[DEBUG] 23:09:31.118 io.netty.util.internal.PlatformDependent0.explicitNoUnsafeCause0() - -Dio.netty.noUnsafe: false
[DEBUG] 23:09:31.118 io.netty.util.internal.PlatformDependent0.javaVersion0() - Java version: 13
[DEBUG] 23:09:31.120 io.netty.util.internal.PlatformDependent0.<clinit>() - sun.misc.Unsafe.theUnsafe: available
[DEBUG] 23:09:31.120 io.netty.util.internal.PlatformDependent0.<clinit>() - sun.misc.Unsafe.copyMemory: available
[DEBUG] 23:09:31.121 io.netty.util.internal.PlatformDependent0.<clinit>() - java.nio.Buffer.address: available
[DEBUG] 23:09:31.122 io.netty.util.internal.PlatformDependent0.<clinit>() - direct buffer constructor: unavailable
java.lang.UnsupportedOperationException: Reflective setAccessible(true) disabled
at io.netty.util.internal.ReflectionUtil.trySetAccessible(ReflectionUtil.java:31) ~[netty-common-4.1.47.Final.jar:4.1.47.Final]
at io.netty.util.internal.PlatformDependent0$4.run(PlatformDependent0.java:225) ~[netty-common-4.1.47.Final.jar:4.1.47.Final]
at java.security.AccessController.doPrivileged(AccessController.java:312) ~[?:?]
at io.netty.util.internal.PlatformDependent0.<clinit>(PlatformDependent0.java:219) ~[netty-common-4.1.47.Final.jar:4.1.47.Final]
at io.netty.util.internal.PlatformDependent.isAndroid(PlatformDependent.java:289) ~[netty-common-4.1.47.Final.jar:4.1.47.Final]
at io.netty.util.internal.PlatformDependent.<clinit>(PlatformDependent.java:92) ~[netty-common-4.1.47.Final.jar:4.1.47.Final]
at io.netty.util.HashedWheelTimer.<init>(HashedWheelTimer.java:109) ~[netty-common-4.1.47.Final.jar:4.1.47.Final]
at io.netty.util.HashedWheelTimer.<init>(HashedWheelTimer.java:218) ~[netty-common-4.1.47.Final.jar:4.1.47.Final]
at io.netty.util.HashedWheelTimer.<init>(HashedWheelTimer.java:197) ~[netty-common-4.1.47.Final.jar:4.1.47.Final]
at io.netty.util.HashedWheelTimer.<init>(HashedWheelTimer.java:179) ~[netty-common-4.1.47.Final.jar:4.1.47.Final]
at io.netty.util.HashedWheelTimer.<init>(HashedWheelTimer.java:163) ~[netty-common-4.1.47.Final.jar:4.1.47.Final]
at io.netty.util.HashedWheelTimer.<init>(HashedWheelTimer.java:122) ~[netty-common-4.1.47.Final.jar:4.1.47.Final]
at org.apache.plc4x.java.spi.connection.DefaultNettyPlcConnection.<clinit>(DefaultNettyPlcConnection.java:49) ~[plc4j-spi-0.8.0-SNAPSHOT.jar:0.8.0-SNAPSHOT]
at org.apache.plc4x.java.spi.connection.GeneratedDriverBase.getConnection(GeneratedDriverBase.java:138) ~[plc4j-spi-0.8.0-SNAPSHOT.jar:0.8.0-SNAPSHOT]
at org.apache.plc4x.java.PlcDriverManager.getConnection(PlcDriverManager.java:73) ~[plc4j-api-0.8.0-SNAPSHOT.jar:0.8.0-SNAPSHOT]
at it.fox.datapicker.HelloPlc4x.lambda$0(HelloPlc4x.java:83) ~[main/:?]
at org.pragmaticindustries.cockpit.plc.pool2.CachedDriverManager.lambda$getConnection_$0(CachedDriverManager.java:195) ~[pool2-1.0.0-SNAPSHOT.jar:?]
at java.util.concurrent.CompletableFuture$AsyncRun.run(CompletableFuture.java:1807) [?:?]
at java.util.concurrent.CompletableFuture$AsyncRun.exec(CompletableFuture.java:1799) [?:?]
at java.util.concurrent.ForkJoinTask.doExec(ForkJoinTask.java:290) [?:?]
at java.util.concurrent.ForkJoinPool$WorkQueue.topLevelExec(ForkJoinPool.java:1016) [?:?]
at java.util.concurrent.ForkJoinPool.scan(ForkJoinPool.java:1665) [?:?]
at java.util.concurrent.ForkJoinPool.runWorker(ForkJoinPool.java:1598) [?:?]
at java.util.concurrent.ForkJoinWorkerThread.run(ForkJoinWorkerThread.java:177) [?:?]
[DEBUG] 23:09:31.133 io.netty.util.internal.PlatformDependent0.<clinit>() - java.nio.Bits.unaligned: available, true
[DEBUG] 23:09:31.135 io.netty.util.internal.PlatformDependent0.<clinit>() - jdk.internal.misc.Unsafe.allocateUninitializedArray(int): unavailable
java.lang.IllegalAccessException: class io.netty.util.internal.PlatformDependent0$6 cannot access class jdk.internal.misc.Unsafe (in module java.base) because module java.base does not export jdk.internal.misc to unnamed module @16ce8dcf
at jdk.internal.reflect.Reflection.newIllegalAccessException(Reflection.java:376) ~[?:?]
at java.lang.reflect.AccessibleObject.checkAccess(AccessibleObject.java:642) ~[?:?]
at java.lang.reflect.Method.invoke(Method.java:559) ~[?:?]
at io.netty.util.internal.PlatformDependent0$6.run(PlatformDependent0.java:335) ~[netty-common-4.1.47.Final.jar:4.1.47.Final]
at java.security.AccessController.doPrivileged(AccessController.java:312) ~[?:?]
at io.netty.util.internal.PlatformDependent0.<clinit>(PlatformDependent0.java:326) ~[netty-common-4.1.47.Final.jar:4.1.47.Final]
at io.netty.util.internal.PlatformDependent.isAndroid(PlatformDependent.java:289) ~[netty-common-4.1.47.Final.jar:4.1.47.Final]
at io.netty.util.internal.PlatformDependent.<clinit>(PlatformDependent.java:92) ~[netty-common-4.1.47.Final.jar:4.1.47.Final]
at io.netty.util.HashedWheelTimer.<init>(HashedWheelTimer.java:109) ~[netty-common-4.1.47.Final.jar:4.1.47.Final]
at io.netty.util.HashedWheelTimer.<init>(HashedWheelTimer.java:218) ~[netty-common-4.1.47.Final.jar:4.1.47.Final]
at io.netty.util.HashedWheelTimer.<init>(HashedWheelTimer.java:197) ~[netty-common-4.1.47.Final.jar:4.1.47.Final]
at io.netty.util.HashedWheelTimer.<init>(HashedWheelTimer.java:179) ~[netty-common-4.1.47.Final.jar:4.1.47.Final]
at io.netty.util.HashedWheelTimer.<init>(HashedWheelTimer.java:163) ~[netty-common-4.1.47.Final.jar:4.1.47.Final]
at io.netty.util.HashedWheelTimer.<init>(HashedWheelTimer.java:122) ~[netty-common-4.1.47.Final.jar:4.1.47.Final]
at org.apache.plc4x.java.spi.connection.DefaultNettyPlcConnection.<clinit>(DefaultNettyPlcConnection.java:49) ~[plc4j-spi-0.8.0-SNAPSHOT.jar:0.8.0-SNAPSHOT]
at org.apache.plc4x.java.spi.connection.GeneratedDriverBase.getConnection(GeneratedDriverBase.java:138) ~[plc4j-spi-0.8.0-SNAPSHOT.jar:0.8.0-SNAPSHOT]
at org.apache.plc4x.java.PlcDriverManager.getConnection(PlcDriverManager.java:73) ~[plc4j-api-0.8.0-SNAPSHOT.jar:0.8.0-SNAPSHOT]
at it.fox.datapicker.HelloPlc4x.lambda$0(HelloPlc4x.java:83) ~[main/:?]
at org.pragmaticindustries.cockpit.plc.pool2.CachedDriverManager.lambda$getConnection_$0(CachedDriverManager.java:195) ~[pool2-1.0.0-SNAPSHOT.jar:?]
at java.util.concurrent.CompletableFuture$AsyncRun.run(CompletableFuture.java:1807) [?:?]
at java.util.concurrent.CompletableFuture$AsyncRun.exec(CompletableFuture.java:1799) [?:?]
at java.util.concurrent.ForkJoinTask.doExec(ForkJoinTask.java:290) [?:?]
at java.util.concurrent.ForkJoinPool$WorkQueue.topLevelExec(ForkJoinPool.java:1016) [?:?]
at java.util.concurrent.ForkJoinPool.scan(ForkJoinPool.java:1665) [?:?]
at java.util.concurrent.ForkJoinPool.runWorker(ForkJoinPool.java:1598) [?:?]
at java.util.concurrent.ForkJoinWorkerThread.run(ForkJoinWorkerThread.java:177) [?:?]
[DEBUG] 23:09:31.136 io.netty.util.internal.PlatformDependent0.<clinit>() - java.nio.DirectByteBuffer.<init>(long, int): unavailable
[DEBUG] 23:09:31.136 io.netty.util.internal.PlatformDependent.unsafeUnavailabilityCause0() - sun.misc.Unsafe: available
[DEBUG] 23:09:31.137 io.netty.util.internal.PlatformDependent.maxDirectMemory0() - maxDirectMemory: 4294967296 bytes (maybe)
[DEBUG] 23:09:31.137 io.netty.util.internal.PlatformDependent.tmpdir0() - -Dio.netty.tmpdir: /var/folders/p1/lb5grfpn3tncxdtrptqq9fw40000gp/T (java.io.tmpdir)
[DEBUG] 23:09:31.138 io.netty.util.internal.PlatformDependent.bitMode0() - -Dio.netty.bitMode: 64 (sun.arch.data.model)
[DEBUG] 23:09:31.138 io.netty.util.internal.PlatformDependent.<clinit>() - -Dio.netty.maxDirectMemory: -1 bytes
[DEBUG] 23:09:31.139 io.netty.util.internal.PlatformDependent.<clinit>() - -Dio.netty.uninitializedArrayAllocationThreshold: -1
[DEBUG] 23:09:31.140 io.netty.util.internal.CleanerJava9.<clinit>() - java.nio.ByteBuffer.cleaner(): available
[DEBUG] 23:09:31.140 io.netty.util.internal.PlatformDependent.<clinit>() - -Dio.netty.noPreferDirect: false
[DEBUG] 23:09:31.155 io.netty.util.internal.PlatformDependent.<clinit>() - org.jctools-core.MpscChunkedArrayQueue: available
[DEBUG] 23:09:31.179 io.netty.channel.MultithreadEventLoopGroup.<clinit>() - -Dio.netty.eventLoopThreads: 16
[DEBUG] 23:09:31.191 io.netty.util.internal.InternalThreadLocalMap.<clinit>() - -Dio.netty.threadLocalMap.stringBuilder.initialSize: 1024
[DEBUG] 23:09:31.191 io.netty.util.internal.InternalThreadLocalMap.<clinit>() - -Dio.netty.threadLocalMap.stringBuilder.maxSize: 4096
[DEBUG] 23:09:31.196 io.netty.channel.nio.NioEventLoop.<clinit>() - -Dio.netty.noKeySetOptimization: false
[DEBUG] 23:09:31.196 io.netty.channel.nio.NioEventLoop.<clinit>() - -Dio.netty.selectorAutoRebuildThreshold: 512
[INFO ] 23:09:31.208 org.apache.plc4x.java.transport.tcp.TcpChannelFactory.configureBootstrap() - Configuring Bootstrap with Configuration{local-rack=1, local-slot=1, remote-rack=0, remot-slot=0, pduSize=1024, maxAmqCaller=8, maxAmqCallee=8, controllerType='null'}
[DEBUG] 23:09:31.227 io.netty.channel.DefaultChannelId.<clinit>() - -Dio.netty.processId: 84362 (auto-detected)
[DEBUG] 23:09:31.230 io.netty.util.NetUtil.<clinit>() - -Djava.net.preferIPv4Stack: false
[DEBUG] 23:09:31.230 io.netty.util.NetUtil.<clinit>() - -Djava.net.preferIPv6Addresses: false
[DEBUG] 23:09:31.235 io.netty.util.NetUtil.<clinit>() - Loopback interface: lo0 (lo0, 0:0:0:0:0:0:0:1%lo0)
[DEBUG] 23:09:31.236 io.netty.util.NetUtil.run() - Failed to get SOMAXCONN from sysctl and file /proc/sys/net/core/somaxconn. Default: 128
[DEBUG] 23:09:31.239 io.netty.channel.DefaultChannelId.<clinit>() - -Dio.netty.machineId: 00:e0:4c:ff:fe:68:01:3f (auto-detected)
[DEBUG] 23:09:31.280 io.netty.buffer.PooledByteBufAllocator.<clinit>() - -Dio.netty.allocator.numHeapArenas: 16
[DEBUG] 23:09:31.280 io.netty.buffer.PooledByteBufAllocator.<clinit>() - -Dio.netty.allocator.numDirectArenas: 16
[DEBUG] 23:09:31.280 io.netty.buffer.PooledByteBufAllocator.<clinit>() - -Dio.netty.allocator.pageSize: 8192
[DEBUG] 23:09:31.280 io.netty.buffer.PooledByteBufAllocator.<clinit>() - -Dio.netty.allocator.maxOrder: 11
[DEBUG] 23:09:31.281 io.netty.buffer.PooledByteBufAllocator.<clinit>() - -Dio.netty.allocator.chunkSize: 16777216
[DEBUG] 23:09:31.281 io.netty.buffer.PooledByteBufAllocator.<clinit>() - -Dio.netty.allocator.tinyCacheSize: 512
[DEBUG] 23:09:31.281 io.netty.buffer.PooledByteBufAllocator.<clinit>() - -Dio.netty.allocator.smallCacheSize: 256
[DEBUG] 23:09:31.281 io.netty.buffer.PooledByteBufAllocator.<clinit>() - -Dio.netty.allocator.normalCacheSize: 64
[DEBUG] 23:09:31.281 io.netty.buffer.PooledByteBufAllocator.<clinit>() - -Dio.netty.allocator.maxCachedBufferCapacity: 32768
[DEBUG] 23:09:31.282 io.netty.buffer.PooledByteBufAllocator.<clinit>() - -Dio.netty.allocator.cacheTrimInterval: 8192
[DEBUG] 23:09:31.282 io.netty.buffer.PooledByteBufAllocator.<clinit>() - -Dio.netty.allocator.cacheTrimIntervalMillis: 0
[DEBUG] 23:09:31.282 io.netty.buffer.PooledByteBufAllocator.<clinit>() - -Dio.netty.allocator.useCacheForAllThreads: true
[DEBUG] 23:09:31.282 io.netty.buffer.PooledByteBufAllocator.<clinit>() - -Dio.netty.allocator.maxCachedByteBuffersPerChunk: 1023
[DEBUG] 23:09:31.291 io.netty.buffer.ByteBufUtil.<clinit>() - -Dio.netty.allocator.type: pooled
[DEBUG] 23:09:31.291 io.netty.buffer.ByteBufUtil.<clinit>() - -Dio.netty.threadLocalDirectBufferSize: 0
[DEBUG] 23:09:31.291 io.netty.buffer.ByteBufUtil.<clinit>() - -Dio.netty.maxThreadLocalCharBufferSize: 16384
[INFO ] 23:09:31.425 org.apache.plc4x.java.s7.readwrite.protocol.S7ProtocolLogic.onConnect() - S7 Driver running in ACTIVE mode.
[DEBUG] 23:09:31.426 org.apache.plc4x.java.s7.readwrite.protocol.S7ProtocolLogic.onConnect() - Sending COTP Connection Request
[DEBUG] 23:09:31.446 org.apache.plc4x.java.spi.Plc4xNettyWrapper.encode() - Forwarding request to plc TPKTPacket[payload=COTPPacketConnectionRequest[parameters={COTPParameterCalledTsap[tsapId=256],COTPParameterCallingTsap[tsapId=785],COTPParameterTpduSize[tpduSize=SIZE_1024]},payload=<null>,destinationReference=0,sourceReference=15,protocolClass=CLASS_0]]
[DEBUG] 23:09:31.450 io.netty.util.Recycler.<clinit>() - -Dio.netty.recycler.maxCapacityPerThread: 4096
[DEBUG] 23:09:31.450 io.netty.util.Recycler.<clinit>() - -Dio.netty.recycler.maxSharedCapacityFactor: 2
[DEBUG] 23:09:31.450 io.netty.util.Recycler.<clinit>() - -Dio.netty.recycler.linkCapacity: 16
[DEBUG] 23:09:31.450 io.netty.util.Recycler.<clinit>() - -Dio.netty.recycler.ratio: 8
[DEBUG] 23:09:31.457 io.netty.buffer.AbstractByteBuf.<clinit>() - -Dio.netty.buffer.checkAccessible: true
[DEBUG] 23:09:31.457 io.netty.buffer.AbstractByteBuf.<clinit>() - -Dio.netty.buffer.checkBounds: true
[DEBUG] 23:09:31.457 io.netty.util.ResourceLeakDetectorFactory.newResourceLeakDetector() - Loaded default ResourceLeakDetector: io.netty.util.ResourceLeakDetector@466425b5
[DEBUG] 23:09:31.480 org.apache.plc4x.java.spi.GeneratedDriverByteToMessageCodec.encode() - Sending bytes to PLC for message TPKTPacket[payload=COTPPacketConnectionRequest[parameters={COTPParameterCalledTsap[tsapId=256],COTPParameterCallingTsap[tsapId=785],COTPParameterTpduSize[tpduSize=SIZE_1024]},payload=<null>,destinationReference=0,sourceReference=15,protocolClass=CLASS_0]] as data 0300001611e00000000f00c2020100c1020311c0010a
[DEBUG] 23:09:31.601 org.apache.plc4x.java.s7.readwrite.protocol.S7ProtocolLogic.lambda$onConnect$9() - Got COTP Connection Response
[DEBUG] 23:09:31.601 org.apache.plc4x.java.s7.readwrite.protocol.S7ProtocolLogic.lambda$onConnect$9() - Sending S7 Connection Request
[DEBUG] 23:09:31.603 org.apache.plc4x.java.spi.Plc4xNettyWrapper.encode() - Forwarding request to plc TPKTPacket[payload=COTPPacketData[parameters=<null>,payload=S7MessageRequest[tpduReference=0,parameter=S7ParameterSetupCommunication[maxAmqCaller=8,maxAmqCallee=8,pduLength=1008],payload=<null>],eot=true,tpduRef=1]]
[DEBUG] 23:09:31.606 org.apache.plc4x.java.spi.GeneratedDriverByteToMessageCodec.encode() - Sending bytes to PLC for message TPKTPacket[payload=COTPPacketData[parameters=<null>,payload=S7MessageRequest[tpduReference=0,parameter=S7ParameterSetupCommunication[maxAmqCaller=8,maxAmqCallee=8,pduLength=1008],payload=<null>],eot=true,tpduRef=1]] as data 0300001902f08132010000000000080000f0000008000803f0
[DEBUG] 23:09:31.654 org.apache.plc4x.java.s7.readwrite.protocol.S7ProtocolLogic.lambda$onConnect$8() - Got S7 Connection Response
[DEBUG] 23:09:31.654 org.apache.plc4x.java.s7.readwrite.protocol.S7ProtocolLogic.lambda$onConnect$8() - Sending S7 Identification Request
[DEBUG] 23:09:31.660 org.apache.plc4x.java.spi.Plc4xNettyWrapper.encode() - Forwarding request to plc TPKTPacket[payload=COTPPacketData[parameters=<null>,payload=S7MessageUserData[tpduReference=1,parameter=S7ParameterUserData[items={S7ParameterUserDataItemCPUFunctions[method=17,cpuFunctionType=4,cpuFunctionGroup=4,cpuSubfunction=1,sequenceNumber=0,dataUnitReferenceNumber=<null>,lastDataUnit=<null>,errorCode=<null>]}],payload=S7PayloadUserData[items={S7PayloadUserDataItemCpuFunctionReadSzlRequest[returnCode=OK,transportSize=OCTET_STRING,szlId=SzlId[typeClass=CPU,sublistExtract=0,sublistList=MODULE_IDENTIFICATION],szlIndex=0]}]],eot=true,tpduRef=2]]
[DEBUG] 23:09:31.664 org.apache.plc4x.java.spi.GeneratedDriverByteToMessageCodec.encode() - Sending bytes to PLC for message TPKTPacket[payload=COTPPacketData[parameters=<null>,payload=S7MessageUserData[tpduReference=1,parameter=S7ParameterUserData[items={S7ParameterUserDataItemCPUFunctions[method=17,cpuFunctionType=4,cpuFunctionGroup=4,cpuSubfunction=1,sequenceNumber=0,dataUnitReferenceNumber=<null>,lastDataUnit=<null>,errorCode=<null>]}],payload=S7PayloadUserData[items={S7PayloadUserDataItemCpuFunctionReadSzlRequest[returnCode=OK,transportSize=OCTET_STRING,szlId=SzlId[typeClass=CPU,sublistExtract=0,sublistList=MODULE_IDENTIFICATION],szlIndex=0]}]],eot=true,tpduRef=2]] as data 0300002102f082320700000001000800080001120411440100ff09000400110000
[DEBUG] 23:09:31.715 org.apache.plc4x.java.s7.readwrite.protocol.S7ProtocolLogic.lambda$onConnect$7() - Got S7 Identification Response
[DEBUG] 23:09:31.716 org.pragmaticindustries.cockpit.plc.pool2.CachedDriverManager.lambda$getConnection_$0() - Connection successfully established
[DEBUG] 23:09:31.716 org.pragmaticindustries.cockpit.plc.pool2.CachedDriverManager.checkQueue() - Connection is available, checking if someone is waiting in the queue...
[DEBUG] 23:09:31.716 org.pragmaticindustries.cockpit.plc.pool2.CachedDriverManager.getConnection_() - Connection was requested and is available, thus, returning Chached Connection for usage
java.lang.UnsupportedOperationException
at org.pragmaticindustries.cockpit.plc.pool2.CachedPlcConnection.getMetadata(CachedPlcConnection.java:106)
at it.fox.datapicker.HelloPlc4x.main(HelloPlc4x.java:91)
2020-11-26 23:09:31,720 pool-1-thread-1 DEBUG Stopping LoggerContext[name=55054057, org.apache.logging.log4j.core.LoggerContext@2ca26d77]
2020-11-26 23:09:31,720 pool-1-thread-1 DEBUG Stopping LoggerContext[name=55054057, org.apache.logging.log4j.core.LoggerContext@2ca26d77]...
2020-11-26 23:09:31,723 pool-1-thread-1 DEBUG Shutting down OutputStreamManager SYSTEM_OUT.false.false
2020-11-26 23:09:31,724 pool-1-thread-1 DEBUG OutputStream closed
2020-11-26 23:09:31,724 pool-1-thread-1 DEBUG Shut down OutputStreamManager SYSTEM_OUT.false.false, all resources released: true
2020-11-26 23:09:31,724 pool-1-thread-1 DEBUG Appender Console stopped with status true
2020-11-26 23:09:31,724 pool-1-thread-1 DEBUG Stopped XmlConfiguration[location=/Users/fox/Documents/workspace/2020-06-30 - HelloPlc4x/bin/main/log4j2.xml] OK
2020-11-26 23:09:31,724 pool-1-thread-1 DEBUG Stopped LoggerContext[name=55054057, org.apache.logging.log4j.core.LoggerContext@2ca26d77] with status true
Did you spot some trouble ?
Regards,
Stefano
||||
AW: AW: Test on plc4x-pool2
Posted by Julian Feinauer <j....@pragmaticminds.de>.
Hi,
first, thanks for reporting.
As discussed in Slack we try to fix the issue and I think I already pushed a fix.
So just for the list to notice : )
Julian
Von: Stefano Bossi <st...@gmail.com>
Datum: Freitag, 27. November 2020 um 09:26
An: dev@plc4x.apache.org <de...@plc4x.apache.org>
Betreff: Re: AW: Test on plc4x-pool2
ok,
l'et's wait Julian, who is probably doing his father work :-D
Anyway, Netty is really hard to fine tune!
Regards,
S.
On 27/11/2020 08:52, Christofer Dutz wrote:
Hi Stefano,
I really wonder how often I will end up looking up this stupid java.lang.UnsupportedOperationException …
I have to admit that for me this is one of the most annoying things with Netty :-/
But seeing the actual error is coming from the pool, I guess Julian should probably help you with this, I doubt this is something I can help with.
Chris
Von: Stefano Bossi <st...@gmail.com>
Datum: Donnerstag, 26. November 2020 um 23:16
An: dev@plc4x.apache.org<ma...@plc4x.apache.org> <de...@plc4x.apache.org>
Betreff: Test on plc4x-pool2
Hi Julian,
I have tried to integrate in my code the new pool library you wrote but without success, I have probably did something wrong.
I am started trying to work with the HelloPlc4x
PlcDriverManager manager = new PlcDriverManager();
PlcDriverManager cached = new CachedDriverManager(connectionString, () -> {
try {
return manager.getConnection(connectionString);
} catch (PlcConnectionException e) {
e.printStackTrace();
}
return null;
});
PlcConnection plcConnection = cached.getConnection(connectionString);
// Check if this connection support reading of data.
if (!plcConnection.getMetadata().canRead()) {
logger.error("This connection doesn't support reading.");
return;
}
integrate When the code reach the line plcConnection.getMetadata().canRead()
integrate an exception is rised:
bash-3.2$ /Users/fox/.jenv/versions/openjdk64-13.0.2/bin/java -agentlib:jdwp=transport=dt_socket,server=n,suspend=y,address=localhost:51806 -ea -Dfile.encoding=UTF-8 @/var/folders/p1/lb5grfpn3tncxdtrptqq9fw40000gp/T/cp_dkqa6x1i5h7yfdha7mxc6sn5h.argfile it.fox.datapicker.HelloPlc4x
2020-11-26 23:09:30,677 main DEBUG Apache Log4j Core 2.14.0 initializing configuration XmlConfiguration[location=/Users/fox/Documents/workspace/2020-06-30 - HelloPlc4x/bin/main/log4j2.xml]
2020-11-26 23:09:30,684 main DEBUG Installed 1 script engine
Warning: Nashorn engine is planned to be removed from a future JDK release
2020-11-26 23:09:30,885 main DEBUG Oracle Nashorn version: 13.0.2, language: ECMAScript, threading: Not Thread Safe, compile: true, names: [nashorn, Nashorn, js, JS, JavaScript, javascript, ECMAScript, ecmascript], factory class: jdk.nashorn.api.scripting.NashornScriptEngineFactory
2020-11-26 23:09:30,885 main DEBUG PluginManager 'Core' found 122 plugins
2020-11-26 23:09:30,885 main DEBUG PluginManager 'Level' found 0 plugins
2020-11-26 23:09:30,889 main DEBUG PluginManager 'Lookup' found 16 plugins
2020-11-26 23:09:30,890 main DEBUG Building Plugin[name=layout, class=org.apache.logging.log4j.core.layout.PatternLayout].
2020-11-26 23:09:30,899 main DEBUG PluginManager 'TypeConverter' found 26 plugins
2020-11-26 23:09:30,911 main DEBUG PatternLayout$Builder(pattern="[%-5level] %d{HH:mm:ss.SSS} %logger{36}.%M() - %msg%n", PatternSelector=null, Configuration(/Users/fox/Documents/workspace/2020-06-30 - HelloPlc4x/bin/main/log4j2.xml), Replace=null, charset="null", alwaysWriteExceptions="null", disableAnsi="null", noConsoleNoAnsi="null", header="null", footer="null")
2020-11-26 23:09:30,911 main DEBUG PluginManager 'Converter' found 44 plugins
2020-11-26 23:09:30,912 main DEBUG Building Plugin[name=appender, class=org.apache.logging.log4j.core.appender.ConsoleAppender].
2020-11-26 23:09:30,917 main DEBUG ConsoleAppender$Builder(target="SYSTEM_OUT", follow="null", direct="null", bufferedIo="null", bufferSize="null", immediateFlush="null", ignoreExceptions="null", PatternLayout([%-5level] %d{HH:mm:ss.SSS} %logger{36}.%M() - %msg%n), name="Console", Configuration(/Users/fox/Documents/workspace/2020-06-30 - HelloPlc4x/bin/main/log4j2.xml), Filter=null, ={})
2020-11-26 23:09:30,919 main DEBUG Starting OutputStreamManager SYSTEM_OUT.false.false
2020-11-26 23:09:30,919 main DEBUG Building Plugin[name=appenders, class=org.apache.logging.log4j.core.config.AppendersPlugin].
2020-11-26 23:09:30,922 main DEBUG createAppenders(={Console})
2020-11-26 23:09:30,922 main DEBUG Building Plugin[name=AppenderRef, class=org.apache.logging.log4j.core.config.AppenderRef].
2020-11-26 23:09:30,926 main DEBUG createAppenderRef(ref="Console", level="TRACE", Filter=null)
2020-11-26 23:09:30,926 main DEBUG Building Plugin[name=root, class=org.apache.logging.log4j.core.config.LoggerConfig$RootLogger].
2020-11-26 23:09:30,927 main DEBUG createLogger(additivity="false", level="DEBUG", includeLocation="null", ={Console}, ={}, Configuration(/Users/fox/Documents/workspace/2020-06-30 - HelloPlc4x/bin/main/log4j2.xml), Filter=null)
2020-11-26 23:09:30,929 main DEBUG Building Plugin[name=loggers, class=org.apache.logging.log4j.core.config.LoggersPlugin].
2020-11-26 23:09:30,930 main DEBUG createLoggers(={root})
2020-11-26 23:09:30,931 main DEBUG Configuration XmlConfiguration[location=/Users/fox/Documents/workspace/2020-06-30 - HelloPlc4x/bin/main/log4j2.xml] initialized
2020-11-26 23:09:30,932 main DEBUG Starting configuration XmlConfiguration[location=/Users/fox/Documents/workspace/2020-06-30 - HelloPlc4x/bin/main/log4j2.xml]
2020-11-26 23:09:30,932 main DEBUG Started configuration XmlConfiguration[location=/Users/fox/Documents/workspace/2020-06-30 - HelloPlc4x/bin/main/log4j2.xml] OK.
2020-11-26 23:09:30,933 main DEBUG Shutting down OutputStreamManager SYSTEM_OUT.false.false-1
2020-11-26 23:09:30,933 main DEBUG OutputStream closed
2020-11-26 23:09:30,933 main DEBUG Shut down OutputStreamManager SYSTEM_OUT.false.false-1, all resources released: true
2020-11-26 23:09:30,934 main DEBUG Appender DefaultConsole-1 stopped with status true
2020-11-26 23:09:30,934 main DEBUG Stopped org.apache.logging.log4j.core.config.DefaultConfiguration@6cc4c815 OK
2020-11-26 23:09:30,989 main DEBUG Registering MBean org.apache.logging.log4j2:type=55054057
2020-11-26 23:09:30,992 main DEBUG Registering MBean org.apache.logging.log4j2:type=55054057,component=StatusLogger
2020-11-26 23:09:30,993 main DEBUG Registering MBean org.apache.logging.log4j2:type=55054057,component=ContextSelector
2020-11-26 23:09:30,994 main DEBUG Registering MBean org.apache.logging.log4j2:type=55054057,component=Loggers,name=
2020-11-26 23:09:30,995 main DEBUG Registering MBean org.apache.logging.log4j2:type=55054057,component=Appenders,name=Console
2020-11-26 23:09:30,997 main DEBUG org.apache.logging.log4j.core.util.SystemClock supports precise timestamps.
2020-11-26 23:09:30,997 main DEBUG Reconfiguration complete for context[name=55054057] at URI /Users/fox/Documents/workspace/2020-06-30 - HelloPlc4x/bin/main/log4j2.xml (org.apache.logging.log4j.core.LoggerContext@2ca26d77) with optional ClassLoader: null
2020-11-26 23:09:30,997 main DEBUG Shutdown hook enabled. Registering a new one.
2020-11-26 23:09:30,998 main DEBUG LoggerContext[name=55054057, org.apache.logging.log4j.core.LoggerContext@2ca26d77] started OK.
[INFO ] 23:09:31.011 it.fox.datapicker.HelloPlc4x.main() - start
[INFO ] 23:09:31.014 org.apache.plc4x.java.PlcDriverManager.<init>() - Instantiating new PLC Driver Manager with class loader jdk.internal.loader.ClassLoaders$AppClassLoader@55054057
[INFO ] 23:09:31.014 org.apache.plc4x.java.PlcDriverManager.<init>() - Registering available drivers...
[INFO ] 23:09:31.018 org.apache.plc4x.java.PlcDriverManager.<init>() - Registering driver for Protocol s7 (Siemens S7 (Basic))
[INFO ] 23:09:31.020 org.apache.plc4x.java.PlcDriverManager.<init>() - Registering driver for Protocol mock (Mock Protocol Implementation)
[INFO ] 23:09:31.021 org.apache.plc4x.java.PlcDriverManager.<init>() - Instantiating new PLC Driver Manager with class loader jdk.internal.loader.ClassLoaders$AppClassLoader@55054057
[INFO ] 23:09:31.022 org.apache.plc4x.java.PlcDriverManager.<init>() - Registering available drivers...
[INFO ] 23:09:31.023 org.apache.plc4x.java.PlcDriverManager.<init>() - Registering driver for Protocol s7 (Siemens S7 (Basic))
[INFO ] 23:09:31.023 org.apache.plc4x.java.PlcDriverManager.<init>() - Registering driver for Protocol mock (Mock Protocol Implementation)
[INFO ] 23:09:31.025 org.pragmaticindustries.cockpit.plc.pool2.CachedDriverManager.<init>() - Creating new cached Connection for url s7://192.168.1.192 with timeout 1000 ms
[DEBUG] 23:09:31.025 org.pragmaticindustries.cockpit.plc.pool2.CachedDriverManager.getConnection_() - Connection was requested but no connection is active, trying to establish a Connection
[DEBUG] 23:09:31.026 org.pragmaticindustries.cockpit.plc.pool2.CachedDriverManager.lambda$getConnection_$0() - Starting to establish Connection
[DEBUG] 23:09:31.097 io.netty.util.internal.logging.InternalLoggerFactory.newDefaultFactory() - Using SLF4J as the default logging framework
[DEBUG] 23:09:31.101 io.netty.util.ResourceLeakDetector.<clinit>() - -Dio.netty.leakDetection.level: simple
[DEBUG] 23:09:31.101 io.netty.util.ResourceLeakDetector.<clinit>() - -Dio.netty.leakDetection.targetRecords: 4
[DEBUG] 23:09:31.105 io.netty.util.ResourceLeakDetectorFactory.newResourceLeakDetector() - Loaded default ResourceLeakDetector: io.netty.util.ResourceLeakDetector@16dc2e81
[DEBUG] 23:09:31.117 io.netty.util.internal.PlatformDependent.isOsx0() - Platform: MacOS
[DEBUG] 23:09:31.118 io.netty.util.internal.PlatformDependent0.explicitNoUnsafeCause0() - -Dio.netty.noUnsafe: false
[DEBUG] 23:09:31.118 io.netty.util.internal.PlatformDependent0.javaVersion0() - Java version: 13
[DEBUG] 23:09:31.120 io.netty.util.internal.PlatformDependent0.<clinit>() - sun.misc.Unsafe.theUnsafe: available
[DEBUG] 23:09:31.120 io.netty.util.internal.PlatformDependent0.<clinit>() - sun.misc.Unsafe.copyMemory: available
[DEBUG] 23:09:31.121 io.netty.util.internal.PlatformDependent0.<clinit>() - java.nio.Buffer.address: available
[DEBUG] 23:09:31.122 io.netty.util.internal.PlatformDependent0.<clinit>() - direct buffer constructor: unavailable
java.lang.UnsupportedOperationException: Reflective setAccessible(true) disabled
at io.netty.util.internal.ReflectionUtil.trySetAccessible(ReflectionUtil.java:31) ~[netty-common-4.1.47.Final.jar:4.1.47.Final]
at io.netty.util.internal.PlatformDependent0$4.run(PlatformDependent0.java:225) ~[netty-common-4.1.47.Final.jar:4.1.47.Final]
at java.security.AccessController.doPrivileged(AccessController.java:312) ~[?:?]
at io.netty.util.internal.PlatformDependent0.<clinit>(PlatformDependent0.java:219) ~[netty-common-4.1.47.Final.jar:4.1.47.Final]
at io.netty.util.internal.PlatformDependent.isAndroid(PlatformDependent.java:289) ~[netty-common-4.1.47.Final.jar:4.1.47.Final]
at io.netty.util.internal.PlatformDependent.<clinit>(PlatformDependent.java:92) ~[netty-common-4.1.47.Final.jar:4.1.47.Final]
at io.netty.util.HashedWheelTimer.<init>(HashedWheelTimer.java:109) ~[netty-common-4.1.47.Final.jar:4.1.47.Final]
at io.netty.util.HashedWheelTimer.<init>(HashedWheelTimer.java:218) ~[netty-common-4.1.47.Final.jar:4.1.47.Final]
at io.netty.util.HashedWheelTimer.<init>(HashedWheelTimer.java:197) ~[netty-common-4.1.47.Final.jar:4.1.47.Final]
at io.netty.util.HashedWheelTimer.<init>(HashedWheelTimer.java:179) ~[netty-common-4.1.47.Final.jar:4.1.47.Final]
at io.netty.util.HashedWheelTimer.<init>(HashedWheelTimer.java:163) ~[netty-common-4.1.47.Final.jar:4.1.47.Final]
at io.netty.util.HashedWheelTimer.<init>(HashedWheelTimer.java:122) ~[netty-common-4.1.47.Final.jar:4.1.47.Final]
at org.apache.plc4x.java.spi.connection.DefaultNettyPlcConnection.<clinit>(DefaultNettyPlcConnection.java:49) ~[plc4j-spi-0.8.0-SNAPSHOT.jar:0.8.0-SNAPSHOT]
at org.apache.plc4x.java.spi.connection.GeneratedDriverBase.getConnection(GeneratedDriverBase.java:138) ~[plc4j-spi-0.8.0-SNAPSHOT.jar:0.8.0-SNAPSHOT]
at org.apache.plc4x.java.PlcDriverManager.getConnection(PlcDriverManager.java:73) ~[plc4j-api-0.8.0-SNAPSHOT.jar:0.8.0-SNAPSHOT]
at it.fox.datapicker.HelloPlc4x.lambda$0(HelloPlc4x.java:83) ~[main/:?]
at org.pragmaticindustries.cockpit.plc.pool2.CachedDriverManager.lambda$getConnection_$0(CachedDriverManager.java:195) ~[pool2-1.0.0-SNAPSHOT.jar:?]
at java.util.concurrent.CompletableFuture$AsyncRun.run(CompletableFuture.java:1807) [?:?]
at java.util.concurrent.CompletableFuture$AsyncRun.exec(CompletableFuture.java:1799) [?:?]
at java.util.concurrent.ForkJoinTask.doExec(ForkJoinTask.java:290) [?:?]
at java.util.concurrent.ForkJoinPool$WorkQueue.topLevelExec(ForkJoinPool.java:1016) [?:?]
at java.util.concurrent.ForkJoinPool.scan(ForkJoinPool.java:1665) [?:?]
at java.util.concurrent.ForkJoinPool.runWorker(ForkJoinPool.java:1598) [?:?]
at java.util.concurrent.ForkJoinWorkerThread.run(ForkJoinWorkerThread.java:177) [?:?]
[DEBUG] 23:09:31.133 io.netty.util.internal.PlatformDependent0.<clinit>() - java.nio.Bits.unaligned: available, true
[DEBUG] 23:09:31.135 io.netty.util.internal.PlatformDependent0.<clinit>() - jdk.internal.misc.Unsafe.allocateUninitializedArray(int): unavailable
java.lang.IllegalAccessException: class io.netty.util.internal.PlatformDependent0$6 cannot access class jdk.internal.misc.Unsafe (in module java.base) because module java.base does not export jdk.internal.misc to unnamed module @16ce8dcf
at jdk.internal.reflect.Reflection.newIllegalAccessException(Reflection.java:376) ~[?:?]
at java.lang.reflect.AccessibleObject.checkAccess(AccessibleObject.java:642) ~[?:?]
at java.lang.reflect.Method.invoke(Method.java:559) ~[?:?]
at io.netty.util.internal.PlatformDependent0$6.run(PlatformDependent0.java:335) ~[netty-common-4.1.47.Final.jar:4.1.47.Final]
at java.security.AccessController.doPrivileged(AccessController.java:312) ~[?:?]
at io.netty.util.internal.PlatformDependent0.<clinit>(PlatformDependent0.java:326) ~[netty-common-4.1.47.Final.jar:4.1.47.Final]
at io.netty.util.internal.PlatformDependent.isAndroid(PlatformDependent.java:289) ~[netty-common-4.1.47.Final.jar:4.1.47.Final]
at io.netty.util.internal.PlatformDependent.<clinit>(PlatformDependent.java:92) ~[netty-common-4.1.47.Final.jar:4.1.47.Final]
at io.netty.util.HashedWheelTimer.<init>(HashedWheelTimer.java:109) ~[netty-common-4.1.47.Final.jar:4.1.47.Final]
at io.netty.util.HashedWheelTimer.<init>(HashedWheelTimer.java:218) ~[netty-common-4.1.47.Final.jar:4.1.47.Final]
at io.netty.util.HashedWheelTimer.<init>(HashedWheelTimer.java:197) ~[netty-common-4.1.47.Final.jar:4.1.47.Final]
at io.netty.util.HashedWheelTimer.<init>(HashedWheelTimer.java:179) ~[netty-common-4.1.47.Final.jar:4.1.47.Final]
at io.netty.util.HashedWheelTimer.<init>(HashedWheelTimer.java:163) ~[netty-common-4.1.47.Final.jar:4.1.47.Final]
at io.netty.util.HashedWheelTimer.<init>(HashedWheelTimer.java:122) ~[netty-common-4.1.47.Final.jar:4.1.47.Final]
at org.apache.plc4x.java.spi.connection.DefaultNettyPlcConnection.<clinit>(DefaultNettyPlcConnection.java:49) ~[plc4j-spi-0.8.0-SNAPSHOT.jar:0.8.0-SNAPSHOT]
at org.apache.plc4x.java.spi.connection.GeneratedDriverBase.getConnection(GeneratedDriverBase.java:138) ~[plc4j-spi-0.8.0-SNAPSHOT.jar:0.8.0-SNAPSHOT]
at org.apache.plc4x.java.PlcDriverManager.getConnection(PlcDriverManager.java:73) ~[plc4j-api-0.8.0-SNAPSHOT.jar:0.8.0-SNAPSHOT]
at it.fox.datapicker.HelloPlc4x.lambda$0(HelloPlc4x.java:83) ~[main/:?]
at org.pragmaticindustries.cockpit.plc.pool2.CachedDriverManager.lambda$getConnection_$0(CachedDriverManager.java:195) ~[pool2-1.0.0-SNAPSHOT.jar:?]
at java.util.concurrent.CompletableFuture$AsyncRun.run(CompletableFuture.java:1807) [?:?]
at java.util.concurrent.CompletableFuture$AsyncRun.exec(CompletableFuture.java:1799) [?:?]
at java.util.concurrent.ForkJoinTask.doExec(ForkJoinTask.java:290) [?:?]
at java.util.concurrent.ForkJoinPool$WorkQueue.topLevelExec(ForkJoinPool.java:1016) [?:?]
at java.util.concurrent.ForkJoinPool.scan(ForkJoinPool.java:1665) [?:?]
at java.util.concurrent.ForkJoinPool.runWorker(ForkJoinPool.java:1598) [?:?]
at java.util.concurrent.ForkJoinWorkerThread.run(ForkJoinWorkerThread.java:177) [?:?]
[DEBUG] 23:09:31.136 io.netty.util.internal.PlatformDependent0.<clinit>() - java.nio.DirectByteBuffer.<init>(long, int): unavailable
[DEBUG] 23:09:31.136 io.netty.util.internal.PlatformDependent.unsafeUnavailabilityCause0() - sun.misc.Unsafe: available
[DEBUG] 23:09:31.137 io.netty.util.internal.PlatformDependent.maxDirectMemory0() - maxDirectMemory: 4294967296 bytes (maybe)
[DEBUG] 23:09:31.137 io.netty.util.internal.PlatformDependent.tmpdir0() - -Dio.netty.tmpdir: /var/folders/p1/lb5grfpn3tncxdtrptqq9fw40000gp/T (java.io.tmpdir)
[DEBUG] 23:09:31.138 io.netty.util.internal.PlatformDependent.bitMode0() - -Dio.netty.bitMode: 64 (sun.arch.data.model)
[DEBUG] 23:09:31.138 io.netty.util.internal.PlatformDependent.<clinit>() - -Dio.netty.maxDirectMemory: -1 bytes
[DEBUG] 23:09:31.139 io.netty.util.internal.PlatformDependent.<clinit>() - -Dio.netty.uninitializedArrayAllocationThreshold: -1
[DEBUG] 23:09:31.140 io.netty.util.internal.CleanerJava9.<clinit>() - java.nio.ByteBuffer.cleaner(): available
[DEBUG] 23:09:31.140 io.netty.util.internal.PlatformDependent.<clinit>() - -Dio.netty.noPreferDirect: false
[DEBUG] 23:09:31.155 io.netty.util.internal.PlatformDependent.<clinit>() - org.jctools-core.MpscChunkedArrayQueue: available
[DEBUG] 23:09:31.179 io.netty.channel.MultithreadEventLoopGroup.<clinit>() - -Dio.netty.eventLoopThreads: 16
[DEBUG] 23:09:31.191 io.netty.util.internal.InternalThreadLocalMap.<clinit>() - -Dio.netty.threadLocalMap.stringBuilder.initialSize: 1024
[DEBUG] 23:09:31.191 io.netty.util.internal.InternalThreadLocalMap.<clinit>() - -Dio.netty.threadLocalMap.stringBuilder.maxSize: 4096
[DEBUG] 23:09:31.196 io.netty.channel.nio.NioEventLoop.<clinit>() - -Dio.netty.noKeySetOptimization: false
[DEBUG] 23:09:31.196 io.netty.channel.nio.NioEventLoop.<clinit>() - -Dio.netty.selectorAutoRebuildThreshold: 512
[INFO ] 23:09:31.208 org.apache.plc4x.java.transport.tcp.TcpChannelFactory.configureBootstrap() - Configuring Bootstrap with Configuration{local-rack=1, local-slot=1, remote-rack=0, remot-slot=0, pduSize=1024, maxAmqCaller=8, maxAmqCallee=8, controllerType='null'}
[DEBUG] 23:09:31.227 io.netty.channel.DefaultChannelId.<clinit>() - -Dio.netty.processId: 84362 (auto-detected)
[DEBUG] 23:09:31.230 io.netty.util.NetUtil.<clinit>() - -Djava.net.preferIPv4Stack: false
[DEBUG] 23:09:31.230 io.netty.util.NetUtil.<clinit>() - -Djava.net.preferIPv6Addresses: false
[DEBUG] 23:09:31.235 io.netty.util.NetUtil.<clinit>() - Loopback interface: lo0 (lo0, 0:0:0:0:0:0:0:1%lo0)
[DEBUG] 23:09:31.236 io.netty.util.NetUtil.run() - Failed to get SOMAXCONN from sysctl and file /proc/sys/net/core/somaxconn. Default: 128
[DEBUG] 23:09:31.239 io.netty.channel.DefaultChannelId.<clinit>() - -Dio.netty.machineId: 00:e0:4c:ff:fe:68:01:3f (auto-detected)
[DEBUG] 23:09:31.280 io.netty.buffer.PooledByteBufAllocator.<clinit>() - -Dio.netty.allocator.numHeapArenas: 16
[DEBUG] 23:09:31.280 io.netty.buffer.PooledByteBufAllocator.<clinit>() - -Dio.netty.allocator.numDirectArenas: 16
[DEBUG] 23:09:31.280 io.netty.buffer.PooledByteBufAllocator.<clinit>() - -Dio.netty.allocator.pageSize: 8192
[DEBUG] 23:09:31.280 io.netty.buffer.PooledByteBufAllocator.<clinit>() - -Dio.netty.allocator.maxOrder: 11
[DEBUG] 23:09:31.281 io.netty.buffer.PooledByteBufAllocator.<clinit>() - -Dio.netty.allocator.chunkSize: 16777216
[DEBUG] 23:09:31.281 io.netty.buffer.PooledByteBufAllocator.<clinit>() - -Dio.netty.allocator.tinyCacheSize: 512
[DEBUG] 23:09:31.281 io.netty.buffer.PooledByteBufAllocator.<clinit>() - -Dio.netty.allocator.smallCacheSize: 256
[DEBUG] 23:09:31.281 io.netty.buffer.PooledByteBufAllocator.<clinit>() - -Dio.netty.allocator.normalCacheSize: 64
[DEBUG] 23:09:31.281 io.netty.buffer.PooledByteBufAllocator.<clinit>() - -Dio.netty.allocator.maxCachedBufferCapacity: 32768
[DEBUG] 23:09:31.282 io.netty.buffer.PooledByteBufAllocator.<clinit>() - -Dio.netty.allocator.cacheTrimInterval: 8192
[DEBUG] 23:09:31.282 io.netty.buffer.PooledByteBufAllocator.<clinit>() - -Dio.netty.allocator.cacheTrimIntervalMillis: 0
[DEBUG] 23:09:31.282 io.netty.buffer.PooledByteBufAllocator.<clinit>() - -Dio.netty.allocator.useCacheForAllThreads: true
[DEBUG] 23:09:31.282 io.netty.buffer.PooledByteBufAllocator.<clinit>() - -Dio.netty.allocator.maxCachedByteBuffersPerChunk: 1023
[DEBUG] 23:09:31.291 io.netty.buffer.ByteBufUtil.<clinit>() - -Dio.netty.allocator.type: pooled
[DEBUG] 23:09:31.291 io.netty.buffer.ByteBufUtil.<clinit>() - -Dio.netty.threadLocalDirectBufferSize: 0
[DEBUG] 23:09:31.291 io.netty.buffer.ByteBufUtil.<clinit>() - -Dio.netty.maxThreadLocalCharBufferSize: 16384
[INFO ] 23:09:31.425 org.apache.plc4x.java.s7.readwrite.protocol.S7ProtocolLogic.onConnect() - S7 Driver running in ACTIVE mode.
[DEBUG] 23:09:31.426 org.apache.plc4x.java.s7.readwrite.protocol.S7ProtocolLogic.onConnect() - Sending COTP Connection Request
[DEBUG] 23:09:31.446 org.apache.plc4x.java.spi.Plc4xNettyWrapper.encode() - Forwarding request to plc TPKTPacket[payload=COTPPacketConnectionRequest[parameters={COTPParameterCalledTsap[tsapId=256],COTPParameterCallingTsap[tsapId=785],COTPParameterTpduSize[tpduSize=SIZE_1024]},payload=<null>,destinationReference=0,sourceReference=15,protocolClass=CLASS_0]]
[DEBUG] 23:09:31.450 io.netty.util.Recycler.<clinit>() - -Dio.netty.recycler.maxCapacityPerThread: 4096
[DEBUG] 23:09:31.450 io.netty.util.Recycler.<clinit>() - -Dio.netty.recycler.maxSharedCapacityFactor: 2
[DEBUG] 23:09:31.450 io.netty.util.Recycler.<clinit>() - -Dio.netty.recycler.linkCapacity: 16
[DEBUG] 23:09:31.450 io.netty.util.Recycler.<clinit>() - -Dio.netty.recycler.ratio: 8
[DEBUG] 23:09:31.457 io.netty.buffer.AbstractByteBuf.<clinit>() - -Dio.netty.buffer.checkAccessible: true
[DEBUG] 23:09:31.457 io.netty.buffer.AbstractByteBuf.<clinit>() - -Dio.netty.buffer.checkBounds: true
[DEBUG] 23:09:31.457 io.netty.util.ResourceLeakDetectorFactory.newResourceLeakDetector() - Loaded default ResourceLeakDetector: io.netty.util.ResourceLeakDetector@466425b5
[DEBUG] 23:09:31.480 org.apache.plc4x.java.spi.GeneratedDriverByteToMessageCodec.encode() - Sending bytes to PLC for message TPKTPacket[payload=COTPPacketConnectionRequest[parameters={COTPParameterCalledTsap[tsapId=256],COTPParameterCallingTsap[tsapId=785],COTPParameterTpduSize[tpduSize=SIZE_1024]},payload=<null>,destinationReference=0,sourceReference=15,protocolClass=CLASS_0]] as data 0300001611e00000000f00c2020100c1020311c0010a
[DEBUG] 23:09:31.601 org.apache.plc4x.java.s7.readwrite.protocol.S7ProtocolLogic.lambda$onConnect$9() - Got COTP Connection Response
[DEBUG] 23:09:31.601 org.apache.plc4x.java.s7.readwrite.protocol.S7ProtocolLogic.lambda$onConnect$9() - Sending S7 Connection Request
[DEBUG] 23:09:31.603 org.apache.plc4x.java.spi.Plc4xNettyWrapper.encode() - Forwarding request to plc TPKTPacket[payload=COTPPacketData[parameters=<null>,payload=S7MessageRequest[tpduReference=0,parameter=S7ParameterSetupCommunication[maxAmqCaller=8,maxAmqCallee=8,pduLength=1008],payload=<null>],eot=true,tpduRef=1]]
[DEBUG] 23:09:31.606 org.apache.plc4x.java.spi.GeneratedDriverByteToMessageCodec.encode() - Sending bytes to PLC for message TPKTPacket[payload=COTPPacketData[parameters=<null>,payload=S7MessageRequest[tpduReference=0,parameter=S7ParameterSetupCommunication[maxAmqCaller=8,maxAmqCallee=8,pduLength=1008],payload=<null>],eot=true,tpduRef=1]] as data 0300001902f08132010000000000080000f0000008000803f0
[DEBUG] 23:09:31.654 org.apache.plc4x.java.s7.readwrite.protocol.S7ProtocolLogic.lambda$onConnect$8() - Got S7 Connection Response
[DEBUG] 23:09:31.654 org.apache.plc4x.java.s7.readwrite.protocol.S7ProtocolLogic.lambda$onConnect$8() - Sending S7 Identification Request
[DEBUG] 23:09:31.660 org.apache.plc4x.java.spi.Plc4xNettyWrapper.encode() - Forwarding request to plc TPKTPacket[payload=COTPPacketData[parameters=<null>,payload=S7MessageUserData[tpduReference=1,parameter=S7ParameterUserData[items={S7ParameterUserDataItemCPUFunctions[method=17,cpuFunctionType=4,cpuFunctionGroup=4,cpuSubfunction=1,sequenceNumber=0,dataUnitReferenceNumber=<null>,lastDataUnit=<null>,errorCode=<null>]}],payload=S7PayloadUserData[items={S7PayloadUserDataItemCpuFunctionReadSzlRequest[returnCode=OK,transportSize=OCTET_STRING,szlId=SzlId[typeClass=CPU,sublistExtract=0,sublistList=MODULE_IDENTIFICATION],szlIndex=0]}]],eot=true,tpduRef=2]]
[DEBUG] 23:09:31.664 org.apache.plc4x.java.spi.GeneratedDriverByteToMessageCodec.encode() - Sending bytes to PLC for message TPKTPacket[payload=COTPPacketData[parameters=<null>,payload=S7MessageUserData[tpduReference=1,parameter=S7ParameterUserData[items={S7ParameterUserDataItemCPUFunctions[method=17,cpuFunctionType=4,cpuFunctionGroup=4,cpuSubfunction=1,sequenceNumber=0,dataUnitReferenceNumber=<null>,lastDataUnit=<null>,errorCode=<null>]}],payload=S7PayloadUserData[items={S7PayloadUserDataItemCpuFunctionReadSzlRequest[returnCode=OK,transportSize=OCTET_STRING,szlId=SzlId[typeClass=CPU,sublistExtract=0,sublistList=MODULE_IDENTIFICATION],szlIndex=0]}]],eot=true,tpduRef=2]] as data 0300002102f082320700000001000800080001120411440100ff09000400110000
[DEBUG] 23:09:31.715 org.apache.plc4x.java.s7.readwrite.protocol.S7ProtocolLogic.lambda$onConnect$7() - Got S7 Identification Response
[DEBUG] 23:09:31.716 org.pragmaticindustries.cockpit.plc.pool2.CachedDriverManager.lambda$getConnection_$0() - Connection successfully established
[DEBUG] 23:09:31.716 org.pragmaticindustries.cockpit.plc.pool2.CachedDriverManager.checkQueue() - Connection is available, checking if someone is waiting in the queue...
[DEBUG] 23:09:31.716 org.pragmaticindustries.cockpit.plc.pool2.CachedDriverManager.getConnection_() - Connection was requested and is available, thus, returning Chached Connection for usage
java.lang.UnsupportedOperationException
at org.pragmaticindustries.cockpit.plc.pool2.CachedPlcConnection.getMetadata(CachedPlcConnection.java:106)
at it.fox.datapicker.HelloPlc4x.main(HelloPlc4x.java:91)
2020-11-26 23:09:31,720 pool-1-thread-1 DEBUG Stopping LoggerContext[name=55054057, org.apache.logging.log4j.core.LoggerContext@2ca26d77]
2020-11-26 23:09:31,720 pool-1-thread-1 DEBUG Stopping LoggerContext[name=55054057, org.apache.logging.log4j.core.LoggerContext@2ca26d77]...
2020-11-26 23:09:31,723 pool-1-thread-1 DEBUG Shutting down OutputStreamManager SYSTEM_OUT.false.false
2020-11-26 23:09:31,724 pool-1-thread-1 DEBUG OutputStream closed
2020-11-26 23:09:31,724 pool-1-thread-1 DEBUG Shut down OutputStreamManager SYSTEM_OUT.false.false, all resources released: true
2020-11-26 23:09:31,724 pool-1-thread-1 DEBUG Appender Console stopped with status true
2020-11-26 23:09:31,724 pool-1-thread-1 DEBUG Stopped XmlConfiguration[location=/Users/fox/Documents/workspace/2020-06-30 - HelloPlc4x/bin/main/log4j2.xml] OK
2020-11-26 23:09:31,724 pool-1-thread-1 DEBUG Stopped LoggerContext[name=55054057, org.apache.logging.log4j.core.LoggerContext@2ca26d77] with status true
Did you spot some trouble ?
Regards,
Stefano
Re: AW: Test on plc4x-pool2
Posted by Stefano Bossi <st...@gmail.com>.
ok,
l'et's wait Julian, who is probably doing his father work :-D
Anyway, Netty is really hard to fine tune!
Regards,
S.
On 27/11/2020 08:52, Christofer Dutz wrote:
> Hi Stefano,
>
> I really wonder how often I will end up looking up this stupid java.lang.UnsupportedOperationException …
> I have to admit that for me this is one of the most annoying things with Netty :-/
>
> But seeing the actual error is coming from the pool, I guess Julian should probably help you with this, I doubt this is something I can help with.
>
> Chris
>
> Von: Stefano Bossi <st...@gmail.com>
> Datum: Donnerstag, 26. November 2020 um 23:16
> An: dev@plc4x.apache.org <de...@plc4x.apache.org>
> Betreff: Test on plc4x-pool2
> Hi Julian,
>
> I have tried to integrate in my code the new pool library you wrote but without success, I have probably did something wrong.
>
> I am started trying to work with the HelloPlc4x
>
>
> PlcDriverManager manager = new PlcDriverManager();
>
> PlcDriverManager cached = new CachedDriverManager(connectionString, () -> {
>
> try {
>
> return manager.getConnection(connectionString);
>
> } catch (PlcConnectionException e) {
>
> e.printStackTrace();
>
> }
>
> return null;
>
> });
>
> PlcConnection plcConnection = cached.getConnection(connectionString);
>
> // Check if this connection support reading of data.
>
> if (!plcConnection.getMetadata().canRead()) {
>
> logger.error("This connection doesn't support reading.");
>
> return;
>
> }
>
>
>
>
>
> integrate When the code reach the line plcConnection.getMetadata().canRead()
>
> integrate an exception is rised:
>
>
>
> bash-3.2$ /Users/fox/.jenv/versions/openjdk64-13.0.2/bin/java -agentlib:jdwp=transport=dt_socket,server=n,suspend=y,address=localhost:51806 -ea -Dfile.encoding=UTF-8 @/var/folders/p1/lb5grfpn3tncxdtrptqq9fw40000gp/T/cp_dkqa6x1i5h7yfdha7mxc6sn5h.argfile it.fox.datapicker.HelloPlc4x
>
> 2020-11-26 23:09:30,677 main DEBUG Apache Log4j Core 2.14.0 initializing configuration XmlConfiguration[location=/Users/fox/Documents/workspace/2020-06-30 - HelloPlc4x/bin/main/log4j2.xml]
>
> 2020-11-26 23:09:30,684 main DEBUG Installed 1 script engine
>
> Warning: Nashorn engine is planned to be removed from a future JDK release
>
> 2020-11-26 23:09:30,885 main DEBUG Oracle Nashorn version: 13.0.2, language: ECMAScript, threading: Not Thread Safe, compile: true, names: [nashorn, Nashorn, js, JS, JavaScript, javascript, ECMAScript, ecmascript], factory class: jdk.nashorn.api.scripting.NashornScriptEngineFactory
>
> 2020-11-26 23:09:30,885 main DEBUG PluginManager 'Core' found 122 plugins
>
> 2020-11-26 23:09:30,885 main DEBUG PluginManager 'Level' found 0 plugins
>
> 2020-11-26 23:09:30,889 main DEBUG PluginManager 'Lookup' found 16 plugins
>
> 2020-11-26 23:09:30,890 main DEBUG Building Plugin[name=layout, class=org.apache.logging.log4j.core.layout.PatternLayout].
>
> 2020-11-26 23:09:30,899 main DEBUG PluginManager 'TypeConverter' found 26 plugins
>
> 2020-11-26 23:09:30,911 main DEBUG PatternLayout$Builder(pattern="[%-5level] %d{HH:mm:ss.SSS} %logger{36}.%M() - %msg%n", PatternSelector=null, Configuration(/Users/fox/Documents/workspace/2020-06-30 - HelloPlc4x/bin/main/log4j2.xml), Replace=null, charset="null", alwaysWriteExceptions="null", disableAnsi="null", noConsoleNoAnsi="null", header="null", footer="null")
>
> 2020-11-26 23:09:30,911 main DEBUG PluginManager 'Converter' found 44 plugins
>
> 2020-11-26 23:09:30,912 main DEBUG Building Plugin[name=appender, class=org.apache.logging.log4j.core.appender.ConsoleAppender].
>
> 2020-11-26 23:09:30,917 main DEBUG ConsoleAppender$Builder(target="SYSTEM_OUT", follow="null", direct="null", bufferedIo="null", bufferSize="null", immediateFlush="null", ignoreExceptions="null", PatternLayout([%-5level] %d{HH:mm:ss.SSS} %logger{36}.%M() - %msg%n), name="Console", Configuration(/Users/fox/Documents/workspace/2020-06-30 - HelloPlc4x/bin/main/log4j2.xml), Filter=null, ={})
>
> 2020-11-26 23:09:30,919 main DEBUG Starting OutputStreamManager SYSTEM_OUT.false.false
>
> 2020-11-26 23:09:30,919 main DEBUG Building Plugin[name=appenders, class=org.apache.logging.log4j.core.config.AppendersPlugin].
>
> 2020-11-26 23:09:30,922 main DEBUG createAppenders(={Console})
>
> 2020-11-26 23:09:30,922 main DEBUG Building Plugin[name=AppenderRef, class=org.apache.logging.log4j.core.config.AppenderRef].
>
> 2020-11-26 23:09:30,926 main DEBUG createAppenderRef(ref="Console", level="TRACE", Filter=null)
>
> 2020-11-26 23:09:30,926 main DEBUG Building Plugin[name=root, class=org.apache.logging.log4j.core.config.LoggerConfig$RootLogger].
>
> 2020-11-26 23:09:30,927 main DEBUG createLogger(additivity="false", level="DEBUG", includeLocation="null", ={Console}, ={}, Configuration(/Users/fox/Documents/workspace/2020-06-30 - HelloPlc4x/bin/main/log4j2.xml), Filter=null)
>
> 2020-11-26 23:09:30,929 main DEBUG Building Plugin[name=loggers, class=org.apache.logging.log4j.core.config.LoggersPlugin].
>
> 2020-11-26 23:09:30,930 main DEBUG createLoggers(={root})
>
> 2020-11-26 23:09:30,931 main DEBUG Configuration XmlConfiguration[location=/Users/fox/Documents/workspace/2020-06-30 - HelloPlc4x/bin/main/log4j2.xml] initialized
>
> 2020-11-26 23:09:30,932 main DEBUG Starting configuration XmlConfiguration[location=/Users/fox/Documents/workspace/2020-06-30 - HelloPlc4x/bin/main/log4j2.xml]
>
> 2020-11-26 23:09:30,932 main DEBUG Started configuration XmlConfiguration[location=/Users/fox/Documents/workspace/2020-06-30 - HelloPlc4x/bin/main/log4j2.xml] OK.
>
> 2020-11-26 23:09:30,933 main DEBUG Shutting down OutputStreamManager SYSTEM_OUT.false.false-1
>
> 2020-11-26 23:09:30,933 main DEBUG OutputStream closed
>
> 2020-11-26 23:09:30,933 main DEBUG Shut down OutputStreamManager SYSTEM_OUT.false.false-1, all resources released: true
>
> 2020-11-26 23:09:30,934 main DEBUG Appender DefaultConsole-1 stopped with status true
>
> 2020-11-26 23:09:30,934 main DEBUG Stopped org.apache.logging.log4j.core.config.DefaultConfiguration@6cc4c815 OK
>
> 2020-11-26 23:09:30,989 main DEBUG Registering MBean org.apache.logging.log4j2:type=55054057
>
> 2020-11-26 23:09:30,992 main DEBUG Registering MBean org.apache.logging.log4j2:type=55054057,component=StatusLogger
>
> 2020-11-26 23:09:30,993 main DEBUG Registering MBean org.apache.logging.log4j2:type=55054057,component=ContextSelector
>
> 2020-11-26 23:09:30,994 main DEBUG Registering MBean org.apache.logging.log4j2:type=55054057,component=Loggers,name=
>
> 2020-11-26 23:09:30,995 main DEBUG Registering MBean org.apache.logging.log4j2:type=55054057,component=Appenders,name=Console
>
> 2020-11-26 23:09:30,997 main DEBUG org.apache.logging.log4j.core.util.SystemClock supports precise timestamps.
>
> 2020-11-26 23:09:30,997 main DEBUG Reconfiguration complete for context[name=55054057] at URI /Users/fox/Documents/workspace/2020-06-30 - HelloPlc4x/bin/main/log4j2.xml (org.apache.logging.log4j.core.LoggerContext@2ca26d77) with optional ClassLoader: null
>
> 2020-11-26 23:09:30,997 main DEBUG Shutdown hook enabled. Registering a new one.
>
> 2020-11-26 23:09:30,998 main DEBUG LoggerContext[name=55054057, org.apache.logging.log4j.core.LoggerContext@2ca26d77] started OK.
>
> [INFO ] 23:09:31.011 it.fox.datapicker.HelloPlc4x.main() - start
>
> [INFO ] 23:09:31.014 org.apache.plc4x.java.PlcDriverManager.<init>() - Instantiating new PLC Driver Manager with class loader jdk.internal.loader.ClassLoaders$AppClassLoader@55054057
>
> [INFO ] 23:09:31.014 org.apache.plc4x.java.PlcDriverManager.<init>() - Registering available drivers...
>
> [INFO ] 23:09:31.018 org.apache.plc4x.java.PlcDriverManager.<init>() - Registering driver for Protocol s7 (Siemens S7 (Basic))
>
> [INFO ] 23:09:31.020 org.apache.plc4x.java.PlcDriverManager.<init>() - Registering driver for Protocol mock (Mock Protocol Implementation)
>
> [INFO ] 23:09:31.021 org.apache.plc4x.java.PlcDriverManager.<init>() - Instantiating new PLC Driver Manager with class loader jdk.internal.loader.ClassLoaders$AppClassLoader@55054057
>
> [INFO ] 23:09:31.022 org.apache.plc4x.java.PlcDriverManager.<init>() - Registering available drivers...
>
> [INFO ] 23:09:31.023 org.apache.plc4x.java.PlcDriverManager.<init>() - Registering driver for Protocol s7 (Siemens S7 (Basic))
>
> [INFO ] 23:09:31.023 org.apache.plc4x.java.PlcDriverManager.<init>() - Registering driver for Protocol mock (Mock Protocol Implementation)
>
> [INFO ] 23:09:31.025 org.pragmaticindustries.cockpit.plc.pool2.CachedDriverManager.<init>() - Creating new cached Connection for url s7://192.168.1.192 with timeout 1000 ms
>
> [DEBUG] 23:09:31.025 org.pragmaticindustries.cockpit.plc.pool2.CachedDriverManager.getConnection_() - Connection was requested but no connection is active, trying to establish a Connection
>
> [DEBUG] 23:09:31.026 org.pragmaticindustries.cockpit.plc.pool2.CachedDriverManager.lambda$getConnection_$0() - Starting to establish Connection
>
> [DEBUG] 23:09:31.097 io.netty.util.internal.logging.InternalLoggerFactory.newDefaultFactory() - Using SLF4J as the default logging framework
>
> [DEBUG] 23:09:31.101 io.netty.util.ResourceLeakDetector.<clinit>() - -Dio.netty.leakDetection.level: simple
>
> [DEBUG] 23:09:31.101 io.netty.util.ResourceLeakDetector.<clinit>() - -Dio.netty.leakDetection.targetRecords: 4
>
> [DEBUG] 23:09:31.105 io.netty.util.ResourceLeakDetectorFactory.newResourceLeakDetector() - Loaded default ResourceLeakDetector: io.netty.util.ResourceLeakDetector@16dc2e81
>
> [DEBUG] 23:09:31.117 io.netty.util.internal.PlatformDependent.isOsx0() - Platform: MacOS
>
> [DEBUG] 23:09:31.118 io.netty.util.internal.PlatformDependent0.explicitNoUnsafeCause0() - -Dio.netty.noUnsafe: false
>
> [DEBUG] 23:09:31.118 io.netty.util.internal.PlatformDependent0.javaVersion0() - Java version: 13
>
> [DEBUG] 23:09:31.120 io.netty.util.internal.PlatformDependent0.<clinit>() - sun.misc.Unsafe.theUnsafe: available
>
> [DEBUG] 23:09:31.120 io.netty.util.internal.PlatformDependent0.<clinit>() - sun.misc.Unsafe.copyMemory: available
>
> [DEBUG] 23:09:31.121 io.netty.util.internal.PlatformDependent0.<clinit>() - java.nio.Buffer.address: available
>
> [DEBUG] 23:09:31.122 io.netty.util.internal.PlatformDependent0.<clinit>() - direct buffer constructor: unavailable
>
> java.lang.UnsupportedOperationException: Reflective setAccessible(true) disabled
>
> at io.netty.util.internal.ReflectionUtil.trySetAccessible(ReflectionUtil.java:31) ~[netty-common-4.1.47.Final.jar:4.1.47.Final]
>
> at io.netty.util.internal.PlatformDependent0$4.run(PlatformDependent0.java:225) ~[netty-common-4.1.47.Final.jar:4.1.47.Final]
>
> at java.security.AccessController.doPrivileged(AccessController.java:312) ~[?:?]
>
> at io.netty.util.internal.PlatformDependent0.<clinit>(PlatformDependent0.java:219) ~[netty-common-4.1.47.Final.jar:4.1.47.Final]
>
> at io.netty.util.internal.PlatformDependent.isAndroid(PlatformDependent.java:289) ~[netty-common-4.1.47.Final.jar:4.1.47.Final]
>
> at io.netty.util.internal.PlatformDependent.<clinit>(PlatformDependent.java:92) ~[netty-common-4.1.47.Final.jar:4.1.47.Final]
>
> at io.netty.util.HashedWheelTimer.<init>(HashedWheelTimer.java:109) ~[netty-common-4.1.47.Final.jar:4.1.47.Final]
>
> at io.netty.util.HashedWheelTimer.<init>(HashedWheelTimer.java:218) ~[netty-common-4.1.47.Final.jar:4.1.47.Final]
>
> at io.netty.util.HashedWheelTimer.<init>(HashedWheelTimer.java:197) ~[netty-common-4.1.47.Final.jar:4.1.47.Final]
>
> at io.netty.util.HashedWheelTimer.<init>(HashedWheelTimer.java:179) ~[netty-common-4.1.47.Final.jar:4.1.47.Final]
>
> at io.netty.util.HashedWheelTimer.<init>(HashedWheelTimer.java:163) ~[netty-common-4.1.47.Final.jar:4.1.47.Final]
>
> at io.netty.util.HashedWheelTimer.<init>(HashedWheelTimer.java:122) ~[netty-common-4.1.47.Final.jar:4.1.47.Final]
>
> at org.apache.plc4x.java.spi.connection.DefaultNettyPlcConnection.<clinit>(DefaultNettyPlcConnection.java:49) ~[plc4j-spi-0.8.0-SNAPSHOT.jar:0.8.0-SNAPSHOT]
>
> at org.apache.plc4x.java.spi.connection.GeneratedDriverBase.getConnection(GeneratedDriverBase.java:138) ~[plc4j-spi-0.8.0-SNAPSHOT.jar:0.8.0-SNAPSHOT]
>
> at org.apache.plc4x.java.PlcDriverManager.getConnection(PlcDriverManager.java:73) ~[plc4j-api-0.8.0-SNAPSHOT.jar:0.8.0-SNAPSHOT]
>
> at it.fox.datapicker.HelloPlc4x.lambda$0(HelloPlc4x.java:83) ~[main/:?]
>
> at org.pragmaticindustries.cockpit.plc.pool2.CachedDriverManager.lambda$getConnection_$0(CachedDriverManager.java:195) ~[pool2-1.0.0-SNAPSHOT.jar:?]
>
> at java.util.concurrent.CompletableFuture$AsyncRun.run(CompletableFuture.java:1807) [?:?]
>
> at java.util.concurrent.CompletableFuture$AsyncRun.exec(CompletableFuture.java:1799) [?:?]
>
> at java.util.concurrent.ForkJoinTask.doExec(ForkJoinTask.java:290) [?:?]
>
> at java.util.concurrent.ForkJoinPool$WorkQueue.topLevelExec(ForkJoinPool.java:1016) [?:?]
>
> at java.util.concurrent.ForkJoinPool.scan(ForkJoinPool.java:1665) [?:?]
>
> at java.util.concurrent.ForkJoinPool.runWorker(ForkJoinPool.java:1598) [?:?]
>
> at java.util.concurrent.ForkJoinWorkerThread.run(ForkJoinWorkerThread.java:177) [?:?]
>
> [DEBUG] 23:09:31.133 io.netty.util.internal.PlatformDependent0.<clinit>() - java.nio.Bits.unaligned: available, true
>
> [DEBUG] 23:09:31.135 io.netty.util.internal.PlatformDependent0.<clinit>() - jdk.internal.misc.Unsafe.allocateUninitializedArray(int): unavailable
>
> java.lang.IllegalAccessException: class io.netty.util.internal.PlatformDependent0$6 cannot access class jdk.internal.misc.Unsafe (in module java.base) because module java.base does not export jdk.internal.misc to unnamed module @16ce8dcf
>
> at jdk.internal.reflect.Reflection.newIllegalAccessException(Reflection.java:376) ~[?:?]
>
> at java.lang.reflect.AccessibleObject.checkAccess(AccessibleObject.java:642) ~[?:?]
>
> at java.lang.reflect.Method.invoke(Method.java:559) ~[?:?]
>
> at io.netty.util.internal.PlatformDependent0$6.run(PlatformDependent0.java:335) ~[netty-common-4.1.47.Final.jar:4.1.47.Final]
>
> at java.security.AccessController.doPrivileged(AccessController.java:312) ~[?:?]
>
> at io.netty.util.internal.PlatformDependent0.<clinit>(PlatformDependent0.java:326) ~[netty-common-4.1.47.Final.jar:4.1.47.Final]
>
> at io.netty.util.internal.PlatformDependent.isAndroid(PlatformDependent.java:289) ~[netty-common-4.1.47.Final.jar:4.1.47.Final]
>
> at io.netty.util.internal.PlatformDependent.<clinit>(PlatformDependent.java:92) ~[netty-common-4.1.47.Final.jar:4.1.47.Final]
>
> at io.netty.util.HashedWheelTimer.<init>(HashedWheelTimer.java:109) ~[netty-common-4.1.47.Final.jar:4.1.47.Final]
>
> at io.netty.util.HashedWheelTimer.<init>(HashedWheelTimer.java:218) ~[netty-common-4.1.47.Final.jar:4.1.47.Final]
>
> at io.netty.util.HashedWheelTimer.<init>(HashedWheelTimer.java:197) ~[netty-common-4.1.47.Final.jar:4.1.47.Final]
>
> at io.netty.util.HashedWheelTimer.<init>(HashedWheelTimer.java:179) ~[netty-common-4.1.47.Final.jar:4.1.47.Final]
>
> at io.netty.util.HashedWheelTimer.<init>(HashedWheelTimer.java:163) ~[netty-common-4.1.47.Final.jar:4.1.47.Final]
>
> at io.netty.util.HashedWheelTimer.<init>(HashedWheelTimer.java:122) ~[netty-common-4.1.47.Final.jar:4.1.47.Final]
>
> at org.apache.plc4x.java.spi.connection.DefaultNettyPlcConnection.<clinit>(DefaultNettyPlcConnection.java:49) ~[plc4j-spi-0.8.0-SNAPSHOT.jar:0.8.0-SNAPSHOT]
>
> at org.apache.plc4x.java.spi.connection.GeneratedDriverBase.getConnection(GeneratedDriverBase.java:138) ~[plc4j-spi-0.8.0-SNAPSHOT.jar:0.8.0-SNAPSHOT]
>
> at org.apache.plc4x.java.PlcDriverManager.getConnection(PlcDriverManager.java:73) ~[plc4j-api-0.8.0-SNAPSHOT.jar:0.8.0-SNAPSHOT]
>
> at it.fox.datapicker.HelloPlc4x.lambda$0(HelloPlc4x.java:83) ~[main/:?]
>
> at org.pragmaticindustries.cockpit.plc.pool2.CachedDriverManager.lambda$getConnection_$0(CachedDriverManager.java:195) ~[pool2-1.0.0-SNAPSHOT.jar:?]
>
> at java.util.concurrent.CompletableFuture$AsyncRun.run(CompletableFuture.java:1807) [?:?]
>
> at java.util.concurrent.CompletableFuture$AsyncRun.exec(CompletableFuture.java:1799) [?:?]
>
> at java.util.concurrent.ForkJoinTask.doExec(ForkJoinTask.java:290) [?:?]
>
> at java.util.concurrent.ForkJoinPool$WorkQueue.topLevelExec(ForkJoinPool.java:1016) [?:?]
>
> at java.util.concurrent.ForkJoinPool.scan(ForkJoinPool.java:1665) [?:?]
>
> at java.util.concurrent.ForkJoinPool.runWorker(ForkJoinPool.java:1598) [?:?]
>
> at java.util.concurrent.ForkJoinWorkerThread.run(ForkJoinWorkerThread.java:177) [?:?]
>
> [DEBUG] 23:09:31.136 io.netty.util.internal.PlatformDependent0.<clinit>() - java.nio.DirectByteBuffer.<init>(long, int): unavailable
>
> [DEBUG] 23:09:31.136 io.netty.util.internal.PlatformDependent.unsafeUnavailabilityCause0() - sun.misc.Unsafe: available
>
> [DEBUG] 23:09:31.137 io.netty.util.internal.PlatformDependent.maxDirectMemory0() - maxDirectMemory: 4294967296 bytes (maybe)
>
> [DEBUG] 23:09:31.137 io.netty.util.internal.PlatformDependent.tmpdir0() - -Dio.netty.tmpdir: /var/folders/p1/lb5grfpn3tncxdtrptqq9fw40000gp/T (java.io.tmpdir)
>
> [DEBUG] 23:09:31.138 io.netty.util.internal.PlatformDependent.bitMode0() - -Dio.netty.bitMode: 64 (sun.arch.data.model)
>
> [DEBUG] 23:09:31.138 io.netty.util.internal.PlatformDependent.<clinit>() - -Dio.netty.maxDirectMemory: -1 bytes
>
> [DEBUG] 23:09:31.139 io.netty.util.internal.PlatformDependent.<clinit>() - -Dio.netty.uninitializedArrayAllocationThreshold: -1
>
> [DEBUG] 23:09:31.140 io.netty.util.internal.CleanerJava9.<clinit>() - java.nio.ByteBuffer.cleaner(): available
>
> [DEBUG] 23:09:31.140 io.netty.util.internal.PlatformDependent.<clinit>() - -Dio.netty.noPreferDirect: false
>
> [DEBUG] 23:09:31.155 io.netty.util.internal.PlatformDependent.<clinit>() - org.jctools-core.MpscChunkedArrayQueue: available
>
> [DEBUG] 23:09:31.179 io.netty.channel.MultithreadEventLoopGroup.<clinit>() - -Dio.netty.eventLoopThreads: 16
>
> [DEBUG] 23:09:31.191 io.netty.util.internal.InternalThreadLocalMap.<clinit>() - -Dio.netty.threadLocalMap.stringBuilder.initialSize: 1024
>
> [DEBUG] 23:09:31.191 io.netty.util.internal.InternalThreadLocalMap.<clinit>() - -Dio.netty.threadLocalMap.stringBuilder.maxSize: 4096
>
> [DEBUG] 23:09:31.196 io.netty.channel.nio.NioEventLoop.<clinit>() - -Dio.netty.noKeySetOptimization: false
>
> [DEBUG] 23:09:31.196 io.netty.channel.nio.NioEventLoop.<clinit>() - -Dio.netty.selectorAutoRebuildThreshold: 512
>
> [INFO ] 23:09:31.208 org.apache.plc4x.java.transport.tcp.TcpChannelFactory.configureBootstrap() - Configuring Bootstrap with Configuration{local-rack=1, local-slot=1, remote-rack=0, remot-slot=0, pduSize=1024, maxAmqCaller=8, maxAmqCallee=8, controllerType='null'}
>
> [DEBUG] 23:09:31.227 io.netty.channel.DefaultChannelId.<clinit>() - -Dio.netty.processId: 84362 (auto-detected)
>
> [DEBUG] 23:09:31.230 io.netty.util.NetUtil.<clinit>() - -Djava.net.preferIPv4Stack: false
>
> [DEBUG] 23:09:31.230 io.netty.util.NetUtil.<clinit>() - -Djava.net.preferIPv6Addresses: false
>
> [DEBUG] 23:09:31.235 io.netty.util.NetUtil.<clinit>() - Loopback interface: lo0 (lo0, 0:0:0:0:0:0:0:1%lo0)
>
> [DEBUG] 23:09:31.236 io.netty.util.NetUtil.run() - Failed to get SOMAXCONN from sysctl and file /proc/sys/net/core/somaxconn. Default: 128
>
> [DEBUG] 23:09:31.239 io.netty.channel.DefaultChannelId.<clinit>() - -Dio.netty.machineId: 00:e0:4c:ff:fe:68:01:3f (auto-detected)
>
> [DEBUG] 23:09:31.280 io.netty.buffer.PooledByteBufAllocator.<clinit>() - -Dio.netty.allocator.numHeapArenas: 16
>
> [DEBUG] 23:09:31.280 io.netty.buffer.PooledByteBufAllocator.<clinit>() - -Dio.netty.allocator.numDirectArenas: 16
>
> [DEBUG] 23:09:31.280 io.netty.buffer.PooledByteBufAllocator.<clinit>() - -Dio.netty.allocator.pageSize: 8192
>
> [DEBUG] 23:09:31.280 io.netty.buffer.PooledByteBufAllocator.<clinit>() - -Dio.netty.allocator.maxOrder: 11
>
> [DEBUG] 23:09:31.281 io.netty.buffer.PooledByteBufAllocator.<clinit>() - -Dio.netty.allocator.chunkSize: 16777216
>
> [DEBUG] 23:09:31.281 io.netty.buffer.PooledByteBufAllocator.<clinit>() - -Dio.netty.allocator.tinyCacheSize: 512
>
> [DEBUG] 23:09:31.281 io.netty.buffer.PooledByteBufAllocator.<clinit>() - -Dio.netty.allocator.smallCacheSize: 256
>
> [DEBUG] 23:09:31.281 io.netty.buffer.PooledByteBufAllocator.<clinit>() - -Dio.netty.allocator.normalCacheSize: 64
>
> [DEBUG] 23:09:31.281 io.netty.buffer.PooledByteBufAllocator.<clinit>() - -Dio.netty.allocator.maxCachedBufferCapacity: 32768
>
> [DEBUG] 23:09:31.282 io.netty.buffer.PooledByteBufAllocator.<clinit>() - -Dio.netty.allocator.cacheTrimInterval: 8192
>
> [DEBUG] 23:09:31.282 io.netty.buffer.PooledByteBufAllocator.<clinit>() - -Dio.netty.allocator.cacheTrimIntervalMillis: 0
>
> [DEBUG] 23:09:31.282 io.netty.buffer.PooledByteBufAllocator.<clinit>() - -Dio.netty.allocator.useCacheForAllThreads: true
>
> [DEBUG] 23:09:31.282 io.netty.buffer.PooledByteBufAllocator.<clinit>() - -Dio.netty.allocator.maxCachedByteBuffersPerChunk: 1023
>
> [DEBUG] 23:09:31.291 io.netty.buffer.ByteBufUtil.<clinit>() - -Dio.netty.allocator.type: pooled
>
> [DEBUG] 23:09:31.291 io.netty.buffer.ByteBufUtil.<clinit>() - -Dio.netty.threadLocalDirectBufferSize: 0
>
> [DEBUG] 23:09:31.291 io.netty.buffer.ByteBufUtil.<clinit>() - -Dio.netty.maxThreadLocalCharBufferSize: 16384
>
> [INFO ] 23:09:31.425 org.apache.plc4x.java.s7.readwrite.protocol.S7ProtocolLogic.onConnect() - S7 Driver running in ACTIVE mode.
>
> [DEBUG] 23:09:31.426 org.apache.plc4x.java.s7.readwrite.protocol.S7ProtocolLogic.onConnect() - Sending COTP Connection Request
>
> [DEBUG] 23:09:31.446 org.apache.plc4x.java.spi.Plc4xNettyWrapper.encode() - Forwarding request to plc TPKTPacket[payload=COTPPacketConnectionRequest[parameters={COTPParameterCalledTsap[tsapId=256],COTPParameterCallingTsap[tsapId=785],COTPParameterTpduSize[tpduSize=SIZE_1024]},payload=<null>,destinationReference=0,sourceReference=15,protocolClass=CLASS_0]]
>
> [DEBUG] 23:09:31.450 io.netty.util.Recycler.<clinit>() - -Dio.netty.recycler.maxCapacityPerThread: 4096
>
> [DEBUG] 23:09:31.450 io.netty.util.Recycler.<clinit>() - -Dio.netty.recycler.maxSharedCapacityFactor: 2
>
> [DEBUG] 23:09:31.450 io.netty.util.Recycler.<clinit>() - -Dio.netty.recycler.linkCapacity: 16
>
> [DEBUG] 23:09:31.450 io.netty.util.Recycler.<clinit>() - -Dio.netty.recycler.ratio: 8
>
> [DEBUG] 23:09:31.457 io.netty.buffer.AbstractByteBuf.<clinit>() - -Dio.netty.buffer.checkAccessible: true
>
> [DEBUG] 23:09:31.457 io.netty.buffer.AbstractByteBuf.<clinit>() - -Dio.netty.buffer.checkBounds: true
>
> [DEBUG] 23:09:31.457 io.netty.util.ResourceLeakDetectorFactory.newResourceLeakDetector() - Loaded default ResourceLeakDetector: io.netty.util.ResourceLeakDetector@466425b5
>
> [DEBUG] 23:09:31.480 org.apache.plc4x.java.spi.GeneratedDriverByteToMessageCodec.encode() - Sending bytes to PLC for message TPKTPacket[payload=COTPPacketConnectionRequest[parameters={COTPParameterCalledTsap[tsapId=256],COTPParameterCallingTsap[tsapId=785],COTPParameterTpduSize[tpduSize=SIZE_1024]},payload=<null>,destinationReference=0,sourceReference=15,protocolClass=CLASS_0]] as data 0300001611e00000000f00c2020100c1020311c0010a
>
> [DEBUG] 23:09:31.601 org.apache.plc4x.java.s7.readwrite.protocol.S7ProtocolLogic.lambda$onConnect$9() - Got COTP Connection Response
>
> [DEBUG] 23:09:31.601 org.apache.plc4x.java.s7.readwrite.protocol.S7ProtocolLogic.lambda$onConnect$9() - Sending S7 Connection Request
>
> [DEBUG] 23:09:31.603 org.apache.plc4x.java.spi.Plc4xNettyWrapper.encode() - Forwarding request to plc TPKTPacket[payload=COTPPacketData[parameters=<null>,payload=S7MessageRequest[tpduReference=0,parameter=S7ParameterSetupCommunication[maxAmqCaller=8,maxAmqCallee=8,pduLength=1008],payload=<null>],eot=true,tpduRef=1]]
>
> [DEBUG] 23:09:31.606 org.apache.plc4x.java.spi.GeneratedDriverByteToMessageCodec.encode() - Sending bytes to PLC for message TPKTPacket[payload=COTPPacketData[parameters=<null>,payload=S7MessageRequest[tpduReference=0,parameter=S7ParameterSetupCommunication[maxAmqCaller=8,maxAmqCallee=8,pduLength=1008],payload=<null>],eot=true,tpduRef=1]] as data 0300001902f08132010000000000080000f0000008000803f0
>
> [DEBUG] 23:09:31.654 org.apache.plc4x.java.s7.readwrite.protocol.S7ProtocolLogic.lambda$onConnect$8() - Got S7 Connection Response
>
> [DEBUG] 23:09:31.654 org.apache.plc4x.java.s7.readwrite.protocol.S7ProtocolLogic.lambda$onConnect$8() - Sending S7 Identification Request
>
> [DEBUG] 23:09:31.660 org.apache.plc4x.java.spi.Plc4xNettyWrapper.encode() - Forwarding request to plc TPKTPacket[payload=COTPPacketData[parameters=<null>,payload=S7MessageUserData[tpduReference=1,parameter=S7ParameterUserData[items={S7ParameterUserDataItemCPUFunctions[method=17,cpuFunctionType=4,cpuFunctionGroup=4,cpuSubfunction=1,sequenceNumber=0,dataUnitReferenceNumber=<null>,lastDataUnit=<null>,errorCode=<null>]}],payload=S7PayloadUserData[items={S7PayloadUserDataItemCpuFunctionReadSzlRequest[returnCode=OK,transportSize=OCTET_STRING,szlId=SzlId[typeClass=CPU,sublistExtract=0,sublistList=MODULE_IDENTIFICATION],szlIndex=0]}]],eot=true,tpduRef=2]]
>
> [DEBUG] 23:09:31.664 org.apache.plc4x.java.spi.GeneratedDriverByteToMessageCodec.encode() - Sending bytes to PLC for message TPKTPacket[payload=COTPPacketData[parameters=<null>,payload=S7MessageUserData[tpduReference=1,parameter=S7ParameterUserData[items={S7ParameterUserDataItemCPUFunctions[method=17,cpuFunctionType=4,cpuFunctionGroup=4,cpuSubfunction=1,sequenceNumber=0,dataUnitReferenceNumber=<null>,lastDataUnit=<null>,errorCode=<null>]}],payload=S7PayloadUserData[items={S7PayloadUserDataItemCpuFunctionReadSzlRequest[returnCode=OK,transportSize=OCTET_STRING,szlId=SzlId[typeClass=CPU,sublistExtract=0,sublistList=MODULE_IDENTIFICATION],szlIndex=0]}]],eot=true,tpduRef=2]] as data 0300002102f082320700000001000800080001120411440100ff09000400110000
>
> [DEBUG] 23:09:31.715 org.apache.plc4x.java.s7.readwrite.protocol.S7ProtocolLogic.lambda$onConnect$7() - Got S7 Identification Response
>
> [DEBUG] 23:09:31.716 org.pragmaticindustries.cockpit.plc.pool2.CachedDriverManager.lambda$getConnection_$0() - Connection successfully established
>
> [DEBUG] 23:09:31.716 org.pragmaticindustries.cockpit.plc.pool2.CachedDriverManager.checkQueue() - Connection is available, checking if someone is waiting in the queue...
>
> [DEBUG] 23:09:31.716 org.pragmaticindustries.cockpit.plc.pool2.CachedDriverManager.getConnection_() - Connection was requested and is available, thus, returning Chached Connection for usage
>
> java.lang.UnsupportedOperationException
>
> at org.pragmaticindustries.cockpit.plc.pool2.CachedPlcConnection.getMetadata(CachedPlcConnection.java:106)
>
> at it.fox.datapicker.HelloPlc4x.main(HelloPlc4x.java:91)
>
> 2020-11-26 23:09:31,720 pool-1-thread-1 DEBUG Stopping LoggerContext[name=55054057, org.apache.logging.log4j.core.LoggerContext@2ca26d77]
>
> 2020-11-26 23:09:31,720 pool-1-thread-1 DEBUG Stopping LoggerContext[name=55054057, org.apache.logging.log4j.core.LoggerContext@2ca26d77]...
>
> 2020-11-26 23:09:31,723 pool-1-thread-1 DEBUG Shutting down OutputStreamManager SYSTEM_OUT.false.false
>
> 2020-11-26 23:09:31,724 pool-1-thread-1 DEBUG OutputStream closed
>
> 2020-11-26 23:09:31,724 pool-1-thread-1 DEBUG Shut down OutputStreamManager SYSTEM_OUT.false.false, all resources released: true
>
> 2020-11-26 23:09:31,724 pool-1-thread-1 DEBUG Appender Console stopped with status true
>
> 2020-11-26 23:09:31,724 pool-1-thread-1 DEBUG Stopped XmlConfiguration[location=/Users/fox/Documents/workspace/2020-06-30 - HelloPlc4x/bin/main/log4j2.xml] OK
>
> 2020-11-26 23:09:31,724 pool-1-thread-1 DEBUG Stopped LoggerContext[name=55054057, org.apache.logging.log4j.core.LoggerContext@2ca26d77] with status true
>
>
> Did you spot some trouble ?
>
> Regards,
> Stefano
>
AW: Test on plc4x-pool2
Posted by Christofer Dutz <ch...@c-ware.de>.
Hi Stefano,
I really wonder how often I will end up looking up this stupid java.lang.UnsupportedOperationException …
I have to admit that for me this is one of the most annoying things with Netty :-/
But seeing the actual error is coming from the pool, I guess Julian should probably help you with this, I doubt this is something I can help with.
Chris
Von: Stefano Bossi <st...@gmail.com>
Datum: Donnerstag, 26. November 2020 um 23:16
An: dev@plc4x.apache.org <de...@plc4x.apache.org>
Betreff: Test on plc4x-pool2
Hi Julian,
I have tried to integrate in my code the new pool library you wrote but without success, I have probably did something wrong.
I am started trying to work with the HelloPlc4x
PlcDriverManager manager = new PlcDriverManager();
PlcDriverManager cached = new CachedDriverManager(connectionString, () -> {
try {
return manager.getConnection(connectionString);
} catch (PlcConnectionException e) {
e.printStackTrace();
}
return null;
});
PlcConnection plcConnection = cached.getConnection(connectionString);
// Check if this connection support reading of data.
if (!plcConnection.getMetadata().canRead()) {
logger.error("This connection doesn't support reading.");
return;
}
integrate When the code reach the line plcConnection.getMetadata().canRead()
integrate an exception is rised:
bash-3.2$ /Users/fox/.jenv/versions/openjdk64-13.0.2/bin/java -agentlib:jdwp=transport=dt_socket,server=n,suspend=y,address=localhost:51806 -ea -Dfile.encoding=UTF-8 @/var/folders/p1/lb5grfpn3tncxdtrptqq9fw40000gp/T/cp_dkqa6x1i5h7yfdha7mxc6sn5h.argfile it.fox.datapicker.HelloPlc4x
2020-11-26 23:09:30,677 main DEBUG Apache Log4j Core 2.14.0 initializing configuration XmlConfiguration[location=/Users/fox/Documents/workspace/2020-06-30 - HelloPlc4x/bin/main/log4j2.xml]
2020-11-26 23:09:30,684 main DEBUG Installed 1 script engine
Warning: Nashorn engine is planned to be removed from a future JDK release
2020-11-26 23:09:30,885 main DEBUG Oracle Nashorn version: 13.0.2, language: ECMAScript, threading: Not Thread Safe, compile: true, names: [nashorn, Nashorn, js, JS, JavaScript, javascript, ECMAScript, ecmascript], factory class: jdk.nashorn.api.scripting.NashornScriptEngineFactory
2020-11-26 23:09:30,885 main DEBUG PluginManager 'Core' found 122 plugins
2020-11-26 23:09:30,885 main DEBUG PluginManager 'Level' found 0 plugins
2020-11-26 23:09:30,889 main DEBUG PluginManager 'Lookup' found 16 plugins
2020-11-26 23:09:30,890 main DEBUG Building Plugin[name=layout, class=org.apache.logging.log4j.core.layout.PatternLayout].
2020-11-26 23:09:30,899 main DEBUG PluginManager 'TypeConverter' found 26 plugins
2020-11-26 23:09:30,911 main DEBUG PatternLayout$Builder(pattern="[%-5level] %d{HH:mm:ss.SSS} %logger{36}.%M() - %msg%n", PatternSelector=null, Configuration(/Users/fox/Documents/workspace/2020-06-30 - HelloPlc4x/bin/main/log4j2.xml), Replace=null, charset="null", alwaysWriteExceptions="null", disableAnsi="null", noConsoleNoAnsi="null", header="null", footer="null")
2020-11-26 23:09:30,911 main DEBUG PluginManager 'Converter' found 44 plugins
2020-11-26 23:09:30,912 main DEBUG Building Plugin[name=appender, class=org.apache.logging.log4j.core.appender.ConsoleAppender].
2020-11-26 23:09:30,917 main DEBUG ConsoleAppender$Builder(target="SYSTEM_OUT", follow="null", direct="null", bufferedIo="null", bufferSize="null", immediateFlush="null", ignoreExceptions="null", PatternLayout([%-5level] %d{HH:mm:ss.SSS} %logger{36}.%M() - %msg%n), name="Console", Configuration(/Users/fox/Documents/workspace/2020-06-30 - HelloPlc4x/bin/main/log4j2.xml), Filter=null, ={})
2020-11-26 23:09:30,919 main DEBUG Starting OutputStreamManager SYSTEM_OUT.false.false
2020-11-26 23:09:30,919 main DEBUG Building Plugin[name=appenders, class=org.apache.logging.log4j.core.config.AppendersPlugin].
2020-11-26 23:09:30,922 main DEBUG createAppenders(={Console})
2020-11-26 23:09:30,922 main DEBUG Building Plugin[name=AppenderRef, class=org.apache.logging.log4j.core.config.AppenderRef].
2020-11-26 23:09:30,926 main DEBUG createAppenderRef(ref="Console", level="TRACE", Filter=null)
2020-11-26 23:09:30,926 main DEBUG Building Plugin[name=root, class=org.apache.logging.log4j.core.config.LoggerConfig$RootLogger].
2020-11-26 23:09:30,927 main DEBUG createLogger(additivity="false", level="DEBUG", includeLocation="null", ={Console}, ={}, Configuration(/Users/fox/Documents/workspace/2020-06-30 - HelloPlc4x/bin/main/log4j2.xml), Filter=null)
2020-11-26 23:09:30,929 main DEBUG Building Plugin[name=loggers, class=org.apache.logging.log4j.core.config.LoggersPlugin].
2020-11-26 23:09:30,930 main DEBUG createLoggers(={root})
2020-11-26 23:09:30,931 main DEBUG Configuration XmlConfiguration[location=/Users/fox/Documents/workspace/2020-06-30 - HelloPlc4x/bin/main/log4j2.xml] initialized
2020-11-26 23:09:30,932 main DEBUG Starting configuration XmlConfiguration[location=/Users/fox/Documents/workspace/2020-06-30 - HelloPlc4x/bin/main/log4j2.xml]
2020-11-26 23:09:30,932 main DEBUG Started configuration XmlConfiguration[location=/Users/fox/Documents/workspace/2020-06-30 - HelloPlc4x/bin/main/log4j2.xml] OK.
2020-11-26 23:09:30,933 main DEBUG Shutting down OutputStreamManager SYSTEM_OUT.false.false-1
2020-11-26 23:09:30,933 main DEBUG OutputStream closed
2020-11-26 23:09:30,933 main DEBUG Shut down OutputStreamManager SYSTEM_OUT.false.false-1, all resources released: true
2020-11-26 23:09:30,934 main DEBUG Appender DefaultConsole-1 stopped with status true
2020-11-26 23:09:30,934 main DEBUG Stopped org.apache.logging.log4j.core.config.DefaultConfiguration@6cc4c815 OK
2020-11-26 23:09:30,989 main DEBUG Registering MBean org.apache.logging.log4j2:type=55054057
2020-11-26 23:09:30,992 main DEBUG Registering MBean org.apache.logging.log4j2:type=55054057,component=StatusLogger
2020-11-26 23:09:30,993 main DEBUG Registering MBean org.apache.logging.log4j2:type=55054057,component=ContextSelector
2020-11-26 23:09:30,994 main DEBUG Registering MBean org.apache.logging.log4j2:type=55054057,component=Loggers,name=
2020-11-26 23:09:30,995 main DEBUG Registering MBean org.apache.logging.log4j2:type=55054057,component=Appenders,name=Console
2020-11-26 23:09:30,997 main DEBUG org.apache.logging.log4j.core.util.SystemClock supports precise timestamps.
2020-11-26 23:09:30,997 main DEBUG Reconfiguration complete for context[name=55054057] at URI /Users/fox/Documents/workspace/2020-06-30 - HelloPlc4x/bin/main/log4j2.xml (org.apache.logging.log4j.core.LoggerContext@2ca26d77) with optional ClassLoader: null
2020-11-26 23:09:30,997 main DEBUG Shutdown hook enabled. Registering a new one.
2020-11-26 23:09:30,998 main DEBUG LoggerContext[name=55054057, org.apache.logging.log4j.core.LoggerContext@2ca26d77] started OK.
[INFO ] 23:09:31.011 it.fox.datapicker.HelloPlc4x.main() - start
[INFO ] 23:09:31.014 org.apache.plc4x.java.PlcDriverManager.<init>() - Instantiating new PLC Driver Manager with class loader jdk.internal.loader.ClassLoaders$AppClassLoader@55054057
[INFO ] 23:09:31.014 org.apache.plc4x.java.PlcDriverManager.<init>() - Registering available drivers...
[INFO ] 23:09:31.018 org.apache.plc4x.java.PlcDriverManager.<init>() - Registering driver for Protocol s7 (Siemens S7 (Basic))
[INFO ] 23:09:31.020 org.apache.plc4x.java.PlcDriverManager.<init>() - Registering driver for Protocol mock (Mock Protocol Implementation)
[INFO ] 23:09:31.021 org.apache.plc4x.java.PlcDriverManager.<init>() - Instantiating new PLC Driver Manager with class loader jdk.internal.loader.ClassLoaders$AppClassLoader@55054057
[INFO ] 23:09:31.022 org.apache.plc4x.java.PlcDriverManager.<init>() - Registering available drivers...
[INFO ] 23:09:31.023 org.apache.plc4x.java.PlcDriverManager.<init>() - Registering driver for Protocol s7 (Siemens S7 (Basic))
[INFO ] 23:09:31.023 org.apache.plc4x.java.PlcDriverManager.<init>() - Registering driver for Protocol mock (Mock Protocol Implementation)
[INFO ] 23:09:31.025 org.pragmaticindustries.cockpit.plc.pool2.CachedDriverManager.<init>() - Creating new cached Connection for url s7://192.168.1.192 with timeout 1000 ms
[DEBUG] 23:09:31.025 org.pragmaticindustries.cockpit.plc.pool2.CachedDriverManager.getConnection_() - Connection was requested but no connection is active, trying to establish a Connection
[DEBUG] 23:09:31.026 org.pragmaticindustries.cockpit.plc.pool2.CachedDriverManager.lambda$getConnection_$0() - Starting to establish Connection
[DEBUG] 23:09:31.097 io.netty.util.internal.logging.InternalLoggerFactory.newDefaultFactory() - Using SLF4J as the default logging framework
[DEBUG] 23:09:31.101 io.netty.util.ResourceLeakDetector.<clinit>() - -Dio.netty.leakDetection.level: simple
[DEBUG] 23:09:31.101 io.netty.util.ResourceLeakDetector.<clinit>() - -Dio.netty.leakDetection.targetRecords: 4
[DEBUG] 23:09:31.105 io.netty.util.ResourceLeakDetectorFactory.newResourceLeakDetector() - Loaded default ResourceLeakDetector: io.netty.util.ResourceLeakDetector@16dc2e81
[DEBUG] 23:09:31.117 io.netty.util.internal.PlatformDependent.isOsx0() - Platform: MacOS
[DEBUG] 23:09:31.118 io.netty.util.internal.PlatformDependent0.explicitNoUnsafeCause0() - -Dio.netty.noUnsafe: false
[DEBUG] 23:09:31.118 io.netty.util.internal.PlatformDependent0.javaVersion0() - Java version: 13
[DEBUG] 23:09:31.120 io.netty.util.internal.PlatformDependent0.<clinit>() - sun.misc.Unsafe.theUnsafe: available
[DEBUG] 23:09:31.120 io.netty.util.internal.PlatformDependent0.<clinit>() - sun.misc.Unsafe.copyMemory: available
[DEBUG] 23:09:31.121 io.netty.util.internal.PlatformDependent0.<clinit>() - java.nio.Buffer.address: available
[DEBUG] 23:09:31.122 io.netty.util.internal.PlatformDependent0.<clinit>() - direct buffer constructor: unavailable
java.lang.UnsupportedOperationException: Reflective setAccessible(true) disabled
at io.netty.util.internal.ReflectionUtil.trySetAccessible(ReflectionUtil.java:31) ~[netty-common-4.1.47.Final.jar:4.1.47.Final]
at io.netty.util.internal.PlatformDependent0$4.run(PlatformDependent0.java:225) ~[netty-common-4.1.47.Final.jar:4.1.47.Final]
at java.security.AccessController.doPrivileged(AccessController.java:312) ~[?:?]
at io.netty.util.internal.PlatformDependent0.<clinit>(PlatformDependent0.java:219) ~[netty-common-4.1.47.Final.jar:4.1.47.Final]
at io.netty.util.internal.PlatformDependent.isAndroid(PlatformDependent.java:289) ~[netty-common-4.1.47.Final.jar:4.1.47.Final]
at io.netty.util.internal.PlatformDependent.<clinit>(PlatformDependent.java:92) ~[netty-common-4.1.47.Final.jar:4.1.47.Final]
at io.netty.util.HashedWheelTimer.<init>(HashedWheelTimer.java:109) ~[netty-common-4.1.47.Final.jar:4.1.47.Final]
at io.netty.util.HashedWheelTimer.<init>(HashedWheelTimer.java:218) ~[netty-common-4.1.47.Final.jar:4.1.47.Final]
at io.netty.util.HashedWheelTimer.<init>(HashedWheelTimer.java:197) ~[netty-common-4.1.47.Final.jar:4.1.47.Final]
at io.netty.util.HashedWheelTimer.<init>(HashedWheelTimer.java:179) ~[netty-common-4.1.47.Final.jar:4.1.47.Final]
at io.netty.util.HashedWheelTimer.<init>(HashedWheelTimer.java:163) ~[netty-common-4.1.47.Final.jar:4.1.47.Final]
at io.netty.util.HashedWheelTimer.<init>(HashedWheelTimer.java:122) ~[netty-common-4.1.47.Final.jar:4.1.47.Final]
at org.apache.plc4x.java.spi.connection.DefaultNettyPlcConnection.<clinit>(DefaultNettyPlcConnection.java:49) ~[plc4j-spi-0.8.0-SNAPSHOT.jar:0.8.0-SNAPSHOT]
at org.apache.plc4x.java.spi.connection.GeneratedDriverBase.getConnection(GeneratedDriverBase.java:138) ~[plc4j-spi-0.8.0-SNAPSHOT.jar:0.8.0-SNAPSHOT]
at org.apache.plc4x.java.PlcDriverManager.getConnection(PlcDriverManager.java:73) ~[plc4j-api-0.8.0-SNAPSHOT.jar:0.8.0-SNAPSHOT]
at it.fox.datapicker.HelloPlc4x.lambda$0(HelloPlc4x.java:83) ~[main/:?]
at org.pragmaticindustries.cockpit.plc.pool2.CachedDriverManager.lambda$getConnection_$0(CachedDriverManager.java:195) ~[pool2-1.0.0-SNAPSHOT.jar:?]
at java.util.concurrent.CompletableFuture$AsyncRun.run(CompletableFuture.java:1807) [?:?]
at java.util.concurrent.CompletableFuture$AsyncRun.exec(CompletableFuture.java:1799) [?:?]
at java.util.concurrent.ForkJoinTask.doExec(ForkJoinTask.java:290) [?:?]
at java.util.concurrent.ForkJoinPool$WorkQueue.topLevelExec(ForkJoinPool.java:1016) [?:?]
at java.util.concurrent.ForkJoinPool.scan(ForkJoinPool.java:1665) [?:?]
at java.util.concurrent.ForkJoinPool.runWorker(ForkJoinPool.java:1598) [?:?]
at java.util.concurrent.ForkJoinWorkerThread.run(ForkJoinWorkerThread.java:177) [?:?]
[DEBUG] 23:09:31.133 io.netty.util.internal.PlatformDependent0.<clinit>() - java.nio.Bits.unaligned: available, true
[DEBUG] 23:09:31.135 io.netty.util.internal.PlatformDependent0.<clinit>() - jdk.internal.misc.Unsafe.allocateUninitializedArray(int): unavailable
java.lang.IllegalAccessException: class io.netty.util.internal.PlatformDependent0$6 cannot access class jdk.internal.misc.Unsafe (in module java.base) because module java.base does not export jdk.internal.misc to unnamed module @16ce8dcf
at jdk.internal.reflect.Reflection.newIllegalAccessException(Reflection.java:376) ~[?:?]
at java.lang.reflect.AccessibleObject.checkAccess(AccessibleObject.java:642) ~[?:?]
at java.lang.reflect.Method.invoke(Method.java:559) ~[?:?]
at io.netty.util.internal.PlatformDependent0$6.run(PlatformDependent0.java:335) ~[netty-common-4.1.47.Final.jar:4.1.47.Final]
at java.security.AccessController.doPrivileged(AccessController.java:312) ~[?:?]
at io.netty.util.internal.PlatformDependent0.<clinit>(PlatformDependent0.java:326) ~[netty-common-4.1.47.Final.jar:4.1.47.Final]
at io.netty.util.internal.PlatformDependent.isAndroid(PlatformDependent.java:289) ~[netty-common-4.1.47.Final.jar:4.1.47.Final]
at io.netty.util.internal.PlatformDependent.<clinit>(PlatformDependent.java:92) ~[netty-common-4.1.47.Final.jar:4.1.47.Final]
at io.netty.util.HashedWheelTimer.<init>(HashedWheelTimer.java:109) ~[netty-common-4.1.47.Final.jar:4.1.47.Final]
at io.netty.util.HashedWheelTimer.<init>(HashedWheelTimer.java:218) ~[netty-common-4.1.47.Final.jar:4.1.47.Final]
at io.netty.util.HashedWheelTimer.<init>(HashedWheelTimer.java:197) ~[netty-common-4.1.47.Final.jar:4.1.47.Final]
at io.netty.util.HashedWheelTimer.<init>(HashedWheelTimer.java:179) ~[netty-common-4.1.47.Final.jar:4.1.47.Final]
at io.netty.util.HashedWheelTimer.<init>(HashedWheelTimer.java:163) ~[netty-common-4.1.47.Final.jar:4.1.47.Final]
at io.netty.util.HashedWheelTimer.<init>(HashedWheelTimer.java:122) ~[netty-common-4.1.47.Final.jar:4.1.47.Final]
at org.apache.plc4x.java.spi.connection.DefaultNettyPlcConnection.<clinit>(DefaultNettyPlcConnection.java:49) ~[plc4j-spi-0.8.0-SNAPSHOT.jar:0.8.0-SNAPSHOT]
at org.apache.plc4x.java.spi.connection.GeneratedDriverBase.getConnection(GeneratedDriverBase.java:138) ~[plc4j-spi-0.8.0-SNAPSHOT.jar:0.8.0-SNAPSHOT]
at org.apache.plc4x.java.PlcDriverManager.getConnection(PlcDriverManager.java:73) ~[plc4j-api-0.8.0-SNAPSHOT.jar:0.8.0-SNAPSHOT]
at it.fox.datapicker.HelloPlc4x.lambda$0(HelloPlc4x.java:83) ~[main/:?]
at org.pragmaticindustries.cockpit.plc.pool2.CachedDriverManager.lambda$getConnection_$0(CachedDriverManager.java:195) ~[pool2-1.0.0-SNAPSHOT.jar:?]
at java.util.concurrent.CompletableFuture$AsyncRun.run(CompletableFuture.java:1807) [?:?]
at java.util.concurrent.CompletableFuture$AsyncRun.exec(CompletableFuture.java:1799) [?:?]
at java.util.concurrent.ForkJoinTask.doExec(ForkJoinTask.java:290) [?:?]
at java.util.concurrent.ForkJoinPool$WorkQueue.topLevelExec(ForkJoinPool.java:1016) [?:?]
at java.util.concurrent.ForkJoinPool.scan(ForkJoinPool.java:1665) [?:?]
at java.util.concurrent.ForkJoinPool.runWorker(ForkJoinPool.java:1598) [?:?]
at java.util.concurrent.ForkJoinWorkerThread.run(ForkJoinWorkerThread.java:177) [?:?]
[DEBUG] 23:09:31.136 io.netty.util.internal.PlatformDependent0.<clinit>() - java.nio.DirectByteBuffer.<init>(long, int): unavailable
[DEBUG] 23:09:31.136 io.netty.util.internal.PlatformDependent.unsafeUnavailabilityCause0() - sun.misc.Unsafe: available
[DEBUG] 23:09:31.137 io.netty.util.internal.PlatformDependent.maxDirectMemory0() - maxDirectMemory: 4294967296 bytes (maybe)
[DEBUG] 23:09:31.137 io.netty.util.internal.PlatformDependent.tmpdir0() - -Dio.netty.tmpdir: /var/folders/p1/lb5grfpn3tncxdtrptqq9fw40000gp/T (java.io.tmpdir)
[DEBUG] 23:09:31.138 io.netty.util.internal.PlatformDependent.bitMode0() - -Dio.netty.bitMode: 64 (sun.arch.data.model)
[DEBUG] 23:09:31.138 io.netty.util.internal.PlatformDependent.<clinit>() - -Dio.netty.maxDirectMemory: -1 bytes
[DEBUG] 23:09:31.139 io.netty.util.internal.PlatformDependent.<clinit>() - -Dio.netty.uninitializedArrayAllocationThreshold: -1
[DEBUG] 23:09:31.140 io.netty.util.internal.CleanerJava9.<clinit>() - java.nio.ByteBuffer.cleaner(): available
[DEBUG] 23:09:31.140 io.netty.util.internal.PlatformDependent.<clinit>() - -Dio.netty.noPreferDirect: false
[DEBUG] 23:09:31.155 io.netty.util.internal.PlatformDependent.<clinit>() - org.jctools-core.MpscChunkedArrayQueue: available
[DEBUG] 23:09:31.179 io.netty.channel.MultithreadEventLoopGroup.<clinit>() - -Dio.netty.eventLoopThreads: 16
[DEBUG] 23:09:31.191 io.netty.util.internal.InternalThreadLocalMap.<clinit>() - -Dio.netty.threadLocalMap.stringBuilder.initialSize: 1024
[DEBUG] 23:09:31.191 io.netty.util.internal.InternalThreadLocalMap.<clinit>() - -Dio.netty.threadLocalMap.stringBuilder.maxSize: 4096
[DEBUG] 23:09:31.196 io.netty.channel.nio.NioEventLoop.<clinit>() - -Dio.netty.noKeySetOptimization: false
[DEBUG] 23:09:31.196 io.netty.channel.nio.NioEventLoop.<clinit>() - -Dio.netty.selectorAutoRebuildThreshold: 512
[INFO ] 23:09:31.208 org.apache.plc4x.java.transport.tcp.TcpChannelFactory.configureBootstrap() - Configuring Bootstrap with Configuration{local-rack=1, local-slot=1, remote-rack=0, remot-slot=0, pduSize=1024, maxAmqCaller=8, maxAmqCallee=8, controllerType='null'}
[DEBUG] 23:09:31.227 io.netty.channel.DefaultChannelId.<clinit>() - -Dio.netty.processId: 84362 (auto-detected)
[DEBUG] 23:09:31.230 io.netty.util.NetUtil.<clinit>() - -Djava.net.preferIPv4Stack: false
[DEBUG] 23:09:31.230 io.netty.util.NetUtil.<clinit>() - -Djava.net.preferIPv6Addresses: false
[DEBUG] 23:09:31.235 io.netty.util.NetUtil.<clinit>() - Loopback interface: lo0 (lo0, 0:0:0:0:0:0:0:1%lo0)
[DEBUG] 23:09:31.236 io.netty.util.NetUtil.run() - Failed to get SOMAXCONN from sysctl and file /proc/sys/net/core/somaxconn. Default: 128
[DEBUG] 23:09:31.239 io.netty.channel.DefaultChannelId.<clinit>() - -Dio.netty.machineId: 00:e0:4c:ff:fe:68:01:3f (auto-detected)
[DEBUG] 23:09:31.280 io.netty.buffer.PooledByteBufAllocator.<clinit>() - -Dio.netty.allocator.numHeapArenas: 16
[DEBUG] 23:09:31.280 io.netty.buffer.PooledByteBufAllocator.<clinit>() - -Dio.netty.allocator.numDirectArenas: 16
[DEBUG] 23:09:31.280 io.netty.buffer.PooledByteBufAllocator.<clinit>() - -Dio.netty.allocator.pageSize: 8192
[DEBUG] 23:09:31.280 io.netty.buffer.PooledByteBufAllocator.<clinit>() - -Dio.netty.allocator.maxOrder: 11
[DEBUG] 23:09:31.281 io.netty.buffer.PooledByteBufAllocator.<clinit>() - -Dio.netty.allocator.chunkSize: 16777216
[DEBUG] 23:09:31.281 io.netty.buffer.PooledByteBufAllocator.<clinit>() - -Dio.netty.allocator.tinyCacheSize: 512
[DEBUG] 23:09:31.281 io.netty.buffer.PooledByteBufAllocator.<clinit>() - -Dio.netty.allocator.smallCacheSize: 256
[DEBUG] 23:09:31.281 io.netty.buffer.PooledByteBufAllocator.<clinit>() - -Dio.netty.allocator.normalCacheSize: 64
[DEBUG] 23:09:31.281 io.netty.buffer.PooledByteBufAllocator.<clinit>() - -Dio.netty.allocator.maxCachedBufferCapacity: 32768
[DEBUG] 23:09:31.282 io.netty.buffer.PooledByteBufAllocator.<clinit>() - -Dio.netty.allocator.cacheTrimInterval: 8192
[DEBUG] 23:09:31.282 io.netty.buffer.PooledByteBufAllocator.<clinit>() - -Dio.netty.allocator.cacheTrimIntervalMillis: 0
[DEBUG] 23:09:31.282 io.netty.buffer.PooledByteBufAllocator.<clinit>() - -Dio.netty.allocator.useCacheForAllThreads: true
[DEBUG] 23:09:31.282 io.netty.buffer.PooledByteBufAllocator.<clinit>() - -Dio.netty.allocator.maxCachedByteBuffersPerChunk: 1023
[DEBUG] 23:09:31.291 io.netty.buffer.ByteBufUtil.<clinit>() - -Dio.netty.allocator.type: pooled
[DEBUG] 23:09:31.291 io.netty.buffer.ByteBufUtil.<clinit>() - -Dio.netty.threadLocalDirectBufferSize: 0
[DEBUG] 23:09:31.291 io.netty.buffer.ByteBufUtil.<clinit>() - -Dio.netty.maxThreadLocalCharBufferSize: 16384
[INFO ] 23:09:31.425 org.apache.plc4x.java.s7.readwrite.protocol.S7ProtocolLogic.onConnect() - S7 Driver running in ACTIVE mode.
[DEBUG] 23:09:31.426 org.apache.plc4x.java.s7.readwrite.protocol.S7ProtocolLogic.onConnect() - Sending COTP Connection Request
[DEBUG] 23:09:31.446 org.apache.plc4x.java.spi.Plc4xNettyWrapper.encode() - Forwarding request to plc TPKTPacket[payload=COTPPacketConnectionRequest[parameters={COTPParameterCalledTsap[tsapId=256],COTPParameterCallingTsap[tsapId=785],COTPParameterTpduSize[tpduSize=SIZE_1024]},payload=<null>,destinationReference=0,sourceReference=15,protocolClass=CLASS_0]]
[DEBUG] 23:09:31.450 io.netty.util.Recycler.<clinit>() - -Dio.netty.recycler.maxCapacityPerThread: 4096
[DEBUG] 23:09:31.450 io.netty.util.Recycler.<clinit>() - -Dio.netty.recycler.maxSharedCapacityFactor: 2
[DEBUG] 23:09:31.450 io.netty.util.Recycler.<clinit>() - -Dio.netty.recycler.linkCapacity: 16
[DEBUG] 23:09:31.450 io.netty.util.Recycler.<clinit>() - -Dio.netty.recycler.ratio: 8
[DEBUG] 23:09:31.457 io.netty.buffer.AbstractByteBuf.<clinit>() - -Dio.netty.buffer.checkAccessible: true
[DEBUG] 23:09:31.457 io.netty.buffer.AbstractByteBuf.<clinit>() - -Dio.netty.buffer.checkBounds: true
[DEBUG] 23:09:31.457 io.netty.util.ResourceLeakDetectorFactory.newResourceLeakDetector() - Loaded default ResourceLeakDetector: io.netty.util.ResourceLeakDetector@466425b5
[DEBUG] 23:09:31.480 org.apache.plc4x.java.spi.GeneratedDriverByteToMessageCodec.encode() - Sending bytes to PLC for message TPKTPacket[payload=COTPPacketConnectionRequest[parameters={COTPParameterCalledTsap[tsapId=256],COTPParameterCallingTsap[tsapId=785],COTPParameterTpduSize[tpduSize=SIZE_1024]},payload=<null>,destinationReference=0,sourceReference=15,protocolClass=CLASS_0]] as data 0300001611e00000000f00c2020100c1020311c0010a
[DEBUG] 23:09:31.601 org.apache.plc4x.java.s7.readwrite.protocol.S7ProtocolLogic.lambda$onConnect$9() - Got COTP Connection Response
[DEBUG] 23:09:31.601 org.apache.plc4x.java.s7.readwrite.protocol.S7ProtocolLogic.lambda$onConnect$9() - Sending S7 Connection Request
[DEBUG] 23:09:31.603 org.apache.plc4x.java.spi.Plc4xNettyWrapper.encode() - Forwarding request to plc TPKTPacket[payload=COTPPacketData[parameters=<null>,payload=S7MessageRequest[tpduReference=0,parameter=S7ParameterSetupCommunication[maxAmqCaller=8,maxAmqCallee=8,pduLength=1008],payload=<null>],eot=true,tpduRef=1]]
[DEBUG] 23:09:31.606 org.apache.plc4x.java.spi.GeneratedDriverByteToMessageCodec.encode() - Sending bytes to PLC for message TPKTPacket[payload=COTPPacketData[parameters=<null>,payload=S7MessageRequest[tpduReference=0,parameter=S7ParameterSetupCommunication[maxAmqCaller=8,maxAmqCallee=8,pduLength=1008],payload=<null>],eot=true,tpduRef=1]] as data 0300001902f08132010000000000080000f0000008000803f0
[DEBUG] 23:09:31.654 org.apache.plc4x.java.s7.readwrite.protocol.S7ProtocolLogic.lambda$onConnect$8() - Got S7 Connection Response
[DEBUG] 23:09:31.654 org.apache.plc4x.java.s7.readwrite.protocol.S7ProtocolLogic.lambda$onConnect$8() - Sending S7 Identification Request
[DEBUG] 23:09:31.660 org.apache.plc4x.java.spi.Plc4xNettyWrapper.encode() - Forwarding request to plc TPKTPacket[payload=COTPPacketData[parameters=<null>,payload=S7MessageUserData[tpduReference=1,parameter=S7ParameterUserData[items={S7ParameterUserDataItemCPUFunctions[method=17,cpuFunctionType=4,cpuFunctionGroup=4,cpuSubfunction=1,sequenceNumber=0,dataUnitReferenceNumber=<null>,lastDataUnit=<null>,errorCode=<null>]}],payload=S7PayloadUserData[items={S7PayloadUserDataItemCpuFunctionReadSzlRequest[returnCode=OK,transportSize=OCTET_STRING,szlId=SzlId[typeClass=CPU,sublistExtract=0,sublistList=MODULE_IDENTIFICATION],szlIndex=0]}]],eot=true,tpduRef=2]]
[DEBUG] 23:09:31.664 org.apache.plc4x.java.spi.GeneratedDriverByteToMessageCodec.encode() - Sending bytes to PLC for message TPKTPacket[payload=COTPPacketData[parameters=<null>,payload=S7MessageUserData[tpduReference=1,parameter=S7ParameterUserData[items={S7ParameterUserDataItemCPUFunctions[method=17,cpuFunctionType=4,cpuFunctionGroup=4,cpuSubfunction=1,sequenceNumber=0,dataUnitReferenceNumber=<null>,lastDataUnit=<null>,errorCode=<null>]}],payload=S7PayloadUserData[items={S7PayloadUserDataItemCpuFunctionReadSzlRequest[returnCode=OK,transportSize=OCTET_STRING,szlId=SzlId[typeClass=CPU,sublistExtract=0,sublistList=MODULE_IDENTIFICATION],szlIndex=0]}]],eot=true,tpduRef=2]] as data 0300002102f082320700000001000800080001120411440100ff09000400110000
[DEBUG] 23:09:31.715 org.apache.plc4x.java.s7.readwrite.protocol.S7ProtocolLogic.lambda$onConnect$7() - Got S7 Identification Response
[DEBUG] 23:09:31.716 org.pragmaticindustries.cockpit.plc.pool2.CachedDriverManager.lambda$getConnection_$0() - Connection successfully established
[DEBUG] 23:09:31.716 org.pragmaticindustries.cockpit.plc.pool2.CachedDriverManager.checkQueue() - Connection is available, checking if someone is waiting in the queue...
[DEBUG] 23:09:31.716 org.pragmaticindustries.cockpit.plc.pool2.CachedDriverManager.getConnection_() - Connection was requested and is available, thus, returning Chached Connection for usage
java.lang.UnsupportedOperationException
at org.pragmaticindustries.cockpit.plc.pool2.CachedPlcConnection.getMetadata(CachedPlcConnection.java:106)
at it.fox.datapicker.HelloPlc4x.main(HelloPlc4x.java:91)
2020-11-26 23:09:31,720 pool-1-thread-1 DEBUG Stopping LoggerContext[name=55054057, org.apache.logging.log4j.core.LoggerContext@2ca26d77]
2020-11-26 23:09:31,720 pool-1-thread-1 DEBUG Stopping LoggerContext[name=55054057, org.apache.logging.log4j.core.LoggerContext@2ca26d77]...
2020-11-26 23:09:31,723 pool-1-thread-1 DEBUG Shutting down OutputStreamManager SYSTEM_OUT.false.false
2020-11-26 23:09:31,724 pool-1-thread-1 DEBUG OutputStream closed
2020-11-26 23:09:31,724 pool-1-thread-1 DEBUG Shut down OutputStreamManager SYSTEM_OUT.false.false, all resources released: true
2020-11-26 23:09:31,724 pool-1-thread-1 DEBUG Appender Console stopped with status true
2020-11-26 23:09:31,724 pool-1-thread-1 DEBUG Stopped XmlConfiguration[location=/Users/fox/Documents/workspace/2020-06-30 - HelloPlc4x/bin/main/log4j2.xml] OK
2020-11-26 23:09:31,724 pool-1-thread-1 DEBUG Stopped LoggerContext[name=55054057, org.apache.logging.log4j.core.LoggerContext@2ca26d77] with status true
Did you spot some trouble ?
Regards,
Stefano