I was having an issue with connecting to the ReadyNAS web admin. When I logged in I just got the loading bar. Eventually it timed out and gave me a few options to retry or check RAIDar, etc.

After some investigating I saw that I was getting a 500 error when the browser was trying to get dbbroker. I checked the apache logs and found the following errors...

# systemctl status -a apache2
apache2.service - The Apache HTTP Server
      Loaded: loaded (/lib/systemd/system/apache2.service; enabled)
      Active: active (running) since Thu, 03 Sep 2015 21:03:37 -0500; 1min 51s ago
     Process: 3016 ExecStart=/usr/sbin/apache2 $OPTIONS -k start (code=exited, status=0/SUCCESS)
     Process: 2910 ExecStartPre=/frontview/bin/fvapps (code=exited, status=0/SUCCESS)
    Main PID: 3018 (apache2)
      CGroup: name=systemd:/system/apache2.service
          ├ 3018 /usr/sbin/apache2 -k start
          ├ 3019 apache_log
          ├ 3020 /usr/sbin/apache2 -k start
          ├ 3021 /usr/sbin/apache2 -k start
          ├ 3022 /usr/sbin/apache2 -k start
          ├ 3023 /usr/sbin/apache2 -k start
          ├ 3025 /usr/sbin/apache2 -k start
          ├ 3026 /usr/sbin/apache2 -k start
          ├ 3046 /usr/sbin/apache2 -k start
          ├ 3047 /usr/sbin/apache2 -k start
          ├ 3048 /usr/sbin/apache2 -k start
          └ 3054 /usr/sbin/apache2 -k start

Sep 03 21:05:22 ReadyNas apache2[3048]: [error] [client 1.2.3.191] Premature end of script headers: dbbroker.cgi, referer: https://1.2.3.15/admin/
Sep 03 21:05:23 ReadyNas apache_access[3019]: 1.2.3.191 "POST /dbbroker HTTP/1.1" 500
Sep 03 21:05:23 ReadyNas apache_access[3019]: 1.2.3.191 "GET /favicon.ico HTTP/1.1" 200
Sep 03 21:05:24 ReadyNas apache2[3023]: [error] [client 1.2.3.191] Connect rddclient failed, referer: https://1.2.3.15/admin/
Sep 03 21:05:24 ReadyNas apache2[3023]: [error] [client 1.2.3.191] Premature end of script headers: dbbroker.cgi, referer: https://1.2.3.15/admin/
Sep 03 21:05:24 ReadyNas apache_access[3019]: 1.2.3.191 "POST /dbbroker HTTP/1.1" 500
Sep 03 21:05:26 ReadyNas apache2[3026]: [error] [client 1.2.3.191] Connect rddclient failed, referer: https://1.2.3.15/admin/
Sep 03 21:05:26 ReadyNas apache2[3026]: [error] [client 1.2.3.191] Premature end of script headers: dbbroker.cgi, referer: https://1.2.3.15/admin/
Sep 03 21:05:27 ReadyNas apache_access[3019]: Suppressed 1 duplicate messages
Sep 03 21:05:27 ReadyNas apache_access[3019]: 1.2.3.191 "GET /favicon.ico HTTP/1.1" 200

Well "Premature end of script headers: dbbroker.cgi" doesn't sound very good. Based on a hint from this thread, I checked the status of readynasd...

# systemctl status -a readynasd
readynasd.service - ReadyNAS System Daemon
      Loaded: loaded (/lib/systemd/system/readynasd.service; enabled)
      Active: inactive (dead) since Thu, 27 Aug 2015 03:03:10 -0500; 1 weeks and 0 days ago
    Main PID: 1345 (code=exited, status=0/SUCCESS)
      Status: "Start Main process"
      CGroup: name=systemd:/system/readynasd.service

Aug 27 00:00:25 ReadyNas readynasd[1345]: Snapshot 'c_1440651624' has been successfully created for share or LUN 'Pictures'.
Aug 27 00:00:26 ReadyNas readynasd[1345]: Snapshot 'c_1440651625' has been successfully created for share or LUN 'Videos'.
Aug 27 00:21:53 ReadyNas readynasd[1345]: Smart Snapshot successfully deleted snapshot '2015_07_30__00_00_40' from share or LUN 'Backup'.
Aug 27 00:22:00 ReadyNas readynasd[1345]: Smart Snapshot successfully deleted snapshot '2015_07_30__00_00_43' from share or LUN 'Documents'.
Aug 27 00:22:07 ReadyNas readynasd[1345]: Smart Snapshot successfully deleted snapshot '2015_07_30__00_00_44' from share or LUN 'Music'.
Aug 27 00:22:14 ReadyNas readynasd[1345]: Smart Snapshot successfully deleted snapshot '2015_07_30__00_00_45' from share or LUN 'Pictures'.
Aug 27 00:22:21 ReadyNas readynasd[1345]: Smart Snapshot successfully deleted snapshot '2015_07_30__00_00_46' from share or LUN 'Videos'.
Aug 27 03:03:09 ReadyNas readynasd[1345]: g_dbus_connection_real_closed: Remote peer vanished with error: Underlying GIOStream returned 0 bytes on an async read (g-io-error-quark, 0). Exiting.
Aug 27 03:03:09 ReadyNas readynasd[1345]: Exit main thread by SIGTERM.
Aug 27 03:03:09 ReadyNas readynasd[1345]: readynasd is halted.

Well, there's your problem. Let's fix that right up

# systemctl restart readynasd

.... wait for it .... wait for it ....

#systemctl status -a readynasd
readynasd.service - ReadyNAS System Daemon
      Loaded: loaded (/lib/systemd/system/readynasd.service; enabled)
      Active: active (running) since Thu, 03 Sep 2015 21:07:06 -0500; 35min ago
    Main PID: 3138 (readynasd)
      Status: "Start Main process"
      CGroup: name=systemd:/system/readynasd.service
          └ 3138 /usr/sbin/readynasd -v 3 -t

Sep 03 21:07:47 ReadyNas readynasd[3138]: Smart Snapshot successfully deleted snapshot '2015_08_04__00_00_33' from share or LUN 'Pictures'.
Sep 03 21:07:48 ReadyNas readynasd[3138]: Smart Snapshot successfully deleted snapshot '2015_08_03__00_00_57' from share or LUN 'Pictures'.
Sep 03 21:07:49 ReadyNas readynasd[3138]: Smart Snapshot successfully deleted snapshot '2015_08_02__00_00_19' from share or LUN 'Pictures'.
Sep 03 21:07:49 ReadyNas readynasd[3138]: Smart Snapshot successfully deleted snapshot '2015_07_04__00_00_43' from share or LUN 'Pictures'.
Sep 03 21:07:56 ReadyNas readynasd[3138]: Smart Snapshot successfully deleted snapshot '2015_08_06__00_00_28' from share or LUN 'Videos'.
Sep 03 21:07:56 ReadyNas readynasd[3138]: Smart Snapshot successfully deleted snapshot '2015_08_05__00_00_53' from share or LUN 'Videos'.
Sep 03 21:07:56 ReadyNas readynasd[3138]: Smart Snapshot successfully deleted snapshot '2015_08_04__00_00_34' from share or LUN 'Videos'.
Sep 03 21:07:57 ReadyNas readynasd[3138]: Smart Snapshot successfully deleted snapshot '2015_08_03__00_00_58' from share or LUN 'Videos'.
Sep 03 21:07:57 ReadyNas readynasd[3138]: Smart Snapshot successfully deleted snapshot '2015_08_02__00_00_21' from share or LUN 'Videos'.
Sep 03 21:07:57 ReadyNas readynasd[3138]: Smart Snapshot successfully deleted snapshot '2015_07_04__00_00_44' from share or LUN 'Videos'.

And we're back in business. Admin is once again functioning!

Next Post Previous Post