problems with sched tapset on ubuntu precise 3.2.0

problems with sched tapset on ubuntu precise 3.2.0

[Thiago Manel]

Hi list,

I'm facing the following error when trying to run  testsuite/systemtap.examples/
process/schedtimes.stp script

stap schedtimes.stp -x 2064

Warning: make exited with status: 2
Warning: make exited with status: 2
Warning: make exited with status: 2
Warning: make exited with status: 2
^CWarning: make exited with status: 130
semantic error: no match while resolving probe point
kernel.trace("sched_switch")
Pass 2: analysis failed.  Try again with another '--vp 01' option.

In fact, my installation does not know the "sched_switch" probe point ...

stap -l 'kernel.function("sched_s*")'
kernel.function("sched_set_stop_task@/build/buildd/linux-3.2.0/kernel/sched.c:2205")
kernel.function("sched_setaffinity@/build/buildd/linux-3.2.0/kernel/sched.c:5543")
kernel.function("sched_setscheduler@/build/buildd/linux-3.2.0/kernel/sched.c:5407")
kernel.function("sched_setscheduler_nocheck@/build/buildd/linux-3.2.0/kernel/sched.c:5425")
kernel.function("sched_show@/build/buildd/linux-3.2.0/fs/proc/base.c:1359")
kernel.function("sched_show_task@/build/buildd/linux-3.2.0/kernel/sched.c:5998")
kernel.function("sched_slice@/build/buildd/linux-3.2.0/kernel/sched_fair.c:514")
kernel.function("sched_smt_power_savings_show@/build/buildd/linux-3.2.0/kernel/sched.c:7960")
kernel.function("sched_smt_power_savings_store@/build/buildd/linux-3.2.0/kernel/sched.c:7966")
kernel.function("sched_submit_work@/build/buildd/linux-3.2.0/kernel/sched.c:4473")

I followed the instructions from
http://sourceware.org/systemtap/wiki/SystemtapOnUbuntu and the
simpler, vfs.read probe worked just fine

root@abotoado:~# stap -v -e 'probe vfs.read {printf("readperformed\n"); exit()}'
Pass 1: parsed user script and 77 library script(s) using
92536virt/22580res/2604shr kb, in 60usr/0sys/70real ms.
Pass 2: analyzed script: 1 probe(s), 22 function(s), 3 embed(s), 1
global(s) using 362872virt/144892res/7824shr kb, in
1000usr/210sys/1208real ms.
Pass 3: using cached
/root/.systemtap/cache/14/stap_146e14d355110070f5e702520662db0f_10803.c
Pass 4: using cached
/root/.systemtap/cache/14/stap_146e14d355110070f5e702520662db0f_10803.ko
Pass 5: starting run.
readperformed
Pass 5: run completed in 0usr/10sys/529real ms.


Do you guys have any clue on how to debug this issue ?

A bit of context ...

root@abotoado:~# uname -a
Linux abotoado 3.2.0-23-generic #36-Ubuntu SMP Tue Apr 10 20:39:51 UTC
2012 x86_64 x86_64 x86_64 GNU/Linux

root@abotoado:~# dpkg -l | grep  linux-image-3.2.0-23-generic
ii  linux-image-3.2.0-23-generic           3.2.0-23.36
            Linux kernel image for version 3.2.0 on 64 bit x86 SMP
ii  linux-image-3.2.0-23-generic-dbgsym    3.2.0-23.36
            Linux kernel debug image for version 3.2.0 on 64 bit x86
SMP

Thank you in advance


--
Thiago Emmanuel Pereira da Cunha Silva
-----------------------------------------------
www.lsd.ufcg.edu.br/~thiagoepdc
-----------------------------------------------

Re: problems with sched tapset on ubuntu precise 3.2.0

[David Smith]

On 05/07/2013 10:05 AM, Thiago Manel wrote:
> Hi list,
> 
> I'm facing the following error when trying to run  testsuite/systemtap.examples/
> process/schedtimes.stp script
> 
> stap schedtimes.stp -x 2064
> 
> Warning: make exited with status: 2
> Warning: make exited with status: 2
> Warning: make exited with status: 2
> Warning: make exited with status: 2
> ^CWarning: make exited with status: 130
> semantic error: no match while resolving probe point
> kernel.trace("sched_switch")
> Pass 2: analysis failed.  Try again with another '--vp 01' option.
> 
> In fact, my installation does not know the "sched_switch" probe point ...
> 
> stap -l 'kernel.function("sched_s*")'
> kernel.function("sched_set_stop_task@/build/buildd/linux-3.2.0/kernel/sched.c:2205")
> kernel.function("sched_setaffinity@/build/buildd/linux-3.2.0/kernel/sched.c:5543")
> kernel.function("sched_setscheduler@/build/buildd/linux-3.2.0/kernel/sched.c:5407")
> kernel.function("sched_setscheduler_nocheck@/build/buildd/linux-3.2.0/kernel/sched.c:5425")
> kernel.function("sched_show@/build/buildd/linux-3.2.0/fs/proc/base.c:1359")
> kernel.function("sched_show_task@/build/buildd/linux-3.2.0/kernel/sched.c:5998")
> kernel.function("sched_slice@/build/buildd/linux-3.2.0/kernel/sched_fair.c:514")
> kernel.function("sched_smt_power_savings_show@/build/buildd/linux-3.2.0/kernel/sched.c:7960")
> kernel.function("sched_smt_power_savings_store@/build/buildd/linux-3.2.0/kernel/sched.c:7966")
> kernel.function("sched_submit_work@/build/buildd/linux-3.2.0/kernel/sched.c:4473")

You misread the error message a bit. Here's how the scheduler.cpu_off
probe point is defined:

====
probe scheduler.cpu_off =
	kernel.trace("sched_switch") !,
	kernel.function("context_switch")
{
    name = "cpu_off"
    task_prev = $prev
    task_next = $next
    idle = __is_idle()
}
====

So, that probe point looks for the kernel tracepoint 'sched_switch' or
the kernel function 'context_switch' (if it finds the tracepoint, it
won't bother with the function).

Since you got that error, that means systemtap thinks you don't have either.

Let's test that theory. Try the following commands on your kernel and
see what you get. Your 3.2 kernel should have both (assuming
CONFIG_TRACEPOINTS is on).

# stap -l 'kernel.trace("sched_*")'
# stap -l 'kernel.function("context_switch")'

Is CONFIG_TRACEPOINTS on in your kernel?

-- 
David Smith
dsmith@redhat.com
Red Hat
http://www.redhat.com
256.217.0141 (direct)
256.837.0057 (fax)

Re: problems with sched tapset on ubuntu precise 3.2.0

[Thiago Manel]

Hi David, sorry for the late response

- for the first check, I see an error:

stap -vv -l 'kernel.trace("sched_*")'
Systemtap translator/driver (version 1.6/0.152 non-git sources)
Copyright (C) 2005-2011 Red Hat, Inc. and others
This is free software; see the source for copying conditions.
enabled features: AVAHI LIBSQLITE3 NSS BOOST_SHARED_PTR TR1_UNORDERED_MAP NLS
Created temporary directory "/tmp/stapNw4kVW"
Session arch: x86_64 release: 3.2.0-23-generic
Searched: " /usr/share/systemtap/tapset/x86_64/*.stp ", found: 4, processed: 4
Searched: " /usr/share/systemtap/tapset/*.stp ", found: 73, processed: 73
Pass 1: parsed user script and 77 library script(s) using
84096virt/22508res/2556shr kb, in 60usr/0sys/70real ms.
semantic error: no match while resolving probe point kernel.trace("sched_*")
Pass 2: analyzed script: 0 probe(s), 0 function(s), 0 embed(s), 0
global(s) using 230984virt/23700res/2908shr kb, in
40usr/100sys/125real ms.
Running rm -rf /tmp/stapNw4kVW
Spawn waitpid result (0x0): 0

- whereas for the second one, it succeeds:

 stap -l 'kernel.function("context_switch")'
kernel.function("context_switch@/build/buildd/linux-3.2.0/kernel/sched.c:3287")

Regarding the CONFIG_TRACEPOINTS (I'm not sure I'm looking to the
right place) I have ...

$ cat /sys/kernel/debug/tracing/tracing_enabled
1

$ cat /sys/kernel/debug/tracing/available_tracers
blk function_graph mmiotrace wakeup_rt wakeup function nop

So, no sched_switch there, although ...

$ cat /sys/kernel/debug/tracing/events/sched/sched_switch/enable
1



On Tue, May 7, 2013 at 3:28 PM, David Smith <dsmith@redhat.com> wrote:
> On 05/07/2013 10:05 AM, Thiago Manel wrote:
>> Hi list,
>>
>> I'm facing the following error when trying to run  testsuite/systemtap.examples/
>> process/schedtimes.stp script
>>
>> stap schedtimes.stp -x 2064
>>
>> Warning: make exited with status: 2
>> Warning: make exited with status: 2
>> Warning: make exited with status: 2
>> Warning: make exited with status: 2
>> ^CWarning: make exited with status: 130
>> semantic error: no match while resolving probe point
>> kernel.trace("sched_switch")
>> Pass 2: analysis failed.  Try again with another '--vp 01' option.
>>
>> In fact, my installation does not know the "sched_switch" probe point ...
>>
>> stap -l 'kernel.function("sched_s*")'
>> kernel.function("sched_set_stop_task@/build/buildd/linux-3.2.0/kernel/sched.c:2205")
>> kernel.function("sched_setaffinity@/build/buildd/linux-3.2.0/kernel/sched.c:5543")
>> kernel.function("sched_setscheduler@/build/buildd/linux-3.2.0/kernel/sched.c:5407")
>> kernel.function("sched_setscheduler_nocheck@/build/buildd/linux-3.2.0/kernel/sched.c:5425")
>> kernel.function("sched_show@/build/buildd/linux-3.2.0/fs/proc/base.c:1359")
>> kernel.function("sched_show_task@/build/buildd/linux-3.2.0/kernel/sched.c:5998")
>> kernel.function("sched_slice@/build/buildd/linux-3.2.0/kernel/sched_fair.c:514")
>> kernel.function("sched_smt_power_savings_show@/build/buildd/linux-3.2.0/kernel/sched.c:7960")
>> kernel.function("sched_smt_power_savings_store@/build/buildd/linux-3.2.0/kernel/sched.c:7966")
>> kernel.function("sched_submit_work@/build/buildd/linux-3.2.0/kernel/sched.c:4473")
>
> You misread the error message a bit. Here's how the scheduler.cpu_off
> probe point is defined:
>
> ====
> probe scheduler.cpu_off =
>         kernel.trace("sched_switch") !,
>         kernel.function("context_switch")
> {
>     name = "cpu_off"
>     task_prev = $prev
>     task_next = $next
>     idle = __is_idle()
> }
> ====
>
> So, that probe point looks for the kernel tracepoint 'sched_switch' or
> the kernel function 'context_switch' (if it finds the tracepoint, it
> won't bother with the function).
>
> Since you got that error, that means systemtap thinks you don't have either.
>
> Let's test that theory. Try the following commands on your kernel and
> see what you get. Your 3.2 kernel should have both (assuming
> CONFIG_TRACEPOINTS is on).
>
> # stap -l 'kernel.trace("sched_*")'
> # stap -l 'kernel.function("context_switch")'
>
> Is CONFIG_TRACEPOINTS on in your kernel?
>
> --
> David Smith
> dsmith@redhat.com
> Red Hat
> http://www.redhat.com
> 256.217.0141 (direct)
> 256.837.0057 (fax)



-- 
Thiago Emmanuel Pereira da Cunha Silva
-----------------------------------------------
www.lsd.ufcg.edu.br/~thiagoepdc
-----------------------------------------------

Re: problems with sched tapset on ubuntu precise 3.2.0

[David Smith]

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

On 05/08/2013 08:25 AM, Thiago Manel wrote:
> Hi David, sorry for the late response
> 
> - for the first check, I see an error:
> 
> stap -vv -l 'kernel.trace("sched_*")'
> Systemtap translator/driver (version 1.6/0.152 non-git sources)
> Copyright (C) 2005-2011 Red Hat, Inc. and others
> This is free software; see the source for copying conditions.
> enabled features: AVAHI LIBSQLITE3 NSS BOOST_SHARED_PTR TR1_UNORDERED_MAP NLS
> Created temporary directory "/tmp/stapNw4kVW"
> Session arch: x86_64 release: 3.2.0-23-generic
> Searched: " /usr/share/systemtap/tapset/x86_64/*.stp ", found: 4, processed: 4
> Searched: " /usr/share/systemtap/tapset/*.stp ", found: 73, processed: 73
> Pass 1: parsed user script and 77 library script(s) using
> 84096virt/22508res/2556shr kb, in 60usr/0sys/70real ms.
> semantic error: no match while resolving probe point kernel.trace("sched_*")
> Pass 2: analyzed script: 0 probe(s), 0 function(s), 0 embed(s), 0
> global(s) using 230984virt/23700res/2908shr kb, in
> 40usr/100sys/125real ms.
> Running rm -rf /tmp/stapNw4kVW
> Spawn waitpid result (0x0): 0
> 
> - whereas for the second one, it succeeds:
> 
>  stap -l 'kernel.function("context_switch")'
> kernel.function("context_switch@/build/buildd/linux-3.2.0/kernel/sched.c:3287")
> 
> Regarding the CONFIG_TRACEPOINTS (I'm not sure I'm looking to the
> right place) I have ...

On a fedora system, you'd look in /boot/config-`uname -r`. I don't know
where you'd find the kernel config file on ubuntu.

I see where the error is coming from now. The process/schedtimes.stp
script is written to only use tracepoints, it doesn't have the
kernel.function fallback like the scheduler.cpu_off tapset probe alias.
So, if your kernel doesn't have the sched kernel tracepoints the
schedtimes.stp script won't work as written. We could try adding in the
kernel.function fallback, but on many kernels that kernel function gets
inlined which makes it difficult to find the arguments.

Here's an (untested) version of schedtimes.stp with the kernel.function
fallbacks added. See if it works for you.

-- 
David Smith
dsmith@redhat.com
Red Hat
http://www.redhat.com
256.217.0141 (direct)
256.837.0057 (fax)

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

#! /usr/bin/env stap

############################################################
# Schedtimes.stp
#
# Copyright (C) 2009 Red Hat, Inc.
#
# This program is free software; you can redistribute it and/or modify
# it under the terms of the GNU General Public License version 2 as
# published by the Free Software Foundation.

# Author: Jason Baron <jbaron@redhat.com>
# profiles threads and displays their run times, queued times,
# wait times, including i/o wait times.
# Has two modes. When no arguments are given it profiles all
# threads. Alternatively, you can pass -c "program name"
############################################################

//constants
global RUNNING=0, QUEUED=1, SLEEPING=2

global traced_pid
global run_time, queued_time,  sleep_time, io_wait_time
global pid_state, pid_names
global previous_timestamp
global io_wait_count
global io_wait_incremented

function get_iowait:long(queue:long)
{
  return @cast(queue,"rq","kernel")->nr_iowait->counter;
}

probe kernel.trace("sched_switch")!, kernel.function("context_switch") {
  previous_pid = $prev->pid;
  next_pid = $next->pid;
  if (traced_pid) {
    if (previous_pid != traced_pid) {
      previous_pid = 0;
    }
    if (next_pid != traced_pid) {
      next_pid = 0;
    }
  }
  if (previous_pid) {
    if (!([previous_pid] in pid_state)) {
      //use this state as entry into state machine
      previous_timestamp[previous_pid] = gettimeofday_us();
      pid_names[previous_pid] = kernel_string($prev->comm);
      if ($prev->state > 0) {
        pid_state[previous_pid] = SLEEPING;
      } else if ($prev->state == 0) {
        pid_state[previous_pid] = QUEUED;
      } else {
        printf("unknown transition:\n");
        printf("pid state: %d our state: %d\n",
          $prev->state, pid_state[previous_pid]);
      }
    } else if (pid_state[previous_pid] == RUNNING) {
      pid_names[previous_pid] = kernel_string($prev->comm);
      t = gettimeofday_us();  
      run_time[previous_pid] += (t - previous_timestamp[previous_pid]);
      previous_timestamp[previous_pid] = t;
      if ($prev->state > 0) {
        if (@defined($rq) && (get_iowait($rq) - io_wait_count[previous_pid]) > 0)
          io_wait_incremented[previous_pid] = 1;  
        pid_state[previous_pid] = SLEEPING;
      } else if ($prev->state == 0) {
        pid_state[previous_pid] = QUEUED;
      } else {
        printf("unknown transition:\n");
        printf("pid state: %d our state: %d\n",
          $prev->state, pid_state[previous_pid]);
      }
    } else {
      printf("unknown transition:\n");
      printf("%s pid state: %d our state: %d\n",
           pid_names[previous_pid],
           $prev->state, pid_state[previous_pid]);
    }
  }
  if (next_pid) {
    if (@defined($rq))
      io_wait_count[next_pid] = get_iowait($rq);
    if (!([next_pid] in pid_state)) {
      //use this state as entry into state machine
      previous_timestamp[next_pid] =  gettimeofday_us();
      pid_state[next_pid] = RUNNING;
      pid_names[next_pid] = kernel_string($next->comm);
    } else if (pid_state[next_pid] == QUEUED) {
      t = gettimeofday_us();
      queued_time[next_pid] += (t - previous_timestamp[next_pid]);
      previous_timestamp[next_pid] = t;
      pid_state[next_pid] = RUNNING;
      pid_names[next_pid] = kernel_string($next->comm);
    } else {
      printf("unknown transition:\n");
      printf("%s pid state: %d our state: %d\n",
        pid_names[next_pid],
        $next->state, pid_state[next_pid]);
    }
  }
}

probe kernel.trace("sched_wakeup"), kernel.function("try_to_wake_up") {
  wakeup_pid = $p->pid;
  if (traced_pid && (wakeup_pid != traced_pid)) next
  if ((!$success) && (pid_state[wakeup_pid] != SLEEPING)) next
  if (!wakeup_pid) next

  if (!([wakeup_pid] in pid_state)) {
    //use this state as entry into state machine
    previous_timestamp[wakeup_pid] =  gettimeofday_us();
    pid_state[wakeup_pid] = QUEUED;
    pid_names[wakeup_pid] = kernel_string($p->comm);
  } else if (pid_state[wakeup_pid] == SLEEPING) {
    t = gettimeofday_us();
    sleep_time[wakeup_pid] += (t - previous_timestamp[wakeup_pid]);
    if (io_wait_incremented[wakeup_pid] == 1) {
      io_wait_time[wakeup_pid] += (t - previous_timestamp[wakeup_pid]);
      io_wait_incremented[wakeup_pid] = 0;
    }
    previous_timestamp[wakeup_pid] = t;
    pid_state[wakeup_pid] = QUEUED;
    pid_names[wakeup_pid] = kernel_string($p->comm);
  } else {
    printf("unknown transition:\n");
    printf("pid state: %d our state: %d\n",
      $p->state, pid_state[wakeup_pid]);
  }
}

probe begin {
  traced_pid = target();
  if (traced_pid == 0) {
    printf("all mode\n");
  } else {
    printf("target mode\n");
    printf("traced pid: %d\n", traced_pid);
  }
}

probe end {
  t = gettimeofday_us();
  foreach (pid in pid_state) {
    if (pid_state[pid] == SLEEPING)
      sleep_time[pid] += (t - previous_timestamp[pid]);
    if (pid_state[pid] == QUEUED)
      queued_time[pid] += (t - previous_timestamp[pid]);
    if (pid_state[pid] == RUNNING)
      run_time[pid] += (t - previous_timestamp[pid]);
  }
  printf ("%16s: %6s %10s %10s %10s %10s %10s\n\n",
         "execname", "pid", "run(us)", "sleep(us)", "io_wait(us)",
         "queued(us)", "total(us)")
  foreach (pid+ in run_time) {
    printf("%16s: %6d %10d %10d %10d %10d %10d\n", 
      pid_names[pid], pid, run_time[pid], sleep_time[pid], 
      io_wait_time[pid], queued_time[pid],
      (run_time[pid] + sleep_time[pid] + queued_time[pid]));
  }
}

Re: problems with sched tapset on ubuntu precise 3.2.0

[Thiago Manel]

David,

The first check indicates the kernel was compiled correctly
(CONFIG_TRACEPOINTS=y)

cat /boot/config-`uname -r` | grep TRACE
CONFIG_STACKTRACE_SUPPORT=y
# CONFIG_RCU_TRACE is not set
# CONFIG_TREE_RCU_TRACE is not set
CONFIG_TRACEPOINTS=y
CONFIG_HAVE_ARCH_TRACEHOOK=y
CONFIG_CAN_PM_TRACE=y

I also run the new schedtimes.stp, unfortunately I faced the error you
said, it was not able find the args ...

semantic error: not accessible at this address (0xffffffff81659cc6,
dieoffset: 0x7bd1ea): identifier '$prev' at :35:18
        source:   previous_pid = $prev->pid;


I will downgrade to a 2.* kernel, thanks for the helping anyway.

On Wed, May 8, 2013 at 11:15 AM, David Smith <dsmith@redhat.com> wrote:
> On 05/08/2013 08:25 AM, Thiago Manel wrote:
>> Hi David, sorry for the late response
>>
>> - for the first check, I see an error:
>>
>> stap -vv -l 'kernel.trace("sched_*")'
>> Systemtap translator/driver (version 1.6/0.152 non-git sources)
>> Copyright (C) 2005-2011 Red Hat, Inc. and others
>> This is free software; see the source for copying conditions.
>> enabled features: AVAHI LIBSQLITE3 NSS BOOST_SHARED_PTR TR1_UNORDERED_MAP NLS
>> Created temporary directory "/tmp/stapNw4kVW"
>> Session arch: x86_64 release: 3.2.0-23-generic
>> Searched: " /usr/share/systemtap/tapset/x86_64/*.stp ", found: 4, processed: 4
>> Searched: " /usr/share/systemtap/tapset/*.stp ", found: 73, processed: 73
>> Pass 1: parsed user script and 77 library script(s) using
>> 84096virt/22508res/2556shr kb, in 60usr/0sys/70real ms.
>> semantic error: no match while resolving probe point kernel.trace("sched_*")
>> Pass 2: analyzed script: 0 probe(s), 0 function(s), 0 embed(s), 0
>> global(s) using 230984virt/23700res/2908shr kb, in
>> 40usr/100sys/125real ms.
>> Running rm -rf /tmp/stapNw4kVW
>> Spawn waitpid result (0x0): 0
>>
>> - whereas for the second one, it succeeds:
>>
>>  stap -l 'kernel.function("context_switch")'
>> kernel.function("context_switch@/build/buildd/linux-3.2.0/kernel/sched.c:3287")
>>
>> Regarding the CONFIG_TRACEPOINTS (I'm not sure I'm looking to the
>> right place) I have ...
>
> On a fedora system, you'd look in /boot/config-`uname -r`. I don't know
> where you'd find the kernel config file on ubuntu.
>
> I see where the error is coming from now. The process/schedtimes.stp
> script is written to only use tracepoints, it doesn't have the
> kernel.function fallback like the scheduler.cpu_off tapset probe alias.
> So, if your kernel doesn't have the sched kernel tracepoints the
> schedtimes.stp script won't work as written. We could try adding in the
> kernel.function fallback, but on many kernels that kernel function gets
> inlined which makes it difficult to find the arguments.
>
> Here's an (untested) version of schedtimes.stp with the kernel.function
> fallbacks added. See if it works for you.
>
> --
> David Smith
> dsmith@redhat.com
> Red Hat
> http://www.redhat.com
> 256.217.0141 (direct)
> 256.837.0057 (fax)



-- 
Thiago Emmanuel Pereira da Cunha Silva
-----------------------------------------------
www.lsd.ufcg.edu.br/~thiagoepdc
-----------------------------------------------

Re: problems with sched tapset on ubuntu precise 3.2.0

[David Smith]

On 05/08/2013 09:56 AM, Thiago Manel wrote:
> David,
> 
> The first check indicates the kernel was compiled correctly
> (CONFIG_TRACEPOINTS=y)
> 
> cat /boot/config-`uname -r` | grep TRACE
> CONFIG_STACKTRACE_SUPPORT=y
> # CONFIG_RCU_TRACE is not set
> # CONFIG_TREE_RCU_TRACE is not set
> CONFIG_TRACEPOINTS=y
> CONFIG_HAVE_ARCH_TRACEHOOK=y
> CONFIG_CAN_PM_TRACE=y
> 
> I also run the new schedtimes.stp, unfortunately I faced the error you
> said, it was not able find the args ...
> 
> semantic error: not accessible at this address (0xffffffff81659cc6,
> dieoffset: 0x7bd1ea): identifier '$prev' at :35:18
>         source:   previous_pid = $prev->pid;
> 
> 
> I will downgrade to a 2.* kernel, thanks for the helping anyway.

I've had another thought here. It could be that the tracepoints are
there, but systemtap is having trouble finding them. On my system
(3.8.11-200.fc18.x86_64), here's what the following command returns:

# fgrep __tracepoint_sched /proc/kallsyms
ffffffff81cc86e0 D __tracepoint_sched_pi_setprio
ffffffff81cc8720 D __tracepoint_sched_stat_runtime
ffffffff81cc8760 D __tracepoint_sched_stat_blocked
ffffffff81cc87a0 D __tracepoint_sched_stat_iowait
ffffffff81cc87e0 D __tracepoint_sched_stat_sleep
ffffffff81cc8820 D __tracepoint_sched_stat_wait
ffffffff81cc8860 D __tracepoint_sched_process_exec
ffffffff81cc88a0 D __tracepoint_sched_process_fork
ffffffff81cc88e0 D __tracepoint_sched_process_wait
ffffffff81cc8920 D __tracepoint_sched_wait_task
ffffffff81cc8960 D __tracepoint_sched_process_exit
ffffffff81cc89a0 D __tracepoint_sched_process_free
ffffffff81cc89e0 D __tracepoint_sched_migrate_task
ffffffff81cc8a20 D __tracepoint_sched_switch
ffffffff81cc8a60 D __tracepoint_sched_wakeup_new
ffffffff81cc8aa0 D __tracepoint_sched_wakeup
ffffffff81cc8ae0 D __tracepoint_sched_kthread_stop_ret
ffffffff81cc8b20 D __tracepoint_sched_kthread_stop

Can you try that on your 3.2.0 kernel?

-- 
David Smith
dsmith@redhat.com
Red Hat
http://www.redhat.com
256.217.0141 (direct)
256.837.0057 (fax)

Re: problems with sched tapset on ubuntu precise 3.2.0

[Thiago Manel]

David, my output is

uname -a
Linux abotoado 3.2.0-23-generic #36-Ubuntu SMP Tue Apr 10 20:39:51 UTC
2012 x86_64 x86_64 x86_64 GNU/Linux

root@abotoado:/tmp# fgrep __tracepoint_sched /proc/kallsyms
ffffffff81cd3f80 D __tracepoint_sched_pi_setprio
ffffffff81cd3fc0 D __tracepoint_sched_stat_runtime
ffffffff81cd4000 D __tracepoint_sched_stat_iowait
ffffffff81cd4040 D __tracepoint_sched_stat_sleep
ffffffff81cd4080 D __tracepoint_sched_stat_wait
ffffffff81cd40c0 D __tracepoint_sched_process_fork
ffffffff81cd4100 D __tracepoint_sched_process_wait
ffffffff81cd4140 D __tracepoint_sched_wait_task
ffffffff81cd4180 D __tracepoint_sched_process_exit
ffffffff81cd41c0 D __tracepoint_sched_process_free
ffffffff81cd4200 D __tracepoint_sched_migrate_task
ffffffff81cd4240 D __tracepoint_sched_switch
ffffffff81cd4280 D __tracepoint_sched_wakeup_new
ffffffff81cd42c0 D __tracepoint_sched_wakeup
ffffffff81cd4300 D __tracepoint_sched_kthread_stop_ret
ffffffff81cd4340 D __tracepoint_sched_kthread_stop
ffffffffa04c2360 d __tracepoint_sched_switch    [lttng_probe_sched]
ffffffffa04c2220 d __tracepoint_sched_process_wait      [lttng_probe_sched]
ffffffffa04c23a0 d __tracepoint_sched_wakeup_new        [lttng_probe_sched]
ffffffffa04c2120 d __tracepoint_sched_stat_iowait       [lttng_probe_sched]
ffffffffa04c22e0 d __tracepoint_sched_process_free      [lttng_probe_sched]
ffffffffa04c22a0 d __tracepoint_sched_process_exit      [lttng_probe_sched]
ffffffffa04c20a0 d __tracepoint_sched_pi_setprio        [lttng_probe_sched]
ffffffffa04c21a0 d __tracepoint_sched_stat_wait [lttng_probe_sched]
ffffffffa04c2460 d __tracepoint_sched_kthread_stop      [lttng_probe_sched]
ffffffffa04c2320 d __tracepoint_sched_migrate_task      [lttng_probe_sched]
ffffffffa04c2160 d __tracepoint_sched_stat_sleep        [lttng_probe_sched]
ffffffffa04c2260 d __tracepoint_sched_wait_task [lttng_probe_sched]
ffffffffa04c23e0 d __tracepoint_sched_wakeup    [lttng_probe_sched]
ffffffffa04c2420 d __tracepoint_sched_kthread_stop_ret  [lttng_probe_sched]
ffffffffa04c20e0 d __tracepoint_sched_stat_runtime      [lttng_probe_sched]

On Mon, May 13, 2013 at 6:21 PM, David Smith <dsmith@redhat.com> wrote:
> On 05/08/2013 09:56 AM, Thiago Manel wrote:
>> David,
>>
>> The first check indicates the kernel was compiled correctly
>> (CONFIG_TRACEPOINTS=y)
>>
>> cat /boot/config-`uname -r` | grep TRACE
>> CONFIG_STACKTRACE_SUPPORT=y
>> # CONFIG_RCU_TRACE is not set
>> # CONFIG_TREE_RCU_TRACE is not set
>> CONFIG_TRACEPOINTS=y
>> CONFIG_HAVE_ARCH_TRACEHOOK=y
>> CONFIG_CAN_PM_TRACE=y
>>
>> I also run the new schedtimes.stp, unfortunately I faced the error you
>> said, it was not able find the args ...
>>
>> semantic error: not accessible at this address (0xffffffff81659cc6,
>> dieoffset: 0x7bd1ea): identifier '$prev' at :35:18
>>         source:   previous_pid = $prev->pid;
>>
>>
>> I will downgrade to a 2.* kernel, thanks for the helping anyway.
>
> I've had another thought here. It could be that the tracepoints are
> there, but systemtap is having trouble finding them. On my system
> (3.8.11-200.fc18.x86_64), here's what the following command returns:
>
> # fgrep __tracepoint_sched /proc/kallsyms
> ffffffff81cc86e0 D __tracepoint_sched_pi_setprio
> ffffffff81cc8720 D __tracepoint_sched_stat_runtime
> ffffffff81cc8760 D __tracepoint_sched_stat_blocked
> ffffffff81cc87a0 D __tracepoint_sched_stat_iowait
> ffffffff81cc87e0 D __tracepoint_sched_stat_sleep
> ffffffff81cc8820 D __tracepoint_sched_stat_wait
> ffffffff81cc8860 D __tracepoint_sched_process_exec
> ffffffff81cc88a0 D __tracepoint_sched_process_fork
> ffffffff81cc88e0 D __tracepoint_sched_process_wait
> ffffffff81cc8920 D __tracepoint_sched_wait_task
> ffffffff81cc8960 D __tracepoint_sched_process_exit
> ffffffff81cc89a0 D __tracepoint_sched_process_free
> ffffffff81cc89e0 D __tracepoint_sched_migrate_task
> ffffffff81cc8a20 D __tracepoint_sched_switch
> ffffffff81cc8a60 D __tracepoint_sched_wakeup_new
> ffffffff81cc8aa0 D __tracepoint_sched_wakeup
> ffffffff81cc8ae0 D __tracepoint_sched_kthread_stop_ret
> ffffffff81cc8b20 D __tracepoint_sched_kthread_stop
>
> Can you try that on your 3.2.0 kernel?
>
> --
> David Smith
> dsmith@redhat.com
> Red Hat
> http://www.redhat.com
> 256.217.0141 (direct)
> 256.837.0057 (fax)



-- 
Thiago Emmanuel Pereira da Cunha Silva
-----------------------------------------------
www.lsd.ufcg.edu.br/~thiagoepdc
-----------------------------------------------

Re: problems with sched tapset on ubuntu precise 3.2.0

[Josh Stone]

I took a look at Ubuntu's linux-headers-3.2.0-23, and it does appear to
have the right trace/events/sched.h for the tracepoint, so it's bizarre
that stap's detection isn't working.

If you're willing to keep digging, here's a command which will dump a
lot of information as stap looks for tracepoints on your system:

  stap -l 'kernel.trace("sched_switch")' --poison-cache --vp 09

That should list all the tracepoint headers it discovers, which here we
care about trace/events/sched.h.  Then you'll see the compilation
attempt for each one, something like this:

> Processing tracepoint header
> /lib/modules/3.8.11-200.fc18.x86_64/build/include/trace/events/sched.h
> with query /tmp/stapPj56Fw/tracequery_kmod_1/tracequery_kmod_1_30.c

... and later a gcc invocation for that matching tracequery_kmod_1_30.c

Assuming that compiled ok, then it will be cached like:

> Copying /tmp/stapPj56Fw/tracequery_kmod_1/tracequery_kmod_1_30.o to
> /home/jistone/.systemtap/cache/99/tracequery_995371d23264963c11356fa9e1b689eb_837.o

And you can inspect that object to see what stap sees:

> $ nm --defined-only /home/jistone/.systemtap/cache/99/tracequery_995371d23264963c11356fa9e1b689eb_837.o
> 0000000000000000 T stapprobe_sched_kthread_stop
> 0000000000000010 T stapprobe_sched_kthread_stop_ret
> 0000000000000050 T stapprobe_sched_migrate_task
> 0000000000000110 T stapprobe_sched_pi_setprio
> 00000000000000b0 T stapprobe_sched_process_exec
> 0000000000000070 T stapprobe_sched_process_exit
> 00000000000000a0 T stapprobe_sched_process_fork
> 0000000000000060 T stapprobe_sched_process_free
> 0000000000000090 T stapprobe_sched_process_wait
> 00000000000000f0 T stapprobe_sched_stat_blocked
> 00000000000000e0 T stapprobe_sched_stat_iowait
> 0000000000000100 T stapprobe_sched_stat_runtime
> 00000000000000d0 T stapprobe_sched_stat_sleep
> 00000000000000c0 T stapprobe_sched_stat_wait
> 0000000000000040 T stapprobe_sched_switch
> 0000000000000080 T stapprobe_sched_wait_task
> 0000000000000020 T stapprobe_sched_wakeup
> 0000000000000030 T stapprobe_sched_wakeup_new

Re: problems with sched tapset on ubuntu precise 3.2.0

[Josh Stone]

On 05/08/2013 06:25 AM, Thiago Manel wrote:
> Systemtap translator/driver (version 1.6/0.152 non-git sources)
> Copyright (C) 2005-2011 Red Hat, Inc. and others
> This is free software; see the source for copying conditions.
> enabled features: AVAHI LIBSQLITE3 NSS BOOST_SHARED_PTR TR1_UNORDERED_MAP NLS
> Created temporary directory "/tmp/stapNw4kVW"
> Session arch: x86_64 release: 3.2.0-23-generic

Actually, the problem may just be stap 1.6 versus kernel 3.2.  Looking
back at our release notes, the first we had tested with any 3.x kernel
was stap 1.7.

And specifically with tracepoints, back then we used to try to compile
all discovered tracepoint headers together, which we've since decided is
too fragile.  If any of them are broken (and they often neglect
dependent headers), then we'd fail to discover any tracepoints at all.
These days we test each tracepoint header separately to avoid this.

So if you can try with a newer systemtap build, I think you'll have
better luck.  And if so, perhaps file a bug in Ubuntu for this issue.

Re: problems with sched tapset on ubuntu precise 3.2.0

[Thiago Manel]

I will try upgrading to a newer stap, thanks Josh.

... and, to finish this debug session I spotted a compiling problem
(by 'kernel.trace("sched_switch")' --poison-cache --vp 09), see below

make -f scripts/Makefile.build obj=/tmp/stapAJ6lCC/
tracequery_kmod_20
  gcc -Wp,-MD,/tmp/stapAJ6lCC/tracequery_kmod_20/.tracequery_kmod_20.o.d
 -nostdinc -isystem /usr/lib/gcc/x86_64-linux-gnu/4.6/include
-I/usr/src/linux-headers-3.2.0-23-generic/arch/x86/include
-Iarch/x86/include/generated -Iinclude  -include
/usr/src/linux-headers-3.2.0-23-generic/include/linux/kconfig.h
-Iubuntu/include  -D__KERNEL__ -Wall -Wundef -Wstrict-prototypes
-Wno-trigraphs -fno-strict-aliasing -fno-common
-Werror-implicit-function-declaration -Wno-format-security
-fno-delete-null-pointer-checks -O2 -m64 -mtune=generic -mno-red-zone
-mcmodel=kernel -funit-at-a-time -maccumulate-outgoing-args
-fstack-protector -DCONFIG_AS_CFI=1 -DCONFIG_AS_CFI_SIGNAL_FRAME=1
-DCONFIG_AS_CFI_SECTIONS=1 -DCONFIG_AS_FXSAVEQ=1 -pipe
-Wno-sign-compare -fno-asynchronous-unwind-tables -mno-sse -mno-mmx
-mno-sse2 -mno-3dnow -Wframe-larger-than=1024
-Wno-unused-but-set-variable -fno-omit-frame-pointer
-fno-optimize-sibling-calls -pg -Wdeclaration-after-statement
-Wno-pointer-sign -fno-strict-overflow -fconserve-stack
-DCC_HAVE_ASM_GOTO -g -Wno-implicit-function-declaration -Werror
-I/build/buildd/linux-3.2.0/debian/build/build-generic  -DMODULE
-D"KBUILD_STR(s)=#s"
-D"KBUILD_BASENAME=KBUILD_STR(tracequery_kmod_20)"
-D"KBUILD_MODNAME=KBUILD_STR(tracequery_kmod_20)" -c -o
/tmp/stapAJ6lCC/tracequery_kmod_20/.tmp_tracequery_kmod_20.o
/tmp/stapAJ6lCC/tracequery_kmod_20/tracequery_kmod_20.c
/tmp/stapAJ6lCC/tracequery_kmod_20/tracequery_kmod_20.c:23:30: fatal
error: fs/xfs/xfs_types.h: No such file or directory
compilation terminated.
make[1]: *** [/tmp/stapAJ6lCC/tracequery_kmod_20/tracequery_kmod_20.o] Error 1
make: *** [_module_/tmp/stapAJ6lCC/tracequery_kmod_20] Error 2
make: Leaving directory `/usr/src/linux-headers-3.2.0-23-generic'
Spawn waitpid result (0x200): 2

Warning: make exited with status: 2


On Tue, May 14, 2013 at 5:24 PM, Josh Stone <jistone@redhat.com> wrote:
> On 05/08/2013 06:25 AM, Thiago Manel wrote:
>> Systemtap translator/driver (version 1.6/0.152 non-git sources)
>> Copyright (C) 2005-2011 Red Hat, Inc. and others
>> This is free software; see the source for copying conditions.
>> enabled features: AVAHI LIBSQLITE3 NSS BOOST_SHARED_PTR TR1_UNORDERED_MAP NLS
>> Created temporary directory "/tmp/stapNw4kVW"
>> Session arch: x86_64 release: 3.2.0-23-generic
>
> Actually, the problem may just be stap 1.6 versus kernel 3.2.  Looking
> back at our release notes, the first we had tested with any 3.x kernel
> was stap 1.7.
>
> And specifically with tracepoints, back then we used to try to compile
> all discovered tracepoint headers together, which we've since decided is
> too fragile.  If any of them are broken (and they often neglect
> dependent headers), then we'd fail to discover any tracepoints at all.
> These days we test each tracepoint header separately to avoid this.
>
> So if you can try with a newer systemtap build, I think you'll have
> better luck.  And if so, perhaps file a bug in Ubuntu for this issue.



-- 
Thiago Emmanuel Pereira da Cunha Silva
-----------------------------------------------
www.lsd.ufcg.edu.br/~thiagoepdc
-----------------------------------------------

Re: problems with sched tapset on ubuntu precise 3.2.0

[Josh Stone]

On 05/14/2013 01:35 PM, Thiago Manel wrote:
> I will try upgrading to a newer stap, thanks Josh.
> 
> ... and, to finish this debug session I spotted a compiling problem (by
> 'kernel.trace("sched_switch")' --poison-cache --vp 09), see below
> 
[...]
> /tmp/stapAJ6lCC/tracequery_kmod_20/tracequery_kmod_20.c:23:30: fatal
> error: fs/xfs/xfs_types.h: No such file or directory

Hmm, ok, the fact that this got up to kmod_20 means I was remembering
incorrectly.  We used to *try* all headers together, but then we did
fall back to testing them individually.

> Maybe I'm adding some noise but digging the commit history I saw this
> (http://git.stealer.net/?p=systemtap.git;a=commitdiff;h=88637c31488f4987cc63c3f71263917dd98ca9cf)
> --- which has the following description
> 
> "Including xfs_types.h unconditionally on installations with no kernel
> debuginfo would cause normal tracepoint processing to fail too.
> * tapsets.cxx (tracepoint_extra_decls): Include xfs_types.h
>  only if we know the kernel source tree."

Yes this commit looks related, but it's old enough that you should have
it.  (git describe --contains 88637c3 -> release-1.4~119)

I think the one you need is commit 50b72692 (release-1.7~151^2~105).
That limited the xfs_types.h hack to only tracepoint headers with "xfs"
in their name.

Also, the option for the source tree did show up in your command line as
"-I/build/buildd/linux-3.2.0/debian/build/build-generic".  I guess you
don't actually have "fs/xfs/xfs_types.h" in that path?  Do you even have
/build/buildd/... at all?  This may be tracepoint_builder::init_dw too
eager to trust DW_AT_comp_dir...