-
Type:
Improvement
-
Resolution: Fixed
-
Priority:
Major - P3
-
Affects Version/s: None
-
Component/s: Logging
-
Labels:None
-
Fully Compatible
-
Security 2020-11-02, Security 2020-11-16, Security 2020-11-30, Security 2020-12-14, Security 2020-12-28, Security 2021-03-22, Security 2021-04-05, Security 2021-04-19, Security 2021-05-03
-
(copied to CRM)
When the server tries to (re-)authorize sessions using the slow LDAP server, this will stall all new authorizations, including those using the SCRAM mechanism.
To simplify RCA process I propose to include the new section named Authorization, for example:
Before:
2020-02-25T08:07:44.108-0800 I COMMAND [conn141] command admin.system.users appName: "MongoDB Shell" command: isMaster { isMaster: 1.0, saslSupportedMechs: "test.local852", lsid: { id: UUID("f7a3f71c-18c2-400a-8e93-4dceb8a26ccb") }, $db: "test" } numYields:0 reslen:268 locks:{ Global: { acquireCount: { r: 1 } }, Database: { acquireCount: { r: 1 } }, Collection: { acquireCount: { r: 1 } } } storage:{} protocol:op_msg 11722ms
After:
2020-02-25T08:07:44.108-0800 I COMMAND [conn141] command admin.system.users appName: "MongoDB Shell" command: isMaster { isMaster: 1.0, saslSupportedMechs: "test.local852", lsid: { id: UUID("f7a3f71c-18c2-400a-8e93-4dceb8a26ccb") }, $db: "test" } numYields:0 reslen:268 locks:{ Global: { acquireCount: { r: 1 } }, Database: { acquireCount: { r: 1 } }, Collection: { acquireCount: { r: 1 } }, Authorization: { acquireWaitCount: { r: 1 }, timeAcquiringMicros: { w: 11710012 } } } storage:{} protocol:op_msg 11722ms
Right now it's not obvious that a SCRAM authorization stalled due to the exclusive lock which was held by another session's authorization cache refresh (reaching out to the LDAP server and waiting for a response) - unless server has debug logging enabled.
- is documented by
-
DOCS-14398 [SERVER] Log time spent waiting for an authorization lock in the locks section
-
- Closed
-
- related to
-
-
- Closed
-