FS#18681 - [dcron] cron.daily scripts ran multiple times since cron package update
Attached to Project:
Arch Linux
Opened by Paul Ezvan (paulez) - Sunday, 14 March 2010, 19:44 GMT
Last edited by Andrea Scarpino (BaSh) - Sunday, 29 May 2011, 23:07 GMT
Opened by Paul Ezvan (paulez) - Sunday, 14 March 2010, 19:44 GMT
Last edited by Andrea Scarpino (BaSh) - Sunday, 29 May 2011, 23:07 GMT
|
Details
Description:
Since cron package update to dcron I get a weird behaviour with cron.daily scripts. Indeed these scripts are executed multiple times, which is somewhat annoying for big backups. I added this little script in cron.daily to show this : #!/bin/bash # Test cron date >> /var/log/date_cron And I get this : Sat Mar 6 14:53:32 CET 2010 Sat Mar 6 14:58:50 CET 2010 Sat Mar 6 15:04:18 CET 2010 Sun Mar 7 14:58:30 CET 2010 Sun Mar 7 14:58:30 CET 2010 Sun Mar 7 15:09:07 CET 2010 Sun Mar 7 15:13:29 CET 2010 Mon Mar 8 15:12:19 CET 2010 Mon Mar 8 15:12:19 CET 2010 Mon Mar 8 15:20:50 CET 2010 Tue Mar 9 15:24:35 CET 2010 Tue Mar 9 15:24:35 CET 2010 Tue Mar 9 15:31:58 CET 2010 We can see that the script is executed three times a day instead of one. Here is /var/spool/cron/root : # root crontab # DO NOT EDIT THIS FILE MANUALLY! USE crontab -e INSTEAD # man 1 crontab for acceptable formats: # <minute> <hour> <day> <month> <dow> <tags and command> # <@freq> <tags and command> # SYSTEM DAILY/WEEKLY/... FOLDERS @hourly ID=sys-hourly /usr/sbin/run-cron /etc/cron.hourly @daily ID=sys-daily /usr/sbin/run-cron /etc/cron.daily @weekly ID=sys-weekly /usr/sbin/run-cron /etc/cron.weekly @monthly ID=sys-monthly /usr/sbin/run-cron /etc/cron.monthly Package version : dcron-4.4-2 |
This task depends upon
Closed by Andrea Scarpino (BaSh)
Sunday, 29 May 2011, 23:07 GMT
Reason for closing: Fixed
Additional comments about closing: dcron 4.5-1
Sunday, 29 May 2011, 23:07 GMT
Reason for closing: Fixed
Additional comments about closing: dcron 4.5-1
Mar 16 23:04:02 krom crond[11234]: mailing cron output for user root job sys-daily
Mar 16 23:04:43 krom crond[24921]: mailing cron output for user root job sys-daily
(mailed output is the same)
dcron-4.4-2
Mar 16 23:04:02 krom crond[11234]: mailing cron output for user root job sys-daily
Mar 16 23:04:43 krom crond[24921]: mailing cron output for user root job sys-daily
(mailed output is the same)
dcron-4.4-2
Mar 19 10:51:01 svibor crond[1242]: FILE /var/spool/cron/root USER root PID 2245
3 job sys-weekly
Mar 19 10:53:01 svibor crond[1242]: FILE /var/spool/cron/root USER root PID 1341
8 job sys-weekly
As you can see, the same weekly job is executed twice. I have to say, however, that this started only after March 14, when the DST took place. Can this be related?
I reinstalled it:
# pacman -S dcron
# /etc/rc.d/cron restart
and it seems the problem disappeared (tested only that night).
If you change your crontab lines from:
@daily ID=XX command
to:
* * * * * FREQ=1d ID=XX command
does the scheduling error still occur? I expect it will, but it'd be good to know for sure.
Jul 20 20:01:01 fuxter-laptop crond[1957]: FILE /var/spool/cron/root USER root PID 6472 job backup_daily
Jul 20 20:07:01 fuxter-laptop crond[1957]: FILE /var/spool/cron/root USER root PID 6538 job backup_daily
Jul 20 20:17:01 fuxter-laptop crond[1957]: FILE /var/spool/cron/root USER root PID 6709 job backup_daily
Jul 20 20:27:01 fuxter-laptop crond[1957]: FILE /var/spool/cron/root USER root PID 6899 job backup_daily
Jul 20 20:37:01 fuxter-laptop crond[1957]: FILE /var/spool/cron/root USER root PID 7167 job backup_daily
Jul 20 20:47:01 fuxter-laptop crond[1957]: FILE /var/spool/cron/root USER root PID 7337 job backup_daily
Jul 20 20:57:01 fuxter-laptop crond[1957]: FILE /var/spool/cron/root USER root PID 7737 job backup_daily
Jul 20 21:07:01 fuxter-laptop crond[1957]: FILE /var/spool/cron/root USER root PID 7985 job backup_daily
Jul 20 21:12:01 fuxter-laptop crond[1957]: FILE /var/spool/cron/root USER root PID 8240 job sys-daily
Jul 20 21:12:01 fuxter-laptop crond[1957]: FILE /var/spool/cron/fuxter USER fuxter PID 8241 job nds_releases
Jul 20 21:12:01 fuxter-laptop crond[1957]: FILE /var/spool/cron/fuxter USER fuxter PID 8242 job psp_releases
Jul 20 21:17:01 fuxter-laptop crond[1957]: FILE /var/spool/cron/root USER root PID 8673 job backup_daily
Jul 20 21:23:32 fuxter-laptop crond[8858]: mailing cron output for user root job backup_daily
Jul 20 21:23:43 fuxter-laptop crond[8871]: mailing cron output for user root job backup_daily
Jul 20 21:23:51 fuxter-laptop crond[8878]: mailing cron output for user root job backup_daily
Jul 20 21:23:56 fuxter-laptop crond[8884]: mailing cron output for user root job backup_daily
Jul 20 21:24:09 fuxter-laptop crond[8891]: mailing cron output for user root job backup_daily
Jul 20 21:24:09 fuxter-laptop crond[8892]: mailing cron output for user root job backup_daily
Jul 20 21:25:05 fuxter-laptop crond[8906]: mailing cron output for user root job backup_daily
the job is:
@daily ID=backup_daily /root/backups/backup_daily.sh
* * * * * ID=backup_daily FREQ=1d /root/backups/backup_daily.sh gives the same result.
as you can guess my four months backup system has gone south ("backup_weekly" and "backup_monthly" act the same way). the only way i can use dcron is adding & sign to the end of the "command", but that's cheating, you know =)
i would like to help with testing.
pardon my russian
Sep 16 21:50:01 lemlin01 crond[1484]: FILE /var/spool/cron/root USER root PID 30194 job sys-hourly
Sep 16 23:50:01 lemlin01 crond[1484]: FILE /var/spool/cron/root USER root PID 30948 job sys-hourly
Sep 17 01:50:01 lemlin01 crond[1484]: FILE /var/spool/cron/root USER root PID 31717 job sys-hourly
Sep 17 03:50:01 lemlin01 crond[1484]: FILE /var/spool/cron/root USER root PID 32470 job sys-hourly
Sep 17 05:50:01 lemlin01 crond[1484]: FILE /var/spool/cron/root USER root PID 790 job sys-hourly
Sep 17 07:50:01 lemlin01 crond[1484]: FILE /var/spool/cron/root USER root PID 1570 job sys-hourly
Sep 17 09:50:01 lemlin01 crond[1484]: FILE /var/spool/cron/root USER root PID 2673 job sys-hourly
Sep 17 11:02:01 lemlin01 crond[1484]: FILE /var/spool/cron/root USER root PID 3177 job sys-daily
Sep 17 11:05:01 lemlin01 crond[1484]: FILE /var/spool/cron/root USER root PID 3784 job sys-daily
Sep 17 11:05:52 lemlin01 crond[3808]: mailing cron output for user root job sys-daily
[2010-09-16 10:01] upgraded chromium (6.0.472.53-1 -> 6.0.472.59-1)
[2010-09-16 10:01] upgraded lib32-gcc-libs (4.5.1-6 -> 4.5.1-7)
[2010-09-16 10:01] upgraded gcc-libs-multilib (4.5.1-6 -> 4.5.1-7)
[2010-09-16 10:01] upgraded xulrunner (1.9.2.9-1 -> 1.9.2.10-1)
[2010-09-16 10:01] upgraded firefox (3.6.9-1 -> 3.6.10-1)
[2010-09-16 10:01] upgraded lib32-alsa-lib (1.0.23-3 -> 1.0.23-4)
[2010-09-16 10:01] upgraded lib32-alsa-plugins (1.0.23-4 -> 1.0.23-5)
[2010-09-16 10:01] upgraded lib32-pcre (8.10-2 -> 8.10-3)
[2010-09-16 10:01] upgraded lib32-zlib (1.2.5-4 -> 1.2.5-5)
[2010-09-16 10:01] upgraded lib32-glib2 (2.24.1-2 -> 2.24.1-3)
[2010-09-16 10:01] upgraded lib32-atk (1.30.0-2 -> 1.30.0-3)
[2010-09-16 10:01] upgraded lib32-attr (2.4.44-3 -> 2.4.44-4)
[2010-09-16 10:01] upgraded lib32-libpng (1.4.3-2 -> 1.4.3-3)
[2010-09-16 10:01] upgraded lib32-libxdmcp (1.0.3-3 -> 1.0.3-4)
[2010-09-16 10:01] upgraded lib32-libxau (1.0.6-1 -> 1.0.6-2)
[2010-09-16 10:01] upgraded lib32-libxcb (1.7-1 -> 1.7-2)
[2010-09-16 10:01] upgraded lib32-libx11 (1.3.5-1 -> 1.3.5-2)
[2010-09-16 10:01] upgraded lib32-libxrender (0.9.6-3 -> 0.9.6-4)
[2010-09-16 10:01] upgraded lib32-expat (2.0.1-6 -> 2.0.1-7)
[2010-09-16 10:01] upgraded lib32-freetype2 (2.4.2-2 -> 2.4.2-3)
[2010-09-16 10:01] upgraded lib32-fontconfig (2.8.0-2 -> 2.8.0-3)
[2010-09-16 10:01] upgraded lib32-pixman (0.18.4-1 -> 0.18.4-2)
[2010-09-16 10:01] upgraded lib32-cairo (1.8.10-2 -> 1.10.0-3)
[2010-09-16 10:01] upgraded lib32-openssl (1.0.0.a-5 -> 1.0.0.a-6)
[2010-09-16 10:01] upgraded lib32-curl (7.21.1-2 -> 7.21.1-3)
[2010-09-16 10:01] upgraded lib32-db (4.8.26-4 -> 4.8.26-5)
[2010-09-16 10:01] upgraded lib32-dbus-core (1.2.24-2 -> 1.4.0-2)
[2010-09-16 10:01] upgraded lib32-util-linux-ng (2.18-2 -> 2.18-3)
[2010-09-16 10:01] upgraded lib32-e2fsprogs (1.41.12-2 -> 1.41.12-3)
[2010-09-16 10:01] upgraded lib32-libogg (1.2.0-3 -> 1.2.0-4)
[2010-09-16 10:01] upgraded lib32-flac (1.2.1-6 -> 1.2.1-7)
[2010-09-16 10:01] upgraded lib32-ncurses (5.7-4 -> 5.7-5)
[2010-09-16 10:01] upgraded lib32-readline (6.1.002-2 -> 6.1.002-3)
[2010-09-16 10:01] upgraded lib32-libgpg-error (1.9-3 -> 1.9-4)
[2010-09-16 10:01] upgraded lib32-libgcrypt (1.4.6-2 -> 1.4.6-3)
[2010-09-16 10:01] upgraded lib32-gnutls (2.8.6-3 -> 2.8.6-4)
[2010-09-16 10:01] upgraded lib32-libxft (2.1.14-2 -> 2.1.14-3)
[2010-09-16 10:01] upgraded lib32-pango (1.28.1-2 -> 1.28.1-3)
[2010-09-16 10:01] upgraded lib32-sqlite3 (3.7.1-1 -> 3.7.1-2)
[2010-09-16 10:01] upgraded lib32-heimdal (1.3.3-2 -> 1.3.3-3)
[2010-09-16 10:01] upgraded lib32-libjpeg (8.0.2-2 -> 8.0.2-3)
[2010-09-16 10:01] upgraded lib32-libtiff (3.9.4-2 -> 3.9.4-3)
[2010-09-16 10:01] upgraded lib32-libcups (1.4.4-4 -> 1.4.4-5)
[2010-09-16 10:01] upgraded lib32-libxfixes (4.0.5-2 -> 4.0.5-3)
[2010-09-16 10:01] upgraded lib32-libxcursor (1.1.10-2 -> 1.1.10-3)
[2010-09-16 10:01] upgraded lib32-libxext (1.1.2-2 -> 1.1.2-3)
[2010-09-16 10:01] upgraded lib32-libxrandr (1.3.0-2 -> 1.3.0-3)
[2010-09-16 10:01] upgraded lib32-libxi (1.3.2-2 -> 1.3.2-3)
[2010-09-16 10:01] upgraded lib32-libxinerama (1.1-2 -> 1.1-3)
[2010-09-16 10:01] upgraded lib32-libxcomposite (0.4.2-2 -> 0.4.2-3)
[2010-09-16 10:01] upgraded lib32-libxdamage (1.1.3-2 -> 1.1.3-3)
[2010-09-16 10:02] upgraded lib32-gtk2 (2.20.1-3 -> 2.20.1-4)
[2010-09-16 10:02] upgraded lib32-libasyncns (0.8-4 -> 0.8-5)
[2010-09-16 10:02] upgraded lib32-libcap (2.19-2 -> 2.19-3)
[2010-09-16 10:02] upgraded lib32-libdrm (2.4.21-3 -> 2.4.21-4)
[2010-09-16 10:02] upgraded lib32-libice (1.0.6-2 -> 1.0.6-3)
[2010-09-16 10:02] upgraded lib32-libmng (1.0.10-4 -> 1.0.10-5)
[2010-09-16 10:02] upgraded lib32-libsm (1.1.1-2 -> 1.1.1-3)
[2010-09-16 10:02] upgraded lib32-libvorbis (1.3.1-3 -> 1.3.1-4)
[2010-09-16 10:02] upgraded lib32-libsndfile (1.0.21-4 -> 1.0.21-5)
[2010-09-16 10:02] upgraded lib32-libtool (2.2.10-6 -> 2.2.10-7)
[2010-09-16 10:02] upgraded lib32-libxml2 (2.7.7-2 -> 2.7.7-3)
[2010-09-16 10:02] upgraded lib32-libxt (1.0.8-2 -> 1.0.8-3)
[2010-09-16 10:02] upgraded lib32-libxmu (1.0.5-2 -> 1.0.5-3)
[2010-09-16 10:02] upgraded lib32-libxss (1.2.0-2 -> 1.2.0-3)
[2010-09-16 10:02] upgraded lib32-libxtst (1.1.0-2 -> 1.1.0-3)
[2010-09-16 10:02] upgraded lib32-libxv (1.0.5-2 -> 1.0.5-3)
[2010-09-16 10:02] upgraded lib32-libxxf86dga (1.1.1-2 -> 1.1.1-3)
[2010-09-16 10:02] upgraded lib32-libxxf86vm (1.1.0-2 -> 1.1.0-3)
[2010-09-16 10:02] upgraded lib32-mesa (7.8.2-4 -> 7.8.2-5)
[2010-09-16 10:02] upgraded lib32-nspr (4.8.6-1 -> 4.8.6-2)
[2010-09-16 10:02] upgraded lib32-nss (3.12.7-1 -> 3.12.7-2)
[2010-09-16 10:02] upgraded lib32-pulseaudio (0.9.21-12 -> 0.9.21-13)
[2010-09-16 10:02] upgraded lib32-xcb-util (0.3.6-2 -> 0.3.6-3)
[2010-09-16 10:02] upgraded libtool-multilib (2.2.10-6 -> 2.2.10-7)
[2010-09-16 10:02] upgraded ntfs-3g (2010.5.22-1 -> 2010.8.8-1)
[2010-09-16 10:02] upgraded perl-xyne-arch (2010.09.13.1-1 -> 2010.09.13.1-2)
[2010-09-16 10:02] upgraded skype (2.1.0.81-4 -> 2.1.0.81-5)
[2010-09-16 10:02] upgraded wine (1.3.2-1 -> 1.3.2-2)
[2010-09-16 10:02] upgraded xz (4.999.9beta-5 -> 4.999.9beta_174_g41bc-1)
[2010-09-16 10:38] upgraded grisbi (0.6.0-1 -> 0.6.0-2)
[2010-09-16 10:38] upgraded python-keyring (0.3-2 -> 0.4-1)
[2010-09-16 10:38] upgraded ranger (1.1.2-2 -> 1.2.0-1)
[2010-09-16 10:41] ==> upgraded, to compile the module for the new kernel version.
[2010-09-16 10:41] upgraded virtualbox_bin (3.2.8-2 -> 3.2.8-3)
[2010-09-16 13:22] upgraded kdelibs (4.5.1-1 -> 4.5.1-2)
[2010-09-16 13:24] upgraded kdelibs (4.5.1-2 -> 4.5.1-1)
[2010-09-16 13:31] upgraded kdevelop (4.0.2-1 -> 4.0.2-1)
[2010-09-16 20:26] upgraded lib32-cairo (1.10.0-3 -> 1.8.10-2)
[2010-09-16 22:19] upgraded lib32-dbus-core (1.4.0-2 -> 1.2.24-3)
[2010-09-16 22:19] upgraded mdadm (3.1.3-1 -> 3.1.4-1)
[2010-09-16 22:19] upgraded thunderbird (3.1.3-1 -> 3.1.4-1)
[2010-09-16 22:19] upgraded xfsprogs (3.1.2-1 -> 3.1.3-1)
[2010-09-16 23:43] upgraded ranger (1.2.0-1 -> 1.2.1-2)
There where many inquiries in forums and flyspray to replace dcron with {b/f}cron. While I understand the motivation not to add new deps in the core setup, I also think that /core must not contain software with long-standing open bugs.
BTW, fcron has been moved from AUR to /community in July.
This rule:
* * * * * ID=repo-cache FREQ=5h /home/wooptoo/bin/repo-cache
Randomly runs twice:
Oct 18 04:16:01 localhost crond[3808]: FILE /var/spool/cron/root USER root PID 14066 job repo-cache
Oct 18 04:17:01 localhost crond[3808]: FILE /var/spool/cron/root USER root PID 14069 job repo-cache
Oct 18 22:17:01 localhost crond[3808]: FILE /var/spool/cron/root USER root PID 8227 job repo-cache
Oct 18 22:22:01 localhost crond[3808]: FILE /var/spool/cron/root USER root PID 8229 job repo-cache
Oct 19 10:17:01 localhost crond[3808]: FILE /var/spool/cron/root USER root PID 14424 job repo-cache
Oct 19 10:21:01 localhost crond[3808]: FILE /var/spool/cron/root USER root PID 14426 job repo-cache
This is with HARDWARECLOCK="UTC" in the rc.conf, btw.
http://slackware.osuosl.org/slackware-13.1/source/a/dcron/
This problem seems to be associated with daylight savings time change as Vincent Cappe (vcap) says. Summer time here is GMT+1 and I can see that during summer time the hourly job ran only every 2 hours.
The daily job seems to run twice every 4 days during summer time (it didn't run twice on the day the time changed) and so far not enough days have passed to be quite sure of the frequency at which the job is run twice during winter time (at first glance it seems to be every 5 days but it needs at least a couple more observations to confirm).
cron.hourly runs twice every hour in ~5min intervals.
Basically, it happens when SynchronizeDir() is called while crond is waiting for a (named?) job to complete. Now, SynchronizeDir() is called every 60 iterations of the main loop and there is one iteration every ten seconds when a job is running; so a crontab entry like the following will trigger the bug every time (it only happen with @foobar and FREQ= jobs, if i am not mistaken):
* * * * * ID=donothing FREQ=20m sleep 660
if there is no bug it should run every 20 minutes; with the bug it will run about every 10 minutes.
@hourly ID=sys-hourly /usr/sbin/run-cron /etc/cron.hourly
@daily ID=sys-daily /usr/sbin/run-cron /etc/cron.daily
@weekly ID=sys-weekly /usr/sbin/run-cron /etc/cron.weekly
@monthly ID=sys-monthly /usr/sbin/run-cron /etc/cron.monthly
Does that fit with your observations?
Yes, if any of those run long enough (or a unlucky enough) to cross with a SynchronizeDir(), it will trigger the bug, afaiu.
Indeed, i discovered that accidentally while stress-testing my box; it caused updatedb to take a little longer than usual to finish, hence triggering the bug (which i had never seen previously).
As to timing, the earliest I'll have a chunk of time to give to this will be this coming weekend. The latest will be during the Christmas break. This is high on my todo list and I will try hard to make it earlier rather than later. Fixes will be pushed first to aur/dcron-git, and I will let everyone know they're available. I'll make an official release as soon as it sounds stable.
In addition to cron jobs running twice, I have a reason to believe that cron.monthly doesn't run at all. Two of my systems running Arch are configured to do monthly backups via rsnapshot but it just never happens.
Also, I had some time to look at the code last night. It looks pretty tidy (except for some mixing of tabs and spaces :p), but it'll take me some time to get to grips with how it all works, as it's pretty complex. I'm hopeful I'll have something in a few days.
I've created an AUR package called dcron-maint (http://aur.archlinux.org/packages.php?ID=46757) containing this patch and the patch from https://bugs.archlinux.org/task/19123.