[ReplicaSetMonitorWatcher] ERROR: MessagingPort::call() wrong id

[Michael Conigliaro]

Does anyone know what this message in a replica set means? I started
seeing this on 3/4 of my replica sets last night. I had to restart
MongoDB to make the errors go away. This is on Ubuntu with the 1.8.0
packages.

Fri Apr 1 14:46:53 [ReplicaSetMonitorWatcher] ERROR:
MessagingPort::call() wrong id got:5d9a0233 expect:5d9a0241
toSend op: 2004
response msgid:1757333549
response len: 258
response op: 1
farEnd: 10.218.53.195:27018
Fri Apr 1 14:46:53 [ReplicaSetMonitorWatcher] Assertion failure
false util/message.cpp 512
0x5512de 0x562ce1 0x55cb3e 0x55dc24 0x57d414 0x59b870 0x57e91a
0x58dc71 0x589dcc 0x58c37c 0x57bc05 0x591a78 0x5924be 0x5926a2
0x592904 0x5984b5 0x5457eb 0x5470a4 0x8b92d0 0x7f60a0ee
c9ca
/usr/bin/mongod(_ZN5mongo12sayDbContextEPKc+0xae) [0x5512de]
/usr/bin/mongod(_ZN5mongo8assertedEPKcS1_j+0x111) [0x562ce1]
/usr/bin/mongod(_ZN5mongo13MessagingPort4recvERKNS_7MessageERS1_
+0x32e) [0x55cb3e]
/usr/bin/mongod(_ZN5mongo13MessagingPort4callERNS_7MessageES2_+0x34)
[0x55dc24]
/usr/bin/
mongod(_ZN5mongo18DBClientConnection4callERNS_7MessageES2_bPSs+0x34)
[0x57d414]
/usr/bin/mongod(_ZN5mongo14DBClientCursor4initEv+0x150) [0x59b870]
/usr/bin/
mongod(_ZN5mongo12DBClientBase5queryERKSsNS_5QueryEiiPKNS_7BSONObjEii
+0x32a) [0x57e91a]
/usr/bin/
mongod(_ZN5mongo18DBClientConnection5queryERKSsNS_5QueryEiiPKNS_7BSONObjEii
+0xa1) [0x58dc71]
/usr/bin/
mongod(_ZN5mongo17DBClientInterface7findOneERKSsRKNS_5QueryEPKNS_7BSONObjEi
+0x7c) [0x589dcc]
/usr/bin/
mongod(_ZN5mongo20DBClientWithCommands10runCommandERKSsRKNS_7BSONObjERS3_i
+0x8c) [0x58c37c]
/usr/bin/
mongod(_ZN5mongo20DBClientWithCommands8isMasterERbPNS_7BSONObjE+0x75)
[0x57bc05]
/usr/bin/
mongod(_ZN5mongo17ReplicaSetMonitor16_checkConnectionEPNS_18DBClientConnectionERSsb
+0x88) [0x591a78]
/usr/bin/mongod(_ZN5mongo17ReplicaSetMonitor6_checkEv+0x13e)
[0x5924be]
/usr/bin/mongod(_ZN5mongo17ReplicaSetMonitor5checkEv+0x62) [0x5926a2]
/usr/bin/mongod(_ZN5mongo17ReplicaSetMonitor8checkAllEv+0x234)
[0x592904]
/usr/bin/mongod(_ZN5mongo24ReplicaSetMonitorWatcher3runEv+0x15)
[0x5984b5]
/usr/bin/
mongod(_ZN5mongo13BackgroundJob7jobBodyEN5boost10shared_ptrINS0_9JobStatusEEE
+0x12b) [0x5457eb]
/usr/bin/
mongod(_ZN5boost6detail11thread_dataINS_3_bi6bind_tIvNS_4_mfi3mf1IvN5mongo13BackgroundJobENS_10shared_ptrINS7_9JobStatusEEEEENS2_5list2INS2_5valueIPS7_EENSD_ISA_EEEEEEE3runEv
+0x74) [0x5470a4]
/usr/bin/mongod(thread_proxy+0x80) [0x8b92d0]
/lib/libpthread.so.0(+0x69ca) [0x7f60a0eec9ca]

[Scott Hernandez]

This error message is just saying that the request-id and the
response-id were not the same for the query (op:2004).

If this is random it could indicate network hiccups. Did you have any
network errors at the same time?

If this pops up again can you post the logs from the replicas for that
time in a new jira issue?

> --
> You received this message because you are subscribed to the Google Groups "mongodb-user" group.
> To post to this group, send email to mongod...@googlegroups.com.
> To unsubscribe from this group, send email to mongodb-user...@googlegroups.com.
> For more options, visit this group at http://groups.google.com/group/mongodb-user?hl=en.
>
>

[Michael Conigliaro]

I don't know if there was a network hiccup, but it's possible. This
happened in the middle of the night on a bunch of EC2 instances. This
message was seen every few seconds on the masters. Approximately 7
minutes after this started, I see a message in the slave like this:

Fri Apr 1 06:57:18 [ReplSetHealthPollTask] replSet info
mongodb04.example.com:27018 is down (or slow to respond):
DBClientBase::findOne: transport error: 10.115.30.111:27018 query:
{ ping: 1 }
Fri Apr 1 06:57:18 [rs Manager] replSet info electSelf 1
Fri Apr 1 06:57:18 [rs Manager] replSet PRIMARY

So failover *seemed* to work from the point of view of the servers/.
However, I still saw tons of these (several per second) in the
mongos.log:

Fri Apr 1 06:51:22 [conn2493] ERROR: MessagingPort::call() wrong id
got:ddb88f69 expect:ddb88f81
Fri Apr 1 06:51:22 [conn2493] Assertion failure false util/
message.cpp 512

From this point, my apps could not seem to connect to the mongo
routers until I restarted them. The java driver was just throwing all
kinds of exceptions about not being able to find a master:

com.mongodb.MongoException: socket exception

com.mongodb.MongoException: not talking to master and retries used up

com.mongodb.MongoException: ReplicaSetMonitor no master found for set:
1

com.mongodb.MongoException: setShardVersion failed! { "errmsg" : "not
master", "ok" : 0 }

- Mike

[Eliot Horowitz]

This is almost definitely the bug that was just fixed for 1.8.1-rc1.
You may want to try that if it happens again.

On Fri, Apr 1, 2011 at 11:56 AM, Michael Conigliaro