Re: [LKP] [sched/core] 9edfbfed3f5: +88.2% hackbench.time.involuntary_context_switches

[Markus Pargmann]

Hi,

On Mon, Feb 09, 2015 at 09:31:20AM +0100, Peter Zijlstra wrote:
> On Mon, Feb 09, 2015 at 01:58:33PM +0800, Huang Ying wrote:
> > FYI, we noticed the below changes on
> > 
> > git://git.kernel.org/pub/scm/linux/kernel/git/tip/tip.git sched/core
> > commit 9edfbfed3f544a7830d99b341f0c175995a02950 ("sched/core: Rework rq->clock update skips")
> > 
> > 
> > testbox/testcase/testparams: xps2/hackbench/performance-1600%-process-socket
> > 
> > cebde6d681aa45f9  9edfbfed3f544a7830d99b341f  
> > ----------------  --------------------------  
> >          %stddev     %change         %stddev
> >              \          |                \  
> >    1839273 Â  6%     +88.2%    3462337 Â  4%  hackbench.time.involuntary_context_switches
> >   41965851 Â  5%      +5.6%   44307403 Â  1%  hackbench.time.voluntary_context_switches
> >        388 Â 39%     -58.6%        160 Â 10%  sched_debug.cfs_rq[1]:/.tg_load_contrib
> >      12957 Â 14%     -60.5%       5117 Â 11%  sched_debug.cfs_rq[2]:/.tg_load_avg
> >      30505 Â 14%     -57.7%      12905 Â  6%  sched_debug.cfs_rq[3]:/.tg_load_avg
> >       2790 Â 24%     -65.4%        964 Â 32%  sched_debug.cfs_rq[3]:/.blocked_load_avg
> >       2915 Â 23%     -62.2%       1101 Â 29%  sched_debug.cfs_rq[3]:/.tg_load_contrib
> >    1839273 Â  6%     +88.2%    3462337 Â  4%  time.involuntary_context_switches
> >       1474 Â 28%     -61.7%        565 Â 43%  sched_debug.cfs_rq[2]:/.tg_load_contrib
> >      11830 Â 15%     +63.0%      19285 Â 11%  sched_debug.cpu#4.sched_goidle
> >      19319 Â 29%     +91.1%      36913 Â  7%  sched_debug.cpu#3.sched_goidle
> >       5899 Â 31%     -35.6%       3801 Â 11%  sched_debug.cfs_rq[4]:/.blocked_load_avg
> >       5999 Â 30%     -34.5%       3929 Â 11%  sched_debug.cfs_rq[4]:/.tg_load_contrib
> >      37884 Â 13%     -33.5%      25207 Â  7%  sched_debug.cfs_rq[4]:/.tg_load_avg
> >     229547 Â  5%     +47.9%     339519 Â  5%  cpuidle.C1-NHM.usage
> >      35712 Â  3%     +31.7%      47036 Â  9%  cpuidle.C3-NHM.usage
> >       5010 Â  9%     -29.0%       3556 Â 20%  sched_debug.cfs_rq[6]:/.blocked_load_avg
> >       5139 Â  9%     -28.2%       3690 Â 19%  sched_debug.cfs_rq[6]:/.tg_load_contrib
> >      49568 Â  6%     +24.8%      61867 Â  7%  sched_debug.cpu#1.sched_goidle
> >      26369 Â 35%     -42.0%      15289 Â 29%  cpuidle.C6-NHM.usage
> >         18 Â 16%     +36.5%         25 Â  7%  sched_debug.cpu#4.nr_running
> >       1.41 Â 12%     -19.3%       1.14 Â 13%  perf-profile.cpu-cycles.sock_wfree.unix_destruct_scm.skb_release_head_state.skb_release_all.consume_skb
> >         25 Â 15%     +28.7%         32 Â  9%  sched_debug.cpu#3.nr_running
> >       1.63 Â 11%     -18.0%       1.34 Â 12%  perf-profile.cpu-cycles.unix_destruct_scm.skb_release_head_state.skb_release_all.consume_skb.unix_stream_recvmsg
> >       0.57 Â  8%      +9.6%       0.62 Â  5%  turbostat.CPU%c1
> >        148 Â 11%     -16.7%        123 Â  7%  sched_debug.cfs_rq[1]:/.load
> >        109 Â  6%     +17.1%        128 Â  6%  sched_debug.cpu#6.cpu_load[0]
> >       2.41 Â  8%     -13.3%       2.09 Â 11%  perf-profile.cpu-cycles.skb_release_head_state.skb_release_all.consume_skb.unix_stream_recvmsg.sock_aio_read
> >        147 Â 12%     -16.4%        123 Â  7%  sched_debug.cpu#1.load
> >        111 Â  5%     +15.4%        129 Â  5%  sched_debug.cpu#6.cpu_load[2]
> >        110 Â  5%     +14.9%        127 Â  5%  sched_debug.cfs_rq[6]:/.runnable_load_avg
> >        112 Â  5%     +14.5%        128 Â  4%  sched_debug.cpu#6.cpu_load[3]
> >        113 Â  5%     +13.2%        128 Â  3%  sched_debug.cpu#6.cpu_load[4]
> >     789953 Â  2%     -10.8%     704528 Â  4%  sched_debug.cpu#3.avg_idle
> >      15471 Â  5%      -7.7%      14278 Â  2%  sched_debug.cpu#5.curr->pid
> >    2675106 Â 10%     +16.2%    3109411 Â  1%  sched_debug.cpu#4.nr_switches
> >    2675140 Â 10%     +16.2%    3109440 Â  1%  sched_debug.cpu#4.sched_count
> >     155201 Â  5%     +14.6%     177901 Â  3%  softirqs.RCU
> >       8.64 Â  6%      -9.6%       7.82 Â  5%  perf-profile.cpu-cycles.skb_release_all.consume_skb.unix_stream_recvmsg.sock_aio_read.sock_aio_read
> >    2658351 Â 11%     +13.7%    3021564 Â  2%  sched_debug.cpu#5.sched_count
> >    2658326 Â 11%     +13.7%    3021539 Â  2%  sched_debug.cpu#5.nr_switches
> >      71443 Â  5%      +9.9%      78486 Â  0%  vmstat.system.cs
> >       8209 Â  5%      +7.3%       8805 Â  0%  vmstat.system.in
> > 
> 
> OK, so the interesting number is total runtime; I cannot find it.
> Therefore I cannot say what if anything changed. This is just a bunch of
> random numbers afaict.

The total runtime of hackbench in v3.19 compared to v3.15 to v3.18 is
shown here [1] (Group 5 -> linux_perf.hackbench). It is not the same
project so the profiling data is not related and not recorded. The
results should be reproducable by simply running hackbench with the same
options as cbenchsuite [2] did. The options are always listed in the
result browser [1] below the plots.

Best Regards,

Markus

[1] http://results.cbenchsuite.org/plots/2015-02-09__v3.15-v3.19-quad/detailed/
[2] http://cbenchsuite.org

Attachment: signature.asc
Description: Digital signature