Failed to open "/var/log/mongodb/mongod.log"

In Lecture: Basic security: Part 2, I’m trying to run mongod -f /etc/mongod.conf but I get the following error:
F CONTROL [main] Failed global initialization: FileNotOpen: Failed to open "/var/log/mongodb/mongod.log"

Additional information:
image

I’m not sure if the permissions set for the log files are correct, but I’m able to print its content in the console.

If the process is not initiated with super user privileges, then mongod is not able to write the file.

There are two options:

  1. run as superuser (preferred)
  2. normal user

chmod 400 mongod.log is good idea for the first option, but it’s not strictly necessary.

For the second option group and user have no write permissions. So it needs chmod 444 mongod.log. But this will likely return errors, because most of other files require super user privileges.

I’d run the process as superuser using sudo <process>.


Hopefully someone will point out an error if this is not correct :slight_smile:

Hi @Santiago_Miranda ,

I tried running with super user privileges but it just quits without printing any error message, but I can see that some errors have been printed in mongod.log file, should I provide the logs ?

Are you running mongo as

sudo mongod -f  /etc/mongod.conf

?

Yes:

Are the owner and group for both files set correctly or should they be changes to the user ? I couldn’t find information regarding this.

What is the output of ls /etc/mongod.conf ?

image

# mongod.conf

# for documentation of all options, see:
#   http://docs.mongodb.org/manual/reference/configuration-options/

# Where and how to store data.
storage:
  dbPath: /var/lib/mongodb
  journal:
    enabled: true
#  engine:
#  mmapv1:
#  wiredTiger:

# where to write logging data.
systemLog:
  destination: file
  logAppend: true
  path: /var/log/mongodb/mongod.log

# network interfaces
net:
  port: 27017
  bindIp: 127.0.0.1


# how the process runs
processManagement:
  timeZoneInfo: /usr/share/zoneinfo

security:
    authorization: enabled

#operationProfiling:

#replication:

#sharding:

## Enterprise-Only Options:

#auditLog:

#snmp:

1 Like

Yes maybe include what is on the log file now.

mongod.log

2020-10-24T12:55:43.374+0100 I CONTROL  [main] ***** SERVER RESTARTED *****
2020-10-24T12:55:43.501+0100 I CONTROL  [initandlisten] MongoDB starting : pid=2608 port=27017 dbpath=/var/lib/mongodb 64-bit host=MSI
2020-10-24T12:55:43.501+0100 I CONTROL  [initandlisten] db version v3.6.8
2020-10-24T12:55:43.501+0100 I CONTROL  [initandlisten] git version: 8e540c0b6db93ce994cc548f000900bdc740f80a
2020-10-24T12:55:43.501+0100 I CONTROL  [initandlisten] OpenSSL version: OpenSSL 1.1.1g  21 Apr 2020
2020-10-24T12:55:43.501+0100 I CONTROL  [initandlisten] allocator: tcmalloc
2020-10-24T12:55:43.501+0100 I CONTROL  [initandlisten] modules: none
2020-10-24T12:55:43.501+0100 I CONTROL  [initandlisten] build environment:
2020-10-24T12:55:43.501+0100 I CONTROL  [initandlisten]     distarch: x86_64
2020-10-24T12:55:43.501+0100 I CONTROL  [initandlisten]     target_arch: x86_64
2020-10-24T12:55:43.501+0100 I CONTROL  [initandlisten] options: { config: "/etc/mongod.conf", net: { bindIp: "127.0.0.1", 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" } }
2020-10-24T12:55:43.501+0100 W -        [initandlisten] Detected unclean shutdown - /var/lib/mongodb/mongod.lock is not empty.
2020-10-24T12:55:43.502+0100 I -        [initandlisten] Detected data files in /var/lib/mongodb created by the 'wiredTiger' storage engine, so setting the active storage engine to 'wiredTiger'.
2020-10-24T12:55:43.502+0100 W STORAGE  [initandlisten] Recovering data from the last clean checkpoint.
2020-10-24T12:55:43.502+0100 I STORAGE  [initandlisten] wiredtiger_open config: create,cache_size=7603M,session_max=20000,eviction=(threads_min=4,threads_max=4),config_base=false,statistics=(fast),cache_cursors=false,compatibility=(release="3.0",require_max="3.0"),log=(enabled=true,archive=true,path=journal,compressor=snappy),file_manager=(close_idle_time=100000),statistics_log=(wait=0),verbose=(recovery_progress),2020-10-24T12:55:44.356+0100 E STORAGE  [initandlisten] WiredTiger error (-31802) [1603540544:356261][2608:0x7f8b34b90ac0], file:WiredTiger.wt, connection: unable to read root page from file:WiredTiger.wt: WT_ERROR: non-specific WiredTiger error
2020-10-24T12:55:44.356+0100 E STORAGE  [initandlisten] WiredTiger error (0) [1603540544:356397][2608:0x7f8b34b90ac0], file:WiredTiger.wt, connection: WiredTiger has failed to open its metadata
2020-10-24T12:55:44.356+0100 E STORAGE  [initandlisten] WiredTiger error (0) [1603540544:356443][2608:0x7f8b34b90ac0], file:WiredTiger.wt, connection: This may be due to the database files being encrypted, being from an older version or due to corruption on disk
2020-10-24T12:55:44.356+0100 E STORAGE  [initandlisten] WiredTiger error (0) [1603540544:356482][2608:0x7f8b34b90ac0], file:WiredTiger.wt, connection: You should confirm that you have opened the database with 
the correct options including all encryption and compression options
2020-10-24T12:55:44.358+0100 E -        [initandlisten] Assertion: 28595:-31802: WT_ERROR: non-specific WiredTiger error src/mongo/db/storage/wiredtiger/wiredtiger_kv_engine.cpp 421
2020-10-24T12:55:44.358+0100 I STORAGE  [initandlisten] exception in initAndListen: Location28595: -31802: WT_ERROR: non-specific WiredTiger error, terminating
2020-10-24T12:55:44.358+0100 I NETWORK  [initandlisten] shutdown: going to close listening sockets...
2020-10-24T12:55:44.358+0100 I NETWORK  [initandlisten] removing socket file: /tmp/mongodb-27017.sock
2020-10-24T12:55:44.360+0100 I CONTROL  [initandlisten] now exiting
2020-10-24T12:55:44.360+0100 I CONTROL  [initandlisten] shutting down with code:100

I’m looking at :

Detected unclean shutdown - /var/lib/mongodb/mongod.lock is not empty

This maybe the one causing the problem ?

Yes, probably. I’ve never seen that.

I would remove that file sudo rm /var/lib/mongodb/mongod.lock (double check the path is correct).

Never run mongodb with user root. You have to run it with user mongodb.

But for M103 you are supposed to use the IDE included in the course.

@steevej-1495 There is no other way in Ubuntu, even as a service systemctl start mongod.service it will ask to run with superuser privileges. And the user has only localhost enabled.

What exactly do you mean?

But for M103 you are supposed to use the IDE included in the course.

So I can’t follow the course on my own computer instead ?

Didn’t solve the main problem, the logs:

2020-10-24T13:24:06.496+0100 I CONTROL  [main] ***** SERVER RESTARTED *****
2020-10-24T13:24:06.640+0100 I CONTROL  [initandlisten] MongoDB starting : pid=3509 port=27017 dbpath=/var/lib/mongodb 64-bit host=MSI
2020-10-24T13:24:06.640+0100 I CONTROL  [initandlisten] db version v3.6.8
2020-10-24T13:24:06.640+0100 I CONTROL  [initandlisten] git version: 8e540c0b6db93ce994cc548f000900bdc740f80a
2020-10-24T13:24:06.640+0100 I CONTROL  [initandlisten] OpenSSL version: OpenSSL 1.1.1g  21 Apr 2020
2020-10-24T13:24:06.640+0100 I CONTROL  [initandlisten] allocator: tcmalloc
2020-10-24T13:24:06.640+0100 I CONTROL  [initandlisten] modules: none
2020-10-24T13:24:06.640+0100 I CONTROL  [initandlisten] build environment:
2020-10-24T13:24:06.640+0100 I CONTROL  [initandlisten]     distarch: x86_64
2020-10-24T13:24:06.640+0100 I CONTROL  [initandlisten]     target_arch: x86_64
2020-10-24T13:24:06.640+0100 I CONTROL  [initandlisten] options: { config: "/etc/mongod.conf", net: { bindIp: "127.0.0.1", 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" } }
2020-10-24T13:24:06.642+0100 I -        [initandlisten] Detected data files in /var/lib/mongodb created by the 'wiredTiger' storage engine, so setting the active storage engine to 'wiredTiger'.
2020-10-24T13:24:06.642+0100 I STORAGE  [initandlisten] wiredtiger_open config: create,cache_size=7603M,session_max=20000,eviction=(threads_min=4,threads_max=4),config_base=false,statistics=(fast),cache_cursors=false,compatibility=(release="3.0",require_max="3.0"),log=(enabled=true,archive=true,path=journal,compressor=snappy),file_manager=(close_idle_time=100000),statistics_log=(wait=0),verbose=(recovery_progress),2020-10-24T13:24:07.155+0100 E STORAGE  [initandlisten] WiredTiger error (-31802) [1603542247:155819][3509:0x7f7e28850ac0], file:WiredTiger.wt, connection: unable to read root page from file:WiredTiger.wt: WT_ERROR: non-specific WiredTiger error
2020-10-24T13:24:07.155+0100 E STORAGE  [initandlisten] WiredTiger error (0) [1603542247:155888][3509:0x7f7e28850ac0], file:WiredTiger.wt, connection: WiredTiger has failed to open its metadata
2020-10-24T13:24:07.155+0100 E STORAGE  [initandlisten] WiredTiger error (0) [1603542247:155908][3509:0x7f7e28850ac0], file:WiredTiger.wt, connection: This may be due to the database files being encrypted, being from an older version or due to corruption on disk
2020-10-24T13:24:07.155+0100 E STORAGE  [initandlisten] WiredTiger error (0) [1603542247:155924][3509:0x7f7e28850ac0], file:WiredTiger.wt, connection: You should confirm that you have opened the database with 
the correct options including all encryption and compression options
2020-10-24T13:24:07.156+0100 E -        [initandlisten] Assertion: 28595:-31802: WT_ERROR: non-specific WiredTiger error src/mongo/db/storage/wiredtiger/wiredtiger_kv_engine.cpp 421
2020-10-24T13:24:07.157+0100 I STORAGE  [initandlisten] exception in initAndListen: Location28595: -31802: WT_ERROR: non-specific WiredTiger error, terminating
2020-10-24T13:24:07.157+0100 I NETWORK  [initandlisten] shutdown: going to close listening sockets...
2020-10-24T13:24:07.157+0100 I NETWORK  [initandlisten] removing socket file: /tmp/mongodb-27017.sock
2020-10-24T13:24:07.158+0100 I CONTROL  [initandlisten] now exiting
2020-10-24T13:24:07.158+0100 I CONTROL  [initandlisten] shutting down with code:100

Yes you may but you have to adjust the instructions. Starting it with systemd will be in your way all the time. You have permission issues because the directories have permissions set for the mongodb user. If you want to work as another user you must change the owner ship of the directories to this user.

Yes, that’s strange. The error related to the lock file is gone, and I don’t really know what’s that storage error.

Those WiredTiger files are trickier and not sure what you’re supposed to do with them. You can find the files under the storage folder.

The good thing is, now you know where the errors are…

I would simply wipe out the directory and start from scratch.

1 Like

Well, that was it, Thanks :slight_smile: