Advanced Threat Analytics MongoDB service won’t start
So while patching our ATA Center and ATA Gateway server, we found that after a reboot, the ATA services weren’t coming back up on our Center box. Seemed that the services were cycling between the Microsoft Advanced Threat Analytics Center and Microsoft Advanced Threat Analytics Gateway services kept trying to start and failed.
Looking in the event logs, we don’t get much
So then we checked the MongoDB service and noticed it wasn’t started, and when trying to start, it immediately failed.
In the MongoDB log file, we found the following
*************
2016-02-19T08:09:49.195-0600 I STORAGE [initandlisten] exception in initAndListen: 12596 old lock file, terminating
2016-02-19T08:09:49.195-0600 I CONTROL [serviceStopWorker] dbexit: rc: 49
2016-02-19T08:10:28.112-0600 I CONTROL ***** SERVER RESTARTED *****
2016-02-19T08:10:28.131-0600 I CONTROL Trying to start Windows service ‘MongoDB’
2016-02-19T08:10:28.133-0600 I STORAGE Service running
2016-02-19T08:10:28.134-0600 W – [initandlisten] Detected unclean shutdown – E:\DBs\mongod.lock is not empty.
2016-02-19T08:10:28.149-0600 I STORAGE [initandlisten] **************
old lock file: E:\DBs\mongod.lock. probably means unclean shutdown,
but there are no journal files to recover.
this is likely human error or filesystem corruption.
please make sure that your journal directory is mounted.
found 2 dbs.
see: http://dochub.mongodb.org/core/repair for more information
*************
Seems that there was an un-clean shutdown for some reason, so after some research, we came across the following article
https://docs.mongodb.org/manual/tutorial/recover-data-following-unexpected-shutdown/
We decided to try and replace the original files with the repaired files because we know it was a clean shutdown and weren’t too worried about corruption. (We also had a backup just in case!)
We ran the following command because our databases are on the E: volume, you can find mongod under C:\Program Files\Microsoft Advanced Threat Analytics\Center\MongoDB\bin
mongod –dbpath E:/DBs –repair –repairpath E:/DBs/DB0
2016-02-19T08:15:24.824-0600 W – [initandlisten] Detected unclean shutdown – E:/DBs\mongod.lock is not empty.
2016-02-19T08:15:24.967-0600 I CONTROL [initandlisten] MongoDB starting : pid=4124 port=27017 dbpath=E:/DBs 64-bit host=NTXEBC-ATA
2016-02-19T08:15:24.967-0600 I CONTROL [initandlisten] targetMinOS: Windows 7/Windows Server 2008 R2
2016-02-19T08:15:24.987-0600 I CONTROL [initandlisten] db version v3.0.5
2016-02-19T08:15:24.987-0600 I CONTROL [initandlisten] git version: 8bc4ae20708dbb493cb09338d9e7be6698e4a3a3
2016-02-19T08:15:24.988-0600 I CONTROL [initandlisten] build info: windows sys.getwindowsversion(major=6, minor=1, build=7601, platform=2, service_pack=’Service Pack 1′) BOOST_LIB_VERSION=1_49
2016-02-19T08:15:24.990-0600 I CONTROL [initandlisten] allocator: tcmalloc
2016-02-19T08:15:24.990-0600 I CONTROL [initandlisten] options: { repair: true, storage: { dbPath: “E:/DBs”, repairPath: “E:/DBs/DB0” } }
2016-02-19T08:15:24.992-0600 I STORAGE [initandlisten] exception in initAndListen: 12590 repairpath (E:/DBs/DB0) does not exist, terminating
2016-02-19T08:15:25.024-0600 I CONTROL [initandlisten] now exiting
2016-02-19T08:15:25.030-0600 I NETWORK [initandlisten] shutdown: going to close listening sockets…
2016-02-19T08:15:25.031-0600 I NETWORK [initandlisten] shutdown: going to flush diaglog…
2016-02-19T08:15:25.032-0600 I NETWORK [initandlisten] shutdown: going to close sockets…
2016-02-19T08:15:25.033-0600 I STORAGE [initandlisten] shutdown: waiting for fs preallocator…
And in the logs we saw the following, looks like the service has come up now
2016-02-19T08:14:52.264-0600 I STORAGE [initandlisten] exception in initAndListen: 12596 old lock file, terminating
2016-02-19T08:14:52.265-0600 I CONTROL [serviceStopWorker] dbexit: rc: 49
2016-02-19T08:15:31.700-0600 I CONTROL ***** SERVER RESTARTED *****
2016-02-19T08:15:31.726-0600 I CONTROL Trying to start Windows service ‘MongoDB’
2016-02-19T08:15:31.727-0600 I STORAGE Service running
2016-02-19T08:15:31.745-0600 I JOURNAL [initandlisten] journal dir=E:\DBs\journal
2016-02-19T08:15:31.753-0600 I JOURNAL [initandlisten] recover : no journal files present, no recovery needed
2016-02-19T08:15:31.870-0600 I CONTROL [initandlisten] MongoDB starting : pid=3188 port=27017 dbpath=E:\DBs 64-bit host=NTXEBC-ATA
2016-02-19T08:15:31.870-0600 I CONTROL [initandlisten] targetMinOS: Windows 7/Windows Server 2008 R2
2016-02-19T08:15:31.870-0600 I CONTROL [initandlisten] db version v3.0.5
2016-02-19T08:15:31.870-0600 I CONTROL [initandlisten] git version: 8bc4ae20708dbb493cb09338d9e7be6698e4a3a3
2016-02-19T08:15:31.870-0600 I CONTROL [initandlisten] build info: windows sys.getwindowsversion(major=6, minor=1, build=7601, platform=2, service_pack=’Service Pack 1′) BOOST_LIB_VERSION=1_49
2016-02-19T08:15:31.870-0600 I CONTROL [initandlisten] allocator: tcmalloc
2016-02-19T08:15:31.870-0600 I CONTROL [initandlisten] options: { config: “C:\Program Files\Microsoft Advanced Threat Analytics\Center\MongoDB\bin\mongod.cfg”, net: { bindIp: “127.0.0.1”, port: 27017 }, operationProfiling: { slowOpThresholdMs: 1000 }, service: true, storage: { dbPath: “E:\DBs”, mmapv1: { journal: { commitIntervalMs: 300 } }, syncPeriodSecs: 10.0 }, systemLog: { destination: “file”, logAppend: true, path: “C:\Program Files\Microsoft Advanced Threat Analytics\Center\MongoDB\bin\log\MongoDB.log” } }
2016-02-19T08:15:31.876-0600 I JOURNAL [durability] Durability thread started
2016-02-19T08:15:31.877-0600 I JOURNAL [journal writer] Journal writer thread started
2016-02-19T08:15:35.746-0600 I NETWORK [initandlisten] waiting for connections on port 27017
2016-02-19T08:15:35.805-0600 I NETWORK [initandlisten] connection accepted from 127.0.0.1:61681 #1 (1 connection now open)
Then our ATA services came back up
And we are live again!