Mongod 'detected unclean shutdown - /var/lib/mongo/mongod.lock is not empty'

827 views
Skip to first unread message
derrick.m....@gmail.com

unread,
Mar 21, 2018, 3:05:05 AM3/21/18
to mongodb-user
Environment: RHEL
distarch: x86_64
target_arch: x86_64
Linux + Apache running mongod daemon
Hello,
We are a Digital Media team working within the Disney Corporate group and have been using mongo for some time now. We recently came across an issue where mongod would not start due to an 'unclean shutdown' and was told by a Principal Solutions Architect that it is due to the admin database being possibly corrupted.
I will attach a copy of the directory with the issue and also the log that we have. It would be extremely helpful if we can recover what we have.
2018-03-19T17:24:34.563-0700 I CONTROL  [initandlisten] MongoDB starting : pid=21699 port=27017 dbpath=/var/lib/mongo 64-bit host=clnckwwv0027

2018-03-19T17:24:34.563-0700 I CONTROL  [initandlisten] db version v3.4.10

2018-03-19T17:24:34.563-0700 I CONTROL  [initandlisten] git version: 078f28920cb24de0dd479b5ea6c66c644f6326e9

2018-03-19T17:24:34.563-0700 I CONTROL  [initandlisten] OpenSSL version: OpenSSL 1.0.1e-fips 11 Feb 2013

2018-03-19T17:24:34.563-0700 I CONTROL  [initandlisten] allocator: tcmalloc

2018-03-19T17:24:34.563-0700 I CONTROL  [initandlisten] modules: none

2018-03-19T17:24:34.563-0700 I CONTROL  [initandlisten] build environment:

2018-03-19T17:24:34.563-0700 I CONTROL  [initandlisten]     distmod: rhel70

2018-03-19T17:24:34.563-0700 I CONTROL  [initandlisten]     distarch: x86_64

2018-03-19T17:24:34.563-0700 I CONTROL  [initandlisten]     target_arch: x86_64

2018-03-19T17:24:34.563-0700 I CONTROL  [initandlisten] options: { repair: true, storage: { dbPath: "/var/lib/mongo" } }

2018-03-19T17:24:34.563-0700 W -        [initandlisten] Detected unclean shutdown - /var/lib/mongo/mongod.lock is not empty.

2018-03-19T17:24:34.584-0700 I -        [initandlisten] Detected data files in /var/lib/mongo created by the 'wiredTiger' storage engine, so setting the active storage engine to 'wiredTiger'.

2018-03-19T17:24:34.584-0700 W STORAGE  [initandlisten] Recovering data from the last clean checkpoint.

2018-03-19T17:24:34.585-0700 I STORAGE  [initandlisten]

2018-03-19T17:24:34.585-0700 I STORAGE  [initandlisten] ** WARNING: Using the XFS filesystem is strongly recommended with the WiredTiger storage engine

2018-03-19T17:24:34.585-0700 I STORAGE  [initandlisten] **          See http://dochub.mongodb.org/core/prodnotes-filesystem

2018-03-19T17:24:34.585-0700 I STORAGE  [initandlisten] wiredtiger_open config: create,cache_size=3479M,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),checkpoint=(wait=60,log_size=2GB),statistics_log=(wait=0),,log=(enabled=false),

2018-03-19T17:24:34.609-0700 I STORAGE  [initandlisten] Repairing size cache

2018-03-19T17:24:34.609-0700 I STORAGE  [initandlisten] Verify succeeded on uri table:sizeStorer. Not salvaging.

2018-03-19T17:24:34.610-0700 I STORAGE  [initandlisten] Repairing catalog metadata

2018-03-19T17:24:34.610-0700 I STORAGE  [initandlisten] Verify succeeded on uri table:_mdb_catalog. Not salvaging.

2018-03-19T17:24:34.631-0700 I CONTROL  [initandlisten]

2018-03-19T17:24:34.631-0700 I CONTROL  [initandlisten] ** WARNING: Access control is not enabled for the database.

2018-03-19T17:24:34.631-0700 I CONTROL  [initandlisten] **          Read and write access to data and configuration is unrestricted.

