In this case I would suggest you to contact Episerver support services and file a support case. I'd say this is related to your database and/or catalog structure

I've been spinning my wheels for this for awhile, and Episerver Expert services isn't an option. Our current production website uses the same exact catalog. I just re-pulled down the commercemanager database from production to dev and reupgraded the sql. I'm still having this issue. Any ideas where you would start with this issue?

-Paul

Let me ask you something, is it possible that the new versions of Commerce aren't compatable with a catalog of our size? We've got 33,000 products.

This issue appears to occur when calling the function CatalogContentProperty_LoadBatch. Looking at the CatalogContentProperties table, we've got 1.5 million records. Could this be causing the issue here? I pulled in the quicksilver commerce demo and it worked for me.

-Paul

Worth noting, I'm connecting to a database on my dev environment that went through the sql upgrade, but the data is exactly the same. This data works on production, but no dev.

Try setting the commandTimeout higher to see if it alleviates the problem for now.

<dataService defaultProvider="SqlDataProvider">
      <providers>
        <add name="SqlDataProvider" type="Mediachase.Data.Provider.SqlDataProvider, Mediachase.SqlDataProvider" connectionStringName="EcfSqlConnection" applicationName="ECApplication" commandTimeout="120" />
      </providers>
    </dataService>

33k products and 1.5M rows in CatalogProperty are not something particular big, and they are in well supported size of catalog.

However your dev machine might be less powerful than your production server, which makes SQL Server takes longer time to process the request.

As I said, it'd be best if we get a hand on your database. Or you can use SQL Profiler to see which parameters cause timeout on that SP, and try to get an execution plan on that. 

Hey Guys,
Thanks for your help with this issue. I put that line into the web.config and it didn't fix the issue. I repulled out production database to our dev enviornment and reran the migration scripts and still no go.

So I've been looking into this issue for awhile now and I've narrowed it down to a single stored procedure. That procedure takes FOREVER to run.

When I run the following query it takes a long time.

declare @p1 dbo.udttCatalogContentPropertyReference
insert into @p1 values(602,1,44,N'en')
insert into @p1 values(604,1,44,N'en')
insert into @p1 values(605,1,44,N'en')
insert into @p1 values(606,1,44,N'en')
insert into @p1 values(625,1,44,N'en')
insert into @p1 values(626,1,44,N'en')
insert into @p1 values(698,1,44,N'en')
insert into @p1 values(786,1,44,N'en')
insert into @p1 values(787,1,44,N'en')
insert into @p1 values(788,1,44,N'en')
insert into @p1 values(1000,1,44,N'en')
insert into @p1 values(1012,1,44,N'en')
insert into @p1 values(1099,1,44,N'en')
insert into @p1 values(1104,1,44,N'en')

exec CatalogContentProperty_LoadBatch @PropertyReferences=@p1
go

This is what my CatalogContentProperty Stored proc looks like.

CREATE PROCEDURE [dbo].[CatalogContentProperty_LoadBatch]
	@PropertyReferences [udttCatalogContentPropertyReference] READONLY
