Fan control?

[jaker]

Hi
I've set the temperature to 40 degrees. One disk was again spinning while in Standby with WOL. As I started the NAS with WOL command, the fan started to spin with quite high speed. As the device started up, I checked the temperatures. Perhaps it was 48C before the fan started spinning.

Code: Select all

Disk   Status   Current temperature   Max temperature   Max temperature ever reached
sda   active   45 °C   48 °C   52 °C
sdb   active   45 °C   46 °C   52 °C

I shut down the NAS earlier so I did this once more. Here's the new logfile.

Code: Select all

root@ZENfvdwsl-base:/diskmon.20-29-21 # cat log1
==== Thu Sep 24 16:31:02 EEST 2020 ====
[   36.324860] jbd2/sda1-8(773): WRITE block 1186 on sda1 (2 sectors)
[   36.404451] sync(832): WRITE block 2 on sda1 (2 sectors)
[   36.404502] sync(832): WRITE block 4 on sda1 (2 sectors)
[   36.404526] sync(832): WRITE block 6 on sda1 (2 sectors)
[   36.404554] sync(832): WRITE block 524 on sda1 (2 sectors)
[   36.404592] sync(832): WRITE block 1034 on sda1 (2 sectors)
[   36.404627] sync(832): WRITE block 16904 on sda1 (2 sectors)
[   36.404662] sync(832): WRITE block 49676 on sda1 (2 sectors)
[   36.404697] sync(832): WRITE block 82440 on sda1 (2 sectors)
[   36.404732] sync(832): WRITE block 131078 on sda1 (2 sectors)
[   36.404767] sync(832): WRITE block 131086 on sda1 (2 sectors)
[   36.404804] sync(832): WRITE block 131090 on sda1 (2 sectors)
[   36.404840] sync(832): WRITE block 131106 on sda1 (2 sectors)
[   36.404869] sync(832): WRITE block 131108 on sda1 (2 sectors)
[   36.404896] sync(832): WRITE block 131118 on sda1 (2 sectors)
[   36.404933] sync(832): WRITE block 131120 on sda1 (2 sectors)
[   36.404960] sync(832): WRITE block 131128 on sda1 (2 sectors)
[   36.404997] sync(832): WRITE block 131136 on sda1 (2 sectors)
[   36.405027] sync(832): WRITE block 131138 on sda1 (2 sectors)
[   36.405046] sync(832): WRITE block 131140 on sda1 (2 sectors)
[   36.405094] sync(832): WRITE block 131148 on sda1 (2 sectors)
[   36.405126] sync(832): WRITE block 131150 on sda1 (2 sectors)
[   36.405154] sync(832): WRITE block 131154 on sda1 (2 sectors)
[   36.405193] sync(832): WRITE block 147976 on sda1 (2 sectors)
[   36.405233] sync(832): WRITE block 148678 on sda1 (2 sectors)
[   36.405643] sync(832): WRITE block 163842 on sda1 (2 sectors)
[   36.405675] sync(832): WRITE block 163844 on sda1 (2 sectors)
[   36.405694] sync(832): WRITE block 163846 on sda1 (2 sectors)
[   36.405721] sync(832): WRITE block 163854 on sda1 (2 sectors)
[   36.405755] sync(832): WRITE block 163856 on sda1 (2 sectors)
[   36.405783] sync(832): WRITE block 164356 on sda1 (2 sectors)
[   36.405887] sync(832): WRITE block 164368 on sda1 (2 sectors)
[   36.405968] sync(832): WRITE block 164568 on sda1 (2 sectors)
[   36.406047] sync(832): WRITE block 165126 on sda1 (2 sectors)
[   36.406125] sync(832): WRITE block 212994 on sda1 (2 sectors)
[   36.406203] sync(832): WRITE block 507906 on sda1 (2 sectors)
[   36.406236] sync(832): WRITE block 507908 on sda1 (2 sectors)
[   36.406296] sync(832): WRITE block 507910 on sda1 (2 sectors)
[   36.406328] sync(832): WRITE block 508420 on sda1 (2 sectors)
[   36.406422] sync(832): WRITE block 589828 on sda1 (2 sectors)
[   36.406540] sync(832): WRITE block 589848 on sda1 (2 sectors)
[   36.406696] sync(832): WRITE block 589878 on sda1 (2 sectors)
[   36.406739] sync(832): WRITE block 589898 on sda1 (2 sectors)
[   36.406778] sync(832): WRITE block 590352 on sda1 (2 sectors)
[   36.406817] sync(832): WRITE block 590442 on sda1 (2 sectors)
[   36.406855] sync(832): WRITE block 770052 on sda1 (2 sectors)
[   36.407307] sync(832): WRITE block 770054 on sda1 (2 sectors)
[   36.407341] sync(832): WRITE block 770088 on sda1 (2 sectors)
[   36.407376] sync(832): WRITE block 770698 on sda1 (2 sectors)
[   36.407411] sync(832): WRITE block 999428 on sda1 (2 sectors)
[   36.407438] sync(832): WRITE block 999430 on sda1 (2 sectors)
[   36.407465] sync(832): WRITE block 999622 on sda1 (2 sectors)
[   36.407545] sync(832): WRITE block 999630 on sda1 (2 sectors)
[   36.407625] sync(832): WRITE block 999632 on sda1 (2 sectors)
[   36.407696] sync(832): WRITE block 1000036 on sda1 (2 sectors)
[   36.407743] sync(832): WRITE block 1015812 on sda1 (2 sectors)
[   36.407826] sync(832): WRITE block 1015820 on sda1 (2 sectors)
[   36.407947] sync(832): WRITE block 1015836 on sda1 (2 sectors)
[   36.408026] sync(832): WRITE block 1016340 on sda1 (2 sectors)
[   37.175553] diskmon(849): READ block 804272 on sda1 (2 sectors)
[   49.114033] random: crng init done
[   51.436718] rcS(979): READ block 770568 on sda1 (2 sectors)
[   51.437328] rcS(979): READ block 771118 on sda1 (20 sectors)
[   51.441634] wol-fvdw-sl(979): READ block 98028 on sda1 (2 sectors)
[   51.447877] wol-fvdw-sl(979): dirtied inode 125259 (time-suspend.txt) on sda1
[   51.447927] wol-fvdw-sl(979): dirtied inode 125259 (time-suspend.txt) on sda1
[   51.456814] sh(981): READ block 999620 on sda1 (2 sectors)
[   51.456939] sh(981): READ block 999636 on sda1 (2 sectors)
[   51.456989] sh(981): READ block 999638 on sda1 (2 sectors)
[   51.457050] sh(981): READ block 999640 on sda1 (2 sectors)
[   51.457079] sh(981): READ block 999642 on sda1 (2 sectors)
[   51.457106] sh(981): READ block 999644 on sda1 (2 sectors)
[   51.457131] sh(981): READ block 999646 on sda1 (2 sectors)
[   51.457174] sh(981): READ block 999648 on sda1 (2 sectors)
[   51.457201] sh(981): READ block 999650 on sda1 (2 sectors)
[   51.457227] sh(981): READ block 999652 on sda1 (2 sectors)
[   51.457252] sh(981): READ block 999654 on sda1 (2 sectors)
[   51.457294] sh(981): READ block 999656 on sda1 (2 sectors)
[   51.457321] sh(981): READ block 999658 on sda1 (2 sectors)
[   51.457346] sh(981): READ block 999660 on sda1 (2 sectors)
[   51.457371] sh(981): READ block 999662 on sda1 (2 sectors)
[   51.457413] sh(981): READ block 999664 on sda1 (2 sectors)
[   51.457441] sh(981): READ block 999666 on sda1 (2 sectors)
[   51.457466] sh(981): READ block 999668 on sda1 (2 sectors)
[   51.457491] sh(981): READ block 999670 on sda1 (2 sectors)
[   51.457533] sh(981): READ block 999672 on sda1 (2 sectors)
[   51.457560] sh(981): READ block 999674 on sda1 (2 sectors)
[   51.457585] sh(981): READ block 999676 on sda1 (2 sectors)
[   51.457610] sh(981): READ block 999678 on sda1 (2 sectors)
[   51.457651] sh(981): READ block 999680 on sda1 (2 sectors)
[   51.457673] sh(981): READ block 999624 on sda1 (2 sectors)
[   51.461249] sh(981): READ block 815384 on sda1 (4 sectors)
[   51.475719] leds_switch(981): READ block 815252 on sda1 (6 sectors)
[   51.478388] leds_switch(982): READ block 803972 on sda1 (2 sectors)
[   51.491874] leds_switch(983): READ block 803858 on sda1 (2 sectors)
[   51.492419] leds_switch(983): READ block 809388 on sda1 (6 sectors)
[   51.538520] leds_switch(991): READ block 803960 on sda1 (2 sectors)
[   51.539117] leds_switch(991): READ block 808612 on sda1 (8 sectors)
[   51.624761] mdadm-events(1000): READ block 803856 on sda1 (2 sectors)
[   51.627290] mdadm-events(1000): READ block 804034 on sda1 (2 sectors)
[   51.627566] mdadm-events(1000): READ block 807388 on sda1 (32 sectors)
[   51.630329] cat(1000): READ block 623394 on sda1 (2 sectors)
[   52.584606] mv643xx_eth_port mv643xx_eth_port.0 eth0: link down
[   52.590704] IPv6: ADDRCONF(NETDEV_UP): eth0: link is not ready
[   52.606361] sh(1023): READ block 803874 on sda1 (2 sectors)
[   52.606796] sh(1023): READ block 805078 on sda1 (32 sectors)
[   52.607813] sudo(1023): READ block 575594 on sda1 (24 sectors)
[   52.607910] sudo(1023): READ block 575682 on sda1 (116 sectors)
[   52.619879] sudo(1023): READ block 575522 on sda1 (72 sectors)
[   52.620210] sudo(1023): READ block 770742 on sda1 (2 sectors)
[   52.620642] sudo(1023): READ block 770748 on sda1 (2 sectors)
[   52.621253] sudo(1023): READ block 816932 on sda1 (20 sectors)
[   52.621986] sudo(1023): READ block 770750 on sda1 (2 sectors)
[   52.622290] sudo(1023): READ block 773336 on sda1 (32 sectors)
[   52.628296] sudo(1023): READ block 248034 on sda1 (32 sectors)
[   52.628365] sudo(1023): READ block 248578 on sda1 (64 sectors)
[   52.628417] sudo(1023): READ block 248706 on sda1 (30 sectors)
[   52.643110] sudo(1023): READ block 999552 on sda1 (2 sectors)
[   52.643239] sudo(1023): READ block 999554 on sda1 (2 sectors)
[   52.643305] sudo(1023): READ block 999556 on sda1 (2 sectors)
[   52.643366] sudo(1023): READ block 999558 on sda1 (2 sectors)
[   52.643450] sudo(1023): READ block 999560 on sda1 (2 sectors)
[   52.643513] sudo(1023): READ block 999562 on sda1 (2 sectors)
[   52.643574] sudo(1023): READ block 999564 on sda1 (2 sectors)
[   52.643634] sudo(1023): READ block 999566 on sda1 (2 sectors)
[   52.643719] sudo(1023): READ block 999568 on sda1 (2 sectors)
[   52.643781] sudo(1023): READ block 999570 on sda1 (2 sectors)
[   52.643841] sudo(1023): READ block 999572 on sda1 (2 sectors)
[   52.643902] sudo(1023): READ block 999574 on sda1 (2 sectors)
[   52.644099] sudo(1023): READ block 999576 on sda1 (2 sectors)
[   52.644173] sudo(1023): READ block 999578 on sda1 (2 sectors)
[   52.644235] sudo(1023): READ block 999580 on sda1 (2 sectors)
[   52.644295] sudo(1023): READ block 999582 on sda1 (2 sectors)
[   52.644374] sudo(1023): READ block 999584 on sda1 (2 sectors)
[   52.644436] sudo(1023): READ block 999586 on sda1 (2 sectors)
[   52.644496] sudo(1023): READ block 999588 on sda1 (2 sectors)
[   52.644557] sudo(1023): READ block 999590 on sda1 (2 sectors)
[   52.644635] sudo(1023): READ block 999592 on sda1 (2 sectors)
[   52.644697] sudo(1023): READ block 999594 on sda1 (2 sectors)
[   52.644757] sudo(1023): READ block 999596 on sda1 (2 sectors)
[   52.644817] sudo(1023): READ block 999598 on sda1 (2 sectors)
[   52.644894] sudo(1023): READ block 999600 on sda1 (2 sectors)
[   52.644956] sudo(1023): READ block 999602 on sda1 (2 sectors)
[   52.645016] sudo(1023): READ block 999604 on sda1 (2 sectors)
[   52.645076] sudo(1023): READ block 999606 on sda1 (2 sectors)
[   52.645136] sudo(1023): READ block 999608 on sda1 (2 sectors)
[   52.645201] sudo(1023): READ block 999610 on sda1 (2 sectors)
[   52.645262] sudo(1023): READ block 999612 on sda1 (2 sectors)
[   52.645327] sudo(1023): READ block 999614 on sda1 (2 sectors)
[   52.658783] sudo(1023): READ block 814910 on sda1 (4 sectors)
[   52.659674] sudo(1023): READ block 819814 on sda1 (2 sectors)
[   52.659989] sudo(1023): READ block 824356 on sda1 (32 sectors)
[   52.673780] sudo(1023): READ block 836194 on sda1 (60 sectors)
[   52.683803] sudo(1023): READ block 98010 on sda1 (2 sectors)
[   52.685106] sudo(1023): READ block 98012 on sda1 (2 sectors)
[   52.685988] sudo(1023): READ block 770836 on sda1 (2 sectors)
[   52.686344] sudo(1023): READ block 770982 on sda1 (2 sectors)
[   52.688474] sudo(1023): READ block 770752 on sda1 (2 sectors)
[   52.688871] sudo(1023): READ block 773388 on sda1 (32 sectors)
[   52.689419] sudo(1023): READ block 250282 on sda1 (88 sectors)
[   52.689491] sudo(1023): READ block 770754 on sda1 (2 sectors)
[   52.704738] sudo(1023): READ block 770756 on sda1 (2 sectors)
[   52.705019] sudo(1023): READ block 262916 on sda1 (46 sectors)
[   52.717288] sudo(1023): READ block 248674 on sda1 (32 sectors)
[   52.717369] sudo(1023): READ block 248770 on sda1 (64 sectors)
[   52.717465] sudo(1023): READ block 249892 on sda1 (128 sectors)
[   52.717508] sudo(1023): READ block 250114 on sda1 (32 sectors)
[   52.718296] sudo(1023): READ block 804480 on sda1 (2 sectors)
[   52.718687] sudo(1023): READ block 816984 on sda1 (32 sectors)
[   52.719215] sudo(1023): READ block 820514 on sda1 (32 sectors)
[   52.719250] sudo(1023): READ block 820674 on sda1 (4 sectors)
[   52.720131] sudo(1023): READ block 778248 on sda1 (2 sectors)
[   52.728536] sudo(1023): READ block 778004 on sda1 (32 sectors)
[   52.729034] sudo(1023): READ block 377722 on sda1 (8 sectors)
[   52.729102] sudo(1023): READ block 377474 on sda1 (64 sectors)
[   52.729165] sudo(1023): READ block 377794 on sda1 (62 sectors)
[   52.744127] sudo(1023): READ block 377698 on sda1 (24 sectors)
[   52.744905] sudo(1023): READ block 250146 on sda1 (136 sectors)
[   52.746774] sudo(1023): READ block 815550 on sda1 (2 sectors)
[   52.750960] sudo(1023): READ block 770740 on sda1 (2 sectors)
[   52.751349] sudo(1023): READ block 773248 on sda1 (32 sectors)
[   52.752578] hdparm(1023): READ block 247546 on sda1 (8 sectors)
[   52.752656] hdparm(1023): READ block 247810 on sda1 (64 sectors)
[   52.752719] hdparm(1023): READ block 247938 on sda1 (64 sectors)
[   52.755644] hdparm(1023): READ block 247522 on sda1 (24 sectors)
[   54.977794] mv643xx_eth_port mv643xx_eth_port.0 eth0: link up, 1000 Mb/s, full duplex, flow control enabled
[   54.987607] IPv6: ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready
[   56.616050] kworker/u2:3(581): WRITE block 162890 on sda1 (2 sectors)
[   56.616374] jbd2/sda1-8(773): WRITE block 1188 on sda1 (2 sectors)
[   56.616413] jbd2/sda1-8(773): WRITE block 1190 on sda1 (2 sectors)
[   56.616437] jbd2/sda1-8(773): WRITE block 1192 on sda1 (2 sectors)
[   56.616456] jbd2/sda1-8(773): WRITE block 1194 on sda1 (2 sectors)
[   56.616473] jbd2/sda1-8(773): WRITE block 1196 on sda1 (2 sectors)
[   56.616491] jbd2/sda1-8(773): WRITE block 1198 on sda1 (2 sectors)
[   56.644146] ata1.00: exception Emask 0x0 SAct 0x8000000 SErr 0x0 action 0x6
[   56.651093] ata1.00: waking up from sleep
[   56.664155] ata1: hard resetting link
[   57.173997] ata1: SATA link up 3.0 Gbps (SStatus 123 SControl F300)
[   57.224246] ata1.00: configured for UDMA/133
[   57.228561] ata1: EH complete
[   60.082759] jbd2/sda1-8(773): WRITE block 1200 on sda1 (2 sectors)
[   60.174387] wol-fvdw-sl(979): WRITE block 2 on sda1 (2 sectors)
[   60.174425] wol-fvdw-sl(979): WRITE block 4 on sda1 (2 sectors)
[   60.174460] wol-fvdw-sl(979): WRITE block 82440 on sda1 (2 sectors)
[   60.174496] wol-fvdw-sl(979): WRITE block 147976 on sda1 (2 sectors)
[   60.174532] wol-fvdw-sl(979): WRITE block 999634 on sda1 (2 sectors)
[   65.204023] ata1.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x6
[   65.210456] ata1.00: waking up from sleep
[   65.214522] ata1: hard resetting link
[   65.723998] ata1: SATA link up 3.0 Gbps (SStatus 123 SControl F300)
[   65.774249] ata1.00: configured for UDMA/133
[   65.778511] ata1.00: retrying FLUSH 0xea Emask 0x0
[   65.783468] ata1: EH complete
==== Thu Sep 24 17:01:10 EEST 2020 ====
[ 1844.354379] ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x6
[ 1844.360809] ata2.00: waking up from sleep
[ 1844.364887] ata2: hard resetting link
[ 1844.874363] ata2: SATA link up 3.0 Gbps (SStatus 123 SControl F300)
[ 1844.924604] ata2.00: configured for UDMA/133
[ 1844.928922] ata2: EH complete
==== Thu Sep 24 20:29:21 EEST 2020 ====
[14335.525358] leds_switch(23963): READ block 738032 on sda1 (2 sectors)
[14335.538834] leds_switch(23963): READ block 738882 on sda1 (32 sectors)
[14335.542858] blkid(23963): READ block 181410 on sda1 (96 sectors)
[14335.542920] blkid(23963): READ block 181570 on sda1 (10 sectors)
[14335.562374] blkid(23963): READ block 1946949248 on sda8 (8 sectors)
[14335.589673] blkid(23963): READ block 1946949464 on sda8 (8 sectors)
[14335.615466] blkid(23967): READ block 1946949248 on sdb8 (8 sectors)
[14335.642931] blkid(23967): READ block 1946949464 on sdb8 (8 sectors)
[14335.645325] blkid(23967): READ block 0 on sdb (8 sectors)
[14335.670517] blkid(23967): READ block 3213000 on sdb (8 sectors)
[14335.681616] blkid(23967): READ block 5140736 on sdb (8 sectors)
[14335.691992] blkid(23967): READ block 5397776 on sdb (8 sectors)
[14335.723049] blkid(23967): READ block 6554456 on sdb (8 sectors)
[14335.726844] blkid(23967): READ block 2184840 on sdb (8 sectors)
root@ZENfvdwsl-base:/diskmon.20-29-21 #


