* [linus:master] [fs] a914bd93f3: stress-ng.close.close_calls_per_sec 52.2% regression
@ 2025-04-17 8:23 kernel test robot
2025-04-17 9:54 ` Mateusz Guzik
0 siblings, 1 reply; 6+ messages in thread
From: kernel test robot @ 2025-04-17 8:23 UTC (permalink / raw)
To: Mateusz Guzik
Cc: oe-lkp, lkp, linux-kernel, Christian Brauner, linux-fsdevel, oliver.sang
Hello,
kernel test robot noticed a 52.2% regression of stress-ng.close.close_calls_per_sec on:
commit: a914bd93f3edfedcdd59deb615e8dd1b3643cac5 ("fs: use fput_close() in filp_close()")
https://git.kernel.org/cgit/linux/kernel/git/torvalds/linux.git master
[still regression on linus/master 7cdabafc001202de9984f22c973305f424e0a8b7]
[still regression on linux-next/master 01c6df60d5d4ae00cd5c1648818744838bba7763]
testcase: stress-ng
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:
nr_threads: 100%
testtime: 60s
test: close
cpufreq_governor: performance
the data is not very stable, but the regression trend seems clear.
a914bd93f3edfedcdd59deb615e8dd1b3643cac5/matrix.json: "stress-ng.close.close_calls_per_sec": [
a914bd93f3edfedcdd59deb615e8dd1b3643cac5/matrix.json- 193538.65,
a914bd93f3edfedcdd59deb615e8dd1b3643cac5/matrix.json- 232133.85,
a914bd93f3edfedcdd59deb615e8dd1b3643cac5/matrix.json- 276146.66,
a914bd93f3edfedcdd59deb615e8dd1b3643cac5/matrix.json- 193345.38,
a914bd93f3edfedcdd59deb615e8dd1b3643cac5/matrix.json- 209411.34,
a914bd93f3edfedcdd59deb615e8dd1b3643cac5/matrix.json- 254782.41
a914bd93f3edfedcdd59deb615e8dd1b3643cac5/matrix.json- ],
3e46a92a27c2927fcef996ba06cbe299da629c28/matrix.json: "stress-ng.close.close_calls_per_sec": [
3e46a92a27c2927fcef996ba06cbe299da629c28/matrix.json- 427893.13,
3e46a92a27c2927fcef996ba06cbe299da629c28/matrix.json- 456267.6,
3e46a92a27c2927fcef996ba06cbe299da629c28/matrix.json- 509121.02,
3e46a92a27c2927fcef996ba06cbe299da629c28/matrix.json- 544289.08,
3e46a92a27c2927fcef996ba06cbe299da629c28/matrix.json- 354004.06,
3e46a92a27c2927fcef996ba06cbe299da629c28/matrix.json- 552310.73
3e46a92a27c2927fcef996ba06cbe299da629c28/matrix.json- ],
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@intel.com>
| Closes: https://lore.kernel.org/oe-lkp/202504171513.6d6f8a16-lkp@intel.com
Details are as below:
-------------------------------------------------------------------------------------------------->
The kernel config and materials to reproduce are available at:
https://download.01.org/0day-ci/archive/20250417/202504171513.6d6f8a16-lkp@intel.com
=========================================================================================
compiler/cpufreq_governor/kconfig/nr_threads/rootfs/tbox_group/test/testcase/testtime:
gcc-12/performance/x86_64-rhel-9.4/100%/debian-12-x86_64-20240206.cgz/igk-spr-2sp1/close/stress-ng/60s
commit:
3e46a92a27 ("fs: use fput_close_sync() in close()")
a914bd93f3 ("fs: use fput_close() in filp_close()")
3e46a92a27c2927f a914bd93f3edfedcdd59deb615e
---------------- ---------------------------
%stddev %change %stddev
\ | \
355470 ± 14% -17.6% 292767 ± 7% cpuidle..usage
5.19 -0.6 4.61 ± 3% mpstat.cpu.all.usr%
495615 ± 7% -38.5% 304839 ± 8% vmstat.system.cs
780096 ± 5% -23.5% 596446 ± 3% vmstat.system.in
2512168 ± 17% -45.8% 1361659 ± 71% sched_debug.cfs_rq:/.avg_vruntime.min
2512168 ± 17% -45.8% 1361659 ± 71% sched_debug.cfs_rq:/.min_vruntime.min
700402 ± 2% +19.8% 838744 ± 10% sched_debug.cpu.avg_idle.avg
81230 ± 6% -59.6% 32788 ± 69% sched_debug.cpu.nr_switches.avg
27992 ± 20% -70.2% 8345 ± 74% sched_debug.cpu.nr_switches.min
473980 ± 14% -52.2% 226559 ± 13% stress-ng.close.close_calls_per_sec
4004843 ± 8% -21.1% 3161813 ± 8% stress-ng.time.involuntary_context_switches
9475 +1.1% 9582 stress-ng.time.system_time
183.50 ± 2% -37.8% 114.20 ± 3% stress-ng.time.user_time
25637892 ± 6% -42.6% 14725385 ± 9% stress-ng.time.voluntary_context_switches
23.01 ± 2% -1.4 21.61 ± 3% perf-stat.i.cache-miss-rate%
17981659 -10.8% 16035508 ± 4% perf-stat.i.cache-misses
77288888 ± 2% -6.5% 72260357 ± 4% perf-stat.i.cache-references
504949 ± 6% -38.1% 312536 ± 8% perf-stat.i.context-switches
33030 +15.7% 38205 ± 4% perf-stat.i.cycles-between-cache-misses
4.34 ± 10% -38.3% 2.68 ± 20% perf-stat.i.metric.K/sec
26229 ± 44% +37.8% 36145 ± 4% perf-stat.overall.cycles-between-cache-misses
30.09 -12.8 17.32 perf-profile.calltrace.cycles-pp.filp_flush.filp_close.__do_sys_close_range.do_syscall_64.entry_SYSCALL_64_after_hwframe
9.32 -9.3 0.00 perf-profile.calltrace.cycles-pp.fput.filp_close.__do_sys_close_range.do_syscall_64.entry_SYSCALL_64_after_hwframe
41.15 -5.9 35.26 perf-profile.calltrace.cycles-pp.__dup2
41.02 -5.9 35.17 perf-profile.calltrace.cycles-pp.do_syscall_64.entry_SYSCALL_64_after_hwframe.__dup2
41.03 -5.8 35.18 perf-profile.calltrace.cycles-pp.entry_SYSCALL_64_after_hwframe.__dup2
13.86 -5.5 8.35 perf-profile.calltrace.cycles-pp.filp_flush.filp_close.do_dup2.__x64_sys_dup2.do_syscall_64
40.21 -5.5 34.71 perf-profile.calltrace.cycles-pp.__x64_sys_dup2.do_syscall_64.entry_SYSCALL_64_after_hwframe.__dup2
38.01 -4.9 33.10 perf-profile.calltrace.cycles-pp.do_dup2.__x64_sys_dup2.do_syscall_64.entry_SYSCALL_64_after_hwframe.__dup2
4.90 ± 2% -1.9 2.96 ± 3% perf-profile.calltrace.cycles-pp.locks_remove_posix.filp_flush.filp_close.__do_sys_close_range.do_syscall_64
2.63 ± 9% -1.9 0.76 ± 18% perf-profile.calltrace.cycles-pp.asm_sysvec_apic_timer_interrupt.filp_flush.filp_close.__do_sys_close_range.do_syscall_64
4.44 -1.7 2.76 ± 2% perf-profile.calltrace.cycles-pp.dnotify_flush.filp_flush.filp_close.__do_sys_close_range.do_syscall_64
2.50 ± 2% -0.9 1.56 ± 3% perf-profile.calltrace.cycles-pp.locks_remove_posix.filp_flush.filp_close.do_dup2.__x64_sys_dup2
2.22 -0.8 1.42 ± 2% perf-profile.calltrace.cycles-pp.dnotify_flush.filp_flush.filp_close.do_dup2.__x64_sys_dup2
1.66 ± 5% -0.3 1.37 ± 5% perf-profile.calltrace.cycles-pp.ksys_dup3.__x64_sys_dup2.do_syscall_64.entry_SYSCALL_64_after_hwframe.__dup2
1.60 ± 5% -0.3 1.32 ± 5% perf-profile.calltrace.cycles-pp._raw_spin_lock.ksys_dup3.__x64_sys_dup2.do_syscall_64.entry_SYSCALL_64_after_hwframe
0.58 ± 2% +0.0 0.62 ± 2% perf-profile.calltrace.cycles-pp.do_read_fault.do_pte_missing.__handle_mm_fault.handle_mm_fault.do_user_addr_fault
0.54 ± 2% +0.0 0.58 ± 2% perf-profile.calltrace.cycles-pp.filemap_map_pages.do_read_fault.do_pte_missing.__handle_mm_fault.handle_mm_fault
0.72 ± 4% +0.1 0.79 ± 4% perf-profile.calltrace.cycles-pp._raw_spin_lock.__do_sys_close_range.do_syscall_64.entry_SYSCALL_64_after_hwframe.syscall
0.00 +1.8 1.79 ± 5% perf-profile.calltrace.cycles-pp.asm_sysvec_apic_timer_interrupt.fput_close.filp_close.__do_sys_close_range.do_syscall_64
19.11 +4.4 23.49 perf-profile.calltrace.cycles-pp.filp_close.do_dup2.__x64_sys_dup2.do_syscall_64.entry_SYSCALL_64_after_hwframe
40.94 +6.5 47.46 perf-profile.calltrace.cycles-pp.filp_close.__do_sys_close_range.do_syscall_64.entry_SYSCALL_64_after_hwframe.syscall
42.24 +6.6 48.79 perf-profile.calltrace.cycles-pp.syscall
42.14 +6.6 48.72 perf-profile.calltrace.cycles-pp.entry_SYSCALL_64_after_hwframe.syscall
42.14 +6.6 48.72 perf-profile.calltrace.cycles-pp.do_syscall_64.entry_SYSCALL_64_after_hwframe.syscall
41.86 +6.6 48.46 perf-profile.calltrace.cycles-pp.__do_sys_close_range.do_syscall_64.entry_SYSCALL_64_after_hwframe.syscall
0.00 +14.6 14.60 ± 2% perf-profile.calltrace.cycles-pp.fput_close.filp_close.do_dup2.__x64_sys_dup2.do_syscall_64
0.00 +29.0 28.95 ± 2% perf-profile.calltrace.cycles-pp.fput_close.filp_close.__do_sys_close_range.do_syscall_64.entry_SYSCALL_64_after_hwframe
45.76 -19.0 26.72 perf-profile.children.cycles-pp.filp_flush
14.67 -14.7 0.00 perf-profile.children.cycles-pp.fput
41.20 -5.9 35.30 perf-profile.children.cycles-pp.__dup2
40.21 -5.5 34.71 perf-profile.children.cycles-pp.__x64_sys_dup2
38.53 -5.2 33.33 perf-profile.children.cycles-pp.do_dup2
7.81 ± 2% -3.1 4.74 ± 3% perf-profile.children.cycles-pp.locks_remove_posix
7.03 -2.6 4.40 ± 2% perf-profile.children.cycles-pp.dnotify_flush
1.24 ± 3% -0.4 0.86 ± 4% perf-profile.children.cycles-pp.syscall_exit_to_user_mode
1.67 ± 5% -0.3 1.37 ± 5% perf-profile.children.cycles-pp.ksys_dup3
0.29 -0.1 0.22 ± 2% perf-profile.children.cycles-pp.update_load_avg
0.10 ± 10% -0.1 0.05 ± 46% perf-profile.children.cycles-pp.__x64_sys_fcntl
0.17 ± 7% -0.1 0.12 ± 4% perf-profile.children.cycles-pp.entry_SYSCALL_64
0.15 ± 3% -0.0 0.10 ± 18% perf-profile.children.cycles-pp.clockevents_program_event
0.06 ± 11% -0.0 0.02 ± 99% perf-profile.children.cycles-pp.stress_close_func
0.13 ± 5% -0.0 0.10 ± 7% perf-profile.children.cycles-pp.__switch_to
0.06 ± 7% -0.0 0.04 ± 71% perf-profile.children.cycles-pp.lapic_next_deadline
0.11 ± 3% -0.0 0.09 ± 5% perf-profile.children.cycles-pp.__update_load_avg_cfs_rq
0.06 ± 6% +0.0 0.08 ± 6% perf-profile.children.cycles-pp.__folio_batch_add_and_move
0.26 ± 2% +0.0 0.28 ± 3% perf-profile.children.cycles-pp.folio_remove_rmap_ptes
0.08 ± 4% +0.0 0.11 ± 10% perf-profile.children.cycles-pp.set_pte_range
0.45 ± 2% +0.0 0.48 ± 2% perf-profile.children.cycles-pp.zap_present_ptes
0.18 ± 3% +0.0 0.21 ± 4% perf-profile.children.cycles-pp.folios_put_refs
0.29 ± 3% +0.0 0.32 ± 3% perf-profile.children.cycles-pp.__tlb_batch_free_encoded_pages
0.29 ± 3% +0.0 0.32 ± 3% perf-profile.children.cycles-pp.free_pages_and_swap_cache
0.34 ± 4% +0.0 0.38 ± 3% perf-profile.children.cycles-pp.tlb_finish_mmu
0.24 ± 3% +0.0 0.27 ± 5% perf-profile.children.cycles-pp._raw_spin_lock_irqsave
0.73 ± 2% +0.0 0.78 ± 2% perf-profile.children.cycles-pp.do_read_fault
0.69 ± 2% +0.0 0.74 ± 2% perf-profile.children.cycles-pp.filemap_map_pages
42.26 +6.5 48.80 perf-profile.children.cycles-pp.syscall
41.86 +6.6 48.46 perf-profile.children.cycles-pp.__do_sys_close_range
60.05 +10.9 70.95 perf-profile.children.cycles-pp.filp_close
0.00 +44.5 44.55 ± 2% perf-profile.children.cycles-pp.fput_close
14.31 ± 2% -14.3 0.00 perf-profile.self.cycles-pp.fput
30.12 ± 2% -13.0 17.09 perf-profile.self.cycles-pp.filp_flush
19.17 ± 2% -9.5 9.68 ± 3% perf-profile.self.cycles-pp.do_dup2
7.63 ± 3% -3.0 4.62 ± 4% perf-profile.self.cycles-pp.locks_remove_posix
6.86 ± 3% -2.6 4.28 ± 3% perf-profile.self.cycles-pp.dnotify_flush
0.64 ± 4% -0.4 0.26 ± 4% perf-profile.self.cycles-pp.syscall_exit_to_user_mode
0.22 ± 10% -0.1 0.15 ± 11% perf-profile.self.cycles-pp.x64_sys_call
0.23 ± 3% -0.1 0.17 ± 8% perf-profile.self.cycles-pp.__schedule
0.08 ± 19% -0.1 0.03 ±100% perf-profile.self.cycles-pp.pick_eevdf
0.06 ± 7% -0.0 0.03 ±100% perf-profile.self.cycles-pp.lapic_next_deadline
0.13 ± 7% -0.0 0.10 ± 10% perf-profile.self.cycles-pp.__switch_to
0.09 ± 8% -0.0 0.06 ± 8% perf-profile.self.cycles-pp.__update_load_avg_se
0.08 ± 4% -0.0 0.05 ± 7% perf-profile.self.cycles-pp.asm_sysvec_apic_timer_interrupt
0.08 ± 9% -0.0 0.06 ± 11% perf-profile.self.cycles-pp.entry_SYSCALL_64
0.06 ± 7% +0.0 0.08 ± 8% perf-profile.self.cycles-pp.filemap_map_pages
0.12 ± 3% +0.0 0.14 ± 4% perf-profile.self.cycles-pp.folios_put_refs
0.25 ± 2% +0.0 0.27 ± 3% perf-profile.self.cycles-pp.folio_remove_rmap_ptes
0.17 ± 5% +0.0 0.20 ± 6% perf-profile.self.cycles-pp._raw_spin_lock_irqsave
0.00 +0.1 0.07 ± 5% perf-profile.self.cycles-pp.do_nanosleep
0.00 +0.1 0.10 ± 15% perf-profile.self.cycles-pp.filp_close
0.00 +43.9 43.86 ± 2% perf-profile.self.cycles-pp.fput_close
2.12 ± 47% +151.1% 5.32 ± 28% perf-sched.sch_delay.avg.ms.__cond_resched.__do_sys_close_range.do_syscall_64.entry_SYSCALL_64_after_hwframe.[unknown]
0.28 ± 60% +990.5% 3.08 ± 53% perf-sched.sch_delay.avg.ms.__cond_resched.__kmalloc_cache_noprof.do_eventfd.__x64_sys_eventfd2.do_syscall_64
0.96 ± 28% +35.5% 1.30 ± 25% perf-sched.sch_delay.avg.ms.__cond_resched.__kmalloc_noprof.load_elf_phdrs.load_elf_binary.exec_binprm
2.56 ± 43% +964.0% 27.27 ±161% perf-sched.sch_delay.avg.ms.__cond_resched.dput.open_last_lookups.path_openat.do_filp_open
12.80 ±139% +366.1% 59.66 ±107% perf-sched.sch_delay.avg.ms.__cond_resched.dput.shmem_unlink.vfs_unlink.do_unlinkat
2.78 ± 25% +50.0% 4.17 ± 19% perf-sched.sch_delay.avg.ms.__cond_resched.kmem_cache_alloc_lru_noprof.__d_alloc.d_alloc_cursor.dcache_dir_open
0.78 ± 18% +39.3% 1.09 ± 19% perf-sched.sch_delay.avg.ms.__cond_resched.kmem_cache_alloc_noprof.mas_alloc_nodes.mas_preallocate.vma_shrink
2.63 ± 10% +16.7% 3.07 ± 4% perf-sched.sch_delay.avg.ms.__cond_resched.kmem_cache_alloc_noprof.vm_area_alloc.__mmap_new_vma.__mmap_region
0.04 ±223% +3483.1% 1.38 ± 67% perf-sched.sch_delay.avg.ms.__cond_resched.netlink_release.__sock_release.sock_close.__fput
0.72 ± 17% +42.5% 1.02 ± 22% perf-sched.sch_delay.avg.ms.__cond_resched.stop_one_cpu.sched_exec.bprm_execve.part
0.35 ±134% +457.7% 1.94 ± 61% perf-sched.sch_delay.avg.ms.__cond_resched.task_numa_work.task_work_run.syscall_exit_to_user_mode.do_syscall_64
1.88 ± 34% +574.9% 12.69 ±115% perf-sched.sch_delay.avg.ms.__cond_resched.task_work_run.syscall_exit_to_user_mode.do_syscall_64.entry_SYSCALL_64_after_hwframe
2.41 ± 10% +18.0% 2.84 ± 9% perf-sched.sch_delay.avg.ms.__cond_resched.wp_page_copy.__handle_mm_fault.handle_mm_fault.do_user_addr_fault
1.85 ± 36% +155.6% 4.73 ± 50% perf-sched.sch_delay.avg.ms.io_schedule.folio_wait_bit_common.__do_fault.do_read_fault
28.94 ± 26% -52.4% 13.78 ± 36% perf-sched.sch_delay.avg.ms.pipe_read.vfs_read.ksys_read.do_syscall_64
2.24 ± 9% +22.1% 2.74 ± 8% perf-sched.sch_delay.avg.ms.schedule_preempt_disabled.rwsem_down_write_slowpath.down_write.unlink_file_vma_batch_final
2.19 ± 7% +17.3% 2.57 ± 6% perf-sched.sch_delay.avg.ms.schedule_preempt_disabled.rwsem_down_write_slowpath.down_write.vma_link_file
2.39 ± 6% +16.4% 2.79 ± 9% perf-sched.sch_delay.avg.ms.schedule_preempt_disabled.rwsem_down_write_slowpath.down_write.vma_prepare
0.34 ± 77% +1931.5% 6.95 ± 99% perf-sched.sch_delay.max.ms.__cond_resched.__kmalloc_cache_noprof.do_eventfd.__x64_sys_eventfd2.do_syscall_64
29.69 ± 28% +129.5% 68.12 ± 28% perf-sched.sch_delay.max.ms.__cond_resched.__kmalloc_cache_noprof.perf_event_mmap_event.perf_event_mmap.__mmap_region
1.48 ± 96% +284.6% 5.68 ± 56% perf-sched.sch_delay.max.ms.__cond_resched.copy_strings_kernel.kernel_execve.call_usermodehelper_exec_async.ret_from_fork
3.59 ± 57% +124.5% 8.06 ± 45% perf-sched.sch_delay.max.ms.__cond_resched.down_read.mmap_read_lock_maybe_expand.get_arg_page.copy_string_kernel
3.39 ± 91% +112.0% 7.19 ± 44% perf-sched.sch_delay.max.ms.__cond_resched.down_read_killable.iterate_dir.__x64_sys_getdents64.do_syscall_64
22.16 ± 77% +117.4% 48.17 ± 34% perf-sched.sch_delay.max.ms.__cond_resched.down_write_killable.exec_mmap.begin_new_exec.load_elf_binary
8.72 ± 17% +358.5% 39.98 ± 61% perf-sched.sch_delay.max.ms.__cond_resched.kmem_cache_alloc_noprof.mas_alloc_nodes.mas_preallocate.__mmap_new_vma
0.04 ±223% +3484.4% 1.38 ± 67% perf-sched.sch_delay.max.ms.__cond_resched.netlink_release.__sock_release.sock_close.__fput
0.53 ±154% +676.1% 4.12 ± 61% perf-sched.sch_delay.max.ms.__cond_resched.task_numa_work.task_work_run.syscall_exit_to_user_mode.do_syscall_64
25.76 ± 70% +9588.9% 2496 ±127% perf-sched.sch_delay.max.ms.__cond_resched.task_work_run.syscall_exit_to_user_mode.do_syscall_64.entry_SYSCALL_64_after_hwframe
51.53 ± 26% -58.8% 21.22 ±106% perf-sched.sch_delay.max.ms.devkmsg_read.vfs_read.ksys_read.do_syscall_64
4.97 ± 48% +154.8% 12.66 ± 75% perf-sched.sch_delay.max.ms.io_schedule.folio_wait_bit_common.__do_fault.do_read_fault
4.36 ± 48% +147.7% 10.81 ± 29% perf-sched.wait_and_delay.avg.ms.__cond_resched.__do_sys_close_range.do_syscall_64.entry_SYSCALL_64_after_hwframe.[unknown]
108632 ± 4% +23.9% 134575 ± 6% perf-sched.wait_and_delay.count.__cond_resched.__do_sys_close_range.do_syscall_64.entry_SYSCALL_64_after_hwframe.[unknown]
572.67 ± 6% +37.3% 786.17 ± 7% perf-sched.wait_and_delay.count.__cond_resched.__wait_for_common.affine_move_task.__set_cpus_allowed_ptr.__sched_setaffinity
596.67 ± 12% +43.9% 858.50 ± 13% perf-sched.wait_and_delay.count.__cond_resched.__wait_for_common.wait_for_completion_state.call_usermodehelper_exec.__request_module
294.83 ± 9% +31.1% 386.50 ± 11% perf-sched.wait_and_delay.count.__cond_resched.dput.terminate_walk.path_openat.do_filp_open
1223275 ± 2% -17.7% 1006293 ± 6% perf-sched.wait_and_delay.count.do_nanosleep.hrtimer_nanosleep.common_nsleep.__x64_sys_clock_nanosleep
2772 ± 11% +43.6% 3980 ± 11% perf-sched.wait_and_delay.count.do_wait.kernel_wait.call_usermodehelper_exec_work.process_one_work
11690 ± 7% +29.8% 15173 ± 10% perf-sched.wait_and_delay.count.io_schedule.folio_wait_bit_common.filemap_fault.__do_fault
4072 ±100% +163.7% 10737 ± 7% perf-sched.wait_and_delay.count.irqentry_exit_to_user_mode.asm_exc_page_fault.[unknown].[unknown]
8811 ± 6% +26.2% 11117 ± 9% perf-sched.wait_and_delay.count.irqentry_exit_to_user_mode.asm_sysvec_apic_timer_interrupt.[unknown].[unknown]
662.17 ± 29% +187.8% 1905 ± 29% perf-sched.wait_and_delay.count.pipe_read.vfs_read.ksys_read.do_syscall_64
15.50 ± 11% +48.4% 23.00 ± 16% perf-sched.wait_and_delay.count.schedule_hrtimeout_range.do_poll.constprop.0.do_sys_poll
167.67 ± 20% +48.0% 248.17 ± 26% perf-sched.wait_and_delay.count.schedule_preempt_disabled.rwsem_down_write_slowpath.down_write.open_last_lookups
2680 ± 12% +42.5% 3820 ± 11% perf-sched.wait_and_delay.count.schedule_timeout.___down_common.__down_timeout.down_timeout
137.17 ± 13% +31.8% 180.83 ± 9% perf-sched.wait_and_delay.count.schedule_timeout.__wait_for_common.wait_for_completion_state.__wait_rcu_gp
2636 ± 12% +43.1% 3772 ± 12% perf-sched.wait_and_delay.count.schedule_timeout.__wait_for_common.wait_for_completion_state.call_usermodehelper_exec
10.50 ± 11% +74.6% 18.33 ± 23% perf-sched.wait_and_delay.count.schedule_timeout.kcompactd.kthread.ret_from_fork
5619 ± 5% +38.8% 7797 ± 9% perf-sched.wait_and_delay.count.smpboot_thread_fn.kthread.ret_from_fork.ret_from_fork_asm
70455 ± 4% +32.3% 93197 ± 6% perf-sched.wait_and_delay.count.syscall_exit_to_user_mode.do_syscall_64.entry_SYSCALL_64_after_hwframe.[unknown]
6990 ± 4% +37.4% 9603 ± 9% perf-sched.wait_and_delay.count.worker_thread.kthread.ret_from_fork.ret_from_fork_asm
191.28 ±124% +1455.2% 2974 ±100% perf-sched.wait_and_delay.max.ms.__cond_resched.dput.path_openat.do_filp_open.do_sys_openat2
2.24 ± 48% +144.6% 5.48 ± 29% perf-sched.wait_time.avg.ms.__cond_resched.__do_sys_close_range.do_syscall_64.entry_SYSCALL_64_after_hwframe.[unknown]
8.06 ±101% +618.7% 57.94 ± 68% perf-sched.wait_time.avg.ms.__cond_resched.__fput.__x64_sys_close.do_syscall_64.entry_SYSCALL_64_after_hwframe
0.28 ±146% +370.9% 1.30 ± 64% perf-sched.wait_time.avg.ms.__cond_resched.down_write.__split_vma.vms_gather_munmap_vmas.do_vmi_align_munmap
3.86 ± 5% +86.0% 7.18 ± 44% perf-sched.wait_time.avg.ms.__cond_resched.down_write.free_pgtables.exit_mmap.__mmput
2.54 ± 29% +51.6% 3.85 ± 12% perf-sched.wait_time.avg.ms.__cond_resched.down_write_killable.__do_sys_brk.do_syscall_64.entry_SYSCALL_64_after_hwframe
1.11 ± 39% +201.6% 3.36 ± 47% perf-sched.wait_time.avg.ms.__cond_resched.down_write_killable.exec_mmap.begin_new_exec.load_elf_binary
3.60 ± 68% +1630.2% 62.29 ±153% perf-sched.wait_time.avg.ms.__cond_resched.dput.step_into.link_path_walk.part
0.20 ± 64% +115.4% 0.42 ± 42% perf-sched.wait_time.avg.ms.__cond_resched.filemap_read.__kernel_read.load_elf_binary.exec_binprm
55.51 ± 53% +218.0% 176.54 ± 83% perf-sched.wait_time.avg.ms.__cond_resched.kmem_cache_alloc_noprof.security_inode_alloc.inode_init_always_gfp.alloc_inode
3.22 ± 3% +15.4% 3.72 ± 9% perf-sched.wait_time.avg.ms.__cond_resched.kmem_cache_alloc_noprof.vm_area_dup.__split_vma.vms_gather_munmap_vmas
0.04 ±223% +37562.8% 14.50 ±198% perf-sched.wait_time.avg.ms.__cond_resched.netlink_release.__sock_release.sock_close.__fput
1.19 ± 30% +59.3% 1.90 ± 34% perf-sched.wait_time.avg.ms.__cond_resched.remove_vma.vms_complete_munmap_vmas.do_vmi_align_munmap.do_vmi_munmap
0.36 ±133% +447.8% 1.97 ± 60% perf-sched.wait_time.avg.ms.__cond_resched.task_numa_work.task_work_run.syscall_exit_to_user_mode.do_syscall_64
1.73 ± 47% +165.0% 4.58 ± 51% perf-sched.wait_time.avg.ms.io_schedule.folio_wait_bit_common.__do_fault.do_read_fault
1.10 ± 21% +693.9% 8.70 ± 70% perf-sched.wait_time.avg.ms.irqentry_exit_to_user_mode.asm_sysvec_call_function_single.[unknown]
54.56 ± 32% +400.2% 272.90 ± 67% perf-sched.wait_time.avg.ms.schedule_timeout.__wait_for_common.wait_for_completion_state.kernel_clone
10.87 ± 18% +151.7% 27.36 ± 68% perf-sched.wait_time.max.ms.__cond_resched.__anon_vma_prepare.__vmf_anon_prepare.do_pte_missing.__handle_mm_fault
123.35 ±181% +1219.3% 1627 ± 82% perf-sched.wait_time.max.ms.__cond_resched.__fput.__x64_sys_close.do_syscall_64.entry_SYSCALL_64_after_hwframe
9.68 ±108% +5490.2% 541.19 ±185% perf-sched.wait_time.max.ms.__cond_resched.__kmalloc_cache_noprof.do_epoll_create.__x64_sys_epoll_create.do_syscall_64
3.39 ± 91% +112.0% 7.19 ± 44% perf-sched.wait_time.max.ms.__cond_resched.down_read_killable.iterate_dir.__x64_sys_getdents64.do_syscall_64
1.12 ±128% +407.4% 5.67 ± 52% perf-sched.wait_time.max.ms.__cond_resched.down_write.__split_vma.vms_gather_munmap_vmas.do_vmi_align_munmap
30.58 ± 29% +1741.1% 563.04 ± 80% perf-sched.wait_time.max.ms.__cond_resched.down_write.free_pgtables.exit_mmap.__mmput
3.82 ±114% +232.1% 12.70 ± 49% perf-sched.wait_time.max.ms.__cond_resched.down_write.vms_gather_munmap_vmas.__mmap_prepare.__mmap_region
7.75 ± 46% +72.4% 13.36 ± 32% perf-sched.wait_time.max.ms.__cond_resched.down_write_killable.__do_sys_brk.do_syscall_64.entry_SYSCALL_64_after_hwframe
13.39 ± 48% +259.7% 48.17 ± 34% perf-sched.wait_time.max.ms.__cond_resched.down_write_killable.exec_mmap.begin_new_exec.load_elf_binary
12.46 ± 30% +90.5% 23.73 ± 34% perf-sched.wait_time.max.ms.__cond_resched.down_write_killable.vm_mmap_pgoff.ksys_mmap_pgoff.do_syscall_64
479.90 ± 78% +496.9% 2864 ±141% perf-sched.wait_time.max.ms.__cond_resched.dput.open_last_lookups.path_openat.do_filp_open
185.75 ±116% +875.0% 1811 ± 84% perf-sched.wait_time.max.ms.__cond_resched.dput.path_openat.do_filp_open.do_sys_openat2
2.52 ± 44% +105.2% 5.18 ± 36% perf-sched.wait_time.max.ms.__cond_resched.kmem_cache_alloc_noprof.vm_area_alloc.alloc_bprm.kernel_execve
0.04 ±223% +37564.1% 14.50 ±198% perf-sched.wait_time.max.ms.__cond_resched.netlink_release.__sock_release.sock_close.__fput
0.54 ±153% +669.7% 4.15 ± 61% perf-sched.wait_time.max.ms.__cond_resched.task_numa_work.task_work_run.syscall_exit_to_user_mode.do_syscall_64
28.22 ± 14% +41.2% 39.84 ± 25% perf-sched.wait_time.max.ms.__cond_resched.unmap_vmas.vms_clear_ptes.part.0
4.90 ± 51% +158.2% 12.66 ± 75% perf-sched.wait_time.max.ms.io_schedule.folio_wait_bit_common.__do_fault.do_read_fault
26.54 ± 66% +5220.1% 1411 ± 84% perf-sched.wait_time.max.ms.irqentry_exit_to_user_mode.asm_sysvec_call_function_single.[unknown]
1262 ± 9% +434.3% 6744 ± 60% perf-sched.wait_time.max.ms.schedule_timeout.__wait_for_common.wait_for_completion_state.kernel_clone
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
^ permalink raw reply [flat|nested] 6+ messages in thread* Re: [linus:master] [fs] a914bd93f3: stress-ng.close.close_calls_per_sec 52.2% regression 2025-04-17 8:23 [linus:master] [fs] a914bd93f3: stress-ng.close.close_calls_per_sec 52.2% regression kernel test robot @ 2025-04-17 9:54 ` Mateusz Guzik 2025-04-17 10:02 ` Mateusz Guzik 0 siblings, 1 reply; 6+ messages in thread From: Mateusz Guzik @ 2025-04-17 9:54 UTC (permalink / raw) To: kernel test robot Cc: oe-lkp, lkp, linux-kernel, Christian Brauner, linux-fsdevel On Thu, Apr 17, 2025 at 10:24 AM kernel test robot <oliver.sang@intel.com> wrote: > > > > Hello, > > kernel test robot noticed a 52.2% regression of stress-ng.close.close_calls_per_sec on: > > > commit: a914bd93f3edfedcdd59deb615e8dd1b3643cac5 ("fs: use fput_close() in filp_close()") > https://git.kernel.org/cgit/linux/kernel/git/torvalds/linux.git master > > [still regression on linus/master 7cdabafc001202de9984f22c973305f424e0a8b7] > [still regression on linux-next/master 01c6df60d5d4ae00cd5c1648818744838bba7763] > > testcase: stress-ng > 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: > > nr_threads: 100% > testtime: 60s > test: close > cpufreq_governor: performance > > > the data is not very stable, but the regression trend seems clear. > > a914bd93f3edfedcdd59deb615e8dd1b3643cac5/matrix.json: "stress-ng.close.close_calls_per_sec": [ > a914bd93f3edfedcdd59deb615e8dd1b3643cac5/matrix.json- 193538.65, > a914bd93f3edfedcdd59deb615e8dd1b3643cac5/matrix.json- 232133.85, > a914bd93f3edfedcdd59deb615e8dd1b3643cac5/matrix.json- 276146.66, > a914bd93f3edfedcdd59deb615e8dd1b3643cac5/matrix.json- 193345.38, > a914bd93f3edfedcdd59deb615e8dd1b3643cac5/matrix.json- 209411.34, > a914bd93f3edfedcdd59deb615e8dd1b3643cac5/matrix.json- 254782.41 > a914bd93f3edfedcdd59deb615e8dd1b3643cac5/matrix.json- ], > > 3e46a92a27c2927fcef996ba06cbe299da629c28/matrix.json: "stress-ng.close.close_calls_per_sec": [ > 3e46a92a27c2927fcef996ba06cbe299da629c28/matrix.json- 427893.13, > 3e46a92a27c2927fcef996ba06cbe299da629c28/matrix.json- 456267.6, > 3e46a92a27c2927fcef996ba06cbe299da629c28/matrix.json- 509121.02, > 3e46a92a27c2927fcef996ba06cbe299da629c28/matrix.json- 544289.08, > 3e46a92a27c2927fcef996ba06cbe299da629c28/matrix.json- 354004.06, > 3e46a92a27c2927fcef996ba06cbe299da629c28/matrix.json- 552310.73 > 3e46a92a27c2927fcef996ba06cbe299da629c28/matrix.json- ], > > > 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@intel.com> > | Closes: https://lore.kernel.org/oe-lkp/202504171513.6d6f8a16-lkp@intel.com > > > Details are as below: > --------------------------------------------------------------------------------------------------> > > > The kernel config and materials to reproduce are available at: > https://download.01.org/0day-ci/archive/20250417/202504171513.6d6f8a16-lkp@intel.com > > ========================================================================================= > compiler/cpufreq_governor/kconfig/nr_threads/rootfs/tbox_group/test/testcase/testtime: > gcc-12/performance/x86_64-rhel-9.4/100%/debian-12-x86_64-20240206.cgz/igk-spr-2sp1/close/stress-ng/60s > > commit: > 3e46a92a27 ("fs: use fput_close_sync() in close()") > a914bd93f3 ("fs: use fput_close() in filp_close()") > I'm going to have to chew on it. First, the commit at hand states: fs: use fput_close() in filp_close() When tracing a kernel build over refcounts seen this is a wash: @[kprobe:filp_close]: [0] 32195 |@@@@@@@@@@ | [1] 164567 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@| I verified vast majority of the skew comes from do_close_on_exec() which could be changed to use a different variant instead. So if need be this is trivially revertable without a major loss anywhere. But also: Even without changing that, the 19.5% of calls which got here still can save the extra atomic. Calls here are borderline non-existent compared to fput (over 3.2 mln!), so they should not negatively affect scalability. As the code converts a lock xadd into a lock cmpxchg loop in exchange for saving an atomic if this is the last close. This indeed scales worse if this in fact does not close the file. stress-ng dups fd 2 several times and then closes it in close_range() in a loop. this manufactures a case where this is never the last close and the cmpxchg loop is a plain loss. While I don't believe this represents real-world behavior, maybe something can be done. I note again this patch can be whacked altogether without any tears shed. So I'm going to chew on it. > 3e46a92a27c2927f a914bd93f3edfedcdd59deb615e > ---------------- --------------------------- > %stddev %change %stddev > \ | \ > 355470 ą 14% -17.6% 292767 ą 7% cpuidle..usage > 5.19 -0.6 4.61 ą 3% mpstat.cpu.all.usr% > 495615 ą 7% -38.5% 304839 ą 8% vmstat.system.cs > 780096 ą 5% -23.5% 596446 ą 3% vmstat.system.in > 2512168 ą 17% -45.8% 1361659 ą 71% sched_debug.cfs_rq:/.avg_vruntime.min > 2512168 ą 17% -45.8% 1361659 ą 71% sched_debug.cfs_rq:/.min_vruntime.min > 700402 ą 2% +19.8% 838744 ą 10% sched_debug.cpu.avg_idle.avg > 81230 ą 6% -59.6% 32788 ą 69% sched_debug.cpu.nr_switches.avg > 27992 ą 20% -70.2% 8345 ą 74% sched_debug.cpu.nr_switches.min > 473980 ą 14% -52.2% 226559 ą 13% stress-ng.close.close_calls_per_sec > 4004843 ą 8% -21.1% 3161813 ą 8% stress-ng.time.involuntary_context_switches > 9475 +1.1% 9582 stress-ng.time.system_time > 183.50 ą 2% -37.8% 114.20 ą 3% stress-ng.time.user_time > 25637892 ą 6% -42.6% 14725385 ą 9% stress-ng.time.voluntary_context_switches > 23.01 ą 2% -1.4 21.61 ą 3% perf-stat.i.cache-miss-rate% > 17981659 -10.8% 16035508 ą 4% perf-stat.i.cache-misses > 77288888 ą 2% -6.5% 72260357 ą 4% perf-stat.i.cache-references > 504949 ą 6% -38.1% 312536 ą 8% perf-stat.i.context-switches > 33030 +15.7% 38205 ą 4% perf-stat.i.cycles-between-cache-misses > 4.34 ą 10% -38.3% 2.68 ą 20% perf-stat.i.metric.K/sec > 26229 ą 44% +37.8% 36145 ą 4% perf-stat.overall.cycles-between-cache-misses > 30.09 -12.8 17.32 perf-profile.calltrace.cycles-pp.filp_flush.filp_close.__do_sys_close_range.do_syscall_64.entry_SYSCALL_64_after_hwframe > 9.32 -9.3 0.00 perf-profile.calltrace.cycles-pp.fput.filp_close.__do_sys_close_range.do_syscall_64.entry_SYSCALL_64_after_hwframe > 41.15 -5.9 35.26 perf-profile.calltrace.cycles-pp.__dup2 > 41.02 -5.9 35.17 perf-profile.calltrace.cycles-pp.do_syscall_64.entry_SYSCALL_64_after_hwframe.__dup2 > 41.03 -5.8 35.18 perf-profile.calltrace.cycles-pp.entry_SYSCALL_64_after_hwframe.__dup2 > 13.86 -5.5 8.35 perf-profile.calltrace.cycles-pp.filp_flush.filp_close.do_dup2.__x64_sys_dup2.do_syscall_64 > 40.21 -5.5 34.71 perf-profile.calltrace.cycles-pp.__x64_sys_dup2.do_syscall_64.entry_SYSCALL_64_after_hwframe.__dup2 > 38.01 -4.9 33.10 perf-profile.calltrace.cycles-pp.do_dup2.__x64_sys_dup2.do_syscall_64.entry_SYSCALL_64_after_hwframe.__dup2 > 4.90 ą 2% -1.9 2.96 ą 3% perf-profile.calltrace.cycles-pp.locks_remove_posix.filp_flush.filp_close.__do_sys_close_range.do_syscall_64 > 2.63 ą 9% -1.9 0.76 ą 18% perf-profile.calltrace.cycles-pp.asm_sysvec_apic_timer_interrupt.filp_flush.filp_close.__do_sys_close_range.do_syscall_64 > 4.44 -1.7 2.76 ą 2% perf-profile.calltrace.cycles-pp.dnotify_flush.filp_flush.filp_close.__do_sys_close_range.do_syscall_64 > 2.50 ą 2% -0.9 1.56 ą 3% perf-profile.calltrace.cycles-pp.locks_remove_posix.filp_flush.filp_close.do_dup2.__x64_sys_dup2 > 2.22 -0.8 1.42 ą 2% perf-profile.calltrace.cycles-pp.dnotify_flush.filp_flush.filp_close.do_dup2.__x64_sys_dup2 > 1.66 ą 5% -0.3 1.37 ą 5% perf-profile.calltrace.cycles-pp.ksys_dup3.__x64_sys_dup2.do_syscall_64.entry_SYSCALL_64_after_hwframe.__dup2 > 1.60 ą 5% -0.3 1.32 ą 5% perf-profile.calltrace.cycles-pp._raw_spin_lock.ksys_dup3.__x64_sys_dup2.do_syscall_64.entry_SYSCALL_64_after_hwframe > 0.58 ą 2% +0.0 0.62 ą 2% perf-profile.calltrace.cycles-pp.do_read_fault.do_pte_missing.__handle_mm_fault.handle_mm_fault.do_user_addr_fault > 0.54 ą 2% +0.0 0.58 ą 2% perf-profile.calltrace.cycles-pp.filemap_map_pages.do_read_fault.do_pte_missing.__handle_mm_fault.handle_mm_fault > 0.72 ą 4% +0.1 0.79 ą 4% perf-profile.calltrace.cycles-pp._raw_spin_lock.__do_sys_close_range.do_syscall_64.entry_SYSCALL_64_after_hwframe.syscall > 0.00 +1.8 1.79 ą 5% perf-profile.calltrace.cycles-pp.asm_sysvec_apic_timer_interrupt.fput_close.filp_close.__do_sys_close_range.do_syscall_64 > 19.11 +4.4 23.49 perf-profile.calltrace.cycles-pp.filp_close.do_dup2.__x64_sys_dup2.do_syscall_64.entry_SYSCALL_64_after_hwframe > 40.94 +6.5 47.46 perf-profile.calltrace.cycles-pp.filp_close.__do_sys_close_range.do_syscall_64.entry_SYSCALL_64_after_hwframe.syscall > 42.24 +6.6 48.79 perf-profile.calltrace.cycles-pp.syscall > 42.14 +6.6 48.72 perf-profile.calltrace.cycles-pp.entry_SYSCALL_64_after_hwframe.syscall > 42.14 +6.6 48.72 perf-profile.calltrace.cycles-pp.do_syscall_64.entry_SYSCALL_64_after_hwframe.syscall > 41.86 +6.6 48.46 perf-profile.calltrace.cycles-pp.__do_sys_close_range.do_syscall_64.entry_SYSCALL_64_after_hwframe.syscall > 0.00 +14.6 14.60 ą 2% perf-profile.calltrace.cycles-pp.fput_close.filp_close.do_dup2.__x64_sys_dup2.do_syscall_64 > 0.00 +29.0 28.95 ą 2% perf-profile.calltrace.cycles-pp.fput_close.filp_close.__do_sys_close_range.do_syscall_64.entry_SYSCALL_64_after_hwframe > 45.76 -19.0 26.72 perf-profile.children.cycles-pp.filp_flush > 14.67 -14.7 0.00 perf-profile.children.cycles-pp.fput > 41.20 -5.9 35.30 perf-profile.children.cycles-pp.__dup2 > 40.21 -5.5 34.71 perf-profile.children.cycles-pp.__x64_sys_dup2 > 38.53 -5.2 33.33 perf-profile.children.cycles-pp.do_dup2 > 7.81 ą 2% -3.1 4.74 ą 3% perf-profile.children.cycles-pp.locks_remove_posix > 7.03 -2.6 4.40 ą 2% perf-profile.children.cycles-pp.dnotify_flush > 1.24 ą 3% -0.4 0.86 ą 4% perf-profile.children.cycles-pp.syscall_exit_to_user_mode > 1.67 ą 5% -0.3 1.37 ą 5% perf-profile.children.cycles-pp.ksys_dup3 > 0.29 -0.1 0.22 ą 2% perf-profile.children.cycles-pp.update_load_avg > 0.10 ą 10% -0.1 0.05 ą 46% perf-profile.children.cycles-pp.__x64_sys_fcntl > 0.17 ą 7% -0.1 0.12 ą 4% perf-profile.children.cycles-pp.entry_SYSCALL_64 > 0.15 ą 3% -0.0 0.10 ą 18% perf-profile.children.cycles-pp.clockevents_program_event > 0.06 ą 11% -0.0 0.02 ą 99% perf-profile.children.cycles-pp.stress_close_func > 0.13 ą 5% -0.0 0.10 ą 7% perf-profile.children.cycles-pp.__switch_to > 0.06 ą 7% -0.0 0.04 ą 71% perf-profile.children.cycles-pp.lapic_next_deadline > 0.11 ą 3% -0.0 0.09 ą 5% perf-profile.children.cycles-pp.__update_load_avg_cfs_rq > 0.06 ą 6% +0.0 0.08 ą 6% perf-profile.children.cycles-pp.__folio_batch_add_and_move > 0.26 ą 2% +0.0 0.28 ą 3% perf-profile.children.cycles-pp.folio_remove_rmap_ptes > 0.08 ą 4% +0.0 0.11 ą 10% perf-profile.children.cycles-pp.set_pte_range > 0.45 ą 2% +0.0 0.48 ą 2% perf-profile.children.cycles-pp.zap_present_ptes > 0.18 ą 3% +0.0 0.21 ą 4% perf-profile.children.cycles-pp.folios_put_refs > 0.29 ą 3% +0.0 0.32 ą 3% perf-profile.children.cycles-pp.__tlb_batch_free_encoded_pages > 0.29 ą 3% +0.0 0.32 ą 3% perf-profile.children.cycles-pp.free_pages_and_swap_cache > 0.34 ą 4% +0.0 0.38 ą 3% perf-profile.children.cycles-pp.tlb_finish_mmu > 0.24 ą 3% +0.0 0.27 ą 5% perf-profile.children.cycles-pp._raw_spin_lock_irqsave > 0.73 ą 2% +0.0 0.78 ą 2% perf-profile.children.cycles-pp.do_read_fault > 0.69 ą 2% +0.0 0.74 ą 2% perf-profile.children.cycles-pp.filemap_map_pages > 42.26 +6.5 48.80 perf-profile.children.cycles-pp.syscall > 41.86 +6.6 48.46 perf-profile.children.cycles-pp.__do_sys_close_range > 60.05 +10.9 70.95 perf-profile.children.cycles-pp.filp_close > 0.00 +44.5 44.55 ą 2% perf-profile.children.cycles-pp.fput_close > 14.31 ą 2% -14.3 0.00 perf-profile.self.cycles-pp.fput > 30.12 ą 2% -13.0 17.09 perf-profile.self.cycles-pp.filp_flush > 19.17 ą 2% -9.5 9.68 ą 3% perf-profile.self.cycles-pp.do_dup2 > 7.63 ą 3% -3.0 4.62 ą 4% perf-profile.self.cycles-pp.locks_remove_posix > 6.86 ą 3% -2.6 4.28 ą 3% perf-profile.self.cycles-pp.dnotify_flush > 0.64 ą 4% -0.4 0.26 ą 4% perf-profile.self.cycles-pp.syscall_exit_to_user_mode > 0.22 ą 10% -0.1 0.15 ą 11% perf-profile.self.cycles-pp.x64_sys_call > 0.23 ą 3% -0.1 0.17 ą 8% perf-profile.self.cycles-pp.__schedule > 0.08 ą 19% -0.1 0.03 ą100% perf-profile.self.cycles-pp.pick_eevdf > 0.06 ą 7% -0.0 0.03 ą100% perf-profile.self.cycles-pp.lapic_next_deadline > 0.13 ą 7% -0.0 0.10 ą 10% perf-profile.self.cycles-pp.__switch_to > 0.09 ą 8% -0.0 0.06 ą 8% perf-profile.self.cycles-pp.__update_load_avg_se > 0.08 ą 4% -0.0 0.05 ą 7% perf-profile.self.cycles-pp.asm_sysvec_apic_timer_interrupt > 0.08 ą 9% -0.0 0.06 ą 11% perf-profile.self.cycles-pp.entry_SYSCALL_64 > 0.06 ą 7% +0.0 0.08 ą 8% perf-profile.self.cycles-pp.filemap_map_pages > 0.12 ą 3% +0.0 0.14 ą 4% perf-profile.self.cycles-pp.folios_put_refs > 0.25 ą 2% +0.0 0.27 ą 3% perf-profile.self.cycles-pp.folio_remove_rmap_ptes > 0.17 ą 5% +0.0 0.20 ą 6% perf-profile.self.cycles-pp._raw_spin_lock_irqsave > 0.00 +0.1 0.07 ą 5% perf-profile.self.cycles-pp.do_nanosleep > 0.00 +0.1 0.10 ą 15% perf-profile.self.cycles-pp.filp_close > 0.00 +43.9 43.86 ą 2% perf-profile.self.cycles-pp.fput_close > 2.12 ą 47% +151.1% 5.32 ą 28% perf-sched.sch_delay.avg.ms.__cond_resched.__do_sys_close_range.do_syscall_64.entry_SYSCALL_64_after_hwframe.[unknown] > 0.28 ą 60% +990.5% 3.08 ą 53% perf-sched.sch_delay.avg.ms.__cond_resched.__kmalloc_cache_noprof.do_eventfd.__x64_sys_eventfd2.do_syscall_64 > 0.96 ą 28% +35.5% 1.30 ą 25% perf-sched.sch_delay.avg.ms.__cond_resched.__kmalloc_noprof.load_elf_phdrs.load_elf_binary.exec_binprm > 2.56 ą 43% +964.0% 27.27 ą161% perf-sched.sch_delay.avg.ms.__cond_resched.dput.open_last_lookups.path_openat.do_filp_open > 12.80 ą139% +366.1% 59.66 ą107% perf-sched.sch_delay.avg.ms.__cond_resched.dput.shmem_unlink.vfs_unlink.do_unlinkat > 2.78 ą 25% +50.0% 4.17 ą 19% perf-sched.sch_delay.avg.ms.__cond_resched.kmem_cache_alloc_lru_noprof.__d_alloc.d_alloc_cursor.dcache_dir_open > 0.78 ą 18% +39.3% 1.09 ą 19% perf-sched.sch_delay.avg.ms.__cond_resched.kmem_cache_alloc_noprof.mas_alloc_nodes.mas_preallocate.vma_shrink > 2.63 ą 10% +16.7% 3.07 ą 4% perf-sched.sch_delay.avg.ms.__cond_resched.kmem_cache_alloc_noprof.vm_area_alloc.__mmap_new_vma.__mmap_region > 0.04 ą223% +3483.1% 1.38 ą 67% perf-sched.sch_delay.avg.ms.__cond_resched.netlink_release.__sock_release.sock_close.__fput > 0.72 ą 17% +42.5% 1.02 ą 22% perf-sched.sch_delay.avg.ms.__cond_resched.stop_one_cpu.sched_exec.bprm_execve.part > 0.35 ą134% +457.7% 1.94 ą 61% perf-sched.sch_delay.avg.ms.__cond_resched.task_numa_work.task_work_run.syscall_exit_to_user_mode.do_syscall_64 > 1.88 ą 34% +574.9% 12.69 ą115% perf-sched.sch_delay.avg.ms.__cond_resched.task_work_run.syscall_exit_to_user_mode.do_syscall_64.entry_SYSCALL_64_after_hwframe > 2.41 ą 10% +18.0% 2.84 ą 9% perf-sched.sch_delay.avg.ms.__cond_resched.wp_page_copy.__handle_mm_fault.handle_mm_fault.do_user_addr_fault > 1.85 ą 36% +155.6% 4.73 ą 50% perf-sched.sch_delay.avg.ms.io_schedule.folio_wait_bit_common.__do_fault.do_read_fault > 28.94 ą 26% -52.4% 13.78 ą 36% perf-sched.sch_delay.avg.ms.pipe_read.vfs_read.ksys_read.do_syscall_64 > 2.24 ą 9% +22.1% 2.74 ą 8% perf-sched.sch_delay.avg.ms.schedule_preempt_disabled.rwsem_down_write_slowpath.down_write.unlink_file_vma_batch_final > 2.19 ą 7% +17.3% 2.57 ą 6% perf-sched.sch_delay.avg.ms.schedule_preempt_disabled.rwsem_down_write_slowpath.down_write.vma_link_file > 2.39 ą 6% +16.4% 2.79 ą 9% perf-sched.sch_delay.avg.ms.schedule_preempt_disabled.rwsem_down_write_slowpath.down_write.vma_prepare > 0.34 ą 77% +1931.5% 6.95 ą 99% perf-sched.sch_delay.max.ms.__cond_resched.__kmalloc_cache_noprof.do_eventfd.__x64_sys_eventfd2.do_syscall_64 > 29.69 ą 28% +129.5% 68.12 ą 28% perf-sched.sch_delay.max.ms.__cond_resched.__kmalloc_cache_noprof.perf_event_mmap_event.perf_event_mmap.__mmap_region > 1.48 ą 96% +284.6% 5.68 ą 56% perf-sched.sch_delay.max.ms.__cond_resched.copy_strings_kernel.kernel_execve.call_usermodehelper_exec_async.ret_from_fork > 3.59 ą 57% +124.5% 8.06 ą 45% perf-sched.sch_delay.max.ms.__cond_resched.down_read.mmap_read_lock_maybe_expand.get_arg_page.copy_string_kernel > 3.39 ą 91% +112.0% 7.19 ą 44% perf-sched.sch_delay.max.ms.__cond_resched.down_read_killable.iterate_dir.__x64_sys_getdents64.do_syscall_64 > 22.16 ą 77% +117.4% 48.17 ą 34% perf-sched.sch_delay.max.ms.__cond_resched.down_write_killable.exec_mmap.begin_new_exec.load_elf_binary > 8.72 ą 17% +358.5% 39.98 ą 61% perf-sched.sch_delay.max.ms.__cond_resched.kmem_cache_alloc_noprof.mas_alloc_nodes.mas_preallocate.__mmap_new_vma > 0.04 ą223% +3484.4% 1.38 ą 67% perf-sched.sch_delay.max.ms.__cond_resched.netlink_release.__sock_release.sock_close.__fput > 0.53 ą154% +676.1% 4.12 ą 61% perf-sched.sch_delay.max.ms.__cond_resched.task_numa_work.task_work_run.syscall_exit_to_user_mode.do_syscall_64 > 25.76 ą 70% +9588.9% 2496 ą127% perf-sched.sch_delay.max.ms.__cond_resched.task_work_run.syscall_exit_to_user_mode.do_syscall_64.entry_SYSCALL_64_after_hwframe > 51.53 ą 26% -58.8% 21.22 ą106% perf-sched.sch_delay.max.ms.devkmsg_read.vfs_read.ksys_read.do_syscall_64 > 4.97 ą 48% +154.8% 12.66 ą 75% perf-sched.sch_delay.max.ms.io_schedule.folio_wait_bit_common.__do_fault.do_read_fault > 4.36 ą 48% +147.7% 10.81 ą 29% perf-sched.wait_and_delay.avg.ms.__cond_resched.__do_sys_close_range.do_syscall_64.entry_SYSCALL_64_after_hwframe.[unknown] > 108632 ą 4% +23.9% 134575 ą 6% perf-sched.wait_and_delay.count.__cond_resched.__do_sys_close_range.do_syscall_64.entry_SYSCALL_64_after_hwframe.[unknown] > 572.67 ą 6% +37.3% 786.17 ą 7% perf-sched.wait_and_delay.count.__cond_resched.__wait_for_common.affine_move_task.__set_cpus_allowed_ptr.__sched_setaffinity > 596.67 ą 12% +43.9% 858.50 ą 13% perf-sched.wait_and_delay.count.__cond_resched.__wait_for_common.wait_for_completion_state.call_usermodehelper_exec.__request_module > 294.83 ą 9% +31.1% 386.50 ą 11% perf-sched.wait_and_delay.count.__cond_resched.dput.terminate_walk.path_openat.do_filp_open > 1223275 ą 2% -17.7% 1006293 ą 6% perf-sched.wait_and_delay.count.do_nanosleep.hrtimer_nanosleep.common_nsleep.__x64_sys_clock_nanosleep > 2772 ą 11% +43.6% 3980 ą 11% perf-sched.wait_and_delay.count.do_wait.kernel_wait.call_usermodehelper_exec_work.process_one_work > 11690 ą 7% +29.8% 15173 ą 10% perf-sched.wait_and_delay.count.io_schedule.folio_wait_bit_common.filemap_fault.__do_fault > 4072 ą100% +163.7% 10737 ą 7% perf-sched.wait_and_delay.count.irqentry_exit_to_user_mode.asm_exc_page_fault.[unknown].[unknown] > 8811 ą 6% +26.2% 11117 ą 9% perf-sched.wait_and_delay.count.irqentry_exit_to_user_mode.asm_sysvec_apic_timer_interrupt.[unknown].[unknown] > 662.17 ą 29% +187.8% 1905 ą 29% perf-sched.wait_and_delay.count.pipe_read.vfs_read.ksys_read.do_syscall_64 > 15.50 ą 11% +48.4% 23.00 ą 16% perf-sched.wait_and_delay.count.schedule_hrtimeout_range.do_poll.constprop.0.do_sys_poll > 167.67 ą 20% +48.0% 248.17 ą 26% perf-sched.wait_and_delay.count.schedule_preempt_disabled.rwsem_down_write_slowpath.down_write.open_last_lookups > 2680 ą 12% +42.5% 3820 ą 11% perf-sched.wait_and_delay.count.schedule_timeout.___down_common.__down_timeout.down_timeout > 137.17 ą 13% +31.8% 180.83 ą 9% perf-sched.wait_and_delay.count.schedule_timeout.__wait_for_common.wait_for_completion_state.__wait_rcu_gp > 2636 ą 12% +43.1% 3772 ą 12% perf-sched.wait_and_delay.count.schedule_timeout.__wait_for_common.wait_for_completion_state.call_usermodehelper_exec > 10.50 ą 11% +74.6% 18.33 ą 23% perf-sched.wait_and_delay.count.schedule_timeout.kcompactd.kthread.ret_from_fork > 5619 ą 5% +38.8% 7797 ą 9% perf-sched.wait_and_delay.count.smpboot_thread_fn.kthread.ret_from_fork.ret_from_fork_asm > 70455 ą 4% +32.3% 93197 ą 6% perf-sched.wait_and_delay.count.syscall_exit_to_user_mode.do_syscall_64.entry_SYSCALL_64_after_hwframe.[unknown] > 6990 ą 4% +37.4% 9603 ą 9% perf-sched.wait_and_delay.count.worker_thread.kthread.ret_from_fork.ret_from_fork_asm > 191.28 ą124% +1455.2% 2974 ą100% perf-sched.wait_and_delay.max.ms.__cond_resched.dput.path_openat.do_filp_open.do_sys_openat2 > 2.24 ą 48% +144.6% 5.48 ą 29% perf-sched.wait_time.avg.ms.__cond_resched.__do_sys_close_range.do_syscall_64.entry_SYSCALL_64_after_hwframe.[unknown] > 8.06 ą101% +618.7% 57.94 ą 68% perf-sched.wait_time.avg.ms.__cond_resched.__fput.__x64_sys_close.do_syscall_64.entry_SYSCALL_64_after_hwframe > 0.28 ą146% +370.9% 1.30 ą 64% perf-sched.wait_time.avg.ms.__cond_resched.down_write.__split_vma.vms_gather_munmap_vmas.do_vmi_align_munmap > 3.86 ą 5% +86.0% 7.18 ą 44% perf-sched.wait_time.avg.ms.__cond_resched.down_write.free_pgtables.exit_mmap.__mmput > 2.54 ą 29% +51.6% 3.85 ą 12% perf-sched.wait_time.avg.ms.__cond_resched.down_write_killable.__do_sys_brk.do_syscall_64.entry_SYSCALL_64_after_hwframe > 1.11 ą 39% +201.6% 3.36 ą 47% perf-sched.wait_time.avg.ms.__cond_resched.down_write_killable.exec_mmap.begin_new_exec.load_elf_binary > 3.60 ą 68% +1630.2% 62.29 ą153% perf-sched.wait_time.avg.ms.__cond_resched.dput.step_into.link_path_walk.part > 0.20 ą 64% +115.4% 0.42 ą 42% perf-sched.wait_time.avg.ms.__cond_resched.filemap_read.__kernel_read.load_elf_binary.exec_binprm > 55.51 ą 53% +218.0% 176.54 ą 83% perf-sched.wait_time.avg.ms.__cond_resched.kmem_cache_alloc_noprof.security_inode_alloc.inode_init_always_gfp.alloc_inode > 3.22 ą 3% +15.4% 3.72 ą 9% perf-sched.wait_time.avg.ms.__cond_resched.kmem_cache_alloc_noprof.vm_area_dup.__split_vma.vms_gather_munmap_vmas > 0.04 ą223% +37562.8% 14.50 ą198% perf-sched.wait_time.avg.ms.__cond_resched.netlink_release.__sock_release.sock_close.__fput > 1.19 ą 30% +59.3% 1.90 ą 34% perf-sched.wait_time.avg.ms.__cond_resched.remove_vma.vms_complete_munmap_vmas.do_vmi_align_munmap.do_vmi_munmap > 0.36 ą133% +447.8% 1.97 ą 60% perf-sched.wait_time.avg.ms.__cond_resched.task_numa_work.task_work_run.syscall_exit_to_user_mode.do_syscall_64 > 1.73 ą 47% +165.0% 4.58 ą 51% perf-sched.wait_time.avg.ms.io_schedule.folio_wait_bit_common.__do_fault.do_read_fault > 1.10 ą 21% +693.9% 8.70 ą 70% perf-sched.wait_time.avg.ms.irqentry_exit_to_user_mode.asm_sysvec_call_function_single.[unknown] > 54.56 ą 32% +400.2% 272.90 ą 67% perf-sched.wait_time.avg.ms.schedule_timeout.__wait_for_common.wait_for_completion_state.kernel_clone > 10.87 ą 18% +151.7% 27.36 ą 68% perf-sched.wait_time.max.ms.__cond_resched.__anon_vma_prepare.__vmf_anon_prepare.do_pte_missing.__handle_mm_fault > 123.35 ą181% +1219.3% 1627 ą 82% perf-sched.wait_time.max.ms.__cond_resched.__fput.__x64_sys_close.do_syscall_64.entry_SYSCALL_64_after_hwframe > 9.68 ą108% +5490.2% 541.19 ą185% perf-sched.wait_time.max.ms.__cond_resched.__kmalloc_cache_noprof.do_epoll_create.__x64_sys_epoll_create.do_syscall_64 > 3.39 ą 91% +112.0% 7.19 ą 44% perf-sched.wait_time.max.ms.__cond_resched.down_read_killable.iterate_dir.__x64_sys_getdents64.do_syscall_64 > 1.12 ą128% +407.4% 5.67 ą 52% perf-sched.wait_time.max.ms.__cond_resched.down_write.__split_vma.vms_gather_munmap_vmas.do_vmi_align_munmap > 30.58 ą 29% +1741.1% 563.04 ą 80% perf-sched.wait_time.max.ms.__cond_resched.down_write.free_pgtables.exit_mmap.__mmput > 3.82 ą114% +232.1% 12.70 ą 49% perf-sched.wait_time.max.ms.__cond_resched.down_write.vms_gather_munmap_vmas.__mmap_prepare.__mmap_region > 7.75 ą 46% +72.4% 13.36 ą 32% perf-sched.wait_time.max.ms.__cond_resched.down_write_killable.__do_sys_brk.do_syscall_64.entry_SYSCALL_64_after_hwframe > 13.39 ą 48% +259.7% 48.17 ą 34% perf-sched.wait_time.max.ms.__cond_resched.down_write_killable.exec_mmap.begin_new_exec.load_elf_binary > 12.46 ą 30% +90.5% 23.73 ą 34% perf-sched.wait_time.max.ms.__cond_resched.down_write_killable.vm_mmap_pgoff.ksys_mmap_pgoff.do_syscall_64 > 479.90 ą 78% +496.9% 2864 ą141% perf-sched.wait_time.max.ms.__cond_resched.dput.open_last_lookups.path_openat.do_filp_open > 185.75 ą116% +875.0% 1811 ą 84% perf-sched.wait_time.max.ms.__cond_resched.dput.path_openat.do_filp_open.do_sys_openat2 > 2.52 ą 44% +105.2% 5.18 ą 36% perf-sched.wait_time.max.ms.__cond_resched.kmem_cache_alloc_noprof.vm_area_alloc.alloc_bprm.kernel_execve > 0.04 ą223% +37564.1% 14.50 ą198% perf-sched.wait_time.max.ms.__cond_resched.netlink_release.__sock_release.sock_close.__fput > 0.54 ą153% +669.7% 4.15 ą 61% perf-sched.wait_time.max.ms.__cond_resched.task_numa_work.task_work_run.syscall_exit_to_user_mode.do_syscall_64 > 28.22 ą 14% +41.2% 39.84 ą 25% perf-sched.wait_time.max.ms.__cond_resched.unmap_vmas.vms_clear_ptes.part.0 > 4.90 ą 51% +158.2% 12.66 ą 75% perf-sched.wait_time.max.ms.io_schedule.folio_wait_bit_common.__do_fault.do_read_fault > 26.54 ą 66% +5220.1% 1411 ą 84% perf-sched.wait_time.max.ms.irqentry_exit_to_user_mode.asm_sysvec_call_function_single.[unknown] > 1262 ą 9% +434.3% 6744 ą 60% perf-sched.wait_time.max.ms.schedule_timeout.__wait_for_common.wait_for_completion_state.kernel_clone > > > > > 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 > -- Mateusz Guzik <mjguzik gmail.com> ^ permalink raw reply [flat|nested] 6+ messages in thread
* Re: [linus:master] [fs] a914bd93f3: stress-ng.close.close_calls_per_sec 52.2% regression 2025-04-17 9:54 ` Mateusz Guzik @ 2025-04-17 10:02 ` Mateusz Guzik 2025-04-17 10:17 ` Mateusz Guzik 0 siblings, 1 reply; 6+ messages in thread From: Mateusz Guzik @ 2025-04-17 10:02 UTC (permalink / raw) To: kernel test robot Cc: oe-lkp, lkp, linux-kernel, Christian Brauner, linux-fsdevel On Thu, Apr 17, 2025 at 11:54 AM Mateusz Guzik <mjguzik@gmail.com> wrote: > > On Thu, Apr 17, 2025 at 10:24 AM kernel test robot > <oliver.sang@intel.com> wrote: > > > > > > > > Hello, > > > > kernel test robot noticed a 52.2% regression of stress-ng.close.close_calls_per_sec on: > > > > > > commit: a914bd93f3edfedcdd59deb615e8dd1b3643cac5 ("fs: use fput_close() in filp_close()") > > https://git.kernel.org/cgit/linux/kernel/git/torvalds/linux.git master > > > > [still regression on linus/master 7cdabafc001202de9984f22c973305f424e0a8b7] > > [still regression on linux-next/master 01c6df60d5d4ae00cd5c1648818744838bba7763] > > > > testcase: stress-ng > > 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: > > > > nr_threads: 100% > > testtime: 60s > > test: close > > cpufreq_governor: performance > > > > > > the data is not very stable, but the regression trend seems clear. > > > > a914bd93f3edfedcdd59deb615e8dd1b3643cac5/matrix.json: "stress-ng.close.close_calls_per_sec": [ > > a914bd93f3edfedcdd59deb615e8dd1b3643cac5/matrix.json- 193538.65, > > a914bd93f3edfedcdd59deb615e8dd1b3643cac5/matrix.json- 232133.85, > > a914bd93f3edfedcdd59deb615e8dd1b3643cac5/matrix.json- 276146.66, > > a914bd93f3edfedcdd59deb615e8dd1b3643cac5/matrix.json- 193345.38, > > a914bd93f3edfedcdd59deb615e8dd1b3643cac5/matrix.json- 209411.34, > > a914bd93f3edfedcdd59deb615e8dd1b3643cac5/matrix.json- 254782.41 > > a914bd93f3edfedcdd59deb615e8dd1b3643cac5/matrix.json- ], > > > > 3e46a92a27c2927fcef996ba06cbe299da629c28/matrix.json: "stress-ng.close.close_calls_per_sec": [ > > 3e46a92a27c2927fcef996ba06cbe299da629c28/matrix.json- 427893.13, > > 3e46a92a27c2927fcef996ba06cbe299da629c28/matrix.json- 456267.6, > > 3e46a92a27c2927fcef996ba06cbe299da629c28/matrix.json- 509121.02, > > 3e46a92a27c2927fcef996ba06cbe299da629c28/matrix.json- 544289.08, > > 3e46a92a27c2927fcef996ba06cbe299da629c28/matrix.json- 354004.06, > > 3e46a92a27c2927fcef996ba06cbe299da629c28/matrix.json- 552310.73 > > 3e46a92a27c2927fcef996ba06cbe299da629c28/matrix.json- ], > > > > > > 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@intel.com> > > | Closes: https://lore.kernel.org/oe-lkp/202504171513.6d6f8a16-lkp@intel.com > > > > > > Details are as below: > > --------------------------------------------------------------------------------------------------> > > > > > > The kernel config and materials to reproduce are available at: > > https://download.01.org/0day-ci/archive/20250417/202504171513.6d6f8a16-lkp@intel.com > > > > ========================================================================================= > > compiler/cpufreq_governor/kconfig/nr_threads/rootfs/tbox_group/test/testcase/testtime: > > gcc-12/performance/x86_64-rhel-9.4/100%/debian-12-x86_64-20240206.cgz/igk-spr-2sp1/close/stress-ng/60s > > > > commit: > > 3e46a92a27 ("fs: use fput_close_sync() in close()") > > a914bd93f3 ("fs: use fput_close() in filp_close()") > > > > I'm going to have to chew on it. > > First, the commit at hand states: > fs: use fput_close() in filp_close() > > When tracing a kernel build over refcounts seen this is a wash: > @[kprobe:filp_close]: > [0] 32195 |@@@@@@@@@@ > | > [1] 164567 > |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@| > > I verified vast majority of the skew comes from do_close_on_exec() which > could be changed to use a different variant instead. > > So if need be this is trivially revertable without a major loss anywhere. > > But also: > Even without changing that, the 19.5% of calls which got here still can > save the extra atomic. Calls here are borderline non-existent compared > to fput (over 3.2 mln!), so they should not negatively affect > scalability. > > As the code converts a lock xadd into a lock cmpxchg loop in exchange > for saving an atomic if this is the last close. This indeed scales > worse if this in fact does not close the file. > > stress-ng dups fd 2 several times and then closes it in close_range() > in a loop. this manufactures a case where this is never the last close > and the cmpxchg loop is a plain loss. > huh, bad editing bottom line though is there is a known tradeoff there and stress-ng manufactures a case where it is always the wrong one. fd 2 at hand is inherited (it's the tty) and shared between *all* workers on all CPUs. Ignoring some fluff, it's this in a loop: dup2(2, 1024) = 1024 dup2(2, 1025) = 1025 dup2(2, 1026) = 1026 dup2(2, 1027) = 1027 dup2(2, 1028) = 1028 dup2(2, 1029) = 1029 dup2(2, 1030) = 1030 dup2(2, 1031) = 1031 [..] close_range(1024, 1032, 0) = 0 where fd 2 is the same file object in all 192 workers doing this. > While I don't believe this represents real-world behavior, maybe > something can be done. I note again this patch can be whacked > altogether without any tears shed. > > So I'm going to chew on it. > > > 3e46a92a27c2927f a914bd93f3edfedcdd59deb615e > > ---------------- --------------------------- > > %stddev %change %stddev > > \ | \ > > 355470 ą 14% -17.6% 292767 ą 7% cpuidle..usage > > 5.19 -0.6 4.61 ą 3% mpstat.cpu.all.usr% > > 495615 ą 7% -38.5% 304839 ą 8% vmstat.system.cs > > 780096 ą 5% -23.5% 596446 ą 3% vmstat.system.in > > 2512168 ą 17% -45.8% 1361659 ą 71% sched_debug.cfs_rq:/.avg_vruntime.min > > 2512168 ą 17% -45.8% 1361659 ą 71% sched_debug.cfs_rq:/.min_vruntime.min > > 700402 ą 2% +19.8% 838744 ą 10% sched_debug.cpu.avg_idle.avg > > 81230 ą 6% -59.6% 32788 ą 69% sched_debug.cpu.nr_switches.avg > > 27992 ą 20% -70.2% 8345 ą 74% sched_debug.cpu.nr_switches.min > > 473980 ą 14% -52.2% 226559 ą 13% stress-ng.close.close_calls_per_sec > > 4004843 ą 8% -21.1% 3161813 ą 8% stress-ng.time.involuntary_context_switches > > 9475 +1.1% 9582 stress-ng.time.system_time > > 183.50 ą 2% -37.8% 114.20 ą 3% stress-ng.time.user_time > > 25637892 ą 6% -42.6% 14725385 ą 9% stress-ng.time.voluntary_context_switches > > 23.01 ą 2% -1.4 21.61 ą 3% perf-stat.i.cache-miss-rate% > > 17981659 -10.8% 16035508 ą 4% perf-stat.i.cache-misses > > 77288888 ą 2% -6.5% 72260357 ą 4% perf-stat.i.cache-references > > 504949 ą 6% -38.1% 312536 ą 8% perf-stat.i.context-switches > > 33030 +15.7% 38205 ą 4% perf-stat.i.cycles-between-cache-misses > > 4.34 ą 10% -38.3% 2.68 ą 20% perf-stat.i.metric.K/sec > > 26229 ą 44% +37.8% 36145 ą 4% perf-stat.overall.cycles-between-cache-misses > > 30.09 -12.8 17.32 perf-profile.calltrace.cycles-pp.filp_flush.filp_close.__do_sys_close_range.do_syscall_64.entry_SYSCALL_64_after_hwframe > > 9.32 -9.3 0.00 perf-profile.calltrace.cycles-pp.fput.filp_close.__do_sys_close_range.do_syscall_64.entry_SYSCALL_64_after_hwframe > > 41.15 -5.9 35.26 perf-profile.calltrace.cycles-pp.__dup2 > > 41.02 -5.9 35.17 perf-profile.calltrace.cycles-pp.do_syscall_64.entry_SYSCALL_64_after_hwframe.__dup2 > > 41.03 -5.8 35.18 perf-profile.calltrace.cycles-pp.entry_SYSCALL_64_after_hwframe.__dup2 > > 13.86 -5.5 8.35 perf-profile.calltrace.cycles-pp.filp_flush.filp_close.do_dup2.__x64_sys_dup2.do_syscall_64 > > 40.21 -5.5 34.71 perf-profile.calltrace.cycles-pp.__x64_sys_dup2.do_syscall_64.entry_SYSCALL_64_after_hwframe.__dup2 > > 38.01 -4.9 33.10 perf-profile.calltrace.cycles-pp.do_dup2.__x64_sys_dup2.do_syscall_64.entry_SYSCALL_64_after_hwframe.__dup2 > > 4.90 ą 2% -1.9 2.96 ą 3% perf-profile.calltrace.cycles-pp.locks_remove_posix.filp_flush.filp_close.__do_sys_close_range.do_syscall_64 > > 2.63 ą 9% -1.9 0.76 ą 18% perf-profile.calltrace.cycles-pp.asm_sysvec_apic_timer_interrupt.filp_flush.filp_close.__do_sys_close_range.do_syscall_64 > > 4.44 -1.7 2.76 ą 2% perf-profile.calltrace.cycles-pp.dnotify_flush.filp_flush.filp_close.__do_sys_close_range.do_syscall_64 > > 2.50 ą 2% -0.9 1.56 ą 3% perf-profile.calltrace.cycles-pp.locks_remove_posix.filp_flush.filp_close.do_dup2.__x64_sys_dup2 > > 2.22 -0.8 1.42 ą 2% perf-profile.calltrace.cycles-pp.dnotify_flush.filp_flush.filp_close.do_dup2.__x64_sys_dup2 > > 1.66 ą 5% -0.3 1.37 ą 5% perf-profile.calltrace.cycles-pp.ksys_dup3.__x64_sys_dup2.do_syscall_64.entry_SYSCALL_64_after_hwframe.__dup2 > > 1.60 ą 5% -0.3 1.32 ą 5% perf-profile.calltrace.cycles-pp._raw_spin_lock.ksys_dup3.__x64_sys_dup2.do_syscall_64.entry_SYSCALL_64_after_hwframe > > 0.58 ą 2% +0.0 0.62 ą 2% perf-profile.calltrace.cycles-pp.do_read_fault.do_pte_missing.__handle_mm_fault.handle_mm_fault.do_user_addr_fault > > 0.54 ą 2% +0.0 0.58 ą 2% perf-profile.calltrace.cycles-pp.filemap_map_pages.do_read_fault.do_pte_missing.__handle_mm_fault.handle_mm_fault > > 0.72 ą 4% +0.1 0.79 ą 4% perf-profile.calltrace.cycles-pp._raw_spin_lock.__do_sys_close_range.do_syscall_64.entry_SYSCALL_64_after_hwframe.syscall > > 0.00 +1.8 1.79 ą 5% perf-profile.calltrace.cycles-pp.asm_sysvec_apic_timer_interrupt.fput_close.filp_close.__do_sys_close_range.do_syscall_64 > > 19.11 +4.4 23.49 perf-profile.calltrace.cycles-pp.filp_close.do_dup2.__x64_sys_dup2.do_syscall_64.entry_SYSCALL_64_after_hwframe > > 40.94 +6.5 47.46 perf-profile.calltrace.cycles-pp.filp_close.__do_sys_close_range.do_syscall_64.entry_SYSCALL_64_after_hwframe.syscall > > 42.24 +6.6 48.79 perf-profile.calltrace.cycles-pp.syscall > > 42.14 +6.6 48.72 perf-profile.calltrace.cycles-pp.entry_SYSCALL_64_after_hwframe.syscall > > 42.14 +6.6 48.72 perf-profile.calltrace.cycles-pp.do_syscall_64.entry_SYSCALL_64_after_hwframe.syscall > > 41.86 +6.6 48.46 perf-profile.calltrace.cycles-pp.__do_sys_close_range.do_syscall_64.entry_SYSCALL_64_after_hwframe.syscall > > 0.00 +14.6 14.60 ą 2% perf-profile.calltrace.cycles-pp.fput_close.filp_close.do_dup2.__x64_sys_dup2.do_syscall_64 > > 0.00 +29.0 28.95 ą 2% perf-profile.calltrace.cycles-pp.fput_close.filp_close.__do_sys_close_range.do_syscall_64.entry_SYSCALL_64_after_hwframe > > 45.76 -19.0 26.72 perf-profile.children.cycles-pp.filp_flush > > 14.67 -14.7 0.00 perf-profile.children.cycles-pp.fput > > 41.20 -5.9 35.30 perf-profile.children.cycles-pp.__dup2 > > 40.21 -5.5 34.71 perf-profile.children.cycles-pp.__x64_sys_dup2 > > 38.53 -5.2 33.33 perf-profile.children.cycles-pp.do_dup2 > > 7.81 ą 2% -3.1 4.74 ą 3% perf-profile.children.cycles-pp.locks_remove_posix > > 7.03 -2.6 4.40 ą 2% perf-profile.children.cycles-pp.dnotify_flush > > 1.24 ą 3% -0.4 0.86 ą 4% perf-profile.children.cycles-pp.syscall_exit_to_user_mode > > 1.67 ą 5% -0.3 1.37 ą 5% perf-profile.children.cycles-pp.ksys_dup3 > > 0.29 -0.1 0.22 ą 2% perf-profile.children.cycles-pp.update_load_avg > > 0.10 ą 10% -0.1 0.05 ą 46% perf-profile.children.cycles-pp.__x64_sys_fcntl > > 0.17 ą 7% -0.1 0.12 ą 4% perf-profile.children.cycles-pp.entry_SYSCALL_64 > > 0.15 ą 3% -0.0 0.10 ą 18% perf-profile.children.cycles-pp.clockevents_program_event > > 0.06 ą 11% -0.0 0.02 ą 99% perf-profile.children.cycles-pp.stress_close_func > > 0.13 ą 5% -0.0 0.10 ą 7% perf-profile.children.cycles-pp.__switch_to > > 0.06 ą 7% -0.0 0.04 ą 71% perf-profile.children.cycles-pp.lapic_next_deadline > > 0.11 ą 3% -0.0 0.09 ą 5% perf-profile.children.cycles-pp.__update_load_avg_cfs_rq > > 0.06 ą 6% +0.0 0.08 ą 6% perf-profile.children.cycles-pp.__folio_batch_add_and_move > > 0.26 ą 2% +0.0 0.28 ą 3% perf-profile.children.cycles-pp.folio_remove_rmap_ptes > > 0.08 ą 4% +0.0 0.11 ą 10% perf-profile.children.cycles-pp.set_pte_range > > 0.45 ą 2% +0.0 0.48 ą 2% perf-profile.children.cycles-pp.zap_present_ptes > > 0.18 ą 3% +0.0 0.21 ą 4% perf-profile.children.cycles-pp.folios_put_refs > > 0.29 ą 3% +0.0 0.32 ą 3% perf-profile.children.cycles-pp.__tlb_batch_free_encoded_pages > > 0.29 ą 3% +0.0 0.32 ą 3% perf-profile.children.cycles-pp.free_pages_and_swap_cache > > 0.34 ą 4% +0.0 0.38 ą 3% perf-profile.children.cycles-pp.tlb_finish_mmu > > 0.24 ą 3% +0.0 0.27 ą 5% perf-profile.children.cycles-pp._raw_spin_lock_irqsave > > 0.73 ą 2% +0.0 0.78 ą 2% perf-profile.children.cycles-pp.do_read_fault > > 0.69 ą 2% +0.0 0.74 ą 2% perf-profile.children.cycles-pp.filemap_map_pages > > 42.26 +6.5 48.80 perf-profile.children.cycles-pp.syscall > > 41.86 +6.6 48.46 perf-profile.children.cycles-pp.__do_sys_close_range > > 60.05 +10.9 70.95 perf-profile.children.cycles-pp.filp_close > > 0.00 +44.5 44.55 ą 2% perf-profile.children.cycles-pp.fput_close > > 14.31 ą 2% -14.3 0.00 perf-profile.self.cycles-pp.fput > > 30.12 ą 2% -13.0 17.09 perf-profile.self.cycles-pp.filp_flush > > 19.17 ą 2% -9.5 9.68 ą 3% perf-profile.self.cycles-pp.do_dup2 > > 7.63 ą 3% -3.0 4.62 ą 4% perf-profile.self.cycles-pp.locks_remove_posix > > 6.86 ą 3% -2.6 4.28 ą 3% perf-profile.self.cycles-pp.dnotify_flush > > 0.64 ą 4% -0.4 0.26 ą 4% perf-profile.self.cycles-pp.syscall_exit_to_user_mode > > 0.22 ą 10% -0.1 0.15 ą 11% perf-profile.self.cycles-pp.x64_sys_call > > 0.23 ą 3% -0.1 0.17 ą 8% perf-profile.self.cycles-pp.__schedule > > 0.08 ą 19% -0.1 0.03 ą100% perf-profile.self.cycles-pp.pick_eevdf > > 0.06 ą 7% -0.0 0.03 ą100% perf-profile.self.cycles-pp.lapic_next_deadline > > 0.13 ą 7% -0.0 0.10 ą 10% perf-profile.self.cycles-pp.__switch_to > > 0.09 ą 8% -0.0 0.06 ą 8% perf-profile.self.cycles-pp.__update_load_avg_se > > 0.08 ą 4% -0.0 0.05 ą 7% perf-profile.self.cycles-pp.asm_sysvec_apic_timer_interrupt > > 0.08 ą 9% -0.0 0.06 ą 11% perf-profile.self.cycles-pp.entry_SYSCALL_64 > > 0.06 ą 7% +0.0 0.08 ą 8% perf-profile.self.cycles-pp.filemap_map_pages > > 0.12 ą 3% +0.0 0.14 ą 4% perf-profile.self.cycles-pp.folios_put_refs > > 0.25 ą 2% +0.0 0.27 ą 3% perf-profile.self.cycles-pp.folio_remove_rmap_ptes > > 0.17 ą 5% +0.0 0.20 ą 6% perf-profile.self.cycles-pp._raw_spin_lock_irqsave > > 0.00 +0.1 0.07 ą 5% perf-profile.self.cycles-pp.do_nanosleep > > 0.00 +0.1 0.10 ą 15% perf-profile.self.cycles-pp.filp_close > > 0.00 +43.9 43.86 ą 2% perf-profile.self.cycles-pp.fput_close > > 2.12 ą 47% +151.1% 5.32 ą 28% perf-sched.sch_delay.avg.ms.__cond_resched.__do_sys_close_range.do_syscall_64.entry_SYSCALL_64_after_hwframe.[unknown] > > 0.28 ą 60% +990.5% 3.08 ą 53% perf-sched.sch_delay.avg.ms.__cond_resched.__kmalloc_cache_noprof.do_eventfd.__x64_sys_eventfd2.do_syscall_64 > > 0.96 ą 28% +35.5% 1.30 ą 25% perf-sched.sch_delay.avg.ms.__cond_resched.__kmalloc_noprof.load_elf_phdrs.load_elf_binary.exec_binprm > > 2.56 ą 43% +964.0% 27.27 ą161% perf-sched.sch_delay.avg.ms.__cond_resched.dput.open_last_lookups.path_openat.do_filp_open > > 12.80 ą139% +366.1% 59.66 ą107% perf-sched.sch_delay.avg.ms.__cond_resched.dput.shmem_unlink.vfs_unlink.do_unlinkat > > 2.78 ą 25% +50.0% 4.17 ą 19% perf-sched.sch_delay.avg.ms.__cond_resched.kmem_cache_alloc_lru_noprof.__d_alloc.d_alloc_cursor.dcache_dir_open > > 0.78 ą 18% +39.3% 1.09 ą 19% perf-sched.sch_delay.avg.ms.__cond_resched.kmem_cache_alloc_noprof.mas_alloc_nodes.mas_preallocate.vma_shrink > > 2.63 ą 10% +16.7% 3.07 ą 4% perf-sched.sch_delay.avg.ms.__cond_resched.kmem_cache_alloc_noprof.vm_area_alloc.__mmap_new_vma.__mmap_region > > 0.04 ą223% +3483.1% 1.38 ą 67% perf-sched.sch_delay.avg.ms.__cond_resched.netlink_release.__sock_release.sock_close.__fput > > 0.72 ą 17% +42.5% 1.02 ą 22% perf-sched.sch_delay.avg.ms.__cond_resched.stop_one_cpu.sched_exec.bprm_execve.part > > 0.35 ą134% +457.7% 1.94 ą 61% perf-sched.sch_delay.avg.ms.__cond_resched.task_numa_work.task_work_run.syscall_exit_to_user_mode.do_syscall_64 > > 1.88 ą 34% +574.9% 12.69 ą115% perf-sched.sch_delay.avg.ms.__cond_resched.task_work_run.syscall_exit_to_user_mode.do_syscall_64.entry_SYSCALL_64_after_hwframe > > 2.41 ą 10% +18.0% 2.84 ą 9% perf-sched.sch_delay.avg.ms.__cond_resched.wp_page_copy.__handle_mm_fault.handle_mm_fault.do_user_addr_fault > > 1.85 ą 36% +155.6% 4.73 ą 50% perf-sched.sch_delay.avg.ms.io_schedule.folio_wait_bit_common.__do_fault.do_read_fault > > 28.94 ą 26% -52.4% 13.78 ą 36% perf-sched.sch_delay.avg.ms.pipe_read.vfs_read.ksys_read.do_syscall_64 > > 2.24 ą 9% +22.1% 2.74 ą 8% perf-sched.sch_delay.avg.ms.schedule_preempt_disabled.rwsem_down_write_slowpath.down_write.unlink_file_vma_batch_final > > 2.19 ą 7% +17.3% 2.57 ą 6% perf-sched.sch_delay.avg.ms.schedule_preempt_disabled.rwsem_down_write_slowpath.down_write.vma_link_file > > 2.39 ą 6% +16.4% 2.79 ą 9% perf-sched.sch_delay.avg.ms.schedule_preempt_disabled.rwsem_down_write_slowpath.down_write.vma_prepare > > 0.34 ą 77% +1931.5% 6.95 ą 99% perf-sched.sch_delay.max.ms.__cond_resched.__kmalloc_cache_noprof.do_eventfd.__x64_sys_eventfd2.do_syscall_64 > > 29.69 ą 28% +129.5% 68.12 ą 28% perf-sched.sch_delay.max.ms.__cond_resched.__kmalloc_cache_noprof.perf_event_mmap_event.perf_event_mmap.__mmap_region > > 1.48 ą 96% +284.6% 5.68 ą 56% perf-sched.sch_delay.max.ms.__cond_resched.copy_strings_kernel.kernel_execve.call_usermodehelper_exec_async.ret_from_fork > > 3.59 ą 57% +124.5% 8.06 ą 45% perf-sched.sch_delay.max.ms.__cond_resched.down_read.mmap_read_lock_maybe_expand.get_arg_page.copy_string_kernel > > 3.39 ą 91% +112.0% 7.19 ą 44% perf-sched.sch_delay.max.ms.__cond_resched.down_read_killable.iterate_dir.__x64_sys_getdents64.do_syscall_64 > > 22.16 ą 77% +117.4% 48.17 ą 34% perf-sched.sch_delay.max.ms.__cond_resched.down_write_killable.exec_mmap.begin_new_exec.load_elf_binary > > 8.72 ą 17% +358.5% 39.98 ą 61% perf-sched.sch_delay.max.ms.__cond_resched.kmem_cache_alloc_noprof.mas_alloc_nodes.mas_preallocate.__mmap_new_vma > > 0.04 ą223% +3484.4% 1.38 ą 67% perf-sched.sch_delay.max.ms.__cond_resched.netlink_release.__sock_release.sock_close.__fput > > 0.53 ą154% +676.1% 4.12 ą 61% perf-sched.sch_delay.max.ms.__cond_resched.task_numa_work.task_work_run.syscall_exit_to_user_mode.do_syscall_64 > > 25.76 ą 70% +9588.9% 2496 ą127% perf-sched.sch_delay.max.ms.__cond_resched.task_work_run.syscall_exit_to_user_mode.do_syscall_64.entry_SYSCALL_64_after_hwframe > > 51.53 ą 26% -58.8% 21.22 ą106% perf-sched.sch_delay.max.ms.devkmsg_read.vfs_read.ksys_read.do_syscall_64 > > 4.97 ą 48% +154.8% 12.66 ą 75% perf-sched.sch_delay.max.ms.io_schedule.folio_wait_bit_common.__do_fault.do_read_fault > > 4.36 ą 48% +147.7% 10.81 ą 29% perf-sched.wait_and_delay.avg.ms.__cond_resched.__do_sys_close_range.do_syscall_64.entry_SYSCALL_64_after_hwframe.[unknown] > > 108632 ą 4% +23.9% 134575 ą 6% perf-sched.wait_and_delay.count.__cond_resched.__do_sys_close_range.do_syscall_64.entry_SYSCALL_64_after_hwframe.[unknown] > > 572.67 ą 6% +37.3% 786.17 ą 7% perf-sched.wait_and_delay.count.__cond_resched.__wait_for_common.affine_move_task.__set_cpus_allowed_ptr.__sched_setaffinity > > 596.67 ą 12% +43.9% 858.50 ą 13% perf-sched.wait_and_delay.count.__cond_resched.__wait_for_common.wait_for_completion_state.call_usermodehelper_exec.__request_module > > 294.83 ą 9% +31.1% 386.50 ą 11% perf-sched.wait_and_delay.count.__cond_resched.dput.terminate_walk.path_openat.do_filp_open > > 1223275 ą 2% -17.7% 1006293 ą 6% perf-sched.wait_and_delay.count.do_nanosleep.hrtimer_nanosleep.common_nsleep.__x64_sys_clock_nanosleep > > 2772 ą 11% +43.6% 3980 ą 11% perf-sched.wait_and_delay.count.do_wait.kernel_wait.call_usermodehelper_exec_work.process_one_work > > 11690 ą 7% +29.8% 15173 ą 10% perf-sched.wait_and_delay.count.io_schedule.folio_wait_bit_common.filemap_fault.__do_fault > > 4072 ą100% +163.7% 10737 ą 7% perf-sched.wait_and_delay.count.irqentry_exit_to_user_mode.asm_exc_page_fault.[unknown].[unknown] > > 8811 ą 6% +26.2% 11117 ą 9% perf-sched.wait_and_delay.count.irqentry_exit_to_user_mode.asm_sysvec_apic_timer_interrupt.[unknown].[unknown] > > 662.17 ą 29% +187.8% 1905 ą 29% perf-sched.wait_and_delay.count.pipe_read.vfs_read.ksys_read.do_syscall_64 > > 15.50 ą 11% +48.4% 23.00 ą 16% perf-sched.wait_and_delay.count.schedule_hrtimeout_range.do_poll.constprop.0.do_sys_poll > > 167.67 ą 20% +48.0% 248.17 ą 26% perf-sched.wait_and_delay.count.schedule_preempt_disabled.rwsem_down_write_slowpath.down_write.open_last_lookups > > 2680 ą 12% +42.5% 3820 ą 11% perf-sched.wait_and_delay.count.schedule_timeout.___down_common.__down_timeout.down_timeout > > 137.17 ą 13% +31.8% 180.83 ą 9% perf-sched.wait_and_delay.count.schedule_timeout.__wait_for_common.wait_for_completion_state.__wait_rcu_gp > > 2636 ą 12% +43.1% 3772 ą 12% perf-sched.wait_and_delay.count.schedule_timeout.__wait_for_common.wait_for_completion_state.call_usermodehelper_exec > > 10.50 ą 11% +74.6% 18.33 ą 23% perf-sched.wait_and_delay.count.schedule_timeout.kcompactd.kthread.ret_from_fork > > 5619 ą 5% +38.8% 7797 ą 9% perf-sched.wait_and_delay.count.smpboot_thread_fn.kthread.ret_from_fork.ret_from_fork_asm > > 70455 ą 4% +32.3% 93197 ą 6% perf-sched.wait_and_delay.count.syscall_exit_to_user_mode.do_syscall_64.entry_SYSCALL_64_after_hwframe.[unknown] > > 6990 ą 4% +37.4% 9603 ą 9% perf-sched.wait_and_delay.count.worker_thread.kthread.ret_from_fork.ret_from_fork_asm > > 191.28 ą124% +1455.2% 2974 ą100% perf-sched.wait_and_delay.max.ms.__cond_resched.dput.path_openat.do_filp_open.do_sys_openat2 > > 2.24 ą 48% +144.6% 5.48 ą 29% perf-sched.wait_time.avg.ms.__cond_resched.__do_sys_close_range.do_syscall_64.entry_SYSCALL_64_after_hwframe.[unknown] > > 8.06 ą101% +618.7% 57.94 ą 68% perf-sched.wait_time.avg.ms.__cond_resched.__fput.__x64_sys_close.do_syscall_64.entry_SYSCALL_64_after_hwframe > > 0.28 ą146% +370.9% 1.30 ą 64% perf-sched.wait_time.avg.ms.__cond_resched.down_write.__split_vma.vms_gather_munmap_vmas.do_vmi_align_munmap > > 3.86 ą 5% +86.0% 7.18 ą 44% perf-sched.wait_time.avg.ms.__cond_resched.down_write.free_pgtables.exit_mmap.__mmput > > 2.54 ą 29% +51.6% 3.85 ą 12% perf-sched.wait_time.avg.ms.__cond_resched.down_write_killable.__do_sys_brk.do_syscall_64.entry_SYSCALL_64_after_hwframe > > 1.11 ą 39% +201.6% 3.36 ą 47% perf-sched.wait_time.avg.ms.__cond_resched.down_write_killable.exec_mmap.begin_new_exec.load_elf_binary > > 3.60 ą 68% +1630.2% 62.29 ą153% perf-sched.wait_time.avg.ms.__cond_resched.dput.step_into.link_path_walk.part > > 0.20 ą 64% +115.4% 0.42 ą 42% perf-sched.wait_time.avg.ms.__cond_resched.filemap_read.__kernel_read.load_elf_binary.exec_binprm > > 55.51 ą 53% +218.0% 176.54 ą 83% perf-sched.wait_time.avg.ms.__cond_resched.kmem_cache_alloc_noprof.security_inode_alloc.inode_init_always_gfp.alloc_inode > > 3.22 ą 3% +15.4% 3.72 ą 9% perf-sched.wait_time.avg.ms.__cond_resched.kmem_cache_alloc_noprof.vm_area_dup.__split_vma.vms_gather_munmap_vmas > > 0.04 ą223% +37562.8% 14.50 ą198% perf-sched.wait_time.avg.ms.__cond_resched.netlink_release.__sock_release.sock_close.__fput > > 1.19 ą 30% +59.3% 1.90 ą 34% perf-sched.wait_time.avg.ms.__cond_resched.remove_vma.vms_complete_munmap_vmas.do_vmi_align_munmap.do_vmi_munmap > > 0.36 ą133% +447.8% 1.97 ą 60% perf-sched.wait_time.avg.ms.__cond_resched.task_numa_work.task_work_run.syscall_exit_to_user_mode.do_syscall_64 > > 1.73 ą 47% +165.0% 4.58 ą 51% perf-sched.wait_time.avg.ms.io_schedule.folio_wait_bit_common.__do_fault.do_read_fault > > 1.10 ą 21% +693.9% 8.70 ą 70% perf-sched.wait_time.avg.ms.irqentry_exit_to_user_mode.asm_sysvec_call_function_single.[unknown] > > 54.56 ą 32% +400.2% 272.90 ą 67% perf-sched.wait_time.avg.ms.schedule_timeout.__wait_for_common.wait_for_completion_state.kernel_clone > > 10.87 ą 18% +151.7% 27.36 ą 68% perf-sched.wait_time.max.ms.__cond_resched.__anon_vma_prepare.__vmf_anon_prepare.do_pte_missing.__handle_mm_fault > > 123.35 ą181% +1219.3% 1627 ą 82% perf-sched.wait_time.max.ms.__cond_resched.__fput.__x64_sys_close.do_syscall_64.entry_SYSCALL_64_after_hwframe > > 9.68 ą108% +5490.2% 541.19 ą185% perf-sched.wait_time.max.ms.__cond_resched.__kmalloc_cache_noprof.do_epoll_create.__x64_sys_epoll_create.do_syscall_64 > > 3.39 ą 91% +112.0% 7.19 ą 44% perf-sched.wait_time.max.ms.__cond_resched.down_read_killable.iterate_dir.__x64_sys_getdents64.do_syscall_64 > > 1.12 ą128% +407.4% 5.67 ą 52% perf-sched.wait_time.max.ms.__cond_resched.down_write.__split_vma.vms_gather_munmap_vmas.do_vmi_align_munmap > > 30.58 ą 29% +1741.1% 563.04 ą 80% perf-sched.wait_time.max.ms.__cond_resched.down_write.free_pgtables.exit_mmap.__mmput > > 3.82 ą114% +232.1% 12.70 ą 49% perf-sched.wait_time.max.ms.__cond_resched.down_write.vms_gather_munmap_vmas.__mmap_prepare.__mmap_region > > 7.75 ą 46% +72.4% 13.36 ą 32% perf-sched.wait_time.max.ms.__cond_resched.down_write_killable.__do_sys_brk.do_syscall_64.entry_SYSCALL_64_after_hwframe > > 13.39 ą 48% +259.7% 48.17 ą 34% perf-sched.wait_time.max.ms.__cond_resched.down_write_killable.exec_mmap.begin_new_exec.load_elf_binary > > 12.46 ą 30% +90.5% 23.73 ą 34% perf-sched.wait_time.max.ms.__cond_resched.down_write_killable.vm_mmap_pgoff.ksys_mmap_pgoff.do_syscall_64 > > 479.90 ą 78% +496.9% 2864 ą141% perf-sched.wait_time.max.ms.__cond_resched.dput.open_last_lookups.path_openat.do_filp_open > > 185.75 ą116% +875.0% 1811 ą 84% perf-sched.wait_time.max.ms.__cond_resched.dput.path_openat.do_filp_open.do_sys_openat2 > > 2.52 ą 44% +105.2% 5.18 ą 36% perf-sched.wait_time.max.ms.__cond_resched.kmem_cache_alloc_noprof.vm_area_alloc.alloc_bprm.kernel_execve > > 0.04 ą223% +37564.1% 14.50 ą198% perf-sched.wait_time.max.ms.__cond_resched.netlink_release.__sock_release.sock_close.__fput > > 0.54 ą153% +669.7% 4.15 ą 61% perf-sched.wait_time.max.ms.__cond_resched.task_numa_work.task_work_run.syscall_exit_to_user_mode.do_syscall_64 > > 28.22 ą 14% +41.2% 39.84 ą 25% perf-sched.wait_time.max.ms.__cond_resched.unmap_vmas.vms_clear_ptes.part.0 > > 4.90 ą 51% +158.2% 12.66 ą 75% perf-sched.wait_time.max.ms.io_schedule.folio_wait_bit_common.__do_fault.do_read_fault > > 26.54 ą 66% +5220.1% 1411 ą 84% perf-sched.wait_time.max.ms.irqentry_exit_to_user_mode.asm_sysvec_call_function_single.[unknown] > > 1262 ą 9% +434.3% 6744 ą 60% perf-sched.wait_time.max.ms.schedule_timeout.__wait_for_common.wait_for_completion_state.kernel_clone > > > > > > > > > > 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 > > > > > -- > Mateusz Guzik <mjguzik gmail.com> -- Mateusz Guzik <mjguzik gmail.com> ^ permalink raw reply [flat|nested] 6+ messages in thread
* Re: [linus:master] [fs] a914bd93f3: stress-ng.close.close_calls_per_sec 52.2% regression 2025-04-17 10:02 ` Mateusz Guzik @ 2025-04-17 10:17 ` Mateusz Guzik 2025-04-18 8:12 ` Oliver Sang 0 siblings, 1 reply; 6+ messages in thread From: Mateusz Guzik @ 2025-04-17 10:17 UTC (permalink / raw) To: kernel test robot Cc: oe-lkp, lkp, linux-kernel, Christian Brauner, linux-fsdevel On Thu, Apr 17, 2025 at 12:02:55PM +0200, Mateusz Guzik wrote: > bottom line though is there is a known tradeoff there and stress-ng > manufactures a case where it is always the wrong one. > > fd 2 at hand is inherited (it's the tty) and shared between *all* > workers on all CPUs. > > Ignoring some fluff, it's this in a loop: > dup2(2, 1024) = 1024 > dup2(2, 1025) = 1025 > dup2(2, 1026) = 1026 > dup2(2, 1027) = 1027 > dup2(2, 1028) = 1028 > dup2(2, 1029) = 1029 > dup2(2, 1030) = 1030 > dup2(2, 1031) = 1031 > [..] > close_range(1024, 1032, 0) = 0 > > where fd 2 is the same file object in all 192 workers doing this. > the following will still have *some* impact, but the drop should be much lower it also has a side effect of further helping the single-threaded case by shortening the code when it works diff --git a/include/linux/file_ref.h b/include/linux/file_ref.h index 7db62fbc0500..c73865ed4251 100644 --- a/include/linux/file_ref.h +++ b/include/linux/file_ref.h @@ -181,17 +181,15 @@ static __always_inline __must_check bool file_ref_put_close(file_ref_t *ref) long old, new; old = atomic_long_read(&ref->refcnt); - do { - if (unlikely(old < 0)) - return __file_ref_put_badval(ref, old); - - if (old == FILE_REF_ONEREF) - new = FILE_REF_DEAD; - else - new = old - 1; - } while (!atomic_long_try_cmpxchg(&ref->refcnt, &old, new)); - - return new == FILE_REF_DEAD; + if (likely(old == FILE_REF_ONEREF)) { + new = FILE_REF_DEAD; + if (likely(atomic_long_try_cmpxchg(&ref->refcnt, &old, new))) + return true; + /* + * The ref has changed from under us, don't play any games. + */ + } + return file_ref_put(ref); } /** ^ permalink raw reply [flat|nested] 6+ messages in thread
* Re: [linus:master] [fs] a914bd93f3: stress-ng.close.close_calls_per_sec 52.2% regression 2025-04-17 10:17 ` Mateusz Guzik @ 2025-04-18 8:12 ` Oliver Sang 2025-04-18 11:46 ` Mateusz Guzik 0 siblings, 1 reply; 6+ messages in thread From: Oliver Sang @ 2025-04-18 8:12 UTC (permalink / raw) To: Mateusz Guzik Cc: oe-lkp, lkp, linux-kernel, Christian Brauner, linux-fsdevel, oliver.sang hi, Mateusz Guzik, On Thu, Apr 17, 2025 at 12:17:54PM +0200, Mateusz Guzik wrote: > On Thu, Apr 17, 2025 at 12:02:55PM +0200, Mateusz Guzik wrote: > > bottom line though is there is a known tradeoff there and stress-ng > > manufactures a case where it is always the wrong one. > > > > fd 2 at hand is inherited (it's the tty) and shared between *all* > > workers on all CPUs. > > > > Ignoring some fluff, it's this in a loop: > > dup2(2, 1024) = 1024 > > dup2(2, 1025) = 1025 > > dup2(2, 1026) = 1026 > > dup2(2, 1027) = 1027 > > dup2(2, 1028) = 1028 > > dup2(2, 1029) = 1029 > > dup2(2, 1030) = 1030 > > dup2(2, 1031) = 1031 > > [..] > > close_range(1024, 1032, 0) = 0 > > > > where fd 2 is the same file object in all 192 workers doing this. > > > > the following will still have *some* impact, but the drop should be much > lower > > it also has a side effect of further helping the single-threaded case by > shortening the code when it works we applied below patch upon a914bd93f3. it seems it not only recovers the regression we saw on a914bd93f3, but also causes further performance benefit that it's +29.4% better than 3e46a92a27 (parent of a914bd93f3). at the same time, I also list stress-ng.close.ops_per_sec here which is not in our original report since the data has overlap so our code logic don't think they are reliable then will not list in table without some 'force' option. in a stress-ng close test, the output looks like below: 2025-04-18 02:58:28 stress-ng --timeout 60 --times --verify --metrics --no-rand-seed --close 192 stress-ng: info: [6268] setting to a 1 min run per stressor stress-ng: info: [6268] dispatching hogs: 192 close stress-ng: info: [6268] note: /proc/sys/kernel/sched_autogroup_enabled is 1 and this can impact scheduling throughput for processes not attached to a tty. Setting this to 0 may improve performance metrics stress-ng: metrc: [6268] stressor bogo ops real time usr time sys time bogo ops/s bogo ops/s CPU used per RSS Max stress-ng: metrc: [6268] (secs) (secs) (secs) (real time) (usr+sys time) instance (%) (KB) stress-ng: metrc: [6268] close 1568702 60.08 171.29 9524.58 26108.29 161.79 84.05 1548 <--- (1) stress-ng: metrc: [6268] miscellaneous metrics: stress-ng: metrc: [6268] close 600923.80 close calls per sec (harmonic mean of 192 instances) <--- (2) stress-ng: info: [6268] for a 60.14s run time: stress-ng: info: [6268] 11547.73s available CPU time stress-ng: info: [6268] 171.29s user time ( 1.48%) stress-ng: info: [6268] 9525.12s system time ( 82.48%) stress-ng: info: [6268] 9696.41s total time ( 83.97%) stress-ng: info: [6268] load average: 520.00 149.63 51.46 stress-ng: info: [6268] skipped: 0 stress-ng: info: [6268] passed: 192: close (192) stress-ng: info: [6268] failed: 0 stress-ng: info: [6268] metrics untrustworthy: 0 stress-ng: info: [6268] successful run completed in 1 min the stress-ng.close.close_calls_per_sec data is from (2) the stress-ng.close.ops_per_sec data is from line (1), bogo ops/s (real time) from below, seems a914bd93f3 also has a small regression for stress-ng.close.ops_per_sec but not obvious since data is not stable enough. 9f0124114f almost has same data as 3e46a92a27 regarding to this stress-ng.close.ops_per_sec. summary data: ========================================================================================= compiler/cpufreq_governor/kconfig/nr_threads/rootfs/tbox_group/test/testcase/testtime: gcc-12/performance/x86_64-rhel-9.4/100%/debian-12-x86_64-20240206.cgz/igk-spr-2sp1/close/stress-ng/60s commit: 3e46a92a27 ("fs: use fput_close_sync() in close()") a914bd93f3 ("fs: use fput_close() in filp_close()") 9f0124114f <--- a914bd93f3 + patch 3e46a92a27c2927f a914bd93f3edfedcdd59deb615e 9f0124114f707363af03caed5ae ---------------- --------------------------- --------------------------- %stddev %change %stddev %change %stddev \ | \ | \ 473980 ± 14% -52.2% 226559 ± 13% +29.4% 613288 ± 12% stress-ng.close.close_calls_per_sec 1677393 ± 3% -6.0% 1576636 ± 5% +0.6% 1686892 ± 3% stress-ng.close.ops 27917 ± 3% -6.0% 26237 ± 5% +0.6% 28074 ± 3% stress-ng.close.ops_per_sec full data is as [1] > > diff --git a/include/linux/file_ref.h b/include/linux/file_ref.h > index 7db62fbc0500..c73865ed4251 100644 > --- a/include/linux/file_ref.h > +++ b/include/linux/file_ref.h > @@ -181,17 +181,15 @@ static __always_inline __must_check bool file_ref_put_close(file_ref_t *ref) > long old, new; > > old = atomic_long_read(&ref->refcnt); > - do { > - if (unlikely(old < 0)) > - return __file_ref_put_badval(ref, old); > - > - if (old == FILE_REF_ONEREF) > - new = FILE_REF_DEAD; > - else > - new = old - 1; > - } while (!atomic_long_try_cmpxchg(&ref->refcnt, &old, new)); > - > - return new == FILE_REF_DEAD; > + if (likely(old == FILE_REF_ONEREF)) { > + new = FILE_REF_DEAD; > + if (likely(atomic_long_try_cmpxchg(&ref->refcnt, &old, new))) > + return true; > + /* > + * The ref has changed from under us, don't play any games. > + */ > + } > + return file_ref_put(ref); > } > > /** [1] ========================================================================================= compiler/cpufreq_governor/kconfig/nr_threads/rootfs/tbox_group/test/testcase/testtime: gcc-12/performance/x86_64-rhel-9.4/100%/debian-12-x86_64-20240206.cgz/igk-spr-2sp1/close/stress-ng/60s commit: 3e46a92a27 ("fs: use fput_close_sync() in close()") a914bd93f3 ("fs: use fput_close() in filp_close()") 9f0124114f <--- a914bd93f3 + patch 3e46a92a27c2927f a914bd93f3edfedcdd59deb615e 9f0124114f707363af03caed5ae ---------------- --------------------------- --------------------------- %stddev %change %stddev %change %stddev \ | \ | \ 355470 ± 14% -17.6% 292767 ± 7% -8.9% 323894 ± 6% cpuidle..usage 5.19 -0.6 4.61 ± 3% -0.0 5.18 ± 2% mpstat.cpu.all.usr% 495615 ± 7% -38.5% 304839 ± 8% -5.5% 468431 ± 7% vmstat.system.cs 780096 ± 5% -23.5% 596446 ± 3% -4.7% 743238 ± 5% vmstat.system.in 4004843 ± 8% -21.1% 3161813 ± 8% -6.2% 3758245 ± 10% time.involuntary_context_switches 9475 +1.1% 9582 +0.3% 9504 time.system_time 183.50 ± 2% -37.8% 114.20 ± 3% -3.4% 177.34 ± 2% time.user_time 25637892 ± 6% -42.6% 14725385 ± 9% -6.4% 23992138 ± 7% time.voluntary_context_switches 2512168 ± 17% -45.8% 1361659 ± 71% +0.5% 2524627 ± 15% sched_debug.cfs_rq:/.avg_vruntime.min 2512168 ± 17% -45.8% 1361659 ± 71% +0.5% 2524627 ± 15% sched_debug.cfs_rq:/.min_vruntime.min 700402 ± 2% +19.8% 838744 ± 10% +5.0% 735486 ± 4% sched_debug.cpu.avg_idle.avg 81230 ± 6% -59.6% 32788 ± 69% -6.1% 76301 ± 7% sched_debug.cpu.nr_switches.avg 27992 ± 20% -70.2% 8345 ± 74% +11.7% 31275 ± 26% sched_debug.cpu.nr_switches.min 473980 ± 14% -52.2% 226559 ± 13% +29.4% 613288 ± 12% stress-ng.close.close_calls_per_sec 1677393 ± 3% -6.0% 1576636 ± 5% +0.6% 1686892 ± 3% stress-ng.close.ops 27917 ± 3% -6.0% 26237 ± 5% +0.6% 28074 ± 3% stress-ng.close.ops_per_sec 4004843 ± 8% -21.1% 3161813 ± 8% -6.2% 3758245 ± 10% stress-ng.time.involuntary_context_switches 9475 +1.1% 9582 +0.3% 9504 stress-ng.time.system_time 183.50 ± 2% -37.8% 114.20 ± 3% -3.4% 177.34 ± 2% stress-ng.time.user_time 25637892 ± 6% -42.6% 14725385 ± 9% -6.4% 23992138 ± 7% stress-ng.time.voluntary_context_switches 23.01 ± 2% -1.4 21.61 ± 3% +0.1 23.13 ± 2% perf-stat.i.cache-miss-rate% 17981659 -10.8% 16035508 ± 4% -0.5% 17886941 ± 4% perf-stat.i.cache-misses 77288888 ± 2% -6.5% 72260357 ± 4% -1.7% 75978329 ± 3% perf-stat.i.cache-references 504949 ± 6% -38.1% 312536 ± 8% -5.7% 476406 ± 7% perf-stat.i.context-switches 33030 +15.7% 38205 ± 4% +1.3% 33444 ± 4% perf-stat.i.cycles-between-cache-misses 4.34 ± 10% -38.3% 2.68 ± 20% +0.1% 4.34 ± 11% perf-stat.i.metric.K/sec 26229 ± 44% +37.8% 36145 ± 4% +21.8% 31948 ± 4% perf-stat.overall.cycles-between-cache-misses 2.12 ± 47% +151.1% 5.32 ± 28% -13.5% 1.84 ± 27% perf-sched.sch_delay.avg.ms.__cond_resched.__do_sys_close_range.do_syscall_64.entry_SYSCALL_64_after_hwframe.[unknown] 0.28 ± 60% +990.5% 3.08 ± 53% +6339.3% 18.16 ±314% perf-sched.sch_delay.avg.ms.__cond_resched.__kmalloc_cache_noprof.do_eventfd.__x64_sys_eventfd2.do_syscall_64 0.96 ± 28% +35.5% 1.30 ± 25% -7.5% 0.89 ± 29% perf-sched.sch_delay.avg.ms.__cond_resched.__kmalloc_noprof.load_elf_phdrs.load_elf_binary.exec_binprm 2.56 ± 43% +964.0% 27.27 ±161% +456.1% 14.25 ±127% perf-sched.sch_delay.avg.ms.__cond_resched.dput.open_last_lookups.path_openat.do_filp_open 12.80 ±139% +366.1% 59.66 ±107% +242.3% 43.82 ±204% perf-sched.sch_delay.avg.ms.__cond_resched.dput.shmem_unlink.vfs_unlink.do_unlinkat 2.78 ± 25% +50.0% 4.17 ± 19% +22.2% 3.40 ± 18% perf-sched.sch_delay.avg.ms.__cond_resched.kmem_cache_alloc_lru_noprof.__d_alloc.d_alloc_cursor.dcache_dir_open 0.78 ± 18% +39.3% 1.09 ± 19% +24.7% 0.97 ± 36% perf-sched.sch_delay.avg.ms.__cond_resched.kmem_cache_alloc_noprof.mas_alloc_nodes.mas_preallocate.vma_shrink 2.63 ± 10% +16.7% 3.07 ± 4% +1.3% 2.67 ± 15% perf-sched.sch_delay.avg.ms.__cond_resched.kmem_cache_alloc_noprof.vm_area_alloc.__mmap_new_vma.__mmap_region 0.04 ±223% +3483.1% 1.38 ± 67% +2231.2% 0.90 ±243% perf-sched.sch_delay.avg.ms.__cond_resched.netlink_release.__sock_release.sock_close.__fput 0.72 ± 17% +42.5% 1.02 ± 22% +20.4% 0.86 ± 15% perf-sched.sch_delay.avg.ms.__cond_resched.stop_one_cpu.sched_exec.bprm_execve.part 0.35 ±134% +457.7% 1.94 ± 61% +177.7% 0.97 ±104% perf-sched.sch_delay.avg.ms.__cond_resched.task_numa_work.task_work_run.syscall_exit_to_user_mode.do_syscall_64 1.88 ± 34% +574.9% 12.69 ±115% +389.0% 9.20 ±214% perf-sched.sch_delay.avg.ms.__cond_resched.task_work_run.syscall_exit_to_user_mode.do_syscall_64.entry_SYSCALL_64_after_hwframe 2.41 ± 10% +18.0% 2.84 ± 9% +62.4% 3.91 ± 81% perf-sched.sch_delay.avg.ms.__cond_resched.wp_page_copy.__handle_mm_fault.handle_mm_fault.do_user_addr_fault 1.85 ± 36% +155.6% 4.73 ± 50% +27.5% 2.36 ± 54% perf-sched.sch_delay.avg.ms.io_schedule.folio_wait_bit_common.__do_fault.do_read_fault 28.94 ± 26% -52.4% 13.78 ± 36% -29.1% 20.52 ± 50% perf-sched.sch_delay.avg.ms.pipe_read.vfs_read.ksys_read.do_syscall_64 2.24 ± 9% +22.1% 2.74 ± 8% +14.2% 2.56 ± 14% perf-sched.sch_delay.avg.ms.schedule_preempt_disabled.rwsem_down_write_slowpath.down_write.unlink_file_vma_batch_final 2.19 ± 7% +17.3% 2.57 ± 6% +6.4% 2.33 ± 6% perf-sched.sch_delay.avg.ms.schedule_preempt_disabled.rwsem_down_write_slowpath.down_write.vma_link_file 2.39 ± 6% +16.4% 2.79 ± 9% +12.3% 2.69 ± 8% perf-sched.sch_delay.avg.ms.schedule_preempt_disabled.rwsem_down_write_slowpath.down_write.vma_prepare 0.34 ± 77% +1931.5% 6.95 ± 99% +5218.5% 18.19 ±313% perf-sched.sch_delay.max.ms.__cond_resched.__kmalloc_cache_noprof.do_eventfd.__x64_sys_eventfd2.do_syscall_64 29.69 ± 28% +129.5% 68.12 ± 28% +11.1% 32.99 ± 30% perf-sched.sch_delay.max.ms.__cond_resched.__kmalloc_cache_noprof.perf_event_mmap_event.perf_event_mmap.__mmap_region 7.71 ± 21% +10.4% 8.51 ± 25% -30.5% 5.36 ± 30% perf-sched.sch_delay.max.ms.__cond_resched.__kmalloc_node_noprof.seq_read_iter.vfs_read.ksys_read 1.48 ± 96% +284.6% 5.68 ± 56% -39.2% 0.90 ±112% perf-sched.sch_delay.max.ms.__cond_resched.copy_strings_kernel.kernel_execve.call_usermodehelper_exec_async.ret_from_fork 3.59 ± 57% +124.5% 8.06 ± 45% +44.7% 5.19 ± 72% perf-sched.sch_delay.max.ms.__cond_resched.down_read.mmap_read_lock_maybe_expand.get_arg_page.copy_string_kernel 3.39 ± 91% +112.0% 7.19 ± 44% +133.6% 7.92 ±129% perf-sched.sch_delay.max.ms.__cond_resched.down_read_killable.iterate_dir.__x64_sys_getdents64.do_syscall_64 22.16 ± 77% +117.4% 48.17 ± 34% +41.9% 31.45 ± 54% perf-sched.sch_delay.max.ms.__cond_resched.down_write_killable.exec_mmap.begin_new_exec.load_elf_binary 8.72 ± 17% +358.5% 39.98 ± 61% +98.6% 17.32 ± 77% perf-sched.sch_delay.max.ms.__cond_resched.kmem_cache_alloc_noprof.mas_alloc_nodes.mas_preallocate.__mmap_new_vma 35.71 ± 49% +1.8% 36.35 ± 37% -48.6% 18.34 ± 25% perf-sched.sch_delay.max.ms.__cond_resched.kmem_cache_alloc_noprof.vm_area_dup.__split_vma.vms_gather_munmap_vmas 0.04 ±223% +3484.4% 1.38 ± 67% +2231.2% 0.90 ±243% perf-sched.sch_delay.max.ms.__cond_resched.netlink_release.__sock_release.sock_close.__fput 0.53 ±154% +676.1% 4.12 ± 61% +161.0% 1.39 ±109% perf-sched.sch_delay.max.ms.__cond_resched.task_numa_work.task_work_run.syscall_exit_to_user_mode.do_syscall_64 25.76 ± 70% +9588.9% 2496 ±127% +2328.6% 625.69 ±272% perf-sched.sch_delay.max.ms.__cond_resched.task_work_run.syscall_exit_to_user_mode.do_syscall_64.entry_SYSCALL_64_after_hwframe 51.53 ± 26% -58.8% 21.22 ±106% +13.1% 58.30 ±190% perf-sched.sch_delay.max.ms.devkmsg_read.vfs_read.ksys_read.do_syscall_64 4.97 ± 48% +154.8% 12.66 ± 75% +25.0% 6.21 ± 42% perf-sched.sch_delay.max.ms.io_schedule.folio_wait_bit_common.__do_fault.do_read_fault 4.36 ± 48% +147.7% 10.81 ± 29% -14.1% 3.75 ± 26% perf-sched.wait_and_delay.avg.ms.__cond_resched.__do_sys_close_range.do_syscall_64.entry_SYSCALL_64_after_hwframe.[unknown] 108632 ± 4% +23.9% 134575 ± 6% -1.3% 107223 ± 4% perf-sched.wait_and_delay.count.__cond_resched.__do_sys_close_range.do_syscall_64.entry_SYSCALL_64_after_hwframe.[unknown] 572.67 ± 6% +37.3% 786.17 ± 7% +1.9% 583.75 ± 8% perf-sched.wait_and_delay.count.__cond_resched.__wait_for_common.affine_move_task.__set_cpus_allowed_ptr.__sched_setaffinity 596.67 ± 12% +43.9% 858.50 ± 13% +2.4% 610.75 ± 8% perf-sched.wait_and_delay.count.__cond_resched.__wait_for_common.wait_for_completion_state.call_usermodehelper_exec.__request_module 294.83 ± 9% +31.1% 386.50 ± 11% +1.7% 299.75 ± 11% perf-sched.wait_and_delay.count.__cond_resched.dput.terminate_walk.path_openat.do_filp_open 1223275 ± 2% -17.7% 1006293 ± 6% +0.5% 1228897 perf-sched.wait_and_delay.count.do_nanosleep.hrtimer_nanosleep.common_nsleep.__x64_sys_clock_nanosleep 2772 ± 11% +43.6% 3980 ± 11% +6.6% 2954 ± 9% perf-sched.wait_and_delay.count.do_wait.kernel_wait.call_usermodehelper_exec_work.process_one_work 11690 ± 7% +29.8% 15173 ± 10% +5.6% 12344 ± 7% perf-sched.wait_and_delay.count.io_schedule.folio_wait_bit_common.filemap_fault.__do_fault 4072 ±100% +163.7% 10737 ± 7% +59.4% 6491 ± 58% perf-sched.wait_and_delay.count.irqentry_exit_to_user_mode.asm_exc_page_fault.[unknown].[unknown] 8811 ± 6% +26.2% 11117 ± 9% +2.6% 9039 ± 8% perf-sched.wait_and_delay.count.irqentry_exit_to_user_mode.asm_sysvec_apic_timer_interrupt.[unknown].[unknown] 662.17 ± 29% +187.8% 1905 ± 29% +36.2% 901.58 ± 32% perf-sched.wait_and_delay.count.pipe_read.vfs_read.ksys_read.do_syscall_64 15.50 ± 11% +48.4% 23.00 ± 16% -6.5% 14.50 ± 24% perf-sched.wait_and_delay.count.schedule_hrtimeout_range.do_poll.constprop.0.do_sys_poll 167.67 ± 20% +48.0% 248.17 ± 26% -8.3% 153.83 ± 27% perf-sched.wait_and_delay.count.schedule_preempt_disabled.rwsem_down_write_slowpath.down_write.open_last_lookups 2680 ± 12% +42.5% 3820 ± 11% +6.7% 2860 ± 9% perf-sched.wait_and_delay.count.schedule_timeout.___down_common.__down_timeout.down_timeout 137.17 ± 13% +31.8% 180.83 ± 9% +12.4% 154.17 ± 16% perf-sched.wait_and_delay.count.schedule_timeout.__wait_for_common.wait_for_completion_state.__wait_rcu_gp 2636 ± 12% +43.1% 3772 ± 12% +6.1% 2797 ± 10% perf-sched.wait_and_delay.count.schedule_timeout.__wait_for_common.wait_for_completion_state.call_usermodehelper_exec 10.50 ± 11% +74.6% 18.33 ± 23% +19.0% 12.50 ± 18% perf-sched.wait_and_delay.count.schedule_timeout.kcompactd.kthread.ret_from_fork 5619 ± 5% +38.8% 7797 ± 9% +9.2% 6136 ± 8% perf-sched.wait_and_delay.count.smpboot_thread_fn.kthread.ret_from_fork.ret_from_fork_asm 70455 ± 4% +32.3% 93197 ± 6% +1.1% 71250 ± 3% perf-sched.wait_and_delay.count.syscall_exit_to_user_mode.do_syscall_64.entry_SYSCALL_64_after_hwframe.[unknown] 6990 ± 4% +37.4% 9603 ± 9% +7.7% 7528 ± 5% perf-sched.wait_and_delay.count.worker_thread.kthread.ret_from_fork.ret_from_fork_asm 191.28 ±124% +1455.2% 2974 ±100% +428.0% 1009 ±166% perf-sched.wait_and_delay.max.ms.__cond_resched.dput.path_openat.do_filp_open.do_sys_openat2 1758 ±118% -87.9% 211.89 ±211% -96.6% 59.86 ±184% perf-sched.wait_and_delay.max.ms.devkmsg_read.vfs_read.ksys_read.do_syscall_64 2.24 ± 48% +144.6% 5.48 ± 29% -14.7% 1.91 ± 25% perf-sched.wait_time.avg.ms.__cond_resched.__do_sys_close_range.do_syscall_64.entry_SYSCALL_64_after_hwframe.[unknown] 8.06 ±101% +618.7% 57.94 ± 68% +332.7% 34.88 ±100% perf-sched.wait_time.avg.ms.__cond_resched.__fput.__x64_sys_close.do_syscall_64.entry_SYSCALL_64_after_hwframe 0.28 ±146% +370.9% 1.30 ± 64% +260.2% 0.99 ±148% perf-sched.wait_time.avg.ms.__cond_resched.down_write.__split_vma.vms_gather_munmap_vmas.do_vmi_align_munmap 3.86 ± 5% +86.0% 7.18 ± 44% +41.7% 5.47 ± 32% perf-sched.wait_time.avg.ms.__cond_resched.down_write.free_pgtables.exit_mmap.__mmput 2.54 ± 29% +51.6% 3.85 ± 12% +9.6% 2.78 ± 39% perf-sched.wait_time.avg.ms.__cond_resched.down_write_killable.__do_sys_brk.do_syscall_64.entry_SYSCALL_64_after_hwframe 1.11 ± 39% +201.6% 3.36 ± 47% +77.3% 1.98 ± 86% perf-sched.wait_time.avg.ms.__cond_resched.down_write_killable.exec_mmap.begin_new_exec.load_elf_binary 3.60 ± 68% +1630.2% 62.29 ±153% +398.4% 17.94 ±134% perf-sched.wait_time.avg.ms.__cond_resched.dput.step_into.link_path_walk.part 0.20 ± 64% +115.4% 0.42 ± 42% +145.2% 0.48 ± 83% perf-sched.wait_time.avg.ms.__cond_resched.filemap_read.__kernel_read.load_elf_binary.exec_binprm 142.09 ±145% +58.3% 224.93 ±104% +179.8% 397.63 ±102% perf-sched.wait_time.avg.ms.__cond_resched.kmem_cache_alloc_noprof.alloc_pid.copy_process.kernel_clone 55.51 ± 53% +218.0% 176.54 ± 83% +96.2% 108.89 ± 87% perf-sched.wait_time.avg.ms.__cond_resched.kmem_cache_alloc_noprof.security_inode_alloc.inode_init_always_gfp.alloc_inode 3.22 ± 3% +15.4% 3.72 ± 9% +2.3% 3.30 ± 7% perf-sched.wait_time.avg.ms.__cond_resched.kmem_cache_alloc_noprof.vm_area_dup.__split_vma.vms_gather_munmap_vmas 0.04 ±223% +37562.8% 14.50 ±198% +2231.2% 0.90 ±243% perf-sched.wait_time.avg.ms.__cond_resched.netlink_release.__sock_release.sock_close.__fput 1.19 ± 30% +59.3% 1.90 ± 34% +3.7% 1.24 ± 37% perf-sched.wait_time.avg.ms.__cond_resched.remove_vma.vms_complete_munmap_vmas.do_vmi_align_munmap.do_vmi_munmap 0.36 ±133% +447.8% 1.97 ± 60% +174.5% 0.99 ±103% perf-sched.wait_time.avg.ms.__cond_resched.task_numa_work.task_work_run.syscall_exit_to_user_mode.do_syscall_64 1.73 ± 47% +165.0% 4.58 ± 51% +45.7% 2.52 ± 52% perf-sched.wait_time.avg.ms.io_schedule.folio_wait_bit_common.__do_fault.do_read_fault 1.10 ± 21% +693.9% 8.70 ± 70% +459.3% 6.13 ±173% perf-sched.wait_time.avg.ms.irqentry_exit_to_user_mode.asm_sysvec_call_function_single.[unknown] 54.56 ± 32% +400.2% 272.90 ± 67% +345.0% 242.76 ± 41% perf-sched.wait_time.avg.ms.schedule_timeout.__wait_for_common.wait_for_completion_state.kernel_clone 10.87 ± 18% +151.7% 27.36 ± 68% +69.1% 18.38 ± 83% perf-sched.wait_time.max.ms.__cond_resched.__anon_vma_prepare.__vmf_anon_prepare.do_pte_missing.__handle_mm_fault 123.35 ±181% +1219.3% 1627 ± 82% +469.3% 702.17 ±118% perf-sched.wait_time.max.ms.__cond_resched.__fput.__x64_sys_close.do_syscall_64.entry_SYSCALL_64_after_hwframe 9.68 ±108% +5490.2% 541.19 ±185% -56.7% 4.19 ±327% perf-sched.wait_time.max.ms.__cond_resched.__kmalloc_cache_noprof.do_epoll_create.__x64_sys_epoll_create.do_syscall_64 3.39 ± 91% +112.0% 7.19 ± 44% +52.9% 5.19 ± 54% perf-sched.wait_time.max.ms.__cond_resched.down_read_killable.iterate_dir.__x64_sys_getdents64.do_syscall_64 1.12 ±128% +407.4% 5.67 ± 52% +536.0% 7.11 ±144% perf-sched.wait_time.max.ms.__cond_resched.down_write.__split_vma.vms_gather_munmap_vmas.do_vmi_align_munmap 30.58 ± 29% +1741.1% 563.04 ± 80% +1126.4% 375.06 ±119% perf-sched.wait_time.max.ms.__cond_resched.down_write.free_pgtables.exit_mmap.__mmput 3.82 ±114% +232.1% 12.70 ± 49% +155.2% 9.76 ±120% perf-sched.wait_time.max.ms.__cond_resched.down_write.vms_gather_munmap_vmas.__mmap_prepare.__mmap_region 7.75 ± 46% +72.4% 13.36 ± 32% +18.4% 9.17 ± 86% perf-sched.wait_time.max.ms.__cond_resched.down_write_killable.__do_sys_brk.do_syscall_64.entry_SYSCALL_64_after_hwframe 13.39 ± 48% +259.7% 48.17 ± 34% +107.1% 27.74 ± 58% perf-sched.wait_time.max.ms.__cond_resched.down_write_killable.exec_mmap.begin_new_exec.load_elf_binary 12.46 ± 30% +90.5% 23.73 ± 34% +25.5% 15.64 ± 44% perf-sched.wait_time.max.ms.__cond_resched.down_write_killable.vm_mmap_pgoff.ksys_mmap_pgoff.do_syscall_64 479.90 ± 78% +496.9% 2864 ±141% +310.9% 1972 ±132% perf-sched.wait_time.max.ms.__cond_resched.dput.open_last_lookups.path_openat.do_filp_open 185.75 ±116% +875.0% 1811 ± 84% +264.8% 677.56 ±141% perf-sched.wait_time.max.ms.__cond_resched.dput.path_openat.do_filp_open.do_sys_openat2 2.52 ± 44% +105.2% 5.18 ± 36% +38.3% 3.49 ± 74% perf-sched.wait_time.max.ms.__cond_resched.kmem_cache_alloc_noprof.vm_area_alloc.alloc_bprm.kernel_execve 0.04 ±223% +37564.1% 14.50 ±198% +2231.2% 0.90 ±243% perf-sched.wait_time.max.ms.__cond_resched.netlink_release.__sock_release.sock_close.__fput 0.54 ±153% +669.7% 4.15 ± 61% +161.6% 1.41 ±108% perf-sched.wait_time.max.ms.__cond_resched.task_numa_work.task_work_run.syscall_exit_to_user_mode.do_syscall_64 28.22 ± 14% +41.2% 39.84 ± 25% +27.1% 35.87 ± 43% perf-sched.wait_time.max.ms.__cond_resched.unmap_vmas.vms_clear_ptes.part.0 4.90 ± 51% +158.2% 12.66 ± 75% +26.7% 6.21 ± 42% perf-sched.wait_time.max.ms.io_schedule.folio_wait_bit_common.__do_fault.do_read_fault 26.54 ± 66% +5220.1% 1411 ± 84% +2691.7% 740.84 ±187% perf-sched.wait_time.max.ms.irqentry_exit_to_user_mode.asm_sysvec_call_function_single.[unknown] 1262 ± 9% +434.3% 6744 ± 60% +293.8% 4971 ± 41% perf-sched.wait_time.max.ms.schedule_timeout.__wait_for_common.wait_for_completion_state.kernel_clone 30.09 -12.8 17.32 -2.9 27.23 perf-profile.calltrace.cycles-pp.filp_flush.filp_close.__do_sys_close_range.do_syscall_64.entry_SYSCALL_64_after_hwframe 9.32 -9.3 0.00 -9.3 0.00 perf-profile.calltrace.cycles-pp.fput.filp_close.__do_sys_close_range.do_syscall_64.entry_SYSCALL_64_after_hwframe 41.15 -5.9 35.26 -0.2 40.94 perf-profile.calltrace.cycles-pp.__dup2 41.02 -5.9 35.17 -0.2 40.81 perf-profile.calltrace.cycles-pp.do_syscall_64.entry_SYSCALL_64_after_hwframe.__dup2 41.03 -5.8 35.18 -0.2 40.83 perf-profile.calltrace.cycles-pp.entry_SYSCALL_64_after_hwframe.__dup2 13.86 -5.5 8.35 -1.1 12.79 perf-profile.calltrace.cycles-pp.filp_flush.filp_close.do_dup2.__x64_sys_dup2.do_syscall_64 40.21 -5.5 34.71 -0.2 40.02 perf-profile.calltrace.cycles-pp.__x64_sys_dup2.do_syscall_64.entry_SYSCALL_64_after_hwframe.__dup2 38.01 -4.9 33.10 +0.1 38.09 perf-profile.calltrace.cycles-pp.do_dup2.__x64_sys_dup2.do_syscall_64.entry_SYSCALL_64_after_hwframe.__dup2 4.90 ± 2% -1.9 2.96 ± 3% -0.5 4.38 ± 2% perf-profile.calltrace.cycles-pp.locks_remove_posix.filp_flush.filp_close.__do_sys_close_range.do_syscall_64 2.63 ± 9% -1.9 0.76 ± 18% -0.5 2.11 ± 2% perf-profile.calltrace.cycles-pp.asm_sysvec_apic_timer_interrupt.filp_flush.filp_close.__do_sys_close_range.do_syscall_64 4.44 -1.7 2.76 ± 2% -0.4 3.99 perf-profile.calltrace.cycles-pp.dnotify_flush.filp_flush.filp_close.__do_sys_close_range.do_syscall_64 2.50 ± 2% -0.9 1.56 ± 3% -0.2 2.28 ± 2% perf-profile.calltrace.cycles-pp.locks_remove_posix.filp_flush.filp_close.do_dup2.__x64_sys_dup2 2.22 -0.8 1.42 ± 2% -0.2 2.04 perf-profile.calltrace.cycles-pp.dnotify_flush.filp_flush.filp_close.do_dup2.__x64_sys_dup2 1.66 ± 5% -0.3 1.37 ± 5% -0.2 1.42 ± 4% perf-profile.calltrace.cycles-pp.ksys_dup3.__x64_sys_dup2.do_syscall_64.entry_SYSCALL_64_after_hwframe.__dup2 1.60 ± 5% -0.3 1.32 ± 5% -0.2 1.36 ± 4% perf-profile.calltrace.cycles-pp._raw_spin_lock.ksys_dup3.__x64_sys_dup2.do_syscall_64.entry_SYSCALL_64_after_hwframe 0.00 +0.0 0.00 +0.6 0.65 ± 5% perf-profile.calltrace.cycles-pp._raw_spin_lock.__do_sys_close_range.do_syscall_64.entry_SYSCALL_64_after_hwframe.close_range 0.00 +0.0 0.00 +41.2 41.20 perf-profile.calltrace.cycles-pp.filp_close.__do_sys_close_range.do_syscall_64.entry_SYSCALL_64_after_hwframe.close_range 0.00 +0.0 0.00 +42.0 42.01 perf-profile.calltrace.cycles-pp.__do_sys_close_range.do_syscall_64.entry_SYSCALL_64_after_hwframe.close_range 0.00 +0.0 0.00 +42.4 42.36 perf-profile.calltrace.cycles-pp.do_syscall_64.entry_SYSCALL_64_after_hwframe.close_range 0.00 +0.0 0.00 +42.4 42.36 perf-profile.calltrace.cycles-pp.entry_SYSCALL_64_after_hwframe.close_range 0.00 +0.0 0.00 +42.4 42.44 perf-profile.calltrace.cycles-pp.close_range 0.58 ± 2% +0.0 0.62 ± 2% +0.0 0.61 ± 3% perf-profile.calltrace.cycles-pp.do_read_fault.do_pte_missing.__handle_mm_fault.handle_mm_fault.do_user_addr_fault 1.40 ± 4% +0.0 1.44 ± 9% -0.4 0.99 ± 6% perf-profile.calltrace.cycles-pp.__close 0.54 ± 2% +0.0 0.58 ± 2% +0.0 0.56 ± 3% perf-profile.calltrace.cycles-pp.filemap_map_pages.do_read_fault.do_pte_missing.__handle_mm_fault.handle_mm_fault 1.34 ± 5% +0.0 1.40 ± 9% -0.4 0.93 ± 6% perf-profile.calltrace.cycles-pp.do_syscall_64.entry_SYSCALL_64_after_hwframe.__close 1.35 ± 5% +0.1 1.40 ± 9% -0.4 0.93 ± 6% perf-profile.calltrace.cycles-pp.entry_SYSCALL_64_after_hwframe.__close 0.72 ± 4% +0.1 0.79 ± 4% -0.7 0.00 perf-profile.calltrace.cycles-pp._raw_spin_lock.__do_sys_close_range.do_syscall_64.entry_SYSCALL_64_after_hwframe.syscall 1.23 ± 5% +0.1 1.31 ± 10% -0.5 0.77 ± 8% perf-profile.calltrace.cycles-pp.__x64_sys_close.do_syscall_64.entry_SYSCALL_64_after_hwframe.__close 0.00 +1.8 1.79 ± 5% +1.4 1.35 ± 3% perf-profile.calltrace.cycles-pp.asm_sysvec_apic_timer_interrupt.fput_close.filp_close.__do_sys_close_range.do_syscall_64 19.11 +4.4 23.49 +0.7 19.76 perf-profile.calltrace.cycles-pp.filp_close.do_dup2.__x64_sys_dup2.do_syscall_64.entry_SYSCALL_64_after_hwframe 40.94 +6.5 47.46 -40.9 0.00 perf-profile.calltrace.cycles-pp.filp_close.__do_sys_close_range.do_syscall_64.entry_SYSCALL_64_after_hwframe.syscall 42.24 +6.6 48.79 -42.2 0.00 perf-profile.calltrace.cycles-pp.syscall 42.14 +6.6 48.72 -42.1 0.00 perf-profile.calltrace.cycles-pp.entry_SYSCALL_64_after_hwframe.syscall 42.14 +6.6 48.72 -42.1 0.00 perf-profile.calltrace.cycles-pp.do_syscall_64.entry_SYSCALL_64_after_hwframe.syscall 41.86 +6.6 48.46 -41.9 0.00 perf-profile.calltrace.cycles-pp.__do_sys_close_range.do_syscall_64.entry_SYSCALL_64_after_hwframe.syscall 0.00 +14.6 14.60 ± 2% +6.4 6.41 perf-profile.calltrace.cycles-pp.fput_close.filp_close.do_dup2.__x64_sys_dup2.do_syscall_64 0.00 +29.0 28.95 ± 2% +12.5 12.50 perf-profile.calltrace.cycles-pp.fput_close.filp_close.__do_sys_close_range.do_syscall_64.entry_SYSCALL_64_after_hwframe 45.76 -19.0 26.72 -4.1 41.64 perf-profile.children.cycles-pp.filp_flush 14.67 -14.7 0.00 -14.7 0.00 perf-profile.children.cycles-pp.fput 41.20 -5.9 35.30 -0.2 40.99 perf-profile.children.cycles-pp.__dup2 40.21 -5.5 34.71 -0.2 40.03 perf-profile.children.cycles-pp.__x64_sys_dup2 38.53 -5.2 33.33 +0.1 38.59 perf-profile.children.cycles-pp.do_dup2 7.81 ± 2% -3.1 4.74 ± 3% -0.8 7.02 ± 2% perf-profile.children.cycles-pp.locks_remove_posix 7.03 -2.6 4.40 ± 2% -0.7 6.37 perf-profile.children.cycles-pp.dnotify_flush 5.60 ± 16% -1.3 4.27 ± 14% -0.7 4.89 ± 2% perf-profile.children.cycles-pp.asm_sysvec_apic_timer_interrupt 1.24 ± 3% -0.4 0.86 ± 4% -0.0 1.21 perf-profile.children.cycles-pp.syscall_exit_to_user_mode 1.67 ± 5% -0.3 1.37 ± 5% -0.2 1.42 ± 4% perf-profile.children.cycles-pp.ksys_dup3 3.09 ± 3% -0.1 2.95 ± 4% -0.3 2.82 ± 3% perf-profile.children.cycles-pp._raw_spin_lock 0.29 -0.1 0.22 ± 2% +0.0 0.30 ± 2% perf-profile.children.cycles-pp.update_load_avg 0.10 ± 71% -0.1 0.04 ±112% -0.1 0.05 ± 30% perf-profile.children.cycles-pp.hrtimer_update_next_event 0.10 ± 10% -0.1 0.05 ± 46% +0.0 0.13 ± 7% perf-profile.children.cycles-pp.__x64_sys_fcntl 0.17 ± 7% -0.1 0.12 ± 4% -0.0 0.14 ± 5% perf-profile.children.cycles-pp.entry_SYSCALL_64 0.15 ± 3% -0.0 0.10 ± 18% -0.0 0.15 ± 3% perf-profile.children.cycles-pp.clockevents_program_event 0.04 ± 45% -0.0 0.00 +0.0 0.07 ± 7% perf-profile.children.cycles-pp.update_irq_load_avg 0.06 ± 11% -0.0 0.02 ± 99% +0.0 0.08 ± 24% perf-profile.children.cycles-pp.stress_close_func 0.13 ± 5% -0.0 0.10 ± 7% +0.0 0.14 ± 9% perf-profile.children.cycles-pp.__switch_to 0.06 ± 7% -0.0 0.04 ± 71% -0.0 0.06 ± 8% perf-profile.children.cycles-pp.lapic_next_deadline 0.11 ± 3% -0.0 0.09 ± 5% -0.0 0.10 ± 4% perf-profile.children.cycles-pp.__update_load_avg_cfs_rq 1.49 ± 3% -0.0 1.48 ± 2% +0.2 1.68 ± 4% perf-profile.children.cycles-pp.x64_sys_call 0.00 +0.0 0.00 +42.5 42.47 perf-profile.children.cycles-pp.close_range 0.23 ± 2% +0.0 0.24 ± 5% +0.0 0.26 ± 5% perf-profile.children.cycles-pp.__irq_exit_rcu 0.06 ± 6% +0.0 0.08 ± 6% +0.0 0.07 ± 9% perf-profile.children.cycles-pp.__folio_batch_add_and_move 0.26 ± 2% +0.0 0.28 ± 3% +0.0 0.28 ± 6% perf-profile.children.cycles-pp.folio_remove_rmap_ptes 0.08 ± 4% +0.0 0.11 ± 10% +0.0 0.09 ± 7% perf-profile.children.cycles-pp.set_pte_range 0.45 ± 2% +0.0 0.48 ± 2% +0.0 0.48 ± 4% perf-profile.children.cycles-pp.zap_present_ptes 0.18 ± 3% +0.0 0.21 ± 4% +0.0 0.20 ± 4% perf-profile.children.cycles-pp.folios_put_refs 0.29 ± 3% +0.0 0.32 ± 3% +0.0 0.31 ± 4% perf-profile.children.cycles-pp.__tlb_batch_free_encoded_pages 0.29 ± 3% +0.0 0.32 ± 3% +0.0 0.31 ± 5% perf-profile.children.cycles-pp.free_pages_and_swap_cache 1.42 ± 5% +0.0 1.45 ± 9% -0.4 1.00 ± 6% perf-profile.children.cycles-pp.__close 0.34 ± 4% +0.0 0.38 ± 3% +0.0 0.36 ± 4% perf-profile.children.cycles-pp.tlb_finish_mmu 0.24 ± 3% +0.0 0.27 ± 5% -0.0 0.23 ± 5% perf-profile.children.cycles-pp._raw_spin_lock_irqsave 0.69 ± 2% +0.0 0.74 ± 2% +0.0 0.72 ± 5% perf-profile.children.cycles-pp.filemap_map_pages 0.73 ± 2% +0.0 0.78 ± 2% +0.0 0.77 ± 5% perf-profile.children.cycles-pp.do_read_fault 0.65 ± 7% +0.1 0.70 ± 15% -0.5 0.17 ± 10% perf-profile.children.cycles-pp.fput_close_sync 1.24 ± 5% +0.1 1.33 ± 10% -0.5 0.79 ± 8% perf-profile.children.cycles-pp.__x64_sys_close 42.26 +6.5 48.80 -42.3 0.00 perf-profile.children.cycles-pp.syscall 41.86 +6.6 48.46 +0.2 42.02 perf-profile.children.cycles-pp.__do_sys_close_range 60.05 +10.9 70.95 +0.9 60.97 perf-profile.children.cycles-pp.filp_close 0.00 +44.5 44.55 ± 2% +19.7 19.70 perf-profile.children.cycles-pp.fput_close 14.31 ± 2% -14.3 0.00 -14.3 0.00 perf-profile.self.cycles-pp.fput 30.12 ± 2% -13.0 17.09 -2.4 27.73 perf-profile.self.cycles-pp.filp_flush 19.17 ± 2% -9.5 9.68 ± 3% -0.6 18.61 perf-profile.self.cycles-pp.do_dup2 7.63 ± 3% -3.0 4.62 ± 4% -0.7 6.90 ± 2% perf-profile.self.cycles-pp.locks_remove_posix 6.86 ± 3% -2.6 4.28 ± 3% -0.6 6.25 perf-profile.self.cycles-pp.dnotify_flush 0.64 ± 4% -0.4 0.26 ± 4% -0.0 0.62 ± 3% perf-profile.self.cycles-pp.syscall_exit_to_user_mode 0.22 ± 10% -0.1 0.15 ± 11% +0.1 0.34 ± 2% perf-profile.self.cycles-pp.x64_sys_call 0.23 ± 3% -0.1 0.17 ± 8% +0.0 0.25 ± 3% perf-profile.self.cycles-pp.__schedule 0.10 ± 44% -0.1 0.05 ± 71% +0.0 0.15 ± 3% perf-profile.self.cycles-pp.pick_next_task_fair 0.08 ± 19% -0.1 0.03 ±100% -0.0 0.06 ± 7% perf-profile.self.cycles-pp.pick_eevdf 0.04 ± 44% -0.0 0.00 +0.0 0.07 ± 8% perf-profile.self.cycles-pp.__x64_sys_fcntl 0.06 ± 7% -0.0 0.03 ±100% -0.0 0.06 ± 8% perf-profile.self.cycles-pp.lapic_next_deadline 0.13 ± 7% -0.0 0.10 ± 10% +0.0 0.13 ± 8% perf-profile.self.cycles-pp.__switch_to 0.09 ± 8% -0.0 0.06 ± 8% +0.0 0.10 perf-profile.self.cycles-pp.__update_load_avg_se 0.08 ± 4% -0.0 0.05 ± 7% -0.0 0.07 perf-profile.self.cycles-pp.asm_sysvec_apic_timer_interrupt 0.08 ± 9% -0.0 0.06 ± 11% -0.0 0.05 ± 8% perf-profile.self.cycles-pp.entry_SYSCALL_64 0.06 ± 7% +0.0 0.08 ± 8% +0.0 0.07 ± 8% perf-profile.self.cycles-pp.filemap_map_pages 0.12 ± 3% +0.0 0.14 ± 4% +0.0 0.13 ± 6% perf-profile.self.cycles-pp.folios_put_refs 0.25 ± 2% +0.0 0.27 ± 3% +0.0 0.27 ± 6% perf-profile.self.cycles-pp.folio_remove_rmap_ptes 0.17 ± 5% +0.0 0.20 ± 6% -0.0 0.17 ± 4% perf-profile.self.cycles-pp._raw_spin_lock_irqsave 0.64 ± 7% +0.1 0.70 ± 15% -0.5 0.17 ± 11% perf-profile.self.cycles-pp.fput_close_sync 0.00 +0.1 0.07 ± 5% +0.0 0.00 perf-profile.self.cycles-pp.do_nanosleep 0.00 +0.1 0.10 ± 15% +0.0 0.00 perf-profile.self.cycles-pp.filp_close 0.00 +43.9 43.86 ± 2% +19.4 19.35 perf-profile.self.cycles-pp.fput_close ^ permalink raw reply [flat|nested] 6+ messages in thread
* Re: [linus:master] [fs] a914bd93f3: stress-ng.close.close_calls_per_sec 52.2% regression 2025-04-18 8:12 ` Oliver Sang @ 2025-04-18 11:46 ` Mateusz Guzik 0 siblings, 0 replies; 6+ messages in thread From: Mateusz Guzik @ 2025-04-18 11:46 UTC (permalink / raw) To: Oliver Sang; +Cc: oe-lkp, lkp, linux-kernel, Christian Brauner, linux-fsdevel On Fri, Apr 18, 2025 at 10:13 AM Oliver Sang <oliver.sang@intel.com> wrote: > > hi, Mateusz Guzik, > > On Thu, Apr 17, 2025 at 12:17:54PM +0200, Mateusz Guzik wrote: > > On Thu, Apr 17, 2025 at 12:02:55PM +0200, Mateusz Guzik wrote: > > > bottom line though is there is a known tradeoff there and stress-ng > > > manufactures a case where it is always the wrong one. > > > > > > fd 2 at hand is inherited (it's the tty) and shared between *all* > > > workers on all CPUs. > > > > > > Ignoring some fluff, it's this in a loop: > > > dup2(2, 1024) = 1024 > > > dup2(2, 1025) = 1025 > > > dup2(2, 1026) = 1026 > > > dup2(2, 1027) = 1027 > > > dup2(2, 1028) = 1028 > > > dup2(2, 1029) = 1029 > > > dup2(2, 1030) = 1030 > > > dup2(2, 1031) = 1031 > > > [..] > > > close_range(1024, 1032, 0) = 0 > > > > > > where fd 2 is the same file object in all 192 workers doing this. > > > > > > > the following will still have *some* impact, but the drop should be much > > lower > > > > it also has a side effect of further helping the single-threaded case by > > shortening the code when it works > > we applied below patch upon a914bd93f3. it seems it not only recovers the > regression we saw on a914bd93f3, but also causes further performance benefit > that it's +29.4% better than 3e46a92a27 (parent of a914bd93f3). > > at the same time, I also list stress-ng.close.ops_per_sec here which is not > in our original report since the data has overlap so our code logic don't > think they are reliable then will not list in table without some 'force' > option. > some drop for highly concurrent close of *the same* file is expected. it's a tradeoff optimizing for a case where the call to close deals with the last fd, which is most common in real life if one was to try to dig deeper the real baseline would be against 23e490336467fcdaf95e1efcf8f58067b59f647b , which is just prior to any of the ref changes, but i'm not sure doing this is warranted I very much expect the patchset is a net loss for this stress-ng run, but also per the above description stress-ng does not accurately represent what happens in the real world, turning the tradeoff introduced in the patchset into a problem. all that said, i'll do a proper patch submission for what i posted here, thanks for testing > in a stress-ng close test, the output looks like below: > > 2025-04-18 02:58:28 stress-ng --timeout 60 --times --verify --metrics --no-rand-seed --close 192 > stress-ng: info: [6268] setting to a 1 min run per stressor > stress-ng: info: [6268] dispatching hogs: 192 close > stress-ng: info: [6268] note: /proc/sys/kernel/sched_autogroup_enabled is 1 and this can impact scheduling throughput for processes not attached to a tty. Setting this to 0 may improve performance metrics > stress-ng: metrc: [6268] stressor bogo ops real time usr time sys time bogo ops/s bogo ops/s CPU used per RSS Max > stress-ng: metrc: [6268] (secs) (secs) (secs) (real time) (usr+sys time) instance (%) (KB) > stress-ng: metrc: [6268] close 1568702 60.08 171.29 9524.58 26108.29 161.79 84.05 1548 <--- (1) > stress-ng: metrc: [6268] miscellaneous metrics: > stress-ng: metrc: [6268] close 600923.80 close calls per sec (harmonic mean of 192 instances) <--- (2) > stress-ng: info: [6268] for a 60.14s run time: > stress-ng: info: [6268] 11547.73s available CPU time > stress-ng: info: [6268] 171.29s user time ( 1.48%) > stress-ng: info: [6268] 9525.12s system time ( 82.48%) > stress-ng: info: [6268] 9696.41s total time ( 83.97%) > stress-ng: info: [6268] load average: 520.00 149.63 51.46 > stress-ng: info: [6268] skipped: 0 > stress-ng: info: [6268] passed: 192: close (192) > stress-ng: info: [6268] failed: 0 > stress-ng: info: [6268] metrics untrustworthy: 0 > stress-ng: info: [6268] successful run completed in 1 min > > > > the stress-ng.close.close_calls_per_sec data is from (2) > the stress-ng.close.ops_per_sec data is from line (1), bogo ops/s (real time) > > from below, seems a914bd93f3 also has a small regression for > stress-ng.close.ops_per_sec but not obvious since data is not stable enough. > 9f0124114f almost has same data as 3e46a92a27 regarding to this > stress-ng.close.ops_per_sec. > > > summary data: > > ========================================================================================= > compiler/cpufreq_governor/kconfig/nr_threads/rootfs/tbox_group/test/testcase/testtime: > gcc-12/performance/x86_64-rhel-9.4/100%/debian-12-x86_64-20240206.cgz/igk-spr-2sp1/close/stress-ng/60s > > commit: > 3e46a92a27 ("fs: use fput_close_sync() in close()") > a914bd93f3 ("fs: use fput_close() in filp_close()") > 9f0124114f <--- a914bd93f3 + patch > > 3e46a92a27c2927f a914bd93f3edfedcdd59deb615e 9f0124114f707363af03caed5ae > ---------------- --------------------------- --------------------------- > %stddev %change %stddev %change %stddev > \ | \ | \ > 473980 ą 14% -52.2% 226559 ą 13% +29.4% 613288 ą 12% stress-ng.close.close_calls_per_sec > 1677393 ą 3% -6.0% 1576636 ą 5% +0.6% 1686892 ą 3% stress-ng.close.ops > 27917 ą 3% -6.0% 26237 ą 5% +0.6% 28074 ą 3% stress-ng.close.ops_per_sec > > > full data is as [1] > > > > > > diff --git a/include/linux/file_ref.h b/include/linux/file_ref.h > > index 7db62fbc0500..c73865ed4251 100644 > > --- a/include/linux/file_ref.h > > +++ b/include/linux/file_ref.h > > @@ -181,17 +181,15 @@ static __always_inline __must_check bool file_ref_put_close(file_ref_t *ref) > > long old, new; > > > > old = atomic_long_read(&ref->refcnt); > > - do { > > - if (unlikely(old < 0)) > > - return __file_ref_put_badval(ref, old); > > - > > - if (old == FILE_REF_ONEREF) > > - new = FILE_REF_DEAD; > > - else > > - new = old - 1; > > - } while (!atomic_long_try_cmpxchg(&ref->refcnt, &old, new)); > > - > > - return new == FILE_REF_DEAD; > > + if (likely(old == FILE_REF_ONEREF)) { > > + new = FILE_REF_DEAD; > > + if (likely(atomic_long_try_cmpxchg(&ref->refcnt, &old, new))) > > + return true; > > + /* > > + * The ref has changed from under us, don't play any games. > > + */ > > + } > > + return file_ref_put(ref); > > } > > > > /** > > > [1] > ========================================================================================= > compiler/cpufreq_governor/kconfig/nr_threads/rootfs/tbox_group/test/testcase/testtime: > gcc-12/performance/x86_64-rhel-9.4/100%/debian-12-x86_64-20240206.cgz/igk-spr-2sp1/close/stress-ng/60s > > commit: > 3e46a92a27 ("fs: use fput_close_sync() in close()") > a914bd93f3 ("fs: use fput_close() in filp_close()") > 9f0124114f <--- a914bd93f3 + patch > > 3e46a92a27c2927f a914bd93f3edfedcdd59deb615e 9f0124114f707363af03caed5ae > ---------------- --------------------------- --------------------------- > %stddev %change %stddev %change %stddev > \ | \ | \ > 355470 ą 14% -17.6% 292767 ą 7% -8.9% 323894 ą 6% cpuidle..usage > 5.19 -0.6 4.61 ą 3% -0.0 5.18 ą 2% mpstat.cpu.all.usr% > 495615 ą 7% -38.5% 304839 ą 8% -5.5% 468431 ą 7% vmstat.system.cs > 780096 ą 5% -23.5% 596446 ą 3% -4.7% 743238 ą 5% vmstat.system.in > 4004843 ą 8% -21.1% 3161813 ą 8% -6.2% 3758245 ą 10% time.involuntary_context_switches > 9475 +1.1% 9582 +0.3% 9504 time.system_time > 183.50 ą 2% -37.8% 114.20 ą 3% -3.4% 177.34 ą 2% time.user_time > 25637892 ą 6% -42.6% 14725385 ą 9% -6.4% 23992138 ą 7% time.voluntary_context_switches > 2512168 ą 17% -45.8% 1361659 ą 71% +0.5% 2524627 ą 15% sched_debug.cfs_rq:/.avg_vruntime.min > 2512168 ą 17% -45.8% 1361659 ą 71% +0.5% 2524627 ą 15% sched_debug.cfs_rq:/.min_vruntime.min > 700402 ą 2% +19.8% 838744 ą 10% +5.0% 735486 ą 4% sched_debug.cpu.avg_idle.avg > 81230 ą 6% -59.6% 32788 ą 69% -6.1% 76301 ą 7% sched_debug.cpu.nr_switches.avg > 27992 ą 20% -70.2% 8345 ą 74% +11.7% 31275 ą 26% sched_debug.cpu.nr_switches.min > 473980 ą 14% -52.2% 226559 ą 13% +29.4% 613288 ą 12% stress-ng.close.close_calls_per_sec > 1677393 ą 3% -6.0% 1576636 ą 5% +0.6% 1686892 ą 3% stress-ng.close.ops > 27917 ą 3% -6.0% 26237 ą 5% +0.6% 28074 ą 3% stress-ng.close.ops_per_sec > 4004843 ą 8% -21.1% 3161813 ą 8% -6.2% 3758245 ą 10% stress-ng.time.involuntary_context_switches > 9475 +1.1% 9582 +0.3% 9504 stress-ng.time.system_time > 183.50 ą 2% -37.8% 114.20 ą 3% -3.4% 177.34 ą 2% stress-ng.time.user_time > 25637892 ą 6% -42.6% 14725385 ą 9% -6.4% 23992138 ą 7% stress-ng.time.voluntary_context_switches > 23.01 ą 2% -1.4 21.61 ą 3% +0.1 23.13 ą 2% perf-stat.i.cache-miss-rate% > 17981659 -10.8% 16035508 ą 4% -0.5% 17886941 ą 4% perf-stat.i.cache-misses > 77288888 ą 2% -6.5% 72260357 ą 4% -1.7% 75978329 ą 3% perf-stat.i.cache-references > 504949 ą 6% -38.1% 312536 ą 8% -5.7% 476406 ą 7% perf-stat.i.context-switches > 33030 +15.7% 38205 ą 4% +1.3% 33444 ą 4% perf-stat.i.cycles-between-cache-misses > 4.34 ą 10% -38.3% 2.68 ą 20% +0.1% 4.34 ą 11% perf-stat.i.metric.K/sec > 26229 ą 44% +37.8% 36145 ą 4% +21.8% 31948 ą 4% perf-stat.overall.cycles-between-cache-misses > 2.12 ą 47% +151.1% 5.32 ą 28% -13.5% 1.84 ą 27% perf-sched.sch_delay.avg.ms.__cond_resched.__do_sys_close_range.do_syscall_64.entry_SYSCALL_64_after_hwframe.[unknown] > 0.28 ą 60% +990.5% 3.08 ą 53% +6339.3% 18.16 ą314% perf-sched.sch_delay.avg.ms.__cond_resched.__kmalloc_cache_noprof.do_eventfd.__x64_sys_eventfd2.do_syscall_64 > 0.96 ą 28% +35.5% 1.30 ą 25% -7.5% 0.89 ą 29% perf-sched.sch_delay.avg.ms.__cond_resched.__kmalloc_noprof.load_elf_phdrs.load_elf_binary.exec_binprm > 2.56 ą 43% +964.0% 27.27 ą161% +456.1% 14.25 ą127% perf-sched.sch_delay.avg.ms.__cond_resched.dput.open_last_lookups.path_openat.do_filp_open > 12.80 ą139% +366.1% 59.66 ą107% +242.3% 43.82 ą204% perf-sched.sch_delay.avg.ms.__cond_resched.dput.shmem_unlink.vfs_unlink.do_unlinkat > 2.78 ą 25% +50.0% 4.17 ą 19% +22.2% 3.40 ą 18% perf-sched.sch_delay.avg.ms.__cond_resched.kmem_cache_alloc_lru_noprof.__d_alloc.d_alloc_cursor.dcache_dir_open > 0.78 ą 18% +39.3% 1.09 ą 19% +24.7% 0.97 ą 36% perf-sched.sch_delay.avg.ms.__cond_resched.kmem_cache_alloc_noprof.mas_alloc_nodes.mas_preallocate.vma_shrink > 2.63 ą 10% +16.7% 3.07 ą 4% +1.3% 2.67 ą 15% perf-sched.sch_delay.avg.ms.__cond_resched.kmem_cache_alloc_noprof.vm_area_alloc.__mmap_new_vma.__mmap_region > 0.04 ą223% +3483.1% 1.38 ą 67% +2231.2% 0.90 ą243% perf-sched.sch_delay.avg.ms.__cond_resched.netlink_release.__sock_release.sock_close.__fput > 0.72 ą 17% +42.5% 1.02 ą 22% +20.4% 0.86 ą 15% perf-sched.sch_delay.avg.ms.__cond_resched.stop_one_cpu.sched_exec.bprm_execve.part > 0.35 ą134% +457.7% 1.94 ą 61% +177.7% 0.97 ą104% perf-sched.sch_delay.avg.ms.__cond_resched.task_numa_work.task_work_run.syscall_exit_to_user_mode.do_syscall_64 > 1.88 ą 34% +574.9% 12.69 ą115% +389.0% 9.20 ą214% perf-sched.sch_delay.avg.ms.__cond_resched.task_work_run.syscall_exit_to_user_mode.do_syscall_64.entry_SYSCALL_64_after_hwframe > 2.41 ą 10% +18.0% 2.84 ą 9% +62.4% 3.91 ą 81% perf-sched.sch_delay.avg.ms.__cond_resched.wp_page_copy.__handle_mm_fault.handle_mm_fault.do_user_addr_fault > 1.85 ą 36% +155.6% 4.73 ą 50% +27.5% 2.36 ą 54% perf-sched.sch_delay.avg.ms.io_schedule.folio_wait_bit_common.__do_fault.do_read_fault > 28.94 ą 26% -52.4% 13.78 ą 36% -29.1% 20.52 ą 50% perf-sched.sch_delay.avg.ms.pipe_read.vfs_read.ksys_read.do_syscall_64 > 2.24 ą 9% +22.1% 2.74 ą 8% +14.2% 2.56 ą 14% perf-sched.sch_delay.avg.ms.schedule_preempt_disabled.rwsem_down_write_slowpath.down_write.unlink_file_vma_batch_final > 2.19 ą 7% +17.3% 2.57 ą 6% +6.4% 2.33 ą 6% perf-sched.sch_delay.avg.ms.schedule_preempt_disabled.rwsem_down_write_slowpath.down_write.vma_link_file > 2.39 ą 6% +16.4% 2.79 ą 9% +12.3% 2.69 ą 8% perf-sched.sch_delay.avg.ms.schedule_preempt_disabled.rwsem_down_write_slowpath.down_write.vma_prepare > 0.34 ą 77% +1931.5% 6.95 ą 99% +5218.5% 18.19 ą313% perf-sched.sch_delay.max.ms.__cond_resched.__kmalloc_cache_noprof.do_eventfd.__x64_sys_eventfd2.do_syscall_64 > 29.69 ą 28% +129.5% 68.12 ą 28% +11.1% 32.99 ą 30% perf-sched.sch_delay.max.ms.__cond_resched.__kmalloc_cache_noprof.perf_event_mmap_event.perf_event_mmap.__mmap_region > 7.71 ą 21% +10.4% 8.51 ą 25% -30.5% 5.36 ą 30% perf-sched.sch_delay.max.ms.__cond_resched.__kmalloc_node_noprof.seq_read_iter.vfs_read.ksys_read > 1.48 ą 96% +284.6% 5.68 ą 56% -39.2% 0.90 ą112% perf-sched.sch_delay.max.ms.__cond_resched.copy_strings_kernel.kernel_execve.call_usermodehelper_exec_async.ret_from_fork > 3.59 ą 57% +124.5% 8.06 ą 45% +44.7% 5.19 ą 72% perf-sched.sch_delay.max.ms.__cond_resched.down_read.mmap_read_lock_maybe_expand.get_arg_page.copy_string_kernel > 3.39 ą 91% +112.0% 7.19 ą 44% +133.6% 7.92 ą129% perf-sched.sch_delay.max.ms.__cond_resched.down_read_killable.iterate_dir.__x64_sys_getdents64.do_syscall_64 > 22.16 ą 77% +117.4% 48.17 ą 34% +41.9% 31.45 ą 54% perf-sched.sch_delay.max.ms.__cond_resched.down_write_killable.exec_mmap.begin_new_exec.load_elf_binary > 8.72 ą 17% +358.5% 39.98 ą 61% +98.6% 17.32 ą 77% perf-sched.sch_delay.max.ms.__cond_resched.kmem_cache_alloc_noprof.mas_alloc_nodes.mas_preallocate.__mmap_new_vma > 35.71 ą 49% +1.8% 36.35 ą 37% -48.6% 18.34 ą 25% perf-sched.sch_delay.max.ms.__cond_resched.kmem_cache_alloc_noprof.vm_area_dup.__split_vma.vms_gather_munmap_vmas > 0.04 ą223% +3484.4% 1.38 ą 67% +2231.2% 0.90 ą243% perf-sched.sch_delay.max.ms.__cond_resched.netlink_release.__sock_release.sock_close.__fput > 0.53 ą154% +676.1% 4.12 ą 61% +161.0% 1.39 ą109% perf-sched.sch_delay.max.ms.__cond_resched.task_numa_work.task_work_run.syscall_exit_to_user_mode.do_syscall_64 > 25.76 ą 70% +9588.9% 2496 ą127% +2328.6% 625.69 ą272% perf-sched.sch_delay.max.ms.__cond_resched.task_work_run.syscall_exit_to_user_mode.do_syscall_64.entry_SYSCALL_64_after_hwframe > 51.53 ą 26% -58.8% 21.22 ą106% +13.1% 58.30 ą190% perf-sched.sch_delay.max.ms.devkmsg_read.vfs_read.ksys_read.do_syscall_64 > 4.97 ą 48% +154.8% 12.66 ą 75% +25.0% 6.21 ą 42% perf-sched.sch_delay.max.ms.io_schedule.folio_wait_bit_common.__do_fault.do_read_fault > 4.36 ą 48% +147.7% 10.81 ą 29% -14.1% 3.75 ą 26% perf-sched.wait_and_delay.avg.ms.__cond_resched.__do_sys_close_range.do_syscall_64.entry_SYSCALL_64_after_hwframe.[unknown] > 108632 ą 4% +23.9% 134575 ą 6% -1.3% 107223 ą 4% perf-sched.wait_and_delay.count.__cond_resched.__do_sys_close_range.do_syscall_64.entry_SYSCALL_64_after_hwframe.[unknown] > 572.67 ą 6% +37.3% 786.17 ą 7% +1.9% 583.75 ą 8% perf-sched.wait_and_delay.count.__cond_resched.__wait_for_common.affine_move_task.__set_cpus_allowed_ptr.__sched_setaffinity > 596.67 ą 12% +43.9% 858.50 ą 13% +2.4% 610.75 ą 8% perf-sched.wait_and_delay.count.__cond_resched.__wait_for_common.wait_for_completion_state.call_usermodehelper_exec.__request_module > 294.83 ą 9% +31.1% 386.50 ą 11% +1.7% 299.75 ą 11% perf-sched.wait_and_delay.count.__cond_resched.dput.terminate_walk.path_openat.do_filp_open > 1223275 ą 2% -17.7% 1006293 ą 6% +0.5% 1228897 perf-sched.wait_and_delay.count.do_nanosleep.hrtimer_nanosleep.common_nsleep.__x64_sys_clock_nanosleep > 2772 ą 11% +43.6% 3980 ą 11% +6.6% 2954 ą 9% perf-sched.wait_and_delay.count.do_wait.kernel_wait.call_usermodehelper_exec_work.process_one_work > 11690 ą 7% +29.8% 15173 ą 10% +5.6% 12344 ą 7% perf-sched.wait_and_delay.count.io_schedule.folio_wait_bit_common.filemap_fault.__do_fault > 4072 ą100% +163.7% 10737 ą 7% +59.4% 6491 ą 58% perf-sched.wait_and_delay.count.irqentry_exit_to_user_mode.asm_exc_page_fault.[unknown].[unknown] > 8811 ą 6% +26.2% 11117 ą 9% +2.6% 9039 ą 8% perf-sched.wait_and_delay.count.irqentry_exit_to_user_mode.asm_sysvec_apic_timer_interrupt.[unknown].[unknown] > 662.17 ą 29% +187.8% 1905 ą 29% +36.2% 901.58 ą 32% perf-sched.wait_and_delay.count.pipe_read.vfs_read.ksys_read.do_syscall_64 > 15.50 ą 11% +48.4% 23.00 ą 16% -6.5% 14.50 ą 24% perf-sched.wait_and_delay.count.schedule_hrtimeout_range.do_poll.constprop.0.do_sys_poll > 167.67 ą 20% +48.0% 248.17 ą 26% -8.3% 153.83 ą 27% perf-sched.wait_and_delay.count.schedule_preempt_disabled.rwsem_down_write_slowpath.down_write.open_last_lookups > 2680 ą 12% +42.5% 3820 ą 11% +6.7% 2860 ą 9% perf-sched.wait_and_delay.count.schedule_timeout.___down_common.__down_timeout.down_timeout > 137.17 ą 13% +31.8% 180.83 ą 9% +12.4% 154.17 ą 16% perf-sched.wait_and_delay.count.schedule_timeout.__wait_for_common.wait_for_completion_state.__wait_rcu_gp > 2636 ą 12% +43.1% 3772 ą 12% +6.1% 2797 ą 10% perf-sched.wait_and_delay.count.schedule_timeout.__wait_for_common.wait_for_completion_state.call_usermodehelper_exec > 10.50 ą 11% +74.6% 18.33 ą 23% +19.0% 12.50 ą 18% perf-sched.wait_and_delay.count.schedule_timeout.kcompactd.kthread.ret_from_fork > 5619 ą 5% +38.8% 7797 ą 9% +9.2% 6136 ą 8% perf-sched.wait_and_delay.count.smpboot_thread_fn.kthread.ret_from_fork.ret_from_fork_asm > 70455 ą 4% +32.3% 93197 ą 6% +1.1% 71250 ą 3% perf-sched.wait_and_delay.count.syscall_exit_to_user_mode.do_syscall_64.entry_SYSCALL_64_after_hwframe.[unknown] > 6990 ą 4% +37.4% 9603 ą 9% +7.7% 7528 ą 5% perf-sched.wait_and_delay.count.worker_thread.kthread.ret_from_fork.ret_from_fork_asm > 191.28 ą124% +1455.2% 2974 ą100% +428.0% 1009 ą166% perf-sched.wait_and_delay.max.ms.__cond_resched.dput.path_openat.do_filp_open.do_sys_openat2 > 1758 ą118% -87.9% 211.89 ą211% -96.6% 59.86 ą184% perf-sched.wait_and_delay.max.ms.devkmsg_read.vfs_read.ksys_read.do_syscall_64 > 2.24 ą 48% +144.6% 5.48 ą 29% -14.7% 1.91 ą 25% perf-sched.wait_time.avg.ms.__cond_resched.__do_sys_close_range.do_syscall_64.entry_SYSCALL_64_after_hwframe.[unknown] > 8.06 ą101% +618.7% 57.94 ą 68% +332.7% 34.88 ą100% perf-sched.wait_time.avg.ms.__cond_resched.__fput.__x64_sys_close.do_syscall_64.entry_SYSCALL_64_after_hwframe > 0.28 ą146% +370.9% 1.30 ą 64% +260.2% 0.99 ą148% perf-sched.wait_time.avg.ms.__cond_resched.down_write.__split_vma.vms_gather_munmap_vmas.do_vmi_align_munmap > 3.86 ą 5% +86.0% 7.18 ą 44% +41.7% 5.47 ą 32% perf-sched.wait_time.avg.ms.__cond_resched.down_write.free_pgtables.exit_mmap.__mmput > 2.54 ą 29% +51.6% 3.85 ą 12% +9.6% 2.78 ą 39% perf-sched.wait_time.avg.ms.__cond_resched.down_write_killable.__do_sys_brk.do_syscall_64.entry_SYSCALL_64_after_hwframe > 1.11 ą 39% +201.6% 3.36 ą 47% +77.3% 1.98 ą 86% perf-sched.wait_time.avg.ms.__cond_resched.down_write_killable.exec_mmap.begin_new_exec.load_elf_binary > 3.60 ą 68% +1630.2% 62.29 ą153% +398.4% 17.94 ą134% perf-sched.wait_time.avg.ms.__cond_resched.dput.step_into.link_path_walk.part > 0.20 ą 64% +115.4% 0.42 ą 42% +145.2% 0.48 ą 83% perf-sched.wait_time.avg.ms.__cond_resched.filemap_read.__kernel_read.load_elf_binary.exec_binprm > 142.09 ą145% +58.3% 224.93 ą104% +179.8% 397.63 ą102% perf-sched.wait_time.avg.ms.__cond_resched.kmem_cache_alloc_noprof.alloc_pid.copy_process.kernel_clone > 55.51 ą 53% +218.0% 176.54 ą 83% +96.2% 108.89 ą 87% perf-sched.wait_time.avg.ms.__cond_resched.kmem_cache_alloc_noprof.security_inode_alloc.inode_init_always_gfp.alloc_inode > 3.22 ą 3% +15.4% 3.72 ą 9% +2.3% 3.30 ą 7% perf-sched.wait_time.avg.ms.__cond_resched.kmem_cache_alloc_noprof.vm_area_dup.__split_vma.vms_gather_munmap_vmas > 0.04 ą223% +37562.8% 14.50 ą198% +2231.2% 0.90 ą243% perf-sched.wait_time.avg.ms.__cond_resched.netlink_release.__sock_release.sock_close.__fput > 1.19 ą 30% +59.3% 1.90 ą 34% +3.7% 1.24 ą 37% perf-sched.wait_time.avg.ms.__cond_resched.remove_vma.vms_complete_munmap_vmas.do_vmi_align_munmap.do_vmi_munmap > 0.36 ą133% +447.8% 1.97 ą 60% +174.5% 0.99 ą103% perf-sched.wait_time.avg.ms.__cond_resched.task_numa_work.task_work_run.syscall_exit_to_user_mode.do_syscall_64 > 1.73 ą 47% +165.0% 4.58 ą 51% +45.7% 2.52 ą 52% perf-sched.wait_time.avg.ms.io_schedule.folio_wait_bit_common.__do_fault.do_read_fault > 1.10 ą 21% +693.9% 8.70 ą 70% +459.3% 6.13 ą173% perf-sched.wait_time.avg.ms.irqentry_exit_to_user_mode.asm_sysvec_call_function_single.[unknown] > 54.56 ą 32% +400.2% 272.90 ą 67% +345.0% 242.76 ą 41% perf-sched.wait_time.avg.ms.schedule_timeout.__wait_for_common.wait_for_completion_state.kernel_clone > 10.87 ą 18% +151.7% 27.36 ą 68% +69.1% 18.38 ą 83% perf-sched.wait_time.max.ms.__cond_resched.__anon_vma_prepare.__vmf_anon_prepare.do_pte_missing.__handle_mm_fault > 123.35 ą181% +1219.3% 1627 ą 82% +469.3% 702.17 ą118% perf-sched.wait_time.max.ms.__cond_resched.__fput.__x64_sys_close.do_syscall_64.entry_SYSCALL_64_after_hwframe > 9.68 ą108% +5490.2% 541.19 ą185% -56.7% 4.19 ą327% perf-sched.wait_time.max.ms.__cond_resched.__kmalloc_cache_noprof.do_epoll_create.__x64_sys_epoll_create.do_syscall_64 > 3.39 ą 91% +112.0% 7.19 ą 44% +52.9% 5.19 ą 54% perf-sched.wait_time.max.ms.__cond_resched.down_read_killable.iterate_dir.__x64_sys_getdents64.do_syscall_64 > 1.12 ą128% +407.4% 5.67 ą 52% +536.0% 7.11 ą144% perf-sched.wait_time.max.ms.__cond_resched.down_write.__split_vma.vms_gather_munmap_vmas.do_vmi_align_munmap > 30.58 ą 29% +1741.1% 563.04 ą 80% +1126.4% 375.06 ą119% perf-sched.wait_time.max.ms.__cond_resched.down_write.free_pgtables.exit_mmap.__mmput > 3.82 ą114% +232.1% 12.70 ą 49% +155.2% 9.76 ą120% perf-sched.wait_time.max.ms.__cond_resched.down_write.vms_gather_munmap_vmas.__mmap_prepare.__mmap_region > 7.75 ą 46% +72.4% 13.36 ą 32% +18.4% 9.17 ą 86% perf-sched.wait_time.max.ms.__cond_resched.down_write_killable.__do_sys_brk.do_syscall_64.entry_SYSCALL_64_after_hwframe > 13.39 ą 48% +259.7% 48.17 ą 34% +107.1% 27.74 ą 58% perf-sched.wait_time.max.ms.__cond_resched.down_write_killable.exec_mmap.begin_new_exec.load_elf_binary > 12.46 ą 30% +90.5% 23.73 ą 34% +25.5% 15.64 ą 44% perf-sched.wait_time.max.ms.__cond_resched.down_write_killable.vm_mmap_pgoff.ksys_mmap_pgoff.do_syscall_64 > 479.90 ą 78% +496.9% 2864 ą141% +310.9% 1972 ą132% perf-sched.wait_time.max.ms.__cond_resched.dput.open_last_lookups.path_openat.do_filp_open > 185.75 ą116% +875.0% 1811 ą 84% +264.8% 677.56 ą141% perf-sched.wait_time.max.ms.__cond_resched.dput.path_openat.do_filp_open.do_sys_openat2 > 2.52 ą 44% +105.2% 5.18 ą 36% +38.3% 3.49 ą 74% perf-sched.wait_time.max.ms.__cond_resched.kmem_cache_alloc_noprof.vm_area_alloc.alloc_bprm.kernel_execve > 0.04 ą223% +37564.1% 14.50 ą198% +2231.2% 0.90 ą243% perf-sched.wait_time.max.ms.__cond_resched.netlink_release.__sock_release.sock_close.__fput > 0.54 ą153% +669.7% 4.15 ą 61% +161.6% 1.41 ą108% perf-sched.wait_time.max.ms.__cond_resched.task_numa_work.task_work_run.syscall_exit_to_user_mode.do_syscall_64 > 28.22 ą 14% +41.2% 39.84 ą 25% +27.1% 35.87 ą 43% perf-sched.wait_time.max.ms.__cond_resched.unmap_vmas.vms_clear_ptes.part.0 > 4.90 ą 51% +158.2% 12.66 ą 75% +26.7% 6.21 ą 42% perf-sched.wait_time.max.ms.io_schedule.folio_wait_bit_common.__do_fault.do_read_fault > 26.54 ą 66% +5220.1% 1411 ą 84% +2691.7% 740.84 ą187% perf-sched.wait_time.max.ms.irqentry_exit_to_user_mode.asm_sysvec_call_function_single.[unknown] > 1262 ą 9% +434.3% 6744 ą 60% +293.8% 4971 ą 41% perf-sched.wait_time.max.ms.schedule_timeout.__wait_for_common.wait_for_completion_state.kernel_clone > 30.09 -12.8 17.32 -2.9 27.23 perf-profile.calltrace.cycles-pp.filp_flush.filp_close.__do_sys_close_range.do_syscall_64.entry_SYSCALL_64_after_hwframe > 9.32 -9.3 0.00 -9.3 0.00 perf-profile.calltrace.cycles-pp.fput.filp_close.__do_sys_close_range.do_syscall_64.entry_SYSCALL_64_after_hwframe > 41.15 -5.9 35.26 -0.2 40.94 perf-profile.calltrace.cycles-pp.__dup2 > 41.02 -5.9 35.17 -0.2 40.81 perf-profile.calltrace.cycles-pp.do_syscall_64.entry_SYSCALL_64_after_hwframe.__dup2 > 41.03 -5.8 35.18 -0.2 40.83 perf-profile.calltrace.cycles-pp.entry_SYSCALL_64_after_hwframe.__dup2 > 13.86 -5.5 8.35 -1.1 12.79 perf-profile.calltrace.cycles-pp.filp_flush.filp_close.do_dup2.__x64_sys_dup2.do_syscall_64 > 40.21 -5.5 34.71 -0.2 40.02 perf-profile.calltrace.cycles-pp.__x64_sys_dup2.do_syscall_64.entry_SYSCALL_64_after_hwframe.__dup2 > 38.01 -4.9 33.10 +0.1 38.09 perf-profile.calltrace.cycles-pp.do_dup2.__x64_sys_dup2.do_syscall_64.entry_SYSCALL_64_after_hwframe.__dup2 > 4.90 ą 2% -1.9 2.96 ą 3% -0.5 4.38 ą 2% perf-profile.calltrace.cycles-pp.locks_remove_posix.filp_flush.filp_close.__do_sys_close_range.do_syscall_64 > 2.63 ą 9% -1.9 0.76 ą 18% -0.5 2.11 ą 2% perf-profile.calltrace.cycles-pp.asm_sysvec_apic_timer_interrupt.filp_flush.filp_close.__do_sys_close_range.do_syscall_64 > 4.44 -1.7 2.76 ą 2% -0.4 3.99 perf-profile.calltrace.cycles-pp.dnotify_flush.filp_flush.filp_close.__do_sys_close_range.do_syscall_64 > 2.50 ą 2% -0.9 1.56 ą 3% -0.2 2.28 ą 2% perf-profile.calltrace.cycles-pp.locks_remove_posix.filp_flush.filp_close.do_dup2.__x64_sys_dup2 > 2.22 -0.8 1.42 ą 2% -0.2 2.04 perf-profile.calltrace.cycles-pp.dnotify_flush.filp_flush.filp_close.do_dup2.__x64_sys_dup2 > 1.66 ą 5% -0.3 1.37 ą 5% -0.2 1.42 ą 4% perf-profile.calltrace.cycles-pp.ksys_dup3.__x64_sys_dup2.do_syscall_64.entry_SYSCALL_64_after_hwframe.__dup2 > 1.60 ą 5% -0.3 1.32 ą 5% -0.2 1.36 ą 4% perf-profile.calltrace.cycles-pp._raw_spin_lock.ksys_dup3.__x64_sys_dup2.do_syscall_64.entry_SYSCALL_64_after_hwframe > 0.00 +0.0 0.00 +0.6 0.65 ą 5% perf-profile.calltrace.cycles-pp._raw_spin_lock.__do_sys_close_range.do_syscall_64.entry_SYSCALL_64_after_hwframe.close_range > 0.00 +0.0 0.00 +41.2 41.20 perf-profile.calltrace.cycles-pp.filp_close.__do_sys_close_range.do_syscall_64.entry_SYSCALL_64_after_hwframe.close_range > 0.00 +0.0 0.00 +42.0 42.01 perf-profile.calltrace.cycles-pp.__do_sys_close_range.do_syscall_64.entry_SYSCALL_64_after_hwframe.close_range > 0.00 +0.0 0.00 +42.4 42.36 perf-profile.calltrace.cycles-pp.do_syscall_64.entry_SYSCALL_64_after_hwframe.close_range > 0.00 +0.0 0.00 +42.4 42.36 perf-profile.calltrace.cycles-pp.entry_SYSCALL_64_after_hwframe.close_range > 0.00 +0.0 0.00 +42.4 42.44 perf-profile.calltrace.cycles-pp.close_range > 0.58 ą 2% +0.0 0.62 ą 2% +0.0 0.61 ą 3% perf-profile.calltrace.cycles-pp.do_read_fault.do_pte_missing.__handle_mm_fault.handle_mm_fault.do_user_addr_fault > 1.40 ą 4% +0.0 1.44 ą 9% -0.4 0.99 ą 6% perf-profile.calltrace.cycles-pp.__close > 0.54 ą 2% +0.0 0.58 ą 2% +0.0 0.56 ą 3% perf-profile.calltrace.cycles-pp.filemap_map_pages.do_read_fault.do_pte_missing.__handle_mm_fault.handle_mm_fault > 1.34 ą 5% +0.0 1.40 ą 9% -0.4 0.93 ą 6% perf-profile.calltrace.cycles-pp.do_syscall_64.entry_SYSCALL_64_after_hwframe.__close > 1.35 ą 5% +0.1 1.40 ą 9% -0.4 0.93 ą 6% perf-profile.calltrace.cycles-pp.entry_SYSCALL_64_after_hwframe.__close > 0.72 ą 4% +0.1 0.79 ą 4% -0.7 0.00 perf-profile.calltrace.cycles-pp._raw_spin_lock.__do_sys_close_range.do_syscall_64.entry_SYSCALL_64_after_hwframe.syscall > 1.23 ą 5% +0.1 1.31 ą 10% -0.5 0.77 ą 8% perf-profile.calltrace.cycles-pp.__x64_sys_close.do_syscall_64.entry_SYSCALL_64_after_hwframe.__close > 0.00 +1.8 1.79 ą 5% +1.4 1.35 ą 3% perf-profile.calltrace.cycles-pp.asm_sysvec_apic_timer_interrupt.fput_close.filp_close.__do_sys_close_range.do_syscall_64 > 19.11 +4.4 23.49 +0.7 19.76 perf-profile.calltrace.cycles-pp.filp_close.do_dup2.__x64_sys_dup2.do_syscall_64.entry_SYSCALL_64_after_hwframe > 40.94 +6.5 47.46 -40.9 0.00 perf-profile.calltrace.cycles-pp.filp_close.__do_sys_close_range.do_syscall_64.entry_SYSCALL_64_after_hwframe.syscall > 42.24 +6.6 48.79 -42.2 0.00 perf-profile.calltrace.cycles-pp.syscall > 42.14 +6.6 48.72 -42.1 0.00 perf-profile.calltrace.cycles-pp.entry_SYSCALL_64_after_hwframe.syscall > 42.14 +6.6 48.72 -42.1 0.00 perf-profile.calltrace.cycles-pp.do_syscall_64.entry_SYSCALL_64_after_hwframe.syscall > 41.86 +6.6 48.46 -41.9 0.00 perf-profile.calltrace.cycles-pp.__do_sys_close_range.do_syscall_64.entry_SYSCALL_64_after_hwframe.syscall > 0.00 +14.6 14.60 ą 2% +6.4 6.41 perf-profile.calltrace.cycles-pp.fput_close.filp_close.do_dup2.__x64_sys_dup2.do_syscall_64 > 0.00 +29.0 28.95 ą 2% +12.5 12.50 perf-profile.calltrace.cycles-pp.fput_close.filp_close.__do_sys_close_range.do_syscall_64.entry_SYSCALL_64_after_hwframe > 45.76 -19.0 26.72 -4.1 41.64 perf-profile.children.cycles-pp.filp_flush > 14.67 -14.7 0.00 -14.7 0.00 perf-profile.children.cycles-pp.fput > 41.20 -5.9 35.30 -0.2 40.99 perf-profile.children.cycles-pp.__dup2 > 40.21 -5.5 34.71 -0.2 40.03 perf-profile.children.cycles-pp.__x64_sys_dup2 > 38.53 -5.2 33.33 +0.1 38.59 perf-profile.children.cycles-pp.do_dup2 > 7.81 ą 2% -3.1 4.74 ą 3% -0.8 7.02 ą 2% perf-profile.children.cycles-pp.locks_remove_posix > 7.03 -2.6 4.40 ą 2% -0.7 6.37 perf-profile.children.cycles-pp.dnotify_flush > 5.60 ą 16% -1.3 4.27 ą 14% -0.7 4.89 ą 2% perf-profile.children.cycles-pp.asm_sysvec_apic_timer_interrupt > 1.24 ą 3% -0.4 0.86 ą 4% -0.0 1.21 perf-profile.children.cycles-pp.syscall_exit_to_user_mode > 1.67 ą 5% -0.3 1.37 ą 5% -0.2 1.42 ą 4% perf-profile.children.cycles-pp.ksys_dup3 > 3.09 ą 3% -0.1 2.95 ą 4% -0.3 2.82 ą 3% perf-profile.children.cycles-pp._raw_spin_lock > 0.29 -0.1 0.22 ą 2% +0.0 0.30 ą 2% perf-profile.children.cycles-pp.update_load_avg > 0.10 ą 71% -0.1 0.04 ą112% -0.1 0.05 ą 30% perf-profile.children.cycles-pp.hrtimer_update_next_event > 0.10 ą 10% -0.1 0.05 ą 46% +0.0 0.13 ą 7% perf-profile.children.cycles-pp.__x64_sys_fcntl > 0.17 ą 7% -0.1 0.12 ą 4% -0.0 0.14 ą 5% perf-profile.children.cycles-pp.entry_SYSCALL_64 > 0.15 ą 3% -0.0 0.10 ą 18% -0.0 0.15 ą 3% perf-profile.children.cycles-pp.clockevents_program_event > 0.04 ą 45% -0.0 0.00 +0.0 0.07 ą 7% perf-profile.children.cycles-pp.update_irq_load_avg > 0.06 ą 11% -0.0 0.02 ą 99% +0.0 0.08 ą 24% perf-profile.children.cycles-pp.stress_close_func > 0.13 ą 5% -0.0 0.10 ą 7% +0.0 0.14 ą 9% perf-profile.children.cycles-pp.__switch_to > 0.06 ą 7% -0.0 0.04 ą 71% -0.0 0.06 ą 8% perf-profile.children.cycles-pp.lapic_next_deadline > 0.11 ą 3% -0.0 0.09 ą 5% -0.0 0.10 ą 4% perf-profile.children.cycles-pp.__update_load_avg_cfs_rq > 1.49 ą 3% -0.0 1.48 ą 2% +0.2 1.68 ą 4% perf-profile.children.cycles-pp.x64_sys_call > 0.00 +0.0 0.00 +42.5 42.47 perf-profile.children.cycles-pp.close_range > 0.23 ą 2% +0.0 0.24 ą 5% +0.0 0.26 ą 5% perf-profile.children.cycles-pp.__irq_exit_rcu > 0.06 ą 6% +0.0 0.08 ą 6% +0.0 0.07 ą 9% perf-profile.children.cycles-pp.__folio_batch_add_and_move > 0.26 ą 2% +0.0 0.28 ą 3% +0.0 0.28 ą 6% perf-profile.children.cycles-pp.folio_remove_rmap_ptes > 0.08 ą 4% +0.0 0.11 ą 10% +0.0 0.09 ą 7% perf-profile.children.cycles-pp.set_pte_range > 0.45 ą 2% +0.0 0.48 ą 2% +0.0 0.48 ą 4% perf-profile.children.cycles-pp.zap_present_ptes > 0.18 ą 3% +0.0 0.21 ą 4% +0.0 0.20 ą 4% perf-profile.children.cycles-pp.folios_put_refs > 0.29 ą 3% +0.0 0.32 ą 3% +0.0 0.31 ą 4% perf-profile.children.cycles-pp.__tlb_batch_free_encoded_pages > 0.29 ą 3% +0.0 0.32 ą 3% +0.0 0.31 ą 5% perf-profile.children.cycles-pp.free_pages_and_swap_cache > 1.42 ą 5% +0.0 1.45 ą 9% -0.4 1.00 ą 6% perf-profile.children.cycles-pp.__close > 0.34 ą 4% +0.0 0.38 ą 3% +0.0 0.36 ą 4% perf-profile.children.cycles-pp.tlb_finish_mmu > 0.24 ą 3% +0.0 0.27 ą 5% -0.0 0.23 ą 5% perf-profile.children.cycles-pp._raw_spin_lock_irqsave > 0.69 ą 2% +0.0 0.74 ą 2% +0.0 0.72 ą 5% perf-profile.children.cycles-pp.filemap_map_pages > 0.73 ą 2% +0.0 0.78 ą 2% +0.0 0.77 ą 5% perf-profile.children.cycles-pp.do_read_fault > 0.65 ą 7% +0.1 0.70 ą 15% -0.5 0.17 ą 10% perf-profile.children.cycles-pp.fput_close_sync > 1.24 ą 5% +0.1 1.33 ą 10% -0.5 0.79 ą 8% perf-profile.children.cycles-pp.__x64_sys_close > 42.26 +6.5 48.80 -42.3 0.00 perf-profile.children.cycles-pp.syscall > 41.86 +6.6 48.46 +0.2 42.02 perf-profile.children.cycles-pp.__do_sys_close_range > 60.05 +10.9 70.95 +0.9 60.97 perf-profile.children.cycles-pp.filp_close > 0.00 +44.5 44.55 ą 2% +19.7 19.70 perf-profile.children.cycles-pp.fput_close > 14.31 ą 2% -14.3 0.00 -14.3 0.00 perf-profile.self.cycles-pp.fput > 30.12 ą 2% -13.0 17.09 -2.4 27.73 perf-profile.self.cycles-pp.filp_flush > 19.17 ą 2% -9.5 9.68 ą 3% -0.6 18.61 perf-profile.self.cycles-pp.do_dup2 > 7.63 ą 3% -3.0 4.62 ą 4% -0.7 6.90 ą 2% perf-profile.self.cycles-pp.locks_remove_posix > 6.86 ą 3% -2.6 4.28 ą 3% -0.6 6.25 perf-profile.self.cycles-pp.dnotify_flush > 0.64 ą 4% -0.4 0.26 ą 4% -0.0 0.62 ą 3% perf-profile.self.cycles-pp.syscall_exit_to_user_mode > 0.22 ą 10% -0.1 0.15 ą 11% +0.1 0.34 ą 2% perf-profile.self.cycles-pp.x64_sys_call > 0.23 ą 3% -0.1 0.17 ą 8% +0.0 0.25 ą 3% perf-profile.self.cycles-pp.__schedule > 0.10 ą 44% -0.1 0.05 ą 71% +0.0 0.15 ą 3% perf-profile.self.cycles-pp.pick_next_task_fair > 0.08 ą 19% -0.1 0.03 ą100% -0.0 0.06 ą 7% perf-profile.self.cycles-pp.pick_eevdf > 0.04 ą 44% -0.0 0.00 +0.0 0.07 ą 8% perf-profile.self.cycles-pp.__x64_sys_fcntl > 0.06 ą 7% -0.0 0.03 ą100% -0.0 0.06 ą 8% perf-profile.self.cycles-pp.lapic_next_deadline > 0.13 ą 7% -0.0 0.10 ą 10% +0.0 0.13 ą 8% perf-profile.self.cycles-pp.__switch_to > 0.09 ą 8% -0.0 0.06 ą 8% +0.0 0.10 perf-profile.self.cycles-pp.__update_load_avg_se > 0.08 ą 4% -0.0 0.05 ą 7% -0.0 0.07 perf-profile.self.cycles-pp.asm_sysvec_apic_timer_interrupt > 0.08 ą 9% -0.0 0.06 ą 11% -0.0 0.05 ą 8% perf-profile.self.cycles-pp.entry_SYSCALL_64 > 0.06 ą 7% +0.0 0.08 ą 8% +0.0 0.07 ą 8% perf-profile.self.cycles-pp.filemap_map_pages > 0.12 ą 3% +0.0 0.14 ą 4% +0.0 0.13 ą 6% perf-profile.self.cycles-pp.folios_put_refs > 0.25 ą 2% +0.0 0.27 ą 3% +0.0 0.27 ą 6% perf-profile.self.cycles-pp.folio_remove_rmap_ptes > 0.17 ą 5% +0.0 0.20 ą 6% -0.0 0.17 ą 4% perf-profile.self.cycles-pp._raw_spin_lock_irqsave > 0.64 ą 7% +0.1 0.70 ą 15% -0.5 0.17 ą 11% perf-profile.self.cycles-pp.fput_close_sync > 0.00 +0.1 0.07 ą 5% +0.0 0.00 perf-profile.self.cycles-pp.do_nanosleep > 0.00 +0.1 0.10 ą 15% +0.0 0.00 perf-profile.self.cycles-pp.filp_close > 0.00 +43.9 43.86 ą 2% +19.4 19.35 perf-profile.self.cycles-pp.fput_close > > -- Mateusz Guzik <mjguzik gmail.com> ^ permalink raw reply [flat|nested] 6+ messages in thread
end of thread, other threads:[~2025-04-18 11:46 UTC | newest] Thread overview: 6+ messages (download: mbox.gz / follow: Atom feed) -- links below jump to the message on this page -- 2025-04-17 8:23 [linus:master] [fs] a914bd93f3: stress-ng.close.close_calls_per_sec 52.2% regression kernel test robot 2025-04-17 9:54 ` Mateusz Guzik 2025-04-17 10:02 ` Mateusz Guzik 2025-04-17 10:17 ` Mateusz Guzik 2025-04-18 8:12 ` Oliver Sang 2025-04-18 11:46 ` Mateusz Guzik
This is a public inbox, see mirroring instructions for how to clone and mirror all data and code used for this inbox
all inboxes | Powered by JetHome®