Swap File Growing - question on log rotate & demandshaper log

Hi

I have been following the discussions regarding log rotate. I don’t understand some of the detail but I do understand the principle.

I am self hosted on RPI and fully up to date as far as I know

I have had an issue for some time where the swap file grows, slowly at first and then very quickly fills totally and freezes the system. To avoid this I set up a daily reboot in cron as several times I was away and unable to clear the swap in a different way. Seeing all the comments regarding a solution to the log file issue I recently removed the reboot entry from cron. Unfortunately after a few days the swap file is growing again and I do not want to lose data.

One thing on my system that is maybe not to common. I have 4 smartplugs setup with Trystan’s help and have been testing demandshaper (which is now working well with few problems) and providing feedback. I understand Demandshaper generates a lot of logging. Is this logging included in the log rotate feature? If not it maybe the cause of my growing swap file.

If you run a full update, it should solve this problem.

The command

df -h

will tell you if it is the /var/log filling up.

It is possible that something else is causing the log to fill up.

Hi Ian, the thing to do is check your /var/log partition and it’s sub-folders to see which logfiles are getting too big.

Does demandshaper log to emoncms.log or it’s own logfile?

Have you fully updated recently to pull in the fixes for the issue?

Have you checked your update log to see if all updates are successfully applied?

If theres no obvious signs of updates not being applied, then we would need to check your logrotate components manually

ls -la /etc/cron.*/logrotate
ls -la /etc/logrotate*

should confirm if the symlinks are ok first, are there any logrotate logs at /var/log/logrotate?

Fully up to date as far as the logs show.

LAST ENTRIES ON THE LOG FILE
Starting update via service-runner-update.sh (v2.0) >
- emonSD version: emonSD-30Oct18
emonSD base image check passed...continue update
git pull /home/pi/emonpi
enable-ssh
enable-ssh-button
gpiozero-enable-ssh
greeebs-patch-1
* master
python-systemd-servicerunner
On branch master
Your branch is up-to-date with 'origin/master'.
nothing to commit, working tree clean
From https://github.com/openenergymonitor/emonpi
b8c057f..0a0c6ba master -> origin/master
Updating b8c057f..0a0c6ba
Fast-forward
defaults/etc/emonhub/emonhub.env | 3 ---
update/emonhub.sh | 19 +++++++++++++++----
2 files changed, 15 insertions(+), 7 deletions(-)
delete mode 100644 defaults/etc/emonhub/emonhub.env
-------------------------------------------------------------
Main Update Script
-------------------------------------------------------------
Date: Thu 20 Jun 19:10:07 UTC 2019
EUID: 1000
usrdir: /home/pi
type: emoncms
firmware: emonpi
Checking environment:
- pi user found

EUID: 1000
Hardware detected: rfm2pi
Stopping emonPiLCD service
Display update message on LCD
I2C LCD NOT DETECTED on either 0x['27', '3f'] ...exiting LCD script
Start emoncms update:

-------------------------------------------------------------
Emoncms update started
Emoncms update script V1.3 (26th March 2019)
-------------------------------------------------------------
- usr directory: /home/pi
- emoncms directory: /var/www/emoncms

current settings.php md5: 7a230f6017e462da706acc45ffeb077d
Default settings.php md5: 0e4803a641b7784ed23edf87506ce761
settings.php HAS been user modified

Checking status of /var/www/emoncms git repository
- git branch: stable
- no local changes
- running: git pull origin stable

From https://github.com/emoncms/emoncms
* branch stable -> FETCH_HEAD
Already up-to-date.

NEW default settings.php md5: 0e4803a641b7784ed23edf87506ce761
settings.php not updated

-------------------------------------------------------------
Updating Emoncms Modules
-------------------------------------------------------------

------------------------------------------
Updating /var/www/emoncms/Modules/app module
------------------------------------------
- git branch: stable
- git tags: 2.0.1-5-g6e5016a
- no local changes
- running: git pull origin stable

From https://github.com/emoncms/app
* branch stable -> FETCH_HEAD
Already up-to-date.

------------------------------------------
Updating /var/www/emoncms/Modules/config module
------------------------------------------
- git branch: stable
- git tags: 2.0.2-1-g1d9238e
- no local changes
- running: git pull origin stable

From https://github.com/emoncms/config
* branch stable -> FETCH_HEAD
Already up-to-date.

------------------------------------------
Updating /var/www/emoncms/Modules/dashboard module
------------------------------------------
- git branch: stable
- git tags: 2.0.2-6-gabd1a0b
- no local changes
- running: git pull origin stable

From https://github.com/emoncms/dashboard
* branch stable -> FETCH_HEAD
abd1a0b..337df80 stable -> origin/stable
Updating abd1a0b..337df80
Fast-forward
Views/dashboard_list.php | 318 +++++--
dashboard_controller.php | 8 +-
dashboard_model.php | 22 +-
locale/cy_GB/LC_MESSAGES/dashboard_messages.mo | Bin 0 -> 1067 bytes
locale/cy_GB/LC_MESSAGES/dashboard_messages.po | 1203 ++++++++++++++++++++++++
module.json | 2 +-
6 files changed, 1448 insertions(+), 105 deletions(-)
create mode 100644 locale/cy_GB/LC_MESSAGES/dashboard_messages.mo
create mode 100644 locale/cy_GB/LC_MESSAGES/dashboard_messages.po

