[cel:nfsd-testing] [nfsd] ab62726202: fsmark.app_overhead 186.4% regression

[kernel test robot <oliver.sang@intel.com>]

Hello,

kernel test robot noticed a 186.4% regression of fsmark.app_overhead on:
(but no diff for fsmark.files_per_sec as below (a))


commit: ab627262022ed8c6a68e619ed03a14e47acf2e39 ("nfsd: allocate new session-based DRC slots on demand.")
https://git.kernel.org/cgit/linux/kernel/git/cel/linux nfsd-testing

testcase: fsmark
config: x86_64-rhel-9.4
compiler: gcc-12
test machine: 64 threads 2 sockets Intel(R) Xeon(R) Gold 6346 CPU @ 3.10GHz (Ice Lake) with 256G memory
parameters:

	iterations: 1x
	nr_threads: 32t
	disk: 1HDD
	fs: btrfs
	fs2: nfsv4
	filesize: 16MB
	test_size: 15G
	sync_method: NoSync
	nr_directories: 16d
	nr_files_per_directory: 256fpd
	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/202412271641.cfba5666-lkp@intel.com


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


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

=========================================================================================
compiler/cpufreq_governor/disk/filesize/fs2/fs/iterations/kconfig/nr_directories/nr_files_per_directory/nr_threads/rootfs/sync_method/tbox_group/test_size/testcase:
  gcc-12/performance/1HDD/16MB/nfsv4/btrfs/1x/x86_64-rhel-9.4/16d/256fpd/32t/debian-12-x86_64-20240206.cgz/NoSync/lkp-icl-2sp7/15G/fsmark

commit: 
  ccd01c7601 ("nfsd: add session slot count to /proc/fs/nfsd/clients/*/info")
  ab62726202 ("nfsd: allocate new session-based DRC slots on demand.")

