Retryable SetFacetOperation logging

Abstract

Overview of xConnect SetFacetOperation logging during the retry strategy.

The PatchFacetOperation operation performs updates to calculated facets and creates one or more SetFacetOperation operations in the process.

Historically, if the SetFacetOperation failed, another operation was created according to the retry strategy (so the whole operation does not fail but is retried). However, this error still appeared in the logs. For example:

2020-07-23 04:33:21.054 +00:00 [Error] Sitecore.XConnect.Operations.SetFacetOperation`1[Sitecore.XConnect.Facet]: Sitecore.XConnect.Operations.FacetOperationException: Operation #18, Conflict, Contact {cff913e9-636a-0000-0000-05e696b95c27}, KeyBehaviorCache 

2020-07-23 04:33:21.054 +00:00 [Error] Sitecore.XConnect.Operations.SetFacetOperation`1[Sitecore.XConnect.Facet]: Sitecore.XConnect.Operations.FacetOperationException: Operation #19, Conflict, Contact {cff913e9-636a-0000-0000-05e696b95c27}, InteractionsCache 

2020-07-23 04:33:21.054 +00:00 [Error] Sitecore.XConnect.Operations.SetFacetOperation`1[Sitecore.XConnect.Facet]: Sitecore.XConnect.Operations.FacetOperationException: Operation #20, Conflict, Contact {cff913e9-636a-0000-0000-05e696b95c27}, ExmKeyBehaviorCache 

2020-07-23 04:33:21.101 +00:00 [Error] Sitecore.XConnect.Operations.SetFacetOperation`1[Sitecore.XConnect.Facet]: Sitecore.XConnect.Operations.FacetOperationException: Operation #21, Conflict, Contact {cff913e9-636a-0000-0000-05e696b95c27}, EngagementMeasures

Note

Historically, when the PatchFacetOperation operation was successful, it did not write a log entry.

The extending xConnect logging feature improves the logging of retryable SetFacetOperation operations. Errors are written to the log only if the whole PatchFacetOperation operation fails. When the SetFacetOperation fails under a PatchFacetOperation operation, it writes [Debug] information to the log file instead.

Retryable SetFacetOperation log output example

Every PatchFacetOperation is assigned a unique ID. You can find all child operations with this ID. When the MinimumLevel of logging is set to Warning, then only failed PatchFacetOperation operations appear in the log. For example:

2021-06-01 10:16:20.131 +03:00 [Error] [XdbContextLoggingPlugin] XdbContext Operation Exception, Operation #1, Batch #f917f8a7-c7ea-458d-b589-b6accf217870, Sitecore.XConnect.Operations.PatchFacetOperation`1[Sitecore.XConnect.Facet]: Sitecore.XConnect.Operations.FacetOperationException: Operation #1, Conflict, Contact {5f056110-fbd9-0000-0000-0625942c1bac}, ContactBehaviorProfile 

2021-06-01 10:16:20.131 +03:00 [Error] [XdbContextLoggingPlugin] XdbContext Operation Exception, Operation #2, Batch #f917f8a7-c7ea-458d-b589-b6accf217870, Sitecore.XConnect.Operations.PatchFacetOperation`1[Sitecore.XConnect.Facet]: Sitecore.XConnect.Operations.FacetOperationException: Operation #2, Conflict, Contact {5f056110-fbd9-0000-0000-0625942c1bac}, EngagementMeasures 

2021-06-01 10:16:20.131 +03:00 [Error] [XdbContextLoggingPlugin] XdbContext Operation Exception, Operation #3, Batch #f917f8a7-c7ea-458d-b589-b6accf217870, Sitecore.XConnect.Operations.PatchFacetOperation`1[Sitecore.XConnect.Facet]: Sitecore.XConnect.Operations.FacetOperationException: Operation #3, Conflict, Contact {5f056110-fbd9-0000-0000-0625942c1bac}, ExmKeyBehaviorCache 

2021-06-01 10:16:20.131 +03:00 [Error] [XdbContextLoggingPlugin] XdbContext Operation Exception, Operation #4, Batch #f917f8a7-c7ea-458d-b589-b6accf217870, Sitecore.XConnect.Operations.PatchFacetOperation`1[Sitecore.XConnect.Facet]: Sitecore.XConnect.Operations.FacetOperationException: Operation #4, Conflict, Contact {5f056110-fbd9-0000-0000-0625942c1bac}, InteractionsCache 

2021-06-01 10:16:20.131 +03:00 [Error] [XdbContextLoggingPlugin] XdbContext Operation Exception, Operation #5, Batch #f917f8a7-c7ea-458d-b589-b6accf217870, Sitecore.XConnect.Operations.PatchFacetOperation`1[Sitecore.XConnect.Facet]: Sitecore.XConnect.Operations.FacetOperationException: Operation #5, Conflict, Contact {5f056110-fbd9-0000-0000-0625942c1bac}, KeyBehaviorCache

The log contains:

  • The ID of the PatchFacetOperation. For example, #f917f8a7-c7ea-458d-b589-b6accf217870.

  • The number of the suboperation within the PatchFacetOperation operation. For example, Operation #2.

  • The entity where the error occurred. For example, Contact {5f056110-fbd9-0000-0000-0625942c1bac}.

  • The name of the facet where the operation failed. For example, ContactBehaviorProfile, InteractionsCache, EngagementMeasures.

When you set the MinimumLevel to Debug, it logs all retried operations and successful operations. For example:

Failed operation log:

2021-06-01 09:33:30.624 +03:00 [Debug] [XdbContextLoggingPlugin] XdbContext Operation Warning, Operation #1, Batch #220a6442-af3c-4716-ae50-671bd56b43b7, retry attempt: 0, Sitecore.XConnect.Operations.PatchFacetOperation`1[Sitecore.XConnect.Facet], Failed Sub Operation: Sitecore.XConnect.Operations.RetryableSetFacetOperation`1[Sitecore.XConnect.Facet]: Sitecore.XConnect.Operations.FacetOperationException: Operation #12, Conflict, Contact {37c1876d-cf50-0000-0000-062592a80077}, ContactBehaviorProfile 

2021-06-01 09:33:31.862 +03:00 [Debug] [XdbContextLoggingPlugin] XdbContext Operation Warning, Operation #1, Batch #220a6442-af3c-4716-ae50-671bd56b43b7, retry attempt: 1, Sitecore.XConnect.Operations.PatchFacetOperation`1[Sitecore.XConnect.Facet], Failed Sub Operation: Sitecore.XConnect.Operations.RetryableSetFacetOperation`1[Sitecore.XConnect.Facet]: Sitecore.XConnect.Operations.FacetOperationException: Operation #23, Conflict, Contact {37c1876d-cf50-0000-0000-062592a80077}, ContactBehaviorProfile 

2021-06-01 09:33:32.889 +03:00 [Debug] [XdbContextLoggingPlugin] XdbContext Operation Warning, Operation #1, Batch #220a6442-af3c-4716-ae50-671bd56b43b7, retry attempt: 2, Sitecore.XConnect.Operations.PatchFacetOperation`1[Sitecore.XConnect.Facet], Failed Sub Operation: Sitecore.XConnect.Operations.RetryableSetFacetOperation`1[Sitecore.XConnect.Facet]: Sitecore.XConnect.Operations.FacetOperationException: Operation #34, Conflict, Contact {37c1876d-cf50-0000-0000-062592a80077}, ContactBehaviorProfile 

****************************************************** 

2021-06-01 09:33:38.885 +03:00 [Debug] [XdbContextLoggingPlugin] XdbContext Operation Warning, Operation #1, Batch #220a6442-af3c-4716-ae50-671bd56b43b7, retry attempt: 10, Sitecore.XConnect.Operations.PatchFacetOperation`1[Sitecore.XConnect.Facet], Failed Sub Operation: Sitecore.XConnect.Operations.RetryableSetFacetOperation`1[Sitecore.XConnect.Facet]: Sitecore.XConnect.Operations.FacetOperationException: Operation #122, Conflict, Contact {37c1876d-cf50-0000-0000-062592a80077}, ContactBehaviorProfile 

2021-06-01 09:33:38.886 +03:00 [Error] [XdbContextLoggingPlugin] XdbContext Operation Exception, Operation #1, Batch #220a6442-af3c-4716-ae50-671bd56b43b7, Sitecore.XConnect.Operations.PatchFacetOperation`1[Sitecore.XConnect.Facet]: Sitecore.XConnect.Operations.FacetOperationException: Operation #1, Conflict, Contact {37c1876d-cf50-0000-0000-062592a80077}, ContactBehaviorProfile

Successful operation log:

2021-06-01 09:33:32.869 +03:00 [Debug] [XdbContextLoggingPlugin] XdbContext Operation Warning, Operation #1, Batch #bd29d615-89c9-48ba-961a-ff9a9617ddd1, retry attempt: 7, Sitecore.XConnect.Operations.PatchFacetOperation`1[Sitecore.XConnect.Facet], Failed Sub Operation: Sitecore.XConnect.Operations.RetryableSetFacetOperation`1[Sitecore.XConnect.Facet]: Sitecore.XConnect.Operations.FacetOperationException: Operation #89, Conflict, Contact {37c1876d-cf50-0000-0000-062592a80077}, ContactBehaviorProfile 

2021-06-01 09:33:32.879 +03:00 [Debug] [XdbContextLoggingPlugin] Xdb Operation Completed, Parent Operation #1, Batch #bd29d615-89c9-48ba-961a-ff9a9617ddd1, Sitecore.XConnect.Operations.PatchFacetOperation`1[Sitecore.XConnect.Facet], Successfully Completed Operation: Sitecore.XConnect.Operations.RetryableSetFacetOperation`1[Sitecore.XConnect.Facet]

The log contains:

  • The ID of the PatchFacetOperation so you can find all related operations. For example, #220a6442-af3c-4716-ae50-671bd56b43b7.

  • The number of the suboperation within the PatchFacetOperation operation. For example, Operation #2.

  • The retry attempt.

  • The entity where the error occurred. For example, Contact {5f056110-fbd9-0000-0000-0625942c1bac}.

  • The name of the facet where the operation failed. For example, ContactBehaviorProfile, InteractionsCache, EngagementMeasures.

  • The status of the operation: Successfully Completed Operation, Failed Sub Operation, or Conflict.