As it has also following line

Code: Select all

[   56.644146] ata1.00: exception Emask 0x0 SAct 0x8000000 SErr 0x0 action 0x6

Here's also the dmesg output.

Code: Select all

root@ZENfvdwsl-base:/diskmon.20-29-21 # dmesg
[14336.075075] rcS(776): dirtied inode 6127 (boot.log) on sda1
[14336.075131] rcS(776): dirtied inode 6127 (boot.log) on sda1
[14336.090233] killall(24014): READ block 758050 on sda1 (88 sectors)
[14336.159518] mv(24018): READ block 851972 on sda1 (2 sectors)
[14336.643707] mv(24018): dirtied inode 106081 (?) on sda1
[14336.643770] mv(24018): READ block 851970 on sda1 (2 sectors)
[14336.643879] mv(24018): READ block 868354 on sda1 (2 sectors)
[14336.653673] mv(24018): dirtied inode 106082 (tmp) on sda1
[14336.654221] mv(24018): dirtied inode 106083 (logseq) on sda1
[14336.654609] mv(24018): dirtied inode 106084 (log2) on sda1
[14336.654910] mv(24018): dirtied inode 106085 (log1) on sda1
[14336.656041] mv(24018): dirtied inode 106086 (status) on sda1
[14336.748898] chmod(24026): dirtied inode 79561 (share) on sda1
[14336.775525] rmdir(24029): dirtied inode 79562 (?) on sda1
[14336.784489] rm(24030): dirtied inode 20442 (?) on sda1
[14336.784733] rm(24030): dirtied inode 20441 (?) on sda1
[14336.785003] rm(24030): dirtied inode 20440 (?) on sda1
[14336.794002] blkid(24031): READ block 1670528 on sda5 (8 sectors)
[14337.903951] EXT4-fs (sda5): mounting ext3 file system using the ext4 subsystem
[14338.157329] EXT4-fs (sda5): warning: maximal mount count reached, running e2fsck is recommended
[14338.287180] EXT4-fs (sda5): recovery complete
[14338.326925] EXT4-fs (sda5): mounted filesystem with ordered data mode. Opts: (null)
[14338.583598] Adding 514076k swap on /dev/sda3.  Priority:-2 extents:1 across:514076k
[14351.526198] udevd (24220): /proc/24220/oom_adj is deprecated, please use /proc/24220/oom_score_adj instead.
[14351.536231] udev: starting version 130
[14352.055725] synth uevent: /gpiochip0: failed to send uevent
[14352.055753] gpio gpiochip0: uevent: failed to send synthetic uevent
[14352.187125] synth uevent: /gpiochip1: failed to send uevent
[14352.187153] gpio gpiochip1: uevent: failed to send synthetic uevent
[14360.149368] md: md0 stopped.
[14360.233354] md0: detected capacity change from 0 to 1993675374592
[14367.118633] EXT4-fs (md0): recovery complete
[14367.156959] EXT4-fs (md0): mounted filesystem with ordered data mode. Opts: user_xattr,acl,nodelalloc
root@ZENfvdwsl-base:/diskmon.20-29-21 #

[Jocko]

Thank you for this new test !

I have only more question: after 17:00 and up to 20:30, do you think disks were sleeping ?

[jaker]

Sorry I should have written notes about this. Anyway in my opinion the disks stopped correctly after entering the standby. Within one hour I listened it again and I heard that disk is spinning. Then I was away for about 2-3 hours and as I got back disk was spinning. After a while I woke it up and gathered the logfile to be sent here.

I don't think that the disk would have been stopped during that time you mentioned.

[Mijzelf]

What does the WOL script exactly do? I would expect something like

Code: Select all

... setup wol packet listener
... put everything in low-power mode

sync                                       # flush disk cache
hdparm -y /dev/sda
hdparm -y /dev/sdb               # put disks asleep

do
    sleep 10
while wol

... power up ...


In the logs I see sync is called, and hdparm, but after sync I see 'wol-fvdw-sl' dirtying inodes, causing jbd2/sda1-8 to do a write after hdparm, and later also some WRITE's.
The ata exception at 1844 is strange, as it is more or less reproducible in time.

Code: Select all

[   65.783468] ata1: EH complete
==== Thu Sep 24 17:01:10 EEST 2020 ====
[ 1844.354379] ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x6

Code: Select all

[   40.911663] ata1: EH complete
==== Wed Sep 23 21:26:04 EEST 2020 ====
[ 1820.012565] ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x6

In both cases 1780 seconds between the 2 loglines of the ata bus. Striking is that the first event is from ata1, and the 2nd from ata2.
Any idea what causes the ata1 exception around 60 seconds after boot? Maybe it can also be applied to ata2, preventing the spontaneous one around 1820 seconds.

Is some daemon polling the disk? Maybe 'hdparm -C'?

[Jocko]

Hi Mijzelf

Some useful information

In the logs I see sync is called, and hdparm, but after sync I see 'wol-fvdw-sl' dirtying inodes, causing jbd2/sda1-8 to do a write after hdparm, and later also some WRITE's.

This is the expected behaviour fvdw-wol daemon reset the file 'time-suspend.txt' when it receives the wol magic packet.
This file allows fvdw-sl-wol to wake up the nas after a suspend time without receiving the wol magiv packet.

The ata exception at 1844 is strange, as it is more or less reproducible in time.

Currently we have identified what occurs it. On nas with fan, a fan daemon is also running on wol standby state. This to spin down the fan if it is up when the nas switches to wol standby (or later if the temp disk is too hot).
fvdw goes to look at this point

[fvdw]

For info
This is the relevant part of the wol daemon.
The wol daemon not only listen to receive a magic packet but also monitors push button event which also may wake up the nas. Furthermore the nas can be put in wol state for a given time by tempguard daemon in case of too high disk temperature, itime is an integer used in wol daemon to wake up the nas after a suspend time is expired

