Cron sometimes starts two jobs from the same crontab entry

[Terry Barnaby]

I have a simple backup system that starts off a backup once per night 
during the weekdays. There is a crontab file in /etc/cron.d with the 
following entries:

################################################################################
# Beam Bbackup cron setup               Backup to ...
################################################################################
#
# Min Hour Day Month WeekDay

# Perform incremental backup to every work day
01 23 * * 1 root /src/bbackup/bbackup-beam
01 23 * * 2 root /src/bbackup/bbackup-beam
01 23 * * 3 root /src/bbackup/bbackup-beam
01 23 * * 4 root /src/bbackup/bbackup-beam
01 23 * * 5 root /src/bbackup/bbackup-beam

This system has been in use for 10 years or more on various Fedora 
versions. However about 18 months ago I have seen a problem where cron 
will start two backups with identical start times occasionally.

I have had to add a file lock system in the bbackup-beam to cope with this.

Any idea on why cron might start the same job off twice at the same time 
? Could there be a time change issue with chronyd ?

Terry

[Ed Greshko]

On 2020-04-07 14:07, Terry Barnaby wrote:
> I have a simple backup system that starts off a backup once per night during the weekdays. There is a crontab file in /etc/cron.d with the following entries:
>
> ################################################################################
> # Beam Bbackup cron setup               Backup to ...
> ################################################################################
> #
> # Min Hour Day Month WeekDay
>
> # Perform incremental backup to every work day
> 01 23 * * 1 root /src/bbackup/bbackup-beam
> 01 23 * * 2 root /src/bbackup/bbackup-beam
> 01 23 * * 3 root /src/bbackup/bbackup-beam
> 01 23 * * 4 root /src/bbackup/bbackup-beam
> 01 23 * * 5 root /src/bbackup/bbackup-beam
>
> This system has been in use for 10 years or more on various Fedora versions. However about 18 months ago I have seen a problem where cron will start two backups with identical start times occasionally.
>
> I have had to add a file lock system in the bbackup-beam to cope with this.
>
> Any idea on why cron might start the same job off twice at the same time ? Could there be a time change issue with chronyd ?

I don't have an answer to your question.  But wonder if using just

01 23 * * 1-5 root /src/bbackup/bbackup-beam

would help avoid the problem.

I assume the system is up 24/7?

[Terry Barnaby]

On 07/04/2020 08:21, Ed Greshko wrote:
> On 2020-04-07 14:07, Terry Barnaby wrote:
> > I have a simple backup system that starts off a backup once per night during the weekdays. There is a crontab file in /etc/cron.d with the following entries:
> >
> > ################################################################################
> > # Beam Bbackup cron setup               Backup to ...
> > ################################################################################
> > #
> > # Min Hour Day Month WeekDay
> >
> > # Perform incremental backup to every work day
> > 01 23 * * 1 root /src/bbackup/bbackup-beam
> > 01 23 * * 2 root /src/bbackup/bbackup-beam
> > 01 23 * * 3 root /src/bbackup/bbackup-beam
> > 01 23 * * 4 root /src/bbackup/bbackup-beam
> > 01 23 * * 5 root /src/bbackup/bbackup-beam
> >
> > This system has been in use for 10 years or more on various Fedora versions. However about 18 months ago I have seen a problem where cron will start two backups with identical start times occasionally.
> >
> > I have had to add a file lock system in the bbackup-beam to cope with this.
> >
> > Any idea on why cron might start the same job off twice at the same time ? Could there be a time change issue with chronyd ?
>
> I don't have an answer to your question.  But wonder if using just
>
> 01 23 * * 1-5 root /src/bbackup/bbackup-beam
>
> would help avoid the problem.
>
> I assume the system is up 24/7?

Yes, server is up 24/7.

Well I could try that, but I already have a workaround.

The reason for asking is to find out if I am doing something wrong, if 
this is a known "feature" or is a bug in Fedora31. It could be a nasty 
little bug for some.

[Iosif Fettich]

Hi,
> On 2020-04-07 14:07, Terry Barnaby wrote:
> > I have a simple backup system that starts off a backup once per night during the weekdays. There is a crontab file in /etc/cron.d with the following entries:
> >
> > ################################################################################
> > # Beam Bbackup cron setup               Backup to ...
> > ################################################################################
> > #
> > # Min Hour Day Month WeekDay
> >
> > # Perform incremental backup to every work day
> > 01 23 * * 1 root /src/bbackup/bbackup-beam
> > 01 23 * * 2 root /src/bbackup/bbackup-beam
> > 01 23 * * 3 root /src/bbackup/bbackup-beam
> > 01 23 * * 4 root /src/bbackup/bbackup-beam
> > 01 23 * * 5 root /src/bbackup/bbackup-beam
> >
> > This system has been in use for 10 years or more on various Fedora versions. However about 18 months ago I have seen a problem where cron will start two backups with identical start times occasionally.
> >
> > I have had to add a file lock system in the bbackup-beam to cope with this.
> >
> > Any idea on why cron might start the same job off twice at the same time ? Could there be a time change issue with chronyd ?

Are you sure that the jobs you saw started *twice*...?

If one of the jobs would not finish till next launch time, maybe just 
hanging around due to some error, you'll end up with multiple jobs out 
there, despite the fact that they started days apart.

Another possible issue might be the daylight saving time. If you're using 
a non-UTC timezone, there are datetimes that repeat or that are missing. 
23:01 seems not to be among them, but what do I know...

Same thing might happen if there are periodical bigger time adjustements 
(NTP, manual, ...).

If it happens more than once that the system time is 23:01, launching the 
script each time is not only legit, but actually mandatory.

Best regards,

Iosif Fettich

[Terry Barnaby]

On 07/04/2020 09:25, Iosif Fettich wrote:
> Hi,
> > On 2020-04-07 14:07, Terry Barnaby wrote:
> > > I have a simple backup system that starts off a backup once per 
> > > night during the weekdays. There is a crontab file in /etc/cron.d 
> > > with the following entries:
> > >
> > > ################################################################################
> > >
> > > # Beam Bbackup cron setup               Backup to ...
> > > ################################################################################
> > >
> > > #
> > > # Min Hour Day Month WeekDay
> > >
> > > # Perform incremental backup to every work day
> > > 01 23 * * 1 root /src/bbackup/bbackup-beam
> > > 01 23 * * 2 root /src/bbackup/bbackup-beam
> > > 01 23 * * 3 root /src/bbackup/bbackup-beam
> > > 01 23 * * 4 root /src/bbackup/bbackup-beam
> > > 01 23 * * 5 root /src/bbackup/bbackup-beam
> > >
> > > This system has been in use for 10 years or more on various Fedora 
> > > versions. However about 18 months ago I have seen a problem where 
> > > cron will start two backups with identical start times occasionally.
> > >
> > > I have had to add a file lock system in the bbackup-beam to cope 
> > > with this.
> > >
> > > Any idea on why cron might start the same job off twice at the same 
> > > time ? Could there be a time change issue with chronyd ?
>
> Are you sure that the jobs you saw started *twice*...?
>
> If one of the jobs would not finish till next launch time, maybe just 
> hanging around due to some error, you'll end up with multiple jobs out 
> there, despite the fact that they started days apart.
>
> Another possible issue might be the daylight saving time. If you're 
> using a non-UTC timezone, there are datetimes that repeat or that are 
> missing. 23:01 seems not to be among them, but what do I know...
>
> Same thing might happen if there are periodical bigger time 
> adjustements (NTP, manual, ...).
>
> If it happens more than once that the system time is 23:01, launching 
> the script each time is not only legit, but actually mandatory.
>
> Best regards,
>
> Iosif Fettich

I am pretty sure two jobs are started at the same time. The backup 
script. that is run. writes some logging text to a log file with the 
datetime it started. I see two entries with the same datetime and 
without the file lock the backups get messed up due to two operating at 
once. This "fault" has happened about 4 times in the last year.

I have assumed the system time is always UTC synchronised using chronyd. 
The servers user code is running under the GMT timezone. I was wondering 
if the tweaking of the time by chronyd could cause this issue, but I 
would have thought this situation would have been handled by crond if 
this could happen and I have seen this issue about 4 times in a year, so 
it is not a totally sporadic event.

Terry

[Tim]

On Tue, 2020-04-07 at 07:07 +0100, Terry Barnaby wrote:
> I have had to add a file lock system in the bbackup-beam to cope with
> this.

Probably a good thing to do, anyway.

[Samuel Sieb]

On 4/6/20 11:07 PM, Terry Barnaby wrote:
> This system has been in use for 10 years or more on various Fedora 
> versions. However about 18 months ago I have seen a problem where cron 
> will start two backups with identical start times occasionally.
>
> I have had to add a file lock system in the bbackup-beam to cope with this.
>
> Any idea on why cron might start the same job off twice at the same time 
> ? Could there be a time change issue with chronyd ?

Have you checked the logs to see when the jobs were started and if there 
are any relevant messages?

[Terry Barnaby]

On 07/04/2020 09:03, Samuel Sieb wrote:
> On 4/6/20 11:07 PM, Terry Barnaby wrote:
> > This system has been in use for 10 years or more on various Fedora 
> > versions. However about 18 months ago I have seen a problem where 
> > cron will start two backups with identical start times occasionally.
> >
> > I have had to add a file lock system in the bbackup-beam to cope with 
> > this.
> >
> > Any idea on why cron might start the same job off twice at the same 
> > time ? Could there be a time change issue with chronyd ?
>
> Have you checked the logs to see when the jobs were started and if 
> there are any relevant messages?
> _______________________________________________

Yes, there is nothing unusual in /var/log/cron:

Apr  6 22:01:01 beam CROND[651585]: (root) CMD (run-parts /etc/cron.hourly)
Apr  6 22:01:01 beam run-parts[651585]: (/etc/cron.hourly) starting 0anacron
Apr  6 22:01:01 beam run-parts[651585]: (/etc/cron.hourly) finished 0anacron
Apr  6 23:01:01 beam CROND[652722]: (root) CMD (/src/bbackup/bbackup-beam)
Apr  6 23:01:01 beam CROND[652721]: (root) CMD (run-parts /etc/cron.hourly)
Apr  6 23:01:01 beam run-parts[652721]: (/etc/cron.hourly) starting 0anacron
Apr  6 23:01:01 beam CROND[652720]: (root) CMDOUT (Waking up 
70:85:c2:0f:68:07...)
Apr  6 23:01:01 beam run-parts[652721]: (/etc/cron.hourly) finished 0anacron
Apr  6 23:01:21 beam CROND[652720]: (root) CMDOUT (Starting Backup)

