Loading edit mode very slowly every once in a while

Erik Strandler

Vote:

Hi!

Sometimes when trying to enter edit mode, it takes several minutes to load it even though no restart of the application has happened or anything. From what I have been able to find out so far, the longest time is spent in the database. Where some GET requests to Home/Index that is /episerver/cms takes as long as 2,5 minutes (where nearly 100% of it is spent in the database). Where it makes 1600 sql queries.

SELECT Id, ItemType FROM [dbo].[VW_EPiServer.Shell.Profile.ProfileData] WHERE [UserName] = @UserName

SELECT Id, ItemType,[UserName] FROM [dbo].[VW_EPiServer.Shell.Profile.ProfileData] WHERE [StoreId] = @StoreId

SELECT tblBigTableReference.ElementType, tblBigTableReference.ElementStoreName, tblBigTableReference.PropertyName, tblBigTableReference.RefIdValue, tblBigTableIdentity.Guid, tblBigTableReference.LongValue, tblBigTableReference.Type, tblBigTableReference.StringValue, tblBigTableReference.ExternalIdValue, tblBigTableReference.DecimalValue FROM [dbo].[tblBigTableReference] LEFT OUTER JOIN [dbo].[tblBigTableIdentity] ON tblBigTableReference.RefIdValue = tblBigTableIdentity.pkId WHERE tblBigTableReference.pkId= @Id AND (tblBigTableReference.Type = @Reference OR tblBigTableReference.Type = @Provider)

SELECT c.name AS column_name,t.name AS type_name,c.max_length,c.precision,c.scale, CAST(CASE WHEN EXISTS(SELECT * FROM sys.index_columns AS i WHERE i.object_id=c.object_id AND i.column_id=c.column_id) THEN 1 ELSE 0 END AS BIT) AS column_indexed FROM sys.columns AS c JOIN sys.types AS t ON c.user_type_id=t.user_type_id WHERE c.object_id = OBJECT_ID('tblBigTableReference') ORDER BY c.column_id;

SELECT CollectionType, ElementType, ElementStoreName, IsKey, [Index] Indexvalue, [BooleanValue], [IntegerValue], [LongValue], [DateTimeValue], [GuidValue], [FloatValue], [StringValue], [BinaryValue], [RefIdValue], [ExternalIdValue], [DecimalValue], tblBigTableIdentity.Guid FROM [dbo].[tblBigTableReference] LEFT OUTER JOIN [dbo].[tblBigTableIdentity] ON tblBigTableReference.RefIdValue = tblBigTableIdentity.pkId WHERE tblBigTableReference.pkId = @pkId AND PropertyName=@PropertyName ORDER BY [Index] ASC, IsKey DESC

SELECT TOP(1) "EPiServer.Shell.Storage.PersonalizedViewSettingsStorage".Id, "EPiServer.Shell.Storage.PersonalizedViewSettingsStorage".ItemType, "EPiServer.Shell.Storage.PersonalizedViewSettingsStorage"."UserName", "EPiServer.Shell.Storage.PersonalizedViewSettingsStorage"."ViewName" FROM [dbo].[VW_EPiServer.Shell.Storage.PersonalizedViewSettingsStorage] as "EPiServer.Shell.Storage.PersonalizedViewSettingsStorage" WHERE ("EPiServer.Shell.Storage.PersonalizedViewSettingsStorage".[UserName] = @Param0 AND "EPiServer.Shell.Storage.PersonalizedViewSettingsStorage".[ViewName] = @Param1)

netNotificationSubscriptionListByKey

SELECT [Limit1].[UserId] AS [UserId], [Limit1].[PropertyNames] AS [PropertyNames], [Limit1].[PropertyValueStrings] AS [PropertyValueStrings], [Limit1].[PropertyValueBinary] AS [PropertyValueBinary], [Limit1].[LastUpdatedDate] AS [LastUpdatedDate] FROM ( SELECT TOP (1) [Extent1].[UserId] AS [UserId], [Extent1].[PropertyNames] AS [PropertyNames], [Extent1].[PropertyValueStrings] AS [PropertyValueStrings], [Extent1].[PropertyValueBinary] AS [PropertyValueBinary], [Extent1].[LastUpdatedDate] AS [LastUpdatedDate] FROM [dbo].[Profiles] AS [Extent1] INNER JOIN [dbo].[Users] AS [Extent2] ON [Extent1].[UserId] = [Extent2].[UserId] INNER JOIN [dbo].[Applications] AS [Extent3] ON [Extent2].[ApplicationId] = [Extent3].[ApplicationId] WHERE (((LOWER([Extent3].[ApplicationName])) = (LOWER(@p__linq__0))) OR ((LOWER([Extent3].[ApplicationName]) IS NULL) AND (LOWER(@p__linq__0) IS NULL))) AND (((LOWER([Extent2].[UserName])) = (LOWER(@p__linq__1))) OR ((LOWER([Extent2].[UserName]) IS NULL) AND (LOWER(@p__linq__1) IS NULL))) ) AS [Limit1]

netSynchedUserList

Where it keeps re-iterating between the last two for the remaining 1580 queries, i'm assuming by iterating through all users or something. Does anyone recognize this problem? It is currently not a very good way for the editors to work if the site takes 2+ minutes to load sometimes.

Br,

Erik

#199732

Dec 07, 2018 17:34

Magnus Eriksson

Vote:

Hi Erik,

Did you resolve this problem? And in that case what did you do? (we seem to have the same problem now)

regards

Magnus

#204209

May 22, 2019 15:17

Vote:

Think I'm looking at this now as well. Will report back!

#207761

Edited, Oct 02, 2019 11:13

Tomas Hensrud Gulla

Vote:

What version of Episerver are you running?

#207766

Oct 02, 2019 12:55

Vote:

<package id="EPiServer.Azure" version="9.4.4" targetFramework="net471" />
<package id="EPiServer.CMS.AspNet" version="11.11.3" targetFramework="net471" />
<package id="EPiServer.CMS.Core" version="11.11.3" targetFramework="net471" />
<package id="EPiServer.CMS.TinyMce" version="2.8.0" targetFramework="net471" />
<package id="EPiServer.CMS.UI" version="11.19.2" targetFramework="net472" />
<package id="EPiServer.CMS.UI.Core" version="11.19.2" targetFramework="net472" />
<package id="EPiServer.Find" version="13.0.5" targetFramework="net471" />
<package id="EPiServer.Find.Cms" version="13.0.5" targetFramework="net471" />
<package id="EPiServer.Find.Framework" version="13.0.5" targetFramework="net471" />
<package id="EPiServer.Framework" version="11.11.3" targetFramework="net471" />
<package id="EPiServer.Framework.AspNet" version="11.11.3" targetFramework="net471" />
<package id="EPiServer.ServiceLocation.StructureMap" version="2.0.1" targetFramework="net471" />

#207767

Oct 02, 2019 13:02

Vote:

I just did a quick test modyfying and adding a WHERE 0 = 1 to the netNotificationSubscriptionListByKey procedure so that it returns 0 rows.

That reduces the netSynchedUserList calls to only 1 (from 119) when loading Edit Mode.

Have an open dev support ticket running as well...

#207800

Edited, Oct 03, 2019 15:26

Vote:

There is now a Bug ticket created. The call is being made indirectly on Edit Mode load (where its not needed).

Will add more info when it arrives.

#207822

Oct 04, 2019 13:31

One Techlåda

Vote:

We are also starting to have some issues for some users not everyone yet

<package id="EPiServer.CMS" version="11.12.0" targetFramework="net462" />
<package id="EPiServer.CMS.AspNet" version="11.12.0" targetFramework="net462" />
<package id="EPiServer.CMS.Core" version="11.12.0" targetFramework="net462" />
<package id="EPiServer.CMS.TinyMce" version="2.8.0" targetFramework="net462" />
<package id="EPiServer.CMS.UI" version="11.20.1" targetFramework="net462" />
<package id="EPiServer.CMS.UI.Core" version="11.20.1" targetFramework="net462" />
<package id="EPiServer.Forms" version="4.24.2" targetFramework="net462" />
<package id="EPiServer.Forms.Core" version="4.24.2" targetFramework="net462" />
<package id="EPiServer.Forms.UI" version="4.24.2" targetFramework="net462" />
<package id="EPiServer.Framework" version="11.12.0" targetFramework="net462" />
<package id="EPiServer.Framework.AspNet" version="11.12.0" targetFramework="net462" />
<package id="EPiServer.Labs.LanguageManager" version="3.3.1" targetFramework="net462" />
<package id="EPiServer.Logging.Log4Net" version="2.2.2" targetFramework="net462" />
<package id="EPiServer.Marketing.KPI" version="2.5.2" targetFramework="net462" />
<package id="EPiServer.Marketing.Messaging" version="1.3.0" targetFramework="net462" />
<package id="EPiServer.Marketing.Testing" version="2.5.9" targetFramework="net462" />
<package id="EPiServer.Packaging" version="3.4.0" targetFramework="net462" />
<package id="EPiServer.Packaging.UI" version="3.4.0" targetFramework="net462" />
<package id="EPiServer.Search" version="9.0.3" targetFramework="net462" />
<package id="EPiServer.Search.Cms" version="9.0.3" targetFramework="net462" />
<package id="EPiServer.ServiceLocation.StructureMap" version="2.0.1" targetFramework="net462" />

#207859

Oct 07, 2019 14:18

Vote:

If my client was hosting with access to the db server I would do something similar to the WHERE 0 = 1 to the netNotificationSubscriptionListByKey SP hack right away. A bit more complicated to do a temporary quick fix with DXC-S...

#207860

Oct 07, 2019 14:28

Alan Keegan - Oct 09, 2019 1:33

Hi Johan, would you mind posting the full netNotificationSubscriptionListByKey procedure so I can see where you added the "WHERE 0 = 1" clause? Thanks!

One Techlåda - Oct 09, 2019 8:29

SET ANSI_NULLS ON
GO
SET QUOTED_IDENTIFIER ON
GO
ALTER PROCEDURE [dbo].[netNotificationSubscriptionListByKey]
@SubscriptionKey [nvarchar](255),
@SubscriptionKeyMatchMode INT = 0 -- Exact = 0, Before = 1, After = 2
AS
BEGIN
DECLARE @key [nvarchar](256) = @SubscriptionKey + CASE SUBSTRING(@SubscriptionKey, LEN(@SubscriptionKey), 1) WHEN N'/' THEN N'' ELSE N'/' END
IF @SubscriptionKeyMatchMode = 1
SELECT [pkID], [UserName], [SubscriptionKey] FROM [dbo].[tblNotificationSubscription] WHERE Active = 1 AND (SubscriptionKey = @key OR @key LIKE SubscriptionKey + '%')
ELSE IF @SubscriptionKeyMatchMode = 2
SELECT [pkID], [UserName], [SubscriptionKey] FROM [dbo].[tblNotificationSubscription] WHERE Active = 1 AND (SubscriptionKey = @key OR SubscriptionKey LIKE @key + '%')
ELSE
SELECT [pkID], [UserName], [SubscriptionKey] FROM [dbo].[tblNotificationSubscription] WHERE Active = 1 AND SubscriptionKey = @key
END

So I would say just adding AND 1 = 0 On every select statement

- Oct 09, 2019 10:31

When profiling I only say @SubscriptionKeyMatchMode=1 so you only need to add it for the SELECT in that IF. Notice that this was just a narrowing down profiling activity on my end, I haven't altered the SP in production.

One Techlåda - Oct 09, 2019 12:50

Yes, you are correct. We did the change this morning in our prod enviroment and for the editors who had a loading time of a few minutes its now only a few seconds. We did it only on on Mode 1

One Techlåda

Vote:

We are hosting our own db so it can be done.

What are the tblNotificationSubscription used for? Is there a job that uses it somehow?

#207865

Oct 07, 2019 15:25

One Techlåda

Vote:

Do you have the Bug number?
We have around 500 editors on our site and for the ones that are last in the list it takes over 2 minutes to just enter epi edit mode.
We will do your fix tomorrow morning.

#207910

Oct 08, 2019 14:29

Vote:

I think it's used by Projects, Edit Mode comments, Content Approvals and maybe something else. I guess also the product news feed.

It's not on the public bug list yet but when I find out it is I will post the link here.

Are you also running a auth setup that puts stuff in the tblSynched*-tables? I also noted that Epi should look into better indexing or possibly cache those calls as well as fixing the unnecessary indirect call.

#207912

Oct 08, 2019 14:41

One Techlåda

Vote:

ok.

What we have found out is this:

It runs: exec netNotificationSubscriptionListByKey @SubscriptionKey=N'feature://notification/',@SubscriptionKeyMatchMode=1

And gets a list of users, then it calls "synchedUser" for every user in the list until it finds the user who is trying to login, so if you are in the bottom of the list it makes a lot of calls, and it iterates the list with calls to "synchedUser" twice.

#207916

Oct 08, 2019 14:53

Vote:

We haven't verified that this solves our issue yet, but looks like it should be fixed now in EPiServer.CMS.UI 11.22.1.

Bug - CMS-14762

#208782

Edited, Nov 01, 2019 10:29

Vote:

Looks like they only addressed the unnecessary call when Edit Mode loads and not the overall slowness and shooting database queries individually from inside a loop.

I still see slow transactions with the same pattern in Application Insights.

#210762

Dec 04, 2019 22:58

Vote:

I can confirm that upgrading the EPiServer.CMS.UI solved our issues with accessing edit mode at least, now taking <1s instead of ~1 min :)

#210953

Dec 13, 2019 9:47