Mongodb on Ubuntu -' Main process exited, code=exited, status=1/FAILURE'

ok, I have the below:

My OS is Ubuntu 16.04.
And the ownerships along my files are:
for directories in / owned by root, apart from (as per directories around mongodb):

  • var/lib/mongodb owned by mongodb user
  • var/log/mongodb owned by mongodb user
  • I also noticed that /etc/mongod.conf is under root user, is this correct?

Then in my home directory all the files under /home/user/ are owned by user

Do not use systemctl status like

when you start a process manually like

Use the commands

But it is owned by root, not good.

I have changed the ownership of the mongod.conf to user mongodb
sudo chown -R mongodb:mongodb /etc/mongod.conf

and then rerun manually with the command:
sudo -u mongodb /usr/bin/mongod --auth --config /etc/mongod.conf

Now I am able to see logs inside

var/log/mongodb

2022-03-24T22:28:15.179+0200 I  CONTROL  [initandlisten] OpenSSL version: OpenSSL 1.0.2g  1 Mar 2016
2022-03-24T22:28:15.179+0200 I  CONTROL  [initandlisten] allocator: tcmalloc
2022-03-24T22:28:15.179+0200 I  CONTROL  [initandlisten] modules: none
2022-03-24T22:28:15.179+0200 I  CONTROL  [initandlisten] build environment:
2022-03-24T22:28:15.179+0200 I  CONTROL  [initandlisten]     distmod: ubuntu1604
2022-03-24T22:28:15.179+0200 I  CONTROL  [initandlisten]     distarch: x86_64
2022-03-24T22:28:15.179+0200 I  CONTROL  [initandlisten]     target_arch: x86_64
2022-03-24T22:28:15.179+0200 I  CONTROL  [initandlisten] options: { config: "/etc/mongod.conf", net: { bindIp: "0.0.0.0", port: 23654 }, processManagement: { timeZoneInfo: "/usr/share/zoneinfo" }, security: { authorization: "enabled" }, storage: { dbPath: "/var/lib/mongodb", journal: { enabled: true } }, systemLog: { destination: "file", logAppend: true, path: "/var/log/mongodb/mongod.log" } }
2022-03-24T22:28:15.182+0200 I  STORAGE  [initandlisten] Detected data files in /var/lib/mongodb created by the 'wiredTiger' storage engine, so setting the active storage engine to 'wiredTiger'.
2022-03-24T22:28:15.182+0200 I  STORAGE  [initandlisten]
2022-03-24T22:28:15.182+0200 I  STORAGE  [initandlisten] ** WARNING: Using the XFS filesystem is strongly recommended with the WiredTiger storage engine
2022-03-24T22:28:15.182+0200 I  STORAGE  [initandlisten] **          See http://dochub.mongodb.org/core/prodnotes-filesystem
2022-03-24T22:28:15.182+0200 I  STORAGE  [initandlisten] wiredtiger_open config: create,cache_size=1463M,cache_overflow=(file_max=0M),session_max=33000,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),statistics_log=(wait=0),verbose=[recovery_progress,checkpoint_progress],
2022-03-24T22:28:16.844+0200 E  STORAGE  [initandlisten] WiredTiger error (13) [1648153696:844130][24294:0x7f4bdfc9ab00], wiredtiger_open: __posix_open_file, 712: /var/lib/mongodb/WiredTiger.turtle: handle-open: open: Permission denied Raw: [1648153696:844130][24294:0x7f4bdfc9ab00], wiredtiger_open: __posix_open_file, 712: /var/lib/mongodb/WiredTiger.turtle: handle-open: open: Permission denied
2022-03-24T22:28:16.844+0200 E  STORAGE  [initandlisten] WiredTiger error (13) [1648153696:844481][24294:0x7f4bdfc9ab00], wiredtiger_open: __posix_open_file, 712: /var/lib/mongodb/WiredTiger.turtle: handle-open: open: Permission denied Raw: [1648153696:844481][24294:0x7f4bdfc9ab00], wiredtiger_open: __posix_open_file, 712: /var/lib/mongodb/WiredTiger.turtle: handle-open: open: Permission denied
2022-03-24T22:28:16.845+0200 E  STORAGE  [initandlisten] WiredTiger error (13) [1648153696:845360][24294:0x7f4bdfc9ab00], wiredtiger_open: __posix_open_file, 712: /var/lib/mongodb/WiredTiger.turtle: handle-open: open: Permission denied Raw: [1648153696:845360][24294:0x7f4bdfc9ab00], wiredtiger_open: __posix_open_file, 712: /var/lib/mongodb/WiredTiger.turtle: handle-open: open: Permission denied
2022-03-24T22:28:16.845+0200 W  STORAGE  [initandlisten] Failed to start up WiredTiger under any compatibility version.
2022-03-24T22:28:16.845+0200 F  STORAGE  [initandlisten] Reason: 13: Permission denied

I believe that all the problems were some kind related to the wrong ownership some mongo related files or directories have.

Output of

ls -l /var/lib/mongodb/

All errors indicate some permissions issue
Something wrong in the way you are starting mongod
How can be your home dir /home/mongod?
How do you login to your system?
What does id command show?
Looks like you are switching to mongod user

I get the below when running id

$ id
uid=1000(user) gid=1000(user) groups=1000(user),4(adm),24(cdrom),27(sudo),30(dip),46(plugdev),113(lpadmin),129(sambashare)

Well I have also tried the below with the correct homedir, using the user ‘user’ but still getting same error:

mongod  --dbpath /home/user/mongodb --logpath /home/user/mongodb/mongod.log --port 27017
2022-03-27T21:06:52.191+0300 F  CONTROL  [main] Failed global initialization: FileNotOpen: Failed to open "/home/user/mongodb/mongod.log"

I have noticed at least 3 different ownership users which basically own the various directories as below:

  • user:user for directory /home/user/

  • user :root for most directories in / apart from

    • /data owned by mongodb
    • /var/log/mongodb owned by mongodb
    • /var/lib/mongodb owned by mongodb
    • /etc/mongod.conf owned by mongodb

Is there any other file in / that is related to mongod and should change its ownership to mongodb?
Or in any case, does the above structure with their related ownerships sound problematic?

Does this dir exist?

ls -lrt /home/user/mongodb
or cd /home/user/mongodb

Did you create and try with /data/db?
You have to use sudo to create dir under root folder and chown ownership similar to what was done for /var dirs

I created this dir

/home/user/mongodb

and used
sudo chown -R mongodb:mongodb /home/user/mongodb/

to change ownership to mongodb.
This
/data/db
already existed in root dir, but tried to remove and then recreate and use it due to permission issues (see below)

mongod
2022-03-29T13:20:26.963+0300 I  CONTROL  [main] Automatically disabling TLS 1.0, to force-enable TLS 1.0 specify --sslDisabledProtocols 'none'
2022-03-29T13:20:26.995+0300 I  CONTROL  [initandlisten] MongoDB starting : pid=4456 port=27017 dbpath=/data/db 64-bit host=snf-870308
2022-03-29T13:20:26.997+0300 I  CONTROL  [initandlisten] db version v4.2.0
2022-03-29T13:20:26.997+0300 I  CONTROL  [initandlisten] git version: a4b751dcf51dd249c5865812b390cfd1c0129c30
2022-03-29T13:20:26.998+0300 I  CONTROL  [initandlisten] OpenSSL version: OpenSSL 1.0.2g  1 Mar 2016
2022-03-29T13:20:26.998+0300 I  CONTROL  [initandlisten] allocator: tcmalloc
2022-03-29T13:20:26.998+0300 I  CONTROL  [initandlisten] modules: none
2022-03-29T13:20:26.998+0300 I  CONTROL  [initandlisten] build environment:
2022-03-29T13:20:26.998+0300 I  CONTROL  [initandlisten]     distmod: ubuntu1604
2022-03-29T13:20:26.998+0300 I  CONTROL  [initandlisten]     distarch: x86_64
2022-03-29T13:20:26.998+0300 I  CONTROL  [initandlisten]     target_arch: x86_64
2022-03-29T13:20:26.998+0300 I  CONTROL  [initandlisten] options: {}
2022-03-29T13:20:26.999+0300 I  STORAGE  [initandlisten] exception in initAndListen: IllegalOperation: Attempted to create a lock file on a read-only directory: /data/db, terminating
2022-03-29T13:20:26.999+0300 I  NETWORK  [initandlisten] shutdown: going to close listening sockets...
2022-03-29T13:20:27.000+0300 I  NETWORK  [initandlisten] removing socket file: /tmp/mongodb-27017.sock
2022-03-29T13:20:27.000+0300 I  -        [initandlisten] Stopping further Flow Control ticket acquisitions.
2022-03-29T13:20:27.000+0300 I  CONTROL  [initandlisten] now exiting
2022-03-29T13:20:27.000+0300 I  CONTROL  [initandlisten] shutting down with code:100

Should I use this to add permissions :

sudo chmod -R go+w /data/db

or better remove and start from scratch all the installation once again…although I have a few collections on .

Hi @Konstantina_Arnaoutaki welcome to the community!

From what I gathered on the information so far, it appears that the main issue here is permissions and consistency, as we are seeing some files under the dbpath are owned by one user (mongodb), and some other files are owned by root. This mix of ownership implies that mongod was not consistently started under one user: one time it was run as root, other times it was not.

In addition, it appears that the file locations are also not consistent, e.g. sometimes it’s under the root directory (/data/db), sometimes it’s under other directories (/home/user/mongodb, /var/lib/mongodb or similar, among others).

One particular thing I noticed is that in your initial post, the /etc/mongod.conf file contains instructions for mongod to listen to port 23654. The existence of the file mongodb-23654.sock and also mongodb-27017.sock suggested that this was changed for some reason (as @Ramachandra_Tummala pointed out earlier). This is not the standard MongoDB port, so it’s probably best to set all settings in the config files to its default values so that there are no unexpected values to deal with in the future.

Depending on your preference, I would suggest to stick to one method of running MongoDB, be it from a service, running manually, or some other method you prefer, and keep using that method throughout. It may be easier in the long run to use the existing service and fix the permission issues, but your mileage may vary.

I would suggest to:

  • Set the port setting in the /etc/mongod.conf to be 27017 instead of 23654
  • The ownership of the files under directory /var/lib/mongodb and /var/log/mongodb should be owned by mongodb user, as per the settings in /etc/mongod.conf
  • Use the service starter to start the MongoDB process (systemctl), and avoid using sudo to run mongod manually
  • If the service failed to start, please post the error message in /var/log/mongodb/mongod.log. Since this file should be owned by the mongodb user, please be careful in extracting the content of this file as using sudo incorrectly could change the ownership of this file and put us back to the same permission issues again
  • If anyone else have sudo access to this machine, please let them know not to undo all your work that was done in the previous points by running sudo mongod or change any permission in any MongoDB-related directories

Best regards
Kevin

3 Likes

thank you so much for all the above!
I have followed your instructions and have come so far here:

  • changed port to 27017 (checked firewall status also)

  • checked ownership of /var/lib/mongodb . Is it worrying that the permissions are not all the same of all the files included?

ls -l /var/lib/mongodb
total 38488
-rw------- 1 mongodb mongodb    36864 Μάρ  22 00:04 collection-0-2356690320700739995.wt
-rw------- 1 mongodb mongodb 36732928 Μάρ  22 00:04 collection-0-5563536140699528517.wt
-rw------- 1 mongodb mongodb    40960 Μάρ  22 00:04 collection-10-5563536140699528517.wt
-rw------- 1 mongodb mongodb   184320 Μάρ  22 00:04 collection-12-5563536140699528517.wt
-rw------- 1 mongodb mongodb    36864 Μάρ  22 00:04 collection-14-5563536140699528517.wt
-rw------- 1 mongodb mongodb   532480 Μάρ  22 00:04 collection-20-5563536140699528517.wt
-rw------- 1 mongodb mongodb    36864 Μάρ  22 00:04 collection-2-2356690320700739995.wt
-rw------- 1 mongodb mongodb   307200 Μάρ  22 00:04 collection-2-5563536140699528517.wt
-rw------- 1 mongodb mongodb    24576 Μάρ  22 00:04 collection-4-2356690320700739995.wt
-rw------- 1 mongodb mongodb   114688 Μάρ  22 00:04 collection-4-5563536140699528517.wt
-rw------- 1 mongodb mongodb   294912 Μάρ  22 00:04 collection-6-5563536140699528517.wt
-rw------- 1 mongodb mongodb    36864 Μάρ  22 00:04 collection-8-2356690320700739995.wt
-rw------- 1 mongodb mongodb   172032 Μάρ  22 00:04 collection-8-5563536140699528517.wt
drwx------ 2 mongodb mongodb     4096 Μάρ  21 23:26 diagnostic.data
-rw------- 1 mongodb mongodb    36864 Νοέ  17 10:42 index-10-2356690320700739995.wt
-rw------- 1 mongodb mongodb    24576 Νοέ  17 12:02 index-11-5563536140699528517.wt
-rw------- 1 mongodb mongodb    36864 Μάρ  22 00:04 index-1-2356690320700739995.wt
-rw------- 1 mongodb mongodb    24576 Νοέ  17 12:02 index-13-5563536140699528517.wt
-rw------- 1 mongodb mongodb    36864 Νοέ  23 21:45 index-15-5563536140699528517.wt
-rw------- 1 mongodb mongodb   180224 Νοέ  17 11:55 index-1-5563536140699528517.wt
-rw------- 1 mongodb mongodb    49152 Νοέ  23 11:26 index-21-5563536140699528517.wt
-rw------- 1 mongodb mongodb    36864 Μάρ  22 00:04 index-3-2356690320700739995.wt
-rw------- 1 mongodb mongodb    49152 Νοέ  17 12:00 index-3-5563536140699528517.wt
-rw------- 1 mongodb mongodb    24576 Μάρ  22 00:04 index-5-2356690320700739995.wt
-rw------- 1 mongodb mongodb    20480 Νοέ  17 12:00 index-5-5563536140699528517.wt
-rw------- 1 mongodb mongodb    12288 Μάρ  22 00:04 index-6-2356690320700739995.wt
-rw------- 1 mongodb mongodb    49152 Νοέ  17 12:01 index-7-5563536140699528517.wt
-rw------- 1 mongodb mongodb    36864 Νοέ  17 10:41 index-9-2356690320700739995.wt
-rw------- 1 mongodb mongodb    53248 Νοέ  17 12:01 index-9-5563536140699528517.wt
drwx------ 2 mongodb mongodb     4096 Μάρ  29 17:45 journal
-rw------- 1 mongodb mongodb    36864 Μάρ  22 00:04 _mdb_catalog.wt
-rw------- 1 mongodb mongodb        0 Μάρ  27 20:50 mongod.lock
-rw------- 1 mongodb mongodb    36864 Μάρ  22 00:04 sizeStorer.wt
-rw------- 1 mongodb mongodb      114 Νοέ  16 21:08 storage.bson
-rw------- 1 mongodb mongodb       44 Νοέ  16 21:08 WiredTiger
-rw------- 1 mongodb mongodb     4096 Μάρ  21 23:26 WiredTigerLAS.wt
-rw------- 1 mongodb mongodb       21 Μάρ  27 20:50 WiredTiger.lock
-rw------- 1 mongodb mongodb     1190 Μάρ  22 00:04 WiredTiger.turtle
-rw------- 1 mongodb mongodb    73728 Μάρ  29 17:45 WiredTiger.wt
  • checked ownership of /var/log/mongodb
    -rw------- 1 mongodb mongodb 41533 Μάρ 29 17:45 /var/log/mongodb/mongod.log

  • used systemctl start mongod to start mongod

  • I tried vim /var/log/mongodb/mongod.log but got Permission denied,so I used sudo vim /var/log/mongodb/mongod.log and got the below:

