Modifying msRTCSIP-UserPolicies causes logon failures. Event 41009
I want to document an issue I came across in hopes that it will save someone some pain. When modifying msRTCSIP-UserPolicies manually you may end up with a configuration which causes log on failures and is not recommended by Microsoft. The policies that are applied to a user are stored in AD in a multi-valued attribute called msRTCSIP-UserPolicies for each user.
The format of these entries is "XX:YYYYYYYYY", where XX defines the type of the policy and YYYY is a number denoting the specific policy applied for that user.
The values of XX based on my lab experiments are as following:
XX=0 - Default Policy
XX=1 - Conference Policy
XX=5 - Location Policy
XX=7 - Voice Policy
XX=9 - Dial plan policy
XX=11 - Client Version Policy
XX=13 - Client Policy
XX=15 - Archiving Policy
XX=19 - PIN Policy
XX=21 - External Access Policy
Each user has a default policy associated with their account, therefore msRTCSIP-UserPolicies for every user will have an entry of 0=<random number>.
If we use the table above to analyze Molly's account (screenshot below) we can figure out that the user Molly has a 'External Access Policy' and a 'Client policy' applied along with the default policy.
Why is this important? Or how can modifying this cause problems? I came across a case where the customer used a VBScript to update the External access policy for all users to "21=9" instead of using Lync Server Management Shell or Lync Server Control Panel. The logic of the script was to modify each Lync enabled user's msRTCSIP-UserPolicies to remove "21=8" and add "21=9". The problem was that some of the users had a different policy applied to them, policy with value "21=4" and when the script ran it added "21=9" to those users account along with "21=4". This left the user's account in an inconsistent state, where they had two policies assigned for controlling the same functionality (External User Access).
To test the theory in our labs, I just added another entry in the msRTCSIP-UserPolicies for External Access Policy when one already existed.
[The existing policy was 21=1 and I added 21=2 manually]
After adding a duplicate entry I attempted to sign-out from the already signed-in client the following error was logged:
Log Name: Lync Server
Source: LS Client Version Filter
Date: 8/25/2012 6:20:00 AM
Event ID: 41009
Task Category: (1041)
Level: Warning
Keywords: Classic
User: N/A
Computer: LyncSE-FE.tailspintoys.com
Description:
Exception occurred while processing request.
Method: UNKNOWN Exception: An item with the same key has already been added.
Exception Type: System.ArgumentException
Stack Trace:
at System.Collections.Generic.Dictionary`2.Insert(TKey key, TValue value, Boolean add)
at Microsoft.Rtc.Management.ServiceConsumer.PolicyScopeContext.PolicyAssignments.Parse(String policyAssignmentData)
at Microsoft.Rtc.Management.ServiceConsumer.PolicyScopeContext..ctor(String policyAssignments)
at Microsoft.Rtc.Management.ServiceConsumer.PolicyReader.Read[T](String policyAssignmentData)
at Microsoft.Rtc.ClientVersionFilter.ClientVersionFilter.OnRequest(Object sender, RequestReceivedEventArgs eventArgs)
Cause: Internal error.
Resolution:
Contact Microsoft Customer Service and Support.
Event Xml:
<Event xmlns="https://schemas.microsoft.com/win/2004/08/events/event">
<System>
<Provider Name="LS Client Version Filter" />
<EventID Qualifiers="33809">41009</EventID>
<Level>3</Level>
<Task>1041</Task>
<Keywords>0x80000000000000</Keywords>
<TimeCreated SystemTime="2012-08-25T06:20:00.000000000Z" />
<EventRecordID>94037</EventRecordID>
<Channel>Lync Server</Channel>
<Computer>LyncSE-FE.tailspintoys.com</Computer>
<Security />
</System>
<EventData>
<Data>UNKNOWN</Data>
<Data>An item with the same key has already been added.</Data>
<Data>System.ArgumentException</Data>
<Data> at System.Collections.Generic.Dictionary`2.Insert(TKey key, TValue value, Boolean add)
at Microsoft.Rtc.Management.ServiceConsumer.PolicyScopeContext.PolicyAssignments.Parse(String policyAssignmentData)
at Microsoft.Rtc.Management.ServiceConsumer.PolicyScopeContext..ctor(String policyAssignments)
at Microsoft.Rtc.Management.ServiceConsumer.PolicyReader.Read[T](String policyAssignmentData)
at Microsoft.Rtc.ClientVersionFilter.ClientVersionFilter.OnRequest(Object sender, RequestReceivedEventArgs eventArgs)</Data>
</EventData>
</Event>
Under these conditions if you try to sign-in again the client seems to take a lot of time at the following screen:
And eventually errors out with the following message:
After some time the client tries again and will keep on repeating the process. Each time it fails Event 41009 is logged. Collecting ClientVersionFilter/UserServices in the Lync Logging Tool does not reveal much information and the ClientVersionFilter log is blank.
In SipStack logs the server does not respond after the client sends the final REGISTER packet [tested TLS-DSK, Kerberos and NTLM auth]:
In network traces we see an Ack+RST from the server after some time(27 Secs in the screen shot below) indicating that the server closed down the connection from the client:
The Lync Control panel, unfortunately, does not show any problems with the user's account:
Customer reported that when they try moving the user to a legacy pool they get an error similar to "An item with the same key has already been added." as well. The resolution is to simply remove the extra/duplicate entry from the user account. Once the entry is removed the user will be able to sign-in again, no changes required.
The entry which needs to be removed should be the one which was added manually, if the other entry is removed you will get an error similar to the following:
