System Task fails with timeout for scheduled Epicor Function

carlosqt · July 10, 2023, 4:09pm

Hi Everyone,

I migrated a bpm directive from a standard data directive (custom code) to an Epicor Function. Both take around 2 hours to complete, but when this function is called from a BPM data directive it runs and completes successfully, however, if I run this Function via Scheduled Epicor Function, it goes into System Monitor as an scheduled task and after few seconds fails with a Timeout exception.

I have tested:

If custom code executes as a BPM std data directive, it completes successfully (~2 hrs)
If custom code runs as an Epicor Function called from a BPM std data directive, it completes successfully (~2 hrs)
If the Epicor Function is scheduled and run through System Agent, it fails with timeout.

I assume the timeout settings on the appserver host.config file is not the same used by the System Agent. Epicor version is 2022.2.21.
Can anyone point out where can this timeout limit be changed/increased? @Olga , @josecgomez @timshuwy ?

Application Error
Exception caught in: Epicor.ServiceModel

Error Detail

Message: Timeout expired. The timeout period elapsed prior to obtaining a connection from the pool.
This may have occurred because all pooled connections were in use and max pool size was reached.

Program: Epicor.ServiceModel.dll
Method: CallWithCommunicationFailureRetry

Client Stack Trace

at Ice.Cloud.ProxyBase1.CallWithCommunicationFailureRetry(String methodName, ProxyValuesIn valuesIn, ProxyValuesOut valuesOut, RestRpcValueSerializer serializer) at Ice.Cloud.ProxyBase1.CallWithMultistepBpmHandling(String methodName, ProxyValuesIn valuesIn, ProxyValuesOut valuesOut, Boolean useSparseCopy)
at Ice.Cloud.ProxyBase`1.Call(String methodName, ProxyValuesIn valuesIn, ProxyValuesOut valuesOut, Boolean useSparseCopy)
at Ice.Proxy.BO.ReportMonitorImpl.GetRowsKeepIdleTimeWithBallonInfo(String whereClauseSysRptLst, Boolean getBallonInfo, String whereClauseSysTask, String whereClauseSysTaskLog, DataSet& sysMonitorData)
at Ice.Adapters.ReportMonitorAdapter.GetRowsKeepIdleTimeWithBallonInfo(SearchOptions opts, Boolean getBallonInfo, SysMonitorTasksDataSet& sysMonitorData)

Executing library ‘LIBRARYID’ function ‘FunctionName’
“AppServerName”:
An error occurred trying to run task ID 81098 for agent “SystemTaskAgent”
on the application server (User: “username”, Task Description: “Run Epicor Function”).

Error details:
Ice.Common.BusinessObjectException:
Program Ice.Services.Lib.RunTask when executing task 81098 raised an unexpected exception with the following message: RunTask:
System.Data.Entity.Core.EntityException: The underlying provider failed on Open.
—> System.InvalidOperationException: Timeout expired. The timeout period elapsed prior to obtaining a connection from the pool. This may have occurred because all pooled connections were in use and max pool size was reached.
at System.Data.ProviderBase.DbConnectionFactory.TryGetConnection(DbConnection owningConnection, TaskCompletionSource1 retry, DbConnectionOptions userOptions, DbConnectionInternal oldConnection, DbConnectionInternal& connection) at System.Data.ProviderBase.DbConnectionInternal.TryOpenConnectionInternal(DbConnection outerConnection, DbConnectionFactory connectionFactory, TaskCompletionSource1 retry, DbConnectionOptions userOptions)
at System.Data.SqlClient.SqlConnection.TryOpen(TaskCompletionSource1 retry) at System.Data.SqlClient.SqlConnection.Open() at Epicor.Data.Provider.EpiConnection.Open() in C:\_releases\ICE\ICE4.2.200.21\Source\Server\Framework\Epicor.System\Data\EpiProvider2\EpiConnection.cs:line 241 at System.Data.Entity.Infrastructure.Interception.InternalDispatcher1.Dispatch[TTarget,TInterceptionContext](TTarget target, Action2 operation, TInterceptionContext interceptionContext, Action3 executing, Action`3 executed)
at System.Data.Entity.Infrastructure.Interception.DbConnectionDispatcher.Open(DbConnection connection, DbInterceptionContext interceptionContext)
at System.Data.Entity.Core.EntityClient.EntityConnection.Open()
— End of inner exception stack trace —

The Task Agent is setup with the defaults:
Operation Timeout is set to 24 hrs

Thanks

Olga · July 10, 2023, 4:24pm

Technically, the timeout shown does not have anything with functions or tasks. It is timeout for database connection open. Do you use same app pool for user access and task agent?

carlosqt · July 10, 2023, 4:33pm

Hi Olga,
Yes, I believe so. It’s a single App Server url for the client and for the task agent.

klincecum · July 10, 2023, 5:09pm

This is interesting. The issue shouldn’t be a timeout related to running from the scheduler itself. I have some that run that way.

I wonder what’s different here?

Olga · July 10, 2023, 5:46pm

What is the full exception stack in server side event viewer?

carlosqt · July 11, 2023, 9:23am

@Olga below the 3 category of logs taken from the server

Windows Logs > Application:

All these events in the event log show the same exception message.

RequestPath: /SERVERNAME/api/rpc/Ice.BO.SysAgent/GetByIdForTaskAgent
RequestPath: /SERVERNAME/api/rpc/Ice.BO.ReportMonitor/GetRowsKeepIdleTimeWithBallonInfo
RequestPath: /SERVERNAME/api/rpc/Ice.Lib.RunTask/RunSystemTasks
RequestPath: /SERVERNAME/api/rpc/Ice.BO.ReportMonitor/GetRowsKeepIdleTimeWithBallonInfo
RequestPath: /SERVERNAME/api/rpc/Ice.BO.SysAgent/PurgeTaskHistory
RequestPath: /SERVERNAME/api/rpc/Ice.BO.ReportMonitor/GetRowsKeepIdleTimeWithBallonInfo
RequestPath: /SERVERNAME/api/rpc/Ice.BO.SysAgent/GetByIdForTaskAgent

Category: Microsoft.AspNetCore.Diagnostics.ExceptionHandlerMiddleware
EventId: 1
SpanId: 62ac0f203edfbd40
TraceId: 54eeb74b626eb57fc0e7121b0a26b083
ParentId: 0000000000000000
RequestId: 80004b75-0004-ec00-b63f-84710c7967bb
RequestPath: /SERVERNAME/api/rpc/Ice.BO.SysAgent/GetByIdForTaskAgent

An unhandled exception has occurred while executing the request.

Exception: 
System.InvalidOperationException: Timeout expired.  The timeout period elapsed prior to obtaining a connection from the pool.  This may have occurred because all pooled connections were in use and max pool size was reached.
   at System.Data.ProviderBase.DbConnectionFactory.TryGetConnection(DbConnection owningConnection, TaskCompletionSource`1 retry, DbConnectionOptions userOptions, DbConnectionInternal oldConnection, DbConnectionInternal& connection)
   at System.Data.ProviderBase.DbConnectionInternal.TryOpenConnectionInternal(DbConnection outerConnection, DbConnectionFactory connectionFactory, TaskCompletionSource`1 retry, DbConnectionOptions userOptions)
   at System.Data.SqlClient.SqlConnection.TryOpen(TaskCompletionSource`1 retry)
   at System.Data.SqlClient.SqlConnection.Open()
   at Epicor.Data.Database.CreateConnection(Boolean open) in C:\_releases\ICE\ICE4.2.200.21\Source\Server\Framework\Epicor.System\Data\Database.cs:line 48
   at Epicor.AppServerNotification.DatabaseNotification.InnerBroadcast() in C:\_releases\ICE\ICE4.2.200.21\Source\Server\Framework\Epicor.System\AppServerNotification\DatabaseNotification.cs:line 51
   at Epicor.AppServerNotification.DatabaseNotification.Broadcast() in C:\_releases\ICE\ICE4.2.200.21\Source\Server\Framework\Epicor.System\AppServerNotification\DatabaseNotification.cs:line 44
   at Epicor.Hosting.CallContext.Create(Operation op, UserFileItem user, ISessionBuilder sessionBuilder) in C:\_releases\ICE\ICE4.2.200.21\Source\Server\Framework\Epicor.Ice\Hosting\CallContext.cs:line 132
   at Ice.Security.AuthenticationHelper.CheckAccess(String authorizationScheme, String authorizationValue, IEnumerable`1 headers, String clientAddress, String action, Boolean isRpcCall) in C:\_releases\ICE\ICE4.2.200.21\Source\Server\Framework\Epicor.Ice\Security\AuthenticationHelper.cs:line 56
   at Ice.Hosting.AspNetCore.Middleware.AuthorizationMiddleware.Invoke(HttpContext context, CurrentCallInformationService currentCallInformation) in C:\_releases\ICE\ICE4.2.200.21\Source\Server\Hosting\AspNetCore\Ice.Hosting.AspNetCore\Middleware\AuthorizationMiddleware.cs:line 44
   at Ice.Hosting.AspNetCore.ETags.ETagMiddleware.Invoke(HttpContext httpContext) in C:\_releases\ICE\ICE4.2.200.21\Source\Server\Hosting\AspNetCore\Ice.Hosting.AspNetCore\ETags\ETagMiddleware.cs:line 110
   at Ice.Hosting.AspNetCore.ETags.ETagMiddleware.Invoke(HttpContext httpContext) in C:\_releases\ICE\ICE4.2.200.21\Source\Server\Hosting\AspNetCore\Ice.Hosting.AspNetCore\ETags\ETagMiddleware.cs:line 110
   at Ice.Hosting.AspNetCore.Middleware.DecompressRequestMiddleware.Invoke(HttpContext context) in C:\_releases\ICE\ICE4.2.200.21\Source\Server\Hosting\AspNetCore\Ice.Hosting.AspNetCore\Middleware\DecompressRequestMiddleware.cs:line 42
   at Epicor.RESTApi.Middleware.ApiKeyEnforcerMiddleware.Invoke(HttpContext context) in C:\_releases\ICE\ICE4.2.200.21\Source\Server\Hosting\AspNetCore\Ice.Hosting.AspNetCore\Middleware\ApiKeyEnforcerMiddleware.cs:line 79
   at Microsoft.AspNetCore.Diagnostics.ExceptionHandlerMiddleware.<Invoke>g__Awaited|6_0(ExceptionHandlerMiddleware middleware, HttpContext context, Task task)


Category: Microsoft.AspNetCore.Diagnostics.ExceptionHandlerMiddleware
EventId: 1
SpanId: ed2a3b68b8d38811
TraceId: 21aeeb534096de830c94a0cb5d8fb4cb
ParentId: 0000000000000000
RequestId: 8000389b-0004-e500-b63f-84710c7967bb
RequestPath: /SERVERNAME/api/rpc/Ice.Lib.RunTask/RunSystemTasks

An unhandled exception has occurred while executing the request.

Exception: 
System.Data.Entity.Core.EntityException: The underlying provider failed on Open.
 ---> System.InvalidOperationException: Timeout expired.  The timeout period elapsed prior to obtaining a connection from the pool.  This may have occurred because all pooled connections were in use and max pool size was reached.
   at System.Data.ProviderBase.DbConnectionFactory.TryGetConnection(DbConnection owningConnection, TaskCompletionSource`1 retry, DbConnectionOptions userOptions, DbConnectionInternal oldConnection, DbConnectionInternal& connection)
   at System.Data.ProviderBase.DbConnectionInternal.TryOpenConnectionInternal(DbConnection outerConnection, DbConnectionFactory connectionFactory, TaskCompletionSource`1 retry, DbConnectionOptions userOptions)
   at System.Data.SqlClient.SqlConnection.TryOpen(TaskCompletionSource`1 retry)
   at System.Data.SqlClient.SqlConnection.Open()
   at Epicor.Data.Provider.EpiConnection.Open() in C:\_releases\ICE\ICE4.2.200.21\Source\Server\Framework\Epicor.System\Data\EpiProvider2\EpiConnection.cs:line 241
   at System.Data.Entity.Infrastructure.Interception.InternalDispatcher`1.Dispatch[TTarget,TInterceptionContext](TTarget target, Action`2 operation, TInterceptionContext interceptionContext, Action`3 executing, Action`3 executed)
   at System.Data.Entity.Infrastructure.Interception.DbConnectionDispatcher.Open(DbConnection connection, DbInterceptionContext interceptionContext)
   at System.Data.Entity.Core.EntityClient.EntityConnection.Open()
   --- End of inner exception stack trace ---
   at System.Data.Entity.Core.EntityClient.EntityConnection.Open()
   at Ice.Services.ContextFactory.CreateContext() in C:\_releases\ICE\ICE4.2.200.21\Source\Server\Framework\Epicor.System\Services\ContextFactory.cs:line 70
   at Ice.Services.ContextFactory.CreateContext[TDataContext]() in C:\_releases\ICE\ICE4.2.200.21\Source\Server\Framework\Epicor.System\Services\ContextFactory.cs:line 39
   at Epicor.Hosting.CallContext.CreateSession(Operation op, UserFileItem user, ISessionBuilder sessionBuilder, String companyId) in C:\_releases\ICE\ICE4.2.200.21\Source\Server\Framework\Epicor.Ice\Hosting\CallContext.cs:line 237
   at Epicor.Hosting.CallContext.Create(Operation op, UserFileItem user, ISessionBuilder sessionBuilder) in C:\_releases\ICE\ICE4.2.200.21\Source\Server\Framework\Epicor.Ice\Hosting\CallContext.cs:line 132
   at Ice.Security.AuthenticationHelper.CheckAccess(String authorizationScheme, String authorizationValue, IEnumerable`1 headers, String clientAddress, String action, Boolean isRpcCall) in C:\_releases\ICE\ICE4.2.200.21\Source\Server\Framework\Epicor.Ice\Security\AuthenticationHelper.cs:line 56
   at Ice.Hosting.AspNetCore.Middleware.AuthorizationMiddleware.Invoke(HttpContext context, CurrentCallInformationService currentCallInformation) in C:\_releases\ICE\ICE4.2.200.21\Source\Server\Hosting\AspNetCore\Ice.Hosting.AspNetCore\Middleware\AuthorizationMiddleware.cs:line 44
   at Ice.Hosting.AspNetCore.ETags.ETagMiddleware.Invoke(HttpContext httpContext) in C:\_releases\ICE\ICE4.2.200.21\Source\Server\Hosting\AspNetCore\Ice.Hosting.AspNetCore\ETags\ETagMiddleware.cs:line 110
   at Ice.Hosting.AspNetCore.ETags.ETagMiddleware.Invoke(HttpContext httpContext) in C:\_releases\ICE\ICE4.2.200.21\Source\Server\Hosting\AspNetCore\Ice.Hosting.AspNetCore\ETags\ETagMiddleware.cs:line 110
   at Ice.Hosting.AspNetCore.Middleware.DecompressRequestMiddleware.Invoke(HttpContext context) in C:\_releases\ICE\ICE4.2.200.21\Source\Server\Hosting\AspNetCore\Ice.Hosting.AspNetCore\Middleware\DecompressRequestMiddleware.cs:line 42
   at Epicor.RESTApi.Middleware.ApiKeyEnforcerMiddleware.Invoke(HttpContext context) in C:\_releases\ICE\ICE4.2.200.21\Source\Server\Hosting\AspNetCore\Ice.Hosting.AspNetCore\Middleware\ApiKeyEnforcerMiddleware.cs:line 79
   at Microsoft.AspNetCore.Diagnostics.ExceptionHandlerMiddleware.<Invoke>g__Awaited|6_0(ExceptionHandlerMiddleware middleware, HttpContext context, Task task)

Applications and Services Logs > Epicor App Server:

Ice.Common.EpicorServerException: Timeout expired.  The timeout period elapsed prior to obtaining a connection from the pool.  This may have occurred because all pooled connections were in use and max pool size was reached.
 ---> System.InvalidOperationException: Timeout expired.  The timeout period elapsed prior to obtaining a connection from the pool.  This may have occurred because all pooled connections were in use and max pool size was reached.
   at System.Data.ProviderBase.DbConnectionFactory.TryGetConnection(DbConnection owningConnection, TaskCompletionSource`1 retry, DbConnectionOptions userOptions, DbConnectionInternal oldConnection, DbConnectionInternal& connection)
   at System.Data.ProviderBase.DbConnectionInternal.TryOpenConnectionInternal(DbConnection outerConnection, DbConnectionFactory connectionFactory, TaskCompletionSource`1 retry, DbConnectionOptions userOptions)
   at System.Data.SqlClient.SqlConnection.TryOpen(TaskCompletionSource`1 retry)
   at System.Data.SqlClient.SqlConnection.Open()
   at Epicor.Data.Database.CreateConnection(Boolean open) in C:\_releases\ICE\ICE4.2.200.21\Source\Server\Framework\Epicor.System\Data\Database.cs:line 48
   at Epicor.AppServerNotification.DatabaseNotification.InnerBroadcast() in C:\_releases\ICE\ICE4.2.200.21\Source\Server\Framework\Epicor.System\AppServerNotification\DatabaseNotification.cs:line 51
   at Epicor.AppServerNotification.DatabaseNotification.Broadcast() in C:\_releases\ICE\ICE4.2.200.21\Source\Server\Framework\Epicor.System\AppServerNotification\DatabaseNotification.cs:line 44
   at Epicor.Hosting.CallContext.Create(Operation op, UserFileItem user, ISessionBuilder sessionBuilder) in C:\_releases\ICE\ICE4.2.200.21\Source\Server\Framework\Epicor.Ice\Hosting\CallContext.cs:line 132
   at Ice.Security.AuthenticationHelper.CheckAccess(String authorizationScheme, String authorizationValue, IEnumerable`1 headers, String clientAddress, String action, Boolean isRpcCall) in C:\_releases\ICE\ICE4.2.200.21\Source\Server\Framework\Epicor.Ice\Security\AuthenticationHelper.cs:line 56
   at Ice.Hosting.AspNetCore.Middleware.AuthorizationMiddleware.Invoke(HttpContext context, CurrentCallInformationService currentCallInformation) in C:\_releases\ICE\ICE4.2.200.21\Source\Server\Hosting\AspNetCore\Ice.Hosting.AspNetCore\Middleware\AuthorizationMiddleware.cs:line 44
   at Ice.Hosting.AspNetCore.ETags.ETagMiddleware.Invoke(HttpContext httpContext) in C:\_releases\ICE\ICE4.2.200.21\Source\Server\Hosting\AspNetCore\Ice.Hosting.AspNetCore\ETags\ETagMiddleware.cs:line 110
   at Ice.Hosting.AspNetCore.ETags.ETagMiddleware.Invoke(HttpContext httpContext) in C:\_releases\ICE\ICE4.2.200.21\Source\Server\Hosting\AspNetCore\Ice.Hosting.AspNetCore\ETags\ETagMiddleware.cs:line 110
   at Ice.Hosting.AspNetCore.Middleware.DecompressRequestMiddleware.Invoke(HttpContext context) in C:\_releases\ICE\ICE4.2.200.21\Source\Server\Hosting\AspNetCore\Ice.Hosting.AspNetCore\Middleware\DecompressRequestMiddleware.cs:line 42
   at Epicor.RESTApi.Middleware.ApiKeyEnforcerMiddleware.Invoke(HttpContext context) in C:\_releases\ICE\ICE4.2.200.21\Source\Server\Hosting\AspNetCore\Ice.Hosting.AspNetCore\Middleware\ApiKeyEnforcerMiddleware.cs:line 79
   at Microsoft.AspNetCore.Diagnostics.ExceptionHandlerMiddleware.<Invoke>g__Awaited|6_0(ExceptionHandlerMiddleware middleware, HttpContext context, Task task)
   --- End of inner exception stack trace ---


Ice.Common.EpicorServerException: The underlying provider failed on Open.
 ---> System.Data.Entity.Core.EntityException: The underlying provider failed on Open.
 ---> System.InvalidOperationException: Timeout expired.  The timeout period elapsed prior to obtaining a connection from the pool.  This may have occurred because all pooled connections were in use and max pool size was reached.
   at System.Data.ProviderBase.DbConnectionFactory.TryGetConnection(DbConnection owningConnection, TaskCompletionSource`1 retry, DbConnectionOptions userOptions, DbConnectionInternal oldConnection, DbConnectionInternal& connection)
   at System.Data.ProviderBase.DbConnectionInternal.TryOpenConnectionInternal(DbConnection outerConnection, DbConnectionFactory connectionFactory, TaskCompletionSource`1 retry, DbConnectionOptions userOptions)
   at System.Data.SqlClient.SqlConnection.TryOpen(TaskCompletionSource`1 retry)
   at System.Data.SqlClient.SqlConnection.Open()
   at Epicor.Data.Provider.EpiConnection.Open() in C:\_releases\ICE\ICE4.2.200.21\Source\Server\Framework\Epicor.System\Data\EpiProvider2\EpiConnection.cs:line 241
   at System.Data.Entity.Infrastructure.Interception.InternalDispatcher`1.Dispatch[TTarget,TInterceptionContext](TTarget target, Action`2 operation, TInterceptionContext interceptionContext, Action`3 executing, Action`3 executed)
   at System.Data.Entity.Infrastructure.Interception.DbConnectionDispatcher.Open(DbConnection connection, DbInterceptionContext interceptionContext)
   at System.Data.Entity.Core.EntityClient.EntityConnection.Open()
   --- End of inner exception stack trace ---
   at System.Data.Entity.Core.EntityClient.EntityConnection.Open()
   at Ice.Services.ContextFactory.CreateContext() in C:\_releases\ICE\ICE4.2.200.21\Source\Server\Framework\Epicor.System\Services\ContextFactory.cs:line 70
   at Ice.Services.ContextFactory.CreateContext[TDataContext]() in C:\_releases\ICE\ICE4.2.200.21\Source\Server\Framework\Epicor.System\Services\ContextFactory.cs:line 39
   at Ice.Services.Lib.RunTaskSvc.SetTaskStatus(String status, Int64 taskNumber, Boolean clearActivityMessage, Boolean isAPRTask) in C:\_releases\ICE\ICE4.2.200.0\Source\Server\Services\Lib\RunTask\RunTask.cs:line 805
   at Ice.Services.Lib.RunTaskSvc.InnerRunTask(Int64 ipTaskNum, Boolean suppressTransaction) in C:\_releases\ICE\ICE4.2.200.0\Source\Server\Services\Lib\RunTask\RunTask.cs:line 540
   at Ice.Services.Lib.RunTaskSvc.RunTask(Int64 ipTaskNum) in C:\_releases\ICE\ICE4.2.200.0\Source\Server\Services\Lib\RunTask\RunTask.cs:line 328
   at Ice.Services.Lib.RunTaskSvcFacade.RunTask(Int64 ipTaskNum) in C:\_releases\ICE\ICE4.2.200.0\Source\Server\Services\Lib\RunTask\RunTaskSvcFacade.cs:line 165
   at Microsoft.Extensions.Internal.ObjectMethodExecutor.<>c__DisplayClass33_0.<WrapVoidMethod>b__0(Object target, Object[] parameters)
   at Microsoft.AspNetCore.Mvc.Infrastructure.ActionMethodExecutor.VoidResultExecutor.Execute(IActionResultTypeMapper mapper, ObjectMethodExecutor executor, Object controller, Object[] arguments)
   at Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker.InvokeActionMethodAsync()
   at Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker.Next(State& next, Scope& scope, Object& state, Boolean& isCompleted)
   at Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker.InvokeNextActionFilterAsync()
   --- End of inner exception stack trace ---

Applications and Services Logs > Epicor ICE Task Agent Service:

"SERVERNAME": Agent "SystemTaskAgent" completed with the following error:
Error details:
System.InvalidOperationException: Timeout expired.  The timeout period elapsed prior to obtaining a connection from the pool.  This may have occurred because all pooled connections were in use and max pool size was reached.
   at Ice.Cloud.ProxyBase`1.CallWithCommunicationFailureRetry(String methodName, ProxyValuesIn valuesIn, ProxyValuesOut valuesOut, RestRpcValueSerializer serializer) in C:\_releases\ICE\ICE4.2.200.0\Source\Shared\Framework\Epicor.ServiceModel\Cloud\ProxyBase.cs:line 725
   at Ice.Cloud.ProxyBase`1.CallWithMultistepBpmHandling(String methodName, ProxyValuesIn valuesIn, ProxyValuesOut valuesOut, Boolean useSparseCopy) in C:\_releases\ICE\ICE4.2.200.0\Source\Shared\Framework\Epicor.ServiceModel\Cloud\ProxyBase.cs:line 670
   at Ice.Cloud.ProxyBase`1.Call(String methodName, ProxyValuesIn valuesIn, ProxyValuesOut valuesOut, Boolean useSparseCopy) in C:\_releases\ICE\ICE4.2.200.0\Source\Shared\Framework\Epicor.ServiceModel\Cloud\ProxyBase.cs:line 649
   at Ice.Proxy.BO.SysAgentImpl.GetByIdForTaskAgent(String agentID, Boolean firstPass) in C:\_releases\ICE\ICE4.2.200.0\Source\Shared\Contracts\BO\SysAgent\SysAgentProxy.cs:line 65
   at Ice.TaskAgentCore.ImplCaller.ImplCaller`1.Call[TResult](Func`2 doWork, ExceptionBehavior communicationExceptionBehavior, ExceptionBehavior timeoutExceptionBehavior)
   at Ice.TaskAgentCore.ScheduledTaskRunner.QueryAndQueueAvailableSchedules()
   at Ice.TaskAgentCore.ScheduledTaskRunner.Process()
   at Ice.TaskAgentCore.SequentialAsyncActionRunner.HandleContinuation(Task task, Action action, Action cancelAction, Action`1 exceptionAction)
   at Ice.TaskAgentCore.SequentialAsyncActionRunner.<>c__DisplayClass12_0.<RunAfterDelay>b__0(Task task)
   at System.Threading.Tasks.Task.Execute()

"SERVERNAME": An error occurred trying to call RunSystemProcess on the application server.
Error details:
Ice.Common.EpicorServerException: The underlying provider failed on Open.
   at Ice.Cloud.ProxyBase`1.CallWithCommunicationFailureRetry(String methodName, ProxyValuesIn valuesIn, ProxyValuesOut valuesOut, RestRpcValueSerializer serializer) in C:\_releases\ICE\ICE4.2.200.0\Source\Shared\Framework\Epicor.ServiceModel\Cloud\ProxyBase.cs:line 725
   at Ice.Cloud.ProxyBase`1.CallWithMultistepBpmHandling(String methodName, ProxyValuesIn valuesIn, ProxyValuesOut valuesOut, Boolean useSparseCopy) in C:\_releases\ICE\ICE4.2.200.0\Source\Shared\Framework\Epicor.ServiceModel\Cloud\ProxyBase.cs:line 670
   at Ice.Cloud.ProxyBase`1.Call(String methodName, ProxyValuesIn valuesIn, ProxyValuesOut valuesOut, Boolean useSparseCopy) in C:\_releases\ICE\ICE4.2.200.0\Source\Shared\Framework\Epicor.ServiceModel\Cloud\ProxyBase.cs:line 649
   at Ice.Proxy.Lib.RunTaskImpl.RunSystemTasks() in C:\_releases\ICE\ICE4.2.200.0\Source\Shared\Contracts\Lib\RunTask\RunTaskProxy.cs:line 49
   at Ice.TaskAgentCore.ImplCaller.RunTaskImplCaller`1.<>c__DisplayClass4_0.<Call>b__0(TImpl impl)
   at Ice.TaskAgentCore.ImplCaller.RunTaskImplCaller`1.Call[TResult](Func`2 doWork, ExceptionBehavior communicationExceptionBehavior, ExceptionBehavior timeoutExceptionBehavior, Boolean isContinuousProcessingTask)
   at Ice.TaskAgentCore.ImplCaller.RunTaskImplCaller`1.Call(Action`1 doWork, ExceptionBehavior communicationExceptionBehavior, ExceptionBehavior timeoutExceptionBehavior, Boolean isContinuousProcessingTask)
   at Ice.TaskAgentCore.ServiceCaller.RunTask_RunSystemTasks(ExceptionBehavior communicationExceptionBehavior, ExceptionBehavior timeoutExceptionBehavior)
   at Ice.TaskAgentCore.SystemTaskRunner.Process()
   at Ice.TaskAgentCore.SequentialAsyncActionRunner.HandleContinuation(Task task, Action action, Action cancelAction, Action`1 exceptionAction)
   at Ice.TaskAgentCore.SequentialAsyncActionRunner.<>c__DisplayClass12_0.<RunAfterDelay>b__0(Task task)
   at System.Threading.Tasks.Task.Execute()

"SERVERNAME": Following error occurred while purging SysTask records: 
Error details:
System.InvalidOperationException: Timeout expired.  The timeout period elapsed prior to obtaining a connection from the pool.  This may have occurred because all pooled connections were in use and max pool size was reached.
   at Ice.Cloud.ProxyBase`1.CallWithCommunicationFailureRetry(String methodName, ProxyValuesIn valuesIn, ProxyValuesOut valuesOut, RestRpcValueSerializer serializer) in C:\_releases\ICE\ICE4.2.200.0\Source\Shared\Framework\Epicor.ServiceModel\Cloud\ProxyBase.cs:line 725
   at Ice.Cloud.ProxyBase`1.CallWithMultistepBpmHandling(String methodName, ProxyValuesIn valuesIn, ProxyValuesOut valuesOut, Boolean useSparseCopy) in C:\_releases\ICE\ICE4.2.200.0\Source\Shared\Framework\Epicor.ServiceModel\Cloud\ProxyBase.cs:line 670
   at Ice.Cloud.ProxyBase`1.Call(String methodName, ProxyValuesIn valuesIn, ProxyValuesOut valuesOut, Boolean useSparseCopy) in C:\_releases\ICE\ICE4.2.200.0\Source\Shared\Framework\Epicor.ServiceModel\Cloud\ProxyBase.cs:line 649
   at Ice.Proxy.BO.SysAgentImpl.PurgeTaskHistory(Nullable`1 purgeDate) in C:\_releases\ICE\ICE4.2.200.0\Source\Shared\Contracts\BO\SysAgent\SysAgentProxy.cs:line 83
   at Ice.TaskAgentCore.ServiceCaller.<>c__DisplayClass40_0.<SysAgent_PurgeTaskHistory>b__0(SysAgentImpl impl)
   at Ice.TaskAgentCore.ImplCaller.ImplCaller`1.<>c__DisplayClass4_0.<Call>b__0(TImpl impl)
   at Ice.TaskAgentCore.ImplCaller.ImplCaller`1.Call[TResult](Func`2 doWork, ExceptionBehavior communicationExceptionBehavior, ExceptionBehavior timeoutExceptionBehavior)
   at Ice.TaskAgentCore.ImplCaller.ImplCaller`1.Call(Action`1 doWork, ExceptionBehavior communicationExceptionBehavior, ExceptionBehavior timeoutExceptionBehavior)
   at Ice.TaskAgentCore.ServiceCaller.SysAgent_PurgeTaskHistory(DateTime purgeDate, ExceptionBehavior communicationExceptionBehavior, ExceptionBehavior timeoutExceptionBehavior)
   at Ice.TaskAgentCore.TaskHistoryPurgeRunner.Process()
   at Ice.TaskAgentCore.SequentialAsyncActionRunner.HandleContinuation(Task task, Action action, Action cancelAction, Action`1 exceptionAction)
   at Ice.TaskAgentCore.SequentialAsyncActionRunner.<>c__DisplayClass12_0.<RunAfterDelay>b__0(Task task)
   at System.Threading.Tasks.Task.Execute()

"SERVERNAME": Agent "SystemTaskAgent" completed with the following error:
Error details:
Ice.Common.EpicorServerException: The underlying provider failed on Open.
   at Ice.Cloud.ProxyBase`1.CallWithCommunicationFailureRetry(String methodName, ProxyValuesIn valuesIn, ProxyValuesOut valuesOut, RestRpcValueSerializer serializer) in C:\_releases\ICE\ICE4.2.200.0\Source\Shared\Framework\Epicor.ServiceModel\Cloud\ProxyBase.cs:line 725
   at Ice.Cloud.ProxyBase`1.CallWithMultistepBpmHandling(String methodName, ProxyValuesIn valuesIn, ProxyValuesOut valuesOut, Boolean useSparseCopy) in C:\_releases\ICE\ICE4.2.200.0\Source\Shared\Framework\Epicor.ServiceModel\Cloud\ProxyBase.cs:line 670
   at Ice.Cloud.ProxyBase`1.Call(String methodName, ProxyValuesIn valuesIn, ProxyValuesOut valuesOut, Boolean useSparseCopy) in C:\_releases\ICE\ICE4.2.200.0\Source\Shared\Framework\Epicor.ServiceModel\Cloud\ProxyBase.cs:line 649
   at Ice.Proxy.BO.SysAgentImpl.GetByIdForTaskAgent(String agentID, Boolean firstPass) in C:\_releases\ICE\ICE4.2.200.0\Source\Shared\Contracts\BO\SysAgent\SysAgentProxy.cs:line 65
   at Ice.TaskAgentCore.ImplCaller.ImplCaller`1.Call[TResult](Func`2 doWork, ExceptionBehavior communicationExceptionBehavior, ExceptionBehavior timeoutExceptionBehavior)
   at Ice.TaskAgentCore.ScheduledTaskRunner.QueryAndQueueAvailableSchedules()
   at Ice.TaskAgentCore.ScheduledTaskRunner.Process()
   at Ice.TaskAgentCore.SequentialAsyncActionRunner.HandleContinuation(Task task, Action action, Action cancelAction, Action`1 exceptionAction)
   at Ice.TaskAgentCore.SequentialAsyncActionRunner.<>c__DisplayClass12_0.<RunAfterDelay>b__0(Task task)
   at System.Threading.Tasks.Task.Execute()

"SERVERNAME": The following error occurred while purging reports:
Error details:
System.InvalidOperationException: Timeout expired.  The timeout period elapsed prior to obtaining a connection from the pool.  This may have occurred because all pooled connections were in use and max pool size was reached.
   at Ice.Cloud.ProxyBase`1.CallWithCommunicationFailureRetry(String methodName, ProxyValuesIn valuesIn, ProxyValuesOut valuesOut, RestRpcValueSerializer serializer) in C:\_releases\ICE\ICE4.2.200.0\Source\Shared\Framework\Epicor.ServiceModel\Cloud\ProxyBase.cs:line 725
   at Ice.Cloud.ProxyBase`1.CallWithMultistepBpmHandling(String methodName, ProxyValuesIn valuesIn, ProxyValuesOut valuesOut, Boolean useSparseCopy) in C:\_releases\ICE\ICE4.2.200.0\Source\Shared\Framework\Epicor.ServiceModel\Cloud\ProxyBase.cs:line 670
   at Ice.Cloud.ProxyBase`1.Call(String methodName, ProxyValuesIn valuesIn, ProxyValuesOut valuesOut, Boolean useSparseCopy) in C:\_releases\ICE\ICE4.2.200.0\Source\Shared\Framework\Epicor.ServiceModel\Cloud\ProxyBase.cs:line 649
   at Ice.Proxy.BO.SysAgentImpl.PurgeReports(Nullable`1 purgeDate) in C:\_releases\ICE\ICE4.2.200.0\Source\Shared\Contracts\BO\SysAgent\SysAgentProxy.cs:line 90
   at Ice.TaskAgentCore.ServiceCaller.<>c__DisplayClass39_0.<SysAgent_PurgeReports>b__0(SysAgentImpl impl)
   at Ice.TaskAgentCore.ImplCaller.ImplCaller`1.<>c__DisplayClass4_0.<Call>b__0(TImpl impl)
   at Ice.TaskAgentCore.ImplCaller.ImplCaller`1.Call[TResult](Func`2 doWork, ExceptionBehavior communicationExceptionBehavior, ExceptionBehavior timeoutExceptionBehavior)
   at Ice.TaskAgentCore.ImplCaller.ImplCaller`1.Call(Action`1 doWork, ExceptionBehavior communicationExceptionBehavior, ExceptionBehavior timeoutExceptionBehavior)
   at Ice.TaskAgentCore.ServiceCaller.SysAgent_PurgeReports(DateTime purgeDate, ExceptionBehavior communicationExceptionBehavior, ExceptionBehavior timeoutExceptionBehavior)
   at Ice.TaskAgentCore.ReportPurgeRunner.Process()
   at Ice.TaskAgentCore.SequentialAsyncActionRunner.HandleContinuation(Task task, Action action, Action cancelAction, Action`1 exceptionAction)
   at Ice.TaskAgentCore.SequentialAsyncActionRunner.<>c__DisplayClass12_0.<RunAfterDelay>b__0(Task task)
   at System.Threading.Tasks.Task.Execute()

"SERVERNAME": Agent "SystemTaskAgent" completed with the following error:
Error details:
Ice.Common.EpicorServerException: The underlying provider failed on Open.
   at Ice.Cloud.ProxyBase`1.CallWithCommunicationFailureRetry(String methodName, ProxyValuesIn valuesIn, ProxyValuesOut valuesOut, RestRpcValueSerializer serializer) in C:\_releases\ICE\ICE4.2.200.0\Source\Shared\Framework\Epicor.ServiceModel\Cloud\ProxyBase.cs:line 725
   at Ice.Cloud.ProxyBase`1.CallWithMultistepBpmHandling(String methodName, ProxyValuesIn valuesIn, ProxyValuesOut valuesOut, Boolean useSparseCopy) in C:\_releases\ICE\ICE4.2.200.0\Source\Shared\Framework\Epicor.ServiceModel\Cloud\ProxyBase.cs:line 670
   at Ice.Cloud.ProxyBase`1.Call(String methodName, ProxyValuesIn valuesIn, ProxyValuesOut valuesOut, Boolean useSparseCopy) in C:\_releases\ICE\ICE4.2.200.0\Source\Shared\Framework\Epicor.ServiceModel\Cloud\ProxyBase.cs:line 649
   at Ice.Proxy.BO.SysAgentImpl.GetByIdForTaskAgent(String agentID, Boolean firstPass) in C:\_releases\ICE\ICE4.2.200.0\Source\Shared\Contracts\BO\SysAgent\SysAgentProxy.cs:line 65
   at Ice.TaskAgentCore.ImplCaller.ImplCaller`1.Call[TResult](Func`2 doWork, ExceptionBehavior communicationExceptionBehavior, ExceptionBehavior timeoutExceptionBehavior)
   at Ice.TaskAgentCore.ScheduledTaskRunner.QueryAndQueueAvailableSchedules()
   at Ice.TaskAgentCore.ScheduledTaskRunner.Process()
   at Ice.TaskAgentCore.SequentialAsyncActionRunner.HandleContinuation(Task task, Action action, Action cancelAction, Action`1 exceptionAction)
   at Ice.TaskAgentCore.SequentialAsyncActionRunner.<>c__DisplayClass12_0.<RunAfterDelay>b__0(Task task)
   at System.Threading.Tasks.Task.Execute()

Olga · July 11, 2023, 1:43pm

You have the same error in different places… Looks like a pool starvation to me. Maybe your server is just busy and connection pool size is reached?

carlosqt · July 11, 2023, 1:58pm

Thanks Olga. That is probably the case, but if before or after getting this error, I run the client and make the BPM trigger the same Epicor Function, it runs without a problem (it blocks the client UI), but does not throws any timeout. If the function is called from the BPM directive it does not exhausts the pool.

Olga · July 11, 2023, 2:13pm

try to use something like sp_whoisactive to figure out what is going on SQL server in both cases.

markdamen · January 20, 2025, 11:01pm

@carlosqt I’m going to create a new post, but just tagging this one also to see if it jogs your memory - did you ever solve the weird issue where the Function exhausts the connection pool when run direct but not when called from DD? Cheers.

carlosqt · January 21, 2025, 12:49pm

Hi Mark,
In my case, a customer requested to move a large BPM to an Epicor Function to run it on a schedule. I did that with their BPM custom code almost as-is, however, I had this timeout error when ran through the schedule function process. If the Function was executed via a BPM, it was fine (took long, but ran).

To solve the issue, I had to reimplement the function code more efficiently by removing unnecessary loops and queries from the original version. In fact it was processing 3 types of transactions, so besides improving the code, I also split the function into multiple functions. Smaller sets of data were processed by different scheduled functions. Maybe that can work for you too.

Topic		Replies	Views
Task stuck Epicor ERP 10 bpm	11	1033	April 16, 2023
BPM runtime caught an unexpected in simple ChangeLog BPM Kinetic ERP bpm	14	2193	July 15, 2024
BPM that runs off of scheduled task may be causing issues with Task Agent Kinetic ERP scheduled-bpm	5	485	March 29, 2024
End Active Tasks Using BPM's or Functions - Help Needed Kinetic ERP epicor , bpm	2	605	October 17, 2023
Call an Epicor Function asynchronously Kinetic ERP functions	35	4485	October 15, 2024