Tracking down pesky sql lock timeout issues

Hello!

We are intermittently seeing these sorts of lockouts:

System.Data.Entity.Core.EntityCommandExecutionException: An error occurred while reading from the store provider’s data reader. See the inner exception for details. —> System.Data.SqlClient.SqlException: Lock request time out period exceeded.
at System.Data.SqlClient.SqlConnection.OnError(SqlException exception, Boolean breakConnection, Action1 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.SqlDataReader.TryHasMoreRows(Boolean& moreRows) at System.Data.SqlClient.SqlDataReader.TryReadInternal(Boolean setTimeout, Boolean& more) at System.Data.SqlClient.SqlDataReader.Read() at System.Data.Entity.Core.Common.Internal.Materialization.Shaper1.StoreRead()
— End of inner exception stack trace —
at System.Data.Entity.Core.Common.Internal.Materialization.Shaper1.HandleReaderException(Exception e) at System.Data.Entity.Core.Common.Internal.Materialization.Shaper1.StoreRead()
at System.Data.Entity.Core.Common.Internal.Materialization.Shaper1.SimpleEnumerator.MoveNext() at System.Linq.Enumerable.FirstOrDefault[TSource](IEnumerable1 source)
at System.Data.Entity.Core.Objects.CompiledQuery.ExecuteQuery[TResult](ObjectContext context, Object[] parameterValues)
at System.Data.Entity.Core.Objects.CompiledQuery.Invoke[TArg0,TArg1,TResult](TArg0 arg0, TArg1 arg1)
at Epicor.Data.DBExpressionCompiler.<>c__DisplayClass33_13.<Compile>b__3(TContext c, Func3 query) in C:_Releases\ICE\ICE3.2.300.15\Source\Framework\Epicor.System\Data\DBExpressionCompiler.Generated.cs:line 1089
at Epicor.Data.DBExpressionCompiler.GetResult[TContext,TQuery,TResult](Func3 executeQuery, Cache cacheSetting, TContext dataContext, TQuery query) in C:\_Releases\ICE\ICE3.2.300.15\Source\Framework\Epicor.System\Data\DBExpressionCompiler.cs:line 445 at Epicor.Data.DBExpressionCompiler.InvokeSingle[TContext,TQuery,TResult](Expression expression, Cache currentCacheSetting, Boolean cacheQuery, TContext dataContext, Func2 getDataCacheKey, Func2 compileQuery, Func3 executeQuery) in C:_Releases\ICE\ICE3.2.300.15\Source\Framework\Epicor.System\Data\DBExpressionCompiler.cs:line 306
at Epicor.Data.DBExpressionCompiler.<>c__DisplayClass33_03.<Compile>b__0(TContext context, TArg1 arg1) in C:\_Releases\ICE\ICE3.2.300.15\Source\Framework\Epicor.System\Data\DBExpressionCompiler.Generated.cs:line 1082 at Erp.Tables.OrderRel.FindFirstBySysRowIDWithUpdLock(ErpContext dataContext, Guid sysRowID) in C:\_projects\ERP\RL10.2.300.0\Source\Server\Db\Erp.Data.910100\ErpContext.Model.cs:line 1597973 at Erp.Services.BO.SalesOrderSvc.GetDBRowWithUpdLock(Int32 tableNumber, Guid rowID) in C:\_Releases\ERP\UD10.2.300.15\Source\Server\Services\BO\SalesOrder\SalesOrder.Designer.cs:line 420 at Ice.TablesetBound3.UpdateRow(IceDataContext dataContext, Int32 tableNum, IIceTable table, IceRow updatedRow, IceRow originalRow, IColumnUncensor uncensor, TablesetProfilingCollector parentTraceCollector) in C:_Releases\ICE\ICE3.2.300.15\Source\Framework\Epicor.Ice\Services\TablesetBound.cs:line 1246
at Ice.TablesetBound3.WriteTable(IceDataContext dataContext, Int32 tableIndex, IIceTable table, TablesetProfilingCollector parentTraceCollector) in C:\_Releases\ICE\ICE3.2.300.15\Source\Framework\Epicor.Ice\Services\TablesetBound.cs:line 974 at Ice.TablesetBound3.InnerUpdate[TUpdater](IceDataContext dataContext, TFullTableset tableset) in C:_Releases\ICE\ICE3.2.300.15\Source\Framework\Epicor.Ice\Services\TablesetBound.cs:line 866
at Erp.Services.BO.SalesOrderSvc.Update(SalesOrderTableset& ds) in C:_Releases\ERP\UD10.2.300.15\Source\Server\Services\BO\SalesOrder\SalesOrder.Designer.cs:line 3898
at Epicor.Customization.Bpm.MethodCustomizationBase23.RunDirectives(TParam parameters) in C:\_Releases\ICE\ICE3.2.300.15\Source\Server\Internal\Lib\Epicor.Customization.BPM\MethodCustomizationBase2.cs:line 197 at Epicor.Customization.Bpm.CustomizationBase23.Execute(TParam parameters) in C:_Releases\ICE\ICE3.2.300.15\Source\Server\Internal\Lib\Epicor.Customization.BPM\CustomizationBase2.cs:line 73
at Epicor.Customization.Bpm.BO50B63956D3AF4C44970D4E5949F9D4D6.SalesOrderSvcCustomization.Update(SalesOrderTableset& ds)
at Erp.Services.BO.SalesOrderSvcFacade.Update(SalesOrderTableset& ds) in C:_Releases\ERP\UD10.2.300.15\Source\Server\Services\BO\SalesOrder\SalesOrderSvcFacade.cs:line 9195
at Ice.TablesetBound`3.CallUpdate(Object serviceObject, TFullTableset& workingTs, BOUpdErrorTableset errors, IceRow originalParentRecord) in C:_Releases\ICE\ICE3.2.300.15\Source\Framework\Epicor.Ice\Services\TablesetBound.UpdateExt.cs:line 1333’


I’d like to make sure it is not a BPM that would be causing the lock…how can I go about matching the ID given in the error to the bpm id?

Epicor.Customization.Bpm.BO50B63956D3AF4C44970D4E5949F9D4D6.SalesOrderSvcCustomization.Update(SalesOrderTableset& ds)

Looks like from that code it is a BPM on the SalesOrder.Update method. This query should help you identify the name of the BPM.

If you have your hands tied because you’re a cloud user, you should be able to do the same query in a BAQ… maybe.

select DirectiveID, SysRowID, [Name], [Order]
from Ice.BpDirective
where BpMethodCode = 'Erp.SalesOrder.Update'
order by BpMethodCode

Thanks Mark! However, none of the ID’s match to what the error shows:
image

OK - I found something that looks more like the ID you posted.

C:\inetpub\wwwroot\ERP102300AppName\Server\BPM\Sources\BO\SalesOrder.Update\1.2019.05.30.17.51.07

This is a folder on your Epicor App server - the last bit will differ on your system, but look in the latest folder.

In the folder are the .cs files relating to the built code. Inside the file, the name space shows:

namespace Epicor.Customization.Bpm.BO10DD849F96514ADDA9857C1A9D126322

You could also try and look at what each BPM is actually doing, based on the error it seems to be trying to lock OrderRel.