Monday, March 2, 2015

SharePoint 2013: UserProfileImportJob Generic failure

Problem

You are unable to get the User Profile Service application to run successfully.  You rebuild the service application several times in an attempt to resolve the issue.  The service application can be completely rebuilt without issues, and you can create a new synchronization connection without issue.  However, the moment that you start a new synchronization, the service fails, no user profiles are imported and you see the following set of message appear every minute (per the timer job schedule):
Log Name:      Application
Source:        Microsoft-SharePoint Products-SharePoint Foundation
Date:          [date/time]
Event ID:      6398
Task Category: Timer
Level:         Critical
Keywords:      
User:          [farm service account]
Computer:      [farm app server]
Description:
The Execute method of job definition 
Microsoft.Office.Server.UserProfiles.UserProfileImportJob 
(ID 3c97e43b-0b13-405a-9bf3-3ff0277ad969) threw an exception. 
More information is included below.

Generic failure 
Event Xml:
...

Log Name:      Application
Source:        MsiInstaller
Date:          [date/time]
Event ID:      1004
Task Category: None
Level:         Warning
Keywords:      Classic
User:          NETWORK SERVICE
Computer:      [farm app server]
Description:
Detection of product '{90150000-104C-0000-1000-0000000FF1CE}', 
feature 'PeopleILM', component '{1AE472A9-E94A-41DC-9E98-F89A2821658F}' 
failed.  The resource 
'D:\Program Files\Microsoft Office Servers\15.0\Tools\makecert.exe' 
does not exist.
Event Xml:
...

Log Name:      Application
Source:        MsiInstaller
Date:          [date/time]
Event ID:      1001
Task Category: None
Level:         Warning
Keywords:      Classic
User:          NETWORK SERVICE
Computer:      [farm app server]
Description:
Detection of product '{90150000-104C-0000-1000-0000000FF1CE}', 
feature 'PeopleILM' failed during request for component 
'{1681AE41-ADA8-4B70-BC11-98A5A4EDD046}'
Event Xml:
...
You also see numerous instances of error event 6313 messages appearing in the application log:
Log Name:      Application
Source:        FIMSynchronizationService
Date:          [date/time]
Event ID:      6313
Task Category: Server
Level:         Error
Keywords:      Classic
User:          N/A
Computer:      [farm app server]
Description:
The server encountered an unexpected error creating 
performance counters for management agent "ILMMA".
 Performance counters will not be available for this management agent.
Event Xml:
...

Log Name:      Application
Source:        FIMSynchronizationService
Date:          [date/time]
Event ID:      6313
Task Category: Server
Level:         Error
Keywords:      Classic
User:          N/A
Computer:      [farm app server]
Description:
The server encountered an unexpected error creating 
performance counters for management agent "MOSS-UserProfile".
 Performance counters will not be available for this management agent.
Event Xml:
...

Log Name:      Application
Source:        FIMSynchronizationService
Date:          [date/time]
Event ID:      6313
Task Category: Server
Level:         Error
Keywords:      Classic
User:          N/A
Computer:      [farm app server]
Description:
The server encountered an unexpected error creating 
performance counters for management agent "MOSSAD-OCS Sync Connection 1".
 Performance counters will not be available for this management agent.
Event Xml:
...
The problem was found to involve the ability of the NETWORK SERVICE account to access certain User Profile Service application resources.

Solution
  1. Log into the farm application server on which the User Profile Service application is running (and on which the FIM services will be running too).
  2. Open the server's Application log, and look for 1001 and 1004 event messages accompanied by a 6398 timer event message.
  3. Note down the folder identified in the 1004 Warning message.
  4. Navigate to this folder.
  5. Grant the NETWORK SERVICE account Read & Execute privilege to the folder.
  6. Monitor the server's Application log for new appearances of the 1001, 1004 and 6398 set of messages.
  7. If no new sets occur, the issue has been resolved.  Otherwise, repeat steps (3) through (6) until they no longer occur.
  8. After all instances have been resolved, FIM synchronization will proceed normally.

