VertxJVMEventChannel could not be instantiated

[zheng-kai]

Describe the bug
When I frequently use GCToolKit to analyze GC logs in a program, it throws an error: VertxJVMEventChannel could not be instantiated. It appears that GCToolKit fails to close certain connections, which ultimately leads to this error.

To Reproduce
Steps to reproduce the behavior:

1. Download Main.java and gc_11_par.log:
   gc_11_par.log

public class Main {
    public static void main(String[] args) throws IOException, InterruptedException {
        String gcLogFile = "D:\\gc_11_par.log";
        if (gcLogFile.isBlank()) {
            throw new IllegalArgumentException("This sample requires a path to a GC log file.");
        }
        if (Files.notExists(Path.of(gcLogFile))) {
            throw new IllegalArgumentException(String.format("File %s not found.", gcLogFile));
        }
        for (int i = 0; i < 1000; i++) {
            System.out.println(i);
            Main main = new Main();
            main.analyze(gcLogFile);
        }
    }

    public void analyze(String gcLogFile) throws IOException {
        GCLogFile logFile = new SingleGCLogFile(Path.of(gcLogFile));
        GCToolKit gcToolKit = new GCToolKit();
        gcToolKit.loadAggregationsFromServiceLoader();
        JavaVirtualMachine machine = gcToolKit.analyze(logFile);
    }
}

2. Compiler and run Main.class with JDK11.
   On my computer, the error occurs around the 200th loop iteration. Here is the ERROR message:

Exception in thread "main" java.util.ServiceConfigurationError: com.microsoft.gctoolkit.message.JVMEventChannel: Provider com.microsoft.gctoolkit.vertx.VertxJVMEventChannel could not be instantiated
	at java.base/java.util.ServiceLoader.fail(ServiceLoader.java:582)
	at java.base/java.util.ServiceLoader$ProviderImpl.newInstance(ServiceLoader.java:804)
	at java.base/java.util.ServiceLoader$ProviderImpl.get(ServiceLoader.java:722)
	at java.base/java.util.ServiceLoader$3.next(ServiceLoader.java:1395)
	at java.base/java.util.ServiceLoader.findFirst(ServiceLoader.java:1810)
	at [email protected]/com.microsoft.gctoolkit.GCToolKit.loadJVMEventChannel(GCToolKit.java:179)
	at [email protected]/com.microsoft.gctoolkit.GCToolKit.loadDataSourceParsers(GCToolKit.java:224)
	at [email protected]/com.microsoft.gctoolkit.GCToolKit.analyze(GCToolKit.java:304)
	at Test/groupId.Main.analyze(Main.java:32)
	at Test/groupId.Main.main(Main.java:24)
Caused by: java.lang.IllegalStateException: failed to create a child event loop
	at io.netty.util.concurrent.MultithreadEventExecutorGroup.<init>(MultithreadEventExecutorGroup.java:88)
	at io.netty.util.concurrent.MultithreadEventExecutorGroup.<init>(MultithreadEventExecutorGroup.java:60)
	at io.netty.util.concurrent.MultithreadEventExecutorGroup.<init>(MultithreadEventExecutorGroup.java:49)
	at io.netty.channel.MultithreadEventLoopGroup.<init>(MultithreadEventLoopGroup.java:59)
	at io.netty.channel.nio.NioEventLoopGroup.<init>(NioEventLoopGroup.java:87)
	at io.netty.channel.nio.NioEventLoopGroup.<init>(NioEventLoopGroup.java:82)
	at io.netty.channel.nio.NioEventLoopGroup.<init>(NioEventLoopGroup.java:69)
	at [email protected]/io.vertx.core.impl.transports.JDKTransport.eventLoopGroup(JDKTransport.java:34)
	at [email protected]/io.vertx.core.impl.VertxImpl.<init>(VertxImpl.java:181)
	at [email protected]/io.vertx.core.impl.VertxBuilder.vertx(VertxBuilder.java:229)
	at [email protected]/io.vertx.core.Vertx.vertx(Vertx.java:87)
	at [email protected]/io.vertx.core.Vertx.vertx(Vertx.java:77)
	at [email protected]/com.microsoft.gctoolkit.vertx.VertxChannel.<init>(VertxChannel.java:24)
	at [email protected]/com.microsoft.gctoolkit.vertx.VertxJVMEventChannel.<init>(VertxJVMEventChannel.java:20)
	at jdk.internal.reflect.GeneratedConstructorAccessor3.newInstance(Unknown Source)
	at java.base/jdk.internal.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
	at java.base/java.lang.reflect.Constructor.newInstance(Constructor.java:490)
	at java.base/java.util.ServiceLoader$ProviderImpl.newInstance(ServiceLoader.java:780)
	... 8 more
