locked
User Profiles Synch Service starting failes after "ILM Configuration: Starting services" RRS feed

  • Question

  • Hello guys.

    I tried to configure user profiles synchronization and it could not be started without any problems as expected :)

    This time I got the following error in logs:

    02.05.2013 10:54:03.34 OWSTIMER.EXE (0x17DC) 0x183C SharePoint Portal Server User Profiles 9q1k Medium ILM Configuration: Starting services. 0160471f-15fc-4d97-8227-05b86f4d0fc7
    02.05.2013 10:54:33.52 OWSTIMER.EXE (0x17DC) 0x183C SharePoint Portal Server User Profiles 9q15 High UserProfileApplication.SynchronizeMIIS: Failed to configure ILM, will attempt during next rerun. Exception: System.FormatException: Index (zero based) must be greater than or equal to zero and less than the size of the argument list.     at System.Text.StringBuilder.AppendFormat(IFormatProvider provider, String format, Object[] args)     at System.String.Format(IFormatProvider provider, String format, Object[] args)     at Microsoft.Office.Server.Administration.ProfileSynchronizationServiceInstance.IsStarted(ServiceController controller)     at Microsoft.Office.Server.Administration.ProfileSynchronizationServiceInstance.WaitUntilStarted()     at Microsoft.Office.Server.Administration.UserProfileApplication.SetupSynchronizationService(ProfileSynchronizationServiceInstance profileSyncInstance). 0160471f-15fc-4d97-8227-05b86f4d0fc7
    02.05.2013 10:54:33.52 OWSTIMER.EXE (0x17DC) 0x183C SharePoint Portal Server User Profiles 9i1u Medium UserProfileApplication.SynchronizeMIIS: End setup for 'UserProfilesService'. 0160471f-15fc-4d97-8227-05b86f4d0fc7

    -

    So, what I have and what I've done:.

    1) I have a test 2-servers farm installation (Database server + WFE/Application server); SQL Server 2008 R2 SP2, SHP 2010 SP1 + October 2012 CU; There are no any service applications except default ones(Security Token Service and Application Discovery and Load Balancer Service Application) as well as there are  no any services started except default :) 

    2) I created a site collection and manage path for MySites, created a new UPA and its proxy.

    That's all. Now, if I try starting User Profiles Synchronization Service, it stucks on "starting" for about 10 mins and I see the error above in ULS. Hope you can somehow help me.

    -

    By the way, I don't want a both sides synchronization this time, I just need to check some stuff with People Search. Will "Read" rights for Managed Account in AD be enough to export profiles from AD? (I mean if I select my farm account as a synchronization account, will it work?)

    -

    Thank's in advance!

    Anton.

    UPDATED

    The problem probably was due to the lack of internet access. As Raymond Diack said:

    "the farm account needs internet access to do a CRL check to these sites:

    crl.microsoft.com
    ctldl.windowsupdate.com
    ctldl.windowsupdate.nsatc.net
    www.update.microsoft.com.nsatc.net "


    Tuesday, February 5, 2013 7:22 AM

Answers

  • I've just run into a similar problem but with SP 2013 - in our case the User Profile Synchronization service was stuck on "Starting", and eventually failed to start (along with the corresponding FIM services).  We discovered after about 15 hours of troubleshooting that the farm account needs internet access to do a CRL check to these sites:

    crl.microsoft.com
    ctldl.windowsupdate.com
    ctldl.windowsupdate.nsatc.net
    www.update.microsoft.com.nsatc.net

    The error we were getting in the ULS log seems to be the same as yours:

    UserProfileApplication.SynchronizeMIIS: Failed to configure ILM, will attempt during next rerun. Exception: System.FormatException: Index (zero based) must be greater than or equal to zero and less than the size of the argument list.   

    Hope that helps.

     
    • Proposed as answer by Nik Patel Saturday, June 29, 2013 2:03 AM
    • Marked as answer by Trevor SewardMVP Wednesday, August 21, 2013 10:18 PM
    Sunday, March 24, 2013 12:31 AM

All replies

  • Hello Anton, 

    This issue was addressed at this address, see if the suggested solution solves your difficulty.

    Reference:

    http://social.technet.microsoft.com/forums/en-US/sharepointadminprevious/thread/50e92b07-66d5-4025-894b-efaf0e59330e/

    I hope i helped.


    Hezequias Vasconcelos

    Tuesday, February 5, 2013 11:21 AM
  • Thanks a lot for the reply.. I checked those post out, but the suggested methods doesn't cover my error... I also tried to use Process Monitor during UPSS starting, but couldn't find there someth usefull..
    By the way, my farm is not connected to the internet.. Could it be the reason? I have already encountered the need in internet connection to perform some actions before...
    Wednesday, February 6, 2013 10:08 AM
  • I've built out multiple farms and when it comes to the UPS the best advice is to delete the current application and start over. Follow this guide and do not skip any steps - http://www.harbar.net/articles/sp2010ups.aspx (apparently I can't add links because I'm unverified, my old account no longer works here for some reason so I had to use an alternate, sorry). Re-provisioning takes much less time than troubleshooting, most likely you have missed a step along the way (I've done this dozens of times and I still miss steps).

    I don't think internet connectivity should matter, but feel free to correct me if I'm wrong. 


    *EDIT - You need to follow the directions when it comes to accounts, trying to skip these steps will only cause headaches.
    • Proposed as answer by __BN_ Wednesday, February 6, 2013 4:53 PM
    • Edited by __BN_ Wednesday, February 6, 2013 4:57 PM
    • Unproposed as answer by Martynenko Anton Sunday, February 10, 2013 7:53 PM
    Wednesday, February 6, 2013 4:52 PM
  • Thank's for the advice, Bin.

    Unfortunately, I already tried to reprovision UPS for a couple of times, but with no result.. I got an error with permissions once, but after fixing it, I got the error above again :(

    So I'll unmark your post as an answer, hope some1 will have an idea or smth...

    Sunday, February 10, 2013 7:53 PM
  • Can you post the ULS logs that contain entries around the error, including the error itself?

    SharePoint - Nauplius Applications
    Microsoft SharePoint Server MVP
    MCITP: SharePoint Administrator 2010

    -----------------------
    This post is my own opinion and does not necessarily reflect the opinion or view of Microsoft, its employees, or other MVPs.

    Sunday, February 10, 2013 8:03 PM
  • Sure, here is the stack near the error without any filters: 

    11:13:11.88 OWSTIMER.EXE (0x0AA8) 0x0EA8 SharePoint Portal Server User Profiles 9q1j Medium ILM Configuration: Opening firewall ports. 589d9196-6647-4432-9ab0-a389871310b7
    11:13:12.13 OWSTIMER.EXE (0x0AA8) 0x0EA8 SharePoint Portal Server User Profiles 9q1k Medium ILM Configuration: Starting services. 589d9196-6647-4432-9ab0-a389871310b7
    11:13:12.36 w3wp.exe (0x1364) 0x0CA0 SharePoint Foundation Topology e5mc Medium WcfSendRequest: RemoteAddress: 'http://hq-tcc-app-02:32843/900539dde24c4bc9a0db06a9f9fe6ebf/MetadataWebService.svc' Channel: 'Microsoft.SharePoint.Taxonomy.IMetadataWebServiceApplication' Action: 'http://schemas.microsoft.com/sharepoint/taxonomy/soap/IDataAccessReadOnly/GetChanges' MessageId: 'urn:uuid:80a1f95b-37a3-45f1-89a6-f33de57b678a'
    11:13:12.36 w3wp.exe (0x0788) 0x0D2C SharePoint Foundation Topology e5mb Medium WcfReceiveRequest: LocalAddress: 'http://hq-tcc-app-02.corp.fsk-ees.local:32843/900539dde24c4bc9a0db06a9f9fe6ebf/MetadataWebService.svc' Channel: 'System.ServiceModel.Channels.ServiceChannel' Action: 'http://schemas.microsoft.com/sharepoint/taxonomy/soap/IDataAccessReadOnly/GetChanges' MessageId: 'urn:uuid:80a1f95b-37a3-45f1-89a6-f33de57b678a' 75b52d1d-0e9e-45a6-8122-c578bc8aeaf7
    11:13:12.36 w3wp.exe (0x0788) 0x0D2C SharePoint Foundation Monitoring nasq Medium Entering monitored scope (ExecuteWcfServerOperation) 75b52d1d-0e9e-45a6-8122-c578bc8aeaf7
    11:13:12.36 w3wp.exe (0x0788) 0x0D2C SharePoint Server Taxonomy fuc5 Medium MetadataWebServiceApplication.GetChanges called on 'Служба управляемых метаданных' starting. 75b52d1d-0e9e-45a6-8122-c578bc8aeaf7
    11:13:12.36 w3wp.exe (0x0788) 0x0D2C SharePoint Server Taxonomy fuc6 Medium MetadataWebServiceApplication.GetChanges called on 'Служба управляемых метаданных' completed. 75b52d1d-0e9e-45a6-8122-c578bc8aeaf7
    11:13:12.38 w3wp.exe (0x0788) 0x0D2C SharePoint Foundation Monitoring b4ly Medium Leaving Monitored Scope (ExecuteWcfServerOperation). Время выполнения=4,01622273221876 75b52d1d-0e9e-45a6-8122-c578bc8aeaf7
    11:13:12.75 OWSTIMER.EXE (0x0AA8) 0x16F0 SharePoint Foundation Monitoring nasq Medium Entering monitored scope (Timer Job job-timer-locks) ea70e10e-4455-47ea-a3fd-e7cb0f0a9ce4
    11:13:12.75 OWSTIMER.EXE (0x0AA8) 0x16F0 SharePoint Foundation Monitoring b4ly Medium Leaving Monitored Scope (Timer Job job-timer-locks). Время выполнения=4,16512433842849 ea70e10e-4455-47ea-a3fd-e7cb0f0a9ce4
    11:13:22.52 w3wp.exe (0x1364) 0x0CA0 SharePoint Foundation Topology e5mc Medium WcfSendRequest: RemoteAddress: 'http://hq-tcc-app-02:32843/900539dde24c4bc9a0db06a9f9fe6ebf/MetadataWebService.svc' Channel: 'Microsoft.SharePoint.Taxonomy.IMetadataWebServiceApplication' Action: 'http://schemas.microsoft.com/sharepoint/taxonomy/soap/IDataAccessReadOnly/GetChanges' MessageId: 'urn:uuid:5b799d56-3784-48ff-beaf-6fb6bfeade78'
    11:13:22.52 w3wp.exe (0x0788) 0x1544 SharePoint Foundation Topology e5mb Medium WcfReceiveRequest: LocalAddress: 'http://hq-tcc-app-02.corp.fsk-ees.local:32843/900539dde24c4bc9a0db06a9f9fe6ebf/MetadataWebService.svc' Channel: 'System.ServiceModel.Channels.ServiceChannel' Action: 'http://schemas.microsoft.com/sharepoint/taxonomy/soap/IDataAccessReadOnly/GetChanges' MessageId: 'urn:uuid:5b799d56-3784-48ff-beaf-6fb6bfeade78' 941bbfb5-84aa-411e-b310-74830120b860
    11:13:22.52 w3wp.exe (0x0788) 0x1544 SharePoint Foundation Monitoring nasq Medium Entering monitored scope (ExecuteWcfServerOperation) 941bbfb5-84aa-411e-b310-74830120b860
    11:13:22.52 w3wp.exe (0x0788) 0x1544 SharePoint Server Taxonomy fuc5 Medium MetadataWebServiceApplication.GetChanges called on 'Служба управляемых метаданных' starting. 941bbfb5-84aa-411e-b310-74830120b860
    11:13:22.52 w3wp.exe (0x0788) 0x1544 SharePoint Server Taxonomy fuc6 Medium MetadataWebServiceApplication.GetChanges called on 'Служба управляемых метаданных' completed. 941bbfb5-84aa-411e-b310-74830120b860
    11:13:22.52 w3wp.exe (0x0788) 0x1544 SharePoint Foundation Monitoring b4ly Medium Leaving Monitored Scope (ExecuteWcfServerOperation). Время выполнения=2,92432418086656 941bbfb5-84aa-411e-b310-74830120b860
    11:13:26.78 OWSTIMER.EXE (0x0AA8) 0x0894 SharePoint Foundation Monitoring nasq Medium Entering monitored scope (Timer Job SchedulingUnpublish) 6044b3fe-8ca7-4f76-81b0-ea55e6795d5b
    11:13:26.78 OWSTIMER.EXE (0x0AA8) 0x0894 SharePoint Foundation Monitoring b4ly Medium Leaving Monitored Scope (Timer Job SchedulingUnpublish). Время выполнения=2,56094000773841 6044b3fe-8ca7-4f76-81b0-ea55e6795d5b
    11:13:32.66 w3wp.exe (0x1364) 0x0CA0 SharePoint Foundation Topology e5mc Medium WcfSendRequest: RemoteAddress: 'http://hq-tcc-app-02:32843/900539dde24c4bc9a0db06a9f9fe6ebf/MetadataWebService.svc' Channel: 'Microsoft.SharePoint.Taxonomy.IMetadataWebServiceApplication' Action: 'http://schemas.microsoft.com/sharepoint/taxonomy/soap/IDataAccessReadOnly/GetChanges' MessageId: 'urn:uuid:f5648c05-71d7-443c-b12d-946eb36bcb3f'
    11:13:32.66 w3wp.exe (0x0788) 0x1544 SharePoint Foundation Topology e5mb Medium WcfReceiveRequest: LocalAddress: 'http://hq-tcc-app-02.corp.fsk-ees.local:32843/900539dde24c4bc9a0db06a9f9fe6ebf/MetadataWebService.svc' Channel: 'System.ServiceModel.Channels.ServiceChannel' Action: 'http://schemas.microsoft.com/sharepoint/taxonomy/soap/IDataAccessReadOnly/GetChanges' MessageId: 'urn:uuid:f5648c05-71d7-443c-b12d-946eb36bcb3f' 1af7e327-bb71-49f8-a598-2e85ae5ce2a6
    11:13:32.66 w3wp.exe (0x0788) 0x1544 SharePoint Foundation Monitoring nasq Medium Entering monitored scope (ExecuteWcfServerOperation) 1af7e327-bb71-49f8-a598-2e85ae5ce2a6
    11:13:32.66 w3wp.exe (0x0788) 0x1544 SharePoint Server Taxonomy fuc5 Medium MetadataWebServiceApplication.GetChanges called on 'Служба управляемых метаданных' starting. 1af7e327-bb71-49f8-a598-2e85ae5ce2a6
    11:13:32.71 w3wp.exe (0x0788) 0x1544 SharePoint Server Taxonomy fuc6 Medium MetadataWebServiceApplication.GetChanges called on 'Служба управляемых метаданных' completed. 1af7e327-bb71-49f8-a598-2e85ae5ce2a6
    11:13:32.72 w3wp.exe (0x0788) 0x1544 SharePoint Foundation Monitoring b4ly Medium Leaving Monitored Scope (ExecuteWcfServerOperation). Время выполнения=65,7127512016192 1af7e327-bb71-49f8-a598-2e85ae5ce2a6
    11:13:39.79 OWSTIMER.EXE (0x0AA8) 0x0500 SharePoint Foundation Monitoring nasq Medium Entering monitored scope (Timer Job SchedulingApproval) 69e34469-a502-4257-80f4-d8fb990f2bf7
    11:13:39.80 OWSTIMER.EXE (0x0AA8) 0x0500 SharePoint Foundation Monitoring b4ly Medium Leaving Monitored Scope (Timer Job SchedulingApproval). Время выполнения=11,6191443325898 69e34469-a502-4257-80f4-d8fb990f2bf7
    11:13:40.33 w3wp.exe (0x1364) 0x0E98 SharePoint Portal Server Runtime 8gp7 Medium Topology cache updated. (AppDomain: /LM/W3SVC/961767364/ROOT-1-130050376913614507)
    11:13:42.88 w3wp.exe (0x1364) 0x0CA0 SharePoint Foundation Topology e5mc Medium WcfSendRequest: RemoteAddress: 'http://hq-tcc-app-02:32843/900539dde24c4bc9a0db06a9f9fe6ebf/MetadataWebService.svc' Channel: 'Microsoft.SharePoint.Taxonomy.IMetadataWebServiceApplication' Action: 'http://schemas.microsoft.com/sharepoint/taxonomy/soap/IDataAccessReadOnly/GetChanges' MessageId: 'urn:uuid:23bdd02e-0716-4697-b55d-55862694ebe1'
    11:13:42.89 w3wp.exe (0x0788) 0x0D2C SharePoint Foundation Topology e5mb Medium WcfReceiveRequest: LocalAddress: 'http://hq-tcc-app-02.corp.fsk-ees.local:32843/900539dde24c4bc9a0db06a9f9fe6ebf/MetadataWebService.svc' Channel: 'System.ServiceModel.Channels.ServiceChannel' Action: 'http://schemas.microsoft.com/sharepoint/taxonomy/soap/IDataAccessReadOnly/GetChanges' MessageId: 'urn:uuid:23bdd02e-0716-4697-b55d-55862694ebe1' c7b0b8bc-dad4-4863-98e0-92838dafa933
    11:13:42.89 w3wp.exe (0x0788) 0x0D2C SharePoint Foundation Monitoring nasq Medium Entering monitored scope (ExecuteWcfServerOperation) c7b0b8bc-dad4-4863-98e0-92838dafa933
    11:13:42.89 w3wp.exe (0x0788) 0x0D2C SharePoint Server Taxonomy fuc5 Medium MetadataWebServiceApplication.GetChanges called on 'Служба управляемых метаданных' starting. c7b0b8bc-dad4-4863-98e0-92838dafa933
    11:13:42.89 w3wp.exe (0x0788) 0x0D2C SharePoint Server Taxonomy fuc6 Medium MetadataWebServiceApplication.GetChanges called on 'Служба управляемых метаданных' completed. c7b0b8bc-dad4-4863-98e0-92838dafa933
    11:13:42.89 w3wp.exe (0x0788) 0x0D2C SharePoint Foundation Monitoring b4ly Medium Leaving Monitored Scope (ExecuteWcfServerOperation). Время выполнения=2,88158131829604 c7b0b8bc-dad4-4863-98e0-92838dafa933
    11:13:42.89 OWSTIMER.EXE (0x0AA8) 0x0EA8 SharePoint Portal Server User Profiles 9q15 High UserProfileApplication.SynchronizeMIIS: Failed to configure ILM, will attempt during next rerun. Exception: System.FormatException: Index (zero based) must be greater than or equal to zero and less than the size of the argument list.     at System.Text.StringBuilder.AppendFormat(IFormatProvider provider, String format, Object[] args)     at System.String.Format(IFormatProvider provider, String format, Object[] args)     at Microsoft.Office.Server.Administration.ProfileSynchronizationServiceInstance.IsStarted(ServiceController controller)     at Microsoft.Office.Server.Administration.ProfileSynchronizationServiceInstance.WaitUntilStarted()     at Microsoft.Office.Server.Administration.UserProfileApplication.SetupSynchronizationService(ProfileSynchronizationServiceInstance profileSyncInstance). 589d9196-6647-4432-9ab0-a389871310b7
    11:13:42.89 OWSTIMER.EXE (0x0AA8) 0x0EA8 SharePoint Portal Server User Profiles 9i1u Medium UserProfileApplication.SynchronizeMIIS: End setup for 'UPS'. 589d9196-6647-4432-9ab0-a389871310b7
    11:13:42.89 OWSTIMER.EXE (0x0AA8) 0x0EA8 SharePoint Foundation Topology 8xqz Medium Updating SPPersistedObject ProfileSynchronizationSetupJob Name=ProfileSynchronizationSetupJob. Version: 15232 Ensure: False, HashCode: 11248478, Id: c8e4ed56-ab72-4b99-8532-d282d3f26896, Stack:    at Microsoft.SharePoint.Administration.SPPersistedObject.BaseUpdate()     at Microsoft.SharePoint.Administration.SPJobDefinition.Update()     at Microsoft.Office.Server.Administration.ProfileSynchronizationSetupJob.Execute(SPJobState state)     at Microsoft.SharePoint.Administration.SPTimerJobInvokeInternal.Invoke(SPJobDefinition jd, Guid targetInstanceId, Boolean isTimerService, Int32& result)     at Microsoft.SharePoint.Administration.SPTimerJobInvoke.Invoke(TimerJobExecuteData& data, Int32& result) 589d9196-6647-4432-9ab0-a389871310b7
    11:13:42.92 OWSTIMER.EXE (0x0AA8) 0x0EA8 SharePoint Foundation Monitoring b4ly High Leaving Monitored Scope (Timer Job ProfileSynchronizationSetupJob). Время выполнения=161321,353202712 589d9196-6647-4432-9ab0-a389871310b7
    11:13:42.96 OWSTIMER.EXE (0x0AA8) 0x0EA8 SharePoint Foundation Topology 8dyx High Deleting the SPPersistedObject, ProfileSynchronizationSetupJob Name=ProfileSynchronizationSetupJob. 589d9196-6647-4432-9ab0-a389871310b7


    Monday, February 11, 2013 7:26 AM
  • In Harbar's post I found a note: 

    "The SharePoint Configuration Wizard (PSConfig) supports named instances (e.g. SQLServerName\InstanceName), but UPS does not. Therefore if we wish to use named instances and UPS we must configure an Alias, and we must do this before we run PSConfig to create the farm.

    Note: this issue is fixed in the June 2010 Cumulative Update for SharePoint Server. Thus if we are running the June CU or later, we do not need to configure an alias. However, I strongly recommend you use an alias, as it is a best practice for addressing SQL named instances regardless of this issue."

    Actually I realy have an SQL named instance.. But I also have October 2012 CU installed, so those issue should be fixed...

    It's also said that after creating an alias for the instance I can create a farm using it.. Huh, what an irony.

    Guys, I realy don't want to recreate everything if this probably won't help.. I'll leave this method as my last attempt, hope there is something else, that can help...

    Monday, February 11, 2013 11:50 AM
  • Well, I removed all databases, configured aliases, reconfigured farm, didn't start ANY services, configured UPS, step-by-step following Harbar's guide. But still no result. Same error :(

    The only things, that differs are My Sites application pool(but we don't even need this web application right now :( ) and UPS Pool account - I used farm acount, but this should not be the reason...

    Please help.

    Wednesday, February 13, 2013 11:14 AM
  • Can you turn up the diagnostic logging on the UPA and try again?

    SharePoint - Nauplius Applications
    Microsoft SharePoint Server MVP
    MCITP: SharePoint Administrator 2010

    -----------------------
    This post is my own opinion and does not necessarily reflect the opinion or view of Microsoft, its employees, or other MVPs.

    Wednesday, February 13, 2013 5:22 PM
  • I'm not sure, that I understood you right. I use ULS log viewer to see, whats going on in the farm... Is it enough? Here is an all log info from farm right after clicking "start" at UP synchronization service filtered by User Profiles. (I can send you all the log file withour filtering by e-mail, becouse its bigger then 60000char..)

    Same, but filtered by User Profiles:

    02.14.2013 14:14:00.85 OWSTIMER.EXE (0x1780) 0x0F74 SharePoint Portal Server User Profiles ojwk High User Profile Application: Begin synchronizing profile property display names for language lcid = '1049'. b6777234-3f11-444c-8d43-091ee39cbb93
    02.14.2013 14:14:00.85 OWSTIMER.EXE (0x1780) 0x0F74 SharePoint Portal Server User Profiles ojwl High User Profile Application: Done synchronizing profile property display names for language lcid = '1049'. b6777234-3f11-444c-8d43-091ee39cbb93
    02.14.2013 14:14:01.89 OWSTIMER.EXE (0x1780) 0x0DA4 SharePoint Portal Server User Profiles erx1 Medium Provisioning service instance Служба синхронизации профилей пользователей. 9a75ed6e-8724-4b0d-a371-6ef8d197f1b3
    02.14.2013 14:14:01.99 OWSTIMER.EXE (0x1780) 0x0DA4 SharePoint Portal Server User Profiles erx2 Medium The service instance Служба синхронизации профилей пользователей is successfully provisioned. 9a75ed6e-8724-4b0d-a371-6ef8d197f1b3
    02.14.2013 14:14:32.44 OWSTIMER.EXE (0x1780) 0x0DA4 SharePoint Portal Server User Profiles 9i1s Medium UserProfileApplication.SynchronizeMIIS: Begin setup for 'User Profiles Service'. 9a75ed6e-8724-4b0d-a371-6ef8d197f1b3
    02.14.2013 14:14:32.47 OWSTIMER.EXE (0x1780) 0x0DA4 SharePoint Portal Server User Profiles 9i1y Medium ILM Configuration: Validating account. 9a75ed6e-8724-4b0d-a371-6ef8d197f1b3
    02.14.2013 14:14:32.52 OWSTIMER.EXE (0x1780) 0x0DA4 SharePoint Portal Server User Profiles 9i20 Medium ILM Configuration: Validating the system groups 9a75ed6e-8724-4b0d-a371-6ef8d197f1b3
    02.14.2013 14:14:32.52 OWSTIMER.EXE (0x1780) 0x0DA4 SharePoint Portal Server User Profiles 9i23 Medium ILM Configuration: Setting up WMI 9a75ed6e-8724-4b0d-a371-6ef8d197f1b3
    02.14.2013 14:14:32.56 OWSTIMER.EXE (0x1780) 0x0DA4 SharePoint Portal Server User Profiles 9i24 Medium ILM Configuration: Setting required permissions 9a75ed6e-8724-4b0d-a371-6ef8d197f1b3
    02.14.2013 14:14:32.59 OWSTIMER.EXE (0x1780) 0x0DA4 SharePoint Portal Server User Profiles 9i26 Medium ILM Configuration: Create install config file 9a75ed6e-8724-4b0d-a371-6ef8d197f1b3
    02.14.2013 14:14:32.59 OWSTIMER.EXE (0x1780) 0x0DA4 SharePoint Portal Server User Profiles 9i28 Medium ILM Configuration: Update source project 9a75ed6e-8724-4b0d-a371-6ef8d197f1b3
    02.14.2013 14:14:32.59 OWSTIMER.EXE (0x1780) 0x0DA4 SharePoint Portal Server User Profiles 9i29 Medium ILM Configuration: Changing service account credentials 9a75ed6e-8724-4b0d-a371-6ef8d197f1b3
    02.14.2013 14:14:32.61 OWSTIMER.EXE (0x1780) 0x0DA4 SharePoint Portal Server User Profiles d3bo Medium ILM Configuration: Setting policy for service account 9a75ed6e-8724-4b0d-a371-6ef8d197f1b3
    02.14.2013 14:14:32.67 OWSTIMER.EXE (0x1780) 0x0DA4 SharePoint Portal Server User Profiles 9i2a Medium ILM Configuration: Configuring database 9a75ed6e-8724-4b0d-a371-6ef8d197f1b3
    02.14.2013 14:14:33.11 OWSTIMER.EXE (0x1780) 0x0DA4 SharePoint Portal Server User Profiles 9i2b Medium ILM Configuration: Re-starting mms service 9a75ed6e-8724-4b0d-a371-6ef8d197f1b3
    02.14.2013 14:15:00.97 OWSTIMER.EXE (0x1780) 0x1048 SharePoint Portal Server User Profiles ojwk High User Profile Application: Begin synchronizing profile property display names for language lcid = '1049'. f6e71f77-2ea1-4a8a-ba93-7014dbc7d3d7
    02.14.2013 14:15:00.99 OWSTIMER.EXE (0x1780) 0x1048 SharePoint Portal Server User Profiles ojwl High User Profile Application: Done synchronizing profile property display names for language lcid = '1049'. f6e71f77-2ea1-4a8a-ba93-7014dbc7d3d7
    02.14.2013 14:15:25.99 OWSTIMER.EXE (0x1780) 0x0DA4 SharePoint Portal Server User Profiles 9i2d Medium ILM Configuration: Checking mms service 9a75ed6e-8724-4b0d-a371-6ef8d197f1b3
    02.14.2013 14:15:26.04 OWSTIMER.EXE (0x1780) 0x0DA4 SharePoint Portal Server User Profiles 9q1e Medium ILM Configuration: Configuring XML file. 9a75ed6e-8724-4b0d-a371-6ef8d197f1b3
    02.14.2013 14:15:26.06 OWSTIMER.EXE (0x1780) 0x0DA4 SharePoint Portal Server User Profiles 9q1f Medium ILM Configuration: Checking for existing FIM database. 9a75ed6e-8724-4b0d-a371-6ef8d197f1b3
    02.14.2013 14:15:26.06 OWSTIMER.EXE (0x1780) 0x0DA4 SharePoint Portal Server User Profiles eee3 Medium ILM Configuration: Building database. 9a75ed6e-8724-4b0d-a371-6ef8d197f1b3
    02.14.2013 14:16:00.30 OWSTIMER.EXE (0x1780) 0x1048 SharePoint Portal Server User Profiles ojwk High User Profile Application: Begin synchronizing profile property display names for language lcid = '1049'. 042919f9-ab3f-4624-9704-fab0ae3fa047
    02.14.2013 14:16:00.30 OWSTIMER.EXE (0x1780) 0x1048 SharePoint Portal Server User Profiles ojwl High User Profile Application: Done synchronizing profile property display names for language lcid = '1049'. 042919f9-ab3f-4624-9704-fab0ae3fa047
    02.14.2013 14:16:18.44 OWSTIMER.EXE (0x1780) 0x0DA4 SharePoint Portal Server User Profiles 9q1h Medium ILM Configuration: Configuring certificate. 9a75ed6e-8724-4b0d-a371-6ef8d197f1b3
    02.14.2013 14:16:19.27 OWSTIMER.EXE (0x1780) 0x0DA4 SharePoint Portal Server User Profiles 9q1g Medium ILM Configuration: Configuring Registry keys. 9a75ed6e-8724-4b0d-a371-6ef8d197f1b3
    02.14.2013 14:16:19.30 OWSTIMER.EXE (0x1780) 0x0DA4 SharePoint Portal Server User Profiles 9q1i Medium ILM Configuration: Setting file permissions. 9a75ed6e-8724-4b0d-a371-6ef8d197f1b3
    02.14.2013 14:16:19.30 OWSTIMER.EXE (0x1780) 0x0DA4 SharePoint Portal Server User Profiles 9q1j Medium ILM Configuration: Opening firewall ports. 9a75ed6e-8724-4b0d-a371-6ef8d197f1b3
    02.14.2013 14:16:19.46 OWSTIMER.EXE (0x1780) 0x0DA4 SharePoint Portal Server User Profiles 9q1k Medium ILM Configuration: Starting services. 9a75ed6e-8724-4b0d-a371-6ef8d197f1b3
    02.14.2013 14:16:49.63 OWSTIMER.EXE (0x1780) 0x0DA4 SharePoint Portal Server User Profiles 9q15 High UserProfileApplication.SynchronizeMIIS: Failed to configure ILM, will attempt during next rerun. Exception: System.FormatException: Index (zero based) must be greater than or equal to zero and less than the size of the argument list.     at System.Text.StringBuilder.AppendFormat(IFormatProvider provider, String format, Object[] args)     at System.String.Format(IFormatProvider provider, String format, Object[] args)     at Microsoft.Office.Server.Administration.ProfileSynchronizationServiceInstance.IsStarted(ServiceController controller)     at Microsoft.Office.Server.Administration.ProfileSynchronizationServiceInstance.WaitUntilStarted()     at Microsoft.Office.Server.Administration.UserProfileApplication.SetupSynchronizationService(ProfileSynchronizationServiceInstance profileSyncInstance). 9a75ed6e-8724-4b0d-a371-6ef8d197f1b3
    02.14.2013 14:16:49.63 OWSTIMER.EXE (0x1780) 0x0DA4 SharePoint Portal Server User Profiles 9i1u Medium UserProfileApplication.SynchronizeMIIS: End setup for 'User Profiles Service'. 9a75ed6e-8724-4b0d-a371-6ef8d197f1b3
    02.14.2013 14:17:16.66 OWSTIMER.EXE (0x1780) 0x05EC SharePoint Portal Server User Profiles 9i1s Medium UserProfileApplication.SynchronizeMIIS: Begin setup for 'User Profiles Service'. 83917bf3-d2c7-4069-9d0c-7fe009171546


    Nothing new here...

    Thursday, February 14, 2013 10:43 AM
  • No, nothing new there at all...

    Go into CA -> Monitoring -> Configuring diagnostic logging

    Under the SharePoint Server, check User Profile and User Profile Manager.  Select Verbose under the Trace section below.  Hit OK and repeat the issue.


    SharePoint - Nauplius Applications
    Microsoft SharePoint Server MVP
    MCITP: SharePoint Administrator 2010

    -----------------------
    This post is my own opinion and does not necessarily reflect the opinion or view of Microsoft, its employees, or other MVPs.

    Thursday, February 14, 2013 7:51 PM
  • Trevor, I'm sorry for such a late answer, just couldn't start UPS due to some temporary errors.

    I did what you suggested step by step, still got the same error in logs and I don't see any new records in ULS associated with User Profiles if sorted by category="User Profiles". I can post it here, but its absolutely same as the above one...

    Monday, February 18, 2013 10:32 AM
  • I've just run into a similar problem but with SP 2013 - in our case the User Profile Synchronization service was stuck on "Starting", and eventually failed to start (along with the corresponding FIM services).  We discovered after about 15 hours of troubleshooting that the farm account needs internet access to do a CRL check to these sites:

    crl.microsoft.com
    ctldl.windowsupdate.com
    ctldl.windowsupdate.nsatc.net
    www.update.microsoft.com.nsatc.net

    The error we were getting in the ULS log seems to be the same as yours:

    UserProfileApplication.SynchronizeMIIS: Failed to configure ILM, will attempt during next rerun. Exception: System.FormatException: Index (zero based) must be greater than or equal to zero and less than the size of the argument list.   

    Hope that helps.

     
    • Proposed as answer by Nik Patel Saturday, June 29, 2013 2:03 AM
    • Marked as answer by Trevor SewardMVP Wednesday, August 21, 2013 10:18 PM
    Sunday, March 24, 2013 12:31 AM
  • Oh!

    Are you sure that farm account needs an internet access? Could you please post some proofs? 

    The farm doesn't have an internet access, so I also supposed that it could be the reason but didn't find any info about it...

    Sunday, April 7, 2013 5:38 PM
  • The farm does not need Internet access in order for the UPSS to provision successfully.  There is another issue when the farm does not have Internet access with regards to CRLs:

    http://support.microsoft.com/kb/2625048


    SharePoint - Nauplius Applications
    Microsoft SharePoint Server MVP
    MCITP: SharePoint Administrator 2010

    -----------------------
    This post is my own opinion and does not necessarily reflect the opinion or view of Microsoft, its employees, or other MVPs.

    Sunday, April 7, 2013 5:40 PM
  • Hi guys,

    I'm not in the country at the moment and tied up with other projects so I'm not in a position to try and reproduce this again and give you proofs - but in our environment (maybe ours is different somehow), I definitely needed to give my farm proxy access.  I was using a VM and to prove my theory after it finally worked with the proxy access, I rolled back to my snapshot just before provisioning the UPSS, removed proxy access, and it failed.  Added proxy access again, and it succeeded.

    During the provisioning process I was examining my DNS cache using ipconfig /displaydns and that's what showed me the sites the server was trying to resolve and get to.  Once I enabled the proxy, i could see connections build up to our proxy by doing a netstat.

    Trevor, we also had the issue outlined in the KB you posted - but I had done those steps prior to my provisioning issue with UPSS.

    Again might be something weird and unique in our environment, but thought i'd share it since i wasted many hours on it.

    cheers

    Ray

    • Proposed as answer by Sandar Tuesday, July 9, 2013 1:22 AM
    Sunday, April 7, 2013 6:07 PM
  • That would be something unique with your environment.  The UPSS does not require Internet access.

    SharePoint - Nauplius Applications
    Microsoft SharePoint Server MVP
    MCITP: SharePoint Administrator 2010

    -----------------------
    This post is my own opinion and does not necessarily reflect the opinion or view of Microsoft, its employees, or other MVPs.

    Sunday, April 7, 2013 6:09 PM
  • Wow!!! Thanks to Raymond Diack..

    I simply can't believe it but I was having this issue in my offline environment.. I came across same error - UserProfileApplication.SynchronizeMIIS: Failed to configure ILM, will attempt during next rerun. Exception: System.FormatException..

    After enabling internet in my VM.. I was able to start the User Profile Sync Service.. I haven't traced any internet traffic but I am planning to do it to see what triggers User Profile Sync to access internet... This is unusual fix but it does the job.. Thanks Raymond....

    Nik


    Nik Patel
    Slalom Consulting
    Blog: http://nikspatel.wordpress.com
    Follow me at http://twitter.com/nikxpatel

    Saturday, June 29, 2013 2:03 AM
  • Cool Nik - glad this (rather unorthodox!) 'fix' was helpful.  
    Monday, July 1, 2013 9:36 PM
  • Love that you're so certain...

    Just had this exact same scenario in our SharePoint 2013 farm. Getting error: "Failed to configure ILM, will attempt during next rerun. Exception: System.FormatException: Index (zero based) must be greater than or equal to zero and less than the size of the argument list."

    We then changed the firewall ruleset to allow the application server access to the internet and the UPSS came right up.

    Monday, July 8, 2013 2:45 PM
  • Hi ,

    It might be late but I thought I should share my experience which could help someone.

    I was also facing the same issue.

    Error 1: UserProfileApplication.SynchronizeMIIS: Failed to configure ILM, will attempt during next rerun.

    Error 2 : UserProfileApplication.SynchronizeMIIS: Error updating users with FIM permissions: System.ServiceModel.ProtocolException:

    When I was reading this article about having internet access for the farm account. I found that, Internet was enable on my server and due to which, My Synchronization service was stuck on "Starting" and and eventually failing to start.

    Later disabling this my Synchronization service was started without an error.

    Regards,

    Yogendra


    My name is yogendra


    Wednesday, September 25, 2013 3:17 PM
  • Just to follow up on this solution.  Looks like this is only needed in order to establish/validate the FIM Certs that are created during the provisioning process when starting the UPS Service for the first time on a SharePoint server.  I have a Test server on a separate domain from our Production server, neither of them have access outside of our network yet the Test server has UPS working just fine.  I could not get the User Profile Synchronization Service to start on our Production server until I opened up access to these sites through our Firewall.

    My guess is that the server does a one-time ping to Microsoft when creating the cert and then never needs to "phone home" again unless you delete UPS and recreate it.  I'm also wondering if this is the result of a CU or SP as my Test server has had UPS up and running for well over a year and probably didn't even have SP1 installed at the time UPS was configured and my Production Server was already at SP2 (14.0.7015.1000) when I tried to configure UPS.  Either that or my Test server had WWW access at the time USP was configured and then it was removed at a later date; I honestly don't recall as we have a separate network team that handles our firewall and like I said the Test server was setup over a year ago.

    • Edited by tlgnome24 Friday, February 7, 2014 8:22 PM
    Friday, February 7, 2014 8:17 PM
  • I've just confirmed this is still a problem, on a SharePoint 2013 farm with Dec 2018 CU I inherited recently. As per the above suggestions about "internet access" for the addresses, I just put an entry in the HOSTS file pointed back at 127.0.0.1 and it's finally provisioning fine - hope that helps someone
    Monday, April 8, 2019 3:09 PM