[lkp] [sched] ed4ab8ce76: +112.7% unixbench.score

From: kernel test robot
Date: Wed Jan 27 2016 - 21:03:21 EST

FYI, we noticed the below changes on

https://git.kernel.org/pub/scm/linux/kernel/git/mel/linux-balancenuma sched-disable-schedstats-v2r1
commit ed4ab8ce76b14db0f82f17d6bf20898532f24040 ("sched: Make schedstats a runtime tunable that is disabled by default")


=========================================================================================
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/5K/btrfs/1x/x86_64-rhel/16d/256fpd/32t/debian-x86_64-2015-02-07.cgz/fsyncBeforeClose/lkp-ne04/400M/fsmark

commit:
v4.5-rc1
ed4ab8ce76b14db0f82f17d6bf20898532f24040

v4.5-rc1 ed4ab8ce76b14db0f82f17d6bf
---------------- --------------------------
%stddev %change %stddev
\ | \
1473135 ± 4% -27.2% 1072149 ± 0% fsmark.app_overhead
351.48 ± 0% -2.4% 342.91 ± 0% fsmark.files_per_sec
3063192 ± 0% -4.5% 2926520 ± 1% fsmark.time.file_system_outputs
47561 ± 5% -71.1% 13740 ± 2% fsmark.time.involuntary_context_switches
10586 ± 0% -9.5% 9583 ± 0% fsmark.time.minor_page_faults
21.60 ± 16% -67.6% 7.00 ± 0% fsmark.time.percent_of_cpu_this_job_got
54.52 ± 3% -67.8% 17.54 ± 0% fsmark.time.system_time
1100909 ± 2% -52.8% 520080 ± 2% fsmark.time.voluntary_context_switches
4096 ± 2% -100.0% 0.00 ± 0% proc-vmstat.numa_pte_updates
393712 ± 17% -19.6% 316676 ± 1% numa-numastat.node1.local_node
393716 ± 17% -19.6% 316678 ± 1% numa-numastat.node1.numa_hit
2881 ± 15% -73.5% 762.80 ± 9% slabinfo.btrfs_trans_handle.active_objs
2895 ± 15% -73.7% 762.80 ± 9% slabinfo.btrfs_trans_handle.num_objs
47946 ± 6% -34.1% 31613 ± 0% softirqs.RCU
51042 ± 7% -37.0% 32159 ± 5% softirqs.SCHED
106261 ± 8% -22.8% 82065 ± 8% softirqs.TIMER
332.10 ± 15% -76.0% 79.70 ± 50% turbostat.Avg_MHz
20.95 ± 15% -72.5% 5.76 ± 50% turbostat.CPU%c1
6.73 ± 8% +260.6% 24.28 ± 7% turbostat.Pkg%pc3
10377 ± 1% -7.4% 9608 ± 1% vmstat.io.bo
12577 ± 2% -40.6% 7470 ± 1% vmstat.system.cs
1436 ± 2% -28.2% 1031 ± 0% vmstat.system.in
47561 ± 5% -71.1% 13740 ± 2% time.involuntary_context_switches
10586 ± 0% -9.5% 9583 ± 0% time.minor_page_faults
21.60 ± 16% -67.6% 7.00 ± 0% time.percent_of_cpu_this_job_got
54.52 ± 3% -67.8% 17.54 ± 0% time.system_time
0.75 ± 6% +14.2% 0.85 ± 4% time.user_time
1100909 ± 2% -52.8% 520080 ± 2% time.voluntary_context_switches
2.861e+08 ± 2% -81.1% 54100491 ± 11% cpuidle.C1-NHM.time
167488 ± 5% -75.3% 41433 ± 5% cpuidle.C1-NHM.usage
55038510 ± 6% -41.2% 32338858 ± 12% cpuidle.C1E-NHM.time
50732 ± 7% -22.4% 39376 ± 6% cpuidle.C1E-NHM.usage
3.415e+08 ± 1% -18.4% 2.788e+08 ± 3% cpuidle.C3-NHM.time
199101 ± 1% -12.3% 174545 ± 1% cpuidle.C3-NHM.usage
3.389e+08 ± 4% -74.3% 86968082 ± 7% cpuidle.POLL.time
352604 ± 4% -78.7% 74952 ± 6% cpuidle.POLL.usage
75411 ± 13% +15.1% 86761 ± 3% numa-vmstat.node0.nr_active_file
140558 ± 15% +23.0% 172844 ± 2% numa-vmstat.node0.nr_dirtied
818.00 ± 17% +27.2% 1040 ± 1% numa-vmstat.node0.nr_dirty
199274 ± 11% +16.2% 231531 ± 1% numa-vmstat.node0.nr_file_pages
122909 ± 10% +16.5% 143210 ± 0% numa-vmstat.node0.nr_inactive_file
24133 ± 13% +17.3% 28307 ± 1% numa-vmstat.node0.nr_slab_reclaimable
139704 ± 15% +23.0% 171771 ± 2% numa-vmstat.node0.nr_written
30848 ± 9% -43.8% 17343 ± 4% numa-vmstat.node1.nr_active_file
43238 ± 16% -69.9% 12996 ± 14% numa-vmstat.node1.nr_dirtied
316.70 ± 19% -67.7% 102.30 ± 22% numa-vmstat.node1.nr_dirty
103100 ± 6% -29.5% 72713 ± 2% numa-vmstat.node1.nr_file_pages
70905 ± 5% -22.9% 54635 ± 2% numa-vmstat.node1.nr_inactive_file
9936 ± 9% -33.4% 6622 ± 7% numa-vmstat.node1.nr_slab_reclaimable
42907 ± 16% -70.0% 12890 ± 14% numa-vmstat.node1.nr_written
313222 ± 7% -12.3% 274716 ± 2% numa-vmstat.node1.numa_hit
309494 ± 7% -12.5% 270899 ± 2% numa-vmstat.node1.numa_local
318673 ± 13% +15.0% 366549 ± 3% numa-meminfo.node0.Active
301654 ± 13% +15.0% 347052 ± 3% numa-meminfo.node0.Active(file)
3274 ± 17% +27.2% 4165 ± 1% numa-meminfo.node0.Dirty
797112 ± 11% +16.2% 926133 ± 1% numa-meminfo.node0.FilePages
495267 ± 10% +16.9% 578895 ± 1% numa-meminfo.node0.Inactive
491645 ± 10% +16.5% 572849 ± 0% numa-meminfo.node0.Inactive(file)
980996 ± 10% +15.0% 1127768 ± 1% numa-meminfo.node0.MemUsed
96537 ± 13% +17.3% 113231 ± 1% numa-meminfo.node0.SReclaimable
138003 ± 8% -40.5% 82163 ± 5% numa-meminfo.node1.Active
123397 ± 9% -43.8% 69374 ± 4% numa-meminfo.node1.Active(file)
1268 ± 19% -67.5% 411.80 ± 22% numa-meminfo.node1.Dirty
412410 ± 6% -29.5% 290854 ± 2% numa-meminfo.node1.FilePages
288842 ± 4% -23.4% 221309 ± 3% numa-meminfo.node1.Inactive
283626 ± 5% -22.9% 218545 ± 2% numa-meminfo.node1.Inactive(file)
523063 ± 5% -25.7% 388503 ± 3% numa-meminfo.node1.MemUsed
39748 ± 9% -33.3% 26492 ± 7% numa-meminfo.node1.SReclaimable
58456 ± 7% -21.7% 45747 ± 5% numa-meminfo.node1.Slab
73085 ± 0% -100.0% 0.00 ± -1% latency_stats.avg.wait_log_commit.[btrfs].btrfs_sync_log.[btrfs].btrfs_sync_file.[btrfs].vfs_fsync_range.do_fsync.SyS_fsync.entry_SYSCALL_64_fastpath
30118 ± 0% -100.0% 0.00 ± -1% latency_stats.avg.write_all_supers.[btrfs].write_ctree_super.[btrfs].btrfs_sync_log.[btrfs].btrfs_sync_file.[btrfs].vfs_fsync_range.do_fsync.SyS_fsync.entry_SYSCALL_64_fastpath
78833 ± 0% -100.0% 0.00 ± -1% latency_stats.hits.btrfs_start_ordered_extent.[btrfs].btrfs_wait_ordered_range.[btrfs].btrfs_sync_file.[btrfs].vfs_fsync_range.do_fsync.SyS_fsync.entry_SYSCALL_64_fastpath
10142 ± 1% -100.0% 0.00 ± -1% latency_stats.hits.btrfs_sync_log.[btrfs].btrfs_sync_file.[btrfs].vfs_fsync_range.do_fsync.SyS_fsync.entry_SYSCALL_64_fastpath
57499 ± 9% -100.0% 0.00 ± -1% latency_stats.hits.btrfs_tree_lock.[btrfs].btrfs_lock_root_node.[btrfs].btrfs_search_slot.[btrfs].btrfs_insert_empty_items.[btrfs].btrfs_new_inode.[btrfs].btrfs_create.[btrfs].vfs_create.path_openat.do_filp_open.do_sys_open.SyS_open.entry_SYSCALL_64_fastpath
56081 ± 8% -100.0% 0.00 ± -1% latency_stats.hits.btrfs_tree_lock.[btrfs].btrfs_lock_root_node.[btrfs].btrfs_search_slot.[btrfs].btrfs_insert_empty_items.[btrfs].insert_with_overflow.[btrfs].btrfs_insert_dir_item.[btrfs].btrfs_add_link.[btrfs].btrfs_create.[btrfs].vfs_create.path_openat.do_filp_open.do_sys_open
72520 ± 3% -100.0% 0.00 ± -1% latency_stats.hits.btrfs_tree_lock.[btrfs].btrfs_search_slot.[btrfs].btrfs_insert_empty_items.[btrfs].btrfs_new_inode.[btrfs].btrfs_create.[btrfs].vfs_create.path_openat.do_filp_open.do_sys_open.SyS_open.entry_SYSCALL_64_fastpath
41230 ± 48% -100.0% 0.00 ± -1% latency_stats.hits.btrfs_tree_lock.[btrfs].btrfs_search_slot.[btrfs].btrfs_insert_empty_items.[btrfs].insert_with_overflow.[btrfs].btrfs_insert_dir_item.[btrfs].btrfs_add_link.[btrfs].btrfs_create.[btrfs].vfs_create.path_openat.do_filp_open.do_sys_open.SyS_open
9324 ± 6% -100.0% 0.00 ± -1% latency_stats.hits.btrfs_tree_read_lock.[btrfs].btrfs_read_lock_root_node.[btrfs].btrfs_search_slot.[btrfs].btrfs_insert_empty_items.[btrfs].copy_items.[btrfs].btrfs_log_inode.[btrfs].btrfs_log_inode_parent.[btrfs].btrfs_log_dentry_safe.[btrfs].btrfs_sync_file.[btrfs].vfs_fsync_range.do_fsync.SyS_fsync
11745 ± 4% -100.0% 0.00 ± -1% latency_stats.hits.btrfs_tree_read_lock.[btrfs].btrfs_read_lock_root_node.[btrfs].btrfs_search_slot.[btrfs].btrfs_insert_empty_items.[btrfs].insert_with_overflow.[btrfs].btrfs_insert_dir_item.[btrfs].btrfs_add_link.[btrfs].btrfs_create.[btrfs].vfs_create.path_openat.do_filp_open.do_sys_open
10752 ± 5% -100.0% 0.00 ± -1% latency_stats.hits.btrfs_tree_read_lock.[btrfs].btrfs_read_lock_root_node.[btrfs].btrfs_search_slot.[btrfs].btrfs_lookup_xattr.[btrfs].__btrfs_getxattr.[btrfs].btrfs_xattr_handler_get.[btrfs].generic_getxattr.cap_inode_need_killpriv.security_inode_need_killpriv.dentry_needs_remove_privs.file_remove_privs.btrfs_file_write_iter.[btrfs]
18352 ± 89% -100.0% 0.00 ± -1% latency_stats.hits.btrfs_tree_read_lock.[btrfs].btrfs_search_slot.[btrfs].btrfs_lookup_dir_item.[btrfs].btrfs_lookup_dentry.[btrfs].btrfs_lookup.[btrfs].lookup_real.path_openat.do_filp_open.do_sys_open.SyS_open.entry_SYSCALL_64_fastpath
50807 ± 3% -100.0% 0.00 ± -1% latency_stats.hits.btrfs_tree_read_lock.[btrfs].btrfs_search_slot.[btrfs].btrfs_lookup_xattr.[btrfs].__btrfs_getxattr.[btrfs].btrfs_xattr_handler_get.[btrfs].generic_getxattr.cap_inode_need_killpriv.security_inode_need_killpriv.dentry_needs_remove_privs.file_remove_privs.btrfs_file_write_iter.[btrfs].__vfs_write
35878 ± 27% -100.0% 0.00 ± -1% latency_stats.hits.pipe_wait.pipe_read.__vfs_read.vfs_read.SyS_read.entry_SYSCALL_64_fastpath
79830 ± 0% -100.0% 0.00 ± -1% latency_stats.hits.wait_log_commit.[btrfs].btrfs_sync_log.[btrfs].btrfs_sync_file.[btrfs].vfs_fsync_range.do_fsync.SyS_fsync.entry_SYSCALL_64_fastpath
84552 ± 0% -100.0% 0.00 ± -1% latency_stats.hits.wait_on_page_bit.__filemap_fdatawait_range.filemap_fdatawait_range.btrfs_wait_ordered_range.[btrfs].btrfs_sync_file.[btrfs].vfs_fsync_range.do_fsync.SyS_fsync.entry_SYSCALL_64_fastpath
8386 ± 28% -100.0% 0.00 ± -1% latency_stats.max.btrfs_start_ordered_extent.[btrfs].btrfs_wait_ordered_range.[btrfs].btrfs_sync_file.[btrfs].vfs_fsync_range.do_fsync.SyS_fsync.entry_SYSCALL_64_fastpath
8798 ± 16% -100.0% 0.00 ± -1% latency_stats.max.wait_for_writer.[btrfs].btrfs_sync_log.[btrfs].btrfs_sync_file.[btrfs].vfs_fsync_range.do_fsync.SyS_fsync.entry_SYSCALL_64_fastpath
258437 ± 5% -100.0% 0.00 ± -1% latency_stats.max.wait_log_commit.[btrfs].btrfs_sync_log.[btrfs].btrfs_sync_file.[btrfs].vfs_fsync_range.do_fsync.SyS_fsync.entry_SYSCALL_64_fastpath
16354 ± 3% -100.0% 0.00 ± -1% latency_stats.max.wait_on_page_bit.__filemap_fdatawait_range.filemap_fdatawait_range.btrfs_wait_marked_extents.[btrfs].btrfs_sync_log.[btrfs].btrfs_sync_file.[btrfs].vfs_fsync_range.do_fsync.SyS_fsync.entry_SYSCALL_64_fastpath
1622499 ± 29% -100.0% 0.00 ± -1% latency_stats.max.wait_on_page_bit.__filemap_fdatawait_range.filemap_fdatawait_range.btrfs_wait_ordered_range.[btrfs].btrfs_sync_file.[btrfs].vfs_fsync_range.do_fsync.SyS_fsync.entry_SYSCALL_64_fastpath
173227 ± 12% -100.0% 0.00 ± -1% latency_stats.max.write_all_supers.[btrfs].write_ctree_super.[btrfs].btrfs_sync_log.[btrfs].btrfs_sync_file.[btrfs].vfs_fsync_range.do_fsync.SyS_fsync.entry_SYSCALL_64_fastpath
17461880 ± 5% -100.0% 0.00 ± -1% latency_stats.sum.btrfs_start_ordered_extent.[btrfs].btrfs_wait_ordered_range.[btrfs].btrfs_sync_file.[btrfs].vfs_fsync_range.do_fsync.SyS_fsync.entry_SYSCALL_64_fastpath
7972317 ± 1% -100.0% 0.00 ± -1% latency_stats.sum.btrfs_sync_log.[btrfs].btrfs_sync_file.[btrfs].vfs_fsync_range.do_fsync.SyS_fsync.entry_SYSCALL_64_fastpath
8859 ±100% -100.0% 0.00 ± -1% latency_stats.sum.btrfs_tree_lock.[btrfs].btrfs_lock_root_node.[btrfs].btrfs_search_slot.[btrfs].btrfs_insert_empty_items.[btrfs].alloc_reserved_file_extent.[btrfs].__btrfs_run_delayed_refs.[btrfs].btrfs_run_delayed_refs.[btrfs].btrfs_commit_transaction.[btrfs].btrfs_sync_file.[btrfs].vfs_fsync_range.do_fsync.SyS_fsync
6913 ± 43% -100.0% 0.00 ± -1% latency_stats.sum.btrfs_tree_lock.[btrfs].btrfs_lock_root_node.[btrfs].btrfs_search_slot.[btrfs].btrfs_insert_empty_items.[btrfs].btrfs_csum_file_blocks.[btrfs].copy_items.[btrfs].btrfs_log_inode.[btrfs].btrfs_log_inode_parent.[btrfs].btrfs_log_dentry_safe.[btrfs].btrfs_sync_file.[btrfs].vfs_fsync_range.do_fsync
229131 ± 21% -100.0% 0.00 ± -1% latency_stats.sum.btrfs_tree_lock.[btrfs].btrfs_lock_root_node.[btrfs].btrfs_search_slot.[btrfs].btrfs_insert_empty_items.[btrfs].btrfs_insert_delayed_items.[btrfs].btrfs_commit_inode_delayed_items.[btrfs].btrfs_log_inode.[btrfs].btrfs_log_inode_parent.[btrfs].btrfs_log_dentry_safe.[btrfs].btrfs_sync_file.[btrfs].vfs_fsync_range.do_fsync
1850677 ± 9% -100.0% 0.00 ± -1% latency_stats.sum.btrfs_tree_lock.[btrfs].btrfs_lock_root_node.[btrfs].btrfs_search_slot.[btrfs].btrfs_insert_empty_items.[btrfs].btrfs_new_inode.[btrfs].btrfs_create.[btrfs].vfs_create.path_openat.do_filp_open.do_sys_open.SyS_open.entry_SYSCALL_64_fastpath
65647 ± 10% -100.0% 0.00 ± -1% latency_stats.sum.btrfs_tree_lock.[btrfs].btrfs_lock_root_node.[btrfs].btrfs_search_slot.[btrfs].btrfs_insert_empty_items.[btrfs].copy_items.[btrfs].btrfs_log_inode.[btrfs].btrfs_log_inode_parent.[btrfs].btrfs_log_dentry_safe.[btrfs].btrfs_sync_file.[btrfs].vfs_fsync_range.do_fsync.SyS_fsync
1695583 ± 8% -100.0% 0.00 ± -1% latency_stats.sum.btrfs_tree_lock.[btrfs].btrfs_lock_root_node.[btrfs].btrfs_search_slot.[btrfs].btrfs_insert_empty_items.[btrfs].insert_with_overflow.[btrfs].btrfs_insert_dir_item.[btrfs].btrfs_add_link.[btrfs].btrfs_create.[btrfs].vfs_create.path_openat.do_filp_open.do_sys_open
212868 ± 50% -100.0% 0.00 ± -1% latency_stats.sum.btrfs_tree_lock.[btrfs].btrfs_lock_root_node.[btrfs].btrfs_search_slot.[btrfs].btrfs_insert_empty_items.[btrfs].insert_with_overflow.[btrfs].btrfs_insert_dir_item.[btrfs].btrfs_add_link.[btrfs].btrfs_mkdir.[btrfs].vfs_mkdir.SyS_mkdir.entry_SYSCALL_64_fastpath
12786 ± 12% -100.0% 0.00 ± -1% latency_stats.sum.btrfs_tree_lock.[btrfs].btrfs_lock_root_node.[btrfs].btrfs_search_slot.[btrfs].btrfs_truncate_inode_items.[btrfs].btrfs_log_inode.[btrfs].btrfs_log_inode_parent.[btrfs].btrfs_log_dentry_safe.[btrfs].btrfs_sync_file.[btrfs].vfs_fsync_range.do_fsync.SyS_fsync.entry_SYSCALL_64_fastpath
45005 ± 13% -100.0% 0.00 ± -1% latency_stats.sum.btrfs_tree_lock.[btrfs].btrfs_lock_root_node.[btrfs].btrfs_search_slot.[btrfs].drop_objectid_items.[btrfs].btrfs_log_inode.[btrfs].btrfs_log_inode_parent.[btrfs].btrfs_log_dentry_safe.[btrfs].btrfs_sync_file.[btrfs].vfs_fsync_range.do_fsync.SyS_fsync.entry_SYSCALL_64_fastpath
215659 ± 14% -100.0% 0.00 ± -1% latency_stats.sum.btrfs_tree_lock.[btrfs].btrfs_search_slot.[btrfs].btrfs_insert_empty_items.[btrfs].btrfs_insert_delayed_items.[btrfs].btrfs_commit_inode_delayed_items.[btrfs].btrfs_log_inode.[btrfs].btrfs_log_inode_parent.[btrfs].btrfs_log_dentry_safe.[btrfs].btrfs_sync_file.[btrfs].vfs_fsync_range.do_fsync.SyS_fsync
1367601 ± 4% -100.0% 0.00 ± -1% latency_stats.sum.btrfs_tree_lock.[btrfs].btrfs_search_slot.[btrfs].btrfs_insert_empty_items.[btrfs].btrfs_new_inode.[btrfs].btrfs_create.[btrfs].vfs_create.path_openat.do_filp_open.do_sys_open.SyS_open.entry_SYSCALL_64_fastpath
668316 ± 56% -100.0% 0.00 ± -1% latency_stats.sum.btrfs_tree_lock.[btrfs].btrfs_search_slot.[btrfs].btrfs_insert_empty_items.[btrfs].insert_with_overflow.[btrfs].btrfs_insert_dir_item.[btrfs].btrfs_add_link.[btrfs].btrfs_create.[btrfs].vfs_create.path_openat.do_filp_open.do_sys_open.SyS_open
271351 ± 6% -100.0% 0.00 ± -1% latency_stats.sum.btrfs_tree_lock.[btrfs].btrfs_search_slot.[btrfs].btrfs_lookup_inode.[btrfs].__btrfs_update_delayed_inode.[btrfs].btrfs_commit_inode_delayed_items.[btrfs].btrfs_log_inode.[btrfs].btrfs_log_inode_parent.[btrfs].btrfs_log_dentry_safe.[btrfs].btrfs_sync_file.[btrfs].vfs_fsync_range.do_fsync.SyS_fsync
93978 ± 8% -100.0% 0.00 ± -1% latency_stats.sum.btrfs_tree_read_lock.[btrfs].btrfs_read_lock_root_node.[btrfs].btrfs_search_forward.[btrfs].btrfs_log_inode.[btrfs].btrfs_log_inode_parent.[btrfs].btrfs_log_dentry_safe.[btrfs].btrfs_sync_file.[btrfs].vfs_fsync_range.do_fsync.SyS_fsync.entry_SYSCALL_64_fastpath
8958 ± 10% -100.0% 0.00 ± -1% latency_stats.sum.btrfs_tree_read_lock.[btrfs].btrfs_read_lock_root_node.[btrfs].btrfs_search_slot.[btrfs].btrfs_csum_file_blocks.[btrfs].copy_items.[btrfs].btrfs_log_inode.[btrfs].btrfs_log_inode_parent.[btrfs].btrfs_log_dentry_safe.[btrfs].btrfs_sync_file.[btrfs].vfs_fsync_range.do_fsync.SyS_fsync
21415 ± 12% -100.0% 0.00 ± -1% latency_stats.sum.btrfs_tree_read_lock.[btrfs].btrfs_read_lock_root_node.[btrfs].btrfs_search_slot.[btrfs].btrfs_insert_empty_items.[btrfs].btrfs_insert_delayed_items.[btrfs].btrfs_commit_inode_delayed_items.[btrfs].btrfs_log_inode.[btrfs].btrfs_log_inode_parent.[btrfs].btrfs_log_dentry_safe.[btrfs].btrfs_sync_file.[btrfs].vfs_fsync_range.do_fsync
235483 ± 5% -100.0% 0.00 ± -1% latency_stats.sum.btrfs_tree_read_lock.[btrfs].btrfs_read_lock_root_node.[btrfs].btrfs_search_slot.[btrfs].btrfs_insert_empty_items.[btrfs].btrfs_new_inode.[btrfs].btrfs_create.[btrfs].vfs_create.path_openat.do_filp_open.do_sys_open.SyS_open.entry_SYSCALL_64_fastpath
98497 ± 8% -100.0% 0.00 ± -1% latency_stats.sum.btrfs_tree_read_lock.[btrfs].btrfs_read_lock_root_node.[btrfs].btrfs_search_slot.[btrfs].btrfs_insert_empty_items.[btrfs].copy_items.[btrfs].btrfs_log_inode.[btrfs].btrfs_log_inode_parent.[btrfs].btrfs_log_dentry_safe.[btrfs].btrfs_sync_file.[btrfs].vfs_fsync_range.do_fsync.SyS_fsync
314718 ± 5% -100.0% 0.00 ± -1% latency_stats.sum.btrfs_tree_read_lock.[btrfs].btrfs_read_lock_root_node.[btrfs].btrfs_search_slot.[btrfs].btrfs_insert_empty_items.[btrfs].insert_with_overflow.[btrfs].btrfs_insert_dir_item.[btrfs].btrfs_add_link.[btrfs].btrfs_create.[btrfs].vfs_create.path_openat.do_filp_open.do_sys_open
108828 ± 8% -100.0% 0.00 ± -1% latency_stats.sum.btrfs_tree_read_lock.[btrfs].btrfs_read_lock_root_node.[btrfs].btrfs_search_slot.[btrfs].btrfs_log_inode.[btrfs].btrfs_log_inode_parent.[btrfs].btrfs_log_dentry_safe.[btrfs].btrfs_sync_file.[btrfs].vfs_fsync_range.do_fsync.SyS_fsync.entry_SYSCALL_64_fastpath
51098 ± 4% -100.0% 0.00 ± -1% latency_stats.sum.btrfs_tree_read_lock.[btrfs].btrfs_read_lock_root_node.[btrfs].btrfs_search_slot.[btrfs].btrfs_lookup_csum.[btrfs].btrfs_csum_file_blocks.[btrfs].copy_items.[btrfs].btrfs_log_inode.[btrfs].btrfs_log_inode_parent.[btrfs].btrfs_log_dentry_safe.[btrfs].btrfs_sync_file.[btrfs].vfs_fsync_range.do_fsync
175287 ± 7% -100.0% 0.00 ± -1% latency_stats.sum.btrfs_tree_read_lock.[btrfs].btrfs_read_lock_root_node.[btrfs].btrfs_search_slot.[btrfs].btrfs_lookup_dir_item.[btrfs].btrfs_lookup_dentry.[btrfs].btrfs_lookup.[btrfs].lookup_real.path_openat.do_filp_open.do_sys_open.SyS_open.entry_SYSCALL_64_fastpath
118581 ± 9% -100.0% 0.00 ± -1% latency_stats.sum.btrfs_tree_read_lock.[btrfs].btrfs_read_lock_root_node.[btrfs].btrfs_search_slot.[btrfs].btrfs_lookup_inode.[btrfs].__btrfs_update_delayed_inode.[btrfs].btrfs_commit_inode_delayed_items.[btrfs].btrfs_log_inode.[btrfs].btrfs_log_inode_parent.[btrfs].btrfs_log_dentry_safe.[btrfs].btrfs_sync_file.[btrfs].vfs_fsync_range.do_fsync
257043 ± 6% -100.0% 0.00 ± -1% latency_stats.sum.btrfs_tree_read_lock.[btrfs].btrfs_read_lock_root_node.[btrfs].btrfs_search_slot.[btrfs].btrfs_lookup_xattr.[btrfs].__btrfs_getxattr.[btrfs].btrfs_xattr_handler_get.[btrfs].generic_getxattr.cap_inode_need_killpriv.security_inode_need_killpriv.dentry_needs_remove_privs.file_remove_privs.btrfs_file_write_iter.[btrfs]
42705 ± 5% -100.0% 0.00 ± -1% latency_stats.sum.btrfs_tree_read_lock.[btrfs].btrfs_read_lock_root_node.[btrfs].btrfs_search_slot.[btrfs].btrfs_truncate_inode_items.[btrfs].btrfs_log_inode.[btrfs].btrfs_log_inode_parent.[btrfs].btrfs_log_dentry_safe.[btrfs].btrfs_sync_file.[btrfs].vfs_fsync_range.do_fsync.SyS_fsync.entry_SYSCALL_64_fastpath
66105 ± 8% -100.0% 0.00 ± -1% latency_stats.sum.btrfs_tree_read_lock.[btrfs].btrfs_read_lock_root_node.[btrfs].btrfs_search_slot.[btrfs].drop_objectid_items.[btrfs].btrfs_log_inode.[btrfs].btrfs_log_inode_parent.[btrfs].btrfs_log_dentry_safe.[btrfs].btrfs_sync_file.[btrfs].vfs_fsync_range.do_fsync.SyS_fsync.entry_SYSCALL_64_fastpath
56090 ± 7% -100.0% 0.00 ± -1% latency_stats.sum.btrfs_tree_read_lock.[btrfs].btrfs_search_forward.[btrfs].btrfs_log_inode.[btrfs].btrfs_log_inode_parent.[btrfs].btrfs_log_dentry_safe.[btrfs].btrfs_sync_file.[btrfs].vfs_fsync_range.do_fsync.SyS_fsync.entry_SYSCALL_64_fastpath
43378 ± 13% -100.0% 0.00 ± -1% latency_stats.sum.btrfs_tree_read_lock.[btrfs].btrfs_search_slot.[btrfs].btrfs_log_inode.[btrfs].btrfs_log_inode_parent.[btrfs].btrfs_log_dentry_safe.[btrfs].btrfs_sync_file.[btrfs].vfs_fsync_range.do_fsync.SyS_fsync.entry_SYSCALL_64_fastpath
377987 ± 89% -100.0% 0.00 ± -1% latency_stats.sum.btrfs_tree_read_lock.[btrfs].btrfs_search_slot.[btrfs].btrfs_lookup_dir_item.[btrfs].btrfs_lookup_dentry.[btrfs].btrfs_lookup.[btrfs].lookup_real.path_openat.do_filp_open.do_sys_open.SyS_open.entry_SYSCALL_64_fastpath
889722 ± 3% -100.0% 0.00 ± -1% latency_stats.sum.btrfs_tree_read_lock.[btrfs].btrfs_search_slot.[btrfs].btrfs_lookup_xattr.[btrfs].__btrfs_getxattr.[btrfs].btrfs_xattr_handler_get.[btrfs].generic_getxattr.cap_inode_need_killpriv.security_inode_need_killpriv.dentry_needs_remove_privs.file_remove_privs.btrfs_file_write_iter.[btrfs].__vfs_write
1588928 ± 30% -100.0% 0.00 ± -1% latency_stats.sum.do_wait.SyS_wait4.entry_SYSCALL_64_fastpath
10889 ± 29% -100.0% 0.00 ± -1% latency_stats.sum.ep_poll.SyS_epoll_wait.entry_SYSCALL_64_fastpath
2505908 ± 31% -100.0% 0.00 ± -1% latency_stats.sum.pipe_wait.pipe_read.__vfs_read.vfs_read.SyS_read.entry_SYSCALL_64_fastpath
19734 ± 7% -100.0% 0.00 ± -1% latency_stats.sum.pipe_wait.wait_for_partner.fifo_open.do_dentry_open.vfs_open.path_openat.do_filp_open.do_sys_open.SyS_open.entry_SYSCALL_64_fastpath
393857 ± 14% -100.0% 0.00 ± -1% latency_stats.sum.wait_for_writer.[btrfs].btrfs_sync_log.[btrfs].btrfs_sync_file.[btrfs].vfs_fsync_range.do_fsync.SyS_fsync.entry_SYSCALL_64_fastpath
5.835e+09 ± 0% -100.0% 0.00 ± -1% latency_stats.sum.wait_log_commit.[btrfs].btrfs_sync_log.[btrfs].btrfs_sync_file.[btrfs].vfs_fsync_range.do_fsync.SyS_fsync.entry_SYSCALL_64_fastpath
23983772 ± 0% -100.0% 0.00 ± -1% latency_stats.sum.wait_on_page_bit.__filemap_fdatawait_range.filemap_fdatawait_range.btrfs_wait_marked_extents.[btrfs].btrfs_sync_log.[btrfs].btrfs_sync_file.[btrfs].vfs_fsync_range.do_fsync.SyS_fsync.entry_SYSCALL_64_fastpath
7.308e+08 ± 4% -100.0% 0.00 ± -1% latency_stats.sum.wait_on_page_bit.__filemap_fdatawait_range.filemap_fdatawait_range.btrfs_wait_ordered_range.[btrfs].btrfs_sync_file.[btrfs].vfs_fsync_range.do_fsync.SyS_fsync.entry_SYSCALL_64_fastpath
1.384e+08 ± 0% -100.0% 0.00 ± -1% latency_stats.sum.write_all_supers.[btrfs].write_ctree_super.[btrfs].btrfs_sync_log.[btrfs].btrfs_sync_file.[btrfs].vfs_fsync_range.do_fsync.SyS_fsync.entry_SYSCALL_64_fastpath

