Why is it that mongodb restarts are slow or even impossible to start when the number of collections is large

codinghuang_N_A · 2024-05-31T02:26:38.128Z

Since I didn’t pay attention early on to mongodb’s inability to support large collections, I now have 10w collections in my mongodb database. We then tried to restart the database, but found that the database would not start. I found that the database would continuously read the collection during the startup process, can anyone explain this phenomenon from the design of mongodb? Why do we need to traverse the collection? Is there a configuration or method that allows the database to start quickly?

Peter_Hubbard · 2024-05-31T08:15:46.202Z

Hi, there could be many reasons why the database is not starting up. If you can show what you are seeing in the log file on startup that would help.

In the meantime you can review the documentation on how to reduce the number of collections that you have (10 000 per replica set is a good upper limit.)

mongodb.com

Reduce Number of Collections - MongoDB Atlas

codinghuang_N_A · 2024-06-04T09:16:15.615Z

Hello, thank you for your reply! This is our mongodb startup log (The mongodb version is 4.2.24):

2024-05-31T07:23:17.717+0000 I CONTROL [main] Automatically disabling TLS 1.0, to force-enable TLS 1.0 specify --sslDisabledProtocols ‘none’

2024-05-31T07:23:17.720+0000 W ASIO [main] No TransportLayer configured during NetworkInterface startup

2024-05-31T07:23:17.735+0000 I CONTROL [initandlisten] MongoDB starting : pid=2690375 port=27017 dbpath=/data/db/workdir/data_20240529044004 64-bit host=0a534cc6e821

2024-05-31T07:23:17.735+0000 I CONTROL [initandlisten] db version v4.2.24

2024-05-31T07:23:17.735+0000 I CONTROL [initandlisten] git version: 5e4ec1d24431fcdd28b579a024c5c801b8cde4e2

2024-05-31T07:23:17.735+0000 I CONTROL [initandlisten] OpenSSL version: OpenSSL 1.1.1 11 Sep 2018

2024-05-31T07:23:17.735+0000 I CONTROL [initandlisten] allocator: tcmalloc

2024-05-31T07:23:17.735+0000 I CONTROL [initandlisten] modules: none

2024-05-31T07:23:17.735+0000 I CONTROL [initandlisten] build environment:

2024-05-31T07:23:17.735+0000 I CONTROL [initandlisten] distmod: ubuntu1804

2024-05-31T07:23:17.735+0000 I CONTROL [initandlisten] distarch: x86_64

2024-05-31T07:23:17.735+0000 I CONTROL [initandlisten] target_arch: x86_64

2024-05-31T07:23:17.735+0000 I CONTROL [initandlisten] options: { config: “./mongod.conf”, net: { bindIp: “0.0.0.0”, port: 27017, unixDomainSocket: { enabled: false } }, processManagement: { fork: true, pidFilePath: “/data/db/workdir/tmp/mongod.pid” }, security: { authorization: “enabled” }, storage: { dbPath: “/data/db/workdir/data_20240529044004”, directoryPerDB: true }, systemLog: { destination: “file”, logAppend: true, path: “/data/db/workdir/tmp/mongod.log” } }

2024-05-31T07:23:17.745+0000 I STORAGE [initandlisten] Detected data files in /data/db/workdir/data_20240529044004 created by the ‘wiredTiger’ storage engine, so setting the active storage engine to ‘wiredTiger’.

2024-05-31T07:23:17.745+0000 I STORAGE [initandlisten]

2024-05-31T07:23:17.745+0000 I STORAGE [initandlisten] ** WARNING: Using the XFS filesystem is strongly recommended with the WiredTiger storage engine

2024-05-31T07:23:17.745+0000 I STORAGE [initandlisten] ** See http://dochub.mongodb.org/core/prodnotes-filesystem

2024-05-31T07:23:17.745+0000 I STORAGE [initandlisten] wiredtiger_open config: create,cache_size=30993M,cache_overflow=(file_max=0M),session_max=33000,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,close_scan_interval=10,close_handle_minimum=250),statistics_log=(wait=0),verbose=[recovery_progress,checkpoint_progress],

2024-05-31T07:23:42.493+0000 I STORAGE [initandlisten] WiredTiger message [1717140222:493956][2690375:0x7fa1a721db00], txn-recover: Set global recovery timestamp: (1716928828, 1)

2024-05-31T07:23:42.526+0000 I RECOVERY [initandlisten] WiredTiger recoveryTimestamp. Ts: Timestamp(1716928828, 1)

2024-05-31T07:23:43.530+0000 I STORAGE [initandlisten] Starting OplogTruncaterThread local.oplog.rs

2024-05-31T07:23:43.530+0000 I STORAGE [initandlisten] The size storer reports that the oplog contains 3091948 records totaling to 2146893724 bytes

2024-05-31T07:23:43.530+0000 I STORAGE [initandlisten] Sampling the oplog to determine where to place markers for truncation

2024-05-31T07:23:43.532+0000 I STORAGE [initandlisten] Sampling from the oplog between May 20 07:14:18:11802 and May 28 20:40:28:1 to determine where to place markers for truncation

2024-05-31T07:23:43.532+0000 I STORAGE [initandlisten] Taking 999 samples and assuming that each section of oplog contains approximately 30928 records totaling to 21474853 bytes

2024-05-31T07:23:43.594+0000 I STORAGE [initandlisten] Placing a marker at optime May 20 07:14:55:5092

2024-05-31T07:23:43.594+0000 I STORAGE [initandlisten] Placing a marker at optime May 20 07:19:38:7167

2024-05-31T07:23:43.594+0000 I STORAGE [initandlisten] Placing a marker at optime May 20 07:25:44:195

2024-05-31T07:23:43.594+0000 I STORAGE [initandlisten] Placing a marker at optime May 20 07:25:45:4460

2024-05-31T07:23:43.594+0000 I STORAGE [initandlisten] Placing a marker at optime May 20 07:31:26:3515

2024-05-31T07:23:43.594+0000 I STORAGE [initandlisten] Placing a marker at optime May 20 07:31:28:1447

2024-05-31T07:23:43.594+0000 I STORAGE [initandlisten] Placing a marker at optime May 20 07:37:35:3786

2024-05-31T07:23:43.594+0000 I STORAGE [initandlisten] Placing a marker at optime May 20 07:37:37:1650

2024-05-31T07:23:43.594+0000 I STORAGE [initandlisten] Placing a marker at optime May 20 07:43:25:5931

2024-05-31T07:23:43.594+0000 I STORAGE [initandlisten] Placing a marker at optime May 20 07:43:30:1207

2024-05-31T07:23:43.594+0000 I STORAGE [initandlisten] Placing a marker at optime May 20 07:49:10:10280

2024-05-31T07:23:43.594+0000 I STORAGE [initandlisten] Placing a marker at optime May 20 07:49:28:1839

2024-05-31T07:23:43.594+0000 I STORAGE [initandlisten] Placing a marker at optime May 20 08:01:09:1177

2024-05-31T07:23:43.594+0000 I STORAGE [initandlisten] Placing a marker at optime May 20 08:01:11:8227

2024-05-31T07:23:43.594+0000 I STORAGE [initandlisten] Placing a marker at optime May 20 08:07:32:1291

2024-05-31T07:23:43.594+0000 I STORAGE [initandlisten] Placing a marker at optime May 20 08:07:34:4568

2024-05-31T07:23:43.594+0000 I STORAGE [initandlisten] Placing a marker at optime May 20 08:14:01:3530

2024-05-31T07:23:43.594+0000 I STORAGE [initandlisten] Placing a marker at optime May 20 08:14:02:10668

2024-05-31T07:23:43.594+0000 I STORAGE [initandlisten] Placing a marker at optime May 20 08:20:09:5760

2024-05-31T07:23:43.594+0000 I STORAGE [initandlisten] Placing a marker at optime May 20 08:20:19:16

2024-05-31T07:23:43.594+0000 I STORAGE [initandlisten] Placing a marker at optime May 20 08:25:49:4629

2024-05-31T07:23:43.594+0000 I STORAGE [initandlisten] Placing a marker at optime May 20 08:25:59:94

2024-05-31T07:23:43.594+0000 I STORAGE [initandlisten] Placing a marker at optime May 20 08:31:21:46

2024-05-31T07:23:43.594+0000 I STORAGE [initandlisten] Placing a marker at optime May 20 08:47:29:1857

2024-05-31T07:23:43.594+0000 I STORAGE [initandlisten] Placing a marker at optime May 20 08:50:59:665

2024-05-31T07:23:43.594+0000 I STORAGE [initandlisten] Placing a marker at optime May 20 09:02:49:113

2024-05-31T07:23:43.594+0000 I STORAGE [initandlisten] Placing a marker at optime May 20 09:02:51:8621

2024-05-31T07:23:43.594+0000 I STORAGE [initandlisten] Placing a marker at optime May 20 10:15:06:5272

2024-05-31T07:23:43.594+0000 I STORAGE [initandlisten] Placing a marker at optime May 20 10:15:29:8702

2024-05-31T07:23:43.594+0000 I STORAGE [initandlisten] Placing a marker at optime May 20 10:19:58:8353

2024-05-31T07:23:43.594+0000 I STORAGE [initandlisten] Placing a marker at optime May 20 10:30:43:1087

2024-05-31T07:23:43.594+0000 I STORAGE [initandlisten] Placing a marker at optime May 20 10:31:14:2346

2024-05-31T07:23:43.594+0000 I STORAGE [initandlisten] Placing a marker at optime May 20 10:32:11:37

2024-05-31T07:23:43.594+0000 I STORAGE [initandlisten] Placing a marker at optime May 20 10:36:25:749

2024-05-31T07:23:43.594+0000 I STORAGE [initandlisten] Placing a marker at optime May 20 10:37:20:3536

2024-05-31T07:23:43.594+0000 I STORAGE [initandlisten] Placing a marker at optime May 20 10:38:52:1790

2024-05-31T07:23:43.594+0000 I STORAGE [initandlisten] Placing a marker at optime May 20 15:46:08:40

2024-05-31T07:23:43.594+0000 I STORAGE [initandlisten] Placing a marker at optime May 20 16:08:53:1884

2024-05-31T07:23:43.594+0000 I STORAGE [initandlisten] Placing a marker at optime May 20 18:39:40:3

2024-05-31T07:23:43.594+0000 I STORAGE [initandlisten] Placing a marker at optime May 20 18:54:05:264

2024-05-31T07:23:43.594+0000 I STORAGE [initandlisten] Placing a marker at optime May 21 02:28:31:2067

2024-05-31T07:23:43.594+0000 I STORAGE [initandlisten] Placing a marker at optime May 21 02:39:01:4048

2024-05-31T07:23:43.594+0000 I STORAGE [initandlisten] Placing a marker at optime May 21 02:44:38:1156

2024-05-31T07:23:43.594+0000 I STORAGE [initandlisten] Placing a marker at optime May 21 06:40:52:2721

2024-05-31T07:23:43.594+0000 I STORAGE [initandlisten] Placing a marker at optime May 21 06:52:20:651

2024-05-31T07:23:43.594+0000 I STORAGE [initandlisten] Placing a marker at optime May 21 07:10:02:5799

2024-05-31T07:23:43.594+0000 I STORAGE [initandlisten] Placing a marker at optime May 21 07:42:50:4542

2024-05-31T07:23:43.594+0000 I STORAGE [initandlisten] Placing a marker at optime May 21 07:53:33:1756

2024-05-31T07:23:43.594+0000 I STORAGE [initandlisten] Placing a marker at optime May 21 07:57:50:2666

2024-05-31T07:23:43.594+0000 I STORAGE [initandlisten] Placing a marker at optime May 21 08:08:59:6

2024-05-31T07:23:43.594+0000 I STORAGE [initandlisten] Placing a marker at optime May 21 08:39:55:861

2024-05-31T07:23:43.594+0000 I STORAGE [initandlisten] Placing a marker at optime May 21 08:57:12:13923

2024-05-31T07:23:43.594+0000 I STORAGE [initandlisten] Placing a marker at optime May 21 09:07:12:14953

2024-05-31T07:23:43.594+0000 I STORAGE [initandlisten] Placing a marker at optime May 21 09:13:28:1376

2024-05-31T07:23:43.594+0000 I STORAGE [initandlisten] Placing a marker at optime May 21 09:13:36:1679

2024-05-31T07:23:43.594+0000 I STORAGE [initandlisten] Placing a marker at optime May 21 09:13:41:9632

2024-05-31T07:23:43.594+0000 I STORAGE [initandlisten] Placing a marker at optime May 21 09:28:04:305

2024-05-31T07:23:43.594+0000 I STORAGE [initandlisten] Placing a marker at optime May 21 09:28:19:280

2024-05-31T07:23:43.594+0000 I STORAGE [initandlisten] Placing a marker at optime May 21 09:28:40:4102

2024-05-31T07:23:43.594+0000 I STORAGE [initandlisten] Placing a marker at optime May 21 09:29:05:976

