You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@plc4x.apache.org by "Julian Feinauer (Jira)" <ji...@apache.org> on 2019/12/05 12:16:00 UTC

[jira] [Comment Edited] (PLC4X-158) Too many open files after less than 24 hours of Scraper use

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

Julian Feinauer edited comment on PLC4X-158 at 12/5/19 12:15 PM:
-----------------------------------------------------------------

Ah, nice, thanks [~swiendl]. I think I already spotted the issue (although I do not yet fully understand it).
In the scraper we always open a connection and close it afterwards as its intended to run with a Connection Pool. But you use it without (our fault, bad javadoc). So this is the "expected" behavior. I do not understand why this leads to leaking sockets yet, but you can shut that definetly down by using a pool.
Here is an example of our Spring Boot Config with plc4x

{code:java}
    @Bean
    public PlcDriverManager plcDriverManager() {
        long connectionTimeoutMs = 1_000;
        return pooledPlcDriverManager(connectionTimeoutMs);
    }

    // Bean like definition
    private PooledPlcDriverManager pooledPlcDriverManager(long connectionTimeoutMs) {
        return new PooledPlcDriverManager(pooledPlcConnectionFactory -> {
            GenericKeyedObjectPoolConfig<PlcConnection> poolConfig = new GenericKeyedObjectPoolConfig<>();
            // This makes it robust for PLCs which allow only one connection
            poolConfig.setMaxTotalPerKey(1);
            // When the connecton is in use and is requested block some time until a
            // NoSuchElementException is thrown
            poolConfig.setBlockWhenExhausted(true);
            poolConfig.setMaxWaitMillis(connectionTimeoutMs);
            return new GenericKeyedObjectPool<>(pooledPlcConnectionFactory, poolConfig);
        });
    }
{code}

Its a copy from our setting (probably a semicolon or so is missing, I just delted our specific custom extensions for monitoring). But you should basically just have to use this bean as driverManager in your code and all problems should go away.



was (Author: julian.feinauer):
Ah, nice, thanks [~swiendl]. I think I already spotted the issue (although I do not yet fully understand it).
In the scraper we always open a connection and close it afterwards as its intended to run with a Connection Pool. But you use it without (our fault, bad javadoc). So this is the "expected" behavior. I do not understand why this leads to leaking sockets yet, but you can shut that definetly down by using a pool.
Here is an example of our Spring Boot Config with plc4x

{code:java}
    @Bean
    public PlcDriverManager plcDriverManager() {
        long connectionTimeoutMs = 1_000;
        final PrometheusPlcMonitor monitor = plcMonitor();
        return pooledPlcDriverManager(connectionTimeoutMs);
    }

    // Bean like definition
    private PooledPlcDriverManager pooledPlcDriverManager(long connectionTimeoutMs) {
        return new PooledPlcDriverManager(pooledPlcConnectionFactory -> {
            GenericKeyedObjectPoolConfig<PlcConnection> poolConfig = new GenericKeyedObjectPoolConfig<>();
            // This makes it robust for PLCs which allow only one connection
            poolConfig.setMaxTotalPerKey(1);
            // When the connecton is in use and is requested block some time until a
            // NoSuchElementException is thrown
            poolConfig.setBlockWhenExhausted(true);
            poolConfig.setMaxWaitMillis(connectionTimeoutMs);
            return new GenericKeyedObjectPool<>(pooledPlcConnectionFactory, poolConfig);
        });
    }
{code}

Its a copy from our setting (probably a semicolon or so is missing, I just delted our specific custom extensions for monitoring). But you should basically just have to use this bean as driverManager in your code and all problems should go away.


> Too many open files after less than 24 hours of Scraper use
> -----------------------------------------------------------
>
>                 Key: PLC4X-158
>                 URL: https://issues.apache.org/jira/browse/PLC4X-158
>             Project: Apache PLC4X
>          Issue Type: Bug
>          Components: Util-Scraper
>    Affects Versions: 0.5.0
>            Reporter: Sebastian Wiendl
>            Priority: Major
>
> After less than 24 hours of scraping 9 fields every 100 ms PLC4J starts spewing the following exceptions:{code}2019-12-03 12:35:42.352  WARN 7481 --- [triggeredscraper-scheduling-thread-9] o.a.p.j.s.t.TriggeredScraperTask         : Exception during scraping of Job example, Connection-Alias S7: Error-message: null - for stack-trace change logging to DEBUG
> 2019-12-03 12:35:42.352  INFO 7481 --- [triggeredscraper-executor-thread-5] o.a.p.j.s7.connection.S7PlcConnection    : Setting up S7 Connection with: host-name 172.30.74.65, rack 0, slot 0, pdu-size 1024, max-amq-caller 8, max-amq-callee 8
> 2019-12-03 12:35:42.355  WARN 7481 --- [triggeredscraper-executor-thread-4] o.a.p.j.s.t.TriggeredScraperImpl         : Unable to instantiate connection to s7://172.30.74.65/0/0
> 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) ~[plc4j-connection-pool-0.5.0.jar!/:0.5.0]
> 	at org.apache.plc4x.java.utils.connectionpool.PooledPlcDriverManager.getConnection(PooledPlcDriverManager.java:100) ~[plc4j-connection-pool-0.5.0.jar!/:0.5.0]
> 	at org.apache.plc4x.java.scraper.triggeredscraper.TriggeredScraperImpl.lambda$getPlcConnection$2(TriggeredScraperImpl.java:300) ~[plc4j-scraper-0.5.0.jar!/:0.5.0]
> 	at java.util.concurrent.CompletableFuture$AsyncSupply.run(CompletableFuture.java:1590) ~[na:1.8.0_201]
> 	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) ~[na:1.8.0_201]
> 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) ~[na:1.8.0_201]
> 	at java.lang.Thread.run(Thread.java:748) ~[na:1.8.0_201]
> Caused by: org.apache.plc4x.java.api.exceptions.PlcConnectionException: Error creating channel.
> 	at org.apache.plc4x.java.tcp.connection.TcpSocketChannelFactory.createChannel(TcpSocketChannelFactory.java:87) ~[plc4j-protocol-driver-base-tcp-0.5.0.jar!/:0.5.0]
> 	at org.apache.plc4x.java.base.connection.NettyPlcConnection.connect(NettyPlcConnection.java:67) ~[plc4j-protocol-driver-base-0.5.0.jar!/:0.5.0]
> 	at org.apache.plc4x.java.PlcDriverManager.getConnection(PlcDriverManager.java:73) ~[plc4j-api-0.5.0.jar!/:0.5.0]
> 	at org.apache.plc4x.java.utils.connectionpool.PooledPlcDriverManager.access$201(PooledPlcDriverManager.java:37) ~[plc4j-connection-pool-0.5.0.jar!/:0.5.0]
> 	at org.apache.plc4x.java.utils.connectionpool.PooledPlcDriverManager$1.create(PooledPlcDriverManager.java:89) ~[plc4j-connection-pool-0.5.0.jar!/:0.5.0]
> 	at org.apache.plc4x.java.utils.connectionpool.PooledPlcDriverManager$1.create(PooledPlcDriverManager.java:82) ~[plc4j-connection-pool-0.5.0.jar!/:0.5.0]
> 	at org.apache.commons.pool2.BaseKeyedPooledObjectFactory.makeObject(BaseKeyedPooledObjectFactory.java:60) ~[commons-pool2-2.7.0.jar!/:2.7.0]
> 	at org.apache.commons.pool2.impl.GenericKeyedObjectPool.create(GenericKeyedObjectPool.java:1041) ~[commons-pool2-2.7.0.jar!/:2.7.0]
> 	at org.apache.commons.pool2.impl.GenericKeyedObjectPool.borrowObject(GenericKeyedObjectPool.java:342) ~[commons-pool2-2.7.0.jar!/:2.7.0]
> 	at org.apache.commons.pool2.impl.GenericKeyedObjectPool.borrowObject(GenericKeyedObjectPool.java:265) ~[commons-pool2-2.7.0.jar!/:2.7.0]
> 	at org.apache.plc4x.java.utils.connectionpool.PooledPlcDriverManager.getConnection(PooledPlcDriverManager.java:115) ~[plc4j-connection-pool-0.5.0.jar!/:0.5.0]
> 	... 6 common frames omitted
> Caused by: java.lang.IllegalStateException: failed to create a child event loop
> 	at io.netty.util.concurrent.MultithreadEventExecutorGroup.<init>(MultithreadEventExecutorGroup.java:88) ~[netty-common-4.1.43.Final.jar!/:4.1.43.Final]
> 	at io.netty.util.concurrent.MultithreadEventExecutorGroup.<init>(MultithreadEventExecutorGroup.java:58) ~[netty-common-4.1.43.Final.jar!/:4.1.43.Final]
> 	at io.netty.channel.MultithreadEventLoopGroup.<init>(MultithreadEventLoopGroup.java:52) ~[netty-transport-4.1.43.Final.jar!/:4.1.43.Final]
> 	at io.netty.channel.nio.NioEventLoopGroup.<init>(NioEventLoopGroup.java:88) ~[netty-transport-4.1.43.Final.jar!/:4.1.43.Final]
> 	at io.netty.channel.nio.NioEventLoopGroup.<init>(NioEventLoopGroup.java:83) ~[netty-transport-4.1.43.Final.jar!/:4.1.43.Final]
> 	at io.netty.channel.nio.NioEventLoopGroup.<init>(NioEventLoopGroup.java:64) ~[netty-transport-4.1.43.Final.jar!/:4.1.43.Final]
> 	at io.netty.channel.nio.NioEventLoopGroup.<init>(NioEventLoopGroup.java:52) ~[netty-transport-4.1.43.Final.jar!/:4.1.43.Final]
> 	at io.netty.channel.nio.NioEventLoopGroup.<init>(NioEventLoopGroup.java:44) ~[netty-transport-4.1.43.Final.jar!/:4.1.43.Final]
> 	at org.apache.plc4x.java.tcp.connection.TcpSocketChannelFactory.createChannel(TcpSocketChannelFactory.java:58) ~[plc4j-protocol-driver-base-tcp-0.5.0.jar!/:0.5.0]
> 	... 16 common frames omitted
> Caused by: io.netty.channel.ChannelException: failed to open a new selector
> 	at io.netty.channel.nio.NioEventLoop.openSelector(NioEventLoop.java:181) ~[netty-transport-4.1.43.Final.jar!/:4.1.43.Final]
> 	at io.netty.channel.nio.NioEventLoop.<init>(NioEventLoop.java:147) ~[netty-transport-4.1.43.Final.jar!/:4.1.43.Final]
> 	at io.netty.channel.nio.NioEventLoopGroup.newChild(NioEventLoopGroup.java:138) ~[netty-transport-4.1.43.Final.jar!/:4.1.43.Final]
> 	at io.netty.channel.nio.NioEventLoopGroup.newChild(NioEventLoopGroup.java:37) ~[netty-transport-4.1.43.Final.jar!/:4.1.43.Final]
> 	at io.netty.util.concurrent.MultithreadEventExecutorGroup.<init>(MultithreadEventExecutorGroup.java:84) ~[netty-common-4.1.43.Final.jar!/:4.1.43.Final]
> 	... 24 common frames omitted
> Caused by: java.io.IOException: Too many open files
> 	at sun.nio.ch.IOUtil.makePipe(Native Method) ~[na:1.8.0_201]
> 	at sun.nio.ch.EPollSelectorImpl.<init>(EPollSelectorImpl.java:65) ~[na:1.8.0_201]
> 	at sun.nio.ch.EPollSelectorProvider.openSelector(EPollSelectorProvider.java:36) ~[na:1.8.0_201]
> 	at io.netty.channel.nio.NioEventLoop.openSelector(NioEventLoop.java:179) ~[netty-transport-4.1.43.Final.jar!/:4.1.43.Final]
> 	... 28 common frames omitted
> {code}Any ideas whats causing this and how to fix?



--
This message was sent by Atlassian Jira
(v8.3.4#803005)