Update 5/20/13.--After it started its 3 hour backup for the 4th time in a day I shut the backup off and erased the TC's HD. It's been off and will be off for awhile. I have overnight backups running on all 4 HD's in the Mac, a clone of the HD and a sync of the HD users folder, so I'm not losing anything.
The TC was only used for stuff during the day and running 3 hours when it went beserk impact the rest of the system. The TC is 5 years old so it's hard to know if the problem is the backup or the HD. The only tools to debug or test the HD is with Apple if you bring it to them. They haven't released their tools or has anyone developed them.
The other problem is that even when the backup erases the old 50+ GByte backup it doesn't reclaim the space on the HD. It seem to just keep it flagged as used but not available, so the free space keeps getting reduced by these 50+ GByte backups, which I assume it eventually uses when the HD gets full and it needs the space. In the meantime half the HD is taken with these useless large backups.
Original Post.--This is what happens with the Time Machine and backup:
5/16/13 3:05:18.401 AM com.apple.backupd: Using file event preflight for Mac HD
5/16/13 3:05:24.388 AM com.apple.backupd: Will copy (1.8 MB) from Mac HD
5/16/13 3:05:24.392 AM com.apple.backupd: Found 123 files (1.8 MB) needing backup
5/16/13 3:05:24.413 AM com.apple.backupd: 3.15 GB required (including padding), 351.51 GB available
5/16/13 3:20:31.116 AM com.apple.backupd: Copied 2091 files (19.2 MB) from volume Mac HD.
5/16/13 3:20:32.499 AM com.apple.backupd: Using file event preflight for Mac HD
5/16/13 3:20:44.024 AM com.apple.backupd: Will copy (1.1 MB) from Mac HD
5/16/13 3:20:44.165 AM com.apple.backupd: Found 71 files (1.1 MB) needing backup
5/16/13 3:20:44.166 AM com.apple.backupd: 3.28 GB required (including padding), 351.41 GB available
5/16/13 4:20:50.927 AM com.apple.backupd: Copied 17.92 GB of 17.92 GB, 79237 of 79237 items
5/16/13 5:21:32.178 AM com.apple.backupd: Copied 32.93 GB of 32.93 GB, 150792 of 150792 items
5/16/13 6:21:48.303 AM com.apple.backupd: Copied 50.43 GB of 50.43 GB, 490465 of 490465 items
5/16/13 6:28:41.303 AM com.apple.backupd: Copied 596836 files (51.62 GB) from volume Mac HD.
5/16/13 6:28:45.282 AM com.apple.backupd: Created new backup: 2013-05-16-062843
As you can see the backup starts normally but then decides to backup 50+ GBytes of files and at 3-5 am there's nothing happening besides the normal Apple stuff. I have daily backups at 11 pm, 1 am, 3 am and 5am but they only copy and don't interfer with the backup on many days.
This is a puzzler which defies logic to determine the problem since erasing the TC on April 16th, it's happened seven times, with the start time of the backup:
April 17th 5 pm
April 18th 2 pm
April 22nd 5 pm
April 26th 1 pm
May 5th 7 pm
May 6th 1 pm
May 16 3 am
May 16 9 am
May 16 5 pm
May 17 1 pm
Anyway, that's 460+ GBytes for what I don't know. This time I plan to let the TC run out of space where the backup has to erase backups first to see what happens. Normally I stop the backup and erase the TC when it gets below 100 GBytes free space.