Skip to main content

TrueImage deleted backup immediately after finishing - why?

Thread solved

Why does TrueImage delete the backup that it just took 9 hours to create?

It created a full_b5 version, then once it finished it deleted it.

See log:

2020-07-18T17:04:35:464+09:00 21816 I00000000: -----
2020-07-18T17:04:35:464+09:00 21816 I00000000: ATI Demon started. Version: 23.5.1.17750.
2020-07-18T17:04:35:511+09:00 21816 I00640000: Backup reserve copy attributes: format tib; need_reserve_backup_copy false; 
2020-07-18T17:04:35:512+09:00 21816 I00640002: Operation hostToQnap started manually.
2020-07-18T17:04:38:080+09:00 21816 I00640000: Backup reserve copy attributes: format tib; need_reserve_backup_copy false; 
2020-07-18T17:04:38:093+09:00 21816 I013C0000: Operation: Backup
2020-07-18T17:04:38:098+09:00 21816 I0064000B: Priority changed to Low.
2020-07-18T17:04:40:954+09:00 21816 W01E50023: Error 0x1e50023: The specified file does not exist: \\QNAS1\Acronis\host\hostToQnap_full_b5_s1_v7.tib.
| trace level: warning
| line: 0x4d3f22948e29f19e
| file: c:\bs_hudson\workspace\790\products\imager\archive\impl\utils.cpp:199
| function: `anonymous-namespace'::GenerateGuiErrorWithPath
| line: 0x4d3f22948e29f19e, c:\bs_hudson\workspace\790\products\imager\archive\impl\utils.cpp:199, `anonymous-namespace'::GenerateGuiErrorWithPath
| $module: ti_demon_vs_17750
|
| error 0xb007f: The initial full backup version is not accessible at the moment.
| line: 0x65e40aa0b487193
| file: c:\bs_hudson\workspace\790\products\imager\archive\impl\operations\archive_operation_backup.cpp:770
| function: TrueImage::Archive::BackupArchiveOperationImpl::TraceFirstVolumeExistance
| line: 0x65e40aa0b487193, c:\bs_hudson\workspace\790\products\imager\archive\impl\operations\archive_operation_backup.cpp:770, TrueImage::Archive::BackupArchiveOperationImpl::TraceFirstVolumeExistance
| $module: ti_demon_vs_17750
|
| error 0x40011: The specified file does not exist.
| line: 0xf35f747b3b21fc69
| file: c:\bs_hudson\workspace\790\core\file\windows\winnt_dir.cpp:1376
| function: winnt_dir::iterator::iterator
| line: 0xf35f747b3b21fc69, c:\bs_hudson\workspace\790\core\file\windows\winnt_dir.cpp:1376, winnt_dir::iterator::iterator
| function: FindFirstFileW
| path: \\?\UNC\QNAS1\Acronis\host\hostToQnap_full_b5_s1_v7.tib
| $module: ti_demon_vs_17750
|
| error 0xfff0: The system cannot find the file specified
| line: 0xbd28fdbd64edb8f1
| file: c:\bs_hudson\workspace\790\core\common\error.cpp:307
| function: Common::Error::AddWindowsError
| line: 0xbd28fdbd64edb8f1, c:\bs_hudson\workspace\790\core\common\error.cpp:307, Common::Error::AddWindowsError
| code: 0x80070002
| $module: ti_demon_vs_17750
2020-07-18T17:04:41:018+09:00 21816 I000B03F0: Create Backup Archive From:       To file:        "nas://QNAS1/Acronis/host/hostToQnap.tib" Compression:    Normal File Split:      200 GB Exclude: Files matching mask Match criterion:    hiberfil.sys, pagefile.sys, $Recycle.Bin, swapfile.sys, System Volume Information, *.tib, *.tib.metadata, *.~, *.tmp, C:\Users\xxxx\AppData\Local\Temp, C:\Users\xxx\AppData\Local\Temp, C:\Users\xxxxx\AppData\Local\Microsoft\Windows\INetCache, C:\Users\xxxx\AppData\Local\Microsoft\Windows\INetCache, C:\Users\xxxxx\AppData\Local\Mozilla\Firefox\Profiles\*\cache2, C:\Users\xxxx\AppData\Local\Mozilla\Firefox\Profiles\*\OfflineCache, C:\Users\xxxx\AppData\Local\Opera Software\Opera Stable\Cache, C:\Users\xxxxx\AppData\Local\Opera Software\Opera Stable\Media Cache, C:\Users\xxxxx\AppData\Local\Google\Chrome\User Data\Default\Cache, C:\Users\xxxxxx\AppData\Local\Mozilla\Firefox\Profiles\*\cache2, C:\Users\xxxxx\AppData\Local\Mozilla\Firefox\Profiles\*\OfflineC
ache, C:\Users\xxxx\AppData\Local\Opera Software\Opera Stable\Cache, C:\Users\xxxx\AppData\Local\Opera Software\Opera Stable\Media Cache, C:\Users\xxxxx\AppData\Local\Google\Chrome\User Data\Default\Cache, C:\WINDOWS\CSC  
2020-07-18T17:04:41:025+09:00 21816 I000101F8: Pending operation 173 started: 'Creating partition image'.
2020-07-18T17:04:41:624+09:00 21816 I000101F8: Pending operation 173 started: 'Creating partition image'.
2020-07-18T17:04:41:878+09:00 22160 I00640000: Writing full version to file: hostToQnap_full_b5_s1_v1.tib
2020-07-18T17:04:42:024+09:00 21816 I000101F8: Pending operation 173 started: 'Creating partition image'.
2020-07-18T17:38:33:930+09:00 21816 I000101F8: Pending operation 173 started: 'Creating partition image'.
2020-07-18T17:38:38:871+09:00 21816 I000101F8: Pending operation 173 started: 'Creating partition image'.
2020-07-18T17:43:41:817+09:00 7076 I00640000: Writing full version to file: hostToQnap_full_b5_s1_v2.tib
2020-07-18T19:12:20:173+09:00 7076 I00640000: Writing full version to file: hostToQnap_full_b5_s1_v3.tib
2020-07-18T20:44:12:244+09:00 7076 I00640000: Writing full version to file: hostToQnap_full_b5_s1_v4.tib
2020-07-18T22:14:17:231+09:00 7076 I00640000: Writing full version to file: hostToQnap_full_b5_s1_v5.tib
2020-07-18T23:51:45:745+09:00 7076 I00640000: Writing full version to file: hostToQnap_full_b5_s1_v6.tib
2020-07-19T01:24:13:886+09:00 7076 I00640000: Writing full version to file: hostToQnap_full_b5_s1_v7.tib
2020-07-19T02:05:30:693+09:00 21816 I000101F8: Pending operation 173 started: 'Creating partition image'.
2020-07-19T02:05:30:696+09:00 21816 I000101F8: Pending operation 173 started: 'Creating partition image'.
2020-07-19T02:05:31:012+09:00 21816 I00640000: The following backups have been successfully created: "nas://QNAS1/Acronis/host/hostToQnap_full_b5_s1_v1.tib"
"nas://QNAS1/Acronis/host/hostToQnap_full_b5_s1_v2.tib"
"nas://QNAS1/Acronis/host/hostToQnap_full_b5_s1_v3.tib"
"nas://QNAS1/Acronis/host/hostToQnap_full_b5_s1_v4.tib"
"nas://QNAS1/Acronis/host/hostToQnap_full_b5_s1_v5.tib"
"nas://QNAS1/Acronis/host/hostToQnap_full_b5_s1_v6.tib"
"nas://QNAS1/Acronis/host/hostToQnap_full_b5_s1_v7.tib"
2020-07-19T02:05:31:738+09:00 21816 I000B0000: Consolidate Backup Archive Location:     "nas://QNAS1/Acronis/host/hostToQnap_full_b5_s1_v7.tib" Destination:      "nas://QNAS1/Acronis/host/hostToQnap_full_b5_s1_v7_6C8615E1-E5AC-46A2-8D18-19345BB7E08F.tib"  
2020-07-19T02:05:32:392+09:00 21816 E000B03E9: Error 0xb03e9: Failed to open data stream. Try to remove the backup from the list, add it again by clicking 'Add existing backup' and recreate the backup settings.
| trace level: error
| line: 0x6d5b4dcc0ba14815
| file: c:\bs_hudson\workspace\790\products\imager\archive\impl\operations\archive_operation_clone.cpp:2583
| function: TrueImage::Archive::CloneArchiveOperationImpl::SwitchToArchive
| line: 0x6d5b4dcc0ba14815, c:\bs_hudson\workspace\790\products\imager\archive\impl\operations\archive_operation_clone.cpp:2583, TrueImage::Archive::CloneArchiveOperationImpl::SwitchToArchive
| $module: ti_demon_vs_17750
|
| error 0x1e50006: The specified file does not exist.
| line: 0x6d5b4dcc0ba1465f
| file: c:\bs_hudson\workspace\790\products\imager\archive\impl\operations\archive_operation_clone.cpp:2145
| function: TrueImage::Archive::CloneArchiveOperationImpl::PrepareReadStream
| line: 0x6d5b4dcc0ba1465f, c:\bs_hudson\workspace\790\products\imager\archive\impl\operations\archive_operation_clone.cpp:2145, TrueImage::Archive::CloneArchiveOperationImpl::PrepareReadStream
| $module: ti_demon_vs_17750
|
| error 0x40011: The specified file does not exist.
| line: 0x132134cb418e750a
| file: c:\bs_hudson\workspace\790\products\imager\archive\impl\archive_data_stream_impl.cpp:1309
| function: TrueImage::Archive::GetArchiveVolumeInformation
| line: 0x132134cb418e750a, c:\bs_hudson\workspace\790\products\imager\archive\impl\archive_data_stream_impl.cpp:1309, TrueImage::Archive::GetArchiveVolumeInformation
| $module: ti_demon_vs_17750
2020-07-19T02:05:32:559+09:00 21816 I000B0000: Deleting backup file with path nas://QNAS1/Acronis/host/hostToQnap_inc_b5_s7_v1.tib.
2020-07-19T02:05:32:560+09:00 21816 I000B0000: Deleting backup file with path nas://QNAS1/Acronis/host/hostToQnap_inc_b5_s6_v1.tib.
2020-07-19T02:05:32:561+09:00 21816 I000B0000: Deleting backup file with path nas://QNAS1/Acronis/host/hostToQnap_inc_b5_s5_v1.tib.
2020-07-19T02:05:32:563+09:00 21816 I000B0000: Deleting backup file with path nas://QNAS1/Acronis/host/hostToQnap_inc_b5_s4_v1.tib.
2020-07-19T02:05:32:565+09:00 21816 I000B0000: Deleting backup file with path nas://QNAS1/Acronis/host/hostToQnap_inc_b5_s3_v1.tib.
2020-07-19T02:05:32:566+09:00 21816 I000B0000: Deleting backup file with path nas://QNAS1/Acronis/host/hostToQnap_inc_b5_s2_v1.tib.
2020-07-19T02:05:32:568+09:00 21816 I000B0000: Deleting backup file with path nas://QNAS1/Acronis/host/hostToQnap_full_b5_s1_v7.tib.
2020-07-19T02:05:40:320+09:00 21816 I000B0000: Deleting backup file with path nas://QNAS1/Acronis/host/hostToQnap_full_b5_s1_v6.tib.
2020-07-19T02:05:53:700+09:00 21816 I000B0000: Deleting backup file with path nas://QNAS1/Acronis/host/hostToQnap_full_b5_s1_v5.tib.
2020-07-19T02:06:10:327+09:00 21816 I000B0000: Deleting backup file with path nas://QNAS1/Acronis/host/hostToQnap_full_b5_s1_v4.tib.
2020-07-19T02:06:35:159+09:00 21816 I000B0000: Deleting backup file with path nas://QNAS1/Acronis/host/hostToQnap_full_b5_s1_v3.tib.
2020-07-19T02:06:53:993+09:00 21816 I000B0000: Deleting backup file with path nas://QNAS1/Acronis/host/hostToQnap_full_b5_s1_v2.tib.
2020-07-19T02:07:10:356+09:00 21816 I000B0000: Deleting backup file with path nas://QNAS1/Acronis/host/hostToQnap_full_b5_s1_v1.tib.
2020-07-19T02:07:17:100+09:00 21816 I013C0006: Operation has succeeded.
0 Users found this helpful

GT, welcome to these public User Forums.

From looking at your log data, it would suggest that you have been modifying the backup task settings and also possibly manually deleting backup files outside of using the ATI GUI options.

The first indication of this is in the lines:

Error 0x1e50023: The specified file does not exist: \\QNAS1\Acronis\host\hostToQnap_full_b5_s1_v7.tib.
| error 0xb007f: The initial full backup version is not accessible at the moment.
| error 0x40011: The specified file does not exist.
| function: FindFirstFileW
| path: \\?\UNC\QNAS1\Acronis\host\hostToQnap_full_b5_s1_v7.tib
| $module: ti_demon_vs_17750
| error 0xfff0: The system cannot find the file specified
| code: 0x80070002

ATI 2019 is looking for an existing file with the above name but does not find it!  It then starts a new backup for the b5 backup sequence using a file split size of 200GB, hence why you are seeing up to _v7 in the file names.

The log then shows success in creating the following files:

The following backups have been successfully created:
"nas://QNAS1/Acronis/host/hostToQnap_full_b5_s1_v1.tib"
"nas://QNAS1/Acronis/host/hostToQnap_full_b5_s1_v2.tib"
"nas://QNAS1/Acronis/host/hostToQnap_full_b5_s1_v3.tib"
"nas://QNAS1/Acronis/host/hostToQnap_full_b5_s1_v4.tib"
"nas://QNAS1/Acronis/host/hostToQnap_full_b5_s1_v5.tib"
"nas://QNAS1/Acronis/host/hostToQnap_full_b5_s1_v6.tib"
"nas://QNAS1/Acronis/host/hostToQnap_full_b5_s1_v7.tib"

The task then tries to perform automatic cleanup actions (shown as consolidation) but cannot find files on the target destination.

Consolidate Backup Archive Location:     "nas://QNAS1/Acronis/host/hostToQnap_full_b5_s1_v7.tib"
Destination:      "nas://QNAS1/Acronis/host/hostToQnap_full_b5_s1_v7_6C8615E1-E5AC-46A2-8D18-19345BB7E08F.tib"  
Error 0xb03e9: Failed to open data stream. Try to remove the backup from the list, add it again by clicking 'Add existing backup' and recreate the backup settings.
| error 0x1e50006: The specified file does not exist.
| error 0x40011: The specified file does not exist.

After the above error, automatic cleanup then starts deleting files that must have been created by an earlier run of the task when using different settings.

Deleting backup file with path
nas://QNAS1/Acronis/host/hostToQnap_inc_b5_s7_v1.tib.
nas://QNAS1/Acronis/host/hostToQnap_inc_b5_s6_v1.tib.
nas://QNAS1/Acronis/host/hostToQnap_inc_b5_s5_v1.tib.
nas://QNAS1/Acronis/host/hostToQnap_inc_b5_s4_v1.tib.
nas://QNAS1/Acronis/host/hostToQnap_inc_b5_s3_v1.tib.
nas://QNAS1/Acronis/host/hostToQnap_inc_b5_s2_v1.tib.
nas://QNAS1/Acronis/host/hostToQnap_full_b5_s1_v7.tib.
nas://QNAS1/Acronis/host/hostToQnap_full_b5_s1_v6.tib.
nas://QNAS1/Acronis/host/hostToQnap_full_b5_s1_v5.tib.
nas://QNAS1/Acronis/host/hostToQnap_full_b5_s1_v4.tib.
nas://QNAS1/Acronis/host/hostToQnap_full_b5_s1_v3.tib.
nas://QNAS1/Acronis/host/hostToQnap_full_b5_s1_v2.tib.
nas://QNAS1/Acronis/host/hostToQnap_full_b5_s1_v1.tib.
Operation has succeeded.

Note the files using s7 to s2 above which are incremental files not created by this backup task execution before the further new files are deleted.

I would recommend creating a new backup task, with a new, unique name and using the settings that you want to use from this point forward, including cleanup rules, and this should then behave as you expect it to do.

Sorry for the very tardy response. You're correct that I had needed to delete older archives (out of space on the destination). It does seem to be working OK as long as you don't manually delete. It just seemed a bit odd to delete the very files it just created.

Thanks for your response!

GT, ATI tracks all the files it creates in an internal database, so the issue with deleting any files in Explorer etc is simply that the database doesn't get updated which then causes other issues such as the one you have seen.

ATI 2019 introduced a new 'Clean up versions' tool that should be used to remove any unwanted backup files, where the tool correctly updates the database.