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

creating background index and then dropping doesn't seem to cancel background build on secondary

    • Type: Icon: Bug Bug
    • Resolution: Done
    • Priority: Icon: Major - P3 Major - P3
    • 2.5.5
    • Affects Version/s: None
    • Component/s: Index Maintenance
    • ALL

      started up a 2.4 replica set, and added a 2.5.3 secondary

      • create an index with {background:true}

        on a large collection, on the primary

      • immediately call dropIndexes()

      From my understanding of how background indexing should now work in 2.5.x the background index build should be aborted when the dropIndexes command is sent. However it looks like the secondary is continuing to build the index to completion before dropping it.

      >  m31001| Mon Nov 18 16:34:16.929 [repl writer worker 1] CMD: dropIndexes poo.test
       m27000| 2013-11-18T16:34:16.929-0500 [repl writer worker 1] CMD: dropIndexes poo.test
       m27000| 2013-11-18T16:34:17.008-0500 [conn35] end connection 127.0.0.1:63104 (2 connections now open)
       m27000| 2013-11-18T16:34:17.009-0500 [initandlisten] connection accepted from 127.0.0.1:63127 #37 (3 connections now open)
      
      >
      >
      >  m31000| Mon Nov 18 16:34:18.231 [conn49] end connection 127.0.0.1:63105 (6 connections now open)
       m31000| Mon Nov 18 16:34:18.231 [initandlisten] connection accepted from 127.0.0.1:63128 #51 (7 connections now open)
      
      >
      > rs1.getPrimary().getDB("poo").test.createIndex({x:1}, {background:true})
      rs1.getPrimary().getDB("poo").test.dropIndexes()
      ReplSetTest Could not call ismaster on node 2: {
      
      }
       m31000| Mon Nov 18 16:34:21.857 [conn1] build index poo.test { x: 1.0 } background
      > rs1.getPrimary().getDB("poo").test.dropIndexes()
       m31000| Mon Nov 18 16:34:24.000 [conn1]                Background Index Build Progress: 390700/1000000 39%
      
      
       m31000| Mon Nov 18 16:34:26.213 [journal] old journal file will be removed: /data/db/test-0/journal/j._0
       m31000| Mon Nov 18 16:34:26.214 [journal] old journal file will be removed: /data/db/test-0/journal/j._1
       m31000| Mon Nov 18 16:34:27.000 [conn1]                Background Index Build Progress: 884300/1000000 88%
       m31000| Mon Nov 18 16:34:27.658 [conn1] build index done.  scanned 1000000 total records. 5.801 secs
       m31000| Mon Nov 18 16:34:27.658 [conn1] insert poo.system.indexes ninserted:1 keyUpdates:0 numYields: 67 locks(micros) w:10542174 5801ms
       m31001| Mon Nov 18 16:34:27.659 [repl writer worker 1] info: indexing in foreground on this replica; was a background index build on the primary
       m31001| Mon Nov 18 16:34:27.659 [repl writer worker 1] build index poo.test { x: 1.0 }
       m27000| 2013-11-18T16:34:27.659-0500 [repl index builder 3] build index on: poo.test properties: { "v" : 1, "key" : { "x" : 1 }, "ns" : "poo.test", "name" : "x_1", "background" : true }
      ReplSetTest Could not call ismaster on node 2: {
      
      }
       m31000| Mon Nov 18 16:34:27.660 [conn1] CMD: dropIndexes poo.test
      {
        "nIndexesWas": 2,
        "msg": "non-_id indexes dropped for collection",
        "ok": 1
      }
      >
      
      >
      >  m27000| 2013-11-18T16:34:30.000-0500 [repl index builder 3]          Background Index Build Progress: 257800/1000000 25%
       m31001| Mon Nov 18 16:34:31.830 [conn39] end connection 127.0.0.1:63116 (2 connections now open)
       m31001| Mon Nov 18 16:34:31.830 [initandlisten] connection accepted from 127.0.0.1:63142 #41 (3 connections now open)
       m31001| Mon Nov 18 16:34:31.960 [repl writer worker 1] build index done.  scanned 1000000 total records. 4.3 secs
       m31001| Mon Nov 18 16:34:32.136 [repl writer worker 1] CMD: dropIndexes poo.test
       m31001| Mon Nov 18 16:34:32.239 [conn40] end connection 127.0.0.1:63117 (2 connections now open)
       m31001| Mon Nov 18 16:34:32.240 [initandlisten] connection accepted from 127.0.0.1:63143 #42 (3 connections now open)
       m27000| 2013-11-18T16:34:33.000-0500 [repl index builder 3]            Background Index Build Progress: 584400/1000000 58%
       m27000| 2013-11-18T16:34:36.000-0500 [repl index builder 3]            Background Index Build Progress: 911300/1000000 91%
       m27000| 2013-11-18T16:34:36.824-0500 [repl index builder 3] build index done.  scanned 1000000 total records. 9.164 secs
       m27000| 2013-11-18T16:34:36.825-0500 [repl writer worker 1] CMD: dropIndexes poo.test
       m31000| Mon Nov 18 16:34:42.382 [conn50] end connection 127.0.0.1:63125 (6 connections now open)
       m31000| Mon Nov 18 16:34:42.383 [initandlisten] connection accepted from 127.0.0.1:63150 #52 (7 connections now open)
       m27000| 2013-11-18T16:34:45.518-0500 [conn36] end connection 127.0.0.1:63126 (2 connections now open)
       m27000| 2013-11-18T16:34:45.520-0500 [initandlisten] connection accepted from 127.0.0.1:63153 #38 (3 connections now open)
       m27000| 2013-11-18T16:34:47.028-0500 [conn37] end connection 127.0.0.1:63127 (2 connections now open)
       m27000| 2013-11-18T16:34:47.029-0500 [initandlisten] connection accepted from 127.0.0.1:63154 #39 (3 connections now open)
      

            Assignee:
            milkie@mongodb.com Eric Milkie
            Reporter:
            mikeo@mongodb.com Michael O'Brien
            Votes:
            0 Vote for this issue
            Watchers:
            3 Start watching this issue

              Created:
              Updated:
              Resolved: