Time Machine backup very slow in Lion

It took about 8 hours, but the Time Machine Backups volume eventually did dismount itself. My hourly backups are now taking about 9 minutes (most of that in "Cleaning up..." mode) and the volume is properly dismounting itself after each backup.

Thanks to all, especially Tony and Pondini. Now I just have my fingers crossed that it keeps working this way.

Disk Repair found no errors, so everything just seems to be fine. My backups now usually also take about 9 minutes, sometimes a bit longer. A lot of "Cleaning Up..." also, but that depends on how much I've used my computer the day before and the last week.

I have one more question: is the volume supposed to eject itself after you have used time machine ('Enter Time Machine') and left it by cancelling for example? I still have to eject manually (asking an admin password so something must be tying it up), or wait for the next hourly backup were it will eject after finishing.

ReyeBan wrote:

I have one more question: is the volume supposed to eject itself after you have used time machine ('Enter Time Machine') and left it by cancelling for example? I still have to eject manually (asking an admin password so something must be tying it up), or wait for the next hourly backup were it will eject after finishing.

That's how it always worked for me (even with SL).

except that it never asks for my Admin Password (see if anything is happening in Console).

Yes, that's how it always worked for me, also. If you manually mount the volume, or it is mounted by a command to "Enter Time Machine" it will not automatically dismount - until the next backup is complete.

Nothing even during a time Machine Backup!

But the Time Machine logs should show up during or shortly after the backup happens?

Anyway! After repairing my backup drive that took more than 16 hours Time Machine backups work without problem. They take slightly longer than with Snow Leopard (most of the time preparing and cleaning), but guess my old MacBook 2007 with 2,5 GB is to blame for that.

So I am happy my MacBook is backed up regularly again! :-)

Thanks again Pondini for all your help!

Tony T1 wrote:

That's how it always worked for me (even with SL).

except that it never asks for my Admin Password (see if anything is happening in Console).

Tony

It probably asks my password because I normally work from a non-admin account. I'll try from an admin account.

Thanks

Reye

Georg Portenkirchner wrote:

But the Time Machine logs should show up during or shortly after the backup happens?

Georg

Are you logged in with admin rights? If you're working from a non-admin account, you won't see those logs. They show up immediately in Console for admins.

Reye

Yep, no password is asked when I am logged on with admin rights.

ReyeBan wrote:

Georg Portenkirchner wrote:

But the Time Machine logs should show up during or shortly after the backup happens?

Georg

Are you logged in with admin rights? If you're working from a non-admin account, you won't see those logs. They show up immediately in Console for admins.

Reye

Thanks Reye. You are right, I was looking at the logs from my "every day" account.

Here we go again. Backups worked for a day and a half. First backup today worked but all of them since will not eject even though the backups were successful.

I thought mine was reindexing again too after working correctly for 2 days since I saw in the time machine icon messages 'Indexing Backup' at the start of an hourly backup. This was how my previous reindexing also started. However, this one seems to have finished a lot quicker since when I came back to my computer after 30 to 45 minutes, the backup disk was ejected and no indexing is going on. Maybe it only indexes the last couple of backups, I don't know. I just hope that the next hourly backup doesn't restart an 8 hour indexing again.

Hi everyone,

I just wanted to add something to this discussion even though my solution was painfully obvious. When i set up my time capsule for the first time i decided to create a new network instead of bridge over my existing network. Everything was working fine, but then all of a sudden back ups, the preparing and cleaning up stage, pretty much the whole process slowed to a crawl. WHen i was at my wits end I was about to switch off my wi-fi and use a USB to do the transfer, i noticed that the actual wi-fi network that was being used was my old network and not the one that the time capsule was set up on. once I switched my wi-fi network to the time capsule as my primary things were moving very smoothly and very quickly.

Cheers.

Another data point.

Backing up to a MacMini running Snow Leopard. (Not SL Server, SL). This runs MacZFS and shares via AFP to multiple family machines that backup via TM. The MacMini is dedicated to this purpose.

Because of MacZFS I'm extremely confident that there are no disk errors. (The pool contains three 1.5TB disks in a RAIDZ format).

There are daily snapshots on the ZFS pool, so if Bad Things happen with TM I can always roll back.

One family member, running SL on a MBP, has just backed up 743GB. It took over a day via WiFi.

I've just upgraded SL to Lion on a MacPro1,1. This has three disks with multiple partitions on one disk. The main disk though is a single patition (apart from Bootcamp).

The main disk is brand new. SInce I had insufficient room on my existing disk, I bought a new 2TB and copied over the old disk onto the new, and then upgraded to Lion. As a consequence I'm pretty happy that the filesystem on the main disk is in good shape.

The MacPro is connected via GigE to the MacMini. It's quite capable of transferring hundred of Mbps over this link (as observed during the TM backup). When it copies, it does so very quickly, It just pauses for very long times between copying.

I removed ALL files from my share on the backup server, so TM started anew.

Aug 12 22:40:28 xxx com.apple.backupd[15168]: Starting standard backup

Aug 12 22:40:28 xxx com.apple.backupd[15168]: Attempting to mount network destination URL: afp://x@y._afpovertcp._tcp.local/Wells-3

Aug 12 22:40:30 xxx com.apple.backupd[15168]: Mounted network destination at mountpoint: /Volumes/Wells-3 using URL: afp://x@y._afpovertcp._tcp.local/Wells-3

Aug 12 22:40:45 xxx com.apple.backupd[15168]: Creating disk image /Volumes/Wells-3/xxx.sparsebundle

Aug 12 22:41:10 xxx com.apple.backupd[15168]: Failed to hide extension on /Volumes/Wells-3/xxx.sparsebundle, error: Error Domain=NSCocoaErrorDomain Code=4 "The file “xxx.sparsebundle” doesn’t exist." UserInfo=0x7fa92d305660 {NSURL=/Volumes/Wells-3/xxx.sparsebundle/, NSFilePath=/Volumes/Wells-3/xxx.sparsebundle, NSUnderlyingError=0x7fa92d3051f0 "The operation couldn’t be completed. No such file or directory"}.

Aug 12 22:41:17 xxx com.apple.backupd[15168]: QUICKCHECK ONLY; FILESYSTEM CLEAN

Aug 12 22:41:20 xxx com.apple.backupd[15168]: Disk image /Volumes/Wells-3/xxx.sparsebundle mounted at: /Volumes/Time Machine Backups

Aug 12 22:41:21 xxx com.apple.backupd[15168]: Backing up to: /Volumes/Time Machine Backups/Backups.backupdb

Aug 12 22:41:21 xxx com.apple.backupd[15168]: Ownership is disabled on the backup destination volume. Enabling.

Aug 12 22:41:22 xxx com.apple.backupd[15168]: Backup content size: 2.8 GB excluded items size: 13.2 MB for volume H

Aug 12 22:43:01 xxx com.apple.backupd[15168]: Backup content size: 737.0 GB excluded items size: 551.8 GB for volume C

Aug 12 22:46:01 xxx com.apple.backupd[15168]: Backup content size: 132.3 GB excluded items size: 45.7 GB for volume B

Aug 12 22:46:11 xxx com.apple.backupd[15168]: Backup content size: 31.9 GB excluded items size: 1.2 GB for volume E

Aug 12 22:46:12 xxx com.apple.backupd[15168]: Backup content size: 32.3 GB excluded items size: 65.1 MB for volume D

Aug 12 22:46:12 xxx com.apple.backupd[15168]: 404.91 GB required (including padding), 696.52 GB available

Aug 12 22:46:12 xxx com.apple.backupd[15168]: Waiting for index to be ready (101)

Aug 12 22:52:45 xxx com.apple.backupd[15168]: CoreEndianFlipData: error -4940 returned for rsrc type FREF (id 131, length 7, native = no)

Aug 12 22:54:25 xxx com.apple.backupd[15168]: Copied 16120 files (1.3 GB) from volume H.

Aug 12 23:41:23 xxx com.apple.backupd[15168]: Copied 16.4 GB of 337.4 GB, 295032 of 3687840 items

Aug 13 00:41:24 xxx com.apple.backupd[15168]: Copied 23.9 GB of 337.4 GB, 425369 of 3687840 items

Aug 13 01:41:28 xxx com.apple.backupd[15168]: Copied 49.1 GB of 337.4 GB, 545418 of 3687840 items

Aug 13 02:47:08 xxx com.apple.backupd[15168]: Copied 52.3 GB of 337.4 GB, 565276 of 3687840 items

Aug 13 03:47:11 xxx com.apple.backupd[15168]: Copied 62.4 GB of 337.4 GB, 640777 of 3687840 items

Aug 13 04:47:11 xxx com.apple.backupd[15168]: Copied 68.3 GB of 337.4 GB, 908891 of 3687840 items

Aug 13 06:01:03 xxx com.apple.backupd[15168]: Copied 69.3 GB of 337.4 GB, 909417 of 3687840 items

Aug 13 07:19:59 xxx com.apple.backupd[15168]: Copied 71.9 GB of 337.4 GB, 945519 of 3687840 items

Aug 13 08:46:23 xxx com.apple.backupd[15168]: Copied 73.8 GB of 337.4 GB, 1089103 of 3687840 items

Aug 13 10:02:47 xxx com.apple.backupd[15168]: Copied 78.1 GB of 337.4 GB, 1145902 of 3687840 items

Aug 13 10:55:32 xxx com.apple.backupd[15168]: CoreEndianFlipData: error -4940 returned for rsrc type FREF (id 131, length 7, native = no)

Aug 13 10:55:32 xxx com.apple.backupd[15168]: CoreEndianFlipData: error -4940 returned for rsrc type FREF (id 132, length 7, native = no)

Aug 13 11:49:02 xxx com.apple.backupd[15168]: Copied 85.6 GB of 337.4 GB, 1182128 of 3687840 items

Aug 13 13:12:58 xxx com.apple.backupd[15168]: Copied 87.7 GB of 337.4 GB, 1205294 of 3687840 items

Aug 13 14:43:32 xxx com.apple.backupd[15168]: Copied 91.0 GB of 337.4 GB, 1243557 of 3687840 items

Aug 13 16:07:38 xxx com.apple.backupd[15168]: Copied 94.7 GB of 337.4 GB, 1264643 of 3687840 items

Aug 13 17:05:30 xxx com.apple.backupd[15168]: CoreEndianFlipData: error -4940 returned for rsrc type FREF (id 128, length 7, native = no)

Aug 13 17:05:31 xxx com.apple.backupd[15168]: CoreEndianFlipData: error -4940 returned for rsrc type FREF (id 133, length 7, native = no)

Aug 13 17:06:07 xxx com.apple.backupd[15168]: CoreEndianFlipData: error -4940 returned for rsrc type FREF (id 128, length 7, native = no)

Aug 13 17:07:00 xxx com.apple.backupd[15168]: CoreEndianFlipData: error -4940 returned for rsrc type FREF (id 132, length 7, native = no)

Aug 13 17:07:00 xxx com.apple.backupd[15168]: CoreEndianFlipData: error -4940 returned for rsrc type FREF (id 128, length 7, native = no)

Aug 13 17:07:02 xxx com.apple.backupd[15168]: CoreEndianFlipData: error -4940 returned for rsrc type FREF (id 129, length 7, native = no)

Aug 13 17:07:43 xxx com.apple.backupd[15168]: Copied 103.4 GB of 337.4 GB, 1329839 of 3687840 items

