Tuesday, December 10, 2019

Client-side fix: Cisco AnyConnect reconnects every few minutes

TL;DR If Cisco AnyConnect is disconnecting, reconnecting every few minutes, try blocking UDP in/out ports for the vpnagent executable/service.

Cisco AnyConnect Secure Mobility Client version 4.7.04056

This one drove me nuts for the longest time until I found time to dedicate to troubleshooting it myself. Symptoms were that my AnyConnect client had been disconnecting, reconnecting every few minutes (2:50 to be exact!), which would, in turn, timeout my RDP session. Total reconnect time was only a few seconds, but you can imagine how having your concentration broken every three minutes is a productivity killer!

I had troubleshot this with my ISP, Comcast/Xfinity and my customer (whose site I was connecting to via VPN). Both essentially were pointing fingers at each other. It would be easy to blame the ISP because the problem didn't happen over my hotspot, but I can't help but think that the VPN server wasn't configured to properly handle such situations. Anyway, I decided to live with it (for far too long) until I could do some troubleshooting myself and figure out next steps.

My troubleshooting steps are below, in case anyone is interested.

Wireshark

Wireshark VPN test-2019-12-09-A.pcapng

Wireshark VPN test-2019-12-09-G-Comcast.pcapng

Wireshark VPN test-2019-12-09-F-Hotspot.pcapng

Wireshark VPN test-2019-12-09-E-Comcast-Reconnect at 129 sec.pcapng

Wireshark VPN test-2019-12-09-D-Hotspot.pcapng

Wireshark VPN test-2019-12-09-C-Comcast-Reconnect at 91 sec.pcapng

Wireshark VPN test-2019-12-09-B.pcapng

Noticed that most application traffic happens via DTLS (OpenSSL) over UDP, but every 20 seconds, there's a TLSv1.2 transmission from the client [PSH, ACK], but no response from the server.  Client retransmits the [PSH, ACK] in intervals of 0.3, 0.6, 1.2, 2.4, 4.8, 9.6 seconds, and then sends a RST.

Google search

cisco vpn client tls every 20 seconds no ack

https://community.cisco.com/t5/vpn-and-anyconnect/anyconnect-vpn-session-disconnect-and-reconnect/td-p/2474657

Article above references this, which was the most helpful

https://www.cisco.com/c/en/us/support/docs/security/anyconnect-secure-mobility-client/116881-technote-anyconnect-00.html

As long as DTLS is enabled, the client applies the DTLS MTU (in this case 1418) on the VPN adapter (which is enabled before the DTLS tunnel is established and is needed for routes/filters enforcement), to ensure optimum performance. If the DTLS tunnel cannot be established or it is dropped at some point, the client fails over to TLS and adjusts the MTU on the virtual adapter (VA) to the TLS MTU value (this requires a session level reconnect).

Block UDP (in & out) for VPN client in Windows Firewall

C:\Program Files (x86)\Cisco\Cisco AnyConnect Secure Mobility Client\vpnagent.exe

 

Sunday, December 23, 2018

Database upgrade failure FIM 2010 R2 4.1.3766.0 to MIM 2016 RTM 4.3.0.0 (4.3.1935.0)

Johnny-come-lately here. I ran into the same problem that others have while upgrading from FIM to MIM. You can find the references below; they refer to a download for a Microsoft.IdentityManagement.DatabaseUpgrade.exe.config file. However, I couldn't find a link to actually download the file, so I did a bit of forensics and compared the config file from the SP1 update to that from RTM. I merged the relevant parts and BANG!, the installation succeeded. To save everyone else the trouble, here are the before and after files; and my relevant installation notes are below.

Cheers & happy holidays!

Microsoft.IdentityManagement.DatabaseUpgrade.exe-MIM2016RTM.config

Microsoft.IdentityManagement.DatabaseUpgrade.exe-FIXED.config

Error while running setup for Service and Portal
Installing Microsoft Identity Manager Service and Portal

There is a problem with this Windows Installer package. A program run as part of the setup did not finish as expected Contact your support personnel or package vendor.


Run MSI with logging
set datetime=%date:~-4%-%date:~-10,2%-%date:~-7,2%_%time:~0,2%-%time:~3,2%-%time:~6,2%
msiexec /i "E:\Service and Portal\Service and Portal.msi" /L*V "D:\Install\Service and Portal.msi-%datetime%.log"

Check error log
"D:\Install\Service and Portal.msi-2018-12-22_18-17-12.log"
MSI (s) (60:5C) [18:20:53:410]: Executing op: CustomActionSchedule(Action=UpgradeDatabase,ActionType=1042,Source=C:\Program Files\Microsoft Forefront Identity Manager\2010\Service\Microsoft.IdentityManagement.DatabaseUpgrade.exe,Target=/ConnectionString:"Data Source=MY-SQL-ALIAS;Initial Catalog=FIMService;Integrated Security=SSPI;Pooling=true;Connection Timeout=225" /FimServiceAccountName:"MYDOMAIN\-svc-fimsvc" /FimServiceDatabaseName:"FIMService",)

CustomAction UpgradeDatabase returned actual error code -2 (note this may not be 100% accurate if translation happened inside sandbox)

MSI (s) (60:5C) [18:21:01:739]: Note: 1: 1722 2: UpgradeDatabase 3: C:\Program Files\Microsoft Forefront Identity Manager\2010\Service\Microsoft.IdentityManagement.DatabaseUpgrade.exe 4: /ConnectionString:"Data Source=MY-SQL-ALIAS;Initial Catalog=FIMService;Integrated Security=SSPI;Pooling=true;Connection Timeout=225" /FimServiceAccountName:"MYDOMAIN\-svc-fimsvc" /FimServiceDatabaseName:"FIMService"

Error 1722. There is a problem with this Windows Installer package. A program run as part of the setup did not finish as expected. Contact your support personnel or package vendor. Action UpgradeDatabase, location: C:\Program Files\Microsoft Forefront Identity Manager\2010\Service\Microsoft.IdentityManagement.DatabaseUpgrade.exe, command: /ConnectionString:"Data Source=MY-SQL-ALIAS;Initial Catalog=FIMService;Integrated Security=SSPI;Pooling=true;Connection Timeout=225" /FimServiceAccountName:"MYDOMAIN\-svc-fimsvc" /FimServiceDatabaseName:"FIMService"

MSI (s) (60:5C) [18:21:35:553]: Product: Microsoft Identity Manager Service and Portal -- Error 1722. There is a problem with this Windows Installer package. A program run as part of the setup did not finish as expected. Contact your support personnel or package vendor. Action UpgradeDatabase, location: C:\Program Files\Microsoft Forefront Identity Manager\2010\Service\Microsoft.IdentityManagement.DatabaseUpgrade.exe, command: /ConnectionString:"Data Source=MY-SQL-ALIAS;Initial Catalog=FIMService;Integrated Security=SSPI;Pooling=true;Connection Timeout=225" /FimServiceAccountName:"MYDOMAIN\-svc-fimsvc" /FimServiceDatabaseName:"FIMService"
Copy from installation media
From
"E:\Service and Portal"

To
"D:\Install\Service and Portal"
Try this command manually
"D:\Install\Service and Portal\Program Files\Microsoft Forefront Identity Manager\2010\Service\Microsoft.IdentityManagement.DatabaseUpgrade.exe"  /ConnectionString:"Data Source=MY-SQL-ALIAS;Initial Catalog=FIMService;Integrated Security=SSPI;Pooling=true;Connection Timeout=225" /FimServiceAccountName:"MYDOMAIN\-svc-fimsvc" /FimServiceDatabaseName:"FIMService"

Check trace log
"D:\Install\Service and Portal\Program Files\Microsoft Forefront Identity Manager\2010\Service\Microsoft.IdentityManagement.DatabaseUpgrade_tracelog.txt"
Microsoft.ResourceManagement Verbose: 0 : --********************************************************
--*                
    DateTime=2018-12-23T03:02:53.7616813Z
Microsoft.ResourceManagement Verbose: 0 : Execute SQL : The following sql statement failed.
 --********************************************************
--*                                                      *
--*   Copyright (C) Microsoft. All rights reserved.      *
--*                                                      *
--********************************************************
CREATE PROCEDURE [fim].[GetIdentifiersFromObjectKeys]
    @objectKeyList fim.ObjectKeyListInternal READONLY
AS
BEGIN

    SELECT
        [o].[ObjectKey],
    DateTime=2018-12-23T03:02:54.0898207Z
Microsoft.ResourceManagement Verbose: 0 : Execute SQL : The transaction failed with the following errors System.Data.SqlClient.SqlException: Column, parameter, or variable #1: Cannot find data type fim.ObjectKeyListInternal.
Must declare the table variable "@objectKeyList".
Parameter or variable '@objectKeyList' has an invalid data type.
   at System.Data.SqlClient.SqlConnection.OnError(SqlException exception, Boolean breakConnection)
   at System.Data.SqlClient.TdsParser.ThrowExceptionAndWarning(TdsParserStateObject stateObj)
   at System.Dat
    DateTime=2018-12-23T03:02:54.0898207Z
Microsoft.ResourceManagement Verbose: 0 : Schema upgrade : Completed processing script file GeneratedDBUpgradeScript.sql
    DateTime=2018-12-23T03:02:54.0898207Z
Microsoft.ResourceManagement Verbose: 0 : Adding SQL Agent jobs
    DateTime=2018-12-23T03:02:54.0898207Z
Microsoft.ResourceManagement Verbose: 0 : SQL Agent jobs were added
    DateTime=2018-12-23T03:02:54.3884661Z
Microsoft.ResourceManagement Verbose: 0 : Schema upgrade: Completed with following errors.
    DateTime=2018-12-23T03:02:57.4545928Z
Microsoft.ResourceManagement Verbose: 0 : Execute SQL : The upgrade tool has rolled back.
The sql transaction running the script GeneratedDBUpgradeScript.sql failed.
 Exception: System.Data.SqlClient.SqlException: Column, parameter, or variable #1: Cannot find data type fim.ObjectKeyListInternal.
Must declare the table variable "@objectKeyList".
Parameter or variable '@objectKeyList' has an invalid data type.
   at System.Data.SqlClient.SqlConnection.OnError(SqlException exception, Boolean breakConnection)
   at System.Data.SqlClient.TdsParse
    DateTime=2018-12-23T03:02:57.4545928Z
Microsoft.ResourceManagement Error: 3 : Database upgrade : Encountered errors when upgrading the database schema.
    DateTime=2018-12-23T03:02:57.4545928Z
Check FIM version
Forefront Identity Manager 2010 R2
4.1.3766.0






Check database version
SELECT [Version]
      ,[BinaryVersion]
FROM [FIMService].[fim].[Version]
Version
BinaryVersion
1128
4.1.3766.0
Hack DatabaseUpgrade.config file
References:





Merge config file from SP1 to RTM
D:\Install\Service and Portal\Program Files\Microsoft Forefront Identity Manager\2010\Service\Microsoft.IdentityManagement.DatabaseUpgrade.exe.config

Replace this
<!-- 2001 == vNext -->
<Version Id="1122to2001" SourceVersion="1122" TargetVersion="2001">
  <SqlScripts>
    <SqlScript Id="PreProcess1122" File="NoOperation.sql" EmbeddedAsResource="true" ContinueOnError="false" Type="PreProcess" />
    <SqlScript Id="Upgrade1122" File="NoOperation.sql" EmbeddedAsResource="true" ContinueOnError="false" Type="SchemaUpgrade" />
    <SqlScript Id="PostProcess1122" File="NoOperation.sql" EmbeddedAsResource="true" ContinueOnError="false" Type="PostProcess" />
  </SqlScripts>
</Version>

With this
<Version Id="1122to1123" SourceVersion="1122" TargetVersion="1123">
  <SqlScripts>
    <SqlScript Id="PreProcess1122" File="NoOperation.sql" EmbeddedAsResource="true" ContinueOnError="false" Type="PreProcess" />
    <SqlScript Id="Upgrade1122" File="NoOperation.sql" EmbeddedAsResource="true" ContinueOnError="false" Type="SchemaUpgrade" />
    <SqlScript Id="PostProcess1122" File="NoOperation.sql" EmbeddedAsResource="true" ContinueOnError="false" Type="PostProcess" />
  </SqlScripts>
</Version>
<!-- Next 100 update blocks are reserved for future LDR1 patches-->
<Version Id="1123to1124" SourceVersion="1123" TargetVersion="1124">
  <SqlScripts>
    <SqlScript Id="PreProcess1123" File="NoOperation.sql" EmbeddedAsResource="true" ContinueOnError="false" Type="PreProcess" />
    <SqlScript Id="Upgrade1123" File="NoOperation.sql" EmbeddedAsResource="true" ContinueOnError="false" Type="SchemaUpgrade" />
    <SqlScript Id="PostProcess1123" File="NoOperation.sql" EmbeddedAsResource="true" ContinueOnError="false" Type="PostProcess" />
  </SqlScripts>
</Version>
<Version Id="1124to1125" SourceVersion="1124" TargetVersion="1125">
  <SqlScripts>
    <SqlScript Id="PreProcess1124" File="NoOperation.sql" EmbeddedAsResource="true" ContinueOnError="false" Type="PreProcess" />
    <SqlScript Id="Upgrade1124" File="NoOperation.sql" EmbeddedAsResource="true" ContinueOnError="false" Type="SchemaUpgrade" />
    <SqlScript Id="PostProcess1124" File="NoOperation.sql" EmbeddedAsResource="true" ContinueOnError="false" Type="PostProcess" />
  </SqlScripts>
</Version>
<Version Id="1125to1126" SourceVersion="1125" TargetVersion="1126">
  <SqlScripts>
    <SqlScript Id="PreProcess1125" File="NoOperation.sql" EmbeddedAsResource="true" ContinueOnError="false" Type="PreProcess" />
    <SqlScript Id="Upgrade1125" File="NoOperation.sql" EmbeddedAsResource="true" ContinueOnError="false" Type="SchemaUpgrade" />
    <SqlScript Id="PostProcess1125" File="NoOperation.sql" EmbeddedAsResource="true" ContinueOnError="false" Type="PostProcess" />
  </SqlScripts>
</Version>
<Version Id="1126to1127" SourceVersion="1126" TargetVersion="1127">
  <SqlScripts>
    <SqlScript Id="PreProcess1126" File="NoOperation.sql" EmbeddedAsResource="true" ContinueOnError="false" Type="PreProcess" />
    <SqlScript Id="Upgrade1126" File="NoOperation.sql" EmbeddedAsResource="true" ContinueOnError="false" Type="SchemaUpgrade" />
    <SqlScript Id="PostProcess1126" File="NoOperation.sql" EmbeddedAsResource="true" ContinueOnError="false" Type="PostProcess" />
  </SqlScripts>
</Version>
<Version Id="1127to1128" SourceVersion="1127" TargetVersion="1128">
  <SqlScripts>
    <SqlScript Id="PreProcess1127" File="NoOperation.sql" EmbeddedAsResource="true" ContinueOnError="false" Type="PreProcess" />
    <SqlScript Id="Upgrade1127" File="NoOperation.sql" EmbeddedAsResource="true" ContinueOnError="false" Type="SchemaUpgrade" />
    <SqlScript Id="PostProcess1127" File="NoOperation.sql" EmbeddedAsResource="true" ContinueOnError="false" Type="PostProcess" />
  </SqlScripts>
</Version>
<!-- 2001 == vNext -->
<Version Id="1128to2001" SourceVersion="1128" TargetVersion="2001">
  <SqlScripts>
    <SqlScript Id="PreProcess1128" File="NoOperation.sql" EmbeddedAsResource="true" ContinueOnError="false" Type="PreProcess" />
    <SqlScript Id="Upgrade1128" File="NoOperation.sql" EmbeddedAsResource="true" ContinueOnError="false" Type="SchemaUpgrade" />
    <SqlScript Id="PostProcess1128" File="NoOperation.sql" EmbeddedAsResource="true" ContinueOnError="false" Type="PostProcess" />
  </SqlScripts>
</Version>
Restore FIMService database from backup


Enable Service Broker on FIMService datbase


Re-Run MSI with logging
set datetime=%date:~-4%-%date:~-10,2%-%date:~-7,2%_%time:~0,2%-%time:~3,2%-%time:~6,2%
msiexec /i "D:\Install\Service and Portal\Service and Portal.msi" /L*V "D:\Install\Service and Portal.msi-%datetime%.log"


(Not a showstopper)

The database upgrade tool has encountered at least one error when upgrading FIM configuration objects. Please see the Forefront Identity Manager application event log for more detail.




SUCCESS!


FYI, event log
Forefront Identity Manager event log
Log Name:      Forefront Identity Manager
Source:        Microsoft.ResourceManagement
Date:          12/23/2018 9:07:30 AM
Event ID:      3
Task Category: None
Level:         Error
Keywords:      Classic
User:          N/A
Computer:      MYMIMSERVER.mydomain.local
Description:
Workflow host activation failed for workflow definition id : d69415a1-490f-4990-b31d-f41108ace09d, version key: 201. Exception: Object reference not set to an instance of an object.   at Microsoft.ResourceManagement.Workflow.Hosting.HostActivator.ActivateHost(ResourceManagementWorkflowDefinition workflowDefinition, Boolean suspendWorkflowStartupAndTimerOperations)
   at Microsoft.ResourceManagement.Workflow.Hosting.HostActivator.RetrieveWorkflowDataForHostActivator()

FYI, trace log
"D:\Program Files\Microsoft Identity Manager\2016\Service\Microsoft.IdentityManagement.DatabaseUpgrade_tracelog.txt"
    DateTime=2018-12-23T16:47:55.1994988Z
