Unexpected row count errors (R5)

[jguengerich]

I know it is probably going to be difficult for anyone to provide insight on this, since it doesn't happen consistently, but I thought it was worth a try.

Using R5, but modified.

Every once in a while, I have this series of errors show up in my log, always originating from the same page when calling ClearExistingTaxes:
EDIT: Acutally sometimes it is ClearExistingShipping (from the same page).

This shows up twice with the exact same timestamp:

Code: Select all

2016-04-14 09:55:47,351 ERROR lushingEventListener Could not synchronize database state with session
NHibernate.StaleStateException: Unexpected row count: 0; expected: 1
   at NHibernate.AdoNet.Expectations.BasicExpectation.VerifyOutcomeNonBatched(Int32 rowCount, IDbCommand statement)
   at NHibernate.Persister.Entity.AbstractEntityPersister.Delete(Object id, Object version, Int32 j, Object obj, SqlCommandInfo sql, ISessionImplementor session, Object[] loadedState)
   at NHibernate.Persister.Entity.AbstractEntityPersister.Delete(Object id, Object version, Object obj, ISessionImplementor session)
   at NHibernate.Action.EntityDeleteAction.Execute()
   at NHibernate.Engine.ActionQueue.Execute(IExecutable executable)
   at NHibernate.Engine.ActionQueue.ExecuteActions(IList list)
   at NHibernate.Event.Default.AbstractFlushingEventListener.PerformExecutions(IEventSource session)

Then this twice with the exact same timestamp (slightly after the previous timestamp):

Code: Select all

2016-04-14 09:55:47,460 ERROR AbleCommerce         An error has occured at https://orders.urschel.com/Checkout/Shipping.aspx
System.Web.HttpUnhandledException (0x80004005): Exception of type 'System.Web.HttpUnhandledException' was thrown. ---> NHibernate.StaleStateException: Unexpected row count: 0; expected: 1
   at CommerceBuilder.DomainModel.EntityWithTypedId`1.Delete()
   at CommerceBuilder.Taxes.TaxCalculator.ClearExistingTaxes(Basket basket)
   at CommerceBuilder.Taxes.TaxCalculator.Calculate(Basket basket)
   at CommerceBuilder.Services.Checkout.BasketService.Recalculate(Basket basket)
   at AbleCommerce.Checkout.Shipping.ShipMethodsList_SelectedIndexChanged(Object sender, EventArgs e)
   at System.Web.UI.WebControls.ListControl.OnSelectedIndexChanged(EventArgs e)
   at System.Web.UI.Page.RaiseChangedEvents()
   at System.Web.UI.Page.ProcessRequestMain(Boolean includeStagesBeforeAsyncPoint, Boolean includeStagesAfterAsyncPoint)
   at System.Web.UI.Page.HandleError(Exception e)
   at System.Web.UI.Page.ProcessRequestMain(Boolean includeStagesBeforeAsyncPoint, Boolean includeStagesAfterAsyncPoint)
   at System.Web.UI.Page.ProcessRequest(Boolean includeStagesBeforeAsyncPoint, Boolean includeStagesAfterAsyncPoint)
   at System.Web.UI.Page.ProcessRequest()
   at System.Web.UI.Page.ProcessRequest(HttpContext context)
   at System.Web.HttpApplication.CallHandlerExecutionStep.System.Web.HttpApplication.IExecutionStep.Execute()
   at System.Web.HttpApplication.ExecuteStep(IExecutionStep step, Boolean& completedSynchronously)

Then this pair of messages twice, all 4 messages with the same timestamp (slightly after the previous timestamp).

Code: Select all

2016-04-14 09:55:47,616 ERROR lushingEventListener Could not synchronize database state with session
NHibernate.StaleStateException: Unexpected row count: 0; expected: 1
   at NHibernate.AdoNet.Expectations.BasicExpectation.VerifyOutcomeNonBatched(Int32 rowCount, IDbCommand statement)
   at NHibernate.Persister.Entity.AbstractEntityPersister.Delete(Object id, Object version, Int32 j, Object obj, SqlCommandInfo sql, ISessionImplementor session, Object[] loadedState)
   at NHibernate.Persister.Entity.AbstractEntityPersister.Delete(Object id, Object version, Object obj, ISessionImplementor session)
   at NHibernate.Action.EntityDeleteAction.Execute()
   at NHibernate.Engine.ActionQueue.Execute(IExecutable executable)
   at NHibernate.Engine.ActionQueue.ExecuteActions(IList list)
   at NHibernate.Event.Default.AbstractFlushingEventListener.PerformExecutions(IEventSource session)
2016-04-14 09:55:47,616 ERROR AbleCommerce         Unable to save page view record. Unexpected row count: 0; expected: 1
NHibernate.StaleStateException: Unexpected row count: 0; expected: 1
   at CommerceBuilder.DomainModel.EntityWithTypedId`1.Save()
   at CommerceBuilder.Services.PageTracker.Track(HttpApplication application, HttpContext context)

Does anyone have any idea what might cause these errors?

[mazhar]

It seems like it happens when it tries to delete something which is already deleted from database. Not sure about how to trigger this scenario though. Is thee any custom code in place which maybe removing basket items before this system routine or maybe directly from database without involving Nhibernate?

[jguengerich]

It is custom code. Based on the second error message's call stack, the code below is executing. See the notes embedded in the code. Also, as I mentioned, most of the time there is no error.

Code: Select all

// Second error message's call stack points to the Recalculate line at the bottom of this snippet.  This is the preceding code which potentially changes the basket.  There's no information in the first error message's call stack to indicate if that error is happening in this code somewhere, or if the first error message is coming from the same place as the second.
                foreach (BasketShipment shipment in shipments)
                {
                    shipment.ShipMethod = selectedShipMethod;
                    shipment.ShipMessage = "";
                    shipment.Save();
                    if (shipment.ShipMethod == null) allMethodsValid = false;
                    _ShipmentIndex++;
                }
                if (!allMethodsValid)
                {
                    //HANDLE ERROR MESSAGE (UNEXPECTED)
                    InvalidShipMethodPanel.Visible = true;
                }
                basket.Save();
                basket = null;
// ChargeMyShippingCheckBox_CheckedChanged potentially calls code to package and/or recalculate the basket, but the basket is saved if it does, and I have just saved it prior to this, so I'm not sure how the Recalculate below would try to access something that has already been deleted.
                if (ChargeMyShippingCheckBox.Checked != orginalChecked) ChargeMyShippingCheckBox_CheckedChanged(ChargeMyShippingCheckBox, e);
                basket = AbleContext.Current.User.Basket;
                IBasketService preCheckoutService = AbleContext.Resolve<IBasketService>();
// Second error message's call stack points to following line.
                preCheckoutService.Recalculate(basket);