[SERVER-28193] Startup delay when running up a cloned secondary Created: 04/Mar/17 Updated: 12/Jul/17 Resolved: 09/Jun/17 |
|
| Status: | Closed |
| Project: | Core Server |
| Component/s: | MMAPv1 |
| Affects Version/s: | 3.4.2 |
| Fix Version/s: | None |
| Type: | Question | Priority: | Major - P3 |
| Reporter: | Paul Reed | Assignee: | Mark Agarunov |
| Resolution: | Cannot Reproduce | Votes: | 0 |
| Labels: | None | ||
| Remaining Estimate: | Not Specified | ||
| Time Spent: | Not Specified | ||
| Original Estimate: | Not Specified | ||
| Participants: |
| Description |
|
When starting up the mongod service on a standalone machine utilising a cloned drive from a stopped secondary, there is a start up delay of 2-3 minutes whilst stuff (unlogged) occurs. Is there a way to prevent this delay ? Process Log extract:
|
| Comments |
| Comment by Mark Agarunov [ 09/Jun/17 ] | |||||||||||||||
|
Hello paul.reed, Unfortunately I have still not been able to reproduce the behavior you've described. I've closed this ticket as "cannot reproduce", but if any new information comes to light, please let us know and we will further investigate the issue. Thanks, | |||||||||||||||
| Comment by Mark Agarunov [ 01/May/17 ] | |||||||||||||||
|
Hello paul.reed, My apologies for the delay in response. Unfortunately we have not yet established a definitive cause for the behavior you're seeing and are still investigating the issue. We will post updates on this as they are available. Thanks, | |||||||||||||||
| Comment by Paul Reed [ 25/Apr/17 ] | |||||||||||||||
|
Any progress on this ? | |||||||||||||||
| Comment by Paul Reed [ 04/Apr/17 ] | |||||||||||||||
|
Ok - I have done that. Same machine as before. open shell
As you can see that this is now super speedy. – The machine running against this cloned drive is not one of the members of the replset. | |||||||||||||||
| Comment by Mark Agarunov [ 03/Apr/17 ] | |||||||||||||||
|
Hello paul.reed, Thank you for providing these files. Looking over the logs, it looks like the startup time may be disk io limited, however I would like to compare these logs to the logs from a startup that you don't experience the issue, also with verbose logging enabled. This would allow us to verify if the cause of the longer startup is a bug or a symptom of disk io limiting the speed of MMAPv1 recovery. To restate, please provide the complete logs, with verbose logging enabled as before, from a startup where this issue is not present if possible. Thanks, | |||||||||||||||
| Comment by Paul Reed [ 28/Mar/17 ] | |||||||||||||||
|
Files now uploaded - was not in the office last week. | |||||||||||||||
| Comment by Paul Reed [ 21/Mar/17 ] | |||||||||||||||
|
Sorry - will upload tomorrow. Missed that you were waiting on me. | |||||||||||||||
| Comment by Mark Agarunov [ 21/Mar/17 ] | |||||||||||||||
|
Hello paul.reed, We haven’t heard back from you for some time, so I’m going to mark this ticket as resolved. If this is still an issue for you, please provide additional information and we will reopen the ticket. Thanks, | |||||||||||||||
| Comment by Mark Agarunov [ 10/Mar/17 ] | |||||||||||||||
|
Hello paul.reed, Thank you for providing this. We are still investigating the issue and may need some more information. If possible, please provide:
I've created an upload portal so that you can securely send us these files. Thanks, | |||||||||||||||
| Comment by Paul Reed [ 08/Mar/17 ] | |||||||||||||||
|
I wont post it here: but it does these operations over and over - I guess for every collection/database. mmf open c:/MongoDBDrive/data\z-Resources\z-Resources.ns 2017-03-08T20:12:57.197+0000 D STORAGE [initandlisten] test().Got99: clearing plan cache - collection info cache reset
2017-03-08T20:12:57.470+0000 D INDEX [initandlisten] "IndexRebuilder"::checkNS: admin.system.indexes
Taking 3 minutes in total.
log shows nothing unusual I think:
| |||||||||||||||
| Comment by Mark Agarunov [ 08/Mar/17 ] | |||||||||||||||
|
Hello paul.reed, Thank you for the report. To get a better idea of what may be causing this behavior, please set the logging verbosity for mongod to 5, either by passing -vvvvv as an option to mongod on the command line, or setting the verbosity parameter under systemLog in your configuration file to 5, and provide the complete log file from mongod. This may shed some light on what mongod is doing during this delay. Thanks, | |||||||||||||||
| Comment by Paul Reed [ 07/Mar/17 ] | |||||||||||||||
|
I am also seeing the delay on replicaset servers as well actually.
| |||||||||||||||
| Comment by Paul Reed [ 04/Mar/17 ] | |||||||||||||||
|
*I meant 2 -3 minutes - of course 2-3 seconds would be fine. !! We are running about 1TB of data. |