A few days back, the default views for a couple of entities in one of our Dynamics CRM 4 instance failed to open. The most notable was the “Active Contacts” view on the Contact entity. The same view continued to open properly on all other deployments. In fact, we had imported the organization from another instance of Dynamics CRM and the views were opening on the original instance. Below is the error that we were receiving. There’s nothing that could be deduced from it, other than something was failing.
The first step to troubleshoot was to enable tracing on the CRM instance. To do that, you have to make a few registry entries. The details are outlined here. The registry setting of TraceEnabled
, TraceDirectory
, and TraceRefresh
are required. We, however, found out that even after setting the TraceDirectory
, our trace logs were created in the default C:\Program Files\Microsoft Dynamics CRM\Trace
directory. Maybe, the path is to be provided in a specific format, but that is yet to be investigated. Here is a view of our registry settings –
Once, the setting was done, the trace files generation started and we started getting files with names of the format ServerName-w3wp-wwwroot-yyyymmdd-X
. The trailing X
stands for the file number generated for a single day, and will typically have a value of 1
. If you set the TraceFileSizeLimit
registry flag, then each file will have a maximum size limit, and multiple files (with trailing 1,2,3…and so on) may get created for a single day.
We tried to open the culprit view again to have the trace generated. This is what we received in the log file –
[2011-02-02 04:04:51.8] Process: w3wp |Organization:f79g217f-763c-e045-ah72-895056hgyy76 |Thread: 9 |Category: Platform.Sql |User: s45g217f-333d-sddd-ehd2-643877rehh44 |Level: Error | BusinessProcessObject.ExecuteQuery
>Exception when executing query: select top 51 contact0.Telephone1 as 'telephone1', contact0.EMailAddress1 as 'emailaddress1', contact0.CreatedBy as 'createdby', contact0.LastName as 'lastname', contact0.FirstName as 'firstname', contact0.JobTitle as 'jobtitle', contact0.ContactId as 'contactid', contact0.CreatedByYomiName as 'createdbyyominame', contact0.CreatedByDsc as 'createdbydsc', contact0.CreatedByName as 'createdbyname' from Contact as contact0 where (contact0.StateCode = 0 and (contact0.DeletionStateCode in (0))) order by contact0.FirstName asc, contact0.ContactId asc Exception: System.Data.SqlClient.SqlException: Timeout expired. The timeout period elapsed prior to completion of the operation or the server is not responding.
at System.Data.SqlClient.SqlConnection.OnError(SqlException exception, Boolean breakConnection)
at System.Data.SqlClient.TdsParser.ThrowExceptionAndWarning(TdsParserStateObject stateObj)
at System.Data.SqlClient.TdsParser.Run(RunBehavior runBehavior, SqlCommand cmdHandler, SqlDataReader dataStream, BulkCopySimpleResultSet bulkCopyHandler, TdsParserStateObject stateObj)
at System.Data.SqlClient.SqlDataReader.ConsumeMetaData()
at System.Data.SqlClient.SqlDataReader.get_MetaData()
at System.Data.SqlClient.SqlCommand.FinishExecuteReader(SqlDataReader ds, RunBehavior runBehavior, String resetOptionsString)
at System.Data.SqlClient.SqlCommand.RunExecuteReaderTds(CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStream, Boolean async)
at System.Data.SqlClient.SqlCommand.RunExecuteReader(CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStream, String method, DbAsyncResult result)
at System.Data.SqlClient.SqlCommand.RunExecuteReader(CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStream, String method)
at System.Data.SqlClient.SqlCommand.ExecuteReader(CommandBehavior behavior, String method)
at System.Data.SqlClient.SqlCommand.ExecuteDbDataReader(CommandBehavior behavior)
at System.Data.Common.DbCommand.System.Data.IDbCommand.ExecuteReader()
at Microsoft.Crm.CrmDbConnection.InternalExecuteReader(IDbCommand command)
at Microsoft.Crm.CrmDbConnection.ExecuteReader(IDbCommand command, Boolean impersonate)
at Microsoft.Crm.BusinessEntities.BusinessProcessObject.ExecuteQuery(CrmDbConnection dbConnection, IDbCommand command, ISqlExecutionContext context)
Please note that your GUIDs for the organization and user will be different from the ones specified above. The important line is the one highlighted in red. It specifies the query that failed to run at the SQL Server (again, your query may be different in case you have customized the view) and the exception thrown – Exception: System.Data.SqlClient.SqlException: Timeout expired. The timeout period elapsed prior to completion of the operation or the server is not responding
. This clearly says that the query is taking a long time to execute and it timed out. We connected to the CRM organization database using SQL Server Management Studio and ran the query to find out the execution time. It was taking around 51 seconds to execute. It turned out that the default query execution timeout for CRM is 30 seconds. We ran the same query on other CRM instances and it ran within 5 seconds. So, that was why the views were opening on all other instances. The timeout values can be overridden by two registry settings OLEDBTimeout
and ExtendedTimeout
. In our case, since it was simply views (ExtendedTimeout
is used for long running operations – imports & other stuff), we just needed to add the OLEDBTimeout
registry setting. We set its value to 120 seconds and the view started working. You can see the detailed steps here (although the KB article refers to another problem, the steps in the Resolution section are for adding the timeout registry settings).
You can use this approach to fix timeout issues immediately, however for a more sustainable and long-term approach, the database indexes & query execution plans need to be looked at.
19.174035
72.960290