Mosquitto broker: High CPU usage (100%)

[alex9446]

Hello,
i have on a raspberry pi B an installation of home assistant (ex hassos).

Lately i have been experiencing high CPU loads that don't fade as long as the reboot of core_mosquitto addon.
I noticed this fact starting to manifest itself much more frequently when i added new MQTT devices, they went from 3 to 6 devices.

The load is so high that only once time i managed to login via ssh and take a screenshot of process list.

jq processes are created endlessly

Environment

• Hardware: Raspberry Pi 1 Model B
• Home Assistant Core: 0.109.6
• Supervisor: 222
• Host system: 3.13
• Operating environment: Home assistant (ex HassOS)
• Home Assistant configuration: https://github.com/alex9446/home-assistant-config

Mosquitto broker configuration

MQTT login with a non-administrator home assistant user

logins: []
anonymous: false
customize:
  active: false
  folder: mosquitto
certfile: fullchain.pem
keyfile: privkey.pem
require_certificate: false

Mosquitto broker log

[INFO] found esterno on Home Assistant
/bin/auth_srv.sh: line 15: echo: write error: Broken pipe
[INFO] found esterno on Home Assistant
/bin/auth_srv.sh: line 15: echo: write error: Broken pipe
[INFO] found esterno on Home Assistant
/bin/auth_srv.sh: line 15: echo: write error: Broken pipe
[INFO] found esterno on Home Assistant
/bin/auth_srv.sh: line 15: echo: write error: Broken pipe
1589542937: Socket error on client <unknown>, disconnecting.
[INFO] found esterno on Home Assistant
/bin/auth_srv.sh: line 15: echo: write error: Broken pipe
[INFO] found esterno on Home Assistant
/bin/auth_srv.sh: line 15: echo: write error: Broken pipe
[INFO] found esterno on Home Assistant
/bin/auth_srv.sh: line 15: echo: write error: Broken pipe
1589542977: Socket error on client <unknown>, disconnecting.
[ERROR] Auth error with esterno
/bin/auth_srv.sh: line 20: echo: write error: Broken pipe
[ERROR] Auth error with esterno
/bin/auth_srv.sh: line 20: echo: write error: Broken pipe
1589543017: Socket error on client <unknown>, disconnecting.
[INFO] found esterno on Home Assistant
/bin/auth_srv.sh: line 15: echo: write error: Broken pipe
1589543057: Socket error on client <unknown>, disconnecting.
[INFO] found esterno on Home Assistant
/bin/auth_srv.sh: line 15: echo: write error: Broken pipe
[INFO] found esterno on Home Assistant
/bin/auth_srv.sh: line 15: echo: write error: Broken pipe
1589543097: Socket error on client <unknown>, disconnecting.

Supervisor log

log of a more recent event

20-05-19 22:39:57 INFO (MainThread) [supervisor.auth] Auth request from core_mosquitto for esterno
20-05-19 22:40:10 INFO (MainThread) [supervisor.auth] Success login from esterno
20-05-19 22:40:14 INFO (MainThread) [supervisor.auth] Auth request from core_mosquitto for esterno
20-05-19 22:40:26 INFO (MainThread) [supervisor.auth] Success login from esterno
20-05-19 22:40:31 INFO (MainThread) [supervisor.auth] Auth request from core_mosquitto for esterno
20-05-19 22:40:43 INFO (MainThread) [supervisor.auth] Success login from esterno
20-05-19 22:40:48 INFO (MainThread) [supervisor.auth] Auth request from core_mosquitto for esterno
20-05-19 22:41:00 INFO (MainThread) [supervisor.auth] Success login from esterno
20-05-19 22:41:05 INFO (MainThread) [supervisor.auth] Auth request from core_mosquitto for esterno
20-05-19 22:41:16 INFO (MainThread) [supervisor.auth] Success login from esterno
20-05-19 22:41:19 INFO (MainThread) [supervisor.auth] Auth request from core_mosquitto for esterno
20-05-19 22:41:31 INFO (MainThread) [supervisor.auth] Success login from esterno
20-05-19 22:41:36 INFO (MainThread) [supervisor.auth] Auth request from core_mosquitto for esterno
20-05-19 22:41:46 INFO (MainThread) [supervisor.auth] Success login from esterno
20-05-19 22:41:57 INFO (MainThread) [supervisor.auth] Auth request from core_mosquitto for esterno
20-05-19 22:42:08 INFO (MainThread) [supervisor.auth] Success login from esterno
20-05-19 22:42:12 INFO (MainThread) [supervisor.auth] Auth request from core_mosquitto for esterno
20-05-19 22:42:22 INFO (MainThread) [supervisor.auth] Success login from esterno

[alex9446]

The same problem happened today with 3 device connected to mosquitto broker.

This happened after a blackout that involved the tasmota devices, not afflict the raspberry because is under an UPS battery protection.

Below screenshot of top, mosquitto and supervisor logs.

Top

I notice that more time passing since the start of problem, lower is CPU percentage of the single jq process

