Epoll consuming lot more CPU than Nio

[praveen97uma]

I am building a websocket based broker. During load testing, we found that Epoll transport uses around 55% CPU compared to around 20% for Nio, just for maintaining the connections without doing any business specific IO on those connections. Is this expected? What could I be doing wrong? Happy to share any more info required around this.

Total concurrent connections: Around 27K
Boss Threads: 1
Worker Threads: 32

Cores in the VM: 8

Relevant code that sets up netty.

  EventExecutorChooserFactory chooserFactory = DefaultEventExecutorChooserFactory.INSTANCE;

  ThreadFactory bossThreadFactory = ThreadFactoryUtil.createInstrumented("boss", metricRegistry);

  Executor workerExecutor = new ThreadPerTaskExecutor(
          ThreadFactoryUtil.createAffinityThreadFactory("worker.thread", metricRegistry));

private void setupNioEventLoopGroups(EventExecutorChooserFactory chooserFactory, ThreadFactory bossThreadFactory,
            Executor workerExecutor) {
        bossPool = new NioEventLoopGroup(acceptorThreads, bossThreadFactory);
        workerPool = new NioEventLoopGroup(workerThreads, workerExecutor, chooserFactory, SelectorProvider.provider(),
                DefaultSelectStrategyFactory.INSTANCE);
        channelType = NioServerSocketChannel.class;
        log.info("Initialiazing Java NIO Event System");
    }

    private void setupEpollEventLoopGroups(EventExecutorChooserFactory chooserFactory, ThreadFactory bossThreadFactory,
            Executor workerExecutor) {
        bossPool = new EpollEventLoopGroup(acceptorThreads, bossThreadFactory);
        workerPool = new EpollEventLoopGroup(workerThreads, workerExecutor, chooserFactory,
                DefaultSelectStrategyFactory.INSTANCE);
        channelType = EpollServerSocketChannel.class;
        log.info("Initialiazing Epoll IO Event System");
    }


        ServerBootstrap serverBootstrap = new ServerBootstrap().group(bossPool, workerPool);

        // Choose socket options.
        Map<ChannelOption<?>, Object> channelOptions = new HashMap<>();
        channelOptions.put(ChannelOption.SO_BACKLOG, 256);
        channelOptions.put(ChannelOption.ALLOCATOR, new PooledByteBufAllocator(true));
        channelOptions.put(ChannelOption.SO_TIMEOUT, 3000);

        channelOptions.forEach(
                (key, value) -> serverBootstrap.option(ChannelOption.valueOf(String.valueOf(key)), value));

        // Set transport options
        serverBootstrap.childOption(ChannelOption.TCP_NODELAY, true);
        serverBootstrap.childOption(ChannelOption.SO_KEEPALIVE, true);
        serverBootstrap.childOption(ChannelOption.SO_LINGER, -1);
        serverBootstrap.childOption(ChannelOption.SO_REUSEADDR, true);
        serverBootstrap.childOption(ChannelOption.ALLOCATOR, PooledByteBufAllocator.DEFAULT);
        serverBootstrap.childOption(ChannelOption.ALLOW_HALF_CLOSURE, false);
        serverBootstrap.childOption(ChannelOption.SO_SNDBUF, 10 * 1024);
        serverBootstrap.channel(serverGroup.getChannelType());
        serverBootstrap.childHandler(channelInitializer);

Netty version

4.1.68

JVM version (e.g. java -version)

openjdk version "11.0.12" 2021-07-20 LTS
OpenJDK Runtime Environment Zulu11.50+19-CA (build 11.0.12+7-LTS)
OpenJDK 64-Bit Server VM Zulu11.50+19-CA (build 11.0.12+7-LTS, mixed mode)

OS version (e.g. uname -a)

Linux bolt-004 5.8.0-1041-azure #44~20.04.1-Ubuntu SMP Fri Aug 20 20:41:09 UTC 2021 x86_64 x86_64 x86_64 GNU/Linux

Epoll

Nio

[hyperxpro]

More information needed.

[praveen97uma]

@hyperxpro I have added some code. Please let me know if anything specific info would help.

[franz1981]

@praveen97uma
The load and performance result is the same for both the tests?

eg
NIO perform the test in X seconds.
EPOLL perform the test in Y seconds.

[praveen97uma]

@franz1981 Yes, The ramp up to 27K connections is same for both NIO and EPOLL. The graph I shared are in steady state after the ramp up with nothing being written to the connections, except the websocket ping/pongs every 5 sec, which again happens for both the transports.

[franz1981]

Yes, The ramp up to 27K connections is same for both NIO and EPOLL

It would worth to capture some profiling using https://github.com/jvm-profiling-tools/async-profiler

1. https://github.com/jvm-profiling-tools/async-profiler#basic-usage
2. add -XX:+UnlockDiagnosticVMOptions -XX:+DebugNonSafepoints as JVM flags
3. run the profiler with -t -d 10 (or whatever duration you think is ok)

And share the flamegraphs (-f nio.html and -f epoll.html) somehow

qq

Worker Threads: 32
Cores in the VM: 8

if you don't suppose to block on the event loop, why not using 8 worker threads (or less?)

[praveen97uma]

@franz1981 @hyperxpro Here are the files. Profiled for 30s.

https://raw.githubusercontent.com/praveen97uma/experiments/main/epoll.html
https://raw.githubusercontent.com/praveen97uma/experiments/main/nio.html

Screenshots of the same files if convenient.

[franz1981]

there are an insane amount of samples on epollWait0 due to timerset.
What's this instrumented runnable? can be disabled?

Another thing: I won't suggest to set affinity with netty threads > number of cores...is a BAD idea :)
as suggested on

if you don't suppose to block on the event loop, why not using 8 worker threads (or less?)

[hyperxpro]

Also, try this: ServerBootstrap#option(EpollChannelOption.EPOLL_MODE, EpollMode.EDGE_TRIGGERED)

[franz1981]

Good point, it could be that wakeup is spuriously happening (each time, so not so "spuriously") or that there are scheduled tasks that cause epoll to awake and go asleep continuosly

[praveen97uma]

@franz1981 @hyperxpro Thank you both for the help . So, I am doing the following changes and will keep you guys posted.

1. Remove the InstrumntedThreadFactory which instruments threads created/running/terminated created by a thread factory.
2. Reduce the worker threads to 8 (equal to no of cores). I am anyway using separate event loop group for blocking channel handlers. Found out the hard way to not set affinity to threads more than > no of cores.
   3). try ServerBootstrap#option(EpollChannelOption.EPOLL_MODE, EpollMode.EDGE_TRIGGERED)

[praveen97uma]

@franz1981 I made the changes. The CPU has dropped to 40% but, IMO, it is still high.

[franz1981]

It's still too much time...
There are any scheduled task submitted?
looking at the huge amount of sample spent while dequeing the prio q on the right I would say yes

[praveen97uma]

I have scheduled tasks which run at every 200ms to consume messages from a buffer queue for that connection and push to the client. This is scheduled on the channel's event executor itself. That is the cause of all this I guess then. @franz1981

[franz1981]

yeah, probably rescheduling it is a bit more costy with epoll, or it could be due to the hypervised env you run the app, according to the flamegraphs it doesn't seem a bare metal server no? Maybe I'm wrong :)

[hyperxpro]

Are you running the program on Shared-CPU VM or Bare Metal?

[praveen97uma]

Its not a bare metal but Azure's VM. These are virtual CPUs.

[normanmaurer]

@praveen97uma can you upload the flame graph so we can navigate in it ? It seems it spend quite some time on timerfd_settime

[franz1981]

@normanmaurer It looks to me that due to the too tight period of the scheduled tasks (for that virtual env) epoll always find some new scheduled task to rearm, causing that method to be called too much.

                                if (curDeadlineNanos == prevDeadlineNanos) {
                                    // No timer activity needed
                                    strategy = epollWaitNoTimerChange();
                                } else {
                                    // Timerfd needs to be re-armed or disarmed
                                    prevDeadlineNanos = curDeadlineNanos;
                                    strategy = epollWait(curDeadlineNanos);
                                }