References
Notes
  • Thanks to Fred El for his posting that helped point to the solution of the problem.
  • The trick in resolving this issue was to not only look at Critical and Error severity event messages, but also Warning severity ones, which provided the necessary direction and information for actually resolving the problem.
  • The User Profile Service application was running fine previously.  The cause for the change - the permissions for the resource folders - is still being investigated.
  • This problem was first detected when the following error appeared in the app server' Application log right after the usual  6 AM morning timer recycle:
    Log Name:      Application
    Source:        Microsoft-SharePoint Products-SharePoint Foundation
    Date:          [date/time]
    Event ID:      6398
    Task Category: Timer
    Level:         Critical
    Keywords:      
    User:          [farm service account]
    Computer:      [farm app server]
    Description:
    The Execute method of job definition 
    Microsoft.SharePoint.Administration.SPTimerRecycleJobDefinition 
    (ID 966ec95d-d4de-4b54-9cdf-63cb9d2e3623) threw an exception. 
    More information is included below.
    
    The timer service was not recycled because the following jobs 
    were still running: User Profile Service - User Profile 
    Incremental Synchronization
    
    The synchronization task was found to be stuck. Checking the server Services applet, the FIM synchronization service was found to repeatedly stop and start. The Application log also showed these three error events occurring repeatedly:
    Log Name:      Application
    Source:        FIMSynchronizationService
    Date:          [date/time]
    Event ID:      6313
    Task Category: Server
    Level:         Error
    Keywords:      Classic
    User:          N/A
    Computer:      [farm app server]
    Description:
    The server encountered an unexpected error creating performance 
    counters for management agent "ILMMA".
     Performance counters will not be available for this management agent.
    
    Log Name:      Application
    Source:        FIMSynchronizationService
    Date:          [date/time]
    Event ID:      6313
    Task Category: Server
    Level:         Error
    Keywords:      Classic
    User:          N/A
    Computer:      [farm app server]
    Description:
    The server encountered an unexpected error creating performance 
    counters for management agent "MOSS-UserProfile".
     Performance counters will not be available for this management agent.
    
    Log Name:      Application
    Source:        FIMSynchronizationService
    Date:          [date/time]
    Event ID:      6313
    Task Category: Server
    Level:         Error
    Keywords:      Classic
    User:          N/A
    Computer:      [farm app server]
    Description:
    The server encountered an unexpected error creating performance 
    counters for management agent "MOSSAD-nos".
     Performance counters will not be available for this management agent.
    
    Rebuilding the connection then resulted in this event appearing every second in the Application log:
    Log Name:      Application
    Source:        Microsoft-SharePoint Products-SharePoint Foundation
    Date:          [date/time]
    Event ID:      6398
    Task Category: Timer
    Level:         Critical
    Keywords:      
    User:          [farm service account]
    Computer:      [farm app server]
    Description:
    The Execute method of job definition 
    Microsoft.Office.Server.UserProfiles.UserProfileImportJob 
    (ID deabe75d-3701-43c1-9968-920febb91024) threw an exception. More information is included below.
    
    Operation is not valid due to the current state of the object.
    
    Rebuilding the entire service application, creating a new connection and then starting a new synchronization results in this message:
    Log Name:      Application
    Source:        Microsoft-SharePoint Products-SharePoint Foundation
    Date:          [date/time]
    Event ID:      6398
    Task Category: Timer
    Level:         Critical
    Keywords:      
    User:          [farm service account]
    Computer:      [farm app server]
    Description:
    The Execute method of job definition 
    Microsoft.Office.Server.UserProfiles.UserProfileImportJob 
    (ID 3c97e43b-0b13-405a-9bf3-3ff0277ad969) threw an exception. 
    More information is included below.
    
    Generic failure 
    Event Xml:
    ...
    
  • Synchronization Service Manager: tool useful for troubleshooting the SharePoint User Profile Service Application.  You'll find it at this folder location:
    \Program Files\Microsoft Office Servers\15.0\Synchronization Service\UIShell
    Look for miisclient.exe.  It enables you to view the real-time status of UPA processes, among many other things.  I don't use it to manage FIM; just to view status information.  For example, I have used to troubleshoot a UPA that failed to start.  As I tried different troubleshooting steps, I monitored Synchronization Service Manager, watching in real-time to see how far UPA started, before stopping.  It also provides helpful other information, such as confirmation of the Domain Controller that it is connecting to.  If you configured UPA using Auto Detect for DC, you can now determine exactly which DC it is connecting to.  You can also get confirmation of the service account that is running UPA (eg, the farm service account), and the number.

No comments: