Q: Time Machine backup very slow in Lion

I'm also having Time Machine issues. I have an iMac with a 1Tb hard-drive connected via USB. It worked fine until I upgraded to Lion, then TM was stuck on 'Preparing to back-up'. After reading various posts, I deleted the back-up data (reluctantly) and set up a new back-up. Ten days later, it's still stuck on Indexing. Surely it shouldn't take as long as that?

Any suggestions, please?

Cheers

Phil

Philip Raby1 wrote:

 

Ten days later, it's still stuck on Indexing. Surely it shouldn't take as long as that?

Could you elaborate on that? Does backupd log "waiting for index"?

If you read my posts above, you'll see that my problem was the file system events database, but before you try trashing that (I'm not sure what's the safest way to trash it), you should do the following:

1) Check with disk utility that both your internal disk(s) and the backup disks are OK, and if necessary, repair them.

2) Try to reset spotlight indexing. The easiest way to do that is via the Spotlight System Preferences pane. Simply drag your disks into the lists of exceptions, wait a little while for Spotlight to stop indexing, and then remove your disks from the exceptions again to start indexing anew. It might be wise to turn TM off before you do this, and wait for a while before turning TM on again.

Thanks for your reply. I'm trying what you suggest now.

With regard to the backup log, I'm getting pages of the following, which means little to me:

A437-786B05252E04, auto-retries=2, manual-retries=0

2010-07-21 22:06:51.545 Backup[40950:6213] POST /Info.woa/wa/XMLRPC/accountInfo?username=philraby (FAILED), httpStatusCode:-1, errorType:103 (domain=NSPOSIXErrorDomain, code=60), transactionState:5, txnId:0E9F3F73-D355-469C-82D7-273192E1FDFB, auto-retries=2, manual-retries=0

2010-07-21 22:11:06.678 Backup[40950:6213] POST /Info.woa/wa/XMLRPC/accountInfo?username=philraby (FAILED), httpStatusCode:-1, errorType:103 (domain=NSPOSIXErrorDomain, code=60), transactionState:5, txnId:E1516EF7-46D1-40D3-91D4-80C2E12325D7, auto-retries=2, manual-retries=0

2010-07-21 22:14:51.796 Backup[40950:6213] POST /Info.woa/wa/XMLRPC/accountInfo?username=philraby (FAILED), httpStatusCode:-1, errorType:103 (domain=NSPOSIXErrorDomain, code=60), transactionState:5, txnId:176F01B6-A78C-4BD5-A31B-474F14093600, auto-retries=2, manual-retries=0

2010-07-21 22:19:06.925 Backup[40950:6213] POST /Info.woa/wa/XMLRPC/accountInfo?username=philraby (FAILED), httpStatusCode:-1, errorType:103 (domain=NSPOSIXErrorDomain, code=60), transactionState:5, txnId:6BD4ADF2-C3C5-4EF7-9A72-AF19FF081343, auto-retries=2, manual-retries=0

2010-07-21 22:22:52.039 Backup[40950:6213] POST /Info.woa/wa/XMLRPC/accountInfo?username=philraby (FAILED), httpStatusCode:-1, errorType:103 (domain=NSPOSIXErrorDomain, code=60), transactionState:5, txnId:34DFF5D0-CD85-41F6-859D-E8963FCE68B0, auto-retries=2, manual-retries=0

2010-07-21 22:26:39.655 Backup[40950:6213] POST /Info.woa/wa/XMLRPC/accountInfo?username=philraby (FAILED), httpStatusCode:-1, errorType:103 (domain=NSPOSIXErrorDomain, code=60), transactionState:5, txnId:90C728E6-3D89-44DC-B688-8F0D58876950, auto-retries=2, manual-retries=0

2010-07-21 22:30:24.772 Backup[40950:6213] POST /Info.woa/wa/XMLRPC/accountInfo?username=philraby (FAILED), httpStatusCode:-1, errorType:103 (domain=NSPOSIXErrorDomain, code=60), transactionState:5, txnId:16EAFCCB-5951-4314-91B4-E712421CA773, auto-retries=2, manual-retries=0

