Add stats about the delay added to running tasks in Workers

erizo/src/erizo/thread/ThreadPool.cpp

@@ -56,6 +56,14 @@ DurationDistribution ThreadPool::getDurationDistribution() {
   return total_durations;
 }
 
+DurationDistribution ThreadPool::getDelayDistribution() {
+  DurationDistribution total_delays;
+  for (auto worker : workers_) {
+    total_delays += worker->getDelayDistribution();
+  }
+  return total_delays;
+}
+
 void ThreadPool::resetStats() {
   for (auto worker : workers_) {
     worker->resetStats();

erizo/src/erizo/thread/ThreadPool.h

@@ -20,6 +20,7 @@ class ThreadPool {
 
   void resetStats();
   DurationDistribution getDurationDistribution();
+  DurationDistribution getDelayDistribution();
 
  private:
   std::vector<std::shared_ptr<Worker>> workers_;

erizo/src/erizo/thread/Worker.cpp

@@ -59,7 +59,20 @@ Worker::~Worker() {
 }
 
 void Worker::task(Task f) {
-  service_.dispatch(f);
+  std::weak_ptr<Worker> weak_this = shared_from_this();
+  time_point scheduled_at = clock_->now();
+  service_.dispatch([f, scheduled_at, weak_this] {
+    time_point start;
+    if (auto this_ptr = weak_this.lock()) {
+      start = this_ptr->clock_->now();
+    }
+    f();
+    if (auto this_ptr = weak_this.lock()) {
+      time_point end = this_ptr->clock_->now();
+      this_ptr->addToDurationStats(end - start);
+      this_ptr->addToDelayStats(start - scheduled_at);
+    }
+  });
 }
 
 void Worker::start() {
@@ -134,12 +147,12 @@ std::function<void()> Worker::safeTask(std::function<void(std::shared_ptr<Worker
       time_point start = this_ptr->clock_->now();
       f(this_ptr);
       time_point end = this_ptr->clock_->now();
-      this_ptr->addToStats(end - start);
+      this_ptr->addToDurationStats(end - start);
     }
   };
 }
 
-void Worker::addToStats(duration task_duration) {
+void Worker::addToDurationStats(duration task_duration) {
   if (task_duration <= std::chrono::milliseconds(10)) {
     durations_.duration_0_10_ms++;
   } else if (task_duration <= std::chrono::milliseconds(50)) {
@@ -153,9 +166,24 @@ void Worker::addToStats(duration task_duration) {
   }
 }
 
+void Worker::addToDelayStats(duration task_delay) {
+  if (task_delay <= std::chrono::milliseconds(10)) {
+    delays_.duration_0_10_ms++;
+  } else if (task_delay <= std::chrono::milliseconds(50)) {
+    delays_.duration_10_50_ms++;
+  } else if (task_delay <= std::chrono::milliseconds(100)) {
+    delays_.duration_50_100_ms++;
+  } else if (task_delay <= std::chrono::milliseconds(1000)) {
+    delays_.duration_100_1000_ms++;
+  } else {
+    delays_.duration_1000_ms++;
+  }
+}
+
 void Worker::resetStats() {
   task(safeTask([](std::shared_ptr<Worker> worker) {
     worker->durations_.reset();
+    worker->delays_.reset();
   }));
 }
 

erizo/src/erizo/thread/Worker.h

@@ -65,11 +65,13 @@ class Worker : public std::enable_shared_from_this<Worker> {
 
   void resetStats();
   DurationDistribution getDurationDistribution() { return durations_; }
+  DurationDistribution getDelayDistribution() { return delays_; }
 
  private:
   void scheduleEvery(ScheduledTask f, duration period, duration next_delay);
   std::function<void()> safeTask(std::function<void(std::shared_ptr<Worker>)> f);
-  void addToStats(duration task_duration);
+  void addToDurationStats(duration task_duration);
+  void addToDelayStats(duration task_delay);
 
  protected:
   int next_scheduled_ = 0;
@@ -83,6 +85,7 @@ class Worker : public std::enable_shared_from_this<Worker> {
   std::atomic<bool> closed_;
   boost::thread::id thread_id_;
   DurationDistribution durations_;
+  DurationDistribution delays_;
 };
 
 class SimulatedWorker : public Worker {

erizoAPI/ThreadPool.cc

@@ -31,6 +31,7 @@ NAN_MODULE_INIT(ThreadPool::Init) {
   Nan::SetPrototypeMethod(tpl, "close", close);
   Nan::SetPrototypeMethod(tpl, "start", start);
   Nan::SetPrototypeMethod(tpl, "getDurationDistribution", getDurationDistribution);
+  Nan::SetPrototypeMethod(tpl, "getDelayDistribution", getDelayDistribution);
   Nan::SetPrototypeMethod(tpl, "resetStats", resetStats);
 
   constructor.Reset(Nan::GetFunction(tpl).ToLocalChecked());
@@ -76,6 +77,19 @@ NAN_METHOD(ThreadPool::getDurationDistribution) {
   info.GetReturnValue().Set(array);
 }
 
+NAN_METHOD(ThreadPool::getDelayDistribution) {
+  ThreadPool* obj = Nan::ObjectWrap::Unwrap<ThreadPool>(info.Holder());
+  DurationDistribution duration_distribution = obj->me->getDelayDistribution();
+  v8::Local<v8::Array> array = Nan::New<v8::Array>(5);
+  Nan::Set(array, 0, Nan::New(duration_distribution.duration_0_10_ms));
+  Nan::Set(array, 1, Nan::New(duration_distribution.duration_10_50_ms));
+  Nan::Set(array, 2, Nan::New(duration_distribution.duration_50_100_ms));
+  Nan::Set(array, 3, Nan::New(duration_distribution.duration_100_1000_ms));
+  Nan::Set(array, 4, Nan::New(duration_distribution.duration_1000_ms));
+
+  info.GetReturnValue().Set(array);
+}
+
 NAN_METHOD(ThreadPool::resetStats) {
   ThreadPool* obj = Nan::ObjectWrap::Unwrap<ThreadPool>(info.Holder());
   obj->me->resetStats();

erizoAPI/ThreadPool.h

@@ -36,6 +36,7 @@ class ThreadPool : public Nan::ObjectWrap {
     static NAN_METHOD(start);
 
     static NAN_METHOD(getDurationDistribution);
+    static NAN_METHOD(getDelayDistribution);
     static NAN_METHOD(resetStats);
 
     static Nan::Persistent<v8::Function> constructor;

erizo_controller/erizoJS/erizoJSController.js

@@ -686,6 +686,7 @@ exports.ErizoJSController = (erizoJSId, threadPool, ioThreadPool) => {
     metrics.subscribers = subscribers;
 
     metrics.durationDistribution = threadPool.getDurationDistribution();
+    metrics.delayDistribution = threadPool.getDelayDistribution();
     threadPool.resetStats();
 
     clients.forEach((client) => {