"Hold if no archive" fails to capture

My scheduled backups of my MacBook Pro are set to "hold if no archive" so that they will run automatically when the backup disk becomes available. That's been working fine, but recently it's begun behaving strangely. The Activity Monitor shows the backup as waiting for the archive, but then when the archive is mounted the backup starts and then immediately stops, with nothing captured. The log shows a cancel request at the time the archive was mounted. If I then manually trigger the backup, it runs normally.

I've been noticing this for a couple of weeks -- starting before the most recent beta update. Here's a log sequence showing what happens. The backup was scheduled for 03:00 but that that time the lid was closed and the archive was not mounted. I opened the lid at 09:21, at which time Qrecall began to wait, then mounted the archive at 12:11. Something triggered a cancel request and the capture stopped,. I then initiated it manually and it ran fine.

Action 2011-11-10 12:11:04 ------- Capture to 2nd backup.quanta
Action 2011-11-10 09:21:33 Minutia Waiting for archive
Action 2011-11-10 12:11:04 Minutia Received cancel request
Action 2011-11-10 12:11:04 archive: /Volumes/FantomHD/2nd backup.quanta
Action 2011-11-10 12:11:04 Capture Stopped
Action 2011-11-10 12:11:04 The layer created by this capture is incomplete and may be missing items. Use caution when recalling items in this layer.
Action 2011-11-10 12:11:04 ------- Capture finished (00:00)
Action 2011-11-10 12:12:49 ------- Capture to 2nd backup.quanta
Action 2011-11-10 12:12:49 archive: /Volumes/FantomHD/2nd backup.quanta
Action 2011-11-10 12:13:10 Capture Users
Action 2011-11-10 12:13:10 mbhd:Users
Action 2011-11-10 12:13:20 Minutia Locating changes since Tuesday, November 8, 2011 8:02 AM
Action 2011-11-10 12:29:10 Captured 45 items, 1.04 GB (28% duplicate)
Action 2011-11-10 12:29:58 ------- Capture finished (16:54)

Also, the activity monitor doesn't accurately reflect what's going on. Right now mine shows that it's waiting for the next scheduled backup, while I'm in the middle of compacting layers. The log correctly show the compaction as in progress.

Ralph

Ralph Strauch wrote:The Activity Monitor shows the backup as waiting for the archive, but then when the archive is mounted the backup starts and then immediately stops, with nothing captured. The log shows a cancel request at the time the archive was mounted. If I then manually trigger the backup, it runs normally.

Well, that's certainly strange. Start by sending a diagnostic report, as there are additional details about who sent the cancel request and why which don't show up in the regular log window.

Also, the activity monitor doesn't accurately reflect what's going on. Right now mine shows that it's waiting for the next scheduled backup, while I'm in the middle of compacting layers. The log correctly show the compaction as in progress.

This is a known problem. In Lion, the activity monitor process sometimes fails to see when an action starts and thus doesn't monitor it. I've narrow this down to a specific notification message that isn't being delivered, but I don't know yet whether this is a bug in Lion or QRecall.

Whoops!! Operator error!!! Looking at my log more carefully in order to clarify the report I was sending, I see that the "mysterious" cancelation requests that stopped my scheduled backups were caused by low free space warnings. When I manually restarted the warning wasn't active so the backup went ahead and ran. I apologize for wasting your time with my inattention to detail.

Ralph

Ralph,

Please send a diagnostic report anyway. I'm still interested in gathering more information about why the activity window is sometime not monitoring actions.

In fact, if anyone has encountered this issue in the last week, please send a diagnostic report (Help > Send Report...).