[SERVER-33554] Can't start MongoDB Created: 28/Feb/18  Updated: 23/Mar/18  Resolved: 23/Mar/18

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

Type: Bug Priority: Major - P3
Reporter: Thunpisit Amnuaikiatloet Assignee: Dmitry Agranat
Resolution: Incomplete Votes: 0
Labels: None
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified

Operating System: ALL
Participants:

 Description   

2018-02-27T16:38:27.041+0000 I CONTROL  [main] ***** SERVER RESTARTED *****
2018-02-27T16:38:27.061+0000 I CONTROL  [initandlisten] MongoDB starting : pid=16094 port=27017 dbpath=/var/lib/mongodb 64-bit host=thunpisit
2018-02-27T16:38:27.061+0000 I CONTROL  [initandlisten] db version v3.6.3
2018-02-27T16:38:27.061+0000 I CONTROL  [initandlisten] git version: 9586e557d54ef70f9ca4b43c26892cd55257e1a5
2018-02-27T16:38:27.061+0000 I CONTROL  [initandlisten] OpenSSL version: OpenSSL 1.0.2g  1 Mar 2016
2018-02-27T16:38:27.061+0000 I CONTROL  [initandlisten] allocator: tcmalloc
2018-02-27T16:38:27.061+0000 I CONTROL  [initandlisten] modules: none
2018-02-27T16:38:27.061+0000 I CONTROL  [initandlisten] build environment:
2018-02-27T16:38:27.061+0000 I CONTROL  [initandlisten]     distmod: ubuntu1604
2018-02-27T16:38:27.061+0000 I CONTROL  [initandlisten]     distarch: x86_64
2018-02-27T16:38:27.061+0000 I CONTROL  [initandlisten]     target_arch: x86_64
2018-02-27T16:38:27.061+0000 I CONTROL  [initandlisten] options: { config: "/etc/mongod.conf", net: { bindIp: "127.0.0.1", port: 27017 }, processManagement: { timeZoneInfo: "/usr/share/zoneinfo" }, storage: { dbPath: "/var/lib/mongodb", journal: { enabled: true } }, systemLog: { destination: "file", logAppend: true, path: "/var/log/mongodb/mongod.log" } }
2018-02-27T16:38:27.061+0000 W -        [initandlisten] Detected unclean shutdown - /var/lib/mongodb/mongod.lock is not empty.
2018-02-27T16:38:27.062+0000 I -        [initandlisten] Detected data files in /var/lib/mongodb created by the 'wiredTiger' storage engine, so setting the active storage engine to 'wiredTiger'.
2018-02-27T16:38:27.062+0000 W STORAGE  [initandlisten] Recovering data from the last clean checkpoint.
2018-02-27T16:38:27.062+0000 I STORAGE  [initandlisten] 
2018-02-27T16:38:27.062+0000 I STORAGE  [initandlisten] ** WARNING: Using the XFS filesystem is strongly recommended with the WiredTiger storage engine
2018-02-27T16:38:27.062+0000 I STORAGE  [initandlisten] **          See http://dochub.mongodb.org/core/prodnotes-filesystem
2018-02-27T16:38:27.062+0000 I STORAGE  [initandlisten] wiredtiger_open config: create,cache_size=256M,session_max=20000,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),
2018-02-27T16:38:28.091+0000 I STORAGE  [initandlisten] WiredTiger message [1519749508:91476][16094:0x7f88fac071c0], txn-recover: Main recovery loop: starting at 22/256
2018-02-27T16:38:28.091+0000 I STORAGE  [initandlisten] WiredTiger message [1519749508:91787][16094:0x7f88fac071c0], txn-recover: Recovering log 22 through 23
2018-02-27T16:38:28.154+0000 I STORAGE  [initandlisten] WiredTiger message [1519749508:154468][16094:0x7f88fac071c0], txn-recover: Recovering log 23 through 23
2018-02-27T16:38:28.238+0000 I CONTROL  [initandlisten] 
2018-02-27T16:38:28.238+0000 I CONTROL  [initandlisten] ** WARNING: Access control is not enabled for the database.
2018-02-27T16:38:28.238+0000 I CONTROL  [initandlisten] **          Read and write access to data and configuration is unrestricted.
2018-02-27T16:38:28.238+0000 I CONTROL  [initandlisten] 
2018-02-27T16:38:28.248+0000 F STORAGE  [initandlisten] Unable to start up mongod due to missing featureCompatibilityVersion document.
2018-02-27T16:38:28.248+0000 F STORAGE  [initandlisten] Please run with --repair to restore the document.
2018-02-27T16:38:28.248+0000 F -        [initandlisten] Fatal Assertion 40652 at src/mongo/db/db.cpp 661
2018-02-27T16:38:28.248+0000 F -        [initandlisten] 
 
***aborting after fassert() failure



 Comments   
Comment by Kelsey Schubert [ 23/Mar/18 ]

Hi thunpisit,

We haven’t heard back from you for some time, so I’m going to mark this ticket as resolved. If this is still an issue for you, please provide additional information and we will reopen the ticket.

Regards,
Kelsey

Comment by Dmitry Agranat [ 18/Mar/18 ]

Hi thunpisit,

We still need the information requested in this comment to diagnose the problem. If this is still an issue for you, can you please provide this information?

Thanks,
Dima

Comment by Dmitry Agranat [ 14/Mar/18 ]

Hi ksemenov, please open a new ticket with a detailed issue description and provide the information I've requested in my last comment.

Thanks,
Dima

Comment by Konstantin Semenov [ 13/Mar/18 ]

I have encountered the same issue on Kubernetes when deployed with a helm chart (https://github.com/kubernetes/charts/tree/master/stable/mongodb)
When kubernetes reschedules the mongo container due to the underlying vm failure,
during write activity, the new mongo container fails with the following trail:

nami    INFO  Initializing mongodb
mongodb INFO 
mongodb INFO  ########################################################################
mongodb INFO   Installation parameters for mongodb:
mongodb INFO     Persisted data and properties have been restored.
mongodb INFO     Any input specified will not take effect.
mongodb INFO   This installation requires no credentials.
mongodb INFO  ########################################################################
mongodb INFO 
nami    INFO  mongodb successfully initialized
INFO  ==> Starting mongodb... 
INFO  ==> Starting mongod...
2018-03-13T18:41:13.840+0000 I CONTROL  [initandlisten] MongoDB starting : pid=41 port=27017 dbpath=/opt/bitnami/mongodb/data/db 64-bit host=stultified-umbrellabird-mongodb-6d45b86f77-qfrsg
2018-03-13T18:41:13.840+0000 I CONTROL  [initandlisten] db version v3.7.1
2018-03-13T18:41:13.840+0000 I CONTROL  [initandlisten] git version: 86c02f1c786ccf46f97f4561ab0ad85aed87c297
2018-03-13T18:41:13.840+0000 I CONTROL  [initandlisten] OpenSSL version: OpenSSL 1.0.1t  3 May 2016
2018-03-13T18:41:13.840+0000 I CONTROL  [initandlisten] allocator: tcmalloc
2018-03-13T18:41:13.840+0000 I CONTROL  [initandlisten] modules: none
2018-03-13T18:41:13.840+0000 I CONTROL  [initandlisten] build environment:
2018-03-13T18:41:13.840+0000 I CONTROL  [initandlisten]     distmod: debian81
2018-03-13T18:41:13.840+0000 I CONTROL  [initandlisten]     distarch: x86_64
2018-03-13T18:41:13.840+0000 I CONTROL  [initandlisten]     target_arch: x86_64
2018-03-13T18:41:13.840+0000 I CONTROL  [initandlisten] options: { config: "/opt/bitnami/mongodb/conf/mongodb.conf", net: { bindIp: "0.0.0.0", port: 27017, unixDomainSocket: { enabled: true, pathPrefix: "/opt/bitnami/mongodb/tmp" } }, processManagement: { fork: false, pidFilePath: "/opt/bitnami/mongodb/tmp/mongodb.pid" }, security: { authorization: "disabled" }, setParameter: { enableLocalhostAuthBypass: "true" }, storage: { dbPath: "/opt/bitnami/mongodb/data/db", journal: { enabled: true } }, systemLog: { destination: "file", logAppend: true, path: true } }
2018-03-13T18:41:13.840+0000 W STORAGE  [initandlisten] Detected unclean shutdown - /opt/bitnami/mongodb/data/db/mongod.lock is not empty.
2018-03-13T18:41:13.840+0000 I STORAGE  [initandlisten] Detected data files in /opt/bitnami/mongodb/data/db created by the 'wiredTiger' storage engine, so setting the active storage engine to 'wiredTiger'.
2018-03-13T18:41:13.840+0000 W STORAGE  [initandlisten] Recovering data from the last clean checkpoint.
2018-03-13T18:41:13.840+0000 I STORAGE  [initandlisten] 
2018-03-13T18:41:13.840+0000 I STORAGE  [initandlisten] ** WARNING: Using the XFS filesystem is strongly recommended with the WiredTiger storage engine
2018-03-13T18:41:13.840+0000 I STORAGE  [initandlisten] **          See http://dochub.mongodb.org/core/prodnotes-filesystem
2018-03-13T18:41:13.840+0000 I STORAGE  [initandlisten] wiredtiger_open config: create,cache_size=1463M,session_max=20000,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),
2018-03-13T18:41:14.732+0000 I STORAGE  [initandlisten] WiredTiger message [1520966474:732180][41:0x7f93f0b9aa00], txn-recover: Main recovery loop: starting at 9/256
2018-03-13T18:41:14.732+0000 I STORAGE  [initandlisten] WiredTiger message [1520966474:732623][41:0x7f93f0b9aa00], txn-recover: Recovering log 9 through 10
2018-03-13T18:41:14.802+0000 I STORAGE  [initandlisten] WiredTiger message [1520966474:802041][41:0x7f93f0b9aa00], txn-recover: Recovering log 10 through 10
2018-03-13T18:41:14.893+0000 I CONTROL  [initandlisten] 
2018-03-13T18:41:14.894+0000 I CONTROL  [initandlisten] ** NOTE: This is a development version (3.7.1) of MongoDB.
2018-03-13T18:41:14.894+0000 I CONTROL  [initandlisten] **       Not recommended for production.
2018-03-13T18:41:14.894+0000 I CONTROL  [initandlisten] 
2018-03-13T18:41:14.894+0000 I CONTROL  [initandlisten] 
2018-03-13T18:41:14.894+0000 I CONTROL  [initandlisten] ** WARNING: /sys/kernel/mm/transparent_hugepage/enabled is 'always'.
2018-03-13T18:41:14.894+0000 I CONTROL  [initandlisten] **        We suggest setting it to 'never'
2018-03-13T18:41:14.894+0000 I CONTROL  [initandlisten] 
2018-03-13T18:41:14.894+0000 I CONTROL  [initandlisten] ** WARNING: /sys/kernel/mm/transparent_hugepage/defrag is 'always'.
2018-03-13T18:41:14.894+0000 I CONTROL  [initandlisten] **        We suggest setting it to 'never'
2018-03-13T18:41:14.894+0000 I CONTROL  [initandlisten] 
2018-03-13T18:41:14.894+0000 I CONTROL  [initandlisten] ** WARNING: soft rlimits too low. rlimits set to 15708 processes, 65536 files. Number of processes should be at least 32768 : 0.5 times number of files.
2018-03-13T18:41:14.894+0000 I CONTROL  [initandlisten] 
2018-03-13T18:41:14.901+0000 F STORAGE  [initandlisten] Unable to start up mongod due to missing featureCompatibilityVersion document.
2018-03-13T18:41:14.901+0000 F STORAGE  [initandlisten] Please run with --repair to restore the document.
2018-03-13T18:41:14.901+0000 F -        [initandlisten] Fatal Assertion 40652 at src/mongo/db/db.cpp 659
2018-03-13T18:41:14.901+0000 F -        [initandlisten] 
 
***aborting after fassert() failure

It boots cleanly when there is no write activity during the shutdown.
The write load was very light - every second, the simplest possible object * {id: x} *
was saved to the database.

Comment by Dmitry Agranat [ 01/Mar/18 ]

Hi thunpisit,

Thank you for reporting this issue.

Could you please clarify the exact steps (and provide the logs showing these steps) that led to this situation? Specifically, was it a clean installation of MongoDB 3.6.3 or an upgrade?

Thanks,
Dima

Comment by Thunpisit Amnuaikiatloet [ 01/Mar/18 ]

This happens in both of my droplet in Digitalocean.com when they automatically restart their system during the maintenance. I installed mongoDB from instruction of https://docs.mongodb.com/manual/tutorial/install-mongodb-on-ubuntu/ using package "mongodb-org" not the Ubuntu one. I've try restarting the droplet and many of commands but not successful on starting the mongoDB

However, by uninstalling MongoDB and delete every folder that related to MongoDB following the https://docs.mongodb.com/manual/tutorial/install-mongodb-on-ubuntu/ would fix the problem but I would lose all the data and configuration in the process.

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