[lkp] [f2fs] 974b5afbf1: +187.0% fsmark.time.voluntary_context_switches
From: kernel test robot
Date: Sun Feb 14 2016 - 02:31:01 EST
FYI, we noticed the below changes on
https://git.kernel.org/pub/scm/linux/kernel/git/jaegeuk/f2fs dev-test
commit 974b5afbf16ecd3e01cefd5d52e3090b6d967693 ("f2fs: use writepages->lock for WB_SYNC_ALL")
=========================================================================================
compiler/disk/filesize/fs/iterations/kconfig/nr_directories/nr_files_per_directory/nr_threads/rootfs/sync_method/tbox_group/test_size/testcase:
gcc-4.9/1HDD/16MB/f2fs/1x/x86_64-rhel/16d/256fpd/32t/debian-x86_64-2015-02-07.cgz/fsyncBeforeClose/nhm4/60G/fsmark
commit:
ac247fd0403387a3f264b86b41cdc71543e66400
974b5afbf16ecd3e01cefd5d52e3090b6d967693
ac247fd0403387a3 974b5afbf16ecd3e01cefd5d52
---------------- --------------------------
%stddev %change %stddev
\ | \
40098 ± 2% +25.7% 50389 ± 3% fsmark.time.involuntary_context_switches
19.30 ± 2% +18.1% 22.80 ± 1% fsmark.time.percent_of_cpu_this_job_got
97.36 ± 1% +18.1% 115.00 ± 1% fsmark.time.system_time
804635 ± 1% +187.0% 2309592 ± 5% fsmark.time.voluntary_context_switches
1904 ± 1% -18.8% 1546 ± 3% uptime.idle
38568 ± 2% +19.0% 45897 ± 3% softirqs.RCU
45610 ± 1% +26.9% 57875 ± 1% softirqs.SCHED
78751 ± 1% +39.3% 109673 ± 0% softirqs.TIMER
65587 ± 0% +76.5% 115770 ± 0% vmstat.memory.free
4605 ± 1% +159.8% 11962 ± 3% vmstat.system.cs
564.10 ± 1% +75.7% 991.10 ± 0% vmstat.system.in
65578 ± 0% +76.3% 115584 ± 0% meminfo.MemFree
69193 ± 0% +46.4% 101331 ± 2% meminfo.SReclaimable
79277 ± 0% +53.9% 121991 ± 0% meminfo.SUnreclaim
148470 ± 0% +50.4% 223322 ± 1% meminfo.Slab
1066 ± 2% +45.8% 1554 ± 1% time.file_system_inputs
40098 ± 2% +25.7% 50389 ± 3% time.involuntary_context_switches
19.30 ± 2% +18.1% 22.80 ± 1% time.percent_of_cpu_this_job_got
97.36 ± 1% +18.1% 115.00 ± 1% time.system_time
804635 ± 1% +187.0% 2309592 ± 5% time.voluntary_context_switches
4.80 ± 3% +240.9% 16.37 ± 3% turbostat.%Busy
150.30 ± 3% +259.0% 539.60 ± 3% turbostat.Avg_MHz
10.10 ± 2% +69.4% 17.11 ± 2% turbostat.CPU%c1
24.51 ± 2% +12.3% 27.54 ± 2% turbostat.CPU%c3
60.59 ± 0% -35.7% 38.99 ± 2% turbostat.CPU%c6
56.00 ± 1% +12.9% 63.20 ± 1% turbostat.CoreTmp
1.042e+08 ± 3% -32.6% 70243667 ± 5% cpuidle.C1E-NHM.time
5.49e+08 ± 2% +23.1% 6.76e+08 ± 2% cpuidle.C3-NHM.time
155243 ± 2% +22.3% 189817 ± 3% cpuidle.C3-NHM.usage
3.052e+09 ± 0% -17.6% 2.515e+09 ± 1% cpuidle.C6-NHM.time
132307 ± 2% +20.6% 159621 ± 2% cpuidle.C6-NHM.usage
64832253 ± 9% +626.5% 4.71e+08 ± 4% cpuidle.POLL.time
95963 ± 2% +987.2% 1043299 ± 8% cpuidle.POLL.usage
582.20 ± 0% +1e+05% 583505 ± 7% slabinfo.f2fs_extent_node.active_objs
7.20 ± 5% +1.1e+05% 7994 ± 7% slabinfo.f2fs_extent_node.active_slabs
582.20 ± 0% +1e+05% 583664 ± 7% slabinfo.f2fs_extent_node.num_objs
7.20 ± 5% +1.1e+05% 7994 ± 7% slabinfo.f2fs_extent_node.num_slabs
10171 ± 6% +22.6% 12471 ± 10% slabinfo.free_nid.active_objs
10194 ± 6% +23.4% 12580 ± 9% slabinfo.free_nid.num_objs
1834 ± 1% +543.2% 11798 ± 0% slabinfo.kmalloc-256.active_objs
78.70 ± 6% +406.9% 398.90 ± 1% slabinfo.kmalloc-256.active_slabs
2524 ± 6% +403.5% 12710 ± 1% slabinfo.kmalloc-256.num_objs
78.70 ± 6% +406.9% 398.90 ± 1% slabinfo.kmalloc-256.num_slabs
355.80 ± 0% +2796.0% 10303 ± 1% slabinfo.kmalloc-4096.active_objs
55.00 ± 1% +8795.8% 4892 ± 3% slabinfo.kmalloc-4096.active_slabs
378.60 ± 0% +2639.0% 10369 ± 1% slabinfo.kmalloc-4096.num_objs
55.00 ± 1% +8795.8% 4892 ± 3% slabinfo.kmalloc-4096.num_slabs
2929 ± 11% +1926.0% 59360 ± 5% proc-vmstat.allocstall
160.70 ± 28% +461.8% 902.80 ± 39% proc-vmstat.compact_isolated
116.60 ± 21% +1575.8% 1954 ±124% proc-vmstat.compact_migrate_scanned
1657 ± 10% +10214.9% 170917 ± 14% proc-vmstat.kswapd_high_wmark_hit_quickly
14489 ± 3% +974.7% 155724 ± 12% proc-vmstat.kswapd_low_wmark_hit_quickly
16393 ± 0% +76.3% 28901 ± 0% proc-vmstat.nr_free_pages
17297 ± 0% +46.4% 25331 ± 2% proc-vmstat.nr_slab_reclaimable
19818 ± 0% +53.9% 30499 ± 0% proc-vmstat.nr_slab_unreclaimable
16253363 ± 0% +21.1% 19685684 ± 0% proc-vmstat.numa_hit
16253363 ± 0% +21.1% 19685684 ± 0% proc-vmstat.numa_local
16974 ± 2% +1830.1% 327619 ± 13% proc-vmstat.pageoutrun
16298906 ± 0% +44.0% 23466530 ± 0% proc-vmstat.pgalloc_dma32
15711596 ± 0% +45.8% 22903686 ± 0% proc-vmstat.pgfree
480139 ± 8% +1593.6% 8131796 ± 5% proc-vmstat.pgscan_direct_dma32
14970914 ± 0% -51.0% 7341759 ± 5% proc-vmstat.pgscan_kswapd_dma32
396381 ± 11% +1928.7% 8041357 ± 5% proc-vmstat.pgsteal_direct_dma32
14805624 ± 0% -51.4% 7188819 ± 5% proc-vmstat.pgsteal_kswapd_dma32
207014 ± 0% +6368.5% 13390822 ± 1% proc-vmstat.slabs_scanned
0.00 ± -1% +Inf% 19563 ± 50% 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% 31033 ± 94% latency_stats.avg.allocate_data_block.[f2fs].do_write_page.[f2fs].write_node_page.[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
43514 ±179% -24.3% 32919 ± 42% 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% 39044 ± 40% 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
9117306 ±127% -99.9% 10078 ±263% 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.entry_SYSCALL_64_fastpath
33.75 ±173% +1.9e+05% 62857 ±114% latency_stats.avg.pipe_write.__vfs_write.vfs_write.SyS_write.entry_SYSCALL_64_fastpath
0.00 ± -1% +Inf% 78722 ± 14% 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_kmem_pages_node.copy_process._do_fork.SyS_clone
0.00 ± -1% +Inf% 73283 ± 1% 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% 84609 ± 12% 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_meta_page.[f2fs]
0.00 ± -1% +Inf% 75164 ± 12% 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.new_node_page.[f2fs]
0.00 ± -1% +Inf% 85332 ± 1% 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
0.00 ± -1% +Inf% 65254 ± 66% 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.pte_alloc_one.__pte_alloc.handle_mm_fault
0.00 ± -1% +Inf% 75091 ± 35% 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_vma.handle_mm_fault.__do_page_fault.do_page_fault
0.00 ± -1% +Inf% 64635 ± 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_vma.wp_page_copy.do_wp_page.handle_mm_fault
57408 ± 1% -93.3% 3824 ± 10% latency_stats.avg.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
49060 ± 2% +1508.8% 789275 ± 10% 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
0.00 ± -1% +Inf% 129504 ± 33% 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% 38782 ± 81% latency_stats.max.allocate_data_block.[f2fs].do_write_page.[f2fs].write_node_page.[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% 86260 ± 46% 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
13770 ± 38% +2493.6% 357160 ± 18% 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
71537 ±135% -90.4% 6880 ± 17% latency_stats.max.call_rwsem_down_write_failed.get_node_info.[f2fs].new_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.f2fs_file_write_iter.[f2fs].__vfs_write
15813502 ±166% -99.9% 10078 ±263% 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.entry_SYSCALL_64_fastpath
33.75 ±173% +2.2e+05% 73000 ±113% latency_stats.max.pipe_write.__vfs_write.vfs_write.SyS_write.entry_SYSCALL_64_fastpath
0.00 ± -1% +Inf% 97634 ± 0% 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_kmem_pages_node.copy_process._do_fork.SyS_clone
0.00 ± -1% +Inf% 99094 ± 0% 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% 97469 ± 0% 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_meta_page.[f2fs]
0.00 ± -1% +Inf% 95084 ± 5% 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.new_node_page.[f2fs]
0.00 ± -1% +Inf% 98808 ± 0% 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
0.00 ± -1% +Inf% 66744 ± 65% 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.pte_alloc_one.__pte_alloc.handle_mm_fault
0.00 ± -1% +Inf% 87727 ± 33% 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_vma.handle_mm_fault.__do_page_fault.do_page_fault
0.00 ± -1% +Inf% 69586 ± 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_vma.wp_page_copy.do_wp_page.handle_mm_fault
20738812 ± 27% -87.5% 2591032 ±122% latency_stats.sum.alloc_nid.[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.f2fs_file_write_iter.[f2fs].__vfs_write.vfs_write.SyS_write
0.00 ± -1% +Inf% 423935 ± 53% 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% 51307 ± 98% latency_stats.sum.allocate_data_block.[f2fs].do_write_page.[f2fs].write_node_page.[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
1.391e+08 ± 38% +329.4% 5.974e+08 ± 19% latency_stats.sum.balance_dirty_pages.balance_dirty_pages_ratelimited.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
0.00 ± -1% +Inf% 188844 ± 44% 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
13770 ± 38% +4.1e+05% 56903822 ± 3% 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
0.00 ± -1% +Inf% 190702 ±103% 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
33143824 ± 9% -84.9% 5019833 ± 18% latency_stats.sum.get_request.blk_queue_bio.generic_make_request.submit_bio.__submit_merged_bio.[f2fs].f2fs_submit_merged_bio.[f2fs].sync_node_pages.[f2fs].f2fs_sync_file.[f2fs].vfs_fsync_range.do_fsync.SyS_fsync.entry_SYSCALL_64_fastpath
2913424 ± 31% -71.7% 823962 ± 30% latency_stats.sum.get_request.blk_queue_bio.generic_make_request.submit_bio.__submit_merged_bio.[f2fs].f2fs_submit_page_mbio.[f2fs].do_write_page.[f2fs].write_node_page.[f2fs].f2fs_write_node_page.[f2fs].sync_node_pages.[f2fs].f2fs_sync_file.[f2fs].vfs_fsync_range
356283 ±145% -54.1% 163527 ± 96% latency_stats.sum.get_request.blk_queue_bio.generic_make_request.submit_bio.submit_bio_wait.f2fs_issue_flush.[f2fs].f2fs_sync_file.[f2fs].vfs_fsync_range.do_fsync.SyS_fsync.entry_SYSCALL_64_fastpath
20099124 ±162% -99.9% 10078 ±263% 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.entry_SYSCALL_64_fastpath
33.75 ±173% +2.2e+05% 73005 ±113% latency_stats.sum.pipe_write.__vfs_write.vfs_write.SyS_write.entry_SYSCALL_64_fastpath
0.00 ± -1% +Inf% 615502 ± 53% 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_kmem_pages_node.copy_process._do_fork.SyS_clone
0.00 ± -1% +Inf% 98280568 ± 12% 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% 301619 ± 56% 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_meta_page.[f2fs]
0.00 ± -1% +Inf% 481793 ± 63% 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.new_node_page.[f2fs]
0.00 ± -1% +Inf% 26057234 ± 5% 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
0.00 ± -1% +Inf% 101284 ± 93% 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.pte_alloc_one.__pte_alloc.handle_mm_fault
0.00 ± -1% +Inf% 333615 ± 52% 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_vma.handle_mm_fault.__do_page_fault.do_page_fault
0.00 ± -1% +Inf% 138162 ± 93% 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_vma.wp_page_copy.do_wp_page.handle_mm_fault
13154 ± 1% +23.4% 16233 ± 6% sched_debug.cfs_rq:/.exec_clock.0
8553 ± 0% +54.7% 13230 ± 6% sched_debug.cfs_rq:/.exec_clock.1
8198 ± 1% +51.5% 12425 ± 1% sched_debug.cfs_rq:/.exec_clock.2
8134 ± 1% +51.6% 12333 ± 1% sched_debug.cfs_rq:/.exec_clock.3
6757 ± 1% +23.1% 8318 ± 2% sched_debug.cfs_rq:/.exec_clock.4
6611 ± 1% +28.2% 8477 ± 2% sched_debug.cfs_rq:/.exec_clock.5
6746 ± 2% +23.9% 8357 ± 2% sched_debug.cfs_rq:/.exec_clock.6
6753 ± 2% +24.8% 8425 ± 1% sched_debug.cfs_rq:/.exec_clock.7
8113 ± 0% +35.3% 10975 ± 1% sched_debug.cfs_rq:/.exec_clock.avg
13154 ± 1% +24.5% 16373 ± 4% sched_debug.cfs_rq:/.exec_clock.max
6542 ± 1% +24.7% 8158 ± 1% sched_debug.cfs_rq:/.exec_clock.min
2058 ± 4% +41.6% 2913 ± 5% sched_debug.cfs_rq:/.exec_clock.stddev
72862 ± 1% +11.4% 81181 ± 3% sched_debug.cfs_rq:/.min_vruntime.5
5374 ± 3% -28.0% 3867 ± 16% sched_debug.cfs_rq:/.min_vruntime.stddev
-15402 ± -7% -52.8% -7264 ±-35% sched_debug.cfs_rq:/.spread0.4
-16718 ± -6% -61.4% -6457 ±-62% sched_debug.cfs_rq:/.spread0.5
-15098 ± -7% -63.1% -5565 ±-67% sched_debug.cfs_rq:/.spread0.7
-11694 ± -4% -50.9% -5743 ±-55% sched_debug.cfs_rq:/.spread0.avg
-17636 ± -4% -34.4% -11575 ±-32% sched_debug.cfs_rq:/.spread0.min
5375 ± 3% -28.0% 3867 ± 16% sched_debug.cfs_rq:/.spread0.stddev
676391 ± 8% -47.7% 353495 ± 32% sched_debug.cpu.avg_idle.min
108056 ± 15% +92.1% 207595 ± 16% sched_debug.cpu.avg_idle.stddev
45103 ± 2% +21.1% 54620 ± 3% sched_debug.cpu.nr_load_updates.0
18846 ± 4% +70.1% 32053 ± 4% sched_debug.cpu.nr_load_updates.1
17706 ± 5% +52.2% 26944 ± 3% sched_debug.cpu.nr_load_updates.2
17047 ± 2% +56.1% 26602 ± 3% sched_debug.cpu.nr_load_updates.3
10781 ± 2% +25.4% 13521 ± 2% sched_debug.cpu.nr_load_updates.4
11231 ± 2% +25.5% 14091 ± 3% sched_debug.cpu.nr_load_updates.5
10556 ± 1% +26.0% 13300 ± 2% sched_debug.cpu.nr_load_updates.6
10601 ± 2% +27.7% 13541 ± 3% sched_debug.cpu.nr_load_updates.7
17734 ± 1% +37.2% 24335 ± 1% sched_debug.cpu.nr_load_updates.avg
45103 ± 2% +21.2% 54662 ± 3% sched_debug.cpu.nr_load_updates.max
10419 ± 1% +26.4% 13166 ± 1% sched_debug.cpu.nr_load_updates.min
10889 ± 3% +24.3% 13541 ± 3% sched_debug.cpu.nr_load_updates.stddev
230386 ± 11% +42.9% 329109 ± 8% sched_debug.cpu.nr_switches.0
202377 ± 8% +251.4% 711088 ± 4% sched_debug.cpu.nr_switches.1
171137 ± 19% +180.6% 480135 ± 8% sched_debug.cpu.nr_switches.2
203086 ± 18% +117.9% 442482 ± 6% sched_debug.cpu.nr_switches.3
83980 ± 6% +109.3% 175809 ± 14% sched_debug.cpu.nr_switches.4
89866 ± 11% +75.8% 158005 ± 7% sched_debug.cpu.nr_switches.5
83814 ± 10% +88.5% 158008 ± 10% sched_debug.cpu.nr_switches.6
85831 ± 14% +78.4% 153106 ± 13% sched_debug.cpu.nr_switches.7
143810 ± 1% +126.7% 325968 ± 3% sched_debug.cpu.nr_switches.avg
250243 ± 5% +184.3% 711514 ± 4% sched_debug.cpu.nr_switches.max
76332 ± 3% +87.6% 143189 ± 8% sched_debug.cpu.nr_switches.min
65017 ± 6% +198.8% 194260 ± 5% sched_debug.cpu.nr_switches.stddev
203.80 ± 36% +113.9% 436.00 ± 9% sched_debug.cpu.nr_uninterruptible.4
271442 ± 9% +36.5% 370389 ± 7% sched_debug.cpu.sched_count.0
202559 ± 8% +251.6% 712283 ± 4% sched_debug.cpu.sched_count.1
171330 ± 19% +180.8% 481155 ± 8% sched_debug.cpu.sched_count.2
203293 ± 18% +118.1% 443428 ± 6% sched_debug.cpu.sched_count.3
84236 ± 6% +110.5% 177352 ± 14% sched_debug.cpu.sched_count.4
90110 ± 11% +77.1% 159606 ± 7% sched_debug.cpu.sched_count.5
84044 ± 10% +89.9% 159621 ± 10% sched_debug.cpu.sched_count.6
86056 ± 14% +79.6% 154524 ± 13% sched_debug.cpu.sched_count.7
149134 ± 1% +122.8% 332295 ± 3% sched_debug.cpu.sched_count.avg
277382 ± 7% +158.6% 717324 ± 4% sched_debug.cpu.sched_count.max
76562 ± 3% +89.1% 144747 ± 8% sched_debug.cpu.sched_count.min
73405 ± 6% +167.7% 196494 ± 5% sched_debug.cpu.sched_count.stddev
93022 ± 14% +46.7% 136420 ± 10% sched_debug.cpu.sched_goidle.0
80762 ± 10% +310.6% 331612 ± 4% sched_debug.cpu.sched_goidle.1
65323 ± 24% +230.1% 215622 ± 9% sched_debug.cpu.sched_goidle.2
81365 ± 22% +142.9% 197613 ± 7% sched_debug.cpu.sched_goidle.3
24975 ± 10% +175.0% 68669 ± 17% sched_debug.cpu.sched_goidle.4
28091 ± 18% +113.2% 59878 ± 9% sched_debug.cpu.sched_goidle.5
25071 ± 17% +139.1% 59944 ± 12% sched_debug.cpu.sched_goidle.6
25926 ± 22% +122.1% 57579 ± 17% sched_debug.cpu.sched_goidle.7
53067 ± 1% +165.5% 140918 ± 4% sched_debug.cpu.sched_goidle.avg
103919 ± 6% +219.2% 331734 ± 4% sched_debug.cpu.sched_goidle.max
21303 ± 5% +146.7% 52553 ± 10% sched_debug.cpu.sched_goidle.min
30666 ± 6% +209.8% 95012 ± 5% sched_debug.cpu.sched_goidle.stddev
114436 ± 5% +504.9% 692179 ± 7% sched_debug.cpu.ttwu_count.0
85402 ± 9% +51.2% 129168 ± 8% sched_debug.cpu.ttwu_count.1
97257 ± 16% +34.8% 131088 ± 10% sched_debug.cpu.ttwu_count.2
77150 ± 10% +62.7% 125500 ± 8% sched_debug.cpu.ttwu_count.3
87047 ± 1% +107.1% 180272 ± 3% sched_debug.cpu.ttwu_count.avg
125384 ± 6% +452.1% 692194 ± 7% sched_debug.cpu.ttwu_count.max
57245 ± 8% +22.4% 70061 ± 8% sched_debug.cpu.ttwu_count.min
22286 ± 16% +775.5% 195117 ± 8% sched_debug.cpu.ttwu_count.stddev
65970 ± 1% +25.1% 82512 ± 3% sched_debug.cpu.ttwu_local.0
36267 ± 2% +19.0% 43155 ± 6% sched_debug.cpu.ttwu_local.1
36396 ± 3% +17.8% 42878 ± 8% sched_debug.cpu.ttwu_local.2
36182 ± 3% +15.9% 41920 ± 5% sched_debug.cpu.ttwu_local.3
34843 ± 0% +14.8% 39990 ± 3% sched_debug.cpu.ttwu_local.avg
65970 ± 1% +25.1% 82533 ± 3% sched_debug.cpu.ttwu_local.max
12737 ± 2% +38.6% 17657 ± 4% sched_debug.cpu.ttwu_local.stddev
nhm4: Nehalem
Memory: 4G
fsmark.time.system_time
120 ++--------------------------------------------------------------------+
| O |
115 ++ OOOO O O O |
| O O OOO O O O |
| OO OO OO OO O O O O O O |
110 +OO O O OO O O O O O |
O O O O |
105 ++ |
| * |
100 ++ :: *. * |
|**.*: **.** **. ** * ** .* * * **.** : ** * * *. *|
* * * * * * *** + * * + * : ** : :.* ***.* ** * *
95 ++ * * * * +: * |
| * |
90 ++--------------------------------------------------------------------+
fsmark.time.voluntary_context_switches
3e+06 ++----------------------------------------------------------------+
|O O O |
| O O OO O O O |
2.5e+06 O+O OO O OO O O O O OO O O |
| O O O O OO O OO O OOO O O |
| O O O O O |
2e+06 ++ |
| |
1.5e+06 ++ |
| |
| |
1e+06 ++ |
****.*******.********.*******.*******.*******.********.*******.****
| |
500000 ++----------------------------------------------------------------+
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:
default-watchdogs:
oom-killer:
watchdog:
commit: 974b5afbf16ecd3e01cefd5d52e3090b6d967693
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:
fsmark:
filesize: 16MB
test_size: 60G
sync_method: fsyncBeforeClose
nr_directories: 16d
nr_files_per_directory: 256fpd
queue: bisect
testbox: nhm4
tbox_group: nhm4
kconfig: x86_64-rhel
enqueue_time: 2016-02-10 15:11:15.543683635 +08:00
compiler: gcc-4.9
rootfs: debian-x86_64-2015-02-07.cgz
id: f4fa0b2b0d60f3cbc15108e26ade977e01dedf0a
user: lkp
head_commit: c06a2a7722d2e55368aabf0ca1ed44092a57a9ed
base_commit: 388f7b1d6e8ca06762e2454d28d6c3c55ad0fe95
branch: linux-next/master
result_root: "/result/fsmark/1x-32t-1HDD-f2fs-16MB-60G-fsyncBeforeClose-16d-256fpd/nhm4/debian-x86_64-2015-02-07.cgz/x86_64-rhel/gcc-4.9/974b5afbf16ecd3e01cefd5d52e3090b6d967693/0"
job_file: "/lkp/scheduled/nhm4/bisect_fsmark-1x-32t-1HDD-f2fs-16MB-60G-fsyncBeforeClose-16d-256fpd-debian-x86_64-2015-02-07.cgz-x86_64-rhel-974b5afbf16ecd3e01cefd5d52e3090b6d967693-20160210-69915-wscxbo-0.yaml"
max_uptime: 1636.8999999999999
initrd: "/osimage/debian/debian-x86_64-2015-02-07.cgz"
bootloader_append:
- root=/dev/ram0
- user=lkp
- job=/lkp/scheduled/nhm4/bisect_fsmark-1x-32t-1HDD-f2fs-16MB-60G-fsyncBeforeClose-16d-256fpd-debian-x86_64-2015-02-07.cgz-x86_64-rhel-974b5afbf16ecd3e01cefd5d52e3090b6d967693-20160210-69915-wscxbo-0.yaml
- ARCH=x86_64
- kconfig=x86_64-rhel
- branch=linux-next/master
- commit=974b5afbf16ecd3e01cefd5d52e3090b6d967693
- BOOT_IMAGE=/pkg/linux/x86_64-rhel/gcc-4.9/974b5afbf16ecd3e01cefd5d52e3090b6d967693/vmlinuz-4.5.0-rc2-00261-g974b5af
- max_uptime=1636
- RESULT_ROOT=/result/fsmark/1x-32t-1HDD-f2fs-16MB-60G-fsyncBeforeClose-16d-256fpd/nhm4/debian-x86_64-2015-02-07.cgz/x86_64-rhel/gcc-4.9/974b5afbf16ecd3e01cefd5d52e3090b6d967693/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/974b5afbf16ecd3e01cefd5d52e3090b6d967693/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/974b5afbf16ecd3e01cefd5d52e3090b6d967693/linux-headers.cgz"
repeat_to: 5
kernel: "/pkg/linux/x86_64-rhel/gcc-4.9/974b5afbf16ecd3e01cefd5d52e3090b6d967693/vmlinuz-4.5.0-rc2-00261-g974b5af"
dequeue_time: 2016-02-10 16:31:50.889688281 +08:00
job_state: finished
loadavg: 32.16 26.33 13.46 1/156 7259
start_time: '1455093140'
end_time: '1455093636'
version: "/lkp/lkp/.src-20160210-100108"
Attachment:
reproduce.sh
Description: Bourne shell script