beam.smp chewing CPU on v1.31.0 on arm #4307

leewillis77 · 2024-10-27T16:17:18Z

Is there an existing issue for this?

I have searched the existing issues

What happened?

I've upgraded to v1.31.0 and after the upgrade I noticed* that there's a beam.smp process chewing up CPU time:

  PID USER      PR  NI    VIRT    RES    SHR S  %CPU  %MEM     TIME+ COMMAND
 1041 10000     20   0  192432  64284   4732 S 144.9   3.4   6:13.18 beam.smp

The system is idle currently (car is asleep, and neither teslamate nor grafana are open on any devices).

It's possible this was happening before the latest upgrade - I can't say for sure.

Expected Behavior

System is idle with no excessive CPU hogging.

Steps To Reproduce

No response

Relevant log output

PID USER      PR  NI    VIRT    RES    SHR S  %CPU  %MEM     TIME+ COMMAND
 1041 10000     20   0  192432  64284   4732 S 144.9   3.4   6:13.18 beam.smp

Screenshots

No response

Additional data

No response

Type of installation

Docker

Version

v1.31.0

The text was updated successfully, but these errors were encountered:

swiffer · 2024-10-27T16:31:47Z

Seems to be caused by rammitmq (quick google search) which is not utilized by teslamate. Could that be ?

leewillis77 · 2024-10-27T16:45:29Z

@swiffer There's nothing else running on the box other than teslamate, and the processes in question look like they're coming from docker:

