/var/log filled up in emonSD-03May16

Hi,

I’ve got emonSD-03May16 running on a Pi, which was rebooted 6 days ago. Today I found that that /var/log Filesystem is full, and looks like it filled up around 08:26:16 yesterday (Monday 23rd), and it looks like logrotate hasn’t been working.

The logrotate log file shows zero length, but with a recent timestamp:

-rw-r--r-- 1 root root 0 May 24 21:17 /var/log/logrotate/logrotate.log

The status file shows timestamp from when logging filled up:
-rw-r--r-- 1 root root 29 May 23 08:17 /var/log/logrotate/logrotate.status
[email protected]:/etc $ cat /var/log/logrotate/logrotate.status
logrotate state -- version 2

When I look in /var/log, there are no .gz files - but the logrotate.conf shows it should compress in place?

ls -l /var/log
total 42352
drwxr-xr-x 2 root adm 60 May 17 21:02 apache2
-rw-r----- 1 root adm 25419776 May 24 21:46 auth.log
-rw------- 1 root utmp 0 May 17 21:01 btmp
-rw-r----- 1 root adm 229376 May 24 21:46 daemon.log
-rw-r----- 1 root adm 989 May 17 21:02 debug
-rw-rw-rw- 1 root root 405 May 17 22:03 emoncms.log
drwxr-xr-x 2 emonhub root 80 May 23 04:02 emonhub
drwxr-xr-x 2 pi root 60 May 17 21:01 emonpilcd
-rw-r----- 1 root adm 49152 May 24 21:17 kern.log
drwxr-xr-x 2 pi pi 80 May 24 21:17 logrotate
-rw-r----- 1 root adm 49152 May 24 21:17 messages
-rw-rw-rw- 1 root root 0 May 17 21:02 mqtt_input.log
drwxr-xr-x 2 mysql adm 60 May 17 21:02 mysql
-rw-rw-rw- 1 root root 0 May 17 21:02 mysql.log
drwxr-xr-x 2 openhab openhab 240 May 23 23:59 openhab
drwxr-xr-x 2 redis redis 60 May 17 21:02 redis
-rw-rw-rw- 1 root root 1740800 May 24 21:45 service-runner.log
-rw-r----- 1 root adm 15863808 May 24 21:46 syslog
-rw-rw-r-- 1 root utmp 6528 May 24 20:47 wtmp

/etc/logrotate.conf is a link to /var/www/emoncms/scripts/logger/logrotate.conf which I haven’t changed:
-rw-r--r-- 1 pi pi 768 Apr 29 10:46 /var/www/emoncms/scripts/logger/logrotate.conf

The logrotate.conf has a comment
# default is daily run, move cron script to make this happen hourly:
# sudo mv /etc/cron.daily/logrotate /etc/cron.hourly/logrotate

so I looked in /etc/cron.daily/logrotate and it’s a zero length file:
-rw-r--r-- 1 root root 0 Apr 28 22:17 /etc/cron.daily/logrotate

And logrotate also exists in cron.hourly and it’s a link:
lrwxrwxrwx 1 root root 41 Jan 26 15:35 /etc/cron.hourly/logrotate -> /var/www/emoncms/scripts/logger/logrotate

-rwxrwxr-x 1 pi pi 175 Feb 20 15:57 /var/www/emoncms/scripts/logger/logrotate

cat /var/www/emoncms/scripts/logger/logrotate
#!/bin/sh

test -x /usr/sbin/logrotate || exit 0
/usr/sbin/logrotate -v -s /var/log/logrotate/logrotate.status /etc/logrotate.conf 2>&1 | tee /var/log/logrotate/logrotate.log

Any ideas ? should I try to delete the empty logrotate file from /etc/cron.daily/ ?

Also, I don’t know if this is related or not, but root crontab seems to contain lots of identical entries:

sudo crontab -l
<comments snipped>
# m h dom mon dow command

*/5 * * * * /usr/local/bin/wifi-check > /home/pi/data/wificheck.log 2>&1

          • /home/pi/emonpi/service-runner >> /var/log/service-runner.log 2>&1
          • /home/pi/emonpi/service-runner >> /var/log/service-runner.log 2>&1
          • /home/pi/emonpi/service-runner >> /var/log/service-runner.log 2>&1
          • /home/pi/emonpi/service-runner >> /var/log/service-runner.log 2>&1
          • /home/pi/emonpi/service-runner >> /var/log/service-runner.log 2>&1
          • /home/pi/emonpi/service-runner >> /var/log/service-runner.log 2>&1
          • /home/pi/emonpi/service-runner >> /var/log/service-runner.log 2>&1
          • /home/pi/emonpi/service-runner >> /var/log/service-runner.log 2>&1
          • /home/pi/emonpi/service-runner >> /var/log/service-runner.log 2>&1
          • /home/pi/emonpi/service-runner >> /var/log/service-runner.log 2>&1
          • /home/pi/emonpi/service-runner >> /var/log/service-runner.log 2>&1
          • /home/pi/emonpi/service-runner >> /var/log/service-runner.log 2>&1
          • /home/pi/emonpi/service-runner >> /var/log/service-runner.log 2>&1
          • /home/pi/emonpi/service-runner >> /var/log/service-runner.log 2>&1
          • /home/pi/emonpi/service-runner >> /var/log/service-runner.log 2>&1

