Apple Event: May 7th at 7 am PT

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

Level 1

98 points

Two Time Machine Mysteries

Yesterday, after a successful Time Machine backup I noticed there were two temporary folders on my Desktop, which I should have deleted BEFORE the backup. Hence I entered Time Machine. First I clicked on the second folder in list view to select it, then on the first one (which deselected the other one) so that only the first folder was selected, right clicked on it and deleted that backup. Unfortunately, after a while, BOTH ( ! ) folders had disappeared! I'm 100% sure that just ONE ( ! ) was selected.

I closed TM. Opened it again (I thought refreshing the view would make the one folder (which I didn't select & delete) visible again, but it really was gone.

A few minutes later, because I had modified a small, but important file, I ran Time Machine backup again and noticed a strange behaviour:

First it said , backing up 100MB of 500MB, then just before reaching the 500MB it said backing up 450MB of 800MB, then before reaching the 800MB it said backing up 750MB of 1.2GB and so on (the target backup size got permanently corrected) until 15GB ( ! ) were copied.

I hope someone can explain these two strange incidents, because otherwise I would question the reliability of my backups.

Many thanks.

iMac (27-inch Mid 2010), OS X Mountain Lion (10.8.2)

Posted on May 1, 2013 12:24 AM

Best reply

Linc Davis

Level 10

209,547 points

Posted on May 1, 2013 7:29 AM

First, start a second backup on another external drive. One backup is not enough to be safe.

Then repair the backup volume in Disk Utility. If any problems are found, repeat. If there's ever another problem with the drive, replace it.

View in context

34 replies

coxorange Author

Level 1

98 points

Aug 17, 2013 4:21 AM in response to coxorange

Yesterday I got the following log for a Time Machine backup:

02:46:01 - Starting manual backup

02:46:13 - Backing up to: /Volumes/MyBook/Backups.backupdb

02:46:36 - Using file event preflight for Macintosh HD

02:48:25 - Will copy (151 MB) from Macintosh HD

02:48:26 - Found 1139 files (181 MB) needing backup

02:48:26 - 1.24 GB required (including padding), 458.47 GB available

03:28:19 - Copied 17069 files (152.7 MB) from volume Macintosh HD.

03:28:25 - Using file event preflight for Macintosh HD

03:28:25 - Will copy (160 KB) from Macintosh HD

03:28:25 - Found 22 files (160 KB) needing backup

03:28:25 - 1.02 GB required (including padding), 458.32 GB available

03:28:55 - Copied 1623 files (665 KB) from volume Macintosh HD.

03:28:57 - Created new backup: 2013-08-17-032855

03:29:00 - Starting post-backup thinning

03:30:15 - Deleted /Volumes/MyBook/Backups.backupdb/uome’s iMac/2013-07-18-030947 (150.8 MB)

03:30:15 - Post-back up thinning complete: 1 expired backups removed

03:30:28 - Backup completed successfully.

What might have happened between 2:48 and 3:28?

It seemed that the backup drive didn't do anything,

but the Mac's internal hard drive was working during this time.

I just would like to understand why some backups take long,

even though there isn't much to backup.

Another question: Is there a way to verify if a Time Machine backup

arrived correctly on the backup drive?

Many thanks.

Pondini

Level 8

38,863 points

Aug 17, 2013 5:50 AM in response to coxorange

coxorange wrote:

. . .

What might have happened between 2:48 and 3:28?

Hard to tell from the log messages sent by backupd. 😟

Forgive me, but I've kinda lost the trail here -- is the TM disk you're currently using set up as RAID 1 now? If so, as I understand it, some do periodic checks, repairs, or other maintenance (I forget the term) -- could it have been doing something like that? Are there any indications when such things are going on?

You might want to look at your system.log directly for that period, not just the backupd messages. There might be some low-level messages sent by the kernel or other processes that would explain it.

Does the drive have a sleep or "spin down" mode of its own? Sometimes those don't wake up quickly enough, especially as the drive ages. If so, it's possible that's what happened, although usually that will trigger a backup failure.

Another question: Is there a way to verify if a Time Machine backup arrived correctly on the backup drive?

Yes and no. If there are I/O or other errors, TM will fail, of course.

If there are directory or indexing problems on the TM drive, TM may or may not detect them during a backup.

You can run Verify Disk on the backups via Disk Utility. That will check the various directories and catalogs to verify that the files & folders that are there are all where they're supposed to be. But it can't tell if everything that's supposed to be there is there, or if a file is damaged internally.

Sometimes, you can force a "deep traversal" (or "deep scan") on the next backup by cancelling one while it's copying. Other times, you can force it by starting from your Recovery HD and using the copy of Disk Utility there to run Repair Disk on your internal HD. The deep traversal compares everything on your Mac to the most recent completed backup, to figure out what's new or changed. That takes longer, of course, but does send some messages to that effect to the logs so you know it was done.

If you're comfy with UNIX and Terminal, you can use the tmutil command with the compare verb to do a similar procedure.

You can do a full system restore to another disk/partition, start up from it, and verify that everything works properly.

coxorange Author

Level 1

98 points

Aug 17, 2013 11:54 AM in response to Pondini

Many thanks for your answer.

Pondini wrote:

is the TM disk you're currently using set up as RAID 1 now? If so, as I understand it, some do periodic checks, repairs, or other maintenance (I forget the term) -- could it have been doing something like that? Are there any indications when such things are going on?

Yes it's set up as RAID 1. Maintenance jobs (defragmentation etc.) are always performed when the Time Machine backup is completed (if the drives stays ON). After some minutes you can hear clearly when everything is finished. Besides, this drive is protected against unintended ejecting/turning-off during write operations, so this is not a way to damage data.

Does the drive have a sleep or "spin down" mode of its own? Sometimes those don't wake up quickly enough, especially as the drive ages. If so, it's possible that's what happened, although usually that will trigger a backup failure.

The drive had been turned on before the backup and it was ready. It isn't aged yet either.

You might want to look at your system.log directly for that period, not just the backupd messages. There might be some low-level messages sent by the kernel or other processes that would explain it.

I've checked the system.log between 02.48:26 and 03:28:19 and removed all lines resulting from my brightness dimmer (lots of lines) - now there are still 510 lines - too much to insert here I guess (or not?). Here are the first 5 minutes:

Aug 17 02:48:33 uomes-iMac com.apple.launchd[1] (com.apple.sleepservicesd[34076]): Exited: Killed: 9

Aug 17 02:48:33 uomes-iMac kernel[0]: memorystatus_thread: idle exiting pid 34076 [SleepServicesD]

Aug 17 02:48:39 uomes-iMac com.apple.launchd[1] (com.apple.cfprefsd.xpc.daemon[34077]): Exited: Killed: 9

Aug 17 02:48:39 uomes-iMac kernel[0]: memorystatus_thread: idle exiting pid 34077 [cfprefsd]

Aug 17 02:48:45 uomes-iMac com.apple.launchd[1] (com.apple.sleepservicesd[34078]): Exited: Killed: 9

Aug 17 02:48:45 uomes-iMac kernel[0]: memorystatus_thread: idle exiting pid 34078 [SleepServicesD]

Aug 17 02:48:48 uomes-iMac com.apple.launchd.peruser.89[34060] (com.apple.distnoted.xpc.agent[34063]): Exited: Killed: 9

Aug 17 02:48:48 uomes-iMac kernel[0]: memorystatus_thread: idle exiting pid 34063 [distnoted]

Aug 17 02:49:40 uomes-iMac com.apple.launchd[1] (com.apple.sleepservicesd[34079]): Exited: Killed: 9

Aug 17 02:49:40 uomes-iMac kernel[0]: memorystatus_thread: idle exiting pid 34079 [SleepServicesD]

Aug 17 02:49:40 uomes-iMac.local distnoted[34084]: # distnote server agent absolute time: 1241566.144217091 civil time: Sat Aug 17 02:49:40 2013 pid: 34084 uid: 89 root: no

Aug 17 02:50:14 uomes-iMac com.apple.launchd[1] (com.apple.cfprefsd.xpc.daemon[34086]): Exited: Killed: 9

Aug 17 02:50:15 uomes-iMac kernel[0]: memorystatus_thread: idle exiting pid 34086 [cfprefsd]

Aug 17 02:50:17 uomes-iMac com.apple.launchd.peruser.89[34080] (com.apple.cfprefsd.xpc.agent[34085]): Exited: Killed: 9

Aug 17 02:50:17 uomes-iMac kernel[0]: memorystatus_thread: idle exiting pid 34085 [cfprefsd]

Aug 17 02:50:18 uomes-iMac com.apple.launchd[1] (com.apple.sleepservicesd[34083]): Exited: Killed: 9

Aug 17 02:50:19 uomes-iMac kernel[0]: memorystatus_thread: idle exiting pid 34083 [SleepServicesD]

Aug 17 02:50:38 uomes-iMac com.apple.launchd[1] (com.apple.sleepservicesd[34087]): Exited: Killed: 9

Aug 17 02:50:38 uomes-iMac kernel[0]: memorystatus_thread: idle exiting pid 34087 [SleepServicesD]

Aug 17 02:51:09 uomes-iMac.local mdworker[34088]: Unable to talk to lsboxd

Aug 17 02:51:12 uomes-iMac kernel[0]: Sandbox: sandboxd(34092) deny mach-lookup com.apple.coresymbolicationd

Aug 17 02:51:14 uomes-iMac com.apple.launchd.peruser.501[144] (com.apple.cfprefsd.xpc.agent[34090]): Exited: Killed: 9

Aug 17 02:51:14 uomes-iMac kernel[0]: memorystatus_thread: idle exiting pid 34090 [cfprefsd]

Aug 17 02:51:17 uomes-iMac com.apple.launchd[1] (com.apple.sleepservicesd[34089]): Exited: Killed: 9

Aug 17 02:51:18 uomes-iMac.local sandboxd[34092] ([34088]): mdworker(34088) deny mach-lookup com.apple.ls.boxd

Aug 17 02:51:18 uomes-iMac kernel[0]: memorystatus_thread: idle exiting pid 34089 [SleepServicesD]

Aug 17 02:51:19 uomes-iMac com.apple.launchd.peruser.89[34080] (com.apple.distnoted.xpc.agent[34084]): Exited: Killed: 9

Aug 17 02:51:19 uomes-iMac kernel[0]: memorystatus_thread: idle exiting pid 34084 [distnoted]

Aug 17 02:51:23 uomes-iMac com.apple.launchd[1] (com.apple.cfprefsd.xpc.daemon[34091]): Exited: Killed: 9

Aug 17 02:51:23 uomes-iMac kernel[0]: memorystatus_thread: idle exiting pid 34091 [cfprefsd]

Aug 17 02:51:30 uomes-iMac com.apple.launchd.peruser.501[144] (com.apple.cfprefsd.xpc.agent[34094]): Exited: Killed: 9

Aug 17 02:51:30 uomes-iMac kernel[0]: memorystatus_thread: idle exiting pid 34094 [cfprefsd]

Aug 17 02:52:51 uomes-iMac com.apple.launchd.peruser.501[144] (com.apple.pbs[34096]): Exited: Killed: 9

Aug 17 02:52:52 uomes-iMac kernel[0]: memorystatus_thread: idle exiting pid 34096 [pbs]

Aug 17 02:52:58 uomes-iMac com.apple.launchd[1] (com.apple.sleepservicesd[34093]): Exited: Killed: 9

Aug 17 02:52:58 uomes-iMac kernel[0]: memorystatus_thread: idle exiting pid 34093 [SleepServicesD]

Aug 17 02:53:10 uomes-iMac com.apple.launchd[1] (com.apple.sleepservicesd[34098]): Exited: Killed: 9

Aug 17 02:53:10 uomes-iMac kernel[0]: memorystatus_thread: idle exiting pid 34098 [SleepServicesD]

Aug 17 02:53:23 uomes-iMac com.apple.launchd[1] (com.apple.sleepservicesd[34099]): Exited: Killed: 9

Aug 17 02:53:23 uomes-iMac kernel[0]: memorystatus_thread: idle exiting pid 34099 [SleepServicesD]

Aug 17 02:53:35 uomes-iMac com.apple.launchd[1] (com.apple.sleepservicesd[34100]): Exited: Killed: 9

Aug 17 02:53:35 uomes-iMac kernel[0]: memorystatus_thread: idle exiting pid 34100 [SleepServicesD]

...

Another question: Is there a way to verify if a Time Machine backup arrived correctly on the backup drive?

If you're comfy with UNIX and Terminal, you can use the tmutil command with the compare verb to do a similar procedure.

Sounds interesting. Where can I find more detailed information? Alternatively, can tmutil (or another app) just read all files from the backup drive to confirm readability (without comparing)?

Thanks again!

Pondini

Level 8

38,863 points

Aug 17, 2013 12:34 PM in response to coxorange

coxorange wrote:

. . .

Does the drive have a sleep or "spin down" mode of its own? Sometimes those don't wake up quickly enough, especially as the drive ages. If so, it's possible that's what happened, although usually that will trigger a backup failure.

The drive had been turned on before the backup and it was ready. It isn't aged yet either.

It's still a slim possibility. If it goes to sleep on it's own while TM is doing something else, it may not wake up fast enough when TM wants it again, although usually there'll be some sort of message in the logs. You might want to check the documentation, web site, etc., for the RAID box to see if there's a way to alter or disable it, or any similar problems posted by others.

I've checked the system.log between 02.48:26 and 03:28:19 and removed all lines resulting from my brightness dimmer (lots of lines) - now there are still 510 lines - too much to insert here I guess (or not?). Here are the first 5 minutes:

Aug 17 02:48:33 uomes-iMac com.apple.launchd[1] (com.apple.sleepservicesd[34076]): Exited: Killed: 9

Aug 17 02:48:33 uomes-iMac kernel[0]: memorystatus_thread: idle exiting pid 34076 [SleepServicesD]

I assume that's the dimmer? If so, I don't see anything else of interest.

Another question: Is there a way to verify if a Time Machine backup arrived correctly on the backup drive?

If you're comfy with UNIX and Terminal, you can use the tmutil command with the compare verb to do a similar procedure.

Sounds interesting. Where can I find more detailed information?

If you're not already familiar with UNIX and Terminal, it's not easy -- Terminal is a command-line interface without the prompts, help, and protections of OSX, and the works can be a bit obscure, as can the UNIX syntax. It's also easy to cause considerable damage. But try this:

Go to this web page with what's called the MAN(ual) page for tmutil:

https://developer.apple.com/library/mac/documentation/Darwin/Reference/ManPages/ man8/tmutil.8.html

Scroll down to the compare verb. I'm no Terminal expert, and I've not fooled with tmutil much for anything like your purpose; offhand, I don't think you can get it to just list any differences.

I've also not run across any basic tutorials on how to use Terminal and UNIX -- the syntax, options, etc. get rather daunting.

Alternatively, can tmutil(or another app) just read all files from the backup drive to confirm readability (without comparing)?

The deep traversal/scan compares the file/folder structure, sizes, and modification dates, but doesn't look inside files.

The TM browser (the "Star Wars" display) just shows the file/folder structure. You can display some sorts of files via QuickLook, but not complex ones like images, video, etc.

Two Time Machine Mysteries