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

The repl two-phase collection drop reaper can log the same drop several times with different notification optimes

    • Type: Icon: Task Task
    • Resolution: Won't Do
    • Priority: Icon: Major - P3 Major - P3
    • None
    • Affects Version/s: None
    • Component/s: Storage
    • Labels:
      None
    • Storage Execution

      [ReplicaSetFixture:job9:secondary] 2019-01-16T20:03:29.431+0000 I REPL     [replication-4] Completing collection drop for test.system.drop.1547668969i105t1.index_bigkeys_background_test with drop optime { ts: Timestamp(1547668969, 105), t: 1 } (notification optime: { ts: Timestamp(1547669004, 2), t: 2 })
      [ReplicaSetFixture:job9:secondary] 2019-01-16T20:03:29.431+0000 I REPL     [replication-7] Completing collection drop for test.system.drop.1547668969i105t1.index_bigkeys_background_test with drop optime { ts: Timestamp(1547668969, 105), t: 1 } (notification optime: { ts: Timestamp(1547669005, 1), t: 2 })
      [ReplicaSetFixture:job9:secondary] 2019-01-16T20:03:29.431+0000 I REPL     [replication-3] Completing collection drop for test.system.drop.1547668969i105t1.index_bigkeys_background_test with drop optime { ts: Timestamp(1547668969, 105), t: 1 } (notification optime: { ts: Timestamp(1547669004, 2), t: 2 })
      [ReplicaSetFixture:job9:secondary] 2019-01-16T20:03:29.431+0000 I REPL     [replication-5] Completing collection drop for test.system.drop.1547668969i105t1.index_bigkeys_background_test with drop optime { ts: Timestamp(1547668969, 105), t: 1 } (notification optime: { ts: Timestamp(1547669005, 2), t: 2 })
      [ReplicaSetFixture:job9:secondary] 2019-01-16T20:03:29.431+0000 I REPL     [replication-0] Completing collection drop for test.system.drop.1547668969i105t1.index_bigkeys_background_test with drop optime { ts: Timestamp(1547668969, 105), t: 1 } (notification optime: { ts: Timestamp(1547669004, 1), t: 2 })
      [ReplicaSetFixture:job9:secondary] 2019-01-16T20:03:29.431+0000 I REPL     [replication-2] Completing collection drop for test.system.drop.1547668969i105t1.index_bigkeys_background_test with drop optime { ts: Timestamp(1547668969, 105), t: 1 } (notification optime: { ts: Timestamp(1547669004, 1), t: 2 })
      [ReplicaSetFixture:job9:secondary] 2019-01-16T20:03:29.431+0000 I REPL     [replication-1] Completing collection drop for test.system.drop.1547668969i105t1.index_bigkeys_background_test with drop optime { ts: Timestamp(1547668969, 105), t: 1 } (notification optime: { ts: Timestamp(1547669004, 2), t: 2 })
      [ReplicaSetFixture:job9:secondary] 2019-01-16T20:03:29.434+0000 I REPL     [replication-6] Completing collection drop for test.system.drop.1547668969i105t1.index_bigkeys_background_test with drop optime { ts: Timestamp(1547668969, 105), t: 1 } (notification optime: { ts: Timestamp(1547669005, 1), t: 2 })
      

      Replication has many threads that run the code that notifies the drop-pending-reaper of work and executes that work synchronously. And the drop-pending-reaper does not prevent multiple callers from running drop collection for the same collection: it is a race between whether the first caller finishes the drop collection and deletes entries from the reaper's map before the next caller redundantly accesses the map to find drops to execute.

            Assignee:
            backlog-server-execution [DO NOT USE] Backlog - Storage Execution Team
            Reporter:
            dianna.hohensee@mongodb.com Dianna Hohensee (Inactive)
            Votes:
            0 Vote for this issue
            Watchers:
            6 Start watching this issue

              Created:
              Updated:
              Resolved: