Direkt zum Inhalt

Acronis didn't backup when I turned on the computer this morning

I have Acronis set to backup at 7AM every day. This morning I expected to see a new backup when I booted at 9AM but I don't. When I bring up ATI it says "Queued" and it is 10AM now. I thought ATI would do the backup in the background but it seems that I need to bring it up first.

I would include the log but I can't find an option to do that.

What is the expected action.

0 Users found this helpful

I have attached a screenshot of my backup drive/folder and as you can see there is no backup as of today (1/5/19).

 

Here is the log:

1/5/2019 9:27:48 AM: -----
1/5/2019 9:27:48 AM: ATI Demon started. Version: 23.4.1.14690.
1/5/2019 9:27:48 AM: Backup reserve copy attributes: format tib; need_reserve_backup_copy false;
1/5/2019 9:27:48 AM: Operation EDDYS-XPS_inc_b1_s2_v1 started by schedule.
1/5/2019 9:27:56 AM: Backup reserve copy attributes: format tib; need_reserve_backup_copy false;
1/5/2019 9:27:56 AM: Operation: Backup
1/5/2019 9:27:56 AM: Priority changed to Low.
1/5/2019 9:27:56 AM: Create Backup Archive From: To file: O:\Acronis Backups\Dad\XPS15_original_181229\EDDYS-XPS_full_b1_s1_v1.tib Compression: Normal Exclude: Files matching mask Match criterion: hiberfil.sys, pagefile.sys, $Recycle.Bin, swapfile.sys, System Volume Information, *.tib, *.tib.metadata, *.~, *.tmp, C:\Users\eddy\AppData\Local\Temp, C:\Users\eddy\AppData\Local\Microsoft\Windows\INetCache, C:\Users\eddy\AppData\Local\Mozilla\Firefox\Profiles\*\cache2, C:\Users\eddy\AppData\Local\Mozilla\Firefox\Profiles\*\OfflineCache, C:\Users\eddy\AppData\Local\Opera Software\Opera Stable\Cache, C:\Users\eddy\AppData\Local\Opera Software\Opera Stable\Media Cache, C:\Users\eddy\AppData\Local\Google\Chrome\User Data\Default\Cache, C:\Windows\CSC
1/5/2019 9:27:56 AM: Pending operation 173 started: 'Creating partition image'.
1/5/2019 9:27:57 AM: Volume Tracker has failed to find changes on volume '\\?\Volume{16bf8ef5-360a-46b0-bf98-1109f7dba2e3}\'.
1/5/2019 9:27:57 AM: Writing incremental version to file: EDDYS-XPS_inc_b1_s2_v1.tib
1/5/2019 9:27:57 AM: Pending operation 173 started: 'Creating partition image'.
1/5/2019 10:00:11 AM: Pending operation 173 started: 'Creating partition image'.

Start: 1/5/2019 9:27:48 AM
Stop: 1/5/2019 10:00:11 AM
Total Time: 00:32:23

Anhang Größe
484984-162491.png 14.69 KB

Eddy, 'Queued' simply means that ATI believes there is already another task running and only one active task is allowed.

Use the MVP Log Viewer tool to access the logs involved - the link is in my signature.  The default view in the log viewer is for tasks (ti_demon logs) but you may need to look at the scheduler 2 logs too.  You can change to the different logs using the Log type option in the viewer.

Eddy, the log doesn't show an issue other than the task being stopped before the backup has completed which may just be the point where the log was captured.

I added the log and a screen shot while you were typing (race condition ... what are the chances of that happening again?).

EddyQ wrote:

I added the log and a screen shot while you were typing (race condition ... what are the chances of that happening again?).

I will keep an eye on it  and see if it happens again tomorrow morning.

It happened  to me again this morning. I started the computer at about 8AM and later around 9 it still had not started a backup (scheled for 7A)  So I opened ATI and the backup started. I thought it would be running i the background such that when I booted it would start the backup. Can someone please explain this?

 

