Backups fail a few times before successfully running

David, the Demon logs (quoted above) contain only a subset of the messages that ATI may be writing for your backup tasks with this issue.

There is a new MVP Assistant log viewer tool that has now been made available by Acronis via the Community Tools page.. 

If you have Disks & Partitions backups created on ATI 2020 or later using .tibx files, then look in the Backup Worker logs.

If you have Files & Folders backups using .tib files (or Disk backup using same) then look in the Demon logs.

The log files should be zipped to preserve their original file names if sharing in the forums and would need to be less than 3MB in size, otherwise you would need to share the zip file via a Cloud share service such as OneDrive, Dropbox etc.

Hi Steve,

Thanks for taking the time to look at this.

Just to reiterate, this is a new problem (since upgrade to update 3) although that seems just to be a coincidence.  The last backup before the upgrade was about 10 days ago and that worked fine.  The good thing is that at least the backup works after failing a few times and perhaps if I didn't have notification emails configured I might not even notice. I would however like to know what is causing the failures and try and correct any issues.

I have only ever done 'Entire PC' tasks on this machine and I have no historical backups from ATI2020 or earlier.

I wasn't quite sure what you wanted from the MVP Assistant, the demon files seem to just be the same as the emailed report.  I have uploaded the 2 backup worker files that would have coincided with the 2 failed attempts from yesterday's run.  Nothing jumps out at me from these as to why the run fails.  They do fail early in the process before the backup starts and while the data is being scanned.  The 2 failure emails are about 2 minutes apart.

Although I am concentrating on the failures yesterday, every time I have run a backup recently I get a number of failure emails before the process successfully starts.  In one case there were 6 or 7 failures on retry and the whole job terminated as a failure.

Hopefully you can see something of use in these 2 files or point me in the direction of providing something of more use.

Thanks,

David 

David, the backup worker logs both show the same error when processing the backup data:

Failed to lock the volume snapshot

At this point I would recommend downloading the Acronis VSS Doctor stand-alone tool and running this on this PC to see if this identifies any issues with VSS here?  If it does, then allow it to fix any issues that it can.

Hi Steve,

The only problem the VSS Doctor revealed was the event log entries which would have been expected.  I decided to perform the usual suspects of:

chkdsk

sfc /scannow (which found some corrupt files and fixed them)

dism /online /cleanup-image /restorehealth

I then ran the backup again and although the task is still running it did send a single 'failed' email before settling into what will hopefully be a successful backup.

David

Update:

I spoke too soon. there were a total of 6 failure emails followed by the job giving up as a failed task with the reason 'Failed to lock the file'.  I have attached today's backup worker files.

The VSS doctor did not show any events for today.

Update2:

Things are going from bad to worse - the next attempt to backup failed with 'The file is corrupted' and all subsequent attempts fail with the same thing almost instantly, so at a dead end now, sadly.

If the Acronis tool does not help try VSSfix32bit

or VSSfix 64 bit

These downloads are from the Macruim Reflect knowledge base and solved a similar problem for me during the 2021 beta when the Acronis tool did not help.

David, the latest logs show a mix of issues here with the first (oldest log) still reporting a VSS issue but this is then superseded in the further logs by network issues with the destination NAS file being not accessible for write operations (shown as the file being locked!).

At this point I would suggest doing a reboot of your laptop and the destination WD NAS box to see if this will clear the lock issue and allow a clean start for the backup task.

Beyond this, you may need to check any logs available on the NAS to ensure that there are no other activities which could be locking the backup file(s) such as a scheduled antivirus scan perhaps?

The most recent log file ends with the following entries:

26/12/2020 05:37:42:667 PM +00:00 15292 I00000000: Pid: 15488 type=log; level=err; message=io#1: failed to open "\\?\UNC\WDMYCLOUDEX4100\Acronis\DBP_Laptop\\DBP-LAPTOP-0004.tibx" (pcs_err=-22);
26/12/2020 05:37:42:667 PM +00:00 15292 I00000000: Pid: 15488 type=log; level=err; message=ar#1: failed to open archive path="\\?\UNC\WDMYCLOUDEX4100\Acronis\DBP_Laptop\\DBP-LAPTOP.tibx" mode=append uuid=00000000000000000000000000000000, err=-5015 (Object is locked);
26/12/2020 05:37:42:667 PM +00:00 15292 I00000000: Pid: 15488 type=log; level=err; message=unable to open archive file (err -5015);
26/12/2020 05:37:42:670 PM +00:00 15292 I00000000: Pid: 15488 type=retcode; value=5015; id=1;
26/12/2020 05:37:42:670 PM +00:00 12160 I00000000: Pid: 15488 >>> exit

Wanted to jump in here to say that I just experienced this exact same issue this morning using a install of TI 2020.  Network destination and same "The file is locked" error with logs showing unable to write to file, unable to access file.

What's strange here is that I can Open location with TI just fine.  I can select the last backup file for recovery and If I were to execute it I am certain it would try to run.  Since this is an OS backup I am unwilling to try that though.  At any rate, it is obvious the file is not locked as the error indicates.

I have reported this to Support along with supporting files.

David,

I hope I have good news for you.  I was able to fix my failed task that erred "The file is locked" or "Failed to lock the file".  This was fairly easy to do but not at all intuitive and I would not expect a user to figure this out on their own.

After giving this error some thought I decided that it just may be likely that the meta data tracking had became corrupted for this file since everything else was working as expected.  So I decided to open the TI app, navigate to the task and click to select it.  Then in the right hand window I clicked on the task destination location icon, checked to make sure the location was correct and then clicked on the OK button.  This caused a message popup shown in the screenshot below.

I clicked on OK again and the screen blurred while the application recalculated the location. After that finished I was returned to the task backup tab.  I then clicked on the Backup now button and the task ran without error and completely successfully.

In my case the backup that failed was the last of a differential to be created prior to the next full backup of the task configuration.  I had some concern that the task may skip this differential after reading the message above so after the backup completed I was please to see that the Activity tab showed a differential file had been created.

Moving to the Recovery tab I found a message displayed that stated there were no backups to recover and instruction to first create a backup for recovery.  So I knew at that point that the meta data had been rewritten for the backup file that I had just created.

Going to the column titled Backups (center column of GUI) I navigated to the bottom of that column and clicked on the down arrow carat (v) to the right of the Add backup label and clicked on Add existing backup.  This opened the navigation explorer from which I navigated to the backup location again and this time I selected the 12KB file in the backup folder then I clicked the Add button and application began to calculate again.  The 12KB file is a file that stores all of the backup chain metadata which is used to identify were all the files of the backup chain are located.  After about 30 seconds the application completed the calculation and returned to the previous screen with the backup tab for the task selected.  I then clicked on the Recovery tab and was presented with the expected screen from which backup file selection can be made by date.  All the backups in the location were then available for selection.

I hope you cen follow these steps and get your task working again.

Bob, good find here and not one that is at all intuitive based on the error message given!

Steve,

I agree, the question is why does it happen?  The only change on my PC was an upgrade from Win 10 Pro 1909 to Win 10 Pro for Workstations 20H2 on 12/3/20 which I believe to be long enough ago to not be related, especially since this is a daily backup task.

Bob, not sure that anyone could answer the question of 'why it happens?' especially with no obvious change activity or other indicator to suggest that metadata could be being scrambled etc??  It isn't unreasonable for users to expect greater resilience and reliability for the new .tibx files and their important metadata linkages, and that there should be some elements of self-repair available to deal with such issues arising!

Thank you both for your comments.

Firstly I think I had reached the point of no return with this task now reporting a corrupt file.  When I browsed the location there was the original 12 KB file and 4 others, the last of which was small and only a partial backup which I guess caused the corruption.  I tried all the GUI options like 'clean up' and 'validate' but each returned an error because of the corruption.

Prior to the corruption, like Enchantech I was able to use the GUI to view the NAS location and the files there without error suggesting that there was no lock in place.

Because of the corruption the only option seemed to be to delete the task entirely which was an option that the GUI did not complain about.  I also rebooted the NAS and laptop as Steve suggested.

So I recreated the task, part of which is to redefine the destination anyway, and ran it. In fact I ran it twice to ensure that there was actually a file to read during the second run.  Both ran to completion successfully.

It is strange though because when this first started going wrong I ended up with my existing old task getting to the corrupted file state so this was not the first fresh task that I created.  It must just be coincidence that the 2 tasks were somehow faulty.

Thanks again for looking at this.  Hopefully things are now sorted but if I get the locked file situation again I know what my first port of call will be.

David

Steve,

Agreed, improved resiliency in metadata handling is on order.  I wonder if possibly the write to disk of metadata could be at issue.  Since we know little if anything about the handling of that data it is impossible to know or even suggest.

David,

Sorry to hear that you had to recreate the task.  Not all bad though as if my outlined procedure had not worked, new task creation would have been my next step.  If that had come to pass I would have followed these steps:

1. From the task drop down menu select Delete
2. Select Remove from the options
3. Select the Add existing task option
4. Navigate to the backup file location and select the 12KB file there an click Add

I believe these actions would cause a recalculation of tracking metadata and get the task working again.  If that failed to be the case, then I would use TI to delete the last backup file created by the task, then delete the task as outlined in steps 1 + 2 above then perform steps 3 + 4 above.  If that fails than I would just create a new task and start fresh.