Past February I enabled disk spindown on my NV+ (4.1.13, with 4 disks). This works nicely, but now I noticed that since then the system clock is very inaccurate. The system runs ntpdate every 4 hours, and the only difference is that now it delays this command until the disks are running. Before, the log (daemon.log) showed:
Feb 25 04:00:01 rn601 ntpdate[15953]: step time server 192.168.100.8 offset 0.090846 sec Feb 25 06:25:17 rn601 ntpdate[16613]: step time server 192.168.100.8 offset 0.029300 sec Feb 25 08:00:01 rn601 ntpdate[16785]: step time server 192.168.100.8 offset 0.018366 sec Feb 25 12:00:02 rn601 ntpdate[17202]: step time server 192.168.100.8 offset 0.047373 sec
which is quite alright, but now it looks like:
Feb 25 18:00:24 rn601 ntpdate[3059]: step time server 192.168.100.8 offset 22.405220 sec Feb 25 20:30:46 rn601 ntpdate[3689]: step time server 192.168.100.8 offset 44.598847 sec Feb 26 04:12:06 rn601 ntpdate[5491]: step time server 192.168.100.8 offset 125.010078 sec
The less frequent ntpdate calls shouldn't make such a difference, but the clock is really bad. Looks like a consequence of the disk spindowns, maybe electrical, or temperature-related?
I am not seeing this behavior on my NV+ or my duo (both have spindown enabled). There are a couple of entries that reach 0.44 seconds, but the .0x range is what it usually is. Nothing in the 10s of seconds.
What drives are you using? I'm wondering how much power they draw during spinup.
Amazingly, since yesterday I find entries about disk spinup/down in the daemon.log; none such appeared before. The only change I can recall is the installation of the ssh addon and a reboot. Time error seems somewhat correlated with length of spindown:
Apr 19 11:11:04 rn601 noflushd[674]: Spinning down disks. Apr 19 14:00:06 rn601 noflushd[674]: Disks spinning up after 169 minutes. Apr 19 14:10:24 rn601 ntpdate[3890]: step time server 192.168.100.8 offset 22.299269 sec Apr 19 14:20:55 rn601 noflushd[674]: Spinning down disks. Apr 19 15:46:42 rn601 noflushd[674]: Disks spinning up after 85 minutes. Apr 19 16:00:23 rn601 ntpdate[4306]: step time server 192.168.100.8 offset 22.271407 sec Apr 19 16:07:06 rn601 noflushd[674]: Spinning down disks. Apr 19 19:04:45 rn601 noflushd[674]: Disks spinning up after 177 minutes. Apr 19 19:28:56 rn601 noflushd[674]: Spinning down disks. Apr 20 00:00:41 rn601 noflushd[674]: Disks spinning up after 271 minutes. Apr 20 00:10:47 rn601 ntpdate[6312]: step time server 192.168.100.8 offset 44.546045 sec Apr 20 02:25:18 rn601 noflushd[674]: Spinning down disks. Apr 20 02:25:29 rn601 noflushd[674]: Disks spinning up after 0 minutes. Apr 20 02:45:30 rn601 noflushd[674]: Spinning down disks. Apr 20 02:53:03 rn601 noflushd[674]: Disks spinning up after 7 minutes. Apr 20 03:13:29 rn601 noflushd[674]: Spinning down disks. Apr 20 04:00:12 rn601 noflushd[674]: Disks spinning up after 46 minutes. Apr 20 04:10:16 rn601 ntpdate[6969]: step time server 192.168.100.8 offset 14.924754 sec Apr 20 04:30:29 rn601 noflushd[674]: Spinning down disks. Apr 20 06:25:10 rn601 noflushd[674]: Disks spinning up after 114 minutes. Apr 20 06:34:51 rn601 ntpdate[7852]: step time server 192.168.100.8 offset 14.827573 sec Apr 20 07:07:32 rn601 noflushd[674]: Spinning down disks. Apr 20 10:20:17 rn601 noflushd[674]: Disks spinning up after 192 minutes. Apr 20 10:30:02 rn601 ntpdate[8828]: step time server 192.168.100.8 offset 0.046450 sec
Except the last one; but this is always like that when the reason for the spinup is me logging in with ssh. I thought about installing the ntpd addon and letting ntp run freely (without syncing the clock), so I could monitor the offset from outside, but the file NTP-Server_4.2.4pl7-readynas-0.9.0.bin that is mentionen in a couple of places is longer in the places where Google tells me it should be. Does anyone have a copy for me?
Correlation with the spindown period suggests that the clock is running slower when the disks are spun down. The longer the spindown, the more time it loses.
What hardware version is your NV+? It should be on the back label (v3 or some such). I can check mine as well - possibly mine is different, which might explain why I am not seeing it.
How much do you want spindown?
Perhaps one option is to contact Netgear support and buy a replacement PSU. That is speculative, but possibly might help.
From the posting, I was assuming the the NAS clock was correct after the NTP corrections.
rmaeder - are you using the default netgear ntp servers? If so, I suspect they are accurate, otherwise my systems (and others) would also be seeing these signs.
ntpdate says it stepped the clock xx seconds. I believe ntpdate is considered 'obsolete' in the community. A proper ntp daemon will check the ntp server's consistency before trusting it. ntpdate just steps the time. If the server is inaccurate, the clock will be inaccurately stepped every time ntpdate is run.
Thanks for all the helpful suggestions and questions. Here's some more info about this case, which narrows down the problem.
1. I use my own ntp server which is very accurate and closely monitored. No chance that it could be the cause. After the corrections the clock is indeed correct.
2. After I wrote my last post I left myself accidentally logged into the unit, and when I returned about 4 hours later I found the disks idle. An "ntpdate -q" showed to my surprise that the clock was still accurate! I then did something which caused the disks to spin up (which introduces a delay of about 10s), and after they were running, the clock was suddenly 14 s late. Within 10 minutes the delayed cron job adjusted it as usual.
So it looks like the clock loses between 14 and 22 s during the actual spin up, but runs normally otherwise. And if there are several spindown/up cycles before the next ntpdate, it loses several times that amount; this is also visible from the log file I posted. Could the timing system in the kernel be hanging during the spinup?
3. As for the h/w version, the back label doesn't have any "V" in it. The unit is from 2006, except for the power supply, which went up in smoke in 2009 (and took the UPS with it..).
EDIT: I analyzed another spindown while logged in. Immediately after spin up the clock was still ok, but then within a few minutes it suddenly jumps those 14 seconds. The syslog has an entry:
Apr 20 15:13:54 rn601 kernel: :40000002|1
which seems correlated with the spinup events. What does this mean?
If it is a kernel thing, it must be limited to specific models, since I am not seeing it. Mine is v3 hardware.
There is a small battery (CR2032) on the system board for the clock - likely it is dead on your system. Not sure if it is related, but if you want to try replacing it there is some info here on removing the battery (ftp://downloads.netgear.com/files/RESET_TIMER.pdf). The link isn't really about replacing it, but once you get it out, you can certainly do that.
That would explain why your offsets are always very similar.
I've just checked on my Pro6 - very different machine of course. I can't see the issue, unless an increase of +0.004 was relevant! 🙂 Sounds like the Kernel clock is stopping while the HDDs are not accessible, how bizarre!
It is bizarre, but I am wondering if the power draw is creating the problem - and that the battery change would ensure that the cmos clock is getting enough power. Just an idea though.
Not a massive expert here, but CMOS clock and Kernel clock should be two different things? The Kernel clock is usually generated by CPU cycles, but it really depends on the system and if alternative timers are provided by the MB. On my Pro 6 "hwclock" (BIOS clock) was still on year 2002, I have synced with the system time (hwclock --systohc), let the HDD spin down, access the NAS again and checked again. No change, both clocks are still ok.
As Stephen says, I'd change that battery anyway. If that does not fix, I'd search the internet for a similar problem with Debian 4
The kernel clock is driven by some real-time clock interrupt. I don't know what the source of that interrupt is on the NV+. Time loss means either that interrupts are being missed (or ignored), or are not generated in the first place.
I agree that the battery change is speculative, but it is an inexpensive thing to try.
I just changed the battery. Unfortunately this did not solve the problem. It still loses 14-22 seconds during each spinup. I noticed that the hwclock is actually correct after a spinup, it is only the system time that gets messed up.
I've run out of ideas here. Can you check the system time (date) several times while the HDDs spin up and confirm it's stuck?
Assuming you have this folder, what do you have in
/sys/devices/system/clocksource/clocksource0/available_clocksource and what do you have in /sys/devices/system/clocksource/clocksource0/current_clocksource
And no, I'm definitely not a linux expert, so what I say here may be rubbish! 🙂
I've analyzed the spin-up process some more. I issue these commands repeatedly: date; ntpdate -q <my good ntp server> first while disks are idle. I then access the exported share from my pc which triggers a spinup. In the terminal window I hit the up arrow to bring back this command. It takes about 10s for the cmd to be echoed. I do this several times in succession. Here is the output:
server 192.168.100.8, stratum 1, offset 0.144709, delay 0.02582 24 Apr 17:33:00 ntpdate[3678]: adjust time server 192.168.100.8 offset 0.144709 sec rn601:/var/log# date; ntpdate -q 192.168.100.8 Thu Apr 24 17:33:16 CEST 2014 server 192.168.100.8, stratum 1, offset 15.014825, delay 0.02577 24 Apr 17:33:16 ntpdate[3682]: step time server 192.168.100.8 offset 15.014825 sec rn601:/var/log# date; ntpdate -q 192.168.100.8 Thu Apr 24 17:33:17 CEST 2014 ... server 192.168.100.8, stratum 1, offset 15.014838, delay 0.02582 24 Apr 17:33:21 ntpdate[3689]: step time server 192.168.100.8 offset 15.014838 sec rn601:/var/log# date; ntpdate -q 192.168.100.8 Thu Apr 24 17:33:23 CEST 2014 server 192.168.100.8, stratum 1, offset 22.364863, delay 0.02580 24 Apr 17:33:24 ntpdate[3691]: step time server 192.168.100.8 offset 22.364863 sec
so it loses 15s, then a bit later, another 7s. This is fairly repeatable.
/sys/devices/system/clocksource/clocksource0/available_clocksource and what do you have in /sys/devices/system/clocksource/clocksource0/current_clocksource
sysfs is mounted, but /sys/devices/system does not contain a clocksource subdirectory, only an empty cpu directory. If there is a hook into the spinup process (just as there is with ACPI operations on modern systems) i could put an ntpdate command in there, but otherwise I should probably just go back to no spindown. The reason I considered it is that this NAS is now only used for storing backups and rarely used items. I had hoped to prolong the life of its disks (one already failed, another one has 5 pending sectors), but spindown probably doesn't help here.
I would like to thank all of you for the interest you took in my case and the time spent helping me.
Turning off spindown is probably the practical solution.
The impact on disk life is a bit hard to assess, as there clearly is more stress on bearings when the drives are spun up. Spinning up 16 times a day might have been too much anyway.
AFAIK, spindown wouldn't help with bad sectors, though I don't really understand the mechanisms that create bad sectors very well. Physical damage is often cited as the cause, but I haven't seen any data on whether spindown reduces the risk of that damage or if it puts the drive more at risk.
I've analyzed the spin-up process some more....this NAS is now only used for storing backups and rarely used items.
Roman I spent a ridiculous amount of time and effort trying to use spindown on my NV+, never succeeding to avoid unexpected spinups, and especially spinups IMMEDIATELY FOLLOWING spindowns which I'm quite certain are not good for hard drives.
I gave-up. I think the "spinup" issue is an underlying Linux issue and not one Netgear has cared to fiddle with. Instead I decided to schedule my NV+ to power On for two hours every day, during which time I have my various PCs scheduled to perform their backups, which in my case are SyncBack Free backups of files, to MTWTFSS and Monthly folders in the ReadyNAS. Every Monday (today!) I let the NV+ run longer, because I do a manual (front pushbutton) backup to a USB drive using Rsync.
On rare occasions that I need the NV+ to be on for whatever reason ie. to retrieve a lost file or something, I turn it on with its Power pb and then return it to Sleep mode with a special Frontview button provided by member WhoCares (I think) here.
