Blame source/vdo/kernel/workItemStats.c

Packit Service 75d76b
/*
Packit Service 75d76b
 * Copyright (c) 2020 Red Hat, Inc.
Packit Service 75d76b
 *
Packit Service 75d76b
 * This program is free software; you can redistribute it and/or
Packit Service 75d76b
 * modify it under the terms of the GNU General Public License
Packit Service 75d76b
 * as published by the Free Software Foundation; either version 2
Packit Service 75d76b
 * of the License, or (at your option) any later version.
Packit Service 75d76b
 * 
Packit Service 75d76b
 * This program is distributed in the hope that it will be useful,
Packit Service 75d76b
 * but WITHOUT ANY WARRANTY; without even the implied warranty of
Packit Service 75d76b
 * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
Packit Service 75d76b
 * GNU General Public License for more details.
Packit Service 75d76b
 * 
Packit Service 75d76b
 * You should have received a copy of the GNU General Public License
Packit Service 75d76b
 * along with this program; if not, write to the Free Software
Packit Service 75d76b
 * Foundation, Inc., 51 Franklin Street, Fifth Floor, Boston, MA
Packit Service 75d76b
 * 02110-1301, USA. 
Packit Service 75d76b
 *
Packit Service 75d76b
 * $Id: //eng/vdo-releases/aluminum/src/c++/vdo/kernel/workItemStats.c#4 $
Packit Service 75d76b
 */
Packit Service 75d76b
Packit Service 75d76b
#include "workItemStats.h"
Packit Service 75d76b
Packit Service 75d76b
#include "atomic.h"
Packit Service 75d76b
#include "logger.h"
Packit Service 75d76b
Packit Service 75d76b
/**
Packit Service 75d76b
 * Scan the work queue stats table for the provided work function and
Packit Service 75d76b
 * priority value. If it's not found, see if an empty slot is
Packit Service 75d76b
 * available.
Packit Service 75d76b
 *
Packit Service 75d76b
 * @param table       The work queue's function table
Packit Service 75d76b
 * @param work        The function we want to record stats for
Packit Service 75d76b
 * @param priority    The priority of the work item
Packit Service 75d76b
 *
Packit Service 75d76b
 * @return   The index of the slot to use (matching or empty), or
Packit Service 75d76b
 *           NUM_WORK_QUEUE_ITEM_STATS if the table is full of
Packit Service 75d76b
 *           non-matching entries.
Packit Service 75d76b
 **/
Packit Service 75d76b
static inline unsigned int scanStatTable(const KvdoWorkFunctionTable *table,
Packit Service 75d76b
                                         KvdoWorkFunction             work,
Packit Service 75d76b
                                         unsigned int                 priority)
Packit Service 75d76b
{
Packit Service 75d76b
  unsigned int i;
Packit Service 75d76b
  /*
Packit Service 75d76b
   * See comments in getStatTableIndex regarding order of memory
Packit Service 75d76b
   * accesses. Work function first, then a barrier, then priority.
Packit Service 75d76b
   */
Packit Service 75d76b
  for (i = 0; i < NUM_WORK_QUEUE_ITEM_STATS; i++) {
Packit Service 75d76b
    if (table->functions[i] == NULL) {
Packit Service 75d76b
      return i;
Packit Service 75d76b
    } else if (table->functions[i] == work) {
Packit Service 75d76b
      smp_rmb();
Packit Service 75d76b
      if (table->priorities[i] == priority) {
Packit Service 75d76b
        return i;
Packit Service 75d76b
      }
Packit Service 75d76b
    }
Packit Service 75d76b
  }
Packit Service 75d76b
  return NUM_WORK_QUEUE_ITEM_STATS;
Packit Service 75d76b
}
Packit Service 75d76b
Packit Service 75d76b
/**
Packit Service 75d76b
 * Scan the work queue stats table for the provided work function and
Packit Service 75d76b
 * priority value. Assign an empty slot if necessary.
Packit Service 75d76b
 *
Packit Service 75d76b
 * @param stats       The stats structure
Packit Service 75d76b
 * @param work        The function we want to record stats for
Packit Service 75d76b
 * @param priority    The priority of the work item
Packit Service 75d76b
 *
Packit Service 75d76b
 * @return   The index of the matching slot, or NUM_WORK_QUEUE_ITEM_STATS
Packit Service 75d76b
 *           if the table is full of non-matching entries.
Packit Service 75d76b
 **/
Packit Service 75d76b
static unsigned int getStatTableIndex(KvdoWorkItemStats *stats,
Packit Service 75d76b
                                      KvdoWorkFunction   work,
Packit Service 75d76b
                                      unsigned int       priority)
Packit Service 75d76b
{
Packit Service 75d76b
  KvdoWorkFunctionTable *functionTable = &stats->functionTable;
Packit Service 75d76b
Packit Service 75d76b
  unsigned int index = scanStatTable(functionTable, work, priority);
Packit Service 75d76b
  if (unlikely(index == NUM_WORK_QUEUE_ITEM_STATS)
Packit Service 75d76b
      || likely(functionTable->functions[index] != NULL)) {
Packit Service 75d76b
    return index;
Packit Service 75d76b
  }
Packit Service 75d76b
Packit Service 75d76b
  unsigned long flags = 0;
Packit Service 75d76b
  // The delayed-work-item processing uses queue->lock in some cases,
Packit Service 75d76b
  // and one case may call into this function, so we can't reuse
Packit Service 75d76b
  // queue->lock here.
Packit Service 75d76b
  spin_lock_irqsave(&functionTable->lock, flags);
Packit Service 75d76b
  // Recheck now that we've got the lock...
Packit Service 75d76b
  index = scanStatTable(functionTable, work, priority);
Packit Service 75d76b
  if ((index == NUM_WORK_QUEUE_ITEM_STATS)
Packit Service 75d76b
      || (functionTable->functions[index] != NULL)) {
Packit Service 75d76b
    spin_unlock_irqrestore(&functionTable->lock, flags);
Packit Service 75d76b
    return index;
Packit Service 75d76b
  }
Packit Service 75d76b
Packit Service 75d76b
  /*
Packit Service 75d76b
   * An uninitialized priority is indistinguishable from a zero
Packit Service 75d76b
   * priority. So store the priority first, and enforce the ordering,
Packit Service 75d76b
   * so that a non-null work function pointer indicates we've finished
Packit Service 75d76b
   * filling in the value. (And, to make this work, we have to read
Packit Service 75d76b
   * the work function first and priority second, when comparing.)
Packit Service 75d76b
   */
Packit Service 75d76b
  functionTable->priorities[index] = priority;
Packit Service 75d76b
  smp_wmb();
Packit Service 75d76b
  functionTable->functions[index] = work;
Packit Service 75d76b
  spin_unlock_irqrestore(&functionTable->lock, flags);
Packit Service 75d76b
  return index;
Packit Service 75d76b
}
Packit Service 75d76b
Packit Service 75d76b
/**
Packit Service 75d76b
 * Get counters on work items, identified by index into the internal
Packit Service 75d76b
 * array.
Packit Service 75d76b
 *
Packit Service 75d76b
 * @param [in]  stats         The collected statistics
Packit Service 75d76b
 * @param [in]  index         The index
Packit Service 75d76b
 * @param [out] enqueuedPtr   The total work items enqueued
Packit Service 75d76b
 * @param [out] processedPtr  The number of work items processed
Packit Service 75d76b
 * @param [out] pendingPtr    The number of work items still pending
Packit Service 75d76b
 **/
Packit Service 75d76b
static void getWorkItemCountsByItem(const KvdoWorkItemStats *stats,
Packit Service 75d76b
                                    unsigned int             index,
Packit Service 75d76b
                                    uint64_t                *enqueuedPtr,
Packit Service 75d76b
                                    uint64_t                *processedPtr,
Packit Service 75d76b
                                    unsigned int            *pendingPtr)
Packit Service 75d76b
{
Packit Service 75d76b
  uint64_t enqueued  = atomic64_read(&stats->enqueued[index]);
Packit Service 75d76b
  uint64_t processed = stats->times[index].count;
Packit Service 75d76b
  unsigned int pending;
Packit Service 75d76b
  if (enqueued < processed) {
Packit Service 75d76b
    // Probably just out of sync.
Packit Service 75d76b
    pending = 1;
Packit Service 75d76b
  } else {
Packit Service 75d76b
    pending = enqueued - processed;
Packit Service 75d76b
    // Pedantic paranoia: Check for overflow of the 32-bit "pending".
Packit Service 75d76b
    if ((pending + processed) < enqueued) {
Packit Service 75d76b
      pending = UINT_MAX;
Packit Service 75d76b
    }
Packit Service 75d76b
  }
Packit Service 75d76b
  *enqueuedPtr  = enqueued;
Packit Service 75d76b
  *processedPtr = processed;
Packit Service 75d76b
  *pendingPtr   = pending;
Packit Service 75d76b
}
Packit Service 75d76b
Packit Service 75d76b
/**
Packit Service 75d76b
 * Get counters on work items not covered by any index value.
Packit Service 75d76b
 *
Packit Service 75d76b
 * @param [in]  stats         The collected statistics
Packit Service 75d76b
 * @param [out] enqueuedPtr   The total work items enqueued
Packit Service 75d76b
 * @param [out] processedPtr  The number of work items processed
Packit Service 75d76b
 **/
Packit Service 75d76b
static void getOtherWorkItemCounts(const KvdoWorkItemStats *stats,
Packit Service 75d76b
                                   uint64_t                *enqueuedPtr,
Packit Service 75d76b
                                   uint64_t                *processedPtr)
Packit Service 75d76b
{
Packit Service 75d76b
  unsigned int pending;
Packit Service 75d76b
  getWorkItemCountsByItem(stats, NUM_WORK_QUEUE_ITEM_STATS,
Packit Service 75d76b
                          enqueuedPtr, processedPtr, &pending);
Packit Service 75d76b
}
Packit Service 75d76b
Packit Service 75d76b
/**
Packit Service 75d76b
 * Get timing stats on work items, identified by index into the
Packit Service 75d76b
 * internal array.
Packit Service 75d76b
 *
Packit Service 75d76b
 * @param [in]  stats  The collected statistics
Packit Service 75d76b
 * @param [in]  index  The index into the array
Packit Service 75d76b
 * @param [out] min    The minimum execution time
Packit Service 75d76b
 * @param [out] mean   The mean execution time
Packit Service 75d76b
 * @param [out] max    The maximum execution time
Packit Service 75d76b
 **/
Packit Service 75d76b
static void getWorkItemTimesByItem(const KvdoWorkItemStats *stats,
Packit Service 75d76b
                                   unsigned int             index,
Packit Service 75d76b
                                   uint64_t                *min,
Packit Service 75d76b
                                   uint64_t                *mean,
Packit Service 75d76b
                                   uint64_t                *max)
Packit Service 75d76b
{
Packit Service 75d76b
  *min  = stats->times[index].min;
Packit Service 75d76b
  *mean = getSampleAverage(&stats->times[index]);
Packit Service 75d76b
  *max  = stats->times[index].max;
Packit Service 75d76b
}
Packit Service 75d76b
Packit Service 75d76b
/**********************************************************************/
Packit Service 75d76b
void updateWorkItemStatsForEnqueue(KvdoWorkItemStats *stats,
Packit Service 75d76b
                                   KvdoWorkItem      *item,
Packit Service 75d76b
                                   int                priority)
Packit Service 75d76b
{
Packit Service 75d76b
  item->statTableIndex = getStatTableIndex(stats, item->statsFunction,
Packit Service 75d76b
                                           priority);
Packit Service 75d76b
  atomic64_add(1, &stats->enqueued[item->statTableIndex]);
Packit Service 75d76b
}
Packit Service 75d76b
Packit Service 75d76b
/**********************************************************************/
Packit Service 75d76b
char *getFunctionName(void *pointer, char *buffer, size_t bufferLength)
Packit Service 75d76b
{
Packit Service 75d76b
  if (pointer == NULL) {
Packit Service 75d76b
    /*
Packit Service 75d76b
     * Format "%ps" logs a null pointer as "(null)" with a bunch of
Packit Service 75d76b
     * leading spaces. We sometimes use this when logging lots of
Packit Service 75d76b
     * data; don't be so verbose.
Packit Service 75d76b
     */
Packit Service 75d76b
    strncpy(buffer, "-", bufferLength);
Packit Service 75d76b
  } else {
Packit Service 75d76b
    /*
Packit Service 75d76b
     * Use a non-const array instead of a string literal below to
Packit Service 75d76b
     * defeat gcc's format checking, which doesn't understand that
Packit Service 75d76b
     * "%ps" actually does support a precision spec in Linux kernel
Packit Service 75d76b
     * code.
Packit Service 75d76b
     */
Packit Service 75d76b
    static char truncatedFunctionNameFormatString[] = "%.*ps";
Packit Service 75d76b
    snprintf(buffer, bufferLength,
Packit Service 75d76b
             truncatedFunctionNameFormatString,
Packit Service 75d76b
             bufferLength - 1,
Packit Service 75d76b
             pointer);
Packit Service 75d76b
Packit Service 75d76b
    char *space = strchr(buffer, ' ');
Packit Service 75d76b
    if (space != NULL) {
Packit Service 75d76b
      *space = '\0';
Packit Service 75d76b
    }
Packit Service 75d76b
  }
Packit Service 75d76b
Packit Service 75d76b
  return buffer;
Packit Service 75d76b
}
Packit Service 75d76b
Packit Service 75d76b
/**********************************************************************/
Packit Service 75d76b
size_t formatWorkItemStats(const KvdoWorkItemStats *stats,
Packit Service 75d76b
                           char                    *buffer,
Packit Service 75d76b
                           size_t                   length)
