-
Type: Bug
-
Resolution: Fixed
-
Priority: Major - P3
-
Affects Version/s: None
-
Component/s: Storage
-
None
-
Fully Compatible
-
ALL
-
v4.4
-
Execution Team 2020-06-29
The following sequence was discovered. I believe this is a 4.4 specific regression.
[conn48] CMD: dropIndexes{"namespace":"test.drop_index","indexes":"[ \"c_1\", \"d_1\" ]"} [conn48] WT12. Beginning transaction [conn48] recording new metadata{"obj":{"md":{"ns":"test.drop_index","options":{"uuid":{"$uuid":"895bfb08-57a0-4501-a6e3-2fe905b02740"}},"indexes":[{"spec":{"v":2,"key":{"_id":1},"name":"_id_"},"ready":true,"multikey":false,"multikeyPaths":{"_id":{"$binary":{"base64":"AA==","subType":"0"}}},"head":0,"prefix":-1,"backgroundSecondary":false},{"spec":{"v":2,"key":{"d":1.0},"name":"d_1"},"ready":true,"multikey":false,"multikeyPaths":{"d":{"$binary":{"base64":"AA==","subType":"0"}}},"head":0,"prefix":-1,"backgroundSecondary":false},{"spec":{"v":2,"key":{"e":1.0},"name":"e_1"},"ready":true,"multikey":false,"multikeyPaths":{"e":{"$binary":{"base64":"AA==","subType":"0"}}},"head":0,"prefix":-1,"backgroundSecondary":false},{"spec":{"v":2,"key":{"a":1.0},"name":"a_1"},"ready":true,"multikey":false,"multikeyPaths":{"a":{"$binary":{"base64":"AA==","subType":"0"}}},"head":0,"prefix":-1,"backgroundSecondary":false}],"prefix":-1},"idxIdent":{"_id_":"index-34-1060380013860550997","d_1":"index-41-1060380013860550997","e_1":"index-43-1060380013860550997","a_1":"index-45-1060380013860550997"},"ns":"test.drop_index","ident":"collection-33-1060380013860550997"}} [conn48] WT set timestamp of future write operations to {"$timestamp":{"t":1591982501,"i":14}} [conn48] WT set timestamp of future write operations to {"$timestamp":{"t":1591982501,"i":14}} [conn48] recording new metadata{"obj":{"md":{"ns":"test.drop_index","options":{"uuid":{"$uuid":"895bfb08-57a0-4501-a6e3-2fe905b02740"}},"indexes":[{"spec":{"v":2,"key":{"_id":1},"name":"_id_"},"ready":true,"multikey":false,"multikeyPaths":{"_id":{"$binary":{"base64":"AA==","subType":"0"}}},"head":0,"prefix":-1,"backgroundSecondary":false},{"spec":{"v":2,"key":{"e":1.0},"name":"e_1"},"ready":true,"multikey":false,"multikeyPaths":{"e":{"$binary":{"base64":"AA==","subType":"0"}}},"head":0,"prefix":-1,"backgroundSecondary":false},{"spec":{"v":2,"key":{"a":1.0},"name":"a_1"},"ready":true,"multikey":false,"multikeyPaths":{"a":{"$binary":{"base64":"AA==","subType":"0"}}},"head":0,"prefix":-1,"backgroundSecondary":false}],"prefix":-1},"idxIdent":{"_id_":"index-34-1060380013860550997","e_1":"index-43-1060380013860550997","a_1":"index-45-1060380013860550997"},"ns":"test.drop_index","ident":"collection-33-1060380013860550997"}} [conn48] WT set timestamp of future write operations to {"$timestamp":{"t":1591982501,"i":15}} [conn48] WT set timestamp of future write operations to {"$timestamp":{"t":1591982501,"i":15}} [conn48] WT123. Last: Timestamp(1591982501, 15) Commit: Timestamp(0, 0)
I suspect this would break rollback and I'm surprised we haven't seen a failure like that come through. The rollback fuzzer has caught them before.
In this case, removing index "C" happens first and gets timestamp(..., 15), then removing index "D" happens second, but gets the earlier timestamp(..., 14).
The oplog entries:
{ "op" : "c", "ns" : "test.$cmd", "ui" : UUID("895bfb08-57a0-4501-a6e3-2fe905b02740"), "o" : { "dropIndexes" : "drop_index", "index" : "d_1" }, "o2" : { "v" : 2, "key" : { "d" : 1 }, "name" : "d_1" }, "ts" : Timestamp(1591982501, 15), "t" : NumberLong(1), "wall" : ISODate("2020-06-12T17:21:41.141Z"), "v" : NumberLong(2) } { "op" : "c", "ns" : "test.$cmd", "ui" : UUID("895bfb08-57a0-4501-a6e3-2fe905b02740"), "o" : { "dropIndexes" : "drop_index", "index" : "c_1" }, "o2" : { "v" : 2, "key" : { "c" : 1 }, "name" : "c_1" }, "ts" : Timestamp(1591982501, 14), "t" : NumberLong(1), "wall" : ISODate("2020-06-12T17:21:41.141Z"), "v" : NumberLong(2) }
Rolling back to 14 should give index C and not D, but given the update chain would result in neither C nor D existing.
- is related to
-
SERVER-34777 multi-index drops are given the wrong timestamps
- Closed
-
WT-6388 Fix-up out-of-order updates in the history store
- Closed
-
WT-6409 Fix failure due to assertion during rollback to stable
- Closed
- related to
-
SERVER-48771 Enforce constraints on "multi-timestamp" transactions
- Closed