[<prev] [next>] [day] [month] [year] [list]
Message-ID: <20160317053934.GC1670@yexl-desktop>
Date: Thu, 17 Mar 2016 13:39:34 +0800
From: kernel test robot <xiaolong.ye@...el.com>
To: Jaegeuk Kim <jaegeuk@...nel.org>
Cc: LKML <linux-kernel@...r.kernel.org>, lkp@...org
Subject: [lkp] [f2fs] 25c1355151: +6.0% fsmark.app_overhead
FYI, we noticed that fsmark.app_overhead +6.0% increasement on
https://git.kernel.org/pub/scm/linux/kernel/git/jaegeuk/f2fs dev-test
commit 25c13551519c66453737e038d104058f94b2e70a ("f2fs: use writepages->lock for WB_SYNC_ALL")
=========================================================================================
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/16MB/f2fs/1x/x86_64-rhel/16d/256fpd/32t/debian-x86_64-2015-02-07.cgz/fsyncBeforeClose/lkp-sb02/60G/fsmark
commit:
b483fadf7e913be838e11e065175205aa17e429a
25c13551519c66453737e038d104058f94b2e70a
b483fadf7e913be8 25c13551519c66453737e038d1
---------------- --------------------------
%stddev %change %stddev
\ | \
552212 ± 1% +6.0% 585551 ± 5% fsmark.app_overhead
21783 ± 1% +38.4% 30142 ± 4% fsmark.time.involuntary_context_switches
671513 ± 8% +78.6% 1199030 ± 4% fsmark.time.voluntary_context_switches
103046 ± 3% +36.4% 140590 ± 4% vmstat.memory.free
1340 ± 5% +71.5% 2299 ± 3% vmstat.system.cs
27693777 ± 11% +23.8% 34297734 ± 8% cpuidle.C1-SNB.time
1.574e+08 ± 30% +141.0% 3.794e+08 ± 16% cpuidle.POLL.time
214433 ± 9% +166.5% 571452 ± 4% cpuidle.POLL.usage
1010 ± 2% +47.4% 1489 ± 1% time.file_system_inputs
21783 ± 1% +38.4% 30142 ± 4% time.involuntary_context_switches
671513 ± 8% +78.6% 1199030 ± 4% time.voluntary_context_switches
191323 ± 6% -14.7% 163263 ± 3% meminfo.Dirty
102976 ± 3% +36.6% 140637 ± 4% meminfo.MemFree
30591 ± 0% +59.9% 48906 ± 2% meminfo.SUnreclaim
107972 ± 0% +23.8% 133628 ± 1% meminfo.Slab
4.88 ± 17% +98.1% 9.66 ± 12% turbostat.%Busy
143.78 ± 17% +100.7% 288.50 ± 12% turbostat.Avg_MHz
9.26 ± 3% +11.3% 10.31 ± 4% turbostat.CPU%c1
3.93 ± 9% +53.5% 6.03 ± 8% turbostat.CorWatt
24.40 ± 5% -20.8% 19.32 ± 5% turbostat.Pkg%pc2
7.06 ± 6% -18.4% 5.76 ± 6% turbostat.Pkg%pc3
28.14 ± 4% -22.4% 21.85 ± 5% turbostat.Pkg%pc6
7.31 ± 4% +29.2% 9.44 ± 5% turbostat.PkgWatt
344.44 ± 15% +38478.6% 132881 ± 8% slabinfo.f2fs_extent_node.active_objs
3.78 ± 20% +48240.6% 1826 ± 8% slabinfo.f2fs_extent_node.active_slabs
344.44 ± 15% +38610.4% 133335 ± 8% slabinfo.f2fs_extent_node.num_objs
3.78 ± 20% +48240.6% 1826 ± 8% slabinfo.f2fs_extent_node.num_slabs
1544 ± 0% +277.3% 5827 ± 6% slabinfo.kmalloc-256.active_objs
117.78 ± 3% +263.5% 428.10 ± 5% slabinfo.kmalloc-256.active_slabs
1892 ± 3% +262.3% 6856 ± 5% slabinfo.kmalloc-256.num_objs
117.78 ± 3% +263.5% 428.10 ± 5% slabinfo.kmalloc-256.num_slabs
295.11 ± 1% +1434.4% 4528 ± 7% slabinfo.kmalloc-4096.active_objs
39.00 ± 1% +2253.3% 917.80 ± 8% slabinfo.kmalloc-4096.active_slabs
315.00 ± 1% +1352.2% 4574 ± 7% slabinfo.kmalloc-4096.num_objs
39.00 ± 1% +2253.3% 917.80 ± 8% slabinfo.kmalloc-4096.num_slabs
93.67 ±164% +4783.1% 4573 ± 18% proc-vmstat.allocstall
110.22 ± 9% +6662.5% 7453 ± 36% proc-vmstat.kswapd_high_wmark_hit_quickly
5848 ± 1% +144.9% 14326 ± 15% proc-vmstat.kswapd_low_wmark_hit_quickly
47830 ± 6% -14.7% 40810 ± 3% proc-vmstat.nr_dirty
25744 ± 3% +36.6% 35157 ± 4% proc-vmstat.nr_free_pages
25.33 ± 26% +1126.4% 310.70 ± 15% proc-vmstat.nr_pages_scanned
7647 ± 0% +59.9% 12224 ± 2% proc-vmstat.nr_slab_unreclaimable
76857 ± 43% -60.7% 30217 ± 53% proc-vmstat.nr_vmscan_immediate_reclaim
6361 ± 0% +253.8% 22511 ± 22% proc-vmstat.pageoutrun
13101725 ± 0% +12.5% 14745650 ± 0% proc-vmstat.pgalloc_dma32
3956682 ± 0% +21.0% 4789042 ± 1% proc-vmstat.pgalloc_normal
16228928 ± 0% +15.3% 18704882 ± 0% proc-vmstat.pgfree
31211 ±107% +2261.2% 736978 ± 16% proc-vmstat.pgscan_direct_dma32
9873 ±107% +2223.3% 229380 ± 16% proc-vmstat.pgscan_direct_normal
13354 ±169% +5000.3% 681106 ± 18% proc-vmstat.pgsteal_direct_dma32
4264 ±168% +4865.8% 211768 ± 18% proc-vmstat.pgsteal_direct_normal
219420 ± 0% +2108.9% 4846809 ± 8% proc-vmstat.slabs_scanned
364381 ±132% -96.1% 14178 ±121% latency_stats.avg.alloc_nid.[f2fs].f2fs_new_inode.[f2fs].f2fs_create.[f2fs].vfs_create.path_openat.do_filp_open.do_sys_open.SyS_open.entry_SYSCALL_64_fastpath
0.00 ± -1% +Inf% 6157 ± 30% latency_stats.avg.allocate_data_block.[f2fs].do_write_page.[f2fs].write_data_page.[f2fs].do_write_data_page.[f2fs].f2fs_write_data_page.[f2fs].__f2fs_writepage.[f2fs].f2fs_write_cache_pages.[f2fs].f2fs_write_data_pages.[f2fs].do_writepages.__filemap_fdatawrite_range.filemap_write_and_wait_range.f2fs_sync_file.[f2fs]
0.00 ± -1% +Inf% 68118 ± 59% latency_stats.avg.call_rwsem_down_read_failed.f2fs_write_begin.[f2fs].generic_perform_write.__generic_file_write_iter.generic_file_write_iter.f2fs_file_write_iter.[f2fs].__vfs_write.vfs_write.SyS_write.entry_SYSCALL_64_fastpath
19231 ± 0% +533.2% 121779 ± 65% latency_stats.avg.call_rwsem_down_write_failed.block_operations.[f2fs].write_checkpoint.[f2fs].f2fs_sync_fs.[f2fs].f2fs_sync_file.[f2fs].vfs_fsync_range.do_fsync.SyS_fsync.entry_SYSCALL_64_fastpath
0.00 ± -1% +Inf% 94391 ±101% latency_stats.avg.call_rwsem_down_write_failed.f2fs_submit_merged_bio.[f2fs].f2fs_write_data_pages.[f2fs].do_writepages.__filemap_fdatawrite_range.filemap_write_and_wait_range.f2fs_sync_file.[f2fs].vfs_fsync_range.do_fsync.SyS_fsync.entry_SYSCALL_64_fastpath
11119 ± 86% +1161.5% 140262 ± 10% latency_stats.avg.call_rwsem_down_write_failed.f2fs_submit_page_mbio.[f2fs].do_write_page.[f2fs].write_data_page.[f2fs].do_write_data_page.[f2fs].f2fs_write_data_page.[f2fs].__f2fs_writepage.[f2fs].f2fs_write_cache_pages.[f2fs].f2fs_write_data_pages.[f2fs].do_writepages.__filemap_fdatawrite_range.filemap_write_and_wait_range
23095 ± 15% -89.6% 2408 ±134% latency_stats.avg.call_rwsem_down_write_failed.set_node_addr.[f2fs].f2fs_write_node_page.[f2fs].sync_node_pages.[f2fs].f2fs_sync_file.[f2fs].vfs_fsync_range.do_fsync.SyS_fsync.entry_SYSCALL_64_fastpath
0.00 ± -1% +Inf% 2220210 ± 60% latency_stats.avg.f2fs_sync_fs.[f2fs].f2fs_sync_file.[f2fs].vfs_fsync_range.do_fsync.SyS_fsync.entry_SYSCALL_64_fastpath
0.00 ± -1% +Inf% 77575 ± 50% latency_stats.avg.wait_iff_congested.shrink_inactive_list.shrink_zone_memcg.shrink_zone.do_try_to_free_pages.try_to_free_pages.__alloc_pages_slowpath.__alloc_pages_nodemask.alloc_pages_current.__page_cache_alloc.pagecache_get_page.grab_cache_page_write_begin
0.00 ± -1% +Inf% 53520 ± 89% latency_stats.avg.wait_iff_congested.shrink_inactive_list.shrink_zone_memcg.shrink_zone.do_try_to_free_pages.try_to_free_pages.__alloc_pages_slowpath.__alloc_pages_nodemask.alloc_pages_current.new_slab.___slab_alloc.__slab_alloc
57788 ± 1% +221.3% 185675 ± 9% latency_stats.hits.wait_on_page_bit.__filemap_fdatawait_range.filemap_fdatawait_range.filemap_write_and_wait_range.f2fs_sync_file.[f2fs].vfs_fsync_range.do_fsync.SyS_fsync.entry_SYSCALL_64_fastpath
723355 ± 82% -73.3% 193177 ± 91% latency_stats.max.alloc_nid.[f2fs].f2fs_new_inode.[f2fs].f2fs_create.[f2fs].vfs_create.path_openat.do_filp_open.do_sys_open.SyS_open.entry_SYSCALL_64_fastpath
0.00 ± -1% +Inf% 19907 ±139% latency_stats.max.allocate_data_block.[f2fs].do_write_page.[f2fs].write_data_page.[f2fs].do_write_data_page.[f2fs].f2fs_write_data_page.[f2fs].__f2fs_writepage.[f2fs].f2fs_write_cache_pages.[f2fs].f2fs_write_data_pages.[f2fs].do_writepages.__filemap_fdatawrite_range.filemap_write_and_wait_range.f2fs_sync_file.[f2fs]
0.00 ± -1% +Inf% 150516 ± 59% latency_stats.max.call_rwsem_down_read_failed.f2fs_write_begin.[f2fs].generic_perform_write.__generic_file_write_iter.generic_file_write_iter.f2fs_file_write_iter.[f2fs].__vfs_write.vfs_write.SyS_write.entry_SYSCALL_64_fastpath
794065 ± 51% -94.4% 44235 ±159% latency_stats.max.call_rwsem_down_read_failed.get_node_info.[f2fs].read_node_page.[f2fs].__get_node_page.[f2fs].get_node_page.[f2fs].get_dnode_of_data.[f2fs].f2fs_reserve_block.[f2fs].f2fs_get_block.[f2fs].f2fs_write_begin.[f2fs].generic_perform_write.__generic_file_write_iter.generic_file_write_iter
1014725 ± 22% -95.6% 44296 ±159% latency_stats.max.call_rwsem_down_read_failed.get_node_info.[f2fs].read_node_page.[f2fs].__get_node_page.[f2fs].get_node_page.[f2fs].get_node_page.[f2fs].f2fs_write_begin.[f2fs].generic_perform_write.__generic_file_write_iter.generic_file_write_iter.f2fs_file_write_iter.[f2fs].__vfs_write
425754 ± 97% -90.1% 42226 ±169% latency_stats.max.call_rwsem_down_read_failed.get_node_info.[f2fs].write_data_page.[f2fs].do_write_data_page.[f2fs].f2fs_write_data_page.[f2fs].__f2fs_writepage.[f2fs].f2fs_write_cache_pages.[f2fs].f2fs_write_data_pages.[f2fs].do_writepages.__filemap_fdatawrite_range.filemap_write_and_wait_range.f2fs_sync_file.[f2fs]
19231 ± 0% +4035.5% 795298 ± 80% latency_stats.max.call_rwsem_down_write_failed.block_operations.[f2fs].write_checkpoint.[f2fs].f2fs_sync_fs.[f2fs].f2fs_sync_file.[f2fs].vfs_fsync_range.do_fsync.SyS_fsync.entry_SYSCALL_64_fastpath
0.00 ± -1% +Inf% 123677 ±103% latency_stats.max.call_rwsem_down_write_failed.f2fs_submit_merged_bio.[f2fs].f2fs_write_data_pages.[f2fs].do_writepages.__filemap_fdatawrite_range.filemap_write_and_wait_range.f2fs_sync_file.[f2fs].vfs_fsync_range.do_fsync.SyS_fsync.entry_SYSCALL_64_fastpath
13652 ± 57% +9571.3% 1320329 ± 20% latency_stats.max.call_rwsem_down_write_failed.f2fs_submit_page_mbio.[f2fs].do_write_page.[f2fs].write_data_page.[f2fs].do_write_data_page.[f2fs].f2fs_write_data_page.[f2fs].__f2fs_writepage.[f2fs].f2fs_write_cache_pages.[f2fs].f2fs_write_data_pages.[f2fs].do_writepages.__filemap_fdatawrite_range.filemap_write_and_wait_range
0.00 ± -1% +Inf% 2342313 ± 61% latency_stats.max.f2fs_sync_fs.[f2fs].f2fs_sync_file.[f2fs].vfs_fsync_range.do_fsync.SyS_fsync.entry_SYSCALL_64_fastpath
192297 ± 57% +239.8% 653426 ± 32% latency_stats.max.get_request.blk_queue_bio.generic_make_request.submit_bio.__submit_merged_bio.[f2fs].f2fs_submit_merged_bio.[f2fs].f2fs_write_data_pages.[f2fs].do_writepages.__filemap_fdatawrite_range.filemap_write_and_wait_range.f2fs_sync_file.[f2fs].vfs_fsync_range
0.00 ± -1% +Inf% 78018 ± 50% latency_stats.max.wait_iff_congested.shrink_inactive_list.shrink_zone_memcg.shrink_zone.do_try_to_free_pages.try_to_free_pages.__alloc_pages_slowpath.__alloc_pages_nodemask.alloc_pages_current.__page_cache_alloc.pagecache_get_page.grab_cache_page_write_begin
0.00 ± -1% +Inf% 54060 ± 89% latency_stats.max.wait_iff_congested.shrink_inactive_list.shrink_zone_memcg.shrink_zone.do_try_to_free_pages.try_to_free_pages.__alloc_pages_slowpath.__alloc_pages_nodemask.alloc_pages_current.new_slab.___slab_alloc.__slab_alloc
4632456 ± 93% -77.6% 1037402 ±121% latency_stats.sum.alloc_nid.[f2fs].f2fs_new_inode.[f2fs].f2fs_create.[f2fs].vfs_create.path_openat.do_filp_open.do_sys_open.SyS_open.entry_SYSCALL_64_fastpath
0.00 ± -1% +Inf% 86433 ± 44% latency_stats.sum.allocate_data_block.[f2fs].do_write_page.[f2fs].write_data_page.[f2fs].do_write_data_page.[f2fs].f2fs_write_data_page.[f2fs].__f2fs_writepage.[f2fs].f2fs_write_cache_pages.[f2fs].f2fs_write_data_pages.[f2fs].do_writepages.__filemap_fdatawrite_range.filemap_write_and_wait_range.f2fs_sync_file.[f2fs]
0.00 ± -1% +Inf% 2383249 ± 92% latency_stats.sum.call_rwsem_down_read_failed.f2fs_write_begin.[f2fs].generic_perform_write.__generic_file_write_iter.generic_file_write_iter.f2fs_file_write_iter.[f2fs].__vfs_write.vfs_write.SyS_write.entry_SYSCALL_64_fastpath
1199350 ±181% -74.2% 309546 ± 10% latency_stats.sum.call_rwsem_down_read_failed.get_node_info.[f2fs].read_node_page.[f2fs].__get_node_page.[f2fs].get_node_page.[f2fs].get_dnode_of_data.[f2fs].get_read_data_page.[f2fs].find_data_page.[f2fs].f2fs_find_entry.[f2fs].f2fs_lookup.[f2fs].lookup_real.path_openat
19231 ± 0% +4037.1% 795607 ± 80% latency_stats.sum.call_rwsem_down_write_failed.block_operations.[f2fs].write_checkpoint.[f2fs].f2fs_sync_fs.[f2fs].f2fs_sync_file.[f2fs].vfs_fsync_range.do_fsync.SyS_fsync.entry_SYSCALL_64_fastpath
0.00 ± -1% +Inf% 150063 ±109% latency_stats.sum.call_rwsem_down_write_failed.f2fs_submit_merged_bio.[f2fs].f2fs_write_data_pages.[f2fs].do_writepages.__filemap_fdatawrite_range.filemap_write_and_wait_range.f2fs_sync_file.[f2fs].vfs_fsync_range.do_fsync.SyS_fsync.entry_SYSCALL_64_fastpath
13652 ± 57% +2.8e+05% 38009621 ± 12% latency_stats.sum.call_rwsem_down_write_failed.f2fs_submit_page_mbio.[f2fs].do_write_page.[f2fs].write_data_page.[f2fs].do_write_data_page.[f2fs].f2fs_write_data_page.[f2fs].__f2fs_writepage.[f2fs].f2fs_write_cache_pages.[f2fs].f2fs_write_data_pages.[f2fs].do_writepages.__filemap_fdatawrite_range.filemap_write_and_wait_range
1168485 ± 81% -58.4% 485914 ± 44% latency_stats.sum.call_rwsem_down_write_failed.get_node_info.[f2fs].new_node_page.[f2fs].new_inode_page.[f2fs].init_inode_metadata.[f2fs].__f2fs_add_link.[f2fs].f2fs_create.[f2fs].vfs_create.path_openat.do_filp_open.do_sys_open.SyS_open
3847 ± 76% +5520.0% 216250 ± 9% latency_stats.sum.call_rwsem_down_write_failed.get_node_info.[f2fs].read_node_page.[f2fs].__get_node_page.[f2fs].get_node_page.[f2fs].get_dnode_of_data.[f2fs].f2fs_reserve_block.[f2fs].get_new_data_page.[f2fs].__f2fs_add_link.[f2fs].f2fs_create.[f2fs].vfs_create.path_openat
5857 ± 81% +5984.5% 356421 ± 57% latency_stats.sum.call_rwsem_down_write_failed.get_node_info.[f2fs].read_node_page.[f2fs].__get_node_page.[f2fs].get_node_page.[f2fs].get_dnode_of_data.[f2fs].get_read_data_page.[f2fs].find_data_page.[f2fs].f2fs_find_entry.[f2fs].f2fs_lookup.[f2fs].lookup_real.path_openat
10101346 ± 20% -90.6% 947017 ±141% latency_stats.sum.call_rwsem_down_write_failed.set_node_addr.[f2fs].f2fs_write_node_page.[f2fs].sync_node_pages.[f2fs].f2fs_sync_file.[f2fs].vfs_fsync_range.do_fsync.SyS_fsync.entry_SYSCALL_64_fastpath
674069 ± 79% -70.0% 202360 ± 6% latency_stats.sum.call_rwsem_down_write_failed.set_node_addr.[f2fs].new_node_page.[f2fs].new_inode_page.[f2fs].init_inode_metadata.[f2fs].__f2fs_add_link.[f2fs].f2fs_create.[f2fs].vfs_create.path_openat.do_filp_open.do_sys_open.SyS_open
0.00 ± -1% +Inf% 7065858 ± 87% latency_stats.sum.f2fs_sync_fs.[f2fs].f2fs_sync_file.[f2fs].vfs_fsync_range.do_fsync.SyS_fsync.entry_SYSCALL_64_fastpath
624892 ± 77% +875.0% 6092743 ± 31% latency_stats.sum.get_request.blk_queue_bio.generic_make_request.submit_bio.__submit_merged_bio.[f2fs].f2fs_submit_merged_bio.[f2fs].f2fs_write_data_pages.[f2fs].do_writepages.__filemap_fdatawrite_range.filemap_write_and_wait_range.f2fs_sync_file.[f2fs].vfs_fsync_range
0.00 ± -1% +Inf% 2781158 ±128% latency_stats.sum.wait_iff_congested.shrink_inactive_list.shrink_zone_memcg.shrink_zone.do_try_to_free_pages.try_to_free_pages.__alloc_pages_slowpath.__alloc_pages_nodemask.alloc_pages_current.__page_cache_alloc.pagecache_get_page.grab_cache_page_write_begin
0.00 ± -1% +Inf% 158254 ±150% latency_stats.sum.wait_iff_congested.shrink_inactive_list.shrink_zone_memcg.shrink_zone.do_try_to_free_pages.try_to_free_pages.__alloc_pages_slowpath.__alloc_pages_nodemask.alloc_pages_current.new_slab.___slab_alloc.__slab_alloc
lkp-sb02: Sandy Bridge-EP
Memory: 4G
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.
View attachment "job.yaml" of type "text/plain" (3884 bytes)
View attachment "reproduce" of type "text/plain" (1012 bytes)
Powered by blists - more mailing lists