2010-07-21 22:35:06.912 Backup[40950:6213] POST /Info.woa/wa/XMLRPC/accountInfo?username=philraby (FAILED), httpStatusCode:-1, errorType:103 (domain=NSPOSIXErrorDomain, code=60), transactionState:5, txnId:8B556784-9DAC-47FE-8779-39C7962C1149, auto-retries=2, manual-retries=0

2010-07-21 22:38:52.022 Backup[40950:6213] POST /Info.woa/wa/XMLRPC/accountInfo?username=philraby (FAILED), httpStatusCode:-1, errorType:103 (domain=NSPOSIXErrorDomain, code=60), transactionState:5, txnId:D7AC05D0-DA69-4563-8140-33A79DBE3EA1, auto-retries=2, manual-retries=0

2010-07-21 22:43:06.649 Backup[40950:6213] POST /Info.woa/wa/XMLRPC/accountInfo?username=philraby (FAILED), httpStatusCode:-1, errorType:103 (domain=NSPOSIXErrorDomain, code=60), transactionState:5, txnId:80BED627-001E-4EB1-B067-255D74B820CF, auto-retries=2, manual-retries=0

2010-07-21 22:46:51.763 Backup[40950:6213] POST /Info.woa/wa/XMLRPC/accountInfo?username=philraby (FAILED), httpStatusCode:-1, errorType:103 (domain=NSPOSIXErrorDomain, code=60), transactionState:5, txnId:3EC5670D-CE04-4520-8AA7-69025DFECB17, auto-retries=2, manual-retries=0

2010-07-21 22:51:06.891 Backup[40950:6213] POST /Info.woa/wa/XMLRPC/accountInfo?username=philraby (FAILED), httpStatusCode:-1, errorType:103 (domain=NSPOSIXErrorDomain, code=60), transactionState:5, txnId:27F244F4-F8AB-44DB-9E9E-0FD7C9FC052C, auto-retries=2, manual-retries=0

2010-07-21 22:54:52.002 Backup[40950:6213] POST /Info.woa/wa/XMLRPC/accountInfo?username=philraby (FAILED), httpStatusCode:-1, errorType:103 (domain=NSPOSIXErrorDomain, code=60), transactionState:5, txnId:63DF2875-EEFD-498E-AF9E-15491A2D7EFD, auto-retries=2, manual-retries=0

Philip Raby1 wrote:

 

Thanks for your reply. I'm trying what you suggest now.

 

With regard to the backup log, I'm getting pages of the following, which means little to me:

 

2010-07-21 22:06:51.545 Backup[40950:6213] POST /Info.woa/wa/XMLRPC/accountInfo?username=philraby (FAILED), httpStatusCode:-1, errorType:103 (domain=NSPOSIXErrorDomain, code=60), transactionState:5, txnId:0E9F3F73-D355-469C-82D7-273192E1FDFB, auto-retries=2, manual-retries=0

I'm pretty sure those messages are from the MobileMe Backup program (you seem to be unable to log on ot MobileMe) and NOT from Time Machine, which appears as com.apple.backupd in the system.log.

Ah, my apologies, that makes sense. I've looked in Console and found lots of these type of messages:

Aug 31 11:29:28 Philip-Rabys-Computer-2 com.apple.backupd[573]: Waiting for index to be ready (100)

Aug 31 11:30:21 Philip-Rabys-Computer-2 UserEventAgent[11]: com.apple.backupd-auto launchd job disabled

Aug 31 11:30:21 Philip-Rabys-Computer-2 UserEventAgent[11]: com.apple.backupd-wake launchd job disabled

Aug 31 11:30:21 Philip-Rabys-Computer-2 UserEventAgent[11]: com.apple.backupd-attach launchd job disabled

Aug 31 11:30:22 Philip-Rabys-Computer-2 com.apple.backupd[573]: Copied 0 files (0 bytes) from volume Macintosh HD.

