[PATCH 04/11] sapi: Add SMP lock profiling app. level data

[Gedare Bloom]

On Mon, Mar 10, 2014 at 9:28 AM, Sebastian Huber
<sebastian.huber at embedded-brains.de> wrote:
> ---
>  cpukit/sapi/include/rtems/profiling.h |   88 ++++++++++++++++++++++++++++++++-
>  cpukit/sapi/src/profilingreportxml.c  |   70 ++++++++++++++++++++++++++
>  2 files changed, 157 insertions(+), 1 deletions(-)
>
> diff --git a/cpukit/sapi/include/rtems/profiling.h b/cpukit/sapi/include/rtems/profiling.h
> index ecb3ff7..2a66015 100644
> --- a/cpukit/sapi/include/rtems/profiling.h
> +++ b/cpukit/sapi/include/rtems/profiling.h
> @@ -66,7 +66,14 @@ typedef enum {
>     *
>     * @see rtems_profiling_per_cpu.
>     */
> -  RTEMS_PROFILING_PER_CPU
> +  RTEMS_PROFILING_PER_CPU,
> +
> +  /**
> +   * @brief Type of SMP lock profiling data.
> +   *
> +   * @see rtems_profiling_smp_lock.
> +   */
> +  RTEMS_PROFILING_SMP_LOCK
>  } rtems_profiling_type;
>
>  /**
> @@ -152,6 +159,80 @@ typedef struct {
>  } rtems_profiling_per_cpu;
>
>  /**
> + * @brief Count of lock contention counters for SMP lock profiling.
> + */
> +#define RTEMS_PROFILING_SMP_LOCK_CONTENTION_COUNTS 4
> +
> +/**
> + * @brief SMP lock profiling data.
> + *
> + * The lock acquire attempt instant is the point in time right after the
> + * interrupt disable action in the lock acquire sequence.
> + *
> + * The lock acquire instant is the point in time right after the lock
> + * acquisition.  This is the begin of the critical section code execution.
> + *
> + * The lock release instant is the point in time right before the interrupt
> + * enable action in the lock release sequence.
> + *
> + * The lock section time is the time elapsed between the lock acquire instant
> + * and the lock release instant.
> + *
> + * The lock acquire time is the time elapsed between the lock acquire attempt
> + * instant and the lock acquire instant.
Move this last point up to where you define lock acquire attempt
instant and lock acquire instant.

> + */
> +typedef struct {
> +  /**
> +   * @brief The profiling data header.
> +   */
> +  rtems_profiling_header header;
> +
> +  /**
> +   * @brief The lock name.
> +   */
> +  const char *name;
> +
> +  /**
> +   * @brief The maximum lock section time in nanoseconds.
> +   */
> +  uint32_t max_section_time;
> +
> +  /**
> +   * @brief The maximum lock acquire time in nanoseconds.
> +   */
> +  uint32_t max_acquire_time;
> +
Any possible issues with 32-bit values here?

> +  /**
> +   * @brief The count of lock uses.
> +   *
> +   * This value may overflow.
> +   */
> +  uint64_t usage_count;
> +
> +  /**
> +   * @brief Total lock section time in nanoseconds.
> +   *
> +   * The average lock section time is the total section time divided by the
> +   * lock usage count.
> +   *
> +   * This value may overflow.
> +   */
> +  uint64_t total_section_time;
> +
> +  /**
> +   * @brief The counts of lock acquire operations by contention.
> +   *
> +   * The contention count for index N corresponds to a lock acquire attempt
> +   * with an initial queue length of N.  The last index corresponds to all
> +   * lock acquire attempts with an initial queue length greater than or equal
> +   * to RTEMS_PROFILING_SMP_LOCK_CONTENTION_COUNTS minus one.
> +   *
> +   * The values may overflow.
> +   */
> +  uint64_t contention_counts[RTEMS_PROFILING_SMP_LOCK_CONTENTION_COUNTS];
contention_counts[0] is when there is no contention hence negligible
acquire_time?

Is total_acquire_time not feasible or interesting to profile?

> +} rtems_profiling_smp_lock;
> +
> +/**
>   * @brief Collection of profiling data.
>   */
>  typedef union {
> @@ -164,6 +245,11 @@ typedef union {
>     * @brief Per-CPU profiling data if indicated by the header.
>     */
>    rtems_profiling_per_cpu per_cpu;
> +
> +  /**
> +   * @brief SMP lock profiling data if indicated by the header.
> +   */
> +  rtems_profiling_smp_lock smp_lock;
>  } rtems_profiling_data;
>
>  /**
> diff --git a/cpukit/sapi/src/profilingreportxml.c b/cpukit/sapi/src/profilingreportxml.c
> index f0a6fd6..5aa1282 100644
> --- a/cpukit/sapi/src/profilingreportxml.c
> +++ b/cpukit/sapi/src/profilingreportxml.c
> @@ -18,6 +18,7 @@
>
>  #include <rtems/profiling.h>
>
> +#include <stddef.h>
>  #include <inttypes.h>
>
>  typedef struct {
> @@ -128,6 +129,72 @@ static void report_per_cpu(context *ctx, const rtems_profiling_per_cpu *per_cpu)
>    update_retval(ctx, rv);
>  }
>
> +static void report_smp_lock(context *ctx, const rtems_profiling_smp_lock *smp_lock)
> +{
> +  rtems_profiling_printf printf_func = ctx->printf_func;
> +  void *printf_arg = ctx->printf_arg;
> +  int rv;
> +  size_t i;
> +
> +  indent(ctx, 1);
> +  rv = (*printf_func)(
> +    printf_arg,
> +    "<SMPLockProfilingReport name=\"%s\">\n",
> +    smp_lock->name
> +  );
> +  update_retval(ctx, rv);
> +
> +  indent(ctx, 2);
> +  rv = (*printf_func)(
> +    printf_arg,
> +    "<MaxSectionTime unit=\"ns\">%" PRIu32 "</MaxSectionTime>\n",
> +    smp_lock->max_section_time
> +  );
> +  update_retval(ctx, rv);
> +
> +  indent(ctx, 2);
> +  rv = (*printf_func)(
> +    printf_arg,
> +    "<MaxAcquireTime unit=\"ns\">%" PRIu32 "</MaxAcquireTime>\n",
> +    smp_lock->max_acquire_time
> +  );
> +  update_retval(ctx, rv);
> +
> +  indent(ctx, 2);
> +  rv = (*printf_func)(
> +    printf_arg,
> +    "<UsageCount>%" PRIu64 "</UsageCount>\n",
> +    smp_lock->usage_count
> +  );
> +  update_retval(ctx, rv);
> +
> +  indent(ctx, 2);
> +  rv = (*printf_func)(
> +    printf_arg,
> +    "<TotalSectionTime unit=\"ns\">%" PRIu64 "</TotalSectionTime>\n",
> +    smp_lock->total_section_time
> +  );
> +  update_retval(ctx, rv);
> +
> +  for (i = 0; i < RTEMS_PROFILING_SMP_LOCK_CONTENTION_COUNTS; ++i) {
> +    indent(ctx, 2);
> +    rv = (*printf_func)(
> +      printf_arg,
> +      "<ContentionCount initialQueueLength=\"%zu\">%" PRIu64 "</ContentionCount>\n",
> +      i,
> +      smp_lock->contention_counts[i]
> +    );
> +    update_retval(ctx, rv);
> +  }
> +
> +  indent(ctx, 1);
> +  rv = (*printf_func)(
> +    printf_arg,
> +    "</SMPLockProfilingReport>\n"
> +  );
> +  update_retval(ctx, rv);
> +}
> +
>  static void report(void *arg, const rtems_profiling_data *data)
>  {
>    context *ctx = arg;
> @@ -136,6 +203,9 @@ static void report(void *arg, const rtems_profiling_data *data)
>      case RTEMS_PROFILING_PER_CPU:
>        report_per_cpu(ctx, &data->per_cpu);
>        break;
> +    case RTEMS_PROFILING_SMP_LOCK:
> +      report_smp_lock(ctx, &data->smp_lock);
> +      break;
>    }
>  }
>
> --
> 1.7.7
>
> _______________________________________________
> rtems-devel mailing list
> rtems-devel at rtems.org
> http://www.rtems.org/mailman/listinfo/rtems-devel