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

Assertion Error: bsonobjbuilder.h:127

    • Type: Icon: Bug Bug
    • Resolution: Duplicate
    • Priority: Icon: Major - P3 Major - P3
    • None
    • Affects Version/s: 2.0.4
    • Component/s: Internal Code
    • Labels:
      None
    • Linux

      During a test, was bombarding the mongos with lots of updates (15K / second).
      MongoS running on my desktop, sharded replicated server running at datacenter.
      After running for a minute or two, saw one of the shards die (both primary and replica mongod's).
      launched mongo, did db.metricValue.validate(

      {force:true}

      ) and got:

      "assertion" : "assertion s/../util/net/../../db/../bson/bsonobjbuilder.h:127",
      "errmsg" : "db assertion failure",
      "ok" : 0,
      "valid" : true

      Thu Jun 28 17:47:39 [conn7] command admin.$cmd command:

      { writebacklisten: ObjectId('4fecc1f63d9b3922414c3655') }

      ntoreturn:1 reslen:44 300000ms
      Thu Jun 28 17:47:52 [conn675] end connection 10.235.37.37:32728
      Thu Jun 28 17:47:52 [initandlisten] connection accepted from 10.235.37.37:32760 #677
      Thu Jun 28 17:48:01 [conn676] end connection 10.235.62.67:50484
      Thu Jun 28 17:48:01 [initandlisten] connection accepted from 10.235.62.67:50518 #678
      Thu Jun 28 17:48:02 [conn214] warning: virtual size (100147MB) - mapped size (94834MB) is large (5248MB). could indicate a memory leak
      Thu Jun 28 17:48:20 [conn613] request split points lookup for chunk megamaid.metricValue { : 253358, : ObjectId('4feca9ab64524c2474007f6d') } -->> { : 263685, : ObjectId('4fecc8d7c953ef589a003357') }
      Thu Jun 28 17:48:20 [conn613] max number of requested split points reached (2) before the end of chunk megamaid.metricValue { : 253358, : ObjectId('4feca9ab64524c2474007f6d') } -->> { : 263685, : ObjectId('4fecc8d7c953ef589a003357') }
      Thu Jun 28 17:48:20 [conn613] SyncClusterConnection connecting to [graphdb301p.mydomain.com:30501]
      Thu Jun 28 17:48:20 [conn613] SyncClusterConnection connecting to [graphdb302p.mydomain.com:30502]
      Thu Jun 28 17:48:20 [conn613] SyncClusterConnection connecting to [graphdb303p.mydomain.com:30503]
      Thu Jun 28 17:48:20 [conn613] starting new replica set monitor for replica set shard-00 with seed of graphdb301p.mydomain.com:30200,graphdb302p.mydomain.com:30300
      Thu Jun 28 17:48:20 [conn613] successfully connected to seed graphdb301p.mydomain.com:30200 for replica set shard-00
      Thu Jun 28 17:48:20 [conn613] Socket recv() errno:104 Connection reset by peer 10.235.54.65:30200
      Thu Jun 28 17:48:20 [conn613] SocketException: remote: 10.235.54.65:30200 error: 9001 socket exception [1] server [10.235.54.65:30200]
      Thu Jun 28 17:48:20 [conn613] DBClientCursor::init call() failed
      Thu Jun 28 17:48:20 Invalid access at address: 0xffffffffffffffe0

      Thu Jun 28 17:48:20 Got signal: 11 (Segmentation fault).

      Thu Jun 28 17:48:20 Backtrace:
      0xa95ce9 0xa9640c 0x342540f4a0 0x5d51b3 0x5d7311 0x5d7b6d 0xa21bd3 0xa2235b 0xa27862 0xa27f5e 0xa22502 0xa6dad6 0x97c4f4 0x97dbfd 0x940f05 0x943a30 0x889107 0x88dcd9 0xaa0bc8 0x6389f7
      /opt/mongo/bin/mongod(_ZN5mongo10abruptQuitEi+0x3a9) [0xa95ce9]
      /opt/mongo/bin/mongod(_ZN5mongo24abruptQuitWithAddrSignalEiP7siginfoPv+0x22c) [0xa9640c]
      /lib64/libpthread.so.0() [0x342540f4a0]
      /opt/mongo/bin/mongod(_ZN5mongo17ReplicaSetMonitor16_checkConnectionEPNS_18DBClientConnectionERSsbi+0x1543) [0x5d51b3]
      /opt/mongo/bin/mongod(_ZN5mongo17ReplicaSetMonitorC1ERKSsRKSt6vectorINS_11HostAndPortESaIS4_EE+0x381) [0x5d7311]
      /opt/mongo/bin/mongod(_ZN5mongo17ReplicaSetMonitor3getERKSsRKSt6vectorINS_11HostAndPortESaIS4_EE+0x1fd) [0x5d7b6d]
      /opt/mongo/bin/mongod(_ZN5mongo5Shard7_rsInitEv+0x133) [0xa21bd3]
      /opt/mongo/bin/mongod(_ZN5mongo5Shard8_setAddrERKSs+0x13b) [0xa2235b]
      /opt/mongo/bin/mongod(_ZN5mongo15StaticShardInfo6reloadEv+0xab2) [0xa27862]
      /opt/mongo/bin/mongod(_ZN5mongo15StaticShardInfo4findERKSs+0x14e) [0xa27f5e]
      /opt/mongo/bin/mongod(_ZN5mongo5Shard5resetERKSs+0x42) [0xa22502]
      /opt/mongo/bin/mongod(_ZN5mongo17SplitChunkCommand3runERKSsRNS_7BSONObjEiRSsRNS_14BSONObjBuilderEb+0xc06) [0xa6dad6]
      /opt/mongo/bin/mongod(_ZN5mongo11execCommandEPNS_7CommandERNS_6ClientEiPKcRNS_7BSONObjERNS_14BSONObjBuilderEb+0x6c4) [0x97c4f4]
      /opt/mongo/bin/mongod(_ZN5mongo12_runCommandsEPKcRNS_7BSONObjERNS_11_BufBuilderINS_16TrivialAllocatorEEERNS_14BSONObjBuilderEbi+0x6fd) [0x97dbfd]
      /opt/mongo/bin/mongod(_ZN5mongo11runCommandsEPKcRNS_7BSONObjERNS_5CurOpERNS_11_BufBuilderINS_16TrivialAllocatorEEERNS_14BSONObjBuilderEbi+0x35) [0x940f05]
      /opt/mongo/bin/mongod(ZN5mongo8runQueryERNS_7MessageERNS_12QueryMessageERNS_5CurOpES1+0x1740) [0x943a30]
      /opt/mongo/bin/mongod() [0x889107]
      /opt/mongo/bin/mongod(_ZN5mongo16assembleResponseERNS_7MessageERNS_10DbResponseERKNS_11HostAndPortE+0x559) [0x88dcd9]
      /opt/mongo/bin/mongod(_ZN5mongo16MyMessageHandler7processERNS_7MessageEPNS_21AbstractMessagingPortEPNS_9LastErrorE+0x78) [0xaa0bc8]
      /opt/mongo/bin/mongod(_ZN5mongo3pms9threadRunEPNS_13MessagingPortE+0x287) [0x6389f7]

      Thu Jun 28 17:48:20 dbexit:
      Thu Jun 28 17:48:20 [conn613] shutdown: going to close listening sockets...
      Thu Jun 28 17:48:20 [conn613] closing listening socket: 5
      Thu Jun 28 17:48:20 [conn613] closing listening socket: 6
      Thu Jun 28 17:48:20 [conn613] closing listening socket: 8
      Thu Jun 28 17:48:20 [conn613] removing socket file: /tmp/mongodb-30212.sock
      Thu Jun 28 17:48:20 [conn303] got request after shutdown()
      Thu Jun 28 17:48:20 [conn613] shutdown: going to flush diaglog...
      Thu Jun 28 17:48:20 [conn613] shutdown: going to close sockets...
      Thu Jun 28 17:48:20 [conn613] shutdown: waiting for fs preallocator...
      Thu Jun 28 17:48:20 [conn613] shutdown: closing all files...
      Thu Jun 28 17:48:20 [conn1] end connection 127.0.0.1:9489
      Thu Jun 28 17:48:20 [conn639] end connection 10.235.37.217:29672
      Thu Jun 28 17:48:20 [conn612] end connection 10.235.37.217:29494
      Thu Jun 28 17:48:20 [conn4] Assertion: 13073:shutting down
      Thu Jun 28 17:48:20 [initandlisten] now exiting
      Thu Jun 28 17:48:20 dbexit: ; exiting immediately
      0x5848a2 0x885c8c 0x88e6da 0xaa0bc8 0x6389f7 0x34254077f1 0x3424ce5ccd
      Logstream::get called in uninitialized state
      Thu Jun 28 17:48:20 [conn298] end connection 10.235.37.217:28854
      /opt/mongo/bin/mongod(_ZN5mongo11msgassertedEiPKc+0x112) [0x5848a2]
      /opt/mongo/bin/mongod(_ZN5mongo15receivedGetMoreERNS_10DbResponseERNS_7MessageERNS_5CurOpE+0x41c) [0x885c8c]
      /opt/mongo/bin/mongod(_ZN5mongo16assembleResponseERNS_7MessageERNS_10DbResponseERKNS_11HostAndPortE+0xf5a) [0x88e6da]
      /opt/mongo/bin/mongod(_ZN5mongo16MyMessageHandler7processERNS_7MessageEPNS_21AbstractMessagingPortEPNS_9LastErrorE+0x78) [0xaa0bc8]
      /opt/mongo/bin/mongod(_ZN5mongo3pms9threadRunEPNS_13MessagingPortE+0x287) [0x6389f7]
      /lib64/libpthread.so.0() [0x34254077f1]
      /lib64/libc.so.6(clone+0x6d) [0x3424ce5ccd]
      Logstream::get called in uninitialized state
      Thu Jun 28 17:48:20 [conn4] AssertionException handling request, closing client connection: 13073 shutting down

            Assignee:
            randolph@mongodb.com Randolph Tan
            Reporter:
            justanyone Kevin J. Rice
            Votes:
            0 Vote for this issue
            Watchers:
            2 Start watching this issue

              Created:
              Updated:
              Resolved: