[SERVER-53226] Use the $currentDate operator to update the current timestamp Created: 04/Dec/20  Updated: 12/Jan/21  Resolved: 12/Jan/21

Status: Closed
Project: Core Server
Component/s: WiredTiger
Affects Version/s: None
Fix Version/s: None

Type: Question Priority: Major - P3
Reporter: pan chen Assignee: Edwin Zhou
Resolution: Done Votes: 0
Labels: None
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified

Attachments: Zip Archive journal.zip     Zip Archive metrics.zip    
Participants:

 Description   

The authLog structure is as follows :

{ "_id": NumberInt("0"), "la": ISODate("2020-12-04T01:25:54.054Z"), }

,

Then I use the following script operation:

for(var i = 0;i<2000;i++)

{ db.authLog.updateOne(\{"_id":i}

, {$currentDate: {"la":true}});
}

Then I discovered that it is possible that the update timestamp with a larger id is smaller than the update timestamp with a smaller id.E.g :

{ "_id": NumberInt("100"), "la": ISODate("2020-12-04T01:25:54.054Z"), }

,

{ "_id": NumberInt("201"), "la": ISODate("2020-12-04T01:25:54.052Z"), }

.

Why does this happen and how to solve it?



 Comments   
Comment by Edwin Zhou [ 12/Jan/21 ]

Hi hellotudou@outlook.com

We haven’t heard back from you for some time, so I’m going to close this ticket. If this is still an issue for you, please provide additional information and we will reopen the ticket.

Best,
Edwin

Comment by Edwin Zhou [ 05/Jan/21 ]

Hi hellotudou@outlook.com,

We still need additional information to diagnose the problem. If this is still an issue for you, would you please attach an archive of the mongod.log files recorded during the occurrence of the issue? Could you also inform us if you were able to successfully use bulk operations to satisfy your requirements, or clarify what you mean by business operations?

It will also be helpful for you to attach a code snipped that you used to update the documents, as well as your deployment topology.

Thanks,
Edwin

Comment by Edwin Zhou [ 21/Dec/20 ]

Hi hellotudou@outlook.com,

Would you please also archive (tar or zip) the mongod.log files recorded during this occurrence and attach it to this ticket? It would also be really helpful to reproduce the issue once more but with a higher log verbosity db.setLogLevel(1, "command") and attach the logs to this ticket.

Were you able to find success with bulk operations? You mentioned that your update operations may be an update of multiple business operations, which suggests to me that bulk operations wouldn't work. Could you clarify what you mean by business operations?

Are you running these operations on a single node, a replica set, or a sharded cluster? Could you also provide a java code snippet that you use to update the documents?

Best,
Edwin

Comment by pan chen [ 19/Dec/20 ]

hi edwin.zhou,

I opened a new mongo using docker to do this operation, and I uploaded both journal logs and metrics.

I am using the java client to do the mongo operation.

Note that the data with id 1847 and 1848, the timestamp is reversed, updated after 1848, but the timestamp is before the time after 1847

journal.zipmetrics.zip

Comment by Edwin Zhou [ 18/Dec/20 ]

Hi hellotudou@outlook.com,

I'm unable to reproduce the behavior you're observing. I've made repeated attempts to hit an out of order operation that is executed within a for loop.

Would you please archive (tar or zip) the $dbpath/diagnostic.data directory (the contents are described here) and attach it to this ticket?

Kind regards,
Edwin

Comment by pan chen [ 14/Dec/20 ]

oh ,thank you .Using bulk operation should solve the problem I said.However, the update operation may be an update of multiple business operations.Can this situation be resolved?

Comment by pan chen [ 10/Dec/20 ]

Oh, thank you. The version of mongoserver I am using is 

MongoDB server version: 4.2.8,

The issue of appeal, I have repeatedly implemented it, but it only happens occasionally.

Comment by Edwin Zhou [ 09/Dec/20 ]

Hi hellotudou@outlook.com,

Thanks for your question and detailed description. Unfortunately, I wasn't able to reproduce the behavior you observed. Could you provide which version of MongoDB you're using?

You can also try the bulk operations builder and initializeOrderedBulkOp() to guarantee the order in which operations are executed.

db = db.getSiblingDB("test");coll = db.getCollection("authLog");
bulk = coll.initializeOrderedBulkOp();
for (var i = 0; i < 2000; i++) {
  bulk.find({ _id: i }).updateOne({ $currentDate: { la: true } });
}
bulk.execute();
 
printjson(coll.findOne({ _id: 100 }));
printjson(coll.findOne({ _id: 201 }));

will output

{ "_id" : 100, "la" : ISODate("2020-12-09T20:52:27.121Z") }
{ "_id" : 201, "la" : ISODate("2020-12-09T20:52:27.124Z") }

Does this help?

Best,
Edwin

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