All of lore.kernel.org
 help / color / mirror / Atom feed
From: kernel test robot <oliver.sang@intel.com>
To: Jeff Layton <jlayton@kernel.org>
Cc: <oe-lkp@lists.linux.dev>, <lkp@intel.com>,
	<linux-kernel@vger.kernel.org>,
	Chuck Lever <chuck.lever@oracle.com>, <linux-nfs@vger.kernel.org>,
	<oliver.sang@intel.com>
Subject: [linus:master] [nfsd]  7e13f4f8d2:  postmark.transactions 10.4% regression
Date: Thu, 6 Feb 2025 15:00:58 +0800	[thread overview]
Message-ID: <202502061435.62604a8d-lkp@intel.com> (raw)



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


                 reply	other threads:[~2025-02-06  7:01 UTC|newest]

Thread overview: [no followups] expand[flat|nested]  mbox.gz  Atom feed

Reply instructions:

You may reply publicly to this message via plain-text email
using any one of the following methods:

* Save the following mbox file, import it into your mail client,
  and reply-to-all from there: mbox

  Avoid top-posting and favor interleaved quoting:
  https://en.wikipedia.org/wiki/Posting_style#Interleaved_style

* Reply using the --to, --cc, and --in-reply-to
  switches of git-send-email(1):

  git send-email \
    --in-reply-to=202502061435.62604a8d-lkp@intel.com \
    --to=oliver.sang@intel.com \
    --cc=chuck.lever@oracle.com \
    --cc=jlayton@kernel.org \
    --cc=linux-kernel@vger.kernel.org \
    --cc=linux-nfs@vger.kernel.org \
    --cc=lkp@intel.com \
    --cc=oe-lkp@lists.linux.dev \
    /path/to/YOUR_REPLY

  https://kernel.org/pub/software/scm/git/docs/git-send-email.html

* If your mail client supports setting the In-Reply-To header
  via mailto: links, try the mailto: link
Be sure your reply has a Subject: header at the top and a blank line before the message body.
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.