I do note that /etc/cron.hourly is performed at a minute past the hour 
as well though ...

/var/log/messages

Feb 24 23:00:03 beam dhcpd[1743]: DHCPREQUEST for 192.168.201.214 from 
00:25:b3:e6:a9:18 via enp4s0
Feb 24 23:00:03 beam dhcpd[1743]: DHCPACK on 192.168.201.214 to 
00:25:b3:e6:a9:18 via enp4s0
Feb 24 23:00:05 beam systemd[1]: Starting system activity accounting tool...
Feb 24 23:00:05 beam systemd[1]: sysstat-collect.service: Succeeded.
Feb 24 23:00:05 beam systemd[1]: Started system activity accounting tool.
Feb 24 23:00:05 beam audit[1]: SERVICE_START pid=1 uid=0 auid=4294967295 
ses=4294967295 msg='unit=sysstat-collect comm="systemd" 
exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
Feb 24 23:00:05 beam audit[1]: SERVICE_STOP pid=1 uid=0 auid=4294967295 
ses=4294967295 msg='unit=sysstat-collect comm="systemd" 
exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
Feb 24 23:00:41 beam dhcpd[1743]: DHCPREQUEST for 192.168.201.241 from 
70:85:c2:0f:68:07 via enp4s0
Feb 24 23:00:41 beam dhcpd[1743]: DHCPACK on 192.168.201.241 to 
70:85:c2:0f:68:07 via enp4s0
Feb 24 23:00:59 beam dhcpd[1743]: DHCPREQUEST for 192.168.201.26 from 
84:1b:5e:70:2a:c9 via enp4s0
Feb 24 23:00:59 beam dhcpd[1743]: DHCPACK on 192.168.201.26 to 
84:1b:5e:70:2a:c9 via enp4s0
Feb 24 23:01:01 beam dhcpd[1743]: DHCPREQUEST for 192.168.201.250 from 
4c:60:de:e4:29:2d via enp4s0
Feb 24 23:01:01 beam dhcpd[1743]: DHCPACK on 192.168.201.250 to 
4c:60:de:e4:29:2d via enp4s0
Feb 24 23:01:20 beam dhcpd[1743]: DHCPREQUEST for 192.168.201.28 from 
00:50:c2:e2:f0:db via enp4s0
Feb 24 23:01:20 beam dhcpd[1743]: DHCPACK on 192.168.201.28 to 
00:50:c2:e2:f0:db via enp4s0
Feb 24 23:01:32 beam dhcpd[1743]: DHCPREQUEST for 192.168.201.8 from 
00:d8:61:a0:a4:06 via enp4s0
Feb 24 23:01:32 beam dhcpd[1743]: DHCPACK on 192.168.201.8 to 
00:d8:61:a0:a4:06 via enp4s0
Feb 24 23:02:21 beam dhcpd[1743]: DHCPREQUEST for 192.168.201.214 from 
00:25:b3:e6:a9:18 via enp4s0
Feb 24 23:02:21 beam dhcpd[1743]: DHCPACK on 192.168.201.214 to 
00:25:b3:e6:a9:18 via enp4s0
Feb 24 23:03:10 beam dhcpd[1743]: DHCPREQUEST for 192.168.201.241 from 
70:85:c2:0f:68:07 via enp4s0

In the backup log:

Bbackup / /usr/beam /home /src /srcOld /dist /opt /scratch /data/svn 
/data/www /data/vwt /data/www /data1/kvm /data/database /data/vwt 
/data/backup at Mon  6 Apr 23:01:01 BST 2020
Bbackup / /usr/beam /home /src /srcOld /dist /opt /scratch /data/svn 
/data/www /data/vwt /data/www /data1/kvm /data/database /data/vwt 
/data/backup at Mon  6 Apr 23:01:01 BST 2020
Backup aborted as locked by another backup
Bbackup completed status: 0 at Tue  7 Apr 11:12:00 BST 2020

The bbackup-beam shell script is pretty basic and I can't see how this 
could have an issue like this.

The same system has been running since 2009 without any issues. This 
problem started happening around Fedora27 or perhaps Fedora29 I think.

Terry

[Iosif Fettich]

Hi Terry,
> The bbackup-beam shell script is pretty basic and I can't see how this could 
> have an issue like this.

Googling on similar issues finds some hits where the cause were two 
running cron daemons, e.g. 
https://stackoverflow.com/questions/1004764/why-is-this-cron-entry-executed-...

I tend to believe it's not the cron entry by itself, but something n the 
environment.

I'm curious what you'll find.

Best rergards,

Iosif

[Iosif Fettich]

Hi Terry,
> Yes, there is nothing unusual in /var/log/cron:
>
> Apr  6 22:01:01 beam CROND[651585]: (root) CMD (run-parts /etc/cron.hourly)

[...]
> /var/log/messages
>
> Feb 24 23:00:03 beam dhcpd[1743]: DHCPREQUEST for 192.168.201.214 from 00:25:b3:e6:a9:18 via enp4s0

