[SERVER-5381] MongoDB Server(ReplicaSet Secondary) remains in state 3(Recovering) after runCommand("compact") on a nonexisting collection. Created: 23/Mar/12  Updated: 24/May/12  Resolved: 24/May/12

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

Type: Bug Priority: Major - P3
Reporter: Guido krömer Assignee: Adam Comerford
Resolution: Won't Fix Votes: 0
Labels: replication
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified
Environment:

[root@dev-db ~]# uname -a
Linux dev-db 2.6.18-194.26.1.el5 #1 SMP Tue Nov 9 12:54:20 EST 2010 x86_64 x86_64 x86_64 GNU/Linux
RECOVERING> db.version()
2.0.2


Operating System: Linux
Participants:

 Description   

The in the summary described behavior happed on a production server, but we could reproduce ist on our development server, too.

I logged in to the secondary server:
SECONDARY> rs.slaveOk()
SECONDARY> show dbs
blablub 0.203125GB
hm 0.203125GB
hm_history 0.953125GB
hm_idealo 0.203125GB
hm_logs 2.2021484375GB
hm_solr 0.203125GB
hm_tracking 9.94921875GB
hmdev 0.203125GB
local 10.1982421875GB
sequences 0.203125GB
test 0.203125GB
tests 0.203125GB

Switched to hm_history database:
SECONDARY> use hm_history

Then started the compact command on two existing collections;
SECONDARY> db.pricehistory_2010.runCommand("compact")

{ "ok" : 1 }

RECOVERING>
SECONDARY> db.pricehistory_2011.runCommand("compact")

{ "ok" : 1 }

Until this step everyting runs fine, but after running a command on a collection wich does not exists the server remains in state recovering. Our production server remained in this state for 5 hours, so that we needed to restart the service.

RECOVERING> db.dffsdfsf23422eqw.runCommand("compact")
{
"assertion" : "namespace hm_history.pricehisto does not exist",
"assertionCode" : 13660,
"errmsg" : "db assertion failure",
"ok" : 0
}
RECOVERING>
RECOVERING>
RECOVERING>
RECOVERING>

Output from rs.Status:
RECOVERING> rs.status()
{
"set" : "hmdev",
"date" : ISODate("2012-03-23T13:47:03Z"),
"myState" : 3,
"syncingTo" : "devdb.hitmeister.intern:27017",
"members" : [
{
"_id" : 0,
"name" : "devdb.hitmeister.intern:27017",
"health" : 1,
"state" : 1,
"stateStr" : "PRIMARY",
"uptime" : 2238,
"optime" :

{ "t" : 1332508210000, "i" : 2 }

,
"optimeDate" : ISODate("2012-03-23T13:10:10Z"),
"lastHeartbeat" : ISODate("2012-03-23T13:47:02Z"),
"pingMs" : 0
},
{
"_id" : 1,
"name" : "devdb.hitmeister.intern:27018",
"health" : 1,
"state" : 3,
"stateStr" : "RECOVERING",
"optime" :

{ "t" : 1332508210000, "i" : 2 }

,
"optimeDate" : ISODate("2012-03-23T13:10:10Z"),
"self" : true
}
],
"ok" : 1
}



 Comments   
Comment by Guido krömer [ 23/May/12 ]

Thanks for your advices!

Comment by Adam Comerford [ 18/May/12 ]

Confirmed as still happening in 2.0.5, however, subsequently running a compact on an existing collection does return the secondary to its normal stats. So, as a workaround, just run compact on an actual collection to resolve the issue.

SECONDARY> db.bar.runCommand("compact");
{ "ok" : 1 }
RECOVERING> 
SECONDARY> 
SECONDARY> db.barr.runCommand("compact");
{
	"assertion" : "namespace test.barr does not exist",
	"assertionCode" : 13660,
	"errmsg" : "db assertion failure",
	"ok" : 0
}
RECOVERING> rs.status()
{
	"set" : "testing",
	"date" : ISODate("2012-05-18T14:40:42Z"),
	"myState" : 3,
	"syncingTo" : "mbp.local:30001",
	"members" : [
		{
			"_id" : 0,
			"name" : "mbp.local:30001",
			"health" : 1,
			"state" : 1,
			"stateStr" : "PRIMARY",
			"uptime" : 3348,
			"optime" : {
				"t" : 1337280275000,
				"i" : 9
			},
			"optimeDate" : ISODate("2012-05-17T18:44:35Z"),
			"lastHeartbeat" : ISODate("2012-05-18T14:40:40Z"),
			"pingMs" : 0
		},
		{
			"_id" : 1,
			"name" : "mbp.local:30002",
			"health" : 1,
			"state" : 2,
			"stateStr" : "SECONDARY",
			"uptime" : 3348,
			"optime" : {
				"t" : 1337280275000,
				"i" : 9
			},
			"optimeDate" : ISODate("2012-05-17T18:44:35Z"),
			"lastHeartbeat" : ISODate("2012-05-18T14:40:40Z"),
			"pingMs" : 0
		},
		{
			"_id" : 2,
			"name" : "mbp.local:30003",
			"health" : 1,
			"state" : 3,
			"stateStr" : "RECOVERING",
			"optime" : {
				"t" : 1337280275000,
				"i" : 9
			},
			"optimeDate" : ISODate("2012-05-17T18:44:35Z"),
			"self" : true
		}
	],
	"ok" : 1
}
RECOVERING> db.bar.runCommand("compact");
{ "ok" : 1 }
RECOVERING> 
SECONDARY> rs.status()
{
	"set" : "testing",
	"date" : ISODate("2012-05-18T14:40:49Z"),
	"myState" : 2,
	"syncingTo" : "mbp.local:30001",
	"members" : [
		{
			"_id" : 0,
			"name" : "mbp.local:30001",
			"health" : 1,
			"state" : 1,
			"stateStr" : "PRIMARY",
			"uptime" : 3355,
			"optime" : {
				"t" : 1337280275000,
				"i" : 9
			},
			"optimeDate" : ISODate("2012-05-17T18:44:35Z"),
			"lastHeartbeat" : ISODate("2012-05-18T14:40:48Z"),
			"pingMs" : 0
		},
		{
			"_id" : 1,
			"name" : "mbp.local:30002",
			"health" : 1,
			"state" : 2,
			"stateStr" : "SECONDARY",
			"uptime" : 3355,
			"optime" : {
				"t" : 1337280275000,
				"i" : 9
			},
			"optimeDate" : ISODate("2012-05-17T18:44:35Z"),
			"lastHeartbeat" : ISODate("2012-05-18T14:40:48Z"),
			"pingMs" : 0
		},
		{
			"_id" : 2,
			"name" : "mbp.local:30003",
			"health" : 1,
			"state" : 2,
			"stateStr" : "SECONDARY",
			"optime" : {
				"t" : 1337280275000,
				"i" : 9
			},
			"optimeDate" : ISODate("2012-05-17T18:44:35Z"),
			"self" : true
		}
	],
	"ok" : 1
}
 

Comment by Adam Comerford [ 17/May/12 ]

FYI, testing in the 2.1.1 release, this appears to be fixed:

use foo
switched to db foo
foo:SECONDARY> db.foo.runCommand("compact")
{ "ok" : 1 }
foo:RECOVERING> 
foo:SECONDARY> db.bar.runCommand("compact")
{ "errmsg" : "namespace does not exist", "ok" : 0 }
foo:RECOVERING> 
foo:SECONDARY> 

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