AI OnAI Off

Exception when adding/updating cart or listing cart items, problem with workflow

Kristoffer Lindén
Kristoffer Lindén
Vote:
 

Hi!

We are running Commerce 11.2.2 and are still using workflows. We just found out that exceptions are caught when we run the CartValidate workflow.

Our code:

public bool AddToCart(string code, decimal quantity, out string warningMessage)
        {
            var entry = CatalogContext.Current.GetCatalogEntry(code);

            if (SiteContext.Current.Currency != _cartHelper.Cart.BillingCurrency)
            {
                SiteContext.Current.Currency = _cartHelper.Cart.BillingCurrency;
            }

            var lineItem = _cartHelper.AddEntry(entry, quantity, false);

            // If this is not set explicitly, 
            // place price does not get updated by workflow
            _cartHelper.Cart.ProviderId = "frontend";
            ValidateCart(out warningMessage);

            return _cartHelper.LineItems.Select(x => x.Code).Contains(code);
        }

Running this code gives us this exception:

Mediachase.BusinessFoundation.Data.Meta.ObjectNotFoundException: Object Contact.PrimaryKeyId = 'c0105be4-02c0-4bb5-a257-0b9c76dfa12e' not found
  at Mediachase.BusinessFoundation.Data.Meta.MetaObject.GetRowSource
  at Mediachase.BusinessFoundation.Data.Meta.MetaObject.Load
  at Mediachase.BusinessFoundation.Data.Meta.MetaObject..ctor
  at Mediachase.BusinessFoundation.Data.Meta.MetaObject..ctor
  at Mediachase.BusinessFoundation.Data.Meta.MetaObjectActivator.CreateInstance
  at Mediachase.BusinessFoundation.Data.Meta.MetaObjectActivator.CreateInstance
  at Mediachase.BusinessFoundation.Data.Meta.MetaObjectActivator.CreateInstance
  at Mediachase.BusinessFoundation.Data.Business.EntityObjectDefaultRequestHandler.Load
  at Mediachase.BusinessFoundation.Data.Business.EntityObjectDefaultRequestHandler.Execute
  at Mediachase.BusinessFoundation.Data.Business.BaseRequestHandler.Mediachase.BusinessFoundation.Data.Business.IRequestHandler.Execute
  at Mediachase.BusinessFoundation.Data.Business.BusinessManager.ExecutePipeline
  at Mediachase.BusinessFoundation.Data.Business.BusinessManager.ExecutePipelineInTransaction
  at Mediachase.BusinessFoundation.Data.Business.BusinessManager.Execute
  at Mediachase.BusinessFoundation.Data.Business.BusinessManager.Load
  at Mediachase.BusinessFoundation.Data.Meta.MetaObject.GetRowSource
  at Mediachase.BusinessFoundation.Data.Meta.MetaObject.Load
  at Mediachase.BusinessFoundation.Data.Meta.MetaObject..ctor
  at Mediachase.BusinessFoundation.Data.Meta.MetaObject..ctor
  at Mediachase.BusinessFoundation.Data.Meta.MetaObjectActivator.CreateInstance
  at Mediachase.BusinessFoundation.Data.Meta.MetaObjectActivator.CreateInstance
  at Mediachase.BusinessFoundation.Data.Meta.MetaObjectActivator.CreateInstance
  at Mediachase.BusinessFoundation.Data.Business.EntityObjectDefaultRequestHandler.Load
  at Mediachase.BusinessFoundation.Data.Business.EntityObjectDefaultRequestHandler.Execute
  at Mediachase.BusinessFoundation.Data.Business.BaseRequestHandler.Mediachase.BusinessFoundation.Data.Business.IRequestHandler.Execute
  at Mediachase.BusinessFoundation.Data.Business.BusinessManager.ExecutePipeline
  at Mediachase.BusinessFoundation.Data.Business.BusinessManager.ExecutePipelineInTransaction
  at Mediachase.BusinessFoundation.Data.Business.BusinessManager.Execute
  at Mediachase.BusinessFoundation.Data.Business.BusinessManager.Load

Removing this line of code:

 ValidateCart(out warningMessage);

Which runs the CartValidate workflow, and the exception goes away so I guess there is something in the workflow.

The web works just fine, but I'm nort sure if this affects the perfrormance in any way?

/Kristoffer

#183729
Edited, Oct 20, 2017 15:35
Quan Mai
Quan Mai
Vote:
 

It should not be a problem here. The code to load the contact will simply return null if the contact is not found. But yes I think this can be improved - we will look into it.

#183732
Oct 21, 2017 10:18
Kristoffer Lindén
Kristoffer Lindén
Vote:
 

Thanks Quan!

/Kristoffer

#183736
Oct 22, 2017 21:41
Quan Mai
Quan Mai
Vote:
 

