Community
OpenEnergyMonitor

Community

Log Rotation Frequency ver 10.1.2

Ver 10.1.2 fixes earlier problems with log rotation which now happens hourly.

On one of my emon/Rpi instances, I’ve installed a Mail Transfer Agent (ssmtp) which periodically sends emails to my gmail account reporting a couple of system aspects.

Unfortunately with ver 10.1.2, I’m now getting hourly emails about log rotation which is a total pain …

Is it possible to change log rotation frequency to daily?
If so, how?
Is it desirable or risky to change the frequency to daily?

Any comments most welcome

The logrotation is part of the “logs in ram” strategy to reduce disk writes, if you change from hourly to daily the chances are the logs in ram could grow to such a size that they choke the os and induce a crash.

What exactly is being emailed?

You should not be getting the rotated logs emailed to you due to the nomail setting

if you are getting emailed error reports or cronjob updates, we maybe able to tackle that instead.

@pb66
The most recent email …
From: root [email protected]
Subject: cron [email protected] cd /&& run-parts --report /etc/cron.hourly

/etc/cron.hourly/logrotate:
reading config file /etc/logrotate.conf
error: /etc/logrotate.conf:32 duplicate log entry for /var/log/auth.log Reading state from file: /var/log/logrotate/logrotate.status
Allocating hash table for state file, size 64 entries Creating new state Creating new state Creating new state Creating new state Creating new state Creating new state Creating new state Creating new state Creating new state Creating new state Creating new state Creating new state Creating new state Creating new state Creating new state Creating new state Creating new state Creating new state Creating new state Creating new state Creating new state Creating new state Creating new state Creating new state Creating new state Creating new state Creating new state

Handling 1 logs

