Re: Readynasd not starting after creating /.force_snapshots_upgrade

gronaix · ‎2019-08-09

Hello!

On my ReadyNAS I face currently the following issue, that the readynasd service is not starting. Therefore my access to the admin page is not available.

Background: within upgrading to current ReadyNASOS 6.10.1 created snapshots haven't been able to delete via the webinterface. I resolve this, I followed the suggestions in this topic but it did not help in my situation.

After creating the .force_snapshot_upgrade file with the commands below, my readynasd.service doesn't come back to live:

# touch /.force_snapshots_upgrade
# systemctl restart readynasd

It will give the following output in systemd when trying to restart and keeps it in a loop:

Aug 09 21:13:34 WG-LAN systemd[1]: Starting ReadyNAS System Daemon...
Aug 09 21:13:34 WG-LAN readynasd[32148]: readynasd log started
Aug 09 21:13:34 WG-LAN readynasd[32148]: readynasd started. (restarted=0)
Aug 09 21:13:34 WG-LAN readynasd[32148]: DB (main) schema version: 24 ==> 24
Aug 09 21:13:35 WG-LAN readynasd[32148]: DB (queue) schema version: new ==> 0
Aug 09 21:13:36 WG-LAN readynasd[32148]: Failed to insert into $timemachine_quota table
Aug 09 21:13:36 WG-LAN readynasd[32148]: _rndb_update_timemachine_user() ==> 3 (2ms)
Aug 09 21:13:36 WG-LAN readynasd[32148]: rndb_account_import() ==> 3 (813ms)
Aug 09 21:13:36 WG-LAN readynasd[32148]: rndb_import() ==> 3 (1381ms)
Aug 09 21:13:36 WG-LAN readynasd[32148]: Error rndb_import() ==> rc=3
Aug 09 21:13:36 WG-LAN readynasd[32148]: dba import failed
Aug 09 21:13:36 WG-LAN systemd[1]: readynasd.service: Main process exited, code=exited, status=255/n/a
Aug 09 21:13:36 WG-LAN systemd[1]: Failed to start ReadyNAS System Daemon.
Aug 09 21:13:36 WG-LAN systemd[1]: readynasd.service: Unit entered failed state.
Aug 09 21:13:36 WG-LAN systemd[1]: readynasd.service: Failed with result 'exit-code'.
Aug 09 21:13:36 WG-LAN systemd[1]: readynasd.service: Service hold-off time over, scheduling restart.
Aug 09 21:13:36 WG-LAN systemd[1]: Stopped ReadyNAS System Daemon.

All research in this board and through the web doesn't brought up a solution, particularly the part regarding the failed DB insert seems to be not posted anywhere else.

To fix it myself, I tried to restore several database backups I found in /var/backups/readynas but the outcome remains the same. Even deleting the whole db.sq3 in /var/readynas doesn't startup the daemon.

Meanwhile in getting desperate with the issue, I was able to solve the initial problem and removed the snapshot with the command below

brtfs subvolume delete <path>

Is there any solution available to either

disable the timemachine_quota input at daemon start
reset/sanitize the database so the input will work
restore a backup via SSH/Commandline to initial state before my changes

Some META information which might be required:

# cat /etc/os_version
ReadyNASOS!!version=6.10.1,time=1557877821,arch=arm,descr=ReadyNASOS

# sqlite3 /var/readynasd/db.sq3 "PRAGMA integrity_check"
ok

Best regards,

gronAix

gronaix · ‎2019-08-12

Hi,

will consider reinstalling when I have physical acces to the ReadyNAS. Currently I am trying to fix it from about 1500 km away 🙂

Here are the requested outputs:

Database

root@WG-LAN:~# sqlite3 --header --column  /var/readynasd/db.sq3 'select * from "$timemachine_quota"'
user_id     enabled     capacity_mb
----------  ----------  -----------
110         1           5000
111         1           5000

Timemachine config

root@WG-LAN:~# cat /etc/netatalk/timemachine.conf
# DO NOT EDIT.
[MaxTv's timemachine]
path = /SERIEN/.timemachine/MaxTv
rwlist = MaxTv
valid users = MaxTv
invalid users = guest nobody @guest @nogroup
vol size limit = 4768
time machine = yes

[admin2's timemachine]
path = /SERIEN/.timemachine/admin2
rwlist = admin2
valid users = admin2
invalid users = guest nobody @guest @nogroup
vol size limit = 4768
time machine = yes

Start with debug log-level

root@WG-LAN:~# readynasd -v 5 -l -
[19/08/12 21:01:48] 32056:32056 readynasd.c:1040 () readynasd log started
[19/08/12 21:01:51] 32056:32056 context.c:239 (debug) NEW GLOBAL_CONTEXT: db.sq3=0xc3d118
[19/08/12 21:01:51] 32056:32056 context.c:286 (debug) NEW GLOBAL_CONTEXT: event.sq3=0xc41128
[19/08/12 21:01:51] 32056:32056 context.c:289 (debug) NEW GLOBAL_CONTEXT: globalctx=0xc3cdb8
[19/08/12 21:01:51] 32056:32056 readynasd.c:1299 () readynasd started. (restarted=0)
[19/08/12 21:01:53] 32056:32056 db_access.c:127 (error) Error rndb_import() ==> rc=3
[19/08/12 21:01:53] 32056:32056 readynasd.c:1358 (error) dba import failed

As stated before, I already manually removed the btrfs subvolumes. Can this cause issues with the timemachine configuration?

I tried now to fiddle around with the timemachine.conf (haven't found this file before) and replaced it with an empty file with same access rights and the webinterface is now accessible again. For now it is fine to me, but reinstalling the device is still something to consider.

View solution in original post

StephenB · ‎2019-08-12

It sounds like you are able to access it with ssh. Have you tried simply deleting .force_snapshots_upgrade?

You might also try an OS reinstall.

gronaix · ‎2019-08-12

Hi StephenB,

I deleted the /.force_snapshots_upgrade already, but it'll still run into the issue described above.

Will it be safe for the stored Data to reinstall the OS?

StephenB · ‎2019-08-12

@gronaix wrote:
Will it be safe for the stored Data to reinstall the OS?

It should be (it's designed to be non-destructive). Though it is always a good idea to have a backup.

In addition to partially reinstalling the OS, it will

reset the admin password to password
reset the network configuration to use DHCP with no bonding
turn off volume quota

The procedure is documented on pages 28-29 here: http://www.downloads.netgear.com/files/GDC/READYNAS-100/ReadyNAS_%20OS6_Desktop_HM_EN.pdf

DEADDEADBEEF · ‎2019-08-12

Can you post your $timemachine_quota table?

sqlite3 --header --column  /var/readynasd/db.sq3 'select * from "$timemachine_quota"'

and your timemachine config:

cat /etc/netatalk/timemachine.conf

Starting readynasd with verbose debug logging might also help identifying cause:

readynasd -v 5 -l -

(start readynasd with Debug log-level and output log to stdout)

gronaix · ‎2019-08-12

Hi,