xConnect 100% CPU for hours

Question

Sitecore 9.1

In the middle of some testing on my QA server, the xConnect IIS site went to 100% CPU and started chewing up RAM. Now for 14 hours, the CPU has not come down and the xConnect site has crashed several times for out or memory exceptions. When I IISRESET or reboot, this issue comes right back.

When I look in the Processing Tasks database, everything is empty. And the site is still generating data in Experience Analytics. But all calls to xConnect time out. I do get the normal xConnect time stamp from the site, so it is still running. It is just using 100% doing I don't know what.

I have turned on verbose logging for xConnect, but that provided no details. No errors in Sitecore log other than xDb Unavailable errors.

I have opened a Sitecore ticket, just hoping someone solved this issue before.

Answer 1

TLDR;

When you site throws an error, for some reason Sitecore stuffs the error into xConnect as an interaction. Sometimes these errors are so large, it takes so much CPU to deserialize them, that it brings your xConnect server to a halt. You have to find these interactions and delete them manually.

xConnect logs errors

There is a setting in Sitecore.Analytics.Tracking.config that tells xConnect what level of logging to put into xConnect. Me personally I fancy log files :) But by default the setting is error.

<setting name="Analytics.LogLevel" value="Error" patch:source="Sitecore.Analytics.Tracking.config" />

The error that gets stuff into xConnect looks like this. Its the whole error

{
   "CustomValues":[

   ],
   "Data":"System.Web.HttpUnhandledException (0x80004005): An unhandled exception occurred. ---> System.NullReferenceException: Object reference not set to an instance of an object.\r\n   at Bonfire.Analytics.Dto.Repositories.CampaignRepository.GetCampaignDefinition(Guid campaignId) in C:\\Users\\pirel\\Source\\Repos\\Bonfire.Analytics.Dto\\Bonfire.Analytics.Dto\\Repositories\\CampaignRepository.cs:line 67\r\n   at Bonfire.Analytics.Dto.Repositories.CampaignRepository.<GetHistoric>d__3.MoveNext() in C:\\Users\\pirel\\Source\\Repos\\Bonfire.Analytics.Dto\\Bonfire.Analytics.Dto\\Repositories\\CampaignRepository.cs:line 43\r\n   at Newtonsoft.Json.Serialization.JsonSerializerInternalWriter.SerializeList(JsonWriter writer, IEnumerable values, JsonArrayContract contract, JsonProperty member, JsonContainerContract collectionContract, JsonProperty containerProperty)\r\n   at Newtonsoft.Json.Serialization.JsonSerializerInternalWriter.SerializeObject(JsonWriter writer, Object value, JsonObjectContract contract, JsonProperty member, JsonContainerContract collectionContract, JsonProperty containerProperty)\r\n   at Newtonsoft.Json.Serialization.JsonSerializerInternalWriter.Serialize(JsonWriter jsonWriter, Object value, Type objectType)\r\n   at Newtonsoft.Json.JsonSerializer.SerializeInternal(JsonWriter jsonWriter, Object value, Type objectType)\r\n   at Bonfire.Analytics.Dto.Serialization.JsonNet.ExecuteResult(ControllerContext context) in C:\\Users\\pirel\\Source\\Repos\\Bonfire.Analytics.Dto\\Bonfire.Analytics.Dto\\Serialization\\JsonNet.cs:line 58\r\n   at System.Web.Mvc.ControllerActionInvoker.InvokeActionResultFilterRecursive(IList`1 filters, Int32 filterIndex, ResultExecutingContext preContext, ControllerContext controllerContext, ActionResult actionResult)\r\n   at System.Web.Mvc.ControllerActionInvoker.InvokeActionResultFilterRecursive(IList`1 filters, Int32 filterIndex, ResultExecutingContext preContext, ControllerContext controllerContext, ActionResult actionResult)\r\n   at System.Web.Mvc.ControllerActionInvoker.InvokeActionResultFilterRecursive(IList`1 filters, Int32 filterIndex, ResultExecutingContext preContext, ControllerContext controllerContext, ActionResult actionResult)\r\n   at System.Web.Mvc.ControllerActionInvoker.InvokeActionResultWithFilters(ControllerContext controllerContext, IList`1 filters, ActionResult actionResult)\r\n   at System.Web.Mvc.Async.AsyncControllerActionInvoker.<>c__DisplayClass3_1.<BeginInvokeAction>b__5(IAsyncResult asyncResult)\r\n   at Sitecore.Mvc.Pipelines.MvcEvents.Exception.ShowAspNetErrorMessage.ShowErrorMessage(ExceptionContext exceptionContext, ExceptionArgs args)\r\n   at Sitecore.Mvc.Pipelines.MvcEvents.Exception.ShowAspNetErrorMessage.Process(ExceptionArgs args)\r\n   at (Object , Object )\r\n   at Sitecore.Pipelines.CorePipeline.Run(PipelineArgs args)\r\n   at Sitecore.Pipelines.DefaultCorePipelineManager.Run(String pipelineName, PipelineArgs args, String pipelineDomain, Boolean failIfNotExists)\r\n   at Sitecore.Pipelines.DefaultCorePipelineManager.Run(String pipelineName, PipelineArgs args, String pipelineDomain)\r\n   at Sitecore.Mvc.Pipelines.PipelineService.RunPipeline[TArgs](String pipelineName, TArgs args)\r\n   at Sitecore.Mvc.Filters.PipelineBasedRequestFilter.OnException(ExceptionContext exceptionContext)\r\n   at System.Web.Mvc.ControllerActionInvoker.InvokeExceptionFilters(ControllerContext controllerContext, IList`1 filters, Exception exception)\r\n   at System.Web.Mvc.Async.AsyncControllerActionInvoker.<>c__DisplayClass3_1.<BeginInvokeAction>b__5(IAsyncResult asyncResult)\r\n   at System.Web.Mvc.Async.AsyncControllerActionInvoker.EndInvokeAction(IAsyncResult asyncResult)\r\n   at System.Web.Mvc.Controller.<>c.<BeginExecuteCore>b__152_1(IAsyncResult asyncResult, ExecuteCoreState innerState)\r\n   at System.Web.Mvc.Async.AsyncResultWrapper.WrappedAsyncVoid`1.CallEndDelegate(IAsyncResult asyncResult)\r\n   at System.Web.Mvc.Controller.EndExecuteCore(IAsyncResult asyncResult)\r\n   at System.Web.Mvc.Async.AsyncResultWrapper.WrappedAsyncVoid`1.CallEndDelegate(IAsyncResult asyncResult)\r\n   at System.Web.Mvc.Controller.EndExecute(IAsyncResult asyncResult)\r\n   at System.Web.Mvc.MvcHandler.<>c.<BeginProcessRequest>b__20_1(IAsyncResult asyncResult, ProcessRequestState innerState)\r\n   at System.Web.Mvc.Async.AsyncResultWrapper.WrappedAsyncVoid`1.CallEndDelegate(IAsyncResult asyncResult)\r\n   at System.Web.Mvc.MvcHandler.EndProcessRequest(IAsyncResult asyncResult)\r\n   at Sitecore.Mvc.Routing.RouteHttpHandler.EndProcessRequest(IAsyncResult result)\r\n   at System.Web.HttpApplication.CallHandlerExecutionStep.System.Web.HttpApplication.IExecutionStep.Execute()\r\n   at System.Web.HttpApplication.ExecuteStepImpl(IExecutionStep step)\r\n   at System.Web.HttpApplication.ExecuteStep(IExecutionStep step, Boolean& completedSynchronously)",
   "DataKey":"System.Web.HttpUnhandledException (0x80004005): An unhandled exception occurred. ---> System.NullReferenceException: Object reference not set to an instance of an object.",
   "DefinitionId":"c8bf254a-9ccc-4e16-9009-82b7cd33e4be",
   "Id":"4807eb74-8288-49f4-b10b-a1b0aeac64db",
   "ParentEventId":"0b8d3c23-e77a-4396-a7bd-fd1437669133",
   "Text":"System.Web.HttpUnhandledException (0x80004005): An unhandled exception occurred. ---> System.NullReferenceException: Object reference not set to an instance of an object.",
   "Timestamp":"2019-07-23T15:34:53.0778746Z"
},

My issue

In my environment, in testing we released a build that had a bug. Ever done it? We did it.... And the testers all ran into this error. And it was a big error, a React server side build error. 20k of error text. This all got stuff into xConnect over and over. After a few minutes of that, it was all xConnect could handle. Every time it tried to get the users interactions, it would use 100% cpu trying to deserialize 300k of JSON.

Find the interactions

The easiest way to find the offending interactions it to look for the size of the interaction in the events column.

SELECT TOP (100) [InteractionId]
      ,[Events]
      ,DATALENGTH(Events) 
  FROM [xdb_collection].[Interactions]
Order by DATALENGTH(Events) Desc

It will return a list of interactions sorted by size. What you are really looking for are interactions under 10k. Ones that are 100k or 90k, those are full of errors.

You can take the InteractionId and delete the interaction and interactions facets. The facets are a foreign keys to the interactions. So they must go also.

NOTE: This is destructive. You are losing data at this point. You are not getting it back.

