[<prev] [next>] [<thread-prev] [thread-next>] [day] [month] [year] [list]
Message-ID: <202304210920.e679570a-oliver.sang@intel.com>
Date: Fri, 21 Apr 2023 10:04:17 +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-xfs@...r.kernel.org>, <ying.huang@...el.com>,
<feng.tang@...el.com>, <fengwei.yin@...el.com>,
Alexander Viro <viro@...iv.linux.org.uk>,
Christian Brauner <brauner@...nel.org>,
"Darrick J. Wong" <djwong@...nel.org>,
Hugh Dickins <hughd@...gle.com>,
Andrew Morton <akpm@...ux-foundation.org>,
Dave Chinner <david@...morbit.com>,
Chuck Lever <chuck.lever@...cle.com>,
<linux-fsdevel@...r.kernel.org>, <linux-kernel@...r.kernel.org>,
<linux-mm@...ck.org>, <linux-nfs@...r.kernel.org>
Subject: Re: [RFC PATCH 3/3][RESEND] xfs: mark the inode for high-res
timestamp update in getattr
Hello,
kernel test robot noticed a -4.8% regression of fsmark.files_per_sec on:
commit: 219c0ed2b1f5d2ad921dc206b7b23a0e29e5c516 ("[RFC PATCH 3/3][RESEND] xfs: mark the inode for high-res timestamp update in getattr")
url: https://github.com/intel-lab-lkp/linux/commits/Jeff-Layton/fs-add-infrastructure-for-opportunistic-high-res-ctime-mtime-updates/20230411-223803
base: https://git.kernel.org/cgit/fs/xfs/xfs-linux.git for-next
patch link: https://lore.kernel.org/all/20230411143702.64495-4-jlayton@kernel.org/
patch subject: [RFC PATCH 3/3][RESEND] xfs: mark the inode for high-res timestamp update in getattr
testcase: fsmark
test machine: 96 threads 2 sockets (Ice Lake) with 256G memory
parameters:
iterations: 1x
nr_threads: 1t
disk: 1BRD_32G
fs: xfs
fs2: nfsv4
filesize: 4K
test_size: 4G
sync_method: fsyncBeforeClose
nr_files_per_directory: 1fpd
cpufreq_governor: performance
test-description: The fsmark is a file system benchmark to test synchronous write workloads, for example, mail servers workload.
test-url: https://sourceforge.net/projects/fsmark/
If you fix the issue, kindly add following tag
| Reported-by: kernel test robot <oliver.sang@...el.com>
| Link: https://lore.kernel.org/oe-lkp/202304210920.e679570a-oliver.sang@intel.com
Details are as below:
-------------------------------------------------------------------------------------------------->
To reproduce:
git clone https://github.com/intel/lkp-tests.git
cd lkp-tests
sudo bin/lkp install job.yaml # job file is attached in this email
bin/lkp split-job --compatible job.yaml # generate the yaml file for lkp run
sudo bin/lkp run generated-yaml-file
# if come across any failure that blocks the test,
# please remove ~/.lkp and /lkp dir to run from a clean state.
=========================================================================================
compiler/cpufreq_governor/disk/filesize/fs2/fs/iterations/kconfig/nr_files_per_directory/nr_threads/rootfs/sync_method/tbox_group/test_size/testcase:
gcc-11/performance/1BRD_32G/4K/nfsv4/xfs/1x/x86_64-rhel-8.3/1fpd/1t/debian-11.1-x86_64-20220510.cgz/fsyncBeforeClose/lkp-icl-2sp1/4G/fsmark
commit:
1aa3422f44 ("shmem: mark for high-res timestamps on next update after getattr")
219c0ed2b1 ("xfs: mark the inode for high-res timestamp update in getattr")
1aa3422f44c3001f 219c0ed2b1f5d2ad921dc206b7b
---------------- ---------------------------
%stddev %change %stddev
\ | \
3993 -4.8% 3802 fsmark.files_per_sec
250.44 +5.0% 263.03 fsmark.time.elapsed_time
250.44 +5.0% 263.03 fsmark.time.elapsed_time.max
3182 ± 3% +23.7% 3935 ± 6% fsmark.time.involuntary_context_switches
5761785 +12.9% 6502395 fsmark.time.voluntary_context_switches
4682497 ± 28% -49.1% 2381683 ± 51% numa-meminfo.node0.FilePages
1170661 ± 28% -49.1% 595420 ± 51% numa-vmstat.node0.nr_file_pages
1771594 ± 7% -19.5% 1425973 ± 6% sched_debug.cpu.nr_switches.max
126209 -6.2% 118428 vmstat.io.bo
349577 +2.1% 356924 vmstat.system.cs
1342752 ± 4% +8.3% 1454235 ± 4% turbostat.C1
0.27 -0.0 0.25 ± 2% turbostat.C1%
42.83 ± 3% +36.6% 58.50 ± 21% turbostat.CoreTmp
42.83 ± 3% +36.6% 58.50 ± 21% turbostat.PkgTmp
219.76 +3.5% 227.36 ± 2% turbostat.PkgWatt
167.86 +2.1% 171.31 turbostat.RAMWatt
12018871 +6.4% 12790775 proc-vmstat.numa_hit
11930268 +6.4% 12699729 proc-vmstat.numa_local
313977 +2.1% 320644 proc-vmstat.pgactivate
18057605 +4.3% 18838501 proc-vmstat.pgalloc_normal
781753 +4.3% 815507 proc-vmstat.pgfault
12737726 +6.1% 13516747 proc-vmstat.pgfree
1980800 +4.2% 2064896 proc-vmstat.unevictable_pgs_scanned
1.061e+09 +2.9% 1.092e+09 perf-stat.i.branch-instructions
6265739 ± 7% +16.1% 7274779 ± 7% perf-stat.i.cache-misses
1.751e+08 +2.5% 1.795e+08 perf-stat.i.cache-references
353475 +2.1% 361037 perf-stat.i.context-switches
8.402e+08 +2.0% 8.568e+08 perf-stat.i.dTLB-stores
5.501e+09 +1.8% 5.6e+09 perf-stat.i.instructions
38.10 +2.2% 38.93 perf-stat.i.metric.M/sec
3.58 ± 7% +0.5 4.06 ± 7% perf-stat.overall.cache-miss-rate%
1409 ± 7% -12.8% 1228 ± 6% perf-stat.overall.cycles-between-cache-misses
1.057e+09 +2.9% 1.088e+09 perf-stat.ps.branch-instructions
6241536 ± 7% +16.2% 7250504 ± 7% perf-stat.ps.cache-misses
1.744e+08 +2.5% 1.788e+08 perf-stat.ps.cache-references
352052 +2.2% 359651 perf-stat.ps.context-switches
8.369e+08 +2.0% 8.535e+08 perf-stat.ps.dTLB-stores
5.479e+09 +1.8% 5.579e+09 perf-stat.ps.instructions
1.377e+12 +7.0% 1.474e+12 perf-stat.total.instructions
1.34 ± 12% -0.2 1.10 ± 10% perf-profile.calltrace.cycles-pp.nfs_do_access.nfs_permission.inode_permission.link_path_walk.path_openat
1.35 ± 12% -0.2 1.11 ± 10% perf-profile.calltrace.cycles-pp.nfs_permission.inode_permission.link_path_walk.path_openat.do_filp_open
1.36 ± 12% -0.2 1.12 ± 10% perf-profile.calltrace.cycles-pp.inode_permission.link_path_walk.path_openat.do_filp_open.do_sys_openat2
1.20 ± 12% -0.2 0.96 ± 11% perf-profile.calltrace.cycles-pp.rpc_run_task.nfs4_call_sync_sequence._nfs4_proc_access.nfs4_proc_access.nfs_do_access
1.26 ± 12% -0.2 1.02 ± 11% perf-profile.calltrace.cycles-pp._nfs4_proc_access.nfs4_proc_access.nfs_do_access.nfs_permission.inode_permission
1.26 ± 13% -0.2 1.03 ± 11% perf-profile.calltrace.cycles-pp.nfs4_proc_access.nfs_do_access.nfs_permission.inode_permission.link_path_walk
1.21 ± 12% -0.2 0.98 ± 11% perf-profile.calltrace.cycles-pp.nfs4_call_sync_sequence._nfs4_proc_access.nfs4_proc_access.nfs_do_access.nfs_permission
1.16 ± 12% -0.2 0.94 ± 11% perf-profile.calltrace.cycles-pp.rpc_execute.rpc_run_task.nfs4_call_sync_sequence._nfs4_proc_access.nfs4_proc_access
1.15 ± 12% -0.2 0.93 ± 11% perf-profile.calltrace.cycles-pp.__rpc_execute.rpc_execute.rpc_run_task.nfs4_call_sync_sequence._nfs4_proc_access
1.84 ± 3% -0.2 1.66 ± 5% perf-profile.calltrace.cycles-pp.xlog_cil_push_work.process_one_work.worker_thread.kthread.ret_from_fork
1.39 ± 9% -0.2 1.21 ± 7% perf-profile.calltrace.cycles-pp.nfsd_create_setattr.nfsd_create_locked.nfsd_create.nfsd4_create.nfsd4_proc_compound
1.00 ± 10% -0.2 0.84 ± 9% perf-profile.calltrace.cycles-pp.xlog_state_release_iclog.xlog_force_lsn.xfs_log_force_seq.nfsd_create_setattr.nfsd_create_locked
1.03 ± 10% -0.2 0.86 ± 9% perf-profile.calltrace.cycles-pp.xlog_force_lsn.xfs_log_force_seq.nfsd_create_setattr.nfsd_create_locked.nfsd_create
2.02 ± 4% +0.2 2.27 ± 5% perf-profile.calltrace.cycles-pp.tcp_write_xmit.__tcp_push_pending_frames.tcp_sock_set_cork.svc_tcp_sendto.svc_send
2.04 ± 4% +0.3 2.29 ± 5% perf-profile.calltrace.cycles-pp.__tcp_push_pending_frames.tcp_sock_set_cork.svc_tcp_sendto.svc_send.nfsd
2.20 ± 3% +0.3 2.46 ± 5% perf-profile.calltrace.cycles-pp.tcp_sock_set_cork.svc_tcp_sendto.svc_send.nfsd.kthread
2.29 ± 9% +0.6 2.85 ± 8% perf-profile.calltrace.cycles-pp.path_openat.do_filp_open.do_sys_openat2.__x64_sys_openat.do_syscall_64
2.29 ± 9% +0.6 2.85 ± 8% perf-profile.calltrace.cycles-pp.do_filp_open.do_sys_openat2.__x64_sys_openat.do_syscall_64.entry_SYSCALL_64_after_hwframe
2.34 ± 9% +0.6 2.90 ± 7% perf-profile.calltrace.cycles-pp.do_sys_openat2.__x64_sys_openat.do_syscall_64.entry_SYSCALL_64_after_hwframe.open64
2.35 ± 9% +0.6 2.92 ± 8% perf-profile.calltrace.cycles-pp.entry_SYSCALL_64_after_hwframe.open64
2.34 ± 9% +0.6 2.90 ± 7% perf-profile.calltrace.cycles-pp.__x64_sys_openat.do_syscall_64.entry_SYSCALL_64_after_hwframe.open64
2.39 ± 9% +0.6 2.96 ± 7% perf-profile.calltrace.cycles-pp.open64
2.35 ± 9% +0.6 2.92 ± 8% perf-profile.calltrace.cycles-pp.do_syscall_64.entry_SYSCALL_64_after_hwframe.open64
1.41 ± 12% +0.6 2.04 ± 8% perf-profile.calltrace.cycles-pp.link_path_walk.path_openat.do_filp_open.do_sys_openat2.__x64_sys_openat
0.00 +0.8 0.77 ± 8% perf-profile.calltrace.cycles-pp.__rpc_execute.rpc_execute.rpc_run_task.nfs4_do_call_sync._nfs4_proc_getattr
0.00 +0.8 0.77 ± 9% perf-profile.calltrace.cycles-pp.rpc_execute.rpc_run_task.nfs4_do_call_sync._nfs4_proc_getattr.nfs4_proc_getattr
0.00 +0.8 0.79 ± 8% perf-profile.calltrace.cycles-pp.rpc_run_task.nfs4_do_call_sync._nfs4_proc_getattr.nfs4_proc_getattr.__nfs_revalidate_inode
0.00 +0.8 0.80 ± 9% perf-profile.calltrace.cycles-pp.nfs4_do_call_sync._nfs4_proc_getattr.nfs4_proc_getattr.__nfs_revalidate_inode.nfs_check_verifier
0.00 +0.8 0.80 ± 9% perf-profile.calltrace.cycles-pp._nfs4_proc_getattr.nfs4_proc_getattr.__nfs_revalidate_inode.nfs_check_verifier.nfs_do_lookup_revalidate
0.00 +0.8 0.81 ± 9% perf-profile.calltrace.cycles-pp.nfs4_proc_getattr.__nfs_revalidate_inode.nfs_check_verifier.nfs_do_lookup_revalidate.__nfs_lookup_revalidate
0.00 +0.8 0.84 ± 9% perf-profile.calltrace.cycles-pp.__nfs_revalidate_inode.nfs_check_verifier.nfs_do_lookup_revalidate.__nfs_lookup_revalidate.lookup_fast
0.00 +0.8 0.85 ± 8% perf-profile.calltrace.cycles-pp.nfs_check_verifier.nfs_do_lookup_revalidate.__nfs_lookup_revalidate.lookup_fast.walk_component
0.00 +0.9 0.85 ± 8% perf-profile.calltrace.cycles-pp.nfs_do_lookup_revalidate.__nfs_lookup_revalidate.lookup_fast.walk_component.link_path_walk
0.00 +0.9 0.87 ± 8% perf-profile.calltrace.cycles-pp.__nfs_lookup_revalidate.lookup_fast.walk_component.link_path_walk.path_openat
0.00 +0.9 0.88 ± 9% perf-profile.calltrace.cycles-pp.lookup_fast.walk_component.link_path_walk.path_openat.do_filp_open
0.00 +0.9 0.88 ± 8% perf-profile.calltrace.cycles-pp.walk_component.link_path_walk.path_openat.do_filp_open.do_sys_openat2
1.37 ± 11% -0.2 1.13 ± 9% perf-profile.children.cycles-pp.nfs_do_access
1.46 ± 11% -0.2 1.22 ± 8% perf-profile.children.cycles-pp.inode_permission
1.40 ± 11% -0.2 1.16 ± 8% perf-profile.children.cycles-pp.nfs_permission
1.27 ± 12% -0.2 1.03 ± 11% perf-profile.children.cycles-pp.nfs4_proc_access
1.26 ± 12% -0.2 1.02 ± 11% perf-profile.children.cycles-pp._nfs4_proc_access
1.87 ± 3% -0.2 1.68 ± 5% perf-profile.children.cycles-pp.xlog_cil_push_work
0.08 ± 9% -0.0 0.06 ± 13% perf-profile.children.cycles-pp.tick_program_event
0.08 ± 11% +0.0 0.10 ± 10% perf-profile.children.cycles-pp.refcount_dec_not_one
0.26 ± 8% +0.0 0.30 ± 8% perf-profile.children.cycles-pp.update_curr
0.11 ± 9% +0.0 0.15 ± 11% perf-profile.children.cycles-pp.tcp_rcv_space_adjust
0.24 ± 7% +0.0 0.28 ± 10% perf-profile.children.cycles-pp.skb_release_data
0.17 ± 12% +0.0 0.21 ± 8% perf-profile.children.cycles-pp.napi_consume_skb
0.44 ± 5% +0.0 0.49 ± 3% perf-profile.children.cycles-pp.__might_resched
0.00 +0.1 0.05 ± 8% perf-profile.children.cycles-pp.prepare_to_wait
0.26 ± 8% +0.1 0.32 ± 12% perf-profile.children.cycles-pp.nfsd4_encode_fattr
0.26 ± 8% +0.1 0.32 ± 12% perf-profile.children.cycles-pp.nfsd4_encode_getattr
0.36 ± 5% +0.1 0.46 ± 8% perf-profile.children.cycles-pp.put_cred_rcu
1.49 ± 4% +0.1 1.60 ± 5% perf-profile.children.cycles-pp.inet6_recvmsg
1.47 ± 4% +0.1 1.58 ± 5% perf-profile.children.cycles-pp.tcp_recvmsg
1.72 ± 3% +0.1 1.85 ± 5% perf-profile.children.cycles-pp.sock_recvmsg
1.69 ± 3% +0.2 1.88 ± 3% perf-profile.children.cycles-pp.tcp_rcv_established
1.72 ± 3% +0.2 1.92 ± 3% perf-profile.children.cycles-pp.tcp_v6_do_rcv
2.26 ± 4% +0.2 2.46 ± 4% perf-profile.children.cycles-pp.__netif_receive_skb_one_core
2.15 ± 3% +0.2 2.36 ± 4% perf-profile.children.cycles-pp.ip6_protocol_deliver_rcu
2.09 ± 3% +0.2 2.30 ± 4% perf-profile.children.cycles-pp.tcp_v6_rcv
2.16 ± 3% +0.2 2.36 ± 4% perf-profile.children.cycles-pp.ip6_input_finish
2.32 ± 4% +0.2 2.54 ± 4% perf-profile.children.cycles-pp.__napi_poll
2.32 ± 4% +0.2 2.54 ± 4% perf-profile.children.cycles-pp.process_backlog
2.82 ± 4% +0.3 3.12 ± 3% perf-profile.children.cycles-pp.do_softirq
2.70 ± 4% +0.3 3.00 ± 3% perf-profile.children.cycles-pp.net_rx_action
2.89 ± 4% +0.3 3.20 ± 3% perf-profile.children.cycles-pp.__local_bh_enable_ip
3.43 ± 3% +0.3 3.77 ± 3% perf-profile.children.cycles-pp.ip6_xmit
3.28 ± 4% +0.4 3.64 ± 3% perf-profile.children.cycles-pp.ip6_finish_output2
3.85 ± 2% +0.4 4.22 ± 4% perf-profile.children.cycles-pp.__tcp_transmit_skb
3.50 ± 3% +0.4 3.87 ± 3% perf-profile.children.cycles-pp.inet6_csk_xmit
4.23 ± 2% +0.4 4.62 ± 4% perf-profile.children.cycles-pp.tcp_write_xmit
4.26 ± 2% +0.4 4.66 ± 4% perf-profile.children.cycles-pp.__tcp_push_pending_frames
4.34 ± 2% +0.4 4.75 ± 4% perf-profile.children.cycles-pp.tcp_sock_set_cork
5.24 ± 3% +0.4 5.66 perf-profile.children.cycles-pp.__do_softirq
2.66 ± 9% +0.5 3.12 ± 9% perf-profile.children.cycles-pp.rpc_execute
2.34 ± 9% +0.6 2.89 ± 8% perf-profile.children.cycles-pp.do_filp_open
2.33 ± 9% +0.6 2.89 ± 8% perf-profile.children.cycles-pp.path_openat
2.40 ± 9% +0.6 2.96 ± 7% perf-profile.children.cycles-pp.open64
2.38 ± 9% +0.6 2.95 ± 7% perf-profile.children.cycles-pp.__x64_sys_openat
2.38 ± 8% +0.6 2.95 ± 7% perf-profile.children.cycles-pp.do_sys_openat2
1.52 ± 10% +0.6 2.14 ± 8% perf-profile.children.cycles-pp.link_path_walk
0.00 +0.8 0.80 ± 9% perf-profile.children.cycles-pp.nfs4_do_call_sync
0.00 +0.8 0.80 ± 9% perf-profile.children.cycles-pp._nfs4_proc_getattr
0.00 +0.8 0.81 ± 9% perf-profile.children.cycles-pp.nfs4_proc_getattr
0.00 +0.8 0.84 ± 8% perf-profile.children.cycles-pp.__nfs_revalidate_inode
0.00 +0.8 0.85 ± 8% perf-profile.children.cycles-pp.nfs_check_verifier
0.00 +0.9 0.86 ± 9% perf-profile.children.cycles-pp.nfs_do_lookup_revalidate
0.06 ± 46% +0.9 0.92 ± 8% perf-profile.children.cycles-pp.walk_component
0.04 ± 71% +0.9 0.91 ± 9% perf-profile.children.cycles-pp.lookup_fast
0.00 +0.9 0.87 ± 8% perf-profile.children.cycles-pp.__nfs_lookup_revalidate
0.12 ± 8% +0.0 0.13 ± 8% perf-profile.self.cycles-pp.nfsd_setuser
0.08 ± 14% +0.0 0.10 ± 7% perf-profile.self.cycles-pp.refcount_dec_not_one
0.16 ± 10% +0.0 0.19 ± 6% perf-profile.self.cycles-pp.__might_sleep
0.16 ± 8% +0.0 0.20 ± 10% perf-profile.self.cycles-pp.call_cpuidle
0.06 ± 47% +0.0 0.10 ± 17% perf-profile.self.cycles-pp.put_cred_rcu
0.40 ± 5% +0.0 0.45 ± 3% perf-profile.self.cycles-pp.__might_resched
0.02 ±142% +0.0 0.06 ± 11% perf-profile.self.cycles-pp.apparmor_cred_free
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
View attachment "config-6.3.0-rc1-00016-g219c0ed2b1f5" of type "text/plain" (157266 bytes)
View attachment "job-script" of type "text/plain" (8661 bytes)
View attachment "job.yaml" of type "text/plain" (6129 bytes)
View attachment "reproduce" of type "text/plain" (984 bytes)
Powered by blists - more mailing lists