[lkp] [writeback] f7486eef5e: No primary change, fsmark.time.involuntary_context_switches -35.1%
From: kernel test robot
Date: Tue Apr 05 2016 - 04:47:03 EST
FYI, we noticed that fsmark.time.involuntary_context_switches -35.1% change on
=========================================================================================
compiler/cpufreq_governor/disk/filesize/fs/iterations/kconfig/nr_directories/nr_files_per_directory/nr_threads/rootfs/sync_method/tbox_group/test_size/testcase:
gcc-4.9/performance/1HDD/9B/xfs/1x/x86_64-rhel/16d/256fpd/32t/debian-x86_64-2015-02-07.cgz/fsyncBeforeClose/lkp-sb02/400M/fsmark
commit:
5569d5f86db30a2d202ed57222a177d32a2234b3
f7486eef5ea239905ed71f2316a40eae757ffed2
5569d5f86db30a2d f7486eef5ea239905ed71f2316
---------------- --------------------------
fail:runs %reproduction fail:runs
%stddev %change %stddev
\ | \
106141 ± 0% -35.1% 68920 ± 0% fsmark.time.involuntary_context_switches
342173 ± 0% +35.8% 464725 ± 0% fsmark.time.voluntary_context_switches
284.90 ± 4% -41.7% 166.22 ± 18% slabinfo.blkdev_requests.num_objs
106141 ± 0% -35.1% 68920 ± 0% time.involuntary_context_switches
342173 ± 0% +35.8% 464725 ± 0% time.voluntary_context_switches
27.89 ± 28% -20.6% 22.16 ± 2% turbostat.CPU%c6
9.13 ± 11% +13.2% 10.34 ± 0% turbostat.CorWatt
6.91 ± 65% -38.0% 4.28 ± 5% turbostat.Pkg%pc6
12.63 ± 8% +9.7% 13.85 ± 0% turbostat.PkgWatt
48250249 ± 1% +101.0% 96965425 ± 1% cpuidle.C1-SNB.time
95999 ± 2% +69.6% 162769 ± 0% cpuidle.C1-SNB.usage
2.015e+08 ± 4% +15.3% 2.325e+08 ± 1% cpuidle.C1E-SNB.time
185631 ± 4% +23.7% 229659 ± 1% cpuidle.C1E-SNB.usage
15292 ± 2% +32.4% 20248 ± 2% cpuidle.C3-SNB.usage
563.70 ± 23% -23.9% 429.22 ± 7% cpuidle.POLL.usage
38.96 ± 18% +183.2% 110.33 ± 35% sched_debug.cfs_rq:/.exec_clock.stddev
-4107 ± -4% -64.2% -1470 ±-30% sched_debug.cpu.nr_uninterruptible.min
2469 ± 3% -53.6% 1145 ± 31% sched_debug.cpu.nr_uninterruptible.stddev
28646 ± 1% +45.2% 41602 ± 34% sched_debug.cpu.sched_goidle.avg
19183 ± 3% +74.9% 33552 ± 33% sched_debug.cpu.sched_goidle.min
16895 ± 4% +55.3% 26246 ± 35% sched_debug.cpu.ttwu_count.min
0.00 ± -1% +Inf% 19531 ± 7% latency_stats.avg.blk_wb_wait.blk_queue_bio.generic_make_request.submit_bio._xfs_buf_ioapply.xfs_buf_submit.xlog_bdstrat.xlog_sync.xlog_state_release_iclog._xfs_log_force_lsn.xfs_file_fsync.vfs_fsync_range
0.00 ± -1% +Inf% 19304 ± 2% latency_stats.avg.blk_wb_wait.blk_queue_bio.generic_make_request.submit_bio.xfs_submit_ioend_bio.xfs_submit_ioend.xfs_vm_writepages.do_writepages.__filemap_fdatawrite_range.filemap_write_and_wait_range.xfs_file_fsync.vfs_fsync_range
41.10 ± 20% +25703.2% 10605 ± 1% latency_stats.avg.flush_work.xlog_cil_force_lsn._xfs_log_force_lsn.xfs_file_fsync.vfs_fsync_range.do_fsync.SyS_fsync.entry_SYSCALL_64_fastpath
0.00 ± -1% +Inf% 49655 ± 0% latency_stats.hits.blk_wb_wait.blk_queue_bio.generic_make_request.submit_bio.xfs_submit_ioend_bio.xfs_submit_ioend.xfs_vm_writepages.do_writepages.__filemap_fdatawrite_range.filemap_write_and_wait_range.xfs_file_fsync.vfs_fsync_range
401.30 ± 13% +17370.5% 70109 ± 1% latency_stats.hits.flush_work.xlog_cil_force_lsn._xfs_log_force_lsn.xfs_file_fsync.vfs_fsync_range.do_fsync.SyS_fsync.entry_SYSCALL_64_fastpath
1.20 ± 62% +8.9e+05% 10737 ± 5% latency_stats.hits.xlog_cil_force_lsn._xfs_log_force_lsn.xfs_file_fsync.vfs_fsync_range.do_fsync.SyS_fsync.entry_SYSCALL_64_fastpath
0.00 ± -1% +Inf% 107042 ± 34% latency_stats.max.blk_wb_wait.blk_queue_bio.generic_make_request.submit_bio._xfs_buf_ioapply.xfs_buf_submit.xlog_bdstrat.xlog_sync.xlog_state_release_iclog._xfs_log_force_lsn.xfs_file_fsync.vfs_fsync_range
0.00 ± -1% +Inf% 215477 ± 7% latency_stats.max.blk_wb_wait.blk_queue_bio.generic_make_request.submit_bio.xfs_submit_ioend_bio.xfs_submit_ioend.xfs_vm_writepages.do_writepages.__filemap_fdatawrite_range.filemap_write_and_wait_range.xfs_file_fsync.vfs_fsync_range
752.00 ±164% +17984.7% 135997 ± 11% latency_stats.max.flush_work.xlog_cil_force_lsn._xfs_log_force_lsn.xfs_file_fsync.vfs_fsync_range.do_fsync.SyS_fsync.entry_SYSCALL_64_fastpath
0.00 ± -1% +Inf% 1548061 ± 14% latency_stats.sum.blk_wb_wait.blk_queue_bio.generic_make_request.submit_bio._xfs_buf_ioapply.xfs_buf_submit.xlog_bdstrat.xlog_sync.xlog_state_release_iclog._xfs_log_force_lsn.xfs_file_fsync.vfs_fsync_range
0.00 ± -1% +Inf% 9.584e+08 ± 1% latency_stats.sum.blk_wb_wait.blk_queue_bio.generic_make_request.submit_bio.xfs_submit_ioend_bio.xfs_submit_ioend.xfs_vm_writepages.do_writepages.__filemap_fdatawrite_range.filemap_write_and_wait_range.xfs_file_fsync.vfs_fsync_range
16575 ± 19% +4.5e+06% 7.436e+08 ± 2% latency_stats.sum.flush_work.xlog_cil_force_lsn._xfs_log_force_lsn.xfs_file_fsync.vfs_fsync_range.do_fsync.SyS_fsync.entry_SYSCALL_64_fastpath
6.10 ±187% +8.6e+06% 524627 ± 26% latency_stats.sum.xlog_cil_force_lsn._xfs_log_force_lsn.xfs_file_fsync.vfs_fsync_range.do_fsync.SyS_fsync.entry_SYSCALL_64_fastpath
lkp-sb02: Sandy Bridge-EP
Memory: 4G
fsmark.time.voluntary_context_switches
500000 ++-----------------------------------------------------------------+
450000 OO O O O O O OO O OO O OO O OOO OO OOOOOOOOO OOOOO |
| |
400000 ++ |
350000 *+ *** * ** * ** * * * ** * ** *** ******* **** ***.* *********
|** : : :: : :: : :* : :: : : *.* ** * * * |
300000 ++ : : :: : :: : :: : :: : : |
250000 ++ : : : : : :: : :: : :: : : |
200000 ++ : : : : : :: : :: : :: : : |
| :::: : ::: ::::: ::: :::: |
150000 ++ : : :: : : : : : : : |
100000 ++ : : :: : : : : : : : |
| : : : : : : : : : : |
50000 ++ : : : : : : : : : : |
0 ++O-OO*O*O--O-O--O-O--O-O--O-O------O---------O--------------------+
fsmark.time.involuntary_context_switches
120000 ++-----------------------------------------------------------------+
| |
100000 ****** * ** * ** * ** * ** * ***.**********************.***********
| : : :: : :: : :: : :: : : |
| : : :: : :: : :: : :: : : |
80000 ++ : : : : : :: : :: : :: : : |
OO O :O:O:O: O OO O OO O OO O OOO OO OOOOOOOOO OOOOO |
60000 ++ : : : : : :: : :: : :: : : |
| :::: : ::: :::: :::: :::: |
40000 ++ : : :: : : : : : : : |
| : : :: : : : : : : : |
| : : : : : : : : : : |
20000 ++ : : : : : : : : : : |
| : : : : : : : : : : |
0 ++O-OO*O*O--O-O--O-O--O-O--O-O------O---------O--------------------+
[*] 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 Ye
---
LKP_SERVER: inn
LKP_CGI_PORT: 80
LKP_CIFS_PORT: 139
testcase: fsmark
default-monitors:
wait: activate-monitor
kmsg:
uptime:
iostat:
heartbeat:
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: f7486eef5ea239905ed71f2316a40eae757ffed2
model: Sandy Bridge-EP
memory: 4G
hdd_partitions: "/dev/disk/by-id/ata-HDT722516DLA380_VDSD1DTCEKYAEJ-part2"
swap_partitions:
rootfs_partition: "/dev/disk/by-id/ata-HDT722516DLA380_VDSD1DTCEKYAEJ-part1"
category: benchmark
iterations: 1x
nr_threads: 32t
disk: 1HDD
fs: xfs
fs2:
fsmark:
filesize: 9B
test_size: 400M
sync_method: fsyncBeforeClose
nr_directories: 16d
nr_files_per_directory: 256fpd
queue: bisect
testbox: lkp-sb02
tbox_group: lkp-sb02
kconfig: x86_64-rhel
enqueue_time: 2016-04-03 16:05:57.740062221 +08:00
compiler: gcc-4.9
rootfs: debian-x86_64-2015-02-07.cgz
id: b64882a7c3d6f39bfda62eb93badd0e77d771015
user: lkp
head_commit: ffc95e39fbd3ac43bab189e0b04abc373f4e50a9
base_commit: f55532a0c0b8bb6148f4e07853b876ef73bc69ca
branch: linux-devel/devel-hourly-2016040221
result_root: "/result/fsmark/performance-1x-32t-1HDD-xfs-9B-400M-fsyncBeforeClose-16d-256fpd/lkp-sb02/debian-x86_64-2015-02-07.cgz/x86_64-rhel/gcc-4.9/f7486eef5ea239905ed71f2316a40eae757ffed2/0"
job_file: "/lkp/scheduled/lkp-sb02/bisect_fsmark-performance-1x-32t-1HDD-xfs-9B-400M-fsyncBeforeClose-16d-256fpd-debian-x86_64-2015-02-07.cgz-x86_64-rhel-f7486eef5ea239905ed71f2316a40eae757ffed2-20160403-87961-ol4z1b-0.yaml"
nr_cpu: "$(nproc)"
max_uptime: 863.8799999999999
initrd: "/osimage/debian/debian-x86_64-2015-02-07.cgz"
bootloader_append:
- root=/dev/ram0
- user=lkp
- job=/lkp/scheduled/lkp-sb02/bisect_fsmark-performance-1x-32t-1HDD-xfs-9B-400M-fsyncBeforeClose-16d-256fpd-debian-x86_64-2015-02-07.cgz-x86_64-rhel-f7486eef5ea239905ed71f2316a40eae757ffed2-20160403-87961-ol4z1b-0.yaml
- ARCH=x86_64
- kconfig=x86_64-rhel
- branch=linux-devel/devel-hourly-2016040221
- commit=f7486eef5ea239905ed71f2316a40eae757ffed2
- BOOT_IMAGE=/pkg/linux/x86_64-rhel/gcc-4.9/f7486eef5ea239905ed71f2316a40eae757ffed2/vmlinuz-4.6.0-rc1-00009-gf7486ee
- max_uptime=863
- RESULT_ROOT=/result/fsmark/performance-1x-32t-1HDD-xfs-9B-400M-fsyncBeforeClose-16d-256fpd/lkp-sb02/debian-x86_64-2015-02-07.cgz/x86_64-rhel/gcc-4.9/f7486eef5ea239905ed71f2316a40eae757ffed2/0
- LKP_SERVER=inn
- |2-
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/f7486eef5ea239905ed71f2316a40eae757ffed2/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"
linux_headers_initrd: "/pkg/linux/x86_64-rhel/gcc-4.9/f7486eef5ea239905ed71f2316a40eae757ffed2/linux-headers.cgz"
repeat_to: 5
kernel: "/pkg/linux/x86_64-rhel/gcc-4.9/f7486eef5ea239905ed71f2316a40eae757ffed2/vmlinuz-4.6.0-rc1-00009-gf7486ee"
dequeue_time: 2016-04-03 16:07:14.628754292 +08:00
job_state: finished
loadavg: 28.40 10.88 3.99 1/150 2500
start_time: '1459670868'
end_time: '1459670988'
version: "/lkp/lkp/.src-20160401-231508"
2016-04-03 16:07:46 echo performance > /sys/devices/system/cpu/cpu0/cpufreq/scaling_governor
2016-04-03 16:07:46 echo performance > /sys/devices/system/cpu/cpu1/cpufreq/scaling_governor
2016-04-03 16:07:46 echo performance > /sys/devices/system/cpu/cpu2/cpufreq/scaling_governor
2016-04-03 16:07:46 echo performance > /sys/devices/system/cpu/cpu3/cpufreq/scaling_governor
2016-04-03 16:07:46 mkfs -t xfs /dev/sda2
2016-04-03 16:07:47 mount -t xfs -o nobarrier,inode64 /dev/sda2 /fs/sda2
2016-04-03 16:07:48 ./fs_mark -d /fs/sda2/1 -d /fs/sda2/2 -d /fs/sda2/3 -d /fs/sda2/4 -d /fs/sda2/5 -d /fs/sda2/6 -d /fs/sda2/7 -d /fs/sda2/8 -d /fs/sda2/9 -d /fs/sda2/10 -d /fs/sda2/11 -d /fs/sda2/12 -d /fs/sda2/13 -d /fs/sda2/14 -d /fs/sda2/15 -d /fs/sda2/16 -d /fs/sda2/17 -d /fs/sda2/18 -d /fs/sda2/19 -d /fs/sda2/20 -d /fs/sda2/21 -d /fs/sda2/22 -d /fs/sda2/23 -d /fs/sda2/24 -d /fs/sda2/25 -d /fs/sda2/26 -d /fs/sda2/27 -d /fs/sda2/28 -d /fs/sda2/29 -d /fs/sda2/30 -d /fs/sda2/31 -d /fs/sda2/32 -D 16 -N 256 -n 3200 -L 1 -S 1 -s 9