1/6/2019 9:44:21 AM: -----
1/6/2019 9:44:21 AM: ATI Demon started. Version: 23.4.1.14690.
1/6/2019 9:44:21 AM: Backup reserve copy attributes: format tib; need_reserve_backup_copy false;
1/6/2019 9:44:21 AM: Operation EDDYS-XPS started by schedule.
1/6/2019 9:44:32 AM: Backup reserve copy attributes: format tib; need_reserve_backup_copy false;
1/6/2019 9:44:32 AM: Operation: Backup
1/6/2019 9:44:32 AM: Priority changed to Low.
1/6/2019 9:44:33 AM: Create Backup Archive From: To file: O:\Acronis Backups\Dad\XPS15_190103\EDDYS-XPS.tib Compression: Normal Exclude: Files matching mask Match criterion: hiberfil.sys, pagefile.sys, $Recycle.Bin, swapfile.sys, System Volume Information, *.tib, *.tib.metadata, *.~, *.tmp, C:\Users\eddy\AppData\Local\Temp, C:\Users\Administrator\AppData\Local\Temp, C:\Users\eddy\AppData\Local\Microsoft\Windows\INetCache, C:\Users\Administrator\AppData\Local\Microsoft\Windows\INetCache, C:\Users\eddy\AppData\Local\Mozilla\Firefox\Profiles\*\cache2, C:\Users\eddy\AppData\Local\Mozilla\Firefox\Profiles\*\OfflineCache, C:\Users\eddy\AppData\Local\Opera Software\Opera Stable\Cache, C:\Users\eddy\AppData\Local\Opera Software\Opera Stable\Media Cache, C:\Users\eddy\AppData\Local\Google\Chrome\User Data\Default\Cache, C:\Users\Administrator\AppData\Local\Mozilla\Firefox\Profiles\*\cache2, C:\Users\Administrator\AppData\Local\Mozilla\Firefox\Profiles\*\OfflineCache, C:\Users\Administrator\AppData\Local\Opera Software\Opera Stable\Cache, C:\Users\Administrator\AppData\Local\Opera Software\Opera Stable\Media Cache, C:\Users\Administrator\AppData\Local\Google\Chrome\User Data\Default\Cache, C:\Windows\CSC
1/6/2019 9:44:34 AM: Pending operation 173 started: 'Creating partition image'.
1/6/2019 9:44:34 AM: The last created Volume Tracker checkpoint for volume '\\?\Volume{16bf8ef5-360a-46b0-bf98-1109f7dba2e3}\' belongs to another backup plan.
1/6/2019 9:44:34 AM: Pending operation 173 started: 'Creating partition image'.
1/6/2019 9:45:34 AM: The last created Volume Tracker checkpoint for volume 'C:' belongs to another backup plan.
1/6/2019 9:45:35 AM: Writing incremental version to file: EDDYS-XPS_inc_b1_s4_v1.tib
1/6/2019 9:48:26 AM: Pending operation 173 started: 'Creating partition image'.
1/6/2019 9:50:18 AM: The last created Volume Tracker checkpoint for volume 'W:' belongs to another backup plan.
1/6/2019 9:57:28 AM: Pending operation 173 started: 'Creating partition image'.
1/6/2019 9:57:28 AM: The last created Volume Tracker checkpoint for volume '\\?\Volume{5f313cbc-0bf3-4f09-acb4-15f3a00cc5ff}\' belongs to another backup plan.
1/6/2019 9:57:28 AM: Pending operation 173 started: 'Creating partition image'.
1/6/2019 9:57:28 AM: The last created Volume Tracker checkpoint for volume '\\?\Volume{f2f66483-8bfe-4bf1-9342-2d1401e0ba0b}\' belongs to another backup plan.
1/6/2019 9:57:29 AM: Pending operation 173 started: 'Creating partition image'.
1/6/2019 9:57:29 AM: The last created Volume Tracker checkpoint for volume '\\?\Volume{76bc96b6-0fa5-449e-bd3c-2beed487caef}\' belongs to another backup plan.
1/6/2019 9:57:29 AM: Pending operation 173 started: 'Creating partition image'.
1/6/2019 9:57:29 AM: The following backups have been successfully created: O:\Acronis Backups\Dad\XPS15_190103\EDDYS-XPS_inc_b1_s4_v1.tib
1/6/2019 9:57:29 AM: Operation has succeeded.

Start: 1/6/2019 9:44:21 AM
Stop: 1/6/2019 9:57:29 AM
Total Time: 00:13:08

It happened  to me again this morning. I started the computer at about 8AM and later around 9 it still had not started a backup (scheled for 7A)  So I opened ATI and the backup started.

Eddy, the log does not explain why the scheduled task did not start, it only shows that it ran when you opened the ATI GUI and triggered it to run.

Other logs are needed to understand why it didn't run, such as the Scheduler 2 log from the Log Viewer but please do not copy & paste this to the forum as can be very large - attach it as a zipped file instead.

