[SERVER-20929] Restore error: false invalid document size Created: 14/Oct/15  Updated: 16/Oct/15  Resolved: 16/Oct/15

Status: Closed
Project: Core Server
Component/s: Admin
Affects Version/s: 3.0.7
Fix Version/s: None

Type: Bug Priority: Major - P3
Reporter: Michael Werle Assignee: Unassigned
Resolution: Duplicate Votes: 1
Labels: None
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified
Environment:

OS X 10.11.0
MongoDB installed via Homebrew (tested both bottled and built from source)


Issue Links:
Duplicate
duplicates TOOLS-939 Error restoring database "insertion e... Closed
Operating System: OS X
Steps To Reproduce:
  1. Backup a collection using 3.0.7.
  2. Attempt to restore the collection to a new database.

I have only tested a few collections, from a single DB, but all have failed. I have tested backups from a 3.0.6 instance and backups from a 3.0.7 instance that was upgraded from 3.0.6.

Participants:

 Description   

I cannot restore collections to 3.0.7 from mongodump files that restore fine to 3.0.6. The server log indicates that it thinks objects with invalid (too large) BSON sizes are being restored.

mongorestore log:

$ mongorestore -vvvvv -d test3 --drop dump/development/interviews.bson
2015-10-14T17:13:38.455-0500	checking options
2015-10-14T17:13:38.455-0500		dumping with object check disabled
2015-10-14T17:13:38.459-0500	connected to node type: standalone
2015-10-14T17:13:38.459-0500	standalone server: setting write concern w to 1
2015-10-14T17:13:38.459-0500	using write concern: w='1', j=false, fsync=false, wtimeout=0
2015-10-14T17:13:38.459-0500	mongorestore target is a file, not a directory
2015-10-14T17:13:38.459-0500	inferred collection 'interviews' from file
2015-10-14T17:13:38.459-0500	setting number of insertions workers to number of parallel collections (4)
2015-10-14T17:13:38.459-0500	checking for collection data in dump/development/interviews.bson
2015-10-14T17:13:38.459-0500	reading collection interviews for database test3 from dump/development/interviews.bson
2015-10-14T17:13:38.459-0500	scanning directory dump/development for metadata file
2015-10-14T17:13:38.459-0500	found metadata for collection at dump/development/interviews.metadata.json
2015-10-14T17:13:38.459-0500	finalizing intent manager with multi-database longest task first prioritizer
2015-10-14T17:13:38.459-0500	restoring up to 4 collections in parallel
2015-10-14T17:13:38.459-0500	starting restore routine with id=3
2015-10-14T17:13:38.459-0500	starting restore routine with id=0
2015-10-14T17:13:38.459-0500	ending restore routine with id=0, no more work to do
2015-10-14T17:13:38.459-0500	starting restore routine with id=1
2015-10-14T17:13:38.459-0500	starting restore routine with id=2
2015-10-14T17:13:38.459-0500	ending restore routine with id=2, no more work to do
2015-10-14T17:13:38.459-0500	ending restore routine with id=1, no more work to do
2015-10-14T17:13:38.460-0500	dropping collection test3.interviews before restoring
2015-10-14T17:13:38.460-0500	reading metadata file from dump/development/interviews.metadata.json
2015-10-14T17:13:38.461-0500	creating collection test3.interviews using options from metadata
2015-10-14T17:13:38.461-0500	restoring test3.interviews from file dump/development/interviews.bson
2015-10-14T17:13:38.461-0500		file dump/development/interviews.bson is 1285186099 bytes
2015-10-14T17:13:38.462-0500	using 4 insertion workers
2015-10-14T17:13:38.805-0500	Failed: restore error: test3.interviews: error restoring from dump/development/interviews.bson: insertion error: EOF

Server log:

