1 2 3 Previous Next 32 Replies Latest reply: Oct 28, 2013 6:36 PM by ejtrim
ejtrim Level 1 Level 1 (0 points)

About two years ago I was intrigued about the disparition of several Time Machine backups. After changing to a larger external backup disk, I've been trying to follow the behavior of Time Machine. Overall, it seems to be quite predictable, corresponding to what is explained in its window: mostly keeping hourly backups during 24 hours, then, from these, only keeping the first one in each day during 30 days, and then, from these remaining backups, only keeping one per week as "space" permits. Since the new backup partition is large (240% of the HD disk), it is still far from removing oldest backup(s) in order to free space. However, in my system, Time Machine has removed more backups, which should have been kept, in at least two occassions:

  1. Several weeks ago, one month after having the system down for several days, two or three backups (specifically 2012-07-24-002423 and 2012-07-29-120258) that should be kept as weekly ones were deleted, possibly trying to resyncronize to a new day-of-week for the new series of weekly backups to keep.
  2. Recently, and possibly related with heavy memory load giving 7 GB of swap, TM "got crazy" during two activations, deleting up to eight backups, both daily and weekly ones, which were far from being the oldest backups in the volume.

Has someone else observed this kind of behavior? What can be done to avoid it? If, as it seems, it is a bug in Time Machine, how can I notify Apple?

Since Time Machine seems to have a limit of 5 old backup deletions per activation, and given that occasionally strange (and dangerous) behavior, I think that Time Machine should warn when backups older than one month are deleted, and ask permission when 5 or more backups are going to be deleted (at least giving the user the possibility of configuring it so). We are talking here of data security, so some precautions should be allowed when destroying large quantities of data, which otherwise may not be recoverable.

The essential details follow:

 

Strings in recent system.log messages containing "deleted backup" (first & last groups are normal, there was no hourly backup to delete between them):

 

Oct 27 00:30:46 iMac com.apple.backupd[34391]: Deleted backup /Volumes/iMac HD Time Machine/Backups.backupdb/iMac/2012-09-27-002110: 120.20 GB now available

 

Oct 27 02:27:42 iMac com.apple.backupd[34677]: Deleted backup /Volumes/iMac HD Time Machine/Backups.backupdb/iMac/2012-03-22-232115: 132.85 GB now available

Oct 27 02:29:05 iMac com.apple.backupd[34677]: Deleted backup /Volumes/iMac HD Time Machine/Backups.backupdb/iMac/2012-04-06-000633: 143.17 GB now available

Oct 27 02:30:23 iMac com.apple.backupd[34677]: Deleted backup /Volumes/iMac HD Time Machine/Backups.backupdb/iMac/2012-09-28-002619: 146.29 GB now available

Oct 27 02:31:32 iMac com.apple.backupd[34677]: Deleted backup /Volumes/iMac HD Time Machine/Backups.backupdb/iMac/2012-09-30-004344: 149.48 GB now available

Oct 27 02:31:50 iMac com.apple.backupd[34677]: Deleted backup /Volumes/iMac HD Time Machine/Backups.backupdb/iMac/2012-10-03-000509: 152.58 GB now available

 

Oct 27 03:27:04 iMac com.apple.backupd[34860]: Deleted backup /Volumes/iMac HD Time Machine/Backups.backupdb/iMac/2012-10-08-001931: 155.64 GB now available

Oct 27 03:27:40 iMac com.apple.backupd[34860]: Deleted backup /Volumes/iMac HD Time Machine/Backups.backupdb/iMac/2012-10-14-003758: 159.26 GB now available

Oct 27 03:28:32 iMac com.apple.backupd[34860]: Deleted backup /Volumes/iMac HD Time Machine/Backups.backupdb/iMac/2012-10-22-002147: 162.48 GB now available

 

Oct 27 11:37:36 iMac com.apple.backupd[35839]: Deleted backup /Volumes/iMac HD Time Machine/Backups.backupdb/iMac/2012-10-26-104655: 153.98 GB now available

 

List of backups dates in the backup volume, and free space, taken from the terminal (after deletions: note that the backups marked in red should normally be kept):

 

iMac:~ admin$ ls /Volumes/iMac\ HD\ Time\ Machine/Backups.backupdb/iMac/

2011-10-01-061010    2012-05-31-093201          2012-10-20-002816

2011-10-09-005429          2012-06-07-002543          2012-10-21-021504

