Backup suddenly taking much longer
My backup failed because the disk was full, so as usual I deleted all the versions through the Acronis TrueImage software and started the backup. Usually takes about 12 hours to back up. It's been running for two days now and is approximately 20% done. Not sure where to even start troubleshooting this.
Steve Smith wrote:
David, sorry to hear of this issue but more information is needed to fully understand why your backup should be taking significantly longer than normal?
What type of backup are you doing here? Is that a Disks & Partitions backup, or a Files & Folders backup?
I am backing up two drives C: and E: in a disks backup.
Is the backup of just one disk drive or of more than one drive?
Does it include your Windows OS drive?
Yes, It is backing up the C: Drive which has the OS and the E: drive which is data.
Where is the backup being written to, is this an internal, external, USB or network drive destination?
Backup is to an external USB drive.
After deleting files from the backup drive (that became full), did you do any defragmentation of the drive?
No, but there should have been nothing left on the destination drive. It only contains the backup.
Please download the MVP Log Viewer tool (link in my signature below) and use this to review the log file for your backup operation. Check for any obvious error messages being recorded?
Here are the logs for the two most recent attempts. The log file shows an error that I don't understand but it does not stop the process. I formatted those lines to be larger. I stopped the first after two days and the second after almost 5. They were running at speeds of aprox 45Mbps as opposed to the usual range of aprox 250 - 700 Mbps. Between the two I unplugged the USB drives and plugged them into alternate USB ports.
10/7/2019 1:27:22 PM: -----
10/7/2019 1:27:22 PM: ATI Demon started. Version: 23.5.1.17750.
10/7/2019 1:27:22 PM: Backup reserve copy attributes: format tib; need_reserve_backup_copy false;
10/7/2019 1:27:22 PM: Operation My disks started manually.
10/7/2019 1:27:25 PM: Backup reserve copy attributes: format tib; need_reserve_backup_copy false;
10/7/2019 1:27:25 PM: Operation: Backup
10/7/2019 1:27:25 PM: Priority changed to Low.
10/7/2019 1:27:25 PM: Preparing the media...
10/7/2019 1:27:25 PM: Error 0x4000f: Canceled.
10/7/2019 1:27:25 PM: Create Backup Archive From: Disk 1, Disk 2 To file: G:\My disks.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\david\AppData\Local\Temp, C:\Users\david\AppData\Local\Microsoft\Windows\INetCache, C:\Users\david\AppData\Local\Mozilla\Firefox\Profiles\*\cache2, C:\Users\david\AppData\Local\Mozilla\Firefox\Profiles\*\OfflineCache, C:\Users\david\AppData\Local\Opera Software\Opera Stable\Cache, C:\Users\david\AppData\Local\Opera Software\Opera Stable\Media Cache, C:\Users\david\AppData\Local\Google\Chrome\User Data\Default\Cache, C:\WINDOWS\CSC
10/7/2019 1:27:25 PM: Pending operation 173 started: 'Creating partition image'.
10/7/2019 1:28:03 PM: Writing full version to file: My disks_full_b1_s1_v1.tib
10/7/2019 1:35:44 PM: Pending operation 173 started: 'Creating partition image'.
10/7/2019 1:37:13 PM: Pending operation 173 started: 'Creating partition image'.
10/7/2019 1:37:16 PM: Pending operation 173 started: 'Creating partition image'.
10/9/2019 10:17:13 AM: Terminated by user.
Start: 10/7/2019 1:27:22 PM
Stop: 10/9/2019 10:17:13 AM
Total Time: 1.20:49:51
---- Second Log file ----
10/9/2019 6:23:16 PM: -----
10/9/2019 6:23:16 PM: ATI Demon started. Version: 23.5.1.17750.
10/9/2019 6:23:16 PM: Backup reserve copy attributes: format tib; need_reserve_backup_copy false;
10/9/2019 6:23:16 PM: Operation My disks started manually.
10/9/2019 6:23:19 PM: Backup reserve copy attributes: format tib; need_reserve_backup_copy false;
10/9/2019 6:23:19 PM: Operation: Backup
10/9/2019 6:23:19 PM: Priority changed to Low.
10/9/2019 6:23:19 PM: Preparing the media...
10/9/2019 6:23:19 PM: Error 0x4000f: Canceled.
10/9/2019 6:23:19 PM: Create Backup Archive From: Disk 1, Disk 2 To file: G:\My disks.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\david\AppData\Local\Temp, C:\Users\david\AppData\Local\Microsoft\Windows\INetCache, C:\Users\david\AppData\Local\Mozilla\Firefox\Profiles\*\cache2, C:\Users\david\AppData\Local\Mozilla\Firefox\Profiles\*\OfflineCache, C:\Users\david\AppData\Local\Opera Software\Opera Stable\Cache, C:\Users\david\AppData\Local\Opera Software\Opera Stable\Media Cache, C:\Users\david\AppData\Local\Google\Chrome\User Data\Default\Cache, C:\WINDOWS\CSC
10/9/2019 6:23:19 PM: Pending operation 173 started: 'Creating partition image'.
10/9/2019 6:24:00 PM: Writing full version to file: My disks_full_b1_s1_v1.tib
10/9/2019 6:31:35 PM: Pending operation 173 started: 'Creating partition image'.
10/9/2019 6:32:52 PM: Pending operation 173 started: 'Creating partition image'.
10/9/2019 6:32:56 PM: Pending operation 173 started: 'Creating partition image'.
10/14/2019 1:42:43 PM: Terminated by user.
Start: 10/9/2019 6:23:16 PM
Stop: 10/14/2019 1:42:43 PM
Total Time: 4.19:19:27
David, thanks for answering my earlier questions - can you please zip the log files and upload them to this topic so that I can review the more detailed error message content that gets hidden in the Log View: Short version in the MVP Log Viewer tool (you can see this yourself by switching to Log View: Regular).
Also, please check what your Options > Advanced > Error handling settings are?
What external drive are you using and how is this formatted?
Is this the same drive that has been used without issue previously?
I'd also try isolating each drive to its own unique backup for testing (if you have to keep them as one, you can go back to that later).
Start the first backup of the smaller drive (how big are each of them?) and see how long it takes. Then do the second drive and see how long it takes. If one completes, but the other still takes forever, then you have kind of isolated the problem to that one particular drive and may need to run some disk health checks on it (chkdsk /f /r) and/or run some vendor diagnostic tools on it. If there are bad sectors on the disk, those should be fixed with the command above (assuming the issue is on the C drive and not an unmounted partition like the bootloader or the recovery partition).
The full logs may help identify more of the issue as well - like if the disk is not found (like it's going to sleep or something during the backup).
Steve Smith wrote:
David, thanks for answering my earlier questions - can you please zip the log files and upload them to this topic so that I can review the more detailed error message content that gets hidden in the Log View: Short version in the MVP Log Viewer tool (you can see this yourself by switching to Log View: Regular).
Thank you for trying to troubleshoot this with me. I've had a really really difficult time trying to use this software.
The full log file isn't much different from the short version. Here's one:
10/9/2019 6:23:16 PM: -04:00 15764 I00000000: -----
10/9/2019 6:23:16 PM: -04:00 15764 I00000000: ATI Demon started. Version: 23.5.1.17750.
10/9/2019 6:23:16 PM: -04:00 15764 I00640000: Backup reserve copy attributes: format tib; need_reserve_backup_copy false;
10/9/2019 6:23:16 PM: -04:00 15764 I00640002: Operation My disks started manually.
10/9/2019 6:23:19 PM: -04:00 15764 I00640000: Backup reserve copy attributes: format tib; need_reserve_backup_copy false;
10/9/2019 6:23:19 PM: -04:00 15764 I013C0000: Operation: Backup
10/9/2019 6:23:19 PM: -04:00 15764 I0064000B: Priority changed to Low.
10/9/2019 6:23:19 PM: -04:00 15764 I00180000: Preparing the media...
10/9/2019 6:23:19 PM: -04:00 15764 E0004000F: Error 0x4000f: Canceled.
| trace level: error
| line: 0x37dcad4ee29f425
| file: c:\bs_hudson\workspace\790\builder\lib\fdd_builder.cpp:548
| function: RemovableBuilder::PrepareMedia
| line: 0x37dcad4ee29f425, c:\bs_hudson\workspace\790\builder\lib\fdd_builder.cpp:548, RemovableBuilder::PrepareMedia
| $module: ti_demon_vs_17750
10/9/2019 6:23:19 PM: -04:00 15764 I000B03F0: Create Backup Archive From: Disk 1, Disk 2 To file: G:\My disks.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\david\AppData\Local\Temp, C:\Users\david\AppData\Local\Microsoft\Windows\INetCache, C:\Users\david\AppData\Local\Mozilla\Firefox\Profiles\*\cache2, C:\Users\david\AppData\Local\Mozilla\Firefox\Profiles\*\OfflineCache, C:\Users\david\AppData\Local\Opera Software\Opera Stable\Cache, C:\Users\david\AppData\Local\Opera Software\Opera Stable\Media Cache, C:\Users\david\AppData\Local\Google\Chrome\User Data\Default\Cache, C:\WINDOWS\CSC
10/9/2019 6:23:19 PM: -04:00 15764 I000101F8: Pending operation 173 started: 'Creating partition image'.
10/9/2019 6:24:00 PM: -04:00 15792 I00640000: Writing full version to file: My disks_full_b1_s1_v1.tib
10/9/2019 6:31:35 PM: -04:00 15764 I000101F8: Pending operation 173 started: 'Creating partition image'.
10/9/2019 6:32:52 PM: -04:00 15764 I000101F8: Pending operation 173 started: 'Creating partition image'.
10/9/2019 6:32:56 PM: -04:00 15764 I000101F8: Pending operation 173 started: 'Creating partition image'.
10/14/2019 1:42:43 PM: -04:00 15764 W013C0001: Terminated by user.
Start: 10/9/2019 6:23:16 PM
Stop: 10/14/2019 1:42:43 PM
Total Time: 4.19:19:27
Also, please check what your Options > Advanced > Error handling settings are?
What external drive are you using and how is this formatted?
It is a 6TB Seagate Backup Plus Hub formatted with NTFS
Is this the same drive that has been used without issue previously?
Yes. On September 4 it backed up successfully at 682.1Mbps. Then the disk was full. I did a cleanup versions and it now would take about 12 days to backup .
David, from the amount of time being taken by the backup here (nearly 5 days before failing), there are several possible reasons why the task will show as being Terminated by user including the system being shutdown or restarted (perhaps due to a Windows Update etc), or due to the connection to the drive closing etc.
If the estimate for the backup is being given at upto 12 days, then my initial thought would be to try to reduce the amount of data being included in the backup source. So instead of having: From: Disk 1, Disk 2 To file: G:\My disks.tib as shown in the log, split this backup to be of only one of these disks and make another backup of the other disk, especially if these are very large drives or contain a large amount of data. Keeping your backups to a single disk will make any future recovery a lot simpler, i.e. if Disk 1 fails, you only have to recover from a single, smaller backup image, not one containing both disks.
I just looked at the partitions in Acronis to try to set up the one drive at a trim backup that Bobbo_3C0X1 recommended I try and it looks like the G: drive actually has two partitions (one NTFS and one FAT32)
although when I looked at teh drive through Windows 10 it only showed NTFS
David, the FAT32 partition "Acronis HM" is a hidden partition created by True Image when you create a "survival kit" on the drive. That should be the bootable rescue media added to the drive so you can recover straight from it without needing a separate DVD or flash drive to boot from.
That said, did you try backing up each disk separately to see if you can identify if one can be identified as the culprit? The first drive, having hardly any data on it at all, should be a pretty quick test... and would ideally backup quickly and without issue. But if that hangs, then try the larger disk on its own to see if it completes successfully (or not) too. 3.8TB is going to take some time to backup, I wouldn't worry about the "estimated time" as that is going to be all over the place, but instead, let it run a good 12 hours to see how far along the progress bar is since that's typically how long backups seem to have taken in the past.
Bobbo_3C0X1 wrote:David, the FAT32 partition "Acronis HM" is a hidden partition created by True Image when you create a "survival kit" on the drive. That should be the bootable rescue media added to the drive so you can recover straight from it without needing a separate DVD or flash drive to boot from.
That said, did you try backing up each disk separately to see if you can identify if one can be identified as the culprit? The first drive, having hardly any data on it at all, should be a pretty quick test... and would ideally backup quickly and without issue. But if that hangs, then try the larger disk on its own to see if it completes successfully (or not) too. 3.8TB is going to take some time to backup, I wouldn't worry about the "estimated time" as that is going to be all over the place, but instead, let it run a good 12 hours to see how far along the progress bar is since that's typically how long backups seem to have taken in the past.
The smaller drive backed up in 8 minutes (15 with the verification). Trying the larger one now.
I created a backup of just the C: drive. Ran it overnight and it got through 227GB. By contrast the last time I backed up by partitions it took 11 hours and 22 minutes to do an incremental backup and validate, which is about what backing up by drives used to take.
So, it sounds like splitting the backups into 2 tasks is working successfully on both disks now? If so, I'd leave it be "as is" and let them run this way now. I can't say why the old backup task is/was not working now, but if you have a working solution now and you're OK with the setup, then you're back in business.
The next step, if you want, would be to create a completely new backup task (use a unique name too) and combine all disks in it (if you want - I still recommend keeping each physical disk separate), and see if that task completes or also errors out. If it completes, and the original still does not, we can chalk it up to a problem with that specific task and not necessarily the disks.
Bobbo_3C0X1 wrote:
So, it sounds like splitting the backups into 2 tasks is working successfully on both disks now?
No, I can back up the E: dirve in a reasonable amount of time but the C: drive takes forever. I can back up the whole system in a reasonable time if I choose to back up partitions.
If so, I'd leave it be "as is" and let them run this way now. I can't say why the old backup task is/was not working now, but if you have a working solution now and you're OK with the setup, then you're back in business.
The next step, if you want, would be to create a completely new backup task (use a unique name too) and combine all disks in it (if you want - I still recommend keeping each physical disk separate), and see if that task completes or also errors out. If it completes, and the original still does not, we can chalk it up to a problem with that specific task and not necessarily the disks.
I guess that I can back up using only partition backups and not using disk backups at all. However, that's not the entire point.
I've been using Acronis for a bit over a year now and I've had issues four times. Once was user stupidity but the other three have been genuine problems. Despite having error logs, spending days troubleshooting, and using both Acronis support and the community forums, I've never been able to pinpoint a cause for the issues. I'm eventually told to delete the task and set it back up and if the problem doesn't recur then I'm good. It is supremely unsatisfying and doesn't give me a warm fuzzy feeling that my data is safe. I am at a low point right now and can't really afford to deal with getting a new backup solution so I'll just make do for now but as somebody who had a career in IT I can't think of a lot of experiences with software where I have felt so bad about a product.
David, going back to basics again here.
What is the size of your C: drive, what type of drive is it, i.e. HDD or SSD, how many partitions does it have?
Have you performed a CHKDSK of all the partitions with drive letters?
Does this complete without errors?
Next, go to the drive maker support site and look for any diagnostic tools that will allow you to do a check of the whole drive, and if so, run these.
The drive is a conventional HD with an Intel Optane accelerator.Chkdsk finds no errors:
Windows PowerShell
Copyright (C) Microsoft Corporation. All rights reserved.
Try the new cross-platform PowerShell https://aka.ms/pscore6
PS C:\WINDOWS\system32> chkdsk c:
The type of the file system is NTFS.
Volume label is Windows.
WARNING! /F parameter not specified.
Running CHKDSK in read-only mode.
Stage 1: Examining basic file system structure ...
931072 file records processed.
File verification completed.
8991 large file records processed.
0 bad file records processed.
Stage 2: Examining file name linkage ...
13945 reparse records processed.
1223542 index entries processed.
Index verification completed.
0 unindexed files scanned.
0 unindexed files recovered to lost and found.
13945 reparse records processed.
Stage 3: Examining security descriptors ...
Security descriptor verification completed.
146236 data files processed.
CHKDSK is verifying Usn Journal...
41041160 USN bytes processed.
Usn Journal verification completed.
Windows has scanned the file system and found no problems.
No further action is required.
4768687 MB total disk space.
4447448 MB in 595902 files.
423720 KB in 146237 indexes.
0 KB in bad sectors.
1194719 KB in use by the system.
65536 KB occupied by the log file.
327330816 KB available on disk.
4096 bytes in each allocation unit.
1220784121 total allocation units on disk.
81832704 allocation units available on disk.
PS C:\WINDOWS\system32>
David, your screen shot shows a significant size difference between your C: drive and the E: drive (4.5TB versus 500GB) which partially explains why the backup of E: was much faster.
There are 2 hidden / system partitions (both very small) on your C: drive that cannot be checked using CHKDSK unless you can allocate a drive letter to them to permit this.
Even so, your C: drive only has 331.68GB free space (just 7% free space) out of 4656.92GB total size, which also reduces the space available for the MS VSS snapshot service to use when making a backup.
Ideally, I would recommend splitting the backup of C: into smaller chunks of data, i.e. make separate backup tasks for different types of data according to the sizes involved, i.e. make a backup of just your photos, or videos, or music etc depending on how large these are.
I bought a m.2 2TB drive and moved 489GB of the data from C: to try to increase the available space on C: The backup still runs at essentially the same speed.
The backup ran reasonably quickly until G: filled up and I deleted all of the backups and tried to start over and then it dropped suddenly but only if I back up by drive, not if I back up by partitions.
I will try to figure out how to assign drive letters to the hidden partitions to chkdsk them.
Figured out how to run chkdsk on the hidden partitions. As far as I can tell they are OK:
Possible values for VolumeName along with current mount points are:
\\?\Volume{7a398cd2-3800-4797-b7fc-15b031e8bcf8}\
H:\
\\?\Volume{1f15b033-67b7-4ff0-ba01-79307e9bca33}\
E:\
\\?\Volume{177af676-454c-43f0-87b1-cb3c0fd867c6}\
*** NO MOUNT POINTS ***
\\?\Volume{bf7d0d24-fe98-40cf-b813-f78d2a43c871}\
C:\
\\?\Volume{9bf93843-d06e-4374-a879-8bc694d16c53}\
G:\
\\?\Volume{24f85c97-acff-49e9-a13e-31a4e6da0551}\
F:\
\\?\Volume{3c5740cb-a3a8-4d02-ba17-a772e5d262c1}\
*** NO MOUNT POINTS ***
\\?\Volume{f9b811ee-d943-11e7-b2cd-806e6f6e6963}\
D:\
PS C:\WINDOWS\system32> chkdsk "\\?\Volume{3c5740cb-a3a8-4d02-ba17-a772e5d262c1}"
The type of the file system is FAT32.
Volume SYSTEM created 12/4/2017 2:17 PM
Volume Serial Number is 529C-E30D
Windows is verifying files and folders...
File and folder verification is complete.
Windows has scanned the file system and found no problems.
No further action is required.
100,663,296 bytes total disk space.
156,672 bytes in 8 hidden files.
51,200 bytes in 44 folders.
27,351,040 bytes in 132 files.
73,103,360 bytes available on disk.
1,024 bytes in each allocation unit.
98,304 total allocation units on disk.
71,390 allocation units available on disk.
PS C:\WINDOWS\system32>
chkdsk "\\?\Volume{177af676-454c-43f0-87b1-cb3c0fd867c6}"
The type of the file system is NTFS.
Volume label is Recovery.
WARNING! /F parameter not specified.
Running CHKDSK in read-only mode.
Stage 1: Examining basic file system structure ...
256 file records processed.
File verification completed.
0 large file records processed.
0 bad file records processed.
Stage 2: Examining file name linkage ...
284 index entries processed.
Index verification completed.
0 unindexed files scanned.
0 unindexed files recovered to lost and found.
0 reparse records processed.
0 reparse records processed.
Stage 3: Examining security descriptors ...
Security descriptor verification completed.
15 data files processed.
CHKDSK is verifying Usn Journal...
161520 USN bytes processed.
Usn Journal verification completed.
Windows has scanned the file system and found no problems.
No further action is required.
511999 KB total disk space.
438172 KB in 10 files.
76 KB in 16 indexes.
0 KB in bad sectors.
5167 KB in use by the system.
4224 KB occupied by the log file.
68584 KB available on disk.
4096 bytes in each allocation unit.
127999 total allocation units on disk.
17146 allocation units available on disk.
PS C:\WINDOWS\system32>