------------------------------------------
Updating /var/www/emoncms/Modules/device module
------------------------------------------
- git branch: master
- git tags: 2.0.0-2-g2ea6e74
- no local changes
- running: git pull origin master

From https://github.com/emoncms/device
* branch master -> FETCH_HEAD
Already up-to-date.

------------------------------------------
Updating /var/www/emoncms/Modules/graph module
------------------------------------------
- git branch: stable
- git tags: 2.0.1-7-gc7f4ea9
- no local changes
- running: git pull origin stable

From https://github.com/emoncms/graph
* branch stable -> FETCH_HEAD
Already up-to-date.

------------------------------------------
Updating /var/www/emoncms/Modules/wifi module
------------------------------------------
- git branch: stable
- git tags: 2.0.0-3-gb67783d
- no local changes
- running: git pull origin stable

From https://github.com/emoncms/wifi
* branch stable -> FETCH_HEAD
Already up-to-date.

------------------------------------------
Updating postprocess module
------------------------------------------
- git branch: emonpi
- git tags: 2.1.0
- no local changes
- running: git pull origin emonpi

From https://github.com/emoncms/postprocess
3c2d737..1d25eb6 emonpi -> origin/emonpi
Updating 3c2d737..1d25eb6
Fast-forward
postprocess-module/postprocess_controller.php | 3 +--
1 file changed, 1 insertion(+), 2 deletions(-)
Already on 'emonpi'
Your branch is up-to-date with 'origin/emonpi'.

------------------------------------------
Updating sync module
------------------------------------------
- git branch: master
- git tags: 2.0.1-2-gc5eb931
- no local changes
- running: git pull origin master

From https://github.com/emoncms/sync
c5eb931..3ae3226 master -> origin/master
Updating c5eb931..3ae3226
Fast-forward
readme.md | 4 ++--
sync-module/sync_controller.php | 12 +++++-------
sync-module/sync_menu.php | 27 +++++++++++++++------------
sync-module/sync_view.php | 12 +-----------
4 files changed, 23 insertions(+), 32 deletions(-)
Already on 'master'
Your branch is up-to-date with 'origin/master'.

------------------------------------------
Updating backup module
------------------------------------------
- git branch: stable
- git tags: 2.0.0-12-g67a1f1d
- no local changes
- running: git pull origin stable

From https://github.com/emoncms/backup
67a1f1d..e365ab5 master -> origin/master
Already up-to-date.
Already on 'stable'
Your branch is up-to-date with 'origin/stable'.

------------------------------------------
Auto Installation of Emoncms Modules
------------------------------------------
- graph module already installed
- device module already installed
- postprocess module already installed
- sync module already installed
- backup module already installed

www-data : www-data video systemd-journal

------------------------------------------
SERVICES
------------------------------------------
emoncms_mqtt.service already installed
feedwriter.service already installed
service-runner.service already installed
------------------------------------------
Reloading systemctl deamon
Update Emoncms database
[]

Restarting Services...
- sudo systemctl restart feedwriter.service
--- ActiveState=active ---
- sudo systemctl restart emoncms_mqtt.service
--- ActiveState=active ---
- sudo systemctl restart emonhub.service
--- ActiveState=active ---
Symlinking emonpiupdate.log
Installing emoncms logrotate...

Now setting up Logrotate...
Backing up old logrotate configuration...
Linked to new logrotate configuration...
Backing up old logrotate cron job...
mv: cannot stat '/etc/cron.daily/logrotate': No such file or directory
Linked to new logrotate cron job...

Completed


Completed

Running logrotate...

set log rotate config owner to root

------------------------------------------
Emoncms update script complete
------------------------------------------


Starting emonPi LCD service..


-------------------------------------------------------------
emonPi update done: Thu 20 Jun 19:10:37 UTC 2019
-------------------------------------------------------------
restarting service-runner
service-runner: no process found

pi@emonpi:~ $ df -h
Filesystem      Size  Used Avail Use% Mounted on
/dev/root       3.9G  1.8G  2.0G  48% /
devtmpfs        484M     0  484M   0% /dev
tmpfs           489M     0  489M   0% /dev/shm
tmpfs           489M   19M  470M   4% /run
tmpfs           5.0M  4.0K  5.0M   1% /run/lock
tmpfs           489M     0  489M   0% /sys/fs/cgroup
tmpfs           1.0M     0  1.0M   0% /var/tmp
tmpfs            50M  2.2M   48M   5% /var/log
tmpfs            30M  4.0K   30M   1% /tmp
/dev/mmcblk0p1   43M   22M   21M  52% /boot
/dev/mmcblk0p3   26G  1.6G   23G   7% /home/pi/data
tmpfs            98M     0   98M   0% /run/user/1000
pi@emonpi:~ $

I rebooted this morning so will run df -h tomorrow to see any changes.

Hi

I believe demandshaper has its own log. I don’t know where it is placed.

Fully up to date

All successfully applied according to update log as far as I can tell see reply above.

lrwxrwxrwx 1 root root 46 Jun 20 19:10 /etc/cron.hourly/logrotate -> /var/www/ht                                    ml/emoncms/scripts/logger/logrotate
pi@emonpi:~ $ ls -la /etc/logrotate*
lrwxrwxrwx 1 root root   51 Jun 20 19:10 /etc/logrotate.conf -> /var/www/html/emoncms/scripts/logger/logrotate.conf

/etc/logrotate.d:
total 52
drwxr-xr-x  2 root root 4096 Mar 17 15:57 .
drwxr-xr-x 98 root root 4096 Jun 20 19:10 ..
-rw-r--r--  1 root root  433 Jun  2  2018 apache2
-rw-r--r--  1 root root  173 Sep 13  2017 apt
-rw-r--r--  1 root root   79 Apr 18  2017 aptitude
-rw-r--r--  1 root root  232 Jun 10  2015 dpkg
-rw-r--r--  1 root root  419 Jan 14  2017 lighttpd
-rw-r--r--  1 root root  154 Nov  3  2016 mosquitto
-rw-r--r--  1 root root  802 Jun  7  2017 mysql-server
-rw-r--r--  1 root root   99 Mar 17 15:57 nodered
-rw-r--r--  1 root root  124 Jun 14  2018 redis-server
-rw-r--r--  1 root root  515 Jan 18  2017 rsyslog
-rw-r--r--  1 root root  178 Aug  7  2014 ufw

are there any logrotate logs at /var/log/logrotate?

logrotate.zip (1.2 KB)

Hi

I found a reference to a command @TrystanLea gave me to access the log

 journalctl -f -u demandshaper -n100 

But it does not tell an inexperienced Linux user like me where the log is.

The command returns:-

pi@emonpi:~ $ journalctl -f -u demandshaper -n100
-- Logs begin at Thu 2016-11-03 17:16:43 UTC. --
Jun 21 10:24:27 emonpi systemd[1]: Started Emoncms MQTT Input Script.
Jun 21 10:24:29 emonpi demandshaper[901]: PHP Fatal error:  Uncaught RedisException: Connection refused in /home/pi/demandshaper/run.php:62
Jun 21 10:24:29 emonpi demandshaper[901]: Stack trace:
Jun 21 10:24:29 emonpi demandshaper[901]: #0 /home/pi/demandshaper/run.php(62): Redis->connect('localhost', 6379)
Jun 21 10:24:29 emonpi demandshaper[901]: #1 {main}
Jun 21 10:24:29 emonpi demandshaper[901]:   thrown in /home/pi/demandshaper/run.php on line 62
Jun 21 10:24:29 emonpi demandshaper[901]: Fatal error: Uncaught RedisException: Connection refused in /home/pi/demandshaper/run.php:62
Jun 21 10:24:29 emonpi demandshaper[901]: Stack trace:
Jun 21 10:24:29 emonpi demandshaper[901]: #0 /home/pi/demandshaper/run.php(62): Redis->connect('localhost', 6379)
Jun 21 10:24:29 emonpi demandshaper[901]: #1 {main}
Jun 21 10:24:29 emonpi demandshaper[901]:   thrown in /home/pi/demandshaper/run.php on line 62
Jun 21 10:24:29 emonpi systemd[1]: demandshaper.service: Main process exited, code=exited, status=255/n/a
Jun 21 10:24:29 emonpi systemd[1]: demandshaper.service: Unit entered failed state.
Jun 21 10:24:29 emonpi systemd[1]: demandshaper.service: Failed with result 'exit-code'.
Jun 21 10:25:36 emonpi systemd[1]: demandshaper.service: Service hold-off time over, scheduling restart.
Jun 21 10:25:36 emonpi systemd[1]: Stopped Emoncms MQTT Input Script.
Jun 21 10:25:36 emonpi systemd[1]: Started Emoncms MQTT Input Script.

which suggest quite a lot of activity.

At the top it shows:-
Logs begin at Thu 2016-11-03 17:16:43 UTC.

What does this date refer to?

That will only tell you if the log partition is filling up, the choking and use of swapfile already strongly suggests that is the case. You would be better off running

sudo ls -la /var/log/*/ /var/log

to see if any of the logs are too large.

Your logrotation.log shows a couple of issues which I have previously reported. Firstly

error: /etc/logrotate.conf:32 duplicate log entry for /var/log/auth.log

which is due to the changes made earlier this year to “fix” logrotate where the wildcards were expanded and the number of rotated logs reduced from 12 to 1, neither of these changes had any positive impact.

Reading state from file: /var/log/logrotate/logrotate.status

not required on the Oct2018 image as the original location is now RW, the fix for this should be for the updater to replace the original RO file on earlier images to a symlink to /tmp so all images can revert to the original (default) path.

there seems to be 2 emoncms.logs, one is in a emoncms sub-folder.

The new symlink for the emonpiupdate.log is failing to rotate (logrotate doesn’t follow symlinked logs) . And it seems that the logrotate command in the logrotate cron must be using the -l arg to create a logfile, this option in logrotate always overwrite previous logs, but because the emonSD only rotates with a minimum files size of 1M, it will never be rotated itself, so we can not see previous rotations. This log should be written using output redirection in the command-line instead of the -l arg.

However, none of that points to an imminent full log partition, so we will have to wait till you can get some more info.

What it tells us is that the demandshaper logs are just unhandled stdout and stderr being logged by systemd to journald. We know from experience of emonhub (and L2R) that this means the messages are probably being duplicated to syslog and deamon.log. Providing the output is minimal, it shouldn’t pose an issue. But if the output is high traffic (like emonhub) then the log partition will fill up in between hourly rotations and block logrotate from being able to function, leading to a choked system.

most likely when the demandshaper service was started last OR the earliest log entry once the service has been running a while and the journald logs are being trimmed so only the last nMB’s are retained.

Looking through log locations for demandshaper log I opened up syslog.

I found another puzzle. Many many lines showing Failed to connect to MQTT :-

Jun 21 15:19:30 emonpi lwrfd[1059]: Reconnecting to MQTT ...
Jun 21 15:19:30 emonpi lwrfd[1059]: Failed to connect to MQTT, return code -1
Jun 21 15:19:40 emonpi lwrfd[1059]: Reconnecting to MQTT ...
Jun 21 15:19:40 emonpi lwrfd[1059]: Failed to connect to MQTT, return code -1
Jun 21 15:19:50 emonpi lwrfd[1059]: Reconnecting to MQTT ...
Jun 21 15:19:51 emonpi lwrfd[1059]: Failed to connect to MQTT, return code -1
Jun 21 15:20:01 emonpi lwrfd[1059]: Reconnecting to MQTT ...
Jun 21 15:20:01 emonpi lwrfd[1059]: Failed to connect to MQTT, return code -1
Jun 21 15:20:02 emonpi CRON[4887]: (root) CMD (/usr/local/bin/wifi-check > /home/pi/data/wificheck.log 2>&1)
Jun 21 15:20:11 emonpi lwrfd[1059]: Reconnecting to MQTT ...
Jun 21 15:20:11 emonpi lwrfd[1059]: Failed to connect to MQTT, return code -1
Jun 21 15:20:21 emonpi lwrfd[1059]: Reconnecting to MQTT ...
Jun 21 15:20:21 emonpi lwrfd[1059]: Failed to connect to MQTT, return code -1
Jun 21 15:20:31 emonpi lwrfd[1059]: Reconnecting to MQTT ...
Jun 21 15:20:31 emonpi lwrfd[1059]: Failed to connect to MQTT, return code -1
Jun 21 15:20:41 emonpi lwrfd[1059]: Reconnecting to MQTT ...
Jun 21 15:20:42 emonpi lwrfd[1059]: Failed to connect to MQTT, return code -1
Jun 21 15:20:52 emonpi lwrfd[1059]: Reconnecting to MQTT ...
Jun 21 15:20:52 emonpi lwrfd[1059]: Failed to connect to MQTT, return code -1
Jun 21 15:21:02 emonpi lwrfd[1059]: Reconnecting to MQTT ...
Jun 21 15:21:02 emonpi lwrfd[1059]: Failed to connect to MQTT, return code -1
Jun 21 15:21:12 emonpi lwrfd[1059]: Reconnecting to MQTT ...
Jun 21 15:21:12 emonpi lwrfd[1059]: Failed to connect to MQTT, return code -1
Jun 21 15:21:22 emonpi lwrfd[1059]: Reconnecting to MQTT ...
Jun 21 15:21:22 emonpi lwrfd[1059]: Failed to connect to MQTT, return code -1

But the emoncms log shows

2019-06-21 10:25:37.808|WARN|emoncms_mqtt.php|Not connected, retrying connection
2019-06-21 10:25:37.838|WARN|emoncms_mqtt.php|Connecting to MQTT server: Connection Accepted.: code: 0

And my mqtt connections to and from NodeRed are working.

My MQTT server is on a different RPI as is NodeRed.

they all relate to lwrfd, if you are not using lwrfd on this particular pi then I doubt you have configured it to look to the remote mqtt broker which might be why it fails to connect (to the local broker if it’s not running)

Hi Paul

Re the issues you mention with log rotate. Is this something I need to deal with or is it a fix needed to the way log rotate currently runs. And if so should I bring it to any ones attention?

The whole logs in RAM and logrotate setup is under review, personally I think the current position needs some triage in the interim (and I have said as much) but I don’t think that’s on the cards.

Lets find out what the root issue is first, if it’s a runaway log, a bit of triage to the existing setup isn’t going to resolve it so tacking the source is probably the better plan at this point.

This morning the system has been up 22 hours.

Swap Used: 0.00%

That’s the first time I have seen empty swap after a days use!

For the record:-

pi@emonpi:~/demandshaper $ sudo ls -la /var/log/*/ /var/log
/var/log:
total 2624
drwxr-xr-x 13 root      root          600 Jun 22 07:17 .
drwxr-xr-x 12 root      root         4096 Aug  2  2018 ..
drwxr-xr-x  2 root      adm           120 Jun 22 08:17 apache2
-rw-r-----  1 root      adm         78945 Jun 22 08:46 auth.log
-rw-r--r--  1 root      root         6684 Jun 21 10:24 boot.log
-rw-------  1 root      utmp         1152 Jun 22 08:42 btmp
-rw-r-----  1 root      adm         76843 Jun 22 08:46 daemon.log
-rw-r-----  1 root      adm       1095810 Jun 22 07:17 daemon.log.1
-rw-r-----  1 root      adm          1177 Jun 21 10:24 debug
drwxr-xr-x  2 pi        pi             80 Jun 21 16:01 emoncms
-rw-rw-rw-  1 root      root            0 Jun 21 10:24 emoncms.log
drwxrwxr-x  2 emonhub   emonhub        60 Jun 21 10:24 emonhub
drwxr-xr-x  2 pi        root           60 Jun 21 10:24 emonpilcd
-rw-r-----  1 root      adm         65157 Jun 22 08:45 kern.log
drwxr-xr-x  2 pi        pi             80 Jun 22 08:17 logrotate
-rw-r-----  1 root      adm         45753 Jun 22 08:45 messages
drwxr-xr-x  2 mosquitto mosquitto      40 Jun 21 10:24 mosquitto
-rw-rw-rw-  1 root      root            0 Jun 21 10:24 mqtt_input.log
drwxr-xr-x  2 mysql     adm            60 Jun 21 10:24 mysql
-rw-rw-rw-  1 root      root            0 Jun 21 10:24 mysql.log
-rw-rw-rw-  1 root      root            0 Jun 21 10:24 ntp_update.log
drwxr-xr-x  2 root      root           40 Jun 21 10:24 openhab
drwxr-xr-x  2 root      root           40 Jun 21 10:24 openhab2
drwxr-xr-x  2 redis     redis          60 Jun 21 10:24 redis
-rw-rw-rw-  1 root      root            0 Jun 21 10:24 service-runner.log
drwxr-xr-x  2 root      root           60 Jun 21 10:24 supervisor
-rw-r-----  1 root      adm        191337 Jun 22 08:46 syslog
-rw-r-----  1 root      adm       1087784 Jun 22 05:17 syslog.1
-rw-r-----  1 root      adm           396 Jun 21 10:24 user.log
-rw-rw-r--  1 root      utmp         4224 Jun 22 08:42 wtmp

/var/log/apache2/:
total 1692
drwxr-xr-x  2 root adm      120 Jun 22 08:17 .
drwxr-xr-x 13 root root     600 Jun 22 07:17 ..
-rw-r--r--  1 root root  345540 Jun 22 08:46 access.log
-rw-r--r--  1 root root 1377463 Jun 22 08:17 access.log.1
-rw-rw-rw-  1 root adm     1951 Jun 22 08:15 error.log
-rw-r--r--  1 root root       0 Jun 21 10:24 other_vhosts_access.log

/var/log/emoncms/:
total 4
drwxr-xr-x  2 pi   pi     80 Jun 21 16:01 .
drwxr-xr-x 13 root root  600 Jun 22 07:17 ..
-rw-rw-rw-  1 root root 1058 Jun 22 08:42 emoncms.log
lrwxrwxrwx  1 pi   pi     30 Jun 21 16:01 emonpiupdate.log -> /home/pi/data/emonpiupdate.log

/var/log/emonhub/:
total 8
drwxrwxr-x  2 emonhub emonhub   60 Jun 21 10:24 .
drwxr-xr-x 13 root    root     600 Jun 22 07:17 ..
-rwxrwxr-x  1 emonhub emonhub 6378 Jun 21 16:01 emonhub.log

/var/log/emonpilcd/:
total 4
drwxr-xr-x  2 pi   root  60 Jun 21 10:24 .
drwxr-xr-x 13 root root 600 Jun 22 07:17 ..
-rw-r--r--  1 pi   root 306 Jun 21 16:01 emonpilcd.log

/var/log/logrotate/:
total 12
drwxr-xr-x  2 pi   pi     80 Jun 22 08:17 .
drwxr-xr-x 13 root root  600 Jun 22 07:17 ..
-rw-r--r--  1 root root 5506 Jun 22 08:17 logrotate.log
-rw-r--r--  1 root root 1088 Jun 22 08:17 logrotate.status

/var/log/mosquitto/:
total 0
drwxr-xr-x  2 mosquitto mosquitto  40 Jun 21 10:24 .
drwxr-xr-x 13 root      root      600 Jun 22 07:17 ..

/var/log/mysql/:
total 4
drwxr-xr-x  2 mysql adm    60 Jun 21 10:24 .
drwxr-xr-x 13 root  root  600 Jun 22 07:17 ..
-rw-rw-rw-  1 mysql adm  1569 Jun 21 10:24 error.log

/var/log/openhab/:
total 0
drwxr-xr-x  2 root root  40 Jun 21 10:24 .
drwxr-xr-x 13 root root 600 Jun 22 07:17 ..

/var/log/openhab2/:
total 0
drwxr-xr-x  2 root root  40 Jun 21 10:24 .
drwxr-xr-x 13 root root 600 Jun 22 07:17 ..

/var/log/redis/:
total 4
drwxr-xr-x  2 redis redis   60 Jun 21 10:24 .
drwxr-xr-x 13 root  root   600 Jun 22 07:17 ..
-rw-rw-rw-  1 redis redis 4017 Jun 21 10:24 redis-server.log

/var/log/supervisor/:
total 0
drwxr-xr-x  2 root root  60 Jun 21 10:24 .
drwxr-xr-x 13 root root 600 Jun 22 07:17 ..
-rw-rw-rw-  1 root root   0 Jun 21 10:24 supervisord.log
pi@emonpi:~/demandshaper $

There are quite a lot of messages going into the daemon.log and syslog. What we have discovered is that output to Std outputs end up here via rsyslog and are often duplicated.

What do these logs largely consist of (in terms of messages)? Is there a lot from the demandshaper or is it something else?

[edit]

As Paul said, these relate to the lwrfd service. If you are not using this service you should mask it so it will not run. I will guess the command to see if there is a service there (never used it);

systemctl status lwrfd

Thanks for responding

daemon syslog.zip (70.1 KB)

Nearly all lwrfd failing to connect to mqtt

pi@emonpi:~ $ systemctl status lwrfd
● lwrfd.service - LSB: LightwaveRF MQTT daemon startup
   Loaded: loaded (/etc/init.d/lwrfd; generated; vendor preset: enabled)
   Active: active (running) since Fri 2019-06-21 10:24:32 UTC; 1 day 6h ago
     Docs: man:systemd-sysv-generator(8)
   CGroup: /system.slice/lwrfd.service
           └─1059 /usr/local/bin/lwrfmqtt

Jun 22 16:59:42 emonpi lwrfd[1059]: Reconnecting to MQTT ...
Jun 22 16:59:42 emonpi lwrfd[1059]: Failed to connect to MQTT, return code -1
Jun 22 16:59:52 emonpi lwrfd[1059]: Reconnecting to MQTT ...
Jun 22 16:59:52 emonpi lwrfd[1059]: Failed to connect to MQTT, return code -1
Jun 22 17:00:02 emonpi lwrfd[1059]: Reconnecting to MQTT ...
Jun 22 17:00:02 emonpi lwrfd[1059]: Failed to connect to MQTT, return code -1
Jun 22 17:00:12 emonpi lwrfd[1059]: Reconnecting to MQTT ...
Jun 22 17:00:13 emonpi lwrfd[1059]: Failed to connect to MQTT, return code -1
Jun 22 17:00:23 emonpi lwrfd[1059]: Reconnecting to MQTT ...
Jun 22 17:00:23 emonpi lwrfd[1059]: Failed to connect to MQTT, return code -1
pi@emonpi:~ $

What is the masking command format?

Try sudo systemctl mask --now lwrfd that should stop the service, disable it from starting at boot and mask it all in one hit, you can check it again with systemctl status lwrfd.

[Edit] or it might be sudo systemctl mask lwrfd --now I can’t be sure now.

1 Like

I think it is

sudo systemctl --now mask lwrfd

From man systemctl

 systemctl [OPTIONS...] COMMAND [NAME...]

Today up 2 days 7 minutes

Swap at 2% 2MB

