OPERATIONAL DEFECT DATABASE
...
...
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.
aaskar commented on Mon, 3 Aug 2015 20:19:56 +0000: Thanks Ramon. ramon.fernandez commented on Mon, 3 Aug 2015 19:54:55 +0000: Hi aaskar; I was unable to reproduce the behavior you describe on my end. However we've found other cases of insert when possible" class="issue-link" data-issue-key="SERVER-14322">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 insert when possible" class="issue-link" data-issue-key="SERVER-14322">SERVER-14322. Please feel free to vote for insert when possible" class="issue-link" data-issue-key="SERVER-14322">SERVER-14322 and watch it for updates. Thanks, Ramón. aaskar commented on Tue, 2 Jun 2015 20:23:48 +0000: 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. ramon.fernandez commented on Tue, 2 Jun 2015 19:59:42 +0000: aaskar, I'm definitely unable to reproduce this behavior; this is what I did: I compiled and run your code above Re-started mongod 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: Thread A is issued an update with upsert=true, and determines that no documents match the query predicate. Thread B is issued the same update with upsert=true, and determines that no documents match the query predicate. Thread A completes the update by inserting a new document. 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 insert when possible" class="issue-link" data-issue-key="SERVER-14322">SERVER-14322 and in the various tickets that are marked as a duplicate of it. aaskar commented on Tue, 2 Jun 2015 15:46:16 +0000: 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. ramon.fernandez commented on Tue, 2 Jun 2015 15:06:36 +0000: 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.
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 docIds = new ArrayList(); 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 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
MongoDB Integration
Learn more about where this data comes from
Bug Scrub Advisor
Streamline upgrades with automated vendor bug scrubs
BugZero Enterprise
Wish you caught this bug sooner? Get proactive today.
