[OPENDJ-3825] Spring daylight savings change can break recurring tasks Created: 07/Mar/17  Updated: 08/Nov/19  Resolved: 05/May/17

Status: Done
Project: OpenDJ
Component/s: backends, tools
Affects Version/s: 3.5.0, 2.6.2
Fix Version/s: 5.5.0

Type: Bug Priority: Critical
Reporter: Lake Denman [X] (Inactive) Assignee: Chris Ridd
Resolution: Fixed Votes: 0
Labels: Community, Verified, release-notes
Environment:

Rhel 7.2


Attachments: PNG File CET_CEST.png    
Issue Links:
Backport
is backported by OPENDJ-4044 Backport OPENDJ-3825: Spring daylight... Done
is backported by OPENDJ-4043 Backport OPENDJ-3825: Spring daylight... Done
QA Assignee: Viktor Nawrath [X] (Inactive)
Support Ticket IDs:
Backports: OPENDJ-4043 (3.5.3) OPENDJ-4044 (4.0.1)

 Description   

Just last week this backup command was working but recently the flag --recurringTask "00 02 * * 0" is causing an error as shown below (nonexistent calendar date). In addition these flags are also erring in the same way --recurringTask "00 02 * * 1" and --recurringTask "00 02 * * 2".

Strangely, when using --recurringTask "00 02 * * 3" the command executes successfully.

[basopndj@apim-api-manager-user-store-initial ~]$ /opt/opendj/bin/backup --port 4444 --bindDN "cn=Directory Administrator" -j "/opt/opendj/config/pwd/pwd.txt" --backUpAll --backupID fullbackup01 --compress --backupDirectory "/opt/opendj/backup/fullbackup" --recurringTask "00 02 * * 0"
ERROR: An error occurred while trying to decode the response from the server:

The provided recurring task entry attribute ds-recurring-task-schedule holding

the recurring task schedule has invalid tokens combination yielding a

nonexistent calendar date
[basopndj@apim-api-manager-user-store-initial ~]$ /opt/opendj/bin/backup --port 4444 --bindDN "cn=Directory Administrator" -j "/opt/opendj/config/pwd/pwd.txt" --backUpAll --backupID fullbackup01 --compress --backupDirectory "/opt/opendj/backup/fullbackup" --recurringTask "00 02 * * 3"
Recurring Backup task fullbackup01 scheduled successfully


 Comments   
Comment by Tina Roper [ 08/Mar/17 ]

I had the same results here in my test environment in both 2.6.3 and 3.5.0, in both the command line and through the control panel:

$ ./backup --port 4444 --bindDN "cn=Directory Manager" -w password --backUpAll --backupID fullbackup01 --compress -h host3.example.com --backupDirectory /home/tina/forgerock/opendj/bak/fullbackup --recurringTask "0 2 * * 0"
ERROR:  The server rejected the task for the following reason: The provided
recurring task entry attribute ds-recurring-task-schedule holding the
recurring task schedule has invalid tokens combination yielding a nonexistent
calendar date

I rolled back my VM's date to 2/27 and the command works as expected

$ ./backup --port 4444 --bindDN "cn=Directory Manager" -w password --backUpAll --backupID fullbackup01 --compress -h opendj.example.com --backupDirectory /home/tina/forgerock/opendj/bak/fullbackup --recurringTask "0 2 * * 0"
Recurring Backup task fullbackup01 scheduled successfully
Comment by Ludovic Poitou [ 08/Mar/17 ]

Tina,
Since you've reproduced it, can you provide the details on your environment ?
I'm thinking it could be an environment bug since it's related to date and times.

Personally, I could not reproduce on my Mac with version 3.5.0 nor the latest development build (using bare metal, MacOS X 10.12.3, with 2 different JVMs - 1.8.0_91-b14 by Oracle Corporation and 1.8.0_121-b15 by Azul Systems, Inc.). My Timezone is CET (GMT+1).

$ backup --port 4444 --bindDN "cn=Directory manager" -w secret12 --backUpAll --backupID fullbackup01 --compress --backupDirectory "./bak" --recurringTask "00 02 * * 0"
Recurring Backup task fullbackup01 scheduled successfully

$ backup --port 4444 --bindDN "cn=Directory manager" -w secret12 --backUpAll --backupID fullbackup02 --compress --backupDirectory "./bak" --recurringTask "00 02 * * 0"
Recurring Backup task fullbackup02 scheduled successfully
Comment by Tina Roper [ 08/Mar/17 ]