on EpollEventLoop

[praveen97uma]

@normanmaurer Here is the flame graph(updated). https://raw.githubusercontent.com/praveen97uma/experiments/main/epoll.html

[praveen97uma]

@normanmaurer @franz1981 @hyperxpro Guys, so ByteBuf.duplicate() creates a new UnpooledDuplicatedByteBuf(). Is it possible to let netty create a Pooled version of the bytebuf? This particular call is causing the highest allocations in my profiling.

[normanmaurer]

@praveen97uma if you use the PooledByteBufAllocator it should pool these.

[normanmaurer]

@praveen97uma also can you explain why and how you schedule so many tasks ?

[praveen97uma]

@normanmaurer We had to batch push messages over the connection every 200ms. These msgs are merged in a specific structure to reduce bytes on the wire. I have a buffer queue for every connection and tasks are scheduled for every connection on the eventloops that do this batching and flush over the connection. Is this entirely wrong approach and is there a better way to do this in some other way in netty? Had read about FlushConsolidationHandler but not sure if there is a hook that I can use to do the merging I want to do before flushing.

I am using PolledByteBufAllocator.

serverBootstrap.childOption(ChannelOption.ALLOCATOR, new PooledByteBufAllocator(true));

    public static ByteBuf encodePublishOperation(ByteBufAllocator byteBufAllocator,
            List<ServerPublishOperation> topicPublishes) {

        ByteBuf byteBuf = byteBufAllocator.buffer();

ServerPublishOperation is a ByteBufHolder. Channel's alloc is passed to the above function.

[normanmaurer]

@normanmaurer We had to batch push messages over the connection every 200ms. These msgs are merged in a specific structure to reduce bytes on the wire. I have a buffer queue for every connection and tasks are scheduled for every connection on the eventloops that do this batching and flush over the connection. Is this entirely wrong approach and is there a better way to do this in some other way in netty? Had read about FlushConsolidationHandler but not sure if there is a hook that I can use to do the merging I want to do before flushing.

I am using PolledByteBufAllocator.

serverBootstrap.childOption(ChannelOption.ALLOCATOR, new PooledByteBufAllocator(true));

    public static ByteBuf encodePublishOperation(ByteBufAllocator byteBufAllocator,
            List<ServerPublishOperation> topicPublishes) {

        ByteBuf byteBuf = byteBufAllocator.buffer();

ServerPublishOperation is a ByteBufHolder. Channel's alloc is passed to the above function.

I see... If you switch to retainedDuplicate() it should be pooled as well. Just note that this also will increment the reference count by 1.

[chrisvest]

I have a buffer queue for every connection and tasks are scheduled for every connection on the eventloops that do this batching and flush over the connection. Is this entirely wrong approach and is there a better way to do this in some other way in netty?

If you keep track of your connections (ideally just the ones with messages), you could have a single task scheduled, that go over all current connections and process their batches.

[NiteshKant]

If you keep track of your connections (ideally just the ones with messages), you could have a single task scheduled, that go over all current connections and process their batches.

+1 .. may be not a single task but a single task per eventloop so that you do not have to jump the eventloop for flushing the connection.

[normanmaurer]

I wonder if the time used by timerfd_settime is any indicator that we might be better of to not use it when possible (when the timeout is milliseconds) and just use epoll_wait(...) with the right timeout. WDYT ?

[chrisvest]

Only using epoll_wait when the timeout is greater than a millisecond will cause rounding in timeouts, though. For 200 millisecond timeouts that probably won't matter, but it might for a 1,5 millisecond timeout. So we'd need to pick a cut-off point. On kernel 5.11 and newer, we can use epoll_pwait2, which takes a timespec parameter.

[normanmaurer]

Let me put this on my todo list...

[normanmaurer]

@praveen97uma I think this should improve things: #12145