SD taking a lot longer all of a sudden

[luomat]

I've got SuperDuper running on a Mac Mini which is running 10.11.6.

It has, for a long time, run a nightly backup. It took about 30 minutes. Here's some excerpts from the logs:


2018-07-25 03.30.26 -0400.txt:| 03:30:27 AM | Info | PHASE: 1. Prepare to Copy Files
2018-07-25 03.30.26 -0400.txt:| 03:52:29 AM | Info | Copy complete.

2018-07-26 03.30.27 -0400.txt:| 03:30:27 AM | Info | PHASE: 1. Prepare to Copy Files
2018-07-26 03.30.27 -0400.txt:| 03:56:00 AM | Info | Copy complete.

2018-07-27 03.30.21 -0400.txt:| 03:30:22 AM | Info | PHASE: 1. Prepare to Copy Files
2018-07-27 03.30.21 -0400.txt:| 03:51:59 AM | Info | Copy complete.

2018-07-28 03.30.26 -0400.txt:| 03:30:27 AM | Info | PHASE: 1. Prepare to Copy Files
2018-07-28 03.30.26 -0400.txt:| 03:51:14 AM | Info | Copy complete.

But recently it's taking a lot longer:

2018-09-10 03.30.21 -0400.txt:| 03:30:22 AM | Info | PHASE: 1. Prepare to Copy Files
2018-09-10 03.30.21 -0400.txt:| 05:55:03 AM | Info | Copy complete.

2018-09-11 03.30.27 -0400.txt:| 03:30:27 AM | Info | PHASE: 1. Prepare to Copy Files
2018-09-11 03.30.27 -0400.txt:| 07:22:07 AM | Info | Copy complete.

2018-09-12 03.30.26 -0400.txt:| 03:30:27 AM | Info | PHASE: 1. Prepare to Copy Files
2018-09-12 03.30.26 -0400.txt:| 06:35:45 AM | Info | Copy complete.

2018-09-13 03.30.26 -0400.txt:| 03:30:27 AM | Info | PHASE: 1. Prepare to Copy Files
2018-09-13 03.30.26 -0400.txt:| 06:03:31 AM | Info | Copy complete.

2018-09-14 03.30.26 -0400.txt:| 03:30:27 AM | Info | PHASE: 1. Prepare to Copy Files
2018-09-14 03.30.26 -0400.txt:| 06:28:44 AM | Info | Copy complete.

2018-09-15 03.30.27 -0400.txt:| 03:30:27 AM | Info | PHASE: 1. Prepare to Copy Files
2018-09-15 03.30.27 -0400.txt:| 07:52:19 AM | Info | Copy complete.

2018-09-16 17.24.04 -0400.txt:| 05:24:05 PM | Info | PHASE: 1. Prepare to Copy Files
2018-09-16 17.24.04 -0400.txt:| 09:40:42 PM | Info | Copy complete.

2018-09-17 03.30.27 -0400.txt:| 03:30:27 AM | Info | PHASE: 1. Prepare to Copy Files
2018-09-17 03.30.27 -0400.txt:| 05:31:10 AM | Info | Copy complete.

2018-09-18 03.30.26 -0400.txt:| 03:30:27 AM | Info | PHASE: 1. Prepare to Copy Files
2018-09-18 03.30.26 -0400.txt:| 06:17:47 AM | Info | Copy complete.

2018-09-19 03.30.23 -0400.txt:| 03:30:24 AM | Info | PHASE: 1. Prepare to Copy Files
2018-09-19 03.30.23 -0400.txt:| 06:46:08 AM | Info | Copy complete.

2018-09-20 03.30.26 -0400.txt:| 03:30:27 AM | Info | PHASE: 1. Prepare to Copy Files
2018-09-20 03.30.26 -0400.txt:| 08:01:27 AM | Info | Copy complete.

2018-09-21 03.30.26 -0400.txt:| 03:30:27 AM | Info | PHASE: 1. Prepare to Copy Files
2018-09-21 03.30.26 -0400.txt:| 10:45:04 AM | Info | Copy complete.

I don't see anything in the logs that gives me an idea of why it's taking so much longer, and I've checked the drives with Disk Warrior to make sure there aren't any problems with the drives, but it definitely seems like something must be wrong, doesn't it?

I've put a copy of the logs here:

https://www.dropbox.com/sh/uya6jr3xb...d3d0AweCa?dl=0

(There's a zip and a .tar.xz. The contents are identical, but the .tar.xz is a lot smaller if you have The Unarchiver or 'xz' installed to open it.)

[dnanian]

Can you send the log with the "Send to shirt pocket" button so I can see some of the additional details? Thanks.

[luomat]

I just saw this yesterday (for some reason I didn't get an email when you posted your reply, even though I am "subscribed" to the thread).

SD v112 ran for over 24 hours and seemed to be "stuck" at about 95% done, so I cancelled it. There seemed to be no log created in that instance.

I updated to v113 and ran it again, and it has been running for about 20 minutes and seems to be almost done… so, maybe whatever the issue was has been fixed with the rest of the v113 improvements? I'll definitely keep an eye on it and let you know if I see the long copy times again.

[luomat]

Unfortunately I seem to have been mistaken.

Over an hour later, the progress indicator has stuck the same place where it was stuck before, and it hasn't changed in over an hour.

Screenshot attached

[dnanian]

Send me support email and let's see what we can find out.

[luomat]

I cancelled the copy and sent the interrupted log.

Currently running DiskWarrior on the SuperDuper drive before I try again.

[luomat]

As usual, Dave fixed it!

The Mac had been up for a long time, and had accumulated a bunch of temporary files. That plus the drive itself was "Very Inefficient" according to DiskWarrior.

I rebuilt it with DiskWarrior, rebooted, and ran SuperDuper again, and it finished a Smart Update in about an hour.

Thanks again Dave!

👍⭐⭐⭐⭐⭐