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>] [thread-next>] [day] [month] [year] [list]
Message-ID: <202503311019.7d50fa1b-lkp@intel.com>
Date: Mon, 31 Mar 2025 10:57:45 +0800
From: kernel test robot <oliver.sang@...el.com>
To: Mateusz Guzik <mjguzik@...il.com>
CC: <oe-lkp@...ts.linux.dev>, <lkp@...el.com>, <linux-kernel@...r.kernel.org>,
	Christian Brauner <brauner@...nel.org>, <oliver.sang@...el.com>
Subject: [linus:master] [wait]  84654c7f47:  reaim.jobs_per_min 3.0%
 regression



Hello,

kernel test robot noticed a 3.0% regression of reaim.jobs_per_min on:


commit: 84654c7f47307692d47ea914d01287c8c54b3532 ("wait: avoid spurious calls to prepare_to_wait_event() in ___wait_event()")
https://git.kernel.org/cgit/linux/kernel/git/torvalds/linux.git master

[still regression on linus/master      1a9239bb4253f9076b5b4b2a1a4e8d7defd77a95]
[still regreasion on linux-next/master db8da9da41bced445077925f8a886c776a47440c]

testcase: reaim
config: x86_64-rhel-9.4
compiler: gcc-12
test machine: 192 threads 2 sockets Intel(R) Xeon(R) Platinum 8468V  CPU @ 2.4GHz (Sapphire Rapids) with 384G memory
parameters:

	runtime: 300s
	nr_task: 100%
	disk: 1SSD
	fs: ext4
	test: disk
	cpufreq_governor: performance




If you fix the issue in a separate patch/commit (i.e. not just a new version of
the same patch/commit), kindly add following tags
| Reported-by: kernel test robot <oliver.sang@...el.com>
| Closes: https://lore.kernel.org/oe-lkp/202503311019.7d50fa1b-lkp@intel.com


Details are as below:
-------------------------------------------------------------------------------------------------->


The kernel config and materials to reproduce are available at:
https://download.01.org/0day-ci/archive/20250331/202503311019.7d50fa1b-lkp@intel.com

=========================================================================================
compiler/cpufreq_governor/disk/fs/kconfig/nr_task/rootfs/runtime/tbox_group/test/testcase:
  gcc-12/performance/1SSD/ext4/x86_64-rhel-9.4/100%/debian-12-x86_64-20240206.cgz/300s/igk-spr-2sp4/disk/reaim

commit: 
  46af8e2406 ("pipe: cache 2 pages instead of 1")
  84654c7f47 ("wait: avoid spurious calls to prepare_to_wait_event() in ___wait_event()")