Mosquitto

[ERROR] Auth error with esterno
/bin/auth_srv.sh: line 20: echo: write error: Broken pipe
1590749323: Socket error on client <unknown>, disconnecting.
1590749385: Socket error on client <unknown>, disconnecting.
[ERROR] Auth error with esterno
/bin/auth_srv.sh: line 20: echo: write error: Broken pipe
1590749427: Socket error on client <unknown>, disconnecting.
[INFO] found esterno on Home Assistant
/bin/auth_srv.sh: line 15: echo: write error: Broken pipe
[INFO] found esterno on Home Assistant
/bin/auth_srv.sh: line 15: echo: write error: Broken pipe
1590749467: Socket error on client <unknown>, disconnecting.
[ERROR] Auth error with esterno
/bin/auth_srv.sh: line 20: echo: write error: Broken pipe
[ERROR] Auth error with esterno
/bin/auth_srv.sh: line 20: echo: write error: Broken pipe
[ERROR] Auth error with esterno
/bin/auth_srv.sh: line 20: echo: write error: Broken pipe
1590749507: Socket error on client <unknown>, disconnecting.
[ERROR] Auth error with esterno
/bin/auth_srv.sh: line 20: echo: write error: Broken pipe
[ERROR] Auth error with esterno
/bin/auth_srv.sh: line 20: echo: write error: Broken pipe
1590749547: Socket error on client <unknown>, disconnecting.
[ERROR] Auth error with esterno
/bin/auth_srv.sh: line 20: echo: write error: Broken pipe
1590749587: Socket error on client <unknown>, disconnecting.

Supervisor

20-05-29 10:49:01 INFO (MainThread) [supervisor.auth] Auth request from core_mosquitto for esterno
20-05-29 10:49:02 INFO (MainThread) [supervisor.homeassistant] Updated Home Assistant API token
20-05-29 10:49:32 ERROR (MainThread) [supervisor.homeassistant] Error on call http://172.30.32.1:8123/api/hassio_auth: 
20-05-29 10:49:33 ERROR (MainThread) [supervisor.auth] Can't request auth on Home Assistant!
20-05-29 10:50:07 INFO (MainThread) [supervisor.auth] Auth request from core_mosquitto for esterno
20-05-29 10:50:12 INFO (MainThread) [supervisor.auth] Auth request from core_mosquitto for esterno
20-05-29 10:50:38 INFO (MainThread) [supervisor.auth] Success login from esterno
20-05-29 10:50:40 INFO (MainThread) [supervisor.auth] Success login from esterno
20-05-29 10:50:55 INFO (MainThread) [supervisor.auth] Auth request from core_mosquitto for esterno
20-05-29 10:50:56 INFO (MainThread) [supervisor.auth] Auth request from core_mosquitto for esterno
20-05-29 10:51:10 INFO (MainThread) [supervisor.auth] Auth request from core_mosquitto for esterno
20-05-29 10:51:25 ERROR (MainThread) [supervisor.homeassistant] Error on call http://172.30.32.1:8123/api/hassio_auth: 
20-05-29 10:51:25 ERROR (MainThread) [supervisor.auth] Can't request auth on Home Assistant!
20-05-29 10:51:26 ERROR (MainThread) [supervisor.homeassistant] Error on call http://172.30.32.1:8123/api/hassio_auth: 
20-05-29 10:51:26 ERROR (MainThread) [supervisor.auth] Can't request auth on Home Assistant!
20-05-29 10:51:37 INFO (MainThread) [supervisor.auth] Auth request from core_mosquitto for esterno
20-05-29 10:51:38 INFO (MainThread) [supervisor.auth] Auth request from core_mosquitto for esterno
20-05-29 10:51:45 ERROR (MainThread) [supervisor.homeassistant] Error on call http://172.30.32.1:8123/api/hassio_auth: 
20-05-29 10:51:45 ERROR (MainThread) [supervisor.auth] Can't request auth on Home Assistant!
20-05-29 10:51:56 INFO (MainThread) [supervisor.auth] Auth request from core_mosquitto for esterno
20-05-29 10:52:08 ERROR (MainThread) [supervisor.homeassistant] Error on call http://172.30.32.1:8123/api/hassio_auth: 
20-05-29 10:52:08 ERROR (MainThread) [supervisor.auth] Can't request auth on Home Assistant!
20-05-29 10:52:10 ERROR (MainThread) [supervisor.homeassistant] Error on call http://172.30.32.1:8123/api/hassio_auth: 
20-05-29 10:52:10 ERROR (MainThread) [supervisor.auth] Can't request auth on Home Assistant!
20-05-29 10:52:27 ERROR (MainThread) [supervisor.homeassistant] Error on call http://172.30.32.1:8123/api/hassio_auth: 
20-05-29 10:52:27 ERROR (MainThread) [supervisor.auth] Can't request auth on Home Assistant!
20-05-29 10:53:43 INFO (MainThread) [supervisor.auth] Auth request from core_mosquitto for esterno
20-05-29 10:54:00 INFO (MainThread) [supervisor.auth] Success login from esterno

