Upgraded to Lion: Time Machine spends a LOT of time indexing backup
I upgraded my MacBook Pro to Lion and one of the problems I've had is that Time Machine keeps running and running, and the fans go on.
This usually seems to be in the state where it indexes the backup.
This is to a Time Capsule, there is about 90 Gb left on the drive. I am connecting wirelessly over an n-network. The backups go about 4 months back. Left to itself the backup finishes in "quite a while".
Under 10.6 this was an almost invisible process. Now I am annoyed hourly. Any suggestions?
EDIT: I grepped for "backup" in the log messages (/private/var/log/system.log) and got the following from the last backup (which I cancelled):
24/07/11 14.42.22,185 com.apple.backupd: Starting standard backup
24/07/11 14.42.24,013 com.apple.backupd: Attempting to mount network destination URL: afp://Thorbj%C3%B8rn%20Ravn%20Andersen@Thorbj%C3%B8rn%20TC._afpovertcp._tcp.local/Data
24/07/11 14.42.31,097 com.apple.backupd: Mounted network destination at mountpoint: /Volumes/Data using URL: afp://Thorbj%C3%B8rn%20Ravn%20Andersen@Thorbj%C3%B8rn%20TC._afpovertcp._tcp.local/Data
24/07/11 14.42.35,981 com.apple.backupd: QUICKCHECK ONLY; FILESYSTEM CLEAN
24/07/11 14.42.39,214 com.apple.backupd: Disk image /Volumes/Data/Thorbjørns MBP.sparsebundle mounted at: /Volumes/Time Machine-sikkerhedskopier
24/07/11 14.42.39,287 com.apple.backupd: Backing up to: /Volumes/Time Machine-sikkerhedskopier/Backups.backupdb
24/07/11 14.45.02,101 com.apple.backupd: Waiting for index to be ready (100)
24/07/11 14.45.21,588 mds: (Error) Backup: doBackupIndexFile could not stat backup location /.MobileBackups/Computer/2011-07-24-144225/Volume/Users/ravn/Library/Application Support/Google/Chrome/Default/History Index 2011-07-journal /.MobileBackups/Computer/2011-07-24-144225/Volume/Users/ravn/Library/Application Support/Google/Chrome/Default/History Index 2011-07-journal. Error 2 with uid 0
24/07/11 14.57.34,633 com.apple.backupd: 23.71 GB required (including padding), 71.79 GB available
24/07/11 14.57.34,680 com.apple.backupd: Waiting for index to be ready (100)
24/07/11 14.58.38,530 com.apple.backupd: Waiting for index to be ready (100)
24/07/11 14.59.56,176 com.apple.backupd: Waiting for index to be ready (100)
24/07/11 15.00.56,663 com.apple.backupd: Waiting for index to be ready (100)
24/07/11 15.01.57,479 com.apple.backupd: Waiting for index to be ready (100)
24/07/11 15.02.57,783 com.apple.backupd: Waiting for index to be ready (100)
24/07/11 15.03.59,499 com.apple.backupd: Waiting for index to be ready (100)
24/07/11 15.05.00,659 com.apple.backupd: Waiting for index to be ready (100)
24/07/11 15.06.01,065 com.apple.backupd: Waiting for index to be ready (100)
24/07/11 15.07.01,923 com.apple.backupd: Waiting for index to be ready (100)
24/07/11 15.08.03,008 com.apple.backupd: Waiting for index to be ready (100)
24/07/11 15.09.03,818 com.apple.backupd: Waiting for index to be ready (100)
24/07/11 15.10.05,692 com.apple.backupd: Waiting for index to be ready (100)
24/07/11 15.11.06,368 com.apple.backupd: Waiting for index to be ready (100)
24/07/11 15.12.06,780 com.apple.backupd: Waiting for index to be ready (100)
24/07/11 15.13.07,700 com.apple.backupd: Waiting for index to be ready (100)
24/07/11 15.14.08,159 com.apple.backupd: Waiting for index to be ready (100)
24/07/11 15.15.09,275 com.apple.backupd: Waiting for index to be ready (100)
24/07/11 15.15.11,044 com.apple.backupd: Copied 0 files (0 bytes) from volume OSX.
24/07/11 15.15.12,154 mds: (Error) Volume: Could not find requested backup type:2 for volume
24/07/11 15.16.42,159 com.apple.backupd: Backup canceled.
24/07/11 15.16.46,704 com.apple.backupd: Ejected Time Machine disk image.
24/07/11 15.16.47,816 com.apple.backupd: Ejected Time Machine network volume.
Is the "Could not find requested backup type: 2 for volume" message important?
I had the same problem after first upgrading to Lion. I erased my Time Machine and it seems to work fine now.
From your situation, it's hard to tell if this is normal or if the process is somehow stuck.
You can monitor what is happening from the Time Machine system preference while the backups are taking longer than expected.
For more detail - fire up the Console.app and type backupd in the String Matching / filter control. You might be able to determine if the process is taking a lot of time deleting old backups or something else. You'll also see the timing and the volume of data that might help if you are having slower transfer over the network than before.
Good luck hunting down a cause...
[Edit - responding to additional details on the mount aborting - index failing to get ready.]
OK - this likely won't fix itself. It's always nice to follow the recommended systematic steps to troubleshoot time machine, but I might start first with a verify pass of your existing backup files.
To verify, hold the option key and click your Time Machine icon in the menu bar - the verify process should get you a more concrete error you can understand or it might just fix the issue altogether. Your mac is timing out waiting for a preliminary steo to finish and it's not clear why.
I had a similar problem: after my upgrade to Lion I get the "Waiting for index to be ready (100)" messages, and the complete Time Machine backup takes a LONG time (like, 45 minutes+) even for very small changes.
But my console/backupd logs had no error messages; the backups simply took a long time.
But I think I've fixed it, here's how:
- Mount the backup disk (in Finder do Command-K to mount it if it's not already mounted).
- Find the Time Machine image on the backup disk. My Mac is called "SvecBook," so the Time Machine image is SvecBook.sparsebundle. Right click on the "SvecBook.sparsebundle" file and "Open With" -> DiskImageMounter.app.
- Then I opened Disk Utility, clicked on the SvecBook.sparsebundle "Time Machine Backups" partition, the "First Aid" tab, then "Repair Disk."
- This takes a while, at least 30 minutes on my machine.
- No errors were found.
- If you're using a backup server, unmount the backup disk.
The first time I tried this the TimeMachine backups still took forever, spinning on "Waiting for index" for a LONG time.
The second time I did this TimeMachine backups worked! Now TimeMachine backups complete quickly, everything looks good!
I have no idea what was changed or fixed by the "Repair Disk" process since it didn't report anything was broken. And I have no idea why this seemingly fixed the problem the second time but not the first.
But it works for me, for now!
Maybe this is doing the same thing as what @bmike's "Verify Backups" answer did, but that didn't work for me. (Of course, my "method" didn't work for me the first time.)
Edit: My Lion Time Machine backups have been working perfectly since my original answer almost 2 months ago. So I'm going to call this a good fix.
Here's what I had to do to fix "Waiting for index to be ready (100)" error:
- Mount the {MyTimeMachine}.sparsebundle disk image
- Delete the .Spotlight-V100 folder w/ this command:
sudo rm -rf /Volumes/{MyTimeMachine}/.Spotlight-V100
- Open Spotlight preferences, go to Privacy tab, and add the {MyTimeMachine} volume to list of excluded directories
- Unmount/eject {MyTimeMachine}
- Run "Backup Now"
Where {MyTimeMachine} is a variable = the name of your sparsebundle disk