2024-05-31T07:23:43.594+0000 I STORAGE [initandlisten] Placing a marker at optime May 21 09:29:43:232

2024-05-31T07:23:43.594+0000 I STORAGE [initandlisten] Placing a marker at optime May 21 09:30:29:605

2024-05-31T07:23:43.594+0000 I STORAGE [initandlisten] Placing a marker at optime May 21 09:32:35:322

2024-05-31T07:23:43.594+0000 I STORAGE [initandlisten] Placing a marker at optime May 21 11:41:22:344

2024-05-31T07:23:43.594+0000 I STORAGE [initandlisten] Placing a marker at optime May 22 07:30:23:44

2024-05-31T07:23:43.594+0000 I STORAGE [initandlisten] Placing a marker at optime May 22 10:42:51:5

2024-05-31T07:23:43.594+0000 I STORAGE [initandlisten] Placing a marker at optime May 22 16:32:38:24

2024-05-31T07:23:43.594+0000 I STORAGE [initandlisten] Placing a marker at optime May 23 07:49:35:19

2024-05-31T07:23:43.594+0000 I STORAGE [initandlisten] Placing a marker at optime May 24 08:07:13:1

2024-05-31T07:23:43.594+0000 I STORAGE [initandlisten] Placing a marker at optime May 24 11:19:57:111

2024-05-31T07:23:43.594+0000 I STORAGE [initandlisten] Placing a marker at optime May 24 11:20:09:3813

2024-05-31T07:23:43.594+0000 I STORAGE [initandlisten] Placing a marker at optime May 24 11:20:42:3699

2024-05-31T07:23:43.594+0000 I STORAGE [initandlisten] Placing a marker at optime May 24 11:20:51:2203

2024-05-31T07:23:43.594+0000 I STORAGE [initandlisten] Placing a marker at optime May 24 11:20:53:6439

2024-05-31T07:23:43.594+0000 I STORAGE [initandlisten] Placing a marker at optime May 24 11:21:06:2268

2024-05-31T07:23:43.594+0000 I STORAGE [initandlisten] Placing a marker at optime May 24 11:21:09:318

2024-05-31T07:23:43.594+0000 I STORAGE [initandlisten] Placing a marker at optime May 24 11:21:19:7372

2024-05-31T07:23:43.594+0000 I STORAGE [initandlisten] Placing a marker at optime May 24 11:21:38:960

2024-05-31T07:23:43.594+0000 I STORAGE [initandlisten] Placing a marker at optime May 24 11:21:39:245

2024-05-31T07:23:43.594+0000 I STORAGE [initandlisten] Placing a marker at optime May 24 11:22:07:6731

2024-05-31T07:23:43.594+0000 I STORAGE [initandlisten] Placing a marker at optime May 24 11:22:08:9326

2024-05-31T07:23:43.594+0000 I STORAGE [initandlisten] Placing a marker at optime May 24 20:13:56:2

2024-05-31T07:23:43.594+0000 I STORAGE [initandlisten] Placing a marker at optime May 27 02:49:21:43

2024-05-31T07:23:43.594+0000 I STORAGE [initandlisten] Placing a marker at optime May 27 07:53:54:2045

2024-05-31T07:23:43.594+0000 I STORAGE [initandlisten] Placing a marker at optime May 27 07:54:24:3039

2024-05-31T07:23:43.594+0000 I STORAGE [initandlisten] Placing a marker at optime May 27 07:54:52:193

2024-05-31T07:23:43.594+0000 I STORAGE [initandlisten] Placing a marker at optime May 27 07:54:55:100

2024-05-31T07:23:43.595+0000 I STORAGE [initandlisten] Placing a marker at optime May 27 07:54:56:5824

2024-05-31T07:23:43.595+0000 I STORAGE [initandlisten] Placing a marker at optime May 27 07:55:09:6624

2024-05-31T07:23:43.595+0000 I STORAGE [initandlisten] Placing a marker at optime May 27 07:55:11:1611

2024-05-31T07:23:43.595+0000 I STORAGE [initandlisten] Placing a marker at optime May 27 07:55:25:2694

2024-05-31T07:23:43.595+0000 I STORAGE [initandlisten] Placing a marker at optime May 27 07:55:26:9366

2024-05-31T07:23:43.595+0000 I STORAGE [initandlisten] Placing a marker at optime May 27 07:55:43:1589

