November Happy Hour will be moved to Thursday December 5th.
November Happy Hour will be moved to Thursday December 5th.
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.
I shoot from the hip 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..).
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
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)
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...
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 "
?
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.
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)
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...
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
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
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
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
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!