I have a stored procedure which was running fine till 12/11 with average execution time under 2 hours. From Tuesday (12/11) onward, the stored procedure is running continuously for more than 3 hours and had to be killed and re-run again manually.
- On 12/12, we went ahead and scripted out the stored procedure. Dropped the current procedure and recreated it and it worked fine.
- On 12/13, when the procedure again took a long time to execute, we tried a similar approach of dropping and recreating it, but it didn't work this time. We had to manually run each line of the stored procedure.
- Today also it is taking a long time to run.
One thing to note is whenever that particular stored procedure is run, the processor utilization shoots up to 95%. We have SQLMonitor tool which depicts the same -
To eradicate the possibility of parameter sniffing, I cleared out the proc cache using DBCC FREEPROCCACHE
and re-ran the procedure at 5:30 AM EST again by dropping and re-creating it. Even after that there is a spike in processor utilization. Below is the current processor utilization after proc cache has been cleared -
Below is the stored procedure FYI -
CREATE PROCEDURE [dbo].[Build_Base02_Orders]
AS
BEGIN
SET NOCOUNT ON;
declare @Start_Date datetime = getdate();
declare @Last_Date datetime
DECLARE @PROMOHIGHDATE INT = (SELECT MAX(FILE_DATE) FROM Stage1_Promotion);
--Create the Orders from Items
drop table WinstonBrand_Base.dbo.Orders;
With OrdersBase1 as
(
Select * from WinstonBrand.dbo.Stage3_Orders Orders
UNION ALL
Select * from WinstonBrand.dbo.Stage1_Order_Header_HH HH
WHERE YEAR(ORDDATE) = '2005' AND NOT EXISTS (SELECT 1 FROM WinstonBrand.dbo.Stage3_Orders SO WHERE HH.ORDNO = SO.ORDNO)
)
Select *,
Row_Number() over (partition by Orders.ORDNO order by Orders.Ordno,Orders.ORDDATE DESC) as lastposition
into #baseorders
from OrdersBase1 Orders
where indid is not null
and exists
(select 1 from WinstonBrand_Base.dbo.Items items where items.ITMORDNO = orders.ORDNO)
;WITH Orders AS
(
SELECT b.*,OrderLoadDates.File_Date,
ROW_NUMBER() OVER(PARTITION BY HHID ORDER BY HHID,Ordno,Orddate) AS HOSEQNUM,
ROW_NUMBER() OVER(PARTITION BY HHID ORDER BY Orddate DESC) AS HOSEQNUMD,
P.PROMO_DESC,P.PROMO_QUALIFY_AMT
FROM #BaseOrders b
OUTER APPLY (SELECT * FROM ufnGetLastOrdHeader(b.ORDNO) a WHERE b.ORDNO=a.ORDER_NUMBER) OrderLoadDates
OUTER APPLY ufnGetSTAGE1_Promotion(Offer,@PROMOHIGHDATE) P
WHERE b.lastposition = 1
),
ORD_ODATE AS (
SELECT
HHID HO_HHID, ORDDATE HO_ODATE
FROM ORDERS
WHERE HOSEQNUM = 1
),
SHPING_CRT_HEADER AS (
SELECT
ORDER_NUMBER, MEDIUM_CODE, SOURCE_CODE, CAMPAIGN_CODE, TERM_CODE, CONTENT_CODE
FROM(
SELECT
ORDER_NUMBER,
MEDIUM_CODE,
SOURCE_CODE,
CAMPAIGN_CODE,
TERM_CODE,
CONTENT_CODE,
ROW_NUMBER() OVER(PARTITION BY CART_ID,ORDER_NUMBER ORDER BY LOAD_DATE DESC) ROW_SELECT
FROM WinstonBrand.DBO.LTD_Shopping_Cart_Header
WHERE --MEDIUM_CODE <> ''
(MEDIUM_CODE <> '' OR SOURCE_CODE <> '' OR CAMPAIGN_CODE <> '' OR TERM_CODE <> '' OR CONTENT_CODE <> '')
)A
WHERE ROW_SELECT = 1
)
SELECT
HHID,
INDID,
ADDRID,
COMPID,
ACCTNO,
EMAIL_ADD EMAIL,
Orders.ORDNO,
CAST(HOSEQNUM AS INT) AS HOSEQNUM,
CAST(HOSEQNUMD AS INT) AS HOSEQNUMD,
ORDDATE,
CAST(ORDTDOL AS NUMERIC(9,2)) AS ORDTDOL,
ORDITEMQTY,
ORDSHIPQTY,
CAST(1 AS INT) AS ORDFREQ,
SOURCE AS ORDSOURCE,
Ordchanneltype AS ORDCHANNEL,
CAST(ORDCOGS AS NUMERIC(9,2)) AS ORDCOGS,
CAST(ORDCANCEL AS NUMERIC(9,2)) AS ORDCANCEL,
CAST(ORDRETURN AS NUMERIC(9,2)) AS ORDRETURN,
CAST(ORDSOLDOUT AS NUMERIC(9,2)) AS ORDSOLDOUT,
CAST(ORDDISCNT AS NUMERIC(9,2)) AS ORDDISCNT,
CAST(ORDERTAX_AMOUNT AS NUMERIC(9,2)) AS TAXAMT,
ORDPAYMENT1,
ORDPAYMENT2,
ORDCCTYPE,
OTYPE,
offer AS ORDOFFER,
PROMO_DESC,
PROMO_QUALIFY_AMT,
keycode AS ORDKEYCODE,
ORDDER_ENTRY_DATE AS ORDER_ENTRY_DATE,
CASE WHEN file_date = '20130829' OR file_date > '20130901' THEN TRY_CONVERT(NUMERIC(9,2),FREIGHT_CHARGES)
ELSE TRY_CONVERT(NUMERIC(9,2) ,ORDERFREIGHT_AMOUNT) END
AS ORDERFREIGHT_AMOUNT,
CAST(PAYMENT_TYPECODE AS VARCHAR(20)) AS PAYMENT_TYPECODE,
SERVICE_LEVEL,
GIFT_FLAG,
UNDISCOUNTED_FREIGHT AS ORDER_UNDISCOUNTED_FREIGHT_AMOUNT,
FULLY_SHIPPEDFLAG,
APPLIED_PROMOCODE,
PROMO_GIVEN,
PROMO_DISCOUNT,
MEMBER_DISCOUNT,
MEMBER_PROGRAM,
MEMBER_PROGRAM_SEQ,
UPSELL_SEQ,
REPLACE(DETAIL_REFERRING_CAT,',','') DETAIL_REFERRING_CAT,
REFERRING_DOMAIN,
REPLACE(REFERRING_WEBSITE,',',' ') REFERRING_WEBSITE,
REPLACE(SEARCH_PHRASE,',',' ') SEARCH_PHRASE,
BRAND_CWD_EFFORT,
BRANDFROM_ORDER,
CASE WHEN file_date = '20130829' OR file_date > '20130901' THEN
TRY_CONVERT(NUMERIC(9,2), ADDTL_ORDER_CHARGES) ELSE TRY_CONVERT(NUMERIC(9,2) ,EST_FREIGHTCOSTS ) END AS PROCESSING_FEE,
CAST(ORDMKTCAT AS NUMERIC(9,2)) AS ORDMKTCAT,
CAST (ORDMKTWEB AS NUMERIC(9,2)) AS ORDMKTWEB,
TRY_CONVERT(NUMERIC(9,2),ACTUAL_FREIGHTCOSTS) AS ORDFREIGHT_EXPENSE,
CASE
WHEN CAST(ORDMKTCAT AS NUMERIC(9,2)) > 0 AND CAST (ORDMKTWEB AS NUMERIC(9,2)) > 0 THEN 'CATALOG & WEB'
WHEN CAST (ORDMKTWEB AS NUMERIC(9,2)) > 0 AND CAST(ORDMKTCAT AS NUMERIC(9,2)) = 0 THEN 'WEB ONLY'
WHEN CAST(ORDMKTCAT AS NUMERIC(9,2)) > 0 AND CAST (ORDMKTWEB AS NUMERIC(9,2)) = 0 THEN 'CATALOG ONLY'
ELSE NULL
END AS MRKTCHANNEL,
HO_ODATE,
ISNULL(MEDIUM_CODE,'') UTM_MEDIUM_CODE,
ISNULL(SOURCE_CODE,'') UTM_SOURCE_CODE,
ISNULL(CAMPAIGN_CODE,'') UTM_CAMPAIGN_CODE,
ISNULL(TERM_CODE,'') UTM_TERM_CODE,
ISNULL(CONTENT_CODE,'') UTM_CONTENT_CODE
INTO WinstonBrand_Base.dbo.Orders
FROM Orders
OUTER APPLY ufnGetOrderItemSum(ORDNO ,GIFT) CUSTITEM
LEFT JOIN ORD_ODATE ON HHID = HO_HHID
LEFT JOIN SHPING_CRT_HEADER S ON Orders.ORDNO = S.ORDER_NUMBER;
/****** Object: Index [NonClusteredIndex-20130929-123603] Script Date: 9/29/2013 12:37:39 PM ******/
CREATE NONCLUSTERED INDEX [NonClusteredIndex-20130929-123603] ON WinstonBrand_Base.dbo.Orders
(
[HHID] ASC,
[INDID] ASC,
[ACCTNO] ASC,
[ORDNO] ASC,
--[AOSEQNUM] ASC,
[HOSEQNUM] ASC,
[HOSEQNUMD] ASC,
--[IOSEQNUM] ASC,
[ORDDATE] ASC
)WITH (PAD_INDEX = OFF, STATISTICS_NORECOMPUTE = OFF, SORT_IN_TEMPDB = OFF, DROP_EXISTING = OFF, ONLINE = OFF, ALLOW_ROW_LOCKS = ON, ALLOW_PAGE_LOCKS = ON) ON [PRIMARY];
END
Here is the user-defined function ufnGetLastOrdHeader
used in the stored procedure -
USE [WinstonBrand]
GO
/****** Object: UserDefinedFunction [dbo].[ufnGetLastOrdHeader] Script Date: 12/14/2018 6:50:33 AM ******/
SET ANSI_NULLS ON
GO
SET QUOTED_IDENTIFIER ON
GO
CREATE FUNCTION [dbo].[ufnGetLastOrdHeader](@ORDNO varchar(20))
RETURNS TABLE
AS
RETURN (
select ORDER_NUMBER, ORDERFREIGHT_AMOUNT,UNDISCOUNTED_FREIGHT,ACTUAL_FREIGHTCOSTS,EST_FREIGHTCOSTS, ADDTL_ORDER_CHARGES,ADDTL_HANDLING_FEE,FREIGHT_CHARGES, file_date,lastposition from(
SELECT ORDER_NUMBER, ORDERFREIGHT_AMOUNT,UNDISCOUNTED_FREIGHT,ACTUAL_FREIGHTCOSTS,EST_FREIGHTCOSTS,ADDTL_ORDER_CHARGES,ADDTL_HANDLING_FEE,FREIGHT_CHARGES,file_date
, row_number() over (partition by ORDER_NUMBER order by FILE_DATE DESC) as lastposition
FROM Stage1_Order_Header where ORDER_NUMBER=@ORDNO
) S1_OH where lastposition=1)
GO
My question is I am unable to understand why there is a sudden processor utilization when only this procedure is run. Is there anything else other than parameter sniffing which I should look at. The version of SQL Server is 2016-SP1. Let me know if any more details are required.
EDIT -
I ran the following 4 commands on my SSMS
window
DBCC FREESYSTEMCACHE ('ALL')
DBCC FREESESSIONCACHE
DBCC FREEPROCCACHE
DBCC DROPCLEANBUFFERS
After that I started executing my query by making a few changes (since it was being done on a PRODUCTION box). Below is the used query and the execution plan -
SET STATISTICS IO ON;
SET STATISTICS TIME ON;
SET NOCOUNT ON;
declare @Start_Date datetime = getdate();
declare @Last_Date datetime
DECLARE @PROMOHIGHDATE INT = (SELECT MAX(FILE_DATE) FROM Stage1_Promotion);
With OrdersBase1 as
(
Select * from WinstonBrand.dbo.Stage3_Orders Orders with (nolock)
UNION ALL
Select * from WinstonBrand.dbo.Stage1_Order_Header_HH HH with (nolock)
WHERE YEAR(ORDDATE) = '2005' AND NOT EXISTS (SELECT 1 FROM WinstonBrand.dbo.Stage3_Orders SO with (nolock) WHERE HH.ORDNO = SO.ORDNO)
)
Select *,
Row_Number() over (partition by Orders.ORDNO order by Orders.Ordno,Orders.ORDDATE DESC) as lastposition
into #baseorders
from OrdersBase1 Orders with (nolock) --WinstonBrand.dbo.stage3_Orders Orders
where indid is not null
and exists
(select 1 from WinstonBrand_Base.dbo.Items items with (nolock) where items.ITMORDNO = orders.ORDNO)
;WITH Orders AS
(
SELECT b.*,OrderLoadDates.File_Date,
ROW_NUMBER() OVER(PARTITION BY HHID ORDER BY HHID,Ordno,Orddate) AS HOSEQNUM,
ROW_NUMBER() OVER(PARTITION BY HHID ORDER BY Orddate DESC) AS HOSEQNUMD,
P.PROMO_DESC,P.PROMO_QUALIFY_AMT
FROM #BaseOrders b
OUTER APPLY (SELECT * FROM ufnGetLastOrdHeader(b.ORDNO) a WHERE b.ORDNO=a.ORDER_NUMBER) OrderLoadDates
OUTER APPLY ufnGetSTAGE1_Promotion(Offer,@PROMOHIGHDATE) P
WHERE b.lastposition = 1
),
ORD_ODATE AS (
SELECT
HHID HO_HHID, ORDDATE HO_ODATE
FROM ORDERS
WHERE HOSEQNUM = 1
),
SHPING_CRT_HEADER AS (
SELECT
ORDER_NUMBER, MEDIUM_CODE, SOURCE_CODE, CAMPAIGN_CODE, TERM_CODE, CONTENT_CODE
FROM(
SELECT
ORDER_NUMBER,
MEDIUM_CODE,
SOURCE_CODE,
CAMPAIGN_CODE,
TERM_CODE,
CONTENT_CODE,
ROW_NUMBER() OVER(PARTITION BY CART_ID,ORDER_NUMBER ORDER BY LOAD_DATE DESC) ROW_SELECT
FROM WinstonBrand.DBO.LTD_Shopping_Cart_Header with (nolock)
WHERE --MEDIUM_CODE <> ''
(MEDIUM_CODE <> '' OR SOURCE_CODE <> '' OR CAMPAIGN_CODE <> '' OR TERM_CODE <> '' OR CONTENT_CODE <> '')
)A
WHERE ROW_SELECT = 1
)
SELECT
HHID,
INDID,
ADDRID,
COMPID,
ACCTNO,
EMAIL_ADD EMAIL,
Orders.ORDNO,
CAST(HOSEQNUM AS INT) AS HOSEQNUM,
CAST(HOSEQNUMD AS INT) AS HOSEQNUMD,
ORDDATE,
CAST(ORDTDOL AS NUMERIC(9,2)) AS ORDTDOL,
ORDITEMQTY,
ORDSHIPQTY,
CAST(1 AS INT) AS ORDFREQ,
SOURCE AS ORDSOURCE,
Ordchanneltype AS ORDCHANNEL,
CAST(ORDCOGS AS NUMERIC(9,2)) AS ORDCOGS,
CAST(ORDCANCEL AS NUMERIC(9,2)) AS ORDCANCEL,
CAST(ORDRETURN AS NUMERIC(9,2)) AS ORDRETURN,
CAST(ORDSOLDOUT AS NUMERIC(9,2)) AS ORDSOLDOUT,
CAST(ORDDISCNT AS NUMERIC(9,2)) AS ORDDISCNT,
CAST(ORDERTAX_AMOUNT AS NUMERIC(9,2)) AS TAXAMT,
ORDPAYMENT1,
ORDPAYMENT2,
ORDCCTYPE,
OTYPE,
offer AS ORDOFFER,
PROMO_DESC,
PROMO_QUALIFY_AMT,
keycode AS ORDKEYCODE,
ORDDER_ENTRY_DATE AS ORDER_ENTRY_DATE,
--Freight_Charges,
CASE WHEN file_date = '20130829' OR file_date > '20130901' THEN TRY_CONVERT(NUMERIC(9,2),FREIGHT_CHARGES)
ELSE TRY_CONVERT(NUMERIC(9,2) ,ORDERFREIGHT_AMOUNT) END
AS ORDERFREIGHT_AMOUNT,
CAST(PAYMENT_TYPECODE AS VARCHAR(20)) AS PAYMENT_TYPECODE,
SERVICE_LEVEL,
GIFT_FLAG,
UNDISCOUNTED_FREIGHT AS ORDER_UNDISCOUNTED_FREIGHT_AMOUNT,
--ACTUAL_FREIGHTCOSTS as FREIGHT_EXPENSE,
FULLY_SHIPPEDFLAG,
APPLIED_PROMOCODE,
PROMO_GIVEN,
PROMO_DISCOUNT,
MEMBER_DISCOUNT,
MEMBER_PROGRAM,
MEMBER_PROGRAM_SEQ,
UPSELL_SEQ,
REPLACE(DETAIL_REFERRING_CAT,',','') DETAIL_REFERRING_CAT,
REFERRING_DOMAIN,
REPLACE(REFERRING_WEBSITE,',',' ') REFERRING_WEBSITE,
REPLACE(SEARCH_PHRASE,',',' ') SEARCH_PHRASE,
BRAND_CWD_EFFORT,
BRANDFROM_ORDER,
CASE WHEN file_date = '20130829' OR file_date > '20130901' THEN
TRY_CONVERT(NUMERIC(9,2), ADDTL_ORDER_CHARGES) ELSE TRY_CONVERT(NUMERIC(9,2) ,EST_FREIGHTCOSTS ) END AS PROCESSING_FEE,
CAST(ORDMKTCAT AS NUMERIC(9,2)) AS ORDMKTCAT,
CAST (ORDMKTWEB AS NUMERIC(9,2)) AS ORDMKTWEB,
TRY_CONVERT(NUMERIC(9,2),ACTUAL_FREIGHTCOSTS) AS ORDFREIGHT_EXPENSE,
CASE
WHEN CAST(ORDMKTCAT AS NUMERIC(9,2)) > 0 AND CAST (ORDMKTWEB AS NUMERIC(9,2)) > 0 THEN 'CATALOG & WEB'
WHEN CAST (ORDMKTWEB AS NUMERIC(9,2)) > 0 AND CAST(ORDMKTCAT AS NUMERIC(9,2)) = 0 THEN 'WEB ONLY'
WHEN CAST(ORDMKTCAT AS NUMERIC(9,2)) > 0 AND CAST (ORDMKTWEB AS NUMERIC(9,2)) = 0 THEN 'CATALOG ONLY'
ELSE NULL
END AS MRKTCHANNEL,
HO_ODATE,
ISNULL(MEDIUM_CODE,'') UTM_MEDIUM_CODE,
ISNULL(SOURCE_CODE,'') UTM_SOURCE_CODE,
ISNULL(CAMPAIGN_CODE,'') UTM_CAMPAIGN_CODE,
ISNULL(TERM_CODE,'') UTM_TERM_CODE,
ISNULL(CONTENT_CODE,'') UTM_CONTENT_CODE
INTO WinstonBrand_Base.dbo.Orders_DBA
FROM Orders with (nolock)
OUTER APPLY ufnGetOrderItemSum(ORDNO ,GIFT) CUSTITEM
LEFT JOIN ORD_ODATE ON HHID = HO_HHID
LEFT JOIN SHPING_CRT_HEADER S ON Orders.ORDNO = S.ORDER_NUMBER;
/****** Object: Index [NonClusteredIndex-20130929-123603] Script Date: 9/29/2013 12:37:39 PM ******/
CREATE NONCLUSTERED INDEX [NonClusteredIndex-20130929-123603_DBA] ON WinstonBrand_Base.dbo.Orders_DBA
(
[HHID] ASC,
[INDID] ASC,
[ACCTNO] ASC,
[ORDNO] ASC,
[HOSEQNUM] ASC,
[HOSEQNUMD] ASC,
[ORDDATE] ASC
)WITH (PAD_INDEX = OFF, STATISTICS_NORECOMPUTE = OFF, SORT_IN_TEMPDB = OFF, DROP_EXISTING = OFF, ONLINE = OFF, ALLOW_ROW_LOCKS = ON, ALLOW_PAGE_LOCKS = ON) ON [PRIMARY];
SET STATISTICS IO OFF;
SET STATISTICS TIME OFF;
Below are the messages printed on SSMS Result window -
SQL Server Execution Times: CPU time = 0 ms, elapsed time = 0 ms.
SQL Server Execution Times: CPU time = 0 ms, elapsed time = 0 ms. Table 'Stage1_Promotion'. Scan count 1, logical reads 2248, physical reads 4, read-ahead reads 2198, lob logical reads 0, lob physical reads 0, lob read-ahead reads 0.
SQL Server Execution Times: CPU time = 47 ms, elapsed time = 68 ms. Table 'Items'. Scan count 6, logical reads 11895581, physical reads 8481, read-ahead reads 11793819, lob logical reads 0, lob physical reads 0, lob read-ahead reads 0. Table 'Stage3_Orders'. Scan count 12, logical reads 2258024, physical reads 41, read-ahead reads 2257333, lob logical reads 0, lob physical reads 0, lob read-ahead reads 0. Table 'Stage1_Order_Header_HH'. Scan count 6, logical reads 435021, physical reads 0, read-ahead reads 435021, lob logical reads 0, lob physical reads 0, lob read-ahead reads 0. Table 'Worktable'. Scan count 0, logical reads 0, physical reads 0, read-ahead reads 0, lob logical reads 0, lob physical reads 0, lob read-ahead reads 0. Table 'Workfile'. Scan count 50, logical reads 83864, physical reads 7283, read-ahead reads 76581, lob logical reads 0, lob physical reads 0, lob read-ahead reads 0.
SQL Server Execution Times: CPU time = 1370469 ms, elapsed time = 836897 ms.
SQL Server parse and compile time: CPU time = 5734 ms, elapsed time = 5827 ms. Table 'Worktable'. Scan count 203343290, logical reads 1778461093, physical reads 470694, read-ahead reads 2151647, lob logical reads 0, lob physical reads 0, lob read-ahead reads 0. Table 'LTD_Shopping_Cart_Header'. Scan count 1, logical reads 404060, physical reads 0, read-ahead reads 404060, lob logical reads 0, lob physical reads 0, lob read-ahead reads 0. Table 'Workfile'. Scan count 3752, logical reads 9917704, physical reads 1903935, read-ahead reads 13387577, lob logical reads 0, lob physical reads 0, lob read-ahead reads 0. Table 'Items'. Scan count 1, logical reads 11895581, physical reads 6902, read-ahead reads 11292947, lob logical reads 0, lob physical reads 0, lob read-ahead reads 0. Table 'Stage1_Order_Header'. Scan count 2, logical reads 2068767, physical reads 4, read-ahead reads 1034391, lob logical reads 0, lob physical reads 0, lob read-ahead reads 0. Table '#baseorders_________________________________________________________________________________________________________000000001C31'. Scan count 2, logical reads 4239764, physical reads 140, read-ahead reads 1994015, lob logical reads 0, lob physical reads 0, lob read-ahead reads 0. Table 'Stage1_Promotion'. Scan count 2, logical reads 4496, physical reads 4, read-ahead reads 2198, lob logical reads 0, lob physical reads 0, lob read-ahead reads 0. Warning: Null value is eliminated by an aggregate or other SET operation.
SQL Server Execution Times: CPU time = 7282594 ms, elapsed time = 8292072 ms. Table 'Worktable'. Scan count 0, logical reads 0, physical reads 0, read-ahead reads 521245, lob logical reads 0, lob physical reads 0, lob read-ahead reads 0. Table 'Orders_DBA'. Scan count 1, logical reads 2343169, physical reads 0, read-ahead reads 31057, lob logical reads 0, lob physical reads 0, lob read-ahead reads 0.
SQL Server Execution Times: CPU time = 298765 ms, elapsed time = 312090 ms.
SQL Server Execution Times: CPU time = 0 ms, elapsed time = 0 ms.
Below is the Resource Utilization graph for the time period the query ran. The query started to run at 15:43 EST
and took 2:37:27
hours to complete.
Here is the link to the query plan.