2015-10-14T17:13:38.458-0500 I NETWORK  [initandlisten] connection accepted from 127.0.0.1:59878 #15 (1 connection now open)
2015-10-14T17:13:38.458-0500 D COMMAND  [conn15] run command admin.$cmd { getnonce: 1 }
2015-10-14T17:13:38.458-0500 I COMMAND  [conn15] command admin.$cmd command: getnonce { getnonce: 1 } keyUpdates:0 writeConflicts:0 numYields:0 reslen:65 locks:{} 0ms
2015-10-14T17:13:38.458-0500 D COMMAND  [conn15] run command admin.$cmd { ping: 1 }
2015-10-14T17:13:38.458-0500 I COMMAND  [conn15] command admin.$cmd command: ping { ping: 1 } keyUpdates:0 writeConflicts:0 numYields:0 reslen:37 locks:{} 0ms
2015-10-14T17:13:38.458-0500 D COMMAND  [conn15] run command admin.$cmd { ismaster: 1 }
2015-10-14T17:13:38.458-0500 I COMMAND  [conn15] command admin.$cmd command: isMaster { ismaster: 1 } keyUpdates:0 writeConflicts:0 numYields:0 reslen:178 locks:{} 0ms
2015-10-14T17:13:38.459-0500 D COMMAND  [conn15] run command admin.$cmd { ping: 1 }
2015-10-14T17:13:38.459-0500 I COMMAND  [conn15] command admin.$cmd command: ping { ping: 1 } keyUpdates:0 writeConflicts:0 numYields:0 reslen:37 locks:{} 0ms
2015-10-14T17:13:38.459-0500 D COMMAND  [conn15] run command admin.$cmd { isMaster: 1 }
2015-10-14T17:13:38.459-0500 I COMMAND  [conn15] command admin.$cmd command: isMaster { isMaster: 1 } keyUpdates:0 writeConflicts:0 numYields:0 reslen:178 locks:{} 0ms
2015-10-14T17:13:38.459-0500 D COMMAND  [conn15] run command admin.$cmd { isMaster: 1 }
2015-10-14T17:13:38.459-0500 I COMMAND  [conn15] command admin.$cmd command: isMaster { isMaster: 1 } keyUpdates:0 writeConflicts:0 numYields:0 reslen:178 locks:{} 0ms
2015-10-14T17:13:38.459-0500 D COMMAND  [conn15] run command test3.$cmd { listCollections: 1, cursor: { batchSize: 0 } }
2015-10-14T17:13:38.460-0500 I COMMAND  [conn15] command test3.$cmd command: listCollections { listCollections: 1, cursor: { batchSize: 0 } } keyUpdates:0 writeConflicts:0 numYields:0 reslen:114 locks:{ Global: { acquireCount: { r: 2 } }, MMAPV1Journal: { acquireCount: { r: 1 } }, Database: { acquireCount: { R: 1 } } } 0ms
2015-10-14T17:13:38.460-0500 I QUERY    [conn15] getmore test3.$cmd.listCollections cursorid:7546192025 ntoreturn:0 keyUpdates:0 writeConflicts:0 numYields:0 nreturned:2 reslen:115 locks:{} 0ms
2015-10-14T17:13:38.460-0500 D COMMAND  [conn15] run command test3.$cmd { drop: "interviews" }
2015-10-14T17:13:38.460-0500 I COMMAND  [conn15] CMD: drop test3.interviews
2015-10-14T17:13:38.460-0500 D STORAGE  [conn15] dropCollection: test3.interviews
2015-10-14T17:13:38.460-0500 D INDEX    [conn15]         dropAllIndexes dropping: { v: 1, key: { _id: 1 }, name: "_id_", ns: "test3.interviews" }
2015-10-14T17:13:38.460-0500 D STORAGE  [conn15] test3.interviews: clearing plan cache - collection info cache reset
2015-10-14T17:13:38.460-0500 D STORAGE  [conn15]         dropIndexes done
2015-10-14T17:13:38.460-0500 D STORAGE  [conn15]    ***** ROLLING BACK 0 disk writes
2015-10-14T17:13:38.460-0500 D STORAGE  [conn15]    ***** ROLLING BACK 0 custom changes
2015-10-14T17:13:38.460-0500 I COMMAND  [conn15] command test3.$cmd command: drop { drop: "interviews" } keyUpdates:0 writeConflicts:0 numYields:0 reslen:79 locks:{ Global: { acquireCount: { r: 1, w: 1 } }, MMAPV1Journal: { acquireCount: { w: 2 } }, Database: { acquireCount: { W: 1 } }, Metadata: { acquireCount: { W: 2 } } } 0ms
2015-10-14T17:13:38.461-0500 D COMMAND  [conn15] run command test3.$cmd { create: "interviews", flags: 1 }
2015-10-14T17:13:38.461-0500 D STORAGE  [conn15] create collection test3.interviews { flags: 1 }
2015-10-14T17:13:38.461-0500 D STORAGE  [conn15] MmapV1ExtentManager::allocateExtent desiredSize:8192 fromFreeList: 1 eloc: 0:5000
2015-10-14T17:13:38.461-0500 D STORAGE  [conn15] test3.interviews: clearing plan cache - collection info cache reset
2015-10-14T17:13:38.461-0500 D STORAGE  [conn15] allocating new extent
2015-10-14T17:13:38.461-0500 D STORAGE  [conn15] MmapV1ExtentManager::allocateExtent desiredSize:131072 fromFreeList: 1 eloc: 0:9000
2015-10-14T17:13:38.461-0500 D STORAGE  [conn15] test3.interviews: clearing plan cache - collection info cache reset
2015-10-14T17:13:38.461-0500 D STORAGE  [conn15]    ***** ROLLING BACK 0 disk writes
2015-10-14T17:13:38.461-0500 D STORAGE  [conn15]    ***** ROLLING BACK 0 custom changes
2015-10-14T17:13:38.461-0500 I COMMAND  [conn15] command test3.$cmd command: create { create: "interviews", flags: 1 } keyUpdates:0 writeConflicts:0 numYields:0 reslen:37 locks:{ Global: { acquireCount: { r: 1, w: 1 } }, MMAPV1Journal: { acquireCount: { w: 2 } }, Database: { acquireCount: { W: 1 } }, Metadata: { acquireCount: { W: 2 } } } 0ms
2015-10-14T17:13:38.556-0500 I NETWORK  [initandlisten] connection accepted from 127.0.0.1:59879 #16 (2 connections now open)
2015-10-14T17:13:38.556-0500 D COMMAND  [conn16] run command admin.$cmd { getnonce: 1 }
2015-10-14T17:13:38.556-0500 I COMMAND  [conn16] command admin.$cmd command: getnonce { getnonce: 1 } keyUpdates:0 writeConflicts:0 numYields:0 reslen:65 locks:{} 0ms
2015-10-14T17:13:38.560-0500 I NETWORK  [initandlisten] connection accepted from 127.0.0.1:59880 #17 (3 connections now open)
2015-10-14T17:13:38.560-0500 D COMMAND  [conn17] run command admin.$cmd { getnonce: 1 }
2015-10-14T17:13:38.560-0500 I COMMAND  [conn17] command admin.$cmd command: getnonce { getnonce: 1 } keyUpdates:0 writeConflicts:0 numYields:0 reslen:64 locks:{} 0ms
2015-10-14T17:13:38.570-0500 I NETWORK  [initandlisten] connection accepted from 127.0.0.1:59881 #18 (4 connections now open)
2015-10-14T17:13:38.570-0500 D COMMAND  [conn18] run command admin.$cmd { getnonce: 1 }
2015-10-14T17:13:38.570-0500 I COMMAND  [conn18] command admin.$cmd command: getnonce { getnonce: 1 } keyUpdates:0 writeConflicts:0 numYields:0 reslen:65 locks:{} 0ms
2015-10-14T17:13:38.650-0500 D JOURNAL  [journal writer] lsn set 166014
2015-10-14T17:13:38.798-0500 I -        [conn18] Assertion: 10334:BSONObj size: 33541467 (0x1FFCD5B) is invalid. Size must be between 0 and 16793600(16MB) First element: insert: "interviews"
2015-10-14T17:13:38.804-0500 I CONTROL  [conn18]
 0x105eca5b9 0x105e772ae 0x105e64852 0x105e646fa 0x105763109 0x10594483f 0x1057a36fd 0x105a0a6be 0x1057432ce 0x105e87421 0x105efff69 0x7fff8f13a9b1 0x7fff8f13a92e 0x7fff8f138385
