Saturday, November 19, 2016

workflow must be in published state error message while saving Case record in Dynamics CRM 2016 online

while working on dynamics crm 2016 online I got below error while saving case record.
"workflow must be in published state". once download the message I got below


Unhandled Exception: System.ServiceModel.FaultException`1[[Microsoft.Xrm.Sdk.OrganizationServiceFault, Microsoft.Xrm.Sdk, Version=8.0.0.0, Culture=neutral, PublicKeyToken=31bf3856ad364e35]]: Workflow must be in Published state.Detail:
<OrganizationServiceFault xmlns:i="http://www.w3.org/2001/XMLSchema-instance" xmlns="http://schemas.microsoft.com/xrm/2011/Contracts">
  <ErrorCode>-2147200953</ErrorCode>
  <ErrorDetails xmlns:d2p1="http://schemas.datacontract.org/2004/07/System.Collections.Generic">
    <KeyValuePairOfstringanyType>
      <d2p1:key>0</d2p1:key>
      <d2p1:value xmlns:d4p1="http://www.w3.org/2001/XMLSchema" i:type="d4p1:string">Workflow must be in Published state.</d2p1:value>
    </KeyValuePairOfstringanyType>
    <KeyValuePairOfstringanyType>
      <d2p1:key>1</d2p1:key>
      <d2p1:value xmlns:d4p1="http://www.w3.org/2001/XMLSchema" i:type="d4p1:string">workflowId</d2p1:value>
    </KeyValuePairOfstringanyType>
  </ErrorDetails>
  <Message>Workflow must be in Published state.</Message>
  <Timestamp>2016-11-19T14:29:41.1347733Z</Timestamp>
  <ExceptionSource i:nil="true" />
  <InnerFault i:nil="true" />
  <OriginalException i:nil="true" />
  <TraceText>
[Microsoft.Crm.Service.ObjectModel: Microsoft.Crm.Service.ObjectModel.CasePostCreatePlugin]
[ffde44b1-a685-4948-85b8-e4091bc2a98b: CasePostCreatePlugin]
 
               
                [Microsoft.Crm.ObjectModel: Microsoft.Crm.Extensibility.InternalOperationPlugin]
                [46f6cf4c-14ae-4f1e-98a1-eae99a37e95c: ExecuteWorkflowWithInputArguments]
               
               
</TraceText>
</OrganizationServiceFault>
strange, I activated all workflows, business process, still same issue.
then I deleted all (taken back up) 1st, still same issue.
then I just though to see anything related to case, I landed to SLA.
I just deactivated, then I was able to save Case record.
even then I activated SLA, also I was able to save.


SO JUST deactivate and activate again is the solution. but do not know why?


Regards,
yes.sudhashu

Thursday, September 29, 2016

Dynamics CRM App for Outlook Client (light weight App)

There is a cool App (https://technet.microsoft.com/en-us/library/dn946901.aspx ) available for Dynamics CRM online only (as of now)
here below are step by step and some more details....


1st RULE: this is only available for MS CRM 2016 Online.
so you can use office 365 out look or offline outlook client also, but ms crm will be on line version.


Basic settings
once you login to your online dynamics crm instance, you will find something below, if you will click on the gear icon on top right corner of your screen
here you see dynamics crm app for phone and tablets for all 3 major mobile player, Windows, Apple and Android (from google)


next you will see the "Dynamics CRM App for outlook".
as in above screen , if you see the red cross and message "your account's email settings aren't configured to use this app", then login to crm and setup the email account in users profile that you are accessing now and then you will see as below.

this means, for this user, the email account mentioned in the user profile will be able to get the app for outlook. the message says "we are adding the app in background". finally you will see as below with message "Already added to your outlook". now you are ready to use the app for this email is , either on office 365 or in your outlook if you have configured this account in outlook.


for Office 365
now login to your office 365 email account and once you select any email, on right side panel you will see "Dynamics CRM icon" as below. have patience if it does not load immediately , may take some time.


Once you click that , it will launch the App. it will download the metadata as below
then it will load below screen as per the logic, if the contact present in crm or not, it will ask you to track the email in crm or not etc as below.
if you click Track, then you have choice to set regarding (this has option to search and find) or also without set regarding you can track in crm as below
if you s
earch you will get the rsults as below for each entities....



then there is option you can Untrack and also change regarding value for the email tracked in CRM as below....
While searching for a record to set regarding, if it is not present you can just go ahead and create a new record by clicking the + icon as below highlighted....
after clicking the icon (say clicked Case) it will open up the new record form (here case), this might open the quick create form as below...

this is all about the app in office 365.

for Outlook client
for this you need to install the outlook client that is available in crm or can download from internet.
select online while configuring the org.
then in the outlook, you will see login screen as below.
once you login it will connect to the online crm org as below
once you select any email from that email account in outlook you will get below screen to Track, change, untrack depending on new email or tracked email. here its for one tracked email, so change and untrack.
if you select track you will get the same kind of screen as we got for office 356 login, same search, create new record etc.

Security role for crm outlook app
there is a security role needs to be enabled for the user to get the app, this also needs to be granted in the security role , so that the user will not see the red cross in image 1.

you can the eligible users from CRM by going to Settings -> CRM App for Outlook. this will list out the user which are eligible, means granted to access outlook app access.

hope this is a great step from MS. this will help from many angles....
at least for online users they do not have to install outlook client , unless they need to access more crm from outlook.

hope this also helps people to understand some...

Regards,
Sudhanshu



Thursday, September 8, 2016

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