Unscheduled backup happens on waking computer
So after getting ATI to properly read differences on an SD card to perform incremental backups, within a couple of days I observe strange behaviour.
The backup is set to daily at 2230 hours, which was fine initially. Nowadays whenever I wake the computer up during day time, ATI would immediately initiate another backup which remains stuck at 0% calculating the time.
If I stop it, the UI still shows up as stuck in that state. I have to reboot the entire system to snap ATI out of it, of which it would finally recognise a user cancel input event.
A couple of questions
- Why does it commence with backup at a timing it was not configured to?
- Why does this backup on wake remains stuck 0%?
- Why doesn't ATI respond properly to user STOP input? And requiring a reboot to take effect?
I've reconfigured the schedule to no avail. ATI just seems to want to do its own thing against my settings.
I have unscheduled and re-scheduled and it still goes with its own timing.
Aaron, if you have the MVP Log Viewer tool, please check the log files for your backup task to see if there any messages there that offer an explanation for what is happening here? The tool is available via the Community Tools link in my signature..
Also, check your Error Handling options on the Advance page for the task - I normally disable these so that if an error occurs it tells me instead of keep on retrying and spamming me with email notifications etc. Just wondering if the backup is restarting due to a previous error?
See KB 46205: Acronis Software: Troubleshooting Scheduled Backup Issues which has some suggestions that may be helpful.
The community tools only apply to versions 2017-2018.
For error handling, I typically set backups to ignore bad sectors.
I have disabled the Repeat attempt option, we'll see if that's the initial culprit.
Aaron, sorry but the statement about the 2017 - 2018 versions only applies to having an option in the GUI for the Community Tools. The MVP Log Viewer works with all versions from ATI 2015 onwards as shown by the Help text in the tool:
So on waking the computer today, yet again ATI initialises another (comatose) backup sequence for whatever reasons. The community tool does not show any log of the one currently "running" today, but I took a peek at a similar failed unscheduled attempt few days back
log uuid=3D8732BD-8289-428C-972A-F2A305FD2E6E; product=True Image; version=18.0; build=6613; task=95415547-1547-4CFB-8E25-D625080C788C; task_name=SanDisk128
Start= 4/5/2018 12:33:59
id=1; date/time=4/5/2018 12:33:59; message=Backup reserve copy attributes: format tib; need_reserve_backup_copy false
id=2; date/time=4/5/2018 12:34:00; message=Operation SanDisk128 started by schedule.
id=3; date/time=4/5/2018 12:34:00; message=Operation description: Stage Description.
id=4; date/time=4/5/2018 12:34:00; message=AcronisLRPCConnect::BEGIN id=11,420
id=5; date/time=4/5/2018 12:34:00; message=AcronisLRPCConnect::BEGIN id=908
id=6; date/time=4/5/2018 12:34:00; message=Retreiving Fdisk ver1 disk set to Fdisk ver2c disk set...
id=7; date/time=4/5/2018 12:34:00; message=Fdisk2: Use Disk 1 host= 0 bus = 0 target = 0
id=8; date/time=4/5/2018 12:34:00; message=Fdisk2: Use Disk 2 host= 0 bus = 0 target = 0
id=9; date/time=4/5/2018 12:34:00; message=Refreshing Drivers...
id=10; date/time=4/5/2018 12:34:00; message=Enter to process disks in Mbr Driver (id = 9)
id=11; date/time=4/5/2018 12:34:00; message=Exit from process disks in Mbr Driver (id = 9)
id=12; date/time=4/5/2018 12:34:00; message=Enter to process disks in Gpt Driver (id = 10)
id=13; date/time=4/5/2018 12:34:00; message=Try to load Alternate Header from 1000215215
id=14; date/time=4/5/2018 12:34:00; message=Gpt Disk 9E253870-2326-4E32-8BBE-7E476385298C LBA=1000215215 ALBA=1
id=15; date/time=4/5/2018 12:34:00; message=try to loading Header from 1
id=16; date/time=4/5/2018 12:34:00; message=Gpt Disk 9E253870-2326-4E32-8BBE-7E476385298C LBA=1 ALBA=1000215215
id=17; date/time=4/5/2018 12:34:00; message=Exit from process disks in Gpt Driver (id = 10)
id=18; date/time=4/5/2018 12:34:00; message=LDM: New ProcessDisks(rawLayer, headLayer)
id=19; date/time=4/5/2018 12:34:00; message=ProcessDisks: One more disk to check
id=20; date/time=4/5/2018 12:34:00; message=ProcessDisks: One more disk to check
id=21; date/time=4/5/2018 12:34:00; message=Mark All groups as Root Like Dgs
id=22; date/time=4/5/2018 12:34:00; message=------ Volumes Objects ------
id=23; date/time=4/5/2018 12:34:00; message=LDM initialization complete
id=24; date/time=4/5/2018 12:34:00; message=Analyzing partition '0-0'...
id=25; date/time=4/5/2018 12:34:00; message=Analyzing partition '1-1'...
id=26; date/time=4/5/2018 12:34:00; message=Analyzing partition 'C:'...
id=27; date/time=4/5/2018 12:34:00; message=Analyzing partition '1-4'...
id=28; date/time=4/5/2018 12:34:01; message=Analyzing partition '0-0'...
id=29; date/time=4/5/2018 12:34:01; message=Analyzing partition 'A:'...
id=30; date/time=4/5/2018 12:34:01; message=Backup reserve copy attributes: format tib; need_reserve_backup_copy false
id=31; date/time=4/5/2018 12:34:01; message=Operation: backup
id=32; date/time=4/5/2018 12:34:01; message=Priority changed to Low.
id=33; date/time=4/5/2018 12:34:01; message=Cannot access the path: E:\Acronis Backups\SanDisk128_full_b1_s1_v1.tib; line_tag=0x4D3F22948E29F1C0
Error_Code=ASMA5QHA8SmOlCI/TUNhbm5vdCBhY2Nlc3MgdGhlIHBhdGg6IEU6XEFjcm9uaXMgQmFja3Vwc1xTYW5EaXNrMTI4X2Z1bGxfYjFfczFfdjEudGliACRtb2R1bGUAV0M6XFByb2dyYW0gRmlsZXMgKHg4NilcQ29tbW9uIEZpbGVzXEFjcm9uaXNcVHJ1ZUltYWdlSG9tZVxUcnVlSW1hZ2VIb21lU2VydmljZS5leGUAAH8ACwBFcUgLqkBeBlRoZSBpbml0aWFsIGZ1bGwgYmFja3VwIHZlcnNpb24gaXMgbm90IGFjY2Vzc2libGUgYXQgdGhlIG1vbWVudC4AAC0ABAAG/CE7e3Rf81RoZSBzcGVjaWZpZWQgZmlsZSBwYXRoIGRvZXMgbm90IGV4aXN0LgBmdW5jdGlvbgBBRmluZEZpcnN0RmlsZVcAcGF0aABXXFw/XEU6XEFjcm9uaXMgQmFja3Vwc1xTYW5EaXNrMTI4X2Z1bGxfYjFfczFfdjEudGliACRtb2R1bGUATgAAAAAAAAAAAPD/AADDuO1kvf0ovVRoZSBzeXN0ZW0gY2Fubm90IGZpbmQgdGhlIHBhdGggc3BlY2lmaWVkAGNvZGUATgMAB4AAAAAAAA==
id=34; date/time=4/5/2018 12:34:01; message=The initial full backup version is not accessible at the moment.; line_tag=0x65E40AA0B487145; hide=1
id=35; date/time=4/5/2018 12:34:01; message=The specified file path does not exist.; line_tag=0xF35F747B3B21FC06; hide=1
id=36; date/time=4/5/2018 12:34:01; message=The system cannot find the path specified; line_tag=0xBD28FDBD64EDB8C3; hide=1
id=37; date/time=4/5/2018 12:34:01; message=The specified file path does not exist.; line_tag=0xF35F747B3B21F8E2
Error_Code=AS0ABADi+CE7e3Rf81RoZSBzcGVjaWZpZWQgZmlsZSBwYXRoIGRvZXMgbm90IGV4aXN0LgBmdW5jdGlvbgBBT3BlbkZpbGVXAHBhdGgAV1xcP1xFOlxBY3JvbmlzIEJhY2t1cHNcU2FuRGlzazEyOF9pbmNfYjFfczRfdjEudGliACRtb2R1bGUATgAAAAAAAAAAAPD/AADDuO1kvf0ovVRoZSBzeXN0ZW0gY2Fubm90IGZpbmQgdGhlIHBhdGggc3BlY2lmaWVkAGNvZGUATgMAB4AAAAAAAA==
id=38; date/time=4/5/2018 12:34:01; message=The system cannot find the path specified; line_tag=0xBD28FDBD64EDB8C3; hide=1
id=39; date/time=4/5/2018 12:44:01; message=Cannot access the path: E:\Acronis Backups\SanDisk128_inc_b1_s4_v1.tib; line_tag=0x4D3F22948E29F1C0
Error_Code=ASMA5QHA8SmOlCI/TUNhbm5vdCBhY2Nlc3MgdGhlIHBhdGg6IEU6XEFjcm9uaXMgQmFja3Vwc1xTYW5EaXNrMTI4X2luY19iMV9zNF92MS50aWIAJG1vZHVsZQBXQzpcUHJvZ3JhbSBGaWxlcyAoeDg2KVxDb21tb24gRmlsZXNcQWNyb25pc1xUcnVlSW1hZ2VIb21lXFRydWVJbWFnZUhvbWVTZXJ2aWNlLmV4ZQAA6QMLAEpvSAuqQF4GQ2hlY2sgd2hldGhlciB0aGUgc291cmNlIGFuZCBkZXN0aW5hdGlvbiBwYXJ0aXRpb25zIGV4aXN0LgAADwAEAElpP2pnq44dQ2FuY2VsZWQuAAAtAAQA4vghO3t0X/NUaGUgc3BlY2lmaWVkIGZpbGUgcGF0aCBkb2VzIG5vdCBleGlzdC4AZnVuY3Rpb24AQU9wZW5GaWxlVwBwYXRoAFdcXD9cRTpcQWNyb25pcyBCYWNrdXBzXFNhbkRpc2sxMjhfaW5jX2IxX3M0X3YxLnRpYgAkbW9kdWxlAE4AAAAAAAAAAADw/wAAw7jtZL39KL1UaGUgc3lzdGVtIGNhbm5vdCBmaW5kIHRoZSBwYXRoIHNwZWNpZmllZABjb2RlAE4DAAeAAAAAAAA=
id=40; date/time=4/5/2018 12:44:01; message=Check whether the source and destination partitions exist.; line_tag=0x65E40AA0B486F4A; hide=1
id=41; date/time=4/5/2018 12:44:01; message=Canceled.; line_tag=0x1D8EAB676A3F6949; hide=1
id=42; date/time=4/5/2018 12:44:01; message=The specified file path does not exist.; line_tag=0xF35F747B3B21F8E2; hide=1
id=43; date/time=4/5/2018 12:44:01; message=The system cannot find the path specified; line_tag=0xBD28FDBD64EDB8C3; hide=1
id=44; date/time=4/5/2018 12:44:02; message=ServerLRPC::_CloseConnection id=11,420
id=45; date/time=4/5/2018 12:44:02; message=ServerLRPC::_CloseConnection id=908
id=46; date/time=4/5/2018 12:44:02; message=ServerLRPC::_CloseConnection id=908
id=47; date/time=4/5/2018 12:44:02; message=ServerLRPC::_CloseConnection id=11,420
id=48; date/time=4/5/2018 12:44:02; message=Operation has completed with errors.; line_tag=0x9F2C53C72E8BCE18
Error_Code=AQUAPAEYzosux1Msn09wZXJhdGlvbiBoYXMgY29tcGxldGVkIHdpdGggZXJyb3JzLgAkbW9kdWxlAFdDOlxQcm9ncmFtIEZpbGVzICh4ODYpXENvbW1vbiBGaWxlc1xBY3JvbmlzXFRydWVJbWFnZUhvbWVcVHJ1ZUltYWdlSG9tZVNlcnZpY2UuZXhlAAA=
Start= 4/5/2018 12:33:59
Finish= 4/5/2018 12:44:02
Total Time= 00:10:03
So it reports cannot access path to the backup files. Well, the hard drive is sitting right there (connected via USB hub) and I can view it via Windows Explorer. And for sure the backup settings for my laptop's main SSD has no such problem (same backup folder path), although scheduled on a weekly basis.
I do not see any information that suggests why ATI wants to perform a backup everyday when I wake from sleep; I did not call for it. And then there's the question why it cannot access the backup drive/folder.
Ok today's situation is slightly different. When I open up ATI it does not indicate a backup sequence in progress. This time round only the taskbar icon is reporting it (0% as usual).
I am honestly confused with what ATI itself thinks it's doing.
Aaron, given the errors shown in the log you posted above, I would recommend deleting this backup task and creating a new task with a different/unique name and pointing to a new target folder (if possible).
The alternative would be to try reselecting both the Source and Destination for this task, assuming that you haven't already tried this?
Another option would be to use the Acronis Scheduler Manager to do a clean out of all schedule entries - run the schedmgr.exe as Administrator then in the new command prompt window, run 'get list' to get a list of all the tasks that are currently present, so you have an idea of how many such tasks are present.
If you want to dig deeper to see what these tasks are, then compare the information in the listing with the files in the C:\Program Data\Acronis\TrueImageHome\Scripts folder - you should see files that match the long names shown. You can then open these files in Notepad to see which task each is refering to (in the XML data near the top of the file).
Using the Scheduler Manager tool, you can issue 'task zap' to remove all schedule entries and make a clean start again. You will need to edit each of your ATI tasks to reset any Schedules. Or else you can follow the instructions in the KB document for the tool to remove individual tasks using the tool.
I set Acronis Scheduler Manager set logflags support and it seemed to produce three log files at C:\Program Files (x86)\Common Files\Acronis\Schedule2\Logs , attached below.
If I see the list of scheduled tasks, it reports
inst=rlx start=yes loc task=0-0 > get list
Id ExecApp ExecCmd
--- ---------------
CurUser 1 (ARMS\icela):
1-3 ~*TrueImageHomeNotify* /dummy /script:"EFFA6885-08C7-4090-845D-D7FD0A979BC6" /uuid:"EFFA6885-08C7-4090-845D-D7FD0A979BC6" /run_mode:?RunMode?
1-6 ~*TrueImageHomeNotify* /dummy /script:"0A4F02ED-8679-4976-B99A-63D7B306A6AE" /uuid:"0A4F02ED-8679-4976-B99A-63D7B306A6AE" /run_mode:?RunMode?
1-7 ~*TrueImageHomeNotify* /dummy /script:"D6ECC27B-EDE3-48CC-9E5D-41D6445F6489" /uuid:"D6ECC27B-EDE3-48CC-9E5D-41D6445F6489" /run_mode:?RunMode?
1-9 ~*TrueImageHomeNotify* /dummy /script:"69737964-4822-42AC-A507-4519179A188E" /uuid:"69737964-4822-42AC-A507-4519179A188E" /run_mode:?RunMode?
1-11 ~*TrueImageHomeNotify* /dummy /script:"D7C18ECA-648D-4877-BE0E-4C7EC682B60C" /uuid:"D7C18ECA-648D-4877-BE0E-4C7EC682B60C" /run_mode:?RunMode?
1-14 ~*TrueImageHomeNotify* /dummy /script:"95415547-1547-4CFB-8E25-D625080C788C" /uuid:"95415547-1547-4CFB-8E25-D625080C788C" /run_mode:?RunMode?
1-15 C:\Program Files (x86)\Acronis\TrueImageHome\TrueImageMonitor.exe /shutup
User 2 (NT AUTHORITY\SYSTEM):
2-1 ~C:\Program Files (x86)\Acronis\TrueImageHome\prl_stat.exe for_scheduler
2-2
2-3
2-4
2-5
2-6
C:\ProgramData\Acronis\TrueImageHome\Scripts only seems to have three in the folder though,
- 95415547-1547-4CFB-8E25-D625080C788C.tib.tis
- D7C18ECA-648D-4877-BE0E-4C7EC682B60C.tib.tis
- EFFA6885-08C7-4090-845D-D7FD0A979BC6.tib.tis
95415547-1547-4CFB-8E25-D625080C788C.tib.tis is the one that pertains to the backup of the SD card but I found no scheduling details in the XML elements.
I cannot tell from the available information where the extraneous scheduling comes from.
Aaron, sorry but the log files don't really tell me anything more than we already know here.
Personally, I would use the Scheduler Manager to do a clean out of all current schedule entries by using 'task zap' then go into the ATI GUI and set the schedule for any of your actual tasks that are using one.
There is no schedule information in the script XML files that you can access and no other information provided by Acronis on how their scheduling works 'under the covers'.
Well I don't know, now the backup task doesn't inexplicably pop on waking the computer up during the day. Did it somehow correct itself, I cannot tell. If this self-starts do arise again in future, I will attempt a schedule wipe with ASM to see if that helps. Thanks.