I just had an awesome experience debugging a Time Machine hang. A backup was hanging indefinitely as far as I can tell. I couldn't stop it through the preferences pane, or pull down in the menu bar. Looking at the system log, I found the following:
Mar 28 22:08:50 Tornado mds[36]: (Error) Import: importer:0x85d400 Importer start failed for 89 (kr:268435459 (ipc/send) invalid destination port)
Mar 28 22:09:20: --- last message repeated 7 times ---
Mar 28 22:09:22 Tornado mds[36]: (Error) Import: importer:0x85d400 Importer start failed for 89 (kr:268435459 (ipc/send) invalid destination port)
Mar 28 22:09:52: --- last message repeated 7 times ---
Mar 28 22:09:54 Tornado mds[36]: (Error) Import: importer:0x85d400 Importer start failed for 89 (kr:268435459 (ipc/send) invalid destination port)
Mar 28 22:10:24: --- last message repeated 7 times ---
Mar 28 22:10:26 Tornado mds[36]: (Error) Import: importer:0x85d400 Importer start failed for 89 (kr:268435459 (ipc/send) invalid destination port)
Mar 28 22:10:37: --- last message repeated 2 times ---
Assuming these errors were related, I opened up Activity Monitor, and killed the mds process and was greeted with the following in the sytem log:
Mar 28 22:10:37 Tornado com.apple.launchd[97] (com.apple.Spotlight[145]): Exited abnormally: Interrupt
So it looks like mds is part of Spotlight, maybe the indexing process. Immediately after I killed the process, my Time Machine backup unfroze and reported an error.
Mar 28 22:11:33 Tornado /System/Library/CoreServices/backupd[15448]: Indexing a file failed. Returned -1120 for: /Library/Application Support/Mozilla, /Volumes/Backup/Backups.backupdb/Tornado/2009-03-22-011202.inProgress/E3158A6F-868B-4E81-82EE-7D3151A1A287/Magnus/Library/Application Support/Mozilla
Mar 28 22:11:33 Tornado /System/Library/CoreServices/backupd[15448]: Aborting backup because indexing a file failed.
Mar 28 22:11:33 Tornado /System/Library/CoreServices/backupd[15448]: Stopping backup.
Mar 28 22:11:33 Tornado /System/Library/CoreServices/backupd[15448]: Bulk setting Spotlight attributes failed.
Mar 28 22:11:34 Tornado /System/Library/CoreServices/backupd[15448]: Copied 101 files (12 KB) from volume Magnus.
Mar 28 22:11:34 Tornado /System/Library/CoreServices/backupd[15448]: Copy stage failed with error:11
Elsewhere on the internet people claim that their hard drives start thrashing if Time Machine is backing up at the same time Spotlight is indexing a back up volume. I didn't hear any thrashing on my backup drive. I think there is something else at work. In the above system log messages there is a line saying "Bulk setting Spotlight attributes failed." That's a printout from the backupd process which I assume is part of Time Machine. I'm going to guess that Time Machine and Spotlight running at the same time with Spotlight indexing the backup drive can hit a bug that causes the two processes to dead lock.
I added my Time Machine backup database to Spotlight's privacy list so it won't index my backup drive. It doesn't prove that it's the problem, but after killing mds, and telling Spotlight to ignore the backup drive, the next Time Machine backup completed fine.
Sunday, March 29, 2009
Subscribe to:
Post Comments (Atom)
3 comments:
This proves once again what a POS Spotlight is. I actually completely disabled it on my machine once (I never use it), but then realized that Mail depends on it for email searching so I had to enable it again.
Thanks for the helpful tip. I started backing up my MBP to an external USB drive last night, and this morning I noticed it was hung up at 180 GB out of 189 GB. I didn't see an mds process running in Activity Monitor, but as soon as I added the backup drive to the privacy list in Spotlight, the backup immediately resumed!
Wow, that definitely points the finger directly at Spotlight and TimeMachine not playing nice.
Post a Comment