Emoncms_mqtt.php very high ram use

ullmf · 1 April 2023 07:40

I have installed emoncms under proxmox, Ubuntu 20.02 with php8.2 with the current stable branch.
Everything works as it should. However, the memory usage is constantly increasing up to 100%. At 100% the memory is released again. The feedwriter works (feedwriter: Active Running - sleep 300s 462 feed points pending write).
This would not be a problem if releasing the memory did not fully utilise the CPU.
If, for example, the copying of files happens to coincide with the release of memory, the system is 100% busy and blocks the Windows computers.

The log files contain no indication of this behaviour.

I have also tried it with php 8.1 and Ubuntu 22.04 with the same result.
For the last few years I have used a Pi for emoncms without any problems and this behaviour did not occur. The memory was never used more than 30% - 40% at any time.
Does anyone have an idea how I could solve this?

lucwillems · 16 April 2023 13:37

i’m seeing simular issues, high memory usage for emoncms_mqtt until it’s oom killed by kernel

Apr 15 22:36:03 vemonpi systemd[1]: emoncms_mqtt.service: A process of this unit has been killed by the OOM killer.
Apr 15 22:36:03 vemonpi systemd[1]: emoncms_mqtt.service: Main process exited, code=killed, status=9/KILL
Apr 15 22:36:03 vemonpi systemd[1]: emoncms_mqtt.service: Failed with result 'oom-kill'.
Apr 15 22:36:03 vemonpi systemd[1]: emoncms_mqtt.service: Consumed 2min 11.200s CPU time.
Apr 15 22:37:03 vemonpi systemd[1]: emoncms_mqtt.service: Scheduled restart job, restart counter is at 3.
Apr 15 22:37:03 vemonpi systemd[1]: Stopped Emoncms emoncms_mqtt script.
Apr 15 22:37:03 vemonpi systemd[1]: emoncms_mqtt.service: Consumed 2min 11.200s CPU time.
Apr 15 22:37:03 vemonpi systemd[1]: Started Emoncms emoncms_mqtt script.
Apr 16 03:38:10 vemonpi systemd[1]: emoncms_mqtt.service: A process of this unit has been killed by the OOM killer.
Apr 16 03:38:10 vemonpi systemd[1]: emoncms_mqtt.service: Main process exited, code=killed, status=9/KILL
Apr 16 03:38:10 vemonpi systemd[1]: emoncms_mqtt.service: Failed with result 'oom-kill'.
Apr 16 03:38:10 vemonpi systemd[1]: emoncms_mqtt.service: Consumed 2min 2.821s CPU time.
Apr 16 03:39:11 vemonpi systemd[1]: emoncms_mqtt.service: Scheduled restart job, restart counter is at 4.
Apr 16 03:39:11 vemonpi systemd[1]: Stopped Emoncms emoncms_mqtt script.
Apr 16 03:39:11 vemonpi systemd[1]: emoncms_mqtt.service: Consumed 2min 2.821s CPU time.
Apr 16 03:39:11 vemonpi systemd[1]: Started Emoncms emoncms_mqtt script.

Apr 15 12:35:58 vemonpi kernel: oom-kill:constraint=CONSTRAINT_NONE,nodemask=(null),cpuset=/,mems_allowed=0,global_oom,task_memcg=/system.slice/emoncms_mqtt.service,task=php,pid>
Apr 15 12:35:58 vemonpi kernel: Out of memory: Killed process 591 (php) total-vm:4923140kB, anon-rss:3817860kB, file-rss:0kB, shmem-rss:0kB, UID:0 pgtables:9584kB oom_score_adj:0

ullmf · 16 April 2023 14:23

At the moment, I am experimenting with the memory-limit parameter in the php.ini files in the /etc/php/8.2/xxx folders.
Changes to php.ini in the fpm folder have no effect.
If I set the memory-limit in the folder apache2 and cli to 512MB I have no more memory problems. But I have gaps in the graphics - see picture:
solar_1

Currently I have set the limit for apache2 back to -1 and for cli to 1024M. This way I have fewer gaps and no memory problems.
But it’s not nice…

lucwillems · 16 April 2023 17:13

as far i can see , i get a fixed increase of 2048 bytes (2K) every 10 seconds, which is the rate emonTXT is sending input data
i’m currently testing memory_limit=512M for cli , see what happens.

