Error opening an order

[CraigS]

Hello,
We are receiving this error sometimes when opening an order through the SoftPro SDK. Any ideas on what would cause this error and how to prevent it? This code is running inside a SoftPro Server Package. Thank you.

NHibernate.Exceptions.GenericADOException: could not delete collection: [SoftPro.Select.Client.Runtime.Session.Locks#d18bdcfc-a3c1-4cc5-87cf-0588106bf336][SQL: DELETE FROM core.LockView WHERE SessionID = @p0] ---> System.Data.SqlClient.SqlException: Execution Timeout Expired. The timeout period elapsed prior to completion of the operation or the server is not responding.
Operation cancelled by user. ---> System.ComponentModel.Win32Exception: The wait operation timed out
--- End of inner exception stack trace ---
at System.Data.SqlClient.SqlConnection.OnError(SqlException exception, Boolean breakConnection, Action`1 wrapCloseInAction)
at System.Data.SqlClient.TdsParser.ThrowExceptionAndWarning(TdsParserStateObject stateObj, Boolean callerHasConnectionLock, Boolean asyncClose)
at System.Data.SqlClient.TdsParser.TryRun(RunBehavior runBehavior, SqlCommand cmdHandler, SqlDataReader dataStream, BulkCopySimpleResultSet bulkCopyHandler, TdsParserStateObject stateObj, Boolean& dataReady)
at System.Data.SqlClient.SqlCommand.FinishExecuteReader(SqlDataReader ds, RunBehavior runBehavior, String resetOptionsString, Boolean isInternal, Boolean forDescribeParameterEncryption, Boolean shouldCacheForAlwaysEncrypted)
at System.Data.SqlClient.SqlCommand.RunExecuteReaderTds(CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStream, Boolean async, Int32 timeout, Task& task, Boolean asyncWrite, Boolean inRetry, SqlDataReader ds, Boolean describeParameterEncryptionRequest)
at System.Data.SqlClient.SqlCommand.RunExecuteReader(CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStream, String method, TaskCompletionSource`1 completion, Int32 timeout, Task& task, Boolean& usedCache, Boolean asyncWrite, Boolean inRetry)
at System.Data.SqlClient.SqlCommand.InternalExecuteNonQuery(TaskCompletionSource`1 completion, String methodName, Boolean sendToPipe, Int32 timeout, Boolean& usedCache, Boolean asyncWrite, Boolean inRetry)
at System.Data.SqlClient.SqlCommand.ExecuteNonQuery()
at NHibernate.AdoNet.AbstractBatcher.ExecuteNonQuery(IDbCommand cmd)
at NHibernate.Persister.Collection.AbstractCollectionPersister.Remove(Object id, ISessionImplementor session)
--- End of inner exception stack trace ---
at NHibernate.Persister.Collection.AbstractCollectionPersister.Remove(Object id, ISessionImplementor session)
at NHibernate.Action.CollectionUpdateAction.Execute()
at NHibernate.Engine.ActionQueue.Execute(IExecutable executable)
at NHibernate.Engine.ActionQueue.ExecuteActions(IList list)
at NHibernate.Engine.ActionQueue.ExecuteActions()
at NHibernate.Event.Default.AbstractFlushingEventListener.PerformExecutions(IEventSource session)
at NHibernate.Event.Default.DefaultFlushEventListener.OnFlush(FlushEvent event)
at NHibernate.Impl.SessionImpl.Flush()
at SoftPro.PersistenceModel.DeadlockDetectionAspect.SoftPro.ServerModel.Aspects.IAspect.Process(Action method) in D:\a\1\s\Code\SPNet\Models\PersistenceModel\DeadlockDetectionAspect.cs:line 33
at SoftPro.PersistenceModel.UniqueConstraintViolationAspect.SoftPro.ServerModel.Aspects.IAspect.Process(Action method) in D:\a\1\s\Code\SPNet\Models\PersistenceModel\UniqueConstraintViolationAspect.cs:line 32
at SoftPro.PersistenceModel.StaleObjectStateExceptionAspect.SoftPro.ServerModel.Aspects.IAspect.Process(Action method) in D:\a\1\s\Code\SPNet\Models\PersistenceModel\StaleObjectStateExceptionAspect.cs:line 23
at SoftPro.Select.Server.Runtime.LockProvider.Acquire(Guid objectType, Guid objectIdentifier, String& owner, String& reason) in D:\a\1\s\Code\SPNet\Select\SelectServer\Runtime\LockProvider.cs:line 165
at SoftPro.Select.Service.Runtime.LockContext.Acquire(Guid objectType, Guid objectIdentifier) in D:\a\1\s\Code\SPNet\Select\SelectService\Runtime\LockContext.cs:line 49
at SoftPro.OrderTracking.Server.Orders.OrderStore.ReadOrder(OrderIdentifier id, Boolean readOnly, Byte[]& data) in D:\a\1\s\Code\SPNet\ProForm\ProFormServer\Orders\OrderStore.cs:line 1388
at SoftPro.OrderTracking.Server.Orders.OrderStore.SoftPro.OrderTracking.Client.Orders.IOrderStore.OpenOrder(OrderIdentifier id, OrderEditMode mode) in D:\a\1\s\Code\SPNet\ProForm\ProFormServer\Orders\OrderStore.cs:line 1253
at SoftPro.OrderTracking.Server.Orders.OrderStore.SoftPro.OrderTracking.Client.Orders.IOrderStore.OpenOrder(IOrderInfo orderInfo, OrderEditMode mode) in D:\a\1\s\Code\SPNet\ProForm\ProFormServer\Orders\OrderStore.cs:line 1219

[vmrvichin]

Can you provide your code for the process of getting the services required from the GetService methods and the code that uses those services to search for and open an order, and I'll take a look at them. If that all looks good, then this sort of error would be outside the scope of this forum and instead should be directed to SoftPro support.

[CraigS]

Thank you for your reply.

Here is the code that we use to open an order and add a note to the order using a method called AddNote. Below that are the GetOrderStore and OpenOrder methods that are called from AddNote.

public APIResponse AddNote(string orderNumber, string note, string categories)
{
// categories is a command delimited list of category ids.
APIResponse response = new APIResponse();
response.Success = false;

IOrderStore orderStore = null;
IOrder theOrder = null;
using (RuntimeContext.Impersonate())
{
try
{
orderStore = GetOrderStore();
theOrder = OpenOrder(orderStore, orderNumber, OrderEditMode.ReadWrite);

// Add top level note.
dynamic newNote = theOrder.CreateNew("Note");
newNote.Text = note;

// Set categories
if (!string.IsNullOrEmpty(categories))
newNote.Categories = categories;

// Save note to order.
IList notes = (IList)theOrder.Order["Notes"];
notes.Add(newNote);

// Save order.
orderStore.ApplyChanges(theOrder);

response.Success = true;
}
catch (Exception ex)
{
response.Success = false;
response.Message = GetErrorMessage(ex);
}
finally
{
// Dispose of SoftPro objects
if (theOrder != null)
theOrder.Dispose();
}
}

return response;
}


protected IOrderStore GetOrderStore()
{
var orderStore = Alanna.AlannaPackage.GetService<IOrderStore>();
if (orderStore == null)
throw new Exception("Order Store is null.");

return orderStore;
}

protected IOrder OpenOrder(IOrderStore orderStore, string orderNumber, OrderEditMode orderEditMode)
{
IOrder theOrder = null;

var orderInfo = orderStore.Orders.Where(o => o.Number == orderNumber).FirstOrDefault();
if (orderInfo != null)
{
theOrder = orderStore.OpenOrder(orderInfo, orderEditMode);
if (theOrder == null)
throw new Exception($"Unable to open order number {orderNumber}.");
}
else
throw new Exception($"Order number {orderNumber} not found.");

return theOrder;
}

[vmrvichin]

That all looks pretty textbook. The only other idea I have is is the AddNote method being called multiple times from different threads, and is it possible that 2 different threads are attempting to manipulate the same order, at the same time? I spun up a quick test server package and while I wasn't able to replicate your exact error message, I did get some other strange NHibernate errors when my 2 threads were fighting over the same order.

[CraigS]

Yes, it's possible that multiple threads are trying to open the same order at the same time. Our server package implements an http listener that accepts incoming http requests to initiate the action of opening the order and saving the note. It's certainly possible that there are multiple http requests coming in at the same time and even for the same order. Is there anything that I can do to prevent this error? Also, there is a pool of SoftPro Servers running, but our server package only actually runs and listens for http requests on one of them. Thank you.