Julian, thank you so much for your attention on this. Your code changes
look good but unfortunately I am still experiencing the problem.
Here is some log output from my program. You can see that the close is
called on the DefaultNettyPlcConnection, but I do not see the output from
your code modification that I would expect if the closeEventLoopForChannel
method was being called (Either logger.info("Channel is closed, closing
worker Group also") or logger.warn("Trying to remove EventLoop for Channel
{} but have none stored", channel).
The nioEventLoopGroup threads continue to persist after every
plcConnection.
I hope I have built everything correctly...I checked out your branch with:
git clone --single-branch --branch bugfix/close-eventloop-after-channel
https://github.com/apache/plc4x.git
And wiped out my local m2 maven repository before building the code with:
./mvnw install -DskipTests
I also removed references to the apache snapshot repo from my project pom
and by all appearances I am using the correct 0.8.0-SNAPSHOT jars that are
locally built in my local m2 repo. Here is some log info from my test:
2020-08-24_10:15:43.450 DEBUG PooledPlcDriverManager - Try to borrow an
object for url modbus://192.168.0.5:503?unit-identifier=50
2020-08-24_10:15:43.452 INFO TcpChannelFactory - Configuring Bootstrap
with Configuration{}
2020-08-24_10:15:43.458 DEBUG ModbusManager - Connection Metadata:
2020-08-24_10:15:43.459 DEBUG ModbusManager -
org.apache.plc4x.java.spi.connection.DefaultNettyPlcConnection@185c140
2020-08-24_10:15:43.462 DEBUG Plc4xNettyWrapper - Forwarding request to plc
ModbusTcpADU[transactionIdentifier=10,unitIdentifier=50,pdu=ModbusPDUReadHoldingRegistersRequest[startingAddress=67,quantity=1]]
2020-08-24_10:15:43.466 DEBUG GeneratedDriverByteToMessageCodec - Sending
bytes to PLC for message
ModbusTcpADU[transactionIdentifier=10,unitIdentifier=50,pdu=ModbusPDUReadHoldingRegistersRequest[startingAddress=67,quantity=1]]
as data 000a00000006320300430001
2020-08-24_10:15:43.470 DEBUG Plc4xNettyWrapper - Forwarding request to plc
ModbusTcpADU[transactionIdentifier=11,unitIdentifier=50,pdu=ModbusPDUReadHoldingRegistersRequest[startingAddress=69,quantity=1]]
2020-08-24_10:15:43.471 DEBUG GeneratedDriverByteToMessageCodec - Sending
bytes to PLC for message
ModbusTcpADU[transactionIdentifier=11,unitIdentifier=50,pdu=ModbusPDUReadHoldingRegistersRequest[startingAddress=69,quantity=1]]
as data 000b00000006320300450001
2020-08-24_10:15:43.480 DEBUG Plc4xNettyWrapper - Forwarding request to plc
ModbusTcpADU[transactionIdentifier=12,unitIdentifier=50,pdu=ModbusPDUReadHoldingRegistersRequest[startingAddress=68,quantity=1]]
2020-08-24_10:15:43.481 DEBUG GeneratedDriverByteToMessageCodec - Sending
bytes to PLC for message
ModbusTcpADU[transactionIdentifier=12,unitIdentifier=50,pdu=ModbusPDUReadHoldingRegistersRequest[startingAddress=68,quantity=1]]
as data 000c00000006320300440001
2020-08-24_10:15:43.484 DEBUG Plc4xNettyWrapper - Forwarding request to plc
ModbusTcpADU[transactionIdentifier=13,unitIdentifier=50,pdu=ModbusPDUReadHoldingRegistersRequest[startingAddress=66,quantity=1]]
2020-08-24_10:15:43.485 DEBUG GeneratedDriverByteToMessageCodec - Sending
bytes to PLC for message
ModbusTcpADU[transactionIdentifier=13,unitIdentifier=50,pdu=ModbusPDUReadHoldingRegistersRequest[startingAddress=66,quantity=1]]
as data 000d00000006320300420001
2020-08-24_10:15:43.489 DEBUG PooledPlcDriverManager - close called on
org.apache.plc4x.java.spi.connection.DefaultNettyPlcConnection@185c140
2020-08-24_10:15:43.490 INFO ReadModbusTask - Read Modbus Task Completed.
Some details from my code:
Getting the connection:
PlcConnection plcConnection =
pooledDriverManager.getConnection(modbusServerURI);
if (plcConnection.isConnected()) {
LOG.trace("The connection is connected");
} else {
LOG.trace("The connection is not connected. Connecting
now...");
plcConnection.connect();
}
Reading the plc and closing the connection:
PlcReadRequest.Builder builder = plcConnection.readRequestBuilder();
builder.addItem("devicename", "holding-register:1[8]");
builder.addItem("generatorstate", "holding-register:67");
builder.addItem("batteryvoltage", "holding-register:513[2]");
builder.addItem("batterycurrent", "holding-register:515[2]");
builder.addItem("pvpowerwatts", "holding-register:69[2]");
builder.addItem("pvinputthishourkwh", "holding-register:307[2]");
PlcReadRequest readRequest = builder.build();
PlcReadResponse response;
try {
response = readRequest.execute().get(5, TimeUnit.SECONDS);
//process response
catch (InterruptedException | ExecutionException | TimeoutException ex) {
LOG.error("Error in executing gateway read - interrupted or
timed out", ex);
}
} finally {
plcConnection.close();
} catch (Exception ex) {
LOG.error("Error closing modbus connection", ex);
}
}
Other details:
openjdk version: "13.0.2" 2020-01-15
Linux Version:
PRETTY_NAME="Raspbian GNU/Linux 10 (buster)"
NAME="Raspbian GNU/Linux"
VERSION="10 (buster)"
On Mon, Aug 24, 2020 at 4:39 AM Julian Feinauer <
j.feina...@pragmaticminds.de> wrote:
> Hi,
>
> short feedback. I looked into the code and indeed it seems that we had a
> bug there which could lead tot he socket leak you described.
> I pushed a fix in the branch:
>
> https://github.com/apache/plc4x/tree/bugfix/close-eventloop-after-channel
>
> Would you mind taking a look and testing this with your code @Adam Rossi?
>
> Thanks!
> Juliasn
>
> Am 24.08.20, 08:26 schrieb "Julian Feinauer" <
> j.feina...@pragmaticminds.de>:
>
> Perhaps, some related questions:
>
> - You are using Linux for your Tests?
> - Do you close all Connections properly?
> Normally the `PlcConnection.close()` method should close the EventLoop.
>
> Julian
>
> Am 24.08.20, 08:23 schrieb "Julian Feinauer" <
> j.feina...@pragmaticminds.de>:
>
> Hi Adam,
>
> I will have a look today!
>
> Do we have a Jira Issue for it already?
>
> Julian
>
> Am 24.08.20, 07:38 schrieb "Christofer Dutz" <
> christofer.d...@c-ware.de>:
>
> Hi Adam,
>
> of course that's unfortunate ... also I will not be able to
> address this issue soon as I have to work on the tasks of my research
> project.
> I have one more month to work on this and I'm months behind
> schedule because I have been doing free support way too much lately.
>
> I really hope Julian will be able to help ... he's way more
> into the details of Netty than I am (cause he's got the book ;-) )
>
> So Julian? ... it would be super awesome if you could take on
> this issue.
>
> Chris
>
>
>
> Am 24.08.20, 00:17 schrieb "Adam Rossi" <ac.ro...@gmail.com>:
>
> Thanks, I did test with 0.8.0-SNAPSHOT and see the same
> behavior. In every
> plcConnection a nioEventLoopGroup thread is created and
> does not ever seem
> to be destroyed.
>
> I wish I understood the io.netty.channel.EventLoopGroup
> class better to be
> more helpful here. Would an example program that
> reproduces this thread
> leak be useful?
>
> jconsole shows the thread data as:
>
> Name: nioEventLoopGroup-19-1
> State: RUNNABLE
> Total blocked: 0 Total waited: 0
>
> Stack trace:
> java.base@13.0.2/sun.nio.ch.EPoll.wait(Native Method)
> java.base@13.0.2
>
> /sun.nio.ch.EPollSelectorImpl.doSelect(EPollSelectorImpl.java:120)
> java.base@13.0.2
>
> /sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:124)
> - locked
> io.netty.channel.nio.SelectedSelectionKeySet@1838f97
> - locked sun.nio.ch.EPollSelectorImpl@1f49287
> java.base@13.0.2/sun.nio.ch
> .SelectorImpl.select(SelectorImpl.java:141)
>
> app//io.netty.channel.nio.SelectedSelectionKeySetSelector.select(SelectedSelectionKeySetSelector.java:68)
>
> app//io.netty.channel.nio.NioEventLoop.select(NioEventLoop.java:803)
>
> app//io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:457)
>
> app//io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:989)
>
> app//io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74)
>
> app//io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
> java.base@13.0.2/java.lang.Thread.run(Thread.java:830)
>
>
> Regards, Adam
>
> On Sun, Aug 23, 2020 at 1:00 PM Christofer Dutz <
> christofer.d...@c-ware.de>
> wrote:
>
> > Hi Adam,
> >
> > the Apache SNAPSHOT repo is at:
> >
> https://repository.apache.org/content/repositories/snapshots
> >
> > Adding this to your pom should help:
> >
> > <!-- Make Snapshots of Apache projects available -->
> > <repositories>
> > <repository>
> > <id>apache-snapshots</id>
> > <url>
> https://repository.apache.org/content/repositories/snapshots
> > </url>
> > <releases>
> > <enabled>false</enabled>
> > </releases>
> > <snapshots>
> > <enabled>true</enabled>
> > </snapshots>
> > </repository>
> > </repositories>
> >
> > <!-- Make Snapshots of Apache plugins available -->
> > <pluginRepositories>
> > <pluginRepository>
> > <id>apache-snapshots</id>
> > <url>
> https://repository.apache.org/content/repositories/snapshots
> > </url>
> > <releases>
> > <enabled>false</enabled>
> > </releases>
> > <snapshots>
> > <enabled>true</enabled>
> > </snapshots>
> > </pluginRepository>
> > </pluginRepositories>
> >
> > Chris
> > Am 23.08.20, 18:56 schrieb "Adam Rossi" <
> ac.ro...@gmail.com>:
> >
> > Sure thing. Is 0.8.0-snapshot hosted anywhere or is
> that something
> > that needs to be built? Regards Adam
> >
> > > On Aug 23, 2020, at 12:31 PM, Christofer Dutz <
> > christofer.d...@c-ware.de> wrote:
> > >
> > > Hmm ...
> > >
> > > Could you possibly give 0.8.0-SNAPSHOT a try? ....
> or 0.6.x? ...
> > 0.7.0 was the first of the new generation drivers. We're
> maintaining the
> > 0.6 branch and working hard on making the new generation
> drivers 100%
> > production ready.
> > >
> > > Chris
> > >
> > >
> > > Am 23.08.20, 18:06 schrieb "Adam Rossi" <
> ac.ro...@gmail.com>:
> > >
> > > This is the latest 0.7.0 release from Maven.
> > >
> > >
> > > Regards Adam
> > >
> > >> On Aug 23, 2020, at 11:56 AM, Christofer Dutz <
> > christofer.d...@c-ware.de> wrote:
> > >>
> > >> Hi Adam,
> > >>
> > >> which version of PLC4X are you using? I know we
> had similar reports
> > some time ago, but had thought we had fixed them
> > >>
> > >> Chris
> > >>
> > >>
> > >>
> > >> Am 23.08.20, 16:40 schrieb "Adam Rossi" <
> ac.ro...@gmail.com>:
> > >>
> > >> Howdy. I am seeing a persistent thread being
> created for every
> > >> plcConnection connect which looks like the
> following:
> > >>
> > >> Name: nioEventLoopGroup-11-1
> > >> State: RUNNABLE
> > >> Total blocked: 0 Total waited: 0
> > >>
> > >> Stack trace:
> > >> java.base@13.0.2/sun.nio.ch.EPoll.wait(Native
> Method)
> > >> java.base@13.0.2
> > >>
> /sun.nio.ch.EPollSelectorImpl.doSelect(EPollSelectorImpl.java:120)
> > >> java.base@13.0.2
> > >>
> /sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:124)
> > >> - locked
> io.netty.channel.nio.SelectedSelectionKeySet@f6df6b
> > >> - locked sun.nio.ch.EPollSelectorImpl@7ffc19
> > >> java.base@13.0.2/sun.nio.ch
> > .SelectorImpl.select(SelectorImpl.java:141)
> > >>
> >
> app//io.netty.channel.nio.SelectedSelectionKeySetSelector.select(SelectedSelectionKeySetSelector.java:68)
> > >>
> >
> app//io.netty.channel.nio.NioEventLoop.select(NioEventLoop.java:803)
> > >>
> app//io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:457)
> > >>
> >
> app//io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:989)
> > >>
> >
> app//io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74)
> > >>
> >
> app//io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
> > >> java.base@13.0.2
> /java.lang.Thread.run(Thread.java:830)
> > >>
> > >>
> > >> This happens both when creating a connection
> directly or when
> > using the
> > >> plc4x connection pool.
> > >>
> > >> In both cases I am obtaining the connection,
> reading some modbus
> > values,
> > >> and then closing the connection. From the
> plcConnection metadata
> > the
> > >> connection type I am using is:
> > >>
> > >>
> org.apache.plc4x.java.spi.connection.DefaultNettyPlcConnection
> > >>
> > >> Over time thousands of these nioEventLoopGroup
> threads are
> > created and I
> > >> experience an OutOfMemory error in my program.
> > >>
> > >> Has anyone experienced this problem? Is there a
> way to force
> > these threads
> > >> to close, timeout, or to specify the total
> thread limit?
> > >>
> > >> Thanks and Regards, Adam
> > >>
> > >
> >
> >
>
>
>
>
>
