Want to highlight a helpful answer? Upvote!

Did someone help you, or did an answer or User Tip resolve your issue? Upvote by selecting the upvote arrow. Your feedback helps others! Learn more about when to upvote >

Looks like no one’s replied in a while. To start the conversation again, simply ask a new question.

User profile for user: Barry Lyga
Barry Lyga Author
User level: Level 1
5 points

Time Machine Needs too much space, goes too slow?

I noticed recently that TM was taking a long time during backups, sometimes as long as 15-20 minutes to back up data in the MB, not GB, range. While doing some troubleshooting, I installed Time Machine Buddy. When I looked at the logs, I noticed stuff like this:


Found 145 files (91.5 MB) needing backup

5 GB required (including padding), 984.9 GB available

Copied 3434 files (8.8 MB) from volume myMac.

Using file event preflight for myMac

Will copy (305 bytes) from myMac

Found 14 files (305 bytes) needing backup

4.89 GB required (including padding), 984.89 GB available


So...to backup 91.5MB, it needs 5GB?


To backup 305 bytes (not KB, not MB -- bytes!), it needs 4.89GB?


What the heck? Could this be what's slowing down my backups -- some glitch making TM think it needs vastly more space than it actually needs?

iMac, OS X Mountain Lion (10.8.2)

Posted on Feb 13, 2013 10:59 AM

Reply
37 replies
User profile for user: Linc Davis
Linc Davis
User level: Level 10
209,535 points

Feb 13, 2013 2:04 PM in response to Barry Lyga

If you have more than one user account, these instructions must be carried out as an administrator.

Launch the Console application in any of the following ways:

☞ Enter the first few letters of its name into a Spotlight search. Select it in the results (it should be at the top.)

☞ In the Finder, select Go ▹ Utilities from the menu bar, or press the key combination shift-command-U. The application is in the folder that opens.

☞ Open LaunchPad. Click Utilities, then Console in the icon grid.

Make sure the title of the Console window is All Messages. If it isn't, select All Messages from the SYSTEM LOG QUERIES menu on the left.

Enter the word "Starting" (without the quotes) in the String Matching text field. You should now see log messages with the words "Starting * backup," where * represents any of the words "automatic," "manual," or "standard." Note the timestamp of the last such message. Clear the text field and scroll back in the log to that time. Select the messages timestamped from then until the end of the backup, or the end of the log if that's not clear. Copy them (command-C) to the Clipboard. Paste (command-V) into a reply to this message.

If there are runs of repeated messages, post only one example of each. Don't post many repetitions of the same message.

When posting a log extract, be selective. Don't post more than is requested.

Please do not indiscriminately dump thousands of lines from the log into this discussion.


Some personal information, such as the names of your files, may be included — anonymize before posting.

Reply
User profile for user: Barry Lyga
Barry Lyga Author
User level: Level 1
5 points

Feb 13, 2013 2:22 PM in response to Linc Davis

Hi, Linc,


OK, here you go... I deleted several duplicate lines referring, mainly, to an inability to connect to my iPhone or iPad -- apparently iTunes is having trouble finding them on my network.


Sorry this is so long. I can prune it further or just paste in something from Time Machine Buddy, if that's easier.


2/13/13 4:50:15.659 PM com.apple.backupd[6536]: Starting automatic backup

2/13/13 4:50:16.204 PM com.apple.backupd[6536]: Backing up to: /Volumes/Chronovessel/Backups.backupdb

2/13/13 4:50:17.364 PM com.apple.backupd[6536]: Deep event scan at path:/Users/barrylyga/Pictures/iPhoto Library/Database/apdb reason:must scan subdirs|missed reservation|

2/13/13 4:50:17.366 PM com.apple.backupd[6536]: Finished scan

2/13/13 4:50:27.261 PM mdworker[6540]: Unable to talk to lsboxd

2/13/13 4:50:27.307 PM sandboxd[6541]: ([6540]) mdworker(6540) deny mach-lookup com.apple.ls.boxd

2/13/13 4:50:27.000 PM kernel[0]: Sandbox: sandboxd(6541) deny mach-lookup com.apple.coresymbolicationd

2/13/13 4:50:35.449 PM com.apple.usbmuxd[27]: HandleUSBMuxConnect Client 0x1004233f0-AppleMobileDeviceHelper/com.apple.SyncServices.AppleMobileDeviceHel per requesting attach to 0x67:62078 failed, no such device

2/13/13 4:50:35.450 PM AppleMobileDeviceHelper[846]: AMDeviceConnect (thread 0x7fff7bc07180): Could not connect to lockdown port (62078) on device 103 - 93b2e94e54c5be181f55077904681a20bd8cf107: 0xe8000084.

