MS CRM 2016 SharePoint integration error "The server encountered an error processing the request. see server logs for more details."

while setting up ms crm 2016 and sharepoint 2016 server side for document management, I got below error while accessing metadataendpoint URL http://crmbox:81/XrmServices/2015/metadataendpoint.svc/json/?orgName=Agency

this message was not enough to understand.



hence I have used crm diagnostic tool to get more details of error.

after running the tool I got below details in log .. just see the highlighted one

SELECT  Id, [CertificateData], [Name], [ParentId], [StoreFindType], [StoreLocation], [StoreName], [Type]  FROM [Certificates]   WHERE ((([Type] = 'S2STokenIssuer'))  OR (([Type] = 'AlternativeS2STokenIssuer')) )

when I ran this query in MSCRM_CONFIG DB, I got no result. but in another env, where it was working fine, I got one result.

then another message in the log file said

TraceHandledException.aspxHandling an exception. Exception details: Microsoft.Crm.CrmException: No S2STokenIssuer certificate present in config database.

this says very clearly that there is no S2TokenIssuer. so found that, some how below command was not executed . you can follow https://technet.microsoft.com/en-us/library/dn949332.aspx for details of document management.

.\CertificateReconfiguration.ps1 -certificateFile c:\Personalcertfile.pfx -password personal_certfile_password -updateCrm -certificateType S2STokenIssuer -serviceAccount contoso\CRMAsyncService -storeFindType FindBySubjectDistinguishedName

details log