AS
BEGIN
	
	IF dbo.mdpfn_sys_IsAzureCompatible() = 0  --Fields will be encrypted only when DB does not support Azure
		BEGIN
		EXEC mdpsp_sys_OpenSymmetricKey
		
		;WITH CTE1 AS (
			SELECT R.*, E.CatalogId
			FROM @PropertyReferences R
			INNER JOIN CatalogEntry E ON E.CatalogEntryId = R.ObjectId AND R.ObjectTypeId = 0
		UNION ALL
			SELECT R.*, N.CatalogId
			FROM @PropertyReferences R
			INNER JOIN CatalogNode N ON N.CatalogNodeId = R.ObjectId AND R.ObjectTypeId = 1
		),
		CTE2 AS (
			SELECT CTE1.ObjectId, CTE1.ObjectTypeId, CTE1.MetaClassId, ISNULL(L.LanguageCode, C.DefaultLanguage) AS LanguageName, C.DefaultLanguage
			FROM CTE1
			INNER JOIN [Catalog] C ON C.CatalogId = CTE1.CatalogId
			LEFT OUTER JOIN CatalogLanguage L ON L.CatalogId = CTE1.CatalogId AND L.LanguageCode = CTE1.LanguageName
		)
		-- Select CatalogContentProperty data
		SELECT P.ObjectId, P.ObjectTypeId, P.MetaFieldId, P.MetaClassId, P.MetaFieldName, P.LanguageName,
							P.Boolean, P.Number, P.FloatNumber, P.[Money], P.[Decimal], P.[Date], P.[Binary], P.[String], 
							CASE WHEN (F.IsEncrypted = 1 AND dbo.mdpfn_sys_IsLongStringMetaField(F.DataTypeId) = 1) 
								THEN dbo.mdpfn_sys_EncryptDecryptString(P.LongString, 0) 
								ELSE P.LongString END 
							AS LongString,
							P.[Guid]  
		FROM dbo.CatalogContentProperty P
		INNER JOIN MetaField F ON P.MetaFieldId = F.MetaFieldId
		INNER JOIN CTE2 ON
			P.ObjectId = CTE2.ObjectId AND
			P.ObjectTypeId = CTE2.ObjectTypeId AND
			P.MetaClassId = CTE2.MetaClassId AND
			((F.MultiLanguageValue = 1 AND P.LanguageName = CTE2.LanguageName COLLATE DATABASE_DEFAULT) OR ((F.MultiLanguageValue = 0 AND P.LanguageName = CTE2.DefaultLanguage COLLATE DATABASE_DEFAULT)))
		EXEC mdpsp_sys_CloseSymmetricKey
		END
	ELSE
		BEGIN
		
		;WITH CTE1 AS (
			SELECT R.*, E.CatalogId
			FROM @PropertyReferences R
			INNER JOIN CatalogEntry E ON E.CatalogEntryId = R.ObjectId AND R.ObjectTypeId = 0
		UNION ALL
			SELECT R.*, N.CatalogId
			FROM @PropertyReferences R
			INNER JOIN CatalogNode N ON N.CatalogNodeId = R.ObjectId AND R.ObjectTypeId = 1
		),
		CTE2 AS (
			SELECT CTE1.ObjectId, CTE1.ObjectTypeId, CTE1.MetaClassId, ISNULL(L.LanguageCode, C.DefaultLanguage) AS LanguageName, C.DefaultLanguage
			FROM CTE1
			INNER JOIN [Catalog] C ON C.CatalogId = CTE1.CatalogId
			LEFT OUTER JOIN CatalogLanguage L ON L.CatalogId = CTE1.CatalogId AND L.LanguageCode = CTE1.LanguageName
		)	
		SELECT P.ObjectId, P.ObjectTypeId, P.MetaFieldId, P.MetaClassId, P.MetaFieldName, P.LanguageName,
							P.Boolean, P.Number, P.FloatNumber, P.[Money], P.[Decimal], P.[Date], P.[Binary], P.[String], P.LongString LongString,
							P.[Guid]  
		FROM dbo.CatalogContentProperty P
		INNER JOIN MetaField F ON P.MetaFieldId = F.MetaFieldId
		INNER JOIN CTE2 ON
			P.ObjectId = CTE2.ObjectId AND
			P.ObjectTypeId = CTE2.ObjectTypeId AND
			P.MetaClassId = CTE2.MetaClassId AND
			((F.MultiLanguageValue = 1 AND P.LanguageName = CTE2.LanguageName COLLATE DATABASE_DEFAULT) OR ((F.MultiLanguageValue = 0 AND P.LanguageName = CTE2.DefaultLanguage COLLATE DATABASE_DEFAULT)))
		END
	-- Select CatalogContentEx data
	SELECT *
	FROM dbo.CatalogContentEx Ex 
	INNER JOIN @PropertyReferences R ON Ex.ObjectId = R.ObjectId AND Ex.ObjectTypeId = R.ObjectTypeId
END


GO

The crazy thing about this, is that when I run the query SQL contents straight from the stored procedure it's fast!

declare @PropertyReferences dbo.udttCatalogContentPropertyReference
insert into @PropertyReferences values(602,1,44,N'en')
insert into @PropertyReferences values(604,1,44,N'en')
insert into @PropertyReferences values(605,1,44,N'en')
insert into @PropertyReferences values(606,1,44,N'en')
insert into @PropertyReferences values(625,1,44,N'en')
insert into @PropertyReferences values(626,1,44,N'en')
insert into @PropertyReferences values(698,1,44,N'en')
insert into @PropertyReferences values(786,1,44,N'en')
insert into @PropertyReferences values(787,1,44,N'en')
insert into @PropertyReferences values(788,1,44,N'en')
insert into @PropertyReferences values(1000,1,44,N'en')
insert into @PropertyReferences values(1012,1,44,N'en')
insert into @PropertyReferences values(1099,1,44,N'en')
insert into @PropertyReferences values(1104,1,44,N'en')


	IF dbo.mdpfn_sys_IsAzureCompatible() = 0  --Fields will be encrypted only when DB does not support Azure
		BEGIN
		EXEC mdpsp_sys_OpenSymmetricKey
		
		;WITH CTE1 AS (
			SELECT R.*, E.CatalogId
			FROM @PropertyReferences R
			INNER JOIN CatalogEntry E ON E.CatalogEntryId = R.ObjectId AND R.ObjectTypeId = 0
		UNION ALL
			SELECT R.*, N.CatalogId
			FROM @PropertyReferences R
			INNER JOIN CatalogNode N ON N.CatalogNodeId = R.ObjectId AND R.ObjectTypeId = 1
		),
		CTE2 AS (
			SELECT CTE1.ObjectId, CTE1.ObjectTypeId, CTE1.MetaClassId, ISNULL(L.LanguageCode, C.DefaultLanguage) AS LanguageName, C.DefaultLanguage
			FROM CTE1
			INNER JOIN [Catalog] C ON C.CatalogId = CTE1.CatalogId
			LEFT OUTER JOIN CatalogLanguage L ON L.CatalogId = CTE1.CatalogId AND L.LanguageCode = CTE1.LanguageName
		)
		-- Select CatalogContentProperty data
		SELECT P.ObjectId, P.ObjectTypeId, P.MetaFieldId, P.MetaClassId, P.MetaFieldName, P.LanguageName,
							P.Boolean, P.Number, P.FloatNumber, P.[Money], P.[Decimal], P.[Date], P.[Binary], P.[String], 
							CASE WHEN (F.IsEncrypted = 1 AND dbo.mdpfn_sys_IsLongStringMetaField(F.DataTypeId) = 1) 
								THEN dbo.mdpfn_sys_EncryptDecryptString(P.LongString, 0) 
								ELSE P.LongString END 
							AS LongString,
							P.[Guid]  
		FROM dbo.CatalogContentProperty P
		INNER JOIN MetaField F ON P.MetaFieldId = F.MetaFieldId
		INNER JOIN CTE2 ON
			P.ObjectId = CTE2.ObjectId AND
			P.ObjectTypeId = CTE2.ObjectTypeId AND
			P.MetaClassId = CTE2.MetaClassId AND
			((F.MultiLanguageValue = 1 AND P.LanguageName = CTE2.LanguageName COLLATE DATABASE_DEFAULT) OR ((F.MultiLanguageValue = 0 AND P.LanguageName = CTE2.DefaultLanguage COLLATE DATABASE_DEFAULT)))
		EXEC mdpsp_sys_CloseSymmetricKey
		END
	ELSE
		BEGIN
		
		;WITH CTE1 AS (
			SELECT R.*, E.CatalogId
			FROM @PropertyReferences R
			INNER JOIN CatalogEntry E ON E.CatalogEntryId = R.ObjectId AND R.ObjectTypeId = 0
		UNION ALL
			SELECT R.*, N.CatalogId
			FROM @PropertyReferences R
			INNER JOIN CatalogNode N ON N.CatalogNodeId = R.ObjectId AND R.ObjectTypeId = 1
		),
		CTE2 AS (
			SELECT CTE1.ObjectId, CTE1.ObjectTypeId, CTE1.MetaClassId, ISNULL(L.LanguageCode, C.DefaultLanguage) AS LanguageName, C.DefaultLanguage
			FROM CTE1
			INNER JOIN [Catalog] C ON C.CatalogId = CTE1.CatalogId
			LEFT OUTER JOIN CatalogLanguage L ON L.CatalogId = CTE1.CatalogId AND L.LanguageCode = CTE1.LanguageName
		)	
		SELECT P.ObjectId, P.ObjectTypeId, P.MetaFieldId, P.MetaClassId, P.MetaFieldName, P.LanguageName,
							P.Boolean, P.Number, P.FloatNumber, P.[Money], P.[Decimal], P.[Date], P.[Binary], P.[String], P.LongString LongString,
							P.[Guid]  
		FROM dbo.CatalogContentProperty P
		INNER JOIN MetaField F ON P.MetaFieldId = F.MetaFieldId
		INNER JOIN CTE2 ON
			P.ObjectId = CTE2.ObjectId AND
			P.ObjectTypeId = CTE2.ObjectTypeId AND
			P.MetaClassId = CTE2.MetaClassId AND
			((F.MultiLanguageValue = 1 AND P.LanguageName = CTE2.LanguageName COLLATE DATABASE_DEFAULT) OR ((F.MultiLanguageValue = 0 AND P.LanguageName = CTE2.DefaultLanguage COLLATE DATABASE_DEFAULT)))
		END
	-- Select CatalogContentEx data
	SELECT *
	FROM dbo.CatalogContentEx Ex 
	INNER JOIN @PropertyReferences R ON Ex.ObjectId = R.ObjectId AND Ex.ObjectTypeId = R.ObjectTypeId

This is litterally exactly the same query/parameters as what the stored proc runs, except running this code through the stored proc is slow as heck, and it's like 0 seconds doing it here.

Ha, you might be one victim of what called "parameter sniffing" 

Try

ATER PROCEDURE [dbo].[CatalogContentProperty_LoadBatch]
	@PropertyReferences [udttCatalogContentPropertyReference] READONLY
WITH RECOMPILE 
AS ....

Thanks for your help with this Quan. I did that, but still no go. It's still ridiculously slow. I made the below change, and it seems to have fixed everything however I'm not really a huge fan of rewriting EPiserver stored procedures. Though, worth noting this one was way over engineered.

ALTER PROCEDURE [dbo].[CatalogContentProperty_LoadBatch]
	@PropertyReferences [udttCatalogContentPropertyReference] READONLY
AS
BEGIN
	

SELECT ccp.objectId, ccp.objectTypeId, ccp.MetaFieldId, ccp.MetaClassId, ccp.MetaFieldName, ccp.LanguageName, ccp.Boolean, ccp.Number, ccp.FloatNumber, ccp.[Money], ccp.[Decimal], ccp.[Date], ccp.[Binary], ccp.[String], ccp.[LongString], ccp.[Guid]	
FROM CatalogContentProperty ccp 
	INNER JOIN @PropertyReferences pr ON ccp.ObjectId = pr.ObjectId 
		AND ccp.LanguageName = pr.LanguageName 
		AND ccp.MetaClassId = pr.MetaClassId


	-- Select CatalogContentEx data
	SELECT *
	FROM dbo.CatalogContentEx Ex 
	INNER JOIN @PropertyReferences R ON Ex.ObjectId = R.ObjectId AND Ex.ObjectTypeId = R.ObjectTypeId
END

GO

No rewriting Episerver SPs should not be the solution.

Care to run with execution plan to see the difference? 

I agree 100%. But the current stored proc isn't working. I'll work through this with you though, I'd love to come up with a better solution.

Do you want a screenshot of the execution plan, or an xml dump?

why not both? one for a quick glance and one for detail investigation

This is the execution plan that occurs when I run the contents of the sql.

This is the execution plan from the stored proc execution.

It's crazy how different these execution plans are despite the fact that it's litterally exactly the same database/code. The only difference between these, is that one is in a stored proc and the other is the code that's inside the stored proc that I pulled out and added the execution variables at the top.

Not sure if this is a cuprit, or a symptom, but when I run this stored procedure and view the execution plan, I notice that there is a hash match, with a warning in the execution plan. Mousing over this is says this...

The records returned between the adhoc and stored procedure are exactly the same, except the execution plan is different, the adhoc one is 0 seconds while the other one is about 40. Also the records returned are the same, except the adhoc one is sorted by objectid, while the other one isn't sorted by anything really.

-Paul

You can view the full sql execution plan here...

Adhoc Query
https://filebin.net/037p73eu0aaqiscp/Episerver.CatalogContentProperty_LoadBatch_Adhoc_Execution_Plan.sqlplan

Stored Procedure
https://filebin.net/037p73eu0aaqiscp/Episerver.CatalogContentProperty_LoadBatch_StoredProcedure_Execution_Plan.sqlplan

Where is the xml dump. It looks like for the SP SQL Server did not use the clustered index, but trying to use some other indexes instead. It was unclear which index was used from the screenshot 

I just posted the full sql execution plans for both the adhock and the stored procedure.

I still believe this is the doing of parameter sniffing - Can you execute the SP with the WITH RECOMPILE option? 

EXECUTE sp params WITH RECOMPILE

I ran the stored procedure with WITH RECOMPILE, as you mentioned and it still took 40 seconds.

Here is the full Execution Plan.

https://filebin.net/r54svoy1knnojfr4/Episerver.CatalogContentProperty_LoadBatch_StoredProcedure_Execution_Plan_WITH_RECOMPILE.sqlplan

Mind trying to drop the execution plan for the procedure and try again? 

https://serverfault.com/questions/91285/how-do-i-remove-a-specific-bad-plan-from-the-sql-server-query-cache 

I just dropped all execution plans related to this query. After making this change, I ran the query again and it still took a very long time. Slightly longer than before. Definilty no improvement and the execution plan looks the same to me.

This is an interesting case and I'd like to help. However this remote, async diagnose will take (long) time. As I said it would be better if we can get a hand on your db for proper investigation, via official channel :)

I actually just made some progress with this. It definitly looks like some type of parameter sniffing. I modified the CatalogContentProperty_LoadBatch stored procedure, and change the incoming @PropertyReferences user defined table, to insert into a temp table. Then I changed all references to that variable to be use my temp table, as opposed to the @PropertyReferences udt.

USE [EPiServer.CommerceManager]
GO

/****** Object:  StoredProcedure [dbo].[CatalogContentProperty_LoadBatch]    Script Date: 8/16/2017 9:17:58 AM ******/
SET ANSI_NULLS ON
GO

SET QUOTED_IDENTIFIER ON
GO


ALTER PROCEDURE [dbo].[CatalogContentProperty_LoadBatch]
	@PropertyReferences [udttCatalogContentPropertyReference] READONLY
AS
BEGIN

SELECT *
INTO #TempPropertyReference
FROM @PropertyReferences

	IF dbo.mdpfn_sys_IsAzureCompatible() = 0  --Fields will be encrypted only when DB does not support Azure
		BEGIN
		EXEC mdpsp_sys_OpenSymmetricKey
		
		;WITH CTE1 AS (
			SELECT R.*, E.CatalogId
			FROM #TempPropertyReference R
			INNER JOIN CatalogEntry E ON E.CatalogEntryId = R.ObjectId AND R.ObjectTypeId = 0
		UNION ALL
			SELECT R.*, N.CatalogId
			FROM #TempPropertyReference R
			INNER JOIN CatalogNode N ON N.CatalogNodeId = R.ObjectId AND R.ObjectTypeId = 1
		),
		CTE2 AS (
			SELECT CTE1.ObjectId, CTE1.ObjectTypeId, CTE1.MetaClassId, ISNULL(L.LanguageCode, C.DefaultLanguage) AS LanguageName, C.DefaultLanguage
			FROM CTE1
			INNER JOIN [Catalog] C ON C.CatalogId = CTE1.CatalogId
			LEFT OUTER JOIN CatalogLanguage L ON L.CatalogId = CTE1.CatalogId AND L.LanguageCode = CTE1.LanguageName
		)
		-- Select CatalogContentProperty data
		SELECT P.ObjectId, P.ObjectTypeId, P.MetaFieldId, P.MetaClassId, P.MetaFieldName, P.LanguageName,
							P.Boolean, P.Number, P.FloatNumber, P.[Money], P.[Decimal], P.[Date], P.[Binary], P.[String], 
							CASE WHEN (F.IsEncrypted = 1 AND dbo.mdpfn_sys_IsLongStringMetaField(F.DataTypeId) = 1) 
								THEN dbo.mdpfn_sys_EncryptDecryptString(P.LongString, 0) 
								ELSE P.LongString END 
							AS LongString,
							P.[Guid]  
		FROM dbo.CatalogContentProperty P
		INNER JOIN MetaField F ON P.MetaFieldId = F.MetaFieldId
		INNER JOIN CTE2 ON
			P.ObjectId = CTE2.ObjectId AND
			P.ObjectTypeId = CTE2.ObjectTypeId AND
			P.MetaClassId = CTE2.MetaClassId AND
			((F.MultiLanguageValue = 1 AND P.LanguageName = CTE2.LanguageName COLLATE DATABASE_DEFAULT) OR ((F.MultiLanguageValue = 0 AND P.LanguageName = CTE2.DefaultLanguage COLLATE DATABASE_DEFAULT)))
		EXEC mdpsp_sys_CloseSymmetricKey
		END
	ELSE
		BEGIN
		
		;WITH CTE1 AS (
			SELECT R.*, E.CatalogId
			FROM #TempPropertyReference R
			INNER JOIN CatalogEntry E ON E.CatalogEntryId = R.ObjectId AND R.ObjectTypeId = 0
		UNION ALL
			SELECT R.*, N.CatalogId
			FROM #TempPropertyReference R
			INNER JOIN CatalogNode N ON N.CatalogNodeId = R.ObjectId AND R.ObjectTypeId = 1
		),
		CTE2 AS (
			SELECT CTE1.ObjectId, CTE1.ObjectTypeId, CTE1.MetaClassId, ISNULL(L.LanguageCode, C.DefaultLanguage) AS LanguageName, C.DefaultLanguage
			FROM CTE1
			INNER JOIN [Catalog] C ON C.CatalogId = CTE1.CatalogId
			LEFT OUTER JOIN CatalogLanguage L ON L.CatalogId = CTE1.CatalogId AND L.LanguageCode = CTE1.LanguageName
		)	
		SELECT P.ObjectId, P.ObjectTypeId, P.MetaFieldId, P.MetaClassId, P.MetaFieldName, P.LanguageName,
							P.Boolean, P.Number, P.FloatNumber, P.[Money], P.[Decimal], P.[Date], P.[Binary], P.[String], P.LongString LongString,
							P.[Guid]  
		FROM dbo.CatalogContentProperty P
		INNER JOIN MetaField F ON P.MetaFieldId = F.MetaFieldId
		INNER JOIN CTE2 ON
			P.ObjectId = CTE2.ObjectId AND
			P.ObjectTypeId = CTE2.ObjectTypeId AND
			P.MetaClassId = CTE2.MetaClassId AND
			((F.MultiLanguageValue = 1 AND P.LanguageName = CTE2.LanguageName COLLATE DATABASE_DEFAULT) OR ((F.MultiLanguageValue = 0 AND P.LanguageName = CTE2.DefaultLanguage COLLATE DATABASE_DEFAULT)))
		END
	-- Select CatalogContentEx data
	SELECT *
	FROM dbo.CatalogContentEx Ex 
	INNER JOIN #TempPropertyReference R ON Ex.ObjectId = R.ObjectId AND Ex.ObjectTypeId = R.ObjectTypeId

END


GO

This solution isn't ideal, as I'm modifying an Episerver stored procedure. But at this point I'm seeing no other options.

Yes, it's definitely a parameter sniffing problem. It might also affect other customers - but it's currently not-reproducible on our test environment. The right way to fix it is to contact developer support service and provide the db. We will work on this to find a solution that we all can be happy with.

When you get a moment, check your gmail. We've gone through Episerver Expert services and it wasn't a viable avenue for us.

Hi,

I can see that you contacted Episerver support service, how is it going? 

This issue is resolved. I cleared database statistics and this resolved the issue.

-Paul

But worth noting, is I replicated this three times. I pulled down our production server to our dev and re-ran the database upgrade, and had this problem all three times.

Yes, updating statistics is a way to resolve it - but perhaps you might want to try to turn on auto statistics update?

Now I have more time to look at your execution plans you attached, and it's now quite clear (I learned a lot since last time) SQL Server choosed the very bad plan. Instead of using CTE2 which would filter the rows a lot, it uses the MetaFieldId join which is very heavy (Index seek and look up 1.5M rows). This can be explained that the statistics were heavily out of date and the execution plan was based on the assumption that MetaFieldId is very selective (which it is not)

Auto update statistics were on. :/