Time machine forever "preparing" after software update

gpc


Joined
Apr 4, 2008
Messages
9
Reaction score
0
Points
1
Your Mac's Specs
MacBookPro6,2 - Intel Core i7 - 2.66 GHz - 8 GB RAM
Yesterday I allowed software update to update the following:

• Quicktime 7.5
• Digital Raw Camera Compatibility 2.1

The next time Time Machine ran, it appeared to back up about 160 MB (I could be misremembering the number) but instead of finishing, it immediately started "preparing" again. Now it never stops "preparing."

There's no disk activity on the backup drive or the main drive, but Finder uses about 30% of CPU when it's "preparing."

I've tried leaving it to run for hours on end, with no luck. I've tried various combinations of turning Time machine off, dismounting and remounting the backup drive, restarting the Mac, turning Time Machine back on...

When I enter Time Machine, the most recent backup is the one from before the software update. There's no sign of anything backed up more recently.

Anyone have any ideas?

MacBook4,1, 4 GB memory, OSX 10.5.3. Backup drive is on a USB and has about 30 GB available out of 120. There's about 50 GB on the main drive to be included in backups.
 
Joined
Oct 13, 2006
Messages
724
Reaction score
60
Points
28
Location
Blacksburg, VA
Your Mac's Specs
13'' Macbook w/ 2Ghz Core Duo, 2GB DDR2, 250GB HD, 10.5.4. iPod Touch.
gpc, what happens when you attempt to verify the permissions of this disk/perform a disk repair?
 
OP
G

gpc


Joined
Apr 4, 2008
Messages
9
Reaction score
0
Points
1
Your Mac's Specs
MacBookPro6,2 - Intel Core i7 - 2.66 GHz - 8 GB RAM
Ah, good idea. But no, that hasn't worked. For the Time Machine drive, the buttons for Verify or Repair Disk Permissions are grayed out. I tried Verify Disk and Repair Disk, which were available, and after about 15 minutes it tells me the volume "appears to be OK."

I'll try verifying the permissions of the main drive next, altho I don't think that's what you meant...
 
OP
G

gpc


Joined
Apr 4, 2008
Messages
9
Reaction score
0
Points
1
Your Mac's Specs
MacBookPro6,2 - Intel Core i7 - 2.66 GHz - 8 GB RAM
Still no joy. Disk Utility did find thousands of permission problems on the main drive, all but half a dozen of them related to HP software. Fixed all those. Also ran Verify Disk on the main drive and learned the file and directory counts were each off by 1. Repaired that using Disk Utility booted from the Install DVD.

Started up TM again. It spent many minutes "preparing" with a significant amount of disk activity, which seemed promising. But now 40 minutes in, it is still "preparing," with no disk activity, Finder at about 20 CPU.
 
Joined
Oct 13, 2006
Messages
724
Reaction score
60
Points
28
Location
Blacksburg, VA
Your Mac's Specs
13'' Macbook w/ 2Ghz Core Duo, 2GB DDR2, 250GB HD, 10.5.4. iPod Touch.
Odd.

Can you post your system.log? Specifically, any line that contains "backupd". You can do this by opening up Console (Spotlight it), clicking on system.log and entering backupd in the search field on the top right.
 
OP
G

gpc


Joined
Apr 4, 2008
Messages
9
Reaction score
0
Points
1
Your Mac's Specs
MacBookPro6,2 - Intel Core i7 - 2.66 GHz - 8 GB RAM
Here you go:

Jun 13 19:08:30 Pakari /System/Library/CoreServices/backupd[2174]: Waiting for index to be ready (915 > 0)
Jun 13 19:09:00 Pakari /System/Library/CoreServices/backupd[2174]: Waiting for index to be ready (915 > 0)
Jun 13 19:09:30 Pakari /System/Library/CoreServices/backupd[2174]: Waiting for index to be ready (915 > 0)
Jun 13 19:10:00 Pakari /System/Library/CoreServices/backupd[2174]: Waiting for index to be ready (915 > 0)
Jun 13 19:10:30 Pakari /System/Library/CoreServices/backupd[2174]: Waiting for index to be ready (915 > 0)
Jun 13 19:10:47 Pakari /System/Library/CoreServices/backupd[2174]: Copied 0 files (0 bytes) from volume Graham's Disk.
Jun 13 19:10:53 Pakari /System/Library/CoreServices/backupd[2174]: Backup canceled.


There are hundreds of lines of the "waiting," every 30 seconds going to back to whenever I last tried turning on TM. 19:10:47 must be when I turned it off again a short while ago.

And here is what goes into the log when I turn it on and manually start a backup:

Jun 13 19:26:07 Pakari /System/Library/CoreServices/backupd[3587]: Backup requested by user
Jun 13 19:26:07 Pakari /System/Library/CoreServices/backupd[3587]: Starting standard backup
Jun 13 19:26:07 Pakari /System/Library/CoreServices/backupd[3587]: Backing up to: /Volumes/Time Machine Pakari-1/Backups.backupdb
Jun 13 19:26:08 Pakari /System/Library/CoreServices/backupd[3587]: Event store UUIDs don't match for volume: Graham's Disk
Jun 13 19:26:08 Pakari /System/Library/CoreServices/backupd[3587]: Node requires deep traversal:/ reason:kFSEDBEventFlagMustScanSubDirs|kFSEDBEventFlagReasonEventDBUntrustable|


"Time Machine Pakari-1" is the backup drive's name. It has been chattering away at a lowish level of activity for about 8 minutes now, with no new entries in the log (I've hit "reload"). Still "preparing..."
 
OP
G

gpc


Joined
Apr 4, 2008
Messages
9
Reaction score
0
Points
1
Your Mac's Specs
MacBookPro6,2 - Intel Core i7 - 2.66 GHz - 8 GB RAM
And here's where the "waiting" lines begin, coinciding with the time that the backup drive stops its activity:

Jun 13 19:26:08 Pakari /System/Library/CoreServices/backupd[3587]: Node requires deep traversal:/ reason:kFSEDBEventFlagMustScanSubDirs|kFSEDBEventFlagReasonEventDBUntrustable|
Jun 13 19:38:39 Pakari /System/Library/CoreServices/backupd[3587]: No pre-backup thinning needed: 1.89 GB requested (including padding), 28.96 GB available
Jun 13 19:38:39 Pakari /System/Library/CoreServices/backupd[3587]: Waiting for index to be ready (915 > 0)
Jun 13 19:39:09: --- last message repeated 2 times ---
Jun 13 19:39:09 Pakari /System/Library/CoreServices/backupd[3587]: Waiting for index to be ready (915 > 0)
Jun 13 19:39:39: --- last message repeated 1 time ---
Jun 13 19:39:54 Pakari /System/Library/CoreServices/backupd[3587]: Waiting for index to be ready (915 > 0)
Jun 13 19:40:24 Pakari /System/Library/CoreServices/backupd[3587]: Waiting for index to be ready (915 > 0)
 
Joined
Oct 13, 2006
Messages
724
Reaction score
60
Points
28
Location
Blacksburg, VA
Your Mac's Specs
13'' Macbook w/ 2Ghz Core Duo, 2GB DDR2, 250GB HD, 10.5.4. iPod Touch.
Waiting for the index to be ready huh?

Time Machine may be waiting for some reason on Spotlight (just speculation). Have you tried to turn off indexing for your Time Machine drive as well as your primary drive? Give it a shot, it wouldn't hurt anything.
 
Joined
Oct 13, 2006
Messages
724
Reaction score
60
Points
28
Location
Blacksburg, VA
Your Mac's Specs
13'' Macbook w/ 2Ghz Core Duo, 2GB DDR2, 250GB HD, 10.5.4. iPod Touch.
Make sure that you turn off Time Machine before you do any of that, just to be safe.
 
OP
G

gpc


Joined
Apr 4, 2008
Messages
9
Reaction score
0
Points
1
Your Mac's Specs
MacBookPro6,2 - Intel Core i7 - 2.66 GHz - 8 GB RAM
Nope, that hasn't helped, but it looks as if something very odd is going on with the backup drive. I looked back through system.log to where the backup was first attempted after the Quicktime/Raw Camera software update. There's a slew of errors there including warnings about low disk space on the backup drive.

So I ran verify disk again. Again OK. But in system.log, right after saying everything is OK with the disk, there are the low space and I/O errors again. Yet there is about 29 GB of free space on the volume.

Looking at the backup volume in Finder, I see the package for the backup that never finishes:
2008-06-10-184722.inProgress
Created back 4 days ago when this problem started, last modified when I last tried turning TM on earlier today.

Do you think it's safe to delete that package and see if TM recovers? Get Info reports it is 46 GB, about the same as it does for every completed backup folder above it. TM prefs reports there is 51 GB of total included files on the main drive.

Here are the system.log lines from the disk verify. disk2s5 is the volume "Time Machine Pakari-1". And yes, it is still excluded from Spotlight, despite the lines about "/Volumes/Time Machine Pakari-1/.Spotlight-V100..."

Jun 14 12:19:23 Pakari Disk Utility[4629]: **********
Jun 14 12:19:23 Pakari Disk Utility[4629]: Disk Utility started.
Jun 14 12:20:32 Pakari Disk Utility[4629]: Verifying volume “Time Machine Pakari-1”
Jun 14 12:20:32 Pakari Disk Utility[4629]: Starting verification tool:
Jun 14 12:20:33 Pakari Disk Utility[4629]: Checking Journaled HFS Plus volume.
Jun 14 12:20:33 Pakari Disk Utility[4629]: Detected a case-sensitive catalog.
Jun 14 12:20:33 Pakari Disk Utility[4629]: Checking Extents Overflow file.
Jun 14 12:20:33 Pakari Disk Utility[4629]: Checking Catalog file.
Jun 14 12:22:18 Pakari Disk Utility[4629]: Checking multi-linked files.
Jun 14 12:23:49 Pakari Disk Utility[4629]: Checking Catalog hierarchy.
Jun 14 12:29:00 Pakari Disk Utility[4629]: Checking Extended Attributes file.
Jun 14 12:29:52 Pakari Disk Utility[4629]: Checking multi-linked directories.
Jun 14 12:37:06 Pakari Disk Utility[4629]: Checking volume bitmap.
Jun 14 12:37:06 Pakari Disk Utility[4629]: Checking volume information.
Jun 14 12:37:06 Pakari Disk Utility[4629]: The volume Time Machine Pakari-1 appears to be OK.
Jun 14 12:37:07 Pakari Disk Utility[4629]: Verifying tool completed:
Jun 14 12:37:07 Pakari Disk Utility[4629]:
Jun 14 12:37:08: --- last message repeated 1 time ---
Jun 14 12:37:08 Pakari kernel[0]: jnl: disk2s5: flushing fs disk buffer returned 0x5
Jun 14 12:37:16 Pakari kernel[0]: disk2s5: I/O error.
Jun 14 12:37:16 Pakari kernel[0]:
Jun 14 12:37:23: --- last message repeated 1 time ---
Jun 14 12:37:23 Pakari kernel[0]: disk2s5: I/O error.
Jun 14 12:37:23 Pakari kernel[0]:
Jun 14 12:37:30: --- last message repeated 1 time ---
Jun 14 12:37:30 Pakari kernel[0]: disk2s5: I/O error.
Jun 14 12:37:30 Pakari kernel[0]:
Jun 14 12:37:30: --- last message repeated 1 time ---
Jun 14 12:37:30 Pakari mds[31]: (/Volumes/Time Machine Pakari-1/.Spotlight-V100/Store-V1/Stores/6F800D30-7E80-4A00-9EA0-A2F709A9F4E5)(Error) IndexGeneral in void setAttributes(si_set_attr_ctx*, Boolean, long unsigned int):Couldn't update index.
Jun 14 12:37:30 Pakari mds[31]: (/Volumes/Time Machine Pakari-1/.Spotlight-V100/Store-V1/Stores/6F800D30-7E80-4A00-9EA0-A2F709A9F4E5)(Error) IndexGeneral in notify_lowspace:low space for device 234881029 (/Volumes/Time Machine Pakari-1/.Spotlight-V100/Store-V1/Stores/6F800D30-7E80-4A00-9EA0-A2F709A9F4E5)
Jun 14 12:37:30 Pakari mds[31]: (Error) Volume: LOW DISK SPACE device:234881029
Jun 14 12:37:37 Pakari kernel[0]: disk2s5: I/O error.
Jun 14 12:37:37 Pakari kernel[0]:
Jun 14 12:37:43: --- last message repeated 1 time ---
Jun 14 12:37:43 Pakari kernel[0]: disk2s5: I/O error.
Jun 14 12:37:43 Pakari kernel[0]:
Jun 14 12:37:50: --- last message repeated 1 time ---
Jun 14 12:37:50 Pakari kernel[0]: disk2s5: I/O error.
Jun 14 12:37:50 Pakari kernel[0]:
Jun 14 12:37:50: --- last message repeated 1 time ---
Jun 14 12:37:50 Pakari mds[31]: (/Volumes/Time Machine Pakari-1/.Spotlight-V100/Store-V1/Stores/6F800D30-7E80-4A00-9EA0-A2F709A9F4E5)(Error) IndexGeneral in void setAttributes(si_set_attr_ctx*, Boolean, long unsigned int):Couldn't update index.
Jun 14 12:37:50 Pakari mds[31]: (/Volumes/Time Machine Pakari-1/.Spotlight-V100/Store-V1/Stores/6F800D30-7E80-4A00-9EA0-A2F709A9F4E5)(Error) IndexGeneral in notify_lowspace:low space for device 234881029 (/Volumes/Time Machine Pakari-1/.Spotlight-V100/Store-V1/Stores/6F800D30-7E80-4A00-9EA0-A2F709A9F4E5)
Jun 14 12:37:50 Pakari mds[31]: (Error) Volume: LOW DISK SPACE device:234881029
 