Caused by: io.netty.channel.ChannelException: failed to open a new selector
	at io.netty.channel.nio.NioEventLoop.openSelector(NioEventLoop.java:179)
	at io.netty.channel.nio.NioEventLoop.<init>(NioEventLoop.java:146)
	at io.netty.channel.nio.NioEventLoopGroup.newChild(NioEventLoopGroup.java:183)
	at io.netty.channel.nio.NioEventLoopGroup.newChild(NioEventLoopGroup.java:38)
	at io.netty.util.concurrent.MultithreadEventExecutorGroup.<init>(MultithreadEventExecutorGroup.java:84)
	... 25 more
Caused by: java.io.IOException: Unable to establish loopback connection
	at java.base/sun.nio.ch.PipeImpl$Initializer.run(PipeImpl.java:94)
	at java.base/sun.nio.ch.PipeImpl$Initializer.run(PipeImpl.java:61)
	at java.base/java.security.AccessController.doPrivileged(Native Method)
	at java.base/sun.nio.ch.PipeImpl.<init>(PipeImpl.java:171)
	at java.base/sun.nio.ch.SelectorProviderImpl.openPipe(SelectorProviderImpl.java:50)
	at java.base/java.nio.channels.Pipe.open(Pipe.java:155)
	at java.base/sun.nio.ch.WindowsSelectorImpl.<init>(WindowsSelectorImpl.java:142)
	at java.base/sun.nio.ch.WindowsSelectorProvider.openSelector(WindowsSelectorProvider.java:44)
	at io.netty.channel.nio.NioEventLoop.openSelector(NioEventLoop.java:177)
	... 29 more
Caused by: java.net.SocketException: No buffer space available (maximum connections reached?): connect
	at java.base/sun.nio.ch.Net.connect0(Native Method)
	at java.base/sun.nio.ch.Net.connect(Net.java:483)
	at java.base/sun.nio.ch.Net.connect(Net.java:472)
	at java.base/sun.nio.ch.SocketChannelImpl.connect(SocketChannelImpl.java:694)
	at java.base/java.nio.channels.SocketChannel.open(SocketChannel.java:194)
	at java.base/sun.nio.ch.PipeImpl$Initializer$LoopbackConnector.run(PipeImpl.java:127)
	at java.base/sun.nio.ch.PipeImpl$Initializer.run(PipeImpl.java:76)
	... 37 more

Process finished with exit code -1

Expected behavior
The program should execute normally until the loop ends.

Desktop (please complete the following information):

• OS: Windows11
• JDK: JDK11.0.19

java version "11.0.19" 2023-04-18 LTS
Java(TM) SE Runtime Environment 18.9 (build 11.0.19+9-LTS-224)
Java HotSpot(TM) 64-Bit Server VM 18.9 (build 11.0.19+9-LTS-224, mixed mode)

[karianna]

IIRC correctly this is a race condition which is benign but we should fix it :-)

[zheng-kai]

If I want to avoid this problem in the existing version, how should I modify my code? I hope to frequently analyze GC logs during a single execution of the program. Thank you.

[karianna]

@zheng-kai It should not stop you from analyzing a log, so you can carry on as normal

[dsgrieve]

Note fix #290, which went into 3.0.4.

What's interesting to me is the Caused by: java.net.SocketException: No buffer space available (maximum connections reached?): connect. When I run the reproducer on my machine, I get Caused by: java.io.IOException: Too many open files which makes me think gctoolkit is not properly closing files.