[SERVER-21176] Mongo not starting after upgrading to 3.0.7: extraneous permissions in journal file or group ownership problem Created: 27/Oct/15  Updated: 28/Oct/15  Resolved: 28/Oct/15

Status: Closed
Project: Core Server
Component/s: WiredTiger
Affects Version/s: 3.0.7
Fix Version/s: None

Type: Bug Priority: Major - P3
Reporter: Teemu Sirkiä Assignee: Unassigned
Resolution: Done Votes: 0
Labels: None
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified
Environment:

Linux 3.13.0-66-generic #108-Ubuntu SMP Wed Oct 7 15:20:27 UTC 2015 x86_64 x86_64 x86_64 GNU/Linux


Participants:

 Description   

I'm using MongoDB 3.0.6 with WiredTiger. I tried to update the mongodb-org-server package in Ubuntu 14.04 to version 3.0.7. Installation completes but after adding engine: wiredShark to the config file, the server won't start as a daemon. It complains:

2015-10-28T00:39:11.701+0200 I STORAGE  [initandlisten] wiredtiger_open config: create,cache_size=1G,session_max=20000,eviction=(threads_max=4),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),
2015-10-28T00:39:11.731+0200 E STORAGE  [initandlisten] WiredTiger (13) [1445985551:731389][3342:0x7f4f6e6ffbc0]: /var/lib/mongodb/journal/WiredTigerLog.0000000704: Permission denied
2015-10-28T00:39:11.735+0200 I -        [initandlisten] Assertion: 28595:13: Permission denied
2015-10-28T00:39:11.735+0200 I STORAGE  [initandlisten] exception in initAndListen: 28595 13: Permission denied, terminating
2015-10-28T00:39:11.735+0200 I CONTROL  [initandlisten] dbexit:  rc: 100

Starting MongoDB in terminal with command "sudo mongod --config /etc/mongod.conf" everything works.

All file permissions should be OK, files and directories belong to mongodb:mongodb.

As I wasn't able to run MongoDB as a daemon anymore, I had to rollback to 3.0.6 and now everything works again. What might be the problem here?



 Comments   
Comment by Teemu Sirkiä [ 28/Oct/15 ]

Thank you for your help! Yes, it remains as a mystery what happened directly after apt-get install, why the daemon failed to start after editing the mongod.conf. Of course it tried to start before that but that attempt failed because there were those WiredTiger files in the db directory.

 I STORAGE  [initandlisten] exception in initAndListen: 28574 Cannot start server. Detected data files in /var/lib/mongodb created by storage engine 'wiredTiger'. The configured storage engine is 'mmapv1'., terminating

Maybe that attempt made something that caused problems after the correct engine was set. I think this problem was originally caused because the 3.0.6 used INI file configuration and 3.0.7 YAML. I selected to ovewrite the existing config file which caused this attempt to start with the wrong database engine.

But if anyone else gets this same problem, it is very good that this ticket is here and it contains a hint how to resolve the situation. Thanks again!

BR,
Teemu

Comment by Ramon Fernandez Marina [ 28/Oct/15 ]

Thanks for running the experiment ttsirkia, much appreciated. The results confirm the group ownership is not a real issue for users upgrading to 3.0.7.

When mongod was run as root the WiredTigerLog.0000000704 journal file was used for recovery and later removed, so when 3.0.6 was started that file was no longer there.

Given that your 3.0.7 installation is up and running, and since we don't know what permissions that file was created with or how this happened we're going to close this ticket. If this happens again I'd suggest running ls -laR /var/lib/mongodb before attempting anything else.

Thanks again for the help with the troubleshooting.

Regards,
Ramón.

Comment by Teemu Sirkiä [ 28/Oct/15 ]

Yes, it still works after changing the group to nogroup. I cannot anymore investigate how the permissions were yesterday. As I wrote, mongod was running a short time as root because that was the only way to get it running. But before I tested that, it was running (or tried to run) as a daemon and it didn't work. Instantly after downgrading to 3.0.6, the daemon started to work without changing any permissions.

If there was I file with wrong permissions, why 3.0.6 started after downgrading?

Comment by Ramon Fernandez Marina [ 28/Oct/15 ]

Thanks for the quick feedback ttsirkia, and glad to hear you got 3.0.7 running. Group membership should not be an issue here, so I'm wondering if the /var/lib/mongodb/journal/WiredTigerLog.0000000704 file was created by a mongod running as root at some point.

I'd like to ask you to try the following:

sudo /etc/init.d/mongod stop
sudo chgrp -R nogroup /var/lib/mongodb
sudo /etc/init.d/mongod start

and see if mongod starts. If it doesn't then I would argue you've found a bug regarding group ownership and we should investigate it.

Could you please try the experiment above so we can determine if this is a bug in the server?

Thanks,
Ramón.

Comment by Teemu Sirkiä [ 28/Oct/15 ]

Thanks for the tip. This seems to work! Maybe there might be mention about this in the release notes? This is quite nasty thing that it won't start after the upgrade process without changing permissions.

Comment by Ramon Fernandez Marina [ 28/Oct/15 ]

Thanks for uploading the requested information ttsirkia. This may be related to SERVER-18581, which was fixed in 3.0.7: the mongod process no longer belongs to group nogroup but to the mongodb group, so the fact that some of the files under dbpath belong to group nogroup may be the issue here.

Could you please try to chgrp -R mongodb /var/lib/mongodb and fire up 3.0.7 again?

Thanks,
Ramón.

Comment by Teemu Sirkiä [ 27/Oct/15 ]

The config file was that I tried with the version 3.0.7. The directory listing is the current listing in use with the version 3.0.6.

BR,
Teemu

Comment by Teemu Sirkiä [ 27/Oct/15 ]

mongod.conf

# 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: wiredTiger
#  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
 
 
#processManagement:
 
#security:
 
#operationProfiling:
 
#replication:
 
#sharding:
 
## Enterprise-Only Options:
 
#auditLog:
 
#snmp:

ls -laR /var/lib/mongodb
 
/var/lib/mongodb:
total 1714708
drwxr-xr-x  3 mongodb mongodb       4096 Oct 28 01:30 .
drwxr-xr-x 45 root    root          4096 Apr  8  2015 ..
-rw-r--r--  1 mongodb mongodb      49152 Oct 28 00:41 collection-0--2005206986105871875.wt
-rw-r--r--  1 mongodb mongodb      36864 Oct 28 00:42 collection-0--5875186918771494046.wt
-rw-r--r--  1 mongodb mongodb      69632 Oct 28 00:41 collection-126--5875186918771494046.wt
-rw-r--r--  1 mongodb mongodb      36864 Oct 28 00:41 collection-129--5875186918771494046.wt
-rw-r--r--  1 mongodb mongodb      36864 Oct 28 00:41 collection-132--5875186918771494046.wt
-rw-r--r--  1 mongodb mongodb      36864 Oct 28 00:41 collection-135--5875186918771494046.wt
-rw-r--r--  1 mongodb mongodb    4620288 Oct 28 00:41 collection-138--5875186918771494046.wt
-rw-r--r--  1 mongodb mongodb      36864 Oct 28 00:41 collection-144--5875186918771494046.wt
-rw-r--r--  1 mongodb mongodb      61440 Oct 28 00:41 collection-147--5875186918771494046.wt
-rw-r--r--  1 mongodb mongodb      36864 Oct 28 00:41 collection-150--5875186918771494046.wt
-rw-r--r--  1 mongodb mongodb      90112 Oct 28 00:41 collection-153--5875186918771494046.wt
-rw-r--r--  1 mongodb mongodb      16384 Oct 28 00:41 collection-156--5875186918771494046.wt
-rw-r--r--  1 mongodb mongodb      86016 Oct 28 00:41 collection-162--5875186918771494046.wt
-rw-r--r--  1 mongodb mongodb      36864 Oct 28 00:41 collection-188--5875186918771494046.wt
-rw-r--r--  1 mongodb mongodb      36864 Oct 28 00:41 collection-190--5875186918771494046.wt
-rw-r--r--  1 mongodb mongodb 1073737728 Oct 28 01:30 collection-21--6696030056334682656.wt
-rw-r--r--  1 mongodb mongodb   90992640 Oct 28 01:30 collection-24--6696030056334682656.wt
-rw-r--r--  1 mongodb mongodb      36864 Oct 28 00:41 collection-3--6696030056334682656.wt
-rw-r--r--  1 mongodb mongodb      16384 Oct 28 00:41 collection-9--6696030056334682656.wt
-rw-r--r--  1 mongodb mongodb      16384 Oct 27 23:47 index-10--6696030056334682656.wt
-rw-r--r--  1 mongodb mongodb      16384 Aug 24 01:36 index-11--6696030056334682656.wt
-rw-r--r--  1 mongodb mongodb      36864 Oct 27 23:47 index-1--2005206986105871875.wt
-rw-r--r--  1 mongodb mongodb      36864 Oct 27 23:47 index-127--5875186918771494046.wt
-rw-r--r--  1 mongodb mongodb      36864 Oct 28 00:43 index-128--5875186918771494046.wt
-rw-r--r--  1 mongodb mongodb      36864 Oct 27 23:47 index-130--5875186918771494046.wt
-rw-r--r--  1 mongodb mongodb      36864 Oct 28 00:43 index-131--5875186918771494046.wt
-rw-r--r--  1 mongodb mongodb      36864 Oct 27 23:47 index-133--5875186918771494046.wt
-rw-r--r--  1 mongodb mongodb      36864 Oct 27 23:47 index-134--5875186918771494046.wt
-rw-r--r--  1 mongodb mongodb      36864 Oct 28 00:38 index-136--5875186918771494046.wt
-rw-r--r--  1 mongodb mongodb      36864 Oct 27 23:47 index-137--5875186918771494046.wt
-rw-r--r--  1 mongodb mongodb     290816 Oct 28 00:38 index-139--5875186918771494046.wt
-rw-r--r--  1 mongodb mongodb     114688 Oct 27 23:47 index-140--5875186918771494046.wt
-rw-r--r--  1 mongodb mongodb      36864 Oct 27 23:47 index-145--5875186918771494046.wt
-rw-r--r--  1 mongodb mongodb      36864 Oct 27 23:47 index-146--5875186918771494046.wt
-rw-r--r--  1 mongodb mongodb      36864 Oct 28 00:42 index-148--5875186918771494046.wt
-rw-r--r--  1 mongodb mongodb      36864 Oct 27 23:47 index-149--5875186918771494046.wt
-rw-r--r--  1 mongodb mongodb      36864 Oct 27 23:47 index-151--5875186918771494046.wt
-rw-r--r--  1 mongodb mongodb      36864 Oct 27 23:47 index-152--5875186918771494046.wt
-rw-r--r--  1 mongodb mongodb      36864 Oct 28 00:42 index-154--5875186918771494046.wt
-rw-r--r--  1 mongodb mongodb      45056 Oct 28 00:46 index-155--5875186918771494046.wt
-rw-r--r--  1 mongodb mongodb      16384 Oct 27 23:47 index-157--5875186918771494046.wt
-rw-r--r--  1 mongodb mongodb      16384 Oct 28 00:41 index-158--5875186918771494046.wt
-rw-r--r--  1 mongodb mongodb      36864 Oct 28 00:42 index-1--5875186918771494046.wt
-rw-r--r--  1 mongodb mongodb      36864 Oct 27 23:47 index-163--5875186918771494046.wt
-rw-r--r--  1 mongodb mongodb      36864 Oct 27 23:47 index-164--5875186918771494046.wt
-rw-r--r--  1 mongodb mongodb      36864 Oct 27 23:47 index-166--5875186918771494046.wt
-rw-r--r--  1 mongodb mongodb     147456 Oct 27 23:47 index-167--5875186918771494046.wt
-rw-r--r--  1 mongodb mongodb      36864 Oct 27 23:47 index-168--5875186918771494046.wt
-rw-r--r--  1 mongodb mongodb      36864 Oct 28 00:43 index-169--5875186918771494046.wt
-rw-r--r--  1 mongodb mongodb      36864 Oct 28 00:42 index-170--5875186918771494046.wt
-rw-r--r--  1 mongodb mongodb      45056 Oct 28 00:43 index-171--5875186918771494046.wt
-rw-r--r--  1 mongodb mongodb      36864 Oct 27 23:47 index-173--5875186918771494046.wt
-rw-r--r--  1 mongodb mongodb     114688 Oct 27 23:47 index-175--5875186918771494046.wt
-rw-r--r--  1 mongodb mongodb      45056 Aug 24 01:36 index-176--5875186918771494046.wt
-rw-r--r--  1 mongodb mongodb      36864 Oct 27 23:47 index-177--5875186918771494046.wt
-rw-r--r--  1 mongodb mongodb     348160 Oct 28 00:42 index-180--5875186918771494046.wt
-rw-r--r--  1 mongodb mongodb      36864 Oct 27 23:47 index-181--5875186918771494046.wt
-rw-r--r--  1 mongodb mongodb     147456 Oct 27 23:47 index-184--5875186918771494046.wt
-rw-r--r--  1 mongodb mongodb      36864 Oct 27 23:47 index-189--5875186918771494046.wt
-rw-r--r--  1 mongodb mongodb      36864 Oct 27 23:47 index-191--5875186918771494046.wt
-rw-r--r--  1 mongodb mongodb      36864 Oct 28 00:42 index-192--5875186918771494046.wt
-rw-r--r--  1 mongodb mongodb      36864 Oct 27 23:47 index-2--2005206986105871875.wt
-rw-r--r--  1 mongodb mongodb   73519104 Oct 28 01:16 index-22--6696030056334682656.wt
-rw-r--r--  1 mongodb mongodb   27238400 Oct 28 01:16 index-23--6696030056334682656.wt
-rw-r--r--  1 mongodb mongodb    3686400 Oct 28 01:16 index-25--6696030056334682656.wt
-rw-r--r--  1 mongodb mongodb    2727936 Oct 28 01:16 index-26--6696030056334682656.wt
-rw-r--r--  1 mongodb mongodb   40914944 Oct 28 01:16 index-27--6696030056334682656.wt
-rw-r--r--  1 mongodb mongodb    2744320 Oct 28 01:16 index-28--6696030056334682656.wt
-rw-r--r--  1 mongodb mongodb   94760960 Oct 28 01:16 index-29--6696030056334682656.wt
-rw-r--r--  1 mongodb mongodb    9924608 Oct 28 01:16 index-30--6696030056334682656.wt
-rw-r--r--  1 mongodb mongodb    2342912 Oct 28 01:30 index-31--6696030056334682656.wt
-rw-r--r--  1 mongodb mongodb      36864 Oct 27 23:47 index-3--2005206986105871875.wt
-rw-r--r--  1 mongodb mongodb   14364672 Oct 28 01:16 index-32--6696030056334682656.wt
-rw-r--r--  1 mongodb mongodb    3457024 Oct 28 01:16 index-33--6696030056334682656.wt
-rw-r--r--  1 mongodb mongodb    3280896 Oct 28 01:16 index-34--6696030056334682656.wt
-rw-r--r--  1 mongodb mongodb    1572864 Oct 28 01:16 index-35--6696030056334682656.wt
-rw-r--r--  1 mongodb mongodb      36864 Oct 27 23:47 index-4--6696030056334682656.wt
-rw-r--r--  1 mongodb mongodb      36864 Oct 28 00:42 index-5--6696030056334682656.wt
drwxr-xr-x  2 mongodb mongodb       4096 Oct 28 00:41 journal
-rw-------  1 mongodb mongodb   67108864 Apr 16  2015 julia.0
-rw-------  1 mongodb mongodb  134217728 Apr 16  2015 julia.1
-rw-------  1 mongodb mongodb   16777216 Apr 16  2015 julia.ns
-rw-------  1 mongodb mongodb   67108864 May 16 14:08 local.0
-rw-------  1 mongodb mongodb   16777216 May 16 14:08 local.ns
-rw-r--r--  1 mongodb mongodb      36864 Oct 28 00:41 _mdb_catalog.wt
-rwxr-xr-x  1 mongodb mongodb          5 Oct 28 00:41 mongod.lock
-rw-r--r--  1 mongodb mongodb      45056 Oct 28 01:30 sizeStorer.wt
-rw-r--r--  1 mongodb mongodb         95 Apr  8  2015 storage.bson
-rw-r--r--  1 mongodb mongodb         46 Apr  8  2015 WiredTiger
-rw-r--r--  1 mongodb mongodb        495 Apr  8  2015 WiredTiger.basecfg
-rw-r--r--  1 mongodb mongodb         21 Apr  8  2015 WiredTiger.lock
-rw-r--r--  1 mongodb nogroup        907 Oct 28 01:30 WiredTiger.turtle
-rw-r--r--  1 mongodb mongodb     237568 Oct 28 01:30 WiredTiger.wt
 
/var/lib/mongodb/journal:
total 204816
drwxr-xr-x 2 mongodb mongodb     4096 Oct 28 00:41 .
drwxr-xr-x 3 mongodb mongodb     4096 Oct 28 01:30 ..
-rw-r--r-- 1 mongodb nogroup 15335552 Oct 28 01:30 WiredTigerLog.0000000708
-rw-r--r-- 1 mongodb nogroup      128 Oct 28 00:41 WiredTigerPreplog.0000000001

Comment by Ramon Fernandez Marina [ 27/Oct/15 ]

Hi ttsirkia, can you please send us the content of your /etc/mongod.conf file?

The fact that you can run as root seems to indicate a permission problem, so we should rule that out first. Can you also send the output of ls -laR /var/lib/mongodb?

Thanks,
Ramón.

Generated at Thu Feb 08 03:56:33 UTC 2024 using Jira 9.7.1#970001-sha1:2222b88b221c4928ef0de3161136cc90c8356a66.