[Bug] High idle CPU usage

[cruftex]

Search before asking

• I had searched in the issues and found no similar issues.

Apache SkyWalking Component

OAP server (apache/skywalking)

What happened

With OOTB docker compose OAP hase 30-40% idle CPU consumption

docker compose stats output:

CONTAINER ID   NAME            CPU %     MEM USAGE / LIMIT     MEM %     NET I/O          BLOCK I/O     PIDS
7356646a6d75   oap             35.15%    2.725GiB / 61.96GiB   4.40%     101MB / 6.23MB   0B / 7.47MB   289
de19eeaeff0a   elasticsearch   1.03%     1.028GiB / 61.96GiB   1.66%     6.24MB / 100MB   0B / 11.1MB   134
8cf85552cd88   ui              0.19%     490.2MiB / 61.96GiB   0.77%     354kB / 16.5MB   0B / 3.78MB   63

What you expected to happen

CPU% = 0%

How to reproduce

curl -fsSL https://github.com/apache/skywalking/raw/master/docker/docker-compose.yml > docker-compose.yml
docker compose --profile=elasticsearch up -d
sleep 60
docker compose stats

Anything else

Apache Skywalking looks like a very cool project. This was just an OOTB test as new user.
The high CPU and also the high memory usage is an immediate show stopper.

Are you willing to submit a pull request to fix on your own?

• Yes I am willing to submit a pull request on my own!

Code of Conduct

• I agree to follow this project's Code of Conduct

[wu-sheng]

Do you have any agent is running and sending data to it? It could cost some CPU as some timers are running, but 40% seems not reasonable.

[wu-sheng]

Your net IO is 101m, it seems not to be an idel system.

[cruftex]

No I was doing docker compose up and then accessing the dashboard once

[wu-sheng]

There is an initialition to build everything up, then nothing.
You have to run Java async profilier to check, which part is running.

[wu-sheng]

I don't have laptop to rerun quick start, but last time, it was only costing 2% CPU mostly.

[cruftex]

I removed the containers and tried again.

I can see heavy CPU usage for a few seconds then it drops to 40%.

@wu-sheng

I don't have laptop to rerun quick start, but last time, it was only costing 2% CPU mostly.

I will test on a server, one moment.

[wu-sheng]

I can see heavy CPU usage for a few seconds then it drops to 40%.

Init stage is normal. But 40% seems still unnormal.

[cruftex]

I created a fresh Ubuntu 24.04 instance on Digital Ocean of type: 2vcpu-8gb-amd

Setup:

apt-get install docker.io docker-compose-v2
mkdir skywalker
cd skywalker/
curl -fsSL https://github.com/apache/skywalking/raw/master/docker/docker-compose.yml > docker-compose.yml
docker compose --profile=elasticsearch up -d

After 60s the CPU usage stabilizes around 16%:

CONTAINER ID   NAME            CPU %     MEM USAGE / LIMIT     MEM %     NET I/O           BLOCK I/O     PIDS
eabca1469654   oap             16.71%    2.129GiB / 7.756GiB   27.45%    97.5MB / 3.24MB   0B / 3.06MB   64
8745f80f8a4f   elasticsearch   0.25%     756.8MiB / 7.756GiB   9.53%     3.23MB / 97.5MB   0B / 5.3MB    45
84daf5dbd7b6   ui              0.15%     156.6MiB / 7.756GiB   1.97%     5.31kB / 5.33kB   0B / 3MB      26

Maybe on my notebook it is more, since I am running without power plugged in, atm.

Still, 16% is a lot.

[wu-sheng]

I may be able to recheck later next week, when I have my laptop. Still, I recommend you to run async profilier to verify.

[cruftex]

Thanks for the responses!

Before getting involved with a project, I would like to check out the very basics.
Doing debugging with the async profiler means getting involved....

I will look for something more lightweight for my current use case and will look into Skywalking again at a later point in time.

[wu-sheng]

This seems a special behavior of docker-compose. I actually saw there is 16%-25% CPU cost of docker stats.

When I read metrics from demo of skywalking.a.o, https://demo.skywalking.apache.org/dashboard/SO11Y_OAP/ServiceInstance/ZGVtby1vYXAuc2t5d2Fsa2luZy1zaG93Y2FzZQ==.1/ZGVtby1vYXAuc2t5d2Fsa2luZy1zaG93Y2FzZQ==.1_ZGVtby1vYXAtNmI5YzdkODhkOS1ubnBtOA==/Self-Observability-OAP-Instance
username/password: skywalking/skywalking

It only costs 20%-30% with traffic analysis.

I have asked @kezhenxu94 to take a look the profiling.

[wu-sheng]

I run the async-profiling for 30s.

The costs are from default queue scanning. We don't want to use too many locks mechanism or some complex queues, so, we keep trying to read data from the queue/list, which costs some CPUs by default.

[cruftex]

@wu-sheng

Thanks for the profiling!

And thanks for the demo link. Maybe I should have tried the demo before trying to install it by myself.
Looks pretty cool!

It only costs 20%-30% with traffic analysis.

That means probably the actual data processing in demo is negligible, compared to the CPU overhead of the queue.

I looked up the code, here:
https://github.com/apache/skywalking/blob/master/oap-server/server-library/library-datacarrier-queue/src/main/java/org/apache/skywalking/oap/server/library/datacarrier/consumer/MultipleChannelsConsumer.java

The interesting part is this:

        final List consumeList = new ArrayList(2000);
        while (running) {
            boolean hasData = false;
            for (Group target : consumeTargets) {
                boolean consumed = consume(target, consumeList);
                hasData = hasData || consumed;
            }

            if (!hasData) {
                try {
                    Thread.sleep(consumeCycle);
                } catch (InterruptedException e) {
                }
            }
        }

That is a loop scanning through array elements repeatedly.

I found that the consumeCycle is probably 20 millis:
https://github.com/apache/skywalking/blob/master/oap-server/server-library/library-datacarrier-queue/src/main/java/org/apache/skywalking/oap/server/library/datacarrier/DataCarrier.java#L116

The costs are from default queue scanning. We don't want to use too many locks mechanism or some complex queues

Hmm, using a proper concurrent queue would be far less complex and better performing.
The testing code has a lot sleeps. This kind of testing will either produce spurious fails or needs to wait for long times.

Unfortunately there is almost no comments about why this was done this way (why 2000?!)

Is there some benchmarks about this?

[wu-sheng]

I guess it is he place.
This was from old experience to process the data ASAP. For shorter duration when idel, it is easy to make the queue full before the first read.
We could be able to provide the config for idel waiting duration.

[wu-sheng]

I tried, it seems 200ms should be enough to fix this issue. #13227 (comment)
And as this duration only affects the ideal(100% no data)->busy, 200ms should be fine.

[cruftex]

@wu-sheng:
Thanks a lot! Looks like an easy quick fix.

A next improvement step could be: Have a blocking reader thread per partition.
That should not be too much of overhead for the additional threads, removes the single thread consumer bottleneck and any busy waiting techniques.

[wu-sheng]

It is pooled thread, don't need to worry that, AFAIK.

[cruftex]

@wu-sheng I close this discussion since there is a resolution. Thanks for the PR!