Seeing what process and interrupts are competing with a process for the cpu

Seeing what process and interrupts are competing with a process for the cpu

[William Cohen]

[-- Attachment #1: Type: text/plain, Size: 669 bytes --]

This week I was playing with the tracepoints for the scheduler and interrupts to see if I could generate a couple scripts to give people an idea what other processes and irq are using the processor (and competing for the processor). Both scripts show the number of times the process has migrated between cpus and the distribution of time on and off the cpu. The cycle_thief.stp script shows the pid for the processes and the number of times those processes run while the process of interest is not running on the particular cpu. The irq_thief_new.stp shows statistics on the irq that interrupt the running cpu.

Any comments on the scripts would be appreciated.

-Will

[-- Attachment #2: cycle_thief.stp --]
[-- Type: text/plain, Size: 1624 bytes --]

#! /usr/bin/env stap
# Copyright (C) 2010 Red Hat, Inc.
# Write by William Cohen <wcohen@redhat.com>
#
# cycle_theif provide the following information for a specified pid:
#   Number of times the task is migrated to another cpu
#   How long the task is scheduled on and off a processor.
#   task pid that run with the task is scheduled off the processor
#
#
# Run the script with:
#   stap cycle_thief.stp -x pid
#
# control-c to exit data collection

global last_cpu = -1
global pid_on, pid_off, migrated
global time_on, time_off
global cycle_thief

probe kernel.trace("sched_switch") {
  t = gettimeofday_us(); c = cpu();
  if ($prev->pid == target() && $next->pid != target()) {
    /* being switched out */
    pid_off = t; last_cpu = c;
    if (pid_on) time_on <<< pid_off - pid_on;
  } else if ($prev->pid != target() && $next->pid == target()) {
    /* being switched in */
    pid_on = t;
    if (pid_off) time_off <<< pid_on - pid_off;
    if (c != last_cpu) ++migrated;
  }
  /* watch what other processes scheduled while pid off */
  if (pid_off > pid_on && c == last_cpu) {
    cycle_thief[$next->pid] <<< 1;
  }
}

probe end {
  printf("\n")
  printf("task %d migrated: %d\n", target(), migrated)
  if (@count(time_on)) {
    printf("\n")
    printf("task %d on processor (us):\n", target())
    print(@hist_log(time_on));
  }
  if (@count(time_off)) {
    printf("\n")
    printf("task %d off processor (us)\n", target())
      print(@hist_log(time_off));
  }

  printf("other pids taking processor from task %d\n", target())
  foreach (p in cycle_thief-)
    printf("%6d %10d\n", p, @count(cycle_thief[p]))
}

[-- Attachment #3: irq_thief_new.stp --]
[-- Type: text/plain, Size: 2305 bytes --]

#! /usr/bin/env stap
# Copyright (C) 2010 Red Hat, Inc.
# Write by William Cohen <wcohen@redhat.com>
#
# cycle_thief provide the following information for a specified pid:
#   Number of times the task is migrated to another cpu
#   How long the task is scheduled on and off a processor.
#   task pid that run with the task is scheduled off the processor
#
#
# Run the script with:
#   stap irq_thief.stp -x pid
#
# control-c to exit data collection

global last_cpu = -1
global pid_on, pid_off, migrated
global time_on, time_off
global irq_thief
global irq_entry

probe kernel.trace("sched_switch") {
  t = gettimeofday_us(); c = cpu();
  if ($prev->pid == target() && $next->pid != target()) {
    /* being switched out */
    pid_off = t; last_cpu = c;
    if (pid_on) time_on <<< pid_off - pid_on;
  } else if ($prev->pid != target() && $next->pid == target()) {
    /* being switched in */
    pid_on = t;
    if (pid_off) time_off <<< pid_on - pid_off;
    if (c != last_cpu) ++migrated;
  }
}


/* what for interrupts while process is running */
probe kernel.trace("irq_handler_entry")!,
      kernel.trace("irq_entry")
{
  t = gettimeofday_us(); c = cpu();
  i = @defined($irq) ? $irq : $id;
  /* watch what irq run while pid is running */
  if (pid_on > pid_off && c == last_cpu) {
    irq_entry[i] = t
  }
}


probe kernel.trace("irq_handler_exit")!,
      kernel.trace("irq_exit")
{
  i = @defined($irq) ? $irq : $id;
  t = gettimeofday_us(); c = cpu(); irqt=irq_entry[i]
  /* watch what irq run while pid is running */
  if (pid_on > pid_off && c == last_cpu &&  irqt) {
     irq_thief[i] <<< t- irqt;
     delete irq_entry[i]
  }
}


probe end {
  printf("\n")
  printf("task %d migrated: %d\n", target(), migrated)
  if (@count(time_on)) {
    printf("\n")
    printf("task %d on processor (us):\n", target())
    print(@hist_log(time_on));
  }
  if (@count(time_off)) {
    printf("\n")
    printf("task %d off processor (us)\n", target())
      print(@hist_log(time_off));
  }

  printf("irq taking processor from task %d\n", target())

 printf("%6s %10s %10s %10s %10s\n", "irq", "count",
      "min(us)", "avg(us)", "max(us)")
  foreach (p in irq_thief-)
    printf("%6d %10d %10d %10d %10d\n", p, @count(irq_thief[p]),
      @min(irq_thief[p]), @avg(irq_thief[p]), @max(irq_thief[p]))
}