Java: UpdateResult of MongoCollectionImpl#updateOne reports modifiedCount = 0 despite having updated a document

Hi,
We are experiencing a really weird issue in one of our products, where getModifiedCount() of the BulkWriteResult in MongoCollectionImpl#updateOne() returns 0 even though there was an update performed for a field in the database.

Before initiating the update, the field in the persisted document is "lastSync" : ISODate("2021-11-24T14:31:33.000Z").
Then we call MongoCollection.updateOne(filterObject, updateObject, updateOptions), where filterObject holds the ID, and the other parameters are as follows:


Right after executing this line, the persisted document has the new value "lastSync" : ISODate("2021-11-24T14:32:11.000Z"), but getting the modifiedCount of updateOne's result returns 0.
Note: the 1h difference is due to different timezones being used when displaying the date, so that is not the issue :slight_smile:

I don’t understand how this can happen, and was hoping to find some answers here. Any ideas?

For context:
In our application, a web service tracks the latest user activity and updates the corresponding date field lastSync with each call. In this particular case, 3 calls to the service were issued in quick succession. While debugging locally I used fully blocking breakpoints, so no interference between the threads is possible.
2 Threads performed the update with the proper modified count, while the third one reported 0 even though the update was performed and persisted.

Hi @Christian_Schierle,

Can you create a minimal, reproducible example demonstrating the problem?

Regards,
Jeff

Hi @Jeffrey_Yemin ,

We had an issue with insufficient precision when passing the date object to the driver. This does not fully explain the error with an actual time difference described above. But it seems, there were 2 parallel threads that set the new value simultaneously despite the fully stopping breakpoints. I’ll try to verify that once more though.

I set up a database with a collection “testobject” holding only this document:

{
    "_id" : ObjectId("619fa87fa0e5600fb486442f"),
    "id" : "1",
    "lastSync" : ISODate("2021-11-25T15:41:56.000Z")
}

The error was reproducible with the following code using Java 16 and the mongodb driver version 4.3.4:

package main;

import com.mongodb.BasicDBObject;
import com.mongodb.client.MongoClient;
import com.mongodb.client.MongoClients;
import com.mongodb.client.model.UpdateOptions;
import org.bson.Document;

import java.time.LocalDateTime;
import java.time.ZoneId;
import java.util.Date;

public class Main {

    public static void main(String[] args) {
        MongoClient client = MongoClients.create();

        for (int i = 0; i < 3; i++) {
            int finalI = i;
            new Thread(() -> {
                BasicDBObject filterObject = new BasicDBObject("id", "1");
                Document updateObject = new Document();
                Date date = Date.from(LocalDateTime.now().withNano(0).atZone(ZoneId.systemDefault()).toInstant());
                updateObject.put("$set", new BasicDBObject("lastSync", date));
                UpdateOptions updateOptions = new UpdateOptions().upsert(false);

                System.out.println("thread " + finalI + ", update: " + updateObject.toJson());

                long updatedDocuments = client.getDatabase("local-mongo-test").getCollection("testobject").updateOne(filterObject, updateObject, updateOptions).getModifiedCount();
                if (updatedDocuments == 0) {
                    throw new IllegalStateException("update performed, but not reported");
                }
            }).start();
            try {
                Thread.sleep(500);
            } catch (InterruptedException e) {
                e.printStackTrace();
            }
        }
    }
}

Executing this produced the following output:

thread 0, update: {"$set": {"lastSync": {"$date": "2021-11-25T17:22:44Z"}}}
thread 1, update: {"$set": {"lastSync": {"$date": "2021-11-25T17:22:44Z"}}}
Exception in thread "Thread-1" java.lang.IllegalStateException: update performed, but not reported
	at main.Main.lambda$main$0(Main.java:32)
	at java.base/java.lang.Thread.run(Thread.java:831)
thread 2, update: {"$set": {"lastSync": {"$date": "2021-11-25T17:22:45Z"}}}

While building this example, I noticed that the initialized Date object did not contain milliseconds. We need to ignore the nanoseconds provided by LocalDateTime in other parts of the application, so we dropped them using .withNano(0). Meaning that updates performed within the same second would not require a change in the database.

When initializing the Date as follows, the database updates work as expected and no Exception is thrown in the example above:

Date date = new Date(LocalDateTime.now().atZone(ZoneId.systemDefault()).toInstant().toEpochMilli());

It was in fact an issue with insufficient thread safety in combination with automatic retries, if a request did not finish within a certain amount of time.

Sorry for stirring trouble :smiley: