Unexpected behavior from the scheduler

[Nemesis]

I feel a bit stupid making a post about such a simple thing but i am finally done with all my intiial setting up of backup tasks and i am ready to schedule them to run weekly. I have three tasks, one of which a big one which could contain big changes, so i want to do task 1 (small) on monday midnight, task 2 (small) on tuesday midnight and task 3 (big) on wednesday midnight because that one could take a while and depending on the changes in there might take more than 24 hours to complete.

I go into the scheduler of task 1. Enable the “automatically run backups” checkbox. I set “Next time” to 00:00 09/11/2020 which is next monday midnight. I set “Run again every” to “1 weeks” and i put “allowed days” on monday only. I save changed, and then the friggin task suddently says " Next scheduled run: Tuesday at 12:00 AM"

??? Why does it end up with tuesday? I clearly said tuesday is a day that is not allowed.

I noticed the last backup was done last tuesday (manually), so then i thought maybe because i said once every week, it will wait at least one week before doing another run so it can’t do it on monday. To try and bypass this i instead set “run again every” to “1 days” with the only allowed day still on monday, and the “next time” still on the same as above, however this doesn’t solve the problem. Next run is still tuesday.

What is the logic behind this?

[ts678]

@Nemesis

What is the logic behind this?

FWIW it works fine here, but even if it didn’t “logic” questions might need a better scheduler expert.

My test used 2.0.5.1 Beta on Windows 10 to set up a new backup. Nov 9 at 12:00 AM got that time.
Your path might be different, if you checked Automatically run backups. It’s checked by default.
My path was pretty much a straight run-through of a job creation, so never actually ran that backup.

What Duplicati version and OS? Can you do a reproducible step-by-step that creates the problem?
Possibly then an Issue can be filed for development. Please note your time zone. I’m in GMT-05:00

[Nemesis]

Here’s how i can reproduce this issue:

1. Create a new backup task
2. On the schedule page:
3. Put “Next time” on 00:00
4. Put the next date on the next monday. In my case 11/09/2020
5. Put “Run Again Every” on “1 weeks”. (Not entirely sure if this is necessary to reproduce)
6. For “Allowed Days” only tick “Monday”. Make sure no other days are ticked.
7. Click “Next”
8. Click “Save”

Expected Result: For the specified backup task, the “Next scheduled run” should say “Monday at 00:00” or “Monday at 12:00 AM” (I would prefer the first, because this is also the time format i entered the time in, but Duplicati seems to use the latter).

Actual Result: “Next scheduled run” on the specified task says “Tuesday at 12:00 AM”. This is a day that I told the system it was not allowed to run on, and this is a different date than i entered for the “next date” value.

Duplicati version: 2.0.5.1_beta_2020-01-18
Operating System: Synology DSM 6.2.3-25426 Update 2
Docker Version, in case it matters: 18.09.8

I’m a programmer myself but i’ve never opened an issue on Github before :P. Should i do open one?

[ts678]

@Nemesis

Put “Next time” on 00:00

Here it becomes somewhat impossible to match, and I hope it’s not a locale difference, e.g. for a country.
I get a field which is hours, minutes, and AM or PM. 00 hours is not on the dropdown, but typing it gets 12.
Originally I picked a Monday somewhat far out, but it looks like you then get only the date without the time.
So here’s the upcoming Monday, and as testing continues, people may have to pick next Monday for then.

So the above is what I asked for. I don’t know why yours is different, but we can examine it other ways.
My backup has no passwords, so I just do an Export To File and look in the .json to see the schedule:

    "Time": "2020-11-09T05:00:00Z",
    "Repeat": "1W",
    "LastRun": "0001-01-01T05:00:00Z",
    "Rule": "AllowedWeekDays=Monday",
    "AllowedDays": [
      "mon"
    ]

I am 5 hours behind UTC, so my 00:00 (a.k.a. 12:00 AM) Monday shows as five hours later in UTC time.

@Nemesis

I’m a programmer myself

So I will try something harder. The scheduling information is in Duplicati-server.sqlite, viewable using
DB Browser for SQLite or similar. Viewing the Schedule table, I see Time for my backup is 1604898000

(courtesy of epochconverter.com)

