NETGEAR is aware of a growing number of phone and online scams. To learn how to stay safe click here.

Forum Discussion

peachums's avatar
peachums
Aspirant
Oct 23, 2015

ReadyNAS RN20400 Spindown issues, spindown cancelled

I hope someone can help me here before I send this otherwise great NAS back to the supplier.   One big draw for the RN204 was the disk spindown and it just doesnt work. Well I say it doesnt work,...
Other Discussions
Performance
BrianL2's avatar
BrianL2
NETGEAR Employee Retired
Oct 26, 2015

Hi dishmagic66,

 

We are still checking this issue reported by @peachums. Could you check if you got the same disk spin log behavior under systemd-journal.log?

 

 

Kind regards,

 

BrianL
NETGEAR Community Team

dishmagic66's avatar
dishmagic66
Guide
Oct 26, 2015

Hi BrianL,

The behaviour is not really the same as far as  can tell. I renabled diskspindown and post a piece of systemd-journal.log

Oct 26 20:05:33 Readynas apache_access[4079]: 192.168.2.8 "GET /admin/images/system/buttons/btn-question-w.png HTTP/1.1" 404
Oct 26 20:05:33 Readynas apache_access[4079]: 192.168.2.8 "POST /dbbroker HTTP/1.1" 200
Oct 26 20:05:37 Readynas readynasd[3036]: ResetFailedUnit: GDBus.Error:org.freedesktop.systemd1.NoSuchUnit: Unit noflushd.service is not loaded.
Oct 26 20:05:37 Readynas noflushd[18930]: Enabling spindown for disk 4 [sda,0:3:ST2000DM001-1CH164:S1E02AKK:CC29:7200]
Oct 26 20:05:37 Readynas noflushd[18930]: Enabling spindown for disk 3 [sdb,0:2:ST3000VN000-1HJ166:W7302RF3:SC60:5900]
Oct 26 20:05:37 Readynas noflushd[18930]: Enabling spindown for disk 1 [sdd,0:0:ST2000DM001-1CH164:Z1E2SHYW:CC24:7200]
Oct 26 20:05:37 Readynas noflushd[18930]: Enabling spindown for disk 2 [sdc,0:1:ST2000DM001-1CH164:Z1E2S8CP:CC24:7200]
Oct 26 20:05:37 Readynas readynasd[3036]: Automatic disk spin-down enabled.
Oct 26 20:05:38 Readynas afpd[18932]: dsi_tcp_open: invalid header
Oct 26 20:06:01 Readynas cron[2787]: (*system*spindown) RELOAD (/etc/cron.d/spindown)
Oct 26 20:06:31 Readynas systemd[1]: [/lib/systemd/system/fvapp-surveillance.service:6] Invalid executable path in command line, ignoring: mkdir -p /var/nuuo/log
Oct 26 20:06:41 Readynas systemd[1]: [/lib/systemd/system/fvapp-surveillance.service:6] Invalid executable path in command line, ignoring: mkdir -p /var/nuuo/log
Oct 26 20:07:35 Readynas systemd[1]: [/lib/systemd/system/fvapp-surveillance.service:6] Invalid executable path in command line, ignoring: mkdir -p /var/nuuo/log
Oct 26 20:07:43 Readynas dbus[2792]: [system] Activating service name='org.opensuse.Snapper' (using servicehelper)
Oct 26 20:07:43 Readynas snapperd[19177]: Requesting DBus name
Oct 26 20:07:43 Readynas dbus[2792]: [system] Successfully activated service 'org.opensuse.Snapper'
Oct 26 20:07:43 Readynas snapperd[19177]: Loading snapper configs
Oct 26 20:07:43 Readynas snapperd[19177]: Listening for method calls and signals
Oct 26 20:07:45 Readynas readynasd[3036]: head: cannot open `/sys/kernel/config/target/iscsi/*/tpgt*/lun/lun*/lun*/info' for reading: No such file or directory
Oct 26 20:07:49 Readynas readynasd[3036]: sysctl: reading key "net.ipv6.conf.LeafNets.stable_secret"
Oct 26 20:07:49 Readynas readynasd[3036]: sysctl: reading key "net.ipv6.conf.all.stable_secret"
Oct 26 20:07:49 Readynas readynasd[3036]: sysctl: reading key "net.ipv6.conf.default.stable_secret"
Oct 26 20:07:49 Readynas readynasd[3036]: sysctl: reading key "net.ipv6.conf.eth0.stable_secret"
Oct 26 20:07:49 Readynas readynasd[3036]: sysctl: reading key "net.ipv6.conf.eth1.stable_secret"
Oct 26 20:07:49 Readynas readynasd[3036]: sysctl: reading key "net.ipv6.conf.lo.stable_secret"
Oct 26 20:07:49 Readynas readynasd[3036]: sysctl: reading key "net.ipv6.conf.tunl0.stable_secret"
Oct 26 20:07:49 Readynas kernel: nr_pdflush_threads exported in /proc is scheduled for removal
Oct 26 20:07:52 Readynas readynasd[3036]: Segmentation fault (core dumped)
Oct 26 20:07:56 Readynas readynasd[3036]: system log /var/readynasd/system_logs.zip was created successfully!
Oct 26 20:07:56 Readynas readynasd[3036]: fread(/var/readynasd/system_logs.zip) caused errno=2
Oct 26 20:08:55 Readynas apache2[18799]: [error] [client 192.168.2.8] File does not exist: /var/www/currentsetting.htm
Oct 26 20:09:01 Readynas CRON[19630]: pam_unix(cron:session): session opened for user root by (uid=0)
Oct 26 20:09:01 Readynas CRON[19631]: (root) CMD (  [ -x /usr/lib/php5/maxlifetime ] && [ -d /var/lib/php5 ] && find /var/lib/php5/ -depth -mindepth 1 -maxdepth 1 -type f -ignore_readdir_race -cmin +$(/usr/lib/php5/maxlifetime) ! -execdir fuser -s {} 2>/dev/null \; -delete)
Oct 26 20:09:01 Readynas CRON[19630]: pam_unix(cron:session): session closed for user root
Oct 26 20:09:05 Readynas connmand[2798]: ntp: time slew +0.061381 s
Oct 26 20:09:44 Readynas snapperd[19177]: Exiting
Oct 26 20:10:38 Readynas afpd[19688]: dsi_tcp_open: invalid header
Oct 26 20:15:38 Readynas apache2[18570]: [error] [client 192.168.2.8] File does not exist: /var/www/currentsetting.htm
Oct 26 20:16:39 Readynas afpd[19873]: dsi_tcp_open: invalid header
Oct 26 20:17:01 Readynas CRON[19881]: pam_unix(cron:session): session opened for user root by (uid=0)
Oct 26 20:17:01 Readynas CRON[19882]: (root) CMD (   cd / && run-parts --report /etc/cron.hourly)
Oct 26 20:17:01 Readynas CRON[19881]: pam_unix(cron:session): session closed for user root
Oct 26 20:20:39 Readynas afpd[19976]: dsi_tcp_open: invalid header
Oct 26 20:22:42 Readynas apache2[4156]: [error] [client 192.168.2.8] File does not exist: /var/www/currentsetting.htm
Oct 26 20:25:40 Readynas afpd[20111]: dsi_tcp_open: invalid header
Oct 26 20:26:09 Readynas connmand[2798]: ntp: time slew +0.061976 s
Oct 26 20:26:54 Readynas smbd[9115]: pam_unix(samba:session): session closed for user guest
Oct 26 20:26:55 Readynas dbus[2792]: [system] Activating service name='org.opensuse.Snapper' (using servicehelper)
Oct 26 20:26:55 Readynas snapperd[20143]: Requesting DBus name
Oct 26 20:26:55 Readynas dbus[2792]: [system] Successfully activated service 'org.opensuse.Snapper'
Oct 26 20:26:55 Readynas snapperd[20143]: Loading snapper configs
Oct 26 20:26:55 Readynas snapperd[20143]: Listening for method calls and signals
Oct 26 20:26:55 Readynas smbd[9115]: [2015/10/26 20:26:55.971549,  0] ../source3/modules/vfs_snapper.c:823(snapper_list_snaps_unpack)
Oct 26 20:26:55 Readynas smbd[9115]: list_snaps error response: error.no_permissions
Oct 26 20:26:55 Readynas smbd[9115]: [2015/10/26 20:26:55.972040,  0] ../source3/modules/vfs_default.c:1145(vfswrap_fsctl)
Oct 26 20:26:55 Readynas smbd[9115]: FSCTL_GET_SHADOW_COPY_DATA: connectpath /data/Alice, failed - NT_STATUS_ACCESS_DENIED.
Oct 26 20:28:56 Readynas snapperd[20143]: Exiting
Oct 26 20:29:45 Readynas apache2[4096]: [error] [client 192.168.2.8] File does not exist: /var/www/currentsetting.htm
Oct 26 20:31:40 Readynas afpd[20269]: dsi_tcp_open: invalid header
Oct 26 20:35:41 Readynas afpd[20370]: dsi_tcp_open: invalid header
Oct 26 20:36:48 Readynas apache2[18443]: [error] [client 192.168.2.8] File does not exist: /var/www/currentsetting.htm
Oct 26 20:39:01 Readynas CRON[20455]: pam_unix(cron:session): session opened for user root by (uid=0)
Oct 26 20:39:01 Readynas CRON[20456]: (root) CMD (  [ -x /usr/lib/php5/maxlifetime ] && [ -d /var/lib/php5 ] && find /var/lib/php5/ -depth -mindepth 1 -maxdepth 1 -type f -ignore_readdir_race -cmin +$(/usr/lib/php5/maxlifetime) ! -execdir fuser -s {} 2>/dev/null \; -delete)
Oct 26 20:39:02 Readynas CRON[20455]: pam_unix(cron:session): session closed for user root
Oct 26 20:41:41 Readynas afpd[20536]: dsi_tcp_open: invalid header
Oct 26 20:43:13 Readynas connmand[2798]: ntp: time slew +0.061926 s
Oct 26 20:43:51 Readynas apache2[18521]: [error] [client 192.168.2.8] File does not exist: /var/www/currentsetting.htm
Oct 26 20:44:07 Readynas noflushd[18930]: Spinning down disk 3 (/dev/sdb).
Oct 26 20:44:09 Readynas noflushd[18930]: Spindown of disk 3 (/dev/sdb) cancelled.
Oct 26 20:46:42 Readynas afpd[20665]: dsi_tcp_open: invalid header
Oct 26 20:49:10 Readynas noflushd[18930]: Spinning down disk 1 (/dev/sdd).
Oct 26 20:49:23 Readynas noflushd[18930]: Spinning up disk 1 (/dev/sdd) after 0:00:10.
Oct 26 20:49:33 Readynas noflushd[18930]: Spinning down disk 3 (/dev/sdb).
Oct 26 20:49:36 Readynas noflushd[18930]: Spinning down disk 2 (/dev/sdc).
Oct 26 20:49:43 Readynas noflushd[18930]: Spinning down disk 4 (/dev/sda).
Oct 26 20:49:55 Readynas noflushd[18930]: Spinning up disk 3 (/dev/sdb) after 0:00:19.
Oct 26 20:49:55 Readynas noflushd[18930]: Spinning up disk 2 (/dev/sdc) after 0:00:17.
Oct 26 20:50:00 Readynas noflushd[18930]: Spinning up disk 4 (/dev/sda) after 0:00:14.
Oct 26 20:50:42 Readynas afpd[20785]: dsi_tcp_open: invalid header
Oct 26 20:50:55 Readynas apache2[18478]: [error] [client 192.168.2.8] File does not exist: /var/www/currentsetting.htm
Oct 26 20:54:31 Readynas noflushd[18930]: Spinning down disk 1 (/dev/sdd).
Oct 26 20:54:54 Readynas noflushd[18930]: Spinning up disk 1 (/dev/sdd) after 0:00:20.
Oct 26 20:55:04 Readynas noflushd[18930]: Spinning down disk 4 (/dev/sda).
Oct 26 20:55:07 Readynas noflushd[18930]: Spinning down disk 3 (/dev/sdb).
Oct 26 20:55:10 Readynas noflushd[18930]: Spinning down disk 2 (/dev/sdc).
Oct 26 20:55:17 Readynas noflushd[18930]: Spinning up disk 4 (/dev/sda) after 0:00:10.
Oct 26 20:55:18 Readynas noflushd[18930]: Spinning up disk 3 (/dev/sdb) after 0:00:08.
Oct 26 20:55:33 Readynas noflushd[18930]: Spinning up disk 2 (/dev/sdc) after 0:00:21.
Oct 26 20:56:42 Readynas afpd[20968]: dsi_tcp_open: invalid header
Oct 26 20:57:58 Readynas apache2[18799]: [error] [client 192.168.2.8] File does not exist: /var/www/currentsetting.htm
Oct 26 20:58:13 Readynas dbus[2792]: [system] Activating service name='org.opensuse.Snapper' (using servicehelper)
Oct 26 20:58:13 Readynas snapperd[21010]: Requesting DBus name
Oct 26 20:58:13 Readynas dbus[2792]: [system] Successfully activated service 'org.opensuse.Snapper'
Oct 26 20:58:13 Readynas snapperd[21010]: Loading snapper configs
Oct 26 20:58:13 Readynas snapperd[21010]: Listening for method calls and signals
Oct 26 20:58:47 Readynas readynasd[3036]: Smart Snapshot successfully deleted snapshot 2015_10_24__21_00_09 from share or LUN Documents.
Oct 26 21:00:01 Readynas CRON[24203]: pam_unix(cron:session): session opened for user root by (uid=0)
Oct 26 21:00:01 Readynas CRON[24204]: (root) CMD (/etc/cron.hourly/log_rotate_script.sh)
Oct 26 21:00:01 Readynas CRON[24203]: pam_unix(cron:session): session closed for user root
Oct 26 21:00:17 Readynas connmand[2798]: ntp: time slew +0.063175 s
Oct 26 21:00:43 Readynas afpd[24224]: dsi_tcp_open: invalid header
Oct 26 21:00:44 Readynas snapperd[21010]: open failed path:/data/Documents/.snapshots/2496 (No such file or directory)
Oct 26 21:00:45 Readynas readynasd[3036]: Snapshot c_1445889644 was successfully created for share or LUN Documents.
Oct 26 21:02:45 Readynas snapperd[21010]: Exiting
Oct 26 21:05:01 Readynas apache2[4101]: [error] [client 192.168.2.8] File does not exist: /var/www/currentsetting.htm
Oct 26 21:05:43 Readynas afpd[24367]: dsi_tcp_open: invalid header
Oct 26 21:05:54 Readynas noflushd[18930]: Spinning down disk 4 (/dev/sda).
Oct 26 21:05:57 Readynas noflushd[18930]: Spinning down disk 3 (/dev/sdb).
Oct 26 21:06:00 Readynas noflushd[18930]: Spinning down disk 1 (/dev/sdd).
Oct 26 21:06:05 Readynas noflushd[18930]: Spinning down disk 2 (/dev/sdc).
Oct 26 21:06:13 Readynas noflushd[18930]: Spinning up disk 4 (/dev/sda) after 0:00:16.
Oct 26 21:06:13 Readynas noflushd[18930]: Spinning up disk 3 (/dev/sdb) after 0:00:13.
Oct 26 21:06:28 Readynas noflushd[18930]: Spinning up disk 1 (/dev/sdd) after 0:00:23.
Oct 26 21:06:28 Readynas noflushd[18930]: Spinning up disk 2 (/dev/sdc) after 0:00:20.
Oct 26 21:09:01 Readynas CRON[24492]: pam_unix(cron:session): session opened for user root by (uid=0)
Oct 26 21:09:01 Readynas CRON[24493]: (root) CMD (  [ -x /usr/lib/php5/maxlifetime ] && [ -d /var/lib/php5 ] && find /var/lib/php5/ -depth -mindepth 1 -maxdepth 1 -type f -ignore_readdir_race -cmin +$(/usr/lib/php5/maxlifetime) ! -execdir fuser -s {} 2>/dev/null \; -delete)
Oct 26 21:09:01 Readynas CRON[24492]: pam_unix(cron:session): session closed for user root
Oct 26 21:11:19 Readynas noflushd[18930]: Spinning down disk 3 (/dev/sdb).
Oct 26 21:11:32 Readynas noflushd[18930]: Spinning down disk 1 (/dev/sdd).
Oct 26 21:11:35 Readynas noflushd[18930]: Spinning down disk 2 (/dev/sdc).
Oct 26 21:11:42 Readynas noflushd[18930]: Spinning up disk 3 (/dev/sdb) after 0:00:20.
Oct 26 21:11:42 Readynas noflushd[18930]: Spinning up disk 1 (/dev/sdd) after 0:00:07.
Oct 26 21:11:43 Readynas noflushd[18930]: Spinning up disk 2 (/dev/sdc) after 0:00:06.
Oct 26 21:11:43 Readynas afpd[24609]: dsi_tcp_open: invalid header
Oct 26 21:12:03 Readynas noflushd[18930]: Spinning down disk 4 (/dev/sda).
Oct 26 21:12:04 Readynas apache2[4094]: [error] [client 192.168.2.8] File does not exist: /var/www/currentsetting.htm
Oct 26 21:12:16 Readynas noflushd[18930]: Spinning up disk 4 (/dev/sda) after 0:00:10.
Oct 26 21:14:17 Readynas apache_access[4079]: Suppressed 34 duplicate messages
Oct 26 21:14:17 Readynas apache_access[4079]: 192.168.2.3 "POST /dbbroker HTTP/1.1" 401
Oct 26 21:14:19 Readynas apache_access[4079]: 192.168.2.3 "POST /dbbroker HTTP/1.1" 200
Oct 26 21:14:28 Readynas apache_access[4079]: 192.168.2.8 "GET / HTTP/1.1" 302
Oct 26 21:14:29 Readynas apache_access[4079]: 192.168.2.8 "POST /dbbroker HTTP/1.1" 200
Oct 26 21:14:33 Readynas apache_access[4079]: Suppressed 9 duplicate messages
Oct 26 21:14:33 Readynas apache_access[4079]: 192.168.2.8 "POST /fsbroker/ HTTP/1.1" 200
Oct 26 21:14:33 Readynas apache_access[4079]: 192.168.2.8 "POST /fwbroker HTTP/1.1" 200
Oct 26 21:14:33 Readynas apache_access[4079]: 192.168.2.8 "POST /dbbroker HTTP/1.1" 200
Oct 26 21:14:34 Readynas systemd[1]: [/lib/systemd/system/fvapp-surveillance.service:6] Invalid executable path in command line, ignoring: mkdir -p /var/nuuo/log
Oct 26 21:14:37 Readynas apache_access[4079]: Suppressed 1 duplicate messages
Oct 26 21:14:37 Readynas apache_access[4079]: 192.168.2.8 "POST /fwbroker HTTP/1.1" 200
Oct 26 21:14:38 Readynas apache_access[4079]: 192.168.2.8 "POST /dbbroker HTTP/1.1" 200
Oct 26 21:14:46 Readynas dbus[2792]: [system] Activating service name='org.opensuse.Snapper' (using servicehelper)
Oct 26 21:14:46 Readynas snapperd[25430]: Requesting DBus name
Oct 26 21:14:46 Readynas dbus[2792]: [system] Successfully activated service 'org.opensuse.Snapper'
Oct 26 21:14:46 Readynas snapperd[25430]: Loading snapper configs
Oct 26 21:14:46 Readynas snapperd[25430]: Listening for method calls and signals
Oct 26 21:14:47 Readynas readynasd[3036]: head: cannot open `/sys/kernel/config/target/iscsi/*/tpgt*/lun/lun*/lun*/info' for reading: No such file or directory
Oct 26 21:14:49 Readynas readynasd[3036]: sysctl: reading key "net.ipv6.conf.LeafNets.stable_secret"
Oct 26 21:14:49 Readynas readynasd[3036]: sysctl: reading key "net.ipv6.conf.all.stable_secret"
Oct 26 21:14:49 Readynas readynasd[3036]: sysctl: reading key "net.ipv6.conf.default.stable_secret"
Oct 26 21:14:50 Readynas readynasd[3036]: sysctl: reading key "net.ipv6.conf.eth0.stable_secret"
Oct 26 21:14:50 Readynas readynasd[3036]: sysctl: reading key "net.ipv6.conf.eth1.stable_secret"
Oct 26 21:14:50 Readynas readynasd[3036]: sysctl: reading key "net.ipv6.conf.lo.stable_secret"
Oct 26 21:14:50 Readynas readynasd[3036]: sysctl: reading key "net.ipv6.conf.tunl0.stable_secret"

NETGEAR Academy

Boost your skills with the Netgear Academy - Get trained, certified and stay ahead with the latest Netgear technology! 

Join Us!

ProSupport for Business

Comprehensive support plans for maximum network uptime and business peace of mind.

 

Learn More