[CSHARP-698] Shutdown occasionally failing erroneously reporting not using localhost Created: 26/Feb/13  Updated: 16/Jul/13  Resolved: 16/Jul/13

Status: Closed
Project: C# Driver
Component/s: None
Affects Version/s: 1.6
Fix Version/s: None

Type: Bug Priority: Major - P3
Reporter: John Woakes Assignee: Craig Wilson
Resolution: Cannot Reproduce Votes: 0
Labels: None
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified
Environment:

Windows Azure, C# worker role, 3 Replica set databases, no shards.


Attachments: Microsoft Word Logs.csv    

 Description   

We get this error message about 30% of the time

Command 'shutdown' failed: unauthorized: this command must run from localhost when running db without auth (response:

{ "errmsg" : "unauthorized: this command must run from localhost when running db without auth", "ok" : 0.0 }

)

We do not use authentication in the database.

This is the C# code we use to connect to the database for this command. This worked for fine when we were using an earlier version of the database.

MongoServer.Create(string.Format("mongodb://localhost:

{0}

/?slaveOk=true", MongoHostPortSetting.GetMongoHostPortSettings().Port));

This is the stack trace:

MongoDB.Driver.MongoCommandException: Command 'shutdown' failed: unauthorized: this command must run from localhost when running db without auth (response:

{ "errmsg" : "unauthorized: this command must run from localhost when running db without auth", "ok" : 0.0 }

)
at MongoDB.Driver.MongoDatabase.RunCommandAs(Type commandResultType, IMongoCommand command) in C:\work\rstam\mongo-csharp-driver\Driver\Core\MongoDatabase.cs:line 978
at MongoDB.Driver.MongoDatabase.RunCommandAs[TCommandResult](String commandName) in C:\work\rstam\mongo-csharp-driver\Driver\Core\MongoDatabase.cs:line 962
at MongoDB.Driver.MongoServer.Shutdown(MongoCredentials adminCredentials) in C:\work\rstam\mongo-csharp-driver\Driver\Core\MongoServer.cs:line 1008
at MongoWorker.WorkerRole.OnStop() in c:\Sources\iQmetrix\Service\MongoWorker\WorkerRole.cs:line 250

Because the database does not shutdown cleanly it has to do a full recovery when we bring it back up which takes quite a while.



 Comments   
Comment by Sridhar Nanjundeswaran [ 08/Mar/13 ]

What version of mongod are you running?

Comment by John Woakes [ 08/Mar/13 ]

Note: We are running version 1.6 of the C# driver [issue says 1.7]

Comment by John Woakes [ 08/Mar/13 ]

Sounds like a plan. The urgency of this issue is less now for us but it would be nice to get to the bottom of this. If you want us to test anything let me know.

Comment by Craig Wilson [ 08/Mar/13 ]

John, I move this over to a C# issue. We'll continue examining it here.

I'm very surprised that works. Basically, that starts everything over, so somewhere, the you were getting a cached connection that wasn't pointing at localhost, which means your connection pooling thought seems to be right on.

Comment by John Woakes [ 07/Mar/13 ]

Ok, we have it working now. We added MongoServer.UnregisterAllServers() before creating a localhost server and calling shutdown on it.

Comment by Craig Wilson [ 07/Mar/13 ]

That shouldn't interfere because the client settings for a replica set will be different than the ones you are using (seed list vs. loopback) and we pool based on the client settings. I'll keep poking around but good thought. I'll keep it in mind in case we have a bug in our "hashing" logic.

Comment by John Woakes [ 07/Mar/13 ]

Yes, if we RDP into one of the Azure boxes and start up Mongo.exe we can execute a shutdown.

We are wondering if it has something to do with connection pooling? We normally access the database via regular replica set connection, and only for shutdown do we fire up a new server with local host and slave=ok

Comment by Craig Wilson [ 07/Mar/13 ]

John, we are having some trouble reproducing this problem. Sridhar has attempted to replicate in Azure with vmAliases, but was unable to.

Are you able to shutdown the server from the shell?

Comment by John Woakes [ 06/Mar/13 ]

P.S. This seems to be happening every time we shutdown now.

Comment by John Woakes [ 06/Mar/13 ]

Yes we are using the vmName feature of Azure for our Mongo replica set configuration. We have for a while now.

http://msdn.microsoft.com/en-us/library/windowsazure/jj156077

Comment by Sridhar Nanjundeswaran [ 06/Mar/13 ]

I cannot reproduce in my testing. John are you using VMAlias on these nodes. That is the one item I have not tested.

Comment by John Woakes [ 05/Mar/13 ]

Running the db.isMaster() command on the first instance [Primary]

{ setName:iq,
ismaster:true,
secondary:false,
hosts:[MongoDB0:27017,
MongoDB2:27017,
MongoDB1:27017],
primary:MongoDB0:27017,
me:MongoDB0:27017,
maxBsonObjectSize:16777216,
localTime:ISODate(2013-03-05T19:14:04.127Z),
ok:1
}

Comment by John Woakes [ 05/Mar/13 ]

A bit more detail - we run 3 mongo databases in a replica set on 3 Worker Role instances [think VMs]. When Azure shuts down an instance, we run our custom shutdown code. This process does;

1) Step Down via localhost connection if Primary [use replSetGetStatus to find out]
2) Call MongoServer.Shutdown() method in the C# driver via localhost connection and slave ok.
3) Unmount the Cloud drive Mongod.exe is using to persist the database

You should see these steps in the log I attached.

It is possible that the shutdown command is always failing. I will dig into that a bit deeper and get an accurate % failure rate.

Comment by John Woakes [ 05/Mar/13 ]

These are logs of our 3 Azure Replica Set instances shutting down last night. All 3 shutdowns failed.

Comment by Craig Wilson [ 05/Mar/13 ]

Sorry about asking questions you provided in your report.

3) Can you call db.isMaster() on the server you are running? I'm specifically looking for what is returned in the "me" field.
3b) Perhaps SERVER-6591 is the culprit in this one. We have fixed this in our upcoming 2.4 release.

What has me a little confused is why this only happens every once in a while, which wouldn't be explained as above.

sridhar, do you know of anything in Azure that might cause this? When resolving the loopback address in an Azure replica set, does it resolve differently than on a normal machine?

Comment by John Woakes [ 04/Mar/13 ]

1) We are NOT using auth.
2) 1.6
3) We are running localhost on the server.
4) This is our current code:
internal static void ShutdownMongoServer()

{ var server = CreateServer(ServerConnectionType.LocalSlaveOkConnection); server.Shutdown(); }

public static MongoServer CreateServer(ServerConnectionType connectionType)
{
switch (connectionType)
{
case ServerConnectionType.LocalConnection:
return MongoServer.Create(string.Format("mongodb://

{0}:{1}", System.Net.IPAddress.Loopback, MongoHostPortSetting.GetMongoHostPortSettings().Port));

case ServerConnectionType.LocalSlaveOkConnection:
return MongoServer.Create(string.Format("mongodb://{0}

:

{1}

/?slaveOk=true", System.Net.IPAddress.Loopback, MongoHostPortSetting.GetMongoHostPortSettings().Port));

case ServerConnectionType.ReplicaSetNearestConnection:
var settings = MongoDBAzureHelper.GetReplicaSetSettings();
settings.ReadPreference = new ReadPreference(ReadPreferenceMode.Nearest);
return MongoServer.Create(settings);

case ServerConnectionType.ReplicaSetConnection:
return MongoServer.Create(MongoDBAzureHelper.GetReplicaSetSettings());
}

return null;
}

We also tried "localhost" instead of System.Net.IPAddress.Loopback but that has the same behaviour.

Comment by Craig Wilson [ 04/Mar/13 ]

Hi John,
Thanks for reporting. Couple of questions:

1) Are you using auth with your database and have you supplied credentials to the driver?
2) What version of the driver are you running?
3) Are you running from localhost or against a remote server?
4) How exactly are you calling shutdown from the driver?

Generated at Wed Feb 07 21:37:35 UTC 2024 using Jira 9.7.1#970001-sha1:2222b88b221c4928ef0de3161136cc90c8356a66.