Strange things happened with ATI 22500 on wife's PC

Irv, please fix the failing drive as a first measure here, that will only continue to cause other problems if not dealt with!

Next, do NOT delete the 12KB .tibx file you saw in the list of your files - this is a vital file containing metadata and will break the backup if deleted!

The known issue with Backup Settings did exactly as you have observed in terms of resetting settings for all tasks back to default incremental tasks, no cleanup, no notifications etc.  This has now been fixed at the Acronis server side but requires users to reconfigure their task settings.

See the following KB documents published by Acronis with regards to .tibx files.

KB 63518: Acronis True Image 2020: do not delete first tibx file

KB 63227: Acronis True Image: Do not delete .TIB or .TIBX files outside of Acronis True Image

KB 63498: Acronis True Image 2020: new tibx backup format FAQ

KB 63425: Acronis True Image 2020: Limitations of tibx backups

KB 63516: Acronis True Image 2020: Incremental backups do not create separate files when using new backup format

KB 63445: Acronis True Image 2020: how to view and manage backup versions in new backup format

KB 63444: Acronis True Image 2020: tibx backups in local destinations

KB 63613: Acronis True Image: local backups are not available for recovery if "metadata" file appears in the backup destination - if you see metadata file(s).

Steve, thanks. I knew better than mess with that small file so I did leave it. Just wondering if it was needed or was an aborted backup.

I'll replace the drive, like I said, it doesn't hold anything that can't be replaced, either junk, temp, or backup that is done often of some pictures. So I didn't feel there was a rush... but I suspect like you said, it will come back to bite me if I don't.

I'll look at all the referenced links.

Still unsure of the time it takes to do backups? Her time is SIGNIFICANTLY longer than mine, as is the size.

For instance here is my log:

2019-12-27T09:00:00:570-05:00 15416 I00000000: -----
2019-12-27T09:00:00:570-05:00 15416 I00000000: ATI Demon started. Version: 24.5.1.22510.
2019-12-27T09:00:00:732-05:00 15416 I00640000: Backup reserve copy attributes: format tib; need_reserve_backup_copy false;
2019-12-27T09:00:00:732-05:00 15416 I00640002: Operation My disks started by schedule.
2019-12-27T09:00:18:166-05:00 15416 I00640000: Backup reserve copy attributes: format tib; need_reserve_backup_copy false;
2019-12-27T09:00:18:167-05:00 15416 I013C0000: Operation: Backup
2019-12-27T09:00:18:168-05:00 15416 I0064000B: Priority changed to Low.
2019-12-27T10:20:12:410-05:00 15416 I013C0006: Operation has succeeded.

Start: 12/27/2019 9:00:00 AM
Stop: 12/27/2019 10:20:12 AM
Total Time: 01:20:12

1/7th of the time it takes her PC to do a backup?

My backup folder (same model USB drive on 3.0 port):

P:\Acronis_Backup\All Drives>dir
 Volume in drive P is P_Drive
 Volume Serial Number is 6C93-8314

 Directory of P:\Acronis_Backup\All Drives

12/27/2019  09:00 AM    <DIR>          .
12/27/2019  09:00 AM    <DIR>          ..
12/06/2019  09:47 AM   238,902,841,344 My disks-0001.tibx
12/13/2019  10:11 AM   240,459,694,080 My disks-0002.tibx
12/20/2019  10:08 AM   237,416,771,584 My disks-0003.tibx
12/27/2019  10:20 AM   236,526,641,152 My disks-0004.tibx
11/29/2019  08:52 AM   247,224,197,120 My disks.tibx
               5 File(s) 1,200,530,145,280 bytes
               2 Dir(s)  2,362,424,700,928 bytes free

Approximately 40% the size of her backups. If everything were equal, one would expect her backup then to take 2 1/2 times as long as mine, or say 3 1/2 hours, not over 8 hours?

I'll assume there was more processing needed to be done to compress files, but over 8 hours total?

I'm going to keep watching the usage percentage on the USB drive on both our PC's when it is backing up. I can only assume when the drive hits 100% that it basically limits what ATI can do? The usual Write speed is normal for a USB drive from what I've seen on the web, 25MBs. However, both of our PC's have the property set to Quick Disconnect and do not need to use Safely Remove (Hot Swapping). Other way is to Cache the writes but must use Safely Remove before disconnecting. I've just changed her PC to Cache as I think the write delays might have caused a buffer buildup that slowed ATI processing possibly. We'll see next week (of if I get a chance, a test run) to see if that speeds it up?

The best USB ports to use for backup purposes are those on the back I/O panel that are direct to the motherboard.  Other ports like case mounted ones are subject to poor quality which translates into performance issues like you see here.

Although using the I/O panel ports can be inconvenient the are the best option.  Hubs can also have similar issues.  Most of the auxiliary ports on the market are of marginal quality, most make in China, and should be avoided.

Enchantech wrote:

The best USB ports to use for backup purposes are those on the back I/O panel that are direct to the motherboard.  Other ports like case mounted ones are subject to poor quality which translates into performance issues like you see here.

 

True, that is why I checked. This is a Dell XPS and it has ports on the back which are directly part of the planar, 2 2.0 ports on the top (connected via wires to the planar) and 2 3.0 ports on the front (also connected via wire to the planar). It is connected on the back.

It is quite possible the USB 2.0 device on the HUB could be slowing stuff down, but not from the write speeds Task Manager is showing for the USB drive? When I get a chance I might revisit the connections and see what I can do about this. The reason for the HUB was I didn't to bring cables out to the front of the box to connect to the 3.0 ports as I was afraid they could be snapped off as they would stick out.

Irv,

To expand a bit more on the USB connections issue, the problem with most of the cheap versions, including most case mounted ones, are that they lack in providing sufficient power to external HDD's.  Most will only provide around 1 volt.

The best hubs on the market are externally powered and provide a solid 5v @ 3amps.  I have had very good luck with Anker products found on Amazon.  A couple of links provided below.

Anker 7 port hub

Anker 10 port hub

Sabrent 7 port hub

Irv, the default ti_demon logs (as you have posted in this topic) contain minimum information of any diagnostic value - that detailed information has been moved to the backup_worker logs but are a lot harder to read!

It is possible that the failing drive is getting involved here, even if simply by being present on the same SATA bus and causing interrupts etc.

The backup_worker log may show whether the backup is dropping into sector-by-sector mode because of any disk errors.

If possible to do so try disconnecting the failing drive if it isn't directly involved in either the backup source or destination.

Enchantech wrote:

Irv,

To expand a bit more on the USB connections issue, the problem with most of the cheap versions, including most case mounted ones, are that they lack in providing sufficient power to external HDD's.  Most will only provide around 1 volt.

I got 2 of these from Amazon, https://www.amazon.com/gp/product/B00JX1ZS5O/ref=ppx_yo_dt_b_search_asin_title?ie=UTF8&th=1, and it implies 5V... but that might be with a AC PSU that I do not have.

On my PC it didn't work that well (Dell XPS 8700), caused me some 'sleep' issues with the PC. Would not 'come back' our of sleep using the keyboard or mouse (USB dongle, 2.0, Logitech is on the device) so I just disabled sleep and only the display is powered down in the Power Profile. There is warnings about keyboards and mice on the product and others have complained about it.

My External (and my wife's XPS8500) is directly connected to the 3.0 back port.

When I get a chance I think once I get the replacement drive for the one 'failing' I think I'll run some tests for backup timing on that replaced drive and the USB using a new backup plan. Might get some real meaningful data that way?

Still, I think the root problem is the saturation to 100% usability of the USB drive when only ATI is accessing it is the problem? My PC time is reasonable, and even with the long times, on the PC's we don't even know it is running. I might just conclude it is what it is and live with it?

There is an Advanced Option for Shutdown after completion but that wouldn't work for us, but I might have to change the start time if I want to use that.

Steve Smith wrote:

The backup_worker log may show whether the backup is dropping into sector-by-sector mode because of any disk errors.

If possible to do so try disconnecting the failing drive if it isn't directly involved in either the backup source or destination.

I'll try to find those logs when I get a chance to get on her PC?

No, drive is not in the backup plan.

I'd think she'd see other problems if that drive was hitting the bus? Slow loading programs, delays getting data off the disks, bringing in e-mail, all sorts of things. She's not complained of that?

Did have one situation where a program locked the disk and it hung as the disk did go down it seemed. Reboot solved that.

Irv, if sharing the log(s) in the forum, please zip them to preserve the original file name(s) to make it easier to process them.  The logs are found in C:\ProgramData\Acronis\TrueImageHome\Logs\backup_worker and the log names include the date & time of when the task was run.

Steve, OK, found it, but there is more than one?

I think the one in Yellow is the full one, size matches the others above? Maybe the smaller ones happen each time I would open ATI?

ZIP attached with all from 1/1/20

Irv, the backup worker logs do not show any specific problem but only one of the tasks looks to have run through to completion correctly, the others look to have been cancelled?

See the attached revised zip file with the logs formatted to make them easier to read.

Steve, yes, it is easier to read. I did see this part in the log as well in its 'raw' form:

==================

01/01/2020 17:49:19  type=log; level=inf;  message=  
ar#1: archive_slice_create(sid=28,type=inc,user_type=full,uuid=00000000000000000000000000000000,ctime=0);  
 
01/02/2020 02:09:21  type=log; level=inf;  message=  
ar#1: archive_slice_finish(sid=28); 

===================

Maybe you put some together?

I zipped the 3 prior backups for you;

Last one has these as the start and end lines:

==============

2019-12-25T10:00:02:908-05:00 2160 I00000000: >>> --id=10001 --action=browse --agent="Acronis True Image 2020 24.5.1.22510 Win" --archive="M:\\Acronis Backup\\All_Drives\\LARAINE-C, D, and E.tibx"

2019-12-25T11:00:37:623-05:00 2160 I00000000: >>> exit

===============

Just  a little over an hour, and according to ATI it was a FULL backup?

Here is a much older one that has been deleted that I KNOW was FULL, same set of lines with the long pause:

==========

2019-10-23T10:00:26:145-04:00 14028 I00000000: type=log; level=inf; message=ar#1: archive_slice_create(sid=10,type=inc,user_type=full,uuid=00000000000000000000000000000000,ctime=0);

2019-10-23T15:00:04:600-04:00 14028 I00000000: type=log; level=inf; message=ar#1: archive_slice_finish(sid=10);

===========

Only 3 hours. What happens during that period would help explain things.I guess?

I am NOT totally sure if the 3 logs are for a Full or Incremental backup though, but it is attached in the ZIP.

Irv, in the log file output, it tells you what type of backup was being created.

12/11/2019 15:00:02  type=log; level=inf;  message=  
ar#1: archive_slice_create(sid=21,type=inc,user_type=inc,uuid=00000000000000000000000000000000,ctime=0);

It also repeats the breakdown of the file types in the backup shown on the main Backup page for the task:

12/11/2019 15:57:15  type=stat; total_nr=2286458; total_sz=716267281025; pics_nr=1392825; pics_sz=128448357987; music_nr=226859; music_sz=66559282661; video_nr=27376; video_sz=70002271963; docs_nr=35454; docs_sz=492712020; sys_nr=160; sys_sz=209231189; others_nr=603784; others_sz=450555425205; id=1;  

The total_sz is the uncompressed size in bytes etc.

All 3 of the new logs were for incremental backup actions.

OK Steve, these 3 should be FULL then, and did take about 3 hours I recall?

For instance from the 10/23 log:

============

2019-10-23T10:00:26:145-04:00 14028 I00000000: type=log; level=inf; message=ar#1: archive_slice_create(sid=10,type=inc,user_type=full,uuid=00000000000000000000000000000000,ctime=0);

2019-10-23T15:00:04:600-04:00 14028 I00000000: type=log; level=inf; message=ar#1: archive_slice_finish(sid=10);

================

5 hour time difference, but it could be the base for an INCR?

The 10/16 should be full then according to this?

=========

2019-10-16T10:00:07:876-04:00 3812 I00000000: type=log; level=inf; message=ar#1: archive_slice_start_chain_ex(type=full);

=========

It too was over 5 hours:

=========

2019-10-16T10:00:28:585-04:00 3812 I00000000: type=log; level=inf; message=ar#1: archive_slice_create(sid=8,type=inc,user_type=full,uuid=00000000000000000000000000000000,ctime=0);

2019-10-16T15:33:24:663-04:00 3812 I00000000: type=log; level=inf; message=ar#1: archive_slice_finish(sid=8);

===========

Can't find a smoking gun as to why?

New drive should be in tomorrow and I'd do some testing then.

Irv, the further logs show incremental backups.

10/09/2019 15:00:02  type=log; level=inf;  message=  
ar#1: archive_slice_start_chain_ex(type=full);  
 
10/09/2019 15:00:02  type=log; level=inf;  message=  
io#1: start new vol 2 at 0x1134795b000;  
 
10/09/2019 15:00:02  type=log; level=inf;  message=  
ar#1: archive_slice_create(sid=5,type=full,user_type=full,uuid=00000000000000000000000000000000,ctime=0);
 
10/09/2019 15:00:21  type=log; level=inf;  message=  
ar#1: archive_slice_create(sid=6,type=inc,user_type=full,uuid=00000000000000000000000000000000,ctime=0);
 
10/09/2019 18:42:22  type=log; level=inf;  message=  
ar#1: archive_slice_finish(sid=6);  
 
10/09/2019 18:42:22  type=log; level=inf;  message=  
ar#1: archive closing; 

------------------------------------------

10/16/2019 15:00:07  type=log; level=inf;  message=  
ar#1: archive_slice_start_chain_ex(type=full);  
 
10/16/2019 15:00:07  type=log; level=inf;  message=  
io#1: start new vol 3 at 0x19dcc164000;  
 
10/16/2019 15:00:07  type=log; level=inf;  message=  
ar#1: archive_slice_create(sid=7,type=full,user_type=full,uuid=00000000000000000000000000000000,ctime=0);
 
10/16/2019 15:00:28  type=log; level=inf;  message=  
ar#1: archive_slice_create(sid=8,type=inc,user_type=full,uuid=00000000000000000000000000000000,ctime=0);
 
10/16/2019 20:33:24  type=log; level=inf;  message=  
ar#1: archive_slice_finish(sid=8);  
 
10/16/2019 20:33:25  type=log; level=inf;  message=  
ar#1: archive closing;

------------------------------------------

10/23/2019 15:00:01  type=log; level=inf;  message=  
ar#1: archive_slice_start_chain_ex(type=full);  
 
10/23/2019 15:00:01  type=log; level=inf;  message=  
io#1: start new vol 4 at 0x227af0a7000;  
 
10/23/2019 15:00:01  type=log; level=inf;  message=  
ar#1: archive_slice_create(sid=9,type=full,user_type=full,uuid=00000000000000000000000000000000,ctime=0);
 
10/23/2019 15:00:26  type=log; level=inf;  message=  
ar#1: archive_slice_create(sid=10,type=inc,user_type=full,uuid=00000000000000000000000000000000,ctime=0);
 
10/23/2019 20:00:04  type=log; level=inf;  message=  
ar#1: archive_slice_finish(sid=10);  
 
10/23/2019 20:00:04  type=log; level=inf;  message=  
ar#1: archive closing;

------------------------------------------

The first inc backup took 3 hours, then the next 2 took 5 hours each.

OK Steve, it is clear I don't know how to read the log :-)

Old drive is OUT now. New one I'm repopulating with a few files.

I'll start another backup soon.

I looked at all my connections and the USB 3.0 Hub is NOT needed. Had enough ports to handle the 3 devices connected to it. That will remove that which had a USB 2.0 device connected to it out of the equation as well.

Question, the period of time where there is no entry into that log, it anything logged somewhere else?

" The first inc backup took 3 hours, then the next 2 took 5 hours each. "

I guess I don't understand how that could happen? Settings are set to both not allow and wake up from Sleep/Hibernation? I am positively sure she didn't add files between those instances, at least not enough to almost double the time it took to backup?

Sorry Irv, I haven't found where any other information is logged during the long 'quiet' periods shown in the backup_worker logs!  If there is such information then it may not be in a human readable format!

Steve, OK, too bad, that would probably shed some light here.

I'm starting a new backup now on the PC... will post time it too later and the LOG if it is still odd?

Thanks.

Steve, it finished, 8 1/2 hours later...

Worker file of course had a large time gap:

2020-01-03T08:36:50:756-05:00 5596 I00000000: type=log; level=inf; message=ar#1: archive_slice_create(sid=30,type=inc,user_type=full,uuid=00000000000000000000000000000000,ctime=0);

2020-01-03T17:06:03:414-05:00 5596 I00000000: type=log; level=inf; message=ar#1: archive_slice_finish(sid=30);

Of course during the backup the M: USB drive saturated at 100%

See both Task Manager and Performance Monitor:

Disk M: is the USB drive of course.

As you can see above, most of the activity is to M:.

My wife has slew of games, mostly from Gamehouse (doesn't delete them when finished), and of course almost all the data in those folders would be binary, in some case trying to compress them actually could result in larger files even. There are about 1/2 the backup size too:

D:\Games

     Total Files Listed:
           1315391 File(s) 351,894,177,737 bytes
           348755 Dir(s)  47,771,758,592 bytes free

E:\Games

     Total Files Listed:
             995 File(s)    922,537,290 bytes
             104 Dir(s)  90,321,567,744 bytes free

I'm wondering if it would be worth it to exclude those two folders and make another backup? 

Reason being I suspect the time spent on trying to compress those folders is wasted time and possibly causing some other internal ATI problems handling the USB drive and saturating it, that is sending data faster than it can write it?

Since those 2 folders are around 1/2 the backup, if they were excluded and it took a little over 4 hours to do the backup, then it would indicate those folders are not the problem but something else might be?

For reference, here are the last two backups:

01/02/2020  06:00 AM   602,449,760,256 LARAINE-C, D, and E-0009.tibx
01/03/2020  05:06 PM   597,296,885,760 LARAINE-C, D, and E-0010.tibx

For some reason the last one is smaller, and I don't know why it would be 5GB's smaller as I don't recall anything deleted but she probably moved some email to trash?

Confusing...

Irv,

I've been following along here and I'm curious, have you considered running the backup from this PC while it is booted to the bootable recovery media? 

You can use the media to continue the backup by selecting it as an existing backup during the setup.  Doing this will test if there is some underlying issue that is Windows specific or something else.  Example would be that you leave exclusions as is and run the backup with all internal disks offline.  If the backup completes in your expected time range of 3 to 4 hours then this would suggest an issue with Windows or the installed TI app.  If 8 + hours then your theory of the games data being at issue may be true.

The bootable media has a logs feature that you can review after the backup as well that may give further clues if an issue does exist.  You can save that log to any destination you like and then post it here if you wish.  To save right click on the log, select Save as, and then designate a location to save the file.

Enchantech wrote:

Irv,

I've been following along here and I'm curious, have you considered running the backup from this PC while it is booted to the bootable recovery media?

Good idea. Would probably have to run it overnight though. PC couldn't be used when it was run, while it normally can be during a backup.

I was also thinking of creating a new backup scenario using Folders and Files for just those two.

Enchantech wrote:

If the backup completes in your expected time range of 3 to 4 hours then this would suggest an issue with Windows or the installed TI app.  If 8 + hours then your theory of the games data being at issue may be true.

I am not sure though if it did work faster how I would know which was the problem, W10 or ATI?

I really suspect that the problem is basically the files. Having worked on compression code I know sometimes it could result in larger files. Trying to compress a ZIP file usually winds up with a larger file. It is a lot faster to compress a file with many repeating 'bytes' than one with very few repeating ones. Binary files are usually non-repeating. Some game files are possibly compressed already too.

I have already started the test of the 2 folder backup now, so depending on results, a bootable media test might be the next to try.

I'm wondering if another 'compression' choice might be needed, 'Fast' which would not try to compress known highly compressed files, just copy them?

Steve, Enchanted, well, we can FORGET my Game Theory...

I did create a new backup scenario with the SAME settings and started it. It 'scanned' the files and arrived at 336GB's to be backed up. Correct size.

Much to my SURPRISE it stated immediately!

Normally there is a LONG delay before it starts! Look how short the time is to complete!

Basic difference, one drive itself was not included, the SSD that holds the boot record and C: drive. The C: is fairly small too, less than 70GB's.

I have run CHKDSK /F on all the drives too recently. That and SFC /SCANNOW with no problems? There are 2 other folders that could be compressed files, the iPad backup folder (.3GB) and the folder for images from a digital camera (.75GB's).

OK, more confusion, it was progressing well, moving fast. When it reached the 3 min mark to complete, it started backing up, 4 min., then 5 min., until complete. The size of the backup increased almost 2 fold at this point in time.

The last folder is on the E: drive, but that is on the SAME physical drive as D: is?

Now time to complete, 6 min, and the size has gone up to 146GB's from what was 90GB's at the 3 minute mark?

Checked the M: drive and it isn't @ 100%? Drive E: does reach 100% occasionally though?

Make no sense to me?

It continues to climb sitting at the 6 min to complete mark.

I looked at the size of the file written and it is about 30GB's smaller than what the status shows. Wondering if all the time up to the 'end' ATI was just scanning files and determining what to do? Once it figured out everything it then started processing?

It now shows 7 min left and 165GB's backed up????

Irv.

Well, since the backup runs as expected with the C: drive removed from the equation this would indicate something amiss with that drive.

I note that you have run chkdsk on the drive.  Although chkdsk will not harm an SSD, it really is not necessary other than to scan the file system of the drive for errors, in other words chkdsk without options.  The reason for this is that SSD's unlike HDD's do not have physical disk surfaces therefore repair options of chkdsk /r for example have no effect other than /r implies /f so file system errors would be corrected.  SSD controllers however perform the /f equivalent when a trim or garbage collection is run on the drive.

Trimming an SSD in Windows 10 manually is possible.  Drive Optimization via PowerShell command is the right tool to use to achieve both.

In an Admin PS window the following command will check the current Optimization of any drive in the computer both SSD and HDD:

Optimize-Volume -DriveLetter H -Analyze -Verbose

Where H is your target.

The following command will perform a trim process and optimize an SSD drive effectively running the drives controller error correction on all drive cells:

Optimize-Volume -DriveLetter H -ReTrim -Verbose

Where H is your target.

I am posting a screenshot of a PS Retrim below.  I would recommend running an Analyze command on all the machine drives to get an overall health status of the drives.  I would then recommend a Retrim on drive C and any other SSD's you have.  A period run of Retrim is a good idea for drive optimization.  Beyond that, I would suggest detaching the drive cable at both ends of the C drive and re-seating that cable.  If this fix the delay problem replace the cable with a good high quality one.

Note command syntax denoted by the thumbtack.  Colons after drive letters are not required but can be added.

It keeps getting longer until complete... 11 min and 235GB's backed up.

Clearly the slider is not to be confused with percentage complete, not the time remaining.

Enchantech wrote:

Irv.

.

.

Trimming an SSD in Windows 10 manually is possible.  Drive Optimization via PowerShell command is the right tool to use to achieve both.

In an Admin PS window the following command will check the current Optimization of any drive in the computer both SSD and HDD:

Optimize-Volume -DriveLetter H -Analyze -Verbose

Where H is your target.

The following command will perform a trim process and optimize an SSD drive effectively running the drives controller error correction on all drive cells:

Optimize-Volume -DriveLetter H -ReTrim -Verbose

Where H is your target.

 

 

I'll do that when I can get access to the PC again (other than her allowing me to see progress). 

You can see my last two posts, about 30 minutes apart... longer to complete between them and significant GB's more written.

With that in mind, I suspect it will finish when it has backed up all 335 or so GB's. I started probably 2 hours ago I think, and it is about 1/2 done... so I suspect it isn't really the game files, it is just how ATI operates? Seems based on the slider movement it 'determines' what needs to be done and the slider represents how much it had processed, then it does the work, and that takes the bulk of the time? In other words, ATI has no direct way of knowing how long a backup will take, until it is done. All based on some algorithm that may not be a true representation for all possible situations.

Enchantech wrote:

Irv.

Well, since the backup runs as expected with the C: drive removed from the equation this would indicate something amiss with that drive.

I note that you have run chkdsk on the drive.  Although chkdsk will not harm an SSD, it really is not necessary other than to scan the file system of the drive for errors, in other words chkdsk without options.  The reason for this is that SSD's unlike HDD's do not have physical disk surfaces therefore repair options of chkdsk /r for example have no effect other than /r implies /f so file system errors would be corrected.  SSD controllers however perform the /f equivalent when a trim or garbage collection is run on the drive.

Trimming an SSD in Windows 10 manually is possible.  Drive Optimization via PowerShell command is the right tool to use to achieve both.

In an Admin PS window the following command will check the current Optimization of any drive in the computer both SSD and HDD:

Optimize-Volume -DriveLetter H -Analyze -Verbose

Where H is your target.

The following command will perform a trim process and optimize an SSD drive effectively running the drives controller error correction on all drive cells:

Optimize-Volume -DriveLetter H -ReTrim -Verbose

Where H is your target.

I am posting a screenshot of a PS Retrim below.  I would recommend running an Analyze command on all the machine drives to get an overall health status of the drives.  I would then recommend a Retrim on drive C and any other SSD's you have.  A period run of Retrim is a good idea for drive optimization.  Beyond that, I would suggest detaching the drive cable at both ends of the C drive and re-seating that cable.  If this fix the delay problem replace the cable with a good high quality one.

Note command syntax denoted by the thumbtack.  Colons after drive letters are not required but can be added.

I did try this on my SSD C:

----------------

PS C:\> Optimize-Volume -DriveLetter c -Analyze -Verbose
VERBOSE: Invoking analysis on OS (C:)...
VERBOSE: Analysis:  0% complete...
VERBOSE: Analysis:  11% complete...

.

.

VERBOSE: Analysis:  97% complete...
VERBOSE: Analysis:  100% complete.
VERBOSE:
Post Defragmentation Report:
VERBOSE:
 Volume Information:
VERBOSE:   Volume size                 = 110.78 GB
VERBOSE:   Cluster size                = 4 KB
VERBOSE:   Used space                  = 82.02 GB
VERBOSE:   Free space                  = 28.76 GB
VERBOSE:
 Fragmentation:
VERBOSE:   Total fragmented space      = 8%
VERBOSE:   Average fragments per file  = 1.15
VERBOSE:   Movable files and folders   = 330197
VERBOSE:   Unmovable files and folders = 6
VERBOSE:
 Files:
VERBOSE:   Fragmented files            = 12065
VERBOSE:   Total file fragments        = 48761
VERBOSE:
 Folders:
VERBOSE:   Total folders               = 12771
VERBOSE:   Fragmented folders          = 288
VERBOSE:   Total folder fragments      = 1028
VERBOSE:
 Free space:
VERBOSE:   Free space count            = 28446
VERBOSE:   Average free space size     = 1.02 MB
VERBOSE:   Largest free space size     = 4.16 GB
VERBOSE:
 Master File Table (MFT):
VERBOSE:   MFT size                    = 674.25 MB
VERBOSE:   MFT record count            = 690431
VERBOSE:   MFT usage                   = 100%
VERBOSE:   Total MFT fragments         = 4
VERBOSE:  Note: File fragments larger than 64MB are not included in the fragmentation statistics.
VERBOSE:
 You do not need to defragment this volume.

=====================

and

============

PS C:\> Optimize-Volume -DriveLetter c -ReTrim -Verbose
VERBOSE: Invoking retrim on OS (C:)...
VERBOSE: Performing pass 1:
VERBOSE: Retrim:  0% complete...
VERBOSE: Retrim:  100% complete.
VERBOSE:
Post Defragmentation Report:
VERBOSE:
 Volume Information:
VERBOSE:   Volume size                 = 110.78 GB
VERBOSE:   Cluster size                = 4 KB
VERBOSE:   Used space                  = 82.02 GB
VERBOSE:   Free space                  = 28.76 GB
VERBOSE:
 Retrim:
VERBOSE:   Backed allocations          = 110
VERBOSE:   Allocations trimmed         = 635
VERBOSE:   Total space trimmed         = 26.82 GB
PS C:\>

==========

Her SSD is the same size as yours, and I'll do that later. Mine though seemed to be OK.

Irv,

Using small SSD's may have some effect on your outcome.  Does your wife's PC have about the same free space as yours or does it have less?  If less, this might be something to look at as well.  An optimization should help in any case.

If it will help with making the powershell commands easier to use, the following script can be used:

SSDcheck.ps1

Clear-Host
Write-Host "-------------------------------------------------------------------"
$SSD = Read-Host 'Enter SSD drive to Analyse, e.g. C'
Write-Host "-------------------------------------------------------------------"
Optimize-Volume -DriveLetter $SSD -Analyze -Verbose
Write-Host "-------------------------------------------------------------------"
$YN = Read-Host "Do you want to Trim SSD drive $SSD (Y/N?"
if ($YN -like "y") {Optimize-Volume -DriveLetter $SSD -ReTrim -Verbose}
Write-Host "-------------------------------------------------------------------"

Example of above script running on my laptop SSD.

-------------------------------------------------------------------
Enter SSD drive to Analyse, e.g. C: c
-------------------------------------------------------------------
VERBOSE: Invoking analysis on Windows (C:)...

VERBOSE: Analysis:  0% complete...
VERBOSE: Analysis:  28% complete...
VERBOSE: Analysis:  32% complete...
VERBOSE: Analysis:  38% complete...
VERBOSE: Analysis:  43% complete...
VERBOSE: Analysis:  49% complete...
VERBOSE: Analysis:  56% complete...
VERBOSE: Analysis:  61% complete...
VERBOSE: Analysis:  64% complete...
VERBOSE: Analysis:  68% complete...
VERBOSE: Analysis:  75% complete...
VERBOSE: Analysis:  79% complete...
VERBOSE: Analysis:  83% complete...
VERBOSE: Analysis:  88% complete...
VERBOSE: Analysis:  93% complete...
VERBOSE: Analysis:  100% complete.  
VERBOSE:
Post Defragmentation Report:

VERBOSE:
    Volume Information:
VERBOSE:         Volume size                 = 118.00 GB
VERBOSE:         Cluster size                = 4 KB
VERBOSE:         Used space                  = 64.67 GB
VERBOSE:         Free space                  = 53.32 GB
VERBOSE:
    Fragmentation:
VERBOSE:         Total fragmented space      = 4%
VERBOSE:         Average fragments per file  = 1.03
VERBOSE:         Movable files and folders   = 277378
VERBOSE:         Unmovable files and folders = 6
VERBOSE:
    Files:
VERBOSE:         Fragmented files            = 2954
VERBOSE:         Total file fragments        = 8776
VERBOSE:
    Folders:
VERBOSE:         Total folders               = 14756
VERBOSE:         Fragmented folders          = 89
VERBOSE:         Total folder fragments      = 335
VERBOSE:
    Free space:
VERBOSE:         Free space count            = 4991
VERBOSE:         Average free space size     = 10.94 MB
VERBOSE:         Largest free space size     = 28.48 GB
VERBOSE:
    Master File Table (MFT):
VERBOSE:         MFT size                    = 440.50 MB
VERBOSE:         MFT record count            = 451071
VERBOSE:         MFT usage                   = 100%
VERBOSE:         Total MFT fragments         = 2
VERBOSE:     Note: File fragments larger than 64MB are not included in the fragmentation statistics.
VERBOSE:
    You do not need to defragment this volume.
-------------------------------------------------------------------
Do you want to Trim SSD drive c (Y/N?: y

VERBOSE: Invoking retrim on Windows (C:)...

VERBOSE: Performing pass 1:
VERBOSE: Retrim:  0% complete...
VERBOSE: Retrim:  100% complete.  
VERBOSE:
Post Defragmentation Report:

VERBOSE:
    Volume Information:
VERBOSE:         Volume size                 = 118.00 GB
VERBOSE:         Cluster size                = 4 KB
VERBOSE:         Used space                  = 64.67 GB
VERBOSE:         Free space                  = 53.32 GB
VERBOSE:
    Retrim:
VERBOSE:         Backed allocations          = 118
VERBOSE:         Allocations trimmed         = 492
VERBOSE:         Total space trimmed         = 53.29 GB
-------------------------------------------------------------------

PS D:\>

Ran Steve's script on wife's PC..

============

Enter SSD drive to Analyse, e.g. C: c:
-------------------------------------------------------------------             Optimize-Volume : No MSFT_Volume objects found with property 'DriveLetter'      equal to ':'.  Verify the value of the property and retry.                      At E:\ssdcheck.ps1:7 char:5                                                     +     Optimize-Volume -DriveLetter $SSD -Analyze -Verbose                       +     ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~                           + CategoryInfo          : ObjectNotFound: (::Char) [Optimize-Volume], CimJ     obException                                                                      + FullyQualifiedErrorId : CmdletizationQuery_NotFound_DriveLetter,Optimize     -Volume                                                                                                                                                      VERBOSE: Invoking analysis on OS_SSD (C:)...                                    VERBOSE: Analysis:  0% complete...                                              VERBOSE: Analysis:  9% complete...                                              VERBOSE: Analysis:  10% complete...                                             VERBOSE: Analysis:  11% complete...            

.

.

VERBOSE: Analysis:  96% complete...                                             VERBOSE: Analysis:  100% complete...                                            VERBOSE: Analysis:  100% complete.                                              VERBOSE:                                                                        Post Defragmentation Report:                                                    VERBOSE:                                                                         Volume Information:                                                            VERBOSE:   Volume size                 = 465.22 GB                              VERBOSE:   Cluster size                = 4 KB                                   VERBOSE:   Used space                  = 61.68 GB                               VERBOSE:   Free space                  = 403.54 GB                              VERBOSE:                                                                         Fragmentation:                                                                 VERBOSE:   Total fragmented space      = 6%                                     VERBOSE:   Average fragments per file  = 1.05                                   VERBOSE:   Movable files and folders   = 430199                                 VERBOSE:   Unmovable files and folders = 6                                      VERBOSE:                                                                         Files:                                                                         VERBOSE:   Fragmented files            = 11328                                  VERBOSE:   Total file fragments        = 21828                                  VERBOSE:                                                                         Folders:                                                                       VERBOSE:   Total folders               = 15046                                  VERBOSE:   Fragmented folders          = 48                                     VERBOSE:   Total folder fragments      = 151                                    VERBOSE:                                                                         Free space:                                                                    VERBOSE:   Free space count            = 20945                                  VERBOSE:   Average free space size     = 19.71 MB                               VERBOSE:   Largest free space size     = 391.81 GB                              VERBOSE:                                                                         Master File Table (MFT):                                                       VERBOSE:   MFT size                    = 833.25 MB                              VERBOSE:   MFT record count            = 853247                                 VERBOSE:   MFT usage                   = 100%                                   VERBOSE:   Total MFT fragments         = 8                                      VERBOSE:  Note: File fragments larger than 64MB are not included in the         fragmentation statistics.                                                       VERBOSE:                                                                         You do not need to defragment this volume.   

-------------------------------------------------------------------             Do you want to Trim SSD drive c: (Y/N?: y                                       Optimize-Volume : No MSFT_Volume objects found with property 'DriveLetter'      equal to ':'.  Verify the value of the property and retry.                      At E:\ssdcheck.ps1:10 char:25                                                   + ...  ($YN -like "y") {Optimize-Volume -DriveLetter $SSD -ReTrim -Verbose}     +                       ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~          + CategoryInfo          : ObjectNotFound: (::Char) [Optimize-Volume], CimJ     obException                                                                      + FullyQualifiedErrorId : CmdletizationQuery_NotFound_DriveLetter,Optimize     -Volume                                                                                                                                                      VERBOSE: Invoking retrim on OS_SSD (C:)...
VERBOSE: Performing pass 1:
VERBOSE: Retrim:  0% complete...
VERBOSE: Retrim:  21% complete...
VERBOSE: Retrim:  22% complete...
VERBOSE: Retrim:  26% complete...

.

.

VERBOSE: Retrim:  98% complete...
VERBOSE: Retrim:  100% complete.
VERBOSE:
Post Defragmentation Report:
VERBOSE:
 Volume Information:
VERBOSE:   Volume size                 = 465.22 GB
VERBOSE:   Cluster size                = 4 KB
VERBOSE:   Used space                  = 61.68 GB
VERBOSE:   Free space                  = 403.54 GB
VERBOSE:
 Retrim:
VERBOSE:   Backed allocations          = 465
VERBOSE:   Allocations trimmed         = 1389
VERBOSE:   Total space trimmed         = 401.43 GB
-------------------------------------------------------------------

Seems fine.

Enchantech wrote:

Irv,

Using small SSD's may have some effect on your outcome.  Does your wife's PC have about the same free space as yours or does it have less?  If less, this might be something to look at as well.  An optimization should help in any case.

I've got the small SSD, she has the same size as you have, 500GB with only the C: on it.

Irv,

I agree, the drive should be fine.  Looks in order and there really is no way to tell what the drives controller may have corrected by running Trim.  If your backup task performs as it has up to this point then something else is in play that has yet to be discovered.

Forgot to post the final results.

Finished in 2 1/2 hours, that was for 327GB's of files. End file on disk, 286GB's, about a 40GB difference.

> > 2020-01-04T10:08:32:431-05:00 13628 I00000000: -----
> 2020-01-04T10:08:32:431-05:00 13628 I00000000: ATI Demon started. Version: 24.5.1.22510.
> 2020-01-04T10:08:32:472-05:00 13628 I00640000: Backup reserve copy attributes: format tib; need_reserve_backup_copy false;
> 2020-01-04T10:08:32:472-05:00 13628 I00640002: Operation Test-Games started manually.
> 2020-01-04T10:08:32:936-05:00 13628 I00640000: Backup reserve copy attributes: format tib; need_reserve_backup_copy false;
> 2020-01-04T10:08:32:936-05:00 13628 I013C0000: Operation: Backup
> 2020-01-04T10:08:32:936-05:00 13628 I0064000B: Priority changed to High.
> 2020-01-04T10:08:47:837-05:00 13628 I000B03F0: Create Backup Archive From: D:\Games\
> E:\games\
> To file: "Test-Games_full_b1_s1_v1.tib" Compression: Normal Exclude: System files
> 2020-01-04T10:09:03:441-05:00 6868 I00640000: Writing full version to file: Test-Games_full_b1_s1_v1.tib
> 2020-01-04T12:31:12:909-05:00 13628 I00640000: The following backups have been successfully created: "M:\Acronis Backup\Test_Games\Test-Games_full_b1_s1_v1.tib"
> 2020-01-04T12:31:22:213-05:00 13628 I013C0006: Operation has succeeded.

Same sort of stuff, 2 1/2 hour gap in the email of nothing.

Can NOT find a BACKUP_WORKER log, none created for a FOLDER backup? Would there be another log with info I'm unaware of Steve?

Considering the time taken I'd say it is reasonable to assume GAME folders did NOT cause the long time as it was about 1/2 the backup.

I also think the SLIDER and even the time is almost meaningless. It really doesn't know the % done nor the time remaining. At first it know only one thing, the size of the backup to be done, but not the contents, NOR the time to process those or the h/w capability for read or write.

At this point though, about all I can say is ATI 2016 worked faster.

Is it really worth it to try a backup via the boot media?

Irv, there is no backup_worker log for a Files & Folders type backup as this is still following the rules for .tib files as with earlier versions.

If you are comparing time differences between Files & Folders backups with those for Disks & Partitions, then this is not really a valid comparison as different techniques are involved for these in ATI 2020.