----- BEGIN BACKTRACE -----
{"backtrace":[{"b":"10573C000","o":"78E5B9"},{"b":"10573C000","o":"73B2AE"},{"b":"10573C000","o":"728852"},{"b":"10573C000","o":"7286FA"},{"b":"10573C000","o":"27109"},{"b":"10573C000","o":"20883F"},{"b":"10573C000","o":"676FD"},{"b":"10573C000","o":"2CE6BE"},{"b":"10573C000","o":"72CE"},{"b":"10573C000","o":"74B421"},{"b":"10573C000","o":"7C3F69"},{"b":"7FFF8F137000","o":"39B1"},{"b":"7FFF8F137000","o":"392E"},{"b":"7FFF8F137000","o":"1385"}],"processInfo":{ "mongodbVersion" : "3.0.7", "gitVersion" : "nogitversion", "uname" : { "sysname" : "Darwin", "release" : "15.0.0", "version" : "Darwin Kernel Version 15.0.0: Wed Aug 26 16:57:32 PDT 2015; root:xnu-3247.1.106~1/RELEASE_X86_64", "machine" : "x86_64" }, "somap" : [ { "path" : "/usr/local/opt/mongodb/bin/mongod", "machType" : 2, "b" : "10573C000", "buildId" : "461E0283714B3126B5B04D4EB8808F43" }, { "path" : "/usr/lib/libSystem.B.dylib", "machType" : 6, "b" : "7FFF8E274000", "buildId" : "E48AAE3F370E34AEAECA4CA28F211479" }, { "path" : "/usr/lib/libc++.1.dylib", "machType" : 6, "b" : "7FFF9817B000", "buildId" : "54190E1BEE493D6DAC292813D7380BA5" }, { "path" : "/usr/lib/system/libcache.dylib", "machType" : 6, "b" : "7FFF8A46D000", "buildId" : "4948E2C8867F3E9DAAE72F30F0B345C6" }, { "path" : "/usr/lib/system/libcommonCrypto.dylib", "machType" : 6, "b" : "7FFF947CF000", "buildId" : "BD1DCF1983533F6AAFFAEBBA29A302A8" }, { "path" : "/usr/lib/system/libcompiler_rt.dylib", "machType" : 6, "b" : "7FFF8F247000", "buildId" : "253B36E5572D377DAE99A02CE32590E5" }, { "path" : "/usr/lib/system/libcopyfile.dylib", "machType" : 6, "b" : "7FFF878B1000", "buildId" : "CA2602ABE8B73CD8A0C5D86E35FDA09F" }, { "path" : "/usr/lib/system/libcorecrypto.dylib", "machType" : 6, "b" : "7FFF8747A000", "buildId" : "4E1B969F84493B21988051AD58E25AA6" }, { "path" : "/usr/lib/system/libdispatch.dylib", "machType" : 6, "b" : "7FFF94642000", "buildId" : "6B38497E944834339D6B6223F2A99431" }, { "path" : "/usr/lib/system/libdyld.dylib", "machType" : 6, "b" : "7FFF9657A000", "buildId" : "F9D64D8C4C333D06B7F8697F13292894" }, { "path" : "/usr/lib/system/libkeymgr.dylib", "machType" : 6, "b" : "7FFF8BF96000", "buildId" : "470802808B573D758A209E100864DE27" }, { "path" : "/usr/lib/system/liblaunch.dylib", "machType" : 6, "b" : "7FFF8A551000", "buildId" : "7EC0F29743CC3D11B46B7E72E372648A" }, { "path" : "/usr/lib/system/libmacho.dylib", "machType" : 6, "b" : "7FFF8A8EB000", "buildId" : "A9EC23EC11A03B4FA8ACB990C8267A6E" }, { "path" : "/usr/lib/system/libquarantine.dylib", "machType" : 6, "b" : "7FFF90671000", "buildId" : "1693C5FEEA0A312285EB7950ECC7435A" }, { "path" : "/usr/lib/system/libremovefile.dylib", "machType" : 6, "b" : "7FFF96E81000", "buildId" : "C7CFF5F2AFFB3C8DBDB4D66D50E657C0" }, { "path" : "/usr/lib/system/libsystem_asl.dylib", "machType" : 6, "b" : "7FFF982B1000", "buildId" : "97D794DA8CE53676AC5E364F6D172BDA" }, { "path" : "/usr/lib/system/libsystem_blocks.dylib", "machType" : 6, "b" : "7FFF89B71000", "buildId" : "1B4F1F10823E378181626884D14DF0D6" }, { "path" : "/usr/lib/system/libsystem_c.dylib", "machType" : 6, "b" : "7FFF8A1B6000", "buildId" : "A60CE86D1FF332ADA672C7597F884529" }, { "path" : "/usr/lib/system/libsystem_configuration.dylib", "machType" : 6, "b" : "7FFF97AA5000", "buildId" : "EB55C3D8048D350EBF240CBD4479D51C" }, { "path" : "/usr/lib/system/libsystem_coreservices.dylib", "machType" : 6, "b" : "7FFF90665000", "buildId" : "692631A0192332CA9BD5044B1382FFDE" }, { "path" : "/usr/lib/system/libsystem_coretls.dylib", "machType" : 6, "b" : "7FFF93DD2000", "buildId" : "21EDACF1D9B33086982160EB75E7F965" }, { "path" : "/usr/lib/system/libsystem_dnssd.dylib", "machType" : 6, "b" : "7FFF96D6B000", "buildId" : "DB6AB2064AD8369DBF571D246AD60582" }, { "path" : "/usr/lib/system/libsystem_info.dylib", "machType" : 6, "b" : "7FFF8756D000", "buildId" : "65D0643AC8AE3E8D9F6EE4AD823F16B2" }, { "path" : "/usr/lib/system/libsystem_kernel.dylib", "machType" : 6, "b" : "7FFF93A94000", "buildId" : "7DD242A1E2BF39D18787B174046E4F15" }, { "path" : "/usr/lib/system/libsystem_m.dylib", "machType" : 6, "b" : "7FFF8FB5D000", "buildId" : "07D5037230ED3B039FA00662BF8F0098" }, { "path" : "/usr/lib/system/libsystem_malloc.dylib", "machType" : 6, "b" : "7FFF899F2000", "buildId" : "1B57A6143D603F87876F7DB4AF38120F" }, { "path" : "/usr/lib/system/libsystem_network.dylib", "machType" : 6, "b" : "7FFF9A8F8000", "buildId" : "14ECA259D4713E47A843FF0990577893" }, { "path" : "/usr/lib/system/libsystem_networkextension.dylib", "machType" : 6, "b" : "7FFF9A8AC000", "buildId" : "4736FCC59DBA31F4AAC8CD0A177CF502" }, { "path" : "/usr/lib/system/libsystem_notify.dylib", "machType" : 6, "b" : "7FFF96E41000", "buildId" : "56ABC155CB9930A8A8B1C204B5615092" }, { "path" : "/usr/lib/system/libsystem_platform.dylib", "machType" : 6, "b" : "7FFF92A09000", "buildId" : "3F4D2390E3DE3C24A51595DFAC8671C4" }, { "path" : "/usr/lib/system/libsystem_pthread.dylib", "machType" : 6, "b" : "7FFF8F137000", "buildId" : "1373D0F1C6CA364EA6BA8BDBD0D34670" }, { "path" : "/usr/lib/system/libsystem_sandbox.dylib", "machType" : 6, "b" : "7FFF9B01B000", "buildId" : "2F36D536482C39ECBAFD72297728F0A4" }, { "path" : "/usr/lib/system/libsystem_secinit.dylib", "machType" : 6, "b" : "7FFF90897000", "buildId" : "932ED582E80F39DAB0FAF1BC5F1AD2F8" }, { "path" : "/usr/lib/system/libsystem_trace.dylib", "machType" : 6, "b" : "7FFF8B30A000", "buildId" : "E26A91EAAD673FA2A3B679A93DCC716E" }, { "path" : "/usr/lib/system/libunc.dylib", "machType" : 6, "b" : "7FFF9692D000", "buildId" : "D9B0C7B186483AAC931CE7CD362FAA8A" }, { "path" : "/usr/lib/system/libunwind.dylib", "machType" : 6, "b" : "7FFF990F4000", "buildId" : "FDA18078A7753BAFA5A68A7B75D6AA99" }, { "path" : "/usr/lib/system/libxpc.dylib", "machType" : 6, "b" : "7FFF98C42000", "buildId" : "3E09C275A33B357AB0ABA2DDF88EC9D5" }, { "path" : "/usr/lib/libobjc.A.dylib", "machType" : 6, "b" : "7FFF8C396000", "buildId" : "CE3C3C78A7BB3147837555424032FF5E" }, { "path" : "/usr/lib/libauto.dylib", "machType" : 6, "b" : "7FFF8A817000", "buildId" : "460B0167C89B37EC823C52F684B31C26" }, { "path" : "/usr/lib/libc++abi.dylib", "machType" : 6, "b" : "7FFF8A43E000", "buildId" : "F5027B461801344DBD512E6D188C8900" }, { "path" : "/usr/lib/libDiagnosticMessagesClient.dylib", "machType" : 6, "b" : "7FFF8A8E9000", "buildId" : "F2D8CFCCA00A36759C01EF0C663F2445" } ] }}
 mongod(_ZN5mongo15printStackTraceERNSt3__113basic_ostreamIcNS0_11char_traitsIcEEEE+0x39) [0x105eca5b9]
 mongod(_ZN5mongo10logContextEPKc+0x10E) [0x105e772ae]
 mongod(_ZN5mongo11msgassertedEiPKc+0x152) [0x105e64852]
 mongod(_ZN5mongo11msgassertedEiRKNSt3__112basic_stringIcNS0_11char_traitsIcEENS0_9allocatorIcEEEE+0x1A) [0x105e646fa]
 mongod(_ZNK5mongo7BSONObj14_assertInvalidEv+0x4B9) [0x105763109]
 mongod(_ZN5mongo9DbMessage9nextJsObjEv+0x9F) [0x10594483f]
 mongod(_ZN5mongo12QueryMessageC2ERNS_9DbMessageE+0x5D) [0x1057a36fd]
 mongod(_ZN5mongo16assembleResponseEPNS_16OperationContextERNS_7MessageERNS_10DbResponseERKNS_11HostAndPortE+0x44E) [0x105a0a6be]
 mongod(_ZN5mongo16MyMessageHandler7processERNS_7MessageEPNS_21AbstractMessagingPortEPNS_9LastErrorE+0xDE) [0x1057432ce]
 mongod(_ZN5mongo17PortMessageServer17handleIncomingMsgEPv+0x291) [0x105e87421]
 mongod(_ZN5boost12_GLOBAL__N_112thread_proxyEPv+0xA9) [0x105efff69]
 libsystem_pthread.dylib(_pthread_body+0x83) [0x7fff8f13a9b1]
 libsystem_pthread.dylib(_pthread_body+0x0) [0x7fff8f13a92e]
 libsystem_pthread.dylib(thread_start+0xD) [0x7fff8f138385]
-----  END BACKTRACE  -----
2015-10-14T17:13:38.804-0500 I NETWORK  [conn18] AssertionException handling request, closing client connection: 10334 BSONObj size: 33541467 (0x1FFCD5B) is invalid. Size must be between 0 and 16793600(16MB) First element: insert: "interviews"
2015-10-14T17:13:38.849-0500 D NETWORK  [conn16] SocketException: remote: 127.0.0.1:59879 error: 9001 socket exception [CLOSED] server [127.0.0.1:59879]
2015-10-14T17:13:38.849-0500 I NETWORK  [conn16] end connection 127.0.0.1:59879 (2 connections now open)
2015-10-14T17:13:38.849-0500 D NETWORK  [conn15] SocketException: remote: 127.0.0.1:59878 error: 9001 socket exception [CLOSED] server [127.0.0.1:59878]
2015-10-14T17:13:38.849-0500 I NETWORK  [conn15] end connection 127.0.0.1:59878 (1 connection now open)
2015-10-14T17:13:38.851-0500 D NETWORK  [conn17] SocketException: remote: 127.0.0.1:59880 error: 9001 socket exception [CLOSED] server [127.0.0.1:59880]
2015-10-14T17:13:38.851-0500 I NETWORK  [conn17] end connection 127.0.0.1:59880 (0 connections now open)
Waiting for data... (interrupt to abort)



 Comments   
Comment by Ramon Fernandez Marina [ 16/Oct/15 ]

We've now confirmed that this ticket is a duplicate of TOOLS-939, which has already been fixed in master and v3.0 and will be part of upcoming releases in those branches.

The workaround is to use a 3.0.6 mongorestore. Apologies for the inconvenience.

Regards,
Ramón.

Comment by Michael Werle [ 16/Oct/15 ]

Sorry I missed that – I did search, but did not see it, somehow. I'm nearly certain that this issue is a duplicate of that issue.

Comment by Ramon Fernandez Marina [ 16/Oct/15 ]

There's a known issue in mongorestore 3.0.7 (see TOOLS-939) which may explain the behavior described on this ticket. If this is the same issue then a suitable workaround is to use 3.0.6 mongorestore.

Comment by Matt Taylor [X] [ 16/Oct/15 ]

My use case was moving a database from a v2.6.11 server to a different v3.0.7 server.

I tried creating backups using tools from v3.0.7 as well as v2.6.11 and was not able to restore either of them into version v3.0.7 with both the v3.0.7 and v2.6.11 mongorestore commands (standalone or replica set). The one case where I was able to restore the same backup file was using the v3.0.6 restore tool and server.

Comment by Michael Werle [ 16/Oct/15 ]

When I last tested, I used a bson file provided as part of a mongodump backup from MongoLabs from a cluster (no sharding) running Mongo 3.0.6. When that failed, I did the following:

  1. Restored the DB to my local instance running 3.0.6.
  2. Upgraded the my local instance to 3.0.7
  3. Backed up the interviews collection.
  4. Attempted to restore the collection with the "--drop" option on mongorestore.

So, I don't think that there's a meaningful difference in the source of the backup file; it seems to be a problem with the restore process.

Comment by Ramon Fernandez Marina [ 16/Oct/15 ]

No problem mkw. If you can't share your current data perhaps there's an experiment you can try to narrow down the problem: can you try to restore to a 3.0.6 server with the 3.0.7 tools? And/or the other way around – that may tell us if this is an issue with the tools or with the server.

Thanks,
Ramón.

Comment by Michael Werle [ 16/Oct/15 ]

Sorry I'm slow – the collections that I used to test originally have information in them that I cannot release. I haven't had a chance to switch back to 3.0.7 to test some collections that I can upload, but I'll upload some once I get a chance to confirm that they also fail.

Comment by Ramon Fernandez Marina [ 16/Oct/15 ]

Thanks for uploading the data Twenty7, I'm downloading it now and will post an update to this ticket as soon as I have more information.

Comment by Matt Taylor [X] [ 15/Oct/15 ]

I am also receiving a similar error when restoring into Mongo v3.0.7

2015-10-15T19:56:55.240+0000 I -        [conn2] Assertion: 10334:BSONObj size: 17611264 (0x10CBA00) is invalid. Size must be between 0 and 16793600(16MB) First element: insert: "responses"
2015-10-15T19:56:55.245+0000 I CONTROL  [conn2]
 0xf5c949 0xefb781 0xee09df 0xee0a8c 0x8346ff 0x9e9af8 0x873787 0xab3aa7 0x80e43d 0xf0f7eb 0x7f04eee0adf5 0x7f04ed8bcbfd
