[SERVER-25791] Unique index becomes inconsistent with collection data Created: 25/Aug/16 Updated: 18/Apr/17 Resolved: 29/Mar/17 |
|
| Status: | Closed |
| Project: | Core Server |
| Component/s: | Index Maintenance, Querying, WiredTiger, Write Ops |
| Affects Version/s: | 3.2.8 |
| Fix Version/s: | None |
| Type: | Bug | Priority: | Major - P3 |
| Reporter: | imun Mikecin | Assignee: | Eric Milkie |
| Resolution: | Duplicate | Votes: | 3 |
| Labels: | uic | ||
| Remaining Estimate: | Not Specified | ||
| Time Spent: | Not Specified | ||
| Original Estimate: | Not Specified | ||
| Attachments: |
|
||||||||||||
| Issue Links: |
|
||||||||||||
| Operating System: | ALL | ||||||||||||
| Steps To Reproduce: | Try scenario described in the description above. |
||||||||||||
| Participants: | |||||||||||||
| Description |
|
I'm using an unique index:
My applications works in a way that many times an update (using $set and $unset) is sent that should be rejected with an ""E11000 duplicate key error collection: live.tasks.active index: state.agent_1" because of duplicate value in the above index. db.tasks.active.find({_id:ObjectId("57bea0f21ebfd0b31f32da1c")}) but a query that shows all data in the index doesn't show that document: db.tasks.active.find({"state.value":"assigned"}, {"state.agent": 1}) I have tried to do a db.tasks.active.reIndex(), but it failed with a message that db.tasks.active contains duplicate values for an above index so that above index cannot be re-added. Most times I do get E11000, but from time to time update doesn't return an error (as it should) and updates a document making a duplicate index key entry that is not visible in the index itself. |
| Comments |
| Comment by Eric Milkie [ 29/Mar/17 ] | ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
|
We discovered a problem with partial indexes that could explain the behavior you are seeing. Please follow the linked ticket for further updates. | ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
| Comment by Eric Milkie [ 27/Mar/17 ] | ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
|
Hi sime, | ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
| Comment by imun Mikecin [ 07/Sep/16 ] | ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
|
Thomas, 1. I can confirm that there were no unclean shutdowns PHP: mongo PHP: mongodb C++: libmongodb-2.4.14-1.el6.x86_64 (RPM package from RHEL 6) 3. I can confirm that we are not using bulk upserts, but we are doing updates that affect multiple documents. | ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
| Comment by Kelsey Schubert [ 06/Sep/16 ] | ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
|
Hi sime, Thank you for uploading the files, we are still working on reproducing this issue to understand the root cause.
Manual intervention is required to resolve this inconsistent state. I would recommend the following approach:
Please let me know if you have any questions about this approach. Thank you, | ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
| Comment by imun Mikecin [ 29/Aug/16 ] | ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
|
I have just uploaded all log files I have and content of diagnostic.data to the upload portal. Currently, there is still invalid situation: query that uses an unique index doesn't return the same number of documents as a query that doesn't use an index. | ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
| Comment by Kelsey Schubert [ 26/Aug/16 ] | ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
|
Hi sime, Thank you for dump, I have moved it to secure upload portal where it will be only visible to MongoDB employees investigating the issue, and I've confirmed documents exist that violate the unique index's restriction. It appears the problematic documents were inserted between 2016-08-25T14:27:01.000Z and 2016-08-25T14:27:03.000Z. So we can continue to investigate, would you please upload the complete logs and an archive of the diagnostic.data to the upload portal? As Ramon mentioned, if you are able to provide code that reproduces this issue it would greatly speed our investigation. Kind regards, | ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
| Comment by imun Mikecin [ 26/Aug/16 ] | ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
|
Last night we did an upgrade to version 3.2.9. Query with not using an index:
Query with using an index:
I have attached a mongodump of this collection at approximatelly the same time this queries were run (be aware that at the same time this colection was constantly updated by other applications). | ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
| Comment by imun Mikecin [ 25/Aug/16 ] | ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
|
Since this was a production environment that had to be resolved ASAP: I had to replace this collection with another collection (renamed to the name of the old collection) and recreate indexes. We haven't found a problem since (this was done today). But I have previous results of querying an oplog.rs collections that will give you an idea of document schema and sample $set and $unset operations runned by application code (since documents contain real customer data I've had to replace those with XXX):
| ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
| Comment by Ramon Fernandez Marina [ 25/Aug/16 ] | ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
|
simun.mikecin@me.com, is it possible for you to share code that reproduces the behavior you describe? Can you send us a sample of the $set and $unset update operations? Also, can you upload a few sample problematic documents? For example, the one with _id: ObjectId("57bea0f21ebfd0b31f32da1c") and the output of db.tasks.active.find({"state.value":"assigned"}, {"state.agent": 1}) above. Alternatively, if you can share your whole dbpath or a mongodump of the affected collection that may make things easier: I've created a safe, secure upload portal for that. Thanks, | ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
| Comment by imun Mikecin [ 25/Aug/16 ] | ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
|
Just for info: this is a Replica Set with only one server in the Replica Set (because we need oplog.rs). |