2022-03-29T18:01:46.885+0300 I  CONTROL  [initandlisten] options: { config: "/etc/mongod.conf", net: { bindIp: "0.0.0.0", port: 27017 }, processManagement: { timeZoneInfo: "/usr/share/zoneinfo" }, security: { authorization: "enabled" }, storage: { dbPath: "/var/lib/mongodb", journal: { enabled: true } }, systemLog: { destination: "file", logAppend: true, path: "/var/log/mongodb/mongod.log" } }
2022-03-29T18:01:46.885+0300 I  STORAGE  [initandlisten] Detected data files in /var/lib/mongodb created by the 'wiredTiger' storage engine, so setting the active storage engine to 'wiredTiger'.
2022-03-29T18:01:46.885+0300 I  STORAGE  [initandlisten]
2022-03-29T18:01:46.885+0300 I  STORAGE  [initandlisten] ** WARNING: Using the XFS filesystem is strongly recommended with the WiredTiger storage engine
2022-03-29T18:01:46.885+0300 I  STORAGE  [initandlisten] **          See http://dochub.mongodb.org/core/prodnotes-filesystem
2022-03-29T18:01:46.885+0300 I  STORAGE  [initandlisten] wiredtiger_open config: create,cache_size=1463M,cache_overflow=(file_max=0M),session_max=33000,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),statistics_log=(wait=0),verbose=[recovery_progress,checkpoint_progress],
2022-03-29T18:01:48.128+0300 E  STORAGE  [initandlisten] WiredTiger error (2) [1648566108:128072][4214:0x7fc881fbcb00], txn-recover: __posix_open_file, 712: /var/lib/mongodb/journal/WiredTigerLog.0000000015: handle-open: open: No such file or directory Raw: [1648566108:128072][4214:0x7fc881fbcb00], txn-recover: __posix_open_file, 712: /var/lib/mongodb/journal/WiredTigerLog.0000000015: handle-open: open: No such file or directory
2022-03-29T18:01:48.128+0300 E  STORAGE  [initandlisten] WiredTiger error (2) [1648566108:128318][4214:0x7fc881fbcb00], txn-recover: __wt_log_scan, 2625: WiredTiger is unable to read the recovery log.: No such file or directory Raw: [1648566108:128318][4214:0x7fc881fbcb00], txn-recover: __wt_log_scan, 2625: WiredTiger is unable to read the recovery log.: No such file or directory
2022-03-29T18:01:48.128+0300 E  STORAGE  [initandlisten] WiredTiger error (2) [1648566108:128374][4214:0x7fc881fbcb00], txn-recover: __wt_log_scan, 2628: This may be due to the log files being encrypted, being from an older version or due to corruption on disk: No such file or directory Raw: [1648566108:128374][4214:0x7fc881fbcb00], txn-recover: __wt_log_scan, 2628: This may be due to the log files being encrypted, being from an older version or due to corruption on disk: No such file or directory
2022-03-29T18:01:48.128+0300 E  STORAGE  [initandlisten] WiredTiger error (2) [1648566108:128445][4214:0x7fc881fbcb00], txn-recover: __wt_log_scan, 2631: You should confirm that you have opened the database with the correct options including all encryption and compression options: No such file or directory Raw: [1648566108:128445][4214:0x7fc881fbcb00], txn-recover: __wt_log_scan, 2631: You should confirm that you have opened the database with the correct options including all encryption and compression options: No such file or directory
2022-03-29T18:01:48.128+0300 E  STORAGE  [initandlisten] WiredTiger error (-31802) [1648566108:128500][4214:0x7fc881fbcb00], txn-recover: __wt_txn_recover, 770: Recovery failed: WT_ERROR: non-specific WiredTiger error Raw: [1648566108:128500][4214:0x7fc881fbcb00], txn-recover: __wt_txn_recover, 770: Recovery failed: WT_ERROR: non-specific WiredTiger error
2022-03-29T18:01:48.143+0300 E  STORAGE  [initandlisten] WiredTiger error (0) [1648566108:143758][4214:0x7fc881fbcb00], connection: __wt_cache_destroy, 386: cache server: exiting with 1 pages in memory and 0 pages evicted Raw: [1648566108:143758][4214:0x7fc881fbcb00], connection: __wt_cache_destroy, 386: cache server: exiting with 1 pages in memory and 0 pages evicted
2022-03-29T18:01:48.143+0300 E  STORAGE  [initandlisten] WiredTiger error (0) [1648566108:143906][4214:0x7fc881fbcb00], connection: __wt_cache_destroy, 391: cache server: exiting with 78 image bytes in memory Raw: [1648566108:143906][4214:0x7fc881fbcb00], connection: __wt_cache_destroy, 391: cache server: exiting with 78 image bytes in memory
2022-03-29T18:01:48.143+0300 E  STORAGE  [initandlisten] WiredTiger error (0) [1648566108:143949][4214:0x7fc881fbcb00], connection: __wt_cache_destroy, 395: cache server: exiting with 302 bytes in memory Raw: [1648566108:143949][4214:0x7fc881fbcb00], connection: __wt_cache_destroy, 395: cache server: exiting with 302 bytes in memory

is there any other way to access logs without sudo?

Hi @Konstantina_Arnaoutaki

By permission, do you mean that some are rw and some are drwx? That’s not a problem. drwx basically means that it’s a directory that you can go into (as the mongodb user).

No, since the file is owned by mongodb user, and I assume you’re not logging in as that user. What I would suggest though, is to limit the risk of writing out that file and thus changing its permission by using less instead of vim. less will open a file as read only, while vim will usually not.

There are further errors that need fixing from the log you posted:

WiredTiger error (2) [1648566108:128072][4214:0x7fc881fbcb00], txn-recover: __posix_open_file, 712: /var/lib/mongodb/journal/WiredTigerLog.0000000015: handle-open: open: No such file or directory

Could you confirm if this file /var/lib/mongodb/journal/WiredTigerLog.0000000015 is missing or not?

And also:

You should confirm that you have opened the database with the correct options including all encryption and compression option

If this error is genuine (and not the indirect result of the previous error), this is trickier. Since we established that the mongod.conf file was changed multiple times, if there are truly extra parameters to WiredTiger that we don’t know about, it’s difficult to replicate that parameters now.

Best regards
Kevin

1 Like

Hi again @kevinadi thank you so much for all the very well-explained tips so far!
Regarding the current status I have the below as per your questions:

I used the below command

 test -e /var/lib/mongodb/journal/WiredTigerLog.0000000015 && echo file exists || echo file not found
file not found

so it seems missing.

Well, I am the only person handling this database, hence working on the mongod.conf file.
I had once changed the mongod.conf setting by uncommenting the below
# engine: wiredTiger
and then commenting it again but I have not used something more as extra parameters to WiredTiger, is there any way to go on with that?

Hi @Konstantina_Arnaoutaki

I’m afraid we’re in a bit of a jam. From the information we’ve seen so far, it appears that the dbpath is a bit messed up.

The message /var/lib/mongodb/journal/WiredTigerLog.0000000015: handle-open: open: No such file or directory we saw earlier basically means that WiredTiger requires that file to be present to be able to start successfully. The fact that this vital file is missing seems to suggest that the dbpath was tampered with in unexpected ways, unfortunately.

Thus looking at the information so far, I would suggest that the best way to get MongoDB to start again is to start from scratch with an empty dbpath, and restore from a last known good backup. I’m sorry it has come to this, but I don’t see a productive way forward at this point other than a fresh start.

Best regards
Kevin

1 Like