Created attachment 884427 [details] emerge --info after upgrading sys-process/cronie from 1.7.0-r2 to 1.7.1-r1 I ran into a trouble. /etc/cron.hourly and cron.daily getting triggered as expected, but cron.weekly and cron.monthly not. At least not the "re-trigger" (I call it the anacron mode), when the machine was off during the default time for the cron run USE=anacron is set and it worked since 2019. Just on Jan 20th I ran into this and that is the date of aforementioned update Last time cron.weekly worked as expected was Jan 20th. On February 2nd one more run happend but with an error: ------------------------------------------------------------------------------------------------------- # cat /var/log/messages-20240204 | grep cron | grep week Feb 2 19:01:00 brain anacron[27854]: Will run job `cron.weekly' in 46 min. Feb 2 20:01:00 brain anacron[10932]: Job `cron.weekly' locked by another anacron - skipping Feb 2 20:09:11 brain anacron[27854]: Job `cron.weekly' started Feb 2 20:17:10 brain anacron[27854]: Job `cron.weekly' terminated (exit status: 1) (produced output) ------------------------------------------------------------------------------------------------------- I do not have another weird cron or anacron thing installed or active /etc/anacrontab and /etc/cron.hourly/0anacron look all correct Permissions on /etc/cron.* (maybe debatable but like this for long time) -rw-r--r-- 1 root root 541 20. Jan 10:39 anacrontab drwxr-xr-x 2 root root 38 28. Apr 2023 cron.d drwxr-xr-x 2 root root 4096 24. Nov 21:02 cron.daily -rw-r--r-- 1 root root 148 20. Jan 10:39 cron.deny drwxr-x--- 2 root root 93 17. Dez 13:53 cron.hourly drwxr-x--- 2 root root 123 24. Nov 21:02 cron.monthly -rw-r--r-- 1 root root 476 20. Jan 10:39 crontab drwxr-x--- 2 root root 205 24. Nov 21:02 cron.weekly -rw-r--r-- 1 root root 237 29. Apr 2021 mlocate-cron.conf I did study bug551352 and https://forums.gentoo.org/viewtopic-t-1108098-start-0.html. It looks to me all is fine /etc/cron.d/dailyjobs also looks good. I (hectically) filed an upstream bug https://github.com/cronie-crond/cronie/issues/178 I am on the verge to downgrade to former version, as I need my backup to run reliably...
The ebuild didn't change between those versions other than the upstream backports: ``` $ diff -ruN cronie-1.7.0-r2.ebuild cronie-1.7.1-r1.ebuild --- cronie-1.7.0-r2.ebuild 2024-01-16 02:11:52.217381625 +0000 +++ cronie-1.7.1-r1.ebuild 2024-01-24 11:11:04.924572520 +0000 @@ -34,8 +34,7 @@ " PATCHES=( - "${FILESDIR}"/${P}-optional-envionment.patch - "${FILESDIR}"/${P}-optional-default-anacron.patch + "${FILESDIR}"/${P}-envelope-revert.patch ) src_configure() { ```
Actually the cronie-1.7.1.ebuild looks different to both, the 1.7.0 and the 1.7.1-r1 version. But this is above my head and hence I downgraded (luckily the former ebuild still in the system ;-) )
You're going to need to do some investigation here. The only relevant changes were backporting things which ended up in the final release. Maybe try bisecting.
sping: any ideas? I've got none...
> Feb 2 20:17:10 brain anacron[27854]: Job `cron.weekly' terminated (exit status: 1) (produced output) Your /var/log/messages output indicates that it is actually running, but exiting uncleanly. What does `cron.weekly` do? What output was produced? I'm almost certain there will be some hints in there as to what's going wrong :)
What happened on Feb 2nd was a singular event, as far as I can see. Meanwhile I have masked cronie-1.7.1 and 1.7.1-r1 and downgraded. Rightaway cron.monthly started. cron.weekly stared during night, so everything works fine with cronie-1.7.0-r2 I am lost, what else I could analyse when Matt asks "what does 'cron.weekly' do and what output was produced", I get lost a bit (likely due to English limitations) as 'cron.weekly' I do not understand as a command and when cron.weekly only outputs to /var/log/rsnapshot. If that is what is wanted, that is here: __________________________________________________________________________ [2024-02-02T20:10:25] /usr/bin/rsnapshot weekly: started [2024-02-02T20:10:25] /bin/rm -rf /mnt/NAS/BACKUP-brain/weekly.3/ [2024-02-02T20:17:10] mv /mnt/NAS/BACKUP-brain/weekly.2/ /mnt/NAS/BACKUP-brain/weekly.3/ [2024-02-02T20:17:10] mv /mnt/NAS/BACKUP-brain/weekly.1/ /mnt/NAS/BACKUP-brain/weekly.2/ [2024-02-02T20:17:10] mv /mnt/NAS/BACKUP-brain/weekly.0/ /mnt/NAS/BACKUP-brain/weekly.1/ [2024-02-02T20:17:10] mv /mnt/NAS/BACKUP-brain/daily.6/ /mnt/NAS/BACKUP-brain/weekly.0/ [2024-02-02T20:17:10] /usr/bin/logger -p user.info -t rsnapshot[20854] /usr/bin/rsnapshot weekly: completed successfully [2024-02-02T20:17:10] /usr/bin/rsnapshot weekly: completed successfully __________________________________________________________________________ (by reading that, I have to correct my self, cron.weekly did actually run on Feb 2nd, means with cronie-1.7.1-r1) By reading anacrontab, cron.weekly should have been invoked on Sunday 4th again, but didn't (or the Monday after, in case PC was off) and from anacrontab I cannot really understand, by when cron.monthly is expected to be invoked. Unfortunately I my backup server broke down a view weeks ago, so I do not have older logs or such.
here is my /var/log from the time cron.weekly got invoked Feb 2nd Feb 2 19:48:42 brain ntpd[5631]: adjusting clock frequency by 0.066812 to -29.425269ppm Feb 2 20:01:00 brain CROND[10924]: (root) CMD (run-parts /etc/cron.hourly) Feb 2 20:01:00 brain anacron[10932]: Anacron started on 2024-02-02 Feb 2 20:01:00 brain anacron[10932]: Job `cron.daily' locked by another anacron - skipping Feb 2 20:01:00 brain anacron[10932]: Job `cron.weekly' locked by another anacron - skipping Feb 2 20:01:00 brain anacron[10932]: Normal exit (0 jobs run) Feb 2 20:01:01 brain CROND[10923]: (root) CMDEND (run-parts /etc/cron.hourly) Feb 2 20:01:23 brain kernel: Bad packet from [deleted firewall messages] Feb 2 20:01:23 brain kernel: Bad packet from [deleted firewall messages] Feb 2 20:01:31 brain kernel: Bad packet from [deleted firewall messages] Feb 2 20:03:36 brain kernel: Bad packet from [deleted firewall messages] Feb 2 20:05:41 brain kernel: Bad packet from [deleted firewall messages] Feb 2 20:09:06 brain rsnapshot[2627]: /usr/bin/rsnapshot daily: completed successfully Feb 2 20:09:07 brain su[12969]: (to gerber) root on none Feb 2 20:09:07 brain su[12969]: pam_unix(su-l:session): session opened for user gerber(uid=1000) by (uid=0) Feb 2 20:09:07 brain su[12969]: pam_unix(su-l:session): session closed for user gerber Feb 2 20:09:07 brain su[12977]: (to gerber) root on none Feb 2 20:09:07 brain su[12977]: pam_unix(su-l:session): session opened for user gerber(uid=1000) by (uid=0) Feb 2 20:09:07 brain su[12977]: pam_unix(su-l:session): session closed for user gerber Feb 2 20:09:11 brain anacron[27854]: Job `cron.daily' terminated (produced output) Feb 2 20:09:11 brain anacron[27854]: Job `cron.weekly' started Feb 2 20:09:11 brain crontab[13076]: (root) LIST (nobody) Feb 2 20:09:38 brain kernel: IPT OUTPUT @ the END: [deleted firewall messages] Feb 2 20:10:24 brain nfsrahead[20807]: setting /mnt/NAS readahead to 128 Feb 2 20:15:07 brain ntpd[5602]: client_query socket: Address family not supported by protocol Feb 2 20:17:10 brain rsnapshot[20854]: /usr/bin/rsnapshot weekly: completed successfully Feb 2 20:17:10 brain anacron[27854]: Job `cron.weekly' terminated (exit status: 1) (produced output) Feb 2 20:17:10 brain anacron[27854]: Normal exit (2 jobs run) Feb 2 20:17:29 brain ntpd[5602]: client_query socket: Address family not supported by protocol Feb 2 20:18:10 brain ntpd[5602]: client_query socket: Address family not supported by protocol Feb 2 20:18:32 brain ntpd[5602]: client_query socket: Address family not supported by protocol Feb 2 20:22:21 brain kernel: Bad packet from [deleted firewall messages]
Ooops I found this in my /var/log/messages: ________________________________________________________ Feb 4 04:22:00 brain CROND[30188]: (root) CMD ([ ! -f /etc/cron.hourly/0anacron ] && run-parts /etc/cron.weekly) Feb 4 04:22:00 brain CROND[30187]: (root) CMDEND ([ ! -f /etc/cron.hourly/0anacron ] && run-parts /etc/cron.weekly) Feb 4 04:22:42 brain ntpd[5631]: adjusting clock frequency by -0.331271 to -30.520740ppm ________________________________________________________
similar message I got a day earlier for cron.hourly: cat /var/log/messages-20240204 | grep anacron Jan 28 10:56:04 brain anacron[9532]: Job `cron.daily' terminated (produced output) Jan 28 10:56:04 brain anacron[9532]: Normal exit (1 job run) Feb 2 19:01:00 brain anacron[27854]: Anacron started on 2024-02-02 Feb 2 19:01:00 brain anacron[27854]: Will run job `cron.daily' in 26 min. Feb 2 19:01:00 brain anacron[27854]: Will run job `cron.weekly' in 46 min. Feb 2 19:01:00 brain anacron[27854]: Jobs will be executed sequentially Feb 2 19:27:00 brain anacron[27854]: Job `cron.daily' started Feb 2 20:01:00 brain anacron[10932]: Anacron started on 2024-02-02 Feb 2 20:01:00 brain anacron[10932]: Job `cron.daily' locked by another anacron - skipping Feb 2 20:01:00 brain anacron[10932]: Job `cron.weekly' locked by another anacron - skipping Feb 2 20:01:00 brain anacron[10932]: Normal exit (0 jobs run) Feb 2 20:09:11 brain anacron[27854]: Job `cron.daily' terminated (produced output) Feb 2 20:09:11 brain anacron[27854]: Job `cron.weekly' started Feb 2 20:17:10 brain anacron[27854]: Job `cron.weekly' terminated (exit status: 1) (produced output) Feb 2 20:17:10 brain anacron[27854]: Normal exit (2 jobs run) Feb 3 00:01:00 brain anacron[11184]: Anacron started on 2024-02-03 Feb 3 00:01:00 brain anacron[11184]: Normal exit (0 jobs run) Feb 3 01:01:00 brain anacron[25275]: Anacron started on 2024-02-03 Feb 3 01:01:00 brain anacron[25275]: Normal exit (0 jobs run) Feb 3 02:01:00 brain anacron[7276]: Anacron started on 2024-02-03 Feb 3 02:01:00 brain anacron[7276]: Normal exit (0 jobs run) Feb 3 03:01:00 brain anacron[21364]: Anacron started on 2024-02-03 Feb 3 03:01:00 brain anacron[21364]: Will run job `cron.daily' in 30 min. Feb 3 03:01:00 brain anacron[21364]: Jobs will be executed sequentially Feb 3 03:31:00 brain anacron[21364]: Job `cron.daily' started Feb 3 03:46:08 brain anacron[21364]: Job `cron.daily' terminated (exit status: 1) (produced output) Feb 3 03:46:08 brain anacron[21364]: Normal exit (1 job run) Feb 3 04:02:00 brain CROND[3463]: (root) CMD ([ ! -f /etc/cron.hourly/0anacron ] && run-parts /etc/cron.daily) Feb 3 04:02:00 brain CROND[3462]: (root) CMDEND ([ ! -f /etc/cron.hourly/0anacron ] && run-parts /etc/cron.daily) Feb 4 00:01:00 brain anacron[8246]: Anacron started on 2024-02-04 Feb 4 00:01:00 brain anacron[8246]: Normal exit (0 jobs run) Feb 4 01:01:00 brain anacron[2035]: Anacron started on 2024-02-04 Feb 4 01:01:00 brain anacron[2035]: Normal exit (0 jobs run) Feb 4 02:01:00 brain anacron[20287]: Anacron started on 2024-02-04 Feb 4 02:01:00 brain anacron[20287]: Normal exit (0 jobs run) Feb 4 03:01:00 brain anacron[30311]: Anacron started on 2024-02-04 Feb 4 03:01:00 brain anacron[30311]: Will run job `cron.daily' in 34 min. Feb 4 03:01:00 brain anacron[30311]: Jobs will be executed sequentially Feb 4 03:35:00 brain anacron[30311]: Job `cron.daily' started
I am afraid, that all this issue is maybe due to wrong expectations based on my experience with vixie-cron. If that is the case, my apologies for the noise and I hope I did not lose all reputation for bug-reporting :) https://github.com/cronie-crond/cronie/issues/178#issuecomment-1935950957
Hi Axel, (In reply to Axel Gerber from comment #10) > I am afraid, that all this issue is maybe due to wrong expectations based on > my experience with vixie-cron. does that mean that there was no change in behavior between 1.7.0-r2 and 1.7.1-r1 and that the bug should be closed?
Hi Sebastian, I am not that sure yet. There was a change, because right away cron.monthly got triggered as I expected it.... When you read my last post on github, you see, how much I donno :)
please allow me to hold this issue open until the next expected runs of cron.weekly and cron.monthly. # ls -la /var/spool/anacron insgesamt 12 drwxr-x--- 2 root cron 97 28. Apr 2023 . drwxr-xr-x 9 root root 119 15. Sep 2019 .. -rw------- 1 root root 9 11. Feb 03:57 cron.daily -rw------- 1 root root 9 8. Feb 20:26 cron.monthly -rw------- 1 root root 9 9. Feb 03:51 cron.weekly yet I donno how many days "monthly" mean, but shouldn't be more than 31 I will come back here and ask for closure if all runs fine (I am on 1.7.1-r1 again)
Finally it was as we have been suspicious. Cronie 1.7.1-r1 works fine. I don't really like to call it "wrong expectations" which is how I named it upstream, because the documentation is really not easy to follow, what _should_ happen by when... Anyhow this topic can be closed. I hope I did it right with "status" and the field behind. My apologies for the noise. Detailed reasoning is upstream https://github.com/cronie-crond/cronie/issues/178#issuecomment-1992261206