lists.openwall.net   lists  /  announce  owl-users  owl-dev  john-users  john-dev  passwdqc-users  yescrypt  popa3d-users  /  oss-security  kernel-hardening  musl  sabotage  tlsify  passwords  /  crypt-dev  xvendor  /  Bugtraq  Full-Disclosure  linux-kernel  linux-netdev  linux-ext4  linux-hardening  linux-cve-announce  PHC 
Open Source and information security mailing list archives
 
Hash Suite: Windows password security audit tool. GUI, reports in PDF.
[<prev] [next>] [<thread-prev] [thread-next>] [day] [month] [year] [list]
Date:	Tue, 18 Aug 2009 15:50:17 -0700
From:	john stultz <johnstul@...ibm.com>
To:	Thomas Gleixner <tglx@...utronix.de>
Cc:	LKML <linux-kernel@...r.kernel.org>,
	rt-users <linux-rt-users@...r.kernel.org>,
	Ingo Molnar <mingo@...e.hu>,
	Steven Rostedt <rostedt@...dmis.org>,
	Peter Zijlstra <peterz@...radead.org>,
	Carsten Emde <ce@...g.ch>,
	Clark Williams <williams@...hat.com>,
	Frank Rowand <frank.rowand@...sony.com>,
	Robin Gareus <robin@...eus.org>,
	Gregory Haskins <ghaskins@...ell.com>,
	Philippe Reynes <philippe.reynes@...smpp.fr>,
	Fernando Lopez-Lezcano <nando@...ma.stanford.edu>,
	Will Schmidt <will_schmidt@...t.ibm.com>,
	Darren Hart <dvhltc@...ibm.com>, Jan Blunck <jblunck@...e.de>,
	Sven-Thorsten Dietrich <sdietrich@...ell.com>,
	Jon Masters <jcm@...hat.com>
Subject: Re: [ANNOUNCE] 2.6.31-rc6-rt2

On Tue, Aug 18, 2009 at 3:31 PM, john stultz<johnstul@...ibm.com> wrote:
> On Sun, Aug 16, 2009 at 1:41 PM, Thomas Gleixner<tglx@...utronix.de> wrote:
>> We are pleased to announce the next update to our new preempt-rt
>> series.
>>
>>    - update to 2.6.31-rc6
>>
>
> I'm seeing some bad scheduler behavior with this patch. I've seen
> occasional bad behavior with 2.6.29-rt as well, but with .31-rt its
> much worse.
>
> I'm running a SCHED_OTHER cpubound benchmark  (censored to
> xxxxxxxxxxxxx in the logs) that runs for a number of minutes. With
> 2.6.31-rc6 I'm seeing really poor numbers and if I cat
> /proc/sched_debug I see all of the cpu bound tasks are  running on the
> same cpu, while the other procs are basically idle. See the log below:

Thomas didn't like that I censored the benchmark, so until I know
better about what I can say there, I've reproduced a similar effect
with a make -j8 bzImage. See below:

thanks
-john


Sched Debug Version: v0.09, 2.6.31-rc6-rt2 #2
now at 3297823.422240 msecs
  .jiffies                                 : 4297965119
  .sysctl_sched_latency                    : 60.000000
  .sysctl_sched_min_granularity            : 12.000000
  .sysctl_sched_wakeup_granularity         : 15.000000
  .sysctl_sched_child_runs_first           : 0.000001
  .sysctl_sched_features                   : 113917

cpu#0, 2193.531 MHz
  .nr_running                    : 4
  .load                          : 3087
  .nr_switches                   : 10622255
  .nr_load_updates               : 3297812
  .nr_uninterruptible            : 51
  .next_balance                  : 4297.965146
  .curr->pid                     : 26387
  .clock                         : 3297823.016251
  .cpu_load[0]                   : 180594
  .cpu_load[1]                   : 231489
  .cpu_load[2]                   : 238710
  .cpu_load[3]                   : 236501
  .cpu_load[4]                   : 233349
  .rt.rt_nr_running              : 0
  .rt.rt_nr_uninterruptible      : -13
  .rto_schedule                  : 3359261
  .rto_schedule_tail             : 0
  .rto_wakeup                    : 0
  .rto_pulled                    : 0
  .rto_pushed                    : 0
  .yld_count                     : 1
  .sched_switch                  : 0
  .sched_count                   : 17260145
  .sched_goidle                  : 1789234
  .ttwu_count                    : 7093762
  .ttwu_local                    : 7041555
  .bkl_count                     : 544

cfs_rq[0]:
  .exec_clock                    : 1526490.657852
  .MIN_vruntime                  : 1697673.859107
  .min_vruntime                  : 1697721.435148
  .max_vruntime                  : 1697722.132915
  .spread                        : 48.273808
  .spread0                       : 0.000000
  .nr_running                    : 4
  .load                          : 3087
  .nr_spread_over                : 0

rt_rq[0]:
  .rt_nr_running                 : 0
  .rt_throttled                  : 0
  .rt_time                       : 2.794815
  .rt_runtime                    : 950.000000

runnable tasks:
            task   PID         tree-key  switches  prio
exec-runtime         sum-exec        sum-sleep
----------------------------------------------------------------------------------------------------------
          kipmi0   655   1697673.859107   3125949   139
1697673.859107     22219.014181   3087520.179107
            bash  3472   1697721.436567       311   120
1697721.436567        36.956916   2565232.593307
             cc1 26385   1697722.132915       124   120
1697722.132915       113.879128         0.000000
R            cat 26387   1697662.324743         4   120
1697662.324743         1.030048        16.225876

cpu#1, 2193.531 MHz
  .nr_running                    : 7
  .load                          : 7168
  .nr_switches                   : 7939426
  .nr_load_updates               : 3297202
  .nr_uninterruptible            : 165
  .next_balance                  : 4297.965173
  .curr->pid                     : 26336
  .clock                         : 3297823.399906
  .cpu_load[0]                   : 184690
  .cpu_load[1]                   : 229070
  .cpu_load[2]                   : 218000
  .cpu_load[3]                   : 204927
  .cpu_load[4]                   : 198665
  .rt.rt_nr_running              : 0
  .rt.rt_nr_uninterruptible      : -13
  .rto_schedule                  : 3372469
  .rto_schedule_tail             : 0
  .rto_wakeup                    : 0
  .rto_pulled                    : 0
  .rto_pushed                    : 0
  .yld_count                     : 0
  .sched_switch                  : 0
  .sched_count                   : 7948572
  .sched_goidle                  : 2241052
  .ttwu_count                    : 4381283
  .ttwu_local                    : 4325894
  .bkl_count                     : 657

cfs_rq[1]:
  .exec_clock                    : 1071210.085128
  .MIN_vruntime                  : 384918.473172
  .min_vruntime                  : 384918.235870
  .max_vruntime                  : 384918.873276
  .spread                        : 0.400104
  .spread0                       : -1312803.199278
  .nr_running                    : 7
  .load                          : 7168
  .nr_spread_over                : 6

rt_rq[1]:
  .rt_nr_running                 : 0
  .rt_throttled                  : 0
  .rt_time                       : 3.774163
  .rt_runtime                    : 950.000000

runnable tasks:
            task   PID         tree-key  switches  prio
exec-runtime         sum-exec        sum-sleep
----------------------------------------------------------------------------------------------------------
             cc1 26050    384918.473172      2253   120
384918.473172      1909.594817       113.729925
             cc1 26315    384918.593007       500   120
384918.593007       454.022678        28.557925
R            cc1 26336    384918.237098       405   120
384918.237098       356.613052        25.673456
             cc1 26351    384918.816523       304   120
384918.816523       274.220163        24.214767
             cc1 26357    384918.476355       290   120
384918.476355       254.796027        28.269487
             cc1 26364    384918.730242       339   120
384918.730242       314.419053        17.154139
             cc1 26378    384918.873276       110   120
384918.873276       100.034046         5.567260

cpu#2, 2193.531 MHz
  .nr_running                    : 0
  .load                          : 0
  .nr_switches                   : 7657407
  .nr_load_updates               : 3296882
  .nr_uninterruptible            : -118
  .next_balance                  : 4297.965123
  .curr->pid                     : 0
  .clock                         : 3297823.260220
  .cpu_load[0]                   : 177522
  .cpu_load[1]                   : 177522
  .cpu_load[2]                   : 177522
  .cpu_load[3]                   : 177522
  .cpu_load[4]                   : 177522
  .rt.rt_nr_running              : 0
  .rt.rt_nr_uninterruptible      : -6
  .rto_schedule                  : 3332888
  .rto_schedule_tail             : 0
  .rto_wakeup                    : 0
  .rto_pulled                    : 0
  .rto_pushed                    : 0
  .yld_count                     : 0
  .sched_switch                  : 0
  .sched_count                   : 7657972
  .sched_goidle                  : 3078184
  .ttwu_count                    : 4260805
  .ttwu_local                    : 4234948
  .bkl_count                     : 0

cfs_rq[2]:
  .exec_clock                    : 233036.033916
  .MIN_vruntime                  : 0.000001
  .min_vruntime                  : 107747.557398
  .max_vruntime                  : 0.000001
  .spread                        : 0.000000
  .spread0                       : -1589973.877750
  .nr_running                    : 0
  .load                          : 0
  .nr_spread_over                : 0

rt_rq[2]:
  .rt_nr_running                 : 0
  .rt_throttled                  : 0
  .rt_time                       : 0.856935
  .rt_runtime                    : 950.000000

runnable tasks:
            task   PID         tree-key  switches  prio
exec-runtime         sum-exec        sum-sleep
----------------------------------------------------------------------------------------------------------

cpu#3, 2193.531 MHz
  .nr_running                    : 0
  .load                          : 0
  .nr_switches                   : 7631340
  .nr_load_updates               : 3296553
  .nr_uninterruptible            : -98
  .next_balance                  : 4297.965121
  .curr->pid                     : 0
  .clock                         : 3297823.383808
  .cpu_load[0]                   : 177522
  .cpu_load[1]                   : 177522
  .cpu_load[2]                   : 177522
  .cpu_load[3]                   : 177522
  .cpu_load[4]                   : 177522
  .rt.rt_nr_running              : 0
  .rt.rt_nr_uninterruptible      : -15
  .rto_schedule                  : 3331154
  .rto_schedule_tail             : 0
  .rto_wakeup                    : 0
  .rto_pulled                    : 0
  .rto_pushed                    : 0
  .yld_count                     : 0
  .sched_switch                  : 0
  .sched_count                   : 7632024
  .sched_goidle                  : 3084753
  .ttwu_count                    : 4240808
  .ttwu_local                    : 4233012
  .bkl_count                     : 0

cfs_rq[3]:
  .exec_clock                    : 226437.391084
  .MIN_vruntime                  : 0.000001
  .min_vruntime                  : 121397.454749
  .max_vruntime                  : 0.000001
  .spread                        : 0.000000
  .spread0                       : -1576323.980399
  .nr_running                    : 0
  .load                          : 0
  .nr_spread_over                : 0

rt_rq[3]:
  .rt_nr_running                 : 0
  .rt_throttled                  : 0
  .rt_time                       : 0.818937
  .rt_runtime                    : 950.000000

runnable tasks:
            task   PID         tree-key  switches  prio
exec-runtime         sum-exec        sum-sleep
----------------------------------------------------------------------------------------------------------
--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo@...r.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html
Please read the FAQ at  http://www.tux.org/lkml/

Powered by blists - more mailing lists

Powered by Openwall GNU/*/Linux Powered by OpenVZ