Pondini

Q: UPDATED: Serious Time Machine bug on Mountain Lion

This is continued and summarized from a previous thread, Serious Time Machine bug on Mountain Lion, which has grown rather large and unwieldy (and which I marked Solved in error).  There are a few other threads that touch on it as well.

 

 

Some of us have seen a few cases of a pretty nasty problem with Time Machine backups on Mountain Lion.  It doesn't seem to affect a lot of users, but those who have it, don't know it.  It seems to have started at different times for different users, some as long ago as December, 2012.

 

The backups cannot not be used to do a full system restore from recent backups -- they don't appear on the selection screen that shows only "complete" backups.  Plus, they're not recognized as backups by Setup Assistant or Migration Assistant.  They don't appear on the Select the Source or Select Your System windows at all.  But your user data is fine via the Time Machine browser (the "Star Wars" display).

 

What's happening is, the top-level Applications, Library, System and (hidden) private folders are being excluded by some process (not the user, and the exclusions do not appear on the Time Machine Preferences window).  But all backups complete normally, and Verify Backups from the Time Machine menubar on network backups, and Verify Disk or Repair Disk via Disk Utility, don't show a problem  (because what's there is intact; those processes can't tell that what's missing isn't supposed to be missing.)

 

In addition, we've seen a few threads where the problem is intermittent -- backups are unexpectedly large, sometimes often, sometimes less so, intermittently.  In those cases, the folders are backed up, then skipped, then backed-up again, then skipped, etc.  Since they appear to be "new" when backed-up again, they're backed-up in full, making backups of 15 GB or more.

 

 

See #D10 in Time Machine - Troubleshooting for an easy way to tell if you're affected, and a fix.


 

However, as we have no clue as to the cause yet, we need to be sure Apple knows about this, in detail, while it's happening, so I'm asking for some folks who are having these problems, and are fairly comfortable with the Finder at least, and following directions to do other things you may not be so familiar with, to help us collect information and contact Apple before running the fix in the link above (as that will destroy some of the evidence).

 

We're especially interested in folks who are covered by AppleCare, as you can call them for free and get some fairly quick attention.  We can supply some "ammunition" for when you call them (since I haven't had this problem, and don't know how to reproduce it, I can't report it myself). 

 

 

If you're having this problem and just want to run the fix, by all means do so (and check it periodically), but please don't post back with just a "me, too" post, unless you have something significant to add -- this thread may get long and those won't really help.

 

But if you're having a different problem, please do not respond to this thread.  Start a new one, instead.  If you're not sure how to do that, please go to the main Apple Support Communities page;  some Tutorials are listed at the right.  They'll show you how to get started.

Posted on Jun 24, 2013 6:55 AM

Close

Q: UPDATED: Serious Time Machine bug on Mountain Lion

  • All replies
  • Helpful answers

first Previous Page 4 of 12 last Next
  • by Pondini,

    Pondini Pondini Aug 25, 2013 7:33 PM in response to Pondini
    Level 8 (38,747 points)
    Aug 25, 2013 7:33 PM in response to Pondini

    I've posted a tiny app on my website that will check whether your Mac is affected.

     

    Click the link in the blue box here: 

     

    Applications, Library, and/or System folders not backed-up, or, periodic large backups

     

     

    If your Mac is affected, see the yellow box there for a (possibly-temporary) fix.

     

    If you'd like to report it to Apple (every one helps), see the green box there before running the fix.

  • by R C-R,Helpful

    R C-R R C-R Aug 25, 2013 9:00 PM in response to Pondini
    Level 6 (17,680 points)
    Aug 25, 2013 9:00 PM in response to Pondini

    A couple of notes about the tiny app on Pondini's web site:

     

    1. It is intended for Mountain Lion users only. It may or may not work as expected on earlier OS versions.

     

    2. It it is just a simple AppleScript application. If you want to check it out before running it to make sure it doesn't do anything sneaky, you can drop it on the AppleScript Editor icon (it is in the Utilities folder in the root level Applications folder). That will open the script itself in an editor window, so you can see exactly how it does what it does.

     

    3. If you open it in the editor, I suggest that you not make any changes unless you have at least a basic understanding of AppleScript commands.

  • by Pondini,

    Pondini Pondini Aug 25, 2013 9:57 PM in response to R C-R
    Level 8 (38,747 points)
    Aug 25, 2013 9:57 PM in response to R C-R

    It would probably work on Lion, but get rather unhappy on earlier versions of OSX, as they don't have the tmutil command it uses.

     

    And thanks again for writing that for me.    


  • by Ross Barkman,

    Ross Barkman Ross Barkman Aug 27, 2013 1:41 AM in response to Pondini
    Level 1 (0 points)
    Aug 27, 2013 1:41 AM in response to Pondini

    OK, here's some data points that may be useful.  I wrote a small Applescript to monitor the

    com.apple.TimeMachine.plist file every 10 seconds, and to copy it to another location if the timestamp had changed.  I hoped to capture whatever is happening to the .plist.

     

    What I have discovered is that some process, probably part of the Time Machine system itself, changes the .plist file by deleting the IncludeByPath section (which lists /Applications, /Library, /System, /bin, /private, /sbin and /usr) and moving those entries to the ExcludeByPath section.  Shortly afterward (about 15 seconds), the file changes again, and the IncludeByPath section is restored.  This does not happen with every backup, but it does happen regularly.  And it happens when I am nowhere near the MacBook, so it must be a process that is active long-term.

     

    This might possibly be absolutely routine, but it's odd.  I wonder what might happen if the backup process gets interrupted, e.g. if you put the Mac to sleep.  If the .plist file was to stay in the 'excluded' state for any reason, the next backup would remove those paths, but the process would also restore the file to the correct state, so the following backup run would include them again and do a full backup.

     

    I tried deleting & recreating the .plist - it makes no difference.  The file still gets changed to ExcludeByPath and then back to IncludeByPath.

  • by Pondini,

    Pondini Pondini Aug 27, 2013 3:30 AM in response to Ross Barkman
    Level 8 (38,747 points)
    Aug 27, 2013 3:30 AM in response to Ross Barkman

    Ross Barkman wrote:

    . . .

    What I have discovered is that some process, probably part of the Time Machine system itself, changes the .plist file by deleting the IncludeByPath section (which lists /Applications, /Library, /System, /bin, /private, /sbin and /usr) and moving those entries to the ExcludeByPath section.  Shortly afterward (about 15 seconds), the file changes again, and the IncludeByPath section is restored.  This does not happen with every backup, but it does happen regularly.

    Aha!  Major clue! 

     

    Does this happen only when a backup is running? 

     

    Do you have anything else in the ExcludeByPath section besides the 7 top-level libraries (as in the sample below)?  If so, what?

     

     

    And it happens when I am nowhere near the MacBook, so it must be a process that is active long-term.

    It could still be backupd.  It doesn't necessarily terminate when a backup completes.

     

    This might possibly be absolutely routine, but it's odd.

    Absolutely.  Backupd does update it, of course, with the results:

     

    Screen Shot 2013-08-27 at 5.54.36 AM.png

     

    But I can't imagine why it needs to be that frequent.

     

     

    Speculation:  Those exclusions are also kept in a system cache somewhere.  If you have TM off, backupd not running, and delete the plist, they (the correct ones) will come back.  Makes sense, so you can't lose them.  I looked for it briefly, but couldn't find it.  I did confirm it by using OnyX to delete the Boot and Kernel and Extension caches, then deleted the plist and set up TM again, and they did not come back:

     

    Screen Shot 2013-08-27 at 6.11.03 AM.png

     

    I haven't tried it again to see which it is, or if OnyX is also deleting something else, but perhaps whatever it is, if it's corrupted, is triggering all the activity?  Or the two are conflicting -- one changes it to match the cache, then backupd sees it's different than when the backup started, so "fixes" it?

     

     

    If you haven't seen it yet, take a look at #D10 in Time Machine - Troubleshooting. There's a link in the yellow box to what we've figured out so far that you might be interested in.

     

     

    Thanks very much for this.  I'm very hopeful this will help get Apple "cooking" on it, once we can get it to them.  So far, from the few Bug Reports and calls to AppleCare I know about, they don't seem to recognize it as a problem.  At least the first-level support folks don't.

    .

     

    Message was edited by: Pondini

  • by R C-R,

    R C-R R C-R Aug 27, 2013 4:24 AM in response to Pondini
    Level 6 (17,680 points)
    Aug 27, 2013 4:24 AM in response to Pondini

    Pondini wrote:

    Absolutely.  Backupd does update it, of course, {...} But I can't imagine why it needs to be that frequent.

    On my system (which is not affected by the bug) /Library/Preferences/com.apple.TimeMachine.plist is apparently completely replaced (not modified) several times at or around the time of each backup, & perhaps more often than that.

     

    I haven't tried a script to monitor this; instead I used a much cruder technique of opening a Finder 'get info' window for the file & then doing a 'back up now' from the TM menu item. To my surprise, not only did the get info window vanish immediately (presumably because the old file was deleted or overwritten), it vanished several times after that when I repeatedly opened the 'get info' window as fast as I could.

     

    All this happened very quickly. I estimate the file got replaced at least three times over a period of no more that 2-3 seconds.

     

    Note: this may or may not have anything to do with anything, but essentially all my backups, manual or automatic, start with a "backup failed with error 19" message in the log, followed by a successful backup. I believe this is because my backup drive spins down when not in use & it takes a few seconds for it to spin up each time a backup is done.

  • by Ross Barkman,

    Ross Barkman Ross Barkman Aug 27, 2013 6:23 AM in response to Pondini
    Level 1 (0 points)
    Aug 27, 2013 6:23 AM in response to Pondini

    Pondini wrote:

     

    Does this happen only when a backup is running?

     

    Yes, as far as I can tell - i.e. I have watched it happen during a backup, and haven't seen it at any other time.

     

     

    Do you have anything else in the ExcludeByPath section besides the 7 top-level libraries (as in the sample below)?  If so, what?

     

    In my original .plist, yes, there are additional entries which are always there:

     

     



    <string>/Users/(user1)/Library/Calendars/Calendar Cache</string>


    <string>/Users/(user2)/Library/Calendars/Calendar Cache</string>


    <string>/Users/(user2)/Library/Safari/WebpageIcons.db</string>


    <string>/Users/(user2)/Library/Preferences/ByHost/com.apple.DotMacSync.(long hex string).plist</string>


    <string>/Users/(user2)/Library/Mail/Envelope Index</string>


    <string>/Users/(user2)/Library/Mail/Metadata/BackingStoreUpdateJournal</string>


    <string>/Library/Application Support/Microsoft/PlayReady</string>

     

    However, there is nothing in the new .plist I created, apart from when it temporarily changes the IncludeByPath to ExcludeByPath.  So I think the presence of other entries in ExcludeByPath is a red herring.

    Absolutely.  Backupd does update it, of course, with the results:

     

    Fair enough  - but why does it (or some other process) need to exclude all those directories from the backup, and then put them back in?  It's daft.  And it's possible that another background process updates the file.  I wish I knew a way to determine what process wrote it.

  • by Pondini,

    Pondini Pondini Aug 27, 2013 6:27 AM in response to R C-R
    Level 8 (38,747 points)
    Aug 27, 2013 6:27 AM in response to R C-R

    Aha!  More confirmation!  

     

    I can see it at the beginning, to update the destination (probably even if there's only one).  Bytes used and available might have changed since the previous backup (if there's other stuff on the volume);  then at the end of actual copying, when the backup folder is complete; and after any thinning of expired backups, as bytes used/available would change. 

     

    Why more than three? 

     

    Does the speculation in my previous post make any sense?

  • by Pondini,

    Pondini Pondini Aug 27, 2013 6:41 AM in response to Ross Barkman
    Level 8 (38,747 points)
    Aug 27, 2013 6:41 AM in response to Ross Barkman

    Ross Barkman wrote:

    . . .

    Yes, as far as I can tell - i.e. I have watched it happen during a backup, and haven't seen it at any other time.

    That's good to know -- I think it points more and more towards something in OSX, not the 3rd-party app.

     

    If true, it will be much easier to get fixed, of course.

     

    Do you have anything else in the ExcludeByPath section besides the 7 top-level libraries (as in the sample below)?  If so, what?

     

    In my original .plist, yes, there are additional entries which are always there:

    More suspicion on backupd rather than the apps.

     

     

    However, there is nothing in the new .plist I created, apart from when it temporarily changes the IncludeByPath to ExcludeByPath.

    But that's my point -- something as simple as a misspelling, or reference to the wrong variable, in some piece of code that's only used in some fairly unusual circumstances, might be the culprit.

     

    Fair enough  - but why does it (or some other process) need to exclude all those directories from the backup, and then put them back in?

    It doesn't need to - - that's the bug.

     

    And it's possible that another background process updates the file.  I wish I knew a way to determine what process wrote it.

    Absolutely!   

     

    Don't be discouraged - - I may be overly optimistic (doesn't happen often), but we may be closing in on it.

  • by Ross Barkman,

    Ross Barkman Ross Barkman Aug 27, 2013 7:00 AM in response to Pondini
    Level 1 (0 points)
    Aug 27, 2013 7:00 AM in response to Pondini

    Pondini wrote:

     

    But that's my point -- something as simple as a misspelling, or reference to the wrong variable, in some piece of code that's only used in some fairly unusual circumstances, might be the culprit.

     

    Yeah, but as I said, when I deleted the .plist and let Sys Prefs create a new one, the new 'clean' version still gets ine Exclude/Include flip-flop.  So, the presence of the other entries doesn't seem to affect that.  However, I take your point, and will see whether the new .plist still generates the mega backups.

     

    Unfortunately, I wasn't able to test it last night because I had difficulty getting backupd to open the .sparseimage file - turns out one of the special characters in my .sparseimage password doesn't play nicely with Mountain Lion when you enter it manually.  I created the file and stored the password in my keychain under a previous OS; when I tried to check it last night, Keychain Access was unable to display it ("Error creating UTF-8 encoded string from password data!").  I used hdiutil to change it to a textual password, then backupd could mount the image - but I ran out of time to do an actual backup.  Will let you know...

  • by R C-R,

    R C-R R C-R Aug 27, 2013 7:28 AM in response to Pondini
    Level 6 (17,680 points)
    Aug 27, 2013 7:28 AM in response to Pondini

    Pondini wrote:

    Does the speculation in my previous post make any sense?

    Sure ... as much as anything else about this bug does.

     

    BTW, I have a Console log query set up to show every message with "backupd" in it, & I do not see any strict correlation between the time of logged com.apple.backud entries & when the plist file is rewritten.

     

    Very odd.

  • by Pondini,

    Pondini Pondini Aug 27, 2013 9:36 AM in response to R C-R
    Level 8 (38,747 points)
    Aug 27, 2013 9:36 AM in response to R C-R

    Would the fseventr app show anything? 

     

    I tried to use it to track something down a while ago (I forget what), and it didn't tell me anything (or it did but I didn't understand it).

  • by Ross Barkman,

    Ross Barkman Ross Barkman Aug 27, 2013 10:11 AM in response to Pondini
    Level 1 (0 points)
    Aug 27, 2013 10:11 AM in response to Pondini

    I'll take a look at fseventr - but I've found something that might make the changes to the Time Machine .plist files:

     

    CFPreferences Plist Files

    The on-disk property list files used by CFPreferences have always been a private implementation detail, but in previous releases, directly modifying them has mostly worked (though there are some potential data-loss issues for applications that do so, even on previous systems). In 10.8 and later, the CFPreferences agent process (cfprefsd) will cache information from these files and asynchronously write to them. This means that directly modifying plist files is unlikely to have the expected results (new settings will not necessarily be read, and may even be overwritten).

     

    I think what this is saying is that, in Mountain Lion, .plist files should not be modified directly.  Instead, you call a CFPreferences API to request the changes, and cfprefsd carries them out.  This blog post seems to confirm that:

     

    http://rixstep.com/2/2/20130225,00.shtml

     

    So the changes to com.apple.TimeMachine.plist are probably being made by cfprefsd.

  • by Pondini,

    Pondini Pondini Aug 27, 2013 4:56 PM in response to Ross Barkman
    Level 8 (38,747 points)
    Aug 27, 2013 4:56 PM in response to Ross Barkman

    I might buy part of that: on occasion, users have reported contents of the plist coming back after being deleted.

     

    Still doesn't explain the frequent updates, does it?

     

    Weird. 

  • by R C-R,

    R C-R R C-R Aug 27, 2013 5:13 PM in response to Pondini
    Level 6 (17,680 points)
    Aug 27, 2013 5:13 PM in response to Pondini

    Pondini wrote:

    Still doesn't explain the frequent updates, does it?

     

    Weird. 

    I suspect until we figure out why that happens (even on systems with no sign of the bug) we will just be floundering around in the dark.

first Previous Page 4 of 12 last Next