Wake up time after starting suspended computer

jf64 · June 25, 2021, 9:51am

Hi All,

I have 4 backups (A, B, C and D) set, each of them get called in 60 minutes intervals, the time difference between A, B, C and D is 15 minutes each.
In the night at e.g. 3:05 am Duplicati is showing the next scheduled backup is B at 3:15 am. Now I´m suspending the computer (by pressing the power button, which was setup to suspend - not power down! - the computer).
In the morning at e.g. 9:00 am I´m starting the computer (by pressing a key on the USB keyboard). Duplicati is still showing the next scheduled backup is B at 3:15 am. This remains there for 10-15 minutes and no backup will be done.
At some point of time Duplicati executes the missed backups in the order A, B, C and D (which is actually fine for me) and from that point on works everything as expected.

I made few experiments with Pause after startup or hibernation (set it to few seconds), but it didn´t change this behavior.

I just wanted to know, what is the real wake up time for Duplicati?

Regards

drwtsn32 · June 26, 2021, 2:40pm

Did you configure the “pause after startup” option on the main Settings screen?

Capture

AimoE · June 26, 2021, 3:11pm

Is this in Windows terms or Linux terms? Do you mean suspend-to-disk or suspend-to-ram? In my understanding and in my experience, the setting does not apply to suspend-to-ram (which wakes up faster). I have not tried suspend-on-disk so I am not sure of the behaviour in that case.

On Linux, I tried once in another context to implement a script to run right after waking up from suspend-to-ram, and it turned out to be far more difficult than I anticipated, so I am not surprised that Duplicati doesn’t do that either. But someone might have a better understanding of it.

jf64 · June 26, 2021, 4:46pm

Please read the whole article above…

jf64 · June 26, 2021, 4:50pm

My question is related to Windows 10 Prof.

jf64 · June 26, 2021, 4:59pm

Those are the energy settings (in German, “Energy saving”, thus, my earlier wording “suspended” is probably not correct):

But the question remains: How long it takes until Duplicati wakes up?

drwtsn32 · June 26, 2021, 8:35pm

Sorry, missed that part!

Xavron · June 26, 2021, 10:27pm

That should only cause it to pause for set amount of time before running. Eg if you set it to 1 minute then the computer has 1 minute to settle before Duplicati runs.

In code its referred to as startupDelayDurationValue & startupDelayDurationMultiplier. eg 1 being a value and minute being a multiplier.

That won’t solve your problem here for sure unless you had a high value.

There’s way too many possibilities here though as to why its delayed or maybe even “delayed” some of which are Duplicati or settings, some of which are system.

You may have to do some digging to find out the reason.

ts678 · June 26, 2021, 11:10pm

Mine waits roughly 0 to 5 minutes, and my suspicion is that it’s in below time-limited scheduler wait:

github.com

duplicati/duplicati/blob/5af46b6eecc9fe04c140ec5304dabdd50bdaa3af/Duplicati/Server/Scheduler.cs#L370-L380


      
          //Figure out a sensible amount of time to sleep the thread

          if (scheduled.Count > 0)

          {

              //When is the next run scheduled?

              TimeSpan nextrun = scheduled.Values.Min((x) => x.Value) - DateTime.UtcNow;

              if (nextrun.TotalMilliseconds < 0)

                  continue;

          

              //Don't sleep for more than 5 minutes

              waittime = (int)Math.Min(nextrun.TotalMilliseconds, 60 * 1000 * 5);

          }

I have an hourly backup, but I looked at the last 10 morning wake-from-sleep. The delays from wake:

That’s 2:27 average, which fits well with a random delay (depending on timing) from 0 to 5 minutes.

Wake times are in Event Viewer in the system event log as Event ID 1 from Power-Troubleshooter.
Easier method is powercfg /sleepstudy or TurnedOnTimesView (if you don’t mind third-party tools).
I got my backup start from The operation Backup has started in a log-file >= information level.

Is your system quite busy when it wakes up, e.g. if you look at Task Manager CPU and disk usage?
Some people also like to deprioritize Duplicati with thread-priority and/or use-background-io-priority.
This may possibly account for some additional delay in Duplicati getting going. How do you start it?
However you start, what happens if you stop it before sleep, and start it again after system wakes?

“Pause after startup or hibernation” does not work #3693

Possibly this only works (and it does) on Windows? There's a lot of Win32 usage in
https://github.com/duplicati/duplicati/blob/master/Duplicati/Server/LiveControls.cs

jf64 · June 27, 2021, 12:40pm

No, it isn´t. As I mentioned above, we´re talking here about 10-15 minutes, and in that time frame (actually much sooner) the computer is already in a working condition and I´m able to work with.

After ca. 10-15 seconds after login it is at ca 0%.

No, I didn´t do that.

Xavron · June 29, 2021, 9:46pm

You could try setting to eg backups every 5 minutes schedule before the computer suspends with a test. Do one backup to get it rolling. Don’t forget to make a file change before suspending so something gets backed up.

