Try our conversational search powered by Generative AI!

Remote events throughput going through the roof!

Vote:
 

Hi all!

We're currently battling a big questionmark, remote events in the network seems to have increased with over 1200% starting very early this morning.

 

Now, we have no idea why this has happened, and it's a bit troublesome to us that we don't know why. It's not crashing the system, but making the CPUs work harder than they need to. 

I found some EPiServerRemoteEventsListener.exe program from an old blog posts that sniffs remote events, but that only told me that there were a lot of events to sniff, and didn't contain any other information, really.

It has to do with something Commerce, our incremental index change tracker has an absurd amount of changes on 5 categories, but no more information there, either.

Does anyone have any tips debugging Remote Events? :) 

Update 1:
I tried adding logging by adding 

		
		
	x

to the EPiServerLog.config, without any results (nothing extra was logged).
I've also found a list of 100 suspect variants (and 40 products) that were added at the same time as the remote events started, and contains in one of the 5 categories as primary. But I'm not sure what to look for in that list...

Update 2: The plot thickens
So I've find something very curious while looking at the NodeEntryRelations from one of these categories, everytime I query for all the relations, the number of relations differ by +-1. So I do 

select top 1000 CatalogEntryId from NodeEntryRelation where CatalogNodeId = 4985

And for this category (4985), I get either 470 or 469 results from it. The differing 1 relation is a different entry when I checked 6 times. Mystery!

#186871
Edited, Jan 08, 2018 10:20
Vote:
 

We need your version, Joel :) 

#186875
Jan 08, 2018 11:30
Vote:
 

Oh, the shame.

CMS 10.10.6.0
Commerce 11.3.0.0

#186876
Jan 08, 2018 11:33
Vote:
 

Is it possible that there is a code constantly updating the table? I suspect that this is your production site, but can you reproduce the problem on a test site? We can do some experiments there.

#186877
Jan 08, 2018 11:36
Vote:
 

I shoot from the hip cool We can probably do experiments on production, depending a bit on what they are.

One of the 6 products I grabbed from the 1 relation diff is contained in all the 4 biggest categories spamming events. We don't have custom SQL that targets that table (as far as I know..).

#186878
Jan 08, 2018 11:39
Vote:
 

Did a quick SQL profile, tried to follow the journey of 1 catalogEntryId:

exec sp_executesql N'DELETE FROM [NodeEntryRelation] WHERE (([CatalogId] IS NULL AND @oldCatalogId IS NULL) OR [CatalogId]=@oldCatalogId) AND (([CatalogNodeId] IS NULL AND @oldCatalogNodeId IS NULL) OR [CatalogNodeId]=@oldCatalogNodeId) AND (([CatalogEntryId] IS NULL AND @oldCatalogEntryId IS NULL) OR [CatalogEntryId]=@oldCatalogEntryId)',N'@CatalogId int,@oldCatalogId int,@CatalogNodeId int,@oldCatalogNodeId int,@CatalogEntryId int,@oldCatalogEntryId int',@CatalogId=5,@oldCatalogId=5,@CatalogNodeId=4387,@oldCatalogNodeId=4387,@CatalogEntryId=303331,@oldCatalogEntryId=303331


declare @p1 dbo.udttContentList
insert into @p1 values(303331)

exec ecf_NodeEntryRelations @ContentList=@p1


declare @p1 dbo.udttContentList
insert into @p1 values(303331)

exec ecf_NodeEntryRelations @ContentList=@p1


exec ecf_CatalogRelation @CatalogId=0,@CatalogNodeId=0,@CatalogEntryId=303331,@GroupName=N'',@ResponseGroup=4


declare @p1 dbo.udttContentList
insert into @p1 values(303331)

exec ecf_NodeEntryRelations @ContentList=@p1


exec sp_executesql N'INSERT INTO [NodeEntryRelation] ([CatalogId],[CatalogEntryId],[CatalogNodeId],[SortOrder],[IsPrimary]) VALUES (@CatalogId,@CatalogEntryId,@CatalogNodeId,@SortOrder,@IsPrimary); ',N'@CatalogId int,@CatalogEntryId int,@CatalogNodeId int,@SortOrder int,@IsPrimary bit',@CatalogId=5,@CatalogEntryId=303331,@CatalogNodeId=4387,@SortOrder=2548100,@IsPrimary=1


declare @p1 dbo.udttContentList
insert into @p1 values(303331)

exec ecf_NodeEntryRelations @ContentList=@p1


declare @p1 dbo.udttContentList
insert into @p1 values(303331)

exec ecf_NodeEntryRelations @ContentList=@p1


