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?
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.