Become a MacRumors Supporter for $50/year with no ads, ability to filter front page stories, and private forums.

fearlessfool

macrumors newbie
Original poster
My TimeMachine backups are going VERY slowly, but NOT because of the reasons I've generally seen in the forums (i.e. anti-virus and Spotlight). In my case, it appears that TimeMachine is copying over 100,000 files every time it runs, even when there have been no changes.

FWIW, I'm backing up to a ReadyNAS RAID-5 array over 802.11g, but I have three other Macs that also use the ReadyNAS and 11g for TimeMachine backups, and they each finish in a matter of minutes. So that's not the source of slowness.

Here are logs from two successive TimeMachine backups done in the early morning (i.e. when very few files were changed):

Code:
07/07/2009 05:03:02 kernel AFP_VFS afpfs_mount: /Volumes/ReadyNAS, pid 1566 
07/07/2009 05:03:02 backupd[1561] Mounted network destination using URL: afp://ReadyNAS@chimborazo.local/ReadyNAS 
07/07/2009 05:03:02 backupd[1561] Backup destination mounted at path: /Volumes/ReadyNAS 
07/07/2009 05:03:09 backupd[1561] Disk image /Volumes/ReadyNAS/poorbook15_00112435ac80.sparsebundle mounted at: /Volumes/Backup of poorbook15 
07/07/2009 05:03:09 backupd[1561] Backing up to: /Volumes/Backup of poorbook15/Backups.backupdb 
07/07/2009 05:07:06 backupd[1561] No pre-backup thinning needed: 1.11 GB requested (including padding), 760.49 GB available 
07/07/2009 05:25:04 backupd[1561] Copied 70050 files (27.7 MB) from volume Macintosh HD. 
07/07/2009 05:27:18 backupd[1561] No pre-backup thinning needed: 1.10 GB requested (including padding), 760.49 GB available 
07/07/2009 05:40:53 backupd[1561] Copied 72015 files (23.5 MB) from volume Macintosh HD. 
07/07/2009 05:49:06 backupd[1561] Starting post-backup thinning 
07/07/2009 05:49:06 backupd[1561] No post-back up thinning needed: no expired backups exist 
07/07/2009 05:49:09 backupd[1561] Backup completed successfully. 
07/07/2009 05:49:12 backupd[1561] Ejected Time Machine disk image. 
07/07/2009 05:49:13 kernel AFP_VFS afpfs_unmount: /Volumes/ReadyNAS, flags 0, pid 1626

And one hour later:
Code:
07/07/2009 06:50:43 kernel AFP_VFS afpfs_mount: /Volumes/ReadyNAS, pid 1684 
07/07/2009 06:50:43 backupd[1683] Mounted network destination using URL: afp://ReadyNAS@chimborazo.local/ReadyNAS 
07/07/2009 06:50:43 backupd[1683] Backup destination mounted at path: /Volumes/ReadyNAS 
07/07/2009 06:50:49 backupd[1683] Disk image /Volumes/ReadyNAS/poorbook15_00112435ac80.sparsebundle mounted at: /Volumes/Backup of poorbook15 
07/07/2009 06:50:49 backupd[1683] Backing up to: /Volumes/Backup of poorbook15/Backups.backupdb 
07/07/2009 06:52:56 backupd[1683] No pre-backup thinning needed: 1.10 GB requested (including padding), 760.49 GB available 
07/07/2009 07:04:47 backupd[1683] Copied 68493 files (23.7 MB) from volume Macintosh HD. 
07/07/2009 07:06:22 backupd[1683] No pre-backup thinning needed: 1.10 GB requested (including padding), 760.49 GB available 
07/07/2009 07:17:00 backupd[1683] Copied 55374 files (23.4 MB) from volume Macintosh HD. 
07/07/2009 07:23:57 backupd[1683] Starting post-backup thinning 
07/07/2009 07:23:57 backupd[1683] No post-back up thinning needed: no expired backups exist 
07/07/2009 07:24:01 backupd[1683] Backup completed successfully. 
07/07/2009 07:24:04 backupd[1683] Ejected Time Machine disk image. 
07/07/2009 07:24:04 kernel AFP_VFS afpfs_unmount: /Volumes/ReadyNAS, flags 0, pid 1734

Note that each backup of PoorBook required 35-45 minutes to complete. (My other Leopard machines complete within minutes). In both cases, TimeMachine copied tens of thousands of files even though PoorBook had been sitting idle.

So:
  • Has anyone seen this behavior before?
  • Any ideas of what's causing it?
  • Any concrete suggestions on how to fix it?

Thanks in advance.

- ff
 
Register on MacRumors! This sidebar will go away, and you'll see fewer ads.