exec sp_executesql N'INSERT INTO [NodeEntryRelation] ([CatalogId],[CatalogEntryId],[CatalogNodeId],[SortOrder],[IsPrimary]) VALUES (@CatalogId,@CatalogEntryId,@CatalogNodeId,@SortOrder,@IsPrimary); ',N'@CatalogId int,@CatalogEntryId int,@CatalogNodeId int,@SortOrder int,@IsPrimary bit',@CatalogId=5,@CatalogEntryId=303331,@CatalogNodeId=2602,@SortOrder=1,@IsPrimary=0


exec sp_executesql N'INSERT INTO [NodeEntryRelation] ([CatalogId],[CatalogEntryId],[CatalogNodeId],[SortOrder],[IsPrimary]) VALUES (@CatalogId,@CatalogEntryId,@CatalogNodeId,@SortOrder,@IsPrimary); ',N'@CatalogId int,@CatalogEntryId int,@CatalogNodeId int,@SortOrder int,@IsPrimary bit',@CatalogId=5,@CatalogEntryId=303331,@CatalogNodeId=4985,@SortOrder=2,@IsPrimary=0
#186880
Jan 08, 2018 11:48
Vote:
 

OK I'll be assuming that you are using a test environment. How would you use it is up to you, I'm not taking any responsibility if you broke your production site. 

ALTER trigger [dbo].[NodeEntryRelation_UpsertTrigger]
on [dbo].[NodeEntryRelation]
after update, insert
as
begin
set nocount on
IF(EXISTS(SELECT 1 FROM inserted WHERE [CatalogNodeId] = 4985))
BEGIN
RAISERROR('It is not allowed', 10,1)
ROLLBACK TRANSACTION
END

update [dbo].[NodeEntryRelation]
set [Modified] = GETUTCDATE()
from [dbo].[NodeEntryRelation] ner
join inserted
on ner.[CatalogId] = inserted.[CatalogId]
and ner.[CatalogEntryId] = inserted.[CatalogEntryId]
and ner.[CatalogNodeId] = inserted.[CatalogNodeId]
end

This will not break the site, but it will stop any modification to that specific node relation. You can check in your log file to see which code is doing that nasty update.