[stale]

This issue has been automatically marked as stale because it has not had recent activity. It will be closed if no further activity occurs. Thank you for your contributions.

[alex9446]

The problem also occurs when i update home assistant.

So you need to turn off the addon before starting the update.

[stale]

This issue has been automatically marked as stale because it has not had recent activity. It will be closed if no further activity occurs. Thank you for your contributions.

[stale]

This issue has been automatically marked as stale because it has not had recent activity. It will be closed if no further activity occurs. Thank you for your contributions.

[poberth]

I am having the same exact issue.
I even get the broken pipe message on the first client login after the plug-in restarted.

[XStamatiou]

Same here. However I think it is connected with the zigbee2mqtt addon. As soon as I start zigbee2mqtt, I begin to experience high CPU usage to the point where HA will seldomly respond at all.

[Konsts]

Same problem! HA reconnect multiple times and then disconnect

[fti7]

Same Issue here! Why is this issue closed? Reopen please

[fti7]

I have implemented an Workaround here by using an own password_file which is used before the auth plugin.
Looks like the implementation of auth_srv is faulty with a bigger set of Users (here it was about 30 Users (one per device) on an RPI4 with SSD)

[isabellaalstrom]

@fti7 Do you have some kind of tutorial on how to do this? And would you think this could also be remedied by having one user for all devices? I only have 7 users but am experiencing this quite often.

[alex9446]

In the last days/weeks has been happening to me every day, the system is absolutely unstable.
But tonight before rebooting i checked first, and noticed that mosquitto add-on was turned off, despite that the CPU total was at 100%.
I attach some screenshots.

The only anomaly I noticed is in the Core logs, that error loops every minute:

2021-04-02 00:16:01 ERROR (MainThread) [pydroid_ipcam] Failed to communicate with IP Webcam: Cannot connect to host 10.192.168.65:8080 ssl:default [Connect call failed ('10.192.168.65', 8080)]
2021-04-02 00:16:14 ERROR (MainThread) [pydroid_ipcam] Failed to communicate with IP Webcam: Cannot connect to host 10.192.168.65:8080 ssl:default [Connect call failed ('10.192.168.65', 8080)]
2021-04-02 00:16:27 ERROR (MainThread) [pydroid_ipcam] Failed to communicate with IP Webcam: Cannot connect to host 10.192.168.65:8080 ssl:default [Connect call failed ('10.192.168.65', 8080)]
2021-04-02 00:16:40 ERROR (MainThread) [pydroid_ipcam] Failed to communicate with IP Webcam: Cannot connect to host 10.192.168.65:8080 ssl:default [Connect call failed ('10.192.168.65', 8080)]
2021-04-02 00:16:53 ERROR (MainThread) [pydroid_ipcam] Failed to communicate with IP Webcam: Cannot connect to host 10.192.168.65:8080 ssl:default [Connect call failed ('10.192.168.65', 8080)]
2021-04-02 00:17:07 ERROR (MainThread) [pydroid_ipcam] Failed to communicate with IP Webcam: Cannot connect to host 10.192.168.65:8080 ssl:default [Connect call failed ('10.192.168.65', 8080)]
2021-04-02 00:17:20 ERROR (MainThread) [pydroid_ipcam] Failed to communicate with IP Webcam: Cannot connect to host 10.192.168.65:8080 ssl:default [Connect call failed ('10.192.168.65', 8080)]
2021-04-02 00:17:33 ERROR (MainThread) [pydroid_ipcam] Failed to communicate with IP Webcam: Cannot connect to host 10.192.168.65:8080 ssl:default [Connect call failed ('10.192.168.65', 8080)]
2021-04-02 00:17:46 ERROR (MainThread) [pydroid_ipcam] Failed to communicate with IP Webcam: Cannot connect to host 10.192.168.65:8080 ssl:default [Connect call failed ('10.192.168.65', 8080)]
2021-04-02 00:17:59 ERROR (MainThread) [pydroid_ipcam] Failed to communicate with IP Webcam: Cannot connect to host 10.192.168.65:8080 ssl:default [Connect call failed ('10.192.168.65', 8080)]
2021-04-02 00:18:13 ERROR (MainThread) [pydroid_ipcam] Failed to communicate with IP Webcam: Cannot connect to host 10.192.168.65:8080 ssl:default [Connect call failed ('10.192.168.65', 8080)]
2021-04-02 00:18:26 ERROR (MainThread) [pydroid_ipcam] Failed to communicate with IP Webcam: Cannot connect to host 10.192.168.65:8080 ssl:default [Connect call failed ('10.192.168.65', 8080)]
2021-04-02 00:18:39 ERROR (MainThread) [pydroid_ipcam] Failed to communicate with IP Webcam: Cannot connect to host 10.192.168.65:8080 ssl:default [Connect call failed ('10.192.168.65', 8080)]

P.S. I know the camera is off