Re: [PATCH v5 03/17] perf ftrace: add option -t/--tid to filter by thread id

[Changbin Du <changbin.du@gmail.com>]

On Fri, Jul 17, 2020 at 01:01:24PM -0400, Steven Rostedt wrote:
> On Fri, 17 Jul 2020 21:26:50 +0800
> Changbin Du <changbin.du@gmail.com> wrote:
> 
> > On Thu, Jul 16, 2020 at 12:36:30PM -0300, Arnaldo Carvalho de Melo wrote:
> > > Em Sat, Jul 11, 2020 at 08:40:21PM +0800, Changbin Du escreveu:  
> > > > This allows us to trace single thread instead of the whole process.
> > > > 
> > > > Signed-off-by: Changbin Du <changbin.du@gmail.com>
> > > > ---
> > > >  tools/perf/Documentation/perf-ftrace.txt | 4 ++++
> > > >  tools/perf/builtin-ftrace.c              | 2 ++
> > > >  2 files changed, 6 insertions(+)
> > > > 
> > > > diff --git a/tools/perf/Documentation/perf-ftrace.txt b/tools/perf/Documentation/perf-ftrace.txt
> > > > index d79560dea19f..e204bf6d50d8 100644
> > > > --- a/tools/perf/Documentation/perf-ftrace.txt
> > > > +++ b/tools/perf/Documentation/perf-ftrace.txt
> > > > @@ -38,6 +38,10 @@ OPTIONS
> > > >  --pid=::
> > > >  	Trace on existing process id (comma separated list).
> > > >  
> > > > +-t::
> > > > +--tid=::
> > > > +	Trace on existing thread id (comma separated list).
> > > > +  
> > > 
> > > 
> > > Humm, I just  tried:
> > > 
> > > [root@five ~]# yes > /dev/null &
> > > [1] 18265
> > > [root@five ~]# perf ftrace --tid 18265
> > > ^C[root@five ~]#
> > > 
> > > After waiting for a while, nothing, what am I doing wrong?
> > >  
> > I got it wrong. Currently ftrace only can filter by pid. If the pid is not
> > the main thread it won't work.
> 
> Wait what?
> 
> The "pid" for ftrace is really a "task id" which is a thread id.
>
My bad. I traced a sleeping thread yesterday so no event generated.

Now it works:
$ pstree -p 2378
qemu-system-x86(2378)─┬─{qemu-system-x86}(2379)
                      ├─{qemu-system-x86}(2382)
                      ├─{qemu-system-x86}(2385)
                      ├─{qemu-system-x86}(2387)
                      ├─{qemu-system-x86}(2388)
                      ├─{qemu-system-x86}(2389)
                      ├─{qemu-system-x86}(2390)
                      ├─{qemu-system-x86}(2391)
                      ├─{qemu-system-x86}(2392)
$ sudo ./perf ftrace --tid 2388
[sudo] password for changbin:
# tracer: function
#
# entries-in-buffer/entries-written: 0/0   #P:8
#
#           TASK-PID     CPU#   TIMESTAMP  FUNCTION
#              | |         |       |         |
          <idle>-0     [001]   6561.553989: switch_mm_irqs_off <-__schedule
          <idle>-0     [001]   6561.553996: load_new_mm_cr3 <-switch_mm_irqs_off
 qemu-system-x86-2388  [001]   6561.553997: finish_task_switch <-__schedule
 qemu-system-x86-2388  [001]   6561.553998: smp_irq_work_interrupt <-irq_work_interrupt
 qemu-system-x86-2388  [001]   6561.553999: irq_enter <-smp_irq_work_interrupt
 qemu-system-x86-2388  [001]   6561.553999: rcu_irq_enter <-irq_enter
 qemu-system-x86-2388  [001]   6561.554000: __wake_up <-rb_wake_up_waiters
 qemu-system-x86-2388  [001]   6561.554000: __wake_up_common_lock <-__wake_up
 qemu-system-x86-2388  [001]   6561.554000: _raw_spin_lock_irqsave <-__wake_up_common_lock
 qemu-system-x86-2388  [001]   6561.554000: __wake_up_common <-__wake_up_common_lock
 ...
> [root@bxtest ~]# yes > /dev/null &
> [1] 6799
> [root@bxtest ~]# trace-cmd record -e all -P 6799
> Hit Ctrl^C to stop recording
> ^CCPU 0: 3573031 events lost
> CPU0 data recorded at offset=0x838000
>     627675136 bytes in size
> CPU1 data recorded at offset=0x25ed1000
>     0 bytes in size
> CPU2 data recorded at offset=0x25ed1000
>     0 bytes in size
> CPU3 data recorded at offset=0x25ed1000
>     0 bytes in size
> CPU4 data recorded at offset=0x25ed1000
>     0 bytes in size
> CPU5 data recorded at offset=0x25ed1000
>     0 bytes in size
> CPU6 data recorded at offset=0x25ed1000
>     0 bytes in size
> CPU7 data recorded at offset=0x25ed1000
>     0 bytes in size
> [root@bxtest ~]# trace-cmd report | head 
> CPU 1 is empty
> CPU 2 is empty
> CPU 3 is empty
> CPU 4 is empty
> CPU 5 is empty
> CPU 6 is empty
> CPU 7 is empty
> cpus=8
>              yes-6799  [000] 67825.580902: sys_exit:             NR 1 = 8192
>              yes-6799  [000] 67825.580903: sys_exit_write:       0x2000
> 
> 
> What's different about tid vs pid?
> 
> -- Steve
> 
> 
> 
> > 
> > So this patch makes no sense. will drop this.
> > 

-- 
Cheers,
Changbin Du