Aug 13 17:08:53 xxx com.apple.backupd[15168]: CoreEndianFlipData: error -4940 returned for rsrc type FREF (id 129, length 7, native = no)

Aug 13 17:10:11 xxx com.apple.backupd[15168]: CoreEndianFlipData: error -4940 returned for rsrc type FREF (id 131, length 7, native = no)

Aug 13 17:10:21 xxx com.apple.backupd[15168]: CoreEndianFlipData: error -4940 returned for rsrc type FREF (id 128, length 7, native = no)

Aug 13 18:33:26 xxx com.apple.backupd[15168]: Copied 114.7 GB of 337.4 GB, 1389303 of 3687840 items

Aug 13 19:59:49 xxx com.apple.backupd[15168]: Copied 116.0 GB of 337.4 GB, 1407304 of 3687840 items

Aug 13 22:21:57 xxx com.apple.backupd[15168]: Copied 119.4 GB of 337.4 GB, 1435050 of 3687840 items

Aug 13 23:24:39 xxx com.apple.backupd[15168]: Copied 121.5 GB of 337.4 GB, 1475092 of 3687840 items

Aug 14 00:27:36 xxx com.apple.backupd[15168]: Copied 126.3 GB of 337.4 GB, 1531412 of 3687840 items

Aug 14 01:27:36 xxx com.apple.backupd[15168]: Copied 126.5 GB of 337.4 GB, 1532079 of 3687840 items

Aug 14 02:27:46 xxx com.apple.backupd[15168]: Copied 138.4 GB of 337.4 GB, 1534855 of 3687840 items

Aug 14 03:44:28 xxx com.apple.backupd[15168]: Copied 139.8 GB of 337.4 GB, 1534925 of 3687840 items

Aug 14 05:01:50 xxx com.apple.backupd[15168]: Copied 141.7 GB of 337.4 GB, 1535061 of 3687840 items

Aug 14 06:04:31 xxx com.apple.backupd[15168]: Copied 158.7 GB of 337.4 GB, 1581470 of 3687840 items

Aug 14 06:27:25 xxx com.apple.backupd[15168]: CoreEndianFlipData: error -4940 returned for rsrc type FREF (id 128, length 7, native = no)

Aug 14 06:27:34 xxx com.apple.backupd[15168]: CoreEndianFlipData: error -4940 returned for rsrc type FREF (id 131, length 7, native = no)

Aug 14 06:27:39 xxx com.apple.backupd[15168]: CoreEndianFlipData: error -4940 returned for rsrc type FREF (id 131, length 7, native = no)

Aug 14 07:09:03 xxx com.apple.backupd[15168]: Copied 173.5 GB of 337.4 GB, 1613916 of 3687840 items

Aug 14 08:31:39 xxx com.apple.backupd[15168]: Copied 179.5 GB of 337.4 GB, 1621688 of 3687840 items

Aug 14 09:53:19 xxx com.apple.backupd[15168]: Copied 180.4 GB of 337.4 GB, 1633733 of 3687840 items

Aug 14 11:06:43 xxx com.apple.backupd[15168]: Copied 1679063 files (180.9 GB) from volume C.

Aug 14 11:06:50 xxx com.apple.backupd[15168]: Waiting for index to be ready (100)

Aug 14 11:07:50 xxx com.apple.backupd[15168]: Waiting for index to be ready (100)

[snip duplicates]

Aug 14 18:13:22 xxx com.apple.backupd[15168]: Waiting for index to be ready (100)

Aug 14 18:13:30 xxx com.apple.backupd[15168]: Copied 1679063 files (180.9 GB) from volume B.

Aug 14 18:13:44 xxx com.apple.backupd[15168]: Backup canceled.

That's about as clean as it can be, and TM is SLOW. Having stopped TM and restarted it, it is again going oh so slowly, with "Waiting for index to be ready (100)"

Meanwhile, the other machines, on SL, are backing up as usual.

I would say that the evidence points to TM on Lion having some problems.