Messages in this thread | | | From | kernel test robot <> | Subject | [lkp] [f2fs] 974b5afbf1: +187.0% fsmark.time.voluntary_context_switches | Date | Sun, 14 Feb 2016 15:30:37 +0800 |
| |
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" [unhandled content-type:application/x-sh] | |