Tested on both 2.6.3 and 3.5.0 DJ builds. This is a CentOS 6.7 VirtualBox. I tried the following JVM settings, 1.7.0_85-mockbuild_2015_07_25_13_10-b00 by Oracle Corporation and 1.8.0_51-b16 by Oracle Corporation. My Timezone is PST. Vanilla install on everything, nothing special in these environments. I'll upgrade the JVM's today and see if a later version resolves the issue.

Comment by Tina Roper [ 08/Mar/17 ]

Customer also reported the following JVM settings:

java version "1.8.0_112"
Java(TM) SE Runtime Environment (build 1.8.0_112-b15)
Java HotSpot(TM) 64-Bit Server VM (build 25.112-b15, mixed mode)

Comment by Tina Roper [ 09/Mar/17 ]

Customer also tried:

java version "1.8.0_121"
Java(TM) SE Runtime Environment (build 1.8.0_121-b13)
Java HotSpot(TM) 64-Bit Server VM (build 25.121-b13, mixed mode)

Comment by Tina Roper [ 27/Apr/17 ]

I looked at this again today. The command worked as expected in my VM. Nothing was changed in this VM. Still OpenDJ 3.5 with 1.8.0_51-b16. I rolled the date back to when I first saw the error, Mar 7. This did produce the expected error we were seeing:

ERROR: The server rejected the task for the following reason: The provided
recurring task entry attribute ds-recurring-task-schedule holding the
recurring task schedule has invalid tokens combination yielding a nonexistent
calendar date

I tried to enable the debug logging for the org.opends.server.backends.task.RecurringTask class but it doesn't seem to have picked up any additional logging after a restart.

Comment by Chris Ridd [ 28/Apr/17 ]

According to https://www.timeanddate.com/time/zone/usa/los-angeles the customer's timezone changed to daylight savings on 12 March 2017 at 2am.

My understanding of daylight savings is that the clock moves ahead in spring at a certain time of the morning by (usually) an hour. So when the clocks in PST change at 2am, the time actually goes effectively from 01:59:59 to 03:00:00, without ever hitting 02:00:00.

The code that's failing is nextTaskDate = RecurringTasks.getNextIteration(calendar) which is working out when the schedule will next "fire".

I set the server's date to 7 March 2017 PST and tried to set a recurringTask of "00 02 * * 0", which means "2am every Sunday".

Using the debugger I can see it failing when it is trying to call calendar.get(DAY_OF_MONTH) when the calendar is at 2am on 12 March 2017. The IllegalArgumentException thrown indicates "2 -> 3", and indeed 2am is when PST changes to 3am PDT. So this is an invalid date.

Calling calendar.setLenient(true) allows getNextIteration(calendar) to return a valid Date, namely Sun Mar 12 03:00:00 PDT 2017.

I think setting lenient to false for this method makes sense and doesn't have any downsides. The worst that can happen is that a task runs an hour later. We then compute the schedule for the next time the task needs to run, so I don't think there's a risk of running the task too many times.

It would be worth also checking what happens when the clocks move back in autumn/fall. Does the task execute once or twice?

Comment by Viktor Nawrath [X] (Inactive) [ 19/Jun/17 ]

Issue is fixed for PST/PDT timezone (it sets the time to 2017031203xx00). However, I've found some inconsistencies in other timezones. 

In GMT/BST daylight savings time shift, the scheduler skips the hour completely, and schedules the next task run to the week after the shift. (2017032601xx00 becomes 2017040201xx00)

In CET/CEST the task gets schedulet to a nonexsiting time (2017032602xx00) without error, and never runs.

 

Comment by Jean-Noël Rouvignac [ 20/Jun/17 ]

> In CET/CEST the task gets schedulet to a nonexsiting time (2017032602xx00) without error, and never runs.

 

Is it never scheduled later like in the case of GMT/BST?

Comment by Viktor Nawrath [X] (Inactive) [ 20/Jun/17 ]

No, the tasks stays scheduled for 2017032602xx00, and stays in the state "Waiting on start time".

Comment by Viktor Nawrath [X] (Inactive) [ 21/Jun/17 ]

Chris Ridd said the inconsistencies are a JVM issue. Can we do anything about it? Should I investigate further, or can I close the issue? What do you think Jean-Noël Rouvignac , Ludovic Poitou ?

Comment by Viktor Nawrath [X] (Inactive) [ 27/Jun/17 ]

Verified for PST timezone.

Inconsistencies found on different timezones, see comments.

Generated at Fri Nov 27 16:30:30 UTC 2020 using Jira 7.13.12#713012-sha1:6e07c38070d5191bbf7353952ed38f111754533a.