Debugging systemd for mongodb 3.2 on ubuntu 16.04 -- sig 15 killing

Question

I've installed mongodb-org and mongodb-org-server following the instructions on mongodb.org (though for ubuntu 14.x)

At this point running mongodb directly works;

sudo -H -u mongodb bash -c "/usr/bin/mongod -f /etc/mongod.conf"

in /var/log/mongodb.log

2016-06-15T00:57:10.718Z I NETWORK  [initandlisten] waiting for connections on port 27017

I've built out a /lib/systemd/system/mongodb.service (similar to https://gist.github.com/sgnn7/54146c8a13c8b5ca2201)

[Unit]
Description=High-performance, schema-free document-oriented database
After=syslog.target network.target

[Service]
User=mongodb
Group=mongodb
ExecStart=/usr/bin/mongod -f /etc/mongod.conf
ExecStop=/usr/bin/mongod -f /etc/mongod.conf --shutdown

[Install]
WantedBy=multi-user.target

In the mongodb.log this is the result;

2016-06-15T00:47:53.748Z I CONTROL  [initandlisten] MongoDB starting : pid=5592 port=27017 dbpath=/data/wiredtiger 64-bit host=neptune
2016-06-15T00:47:53.748Z I CONTROL  [initandlisten] db version v3.2.7
2016-06-15T00:47:53.748Z I CONTROL  [initandlisten] git version: 4249c1d2b5999ebbf1fdf3bc0e0e3b3ff5c0aaf2
2016-06-15T00:47:53.748Z I CONTROL  [initandlisten] OpenSSL version: OpenSSL 1.0.2g-fips  1 Mar 2016
2016-06-15T00:47:53.748Z I CONTROL  [initandlisten] allocator: tcmalloc
2016-06-15T00:47:53.748Z I CONTROL  [initandlisten] modules: none
2016-06-15T00:47:53.748Z I CONTROL  [initandlisten] build environment:
2016-06-15T00:47:53.748Z I CONTROL  [initandlisten]     distmod: ubuntu1404
2016-06-15T00:47:53.748Z I CONTROL  [initandlisten]     distarch: x86_64
2016-06-15T00:47:53.748Z I CONTROL  [initandlisten]     target_arch: x86_64
2016-06-15T00:47:53.748Z I CONTROL  [initandlisten] options: { config: "/etc/mongod.conf", net: { bindIp: "127.0.0.1", port: 27017, unixDomainSocket: { enabled: true, filePermissions: 329, pathPrefix: "/data/wiredtiger" } }, processManagement: { fork: true, pidFilePath: "/var/run/mongodb/mongodb.pid" }, setParameter: { failIndexKeyTooLong: "false" }, storage: { dbPath: "/data/wiredtiger", directoryPerDB: true, engine: "wiredTiger", journal: { enabled: true }, wiredTiger: { collectionConfig: { blockCompressor: "snappy" }, engineConfig: { cacheSizeGB: 1, directoryForIndexes: true } } }, systemLog: { destination: "file", logAppend: true, path: "/var/log/mongodb/mongodb.log", timeStampFormat: "iso8601-utc" } }
2016-06-15T00:47:53.770Z I STORAGE  [initandlisten] wiredtiger_open config: create,cache_size=1G,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),
2016-06-15T00:47:54.257Z I CONTROL  [initandlisten] 
2016-06-15T00:47:54.257Z I CONTROL  [initandlisten] ** WARNING: /sys/kernel/mm/transparent_hugepage/enabled is 'always'.
2016-06-15T00:47:54.257Z I CONTROL  [initandlisten] **        We suggest setting it to 'never'
2016-06-15T00:47:54.257Z I CONTROL  [initandlisten] 
2016-06-15T00:47:54.257Z I CONTROL  [initandlisten] ** WARNING: /sys/kernel/mm/transparent_hugepage/defrag is 'always'.
2016-06-15T00:47:54.257Z I CONTROL  [initandlisten] **        We suggest setting it to 'never'
2016-06-15T00:47:54.257Z I CONTROL  [initandlisten] 
2016-06-15T00:47:54.270Z I FTDC     [initandlisten] Initializing full-time diagnostic data capture with directory '/data/wiredtiger/diagnostic.data'
2016-06-15T00:47:54.271Z I NETWORK  [HostnameCanonicalizationWorker] Starting hostname canonicalization worker
2016-06-15T00:47:54.271Z I NETWORK  [initandlisten] waiting for connections on port 27017
2016-06-15T00:47:54.305Z I CONTROL  [main] ***** SERVER RESTARTED *****
2016-06-15T00:47:54.310Z I CONTROL  [signalProcessingThread] got signal 15 (Terminated), will terminate after current cmd ends
2016-06-15T00:47:54.310Z I FTDC     [signalProcessingThread] Shutting down full-time diagnostic data capture
2016-06-15T00:47:54.310Z I CONTROL  [signalProcessingThread] now exiting
2016-06-15T00:47:54.310Z I NETWORK  [signalProcessingThread] shutdown: going to close listening sockets...
2016-06-15T00:47:54.310Z I NETWORK  [signalProcessingThread] closing listening socket: 6
2016-06-15T00:47:54.310Z I NETWORK  [signalProcessingThread] closing listening socket: 7
2016-06-15T00:47:54.310Z I NETWORK  [signalProcessingThread] removing socket file: /data/wiredtiger/mongodb-27017.sock
2016-06-15T00:47:54.310Z I NETWORK  [signalProcessingThread] shutdown: going to flush diaglog...
2016-06-15T00:47:54.310Z I NETWORK  [signalProcessingThread] shutdown: going to close sockets...
2016-06-15T00:47:54.310Z I STORAGE  [signalProcessingThread] WiredTigerKVEngine shutting down
 2016-06-15T00:47:54.436Z I STORAGE  [signalProcessingThread] shutdown: removing fs lock...
 2016-06-15T00:47:54.436Z I CONTROL  [signalProcessingThread] dbexit:  rc: 0

