Recently a client of mine was experiencing performance issues with the daily Master Resource Planning (MRP) process run, in particular, not only would it run for extended periods but it would also stop other users from performing their tasks.

Looking under the covers I could see that a large blocking chain would develop just after starting the MRP run. The blocking lock root cause related to the below statement

DELETE FROM INVENTSUMLOGTTS WHERE ((DATAAREAID=@P1) AND (ISCOMMITTED=@P2))

The DELETE statement would be executed by the MRP process near the beginning of the run and would only take 1.5 to 2 seconds but then in the same transaction another 80000+ statements would be executed, and depending on the system contention, the transaction would stay open from several minutes to sometimes 30+ minutes. Basically the locks held by the MRP process on the INVENTSUMLOGTTS table would block other user processes that wanted to insert into this table.

The first port of call to resolve the issue was to determine if there was a statement in the 80000+ subsequent statements was taking too long to execute. Looking at the SQL trace of the MRP run, there wasn’t a statement with a really large duration, however, there was one type of statement that would range from 15 milliseconds to 1.5 second per run that was executed thousands of times. Unfortunately the SQL trace did not contain the API Cursor (prepare statement) that would identify the actual SQL text of the statement in question.

However, while I was running the trace I also ran a DMV query to determine the currently running SQL statements and more often than not the following statement was displayed.

SELECT SUM(A.QTY),A.ITEMID, A.ITEMBOMID A.TRANSTYPE, A.TRANSREFID, A.INVENTREFTRANSID, A.STATUSISSUE,  A.STATUSRECEIPT, A.DATESTATUS, A.INVENTTRANSID,  A.PROBABILITYID, B.INVENTLOCATIONID

FROM INVENTTRANS A,INVENTDIM B

WHERE ((A.DATAAREAID=@P1) AND (((A.ITEMID=@P2) AND (A.STATUSRECEIPT=@P3)) AND ((A.STATUSISSUE>=@P4) AND (A.STATUSISSUE<=@P5)))) AND ((B.DATAAREAID=@P6) AND (A.INVENTDIMID=B.INVENTDIMID))

GROUP BY A.ITEMID, A.ITEMBOMID, A.TRANSTYPE, A.TRANSREFID, A.INVENTREFTRANSID, A.STATUSISSUE, A.STATUSRECEIPT, A.DATESTATUS, A.INVENTTRANSID, A.PROBABILITYID, B.INVENTLOCATIONID

ORDER BY A.ITEMID, A.ITEMBOMID, A.TRANSTYPE,A.TRANSREFID, A.INVENTREFTRANSID, A.STATUSISSUE, A.STATUSRECEIPT, A.DATESTATUS, A.INVENTTRANSID,  A.PROBABILITYID, B.INVENTLOCATIONID

I then tried to find the API cursor call in the SQL Trace that would match the parameter list in the WHERE clause and found thousands of calls like

exec sp_cursorexecute 1073741848,@p2 output,@p3 output,@p4 output,@p5 output, N’xxx’ ,N’1146583′, 0,4,6,N’xxx’

I then saved the SQL trace to a table and ran the following SQL statement against the trace table to verify that the above statement contributed to the bulk of the durations for the MRP run.

SELECT sum(duration*1.000/1000)/1000 FROM Tracetable WHERE textdata LIKE ‘{2ec0bbd3bfdf207d2f0779c26660c3798ccadae611e41b6dbc787103c4a85cdd}1073741848{2ec0bbd3bfdf207d2f0779c26660c3798ccadae611e41b6dbc787103c4a85cdd}’

Where 1073741848 was the API cursor ID.

The query plan for this statement showed that the statement was not using the best index and instead it was performing a range scan over an index based on the ITEMID column. The Index Statistics were all up to date so it wasn’t an out of date statistics issue. I then decided to create a covering index below to try to force a direct lookup

CREATE NONCLUSTERED INDEX ix_INVENTTRANS_mrp
ON dbo.INVENTTRANS  (ITEMID , STATUSRECEIPT , DATAAREAID ,  STATUSISSUE )
INCLUDE (QTY,TRANSTYPE , TRANSREFID , INVENTTRANSID, DATESTATUS, ITEMBOMID , INVENTDIMID , INVENTREFTRANSID , PROBABILITYID )

OK so I created the index and subsequent runs of the MRP process was consistently reduced to 6 to 7 minute per run, the troublesome SQL statement now ran in 10 or less milliseconds.

However, the initial transaction was still holding locks on INVENTSUMLOGTTS TABLE for a period of around 2 minutes, and therefore, other user processes were still being blocked, all be it for a shorter period of time.

Looking at some KB articles on Dynamic AX it seemed that Lock Escalation issues with the MRP process were possible. So I decided to include  the Lock Escalation event into the next SQL trace.

A subsequent trace confirmed that in deed a Lock Escalation event was occurring on the INVENTSUMLOGTTS table, effectively an exclusive table lock was being applied due to the number of records being deleted by the DELETE statement executed by the MRP process.

The delete statement was deleting all records and the escalated table lock was stopping other user processes from inserting records into the INVENTSUMLOGTTS table. So in my case the workaround was to disable the Lock Escalation for the specific table using the following statement.

ALTER TABLE INVENTSUMLOGTTS  SET (LOCK_ESCALATION=DISABLE)

Sure enough the blocking issue was resolved, the MRP process could happily be run and other users would not be blocked from inserting into the INVENTSUMLOGTTS.

Note that disabling lock escalation for a table is a feature SQL Server 2008 or above.