Skip to main content

Why multiple volumes at different times?

Thread needs solution

I'm a new user, and just in the process of getting our backup schedules transferred from our old system (ie. apologies if this is just something dumb!)

Currently, I just have a single backup setup to run nightly at around midnight. This is set up as a version chain taking a folder/file backup of some critical folders. It all appears to be working as expected, other than when the full rolls around, when I'm getting two backup image files of the form;

...._full_b<n>_s1_v1 (~50Mb)

...._full_b<n>_s1_v2 (~320 Mb)

Why is it splitting this into two volumes? I've had a peek under the Options for the backup, and Backup Splitting is set to its default of "automatic". Would this cause this?

Also puzzling is that whereas the incrementals are happening around midnight, the full (last 2 cycles) was not scheduled until around 2:30 in the afternoon. The "prevent the computer going to sleep" is ticked, so should not have been a hibernation issue.

Thanks for any clarification

Andrew.

0 Users found this helpful

Andrew, please can you clarify which version/build of Acronis True Image you are using here, and what Windows OS this is installed / running on?

Further, what is the destination for your nightly backups and how is this formatted, i.e. NTFS, FAT32 etc?

If you are using ATIH 2015, 2016 or 2017 then please download / use the MVP Log Viewer app (link below or in the sticky posts in this forum) and use this to look at what messages are posted to the backup log for your task where you are seeing the two backup files created?

I'm running True Image 2017, build 8053, running on Windows 10. The source of the backup is both local and NAS (QNAP) storage, and the backups are written back to NAS storage (at the moment the same NAS as some of the data is being sourced from).

Now to the logs - I won't pretend to understand everything in these! Other than the first (incremental) log, I've copied these in full, as I'm not sure what is relevant. Apologies for the noise. 

Thanks for any enlightenment!

Andrew

The last incremental shows this starting at 11:59 (scheduled time) as expected. This all appears to complete fine, but all the incrementals seem to report the same error (?) regarding failure to create a snapshot. I haven't a clue the seriousness of this, as they all seem to complete fine.

2017-06-10 23:59:01:352 13496 I00640000: Backup reserve copy attributes: format tib; need_reserve_backup_copy false;
2017-06-10 23:59:01:352 13496 I00640002: Operation AratikaData started by schedule.
2017-06-10 23:59:01:961 13496 I00640000: Backup reserve copy attributes: format tib; need_reserve_backup_copy false;
2017-06-10 23:59:01:961 13496 I013C0000: Operation: Backup
2017-06-10 23:59:01:961 13496 I0064000B: Priority changed to Low.
2017-06-10 23:59:26:230 13496 I0017001A: Error 0x17001a: Failed to create snapshot for backup.

The next log following this, is the first of the full backup runs. There is nothing I can see that indicates why this was deferred to 2:12 PM. This has obviously failed, but its a bit cryptic as to why?

2017-06-12 14:12:49:522 4864 I00640000: Backup reserve copy attributes: format tib; need_reserve_backup_copy false;
2017-06-12 14:12:49:524 4864 I00640002: Operation AratikaData started by schedule.
2017-06-12 14:12:50:137 4864 I00640000: Backup reserve copy attributes: format tib; need_reserve_backup_copy false;
2017-06-12 14:12:50:152 4864 I013C0000: Operation: Backup
2017-06-12 14:12:50:154 4864 I0064000B: Priority changed to Low.
2017-06-12 14:12:50:943 4864 W01E50023: Error 0x1e50023: The specified file does not exist: .
| trace level: warning
| line: 0x4d3f22948e29f1c8
| file: k:\8053\products\imager\archive\impl\utils.cpp:241
| function: `anonymous-namespace'::GenerateGuiErrorWithPath
| line: 0x4d3f22948e29f1c8, k:\8053\products\imager\archive\impl\utils.cpp:241, `anonymous-namespace'::GenerateGuiErrorWithPath
| $module: ti_demon_vs_8053
|
| error 0xb007f: The initial full backup version is not accessible at the moment.
| line: 0x65e40aa0b48716d
| file: k:\8053\products\imager\archive\impl\operations\archive_operation_backup.cpp:732
| function: TrueImage::Archive::BackupArchiveOperationImpl::TraceFirstVolumeExistance
| line: 0x65e40aa0b48716d, k:\8053\products\imager\archive\impl\operations\archive_operation_backup.cpp:732, TrueImage::Archive::BackupArchiveOperationImpl::TraceFirstVolumeExistance
| $module: ti_demon_vs_8053
|
| error 0xb00eb: The specified file does not exist.
| line: 0xd460020904af2928
| file: k:\8053\products\imager\archive\impl\volume_location.cpp:143
| function: TrueImage::Archive::VolumeLocation::OpenDir
| line: 0xd460020904af2928, k:\8053\products\imager\archive\impl\volume_location.cpp:143, TrueImage::Archive::VolumeLocation::OpenDir
| $module: ti_demon_vs_8053
|
| error 0x40011: The specified file does not exist.
| line: 0xadf8677805d429c6
| file: k:\8053\home\network\impl\network_impl.cpp:231
| function: Network::ConvertToCommonError
| line: 0xadf8677805d429c6, k:\8053\home\network\impl\network_impl.cpp:231, Network::ConvertToCommonError
| $module: ti_demon_vs_8053
|
| error 0xfff0: The network path was not found
| line: 0xbd28fdbd64edb8f1
| file: k:\8053\common\error.cpp:307
| function: Common::Error::AddWindowsError
| line: 0xbd28fdbd64edb8f1, k:\8053\common\error.cpp:307, Common::Error::AddWindowsError
| code: 0x80070035
| $module: ti_demon_vs_8053
2017-06-12 14:12:52:703 4864 E01E50023: Error 0x1e50023: The specified file does not exist: .
| trace level: error
| line: 0x4d3f22948e29f1c8
| file: k:\8053\products\imager\archive\impl\utils.cpp:241
| function: `anonymous-namespace'::GenerateGuiErrorWithPath
| line: 0x4d3f22948e29f1c8, k:\8053\products\imager\archive\impl\utils.cpp:241, `anonymous-namespace'::GenerateGuiErrorWithPath
| $module: ti_demon_vs_8053
|
| error 0xb03e9: Cannot open the backup.
| line: 0x65e40aa0b486f50
| file: k:\8053\products\imager\archive\impl\operations\archive_operation_backup.cpp:191
| function: TrueImage::Archive::BackupArchiveOperationImpl::Prepare
| line: 0x65e40aa0b486f50, k:\8053\products\imager\archive\impl\operations\archive_operation_backup.cpp:191, TrueImage::Archive::BackupArchiveOperationImpl::Prepare
| $module: ti_demon_vs_8053
|
| error 0xb00eb: The specified file does not exist.
| line: 0xd460020904af2928
| file: k:\8053\products\imager\archive\impl\volume_location.cpp:143
| function: TrueImage::Archive::VolumeLocation::OpenDir
| line: 0xd460020904af2928, k:\8053\products\imager\archive\impl\volume_location.cpp:143, TrueImage::Archive::VolumeLocation::OpenDir
| $module: ti_demon_vs_8053
|
| error 0x40011: The specified file does not exist.
| line: 0xadf8677805d429c6
| file: k:\8053\home\network\impl\network_impl.cpp:231
| function: Network::ConvertToCommonError
| line: 0xadf8677805d429c6, k:\8053\home\network\impl\network_impl.cpp:231, Network::ConvertToCommonError
| $module: ti_demon_vs_8053
|
| error 0xfff0: The network path was not found
| line: 0xbd28fdbd64edb8f1
| file: k:\8053\common\error.cpp:307
| function: Common::Error::AddWindowsError
| line: 0xbd28fdbd64edb8f1, k:\8053\common\error.cpp:307, Common::Error::AddWindowsError
| code: 0x80070035
| $module: ti_demon_vs_8053
2017-06-12 14:12:53:218 4864 E013C0005: Error 0x13c0005: Operation has completed with errors.
| trace level: error
| line: 0x9f2c53c72e8bcea1
| file: k:\8053\products\imager\demon\main.cpp:683
| function: main
| line: 0x9f2c53c72e8bcea1, k:\8053\products\imager\demon\main.cpp:683, main
| $module: ti_demon_vs_8053

 