# CRM Tracing Version 2.0 # LocalTime: 2016-09-08 14:48:03.321 # Categories: *:Verbose # CallStackOn: No # ComputerName: CRMBOX # CRMVersion: 8.0.0000.1088 # DeploymentType: OnPremise # ScaleGroup: # ServerRole: AppServer, AsyncService, DiscoveryService, ApiServer, HelpServer, DeploymentService, SandboxServer, DeploymentManagementTools, VssWriter, EmailConnector   [2016-09-08 14:48:03.321] Process: w3wp |Organization:00000000-0000-0000-0000-000000000000 |Thread:   13 |Category: Shared |User: 00000000-0000-0000-0000-000000000000 |Level: Verbose |ReqId: 00000000-0000-0000-0000-000000000000 | CrmDbConnection.Open  ilOffset = 0x2E >ConnectionString: Data Source=crmbox.agency.local;Initial Catalog=MSCRM_CONFIG;Integrated Security=True;Min Pool Size=2;Connect Timeout=150;Workstation ID=CRMBOX.w3wp. [2016-09-08 14:48:03.416] Process: w3wp |Organization:00000000-0000-0000-0000-000000000000 |Thread:   13 |Category: Platform.Sql |User: 00000000-0000-0000-0000-000000000000 |Level: Verbose |ReqId: 00000000-0000-0000-0000-000000000000 | CrmDbConnection.InternalExecuteReader  ilOffset = 0x1C >SELECT  Id, [ActiveEndpoint], [ActiveMexEndpoint], [Enabled], [IdentityClaim], [MetadataUri], [Name], [PassiveEndpoint], [RelyingPartyActiveIdentifier], [RelyingPartyPassiveIdentifier]  FROM [FederationProvider]   WHERE ((([Id] = '26332692-cd1e-4dd6-bd5b-07326c43302e')) ) [2016-09-08 14:48:03.431] Process: w3wp |Organization:00000000-0000-0000-0000-000000000000 |Thread:   13 |Category: Platform.Sql |User: 00000000-0000-0000-0000-000000000000 |Level: Verbose |ReqId: 00000000-0000-0000-0000-000000000000 | CrmDbConnection.ExecuteReader  ilOffset = 0x9 >Query execution time: 0.0 seconds; database: MSCRM_CONFIG; Server:crmbox.agency.local; command: SELECT  Id, [ActiveEndpoint], [ActiveMexEndpoint], [Enabled], [IdentityClaim], [MetadataUri], [Name], [PassiveEndpoint], [RelyingPartyActiveIdentifier], [RelyingPartyPassiveIdentifier]  FROM [FederationProvider]   WHERE ((([Id] = '26332692-cd1e-4dd6-bd5b-07326c43302e')) ) ; CommandTimeout: 30. [2016-09-08 14:48:03.431] Process: w3wp |Organization:00000000-0000-0000-0000-000000000000 |Thread:   13 |Category: Platform.Sql |User: 00000000-0000-0000-0000-000000000000 |Level: Verbose |ReqId: 00000000-0000-0000-0000-000000000000 | CrmDbConnection.InternalExecuteReader  ilOffset = 0x1C >SELECT [Id], ColumnName, BigIntColumn, IntColumn, SmallIntColumn, TinyIntColumn, BitColumn, FloatColumn, DateTimeColumn, SmallDateTimeColumn, NVarCharColumn, UniqueIdentifierColumn, VarBinaryColumn FROM [FederationProviderProperties]  WHERE Id IN (SELECT [Id] FROM [FederationProvider]  WHERE ((([Id] = '26332692-cd1e-4dd6-bd5b-07326c43302e')) )) [2016-09-08 14:48:03.431] Process: w3wp |Organization:00000000-0000-0000-0000-000000000000 |Thread:   13 |Category: Platform.Sql |User: 00000000-0000-0000-0000-000000000000 |Level: Verbose |ReqId: 00000000-0000-0000-0000-000000000000 | CrmDbConnection.ExecuteReader  ilOffset = 0x9 >Query execution time: 0.0 seconds; database: MSCRM_CONFIG; Server:crmbox.agency.local; command: SELECT [Id], ColumnName, BigIntColumn, IntColumn, SmallIntColumn, TinyIntColumn, BitColumn, FloatColumn, DateTimeColumn, SmallDateTimeColumn, NVarCharColumn, UniqueIdentifierColumn, VarBinaryColumn FROM [FederationProviderProperties]  WHERE Id IN (SELECT [Id] FROM [FederationProvider]  WHERE ((([Id] = '26332692-cd1e-4dd6-bd5b-07326c43302e')) )); CommandTimeout: 30. [2016-09-08 14:48:03.431] Process: w3wp |Organization:00000000-0000-0000-0000-000000000000 |Thread:   13 |Category: Shared |User: 00000000-0000-0000-0000-000000000000 |Level: Verbose |ReqId: 00000000-0000-0000-0000-000000000000 | CrmDbConnection.Open  ilOffset = 0x2E >ConnectionString: Data Source=crmbox.agency.local;Initial Catalog=MSCRM_CONFIG;Integrated Security=True;Min Pool Size=2;Connect Timeout=150;Workstation ID=CRMBOX.w3wp. [2016-09-08 14:48:03.431] Process: w3wp |Organization:00000000-0000-0000-0000-000000000000 |Thread:   13 |Category: Platform.Sql |User: 00000000-0000-0000-0000-000000000000 |Level: Verbose |ReqId: 00000000-0000-0000-0000-000000000000 | CrmDbConnection.InternalExecuteReader  ilOffset = 0x1C >SELECT  Id  FROM [DataEncryptionKey]   WHERE ((([IsConfigurationRow] = 1)) ) [2016-09-08 14:48:03.431] Process: w3wp |Organization:00000000-0000-0000-0000-000000000000 |Thread:   13 |Category: Platform.Sql |User: 00000000-0000-0000-0000-000000000000 |Level: Verbose |ReqId: 00000000-0000-0000-0000-000000000000 | CrmDbConnection.ExecuteReader  ilOffset = 0x9 >Query execution time: 0.0 seconds; database: MSCRM_CONFIG; Server:crmbox.agency.local; command: SELECT  Id  FROM [DataEncryptionKey]   WHERE ((([IsConfigurationRow] = 1)) ) ; CommandTimeout: 30. [2016-09-08 14:48:03.431] Process: w3wp |Organization:00000000-0000-0000-0000-000000000000 |Thread:   13 |Category: Shared |User: 00000000-0000-0000-0000-000000000000 |Level: Verbose |ReqId: 00000000-0000-0000-0000-000000000000 | CrmDbConnection.Open  ilOffset = 0x2E >ConnectionString: Data Source=crmbox.agency.local;Initial Catalog=MSCRM_CONFIG;Integrated Security=True;Min Pool Size=2;Connect Timeout=150;Workstation ID=CRMBOX.w3wp. [2016-09-08 14:48:03.431] Process: w3wp |Organization:00000000-0000-0000-0000-000000000000 |Thread:   13 |Category: Platform.Sql |User: 00000000-0000-0000-0000-000000000000 |Level: Verbose |ReqId: 00000000-0000-0000-0000-000000000000 | CrmDbConnection.InternalExecuteReader  ilOffset = 0x1C >SELECT  Id, [CrmKeyName]  FROM [DataEncryptionKey]   WHERE ((([IsConfigurationRow] = 0)) ) [2016-09-08 14:48:03.431] Process: w3wp |Organization:00000000-0000-0000-0000-000000000000 |Thread:   13 |Category: Platform.Sql |User: 00000000-0000-0000-0000-000000000000 |Level: Verbose |ReqId: 00000000-0000-0000-0000-000000000000 | CrmDbConnection.ExecuteReader  ilOffset = 0x9 >Query execution time: 0.0 seconds; database: MSCRM_CONFIG; Server:crmbox.agency.local; command: SELECT  Id, [CrmKeyName]  FROM [DataEncryptionKey]   WHERE ((([IsConfigurationRow] = 0)) ) ; CommandTimeout: 30. [2016-09-08 14:48:03.431] Process: w3wp |Organization:00000000-0000-0000-0000-000000000000 |Thread:   13 |Category: Shared |User: 00000000-0000-0000-0000-000000000000 |Level: Verbose |ReqId: 00000000-0000-0000-0000-000000000000 | CrmDbConnection.Open  ilOffset = 0x2E >ConnectionString: Data Source=crmbox.agency.local;Initial Catalog=MSCRM_CONFIG;Integrated Security=True;Min Pool Size=2;Connect Timeout=150;Workstation ID=CRMBOX.w3wp. [2016-09-08 14:48:03.431] Process: w3wp |Organization:00000000-0000-0000-0000-000000000000 |Thread:   13 |Category: Platform.Sql |User: 00000000-0000-0000-0000-000000000000 |Level: Verbose |ReqId: 00000000-0000-0000-0000-000000000000 | CrmDbConnection.InternalExecuteReader  ilOffset = 0x1C >SELECT  Id, [UniqueName], [State]  FROM [Organization]   [2016-09-08 14:48:03.431] Process: w3wp |Organization:00000000-0000-0000-0000-000000000000 |Thread:   13 |Category: Platform.Sql |User: 00000000-0000-0000-0000-000000000000 |Level: Verbose |ReqId: 00000000-0000-0000-0000-000000000000 | CrmDbConnection.ExecuteReader  ilOffset = 0x9 >Query execution time: 0.0 seconds; database: MSCRM_CONFIG; Server:crmbox.agency.local; command: SELECT  Id, [UniqueName], [State]  FROM [Organization]   ; CommandTimeout: 30. [2016-09-08 14:48:04.228] Process: w3wp |Organization:00000000-0000-0000-0000-000000000000 |Thread:   18(MSCRM:-NotificationManager.NotificationWatcherThreadProc) |Category: Platform |User: 00000000-0000-0000-0000-000000000000 |Level: Warning |ReqId: 00000000-0000-0000-0000-000000000000 | ExecutionContext.RunInternal  ilOffset = 0x79 >NotificationWatcherThread Started. [2016-09-08 14:48:04.244] Process: w3wp |Organization:00000000-0000-0000-0000-000000000000 |Thread:   19(MSCRM:-MetadataCache.RemoveUnusedCachesThreadProc) |Category: Platform |User: 00000000-0000-0000-0000-000000000000 |Level: Info |ReqId: 00000000-0000-0000-0000-000000000000 | ExecutionContext.RunInternal  ilOffset = 0x79 >RemoveUnusedCachesThreadProc Started. [2016-09-08 14:48:04.259] Process: w3wp |Organization:00000000-0000-0000-0000-000000000000 |Thread:   13 |Category: Shared |User: 00000000-0000-0000-0000-000000000000 |Level: Verbose |ReqId: 00000000-0000-0000-0000-000000000000 | CrmDbConnection.Open  ilOffset = 0x2E >ConnectionString: Data Source=crmbox.agency.local;Initial Catalog=MSCRM_CONFIG;Integrated Security=True;Min Pool Size=2;Connect Timeout=150;Workstation ID=CRMBOX.w3wp. [2016-09-08 14:48:04.259] Process: w3wp |Organization:00000000-0000-0000-0000-000000000000 |Thread:   13 |Category: Platform.Sql |User: 00000000-0000-0000-0000-000000000000 |Level: Verbose |ReqId: 00000000-0000-0000-0000-000000000000 | CrmDbConnection.InternalExecuteReader  ilOffset = 0x1C >SELECT  Id  FROM [Server]   WHERE ((([Name] = 'CRMBOX')) ) [2016-09-08 14:48:04.259] Process: w3wp |Organization:00000000-0000-0000-0000-000000000000 |Thread:   13 |Category: Platform.Sql |User: 00000000-0000-0000-0000-000000000000 |Level: Verbose |ReqId: 00000000-0000-0000-0000-000000000000 | CrmDbConnection.ExecuteReader  ilOffset = 0x9 >Query execution time: 0.0 seconds; database: MSCRM_CONFIG; Server:crmbox.agency.local; command: SELECT  Id  FROM [Server]   WHERE ((([Name] = 'CRMBOX')) ) ; CommandTimeout: 30. [2016-09-08 14:48:04.259] Process: w3wp |Organization:00000000-0000-0000-0000-000000000000 |Thread:   13 |Category: Shared |User: 00000000-0000-0000-0000-000000000000 |Level: Verbose |ReqId: 00000000-0000-0000-0000-000000000000 | CrmDbConnection.Open  ilOffset = 0x2E >ConnectionString: Data Source=crmbox.agency.local;Initial Catalog=MSCRM_CONFIG;Integrated Security=True;Min Pool Size=2;Connect Timeout=150;Workstation ID=CRMBOX.w3wp. [2016-09-08 14:48:04.259] Process: w3wp |Organization:00000000-0000-0000-0000-000000000000 |Thread:   13 |Category: Platform.Sql |User: 00000000-0000-0000-0000-000000000000 |Level: Verbose |ReqId: 00000000-0000-0000-0000-000000000000 | CrmDbConnection.InternalExecuteReader  ilOffset = 0x1C >SELECT  Id, [DatacenterId], [FullName], [Name], [PodId], [Roles], [ScaleGroupId], [State], [StorageGroupId], [UniqueifierId], [Version]  FROM [Server]   WHERE ((([Id] = '746c799a-2544-e611-80be-080027c30349')) ) [2016-09-08 14:48:04.259] Process: w3wp |Organization:00000000-0000-0000-0000-000000000000 |Thread:   13 |Category: Platform.Sql |User: 00000000-0000-0000-0000-000000000000 |Level: Verbose |ReqId: 00000000-0000-0000-0000-000000000000 | CrmDbConnection.ExecuteReader  ilOffset = 0x9 >Query execution time: 0.0 seconds; database: MSCRM_CONFIG; Server:crmbox.agency.local; command: SELECT  Id, [DatacenterId], [FullName], [Name], [PodId], [Roles], [ScaleGroupId], [State], [StorageGroupId], [UniqueifierId], [Version]  FROM [Server]   WHERE ((([Id] = '746c799a-2544-e611-80be-080027c30349')) ) ; CommandTimeout: 30. [2016-09-08 14:48:04.259] Process: w3wp |Organization:00000000-0000-0000-0000-000000000000 |Thread:   13 |Category: Platform.Sql |User: 00000000-0000-0000-0000-000000000000 |Level: Verbose |ReqId: 00000000-0000-0000-0000-000000000000 | CrmDbConnection.InternalExecuteReader  ilOffset = 0x1C >SELECT [Id], ColumnName, BigIntColumn, IntColumn, SmallIntColumn, TinyIntColumn, BitColumn, FloatColumn, DateTimeColumn, SmallDateTimeColumn, NVarCharColumn, UniqueIdentifierColumn, VarBinaryColumn FROM [ServerProperties]  WHERE Id IN (SELECT [Id] FROM [Server]  WHERE ((([Id] = '746c799a-2544-e611-80be-080027c30349')) )) [2016-09-08 14:48:04.259] Process: w3wp |Organization:00000000-0000-0000-0000-000000000000 |Thread:   13 |Category: Platform.Sql |User: 00000000-0000-0000-0000-000000000000 |Level: Verbose |ReqId: 00000000-0000-0000-0000-000000000000 | CrmDbConnection.ExecuteReader  ilOffset = 0x9 >Query execution time: 0.0 seconds; database: MSCRM_CONFIG; Server:crmbox.agency.local; command: SELECT [Id], ColumnName, BigIntColumn, IntColumn, SmallIntColumn, TinyIntColumn, BitColumn, FloatColumn, DateTimeColumn, SmallDateTimeColumn, NVarCharColumn, UniqueIdentifierColumn, VarBinaryColumn FROM [ServerProperties]  WHERE Id IN (SELECT [Id] FROM [Server]  WHERE ((([Id] = '746c799a-2544-e611-80be-080027c30349')) )); CommandTimeout: 30. [2016-09-08 14:48:04.259] Process: w3wp |Organization:00000000-0000-0000-0000-000000000000 |Thread:   13 |Category: Etm |User: 00000000-0000-0000-0000-000000000000 |Level: Info |ReqId: 00000000-0000-0000-0000-000000000000 | RequestGovernor.Initialize  ilOffset = 0xB >RequestGovernor disabled [2016-09-08 14:48:04.259] Process: w3wp |Organization:00000000-0000-0000-0000-000000000000 |Thread:   13 |Category: Platform |User: 00000000-0000-0000-0000-000000000000 |Level: Verbose |ReqId: 00000000-0000-0000-0000-000000000000 | VirtualPathProviderInitializer.Microsoft.Crm.IApplicationInitializer.Initialize  ilOffset = 0x13 >Initialize MapOrgVirtualPathProvider. [2016-09-08 14:48:04.274] Process: w3wp |Organization:00000000-0000-0000-0000-000000000000 |Thread:   13 |Category: Sandbox.LoadBalancer |User: 00000000-0000-0000-0000-000000000000 |Level: Info |ReqId: 00000000-0000-0000-0000-000000000000 | RunInitializerTracker.TryRun  ilOffset = 0x29 >Initialize: enter [2016-09-08 14:48:04.274] Process: w3wp |Organization:00000000-0000-0000-0000-000000000000 |Thread:   13 |Category: Sandbox.LoadBalancer |User: 00000000-0000-0000-0000-000000000000 |Level: Info |ReqId: 00000000-0000-0000-0000-000000000000 | RunInitializerTracker.TryRun  ilOffset = 0x29 >Initialize: first time [2016-09-08 14:48:04.274] Process: w3wp |Organization:00000000-0000-0000-0000-000000000000 |Thread:   13 |Category: Sandbox.StartStop |User: 00000000-0000-0000-0000-000000000000 |Level: Info |ReqId: 00000000-0000-0000-0000-000000000000 | SandboxHostManager.Initialize  ilOffset = 0x49 >SandboxTraceProvider.Initialize: enter [2016-09-08 14:48:04.274] Process: w3wp |Organization:00000000-0000-0000-0000-000000000000 |Thread:   13 |Category: Sandbox.StartStop |User: 00000000-0000-0000-0000-000000000000 |Level: Info |ReqId: 00000000-0000-0000-0000-000000000000 | SandboxHostManager.Initialize  ilOffset = 0x49 >SandboxTraceProvider.Initialize: exit [2016-09-08 14:48:04.274] Process: w3wp |Organization:00000000-0000-0000-0000-000000000000 |Thread:   13 |Category: Sandbox.StartStop |User: 00000000-0000-0000-0000-000000000000 |Level: Info |ReqId: 00000000-0000-0000-0000-000000000000 | SandboxPerformanceCounter.InitializeCounters  ilOffset = 0x16 >_eventSource: MSCRMSandboxClient [2016-09-08 14:48:04.274] Process: w3wp |Organization:00000000-0000-0000-0000-000000000000 |Thread:   13 |Category: Sandbox.LoadBalancer |User: 00000000-0000-0000-0000-000000000000 |Level: Info |ReqId: 00000000-0000-0000-0000-000000000000 | SandboxHostManager.Initialize  ilOffset = 0x53 >InitializeInternal: enter [2016-09-08 14:48:04.290] Process: w3wp |Organization:00000000-0000-0000-0000-000000000000 |Thread:   13 |Category: Sandbox.StartStop |User: 00000000-0000-0000-0000-000000000000 |Level: Info |ReqId: 00000000-0000-0000-0000-000000000000 | SandboxHostManager.GetDeploymentProperties  ilOffset = 0x18 >deploymentSettingName: SandboxHostMinWorkerProcesses [2016-09-08 14:48:04.290] Process: w3wp |Organization:00000000-0000-0000-0000-000000000000 |Thread:   13 |Category: Sandbox.StartStop |User: 00000000-0000-0000-0000-000000000000 |Level: Info |ReqId: 00000000-0000-0000-0000-000000000000 | SandboxHostManager.GetDeploymentProperties  ilOffset = 0x18 >deploymentSettingName: SandboxHostMaxWorkerProcesses [2016-09-08 14:48:04.290] Process: w3wp |Organization:00000000-0000-0000-0000-000000000000 |Thread:   13 |Category: Sandbox.StartStop |User: 00000000-0000-0000-0000-000000000000 |Level: Info |ReqId: 00000000-0000-0000-0000-000000000000 | SandboxHostManager.GetDeploymentProperties  ilOffset = 0x18 >deploymentSettingName: SandboxHostMaxAssemblyCacheSizeInMByte [2016-09-08 14:48:04.290] Process: w3wp |Organization:00000000-0000-0000-0000-000000000000 |Thread:   13 |Category: Sandbox.StartStop |User: 00000000-0000-0000-0000-000000000000 |Level: Info |ReqId: 00000000-0000-0000-0000-000000000000 | SandboxHostManager.GetDeploymentProperties  ilOffset = 0x18 >deploymentSettingName: SandboxHostMaxWorkerProcessHandleCount [2016-09-08 14:48:04.290] Process: w3wp |Organization:00000000-0000-0000-0000-000000000000 |Thread:   13 |Category: Sandbox.StartStop |User: 00000000-0000-0000-0000-000000000000 |Level: Info |ReqId: 00000000-0000-0000-0000-000000000000 | SandboxHostManager.GetDeploymentProperties  ilOffset = 0x18 >deploymentSettingName: SandboxHostAssemblyCacheExpireTimeInMin [2016-09-08 14:48:04.290] Process: w3wp |Organization:00000000-0000-0000-0000-000000000000 |Thread:   13 |Category: Sandbox.StartStop |User: 00000000-0000-0000-0000-000000000000 |Level: Info |ReqId: 00000000-0000-0000-0000-000000000000 | SandboxHostManager.GetDeploymentProperties  ilOffset = 0x18 >deploymentSettingName: SandboxHostAssemblyCacheMonitorIntervalInMin [2016-09-08 14:48:04.290] Process: w3wp |Organization:00000000-0000-0000-0000-000000000000 |Thread:   13 |Category: Sandbox.StartStop |User: 00000000-0000-0000-0000-000000000000 |Level: Info |ReqId: 00000000-0000-0000-0000-000000000000 | SandboxHostManager.GetDeploymentProperties  ilOffset = 0x18 >deploymentSettingName: SandboxHostJobMemoryLimitHighPercent [2016-09-08 14:48:04.290] Process: w3wp |Organization:00000000-0000-0000-0000-000000000000 |Thread:   13 |Category: Sandbox.StartStop |User: 00000000-0000-0000-0000-000000000000 |Level: Info |ReqId: 00000000-0000-0000-0000-000000000000 | SandboxHostManager.GetDeploymentProperties  ilOffset = 0x18 >deploymentSettingName: SandboxHostJobMemoryLimitLowPercent [2016-09-08 14:48:04.290] Process: w3wp |Organization:00000000-0000-0000-0000-000000000000 |Thread:   13 |Category: Sandbox.StartStop |User: 00000000-0000-0000-0000-000000000000 |Level: Info |ReqId: 00000000-0000-0000-0000-000000000000 | SandboxHostManager.GetDeploymentProperties  ilOffset = 0x18 >deploymentSettingName: SandboxHostWorkerProcessMemoryLimitPercent [2016-09-08 14:48:04.290] Process: w3wp |Organization:00000000-0000-0000-0000-000000000000 |Thread:   13 |Category: Sandbox.StartStop |User: 00000000-0000-0000-0000-000000000000 |Level: Info |ReqId: 00000000-0000-0000-0000-000000000000 | SandboxHostManager.GetDeploymentProperties  ilOffset = 0x18 >deploymentSettingName: SandboxHostJobCpuUsageLimitPercent [2016-09-08 14:48:04.290] Process: w3wp |Organization:00000000-0000-0000-0000-000000000000 |Thread:   13 |Category: Sandbox.StartStop |User: 00000000-0000-0000-0000-000000000000 |Level: Info |ReqId: 00000000-0000-0000-0000-000000000000 | SandboxHostManager.GetDeploymentProperties  ilOffset = 0x18 >deploymentSettingName: SandboxHostReservedCpuCount [2016-09-08 14:48:04.290] Process: w3wp |Organization:00000000-0000-0000-0000-000000000000 |Thread:   13 |Category: Sandbox.StartStop |User: 00000000-0000-0000-0000-000000000000 |Level: Info |ReqId: 00000000-0000-0000-0000-000000000000 | SandboxHostManager.GetDeploymentProperties  ilOffset = 0x18 >deploymentSettingName: SandboxHostCpuPerJobCount [2016-09-08 14:48:04.290] Process: w3wp |Organization:00000000-0000-0000-0000-000000000000 |Thread:   13 |Category: Sandbox.StartStop |User: 00000000-0000-0000-0000-000000000000 |Level: Info |ReqId: 00000000-0000-0000-0000-000000000000 | SandboxHostManager.GetDeploymentProperties  ilOffset = 0x18 >deploymentSettingName: SandboxHostPingOperationTimeoutInSec [2016-09-08 14:48:04.290] Process: w3wp |Organization:00000000-0000-0000-0000-000000000000 |Thread:   13 |Category: Sandbox.StartStop |User: 00000000-0000-0000-0000-000000000000 |Level: Info |ReqId: 00000000-0000-0000-0000-000000000000 | SandboxHostManager.GetDeploymentProperties  ilOffset = 0x18 >deploymentSettingName: SandboxHostMaxWorkerCpuUsageLimitPercent [2016-09-08 14:48:04.290] Process: w3wp |Organization:00000000-0000-0000-0000-000000000000 |Thread:   13 |Category: Sandbox.StartStop |User: 00000000-0000-0000-0000-000000000000 |Level: Info |ReqId: 00000000-0000-0000-0000-000000000000 | SandboxHostManager.GetDeploymentProperties  ilOffset = 0x1E >deploymentSettingName: SandboxWorkerMaxWorkerIdleTimeInMin [2016-09-08 14:48:04.290] Process: w3wp |Organization:00000000-0000-0000-0000-000000000000 |Thread:   13 |Category: Sandbox.StartStop |User: 00000000-0000-0000-0000-000000000000 |Level: Info |ReqId: 00000000-0000-0000-0000-000000000000 | SandboxHostManager.GetDeploymentProperties  ilOffset = 0x1E >deploymentSettingName: SandboxWorkerMaxWorkerLifetimeInMin [2016-09-08 14:48:04.290] Process: w3wp |Organization:00000000-0000-0000-0000-000000000000 |Thread:   13 |Category: Sandbox.StartStop |User: 00000000-0000-0000-0000-000000000000 |Level: Info |ReqId: 00000000-0000-0000-0000-000000000000 | SandboxHostManager.GetDeploymentProperties  ilOffset = 0x1E >deploymentSettingName: SandboxWorkerShutdownTimeInMinutes [2016-09-08 14:48:04.290] Process: w3wp |Organization:00000000-0000-0000-0000-000000000000 |Thread:   13 |Category: Platform |User: 00000000-0000-0000-0000-000000000000 |Level: Info |ReqId: 00000000-0000-0000-0000-000000000000 | SandboxHostManager.GetDeploymentProperties  ilOffset = 0x1E >NestingDepth: 24 [2016-09-08 14:48:04.290] Process: w3wp |Organization:00000000-0000-0000-0000-000000000000 |Thread:   13 |Category: Platform |User: 00000000-0000-0000-0000-000000000000 |Level: Info |ReqId: 00000000-0000-0000-0000-000000000000 | SandboxHostManager.GetDeploymentProperties  ilOffset = 0x1E >IncludeCallStack: True [2016-09-08 14:48:04.306] Process: w3wp |Organization:00000000-0000-0000-0000-000000000000 |Thread:   13 |Category: Platform |User: 00000000-0000-0000-0000-000000000000 |Level: Verbose |ReqId: 00000000-0000-0000-0000-000000000000 | CrmServerService.RetrieveServersInPod  ilOffset = 0x29 >Retrieve multiple Servers [2016-09-08 14:48:04.306] Process: w3wp |Organization:00000000-0000-0000-0000-000000000000 |Thread:   13 |Category: Shared |User: 00000000-0000-0000-0000-000000000000 |Level: Verbose |ReqId: 00000000-0000-0000-0000-000000000000 | CrmDbConnection.Open  ilOffset = 0x2E >ConnectionString: Data Source=crmbox.agency.local;Initial Catalog=MSCRM_CONFIG;Integrated Security=True;Min Pool Size=2;Connect Timeout=150;Workstation ID=CRMBOX.w3wp. [2016-09-08 14:48:04.306] Process: w3wp |Organization:00000000-0000-0000-0000-000000000000 |Thread:   13 |Category: Platform.Sql |User: 00000000-0000-0000-0000-000000000000 |Level: Verbose |ReqId: 00000000-0000-0000-0000-000000000000 | CrmDbConnection.InternalExecuteReader  ilOffset = 0x1C >SELECT  Id, [DatacenterId], [FullName], [Name], [PodId], [Roles], [ScaleGroupId], [State], [StorageGroupId], [UniqueifierId], [Version]  FROM [Server]   WHERE ((([State] = Enabled)) ) [2016-09-08 14:48:04.306] Process: w3wp |Organization:00000000-0000-0000-0000-000000000000 |Thread:   13 |Category: Platform.Sql |User: 00000000-0000-0000-0000-000000000000 |Level: Verbose |ReqId: 00000000-0000-0000-0000-000000000000 | CrmDbConnection.ExecuteReader  ilOffset = 0x9 >Query execution time: 0.0 seconds; database: MSCRM_CONFIG; Server:crmbox.agency.local; command: SELECT  Id, [DatacenterId], [FullName], [Name], [PodId], [Roles], [ScaleGroupId], [State], [StorageGroupId], [UniqueifierId], [Version]  FROM [Server]   WHERE ((([State] = Enabled)) ) ; CommandTimeout: 30. [2016-09-08 14:48:04.306] Process: w3wp |Organization:00000000-0000-0000-0000-000000000000 |Thread:   13 |Category: Platform.Sql |User: 00000000-0000-0000-0000-000000000000 |Level: Verbose |ReqId: 00000000-0000-0000-0000-000000000000 | CrmDbConnection.InternalExecuteReader  ilOffset = 0x1C >SELECT [Id], ColumnName, BigIntColumn, IntColumn, SmallIntColumn, TinyIntColumn, BitColumn, FloatColumn, DateTimeColumn, SmallDateTimeColumn, NVarCharColumn, UniqueIdentifierColumn, VarBinaryColumn FROM [ServerProperties]  WHERE Id IN (SELECT [Id] FROM [Server]  WHERE ((([State] = Enabled)) )) [2016-09-08 14:48:04.306] Process: w3wp |Organization:00000000-0000-0000-0000-000000000000 |Thread:   13 |Category: Platform.Sql |User: 00000000-0000-0000-0000-000000000000 |Level: Verbose |ReqId: 00000000-0000-0000-0000-000000000000 | CrmDbConnection.ExecuteReader  ilOffset = 0x9 >Query execution time: 0.0 seconds; database: MSCRM_CONFIG; Server:crmbox.agency.local; command: SELECT [Id], ColumnName, BigIntColumn, IntColumn, SmallIntColumn, TinyIntColumn, BitColumn, FloatColumn, DateTimeColumn, SmallDateTimeColumn, NVarCharColumn, UniqueIdentifierColumn, VarBinaryColumn FROM [ServerProperties]  WHERE Id IN (SELECT [Id] FROM [Server]  WHERE ((([State] = Enabled)) )); CommandTimeout: 30. [2016-09-08 14:48:04.306] Process: w3wp |Organization:00000000-0000-0000-0000-000000000000 |Thread:   13 |Category: Sandbox.LoadBalancer |User: 00000000-0000-0000-0000-000000000000 |Level: Info |ReqId: 00000000-0000-0000-0000-000000000000 | SandboxHostManager.Initialize  ilOffset = 0x53 >found Sandbox server: CRMBOX [2016-09-08 14:48:04.306] Process: w3wp |Organization:00000000-0000-0000-0000-000000000000 |Thread:   13 |Category: Sandbox.LoadBalancer |User: 00000000-0000-0000-0000-000000000000 |Level: Info |ReqId: 00000000-0000-0000-0000-000000000000 | SandboxHostManager.Initialize  ilOffset = 0x53 >sandboxServers.Count: 1 [2016-09-08 14:48:04.306] Process: w3wp |Organization:00000000-0000-0000-0000-000000000000 |Thread:   13 |Category: Sandbox.LoadBalancer |User: 00000000-0000-0000-0000-000000000000 |Level: Info |ReqId: 00000000-0000-0000-0000-000000000000 | SandboxHostManager.Initialize  ilOffset = 0x53 >server.Name: CRMBOX [2016-09-08 14:48:04.321] Process: w3wp |Organization:00000000-0000-0000-0000-000000000000 |Thread:   13 |Category: Sandbox.LoadBalancer |User: 00000000-0000-0000-0000-000000000000 |Level: Info |ReqId: 00000000-0000-0000-0000-000000000000 | SandboxHostManager.InitializeInternal  ilOffset = 0x154 >UpdateHostNames: newHostList.Count: 1 [2016-09-08 14:48:04.321] Process: w3wp |Organization:00000000-0000-0000-0000-000000000000 |Thread:   13 |Category: Sandbox.LoadBalancer |User: 00000000-0000-0000-0000-000000000000 |Level: Info |ReqId: 00000000-0000-0000-0000-000000000000 | SandboxHostManager.InitializeInternal  ilOffset = 0x154 >Adding host name: CRMBOX [2016-09-08 14:48:04.321] Process: w3wp |Organization:00000000-0000-0000-0000-000000000000 |Thread:   13 |Category: Sandbox.LoadBalancer |User: 00000000-0000-0000-0000-000000000000 |Level: Info |ReqId: 00000000-0000-0000-0000-000000000000 | SandboxHostManager.InitializeInternal  ilOffset = 0x154 >Updating host names [2016-09-08 14:48:04.321] Process: w3wp |Organization:00000000-0000-0000-0000-000000000000 |Thread:   13 |Category: Sandbox.LoadBalancer |User: 00000000-0000-0000-0000-000000000000 |Level: Info |ReqId: 00000000-0000-0000-0000-000000000000 | SandboxHostManager.InitializeInternal  ilOffset = 0x154 >UpdateHostNames: exit [2016-09-08 14:48:04.321] Process: w3wp |Organization:00000000-0000-0000-0000-000000000000 |Thread:   14 |Category: Sandbox |User: 00000000-0000-0000-0000-000000000000 |Level: Verbose |ReqId: 00000000-0000-0000-0000-000000000000 | ExecutionContext.RunInternal  ilOffset = 0x79 >AppDomain: /LM/W3SVC/2/ROOT-1-131177908824467939 [2016-09-08 14:48:04.321] Process: w3wp |Organization:00000000-0000-0000-0000-000000000000 |Thread:   13 |Category: Sandbox.LoadBalancer |User: 00000000-0000-0000-0000-000000000000 |Level: Info |ReqId: 00000000-0000-0000-0000-000000000000 | SandboxHostManager.Initialize  ilOffset = 0x53 >InitializeInternal: try to start SandboxSdkListener; _started: True, SandboxServers.Count: 1, SandboxSdkListener.ListenerStarted: False [2016-09-08 14:48:04.321] Process: w3wp |Organization:00000000-0000-0000-0000-000000000000 |Thread:   15 |Category: Sandbox |User: 00000000-0000-0000-0000-000000000000 |Level: Verbose |ReqId: 00000000-0000-0000-0000-000000000000 | ExecutionContext.RunInternal  ilOffset = 0x79 >Exiting WritePluginTraceLog [2016-09-08 14:48:04.321] Process: w3wp |Organization:00000000-0000-0000-0000-000000000000 |Thread:   20 |Category: Sandbox |User: 00000000-0000-0000-0000-000000000000 |Level: Info |ReqId: 00000000-0000-0000-0000-000000000000 | ExecutionContext.RunInternal  ilOffset = 0x79 >SdkListenerStarterThread: enter [2016-09-08 14:48:04.321] Process: w3wp |Organization:00000000-0000-0000-0000-000000000000 |Thread:   20 |Category: Sandbox.StartStop |User: 00000000-0000-0000-0000-000000000000 |Level: Info |ReqId: 00000000-0000-0000-0000-000000000000 | SandboxSdkListener.SdkListenerStarterThread  ilOffset = 0x1A >StartListening: _startListeningCount: 0 [2016-09-08 14:48:04.337] Process: w3wp |Organization:00000000-0000-0000-0000-000000000000 |Thread:   13 |Category: Sandbox.LoadBalancer |User: 00000000-0000-0000-0000-000000000000 |Level: Info |ReqId: 00000000-0000-0000-0000-000000000000 | SandboxHostManager.Initialize  ilOffset = 0x53 >InitializeInternal: exit [2016-09-08 14:48:04.337] Process: w3wp |Organization:00000000-0000-0000-0000-000000000000 |Thread:   13 |Category: Sandbox.LoadBalancer |User: 00000000-0000-0000-0000-000000000000 |Level: Info |ReqId: 00000000-0000-0000-0000-000000000000 | RunInitializerTracker.TryRun  ilOffset = 0x29 >Initialize: exit [2016-09-08 14:48:04.337] Process: w3wp |Organization:00000000-0000-0000-0000-000000000000 |Thread:   14 |Category: Sandbox.LoadBalancer |User: 00000000-0000-0000-0000-000000000000 |Level: Verbose |ReqId: 00000000-0000-0000-0000-000000000000 | SandboxHostManager.PingHosts  ilOffset = 0x35 >ENTER: PingHosts [2016-09-08 14:48:04.337] Process: w3wp |Organization:00000000-0000-0000-0000-000000000000 |Thread:   14 |Category: Sandbox.LoadBalancer |User: 00000000-0000-0000-0000-000000000000 |Level: Verbose |ReqId: 00000000-0000-0000-0000-000000000000 | SandboxHostManager.PingHosts  ilOffset = 0x35 >checking host names list for new machines: 1 [2016-09-08 14:48:04.337] Process: w3wp |Organization:00000000-0000-0000-0000-000000000000 |Thread:   14 |Category: Sandbox.LoadBalancer |User: 00000000-0000-0000-0000-000000000000 |Level: Verbose |ReqId: 00000000-0000-0000-0000-000000000000 | SandboxHostManager.PingHosts  ilOffset = 0x35 >in: ready clients: 0 [2016-09-08 14:48:04.337] Process: w3wp |Organization:00000000-0000-0000-0000-000000000000 |Thread:   14 |Category: Sandbox.LoadBalancer |User: 00000000-0000-0000-0000-000000000000 |Level: Verbose |ReqId: 00000000-0000-0000-0000-000000000000 | SandboxHostManager.PingHosts  ilOffset = 0x35 >in: pending clients: 0 [2016-09-08 14:48:04.337] Process: w3wp |Organization:00000000-0000-0000-0000-000000000000 |Thread:   14 |Category: Sandbox.LoadBalancer |User: 00000000-0000-0000-0000-000000000000 |Level: Verbose |ReqId: 00000000-0000-0000-0000-000000000000 | SandboxHostManager.PingHosts  ilOffset = 0x35 >checking: CRMBOX [2016-09-08 14:48:04.337] Process: w3wp |Organization:00000000-0000-0000-0000-000000000000 |Thread:   14 |Category: Sandbox.LoadBalancer |User: 00000000-0000-0000-0000-000000000000 |Level: Verbose |ReqId: 00000000-0000-0000-0000-000000000000 | SandboxHostManager.PingHosts  ilOffset = 0x35 >new machine name: CRMBOX [2016-09-08 14:48:04.337] Process: w3wp |Organization:00000000-0000-0000-0000-000000000000 |Thread:   14 |Category: Sandbox.StartStop |User: 00000000-0000-0000-0000-000000000000 |Level: Info |ReqId: 00000000-0000-0000-0000-000000000000 | SandboxHostManager.PingHostsInternal  ilOffset = 0x1F5 >_singleBox: True [2016-09-08 14:48:04.337] Process: w3wp |Organization:00000000-0000-0000-0000-000000000000 |Thread:   14 |Category: Sandbox.LoadBalancer |User: 00000000-0000-0000-0000-000000000000 |Level: Verbose |ReqId: 00000000-0000-0000-0000-000000000000 | SandboxHostManager.PingHosts  ilOffset = 0x35 >single box [2016-09-08 14:48:04.369] Process: w3wp |Organization:00000000-0000-0000-0000-000000000000 |Thread:   20 |Category: Sandbox.StartStop |User: 00000000-0000-0000-0000-000000000000 |Level: Info |ReqId: 00000000-0000-0000-0000-000000000000 | SandboxSdkListener.StartListening  ilOffset = 0x10C >Starting: SDK Listener [2016-09-08 14:48:04.384] Process: w3wp |Organization:00000000-0000-0000-0000-000000000000 |Thread:   20 |Category: Sandbox.StartStop |User: 00000000-0000-0000-0000-000000000000 |Level: Info |ReqId: 00000000-0000-0000-0000-000000000000 | SandboxSdkListener.StartListening  ilOffset = 0x10C >NetTcpBinding [2016-09-08 14:48:04.400] Process: w3wp |Organization:00000000-0000-0000-0000-000000000000 |Thread:   20 |Category: Sandbox.StartStop |User: 00000000-0000-0000-0000-000000000000 |Level: Info |ReqId: 00000000-0000-0000-0000-000000000000 | SandboxSdkListener.StartListening  ilOffset = 0x10C >Uri: net.tcp://localhost/CrmSandboxSdkListener-w3wp [2016-09-08 14:48:04.446] Process: w3wp |Organization:00000000-0000-0000-0000-000000000000 |Thread:   13 |Category: Application |User: 00000000-0000-0000-0000-000000000000 |Level: Info |ReqId: 00000000-0000-0000-0000-000000000000 | AppDomain.OnAssemblyResolveEvent  ilOffset = 0x1B >Attempted to find assembly Microsoft.Crm.Authentication.XmlSerializers, Version=8.0.0.0, Culture=neutral, PublicKeyToken=31bf3856ad364e35 skipped path not being under ISV folder. [2016-09-08 14:48:04.462] Process: w3wp |Organization:00000000-0000-0000-0000-000000000000 |Thread:   20 |Category: Sandbox.StartStop |User: 00000000-0000-0000-0000-000000000000 |Level: Info |ReqId: 00000000-0000-0000-0000-000000000000 | SandboxSdkListener.StartListening  ilOffset = 0x10C >throttle.MaxConcurrentCalls:100 [2016-09-08 14:48:04.462] Process: w3wp |Organization:00000000-0000-0000-0000-000000000000 |Thread:   20 |Category: Sandbox.StartStop |User: 00000000-0000-0000-0000-000000000000 |Level: Info |ReqId: 00000000-0000-0000-0000-000000000000 | SandboxSdkListener.StartListening  ilOffset = 0x10C >throttle.MaxConcurrentInstances:300 [2016-09-08 14:48:04.462] Process: w3wp |Organization:00000000-0000-0000-0000-000000000000 |Thread:   20 |Category: Sandbox.StartStop |User: 00000000-0000-0000-0000-000000000000 |Level: Info |ReqId: 00000000-0000-0000-0000-000000000000 | SandboxSdkListener.StartListening  ilOffset = 0x10C >throttle.MaxConcurrentSessions:200 [2016-09-08 14:48:04.509] Process: w3wp |Organization:00000000-0000-0000-0000-000000000000 |Thread:   14 |Category: Sandbox |User: 00000000-0000-0000-0000-000000000000 |Level: Verbose |ReqId: 00000000-0000-0000-0000-000000000000 | SandboxHostManager.PingHostsInternal  ilOffset = 0x218 >net.pipe://localhost/CrmSandboxHost [2016-09-08 14:48:04.509] Process: w3wp |Organization:00000000-0000-0000-0000-000000000000 |Thread:   14 |Category: Sandbox |User: 00000000-0000-0000-0000-000000000000 |Level: Info |ReqId: 00000000-0000-0000-0000-000000000000 | SandboxHostManager.PingHostsInternal  ilOffset = 0x218 >no clientSpn [2016-09-08 14:48:04.509] Process: w3wp |Organization:00000000-0000-0000-0000-000000000000 |Thread:   14 |Category: Sandbox |User: 00000000-0000-0000-0000-000000000000 |Level: Verbose |ReqId: 00000000-0000-0000-0000-000000000000 | SandboxHostManager.PingHostsInternal  ilOffset = 0x218 >created WCF channel OK [2016-09-08 14:48:04.525] Process: w3wp |Organization:00000000-0000-0000-0000-000000000000 |Thread:   14 |Category: Sandbox |User: 00000000-0000-0000-0000-000000000000 |Level: Verbose |ReqId: 00000000-0000-0000-0000-000000000000 | SandboxHostManager.PingHostsInternal  ilOffset = 0x218 >Channel Settings: CloseTimeout: 00:01:00, OpenTimeout: 00:01:00, ReceiveTimeout: 00:10:00, SendTimeout: 00:01:00, MaxBufferPoolSize: 524288, MaxBufferSize: 128974848, MaxConnections: 10, MaxReceivedMessageSize: 128974848, TransferMode: Buffered, [2016-09-08 14:48:04.525] Process: w3wp |Organization:00000000-0000-0000-0000-000000000000 |Thread:   14 |Category: Sandbox.LoadBalancer |User: 00000000-0000-0000-0000-000000000000 |Level: Verbose |ReqId: 00000000-0000-0000-0000-000000000000 | SandboxHostManager.PingHostsInternal  ilOffset = 0x279 >PingSingleClient: enter: CRMBOX [2016-09-08 14:48:04.525] Process: w3wp |Organization:00000000-0000-0000-0000-000000000000 |Thread:   14 |Category: Sandbox.LoadBalancer |User: 00000000-0000-0000-0000-000000000000 |Level: Verbose |ReqId: 00000000-0000-0000-0000-000000000000 | SandboxHostManager.PingHostsInternal  ilOffset = 0x279 >pinging: CRMBOX [2016-09-08 14:48:04.541] Process: w3wp |Organization:00000000-0000-0000-0000-000000000000 |Thread:   14 |Category: Sandbox.StartStop |User: 00000000-0000-0000-0000-000000000000 |Level: Info |ReqId: 00000000-0000-0000-0000-000000000000 | SandboxCallInfo..cctor  ilOffset = 0x49 >SandboxCallInfo static ctor [2016-09-08 14:48:04.541] Process: w3wp |Organization:00000000-0000-0000-0000-000000000000 |Thread:   14 |Category: Sandbox.StartStop |User: 00000000-0000-0000-0000-000000000000 |Level: Info |ReqId: 00000000-0000-0000-0000-000000000000 | SandboxCallInfo..cctor  ilOffset = 0x83 >_scaleGroupId: 00000000-0000-0000-0000-000000000000 [2016-09-08 14:48:04.541] Process: w3wp |Organization:00000000-0000-0000-0000-000000000000 |Thread:   14 |Category: Sandbox.StartStop |User: 00000000-0000-0000-0000-000000000000 |Level: Info |ReqId: 00000000-0000-0000-0000-000000000000 | SandboxCallInfo..cctor  ilOffset = 0x139 >_serviceClassForServerPrincipalName: HTTP [2016-09-08 14:48:04.588] Process: w3wp |Organization:00000000-0000-0000-0000-000000000000 |Thread:   14 |Category: Sandbox.StartStop |User: 00000000-0000-0000-0000-000000000000 |Level: Info |ReqId: 00000000-0000-0000-0000-000000000000 | SandboxHostManager.PingSingleClient  ilOffset = 0xF9 >SandboxHostSids.AddSid: crmbox; hostSidSddlForm: AGENCY\CRMSANDBOX;S-1-5-21-2247622700-1530773878-3142798104-1111 [2016-09-08 14:48:04.588] Process: w3wp |Organization:00000000-0000-0000-0000-000000000000 |Thread:   14 |Category: Sandbox.LoadBalancer |User: 00000000-0000-0000-0000-000000000000 |Level: Verbose |ReqId: 00000000-0000-0000-0000-000000000000 | SandboxHostManager.PingHostsInternal  ilOffset = 0x279 >pingClient.HostStatus: Ready [2016-09-08 14:48:04.588] Process: w3wp |Organization:00000000-0000-0000-0000-000000000000 |Thread:   14 |Category: Sandbox.LoadBalancer |User: 00000000-0000-0000-0000-000000000000 |Level: Verbose |ReqId: 00000000-0000-0000-0000-000000000000 | SandboxHostManager.PingHosts  ilOffset = 0x35 >adding to ready list: CRMBOX [2016-09-08 14:48:04.588] Process: w3wp |Organization:00000000-0000-0000-0000-000000000000 |Thread:   14 |Category: Sandbox.LoadBalancer |User: 00000000-0000-0000-0000-000000000000 |Level: Verbose |ReqId: 00000000-0000-0000-0000-000000000000 | SandboxHostManager.PingHosts  ilOffset = 0x35 >CRMBOX: removedFromPending: False [2016-09-08 14:48:04.588] Process: w3wp |Organization:00000000-0000-0000-0000-000000000000 |Thread:   14 |Category: Sandbox.LoadBalancer |User: 00000000-0000-0000-0000-000000000000 |Level: Verbose |ReqId: 00000000-0000-0000-0000-000000000000 | SandboxHostManager.PingHosts  ilOffset = 0x35 >checking bad list: 0 [2016-09-08 14:48:04.588] Process: w3wp |Organization:00000000-0000-0000-0000-000000000000 |Thread:   14 |Category: Sandbox.LoadBalancer |User: 00000000-0000-0000-0000-000000000000 |Level: Verbose |ReqId: 00000000-0000-0000-0000-000000000000 | SandboxHostManager.PingHosts  ilOffset = 0x35 >out: ready clients: 1 [2016-09-08 14:48:04.588] Process: w3wp |Organization:00000000-0000-0000-0000-000000000000 |Thread:   14 |Category: Sandbox.LoadBalancer |User: 00000000-0000-0000-0000-000000000000 |Level: Verbose |ReqId: 00000000-0000-0000-0000-000000000000 | SandboxHostManager.PingHosts  ilOffset = 0x35 >out: pending clients: 0 [2016-09-08 14:48:04.604] Process: w3wp |Organization:00000000-0000-0000-0000-000000000000 |Thread:   14 |Category: Sandbox.Monitoring |User: 00000000-0000-0000-0000-000000000000 |Level: Verbose |ReqId: 00000000-0000-0000-0000-000000000000 | SandboxHostManager.PingHostsInternal  ilOffset = 0x47E >>>>>>>>>>>  [2016-09-08 14:48:04.619] Process: w3wp |Organization:00000000-0000-0000-0000-000000000000 |Thread:   14 |Category: Sandbox.Monitoring |User: 00000000-0000-0000-0000-000000000000 |Level: Verbose |ReqId: 00000000-0000-0000-0000-000000000000 | SandboxCounter.PublishCounters  ilOffset = 0x6A1 >_totalNumberSandboxHosts: 1 [2016-09-08 14:48:04.619] Process: w3wp |Organization:00000000-0000-0000-0000-000000000000 |Thread:   14 |Category: Sandbox.Monitoring |User: 00000000-0000-0000-0000-000000000000 |Level: Verbose |ReqId: 00000000-0000-0000-0000-000000000000 | SandboxCounter.PublishCounters  ilOffset = 0x6BF >percentHealthySandboxHosts: 100 [2016-09-08 14:48:04.619] Process: w3wp |Organization:00000000-0000-0000-0000-000000000000 |Thread:   14 |Category: Sandbox.Monitoring |User: 00000000-0000-0000-0000-000000000000 |Level: Verbose |ReqId: 00000000-0000-0000-0000-000000000000 | SandboxCounter.PublishCounters  ilOffset = 0x6DD >executeResponseTimeInMsec: 0 [2016-09-08 14:48:04.619] Process: w3wp |Organization:00000000-0000-0000-0000-000000000000 |Thread:   14 |Category: Sandbox.Monitoring |User: 00000000-0000-0000-0000-000000000000 |Level: Verbose |ReqId: 00000000-0000-0000-0000-000000000000 | SandboxCounter.PublishCounters  ilOffset = 0x6FB >percentExecuteFailures: 0 [2016-09-08 14:48:04.619] Process: w3wp |Organization:00000000-0000-0000-0000-000000000000 |Thread:   14 |Category: Sandbox.Monitoring |User: 00000000-0000-0000-0000-000000000000 |Level: Verbose |ReqId: 00000000-0000-0000-0000-000000000000 | SandboxCounter.PublishCounters  ilOffset = 0x719 >executesPerSecond: 0 [2016-09-08 14:48:04.619] Process: w3wp |Organization:00000000-0000-0000-0000-000000000000 |Thread:   14 |Category: Sandbox.Monitoring |User: 00000000-0000-0000-0000-000000000000 |Level: Verbose |ReqId: 00000000-0000-0000-0000-000000000000 | SandboxCounter.PublishCounters  ilOffset = 0x737 >sdkResponseTimeInMSec: 0 [2016-09-08 14:48:04.619] Process: w3wp |Organization:00000000-0000-0000-0000-000000000000 |Thread:   14 |Category: Sandbox.Monitoring |User: 00000000-0000-0000-0000-000000000000 |Level: Verbose |ReqId: 00000000-0000-0000-0000-000000000000 | SandboxCounter.PublishCounters  ilOffset = 0x755 >percentSdkRequestFailures: 0 [2016-09-08 14:48:04.619] Process: w3wp |Organization:00000000-0000-0000-0000-000000000000 |Thread:   14 |Category: Sandbox.Monitoring |User: 00000000-0000-0000-0000-000000000000 |Level: Verbose |ReqId: 00000000-0000-0000-0000-000000000000 | SandboxCounter.PublishCounters  ilOffset = 0x773 >sdkRequestsPerSecond: 0 [2016-09-08 14:48:04.619] Process: w3wp |Organization:00000000-0000-0000-0000-000000000000 |Thread:   14 |Category: Sandbox.Monitoring |User: 00000000-0000-0000-0000-000000000000 |Level: Verbose |ReqId: 00000000-0000-0000-0000-000000000000 | SandboxCounter.PublishCounters  ilOffset = 0x785 ><<<<<<<<<<  [2016-09-08 14:48:04.619] Process: w3wp |Organization:00000000-0000-0000-0000-000000000000 |Thread:   14 |Category: Sandbox.LoadBalancer |User: 00000000-0000-0000-0000-000000000000 |Level: Verbose |ReqId: 00000000-0000-0000-0000-000000000000 | SandboxHostManager.PingHosts  ilOffset = 0x35 >EXIT: PingHosts [2016-09-08 14:48:04.619] Process: w3wp |Organization:00000000-0000-0000-0000-000000000000 |Thread:   14 |Category: Sandbox.LoadBalancer |User: 00000000-0000-0000-0000-000000000000 |Level: Verbose |ReqId: 00000000-0000-0000-0000-000000000000 | ExecutionContext.RunInternal  ilOffset = 0x79 >_loopCount: 1 [2016-09-08 14:48:04.634] Process: w3wp |Organization:00000000-0000-0000-0000-000000000000 |Thread:   20 |Category: Sandbox.StartStop |User: 00000000-0000-0000-0000-000000000000 |Level: Info |ReqId: 00000000-0000-0000-0000-000000000000 | SandboxSdkListener.StartListening  ilOffset = 0x10C >Started: SDK Listener [2016-09-08 14:48:04.634] Process: w3wp |Organization:00000000-0000-0000-0000-000000000000 |Thread:   20 |Category: Sandbox |User: 00000000-0000-0000-0000-000000000000 |Level: Info |ReqId: 00000000-0000-0000-0000-000000000000 | ExecutionContext.RunInternal  ilOffset = 0x79 >SdkListenerStarterThread: exit/success [2016-09-08 14:48:05.416] Process: w3wp |Organization:00000000-0000-0000-0000-000000000000 |Thread:   13 |Category: Application |User: 00000000-0000-0000-0000-000000000000 |Level: Info |ReqId: 00000000-0000-0000-0000-000000000000 | AppDomain.OnAssemblyResolveEvent  ilOffset = 0x1B >Attempted to find assembly CrmAsyncService, Version=4.0.0.0, Culture=neutral, PublicKeyToken=31bf3856ad364e35 skipped path not being under ISV folder. [2016-09-08 14:48:05.416] Process: w3wp |Organization:00000000-0000-0000-0000-000000000000 |Thread:   13 |Category: Application |User: 00000000-0000-0000-0000-000000000000 |Level: Info |ReqId: 00000000-0000-0000-0000-000000000000 | AppDomain.OnAssemblyResolveEvent  ilOffset = 0x1B >Attempted to find assembly CrmAsyncService, Version=4.0.0.0, Culture=neutral, PublicKeyToken=31bf3856ad364e35 skipped path not being under ISV folder. [2016-09-08 14:48:05.416] Process: w3wp |Organization:00000000-0000-0000-0000-000000000000 |Thread:   13 |Category: Application |User: 00000000-0000-0000-0000-000000000000 |Level: Info |ReqId: 00000000-0000-0000-0000-000000000000 | AppDomain.OnAssemblyResolveEvent  ilOffset = 0x1B >Attempted to find assembly CrmAsyncService, Version=4.0.0.0, Culture=neutral, PublicKeyToken=31bf3856ad364e35 skipped path not being under ISV folder. [2016-09-08 14:48:05.431] Process: w3wp |Organization:00000000-0000-0000-0000-000000000000 |Thread:   13 |Category: Application |User: 00000000-0000-0000-0000-000000000000 |Level: Info |ReqId: 00000000-0000-0000-0000-000000000000 | AppDomain.OnAssemblyResolveEvent  ilOffset = 0x1B >Attempted to find assembly CrmAsyncService, Version=4.0.0.0, Culture=neutral, PublicKeyToken=31bf3856ad364e35 skipped path not being under ISV folder. [2016-09-08 14:48:05.431] Process: w3wp |Organization:00000000-0000-0000-0000-000000000000 |Thread:   13 |Category: Application |User: 00000000-0000-0000-0000-000000000000 |Level: Info |ReqId: 00000000-0000-0000-0000-000000000000 | AppDomain.OnAssemblyResolveEvent  ilOffset = 0x1B >Attempted to find assembly CrmAsyncService, Version=4.0.0.0, Culture=neutral, PublicKeyToken=31bf3856ad364e35 skipped path not being under ISV folder. [2016-09-08 14:48:06.041] Process: w3wp |Organization:00000000-0000-0000-0000-000000000000 |Thread:   13 |Category: Application |User: 00000000-0000-0000-0000-000000000000 |Level: Info |ReqId: 00000000-0000-0000-0000-000000000000 | AppDomain.OnAssemblyResolveEvent  ilOffset = 0x1B >Attempted to find assembly Microsoft.Practices.TransientFaultHandling.Core, Version=5.1.1209.0, Culture=neutral, PublicKeyToken=31bf3856ad364e35 skipped path not being under ISV folder. [2016-09-08 14:48:06.822] Process: w3wp |Organization:00000000-0000-0000-0000-000000000000 |Thread:   13 |Category: Platform.Authentication |User: 00000000-0000-0000-0000-000000000000 |Level: Verbose |ReqId: f9dddc68-26b3-4234-9290-62876bec78d5 | SyncEventExecutionStep.System.Web.HttpApplication.IExecutionStep.Execute  ilOffset = 0x5D >AUTH: Request [GET http://crmbox:5555/XrmServices/2015/metadataendpoint.svc/json?orgName=Agency] from [::1] entered Authentication Pipeline. [2016-09-08 14:48:06.837] Process: w3wp |Organization:00000000-0000-0000-0000-000000000000 |Thread:   13 |Category: Shared |User: 00000000-0000-0000-0000-000000000000 |Level: Verbose |ReqId: f9dddc68-26b3-4234-9290-62876bec78d5 | CrmDbConnection.Open  ilOffset = 0x2E >ConnectionString: Data Source=crmbox.agency.local;Initial Catalog=MSCRM_CONFIG;Integrated Security=True;Min Pool Size=2;Connect Timeout=150;Workstation ID=CRMBOX.w3wp. [2016-09-08 14:48:06.837] Process: w3wp |Organization:00000000-0000-0000-0000-000000000000 |Thread:   13 |Category: Platform.Sql |User: 00000000-0000-0000-0000-000000000000 |Level: Verbose |ReqId: f9dddc68-26b3-4234-9290-62876bec78d5 | CrmDbConnection.InternalExecuteReader  ilOffset = 0x1C >SELECT  Id  FROM [AuthenticationSettings]   WHERE ((([ConfigurationName] = 'OnPremise')) ) [2016-09-08 14:48:06.837] Process: w3wp |Organization:00000000-0000-0000-0000-000000000000 |Thread:   13 |Category: Platform.Sql |User: 00000000-0000-0000-0000-000000000000 |Level: Verbose |ReqId: f9dddc68-26b3-4234-9290-62876bec78d5 | CrmDbConnection.ExecuteReader  ilOffset = 0x9 >Query execution time: 0.0 seconds; database: MSCRM_CONFIG; Server:crmbox.agency.local; command: SELECT  Id  FROM [AuthenticationSettings]   WHERE ((([ConfigurationName] = 'OnPremise')) ) ; CommandTimeout: 30. [2016-09-08 14:48:06.837] Process: w3wp |Organization:00000000-0000-0000-0000-000000000000 |Thread:   13 |Category: Platform.Sql |User: 00000000-0000-0000-0000-000000000000 |Level: Verbose |ReqId: f9dddc68-26b3-4234-9290-62876bec78d5 | CrmDbConnection.InternalExecuteReader  ilOffset = 0x1C >SELECT [Id], ColumnName, BigIntColumn, IntColumn, SmallIntColumn, TinyIntColumn, BitColumn, FloatColumn, DateTimeColumn, SmallDateTimeColumn, NVarCharColumn, UniqueIdentifierColumn, VarBinaryColumn FROM [AuthenticationSettingsProperties]  WHERE Id IN (SELECT [Id] FROM [AuthenticationSettings]  WHERE ((([ConfigurationName] = 'OnPremise')) )) AND ColumnName IN ('CrmAuthentication') [2016-09-08 14:48:06.837] Process: w3wp |Organization:00000000-0000-0000-0000-000000000000 |Thread:   13 |Category: Platform.Sql |User: 00000000-0000-0000-0000-000000000000 |Level: Verbose |ReqId: f9dddc68-26b3-4234-9290-62876bec78d5 | CrmDbConnection.ExecuteReader  ilOffset = 0x9 >Query execution time: 0.0 seconds; database: MSCRM_CONFIG; Server:crmbox.agency.local; command: SELECT [Id], ColumnName, BigIntColumn, IntColumn, SmallIntColumn, TinyIntColumn, BitColumn, FloatColumn, DateTimeColumn, SmallDateTimeColumn, NVarCharColumn, UniqueIdentifierColumn, VarBinaryColumn FROM [AuthenticationSettingsProperties]  WHERE Id IN (SELECT [Id] FROM [AuthenticationSettings]  WHERE ((([ConfigurationName] = 'OnPremise')) )) AND ColumnName IN ('CrmAuthentication'); CommandTimeout: 30. [2016-09-08 14:48:06.837] Process: w3wp |Organization:00000000-0000-0000-0000-000000000000 |Thread:   13 |Category: Application |User: 00000000-0000-0000-0000-000000000000 |Level: Info |ReqId: f9dddc68-26b3-4234-9290-62876bec78d5 | AppDomain.OnAssemblyResolveEvent  ilOffset = 0x1B >Attempted to find assembly Microsoft.Crm.Authentication.XmlSerializers, Version=8.0.0.0, Culture=neutral, PublicKeyToken=31bf3856ad364e35 skipped path not being under ISV folder. [2016-09-08 14:48:06.868] Process: w3wp |Organization:00000000-0000-0000-0000-000000000000 |Thread:   13 |Category: Platform |User: 00000000-0000-0000-0000-000000000000 |Level: Verbose |ReqId: f9dddc68-26b3-4234-9290-62876bec78d5 | AuthenticationPipeline.Authenticate  ilOffset = 0x11 >AUTH: AuthenticationProvider [] will be attempted. [2016-09-08 14:48:06.868] Process: w3wp |Organization:00000000-0000-0000-0000-000000000000 |Thread:   13 |Category: Platform.Authentication |User: 00000000-0000-0000-0000-000000000000 |Level: Info |ReqId: f9dddc68-26b3-4234-9290-62876bec78d5 | AuthenticationPipeline.Authenticate  ilOffset = 0x11 >AUTH: AuthenticationProvider [Microsoft.Crm.Authentication.PassThroughAuthenticationProvider] handled request [http://crmbox:5555/XrmServices/2015/metadataendpoint.svc/json?orgName=Agency] from [::1]. [2016-09-08 14:48:06.884] Process: w3wp |Organization:00000000-0000-0000-0000-000000000000 |Thread:   13 |Category: Platform |User: 00000000-0000-0000-0000-000000000000 |Level: Verbose |ReqId: f9dddc68-26b3-4234-9290-62876bec78d5 | RouteCollection.IsRouteToExistingFile  ilOffset = 0x0 >FileExists ~/XrmServices/2015/metadataendpoint.svc returning True. [2016-09-08 14:48:06.978] Process: w3wp |Organization:00000000-0000-0000-0000-000000000000 |Thread:    7 |Category: Platform |User: 00000000-0000-0000-0000-000000000000 |Level: Verbose |ReqId: f9dddc68-26b3-4234-9290-62876bec78d5 | HostingEnvironmentWrapper.ServiceFileExists  ilOffset = 0x0 >FileExists ~/XrmServices/2015/metadataendpoint.svc returning True. [2016-09-08 14:48:06.978] Process: w3wp |Organization:00000000-0000-0000-0000-000000000000 |Thread:    7 |Category: Platform |User: 00000000-0000-0000-0000-000000000000 |Level: Verbose |ReqId: f9dddc68-26b3-4234-9290-62876bec78d5 | BuildManager.EnsureFirstTimeDirectoryInit  ilOffset = 0x20 >DirectoryExists /XrmServices/2015/App_LocalResources/ returning False. [2016-09-08 14:48:06.978] Process: w3wp |Organization:00000000-0000-0000-0000-000000000000 |Thread:    7 |Category: Platform |User: 00000000-0000-0000-0000-000000000000 |Level: Verbose |ReqId: f9dddc68-26b3-4234-9290-62876bec78d5 | BuildResult.ComputeSourceDependenciesHashCode  ilOffset = 0x8 >GetFileHash(/XrmServices/2015/metadataendpoint.svc, System.Collections.ArrayList) called. [2016-09-08 14:48:07.103] Process: w3wp |Organization:00000000-0000-0000-0000-000000000000 |Thread:   15 |Category: Platform.Authentication |User: 00000000-0000-0000-0000-000000000000 |Level: Verbose |ReqId: 20c4d076-0e42-4c90-b064-dc9e3ed603f2 | SyncEventExecutionStep.System.Web.HttpApplication.IExecutionStep.Execute  ilOffset = 0x5D >AUTH: Request [GET http://crmbox:5555/XrmServices/2015/metadataendpoint.svc/json/?orgName=Agency] from [::1] entered Authentication Pipeline. [2016-09-08 14:48:07.103] Process: w3wp |Organization:00000000-0000-0000-0000-000000000000 |Thread:   15 |Category: Platform |User: 00000000-0000-0000-0000-000000000000 |Level: Verbose |ReqId: 20c4d076-0e42-4c90-b064-dc9e3ed603f2 | AuthenticationPipeline.Authenticate  ilOffset = 0x11 >AUTH: AuthenticationProvider [Microsoft.Crm.Authentication.PassThroughAuthenticationProvider] will be attempted. [2016-09-08 14:48:07.103] Process: w3wp |Organization:00000000-0000-0000-0000-000000000000 |Thread:   15 |Category: Platform.Authentication |User: 00000000-0000-0000-0000-000000000000 |Level: Info |ReqId: 20c4d076-0e42-4c90-b064-dc9e3ed603f2 | AuthenticationPipeline.Authenticate  ilOffset = 0x11 >AUTH: AuthenticationProvider [Microsoft.Crm.Authentication.PassThroughAuthenticationProvider] handled request [http://crmbox:5555/XrmServices/2015/metadataendpoint.svc/json/?orgName=Agency] from [::1]. [2016-09-08 14:48:07.103] Process: w3wp |Organization:00000000-0000-0000-0000-000000000000 |Thread:   15 |Category: Platform |User: 00000000-0000-0000-0000-000000000000 |Level: Verbose |ReqId: 20c4d076-0e42-4c90-b064-dc9e3ed603f2 | RouteCollection.IsRouteToExistingFile  ilOffset = 0x0 >FileExists ~/XrmServices/2015/metadataendpoint.svc returning True. [2016-09-08 14:48:07.103] Process: w3wp |Organization:00000000-0000-0000-0000-000000000000 |Thread:   10 |Category: Shared |User: 00000000-0000-0000-0000-000000000000 |Level: Verbose |ReqId: 20c4d076-0e42-4c90-b064-dc9e3ed603f2 | CrmDbConnection.Open  ilOffset = 0x2E >ConnectionString: Data Source=crmbox.agency.local;Initial Catalog=MSCRM_CONFIG;Integrated Security=True;Min Pool Size=2;Connect Timeout=150;Workstation ID=CRMBOX.w3wp. [2016-09-08 14:48:07.103] Process: w3wp |Organization:00000000-0000-0000-0000-000000000000 |Thread:   10 |Category: Platform.Sql |User: 00000000-0000-0000-0000-000000000000 |Level: Verbose |ReqId: 20c4d076-0e42-4c90-b064-dc9e3ed603f2 | CrmDbConnection.InternalExecuteReader  ilOffset = 0x1C >SELECT  Id  FROM [Organization]   WHERE ((([UniqueName] = 'Agency')) ) [2016-09-08 14:48:07.103] Process: w3wp |Organization:00000000-0000-0000-0000-000000000000 |Thread:   10 |Category: Platform.Sql |User: 00000000-0000-0000-0000-000000000000 |Level: Verbose |ReqId: 20c4d076-0e42-4c90-b064-dc9e3ed603f2 | CrmDbConnection.ExecuteReader  ilOffset = 0x9 >Query execution time: 0.0 seconds; database: MSCRM_CONFIG; Server:crmbox.agency.local; command: SELECT  Id  FROM [Organization]   WHERE ((([UniqueName] = 'Agency')) ) ; CommandTimeout: 30. [2016-09-08 14:48:07.118] Process: w3wp |Organization:00000000-0000-0000-0000-000000000000 |Thread:   10 |Category: Shared |User: 00000000-0000-0000-0000-000000000000 |Level: Verbose |ReqId: 20c4d076-0e42-4c90-b064-dc9e3ed603f2 | CrmDbConnection.Open  ilOffset = 0x2E >ConnectionString: Data Source=crmbox.agency.local;Initial Catalog=MSCRM_CONFIG;Integrated Security=True;Min Pool Size=2;Connect Timeout=150;Workstation ID=CRMBOX.w3wp. [2016-09-08 14:48:07.118] Process: w3wp |Organization:00000000-0000-0000-0000-000000000000 |Thread:   10 |Category: Platform.Sql |User: 00000000-0000-0000-0000-000000000000 |Level: Verbose |ReqId: 20c4d076-0e42-4c90-b064-dc9e3ed603f2 | CrmDbConnection.InternalExecuteReader  ilOffset = 0x1C >SELECT  Id, [AreReportsPublished], [AvailabilityGroup], [ConnectionString], [DatabaseName], [DatacenterId], [DelegatedAdminCrmUserId], [FriendlyName], [HelpContentServerUrl], [MirroredSqlServerName], [PartitionNumber], [ProvisioningActionInProgress], [ScaleGroupId], [SqlServerName], [SrsUrl], [State], [StorageGroupId], [StorageLicensesPurchasedModifiedOn], [SupportUserCrmUserId], [Type], [UniqueName], [UniqueifierId], [UrlName], [UserLicensesPurchasedModifiedOn]  FROM [Organization]   WHERE ((([Id] = '62d86e90-01d2-462a-a4fc-4cd113c943c6')) ) [2016-09-08 14:48:07.118] Process: w3wp |Organization:00000000-0000-0000-0000-000000000000 |Thread:   10 |Category: Platform.Sql |User: 00000000-0000-0000-0000-000000000000 |Level: Verbose |ReqId: 20c4d076-0e42-4c90-b064-dc9e3ed603f2 | CrmDbConnection.ExecuteReader  ilOffset = 0x9 >Query execution time: 0.0 seconds; database: MSCRM_CONFIG; Server:crmbox.agency.local; command: SELECT  Id, [AreReportsPublished], [AvailabilityGroup], [ConnectionString], [DatabaseName], [DatacenterId], [DelegatedAdminCrmUserId], [FriendlyName], [HelpContentServerUrl], [MirroredSqlServerName], [PartitionNumber], [ProvisioningActionInProgress], [ScaleGroupId], [SqlServerName], [SrsUrl], [State], [StorageGroupId], [StorageLicensesPurchasedModifiedOn], [SupportUserCrmUserId], [Type], [UniqueName], [UniqueifierId], [UrlName], [UserLicensesPurchasedModifiedOn]  FROM [Organization]   WHERE ((([Id] = '62d86e90-01d2-462a-a4fc-4cd113c943c6')) ) ; CommandTimeout: 30. [2016-09-08 14:48:07.118] Process: w3wp |Organization:00000000-0000-0000-0000-000000000000 |Thread:   10 |Category: Platform.Sql |User: 00000000-0000-0000-0000-000000000000 |Level: Verbose |ReqId: 20c4d076-0e42-4c90-b064-dc9e3ed603f2 | CrmDbConnection.InternalExecuteReader  ilOffset = 0x1C >SELECT [Id], ColumnName, BigIntColumn, IntColumn, SmallIntColumn, TinyIntColumn, BitColumn, FloatColumn, DateTimeColumn, SmallDateTimeColumn, NVarCharColumn, UniqueIdentifierColumn, VarBinaryColumn FROM [OrganizationProperties]  WHERE Id IN (SELECT [Id] FROM [Organization]  WHERE ((([Id] = '62d86e90-01d2-462a-a4fc-4cd113c943c6')) )) [2016-09-08 14:48:07.118] Process: w3wp |Organization:00000000-0000-0000-0000-000000000000 |Thread:   10 |Category: Platform.Sql |User: 00000000-0000-0000-0000-000000000000 |Level: Verbose |ReqId: 20c4d076-0e42-4c90-b064-dc9e3ed603f2 | CrmDbConnection.ExecuteReader  ilOffset = 0x9 >Query execution time: 0.0 seconds; database: MSCRM_CONFIG; Server:crmbox.agency.local; command: SELECT [Id], ColumnName, BigIntColumn, IntColumn, SmallIntColumn, TinyIntColumn, BitColumn, FloatColumn, DateTimeColumn, SmallDateTimeColumn, NVarCharColumn, UniqueIdentifierColumn, VarBinaryColumn FROM [OrganizationProperties]  WHERE Id IN (SELECT [Id] FROM [Organization]  WHERE ((([Id] = '62d86e90-01d2-462a-a4fc-4cd113c943c6')) )); CommandTimeout: 30. [2016-09-08 14:48:07.134] Process: w3wp |Organization:00000000-0000-0000-0000-000000000000 |Thread:   10 |Category: Platform |User: 00000000-0000-0000-0000-000000000000 |Level: Verbose |ReqId: 20c4d076-0e42-4c90-b064-dc9e3ed603f2 | MetadataEndpointServiceUtility.GetSigningCertificates  ilOffset = 0x5D >Retrieve multiple Certificates [2016-09-08 14:48:07.134] Process: w3wp |Organization:00000000-0000-0000-0000-000000000000 |Thread:   10 |Category: Shared |User: 00000000-0000-0000-0000-000000000000 |Level: Verbose |ReqId: 20c4d076-0e42-4c90-b064-dc9e3ed603f2 | CrmDbConnection.Open  ilOffset = 0x2E >ConnectionString: Data Source=crmbox.agency.local;Initial Catalog=MSCRM_CONFIG;Integrated Security=True;Min Pool Size=2;Connect Timeout=150;Workstation ID=CRMBOX.w3wp. [2016-09-08 14:48:07.134] Process: w3wp |Organization:00000000-0000-0000-0000-000000000000 |Thread:   10 |Category: Platform.Sql |User: 00000000-0000-0000-0000-000000000000 |Level: Verbose |ReqId: 20c4d076-0e42-4c90-b064-dc9e3ed603f2 | CrmDbConnection.InternalExecuteReader  ilOffset = 0x1C >SELECT  Id, [CertificateData], [Name], [ParentId], [StoreFindType], [StoreLocation], [StoreName], [Type]  FROM [Certificates]   WHERE ((([Type] = 'S2STokenIssuer'))  OR (([Type] = 'AlternativeS2STokenIssuer')) ) [2016-09-08 14:48:07.134] Process: w3wp |Organization:00000000-0000-0000-0000-000000000000 |Thread:   10 |Category: Platform.Sql |User: 00000000-0000-0000-0000-000000000000 |Level: Verbose |ReqId: 20c4d076-0e42-4c90-b064-dc9e3ed603f2 | CrmDbConnection.ExecuteReader  ilOffset = 0x9 >Query execution time: 0.0 seconds; database: MSCRM_CONFIG; Server:crmbox.agency.local; command: SELECT  Id, [CertificateData], [Name], [ParentId], [StoreFindType], [StoreLocation], [StoreName], [Type]  FROM [Certificates]   WHERE ((([Type] = 'S2STokenIssuer'))  OR (([Type] = 'AlternativeS2STokenIssuer')) ) ; CommandTimeout: 30. [2016-09-08 14:48:07.134] Process: w3wp |Organization:00000000-0000-0000-0000-000000000000 |Thread:   10 |Category: Exception |User: 00000000-0000-0000-0000-000000000000 |Level: Error |ReqId: 20c4d076-0e42-4c90-b064-dc9e3ed603f2 | CrmException.Assert  ilOffset = 0x10                 at CrmException.Assert(Boolean condition, String message)  ilOffset = 0x10                 at MetadataEndpointServiceUtility.GetSigningCertificates()  ilOffset = 0x100                 at MetadataEndpointService.GenerateMetadata(String orgName)  ilOffset = 0x6A                 at   ilOffset = 0xFFFFFFFF                 at SyncMethodInvoker.Invoke(Object instance, Object[] inputs, Object[]& outputs)  ilOffset = 0x222                 at DispatchOperationRuntime.InvokeBegin(MessageRpc& rpc)  ilOffset = 0xC4                 at ImmutableDispatchRuntime.ProcessMessage5(MessageRpc& rpc)  ilOffset = 0x48                 at ImmutableDispatchRuntime.ProcessMessage11(MessageRpc& rpc)  ilOffset = 0x291                 at MessageRpc.Process(Boolean isOperationContextSet)  ilOffset = 0x65                 at ChannelHandler.DispatchAndReleasePump(RequestContext request, Boolean cleanThread, OperationContext currentOperationContext)  ilOffset = 0x239                 at ChannelHandler.HandleRequest(RequestContext request, OperationContext currentOperationContext)  ilOffset = 0xEF                 at ChannelHandler.AsyncMessagePump(IAsyncResult result)  ilOffset = 0x39                 at ChannelHandler.OnAsyncReceiveComplete(IAsyncResult result)  ilOffset = 0x19                 at AsyncThunk.UnhandledExceptionFrame(IAsyncResult result)  ilOffset = 0x0                 at AsyncResult.Complete(Boolean completedSynchronously)  ilOffset = 0xC2                 at AsyncQueueReader.Set(Item item)  ilOffset = 0x2F                 at InputQueue`1.EnqueueAndDispatch(Item item, Boolean canDispatchOnThisThread)  ilOffset = 0xDE                 at InputQueue`1.EnqueueAndDispatch(T item, Action dequeuedCallback, Boolean canDispatchOnThisThread)  ilOffset = 0xE                 at SingletonChannelAcceptor`3.Enqueue(QueueItemType item, Action dequeuedCallback, Boolean canDispatchOnThisThread)  ilOffset = 0x33                 at EnqueueMessageAsyncResult.CompleteParseAndEnqueue(IAsyncResult result)  ilOffset = 0x61                 at EnqueueMessageAsyncResult.HandleParseIncomingMessage(IAsyncResult result)  ilOffset = 0x11                 at AsyncResult.SyncContinue(IAsyncResult result)  ilOffset = 0xB                 at EmptyHttpPipeline.BeginProcessInboundRequest(ReplyChannelAcceptor replyChannelAcceptor, Action dequeuedCallback, AsyncCallback callback, Object state)  ilOffset = 0x11                 at HttpContextReceivedAsyncResult`1.ProcessHttpContextAsync()  ilOffset = 0x9B                 at HttpChannelListener`1.BeginHttpContextReceived(HttpRequestContext context, Action acceptorCallback, AsyncCallback callback, Object state)  ilOffset = 0x0                 at HostedHttpTransportManager.HttpContextReceived(HostedHttpRequestAsyncResult result)  ilOffset = 0x62                 at HostedHttpRequestAsyncResult.HandleRequest()  ilOffset = 0x10E                 at HostedHttpRequestAsyncResult.BeginRequest()  ilOffset = 0x0                 at HostedHttpRequestAsyncResult.OnBeginRequest(Object state)  ilOffset = 0x9                 at AspNetPartialTrustHelpers.PartialTrustInvoke(ContextCallback callback, Object state)  ilOffset = 0x20                 at HostedHttpRequestAsyncResult.OnBeginRequestWithFlow(Object state)  ilOffset = 0x25                 at ScheduledOverlapped.IOCallback(UInt32 errorCode, UInt32 numBytes, NativeOverlapped* nativeOverlapped)  ilOffset = 0x22                 at IOCompletionThunk.UnhandledExceptionFrame(UInt32 error, UInt32 bytesRead, NativeOverlapped* nativeOverlapped)  ilOffset = 0x5                 at _IOCompletionCallback.PerformIOCompletionCallback(UInt32 errorCode, UInt32 numBytes, NativeOverlapped* pOVERLAP)  ilOffset = 0x1E >Crm Exception: Message: No S2STokenIssuer certificate present in config database., ErrorCode: -2147220970 [2016-09-08 14:48:07.134] Process: w3wp |Organization:00000000-0000-0000-0000-000000000000 |Thread:   10 |Category: Platform.Sdk |User: 00000000-0000-0000-0000-000000000000 |Level: Error |ReqId: 20c4d076-0e42-4c90-b064-dc9e3ed603f2 | TraceSource.TraceData  ilOffset = 0x68 >http://msdn.microsoft.com/en-US/library/System.ServiceModel.Diagnostics.TraceHandledException.aspxHandling an exception. Exception details: Microsoft.Crm.CrmException: No S2STokenIssuer certificate present in config database. >   at Microsoft.Crm.CrmException.Assert(Boolean condition, String message) >   at Microsoft.Crm.Extensibility.MetadataEndpointServiceUtility.GetSigningCertificates() >   at Microsoft.Crm.Extensibility.MetadataEndpointService.GenerateMetadata(String orgName) >   at SyncInvokeGenerateMetadata(Object , Object[] , Object[] ) >   at System.ServiceModel.Dispatcher.SyncMethodInvoker.Invoke(Object instance, Object[] inputs, Object[]& outputs) >   at System.ServiceModel.Dispatcher.DispatchOperationRuntime.InvokeBegin(MessageRpc& rpc) >   at System.ServiceModel.Dispatcher.ImmutableDispatchRuntime.ProcessMessage5(MessageRpc& rpc) >   at System.ServiceModel.Dispatcher.ImmutableDispatchRuntime.ProcessMessage11(MessageRpc& rpc) >   at System.ServiceModel.Dispatcher.MessageRpc.Process(Boolean isOperationContextSet)/LM/W3SVC/2/ROOT-1-131177908824467939Microsoft.Crm.CrmException, Microsoft.Crm.Core, Version=8.0.0.0, Culture=neutral, PublicKeyToken=31bf3856ad364e35No S2STokenIssuer certificate present in config database.   at Microsoft.Crm.CrmException.Assert(Boolean condition, String message) >   at Microsoft.Crm.Extensibility.MetadataEndpointServiceUtility.GetSigningCertificates() >   at Microsoft.Crm.Extensibility.MetadataEndpointService.GenerateMetadata(String orgName) >   at SyncInvokeGenerateMetadata(Object , Object[] , Object[] ) >   at System.ServiceModel.Dispatcher.SyncMethodInvoker.Invoke(Object instance, Object[] inputs, Object[]&amp; outputs) >   at System.ServiceModel.Dispatcher.DispatchOperationRuntime.InvokeBegin(MessageRpc&amp; rpc) >   at System.ServiceModel.Dispatcher.ImmutableDispatchRuntime.ProcessMessage5(MessageRpc&amp; rpc) >   at System.ServiceModel.Dispatcher.ImmutableDispatchRuntime.ProcessMessage11(MessageRpc&amp; rpc) >   at System.ServiceModel.Dispatcher.MessageRpc.Process(Boolean isOperationContextSet)Microsoft.Crm.CrmException: No S2STokenIssuer certificate present in config database. >   at Microsoft.Crm.CrmException.Assert(Boolean condition, String message) >   at Microsoft.Crm.Extensibility.MetadataEndpointServiceUtility.GetSigningCertificates() >   at Microsoft.Crm.Extensibility.MetadataEndpointService.GenerateMetadata(String orgName) >   at SyncInvokeGenerateMetadata(Object , Object[] , Object[] ) >   at System.ServiceModel.Dispatcher.SyncMethodInvoker.Invoke(Object instance, Object[] inputs, Object[]&amp; outputs) >   at System.ServiceModel.Dispatcher.DispatchOperationRuntime.InvokeBegin(MessageRpc&amp; rpc) >   at System.ServiceModel.Dispatcher.ImmutableDispatchRuntime.ProcessMessage5(MessageRpc&amp; rpc) >   at System.ServiceModel.Dispatcher.ImmutableDispatchRuntime.ProcessMessage11(MessageRpc&amp; rpc) >   at System.ServiceModel.Dispatcher.MessageRpc.Process(Boolean isOperationContextSet)

 

hope this will help, though this was a stupid mistake to miss one step and being crazy with the error..


Regards,
Yes.Sudhanshu