Scheduling bug, UTC time clock bug?

1

There is something wrong with scheduling backups for only once a day.
It is currently 6 pm PST on Wed and I am trying to schedule backups to run every Wed at 23:00 PST with a start date of today. Duplicati refuses to do this and switches to Tuesday instead a week from now.

Or I want to run a backup tomorrow at 16:00 PST on Thu => this works fine (at least the scheduling part; whether it actually runs at this time I do not know)
If I switch to tomorrow 17:00 PST on Thu => the next run will be a week from now on Wed.

I suspect there is a misconfiguration between the displayed time and an internal UTC time clock.

I also suspect there is also something wrong with the day selection. For instance if I select “backup everyday and pick a time 5 min from now”, Duplicati schedules this fine and runs fine. If I deselect all days except today, then Duplicati schedules it for 6 days later (not 7 days) next week.

I am using 2.0.3.3_beta_2018-04-02

2

Are you seeing this in all these places or just some:

  • “Next time” field of job edit step 4 (Schedule)
  • “Next scheduled run” on the “home” screen job summary
  • “ProposedSchedule” on “About” → “System info” (scroll down to Server state properties)

Did you leave this “in play” and did it actually back up?

3

Clearly a bug. So to clarify I am on PST. It is Friday May 18, around 2:30 pm

I have three backups scheduled.

The main window at top shows:
Next scheduled task: Backup1 Tomorrow at 3:00 AM

The Home screen shows:
Backup1 Next scheduled run: Tomorrow at 3:00 AM
Backup2 Next scheduled run: Wednesday at 5:05 PM
Backup3 Next scheduled run: Thursday at 6:48 PM

Configuration settings for:
Backup1 - Sat 03:00
Backup2 - Thu 17:05
Backup3 - Fri 18:48

System properties:
ServerTime : 2018-05-18T14:25:17.344258-07:00

Server state properties show:
proposedSchedule: [{“Item1":“4”,“Item2”:“2018-05-19T10:00:00Z”},{“Item1”:“7”,“Item2”:"2018-05-24T00:05:00Z”}], {“Item1”:“8”,“Item2”:“2018-05-25T01:48:00Z”},

So, as you can see the server state properties schedule is shifted by 7 hours into the future from what is selected under Configuration screen. This is most likely because of the UTC-7:00 server time. But, here is the bug, the date is not shifted for the two backups that are within 7 hours of midnight.

Home screen days (but not times) are shifted back by one day from Configuration settings for all backup times that are within 7 hours from midnight. Probably Home screen is using server state properties as the base for date and time.

If I schedule a backup 5 mins from now it does indeed run 5 mins from now.

So I think Duplicati handles the backup time correct. However, Duplicati is displaying the wrong day for all backups that are scheduled within the UTC shift period to the next day. This must caused by a bug in the server state properties date/time.
When I schedule a backup for Fri 18:48 the UTC date/time should shift to 2018-05-26T01:48:00 and the next scheduled run should show as Friday at 6:48 PM.

4

Great summary of the issue, thanks!

I’m not within my UTC-6 shift yet so will try to replicate your scenario and get back to you.

Please correct me if this is wrong, but here’s what I’m going to try:

  1. now (outside of UTC-6 shift) schedule a weekly job to start tomorrow at 01:11 AM. This results an expected System Info content of proposedSchedule : [{"Item1":"4","Item2":"2018-05-23T06:11:00Z"}]

  2. later (inside of UTC-6 shift) adjust weekly schedule to start tomorrow at 01:12 AM at which point I EXPECT to see an incorrectly dated proposedSchedule : [{"Item1":"4","Item2":"2018-05-****30****T06:12:00Z"}].

5

You don’t need to wait to be within the UTC-6 shift to see the date bug. Just the schedule needs to be within the time frame.

  1. Schedule your weekly job for Wed as proposed. You should see [{“Item1”:“4”,“Item2”:“2018-05-23T07:11:00Z”}]. The time shifts by 6 hours, the date does not shift but of course it does not need to since it is still the same day.

  2. Schedule another weekly job for Wed 11 pm tomorrow (may 23). You should see [{“Item1”:“4”,“Item2”:“2018-05-30T05:00:00Z”}]. The time shifts by 6 hours but the date does not shift to May 24, which is the bug. It also shifts 6 days ahead, probably because the server thinks we already passed tomorrows backup date. And the schedule will run on 2018-05-29 (a Tuesday) at 11 pm as per Duplicati.

6

Got it, thanks!

Unfortunately, I recently (accidentally) updated my beta install to canary so will have to find somewhere else to test this, but on 2.0.3.6 canary this is what I got:

  • Scheduled a weekly job for “tomorrow” starting no more than my UTC offset hours away from midnight (in my case, I’m UTC-5 so scheduled for 11:11 PM).
  • Checked proposedSchedule line in “About” -> “System info”.
  • Everything looks correctly shifted ahead as it should be
    image

So at this point either it’s working correctly in 2.0.3.6 or I’m not testing the right thing.

I should have a beta install again by tomorrow and will re-check then.

7

I think you are testing correctly and it looks like your install is not showing the bug. So perhaps it got fixed. Or the Mac OS X handles the UTC time differently.

8

I repeated my above test with 2.0.3.3 beta and got the same working result, so perhaps it is an issue specific to MacOS (or more likely installations running on mono).

Edit:
I tested using 2.0.3.3 in a Docker image on my unRAID box (so it should be using mono) and still got the same expected behavior - namely:

  • task scheduled for 11:11 PM tomorrow (2018-05-26)
  • “About” → “System info” showed expected UTC-5 offset of proposedSchedule : [{"Item1":"1","Item2":"2018-05-27T04:11:00Z"}]

So maybe it is MacOS specific or maybe I’m just not testing the right thing.

9

OK, I did some more testing and it got even more confusing. UTC -7 hour shift here.

Test1

  • task scheduled for 11:11 PM tomorrow (2018-05-26), which is Saturday
  • Allowed Days: all are selected
  • “About” -> “System info” shows “2018-05-27T06:11:00Z”

This looks correct and UTC date shifts to Sunday, so backup will run at 11:11pm on Saturday.

Test2

  • task scheduled for 11:11 PM tomorrow (2018-05-26), which is Saturday
  • Allowed Days: only Saturday is selected
  • “About” -> “System info” shows “2018-06-02T06:11:00Z”

This is incorrect, the Saturday run is skipped and next run is scheduled for Friday (6/1) since the UTC date did not shift.

10

Confirmed! It looks like the issue crops up when week+ frequencies are combined with only allowing the job to run on certain days of the week.

Plus, it seems cumulative in that the more times I tested the more off it got (at least with 2.0.3.6).

So from the data below it looks like three is the issue you described as well as another where repeated rescheduling seems to cause the next date AFTER the current scheduled time to be selected rather than the actual next available date. (Note that restarting the server resets it.)

Are you able to replicate this scheduling issue @kenkendk?

Results for 11:11 PM weekly job starting on Saturday (local):

  • allowed to run every day -> Sunday (local) proposedSchedule
  • allowed to run Mondays -> Sunday (local) proposedSchedule
  • allowed to run Tuesdays -> Monday (local) proposedSchedule
  • allowed to run Wednesdays -> Tuesday (local) proposedSchedule
  • allowed to run Thursdays -> Wednesday (local) proposedSchedule
  • allowed to run Fridays -> Thursday (local) proposedSchedule
  • allowed to run Saturdays -> Saturday + 7 (local) proposedSchedule
  • allowed to run Sundays -> Sunday + 7 (local) proposedSchedule

Then again…

  • again allowed to run every day -> Sunday + 7 (local) proposedSchedule
  • again allowed to run Mondays -> Sunday + 7 (local) proposedSchedule
  • again allowed to run Tuesdays -> Monday + 7 (local) proposedSchedule
  • again allowed to run Wednesdays -> Tuesday + 7 (local) proposedSchedule
  • again allowed to run Thursday -> Wednesday + 7 (local) proposedSchedule
  • again allowed to run Friday -> Thursday + 7 (local) proposedSchedule
  • again allowed to run Saturday -> Friday + 7 (local) proposedSchedule
  • again allowed to run Sunday -> Saturday + 7 (local) proposedSchedule

And yet again:

  • again allowed to run every day -> Saturday + 14 (local) proposedSchedule
  • again allowed to run Mondays -> Sunday + 14 (local) proposedSchedule
11

Yes, this happens because the time is stored in UTC, which works nicely in most places.
But for the scheduler, the user expects things to happen in local time. I think all these issues will be resolved if we just change the scheduler such that it stores and uses local time.