Long time(1 hours more ) at startup Community server 5.0.0

Ops and Admin
1

Community server 5.0.0 os: windows 2016

config file:
#systemLog:

path: ./log
logAppend: true
destination: file
storage:
dbPath: ./data/db

directoryPerDB: true
wiredTiger:
engineConfig:
cacheSizeGB: 3.5

inMemory:
engineConfig:
inMemorySizeGB: 0.25

log:

{“t”:{"$date":“2021-07-22T09:22:07.761+08:00”},“s”:“I”, “c”:“CONTROL”, “id”:23285, “ctx”:"-",“msg”:“Automatically disabling TLS 1.0, to force-enable TLS 1.0 specify --sslDisabledProtocols ‘none’”}
{“t”:{"$date":“2021-07-22T09:22:07.843+08:00”},“s”:“I”, “c”:“NETWORK”, “id”:4915701, “ctx”:“main”,“msg”:“Initialized wire specification”,“attr”:{“spec”:{“incomingExternalClient”:{“minWireVersion”:0,“maxWireVersion”:13},“incomingInternalClient”:{“minWireVersion”:0,“maxWireVersion”:13},“outgoing”:{“minWireVersion”:0,“maxWireVersion”:13},“isInternalClient”:true}}}
{“t”:{"$date":“2021-07-22T09:22:07.845+08:00”},“s”:“W”, “c”:“ASIO”, “id”:22601, “ctx”:“main”,“msg”:“No TransportLayer configured during NetworkInterface startup”}
{“t”:{"$date":“2021-07-22T09:22:07.845+08:00”},“s”:“I”, “c”:“NETWORK”, “id”:4648602, “ctx”:“main”,“msg”:“Implicit TCP FastOpen in use.”}
{“t”:{"$date":“2021-07-22T09:22:07.847+08:00”},“s”:“W”, “c”:“ASIO”, “id”:22601, “ctx”:“main”,“msg”:“No TransportLayer configured during NetworkInterface startup”}
{“t”:{"$date":“2021-07-22T09:22:07.847+08:00”},“s”:“I”, “c”:“REPL”, “id”:5123008, “ctx”:“main”,“msg”:“Successfully registered PrimaryOnlyService”,“attr”:{“service”:“TenantMigrationDonorService”,“ns”:“config.tenantMigrationDonors”}}
{“t”:{"$date":“2021-07-22T09:22:07.847+08:00”},“s”:“I”, “c”:“REPL”, “id”:5123008, “ctx”:“main”,“msg”:“Successfully registered PrimaryOnlyService”,“attr”:{“service”:“TenantMigrationRecipientService”,“ns”:“config.tenantMigrationRecipients”}}
{“t”:{"$date":“2021-07-22T09:22:07.848+08:00”},“s”:“I”, “c”:“CONTROL”, “id”:4615611, “ctx”:“initandlisten”,“msg”:“MongoDB starting”,“attr”:{“pid”:7220,“port”:27017,“dbPath”:"./data/db",“architecture”:“64-bit”,“host”:“WIN-0R70AN8D2TT”}}
{“t”:{"$date":“2021-07-22T09:22:07.848+08:00”},“s”:“I”, “c”:“CONTROL”, “id”:23398, “ctx”:“initandlisten”,“msg”:“Target operating system minimum version”,“attr”:{“targetMinOS”:“Windows 7/Windows Server 2008 R2”}}
{“t”:{"$date":“2021-07-22T09:22:07.848+08:00”},“s”:“I”, “c”:“CONTROL”, “id”:23403, “ctx”:“initandlisten”,“msg”:“Build Info”,“attr”:{“buildInfo”:{“version”:“5.0.0”,“gitVersion”:“1184f004a99660de6f5e745573419bda8a28c0e9”,“modules”:[],“allocator”:“tcmalloc”,“environment”:{“distmod”:“windows”,“distarch”:“x86_64”,“target_arch”:“x86_64”}}}}
{“t”:{"$date":“2021-07-22T09:22:07.848+08:00”},“s”:“I”, “c”:“CONTROL”, “id”:51765, “ctx”:“initandlisten”,“msg”:“Operating System”,“attr”:{“os”:{“name”:“Microsoft Windows Server 2016”,“version”:“10.0 (build 14393)”}}}
{“t”:{"$date":“2021-07-22T09:22:07.848+08:00”},“s”:“I”, “c”:“CONTROL”, “id”:21951, “ctx”:“initandlisten”,“msg”:“Options set by command line”,“attr”:{“options”:{“config”:“mongo.conf”,“net”:{“bindIp”:"*"},“storage”:{“dbPath”:"./data/db",“wiredTiger”:{“engineConfig”:{“cacheSizeGB”:3.5}}}}}}
{“t”:{"$date":“2021-07-22T09:22:07.855+08:00”},“s”:“I”, “c”:“STORAGE”, “id”:22270, “ctx”:“initandlisten”,“msg”:“Storage engine to use detected by data files”,“attr”:{“dbpath”:"./data/db",“storageEngine”:“wiredTiger”}}
{“t”:{"$date":“2021-07-22T09:22:07.855+08:00”},“s”:“I”, “c”:“STORAGE”, “id”:22315, “ctx”:“initandlisten”,“msg”:“Opening WiredTiger”,“attr”:{“config”:“create,cache_size=3584M,session_max=33000,eviction=(threads_min=4,threads_max=4),config_base=false,statistics=(fast),log=(enabled=true,archive=true,path=journal,compressor=snappy),builtin_extension_config=(zstd=(compression_level=6)),file_manager=(close_idle_time=600,close_scan_interval=10,close_handle_minimum=250),statistics_log=(wait=0),verbose=[recovery_progress,checkpoint_progress,compact_progress],”}}
{“t”:{"$date":“2021-07-22T09:22:07.897+08:00”},“s”:“I”, “c”:“STORAGE”, “id”:22430, “ctx”:“initandlisten”,“msg”:“WiredTiger message”,“attr”:{“message”:"[1626916927:897302][7220:140733713962704], txn-recover: [WT_VERB_RECOVERY_PROGRESS] Recovering log 194 through 195"}}
{“t”:{"$date":“2021-07-22T09:22:07.968+08:00”},“s”:“I”, “c”:“STORAGE”, “id”:22430, “ctx”:“initandlisten”,“msg”:“WiredTiger message”,“attr”:{“message”:"[1626916927:968324][7220:140733713962704], txn-recover: [WT_VERB_RECOVERY_PROGRESS] Recovering log 195 through 195"}}
{“t”:{"$date":“2021-07-22T09:22:59.234+08:00”},“s”:“I”, “c”:“STORAGE”, “id”:22430, “ctx”:“initandlisten”,“msg”:“WiredTiger message”,“attr”:{“message”:"[1626916979:234341][7220:140733713962704], txn-recover: [WT_VERB_RECOVERY | WT_VERB_RECOVERY_PROGRESS] Main recovery loop: starting at 194/16107776 to 195/256"}}
{“t”:{"$date":“2021-07-22T09:22:59.379+08:00”},“s”:“I”, “c”:“STORAGE”, “id”:22430, “ctx”:“initandlisten”,“msg”:“WiredTiger message”,“attr”:{“message”:"[1626916979:379343][7220:140733713962704], txn-recover: [WT_VERB_RECOVERY_PROGRESS] Recovering log 194 through 195"}}
{“t”:{"$date":“2021-07-22T09:22:59.459+08:00”},“s”:“I”, “c”:“STORAGE”, “id”:22430, “ctx”:“initandlisten”,“msg”:“WiredTiger message”,“attr”:{“message”:"[1626916979:459351][7220:140733713962704], txn-recover: [WT_VERB_RECOVERY_PROGRESS] Recovering log 195 through 195"}}
{“t”:{"$date":“2021-07-22T09:22:59.534+08:00”},“s”:“I”, “c”:“STORAGE”, “id”:22430, “ctx”:“initandlisten”,“msg”:“WiredTiger message”,“attr”:{“message”:"[1626916979:533345][7220:140733713962704], txn-recover: [WT_VERB_RECOVERY | WT_VERB_RECOVERY_PROGRESS] Set global recovery timestamp: (0, 0)"}}
{“t”:{"$date":“2021-07-22T09:22:59.534+08:00”},“s”:“I”, “c”:“STORAGE”, “id”:22430, “ctx”:“initandlisten”,“msg”:“WiredTiger message”,“attr”:{“message”:"[1626916979:533345][7220:140733713962704], txn-recover: [WT_VERB_RECOVERY | WT_VERB_RECOVERY_PROGRESS] Set global oldest timestamp: (0, 0)"}}
{“t”:{"$date":“2021-07-22T09:23:19.534+08:00”},“s”:“I”, “c”:“STORAGE”, “id”:22430, “ctx”:“initandlisten”,“msg”:“WiredTiger message”,“attr”:{“message”:"[1626916999:534545][7220:140733713962704], txn rollback_to_stable: [WT_VERB_RECOVERY_PROGRESS] Rollback to stable has been running for 20 seconds and has inspected 775611 files. For more detailed logging, enable WT_VERB_RTS"}}
{“t”:{"$date":“2021-07-22T09:23:24.653+08:00”},“s”:“I”, “c”:“STORAGE”, “id”:22430, “ctx”:“initandlisten”,“msg”:“WiredTiger message”,“attr”:{“message”:"[1626917004:653684][7220:140733713962704], WT_SESSION.checkpoint: [WT_VERB_CHECKPOINT_PROGRESS] saving checkpoint snapshot min: 1, snapshot max: 1 snapshot count: 0, oldest timestamp: (0, 0) , meta checkpoint timestamp: (0, 0)"}}
{“t”:{"$date":“2021-07-22T09:23:32.057+08:00”},“s”:“I”, “c”:“STORAGE”, “id”:4795906, “ctx”:“initandlisten”,“msg”:“WiredTiger opened”,“attr”:{“durationMillis”:84201}}
{“t”:{"$date":“2021-07-22T09:23:32.057+08:00”},“s”:“I”, “c”:“RECOVERY”, “id”:23987, “ctx”:“initandlisten”,“msg”:“WiredTiger recoveryTimestamp”,“attr”:{“recoveryTimestamp”:{"$timestamp":{“t”:0,“i”:0}}}}
{“t”:{"$date":“2021-07-22T09:23:32.059+08:00”},“s”:“I”, “c”:“STORAGE”, “id”:4366408, “ctx”:“initandlisten”,“msg”:“No table logging settings modifications are required for existing WiredTiger tables”,“attr”:{“loggingEnabled”:true}}

now it’s 10:40 and no new log msg
i have 407,979 files, 15.9 GB data.

8-core CPU occupies 13%, No hard drive reading，memory is 1480M and growth is very slow

thinks

2

storage:
dbPath: ./data/db

wiredTiger:
engineConfig:
cacheSizeGB: 3.5

3

now it’s 14:04 and no new log msg，it pass 4.5hours

4

Finally, almost 6 hours later, it started up

{"t":{"$date":"2021-07-22T09:22:07.761+08:00"},"s":"I",  "c":"CONTROL",  "id":23285,   "ctx":"-","msg":"Automatically disabling TLS 1.0, to force-enable TLS 1.0 specify --sslDisabledProtocols 'none'"}
{"t":{"$date":"2021-07-22T09:22:07.843+08:00"},"s":"I",  "c":"NETWORK",  "id":4915701, "ctx":"main","msg":"Initialized wire specification","attr":{"spec":{"incomingExternalClient":{"minWireVersion":0,"maxWireVersion":13},"incomingInternalClient":{"minWireVersion":0,"maxWireVersion":13},"outgoing":{"minWireVersion":0,"maxWireVersion":13},"isInternalClient":true}}}
{"t":{"$date":"2021-07-22T09:22:07.845+08:00"},"s":"W",  "c":"ASIO",     "id":22601,   "ctx":"main","msg":"No TransportLayer configured during NetworkInterface startup"}
{"t":{"$date":"2021-07-22T09:22:07.845+08:00"},"s":"I",  "c":"NETWORK",  "id":4648602, "ctx":"main","msg":"Implicit TCP FastOpen in use."}
{"t":{"$date":"2021-07-22T09:22:07.847+08:00"},"s":"W",  "c":"ASIO",     "id":22601,   "ctx":"main","msg":"No TransportLayer configured during NetworkInterface startup"}
{"t":{"$date":"2021-07-22T09:22:07.847+08:00"},"s":"I",  "c":"REPL",     "id":5123008, "ctx":"main","msg":"Successfully registered PrimaryOnlyService","attr":{"service":"TenantMigrationDonorService","ns":"config.tenantMigrationDonors"}}
{"t":{"$date":"2021-07-22T09:22:07.847+08:00"},"s":"I",  "c":"REPL",     "id":5123008, "ctx":"main","msg":"Successfully registered PrimaryOnlyService","attr":{"service":"TenantMigrationRecipientService","ns":"config.tenantMigrationRecipients"}}
{"t":{"$date":"2021-07-22T09:22:07.848+08:00"},"s":"I",  "c":"CONTROL",  "id":4615611, "ctx":"initandlisten","msg":"MongoDB starting","attr":{"pid":7220,"port":27017,"dbPath":"./data/db","architecture":"64-bit","host":"WIN-0R70AN8D2TT"}}
{"t":{"$date":"2021-07-22T09:22:07.848+08:00"},"s":"I",  "c":"CONTROL",  "id":23398,   "ctx":"initandlisten","msg":"Target operating system minimum version","attr":{"targetMinOS":"Windows 7/Windows Server 2008 R2"}}
{"t":{"$date":"2021-07-22T09:22:07.848+08:00"},"s":"I",  "c":"CONTROL",  "id":23403,   "ctx":"initandlisten","msg":"Build Info","attr":{"buildInfo":{"version":"5.0.0","gitVersion":"1184f004a99660de6f5e745573419bda8a28c0e9","modules":[],"allocator":"tcmalloc","environment":{"distmod":"windows","distarch":"x86_64","target_arch":"x86_64"}}}}
{"t":{"$date":"2021-07-22T09:22:07.848+08:00"},"s":"I",  "c":"CONTROL",  "id":51765,   "ctx":"initandlisten","msg":"Operating System","attr":{"os":{"name":"Microsoft Windows Server 2016","version":"10.0 (build 14393)"}}}
{"t":{"$date":"2021-07-22T09:22:07.848+08:00"},"s":"I",  "c":"CONTROL",  "id":21951,   "ctx":"initandlisten","msg":"Options set by command line","attr":{"options":{"config":"mongo.conf","net":{"bindIp":"*"},"storage":{"dbPath":"./data/db","wiredTiger":{"engineConfig":{"cacheSizeGB":3.5}}}}}}
{"t":{"$date":"2021-07-22T09:22:07.855+08:00"},"s":"I",  "c":"STORAGE",  "id":22270,   "ctx":"initandlisten","msg":"Storage engine to use detected by data files","attr":{"dbpath":"./data/db","storageEngine":"wiredTiger"}}
{"t":{"$date":"2021-07-22T09:22:07.855+08:00"},"s":"I",  "c":"STORAGE",  "id":22315,   "ctx":"initandlisten","msg":"Opening WiredTiger","attr":{"config":"create,cache_size=3584M,session_max=33000,eviction=(threads_min=4,threads_max=4),config_base=false,statistics=(fast),log=(enabled=true,archive=true,path=journal,compressor=snappy),builtin_extension_config=(zstd=(compression_level=6)),file_manager=(close_idle_time=600,close_scan_interval=10,close_handle_minimum=250),statistics_log=(wait=0),verbose=[recovery_progress,checkpoint_progress,compact_progress],"}}
{"t":{"$date":"2021-07-22T09:22:07.897+08:00"},"s":"I",  "c":"STORAGE",  "id":22430,   "ctx":"initandlisten","msg":"WiredTiger message","attr":{"message":"[1626916927:897302][7220:140733713962704], txn-recover: [WT_VERB_RECOVERY_PROGRESS] Recovering log 194 through 195"}}
{"t":{"$date":"2021-07-22T09:22:07.968+08:00"},"s":"I",  "c":"STORAGE",  "id":22430,   "ctx":"initandlisten","msg":"WiredTiger message","attr":{"message":"[1626916927:968324][7220:140733713962704], txn-recover: [WT_VERB_RECOVERY_PROGRESS] Recovering log 195 through 195"}}
{"t":{"$date":"2021-07-22T09:22:59.234+08:00"},"s":"I",  "c":"STORAGE",  "id":22430,   "ctx":"initandlisten","msg":"WiredTiger message","attr":{"message":"[1626916979:234341][7220:140733713962704], txn-recover: [WT_VERB_RECOVERY | WT_VERB_RECOVERY_PROGRESS] Main recovery loop: starting at 194/16107776 to 195/256"}}
{"t":{"$date":"2021-07-22T09:22:59.379+08:00"},"s":"I",  "c":"STORAGE",  "id":22430,   "ctx":"initandlisten","msg":"WiredTiger message","attr":{"message":"[1626916979:379343][7220:140733713962704], txn-recover: [WT_VERB_RECOVERY_PROGRESS] Recovering log 194 through 195"}}
{"t":{"$date":"2021-07-22T09:22:59.459+08:00"},"s":"I",  "c":"STORAGE",  "id":22430,   "ctx":"initandlisten","msg":"WiredTiger message","attr":{"message":"[1626916979:459351][7220:140733713962704], txn-recover: [WT_VERB_RECOVERY_PROGRESS] Recovering log 195 through 195"}}
{"t":{"$date":"2021-07-22T09:22:59.534+08:00"},"s":"I",  "c":"STORAGE",  "id":22430,   "ctx":"initandlisten","msg":"WiredTiger message","attr":{"message":"[1626916979:533345][7220:140733713962704], txn-recover: [WT_VERB_RECOVERY | WT_VERB_RECOVERY_PROGRESS] Set global recovery timestamp: (0, 0)"}}
{"t":{"$date":"2021-07-22T09:22:59.534+08:00"},"s":"I",  "c":"STORAGE",  "id":22430,   "ctx":"initandlisten","msg":"WiredTiger message","attr":{"message":"[1626916979:533345][7220:140733713962704], txn-recover: [WT_VERB_RECOVERY | WT_VERB_RECOVERY_PROGRESS] Set global oldest timestamp: (0, 0)"}}
{"t":{"$date":"2021-07-22T09:23:19.534+08:00"},"s":"I",  "c":"STORAGE",  "id":22430,   "ctx":"initandlisten","msg":"WiredTiger message","attr":{"message":"[1626916999:534545][7220:140733713962704], txn rollback_to_stable: [WT_VERB_RECOVERY_PROGRESS] Rollback to stable has been running for 20 seconds and has inspected 775611 files. For more detailed logging, enable WT_VERB_RTS"}}
{"t":{"$date":"2021-07-22T09:23:24.653+08:00"},"s":"I",  "c":"STORAGE",  "id":22430,   "ctx":"initandlisten","msg":"WiredTiger message","attr":{"message":"[1626917004:653684][7220:140733713962704], WT_SESSION.checkpoint: [WT_VERB_CHECKPOINT_PROGRESS] saving checkpoint snapshot min: 1, snapshot max: 1 snapshot count: 0, oldest timestamp: (0, 0) , meta checkpoint timestamp: (0, 0)"}}
{"t":{"$date":"2021-07-22T09:23:32.057+08:00"},"s":"I",  "c":"STORAGE",  "id":4795906, "ctx":"initandlisten","msg":"WiredTiger opened","attr":{"durationMillis":84201}}
{"t":{"$date":"2021-07-22T09:23:32.057+08:00"},"s":"I",  "c":"RECOVERY", "id":23987,   "ctx":"initandlisten","msg":"WiredTiger recoveryTimestamp","attr":{"recoveryTimestamp":{"$timestamp":{"t":0,"i":0}}}}
{"t":{"$date":"2021-07-22T09:23:32.059+08:00"},"s":"I",  "c":"STORAGE",  "id":4366408, "ctx":"initandlisten","msg":"No table logging settings modifications are required for existing WiredTiger tables","attr":{"loggingEnabled":true}}
{"t":{"$date":"2021-07-22T15:11:02.608+08:00"},"s":"I",  "c":"STORAGE",  "id":22262,   "ctx":"initandlisten","msg":"Timestamp monitor starting"}
{"t":{"$date":"2021-07-22T15:11:02.611+08:00"},"s":"W",  "c":"CONTROL",  "id":22120,   "ctx":"initandlisten","msg":"Access control is not enabled for the database. Read and write access to data and configuration is unrestricted","tags":["startupWarnings"]}
{"t":{"$date":"2021-07-22T15:11:02.944+08:00"},"s":"I",  "c":"NETWORK",  "id":4915702, "ctx":"initandlisten","msg":"Updated wire specification","attr":{"oldSpec":{"incomingExternalClient":{"minWireVersion":0,"maxWireVersion":13},"incomingInternalClient":{"minWireVersion":0,"maxWireVersion":13},"outgoing":{"minWireVersion":0,"maxWireVersion":13},"isInternalClient":true},"newSpec":{"incomingExternalClient":{"minWireVersion":0,"maxWireVersion":13},"incomingInternalClient":{"minWireVersion":13,"maxWireVersion":13},"outgoing":{"minWireVersion":13,"maxWireVersion":13},"isInternalClient":true}}}
{"t":{"$date":"2021-07-22T15:11:04.959+08:00"},"s":"I",  "c":"STORAGE",  "id":5071100, "ctx":"initandlisten","msg":"Clearing temp directory"}
{"t":{"$date":"2021-07-22T15:11:24.034+08:00"},"s":"I",  "c":"CONTROL",  "id":20536,   "ctx":"initandlisten","msg":"Flow Control is enabled on this deployment"}
{"t":{"$date":"2021-07-22T15:11:24.334+08:00"},"s":"I",  "c":"FTDC",     "id":20625,   "ctx":"initandlisten","msg":"Initializing full-time diagnostic data capture","attr":{"dataDirectory":"./data/db/diagnostic.data"}}
{"t":{"$date":"2021-07-22T15:11:24.401+08:00"},"s":"I",  "c":"NETWORK",  "id":23015,   "ctx":"listener","msg":"Listening on","attr":{"address":"0.0.0.0"}}
{"t":{"$date":"2021-07-22T15:11:24.401+08:00"},"s":"I",  "c":"NETWORK",  "id":23016,   "ctx":"listener","msg":"Waiting for connections","attr":{"port":27017,"ssl":"off"}}
5

Did you migrate from 4.x or have you created the data on 5 ? Are you using HDD or SSD ?

6

@John_Moser1, I’m not the one who posted this, but I’m facing the same issue after migrating. Any tips?