Watch how TimeMachine's
backupd performs its only task, backing up stuff, like an utter moron. Kindly witness the timestamps...
I massaged the log output heavily for readability.
14:35:30 backupd: Node requires deep traversal:/Volumes/Source reason:kFSEDBEventFlagMustScanSubDirs|kFSEDBEventFlagReasonEventDBUntrustable|
14:42:55 backupd: Node requires deep traversal:/Volumes/Installer reason:kFSEDBEventFlagMustScanSubDirs|kFSEDBEventFlagReasonEventDBUntrustable|
14:43:07 backupd: Node requires deep traversal:/Volumes/Users reason:kFSEDBEventFlagMustScanSubDirs|kFSEDBEventFlagReasonEventDBUntrustable|
14:49:37 backupd: Node requires deep traversal:/Volumes/Old Applications reason:kFSEDBEventFlagMustScanSubDirs|kFSEDBEventFlagReasonEventDBUntrustable|
14:50:05 backupd: Node requires deep traversal:/Volumes/Musik reason:kFSEDBEventFlagMustScanSubDirs|kFSEDBEventFlagReasonEventDBUntrustable|
14:50:18 backupd: Node requires deep traversal:/Volumes/Applications reason:kFSEDBEventFlagMustScanSubDirs|kFSEDBEventFlagReasonEventDBUntrustable|
14:51:23 backupd: Node requires deep traversal:/Volumes/Tiger reason:kFSEDBEventFlagMustScanSubDirs|kFSEDBEventFlagReasonEventDBUntrustable|
15:00:08 backupd: Node requires deep traversal:/Volumes/Free reason:kFSEDBEventFlagMustScanSubDirs|kFSEDBEventFlagReasonEventDBUntrustable|
15:00:08 backupd: Node requires deep traversal:/Volumes/Unix reason:kFSEDBEventFlagMustScanSubDirs|kFSEDBEventFlagReasonEventDBUntrustable|
ugh ugh, kFSEDBEventFlagReasonEventDBUntrustable means 25 minutes of scanning.
15:00:13 backupd: Starting pre-backup thinning: 72.73 GB requested (including padding), 52.98 GB available
So the disk is pretty full, and more space is needed. So obviously some
older backups should be deleted..
15:07:22 backupd: Deleted backup /Volumes/Backup of
Aden/Backups.backupdb/Aden/2008-05-21-004709: 53.05 GB now available
It deleted one and it found out it's still not enough.
Should delete another one...
15:07:22 backupd: Stopping backup.
No! Wait!
15:07:28 backupd: Backup canceled.
OMG.
15:07:34 backupd: Ejected Time Machine disk image.
15:07:34 backupd: Compacting backup disk image to recover free space
15:08:10 backupd: Completed backup disk image compaction
15:08:10 backupd: Starting standard backup
15:08:10 backupd: Network volume mounted at: /Volumes/Time Capsule
15:08:13 backupd: Disk image /Volumes/Time Capsule/Aden_000d932edfde.sparsebundle mounted at: /Volumes/Backup of Aden
15:08:13 backupd: Backing up to: /Volumes/Backup of Aden/Backups.backupdb
15:08:13 backupd: Querying receipt database for system packages
15:08:15 backupd: Using system path cache.
15:08:23 backupd: Event store UUIDs don't match for volume: Leopard
15:08:23 backupd: Event store UUIDs don't match for volume: Source
15:08:23 backupd: Event store UUIDs don't match for volume: Installer
15:08:23 backupd: Event store UUIDs don't match for volume: Users
15:08:23 backupd: Event store UUIDs don't match for volume: Old Applications
15:08:23 backupd: Event store UUIDs don't match for volume: Musik
15:08:23 backupd: Event store UUIDs don't match for volume: Applications
15:08:23 backupd: Event store UUIDs don't match for volume: Tiger
15:08:23 backupd: Event store UUIDs don't match for volume: Free
15:08:23 backupd: Event store UUIDs don't match for volume: Unix
Oh noes, it figures out how much space it needs again ?
15:08:23 backupd: Node requires deep traversal:/ reason:kFSEDBEventFlagMustScanSubDirs|kFSEDBEventFlagReasonEventDBUntrustable|
15:17:34 backupd: Node requires deep traversal:/Volumes/Source reason:kFSEDBEventFlagMustScanSubDirs|kFSEDBEventFlagReasonEventDBUntrustable|
15:24:52 backupd: Node requires deep traversal:/Volumes/Installer reason:kFSEDBEventFlagMustScanSubDirs|kFSEDBEventFlagReasonEventDBUntrustable|
15:25:04 backupd: Node requires deep traversal:/Volumes/Users reason:kFSEDBEventFlagMustScanSubDirs|kFSEDBEventFlagReasonEventDBUntrustable|
15:31:35 backupd: Node requires deep traversal:/Volumes/Old Applications reason:kFSEDBEventFlagMustScanSubDirs|kFSEDBEventFlagReasonEventDBUntrustable|
15:32:03 backupd: Node requires deep traversal:/Volumes/Musik reason:kFSEDBEventFlagMustScanSubDirs|kFSEDBEventFlagReasonEventDBUntrustable|
15:32:16 backupd: Node requires deep traversal:/Volumes/Applications reason:kFSEDBEventFlagMustScanSubDirs|kFSEDBEventFlagReasonEventDBUntrustable|
15:33:25 backupd: Node requires deep traversal:/Volumes/Tiger reason:kFSEDBEventFlagMustScanSubDirs|kFSEDBEventFlagReasonEventDBUntrustable|
15:42:06 backupd: Node requires deep traversal:/Volumes/Free reason:kFSEDBEventFlagMustScanSubDirs|kFSEDBEventFlagReasonEventDBUntrustable|
15:42:06 backupd: Node requires deep traversal:/Volumes/Unix reason:kFSEDBEventFlagMustScanSubDirs|kFSEDBEventFlagReasonEventDBUntrustable|
Here we go again. (Removing a lot of output further on)
15:42:11 backupd: Starting pre-backup thinning: 72.73 GB requested (including padding), 53.05 GB available
15:50:21 backupd: Deleted backup /Volumes/Backup of
Aden/Backups.backupdb/Aden/2008-05-20-003027: 53.27 GB now available
15:50:21 backupd: Stopping backup.
15:50:27 backupd: Backup canceled.
15:50:33 backupd: Ejected Time Machine disk image.
15:50:33 backupd: Compacting backup disk image to recover free space
15:51:12 backupd: Completed backup disk image compaction
15:51:12 backupd: Starting standard backup
15:51:12 backupd: Network volume mounted at: /Volumes/Time Capsule
15:51:15 backupd: Disk image /Volumes/Time Capsule/Aden_000d932edfde.sparsebundle mounted at: /Volumes/Backup of Aden
15:51:15 backupd: Backing up to: /Volumes/Backup of Aden/Backups.backupdb
15:51:26 backupd: Node requires deep traversal:/ reason:kFSEDBEventFlagMustScanSubDirs|kFSEDBEventFlagReasonEventDBUntrustable|
16:25:04 backupd: Node requires deep traversal:/Volumes/Unix reason:kFSEDBEventFlagMustScanSubDirs|kFSEDBEventFlagReasonEventDBUntrustable|
16:25:09 backupd: Starting pre-backup thinning: 72.73 GB requested (including padding), 53.27 GB available
16:31:25 backupd: Deleted backup /Volumes/Backup of
Aden/Backups.backupdb/Aden/2008-05-19-004747: 53.47 GB now available
16:31:25 backupd: Stopping backup.
16:31:30 backupd: Backup canceled.
16:31:36 backupd: Ejected Time Machine disk image.
16:31:36 backupd: Compacting backup disk image to recover free space
16:32:15 backupd: Completed backup disk image compaction
16:32:15 backupd: Starting standard backup
16:32:15 backupd: Network volume mounted at: /Volumes/Time Capsule
16:32:17 backupd: Disk image /Volumes/Time Capsule/Aden_000d932edfde.sparsebundle mounted at: /Volumes/Backup of Aden
16:32:17 backupd: Backing up to: /Volumes/Backup of Aden/Backups.backupdb
16:32:27 backupd: Node requires deep traversal:/ reason:kFSEDBEventFlagMustScanSubDirs|kFSEDBEventFlagReasonEventDBUntrustable|
17:06:10 backupd: Node requires deep traversal:/Volumes/Unix reason:kFSEDBEventFlagMustScanSubDirs|kFSEDBEventFlagReasonEventDBUntrustable|
17:06:15 backupd: Starting pre-backup thinning: 72.73 GB requested (including padding), 53.47 GB available
17:14:00 backupd: Deleted backup /Volumes/Backup of
Aden/Backups.backupdb/Aden/2008-05-18-014306: 53.54 GB now available
Two hours later, 0.5 GB have been recovered of the needed 20GB.
So I'd expect only 4 days more to go...
17:14:00 backupd: Stopping backup.
17:14:06 backupd: Backup canceled.
17:14:13 backupd: Ejected Time Machine disk image.
17:14:13 backupd: Compacting backup disk image to recover free space
17:14:52 backupd: Completed backup disk image compaction
17:14:52 backupd: Starting standard backup
17:14:52 backupd: Network volume mounted at: /Volumes/Time Capsule
17:14:55 backupd: Disk image /Volumes/Time Capsule/Aden_000d932edfde.sparsebundle mounted at: /Volumes/Backup of Aden
17:14:55 backupd: Backing up to: /Volumes/Backup of Aden/Backups.backupdb
17:15:04 backupd: Node requires deep traversal:/ reason:kFSEDBEventFlagMustScanSubDirs|kFSEDBEventFlagReasonEventDBUntrustable|
17:49:00 backupd: Node requires deep traversal:/Volumes/Unix reason:kFSEDBEventFlagMustScanSubDirs|kFSEDBEventFlagReasonEventDBUntrustable|
17:49:05 backupd: Starting pre-backup thinning: 72.73 GB requested (including padding), 53.54 GB available
17:55:13 backupd: Deleted backup /Volumes/Backup of
Aden/Backups.backupdb/Aden/2008-05-30-001331: 53.60 GB now available
17:55:13 backupd: Stopping backup.
17:55:19 backupd: Backup canceled.
17:55:25 backupd: Ejected Time Machine disk image.
17:55:25 backupd: Compacting backup disk image to recover free space
17:56:06 backupd: Completed backup disk image compaction
17:56:06 backupd: Starting standard backup
17:56:06 backupd: Network volume mounted at: /Volumes/Time Capsule
17:56:09 backupd: Disk image /Volumes/Time Capsule/Aden_000d932edfde.sparsebundle mounted at: /Volumes/Backup of Aden
17:56:09 backupd: Backing up to: /Volumes/Backup of Aden/Backups.backupdb
17:56:18 backupd: Node requires deep traversal:/ reason:kFSEDBEventFlagMustScanSubDirs|kFSEDBEventFlagReasonEventDBUntrustable|
(Removing even more output further on)
18:30:08 backupd: Starting pre-backup thinning: 72.73 GB requested (including padding), 53.60 GB available
18:38:20 backupd: Deleted backup /Volumes/Backup of
Aden/Backups.backupdb/Aden/2008-05-29-021844: 53.67 GB now available
19:13:07 backupd: Starting pre-backup thinning: 72.73 GB requested (including padding), 53.67 GB available
19:15:46 backupd: Deleted backup /Volumes/Backup of
Aden/Backups.backupdb/Aden/2008-05-28-010002: 53.73 GB now available
19:23:19 backupd: Deleted backup /Volumes/Backup of
Aden/Backups.backupdb/Aden/2008-05-27-221015: 53.79 GB now available
wohoo, deleted two!
19:58:16 backupd: Starting pre-backup thinning: 72.73 GB requested (including padding), 53.79 GB available
20:00:06 backupd: Deleted backup /Volumes/Backup of
Aden/Backups.backupdb/Aden/2008-06-11-142433: 53.83 GB now available
20:00:52 backupd: Deleted backup /Volumes/Backup of
Aden/Backups.backupdb/Aden/2008-06-11-130026: 53.85 GB now available
20:00:52 backupd: Removed all 2 expired backups, more space is needed - deleting oldest backups to make room
20:06:26 backupd: Deleted backup /Volumes/Backup of
Aden/Backups.backupdb/Aden/2008-03-25-000709: 54.24 GB now available
20:06:26 backupd: Deleted 3 backups: oldest backup is now 01.04.2008
20:41:38 backupd: Starting pre-backup thinning: 72.73 GB requested (including padding), 54.24 GB available
20:41:38 backupd: No expired backups exist - deleting oldest backups to make room
20:46:05 backupd: Deleted backup /Volumes/Backup of
Aden/Backups.backupdb/Aden/2008-04-01-015143: 54.52 GB now available
20:49:50 backupd: Deleted backup /Volumes/Backup of
Aden/Backups.backupdb/Aden/2008-04-08-003544: 54.78 GB now available
20:49:50 backupd: Deleted 2 backups: oldest backup is now 23.04.2008
21:24:38 backupd: Starting pre-backup thinning: 72.73 GB requested (including padding), 54.78 GB available
21:24:38 backupd: No expired backups exist - deleting oldest backups to make room
23:23:02 backupd: Deleted backup /Volumes/Backup of
Aden/Backups.backupdb/Aden/2008-04-23-120205: 56.29 GB now available
23:23:02 backupd: Deleted 1 backups: oldest backup is now 30.04.2008
...
ad nauseam