Just a follow up: We did improve it, and our testing shows an improvement of 25% on the validation of a cart with 3 items. 

It'll be available in an upcoming release (probably 11.4)

#183975
Oct 25, 2017 10:41
Menno Zeilstra
Menno Zeilstra
Vote:
 

Just as follow up :  I am using 11.5

And the not found exceptions keep spamming the log! I am getting more than 14000 of this type of errors per hour!  Please make it stop.  Now for some trace:

  • CartService.LoadOrCreateCart

    • 0374    SqlConnection.Somedatabase.database.windows.net | some-prd-episerver-commerce
    • 7374    SqlCommand.ExecuteReader SELECT cls_Contact, Records: 0
    • 0381    CurrentMarket.GetCurrentMarket
    • 0381    CurrentMarket.GetCurrentMarket
    • 0381    LoggerConfigurator.GetLogger
    • 0381    AzureWebAppsInstanceIdEnricher.Enrich
    • 0381    ClientConnectingIPEnricher.Enrich
    • 0381    CloudflareIPCountryEnricher.Enrich
    • 0381    CloudflareRayEnricher.Enrich
    • 0381    RequestUrlPathAndQueryEnricher.Enrich
    • 0381    CurrentContentReferenceEnricher.Enrich
    • 0381    CurrentCustomerIdEnricher.Enrich
    • 0381    ErrorCodeEnricher.Enrich
    • 1382    CartService.SetCartCurrency
      • 0382 LoggerExtensions.PushProperty
      • 0382 AzureWebAppsInstanceIdEnricher.Enrich
      • 0382 ClientConnectingIPEnricher.Enrich
      • 0382 CloudflareIPCountryEnricher.Enrich
      • 0382 CloudflareRayEnricher.Enrich
      • 0382 RequestUrlPathAndQueryEnricher.Enrich
      • 0382 CurrentContentReferenceEnricher.Enrich
      • 0382 CurrentCustomerIdEnricher.Enrich
      • 0382 ErrorCodeEnricher.Enrich
    • 0382    CurrentWarehouse.GetCurrentWarehouse
    • 0382    CurrentWarehouse.GetWarehouseByMarket
    • 0382    CartService.SetCartWarehouse
  • 0381  Error
    ERROR Object Contact.PrimaryKeyId = '80509e35-60b3-478e-b403-3a12247e7a23' not found
Mediachase.BusinessFoundation.Data.Meta.ObjectNotFoundException: Object Contact.PrimaryKeyId = '80509e35-60b3-478e-b403-3a12247e7a23' not found
  at Mediachase.BusinessFoundation.Data.Meta.MetaObject.GetRowSource
  at Mediachase.BusinessFoundation.Data.Meta.MetaObject.Load
  at Mediachase.BusinessFoundation.Data.Meta.MetaObject..ctor
  at Mediachase.BusinessFoundation.Data.Meta.MetaObject..ctor
  at Mediachase.BusinessFoundation.Data.Meta.MetaObjectActivator.CreateInstance
  at Mediachase.BusinessFoundation.Data.Meta.MetaObjectActivator.CreateInstance
  at Mediachase.BusinessFoundation.Data.Meta.MetaObjectActivator.CreateInstance
  at Mediachase.BusinessFoundation.Data.Business.EntityObjectDefaultRequestHandler.Load
  at Mediachase.BusinessFoundation.Data.Business.EntityObjectDefaultRequestHandler.Execute
  at Mediachase.BusinessFoundation.Data.Business.BaseRequestHandler.Mediachase.BusinessFoundation.Data.Business.IRequestHandler.Execute
  at Mediachase.BusinessFoundation.Data.Business.BusinessManager.ExecutePipeline
  at Mediachase.BusinessFoundation.Data.Business.BusinessManager.Execute
  at Mediachase.BusinessFoundation.Data.Business.BusinessManager.Load
  • 0382  LayoutViewModelBase.()
  • 0382  LayoutViewModelFactoryBase.IsEditMode
#200952
Edited, Jan 31, 2019 14:23
Quan Mai
Quan Mai
Vote:
 

The improvement made in 11.4 should have reduced it, but I think we can make further improvement. I will look into this 

#200959
Jan 31, 2019 14:47
Menno Zeilstra
Menno Zeilstra
Vote:
 

Cool!   It would be nice if the absence of a contact  (not found) just would return an empty contact without throwing the exception.

#200960
Jan 31, 2019 15:04
Quan Mai
Quan Mai
Vote:
 

What I don't understand is BusinessManager.Load actually catches the exception and return null (yes, not the perfect way to do it), how could that end up in your log files ... 

#200962
Jan 31, 2019 15:14
Menno Zeilstra
Menno Zeilstra
Vote:
 

It does not end up in our SEQ logger where we log to in our code but somehow the mediachase part of the application writes to the IIS log that stackify picks up on.  Here is just 5 seconds of log ===>>>

  • January 31st, 2019 [2019-01-31]
  • 11:15:01.203
    appservice-episerver-cmd-01 Production [0000-c5d52b]
    ERRORObject Contact.PrimaryKeyId = '1cc44f9c-7198-4f40-9b59-e1001e5e1669' not found
Mediachase.BusinessFoundation.Data.Meta.ObjectNotFoundException: Object Contact.PrimaryKeyId = '1cc44f9c-7198-4f40-9b59-e1001e5e1669' not found
  at Mediachase.BusinessFoundation.Data.Meta.MetaObject.GetRowSource
  at Mediachase.BusinessFoundation.Data.Meta.MetaObject.Load
  at Mediachase.BusinessFoundation.Data.Meta.MetaObject..ctor
  at Mediachase.BusinessFoundation.Data.Meta.MetaObject..ctor
  at Mediachase.BusinessFoundation.Data.Meta.MetaObjectActivator.CreateInstance
  at Mediachase.BusinessFoundation.Data.Meta.MetaObjectActivator.CreateInstance
  at Mediachase.BusinessFoundation.Data.Meta.MetaObjectActivator.CreateInstance
  at Mediachase.BusinessFoundation.Data.Business.EntityObjectDefaultRequestHandler.Load
  at Mediachase.BusinessFoundation.Data.Business.EntityObjectDefaultRequestHandler.Execute
  at Mediachase.BusinessFoundation.Data.Business.BaseRequestHandler.Mediachase.BusinessFoundation.Data.Business.IRequestHandler.Execute
  at Mediachase.BusinessFoundation.Data.Business.BusinessManager.ExecutePipeline
  at Mediachase.BusinessFoundation.Data.Business.BusinessManager.Execute
  at Mediachase.BusinessFoundation.Data.Business.BusinessManager.Load
    fromapm
     View
    Trace
  • 11:15:03.020
    appservice-episerver-cmd-01 Production [0000-390343]
    ERRORObject Contact.PrimaryKeyId = 'a8bc4633-a974-40de-a9c2-f3560f538a6d' not found
Mediachase.BusinessFoundation.Data.Meta.ObjectNotFoundException: Object Contact.PrimaryKeyId = 'a8bc4633-a974-40de-a9c2-f3560f538a6d' not found
  at Mediachase.BusinessFoundation.Data.Meta.MetaObject.GetRowSource
  at Mediachase.BusinessFoundation.Data.Meta.MetaObject.Load
  at Mediachase.BusinessFoundation.Data.Meta.MetaObject..ctor
  at Mediachase.BusinessFoundation.Data.Meta.MetaObject..ctor
  at Mediachase.BusinessFoundation.Data.Meta.MetaObjectActivator.CreateInstance
  at Mediachase.BusinessFoundation.Data.Meta.MetaObjectActivator.CreateInstance
  at Mediachase.BusinessFoundation.Data.Meta.MetaObjectActivator.CreateInstance
  at Mediachase.BusinessFoundation.Data.Business.EntityObjectDefaultRequestHandler.Load
  at Mediachase.BusinessFoundation.Data.Business.EntityObjectDefaultRequestHandler.Execute
  at Mediachase.BusinessFoundation.Data.Business.BaseRequestHandler.Mediachase.BusinessFoundation.Data.Business.IRequestHandler.Execute
  at Mediachase.BusinessFoundation.Data.Business.BusinessManager.ExecutePipeline
  at Mediachase.BusinessFoundation.Data.Business.BusinessManager.Execute
  at Mediachase.BusinessFoundation.Data.Business.BusinessManager.Load
    fromapm
     View
  • Toggle Dropdown
    11:15:03.276
    appservice-episerver-cmd-01 Production [0000-9fd99b]
    ERRORObject Contact.PrimaryKeyId = '7c3c3d5d-2f90-4475-b8c8-0a6fa6a9dc6c' not found