The array disk[5] contains the names of the drives (/dev/sda, dev/sdb, dev/sdc/,/dev/sdd,/dev/sde)

The array Bsd[5] contains which disk are actually present a 1 is entered if disk is present a 0 when not.
System disk is always sda so corresponds with Bsd[0])

The function powermode() tests if disk is active or standby or reurns -1 when no mode can be retrieved.

Code: Select all

    // Force the non system drives to immediately enter the lowest power
    // consumption sleep mode, causing it to shut down completely.
   for (i=1; i<5; ++i)
      {
      if (Bsd[i])
         {
        snprintf(cmd,200,"sudo /usr/sbin/hdparm -Y %s",disk[i]);
        system(cmd);
        sleep(1);
        }
      }
    sleep(1);
// force system disk to standby
    snprintf(cmd,200,"sudo /usr/sbin/hdparm -Y %s",disk[0]);
    system(cmd);
// check if system disk is in standby and remains in standby
   ihd=1;
//   while (powermode(disk[0]) && ihd < 4)
   while ( ihd < 4)      {
      sync();
      sleep(4);
      if (powermode(disk[0]))
         {
         snprintf(cmd,200,"sudo /usr/sbin/hdparm -Y %s",disk[0]);
         system(cmd);
         }
           
      ihd=ihd+1;
      }
//enter monitoring loop
    if (itime)  // max suspend time found
      {
//printf("itime=1\n");
      tstart=time(NULL);
      tend=0;
      while (!wol && !wob && itime) {
        // Wait untill data is received from the socket or from the input.
        usleep(100000);
        FD_ZERO(&readfds);
        FD_SET(sockfd, &readfds);
        FD_SET(fd, &readfds);
        i = (fd > sockfd ? fd : sockfd) + 1;
        select(i, &readfds, NULL, NULL, NULL);

        // Check for Power Button event or WoL MagicPacket.
        if (FD_ISSET(fd, &readfds))     wob = get_power_button_event(fd);
        if (FD_ISSET(sockfd, &readfds)) wol = get_magic_packet(sockfd, my_mac);
        tend=time(NULL)-tstart;
//printf("tend=%d iwait=%d\n",tend, iwait);
        if ( tend > iwait)
           itime=0;
        }
      if (wol) printf("Received Wake-on-LAN Magic Packet.\n");
      if (wob) printf("Received EV_KEY, KEY_POWER input event.\n");
      if(!itime) printf("Waiting time expired.\n");
      }
      else  //normal WOL no suspend max time
      {
      while (!wol && !wob ) {

        // Wait untill data is received from the socket or from the input.
        usleep(100000);
        FD_ZERO(&readfds);
        FD_SET(sockfd, &readfds);
        FD_SET(fd, &readfds);
        i = (fd > sockfd ? fd : sockfd) + 1;
        select(i, &readfds, NULL, NULL, NULL);

        // Check for Power Button event or WoL MagicPacket.
        if (FD_ISSET(fd, &readfds))     wob = get_power_button_event(fd);
        if (FD_ISSET(sockfd, &readfds)) wol = get_magic_packet(sockfd, my_mac);
        }
      if (wol) printf("Received Wake-on-LAN Magic Packet.\n");
      if (wob) printf("Received EV_KEY, KEY_POWER input event.\n");
      }
    close(sockfd);
    close(fd);
    // Wake-up disk
    // The Linux IDE  driver will  automatically  handle
    // issuing a reset if/when needed.

    // Turn on the blue led.