2/13/13 4:50:35.451 PM AppleMobileDeviceHelper[846]: 846:2076209536|DeviceLinkListener.c:_copyMobileDeviceValue| ERROR: Could not connect to attached device: This device is no longer connected. (132)

2/13/13 4:50:35.667 PM SyncServer[6544]: [0x7f9f0240bda0] |DataManager|Warning| Client com.apple.Mail sync alert tool path /System/Library/Frameworks/Message.framework/Resources/MailSync does not exist.

2/13/13 4:50:55.211 PM iTunes[842]: _NotificationSocketReadCallbackGCD (thread 0x7fff7bc07180): Unexpected connection closure...

2/13/13 4:51:28.212 PM WindowServer[78]: _CGXSetWindowHasMainAppearance: Operation on a window 0xf requiring rights kCGSWindowRightOwner by caller Dashboard

2/13/13 4:52:23.060 PM com.apple.backupd[6536]: Found 205 files (95.9 MB) needing backup

2/13/13 4:52:24.781 PM com.apple.backupd[6536]: 5.01 GB required (including padding), 984.87 GB available

2/13/13 4:54:08.578 PM WeatherMin[418]: Getting weather status from 12 availible stations.

2/13/13 4:54:08.579 PM WeatherMin[418]: Getting forecast for 40.6781, -74.0032.

2/13/13 4:54:10.105 PM WeatherMin[418]: Weather status, forecast updated okay.

2/13/13 4:54:30.528 PM mdworker[6728]: Unable to talk to lsboxd

2/13/13 4:54:30.000 PM kernel[0]: Sandbox: sandboxd(6729) deny mach-lookup com.apple.coresymbolicationd

2/13/13 4:54:30.788 PM sandboxd[6729]: ([6728]) mdworker(6728) deny mach-lookup com.apple.ls.boxd

2/13/13 4:55:14.608 PM AppleMobileDeviceHelper[846]: AMDeviceConnect (thread 0x7fff7bc07180): Could not connect to lockdown port (62078) on device 104 - 302e33c46f2e4044e59e471298fc4c09f1c86f6d: 0xe8000084.

2/13/13 4:55:14.981 PM SyncServer[6734]: [0x7fd1c840bda0] |DataManager|Warning| Client com.apple.Mail sync alert tool path /System/Library/Frameworks/Message.framework/Resources/MailSync does not exist.

2/13/13 4:55:20.040 PM iTunes[842]: _NotificationSocketReadCallbackGCD (thread 0x7fff7bc07180): Unexpected connection closure...

2/13/13 4:57:34.301 PM com.apple.backupd[6536]: Copied 18751 files (13.2 MB) from volume myMac.

2/13/13 4:57:34.796 PM com.apple.backupd[6536]: Using file event preflight for myMac

2/13/13 4:57:34.946 PM com.apple.backupd[6536]: Will copy (6.5 MB) from myMac

2/13/13 4:57:34.947 PM com.apple.backupd[6536]: Found 60 files (6.5 MB) needing backup

2/13/13 4:57:34.947 PM com.apple.backupd[6536]: 4.9 GB required (including padding), 984.85 GB available

2/13/13 4:57:59.690 PM GyazMail[261]: 10 no-break space (U+00A0) replaced with space (U+0020)

2/13/13 4:58:26.085 PM com.apple.backupd[6536]: Copied 2908 files (6.5 MB) from volume myMac.

2/13/13 4:58:28.850 PM com.apple.backupd[6536]: Created new backup: 2013-02-13-165828

2/13/13 4:58:37.879 PM com.apple.backupd[6536]: Starting post-backup thinning

2/13/13 4:59:44.501 PM WindowServer[78]: CGXRegisterWindowWithSystemStatusBar: window d already registered

2/13/13 5:00:50.976 PM mdworker[6768]: Unable to talk to lsboxd

2/13/13 5:00:51.000 PM kernel[0]: Sandbox: sandboxd(6769) deny mach-lookup com.apple.coresymbolicationd

2/13/13 5:00:51.891 PM mdworker[6767]: Unable to talk to lsboxd

2/13/13 5:00:52.050 PM sandboxd[6769]: ([6768]) mdworker(6768) deny mach-lookup com.apple.ls.boxd

2/13/13 5:00:52.057 PM sandboxd[6769]: ([6767]) mdworker(6767) deny mach-lookup com.apple.ls.boxd

2/13/13 5:02:43.986 PM SyncServer[6784]: [0x7fa67ac0bda0] |DataManager|Warning| Client com.apple.Mail sync alert tool path /System/Library/Frameworks/Message.framework/Resources/MailSync does not exist.

2/13/13 5:03:36.429 PM com.apple.Preview.TrustedBookmarksService[6790]: Failure to de-serialize bookmark data file.

2/13/13 5:03:37.043 PM com.apple.security.pboxd[6791]: Bug: 12C60: liblaunch.dylib + 23849 [2F71CAF8-6524-329E-AC56-C506658B4C0C]: 0x25

2/13/13 5:04:17.658 PM WindowServer[78]: CGXRegisterWindowWithSystemStatusBar: window d already registered

2/13/13 5:05:03.120 PM lsboxd[347]: @AE relay 4755524c:4755524c

2/13/13 5:05:05.378 PM WebProcess[6803]: objc[6803]: Object 0x7fc1f04136f0 of class NSUserDefaults autoreleased with no pool in place - just leaking - break on objc_autoreleaseNoPool() to debug

2/13/13 5:05:05.389 PM WebProcess[6803]: objc[6803]: Object 0x7fc1f04136f0 of class NSUserDefaults autoreleased with no pool in place - just leaking - break on objc_autoreleaseNoPool() to debug

2/13/13 5:05:14.978 PM com.apple.backupd[6536]: Deleted /Volumes/Chronovessel/Backups.backupdb/iMac/2013-02-12-163340 (25 MB)

2/13/13 5:05:14.978 PM com.apple.backupd[6536]: Post-back up thinning complete: 1 expired backups removed

2/13/13 5:05:17.426 PM com.apple.backupd[6536]: Backup completed successfully.

Reply
User profile for user: Barry Lyga
Barry Lyga Author
User level: Level 1
5 points

Feb 13, 2013 3:37 PM in response to Linc Davis

Thanks, Linc,


I guess what I don't understand, then, is why it takes something like 7 minutes to copy a measly 100MB over Firewire. Why does it "pad" a hundred megs with 4 or 5 gigs of space? (And I guess a third thing: The backup drive is big enough that there's no reason to delete backups yet -- there's still plenty of space on it.)


Anyway, I'm comforted that at least there's nothing WRONG with the backups. (I did try copying a file to the drive manually in order to test it, and it copied lickety-split, so I don't think it's the drive itself.)


I believe you when you say it's a normal backup. I'm just not sure why, for example, right now it's backing up 310MB and has been stuck on 3.3MB of 310MB for over a minute.

Reply
User profile for user: Pondini
Pondini
User level: Level 8
38,863 points

Feb 14, 2013 9:09 AM in response to Barry Lyga

Barry Lyga wrote:

. . .

I guess what I don't understand, then, is why it takes something like 7 minutes to copy a measly 100MB over Firewire.

Per the log, it took 5 minutes (4.52.23 to 4.57.34) to copy 13.2 MB on the first pass -- far too long, absent some sort of problem or other uses of the drive, cpu, etc. Also note it claims to have copied 18,751 files -- that's always high (I suspect it counts metadata like permissions and extended attributes separately), but not that high.


Be sure you don't have some other process reading from or writing to the TM or other drives at the same time, and that your CPU isn't maxed-out.


Why does it "pad" a hundred megs with 4 or 5 gigs of space?

All that's doing is making sure there's enough workspace on the backup drive. In some situations, TM may need to duplicate the Spotlight index, so it requires enough space for that, and other things, on each backup. If there isn't enough, it will delete old backups to make room, but that hasn't happened here.


(And I guess a third thing: The backup drive is big enough that there's no reason to delete backups yet -- there's still plenty of space on it.)

TN routinely "thins" backups; keeping only the first of the day after 24 hours, then one per week after a month. That's entirely different from deleting old ones to make room on the backup drive.


(I did try copying a file to the drive manually in order to test it, and it copied lickety-split, so I don't think it's the drive itself.)

That's a hint, but not a good comparison -- there's a whole lot more going on with a backup, especially one that says it's copied over 18,000 files.



It's not clear just what's wrong here. As Linc says, the backup is otherwise normal; it's just taking all sorts of time both to do the actual backup and to delete old backups (nearly 7 minutes for the one above). As an example, that backup, including deletion of an old one, usually takes less than a minute for me, to a F/W 800 drive. Via F/W 400, it would likely be somewhere from one to two minutes.


Please review the things in the green box of #D2 in Time Machine - Troubleshooting. If there are any things there you haven't done yet, give them a try.


If none of that helps, it's possible the Spotlight index is damaged in a way that Repair Disk can't find. Try deleting it, per the pink box in #D2.


Also, we've seen a few reports of very slow backups and very high file counts that seem to be caused by some very odd files. Look in both the Library/Preferences folder at the top level of your HD, and the one in your home folder (you have to hold the Option key while clicking GO in a Finder menubar to get to that one). See if there are hundreds or thousands of files there with identical names except for odd gibberish -- 4 or more characters, usually before the ".plist". They usually have a size of zero. If so, delete them and Restart your Mac.


As a last resort, do you have another drive you can try? If not, consider getting one -- once you've used it to rule out or implicate your current drive, you can use it to keep "secondary" backups -- that's always prudent, but especially if you're having problems with your primary backups. See Time Machine - Frequently Asked Question #27 for an explanation and some suggestions.

Reply
User profile for user: Barry Lyga
Barry Lyga Author
User level: Level 1
5 points

Feb 14, 2013 12:08 PM in response to Pondini

Tried that stuff and still taking a long, long time. I was checking into the .plist issues. I have a bunch of zero-size files (a couple hundred), but none of them seem to fall into the category you describe. They have names like: com.apple.AddressBook.plist.B4zioyr.


I guess I'll have to pick up a spare drive at some point and give that a shot. And maybe reinstall ML just for the **** of it.

Reply
User profile for user: Pondini
Pondini
User level: Level 8
38,863 points

Feb 14, 2013 12:16 PM in response to Barry Lyga

Barry Lyga wrote:

. . .

They have names like: com.apple.AddressBook.plist.B4zioyr.

That's them. Some had the odd characters before the .plist, some after. Delete them.



I guess I'll have to pick up a spare drive at some point and give that a shot.

Always prudent to keep secondary backups.


And maybe reinstall ML just for the **** of it.

I'd install the most recent "combo" first. If that doesn't do it, a fresh copy of OSX might (I'm not talking about a clean install, just a fresh copy of OSX). Neither takes very long.


See the blue box in Installing the ''combo'' update and/or Reinstalling OSX.

Reply
User profile for user: Barry Lyga
Barry Lyga Author
User level: Level 1
5 points

Feb 16, 2013 8:57 AM in response to Pondini

*sigh*


Well, I reinstalled ML. Reset Time Machine by deleting the .plist. Excluded Crashplan and Dropbox cache folders. Switched from Firewire to USB.


Still dog-slow. It seems to backup to a certain point, then just stall. I can hear the drive grinding away, but TM will be stuck at "Backing up 845KB of 23.2MB" for a minute or two (or three...), then jump ahead, then "stick" again at 7.3MB for a while, etc.


From Time Machine Buddy, just for the heck of it:


Starting automatic backup

Backing up to: /Volumes/Chronovessel/Backups.backupdb

Using file event preflight for myMac

Will copy (21.7 MB) from myMac

Found 311 files (21.7 MB) needing backup

5.8 GB required (including padding), 979 GB available

Copied 32095 files (23.8 MB) from volume myMac.

Using file event preflight for myMac

Will copy (502 bytes) from myMac

Found 26 files (502 bytes) needing backup

5.77 GB required (including padding), 978.97 GB available

Copied 1545 files (535 bytes) from volume myMac.

Created new backup: 2013-02-16-115104

Starting post-backup thinning

Deleted /Volumes/Chronovessel/Backups.backupdb/iMac/2013-02-14-213741 (29 MB)

Post-back up thinning complete: 1 expired backups removed

Backup completed successfully.



At this point, I'll have to pick up a spare drive when I have the opportunity and see if that works. Because nothing else, sadly, has.


Thanks for the help, Linc & Pondini!

Reply
User profile for user: Pondini
Pondini
User level: Level 8
38,863 points

Feb 16, 2013 11:15 AM in response to Barry Lyga

Barry Lyga wrote:

. . .

It seems to backup to a certain point, then just stall. I can hear the drive grinding away, but TM will be stuck at "Backing up 845KB of 23.2MB" for a minute or two (or three...), then jump ahead, then "stick" again at 7.3MB for a while, etc.

By itself, that's not necessarily a problem. The counts don't always seem to get updated frequently.



Will copy (21.7 MB) from myMac

Found 311 files (21.7 MB) needing backup

5.8 GB required (including padding), 979 GB available

Copied 32095 files (23.8 MB) from volume myMac.

There's the huge discrepency in file counts again. The count of count of files copied is often much larger than the first message, but not by that large a factor.


At this point, I'll have to pick up a spare drive when I have the opportunity and see if that works. Because nothing else, sadly, has.

Good plan -- you can't have too many backups, and that may rule out a problem with the TM drive.


Did you delete all those funky .plist files?


And you have Repaired your backups and Verified your internal HD (item 5 in the green box of #D2 in Time Machine - Troubleshooting?)


Have you tried a SafeBoot (item 16 there)?


Reply

Time Machine Needs too much space, goes too slow?

Welcome to Apple Support Community
A forum where Apple customers help each other with their products. Get started with your Apple ID.
Learn more Sign up