Mediachase.BusinessFoundation.Data.Meta.ObjectNotFoundException: Object Contact.PrimaryKeyId = '7c3c3d5d-2f90-4475-b8c8-0a6fa6a9dc6c' not found
  at Mediachase.BusinessFoundation.Data.Meta.MetaObject.GetRowSource
  at Mediachase.BusinessFoundation.Data.Meta.MetaObject.Load
  at Mediachase.BusinessFoundation.Data.Meta.MetaObject..ctor
  at Mediachase.BusinessFoundation.Data.Meta.MetaObject..ctor
  at Mediachase.BusinessFoundation.Data.Meta.MetaObjectActivator.CreateInstance
  at Mediachase.BusinessFoundation.Data.Meta.MetaObjectActivator.CreateInstance
  at Mediachase.BusinessFoundation.Data.Meta.MetaObjectActivator.CreateInstance
  at Mediachase.BusinessFoundation.Data.Business.EntityObjectDefaultRequestHandler.Load
  at Mediachase.BusinessFoundation.Data.Business.EntityObjectDefaultRequestHandler.Execute
  at Mediachase.BusinessFoundation.Data.Business.BaseRequestHandler.Mediachase.BusinessFoundation.Data.Business.IRequestHandler.Execute
  at Mediachase.BusinessFoundation.Data.Business.BusinessManager.ExecutePipeline
  at Mediachase.BusinessFoundation.Data.Business.BusinessManager.Execute
  at Mediachase.BusinessFoundation.Data.Business.BusinessManager.Load
    fromapm
     View
  • 11:15:04.239
    appservice-episerver-cmd-01 Production [0000-cc88f9]
    ERRORObject Contact.PrimaryKeyId = '33ab0680-88a6-4340-8b6f-9d0649e62ada' not found
Mediachase.BusinessFoundation.Data.Meta.ObjectNotFoundException: Object Contact.PrimaryKeyId = '33ab0680-88a6-4340-8b6f-9d0649e62ada' not found
  at Mediachase.BusinessFoundation.Data.Meta.MetaObject.GetRowSource
  at Mediachase.BusinessFoundation.Data.Meta.MetaObject.Load
  at Mediachase.BusinessFoundation.Data.Meta.MetaObject..ctor
  at Mediachase.BusinessFoundation.Data.Meta.MetaObject..ctor
  at Mediachase.BusinessFoundation.Data.Meta.MetaObjectActivator.CreateInstance
  at Mediachase.BusinessFoundation.Data.Meta.MetaObjectActivator.CreateInstance
  at Mediachase.BusinessFoundation.Data.Meta.MetaObjectActivator.CreateInstance
  at Mediachase.BusinessFoundation.Data.Business.EntityObjectDefaultRequestHandler.Load
  at Mediachase.BusinessFoundation.Data.Business.EntityObjectDefaultRequestHandler.Execute
  at Mediachase.BusinessFoundation.Data.Business.BaseRequestHandler.Mediachase.BusinessFoundation.Data.Business.IRequestHandler.Execute
  at Mediachase.BusinessFoundation.Data.Business.BusinessManager.ExecutePipeline
  at Mediachase.BusinessFoundation.Data.Business.BusinessManager.Execute
  at Mediachase.BusinessFoundation.Data.Business.BusinessManager.Load
    fromapm
     View
  • 11:15:06.320
    appservice-episerver-cmd-01 Production [0000-390343]
    ERRORObject Contact.PrimaryKeyId = 'acfc043c-b40d-4956-8c2a-fb944b6e1411' not found
Mediachase.BusinessFoundation.Data.Meta.ObjectNotFoundException: Object Contact.PrimaryKeyId = 'acfc043c-b40d-4956-8c2a-fb944b6e1411' not found
  at Mediachase.BusinessFoundation.Data.Meta.MetaObject.GetRowSource
  at Mediachase.BusinessFoundation.Data.Meta.MetaObject.Load
  at Mediachase.BusinessFoundation.Data.Meta.MetaObject..ctor
  at Mediachase.BusinessFoundation.Data.Meta.MetaObject..ctor
  at Mediachase.BusinessFoundation.Data.Meta.MetaObjectActivator.CreateInstance
  at Mediachase.BusinessFoundation.Data.Meta.MetaObjectActivator.CreateInstance
  at Mediachase.BusinessFoundation.Data.Meta.MetaObjectActivator.CreateInstance
  at Mediachase.BusinessFoundation.Data.Business.EntityObjectDefaultRequestHandler.Load
  at Mediachase.BusinessFoundation.Data.Business.EntityObjectDefaultRequestHandler.Execute
  at Mediachase.BusinessFoundation.Data.Business.BaseRequestHandler.Mediachase.BusinessFoundation.Data.Business.IRequestHandler.Execute
  at Mediachase.BusinessFoundation.Data.Business.BusinessManager.ExecutePipeline
  at Mediachase.BusinessFoundation.Data.Business.BusinessManager.Execute
  at Mediachase.BusinessFoundation.Data.Business.BusinessManager.Load
#200964
Edited, Jan 31, 2019 15:23
Quan Mai
Quan Mai
Vote:
 

When I look into it, the pipepline is actually too complicated to make a meaningful fix. I know that is not something you would like to hear, but, there are legacy parts that should be left as-is.

You can configure stackify to reduce the log, I guess: 

https://stackify.com/retrace-logging-error-tracking/ 

#201088
Feb 05, 2019 14:58
Menno Zeilstra
Menno Zeilstra
Vote:
 

Ok, I configured stackify to only log unhandled exceptions. We will wait and see what will happen.

#201159
Feb 07, 2019 12:57
* 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.