[lkp] [sched/preempt] 103637a5b94: 12.4% fsmark.app_overhead, -1.4% fsmark.files_per_sec
From: kernel test robot
Date: Sat Jul 25 2015 - 02:09:14 EST
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
---
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"
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