Analyze sched_switch ftrace data with vcd viewer

Analyze sched_switch ftrace data with vcd viewer

[Herman ten Brugge]

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

I have written some code to convert the ascii sched_switch output to
vcd format (value change data). Now it is possible to view the context
switches in a vcd viewer. I personally use gtkwave because it is free
and is present in the fedora repository.
To use this program first make a ftrace file with something like:

mount -t debugfs debugfs /debug
echo sched_switch > /debug/tracing/current_tracer
echo 1 > /debug/tracing/tracing_enabled
sleep 10
echo 0 > /debug/tracing/tracing_enabled
cat /debug/tracing/trace > /tmp/trace.txt

Now convert the ascii data and start the viewer:

sched_switch /tmp/trace.txt /tmp/trace.vcd
gtkwave /tmp/trace.vcd

I use the following definitions in the vcd file:
Z   tri state signal (no cpu assigned)
U   undefined (wake up is done waiting for a cpu to become ready)
0/1 binary encoded cpu number
L/H binary encoded cpu number with priority inheritance

De signal names are displayed as:
program_name_as_in_trace_file#priority#processor_load
The priority is:
idle for the idle process
r1..r99 for real time processes
n-19..20 for nice processes

I find this much easier to use then the ascii file that is produced by 
the kernel.

    Herman.

[-- Attachment #2: sched_switch.c --]
[-- Type: text/plain, Size: 17101 bytes --]

#include <stdio.h>
#include <stdlib.h>
#include <string.h>

typedef struct sched_switch_struct
{
  unsigned int program_id;
  unsigned int from_cpu;
  double time;
  unsigned int from_pid;
  unsigned int from_prio;
  unsigned int from_state_id;
  unsigned int wakeup_id;
  unsigned int to_cpu;
  unsigned int to_pid;
  unsigned int to_prio;
  unsigned int to_state_id;
} sched_switch_type;

typedef struct program_struct
{
  char *name;
  double time;
  unsigned int task;
  unsigned int prio;
  unsigned int idle_task;
  char *tag;
  unsigned int running;
  double last_time;
  double max_time;
  double max_pos;
} program_type;

static void
print_help (const char *programname)
{
  printf ("Usage: %s [options] input output\n", programname);
  printf ("       -m  : output in matlab format\n");
  printf ("       -v  : output in vcd format (default)\n");
  printf ("       -p  : print priority inheritance lines\n");
  printf ("       -s  : print max scheduling delay\n");
  printf ("       -h  : print this help\n");
  exit (0);
}

int
main (int argc, char **argv)
{
  enum
  { VCD, MATLAB } output = VCD;
  unsigned int priority_inheritance = 0;
  unsigned int max_sched_delay = 0;
  char *infilename = NULL;
  char *outfilename = NULL;
  unsigned int i;
  unsigned int j;
  unsigned int n;
  unsigned int last_comment = 0;
  FILE *fpi;
  FILE *fpo;
  unsigned int max_cpu = 0;
  unsigned int last_max_cpu = 0;
  unsigned int *first = NULL;
  double *last_time = NULL;
  unsigned int nof_bits = 0;
  unsigned int program_id;
  unsigned int from_cpu;
  double time;
  unsigned int from_pid;
  unsigned int from_prio;
  unsigned int from_state_id;
  unsigned int wakeup_id;
  unsigned int to_cpu;
  unsigned int to_pid;
  unsigned int to_prio;
  unsigned int to_state_id;
  char line[1000];
  char array[1000];
  char program_name[1000];
  char from_state[1000];
  char to_state[1000];
  char wakeup_str[1000];
  unsigned int n_program = 0;
  program_type *program = NULL;
  unsigned int n_state = 0;
  char **state = NULL;
  unsigned int n_wakeup = 0;
  char **wakeup = NULL;
  unsigned int n_sched_switch = 0;
  unsigned int m_sched_switch = 0;
  sched_switch_type *sched_switch = NULL;

  for (i = 1; i < (unsigned int) argc; i++) {
    if (argv[i][0] == '-') {
      switch (argv[i][1]) {
      case 'm':
	output = MATLAB;
	break;
      case 'v':
	output = VCD;
	break;
      case 'p':
	priority_inheritance = 1;
	break;
      case 's':
	max_sched_delay = 1;
	break;
      case 'h':
      default:
	print_help (argv[0]);
	return (0);
      }
    }
    else if (infilename == NULL) {
      infilename = argv[i];
    }
    else if (outfilename == NULL) {
      outfilename = argv[i];
    }
  }
  if (infilename == NULL || outfilename == NULL) {
    print_help (argv[0]);
    return (0);
  }
  fpi = fopen (infilename, "r");
  if (fpi == NULL) {
    fprintf (stderr, "Cannot open filename %s\n", infilename);
    return 1;
  }
  fpo = fopen (outfilename, "w");
  if (fpo == NULL) {
    fprintf (stderr, "Cannot create filename %s\n", outfilename);
    return 1;
  }
  while (fgets (line, sizeof (line), fpi) != NULL) {
    if (line[0] == '#') {
      last_comment = n_sched_switch;
    }
    to_cpu = (unsigned int) -1;
    if (sscanf
	(line, " %s [ %u ] %lf : %u : %u : %s %s %u : %u : %s ", program_name,
	 &from_cpu, &time, &from_pid, &from_prio, from_state, wakeup_str,
	 &to_pid, &to_prio, to_state) == 10 ||
	sscanf (line, " %s [ %u ] %lf : %u : %u : %s %s [ %u ] %u : %u : %s ",
		program_name, &from_cpu, &time, &from_pid, &from_prio,
		from_state, wakeup_str, &to_cpu, &to_pid, &to_prio,
		to_state) == 11) {
      if (to_cpu == (unsigned int) -1) {
	/* incorrect but we have to set something */
	to_cpu = from_cpu;
      }
      if (from_cpu > max_cpu) {
	max_cpu = from_cpu;
      }
      if (to_cpu > max_cpu) {
	max_cpu = to_cpu;
      }
      if (first == NULL || max_cpu != last_max_cpu) {
	first =
	  (unsigned int *) realloc (first,
				    (max_cpu + 1) * sizeof (unsigned int));
	last_time =
	  (double *) realloc (last_time, (max_cpu + 1) * sizeof (double));
	if (first == NULL || last_time == NULL) {
	  fprintf (stderr, "Cannot malloc\n");
	  return 1;
	}
	for (i = last_max_cpu; i <= max_cpu; i++) {
	  /* 2 because first time is not allways correct */
	  first[i] = 2;
	  last_time[i] = 0;
	}
	last_max_cpu = max_cpu;
      }
      for (program_id = 0; program_id < n_program; program_id++) {
	if (strcmp (program[program_id].name, program_name) == 0) {
	  break;
	}
      }
      if (program_id == n_program) {
	program =
	  (program_type *) realloc (program,
				    (n_program + 1) * sizeof (program_type));
	if (program == NULL) {
	  fprintf (stderr, "Cannot malloc\n");
	  return 1;
	}
	program[n_program].name = strdup (program_name);
	program[n_program].time = 0;
	program[n_program].task = from_pid;
	program[n_program].prio = 0;
	program[n_program].idle_task = strcmp (program_name, "<idle>-0") == 0;
	program[n_program].tag = NULL;
	if (program[n_program++].name == NULL) {
	  fprintf (stderr, "Cannot malloc\n");
	  return 1;
	}
      }
      for (from_state_id = 0; from_state_id < n_state; from_state_id++) {
	if (strcmp (state[from_state_id], from_state) == 0) {
	  break;
	}
      }
      if (from_state_id == n_state) {
	state = (char **) realloc (state, (n_state + 1) * sizeof (char *));
	if (state == NULL) {
	  fprintf (stderr, "Cannot malloc\n");
	  return 1;
	}
	state[n_state] = strdup (from_state);
	if (state[n_state++] == NULL) {
	  fprintf (stderr, "Cannot malloc\n");
	  return 1;
	}
      }
      for (to_state_id = 0; to_state_id < n_state; to_state_id++) {
	if (strcmp (state[to_state_id], to_state) == 0) {
	  break;
	}
      }
      if (to_state_id == n_state) {
	state = (char **) realloc (state, (n_state + 1) * sizeof (char *));
	if (state == NULL) {
	  fprintf (stderr, "Cannot malloc\n");
	  return 1;
	}
	state[n_state] = strdup (to_state);
	if (state[n_state++] == NULL) {
	  fprintf (stderr, "Cannot malloc\n");
	  return 1;
	}
      }
      for (wakeup_id = 0; wakeup_id < n_wakeup; wakeup_id++) {
	if (strcmp (wakeup[wakeup_id], wakeup_str) == 0) {
	  break;
	}
      }
      if (wakeup_id == n_wakeup) {
	wakeup = (char **) realloc (wakeup, (n_wakeup + 1) * sizeof (char *));
	if (wakeup == NULL) {
	  fprintf (stderr, "Cannot malloc\n");
	  return 1;
	}
	wakeup[n_wakeup] = strdup (wakeup_str);
	if (wakeup[n_wakeup++] == NULL) {
	  fprintf (stderr, "Cannot malloc\n");
	  return 1;
	}
      }
      if (n_sched_switch >= m_sched_switch) {
	sched_switch =
	  (sched_switch_type *) realloc (sched_switch,
					 (m_sched_switch +
					  1024) * sizeof (sched_switch_type));
	if (sched_switch == NULL) {
	  fprintf (stderr, "Cannot malloc\n");
	  return 1;
	}
	m_sched_switch += 1024;
      }
      sched_switch[n_sched_switch].program_id = program_id;
      sched_switch[n_sched_switch].from_cpu = from_cpu;
      sched_switch[n_sched_switch].time = time;
      sched_switch[n_sched_switch].from_pid = from_pid;
      sched_switch[n_sched_switch].from_prio = from_prio;
      sched_switch[n_sched_switch].from_state_id = from_state_id;
      sched_switch[n_sched_switch].wakeup_id = wakeup_id;
      sched_switch[n_sched_switch].to_cpu = to_cpu;
      sched_switch[n_sched_switch].to_pid = to_pid;
      sched_switch[n_sched_switch].to_prio = to_prio;
      sched_switch[n_sched_switch].to_state_id = to_state_id;
      n_sched_switch++;
      if (wakeup_str[0] == '=') {
	if (first[from_cpu] == 0) {
	  program[program_id].time += time - last_time[from_cpu];
	}
	else if (first[from_cpu]) {
	  first[from_cpu]--;
	}
	last_time[from_cpu] = time;
      }
    }
  }
  for (nof_bits = 31; nof_bits > 0; nof_bits--) {
    if (max_cpu & (1 << nof_bits)) {
      break;
    }
  }
  time = 0;
  for (i = 0; i < n_program; i++) {
    time += program[i].time;
  }
  if (time == 0) {
    time = 1;
  }
  for (i = 0; i < n_sched_switch; i++) {
    for (j = 0; j < n_program; j++) {
      if (sched_switch[i].from_pid == program[j].task) {
	break;
      }
    }
    sched_switch[i].from_pid = j == n_program ? 0 : j;
    for (j = 0; j < n_program; j++) {
      if (sched_switch[i].to_pid == program[j].task) {
	break;
      }
    }
    sched_switch[i].to_pid = j == n_program ? 0 : j;
  }
  for (i = 0; i < n_program; i++) {
    /* Take the highest priority and hope that this is the correct one. */
    /* It might be incorrect due to priority inheritance. */
    n = 0;
    for (j = 0; j < n_sched_switch; j++) {
      if (sched_switch[j].from_pid == i) {
	if (sched_switch[j].from_prio > n) {
	  n = sched_switch[j].from_prio;
	}
      }
      if (sched_switch[j].to_pid == i) {
	if (sched_switch[j].to_prio > n) {
	  n = sched_switch[j].to_prio;
	}
      }
    }
    program[i].prio = n;
    if (program[i].prio < 100) {
      sprintf (line, "%s#r%u#%d", program[i].name, 99 - program[i].prio,
	       (int) (100.0 * program[i].time / time + 0.5));
    }
    else if (program[i].prio == 140) {
      sprintf (line, "%s#idle#%d", program[i].name,
	       (int) (100.0 * program[i].time / time + 0.5));
    }
    else {
      sprintf (line, "%s#n%d#%d", program[i].name,
	       (int) (120 - program[i].prio),
	       (int) (100.0 * program[i].time / time + 0.5));
    }
    free (program[i].name);
    program[i].name = strdup (line);
    if (program[i].name == NULL) {
      fprintf (stderr, "Cannot malloc\n");
      return 1;
    }
    if (priority_inheritance) {
      for (n = 0; n < n_sched_switch; n++) {
	if (sched_switch[n].from_pid == i &&
	    sched_switch[n].from_prio != program[i].prio) {
	  printf ("%.6f %.0fus %s %u %u\n", sched_switch[n].time,
		  (sched_switch[n].time - sched_switch[0].time) * 1e6,
		  program[i].name, sched_switch[n].from_prio,
		  program[i].prio);
	}
	if (sched_switch[n].to_pid == i &&
	    sched_switch[n].to_prio != program[i].prio) {
	  printf ("%.6f %.0fus %s %u %u\n", sched_switch[n].time,
		  (sched_switch[n].time - sched_switch[0].time) * 1e6,
		  program[i].name, sched_switch[n].to_prio, program[i].prio);
	}
      }
    }
  }
  if (max_sched_delay) {
    for (i = 0; i < n_program; i++) {
      program[i].running = 0;
      program[i].last_time = 0;
      program[i].max_time = 0;
      program[i].max_pos = 0;
    }
    for (i = last_comment; i < n_sched_switch; i++) {
      if (wakeup[sched_switch[i].wakeup_id][0] == '=') {
	if (program[sched_switch[i].to_pid].running == (unsigned int) -2) {
	  if (sched_switch[i].time -
	      program[sched_switch[i].to_pid].last_time >
	      program[sched_switch[i].to_pid].max_time) {
	    program[sched_switch[i].to_pid].max_time =
	      sched_switch[i].time -
	      program[sched_switch[i].to_pid].last_time;
	    program[sched_switch[i].to_pid].max_pos = sched_switch[i].time;
	  }
	}
	program[sched_switch[i].from_pid].running = (unsigned int) -1;
	program[sched_switch[i].to_pid].running = sched_switch[i].to_cpu;
      }
      else if (wakeup[sched_switch[i].wakeup_id][0] == '+') {
	program[sched_switch[i].to_pid].running = (unsigned int) -2;
	program[sched_switch[i].to_pid].last_time = sched_switch[i].time;
      }
    }
    for (i = 0; i < n_program; i++) {
      if (program[i].max_time != 0.0) {
	printf ("%8.6f %8.6f %.0fus %s\n", program[i].max_time,
		program[i].max_pos,
		(program[i].max_pos - sched_switch[0].time) * 1e6,
		program[i].name);
      }
    }
  }
  if (output == MATLAB) {
    for (i = 0; i < n_program; i++) {
      fprintf (fpo,
	       "program(%u).str = '%s'; program_time(%u) = %.6f; "
	       "cpuload(%u) = %.6f; program_task(%u) = %u;\n", i + 1,
	       program[i].name, i + 1, program[i].time, i + 1,
	       100.0 * program[i].time / time, i + 1, program[i].task);
    }
    for (i = 0; i < n_state; i++) {
      fprintf (fpo, "state(%u).str = '%s';\n", i + 1, state[i]);
    }
    for (i = 0; i < n_wakeup; i++) {
      fprintf (fpo, "wakeup(%u).str = '%s';\n", i + 1, wakeup[i]);
    }
    fprintf (fpo, "program_id = { ");
    for (i = 0; i < n_sched_switch; i++) {
      fprintf (fpo, "%u ", sched_switch[i].program_id);
    }
    fprintf (fpo, "};\n");
    fprintf (fpo, "from_cpu = { ");
    for (i = 0; i < n_sched_switch; i++) {
      fprintf (fpo, "%u ", sched_switch[i].from_cpu);
    }
    fprintf (fpo, "};\n");
    fprintf (fpo, "time = { ");
    for (i = 0; i < n_sched_switch; i++) {
      fprintf (fpo, "%.6f ", sched_switch[i].time);
    }
    fprintf (fpo, "};\n");
    fprintf (fpo, "from_pid = { ");
    for (i = 0; i < n_sched_switch; i++) {
      fprintf (fpo, "%u ", sched_switch[i].from_pid);
    }
    fprintf (fpo, "};\n");
    fprintf (fpo, "from_prio = { ");
    for (i = 0; i < n_sched_switch; i++) {
      fprintf (fpo, "%u ", sched_switch[i].from_prio);
    }
    fprintf (fpo, "};\n");
    fprintf (fpo, "from_state_id = { ");
    for (i = 0; i < n_sched_switch; i++) {
      fprintf (fpo, "%u ", sched_switch[i].from_state_id);
    }
    fprintf (fpo, "};\n");
    fprintf (fpo, "wakeup_id = { ");
    for (i = 0; i < n_sched_switch; i++) {
      fprintf (fpo, "%u ", sched_switch[i].wakeup_id);
    }
    fprintf (fpo, "};\n");
    fprintf (fpo, "to_cpu = { ");
    for (i = 0; i < n_sched_switch; i++) {
      fprintf (fpo, "%u ", sched_switch[i].to_cpu);
    }
    fprintf (fpo, "};\n");
    fprintf (fpo, "to_pid = { ");
    for (i = 0; i < n_sched_switch; i++) {
      fprintf (fpo, "%u ", sched_switch[i].to_pid);
    }
    fprintf (fpo, "};\n");
    fprintf (fpo, "to_prio = { ");
    for (i = 0; i < n_sched_switch; i++) {
      fprintf (fpo, "%u ", sched_switch[i].to_prio);
    }
    fprintf (fpo, "};\n");
    fprintf (fpo, "to_state_id = { ");
    for (i = 0; i < n_sched_switch; i++) {
      fprintf (fpo, "%u ", sched_switch[i].to_state_id);
    }
    fprintf (fpo, "};\n");
    fprintf (fpo,
	     "save -v7 sched_switch.mat program program_time program_task "
	     "cpuload state wakeup program_id from_cpu time from_pid "
	     "from_prio from_state_id wakeup_id to_cpu to_pid to_prio "
	     "to_state_id;\n");
  }
  else {
    fprintf (fpo, "$timescale 1us $end\n");
    fprintf (fpo, "$scope module sched_switch $end\n");
    for (i = 0; i < n_program; i++) {
      j = 0;
      n = i;
      do {
	line[j++] = (n % 94) + 33;
	n = n / 94;
      } while (n != 0);
      line[j] = '\0';
      array[0] = '\0';
      if (nof_bits > 0) {
	sprintf (array, "[%u:0] ", nof_bits);
      }
      fprintf (fpo, "$var wire %u %s %s %s$end\n", nof_bits + 1, line,
	       program[i].name, array);
      program[i].tag = strdup (line);
      if (program[i].tag == NULL) {
	fprintf (stderr, "Cannot malloc\n");
	return 1;
      }
    }
    fprintf (fpo, "$upscope $end\n");
    fprintf (fpo, "$enddefinitions $end\n");
    /* Z   tri-state signal (no cpu assigned) */
    /* U   undefined (wakeup is done waiting for cpu to become ready) */
    /* 0/1 binary encoded cpu number */
    /* L/H binary encoded cpu number with priority inheritance */
    fprintf (fpo, "#0\n");
    for (i = 0; i < n_program; i++) {
      if (nof_bits > 0) {
	fprintf (fpo, "b");
      }
      for (j = 0; j <= nof_bits; j++) {
	fprintf (fpo, "Z");
      }
      if (nof_bits > 0) {
	fprintf (fpo, " ");
      }
      fprintf (fpo, "%s\n", program[i].tag);
    }
    for (i = 0; i < n_sched_switch; i++) {
      if (sched_switch[i].time - sched_switch[0].time != 0) {
	if (wakeup[sched_switch[i].wakeup_id][0] == '=') {
	  if (i == 0 || sched_switch[i].time != sched_switch[i - 1].time) {
	    fprintf (fpo, "#%.0f\n",
		     (sched_switch[i].time - sched_switch[0].time) * 1e6);
	  }
	  if (sched_switch[i].from_pid != sched_switch[i].to_pid) {
	    if (nof_bits > 0) {
	      fprintf (fpo, "b");
	    }
	    for (j = 0; j <= nof_bits; j++) {
	      fprintf (fpo, "Z");
	    }
	    if (nof_bits > 0) {
	      fprintf (fpo, " ");
	    }
	    fprintf (fpo, "%s\n", program[sched_switch[i].from_pid].tag);
	  }
	  if (nof_bits > 0) {
	    fprintf (fpo, "b");
	  }
	  if (sched_switch[i].to_prio != program[sched_switch[i].to_pid].prio) {
	    for (j = 0; j <= nof_bits; j++) {
	      fprintf (fpo, "%c",
		       "LH"[(sched_switch[i].to_cpu >> (nof_bits - j)) & 1]);
	    }
	  }
	  else {
	    for (j = 0; j <= nof_bits; j++) {
	      fprintf (fpo, "%c",
		       "01"[(sched_switch[i].to_cpu >> (nof_bits - j)) & 1]);
	    }
	  }
	  if (nof_bits > 0) {
	    fprintf (fpo, " ");
	  }
	  fprintf (fpo, "%s\n", program[sched_switch[i].to_pid].tag);
	}
	else if (wakeup[sched_switch[i].wakeup_id][0] == '+') {
	  if (i == 0 || sched_switch[i].time != sched_switch[i - 1].time) {
	    fprintf (fpo, "#%.0f\n",
		     (sched_switch[i].time - sched_switch[0].time) * 1e6);
	  }
	  if (nof_bits > 0) {
	    fprintf (fpo, "b");
	  }
	  for (j = 0; j <= nof_bits; j++) {
	    fprintf (fpo, "X");
	  }
	  if (nof_bits > 0) {
	    fprintf (fpo, " ");
	  }
	  fprintf (fpo, "%s\n", program[sched_switch[i].to_pid].tag);
	}
      }
    }
  }
  fclose (fpi);
  fclose (fpo);
  free (first);
  free (last_time);
  for (i = 0; i < n_program; i++) {
    free (program[i].name);
    free (program[i].tag);
  }
  free (program);
  free (state);
  free (wakeup);
  free (sched_switch);
  return 0;
}

Re: Analyze sched_switch ftrace data with vcd viewer

[Herman ten Brugge]

  Carsten Emde wrote:
> Herman,
>
>   
>> I have written some code to convert the ascii sched_switch output to
>> vcd format (value change data). Now it is possible to view the context
>> switches in a vcd viewer. [..]
>>     
> That's superb, works great. Thanks a lot! If you agree, I would like to
> write a News Article on our Website on it.
>
> I have one question though: Under which license are you willing to make
> the source code available? GPL? If so, would you mind to put the GPL
> license text on top of your source code? It makes things easier.
>   
Great that some one likes the tool all ready. I forgot to  put the 
license in. The header of the
source should be:

/*
  sched_switch - Convert sched_switch ftrace data to vcd or matlab

   Copyright (C) 2009 Herman ten Brugge <hermantenbrugge@home.nl>

   This program is free software; you can redistribute it and/or modify
   it under the terms of the GNU General Public License as published by
   the Free Software Foundation; either version 2 of the License, or
   (at your option) any later version.

   This program is distributed in the hope that it will be useful,
   but WITHOUT ANY WARRANTY; without even the implied warranty of
   MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
   GNU General Public License for more details.

   You should have received a copy of the GNU General Public License
   along with this program; if not, write to the Free Software
   Foundation, Inc., 51 Franklin Street, Fifth Floor, Boston, MA  02110-1301
   USA */


    Herman.

Re: Analyze sched_switch ftrace data with vcd viewer

[Carsten Emde]

Herman,

>>> I have written some code to convert the ascii sched_switch output to
>>> vcd format (value change data). Now it is possible to view the context
>>> switches in a vcd viewer. [..]
>> That's superb, works great. Thanks a lot! If you agree, I would like to
>> write a News Article on our Website on it.
Well, now that my private email has been made public and, no doubt,
*everybody* is impatiently waiting for the announced News Article, here
is it: http://www.osadl.org/Single-View.111+M5d51b7830c8.0.html

	Carsten.

Re: Analyze sched_switch ftrace data with vcd viewer

[GeunSik Lim]

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

On Fri, Jun 5, 2009 at 3:58 AM, Herman ten
Brugge<hermantenbrugge@home.nl> wrote:
> I have written some code to convert the ascii sched_switch output to
> vcd format (value change data). Now it is possible to view the context
> switches in a vcd viewer. I personally use gtkwave because it is free
> and is present in the fedora repository.
> To use this program first make a ftrace file with something like:


Hi Herman ten Brugge,

Thansk you for sharing your code to visualize  sched_switch ftrace data
with vcd viewer like GTKWave.

This is my H/W requirements.
* core: Core2 Quad Q9300
* Memory: DDR3G
* Kernel: 2.6.29-3.fc10.i686.smp kernel

I tested in my fedora 9 distribution with below methods.
But I can not show normal result using "#> gtkware trace.vcd" command.
* screenshot : http://blogfiles5.naver.net/data43/2009/6/12/228/gtkwave-vcd-20090609.1503-invain.png


It seems that you have to update your code for stablization and
functions continually.


F-Geunsik#> wget http://www.osadl.org/uploads/media/sched_switch-0.1.tgz
F-Geunsik#> tar -zxvf sched_switch-0.1.tgz
F-Geunsik#> cd sched_switch-0.1
F-Geunsik#> make
F-Geunsik#> cp ./sched_switch /usr/bin/
F-Geunsik#> cd /syskerneldebug/tracing/
F-Geunsik#> echo sched_switch >current_tracer
F-Geunsik#> echo 1 >tracing_enable
F-Geunsik#> chrt -f 20 sleep 5
F-Geunsik#> cyclictest -t 5 -p 99 -d 60 -i 1000
F-Geunsik#> echo 0 >tracing_enable
F-Geunsik#> cat trace >/tmp/trace.txt
F-Geunsik#> /usr/bin/sched_switch /tmp/trace.txt /tmp/trace.vcd
F-Geunsik#> yum install gtkwave
F-Geunsik#> gtkwave /tmp/trace.vcd




-- 
Regards,
GeunSik Lim ( Samsung Electronics )
Blog : http://blog.naver.com/invain/
e-Mail: geunsik.lim@samsung.com
           leemgs@gmail.com , leemgs1@gmail.com
--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html
Please read the FAQ at  http://www.tux.org/lkml/

[-- Attachment #2: trace.txt --]
[-- Type: text/plain, Size: 4058 bytes --]

# tracer: sched_switch
#
#           TASK-PID    CPU#    TIMESTAMP  FUNCTION
#              | |       |          |         |
##### CPU 2 buffer started ####
          <idle>-0     [002] 4154503800.848883:      0:140:R   + [002] 10987:  2:S
          <idle>-0     [002] 4154503800.848884:      0:140:R ==> [002] 10987:  2:R
      cyclictest-10987 [002] 4154503800.848886:  10987:  2:S ==> [002]     0:140:R
          <idle>-0     [002] 4154503800.849031:      0:140:R   + [002] 10987:  2:S
          <idle>-0     [002] 4154503800.849033:      0:140:R ==> [002] 10987:  2:R
      cyclictest-10987 [002] 4154503800.849035:  10987:  2:S ==> [002]     0:140:R
          <idle>-0     [002] 4154503800.849181:      0:140:R   + [002] 10987:  2:S
          <idle>-0     [002] 4154503800.849182:      0:140:R ==> [002] 10987:  2:R
      cyclictest-10987 [002] 4154503800.849185:  10987:  2:S ==> [002]     0:140:R
          <idle>-0     [002] 4154503800.849331:      0:140:R   + [002] 10987:  2:S
          <idle>-0     [002] 4154503800.849332:      0:140:R ==> [002] 10987:  2:R
      cyclictest-10987 [002] 4154503800.849335:  10987:  2:S ==> [002]     0:140:R
          <idle>-0     [002] 4154503800.849480:      0:140:R   + [002] 10987:  2:S
          <idle>-0     [002] 4154503800.849481:      0:140:R ==> [002] 10987:  2:R
      cyclictest-10987 [002] 4154503800.849484:  10987:  2:S ==> [002]     0:140:R
          <idle>-0     [002] 4154503800.849630:      0:140:R   + [002] 10987:  2:S
          <idle>-0     [002] 4154503800.849631:      0:140:R ==> [002] 10987:  2:R
      cyclictest-10987 [002] 4154503800.849634:  10987:  2:S ==> [002]     0:140:R
          <idle>-0     [002] 4154503800.849781:      0:140:R   + [002] 10987:  2:S
          <idle>-0     [002] 4154503800.849782:      0:140:R ==> [002] 10987:  2:R
      cyclictest-10987 [002] 4154503800.849785:  10987:  2:S ==> [002]     0:140:R
          <idle>-0     [002] 4154503800.849930:      0:140:R   + [002] 10987:  2:S
          <idle>-0     [002] 4154503800.849931:      0:140:R ==> [002] 10987:  2:R
      cyclictest-10987 [002] 4154503800.849934:  10987:  2:S ==> [002]     0:140:R
          <idle>-0     [002] 4154503800.850079:      0:140:R   + [002] 10987:  2:S
          <idle>-0     [002] 4154503800.850081:      0:140:R ==> [002] 10987:  2:R
      cyclictest-10987 [002] 4154503800.850083:  10987:  2:S ==> [002]     0:140:R
          <idle>-0     [002] 4154503800.850229:      0:140:R   + [002] 10987:  2:S
          <idle>-0     [002] 4154503800.850231:      0:140:R ==> [002] 10987:  2:R
      cyclictest-10987 [002] 4154503800.850233:  10987:  2:S ==> [002]     0:140:R
          <idle>-0     [002] 4154503800.850379:      0:140:R   + [002] 10987:  2:S
          <idle>-0     [002] 4154503800.850381:      0:140:R ==> [002] 10987:  2:R
      cyclictest-10987 [002] 4154503800.850383:  10987:  2:S ==> [002]     0:140:R
          <idle>-0     [002] 4154503800.850528:      0:140:R   + [002] 10987:  2:S
          <idle>-0     [002] 4154503800.850530:      0:140:R ==> [002] 10987:  2:R
      cyclictest-10987 [002] 4154503800.850532:  10987:  2:S ==> [002]     0:140:R
          <idle>-0     [002] 4154503800.850678:      0:140:R   + [002] 10987:  2:S
          <idle>-0     [002] 4154503800.850680:      0:140:R ==> [002] 10987:  2:R
      cyclictest-10987 [002] 4154503800.850682:  10987:  2:S ==> [002]     0:140:R
          <idle>-0     [002] 4154503800.850828:      0:140:R   + [002] 10987:  2:S
          <idle>-0     [002] 4154503800.850830:      0:140:R ==> [002] 10987:  2:R
      cyclictest-10987 [002] 4154503800.850833:  10987:  2:S ==> [002]     0:140:R
          <idle>-0     [002] 4154503800.850978:      0:140:R   + [002] 10987:  2:S
          <idle>-0     [002] 4154503800.850980:      0:140:R ==> [002] 10987:  2:R
      cyclictest-10987 [002] 4154503800.850982:  10987:  2:S ==> [002]     0:140:R
          <idle>-0     [002] 4154503800.851128:      0:140:R   + [002] 10987:  2:S
          <idle>-0     [002] 4154503800.851129:      0:140:R ==> [002] 10987:  2:R

[-- Attachment #3: trace.vcd --]
[-- Type: application/x-cdlink, Size: 906 bytes --]

Re: Analyze sched_switch ftrace data with vcd viewer

[Herman ten Brugge]

I tried your vcd file and I can view it with no problems. Did you select 
all signals and then press the insert button in gtkwave?
I run fedora 10 with gtkwave version 'GTKWave Analyzer v3.1.13 
(w)1999-2008 BSI'.

    Herman.


GeunSik Lim wrote:
> On Fri, Jun 5, 2009 at 3:58 AM, Herman ten
> Brugge<hermantenbrugge@home.nl> wrote:
>   
>> I have written some code to convert the ascii sched_switch output to
>> vcd format (value change data). Now it is possible to view the context
>> switches in a vcd viewer. I personally use gtkwave because it is free
>> and is present in the fedora repository.
>> To use this program first make a ftrace file with something like:
>>     
>
>
> Hi Herman ten Brugge,
>
> Thansk you for sharing your code to visualize  sched_switch ftrace data
> with vcd viewer like GTKWave.
>
> This is my H/W requirements.
> * core: Core2 Quad Q9300
> * Memory: DDR3G
> * Kernel: 2.6.29-3.fc10.i686.smp kernel
>
> I tested in my fedora 9 distribution with below methods.
> But I can not show normal result using "#> gtkware trace.vcd" command.
> * screenshot : http://blogfiles5.naver.net/data43/2009/6/12/228/gtkwave-vcd-20090609.1503-invain.png
>
>
> It seems that you have to update your code for stablization and
> functions continually.
>
>
> F-Geunsik#> wget http://www.osadl.org/uploads/media/sched_switch-0.1.tgz
> F-Geunsik#> tar -zxvf sched_switch-0.1.tgz
> F-Geunsik#> cd sched_switch-0.1
> F-Geunsik#> make
> F-Geunsik#> cp ./sched_switch /usr/bin/
> F-Geunsik#> cd /syskerneldebug/tracing/
> F-Geunsik#> echo sched_switch >current_tracer
> F-Geunsik#> echo 1 >tracing_enable
> F-Geunsik#> chrt -f 20 sleep 5
> F-Geunsik#> cyclictest -t 5 -p 99 -d 60 -i 1000
> F-Geunsik#> echo 0 >tracing_enable
> F-Geunsik#> cat trace >/tmp/trace.txt
> F-Geunsik#> /usr/bin/sched_switch /tmp/trace.txt /tmp/trace.vcd
> F-Geunsik#> yum install gtkwave
> F-Geunsik#> gtkwave /tmp/trace.vcd
>
>
>
>
>   

Re: Analyze sched_switch ftrace data with vcd viewer

[Carsten Emde]

Dear GeunSik Lim,

> [..]
> But I can not show normal result using "#> gtkware trace.vcd" command.
> * screenshot : http://blogfiles5.naver.net/data43/2009/6/12/228/gtkwave-vcd-20090609.1503-invain.png
The Quick HOWTO on our download page says:
To select a particular data channel within gtkwave, select sched_switch 
in the top left window and drag and drop the label of the requested 
channel from the bottom left window labeled "Signals" to the drop area 
at the left side of the main wave display area (also labeled "Signals").

Please do so. I have every confidence that it will work.

	Carsten.

Re: Analyze sched_switch ftrace data with vcd viewer

[GeunSik Lim]

On Fri, Jun 12, 2009 at 11:53 PM, Carsten Emde<Carsten.Emde@osadl.org> wrote:
> Dear GeunSik Lim,
>
>> [..]
>> But I can not show normal result using "#> gtkware trace.vcd" command.
>> * screenshot :
>> http://blogfiles5.naver.net/data43/2009/6/12/228/gtkwave-vcd-20090609.1503-invain.png
>
> The Quick HOWTO on our download page says:
> To select a particular data channel within gtkwave, select sched_switch in
> the top left window and drag and drop the label of the requested channel
> from the bottom left window labeled "Signals" to the drop area at the left
> side of the main wave display area (also labeled "Signals").
Thank you for your explanation.
Now is normal.
>
> Please do so. I have every confidence that it will work.
>
>        Carsten.
>



-- 
Regards,
GeunSik Lim ( Samsung Electronics )
Blog : http://blog.naver.com/invain/
e-Mail: geunsik.lim@samsung.com
           leemgs@gmail.com , leemgs1@gmail.com
--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html
Please read the FAQ at  http://www.tux.org/lkml/
--
To unsubscribe from this list: send the line "unsubscribe linux-rt-users" in
the body of a message to majordomo@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html