[SERVER-18784] Errors during concurrent update/upsert on an existing document with a unique index Created: 01/Jun/15  Updated: 16/Oct/21  Resolved: 03/Aug/15

Status: Closed
Project: Core Server
Component/s: Concurrency, Index Maintenance, Querying, Write Ops
Affects Version/s: 2.6.3, 3.0.3
Fix Version/s: None

Type: Bug Priority: Minor - P4
Reporter: aaskar Assignee: Ramon Fernandez Marina
Resolution: Duplicate Votes: 0
Labels: None
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified

Issue Links:
Duplicate
duplicates SERVER-14322 Retry on predicate unique index viola... Closed
Operating System: ALL
Steps To Reproduce:

Tested using version 2.6.3 and 3.0.3.
Run MongoDB locally as follow (Note that the test will write about ~4 GB of data): ./mongodb-osx-x86_64-2.6.10/bin/mongod --dbpath /tmp/mongo Run the following code once, restart the database, comment out the following line: "fillUpCollection(testMongoDB.col1, value, 0, 300);" (IMPORTANT), then run the code again.

package test;
 
import com.mongodb.BasicDBObject;
import com.mongodb.DBCollection;
import com.mongodb.DBObject;
import com.mongodb.Mongo;
import com.mongodb.MongoClient;
 
import java.io.IOException;
import java.util.ArrayList;
import java.util.List;
import java.util.Random;
 
public class TestMongoDB {
    public static final String DOC_ID = "docId";
    public static final String VALUE = "value";
    public static final String DB_NAME = "db1";
    public static final String UNIQUE = "unique";
    public static final String BACKGROUND = "background";
    private DBCollection col1;
    private DBCollection col2;
 
    private static DBCollection getCollection(Mongo mongo, String collectionName) {
        DBCollection col =  mongo.getDB(DB_NAME).getCollection(collectionName);
        BasicDBObject index = new BasicDBObject();
        index.append(DOC_ID, 1);
        DBObject indexOptions = new BasicDBObject();
        indexOptions.put(UNIQUE, true);
        indexOptions.put(BACKGROUND, true);
        col.createIndex(index, indexOptions);
        return col;
    }
 
    private static void storeDoc(String docId, DBObject doc, DBCollection dbCollection) throws IOException {
        BasicDBObject query = new BasicDBObject();
        query.put(DOC_ID, docId);
        dbCollection.update(query, doc, true, false);
        //dbCollection.findAndModify(query, null, null, false, doc, false, true);
    }
 
    public static void main(String[] args) throws Exception{
        final String value = new String(new char[1000000]).replace('\0', 'a');
        Mongo mongo = new MongoClient("localhost:27017");
        final TestMongoDB testMongoDB = new TestMongoDB();
        testMongoDB.col1 = getCollection(mongo, "col1");
        testMongoDB.col2 = getCollection(mongo, "col2");
 
        fillUpCollection(testMongoDB.col1, value, 0, 300);
        //restart Database, comment out previous line, and run again
        fillUpCollection(testMongoDB.col2, value, 0, 2000);
        updateExistingDocuments(testMongoDB, value);
    }
 
    private static void updateExistingDocuments(TestMongoDB testMongoDB, String value) {
        List<String> docIds = new ArrayList<String>();
        for(int i = 0; i < 10; i++) {
            docIds.add(new Random().nextInt(300) + "");
        }
        multiThreadUpdate(testMongoDB.col1, value, docIds);
    }
 
 
    private static void multiThreadUpdate(final DBCollection col, final String value, final List<String> docIds) {
        Runnable worker = new Runnable() {
            @Override
            public void run() {
                try {
                    System.out.println("Started Thread");
                    for(String id : docIds) {
                        storeDoc(id, getDbObject(value, id), col);
                    }
                } catch (Exception e) {
                    System.out.println(e);
                } finally {
                    System.out.println("Completed");
                }
            }
        };
 
        for(int i = 0; i < 8; i++) {
            new Thread(worker).start();
        }
    }
 
    private static DBObject getDbObject(String value, String docId) {
        final DBObject object2 = new BasicDBObject();
        object2.put(DOC_ID, docId);
        object2.put(VALUE, value);
        return object2;
    }
 
    private static void fillUpCollection(DBCollection col, String value, int from, int to) throws IOException {
        for(int i = from ; i <= to; i++) {
            storeDoc(i + "", getDbObject(value, i + ""), col);
        }
    }
}

Sample Output on the second run:

Started Thread
Started Thread
Started Thread
Started Thread
Started Thread
Started Thread
Started Thread
Started Thread
com.mongodb.DuplicateKeyException: Write failed with error code 11000 and error message 'insertDocument :: caused by :: 11000 E11000 duplicate key error index: db1.col1.$docId_1  dup key: { : "290" }'
Completed
com.mongodb.DuplicateKeyException: Write failed with error code 11000 and error message 'insertDocument :: caused by :: 11000 E11000 duplicate key error index: db1.col1.$docId_1  dup key: { : "170" }'
Completed
com.mongodb.DuplicateKeyException: Write failed with error code 11000 and error message 'insertDocument :: caused by :: 11000 E11000 duplicate key error index: db1.col1.$docId_1  dup key: { : "241" }'
Completed
com.mongodb.DuplicateKeyException: Write failed with error code 11000 and error message 'insertDocument :: caused by :: 11000 E11000 duplicate key error index: db1.col1.$docId_1  dup key: { : "127" }'
Completed
com.mongodb.DuplicateKeyException: Write failed with error code 11000 and error message 'insertDocument :: caused by :: 11000 E11000 duplicate key error index: db1.col1.$docId_1  dup key: { : "120" }'
Completed
com.mongodb.DuplicateKeyException: Write failed with error code 11000 and error message 'insertDocument :: caused by :: 11000 E11000 duplicate key error index: db1.col1.$docId_1  dup key: { : "91" }'
Completed
com.mongodb.DuplicateKeyException: Write failed with error code 11000 and error message 'insertDocument :: caused by :: 11000 E11000 duplicate key error index: db1.col1.$docId_1  dup key: { : "136" }'
Completed
Completed

Participants:

 Description   

Given a collection with a unique index and when running concurrent updates (3 threads) with upsert as true on a given existing document, 1 to 2 threads raise the following exception:

Processing failed (Write failed with error code 11000 and error message 'insertDocument :: caused by :: 11000 E11000 duplicate key error index: db1.col1.$key_1  dup key: { : 123 }'):

I would expect all of the three updates to succeed because the document I am trying to update already exists. Instead, it looks like it is trying to do an insert on few or all of the update requests and few fails due to the unique index. Repeating the same concurrent update on the document does not raise any exceptions. Also, using find() on a document to bring it to the working set, then running the concurrent updates on that document also runs as expected.



 Comments   
Comment by aaskar [ 03/Aug/15 ]

Thanks Ramon.

Comment by Ramon Fernandez Marina [ 03/Aug/15 ]

Hi aaskar; I was unable to reproduce the behavior you describe on my end. However we've found other cases of SERVER-14322, where this behavior is easier to trigger with the WiredTiger storage engine. Currently the workaround is to retry the operation at the application level.

I'm going to close this ticket as a duplicate of SERVER-14322. Please feel free to vote for SERVER-14322 and watch it for updates.

Thanks,
Ramón.

Comment by aaskar [ 02/Jun/15 ]

Ramon Fernandez, I have doubled checked again and yes, all 301 documents are in col1. Note that I only checked the content of the document for first 30 and did a count to see that there are 301 documents in the collections. Then I was successful in reproducing the behavior I have described. Note that the moment you list all 301 documents, you would not be able to reproduce the issue until the large number of writes to the other collection and restarting the database occur. It feels to me that when either the documents or the index are in part of the working set, things behave correctly.

Comment by Ramon Fernandez Marina [ 02/Jun/15 ]

aaskar, I'm definitely unable to reproduce this behavior; this is what I did:

  1. I compiled and run your code above
  2. Re-started mongod
  3. Commented out the fillUpCollection(testMongoDB.col1, value, 0, 300); line, re-compiled the code and re-run it

Can you please check that between your first and second runs all documents with doc_id from 0 to 300 are actually present in db.col1? I'm asking because there's a scenario that can account for the behavior you're seeing:

  1. Thread A is issued an update with upsert=true, and determines that no documents match the query predicate.
  2. Thread B is issued the same update with upsert=true, and determines that no documents match the query predicate.
  3. Thread A completes the update by inserting a new document.
  4. Thread B completes the update by inserting the same document.
    If the collection in question contains a unique index on a field "a", then operation #4 will fail with a unique index error, as the same document cannot be inserted twice in a collection with a unique (secondary) index.

This behavior is described in SERVER-14322 and in the various tickets that are marked as a duplicate of it.

Comment by aaskar [ 02/Jun/15 ]

Yes, the code is exactly the same that produced the output you see above on my machine. 3 threads is the original setup when I encountered this issue, but in the test code, I made it 8 and I write to col2 to simulate actions which seems to make it more likely to reproduce the issue. Once I run the test code a second time after restarting MongoDB and commenting out the single thread filling to col1, I get these errors consistently. I am not sure if it is related to disk speed or available RAM. I am not using SSD and I have 8 GB of RAM, but Mongo only takes few hundreds MBs of physical memory.

Did you restart the DB and comment out that line of code, before trying again? If yes, I also suggest trying to increase the document size and number of documents inserted to col2.

Comment by Ramon Fernandez Marina [ 02/Jun/15 ]

Thanks for your report aaskar. I tried reproducing this behavior in 2.6.9 and 3.0.3, but couldn't trigger the errors you describe. Are you sure the code above is the one triggering the problem? You mention 3 threads but the code above starts 8, and I also see col1 and col2 so I'm wondering if you have a slightly different version of this reproducer.

Generated at Thu Feb 08 03:48:44 UTC 2024 using Jira 9.7.1#970001-sha1:2222b88b221c4928ef0de3161136cc90c8356a66.