Is this spin down behaviour normal?

 

- drives are all spun down after reaching spin down delay

- /sbin/powerdown is executed late at night from "at" command in go script (echo "/sbin/powerdown" | at 01:30)

- use WOL to wakeup server in the morning

- server powers on, drives spin up, unRaid boots

- at the end of the boot process drives are spun down

 

I tried spinning the drives down manually using the button on the unRaid Menu and running /sbin/powerdown manually.

Woke up the server and the drives remained spun up.

 

Sounds strange but is there something in unRaid that says if the drives were spun down due to spin down timer and the server is turned off, then spin them down again after the boot process completes??

 

I have Clean Powerdown package installed.

syslog.txt

Normally the NTP subsystem disallows any time server indicating a time dramatically different than yours, making the assumption that the time server is probably wrong.  However when the NTP system is first called with the -g option, as unRAID does, then the very first time check with an external time server will allow the possibility that the local time is not accurate, and sync to that external NTP time server.  In your case, that is what happened.  An NTP server indicated that your local time, taking into account your time zone setting, was far off, by 14400 seconds, and therefore corrected it.  If I recall correctly, 14400 is an exact number of hours, probably 4, so I'm going to guess here, that you had recently updated your unRAID time zone setting.

 

Naturally when this happened, the spin down timers thought 4 hours had passed, and spun the drives down.  Plausible?

Thanks for the info.  I thought you were on to something there but I didn't make any changes to time zone.

I've attached another log from today.

 

This time I disabled spindown for the parity drive and let the server sleep as usual.

All drives spin down except parity and drive 1 which hadn't yet reached the spindown time:

 

May  2 00:43:10 Tower kernel: mdcmd (21): spindown 2 (Routine)

May  2 00:43:30 Tower kernel: mdcmd (22): spindown 4 (Routine)

May  2 00:43:51 Tower kernel: mdcmd (23): spindown 3 (Routine)

 

The last log entry before sleep occurs here:

 

May  2 01:23:43 Tower sshd[7102]: lastlog_filetype: Couldn't stat /var/log/lastlog: No such file or directory

May  2 01:23:43 Tower sshd[7102]: lastlog_openseek: /var/log/lastlog is not a file or directory!

May  2 07:00:16 Tower kernel: PM: Syncing filesystems ... done.

May  2 07:00:16 Tower kernel: Freezing user space processes ... (elapsed 0.00 seconds) done.

May  2 07:00:16 Tower kernel: Freezing remaining freezable tasks ... (elapsed 0.00 seconds) done

 

This morning the server is woken up:

 

May  2 07:00:16 Tower kernel: PM: Syncing filesystems ... done.

 

Soon after all drives except parity are spun down:

 

May  2 07:00:16 Tower kernel: Restarting tasks ... done.

May  2 07:00:16 Tower kernel: r8169: eth0: link down (Network)

May  2 07:00:16 Tower kernel: mdcmd (24): spindown 1 (Routine)

May  2 07:00:16 Tower ifplugd(eth0)[1292]: Link beat lost. (Network)

May  2 07:00:17 Tower kernel: mdcmd (25): spindown 2 (Routine)

May  2 07:00:17 Tower kernel: mdcmd (26): spindown 3 (Routine)

May  2 07:00:18 Tower kernel: mdcmd (27): spindown 4 (Routine)

May  2 07:00:19 Tower kernel: r8169: eth0: link up (Network)

May  2 07:00:20 Tower ifplugd(eth0)[1292]: Link beat detected. (Network)

 

Unless I'm missing some clue in the log it looks very much like the spin down check assumes the time has elapsed i.e. counts the time the server was asleep and spins any applicable drives down. 

Ideally that check should start from 0 again after waking up.

syslog-2011-05-02.txt

I'll certainly take your word for it, that no time zone adjustment was made.  What is odd though is that the adjustment in the first syslog was exactly 4 hours (4 hours X 60 minutes X 60 seconds = 14400 seconds).  The only other idea I have is that you perhaps had recently booted this machine with a Windows based OS.  As I understand, DOS and Windows store the current time in the hardware CMOS clock, where as Linux stores UTC time.  One stores current time and adjusts it back for UTC calcs, and the other stores UTC time and adjusts it forward for local time display.  If that's not it, then I've struck out!

 

The first syslog did not have a sleep transition in it, only the 4 hour adjustment.  The last syslog has an actual S3 sleep cycle displayed, which I have seen before, but still find somewhat unbelievable, that it actually seems to work!  I've seen much worse than your syslog, but I really think users who try this S3 sleep and wake feature should consider it a miracle that it actually works.  As far as I know, unRAID has NEVER had any development done relating to this!  The only reason it works is because the constant kernel upgrading by the fine kernel developers has added S3 sleep support, and a few unRAID users discovered on their own that it could be invoked and seemed to work!  So far, I've never heard of any major issues or data loss.  Which is somewhat surprising to me when I look at the corresponding syslog messages, lost of stops and starts and restarts and resets and errors.  I don't recall any comments from Tom about it, but it should probably be considered 'not officially supported'.

 

That explains why the spindown clocks are wrong.  unRAID does not even know the machine has been sleeping.  I suppose Tom could find a way to detect that it has happened and clear the timers.  Since a number of devices are being informed of the waking up, perhaps unraidd could be registered somewhere and be informed also.

 

By the way, something I found interesting, that's the first time I've seen a 6gbps SATA link up, shown in your syslog for the first drive.  I assume that is a negotiated speed, so therefore your onboard disk controller and your Seagate 2TB drive must both support 6gbps speeds.  The rest of the SATA links are at the usual 3gbps speed.

Nope never booted windows.  In fact the bios time is always in UTC when I check it.

I am frankly surprised that S3 sleep is working as well as it is.  The syslog entries after wake up do seem a bit scary and I am debating whether to just leave the server on with drives spun down and forget sleep altogether.

 

The only reason i started down this path is because I found that from a cold boot this ASUS M4A88TD-M USB3 motherboard will usually not boot off the USB stick.

I typically had to do one hard reset and then it would work.  No idea why.  The USB drive was found during POST but then it would just hang with a flashing cursor when it should be booting.  After waking from sleep though, no issues with the USB key.

 

Would be handy to make unRaid more aware of the sleep state.

 

Yes, the disk controller and Seagate drive support SATA 3.  Bit silly as it will never be used but I tend to over purchase