2024-05-31T07:23:43.595+0000 I STORAGE [initandlisten] Placing a marker at optime May 27 07:55:45:2641

2024-05-31T07:23:43.595+0000 I STORAGE [initandlisten] Placing a marker at optime May 27 07:55:46:7533

2024-05-31T07:23:43.595+0000 I STORAGE [initandlisten] Placing a marker at optime May 27 07:56:00:4305

2024-05-31T07:23:43.595+0000 I STORAGE [initandlisten] Placing a marker at optime May 27 07:56:02:4730

2024-05-31T07:23:43.595+0000 I STORAGE [initandlisten] Placing a marker at optime May 27 15:16:48:21

2024-05-31T07:23:43.595+0000 I STORAGE [initandlisten] Placing a marker at optime May 28 10:27:08:34

2024-05-31T07:23:43.595+0000 I STORAGE [initandlisten] WiredTiger record store oplog processing took 64ms

2024-05-31T07:29:13.816+0000 I STORAGE [initandlisten] Timestamp monitor starting

2024-05-31T07:29:13.818+0000 I CONTROL [initandlisten] ** WARNING: You are running this process as the root user, which is not recommended.

2024-05-31T07:29:13.818+0000 I CONTROL [initandlisten]

2024-05-31T07:29:13.818+0000 I CONTROL [initandlisten] ** WARNING: /sys/kernel/mm/transparent_hugepage/enabled is ‘always’.

2024-05-31T07:29:13.818+0000 I CONTROL [initandlisten] ** We suggest setting it to ‘never’

2024-05-31T07:29:13.818+0000 I CONTROL [initandlisten]

2024-05-31T22:45:14.154+0000 I STORAGE [initandlisten] Flow Control is enabled on this deployment.

2024-05-31T22:45:14.490+0000 I FTDC [initandlisten] Initializing full-time diagnostic data capture with directory ‘/data/db/workdir/data_20240529044004/diagnostic.data’

2024-05-31T22:45:14.494+0000 I STORAGE [initandlisten]

2024-05-31T22:45:14.494+0000 I STORAGE [initandlisten] ** WARNING: mongod started without --replSet yet document(s) are present in local.system.replset.

2024-05-31T22:45:14.494+0000 I STORAGE [initandlisten] ** Database contents may appear inconsistent with the oplog and may appear to not contain

2024-05-31T22:45:14.494+0000 I STORAGE [initandlisten] ** writes that were visible when this node was running as part of a replica set.

2024-05-31T22:45:14.494+0000 I STORAGE [initandlisten] ** Restart with --replSet unless you are doing maintenance and no other clients are connected.

2024-05-31T22:45:14.494+0000 I STORAGE [initandlisten] ** The TTL collection monitor will not start because of this.

2024-05-31T22:45:14.494+0000 I STORAGE [initandlisten] **

2024-05-31T22:45:14.494+0000 I STORAGE [initandlisten] For more info see http://dochub.mongodb.org/core/ttlcollections

2024-05-31T22:45:14.494+0000 I STORAGE [initandlisten]

2024-05-31T22:45:14.495+0000 I NETWORK [listener] Listening on 0.0.0.0

2024-05-31T22:45:14.495+0000 I NETWORK [listener] waiting for connections on port 27017

2024-05-31T22:45:14.659+0000 I COMMAND [LogicalSessionCacheReap] command config.transactions command: find { find: “transactions”, filter: { lastWriteDate: { $lt: new Date(1717193714495) } }, projection: { _id: 1 }, sort: { _id: 1 }, $db: “config” } planSummary: IXSCAN { _id: 1 } keysExamined:1 docsExamined:1 cursorExhausted:1 numYields:1 nreturned:1 queryHash:924420F6 planCacheKey:924420F6 reslen:193 locks:{ ReplicationStateTransition: { acquireCount: { w: 2 } }, Global: { acquireCount: { r: 2 } }, Database: { acquireCount: { r: 2 } }, Collection: { acquireCount: { r: 2 } }, Mutex: { acquireCount: { r: 1 } } } storage:{ data: { bytesRead: 427, timeReadingMicros: 13 }, timeWaitingMicros: { handleLock: 156562 } } protocol:op_msg 163ms

As we can see, it took 15 hours to get started.

Peter_Hubbard · 2024-06-04T09:50:47.040Z

This looks like the database was recovering from an unsafe shutdown and was not started with the appropriate replSet parameter. If this is part of a replica set then please make sure that you are using the correct startup parameters.