[...]
> In the backup log:
>
> Bbackup / /usr/beam /home /src /srcOld /dist /opt /scratch /data/svn /data/www /data/vwt /data/www /data1/kvm /data/database /data/vwt /data/backup at Mon  6 Apr 23:01:01 BST 2020

[...]

Maybe irrelevant, but just mentioning: the log extract from 
/var/log/messages is dated Feb 24, whereas the other two are dated Apr  6.

Best regards,

Iosif

[Terry Barnaby]

On 07/04/2020 13:06, Iosif Fettich wrote:
> Hi Terry,
> > Yes, there is nothing unusual in /var/log/cron:
> >
> > Apr  6 22:01:01 beam CROND[651585]: (root) CMD (run-parts 
> > /etc/cron.hourly)
>
> [...]
> > /var/log/messages
> >
> > Feb 24 23:00:03 beam dhcpd[1743]: DHCPREQUEST for 192.168.201.214 
> > from 00:25:b3:e6:a9:18 via enp4s0
>
> [...]
> > In the backup log:
> >
> > Bbackup / /usr/beam /home /src /srcOld /dist /opt /scratch /data/svn 
> > /data/www /data/vwt /data/www /data1/kvm /data/database /data/vwt 
> > /data/backup at Mon  6 Apr 23:01:01 BST 2020
>
> [...]
>
> Maybe irrelevant, but just mentioning: the log extract from 
> /var/log/messages is dated Feb 24, whereas the other two are dated 
> Apr  6.
>
> Best regards,
>
> Iosif

Yes, missed that. I searched back for 23:01:00 and missed the fact that 
it was the wrong month. There was even less of interest in 
/var/log/messages around Apr  6 23:01:00, just some DHCP requests.

Terry

[Samuel Sieb]

On 4/7/20 3:21 AM, Terry Barnaby wrote:
> On 07/04/2020 09:03, Samuel Sieb wrote:
> > On 4/6/20 11:07 PM, Terry Barnaby wrote:
> > > This system has been in use for 10 years or more on various Fedora 
> > > versions. However about 18 months ago I have seen a problem where 
> > > cron will start two backups with identical start times occasionally.
> > >
> > > I have had to add a file lock system in the bbackup-beam to cope with 
> > > this.
> > >
> > > Any idea on why cron might start the same job off twice at the same 
> > > time ? Could there be a time change issue with chronyd ?
> >
> > Have you checked the logs to see when the jobs were started and if 
> > there are any relevant messages?
> > _______________________________________________
>
> Yes, there is nothing unusual in /var/log/cron:
>
> /var/log/messages

Are you not using the journal?

[Cameron Simpson]

On 07Apr2020 07:07, Terry Barnaby  wrote:
> 01 23 * * 1 root /src/bbackup/bbackup-beam

[...]

1:23am. Do not the timezone shifts happen at 2am (avoids horrible day 
changes if it happened at 12am). So 1:23am can happen twice if 2am steps 
back to 1am.

Our summer time just ended here. Might a similar shift have happened for 
you?

Cheers,
Cameron Simpson

[Ed Greshko]

On 2020-04-08 07:27, Cameron Simpson wrote:
> On 07Apr2020 07:07, Terry Barnaby  wrote:
> > 01 23 * * 1 root /src/bbackup/bbackup-beam
>
> [...]
>
> 1:23am. Do not the timezone shifts happen at 2am (avoids horrible day changes if it happened at 12am). So 1:23am can happen twice if 2am steps back to 1am.
>
> Our summer time just ended here. Might a similar shift have happened for you?

Well, except that the format of the crontab is....

Minute  Hour Day-of-Month .....

:-)

[Patrick O'Callaghan]

On Wed, 2020-04-08 at 07:52 +0800, Ed Greshko wrote:
> On 2020-04-08 07:27, Cameron Simpson wrote:
> > On 07Apr2020 07:07, Terry Barnaby  wrote:
> > > 01 23 * * 1 root /src/bbackup/bbackup-beam
> >
> > [...]
> >
> > 1:23am. Do not the timezone shifts happen at 2am (avoids horrible day changes if it happened at 12am). So 1:23am can happen twice if 2am steps back to 1am.
> >
> > Our summer time just ended here. Might a similar shift have happened for you?
>
> Well, except that the format of the crontab is....
>
> Minute  Hour Day-of-Month .....

How does that avoid the problem? The same time can still happen twice.

poc

[Ed Greshko]

On 2020-04-08 16:56, Patrick O'Callaghan wrote:
> On Wed, 2020-04-08 at 07:52 +0800, Ed Greshko wrote:
> > On 2020-04-08 07:27, Cameron Simpson wrote:
> > > On 07Apr2020 07:07, Terry Barnaby  wrote:
> > > > 01 23 * * 1 root /src/bbackup/bbackup-beam
> > >
> > > [...]
> > >
> > > 1:23am. Do not the timezone shifts happen at 2am (avoids horrible day changes if it happened at 12am). So 1:23am can happen twice if 2am steps back to 1am.
> > >
> > > Our summer time just ended here. Might a similar shift have happened for you?
> >
> > Well, except that the format of the crontab is....
> >
> > Minute  Hour Day-of-Month .....
>
> How does that avoid the problem? The same time can still happen twice.

????

How can 23:01 happen twice at the switch to/from DST?

[Andy Paterson]

I understood crontab used UTC time - daylight saving shouldn't apply
> On 8 Apr 2020, at 10:07, Ed Greshko  wrote:
>
> On 2020-04-08 16:56, Patrick O'Callaghan wrote:
> > > On Wed, 2020-04-08 at 07:52 +0800, Ed Greshko wrote:
> > > On 2020-04-08 07:27, Cameron Simpson wrote:
> > > > On 07Apr2020 07:07, Terry Barnaby  wrote:
> > > > > 01 23 * * 1 root /src/bbackup/bbackup-beam
> > > >
> > > > [...]
> > > >
> > > > 1:23am. Do not the timezone shifts happen at 2am (avoids horrible day changes if it happened at 12am). So 1:23am can happen twice if 2am steps back to 1am.
> > > >
> > > > Our summer time just ended here. Might a similar shift have happened for you?
> > >
> > > Well, except that the format of the crontab is....
> > >
> > > Minute  Hour Day-of-Month .....
> >
> > How does that avoid the problem? The same time can still happen twice.
>
> ????
>
> How can 23:01 happen twice at the switch to/from DST?
>
> -- 
> The key to getting good answers is to ask good questions.
> _______________________________________________
> users mailing list -- [e-mail]
> To unsubscribe send an email to [e-mail]
> Fedora Code of Conduct: https://docs.fedoraproject.org/en-US/project/code-of-conduct/
> List Guidelines: https://fedoraproject.org/wiki/Mailing_list_guidelines
> List Archives: https://lists.fedoraproject.org/archives/list/[e-mail]

[Ed Greshko]

On 2020-04-08 20:01, Andy Paterson via users wrote:
> I understood crontab used UTC time - daylight saving shouldn't apply

Not unless you set the CRON_TZ variable.

Also, if that were the case then the man page wouldn't need to tell you....

Daylight Saving Time and other time changes
       Local time changes of less than three hours, such as those caused by the
       Daylight Saving Time changes, are handled in a special way.   This  only
       applies  to  jobs  that  run at a specific time and jobs that run with a
       granularity greater than one hour.  Jobs that run  more  frequently  are
       scheduled normally.

If time was adjusted one hour forward, those jobs that would have run in
       the interval that has been skipped will be run immediately.  Conversely,
       if time was adjusted backward, running the same job twice is avoided.

Time  changes  of  more than 3 hours are considered to be corrections to
       the clock or the timezone, and the new time is used immediately.

It is  possible  to  use  different  time  zones  for  crontables.   See
       crontab(5) for more information.

[Patrick O'Callaghan]

On Wed, 2020-04-08 at 20:11 +0800, Ed Greshko wrote:
>    If time was adjusted one hour forward, those jobs that would have run in
>    the interval that has been skipped will be run immediately.  Conversely,
>    if time was adjusted backward, running the same job twice is avoided.

Good point.

poc

[Patrick O'Callaghan]

On Wed, 2020-04-08 at 17:06 +0800, Ed Greshko wrote:
> On 2020-04-08 16:56, Patrick O'Callaghan wrote:
> > On Wed, 2020-04-08 at 07:52 +0800, Ed Greshko wrote:
> > > On 2020-04-08 07:27, Cameron Simpson wrote:
> > > > On 07Apr2020 07:07, Terry Barnaby  wrote:
> > > > > 01 23 * * 1 root /src/bbackup/bbackup-beam
> > > >
> > > > [...]
> > > >
> > > > 1:23am. Do not the timezone shifts happen at 2am (avoids horrible day changes if it happened at 12am). So 1:23am can happen twice if 2am steps back to 1am.
> > > >
> > > > Our summer time just ended here. Might a similar shift have happened for you?
> > >
> > > Well, except that the format of the crontab is....
> > >
> > > Minute  Hour Day-of-Month .....
> >
> > How does that avoid the problem? The same time can still happen twice.
>
> ????
>
> How can 23:01 happen twice at the switch to/from DST?

It can happen when switching from summer time (i.e. "fall back"),
though not on switching to summer time ("spring forward"), which of
course is the OP's case.

I don't know how it works where you live, but in the UK the autumn
switch occurs at 2am, which reverts back to being 1am. Thus a time such
as 1:30am occurs twice, and events programmed for that time can be
triggered twice.

poc

[Ed Greshko]

On 2020-04-08 20:21, Patrick O'Callaghan wrote:
> On Wed, 2020-04-08 at 17:06 +0800, Ed Greshko wrote:
> > On 2020-04-08 16:56, Patrick O'Callaghan wrote:
> > > On Wed, 2020-04-08 at 07:52 +0800, Ed Greshko wrote:
> > > > On 2020-04-08 07:27, Cameron Simpson wrote:
> > > > > On 07Apr2020 07:07, Terry Barnaby  wrote:
> > > > > > 01 23 * * 1 root /src/bbackup/bbackup-beam
> > > > >
> > > > > [...]
> > > > >
> > > > > 1:23am. Do not the timezone shifts happen at 2am (avoids horrible day changes if it happened at 12am). So 1:23am can happen twice if 2am steps back to 1am.
> > > > >
> > > > > Our summer time just ended here. Might a similar shift have happened for you?
> > > >
> > > > Well, except that the format of the crontab is....
> > > >
> > > > Minute  Hour Day-of-Month .....
> > >
> > > How does that avoid the problem? The same time can still happen twice.
> >
> > ????
> >
> > How can 23:01 happen twice at the switch to/from DST?
>
> It can happen when switching from summer time (i.e. "fall back"),
> though not on switching to summer time ("spring forward"), which of
> course is the OP's case.
>
> I don't know how it works where you live, but in the UK the autumn
> switch occurs at 2am, which reverts back to being 1am. Thus a time such
> as 1:30am occurs twice, and events programmed for that time can be
> triggered twice.

BUT, we are specifically addressing the OP's situation and the time in his crontab ISN'T within the
time frame of when BST (the OP is in the UK) starts/ends.

Daylight saving time 2020 in United Kingdom began at 1:00 AM on
Sunday, March 29
and ends at 2:00 AM on
Sunday, October 25
All times are in United Kingdom Time.

Not near 23:01 which is the OP's cron start time.

[Patrick O'Callaghan]

On Wed, 2020-04-08 at 20:28 +0800, Ed Greshko wrote:
> > I don't know how it works where you live, but in the UK the autumn
> > switch occurs at 2am, which reverts back to being 1am. Thus a time such
> > as 1:30am occurs twice, and events programmed for that time can be
> > triggered twice.
>
> BUT, we are specifically addressing the OP's situation and the time in his crontab ISN'T within the
> time frame of when BST (the OP is in the UK) starts/ends.

Yes, that's clear. I was simply answering the general question (since
you said "to/from DST"), even though it doesn't apparently affect cron
as such, as documented in the manual.

poc

[Terry Barnaby]

On 08/04/2020 14:37, Patrick O'Callaghan wrote:
> On Wed, 2020-04-08 at 20:28 +0800, Ed Greshko wrote:
> > > I don't know how it works where you live, but in the UK the autumn
> > > switch occurs at 2am, which reverts back to being 1am. Thus a time such
> > > as 1:30am occurs twice, and events programmed for that time can be
> > > triggered twice.
> >
> > BUT, we are specifically addressing the OP's situation and the time in his crontab ISN'T within the
> > time frame of when BST (the OP is in the UK) starts/ends.
>
> Yes, that's clear. I was simply answering the general question (since
> you said "to/from DST"), even though it doesn't apparently affect cron
> as such, as documented in the manual.
>
> poc
> _______________________________________________

Note this has happened a few times this year, (approx 1 in 64 x) so not 
related to DST changes anyway. Might be due to chrony clock resyncs I 
suppose but I think something stranger is going on here or something 
silly and obvious in what I am doing.

I will have a more detailed look at the system and my backup shell 
script and create a simple test cron job to see if it shows the same 
thing ...

Terry

[Cameron Simpson]

On 08Apr2020 14:54, Terry Barnaby  wrote:
> Note this has happened a few times this year, (approx 1 in 64 x) so not 
> related to DST changes anyway. Might be due to chrony clock resyncs I 
> suppose but I think something stranger is going on here or something 
> silly and obvious in what I am doing.
>
> I will have a more detailed look at the system and my backup shell 
> script and create a simple test cron job to see if it shows the same 
> thing ...

How about sticking:

echo "`date` [`date -u`]: start $0 $*" >>some_log_file

at the start. Makes sure the job is actually starting at the cron time.  
Might tell you more about the system time situation.

Cheers,
Cameron Simpson

[Terry Barnaby]

On 08/04/2020 23:11, Cameron Simpson wrote:
> On 08Apr2020 14:54, Terry Barnaby  wrote:
> > Note this has happened a few times this year, (approx 1 in 64 x) so 
> > not related to DST changes anyway. Might be due to chrony clock 
> > resyncs I suppose but I think something stranger is going on here or 
> > something silly and obvious in what I am doing.
> >
> > I will have a more detailed look at the system and my backup shell 
> > script and create a simple test cron job to see if it shows the same 
> > thing ...
>
> How about sticking:
>
> echo "`date` [`date -u`]: start $0 $*" >>some_log_file
>
> at the start. Makes sure the job is actually starting at the cron 
> time.  Might tell you more about the system time situation.
>
> Cheers,
> Cameron Simpson 
> _______________________________________________

The script already has date/time and the log shows (The Wed 8th entries 
entry having the PID):

Bbackup / /usr/beam /home /src /srcOld /dist /opt /scratch /data/svn 
/data/www /data/vwt /data/www /data1/kvm /data/database /data/vwt 
/data/backup at Tue  7 Apr 23:01:01 BST 2020
Bbackup / /usr/beam /home /src /srcOld /dist /opt /scratch /data/svn 
/data/www /data/vwt /data/www /data1/kvm /data/database /data/vwt 
/data/backup at Tue  7 Apr 23:01:01 BST 2020
Backup aborted as locked by another backup
Bbackup completed status: 0 at Wed  8 Apr 00:58:57 BST 2020
Bbackup 805476 / /usr/beam /home /src /srcOld /dist /opt /scratch 
/data/svn /data/www /data/vwt /data/www /data1/kvm /data/database 
/data/vwt /data/backup at Wed  8 Apr 23:01:01 BST 2020
Bbackup 27200 / /usr/beam /home /src /srcOld /dist /opt /scratch 
/data/svn /data/www /data/vwt /data/www /data1/kvm /data/database 
/data/vwt /data/backup at Wed  8 Apr 23:01:01 BST 2020
Backup aborted as locked by another backup
Bbackup completed status: 0 at Thu  9 Apr 01:29:24 BST 2020

I will change it to show down to the us.

Terry

[Ed Greshko]

On 2020-04-09 17:57, Terry Barnaby wrote:
> The script already has date/time and the log shows (The Wed 8th entries entry having the PID):
>
> Bbackup / /usr/beam /home /src /srcOld /dist /opt /scratch /data/svn /data/www /data/vwt /data/www /data1/kvm /data/database /data/vwt /data/backup at Tue  7 Apr 23:01:01 BST 2020
> Bbackup / /usr/beam /home /src /srcOld /dist /opt /scratch /data/svn /data/www /data/vwt /data/www /data1/kvm /data/database /data/vwt /data/backup at Tue  7 Apr 23:01:01 BST 2020
> Backup aborted as locked by another backup

Just wondering, if you look at the journal output for that date and time do you see it being started twice?

For example, I have 2 jobs that start at 19:00 each day and for each time they are started I'd see...

Apr 09 19:00:01 meimei.greshko.com CROND[76409]: (egreshko) CMD (/home/egreshko/bin/getpics-vis)
Apr 09 19:00:01 meimei.greshko.com CROND[76411]: (egreshko) CMD (/home/egreshko/bin/getpics-vis2)

Are you getting 2 starts of the same script recorded?

[Terry Barnaby]

On 09/04/2020 12:24, Ed Greshko wrote:
> On 2020-04-09 17:57, Terry Barnaby wrote:
> > The script already has date/time and the log shows (The Wed 8th entries entry having the PID):
> >
> > Bbackup / /usr/beam /home /src /srcOld /dist /opt /scratch /data/svn /data/www /data/vwt /data/www /data1/kvm /data/database /data/vwt /data/backup at Tue  7 Apr 23:01:01 BST 2020
> > Bbackup / /usr/beam /home /src /srcOld /dist /opt /scratch /data/svn /data/www /data/vwt /data/www /data1/kvm /data/database /data/vwt /data/backup at Tue  7 Apr 23:01:01 BST 2020
> > Backup aborted as locked by another backup
>
> Just wondering, if you look at the journal output for that date and time do you see it being started twice?
>
> For example, I have 2 jobs that start at 19:00 each day and for each time they are started I'd see...
>
> Apr 09 19:00:01 meimei.greshko.com CROND[76409]: (egreshko) CMD (/home/egreshko/bin/getpics-vis)
> Apr 09 19:00:01 meimei.greshko.com CROND[76411]: (egreshko) CMD (/home/egreshko/bin/getpics-vis2)
>
> Are you getting 2 starts of the same script recorded?

No, the cron log in /var/log/cron only shows one for the backup log below:

Bbackup 805476 / /usr/beam /home /src /srcOld /dist /opt /scratch 
/data/svn /data/www /data/vwt /data/www /data1/kvm /data/database 
/data/vwt /data/backup at Wed  8 Apr 23:01:01 BST 2020
Bbackup 27200 / /usr/beam /home /src /srcOld /dist /opt /scratch 
/data/svn /data/www /data/vwt /data/www /data1/kvm /data/database 
/data/vwt /data/backup at Wed  8 Apr 23:01:01 BST 2020
Backup aborted as locked by another backup
Bbackup completed status: 0 at Thu  9 Apr 01:29:24 BST 2020

#/var/log/cron

Apr  8 22:01:01 beam CROND[804585]: (root) CMD (/src/bbackup/bbackup-test1)
Apr  8 22:01:01 beam CROND[804586]: (root) CMD (run-parts /etc/cron.hourly)
Apr  8 22:01:01 beam CROND[804583]: (root) CMDOUT (Starting Bbackup-test1)
Apr  8 22:01:01 beam run-parts[804586]: (/etc/cron.hourly) starting 0anacron
Apr  8 22:01:01 beam run-parts[804586]: (/etc/cron.hourly) finished 0anacron
Apr  8 23:01:01 beam CROND[805474]: (root) CMD (/src/bbackup/bbackup-test1)
Apr  8 23:01:01 beam CROND[805475]: (root) CMD (run-parts /etc/cron.hourly)
Apr  8 23:01:01 beam CROND[805476]: (root) CMD (/src/bbackup/bbackup-beam)
Apr  8 23:01:01 beam CROND[805471]: (root) CMDOUT (Starting Bbackup-test1)
Apr  8 23:01:01 beam run-parts[805475]: (/etc/cron.hourly) starting 0anacron
Apr  8 23:01:01 beam CROND[805473]: (root) CMDOUT (Waking up 
70:85:c2:0f:68:07...)
Apr  8 23:01:01 beam run-parts[805475]: (/etc/cron.hourly) finished 0anacron
Apr  8 23:01:21 beam CROND[805473]: (root) CMDOUT (Starting Backup)
Apr  9 00:01:01 beam CROND[806518]: (root) CMD (run-parts /etc/cron.hourly)
Apr  9 00:01:01 beam CROND[806519]: (root) CMD (/src/bbackup/bbackup-test1)

Strange low PID for second bbackup-beam script run ...

Ahggh found it! There was a VM running on our network of an older 
development Fedora platform based on an image of our old server and it 
still had its backup system running as the cron table entry was still there!

Sorry for all the noise.

[Ed Greshko]

On 2020-04-08 21:37, Patrick O'Callaghan wrote:
> On Wed, 2020-04-08 at 20:28 +0800, Ed Greshko wrote:
> > > I don't know how it works where you live, but in the UK the autumn
> > > switch occurs at 2am, which reverts back to being 1am. Thus a time such
> > > as 1:30am occurs twice, and events programmed for that time can be
> > > triggered twice.
> >
> > BUT, we are specifically addressing the OP's situation and the time in his crontab ISN'T within the
> > time frame of when BST (the OP is in the UK) starts/ends.
>
> Yes, that's clear. I was simply answering the general question (since
> you said "to/from DST"), even though it doesn't apparently affect cron
> as such, as documented in the manual.

OK then.

[Joe Zeff]

On 04/08/2020 06:21 AM, Patrick O'Callaghan wrote:
> I don't know how it works where you live, but in the UK the autumn
> switch occurs at 2am, which reverts back to being 1am. Thus a time such
> as 1:30am occurs twice, and events programmed for that time can be
> triggered twice.

It's the same in the US.  A few years ago, this allowed a three hour 
performance of Rocky Horror to fit into a two hour time slot.

[Cameron Simpson]

On 08Apr2020 07:52, Ed Greshko  wrote:
> On 2020-04-08 07:27, Cameron Simpson wrote:
> > On 07Apr2020 07:07, Terry Barnaby  wrote:
> > > 01 23 * * 1 root /src/bbackup/bbackup-beam
> >
> > [...]
> >
> > 1:23am. Do not the timezone shifts happen at 2am (avoids horrible day changes if it happened at 12am). So 1:23am can happen twice if 2am steps back to 1am.
> >
> > Our summer time just ended here. Might a similar shift have happened for you?
>
> Well, except that the format of the crontab is....
>
> Minute  Hour Day-of-Month .....
>
> :-)

Um, indeed, as you say. I thought about that after my post, too late.

Cheers,
Cameron Simpson

Hi

On Tue, 07 Apr 2020 07:07:36 +0100 Terry Barnaby wrote:
> # Min Hour Day Month WeekDay
> # Perform incremental backup to every work day
> 01 23 * * 1 root /src/bbackup/bbackup-beam
> 01 23 * * 2 root /src/bbackup/bbackup-beam
> 01 23 * * 3 root /src/bbackup/bbackup-beam
> 01 23 * * 4 root /src/bbackup/bbackup-beam
> 01 23 * * 5 root /src/bbackup/bbackup-beam
> This system has been in use for 10 years or more on various Fedora 
> versions. However about 18 months ago I have seen a problem where cron 
> will start two backups with identical start times occasionally.

I have seen that also a few time, but years ago.
> I have had to add a file lock system in the bbackup-beam to cope with this.

I did the same, also for frequent cron jobs that may be stuck for a
too long time, for example if a network outage occurs.

Then (years later) an alternative to cron appeared: systemd.timer.

Pros:
   - Gratuitous execution locking
     "systemctl start X" is a noop if X runs.

- Ease log management
     By default in the system log.
     No more need to redirect stdout and stderr to /dev/null as seen
     in so many crontabs

- Ease tracking processes
     With "systemctl status" "systemctl stop" ...