So the input side of the time from the GUI worked (of course, for me everything worked), however the plan appears to make the input time subject to certain rules such as days of the week, and what you see is the proposed schedule as shown in the GUI for the backup job. You can also see it in About → System Info in

• proposedSchedule : [{“Item1”:“24”,“Item2”:“2020-11-09T05:00:00Z”}]

I would be curious whether you found a conversion problem on the input side, or something caused a skip.
I would also be curious what other times on Monday morning and afternoon work, or do all go to Tuesday?
About → System info also shows my locale though I hope this is not a time zone or locale sensitive issue.

• BrowserLocale : {“Code”:“en-US”,“EnglishName”:“English (United States)”,“DisplayName”:“English (United States)”}

and possibly the OS also has a locale, and I’m not sure how such things work inside of Duplicati anyway…

For completeness, I tried Linux Duplicati 2.0.5.111 on mono version 6.4.0.198 on an old backup. Went fine.

Before filing a GitHub issue, maybe you can poke more at this to see when it happens, and if it ever works.

[Nemesis]

At the time picker i get a 24-hour picker that goes from 00:00 to 23:59. You mentioned a dropdown element? For me it is not a dropdown but more of a textbox with a predetermined format of xx:xx like (00-23):(00-59)

I have also concluded that the “run again every 1 weeks” is not necessary to reproduce this issue. This is just the value that i used when i encountered it.

Here’s the result of the above scheduler:

This is the JSON from my exported task file:

"Time": "2020-11-08T23:00:00Z",
    "Repeat": "1D",
    "LastRun": "0001-01-01T00:00:00Z",
    "Rule": "AllowedWeekDays=Monday",
    "AllowedDays": [
      "mon"
    ]

I am one hour ahead of UTC so the Time seems to be correct in this export.

So I will try something harder.

Sure!

In the Duplicati-server.sqlite on the schedule table i can see the Time value for my backup is 1604876400.

which according to epochconverter is Sunday, November 8, 2020 11:00:00 PM GMT.

Also note the “local time” it says here. This is of course the time i would expect Duplicati to show on the “Next scheduled run” label.

About → Systeminfo → proposedSchedule says:

proposedSchedule : [{“Item1”:“8”,“Item2”:“2020-11-09T23:00:00Z”}]

I would be curious whether you found a conversion problem on the input side, or something caused a skip

It doesn’t seem like a conversion problem on the input side. The backend all seems to be correct.

I would also be curious what other times on Monday morning and afternoon work, or do all go to Tuesday?

Good question.

When changing the time on the scheduler for the task from 00:00 to any other full hour, the “Next scheduled run” switches to “Tomorrow at 1:00 AM” or “Tomorrow at 3:00 AM”, which is right.

When then changing it back to 00:00 again, it jumps back to “Next scheduled run: Tuesday at 12:00 AM”. Note that this happens for 00:00 to 00:59. So the problem seems have to do with the 00 hour in the 24-hour time format which doesn’t exist in the 12-hour time format. Somehow the conversion here seems to go wrong.

I have also concluded that this happens for every single day as long as a time between 00:00 and 00:59 is picked in the 24-hour time picker. It will always skip to 12:00 AM the next day.

About → Systeminfo → Browserlocale shows the following:

BrowserLocale : {“Code”:“en-US”,“EnglishName”:“English (United States)”,“DisplayName”:“English (United States)”}

So my conclusion seems to be that something is going wrong converting between the 12-hour and 24-hour time formats and somehow that causes it to skip a day, however because the database seems correct, it might just be a front-end issue, meaning the scheduler may execute at the time i specified and only the “Next scheduled run” label may be wrong. (Note that the big progress bar at the top says the same.)

I’ll leave the scheduler turned on on my test task on 00:00 on monday where it says it’ll execute on tuesday 12:00 AM and then monday (tomorrow) i will check if the task has been executed or not.

Hope this is enough information. If there is anything else i should do or check to help solve this issue, i will gladly do so.

[ts678]

@Nemesis

For me it is not a dropdown

Click clock icon for time picker. Note mine has 12 (not 00) before 01, but I can type 00 (becomes 12).

Yours looks a bit different, lacking AM/PM, so possibly you’ll also find 00 to 23 if you can get dropdown.

