Ftrace: can trace kthread?

Ftrace: can trace kthread?

[Figo.zhang]

hi,

is it ftrace in 2.6.36-rc8 can trace the kthread? i want to trace the
kswapd/bdi_writeback_thread, but not success. i am sure that kswapd is
running, because i let the system eat huge memory. i can trace some
function such as __do_fault. what is issue on it? 

Best,
Figo.zhang


here is my ftrace script.
i = 1
while true;
do
	echo 1 > /proc/sys/kernel/ftrace_enabled
	echo function_graph > /sys/kernel/debug/tracing/current_tracer
	echo kswapd > /sys/kernel/debug/tracing/set_graph_function
	echo 1 > /sys/kernel/debug/tracing/tracing_on
	echo 1 > /sys/kernel/debug/tracing/tracing_enabled
	sleep 1
	echo 0 > /sys/kernel/debug/tracing/tracing_enabled
	cat /sys/kernel/debug/tracing/trace > ftrace.kswap.log.$i

	let i=i+1;

done

Re: Ftrace: can trace kthread?

[Yong Zhang]

On Thu, Oct 21, 2010 at 3:55 PM, Figo.zhang
<zhangtianfei@leadcoretech.com> wrote:
> hi,
>
> is it ftrace in 2.6.36-rc8 can trace the kthread?

How about the set_ftrace_pid interface?

Thanks,
Yong

> i want to trace the
> kswapd/bdi_writeback_thread, but not success. i am sure that kswapd is
> running, because i let the system eat huge memory. i can trace some
> function such as __do_fault. what is issue on it?
>
> Best,
> Figo.zhang
>
>
> here is my ftrace script.
> i = 1
> while true;
> do
>        echo 1 > /proc/sys/kernel/ftrace_enabled
>        echo function_graph > /sys/kernel/debug/tracing/current_tracer
>        echo kswapd > /sys/kernel/debug/tracing/set_graph_function
>        echo 1 > /sys/kernel/debug/tracing/tracing_on
>        echo 1 > /sys/kernel/debug/tracing/tracing_enabled
>        sleep 1
>        echo 0 > /sys/kernel/debug/tracing/tracing_enabled
>        cat /sys/kernel/debug/tracing/trace > ftrace.kswap.log.$i
>
>        let i=i+1;
>
> done
>
>
>
> --
> 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/
>

Re: Ftrace: can trace kthread?

[Figo.zhang]

On Thu, 2010-10-21 at 16:10 +0800, Yong Zhang wrote:
> On Thu, Oct 21, 2010 at 3:55 PM, Figo.zhang
> <zhangtianfei@leadcoretech.com> wrote:
> > hi,
> >
> > is it ftrace in 2.6.36-rc8 can trace the kthread?
> 
> How about the set_ftrace_pid interface?
> 

i try by set_ftrace_pid, it also can't ftrace the kswapd.

Re: Ftrace: can trace kthread?

[Yong Zhang]

On Thu, Oct 21, 2010 at 4:21 PM, Figo.zhang
<zhangtianfei@leadcoretech.com> wrote:
> On Thu, 2010-10-21 at 16:10 +0800, Yong Zhang wrote:
>> On Thu, Oct 21, 2010 at 3:55 PM, Figo.zhang
>> <zhangtianfei@leadcoretech.com> wrote:
>> > hi,
>> >
>> > is it ftrace in 2.6.36-rc8 can trace the kthread?
>>
>> How about the set_ftrace_pid interface?
>>
>
> i try by set_ftrace_pid, it also can't ftrace the kswapd.

Are you sure kswapd got chance to run on your system?

BTW, I can successfully trace bdi_writeback_thread,
# tracer: function
#
#           TASK-PID    CPU#    TIMESTAMP  FUNCTION
#              | |       |          |         |
       flush-8:0-374   [000] 600743.828496: finish_task_switch <-schedule
       flush-8:0-374   [000] 600743.828498: perf_event_task_sched_in
<-finish_task_switch
       flush-8:0-374   [000] 600743.828498: del_timer_sync <-schedule_timeout
       flush-8:0-374   [000] 600743.828499: try_to_del_timer_sync
<-del_timer_sync
       flush-8:0-374   [000] 600743.828499: lock_timer_base
<-try_to_del_timer_sync
       flush-8:0-374   [000] 600743.828499: _spin_lock_irqsave <-lock_timer_base
       flush-8:0-374   [000] 600743.828500: _spin_unlock_irqrestore
<-try_to_del_timer_sync
       flush-8:0-374   [000] 600743.828500: kthread_should_stop
<-bdi_writeback_task

Thanks,
Yong

Re: Ftrace: can trace kthread?

[Figo.zhang]

> > i try by set_ftrace_pid, it also can't ftrace the kswapd.
> 
> Are you sure kswapd got chance to run on your system?
> 
> BTW, I can successfully trace bdi_writeback_thread,
> # tracer: function
> #
> #           TASK-PID    CPU#    TIMESTAMP  FUNCTION
> #              | |       |          |         |
>        flush-8:0-374   [000] 600743.828496: finish_task_switch <-schedule
>        flush-8:0-374   [000] 600743.828498: perf_event_task_sched_in
> <-finish_task_switch
>        flush-8:0-374   [000] 600743.828498: del_timer_sync <-schedule_timeout
>        flush-8:0-374   [000] 600743.828499: try_to_del_timer_sync
> <-del_timer_sync
>        flush-8:0-374   [000] 600743.828499: lock_timer_base
> <-try_to_del_timer_sync
>        flush-8:0-374   [000] 600743.828499: _spin_lock_irqsave <-lock_timer_base
>        flush-8:0-374   [000] 600743.828500: _spin_unlock_irqrestore
> <-try_to_del_timer_sync
>        flush-8:0-374   [000] 600743.828500: kthread_should_stop
> <-bdi_writeback_task

are you use my scprit to trace the bdi_writeback_thread ?

Re: Ftrace: can trace kthread?

[Yong Zhang]

On Thu, Oct 21, 2010 at 4:44 PM, Figo.zhang
<zhangtianfei@leadcoretech.com> wrote:
>
>> > i try by set_ftrace_pid, it also can't ftrace the kswapd.
>>
>> Are you sure kswapd got chance to run on your system?
>>
>> BTW, I can successfully trace bdi_writeback_thread,
>> # tracer: function
>> #
>> #           TASK-PID    CPU#    TIMESTAMP  FUNCTION
>> #              | |       |          |         |
>>        flush-8:0-374   [000] 600743.828496: finish_task_switch <-schedule
>>        flush-8:0-374   [000] 600743.828498: perf_event_task_sched_in
>> <-finish_task_switch
>>        flush-8:0-374   [000] 600743.828498: del_timer_sync <-schedule_timeout
>>        flush-8:0-374   [000] 600743.828499: try_to_del_timer_sync
>> <-del_timer_sync
>>        flush-8:0-374   [000] 600743.828499: lock_timer_base
>> <-try_to_del_timer_sync
>>        flush-8:0-374   [000] 600743.828499: _spin_lock_irqsave <-lock_timer_base
>>        flush-8:0-374   [000] 600743.828500: _spin_unlock_irqrestore
>> <-try_to_del_timer_sync
>>        flush-8:0-374   [000] 600743.828500: kthread_should_stop
>> <-bdi_writeback_task
>
> are you use my scprit to trace the bdi_writeback_thread ?

No.

I just
echo  0 > tracing_enabled
echo function > current_tracer
echo 374(pid of flush) > set_ftrace_pid
echo 1 > tracing_enabled
wait some time
echo 0 > tracing_enabled
cat trace

So I think this answer your question "could kthread be traced?"

Thanks,
Yong

Re: Ftrace: can trace kthread?

[Figo.zhang]

> I just
> echo  0 > tracing_enabled
> echo function > current_tracer
> echo 374(pid of flush) > set_ftrace_pid
> echo 1 > tracing_enabled
> wait some time
> echo 0 > tracing_enabled
> cat trace
> 
> So I think this answer your question "could kthread be traced?"

i do it the same of you.

[root@myhost tracing]# ps -ax | grep flush
Warning: bad ps syntax, perhaps a bogus '-'? See http://procps.sf.net/faq.html
 1205 ?        S      0:01 [flush-8:0]
11852 pts/1    S+     0:00 grep flush
[root@myhost tracing]# 

so my flusher pid is 1205, i do it as below:

[root@myhost tracing]# echo 0 > tracing_enabled 
[root@myhost tracing]# echo function > current_tracer
[root@myhost tracing]# echo 1205 > set_ftrace_pid 
[root@myhost tracing]# echo 1 > tracing_enabled 

wait ... and open some pdf files, let system eat huge memory...

[root@myhost tracing]# echo 0 > tracing_enabled 
[root@myhost tracing]# cat trace
# tracer: function
#
#           TASK-PID    CPU#    TIMESTAMP  FUNCTION
#              | |       |          |         |


but i canot trace nothing. 

Re: Ftrace: can trace kthread?

[Yong Zhang]

On Thu, Oct 21, 2010 at 4:59 PM, Figo.zhang
<zhangtianfei@leadcoretech.com> wrote:
>
>> I just
>> echo  0 > tracing_enabled
>> echo function > current_tracer
>> echo 374(pid of flush) > set_ftrace_pid
>> echo 1 > tracing_enabled
>> wait some time
>> echo 0 > tracing_enabled
>> cat trace
>>
>> So I think this answer your question "could kthread be traced?"
>
> i do it the same of you.
>
> [root@myhost tracing]# ps -ax | grep flush
> Warning: bad ps syntax, perhaps a bogus '-'? See http://procps.sf.net/faq.html
>  1205 ?        S      0:01 [flush-8:0]
> 11852 pts/1    S+     0:00 grep flush
> [root@myhost tracing]#
>
> so my flusher pid is 1205, i do it as below:
>
> [root@myhost tracing]# echo 0 > tracing_enabled
> [root@myhost tracing]# echo function > current_tracer
> [root@myhost tracing]# echo 1205 > set_ftrace_pid
> [root@myhost tracing]# echo 1 > tracing_enabled
>
> wait ... and open some pdf files, let system eat huge memory...
>
> [root@myhost tracing]# echo 0 > tracing_enabled
> [root@myhost tracing]# cat trace
> # tracer: function
> #
> #           TASK-PID    CPU#    TIMESTAMP  FUNCTION
> #              | |       |          |         |
>
>
> but i canot trace nothing.

Is tracing_on enable(1) on your system?
I enable it on my system by default, so I didn't show it in the previous mail.

Thanks,
Yong

Re: Ftrace: can trace kthread?

[Figo.zhang]

> >
> > [root@myhost tracing]# ps -ax | grep flush
> > Warning: bad ps syntax, perhaps a bogus '-'? See http://procps.sf.net/faq.html
> >  1205 ?        S      0:01 [flush-8:0]
> > 11852 pts/1    S+     0:00 grep flush
> > [root@myhost tracing]#
> >
> > so my flusher pid is 1205, i do it as below:
> >
> > [root@myhost tracing]# echo 0 > tracing_enabled
> > [root@myhost tracing]# echo function > current_tracer
> > [root@myhost tracing]# echo 1205 > set_ftrace_pid
> > [root@myhost tracing]# echo 1 > tracing_enabled
> >
> > wait ... and open some pdf files, let system eat huge memory...
> >
> > [root@myhost tracing]# echo 0 > tracing_enabled
> > [root@myhost tracing]# cat trace
> > # tracer: function
> > #
> > #           TASK-PID    CPU#    TIMESTAMP  FUNCTION
> > #              | |       |          |         |
> >
> >
> > but i canot trace nothing.
> 
> Is tracing_on enable(1) on your system?
> I enable it on my system by default, so I didn't show it in the previous mail.
> 

tracing_on is sure on, my kernel is 2.6.36-rc8, what is your kernel
version?

Re: Ftrace: can trace kthread?

[KOSAKI Motohiro]

> 
> > >
> > > [root@myhost tracing]# ps -ax | grep flush
> > > Warning: bad ps syntax, perhaps a bogus '-'? See http://procps.sf.net/faq.html
> > >  1205 ?        S      0:01 [flush-8:0]
> > > 11852 pts/1    S+     0:00 grep flush
> > > [root@myhost tracing]#
> > >
> > > so my flusher pid is 1205, i do it as below:
> > >
> > > [root@myhost tracing]# echo 0 > tracing_enabled
> > > [root@myhost tracing]# echo function > current_tracer
> > > [root@myhost tracing]# echo 1205 > set_ftrace_pid
> > > [root@myhost tracing]# echo 1 > tracing_enabled
> > >
> > > wait ... and open some pdf files, let system eat huge memory...
> > >
> > > [root@myhost tracing]# echo 0 > tracing_enabled
> > > [root@myhost tracing]# cat trace
> > > # tracer: function
> > > #
> > > #           TASK-PID    CPU#    TIMESTAMP  FUNCTION
> > > #              | |       |          |         |
> > >
> > >
> > > but i canot trace nothing.
> > 
> > Is tracing_on enable(1) on your system?
> > I enable it on my system by default, so I didn't show it in the previous mail.
> > 
> 
> tracing_on is sure on, my kernel is 2.6.36-rc8, what is your kernel
> version?

2.6.36-rc8 + Yong's way works perfectly fine on my x86_64 desktop.

thanks.

Re: Ftrace: can trace kthread?

[Peter Zijlstra]

On Thu, 2010-10-21 at 16:59 +0800, Figo.zhang wrote:
> > I just
> > echo  0 > tracing_enabled
> > echo function > current_tracer
> > echo 374(pid of flush) > set_ftrace_pid
> > echo 1 > tracing_enabled
> > wait some time
> > echo 0 > tracing_enabled
> > cat trace
> > 
> > So I think this answer your question "could kthread be traced?"
> 
> i do it the same of you.

> but i canot trace nothing. 

Your initial attempt had:

        echo kswapd > /sys/kernel/debug/tracing/set_graph_function

have you reset that state?

Re: Ftrace: can trace kthread?

[Steven Rostedt]

On Thu, 2010-10-21 at 12:12 +0200, Peter Zijlstra wrote:
> On Thu, 2010-10-21 at 16:59 +0800, Figo.zhang wrote:
> > > I just
> > > echo  0 > tracing_enabled

I need to remove that file. "tracing_enabled" is pretty much deprecated,
just use tracing_on to enable and disable the trace recording.

> > > echo function > current_tracer
> > > echo 374(pid of flush) > set_ftrace_pid
> > > echo 1 > tracing_enabled
> > > wait some time
> > > echo 0 > tracing_enabled
> > > cat trace
> > > 
> > > So I think this answer your question "could kthread be traced?"
> > 
> > i do it the same of you.
> 
> > but i canot trace nothing. 
> 
> Your initial attempt had:
> 
>         echo kswapd > /sys/kernel/debug/tracing/set_graph_function

Yeah, that wont work. That's because kswapd() is called at system
startup and goes into a loop. The function graph tracer will never see
that function again (it's not called again). It can't know what function
it is in, only what functions it enters.

-- Steve

> 
> have you reset that state?

Re: Ftrace: can trace kthread?

[Steven Rostedt]

Just a quick note. Please send email to my rostedt@goodmis.org address.
I do not check my srostedt@redhat.com address as often.

I know, I know, I have it as my Author tag (but not my signed off by)
and I had to add it to my business card. I just could not be so bold as
to put my goodmis.org address on my Red Hat business card ;-) And there
was no good way to add it as a secondary.

-- Steve

On Thu, 2010-10-21 at 15:55 +0800, Figo.zhang wrote:
> hi,
> 
> is it ftrace in 2.6.36-rc8 can trace the kthread? i want to trace the
> kswapd/bdi_writeback_thread, but not success. i am sure that kswapd is
> running, because i let the system eat huge memory. i can trace some
> function such as __do_fault. what is issue on it? 
> 
> Best,
> Figo.zhang
> 
> 
> here is my ftrace script.
> i = 1
> while true;
> do
> 	echo 1 > /proc/sys/kernel/ftrace_enabled
> 	echo function_graph > /sys/kernel/debug/tracing/current_tracer
> 	echo kswapd > /sys/kernel/debug/tracing/set_graph_function
> 	echo 1 > /sys/kernel/debug/tracing/tracing_on
> 	echo 1 > /sys/kernel/debug/tracing/tracing_enabled
> 	sleep 1
> 	echo 0 > /sys/kernel/debug/tracing/tracing_enabled
> 	cat /sys/kernel/debug/tracing/trace > ftrace.kswap.log.$i
> 
> 	let i=i+1;
> 
> done
> 
> 
>