* [linus:master] [nfsd] 7e13f4f8d2: postmark.transactions 10.4% regression
@ 2025-02-06 7:00 kernel test robot
0 siblings, 0 replies; only message in thread
From: kernel test robot @ 2025-02-06 7:00 UTC (permalink / raw)
To: Jeff Layton
Cc: oe-lkp, lkp, linux-kernel, Chuck Lever, linux-nfs, oliver.sang
Hello,
kernel test robot noticed a 10.4% regression of postmark.transactions on:
commit: 7e13f4f8d27dc02fb88666f603c53ca749d56f92 ("nfsd: handle delegated timestamps in SETATTR")
https://git.kernel.org/cgit/linux/kernel/git/torvalds/linux.git master
[test failed on linus/master bdd4f86c97e60b748027bdf6f6a3729c8a12da15]
[test failed on linux-next/master df4b2bbff898227db0c14264ac7edd634e79f755]
testcase: postmark
config: x86_64-rhel-9.4
compiler: gcc-12
test machine: 4 threads 1 sockets Intel(R) Core(TM) i3-3220 CPU @ 3.30GHz (Ivy Bridge) with 8G memory
parameters:
disk: 1HDD
fs: xfs
fs1: nfsv4
number: 1000n
trans: 30000s
subdirs: 100d
cpufreq_governor: performance
If you fix the issue in a separate patch/commit (i.e. not just a new version of
the same patch/commit), kindly add following tags
| Reported-by: kernel test robot <oliver.sang@intel.com>
| Closes: https://lore.kernel.org/oe-lkp/202502061435.62604a8d-lkp@intel.com
Details are as below:
-------------------------------------------------------------------------------------------------->
The kernel config and materials to reproduce are available at:
https://download.01.org/0day-ci/archive/20250206/202502061435.62604a8d-lkp@intel.com
=========================================================================================
compiler/cpufreq_governor/disk/fs1/fs/kconfig/number/rootfs/subdirs/tbox_group/testcase/trans:
gcc-12/performance/1HDD/nfsv4/xfs/x86_64-rhel-9.4/1000n/debian-12-x86_64-20240206.cgz/100d/lkp-ivb-d04/postmark/30000s
commit:
6ae30d6eb2 ("nfsd: add support for delegated timestamps")
7e13f4f8d2 ("nfsd: handle delegated timestamps in SETATTR")
6ae30d6eb26bce02 7e13f4f8d27dc02fb88666f603c
---------------- ---------------------------
%stddev %change %stddev
\ | \
16.93 -1.5 15.46 mpstat.cpu.all.iowait%
3253 +13.8% 3702 ± 4% uptime.idle
0.70 -11.7% 0.62 ± 2% vmstat.procs.b
4265 -6.1% 4004 ± 3% vmstat.system.cs
80.56 +2.0% 82.16 iostat.cpu.idle
16.90 -8.7% 15.43 iostat.cpu.iowait
1.60 -4.1% 1.53 ± 2% iostat.cpu.system
8974 +5.0% 9424 proc-vmstat.nr_shmem
1446157 +6.3% 1537480 ± 2% proc-vmstat.numa_hit
1446157 +6.3% 1537478 ± 2% proc-vmstat.numa_local
1736096 +5.6% 1834173 ± 2% proc-vmstat.pgalloc_normal
1429310 +11.5% 1594111 ± 3% proc-vmstat.pgfault
1834412 +5.2% 1929590 ± 2% proc-vmstat.pgfree
659217 +5.2% 693777 proc-vmstat.pgpgout
74887 +12.5% 84235 ± 4% proc-vmstat.pgreuse
0.74 ± 10% -23.7% 0.56 ± 17% sched_debug.cfs_rq:/.h_nr_running.avg
360.38 ± 5% +9.0% 392.67 ± 4% sched_debug.cfs_rq:/.load_avg.stddev
0.48 ± 17% -26.1% 0.36 ± 13% sched_debug.cfs_rq:/.nr_running.avg
417.13 ± 5% -14.4% 356.95 ± 4% sched_debug.cfs_rq:/.runnable_avg.avg
382.46 ± 6% -15.4% 323.57 ± 12% sched_debug.cfs_rq:/.runnable_avg.stddev
499.84 ± 7% +39.8% 698.95 ± 22% sched_debug.cpu.clock_task.stddev
0.73 ± 12% -23.4% 0.56 ± 17% sched_debug.cpu.nr_running.avg
2791 ± 2% -8.0% 2567 ± 4% sched_debug.cpu.nr_uninterruptible.max
0.02 ± 6% +13.0% 0.02 ± 5% perf-sched.sch_delay.avg.ms.schedule_timeout.__wait_for_common.__synchronize_srcu.part.0
0.03 ± 10% +36.0% 0.04 ± 6% perf-sched.sch_delay.avg.ms.schedule_timeout.kcompactd.kthread.ret_from_fork
0.01 ± 39% -90.9% 0.00 ±173% perf-sched.sch_delay.avg.ms.syscall_exit_to_user_mode.do_syscall_64.entry_SYSCALL_64_after_hwframe.[unknown]
0.05 -18.8% 0.04 ± 12% perf-sched.sch_delay.max.ms.rpc_wait_bit_killable.__wait_on_bit.out_of_line_wait_on_bit.nfs4_run_open_task
0.01 ± 61% -93.6% 0.00 ±173% perf-sched.sch_delay.max.ms.syscall_exit_to_user_mode.do_syscall_64.entry_SYSCALL_64_after_hwframe.[unknown]
619.85 ± 4% -10.2% 556.79 ± 10% perf-sched.wait_and_delay.avg.ms.schedule_hrtimeout_range.do_poll.constprop.0.do_sys_poll
1642 ± 23% +51.7% 2490 ± 19% perf-sched.wait_and_delay.max.ms.smpboot_thread_fn.kthread.ret_from_fork.ret_from_fork_asm
619.83 ± 4% -10.2% 556.76 ± 10% perf-sched.wait_time.avg.ms.schedule_hrtimeout_range.do_poll.constprop.0.do_sys_poll
0.20 ± 4% +10.4% 0.22 ± 6% perf-sched.wait_time.max.ms.rpc_wait_bit_killable.__wait_on_bit.out_of_line_wait_on_bit.nfs4_run_open_task
1642 ± 23% +51.7% 2490 ± 19% perf-sched.wait_time.max.ms.smpboot_thread_fn.kthread.ret_from_fork.ret_from_fork_asm
16.14 -10.4% 14.46 postmark.creation_mixed_trans
256446 -10.8% 228826 ± 3% postmark.data_read
271043 -10.8% 241851 ± 3% postmark.data_written
16.30 -10.4% 14.61 postmark.deletion_mixed_trans
16.03 -10.4% 14.36 postmark.files_appended
16.34 -10.8% 14.58 ± 3% postmark.files_created
16.34 -10.8% 14.58 ± 3% postmark.files_deleted
16.28 -10.4% 14.58 postmark.files_read
977.64 +12.2% 1096 ± 3% postmark.time.elapsed_time
977.64 +12.2% 1096 ± 3% postmark.time.elapsed_time.max
32.45 -10.4% 29.07 postmark.transactions
9596 ± 3% -51.9% 4617 ± 4% nfsstat.Client.nfs.v4.delegreturn
10.45 -49.4% 5.28 nfsstat.Client.nfs.v4.delegreturn.percent
0.01 ± 3% -13.8% 0.01 ± 3% nfsstat.Client.nfs.v4.exchange_id.percent
0.01 ± 3% -13.8% 0.01 ± 3% nfsstat.Client.nfs.v4.getattr.percent
0.01 ± 3% -13.8% 0.01 ± 3% nfsstat.Client.nfs.v4.pathconf.percent
76622 ± 3% -10.5% 68577 ± 4% nfsstat.Client.rpc.authrefrsh
76621 ± 3% -10.5% 68577 ± 4% nfsstat.Client.rpc.calls
76621 ± 3% -10.5% 68576 ± 4% nfsstat.Server.nfs.v4.compound
76615 ± 3% -10.5% 68570 ± 4% nfsstat.Server.nfs.v4.operations.putfh
76618 ± 3% -10.5% 68573 ± 4% nfsstat.Server.nfs.v4.operations.sequence
76622 ± 3% -10.5% 68577 ± 4% nfsstat.Server.packet.packets
76622 ± 3% -10.5% 68577 ± 4% nfsstat.Server.packet.tcp
76622 ± 3% -10.5% 68577 ± 4% nfsstat.Server.reply.cache.nocache
76622 ± 3% -10.5% 68577 ± 4% nfsstat.Server.rpc.calls
7.92 +4.5% 8.28 perf-stat.i.MPKI
11.06 +0.2 11.25 perf-stat.i.branch-miss-rate%
9.69 +0.2 9.92 perf-stat.i.cache-miss-rate%
7752348 -2.7% 7540156 ± 2% perf-stat.i.cache-references
4273 -6.2% 4010 ± 3% perf-stat.i.context-switches
3.20 +1.5% 3.25 perf-stat.i.cpi
140.79 -6.5% 131.59 ± 3% perf-stat.i.cpu-migrations
454.52 -2.5% 443.37 perf-stat.i.cycles-between-cache-misses
0.34 -1.6% 0.33 perf-stat.i.ipc
0.78 -16.6% 0.65 ± 5% perf-stat.i.metric.K/sec
8.13 +0.1 8.26 perf-stat.overall.branch-miss-rate%
9.46 +0.2 9.65 perf-stat.overall.cache-miss-rate%
538.98 -3.7% 519.07 perf-stat.overall.cycles-between-cache-misses
7744340 -2.7% 7533176 ± 2% perf-stat.ps.cache-references
4268 -6.2% 4006 ± 3% perf-stat.ps.context-switches
140.64 -6.5% 131.47 ± 3% perf-stat.ps.cpu-migrations
7.02 ± 6% -1.8 5.26 ± 23% perf-profile.calltrace.cycles-pp.nfsd.kthread.ret_from_fork.ret_from_fork_asm
6.97 ± 5% -1.7 5.24 ± 23% perf-profile.calltrace.cycles-pp.svc_recv.nfsd.kthread.ret_from_fork.ret_from_fork_asm
6.21 ± 7% -1.7 4.49 ± 22% perf-profile.calltrace.cycles-pp.svc_handle_xprt.svc_recv.nfsd.kthread.ret_from_fork
4.18 ± 6% -1.2 2.97 ± 25% perf-profile.calltrace.cycles-pp.svc_process.svc_handle_xprt.svc_recv.nfsd.kthread
4.17 ± 5% -1.2 2.97 ± 25% perf-profile.calltrace.cycles-pp.svc_process_common.svc_process.svc_handle_xprt.svc_recv.nfsd
3.64 ± 5% -1.0 2.66 ± 26% perf-profile.calltrace.cycles-pp.nfsd4_proc_compound.nfsd_dispatch.svc_process_common.svc_process.svc_handle_xprt
1.06 ± 24% -0.5 0.53 ± 61% perf-profile.calltrace.cycles-pp.xfs_file_fsync.xfs_file_buffered_write.do_iter_readv_writev.vfs_iter_write.nfsd_vfs_write
46.56 ± 2% +2.0 48.60 ± 2% perf-profile.calltrace.cycles-pp.cpuidle_enter.cpuidle_idle_call.do_idle.cpu_startup_entry.start_secondary
53.42 ± 2% +2.2 55.59 ± 2% perf-profile.calltrace.cycles-pp.cpu_startup_entry.start_secondary.common_startup_64
53.42 ± 2% +2.2 55.60 ± 2% perf-profile.calltrace.cycles-pp.start_secondary.common_startup_64
53.34 ± 2% +2.2 55.53 ± 2% perf-profile.calltrace.cycles-pp.do_idle.cpu_startup_entry.start_secondary.common_startup_64
49.91 ± 2% +2.3 52.24 ± 2% perf-profile.calltrace.cycles-pp.cpuidle_idle_call.do_idle.cpu_startup_entry.start_secondary.common_startup_64
7.02 ± 6% -1.8 5.26 ± 23% perf-profile.children.cycles-pp.nfsd
6.97 ± 5% -1.7 5.24 ± 23% perf-profile.children.cycles-pp.svc_recv
6.21 ± 7% -1.7 4.49 ± 22% perf-profile.children.cycles-pp.svc_handle_xprt
4.18 ± 6% -1.2 2.97 ± 25% perf-profile.children.cycles-pp.svc_process
4.17 ± 5% -1.2 2.97 ± 25% perf-profile.children.cycles-pp.svc_process_common
3.64 ± 5% -1.0 2.68 ± 25% perf-profile.children.cycles-pp.nfsd4_proc_compound
1.49 ± 15% -0.6 0.88 ± 20% perf-profile.children.cycles-pp.sched_balance_rq
0.96 ± 7% -0.4 0.52 ± 28% perf-profile.children.cycles-pp.sched_balance_find_src_group
1.88 ± 14% -0.4 1.45 ± 12% perf-profile.children.cycles-pp.__pick_next_task
1.06 ± 24% -0.4 0.63 ± 28% perf-profile.children.cycles-pp.xfs_file_fsync
0.76 ± 32% -0.4 0.36 ± 21% perf-profile.children.cycles-pp.sched_balance_newidle
0.83 ± 14% -0.4 0.45 ± 32% perf-profile.children.cycles-pp.update_sd_lb_stats
0.78 ± 24% -0.3 0.50 ± 35% perf-profile.children.cycles-pp.file_write_and_wait_range
0.97 ± 6% -0.3 0.70 ± 16% perf-profile.children.cycles-pp.update_load_avg
0.65 ± 23% -0.2 0.40 ± 16% perf-profile.children.cycles-pp.nfsd4_open
0.81 ± 15% -0.2 0.56 ± 33% perf-profile.children.cycles-pp.__filemap_fdatawrite_range
0.81 ± 15% -0.2 0.56 ± 33% perf-profile.children.cycles-pp.filemap_fdatawrite_wbc
0.50 ± 30% -0.2 0.27 ± 45% perf-profile.children.cycles-pp.update_sg_lb_stats
0.78 ± 15% -0.2 0.58 ± 31% perf-profile.children.cycles-pp.do_writepages
0.48 ± 14% -0.2 0.29 ± 28% perf-profile.children.cycles-pp.vfs_unlink
0.34 ± 9% -0.2 0.16 ± 44% perf-profile.children.cycles-pp.nfs_file_release
0.50 ± 14% -0.2 0.34 ± 26% perf-profile.children.cycles-pp.nfsd4_remove
0.50 ± 14% -0.2 0.34 ± 26% perf-profile.children.cycles-pp.nfsd_unlink
0.52 ± 9% -0.2 0.36 ± 21% perf-profile.children.cycles-pp.svc_tcp_recvfrom
0.30 ± 18% -0.2 0.15 ± 40% perf-profile.children.cycles-pp.__put_nfs_open_context
0.21 ± 19% -0.2 0.06 ± 77% perf-profile.children.cycles-pp.xfs_remove
0.21 ± 19% -0.2 0.06 ± 77% perf-profile.children.cycles-pp.xfs_vn_unlink
0.43 ± 26% -0.1 0.29 ± 25% perf-profile.children.cycles-pp.__common_interrupt
0.18 ± 45% -0.1 0.04 ±110% perf-profile.children.cycles-pp.rpc_exit_task
0.17 ± 38% -0.1 0.03 ±105% perf-profile.children.cycles-pp.__filemap_fdatawait_range
0.28 ± 22% -0.1 0.14 ± 39% perf-profile.children.cycles-pp.nfs4_do_close
0.27 ± 11% -0.1 0.14 ± 58% perf-profile.children.cycles-pp.xfs_generic_create
0.17 ± 53% -0.1 0.05 ±122% perf-profile.children.cycles-pp.vms_complete_munmap_vmas
0.21 ± 39% -0.1 0.09 ± 64% perf-profile.children.cycles-pp.native_queued_spin_lock_slowpath
0.30 ± 10% -0.1 0.18 ± 12% perf-profile.children.cycles-pp.svc_tcp_read_marker
0.32 ± 11% -0.1 0.21 ± 22% perf-profile.children.cycles-pp.svc_tcp_sock_recv_cmsg
0.27 ± 11% -0.1 0.15 ± 61% perf-profile.children.cycles-pp.dentry_create
0.21 ± 28% -0.1 0.10 ± 74% perf-profile.children.cycles-pp.nfsd4_encode_operation
0.27 ± 11% -0.1 0.15 ± 61% perf-profile.children.cycles-pp.vfs_create
0.18 ± 24% -0.1 0.06 ± 59% perf-profile.children.cycles-pp.autoremove_wake_function
0.30 ± 11% -0.1 0.20 ± 23% perf-profile.children.cycles-pp.task_contending
0.17 ± 23% -0.1 0.06 ± 59% perf-profile.children.cycles-pp.wakeup_preempt
0.14 ± 31% -0.1 0.04 ±110% perf-profile.children.cycles-pp.down_write
0.19 ± 21% -0.1 0.09 ± 63% perf-profile.children.cycles-pp.call_decode
0.14 ± 14% -0.1 0.06 ±100% perf-profile.children.cycles-pp.tick_program_event
0.15 ± 22% -0.1 0.08 ± 58% perf-profile.children.cycles-pp.dev_hard_start_xmit
0.02 ±173% +0.1 0.09 ± 11% perf-profile.children.cycles-pp.complete
0.00 +0.1 0.08 ± 38% perf-profile.children.cycles-pp.timekeeping_max_deferment
0.11 ± 15% +0.1 0.20 ± 22% perf-profile.children.cycles-pp.rpc_wake_up_queued_task
0.02 ±173% +0.1 0.13 ± 56% perf-profile.children.cycles-pp.tick_check_oneshot_broadcast_this_cpu
0.02 ±173% +0.1 0.14 ± 39% perf-profile.children.cycles-pp.swake_up_one
0.03 ±173% +0.1 0.16 ± 30% perf-profile.children.cycles-pp.tmigr_quick_check
0.13 ± 89% +0.2 0.28 ± 30% perf-profile.children.cycles-pp.x86_pmu_disable
0.21 ± 14% +0.2 0.36 ± 24% perf-profile.children.cycles-pp.__mmap_prepare
0.04 ±100% +0.2 0.20 ± 34% perf-profile.children.cycles-pp.folio_alloc_mpol_noprof
0.05 ±103% +0.2 0.21 ± 29% perf-profile.children.cycles-pp.vma_alloc_folio_noprof
0.13 ± 25% +0.2 0.30 ± 26% perf-profile.children.cycles-pp.vms_gather_munmap_vmas
53.42 ± 2% +2.2 55.60 ± 2% perf-profile.children.cycles-pp.start_secondary
0.21 ± 39% -0.1 0.09 ± 64% perf-profile.self.cycles-pp.native_queued_spin_lock_slowpath
0.12 ± 23% -0.1 0.04 ± 63% perf-profile.self.cycles-pp.local_clock_noinstr
0.21 ± 15% -0.1 0.14 ± 26% perf-profile.self.cycles-pp.__switch_to_asm
0.00 +0.1 0.08 ± 23% perf-profile.self.cycles-pp.nfsd_setuser
0.00 +0.1 0.08 ± 23% perf-profile.self.cycles-pp.ttwu_queue_wakelist
0.08 ± 61% +0.1 0.16 ± 12% perf-profile.self.cycles-pp.cpuidle_enter
0.02 ±173% +0.1 0.11 ± 22% perf-profile.self.cycles-pp.tmigr_quick_check
0.00 +0.1 0.10 ± 49% perf-profile.self.cycles-pp.hrtimer_update_next_event
0.02 ±173% +0.1 0.13 ± 56% perf-profile.self.cycles-pp.tick_check_oneshot_broadcast_this_cpu
0.07 ± 62% +0.1 0.18 ± 39% perf-profile.self.cycles-pp.ktime_get_update_offsets_now
0.15 ± 39% +0.1 0.28 ± 22% perf-profile.self.cycles-pp.sched_tick
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] only message in thread
only message in thread, other threads:[~2025-02-06 7:01 UTC | newest]
Thread overview: (only message) (download: mbox.gz follow: Atom feed
-- links below jump to the message on this page --
2025-02-06 7:00 [linus:master] [nfsd] 7e13f4f8d2: postmark.transactions 10.4% regression kernel test robot
This is an external index of several public inboxes,
see mirroring instructions on how to clone and mirror
all data and code used by this external index.