----- BEGIN BACKTRACE -----
{"backtrace":[{"b":"400000","o":"B5C949"},{"b":"400000","o":"AFB781"},{"b":"400000","o":"AE09DF"},{"b":"400000","o":"AE0A8C"},{"b":"400000","o":"4346FF"},{"b":"400000","o":"5E9AF8"},{"b":"400000","o":"473787"},{"b":"400000","o":"6B3AA7"},{"b":"400000","o":"40E43D"},{"b":"400000","o":"B0F7EB"},{"b":"7F04EEE03000","o":"7DF5"},{"b":"7F04ED7C6000","o":"F6BFD"}],"processInfo":{ "mongodbVersion" : "3.0.7", "gitVersion" : "6ce7cbe8c6b899552dadd907604559806aa2e9bd", "uname" : { "sysname" : "Linux", "release" : "4.1.7-15.23.amzn1.x86_64", "version" : "#1 SMP Mon Sep 14 23:20:33 UTC 2015", "machine" : "x86_64" }, "somap" : [ { "elfType" : 2, "b" : "400000", "buildId" : "135D3273A8F29EDEA1A35CFC89771434807D4716" }, { "b" : "7FFED1D7F000", "elfType" : 3, "buildId" : "AF79256455DAB4D8F13725CDA5E71975F69FED3F" }, { "b" : "7F04EEE03000", "path" : "/lib64/libpthread.so.0", "elfType" : 3, "buildId" : "21054340E69FD5F7DDC9DECEF7951CF3F3D2E78E" }, { "b" : "7F04EEB96000", "path" : "/usr/lib64/libssl.so.10", "elfType" : 3, "buildId" : "22480480235F3B1C6C2E5E5953949728676D3796" }, { "b" : "7F04EE7B1000", "path" : "/lib64/libcrypto.so.10", "elfType" : 3, "buildId" : "F1C146B78505646930DD9003AA2B3622C5226D1B" }, { "b" : "7F04EE5A9000", "path" : "/lib64/librt.so.1", "elfType" : 3, "buildId" : "8A6EB7521ABE0518C2803504B52F18412D69C713" }, { "b" : "7F04EE3A5000", "path" : "/lib64/libdl.so.2", "elfType" : 3, "buildId" : "7030B651A4F5D6F32A8D83F3541990E342C50E6C" }, { "b" : "7F04EE0A0000", "path" : "/usr/lib64/libstdc++.so.6", "elfType" : 3, "buildId" : "0A90C35D3174805453EA67A785446D628E298B59" }, { "b" : "7F04EDD9E000", "path" : "/lib64/libm.so.6", "elfType" : 3, "buildId" : "EB09196C8A859427FD964381CDAC80EC0C4C4296" }, { "b" : "7F04EDB88000", "path" : "/lib64/libgcc_s.so.1", "elfType" : 3, "buildId" : "00FA2883FB47B1327397BBF167C52F51A723D013" }, { "b" : "7F04ED7C6000", "path" : "/lib64/libc.so.6", "elfType" : 3, "buildId" : "0EB7F7FA93C9C3E017F7257AE97415730345767B" }, { "b" : "7F04EF01F000", "path" : "/lib64/ld-linux-x86-64.so.2", "elfType" : 3, "buildId" : "F451C8F279B6860B00F835764FFBA0D54879E1C6" }, { "b" : "7F04ED57A000", "path" : "/lib64/libgssapi_krb5.so.2", "elfType" : 3, "buildId" : "FF843C37C38E5BFFD57F7BCCAE05FDADC6390C8F" }, { "b" : "7F04ED297000", "path" : "/lib64/libkrb5.so.3", "elfType" : 3, "buildId" : "0BB150CC29DB5B0E039879EFC00152A75E3B00B9" }, { "b" : "7F04ED094000", "path" : "/usr/lib64/libcom_err.so.2", "elfType" : 3, "buildId" : "5C01209C5AE1B1714F19B07EB58F2A1274B69DC8" }, { "b" : "7F04ECE62000", "path" : "/lib64/libk5crypto.so.3", "elfType" : 3, "buildId" : "1485992B0E5CDBA0A34817FC8C6A4C45E82CD1A9" }, { "b" : "7F04ECC4C000", "path" : "/lib64/libz.so.1", "elfType" : 3, "buildId" : "89C6AF118B6B4FB6A73AE1813E2C8BDD722956D1" }, { "b" : "7F04ECA3D000", "path" : "/lib64/libkrb5support.so.0", "elfType" : 3, "buildId" : "A75A81EC50E9E0164A12B59D9987AD61AC7576C8" }, { "b" : "7F04EC83A000", "path" : "/lib64/libkeyutils.so.1", "elfType" : 3, "buildId" : "37A58210FA50C91E09387765408A92909468D25B" }, { "b" : "7F04EC620000", "path" : "/lib64/libresolv.so.2", "elfType" : 3, "buildId" : "F586C9A0950DFD60125B2F56B0EC6D690128B1FC" }, { "b" : "7F04EC3FF000", "path" : "/usr/lib64/libselinux.so.1", "elfType" : 3, "buildId" : "F5054DC94443326819FBF3065CFDF5E4726F57EE" } ] }}
 mongod(_ZN5mongo15printStackTraceERSo+0x29) [0xf5c949]
 mongod(_ZN5mongo10logContextEPKc+0xE1) [0xefb781]
 mongod(_ZN5mongo11msgassertedEiPKc+0xAF) [0xee09df]
 mongod(+0xAE0A8C) [0xee0a8c]
 mongod(_ZNK5mongo7BSONObj14_assertInvalidEv+0x3DF) [0x8346ff]
 mongod(_ZN5mongo9DbMessage9nextJsObjEv+0x108) [0x9e9af8]
 mongod(_ZN5mongo12QueryMessageC2ERNS_9DbMessageE+0x57) [0x873787]
 mongod(_ZN5mongo16assembleResponseEPNS_16OperationContextERNS_7MessageERNS_10DbResponseERKNS_11HostAndPortE+0x967) [0xab3aa7]
 mongod(_ZN5mongo16MyMessageHandler7processERNS_7MessageEPNS_21AbstractMessagingPortEPNS_9LastErrorE+0xDD) [0x80e43d]
 mongod(_ZN5mongo17PortMessageServer17handleIncomingMsgEPv+0x34B) [0xf0f7eb]
 libpthread.so.0(+0x7DF5) [0x7f04eee0adf5]
 libc.so.6(clone+0x6D) [0x7f04ed8bcbfd]
-----  END BACKTRACE  -----
2015-10-15T19:56:55.245+0000 I NETWORK  [conn2] AssertionException handling request, closing client connection: 10334 BSONObj size: 17611264 (0x10CBA00) is invalid. Size must be between 0 and 16793600(16MB) First element: insert: "responses"

This file will not restore into v3.0.7 but it does restore into v3.0.6. Upgrading to v3.0.7 with this data already imported seems to work without errors. I've uploaded a file that you can use to reproduce this with v3.0.7. I've been able to reproduce this error on CentOS as well as Windows.

Comment by Ramon Fernandez Marina [ 14/Oct/15 ]

mkw, I'm not able to reproduce this behavior. Could you please share with us one of the collections that you're not able to restore? You can upload it safely and securely here.

Thanks,
Ramón.

Generated at Thu Feb 08 03:55:43 UTC 2024 using Jira 9.7.1#970001-sha1:2222b88b221c4928ef0de3161136cc90c8356a66.