I don’t understand why service-runner needs so many entries?

Any help is appreciated.
Ian

Hmm, just found this thread when I started searching for the service-runner problem Extra service-runner commands in crontab - Part II

So looks like a known problem - I just need to re-read to see what I need to do.

I ran into the same issue. Run the latest Update. In the sudo crontab there should be zero service-runner lines. In the Pi user crontab, there should one service-runner line

Ian, got to say I’m impressed with the way you’ve presented your support request, providing loads of information to enable this issue to be resolved.
…wishing others would/could do the same!

Hopefully, Jon’s post will help.

Paul

@Paul - I have an emonPi and I can click in an Update Now button on the Administration page. How does the emonbase Pi (or any other Pi device) do an update?

@Jon - thanks for confirming I was on the right track. Currently running the update - after I worked out how to do the update, as this is the first time i’ve updated from the web interface ! I was on a back level version for a long time (“ain’t broke don’t fix it”) until I updated to the new May 3rd image, so am still getting up to speed on the auto-update features.

@Paul - thanks - I guess that’s 30 years working in IT showing through :wink:

@Jon Since I upgraded from the back level code to the current emonSD, I understand I am now running the same image on my RPi /emonbase as is used on the emonPi, so I also have “update” button in the Admin section of local emoncms. I’ve just run the update, now rebooting as requested in the output from update process. root crontab was already looking better :wink:

The updates are normally done by git ‘pulling’ any changes from the emoncms repo into the local installation.
Simply SSH into the pi, navigate to the emoncms directory, and issue the command ‘git pull’.
You also have the flexibility to ‘pull’ different branches to test new features, or roll back to known stable versions.
But… it’s not for everyone, Git is a bit of a beast, and like learning a foreign language!

Paul

Ho Hum. Feeds not appearing at emoncms.org. emonhub.log shows it’s sending data and getting OK acknowledgment, and correct API key still in emohub.conf. :frowning:

I had that also! Look in the emonhub config near the bottom. The is an [[11]] that needs two line feeds before it!

@Jon Thanks Job - updated and rebooting now…

Doesn’t seem to have fixed it. Checked emonhub.log, no error about config file, although an odd warning which seems to relate to the RFM2Pi module, but I don’t think that is a problem as log says it’s sending data to emoncms.org:

cat emonhub.log
2016-05-24 23:10:30,254 INFO MainThread EmonHub emonHub ‘emon-pi’ variant v1.1
2016-05-24 23:10:30,257 INFO MainThread Opening hub…
2016-05-24 23:10:30,354 INFO MainThread Logging level set to DEBUG
2016-05-24 23:10:30,357 INFO MainThread Creating EmonHubJeeInterfacer ‘RFM2Pi’
2016-05-24 23:10:30,433 DEBUG MainThread Opening serial port: /dev/ttyAMA0 @ 38400 bits/s
2016-05-24 23:10:32,439 WARNING MainThread Device communication error - check settings
2016-05-24 23:10:32,442 INFO MainThread Setting RFM2Pi frequency: 433 (4b)
2016-05-24 23:10:33,446 INFO MainThread Setting RFM2Pi group: 210 (210g)
2016-05-24 23:10:34,450 INFO MainThread Setting RFM2Pi quiet: 0 (0q)
2016-05-24 23:10:35,454 INFO MainThread Setting RFM2Pi baseid: 5 (5i)
2016-05-24 23:10:36,458 INFO MainThread Setting RFM2Pi calibration: 230V (1p)
2016-05-24 23:10:37,462 DEBUG MainThread Setting RFM2Pi subchannels: [‘ToRFM12’]
2016-05-24 23:10:37,466 DEBUG MainThread Interfacer: Subscribed to channel’ : ToRFM12
2016-05-24 23:10:37,468 DEBUG MainThread Setting RFM2Pi pubchannels: [‘ToEmonCMS’]
2016-05-24 23:10:37,502 DEBUG MainThread Interfacer: Subscribed to channel’ : ToRFM12
2016-05-24 23:10:37,561 INFO MainThread Creating EmonHubMqttInterfacer ‘MQTT’
2016-05-24 23:10:37,565 INFO MainThread MQTT Init mqtt_host=127.0.0.1 mqtt_port=1883 mqtt_user=emonpi
2016-05-24 23:10:37,648 DEBUG MainThread MQTT Subscribed to channel’ : ToEmonCMS
2016-05-24 23:10:37,717 INFO MainThread Creating EmonHubEmoncmsHTTPInterfacer ‘emoncmsorg’
2016-05-24 23:10:37,754 DEBUG MainThread emoncmsorg Subscribed to channel’ : ToEmonCMS
2016-05-24 23:10:37,822 INFO MQTT Connecting to MQTT Server
2016-05-24 23:10:37,964 INFO MQTT connection status: Connection successful
2016-05-24 23:10:37,968 DEBUG MQTT CONACK => Return code: 0
2016-05-24 23:10:38,222 INFO MQTT on_subscribe
2016-05-24 23:10:47,776 INFO emoncmsorg sending: https://emoncms.org/input/bulk.json?apikey=E-M-O-N-C-M-S-A-P-I-K-E-Y&data=[]&sentat=1464131447
2016-05-24 23:10:48,951 DEBUG emoncmsorg acknowledged receipt with ‘ok’ from https://emoncms.org
2016-05-24 23:10:57,824 INFO emoncmsorg sending: https://emoncms.org/input/bulk.json?apikey=E-M-O-N-C-M-S-A-P-I-K-E-Y&data=[]&sentat=1464131457
2016-05-24 23:10:58,758 DEBUG emoncmsorg acknowledged receipt with ‘ok’ from https://emoncms.org

time to bring in the big guns! I am out of my skill level!
@Paul?!?

It’s late and I need to go to bed, but any other suggestions will be appreciated.

I have searched the forums, and found Some feeds not updating after upgrading 8.4.0 -> 9.6.0 which mentioned time zone setting, which I have never changed, and was still at UTC, but have changed to Europe/London on local emoncms and emoncms.org, but not made any difference. emonhub.log still shows ‘ok’ acknowledgement from emoncms.org, api key matches what is in emoncms.org, but Inputs not updating.

Thanks for your help tonight guys.

there are two timezone settings. One is a command line. The other one is in Setup > My Account > My Profile:

Maybe this one needs to be set?!?

Hi Ian, What model RFM2Pi are you using and what baud is it running at?

You are right in thinking this appears odd because of the emoncms log entries, otherwise the log simply shows emonhub tries to create an RFM2Pi interfacer with a baud of 38400 and then advises to check the settings for your device as it cannot communicate with it.

so try changing the baud in emonhub.conf if you suspect it could be different (ie 9800 or 57600) otherwise look for a connection / seating issue.

Although it does also show some (attempted) posts to emoncms, the payload is empty “data=[]” and therefore misleading, which is then acknowledged by emoncms.org as successfully received, which although arguably accurate it is again misleading as it did successfully receive no data!

@pb66 Hi Paul, Thanks for your help. I had noticed that emonhub.log did not have the details of packets being processed like it used to, and I incorrectly assumed this was due to a change in logging levels as a result of the update.

As I lay in bed trying to go to sleep last night I reconsidered this, and the warning message about connection to RFM2pi, and wondered if that was the problem. This morning a quick check showed the red led was on solid on the rfm69cw module.

I did a shutdown halt, and powered off the Pi, and after it restarted, it’s all working again. I didn’t change any of the settings in emonhub.conf.

I need to dash to work now, but will be happy to provide any further information later

Thanks
Ian

Hi @IanDavies, sorry to hear you’re having trouble. Agree, thanks for your excellent support request with plenty of info to work with. Also thanks a lot to @Jon and @Paul.

If a user is running a pre-built image (emonSD-03May16) then updata via the web interface should be used rather than git pull since the web interface update does more that just git pull e.g. update db, fix logrotate issue, fix emonhub nodes issue, fix service runner user permission issue etc. The web interface update will work the same on both emonPi and em on Basel (RFM69Pi + Raspberry Pi).

This emonhub conf spacing issue should now be fixed with the latest update.

A solid red light indicates the the RFM12Pi unit has crashed. A power cycle should fix it. This is the reason why the emonhub log does not show any received packets. Do you have a newer RFM69Pi or an older RFM12Pi? . This is an ongoing issue, that only seems to affect some users:

Hi @glyn.hudson I have an RFM69CW (bought from the OEM shop about a year ago) connected to an existing RPi.

Do you mean RFM69Pi? The RFM69CW is the name of the RF module, the RFM69Pi is the name of the whole unit:

Did a power cycle fix the hanging issue?