[SERVER-6549] The correct password may auth fail occasionally. Created: 21/Jul/12  Updated: 11/Jul/16  Resolved: 26/Jul/12

Status: Closed
Project: Core Server
Component/s: Security
Affects Version/s: 2.2.0-rc0
Fix Version/s: 2.2.0-rc1

Type: Bug Priority: Major - P3
Reporter: NOVALUE yangfenqiang Assignee: Spencer Brody (Inactive)
Resolution: Done Votes: 0
Labels: connection
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified
Environment:

Ubuntu 12.04 LTS
Linux yz-uc-core-a08 3.2.0-23-generic #36-Ubuntu SMP Tue Apr 10 20:39:51 UTC 2012 x86_64 x86_64 x86_64 GNU/Linux


Attachments: Text File auth.log     File cleanlog.rar     File testAuth.cc    
Operating System: Linux
Participants:

 Description   

I have to use "while" for a connection auth, because some ratio to auth fail by using the same correct password.

My code:
while (!conn.auth("admin", write_mongos_primary.usr, write_mongos_primary.pwd, errmsg, false)) {
WriteLog(kLogWarning, "[PhoneImport] auth failed: %s.", errmsg.c_str());
}

App program log:
WARNING: 07-21 01:34:35 [PhoneImport] auth failed: { errmsg: "exception: SyncClusterConnection::insert prepare failed: 192.168.130.14:9001:

{ errmsg: "need to login", ok: 0.0 }

192.168.130.15:9001:

{ errmsg: "need...", code: 8003, ok: 0.0 }

.

config mongod 1(192.168.130.14:9001) log:
Sat Jul 21 01:34:25 [conn122] CMD fsync: sync:1 lock:0
Sat Jul 21 01:34:35 [conn2] end connection 192.168.130.14:11766 (96 connections now open)
Sat Jul 21 01:34:38 [conn54] CMD fsync: sync:1 lock:0

config mongod 2(192.168.130.15:9001) log:
Sat Jul 21 01:34:25 [conn122] CMD fsync: sync:1 lock:0
Sat Jul 21 01:34:25 [conn106] CMD fsync: sync:1 lock:0
Sat Jul 21 01:34:35 [conn2] end connection 192.168.130.14:4131 (96 connections now open)
Sat Jul 21 01:34:38 [conn54] CMD fsync: sync:1 lock:0
Sat Jul 21 01:34:38 [conn42] CMD fsync: sync:1 lock:0

mongos locate on 192.168.130.14



 Comments   
Comment by auto [ 26/Jul/12 ]

Author:

{u'date': u'2012-07-26T08:42:27-07:00', u'email': u'spencer@10gen.com', u'name': u'Spencer T Brody'}

Message: SERVER-6549. Use internal permissions when ensuring index in authenticate command
Branch: master
https://github.com/mongodb/mongo/commit/3e23612e277d68903f36a262c350b5512fcd5440

Comment by Spencer Brody (Inactive) [ 25/Jul/12 ]

Thank you for attaching the new logs and simplified test file, that's really helpful. I noticed there are always 15 successful attempts before a failed attempt, and at every timestamp where there is a failed attempt there is a message in the mongos log that looks like "scoped connection to 192.168.130.14:9001,192.168.130.15:9001,192.168.130.16:9001 not being returned to the pool". I'm going to take a look at the mongos code and continue investigating. Thanks for your help bringing this issue to our attention!

Comment by NOVALUE yangfenqiang [ 24/Jul/12 ]

Hi, Spencer:
I restart a mongodb cluster in order to get a more clean logs for auth test.
Attached files are the tiny full mongodb logs, my test program testAuth.cc and its log.

Comment by Spencer Brody (Inactive) [ 23/Jul/12 ]

I don't see any auth failure messages in the logs you attached, are you certain they're from a run that failed?

Comment by NOVALUE yangfenqiang [ 23/Jul/12 ]

The full mongos and config server log is added.

Comment by NOVALUE yangfenqiang [ 23/Jul/12 ]

Simple code for test auth. id.exe run same para ("./id.exe 36308763") two times, but one auth failed.

yz-uc-core-a04$ ./id.exe 98203809
uid:98203809
{}
yz-uc-core-a04$ ./id.exe 98471709
uid:98471709
{}
yz-uc-core-a04$ ./id.exe 74423418
uid:74423418
{}
yz-uc-core-a04$ ./id.exe 36308763
auth failed.{ errmsg: "exception: SyncClusterConnection::insert prepare failed: 192.168.130.14:9001:

{ errmsg: "need to login", ok: 0.0 }

192.168.130.15:9001:

{ errmsg: "need...", code: 8003, ok: 0.0 }

uid:36308763
terminate called after throwing an instance of 'mongo::UserException'
what(): nextSafe():

{ $err: "unauthorized for db:user level: 1", code: 15845 }

Aborted (core dumped)
yz-uc-core-a04$ ./id.exe 36308763
uid:36308763

{ _id: 842454605331302171, uname: "linhaibo301", pwd: 7453393081496482441, email: "jhn001@126.com", phone: 18250341448, tel: "0", nick: "林海波", photo: 1299464260, lcid: 75, sex: 0, email_t: 1321859812, phone_t: 1321868871, t: 1298360383, mt: 1328084329 }

yz-uc-core-a04$ ./id.exe 124381883
uid:124381883

{ _id: 3300575577033534139, uname: "景格里嬿西", pwd: 3417520175039819775, lcid: 56, sex: 1, t: 1342201474, mt: 1342201659 }
Comment by Spencer Brody (Inactive) [ 23/Jul/12 ]

Do you have a test case than can reproduce the problem?

Does it only happen with users on the admin database, or does it happen on other databases as well?

Does it only happen after adding a new user, or does it also happen to users that have been around for a long time?

After authenticating successfully as a given user once, will you ever see the problem resurface with the same user?

Can you attach the full mongos and config server logs from a run of this that includes the auth failures?

Comment by NOVALUE yangfenqiang [ 21/Jul/12 ]

The same program has never auth failed with mongod version 2.0.6.
When I update to 2.20-rc0, this case happened occasionally.

Comment by NOVALUE yangfenqiang [ 21/Jul/12 ]

sorry, Affects Version/s is 2.2.0-rc0

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