Blame source/vdo/kernel/workQueueStats.c

Packit Service d40955
/*
Packit Service d40955
 * Copyright (c) 2020 Red Hat, Inc.
Packit Service d40955
 *
Packit Service d40955
 * This program is free software; you can redistribute it and/or
Packit Service d40955
 * modify it under the terms of the GNU General Public License
Packit Service d40955
 * as published by the Free Software Foundation; either version 2
Packit Service d40955
 * of the License, or (at your option) any later version.
Packit Service d40955
 * 
Packit Service d40955
 * This program is distributed in the hope that it will be useful,
Packit Service d40955
 * but WITHOUT ANY WARRANTY; without even the implied warranty of
Packit Service d40955
 * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
Packit Service d40955
 * GNU General Public License for more details.
Packit Service d40955
 * 
Packit Service d40955
 * You should have received a copy of the GNU General Public License
Packit Service d40955
 * along with this program; if not, write to the Free Software
Packit Service d40955
 * Foundation, Inc., 51 Franklin Street, Fifth Floor, Boston, MA
Packit Service d40955
 * 02110-1301, USA. 
Packit Service d40955
 *
Packit Service d40955
 * $Id: //eng/vdo-releases/aluminum/src/c++/vdo/kernel/workQueueStats.c#6 $
Packit Service d40955
 */
Packit Service d40955
Packit Service d40955
#include "workQueueStats.h"
Packit Service d40955
Packit Service d40955
#include "atomic.h"
Packit Service d40955
#include "logger.h"
Packit Service d40955
#include "workItemStats.h"
Packit Service d40955
#include "workQueueInternals.h"
Packit Service d40955
Packit Service d40955
/**********************************************************************/
Packit Service d40955
int initializeWorkQueueStats(KvdoWorkQueueStats *stats,
Packit Service d40955
                             struct kobject     *queueKObject)
Packit Service d40955
{
Packit Service d40955
  spin_lock_init(&stats->workItemStats.functionTable.lock);
Packit Service d40955
  if (ENABLE_PER_FUNCTION_TIMING_STATS) {
Packit Service d40955
    for (int i = 0; i < NUM_WORK_QUEUE_ITEM_STATS + 1; i++) {
Packit Service d40955
      initSimpleStats(&stats->workItemStats.times[i]);
Packit Service d40955
    }
Packit Service d40955
  }
Packit Service d40955
Packit Service d40955
  stats->queueTimeHistogram
Packit Service d40955
    = makeLogarithmicHistogram(queueKObject, "queue_time",
Packit Service d40955
                               "Queue Time", "work items", "wait time",
Packit Service d40955
                               "microseconds", 9);
Packit Service d40955
  if (stats->queueTimeHistogram == NULL) {
Packit Service d40955
    return -ENOMEM;
Packit Service d40955
  }
Packit Service d40955
Packit Service d40955
  stats->rescheduleQueueLengthHistogram
Packit Service d40955
    = makeLogarithmicHistogram(queueKObject, "reschedule_queue_length",
Packit Service d40955
                               "Reschedule Queue Length", "calls",
Packit Service d40955
                               "queued work items", NULL, 4);
Packit Service d40955
  if (stats->rescheduleQueueLengthHistogram == NULL) {
Packit Service d40955
    return -ENOMEM;
Packit Service d40955
  }
Packit Service d40955
Packit Service d40955
  stats->rescheduleTimeHistogram
Packit Service d40955
    = makeLogarithmicHistogram(queueKObject, "reschedule_time",
Packit Service d40955
                               "Reschedule Time", "calls",
Packit Service d40955
                               "sleep interval", "microseconds", 9);
Packit Service d40955
  if (stats->rescheduleTimeHistogram == NULL) {
Packit Service d40955
    return -ENOMEM;
Packit Service d40955
  }
Packit Service d40955
Packit Service d40955
  stats->runTimeBeforeRescheduleHistogram
Packit Service d40955
    = makeLogarithmicHistogram(queueKObject, "run_time_before_reschedule",
Packit Service d40955
                               "Run Time Before Reschedule",
Packit Service d40955
                               "calls", "run time", "microseconds", 9);
Packit Service d40955
  if (stats->runTimeBeforeRescheduleHistogram == NULL) {
Packit Service d40955
    return -ENOMEM;
Packit Service d40955
  }
Packit Service d40955
Packit Service d40955
  stats->scheduleTimeHistogram
Packit Service d40955
    = makeLogarithmicHistogram(queueKObject, "schedule_time",
Packit Service d40955
                               "Schedule Time",
Packit Service d40955
                               "calls", "sleep interval", "microseconds", 9);
Packit Service d40955
  if (stats->scheduleTimeHistogram == NULL) {
Packit Service d40955
    return -ENOMEM;
Packit Service d40955
  }
Packit Service d40955
Packit Service d40955
  stats->wakeupLatencyHistogram
Packit Service d40955
    = makeLogarithmicHistogram(queueKObject, "wakeup_latency",
Packit Service d40955
                               "Wakeup Latency",
Packit Service d40955
                               "wakeups", "latency", "microseconds", 9);
Packit Service d40955
  if (stats->wakeupLatencyHistogram == NULL) {
Packit Service d40955
    return -ENOMEM;
Packit Service d40955
  }
Packit Service d40955
Packit Service d40955
  stats->wakeupQueueLengthHistogram
Packit Service d40955
    = makeLogarithmicHistogram(queueKObject, "wakeup_queue_length",
Packit Service d40955
                               "Wakeup Queue Length", "wakeups",
Packit Service d40955
                               "queued work items", NULL, 4);
Packit Service d40955
  if (stats->wakeupQueueLengthHistogram == NULL) {
Packit Service d40955
    return -ENOMEM;
Packit Service d40955
  }
Packit Service d40955
Packit Service d40955
  return 0;
Packit Service d40955
}
Packit Service d40955
Packit Service d40955
/**********************************************************************/
Packit Service d40955
void cleanupWorkQueueStats(KvdoWorkQueueStats *stats)
Packit Service d40955
{
Packit Service d40955
  freeHistogram(&stats->queueTimeHistogram);
Packit Service d40955
  freeHistogram(&stats->rescheduleQueueLengthHistogram);
Packit Service d40955
  freeHistogram(&stats->rescheduleTimeHistogram);
Packit Service d40955
  freeHistogram(&stats->runTimeBeforeRescheduleHistogram);
Packit Service d40955
  freeHistogram(&stats->scheduleTimeHistogram);
Packit Service d40955
  freeHistogram(&stats->wakeupLatencyHistogram);
Packit Service d40955
  freeHistogram(&stats->wakeupQueueLengthHistogram);
Packit Service d40955
}
Packit Service d40955
Packit Service d40955
/**********************************************************************/
Packit Service d40955
static uint64_t getTotalProcessed(const SimpleWorkQueue *queue)
Packit Service d40955
{
Packit Service d40955
  uint64_t totalProcessed = 0;
Packit Service d40955
  for (int i = 0; i < NUM_WORK_QUEUE_ITEM_STATS + 1; i++) {
Packit Service d40955
    totalProcessed += queue->stats.workItemStats.times[i].count;
Packit Service d40955
  }
Packit Service d40955
  return totalProcessed;
Packit Service d40955
}
Packit Service d40955
Packit Service d40955
/**********************************************************************/
Packit Service d40955
void logWorkQueueStats(const SimpleWorkQueue *queue)
Packit Service d40955
{
Packit Service d40955
  uint64_t runtimeNS = 0;
Packit Service d40955
  if (queue->thread != NULL) {
Packit Service d40955
    runtimeNS += queue->thread->se.sum_exec_runtime;
Packit Service d40955
  }
Packit Service d40955
Packit Service d40955
  unsigned long nsPerWorkItem = 0;
Packit Service d40955
  uint64_t totalProcessed = getTotalProcessed(queue);
Packit Service d40955
  if (totalProcessed > 0) {
Packit Service d40955
    nsPerWorkItem = runtimeNS / totalProcessed;
Packit Service d40955
  }
Packit Service d40955
  unsigned long runtimeMS = runtimeNS / 1000;
Packit Service d40955
  logInfo("workQ %" PRIptr " (%s) thread cpu usage %lu.%06lus, %" PRIu64
Packit Service d40955
          " tasks, %lu.%03luus/task",
Packit Service d40955
          queue,
Packit Service d40955
          queue->common.name,
Packit Service d40955
          runtimeMS / 1000000, runtimeMS % 1000000,
Packit Service d40955
          totalProcessed,
Packit Service d40955
          nsPerWorkItem / 1000, nsPerWorkItem % 1000);
Packit Service d40955
}
Packit Service d40955
Packit Service d40955
/**********************************************************************/
Packit Service d40955
ssize_t formatRunTimeStats(const KvdoWorkQueueStats *stats, char *buffer)
Packit Service d40955
{
Packit Service d40955
  // Get snapshots of all three at approximately the same time.
Packit Service d40955
  uint64_t startTime = stats->startTime;
Packit Service d40955
  uint64_t runTime = atomic64_read(&stats->runTime);
Packit Service d40955
  uint64_t rescheduleTime = atomic64_read(&stats->rescheduleTime);
Packit Service d40955
  loadFence();                  // rdtsc barrier
Packit Service d40955
  uint64_t now = currentTime(CLOCK_MONOTONIC);
Packit Service d40955
  uint64_t lifetime = now - startTime;
Packit Service d40955
Packit Service d40955
  return sprintf(buffer,
Packit Service d40955
                 "%llu %llu %llu\n",
Packit Service d40955
                 lifetime, runTime, rescheduleTime);
Packit Service d40955
}