2011-10-16-001503          2012-06-14-005742          2012-10-23-004109

2011-10-23-002554          2012-06-21-001427          2012-10-24-002334

2011-11-05-001403          2012-06-28-001245          2012-10-25-002414

2011-11-12-004617          2012-07-05-002056          2012-10-26-002613

2011-11-19-000532          2012-07-12-002639          2012-10-26-012840

2011-11-26-000431          2012-07-19-005850          2012-10-27-012731

2011-12-03-000109          2012-08-05-002510          2012-10-27-032628

2011-12-10-003557          2012-08-12-002739          2012-10-27-042813

2011-12-17-002907          2012-08-19-005740          2012-10-27-052837

2011-12-24-001228          2012-09-03-110847          2012-10-27-062824

2011-12-31-002103          2012-09-10-123630          2012-10-27-113711

2012-01-07-005520          2012-09-17-002437          2012-10-27-123817

2012-01-14-000913          2012-09-24-002309          2012-10-27-133739

2012-01-21-005206          2012-09-29-011601          2012-10-27-143746

2012-01-28-000105          2012-10-01-001701          2012-10-27-153817

2012-02-04-022951          2012-10-02-010201          2012-10-27-163745

2012-02-12-210133          2012-10-04-000909          2012-10-27-173738

2012-02-24-002145          2012-10-07-112125          2012-10-27-183838

2012-03-02-002405          2012-10-09-001929          2012-10-27-193814

2012-03-09-003236          2012-10-10-002008          2012-10-27-203751

2012-03-16-002756          2012-10-11-001416          2012-10-27-213752

2012-03-30-014934          2012-10-12-004500          2012-10-27-223747

2012-04-19-004318          2012-10-13-012506          2012-10-27-233844

2012-04-26-012354          2012-10-15-003823          2012-10-28-011809

2012-05-03-003008          2012-10-16-002207          2012-10-28-013726

2012-05-10-004554          2012-10-17-002306          Latest

2012-05-17-011942          2012-10-18-002230

2012-05-24-001808          2012-10-19-002253

 

iMac:~ admin$ df

Filesystem    512-blocks       Used Available Capacity  Mounted on

/dev/disk0s2   914062528  585638424 327912104    65%    /

devfs                226        226         0   100%    /dev

map -hosts             0          0         0   100%    /net

map auto_home          0          0         0   100%    /home

/dev/disk1s4  2343750000 1980326912 363423088    85%    /Volumes/iMac HD Time Machine

/dev/disk1s3   976562504  568072864 408489640    59%    /Volumes/iMac HD SuperDuper!


