EmonCMS stopped showing historical data, feeds still updating fine

I’m trying to troubleshoot a problem here … My EmonCMS stopped updating historical data on the charts a few days ago, as can be seen here:

The feeds itself are still being updated just fine, nothing wrong with realtime data:

I tried to see if there was any log/alert on EmonCMS itself and did not find it. I’ve logged into the EmonPI instance via SSH and looked at disk usage, the first thing I’ve noticed is that /var/log is small and 100% occupied:
image

dmesg shows a long list of entries, but nothing strikes me as an error or smoking gun:

[4898821.161036] [UFW BLOCK] IN=wlan0 OUT= MAC=b8:27:eb:3f:73:e0:5c:cf:7f:ab:ac:10:08:00 SRC=192.168.6.18 DST=224.0.0.251 LEN=32 TOS=0x00 PREC=0x00 TTL=1 ID=45953 PROTO=2
[4898846.392169] [UFW BLOCK] IN=wlan0 OUT= MAC=b8:27:eb:3f:73:e0:10:be:f5:85:78:a1:08:00 SRC=192.168.6.1 DST=224.0.0.1 LEN=32 TOS=0x00 PREC=0x00 TTL=1 ID=36998 DF PROTO=2
[4898906.671513] [UFW BLOCK] IN=wlan0 OUT= MAC=b8:27:eb:3f:73:e0:10:be:f5:85:78:a1:08:00 SRC=192.168.6.1 DST=224.0.0.1 LEN=32 TOS=0x00 PREC=0x00 TTL=1 ID=37010 DF PROTO=2
[4898912.255367] [UFW BLOCK] IN=wlan0 OUT= MAC=b8:27:eb:3f:73:e0:5c:cf:7f:ab:ac:10:08:00 SRC=192.168.6.18 DST=224.0.0.251 LEN=32 TOS=0x00 PREC=0x00 TTL=1 ID=45970 PROTO=2
[4898914.230703] [UFW BLOCK] IN=wlan0 OUT= MAC=b8:27:eb:3f:73:e0:54:60:09:d0:55:60:08:00 SRC=192.168.6.19 DST=224.0.0.251 LEN=32 TOS=0x00 PREC=0xC0 TTL=1 ID=0 DF PROTO=2
[4898939.705056] [UFW BLOCK] IN=wlan0 OUT= MAC=b8:27:eb:3f:73:e0:c4:e9:84:bc:d9:a0:08:00 SRC=192.168.6.2 DST=224.0.0.1 LEN=32 TOS=0x00 PREC=0xC0 TTL=1 ID=0 DF PROTO=2
[4898942.909127] [UFW BLOCK] IN=wlan0 OUT= MAC=b8:27:eb:3f:73:e0:54:60:09:d0:55:60:08:00 SRC=192.168.6.19 DST=224.0.0.251 LEN=32 TOS=0x00 PREC=0xC0 TTL=1 ID=0 DF PROTO=2

Any ideas on what should I look at next to troubleshoot this problem?

Thanks in advance!
Claudio

Hello Claudio

Could you take a look at the Emoncms Admin page, are all the services running? In particular Im wondering about the feedwriter service?

Or via command line:

sudo service feedwriter status

I notice you log folder is full, it would be good to clear that of the largest log files as well

Try the following to find what the largest logs may be

ls -lh /var/log/
ls -lh /var/log/emonhub
ls -lh /var/log/emoncms

You can then usually clear them by changing the user to root and then clearing them with the pipe command e.g:

sudo -s
> /var/log/emoncms/emoncms.log

> is the bash redirect command.

| is the pipe command. (not to be confused with a lower case L)

1 Like

Thanks for the correction @Bill.Thomson

thumbsup

You are all so quick and willing to help, thank you! Let me answer each question:

Could you take a look at the Emoncms Admin page, are all the services running?

I’m afraid I don’t know where to find this view in the EmonCMS app. Here’s what I see from the setup menu: (logged-in, version 9.9.3)
image

But looking via the command line as suggested, the feedwriter service seems ok:

pi@emonpi(ro):~$ sudo service feedwriter status
● feedwriter.service - LSB: feedwriter script daemon
   Loaded: loaded (/etc/init.d/feedwriter)
   Active: active (exited) since Mon 2020-06-15 10:50:08 BRT; 1 months 1 days ago
  Process: 14063 ExecStop=/etc/init.d/feedwriter stop (code=exited, status=0/SUCCESS)
  Process: 21553 ExecStart=/etc/init.d/feedwriter start (code=exited, status=0/SUCCESS)

Warning: Journal has been rotated since unit was started. Log output is incomplete or unavailable.
pi@emonpi(ro):~$

Try the following to find what the largest logs may be

Nothing super gigantic,here’s the output:

pi@emonpi(ro):~$ ls -lh /var/log/
total 43M
drwxr-xr-x 2 root      adm         60 May 21 18:18 apache2
-rw-r----- 1 root      adm       124K Jul 17 13:40 auth.log
-rw-r----- 1 root      adm       1.0M Jul 14 13:17 auth.log.1
-rw-r----- 1 root      adm          0 Jul 14 12:17 auth.log.2
-rw-r--r-- 1 root      root       20K May 21 18:18 boot.log
-rw------- 1 root      utmp         0 May 21 18:17 btmp
-rw-r----- 1 root      adm       716K Jul 17 13:40 daemon.log
-rw-r----- 1 root      adm       1.7K May 21 18:17 debug
-rw-rw-rw- 1 root      root       23M Jul  9 01:22 emoncms.log
-rw-rw-rw- 1 root      root      5.4M Jul 17 13:17 emoncms.log.1
-rw-rw-rw- 1 root      root         0 Jul 17 12:17 emoncms.log.2
-rw-rw-rw- 1 root      root      2.5M Jul 17 11:17 emoncms.log.3
drwxr-xr-x 2 emonhub   root       120 Jul 17 13:17 emonhub
drwxr-xr-x 2 pi        root        80 Jun 15 11:11 emonpilcd
-rw-r----- 1 root      adm       540K Jul 17 13:40 kern.log
-rw-r----- 1 root      adm       1.1M Jun 14 22:17 kern.log.1
-rw-r----- 1 root      adm       1.1M Jun 13 17:17 kern.log.2
drwxr-xr-x 2 pi        pi          80 Jul 17 13:17 logrotate
-rw-r----- 1 root      adm       536K Jul 17 13:40 messages
-rw-r----- 1 root      adm       1.1M Jun 14 22:17 messages.1
-rw-r----- 1 root      adm       1.1M Jun 13 17:17 messages.2
drwxr-xr-x 2 mosquitto mosquitto   60 May 21 18:18 mosquitto
-rw-rw-rw- 1 root      root         0 May 21 18:18 mqtt_input.log
drwxr-xr-x 2 mysql     adm         60 May 21 18:18 mysql
-rw-rw-rw- 1 root      root         0 May 21 18:18 mysql.log
-rw-rw-rw- 1 root      root         0 May 21 18:18 ntp_update.log
drwxr-xr-x 2 openhab   openhab     40 May 21 18:18 openhab
drwxr-xr-x 2 redis     redis       60 May 21 18:18 redis
-rw-rw-rw- 1 root      root       614 Jun 30 19:20 service-runner.log
drwxr-xr-x 2 root      root        60 May 21 18:18 supervisor
-rw-r----- 1 root      adm       916K Jul 17 13:40 syslog
-rw-r----- 1 root      adm       1.1M Jun 14 20:17 syslog.1
-rw-r----- 1 root      adm       1.1M Jun 13 21:17 syslog.2
-rw-r----- 1 root      adm       364K Jul 17 13:40 ufw.log
-rw-r----- 1 root      adm       1.1M Jun 15 02:17 ufw.log.1
-rw-r----- 1 root      adm       1.1M Jun 13 21:17 ufw.log.2
-rw-rw-r-- 1 root      utmp      1.9K Jul 17 11:34 wtmp
pi@emonpi(ro):~$ ls -lh /var/log/emonhub
total 5.8M
-rw-r--r-- 1 emonhub root 3.3M Jul 17 13:40 emonhub.log
-rw-r--r-- 1 emonhub root    0 Jul 17 13:17 emonhub.log.1
-rw-r--r-- 1 emonhub root 2.5M Jul 17 12:17 emonhub.log.2
-rw-r--r-- 1 emonhub root    0 Jul 17 11:17 emonhub.log.3
pi@emonpi(ro):~$ ls -lh /var/log/emoncms
ls: cannot access /var/log/emoncms: No such file or directory
pi@emonpi(ro):~$ 

I looked into the largest file (emoncms.log), and the last few entries seem OK, there were a few API key erros (I had a wrong key cached on another device) and some mosquitto errors, but no smoking gun around the date the historical data stops. Here’s the tail end:

#0 /var/www/emoncms/scripts/phpmqtt_input.php(121): Mosquitto\Client->loop()
#1 {main}
2020-06-15 13:26:45.237|ERROR|phpmqtt_input.php|exception 'Mosquitto\Exception' in /var/www/emoncms/scripts/phpmqtt_input.php:121
Stack trace:
#0 /var/www/emoncms/scripts/phpmqtt_input.php(121): Mosquitto\Client->loop()
#1 {main}
2020-06-15 13:29:39.986|ERROR|phpmqtt_input.php|exception 'Mosquitto\Exception' in /var/www/emoncms/scripts/phpmqtt_input.php:121
Stack trace:
#0 /var/www/emoncms/scripts/phpmqtt_input.php(121): Mosquitto\Client->loop()
#1 {main}
2020-06-15 13:31:46.511|ERROR|phpmqtt_input.php|exception 'Mosquitto\Exception' in /var/www/emoncms/scripts/phpmqtt_input.php:121
Stack trace:
#0 /var/www/emoncms/scripts/phpmqtt_input.php(121): Mosquitto\Client->loop()
#1 {main}
2020-06-15 13:44:15.003|WARN|phpmqtt_input.php|Not connected, retrying connection
2020-06-15 13:44:17.065|WARN|phpmqtt_input.php|Connecting to MQTT server: Connection Accepted.: code: 0
2020-06-15 23:05:04.303|ERROR|index.php|Invalid API key 'fd8e071852ff0058c13014a7e82b8265'
2020-06-15 23:14:02.032|ERROR|index.php|Invalid API key 'fd8e071852ff0058c13014a7e82b8265'

So now I’m truncating it to see whether it makes a difference:

pi@emonpi(ro):log$ sudo truncate --size 0 emoncms.log && ls -l emoncms.log
-rw-rw-rw- 1 root root 0 Jul 17 13:50 emoncms.log
pi@emonpi(ro):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.9M   34M  18% /var/lib/openhab
tmpfs           1.0M     0  1.0M   0% /var/lib/dhcpcd5
tmpfs           1.0M  4.0K 1020K   1% /var/lib/dhcp
tmpfs            50M   28M   23M  55% /var/log
tmpfs           1.0M     0  1.0M   0% /var/tmp
tmpfs            30M   36K   30M   1% /tmp
/dev/mmcblk0p1   60M   21M   40M  35% /boot
/dev/mmcblk0p3  3.5G  372M  3.0G  12% /home/pi/data
pi@emonpi(ro):log$

So far (~5min), it did not. Next thing I’ll probably try rebooting the Pi.

Great thanks, it looks like feedwriter is exited above, could you try:

sudo service feedwriter restart

You nailed it, restarting the service fixed the issue. To be honest, my lack of familiarity meant that I’d interpreted the “active” part of “active (exited)” in the service status as “oh, it is active, so it must be running”.

Now, for the real puzzling part, after restarting the feedwriter service, there is no gap in history in the charts, as can be seen in the image below:

Was the data buffered somewhere (where?) and the feedwritter service picked up the slack after it restarted? That is great and I’m very happy to see that there are no gaps, but I’d like to understand the mechanism by which this feat is possible :slight_smile:

Yes that’s it, it was buffered, luckily I caught you before you rebooted the system as you would have lost it had you rebooted :slight_smile:

Yes, that was very good indeed. But out of curiosity, do you know where it is buffered? In memory? Temp filesystem on ramdisk? Other?

@heckler, this is clearly an older system so I’d suggest your SD card may be getting tired. At a minimum, I’d suggest keeping regular backups.

I do manual backups monthly. One of these days I’ll have to spend the time and see if I can get it automated. I have another dedicated Pi running Home Assistant, and just recently configured it to perform daily full backups to Google Drive - it brings so much peace of mind …

You can manually run

/opt/emoncms/modules/backup/emoncms-export.sh

A cron job set to run the export script Brian mentioned, is one way to do that.

Although you need to move it off the SD Card as well.

My new Proxmox setup does a nightly backup of the whole container :grinning:.