Cons:
   - It's systemd-ish :-)

I can show you how to convert your crontab to systemd.{service,timer}
if you want.

[Terry Barnaby]

On 09/04/2020 07:00, [e-mail] wrote:
> Hi
>
> On Tue, 07 Apr 2020 07:07:36 +0100 Terry Barnaby wrote:
> > # Min Hour Day Month WeekDay
> > # Perform incremental backup to every work day
> > 01 23 * * 1 root /src/bbackup/bbackup-beam
> > 01 23 * * 2 root /src/bbackup/bbackup-beam
> > 01 23 * * 3 root /src/bbackup/bbackup-beam
> > 01 23 * * 4 root /src/bbackup/bbackup-beam
> > 01 23 * * 5 root /src/bbackup/bbackup-beam
> > This system has been in use for 10 years or more on various Fedora
> > versions. However about 18 months ago I have seen a problem where cron
> > will start two backups with identical start times occasionally.
>
> I have seen that also a few time, but years ago.
> > I have had to add a file lock system in the bbackup-beam to cope with this.
>
> I did the same, also for frequent cron jobs that may be stuck for a
> too long time, for example if a network outage occurs.
>
> Then (years later) an alternative to cron appeared: systemd.timer.
>
> Pros:
>     - Gratuitous execution locking
>       "systemctl start X" is a noop if X runs.
> - Ease log management
>   By default in the system log.
>   No more need to redirect stdout and stderr to /dev/null as seen
>   in so many crontabs
>
> - Ease tracking processes
>   With "systemctl status" "systemctl stop" ...
>
> Cons:
>     - It's systemd-ish :-)
>
> I can show you how to convert your crontab to systemd.{service,timer}
> if you want.

Many thanks. I do use systemd for some things, especially daemon 
management, but this is an old (was reliable) system and it is also used 
on some much older systems. The cron config is very simple, 
understandable and its configuration files are not lost in systemd's 
noise. I think I will keep with cron (while it is still available!) for 
now. As stated it is functions with the lock, I was just feeding back 
the issue in-case there is actually a problem in the system here.