Re: sched_wakeup_new and sched_kthread_stop events cause great overload

[Xiao Guangrong <xiaoguangrong@cn.fujitsu.com>]

Hi Steven,

Sorry for the delay reply since i'm busy during this time.

Steven Rostedt wrote:

>> For sysbench.threads:
>> cat debugfs/tracing/trace | grep "sched_wakeup_new" | wc -l
>> 5001
>> cat debugfs/tracing/trace | grep "sched_kthread_stop" | wc -l
>> 0
> 
> Strange? So if you did:
> 
> cat debugfs/tracing/trace | wc -l
> 
> you should get 5005?
> 

Yes, other 4 lines are tracing message's header

>> For sysbench.mutex:
>> cat debugfs/tracing/trace | grep "sched_wakeup_new" | wc -l
>> 5001
>> cat debugfs/tracing/trace | grep "sched_kthread_stop" | wc -l
>> 0
>>
>> And, if only enable sched_kthread_stop event, the sysbench.threads's
>> overload is 5.90%, the sysbench.mutex's overload is 3.36%.
> 
> Could be something that messes with the cache lines?

We don't know the real reason, but we can keep fighting for this issue, once
we get useful information, we will sent to you.

> 
>> It hardly explain why sched_kthread_stop is never called but cause great overload.
> 
> Would be worth running perf against this test, to see where the issues
> are occurring.
> 

We've used 'perf' to tracing it:
perf record -e sched:sched_wakeup_new -e sched:sched_kthread_stop -f -i -a -c 1 sysbench --num-threads=5000 --max-requests=50000 --test=threads --thread-yields=1000 --thread-locks=10000 run

The output is:
# Samples: 5001
#
# Overhead          Command           Shared Object  Symbol
# ........  ...............  ......................  ......
#
    99.98%         sysbench  /lib64/libc-2.10.90.so  [.] clone
     0.02%  perf.2.6.31-38.  /lib64/libc-2.10.90.so  [.] fork
#
# (For a higher level overview, try: perf report --sort comm,dso)
#

The result shows that the most time is costed on clone and fork, and no path to
call sched_kthread_stop.

Xiao