=========================================================================================
compiler/kconfig/nr_task/rootfs/tbox_group/test/testcase:
gcc-4.9/x86_64-rhel/100%/debian-x86_64-2015-02-07.cgz/nhm-white2/context1/unixbench

commit:
v4.5-rc1
ed4ab8ce76b14db0f82f17d6bf20898532f24040

v4.5-rc1 ed4ab8ce76b14db0f82f17d6bf
---------------- --------------------------
%stddev %change %stddev
\ | \
1514 ± 0% +112.7% 3222 ± 0% unixbench.score
80462 ± 33% +1766.4% 1501718 ± 53% unixbench.time.involuntary_context_switches
388.27 ± 0% -3.2% 375.73 ± 0% unixbench.time.system_time
10.93 ± 1% +101.5% 22.03 ± 0% unixbench.time.user_time
60435954 ± 0% +109.5% 1.266e+08 ± 1% unixbench.time.voluntary_context_switches
906365 ± 2% +96.9% 1784406 ± 14% vmstat.system.cs
80462 ± 33% +1766.4% 1501718 ± 53% time.involuntary_context_switches
10.93 ± 1% +101.5% 22.03 ± 0% time.user_time
60435954 ± 0% +109.5% 1.266e+08 ± 1% time.voluntary_context_switches
1.209e+08 ± 0% -100.0% 0.00 ± -1% latency_stats.hits.pipe_wait.pipe_read.__vfs_read.vfs_read.SyS_read.entry_SYSCALL_64_fastpath
233697 ± 4% -100.0% 0.00 ± -1% latency_stats.sum.do_wait.SyS_wait4.entry_SYSCALL_64_fastpath
31068 ± 11% -100.0% 0.00 ± -1% latency_stats.sum.ep_poll.SyS_epoll_wait.entry_SYSCALL_64_fastpath
2.42e+08 ± 0% -100.0% 0.00 ± -1% latency_stats.sum.pipe_wait.pipe_read.__vfs_read.vfs_read.SyS_read.entry_SYSCALL_64_fastpath
17252 ± 5% -100.0% 0.00 ± -1% latency_stats.sum.pipe_wait.wait_for_partner.fifo_open.do_dentry_open.vfs_open.path_openat.do_filp_open.do_sys_open.SyS_open.entry_SYSCALL_64_fastpath
1095198 ±296% -100.0% 0.00 ± -1% latency_stats.sum.wait_on_page_bit.__filemap_fdatawait_range.filemap_fdatawait_keep_errors.sync_inodes_sb.sync_inodes_one_sb.iterate_supers.sys_sync.entry_SYSCALL_64_fastpath


lkp-ne04: Nehalem-EP
Memory: 12G

nhm-white2: Nehalem
Memory: 4G

unixbench.time.system_time

390 ++--------------------------------------------------------------------+
388 *+*.*.. .*.*.*.*..*. *.*.*. .*.*.*.*.*..*.*.*. .*.*..*.*.*
| * *.*.*.*. + *. * |
386 ++ *..* |
384 ++ |
| |
382 ++ |
380 ++ |
378 ++ |
| O O O O |
376 O+ O O O O O O O O O O O |
374 ++ O O O O O O O |
| O |
372 ++ O |
370 ++--------------------------------------------------------------------+


unixbench.time.voluntary_context_switches

1.3e+08 ++------O----------------------------O---O---O----O---------------+
O O O O O O O O O O O O O O O O O O O |
1.2e+08 ++ O |
| |
1.1e+08 ++ |
| |
1e+08 ++ |
| |
9e+07 ++ |
| |
8e+07 ++ |
| |
7e+07 ++ |
| .*.*.*.*.*.*. |
6e+07 *+*-*-*-*-*-*-*--*-------------*-*-*-*-*-*-*-*-*--*-*-*-*-*-*-*-*-*

[*] bisect-good sample
[O] bisect-bad sample

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: unixbench
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: ed4ab8ce76b14db0f82f17d6bf20898532f24040
model: Nehalem
memory: 4G
nr_cpu: 8
hdd_partitions:
swap_partitions:
rootfs_partition:
netconsole_port: 6671
category: benchmark
nr_task: 100%
unixbench:
test: context1
queue: bisect
testbox: nhm-white2
tbox_group: nhm-white2
kconfig: x86_64-rhel
enqueue_time: 2016-01-27 10:25:46.000404539 +08:00
id: c44457b1715215c3f6591c13bfe6218597395559
user: lkp
compiler: gcc-4.9
head_commit: e7e6c6fba9b63d1c6d871e629cf69cda04fedeec
base_commit: 92e963f50fc74041b5e9e744c330dca48e04f08d
branch: linux-devel/devel-hourly-2016012622
rootfs: debian-x86_64-2015-02-07.cgz
result_root: "/result/unixbench/100%-context1/nhm-white2/debian-x86_64-2015-02-07.cgz/x86_64-rhel/gcc-4.9/ed4ab8ce76b14db0f82f17d6bf20898532f24040/0"
job_file: "/lkp/scheduled/nhm-white2/bisect_unixbench-100%-context1-debian-x86_64-2015-02-07.cgz-x86_64-rhel-ed4ab8ce76b14db0f82f17d6bf20898532f24040-20160127-17977-17yvzjm-0.yaml"
max_uptime: 959.52
initrd: "/osimage/debian/debian-x86_64-2015-02-07.cgz"
bootloader_append:
- root=/dev/ram0
- user=lkp
- job=/lkp/scheduled/nhm-white2/bisect_unixbench-100%-context1-debian-x86_64-2015-02-07.cgz-x86_64-rhel-ed4ab8ce76b14db0f82f17d6bf20898532f24040-20160127-17977-17yvzjm-0.yaml
- ARCH=x86_64
- kconfig=x86_64-rhel
- branch=linux-devel/devel-hourly-2016012622
- commit=ed4ab8ce76b14db0f82f17d6bf20898532f24040
- BOOT_IMAGE=/pkg/linux/x86_64-rhel/gcc-4.9/ed4ab8ce76b14db0f82f17d6bf20898532f24040/vmlinuz-4.5.0-rc1-00001-ged4ab8c
- max_uptime=959
- RESULT_ROOT=/result/unixbench/100%-context1/nhm-white2/debian-x86_64-2015-02-07.cgz/x86_64-rhel/gcc-4.9/ed4ab8ce76b14db0f82f17d6bf20898532f24040/0
- LKP_SERVER=inn
- |2-


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/ed4ab8ce76b14db0f82f17d6bf20898532f24040/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,/lkp/benchmarks/unixbench.cgz"
linux_headers_initrd: "/pkg/linux/x86_64-rhel/gcc-4.9/ed4ab8ce76b14db0f82f17d6bf20898532f24040/linux-headers.cgz"
repeat_to: 2
kernel: "/pkg/linux/x86_64-rhel/gcc-4.9/ed4ab8ce76b14db0f82f17d6bf20898532f24040/vmlinuz-4.5.0-rc1-00001-ged4ab8c"
dequeue_time: 2016-01-27 10:28:29.223400928 +08:00
job_state: finished
loadavg: 5.91 2.60 0.98 1/164 2889
start_time: '1453861733'
end_time: '1453861863'
version: "/lkp/lkp/.src-20160127-083800"

Attachment: reproduce.sh
Description: Bourne shell script