iMac, Mac OS X (10.6.8), 4 GB RAM
  • 1. Re: Time Machine 1.1 sometimes deletes backups that should keep
    ejtrim Level 1 Level 1 (0 points)

    Although it seemed back to normal, suddenly, for no apparent reason, Time Machine has just removed yet another weekly backup:

     

    Oct 30 00:34:17 iMac com.apple.backupd[5288]: Starting standard backup

    Oct 30 00:34:18 iMac com.apple.backupd[5288]: Backing up to: /Volumes/iMac HD Time Machine/Backups.backupdb

    Oct 30 00:34:31 iMac com.apple.backupd[5288]: No pre-backup thinning needed: 7.36 GB requested (including padding), 161.35 GB available

    Oct 30 00:35:27 iMac com.apple.backupd[5288]: Copied 2572 files (814.0 MB) from volume Macintosh HD.

    Oct 30 00:35:29 iMac com.apple.backupd[5288]: No pre-backup thinning needed: 6.78 GB requested (including padding), 160.55 GB available

    Oct 30 00:35:36 iMac com.apple.backupd[5288]: Copied 472 files (325.0 MB) from volume Macintosh HD.

    Oct 30 00:35:41 iMac com.apple.backupd[5288]: Starting post-backup thinning

    Oct 30 00:37:26 iMac com.apple.backupd[5288]: Deleted backup /Volumes/iMac HD Time Machine/Backups.backupdb/iMac/2012-09-17-002437: 165.86 GB now available

    Oct 30 00:37:26 iMac com.apple.backupd[5288]: Post-back up thinning complete: 1 expired backups removed

    Oct 30 00:37:28 iMac com.apple.backupd[5288]: Backup completed successfully.

     

    Normally, it was the 2012-09-30-004344 backup that had to be removed instead, was removed as part of the eight-deletion "burst" of Oct 27 shown in my first post.

     

    (Apparently, largely overestimating space needs is "normal" Time Machine beahvior.)

  • 2. Re: Time Machine 1.1 sometimes deletes backups that should keep
    RRFS Level 5 Level 5 (4,430 points)

    here is one of the best and most complete references on TM

     

    Pondini's Time Machine FAQ

     

    hope it will help

  • 3. Re: Time Machine 1.1 sometimes deletes backups that should keep
    ejtrim Level 1 Level 1 (0 points)

    Sorry, I haven't mentioned that I've read Pondini's great website on Time Machine, as well as searched through this Apple Support Communities site and elsewhere. Unfortunately, I have found no explanation of that behavior, which I suspect may happen to many people, but gets unnoticed.

     

    Although Pondini offers some explanations for unexpectedly deleted backups in item #E1, none of them apply in this case. For instance, I have verified with Time Tracker, and from the system.log* files in Console, that no large backup was made. Anyway, if it were the case, Time Machine should have just deleted the oldest backups, but not some intermediate backups apparently chosen at random. Here is the complete list of system log messages for the 8-backup deletion:

     

    Oct 27 02:25:37 iMac com.apple.backupd[34677]: Starting standard backup

    Oct 27 02:25:38 iMac com.apple.backupd[34677]: Backing up to: /Volumes/iMac HD Time Machine/Backups.backupdb

    Oct 27 02:25:56 iMac com.apple.backupd[34677]: No pre-backup thinning needed: 8.74 GB requested (including padding), 119.80 GB available

    Oct 27 02:26:17 iMac com.apple.backupd[34677]: Error: (-8084) SrcErr:YES Copying /Users/admin/Library/Application Support/Google/Chrome/Default/databases/chrome-extension_edacconmaakjimmfgnbloc blbcdcpbko_0/3-journal to (null)

    Oct 27 02:26:45 iMac com.apple.backupd[34677]: Copied 1135 files (45.5 MB) from volume Macintosh HD.

    Oct 27 02:26:46 iMac com.apple.backupd[34677]: No pre-backup thinning needed: 8.70 GB requested (including padding), 119.76 GB available

    Oct 27 02:26:50 iMac com.apple.backupd[34677]: Copied 437 files (4.3 MB) from volume Macintosh HD.

    Oct 27 02:26:54 iMac com.apple.backupd[34677]: Starting post-backup thinning

    Oct 27 02:27:42 iMac com.apple.backupd[34677]: Deleted backup /Volumes/iMac HD Time Machine/Backups.backupdb/iMac/2012-03-22-232115: 132.85 GB now available

    Oct 27 02:29:05 iMac com.apple.backupd[34677]: Deleted backup /Volumes/iMac HD Time Machine/Backups.backupdb/iMac/2012-04-06-000633: 143.17 GB now available

    Oct 27 02:30:23 iMac com.apple.backupd[34677]: Deleted backup /Volumes/iMac HD Time Machine/Backups.backupdb/iMac/2012-09-28-002619: 146.29 GB now available

    Oct 27 02:31:32 iMac com.apple.backupd[34677]: Deleted backup /Volumes/iMac HD Time Machine/Backups.backupdb/iMac/2012-09-30-004344: 149.48 GB now available

    Oct 27 02:31:50 iMac com.apple.backupd[34677]: Deleted backup /Volumes/iMac HD Time Machine/Backups.backupdb/iMac/2012-10-03-000509: 152.58 GB now available

    Oct 27 02:31:50 iMac com.apple.backupd[34677]: Post-back up thinning complete: 5 expired backups removed

    Oct 27 02:31:52 iMac com.apple.backupd[34677]: Backup completed successfully.

     

    Oct 27 03:25:38 iMac com.apple.backupd[34860]: Starting standard backup

    Oct 27 03:25:38 iMac com.apple.backupd[34860]: Backing up to: /Volumes/iMac HD Time Machine/Backups.backupdb

    Oct 27 03:25:48 iMac com.apple.backupd[34860]: No pre-backup thinning needed: 8.79 GB requested (including padding), 152.58 GB available

    Oct 27 03:26:23 iMac com.apple.backupd[34860]: Copied 1273 files (84.8 MB) from volume Macintosh HD.

    Oct 27 03:26:24 iMac com.apple.backupd[34860]: No pre-backup thinning needed: 8.70 GB requested (including padding), 152.50 GB available

    Oct 27 03:26:27 iMac com.apple.backupd[34860]: Copied 439 files (11.1 MB) from volume Macintosh HD.

    Oct 27 03:26:30 iMac com.apple.backupd[34860]: Starting post-backup thinning

    Oct 27 03:27:04 iMac com.apple.backupd[34860]: Deleted backup /Volumes/iMac HD Time Machine/Backups.backupdb/iMac/2012-10-08-001931: 155.64 GB now available

    Oct 27 03:27:40 iMac com.apple.backupd[34860]: Deleted backup /Volumes/iMac HD Time Machine/Backups.backupdb/iMac/2012-10-14-003758: 159.26 GB now available

    Oct 27 03:28:32 iMac com.apple.backupd[34860]: Deleted backup /Volumes/iMac HD Time Machine/Backups.backupdb/iMac/2012-10-22-002147: 162.48 GB now available

    Oct 27 03:28:32 iMac com.apple.backupd[34860]: Post-back up thinning complete: 3 expired backups removed

    Oct 27 03:28:33 iMac com.apple.backupd[34860]: Backup completed successfully.

     

    Incidentally, item #D4 mentions, as one possible reason for large backup, that erasing an partition excluded from Time Machine backups will make it removed from the exclusion list. I haven't seen that removal after SuperDuper erases a partition when preparing a full backup.

     

    Of course, the main danger is: will Time Machine remove much more backups for no appaarent reason? This might be prevented with an application that runs hourly and warns when that begins to happen. But then, the only thing one could do in order to avoid losing more data is to detach the backup disk, buy a new one, and start anew!

  • 4. Re: Time Machine 1.1 sometimes deletes backups that should keep
    ejtrim Level 1 Level 1 (0 points)

    I forgot to remark that all these unexpeted backup deletions weren't performed on the pre-backup thinning phase, where Time Machine may need to free space, but on the post-backup thinning phase, where it only should delete backups which have passed the 24h & 30d periods, but never the older weekly ones, which should be kept as long as space permits. As shown in the previous messages, Time Machine unexpectedly deleted both "kinds" of backups (that in principle it should keep): daily ones within the 30-day period and older weekly ones.

  • 5. Re: Time Machine 1.1 sometimes deletes backups that should keep
    RRFS Level 5 Level 5 (4,430 points)

    Have you tried contacting Apple's Technical people with this meticulously documented/researched issue? Their programmers should be interested (although hard to reach) about your find. 

  • 6. Re: Time Machine 1.1 sometimes deletes backups that should keep
    ejtrim Level 1 Level 1 (0 points)

    No... I don't know of any easy way.  I've only seen a place where it seemed that I had to register as developer. Maybe that's what I'd have to do?

  • 8. Re: Time Machine 1.1 sometimes deletes backups that should keep
    ejtrim Level 1 Level 1 (0 points)

    Thank you, RRFS. Done. It seems that, in principle, one doesn't have to expect answer from Apple on the subject.

     

    Unfortunately, I've just seen another block of unexpected deletions at once: three several-month old weekly backups, and a daily one before the 30-day threshold.  Here is the log:

     

    Nov  2 00:37:48 iMac com.apple.backupd[19555]: Starting standard backup

    Nov  2 00:37:48 iMac com.apple.backupd[19555]: Backing up to: /Volumes/iMac HD Time Machine/Backups.backupdb

    Nov  2 00:37:56 iMac com.apple.backupd[19555]: No pre-backup thinning needed: 9.07 GB requested (including padding), 172.10 GB available

    Nov  2 00:38:48 iMac com.apple.backupd[19555]: Copied 1545 files (2.2 GB) from volume Macintosh HD.

    Nov  2 00:38:51 iMac com.apple.backupd[19555]: No pre-backup thinning needed: 6.41 GB requested (including padding), 169.87 GB available

    Nov  2 00:38:54 iMac com.apple.backupd[19555]: Copied 175 files (4.4 MB) from volume Macintosh HD.

    Nov  2 00:38:57 iMac com.apple.backupd[19555]: Starting post-backup thinning

    Nov  2 00:40:01 iMac com.apple.backupd[19555]: Deleted backup /Volumes/iMac HD Time Machine/Backups.backupdb/iMac/2012-05-03-003008: 173.85 GB now available

    Nov  2 00:40:44 iMac com.apple.backupd[19555]: Deleted backup /Volumes/iMac HD Time Machine/Backups.backupdb/iMac/2012-05-24-001808: 177.37 GB now available

    Nov  2 00:41:23 iMac com.apple.backupd[19555]: Deleted backup /Volumes/iMac HD Time Machine/Backups.backupdb/iMac/2012-06-07-002543: 179.97 GB now available

    Nov  2 00:42:18 iMac com.apple.backupd[19555]: Deleted backup /Volumes/iMac HD Time Machine/Backups.backupdb/iMac/2012-10-04-000909: 183.25 GB now available

    Nov  2 00:42:18 iMac com.apple.backupd[19555]: Post-back up thinning complete: 4 expired backups removed

    Nov  2 00:42:19 iMac com.apple.backupd[19555]: Backup completed successfully.

     

    It's discouraging that all this happens silently, even though, as it seems, it makes untrue the statement in the main Time Machine window about which backups will be kept.

     

    I've tried to learn about TM's configuration, which I've located in the form of plist file and analyzed with the help of PlistBuddy, but it seem to be OK to me, as well as the plist with the result of the last "half" backup (it's a mistery to me why most backups have two copying phases). As a precaution, I've rebooted the system. Then, I've verified with Disk Utility the backup volume twice (before and after unmounting and powering off the external disk), which "appears to be OK".

  • 9. Re: Time Machine 1.1 sometimes deletes backups that should keep
    Pondini Level 8 Level 8 (38,720 points)

    ejtrim wrote:

    . . .

    1.  Several weeks ago, one month after having the system down for several days, two or three backups (specifically 2012-07-24-002423 and 2012-07-29-120258) that should be kept as weekly ones were deleted, possibly trying to resyncronize to a new day-of-week for the new series of weekly backups to keep.

    Yes, TM does seem to "change the day" of the weekly backup after an extended period of no (completed) backups, resulting in some weeks having no backups retained at all.  I don't know exactly what the circumstances are -- the day doesn't seem to be retained in a plist anywhere, so we can only assume the determination is made by looking at the backups found during the "thinning" process.

     

     

    Extracted from your list:

    Oct 27 02:27:42 iMac com.apple.backupd[34677]: Deleted backup /Volumes/iMac HD Time Machine/Backups.backupdb/iMac/2012-03-22-232115: 132.85 GB now available

     

    2012-03-02-002405  

    2012-03-09-003236     

    2012-03-16-002756       

    2012-03-30-014934      

    March 2, 9, 16, and 30 were all on Fridays.

     

    March 22 was a Thursday, so should have been deleted.  We can only guess now, but it appears there was no backup on March 23.

     

    Oct 27 03:28:32 iMac com.apple.backupd[34860]: Deleted backup /Volumes/iMac HD Time Machine/Backups.backupdb/iMac/2012-10-22-002147: 162.48 GB now available

     

    2012-10-20-002816

    2012-10-21-021504

    2012-10-23-004109

    Yes, it does appear that one should have been retained. 

     

    Incidentally, item #D4 mentions, as one possible reason for large backup, that erasing an partition excluded from Time Machine backups will make it removed from the exclusion list. I haven't seen that removal after SuperDuper erases a partition when preparing a full backup.

    That's because when you erase a partition, it gets a new UUID, and is treated as a different one for most purposes.  So if it's an internal HD that was on the exclusion list, it will be removed from that list, and backed-up on the next backup.  (If it's an external that wasn't on the exclusion list, thus was being backed-up, the "new" volume will be put on the exclusion list by default.)

     

    I don't use SuperDuper, but I suspect it will only back up one volume at a time, so isn't as concerned with trying to keep track of which one is which.

     

    (it's a mistery to me why most backups have two copying phases).

     

    Yes, TM will make a second "pass" if changes are made during the first one, apparently so the timestamp is as close to the last file change as possible. 

     

     

    If you want to pursue this, you can file a detailed Bug Report, per Reporting a Problem to Apple.  (You'll never get an answer from the Feedback site.)

     

    But simplify what you have as much as possible;  you might mention that it seems to happen under various circumstances, but it's probably best to present one representative sample.  Be very clear about the dates, days of the week, etc, and what should or should not have happened, so the engineers don't have to try to figure it out (and perhaps misunderstand).

     

    Don't expect a quick answer;  I've received no response at all to a couple filed in 2010; I recently got a response that one I filed in 2010 under Snow Leopard has been fixed in Mountain Lion.

     

    If you're still on Snow Leopard, you may not get much, if any, satisfaction, since no updates are being made to it anymore, and there were major changes in Lion, and others in Mountain Lion. 

     

    You may get a request for more info, so be sure to keep all the logs, etc., you can.

  • 10. Re: Time Machine 1.1 sometimes deletes backups that should keep
    Pondini Level 8 Level 8 (38,720 points)

    I should add:  If you're depending on Time Machine to keep copies of things you've changed or deleted indefinitely, or even for many months, you may need to reconsider your backup strategy.

     

    First, a single backup is a bit risky -- no matter where it is or how it was made.  All disk drives fail, sometimes sooner, usually later;  no backup app is perfect;  and users sometimes erase the wrong drive, or drop one.  Many experienced users keep "secondary" backups (at least) for just such circumstances.  See Time Machine - Frequently Asked Question #27 for some suggestions.

     

    Second, if you're really concerned about copies of non-current files, perhaps you should be archiving them, either as needed or on some regular schedule, depending on the circumstances.  A dedicated external HD, CDs/DVDs, or even tape storage might be appropriate.

  • 11. Re: Time Machine 1.1 sometimes deletes backups that should keep
    ejtrim Level 1 Level 1 (0 points)

    Thanks, Pondini, for your detailed answers!

    Pondini wrote:

    ejtrim wrote:

    . . .

    1.  Several weeks ago, one month after having the system down for several days, two or three backups (specifically 2012-07-24-002423 and 2012-07-29-120258) that should be kept as weekly ones were deleted, possibly trying to resyncronize to a new day-of-week for the new series of weekly backups to keep.

    Yes, TM does seem to "change the day" of the weekly backup after an extended period of no (completed) backups, resulting in some weeks having no backups retained at all.  I don't know exactly what the circumstances are -- the day doesn't seem to be retained in a plist anywhere, so we can only assume the determination is made by looking at the backups found during the "thinning" process.

    It might be conceded that one of those two backups had been deleted (although I'd prefer to keep both), generating a longer-than-one-week gap, but not both, producing a longer-than-two-weeks gap!

     

    It seem to me that the following simple algorithm would suffice to accomplish what Time Machine promises:

     

    For each backup older than 24 hours, starting with the oldest one:

    (a) if it is older than 30 days, delete it only if there is another one earlier in the "week" ending on that day,

    (b) otherwise, delete it only if there is another one earlier that same day.

     

    I've observed that when Time Machine has a "backlog", it deletes at most five backups each time (what seems prudent!), and that, in these cases, backups of older days are deleted first, but that within a same day newer ones are deleted first.

    Extracted from your list:

    Oct 27 02:27:42 iMac com.apple.backupd[34677]: Deleted backup /Volumes/iMac HD Time Machine/Backups.backupdb/iMac/2012-03-22-232115: 132.85 GB now available

     

    2012-03-02-002405  

    2012-03-09-003236     

    2012-03-16-002756       

    2012-03-30-014934      

    March 2, 9, 16, and 30 were all on Fridays.

     

    March 22 was a Thursday, so should have been deleted.  We can only guess now, but it appears there was no backup on March 23.

    From my records, there had been backups on March 23, although I can't tell when the last-remaining one was deleted.

     

    I'll try to prepare a Bug Report for Apple. I should have noticed the corresponding section on your site! Anyway, I tend to believe that the deletion algorithm hasn't change for the newer OS releases. It seems that there is no much concern about these unexpected deletions, maybe because when one is looking for an old version of a file, one will be happy enough if it's found in one of the remaining backups, otherwise, it's difficult to tell if it should be on a backup of a long past date that should have been retained.

     

    Thank you again for your advice!

  • 12. Re: Time Machine 1.1 sometimes deletes backups that should keep
    ejtrim Level 1 Level 1 (0 points)

    Time Machine has unexpectedly deleted several more backups, all of them (marked in red) about 2 hours before the 24-hour limit, then returned to expected behavior. Here is the complete list of yesterday's deletions (there was no 9pm backup to delete):

     

    Nov  5 04:04:46 iMac com.apple.backupd[18020]: Deleted backup /Volumes/iMac HD Time Machine/Backups.backupdb/iMac/2012-11-04-035134: 163.92 GB now available

    Nov  5 10:07:01 iMac com.apple.backupd[20110]: Deleted backup /Volumes/iMac HD Time Machine/Backups.backupdb/iMac/2012-11-04-114210: 155.69 GB now available

    Nov  5 11:06:46 iMac com.apple.backupd[20335]: Deleted backup /Volumes/iMac HD Time Machine/Backups.backupdb/iMac/2012-11-04-103500: 155.68 GB now available

    Nov  5 12:06:51 iMac com.apple.backupd[20542]: Deleted backup /Volumes/iMac HD Time Machine/Backups.backupdb/iMac/2012-11-04-134014: 153.54 GB now available

    Nov  5 13:06:34 iMac com.apple.backupd[20687]: Deleted backup /Volumes/iMac HD Time Machine/Backups.backupdb/iMac/2012-11-04-124112: 153.56 GB now available

    Nov  5 14:06:28 iMac com.apple.backupd[20828]: Deleted backup /Volumes/iMac HD Time Machine/Backups.backupdb/iMac/2012-11-04-154128: 153.55 GB now available

    Nov  5 15:06:37 iMac com.apple.backupd[21152]: Deleted backup /Volumes/iMac HD Time Machine/Backups.backupdb/iMac/2012-11-04-144118: 153.54 GB now available

    Nov  5 16:06:20 iMac com.apple.backupd[21360]: Deleted backup /Volumes/iMac HD Time Machine/Backups.backupdb/iMac/2012-11-04-174138: 151.67 GB now available

    Nov  5 17:06:31 iMac com.apple.backupd[21510]: Deleted backup /Volumes/iMac HD Time Machine/Backups.backupdb/iMac/2012-11-04-164144: 151.66 GB now available

    Nov  5 18:07:27 iMac com.apple.backupd[21674]: Deleted backup /Volumes/iMac HD Time Machine/Backups.backupdb/iMac/2012-11-04-194018: 151.59 GB now available

    Nov  5 20:48:14 iMac com.apple.backupd[21804]: Deleted backup /Volumes/iMac HD Time Machine/Backups.backupdb/iMac/2012-11-04-184044: 151.57 GB now available

    Nov  5 21:33:14 iMac com.apple.backupd[22086]: Deleted backup /Volumes/iMac HD Time Machine/Backups.backupdb/iMac/2012-11-04-230603: 151.54 GB now available

    Nov  5 22:33:30 iMac com.apple.backupd[22370]: Deleted backup /Volumes/iMac HD Time Machine/Backups.backupdb/iMac/2012-11-04-220537: 151.49 GB now available

    Nov  5 23:32:21 iMac com.apple.backupd[23141]: Deleted backup /Volumes/iMac HD Time Machine/Backups.backupdb/iMac/2012-11-05-000610: 151.47 GB now available

     

    And here is the complete log of Time Machine executions around the first unexpected deletion:

     

    Nov  5 09:04:17 iMac com.apple.backupd[19826]: Starting standard backup

    Nov  5 09:04:27 iMac com.apple.backupd[19826]: Backing up to: /Volumes/iMac HD Time Machine/Backups.backupdb

    Nov  5 09:04:41 iMac com.apple.backupd[19826]: No pre-backup thinning needed: 9.08 GB requested (including padding), 159.15 GB available

    Nov  5 09:05:35 iMac com.apple.backupd[19826]: Copied 1075 files (2.2 GB) from volume Macintosh HD.

    Nov  5 09:05:38 iMac com.apple.backupd[19826]: No pre-backup thinning needed: 6.41 GB requested (including padding), 156.92 GB available

    Nov  5 09:05:40 iMac com.apple.backupd[19826]: Copied 175 files (1.1 MB) from volume Macintosh HD.

    Nov  5 09:05:43 iMac com.apple.backupd[19826]: Starting post-backup thinning

    Nov  5 09:05:43 iMac com.apple.backupd[19826]: No post-back up thinning needed: no expired backups exist

    Nov  5 09:05:43 iMac com.apple.backupd[19826]: Backup completed successfully.

     

    Nov  5 10:04:18 iMac com.apple.backupd[20110]: Starting standard backup

    Nov  5 10:04:18 iMac com.apple.backupd[20110]: Backing up to: /Volumes/iMac HD Time Machine/Backups.backupdb

    Nov  5 10:04:38 iMac com.apple.backupd[20110]: No pre-backup thinning needed: 10.56 GB requested (including padding), 156.92 GB available

    Nov  5 10:06:11 iMac com.apple.backupd[20110]: Copied 1314 files (3.5 GB) from volume Macintosh HD.

    Nov  5 10:06:22 iMac com.apple.backupd[20110]: No pre-backup thinning needed: 6.41 GB requested (including padding), 153.45 GB available

    Nov  5 10:06:32 iMac com.apple.backupd[20110]: Copied 744 files (1.1 MB) from volume Macintosh HD.

    Nov  5 10:06:36 iMac com.apple.backupd[20110]: Starting post-backup thinning

    Nov  5 10:07:01 iMac com.apple.backupd[20110]: Deleted backup /Volumes/iMac HD Time Machine/Backups.backupdb/iMac/2012-11-04-114210: 155.69 GB now available

    Nov  5 10:07:01 iMac com.apple.backupd[20110]: Post-back up thinning complete: 1 expired backups removed

    Nov  5 10:07:01 iMac com.apple.backupd[20110]: Backup completed successfully.

     

    Nov  5 11:04:17 iMac com.apple.backupd[20335]: Starting standard backup

    Nov  5 11:04:27 iMac com.apple.backupd[20335]: Backing up to: /Volumes/iMac HD Time Machine/Backups.backupdb

    Nov  5 11:04:43 iMac com.apple.backupd[20335]: No pre-backup thinning needed: 9.14 GB requested (including padding), 155.69 GB available

    Nov  5 11:05:58 iMac com.apple.backupd[20335]: Copied 1223 files (2.3 GB) from volume Macintosh HD.

    Nov  5 11:06:08 iMac com.apple.backupd[20335]: No pre-backup thinning needed: 6.41 GB requested (including padding), 153.41 GB available

    Nov  5 11:06:17 iMac com.apple.backupd[20335]: Copied 596 files (1.1 MB) from volume Macintosh HD.

    Nov  5 11:06:21 iMac com.apple.backupd[20335]: Starting post-backup thinning

    Nov  5 11:06:46 iMac com.apple.backupd[20335]: Deleted backup /Volumes/iMac HD Time Machine/Backups.backupdb/iMac/2012-11-04-103500: 155.68 GB now available

    Nov  5 11:06:46 iMac com.apple.backupd[20335]: Post-back up thinning complete: 1 expired backups removed

    Nov  5 11:06:46 iMac com.apple.backupd[20335]: Backup completed successfully.

     

    It's a bit disappointing this unexpected and opaque behavior.

  • 13. Re: Time Machine 1.1 sometimes deletes backups that should keep
    Pondini Level 8 Level 8 (38,720 points)

    Odd, indeed.

     

    Those backups were all made on November 4.  Guess what else happened that day?  I wonder if it's trying to adjust for Daylight Savings time (but not getting it quite right).

     

    I don't see the same behavior in my (Mountain Lion) logs for November 5.

     

    I'm not entirely sure how it's done, but the times (and, when necessary, dates) do get adjusted, at least on earlier versions of OSX (I haven't noticed it lately).  When doing a full system restore (starting from an Install disk instead of OSX), the datestamps shown on the selection window were sometimes shown in Pacific Standard Time, not your local time.  I recall some users in England being very confused by that, as the adjustment can change the date as well, since they're 8 hours ahead of Pacific time.

     

     

    Still, this doesn't seem to be a significant bug -- it's not deleting large groups of backups at the wrong time.  By all means, report it to Apple, but if you're depending on Time Machine keeping certain copies of things you've changed or deleted, perhaps you need to reconsider your backup strategy.

  • 14. Re: Time Machine 1.1 sometimes deletes backups that should keep
    ejtrim Level 1 Level 1 (0 points)

    Who knows, maybe, as you say, it's related to DST, but it shouldn't, one week after the hour change took place.

     

    Regarding timestamps, yes, they would be more accurate if timezone indicator were added to logs and backups.

     

    Fortunately, I am not depending on the regularity of remaining backups, but it's not very reassuring to see that quite often Time Machine irregularly deletes old and recent backups for no clear reason. It seems difficult to imagine how what might be a simple algorithm gives that bizarre behavior at times. Maybe Time Machine should double-check before proceeding to deletion.

1 2 3 Previous Next