Collection rename didn't get reflected to replication slaves?

[Roy Smith]

We've got three servers (all running 1.8.3) set up in a replica set.
db1a is the master, db1b and db1c are (currently) the slaves. I
needed to move a collection from one database to another. I did that
by executing (in python):

mongo = pymongo.Connection('dba1.songza.com')
mongo.admin.command("renameCollection", "stations.stations",
to="songza.stations")

It looks like the collection only got renamed on the master, and
didn't propagate to the slaves! If I look at the live databases with
this script:

-----------------------------------------------------------------
#!/usr/bin/env
python

import pymongo

a = pymongo.Connection('db1a.songza.com')
b = pymongo.Connection('db1b.songza.com', slave_okay=True)
c = pymongo.Connection('db1c.songza.com', slave_okay=True)

for db in [a, b, c]:
print db.host, db.songza.stations.count(),
db.stations.stations.count()
-----------------------------------------------------------------

I get:

./stations.py
db1a.songza.com 1356279 0
db1b.songza.com 289 1355991
db1c.songza.com 289 1355991

The rename was done about a week ago, so I don't think I'm looking at
replication lag. Did I just not understand how renameCollection is
suposed to work, or is this a bug in replica sets?

[Eliot Horowitz]

Just tried this on 1.8.3 and it seems ok.
Can you do an rs.status() on each of the nodes, and send the logs?

> --
> 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.
>
>

[Roy Smith]

On Nov 20, 12:59 am, Eliot Horowitz <el...@10gen.com> wrote:
> Just tried this on 1.8.3 and it seems ok.
> Can you do an rs.status() on each of the nodes, and send the logs?

We ended up rebuilding the slaves from the master, and now everything
is consistent. We do have some more of these migrations to perform in
the near future. If I see the same problem again, I'll grab the
rs.status() data and post it here.

I gather from your comment that the procedure we used is correct?

[Roy Smith]

It turns out, we can reproduce this. I created a small test database
with a collection, and tried to rename it:

mongo = pymongo.Connection('db1a.songza.com')
mongo.admin.command("renameCollection",
"test1.stuff",
to="test2.stuff")

when I print the collection sizes in the various replicas:

a = pymongo.Connection('db1a.songza.com')
b = pymongo.Connection('db1b.songza.com', slave_okay=True)
c = pymongo.Connection('db1c.songza.com', slave_okay=True)
for db in [a, b, c]:

