[lkp] [f2fs] b9d777b85f: No primary result change, +18023.3% 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

[kernel test robot]

FYI, we noticed the below changes on

https://git.kernel.org/pub/scm/linux/kernel/git/jaegeuk/f2fs dev-test
commit b9d777b85ff1ff79a1173190317b25bebc404ab4 ("f2fs: check inline_data flag at converting time")


=========================================================================================
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/NoSync/nhm4/60G/fsmark

commit: 
  74fd8d9927ef08db30a85f131a124152aeba66c7
  b9d777b85ff1ff79a1173190317b25bebc404ab4

74fd8d9927ef08db b9d777b85ff1ff79a117319031 
---------------- -------------------------- 
         %stddev     %change         %stddev
             \          |                \  
     10.00 ±  0%     -10.0%       9.00 ±  0%  fsmark.time.percent_of_cpu_this_job_got
     10.00 ±  0%     -10.0%       9.00 ±  0%  time.percent_of_cpu_this_job_got
      2.35 ±  0%      -3.7%       2.26 ±  0%  turbostat.%Busy
     67.30 ±  0%      -4.5%      64.30 ±  0%  turbostat.Avg_MHz
      2116 ±  1%     -98.7%      27.20 ±110%  proc-vmstat.kswapd_inodesteal
    191431 ±  0%     +18.2%     226316 ±  0%  proc-vmstat.slabs_scanned
     56566 ±  0%     +21.3%      68612 ±  0%  proc-vmstat.workingset_nodereclaim
   1176917 ±  2%    -100.0%       0.00 ± -1%  latency_stats.avg.call_rwsem_down_read_failed.f2fs_convert_inline_inode.[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.entry_SYSCALL_64_fastpath
     62312 ± 55%   +1577.8%    1045503 ± 11%  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
     11969 ±  8%    -100.0%       0.00 ± -1%  latency_stats.hits.call_rwsem_down_read_failed.get_node_info.[f2fs].read_node_page.[f2fs].get_node_page.[f2fs].f2fs_convert_inline_inode.[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
   1773702 ±  7%    -100.0%       0.00 ± -1%  latency_stats.max.call_rwsem_down_read_failed.f2fs_convert_inline_inode.[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.entry_SYSCALL_64_fastpath
 3.041e+08 ±  2%    -100.0%       0.00 ± -1%  latency_stats.sum.call_rwsem_down_read_failed.f2fs_convert_inline_inode.[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.entry_SYSCALL_64_fastpath
    163413 ±112%    +165.9%     434477 ±147%  latency_stats.sum.call_rwsem_down_read_failed.f2fs_wait_on_page_writeback.[f2fs].f2fs_wait_on_page_writeback.[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
    788095 ±164%     -60.4%     312194 ±122%  latency_stats.sum.call_rwsem_down_read_failed.f2fs_wait_on_page_writeback.[f2fs].f2fs_wait_on_page_writeback.[f2fs].update_inode.[f2fs].sync_inode_page.[f2fs].reserve_new_block.[f2fs].f2fs_reserve_block.[f2fs].f2fs_get_block.[f2fs].f2fs_write_begin.[f2fs].generic_perform_write.__generic_file_write_iter.generic_file_write_iter
   1743538 ± 56%  +18023.3%   3.16e+08 ±  3%  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
   1677147 ±  9%    -100.0%       0.00 ± -1%  latency_stats.sum.call_rwsem_down_read_failed.get_node_info.[f2fs].read_node_page.[f2fs].get_node_page.[f2fs].f2fs_convert_inline_inode.[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


nhm4: Nehalem
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,
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: b9d777b85ff1ff79a1173190317b25bebc404ab4
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: NoSync
  nr_directories: 16d
  nr_files_per_directory: 256fpd
queue: bisect
testbox: nhm4
tbox_group: nhm4
kconfig: x86_64-rhel
enqueue_time: 2016-01-13 13:40:53.999524332 +08:00
id: fad21a04d3a1fea2a2eec0d7865b7d8bf476bb04
user: lkp
compiler: gcc-4.9
head_commit: 4022f6842ee9752455523cf36ad93f8fc3b5fb90
base_commit: afd2ff9b7e1b367172f18ba7f693dfb62bdcb2dc
branch: linux-devel/devel-hourly-2016011122
rootfs: debian-x86_64-2015-02-07.cgz
result_root: "/result/fsmark/1x-32t-1HDD-f2fs-16MB-60G-NoSync-16d-256fpd/nhm4/debian-x86_64-2015-02-07.cgz/x86_64-rhel/gcc-4.9/b9d777b85ff1ff79a1173190317b25bebc404ab4/0"
job_file: "/lkp/scheduled/nhm4/bisect_fsmark-1x-32t-1HDD-f2fs-16MB-60G-NoSync-16d-256fpd-debian-x86_64-2015-02-07.cgz-x86_64-rhel-b9d777b85ff1ff79a1173190317b25bebc404ab4-20160113-4082-zjwv0v-0.yaml"
max_uptime: 1606.06
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-NoSync-16d-256fpd-debian-x86_64-2015-02-07.cgz-x86_64-rhel-b9d777b85ff1ff79a1173190317b25bebc404ab4-20160113-4082-zjwv0v-0.yaml
- ARCH=x86_64
- kconfig=x86_64-rhel
- branch=linux-devel/devel-hourly-2016011122
- commit=b9d777b85ff1ff79a1173190317b25bebc404ab4
- BOOT_IMAGE=/pkg/linux/x86_64-rhel/gcc-4.9/b9d777b85ff1ff79a1173190317b25bebc404ab4/vmlinuz-4.4.0-rc3-00282-gb9d777b
- max_uptime=1606
- RESULT_ROOT=/result/fsmark/1x-32t-1HDD-f2fs-16MB-60G-NoSync-16d-256fpd/nhm4/debian-x86_64-2015-02-07.cgz/x86_64-rhel/gcc-4.9/b9d777b85ff1ff79a1173190317b25bebc404ab4/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/b9d777b85ff1ff79a1173190317b25bebc404ab4/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/b9d777b85ff1ff79a1173190317b25bebc404ab4/linux-headers.cgz"
repeat_to: 5
kernel: "/pkg/linux/x86_64-rhel/gcc-4.9/b9d777b85ff1ff79a1173190317b25bebc404ab4/vmlinuz-4.4.0-rc3-00282-gb9d777b"
dequeue_time: 2016-01-13 14:28:45.970392984 +08:00
job_state: finished
loadavg: 29.38 25.64 13.09 1/157 7034
start_time: '1452666554'
end_time: '1452667032'
version: "/lkp/lkp/.src-20160113-125011"

Attachment: reproduce.sh
Description: Bourne shell script