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

mongos segfault - ERROR: MessagingPort::call() wrong id got:1 expect:4229ee51

    • Type: Icon: Bug Bug
    • Resolution: Done
    • Priority: Icon: Major - P3 Major - P3
    • 1.7.6
    • Affects Version/s: 1.7.5
    • Component/s: None
    • Labels:
      None
    • Linux

      10.121.14.6 = rs2b (shard 2 secondary)

      mongos log:

      Wed Feb 2 02:43:58 [conn52] ReplicaSetMonitor::_checkConnection: rs1a:27018

      { setName: "set1", ismaster: true, secondary: false, hosts: [ "rs1a:27018", "rs1b:27018" ], arbiters: [ "rs1arbiter:27018" ], maxBsonObjectSize: 16777216, ok: 1.0 }

      recv(): message len -1768263985 is too large-1768263985
      Wed Feb 2 02:43:58 [conn52] DBClientCursor::init call() failed
      Wed Feb 2 02:43:58 [conn58] ERROR: MessagingPort::call() wrong id got:1 expect:4229ee51
      toSend op: 2004
      response msgid:1110044241
      response len: 882
      response op: 8
      farEnd: 10.121.14.3:27018
      Wed Feb 2 02:43:58 [conn58] Assertion failure false util/message.cpp 512
      0x5105ae 0x521dd1 0x51c68e 0x51cb54 0x53d7f4 0x559698 0x53c4aa 0x54cce1 0x54885c 0x54b8ac 0x54ef71 0x5507bb 0x55101c 0x55169b 0x5518a9 0x552698 0x54b8ac 0x652441 0x57bbac 0x6306eb
      /home/david/mongodb/latest/bin/mongos(_ZN5mongo12sayDbContextEPKc+0xae) [0x5105ae]
      /home/david/mongodb/latest/bin/mongos(_ZN5mongo8assertedEPKcS1_j+0x111) [0x521dd1]
      /home/david/mongodb/latest/bin/mongos(ZN5mongo13MessagingPort4recvERKNS_7MessageERS1+0x32e) [0x51c68e]
      /home/david/mongodb/latest/bin/mongos(ZN5mongo13MessagingPort4callERNS_7MessageES2+0x34) [0x51cb54]
      /home/david/mongodb/latest/bin/mongos(_ZN5mongo18DBClientConnection4callERNS_7MessageES2_b+0x34) [0x53d7f4]
      /home/david/mongodb/latest/bin/mongos(_ZN5mongo14DBClientCursor4initEv+0x148) [0x559698]
      /home/david/mongodb/latest/bin/mongos(_ZN5mongo12DBClientBase5queryERKSsNS_5QueryEiiPKNS_7BSONObjEii+0x32a) [0x53c4aa]
      /home/david/mongodb/latest/bin/mongos(_ZN5mongo18DBClientConnection5queryERKSsNS_5QueryEiiPKNS_7BSONObjEii+0xa1) [0x54cce1]
      /home/david/mongodb/latest/bin/mongos(_ZN5mongo17DBClientInterface7findOneERKSsRKNS_5QueryEPKNS_7BSONObjEi+0x7c) [0x54885c]
      /home/david/mongodb/latest/bin/mongos(_ZN5mongo20DBClientWithCommands10runCommandERKSsRKNS_7BSONObjERS3_i+0x8c) [0x54b8ac]
      /home/david/mongodb/latest/bin/mongos(_ZN5mongo17ReplicaSetMonitor12_checkStatusEPNS_18DBClientConnectionE+0x251) [0x54ef71]
      /home/david/mongodb/latest/bin/mongos(_ZN5mongo17ReplicaSetMonitor16_checkConnectionEPNS_18DBClientConnectionERSsb+0x24b) [0x5507bb]
      /home/david/mongodb/latest/bin/mongos(_ZN5mongo17ReplicaSetMonitor6_checkEv+0x13c) [0x55101c]
      /home/david/mongodb/latest/bin/mongos(_ZN5mongo17ReplicaSetMonitor9getMasterEv+0xbb) [0x55169b]
      /home/david/mongodb/latest/bin/mongos(_ZN5mongo18DBClientReplicaSet11checkMasterEv+0x39) [0x5518a9]
      /home/david/mongodb/latest/bin/mongos(_ZN5mongo18DBClientReplicaSet7findOneERKSsRKNS_5QueryEPKNS_7BSONObjEi+0x168) [0x552698]
      /home/david/mongodb/latest/bin/mongos(_ZN5mongo20DBClientWithCommands10runCommandERKSsRKNS_7BSONObjERS3_i+0x8c) [0x54b8ac]
      /home/david/mongodb/latest/bin/mongos(_ZN5mongo15dbgrid_pub_cmds8CountCmd3runERKSsRNS_7BSONObjERSsRNS_14BSONObjBuilderEb+0xcd1) [0x652441]
      /home/david/mongodb/latest/bin/mongos(_ZN5mongo7Command20runAgainstRegisteredEPKcRNS_7BSONObjERNS_14BSONObjBuilderE+0x67c) [0x57bbac]
      /home/david/mongodb/latest/bin/mongos(_ZN5mongo14SingleStrategy7queryOpERNS_7RequestE+0x28b) [0x6306eb]
      Wed Feb 2 02:43:58 [conn58] trying reconnect to rs1a:27018
      Wed Feb 2 02:43:58 [conn52] MessagingPort recv() errno:9 Bad file descriptor 10.121.14.3:27018
      Wed Feb 2 02:43:58 [conn58] reconnect rs1a:27018 ok
      Received signal 11
      Backtrace: 0x52fc75 0x3887c302d0 0x2aaad400021f
      /home/david/mongodb/latest/bin/mongos(_ZN5mongo17printStackAndExitEi+0x75)[0x52fc75]
      /lib64/libc.so.6[0x3887c302d0]
      [0x2aaad400021f]
      ===

      mongod log:

      Wed Feb 2 02:41:39 [conn23006] query sd.metrics ntoreturn:1000 reslen:46032 nscanned:10559887 { $query: { $nor: [ { accId: 2461, tA:

      { $gt: new Date(1294022476708) }

      }, { accId: 2805, tA:

      { $gt: new Date(1296009676708) }

      }, { tA:

      { $gt: new Date(1296355276710) }

      } ] }, $orderby:

      { _id: 1 }

      } nreturned:317 22778ms
      Wed Feb 2 02:41:40 [conn23006] remove sd.metrics query:

      { _id: ObjectId('4d44cfbb160ba0df4800220a'), accId: 1466, sId: 90 }

      139ms
      Wed Feb 2 02:41:58 [conn1099] query admin.$cmd ntoreturn:1 command:

      { writebacklisten: ObjectId('4d4559046224e45291a955ac') }

      reslen:60 300035ms
      Wed Feb 2 02:42:04 [conn23006] query sd.metrics ntoreturn:1000 reslen:36 nscanned:10559589 { $query: { $nor: [ { accId: 2461, tA:

      { $gt: new Date(1294022501675) }

      }, { accId: 2805, tA:

      { $gt: new Date(1296009701675) }

      }, { tA:

      { $gt: new Date(1296355301676) }

      } ] }, $orderby:

      { _id: 1 }

      } nreturned:0 22594ms
      Wed Feb 2 02:42:19 [conn18918] insert postbacks.postbacks 109ms
      Wed Feb 2 02:43:27 [conn23006] query sd.metrics ntoreturn:1000 reslen:3416 nscanned:10559589 { $query: { $nor: [ { accId: 2461, tA:

      { $gt: new Date(1294022584451) }

      }, { accId: 2805, tA:

      { $gt: new Date(1296009784451) }

      }, { tA:

      { $gt: new Date(1296355384453) }

      } ] }, $orderby:

      { _id: 1 }

      } nreturned:26 22849ms
      Wed Feb 2 02:43:51 [conn23006] query sd.metrics ntoreturn:1000 reslen:36 nscanned:10559563 { $query: { $nor: [ { accId: 2461, tA:

      { $gt: new Date(1294022608547) }

      }, { accId: 2805, tA:

      { $gt: new Date(1296009808547) }

      }, { tA:

      { $gt: new Date(1296355408549) }

      } ] }, $orderby:

      { _id: 1 }

      } nreturned:0 23111ms
      Wed Feb 2 02:43:58 [conn23143] SocketException in connThread, closing client connection
      Wed Feb 2 02:44:20 [conn1098] query admin.$cmd ntoreturn:1 command:

      { writebacklisten: ObjectId('4d455923c7428daa454d3b68') }

      reslen:60 300035ms
      Wed Feb 2 02:44:51 [conn16] query admin.$cmd ntoreturn:1 command:

      { writebacklisten: ObjectId('4d4559969d5ef329e2d8d1aa') }

      reslen:60 300033ms
      Wed Feb 2 02:44:51 [conn1095] query admin.$cmd ntoreturn:1 command:

      { writebacklisten: ObjectId('4d455817ae7b83da66a9a343') }

      reslen:60 300035ms
      Wed Feb 2 02:44:51 [conn1094] query admin.$cmd ntoreturn:1 command:

      { writebacklisten: ObjectId('4d455945716e637f9b5b4671') }

      reslen:60 300037ms
      Wed Feb 2 02:44:51 [conn1097] query admin.$cmd ntoreturn:1 command:

      { writebacklisten: ObjectId('4d455966fc9c48967db5963d') }

      reslen:60 300034ms
      Wed Feb 2 02:44:53 [conn1091] query admin.$cmd ntoreturn:1 command:

      { writebacklisten: ObjectId('4d4556df032f12d427a93e4a') }

      reslen:60 300034ms
      Wed Feb 2 02:44:53 [conn1096] query admin.$cmd ntoreturn:1 command:

      { writebacklisten: ObjectId('4d4557773cf5827a677a4dfd') }

      reslen:60 300034ms
      Wed Feb 2 02:44:54 [conn33] query admin.$cmd ntoreturn:1 command:

      { writebacklisten: ObjectId('4d4559ba0e7011b0b8f09b0c') }

      reslen:60 300034ms
      Wed Feb 2 02:44:56 [conn1092] query admin.$cmd ntoreturn:1 command:

      { writebacklisten: ObjectId('4d45669b4f797a4d910ad3de') }

      reslen:60 300034ms
      Wed Feb 2 02:45:11 [conn616] query admin.$cmd ntoreturn:1 command:

      { writebacklisten: ObjectId('4d4582133dfd0f0c561934c0') }

      reslen:60 300033ms
      Wed Feb 2 02:45:15 [conn20657] insert sd.metrics 113ms
      Wed Feb 2 02:45:16 [conn23006] query sd.metrics ntoreturn:1000 reslen:36 nscanned:10563476 { $query: { $nor: [ { accId: 2461, tA:

      { $gt: new Date(1294022691823) }

      }, { accId: 2805, tA:

      { $gt: new Date(1296009891823) }

      }, { tA:

      { $gt: new Date(1296355491825) }

      } ] }, $orderby:

      { _id: 1 }

      } nreturned:0 24887ms
      Wed Feb 2 02:45:23 [conn5242] query admin.$cmd ntoreturn:1 command:

      { writebacklisten: ObjectId('4d4559e6622687ffd909ae30') }

      reslen:60 300034ms
      Wed Feb 2 02:45:26 [conn1090] query admin.$cmd ntoreturn:1 command:

      { writebacklisten: ObjectId('4d4558dc3744c988cb50e729') }

      reslen:60 300033ms
      Wed Feb 2 02:45:26 [conn22723] insert sd.metrics 199ms
      Wed Feb 2 02:45:33 [conn22050] request split points lookup for chunk sd.processes { : 686, : 12 } -->> { : 686, : 15 }
      Wed Feb 2 02:45:40 [conn22781] query admin.$cmd ntoreturn:1 command:

      { setShardVersion: "sd.metrics", configdb: "config1:27019", version: Timestamp 7000|183, serverID: ObjectId('4d4564eaa593a1965ad27a3b'), shard: "shard1", shardHost: "set1/rs1a:27018,rs1b:27018" }

      reslen:81 152ms
      Wed Feb 2 02:45:40 [conn22781] query admin.$cmd ntoreturn:1 command:

      { setShardVersion: "sd.processes", configdb: "config1:27019", version: Timestamp 10000|1359, serverID: ObjectId('4d4564eaa593a1965ad27a3b'), shard: "shard1", shardHost: "set1/rs1a:27018,rs1b:27018" }

      reslen:81 202ms
      Wed Feb 2 02:45:40 [conn19127] query admin.$cmd ntoreturn:1 command:

      { setShardVersion: "sd.servers", configdb: "config1:27019", version: Timestamp 0|0, serverID: ObjectId('4d4564eaa593a1965ad27a3b'), shard: "shard1", shardHost: "set1/rs1a:27018,rs1b:27018" }

      reslen:53 172ms
      Wed Feb 2 02:45:40 [conn22050] warning: chunk is larger than 209715200 bytes because of key

      { accId: 686, sId: 12 }

      Wed Feb 2 02:45:40 [conn22050] warning: chunk is larger than 209715200 bytes because of key

      { accId: 686, sId: 14 }

      Wed Feb 2 02:45:40 [conn22050] Finding the split vector for sd.processes over

      { accId: 1.0, sId: 1.0 }

      keyCount: 5109 numSplits: 1 took 6784 ms.
      Wed Feb 2 02:45:40 [conn22050] query admin.$cmd ntoreturn:1 command: { splitVector: "sd.processes", keyPattern:

      { accId: 1.0, sId: 1.0 }

      , min:

      { accId: 686, sId: 12 }

      , max:

      { accId: 686, sId: 15 }

      , maxChunkSizeBytes: 209715200, maxSplitPoints: 2, maxChunkObjects: 250000 } reslen:97 6784ms
      Wed Feb 2 02:45:44 [conn5070] query admin.$cmd ntoreturn:1 command:

      { writebacklisten: ObjectId('4d455a0a8e59ae581439ccb3') }

      reslen:60 300035ms
      Wed Feb 2 02:45:48 [conn602] query admin.$cmd ntoreturn:1 command:

      { writebacklisten: ObjectId('4d45820e134e08aea1fe96e0') }

      reslen:60 300034ms
      Wed Feb 2 02:45:49 [conn21170] insert sd.metrics 247ms
      Wed Feb 2 02:45:49 [conn22791] insert sd.metrics 129ms
      Wed Feb 2 02:45:49 [conn23051] insert sd.metrics 146ms
      Wed Feb 2 02:45:49 [conn2293] query sd.$cmd ntoreturn:1 command: { count: "sessions", query: {} } reslen:64 193ms
      Wed Feb 2 02:45:50 [conn16731] insert sd.metrics 171ms
      Wed Feb 2 02:45:51 [conn18934] insert sd.metrics 287ms
      Wed Feb 2 02:45:51 [conn21940] insert sd.metrics 101ms
      Wed Feb 2 02:45:51 [conn19757] insert sd.metrics 131ms
      Wed Feb 2 02:45:53 [conn21164] insert sd.metrics 325ms
      Wed Feb 2 02:45:54 [conn20805] insert sd.metrics 126ms
      Wed Feb 2 02:45:56 [conn20840] insert sd.processes 338ms
      Wed Feb 2 02:45:57 [conn21635] insert sd.metrics 163ms
      Wed Feb 2 02:45:58 [conn20928] insert sd.metrics 223ms

            Assignee:
            eliot Eliot Horowitz (Inactive)
            Reporter:
            boxedice David Mytton
            Votes:
            0 Vote for this issue
            Watchers:
            0 Start watching this issue

              Created:
              Updated:
              Resolved: