Uploaded image for project: 'WiredTiger'
  1. WiredTiger
  2. WT-7675

Value of `query_timestamp(get=last_checkpoint)` changing (seemingly) without a taking a checkpoint

    XMLWordPrintable

    Details

    • Type: Bug
    • Status: In Progress
    • Priority: Major - P3
    • Resolution: Unresolved
    • Affects Version/s: 4.2.14
    • Fix Version/s: 5.1 Required
    • Component/s: Backup, Checkpoints
    • Labels:
      None
    • Story Points:
      5
    • Sprint:
      Storage - Ra 2021-06-28

      Description

      MDB backups of WT want to know the "checkpoint timestamp" of the data pinned by a backup cursor. IIRC Susan LoVerso offered providing a query_timestamp API for doing so, to which I responded "we're good".

      Instead MDB does optimistic concurrency control between opening backup cursors and taking checkpoints. We don't serialize the operations, but rather do the simple check + recheck:

      1. query_timestamp(get=last_checkpoint)
      2. open backup cursor
      3. query_timestamp(get=last_checkpoint)

      If the values are the same, we know the timestamp of the data being copied by the backup. If we are not taking a checkpoint during any of these calls to query_timestamp, we believe the returned timestamp should always match.

      We're observing cases where this assumption is not holding. We're seeing consecutive calls to query_timestamp returning different values, but no checkpoint was taken that would explain why. Unfortunately we don't have perfect logging of the values returned by "query_timestamp".

      As an example:

      D2 RECOVERY [WTCheckpointThread] Performing stable checkpoint. StableTimestamp: Timestamp(1623229619, 2), OplogNeededForRollback: Timestamp(1623229619, 2)
      D1 STORAGE  [WTCheckpointThread] Checkpoint took 57 seconds to complete.
      I  STORAGE  [conn29862] Opened backup cursor. ID: <snip> Term: 547
      I  STORAGE  [conn29862] Closed backup cursor. ID: <snip>
      <long log line saying an error was returned due to the timestamps not matching>
      D2 RECOVERY [WTCheckpointThread] Performing stable checkpoint. StableTimestamp: Timestamp(1623229735, 2), OplogNeededForRollback: Timestamp(1623229735, 2)
      

      Susan LoVerso noted that the conn->txn_global.last_ckpt_timestamp value is written to without a mutex which could explain this observation.

        Attachments

          Activity

            People

            Assignee:
            ravi.giri Ravi Giri
            Reporter:
            daniel.gottlieb Daniel Gottlieb
            Votes:
            0 Vote for this issue
            Watchers:
            7 Start watching this issue

              Dates

              Created:
              Updated: