Facing issues while starting the percona mongodb service

MongoDB Percona Server for MongoDB
1

Facing an issue to start the percona mongodb service , version 4.0.22 .

my mongod config file

systemLog:
destination: file
logRotate: rename
path: /var/log/mongodb/mongod.log
storage:
dbPath: /data/mongodb
journal:
enabled: true
directoryPerDB: true
processManagement:
pidFilePath: /var/run/mongod.pid
fork: true
net:
port: 27017
compression:
compressors: snappy
bindIpAll: true

Error in log singal 15 shutdown service
2021-02-03T06:25:19.030+0000 I STORAGE [initandlisten] Detected data files in /data/mongodb created by the ‘wiredTiger’ storage engine, so setting the active storage engine to ‘wiredTiger’.
2021-02-03T06:25:19.030+0000 I STORAGE [initandlisten] wiredtiger_open config: create,cache_size=30963M,cache_overflow=(file_max=0M),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),
2021-02-03T06:25:22.577+0000 I STORAGE [initandlisten] WiredTiger message [1612333522:577021][7029:0x7f286dc13b80], txn-recover: Main recovery loop: starting at 299696/74728448 to 299697/256
2021-02-03T06:25:22.642+0000 I STORAGE [initandlisten] WiredTiger message [1612333522:642429][7029:0x7f286dc13b80], txn-recover: Recovering log 299696 through 299697
2021-02-03T06:25:22.660+0000 I STORAGE [initandlisten] WiredTiger message [1612333522:660722][7029:0x7f286dc13b80], txn-recover: Recovering log 299697 through 299697
2021-02-03T06:25:22.708+0000 I STORAGE [initandlisten] WiredTiger message [1612333522:708447][7029:0x7f286dc13b80], txn-recover: Set global recovery timestamp: 0
2021-02-03T06:25:22.723+0000 I RECOVERY [initandlisten] WiredTiger recoveryTimestamp. Ts: Timestamp(0, 0)
2021-02-03T06:26:04.393+0000 I STORAGE [initandlisten] Starting OplogTruncaterThread local.oplog.rs
2021-02-03T06:26:04.393+0000 I STORAGE [initandlisten] The size storer reports that the oplog contains 157359505 records totaling to 67809353129 bytes
2021-02-03T06:26:04.393+0000 I STORAGE [initandlisten] Sampling the oplog to determine where to place markers for truncation
2021-02-03T06:26:04.395+0000 I STORAGE [initandlisten] Sampling from the oplog between Feb 1 12:44:33:2654 and Feb 3 06:19:43:135 to determine where to place markers for truncation
2021-02-03T06:26:04.395+0000 I STORAGE [initandlisten] Taking 994 samples and assuming that each section of oplog contains approximately 1581673 records totaling to 681574481 bytes
2021-02-03T06:26:13.987+0000 I STORAGE [initandlisten] Placing a marker at optime Feb 1 13:26:41:924
2021-02-03T06:26:13.987+0000 I STORAGE [initandlisten] Placing a marker at optime Feb 1 13:51:40:248
2021-02-03T06:26:13.987+0000 I STORAGE [initandlisten] Placing a marker at optime Feb 1 14:11:14:1527
2021-02-03T06:26:13.987+0000 I STORAGE [initandlisten] Placing a marker at optime Feb 1 14:52:29:718
2021-02-03T06:26:13.987+0000 I STORAGE [initandlisten] Placing a marker at optime Feb 1 15:14:59:742
2021-02-03T06:26:13.987+0000 I STORAGE [initandlisten] Placing a marker at optime Feb 1 15:26:12:937
2021-02-03T06:26:13.987+0000 I STORAGE [initandlisten] Placing a marker at optime Feb 1 15:52:02:193
2021-02-03T06:26:13.987+0000 I STORAGE [initandlisten] Placing a marker at optime Feb 1 16:13:21:293
2021-02-03T06:26:13.987+0000 I STORAGE [initandlisten] Placing a marker at optime Feb 1 16:47:11:2336
2021-02-03T06:26:13.987+0000 I STORAGE [initandlisten] Placing a marker at optime Feb 1 17:18:41:1126
2021-02-03T06:26:13.987+0000 I STORAGE [initandlisten] Placing a marker at optime Feb 1 17:56:25:1522
2021-02-03T06:26:13.987+0000 I STORAGE [initandlisten] Placing a marker at optime Feb 1 18:16:39:387
2021-02-03T06:26:13.987+0000 I STORAGE [initandlisten] Placing a marker at optime Feb 1 18:52:22:1042
2021-02-03T06:26:13.987+0000 I STORAGE [initandlisten] Placing a marker at optime Feb 1 19:27:57:2070
2021-02-03T06:26:13.987+0000 I STORAGE [initandlisten] Placing a marker at optime Feb 1 19:55:26:653
2021-02-03T06:26:13.987+0000 I STORAGE [initandlisten] Placing a marker at optime Feb 1 20:19:45:1126
2021-02-03T06:26:13.987+0000 I STORAGE [initandlisten] Placing a marker at optime Feb 1 20:49:50:448
2021-02-03T06:26:13.987+0000 I STORAGE [initandlisten] Placing a marker at optime Feb 1 21:21:41:706
2021-02-03T06:26:13.987+0000 I STORAGE [initandlisten] Placing a marker at optime Feb 1 21:50:41:3276
2021-02-03T06:26:13.987+0000 I STORAGE [initandlisten] Placing a marker at optime Feb 1 22:53:04:103
2021-02-03T06:26:13.987+0000 I STORAGE [initandlisten] Placing a marker at optime Feb 1 23:44:12:958
2021-02-03T06:26:13.987+0000 I STORAGE [initandlisten] Placing a marker at optime Feb 2 00:21:37:425
2021-02-03T06:26:13.987+0000 I STORAGE [initandlisten] Placing a marker at optime Feb 2 00:57:36:38
2021-02-03T06:26:13.987+0000 I STORAGE [initandlisten] Placing a marker at optime Feb 2 01:48:30:1124
2021-02-03T06:26:13.987+0000 I STORAGE [initandlisten] Placing a marker at optime Feb 2 02:29:56:2982
2021-02-03T06:26:13.987+0000 I STORAGE [initandlisten] Placing a marker at optime Feb 2 03:08:11:614
2021-02-03T06:26:13.987+0000 I STORAGE [initandlisten] Placing a marker at optime Feb 2 03:48:13:2458
2021-02-03T06:26:13.987+0000 I STORAGE [initandlisten] Placing a marker at optime Feb 2 04:03:41:392
2021-02-03T06:26:13.987+0000 I STORAGE [initandlisten] Placing a marker at optime Feb 2 04:28:43:423
2021-02-03T06:26:13.987+0000 I STORAGE [initandlisten] Placing a marker at optime Feb 2 05:02:47:3047
2021-02-03T06:26:13.987+0000 I STORAGE [initandlisten] Placing a marker at optime Feb 2 05:14:59:1634
2021-02-03T06:26:13.987+0000 I STORAGE [initandlisten] Placing a marker at optime Feb 2 05:38:54:1852
2021-02-03T06:26:13.987+0000 I STORAGE [initandlisten] Placing a marker at optime Feb 2 05:52:02:31
2021-02-03T06:26:13.987+0000 I STORAGE [initandlisten] Placing a marker at optime Feb 2 06:04:23:1496
2021-02-03T06:26:13.987+0000 I STORAGE [initandlisten] Placing a marker at optime Feb 2 06:45:17:895
2021-02-03T06:26:13.987+0000 I STORAGE [initandlisten] Placing a marker at optime Feb 2 07:32:37:1475
2021-02-03T06:26:13.987+0000 I STORAGE [initandlisten] Placing a marker at optime Feb 2 07:39:23:376
2021-02-03T06:26:13.987+0000 I STORAGE [initandlisten] Placing a marker at optime Feb 2 07:56:38:471
2021-02-03T06:26:13.987+0000 I STORAGE [initandlisten] Placing a marker at optime Feb 2 08:24:35:89
2021-02-03T06:26:13.987+0000 I STORAGE [initandlisten] Placing a marker at optime Feb 2 08:45:30:160
2021-02-03T06:26:13.987+0000 I STORAGE [initandlisten] Placing a marker at optime Feb 2 09:21:16:8572
2021-02-03T06:26:13.987+0000 I STORAGE [initandlisten] Placing a marker at optime Feb 2 09:53:47:271
2021-02-03T06:26:13.987+0000 I STORAGE [initandlisten] Placing a marker at optime Feb 2 10:06:16:1121
2021-02-03T06:26:13.987+0000 I STORAGE [initandlisten] Placing a marker at optime Feb 2 10:35:19:1374
2021-02-03T06:26:13.987+0000 I STORAGE [initandlisten] Placing a marker at optime Feb 2 10:57:53:439
2021-02-03T06:26:13.987+0000 I STORAGE [initandlisten] Placing a marker at optime Feb 2 11:30:16:4402
2021-02-03T06:26:13.987+0000 I STORAGE [initandlisten] Placing a marker at optime Feb 2 12:05:06:177
2021-02-03T06:26:13.987+0000 I STORAGE [initandlisten] Placing a marker at optime Feb 2 12:34:29:67
2021-02-03T06:26:13.987+0000 I STORAGE [initandlisten] Placing a marker at optime Feb 2 13:03:25:442
2021-02-03T06:26:13.987+0000 I STORAGE [initandlisten] Placing a marker at optime Feb 2 13:35:26:11
2021-02-03T06:26:13.987+0000 I STORAGE [initandlisten] Placing a marker at optime Feb 2 14:04:44:489
2021-02-03T06:26:13.987+0000 I STORAGE [initandlisten] Placing a marker at optime Feb 2 14:22:53:556
2021-02-03T06:26:13.987+0000 I STORAGE [initandlisten] Placing a marker at optime Feb 2 14:58:19:1145
2021-02-03T06:26:13.987+0000 I STORAGE [initandlisten] Placing a marker at optime Feb 2 15:15:52:969
2021-02-03T06:26:13.987+0000 I STORAGE [initandlisten] Placing a marker at optime Feb 2 15:33:21:453
2021-02-03T06:26:13.987+0000 I STORAGE [initandlisten] Placing a marker at optime Feb 2 15:58:41:620
2021-02-03T06:26:13.987+0000 I STORAGE [initandlisten] Placing a marker at optime Feb 2 16:13:04:51
2021-02-03T06:26:13.987+0000 I STORAGE [initandlisten] Placing a marker at optime Feb 2 16:36:33:72
2021-02-03T06:26:13.987+0000 I STORAGE [initandlisten] Placing a marker at optime Feb 2 17:03:20:100
2021-02-03T06:26:13.987+0000 I STORAGE [initandlisten] Placing a marker at optime Feb 2 17:36:24:410
2021-02-03T06:26:13.987+0000 I STORAGE [initandlisten] Placing a marker at optime Feb 2 17:56:03:186
2021-02-03T06:26:13.987+0000 I STORAGE [initandlisten] Placing a marker at optime Feb 2 18:08:40:281
2021-02-03T06:26:13.987+0000 I STORAGE [initandlisten] Placing a marker at optime Feb 2 18:30:16:870
2021-02-03T06:26:13.987+0000 I STORAGE [initandlisten] Placing a marker at optime Feb 2 18:57:05:621
2021-02-03T06:26:13.987+0000 I STORAGE [initandlisten] Placing a marker at optime Feb 2 19:17:07:2131
2021-02-03T06:26:13.987+0000 I STORAGE [initandlisten] Placing a marker at optime Feb 2 19:51:49:116
2021-02-03T06:26:13.987+0000 I STORAGE [initandlisten] Placing a marker at optime Feb 2 20:07:41:575
2021-02-03T06:26:13.987+0000 I STORAGE [initandlisten] Placing a marker at optime Feb 2 20:19:14:107
2021-02-03T06:26:13.987+0000 I STORAGE [initandlisten] Placing a marker at optime Feb 2 20:33:05:21
2021-02-03T06:26:13.987+0000 I STORAGE [initandlisten] Placing a marker at optime Feb 2 20:47:54:972
2021-02-03T06:26:13.987+0000 I STORAGE [initandlisten] Placing a marker at optime Feb 2 21:03:52:2509
2021-02-03T06:26:13.987+0000 I STORAGE [initandlisten] Placing a marker at optime Feb 2 21:19:55:1153
2021-02-03T06:26:13.987+0000 I STORAGE [initandlisten] Placing a marker at optime Feb 2 21:44:06:285
2021-02-03T06:26:13.987+0000 I STORAGE [initandlisten] Placing a marker at optime Feb 2 22:11:05:1113
2021-02-03T06:26:13.987+0000 I STORAGE [initandlisten] Placing a marker at optime Feb 2 22:27:26:1352
2021-02-03T06:26:13.987+0000 I STORAGE [initandlisten] Placing a marker at optime Feb 2 22:41:00:858
2021-02-03T06:26:13.987+0000 I STORAGE [initandlisten] Placing a marker at optime Feb 2 22:53:46:259
2021-02-03T06:26:13.987+0000 I STORAGE [initandlisten] Placing a marker at optime Feb 2 23:04:55:249
2021-02-03T06:26:13.987+0000 I STORAGE [initandlisten] Placing a marker at optime Feb 2 23:21:06:1657
2021-02-03T06:26:13.987+0000 I STORAGE [initandlisten] Placing a marker at optime Feb 2 23:59:15:253
2021-02-03T06:26:13.987+0000 I STORAGE [initandlisten] Placing a marker at optime Feb 3 00:15:41:284
2021-02-03T06:26:13.987+0000 I STORAGE [initandlisten] Placing a marker at optime Feb 3 00:34:54:1279
2021-02-03T06:26:13.987+0000 I STORAGE [initandlisten] Placing a marker at optime Feb 3 00:57:01:2091
2021-02-03T06:26:13.987+0000 I STORAGE [initandlisten] Placing a marker at optime Feb 3 01:15:38:904
2021-02-03T06:26:13.987+0000 I STORAGE [initandlisten] Placing a marker at optime Feb 3 01:34:20:2903
2021-02-03T06:26:13.987+0000 I STORAGE [initandlisten] Placing a marker at optime Feb 3 02:09:57:163
2021-02-03T06:26:13.987+0000 I STORAGE [initandlisten] Placing a marker at optime Feb 3 02:49:10:316
2021-02-03T06:26:13.987+0000 I STORAGE [initandlisten] Placing a marker at optime Feb 3 03:12:29:3699
2021-02-03T06:26:13.987+0000 I STORAGE [initandlisten] Placing a marker at optime Feb 3 03:21:59:1336
2021-02-03T06:26:13.987+0000 I STORAGE [initandlisten] Placing a marker at optime Feb 3 03:29:52:1956
2021-02-03T06:26:13.987+0000 I STORAGE [initandlisten] Placing a marker at optime Feb 3 03:37:24:2119
2021-02-03T06:26:13.987+0000 I STORAGE [initandlisten] Placing a marker at optime Feb 3 03:45:36:1569
2021-02-03T06:26:13.987+0000 I STORAGE [initandlisten] Placing a marker at optime Feb 3 03:55:12:480
2021-02-03T06:26:13.987+0000 I STORAGE [initandlisten] Placing a marker at optime Feb 3 04:16:53:5095
2021-02-03T06:26:13.987+0000 I STORAGE [initandlisten] Placing a marker at optime Feb 3 04:32:21:150
2021-02-03T06:26:13.987+0000 I STORAGE [initandlisten] Placing a marker at optime Feb 3 04:49:03:239
2021-02-03T06:26:13.987+0000 I STORAGE [initandlisten] Placing a marker at optime Feb 3 05:32:48:2010
2021-02-03T06:26:13.987+0000 I STORAGE [initandlisten] Placing a marker at optime Feb 3 05:50:23:542
2021-02-03T06:26:13.987+0000 I STORAGE [initandlisten] Placing a marker at optime Feb 3 06:03:20:2151
2021-02-03T06:26:13.987+0000 I STORAGE [initandlisten] WiredTiger record store oplog processing took 9593ms
2021-02-03T06:26:49.147+0000 I CONTROL [signalProcessingThread] got signal 15 (Terminated), will terminate after current cmd ends
2021-02-03T06:26:49.147+0000 I REPL [signalProcessingThread] Stepping down the ReplicationCoordinator for shutdown, waitTime: 10000ms
2021-02-03T06:26:49.148+0000 I NETWORK [signalProcessingThread] shutdown: going to close listening sockets…
2021-02-03T06:26:49.148+0000 I NETWORK [signalProcessingThread] removing socket file: /tmp/mongodb-27017.sock
2021-02-03T06:26:49.148+0000 I NETWORK [signalProcessingThread] Shutting down the global connection pool
2021-02-03T06:26:49.148+0000 I STORAGE [signalProcessingThread] Shutting down the PeriodicThreadToAbortExpiredTransactions
2021-02-03T06:26:49.148+0000 I REPL [signalProcessingThread] Shutting down the ReplicationCoordinator
2021-02-03T06:26:49.148+0000 I REPL [signalProcessingThread] shutting down replication subsystems
2021-02-03T06:26:49.148+0000 W REPL [signalProcessingThread] ReplicationCoordinatorImpl::shutdown() called before startup() finished. Shutting down without cleaning up the replication system
2021-02-03T06:26:49.148+0000 I SHARDING [signalProcessingThread] Shutting down the ShardingInitializationMongoD
2021-02-03T06:26:49.148+0000 I COMMAND [signalProcessingThread] Killing all open transactions
2021-02-03T06:26:49.148+0000 I - [signalProcessingThread] Killing all operations for shutdown
2021-02-03T06:26:49.148+0000 I NETWORK [signalProcessingThread] Shutting down the ReplicaSetMonitor
2021-02-03T06:26:49.148+0000 I CONTROL [signalProcessingThread] Shutting down free monitoring
2021-02-03T06:26:49.148+0000 I FTDC [signalProcessingThread] Shutting down full-time data capture
2021-02-03T06:26:49.148+0000 I STORAGE [signalProcessingThread] Shutting down the HealthLog
2021-02-03T06:26:49.148+0000 I STORAGE [signalProcessingThread] Acquiring the global lock for shutdown
2021-02-03T06:28:36.072+0000 I STORAGE [signalProcessingThread] Shutting down the storage engine
2021-02-03T06:28:36.072+0000 I STORAGE [initandlisten] exception in initAndListen: InterruptedAtShutdown: interrupted at shutdown, terminating
2021-02-03T06:28:36.072+0000 I CONTROL [initandlisten] While running shutdown tasks with the intent to exit with code 0, an additional shutdown request arrived with the intent to exit with a different exit code 100; ignoring the conflicting exit code
2021-02-03T06:28:36.085+0000 I STORAGE [WTOplogJournalThread] oplog journal thread loop shutting down
2021-02-03T06:28:36.090+0000 I STORAGE [signalProcessingThread] WiredTigerKVEngine shutting down
2021-02-03T06:28:36.090+0000 I STORAGE [signalProcessingThread] Shutting down session sweeper thread
2021-02-03T06:28:36.090+0000 I STORAGE [signalProcessingThread] Finished shutting down session sweeper thread
2021-02-03T06:28:36.457+0000 I STORAGE [signalProcessingThread] Downgrading WiredTiger datafiles.
2021-02-03T06:28:37.733+0000 I STORAGE [signalProcessingThread] WiredTiger message [1612333717:733953][7029:0x7f2867aeb700], txn-recover: Main recovery loop: starting at 299698/21731712 to 299699/256
2021-02-03T06:28:37.823+0000 I STORAGE [signalProcessingThread] WiredTiger message [1612333717:823117][7029:0x7f2867aeb700], txn-recover: Recovering log 299698 through 299699
2021-02-03T06:28:37.870+0000 I STORAGE [signalProcessingThread] WiredTiger message [1612333717:870311][7029:0x7f2867aeb700], txn-recover: Recovering log 299699 through 299699
2021-02-03T06:28:37.918+0000 I STORAGE [signalProcessingThread] WiredTiger message [1612333717:918545][7029:0x7f2867aeb700], txn-recover: Set global recovery timestamp: 0
2021-02-03T06:32:17.148+0000 I STORAGE [signalProcessingThread] shutdown: removing fs lock…
2021-02-03T06:32:17.148+0000 I - [signalProcessingThread] Dropping the scope cache for shutdown
2021-02-03T06:32:17.148+0000 I CONTROL [signalProcessingThread] now exiting
2021-02-03T06:32:17.148+0000 I CONTROL [signalProcessingThread] shutting down with code:0
sh-4.2#

Even tried revoming the fork from both mongod.conf and systemd unit files no luck

1 Like
2

Hi, most likely this is systemd default service start timeout (90 secs) causing problems since you have a recovery going on.
change this to something like 15 min for the purpose of the recovery. Inside [Service] section of mongod.service file:

TimeoutSec=900
1 Like
3

Hi Team ,

Thanks for the mail.

Today i faced the same issues in different server as the we are getting the signal 15 error and service getting crashing after some time , even i configured the timeout in systemd unit files for mongodb . After the timeout the process getting crashed.

1 Like
4

Hi, if it is right after the timeout, then you might need a higher value timeout. 900 sec was only a suggestion, but it is possible recovery is taking longer.

1 Like