Timeout/exception on call to IOrderStore.NewOrder(OrderCreationSpec)

Discussions concerning general integration topics.

Moderator: Phil Barton

Post Reply
at2k21
Posts: 17
Joined: Wed Aug 16, 2017 5:33 pm

Timeout/exception on call to IOrderStore.NewOrder(OrderCreationSpec)

Post by at2k21 » Wed Jun 13, 2018 10:40 am

I am experiencing what I believe is a timeout on an inconsistent basis. On a call to NewOrder on the IOrderStore passing in an OrderCreationSpec it will throw an exception with the helpful message "One or more errors occurred" after a 2 minute pause. When checked later using the Select Client the order is in fact created. Any idea what is going on here? This situation is very frustrating and any help would be appreciated.

For reference a simplified version of my code is below with checking and error handling removed for readability.

Code: Select all


var creds = new NetworkCredential(Username, Password, "[SERVER]");
SelectServer server = new SelectServer(new Uri(ServerUri), creds);
server.TryAuthenticate(out var reason);
IOrderStore os = server.GetService<IOrderStore>();
OrderCreationSpec spec = new OrderCreationSpec { BaseNumber = order.BaseNumber };
var newOrder = os.NewOrder(spec); //  <---- Exception gets thrown here after 2 minute pause.

This doesn't happen every time but at a high enough frequency to make it a real problem. I have measured failure rates between .5% and 3.6%.

BobRichards
Posts: 1006
Joined: Wed Jan 15, 2014 3:50 pm
Location: Raleigh, NC
Contact:

Re: Timeout/exception on call to IOrderStore.NewOrder(OrderCreationSpec)

Post by BobRichards » Wed Jun 13, 2018 11:05 am

Please pass us the Select version number and the complete call stack. Is this a production or a development environment? Thanks.
Bob Richards, Software Developer, SoftPro

at2k21
Posts: 17
Joined: Wed Aug 16, 2017 5:33 pm

Re: Timeout/exception on call to IOrderStore.NewOrder(OrderCreationSpec)

Post by at2k21 » Wed Jun 13, 2018 12:02 pm

The Select version number is 4.3.50811.33. It is a production environment. I don't have access to the stack. I will have to see if I can wrangle one up. Is there anything you can do to help until then?

at2k21
Posts: 17
Joined: Wed Aug 16, 2017 5:33 pm

Re: Timeout/exception on call to IOrderStore.NewOrder(OrderCreationSpec)

Post by at2k21 » Wed Jun 13, 2018 12:45 pm

I was able to wrangle up the following stack for your review. This seems to verify my thought that there is a timeout. Please let me know if I can provide any further information.

Code: Select all

Message: One or more errors occurred. 
Target: Void ThrowIfExceptional(Boolean) 
Stack:    at System.Threading.Tasks.Task.ThrowIfExceptional(Boolean includeTaskCanceledExceptions)
   at System.Threading.Tasks.Task`1.GetResultCore(Boolean waitCompletionNotification)
   at System.Threading.Tasks.Task`1.get_Result()
   at SoftPro.OrderTracking.Client.Orders.OrderStore.SoftPro.OrderTracking.Client.Orders.IOrderStore.NewOrder(OrderCreationSpec spec, IProgress`1 progressCallback, CancellationToken cancel)
   at SoftPro.OrderTracking.Client.Orders.OrderStore.SoftPro.OrderTracking.Client.Orders.IOrderStore.NewOrder(OrderCreationSpec spec, IProgress`1 progressCallback)
   at SoftPro.OrderTracking.Client.Orders.OrderStore.SoftPro.OrderTracking.Client.Orders.IOrderStore.NewOrder(OrderCreationSpec spec)
   at Softpro.Select.Proxy.Proxy.AddOrder(Order order, String& errorMessage) in C:\Redacted\Softpro.Select.Proxy\Proxy.cs:line 348 