@Nemesis

Somehow the conversion here seems to go wrong.

Possibly you mean the proposed schedule. Initial conversion seem right per two tests, if I followed right.

@Nemesis

I have also concluded that this happens for every single day as long as a time between 00:00 and 00:59 is picked in the 24-hour time picker. It will always skip to 12:00 AM the next day.

If you mean that non-even times such as 01:01 are OK, I wonder if the odd hour is related to GMT+01?

@Nemesis

BrowserLocale : {“Code”:“en-US”,“EnglishName”:“English (United States)”,“DisplayName”:“English (United States)”}

Is the entire Synology in US English (with its conventions), or does it give local choices initially or later? Given your system preference for 24 hour time will possibly mean a developer must match its settings. Adding to my list of things I hope it isn’t is a Synology-only problem. It’d be nice if Linux VMs can do this, given exactly the right setup which is still somewhat TBD. Do you have any other systems to test with?

If not, I’d say file the Issue, point here, and be prepared for possible questions if an expert picks this up.

[Nemesis]

@ts678

Yours looks a bit different, lacking AM/PM, so possibly you’ll also find 00 to 23 if you can get dropdown.

That is correct, i got a 00 to 23 and 00 to 59 dropdown list when clicking the clock.

@ts678

Possibly you mean the proposed schedule.

Sorry i’m not entirely sure what you mean.

@ts678

If you mean that non-even times such as 01:01 are OK

Yes anything after 00:59 is perfectly fine. It really has to do with the 00 hour.

@ts678

I wonder if the odd hour is related to GMT+01?

I wonder if someone in a different timezone with a 24-hour clock will have the same issue. This is something i can’t really test myself (i think?)

@ts678

Is the entire Synology in US English (with its conventions), or does it give local choices initially or later?

When executing the ‘locale’ linux command SSH’d into the Synology NAS, i get the following:

LANG=en_US.utf8
LC_CTYPE="en_US.utf8"
LC_NUMERIC="en_US.utf8"
LC_TIME="en_US.utf8"
LC_COLLATE="en_US.utf8"
LC_MONETARY="en_US.utf8"
LC_MESSAGES="en_US.utf8"
LC_PAPER="en_US.utf8"
LC_NAME="en_US.utf8"
LC_ADDRESS="en_US.utf8"
LC_TELEPHONE="en_US.utf8"
LC_MEASUREMENT="en_US.utf8"
LC_IDENTIFICATION="en_US.utf8"
LC_ALL=en_US.utf8

Does that answer your question?

@ts678

It’d be nice if Linux VMs can do this, given exactly the right setup which is still somewhat TBD. Do you have any other systems to test with?

I can spin up a Linux vm on another device but that wont be on the Synology as my Synology unit has a rather weak CPU that’s not really meant for VM’s.Is that a problem?

Also:

I actually have some rather interesting information:

@Nemesis

however because the database seems correct, it might just be a front-end issue, meaning the scheduler may execute at the time i specified and only the “Next scheduled run” label may be wrong

The scheduled task that i left on, which i mentioned here:

@Nemesis

I’ll leave the scheduler turned on on my test task on 00:00 on monday where it says it’ll execute on tuesday 12:00 AM and then monday (tomorrow) i will check if the task has been executed or not.

did not actually run. So somehow even though the backend looks completely fine with all datetime values on monday midnight, the task still did not execute. It now (on monday 09/11/2020) says “Next scheduled run: Tomorrow at 12:00 AM” with still the same scheduler settings:

[ts678]

@Nemesis

When then changing it back to 00:00 again, it jumps back to “Next scheduled run: Tuesday at 12:00 AM”. Note that this happens for 00:00 to 00:59. So the problem seems have to do with the 00 hour in the 24-hour time format which doesn’t exist in the 12-hour time format. Somehow the conversion here seems to go wrong.

@ts678

@Nemesis

Somehow the conversion here seems to go wrong.

Possibly you mean the proposed schedule. Initial conversion seem right per two tests, if I followed right.

@Nemesis

Sorry i’m not entirely sure what you mean.