Eddy, thank you for the new log but please use zipped files to preserve the original file names if attaching any further logs.

The new log confirms that your computer was turned off between 22:23pm and 08:07am the next morning, and also shows that ATI did try to launch 3 backup tasks at that time.

06/01/2019 08:07:58 :176  Trying task 1-1 as TIME_NORMAL
06/01/2019 08:07:58 :176  Stored token 00000000 replaced with 00000000
06/01/2019 08:07:58 :176  Windows fast startup state to disable: ENABLED PRESENCE
06/01/2019 08:07:58 :176  Windows fast startup state disabled: BACKUP PRESENCE
06/01/2019 08:07:58 :189  Trying task 1-2 as TIME_NORMAL
06/01/2019 08:07:58 :189  Stored token 00000000 replaced with 00000000
06/01/2019 08:07:58 :220  Trying task 1-3 as TIME_NORMAL
06/01/2019 08:07:58 :220  Stored token 00000000 replaced with 00000000
06/01/2019 08:07:58 :229  next wake up time = 7.01.2019 06:59:00
06/01/2019 08:07:58 :229  SetWaitableTimer(131913359400000000): > error=0

It then shows:

06/01/2019 08:07:58 :244  Running task 1-1

06/01/2019 08:07:58 :362  Running task 1-2

06/01/2019 08:07:58 :493  Running task 1-3 pending because of: MUTEXES

06/01/2019 08:07:58 :906  Task 1-1 completed with exit code=0

06/01/2019 08:07:58 :906  Running task 1-3 pending because of: MUTEXES

06/01/2019 08:25:18 :916  Running task 1-3 pending because of: MUTEXES

06/01/2019 09:03:40 :381  Running task 1-3 pending because of: MUTEXES

06/01/2019 09:44:20 :977  Running task 1-3 pending because of: MUTEXES

06/01/2019 09:44:20 :983  Task 1-2 completed with exit code=0

You then triggered Task 1-3 manually via the ATI GUI so the next entry shown in the log is:

06/01/2019 09:57:30 :076  Task 1-3 completed with exit code=0

What the above tells us is that you have 3 different backup tasks that are being triggered when your computer starts up and the reason why your 7am task didn't run is simply because it was queued behind the other 2 active tasks. 

pending because of: MUTEXES = the task is Queued!
completed with exit code=0 = the task completed successfully (0 errors!).

I didn't have any drives connected except drives C and W (both are partitions on my internal drive) and O (my backup drive). So does that mean when I disconnect the other drives I have to do something special? 

EddyQ wrote:

I didn't have any drives connected except drives C and W (both are partitions on my internal drive) and O (my backup drive). So does that mean when I disconnect the other drives I have to do something special? 

Eddy, this is nothing to do with what drives are connected, simply that there were 2 other tasks queued to run ahead of your scheduled task for whatever reason this is on your computer.

Check the ti_demon logs for logs created after you turned on the computer at 08:07 today.

What are ti_demon logs? And how do I view them? Also if there were other tasks ahead of mine (1) if I wait long enough will they finish (even though those drives are not connected?) or (2) is there a way to prevent them?

EddyQ wrote:

I'll check the TI_demon logs. Also if there were other tasks ahead of mine (1) if I wait long enough will they finish (even though those drives are not connected?) or (2) is there a way to prevent them?

Eddy, when you use the MVP Log Viewer, the ti_demon logs are the default view shown to you and are the logs for any backup or validation activity (among others).

Each line shown in the log viewer is a separate backup activity, so if you look at each in turn, you will see the date / time of the activity in the left side of the main panel (as you copied for your own log earlier in this topic).

These entries should show you what the other tasks were that ran when your system started at 08:07 this morning.  Once you have identified the tasks, then you can decide what action needs to be taken in regard to those tasks.  I suspect that you have tasks where they have a default Advanced option set to 'Run missed operations at system start...' thus causing these tasks to run ahead of your missed scheduled task.

What should I do about this to make the backup work each morning?

I do have 'Run missed operations at system start...' set and I also have 'Run missed operations when an external device is connected'.

EddyQ wrote:

What should I do about this to make the backup work each morning?

I do have 'Run missed operations at system start...' set and I also have 'Run missed operations when an external device is connected'.

You would need to set a delay time using the "with delay (in minutes)" so that the task does not start immediately, i.e. delay by say 30 minutes after system start.

For the run when external device is connected, you should not connect the device until after your missed scheduled task has started, so that the second task is queued behind it.