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

Cannot run mongodump from 2.4 datafiles

    XMLWordPrintableJSON

Details

    • Icon: Bug Bug
    • Resolution: Done
    • Icon: Major - P3 Major - P3
    • 2.6.0-rc0
    • None
    • Tools
    • None
    • ALL
    • Hide

      Run a 2.4 mongod and shut down (after inserting data shown below):

      $ ./mongod-2.4
      ./mongod-2.4 --help for help and startup options
      Fri Jan 31 15:58:53.328 [initandlisten] MongoDB starting : pid=16173 port=27017 dbpath=/data/db/ 64-bit host=sv.local
      Fri Jan 31 15:58:53.328 [initandlisten] db version v2.4.8
      Fri Jan 31 15:58:53.328 [initandlisten] git version: a350fc38922fbda2cec8d5dd842237b904eafc14
      Fri Jan 31 15:58:53.328 [initandlisten] build info: Darwin bs-osx-106-x86-64-2.10gen.cc 10.8.0 Darwin Kernel Version 10.8.0: Tue Jun  7 16:32:41 PDT 2011; root:xnu-1504.15.3~1/RELEASE_X86_64 x86_64 BOOST_LIB_VERSION=1_49
      Fri Jan 31 15:58:53.328 [initandlisten] allocator: system
      Fri Jan 31 15:58:53.328 [initandlisten] options: {}
      Fri Jan 31 15:58:53.331 [initandlisten] journal dir=/data/db/journal
      Fri Jan 31 15:58:53.331 [initandlisten] recover : no journal files present, no recovery needed
      Fri Jan 31 15:58:53.355 [websvr] admin web console waiting for connections on port 28017
      Fri Jan 31 15:58:53.355 [initandlisten] waiting for connections on port 27017
      Fri Jan 31 15:58:56.672 [initandlisten] connection accepted from 127.0.0.1:61236 #1 (1 connection now open)
      Fri Jan 31 15:59:02.205 [FileAllocator] allocating new datafile /data/db/test.ns, filling with zeroes...
      Fri Jan 31 15:59:02.205 [FileAllocator] creating directory /data/db/_tmp
      Fri Jan 31 15:59:02.236 [FileAllocator] done allocating datafile /data/db/test.ns, size: 16MB,  took 0.031 secs
      Fri Jan 31 15:59:02.259 [FileAllocator] allocating new datafile /data/db/test.0, filling with zeroes...
      Fri Jan 31 15:59:02.420 [FileAllocator] done allocating datafile /data/db/test.0, size: 64MB,  took 0.16 secs
      Fri Jan 31 15:59:02.445 [FileAllocator] allocating new datafile /data/db/test.1, filling with zeroes...
      Fri Jan 31 15:59:02.447 [conn1] build index test.test { _id: 1 }
      Fri Jan 31 15:59:02.455 [conn1] build index done.  scanned 0 total records. 0.008 secs
      Fri Jan 31 15:59:02.455 [conn1] insert test.test ninserted:1 keyUpdates:0 locks(micros) w:251137 251ms
      Fri Jan 31 15:59:02.819 [FileAllocator] done allocating datafile /data/db/test.1, size: 128MB,  took 0.373 secs
      Fri Jan 31 15:59:03.858 [conn1] end connection 127.0.0.1:61236 (0 connections now open)
      ^CFri Jan 31 15:59:05.476 [signalProcessingThread] got signal 2 (Interrupt: 2), will terminate after current cmd ends
      Fri Jan 31 15:59:05.476 [signalProcessingThread] now exiting
      Fri Jan 31 15:59:05.476 dbexit:
      Fri Jan 31 15:59:05.476 [signalProcessingThread] shutdown: going to close listening sockets...
      Fri Jan 31 15:59:05.476 [signalProcessingThread] closing listening socket: 9
      Fri Jan 31 15:59:05.476 [signalProcessingThread] closing listening socket: 10
      Fri Jan 31 15:59:05.476 [signalProcessingThread] closing listening socket: 11
      Fri Jan 31 15:59:05.476 [signalProcessingThread] removing socket file: /tmp/mongodb-27017.sock
      Fri Jan 31 15:59:05.476 [signalProcessingThread] shutdown: going to flush diaglog...
      Fri Jan 31 15:59:05.476 [signalProcessingThread] shutdown: going to close sockets...
      Fri Jan 31 15:59:05.476 [signalProcessingThread] shutdown: waiting for fs preallocator...
      Fri Jan 31 15:59:05.476 [signalProcessingThread] shutdown: lock for final commit...
      Fri Jan 31 15:59:05.476 [signalProcessingThread] shutdown: final commit...
      Fri Jan 31 15:59:05.492 [signalProcessingThread] shutdown: closing all files...
      Fri Jan 31 15:59:05.492 [signalProcessingThread] closeAllFiles() finished
      Fri Jan 31 15:59:05.492 [signalProcessingThread] journalCleanup...
      Fri Jan 31 15:59:05.492 [signalProcessingThread] removeJournalFiles
      Fri Jan 31 15:59:05.493 [signalProcessingThread] shutdown: removing fs lock...
      Fri Jan 31 15:59:05.493 dbexit: really exiting now

      Insert data:

      $ ./mongo
      MongoDB shell version: 2.5.5-pre-
      connecting to: test
      > db.test.insert({x:1})
      > exit
      bye

      Dump using 2.5.5 mongodump:

      $ ./mongodump --dbpath /data/db
      2014-01-31T15:59:09.706-0500 all dbs
      2014-01-31T15:59:09.706-0500 [tools] _DEBUG ReadContext db wasn't open, will try to open local.system.namespaces
      2014-01-31T15:59:09.706-0500 [tools] opening db:  local
      2014-01-31T15:59:09.707-0500 [tools] _DEBUG ReadContext db wasn't open, will try to open test.system.namespaces
      2014-01-31T15:59:09.707-0500 [tools] opening db:  test
      2014-01-31T15:59:09.708-0500 DATABASE: test	 to 	dump/test
      2014-01-31T15:59:09.709-0500 	test.system.indexes to dump/test/system.indexes.bson
      2014-01-31T15:59:09.710-0500 		 1 objects
      2014-01-31T15:59:09.710-0500 	test.test to dump/test/test.bson
      2014-01-31T15:59:09.710-0500 [tools] lock status: r recursive:1 otherCount:-1 otherdb:test
      2014-01-31T15:59:09.710-0500 [tools] Assertion: 16105:expected to be write locked for test.$freelist
      2014-01-31T15:59:09.725-0500 [tools] 0x100d05975 0x100c639b4 0x100c3efd6 0x100c3f22a 0x10032d745 0x10093f97e 0x10093fae8 0x10093fb51 0x1001c696c 0x1001d3e4f 0x1001ee6eb 0x1001e47c0 0x1001e4e80 0x1001e4f6a 0x1001e648d 0x1001e91fa 0x1001bf879 0x1001c70f6 0x10056b884 0x1004e73fc
       0   mongodump                           0x0000000100d05975 _ZN5mongo15printStackTraceERSo + 37
       1   mongodump                           0x0000000100c639b4 _ZN5mongo10logContextEPKc + 228
       2   mongodump                           0x0000000100c3efd6 _ZN5mongo11msgassertedEiPKc + 390
       3   mongodump                           0x0000000100c3f22a _ZNK5mongo13ExceptionInfo6appendERNS_14BSONObjBuilderEPKcS4_ + 0
       4   mongodump                           0x000000010032d745 _ZN5mongo4Lock17assertWriteLockedERKNS_10StringDataE + 165
       5   mongodump                           0x000000010093f97e _ZN5mongo14NamespaceIndex6add_nsERKNS_9NamespaceEPKNS_16NamespaceDetailsE + 72
       6   mongodump                           0x000000010093fae8 _ZN5mongo14NamespaceIndex6add_nsERKNS_10StringDataEPKNS_16NamespaceDetailsE + 78
       7   mongodump                           0x000000010093fb51 _ZN5mongo14NamespaceIndex6add_nsERKNS_10StringDataERKNS_7DiskLocEb + 95
       8   mongodump                           0x00000001001c696c _ZN5mongo8Database19_initExtentFreeListEv + 238
       9   mongodump                           0x00000001001d3e4f _ZN5mongo8Database14_initForWritesEv + 99
       10  mongodump                           0x00000001001ee6eb _ZN5mongo8Database7getFileEiib + 35
       11  mongodump                           0x00000001001e47c0 _ZN5mongo12IndexCatalog21_shouldOverridePluginERKNS_7BSONObjE + 114
       12  mongodump                           0x00000001001e4e80 _ZN5mongo12IndexCatalog20_getAccessMethodNameERKNS_7BSONObjE + 46
       13  mongodump                           0x00000001001e4f6a _ZN5mongo12IndexCatalog19_createAccessMethodEPKNS_15IndexDescriptorEPNS_17IndexCatalogEntryE + 60
       14  mongodump                           0x00000001001e648d _ZN5mongo12IndexCatalog24_setupInMemoryStructuresEPNS_15IndexDescriptorE + 1231
       15  mongodump                           0x00000001001e91fa _ZN5mongo12IndexCatalog4initEv + 818
       16  mongodump                           0x00000001001bf879 _ZN5mongo10CollectionC1ERKNS_10StringDataEPNS_16NamespaceDetailsEPNS_8DatabaseE + 491
       17  mongodump                           0x00000001001c70f6 _ZN5mongo8Database13getCollectionERKNS_10StringDataE + 1212
       18  mongodump                           0x000000010056b884 _ZN5mongo8runCountERKSsRKNS_7BSONObjERSsRi + 196
       19  mongodump                           0x00000001004e73fc _ZN5mongo14DBDirectClient5countERKSsRKNS_7BSONObjEiii + 516
      assertion: 16105 expected to be write locked for test.$freelist
      2014-01-31T15:59:09.727-0500 [tools] thread tools stack usage was 32320 bytes,  which is the most so far
      dbexit: 2014-01-31T15:59:09.728-0500 [tools] shutdown: going to close listening sockets...
      2014-01-31T15:59:09.728-0500 [tools] shutdown: going to flush diaglog...
      2014-01-31T15:59:09.728-0500 [tools] shutdown: going to close sockets...
      2014-01-31T15:59:09.728-0500 [tools] shutdown: waiting for fs preallocator...
      2014-01-31T15:59:09.728-0500 [tools] shutdown: closing all files...
      2014-01-31T15:59:09.728-0500 [tools] is it really ok to close a mongommf outside a write lock? file:/data/db/test.0
      2014-01-31T15:59:09.728-0500 [tools] is it really ok to close a mongommf outside a write lock? file:/data/db/local.0
      2014-01-31T15:59:09.728-0500 [tools] is it really ok to close a mongommf outside a write lock? file:/data/db/test.ns
      2014-01-31T15:59:09.728-0500 [tools] is it really ok to close a mongommf outside a write lock? file:/data/db/local.ns
      2014-01-31T15:59:09.728-0500 [tools] closeAllFiles() finished
      2014-01-31T15:59:09.728-0500 [tools] shutdown: removing fs lock...
      dbexit: really exiting now

      Confirmation that the data has not been dumped:

      $ ls dump/
      test
      $ ls dump/test/
      system.indexes.bson test.bson
      $ bsondump dump/test/test.bson
      file dump/test/test.bson empty, skipping

      Show
      Run a 2.4 mongod and shut down (after inserting data shown below): $ ./mongod-2.4 ./mongod-2.4 --help for help and startup options Fri Jan 31 15:58:53.328 [initandlisten] MongoDB starting : pid=16173 port=27017 dbpath=/data/db/ 64-bit host=sv.local Fri Jan 31 15:58:53.328 [initandlisten] db version v2.4.8 Fri Jan 31 15:58:53.328 [initandlisten] git version: a350fc38922fbda2cec8d5dd842237b904eafc14 Fri Jan 31 15:58:53.328 [initandlisten] build info: Darwin bs-osx-106-x86-64-2.10gen.cc 10.8.0 Darwin Kernel Version 10.8.0: Tue Jun 7 16:32:41 PDT 2011; root:xnu-1504.15.3~1/RELEASE_X86_64 x86_64 BOOST_LIB_VERSION=1_49 Fri Jan 31 15:58:53.328 [initandlisten] allocator: system Fri Jan 31 15:58:53.328 [initandlisten] options: {} Fri Jan 31 15:58:53.331 [initandlisten] journal dir=/data/db/journal Fri Jan 31 15:58:53.331 [initandlisten] recover : no journal files present, no recovery needed Fri Jan 31 15:58:53.355 [websvr] admin web console waiting for connections on port 28017 Fri Jan 31 15:58:53.355 [initandlisten] waiting for connections on port 27017 Fri Jan 31 15:58:56.672 [initandlisten] connection accepted from 127.0.0.1:61236 #1 (1 connection now open) Fri Jan 31 15:59:02.205 [FileAllocator] allocating new datafile /data/db/test.ns, filling with zeroes... Fri Jan 31 15:59:02.205 [FileAllocator] creating directory /data/db/_tmp Fri Jan 31 15:59:02.236 [FileAllocator] done allocating datafile /data/db/test.ns, size: 16MB, took 0.031 secs Fri Jan 31 15:59:02.259 [FileAllocator] allocating new datafile /data/db/test.0, filling with zeroes... Fri Jan 31 15:59:02.420 [FileAllocator] done allocating datafile /data/db/test.0, size: 64MB, took 0.16 secs Fri Jan 31 15:59:02.445 [FileAllocator] allocating new datafile /data/db/test.1, filling with zeroes... Fri Jan 31 15:59:02.447 [conn1] build index test.test { _id: 1 } Fri Jan 31 15:59:02.455 [conn1] build index done. scanned 0 total records. 0.008 secs Fri Jan 31 15:59:02.455 [conn1] insert test.test ninserted:1 keyUpdates:0 locks(micros) w:251137 251ms Fri Jan 31 15:59:02.819 [FileAllocator] done allocating datafile /data/db/test.1, size: 128MB, took 0.373 secs Fri Jan 31 15:59:03.858 [conn1] end connection 127.0.0.1:61236 (0 connections now open) ^CFri Jan 31 15:59:05.476 [signalProcessingThread] got signal 2 (Interrupt: 2), will terminate after current cmd ends Fri Jan 31 15:59:05.476 [signalProcessingThread] now exiting Fri Jan 31 15:59:05.476 dbexit: Fri Jan 31 15:59:05.476 [signalProcessingThread] shutdown: going to close listening sockets... Fri Jan 31 15:59:05.476 [signalProcessingThread] closing listening socket: 9 Fri Jan 31 15:59:05.476 [signalProcessingThread] closing listening socket: 10 Fri Jan 31 15:59:05.476 [signalProcessingThread] closing listening socket: 11 Fri Jan 31 15:59:05.476 [signalProcessingThread] removing socket file: /tmp/mongodb-27017.sock Fri Jan 31 15:59:05.476 [signalProcessingThread] shutdown: going to flush diaglog... Fri Jan 31 15:59:05.476 [signalProcessingThread] shutdown: going to close sockets... Fri Jan 31 15:59:05.476 [signalProcessingThread] shutdown: waiting for fs preallocator... Fri Jan 31 15:59:05.476 [signalProcessingThread] shutdown: lock for final commit... Fri Jan 31 15:59:05.476 [signalProcessingThread] shutdown: final commit... Fri Jan 31 15:59:05.492 [signalProcessingThread] shutdown: closing all files... Fri Jan 31 15:59:05.492 [signalProcessingThread] closeAllFiles() finished Fri Jan 31 15:59:05.492 [signalProcessingThread] journalCleanup... Fri Jan 31 15:59:05.492 [signalProcessingThread] removeJournalFiles Fri Jan 31 15:59:05.493 [signalProcessingThread] shutdown: removing fs lock... Fri Jan 31 15:59:05.493 dbexit: really exiting now Insert data: $ ./mongo MongoDB shell version: 2.5.5-pre- connecting to: test > db.test.insert({x:1}) > exit bye Dump using 2.5.5 mongodump: $ ./mongodump --dbpath /data/db 2014-01-31T15:59:09.706-0500 all dbs 2014-01-31T15:59:09.706-0500 [tools] _DEBUG ReadContext db wasn't open, will try to open local.system.namespaces 2014-01-31T15:59:09.706-0500 [tools] opening db: local 2014-01-31T15:59:09.707-0500 [tools] _DEBUG ReadContext db wasn't open, will try to open test.system.namespaces 2014-01-31T15:59:09.707-0500 [tools] opening db: test 2014-01-31T15:59:09.708-0500 DATABASE: test to dump/test 2014-01-31T15:59:09.709-0500 test.system.indexes to dump/test/system.indexes.bson 2014-01-31T15:59:09.710-0500 1 objects 2014-01-31T15:59:09.710-0500 test.test to dump/test/test.bson 2014-01-31T15:59:09.710-0500 [tools] lock status: r recursive:1 otherCount:-1 otherdb:test 2014-01-31T15:59:09.710-0500 [tools] Assertion: 16105:expected to be write locked for test.$freelist 2014-01-31T15:59:09.725-0500 [tools] 0x100d05975 0x100c639b4 0x100c3efd6 0x100c3f22a 0x10032d745 0x10093f97e 0x10093fae8 0x10093fb51 0x1001c696c 0x1001d3e4f 0x1001ee6eb 0x1001e47c0 0x1001e4e80 0x1001e4f6a 0x1001e648d 0x1001e91fa 0x1001bf879 0x1001c70f6 0x10056b884 0x1004e73fc 0 mongodump 0x0000000100d05975 _ZN5mongo15printStackTraceERSo + 37 1 mongodump 0x0000000100c639b4 _ZN5mongo10logContextEPKc + 228 2 mongodump 0x0000000100c3efd6 _ZN5mongo11msgassertedEiPKc + 390 3 mongodump 0x0000000100c3f22a _ZNK5mongo13ExceptionInfo6appendERNS_14BSONObjBuilderEPKcS4_ + 0 4 mongodump 0x000000010032d745 _ZN5mongo4Lock17assertWriteLockedERKNS_10StringDataE + 165 5 mongodump 0x000000010093f97e _ZN5mongo14NamespaceIndex6add_nsERKNS_9NamespaceEPKNS_16NamespaceDetailsE + 72 6 mongodump 0x000000010093fae8 _ZN5mongo14NamespaceIndex6add_nsERKNS_10StringDataEPKNS_16NamespaceDetailsE + 78 7 mongodump 0x000000010093fb51 _ZN5mongo14NamespaceIndex6add_nsERKNS_10StringDataERKNS_7DiskLocEb + 95 8 mongodump 0x00000001001c696c _ZN5mongo8Database19_initExtentFreeListEv + 238 9 mongodump 0x00000001001d3e4f _ZN5mongo8Database14_initForWritesEv + 99 10 mongodump 0x00000001001ee6eb _ZN5mongo8Database7getFileEiib + 35 11 mongodump 0x00000001001e47c0 _ZN5mongo12IndexCatalog21_shouldOverridePluginERKNS_7BSONObjE + 114 12 mongodump 0x00000001001e4e80 _ZN5mongo12IndexCatalog20_getAccessMethodNameERKNS_7BSONObjE + 46 13 mongodump 0x00000001001e4f6a _ZN5mongo12IndexCatalog19_createAccessMethodEPKNS_15IndexDescriptorEPNS_17IndexCatalogEntryE + 60 14 mongodump 0x00000001001e648d _ZN5mongo12IndexCatalog24_setupInMemoryStructuresEPNS_15IndexDescriptorE + 1231 15 mongodump 0x00000001001e91fa _ZN5mongo12IndexCatalog4initEv + 818 16 mongodump 0x00000001001bf879 _ZN5mongo10CollectionC1ERKNS_10StringDataEPNS_16NamespaceDetailsEPNS_8DatabaseE + 491 17 mongodump 0x00000001001c70f6 _ZN5mongo8Database13getCollectionERKNS_10StringDataE + 1212 18 mongodump 0x000000010056b884 _ZN5mongo8runCountERKSsRKNS_7BSONObjERSsRi + 196 19 mongodump 0x00000001004e73fc _ZN5mongo14DBDirectClient5countERKSsRKNS_7BSONObjEiii + 516 assertion: 16105 expected to be write locked for test.$freelist 2014-01-31T15:59:09.727-0500 [tools] thread tools stack usage was 32320 bytes, which is the most so far dbexit: 2014-01-31T15:59:09.728-0500 [tools] shutdown: going to close listening sockets... 2014-01-31T15:59:09.728-0500 [tools] shutdown: going to flush diaglog... 2014-01-31T15:59:09.728-0500 [tools] shutdown: going to close sockets... 2014-01-31T15:59:09.728-0500 [tools] shutdown: waiting for fs preallocator... 2014-01-31T15:59:09.728-0500 [tools] shutdown: closing all files... 2014-01-31T15:59:09.728-0500 [tools] is it really ok to close a mongommf outside a write lock? file:/data/db/test.0 2014-01-31T15:59:09.728-0500 [tools] is it really ok to close a mongommf outside a write lock? file:/data/db/local.0 2014-01-31T15:59:09.728-0500 [tools] is it really ok to close a mongommf outside a write lock? file:/data/db/test.ns 2014-01-31T15:59:09.728-0500 [tools] is it really ok to close a mongommf outside a write lock? file:/data/db/local.ns 2014-01-31T15:59:09.728-0500 [tools] closeAllFiles() finished 2014-01-31T15:59:09.728-0500 [tools] shutdown: removing fs lock... dbexit: really exiting now Confirmation that the data has not been dumped: $ ls dump/ test $ ls dump/test/ system.indexes.bson test.bson $ bsondump dump/test/test.bson file dump/test/test.bson empty, skipping

    Description

      Cannot run a direct mongodump against the data files of a 2.4 database. See steps to reproduce.

      Attachments

        Activity

          People

            eliot Eliot Horowitz (Inactive)
            sverch Shaun Verch
            Votes:
            0 Vote for this issue
            Watchers:
            8 Start watching this issue

            Dates

              Created:
              Updated:
              Resolved: