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>] [day] [month] [year] [list]
Message-ID: <20160519011657.GB11822@yexl-desktop>
Date:	Thu, 19 May 2016 09:16:57 +0800
From:	kernel test robot <xiaolong.ye@...el.com>
To:	Jens Axboe <axboe@...com>
Cc:	LKML <linux-kernel@...r.kernel.org>, Jens Axboe <axboe@...com>,
	Jens Axboe <axboe@...nel.dk>, lkp@...org
Subject: [lkp] [writeback] 074e46e1ad: fio.write_bw_MBps -10.5% regression

FYI, we noticed fio.write_bw_MBps -10.5% regression due to commit:

commit 074e46e1aded0ac0474a5db4d50d514d9dc42e78 ("writeback: throttle buffered writeback")
https://git.kernel.org/pub/scm/linux/kernel/git/axboe/linux-block.git wb-buf-throttle

in testcase: fio-basic
on test machine: lkp-bdw-ep2:  threads Broadwell-EP with 128G memory
with following conditions: bs=4k/cpufreq_governor=performance/disk=1SSD/fs=xfs/ioengine=sync/nr_task=8/runtime=300/rw=write/test_size=512g



Details are as below:
-------------------------------------------------------------------------------------------------->


=========================================================================================
bs/compiler/cpufreq_governor/disk/fs/ioengine/kconfig/nr_task/rootfs/runtime/rw/tbox_group/test_size/testcase:
  4k/gcc-4.9/performance/1SSD/xfs/sync/x86_64-rhel/8/debian-x86_64-2015-02-07.cgz/300/write/lkp-bdw-ep2/512g/fio-basic

commit: 
  565d33b77b63e5f70357ebf97c4141044854f621
  074e46e1aded0ac0474a5db4d50d514d9dc42e78

565d33b77b63e5f7 074e46e1aded0ac0474a5db4d5 
---------------- -------------------------- 
       fail:runs  %reproduction    fail:runs
           |             |             |    
          1:4          -25%            :5     kmsg.ENERGY_PERF_BIAS:Set_to'normal',was'performance'
          1:4          -25%            :5     kmsg.ENERGY_PERF_BIAS:View_and_update_with_x86_energy_perf_policy(#)
         %stddev     %change         %stddev
             \          |                \  
    289.61 ±  0%      +3.7%     300.36 ±  0%  fio.time.elapsed_time
    289.61 ±  0%      +3.7%     300.36 ±  0%  fio.time.elapsed_time.max
 1.074e+09 ±  0%      -7.1%  9.971e+08 ±  0%  fio.time.file_system_outputs
      3446 ±  9%     -64.2%       1234 ± 27%  fio.time.involuntary_context_switches
    105.50 ±  0%     -12.8%      92.00 ±  0%  fio.time.percent_of_cpu_this_job_got
    268.34 ±  0%     -10.4%     240.47 ±  1%  fio.time.system_time
     98347 ±  0%      +4.6%     102892 ±  0%  fio.time.voluntary_context_switches
      1812 ±  0%     -10.5%       1622 ±  0%  fio.write_bw_MBps
    463987 ±  0%     -10.5%     415407 ±  0%  fio.write_iops
    239.56 ±  0%      -1.9%     235.12 ±  0%  pmeter.Average_Active_Power
      1944 ±  0%      -8.8%       1773 ±  0%  pmeter.performance_per_watt
      3446 ±  9%     -64.2%       1234 ± 27%  time.involuntary_context_switches
    105.50 ±  0%     -12.8%      92.00 ±  0%  time.percent_of_cpu_this_job_got
    268.34 ±  0%     -10.4%     240.47 ±  1%  time.system_time
   1774732 ±  0%     -10.9%    1581981 ±  0%  vmstat.io.bo
      8570 ±  1%     -48.5%       4417 ±  1%  vmstat.system.cs
     17991 ±  0%     -11.1%      15999 ±  0%  vmstat.system.in
     31090 ±  2%      -8.5%      28447 ±  1%  meminfo.Active(anon)
      7169 ± 12%     -32.5%       4839 ±  0%  meminfo.AnonHugePages
     28207 ±  3%      -8.3%      25865 ±  1%  meminfo.AnonPages
    969710 ±  0%     -12.9%     844795 ±  0%  meminfo.Writeback
      4437 ± 22%     -32.7%       2986 ± 24%  numa-vmstat.node0.nr_active_anon
      3915 ± 19%     -27.6%       2835 ± 18%  numa-vmstat.node0.nr_anon_pages
    125910 ±  6%     -14.5%     107612 ±  7%  numa-vmstat.node0.nr_writeback
     17293 ±  5%      -6.5%      16170 ±  5%  numa-vmstat.node1.nr_slab_unreclaimable
    120890 ±  5%     -14.7%     103101 ±  8%  numa-vmstat.node1.nr_writeback
 1.837e+08 ±  5%     +12.8%  2.072e+08 ±  5%  cpuidle.C1-BDW.time
   2471919 ±  1%     +15.3%    2849758 ±  3%  cpuidle.C1-BDW.usage
 1.565e+08 ± 11%     -13.7%   1.35e+08 ± 10%  cpuidle.C1E-BDW.time
 2.784e+08 ± 16%     -80.3%   54791144 ± 18%  cpuidle.C3-BDW.time
    380002 ±  5%     -24.9%     285251 ± 10%  cpuidle.C3-BDW.usage
   1340681 ±  2%     -32.0%     911539 ±  7%  cpuidle.C6-BDW.usage
     71772 ±  6%      -9.0%      65308 ±  4%  numa-meminfo.node0.Active
     17749 ± 22%     -32.7%      11947 ± 24%  numa-meminfo.node0.Active(anon)
      5249 ± 49%     -66.0%       1786 ±123%  numa-meminfo.node0.AnonHugePages
     15662 ± 19%     -27.6%      11342 ± 18%  numa-meminfo.node0.AnonPages
    503521 ±  6%     -14.1%     432594 ±  7%  numa-meminfo.node0.Writeback
     69173 ±  5%      -6.5%      64685 ±  5%  numa-meminfo.node1.SUnreclaim
    483701 ±  5%     -14.7%     412545 ±  8%  numa-meminfo.node1.Writeback
      1.77 ±  1%     -14.4%       1.52 ±  1%  turbostat.%Busy
     59.50 ±  1%     -13.6%      51.40 ±  0%  turbostat.Avg_MHz
      6.52 ±  2%     -17.7%       5.36 ±  2%  turbostat.CPU%c1
      1.47 ± 20%     -82.3%       0.26 ± 23%  turbostat.CPU%c3
      0.24 ± 48%     +52.4%       0.36 ±  5%  turbostat.Pkg%pc6
     93.44 ±  0%      -2.6%      90.99 ±  0%  turbostat.PkgWatt
     58.25 ±  0%      -1.8%      57.22 ±  1%  turbostat.RAMWatt
    675.50 ±  6%     -46.5%     361.60 ±  7%  proc-vmstat.kswapd_low_wmark_hit_quickly
      7768 ±  2%      -8.5%       7108 ±  1%  proc-vmstat.nr_active_anon
      7047 ±  3%      -8.3%       6463 ±  1%  proc-vmstat.nr_anon_pages
    242465 ±  0%     -12.8%     211436 ±  0%  proc-vmstat.nr_writeback
      1544 ±  5%      -9.8%       1393 ±  1%  proc-vmstat.pgactivate
 1.058e+08 ±  0%      -9.4%   95845408 ±  0%  proc-vmstat.pgfree
 1.015e+08 ±  0%      -9.4%   91969429 ±  0%  proc-vmstat.pgscan_kswapd_normal
 1.014e+08 ±  0%      -9.4%   91873948 ±  0%  proc-vmstat.pgsteal_kswapd_normal
      1.76 ±  3%     -23.4%       1.35 ±  4%  perf-profile.cycles-pp.blk_mq_make_request
     18.28 ±  5%     -14.4%      15.64 ±  7%  perf-profile.cycles-pp.call_cpuidle
     19.04 ±  5%     -14.1%      16.34 ±  7%  perf-profile.cycles-pp.cpu_startup_entry
     18.27 ±  5%     -14.5%      15.63 ±  7%  perf-profile.cycles-pp.cpuidle_enter
     15.93 ±  5%     -15.3%      13.50 ±  9%  perf-profile.cycles-pp.cpuidle_enter_state
      1.79 ±  3%     -22.5%       1.39 ±  2%  perf-profile.cycles-pp.generic_make_request
     15.70 ±  5%     -16.1%      13.17 ± 10%  perf-profile.cycles-pp.intel_idle
     18.21 ±  5%     -15.5%      15.40 ±  7%  perf-profile.cycles-pp.start_secondary
      1.79 ±  3%     -22.5%       1.39 ±  2%  perf-profile.cycles-pp.submit_bio
      2.56 ±  0%     -22.5%       1.99 ±  2%  perf-profile.cycles-pp.xfs_submit_ioend
      1.80 ±  3%     -22.5%       1.39 ±  2%  perf-profile.cycles-pp.xfs_submit_ioend_bio
      6238 ±  1%     -14.0%       5367 ±  3%  slabinfo.kmalloc-1024.active_objs
      6430 ±  1%     -15.4%       5442 ±  3%  slabinfo.kmalloc-1024.num_objs
     25207 ±  3%     -65.5%       8700 ±  2%  slabinfo.kmalloc-128.active_objs
    398.75 ±  3%     -66.0%     135.40 ±  1%  slabinfo.kmalloc-128.active_slabs
     25559 ±  3%     -65.9%       8709 ±  1%  slabinfo.kmalloc-128.num_objs
    398.75 ±  3%     -66.0%     135.40 ±  1%  slabinfo.kmalloc-128.num_slabs
     14482 ±  0%     -35.4%       9349 ±  1%  slabinfo.kmalloc-192.active_objs
    347.75 ±  0%     -36.0%     222.40 ±  1%  slabinfo.kmalloc-192.active_slabs
     14626 ±  0%     -36.0%       9360 ±  1%  slabinfo.kmalloc-192.num_objs
    347.75 ±  0%     -36.0%     222.40 ±  1%  slabinfo.kmalloc-192.num_slabs
      1644 ±  1%     -10.0%       1480 ±  1%  slabinfo.kmalloc-4096.active_objs
      1703 ±  1%      -9.5%       1541 ±  1%  slabinfo.kmalloc-4096.num_objs
     22806 ±  2%      -9.4%      20665 ±  3%  slabinfo.kmalloc-512.active_objs
     23061 ±  3%     -10.4%      20670 ±  3%  slabinfo.kmalloc-512.num_objs
     49871 ±  0%     -16.9%      41459 ±  0%  slabinfo.kmalloc-64.active_objs
    783.00 ±  0%     -17.0%     649.80 ±  0%  slabinfo.kmalloc-64.active_slabs
     50152 ±  0%     -17.1%      41598 ±  0%  slabinfo.kmalloc-64.num_objs
    783.00 ±  0%     -17.0%     649.80 ±  0%  slabinfo.kmalloc-64.num_slabs
     22015 ±  1%     -20.7%      17458 ±  4%  slabinfo.kmalloc-96.active_objs
    529.25 ±  1%     -20.8%     419.40 ±  4%  slabinfo.kmalloc-96.active_slabs
     22233 ±  1%     -20.7%      17632 ±  4%  slabinfo.kmalloc-96.num_objs
    529.25 ±  1%     -20.8%     419.40 ±  4%  slabinfo.kmalloc-96.num_slabs
     34.21 ±154%     -93.6%       2.21 ± 38%  sched_debug.cfs_rq:/.runnable_load_avg.avg
      2872 ±161%     -96.2%     108.07 ± 44%  sched_debug.cfs_rq:/.runnable_load_avg.max
    306.53 ±160%     -95.7%      13.25 ± 41%  sched_debug.cfs_rq:/.runnable_load_avg.stddev
     34.84 ±  9%     -21.3%      27.43 ±  3%  sched_debug.cfs_rq:/.util_avg.avg
    471.10 ± 13%     -17.3%     389.73 ±  6%  sched_debug.cfs_rq:/.util_avg.max
     83.48 ±  6%     -18.1%      68.41 ±  3%  sched_debug.cfs_rq:/.util_avg.stddev
    350786 ±  3%     +32.0%     463179 ±  9%  sched_debug.cpu.avg_idle.min
    165474 ±  9%     -23.8%     126079 ± 12%  sched_debug.cpu.avg_idle.stddev
    167991 ±  2%     +19.6%     200863 ±  0%  sched_debug.cpu.clock.avg
    167997 ±  2%     +19.6%     200869 ±  0%  sched_debug.cpu.clock.max
    167942 ±  2%     +19.6%     200832 ±  0%  sched_debug.cpu.clock.min
      8.46 ± 23%     -28.8%       6.02 ± 21%  sched_debug.cpu.clock.stddev
    167991 ±  2%     +19.6%     200863 ±  0%  sched_debug.cpu.clock_task.avg
    167997 ±  2%     +19.6%     200869 ±  0%  sched_debug.cpu.clock_task.max
    167942 ±  2%     +19.6%     200832 ±  0%  sched_debug.cpu.clock_task.min
      8.46 ± 23%     -28.8%       6.02 ± 21%  sched_debug.cpu.clock_task.stddev
      3039 ±153%     -92.6%     224.07 ± 35%  sched_debug.cpu.cpu_load[0].max
      2930 ±155%     -93.4%     192.50 ± 23%  sched_debug.cpu.cpu_load[1].max
    316.33 ±152%     -91.6%      26.43 ± 24%  sched_debug.cpu.cpu_load[1].stddev
     34.90 ±142%     -87.2%       4.47 ± 12%  sched_debug.cpu.cpu_load[2].avg
      2792 ±157%     -93.9%     169.40 ± 19%  sched_debug.cpu.cpu_load[2].max
    300.71 ±154%     -92.6%      22.15 ± 17%  sched_debug.cpu.cpu_load[2].stddev
     32.00 ±144%     -88.4%       3.70 ± 10%  sched_debug.cpu.cpu_load[3].avg
      2573 ±157%     -94.2%     150.10 ± 23%  sched_debug.cpu.cpu_load[3].max
    276.30 ±155%     -93.2%      18.91 ± 17%  sched_debug.cpu.cpu_load[3].stddev
     26.92 ±143%     -87.8%       3.28 ±  7%  sched_debug.cpu.cpu_load[4].avg
      2160 ±157%     -93.3%     145.60 ± 19%  sched_debug.cpu.cpu_load[4].max
    231.48 ±155%     -92.5%      17.47 ± 15%  sched_debug.cpu.cpu_load[4].stddev
     12611 ±  2%     -33.4%       8396 ±  2%  sched_debug.cpu.nr_switches.avg
     68299 ±  7%     -37.6%      42632 ± 11%  sched_debug.cpu.nr_switches.max
     14204 ±  2%     -38.9%       8675 ±  1%  sched_debug.cpu.nr_switches.stddev
     13.50 ± 13%     +95.1%      26.33 ± 15%  sched_debug.cpu.nr_uninterruptible.max
    -30.65 ±-20%     +63.9%     -50.23 ±-17%  sched_debug.cpu.nr_uninterruptible.min
      6.48 ±  7%     +55.3%      10.07 ±  7%  sched_debug.cpu.nr_uninterruptible.stddev
    167990 ±  2%     +19.6%     200861 ±  0%  sched_debug.cpu_clk
    164597 ±  2%     +19.9%     197433 ±  0%  sched_debug.ktime
    167990 ±  2%     +19.6%     200861 ±  0%  sched_debug.sched_clk



                                 fio.write_bw_MBps

  1850 ++-------------------------------------------------------------------+
       | .*..*.*..                                                          |
       *.         *..*..*.*..*..*.. .*..*..*..*.*..*..*..*.*..*..  .*.*..*..*
  1800 ++                          *                             *.         |
       |                                                                    |
       |                                                                    |
  1750 ++                                                                   |
       |                                                                    |
  1700 ++                                                                   |
       |                                                                    |
       |                                                                    |
  1650 ++                                                                   |
       |                                                                    |
       O  O  O O  O                                                         |
  1600 ++-------------------------------------------------------------------+


                                   fio.write_iops

  470000 ++------*----------------------------------------------------------+
         *..*.*.    *.*..*..*.*..*..    .*..  .*.  .*..*.*..       .*..*.*..*
  460000 ++                         *.*.    *.   *.         *..*.*.         |
         |                                                                  |
         |                                                                  |
  450000 ++                                                                 |
         |                                                                  |
  440000 ++                                                                 |
         |                                                                  |
  430000 ++                                                                 |
         |                                                                  |
         |                                                                  |
  420000 ++                                                                 |
         O  O O  O  O                                                       |
  410000 ++-----------------------------------------------------------------+


                                turbostat.Avg_MHz

  75 ++---------------------------------------------------------------------+
     |                                                                      |
     | .*..*..*.*..                                                         |
  70 *+                                                                     |
     |             *..*                                                     |
     |                 :                                                    |
  65 ++                :                                                    |
     |                  :                                                   |
  60 ++                 :       .*..     .*..*..    .*..                   .*
     |                   *..*..*    *..*.       *.*.    *..*..*..*.*..*..*. |
     |                                                                      |
  55 ++                                                                     |
     |                                                                      |
     O  O  O  O O                                                           |
  50 ++---------------------------------------------------------------------+


                                  turbostat._Busy

  2.2 ++--------------------------------------------------------------------+
      | .*..*.                                                              |
  2.1 *+      *..*..                                                        |
    2 ++              .*                                                    |
      |             *.  :                                                   |
  1.9 ++                :                                                   |
      |                  :                                                  |
  1.8 ++                 :               .*..*..     .*.                   .*
      |                   *.*..*..*..*..*       *..*.   *..*..*..*..*.*..*. |
  1.7 ++                                                                    |
  1.6 ++                                                                    |
      |  O                                                                  |
  1.5 O+    O O  O                                                          |
      |                                                                     |
  1.4 ++--------------------------------------------------------------------+


                                 turbostat.CPU_c3

    2 ++--------------------*-----------------------------------------*-----+
  1.8 ++                    :+                                        ::    |
      |                *.. :  +      *..             .*.             :  :   |
  1.6 ++             ..    :   *..  +   *.  .*..   *.   *..          :  :   |
  1.4 ++    *.     .*     *        +      *.     ..        *..*..*.. :   *..*
      |   ..  *..*.               *             *                   :       |
  1.2 *+.*                                                          *       |
    1 ++                                                                    |
  0.8 ++                                                                    |
      |                                                                     |
  0.6 ++                                                                    |
  0.4 ++                                                                    |
      |  O  O    O                                                          |
  0.2 O+      O                                                             |
    0 ++--------------------------------------------------------------------+


                               fio.time.system_time

  285 ++--------------------------------------------------------------------+
  280 ++ *..                                          *                     |
      | +   *.  .*                                    ::                    |
  275 ++      *.  :        .*..         *            : :                    |
  270 *+           :      *    *..     : :           :  :          .*.*..*..|
      |            :    ..             : :  .*..    :   *..     .*.         |
  265 ++            *..*          *.. :   *.    *.. :        .*.            *
  260 ++                             *             *       *.               |
  255 ++                                                                    |
      |                                                                     |
  250 ++                                                                    |
  245 ++         O                                                          |
      |  O    O                                                             |
  240 ++    O                                                               |
  235 O+--------------------------------------------------------------------+


                       fio.time.percent_of_cpu_this_job_got

  110 ++-*--------------------------------------------*---------------------+
  108 ++.   *.*..*                      *            : :                    |
      *           :        .*..        : :           : :                    |
  106 ++           :      *    *..     : :  .*..    :   *          .*.*..*..|
  104 ++           :    ..            :   *.        :    +      .*.         *
      |             *..*          *..*          *..*      +  .*.            |
  102 ++                                                   *.               |
  100 ++                                                                    |
   98 ++                                                                    |
      |                                                                     |
   96 ++                                                                    |
   94 ++                                                                    |
      |       O  O                                                          |
   92 O+ O  O                                                               |
   90 ++--------------------------------------------------------------------+


                               fio.time.elapsed_time

  302 ++--------------------------------------------------------------------+
      O  O  O O  O                                                          |
  300 ++                                                                    |
  298 ++                                                                    |
      |                                                                     |
  296 ++                                                                    |
      |                                                                     |
  294 ++                                                                    |
      |                                                                     |
  292 ++                          *..                           .*..        |
  290 ++                        ..   *.. .*..  .*..        *..*.            |
      |            .*..*..*.*..*        *    *.    *..*. ..         *.*..*..*
  288 *+.       .*.                                     *                   |
      |  *..*.*.                                                            |
  286 ++--------------------------------------------------------------------+


                             fio.time.elapsed_time.max

  302 ++--------------------------------------------------------------------+
      O  O  O O  O                                                          |
  300 ++                                                                    |
  298 ++                                                                    |
      |                                                                     |
  296 ++                                                                    |
      |                                                                     |
  294 ++                                                                    |
      |                                                                     |
  292 ++                          *..                           .*..        |
  290 ++                        ..   *.. .*..  .*..        *..*.            |
      |            .*..*..*.*..*        *    *.    *..*. ..         *.*..*..*
  288 *+.       .*.                                     *                   |
      |  *..*.*.                                                            |
  286 ++--------------------------------------------------------------------+


                         fio.time.voluntary_context_switches

  104000 ++-----------------------------------------------------------------+
         |                                                                  |
  103000 O+ O O  O  O                                                       |
  102000 ++                                                                 |
         |                                                                  |
  101000 ++                                                                 |
         |                                                                  |
  100000 ++                                                                 |
         |                                                                  |
   99000 ++                        .*.          .*..        *.. .*..        |
   98000 ++           *..*..*.*..*.   *..*..*..*    *..*. ..   *    *..*.*..*
         |           +                                   *                  |
   97000 *+.*.*..*..*                                                       |
         |                                                                  |
   96000 ++-----------------------------------------------------------------+


                             fio.time.file_system_outputs

  1.08e+09 ++---------------------------------------------------------------+
           *..*.*..*.*..*..*.*..*.*..*..*.*..*.*..*..*.*..*.*..*..*.*..*.*..*
  1.07e+09 ++                                                               |
  1.06e+09 ++                                                               |
           |                                                                |
  1.05e+09 ++                                                               |
  1.04e+09 ++                                                               |
           |                                                                |
  1.03e+09 ++                                                               |
  1.02e+09 ++                                                               |
           |                                                                |
  1.01e+09 ++                                                               |
     1e+09 ++                                                               |
           O  O O  O O                                                      |
   9.9e+08 ++---------------------------------------------------------------+



	[*] bisect-good sample
	[O] bisect-bad  sample

To reproduce:

        git clone git://git.kernel.org/pub/scm/linux/kernel/git/wfg/lkp-tests.git
        cd lkp-tests
        bin/lkp install job.yaml  # job file is attached in this email
        bin/lkp run     job.yaml



Disclaimer:
Results have been estimated based on internal Intel analysis and are provided
for informational purposes only. Any difference in system hardware or software
design or configuration may affect actual performance.


Thanks,
Xiaolong

View attachment "job.yaml" of type "text/plain" (3687 bytes)

View attachment "reproduce" of type "text/plain" (8624 bytes)

Powered by blists - more mailing lists

Powered by Openwall GNU/*/Linux Powered by OpenVZ