Monday, December 21, 2020

Fighting Mongodb after an unexpected shutdown - WiredTiger.turtle permission issues

 On a sandbox server that we manage, a Mongodb based application that we manage was affected by an unexpected shutdown. While I have these notes in another location, they are, unfortunately, behind a login and therefore not easy for others on the internet to access. I'm dumping these logs here for the benefit of my future self.

In summary:

The WiredTiger.turtle file was owned by root when it should have been owned by the user associated with MongoDB

I'm looking in db/logs/db.log and seeing the following

2020-12-21T14:23:52.569+0000 I CONTROL  [initandlisten] build environment:
2020-12-21T14:23:52.569+0000 I CONTROL  [initandlisten]     distarch: x86_64
2020-12-21T14:23:52.569+0000 I CONTROL  [initandlisten]     target_arch: x86_64
2020-12-21T14:23:52.569+0000 I CONTROL  [initandlisten] options: { net: { port: 6001 }, processManagement: { fork: true }, storage: { dbPath: "db/data" }, systemLog: { destination: "file", path: "db/logs/db.log" } }
2020-12-21T14:23:52.593+0000 I -        [initandlisten] Detected data files in /home/godata/db/data created by the 'wiredTiger' storage engine, so setting the active storage engine to 'wiredTiger'.
2020-12-21T14:23:52.594+0000 I STORAGE  [initandlisten] wiredtiger_open config: create,cache_size=1G,session_max=20000,eviction=(threads_min=4,threads_max=4),config_base=false,statistics=(fast),log=(enabled=true,archive=true,path=journal,compressor=snappy),file_manager=(close_idle_time=100000),checkpoint=(wait=60,log_size=2GB),statistics_log=(wait=0),verbose=(recovery_progress),
2020-12-21T14:23:52.609+0000 E STORAGE  [initandlisten] WiredTiger (13) [1608560632:609444][21617:0x7f28ae23acc0], file:WiredTiger.wt, connection: /home/godata/db/data/WiredTiger.turtle: handle-open: open: Permission denied
2020-12-21T14:23:52.610+0000 I -        [initandlisten] Assertion: 28595:13: Permission denied
2020-12-21T14:23:52.610+0000 I STORAGE  [initandlisten] exception in initAndListen: 28595 13: Permission denied, terminating
2020-12-21T14:23:52.610+0000 I CONTROL  [initandlisten] dbexit:  rc: 10

I'm most concerned about the permission denied

2020-12-21T14:23:52.610+0000 I STORAGE  [initandlisten] exception in initAndListen: 28595 13: Permission denied, terminating

All files are owned by the `godata` user (the user responsible for starting all processes, so I'm not sure why I'm getting permission denied.

I tried repairing the db

platforms/linux/x64/default/mongodb/bin/mongod --dbpath db/data --repair

The output still gives me a permission denied

2020-12-21T14:39:33.590+0000 I CONTROL  [initandlisten] MongoDB starting : pid=4224 port=27017 dbpath=db/data 64-bit host=ubuntu-s-2vcpu-4gb-nyc1-01
2020-12-21T14:39:33.591+0000 I CONTROL  [initandlisten] db version v3.2.21
2020-12-21T14:39:33.591+0000 I CONTROL  [initandlisten] git version: 1ab1010737145ba3761318508ff65ba74dfe8155
2020-12-21T14:39:33.591+0000 I CONTROL  [initandlisten] allocator: tcmalloc
2020-12-21T14:39:33.591+0000 I CONTROL  [initandlisten] modules: none
2020-12-21T14:39:33.592+0000 I CONTROL  [initandlisten] build environment:
2020-12-21T14:39:33.592+0000 I CONTROL  [initandlisten]     distarch: x86_64
2020-12-21T14:39:33.592+0000 I CONTROL  [initandlisten]     target_arch: x86_64
2020-12-21T14:39:33.592+0000 I CONTROL  [initandlisten] options: { repair: true, storage: { dbPath: "db/data" } }
2020-12-21T14:39:33.619+0000 I -        [initandlisten] Detected data files in db/data created by the 'wiredTiger' storage engine, so setting the active storage engine to 'wiredTiger'.
2020-12-21T14:39:33.619+0000 I STORAGE  [initandlisten] Detected WT journal files.  Running recovery from last checkpoint.
2020-12-21T14:39:33.619+0000 I STORAGE  [initandlisten] journal to nojournal transition config: create,cache_size=1G,session_max=20000,eviction=(threads_min=4,threads_max=4),config_base=false,statistics=(fast),log=(enabled=true,archive=true,path=journal,compressor=snappy),file_manager=(close_idle_time=100000),checkpoint=(wait=60,log_size=2GB),statistics_log=(wait=0),verbose=(recovery_progress),
2020-12-21T14:39:33.644+0000 E STORAGE  [initandlisten] WiredTiger (13) [1608561573:644475][4224:0x7f28b011ccc0], file:WiredTiger.wt, connection: db/data/WiredTiger.turtle: handle-open: open: Permission denied
2020-12-21T14:39:33.645+0000 I -        [initandlisten] Assertion: 28718:13: Permission denied
2020-12-21T14:39:33.646+0000 I STORAGE  [initandlisten] exception in initAndListen: 28718 13: Permission denied, terminating
2020-12-21T14:39:33.646+0000 I CONTROL  [initandlisten] dbexit:  rc: 100
I've found a similar issue documented here:

ls -l db/data/WiredTiger.turtle

-rw-r--r-- 1 root root 1011 Dec 21 10:48 db/data/WiredTiger.turtle

As the root user I ran the following command (note.. my setup uses a user user called 'godata', this will vary for others)

chown -R godata:godata /home/godata/db/

I was then able to succesfully launch the standard Go.Data scripts.

No comments:

Sign up for my upcoming Plone 5 Book & Video tutorials

plone 5 for newbies book and videos