-
Type: Bug
-
Resolution: Done
-
Priority: Major - P3
-
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)
- related to
-
SERVER-12164 Write commands are nesting operations, which breaks index build interruptibility
- Closed