/var/log full with errors from emoncms.log

I was just using certbot on my emonHub and python was reporting failures to write to /var/log. So I checked and /var/log is 100% full.

pi@emonpi(rw):log$ df -h
Filesystem      Size  Used Avail Use% Mounted on
/dev/root       3.4G  2.0G  1.3G  62% /
devtmpfs        483M     0  483M   0% /dev
tmpfs           487M     0  487M   0% /dev/shm
tmpfs           487M   56M  432M  12% /run
tmpfs           5.0M  4.0K  5.0M   1% /run/lock
tmpfs           487M     0  487M   0% /sys/fs/cgroup
tmpfs            40M  6.6M   34M  17% /var/lib/openhab
tmpfs           1.0M     0  1.0M   0% /var/lib/dhcp
tmpfs           1.0M  8.0K 1016K   1% /var/lib/dhcpcd5
tmpfs            50M   50M     0 100% /var/log
tmpfs            30M   48K   30M   1% /tmp
/dev/mmcblk0p1   60M   21M   40M  35% /boot
/dev/mmcblk0p3   25G  1.8G   22G   8% /home/pi/data

The files taking up the most space are the emoncms.log files.

pi@emonpi(rw):log$ ls -l
total 49420
drwxr-xr-x 2 root      adm             80 Jul  2 23:17 apache2
-rw-r----- 1 root      adm         626688 Jul  9 18:36 auth.log
-rw-r----- 1 root      adm        1056218 Jul  3 09:17 auth.log.1
-rw-r----- 1 root      adm        1053608 Jun 30 11:17 auth.log.2
-rw-r--r-- 1 root      root          7029 May 24 18:04 boot.log
-rw------- 1 root      utmp          4992 Jul  5 11:40 btmp
-rw-r----- 1 root      adm         626688 Jul  9 18:35 daemon.log
-rw-r----- 1 root      adm        1054505 Jul  1 23:17 daemon.log.1
-rw-r----- 1 root      adm        1053409 Jun 27 02:17 daemon.log.2
-rw-r----- 1 root      adm           1014 May 24 18:03 debug
-rw-rw-rw- 1 root      root      16105472 Jul  9 18:36 emoncms.log
-rw-rw-rw- 1 root      root       2097152 Jul  9 18:17 emoncms.log.1
-rw-rw-rw- 1 root      root       1032192 Jul  9 17:17 emoncms.log.2
-rw-rw-rw- 1 root      root      13164544 Jul  9 16:17 emoncms.log.3
drwxr-xr-x 2 emonhub   root            60 May 24 18:03 emonhub
drwxr-xr-x 2 pi        root            60 May 24 18:03 emonpilcd
-rw-r----- 1 root      adm         606208 Jul  9 18:20 kern.log
-rw-r----- 1 root      adm        1074933 Jul  4 00:17 kern.log.1
-rw-r----- 1 root      adm        1076545 Jul  3 06:17 kern.log.2
drwx------ 2 root      root           480 Jul  9 18:21 letsencrypt
drwxr-xr-x 2 pi        pi              80 Jul  9 18:17 logrotate
-rw-r----- 1 root      adm         606208 Jul  9 18:20 messages
-rw-r----- 1 root      adm        1074933 Jul  4 00:17 messages.1
-rw-r----- 1 root      adm        1076545 Jul  3 06:17 messages.2
drwxr-xr-x 2 mosquitto mosquitto       60 May 24 18:03 mosquitto
-rw-rw-rw- 1 root      root             0 May 24 18:03 mqtt_input.log
drwxr-xr-x 2 mysql     adm             60 May 24 18:03 mysql
-rw-rw-rw- 1 root      root             0 May 24 18:03 mysql.log
-rw-rw-rw- 1 root      root             0 May 24 18:03 ntp_update.log
drwxr-xr-x 2 openhab   openhab        100 Jun 21 03:11 openhab
drwxr-xr-x 2 redis     redis           60 May 24 18:03 redis
-rw-rw-rw- 1 root      root        491520 Jul  9 18:36 service-runner.log
-rw-rw-rw- 1 root      root       1048684 Jun 21 18:17 service-runner.log.1
drwxr-xr-x 2 root      root            60 May 24 18:03 supervisor
-rw-r----- 1 root      adm         892928 Jul  9 18:36 syslog
-rw-r----- 1 root      adm        1091782 Jul  4 00:17 syslog.1
-rw-r----- 1 root      adm        1126311 Jul  3 10:17 syslog.2
-rw-r----- 1 root      adm         376832 Jul  9 18:20 ufw.log
-rw-r----- 1 root      adm        1066596 Jul  4 04:17 ufw.log.1
-rw-r----- 1 root      adm        1052964 Jul  3 10:17 ufw.log.2
-rw-rw-r-- 1 root      utmp         24576 Jul  9 18:30 wtmp

So I looked at emoncms.log and it has lots and lots of this:

2018-07-04 20:17:04.637|ERROR|input_controller.php|Reached the maximal allowed number of diferent NodeIds, limit is 32. Node '17' was ignored.
2018-07-04 20:17:04.761|ERROR|input_controller.php|Reached the maximal allowed number of diferent NodeIds, limit is 32. Node '17' was ignored.
2018-07-04 20:17:04.943|ERROR|input_controller.php|Reached the maximal allowed number of diferent NodeIds, limit is 32. Node '17' was ignored.
2018-07-04 20:17:05.205|ERROR|input_controller.php|Reached the maximal allowed number of diferent NodeIds, limit is 32. Node '17' was ignored.
2018-07-04 20:17:05.274|ERROR|input_controller.php|Reached the maximal allowed number of diferent NodeIds, limit is 32. Node '17' was ignored.
2018-07-04 20:17:05.570|ERROR|input_controller.php|Reached the maximal allowed number of diferent NodeIds, limit is 32. Node '17' was ignored.
2018-07-04 20:17:05.643|ERROR|input_controller.php|Reached the maximal allowed number of diferent NodeIds, limit is 32. Node '17' was ignored.
2018-07-04 20:17:05.883|WARN|PHPFiwa.php|PHPFiwa:post failed to fetch meta id=88088
2018-07-04 20:17:05.893|WARN|PHPFiwa.php|PHPFiwa:post failed to fetch meta id=88089
2018-07-04 20:17:05.903|WARN|PHPFiwa.php|PHPFiwa:post failed to fetch meta id=88122
2018-07-04 20:17:05.921|WARN|PHPFina.php|post() padding max block size exeeded id=88117, 12904994 dp
2018-07-04 20:17:05.942|ERROR|input_controller.php|Reached the maximal allowed number of diferent NodeIds, limit is 32. Node '17' was ignored.
2018-07-04 20:17:06.101|WARN|PHPFiwa.php|PHPFiwa:post failed to fetch meta id=88088
2018-07-04 20:17:06.111|WARN|PHPFiwa.php|PHPFiwa:post failed to fetch meta id=88089
2018-07-04 20:17:06.125|WARN|PHPFiwa.php|PHPFiwa:post failed to fetch meta id=88122
2018-07-04 20:17:06.145|WARN|PHPFina.php|post() padding max block size exeeded id=88117, 12904994 dp
2018-07-04 20:17:06.168|ERROR|input_controller.php|Reached the maximal allowed number of diferent NodeIds, limit is 32. Node '17' was ignored.
2018-07-04 20:17:06.295|WARN|PHPFiwa.php|PHPFiwa:post failed to fetch meta id=88088
2018-07-04 20:17:06.304|WARN|PHPFiwa.php|PHPFiwa:post failed to fetch meta id=88089
2018-07-04 20:17:06.323|WARN|PHPFiwa.php|PHPFiwa:post failed to fetch meta id=88122

First of all, what should I do to clear the logs? Just rm them and allow new logs to start posting?

Second, any idea what is going on?

I think this is one for @Paul or @TrystanLea

How many node ID’s are you using? The log is saying that you have exceeded the default of 32, is that so?

The limit is set within the emoncms settings file, so as to avoid problems with RF, but can be increased if necessary.

As for deleting the logs, I don’t use an emonpi, but it looks as though they are written to tmpfs (RAM) so a reboot??

To add to Paul’s reply, the error

may be being caused by input processes that are trying write to feeds that you have deleted. If you can fix both the nodes and this error at least your log will only fill up slowly.

… and to add to @Paul and @TrystanLea’s comments, the lines like these


2018-07-04 20:17:05.921|WARN|PHPFina.php|post() padding max block size exeeded id=88117, 12904994 dp

are where you have started trying to add data to phpfina feeds that have been dormant for a considerable length of time. You will need to recreate those feeds or change the max-padding limit to allow you to post new data. The phpfina file sizes relate directly to the age of the feed, ie a phpfina feed with just 2 datapoints 1 year apart will be equal in size to a feed that has a complete years worth of data.

Thanks, all. Things are working better now. There was a combination of things going on, all having to do with some old feeds that came in when I moved to my current setup.

I don’t have 32 nodes. My emonCMS server subscribes to an older version of emonHub right now, from when it would add a numbered node when it had a packet that seemed to be for that node. I’ve noticed that over time I seem to collect “garbage” nodes. I needed to go delete those.

You are correct. A reboot did the trick.

Once I got rid of the extraneous nodes and deleted old feeds that were causing problems, the log went quiet.

If I could ask one related question …

Is it true that PHPFIWA is essentially deprecated? I read that comment from Paul in a thread a while back (below). Some of my old feeds were PHPFIWA feeds that I had created in parallel with PHPFINA so I could compare the two engines.

Thanks again,
Brandon