pi@emonpi:~ $ sudo ls -la /var/log/*/ /var/log
/var/log:
total 3268
drwxr-xr-x 13 root      root          600 Jun 23 04:17 .
drwxr-xr-x 12 root      root         4096 Aug  2  2018 ..
drwxr-xr-x  2 root      adm           120 Jun 23 09:17 apache2
-rw-r-----  1 root      adm        156663 Jun 23 10:33 auth.log
-rw-r--r--  1 root      root         6684 Jun 21 10:24 boot.log
-rw-------  1 root      utmp         1152 Jun 22 08:42 btmp
-rw-r-----  1 root      adm        321377 Jun 23 10:33 daemon.log
-rw-r-----  1 root      adm       1069647 Jun 23 04:17 daemon.log.1
-rw-r-----  1 root      adm          1177 Jun 21 10:24 debug
drwxr-xr-x  2 pi        pi             80 Jun 21 16:01 emoncms
-rw-rw-rw-  1 root      root            0 Jun 21 10:24 emoncms.log
drwxrwxr-x  2 emonhub   emonhub        60 Jun 21 10:24 emonhub
drwxr-xr-x  2 pi        root           60 Jun 21 10:24 emonpilcd
-rw-r-----  1 root      adm         99060 Jun 23 10:33 kern.log
drwxr-xr-x  2 pi        pi             80 Jun 23 10:17 logrotate
-rw-r-----  1 root      adm         63659 Jun 23 10:31 messages
drwxr-xr-x  2 mosquitto mosquitto      40 Jun 21 10:24 mosquitto
-rw-rw-rw-  1 root      root            0 Jun 21 10:24 mqtt_input.log
drwxr-xr-x  2 mysql     adm            60 Jun 21 10:24 mysql
-rw-rw-rw-  1 root      root            0 Jun 21 10:24 mysql.log
-rw-rw-rw-  1 root      root            0 Jun 21 10:24 ntp_update.log
drwxr-xr-x  2 root      root           40 Jun 21 10:24 openhab
drwxr-xr-x  2 root      root           40 Jun 21 10:24 openhab2
drwxr-xr-x  2 redis     redis          60 Jun 21 10:24 redis
-rw-rw-rw-  1 root      root            0 Jun 21 10:24 service-runner.log
drwxr-xr-x  2 root      root           60 Jun 21 10:24 supervisor
-rw-r-----  1 root      adm        503247 Jun 23 10:33 syslog
-rw-r-----  1 root      adm       1082933 Jun 23 01:17 syslog.1
-rw-r-----  1 root      adm           396 Jun 21 10:24 user.log
-rw-rw-r--  1 root      utmp         5760 Jun 23 10:33 wtmp

/var/log/apache2/:
total 2148
drwxr-xr-x  2 root adm      120 Jun 23 09:17 .
drwxr-xr-x 13 root root     600 Jun 23 04:17 ..
-rw-r--r--  1 root root  836903 Jun 23 10:33 access.log
-rw-r--r--  1 root root 1349436 Jun 23 09:17 access.log.1
-rw-rw-rw-  1 root adm     6153 Jun 23 09:30 error.log
-rw-r--r--  1 root root       0 Jun 21 10:24 other_vhosts_access.log

/var/log/emoncms/:
total 4
drwxr-xr-x  2 pi   pi     80 Jun 21 16:01 .
drwxr-xr-x 13 root root  600 Jun 23 04:17 ..
-rw-rw-rw-  1 root root 1544 Jun 23 10:31 emoncms.log
lrwxrwxrwx  1 pi   pi     30 Jun 21 16:01 emonpiupdate.log -> /home/pi/data/emonpiupdate.log

/var/log/emonhub/:
total 8
drwxrwxr-x  2 emonhub emonhub   60 Jun 21 10:24 .
drwxr-xr-x 13 root    root     600 Jun 23 04:17 ..
-rwxrwxr-x  1 emonhub emonhub 6378 Jun 21 16:01 emonhub.log

/var/log/emonpilcd/:
total 4
drwxr-xr-x  2 pi   root  60 Jun 21 10:24 .
drwxr-xr-x 13 root root 600 Jun 23 04:17 ..
-rw-r--r--  1 pi   root 306 Jun 21 16:01 emonpilcd.log

/var/log/logrotate/:
total 12
drwxr-xr-x  2 pi   pi     80 Jun 23 10:17 .
drwxr-xr-x 13 root root  600 Jun 23 04:17 ..
-rw-r--r--  1 root root 4985 Jun 23 10:17 logrotate.log
-rw-r--r--  1 root root 1088 Jun 23 10:17 logrotate.status

/var/log/mosquitto/:
total 0
drwxr-xr-x  2 mosquitto mosquitto  40 Jun 21 10:24 .
drwxr-xr-x 13 root      root      600 Jun 23 04:17 ..

/var/log/mysql/:
total 4
drwxr-xr-x  2 mysql adm    60 Jun 21 10:24 .
drwxr-xr-x 13 root  root  600 Jun 23 04:17 ..
-rw-rw-rw-  1 mysql adm  1569 Jun 21 10:24 error.log

/var/log/openhab/:
total 0
drwxr-xr-x  2 root root  40 Jun 21 10:24 .
drwxr-xr-x 13 root root 600 Jun 23 04:17 ..

/var/log/openhab2/:
total 0
drwxr-xr-x  2 root root  40 Jun 21 10:24 .
drwxr-xr-x 13 root root 600 Jun 23 04:17 ..

/var/log/redis/:
total 4
drwxr-xr-x  2 redis redis   60 Jun 21 10:24 .
drwxr-xr-x 13 root  root   600 Jun 23 04:17 ..
-rw-rw-rw-  1 redis redis 4017 Jun 21 10:24 redis-server.log

/var/log/supervisor/:
total 0
drwxr-xr-x  2 root root  60 Jun 21 10:24 .
drwxr-xr-x 13 root root 600 Jun 23 04:17 ..
-rw-rw-rw-  1 root root   0 Jun 21 10:24 supervisord.log
pi@emonpi:~ $

lwrfd stopped so now see what another day does to swap.

pi@emonpi:~ $ systemctl status lwrfd
● lwrfd.service
   Loaded: masked (/dev/null; bad)
   Active: inactive (dead)

Jun 23 10:33:56 emonpi lwrfd[1059]: Reconnecting to MQTT ...
Jun 23 10:33:56 emonpi lwrfd[1059]: Failed to connect to MQTT, return code -1
Jun 23 10:34:06 emonpi lwrfd[1059]: Reconnecting to MQTT ...
Jun 23 10:34:06 emonpi lwrfd[1059]: Failed to connect to MQTT, return code -1
Jun 23 10:34:16 emonpi lwrfd[1059]: Reconnecting to MQTT ...
Jun 23 10:34:17 emonpi lwrfd[1059]: Failed to connect to MQTT, return code -1
Jun 23 10:34:27 emonpi lwrfd[1059]: Reconnecting to MQTT ...
Jun 23 10:34:27 emonpi lwrfd[1059]: Failed to connect to MQTT, return code -1
Jun 23 10:34:35 emonpi systemd[1]: Stopping lwrfd.service...
Jun 23 10:34:35 emonpi systemd[1]: Stopped lwrfd.service.
pi@emonpi:~ $
1 Like

This morning up time 3 days.

Swap at 4.75MB

pi@emonpi:~ $ sudo ls -la /var/log/*/ /var/log
/var/log:
total 3544
drwxr-xr-x 13 root      root          600 Jun 23 04:17 .
drwxr-xr-x 12 root      root         4096 Aug  2  2018 ..
drwxr-xr-x  2 root      adm           120 Jun 24 10:17 apache2
-rw-r-----  1 root      adm        227308 Jun 24 10:22 auth.log
-rw-r--r--  1 root      root         6684 Jun 21 10:24 boot.log
-rw-------  1 root      utmp         1152 Jun 22 08:42 btmp
-rw-r-----  1 root      adm        362388 Jun 24 10:18 daemon.log
-rw-r-----  1 root      adm       1069647 Jun 23 04:17 daemon.log.1
-rw-r-----  1 root      adm          1177 Jun 21 10:24 debug
drwxr-xr-x  2 pi        pi             80 Jun 21 16:01 emoncms
-rw-rw-rw-  1 root      root            0 Jun 21 10:24 emoncms.log
drwxrwxr-x  2 emonhub   emonhub        60 Jun 21 10:24 emonhub
drwxr-xr-x  2 pi        root           60 Jun 21 10:24 emonpilcd
-rw-r-----  1 root      adm        134130 Jun 24 10:18 kern.log
drwxr-xr-x  2 pi        pi             80 Jun 24 10:17 logrotate
-rw-r-----  1 root      adm         82685 Jun 24 10:18 messages
drwxr-xr-x  2 mosquitto mosquitto      40 Jun 21 10:24 mosquitto
-rw-rw-rw-  1 root      root            0 Jun 21 10:24 mqtt_input.log
drwxr-xr-x  2 mysql     adm            60 Jun 21 10:24 mysql
-rw-rw-rw-  1 root      root            0 Jun 21 10:24 mysql.log
-rw-rw-rw-  1 root      root            0 Jun 21 10:24 ntp_update.log
drwxr-xr-x  2 root      root           40 Jun 21 10:24 openhab
drwxr-xr-x  2 root      root           40 Jun 21 10:24 openhab2
drwxr-xr-x  2 redis     redis          60 Jun 21 10:24 redis
-rw-rw-rw-  1 root      root            0 Jun 21 10:24 service-runner.log
drwxr-xr-x  2 root      root           60 Jun 21 10:24 supervisor
-rw-r-----  1 root      adm        622520 Jun 24 10:20 syslog
-rw-r-----  1 root      adm       1082933 Jun 23 01:17 syslog.1
-rw-r-----  1 root      adm           396 Jun 21 10:24 user.log
-rw-rw-r--  1 root      utmp         6528 Jun 24 10:18 wtmp

/var/log/apache2/:
total 1544
drwxr-xr-x  2 root adm      120 Jun 24 10:17 .
drwxr-xr-x 13 root root     600 Jun 23 04:17 ..
-rw-r--r--  1 root root   63989 Jun 24 10:22 access.log
-rw-r--r--  1 root root 1414924 Jun 24 10:17 access.log.1
-rw-rw-rw-  1 root adm    94655 Jun 24 09:28 error.log
-rw-r--r--  1 root root       0 Jun 21 10:24 other_vhosts_access.log

/var/log/emoncms/:
total 4
drwxr-xr-x  2 pi   pi     80 Jun 21 16:01 .
drwxr-xr-x 13 root root  600 Jun 23 04:17 ..
-rw-rw-rw-  1 root root 1888 Jun 24 10:18 emoncms.log
lrwxrwxrwx  1 pi   pi     30 Jun 21 16:01 emonpiupdate.log -> /home/pi/data/emonpiupdate.log

/var/log/emonhub/:
total 8
drwxrwxr-x  2 emonhub emonhub   60 Jun 21 10:24 .
drwxr-xr-x 13 root    root     600 Jun 23 04:17 ..
-rwxrwxr-x  1 emonhub emonhub 6378 Jun 21 16:01 emonhub.log

/var/log/emonpilcd/:
total 4
drwxr-xr-x  2 pi   root  60 Jun 21 10:24 .
drwxr-xr-x 13 root root 600 Jun 23 04:17 ..
-rw-r--r--  1 pi   root 306 Jun 21 16:01 emonpilcd.log

/var/log/logrotate/:
total 12
drwxr-xr-x  2 pi   pi     80 Jun 24 10:17 .
drwxr-xr-x 13 root root  600 Jun 23 04:17 ..
-rw-r--r--  1 root root 5506 Jun 24 10:17 logrotate.log
-rw-r--r--  1 root root 1089 Jun 24 10:17 logrotate.status

/var/log/mosquitto/:
total 0
drwxr-xr-x  2 mosquitto mosquitto  40 Jun 21 10:24 .
drwxr-xr-x 13 root      root      600 Jun 23 04:17 ..

/var/log/mysql/:
total 4
drwxr-xr-x  2 mysql adm    60 Jun 21 10:24 .
drwxr-xr-x 13 root  root  600 Jun 23 04:17 ..
-rw-rw-rw-  1 mysql adm  1569 Jun 21 10:24 error.log

/var/log/openhab/:
total 0
drwxr-xr-x  2 root root  40 Jun 21 10:24 .
drwxr-xr-x 13 root root 600 Jun 23 04:17 ..

/var/log/openhab2/:
total 0
drwxr-xr-x  2 root root  40 Jun 21 10:24 .
drwxr-xr-x 13 root root 600 Jun 23 04:17 ..

/var/log/redis/:
total 4
drwxr-xr-x  2 redis redis   60 Jun 21 10:24 .
drwxr-xr-x 13 root  root   600 Jun 23 04:17 ..
-rw-rw-rw-  1 redis redis 4017 Jun 21 10:24 redis-server.log

/var/log/supervisor/:
total 0
drwxr-xr-x  2 root root  60 Jun 21 10:24 .
drwxr-xr-x 13 root root 600 Jun 23 04:17 ..
-rw-rw-rw-  1 root root   0 Jun 21 10:24 supervisord.log

I don’t want to let the swap get much bigger as past experience suggests it will suddenly grow very rapidly and freeze the Pi.

What is the best way to clear the Swap? I have been rebooting.

What does df -h tell you?

[edit]
You can delete any log file named *.1

Use this truncate command to clear the biggest log files. Reboot Required Every 20 Days Or So To Restore Logging - #35 by borpin

Other than that, you need to investigate what is generating the messages.

Is this a recent EmonSD image as the base?

1 Like

Interesting that swap is still increasing with the stopped lwrfd logging. seeing the output of df -h as @borpin suggests would be useful. Can you tell which logs are now increasing at the faster rate?

Just want to clear up that the demandshaper service does use the emoncms logger https://github.com/emoncms/demandshaper/blob/master/run.php#L34 but it looks like it missed catching a couple of errors above which then went to stdout.