When I started my backup, the amount to be backed was indicated as 25GB. Everything was fine until the progress reached approx. 22GB. Then the amount to back up started growing. I killed the backup after it reached 48GB. I've observed this behavior with 2 separate hard drives (different brands and interfaces (USB 2.0, FW800) too boot).
MacBookPro 2.6 Intel Core i7, 8GB, v10.8.3
If you have more than one user account, these instructions must be carried out as an administrator.
Launch the Console application in any of the following ways:
☞ Enter the first few letters of its name into a Spotlight search. Select it in the results (it should be at the top.)
☞ In the Finder, select Go ▹ Utilities from the menu bar, or press the key combination shift-command-U. The application is in the folder that opens.
☞ Open LaunchPad. Click Utilities, then Console in the icon grid.
Make sure the title of the Console window is All Messages. If it isn't, select All Messages from the SYSTEM LOG QUERIES menu on the left. If you don't see that menu, select
View ▹ Show Log List
from the menu bar.
Enter the word "Starting" (without the quotes) in the String Matching text field. You should now see log messages with the words "Starting * backup," where * represents any of the words "automatic," "manual," or "standard." Note the timestamp of the last such message. Clear the text field and scroll back in the log to that time. Select the messages timestamped from then until the end of the backup, or the end of the log if that's not clear. Copy them (command-C) to the Clipboard. Paste (command-V) into a reply to this message.
If all you see are messages that contain the word "Starting," you didn't clear the search box.
If there are runs of repeated messages, post only one example of each. Don't post many repetitions of the same message.
When posting a log extract, be selective. Don't post more than is requested.
Please do not indiscriminately dump thousands of lines from the log into this discussion.
Some personal information, such as the names of your files, may be included — anonymize before posting.
You gave the same suggestion to my question :
Are Time Machine, Mountain Lion and Retina able to work together?
I'm sorry to report that your suggestion to search 'starting' on the console brings at most one line (instead of thousands!). Furthermore, it does not seem connected to time capsule
See details there.
😟
Time Machine performs a number of different operations during a backup which contribute to its estimates.
If you are not seeing an error message or some other dialog asking you to do something, it is best to allow TM to complete its backup.
Lots of good info here.
I've added annotations prefixed by "###"
5/31/13 6:25:49.539 PM com.apple.backupd[418]: Starting manual backup
5/31/13 6:25:50.024 PM com.apple.backupd[418]: Backing up to: /Volumes/SamsungHD/Backups.backupdb
5/31/13 6:25:52.096 PM com.apple.backupd[418]: Using file event preflight for Macintosh HD
5/31/13 6:25:56.445 PM com.apple.backupd[418]: Will copy (22.08 GB) from Macintosh HD
5/31/13 6:25:56.562 PM com.apple.backupd[418]: Found 11041 files (22.9 GB) needing backup
### Note the initial estimate
5/31/13 6:25:56.566 PM com.apple.backupd[418]: 28.16 GB required (including padding), 393 GB available
### I noticed that the actual amount backed up has nearly doubled, so I canceled it.
5/31/13 6:37:33.199 PM com.apple.backupd[418]: Copied 18033 files (44 GB) from volume Macintosh HD.
5/31/13 6:37:33.887 PM com.apple.backupd[418]: Backup canceled.
### I resumed the backup again...
5/31/13 6:38:27.991 PM com.apple.backupd[418]: Starting manual backup
5/31/13 6:38:28.237 PM com.apple.backupd[418]: Backup failed with error: 19
5/31/13 6:38:28.237 PM com.apple.backupd[418]: Starting manual backup
5/31/13 6:38:28.243 PM com.apple.backupd[418]: Backing up to: /Volumes/SamsungHD/Backups.backupdb
5/31/13 6:38:30.627 PM com.apple.backupd[418]: Using file event preflight for Macintosh HD
5/31/13 6:38:35.973 PM com.apple.backupd[418]: Will copy (6.1 MB) from Macintosh HD
### Again note the estimate...
5/31/13 6:38:36.184 PM com.apple.backupd[418]: Found 6511 files (644.1 MB) needing backup
5/31/13 6:38:36.187 PM com.apple.backupd[418]: 1.49 GB required (including padding), 370.4 GB available
### And I killed it again after it went over.
5/31/13 6:39:40.914 PM com.apple.backupd[418]: Copied 17656 files (2.83 GB) from volume Macintosh HD.
5/31/13 6:39:41.282 PM com.apple.backupd[418]: Backup canceled.
I've used time machine on my macs for well over 5 years and I've never seen this behavior. And my backup regime is every week (religiously observed) onto 2 drives, so I've done a lot of time travel if you will.
Furthermore, the suggestion on the website you linked to, that Spotlight just happened to be running and therefore the extra data was coming from its indexes increasing, doesn't add up to me.
My harddrive capacity is 750GB, of which 386GB is used (mostly binary and presumable un-indexable to begin with).
Spotlight generating 20+GB of index during such a short timespan is very problematic as it would mean Spotlight is pointlessly indexing binary data.
I really think it was a bug with the operating system and/or a corrupt file system.
I suggest you do two things. First, if you haven't already done so, start a new backup on another external storage device. You should do that anyway, as one backup isn't enough to be safe.
Rebuild the Spotlight index on the source volume(s) by following these instructions:
Just wondering what would happen if you allow the backup to finish.
Any error messages or alerts?
I did allow the backups (on 2 external hard drives) to finish, here are the logs:
6/1/13 1:19:57.048 PM com.apple.backupd[1257]: Starting manual backup
6/1/13 1:19:57.691 PM com.apple.backupd[1257]: Backing up to: /Volumes/MyBook/Backups.backupdb
6/1/13 1:20:01.359 PM com.apple.backupd[1257]: Using file event preflight for Macintosh HD
6/1/13 1:20:09.138 PM com.apple.backupd[1257]: Will copy (21.3 MB) from Macintosh HD
6/1/13 1:20:15.971 PM com.apple.backupd[1257]: Found 6662 files (659.3 MB) needing backup
6/1/13 1:20:15.996 PM com.apple.backupd[1257]: 1.34 GB required (including padding), 291.24 GB available
6/1/13 1:33:13.927 PM com.apple.backupd[1257]: Copied 17813 files (23.48 GB) from volume Macintosh HD.
6/1/13 1:33:14.531 PM com.apple.backupd[1257]: Using file event preflight for Macintosh HD
6/1/13 1:33:15.022 PM com.apple.backupd[1257]: Will copy (317 KB) from Macintosh HD
6/1/13 1:33:15.024 PM com.apple.backupd[1257]: Found 25 files (317 KB) needing backup
6/1/13 1:33:15.025 PM com.apple.backupd[1257]: 580.2 MB required (including padding), 267.74 GB available
6/1/13 1:33:19.340 PM com.apple.backupd[1257]: Copied 247 files (165 bytes) from volume Macintosh HD.
6/1/13 1:33:20.101 PM com.apple.backupd[1257]: Created new backup: 2013-06-01-133319
6/1/13 1:33:53.365 PM com.apple.backupd[1257]: Starting post-backup thinning
6/1/13 1:33:53.365 PM com.apple.backupd[1257]: No post-back up thinning needed: no expired backups exist
6/1/13 1:33:53.421 PM com.apple.backupd[1257]: Backup completed successfully.
6/1/13 2:06:03.046 PM com.apple.backupd[1384]: Starting manual backup
6/1/13 2:06:03.631 PM com.apple.backupd[1384]: Backing up to: /Volumes/SamsungHD/Backups.backupdb
6/1/13 2:06:06.038 PM com.apple.backupd[1384]: Using file event preflight for Macintosh HD
6/1/13 2:06:14.411 PM com.apple.backupd[1384]: Will copy (21.1 MB) from Macintosh HD
6/1/13 2:06:14.633 PM com.apple.backupd[1384]: Found 6656 files (659.1 MB) needing backup
6/1/13 2:06:14.639 PM com.apple.backupd[1384]: 1.25 GB required (including padding), 370.63 GB available
6/1/13 2:12:14.822 PM com.apple.backupd[1384]: Copied 17813 files (23.48 GB) from volume Macintosh HD.
6/1/13 2:12:15.141 PM com.apple.backupd[1384]: Using file event preflight for Macintosh HD
6/1/13 2:12:15.757 PM com.apple.backupd[1384]: Will copy (271 KB) from Macintosh HD
6/1/13 2:12:15.759 PM com.apple.backupd[1384]: Found 37 files (271 KB) needing backup
6/1/13 2:12:15.777 PM com.apple.backupd[1384]: 455.6 MB required (including padding), 347.15 GB available
6/1/13 2:12:20.132 PM com.apple.backupd[1384]: Copied 377 files (18 KB) from volume Macintosh HD.
6/1/13 2:12:20.844 PM com.apple.backupd[1384]: Created new backup: 2013-06-01-141220
6/1/13 2:12:48.111 PM com.apple.backupd[1384]: Starting post-backup thinning
6/1/13 2:12:48.173 PM com.apple.backupd[1384]: Error: Error Domain=NSOSStatusErrorDomain Code=-50 "The operation couldn’t be completed. (OSStatus error -50.)" (paramErr: error in user parameter list) deleting backup: /Volumes/SamsungHD/Backups.backupdb/mbp-ml/2013-05-31-182550.inProgress/93C8195 B-F7AB-46A5-85D6-AEACE7DC1EF3
6/1/13 2:12:48.173 PM com.apple.backupd[1384]: No post-back up thinning needed: no expired backups exist
6/1/13 2:12:48.236 PM com.apple.backupd[1384]: Backup completed successfully.
Again you see the mismatch between what initially is expected to be backed up and what is backed up, which is significantly larger (23.48 GB). It turns out that I just happen to have a VirtualBox disk image that is 23.45GB. Presuming this file was the culprit, I have to wonder why the OS simply can't "see" that the image has changed and notify beforehand.
Anyways I guess this issue is closed. Just to be safe, I'm going to wipe one of the backup hard drives and perform a fresh time machine backup on it.
I don't use virtualization myself, but I understand it can be problematic with Time Machine.
One option of course is to exclude the VB image and back it up manually.
time machine bug (amount to back up grows)