DELETE FROM
    [xdb_collection].[InteractionFacets]
WHERE InteractionId IN 
    (SELECT InteractionId
        FROM [xdb_collection].[Interactions]  
        WHERE InteractionId = 'B6345767-4293-0000-0000-05A41DC536C4');

DELETE FROM [xdb_collection].[Interactions]  
        WHERE InteractionId = 'B6345767-4293-0000-0000-05A41DC536C4';

Now rebuild your xDB Solr index with ConnectSearchIndexer.exe -rr and the issue should be resolved.

Stop errors from making it into xConnect

Change the Analytics.LogLevel to none so we stop pushing errors into xConnect.

<setting name="Analytics.LogLevel" value="None" patch:source="Sitecore.Analytics.Tracking.config" />

Answer 2

For anyone running their xDB on a MongoDB instead of an SQL server on Sitecore 9.1, I created a C# class to cleanup

1. Interactions for bloated events holding very long exceptions
2. ContactFacets holding very long exceptions in PageEvents

Our issue

Similar as the OP, some of our database tables had run full of exceptions. This caused our xConnect IndexWriter to stop processing data from xDB into the xdb Solr index. When trying to run a xdb index rebuild, the rebuild would always stop at somewhere between 60%-80%.

A clear indicator this is happening on your environment is finding the following exception in your Solr logs: "Document contains at least one immense term in field='data_s'"

For us, not only had we been unable to rebuild xdb index, we also had massive delays for updates on EXM lists and processing for A/B testing results would not work properly.

Checking for very long exceptions in events and contact facets

You can check for unusually long strings in your events with the following MongoDB query (using e.g. Robo3T):

db.getCollection('Interactions').aggregate([
{ $unwind :'$events'},
{ $match : {'events.Data': { "$exists": true }} },
    {
        "$redact": {
            "$cond": [
                { "$gt": [ { "$strLenBytes": "$events.Data" }, 30000] },
                "$$KEEP",
                "$$PRUNE"
            ]
        }
    },
{ $project : { _id:0, Id :'$events.Id', DefinitionId: '$events.DefinitionId', ItemId: '$events.ItemId', "Data" : '$events.Data', "DataKey" : '$events.DataKey', "Length in Bytes" : { "$strLenBytes": "$events.Data" } } },
{$sort: {"Length" : 1}},
])

Same goes for contact facets, the query looks like this:

db.getCollection('ContactFacets').aggregate([
{ $unwind :'$content.PageEvents'},
{ $match : {'content.PageEvents.Data': { "$exists": true }} },
   {
        "$redact": {
            "$cond": [
                { "$gt": [ { "$strLenBytes": "$content.PageEvents.Data" }, 20000] },
                "$$KEEP",
                "$$PRUNE"
            ]
        }
    },
{$sort: {"Length" : 1}},
])

Anything between 10.000 and 30.000 bytes should be a likely candidate. The Solr field where this data is written to only allows up to 32.000 bytes.

With the query in place you should get results similar to this:

The C# class provided here checks for events and facet data where string length in bytes is more than 30.000 bytes and then deletes this data from the database.

Answer 3

Check your SQL Server logs for Xdb.Collection, if you can track down what transaction is hanging - that will give you a clue what's going on.

We had similar experience with Sitecore 8.2 and MongoDB. Because with Sitecore 8.2 the process runs in Sitecore app pool, the whole Sitecore was unresponsive.

The problem was with number of visits in the Interactions table for one individual user (More than a million visits). When that user was logging in, it was causing MongoDB to load all data related to the user into MongoDB server memory and as result it hanged (sorry, not enough reputation to comment on your question).

Answer 4

We recently found out that the ContactFacets table is similarly affected by this.

For us, there were about 800 rows of contact facet data stuffed with exceptions, preventing us from rebuilding our xdb index.

I tweaked the OP's SQL script a little and added the query to also delete affected entries from ContactFacets table:

DELETE FROM
    [Xdb.Collection.Shard1].[xdb_collection].[InteractionFacets]
WHERE InteractionId IN 
    (SELECT InteractionId
        FROM [Xdb.Collection.Shard1].[xdb_collection].[Interactions]  
        WHERE (DATALENGTH(Events) > 200000))

DELETE FROM [Xdb.Collection.Shard1].[xdb_collection].[Interactions]  
        WHERE (DATALENGTH(Events) > 200000)

DELETE FROM [Xdb.Collection.Shard1].[xdb_collection].[ContactFacets]
        WHERE (DATALENGTH(FacetData) > 200000)

Apply this script to every collection shard.

DISCLAIMER: This will delete data from your xDB, so make sure to have a backup plan if something goes wrong