| 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
| ||
|
Message-ID: <874mj3c9qw.fsf@yhuang-dev.intel.com>
Date: Thu, 10 Sep 2015 10:02:15 +0800
From: kernel test robot <ying.huang@...el.com>
TO: Konstantin Khlebnikov <khlebnikov@...dex-team.ru>
CC: Ingo Molnar <mingo@...nel.org>
Subject: [lkp] [sched/preempt] fe32d3cd5e: -5.0% fsmark.files_per_sec
FYI, we noticed the below changes on
https://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git master
commit fe32d3cd5e8eb0f82e459763374aa80797023403 ("sched/preempt: Fix cond_resched_lock() and cond_resched_softirq()")
=========================================================================================
tbox_group/testcase/rootfs/kconfig/compiler/cpufreq_governor/iterations/nr_threads/disk/fs/fs2/filesize/test_size/sync_method/nr_directories/nr_files_per_directory:
nhm4/fsmark/debian-x86_64-2015-02-07.cgz/x86_64-rhel/gcc-4.9/performance/1x/32t/1HDD/f2fs/nfsv4/5K/400M/fsyncBeforeClose/16d/256fpd
commit:
c56dadf39761a6157239cac39e3988998c994f98
fe32d3cd5e8eb0f82e459763374aa80797023403
c56dadf39761a615 fe32d3cd5e8eb0f82e45976337
---------------- --------------------------
%stddev %change %stddev
\ | \
24905032 ± 2% -23.3% 19104197 ± 2% fsmark.app_overhead
128.00 ± 0% -5.0% 121.60 ± 0% fsmark.files_per_sec
640.73 ± 0% +5.6% 676.69 ± 0% fsmark.time.elapsed_time
640.73 ± 0% +5.6% 676.69 ± 0% fsmark.time.elapsed_time.max
88485 ± 0% +14.6% 101386 ± 0% fsmark.time.involuntary_context_switches
374807 ± 0% -2.8% 364148 ± 0% fsmark.time.voluntary_context_switches
88485 ± 0% +14.6% 101386 ± 0% time.involuntary_context_switches
18539 ± 1% -11.8% 16345 ± 1% slabinfo.kmalloc-128.active_objs
19786 ± 1% -10.7% 17675 ± 1% slabinfo.kmalloc-128.num_objs
4.23e+08 ± 1% +19.2% 5.042e+08 ± 3% cpuidle.C1-NHM.time
84188847 ± 1% +22.9% 1.034e+08 ± 1% cpuidle.C1E-NHM.time
85925 ± 0% +21.8% 104644 ± 0% cpuidle.C1E-NHM.usage
1.81 ± 0% -5.4% 1.71 ± 0% turbostat.%Busy
53.00 ± 0% -5.7% 50.00 ± 0% turbostat.Avg_MHz
19.57 ± 1% +11.1% 21.73 ± 2% turbostat.CPU%c1
1589 ± 0% -5.0% 1510 ± 0% vmstat.io.bo
22835 ± 0% -3.8% 21965 ± 0% vmstat.system.cs
7892 ± 0% -5.7% 7445 ± 0% vmstat.system.in
75995 ± 0% +10.1% 83680 ± 0% latency_stats.avg.rpc_wait_bit_killable.__rpc_wait_for_completion_task.nfs4_run_open_task.[nfsv4]._nfs4_open_and_get_state.[nfsv4].nfs4_do_open.[nfsv4].nfs4_atomic_open.[nfsv4].nfs_atomic_open.path_openat.do_filp_open.do_sys_open.SyS_open.entry_SYSCALL_64_fastpath
370488 ± 65% -48.0% 192671 ± 8% latency_stats.max.wait_on_page_bit.filemap_fdatawait_range.filemap_write_and_wait_range.nfs4_file_fsync.[nfsv4].vfs_fsync_range.do_fsync.SyS_fsync.entry_SYSCALL_64_fastpath
1353699 ± 0% +4.2% 1410361 ± 0% latency_stats.sum.do_wait.SyS_wait4.entry_SYSCALL_64_fastpath
2451859 ± 1% +4.4% 2559496 ± 0% latency_stats.sum.pipe_wait.pipe_read.__vfs_read.vfs_read.SyS_read.entry_SYSCALL_64_fastpath
18995177 ± 4% -26.9% 13876200 ± 1% latency_stats.sum.rpc_wait_bit_killable.__rpc_execute.rpc_execute.rpc_run_task.nfs4_call_sync_sequence.[nfsv4]._nfs4_proc_lookup.[nfsv4].nfs4_proc_lookup_common.[nfsv4].nfs4_proc_lookup.[nfsv4].nfs_lookup_revalidate.nfs4_lookup_revalidate.lookup_dcache.__lookup_hash
5.941e+09 ± 0% +2.9% 6.116e+09 ± 0% latency_stats.sum.rpc_wait_bit_killable.__rpc_wait_for_completion_task.nfs4_do_close.[nfsv4].__nfs4_close.[nfsv4].nfs4_close_sync.[nfsv4].nfs4_close_context.[nfsv4].__put_nfs_open_context.nfs_release.nfs_file_release.__fput.____fput.task_work_run
6.257e+09 ± 0% +10.1% 6.89e+09 ± 0% latency_stats.sum.rpc_wait_bit_killable.__rpc_wait_for_completion_task.nfs4_run_open_task.[nfsv4]._nfs4_open_and_get_state.[nfsv4].nfs4_do_open.[nfsv4].nfs4_atomic_open.[nfsv4].nfs_atomic_open.path_openat.do_filp_open.do_sys_open.SyS_open.entry_SYSCALL_64_fastpath
4.633e+09 ± 0% +6.9% 4.951e+09 ± 0% latency_stats.sum.wait_on_page_bit.filemap_fdatawait_range.filemap_write_and_wait_range.nfs4_file_fsync.[nfsv4].vfs_fsync_range.do_fsync.SyS_fsync.entry_SYSCALL_64_fastpath
429.00 ± 10% -10.5% 384.00 ± 6% sched_debug.cfs_rq[0]:/.tg->runnable_avg
430.75 ± 10% -10.6% 385.25 ± 6% sched_debug.cfs_rq[1]:/.tg->runnable_avg
15.50 ± 5% +21.0% 18.75 ± 4% sched_debug.cfs_rq[2]:/.nr_spread_over
431.50 ± 10% -10.2% 387.50 ± 6% sched_debug.cfs_rq[2]:/.tg->runnable_avg
437.75 ± 10% -10.1% 393.75 ± 7% sched_debug.cfs_rq[4]:/.tg->runnable_avg
441.00 ± 9% -10.3% 395.75 ± 6% sched_debug.cfs_rq[5]:/.tg->runnable_avg
442.75 ± 9% -10.2% 397.75 ± 6% sched_debug.cfs_rq[6]:/.tg->runnable_avg
1888 ± 41% -55.4% 843.00 ± 39% sched_debug.cfs_rq[7]:/.blocked_load_avg
443.50 ± 9% -9.3% 402.25 ± 6% sched_debug.cfs_rq[7]:/.tg->runnable_avg
1916 ± 41% -54.9% 865.25 ± 39% sched_debug.cfs_rq[7]:/.tg_load_contrib
320180 ± 0% +9.7% 351102 ± 0% sched_debug.cpu#0.clock
320180 ± 0% +9.7% 351102 ± 0% sched_debug.cpu#0.clock_task
46298 ± 11% +20.5% 55770 ± 16% sched_debug.cpu#0.nr_load_updates
-3942 ± -2% -7.1% -3663 ± -1% sched_debug.cpu#0.nr_uninterruptible
320181 ± 0% +9.7% 351102 ± 0% sched_debug.cpu#1.clock
320181 ± 0% +9.7% 351102 ± 0% sched_debug.cpu#1.clock_task
320181 ± 0% +9.7% 351104 ± 0% sched_debug.cpu#2.clock
320181 ± 0% +9.7% 351104 ± 0% sched_debug.cpu#2.clock_task
418.25 ± 7% +35.0% 564.50 ± 0% sched_debug.cpu#2.nr_uninterruptible
320180 ± 0% +9.7% 351103 ± 0% sched_debug.cpu#3.clock
320180 ± 0% +9.7% 351103 ± 0% sched_debug.cpu#3.clock_task
43361 ± 0% +28.5% 55731 ± 21% sched_debug.cpu#3.nr_load_updates
503.00 ± 5% +16.1% 583.75 ± 3% sched_debug.cpu#3.nr_uninterruptible
60027 ± 0% +997.9% 659006 ±155% sched_debug.cpu#3.ttwu_local
320179 ± 0% +9.7% 351103 ± 0% sched_debug.cpu#4.clock
320179 ± 0% +9.7% 351103 ± 0% sched_debug.cpu#4.clock_task
3.50 ± 95% +135.7% 8.25 ± 51% sched_debug.cpu#4.cpu_load[2]
1090 ± 2% +13.7% 1239 ± 2% sched_debug.cpu#4.nr_uninterruptible
320178 ± 0% +9.7% 351087 ± 0% sched_debug.cpu#5.clock
320178 ± 0% +9.7% 351087 ± 0% sched_debug.cpu#5.clock_task
547.50 ± 3% -45.8% 296.75 ± 4% sched_debug.cpu#5.nr_uninterruptible
320178 ± 0% +9.7% 351105 ± 0% sched_debug.cpu#6.clock
320178 ± 0% +9.7% 351105 ± 0% sched_debug.cpu#6.clock_task
542.75 ± 2% -46.0% 293.25 ± 13% sched_debug.cpu#6.nr_uninterruptible
320182 ± 0% +9.7% 351104 ± 0% sched_debug.cpu#7.clock
320182 ± 0% +9.7% 351104 ± 0% sched_debug.cpu#7.clock_task
495.75 ± 3% -39.0% 302.50 ± 6% sched_debug.cpu#7.nr_uninterruptible
320182 ± 0% +9.7% 351105 ± 0% sched_debug.cpu_clk
320014 ± 0% +9.7% 350935 ± 0% sched_debug.ktime
320182 ± 0% +9.7% 351105 ± 0% sched_debug.sched_clk
=========================================================================================
tbox_group/testcase/rootfs/kconfig/compiler/cpufreq_governor/iterations/nr_threads/disk/fs/fs2/filesize/test_size/sync_method/nr_directories/nr_files_per_directory:
nhm4/fsmark/debian-x86_64-2015-02-07.cgz/x86_64-rhel/gcc-4.9/performance/1x/32t/1HDD/xfs/nfsv4/8K/400M/fsyncBeforeClose/16d/256fpd
commit:
c56dadf39761a6157239cac39e3988998c994f98
fe32d3cd5e8eb0f82e459763374aa80797023403
c56dadf39761a615 fe32d3cd5e8eb0f82e45976337
---------------- --------------------------
fail:runs %reproduction fail:runs
| | |
2:4 -50% :4 kmsg.Spurious_LAPIC_timer_interrupt_on_cpu
%stddev %change %stddev
\ | \
5006474 ± 0% +8.3% 5423397 ± 1% fsmark.app_overhead
55958 ± 0% +8.2% 60571 ± 0% fsmark.time.involuntary_context_switches
229728 ± 0% -1.8% 225635 ± 0% fsmark.time.voluntary_context_switches
2156965 ± 0% +15.7% 2495398 ± 0% latency_stats.sum.rpc_wait_bit_killable.__rpc_execute.rpc_execute.rpc_run_task.nfs4_call_sync_sequence.[nfsv4]._nfs4_proc_lookup.[nfsv4].nfs4_proc_lookup_common.[nfsv4].nfs4_proc_lookup.[nfsv4].nfs_lookup_revalidate.nfs4_lookup_revalidate.lookup_dcache.__lookup_hash
2481 ± 2% +10.1% 2731 ± 2% slabinfo.kmalloc-256.num_objs
5226 ± 8% -8.5% 4783 ± 4% slabinfo.vm_area_struct.active_objs
2584 ± 6% -21.8% 2021 ± 8% sched_debug.cfs_rq[2]:/.min_vruntime
-1883 ±-12% +38.9% -2614 ± -8% sched_debug.cfs_rq[2]:/.spread0
7666 ±165% -100.0% 0.00 ± -1% sched_debug.cfs_rq[4]:/.load
229.25 ±110% -100.0% 0.00 ± -1% sched_debug.cfs_rq[4]:/.runnable_load_avg
-2331 ± -9% +17.2% -2731 ± -6% sched_debug.cfs_rq[4]:/.spread0
437.25 ± 61% -100.0% 0.00 ± -1% sched_debug.cfs_rq[4]:/.utilization_load_avg
2091 ± 7% +22.3% 2558 ± 8% sched_debug.cfs_rq[5]:/.min_vruntime
-2376 ± -6% -12.6% -2077 ± -8% sched_debug.cfs_rq[5]:/.spread0
1537704 ± 96% -93.1% 105402 ± 33% sched_debug.cpu#7.nr_switches
1537765 ± 96% -93.1% 105462 ± 33% sched_debug.cpu#7.sched_count
756633 ± 98% -94.6% 41165 ± 43% sched_debug.cpu#7.sched_goidle
nhm4: Nehalem
Memory: 4G
fsmark.time.involuntary_context_switches
65000 ++------------------------------------------------------------------+
64000 ++ O |
O O O O O O O O O O O O O O O |
63000 ++ O |
62000 ++ |
| |
61000 ++ O O O O O
60000 ++ O O O |
59000 ++ |
| |
58000 ++ |
57000 ++ |
*..*.. .*. .*.. .* |
56000 ++ *. *..*. *..*..*.*..*..*..*..*..* |
55000 ++------------------------------------------------------------------+
fsmark.time.voluntary_context_switches
231000 ++-----------------------------------------------------------------+
| .*.. |
230000 ++ .*.*..*.. .* .*.*.. .* |
*..*. *..*. *.. .*. *..*. |
229000 ++ *. |
| |
228000 ++ |
| |
227000 ++ |
O |
226000 ++ O O |
| O O O O O O O O O O O O O O O
225000 ++ O O O O O O O |
| |
224000 ++-----------------------------------------------------------------+
[*] 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
View attachment "job.yaml" of type "text/plain" (3751 bytes)
View attachment "reproduce" of type "text/plain" (1355 bytes)
Powered by blists - more mailing lists