Skip navigation

Time Machine always requires deep traversal?

13583 Views 174 Replies Latest reply: Feb 18, 2014 8:41 AM by bernuli RSS
  • ZX48 Level 1 Level 1 (0 points)
    Currently Being Moderated
    Feb 6, 2013 1:07 AM (in response to ZX48)

    Wait. I've just realised TM has initiated another backup straight after the one I jsut triggered - that is why the HD is spinning. I'm not sure it is fixed. I haven't done anything in the interim and the number of copied files is now already up to 36766 (21.3 MB). :-(

     

    06/02/2013 08:44:51com.apple.backupd[3374]Starting standard backup
    06/02/2013 08:44:51com.apple.backupd[3374]Backing up to: /Volumes/MyBook/Backups.backupdb
    06/02/2013 08:45:28com.apple.backupd[3374]No pre-backup thinning needed: 3.18 GB requested (including padding), 48.06 GB available
    06/02/2013 08:48:38com.apple.backupd[3374]Copied 36766 files (21.3 MB) from volume Snow Leopard SSD.
    06/02/2013 08:48:46com.apple.backupd[3374]No pre-backup thinning needed: 3.15 GB requested (including padding), 48.02 GB available
    06/02/2013 08:49:05com.apple.backupd[3374]Copied 2000 files (629 KB) from volume Snow Leopard SSD.
    06/02/2013 08:49:15com.apple.backupd[3374]Starting post-backup thinning

     

    Any ideas?

     

    Straight after deleting .fseventsd all I had this in that directory was:

     

    sudo ls -l /.fseventsd

     

    total 8

    -rw-------  1 root  admin  36  5 Feb 16:23 fseventsd-uuid

     

    Now I have:

     

    sudo ls -l /.fseventsd

     

    total 32

    -rw-------  1 root  admin  9182  6 Feb 01:42 fc007475e29523e8

    -rw-------  1 root  admin    36  5 Feb 16:23 fseventsd-uuid

     

    So at 01:42 9182 files (?) were created in this directory. Is that correct?

    The only things listed in the console log around 01:42 last night are:

     

    06/02/2013 00:32:19com.apple.backupd[2290]Backup completed successfully.
    06/02/2013 00:42:47kernelPM notification cancel (pid 64, InternetSharing)
    06/02/2013 00:42:47kernelIOPMrootDomain: idle cancel
    06/02/2013 00:52:18kernelPM notification cancel (pid 64, InternetSharing)
    06/02/2013 00:52:18kernelIOPMrootDomain: idle cancel
    06/02/2013 00:55:49kernelPM notification cancel (pid 64, InternetSharing)
    06/02/2013 00:55:49kernelIOPMrootDomain: idle cancel
    06/02/2013 00:57:49kernelPM notification cancel (pid 64, InternetSharing)
    06/02/2013 00:57:49kernelIOPMrootDomain: idle cancel
    06/02/2013 01:02:20kernelPM notification cancel (pid 64, InternetSharing)
    06/02/2013 01:02:20kernelIOPMrootDomain: idle cancel
    06/02/2013 01:07:50kernelPM notification cancel (pid 64, InternetSharing)
    06/02/2013 01:07:50kernelIOPMrootDomain: idle cancel
    06/02/2013 01:11:50kernelPM notification cancel (pid 64, InternetSharing)
    06/02/2013 01:11:50kernelIOPMrootDomain: idle cancel
    06/02/2013 01:12:00kernelCODE SIGNING: cs_invalid_page(0x1000): p=2471[GoogleSoftwareUp] clearing CS_VALID
    06/02/2013 01:13:29kernelPM notification cancel (pid 64, InternetSharing)
    06/02/2013 01:13:29kernelIOPMrootDomain: idle cancel
    06/02/2013 01:21:51kernelPM notification cancel (pid 64, InternetSharing)
    06/02/2013 01:21:51kernelIOPMrootDomain: idle cancel
    06/02/2013 01:40:54kernelPM notification cancel (pid 64, InternetSharing)
    06/02/2013 01:40:54kernelIOPMrootDomain: idle cancel
    06/02/2013 02:06:38kernelPM notification cancel (pid 64, InternetSharing)
    06/02/2013 02:06:38kernelIOPMrootDomain: idle cancel
    06/02/2013 02:08:08kernelPM notification cancel (pid 64, InternetSharing)
    06/02/2013 02:08:08kernelIOPMrootDomain: idle cancel
    06/02/2013 02:10:44kernelCODE SIGNING: cs_invalid_page(0x1000): p=2690[GoogleSoftwareUp] clearing CS_VALID

     

    Any suggestions would be most appreciated!

    Oh, and the backup HD is still churning even though the last backup finished >10 minutes ago

  • ZX48 Level 1 Level 1 (0 points)
    Currently Being Moderated
    Feb 6, 2013 2:04 AM (in response to ZX48)

    An hour later and I'm up to 17,000...(or am I misinterpretting what this number is?). If it is a folder, can I delve into it to see where the specific files are being created?

     

    total 48

    -rw-------  1 root  admin  17812  6 Feb 09:37 fc007475e29523e8

    -rw-------  1 root  admin     36  5 Feb 16:23 fseventsd-uuid

     

    ---

    EDIT:

     

    I now see that this number is the size of the file in bytes,a nd that the preceding "48" is not the number of files, but the number of 512-byte blocks used - so 48 = 24MB.

     

    From the manual:

     

    The Long Format

         If the -l option is given, the following information is displayed for

         each file: file mode, number of links, owner name, group name, number of

         bytes in the file, abbreviated month, day-of-month file was last modi-

         fied, hour file last modified, minute file last modified, and the path-

         name.  In addition, for each directory whose contents are displayed, the

         total number of 512-byte blocks used by the files in the directory is

         displayed on a line by itself, immediately before the information for the

         files in the directory.

     

    So, I guess the question is: Why do I have this one enormous (and growing) file in .fseventsd?

  • bernuli Level 1 Level 1 (50 points)
    Currently Being Moderated
    Feb 6, 2013 7:24 AM (in response to ZX48)

    95% full on the backup hard drive is probably not a good thing.   Perhaps Time Machine will trim down your backups after a few cycles?  Otherwise you should do what you can to free space on the backup drive.

     

    Are you backing up Parallels or VMware virtual machines?

     

    How many TM runs have you been through since clearing .fseventsd?

     

     

    B

  • bernuli Level 1 Level 1 (50 points)
    Currently Being Moderated
    Feb 6, 2013 7:31 AM (in response to ZX48)

    The file size listed in ls -l is bytes.  That is a totally normall file size.  The problem is when you get a ton of outdated files in their.

     

    B

  • Pondini Level 8 Level 8 (38,710 points)
    Currently Being Moderated
    Feb 6, 2013 7:35 AM (in response to ZX48)

    ZX48 wrote:

     

    Wait. I've just realised TM has initiated another backup straight after the one I jsut triggered - that is why the HD is spinning. I'm not sure it is fixed. I haven't done anything in the interim and the number of copied files is now already up to 36766 (21.3 MB). :-(

     

    Look in /Library/Preferences and <home folder>/Library/Preferences -- see if there are thousands of empty files there with 4 or more nonsense characters in the names.   If so, they might be the problem.  Delete them.

     

    total 48

    -rw-------  1 root  admin  17812  6 Feb 09:37 fc007475e29523e8

    -rw-------  1 root  admin     36  5 Feb 16:23 fseventsd-uuid

    . . .

    So, I guess the question is: Why do I have this one enormous (and growing) file in .fseventsd?

     

    That shouldn't matter to Time Machine, since it doesn't back up the Event Store -- it's excluded automatically.  It's used only to determine what other files have been changed and need to be backed-up.  I'm no expert in this area, but your results don't seem out of line, compared to mine.

  • Pondini Level 8 Level 8 (38,710 points)
    Currently Being Moderated
    Feb 6, 2013 7:43 AM (in response to bernuli)

    bernuli wrote:

     

    95% full on the backup hard drive is probably not a good thing.   Perhaps Time Machine will trim down your backups after a few cycles?  Otherwise you should do what you can to free space on the backup drive.

    No, that's not a problem.  Time Machine is designed to use all the available space, and it will delete old backups automatically when it runs out of room.  OSX needs a lot of free space on the startup drive, but a data-only drive doesn't, especially a backup drive where the files aren't accessed frequently.

     

    If there's anything else there, besides the backups, that's usuallly not a good idea, though.

  • ZX48 Level 1 Level 1 (0 points)
    Currently Being Moderated
    Feb 6, 2013 8:09 AM (in response to Pondini)

     

    If there's anything else there, besides the backups, that's usuallly not a good idea, though.

     

    There is actually (some manual copies of some large folders from a different computer). These are held in a separate folder at the root of the drive. Not in a separate partition.

     

    But yes, the drive is full becasue it has been used as a backup for 3 years or so (it is a RAID 1 mirrored WD MyBook 2x1TB connected via FW800. Approx 50GB free.).

     

    I don't have any of the errant pref files.

     

    I just ran terminal command again:

     

    total 88

    -rw-------  1 root  admin  17812  6 Feb 09:37 fc007475e29523e8

    -rw-------  1 root  admin  16405  6 Feb 15:25 fc007475e2a3514b

    -rw-------  1 root  admin     36  5 Feb 16:23 fseventsd-uuid

     

    Then I just ran a backup:

     

    06/02/2013 15:40:10com.apple.backupd[5364]Starting standard backup
    06/02/2013 15:40:10com.apple.backupd[5364]Backing up to: /Volumes/MyBook/Backups.backupdb
    06/02/2013 15:41:05com.apple.backupd[5364]No pre-backup thinning needed: 3.56 GB requested (including padding), 49.31 GB available
    06/02/2013 15:45:28com.apple.backupd[5364]Copied 48527 files (345.5 MB) from volume Snow Leopard SSD.
    06/02/2013 15:45:39com.apple.backupd[5364]No pre-backup thinning needed: 3.15 GB requested (including padding), 48.95 GB available
    06/02/2013 15:46:14com.apple.backupd[5364]Copied 2812 files (1.9 MB) from volume Snow Leopard SSD.
    06/02/2013 15:46:30com.apple.backupd[5364]Starting post-backup thinning
    06/02/2013 15:50:22com.apple.backupd[5364]Deleted backup /Volumes/MyBook/Backups.backupdb/SL/2013-02-04-092140: 48.98 GB now available
    06/02/2013 15:53:40com.apple.backupd[5364]Deleted backup /Volumes/MyBook/Backups.backupdb/SL/2013-02-05-131940: 49.33 GB now available
    06/02/2013 15:53:40com.apple.backupd[5364]Post-back up thinning complete: 2 expired backups removed
    06/02/2013 15:53:43com.apple.backupd[5364]Backup completed successfully.

     

    48,527 files and 345MB taking 5-6 minutes, plus another 7 minutes for the thinning.

     

    I then immediately clicked "Backup Now":

     

    06/02/2013 15:54:43com.apple.backupd[5364]Starting standard backup
    06/02/2013 15:54:43com.apple.backupd[5364]Backing up to: /Volumes/MyBook/Backups.backupdb
    06/02/2013 15:55:25com.apple.backupd[5364]No pre-backup thinning needed: 3.16 GB requested (including padding), 49.33 GB available
    06/02/2013 15:59:40com.apple.backupd[5364]Copied 48510 files (7.5 MB) from volume Snow Leopard SSD.
    06/02/2013 15:59:50com.apple.backupd[5364]No pre-backup thinning needed: 3.16 GB requested (including padding), 49.31 GB available
    06/02/2013 16:00:22com.apple.backupd[5364]Copied 2812 files (1.5 MB) from volume Snow Leopard SSD.
    06/02/2013 16:00:39com.apple.backupd[5364]Starting post-backup thinning

     

    As you can see, it still copied another 48,510 files (but only 7.5MB this time) taking 6 minutes total.


    While it is better than before (I don't have the fans spinning up durign the backup process) it still seems just as broken as before I cleaned up .fseventsd

     

    Please note that after clearing .fseventsd, I managed only 3 backups (of approx 1800 files each), before that number lept to 36k, and now 48k.

     

    Do you think this is as good as I can get it?

  • Pondini Level 8 Level 8 (38,710 points)
    Currently Being Moderated
    Feb 6, 2013 8:50 AM (in response to ZX48)

    ZX48 wrote:

    . . .

    There is actually (some manual copies of some large folders from a different computer). These are held in a separate folder at the root of the drive. Not in a separate partition.

    That should be ok, but really ought to have been put in a separate partition (it's probably too late to partition it now).

     

    Time Machine won't delete it, but if you ever want or need to delete all the backups, it will take a very long time (many minutes, perhaps hours) since you can't just erase the partition.

     

    In addition, be very careful about adding to it -- if the drive gets entirely full, TM won't be able to get started far enough to begin deleting old backups, and will just crash.

     

     

    total 88

    -rw-------  1 root  admin  17812  6 Feb 09:37 fc007475e29523e8

    -rw-------  1 root  admin  16405  6 Feb 15:25 fc007475e2a3514b

    -rw-------  1 root  admin     36  5 Feb 16:23 fseventsd-uuid

    I'm not sure that's bad.  Here's mine so far this month:

     

    -rw-------  1 root  wheel      27723 Feb  1 10:37 636573335c1af6a7

    -rw-------  1 root  wheel      36246 Feb  1 17:59 636573335c1ef5a0

    -rw-------  1 root  wheel      42744 Feb  1 19:15 636573335c20ac62

    -rw-------  1 root  wheel      26874 Feb  2 16:18 636573335c2a41b1

    -rw-------  1 root  wheel      35134 Feb  3 00:02 636573335c2f8efd

    -rw-------  1 root  wheel      26827 Feb  3 16:48 636573335c360052

    -rw-------  1 root  wheel      32491 Feb  4 09:00 636573335c3acf51

    -rw-------  1 root  wheel      28111 Feb  4 19:15 636573335c428bf3

    -rw-------  1 root  wheel      26441 Feb  5 17:29 636573335c4cf953

    -rw-------  1 root  wheel      18985 Feb  5 20:15 636573335c4edbb9

    -rw-------  1 root  wheel         75 Feb  5 20:15 636573335c4edbba

    -rw-------  1 root  wheel         70 Feb  5 20:17 636573335c4efe52

    -rw-------  1 root  wheel         75 Feb  5 20:17 636573335c4efe53

    -rw-------  1 root  wheel        125 Feb  5 20:24 636573335c4f0d7b

    -rw-------  1 root  wheel         75 Feb  5 20:24 636573335c4f0d7c

    -rw-------  1 root  jamespond     36 Feb  5 20:24 fseventsd-uuid

     

    I've not been doing much besides email, but have rebooted a couple of times.

     

     

    As you can see, it still copied another 48,510 files (but only 7.5MB this time) taking 6 minutes total.


    While it is better than before (I don't have the fans spinning up durign the backup process) it still seems just as broken as before I cleaned up .fseventsd

     

    Please note that after clearing .fseventsd, I managed only 3 backups (of approx 1800 files each), before that number lept to 36k, and now 48k.

     

    Do you think this is as good as I can get it?

    Sorry, I really don't know what's going on. 

     

    Have you tried seeing what's getting backed-up, via one of the apps in #A2 of Time Machine - Troubleshooting?

     

    If you haven't yet, try a Safe Boot -- that might help, or find something else wrong.

     

     

    For some reason, it does seem limited to 10.6.8.  I believe a few folks have fixed it by reinstalling Snow Leopard, then only updating to 10.6.7 (but be aware of the 3rd item in #D5 of the same link).

  • ZX48 Level 1 Level 1 (0 points)
    Currently Being Moderated
    Feb 6, 2013 9:11 AM (in response to Pondini)

    Thanks. I can't run 10.6.7 - my machine is only compatible with 10.6.8 (2011 Mac mini i7).

     

    I used Time Tracker - a neat piece of software - thanks!

     

    I think the occasions when I get ~300MB backup are when I've saved something within my Dropbox folder, as I have a 277.7MiB file inside the hidden ".dropbox" folder that is not backed up every time (i.e. not when the backup is 10MB or so). The large file is named: "sigstore.dbx"

     

    That seems like a pretty huge file, and I guess it gets modified any time I make even just a small change to one of the files within Dropbox. Perhaps that whole ".dropbox" folder should be excluded from TM?

     

    In any case, if I expand all of the tree, there is nowhere near the 48,000 files indicated by TM. I can only assume that the TM/console is reporting oncorrectly. (or that TimeTracker can't see all the supposed files).

     

    So excluding the sigstore.dbx woudln't make much difference.

     

    Cheers though!

  • Pondini Level 8 Level 8 (38,710 points)
    Currently Being Moderated
    Feb 6, 2013 9:39 AM (in response to ZX48)

    ZX48 wrote:

     

    Thanks. I can't run 10.6.7 - my machine is only compatible with 10.6.8 (2011 Mac mini i7).

    Rats.  Thought that might be a viable workaround.

     

    That seems like a pretty huge file, and I guess it gets modified any time I make even just a small change to one of the files within Dropbox. Perhaps that whole ".dropbox" folder should be excluded from TM?

    Yes, that's just Dropbox's way of seeing what needs to be sent to their servers.  No reason for Time Machine to back it up.  Mine's excluded.

     

     

    In any case, if I expand all of the tree, there is nowhere near the 48,000 files indicated by TM. I can only assume that the TM/console is reporting oncorrectly. (or that TimeTracker can't see all the supposed files).

    Time Tracker will usually show something on a file/folder you're not authorized to see, such as:

     

    Screen Shot 2013-02-06 at 12.36.27 PM.png

     

    Those are folders we're not permitted to see (inside a hidden folder!)   You can grant yourself permission to see them, but if you don't see anything in red via Time Tracker, the problem is elsewhere.

     

     

    The counts are always high (but not as high as you've geen getting).  I suspect it's counting metadata separately (extended attributes, permissions, ACLs, etc.) but I have no idea how to determine that, or whether that's what it's stumbling over for you.

  • bernuli Level 1 Level 1 (50 points)
    Currently Being Moderated
    Feb 6, 2013 10:45 PM (in response to ZX48)

    I have found that the number of files backupd reports as copied is much larger than the number of new files copied to the TM archive. 

     

    What is happening, at least to me, on 10.6.8 is that TM for some reason thinks a folder has been modified, even though it hasn't.  It then backs up the folder but checks each file individually and skips when it finds no modification compared to what is on the TM drive.  It reports back that it copied every file, though really they are just all hard links.  This all takes extra processing time and slows it down needlessly.

     

    Restarting seems to help with this.

     

    I'll keep digging to try and find out why.

     

     

    B

  • ZX48 Level 1 Level 1 (0 points)
    Currently Being Moderated
    Feb 7, 2013 7:25 AM (in response to bernuli)

    OK. So I guess at least I've figured a few things out. TM makes backups of both my .dropbox folder (containing a 270MB .sigstore.dbx database file AND it backs up my Sente library file (>100MB). Both of these get upadted by the OS/software for very little actual change to my data. So at least this explains why I see sequential backups being approx 500MB even when I do very little actual modification.

     

    It would also explain why the drive is filling up so fast. Hourly backups and approx 0.5GB per hour = 10-12GB per day.


    None of this explains why TM thinks I have 49000 files needing backing up, but I guess I have to live with that bug. At least for me, clearing out fseventsd didn't last for more than 3 backup cycles.

     

    In TimeTracker I do have a number of "red" files. Is it worth investigating inside these?

     

    https://www.dropbox.com/s/0bs96ctkng241ig/TT%20grab.png

  • Pondini Level 8 Level 8 (38,710 points)
    Currently Being Moderated
    Feb 7, 2013 8:31 AM (in response to ZX48)

    ZX48 wrote:

    . . .

    TM makes backups of both my .dropbox folder (containing a 270MB .sigstore.dbx database file AND it backs up my Sente library file (>100MB). Both of these get upadted by the OS/software for very little actual change to my data.

    Yup.  TM backs-up almost everything that's changed at all.  (It does exclude system files, most logs & caches, trash, etc.).

     

     

    None of this explains why TM thinks I have 49000 files needing backing up, but I guess I have to live with that bug. At least for me, clearing out fseventsd didn't last for more than 3 backup cycles.

    That's a tough one.  I can only suspect that you have some non-standard process or app running that's marking things as changed when they really aren't.

     

    Are you running any anti-virus software?  Some of those can cause all sorts of problems, although I don't recall seeing this particular one.

     

    Or any sort of system monitoring app?

     

    In TimeTracker I do have a number of "red" files. Is it worth investigating inside these?

    Those all look like standard system files/folders, and should be small.

  • ZX48 Level 1 Level 1 (0 points)
    Currently Being Moderated
    Feb 7, 2013 8:37 AM (in response to Pondini)

    Could it be CrashPlan Pro?

    The only other thing (I know of) is SecondBar and FanControl

  • Tom Messenger Calculating status...
    Currently Being Moderated
    Feb 7, 2013 8:42 AM (in response to ZX48)

    This is strange – I came to the forum as I've been having a very similar problem. Could be coincidence, but I'm replying to this thread in case there is a connection.

     

    I have been using TM without issue for 2 years, but over the last week or so I have noticed that it is taking a long time to complete it's hourly backups. Despite the fact that I am only working on one file, it prepares and backs up several hundred items, a total of aound 40mb – every hour.

Actions

More Like This

  • Retrieving data ...

Bookmarked By (5)

Legend

  • This solved my question - 10 points
  • This helped me - 5 points
This site contains user submitted content, comments and opinions and is for informational purposes only. Apple disclaims any and all liability for the acts, omissions and conduct of any third parties in connection with or related to your use of the site. All postings and use of the content on this site are subject to the Apple Support Communities Terms of Use.