CentOS 7, MongoDB 3.4.2: Mongod starts from command line but not as service

808 views
Skip to first unread message

Thomas J. Girsch

unread,
Mar 1, 2017, 3:42:52 PM3/1/17
to mongodb-user
When I start mongod from the command line (as user mongod) the service starts up correctly. But when I try to start it as a service using systemctl, it fails.

Command line as user mongod:

$ mongod --config /etc/mongod.conf
about to fork child process, waiting until server is ready for connections.
forked process: 10274
child process started successfully, parent exiting

From the log:

2017-03-01T14:16:23.709-0500 I CONTROL  [main] ***** SERVER RESTARTED *****
2017-03-01T14:16:23.718-0500 I CONTROL  [initandlisten] MongoDB starting : pid=10274 port=27017 dbpath=/data/db 64-bit host=aemongo21.aemaine.com
2017-03-01T14:16:23.718-0500 I CONTROL  [initandlisten] db version v3.4.2
2017-03-01T14:16:23.719-0500 I CONTROL  [initandlisten] git version: 3f76e40c105fc223b3e5aac3e20dcd026b83b38b
2017-03-01T14:16:23.719-0500 I CONTROL  [initandlisten] OpenSSL version: OpenSSL 1.0.1e-fips 11 Feb 2013
2017-03-01T14:16:23.719-0500 I CONTROL  [initandlisten] allocator: tcmalloc
2017-03-01T14:16:23.719-0500 I CONTROL  [initandlisten] modules: none
2017-03-01T14:16:23.719-0500 I CONTROL  [initandlisten] build environment:
2017-03-01T14:16:23.719-0500 I CONTROL  [initandlisten]     distmod: rhel70
2017-03-01T14:16:23.719-0500 I CONTROL  [initandlisten]     distarch: x86_64
2017-03-01T14:16:23.719-0500 I CONTROL  [initandlisten]     target_arch: x86_64
2017-03-01T14:16:23.719-0500 I CONTROL  [initandlisten] options: { config: "/etc/mongod.conf", net: { bindIp: "127.0.0.1,aemongo21.aemaine.com", port: 27017 }, processManagement: { fork: true, pidFilePath: "/var/run/mongodb/mongod.pid" }, replication: { replSetName: "EDS1" }, storage: { dbPath: "/data/db", engine: "wiredTiger", journal: { enabled: true }, wiredTiger: { engineConfig: { directoryForIndexes: true }, indexConfig: { prefixCompression: true } } }, systemLog: { destination: "file", logAppend: true, path: "/var/log/mongodb/mongod.log" } }
2017-03-01T14:16:23.743-0500 I STORAGE  [initandlisten] wiredtiger_open config: create,cache_size=1383M,session_max=20000,eviction=(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),
2017-03-01T14:16:24.430-0500 I STORAGE  [initandlisten] Starting WiredTigerRecordStoreThread local.oplog.rs
2017-03-01T14:16:24.431-0500 I STORAGE  [initandlisten] The size storer reports that the oplog contains 1203025 records totaling to 3495528288 bytes
2017-03-01T14:16:24.438-0500 I STORAGE  [initandlisten] Sampling from the oplog between Jan 16 07:57:55:2 and Mar  1 14:09:03:2 to determine where to place markers for truncation
2017-03-01T14:16:24.438-0500 I STORAGE  [initandlisten] Taking 1004 samples and assuming that each section of oplog contains approximately 11978 records totaling to 34803464 bytes
[...etc...]

$ sudo systemctl start mongod
[returns immediately with no output]

From the log:

2017-03-01T14:18:22.301-0500 I CONTROL  [main] ***** SERVER RESTARTED *****
2017-03-01T14:18:22.308-0500 I CONTROL  [initandlisten] MongoDB starting : pid=10385 port=27017 dbpath=/data/db 64-bit host=aemongo21.aemaine.com
2017-03-01T14:18:22.308-0500 I CONTROL  [initandlisten] db version v3.4.2
2017-03-01T14:18:22.308-0500 I CONTROL  [initandlisten] git version: 3f76e40c105fc223b3e5aac3e20dcd026b83b38b
2017-03-01T14:18:22.308-0500 I CONTROL  [initandlisten] OpenSSL version: OpenSSL 1.0.1e-fips 11 Feb 2013
2017-03-01T14:18:22.308-0500 I CONTROL  [initandlisten] allocator: tcmalloc
2017-03-01T14:18:22.308-0500 I CONTROL  [initandlisten] modules: none
2017-03-01T14:18:22.308-0500 I CONTROL  [initandlisten] build environment:
2017-03-01T14:18:22.308-0500 I CONTROL  [initandlisten]     distmod: rhel70
2017-03-01T14:18:22.308-0500 I CONTROL  [initandlisten]     distarch: x86_64
2017-03-01T14:18:22.308-0500 I CONTROL  [initandlisten]     target_arch: x86_64
2017-03-01T14:18:22.308-0500 I CONTROL  [initandlisten] options: { config: "/etc/mongod.conf", net: { bindIp: "127.0.0.1,aemongo21.aemaine.com", port: 27017 }, processManagement: { fork: true, pidFilePath: "/var/run/mongodb/mongod.pid" }, replication: { replSetName: "EDS1" }, storage: { dbPath: "/data/db", engine: "wiredTiger", journal: { enabled: true }, wiredTiger: { engineConfig: { directoryForIndexes: true }, indexConfig: { prefixCompression: true } } }, systemLog: { destination: "file", logAppend: true, path: "/var/log/mongodb/mongod.log" } }
2017-03-01T14:18:22.335-0500 I STORAGE  [initandlisten] wiredtiger_open config: create,cache_size=1383M,session_max=20000,eviction=(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),
2017-03-01T14:18:22.335-0500 E STORAGE  [initandlisten] WiredTiger error (13) [1488395902:335659][10385:0x7f2b93ca0dc0], wiredtiger_open: /data/db/WiredTiger.turtle: file-exist: stat: Permission denied
2017-03-01T14:18:22.335-0500 I -        [initandlisten] Assertion: 28595:13: Permission denied src/mongo/db/storage/wiredtiger/wiredtiger_kv_engine.cpp 267
2017-03-01T14:18:22.335-0500 I STORAGE  [initandlisten] exception in initAndListen: 28595 13: Permission denied, terminating

2017-03-01T14:18:22.335-0500 I NETWORK  [initandlisten] shutdown: going to close listening sockets...
2017-03-01T14:18:22.335-0500 I NETWORK  [initandlisten] removing socket file: /tmp/mongodb-27017.sock
2017-03-01T14:18:22.336-0500 I NETWORK  [initandlisten] shutdown: going to flush diaglog...
2017-03-01T14:18:22.336-0500 I CONTROL  [initandlisten] now exiting
2017-03-01T14:18:22.336-0500 I CONTROL  [initandlisten] shutting down with code:100

$ ls -la /data/db/WiredTiger.turtle
-rw-rw-r--. 1 mongod mongod 944 Mar  1 14:17 /data/db/WiredTiger.turtle

Ivan Grigolon

unread,
Mar 8, 2017, 12:07:36 AM3/8/17
to mongodb-user

Hi,
        the logs are showing that there is a permission issue on the file /data/db/WiredTiger.turtle.

If I start mongod as user {{vagrant}}, in the dbpath I can see files being created with write permission only for the same owner+group.
[vagrant@localhost m]$ ls -lrt /var/lib/mongo
total 44
-rw-rw-r-- 1 vagrant vagrant   21 Mar  8 00:06 WiredTiger.lock
-rw-rw-r-- 1 vagrant vagrant   49 Mar  8 00:06 WiredTiger
-rw-rw-r-- 1 vagrant vagrant 4096 Mar  8 00:06 WiredTiger.wt
-rw-rw-r-- 1 vagrant vagrant  767 Mar  8 00:06 WiredTiger.turtle
...
If I removed the files in the folder and I started the process as a service instead, you can see that the owner is mongod (which does not have write permission in the dbpath created previously)
[vagrant@localhost m]$ ls -lrt /var/lib/mongo
total 56
-rw-r--r-- 1 mongod mongod   21 Mar  8 00:22 WiredTiger.lock
-rw-r--r-- 1 mongod mongod   49 Mar  8 00:22 WiredTiger
-rw-r--r-- 1 mongod mongod 4096 Mar  8 00:22 WiredTiger.wt
-rw-r--r-- 1 mongod mongod  842 Mar  8 00:22 WiredTiger.turtle
...
One way to fix this problem is to change the owner of the files under the dbpath folder. For example:
[vagrant@localhost m]$ sudo chown mongod:mongod /var/lib/mongo/*/*
[vagrant@localhost m]$ sudo chown mongod:mongod /var/lib/mongo/*
[vagrant@localhost m]$ ls -lrt /var/lib/mongo/*
-rw-rw-r-- 1 mongod mongod    21 Mar  8 00:38 /var/lib/mongo/WiredTiger.lock
-rw-rw-r-- 1 mongod mongod    49 Mar  8 00:38 /var/lib/mongo/WiredTiger
-rw-rw-r-- 1 mongod mongod    95 Mar  8 00:38 /var/lib/mongo/storage.bson
-rw-rw-r-- 1 mongod mongod   918 Mar  8 00:40 /var/lib/mongo/WiredTiger.turtle
...

[vagrant@localhost m]$ sudo systemctl start mongod
...
(mongod service started successfully)

Please ensure that you have a backup of all your data before manually changing anything inside the dbpath directory. Please note that in general, direct manipulation of the dbpath directory is strongly discouraged, since it could put the database into an unexpected and unrecoverable state.

You can find more information about permissions in the MongoDB documentation.

Best Regards,
Ivan

Thomas J. Girsch

unread,
Jun 6, 2017, 9:05:01 PM6/6/17
to mongodb-user
As noted in my example above, the file permissions are correct for user mongod. And the mongod.service file dictates that the startup should be run as user mongod. Yet when I run the systemctl start command, I get that permission error. Logging in as mongod directly and running the mongod command works as expected.

This leads me to believe that despite the way the service is configured, it's NOT running as user mongod.  But I can't figure out what user it might be running as. If it were running as root, it should have whatever permission it wants. So if it's not running as root, and not running as mongod, what user *is* it trying to run as when I execute the systemctl start?

Thomas J. Girsch

unread,
Jun 6, 2017, 9:47:54 PM6/6/17
to mongodb-user
With help from a friend, I was able to find the solution: selinux was messing things up. Changing selinux from "enforcing" to "permissive" mode resolved the problem.
Reply all
Reply to author
Forward
0 new messages