You tested the conversion at 00:00 in two ways, expecting 00:00 Monday 11/09 local time local time.
Being an hour ahead of UTC this means 11/08 11 PM UTC which you saw in the DB and the JSON.
So that conversion seemed correct. The proposed schedule is not the DB schedule. It can be later.
What was unknown is whether reverse conversion back to day-of-week broke, or a delay was done.

@Nemesis

I wonder if someone in a different timezone with a 24-hour clock will have the same issue. This is something i can’t really test myself (i think?)

You can awkwardly try test by setting up VMs, which is probably what anybody else would have to try. Alternatively, if you have things to play with, you can see if you can find a setting that avoids the issue.

@Nemesis

Does that answer your question?

Sort of, but I’m not sure why the clock is 24 hour. Search saw more questions than answers, but see:

Time

To set the time format:

Choose the display time in either 12-hour or 24-hour format.

@Nemesis

I can spin up a Linux vm on another device but that wont be on the Synology as my Synology unit has a rather weak CPU that’s not really meant for VM’s.Is that a problem?

My assumption (which might be wrong) is that a VM is standalone, so host config should be well hidden.

@Nemesis

the backend looks completely fine with all datetime values on monday midnight

Well, JSON and DB had that. As I mentioned, the proposed schedule can seemingly be later, as seen in

proposedSchedule : [{“Item1”:“8”,“Item2”:“2020-11-09T23:00:00Z”}]

so it seems like something has started at the right time and pushed forward 24 hours to the wrong time.
There HAS been at least one change in the scheduler in Canary, though it doesn’t “sound” like your bug:

2.0.5.106_canary_2020-05-11

Fixed a case where backups could run immediately and ignore the scheduled time, thanks @warwickmm

[Nemesis]

@Nemesis

proposedSchedule : [{“Item1”:“8”,“Item2”:“2020-11-09T23:00:00Z”}]

Oh crap i actually misread this when i posted it. Thought it said 2020-11-08. — 8 and 9 are kinda close. Sorry! So the proposedSchedule is wrong too, yeah.

@Nemesis

So my conclusion seems to be

So this conclusion is wrong by definition because i misread and then it also makes sense the task did not execute.

@ts678

What was unknown is whether reverse conversion back to day-of-week broke, or a delay was done.

Yes that’s correct, that is unknown as of now.

@ts678

You can awkwardly try test by setting up VMs, which is probably what anybody else would have to try.

I dont have much free time nowadays but i am wanting to try this, i may report back in a couple of days.

@ts678

Alternatively, if you have things to play with, you can see if you can find a setting that avoids the issue.

I can’t play with settings on the Synology as it’s in use 24/7 for serious purposes that i don’t want to cause problems with.

@ts678

Sort of, but I’m not sure why the clock is 24 hour. Search saw more questions than answers, but see:

Time

In my Synology Control Panel → Regional Settings → Time Format it’s on 24-hour time, which is the most common time format used around here so that’s pretty normal, but i guess that explains where the 24-hour format comes from. I’d also rather not change it to 12-hour now and test because i’m not sure what other changes or impacts that will make/have to the synology.

@ts678

My assumption (which might be wrong) is that a VM is standalone, so host config should be well hidden.

Yes now that i think about it, that is the purpose of a VM so that should be true.

@ts678

Well, JSON and DB had that. As I mentioned, the proposed schedule can seemingly be later, as seen in
(…)
so it seems like something has started at the right time and pushed forward 24 hours to the wrong time.

You’re right, i didnt originally see that when posting the scheduler json.

@ts678

There HAS been at least one change in the scheduler in Canary, though it doesn’t “sound” like your bug:

I agree that i doubt this has to do with it.

Besides potentially more testing on a vm, for example with different time regions but still 24-hour clock, is there any more information needed that i can provide to solve this issue?

[ts678]

@Nemesis

is there any more information needed that i can provide to solve this issue?

The idea of further characterization sounds great unless you want to actually look into code yourself.
Throwing the latest Canary on the VM might also be worthwhile even if the fix doesn’t “look” relevant.

@Nemesis

I dont have much free time nowadays but i am wanting to try this, i may report back in a couple of days.

The too-small volunteer development team has a huge issue backlog, and might not hop on this fast.
Looking around for similar issues is part of filing a GitHub issue, and if found, might bump the priority.