lists.openwall.net   lists  /  announce  owl-users  owl-dev  john-users  john-dev  passwdqc-users  yescrypt  popa3d-users  /  oss-security  kernel-hardening  musl  sabotage  tlsify  passwords  /  crypt-dev  xvendor  /  Bugtraq  Full-Disclosure  linux-kernel  linux-netdev  linux-ext4  linux-hardening  linux-cve-announce  PHC 
Open Source and information security mailing list archives
 
Hash Suite: Windows password security audit tool. GUI, reports in PDF.
[<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

Powered by Openwall GNU/*/Linux Powered by OpenVZ