2018-03-19T17:24:34.631-0700 I CONTROL  [initandlisten] ** WARNING: You are running this process as the root user, which is not recommended.

2018-03-19T17:24:34.631-0700 I CONTROL  [initandlisten]

2018-03-19T17:24:34.631-0700 I CONTROL  [initandlisten]

2018-03-19T17:24:34.631-0700 I CONTROL  [initandlisten] ** WARNING: /sys/kernel/mm/transparent_hugepage/enabled is 'always'.

2018-03-19T17:24:34.631-0700 I CONTROL  [initandlisten] **        We suggest setting it to 'never'

2018-03-19T17:24:34.631-0700 I CONTROL  [initandlisten]

2018-03-19T17:24:34.631-0700 I CONTROL  [initandlisten] ** WARNING: /sys/kernel/mm/transparent_hugepage/defrag is 'always'.

2018-03-19T17:24:34.631-0700 I CONTROL  [initandlisten] **        We suggest setting it to 'never'

2018-03-19T17:24:34.631-0700 I CONTROL  [initandlisten]

2018-03-19T17:24:34.632-0700 I STORAGE  [initandlisten] repairDatabase admin

2018-03-19T17:24:34.632-0700 I STORAGE  [initandlisten] Repairing collection admin.system.users

2018-03-19T17:24:34.632-0700 E STORAGE  [initandlisten] WiredTiger error (2) [1521505474:632502][21699:0x7f5b7fab1e40], file:collection-0--842860930387207451.wt, WT_SESSION.verify: /var/lib/mongo/collection-0--842860930387207451.wt: handle-open: open: No such file or directory

2018-03-19T17:24:34.632-0700 I STORAGE  [initandlisten] Verify failed on uri table:collection-0--842860930387207451. Running a salvage operation.

2018-03-19T17:24:34.632-0700 E STORAGE  [initandlisten] WiredTiger error (2) [1521505474:632754][21699:0x7f5b7fab1e40], file:collection-0--842860930387207451.wt, WT_SESSION.salvage: /var/lib/mongo/collection-0--842860930387207451.wt: handle-open: open: No such file or directory

2018-03-19T17:24:34.632-0700 I -        [initandlisten] Invariant failure rs.get() src/mongo/db/catalog/database.cpp 195

2018-03-19T17:24:34.632-0700 I -        [initandlisten]

***aborting after invariant() failure

2018-03-19T17:24:34.639-0700 F -        [initandlisten] Got signal: 6 (Aborted).
2018-03-19T17:24:34.563-0700 I CONTROL  [initandlisten] MongoDB starting : pid=21699 port=27017 dbpath=/var/lib/mongo 64-bit host=clnckwwv0027
2018-03-19T17:24:34.563-0700 I CONTROL  [initandlisten] db version v3.4.10
2018-03-19T17:24:34.563-0700 I CONTROL  [initandlisten] git version: 078f28920cb24de0dd479b5ea6c66c644f6326e9
2018-03-19T17:24:34.563-0700 I CONTROL  [initandlisten] OpenSSL version: OpenSSL 1.0.1e-fips 11 Feb 2013
2018-03-19T17:24:34.563-0700 I CONTROL  [initandlisten] allocator: tcmalloc
2018-03-19T17:24:34.563-0700 I CONTROL  [initandlisten] modules: none
2018-03-19T17:24:34.563-0700 I CONTROL  [initandlisten] build environment:
2018-03-19T17:24:34.563-0700 I CONTROL  [initandlisten]     distmod: rhel70
2018-03-19T17:24:34.563-0700 I CONTROL  [initandlisten]     distarch: x86_64
2018-03-19T17:24:34.563-0700 I CONTROL  [initandlisten]     target_arch: x86_64
2018-03-19T17:24:34.563-0700 I CONTROL  [initandlisten] options: { repair: true, storage: { dbPath: "/var/lib/mongo" } }
2018-03-19T17:24:34.563-0700 W -        [initandlisten] Detected unclean shutdown - /var/lib/mongo/mongod.lock is not empty.
2018-03-19T17:24:34.584-0700 I -        [initandlisten] Detected data files in /var/lib/mongo created by the 'wiredTiger' storage engine, so setting the active storage engine to 'wiredTiger'.
2018-03-19T17:24:34.584-0700 W STORAGE  [initandlisten] Recovering data from the last clean checkpoint.
2018-03-19T17:24:34.585-0700 I STORAGE  [initandlisten]
2018-03-19T17:24:34.585-0700 I STORAGE  [initandlisten] ** WARNING: Using the XFS filesystem is strongly recommended with the WiredTiger storage engine
2018-03-19T17:24:34.585-0700 I STORAGE  [initandlisten] **          See http://dochub.mongodb.org/core/prodnotes-filesystem
2018-03-19T17:24:34.585-0700 I STORAGE  [initandlisten] wiredtiger_open config: create,cache_size=3479M,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),checkpoint=(wait=60,log_size=2GB),statistics_log=(wait=0),,log=(enabled=false),
2018-03-19T17:24:34.609-0700 I STORAGE  [initandlisten] Repairing size cache
2018-03-19T17:24:34.609-0700 I STORAGE  [initandlisten] Verify succeeded on uri table:sizeStorer. Not salvaging.
2018-03-19T17:24:34.610-0700 I STORAGE  [initandlisten] Repairing catalog metadata
2018-03-19T17:24:34.610-0700 I STORAGE  [initandlisten] Verify succeeded on uri table:_mdb_catalog. Not salvaging.
2018-03-19T17:24:34.631-0700 I CONTROL  [initandlisten]
2018-03-19T17:24:34.631-0700 I CONTROL  [initandlisten] ** WARNING: Access control is not enabled for the database.
2018-03-19T17:24:34.631-0700 I CONTROL  [initandlisten] **          Read and write access to data and configuration is unrestricted.
2018-03-19T17:24:34.631-0700 I CONTROL  [initandlisten] ** WARNING: You are running this process as the root user, which is not recommended.
2018-03-19T17:24:34.631-0700 I CONTROL  [initandlisten]
2018-03-19T17:24:34.631-0700 I CONTROL  [initandlisten]
2018-03-19T17:24:34.631-0700 I CONTROL  [initandlisten] ** WARNING: /sys/kernel/mm/transparent_hugepage/enabled is 'always'.
2018-03-19T17:24:34.631-0700 I CONTROL  [initandlisten] **        We suggest setting it to 'never'
2018-03-19T17:24:34.631-0700 I CONTROL  [initandlisten]
2018-03-19T17:24:34.631-0700 I CONTROL  [initandlisten] ** WARNING: /sys/kernel/mm/transparent_hugepage/defrag is 'always'.
2018-03-19T17:24:34.631-0700 I CONTROL  [initandlisten] **        We suggest setting it to 'never'
2018-03-19T17:24:34.631-0700 I CONTROL  [initandlisten]
2018-03-19T17:24:34.632-0700 I STORAGE  [initandlisten] repairDatabase admin
2018-03-19T17:24:34.632-0700 I STORAGE  [initandlisten] Repairing collection admin.system.users
2018-03-19T17:24:34.632-0700 E STORAGE  [initandlisten] WiredTiger error (2) [1521505474:632502][21699:0x7f5b7fab1e40], file:collection-0--842860930387207451.wt, WT_SESSION.verify: /var/lib/mongo/collection-0--842860930387207451.wt: handle-open: open: No such file or directory
2018-03-19T17:24:34.632-0700 I STORAGE  [initandlisten] Verify failed on uri table:collection-0--842860930387207451. Running a salvage operation.
2018-03-19T17:24:34.632-0700 E STORAGE  [initandlisten] WiredTiger error (2) [1521505474:632754][21699:0x7f5b7fab1e40], file:collection-0--842860930387207451.wt, WT_SESSION.salvage: /var/lib/mongo/collection-0--842860930387207451.wt: handle-open: open: No such file or directory
2018-03-19T17:24:34.632-0700 I -        [initandlisten] Invariant failure rs.get() src/mongo/db/catalog/database.cpp 195
2018-03-19T17:24:34.632-0700 I -        [initandlisten]
***aborting after invariant() failure
2018-03-19T17:24:34.639-0700 F -        [initandlisten] Got signal: 6 (Aborted).
Reply all
Reply to author
Forward
0 new messages