As part of setting up the systemd service I ran

systemctl --system daemon-reload
systemctl unmask mongodb.service
systemctl enable mongodb.service
systemctl start mongodb.service

All data, logs and run directories for mongodb are owned by mongodb.mongodb - and I've created a mongodb subdir of /var/run (owned be mongodb)

What is killing the systemd version immediately after startup?

Anything else I can try? (I've tried 'LimitNOFILE=64000' in [Service])

Thanks!

Solution 1

processManagement: { fork: true, pidFilePath: "/var/run/mongodb/mongodb.pid" }

This is your problem. processManagement.fork should be false (which is also the default) in your mongod.conf file.

Because it is true, mongod is completely unnecessarily forking. Because it is forking, systemd is thinking that the main dæmon process has exited unexpectedly, and it is cleaning up the service back to its stopped state. It does this by explicitly terminating all of the child processes left around by the service. Hence the signal.

This is a readiness protocol mismatch. MongoDB does not speak the forking readiness protocol, and it is not correct to change the systemd service unit to say that it does. It is, rather, correct to change the configuration of MongoDB so that it does not completely unnecessarily fork.

Further reading

• mongodb.service. mongodb package source. Launchpad.
• "linux distributions using systemd". UNIX ulimit Settings. mongoDB documentation.
• https://unix.stackexchange.com/a/187540

Solution 2

Typically - after walking away for 20mins - I came back to something I've been working at for hours and found a solution.

Type=forking

Needed in the /lib/systemd/system/mongodb.service file. Which now looks like;

[Unit]
Description=High-performance, schema-free document-oriented database
After=syslog.target network.target

[Service]
Type=forking
User=mongodb
Group=mongodb
ExecStart=/usr/bin/mongod -f /etc/mongod.conf
ExecStop=/usr/bin/mongod -f /etc/mongod.conf --shutdown

[Install]
WantedBy=multi-user.target

Hope that helps someone else out!

Comments

[Ali W]

See the accepted answer - probably best not to have a forking mongodb process - though this does work if for some reason you have to.