Again. DO NOT use this in your production site. (I know you will, but that's my obligation to say)

#186881
Jan 08, 2018 11:55
Vote:
 

I assume you'd expect an error in the normal application log, so we get the stacktrace for where the error popped up?

I enabled it for ~10 seconds, but got nothing in either of the 4 machines running the application :/

There is of course a risk that in those 10 seconds there weren't any updates to that table, but seems not likely...

#186883
Jan 08, 2018 12:08
Vote:
 

Did it change during that time

"So I've find something very curious while looking at the NodeEntryRelations from one of these categories, everytime I query for all the relations, the number of relations differ by +-1. So I do "

?

#186884
Jan 08, 2018 12:09
Vote:
 

Yep. Executed the alter for the modified trigger -> spammed the select query -> it decreased by 1, but didn't increase (because the trigger cancels the insert?) until I enabled the original trigger again.

#186885
Jan 08, 2018 12:16
Vote:
 

So that should be logged. Mine looks like this

2018-01-08 11:53:34,722 [16] ERROR EPiServer.Cms.Shell.UI.Rest.Internal.ContentStore: Failed to move the content "Puma Black Suede Athletic Sneakers" beneath the content "Mens Sweatshirts".
System.Data.SqlClient.SqlException (0x80131904): The transaction ended in the trigger. The batch has been aborted.
at System.Data.Common.DbDataAdapter.UpdatedRowStatusErrors(RowUpdatedEventArgs rowUpdatedEvent, BatchCommandInfo[] batchCommands, Int32 commandCount)
at System.Data.Common.DbDataAdapter.UpdatedRowStatus(RowUpdatedEventArgs rowUpdatedEvent, BatchCommandInfo[] batchCommands, Int32 commandCount)
at System.Data.Common.DbDataAdapter.Update(DataRow[] dataRows, DataTableMapping tableMapping)
at System.Data.Common.DbDataAdapter.Update(DataRow[] dataRows)
at Mediachase.Data.Provider.SqlDataProvider.<>c__DisplayClass14_1.<SaveRows>b__0() in C:\source\commerce\ECF\Mediachase.SqlDataProvider\SqlDataProvider.cs:line 237
at EPiServer.Data.Providers.SqlTransientErrorsRetryPolicy.Execute[TResult](Func`1 method)
at Mediachase.Data.Provider.SqlDataProvider.WithRetry[TResult](Func`1 action) in C:\source\commerce\ECF\Mediachase.SqlDataProvider\SqlDataProvider.cs:line 124
at Mediachase.Data.Provider.SqlDataProvider.SaveRows(DataCommand command) in C:\source\commerce\ECF\Mediachase.SqlDataProvider\SqlDataProvider.cs:line 234
at Mediachase.Data.Provider.SqlDataProvider.Save(DataCommand command) in C:\source\commerce\ECF\Mediachase.SqlDataProvider\SqlDataProvider.cs:line 113
at Mediachase.Data.Provider.DataService.Save(DataCommand command) in C:\source\commerce\ECF\Mediachase.DataProvider\DataService.cs:line 136
at Mediachase.Commerce.Storage.DataHelper.SaveTableSimpleWorker(DataCommand cmd, DataTable table, DataViewRowState state) in C:\source\commerce\ECF\Mediachase.Commerce\Storage\DataHelper.cs:line 230
at Mediachase.Commerce.Storage.DataHelper.SaveDataSetSimple(DataCommand cmd, DataSet set, String[] tables) in C:\source\commerce\ECF\Mediachase.Commerce\Storage\DataHelper.cs:line 56
at Mediachase.Commerce.Catalog.Data.CatalogRelationAdmin.Save() in C:\source\commerce\ECF\Mediachase.Commerce\Catalog\Data\CatalogRelationAdmin.cs:line 195
at Mediachase.Commerce.Catalog.Managers.CatalogRelationManager.SaveCatalogRelation(CatalogRelationDto dataset) in C:\source\commerce\ECF\Mediachase.Commerce\Catalog\Managers\CatalogRelationManager.cs:line 201
at Mediachase.Commerce.Catalog.Impl.CatalogContextImpl.SaveCatalogRelationDto(CatalogRelationDto dto) in C:\source\commerce\ECF\Mediachase.Commerce\Catalog\Impl\CatalogContextImpl.cs:line 1105
at EPiServer.Commerce.Catalog.Provider.Internal.CatalogContentMoveHandler.SetParentNodeForEntry(ContentReference contentLink, ContentReference newParentLink) in C:\source\commerce\EPiServer.Business.Commerce\Catalog\Provider\Internal\CatalogContentMoveHandler.cs:line 148
at EPiServer.Commerce.Catalog.Provider.Internal.CatalogContentMoveHandler.MoveWithTransaction(Action`2 moveMethod, ContentReference contentLink, ContentReference newParentLink) in C:\source\commerce\EPiServer.Business.Commerce\Catalog\Provider\Internal\CatalogContentMoveHandler.cs:line 193
at EPiServer.Commerce.Catalog.Provider.Internal.CatalogContentMoveHandler.Move(ContentReference contentLink, ContentReference newParentLink) in C:\source\commerce\EPiServer.Business.Commerce\Catalog\Provider\Internal\CatalogContentMoveHandler.cs:line 58
at EPiServer.Commerce.Catalog.Provider.CatalogContentProvider.Move(ContentReference contentLink, ContentReference destinationLink) in C:\source\commerce\EPiServer.Business.Commerce\Catalog\Provider\CatalogContentProvider.cs:line 973
at EPiServer.Core.Internal.DefaultContentRepository.Move(ContentReference contentLink, ContentReference destinationLink, AccessLevel requiredSourceAccess, AccessLevel requiredDestinationAccess)
at EPiServer.IContentRepositoryExtension.Move(IContentRepository contentRepository, ContentReference contentLink, ContentReference destination)
at EPiServer.Cms.Shell.Service.Internal.ContentService.Move(IContent content, ContentReference destination)
at EPiServer.Cms.Shell.UI.Rest.ContentChangeManager.Move(IContent source, IContent destination, Boolean createAsLocalAsset)
at EPiServer.Cms.Shell.UI.Rest.Internal.ContentStore.MoveContent(IContent source, IContent destination, Boolean createAsLocalAsset, ActionResponse`1 response)

#186886
Jan 08, 2018 12:18
Vote:
 

Hey again, had lunch and meetings.

I couldn't see anything in the logs for this, I thought first it was log levels and that I was looking in the wrong places, but then we tried replicating your stack trace, i.e. moving something in the Commerce UI, which appeared in the logs. So the code that's calling the weird insert/delete does not let sql exceptions slip, it looks like...

#186904
Jan 08, 2018 14:30
Vote:
 

A shameful empty catch { } ? 

#186905
Jan 08, 2018 14:45
Vote:
 

Probably. Or catch that only modifies the output. I think we're close to a resolution and I think you will be a bit relieved because it seems to be our code :S

#186906
Jan 08, 2018 15:05
Vote:
 

Definately our code. Seems like we missed to change a NodeRelation -> NodeEntryRelation and hence miss the IsPrimary in an article import. And in that import we also suppressed any errors, just showing them in the output for the import..

Thanks for all the help as always! :-D

#186908
Jan 08, 2018 15:28
* You are NOT allowed to include any hyperlinks in the post because your account hasn't associated to your company. User profile should be updated.