Skip to main content

Cryptic error message during consolidation/deleting old files

Thread needs solution
Beginner
Posts: 2
Comments: 5

I run Acronis True Image 2016 for backups on 3 different PCs. 2 show no errors, but the 3rd PC shows strange error messages when consolidating. This is an example:

<event id="11" level="2" module="485" code="14" time="1547103337" message="&lt;bold>Consolidate Backup Archive&lt;/bold>&lt;endl/>&lt;tabpoint value=30>&lt;indent value=4>Location:&#9;&lt;indent value=10>&lt;textcolor value=&quot;navyblue&quot;>&quot;\\wdnas1\public\Acronis\I10 D-drive\I10_D-drive_to_Z_full_b14_s1_v1.tib&quot;&lt;/textcolor>&lt;/indent>&lt;indent value=4>&lt;endl/>Destination:&#9;&lt;indent value=10>&lt;textcolor value=&quot;navyblue&quot;>&quot;\\wdnas1\public\Acronis\I10 D-drive\I10_D-drive_to_Z_full_b14_s1_v1_32DF3730-F56A-4594-AA51-5E2BB88D869C.tib&quot;&lt;/textcolor>&lt;/indent>&lt;indent value=4>&lt;endl/>&lt;/indent>&lt;endl/>" line_tag="0x6D5B4DCC0BA145CC" >
                <error>AQ4A5QHMRaELzE1bbTxib2xkPkNvbnNvbGlkYXRlIEJhY2t1cCBBcmNoaXZlPC9ib2xkPjxlbmRsLz48dGFicG9pbnQgdmFsdWU9MzA+PGluZGVudCB2YWx1ZT00PkxvY2F0aW9uOgk8aW5kZW50IHZhbHVlPTEwPjx0ZXh0Y29sb3IgdmFsdWU9Im5hdnlibHVlIj4iXFx3ZG5hczFccHVibGljXEFjcm9uaXNcSTEwIEQtZHJpdmVcSTEwX0QtZHJpdmVfdG9fWl9mdWxsX2IxNF9zMV92MS50aWIiPC90ZXh0Y29sb3I+PC9pbmRlbnQ+PGluZGVudCB2YWx1ZT00PjxlbmRsLz5EZXN0aW5hdGlvbjoJPGluZGVudCB2YWx1ZT0xMD48dGV4dGNvbG9yIHZhbHVlPSJuYXZ5Ymx1ZSI+Ilxcd2RuYXMxXHB1YmxpY1xBY3JvbmlzXEkxMCBELWRyaXZlXEkxMF9ELWRyaXZlX3RvX1pfZnVsbF9iMTRfczFfdjFfMzJERjM3MzAtRjU2QS00NTk0LUFBNTEtNUUyQkI4OEQ4NjlDLnRpYiI8L3RleHRjb2xvcj48L2luZGVudD48aW5kZW50IHZhbHVlPTQ+PGVuZGwvPjwvaW5kZW50PjxlbmRsLz4AJG1vZHVsZQBBdGlfZGVtb25fdnNfNjU5NQAkZmlsZQBBazpcNjU5NVxwcm9kdWN0c1xpbWFnZXJcYXJjaGl2ZVxpbXBsXG9wZXJhdGlvbnNcYXJjaGl2ZV9vcGVyYXRpb25fY2xvbmUuY3BwACRmdW5jAEFUcnVlSW1hZ2U6OkFyY2hpdmU6OkNsb25lQXJjaGl2ZU9wZXJhdGlvbkltcGw6OlByZXBhcmUAJGxpbmUATs4HAAAAAAAAAAcECwDMRaELzE1bbTxib2xkPkNvbnNvbGlkYXRlIEJhY2t1cCBBcmNoaXZlPC9ib2xkPjxlbmRsLz48dGFicG9pbnQgdmFsdWU9MzA+PGluZGVudCB2YWx1ZT00PkxvY2F0aW9uOgk8aW5kZW50IHZhbHVlPTEwPjx0ZXh0Y29sb3IgdmFsdWU9Im5hdnlibHVlIj4iXFx3ZG5hczFccHVibGljXEFjcm9uaXNcSTEwIEQtZHJpdmVcSTEwX0QtZHJpdmVfdG9fWl9mdWxsX2IxNF9zMV92MS50aWIiPC90ZXh0Y29sb3I+PC9pbmRlbnQ+PGluZGVudCB2YWx1ZT00PjxlbmRsLz5EZXN0aW5hdGlvbjoJPGluZGVudCB2YWx1ZT0xMD48dGV4dGNvbG9yIHZhbHVlPSJuYXZ5Ymx1ZSI+Ilxcd2RuYXMxXHB1YmxpY1xBY3JvbmlzXEkxMCBELWRyaXZlXEkxMF9ELWRyaXZlX3RvX1pfZnVsbF9iMTRfczFfdjFfMzJERjM3MzAtRjU2QS00NTk0LUFBNTEtNUUyQkI4OEQ4NjlDLnRpYiI8L3RleHRjb2xvcj48L2luZGVudD48aW5kZW50IHZhbHVlPTQ+PGVuZGwvPjwvaW5kZW50PjxlbmRsLz4AJG1vZHVsZQBBdGlfZGVtb25fdnNfNjU5NQAkZmlsZQBBazpcNjU5NVxwcm9kdWN0c1xpbWFnZXJcYXJjaGl2ZVxpbXBsXG9wZXJhdGlvbnNcYXJjaGl2ZV9vcGVyYXRpb25fY2xvbmUuY3BwACRmdW5jAEFUcnVlSW1hZ2U6OkFyY2hpdmU6OkNsb25lQXJjaGl2ZU9wZXJhdGlvbkltcGw6OlByZXBhcmUAJGxpbmUATs4HAAAAAAAAAA==</error>
        </event>

I would attach the full log file, but the upload doesn't allow me to, it only allows graphics :(

The consolidation is called when ATIH decides to delete the oldest full version and its associated incrementals. This is the only time the error message comes up, so I can't determine if it's the consolidation itself or the deletion, but I'd guess it's the consolidation, as the subsequent messages indicate the deletions went OK. The files certainly seem to be deleted from the disk. The backup itself also seems to be OK, both from the log file message "... backups have been successfully created" which comes before the consolidation starts, and from looking at the backup through the ATIH UI and browsing the file structures - I also successfully restored a single file a few days ago.

Does anyone have any thoughts, or even an explanation?

 

0 Users found this helpful
Beginner
Posts: 2
Comments: 5

Ahh, logs are allowed in comments, but not in the original topic item! :)

Attachment Size
485460-162624.log 8.34 KB
Legend
Posts: 46
Comments: 15425

Richard, thanks for posting the full log data, this doesn't actually show any real errors here, and the encoded error data is a red herring too as it just repeats the previous line (twice)!

You can use the MVP Log Viewer tool to read the log files much easier than trying to work around all the XML format data that is included.  Link to the tool in my signature.

log uuid=5FCC10B5-8B65-4E6B-85BF-00EC094F8774;  product=True Image;  version=19.0;  build=6595;  task=F1826E83-EC21-48C3-95F1-60465C89D64E;  task_name=I10_D-drive
Start= 10/01/2019 06:56:00
id=1;  date/time=10/01/2019 06:56:00;  message=Backup reserve copy attributes: format tib; need_reserve_backup_copy false
id=2;  date/time=10/01/2019 06:56:00;  message=Operation I10_D-drive started by schedule.
id=3;  date/time=10/01/2019 06:56:02;  message=Backup reserve copy attributes: format tib; need_reserve_backup_copy false
id=4;  date/time=10/01/2019 06:56:02;  message=Operation: Backup
id=5;  date/time=10/01/2019 06:56:02;  message=Priority changed to Low.
id=6;  date/time=10/01/2019 06:56:02;  message=Create Backup Archive From: Data (D:) To file: E:\Acronis\I10 D-drive backups\I10_D-drive.tib Compression: Normal 
id=7;  date/time=10/01/2019 06:56:02;  message=Pending operation 172 started: 'Creating partition image'.
id=8;  date/time=10/01/2019 06:57:24;  message=Writing full version to file: I10_D-drive_full_b25_s1_v1.tib
id=9;  date/time=10/01/2019 07:21:44;  message=Pending operation 172 started: 'Creating partition image'.
id=10;  date/time=10/01/2019 07:21:44;  message=The following backups have been successfully created: E:\Acronis\I10 D-drive backups\I10_D-drive_full_b25_s1_v1.tib
id=11;  date/time=10/01/2019 07:21:45;  message=Consolidate Backup Archive Location: E:\Acronis\I10 D-drive backups\I10_D-drive_full_b25_s1_v1.tib Destination: E:\Acronis\I10 D-drive backups\I10_D-drive_full_b25_s1_v1_0877077F-D3E0-4AFE-8381-2EC6DF249F9E.tib  
Error_Code=AQ4A5QHMRaELzE1bbTxib2xkPkNvbnNvbGlkYXRlIEJhY2t1cCBBcmNoaXZlPC9ib2xkPjxlbmRsLz48dGFicG9pbnQgdmFsdWU9MzA+PGluZGVudCB2YWx1ZT00PkxvY2F0aW9uOgk8aW5kZW50IHZhbHVlPTEwPjx0ZXh0Y29sb3IgdmFsdWU9Im5hdnlibHVlIj4iRTpcQWNyb25pc1xJMTAgRC1kcml2ZSBiYWNrdXBzXEkxMF9ELWRyaXZlX2Z1bGxfYjI1X3MxX3YxLnRpYiI8L3RleHRjb2xvcj48L2luZGVudD48aW5kZW50IHZhbHVlPTQ+PGVuZGwvPkRlc3RpbmF0aW9uOgk8aW5kZW50IHZhbHVlPTEwPjx0ZXh0Y29sb3IgdmFsdWU9Im5hdnlibHVlIj4iRTpcQWNyb25pc1xJMTAgRC1kcml2ZSBiYWNrdXBzXEkxMF9ELWRyaXZlX2Z1bGxfYjI1X3MxX3YxXzA4NzcwNzdGLUQzRTAtNEFGRS04MzgxLTJFQzZERjI0OUY5RS50aWIiPC90ZXh0Y29sb3I+PC9pbmRlbnQ+PGluZGVudCB2YWx1ZT00PjxlbmRsLz48L2luZGVudD48ZW5kbC8+ACRtb2R1bGUAQXRpX2RlbW9uX3ZzXzY1OTUAJGZpbGUAQWs6XDY1OTVccHJvZHVjdHNcaW1hZ2VyXGFyY2hpdmVcaW1wbFxvcGVyYXRpb25zXGFyY2hpdmVfb3BlcmF0aW9uX2Nsb25lLmNwcAAkZnVuYwBBVHJ1ZUltYWdlOjpBcmNoaXZlOjpDbG9uZUFyY2hpdmVPcGVyYXRpb25JbXBsOjpQcmVwYXJlACRsaW5lAE7OBwAAAAAAAAAHBAsAzEWhC8xNW208Ym9sZD5Db25zb2xpZGF0ZSBCYWNrdXAgQXJjaGl2ZTwvYm9sZD48ZW5kbC8+PHRhYnBvaW50IHZhbHVlPTMwPjxpbmRlbnQgdmFsdWU9ND5Mb2NhdGlvbjoJPGluZGVudCB2YWx1ZT0xMD48dGV4dGNvbG9yIHZhbHVlPSJuYXZ5Ymx1ZSI+IkU6XEFjcm9uaXNcSTEwIEQtZHJpdmUgYmFja3Vwc1xJMTBfRC1kcml2ZV9mdWxsX2IyNV9zMV92MS50aWIiPC90ZXh0Y29sb3I+PC9pbmRlbnQ+PGluZGVudCB2YWx1ZT00PjxlbmRsLz5EZXN0aW5hdGlvbjoJPGluZGVudCB2YWx1ZT0xMD48dGV4dGNvbG9yIHZhbHVlPSJuYXZ5Ymx1ZSI+IkU6XEFjcm9uaXNcSTEwIEQtZHJpdmUgYmFja3Vwc1xJMTBfRC1kcml2ZV9mdWxsX2IyNV9zMV92MV8wODc3MDc3Ri1EM0UwLTRBRkUtODM4MS0yRUM2REYyNDlGOUUudGliIjwvdGV4dGNvbG9yPjwvaW5kZW50PjxpbmRlbnQgdmFsdWU9ND48ZW5kbC8+PC9pbmRlbnQ+PGVuZGwvPgAkbW9kdWxlAEF0aV9kZW1vbl92c182NTk1ACRmaWxlAEFrOlw2NTk1XHByb2R1Y3RzXGltYWdlclxhcmNoaXZlXGltcGxcb3BlcmF0aW9uc1xhcmNoaXZlX29wZXJhdGlvbl9jbG9uZS5jcHAAJGZ1bmMAQVRydWVJbWFnZTo6QXJjaGl2ZTo6Q2xvbmVBcmNoaXZlT3BlcmF0aW9uSW1wbDo6UHJlcGFyZQAkbGluZQBOzgcAAAAAAAAA
id=12;  date/time=10/01/2019 07:21:45;  message=Consolidate Backup Archive Location: E:\Acronis\I10 D-drive backups\I10_D-drive_full_b25_s1_v1.tib Destination: E:\Acronis\I10 D-drive backups\I10_D-drive_full_b25_s1_v1_0877077F-D3E0-4AFE-8381-2EC6DF249F9E.tib  
id=13;  date/time=10/01/2019 07:21:45;  message=Deleting backup file with path E:\Acronis\I10 D-drive backups\I10_D-drive_inc_b20_s14_v1.tib.
id=14;  date/time=10/01/2019 07:21:45;  message=Deleting backup file with path E:\Acronis\I10 D-drive backups\I10_D-drive_inc_b20_s13_v1.tib.
id=15;  date/time=10/01/2019 07:21:45;  message=Deleting backup file with path E:\Acronis\I10 D-drive backups\I10_D-drive_inc_b20_s12_v1.tib.
id=16;  date/time=10/01/2019 07:21:45;  message=Deleting backup file with path E:\Acronis\I10 D-drive backups\I10_D-drive_inc_b20_s11_v1.tib.
id=17;  date/time=10/01/2019 07:21:45;  message=Deleting backup file with path E:\Acronis\I10 D-drive backups\I10_D-drive_inc_b20_s10_v1.tib.
id=18;  date/time=10/01/2019 07:21:45;  message=Deleting backup file with path E:\Acronis\I10 D-drive backups\I10_D-drive_inc_b20_s9_v1.tib.
id=19;  date/time=10/01/2019 07:21:45;  message=Deleting backup file with path E:\Acronis\I10 D-drive backups\I10_D-drive_inc_b20_s8_v1.tib.
id=20;  date/time=10/01/2019 07:21:45;  message=Deleting backup file with path E:\Acronis\I10 D-drive backups\I10_D-drive_inc_b20_s7_v1.tib.
id=21;  date/time=10/01/2019 07:21:45;  message=Deleting backup file with path E:\Acronis\I10 D-drive backups\I10_D-drive_inc_b20_s6_v1.tib.
id=22;  date/time=10/01/2019 07:21:45;  message=Deleting backup file with path E:\Acronis\I10 D-drive backups\I10_D-drive_inc_b20_s5_v1.tib.
id=23;  date/time=10/01/2019 07:21:45;  message=Deleting backup file with path E:\Acronis\I10 D-drive backups\I10_D-drive_inc_b20_s4_v1.tib.
id=24;  date/time=10/01/2019 07:21:45;  message=Deleting backup file with path E:\Acronis\I10 D-drive backups\I10_D-drive_inc_b20_s3_v1.tib.
id=25;  date/time=10/01/2019 07:21:45;  message=Deleting backup file with path E:\Acronis\I10 D-drive backups\I10_D-drive_inc_b20_s2_v1.tib.
id=26;  date/time=10/01/2019 07:21:45;  message=Deleting backup file with path E:\Acronis\I10 D-drive backups\I10_D-drive_full_b20_s1_v1.tib.
id=27;  date/time=10/01/2019 07:21:45;  message=Operation has succeeded.
Start= 10/01/2019 06:56:00
Finish= 10/01/2019 07:21:45
Total Time= 00:25:45

Beginner
Posts: 2
Comments: 5

Steve, that's interesting. How did you interpret the encoded message? That's what I was referring to when I called it cryptic. I use the log viewer, but I couldn't get it (or anything else) to decode the string.

Secondly, you say that this is isn't a real error. I'm rather inclined to agree with you - as I said above, the backups themselves look OK. However, ATI says "The last backup has failed" - see attached screen dump. This is the UI view of the state after the backup for which I attached the log file (finished at 07:21 in the log, at 08:21 on the UI - I've evidently not informed Acronis correctly of the local time offset).

And as you can see, it says the same thing for every single one of the backups on this machine ("I10" in the task name). I could ignore them, but then it would be a case of crying wolf, and I'd miss it if a real error occurred.

It would seem to be something to do with the program, as the 8 "failed" backups are from different sources: 4 partitions on 2 physical drives to different destinations: 2 different physical drives, 1 local within the PC and 1 NAS attached via a physical LAN, so it would not appear to be a hardware-related error. All the different combinations display the same "error" as the one in the log I attached. The "error" occurs when ATI determines that it must do some physical deletions on the destination because I set a limit on the number of backup chains. If no deletion is required on a particular run, there's no error message for that run.

Any thoughts or suggestions would be welcome.

Attachment Size
485550-162678.jpg 141.62 KB
Legend
Posts: 46
Comments: 15425

How did you interpret the encoded message? That's what I was referring to when I called it cryptic. I use the log viewer, but I couldn't get it (or anything else) to decode the string.

Richard, I copied the whole error string into Notepad++ (editor) then used the Base64 Decode plugin tool to expose the message text (not very pretty to read!).




I can only assume that there may be a bug in ATI 2017 with regard to the log showing that everything was done successfully but the GUI telling a different story here!  Unfortunately, ATI 2017 is long since out of support for any fixes so I can only suggest that you go by what the log is saying rather than the GUI unless you are willing to upgrade to ATI 2019 where you would have support should you still see a similar issue.  I have not seen any such problems myself and have systems running both ATI 2019 and 2018 versions.

Beginner
Posts: 2
Comments: 5

Steve

Thanks for the NotePad++ tip, I didn't think of anything like that. I don't think I'll be applying for a job at GCHQ any time soon :)

As for it being a problem that hasn't been seen before, that seems to be the story of my life. I'll have to consider upgrading - it's just that I don't need the new features, and I hate paying for something I already have if it works. But since it seems to have stopped working now, I'll probably go ahead.

Thanks for your attention.

Legend
Posts: 46
Comments: 15425

Richard, I suspect that the majority of people would fail the current entry tests for GCHQ unless you are a member of MENSA..! 

You may want to consider a 30-day trial copy of ATI 2019 to see just how different it is compared to your current ATI 2017, but make a backup of your OS drive as a fallback if needed.