ccd01c76017847d1 ab627262022ed8c6a68e619ed03 
---------------- --------------------------- 
         %stddev     %change         %stddev
             \          |                \  
      5.48 ±  9%     +24.9%       6.85 ± 14%  sched_debug.cpu.nr_uninterruptible.stddev
     12489           +11.1%      13876        uptime.idle
 3.393e+08 ± 16%    +186.4%  9.717e+08 ±  9%  fsmark.app_overhead
      6.40            +0.0%       6.40        fsmark.files_per_sec     <-------- (a)
      6.00           +27.8%       7.67 ±  6%  fsmark.time.percent_of_cpu_this_job_got
     72.33           +15.8%      83.79        iostat.cpu.idle
     25.91 ±  3%     -44.3%      14.42 ± 11%  iostat.cpu.iowait
     72.08           +11.6       83.64        mpstat.cpu.all.idle%
     26.18 ±  3%     -11.6       14.58 ± 11%  mpstat.cpu.all.iowait%
    153772 ±  5%     +19.1%     183126 ±  8%  meminfo.DirectMap4k
    156099           +19.5%     186594        meminfo.Dirty
    467358           -12.9%     406910 ±  2%  meminfo.Writeback
     72.35           +15.8%      83.79        vmstat.cpu.id
     25.90 ±  3%     -44.3%      14.41 ± 11%  vmstat.cpu.wa
     17.61 ±  3%     -45.8%       9.55 ± 10%  vmstat.procs.b
      5909 ±  2%      -6.2%       5545        vmstat.system.in
      0.03 ± 56%     -73.4%       0.01 ±149%  perf-sched.sch_delay.avg.ms.btrfs_commit_transaction.btrfs_sync_file.nfsd_commit.nfsd4_commit
      0.05 ± 60%     -72.1%       0.02 ±165%  perf-sched.sch_delay.max.ms.btrfs_commit_transaction.btrfs_sync_file.nfsd_commit.nfsd4_commit
      0.07 ± 41%     +36.1%       0.10 ±  8%  perf-sched.sch_delay.max.ms.schedule_preempt_disabled.rwsem_down_read_slowpath.down_read.btrfs_tree_read_lock_nested
     13.03 ±170%    +566.0%      86.78 ± 77%  perf-sched.wait_and_delay.avg.ms.schedule_preempt_disabled.__mutex_lock.constprop.0.svc_tcp_sendto
    206.83 ± 14%     -31.5%     141.67 ±  6%  perf-sched.wait_and_delay.count.rpc_wait_bit_killable.__wait_on_bit.out_of_line_wait_on_bit.__rpc_execute
      0.30 ± 62%     -82.1%       0.05 ±110%  perf-sched.wait_time.avg.ms.handle_reserve_ticket.__reserve_bytes.btrfs_reserve_data_bytes.btrfs_check_data_free_space
      7.37 ±  4%     -15.8%       6.20 ±  4%  perf-stat.i.MPKI
     44.13 ±  2%      -2.9       41.25 ±  2%  perf-stat.i.cache-miss-rate%
    103.65 ±  2%     +17.9%     122.17 ±  8%  perf-stat.i.cpu-migrations
    627.67 ±  3%     +25.4%     787.18 ±  6%  perf-stat.i.cycles-between-cache-misses
      0.67            +3.7%       0.70        perf-stat.i.ipc
      1.35            +2.2%       1.38        perf-stat.overall.cpi
    373.39            +4.1%     388.79        perf-stat.overall.cycles-between-cache-misses
      0.74            -2.1%       0.73        perf-stat.overall.ipc
    102.89 ±  2%     +17.9%     121.32 ±  8%  perf-stat.ps.cpu-migrations
     39054           +19.0%      46460 ±  2%  proc-vmstat.nr_dirty
     15139            +2.2%      15476        proc-vmstat.nr_kernel_stack
     45710            +1.9%      46570        proc-vmstat.nr_slab_unreclaimable
    116900           -13.5%     101162        proc-vmstat.nr_writeback
     87038           -18.2%      71185 ±  2%  proc-vmstat.nr_zone_write_pending
   6949807            -3.8%    6688660        proc-vmstat.numa_hit
   6882153            -3.8%    6622312        proc-vmstat.numa_local
  13471776            -2.0%   13204489        proc-vmstat.pgalloc_normal
    584292            +3.8%     606391 ±  3%  proc-vmstat.pgfault
     25859            +9.8%      28392 ±  9%  proc-vmstat.pgreuse
      2.02 ±  8%      -0.3        1.71 ±  5%  perf-profile.calltrace.cycles-pp.asm_sysvec_apic_timer_interrupt.cpuidle_enter_state.cpuidle_enter.cpuidle_idle_call.do_idle
      1.86 ±  8%      -0.3        1.58 ±  6%  perf-profile.calltrace.cycles-pp.sysvec_apic_timer_interrupt.asm_sysvec_apic_timer_interrupt.cpuidle_enter_state.cpuidle_enter.cpuidle_idle_call
      3.42 ±  5%      -0.6        2.87 ±  5%  perf-profile.children.cycles-pp.asm_sysvec_apic_timer_interrupt
      2.96 ±  4%      -0.4        2.55 ±  5%  perf-profile.children.cycles-pp.sysvec_apic_timer_interrupt
      0.35 ± 45%      -0.2        0.14 ± 71%  perf-profile.children.cycles-pp.khugepaged
      0.34 ± 46%      -0.2        0.14 ± 71%  perf-profile.children.cycles-pp.hpage_collapse_scan_pmd
      0.34 ± 46%      -0.2        0.14 ± 71%  perf-profile.children.cycles-pp.khugepaged_scan_mm_slot
      0.34 ± 47%      -0.2        0.14 ± 72%  perf-profile.children.cycles-pp.collapse_huge_page
      1.21 ± 10%      -0.2        1.01 ±  8%  perf-profile.children.cycles-pp.__hrtimer_run_queues
      0.82 ±  9%      -0.1        0.68 ± 10%  perf-profile.children.cycles-pp.update_process_times
      0.41 ±  8%      -0.1        0.29 ± 22%  perf-profile.children.cycles-pp.btrfs_check_data_free_space
      0.21 ±  7%      -0.1        0.11 ± 73%  perf-profile.children.cycles-pp.copy_mc_enhanced_fast_string
      0.55 ± 11%      -0.1        0.46 ± 14%  perf-profile.children.cycles-pp.__set_extent_bit
      0.33 ±  9%      -0.1        0.28 ±  8%  perf-profile.children.cycles-pp.nfs_request_add_commit_list
      0.17 ±  9%      -0.0        0.13 ± 16%  perf-profile.children.cycles-pp.readn
      0.08 ± 13%      -0.0        0.06 ± 14%  perf-profile.children.cycles-pp.load_elf_interp
      1.00 ± 16%      +1.2        2.18 ± 53%  perf-profile.children.cycles-pp.folio_batch_move_lru
      0.21 ±  8%      -0.1        0.11 ± 73%  perf-profile.self.cycles-pp.copy_mc_enhanced_fast_string
      0.05 ± 49%      +0.1        0.15 ± 61%  perf-profile.self.cycles-pp.nfs_update_folio
      0.94 ±  5%      +0.2        1.11 ±  4%  perf-profile.self.cycles-pp._raw_spin_lock_irqsave
      0.25 ± 17%      +0.4        0.63 ± 61%  perf-profile.self.cycles-pp.nfs_page_async_flush




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