print db.host, db.test1.stuff.count(), db.test2.stuff.count(

I get

db1a.songza.com 0 1000
db1b.songza.com 1000 1
db1c.songza.com 1000 1

Here's the output of rs.status() on the three instances. Let me know
if there's anything else I can get you.

Script started on Sun 20 Nov 2011 08:04:57 PM UTC
0;roy@dev1: ~/play/replicate01;32mroy@dev100m:01;34m~/play/replicate00m
$ mongo db1a.songza.oKcom
MongoDB shell version: 1.8.3
fork() available!
connecting to: db1a.songza.com/test
songza:PRIMARY> rs.status()
{
"set" : "songza",
"date" : ISODate("2011-11-20T20:05:14Z"),
"myState" : 1,
"members" : [
{
"_id" : 4,
"name" : "db1a.songza.com",
"health" : 1,
"state" : 1,
"stateStr" : "PRIMARY",
"optime" : {
"t" : 1321819514000,
"i" : 18
},
"optimeDate" : ISODate("2011-11-20T20:05:14Z"),
"self" : true
},
{
"_id" : 5,
"name" : "db1b.songza.com",
"health" : 1,
"state" : 2,
"stateStr" : "SECONDARY",
"uptime" : 57677,
"optime" : {
"t" : 1321819512000,
"i" : 3
},
"optimeDate" : ISODate("2011-11-20T20:05:12Z"),
"lastHeartbeat" : ISODate("2011-11-20T20:05:13Z")
},
{
"_id" : 6,
"name" : "db1c.songza.com",
"health" : 1,
"state" : 2,
"stateStr" : "SECONDARY",
"uptime" : 57673,
"optime" : {
"t" : 1321819512000,
"i" : 3
},
"optimeDate" : ISODate("2011-11-20T20:05:12Z"),
"lastHeartbeat" : ISODate("2011-11-20T20:05:13Z")
}
],
"ok" : 1
}
songza:PRIMARY> bye
0;roy@dev1: ~/play/replicate01;32mroy@dev100m:01;34m~/play/replicate00m
$ mongo db1P1P1b.songza.com
MongoDB shell version: 1.8.3
fork() available!
connecting to: db1b.songza.com/test
songza:SECONDARY> rs.slaveOk()
songza:SECONDARY> rs.status()
{
"set" : "songza",
"date" : ISODate("2011-11-20T20:05:29Z"),
"myState" : 2,
"members" : [
{
"_id" : 4,
"name" : "db1a.songza.com",
"health" : 1,
"state" : 1,
"stateStr" : "PRIMARY",
"uptime" : 57694,
"optime" : {
"t" : 1321819528000,
"i" : 1
},
"optimeDate" : ISODate("2011-11-20T20:05:28Z"),
"lastHeartbeat" : ISODate("2011-11-20T20:05:28Z")
},
{
"_id" : 5,
"name" : "db1b.songza.com",
"health" : 1,
"state" : 2,
"stateStr" : "SECONDARY",
"optime" : {
"t" : 1321819528000,
"i" : 8
},
"optimeDate" : ISODate("2011-11-20T20:05:28Z"),
"self" : true
},
{
"_id" : 6,
"name" : "db1c.songza.com",
"health" : 1,
"state" : 2,
"stateStr" : "SECONDARY",
"uptime" : 57688,
"optime" : {
"t" : 1321819528000,
"i" : 6
},
"optimeDate" : ISODate("2011-11-20T20:05:28Z"),
"lastHeartbeat" : ISODate("2011-11-20T20:05:28Z")
}
],
"ok" : 1
}
songza:SECONDARY> bye
0;roy@dev1: ~/play/replicate01;32mroy@dev100m:01;34m~/play/replicate00m
$ mongo db11Pc.songza.com
MongoDB shell version: 1.8.3
fork() available!
connecting to: db1c.songza.com/test
songza:SECONDARY> rs.slaveOk()
songza:SECONDARY> rs.status
function () { return db._adminCommand("replSetGetStatus"); }
songza:SECONDARY> rs.status()
{
"set" : "songza",
"date" : ISODate("2011-11-20T20:05:41Z"),
"myState" : 2,
"members" : [
{
"_id" : 4,
"name" : "db1a.songza.com",
"health" : 1,
"state" : 1,
"stateStr" : "PRIMARY",
"uptime" : 57701,
"optime" : {
"t" : 1321819538000,
"i" : 7
},
"optimeDate" : ISODate("2011-11-20T20:05:38Z"),
"lastHeartbeat" : ISODate("2011-11-20T20:05:39Z")
},
{
"_id" : 5,
"name" : "db1b.songza.com",
"health" : 1,
"state" : 2,
"stateStr" : "SECONDARY",
"uptime" : 57701,
"optime" : {
"t" : 1321819540000,
"i" : 4
},
"optimeDate" : ISODate("2011-11-20T20:05:40Z"),
"lastHeartbeat" : ISODate("2011-11-20T20:05:41Z")
},
{
"_id" : 6,
"name" : "db1c.songza.com",
"health" : 1,
"state" : 2,
"stateStr" : "SECONDARY",
"optime" : {
"t" : 1321819540000,
"i" : 4
},
"optimeDate" : ISODate("2011-11-20T20:05:40Z"),
"self" : true
}
],
"ok" : 1
}
songza:SECONDARY> bye
0;roy@dev1: ~/play/replicate01;32mroy@dev100m:01;34m~/play/replicate00m
$ exit

Script done on Sun 20 Nov 2011 08:05:45 PM UTC

[Roy Smith]

Here's something else weird.

$ mongo db1b.songza.com

MongoDB shell version: 1.8.3
fork() available!
connecting to: db1b.songza.com/test
songza:SECONDARY> rs.slaveOk()

songza:SECONDARY> use test2
switched to db test2
songza:SECONDARY> db.stuff.find()
error: {
"_id" : ObjectId("4ec95bef7c52a3304047eee5"),
"$err" : "not master and slaveok=false",
"code" : 13435
}

I ran slaveOk(), but it still tells me slaveok=false.

[Eliot Horowitz]

Ah - different dbs.

Its working on the same db, not across dbs.

Added a case: https://jira.mongodb.org/browse/SERVER-4332