rotating pattern: /var/log/*.log /var/log/*/*.log /var/log/syslog /var/log/messages /var/log/btmp /var/log/*  1048576 bytes (1 rotations) empty log files are not rotated, old logs are removed considering log /var/log/auth.log
  Now: 2019-08-06 17:17
  Last rotated at 2019-08-05 10:00
  log does not need rotating (log size is below the 'size' threshold) considering log /var/log/boot.log
  Now: 2019-08-06 17:17
  Last rotated at 2019-08-05 10:00
  log does not need rotating (log size is below the 'size' threshold) considering log /var/log/daemon.log
  Now: 2019-08-06 17:17
  Last rotated at 2019-08-06 10:17
  log does not need rotating (log size is below the 'size' threshold) considering log /var/log/dataplicity.log
  Now: 2019-08-06 17:17
  Last rotated at 2019-08-05 10:00
  log does not need rotating (log size is below the 'size' threshold) considering log /var/log/emoncms.log
  Now: 2019-08-06 17:17
  Last rotated at 2019-08-05 10:00
  log does not need rotating (log size is below the 'size' threshold) considering log /var/log/kern.log
  Now: 2019-08-06 17:17
  Last rotated at 2019-08-05 10:00
  log does not need rotating (log size is below the 'size' threshold) considering log /var/log/mail.log
  Now: 2019-08-06 17:17
  Last rotated at 2019-08-05 12:00
  log does not need rotating (log size is below the 'size' threshold) considering log /var/log/mqtt_input.log
  Now: 2019-08-06 17:17
  Last rotated at 2019-08-05 10:00
  log does not need rotating (log size is below the 'size' threshold) considering log /var/log/mysql.log
  Now: 2019-08-06 17:17
  Last rotated at 2019-08-05 10:00
  log does not need rotating (log size is below the 'size' threshold) considering log /var/log/ntp_update.log
  Now: 2019-08-06 17:17
  Last rotated at 2019-08-05 10:00
  log does not need rotating (log size is below the 'size' threshold) considering log /var/log/service-runner.log
  Now: 2019-08-06 17:17
  Last rotated at 2019-08-05 10:00
  log does not need rotating (log size is below the 'size' threshold) considering log /var/log/user.log
  Now: 2019-08-06 17:17
  Last rotated at 2019-08-05 10:00
  log does not need rotating (log size is below the 'size' threshold) considering log /var/log/apache2/access.log
  Now: 2019-08-06 17:17
  Last rotated at 2019-08-06 14:17
  log does not need rotating (log size is below the 'size' threshold) considering log /var/log/apache2/error.log
  Now: 2019-08-06 17:17
  Last rotated at 2019-08-05 10:00
  log does not need rotating (log size is below the 'size' threshold) considering log /var/log/apache2/other_vhosts_access.log
  Now: 2019-08-06 17:17
  Last rotated at 2019-08-05 10:00
  log does not need rotating (log size is below the 'size' threshold) considering log /var/log/emoncms/emoncms.log
  Now: 2019-08-06 17:17
  Last rotated at 2019-08-05 10:00
  log does not need rotating (log size is below the 'size' threshold) considering log /var/log/emoncms/emonpiupdate.log
  log /var/log/emoncms/emonpiupdate.log is symbolic link. Rotation of symbolic links is not allowed to avoid security issues -- skipping.
considering log /var/log/emonhub/emonhub.log
  Now: 2019-08-06 17:17
  Last rotated at 2019-08-05 13:00
  log does not need rotating (log size is below the 'size' threshold) considering log /var/log/emonpilcd/emonpilcd.log
  Now: 2019-08-06 17:17
  Last rotated at 2019-08-05 10:00
  log does not need rotating (log size is below the 'size' threshold) considering log /var/log/logrotate/logrotate.log
  Now: 2019-08-06 17:17
  Last rotated at 2019-08-05 12:00
  log does not need rotating (log size is below the 'size' threshold) considering log /var/log/mosquitto/mosquitto.log
  Now: 2019-08-06 17:17
  Last rotated at 2019-08-05 10:00
  log does not need rotating (log size is below the 'size' threshold) considering log /var/log/mysql/error.log
  Now: 2019-08-06 17:17
  Last rotated at 2019-08-05 10:00
  log does not need rotating (log size is below the 'size' threshold) considering log /var/log/redis/redis-server.log
  Now: 2019-08-06 17:17
  Last rotated at 2019-08-05 10:00
  log does not need rotating (log size is below the 'size' threshold) considering log /var/log/supervisor/supervisord.log
  Now: 2019-08-06 17:17
  Last rotated at 2019-08-05 10:00
  log does not need rotating (log size is below the 'size' threshold) considering log /var/log/syslog
  Now: 2019-08-06 17:17
  Last rotated at 2019-08-06 16:17
  log does not need rotating (log size is below the 'size' threshold) considering log /var/log/messages
  Now: 2019-08-06 17:17
  Last rotated at 2019-08-05 10:00
  log does not need rotating (log size is below the 'size' threshold) considering log /var/log/btmp
  Now: 2019-08-06 17:17
  Last rotated at 2019-08-05 10:00
  log does not need rotating (log size is below the 'size' threshold)

I am getting emailed two other cronjob reports but that’s by design.

Thanks

There is an error there but I do not think that is the trigger.

Do you have SSH access? If so could you try editing the cron file? IIRC it should be found and edited at

sudo nano /etc/cron.hourly/logrotate.conf

I expect your existing file is

could you add “> /dev/null” after “logrotate.conf” to make it

#!/bin/sh

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

in fact

#!/bin/sh

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

might be a more concise command, I don’t have anything to test this on right now, sorry.

[edit] or maybe even this would be better

#!/bin/sh

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

Very few users set up MTA’s so this isn’t something that’s tested for, once we confirm the right solution we can hopefully get the change into the std code in the repo.

@pb66

The location is actually /etc/cron.hourly/logrotate (no .conf)

I went with your last and ‘even better’ suggestion …

#!/bin/sh

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

It’s now minutes past the ‘dreaded’ 17 mins past the hour and I’ve received NO email :slight_smile:

Looks like you have provided the solution - many thx

I’ll confirm tomorrow and that I still do receive the email that I want to receive about another system aspect.

2 Likes

Ooops! Indeed it is.

I still haven’t tested any of them, but it did occur to me that whilst perhaps simpler to read or neater on the eye it is “bash”. The last but one ie

#!/bin/sh

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

I believe is more posix compliant so should be more portable across linux distros, not really a issue for the emonSD, but for a wider audience it might be a factor.

The important thing now is of course, whether it resolves your issue, the code can be adjusted if needed.

@pb66
I can confirm that the hourly logrotation emails have stopped.
And I did receive an email re another system aspect exactly as intended,
Many thx

Thanks for letting us know John.

I’m sure you are aware, but just to be sure. If you try and update via the updater it will fail to update the emoncms repo due to those local changes you’ve made. Until such time as these changes make it into the master and then on to the stable branch, you will need to undo these changes before running an update and then re apply them afterwards.

Alternatively, you could move your edited file to a safe place outside of any repo’s and symlink it in place (that’s how it’s currently done with the file held in the emoncms repo), that way you will not have to do anything before updating, emoncms will (currently) just overwrite your symlink back to the repo copy and you can then issue a single command to reinstate your symlink.

First mv the file to your home dir giving it a unique/meaningful name

sudo mv /var/www/html/emoncms/scripts/logger/logrotate /home/pi/custom_logrotate.cron

then reset the emoncms repo so it doesn’t block updates

git -C /var/www/html/emoncms checkout -f -B stable

(I assume you are running “stable” branches? and the paths are right but please check)
once you have run the above your setup will (hopefully) be at the state it will be left in when updating, ie the repo “stock” cron is back in play because your symlink has been overwritten.

So all you need to do now is run

sudo ln -sf /home/pi/custom_logrotate.cron /etc/cron.hourly/logrotate

and run that one line again after each update.

Worse case scenario would hopefully be if you forget to do this and get an annoying reminder in the form of an email from logrotate within the hour! But the important thing is you are not left trying to figure out why an update has gone wonky because you forgot to reset the repo beforehand.

Not ideal I know, but hopefully a lesser evil until the changes filter through.

Ha! Looks like I had already implemented this fix in amongst some other changes to logrotate I proposed back in May

IIRC this was to prevent the same log messages going to multiple places, the original code uses “tee” to duplicate the log messages to a log file, leaving the originals to end up somewhere like syslog (or your email inbox), I opted for redirecting the originals to the log file so there is only a single copy, to reduce disk writes and size in ram among other things.

Perhaps @TrystanLea will take another look? I know he’s parked the new installer dev for now, but this is relevant to the current updater too and if I create a PR for the cron edit in the master branch it will cause a merge conflict. (See https://github.com/emoncms/emoncms/compare/logrotate?expand=1).

@pb66
I followed yr suggestion but waited one hour before doing the final comand sudo ln -sf etc.
And sure enough I got an email re log rotation.
I then did the command sudo ln -sf etc and waited an hour plus …
And I received no unwanted email.
All seems copacetic
Many thx for yr ‘hand holding’ help - much appreciated and very necessary

1 Like

Hello @pb66 I’ve changed this in the emoncms master branch here as I think you suggest: https://github.com/emoncms/emoncms/commit/d1ed8a28239269ef3fad0a58004c2801296abcc7

You seem to have dropped the redirection of stderr to stdout off the end so only stdout is being redirected to the logfile, any activity on stderr will still result in a entry on syslog (and an email to John).

As pointed out above, making these changes direct to the master branch has now caused a merge conflict for the other branch. Since you have again not commented on those changes, should I assume you are not interested in discussing those changes and just delete the branch?

Here is the original discussion back in May

and there is an open github issue https://github.com/emoncms/emoncms/issues/1309 and it’s mentioned in Has /var/log Filling up Been Fixed? and Error in log on update to 10.1.0.

As for the line to create the logrotate log file. I hadn’t suggested John make that change here. That was offered up as an alternative to adding logrotate to the list of log files created in the rc.local back in May, although I don’t think it would hurt having it there whilst the rc.local entry remains. That was hopefully going to be part of a larger edit to be the one place the logrotate log folder was managed to ensure the folder was always there and consistently the same, immediately before each logrotate run. It is also a single point to maintain.

I am also thinking the ownership would probably be better as root:adm so that users can access it without using sudo, but I haven’t tested that, and didn’t mention it on his thread to avoid confusing the outstanding changes already suggested and a more recent (untested) edit.

[edit] If you look at the diff side by side (rather than “unified”) it makes the changes much simpler to follow and you can see all I’ve really done is added a test so that only real (original?) files are backed up and not over-written on each subsequent run of the updater. (https://github.com/emoncms/emoncms/compare/logrotate?diff=split&expand=1)

The alternative is to not back up the files at all. There is no point in backing up whatever was there a couple of seconds ago on every click of the update button, 99 times out of 100 that’s just gonna be the same as the repo copy. It’s just needless confusion with no benefit in it’s current form.

I’ve added it in:
https://github.com/emoncms/emoncms/blob/master/scripts/logger/logrotate

No I think keep the branch open, I cant engage with it right now, but I will make a note to take a look soon.

1 Like

Is that what’s desired? Redirecting stdout to the logfile has fixed the problem that
John was having. Surely any additional output to stderr represents some new problem that he and other people will want to know about? So maybe it makes sense to send that both to the logfile and to email?

Hi Dave, I cannot speak for Trystan or John, but yes, although maybe debatable, in my opinion it is. But as usual there is no right answer for all users I guess.

Very few users have MTA’s installed so John is a smaller use group (that I totally agree should be catered for), but since the logrotation has been moved to hourly, I don’t think anyone wants hourly emails about any fault condition, once a day or just on the first occurrence perhaps, yes.

The change to the code I proposed was to prevent duplication and emails, the stderr to stdout redirection was already there. The original output just left to fall where it landed and a “copy” was tee’d to the log file. I’ve just removed the “tee” so that the original output (both streams) went to the log rather than being duplicated to syslog (and John’s inbox)

The stderr output should at least go to the log file, so any other location would require a “tee” so that logs are kept together (and duplicated to email via cron) this would reintroduce duplication as it would then go to both syslog and logrotate.log.

Plus IIRC correctly (and this is just a vague recollection that may not be accurate) I believe logrotate might actually output everything to one stream anyway, so this maybe academic.

Plus as this will all come under the umbrella of log2ram (when running hourly at least), there are plans to be able to introduce more controlled and informative log messages and streams so issues requiring immediate user notification eg log partition full or logrotate unable to complete would be handled in a more deliberate and orderly way eg one email, flashing lights, MQTT or emoncms user notice etc etc.

If you notice in Johns emailed log there is actually an error reported about duplicate info, this error was introduced several months ago by expanding the notoriously troublesome wildcard entries, I have been trying to get that error acknowledged for months but no luck, Johns inbox could take quite a battering waiting for that apparently acceptable error to get resolved. (if it was a separate stream).

I’m also thinking as we move towards a customised event that covers log management as a whole, including logrotation and possibly Monit? that it might also become a systemd timer at some point so I’m keen not to develop any further dependency on cron whilst I implement extended reporting for log2ram.

@pb66

I think I spoke too soon …
The hourly emails stopped which was great …
But several weeks later I’ve discovered that so did logrotation.
My /var/log filled to allowed capacity which I’ve rectified by truncating the the largest files and rebooting.

The script I’m using which is placed in /home/pi/data is …

[email protected]:~/data $ cat CUSTOM_pb66_logrotate.cron

#!/bin/sh

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

[email protected]:~/data $

I’ve tried running the script directly with the following results …

[email protected]:~/data $ ./CUSTOM_pb66_logrotate.cron
./CUSTOM_pb66_logrotate.cron: 4: ./CUSTOM_pb66_logrotate.cron: cannot create /var/log/logrotate/logrotate.log: Permission denied
[email protected]:~/data $ reading config file /etc/logrotate.conf
error: /etc/logrotate.conf:32 duplicate log entry for /var/log/auth.log
Reading state from file: /var/log/logrotate/logrotate.status
Allocating hash table for state file, size 64 entries

Handling 1 logs

rotating pattern: /var/log/*.log /var/log/*/*.log /var/log/syslog /var/log/messages /var/log/btmp /var/log/*  1048576 bytes (1 rotations)
empty log files are not rotated, old logs are removed
switching euid to 0 and egid to 0
error: error switching euid to 0 and egid to 0: Operation not permitted

[email protected]:~/data $

There seems to be a permissions problem but I can’t figure it out.
The script has the following permissions …

[email protected]:~/data $ ls -l
total 519956
-rwxr-xr-x 1 root     root           168 Aug  6 20:16 CUSTOM_pb66_logrotate.cron

Any suggestions most welcome - thx

Do you get the same result if you use sudo?

@pb66

Running sudo ./CUSTOM_pb66_logrotate.cron worked
There were a couple of ‘warnings’ however …

 reading config file /etc/logrotate.conf
error: /etc/logrotate.conf:32 duplicate log entry for /var/log/auth.log

considering log /var/log/emoncms/emonpiupdate.log
Creating new state
  log /var/log/emoncms/emonpiupdate.log is symbolic link. Rotation of symbolic links is not allowed to avoid security issues -- skipping.

After googling how to run a script as root, I was bewildered.
Then the thought occurred to create another script in /home/pi/data (RUN_CUSTOM_script.sh)

!/bin/sh
sudo /home/pi/data/CUSTOM_pb66_logrotate.cron
exit

I changed the symbolic link to run this …

sudo ln -sf /home/pi/data/RUN_CUSTOM_script.sh /etc/cron.hourly/logrotate

Did a forced logrotate …

logrotate -vdf /etc/logrotate.conf

This failed with permission type errors but with sudo it worked

Now to wait for a 17 mins past the hour when a cron driven logrotate should happen …

I got an email indicating that a logrotation had happened BUT I’ve gone full circle!

Here’s the CUSTOM script I’m using …

[email protected]:~/data $ cat CUSTOM_pb66_logrotate.cron
#!/bin/sh

test -x /usr/sbin/logrotate || exit 0
/usr/sbin/logrotate -v -s /var/log/logrotate/logrotate.status /etc/logrotate.conf &>> /var/log/logrotate/logrotate.log
[email protected]:~/data $

And I’m a bit mystified why logrotate.status and logrotate.log have not been updated …

[email protected]:/var/log/logrotate $ ls -l
total 4
-rw-r--r-- 1 root root    0 Sep 26 18:17 logrotate.log
-rw-r--r-- 1 pi   pi   1227 Sep 28 16:44 logrotate.status
[email protected]:/var/log/logrotate $

The logrotation happened at 17:17
Do the permissions look correct?

Any suggestions - thx

Hi John, I think you may be tying yourself up in a knot.

The reason I suggested sudo was because the cron job is executed by the root system user, when you tried to run it as pi, it was expected to fail, by running with sudo you were closer to mimiking the way it actually gets run by cron.

The additional script you have added is not required and to be honest, I do not know for sure what the outcome maybe for the root user running a command using sudo would be exactly.

The forced logrotate would indeed require sudo.

What is the owner of the /var/log/logrotate folder? The folder and content should be all root so try issuing a sudo chown -R /var/log/logrotate that will also change the status file to root ownership as it should not be pi:pi.

The warnings you saw are nothing to worry about. The emonpiupdate.log is located in ~/data so it doesn’t need rotating out of /var/log only the symlink resides in the tmp folder and uses negligible space. The duplicated rules for the auth.log is due to the wildcard’s as I’ve explained earlier in this thread.

TBH I don’t think you need to be doing any of this now, IIRC Trystan added the ammendment to the master repo so you shouldn’t even need the custom cron entry let alone another script to trigger that cron script as root.

Try updating (unless you have other reasons not to do so) and NOT doing the symlink command previously suggested, worst case scenario (with regard to logrotate) is you will get an email if the repo code wasn’t amended, at which point you can just add the symlink to our custom cron (not the new intermediate script).

Then we can look to see if logrotate is working as expected. One major failing of the current setup is that once the partition is full, logrotate cannot function and therefore will not resolve until you intervene.

In the mean time any log that can fill the partition in between hourly checks can gum things up. Should this happen again, you should copy the /var/log folder to your hdd for further investigation before truncating any files so that we can get a look at what was going on when the partition filled up and hopefully apply a fix.

If and when log2ram gets rolled out to the emonSD I’m hoping much of this will be resolved. Meaning that log2ram will manage the possibility of unexpected runaway logs and act accordingly with both action and notifications. No solution can actually stop that possibility entirely without reducing log activity and that is counter productive, no error logs doesn’t mean no errors and working blind there is no way to locate and resolve said errors.

Or you could edit the time the hourly cron gets triggered, if you look at /etc/crontab

[email protected]:~ $ cat /etc/crontab
# /etc/crontab: system-wide crontab
# Unlike any other crontab you don't have to run the `crontab'
# command to install the new version when you edit this file
# and files in /etc/cron.d. These files also have username fields,
# that none of the other crontabs do.

SHELL=/bin/sh
PATH=/usr/local/sbin:/usr/local/bin:/sbin:/bin:/usr/sbin:/usr/bin

# Example of job definition:
# .---------------- minute (0 - 59)
# |  .------------- hour (0 - 23)
# |  |  .---------- day of month (1 - 31)
# |  |  |  .------- month (1 - 12) OR jan,feb,mar,apr ...
# |  |  |  |  .---- day of week (0 - 6) (Sunday=0 or 7) OR sun,mon,tue,wed,thu,fri,sat
# |  |  |  |  |
# *  *  *  *  * user-name command to be executed
17 *    * * *   root    cd / && run-parts --report /etc/cron.hourly
25 6    * * *   root    test -x /usr/sbin/anacron || ( cd / && run-parts --report /etc/cron.daily )
47 6    * * 7   root    test -x /usr/sbin/anacron || ( cd / && run-parts --report /etc/cron.weekly )
52 6    1 * *   root    test -x /usr/sbin/anacron || ( cd / && run-parts --report /etc/cron.monthly )
#
[email protected]:~ $

that 5th line from the bottom

17 *    * * *   root    cd / && run-parts --report /etc/cron.hourly

determines the time the hourly cron runs, you could edit that to trigger in a few minutes time whilst testing and just edit it back to 17 when you’re done. (that’s assuming you do not have any other hourly cron jobs that might get upset by being triggered outside the normal hourly interval at 17mins past each hour)