Why so long to delete a backup?

I am using an Acronis backup location to manage a backup set. The backup policy is set to do a full backup after doing 6 differential backups. The backup folder limit is set to 7. The backup last night was the number eight so Acronis rightfully deleted one backup. However, the deletion activity took about 2:45. Why would it take this long to delete a backup? Is it not just a matter of deleting a file? The log for this activity is as follows:

Code:

1    Information    11/9/2006 4:00:02 AM    The "Dagwood - Drive C" operation started
2    Information    11/9/2006 4:00:02 AM    Analyzing partition 0-0...
3    Information    11/9/2006 4:00:03 AM    Analyzing partition 1-1...
4    Information    11/9/2006 4:00:03 AM    Analyzing partition C:...
5    Information    11/9/2006 4:00:03 AM    Analyzing partition E:...
6    Warning!    11/9/2006 4:00:03 AM    Priority changed to Low priority
7    Information    11/9/2006 4:00:03 AM    Analyzing partition C:...
8    Information    11/9/2006 4:00:06 AM    Create Differential Backup ArchiveFrom:	NTFS (C:)To file:	"\\astro\Astro-USB Backup 2\Acronis Backup-Dagwood-Drive C-Set A\"Compression:	Normal
9    Information    11/9/2006 4:00:07 AM    Pending operation 128 started: "Saving partition structure"
10    Information    11/9/2006 4:00:07 AM    Pending operation 131 started: "Creating partition image"
11    Information    11/9/2006 4:00:07 AM    Locking partition C:...
12    Information    11/9/2006 4:03:41 AM    Check for 'number of backups' rule violation is started. Set number:	7
13    Warning!    11/9/2006 4:03:41 AM    'Number of backups' rule violation is detected. Maximum allowed:	7Current number:	8
14    Warning!    11/9/2006 4:03:41 AM    There is no action available to take against the limit violation. Limit rule: by backup count. By default, the 'delete' action will be used.
15    Information    11/9/2006 4:03:41 AM    Trying to fix limit violation: by backup count.
16    Information    11/9/2006 4:03:41 AM    Deletion is started. Rule:	by backup countNumber of backup will be deleted:	1
17    Information    11/9/2006 4:03:41 AM    Backup deletionLocation:	atis:network?file://astro\Astro-USB Backup 2\Acronis Backup-Dagwood-Drive C-Set A\Number of backups:	1
18    Information    11/9/2006 6:42:20 AM    Completed successfully
19    Information    11/9/2006 6:42:20 AM    Deletion complete.
20    Information    11/9/2006 6:42:21 AM    Operation has succeeded.

 

Any idea on how long the initial backup took?
I wonder if the messages aren’t just getting logged at the end of the process, when the image has been completed.

 

Based on a little test I just ran, I think the deletion does not take place until after the new image is created.
I get the same odd times as you did AND kept getting the "disk getting full" message while the backup was in progress. That message went away when TI finished.

 

I don’t know how to post the scrollie thing like you did, but in a nutshell:
Total time: 3 Min 33 Sec
Time from “The …. operation started” to “Check for ‘number of backups’ rule”: 3 Min 17 Sec
Time from “Check for ‘number of backups’ rule” to “Deletion complete”: 2 Sec
Time from “Check for ‘number of backups’ rule” to “Operation has succeeded”: 16 Sec