Task Agent / App Pool Constant CPU Activity

I am seeing constant CPU activity from my Task Agent and the IIS Application Pool for my app server. I’m having trouble figuring out the cause.

If I restart the Task Agent Service, the problem goes away for a while. It comes back after some amount of time, or possibly some event in Epicor triggering it? Haven’t figured out the trigger.

Stopping the agent for the affected app server stops the issue, but immediately returns on starting the agent.

The system agent has no schedule assigned, and there are no tasks being run. There are no messages in the Event Log for either the Task Agent service or the Epicor App Server.

Has anyone else seen this happen? Any ideas as to the reason?

Version?

10.2.500.4

Did you see this thread?

1 Like

I did find this yesterday. It looked promising from the title, but the problem is different.

In my case the CPU is not being totally consumed by the process, but it constantly hovers around 10%.

RAM hovers at a reasonable value, doesn’t seem to be a runaway query.

Recycling the App Pool does not solve the problem, even temporarily. So it seems pretty clearly to be related to or caused by the Task Agent.

Do you run regular maintenance on your SQL server? I had an interesting one while testing a dashboard in a test environment. It kept timing out. I ended up running a re-index over the database, and an update statistics. That fixed the problem.

So as previously mentioned it may be a scheduled process that is running up against a poor cached query or badly fragmented index.

1 Like

In 10.2.500, we added a bunch of extra logging information to the Task Agent’s log file. The file is at:
%ALLUSERSPROFILE%\Epicor Software Corporation\ICE TaskAgent Service\Logs

Paste that into Windows Explorer and it will automatically figure out what %ALLUSERSPROFILE% is. Your log files will be there with dates in there name. My latest on is log-file-20191220.txt. Open it and you will see a bunch of information. The one to look at first is the new “metric” data. It will look something like this:
Metrics (ExecutingTasks=[0 1 0.001689178], QueuedTasks=[0 1 8.332246E-08], TaskTimes=["00:00:00.0501598" "00:00:00.0510997" "00:00:00.0506297"], TasksFinished=2, ExecutingSchedules=[0 1 0.005436037], SchedulesFinished=2, LongestRunningTask="00:00:00.0511008", LongestWaitingTask="00:00:00")

This is all documented by the way. Basically, you get all kinds of information about what Task Agent is doing internally. The values in square brackets are the minimum, maximum and weighted average since the last metrics were written. In the above “ExecutingTasks=[0 1 0.001689178]” means a maximum of 1 task run over the interval. It didn’t run long since the “weighted average” is very small. This will give you an idea of what is going on.

If that is not enough, you can bump the verbosity of the log by editing the C:\Program Files (x86)\Epicor Software\Epicor Task Agent Service 3.2.500.0\TaskAgentService.exe.config file and change:

<add key="serilog:minimum-level" value="Information" />

to have a value of Verbose. This will give you a huge amount of information. Specifically, you will see what schedules/tasks are started and when they finish. This should be more than enough to figure out what is going on. Put it back to Information when done.

Let us know what you find!

2 Likes

Thank you Jeff. I noticed a message formatted that way in the Event Viewer, all zeros. I’ll dig more into those files and probably bump up the log levels.

…after Star Wars. :slight_smile:

1 Like

Priorities, of course. :slight_smile:

“all zeros” means that Task Agent shouldn’t be doing anything besides polling the application server to see if it has any schedules to run. I would expect a very low CPU utilization for the Task Agent process. I assume you are using the OS Task Manager to see CPU utilization?

So besides that, Task Agent seems to be running correctly? Just trying to get as much information as possible.

Serious question…

With multi-core processors, will you ever see any process (other than “System Idle Process”)use more than 1/#of cores?

When my CAD software is chugging away, it consumes 50% of my dual core system. Never more.

If you had 10 cores in your system, would any process ever exceed 10%?

That depends on what you are running. Task Agent, for example, is multi-threaded so if it has enough work to do, it will use up to 100%. Task Agent should never even get close since it delegates almost all the work to the application server. In this case Task Agent is multi-threaded so that we don’t get one thing waiting for another to finish, not for performance.

For things like CAD software (I’m a Fusion 360 guys myself :wink: ) it should be using 100% if it has work to do. Some things don’t fit well into multi-threading so you have to consider that as well.

1 Like

The Task Agent seems to be running fine in general, but it does seem to take a little more time than normal to process things like reports. And the App Server seems to run a little slower. I don’t have numbers to back that up right now, it’s just an general feeling.

Both the Application Pool and the Task Agent Service run at about 8-12% CPU usage, monitored via Task Manager. The Application Server host (a Hyper-V VM) has multiple Epicor app pools running. Dev, Test, Pilot, Demo environments. This issue is only affecting Test at the moment.

The Task Agent Service is running on a separate VM, and is servicing each of these environments.

I still need to check into those logs. This is just some background information.

1 Like

Using verbose logging I found that the task agent service is polling continuously at a high frequency for a schedule to process. There are none.

2019-12-21 14:08:52.302 -06:00 [INF] Epicor10Test: Agent system.agent has been started.
2019-12-21 14:08:52.365 -06:00 [DBG] Epicor10Test: Processing loop for purging reports has started.
2019-12-21 14:08:52.365 -06:00 [DBG] Epicor10Test: Processing loop for purging task history has started.
2019-12-21 14:08:52.365 -06:00 [DBG] Epicor10Test: Processing loop for system tasks has started.
2019-12-21 14:08:52.365 -06:00 [VRB] Epicor10Test: Begin purging reports.
2019-12-21 14:08:52.365 -06:00 [DBG] Epicor10Test: Processing loop for scheduled tasks has started.
2019-12-21 14:08:52.365 -06:00 [VRB] Epicor10Test: Begin purging task history.
2019-12-21 14:08:52.381 -06:00 [VRB] Epicor10Test: Querying for schedules to process.
2019-12-21 14:08:52.396 -06:00 [VRB] Epicor10Test: End purging reports.
2019-12-21 14:08:52.427 -06:00 [VRB] Epicor10Test: End purging task history.
2019-12-21 14:08:52.443 -06:00 [VRB] Epicor10Test: Querying for schedules to process.
2019-12-21 14:08:52.474 -06:00 [VRB] Epicor10Test: Querying for schedules to process.
2019-12-21 14:08:52.490 -06:00 [VRB] Epicor10Test: Querying for schedules to process.
2019-12-21 14:08:52.506 -06:00 [VRB] Epicor10Test: Querying for schedules to process.
2019-12-21 14:08:52.521 -06:00 [VRB] Epicor10Test: Querying for schedules to process.

That interval for querying schedules is the Processing Delay in System Agent Maintenance. Is yours set to zero? You can set it to whatever number of seconds you like. The larger the number, the less responsive Task Agent will appear. For example, if you set it to 60 seconds and a user prints a report, than they have to wait an average of 30 seconds before Task Agent will check (60 seconds divided by 2) (I was a math major, can you tell? :wink: )

Give that a try and let me know.

1 Like

Don’t forget about system tasks. Task agent should trigger then every 30 sec

1 Like

That was it. What a simple fix. I don’t recall changing that value during system setup. Strange that only 1 of my 4 environments was having the issue. They all had a processing delay of 0.

Thank you

1 Like

@JeffLeBert isnt there a bug in 10.2.300 in that if the processing delay is 0 it is actually slower than if it is set to 3?

This rings a bell with me too. Looked, but couldn’t find the thread I saw it in.

I can’t imaging how 0 would be slower than 3. I wasn’t working much with Task Agent in the 10.2.300 and earlier releases though.

From another thread …

(highlighting mine)