emonSD next steps: filesystem & logrotate

That is a quirk of GitHub, you can not search forks, only the upstream repo and this doesn’t exist on the upstream repo, only on my fork.

1 Like

Yes, that’s great, as you’re not logging much. Some of us are logging 150+ feeds. And I’m planning on another 50+ if I can just find the time to get it coded…

So that’s my SD card down from 294 months to 21 months? Maybe?
OK, I may be a big of an outlier, but I’m willing to bet there are many on here who log dozens of feeds.

1 Like

I found this yesterday suggesting copytruncate was very bad (and that from the author of rsyslog apparently). rsyslog with logrotate: reload rsyslog vs copytruncate - Server Fault

Not had a chance to play with the reload alternative.

Promising results with the log2ram rsync modifications you suggested @pb66

rsync -aXv --inplace --no-whole-file --delete --links $RAM_LOG/ $HDD_LOG/ 2>&1 | $LOG_OUTPUT

brings it down to ~11 sectors/minute 0.09 kb/s, in the previous 6 hours before the modifications, the write rate had increased to 0.86 kb/s so a 10x reduction.

1 Like

In addition to your changes here Comparing azlux:master...pb66:pb66 · azlux/log2ram · GitHub @pb66 have you changed /etc/logrotate.conf? do you keep the /etc/logrotate.d config set for all the modules?

With the above rsync results will you still use cp yourself or will you use the above modifications?

I have now on my test system:

  • restored /etc/logrotate.conf and /etc/cron-hourly/logrotate to default
  • installed your fork of log2ram @pb66
  • applied the rsync modifcation
  • set rsync=true in log2ram.conf
  • added the logfile to the service file:
    ExecStart=/opt/emon/emonhub/src/emonhub.py --config-file=/opt/emon/data/emonhub.conf --logfile=/var/log/emonhub/emonhub.log

Created a /etc/logrotate.d/emonhub configuration containing:

/var/log/emonhub/emonhub.log
{
  rotate 2
  size 1M
  nomail
  copytruncate
  missingok
  notifempty
  compress
}

1M so that I can see this rotating sooner than later.

Is that similar to the configuration that you are using @pb66?

O dear something seems to have just deleted all the logs in /var/log

$ cat log2ram.log 
sending incremental file list
deleting samba/
deleting redis/redis-server.log
deleting redis/
deleting mysql/error.log
deleting mysql/
deleting mosquitto/mosquitto.log
deleting mosquitto/
deleting logrotate/logrotate.status
deleting logrotate/logrotate.log
deleting logrotate/
deleting emonpilcd/emonpilcd.log
deleting emonpilcd/
deleting apt/term.log
deleting apt/history.log
deleting apt/eipp.log.xz
deleting apt/
deleting apache2/other_vhosts_access.log
deleting apache2/error.log
deleting apache2/access.log
deleting apache2/
deleting wtmp
deleting user.log
deleting syslog
deleting rotated_logs
deleting messages
deleting lastlog
deleting kern.log
deleting faillog
deleting emoncms.log
deleting dpkg.log
deleting debug
deleting daemon.log
deleting btmp
deleting bootstrap.log
deleting boot.log
deleting boot
deleting auth.log.1.gz
deleting auth.log
deleting alternatives.log
./
sent 72 bytes  received 631 bytes  1,406.00 bytes/sec
total size is 30  speedup is 0.04

and

pi@emonpi:/var/log $ ls -lh
total 4.0K
-rw-r--r-- 1 root root 972 Apr 23 21:52 log2ram.log
lrwxrwxrwx 1 root root  12 Apr 23 21:52 rotated_logs -> /var/log.old

Those calculations just confirm that you’re far more likely to fill up your 4GB partition and need to buy a new card before you would wear the card out due to exceeding the available writes.
What size card do you have, and how much space is currently being used by your emonCMS data?

To which defaults? Defaults installed by the logrotate package or defaults for the emonSD from the emoncms repo? The package default uses cron-daily.

I’ve put the rync mods in another branch called “rsync_mods” now
https://github.com/azlux/log2ram/compare/master...pb66:rsync_mods

Oh yeah! So I just added that too in the rsync_mods branch too. Plus I changed the size to 50M to match the old tmpfs as well.

Cool, I’ve been running that today as well.

I’ve been looking into the logrotation config this afternoon and not reached a conclusion yet.

There have been some observations about the old emonsd config and also about how logrotate works, especially around the way the configs are loaded and prioritised. But it’s still in progress.

I do have the rotation working just fine on a standard Raspbian image and today I got it working on an emonSD image but it was not using the emonsd logrotation config. It is closer to stock packaged configs which work ok (in that they do not delete all the logs etc) but the rotation routine is not ideal for the emonSD.

I have no idea why your logs have been deleted, I’ve certainly not had that happen to me (yet?). What is in your logrotate.conf exactly.

1 Like

Surely the point is to retain more emonhub logging not less?

By rotating emonhub via logrotate does that not conflict with the rotation done by the code itself?

How do you trigger the logrotate? Log2Ram does not trigger it (IIRC), it just copies the contents of the folder at that point in time when called. The logrotate size directive does not in itself trigger logrotate, just tells logrotate when it is triggered to rotate a file if over that size. This is where monit becomes useful.

I’m not at all sure this is the right approach.

I’d also really like to know what the aim is here. I suggested what the aim (for the logging strategy) is on the other thread. We have conflated disk writes with logging AFAICS.

I think we need to state what we want to achieve from the logging, and then work out the best way to do it.

1 Like

As far as I know, its the logrotate package default:

# see "man logrotate" for details
# rotate log files weekly
weekly

# keep 4 weeks worth of backlogs
rotate 4

# create new (empty) log files after rotating old ones
create

# uncomment this if you want your log files compressed
#compress

# packages drop log rotation information into this directory
include /etc/logrotate.d

# no packages own wtmp, or btmp -- we'll rotate them here
/var/log/wtmp {
    missingok
    monthly
    create 0664 root utmp
    rotate 1
}

/var/log/btmp {
    missingok
    monthly
    create 0660 root utmp
    rotate 1
}

# system-specific logs may be configured here

I have the logrotate in cron.hourly perhaps that is part of the problem, content of which:

#!/bin/sh

test -x /usr/sbin/logrotate || exit 0
/usr/sbin/logrotate /etc/logrotate.conf

Yes that was just for testing, I wanted to see emonhub rotate within a few hours hopefully.

Ok, I must have missed that, I see this in the code: emonhub/src/emonhub.py at emon-pi · openenergymonitor/emonhub · GitHub l will move the logrotate config then,is anything needed in the logrotate config?

Im triggering it via the standard? cron approach /etc/cron.hourly/logrotate, so I understand this would say check the file size every hour and if larger than 1mb rotate, although not the case if this is handled by emonhub, @glyn.hudson handled the configuration for logrotate before, so this is new to me.

Yes dont think we’ve finalised anything yet.

So my rotation setup currently is

  1. Add SyslogIdentifier=emonhub to the emonhub.service file.
  2. Add file to rsyslog.d to catch emonhub log entries and just save the message part to /var/log/emonhub.log.
  3. Monitor the size of the emonhub.log file with monit and call logrotate at a set size (2M currently).
  4. Add file to logrotate.d to rotate the /var/log/emonhub.log and move it to disk, concatenate it to produce a file of 24Hrs of data. Rotate that file once a day.
/var/log/emonhub.log {
        rotate 6
        daily
        size 2M
        maxsize 2M
        missingok
        copytruncate
        notifempty
        postrotate
             mv /var/log/emonhub.log.1 /home/pi/data/emonhub-log/
             cat /home/pi/data/emonhub-log/emonhub.log.1 >> /home/pi/data/emonhub-log/emonhub.log
             rm /home/pi/data/emonhub-log/emonhub.log.1
        endscript
}

/home/pi/data/emonhub-log/emonhub.log {
        rotate 10
        daily
        compress
        missingok
        notifempty
}



(No idea what that peak is)
and


Peaks coincide with writes to disk of rotated logs.

pi@emonpi:/etc/rsyslog.d $ ls -lah /home/pi/data/emonhub-log/em*
-rw-r--r-- 1 root root  45M Apr 23 22:42 /home/pi/data/emonhub-log/emonhub.log
-rw-r--r-- 1 root root 6.0M Apr 23 00:35 /home/pi/data/emonhub-log/emonhub.log.1.gz
-rw-r--r-- 1 root root 6.3M Apr 22 01:21 /home/pi/data/emonhub-log/emonhub.log.2.gz

Currently got nearly 3 days of logs :smile: should they ever be needed. Size is smaller as I have only been keeping the message part of the log entry instead of the additional rsyslog timestamp PID etc.

How long should there be emonhub logs available for? What is the design criteria?

Yes it would. Is there a risk of a race condition between logrotate and Log2Ram?

Thinking out loud:

  • configurability for loglevel (I’m inclined to choose ‘error’ as the log level and change to debug if needed)
  • persistance of emonhub and emoncms logs for issue debugging, could be optional
  • optional persistance of the other logs??
  • removed replication of daemon and syslog
  • silenced apache2 access logs
  • optimised for low write
  • simplified setup (e.g no rc.local mods), persistance of folder structure

log2ram with the rsync modification is showing a promisingly low level of write load, Id be inclined to use this if it halves the write load vs logging direct to the OS partition, the write load may be reduced further with less frequent saves and proportionally with larger volumes of logging data perhaps…?

Prior to those results I was starting to think it would be simpler to log straight to the OS partition and just reduce all the logging to error level + silencing unneeded logs, the write load may be sufficiently small, if the SD card ware equation suggests 70-317 years then its not something we would have to worry about. But I would be concerned about taking this approach with more permissive log levels…

Another option I’ve been thinking about is similar to what I think you suggested @borpin, keeping standard logs in a tmpfs and then logging the emoncms and emonhub logs to disk more directly…

Or perhaps mounting /var/log to a seperate ext4 partition with a reduced sync to disk? I need to read into this option in more detail mount - Advantages/disadvantages of increasing "commit" in fstab - Unix & Linux Stack Exchange

Agreed though @pb66 might be inclined to DEBUG for emonhub.

Agreed, How long? On by default unless load is excessive.

Yes via L2R although I do not really see any reason to do more retention than the standard package setup does for each. Other ‘OEM’ logs (feedwriter, service-runner etc) possibly in line with Emoncms and emonhub.

Definitely. [edit] but done via pulling out the ‘OEM’ service logs directly.

Is this not standard? Is it an issue?

Agreed

Agreed. I’d add to this a mechanism that copes with the installation of additional packages like OpenHab and Node-Red (which L2R achieves).

No, I think that offering some persistence of standard logs via L2R is a good thing - just not set it up on the standard EmonSD I’m using for testing. My focus has been on the other logs which are currently causing issues.

  • I think L2R for most logs achieves the above. Leave each packages standard logrotate settings in place just use L2R to persist them.
  • Use L2R to persist the current ‘OEM’ logs.
  • Handle the rotation and long term persistence of ‘OEM’ logs independently of L2R.

I’d like to see monit included as the mechanism to trigger logrotate as this will prevent any chance of the /var/log filling up.

I also wonder about making a specific version of L2R for our purposes part of any scripts repo.

This can also be part of the install, so where emoncms is not on an SD Card, there is no need for this malarkey! The rotations would still happen, just there would be no need for L2R.

That’s what i’ve been using too, so I’m still in the dark about why your logs were deleted.

Unlike the problem IMO but worth trying!

IMO rather than moving the cron.daily entry to cron.hourly, we should just edit the cron.daily file to comment out the logrotation and add a comment highlighting that L2R is now triggering the rotations and just have one cron entry for L2R that does logrotate before the L2R write.

Not necessarily, IMO we would be better off writing a good logrotate conf for emonhub to reduce the in ram usage, thb 5M files are a bit large and slow to manipulate and search etc. But the 5M catch net when all else fails is still a good feature and it has more appeal when not used with tmp logs ie on a hdd. The proposed test size of 1m is fine for testing but I would probably go for 3M limit for emonhub. Don’t forget the size limit is more to do with proportionately assigning the 50M, the old LR.conf (can I use LR for LogRotate without confusion with L2R?) set all logs at 1M so the least used were utilising the same amount of space in ram as the likes of emonhub, the global size effectively lowered the size across the board because there were so many logs all allowed the same space.

