[<prev] [next>] [day] [month] [year] [list]
Message-ID: <202502061435.62604a8d-lkp@intel.com>
Date: Thu, 6 Feb 2025 15:00:58 +0800
From: kernel test robot <oliver.sang@...el.com>
To: Jeff Layton <jlayton@...nel.org>
CC: <oe-lkp@...ts.linux.dev>, <lkp@...el.com>, <linux-kernel@...r.kernel.org>,
Chuck Lever <chuck.lever@...cle.com>, <linux-nfs@...r.kernel.org>,
<oliver.sang@...el.com>
Subject: [linus:master] [nfsd] 7e13f4f8d2: postmark.transactions 10.4%
regression
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@...el.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
Powered by blists - more mailing lists