FYI, we noticed the below changes on
https://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git master
commit b659ef027792219b590d67a2baf1643a93727d29 ("Btrfs: avoid syncing log in
the fast fsync path when not necessary")
=========================================================================================
tbox_group/testcase/rootfs/kconfig/compiler/cpufreq_governor/period/nr_threads/disk/fs/size/filenum/rwmode/iomode:
lkp-sb02/fileio/debian-x86_64-2015-02-07.cgz/x86_64-rhel/gcc-4.9/performance/600s/100%/1HDD/btrfs/64G/1024f/rndwr/sync
commit:
1ab818b137e198e4d06e987a4b089411f2e39d40
b659ef027792219b590d67a2baf1643a93727d29
1ab818b137e198e4 b659ef027792219b590d67a2ba
---------------- --------------------------
%stddev %change %stddev
\ | \
156.81 ±171% -99.2% 1.20 ± 14% fileio.request_latency_max_ms
17.03 ± 0% +159.7% 44.24 ± 0% fileio.requests_per_sec
2373960 ± 0% +6.7% 2533688 ± 0% fileio.time.file_system_outputs
161019 ± 0% -14.3% 137992 ± 0%
fileio.time.voluntary_context_switches
9810964 ± 2% -17.9% 8052196 ± 1% cpuidle.C3-SNB.time
161019 ± 0% -14.3% 137992 ± 0% time.voluntary_context_switches
3568 ± 0% -2.4% 3484 ± 0% vmstat.io.bo
60476 ± 0% +18.1% 71428 ± 0% proc-vmstat.nr_active_file
507.75 ± 0% +86.4% 946.25 ± 0% proc-vmstat.nr_dirty
10809 ± 0% +15.6% 12497 ± 0% proc-vmstat.nr_slab_reclaimable
52238 ± 0% +13.4% 59232 ± 0% proc-vmstat.pgactivate
10189 ± 8% -9.9% 9180 ± 8%
sched_debug.cfs_rq[0]:/.min_vruntime
1.75 ±4164% +6385.7% 113.50 ± 16%
sched_debug.cpu#2.nr_uninterruptible
14748 ± 3% -7.2% 13685 ± 2% sched_debug.cpu#2.ttwu_local
141.25 ± 47% -83.9% 22.75 ±169%
sched_debug.cpu#3.nr_uninterruptible
50725 ± 0% -9.8% 45774 ± 0% softirqs.BLOCK
43962 ± 1% -13.9% 37864 ± 1% softirqs.RCU
32134 ± 1% -8.8% 29295 ± 1% softirqs.SCHED
62715 ± 1% -9.9% 56488 ± 0% softirqs.TIMER
50.00 ± 0% +2.0% 51.00 ± 0% turbostat.Avg_MHz
0.41 ± 2% -14.5% 0.35 ± 2% turbostat.CPU%c3
2.69 ± 0% -9.9% 2.42 ± 0% turbostat.Pkg%pc2
1.02 ± 4% -22.9% 0.78 ± 4% turbostat.Pkg%pc3
260823 ± 0% +16.8% 304593 ± 0% meminfo.Active
241907 ± 0% +18.1% 285712 ± 0% meminfo.Active(file)
2033 ± 0% +86.2% 3784 ± 0% meminfo.Dirty
43239 ± 0% +15.6% 49990 ± 0% meminfo.SReclaimable
61606 ± 0% +11.0% 68373 ± 0% meminfo.Slab
1571 ± 5% +16.0% 1823 ± 8%
slabinfo.btrfs_delayed_data_ref.active_objs
1577 ± 5% +16.0% 1830 ± 8%
slabinfo.btrfs_delayed_data_ref.num_objs
1256 ± 5% -13.3% 1089 ± 8%
slabinfo.btrfs_delayed_ref_head.active_objs
1261 ± 5% -13.3% 1093 ± 8%
slabinfo.btrfs_delayed_ref_head.num_objs
767.25 ± 2% +14.7% 880.25 ± 4%
slabinfo.btrfs_delayed_tree_ref.active_objs
767.25 ± 2% +14.7% 880.25 ± 4%
slabinfo.btrfs_delayed_tree_ref.num_objs
2933 ± 3% -29.6% 2066 ± 0%
slabinfo.btrfs_extent_buffer.active_objs
2944 ± 2% -29.4% 2079 ± 0%
slabinfo.btrfs_extent_buffer.num_objs
5699 ± 0% +129.2% 13066 ± 0%
slabinfo.btrfs_extent_state.active_objs
111.50 ± 1% +129.6% 256.00 ± 0%
slabinfo.btrfs_extent_state.active_slabs
5699 ± 0% +129.4% 13078 ± 0%
slabinfo.btrfs_extent_state.num_objs
111.50 ± 1% +129.6% 256.00 ± 0%
slabinfo.btrfs_extent_state.num_slabs
351.00 ± 2% +103.5% 714.25 ± 0%
slabinfo.btrfs_ordered_extent.active_objs
376.75 ± 2% +91.1% 720.00 ± 0%
slabinfo.btrfs_ordered_extent.num_objs
12062 ± 0% +122.3% 26821 ± 0% slabinfo.btrfs_path.active_objs
430.50 ± 0% +122.4% 957.50 ± 0% slabinfo.btrfs_path.active_slabs
12062 ± 0% +122.3% 26821 ± 0% slabinfo.btrfs_path.num_objs
430.50 ± 0% +122.4% 957.50 ± 0% slabinfo.btrfs_path.num_slabs
407.25 ± 0% +80.4% 734.50 ± 4%
slabinfo.ext4_extent_status.active_objs
407.25 ± 0% +80.4% 734.50 ± 4%
slabinfo.ext4_extent_status.num_objs
19541 ± 0% +36.8% 26730 ± 0%
slabinfo.radix_tree_node.active_objs
697.50 ± 0% +36.8% 954.25 ± 0%
slabinfo.radix_tree_node.active_slabs
19541 ± 0% +36.8% 26730 ± 0% slabinfo.radix_tree_node.num_objs
697.50 ± 0% +36.8% 954.25 ± 0% slabinfo.radix_tree_node.num_slabs
158807 ± 2% +131.0% 366899 ± 3%
latency_stats.avg.btrfs_log_inode_parent.[btrfs].btrfs_log_dentry_safe.[btrfs].btrfs_sync_file.[btrfs].vfs_fsync_range.do_fsync.SyS_fsync.system_call_fastpath
6668 ±173% +1166.1% 84431 ± 59%
latency_stats.avg.get_request.blk_queue_bio.generic_make_request.submit_bio.submit_stripe_bio.[btrfs].btrfs_map_bio.[btrfs].btrfs_submit_bio_hook.[btrfs].submit_one_bio.[btrfs].flush_epd_write_bio.[btrfs].extent_writepages.[btrfs].btrfs_writepages.[btrfs].do_writepages
13866462 ±166% -81.3% 2589754 ±141%
latency_stats.avg.nfs_wait_on_request.nfs_updatepage.nfs_write_end.generic_perform_write.__generic_file_write_iter.generic_file_write_iter.nfs_file_write.__vfs_write.vfs_write.SyS_write.system_call_fastpath
41062 ± 0% +54.4% 63383 ± 0%
latency_stats.avg.wait_log_commit.[btrfs].btrfs_sync_log.[btrfs].btrfs_sync_file.[btrfs].vfs_fsync_range.do_fsync.SyS_fsync.system_call_fastpath
25520 ± 0% +70.5% 43514 ± 0%
latency_stats.avg.write_all_supers.[btrfs].write_ctree_super.[btrfs].btrfs_sync_log.[btrfs].btrfs_sync_file.[btrfs].vfs_fsync_range.do_fsync.SyS_fsync.system_call_fastpath
18476 ± 1% -35.5% 11911 ± 0%
latency_stats.hits.btrfs_sync_log.[btrfs].btrfs_sync_file.[btrfs].vfs_fsync_range.do_fsync.SyS_fsync.system_call_fastpath
41791 ± 0% -35.9% 26801 ± 0%
latency_stats.hits.wait_log_commit.[btrfs].btrfs_sync_log.[btrfs].btrfs_sync_file.[btrfs].vfs_fsync_range.do_fsync.SyS_fsync.system_call_fastpath
18075 ± 0% -28.7% 12891 ± 0%
latency_stats.hits.wait_on_page_bit.filemap_fdatawait_range.btrfs_wait_marked_extents.[btrfs].btrfs_sync_log.[btrfs].btrfs_sync_file.[btrfs].vfs_fsync_range.do_fsync.SyS_fsync.system_call_fastpath
9830 ± 0% +163.3% 25887 ± 0%
latency_stats.hits.wait_ordered_extents.[btrfs].btrfs_log_changed_extents.[btrfs].btrfs_log_inode.[btrfs].btrfs_log_inode_parent.[btrfs].btrfs_log_dentry_safe.[btrfs].btrfs_sync_file.[btrfs].vfs_fsync_range.do_fsync.SyS_fsync.system_call_fastpath
16441 ± 0% -34.1% 10827 ± 0%
latency_stats.hits.write_all_supers.[btrfs].write_ctree_super.[btrfs].btrfs_sync_log.[btrfs].btrfs_sync_file.[btrfs].vfs_fsync_range.do_fsync.SyS_fsync.system_call_fastpath
774721 ± 2% +17.4% 909689 ± 2%
latency_stats.max.btrfs_log_inode_parent.[btrfs].btrfs_log_dentry_safe.[btrfs].btrfs_sync_file.[btrfs].vfs_fsync_range.do_fsync.SyS_fsync.system_call_fastpath
308974 ±102% -99.9% 169.50 ± 7%
latency_stats.max.btrfs_sync_file.[btrfs].vfs_fsync_range.do_fsync.SyS_fsync.system_call_fastpath
6668 ±173% +1166.1% 84431 ± 59%
latency_stats.max.get_request.blk_queue_bio.generic_make_request.submit_bio.submit_stripe_bio.[btrfs].btrfs_map_bio.[btrfs].btrfs_submit_bio_hook.[btrfs].submit_one_bio.[btrfs].flush_epd_write_bio.[btrfs].extent_writepages.[btrfs].btrfs_writepages.[btrfs].do_writepages
13999612 ±164% -81.5% 2589754 ±141%
latency_stats.max.nfs_wait_on_request.nfs_updatepage.nfs_write_end.generic_perform_write.__generic_file_write_iter.generic_file_write_iter.nfs_file_write.__vfs_write.vfs_write.SyS_write.system_call_fastpath
155855 ±169% -92.6% 11547 ± 28%
latency_stats.sum.btrfs_file_write_iter.[btrfs].__vfs_write.vfs_write.SyS_pwrite64.system_call_fastpath
40811794 ± 1% +8.0% 44071985 ± 1%
latency_stats.sum.btrfs_log_inode_parent.[btrfs].btrfs_log_dentry_safe.[btrfs].btrfs_sync_file.[btrfs].vfs_fsync_range.do_fsync.SyS_fsync.system_call_fastpath
423179 ±111% -98.4% 6944 ± 10%
latency_stats.sum.btrfs_sync_file.[btrfs].vfs_fsync_range.do_fsync.SyS_fsync.system_call_fastpath
11208157 ± 1% -42.1% 6484422 ± 0%
latency_stats.sum.btrfs_sync_log.[btrfs].btrfs_sync_file.[btrfs].vfs_fsync_range.do_fsync.SyS_fsync.system_call_fastpath
55333 ± 3% -73.7% 14563 ± 5%
latency_stats.sum.btrfs_tree_lock.[btrfs].btrfs_lock_root_node.[btrfs].btrfs_search_slot.[btrfs].btrfs_insert_empty_items.[btrfs].btrfs_log_inode.[btrfs].btrfs_log_inode_parent.[btrfs].btrfs_log_dentry_safe.[btrfs].btrfs_sync_file.[btrfs].vfs_fsync_range.do_fsync.SyS_fsync.system_call_fastpath
262263 ± 1% -18.7% 213138 ± 1%
latency_stats.sum.btrfs_tree_read_lock.[btrfs].btrfs_read_lock_root_node.[btrfs].btrfs_search_slot.[btrfs].btrfs_insert_empty_items.[btrfs].btrfs_log_inode.[btrfs].btrfs_log_inode_parent.[btrfs].btrfs_log_dentry_safe.[btrfs].btrfs_sync_file.[btrfs].vfs_fsync_range.do_fsync.SyS_fsync.system_call_fastpath
1387167 ± 0% +6.7% 1479555 ± 1%
latency_stats.sum.do_wait.SyS_wait4.system_call_fastpath
6668 ±173% +1166.1% 84431 ± 59%
latency_stats.sum.get_request.blk_queue_bio.generic_make_request.submit_bio.submit_stripe_bio.[btrfs].btrfs_map_bio.[btrfs].btrfs_submit_bio_hook.[btrfs].submit_one_bio.[btrfs].flush_epd_write_bio.[btrfs].extent_writepages.[btrfs].btrfs_writepages.[btrfs].do_writepages
14672479 ±154% -82.3% 2589754 ±141%
latency_stats.sum.nfs_wait_on_request.nfs_updatepage.nfs_write_end.generic_perform_write.__generic_file_write_iter.generic_file_write_iter.nfs_file_write.__vfs_write.vfs_write.SyS_write.system_call_fastpath
2775089 ± 0% +6.1% 2944954 ± 1%
latency_stats.sum.pipe_wait.pipe_read.__vfs_read.vfs_read.SyS_read.system_call_fastpath
1515574 ± 1% +160.1% 3941685 ± 0%
latency_stats.sum.wait_for_writer.[btrfs].btrfs_sync_log.[btrfs].btrfs_sync_file.[btrfs].vfs_fsync_range.do_fsync.SyS_fsync.system_call_fastpath
47560 ± 10% +335.6% 207189 ± 8%
latency_stats.sum.wait_on_page_bit.extent_write_cache_pages.[btrfs].extent_writepages.[btrfs].btrfs_writepages.[btrfs].do_writepages.__filemap_fdatawrite_range.filemap_fdatawrite_range.btrfs_fdatawrite_range.[btrfs].start_ordered_ops.[btrfs].btrfs_sync_file.[btrfs].vfs_fsync_range.do_fsync
20108473 ± 0% -20.5% 15989866 ± 0%
latency_stats.sum.wait_on_page_bit.filemap_fdatawait_range.btrfs_wait_marked_extents.[btrfs].btrfs_sync_log.[btrfs].btrfs_sync_file.[btrfs].vfs_fsync_range.do_fsync.SyS_fsync.system_call_fastpath
6853626 ± 0% +225.5% 22310007 ± 0%
latency_stats.sum.wait_ordered_extents.[btrfs].btrfs_log_changed_extents.[btrfs].btrfs_log_inode.[btrfs].btrfs_log_inode_parent.[btrfs].btrfs_log_dentry_safe.[btrfs].btrfs_sync_file.[btrfs].vfs_fsync_range.do_fsync.SyS_fsync.system_call_fastpath
4.196e+08 ± 0% +12.3% 4.712e+08 ± 0%
latency_stats.sum.write_all_supers.[btrfs].write_ctree_super.[btrfs].btrfs_sync_log.[btrfs].btrfs_sync_file.[btrfs].vfs_fsync_range.do_fsync.SyS_fsync.system_call_fastpath
lkp-sb02: Sandy Bridge-EP
Memory: 4G
fileio.requests_per_sec
45 ++-O-O--O--O--O-O--O--O--O-O--O--O--O-O--O--O-O--O--O--O-O--O--O--O-O--O
| |
40 ++ |
35 ++ |
| |
30 ++ |
25 ++ |
| |
20 ++ .*.. |
15 *+.*.*..*..*..*.*..*..*..* *..*..*.*..*..*.*..*..*..* |
| |
10 ++ |
5 ++ |
| |
0 O+---------------------------------------------------------------------+
fileio.time.voluntary_context_switches
180000 ++-----------------------------------------------------------------+
| .*.*..*..*.*..*.*..*.. .*.. .*. .*.. |
160000 *+.*.*..*.*. * *.*. *. * |
140000 ++ O O O O O O O O O O O O O O O O O O O O O O O O O
| |
120000 ++ |
100000 ++ O |
| |
80000 ++ |
60000 ++ |
| |
40000 ++ |
20000 ++ |
| |
0 O+-----------------------------------------------------------------+
time.voluntary_context_switches
180000 ++-----------------------------------------------------------------+
| .*.*..*..*.*..*.*..*.. .*.. .*. .*.. |
160000 *+.*.*..*.*. * *.*. *. * |
140000 ++ O O O O O O O O O O O O O O O O O O O O O O O O O
| |
120000 ++ |
100000 ++ O |
| |
80000 ++ |
60000 ++ |
| |
40000 ++ |
20000 ++ |
| |
0 O+-----------------------------------------------------------------+
proc-vmstat.nr_dirty
1000 ++-------------------------------------------------------------------+
900 ++ O O O O O O O O O O O O O O O O O O O O O O O O O
| |
800 ++ O |
700 ++ |
| |
600 ++ |
500 *+.*.*..*..*.*..*..*.*..*..*.*..*..*.*..*.*..*..*.*..* |
400 ++ |
| |
300 ++ |
200 ++ |
| |
100 ++ |
0 O+-------------------------------------------------------------------+
meminfo.Dirty
4000 ++-------------------------------------------------------------------+
| O O O O O O O O O O O O O O O O O O O O O O O O O
3500 ++ |
3000 ++ O |
| |
2500 ++ |
| |
2000 *+.*.*..*..*.*..*..*.*..*..*.*..*..*.*..*.*..*..*.*..* |
| |
1500 ++ |
1000 ++ |
| |
500 ++ |
| |
0 O+-------------------------------------------------------------------+
slabinfo.btrfs_extent_buffer.active_objs
3500 ++-------------------------------------------------------------------+
| *.. .*. .*.. |
3000 ++ .*.. + *. *. *. .*.*..*.*..*..*.*.. |
*..* *..* *..*. * |
2500 ++ |
| |
2000 ++ O O O O O O O O O O O O O O O O O O O O O O O O O
| |
1500 ++ O |
| |
1000 ++ |
| |
500 ++ |
| |
0 O+-------------------------------------------------------------------+
slabinfo.btrfs_extent_buffer.num_objs
3500 ++-------------------------------------------------------------------+
| *.. .*. .*.. |
3000 ++ .*.. + *. *. *. .*.*..*.*..*..*.*.. |
*..* *..* *..*. * |
2500 ++ |
| O |
2000 ++ O O O O O O O O O O O O O O O O O O O O O O O O
| |
1500 ++ O |
| |
1000 ++ |
| |
500 ++ |
| |
0 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,
Ying Huang
---
LKP_SERVER: inn
LKP_CGI_PORT: 80
LKP_CIFS_PORT: 139
testcase: fileio
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: 64291f7db5bd8150a74ad2036f1037e6a0428df2
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
period: 600s
nr_threads: 100%
disk: 1HDD
fs: btrfs
size: 64G
fileio:
filenum: 1024f
rwmode: rndwr
iomode: sync
queue: cyclic
testbox: lkp-sb02
tbox_group: lkp-sb02
kconfig: x86_64-rhel
enqueue_time: 2015-08-23 18:20:46.136635107 +08:00
id: 8f4a54637453145f1101eca4adceb78bc5334509
user: wfg
compiler: gcc-4.9
head_commit: adfde4b103c6a98e315b4245d4d762e825353e67
base_commit: 64291f7db5bd8150a74ad2036f1037e6a0428df2
branch: linux-devel/devel-hourly-2015090114
kernel:
"/pkg/linux/x86_64-rhel/gcc-4.9/64291f7db5bd8150a74ad2036f1037e6a0428df2/vmlinuz-4.2.0"
rootfs: debian-x86_64-2015-02-07.cgz
result_root:
"/result/fileio/performance-600s-100%-1HDD-btrfs-64G-1024f-rndwr-sync/lkp-sb02/debian-x86_64-2015-02-07.cgz/x86_64-rhel/gcc-4.9/64291f7db5bd8150a74ad2036f1037e6a0428df2/0"
job_file:
"/lkp/scheduled/lkp-sb02/cyclic_fileio-performance-600s-100%-1HDD-btrfs-64G-1024f-rndwr-sync-x86_64-rhel-CYCLIC_BASE-64291f7db5bd8150a74ad2036f1037e6a0428df2-20150823-113373-1eaddh9-0.yaml"
dequeue_time: 2015-09-01 21:40:48.037574301 +08:00
nr_cpu: "$(nproc)"
max_uptime: 1905.6399999999996
initrd: "/osimage/debian/debian-x86_64-2015-02-07.cgz"
bootloader_append:
- root=/dev/ram0
- user=wfg
-
job=/lkp/scheduled/lkp-sb02/cyclic_fileio-performance-600s-100%-1HDD-btrfs-64G-1024f-rndwr-sync-x86_64-rhel-CYCLIC_BASE-64291f7db5bd8150a74ad2036f1037e6a0428df2-20150823-113373-1eaddh9-0.yaml
- ARCH=x86_64
- kconfig=x86_64-rhel
- branch=linux-devel/devel-hourly-2015090114
- commit=64291f7db5bd8150a74ad2036f1037e6a0428df2
-
BOOT_IMAGE=/pkg/linux/x86_64-rhel/gcc-4.9/64291f7db5bd8150a74ad2036f1037e6a0428df2/vmlinuz-4.2.0
- max_uptime=1905
-
RESULT_ROOT=/result/fileio/performance-600s-100%-1HDD-btrfs-64G-1024f-rndwr-sync/lkp-sb02/debian-x86_64-2015-02-07.cgz/x86_64-rhel/gcc-4.9/64291f7db5bd8150a74ad2036f1037e6a0428df2/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/wfg/lkp-x86_64.cgz"
modules_initrd:
"/pkg/linux/x86_64-rhel/gcc-4.9/64291f7db5bd8150a74ad2036f1037e6a0428df2/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/fileio.cgz"
