MacOS – Mavericks Time Machine is stuck in the middle of backing up, other times stop unexpectedly

macosnastime-machine

After upgrade to Mavericks I fail to complete a single backup with Time Machine. Tried it both for third-party NAS (QNAP TS-210) having a Time Machine service, and for a simple external HDD enclosure (Mac OS Extended Journalled format).

Some attempts to backup just stop itself long before the estimated time, with no result or error message; with no backup actually completed.

Others just stuck in the middle of copying (not Preparing, but in MBs backed up progress bar) for several hours without anything that could look like activity in progress.

Mavericks 10.9.2; QNAP firmware 4.0.3; Macbook Air Mid-2011.

Other Mac (MBP 2010, Mountain Lion) backs up to the same NAS just fine.

For external HDD, console is full of messages like this:

03-05-14 20:18:49,000 kernel[0]: memorystatus_thread: idle exiting pid 6522 [backupd-helper]
03-05-14 20:18:49,549 com.apple.launchd[1]: (com.apple.backupd-auto[6522]) Idle-exit job was jettisoned. Will bypass throttle interval for next on-demand launch.
03-05-14 20:18:49,550 com.apple.launchd[1]: (com.apple.backupd-auto[6522]) assertion failed: 13C1021: launchd + 43413 [425516B6-9F3E-342F-87B3-EC461EBA6A1A]: 0x9

For NAS, I didn't find anything relevant in Console for hours since the progress got stuck.

Update: For USB-attached external HDD, putting Mac to sleep and back helped to resume the copying–and helped to complete first backup.

Update: For NAS, the following lines appeared in Console just before a backup stopped itself prematurely–happened every time, several times:

04-05-14 16:03:24,545 com.apple.backupd[16637]: Error writing to backup log.  NSFileHandleOperationException:*** -[NSConcreteFileHandle writeData:]: Input/output error
04-05-14 16:03:24,645 com.apple.backupd[16637]: Error writing to backup log.  NSFileHandleOperationException:*** -[NSConcreteFileHandle writeData:]: Input/output error
04-05-14 16:03:24,647 com.apple.backupd[16637]: Error writing to backup log.  NSFileHandleOperationException:*** -[NSConcreteFileHandle writeData:]: Input/output error
04-05-14 16:03:24,648 com.apple.backupd[16637]: Error writing to backup log.  NSFileHandleOperationException:*** -[NSConcreteFileHandle writeData:]: Input/output error
04-05-14 16:03:24,697 com.apple.backupd[16637]: Error writing to backup log.  NSFileHandleOperationException:*** -[NSConcreteFileHandle writeData:]: Input/output error
04-05-14 16:03:24,699 com.apple.backupd[16637]: Error writing to backup log.  NSFileHandleOperationException:*** -[NSConcreteFileHandle writeData:]: Input/output error
04-05-14 16:03:24,701 com.apple.backupd[16637]: Error writing to backup log.  NSFileHandleOperationException:*** -[NSConcreteFileHandle writeData:]: Input/output error
04-05-14 16:03:25,169 com.apple.backupd[16637]: Backup canceled.

After that, upon clicking "Backup Now" in Time Machine, the total amount of files to back up seem to become smaller by the amount reached previous time.

Update: Installed QFix hoping to fix the "I/O error", per some reports of success on QNAP forums. Got stuck "Preparing to backup…" which lasts at least an hour, with no messages in Console, and no network and disk activity per Activity Monitor–the same in several attempts tried. "Preparing…" problem solved with a simple OS X reboot. With QFix installed, backup became much faster. I/O error still happened twice, but at least no more stuck in the middle of backing up (since QFix, done full backup from the scratch: 27GB).

Best Answer

To summarize how I worked around the problem:

  • made sure the problem only exists for Mavericks: made sure that another Mac (pre-Mavericks) still backs up to QNAP NAS seamlessly
  • made sure that problem is only related to QNAP NAS and Mavericks together, not to Mavericks alone. For this, performed back up to external HDD
    • when external HDD backup got stuck with progress bar frozen, Standby-Resume of Mac helped to "unfreeze" Time Machine most of the time
  • to achieve first successful backup with NAS, I first excluded every folder that is on "Macintosh HD": Time Machine Preferences > Options > Exclude these from backups > +. Having minimal successful backup, I added folder by folder, from smallest ones (all <1MB, then all <1GB, then one by one more and more large, largest in the end.
    • when backup stopped itself long before the estimated time, it turned out that it actually copied the part last displayed on progress bar. The next time you invoke Back Up Now, the total amount of files to back up becomes smaller by the amount reached previous time.
  • for QNAP NAS, installed QFix (reboot OS X before invoking new backups). QFix seriously improved copying speed and made the speed consistent, plus resolved "frozen progress" problem at least for a full backup from the scratch.

Still, the problems left for Apple and QNAP to solve are:

  • progress bar which frequently gets frozen in the middle of copying
  • stuck "Preparing backup..." after QFix before OS X reboot
  • backing up stopping itself in the middle of copying, and/or "I/O error" which forces backup progress to stop
Related Question