No, the 2 effectively work independently, there may be some overlap or gaps in the logs where the rotated logs do not perfectly fit with the backed up logs due to a difference in the 2x hourly triggers. This is why I’d like to see them trigger in a more controlled fashion, ie rotate first then sync whats left immediately so that the 2 folders (log.old and log.bak) are in harmony.

Rather than “pulling out” I would favour “not putting in”, we can redirect the output of the emon services within the service unit and send the logs to /var/log/emoncms/ much like with emonhub mentioned above, but using a stdout and errout redirection in the command.

IMO all the emon services should put their logs to a single emoncms folder, incl emoncms.log and backup.log and emonpiupdate.log (although I hope that name changes too). Yes that last one is controversial so I’m not going to try and force it, but there really isn’t any reason why we cannot call L2R write as part of the update process (right at the end) and have a rotation policy for emonpiupdate.log that persists any log that isn’t empty, this reduces the individual log writes to one big write at the end and puts all the logs in one place not scattered across the sdcard.

I have said so many times that I agree with this idea, however I think it must only be a fall back so that if all else fails and the partition fills to 90-95% then a forced rotation occurs, we do not want to only rotate at 90% nor do we want to force a rotation when the partition is at a healthy level. L2R and LR can manage the level ordinarily and if need, monit will force a rotation using the --force flag that overrides the size and time limits.

Sorry if I’ve missed any points but I should get on and do some work now. Overall the length of retention and size of files and loglevels are all configurable so we can indeed tailor the whole L2R+ eco-system to our needs once we have the system in play, it would be foolish to assume that our initial settings will not be improved over time, so we shouldn’t get too bogged down with the smallest details at this point, it needs to be configurable for different uses eg debug/dev/normal running, therefore we can be more flexible at this stage, especially to test it across a wide range of situations. ie we must test with high traffic as even with just error levels, what happens when there is an error? We cannot assume that all systems will be error free and not producing logs, when a fault occurs, we don’t want that misery compounded and complicated by the log management buckling under the strain on top of that error. Likewise, if someone turns on debug level logs to locate an issue, that must not create new errors due to increased log traffic.

[edit] Plus (while I think of it) IMO we should not get involved with messing about with the logrotation config files as defined and managed by the various packages. Since we are needing our own rules, we should just write another config and point our new LR command (from the L2R cron and/or monit etc) to the L2R4OEM specific logrotation config directly, no editing, no symlinks, just cloned and updated within a (emonsd?) repo. I can go in to this in more depth later as I’m sure it raises questions, but (at this point) I think it’s the best way forward.

Agreed - I’ve been using 2M which works nicely for me and generates a single daily log file.

You can only redirect from the service file if a later version of systemd. A better and more robust system across OS distributions will probably be to use the inbuilt rsyslog (with all the builtin protections, reload, file open etc mechanisms) and simply pulling out the messages into the relevant log (which is what it does for every other log) would be a cleaner solution rather than ‘rolling our own’ (as is currently in place for emonhub). Likely to be more efficient as well. I’ve demonstrated it can be done with 1 drop in file for rsyslog.

If installing L2R is problematic for existing setups (and it might be), this would at least be backward compatible to Oct18 images.

Totally agree and every log file should have a rotate policy.

Too high, as at that level, there is nowhere to rotate to. 60% max I’d suggest. It would be better if monit forced the L2R process as that should cope. You could add a global size limit via logrotate for those packages that do not have one.

Does L2R need to run once an hour? Is that just for restore purposes in case of hard crash? Could it be done less frequently based on size?

Getting there I feel.

Agreed, rotated twice? 5mb each time?

fine by me

could you clarify what you mean here?

standard on emonSD but not standard in stock distro, just an uneeded log IMO, but users could turn it back on if needed.

fine by me, that’s the setup I was trying to configure above.

I havent looked into monit yet.

sure a config option in the installer

fine by me

the logging is handled internally by the emoncms logger and has been for some time, the log file appended to here: emoncms/Lib/EmonLogger.php at master · emoncms/emoncms · GitHub keen to keep this this way for now.

fine by me.