System shutting down (sometimes) after scheduled backup

[jjj]

This has happened only twice. The backup runs at 6:30 and takes about ten minutes. Both times, /var/log/system.log looks like this just before the log entries showing where I started the system again:

Oct  2 06:41:02 slynew diskarbitrationd[42]: applet [1513]:34843 not responding.
Oct  2 06:41:03 slynew kernel[0]: jnl: close: flushing the buffer cache (start 0x66a200 end 0x66c400)

I'm backing up to one of three partitions on a FireWire drive. I leave the mirror backup partition unmounted (with the other two mounted) after discovering that SuperDuper can mount and unmount that partition on its own.

I haven't actually witnessed the shutdown, and it doesn't happen every time the backup runs. I'm judging based on the logs and some circumstantial evidence (someone telling me he couldn't ping my system sometime just before 7:30) that the shutdown is happening right after the backup runs.

So I don't know that its connected to SuperDuper, but before calling Apple I thought I'd ask if anyone else has experienced this and/or if any of the above is illuminating.

[dnanian]

Basically, it looks like the drive must have failed or stopped responding properly. Very strange. Running any low-level utilities, antivirus, etc?

[jjj]

But would a failure to respond at the end of a backup make the system shut down (i.e. the whole Mac)?

In answer to your question, no antivirus or the like is running. The scheduled update seems to have run fine. And I've just noticed that the message "kernel[0]: jnl: close: flushing the buffer cache" is the same given when I unmount the mirror partition myself in Disk Utility (such as just after booting).

Speaking of which, is there any possibility that my preference for keeping that partition unmounted, and with other partitions remaining mounted, has anything to do with this?

[dnanian]

It could be indicative of a system-wide failure, yes... and that could be due to a misbehaving drive. No panic.log?

[jjj]

No panic.log, no panic screen ("You need to restart your computer," etc.). Just the next morning, my Mac ain't on.

I watched a scheduled backup this time. Everything seemed to work. This is the system.log:

Oct 10 06:30:16 slynew diskarbitrationd[42]: disk1s2    hfs      CBADEC29-3F8C-357E-8B45-7D072826D110 Mirror                  /Volumes/Mirror
Oct 10 06:30:33 slynew KernelEventAgent[35]: tid 00000000 received unknown event (256)
Oct 10 06:30:33 slynew KernelEventAgent[35]: tid 00000000 received unknown event (256)
Oct 10 06:40:55 slynew diskarbitrationd[42]: applet [591]:19411 not responding.
Oct 10 06:40:55 slynew kernel[0]: jnl: close: flushing the buffer cache (start 0x176200 end 0x178400)

The mirror partition did unmount (or at least it is unmounted after this), and the backup log shows no complaints.

I guess I'm just going to reschedule this during the day and keep watching it until something happens.

[dnanian]

OK. So, "applet" (which is likely our scheduling driver) has asked for the eject. It stops responding while we're waiting for the system to do it. It flushes the journal and then does eject. That seems reasonable without the shutdown, at least!