SharePoint: Troubleshooting guide for importing groups and managers with MIM

Update 9/16/19: Updated some PowerShell and wording to also apply to SharePoint 2019.

I’ve had a few posts in the past explaining various problems with importing Active Directory (AD) groups and managers. However, this post is designed to be more of a troubleshooting guide that is applicable when using Microsoft Identity Manager (MIM) to Sync profiles.

Notes:

  • I’m lumping managers and group memberships in together because they are processed the same way, and are often broken for the same reason.
  • While this post is targeted at using an external identity manager (MIM) for Profile Sync, the same “staging” and “processing” steps and related database tables are used when using Active Directory Import (AD Import) to import user profiles.

First, some background:

Importing managers and group memberships into the SharePoint User Profile Service Application has always been a bit different than importing other user profile properties. That’s because managers and group memberships are not just string values, they are references that show relationships between two objects. These references are not immediately updated upon import. Instead, they are “staged” during the import and then processed afterwards. The processing is done by a timer job. However, which timer job is used, depends on your version of SharePoint, which leads us to troubleshooting step #1:

Check your version:

Prior to the February 2017 cumulative update for SharePoint 2016 (farm build < 16.0.4497.1000), the manager and group processing was done by the Active Directory Import timer job, which didn’t make a whole lot of sense since you’re using an External Identity Manager (MIM) to import the profiles. There is a way to get this to work at these early builds, but at this point, there’s really no excuse to be at a build less than 16.0.4497.1000, so we’re going to move on with the understanding that 16.0.4497.1000 is the minimum build requirement if you want this to work.

After installation of February 2017 CU, we get a new timer job with display name “<UPAName> – Updates Profile Memberships and Relationships Job” — where “<UPAName>” is the name of your User Profile Service Application. The internal name for the job is “ExternalIdentityManagerMembershipsAndRelationshipsJob”, which is what I’ll use going forward since that’s the name you will see in the logs. There are some instances where the timer job is available, but not actually installed in the farm. You can read more about that issue here.

For SharePoint 2019, it works the same way, but the name of the timer job has been changed slightly: “Updates Profile Memberships and Relationships Job” (internal name: UpdateMembershipsAndRelationships).
Also, it appears that at the time of this update (9/16/19), we have a similar problem as we did in early SP 2016 builds. To get the 2019 timer job to process the staged manager and group membership entries, you will likely need to run this PowerShell:

$upa = Get-SPServiceApplication | ?{$_.typename -match "user profile"}
$upa.NoILMUsed = $true
$upa.update()

You can quickly check if and where the processing timer job has been running with this PowerShell:

#Check which server has been running the post-processing job:
$tjs = Get-SPTimerJob |  ? {$_.displayname -match "memberships"} | fl
foreach ($tj in $tjs)
{$tj.name
$tj.displayname
$tj.historyentries | select StartTime, EndTime, ServerName, status -first 10 | sort -Descending starttime}

Special Consideration for Group Memberships:

Depending on which steps / guides you used to configure your management agents within MIM, you may not have the attribute mappings required to properly import group memberships.

Within the MIM client, go to Management Agents and edit the Active Directory Management Agent (ADMA). Choose “Configure Attribute Flow”, and expand the “Group” object type.

Make sure you have a mapping from sAMAccountName to accountName. If not, you’ll need to create one. — It should be a “direct” mapping with “import” direction.

Review the logs:

Remember that PowerShell sample to find where the ExternalIdentityManagerMembershipsAndRelationshipsJob timer job is running? Go run that to see when, and on which server the timer job has been running. Just keep in mind that the time stamps shown in the PowerShell console are in UTC time, so you’ll have to adjust them to your local server time. I believe the default is for this timer job to run every five minutes. However, we’re mainly interested in the instance that ran directly after the Sync completed. That should be the one that processes all of the staged manager and group membership updates.

Digging Deeper:

To troubleshoot deeper, it’s important to understand how the data flows from Active Directory to MIM to SharePoint. With that data flow in mind, we can find at which point the break-down occurs.

High level data flow:

  • Manager and Group Membership info is stored in Active Directory.
  • MIM makes a series of LDAP calls and pulls that data into the MIM Sync database.
  • MIM exports that data to SharePoint where it is staged.
  • The ExternalIdentityManagerMembershipsAndRelationshipsJob timer job processes that staged data and makes the appropriate updates to the user profiles.

Now with that in mind, lets walk through each step and identify the possible breaking points.

Manager and Group Membership info is stored in Active Directory.

This should be pretty obvious, but before you get too far, you should probably check in Active Directory to make sure the users in question have the expected values for manager and group memberships.

While you’re there, check the “primary group” for the user. Because that’s not part of the users “memberOf” attribute, SharePoint doesn’t honor it as a group membership, as I blogged about earlier.

MIM makes a series of LDAP calls and pulls that data into the MIM Sync database.

There are seldom any problems here. If anything, there could be a permission problem where the account configured to connect to AD doesn’t have enough permission to do so. That’s usually pretty obvious within the MIM client as the ADMA will fail on FULLIMPORT with a “Replication access was denied” error, and no user profiles will be imported. Like previous versions of SharePoint utilizing FIM, the AD connection account in MIM needs the “Replicate Directory Changes” permission to each domain you’re importing users from.

MIM exports that data to SharePoint where it is staged.

This is where things get interesting.

During the export step for the SharePoint MA, MIM calls the _vti_bin/ProfileImportExportService.asmx web service to push the profile data into SharePoint.

This is when the user profiles get created and updated. It’s also when the manager values and group memberships get staged.

The following is an example for Managers. The same holds for group memberships, the only difference is the Profile database tables you’d check to see if groups are staged (upa.ImportExportStagedMember) and if they’ve been processed (upa.UserMemberships).

You can run some SQL queries against the Profile database to see where you stand.

— Are Managers processed?

select * from upa.userprofile_full (nolock) where manager is not null

— If not, are they at least staged?

select * from upa.ProfileImportStagingPersonProperties (nolock)

If they are not even staged, then something went wrong during the Sync. Check the property mappings on the SharePoint Management Agent (SPMA), and get verbose ULS logs from the Central Admin server (that’s where the ProfileImportExportService.asmx web service calls are directed) that cover the timeframe for the Export step of the SharePoint MA.

When they’re getting staged, you should see entries like this in the SharePoint ULS logs:

w3wp.exe (APP1:0x4A5C) 0x4B94 SharePoint Portal Server User Profiles aj3b9 Verbose UserProfile.UpdateProfileImportStagingPersonProperty(): ready to write to staging: PartitionID ‘0c37852b-34d0-418e-91c6-2ac25af4be5b’, RecordId ‘7871’, ProfileType ‘User’, Property ‘Manager’, Value ‘contoso_Manager1__653981c2-2454-4fb4-b862-420a9bae387b’ 5841ce9d-9a86-9073-bbda-b799c29ac26b

w3wp.exe (APP1:0x4A5C) 0x4B94 SharePoint Portal Server User Profiles ogvr High User profile record of “contoso\userA” was changed by “contoso\farmAccount”. 5841ce9d-9a86-9073-bbda-b799c29ac26b

In the above ULS log example, the user being updated (contoso\UserA) has record ID 7871 in the upa.UserProfile_Full table, and his manager value is getting staged as “contoso\Manager1”.

The ExternalIdentityManagerMembershipsAndRelationshipsJob timer job processes that staged data.

After the Sync is complete, group memberships will be Staged in the upa.ImportExportStagedMember table of the Profile database.

And manager references will be staged in the upa.ProfileImportStagingPersonProperties table.

Using some of the SQL queries above, you should be able to tell if this data is getting staged or not.

Once it is processed by the timer job, the rows are removed from the upa.ImportExportStagedMember and upa.ProfileImportStagingPersonProperties tables, so if you see data staying in those tables, it’s a good bet that something is going wrong with the processing.

If you see that it’s getting staged, but never processed, then we need to turn our focus to the timer job that does the processing.

Here’s the PowerShell again to check when and where that timer job ran:

#Check which server has been running the post-processing job:
$tjs = Get-SPTimerJob |  ? {$_.displayname -match "memberships"} | fl
foreach ($tj in $tjs)
{$tj.name
$tj.displayname
$tj.historyentries | select StartTime, EndTime, ServerName, status -first 10 | sort -Descending starttime}

If the timer job does not seem to be running at all, you should check out the known issue I blogged about earlier: https://joshroark.com/sharepoint-profile-sync-with-mim-managers-and-group-memberships-are-not-updated/

And make sure your Timer Service is happy in general: https://joshroark.com/sharepoint-all-about-one-time-timer-jobs/

If the timer job is running, but processing is not happening, you need to get ULS logs from the server that ran the job and see what is going on with it. Possibly the timer job is running, but failing with an error.

Here’s what you can expect to see in the logs when it runs successfully. It basically just calls a couple of SQL stored procedures to do the work. IMPORTEXPORT_PostImportUserProperties does the processing for managers, and IMPORTEXPORT_PostImportMembers does the processing for group memberships.

OWSTIMER.EXE (0x2AF8)    0x693C    SharePoint Foundation    Logging Correlation Data    xmnv    Medium    Name=Timer Job UPA-MIM_ExternalIdentityManagerMembershipsAndRelationshipsJob

OWSTIMER.EXE (0x2AF8)    0x693C    SharePoint Portal Server    User Profiles    00000    Medium    ExternalIdentityManagerMembershipsAndRelationshipsJob starting post sync operations

OWSTIMER.EXE (0x0EBC) 0x17E8 SharePoint Portal Server User Profiles afoeg Medium UserProfileApplication.SynchronizationPostProcessing: About to call IMPORTEXPORT_PostImportUserProperties

OWSTIMER.EXE (0x0EBC) 0x17E8 SharePoint Server Database tzkv Verbose SqlCommand: ‘[upa].[ImportExport_PostImportUserProperties]‘ CommandType: StoredProcedure CommandTimeout: 0 Parameter: ‘@correlationId’ Type: UniqueIdentifier Size: 0 Direction: Input Value: ‘00000000-0000-0000-0000-000000000000’

OWSTIMER.EXE (0x0EBC) 0x17E8 SharePoint Portal Server User Profiles afoeh Medium UserProfileApplication.SynchronizationPostProcessing: Returned from IMPORTEXPORT_PostImportUserProperties

OWSTIMER.EXE (0x0EBC) 0x17E8 SharePoint Portal Server User Profiles afoei Medium UserProfileApplication.SynchronizationPostProcessing: About to call IMPORTEXPORT_PostImportMembers

OWSTIMER.EXE (0x0EBC) 0x17E8 SharePoint Server Database tzkv Verbose SqlCommand: ‘[upa].[ImportExport_PostImportMembers]‘ CommandType: StoredProcedure CommandTimeout: 0 Parameter: ‘@correlationId’ Type: UniqueIdentifier Size: 0 Direction: Input Value: ‘00000000-0000-0000-0000-000000000000’

OWSTIMER.EXE (0x0EBC) 0x17E8 SharePoint Portal Server User Profiles afoej Medium UserProfileApplication.SynchronizationPostProcessing: Returned from IMPORTEXPORT_PostImportMembers

And lastly, this is a bit of a “sledge hammer” approach, but we’ve seen instances where invalid data can get “stuck” in the upa.ImportExportStagedMember and upa.ProfileImportStagingPersonProperties tables. Sometimes all you can do is clear them out and try another Full Sync.

It is NOT SUPPORTED to manually delete rows from any SharePoint table. However, there is another way.

If you switch your Synchronization option from External Identity Manager to Active Directory Import, click OK to save, and then switch it back (basically, toggle the setting), that will cause SharePoint to clear out the following tables:

  • DNLookup
  • ImportExportStagedMember
  • ProfileImportStagingPersonProperties

No need to worry, there’s no user data in those tables. It’s just system data that will be rebuilt during the next Sync.

If you want to be extra cautious, you could disable the ‘My Site Cleanup Job’ until after a Sync or two has completed successfully.