Joined
Oct 13, 2006
Messages
724
Reaction score
60
Points
28
Location
Blacksburg, VA
Your Mac's Specs
13'' Macbook w/ 2Ghz Core Duo, 2GB DDR2, 250GB HD, 10.5.4. iPod Touch.
Do you think it's safe to delete that package and see if TM recovers?

By now I would have reformatted the entire TM drive. If you aren't willing to do that though, certainly it wouldn't be the end of the world to delete that package. Hey, if you are worried about it, just save it on another hard drive (if you have space).
 
OP
G

gpc


Joined
Apr 4, 2008
Messages
9
Reaction score
0
Points
1
Your Mac's Specs
MacBookPro6,2 - Intel Core i7 - 2.66 GHz - 8 GB RAM
The drive has all my backups since I bought this computer (3 months ago, switching over from WinXP) so I want to get another drive and have a good backup on it before I reformat this one.

BTW, I found this commentary on a very similar problem:

http://play-control.org/ewing/jibberjabber/on_time_machine_errors_and_.html

On Time Machine Errors and Data Integrity...
[...]
I spoke with a DTS engineer after Cocoaheads, and he confirmed that Time Machine does not do any integrity checks.
 
Joined
Oct 13, 2006
Messages
724
Reaction score
60
Points
28
Location
Blacksburg, VA
Your Mac's Specs
13'' Macbook w/ 2Ghz Core Duo, 2GB DDR2, 250GB HD, 10.5.4. iPod Touch.
Indeed.

I had a similar integrity-based issue with my TM drive a month ago. Everything pointed to a simple repair of the disk, but Disk Manager would fail every time (can't remember why). A manual repair via "fsck_hfs -y" within the terminal did the trick however.
 

Shop Amazon


Shop for your Apple, Mac, iPhone and other computer products on Amazon.
We are a participant in the Amazon Services LLC Associates Program, an affiliate program designed to provide a means for us to earn fees by linking to Amazon and affiliated sites.
Top