46af8e2406c27cc2 84654c7f47307692d47ea914d01 
---------------- --------------------------- 
         %stddev     %change         %stddev
             \          |                \  
     20.32 ±  2%      -3.2       17.17        mpstat.cpu.all.sys%
     54.24 ±  2%     -11.8%      47.82 ±  3%  mpstat.max_utilization_pct
    178465 ± 12%     +26.3%     225351 ± 10%  sched_debug.cfs_rq:/.avg_vruntime.stddev
    178465 ± 12%     +26.3%     225351 ± 10%  sched_debug.cfs_rq:/.min_vruntime.stddev
     10320 ± 15%     +36.8%      14113 ±  6%  sched_debug.cpu.nr_switches.stddev
     75.63            +4.3%      78.87        iostat.cpu.idle
      2.05            -2.9%       1.99        iostat.cpu.iowait
     21.28 ±  2%     -14.8%      18.12        iostat.cpu.system
      1.04            -2.7%       1.01        iostat.cpu.user
      7205            -1.5%       7100        vmstat.io.bi
     42.24 ±  4%     -10.1%      37.99 ±  5%  vmstat.procs.r
    268438            -4.9%     255319        vmstat.system.cs
    176126            -3.0%     170917        vmstat.system.in
    463695            +5.7%     490115 ±  2%  proc-vmstat.nr_active_anon
   1309918            +2.1%    1337119        proc-vmstat.nr_file_pages
    269292            +9.9%     296064 ±  4%  proc-vmstat.nr_shmem
     65965            +1.0%      66627        proc-vmstat.nr_slab_reclaimable
    463695            +5.7%     490115 ±  2%  proc-vmstat.nr_zone_active_anon
 2.171e+08            -1.7%  2.134e+08        proc-vmstat.pgfault
    151.15 ±  2%     -14.3%     129.47        reaim.child_systime
      6.80            +2.2%       6.95        reaim.child_utime
    606391            -3.0%     588044        reaim.jobs_per_min
      3158            -3.0%       3062        reaim.jobs_per_min_child
    628950            -2.7%     611916        reaim.max_jobs_per_min
      1.90            +3.1%       1.96        reaim.parent_time
  50558551            -1.7%   49692848        reaim.time.file_system_outputs
   2051317            -8.8%    1871021        reaim.time.involuntary_context_switches
    164148            -8.4%     150417        reaim.time.major_page_faults
 2.155e+08            -1.7%  2.119e+08        reaim.time.minor_page_faults
      4004           -14.9%       3407        reaim.time.percent_of_cpu_this_job_got
     11615           -15.8%       9783        reaim.time.system_time
  34429088            -5.5%   32518423        reaim.time.voluntary_context_switches
 8.196e+09            -8.7%  7.481e+09        perf-stat.i.branch-instructions
      1.69 ±  2%      +0.1        1.78        perf-stat.i.branch-miss-rate%
 1.442e+08            -2.5%  1.405e+08        perf-stat.i.branch-misses
 1.015e+08            -2.3%   99100519        perf-stat.i.cache-misses
 5.171e+08            -3.6%  4.984e+08        perf-stat.i.cache-references
    272535            -5.0%     258840        perf-stat.i.context-switches
      3.31            -4.5%       3.16        perf-stat.i.cpi
 1.314e+11 ±  2%     -13.7%  1.134e+11        perf-stat.i.cpu-cycles
     31541           -11.9%      27772        perf-stat.i.cpu-migrations
      1274            -8.7%       1163        perf-stat.i.cycles-between-cache-misses
 3.997e+10            -8.6%  3.655e+10        perf-stat.i.instructions
      0.34            +4.0%       0.36        perf-stat.i.ipc
    542.30            -8.3%     497.24        perf-stat.i.major-faults
      8.47            -2.4%       8.27        perf-stat.i.metric.K/sec
    696934            -1.6%     685700        perf-stat.i.minor-faults
    697476            -1.6%     686197        perf-stat.i.page-faults
      0.02 ±  4%     -13.1%       0.01 ±  4%  perf-sched.sch_delay.avg.ms.__cond_resched.stop_one_cpu.sched_exec.bprm_execve.part
      0.02 ±  6%     -25.2%       0.02 ± 13%  perf-sched.sch_delay.avg.ms.anon_pipe_read.fifo_pipe_read.vfs_read.ksys_read
      0.02 ± 17%     -47.2%       0.01 ± 24%  perf-sched.sch_delay.avg.ms.schedule_hrtimeout_range.do_poll.constprop.0.do_sys_poll
      0.01 ± 38%    +134.3%       0.02 ± 29%  perf-sched.sch_delay.avg.ms.schedule_preempt_disabled.rwsem_down_write_slowpath.down_write.do_unlinkat
      0.01 ± 19%     +71.6%       0.01 ± 21%  perf-sched.sch_delay.avg.ms.wait_transaction_locked.add_transaction_credits.start_this_handle.jbd2__journal_start
      0.24 ± 38%    +558.1%       1.55 ± 98%  perf-sched.sch_delay.max.ms.__cond_resched.smpboot_thread_fn.kthread.ret_from_fork.ret_from_fork_asm
      1.42 ± 34%    +513.4%       8.72 ± 59%  perf-sched.sch_delay.max.ms.do_wait.kernel_wait4.do_syscall_64.entry_SYSCALL_64_after_hwframe
      2.44 ±213%    +966.4%      26.02 ± 31%  perf-sched.sch_delay.max.ms.io_schedule.bit_wait_io.__wait_on_bit.out_of_line_wait_on_bit
      1.23 ±186%    +833.2%      11.51 ± 74%  perf-sched.sch_delay.max.ms.io_schedule.bit_wait_io.__wait_on_bit_lock.out_of_line_wait_on_bit_lock
      2.54 ±196%    +700.3%      20.32 ± 25%  perf-sched.sch_delay.max.ms.io_schedule.folio_wait_bit_common.folio_wait_writeback.__filemap_fdatawait_range
      0.77 ± 78%   +1333.4%      10.99 ± 43%  perf-sched.sch_delay.max.ms.schedule_preempt_disabled.__mutex_lock.constprop.0.sync_bdevs
      2.42 ±235%   +1056.6%      27.94 ± 23%  perf-sched.sch_delay.max.ms.schedule_preempt_disabled.rwsem_down_write_slowpath.down_write.open_last_lookups
      3.76 ±217%    +668.9%      28.92 ± 23%  perf-sched.sch_delay.max.ms.schedule_timeout.__wait_for_common.wait_for_completion_state.kernel_clone
      2.76 ±210%    +925.0%      28.30 ± 30%  perf-sched.sch_delay.max.ms.wait_transaction_locked.add_transaction_credits.start_this_handle.jbd2__journal_start
      5.73 ±  4%     +16.7%       6.68 ±  3%  perf-sched.total_wait_and_delay.average.ms
    541419 ±  3%     +26.2%     683124 ±  7%  perf-sched.total_wait_and_delay.count.ms
      5.72 ±  4%     +16.6%       6.67 ±  3%  perf-sched.total_wait_time.average.ms
      0.02 ±  3%     -12.8%       0.02 ±  3%  perf-sched.wait_and_delay.avg.ms.__cond_resched.stop_one_cpu.sched_exec.bprm_execve.part
      0.09 ±  6%     -17.4%       0.07 ±  4%  perf-sched.wait_and_delay.avg.ms.do_task_dead.do_exit.do_group_exit.__x64_sys_exit_group.x64_sys_call
      1.54 ±  7%     +33.8%       2.06 ±  4%  perf-sched.wait_and_delay.avg.ms.io_schedule.folio_wait_bit_common.folio_wait_writeback.__filemap_fdatawait_range
      1.55 ±  8%     +53.9%       2.39 ±  7%  perf-sched.wait_and_delay.avg.ms.jbd2_log_wait_commit.ext4_sync_fs.iterate_supers.ksys_sync
    290.01 ± 17%     -64.0%     104.50 ±  6%  perf-sched.wait_and_delay.avg.ms.schedule_hrtimeout_range.do_poll.constprop.0.do_sys_poll
    182.38 ±  3%     +14.6%     208.99 ±  6%  perf-sched.wait_and_delay.avg.ms.schedule_hrtimeout_range.ep_poll.do_epoll_wait.__x64_sys_epoll_wait
      0.66 ± 23%     +34.4%       0.89 ±  4%  perf-sched.wait_and_delay.avg.ms.schedule_preempt_disabled.__mutex_lock.constprop.0.wait_sb_inodes
      4.16 ±  8%     +21.2%       5.04 ±  5%  perf-sched.wait_and_delay.avg.ms.schedule_preempt_disabled.rwsem_down_write_slowpath.down_write.do_unlinkat
     19.47 ±  8%     -25.2%      14.56 ±  5%  perf-sched.wait_and_delay.avg.ms.schedule_preempt_disabled.rwsem_down_write_slowpath.down_write.open_last_lookups
      2.50 ±  8%     +55.9%       3.89 ±  3%  perf-sched.wait_and_delay.avg.ms.schedule_timeout.__wait_for_common.__flush_workqueue.ext4_sync_fs
     30.55 ± 20%     +37.9%      42.14        perf-sched.wait_and_delay.avg.ms.worker_thread.kthread.ret_from_fork.ret_from_fork_asm
    146.67 ± 34%    +157.6%     377.82 ± 18%  perf-sched.wait_and_delay.count.__cond_resched.smpboot_thread_fn.kthread.ret_from_fork.ret_from_fork_asm
     18593           +25.0%      23245 ±  7%  perf-sched.wait_and_delay.count.__cond_resched.stop_one_cpu.sched_exec.bprm_execve.part
    379.25 ± 13%     -46.4%     203.09        perf-sched.wait_and_delay.count.__x64_sys_pause.do_syscall_64.entry_SYSCALL_64_after_hwframe.[unknown]
     38979           +34.8%      52534 ±  6%  perf-sched.wait_and_delay.count.do_task_dead.do_exit.do_group_exit.__x64_sys_exit_group.x64_sys_call
     38945           +34.4%      52357 ±  6%  perf-sched.wait_and_delay.count.do_wait.kernel_wait4.do_syscall_64.entry_SYSCALL_64_after_hwframe
     20923 ±  2%     +12.5%      23539 ±  6%  perf-sched.wait_and_delay.count.io_schedule.bit_wait_io.__wait_on_bit.out_of_line_wait_on_bit
      3951 ±  3%     +17.1%       4627 ±  8%  perf-sched.wait_and_delay.count.io_schedule.folio_wait_bit_common.filemap_fault.__do_fault
     35593 ±  2%     +40.6%      50040 ±  5%  perf-sched.wait_and_delay.count.io_schedule.folio_wait_bit_common.folio_wait_writeback.__filemap_fdatawait_range
    170.83 ± 45%     +51.1%     258.09 ± 10%  perf-sched.wait_and_delay.count.irqentry_exit_to_user_mode.asm_exc_page_fault.[unknown].[unknown]
     33097           +34.0%      44350 ±  6%  perf-sched.wait_and_delay.count.jbd2_log_wait_commit.ext4_sync_fs.iterate_supers.ksys_sync
    113.50 ±  6%     +68.1%     190.82 ±  6%  perf-sched.wait_and_delay.count.schedule_hrtimeout_range.do_poll.constprop.0.do_sys_poll
      8426 ±  3%     +85.5%      15629 ±  7%  perf-sched.wait_and_delay.count.schedule_preempt_disabled.__mutex_lock.constprop.0.sync_bdevs
     16359 ±  2%     +43.7%      23512 ±  6%  perf-sched.wait_and_delay.count.schedule_preempt_disabled.__mutex_lock.constprop.0.wait_sb_inodes
     12226 ±  2%     +22.8%      15015 ±  8%  perf-sched.wait_and_delay.count.schedule_preempt_disabled.rwsem_down_write_slowpath.down_write.do_unlinkat
      9463 ±  2%     +65.4%      15654 ±  8%  perf-sched.wait_and_delay.count.schedule_preempt_disabled.rwsem_down_write_slowpath.down_write.open_last_lookups
      8482 ±  4%     +28.0%      10855 ±  7%  perf-sched.wait_and_delay.count.schedule_timeout.__wait_for_common.__flush_workqueue.ext4_sync_fs
     38705           +34.4%      52015 ±  6%  perf-sched.wait_and_delay.count.schedule_timeout.__wait_for_common.wait_for_completion_state.kernel_clone
     43408           +33.0%      57748 ±  6%  perf-sched.wait_and_delay.count.schedule_timeout.io_schedule_timeout.__iomap_dio_rw.iomap_dio_rw
     33465           +18.7%      39708 ±  7%  perf-sched.wait_and_delay.count.smpboot_thread_fn.kthread.ret_from_fork.ret_from_fork_asm
     11081 ±  5%     +82.6%      20239 ±  7%  perf-sched.wait_and_delay.count.wait_transaction_locked.add_transaction_credits.start_this_handle.jbd2__journal_start
    422.12 ±133%    +241.6%       1441 ± 63%  perf-sched.wait_and_delay.max.ms.__cond_resched.smpboot_thread_fn.kthread.ret_from_fork.ret_from_fork_asm
      1513 ± 17%     +55.5%       2352        perf-sched.wait_and_delay.max.ms.smpboot_thread_fn.kthread.ret_from_fork.ret_from_fork_asm
      2101 ± 23%    +104.6%       4299 ±  3%  perf-sched.wait_and_delay.max.ms.worker_thread.kthread.ret_from_fork.ret_from_fork_asm
      2.80 ± 27%     +61.0%       4.50 ± 24%  perf-sched.wait_time.avg.ms.__cond_resched.flush_delayed_work.dquot_writeback_dquots.ext4_sync_fs.iterate_supers
      2.79 ±  7%     +75.9%       4.90 ±  6%  perf-sched.wait_time.avg.ms.__cond_resched.super_lock.iterate_supers.ksys_sync.__x64_sys_sync
      0.09 ±  6%     -17.4%       0.07 ±  4%  perf-sched.wait_time.avg.ms.do_task_dead.do_exit.do_group_exit.__x64_sys_exit_group.x64_sys_call
      1.53 ±  7%     +33.8%       2.05 ±  4%  perf-sched.wait_time.avg.ms.io_schedule.folio_wait_bit_common.folio_wait_writeback.__filemap_fdatawait_range
      0.72 ±  6%     -43.3%       0.41 ± 22%  perf-sched.wait_time.avg.ms.jbd2_journal_wait_updates.jbd2_journal_commit_transaction.kjournald2.kthread
      1.54 ±  8%     +53.9%       2.37 ±  7%  perf-sched.wait_time.avg.ms.jbd2_log_wait_commit.ext4_sync_fs.iterate_supers.ksys_sync
    289.99 ± 17%     -64.0%     104.49 ±  6%  perf-sched.wait_time.avg.ms.schedule_hrtimeout_range.do_poll.constprop.0.do_sys_poll
    182.35 ±  3%     +14.6%     208.96 ±  6%  perf-sched.wait_time.avg.ms.schedule_hrtimeout_range.ep_poll.do_epoll_wait.__x64_sys_epoll_wait
      0.65 ± 23%     +34.7%       0.87 ±  4%  perf-sched.wait_time.avg.ms.schedule_preempt_disabled.__mutex_lock.constprop.0.wait_sb_inodes
      4.15 ±  8%     +21.0%       5.02 ±  5%  perf-sched.wait_time.avg.ms.schedule_preempt_disabled.rwsem_down_write_slowpath.down_write.do_unlinkat
     19.46 ±  8%     -25.3%      14.53 ±  5%  perf-sched.wait_time.avg.ms.schedule_preempt_disabled.rwsem_down_write_slowpath.down_write.open_last_lookups
      2.49 ±  8%     +55.9%       3.88 ±  3%  perf-sched.wait_time.avg.ms.schedule_timeout.__wait_for_common.__flush_workqueue.ext4_sync_fs
      6.06 ±  2%      -8.9%       5.52 ±  4%  perf-sched.wait_time.avg.ms.schedule_timeout.rcu_gp_fqs_loop.rcu_gp_kthread.kthread
     30.51 ± 20%     +37.9%      42.09        perf-sched.wait_time.avg.ms.worker_thread.kthread.ret_from_fork.ret_from_fork_asm
     17.78 ± 15%    +523.0%     110.77 ±253%  perf-sched.wait_time.max.ms.__cond_resched.exit_mmap.__mmput.exit_mm.do_exit
    422.09 ±133%    +241.6%       1441 ± 63%  perf-sched.wait_time.max.ms.__cond_resched.smpboot_thread_fn.kthread.ret_from_fork.ret_from_fork_asm
     17.56 ±  8%     +37.2%      24.09 ± 10%  perf-sched.wait_time.max.ms.__cond_resched.super_lock.iterate_supers.ksys_sync.__x64_sys_sync
      1513 ± 17%     +55.5%       2352        perf-sched.wait_time.max.ms.smpboot_thread_fn.kthread.ret_from_fork.ret_from_fork_asm
      2101 ± 23%    +104.6%       4299 ±  3%  perf-sched.wait_time.max.ms.worker_thread.kthread.ret_from_fork.ret_from_fork_asm




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.


-- 
0-DAY CI Kernel Test Service
https://github.com/intel/lkp-tests/wiki


Powered by blists - more mailing lists

Powered by Openwall GNU/*/Linux Powered by OpenVZ