Microsoft.ResourceManagement Information: 1 : WS: Action.Put.Execute.Enter
    DateTime=2018-12-23T16:47:55.1994988Z
Microsoft.ResourceManagement Error: 3 : Reraised Error 50000, Level 14, State 1, Procedure ReRaiseException, Line 37, Message: Reraised Error 50000, Level 14, State 1, Procedure ReRaiseException, Line 37, Message: Reraised Error 2627, Level 14, State 1, Procedure PostProcessManagementPolicyRuleUpdate, Line 585, Message: Violation of PRIMARY KEY constraint 'PK_ManagementPolicyRuleAttribute'. Cannot insert duplicate key in object 'fim.ManagementPolicyRuleAttribute'. The duplicate key value is (2879, 105).
    DateTime=2018-12-23T16:47:55.2776260Z
Microsoft.ResourceManagement Error: 3 : Microsoft.ResourceManagement.WebServices.Exceptions.UnwillingToPerformException: Other ---> System.Data.SqlClient.SqlException: Reraised Error 50000, Level 14, State 1, Procedure ReRaiseException, Line 37, Message: Reraised Error 50000, Level 14, State 1, Procedure ReRaiseException, Line 37, Message: Reraised Error 2627, Level 14, State 1, Procedure PostProcessManagementPolicyRuleUpdate, Line 585, Message: Violation of PRIMARY KEY constraint 'PK_ManagementPolicyRuleAttribute'. Cannot insert duplicate key in object 'fim.ManagementPolicyRuleAttribute'. The duplicate key value is (2879, 105).
   at System.Data.SqlClient.SqlConnection.OnError(SqlException exception, Boolean breakConnection)
   at System.Data.SqlClient.TdsParser.ThrowExceptionAndWarning(TdsParserStateObject stateObj)
   at System.Data.SqlClient.TdsParser.Run(RunBehavior runBehavior, SqlCommand cmdHandler, SqlDataReader dataStream, BulkCopySimpleResultSet bulkCopyHandler, TdsParserStateObject stateObj)
   at System.Data.SqlClient.SqlDataReader.HasMoreRows()
   at System.Data.SqlClient.SqlDataReader.ReadInternal(Boolean setTimeout)
   at System.Data.SqlClient.SqlDataReader.NextResult()
   at Microsoft.ResourceManagement.Data.DataAccess.ProcessRequest(RequestType request)
   --- End of inner exception stack trace ---
    DateTime=2018-12-23T16:47:55.2776260Z
Microsoft.ResourceManagement Warning: 2 : Request 'a3048c6f-fad9-40de-a3eb-b711439d1e6d' failed while trying to commit the changes to the database.  Exception: 'Dispatch Request Failure Source: 'Other''.
    DateTime=2018-12-23T16:47:55.2932514Z
Microsoft.ResourceManagement Verbose: 0 : Request 'a3048c6f-fad9-40de-a3eb-b711439d1e6d' updates have been persisted to permanent storage.
    DateTime=2018-12-23T16:47:55.3088755Z
Microsoft.ResourceManagement Information: 1 : RequestIdentifier 'a3048c6f-fad9-40de-a3eb-b711439d1e6d' exited RequestDispatcher with RequestStatus 'Failed'.
    DateTime=2018-12-23T16:47:55.3088755Z
Microsoft.ResourceManagement Error: 3 : Out-of-box object import : Errors encountered when upgrading the configuration object urn:uuid:a61f2b61-4258-4a02-8fdc-840c739a4bfa.
    DateTime=2018-12-23T16:47:55.3401291Z
Microsoft.ResourceManagement Verbose: 0 : Out-of-box object import : Exception message.
 Failure when making web service call.

SourceObjectID = urn:uuid:a61f2b61-4258-4a02-8fdc-840c739a4bfa
Error = Microsoft.ResourceManagement.WebServices.Exceptions.UnwillingToPerformException: Other ---> System.Data.SqlClient.SqlException: Reraised Error 50000, Level 14, State 1, Procedure ReRaiseException, Line 37, Message: Reraised Error 50000, Level 14, State 1, Procedure ReRaiseException, Line 37, Message: Reraised Error 2627, Level 14, State 1, Procedure
    DateTime=2018-12-23T16:47:55.3401291Z
Microsoft.ResourceManagement Verbose: 0 : Out-of-box object import : Completed processing object import file ConfigurationChange2004.xml.
Check database version
SELECT [Version]
      ,[BinaryVersion]
FROM [FIMService].[fim].[Version]
Version
BinaryVersion
2004
4.3.0.0
MIM Sync version



MIM Service version