LinuxQuestions.org

LinuxQuestions.org (/questions/)
-   Slackware (https://www.linuxquestions.org/questions/slackware-14/)
-   -   Why would logrotate run at odd time? (https://www.linuxquestions.org/questions/slackware-14/why-would-logrotate-run-at-odd-time-4175575149/)

mfoley 03-17-2016 10:20 AM
Why would logrotate run at odd time?
 
I have a logrotate script shown below. It is set to run monthy. It has been working fine for about a year and a half. This morning, on the 17th of the month, it ran. I have no clue why. Any ideas?

Slackware64 14.1 (up-to-date)

Code:
/etc/intrude/blockIP /etc/logfiles/scanCdrives.log
{
  monthly
  notifempty
  rotate 12

  sharedscripts
    postrotate
    /etc/rc.d/rc.firewall stop
    /usr/bin/sleep 2
    /etc/rc.d/rc.firewall start
    echo "/etc/logrotate.d/MAIL Firewall restarted" | /usr/bin/mail -r noreply@myhost.com -s "OHPRS MAIL Firewall restarted" sysadmin
  endscript
}

ButterflyMelissa 03-17-2016 11:00 AM
Just a hunch...full space? But...it's just a loose idea...perhaps I started an avalance of ideas ^^
Melissa

kjhambrick 03-17-2016 11:44 AM
mfoley --

Just a WAG ...

Are you in the USA ?

Could it be because Daylight Saving Time started last weekend ?

-- kjh

bassmadrigal 03-17-2016 11:51 AM
Quote:
Originally Posted by mfoley (Post 5517002)
I have a logrotate script shown below. It is set to run monthy. It has been working fine for about a year and a half. This morning, on the 17th of the month, it ran. I have no clue why. Any ideas?
When did you expect it to run? How is it currently set up to run (crontab, /etc/cron.monthly, etc)?

mfoley 03-18-2016 11:26 AM
This script is in /etc/logrotate.d/MAIL -- a separate file from the shipped-defaults. It is run via the usual convoluted yet standard mechanism: root's crontab > /etc/cron.daily/crontab > /usr/sbin/logrotate / etc/logrotate.conf, the latter of which includes the folder /etc/logrotate.d.

It used to run at the beginning of the month, only, see below. Notice that the new log files are on the last or first day of the month for every month, except a new logfile was created on the 17th of this month.

Code:
-rw-r--r-- 1 root root 41259 2015-05-01 02:47 blockIP.12
-rw-r--r-- 1 root root 63101 2015-06-01 04:36 blockIP.11
-rw-r--r-- 1 root root 81794 2015-06-30 16:16 blockIP.10
-rw-r--r-- 1 root root 58837 2015-08-01 03:34 blockIP.9
-rw-r--r-- 1 root root 51836 2015-09-01 01:37 blockIP.8
-rw-r--r-- 1 root root 34981 2015-10-01 01:33 blockIP.7
-rw-r--r-- 1 root root 28385 2015-11-01 02:41 blockIP.6
-rw-r--r-- 1 root root 29531 2015-12-01 03:10 blockIP.5
-rw-r--r-- 1 root root 29791 2015-12-31 09:25 blockIP.4
-rw-r--r-- 1 root root 30567 2016-02-01 03:42 blockIP.3
-rw-r--r-- 1 root root 29622 2016-02-29 22:03 blockIP.2
-rw-r--r-- 1 root root 21310 2016-03-17 03:54 blockIP.1
-rw-r--r-- 1 root root  8923 2016-03-18 10:47 blockIP
Also, this happened again today on a different server, same logfile/utility!

Code:
-rwxr-x--- 1 root root 35622 2015-07-01 00:59 blockIP.10*
-rwxr-x--- 1 root root 17059 2015-08-01 03:34 blockIP.9*
-rwxr-x--- 1 root root 32040 2015-08-31 21:25 blockIP.8*
-rwxr-x--- 1 root root 25538 2015-10-01 02:05 blockIP.7*
-rwxr-x--- 1 root root 17953 2015-11-01 02:41 blockIP.6*
-rwxr-x--- 1 root root 16054 2015-12-01 02:21 blockIP.5*
-rw-r--r-- 1 root root 19282 2015-12-31 23:45 blockIP.4
-rw-r--r-- 1 root root 18140 2016-01-31 14:28 blockIP.3
-rw-r--r-- 1 root root 12833 2016-02-27 03:25 blockIP.2
-rw-r--r-- 1 root root  6240 2016-03-18 00:36 blockIP.1
-rw-r--r-- 1 root root  2353 2016-03-18 10:35 blockIP
I don't have a size limit specified and anyway the previous log size is only have or less of a typical log. Any idea what would trigger this? I've never seen this phenomenon before.

bassmadrigal 03-18-2016 12:51 PM
Quote:
Originally Posted by mfoley (Post 5517716)
This script is in /etc/logrotate.d/MAIL -- a separate file from the shipped-defaults. It is run via the usual convoluted yet standard mechanism: root's crontab > /etc/cron.daily/crontab > /usr/sbin/logrotate / etc/logrotate.conf, the latter of which includes the folder /etc/logrotate.d.
Out of curiosity, why don't you just use the monthly feature of cron? Either putting an entry in /etc/cron.monthly, or manually using crontab?

Quote:
Originally Posted by mfoley (Post 5517716)
It used to run at the beginning of the month, only, see below. Notice that the new log files are on the last or first day of the month for every month, except a new logfile was created on the 17th of this month.

Code:
-rw-r--r-- 1 root root 41259 2015-05-01 02:47 blockIP.12
-rw-r--r-- 1 root root 63101 2015-06-01 04:36 blockIP.11
-rw-r--r-- 1 root root 81794 2015-06-30 16:16 blockIP.10
-rw-r--r-- 1 root root 58837 2015-08-01 03:34 blockIP.9
-rw-r--r-- 1 root root 51836 2015-09-01 01:37 blockIP.8
-rw-r--r-- 1 root root 34981 2015-10-01 01:33 blockIP.7
-rw-r--r-- 1 root root 28385 2015-11-01 02:41 blockIP.6
-rw-r--r-- 1 root root 29531 2015-12-01 03:10 blockIP.5
-rw-r--r-- 1 root root 29791 2015-12-31 09:25 blockIP.4
-rw-r--r-- 1 root root 30567 2016-02-01 03:42 blockIP.3
-rw-r--r-- 1 root root 29622 2016-02-29 22:03 blockIP.2
-rw-r--r-- 1 root root 21310 2016-03-17 03:54 blockIP.1
-rw-r--r-- 1 root root  8923 2016-03-18 10:47 blockIP
Also, this happened again today on a different server, same logfile/utility!

Code:
-rwxr-x--- 1 root root 35622 2015-07-01 00:59 blockIP.10*
-rwxr-x--- 1 root root 17059 2015-08-01 03:34 blockIP.9*
-rwxr-x--- 1 root root 32040 2015-08-31 21:25 blockIP.8*
-rwxr-x--- 1 root root 25538 2015-10-01 02:05 blockIP.7*
-rwxr-x--- 1 root root 17953 2015-11-01 02:41 blockIP.6*
-rwxr-x--- 1 root root 16054 2015-12-01 02:21 blockIP.5*
-rw-r--r-- 1 root root 19282 2015-12-31 23:45 blockIP.4
-rw-r--r-- 1 root root 18140 2016-01-31 14:28 blockIP.3
-rw-r--r-- 1 root root 12833 2016-02-27 03:25 blockIP.2
-rw-r--r-- 1 root root  6240 2016-03-18 00:36 blockIP.1
-rw-r--r-- 1 root root  2353 2016-03-18 10:35 blockIP
I don't have a size limit specified and anyway the previous log size is only have or less of a typical log. Any idea what would trigger this? I've never seen this phenomenon before.
Did you make any changes/update any packages around that time? There's been several 14.1 patches released in March, but looking through them, nothing stands out to be the culprit. What's the output of the following?

Code:
ls -lrt /var/log/packages | tail -n 20

mfoley 03-19-2016 11:38 AM
Quote:
Originally Posted by bassmadrigal (Post 5517760)
Out of curiosity, why don't you just use the monthly feature of cron? Either putting an entry in /etc/cron.monthly, or manually using crontab?
I've been using the normal, as-shipped logrotate facility for years. It takes care of renaming files, etc. It has always been configured to run out of cron.daily and the monthly entries have always run at the beginning of the month. My /etc/cron.monthly directory is empty.

Quote:
Did you make any changes/update any packages around that time? There's been several 14.1 patches released in March, but looking through them, nothing stands out to be the culprit. What's the output of the following?

Code:
ls -lrt /var/log/packages | tail -n 20
No, no updates on the server I originally posted about since the beginning of January. I generally do updates quarterly.

But, output is:
Code:
> ls -lrt /var/log/packages | tail -n 20
-rw-r--r-- 1 root root    4564 2015-10-03 03:55 ppp-2.4.5-x86_64-3_slack14.1
-rw-r--r-- 1 root root    9290 2015-10-03 03:55 proftpd-1.3.4e-x86_64-1_slack14.1
-rw-r--r-- 1 root root  252458 2015-10-03 03:55 qt-4.8.7-x86_64-1_slack14.1
-rw-r--r-- 1 root root    3692 2015-10-03 03:55 wpa_supplicant-2.4-x86_64-1_slack14.1
-rw-r--r-- 1 root root  11777 2016-01-10 17:40 bind-9.9.8_P2-x86_64-1_slack14.1
-rw-r--r-- 1 root root  35966 2016-01-10 17:40 blueman-r708-x86_64-4_slack14.1
-rw-r--r-- 1 root root  22871 2016-01-10 17:40 curl-7.45.0-x86_64-1_slack14.1
-rw-r--r-- 1 root root  70258 2016-01-10 17:40 glibc-zoneinfo-2015g-noarch-1_slack14.1
-rw-r--r-- 1 root root  38076 2016-01-10 17:40 grub-2.00-x86_64-3_slack14.1
-rw-r--r-- 1 root root    1722 2016-01-10 17:40 jasper-1.900.1-x86_64-4_slack14.1
-rw-r--r-- 1 root root    1979 2016-01-10 17:40 libpng-1.4.19-x86_64-1_slack14.1
-rw-r--r-- 1 root root  62471 2016-01-10 17:40 mozilla-firefox-38.5.2esr-x86_64-1_slack14.1
-rw-r--r-- 1 root root    5756 2016-01-10 17:40 mozilla-nss-3.20.1-x86_64-1_slack14.1
-rw-r--r-- 1 root root  93445 2016-01-10 17:41 mozilla-thunderbird-38.5.0-x86_64-1_slack14.1
-rw-r--r-- 1 root root  22305 2016-01-10 17:41 ntp-4.2.8p4-x86_64-1_slack14.1
-rw-r--r-- 1 root root  33817 2016-01-10 17:41 openssl-1.0.1q-x86_64-1_slack14.1
-rw-r--r-- 1 root root    1622 2016-01-10 17:41 openssl-solibs-1.0.1q-x86_64-1_slack14.1
-rw-r--r-- 1 root root    5568 2016-01-10 17:41 pcre-8.38-x86_64-1_slack14.1
-rw-r--r-- 1 root root  339493 2016-01-10 17:41 seamonkey-2.39-x86_64-1_slack14.1
-rw-r--r-- 1 root root    1697 2016-01-10 17:41 seamonkey-solibs-2.39-x86_64-1_slack14.1

Richard Cranium 03-19-2016 12:34 PM
Is there anything interesting in syslog or messages around that time?

ljb643 03-19-2016 05:34 PM
Another way this can happen is if /var/lib/logrotate.status gets deleted (or mangled). Normally, the daily cron job will run logrotate, logrotate sees the "monthly" directive, and checks logrotate.status to see if it already rotated that file this month. If you lose the information in logrotate.status, the next daily run will be "first in the month".

Also, be aware that the timestamp on the rotated files is the time the last message was written to that file before rotation - not the rotation time.

mfoley 04-01-2016 11:01 AM
As of today (April 1) the montly log files are back to rotating monthly (if 1 month's worth is a sufficient test). No idea what happened, nothing in syslog gives a clue. I guess I'll just forget about it unless there are further occurances.


All times are GMT -5. The time now is 05:58 AM.