no issue found with UI / web scripts.

using emoncms 11.3.0/ php 8.1.17 on debian 11 system

lucwillems · 16 April 2023 18:00

after ~ 25 minutes, it stops executing , with following error log

Apr 16 19:51:33 vemonpi emoncms_mqtt[3797]: Fatal error: Allowed memory size of 536870912 bytes exhausted (tried to allocate 4096 bytes) in /var/www/emoncms/Modules/input/input_model.php on line 240

seems to be multiples of 2048

comparing code running on pi (10.8.5) and on debian vm (11.3.0) i don’t see any difference , but i noticed that during install , phpredis was compiled from github source tree using “HEAD” state on that day

luc@vemonpi:/opt/openenergymonitor/EmonScripts/install/phpredis$ git log
commit 7a055cada8f45e69943b06f1aa5c38d865b81369 (HEAD -> develop, origin/develop, origin/HEAD)
Author: Pavlo Yatsukhnenko <[email protected]>
Date:   Sun Apr 2 18:36:12 2023 +0300

    Use on-stack allocated valiables

so not really a stable known release/state of source tree

borpin · 17 April 2023 15:19

How did you do the install? Using the emonscripts?

Compare setups;

I am running

Ubuntu 22.04.1 LTS (GNU/Linux 5.15.74-1-pve x86_64)

PHP 8.1.2-1ubuntu2.9 (cli) (built: Oct 19 2022 14:58:09) (NTS)
Copyright (c) The PHP Group
Zend Engine v4.1.2, Copyright (c) Zend Technologies
    with Zend OPcache v8.1.2-1ubuntu2.9, Copyright (c), by Zend Technologies

PVE 6.4-13

No issues here on memory.

However, I did notice some changes to the service file. How recently did you do your install? Is it a logging issue?

Question How many topics are you trying to read?

[edit]
Mosquitto in same container or on a separate container?

Darren · 17 April 2023 15:29

I think I’m seeing a similar issue with a fresh RaspberryPi build. I used the latest RPi 32bit Lite OS and the emonscripts to install.

After a few hours everything becomes unresponsive, after a reboot a few hours ago emoncms_mqtt.php is already using 300M!

Server Information

Services

emonhub :- Active Running
emoncms_mqtt :- Active Running
feedwriter :- Active Running - sleep 30s 0 feed points pending write
service-runner :- Active Running
redis-server :- Active Running
mosquitto :- Active Running
demandshaper :- Active Running
emonPiLCD :- Not found or not installed

Emoncms

Version :- low-write 11.3.0
Git :-
- URL :- GitHub - emoncms/emoncms: Web-app for processing, logging and visualising energy, temperature and other environmental data
- Branch :- * stable
- Describe :- 11.3.0
Components :- Emoncms Core v11.3.0 | App v2.6.10 | EmonHub Config v2.1.5 | Dashboard v2.3.3 | Device v2.2.2 | Graph v2.2.3 | Network Setup v1.0.2 | Backup v2.3.2 | DemandShaper v2.2.2 | Postprocess v2.2.7 | Sync v2.1.4 | Usefulscripts v2.3.10 | EmonScripts v1.6.11 | RFM2Pi v1.4.1 | Avrdude-rpi v1.0.1 | Emonhub v2.5.5

Server

CPU :- 1 Threads(s) | 4 Core(s) | 1 Sockets(s) | Cortex-A7 | 57.60MIPS |
OS :- Linux 6.1.21-v7+
Host :- AmonSul | AmonSul | (192.168.20.31)
Date :- 2023-04-17 16:31:20 BST
Uptime :- 16:31:20 up 21:10, 1 user, load average: 0.22, 0.14, 0.10

Memory

RAM :- Used: 40.11%
- Total :- 921.98 MB
- Used :- 369.83 MB
- Free :- 552.15 MB
Swap :- Used: 8.36%
- Total :- 1024 MB
- Used :- 85.56 MB
- Free :- 938.44 MB

Disk