systemd(1)-+-agetty(455)
           |-agetty(456)
           |-alsactl(331)
           |-avahi-daemon(344)---avahi-daemon(356)
           |-colord(1279)-+-{colord}(1280)
           |              `-{colord}(1282)
           |-containerd(454)-+-{containerd}(458)
           |                 |-{containerd}(459)
           |                 |-{containerd}(460)
           |                 |-{containerd}(461)
           |                 |-{containerd}(462)
           |                 |-{containerd}(480)
           |                 |-{containerd}(481)
           |                 |-{containerd}(482)
           |                 |-{containerd}(498)
           |                 |-{containerd}(812)
           |                 |-{containerd}(813)
           |                 `-{containerd}(814)
           |-containerd-shim(828)-+-tini(889)-+-beam.smp(1041)-+-erl_child_setup(1438)---inet_gethost(1486)---inet_gethost(1487)
           |                      |           |                |-{beam.smp}(1435)
           |                      |           |                |-{beam.smp}(1436)
           |                      |           |                |-{beam.smp}(1437)
           |                      |           |                |-{beam.smp}(1439)
           |                      |           |                |-{beam.smp}(1440)
           |                      |           |                |-{beam.smp}(1441)
           |                      |           |                |-{beam.smp}(1442)
           |                      |           |                |-{beam.smp}(1443)
           |                      |           |                |-{beam.smp}(1444)
           |                      |           |                |-{beam.smp}(1445)
           |                      |           |                |-{beam.smp}(1446)
           |                      |           |                |-{beam.smp}(1447)
           |                      |           |                |-{beam.smp}(1448)
           |                      |           |                |-{beam.smp}(1449)
           |                      |           |                |-{beam.smp}(1450)
           |                      |           |                |-{beam.smp}(1451)
           |                      |           |                |-{beam.smp}(1452)
           |                      |           |                |-{beam.smp}(1453)
           |                      |           |                |-{beam.smp}(1454)
           |                      |           |                |-{beam.smp}(1455)
           |                      |           |                |-{beam.smp}(1456)
           |                      |           |                |-{beam.smp}(1457)
           |                      |           |                `-{beam.smp}(1458)

I do have DISABLE_MQTT=true in my docker compose since I'm not using any MQTT services if that helps.

swiffer · 2024-10-27T16:54:48Z

Ok, rabbit is based on erlang, that's where it's coming from. I wonder if #4296 is causing this.

swiffer · 2024-10-27T18:42:26Z

@leewillis77 can you try sertting ERL_MAX_PORTS

https://elixirforum.com/t/elixir-erlang-docker-containers-ram-usage-on-different-oss-kernels/57251/18

leewillis77 · 2024-10-27T18:51:52Z

Hi;

Thanks for the suggestion. I added the following under environment in my docker-compose.yml:

- ERL_MAX_PORTS=1024

It didn't make any difference - was that the correct way to make the change? E.g.

services:
  teslamate:
    image: teslamate/teslamate:latest
    restart: always
    environment:
      - DATABASE_USER=teslamate
      - DATABASE_NAME=teslamate
      - DATABASE_HOST=database
      - DISABLE_MQTT=true
      - ERL_MAX_PORTS=1024

The thread you linked to seems to be concerned with high memory usage, but the problem I'm experiencing is high CPU, not high memory.

s56oa · 2024-10-27T19:00:48Z

I have the same issue.
Running in a docker on Raspberry Pi. Completely new fresh install of Teslamate made today.
Version 1.31.0

swiffer · 2024-10-27T19:03:54Z

@leewillis77 yes, you are right, sorry

Could one of you try

ghcr.io/teslamate-org/teslamate/teslamate:pr-4300

That is the latest before upgrading elixir / erlang

leewillis77 · 2024-10-27T19:06:51Z

I would if I knew how :)

swiffer · 2024-10-27T19:08:18Z

Just replace image in docker compose file, see here

https://docs.teslamate.org/docs/development#testing

leewillis77 · 2024-10-27T19:09:47Z

I tried that actually.:

$ docker compose pull
[+] Pulling 3/3
 ✘ grafana Error   context canceled                                                                                                                                                          0.5s
 ✘ teslamate Error Head "https://ghcr.io/v2/teslamate-org/teslamate/teslamate/manifests/pr-4300": denied                                                                                     0.5s
 ✘ database Error  context canceled

swiffer · 2024-10-27T19:27:59Z

okay, please try again with

image: ghcr.io/teslamate-org/teslamate:pr-4300

the contrib doc had an issue...

leewillis77 · 2024-10-27T19:32:20Z

beam.smp CPU usage is minimal (1.3%) with ghcr.io/teslamate-org/teslamate:pr-4300 vs > 100% as originally reported with the latest release.

  PID USER      PR  NI    VIRT    RES    SHR S  %CPU  %MEM     TIME+ COMMAND
14533 10000     20   0  156660  84144   6616 S   1.3   4.4   0:07.23 beam.smp

swiffer · 2024-10-27T19:48:27Z

@leewillis77 - thanks testing. I guess someone else needs to step in but seems to be caused by the erlang/elixir update @JakobLichterfeld

For now it should be fine to stay on pr-4300 until a fix is on the horizon.

s56oa · 2024-10-27T19:48:46Z

I can confirm the same with image: ghcr.io/teslamate-org/teslamate:pr-4300
Version 1.30.2-dev

beam.smp CPU usage has dropped significantly to around 1,1%.

swiffer · 2024-10-27T19:53:23Z

Out of curiosity - could you check pr-4303 as well, just to make sure if it's caused by dep updates or erlang

leewillis77 · 2024-10-27T20:19:02Z

Out of curiosity - could you check pr-4303 as well, just to make sure if it's caused by dep updates or erlang

beam.smp CPU is high (over 100%) with pr-4303.

leewillis77 · 2024-10-27T20:25:51Z

I'm unfortunately not particularly knowledgeable about the erlang ecosystem, but looking back at the pstree output I posted in #4307 (comment) which references inet_gethost I wonder if erlang/otp#8961 may be related?

baresel · 2024-10-27T20:43:15Z

Same issue for me, i switched to pr-4300 and it fixed the problem for now.

brianmay · 2024-10-27T21:01:35Z

It sounds like in that linked issue the process is just hanging, not using lots of CPU.

brianmay · 2024-10-27T21:39:50Z

Beam is a VM. Probably will have problems debugging this with system tools, think you will need beam tools.

One such tool is the erlang observer. https://blog.sequinstream.com/how-we-used-elixirs-observer-to-hunt-down-bottlenecks/

Having said that, it may be fiddly to get this working in a Docker container. Either the observer needs to have X access somehow (e.g. c0b/docker-elixir#19 (comment)), or you need to run a local beam that connects to the remote beam somehow (https://stackoverflow.com/questions/42164298/using-the-erlang-observer-app-with-a-remote-elixir-phoenix-server-inside-docker). Either way likely to be fiddly.

Also: It seems that our nix flake doesn't compile in the observer. I tried some things, but so far have been failures. Later: Oh, wait, this fixes it:

diff --git a/mix.exs b/mix.exs
index d159eefd..afa1c98a 100644
--- a/mix.exs
+++ b/mix.exs
@@ -27,7 +27,7 @@ defmodule TeslaMate.MixProject do
   def application do
     [
       mod: {TeslaMate.Application, []},
-      extra_applications: [:logger, :runtime_tools]
+      extra_applications: [:logger, :runtime_tools, :wx, :observer]
     ]
   end

(solution copied from https://stackoverflow.com/a/76760603)

JakobLichterfeld · 2024-10-28T08:08:37Z

I can reproduce the high CPU usage, without any high CPU usage, system runs fine with multiple docker containers on Raspberry Pi 3B+ currently logging fine a charge.

JakobLichterfeld · 2024-10-28T08:11:03Z

Thanks for your investigation!

Later: Oh, wait, this fixes it:

--> PR: #4311

JakobLichterfeld · 2024-10-28T08:17:05Z

Perhaps we can disable beams busy waiting: https://stressgrid.com/blog/beam_cpu_usage/

brianmay · 2024-10-28T20:48:45Z

Maybe a problem with Raspbian and latest code? What version are people using? Bookworm? Bullseye? Or Older?

It could also be an ARM specific issue also with latest beam.

brianmay · 2024-10-28T21:10:01Z

I propose that somebody create a pull request from the change to the Dockerfile reverted:

FROM elixir:1.16.2-otp-26 AS builder

We test that. Assuming that test succeeds, we then test:

FROM elixir:1.17.2-otp-26 AS builder

We should test the following also, but I suspect we can't because this is not a valid option:

FROM elixir:1.16.2-otp-27 AS builder

My suspicion is we will find otp-26 good and otp-27 bad, but would be good to prove this is indeed the case.

On the other hand, if the problem is the elixir version, not the erlang version, we probably should try 1.17.3 also.

cwanja · 2024-10-29T02:49:05Z

Maybe a problem with Raspbian and latest code? What version are people using? Bookworm? Bullseye? Or Older?

It could also be an ARM specific issue also with latest beam.

Bullseye here.

Have not update my Pi in months (do not judge me ha). TeslaMate is the only thing running on it. Like others, after updating to 1.31.0, beam.vm shot up and chewed through CPU.

swiffer · 2024-10-29T05:18:29Z

updated my comment with results on amd64 - works without increase in cpu time here. guess having some exploration builds as proposed by brianmay is best to quickly see what is introducing the issue?

baresel · 2024-10-29T07:55:06Z

Maybe a problem with Raspbian and latest code? What version are people using? Bookworm? Bullseye? Or Older?

It could also be an ARM specific issue also with latest beam.

I am on Bullseye too.

JakobLichterfeld · 2024-10-29T10:10:50Z

Maybe a problem with Raspbian and latest code? What version are people using? Bookworm? Bullseye? Or Older?

It could also be an ARM specific issue also with latest beam.

Good point, I hadn't thought of that.
Armv7l, rasbian buster here.

I propose that somebody create a pull request from the change to the Dockerfile reverted

I will be the somebody :-) (as it will be a bit tricky to get CI build as we prevent it if there are changes to the docker file)

swiffer · 2024-10-29T10:12:12Z

could someone affected try these three please?

image: ghcr.io/teslamate-org/teslamate:pr-4314 (1.16.3-otp-26)
image: ghcr.io/teslamate-org/teslamate:pr-4315 (1.17.3-otp-26)
image: ghcr.io/teslamate-org/teslamate:pr-4316 (1.17.3-otp-27)

tried these three as we know that 1.16.2-otp-26 is working and 1.17.2-otp-27 is not.

@JakobLichterfeld - i've been faster 😝

baresel · 2024-10-29T10:48:02Z

ghcr.io/teslamate-org/teslamate:pr-4314
not affected, CPU load in normal ranges

ghcr.io/teslamate-org/teslamate:pr-4315
not affected, same as 4300 or 4314

ghcr.io/teslamate-org/teslamate:pr-4316
definitly affected, CPU load is junoing between 30% and 90%

I also checked again the latest official release, there the load is jumping between 90 and 140% , which is more than i can see in the 4316 testing release!

swiffer · 2024-10-29T10:53:41Z

ok, so it looks like otp27 is causing the issue on arm

@baresel could you provide more details about your env and hardware (OS, Docker Version, Hardware)

baresel · 2024-10-29T11:44:32Z

OS Version: "Raspbian GNU/Linux 11 (bullseye)", Kernel: Linux 6.1.21-v8+
Docker Version: Docker version 20.10.5+dfsg1, build 55c4c88
Hardware: Raspi 4B, 4 GB RAM

DrMichael · 2024-10-29T12:05:13Z

Same here, 4314, 4315 are fine, 4316 has high load.

OS Version: "Raspbian GNU/Linux 11 (bullseye)", Kernel: Linux 6.1.70-v7+
Docker Version: Docker version 27.3.1, build ce12230
Hardware: Raspi 3B+, 1 GB RAM

plutonn · 2024-10-29T12:32:08Z

Hello, 4314, 4315 are fine, 4316 has high load.

OS Version: "Raspbian GNU/Linux 12 (bookworm) aarch64
", Kernel: Linux 6.1.21-v8+
Docker Version: Docker version 27.3.1, build ce12230
Hardware: Raspi 4B+, 8 GB RAM Rev 1.4

JakobLichterfeld · 2024-10-29T12:37:12Z

I assume the OTP27 docker image has set different compiler flags, I suggest a patch release with downgrading to 1.17.3-otp-26, even if I could not find any negative effect beside the "high" load in shown in top on my Raspberry Pi 3B+ (edit: corrected the otp version)

swiffer · 2024-10-29T12:38:06Z

what I do find interesting (but maybe completely unrelated) - RabbitMQ is not supporting OTP 27 as it has significant performance regressions in their use cases.

https://www.rabbitmq.com/docs/which-erlang#erlang-27-support

however we seem to be affected on aarch64 only.

swiffer · 2024-10-29T12:38:32Z

@JakobLichterfeld you mean 1.17.3-otp-26 ?

JakobLichterfeld · 2024-10-29T12:38:52Z

what I do find interesting (but maybe completely unrelated) - RabbitMQ is not supporting OTP 27 as it has significant performance regressions in their use cases.

OK, thats a reason to stay with 1.17.3-otp-26 (edit: correct otp version)

swiffer · 2024-10-29T12:39:58Z

why not 1.17.3-otp-26 (will update my existing PR).

JakobLichterfeld · 2024-10-29T12:44:21Z

@JakobLichterfeld you mean 1.17.3-otp-26 ?

Yeah, sorry for the typo :-D (edited above to avoid confusion)

why not 1.17.3-otp-26 (will update my existing PR).

Yeah, 1.17.3-otp-26

We will need to update the docs, the CI, the nix flake etc. as well

JakobLichterfeld · 2024-10-29T12:47:20Z

We will need to update the docs, the CI, the nix flake etc. as well

I will open a branch for it.

fixes: #4307

…4319) * fix: use elixir-1.17.3-otp-26 to avoid beam.smp chewing CPU on arm fixes: #4307 * docs: update changelog

brianmay · 2024-10-29T23:50:35Z

I had a theory that maybe the problem was otp-27 doesn't work correctly with bullseye. But I think the above tests clearly show bookworm has the same issue.

Just a detail I found interesting.

brianmay · 2024-10-29T23:51:49Z

erlang/otp#8322

OTP27 has various optimizations, wonder if one of these broke things for arm. https://www.erlang.org/blog/optimizations/

brianmay · 2024-10-30T00:00:45Z

Possibly this is not arm specific, but you notice it more on the slower processors.

JakobLichterfeld · 2024-10-30T08:00:27Z

OTP27 has various optimizations, wonder if one of these broke things for arm. https://www.erlang.org/blog/optimizations/

Actually a better explanation than mine, as

I assume the OTP27 docker image has set different compiler flags,

__

Possibly this is not arm specific, but you notice it more on the slower processors.

Yeah good point, currently I do not want dive to deep into this rabbit hole

This was referenced Oct 27, 2024

DO NOT MERGE #4308

Closed

docs: fix ghcr image path in contributing guide #4309

Merged

JakobLichterfeld added kind:bug Something isn't working note:help wanted Extra attention is needed undetermined Not sure if this is considered a real bug note:needs investigation The issue must be investigated first labels Oct 28, 2024

JakobLichterfeld mentioned this issue Oct 28, 2024

build: add wx and observer as extra applications #4311

Closed

JakobLichterfeld changed the title ~~beam.smp chewing CPU on v1.31.0~~ beam.smp chewing CPU on v1.31.0 on arm Oct 29, 2024

swiffer mentioned this issue Oct 29, 2024

fix: downgrade elixir to 1.17.3-otp-26 #4315

Closed

JakobLichterfeld added a commit that referenced this issue Oct 29, 2024

fix: use elixir-1.17.3-otp-26 to avoid beam.smp chewing CPU on arm

8c384a6

fixes: #4307

JakobLichterfeld mentioned this issue Oct 29, 2024

fix: use elixir-1.17.3-otp-26 to avoid beam.smp chewing CPU on arm #4319

Merged

JakobLichterfeld closed this as completed in #4319 Oct 29, 2024

JakobLichterfeld added a commit that referenced this issue Oct 29, 2024

fix: use elixir-1.17.3-otp-26 to avoid beam.smp chewing CPU on arm (#…

cfaa4b8

…4319) * fix: use elixir-1.17.3-otp-26 to avoid beam.smp chewing CPU on arm fixes: #4307 * docs: update changelog

swiffer mentioned this issue Dec 8, 2024

OTP 27.2 exploration #4429

Draft

beam.smp chewing CPU on v1.31.0 on arm #4307

beam.smp chewing CPU on v1.31.0 on arm #4307

Comments

leewillis77 commented Oct 27, 2024

Is there an existing issue for this?

What happened?

Expected Behavior

Steps To Reproduce

Relevant log output

Screenshots

Additional data

Type of installation

Version

swiffer commented Oct 27, 2024

leewillis77 commented Oct 27, 2024

swiffer commented Oct 27, 2024

swiffer commented Oct 27, 2024 • edited Loading

leewillis77 commented Oct 27, 2024

s56oa commented Oct 27, 2024

swiffer commented Oct 27, 2024

leewillis77 commented Oct 27, 2024

swiffer commented Oct 27, 2024

leewillis77 commented Oct 27, 2024

swiffer commented Oct 27, 2024

leewillis77 commented Oct 27, 2024

swiffer commented Oct 27, 2024

s56oa commented Oct 27, 2024

swiffer commented Oct 27, 2024

leewillis77 commented Oct 27, 2024

leewillis77 commented Oct 27, 2024

baresel commented Oct 27, 2024

brianmay commented Oct 27, 2024

brianmay commented Oct 27, 2024 • edited Loading

JakobLichterfeld commented Oct 28, 2024

JakobLichterfeld commented Oct 28, 2024 • edited Loading

JakobLichterfeld commented Oct 28, 2024

brianmay commented Oct 28, 2024 • edited Loading

brianmay commented Oct 28, 2024 • edited Loading

cwanja commented Oct 29, 2024

swiffer commented Oct 29, 2024

baresel commented Oct 29, 2024

JakobLichterfeld commented Oct 29, 2024

swiffer commented Oct 29, 2024 • edited Loading

baresel commented Oct 29, 2024 • edited Loading

swiffer commented Oct 29, 2024

baresel commented Oct 29, 2024

DrMichael commented Oct 29, 2024

plutonn commented Oct 29, 2024

JakobLichterfeld commented Oct 29, 2024 • edited Loading

swiffer commented Oct 29, 2024

swiffer commented Oct 29, 2024

JakobLichterfeld commented Oct 29, 2024 • edited Loading

swiffer commented Oct 29, 2024

JakobLichterfeld commented Oct 29, 2024 • edited Loading

JakobLichterfeld commented Oct 29, 2024

brianmay commented Oct 29, 2024

brianmay commented Oct 29, 2024 • edited Loading

brianmay commented Oct 30, 2024

JakobLichterfeld commented Oct 30, 2024

swiffer commented Oct 27, 2024 •

edited

Loading

brianmay commented Oct 27, 2024 •

edited

Loading

JakobLichterfeld commented Oct 28, 2024 •

edited

Loading

brianmay commented Oct 28, 2024 •

edited

Loading

brianmay commented Oct 28, 2024 •

edited

Loading

swiffer commented Oct 29, 2024 •

edited

Loading

baresel commented Oct 29, 2024 •

edited

Loading

JakobLichterfeld commented Oct 29, 2024 •

edited

Loading

JakobLichterfeld commented Oct 29, 2024 •

edited

Loading

JakobLichterfeld commented Oct 29, 2024 •

edited

Loading

brianmay commented Oct 29, 2024 •

edited

Loading