emonSD next steps: filesystem & logrotate

[Greebo]

@Vster

So that’s my SD card down from 294 months to 21 months? Maybe?

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?

[pb66 (Paul)]

@TrystanLea

• restored /etc/logrotate.conf and /etc/cron-hourly/logrotate to default

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

@TrystanLea

• installed your fork of log2ram @pb66
• applied the rsync modifcation

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

@TrystanLea

• set rsync=true in log2ram.conf

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.

@TrystanLea

• 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

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.

[borpin (Brian Orpin)]

@TrystanLea

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

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.

[TrystanLea]

@pb66

To which defaults?

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

[TrystanLea]

@borpin

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

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

@borpin

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

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?

@borpin

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.

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.

@borpin

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

Yes dont think we’ve finalised anything yet.

[borpin (Brian Orpin)]

@pb66

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.

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 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.

[borpin (Brian Orpin)]

@TrystanLea

I wanted to see emonhub rotate within a few hours hopefully.

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

@TrystanLea

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

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

[TrystanLea]

@borpin

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

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

[borpin (Brian Orpin)]

@TrystanLea

configurability for loglevel (I’m inclined to choose ‘error’ as the log level and change to debug if needed)

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

@TrystanLea

persistance of emonhub and emoncms logs for issue debugging, could be optional

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

@TrystanLea

optional persistance of the other logs??

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.

@TrystanLea

removed replication of daemon and syslog

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

@TrystanLea

silenced apache2 access logs

Is this not standard? Is it an issue?

@TrystanLea

optimised for low write

Agreed

@TrystanLea

simplified setup (e.g no rc.local mods), persistance of folder structure

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

@TrystanLea

keeping standard logs in a tmpfs

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.

[pb66 (Paul)]

@TrystanLea

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

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

@TrystanLea

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

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.

@borpin

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

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.

@borpin

Is there a risk of a race condition between logrotate and Log2Ram?

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.

@borpin

removed replication of daemon and syslog

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

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.

@borpin

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 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.

[borpin (Brian Orpin)]

@pb66

Not necessarily, IMO we would be better off writing a good logrotate conf for emonhub to reduce the in ram usage

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

@pb66

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,

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.

@pb66

IMO all the emon services should put their logs to a single emoncms folder

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

@pb66

I think it [monit] must only be a fall back so that if all else fails and the partition fills to 90-95%

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.

[TrystanLea]

@borpin

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

Agreed, rotated twice? 5mb each time?

@borpin

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.

fine by me

@borpin

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

could you clarify what you mean here?

@borpin

Is this not standard? Is it an issue?

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

@borpin

• 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.

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

@borpin

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 havent looked into monit yet.

@borpin

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.

sure a config option in the installer

[TrystanLea]

@pb66

Not necessarily, IMO we would be better off writing a good logrotate conf for emonhub to reduce the in ram usage,

@pb66

I would probably go for 3M limit for emonhub

fine by me

@pb66

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.

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.

@pb66

IMO all the emon services should put their logs to a single emoncms folder, incl emoncms.log and backup.log and emonpiupdate.log

fine by me.

[borpin (Brian Orpin)]

@TrystanLea

persistance of emonhub and emoncms logs for issue debugging, could be optional

@borpin

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

@TrystanLea

Agreed, rotated twice? 5mb each time?

I think we should measure it in days rather than by size.

@TrystanLea

removed replication of daemon and syslog

@borpin

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

@TrystanLea

could you clarify what you mean here?

Don’t simply dump the daemon.log, it does other things it is just our services are actually badly behaved and drop things into the daemon log that should not go there (or at least should be handled), just rsyslog had not been told what to do with the log entries so drops them into the daemon.log by default. Can’t blame it for that!

Create separate log files for each of the services emon installs. Nothing (from us) will then go into the daemon log so any duplication will not matter. It just needs a file like below and a syslogidentifier in each service file.

I thought I’d added a sample of the rsyslog file to extract the log messages but obviously not (I think I was waiting until I’d tested it over 24Hrs)! I’ll post it tonight.

[TrystanLea]

@borpin

I think we should measure it in days rather than by size.

I like the rotation by size as it helps ensure we stay within the partition size, if its days and the logging level is debug on emonhub you can quickly fill up the partition.

@borpin

Don’t simply dump the daemon.log, it does other things it is just our services are actually badly behaved and drop things into the daemon log that should not go there (or at least should be handled), just rsyslog had not been told what to do with the log entries so drops them into the daemon.log by default. Can’t blame it for that!

fair enough, can see how redirecting emonhub and emoncms logs correctly can fix this.

@borpin

Create separate log files for each of the services emon installs. Nothing (from us) will then go into the daemon log so any duplication will not matter.

great

[borpin (Brian Orpin)]

@TrystanLea

I like the rotation by size as it helps ensure we stay within the partition size, if its days and the logging level is debug on emonhub you can quickly fill up the partition.

Overstating it I think (especially with larger SD cards now) but you could limit it in other ways. Try it and see. Even if it was 24Hrs. For me on the EmonPi, 5Mb of uncompressed files is about 2.5Hrs. Compression by logrotate is about 10:1. Remember, I am moving these to disk as soon as they are rotated.

However the limit is set, I suggest it should be outside of the script itself so it can easily be modified for debug purposes.

Also, if we defaulted to a lower debug level, that would help a normally running system.

[TrystanLea]

Im still having my log folder cleared somehow, do I need to call default logrotate and log2ram from cron.hourly?

Edit, is there a reason your log2ram conf does not include the zram config @pb66? log2ram/log2ram.conf at pb66 · pb66/log2ram · GitHub

[TrystanLea]

Could there by anything that is part of logrotate or log2ram that does not happen immedietly within a couple of seconds of running logrotate or log2ram that would complete say a minute or so later that would then delete the logs and folders?

[TrystanLea]

The issue may have been running your pb66 branch rather than rsync_mods but with rsync turned on… will confirm shortly assuming logs stay in place.

[pb66 (Paul)]

@TrystanLea

Edit, is there a reason your log2ram conf does not include the zram config @pb66?

I forked the repo before that code was added and I’m not planning on adding it just yet as I’m not confident about it’s implementation.

@TrystanLea

Could there by anything that is part of logrotate or log2ram that does not happen immedietly within a couple of seconds of running logrotate or log2ram that would complete say a minute or so later that would then delete the logs and folders?

Have you checked your logs? ie syslog and/or daemon log as well as the L2R log. I think logrotate currently just gets output to syslog? (something else I might look to change for debugging purposes).

I don’t think it’s easy to compare notes when we are all running different things.

I’m running 2 setups currently, an Oct 18 emonSD converted to L2R (pb66/log2ram/rsync_mods rsync mode) and a basic Rasbian image with various bits and bobs but no emon stuff installed, that’s got L2R (pb66/log2ram/pb66 - cp mode) and neither have wiped the logs, as far as I’m aware.

Do yours comeback after a while? Is the folder structure retained? Do any softwares continue to create/add logs?