backupd cleanup very slow and using tons of memory

Question

Level 1

26 points

backupd cleanup very slow and using tons of memory

I've been using Time Machine to backup to our Time Capsule for quite a while, but I've started noticing that backupd is using a lot of CPU and memory. When I check on it, I find it's done the backup (the Time Capsule disk is even dismounted) but the cleanup has been going on for quite a while. Looking at console and searching for backupd shows:

6/1/16 11:28:58.667 PM com.apple.backupd[19054]: Starting automatic backup

6/1/16 11:29:01.288 PM com.apple.backupd[19054]: Network destination already mounted at: /Volumes/Airport Disk

6/1/16 11:29:04.408 PM com.apple.backupd[19054]: Disk image already attached: /Volumes/Airport Disk/hummingbird.sparsebundle, DIHLDiskImageAttach returned: 35 (Resource temporarily unavailable)

6/1/16 11:29:05.668 PM com.apple.backupd[19054]: Disk image /Volumes/Airport Disk/hummingbird.sparsebundle mounted at: /Volumes/Time Machine Backups

6/1/16 11:29:07.075 PM com.apple.backupd[19054]: Backing up to /dev/disk4s2: /Volumes/Time Machine Backups/Backups.backupdb

6/1/16 11:29:36.479 PM com.apple.backupd[19054]: Will copy (469 MB) from Macintosh HD

6/1/16 11:29:36.549 PM com.apple.backupd[19054]: Found 512 files (469 MB) needing backup

6/1/16 11:29:36.616 PM com.apple.backupd[19054]: 3.29 GB required (including padding), 3.94 TB available

6/1/16 11:39:55.243 PM com.apple.backupd[19054]: Copied 856 items (469 MB) from volume Macintosh HD. Linked 10758.

6/1/16 11:40:38.954 PM com.apple.backupd[19054]: Created new backup: 2016-06-01-234037

6/1/16 11:43:30.000 PM kernel[0]: process backupd[19054] thread 5920117 caught burning CPU! It used more than 50% CPU (Actual recent usage: 59%) over 180 seconds. thread lifetime cpu usage 126.459076 seconds, (10.999206 user, 115.459870 system) ledger info: balance: 90001383867 credit: 126276955986 debit: 36275572119 limit: 90000000000 (50%) period: 180000000000 time since last refill (ns): 151181990775

6/2/16 12:07:34.000 AM kernel[0]: process backupd[19054] caught causing excessive wakeups. Observed wakeups rate (per sec): 208; Maximum permitted wakeups rate (per sec): 150; Observation period: 300 seconds; Task lifetime number of wakeups: 171334

6/2/16 1:24:10.000 AM kernel[0]: low swap: killing pid 19054 (backupd)

6/2/16 1:24:14.592 AM com.apple.backupd-helper[18183]: XPC error for connection com.apple.backupd.xpc: Connection interrupted

6/2/16 1:24:14.592 AM com.apple.backupd-helper[18183]: Not starting scheduled Time Machine backup: Failed to send message to backupd

6/2/16 1:24:17.462 AM com.apple.xpc.launchd[1]: (com.apple.backupd[19054]) Service exited due to signal: Killed: 9

Note that the backup itself finished only about 12 minutes after it started but the clean up phase lasted over another 1 1/2 hours, stopping only when the system killed backupd.

I was watching backupd from time to time. After about 20 minutes of clean up, backupd was taking 7.7 Gbytes of memory and was noticeably slowing down my Mac, which is what brought this to my attention. After about 45 minutes of clean up, the progress bar in Time Machine preferences was at 90% and not visibly moving. backupd was up to 19.92 Gbytes and growing steadily. Surprisingly, it was not slowing my mac down as much then.

Looking at subsequent backups in the log, I'm seeing the same pattern repeat.

I just used Disk Utility's First Aid to check the disk and it says my internal disk is fine.

MacBook Air, OS X El Capitan (10.11.5)

Posted on Jun 2, 2016 2:53 PM

Reply

Answer 1

Jun 3, 2016 6:41 AM in response to Liz M

You may have run out of virtual memory on your internal hard drive: 6/2/16 1:24:10.000 AM kernel[0]: low swap: killing pid 19054 (backupd. Your internal disk may be failing or you may be dangerously low on disk space. Low disk space/bad hard drive could cause these kind of errors. Start with checking your internal hard drive.

Have a nice day.

Reply

Answer 2

Liz M Author

Level 1

26 points

Jun 3, 2016 1:03 PM in response to Boyd Porter

Thanks for your response. I did check the internal disk; there were no problems found. It's not full either, with 236Gbytes available out of 499GB total right now.

The swap is running low occasionally because backupd grows totally out of control. During the cleanup phase, I saw it at about 20Gbytes and it was continuing to grow -- about half a G in a minute or so.

Reply

Answer 3

Liz M Author

Level 1

26 points

Jun 4, 2016 8:03 PM in response to Boyd Porter

Just now, I watched another backupd grow and grow to over 51Gbytes (probably not quite to 52) before the system killed it. The cleanup phase ran for 55 minutes that time. My second biggest task is kernel_task with just 1.24 Gbytes. I've never seen any other process at over 2 Gbytes, so 51 Gbytes is incredibly large and I'm not surprised that it swamps out the swap.

Reply

Answer 4

Liz M Author

Level 1

26 points

Jun 7, 2016 6:45 PM in response to Liz M

Just talked to Apple Support about this on chat for a couple hours, and they're escalating this to their engineers. They said it'd take about 4 business days to hear back from them.

I'm routinely killing backupd when it starts misbehaving but have now seen it take as much as 62Gbytes before the system killed it.

Reply

Answer 5

Jun 7, 2016 7:30 PM in response to Liz M

Did you upgrade install El Capo?

If so I would strongly recommend you make an actual disk image or clone.. as your Time Machine backup could now be in bad shape.

Clean install El Capo onto the computer.

migrate your files back but clean install the applications.

I know it is painful but I suspect you will continue having issues.

Otherwise I recommend you find another target for your backup.. even using airdisk on latest Gen6 Airport Extreme is not particularly reliable.. and apple did not support airdisk backup to gen5 AE or earlier.

See http://pondini.org/TM/Airport.html

Using Time Machine to a locally connected USB drive is a lot more reliable.

The alternative is to give up with Time Machine.. it is not as reliable as it was and I continually recommend now people use an alternative like Carbon Copy Cloner. Especially if you are using airdisk on Airport Extreme.

Reply

Answer 6

Liz M Author

Level 1

26 points

Jul 29, 2016 6:52 PM in response to Liz M

This turned out to be the backup disk starting to fail, I think. A couple weeks after I started this discussion, I gt an error from TM saying it could no longer backup to the Time Capsule disk. When I checked Airport Utility, it showed that the disk needed repairs. Note that you the TC still shows green, but if you click it, the little popup says the disk needs repairs. I wish there was some indication that this was the case without clicking on it.

To repair the disk, you reboot the TC which triggers a disk check and repair. Unfortunately, this was not enough to actually fix the problem. Rebooting ours 3-4 times made no difference and the TC still shows that the disk needs repair. It's long out of warrantee, so that wasn't an option. Fortunately, we have another large disk attached to the TC, so I am now backing up to it. Once doing that, I found the cleanup phase is now quick and doesn't grow uncontrollably.

My son was also backing up his MacBook Pro to the internal disk and that appeared to be continuing without any problem. However, when we tried to copy his backup from the internal to the external disk, that failed. So, we started him with new backups on the external disk, as I've been doing and that seems to work alright. We did copy some other large files from the internal to the external disk without any problems. These were large but many times smaller than the backup images.

Apple support suggested removing apps from my computer until the backups started behaving again. I started doing some of that but the easy ones to remove probably weren't the problem and the hard ones were very tedious. The error from TM started showing up before I got very far.

If you're here for a similar problem, I hope this helps.

Reply