Wait maybe 15 minutes, wake the computer, see how long it takes. If its less time then it has to do with the backup schedule time and is a Duplicati thing that way. Though I could test this, I have other things to test.

ts678 · June 29, 2021, 11:44pm

Unfortunately there’s not any log file logging. If it comes down to a developer and a debugger, look here:

github.com

duplicati/duplicati/blob/5af46b6eecc9fe04c140ec5304dabdd50bdaa3af/Duplicati/Server/LiveControls.cs#L331-L400

    
      
          /// <summary>

          /// Gets the time the current pause is expected to end

          /// </summary>

          public DateTime EstimatedPauseEnd { get { return m_waitTimeExpiration; } }

          

          /// <summary>

          /// Method for calling a Win32 API

          /// </summary>

          private void RegisterHibernateMonitor()

          {

              Microsoft.Win32.SystemEvents.PowerModeChanged += new Microsoft.Win32.PowerModeChangedEventHandler(SystemEvents_PowerModeChanged);

          }

          

          /// <summary>

          /// A monitor for detecting when the system hibernates or resumes

          /// </summary>

          /// <param name="sender">Unused sender parameter</param>

          /// <param name="_e">The event information</param>

          private void SystemEvents_PowerModeChanged(object sender, object _e)

          {

This file has been truncated. show original

So there’s a fairly long chain that has to work, presumably set off by the previously mentioned Windows event, then passed into Duplicati. The easiest ways to check the Windows event are already mentioned.

It might be possible to obtain Duplicati state information during the wake pause at About → System info.
There are a couple of variables that get pretty active when a startup delay is deliberately added, such as

estimatedPauseEnd
programState
pauseTimeRemain

however I’m less sure what to expect without a set startup delay (and mine might be different anyway…).

It would also be nice to have the Windows event log and wake information to make sure that part worked.
Yes, I know the computer is out of sleep, but the question is how widely that information was sent around.

ts678 · June 30, 2021, 1:53pm

Interestingly, the event to Duplicati appears to happen (sometimes) before Power-Troubleshooter is able to log its event, based on the timing. Although I was never (in about three tries) able to get it to wake in Pause without a Pause after startup or hibernation in Settings, adding a two minute delay over three runs:

Had estimatedPauseEnd to-the-second two minutes after Power-Troubleshooter’s event in event viewer.

Had estimatedPauseEnd five seconds sooner than that I think. I didn’t write it down fast enough, but proof
07:38:43 Event ID 1 from Power-Troubleshooter
2021-06-30 07:40:38 -04 - [Information-Duplicati.Library.Main.Controller-StartingOperation]: The operation Backup has started from Duplicati log file

A third run was slightly ahead of two-minutes-past-Power-Troubleshooter event, although there are earlier:

09:17:14 Event ID 1 from Kernel-General
The system time has changed to ‎2021‎-‎06‎-‎30T13:17:14.500000000Z from ‎2021‎-‎06‎-‎30T13:16:21.170437700Z.

Change Reason: System time synchronized with the hardware clock.
Process: '' (PID 4).

09:17:15 Event ID 131 from Kernel-Power
Firmware S3 times. ResumeCount: 28, FullResume: 249, AverageResume: 249
09:17:27 Event ID 1 from Power-Troubleshooter
The system has returned from a low power state.

Sleep Time: ‎2021‎-‎06‎-‎30T13:16:00.202244700Z
Wake Time: ‎2021‎-‎06‎-‎30T13:17:20.272831300Z

Wake Source: Device -Intel(R) USB 3.0 eXtensible Host Controller - 1.0 (Microsoft)

estimatedPauseEnd : 2021-06-30T09:19:15.2573866-04:00
programState : Paused

Maybe wake notification inside Windows goes simultaneously to Power-Troubleshooter and Duplicati?

Other notable points are that when the delay is set, Duplicati wakes up Paused, as visible in Tray Icon appearing paused, and top-of-screen pause control offering Resume. In my second test, the missed backup at 07:40 ran when pause ended, so another test would be to try to manually end pause in GUI, either with the top-of-screen resume button, or right-click Tray Icon and do a Resume from the menu.

From a code point of view, it’s possible that Duplicati sees the Resume come in right after the Suspend
from its point of view (because it’s not running while the computer is asleep). That might make issues, however if it lost track of its state, then I’m not sure why it resumes after a longer delay. Needs testing.

I will leave further testing to @jf64 or someone who seems to see Duplicati delay too much on wake.

is disappointing, because I hoped a few second delay might make it run when it un-pauses, but at least further testing using a longer delay (e.g. two minutes) could be done to see if behavior varies from mine.

jf64 · September 16, 2021, 3:40pm

Hi All,

Thank you for your suggestions.
I just got the update Windows 10, Version 20H2 and now it seems to be working as expected: the backup scheduler starts right after the computer is up.

Regards