Aug 31 11:30:23 Philip-Rabys-Computer-2 com.apple.backupd[573]: Backup canceled.

Aug 31 11:48:58 Philip-Rabys-Computer-2 UserEventAgent[11]: com.apple.backupd-auto launchd job enabled

Aug 31 11:48:58 Philip-Rabys-Computer-2 UserEventAgent[11]: com.apple.backupd-wake launchd job enabled

Aug 31 11:48:58 Philip-Rabys-Computer-2 UserEventAgent[11]: com.apple.backupd-attach launchd job enabled

Aug 31 11:49:09 Philip-Rabys-Computer-2 com.apple.backupd[664]: Starting standard

I've also downloaded Time Machine Buddy and this shows:

Starting standard backup

Error loading /Library/Plug-ins/DiskImages/VirtualPCDiskImagePlugin.bundle/Contents/MacOS/Vir tualPCDiskImagePlugin:  dlopen(/Library/Plug-ins/DiskImages/VirtualPCDiskImagePlugin.bundle/Contents/Ma cOS/VirtualPCDiskImagePlugin, 262): no suitable image found.  Did find:

Cannot find function pointer MacDiskImagePluginFactory for factory 7F1FD83E-6684-11D8-968F-000A957703C0 in CFBundle/CFPlugIn 0x10e02ee30 </Library/Plug-ins/DiskImages/VirtualPCDiskImagePlugin.bundle> (bundle, not loaded)

Backing up to: /Volumes/Time Machine Backups/Backups.backupdb

Backup content size: 203.0 GB excluded items size: 3.8 GB for volume Macintosh HD

Backup content size: 21.8 GB excluded items size: 30.5 MB for volume Phil Raby's removeable drive

267.69 GB required (including padding), 892.84 GB available

Thanks again.

Phil

I think you can ignore the messages about the missing Virtual PC disk image plugin. Otherwise, what you've shown so far just shows that you've turned backup off and on again, and that it has started to back up. Let us know what the logs say after a while!

Edit: I missed the first "waiting for index" line. That's normal when the index is in fact not ready (Spotlight is still indexing), but it shouldn't go on like that for days.

Thanks again. Three hours later and nothing fresh in the log, while TM is saying 'Indexing backup'. How long should this take? I have about 218Gb of data.

Cheers

Phil

I think it sometimes may take some hours. How is it doing now?

Since excluding the back-up drive from Spotlight, there's now a change to 'Waiting to back-up'. Maybe we've made progress?

Phil

Not sure what that means. What has it logged? (try: grep backupd /var/log/system.log)

Philip Raby1 wrote:

 

Thanks again. Three hours later and nothing fresh in the log, while TM is saying 'Indexing backup'. How long should this take? I have about 218Gb of data.

 

Cheers

 

Phil

Took me over 5 hours over WiFi for 90Gb.  I've seen reports of it taking over 20 hours over WiFi.

Just be paitent and don't exclude the TM drive from Spotlight.

Tony

My drive is connected via USB, so should be faster, I assume.

Still 'Waiting to Back up' six hours after my last post. Surely this isn't correct?

Phil

Agreed, but look in the Console App, and search for backupd.  If you see continous messages of "wating for ....", then I would wait a little longer.

You should also consider running a Disk Repair with Disk Utility on the TM Volume.

Tony

Thanks for the reply.

Oddly, today I can't find anything in Console relating to backupd. There was yesterday but not now...

I've run Disk Repair.

Phil

Looks like my Lion backup on Time Capsule is now smooth as it use to be when I had Snow Leopard installed.

It is taking approx 5 minutes for 250 Mb on WiFi.

What I did was to unflag all the Spotlight categories in System Preference, then I did a backup that took quite some time. After that I restarted the mac and also Time Capsule, I flagged again the categories I am interested in Spotlight (basically all of them except System Preferences and Fonts). Looks like its now working fine and quick since the last 8 backup over a week. As I said 250 Mb in 5 minutes from start to end. Lets see....