system("/etc/leds_switch on");
return 0;

[fvdw]

about fan daemon it reads disk temperature using this function
this is the function that reads disk temperature in fan daemon
*diskid is a pointer to address containg driver name (for example /dev/sda)

Code: Select all

int tempdisk(char *diskid)
{
   int ret =0;
   int fd;
   int Temp;
   unsigned char buff[STRANGE_BUFFER_LENGTH];
   memset(buff, 0, STRANGE_BUFFER_LENGTH);
   buff[0] = ATA_SMART_CMD;   
   buff[1] = 0xE0;  //ATA_STANDBY_IMMEDIATE           
   buff[2] = ATA_SMART_READ_LOG_SECTOR;
   buff[3] = 1;     
   fd = open(diskid, O_RDONLY | O_NONBLOCK);
   if ((ret=ioctl(fd, HDIO_DRIVE_CMD, buff))) {
      close(fd);
      return -1;
      }
   close(fd);
   if (buff[204] == 0x80) { // a value of 0x80 indicates an invalid temperature value
//printf("%s invalid temperature value \n",diskid);
      return -1;
      }       
      else
      {
      Temp = buff[204];
//printf("%s CURRENT TEMP = %d \n",diskid, Temp);
      return Temp;
      }


@mijzelf, afaik the open function and ioctl cause should not wake up a disk from standby as it talks with the disk firmware, or is this a wrong statement ?

[Mijzelf]

@mijzelf, afaik the open function and ioctl cause should not wake up a disk from standby as it talks with the disk firmware, or is this a wrong statement ?

I *think* it is wrong. I don't have documentation about that, except the implementation of hddtemp, which doesn't display the temperature of a standby/sleeping disk, unless you use the --wake-up switch. If you look at the sata implementation (line 115), you see it first checks the power state, and then reads the SMART values.
There must be a reason for that. I don't know if all disks will spinup on SMART read, but at least some will.

Why are you using sudo? Doesn't the daemon run as root? And another thing, I think using poll() or epoll() instead of select() will reduce the power usage a slightly bit more. Now the CPU has to do some cycles 10 times a second (usleep(100000)), while using poll() a (tickless) kernel can sleep as much as possible, and use the event interrupts to wake your daemon when data is available. For the suspend time you can set a timeout on epoll_wait().

[fvdw]

Thanks for this feedback.

In principle the routine in wol daemon does the same, using smart command to get the info and selects the temperature from it. It does not check power mode of the disk. The reason for that is that the nas will be put in wol state by the tempguard daemon in case the the disk temperature with max fan still exceeds a threshold. In that case automatically wol state is activate for a certain time to let the disk(s) cool down. The disks should cool down in this state as they are send to standby certainly with the fan daemon spinning up the fan. To do this even in standby mode the fan daemon needs to read the temperature.

If this reading of disk temperature wakes up the disk than following modifications could be useful.
Adapt fan daemon to check power mode before reading temperature, no reading when in standby mode when latest tem reading is below the threshold.
In case disk is set to wol state because of overheating disk, activate the fan daemon, let it check temperatures, if temp too high fan will start, sent disks to standby and let the the fan run during the suspend time. The fan daemon will not check temperature but keeps running as long as disk is on standby. If nas wakes up after the suspend time is finished the firmware will check if disk temps are ok, if not again wol state is activated for given time.
When the nas is sent to wol state by the user to procedure could be to let fan daemon check disk temps, activate fan if necessary, sent disk to standby, check after 30 minutes temperatures again and if disk temps ok switch off fan and put disk again to standby.

PS sudo was implemented to be able to run the daemon not as root. But can be taken out.
Thx for the tip on usleep ! I didn't know taht

[jaker]

Just a note about this.

If fandaemon would start up the disk(s) every time it checks the temperatures, then I think both hard disks on my NAS (one with fan and fan control daemon is 2 disk model "Network Space MAX") should be spinning during Standby with WOL.

Isn't the temp checked from both disks?

I think that only one disk of two is spinning at the moment in Standby in WOL state. I don't have any further details about this, I've got to this conclusion only because of the sound when WOL commmand is sent. I hear only one disk to spin up.

If NAS is started up from shutdown state then same spin up sound can be heard twice.