Inner:  --> One or more errors occurred. --> Execution Timeout Expired.  The timeout period elapsed prior to completion of the operation or the server is not responding.
Call Stack:
 - Void Error(System.String) : File:  Line: 0
 - Void Error(System.Exception, System.String) : File:  Line: 0
 - Softpro.Select.Proxy.Model.Basic.Order AddOrder(Softpro.Select.Proxy.Model.Basic.Order, System.String ByRef) : File: C:\Redacted\Softpro.Select.Proxy\Proxy.cs Line: 436
 - SecureSync.SoftproSelect.SoftproSelectResult AddOrder(Softpro.Select.Proxy.Model.Basic.Order) : File: C:\Redacted\Adapter.SoftproSelect\SecureSyncSoftproSelect.cs Line: 656
 - SecureSync.SoftproSelect.SoftproSelectResult CreateOrder(System.Collections.Generic.IDictionary`2[System.String,System.Object]) : File: C:\Redacted\Adapter.SoftproSelect\SecureSyncSoftproSelect.cs Line: 187
 - Softpro.Select.Proxy.Model.Basic.Order CreateOrder(Softpro.Select.Proxy.Model.Basic.Order) : File: C:\Redacted\SoftProHelper.cs Line: 88
 - Softpro.Select.Proxy.Model.Basic.Order CreateOrder(CBImporter.Record) : File: C:\Redacted\SoftProHelper.cs Line: 83
 - CBImporter.RecordToSoftProResult SendSingleRecordToSoftPro(CBImporter.Record, Boolean) : File: C:\Redacted\SimpleForm.cs Line: 307
 - Void ProcessSoftProForFile() : File: C:\Redacted\SimpleForm.cs Line: 256
 - Void ImportFilesWork(System.Object, System.ComponentModel.DoWorkEventArgs) : File: C:\Redacted\SimpleForm.cs Line: 157
 - Void OnDoWork(System.ComponentModel.DoWorkEventArgs) : File:  Line: 0
 - Void WorkerThreadStart(System.Object) : File:  Line: 0
 - System.Object _PrivateProcessMessage(IntPtr, System.Object[], System.Object, System.Object[] ByRef) : File:  Line: 0
 - System.Runtime.Remoting.Messaging.IMessageCtrl AsyncProcessMessage(System.Runtime.Remoting.Messaging.IMessage, System.Runtime.Remoting.Messaging.IMessageSink) : File:  Line: 0
 - Void ThreadPoolCallBack(System.Object) : File:  Line: 0
 - Void WaitCallback_Context(System.Object) : File:  Line: 0
 - Void RunInternal(System.Threading.ExecutionContext, System.Threading.ContextCallback, System.Object, Boolean) : File:  Line: 0
 - Void Run(System.Threading.ExecutionContext, System.Threading.ContextCallback, System.Object, Boolean) : File:  Line: 0
 - Void System.Threading.IThreadPoolWorkItem.ExecuteWorkItem() : File:  Line: 0
 - Boolean Dispatch() : File:  Line: 0
 - Boolean PerformWaitCallback() : File:  Line: 0

at2k21
Posts: 17
Joined: Wed Aug 16, 2017 5:33 pm

Re: Timeout/exception on call to IOrderStore.NewOrder(OrderCreationSpec)

Post by at2k21 » Wed Jun 13, 2018 1:02 pm

As luck would have it I found this matching error on the server.

Code: Select all

Work task failed. Error: One or more errors occurred.
Stack Trace: 

***********************************************************************************
Error: Execution Timeout Expired.  The timeout period elapsed prior to completion of the operation or the server is not responding.
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)
   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 System.Data.SqlClient.SqlCommandSet.ExecuteNonQuery()
   at SoftPro.OrderTracking.Persistence.Orders.OrderObjectContext.SaveOrder(IRootEntity rootEntity, Int32 rootId)
   at SoftPro.OrderTracking.Persistence.Orders.OrdersDataContext.SaveNormalizedOrder(IOrder order, OrderInfo info)
   at SoftPro.OrderTracking.Persistence.Orders.OrdersDataContext.SoftPro.OrderTracking.Server.Orders.IOrdersDataContext.SaveOrder(IOrder order, Dictionary`2 attributes, Dictionary`2 attachments)
   at SoftPro.PersistenceModel.DeadlockDetectionAspect.SoftPro.ServerModel.Aspects.IAspect.Process(Action method)
   at SoftPro.PersistenceModel.UniqueConstraintViolationAspect.SoftPro.ServerModel.Aspects.IAspect.Process(Action method)
   at SoftPro.PersistenceModel.StaleObjectStateExceptionAspect.SoftPro.ServerModel.Aspects.IAspect.Process(Action method)
   at SoftPro.OrderTracking.Server.Orders.OrderStore.SaveOrder(IOrder order, Dictionary`2 attributes, Dictionary`2 attachments)
   at SoftPro.OrderTracking.Server.Orders.OrderStore.ApplyChangesInternal(OrderIdentifier id, Func`1 orderCallback, Func`1 previousOrderCallback, Boolean remoteCall, Dictionary`2 attributes, Dictionary`2& attachments, IOrder& order, Watermark& watermark)
   at SoftPro.OrderTracking.Server.Orders.OrderStore.SoftPro.OrderTracking.Client.Orders.IOrderStore.ApplyChanges(IOrder order)
   at SoftPro.OrderTracking.Server.Orders.OrderStoreService.<>c__DisplayClass17_0.<CreateOrder>b__0(IProgress`1 p, CancellationToken c)
   at SoftPro.Select.Server.Runtime.ServerTaskFactory.<>c__DisplayClass12_0`1.<StartNew>b__0(Object s)
   at System.Threading.Tasks.Task`1.InnerInvoke()
   at System.Threading.Tasks.Task.Execute()
***********************************************************************************
Error: The wait operation timed out
Stack Trace: 

BobRichards
Posts: 1006
Joined: Wed Jan 15, 2014 3:50 pm
Location: Raleigh, NC
Contact:

Re: Timeout/exception on call to IOrderStore.NewOrder(OrderCreationSpec)

Post by BobRichards » Wed Jun 13, 2018 2:03 pm

This is a known bug associated with the mid-tier and has to do with rare circumstances. When the client requests a new order, the request is passed to the mid-tier for processing. A communication thread watches for the completion and when it determines the order is ready, it looks in the session table to send the reply to the initiator (client). The bug is that it is possible for the session table to be corrupted momentarily and then when the comm thread wants to send the response to the client, it can't figure out which one to send it to. This causes the client wait until the WCF connection times out.

If the user creates a standalone client and repeatedly creates new sessions for a short period then closes the session and get a new one, we see this type of thing happen more often. Are you creating lots of new connections to the mid-tier for brief intervals? If so, try reusing the same SelectServer instance.

That being said, the bug is fixed and in testing. It should ship in the July-Aug time frame. It is our bug number 458552 if you want to check back later this summer to determine if it has been shipped.
Bob Richards, Software Developer, SoftPro

at2k21
Posts: 17
Joined: Wed Aug 16, 2017 5:33 pm

Re: Timeout/exception on call to IOrderStore.NewOrder(OrderCreationSpec)

Post by at2k21 » Wed Jun 13, 2018 5:49 pm

Bob,

Thank you for the update. I ran a test changing my code to use a single instance of the SelectServer object and that caused every NewOrder call to fail after one failed.

Post Reply