**** :- - / :- Used: 7.29%
- Total :- 39.36 GB
- Used :- 2.87 GB
- Free :- 34.47 GB
- Read Load :- n/a
- Write Load :- n/a
- Load Time :- n/a
/boot :- Used: 19.77%
- Total :- 254.99 MB
- Used :- 50.42 MB
- Free :- 204.57 MB
- Read Load :- 0 B/s
- Write Load :- 0 B/s
- Load Time :- 20 hours 45 mins
/var/opt/emoncms :- Used: 2.38%
- Total :- 62.45 GB
- Used :- 1.49 GB
- Free :- 57.74 GB
- Read Load :- n/a
- Write Load :- n/a
- Load Time :- n/a
/var/log :- Used: 3.73%
- Total :- 50 MB
- Used :- 1.87 MB
- Free :- 48.13 MB
- Read Load :- n/a
- Write Load :- n/a
- Load Time :- n/a

HTTP

Server :- Apache/2.4.54 (Raspbian) HTTP/1.1 CGI/1.1 80

MySQL

Version :- 10.5.15-MariaDB-0+deb11u1
Host :- 127.0.0.1 (127.0.0.1)
Date :- 2023-04-17 16:31:20 (UTC 01:00‌)
Stats :- Uptime: 79871 Threads: 3 Questions: 2429 Slow queries: 0 Opens: 47 Open tables: 39 Queries per second avg: 0.030

Redis

Version :-
- Redis Server :- 6.0.16
- PHP Redis :- 6.0.0-dev
Host :- localhost:6379
Size :- 95 keys (728.97K)
Uptime :- 0 days

MQTT Server

Version :- Mosquitto 2.0.11
Host :- localhost:1883 (127.0.0.1)

PHP

Version :- 8.1.18 (Zend Version 4.1.18)
Run user :- User: www-data Group: www-data video Script Owner: pi
Modules :- apache2handler calendar Core ctype curl date exif FFI fileinfo filter ftp gd gettext hash iconv json libxml mbstring mosquitto v0.4.0mysqli mysqlnd vmysqlnd 8.1.18openssl pcre PDO pdo_mysql Phar posix readline redis v6.0.0-devReflection session shmop sockets sodium SPL standard sysvmsg sysvsem sysvshm tokenizer Zend OPcache zlib

Pi

Model :- Raspberry Pi 2 Model B Rev 1.1 - 1GB (Sony UK)
Serial num. :- F48BB43A
CPU Temperature :- 44.39°C
GPU Temperature :- 44.4°C
emonpiRelease :- emonSD-10Nov22
File-system :- read-only

Client Information

HTTP

Browser :- Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:109.0) Gecko/20100101 Firefox/112.0
Language :- en-GB,en;q=0.5

Window

Size :- 1663 x 950

Screen

Resolution :- 1920 x 1200

The uptime of 16 hours is misleading as I restarted the emoncms_mqtt service a few hours ago as I was almost out memory again. It dropped to 0 swap in use, but is slowly creeping up.

borpin · 17 April 2023 15:30

@TrystanLea - have you made any changes that might be causing this?

borpin · 17 April 2023 15:41

@Darren @lucwillems @ullmf

This PR checks for redis. Can you try and add in an error message to see if the check is failing?

This is all I can see as a recent change that might be affecting this service.

Anything in the emoncms log?

Darren · 17 April 2023 15:52

I’m seeing errors like this

