Trace a repeating query back to its source in MS Dynamics CRM 2015

Question

Looking at trace logs on SQL Server I see one query that runs about 2500 times a day, with each run taking on average 3200ms, 500000 logical reads and 1300 Physical reads.

This query returns exactly the same 5 rows, every time.

SELECT TOP # "productpricelevel0".ProductId AS "productid",
    "productpricelevel0".UoMId AS "uomid",
    "productpricelevel0".ProductPriceLevelId AS "productpricelevelid",
    coalesce("LL0".Label, "productpricelevel0".ProductIdName) AS "productidname",
    "productpricelevel0".UoMIdName AS "uomidname"
FROM ProductPriceLevel AS "productpricelevel0" WITH (NOLOCK)
LEFT JOIN BusinessDataLocalizedLabel AS "LL0"
    ON (
            "LL0".ObjectId = "productpricelevel0".ProductId
            AND "LL0".LanguageId = @LanguageId0
            AND "LL0".ObjectColumnNumber = @ObjectColumnName0
            )
ORDER BY productidname ASC,
    "productpricelevel0".ProductPriceLevelId ASC

I've tried creating indexes or even an indexed view to make this faster, but CRM implements security and other filtering in the views that are being called, so these just don't help.

If I could edit the source of this query I could fix the performance issues, for example there's a big gain from specifying a table in the order by clause. But it is not my code.

I'd like to figure out what in the system is running it and stop it running 2500 times a day.

How do I trace a query hitting SQL server and work out what view, dashboard or screen is causing the query to be run, so I can customise it away?

Answer 1

You can use the CRM Platform traces to get more details. The CRM Platform at traces a Verbose level log also the SQL Queries that are executed against the DB. Basically you can:

1. Enable CRM Platform traces at a Verbose Level with Call Stack - this is very important, as the call stack can point you towards who is generating the query. If it is a CRM standard query then there isn't much you can do, however if this is a query generated by a plug-in then you can do some optimization (you will see this from the namespaces present in the call stack, usually MS CRM look like Microsoft.Crm.etc while custom plugins have their own namespace).
2. You can search within the traces for keywords that appear in the above query, for example productpricelevel0
3. Once you identified the query, look up the thread that is executing the query and the call stacks on that thread to see if it is being created by a plug-in or workflow or custom web service call or if this is a standard CRM Operation.

You can enable CRM plarform traces either via the registry https://support.microsoft.com/en-us/help/907490/how-to-enable-tracing-in-microsoft-dynamics-crm or use some codeplex tools https://archive.codeplex.com/?p=crmdiagtool2011. You'd need to enable the traces on WebServer, Sandbox and Async Server (since you don't know exactly from where this is coming from)

Also, reading the traces you can some community trace parsers like https://archive.codeplex.com/?p=crmtracereader. You can use this to filter based on the thread number.

Unfortunately, since you don't know yet how to reproduce this query on demand, you would have to enable CRM Platform traces at a Verbose level and leave them running for a period of time (probably look when this query is most often generated throughout a day and enable traces for a short period of time during that interval and repeat this operation until you get the information that you need. This is far from ideal as it will impact the performance and depending on the load generate lots of log files on the CRM Server but from my experience it is your best chance to get an accurate answer to your question.