RTS is restoring a corrupted update from history store to fix the unstable on-disk data store update. With the reproducer from HELP-21635, the following logs are generated while RTS is restoring an update from history store.
{"t":{"$date":"2021-01-25T01:26:58.802+00:00"},"s":"I", "c":"STORAGE", "id":22430, "ctx":"initandlisten","msg":"WiredTiger message","attr":{"message":"[1611538018:802616][1214556:0x7f777dffac80], file:collection-2-4821371008708493446.wt, txn rollback_to_stable: [WT_VERB_RTS] on-disk update aborted with start durable timestamp: (1611537962, 95), commit timestamp: (1611537962, 95), prepared: false and stable timestamp: (1611537961, 236)"}}
{"t":{"$date":"2021-01-25T01:26:58.804+00:00"},"s":"I", "c":"STORAGE", "id":22430, "ctx":"initandlisten","msg":"WiredTiger message","attr":{"message":"[1611538018:804220][1214556:0x7f777dffac80], file:collection-2-4821371008708493446.wt, txn rollback_to_stable: [WT_VERB_RTS] history store update aborted with start timestamp: (1611537963, 206), durable timestamp: (1611537963, 206), stop timestamp: (1611537963, 257), type: 1 and stable timestamp: (1611537961, 236)"}}
{"t":{"$date":"2021-01-25T01:26:58.804+00:00"},"s":"I", "c":"STORAGE", "id":22430, "ctx":"initandlisten","msg":"WiredTiger message","attr":{"message":"[1611538018:804322][1214556:0x7f777dffac80], file:collection-2-4821371008708493446.wt, txn rollback_to_stable: [WT_VERB_RTS] history store update aborted with start timestamp: (1611537963, 155), durable timestamp: (1611537963, 155), stop timestamp: (1611537963, 206), type: 1 and stable timestamp: (1611537961, 236)"}}
{"t":{"$date":"2021-01-25T01:26:58.804+00:00"},"s":"I", "c":"STORAGE", "id":22430, "ctx":"initandlisten","msg":"WiredTiger message","attr":{"message":"[1611538018:804397][1214556:0x7f777dffac80], file:collection-2-4821371008708493446.wt, txn rollback_to_stable: [WT_VERB_RTS] history store update aborted with start timestamp: (1611537963, 105), durable timestamp: (1611537963, 105), stop timestamp: (1611537963, 155), type: 1 and stable timestamp: (1611537961, 236)"}}
{"t":{"$date":"2021-01-25T01:26:58.804+00:00"},"s":"I", "c":"STORAGE", "id":22430, "ctx":"initandlisten","msg":"WiredTiger message","attr":{"message":"[1611538018:804485][1214556:0x7f777dffac80], file:collection-2-4821371008708493446.wt, txn rollback_to_stable: [WT_VERB_RTS] history store update aborted with start timestamp: (1611537963, 57), durable timestamp: (1611537963, 57), stop timestamp: (1611537963, 105), type: 1 and stable timestamp: (1611537961, 236)"}}
{"t":{"$date":"2021-01-25T01:26:58.804+00:00"},"s":"I", "c":"STORAGE", "id":22430, "ctx":"initandlisten","msg":"WiredTiger message","attr":{"message":"[1611538018:804562][1214556:0x7f777dffac80], file:collection-2-4821371008708493446.wt, txn rollback_to_stable: [WT_VERB_RTS] history store update aborted with start timestamp: (1611537963, 12), durable timestamp: (1611537963, 12), stop timestamp: (1611537963, 57), type: 1 and stable timestamp: (1611537961, 236)"}}
{"t":{"$date":"2021-01-25T01:26:58.804+00:00"},"s":"I", "c":"STORAGE", "id":22430, "ctx":"initandlisten","msg":"WiredTiger message","attr":{"message":"[1611538018:804632][1214556:0x7f777dffac80], file:collection-2-4821371008708493446.wt, txn rollback_to_stable: [WT_VERB_RTS] history store update aborted with start timestamp: (1611537962, 226), durable timestamp: (1611537962, 226), stop timestamp: (1611537963, 12), type: 1 and stable timestamp: (1611537961, 236)"}}
{"t":{"$date":"2021-01-25T01:26:58.804+00:00"},"s":"I", "c":"STORAGE", "id":22430, "ctx":"initandlisten","msg":"WiredTiger message","attr":{"message":"[1611538018:804701][1214556:0x7f777dffac80], file:collection-2-4821371008708493446.wt, txn rollback_to_stable: [WT_VERB_RTS] history store update aborted with start timestamp: (1611537962, 181), durable timestamp: (1611537962, 181), stop timestamp: (1611537962, 226), type: 1 and stable timestamp: (1611537961, 236)"}}
{"t":{"$date":"2021-01-25T01:26:58.804+00:00"},"s":"I", "c":"STORAGE", "id":22430, "ctx":"initandlisten","msg":"WiredTiger message","attr":{"message":"[1611538018:804793][1214556:0x7f777dffac80], file:collection-2-4821371008708493446.wt, txn rollback_to_stable: [WT_VERB_RTS] history store update aborted with start timestamp: (1611537962, 140), durable timestamp: (1611537962, 140), stop timestamp: (1611537962, 181), type: 1 and stable timestamp: (1611537961, 236)"}}
{"t":{"$date":"2021-01-25T01:26:58.804+00:00"},"s":"I", "c":"STORAGE", "id":22430, "ctx":"initandlisten","msg":"WiredTiger message","attr":{"message":"[1611538018:804862][1214556:0x7f777dffac80], file:collection-2-4821371008708493446.wt, txn rollback_to_stable: [WT_VERB_RTS] history store update aborted with start timestamp: (1611537962, 95), durable timestamp: (1611537962, 95), stop timestamp: (1611537962, 140), type: 1 and stable timestamp: (1611537961, 236)"}}
{"t":{"$date":"2021-01-25T01:26:58.804+00:00"},"s":"I", "c":"STORAGE", "id":22430, "ctx":"initandlisten","msg":"WiredTiger message","attr":{"message":"[1611538018:804931][1214556:0x7f777dffac80], file:collection-2-4821371008708493446.wt, txn rollback_to_stable: [WT_VERB_RTS] history store update aborted with start timestamp: (1611537962, 64), durable timestamp: (1611537962, 64), stop timestamp: (1611537962, 95), type: 1 and stable timestamp: (1611537961, 236)"}}
{"t":{"$date":"2021-01-25T01:26:58.805+00:00"},"s":"I", "c":"STORAGE", "id":22430, "ctx":"initandlisten","msg":"WiredTiger message","attr":{"message":"[1611538018:804999][1214556:0x7f777dffac80], file:collection-2-4821371008708493446.wt, txn rollback_to_stable: [WT_VERB_RTS] history store update aborted with start timestamp: (1611537962, 35), durable timestamp: (1611537962, 35), stop timestamp: (1611537962, 64), type: 1 and stable timestamp: (1611537961, 236)"}}
{"t":{"$date":"2021-01-25T01:26:58.805+00:00"},"s":"I", "c":"STORAGE", "id":22430, "ctx":"initandlisten","msg":"WiredTiger message","attr":{"message":"[1611538018:805067][1214556:0x7f777dffac80], file:collection-2-4821371008708493446.wt, txn rollback_to_stable: [WT_VERB_RTS] history store update valid with start timestamp: (1611537961, 219), durable timestamp: (1611537961, 219), stop timestamp: (1611537962, 35), type: 1 and stable timestamp: (1611537961, 236)"}}
{"t":{"$date":"2021-01-25T01:26:58.805+00:00"},"s":"I", "c":"STORAGE", "id":22430, "ctx":"initandlisten","msg":"WiredTiger message","attr":{"message":"[1611538018:805170][1214556:0x7f777dffac80], file:collection-2-4821371008708493446.wt, txn rollback_to_stable: [WT_VERB_RTS] update restored from history store (txnid: 0, start_ts: (1611537961, 219), durable_ts: (1611537961, 219)"}}
RTS forms a standard update from Modify updates of history store while replacing a data store update. During this process, it uses the existing data store update as a base update to apply all the modify operations from the history store. But in this situation, the modify updates in the history store are from later timestamp than the data store leads to a wrong full update to be restored.
It is possible that the history store can have updates greater than the data store when eviction occurs in parallel to the checkpoint.
- causes
-
WT-7159 Always write on-disk update as a full update to history store
-
- Closed
-
- related to
-
SERVER-54301 Add correctness tests of recovery using history store
-
- Closed
-