Packit Service 75d76b
{
Packit Service 75d76b
  const KvdoWorkFunctionTable *functionIDs = &stats->functionTable;
Packit Service 75d76b
  size_t currentOffset = 0;
Packit Service 75d76b
Packit Service 75d76b
  uint64_t enqueued, processed;
Packit Service 75d76b
  int i;
Packit Service 75d76b
  for (i = 0; i < NUM_WORK_QUEUE_ITEM_STATS; i++) {
Packit Service 75d76b
    if (functionIDs->functions[i] == NULL) {
Packit Service 75d76b
      break;
Packit Service 75d76b
    }
Packit Service 75d76b
    if (atomic64_read(&stats->enqueued[i]) == 0) {
Packit Service 75d76b
      continue;
Packit Service 75d76b
    }
Packit Service 75d76b
    /*
Packit Service 75d76b
     * The reporting of all of "pending", "enqueued" and "processed"
Packit Service 75d76b
     * here seems redundant, but "pending" is limited to 0 in the case
Packit Service 75d76b
     * where "processed" exceeds "enqueued", either through current
Packit Service 75d76b
     * activity and a lack of synchronization when fetching stats, or
Packit Service 75d76b
     * a coding bug. This report is intended largely for debugging, so
Packit Service 75d76b
     * we'll go ahead and print the not-necessarily-redundant values.
Packit Service 75d76b
     */
Packit Service 75d76b
    unsigned int pending;
Packit Service 75d76b
    getWorkItemCountsByItem(stats, i, &enqueued, &processed, &pending);
Packit Service 75d76b
Packit Service 75d76b
    // Format: fn prio enq proc timeo [ min max mean ]
Packit Service 75d76b
    if (ENABLE_PER_FUNCTION_TIMING_STATS) {
Packit Service 75d76b
      uint64_t min, mean, max;
Packit Service 75d76b
      getWorkItemTimesByItem(stats, i, &min, &mean, &max;;
Packit Service 75d76b
      currentOffset += snprintf(buffer + currentOffset,
Packit Service 75d76b
                                length - currentOffset,
Packit Service 75d76b
                                "%-36ps %d %10llu %10" PRIu64
Packit Service 75d76b
                                " %10llu %10llu %10" PRIu64
Packit Service 75d76b
                                "\n",
Packit Service 75d76b
                                functionIDs->functions[i],
Packit Service 75d76b
                                functionIDs->priorities[i],
Packit Service 75d76b
                                enqueued, processed,
Packit Service 75d76b
                                min, max, mean);
Packit Service 75d76b
    } else {
Packit Service 75d76b
      currentOffset += snprintf(buffer + currentOffset,
Packit Service 75d76b
                                length - currentOffset,
Packit Service 75d76b
                                "%-36ps %d %10llu %10" PRIu64
Packit Service 75d76b
                                "\n",
Packit Service 75d76b
                                functionIDs->functions[i],
Packit Service 75d76b
                                functionIDs->priorities[i],
Packit Service 75d76b
                                enqueued, processed);
Packit Service 75d76b
    }
Packit Service 75d76b
    if (currentOffset >= length) {
Packit Service 75d76b
      break;
Packit Service 75d76b
    }
Packit Service 75d76b
  }
Packit Service 75d76b
  if ((i == NUM_WORK_QUEUE_ITEM_STATS) && (currentOffset < length)) {
Packit Service 75d76b
    uint64_t enqueued, processed;
Packit Service 75d76b
    getOtherWorkItemCounts(stats, &enqueued, &processed);
Packit Service 75d76b
    if (enqueued > 0) {
Packit Service 75d76b
      currentOffset += snprintf(buffer + currentOffset,
Packit Service 75d76b
                                length - currentOffset,
Packit Service 75d76b
                                "%-36s %d %10llu %10" PRIu64
Packit Service 75d76b
                                "\n",
Packit Service 75d76b
                                "OTHER", 0,
Packit Service 75d76b
                                enqueued, processed);
Packit Service 75d76b
    }
Packit Service 75d76b
  }
Packit Service 75d76b
  return currentOffset;
Packit Service 75d76b
}
Packit Service 75d76b
Packit Service 75d76b
/**********************************************************************/
Packit Service 75d76b
void logWorkItemStats(const KvdoWorkItemStats *stats)
Packit Service 75d76b
{
Packit Service 75d76b
  uint64_t totalEnqueued = 0;
Packit Service 75d76b
  uint64_t totalProcessed = 0;
Packit Service 75d76b
Packit Service 75d76b
  const KvdoWorkFunctionTable *functionIDs = &stats->functionTable;
Packit Service 75d76b
Packit Service 75d76b
  int i;
Packit Service 75d76b
  for (i = 0; i < NUM_WORK_QUEUE_ITEM_STATS; i++) {
Packit Service 75d76b
    if (functionIDs->functions[i] == NULL) {
Packit Service 75d76b
      break;
Packit Service 75d76b
    }
Packit Service 75d76b
    if (atomic64_read(&stats->enqueued[i]) == 0) {
Packit Service 75d76b
      continue;
Packit Service 75d76b
    }
Packit Service 75d76b
    /*
Packit Service 75d76b
     * The reporting of all of "pending", "enqueued" and "processed"
Packit Service 75d76b
     * here seems redundant, but "pending" is limited to 0 in the case
Packit Service 75d76b
     * where "processed" exceeds "enqueued", either through current
Packit Service 75d76b
     * activity and a lack of synchronization when fetching stats, or
Packit Service 75d76b
     * a coding bug. This report is intended largely for debugging, so
Packit Service 75d76b
     * we'll go ahead and print the not-necessarily-redundant values.
Packit Service 75d76b
     */
Packit Service 75d76b
    uint64_t enqueued, processed;
Packit Service 75d76b
    unsigned int pending;
Packit Service 75d76b
    getWorkItemCountsByItem(stats, i, &enqueued, &processed, &pending);
Packit Service 75d76b
    totalEnqueued  += enqueued;
Packit Service 75d76b
    totalProcessed += processed;
Packit Service 75d76b
Packit Service 75d76b
    static char work[256]; // arbitrary size
Packit Service 75d76b
    getFunctionName(functionIDs->functions[i], work, sizeof(work));
Packit Service 75d76b
Packit Service 75d76b
    if (ENABLE_PER_FUNCTION_TIMING_STATS) {
Packit Service 75d76b
      uint64_t min, mean, max;
Packit Service 75d76b
      getWorkItemTimesByItem(stats, i, &min, &mean, &max;;
Packit Service 75d76b
      logInfo("  priority %d: %u pending"
Packit Service 75d76b
              " %llu enqueued %llu processed"
Packit Service 75d76b
              " %s"
Packit Service 75d76b
              " times %llu/%llu/%lluns",
Packit Service 75d76b
              functionIDs->priorities[i],
Packit Service 75d76b
              pending, enqueued, processed, work,
Packit Service 75d76b
              min, mean, max);
Packit Service 75d76b
    } else {
Packit Service 75d76b
      logInfo("  priority %d: %u pending"
Packit Service 75d76b
              " %llu enqueued %llu processed"
Packit Service 75d76b
              " %s",
Packit Service 75d76b
              functionIDs->priorities[i],
Packit Service 75d76b
              pending, enqueued, processed, work);
Packit Service 75d76b
    }
Packit Service 75d76b
  }
Packit Service 75d76b
  if (i == NUM_WORK_QUEUE_ITEM_STATS) {
Packit Service 75d76b
    uint64_t enqueued, processed;
Packit Service 75d76b
    getOtherWorkItemCounts(stats, &enqueued, &processed);
Packit Service 75d76b
    if (enqueued > 0) {
Packit Service 75d76b
      totalEnqueued  += enqueued;
Packit Service 75d76b
      totalProcessed += processed;
Packit Service 75d76b
      logInfo("  ... others: %llu enqueued %llu processed",
Packit Service 75d76b
              enqueued, processed);
Packit Service 75d76b
    }
Packit Service 75d76b
  }
Packit Service 75d76b
  logInfo("  total: %llu enqueued %llu processed",
Packit Service 75d76b
          totalEnqueued, totalProcessed);
Packit Service 75d76b
}