The next log follows this, starting at 2:13, and appears to be the run that generates the two volumes. Nothing sticks out for me why it has done this.

I went and had a look at the image file it keeps moaning about (DSCN1363.JPG), and also unsure what the problem is here - this is an old JPG file buried in one of the directories, and I'm totally certain nothing would have been touching this in any way when the backup was running. The only thing in any way different from this file from any others in this directory would be its size - it just happened to be one of the biggest at just over 3Mb? Not sure if this is relevant or not, but does make me wonder if this is somehow related to network delays?

 

2017-06-12 14:13:24:429 6240 I00640000: Backup reserve copy attributes: format tib; need_reserve_backup_copy false;
2017-06-12 14:13:24:445 6240 I00640002: Operation AratikaData started by schedule.
2017-06-12 14:13:25:039 6240 I00640000: Backup reserve copy attributes: format tib; need_reserve_backup_copy false;
2017-06-12 14:13:25:039 6240 I013C0000: Operation: Backup
2017-06-12 14:13:25:039 6240 I0064000B: Priority changed to Low.
2017-06-12 14:13:46:690 6240 I0017001A: Error 0x17001a: Failed to create snapshot for backup.
| trace level: information
| line: 0x616ad0806a6302a6
| file: k:\8053\archive\sel_dir.cpp:1435
| function: Seldir::SelectedDir::MakeSnapshot
| line: 0x616ad0806a6302a6, k:\8053\archive\sel_dir.cpp:1435, Seldir::SelectedDir::MakeSnapshot
| $module: ti_demon_vs_8053
2017-06-12 14:13:46:692 6240 I000B03F0: Create Backup Archive From: C:\Accounting18\Forms\
C:\Data\
\\ARATIKA-NAS\Public\Aratika\Data\
To file: AratikaData_full_b2_s1_v1.tib Compression: Normal Exclude: System files, Files matching mask Match criterion: hiberfil.sys, pagefile.sys, $Recycle.Bin, swapfile.sys, System Volume Information, *.tib, *.tib.metadata, *.~, *.tmp, C:\Users\defaultuser0\AppData\Local\Temp, C:\Users\Andrew\AppData\Local\Temp, C:\Users\VisualSVNService\AppData\Local\Temp, C:\Users\defaultuser0\AppData\Local\Microsoft\Windows\INetCache, C:\Users\Andrew\AppData\Local\Microsoft\Windows\INetCache, C:\Users\VisualSVNService\AppData\Local\Microsoft\Windows\INetCache, C:\Users\Andrew\AppData\Local\Google\Chrome\User Data\Default\Cache, C:\Users\Andrew\AppData\Local\Opera Software, C:\Users\Andrew\AppData\Local\Mozilla\Firefox\Profiles, C:\Users\Andrew\AppData\Local\Google\Chrome\User Data\Default\Cache, C:\Users\Andrew\AppData\Local\Opera Software, C:\Users\Andrew\AppData\Local\Mozilla\Firefox\Profiles, C:\Users\Andrew\AppData\Local\Google\Chrome\User Data\Default\Cache, C:\Users\Andrew\AppData\Local\Opera Software, C:\Users\Andrew\AppData\Local\Mozilla\Firefox\Profiles, C:\windows\CSC
2017-06-12 14:14:04:051 12880 I00640000: Writing full version to file: AratikaData_full_b2_s1_v1.tib
2017-06-12 14:19:03:055 12880 E00040003: Error 0x40003: Error occurred while writing the file.
| trace level: error
| line: 0x1d8eab676a3f6af0
| file: k:\8053\products\imager\archive\impl\operations\archive_message_callback.cpp:1223
| function: TrueImage::Archive::ArchiveMsgWriteCallbackProcessor::ProcessWriteCallback
| line: 0x1d8eab676a3f6af0, k:\8053\products\imager\archive\impl\operations\archive_message_callback.cpp:1223, TrueImage::Archive::ArchiveMsgWriteCallbackProcessor::ProcessWriteCallback
| Path: nas://ARATIKA-NAS/Public/Archive/Aratika/AratikaData_full_b2_s1_v1.tib
| $module: ti_demon_vs_8053
|
| error 0x40003: Error occurred while writing the file.
| line: 0x7ceb2cdc9fb121ae
| file: k:\8053\file\windows\win32_file.cpp:517
| function: win32_nocache_file::Write
| line: 0x7ceb2cdc9fb121ae, k:\8053\file\windows\win32_file.cpp:517, win32_nocache_file::Write
| function: WriteFileNoCache
| $module: ti_demon_vs_8053
|
| error 0xfff0: The network is busy
| line: 0xbd28fdbd64edb8f1
| file: k:\8053\common\error.cpp:307
| function: Common::Error::AddWindowsError
| line: 0xbd28fdbd64edb8f1, k:\8053\common\error.cpp:307, Common::Error::AddWindowsError
| code: 0x80070036
| $module: ti_demon_vs_8053
2017-06-12 14:19:03:055 6240 E00170027: Failed to back up file or folder '\\?\UNC\ARATIKA-NAS\Public\Aratika\Data\Projects\Farm\House\DSCN1363.JPG'. It may be blocked by another application.
Failed to back up the file. (0x170027)
Path = "\\?\UNC\ARATIKA-NAS\Public\Aratika\Data\Projects\Farm\House\DSCN1363.JPG",
$module = "ti_demon_vs_8053"
Archive::BackupOperationContext::OnError:
k:\8053\archive\backuper.cpp(805)
Error occurred while reading the file. (0x40001)
$module = "ti_demon_vs_8053"
ChunkNTBackupStream:
k:\8053\file\ntstream_chunker.cpp(273)
Error occurred while reading the file. (0x40001)
$module = "ti_demon_vs_8053"
`anonymous-namespace'::ReadStreamData:
k:\8053\file\ntstream_chunker.cpp(193)
Failed to back up the file (folder). (0x40019)
Path = "\\?\UNC\ARATIKA-NAS\Public\Aratika\Data\Projects\Farm\House\DSCN1363.JPG",
Hints = 1),
$module = "ti_demon_vs_8053"
`anonymous-namespace'::NTBackupStream::Read:
k:\8053\file\windows\winnt_backup.cpp(817)
An unexpected network error occurred (0xFFF0)
code = 8007003B),
$module = "ti_demon_vs_8053"
Common::Error::AddWindowsError:
k:\8053\common\error.cpp(307) : None
2017-06-12 14:19:33:057 12880 I00040003: Error 0x40003: Reattempting the operation. Error: Error occurred while writing the file..
| trace level: information
| line: 0x1d8eab676a3f6690
| file: k:\8053\products\imager\archive\impl\operations\archive_message_callback.cpp:103
| function: `anonymous-namespace'::TraceReattemptError
| line: 0x1d8eab676a3f6690, k:\8053\products\imager\archive\impl\operations\archive_message_callback.cpp:103, `anonymous-namespace'::TraceReattemptError
| $module: ti_demon_vs_8053
|
| error 0x40003: Error occurred while writing the file.
| line: 0x1d8eab676a3f6af0
| file: k:\8053\products\imager\archive\impl\operations\archive_message_callback.cpp:1223
| function: TrueImage::Archive::ArchiveMsgWriteCallbackProcessor::ProcessWriteCallback
| line: 0x1d8eab676a3f6af0, k:\8053\products\imager\archive\impl\operations\archive_message_callback.cpp:1223, TrueImage::Archive::ArchiveMsgWriteCallbackProcessor::ProcessWriteCallback
| Path: nas://ARATIKA-NAS/Public/Archive/Aratika/AratikaData_full_b2_s1_v1.tib
| $module: ti_demon_vs_8053
|
| error 0x40003: Error occurred while writing the file.
| line: 0x7ceb2cdc9fb121ae
| file: k:\8053\file\windows\win32_file.cpp:517
| function: win32_nocache_file::Write
| line: 0x7ceb2cdc9fb121ae, k:\8053\file\windows\win32_file.cpp:517, win32_nocache_file::Write
| function: WriteFileNoCache
| $module: ti_demon_vs_8053
|
| error 0xfff0: The network is busy
| line: 0xbd28fdbd64edb8f1
| file: k:\8053\common\error.cpp:307
| function: Common::Error::AddWindowsError
| line: 0xbd28fdbd64edb8f1, k:\8053\common\error.cpp:307, Common::Error::AddWindowsError
| code: 0x80070036
| $module: ti_demon_vs_8053
2017-06-12 14:19:33:065 12880 I00640000: Writing full version to file: AratikaData_full_b2_s1_v2.tib
2017-06-12 14:26:14:384 6240 E00040019: Failed to back up file or folder 'DSCN1363.JPG'. It may be blocked by another application.
Error occurred while backing up. (0x40019)
$module = "ti_demon_vs_8053"
`anonymous-namespace'::BackuperHelper::WriteNodeData:
k:\8053\archive\backuper.cpp(758)
Error occurred while reading the file. (0x40001)
$module = "ti_demon_vs_8053"
ChunkNTBackupStream:
k:\8053\file\ntstream_chunker.cpp(273)
Error occurred while reading the file. (0x40001)
$module = "ti_demon_vs_8053"
`anonymous-namespace'::ReadStreamData:
k:\8053\file\ntstream_chunker.cpp(193)
Failed to back up the file (folder). (0x40019)
Path = "\\?\UNC\ARATIKA-NAS\Public\Aratika\Data\Projects\Farm\House\DSCN1363.JPG",
Hints = 1),
$module = "ti_demon_vs_8053"
`anonymous-namespace'::NTBackupStream::Read:
k:\8053\file\windows\winnt_backup.cpp(817)
An unexpected network error occurred (0xFFF0)
code = 8007003B),
$module = "ti_demon_vs_8053"
Common::Error::AddWindowsError:
k:\8053\common\error.cpp(307) : None
2017-06-12 14:26:15:759 6240 W00170019: Error 0x170019: The item was skipped.
| trace level: warning
| line: 0xce542e14da203a81
| file: k:\8053\archive\backuper.cpp:610
| function: `anonymous-namespace'::BackuperHelper::SkipNodes
| line: 0xce542e14da203a81, k:\8053\archive\backuper.cpp:610, `anonymous-namespace'::BackuperHelper::SkipNodes
| Path: //ARATIKA-NAS/Public/Aratika/Data/Projects/Farm/House/DSCN1363.JPG
| $module: ti_demon_vs_8053
2017-06-12 14:30:25:453 6240 I00640000: The following backups have been successfully created: nas://ARATIKA-NAS/Public/Archive/Aratika/AratikaData_full_b2_s1_v1.tib
nas://ARATIKA-NAS/Public/Archive/Aratika/AratikaData_full_b2_s1_v2.tib
2017-06-12 14:30:27:256 6240 I013C0006: Operation has succeeded.
Start: 12/06/2017 2:13:24 PM
Stop: 12/06/2017 2:30:27 PM
Total Time: 00:17:03

Andrew, thank you for confirming your ATIH 2017 version/build and also the source/target details.

The first point that I would make is the KISS principle - Keep It Simple...  you are mixing both local and network resources for both your source and destination and this will make it very much more difficult to isolate different issues involved here.

I would recommend having separate backup tasks, one for local source data, another for the NAS source data.

The snapshot messages may be simply caused because of having the NAS as source - the NAS is not running Windows and therefore cannot create snapshots but is being presented as if it were a Windows source.  This has been seen a number of times previously.

One of the changes in ATIH 2017 is the ability to choose the snapshot method, including having no snapshot, and by having a separate backup task for the NAS source data, you can eliminate these snapshot errors by using that option.  See KB 59440: Acronis True Image 2017: 'Snapshot for backup' option overview for details on using this option.

The other errors shown in the log look to be network related, so again running these tasks separately will help to start to isolate why this is showing.

Thanks for the advice (and treating me gently!)

My overall strategy with the migration is to get as much data as possible off the local drives, so there is minimal machine dependency, but I'd still like to keep the backups logically complete. The local drive data in this case is a couple of IDE environments which performed dismally running off the NAS, so have been retained on a Windows drive (which happens to be an SSD, which amplifies the difference even more).

I'm thinking of setting this up with a simple pre-op to copy these complete IDE structures up to the NAS at backup time, at which point the backup source can be pure NAS. I'll keep you posted how this works, but will need to wait for a complete version chain to run through so will be a few days.

Regards

Andrew