[
https://issues.apache.org/jira/browse/PLC4X-245?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=17192735#comment-17192735
]
Turker TUNALI commented on PLC4X-245:
-------------------------------------
Here it is.
2020-09-09 12:09:39,642 INFO [Timer-Driven Process Thread-2]
org.apache.plc4x.java.PlcDriverManager Instantiating new PLC Driver Manager
with class loader org.apache.nifi.nar.InstanceClassLoader@4f9a8d71
2020-09-09 12:09:39,643 INFO [Timer-Driven Process Thread-2]
org.apache.plc4x.java.PlcDriverManager Registering available drivers...
2020-09-09 12:09:39,648 INFO [Timer-Driven Process Thread-2]
org.apache.plc4x.java.PlcDriverManager Registering driver for Protocol ab-eth
(Allen Bradley ETH)
2020-09-09 12:09:39,650 INFO [Timer-Driven Process Thread-2]
org.apache.plc4x.java.PlcDriverManager Registering driver for Protocol ads
(Beckhoff TwinCat ADS)
2020-09-09 12:09:39,651 INFO [Timer-Driven Process Thread-2]
org.apache.plc4x.java.PlcDriverManager Registering driver for Protocol eip
(EthernetIP)
2020-09-09 12:09:39,655 INFO [Timer-Driven Process Thread-2]
org.apache.plc4x.java.PlcDriverManager Registering driver for Protocol
knxnet-ip (KNXNet/IP)
2020-09-09 12:09:39,657 INFO [Timer-Driven Process Thread-2]
org.apache.plc4x.java.PlcDriverManager Registering driver for Protocol modbus
(Modbus)
2020-09-09 12:09:39,660 INFO [Timer-Driven Process Thread-2]
org.apache.plc4x.java.PlcDriverManager Registering driver for Protocol opcua
(OPC UA (TCP))
2020-09-09 12:09:39,662 INFO [Timer-Driven Process Thread-2]
org.apache.plc4x.java.PlcDriverManager Registering driver for Protocol s7
(Siemens S7 (Basic))
2020-09-09 12:09:39,665 INFO [Timer-Driven Process Thread-2]
org.apache.plc4x.java.PlcDriverManager Registering driver for Protocol
simulated (Simulated PLC4X Datasource)
2020-09-09 12:09:39,784 INFO [Flow Service Tasks Thread-2]
o.a.nifi.controller.StandardFlowService Saved flow controller
org.apache.nifi.controller.FlowController@506b0933 // Another save pending =
false
2020-09-09 12:09:40,019 INFO [Timer-Driven Process Thread-2]
o.a.p.j.transport.tcp.TcpChannelFactory Configuring Bootstrap with
Configuration{}
2020-09-09 12:09:41,226 INFO [nioEventLoopGroup-2-1]
o.a.p.j.s.connection.NettyChannelFactory Unable to connect, shutting down
worker thread.
2020-09-09 12:09:41,230 ERROR [Timer-Driven Process Thread-2]
o.apache.plc4x.nifi.Plc4xSourceProcessor
Plc4xSourceProcessor[id=63c2c1f9-0174-1000-eb3b-2e4a85319f90] Failed to process
session due to org.apache.nifi.processor.exception.ProcessException: Got an
error while trying to get a connection:
org.apache.nifi.processor.exception.ProcessException: Got an error while trying
to get a connection
org.apache.nifi.processor.exception.ProcessException: Got an error while trying
to get a connection
at
org.apache.plc4x.nifi.Plc4xSourceProcessor.onTrigger(Plc4xSourceProcessor.java:85)
at
org.apache.nifi.processor.AbstractProcessor.onTrigger(AbstractProcessor.java:27)
at
org.apache.nifi.controller.StandardProcessorNode.onTrigger(StandardProcessorNode.java:1174)
at
org.apache.nifi.controller.tasks.ConnectableTask.invoke(ConnectableTask.java:213)
at
org.apache.nifi.controller.scheduling.TimerDrivenSchedulingAgent$1.run(TimerDrivenSchedulingAgent.java:117)
at org.apache.nifi.engine.FlowEngine$2.run(FlowEngine.java:110)
at java.util.concurrent.Executors$RunnableAdapter.call(Unknown Source)
at java.util.concurrent.FutureTask.runAndReset(Unknown Source)
at
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(Unknown
Source)
at
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(Unknown
Source)
at java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
at java.lang.Thread.run(Unknown Source)
Caused by: org.apache.plc4x.java.api.exceptions.PlcConnectionException:
org.apache.plc4x.java.api.exceptions.PlcConnectionException: Error creating
channel.
at
org.apache.plc4x.java.utils.connectionpool.PooledPlcDriverManager.getConnection(PooledPlcDriverManager.java:117)
at
org.apache.plc4x.java.utils.connectionpool.PooledPlcDriverManager.getConnection(PooledPlcDriverManager.java:100)
at
org.apache.plc4x.nifi.Plc4xSourceProcessor.onTrigger(Plc4xSourceProcessor.java:49)
... 12 common frames omitted
Caused by: org.apache.plc4x.java.api.exceptions.PlcConnectionException: Error
creating channel.
at
org.apache.plc4x.java.spi.connection.NettyChannelFactory.createChannel(NettyChannelFactory.java:133)
at
org.apache.plc4x.java.spi.connection.DefaultNettyPlcConnection.connect(DefaultNettyPlcConnection.java:89)
at
org.apache.plc4x.java.PlcDriverManager.getConnection(PlcDriverManager.java:74)
at
org.apache.plc4x.java.utils.connectionpool.PooledPlcDriverManager.access$201(PooledPlcDriverManager.java:37)
at
org.apache.plc4x.java.utils.connectionpool.PooledPlcDriverManager$1.create(PooledPlcDriverManager.java:89)
at
org.apache.plc4x.java.utils.connectionpool.PooledPlcDriverManager$1.create(PooledPlcDriverManager.java:82)
at
org.apache.commons.pool2.BaseKeyedPooledObjectFactory.makeObject(BaseKeyedPooledObjectFactory.java:62)
at
org.apache.commons.pool2.impl.GenericKeyedObjectPool.create(GenericKeyedObjectPool.java:1051)
at
org.apache.commons.pool2.impl.GenericKeyedObjectPool.borrowObject(GenericKeyedObjectPool.java:347)
at
org.apache.commons.pool2.impl.GenericKeyedObjectPool.borrowObject(GenericKeyedObjectPool.java:270)
at
org.apache.plc4x.java.utils.connectionpool.PooledPlcDriverManager.getConnection(PooledPlcDriverManager.java:115)
... 14 common frames omitted
Caused by: io.netty.channel.ConnectTimeoutException: connection timed out:
/10.0.2.238:502
at
io.netty.channel.nio.AbstractNioChannel$AbstractNioUnsafe$1.run(AbstractNioChannel.java:261)
at io.netty.util.concurrent.PromiseTask.runTask(PromiseTask.java:98)
at
io.netty.util.concurrent.ScheduledFutureTask.run(ScheduledFutureTask.java:170)
at
io.netty.util.concurrent.AbstractEventExecutor.safeExecute(AbstractEventExecutor.java:164)
at
io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:472)
at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:500)
at
io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:989)
at
io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74)
at
io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
... 1 common frames omitted
2020-09-09 12:09:41,293 INFO [pool-12-thread-1]
o.a.n.c.r.WriteAheadFlowFileRepository Initiating checkpoint of FlowFile
Repository
2020-09-09 12:09:41,293 INFO [pool-12-thread-1]
o.a.n.c.r.WriteAheadFlowFileRepository Successfully checkpointed FlowFile
Repository with 0 records in 0 milliseconds
2020-09-09 12:09:46,240 INFO [Timer-Driven Process Thread-1]
org.apache.plc4x.java.PlcDriverManager Instantiating new PLC Driver Manager
with class loader org.apache.nifi.nar.InstanceClassLoader@4f9a8d71
2020-09-09 12:09:46,240 INFO [Timer-Driven Process Thread-1]
org.apache.plc4x.java.PlcDriverManager Registering available drivers...
2020-09-09 12:09:46,241 INFO [Timer-Driven Process Thread-1]
org.apache.plc4x.java.PlcDriverManager Registering driver for Protocol ab-eth
(Allen Bradley ETH)
2020-09-09 12:09:46,242 INFO [Timer-Driven Process Thread-1]
org.apache.plc4x.java.PlcDriverManager Registering driver for Protocol ads
(Beckhoff TwinCat ADS)
2020-09-09 12:09:46,242 INFO [Timer-Driven Process Thread-1]
org.apache.plc4x.java.PlcDriverManager Registering driver for Protocol eip
(EthernetIP)
2020-09-09 12:09:46,243 INFO [Timer-Driven Process Thread-1]
org.apache.plc4x.java.PlcDriverManager Registering driver for Protocol
knxnet-ip (KNXNet/IP)
2020-09-09 12:09:46,244 INFO [Timer-Driven Process Thread-1]
org.apache.plc4x.java.PlcDriverManager Registering driver for Protocol modbus
(Modbus)
2020-09-09 12:09:46,244 INFO [Timer-Driven Process Thread-1]
org.apache.plc4x.java.PlcDriverManager Registering driver for Protocol opcua
(OPC UA (TCP))
2020-09-09 12:09:46,245 INFO [Timer-Driven Process Thread-1]
org.apache.plc4x.java.PlcDriverManager Registering driver for Protocol s7
(Siemens S7 (Basic))
2020-09-09 12:09:46,245 INFO [Timer-Driven Process Thread-1]
org.apache.plc4x.java.PlcDriverManager Registering driver for Protocol
simulated (Simulated PLC4X Datasource)
2020-09-09 12:09:46,253 INFO [Timer-Driven Process Thread-1]
o.a.p.j.transport.tcp.TcpChannelFactory Configuring Bootstrap with
Configuration{}
2020-09-09 12:09:50,192 INFO [NiFi Web Server-69]
o.a.n.c.s.StandardProcessScheduler Stopping
AttributesToJSON[id=01741004-6a5e-1f34-168a-d494a3ea8b2b]
2020-09-09 12:09:50,192 INFO [NiFi Web Server-69]
o.a.n.controller.StandardProcessorNode Stopping processor:
AttributesToJSON[id=01741004-6a5e-1f34-168a-d494a3ea8b2b]
2020-09-09 12:09:50,193 INFO [NiFi Web Server-69]
o.a.n.c.s.StandardProcessScheduler Stopping
PutFile[id=2f346a5e-0174-1000-9c77-788126fe62c4]
2020-09-09 12:09:50,193 INFO [Timer-Driven Process Thread-2]
o.a.n.c.s.TimerDrivenSchedulingAgent Stopped scheduling
AttributesToJSON[id=01741004-6a5e-1f34-168a-d494a3ea8b2b] to run
2020-09-09 12:09:50,193 INFO [NiFi Web Server-69]
o.a.n.controller.StandardProcessorNode Stopping processor:
PutFile[id=2f346a5e-0174-1000-9c77-788126fe62c4]
2020-09-09 12:09:50,194 INFO [NiFi Web Server-69]
o.a.n.c.s.StandardProcessScheduler Stopping
PutFile[id=01741000-6a5e-1f34-843d-a2685e260de0]
2020-09-09 12:09:50,194 INFO [NiFi Web Server-69]
o.a.n.controller.StandardProcessorNode Stopping processor:
PutFile[id=01741000-6a5e-1f34-843d-a2685e260de0]
2020-09-09 12:09:50,194 INFO [NiFi Web Server-69]
o.a.n.c.s.StandardProcessScheduler Stopping
PutFile[id=01741000-6a5e-1f34-db32-70113dcdabaf]
2020-09-09 12:09:50,194 INFO [NiFi Web Server-69]
o.a.n.controller.StandardProcessorNode Stopping processor:
PutFile[id=01741000-6a5e-1f34-db32-70113dcdabaf]
2020-09-09 12:09:50,194 INFO [NiFi Web Server-69]
o.a.n.c.s.StandardProcessScheduler Stopping
Plc4xSourceProcessor[id=63c2c1f9-0174-1000-eb3b-2e4a85319f90]
2020-09-09 12:09:50,194 INFO [NiFi Web Server-69]
o.a.n.controller.StandardProcessorNode Stopping processor:
Plc4xSourceProcessor[id=63c2c1f9-0174-1000-eb3b-2e4a85319f90]
2020-09-09 12:09:50,194 INFO [Timer-Driven Process Thread-10]
o.a.n.c.s.TimerDrivenSchedulingAgent Stopped scheduling
PutFile[id=2f346a5e-0174-1000-9c77-788126fe62c4] to run
2020-09-09 12:09:50,195 INFO [Timer-Driven Process Thread-7]
o.a.n.c.s.TimerDrivenSchedulingAgent Stopped scheduling
PutFile[id=01741000-6a5e-1f34-843d-a2685e260de0] to run
2020-09-09 12:09:50,195 INFO [Timer-Driven Process Thread-1]
o.a.n.c.s.TimerDrivenSchedulingAgent Stopped scheduling
Plc4xSourceProcessor[id=63c2c1f9-0174-1000-eb3b-2e4a85319f90] to run
2020-09-09 12:09:50,195 INFO [Timer-Driven Process Thread-4]
o.a.n.c.s.TimerDrivenSchedulingAgent Stopped scheduling
PutFile[id=01741000-6a5e-1f34-db32-70113dcdabaf] to run
2020-09-09 12:09:50,324 INFO [Flow Service Tasks Thread-1]
o.a.nifi.controller.StandardFlowService Saved flow controller
org.apache.nifi.controller.FlowController@506b0933 // Another save pending =
false
2020-09-09 12:10:01,294 INFO [pool-12-thread-1]
o.a.n.c.r.WriteAheadFlowFileRepository Initiating checkpoint of FlowFile
Repository
2020-09-09 12:10:01,296 INFO [pool-12-thread-1]
o.a.n.wali.SequentialAccessWriteAheadLog Checkpointed Write-Ahead Log with 0
Records and 0 Swap Files in 2 milliseconds (Stop-the-world time = 1
milliseconds), max Transaction ID 896
2020-09-09 12:10:01,297 INFO [pool-12-thread-1]
o.a.n.c.r.WriteAheadFlowFileRepository Successfully checkpointed FlowFile
Repository with 0 records in 2 milliseconds
> [Modbus] Apache NiFi processor throws java.io.IOException after a while
> -----------------------------------------------------------------------
>
> Key: PLC4X-245
> URL: https://issues.apache.org/jira/browse/PLC4X-245
> Project: Apache PLC4X
> Issue Type: Bug
> Components: Driver-Modbus, Integration-NiFi
> Affects Versions: 0.7.0
> Environment: Apache NiFi 1.12.0, Win2012 Server, PLX4X Nar 0.7.0
> (https://mvnrepository.com/artifact/org.apache.plc4x/plc4j-nifi-plc4x-nar/0.7.0)
> Reporter: Turker TUNALI
> Priority: Major
> Attachments: modbustrace_200828.pcapng, modbustrace_200828_4.pcapng,
> nifi-app.log
>
> Original Estimate: 48h
> Remaining Estimate: 48h
>
> My Plc4xSourceProcessor's, PLC connection String is
> "modbus:tcp://[10.0.2.238:502?slave=1|http://10.0.2.238:502/?slave=1]"; and
> PLC resource address String is "test1=holding-register:1"
>
> I can get the values for 5-10 times with 5 second intervals but then I get
> below exception. I can read the values with the Modbus Poll application, so
> most probably the PLC4X side has a problem.
>
> I may also get some other exceptions when starting the processor, which are
> also below.
>
> PS: Wireshark trace is attached. I've read 16 times then I get the exception.
>
> *
> -- This is the exception which I get after some successful read operations.*
> 2020-08-27 13:19:06,091 WARN [nioEventLoopGroup-8-1]
> io.netty.channel.DefaultChannelPipeline An exceptionCaught() event was fired,
> and it reached at the tail of the pipeline. It usually means the last handler
> in the pipeline did not handle the exception.
> java.io.IOException: An existing connection was forcibly closed by the
> remote host
> at sun.nio.ch.SocketDispatcher.read0(Native Method)
> at sun.nio.ch.SocketDispatcher.read(Unknown Source)
> at sun.nio.ch.IOUtil.readIntoNativeBuffer(Unknown Source)
> at sun.nio.ch.IOUtil.read(Unknown Source)
> at sun.nio.ch.SocketChannelImpl.read(Unknown Source)
> at io.netty.buffer.PooledByteBuf.setBytes(PooledByteBuf.java:253)
> at io.netty.buffer.AbstractByteBuf.writeBytes(AbstractByteBuf.java:1133)
> at
> io.netty.channel.socket.nio.NioSocketChannel.doReadBytes(NioSocketChannel.java:350)
> at
> io.netty.channel.nio.AbstractNioByteChannel$NioByteUnsafe.read(AbstractNioByteChannel.java:148)
> at
> io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:714)
> at
> io.netty.channel.nio.NioEventLoop.processSelectedKeysOptimized(NioEventLoop.java:650)
> at
> io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:576)
> at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:493)
> at
> io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:989)
> at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74)
> at
> io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
> at java.lang.Thread.run(Unknown Source)
>
>
> -- This is the exception which I get sometimes when starting up the
> processor.*
> 2020-08-27 13:17:16,813 WARN [Timer-Driven Process Thread-11]
> o.a.n.controller.tasks.ConnectableTask Administratively Yielding
> Plc4xSourceProcessor[id=2f12f5b4-0174-1000-724e-a53ba0fc1652] due to uncaught
> Exception: java.lang.NullPointerException
> java.lang.NullPointerException: null
> at
> org.apache.plc4x.nifi.Plc4xSourceProcessor.onTrigger(Plc4xSourceProcessor.java:50)
> at
> org.apache.nifi.processor.AbstractProcessor.onTrigger(AbstractProcessor.java:27)
> at
> org.apache.nifi.controller.StandardProcessorNode.onTrigger(StandardProcessorNode.java:1174)
> at
> org.apache.nifi.controller.tasks.ConnectableTask.invoke(ConnectableTask.java:213)
> at
> org.apache.nifi.controller.scheduling.TimerDrivenSchedulingAgent$1.run(TimerDrivenSchedulingAgent.java:117)
> at org.apache.nifi.engine.FlowEngine$2.run(FlowEngine.java:110)
> at java.util.concurrent.Executors$RunnableAdapter.call(Unknown Source)
> at java.util.concurrent.FutureTask.runAndReset(Unknown Source)
> at
> java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(Unknown
> Source)
> at
> java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(Unknown
> Source)
> at java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source)
> at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
> at java.lang.Thread.run(Unknown Source)
--
This message was sent by Atlassian Jira
(v8.3.4#803005)
