Uploaded image for project: 'Core Server'
  1. Core Server
  2. SERVER-29989

BSON field 'OperationSessionInfo.$logicalTime' is a duplicate field

    • Type: Icon: Bug Bug
    • Resolution: Gone away
    • Priority: Icon: Major - P3 Major - P3
    • None
    • Affects Version/s: None
    • Component/s: Sharding
    • Fully Compatible
    • ALL
    • Sharding 2017-07-31, Sharding 2017-08-21

      While running patch with causal consistency set to true by default got this error

      [js_test:commands_namespace_parsing] 2017-07-05T18:09:09.180+0000 assert: [40413] != [73] are not equal : Expected failure code did not match actual in command result: {
      [js_test:commands_namespace_parsing] 2017-07-05T18:09:09.181+0000 	"ok" : 0,
      [js_test:commands_namespace_parsing] 2017-07-05T18:09:09.181+0000 	"errmsg" : "BSON field 'OperationSessionInfo.$logicalTime' is a duplicate field",
      [js_test:commands_namespace_parsing] 2017-07-05T18:09:09.181+0000 	"code" : 40413,
      [js_test:commands_namespace_parsing] 2017-07-05T18:09:09.181+0000 	"codeName" : "Location40413",
      [js_test:commands_namespace_parsing] 2017-07-05T18:09:09.181+0000 	"$logicalTime" : {
      [js_test:commands_namespace_parsing] 2017-07-05T18:09:09.182+0000 		"clusterTime" : Timestamp(1499278149, 2),
      [js_test:commands_namespace_parsing] 2017-07-05T18:09:09.182+0000 		"signature" : {
      [js_test:commands_namespace_parsing] 2017-07-05T18:09:09.182+0000 			"hash" : BinData(0,"ih/XXAirsRLy+ar0M3Ut9wDmC7c="),
      [js_test:commands_namespace_parsing] 2017-07-05T18:09:09.182+0000 			"keyId" : NumberLong("6439350411403984900")
      [js_test:commands_namespace_parsing] 2017-07-05T18:09:09.182+0000 		}
      [js_test:commands_namespace_parsing] 2017-07-05T18:09:09.183+0000 	},
      [js_test:commands_namespace_parsing] 2017-07-05T18:09:09.183+0000 	"operationTime" : Timestamp(1499278149, 2)
      [js_test:commands_namespace_parsing] 2017-07-05T18:09:09.183+0000 } : undefined
      

      Investigated, testing the fix.
      The code running the command on mongos propagates the response from mongod and adds cluster time without check: https://github.com/mongodb/mongo/blob/r3.5.9/src/mongo/s/commands/strategy.cpp#L133
      This also happens when mongod sends the request to a another shard: https://github.com/mongodb/mongo/blob/r3.5.9/src/mongo/db/service_entry_point_mongod.cpp#L267

      The proposed fix is to skip appending cluster time if its already there in https://github.com/mongodb/mongo/blob/r3.5.9/src/mongo/rpc/metadata/logical_time_metadata.cpp#L105. Will use the greatest of both cluster times

            Assignee:
            misha.tyulenev@mongodb.com Misha Tyulenev (Inactive)
            Reporter:
            misha.tyulenev@mongodb.com Misha Tyulenev (Inactive)
            Votes:
            0 Vote for this issue
            Watchers:
            4 Start watching this issue

              Created:
              Updated:
              Resolved: