public inbox for linux-kernel@vger.kernel.org
 help / color / mirror / Atom feed
* [lkp] [sched/preempt] 103637a5b94: 12.4% fsmark.app_overhead, -1.4% fsmark.files_per_sec
@ 2015-07-25  6:09 kernel test robot
  2015-07-25 16:32 ` Konstantin Khlebnikov
  0 siblings, 1 reply; 3+ messages in thread
From: kernel test robot @ 2015-07-25  6:09 UTC (permalink / raw)
  To: Konstantin Khlebnikov; +Cc: lkp, LKML, Peter Zijlstra

[-- Attachment #1: Type: text/plain, Size: 12174 bytes --]

FYI, we noticed the below changes on

git://internal_merge_and_test_tree revert-103637a5b947af7e6abb8d19b341acff6fbf1ec3-103637a5b947af7e6abb8d19b341acff6fbf1ec3
commit 103637a5b947af7e6abb8d19b341acff6fbf1ec3 ("sched/preempt: Fix cond_resched_lock() and cond_resched_softirq()")


=========================================================================================
tbox_group/testcase/rootfs/kconfig/compiler/cpufreq_governor/iterations/nr_threads/disk/fs/fs2/filesize/test_size/sync_method/nr_directories/nr_files_per_directory:
  nhm4/fsmark/debian-x86_64-2015-02-07.cgz/x86_64-rhel/gcc-4.9/performance/1x/32t/1HDD/f2fs/nfsv4/9B/400M/fsyncBeforeClose/16d/256fpd

commit: 
  834b9279b37ad019272ff140497b1e07ab52d124
  103637a5b947af7e6abb8d19b341acff6fbf1ec3

834b9279b37ad019 103637a5b947af7e6abb8d19b3 
---------------- -------------------------- 
         %stddev     %change         %stddev
             \          |                \  
  10808007 ±  2%     +12.4%   12147111 ±  3%  fsmark.app_overhead
    348.95 ±  0%      -1.4%     343.95 ±  0%  fsmark.files_per_sec
    292.92 ±  0%      +1.8%     298.06 ±  0%  fsmark.time.elapsed_time
    292.92 ±  0%      +1.8%     298.06 ±  0%  fsmark.time.elapsed_time.max
    103928 ±  0%     +13.9%     118415 ±  0%  fsmark.time.involuntary_context_switches
    468477 ±  0%      -2.2%     458135 ±  0%  fsmark.time.voluntary_context_switches
    103928 ±  0%     +13.9%     118415 ±  0%  time.involuntary_context_switches
     16609 ±  0%      -2.1%      16267 ±  0%  vmstat.system.in
   4527868 ±  2%     +25.9%    5698416 ±  2%  latency_stats.sum.rpc_wait_bit_killable.__rpc_execute.rpc_execute.rpc_run_task.nfs4_call_sync_sequence.[nfsv4]._nfs4_proc_lookup.[nfsv4].nfs4_proc_lookup_common.[nfsv4].nfs4_proc_lookup.[nfsv4].nfs_lookup_revalidate.nfs4_lookup_revalidate.lookup_dcache.__lookup_hash
 2.317e+09 ±  0%      +5.5%  2.444e+09 ±  0%  latency_stats.sum.rpc_wait_bit_killable.__rpc_wait_for_completion_task.nfs4_run_open_task.[nfsv4]._nfs4_open_and_get_state.[nfsv4].nfs4_do_open.[nfsv4].nfs4_atomic_open.[nfsv4].nfs_atomic_open.path_openat.do_filp_open.do_sys_open.SyS_open.entry_SYSCALL_64_fastpath
 1.548e+09 ±  0%      +2.9%  1.593e+09 ±  0%  latency_stats.sum.wait_on_page_bit.filemap_fdatawait_range.filemap_write_and_wait_range.nfs4_file_fsync.[nfsv4].vfs_fsync_range.do_fsync.SyS_fsync.entry_SYSCALL_64_fastpath
 3.399e+08 ±  1%     +19.0%  4.043e+08 ±  2%  cpuidle.C1-NHM.time
  82737781 ±  0%     +24.8%  1.032e+08 ±  0%  cpuidle.C1E-NHM.time
    141228 ±  0%     +23.4%     174263 ±  0%  cpuidle.C1E-NHM.usage
    128964 ±154%    +209.1%     398639 ± 26%  cpuidle.POLL.time
      3.47 ±  0%      -2.5%       3.38 ±  0%  turbostat.%Busy
    110.25 ±  0%      -2.0%     108.00 ±  0%  turbostat.Avg_MHz
     32.94 ±  0%     +14.4%      37.69 ±  1%  turbostat.CPU%c1
     32.26 ±  1%     -11.3%      28.62 ±  1%  turbostat.CPU%c3
     -2795 ± -9%     -19.2%      -2258 ± -4%  sched_debug.cfs_rq[1]:/.spread0
      3273 ±  4%     +29.9%       4250 ± 10%  sched_debug.cfs_rq[5]:/.avg->runnable_avg_sum
     70.25 ±  4%     +29.5%      91.00 ± 10%  sched_debug.cfs_rq[5]:/.tg_runnable_contrib
     -2687 ±  0%     -14.1%      -2308 ± -2%  sched_debug.cpu#0.nr_uninterruptible
    333314 ± 74%     -46.7%     177695 ±  3%  sched_debug.cpu#0.ttwu_count
    318.25 ± 11%     -41.3%     186.75 ±  6%  sched_debug.cpu#1.nr_uninterruptible
    331.50 ±  9%     -16.0%     278.50 ± 11%  sched_debug.cpu#2.nr_uninterruptible
    172.25 ± 21%     +63.6%     281.75 ± 14%  sched_debug.cpu#3.nr_uninterruptible
    753.75 ±  2%     +38.7%       1045 ±  4%  sched_debug.cpu#4.nr_uninterruptible
    839497 ±169%     -98.0%      16681 ±  1%  sched_debug.cpu#4.ttwu_local
    392.00 ±  3%     -50.6%     193.50 ± 12%  sched_debug.cpu#5.nr_uninterruptible
     12.50 ± 35%    +272.0%      46.50 ± 73%  sched_debug.cpu#6.cpu_load[0]
    385.00 ±  7%     -53.0%     181.00 ±  8%  sched_debug.cpu#6.nr_uninterruptible
    362.00 ±  2%     -53.8%     167.25 ± 15%  sched_debug.cpu#7.nr_uninterruptible


nhm4: Nehalem
Memory: 4G


                               fsmark.files_per_sec

  352 *+-*-------------------------*-----*--*-------------------------------+
  351 ++    *..                  .. :   :    :                              |
      |        .                .    :  :     :                             |
  350 ++        *..           .*     : :      :                             |
  349 ++           *..*..*..*.        *        *...*..*..*                  |
      |                                                                     |
  348 ++                                                                    |
  347 ++                                                                    |
  346 ++                                                                    |
      O     O               O  O      O     O         O           O         |
  345 ++ O                                                     O            O
  344 ++              O  O         O                                        |
      |                                                                     |
  343 ++        O  O                     O     O   O     O  O         O  O  |
  342 ++--------------------------------------------------------------------+


                             fsmark.time.elapsed_time

  299 ++--------------------------------------------------------------------+
      |         O  O                     O     O   O     O  O         O  O  |
  298 ++ O            O  O         O        O         O        O  O         O
  297 O+                    O  O      O                                     |
      |     O                                                               |
  296 ++                                                                    |
  295 ++                                                                    |
      |                                                                     |
  294 ++           *..*..                                                   |
  293 ++         ..      *..                   *...*..*..                   |
      *..   *...*           *..*...  .*..     +          *                  |
  292 ++  ..                       *.    *.. +                              |
  291 ++ *                                  *                               |
      |                                                                     |
  290 ++--------------------------------------------------------------------+


                           fsmark.time.elapsed_time.max

  299 ++--------------------------------------------------------------------+
      |         O  O                     O     O   O     O  O         O  O  |
  298 ++ O            O  O         O        O         O        O  O         O
  297 O+                    O  O      O                                     |
      |     O                                                               |
  296 ++                                                                    |
  295 ++                                                                    |
      |                                                                     |
  294 ++           *..*..                                                   |
  293 ++         ..      *..                   *...*..*..                   |
      *..   *...*           *..*...  .*..     +          *                  |
  292 ++  ..                       *.    *.. +                              |
  291 ++ *                                  *                               |
      |                                                                     |
  290 ++--------------------------------------------------------------------+


                       fsmark.time.voluntary_context_switches

  470000 ++--------------------------------*--------------------------------+
         |                          *..*.     *..  .*..*..*                 |
  468000 *+.*..*..  .*..*..*..    ..             *.                         |
  466000 ++       *.            .*                                          |
         |                    *.                                            |
  464000 ++                                                                 |
         |                                                                  |
  462000 ++                                                                 |
         |                                                                  |
  460000 ++                                                                 |
  458000 ++                                            O  O  O  O  O  O  O  O
         |        O  O     O  O  O  O  O            O                       |
  456000 O+ O  O        O                  O  O  O                          |
         |                                                                  |
  454000 ++-----------------------------------------------------------------+


                      fsmark.time.involuntary_context_switches

  120000 ++-----------------------------------------------------------------+
         |                                             O  O     O  O  O     O
  118000 O+ O        O           O               O  O        O           O  |
  116000 ++    O  O     O  O  O     O  O   O  O                             |
         |                                                                  |
  114000 ++                                                                 |
  112000 ++                                                                 |
         |                                                                  |
  110000 ++                                                                 |
  108000 ++                                                                 |
         |                                                                  |
  106000 ++                                                                 |
  104000 *+.*..*..*..*..           .*..*...*..*..     .*..*                 |
         |              *..*..*..*.              *..*.                      |
  102000 ++-----------------------------------------------------------------+


                          time.involuntary_context_switches

  120000 ++-----------------------------------------------------------------+
         |                                             O  O     O  O  O     O
  118000 O+ O        O           O               O  O        O           O  |
  116000 ++    O  O     O  O  O     O  O   O  O                             |
         |                                                                  |
  114000 ++                                                                 |
  112000 ++                                                                 |
         |                                                                  |
  110000 ++                                                                 |
  108000 ++                                                                 |
         |                                                                  |
  106000 ++                                                                 |
  104000 *+.*..*..*..*..           .*..*...*..*..     .*..*                 |
         |              *..*..*..*.              *..*.                      |
  102000 ++-----------------------------------------------------------------+


	[*] 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,
Ying Huang

[-- Attachment #2: job.yaml --]
[-- Type: text/plain, Size: 3770 bytes --]

---
LKP_SERVER: inn
LKP_CGI_PORT: 80
LKP_CIFS_PORT: 139
testcase: fsmark
default-monitors:
  wait: activate-monitor
  kmsg: 
  uptime: 
  iostat: 
  vmstat: 
  numa-numastat: 
  numa-vmstat: 
  numa-meminfo: 
  proc-vmstat: 
  proc-stat:
    interval: 10
  meminfo: 
  slabinfo: 
  interrupts: 
  lock_stat: 
  latency_stats: 
  softirqs: 
  bdi_dev_mapping: 
  diskstats: 
  nfsstat: 
  cpuidle: 
  cpufreq-stats: 
  turbostat: 
  pmeter: 
  sched_debug:
    interval: 60
cpufreq_governor: performance
default-watchdogs:
  oom-killer: 
  watchdog: 
commit: c88c2520860a5ae9039d1f99e8db03a2b7d9d22e
model: Nehalem
nr_cpu: 8
memory: 4G
hdd_partitions: "/dev/disk/by-id/ata-WDC_WD1003FBYZ-010FB0_WD-WCAW36812041-part1"
swap_partitions: "/dev/disk/by-id/ata-WDC_WD1003FBYZ-010FB0_WD-WCAW36812041-part2"
rootfs_partition: "/dev/disk/by-id/ata-WDC_WD1003FBYZ-010FB0_WD-WCAW36812041-part3"
netconsole_port: 6649
category: benchmark
iterations: 1x
nr_threads: 32t
disk: 1HDD
fs: f2fs
fs2: nfsv4
fsmark:
  filesize: 9B
  test_size: 400M
  sync_method: fsyncBeforeClose
  nr_directories: 16d
  nr_files_per_directory: 256fpd
queue: cyclic
testbox: nhm4
tbox_group: nhm4
kconfig: x86_64-rhel
enqueue_time: 2015-07-14 02:11:29.493801870 +08:00
user: lkp
compiler: gcc-4.9
head_commit: c88c2520860a5ae9039d1f99e8db03a2b7d9d22e
base_commit: bc0195aad0daa2ad5b0d76cce22b167bc3435590
branch: linux-devel/devel-hourly-2015071601
kernel: "/pkg/linux/x86_64-rhel/gcc-4.9/c88c2520860a5ae9039d1f99e8db03a2b7d9d22e/vmlinuz-4.2.0-rc2-02180-gc88c252"
rootfs: debian-x86_64-2015-02-07.cgz
result_root: "/result/fsmark/performance-1x-32t-1HDD-f2fs-nfsv4-9B-400M-fsyncBeforeClose-16d-256fpd/nhm4/debian-x86_64-2015-02-07.cgz/x86_64-rhel/gcc-4.9/c88c2520860a5ae9039d1f99e8db03a2b7d9d22e/0"
job_file: "/lkp/scheduled/nhm4/cyclic_fsmark-performance-1x-32t-1HDD-f2fs-nfsv4-9B-400M-fsyncBeforeClose-16d-256fpd-x86_64-rhel-CYCLIC_HEAD-c88c2520860a5ae9039d1f99e8db03a2b7d9d22e-20150714-86142-172p938-0.yaml"
dequeue_time: 2015-07-16 02:27:47.380333879 +08:00
max_uptime: 1240.3599999999997
initrd: "/osimage/debian/debian-x86_64-2015-02-07.cgz"
bootloader_append:
- root=/dev/ram0
- user=lkp
- job=/lkp/scheduled/nhm4/cyclic_fsmark-performance-1x-32t-1HDD-f2fs-nfsv4-9B-400M-fsyncBeforeClose-16d-256fpd-x86_64-rhel-CYCLIC_HEAD-c88c2520860a5ae9039d1f99e8db03a2b7d9d22e-20150714-86142-172p938-0.yaml
- ARCH=x86_64
- kconfig=x86_64-rhel
- branch=linux-devel/devel-hourly-2015071601
- commit=c88c2520860a5ae9039d1f99e8db03a2b7d9d22e
- BOOT_IMAGE=/pkg/linux/x86_64-rhel/gcc-4.9/c88c2520860a5ae9039d1f99e8db03a2b7d9d22e/vmlinuz-4.2.0-rc2-02180-gc88c252
- max_uptime=1240
- RESULT_ROOT=/result/fsmark/performance-1x-32t-1HDD-f2fs-nfsv4-9B-400M-fsyncBeforeClose-16d-256fpd/nhm4/debian-x86_64-2015-02-07.cgz/x86_64-rhel/gcc-4.9/c88c2520860a5ae9039d1f99e8db03a2b7d9d22e/0
- LKP_SERVER=inn
- |-
  libata.force=1.5Gbps

  earlyprintk=ttyS0,115200 systemd.log_level=err
  debug apic=debug sysrq_always_enabled rcupdate.rcu_cpu_stall_timeout=100
  panic=-1 softlockup_panic=1 nmi_watchdog=panic oops=panic load_ramdisk=2 prompt_ramdisk=0
  console=ttyS0,115200 console=tty0 vga=normal

  rw
lkp_initrd: "/lkp/lkp/lkp-x86_64.cgz"
modules_initrd: "/pkg/linux/x86_64-rhel/gcc-4.9/c88c2520860a5ae9039d1f99e8db03a2b7d9d22e/modules.cgz"
bm_initrd: "/osimage/deps/debian-x86_64-2015-02-07.cgz/lkp.cgz,/osimage/deps/debian-x86_64-2015-02-07.cgz/run-ipconfig.cgz,/osimage/deps/debian-x86_64-2015-02-07.cgz/turbostat.cgz,/lkp/benchmarks/turbostat.cgz,/osimage/deps/debian-x86_64-2015-02-07.cgz/fs.cgz,/osimage/deps/debian-x86_64-2015-02-07.cgz/fs2.cgz,/lkp/benchmarks/fsmark.cgz"
job_state: finished
loadavg: 36.20 23.46 10.15 1/166 4815
start_time: '1436984905'
end_time: '1436985203'
version: "/lkp/lkp/.src-20150715-155933"

[-- Attachment #3: reproduce --]
[-- Type: text/plain, Size: 1332 bytes --]

echo performance > /sys/devices/system/cpu/cpu0/cpufreq/scaling_governor
echo performance > /sys/devices/system/cpu/cpu1/cpufreq/scaling_governor
echo performance > /sys/devices/system/cpu/cpu2/cpufreq/scaling_governor
echo performance > /sys/devices/system/cpu/cpu3/cpufreq/scaling_governor
echo performance > /sys/devices/system/cpu/cpu4/cpufreq/scaling_governor
echo performance > /sys/devices/system/cpu/cpu5/cpufreq/scaling_governor
echo performance > /sys/devices/system/cpu/cpu6/cpufreq/scaling_governor
echo performance > /sys/devices/system/cpu/cpu7/cpufreq/scaling_governor
mkfs -t f2fs /dev/sda1
mount -t f2fs /dev/sda1 /fs/sda1
/etc/init.d/rpcbind start
/etc/init.d/nfs-common start
/etc/init.d/nfs-kernel-server start
mount -t nfs -o vers=4 localhost:/fs/sda1 /nfs/sda1
./fs_mark -d /nfs/sda1/1 -d /nfs/sda1/2 -d /nfs/sda1/3 -d /nfs/sda1/4 -d /nfs/sda1/5 -d /nfs/sda1/6 -d /nfs/sda1/7 -d /nfs/sda1/8 -d /nfs/sda1/9 -d /nfs/sda1/10 -d /nfs/sda1/11 -d /nfs/sda1/12 -d /nfs/sda1/13 -d /nfs/sda1/14 -d /nfs/sda1/15 -d /nfs/sda1/16 -d /nfs/sda1/17 -d /nfs/sda1/18 -d /nfs/sda1/19 -d /nfs/sda1/20 -d /nfs/sda1/21 -d /nfs/sda1/22 -d /nfs/sda1/23 -d /nfs/sda1/24 -d /nfs/sda1/25 -d /nfs/sda1/26 -d /nfs/sda1/27 -d /nfs/sda1/28 -d /nfs/sda1/29 -d /nfs/sda1/30 -d /nfs/sda1/31 -d /nfs/sda1/32 -D 16 -N 256 -n 3200 -L 1 -S 1 -s 9

^ permalink raw reply	[flat|nested] 3+ messages in thread

* Re: [lkp] [sched/preempt] 103637a5b94: 12.4% fsmark.app_overhead, -1.4% fsmark.files_per_sec
  2015-07-25  6:09 [lkp] [sched/preempt] 103637a5b94: 12.4% fsmark.app_overhead, -1.4% fsmark.files_per_sec kernel test robot
@ 2015-07-25 16:32 ` Konstantin Khlebnikov
  2015-07-26  9:01   ` Peter Zijlstra
  0 siblings, 1 reply; 3+ messages in thread
From: Konstantin Khlebnikov @ 2015-07-25 16:32 UTC (permalink / raw)
  To: kernel test robot
  Cc: Konstantin Khlebnikov, LKP, LKML, Peter Zijlstra, Trond Myklebust,
	Anna Schumaker, linux-nfs

I guess that's because of cond_resched_lock() usage in nfs_scan_commit_list().
My patch fixes cond_resched_lock() which never worked since v3.13.

On Sat, Jul 25, 2015 at 9:09 AM, kernel test robot <ying.huang@intel.com> wrote:
> FYI, we noticed the below changes on
>
> git://internal_merge_and_test_tree revert-103637a5b947af7e6abb8d19b341acff6fbf1ec3-103637a5b947af7e6abb8d19b341acff6fbf1ec3
> commit 103637a5b947af7e6abb8d19b341acff6fbf1ec3 ("sched/preempt: Fix cond_resched_lock() and cond_resched_softirq()")
>
>
> =========================================================================================
> tbox_group/testcase/rootfs/kconfig/compiler/cpufreq_governor/iterations/nr_threads/disk/fs/fs2/filesize/test_size/sync_method/nr_directories/nr_files_per_directory:
>   nhm4/fsmark/debian-x86_64-2015-02-07.cgz/x86_64-rhel/gcc-4.9/performance/1x/32t/1HDD/f2fs/nfsv4/9B/400M/fsyncBeforeClose/16d/256fpd
>
> commit:
>   834b9279b37ad019272ff140497b1e07ab52d124
>   103637a5b947af7e6abb8d19b341acff6fbf1ec3
>
> 834b9279b37ad019 103637a5b947af7e6abb8d19b3
> ---------------- --------------------------
>          %stddev     %change         %stddev
>              \          |                \
>   10808007 ±  2%     +12.4%   12147111 ±  3%  fsmark.app_overhead
>     348.95 ±  0%      -1.4%     343.95 ±  0%  fsmark.files_per_sec
>     292.92 ±  0%      +1.8%     298.06 ±  0%  fsmark.time.elapsed_time
>     292.92 ±  0%      +1.8%     298.06 ±  0%  fsmark.time.elapsed_time.max
>     103928 ±  0%     +13.9%     118415 ±  0%  fsmark.time.involuntary_context_switches
>     468477 ±  0%      -2.2%     458135 ±  0%  fsmark.time.voluntary_context_switches
>     103928 ±  0%     +13.9%     118415 ±  0%  time.involuntary_context_switches
>      16609 ±  0%      -2.1%      16267 ±  0%  vmstat.system.in
>    4527868 ±  2%     +25.9%    5698416 ±  2%  latency_stats.sum.rpc_wait_bit_killable.__rpc_execute.rpc_execute.rpc_run_task.nfs4_call_sync_sequence.[nfsv4]._nfs4_proc_lookup.[nfsv4].nfs4_proc_lookup_common.[nfsv4].nfs4_proc_lookup.[nfsv4].nfs_lookup_revalidate.nfs4_lookup_revalidate.lookup_dcache.__lookup_hash
>  2.317e+09 ±  0%      +5.5%  2.444e+09 ±  0%  latency_stats.sum.rpc_wait_bit_killable.__rpc_wait_for_completion_task.nfs4_run_open_task.[nfsv4]._nfs4_open_and_get_state.[nfsv4].nfs4_do_open.[nfsv4].nfs4_atomic_open.[nfsv4].nfs_atomic_open.path_openat.do_filp_open.do_sys_open.SyS_open.entry_SYSCALL_64_fastpath
>  1.548e+09 ±  0%      +2.9%  1.593e+09 ±  0%  latency_stats.sum.wait_on_page_bit.filemap_fdatawait_range.filemap_write_and_wait_range.nfs4_file_fsync.[nfsv4].vfs_fsync_range.do_fsync.SyS_fsync.entry_SYSCALL_64_fastpath
>  3.399e+08 ±  1%     +19.0%  4.043e+08 ±  2%  cpuidle.C1-NHM.time
>   82737781 ±  0%     +24.8%  1.032e+08 ±  0%  cpuidle.C1E-NHM.time
>     141228 ±  0%     +23.4%     174263 ±  0%  cpuidle.C1E-NHM.usage
>     128964 ±154%    +209.1%     398639 ± 26%  cpuidle.POLL.time
>       3.47 ±  0%      -2.5%       3.38 ±  0%  turbostat.%Busy
>     110.25 ±  0%      -2.0%     108.00 ±  0%  turbostat.Avg_MHz
>      32.94 ±  0%     +14.4%      37.69 ±  1%  turbostat.CPU%c1
>      32.26 ±  1%     -11.3%      28.62 ±  1%  turbostat.CPU%c3
>      -2795 ± -9%     -19.2%      -2258 ± -4%  sched_debug.cfs_rq[1]:/.spread0
>       3273 ±  4%     +29.9%       4250 ± 10%  sched_debug.cfs_rq[5]:/.avg->runnable_avg_sum
>      70.25 ±  4%     +29.5%      91.00 ± 10%  sched_debug.cfs_rq[5]:/.tg_runnable_contrib
>      -2687 ±  0%     -14.1%      -2308 ± -2%  sched_debug.cpu#0.nr_uninterruptible
>     333314 ± 74%     -46.7%     177695 ±  3%  sched_debug.cpu#0.ttwu_count
>     318.25 ± 11%     -41.3%     186.75 ±  6%  sched_debug.cpu#1.nr_uninterruptible
>     331.50 ±  9%     -16.0%     278.50 ± 11%  sched_debug.cpu#2.nr_uninterruptible
>     172.25 ± 21%     +63.6%     281.75 ± 14%  sched_debug.cpu#3.nr_uninterruptible
>     753.75 ±  2%     +38.7%       1045 ±  4%  sched_debug.cpu#4.nr_uninterruptible
>     839497 ±169%     -98.0%      16681 ±  1%  sched_debug.cpu#4.ttwu_local
>     392.00 ±  3%     -50.6%     193.50 ± 12%  sched_debug.cpu#5.nr_uninterruptible
>      12.50 ± 35%    +272.0%      46.50 ± 73%  sched_debug.cpu#6.cpu_load[0]
>     385.00 ±  7%     -53.0%     181.00 ±  8%  sched_debug.cpu#6.nr_uninterruptible
>     362.00 ±  2%     -53.8%     167.25 ± 15%  sched_debug.cpu#7.nr_uninterruptible
>
>
> nhm4: Nehalem
> Memory: 4G
>
>
>                                fsmark.files_per_sec
>
>   352 *+-*-------------------------*-----*--*-------------------------------+
>   351 ++    *..                  .. :   :    :                              |
>       |        .                .    :  :     :                             |
>   350 ++        *..           .*     : :      :                             |
>   349 ++           *..*..*..*.        *        *...*..*..*                  |
>       |                                                                     |
>   348 ++                                                                    |
>   347 ++                                                                    |
>   346 ++                                                                    |
>       O     O               O  O      O     O         O           O         |
>   345 ++ O                                                     O            O
>   344 ++              O  O         O                                        |
>       |                                                                     |
>   343 ++        O  O                     O     O   O     O  O         O  O  |
>   342 ++--------------------------------------------------------------------+
>
>
>                              fsmark.time.elapsed_time
>
>   299 ++--------------------------------------------------------------------+
>       |         O  O                     O     O   O     O  O         O  O  |
>   298 ++ O            O  O         O        O         O        O  O         O
>   297 O+                    O  O      O                                     |
>       |     O                                                               |
>   296 ++                                                                    |
>   295 ++                                                                    |
>       |                                                                     |
>   294 ++           *..*..                                                   |
>   293 ++         ..      *..                   *...*..*..                   |
>       *..   *...*           *..*...  .*..     +          *                  |
>   292 ++  ..                       *.    *.. +                              |
>   291 ++ *                                  *                               |
>       |                                                                     |
>   290 ++--------------------------------------------------------------------+
>
>
>                            fsmark.time.elapsed_time.max
>
>   299 ++--------------------------------------------------------------------+
>       |         O  O                     O     O   O     O  O         O  O  |
>   298 ++ O            O  O         O        O         O        O  O         O
>   297 O+                    O  O      O                                     |
>       |     O                                                               |
>   296 ++                                                                    |
>   295 ++                                                                    |
>       |                                                                     |
>   294 ++           *..*..                                                   |
>   293 ++         ..      *..                   *...*..*..                   |
>       *..   *...*           *..*...  .*..     +          *                  |
>   292 ++  ..                       *.    *.. +                              |
>   291 ++ *                                  *                               |
>       |                                                                     |
>   290 ++--------------------------------------------------------------------+
>
>
>                        fsmark.time.voluntary_context_switches
>
>   470000 ++--------------------------------*--------------------------------+
>          |                          *..*.     *..  .*..*..*                 |
>   468000 *+.*..*..  .*..*..*..    ..             *.                         |
>   466000 ++       *.            .*                                          |
>          |                    *.                                            |
>   464000 ++                                                                 |
>          |                                                                  |
>   462000 ++                                                                 |
>          |                                                                  |
>   460000 ++                                                                 |
>   458000 ++                                            O  O  O  O  O  O  O  O
>          |        O  O     O  O  O  O  O            O                       |
>   456000 O+ O  O        O                  O  O  O                          |
>          |                                                                  |
>   454000 ++-----------------------------------------------------------------+
>
>
>                       fsmark.time.involuntary_context_switches
>
>   120000 ++-----------------------------------------------------------------+
>          |                                             O  O     O  O  O     O
>   118000 O+ O        O           O               O  O        O           O  |
>   116000 ++    O  O     O  O  O     O  O   O  O                             |
>          |                                                                  |
>   114000 ++                                                                 |
>   112000 ++                                                                 |
>          |                                                                  |
>   110000 ++                                                                 |
>   108000 ++                                                                 |
>          |                                                                  |
>   106000 ++                                                                 |
>   104000 *+.*..*..*..*..           .*..*...*..*..     .*..*                 |
>          |              *..*..*..*.              *..*.                      |
>   102000 ++-----------------------------------------------------------------+
>
>
>                           time.involuntary_context_switches
>
>   120000 ++-----------------------------------------------------------------+
>          |                                             O  O     O  O  O     O
>   118000 O+ O        O           O               O  O        O           O  |
>   116000 ++    O  O     O  O  O     O  O   O  O                             |
>          |                                                                  |
>   114000 ++                                                                 |
>   112000 ++                                                                 |
>          |                                                                  |
>   110000 ++                                                                 |
>   108000 ++                                                                 |
>          |                                                                  |
>   106000 ++                                                                 |
>   104000 *+.*..*..*..*..           .*..*...*..*..     .*..*                 |
>          |              *..*..*..*.              *..*.                      |
>   102000 ++-----------------------------------------------------------------+
>
>
>         [*] 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,
> Ying Huang

^ permalink raw reply	[flat|nested] 3+ messages in thread

* Re: [lkp] [sched/preempt] 103637a5b94: 12.4% fsmark.app_overhead, -1.4% fsmark.files_per_sec
  2015-07-25 16:32 ` Konstantin Khlebnikov
@ 2015-07-26  9:01   ` Peter Zijlstra
  0 siblings, 0 replies; 3+ messages in thread
From: Peter Zijlstra @ 2015-07-26  9:01 UTC (permalink / raw)
  To: Konstantin Khlebnikov
  Cc: kernel test robot, Konstantin Khlebnikov, LKP, LKML,
	Trond Myklebust, Anna Schumaker, linux-nfs

On Sat, Jul 25, 2015 at 07:32:03PM +0300, Konstantin Khlebnikov wrote:
> I guess that's because of cond_resched_lock() usage in nfs_scan_commit_list().
> My patch fixes cond_resched_lock() which never worked since v3.13.

Yeah, I wasn't surprised to see preemptions go up with this patch, not
total throughput suffer a bit due to that.

^ permalink raw reply	[flat|nested] 3+ messages in thread

end of thread, other threads:[~2015-07-26  9:01 UTC | newest]

Thread overview: 3+ messages (download: mbox.gz follow: Atom feed
-- links below jump to the message on this page --
2015-07-25  6:09 [lkp] [sched/preempt] 103637a5b94: 12.4% fsmark.app_overhead, -1.4% fsmark.files_per_sec kernel test robot
2015-07-25 16:32 ` Konstantin Khlebnikov
2015-07-26  9:01   ` Peter Zijlstra

This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox