I have a RN104 for several years and so far no issues until yesterday. For some unknow reason, it re-booted it's self. I have downloaded the logs and viewed some of the entries, but not sure what to look for. I will paste some short clips here and I hope someone can notice what happened, or provided me with information on some other log entry.
(OS6.9.5)
Frontview Logs tab 18 Apr 2019 12:23:57 System: ReadyNASOS background service started. 18 Apr 2019 12:13:59 System: The system is shutting down.
status.log [19/04/18 12:13:59 PDT] notice:system:LOGMSG_SYSTEM_HALT The system is shutting down.
kernal.log Apr 15 16:24:37 TW kernel: mvneta d0070000.ethernet eth0: bad rx status 0f830000 (overrun error), size=512 Apr 18 12:14:53 TW kernel: nfsd: last server has exited, flushing export cache Apr 18 12:15:02 TW systemd-shutdown[1]: Sending SIGTERM to remaining processes... -- Reboot -- Apr 18 12:22:14 TW kernel: Booting Linux on physical CPU 0x0
readynasd.log Apr 18 00:53:38 TW readynasd[2984]: Snapshot prune worker successfully deleted snapshot 2019_03_21__00_00_04 from share or LUN rsyslog. Apr 18 12:13:59 TW readynasd[2984]: The system is shutting down. Apr 18 12:14:52 TW readynasd[2984]: Exit main thread by SIGTERM. Apr 18 12:14:52 TW readynasd[2984]: readynasd is halted. -- Reboot --
system.log Apr 18 12:09:01 TW CRON[4442]: pam_unix(cron:session): session opened for user root by (uid=0) Apr 18 12:09:01 TW CRON[4446]: (root) CMD ( [ -x /usr/lib/php5/sessionclean ] && /usr/lib/php5/sessionclean) Apr 18 12:09:03 TW CRON[4442]: pam_unix(cron:session): session closed for user root Apr 18 12:14:04 TW msmtpq[4523]: mail for [ -C /etc/msmtprc myemail@email.net --timeout=60 ] : couldn't be sent - host not connected Apr 18 12:14:04 TW msmtpq[4526]: enqueued mail as : [ 2019-04-18-12.14.00 ] ( -C /etc/msmtprc myemail@email.net --timeout=60 ) : successful Apr 18 12:14:07 TW msmtpq[4533]: mail for [ -C /etc/msmtprc myemail@email.net --timeout=60 ] : send was successful Apr 18 12:14:50 TW upsmon[3130]: Signal 15: exiting Apr 18 12:14:50 TW wsdd2[2146]: Terminated received. Apr 18 12:14:50 TW wsdd2[2146]: terminating. Apr 18 12:14:51 TW rpc.mountd[3387]: Caught signal 15, un-registering and exiting. Apr 18 12:14:51 TW minissdpd[3229]: quitting... Apr 18 12:14:53 TW mysqld[2681]: 190418 12:14:53 [Note] /usr/sbin/mysqld: Normal shutdown Apr 18 12:14:53 TW mysqld[2681]: Apr 18 12:14:53 TW mysqld[2681]: 190418 12:14:53 [Note] Event Scheduler: Purging the queue. 0 events Apr 18 12:14:53 TW sshd[2208]: Received signal 15; terminating. Apr 18 12:14:54 TW nmbd[2213]: [2019/04/18 12:14:54.062285, 0] ../source3/nmbd/nmbd.c:58(terminate) Apr 18 12:14:54 TW nmbd[2213]: Got SIGTERM: going down... Apr 18 12:14:54 TW avahi-daemon[2171]: Got SIGTERM, quitting. Apr 18 12:14:54 TW avahi-daemon[2171]: Leaving mDNS multicast group on interface eth0.IPv6 with address 2601:600:997f:6324:2ac6:8eff:fe36:755c. Apr 18 12:14:54 TW avahi-daemon[2171]: Leaving mDNS multicast group on interface eth0.IPv4 with address 192.168.1.158. Apr 18 12:14:54 TW avahi-daemon[2171]: avahi-daemon 0.6.32 exiting. Apr 18 12:14:54 TW rsyncd[2159]: sent 0 bytes received 0 bytes total size 0 Apr 18 12:14:55 TW mysqld[2681]: 190418 12:14:55 InnoDB: Starting shutdown... Apr 18 12:14:55 TW mysqld[2681]: 190418 12:14:55 InnoDB: Waiting for 37 pages to be flushed Apr 18 12:14:57 TW mysqld[2681]: 190418 12:14:57 InnoDB: Shutdown completed; log sequence number 748362230 Apr 18 12:14:57 TW mysqld[2681]: 190418 12:14:57 [Note] /usr/sbin/mysqld: Shutdown complete Apr 18 12:14:57 TW mysqld[2681]: Apr 18 12:14:57 TW mysqld_safe[4628]: mysqld from pid file /var/run/mysqld/mysqld.pid ended Apr 18 12:15:00 TW rpcbind[2216]: rpcbind terminating on signal. Restart with "rpcbind -w" Apr 18 12:15:00 TW connmand[2170]: Terminating Apr 18 12:15:00 TW connmand[2170]: Time request for server 192.168.1.1 failed (101/Network is unreachable) Apr 18 12:15:00 TW connmand[2170]: Time request for server 192.168.1.1 failed (101/Network is unreachable) Apr 18 12:15:00 TW connmand[2170]: Remove interface eth0 [ ethernet ] Apr 18 12:15:00 TW connmand[2170]: Remove interface eth1 [ ethernet ] Apr 18 12:15:00 TW connmand[2170]: eth0 {remove} index 2 Apr 18 12:15:00 TW connmand[2170]: eth1 {remove} index 3 Apr 18 12:15:00 TW connmand[2170]: Exit -- Reboot -- Apr 18 12:22:40 TW wsdd2[2148]: starting.
Looking further... in the systemd-journal.log I found the following:
Apr 18 12:09:03 TW CRON[4442]: pam_unix(cron:session): session closed for user root Apr 18 12:13:44 TW systemd-logind[2157]: Power key pressed. Apr 18 12:13:48 TW systemd-logind[2157]: Power key pressed. Apr 18 12:13:55 TW systemd-logind[2157]: Power key pressed. Apr 18 12:13:59 TW readynasd[2984]: The system is shutting down. Apr 18 12:14:01 TW systemd-logind[2157]: Power key pressed. Apr 18 12:14:02 TW systemd-logind[2157]: Power key pressed. Apr 18 12:14:04 TW systemd-logind[2157]: Power key pressed. Apr 18 12:14:04 TW msmtpq[4523]: mail for [ -C /etc/msmtprc myemail@email.com --timeout=60 ] : couldn't be sent - host not connected Apr 18 12:14:04 TW msmtpq[4526]: enqueued mail as : [ 2019-04-18-12.14.00 ] ( -C /etc/msmtprc negative.nancy@comcast.net --timeout=60 ) : successful Apr 18 12:14:05 TW systemd-logind[2157]: Power key pressed. Apr 18 12:14:07 TW msmtpq[4533]: mail for [ -C /etc/msmtprc myemail@email.com --timeout=60 ] : send was successful Apr 18 12:14:07 TW systemd[1]: Started /sbin/poweroff. Apr 18 12:14:07 TW readynasd[2984]: Running timer as unit: run-r3cc53709fcd14252a89fb719b3b36c36.timer Apr 18 12:14:07 TW readynasd[2984]: Will run service as unit: run-r3cc53709fcd14252a89fb719b3b36c36.service Apr 18 12:14:18 TW systemd-logind[2157]: Power key pressed. Apr 18 12:14:49 TW systemd[1]: Started /sbin/poweroff.
In fact, I found sever of the messages for "Power Key pressed". How or what is causing this? Do I have a bad power button? Some internal OS error causing this issue? There was no one around this day to push any button. The other times are:
Apr 18 00:56:37 TW systemd-logind[2157]: Power key pressed. Apr 18 11:36:52 TW systemd-logind[2157]: Power key pressed. Apr 18 11:58:16 TW systemd-logind[2157]: Power key pressed. Apr 18 12:13:44 TW systemd-logind[2157]: Power key pressed. Apr 18 12:13:48 TW systemd-logind[2157]: Power key pressed. Apr 18 12:13:55 TW systemd-logind[2157]: Power key pressed.
Apr 18 12:13:59 TW readynasd[2984]: The system is shutting down. Apr 18 12:14:01 TW systemd-logind[2157]: Power key pressed. Apr 18 12:14:02 TW systemd-logind[2157]: Power key pressed. Apr 18 12:14:04 TW systemd-logind[2157]: Power key pressed. Apr 18 12:14:05 TW systemd-logind[2157]: Power key pressed. Apr 18 12:14:18 TW systemd-logind[2157]: Power key pressed. Apr 18 12:23:55 TW systemd-logind[2157]: Power key pressed. Apr 18 12:27:08 TW systemd-logind[2157]: Power key pressed. Apr 18 12:42:20 TW systemd-logind[2157]: Power key pressed.
I doubt it's the button itself, but it does sound like something in the power on/off circuitry. The Power on/off (together with the LAN interface) use a separate power called +5VSB (5 volt standby), which coiuld also be the issue. Unfortunately, on the units with external supplies, there isn't much you can do about it except replace the NAS.
Hi @BarkingSpider, make sure your external power supply is not directly exposed to sunlight. The time stamps in your excerpts from the logs are all between 12:00 and 15:00 as I can see. Depending on where you are and the sun shining directly on this power supply, that could be a problem, too, even if you are keeping the Nas in the shade.