2023-04-16 15:01:51.-416|WARN|emoncms_mqtt.php|Connecting to MQTT server: Connection Accepted.: code: 0
2023-04-16 15:02:18.-226|WARN|emoncms_mqtt.php|Not connected, retrying connection
2023-04-16 15:02:22.-372|WARN|emoncms_mqtt.php|Connecting to MQTT server: Connection Accepted.: code: 0
2023-04-16 15:03:02.438|WARN|emoncms_mqtt.php|Not connected, retrying connection
2023-04-16 15:03:10.-361|WARN|emoncms_mqtt.php|Not connected, retrying connection
2023-04-16 15:03:17.-03|WARN|emoncms_mqtt.php|Not connected, retrying connection
2023-04-16 15:03:33.014|WARN|emoncms_mqtt.php|Not connected, retrying connection
2023-04-16 15:03:44.-115|WARN|emoncms_mqtt.php|Not connected, retrying connection
2023-04-16 15:03:55.-269|WARN|emoncms_mqtt.php|Not connected, retrying connection
2023-04-16 15:04:04.103|WARN|emoncms_mqtt.php|Not connected, retrying connection
2023-04-16 15:04:13.-150|WARN|emoncms_mqtt.php|Not connected, retrying connection
2023-04-16 15:04:20.-07|WARN|emoncms_mqtt.php|Not connected, retrying connection
2023-04-16 15:04:31.377|WARN|emoncms_mqtt.php|Not connected, retrying connection
2023-04-16 15:04:37.-376|WARN|emoncms_mqtt.php|Not connected, retrying connection
2023-04-16 15:04:43.311|WARN|emoncms_mqtt.php|Not connected, retrying connection
2023-04-16 15:04:47.-440|WARN|emoncms_mqtt.php|Connecting to MQTT server: Connection Accepted.: code: 0
2023-04-16 15:06:29.-127|WARN|emoncms_mqtt.php|Not connected, retrying connection
2023-04-16 15:06:35.019|WARN|emoncms_mqtt.php|Connecting to MQTT server: Connection Accepted.: code: 0
2023-04-16 15:06:54.-461|WARN|emoncms_mqtt.php|Not connected, retrying connection
2023-04-16 15:07:00.206|WARN|emoncms_mqtt.php|Not connected, retrying connection
2023-04-16 15:07:08.097|WARN|emoncms_mqtt.php|Not connected, retrying connection
2023-04-16 15:07:14.-419|WARN|emoncms_mqtt.php|Connecting to MQTT server: Connection Accepted.: code: 0
2023-04-16 17:20:14.-341|WARN|emoncms_mqtt.php|Not connected, retrying connection
2023-04-16 17:20:14.-257|WARN|emoncms_mqtt.php|Connecting to MQTT server: Connection Accepted.: code: 0
2023-04-17 11:56:24.012|WARN|emoncms_mqtt.php|Not connected, retrying connection
2023-04-17 11:56:24.060|WARN|emoncms_mqtt.php|Connecting to MQTT server: Connection Accepted.: code: 0

But these times co-inside when memory is becoming limited, not when working.

borpin · 17 April 2023 15:54

Those tend to be quite common warnings.
[edit]
Is emoncms set to log INFO (settings.ini)?

ullmf · 17 April 2023 15:57

Redis is running and there is no error in the error log.
I installed it with the emonscripts, without changes.
I have tried 4 combinations of Ubuntu 22.04 with PHP 8.1 and 8.2, and Ubuntu20.04 with PHP 8.1 and 8.2.
I always had the same problem.
Now I have set the CLI - php.ini to a memory limit of 2048M and so the memory consumption remains in a normal range, no freezing of the system when cleaning up memory and only very few gaps in the graphics.
It can run like this for now, but it’s not pretty.

The last years emonCMS ran on a Pi3 without problems with the same Inputs and outputs. Finally it was only moved to a much more powerful system…

Darren · 17 April 2023 16:04

Sadly it was set to WARN. I’ll repost later with some more logs.
I do see some PHP issues in apache2-error.log relating to the solar app, but I don’t think they’re related.

ullmf · 17 April 2023 16:05

Loglevel was 2 (warn) i changed it now to 1 (Info)

Darren · 17 April 2023 16:12

Setting to info, I get this repeatedly:

2023-04-17 16:08:20.-467|INFO|rememberme_model.php|cookieIsValid
2023-04-17 16:08:20.-463|INFO|rememberme_model.php|findTriplet TRIPLET_FOUND
2023-04-17 16:08:21.-475|INFO|rememberme_model.php|cookieIsValid
2023-04-17 16:08:21.-471|INFO|rememberme_model.php|findTriplet TRIPLET_FOUND
2023-04-17 16:08:22.122|INFO|rememberme_model.php|cookieIsValid
2023-04-17 16:08:22.126|INFO|rememberme_model.php|findTriplet TRIPLET_FOUND

borpin · 17 April 2023 16:12

Yes you do

lucwillems · 17 April 2023 18:56

i used the instalscript, but had to add

deb https://packages.sury.org/php/ bullseye main

for php 8.1 install as this was not available in debian, with this it could install all and compile phpredis and Mosquito-PHP

Darren · 17 April 2023 20:42

This graph shows how quickly memory is being used. The first 2 drops are when I rebooted, the last drop @13:00 is when I restarted the emoncms_mqtt service using the buttons on the admin page.

No new interesting messages have been logged in emoncms.log.

borpin · 18 April 2023 12:38

Thanks.

@Darren - could you raise an Issue on GitHub, please?

@TrystanLea

Darren · 18 April 2023 13:36