Logo Questions Linux Laravel Mysql Ubuntu Git Menu
 

How to resolve Heartbeat took longer than "00:00:01" failure?

I have a .NetCore C# project which performs an HTTP POST. The project is set up in Kubernetes and I've noticed the logs below:

Heartbeat took longer than "00:00:01" at "02/22/2020 15:43:45 +00:00".
warn: Microsoft.AspNetCore.Server.Kestrel[22]
      Heartbeat took longer than "00:00:01" at "02/22/2020 15:43:46 +00:00".
warn: Microsoft.AspNetCore.Server.Kestrel[22]
      Heartbeat took longer than "00:00:01" at "02/22/2020 15:43:47 +00:00".
warn: Microsoft.AspNetCore.Server.Kestrel[22]
      Heartbeat took longer than "00:00:01" at "02/22/2020 15:43:48 +00:00".
warn: Microsoft.AspNetCore.Server.Kestrel[22]
      Heartbeat took longer than "00:00:01" at "02/22/2020 15:43:49 +00:00".
warn: Microsoft.AspNetCore.Server.Kestrel[22]
      Heartbeat took longer than "00:00:01" at "02/22/2020 15:43:50 +00:00".
warn: Microsoft.AspNetCore.Server.Kestrel[22]
      Heartbeat took longer than "00:00:01" at "02/22/2020 15:43:51 +00:00".
warn: Microsoft.AspNetCore.Server.Kestrel[22]
      Heartbeat took longer than "00:00:01" at "02/22/2020 15:43:52 +00:00".
warn: Microsoft.AspNetCore.Server.Kestrel[22]
      Heartbeat took longer than "00:00:01" at "02/22/2020 15:43:53 +00:00".
warn: Microsoft.AspNetCore.Server.Kestrel[22]
      Heartbeat took longer than "00:00:01" at "02/22/2020 15:43:54 +00:00".
warn: Microsoft.AspNetCore.Server.Kestrel[22]
      Heartbeat took longer than "00:00:01" at "02/22/2020 15:43:55 +00:00".
warn: Microsoft.AspNetCore.Server.Kestrel[22]
      Heartbeat took longer than "00:00:01" at "02/22/2020 15:43:56 +00:00".
warn: Microsoft.AspNetCore.Server.Kestrel[22]
      Heartbeat took longer than "00:00:01" at "02/22/2020 15:44:33 +00:00".
warn: Microsoft.AspNetCore.Server.Kestrel[22]
      Heartbeat took longer than "00:00:01" at "02/22/2020 15:44:34 +00:00".
warn: Microsoft.AspNetCore.Server.Kestrel[22]
      Heartbeat took longer than "00:00:01" at "02/22/2020 15:44:35 +00:00".

After some initial research, it seems this is a common result of threadpool starvation. Accordingly, in November last year, I made the post asynchronous and also logged the Max threads and Available threads as follows for monitoring purposes:

ThreadPool.GetMaxThreads(out int workerThreads, out int completionPortThreads);
ThreadPool.GetAvailableThreads(out int workerThreadAvailable, out int completionPortThreadsAvailable);
_log.Info(new { message = $"Max threads = {workerThreads} and Available threads = {workerThreadAvailable}" });

Consistently over the past few months, the logging shows: Max threads = 32767 and Available threads = 32766. That seems fine, however, I'm noticing the same Heartbeat error so am wondering if this really is a threadpool starvation issue. Might someone know what else is going on and if this error is actually a result of something else? Any investigation/resolution tips for this would be much appreciated!

like image 424
ENV Avatar asked Mar 15 '21 20:03

ENV


People also ask

Which is longer than 00 00 01 This could be caused by thread pool starvation?

Kestrel[22] Heartbeat took longer than "00:00:01" at "02/22/2020 15:44:35 +00:00". After some initial research, it seems this is a common result of threadpool starvation.

Could be caused by thread pool starvation?

ThreadPool starvation occurs when the pool has no available threads to process new work items and it often causes applications to respond slowly. Using the provided example ASP.NET Core web app, you can cause ThreadPool starvation intentionally and learn how to diagnose it.


1 Answers

This is a resource issue, as @andy pointed out in his response.

According to OP, the solution to this problem is to either increase the server's CPU capacity (vertically) or the number of instances of your app (horizontally).

like image 177
Alex G Avatar answered Oct 26 '22 16:10

Alex G