[SERVER-54445] Compact in Secondary ReplicaSet 4.4.0 change member state Created: 10/Feb/21  Updated: 22/Feb/21  Resolved: 21/Feb/21

Status: Closed
Project: Core Server
Component/s: Build, Logging, Replication
Affects Version/s: 4.4.0
Fix Version/s: None

Type: Question Priority: Major - P3
Reporter: Flavio Liroa Jr Assignee: Dmitry Agranat
Resolution: Duplicate Votes: 0
Labels: None
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified
Environment:

OS:
18.04.4 LTS (Bionic Beaver)


Attachments: Text File logcompact_primary.log     Text File logcompact_secondary_2.log     Text File logcompact_secondary_4.log    
Issue Links:
Duplicate
is duplicated by DOCS-14122 Add clarification about compact comma... Closed
Related
related to SERVER-52735 mongodb crash with "Invariant failure... Closed
Participants:
Case:

 Description   

We have a replicaSet in version 4.4.0 with 1 primary and 2 secondary, as per rs.conf below:

_"members" : [
{
"_id" : 4,
"host" : "10.208.0.102:27017",
"arbiterOnly" : false,
"buildIndexes" : true,
"hidden" : false,
"priority" : 6,
"tags" : {

},
"slaveDelay" : NumberLong(0),
"votes" : 1
},
{
"_id" : 5,
"host" : "10.208.0.101:27017",
"arbiterOnly" : false,
"buildIndexes" : true,
"hidden" : false,
"priority" : 7,
"tags" : {

},
"slaveDelay" : NumberLong(0),
"votes" : 1
},
{
"_id" : 6,
"host" : "10.208.0.104:27017",
"arbiterOnly" : false,
"buildIndexes" : true,
"hidden" : false,
"priority" : 5,
"tags" : {

},
"slaveDelay" : NumberLong(0),
"votes" : 1
}
]_

When executing a compact on the secondary member (.104) at 12:08, it entered maintenance mode and after that the other secondary member (.102) started to delay synchronization and we started to have unavailability in the applications that were connecting secondary instances.

After some delay in replication, I stopped the service at around 12:22 and the .102 instance was back in sync with the primary. Then at 12:28 I started the .104 secondary service and everything went back to normal.

Therefore, I have the following questions:

1 - Why did the .104 member enter maintenance mode, and the MongoDB documentation states that in version 4.4 the compact does not change the state and can be run at any time? (https://docs.mongodb.com/manual/release-notes/4.4/#compact-behavior-change);

2 - Even if the status of the .104 secondary member has changed, why was the secondary (.102) affected?

3 - Even if the secondary .102 had the .104 member as syncSource, once it entered maintenance mode, it should change the syncSource for the primary instance, right? Because in the documentation it informs that it needs to be PRIMARY or SECONDARY (https://docs.mongodb.com/manual/core/replica-set-sync/#initial-sync-source-selection)

Is it a version bug?

Thank you!



 Comments   
Comment by Dmitry Agranat [ 21/Feb/21 ]

Hi flavioliroa@gmail.com,

I already attached the compact logs in version 4.4.3

Thanks for attaching the latest 4.4.3 logs, as expected, we can see that the compact command entered the maintenance mode:

{"t":{"$date":"2021-02-05T14:15:04.562+00:00"},"s":"I",  "c":"REPL",     "id":21350,   "ctx":"conn216","msg":"Going into maintenance mode","attr":{"otherMaintenanceModeTasksInProgress":0}}
{"t":{"$date":"2021-02-05T14:15:04.562+00:00"},"s":"I",  "c":"REPL",     "id":21358,   "ctx":"conn216","msg":"Replica set state transition","attr":{"newState":"RECOVERING","oldState":"SECONDARY"}}
{"t":{"$date":"2021-02-05T14:15:04.563+00:00"},"s":"I",  "c":"COMMAND",  "id":20284,   "ctx":"conn216","msg":"Compact begin","attr":{"namespace":"broker-fulfillment-logistics.scheduleDetailsRequest"}}
{"t":{"$date":"2021-02-05T14:15:06.681+00:00"},"s":"I",  "c":"REPL",     "id":21351,   "ctx":"conn216","msg":"Leaving maintenance mode","attr":{"otherMaintenanceModeTasksOngoing":0}}

It turns out that when I ran the compact I was following rs.status() and it continued as SECONDARY, so I thought it hadn't changed to RECOVERING. I believe I didn't realize it because it was too fast, right?

This is correct

As for the mistake you mentioned above, was that the reason then?

The above issue is being investigated in SERVER-52735

If then the way the compact is made has not been changed in version 4.4, what would be the correct strategy to apply the compact to a replicaSet?

As per our documentation:

  • compact commands do not replicate to secondaries in a replica set.
  • Compact each member separately.
  • Ideally run compact on a secondary.

I will go ahead and close this ticket as the issue was identified and the documentation change was issued in DOCS-14122.

Regards,
Dima

Comment by Flavio Liroa Jr [ 18/Feb/21 ]

Please, Dmitry.

I have another question:

If then the way the compact is made has not been changed in version 4.4, what would be the correct strategy to apply the compact to a replicaSet?

Comment by Flavio Liroa Jr [ 18/Feb/21 ]

Dmitry, good morning!

I already attached the compact logs in version 4.4.3. I noticed that in fact there was a change in the member's status.

It turns out that when I ran the compact I was following rs.status() and it continued as SECONDARY, so I thought it hadn't changed to RECOVERING. I believe I didn't realize it because it was too fast, right?

In the two cases I mentioned (.0 and .3) were there total unavailability of the cluster in the period? That is, the primary also stopped reading and writing?

As for the mistake you mentioned above, was that the reason then?

Hug!

Comment by Dmitry Agranat [ 18/Feb/21 ]

Hi flavioliroa@gmail.com,

Regarding the state of events on 4.4.0, I do not think it is relevant for our investigation because after you have started the compact, you've hit this error (please note that I have redacted the actual collection name and it appears below as redacted.redacted):

{"t":{"$date":"2021-02-02T12:10:18.808+00:00"},"s":"I",  "c":"COMMAND",  "id":20284,   "ctx":"conn353303","msg":"Compact begin","attr":{"namespace":"redacted.redacted"}}
{"t":{"$date":"2021-02-02T12:10:18.819+00:00"},"s":"F",  "c":"-",        "id":23079,   "ctx":"TopologyVersionObserver","msg":"Invariant failure","attr":{"expr":"opCtx != nullptr && _opCtx == nullptr","file":"src/mongo/db/client.cpp","line":126}}

The above issue is being investigated in SERVER-52735

As for 4.4.3, would you please archive (tar or zip) the full mongod.log files from all members covering the time the compact command was executed and the $dbpath/diagnostic.data directory and upload them to the same support uploader location?

Thanks,
Dima

Comment by Flavio Liroa Jr [ 17/Feb/21 ]

Dmitry, good afternoon!

Is there a deadline for the response?

Comment by Dmitry Agranat [ 17/Feb/21 ]

Thanks flavioliroa@gmail.com for the latest update. We are investigating and will let you know about the findings.

Comment by Flavio Liroa Jr [ 15/Feb/21 ]

Hi Dmitry!

Any update?

Comment by Flavio Liroa Jr [ 11/Feb/21 ]

To test, I ran the compact on a secondary instance of another environment with version 4.4.3 and there was no change in the state of the member. It remained operational (SECONDARY status) exactly as the documentation said, but only in this environment with 4.4.0 did this occur.
When you say the documentation is wrong, in what sense?

Comment by Dmitry Agranat [ 11/Feb/21 ]

flavioliroa@gmail.com, the documentation is incorrect, we didn't change the behavior of setting maintenance mode on secondary nodes in MongoDB 4.4. DOCS-14122 should address this inconsistency.

Comment by Flavio Liroa Jr [ 11/Feb/21 ]

Hello, Dmitry Agranat!

About the maintenance mode during the compact, what I wanted to know is that, since the version of MongoDB is 4.4 it shouldn't happen, right? It was exactly the opposite of what the documentation says:

"Before v4.4, compact blocked all operations for the database it was compacting, including MongoDB CRUD Operations, and was therefore recommended for use only during scheduled maintenance periods. Starting in v4.4, the compact command is appropriate for use at any time . "

I attached the logs of the three instances during the period (log_full.zip) and await more information.

Thank you!

Comment by Dmitry Agranat [ 11/Feb/21 ]

Hi flavioliroa@gmail.com,

We didn't change the behavior of setting maintenance mode on secondary nodes. We should make the documentation clearer about this. We have DOCS-14122 to clarify this behavior.

As for the rest of the questions, we'll need more information to understand what has happened.

Would you please archive (tar or zip) the full mongod.log files from all members covering the incident and the $dbpath/diagnostic.data directory (the contents are described here) and upload them to this support uploader location?

Files uploaded to this portal are visible only to MongoDB employees and are routinely deleted after some time.

Thanks,
Dima

Generated at Thu Feb 08 05:33:33 UTC 2024 using Jira 9.7.1#970001-sha1:2222b88b221c4928ef0de3161136cc90c8356a66.