EmonPi stopped updating inputs - /var/log/ full

I’m working from memory, you could check the build guide. But we don’t know how valid that is.

Were there any planned changes to the logrotation? You could check the emonpi update routine code to see if there are any changes in there?

Otherwise, your guess is as good as mine.

[Edit - what about cron.daily? Is the original cron job still there?]

I have just deployed a fix for /var/log filling up on emonPi and emonBase users. To install the fix just run emonPi / emonBase update from admin page of local emoncms.

emonPi update will install a logrotate config that we developed with the help of @Paul for the previous emonSD image. This logrotate config was missed out of the latest image, hence this issue of /var/log filling up.

Here’s the contents of the update:

###################################################################################
# Install log rotate config
###################################################################################
echo "Installing emoncms logrotate..."
echo

# Remove already roated old log files to free up space incase /var/log is full
if ls /var/log/syslog.* > /dev/null 2>&1; then
  sudo rm /var/log/syslog.*
fi

if ls /var/log/*.log.* > /dev/null 2>&1; then
  sudo rm /var/log/*.log.*
fi

# Install emonPi log rotate config
sudo /var/www/emoncms/scripts/logger/install.sh
# Run log roate manually
echo "Running logrotate..."
sudo /usr/sbin/logrotate -v -s /var/log/logrotate/logrotate.status /etc/logrotate.conf > /dev/null 2>&1

Here’s the actual logrotate config that gets installed, unlike the default logrotate this config instructs logrotate to only store 2 rotations of log files and rotate each log after 1Mb. The update will run log rotate manually then after that logrotate will run periodically in the background to clean up logs.

Please report back if this fixes the issue for you.

We can mark it as a solution if it works!!

Two thoughts

  • It has not solved the issue of the emonhub logging going to both the emonhub.log file and syslog (which is part of the root cause).
  • It has not solved keeping logs for longer to aid debugging. This should be straight forward by telling logrotate to save the rotated files to another location on the SD card.

The two logfiles are I think syslog and daemon.log, both seem to have logging content replicated. emonhub.log is no longer written too.

Will discuss the persisting question further with Glyn, perhaps if we can reduce the volume of logging, set the logs to error rather than debug it could work.

What is the concern? There is usually several GB of space free on an SDcard so logs kept for a week are unlikely to fill the SDcard.

The concern is coming from the issues we had a couple of years back where SD cards kept getting corrupted due to excessive writing. SD cards can only handle a relatively low number of repeated writes to the same bit of disk.

Most of the original write load was the repeated writing to the same location on disk resulting from the way we used mysql, the switch to redis for feed and input last time and value fields got rid of a lot of that.

We also made a concerted effort to make all significant writing append only in order to reduce the extent to which the same sd card blocks get written to repeatedly. We also added buffering.

One potential risk of an hourly sync of /var/log without rsync, I think, is that we again start writing over and over the same blocks.

The concern is not that we will fill the SD card its just about trying to avoid the write issue.

We can certainly try rsync, as I’ve said this is a starting point. Much will depend on the logrotation as well. If you are rotating files really quickly then cp or rsync will predominantly be writing new files, just cp won’t be checking first. Hopefully we can relax the log rotations so that users that don’t catch a problem within a couple of hours, do not need to dredge through zipped compressed [edited before I get corrected] rotated files.

1 Like

Yes agreed, multi writes are bad, but as the frequency would be what, ah hour? This is way less than feedwriter, so I do not think it will stress the card more than the data writes do.

I don’t think wear levelling is a new thing for most major SD card manufacturers is it? While it is certainly true that repeated writes to an SD Card will wear it out (My first one died after 12 months of being written to about every few seconds), I don’t think its necessarily “writing to the same location”.

I’m pretty sure most SD cards are good for about 100,000 writes per block, which if you were writing to the same block over and over again every second, would only last 27.7 hours, or 69.4 days if you were writing every minute. I can’t say I’ve ever seen them wear out that fast.

Please understand that I’m not saying we shouldn’t be cognisant of SD Card wear, we just need to be careful not to overstate it.

Also worth mentioning that with wear levelling on a larger card, there’s more blocks to spread the writes around on, so the same wear happens at a slower rate as well.

[EDIT] The converse is also true of course… if your SD card is almost full, there’s very little the wear levelling can do to help you and you WILL be writing to the same locations far more often…

Yes I am aware of wear levelling. We discussed this all quite a bit years back, I can’t quite remember now but it was never quite clear to me how safe it was to rely on it completely… Perhaps it wasn’t the issue and it was all just write volume, here’s the testing I did as part of that effort to reduce the write load, its been a while since I looked at all that Learn | OpenEnergyMonitor

I totally agree that we need to be careful with the writing load, it is just that I think writing a couple of logs every hour or so is negligible wear. Writing the logs directly to the disk is another matter which definitely need to be avoided.

I think that’s probably the case.

I had a weather station and a CurrentCost logging to my Pi1B with a 4GB SD card. It was logging data every minute (from memory) for the weather station and every 4 seconds from the CurrentCost (again from memory). Both of those sets of data were being written to their own RRDs. That SD card stopped writing (it actually went read-only) after just over 12 months.

That was my introduction to SD Card write limits!

It was easy to fix - I just re-imaged the card to a new one and off it went again, but I changed my scripts so that the RRD’s were stored in a tmpfs and flushed (cp’d) to the SD card every 10 minutes. I switched to OEM on a Pi2B+ about 18 months ago, so I’m no longer logging the CurrentCost data but the Pi1B is still running with that same re-imaged card I put into it about 5 years ago.

2 Likes

Interesting. Didn’t know that. I thought the card would be corrupted. Just used dd?

In general, once flash memory becomes corrupted, it becomes read-only.
But, it’s possible for it to become corrupted in a manner which prevents reading as well as writing.
e.g. if the inode table gets mangled.

1 Like

In my cases (and I have had 2 instances now where I’ve exhausted the write life), the filesystem didn’t even need a fsck after it had been imaged to a new card.
I used a windows SD imaging tool, but dd would have done the same trick.

1 Like

Me again with another install that is filling up /var/log/ in less then 24 hours with feedwriter lines (deamon and syslog) these finish by clogging the partition and after a while the little pi locks up and a manual reboot is needed. There are 101 feeds on that that box.
Have to add this is a pi with an external SSD (this thing )
But since /var/log is not on SSD and limited in space … I have emonhub on error level but I think feedwriter logs are coming in and there isn’t a setting for it (or at least I didn’t find it) . Is there a way to stop these feedwriter lines in the logs ? Like only on error ???

Or is my only hope to move the logs partition to the ssd ???

I did update the pi to latest but even the logrotate can’t cope with the massive spitting of lines
In 4 minutes the syslog grew from 251342 to 310812 (after a reboot to clean the partition)

thanks for ideas, solutions :grin:

Server Information
Services
emonhub Active Running
emoncms_mqtt Active Running
feedwriter Active Running - sleep 60s
service-runner Active Running
emonPiLCD Active Exited
redis-server Active Running
mosquitto Active Running
Emoncms Version low-write 9.9.8
Modules Administration : App v1.2.1 : Backup v1.1.6 : EmonHub Config v1.1.0 : Dashboard v1.3.3 : Device v1.2.1 : EventProcesses : Feed : Graph v1.2.3 : Input : Postprocess v1.0.0 : CoreProcess : Schedule : Network Setup v1.0.0 : sync : Time : User : Visualisation : WiFi v1.3.1
Git URL: GitHub - emoncms/emoncms: Web-app for processing, logging and visualising energy, temperature and other environmental data : Branch: * stable : Describe: v9.5.1-1775-gd0db7a57
Server OS Linux 4.14.98-v7+
Host emonpi_130 : emonpi_130 : (192.168.1.130)
Date 2019-03-25 19:07:05 CET
Uptime 19:07:05 up 13 min, 1 user, load average: 0.11, 0.06, 0.04
HTTP Server Apache/2.4.25 (Raspbian) HTTP/1.1 CGI/1.1 80
MySQL Version 5.5.5-10.1.23-MariaDB-9+deb9u1
Host 127.0.0.1 (127.0.0.1)
Date 2019-03-25 19:07:05 (UTC 01:00‌​)
Stats Uptime: 778 Threads: 4 Questions: 1588 Slow queries: 0 Opens: 26 Flush tables: 1 Open tables: 20 Queries per second avg: 2.041
Redis Version 3.2.6
Host localhost:6379 (127.0.0.1)
Size
Uptime 0 days
MQTT Server Version Mosquitto 1.4.10
Host localhost:1883 (127.0.0.1)
Pi Model Raspberry Pi 3 Model B+ Rev 1.3 - 1 GB (Sony UK)
SoC Broadcom BCM2835
Serial num. 5CFC8383
Temperature CPU: 40.78°C - GPU: 40.8’C
Release emonSD-30Oct18
Memory RAM Used: 19.49% Total: 976.73 MB Used: 190.39 MB Free: 786.35 MB
Swap Used: 0.00% Total: 100 MB Used: 0 B Free: 100 MB
Disk Mount Stats
/ Used: 8.17% Total: 22.8 GB Used: 1.86 GB Free: 19.75 GB
/boot Used: 51.49% Total: 42.52 MB Used: 21.89 MB Free: 20.63 MB
/home Used: 0.13% Total: 206.31 GB Used: 275.43 MB Free: 195.56 GB
PHP Version 7.0.33-0+deb9u3 (Zend Version 3.0.0)
Modules apache2handler : calendar v7.0.33-0+deb9u3 : Core v7.0.33-0+deb9u3 : ctype v7.0.33-0+deb9u3 : curl v7.0.33-0+deb9u3 : date v7.0.33-0+deb9u3 : dom v20031129 : exif v7.0.33-0+deb9u3 : fileinfo v1.0.5 : filter v7.0.33-0+deb9u3 : ftp v7.0.33-0+deb9u3 : gd v7.0.33-0+deb9u3 : gettext v7.0.33-0+deb9u3 : hash v1.0 : iconv v7.0.33-0+deb9u3 : igbinary v2.0.1 : json v1.4.0 : libxml v7.0.33-0+deb9u3 : mbstring v7.0.33-0+deb9u3 : mcrypt v7.0.33-0+deb9u3 : mosquitto v0.4.0 : mysqli v7.0.33-0+deb9u3 : mysqlnd vmysqlnd 5.0.12-dev - 20150407 - $Id: b5c5906d452ec590732a93b051f3827e02749b83 $ : openssl v7.0.33-0+deb9u3 : pcre v7.0.33-0+deb9u3 : PDO v7.0.33-0+deb9u3 : pdo_mysql v7.0.33-0+deb9u3 : Phar v2.0.2 : posix v7.0.33-0+deb9u3 : readline v7.0.33-0+deb9u3 : redis v4.1.1 : Reflection v7.0.33-0+deb9u3 : session v7.0.33-0+deb9u3 : shmop v7.0.33-0+deb9u3 : SimpleXML v7.0.33-0+deb9u3 : sockets v7.0.33-0+deb9u3 : SPL v7.0.33-0+deb9u3 : standard v7.0.33-0+deb9u3 : sysvmsg v7.0.33-0+deb9u3 : sysvsem v7.0.33-0+deb9u3 : sysvshm v7.0.33-0+deb9u3 : tokenizer v7.0.33-0+deb9u3 : wddx v7.0.33-0+deb9u3 : xml v7.0.33-0+deb9u3 : xmlreader v7.0.33-0+deb9u3 : xmlwriter v7.0.33-0+deb9u3 : xsl v7.0.33-0+deb9u3 : Zend OPcache v7.0.33-0+deb9u3 : zlib v7.0.33-0+deb9u3
Client Information
HTTP Browser Mozilla/5.0 (Macintosh; Intel Mac OS X 10_11_6) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/11.1.2 Safari/605.1.15
Screen Resolution 2560 x 1600
Window Size 1233 x 1420

My install is filling up the syslog and daemon.log files with Feedwriter entries also. Any hope of a solution? Just purchased my system with everything pre-installed.

Feedwriter or emonhub entries?

These steps will reduce the rate of filling. Reboot Required Every 20 Days Or So To Restore Logging - #47 by borpin

@TrystanLea @glyn.hudson we do need a solution to this for existing setups.

Sorry about this @Gary_Young @bidouilleur I will get the fix for this merged in, it is in progress here: 9.9.9 master merge to stable by TrystanLea · Pull Request #1242 · emoncms/emoncms · GitHub

1 Like

Thanks! I appreciate the response and effort on this.

Gary