Hi I have a Pyramid wsgi webapp served using Apache. The webapp has an hourly job that must be run at the 0th min to fetch time-sensitive data and write to my mysql database. I note that sometimes (not all times) the data might not be written into the database for the midnight 00:00:00 run of the task. Looking at the logs, it seems that Apache has been restarted shortly after every midnight which might cause the problem.
After searching through stackoverflow it seems logrotate might be the culprit for the restart. However, I also note that logrotate is called by crontab which defaults to 6:25am so I have no idea why the restart happens at midnight instead. (My Ubuntu server does NOT have anacron installed)
here are the log files for the last few days from Apache
[Tue May 11 00:00:35.534821 2021] [mpm_event:notice] [pid 72273:tid 140034084613184] AH00489: Apache/2.4.41 (Ubuntu) mod_wsgi/4.6.8 Python/3.8 configured -- resuming normal operations
[Tue May 11 00:00:35.534867 2021] [core:notice] [pid 72273:tid 140034084613184] AH00094: Command line: '/usr/sbin/apache2'
.
.
.
[Wed May 12 00:00:00.029412 2021] [wsgi:error] [pid 72660:tid 140033624434432] 2021-05-12 00:00:00,029 INFO [apscheduler.executors.default:123][ThreadPoolExecutor-0_0] Running job "XYZ (trigger: cron[minute='0'], next run at: 2021-05-12 01:00:00 HKT)" (scheduled at 2021-05-12 00:00:00+08:00)
[Wed May 12 00:00:00.621944 2021] [mpm_event:notice] [pid 72273:tid 140034084613184] AH00493: SIGUSR1 received. Doing graceful restart
[Wed May 12 00:00:03.614647 2021] [wsgi:error] [pid 72660:tid 140033624434432] 2021-05-12 00:00:03,614 INFO [apscheduler.executors.default:144][ThreadPoolExecutor-0_0] Job "XYZ (trigger: cron[minute='0'], next run at: 2021-05-12 01:00:00 HKT)" executed successfully
Interesting to note from the log above that it seems my apscheduler still completed running (with the database written into successfully) and printed to the log after Doing graceful restart and before a new log file is created (contents shown below)
[Wed May 12 00:00:03.641095 2021] [mpm_event:notice] [pid 72273:tid 140034084613184] AH00489: Apache/2.4.41 (Ubuntu) mod_wsgi/4.6.8 Python/3.8 configured -- resuming normal operations
[Wed May 12 00:00:03.641146 2021] [core:notice] [pid 72273:tid 140034084613184] AH00094: Command line: '/usr/sbin/apache2'
.
.
.
[Thu May 13 00:00:00.032261 2021] [wsgi:error] [pid 95013:tid 140083656877824] 2021-05-13 00:00:00,032 INFO [apscheduler.executors.default:123][ThreadPoolExecutor-0_0] Running job "XYZ (trigger: cron[minute='0'], next run at: 2021-05-13 01:00:00 HKT)" (scheduled at 2021-05-13 00:00:00+08:00)
[Thu May 13 00:00:03.764471 2021] [wsgi:error] [pid 95013:tid 140083656877824] 2021-05-13 00:00:03,764 INFO [apscheduler.executors.default:144][ThreadPoolExecutor-0_0] Job "XYZ (trigger: cron[minute='0'], next run at: 2021-05-13 01:00:00 HKT)" executed successfully
[Thu May 13 00:00:34.829438 2021] [mpm_event:notice] [pid 95012:tid 140084121332800] AH00493: SIGUSR1 received. Doing graceful restart
In the log file above, my apscheduler job completed before the restart so my database got written into properly as well.
[Thu May 13 00:00:35.588354 2021] [mpm_event:notice] [pid 95012:tid 140084121332800] AH00489: Apache/2.4.41 (Ubuntu) mod_wsgi/4.6.8 Python/3.8 configured -- resuming normal operations
[Thu May 13 00:00:35.588433 2021] [core:notice] [pid 95012:tid 140084121332800] AH00094: Command line: '/usr/sbin/apache2'
.
.
.
[Fri May 14 00:00:00.020559 2021] [wsgi:error] [pid 2120:tid 140241617286912] 2021-05-14 00:00:00,020 INFO [apscheduler.executors.default:123][ThreadPoolExecutor-0_0] Running job "XYZ (trigger: cron[minute='0'], next run at: 2021-05-14 01:00:00 HKT)" (scheduled at 2021-05-14 00:00:00+08:00)
[Fri May 14 00:00:00.558072 2021] [mpm_event:notice] [pid 2119:tid 140242151496768] AH00493: SIGUSR1 received. Doing graceful restart
for the midnight that just passed, the job didn't complete and database has not been written into. there is also no accompanying INFO [apscheduler.executors.default:144][ThreadPoolExecutor-0_0] Job "XYZ (trigger: cron[minute='0'], next run at: xxxxxxx)" executed successfully line written into either of the logs before and after midnight since the job got terminated abruptly before completing
[Fri May 14 00:00:03.588691 2021] [mpm_event:notice] [pid 2119:tid 140242151496768] AH00489: Apache/2.4.41 (Ubuntu) mod_wsgi/4.6.8 Python/3.8 configured -- resuming normal operations
[Fri May 14 00:00:03.588744 2021] [core:notice] [pid 2119:tid 140242151496768] AH00094: Command line: '/usr/sbin/apache2'
.
.
.
day hasn't ended yet
Here is my crontab file which I believe is standard and state that daily jobs should be run at 6:25AM not midnight.
# /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 )
again my Ubuntu server does NOT have anacron installed
ubuntu@xxx:~$ anacron --help
Command 'anacron' not found, but can be installed with:
sudo apt install anacron
logrotate and apache has cron.daily task
ubuntu@xxx:~$ ls -ln /etc/cron.daily/
total 40
-rwxr-xr-x 1 0 0 539 Apr 14 2020 apache2
-rwxr-xr-x 1 0 0 376 Dec 5 2019 apport
-rwxr-xr-x 1 0 0 1478 Apr 9 2020 apt-compat
-rwxr-xr-x 1 0 0 355 Dec 29 2017 bsdmainutils
-rwxr-xr-x 1 0 0 1187 Sep 6 2019 dpkg
-rwxr-xr-x 1 0 0 377 Jan 21 2019 logrotate
-rwxr-xr-x 1 0 0 1123 Feb 26 2020 man-db
-rwxr-xr-x 1 0 0 4574 Jul 18 2019 popularity-contest
-rwxr-xr-x 1 0 0 214 Dec 7 23:35 update-notifier-common
vi /etc/cron.daily/logrotate
#!/bin/sh
# skip in favour of systemd timer
if [ -d /run/systemd/system ]; then
exit 0
fi
# this cronjob persists removals (but not purges)
if [ ! -x /usr/sbin/logrotate ]; then
exit 0
fi
/usr/sbin/logrotate /etc/logrotate.conf
EXITVALUE=$?
if [ $EXITVALUE != 0 ]; then
/usr/bin/logger -t logrotate "ALERT exited abnormally with [$EXITVALUE]"
fi
exit $EXITVALUE
vi /etc/cron.daily/apache2
#!/bin/sh
# run htcacheclean if set to 'cron' mode
set -e
set -u
type htcacheclean > /dev/null 2>&1 || exit 0
[ -e /etc/default/apache-htcacheclean ] || exit 0
# edit /etc/default/apache-htcacheclean to change this
HTCACHECLEAN_MODE=daemon
HTCACHECLEAN_RUN=auto
HTCACHECLEAN_SIZE=300M
HTCACHECLEAN_PATH=/var/cache/apache2/mod_cache_disk
HTCACHECLEAN_OPTIONS=""
. /etc/default/apache-htcacheclean
[ "$HTCACHECLEAN_MODE" = "cron" ] || exit 0
htcacheclean ${HTCACHECLEAN_OPTIONS} \
-p${HTCACHECLEAN_PATH} \
-l${HTCACHECLEAN_SIZE}
/etc/logrotate.conf is just a standard file
# see "man logrotate" for details
# rotate log files weekly
weekly
# use the adm group by default, since this is the owning group
# of /var/log/syslog.
su root adm
# keep 4 weeks worth of backlogs
rotate 4
# create new (empty) log files after rotating old ones
create
# use date as a suffix of the rotated file
#dateext
# uncomment this if you want your log files compressed
#compress
# packages drop log rotation information into this directory
include /etc/logrotate.d
# system-specific logs may be also be configured here.
apache2 included under logrotate.d
ubuntu@xxx:~$ ls -ln /etc/logrotate.d
total 52
-rw-r--r-- 1 0 0 120 Sep 6 2019 alternatives
-rw-r--r-- 1 0 0 442 Apr 14 2020 apache2
-rw-r--r-- 1 0 0 126 Dec 5 2019 apport
-rw-r--r-- 1 0 0 173 Apr 9 2020 apt
-rw-r--r-- 1 0 0 91 Nov 2 2020 bootlog
-rw-r--r-- 1 0 0 130 Jan 21 2019 btmp
-rw-r--r-- 1 0 0 112 Sep 6 2019 dpkg
-rw-r--r-- 1 0 0 845 Nov 7 2019 mysql-server
-rw-r--r-- 1 0 0 501 Mar 7 2019 rsyslog
-rw-r--r-- 1 0 0 119 Mar 31 2020 ubuntu-advantage-tools
-rw-r--r-- 1 0 0 178 Jan 22 2020 ufw
-rw-r--r-- 1 0 0 235 Jul 21 2020 unattended-upgrades
-rw-r--r-- 1 0 0 145 Feb 19 2018 wtmp
vi /etc/logrotate.d/apache2
/var/log/apache2/*.log {
daily
missingok
rotate 14
compress
delaycompress
notifempty
create 640 root adm
sharedscripts
postrotate
if invoke-rc.d apache2 status > /dev/null 2>&1; then \
invoke-rc.d apache2 reload > /dev/null 2>&1; \
fi;
endscript
prerotate
if [ -d /etc/logrotate.d/httpd-prerotate ]; then \
run-parts /etc/logrotate.d/httpd-prerotate; \
fi; \
endscript
}
I just want to know why my Apache gets restarted at midnight when according to crontab it should be at 6:25AM and change the time to avoid conflict with my 0th min hourly job. thanks!
