2022-07-21 02:38:19

by kernel test robot

[permalink] [raw]
Subject: [xfs] 016a23388c: stress-ng.xattr.ops_per_sec 58.4% improvement



Greeting,

FYI, we noticed a 58.4% improvement of stress-ng.xattr.ops_per_sec due to commit:


commit: 016a23388cdcb2740deb1379dc408f21c84efb11 ("xfs: Add order IDs to log items in CIL")
https://git.kernel.org/cgit/linux/kernel/git/next/linux-next.git master

in testcase: stress-ng
on test machine: 96 threads 2 sockets Ice Lake with 256G memory
with following parameters:

nr_threads: 10%
disk: 1HDD
testtime: 60s
fs: xfs
class: filesystem
test: xattr
cpufreq_governor: performance
ucode: 0xb000280






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.

=========================================================================================
class/compiler/cpufreq_governor/disk/fs/kconfig/nr_threads/rootfs/tbox_group/test/testcase/testtime/ucode:
filesystem/gcc-11/performance/1HDD/xfs/x86_64-rhel-8.3/10%/debian-11.1-x86_64-20220510.cgz/lkp-icl-2sp1/xattr/stress-ng/60s/0xb000280

commit:
df7a4a2134 ("xfs: convert CIL busy extents to per-cpu")
016a23388c ("xfs: Add order IDs to log items in CIL")

df7a4a2134b0a201 016a23388cdcb2740deb1379dc4
---------------- ---------------------------
%stddev %change %stddev
\ | \
843.17 -2.2% 824.83 stress-ng.time.percent_of_cpu_this_job_got
513.69 -3.2% 497.00 stress-ng.time.system_time
9.82 ? 4% +55.3% 15.25 stress-ng.time.user_time
2477 ? 11% +43.4% 3554 ? 7% stress-ng.time.voluntary_context_switches
1491 ? 5% +58.4% 2362 ? 2% stress-ng.xattr.ops
24.86 ? 5% +58.4% 39.37 ? 2% stress-ng.xattr.ops_per_sec
478.80 -18.0% 392.44 ? 8% pmeter.Average_Active_Power
5.633e+09 +214.2% 1.77e+10 cpuidle..time
11447924 +218.2% 36431790 cpuidle..usage
90.89 +5.0% 95.40 iostat.cpu.idle
8.89 ? 2% -49.5% 4.49 ? 8% iostat.cpu.system
217336 ? 35% +92.1% 417442 ? 19% numa-numastat.node1.local_node
261800 ? 26% +68.9% 442286 ? 14% numa-numastat.node1.numa_hit
113.84 +225.9% 370.97 uptime.boot
9907 +246.1% 34288 uptime.idle
0.71 ? 21% +1.0 1.74 ? 19% mpstat.cpu.all.irq%
0.03 ? 22% +0.1 0.08 ? 41% mpstat.cpu.all.soft%
8.37 -5.7 2.69 mpstat.cpu.all.sys%
0.22 ? 3% -0.1 0.11 mpstat.cpu.all.usr%
12094 ? 5% +101.1% 24320 ? 3% numa-meminfo.node1.Active
12034 ? 4% +101.6% 24261 ? 3% numa-meminfo.node1.Active(anon)
973721 ? 12% -25.1% 729724 ? 15% numa-meminfo.node1.MemUsed
15765 ? 7% +66.6% 26257 ? 4% numa-meminfo.node1.Shmem
90.00 +5.2% 94.67 vmstat.cpu.id
3583 ? 16% -51.4% 1740 ? 10% vmstat.io.bo
8.00 -75.0% 2.00 vmstat.procs.r
2453 ? 2% -26.1% 1812 ? 7% vmstat.system.cs
3008 ? 4% +101.5% 6063 ? 3% numa-vmstat.node1.nr_active_anon
3941 ? 7% +66.5% 6562 ? 4% numa-vmstat.node1.nr_shmem
3008 ? 4% +101.5% 6063 ? 3% numa-vmstat.node1.nr_zone_active_anon
262153 ? 25% +68.7% 442138 ? 14% numa-vmstat.node1.numa_hit
217650 ? 35% +91.7% 417295 ? 18% numa-vmstat.node1.numa_local
14235 ? 5% +79.7% 25578 ? 3% meminfo.Active
14056 ? 5% +80.7% 25397 ? 3% meminfo.Active(anon)
92299 ? 9% +129.9% 212241 meminfo.AnonHugePages
615106 -26.1% 454392 meminfo.Committed_AS
290246 -9.7% 262214 meminfo.Inactive
289094 -9.7% 261042 meminfo.Inactive(anon)
6443 ? 2% -34.3% 4236 meminfo.PageTables
19670 ? 4% +44.8% 28486 ? 2% meminfo.Shmem
313.00 ? 3% -57.7% 132.50 ? 10% turbostat.Avg_MHz
9.84 ? 2% -4.1 5.73 ? 11% turbostat.Busy%
3178 -27.2% 2313 turbostat.Bzy_MHz
10327 ? 8% +184.5% 29383 ? 9% turbostat.C1
10034241 ? 18% +178.4% 27936135 ? 25% turbostat.C1E
12775500 +195.0% 37683854 turbostat.IRQ
1020 ? 38% +224.5% 3311 ? 28% turbostat.POLL
297.76 ? 2% -21.2% 234.49 ? 12% turbostat.PkgWatt
223.86 -13.5% 193.73 ? 3% turbostat.RAMWatt
3513 ? 5% +80.6% 6345 ? 3% proc-vmstat.nr_active_anon
70910 -9.0% 64528 proc-vmstat.nr_anon_pages
44.67 ? 9% +131.0% 103.17 proc-vmstat.nr_anon_transparent_hugepages
72274 -9.7% 65266 proc-vmstat.nr_inactive_anon
17728 -4.9% 16865 proc-vmstat.nr_kernel_stack
8735 -8.4% 8002 proc-vmstat.nr_mapped
1610 ? 2% -34.3% 1058 proc-vmstat.nr_page_table_pages
4918 ? 4% +44.7% 7117 ? 2% proc-vmstat.nr_shmem
60230 ? 2% -4.5% 57490 proc-vmstat.nr_slab_unreclaimable
3513 ? 5% +80.6% 6345 ? 3% proc-vmstat.nr_zone_active_anon
72274 -9.7% 65266 proc-vmstat.nr_zone_inactive_anon
526617 +49.6% 787853 proc-vmstat.numa_hit
439279 +59.6% 701034 proc-vmstat.numa_local
6101 ?100% +503.4% 36815 ? 18% proc-vmstat.numa_pte_updates
6679 ? 6% +23.6% 8257 ? 3% proc-vmstat.pgactivate
548679 +50.1% 823551 proc-vmstat.pgalloc_normal
295903 +90.0% 562107 proc-vmstat.pgfault
497304 +63.5% 812879 proc-vmstat.pgfree
238034 ? 15% +43.6% 341879 ? 10% proc-vmstat.pgpgout
14893 ? 2% +85.7% 27658 proc-vmstat.pgreuse
0.35 ? 8% -18.1% 0.29 ? 5% sched_debug.cfs_rq:/.h_nr_running.stddev
106.04 ? 33% -46.4% 56.82 ? 16% sched_debug.cfs_rq:/.load_avg.avg
15560 ? 86% +205.3% 47503 ? 9% sched_debug.cfs_rq:/.min_vruntime.avg
90820 ? 97% +216.6% 287499 ? 10% sched_debug.cfs_rq:/.min_vruntime.max
2780 ? 31% +93.1% 5368 ? 33% sched_debug.cfs_rq:/.min_vruntime.min
19585 ?113% +258.6% 70232 ? 14% sched_debug.cfs_rq:/.min_vruntime.stddev
0.35 ? 8% -18.1% 0.29 ? 5% sched_debug.cfs_rq:/.nr_running.stddev
45.49 ? 44% -45.0% 25.01 ? 40% sched_debug.cfs_rq:/.removed.load_avg.avg
310.83 ? 17% -52.0% 149.13 ? 14% sched_debug.cfs_rq:/.runnable_avg.avg
1420 ? 23% -36.7% 898.99 ? 11% sched_debug.cfs_rq:/.runnable_avg.max
342.97 ? 8% -33.6% 227.68 ? 5% sched_debug.cfs_rq:/.runnable_avg.stddev
-9923 +1391.8% -148037 sched_debug.cfs_rq:/.spread0.min
19585 ?113% +258.6% 70232 ? 14% sched_debug.cfs_rq:/.spread0.stddev
310.20 ? 17% -52.0% 148.85 ? 14% sched_debug.cfs_rq:/.util_avg.avg
1418 ? 23% -36.6% 898.51 ? 11% sched_debug.cfs_rq:/.util_avg.max
342.64 ? 8% -33.6% 227.58 ? 5% sched_debug.cfs_rq:/.util_avg.stddev
848.67 ? 23% -48.6% 436.58 ? 8% sched_debug.cfs_rq:/.util_est_enqueued.max
827890 ? 4% +12.1% 928356 sched_debug.cpu.avg_idle.avg
32263 ?135% +831.1% 300388 ? 39% sched_debug.cpu.avg_idle.min
222276 ? 9% -40.7% 131779 ? 12% sched_debug.cpu.avg_idle.stddev
60070 ? 25% +336.9% 262476 ? 4% sched_debug.cpu.clock.avg
60074 ? 25% +336.9% 262478 ? 4% sched_debug.cpu.clock.max
60064 ? 25% +337.0% 262472 ? 4% sched_debug.cpu.clock.min
59945 ? 25% +335.6% 261099 ? 4% sched_debug.cpu.clock_task.avg
59997 ? 25% +335.5% 261307 ? 4% sched_debug.cpu.clock_task.max
58085 ? 25% +346.0% 259079 ? 4% sched_debug.cpu.clock_task.min
536.59 ? 24% -34.9% 349.39 ? 4% sched_debug.cpu.curr->pid.avg
4447 ? 14% +58.2% 7035 ? 4% sched_debug.cpu.curr->pid.max
0.00 ? 15% -36.9% 0.00 ? 10% sched_debug.cpu.next_balance.stddev
0.15 ? 28% -49.1% 0.08 ? 7% sched_debug.cpu.nr_running.avg
0.35 ? 10% -31.5% 0.24 ? 2% sched_debug.cpu.nr_running.stddev
3353 ? 11% +62.1% 5436 ? 9% sched_debug.cpu.nr_switches.avg
17866 ? 11% +124.0% 40021 ? 34% sched_debug.cpu.nr_switches.max
661.50 ? 21% +64.2% 1086 ? 18% sched_debug.cpu.nr_switches.min
2979 ? 11% +94.4% 5791 ? 31% sched_debug.cpu.nr_switches.stddev
60067 ? 25% +337.0% 262474 ? 4% sched_debug.cpu_clk
58894 ? 25% +343.7% 261303 ? 4% sched_debug.ktime
61215 ? 24% +330.6% 263578 ? 4% sched_debug.sched_clk
3.842e+09 ? 8% -47.9% 2.003e+09 ? 2% perf-stat.i.branch-instructions
0.96 ? 10% +3.0 3.99 ? 73% perf-stat.i.branch-miss-rate%
35273566 ? 13% -39.9% 21212356 ? 29% perf-stat.i.branch-misses
33.21 ? 21% -22.6 10.64 ? 39% perf-stat.i.cache-miss-rate%
39230775 ? 11% -76.8% 9108485 ? 3% perf-stat.i.cache-misses
1.218e+08 ? 19% -50.2% 60677990 ? 59% perf-stat.i.cache-references
2174 ? 4% -21.4% 1710 ? 8% perf-stat.i.context-switches
1.45 ? 5% +109.1% 3.04 ? 36% perf-stat.i.cpi
3.038e+10 ? 6% -60.8% 1.19e+10 ? 9% perf-stat.i.cpu-cycles
115.00 -8.5% 105.24 perf-stat.i.cpu-migrations
930.40 ? 11% +807.4% 8442 ? 44% perf-stat.i.cycles-between-cache-misses
5.78e+09 ? 5% -47.2% 3.05e+09 ? 2% perf-stat.i.dTLB-loads
0.00 ? 63% +0.1 0.09 ? 79% perf-stat.i.dTLB-store-miss-rate%
3.463e+09 ? 5% -47.3% 1.826e+09 perf-stat.i.dTLB-stores
2.093e+10 ? 8% -47.8% 1.093e+10 ? 2% perf-stat.i.instructions
0.70 ? 4% -22.9% 0.54 ? 12% perf-stat.i.ipc
10.70 ? 2% -61.1% 4.17 ? 3% perf-stat.i.major-faults
0.32 ? 6% -60.8% 0.12 ? 9% perf-stat.i.metric.GHz
137.52 ? 6% -47.7% 71.91 ? 2% perf-stat.i.metric.M/sec
3181 ? 6% -24.0% 2417 perf-stat.i.minor-faults
93.71 -4.0 89.73 perf-stat.i.node-load-miss-rate%
8478134 ? 11% -79.5% 1740664 ? 7% perf-stat.i.node-load-misses
7706433 ? 13% -71.6% 2187419 ? 12% perf-stat.i.node-store-misses
5223169 ? 11% -80.5% 1020854 ? 17% perf-stat.i.node-stores
3191 ? 6% -24.1% 2421 perf-stat.i.page-faults
1.46 ? 4% -25.3% 1.09 ? 8% perf-stat.overall.cpi
785.78 ? 14% +66.3% 1306 ? 9% perf-stat.overall.cycles-between-cache-misses
0.69 ? 5% +34.5% 0.93 ? 8% perf-stat.overall.ipc
59.45 ? 7% +8.6 68.05 ? 8% perf-stat.overall.node-store-miss-rate%
3.783e+09 ? 8% -47.1% 2e+09 ? 2% perf-stat.ps.branch-instructions
34716095 ? 13% -39.1% 21149916 ? 29% perf-stat.ps.branch-misses
38631233 ? 11% -76.4% 9098630 ? 3% perf-stat.ps.cache-misses
1.199e+08 ? 19% -49.6% 60460531 ? 59% perf-stat.ps.cache-references
2140 ? 4% -20.5% 1702 ? 8% perf-stat.ps.context-switches
94513 +1.1% 95508 perf-stat.ps.cpu-clock
2.991e+10 ? 6% -60.3% 1.188e+10 ? 9% perf-stat.ps.cpu-cycles
113.21 -7.5% 104.73 perf-stat.ps.cpu-migrations
5.691e+09 ? 5% -46.5% 3.046e+09 ? 2% perf-stat.ps.dTLB-loads
3.409e+09 ? 5% -46.5% 1.823e+09 perf-stat.ps.dTLB-stores
2.061e+10 ? 8% -47.0% 1.092e+10 ? 2% perf-stat.ps.instructions
10.46 ? 2% -60.5% 4.14 ? 3% perf-stat.ps.major-faults
3120 ? 6% -23.0% 2402 perf-stat.ps.minor-faults
8348621 ? 11% -79.2% 1738832 ? 8% perf-stat.ps.node-load-misses
7588743 ? 13% -71.2% 2184925 ? 12% perf-stat.ps.node-store-misses
5142977 ? 11% -80.2% 1019871 ? 17% perf-stat.ps.node-stores
3130 ? 5% -23.1% 2407 perf-stat.ps.page-faults
94513 +1.1% 95508 perf-stat.ps.task-clock
1.324e+12 ? 8% +60.1% 2.119e+12 ? 2% perf-stat.total.instructions
25.64 ? 8% -25.6 0.00 perf-profile.calltrace.cycles-pp.native_queued_spin_lock_slowpath._raw_spin_lock.xlog_cil_insert_items.xlog_cil_commit.__xfs_trans_commit
21.54 ? 5% -16.3 5.22 ? 5% perf-profile.calltrace.cycles-pp.xlog_cil_insert_items.xlog_cil_commit.__xfs_trans_commit.xfs_trans_roll.xfs_defer_trans_roll
16.13 ? 8% -16.1 0.00 perf-profile.calltrace.cycles-pp._raw_spin_lock.xlog_cil_insert_items.xlog_cil_commit.__xfs_trans_commit.xfs_trans_roll
31.27 ? 3% -13.6 17.62 ? 3% perf-profile.calltrace.cycles-pp.xlog_cil_commit.__xfs_trans_commit.xfs_trans_roll.xfs_defer_trans_roll.xfs_defer_finish_noroll
33.10 ? 3% -13.2 19.95 ? 3% perf-profile.calltrace.cycles-pp.__xfs_trans_commit.xfs_trans_roll.xfs_defer_trans_roll.xfs_defer_finish_noroll.__xfs_trans_commit
34.69 ? 2% -12.4 22.26 ? 3% perf-profile.calltrace.cycles-pp.xfs_defer_trans_roll.xfs_defer_finish_noroll.__xfs_trans_commit.xfs_attr_set.xfs_xattr_set
33.95 ? 3% -12.4 21.54 ? 3% perf-profile.calltrace.cycles-pp.xfs_trans_roll.xfs_defer_trans_roll.xfs_defer_finish_noroll.__xfs_trans_commit.xfs_attr_set
11.58 ? 8% -11.6 0.00 perf-profile.calltrace.cycles-pp._raw_spin_lock.xlog_cil_insert_items.xlog_cil_commit.__xfs_trans_commit.xfs_attr_set
14.31 ? 5% -11.6 2.76 ? 6% perf-profile.calltrace.cycles-pp.xlog_cil_insert_items.xlog_cil_commit.__xfs_trans_commit.xfs_attr_set.xfs_xattr_set
65.10 ? 2% -7.8 57.26 ? 2% perf-profile.calltrace.cycles-pp.xfs_attr_set.xfs_xattr_set.__vfs_setxattr.__vfs_setxattr_noperm.vfs_setxattr
65.22 ? 2% -7.8 57.46 ? 2% perf-profile.calltrace.cycles-pp.xfs_xattr_set.__vfs_setxattr.__vfs_setxattr_noperm.vfs_setxattr.setxattr
17.42 ? 3% -7.1 10.36 ? 2% perf-profile.calltrace.cycles-pp.xlog_cil_commit.__xfs_trans_commit.xfs_attr_set.xfs_xattr_set.__vfs_setxattr
39.10 ? 2% -6.0 33.14 ? 3% perf-profile.calltrace.cycles-pp.xfs_defer_finish_noroll.__xfs_trans_commit.xfs_attr_set.xfs_xattr_set.__vfs_setxattr
38.62 ? 2% -5.3 33.28 ? 2% perf-profile.calltrace.cycles-pp.__vfs_setxattr.__vfs_setxattr_noperm.vfs_setxattr.setxattr.path_setxattr
19.28 ? 2% -2.7 16.60 ? 2% perf-profile.calltrace.cycles-pp.__vfs_setxattr_noperm.vfs_setxattr.setxattr.path_setxattr.__x64_sys_lsetxattr
19.38 ? 2% -2.6 16.74 ? 2% perf-profile.calltrace.cycles-pp.__vfs_setxattr_noperm.vfs_setxattr.setxattr.path_setxattr.__x64_sys_setxattr
19.35 ? 2% -2.6 16.72 ? 2% perf-profile.calltrace.cycles-pp.vfs_setxattr.setxattr.path_setxattr.__x64_sys_lsetxattr.do_syscall_64
19.46 ? 2% -2.6 16.87 ? 2% perf-profile.calltrace.cycles-pp.vfs_setxattr.setxattr.path_setxattr.__x64_sys_setxattr.do_syscall_64
19.53 ? 2% -2.5 17.00 ? 2% perf-profile.calltrace.cycles-pp.setxattr.path_setxattr.__x64_sys_lsetxattr.do_syscall_64.entry_SYSCALL_64_after_hwframe
19.62 ? 2% -2.5 17.13 ? 2% perf-profile.calltrace.cycles-pp.setxattr.path_setxattr.__x64_sys_setxattr.do_syscall_64.entry_SYSCALL_64_after_hwframe
26.65 ? 2% -2.4 24.26 ? 2% perf-profile.calltrace.cycles-pp.__vfs_setxattr.__vfs_setxattr_noperm.vfs_setxattr.setxattr.__x64_sys_fsetxattr
26.68 ? 2% -2.4 24.31 ? 2% perf-profile.calltrace.cycles-pp.__vfs_setxattr_noperm.vfs_setxattr.setxattr.__x64_sys_fsetxattr.do_syscall_64
19.94 ? 2% -2.3 17.65 ? 2% perf-profile.calltrace.cycles-pp.path_setxattr.__x64_sys_lsetxattr.do_syscall_64.entry_SYSCALL_64_after_hwframe.lsetxattr
19.95 ? 2% -2.3 17.66 ? 2% perf-profile.calltrace.cycles-pp.__x64_sys_lsetxattr.do_syscall_64.entry_SYSCALL_64_after_hwframe.lsetxattr
26.84 ? 2% -2.3 24.56 ? 2% perf-profile.calltrace.cycles-pp.vfs_setxattr.setxattr.__x64_sys_fsetxattr.do_syscall_64.entry_SYSCALL_64_after_hwframe
19.99 ? 2% -2.3 17.73 ? 2% perf-profile.calltrace.cycles-pp.do_syscall_64.entry_SYSCALL_64_after_hwframe.lsetxattr
20.01 ? 2% -2.2 17.76 ? 2% perf-profile.calltrace.cycles-pp.entry_SYSCALL_64_after_hwframe.lsetxattr
20.02 ? 2% -2.2 17.79 ? 2% perf-profile.calltrace.cycles-pp.path_setxattr.__x64_sys_setxattr.do_syscall_64.entry_SYSCALL_64_after_hwframe.setxattr
20.04 ? 2% -2.2 17.81 ? 2% perf-profile.calltrace.cycles-pp.__x64_sys_setxattr.do_syscall_64.entry_SYSCALL_64_after_hwframe.setxattr
20.08 ? 2% -2.2 17.86 ? 2% perf-profile.calltrace.cycles-pp.lsetxattr
20.08 ? 2% -2.2 17.88 ? 2% perf-profile.calltrace.cycles-pp.do_syscall_64.entry_SYSCALL_64_after_hwframe.setxattr
20.10 ? 2% -2.2 17.91 ? 2% perf-profile.calltrace.cycles-pp.entry_SYSCALL_64_after_hwframe.setxattr
20.16 ? 2% -2.1 18.01 ? 2% perf-profile.calltrace.cycles-pp.setxattr
27.16 ? 2% -2.1 25.08 ? 2% perf-profile.calltrace.cycles-pp.setxattr.__x64_sys_fsetxattr.do_syscall_64.entry_SYSCALL_64_after_hwframe.fsetxattr
27.26 ? 2% -2.0 25.25 ? 2% perf-profile.calltrace.cycles-pp.__x64_sys_fsetxattr.do_syscall_64.entry_SYSCALL_64_after_hwframe.fsetxattr
27.34 ? 2% -2.0 25.37 ? 2% perf-profile.calltrace.cycles-pp.do_syscall_64.entry_SYSCALL_64_after_hwframe.fsetxattr
27.39 ? 2% -1.9 25.45 ? 2% perf-profile.calltrace.cycles-pp.entry_SYSCALL_64_after_hwframe.fsetxattr
27.50 ? 2% -1.9 25.62 ? 2% perf-profile.calltrace.cycles-pp.fsetxattr
4.34 -1.9 2.48 ? 4% perf-profile.calltrace.cycles-pp.xlog_cil_commit.__xfs_trans_commit.xfs_attr_set.xfs_xattr_set.__vfs_removexattr
13.88 -1.0 12.90 ? 3% perf-profile.calltrace.cycles-pp.xfs_attr_set.xfs_xattr_set.__vfs_removexattr.__vfs_removexattr_locked.vfs_removexattr
13.91 -1.0 12.94 ? 3% perf-profile.calltrace.cycles-pp.xfs_xattr_set.__vfs_removexattr.__vfs_removexattr_locked.vfs_removexattr.removexattr
9.23 -0.6 8.64 ? 3% perf-profile.calltrace.cycles-pp.__vfs_removexattr.__vfs_removexattr_locked.vfs_removexattr.removexattr.path_removexattr
7.16 -0.4 6.75 ? 3% perf-profile.calltrace.cycles-pp.__xfs_trans_commit.xfs_attr_set.xfs_xattr_set.__vfs_removexattr.__vfs_removexattr_locked
4.70 -0.4 4.32 ? 3% perf-profile.calltrace.cycles-pp.__vfs_removexattr.__vfs_removexattr_locked.vfs_removexattr.removexattr.__x64_sys_fremovexattr
4.71 -0.4 4.35 ? 3% perf-profile.calltrace.cycles-pp.__vfs_removexattr_locked.vfs_removexattr.removexattr.__x64_sys_fremovexattr.do_syscall_64
4.72 -0.4 4.36 ? 3% perf-profile.calltrace.cycles-pp.vfs_removexattr.removexattr.__x64_sys_fremovexattr.do_syscall_64.entry_SYSCALL_64_after_hwframe
4.74 -0.3 4.39 ? 2% perf-profile.calltrace.cycles-pp.removexattr.__x64_sys_fremovexattr.do_syscall_64.entry_SYSCALL_64_after_hwframe.fremovexattr
4.76 -0.3 4.42 ? 2% perf-profile.calltrace.cycles-pp.__x64_sys_fremovexattr.do_syscall_64.entry_SYSCALL_64_after_hwframe.fremovexattr
4.77 -0.3 4.44 ? 2% perf-profile.calltrace.cycles-pp.do_syscall_64.entry_SYSCALL_64_after_hwframe.fremovexattr
4.78 -0.3 4.45 ? 2% perf-profile.calltrace.cycles-pp.entry_SYSCALL_64_after_hwframe.fremovexattr
4.63 -0.3 4.31 ? 3% perf-profile.calltrace.cycles-pp.__vfs_removexattr_locked.vfs_removexattr.removexattr.path_removexattr.__x64_sys_lremovexattr
4.64 -0.3 4.32 ? 2% perf-profile.calltrace.cycles-pp.vfs_removexattr.removexattr.path_removexattr.__x64_sys_lremovexattr.do_syscall_64
4.80 -0.3 4.48 ? 2% perf-profile.calltrace.cycles-pp.fremovexattr
4.65 -0.3 4.35 ? 2% perf-profile.calltrace.cycles-pp.removexattr.path_removexattr.__x64_sys_lremovexattr.do_syscall_64.entry_SYSCALL_64_after_hwframe
4.64 -0.2 4.39 ? 3% perf-profile.calltrace.cycles-pp.__vfs_removexattr_locked.vfs_removexattr.removexattr.path_removexattr.__x64_sys_removexattr
4.64 -0.2 4.40 ? 3% perf-profile.calltrace.cycles-pp.vfs_removexattr.removexattr.path_removexattr.__x64_sys_removexattr.do_syscall_64
4.66 -0.2 4.43 ? 3% perf-profile.calltrace.cycles-pp.removexattr.path_removexattr.__x64_sys_removexattr.do_syscall_64.entry_SYSCALL_64_after_hwframe
0.58 ? 6% +0.3 0.88 ? 4% perf-profile.calltrace.cycles-pp.xfs_da3_node_lookup_int.xfs_attr_node_lookup.xfs_attr_node_addname_find_attr.xfs_attr_node_addname.xfs_xattri_finish_update
0.58 ? 6% +0.3 0.90 ? 4% perf-profile.calltrace.cycles-pp.xfs_attr_node_lookup.xfs_attr_node_addname_find_attr.xfs_attr_node_addname.xfs_xattri_finish_update.xfs_attr_finish_item
0.59 ? 8% +0.3 0.91 ? 4% perf-profile.calltrace.cycles-pp.user_path_at_empty.path_getxattr.do_syscall_64.entry_SYSCALL_64_after_hwframe.lgetxattr
0.18 ?141% +0.5 0.63 ? 6% perf-profile.calltrace.cycles-pp.xlog_cil_insert_format_items.xlog_cil_insert_items.xlog_cil_commit.__xfs_trans_commit.xfs_attr_set
0.09 ?223% +0.5 0.60 ? 3% perf-profile.calltrace.cycles-pp.xfs_attr3_leaf_add.xfs_attr_node_addname.xfs_xattri_finish_update.xfs_attr_finish_item.xfs_defer_finish_one
0.00 +0.5 0.54 ? 6% perf-profile.calltrace.cycles-pp.user_path_at_empty.path_setxattr.__x64_sys_setxattr.do_syscall_64.entry_SYSCALL_64_after_hwframe
0.00 +0.6 0.56 ? 3% perf-profile.calltrace.cycles-pp.getname_flags.user_path_at_empty.path_getxattr.do_syscall_64.entry_SYSCALL_64_after_hwframe
0.00 +0.6 0.58 ? 4% perf-profile.calltrace.cycles-pp.link_path_walk.path_lookupat.filename_lookup.user_path_at_empty.path_getxattr
0.66 ? 6% +0.6 1.28 ? 34% perf-profile.calltrace.cycles-pp.xfs_attr_node_addname_find_attr.xfs_attr_node_addname.xfs_xattri_finish_update.xfs_attr_finish_item.xfs_defer_finish_one
1.92 ? 7% +0.6 2.54 ? 3% perf-profile.calltrace.cycles-pp.xlog_cil_insert_format_items.xlog_cil_insert_items.xlog_cil_commit.__xfs_trans_commit.xfs_trans_roll
0.00 +0.6 0.63 ? 11% perf-profile.calltrace.cycles-pp.down_read.xlog_cil_commit.__xfs_trans_commit.xfs_attr_set.xfs_xattr_set
1.12 ? 8% +0.6 1.75 ? 3% perf-profile.calltrace.cycles-pp.user_path_at_empty.path_getxattr.do_syscall_64.entry_SYSCALL_64_after_hwframe.getxattr
1.78 ? 5% +0.6 2.42 ? 5% perf-profile.calltrace.cycles-pp.xfs_attr3_leaf_flipflags.xfs_attr_set_iter.xfs_xattri_finish_update.xfs_attr_finish_item.xfs_defer_finish_one
0.91 ? 6% +0.7 1.64 ? 3% perf-profile.calltrace.cycles-pp.xfs_xattr_get.vfs_getxattr.do_getxattr.getxattr.__x64_sys_fgetxattr
0.97 ? 6% +0.8 1.72 ? 3% perf-profile.calltrace.cycles-pp.vfs_getxattr.do_getxattr.getxattr.__x64_sys_fgetxattr.do_syscall_64
1.05 ? 5% +0.8 1.86 ? 3% perf-profile.calltrace.cycles-pp.do_getxattr.getxattr.__x64_sys_fgetxattr.do_syscall_64.entry_SYSCALL_64_after_hwframe
1.10 ? 4% +0.8 1.92 ? 3% perf-profile.calltrace.cycles-pp.getxattr.path_getxattr.do_syscall_64.entry_SYSCALL_64_after_hwframe.lgetxattr
1.11 ? 5% +0.8 1.95 ? 3% perf-profile.calltrace.cycles-pp.getxattr.__x64_sys_fgetxattr.do_syscall_64.entry_SYSCALL_64_after_hwframe.fgetxattr
1.13 ? 5% +0.9 1.99 ? 3% perf-profile.calltrace.cycles-pp.__x64_sys_fgetxattr.do_syscall_64.entry_SYSCALL_64_after_hwframe.fgetxattr
2.33 ? 3% +0.9 3.20 ? 7% perf-profile.calltrace.cycles-pp.xfs_log_ticket_ungrant.xlog_cil_commit.__xfs_trans_commit.xfs_attr_set.xfs_xattr_set
1.16 ? 5% +0.9 2.04 ? 3% perf-profile.calltrace.cycles-pp.do_syscall_64.entry_SYSCALL_64_after_hwframe.fgetxattr
0.64 ? 8% +0.9 1.53 ? 3% perf-profile.calltrace.cycles-pp.path_lookupat.filename_lookup.user_path_at_empty.path_getxattr.do_syscall_64
1.18 ? 5% +0.9 2.08 ? 2% perf-profile.calltrace.cycles-pp.entry_SYSCALL_64_after_hwframe.fgetxattr
0.68 ? 8% +0.9 1.61 ? 3% perf-profile.calltrace.cycles-pp.filename_lookup.user_path_at_empty.path_getxattr.do_syscall_64.entry_SYSCALL_64_after_hwframe
1.23 ? 5% +0.9 2.17 ? 2% perf-profile.calltrace.cycles-pp.fgetxattr
1.94 ? 7% +1.0 2.98 ? 4% perf-profile.calltrace.cycles-pp.xfs_trans_read_buf_map.xfs_da_read_buf.xfs_da3_node_lookup_int.xfs_attr_node_remove_attr.xfs_attr_set_iter
1.75 ? 4% +1.2 2.93 ? 3% perf-profile.calltrace.cycles-pp.path_getxattr.do_syscall_64.entry_SYSCALL_64_after_hwframe.lgetxattr
2.66 ? 7% +1.2 3.84 ? 4% perf-profile.calltrace.cycles-pp.xfs_attr_node_addname.xfs_xattri_finish_update.xfs_attr_finish_item.xfs_defer_finish_one.xfs_defer_finish_noroll
1.81 ? 4% +1.2 3.04 ? 3% perf-profile.calltrace.cycles-pp.do_syscall_64.entry_SYSCALL_64_after_hwframe.lgetxattr
1.85 ? 4% +1.2 3.09 ? 3% perf-profile.calltrace.cycles-pp.entry_SYSCALL_64_after_hwframe.lgetxattr
2.34 ? 5% +1.3 3.62 ? 3% perf-profile.calltrace.cycles-pp.xfs_da_read_buf.xfs_da3_node_lookup_int.xfs_attr_node_remove_attr.xfs_attr_set_iter.xfs_xattri_finish_update
1.95 ? 4% +1.3 3.26 ? 3% perf-profile.calltrace.cycles-pp.lgetxattr
0.70 ? 94% +1.3 2.03 ? 6% perf-profile.calltrace.cycles-pp.xfs_attr3_leaf_read.xfs_attr3_leaf_flipflags.xfs_attr_set_iter.xfs_xattri_finish_update.xfs_attr_finish_item
0.52 ?115% +1.5 2.00 ? 5% perf-profile.calltrace.cycles-pp.xfs_da_read_buf.xfs_attr3_leaf_read.xfs_attr3_leaf_flipflags.xfs_attr_set_iter.xfs_xattri_finish_update
2.68 ? 3% +1.6 4.24 ? 3% perf-profile.calltrace.cycles-pp.xfs_da3_node_lookup_int.xfs_attr_node_remove_attr.xfs_attr_set_iter.xfs_xattri_finish_update.xfs_attr_finish_item
0.00 +1.6 1.58 ? 6% perf-profile.calltrace.cycles-pp.xfs_perag_get.xfs_buf_find.xfs_buf_get_map.xfs_buf_read_map.xfs_trans_read_buf_map
2.52 ? 3% +1.6 4.14 ? 3% perf-profile.calltrace.cycles-pp.xfs_trans_read_buf_map.xfs_da_read_buf.xfs_da3_node_lookup_int.xfs_attr_node_lookup.xfs_attr_set
2.24 ? 6% +1.7 3.95 ? 2% perf-profile.calltrace.cycles-pp.getxattr.path_getxattr.do_syscall_64.entry_SYSCALL_64_after_hwframe.getxattr
0.00 +1.7 1.74 ? 6% perf-profile.calltrace.cycles-pp.xfs_trans_read_buf_map.xfs_da_read_buf.xfs_attr3_leaf_read.xfs_attr3_leaf_flipflags.xfs_attr_set_iter
0.00 +1.9 1.86 ? 10% perf-profile.calltrace.cycles-pp.down_read.xlog_cil_commit.__xfs_trans_commit.xfs_trans_roll.xfs_defer_trans_roll
3.07 ? 4% +2.0 5.03 ? 3% perf-profile.calltrace.cycles-pp.xfs_da_read_buf.xfs_da3_node_lookup_int.xfs_attr_node_lookup.xfs_attr_set.xfs_xattr_set
2.68 ? 5% +2.1 4.83 ? 2% perf-profile.calltrace.cycles-pp.xfs_xattr_get.vfs_getxattr.do_getxattr.getxattr.path_getxattr
2.01 ? 17% +2.2 4.22 ? 2% perf-profile.calltrace.cycles-pp.xfs_da_read_buf.xfs_da3_node_lookup_int.xfs_attr_node_lookup.xfs_attr_node_get.xfs_attr_get
2.82 ? 5% +2.2 5.05 ? 2% perf-profile.calltrace.cycles-pp.vfs_getxattr.do_getxattr.getxattr.path_getxattr.do_syscall_64
2.60 ? 3% +2.2 4.83 ? 3% perf-profile.calltrace.cycles-pp.xfs_trans_alloc_inode.xfs_attr_set.xfs_xattr_set.__vfs_setxattr.__vfs_setxattr_noperm
2.57 ? 7% +2.3 4.85 ? 2% perf-profile.calltrace.cycles-pp.xfs_da3_node_lookup_int.xfs_attr_node_lookup.xfs_attr_node_get.xfs_attr_get.xfs_xattr_get
2.59 ? 7% +2.3 4.87 ? 2% perf-profile.calltrace.cycles-pp.xfs_attr_node_lookup.xfs_attr_node_get.xfs_attr_get.xfs_xattr_get.vfs_getxattr
3.50 ? 3% +2.3 5.81 ? 3% perf-profile.calltrace.cycles-pp.xfs_da3_node_lookup_int.xfs_attr_node_lookup.xfs_attr_set.xfs_xattr_set.__vfs_setxattr
3.52 ? 3% +2.3 5.85 ? 3% perf-profile.calltrace.cycles-pp.xfs_attr_node_lookup.xfs_attr_set.xfs_xattr_set.__vfs_setxattr.__vfs_setxattr_noperm
3.04 ? 5% +2.4 5.41 ? 2% perf-profile.calltrace.cycles-pp.do_getxattr.getxattr.path_getxattr.do_syscall_64.entry_SYSCALL_64_after_hwframe
3.48 ? 6% +2.4 5.89 ? 2% perf-profile.calltrace.cycles-pp.path_getxattr.do_syscall_64.entry_SYSCALL_64_after_hwframe.getxattr
0.26 ?223% +2.4 2.68 ? 4% perf-profile.calltrace.cycles-pp.xfs_buf_read_map.xfs_trans_read_buf_map.xfs_da_read_buf.xfs_da3_node_lookup_int.xfs_attr_node_remove_attr
0.18 ?141% +2.4 2.62 ? 6% perf-profile.calltrace.cycles-pp.xlog_grant_add_space.xfs_log_reserve.xfs_trans_reserve.xfs_trans_alloc.xfs_trans_alloc_inode
3.60 ? 6% +2.5 6.09 ? 2% perf-profile.calltrace.cycles-pp.do_syscall_64.entry_SYSCALL_64_after_hwframe.getxattr
3.66 ? 6% +2.5 6.18 ? 2% perf-profile.calltrace.cycles-pp.entry_SYSCALL_64_after_hwframe.getxattr
0.84 ? 9% +2.5 3.39 ? 2% perf-profile.calltrace.cycles-pp.xfs_trans_read_buf_map.xfs_da_read_buf.xfs_da3_node_lookup_int.xfs_attr_node_lookup.xfs_attr_node_get
3.85 ? 6% +2.6 6.50 ? 3% perf-profile.calltrace.cycles-pp.getxattr
3.30 ? 6% +2.7 6.01 ? 2% perf-profile.calltrace.cycles-pp.xfs_attr_node_get.xfs_attr_get.xfs_xattr_get.vfs_getxattr.do_getxattr
1.81 ? 23% +2.7 4.54 ? 4% perf-profile.calltrace.cycles-pp.xfs_trans_alloc.xfs_trans_alloc_inode.xfs_attr_set.xfs_xattr_set.__vfs_setxattr
3.51 ? 5% +2.8 6.34 ? 2% perf-profile.calltrace.cycles-pp.xfs_attr_get.xfs_xattr_get.vfs_getxattr.do_getxattr.getxattr
0.88 ? 3% +3.2 4.08 ? 4% perf-profile.calltrace.cycles-pp.xfs_log_reserve.xfs_trans_reserve.xfs_trans_alloc.xfs_trans_alloc_inode.xfs_attr_set
1.00 ? 21% +3.2 4.21 ? 4% perf-profile.calltrace.cycles-pp.xfs_trans_reserve.xfs_trans_alloc.xfs_trans_alloc_inode.xfs_attr_set.xfs_xattr_set
5.62 ? 9% +3.8 9.44 ? 3% perf-profile.calltrace.cycles-pp.xfs_attr_node_remove_attr.xfs_attr_set_iter.xfs_xattri_finish_update.xfs_attr_finish_item.xfs_defer_finish_one
8.34 ? 3% +4.5 12.81 ? 3% perf-profile.calltrace.cycles-pp.xfs_attr_set_iter.xfs_xattri_finish_update.xfs_attr_finish_item.xfs_defer_finish_one.xfs_defer_finish_noroll
1.89 ? 26% +5.1 7.02 ? 2% perf-profile.calltrace.cycles-pp.xfs_buf_read_map.xfs_trans_read_buf_map.xfs_da_read_buf.xfs_da3_node_lookup_int.xfs_attr_node_lookup
11.10 ? 3% +5.7 16.79 ? 3% perf-profile.calltrace.cycles-pp.xfs_xattri_finish_update.xfs_attr_finish_item.xfs_defer_finish_one.xfs_defer_finish_noroll.__xfs_trans_commit
11.25 ? 3% +5.8 17.04 ? 3% perf-profile.calltrace.cycles-pp.xfs_attr_finish_item.xfs_defer_finish_one.xfs_defer_finish_noroll.__xfs_trans_commit.xfs_attr_set
11.57 ? 3% +6.0 17.61 ? 3% perf-profile.calltrace.cycles-pp.xfs_defer_finish_one.xfs_defer_finish_noroll.__xfs_trans_commit.xfs_attr_set.xfs_xattr_set
2.01 ? 43% +7.5 9.47 ? 3% perf-profile.calltrace.cycles-pp.xfs_buf_get_map.xfs_buf_read_map.xfs_trans_read_buf_map.xfs_da_read_buf.xfs_da3_node_lookup_int
1.77 ? 27% +8.5 10.30 ? 10% perf-profile.calltrace.cycles-pp.xfs_buf_find.xfs_buf_get_map.xfs_buf_read_map.xfs_trans_read_buf_map.xfs_da_read_buf
35.87 ? 5% -26.2 9.64 ? 5% perf-profile.children.cycles-pp.xlog_cil_insert_items
25.90 ? 8% -24.9 0.96 ? 11% perf-profile.children.cycles-pp.native_queued_spin_lock_slowpath
29.53 ? 7% -24.0 5.50 ? 4% perf-profile.children.cycles-pp._raw_spin_lock
53.08 ? 3% -22.5 30.54 ? 3% perf-profile.children.cycles-pp.xlog_cil_commit
69.58 ? 2% -14.9 54.71 ? 3% perf-profile.children.cycles-pp.__xfs_trans_commit
34.70 ? 2% -12.4 22.28 ? 3% perf-profile.children.cycles-pp.xfs_defer_trans_roll
33.96 ? 3% -12.4 21.56 ? 3% perf-profile.children.cycles-pp.xfs_trans_roll
86.49 ? 2% -9.2 77.26 ? 2% perf-profile.children.cycles-pp.setxattr
79.02 ? 2% -8.8 70.21 ? 2% perf-profile.children.cycles-pp.xfs_attr_set
79.14 ? 2% -8.7 70.41 ? 2% perf-profile.children.cycles-pp.xfs_xattr_set
65.28 ? 2% -7.7 57.55 ? 2% perf-profile.children.cycles-pp.__vfs_setxattr
65.35 ? 2% -7.7 57.66 ? 2% perf-profile.children.cycles-pp.__vfs_setxattr_noperm
65.66 ? 2% -7.5 58.18 ? 2% perf-profile.children.cycles-pp.vfs_setxattr
46.44 ? 2% -6.3 40.14 ? 3% perf-profile.children.cycles-pp.xfs_defer_finish_noroll
39.97 ? 2% -4.5 35.44 ? 2% perf-profile.children.cycles-pp.path_setxattr
19.95 ? 2% -2.3 17.66 ? 2% perf-profile.children.cycles-pp.__x64_sys_lsetxattr
20.04 ? 2% -2.2 17.81 ? 2% perf-profile.children.cycles-pp.__x64_sys_setxattr
20.09 ? 2% -2.2 17.89 ? 2% perf-profile.children.cycles-pp.lsetxattr
27.27 ? 2% -2.0 25.27 ? 2% perf-profile.children.cycles-pp.__x64_sys_fsetxattr
27.53 ? 2% -1.8 25.68 ? 2% perf-profile.children.cycles-pp.fsetxattr
1.90 ? 3% -1.2 0.70 ? 5% perf-profile.children.cycles-pp._xfs_trans_bjoin
1.19 ? 3% -1.1 0.14 ? 9% perf-profile.children.cycles-pp.__list_del_entry_valid
18.90 -1.0 17.90 ? 3% perf-profile.children.cycles-pp.removexattr
13.92 -1.0 12.96 ? 3% perf-profile.children.cycles-pp.__vfs_removexattr
13.97 -0.9 13.04 ? 3% perf-profile.children.cycles-pp.__vfs_removexattr_locked
14.01 -0.9 13.09 ? 3% perf-profile.children.cycles-pp.vfs_removexattr
0.68 ? 2% -0.6 0.13 ? 7% perf-profile.children.cycles-pp.xfs_buf_item_init
0.59 ? 6% -0.4 0.14 perf-profile.children.cycles-pp.__list_add_valid
1.43 ? 4% -0.4 1.02 ? 3% perf-profile.children.cycles-pp.xfs_buf_item_release
0.63 ? 3% -0.4 0.27 ? 2% perf-profile.children.cycles-pp.xfs_buf_item_put
0.56 ? 4% -0.4 0.21 perf-profile.children.cycles-pp.xfs_trans_ijoin
4.76 -0.3 4.42 ? 2% perf-profile.children.cycles-pp.__x64_sys_fremovexattr
4.80 -0.3 4.50 ? 2% perf-profile.children.cycles-pp.fremovexattr
1.01 ? 4% -0.3 0.74 ? 6% perf-profile.children.cycles-pp.xfs_trans_log_inode
0.69 ? 6% -0.2 0.54 ? 4% perf-profile.children.cycles-pp.xfs_trans_dirty_buf
0.58 ? 7% -0.1 0.47 ? 6% perf-profile.children.cycles-pp.xfs_defer_save_resources
0.83 ? 6% -0.1 0.73 ? 4% perf-profile.children.cycles-pp.xfs_trans_log_buf
0.20 ? 7% -0.1 0.12 ? 10% perf-profile.children.cycles-pp.xfs_cil_prepare_item
0.64 ? 3% -0.1 0.56 ? 5% perf-profile.children.cycles-pp.xfs_trans_del_item
0.17 ? 8% -0.0 0.12 ? 19% perf-profile.children.cycles-pp.xlog_cil_process_intents
0.08 ? 6% -0.0 0.05 ? 47% perf-profile.children.cycles-pp.xfs_inode_item_release
0.05 ? 7% +0.0 0.08 ? 6% perf-profile.children.cycles-pp.memset
0.05 +0.0 0.08 ? 11% perf-profile.children.cycles-pp.map_id_up
0.16 ? 8% +0.0 0.19 ? 8% perf-profile.children.cycles-pp.xfs_attr3_leaf_setflag
0.07 ? 12% +0.0 0.10 ? 11% perf-profile.children.cycles-pp.xattr_resolve_name
0.07 ? 11% +0.0 0.10 ? 10% perf-profile.children.cycles-pp.xfs_buf_reverify
0.05 ? 7% +0.0 0.09 ? 14% perf-profile.children.cycles-pp.mnt_want_write
0.08 ? 17% +0.0 0.12 ? 14% perf-profile.children.cycles-pp.xfs_bmbt_disk_set_all
0.06 ? 13% +0.0 0.10 ? 5% perf-profile.children.cycles-pp.xfs_trans_free_extent
0.06 ? 13% +0.0 0.10 ? 5% perf-profile.children.cycles-pp.__xfs_free_extent
0.06 ? 13% +0.0 0.10 ? 14% perf-profile.children.cycles-pp.xfs_attr_leaf_entsize
0.06 ? 13% +0.0 0.10 ? 9% perf-profile.children.cycles-pp.chacha_permute
0.06 ? 13% +0.0 0.10 ? 4% perf-profile.children.cycles-pp.xfs_extent_free_finish_item
0.04 ? 45% +0.0 0.08 ? 8% perf-profile.children.cycles-pp.xfs_defer_create_intents
0.07 ? 8% +0.0 0.11 ? 9% perf-profile.children.cycles-pp.xfs_trans_ichgtime
0.07 ? 15% +0.0 0.11 ? 4% perf-profile.children.cycles-pp.xfs_bmapi_allocate
0.03 ? 70% +0.0 0.07 ? 14% perf-profile.children.cycles-pp.__fdget
0.12 ? 11% +0.0 0.16 ? 7% perf-profile.children.cycles-pp.xfs_attr_match
0.06 ? 17% +0.0 0.10 ? 7% perf-profile.children.cycles-pp.lockref_put_return
0.06 ? 14% +0.0 0.10 ? 7% perf-profile.children.cycles-pp.xfs_bmap_btalloc
0.04 ? 71% +0.0 0.08 ? 10% perf-profile.children.cycles-pp.xfs_attr_get_ilocked
0.06 ? 13% +0.0 0.10 ? 9% perf-profile.children.cycles-pp.xfs_alloc_vextent
0.10 ? 18% +0.0 0.15 ? 8% perf-profile.children.cycles-pp.xfs_verify_fsbext
0.09 ? 11% +0.0 0.14 ? 5% perf-profile.children.cycles-pp.xfs_contig_bits
0.07 ? 10% +0.0 0.11 ? 6% perf-profile.children.cycles-pp.listxattr
0.07 ? 10% +0.0 0.11 ? 6% perf-profile.children.cycles-pp.chacha_block_generic
0.07 ? 15% +0.0 0.11 ? 6% perf-profile.children.cycles-pp.xfs_bmapi_write
0.06 ? 7% +0.0 0.11 ? 9% perf-profile.children.cycles-pp.lockref_get_not_dead
0.07 ? 15% +0.0 0.12 ? 6% perf-profile.children.cycles-pp.xfs_da_grow_inode_int
0.08 ? 16% +0.0 0.13 ? 9% perf-profile.children.cycles-pp.xfs_attr3_leaf_moveents
0.08 ? 11% +0.0 0.13 ? 8% perf-profile.children.cycles-pp.__legitimize_mnt
0.07 ? 15% +0.0 0.12 ? 4% perf-profile.children.cycles-pp.xfs_da_grow_inode
0.10 ? 14% +0.0 0.14 ? 6% perf-profile.children.cycles-pp.xfs_buf_offset
0.02 ?141% +0.0 0.06 ? 7% perf-profile.children.cycles-pp.xfs_alloc_ag_vextent_near
0.09 ? 11% +0.1 0.14 ? 7% perf-profile.children.cycles-pp.xfs_trans_unreserve_and_mod_sb
0.07 ? 14% +0.1 0.12 ? 8% perf-profile.children.cycles-pp.security_inode_permission
0.08 ? 20% +0.1 0.13 ? 6% perf-profile.children.cycles-pp.xfs_attr3_leaf_hdr_to_disk
0.08 ? 5% +0.1 0.13 ? 3% perf-profile.children.cycles-pp.step_into
0.04 ? 45% +0.1 0.09 ? 13% perf-profile.children.cycles-pp.rht_key_get_hash
0.01 ?223% +0.1 0.06 ? 15% perf-profile.children.cycles-pp.should_failslab
0.00 +0.1 0.05 perf-profile.children.cycles-pp.xfs_attr3_leaf_list_int
0.08 ? 4% +0.1 0.13 ? 6% perf-profile.children.cycles-pp.xfs_ilock_attr_map_shared
0.09 ? 7% +0.1 0.14 ? 7% perf-profile.children.cycles-pp.xfs_log_ticket_put
0.08 ? 4% +0.1 0.13 ? 8% perf-profile.children.cycles-pp.xfs_mod_freecounter
0.09 ? 7% +0.1 0.14 ? 5% perf-profile.children.cycles-pp.strncmp
0.12 ? 6% +0.1 0.17 ? 7% perf-profile.children.cycles-pp.xfs_next_bit
0.08 ? 17% +0.1 0.13 ? 7% perf-profile.children.cycles-pp.memcmp
0.02 ? 99% +0.1 0.08 ? 12% perf-profile.children.cycles-pp.crng_make_state
0.02 ? 99% +0.1 0.08 ? 6% perf-profile.children.cycles-pp.check_stack_object
0.01 ?223% +0.1 0.06 ? 9% perf-profile.children.cycles-pp.xfs_da_hashname
0.01 ?223% +0.1 0.06 ? 16% perf-profile.children.cycles-pp.strlen
0.00 +0.1 0.05 ? 7% perf-profile.children.cycles-pp.mnt_drop_write
0.00 +0.1 0.05 ? 7% perf-profile.children.cycles-pp.memcpy
0.00 +0.1 0.05 ? 7% perf-profile.children.cycles-pp.xfs_btree_lookup
0.01 ?223% +0.1 0.06 ? 16% perf-profile.children.cycles-pp.xfs_attr3_leaf_unbalance
0.08 ? 11% +0.1 0.14 ? 4% perf-profile.children.cycles-pp._get_random_bytes
0.02 ?142% +0.1 0.07 ? 9% perf-profile.children.cycles-pp.xfs_alloc_ag_vextent
0.01 ?223% +0.1 0.06 ? 14% perf-profile.children.cycles-pp.xfs_attr_copy_value
0.00 +0.1 0.05 ? 8% perf-profile.children.cycles-pp.xfs_extent_busy_clear
0.09 ? 10% +0.1 0.14 ? 5% perf-profile.children.cycles-pp.xfs_attr3_leaf_getvalue
0.09 ? 4% +0.1 0.14 ? 7% perf-profile.children.cycles-pp.up_write
0.02 ? 99% +0.1 0.08 ? 12% perf-profile.children.cycles-pp.xlog_grant_head_check
0.00 +0.1 0.06 ? 9% perf-profile.children.cycles-pp.exit_to_user_mode_prepare
0.00 +0.1 0.06 ? 13% perf-profile.children.cycles-pp.list_sort
0.12 ? 10% +0.1 0.17 ? 9% perf-profile.children.cycles-pp.path_init
0.11 ? 12% +0.1 0.17 ? 22% perf-profile.children.cycles-pp.ret_from_fork
0.11 ? 12% +0.1 0.17 ? 22% perf-profile.children.cycles-pp.kthread
0.02 ?141% +0.1 0.07 ? 12% perf-profile.children.cycles-pp.syscall_enter_from_user_mode
0.29 ? 8% +0.1 0.35 ? 7% perf-profile.children.cycles-pp.xfs_trans_buf_item_match
0.08 ? 6% +0.1 0.13 ? 10% perf-profile.children.cycles-pp._copy_to_user
0.00 +0.1 0.06 ? 8% perf-profile.children.cycles-pp.xfs_free_ag_extent
0.11 ? 6% +0.1 0.17 ? 7% perf-profile.children.cycles-pp.xfs_ilock
0.00 +0.1 0.06 ? 6% perf-profile.children.cycles-pp.syscall_exit_to_user_mode_prepare
0.10 ? 9% +0.1 0.16 ? 8% perf-profile.children.cycles-pp.xfs_inode_item_size
0.00 +0.1 0.06 ? 15% perf-profile.children.cycles-pp.mnt_drop_write_file
0.01 ?223% +0.1 0.07 ? 5% perf-profile.children.cycles-pp.current_time
0.27 ? 5% +0.1 0.34 ? 5% perf-profile.children.cycles-pp.xfs_da3_node_set_type
0.09 ? 6% +0.1 0.15 ? 7% perf-profile.children.cycles-pp.xfs_iunlock
0.10 ? 14% +0.1 0.16 ? 7% perf-profile.children.cycles-pp.__virt_addr_valid
0.10 ? 9% +0.1 0.16 ? 8% perf-profile.children.cycles-pp.__check_heap_object
0.01 ?223% +0.1 0.07 ? 8% perf-profile.children.cycles-pp.crng_fast_key_erasure
0.10 ? 4% +0.1 0.16 ? 3% perf-profile.children.cycles-pp.xfs_da3_node_hdr_from_disk
0.11 ? 6% +0.1 0.18 ? 17% perf-profile.children.cycles-pp.xfs_attr_is_leaf
0.00 +0.1 0.07 ? 5% perf-profile.children.cycles-pp.xfs_vn_listxattr
0.00 +0.1 0.07 ? 5% perf-profile.children.cycles-pp.xfs_attr_list
0.00 +0.1 0.07 ? 5% perf-profile.children.cycles-pp.xfs_attr_node_list
0.10 ? 13% +0.1 0.17 ? 6% perf-profile.children.cycles-pp.syscall_return_via_sysret
0.12 ? 8% +0.1 0.18 ? 6% perf-profile.children.cycles-pp._copy_from_user
0.12 ? 4% +0.1 0.19 ? 4% perf-profile.children.cycles-pp._IO_default_xsputn
0.12 ? 8% +0.1 0.18 ? 5% perf-profile.children.cycles-pp.get_random_u32
0.13 ? 8% +0.1 0.20 ? 3% perf-profile.children.cycles-pp.xfs_defer_restore_resources
0.12 ? 11% +0.1 0.20 ? 3% perf-profile.children.cycles-pp.xfs_isilocked
0.20 ? 13% +0.1 0.27 ? 8% perf-profile.children.cycles-pp.xfs_bmap_validate_extent
0.14 ? 4% +0.1 0.22 ? 6% perf-profile.children.cycles-pp._raw_spin_unlock_irqrestore
0.22 ? 10% +0.1 0.29 ? 6% perf-profile.children.cycles-pp.xfs_trans_add_item
0.11 ? 13% +0.1 0.19 ? 5% perf-profile.children.cycles-pp.xfs_trans_free
0.08 ? 10% +0.1 0.15 ? 6% perf-profile.children.cycles-pp.xlog_verify_grant_tail
0.14 ? 11% +0.1 0.21 ? 9% perf-profile.children.cycles-pp.xfs_iext_get_extent
0.14 ? 10% +0.1 0.22 ? 5% perf-profile.children.cycles-pp.__radix_tree_lookup
0.12 ? 7% +0.1 0.20 ? 4% perf-profile.children.cycles-pp.memcg_slab_post_alloc_hook
0.16 ? 13% +0.1 0.24 ? 5% perf-profile.children.cycles-pp.kfree
0.13 ? 10% +0.1 0.21 ? 6% perf-profile.children.cycles-pp.rcu_all_qs
0.17 ? 7% +0.1 0.25 ? 5% perf-profile.children.cycles-pp.stress_xattr
0.14 ? 8% +0.1 0.22 ? 9% perf-profile.children.cycles-pp.down_write
0.13 ? 8% +0.1 0.22 ? 5% perf-profile.children.cycles-pp.rhashtable_jhash2
0.02 ?144% +0.1 0.10 ? 37% perf-profile.children.cycles-pp.xfs_attr_create_intent
0.15 ? 7% +0.1 0.24 ? 11% perf-profile.children.cycles-pp.xattr_permission
0.15 ? 17% +0.1 0.24 ? 7% perf-profile.children.cycles-pp.xfs_da3_split
0.13 ? 6% +0.1 0.22 ? 4% perf-profile.children.cycles-pp.copy_user_enhanced_fast_string
0.17 ? 8% +0.1 0.26 ? 7% perf-profile.children.cycles-pp.__legitimize_path
0.18 ? 6% +0.1 0.27 ? 5% perf-profile.children.cycles-pp.__might_fault
0.16 ? 10% +0.1 0.26 ? 8% perf-profile.children.cycles-pp.dput
0.14 ? 17% +0.1 0.24 ? 5% perf-profile.children.cycles-pp.xfs_attr3_leaf_split
0.16 ? 9% +0.1 0.26 ? 6% perf-profile.children.cycles-pp.path_put
0.18 ? 7% +0.1 0.28 ? 4% perf-profile.children.cycles-pp.entry_SYSRETQ_unsafe_stack
0.19 ? 10% +0.1 0.30 ? 4% perf-profile.children.cycles-pp.check_heap_object
0.20 ? 12% +0.1 0.30 ? 4% perf-profile.children.cycles-pp.xfs_buf_set_ref
0.18 ? 12% +0.1 0.29 ? 7% perf-profile.children.cycles-pp.__d_lookup_rcu
0.17 ? 8% +0.1 0.29 ? 6% perf-profile.children.cycles-pp.xfs_bmapi_update_map
0.21 ? 9% +0.1 0.34 ? 5% perf-profile.children.cycles-pp.xfs_da3_fixhashpath
0.18 ? 9% +0.1 0.31 ? 10% perf-profile.children.cycles-pp.__vfs_setxattr_locked
0.18 ? 10% +0.1 0.31 ? 5% perf-profile.children.cycles-pp.xfs_bmapi_trim_map
0.22 ? 12% +0.1 0.34 ? 5% perf-profile.children.cycles-pp.generic_permission
0.19 ? 11% +0.1 0.31 ? 6% perf-profile.children.cycles-pp.xfs_iread_extents
0.20 ? 7% +0.1 0.33 ? 4% perf-profile.children.cycles-pp.xfs_defer_add
0.24 ? 9% +0.1 0.37 ? 9% perf-profile.children.cycles-pp.xfs_inode_to_log_dinode
0.21 ? 10% +0.1 0.34 ? 7% perf-profile.children.cycles-pp.try_to_unlazy
0.21 ? 8% +0.1 0.34 ? 5% perf-profile.children.cycles-pp.xlog_prepare_iovec
0.24 ? 11% +0.1 0.37 ? 4% perf-profile.children.cycles-pp.xfs_trans_brelse
0.24 ? 11% +0.1 0.36 ? 5% perf-profile.children.cycles-pp._atomic_dec_and_lock
0.23 ? 11% +0.1 0.36 ? 5% perf-profile.children.cycles-pp.syscall_exit_to_user_mode
0.22 ? 6% +0.1 0.35 ? 4% perf-profile.children.cycles-pp.xfs_buf_item_size_segment
0.27 ? 9% +0.1 0.41 ? 6% perf-profile.children.cycles-pp.xfs_da_state_free
0.22 ? 7% +0.1 0.36 ? 5% perf-profile.children.cycles-pp.__kmalloc_node
0.23 ? 10% +0.1 0.37 ? 7% perf-profile.children.cycles-pp.complete_walk
0.26 ? 4% +0.2 0.41 ? 2% perf-profile.children.cycles-pp.xfs_attr_defer_replace
0.28 ? 7% +0.2 0.43 ? 3% perf-profile.children.cycles-pp.__cond_resched
0.32 ? 7% +0.2 0.48 ? 6% perf-profile.children.cycles-pp.xfs_buf_item_log
0.26 ? 10% +0.2 0.42 ? 4% perf-profile.children.cycles-pp.lookup_fast
0.39 ? 13% +0.2 0.55 ? 3% perf-profile.children.cycles-pp.xlog_ticket_alloc
0.30 ? 5% +0.2 0.47 ? 3% perf-profile.children.cycles-pp.xfs_trans_dup
0.28 ? 8% +0.2 0.44 ? 5% perf-profile.children.cycles-pp.__might_sleep
0.29 ? 9% +0.2 0.47 ? 5% perf-profile.children.cycles-pp.xfs_errortag_test
0.28 ? 9% +0.2 0.46 ? 5% perf-profile.children.cycles-pp.memcg_slab_free_hook
0.36 ? 15% +0.2 0.55 ? 4% perf-profile.children.cycles-pp.inode_permission
0.70 ? 7% +0.2 0.89 ? 5% perf-profile.children.cycles-pp.xfs_attr3_leaf_add_work
0.32 ? 8% +0.2 0.51 ? 7% perf-profile.children.cycles-pp.memmove
0.32 ? 5% +0.2 0.52 ? 5% perf-profile.children.cycles-pp.vmemdup_user
0.29 ? 8% +0.2 0.50 ? 2% perf-profile.children.cycles-pp.__entry_text_start
1.00 ? 6% +0.2 1.22 ? 2% perf-profile.children.cycles-pp.xlog_cil_alloc_shadow_bufs
0.54 ? 13% +0.2 0.77 ? 9% perf-profile.children.cycles-pp.xfs_iextents_copy
0.38 ? 7% +0.2 0.61 ? 2% perf-profile.children.cycles-pp.xfs_buf_item_size
0.70 ? 11% +0.2 0.94 ? 8% perf-profile.children.cycles-pp.xfs_inode_item_format_attr_fork
0.45 ? 7% +0.2 0.70 ? 3% perf-profile.children.cycles-pp.xfs_iext_lookup_extent
0.43 ? 7% +0.2 0.68 ? 3% perf-profile.children.cycles-pp.up
0.44 ? 6% +0.3 0.70 ? 3% perf-profile.children.cycles-pp.walk_component
0.47 ? 5% +0.3 0.72 ? 4% perf-profile.children.cycles-pp.__check_object_size
0.37 ? 7% +0.3 0.64 ? 6% perf-profile.children.cycles-pp.xfs_attr_leaf_lasthash
0.45 ? 3% +0.3 0.72 ? 6% perf-profile.children.cycles-pp.__might_resched
0.94 ? 7% +0.3 1.23 ? 4% perf-profile.children.cycles-pp.xfs_attr3_leaf_add
0.47 ? 4% +0.3 0.76 ? 5% perf-profile.children.cycles-pp.setxattr_copy
0.52 ? 6% +0.3 0.82 ? 3% perf-profile.children.cycles-pp.xfs_buf_unlock
0.55 ? 4% +0.3 0.88 ? 4% perf-profile.children.cycles-pp.down_trylock
0.85 ? 6% +0.3 1.18 ? 6% perf-profile.children.cycles-pp.xfs_attr3_leaf_remove
0.59 ? 5% +0.4 0.94 ? 4% perf-profile.children.cycles-pp.xfs_buf_trylock
0.56 ? 4% +0.4 0.92 ? 4% perf-profile.children.cycles-pp.memset_erms
0.44 ? 7% +0.4 0.81 ? 5% perf-profile.children.cycles-pp.__rhashtable_lookup
0.55 ? 7% +0.4 0.95 ? 4% perf-profile.children.cycles-pp.xfs_da_state_alloc
0.79 ? 7% +0.4 1.22 ? 3% perf-profile.children.cycles-pp.xfs_buf_rele
0.61 ? 7% +0.4 1.04 ? 4% perf-profile.children.cycles-pp.xfs_attr3_leaf_hdr_from_disk
0.13 ? 11% +0.5 0.58 ? 7% perf-profile.children.cycles-pp.xfs_log_space_wake
1.13 ? 8% +0.5 1.58 ? 5% perf-profile.children.cycles-pp.xfs_inode_item_format
0.89 ? 3% +0.5 1.37 ? 3% perf-profile.children.cycles-pp._raw_spin_lock_irqsave
0.91 ? 10% +0.5 1.39 ? 4% perf-profile.children.cycles-pp.link_path_walk
0.86 ? 5% +0.5 1.36 ? 3% perf-profile.children.cycles-pp.getname_flags
1.14 ? 6% +0.5 1.65 ? 4% perf-profile.children.cycles-pp.memcpy_erms
0.88 ? 8% +0.5 1.41 ? 5% perf-profile.children.cycles-pp.kmem_cache_free
0.95 ? 5% +0.5 1.50 ? 2% perf-profile.children.cycles-pp.strncpy_from_user
0.49 ? 4% +0.6 1.04 ? 3% perf-profile.children.cycles-pp.xfs_log_regrant
0.80 ? 5% +0.6 1.41 ? 4% perf-profile.children.cycles-pp.xfs_attr3_leaf_lookup_int
1.78 ? 5% +0.6 2.43 ? 5% perf-profile.children.cycles-pp.xfs_attr3_leaf_flipflags
1.33 ? 6% +0.7 2.00 ? 4% perf-profile.children.cycles-pp.xfs_attr_node_addname_find_attr
1.56 ? 7% +0.7 2.24 ? 4% perf-profile.children.cycles-pp.xfs_buf_item_format_segment
1.69 ? 6% +0.7 2.40 ? 4% perf-profile.children.cycles-pp.xfs_buf_item_format
1.78 ? 3% +0.7 2.51 ? 13% perf-profile.children.cycles-pp.up_read
1.55 ? 8% +0.9 2.41 ? 3% perf-profile.children.cycles-pp.path_lookupat
1.13 ? 5% +0.9 1.99 ? 3% perf-profile.children.cycles-pp.__x64_sys_fgetxattr
1.07 ? 5% +0.9 1.93 ? 2% perf-profile.children.cycles-pp.xfs_attr3_leaf_toosmall
1.61 ? 8% +0.9 2.50 ? 4% perf-profile.children.cycles-pp.filename_lookup
1.14 ? 5% +0.9 2.06 ? 3% perf-profile.children.cycles-pp.xfs_da3_join
1.25 ? 5% +0.9 2.19 ? 2% perf-profile.children.cycles-pp.fgetxattr
1.61 ? 5% +1.0 2.63 ? 2% perf-profile.children.cycles-pp.kmem_cache_alloc
2.94 ? 3% +1.0 3.98 ? 7% perf-profile.children.cycles-pp.xfs_log_ticket_ungrant
3.24 ? 7% +1.1 4.33 ? 3% perf-profile.children.cycles-pp.xlog_cil_insert_format_items
0.83 ? 7% +1.1 1.93 ? 2% perf-profile.children.cycles-pp.xlog_space_left
0.85 ? 7% +1.1 1.96 ? 2% perf-profile.children.cycles-pp.xlog_grant_push_threshold
1.80 ? 6% +1.1 2.90 ? 3% perf-profile.children.cycles-pp.xfs_bmapi_read
0.87 ? 7% +1.1 1.98 ? 2% perf-profile.children.cycles-pp.xlog_grant_push_ail
2.72 ? 4% +1.1 3.85 ? 10% perf-profile.children.cycles-pp.down_read
2.66 ? 7% +1.2 3.86 ? 4% perf-profile.children.cycles-pp.xfs_attr_node_addname
2.38 ? 5% +1.3 3.69 ? 4% perf-profile.children.cycles-pp.xfs_attr3_leaf_read
1.98 ? 4% +1.3 3.31 ? 3% perf-profile.children.cycles-pp.lgetxattr
0.82 ? 11% +1.3 2.17 ? 4% perf-profile.children.cycles-pp.xfs_perag_put
2.26 ? 6% +1.4 3.66 ? 3% perf-profile.children.cycles-pp.xfs_dabuf_map
2.62 ? 7% +1.5 4.12 ? 3% perf-profile.children.cycles-pp.user_path_at_empty
1.27 ? 6% +2.0 3.30 ? 5% perf-profile.children.cycles-pp.xlog_grant_add_space
3.31 ? 6% +2.7 6.02 ? 2% perf-profile.children.cycles-pp.xfs_attr_node_get
3.28 ? 4% +2.8 6.08 ? 3% perf-profile.children.cycles-pp.xfs_trans_alloc_inode
3.52 ? 5% +2.8 6.36 ? 2% perf-profile.children.cycles-pp.xfs_attr_get
3.60 ? 5% +2.9 6.48 ? 2% perf-profile.children.cycles-pp.xfs_xattr_get
2.24 ? 4% +2.9 5.15 ? 3% perf-profile.children.cycles-pp.xfs_log_reserve
3.80 ? 5% +3.0 6.79 ? 2% perf-profile.children.cycles-pp.vfs_getxattr
2.58 ? 4% +3.1 5.71 ? 3% perf-profile.children.cycles-pp.xfs_trans_alloc
4.11 ? 5% +3.2 7.30 ? 2% perf-profile.children.cycles-pp.do_getxattr
3.42 ? 10% +3.2 6.62 ? 6% perf-profile.children.cycles-pp.xfs_perag_get
5.95 ? 3% +3.5 9.46 ? 3% perf-profile.children.cycles-pp.xfs_attr_node_remove_attr
2.85 ? 3% +3.5 6.38 ? 3% perf-profile.children.cycles-pp.xfs_trans_reserve
5.24 ? 5% +3.6 8.84 ? 2% perf-profile.children.cycles-pp.path_getxattr
8.37 ? 3% +4.5 12.82 ? 3% perf-profile.children.cycles-pp.xfs_attr_set_iter
11.10 ? 3% +5.7 16.80 ? 3% perf-profile.children.cycles-pp.xfs_xattri_finish_update
11.26 ? 3% +5.8 17.06 ? 3% perf-profile.children.cycles-pp.xfs_attr_finish_item
8.53 ? 4% +5.9 14.38 ? 2% perf-profile.children.cycles-pp.xfs_attr_node_lookup
11.60 ? 3% +6.1 17.66 ? 3% perf-profile.children.cycles-pp.xfs_defer_finish_one
8.36 ? 5% +6.1 14.42 ? 2% perf-profile.children.cycles-pp.getxattr
9.65 ? 5% +6.2 15.90 ? 3% perf-profile.children.cycles-pp.xfs_trans_read_buf_map
6.76 ? 8% +6.9 13.70 ? 3% perf-profile.children.cycles-pp.xfs_buf_find
6.93 ? 8% +7.0 13.97 ? 3% perf-profile.children.cycles-pp.xfs_buf_get_map
7.14 ? 7% +7.2 14.32 ? 3% perf-profile.children.cycles-pp.xfs_buf_read_map
12.06 ? 4% +7.9 19.95 ? 2% perf-profile.children.cycles-pp.xfs_da3_node_lookup_int
12.38 ? 4% +7.9 20.31 ? 3% perf-profile.children.cycles-pp.xfs_da_read_buf
25.84 ? 8% -24.9 0.94 ? 11% perf-profile.self.cycles-pp.native_queued_spin_lock_slowpath
1.16 ? 3% -1.1 0.11 ? 8% perf-profile.self.cycles-pp.__list_del_entry_valid
1.08 ? 5% -0.7 0.39 ? 5% perf-profile.self.cycles-pp._xfs_trans_bjoin
0.67 ? 2% -0.6 0.11 ? 7% perf-profile.self.cycles-pp.xfs_buf_item_init
3.32 ? 2% -0.5 2.77 ? 8% perf-profile.self.cycles-pp.xlog_cil_insert_items
0.56 ? 6% -0.5 0.09 ? 5% perf-profile.self.cycles-pp.__list_add_valid
0.62 ? 3% -0.4 0.25 ? 2% perf-profile.self.cycles-pp.xfs_buf_item_put
0.74 ? 4% -0.3 0.43 ? 5% perf-profile.self.cycles-pp.xfs_trans_log_inode
0.44 ? 5% -0.2 0.20 ? 4% perf-profile.self.cycles-pp.xfs_buf_item_release
0.67 ? 5% -0.2 0.51 ? 3% perf-profile.self.cycles-pp.xfs_trans_dirty_buf
0.19 ? 4% -0.1 0.06 ? 11% perf-profile.self.cycles-pp.xfs_trans_ijoin
0.58 ? 3% -0.1 0.47 ? 5% perf-profile.self.cycles-pp.xfs_trans_del_item
0.48 ? 8% -0.1 0.39 ? 5% perf-profile.self.cycles-pp.xlog_cil_alloc_shadow_bufs
0.19 ? 7% -0.1 0.10 ? 9% perf-profile.self.cycles-pp.xfs_cil_prepare_item
0.14 ? 5% -0.1 0.07 ? 14% perf-profile.self.cycles-pp.xfs_defer_save_resources
0.16 ? 9% -0.1 0.11 ? 18% perf-profile.self.cycles-pp.xlog_cil_process_intents
0.15 ? 4% -0.0 0.12 ? 7% perf-profile.self.cycles-pp.xfs_trans_buf_set_type
0.06 ? 13% +0.0 0.08 ? 5% perf-profile.self.cycles-pp.xfs_trans_unreserve_and_mod_sb
0.06 ? 6% +0.0 0.09 ? 14% perf-profile.self.cycles-pp.xfs_attr_is_leaf
0.04 ? 44% +0.0 0.07 ? 11% perf-profile.self.cycles-pp.xfs_trans_alloc_inode
0.07 ? 14% +0.0 0.10 ? 14% perf-profile.self.cycles-pp.xfs_xattr_get
0.07 ? 17% +0.0 0.10 ? 7% perf-profile.self.cycles-pp.xfs_attr_set_iter
0.06 ? 7% +0.0 0.09 ? 10% perf-profile.self.cycles-pp.xfs_trans_alloc
0.09 ? 7% +0.0 0.12 ? 7% perf-profile.self.cycles-pp.xfs_next_bit
0.06 ? 14% +0.0 0.10 ? 7% perf-profile.self.cycles-pp.down_trylock
0.04 ? 71% +0.0 0.07 ? 8% perf-profile.self.cycles-pp.up
0.06 ? 7% +0.0 0.10 ? 6% perf-profile.self.cycles-pp.security_inode_permission
0.06 ? 14% +0.0 0.10 ? 8% perf-profile.self.cycles-pp.xfs_da3_fixhashpath
0.06 ? 14% +0.0 0.10 ? 6% perf-profile.self.cycles-pp.lockref_put_return
0.05 ? 13% +0.0 0.09 ? 7% perf-profile.self.cycles-pp.xfs_trans_free
0.04 ? 45% +0.0 0.08 ? 12% perf-profile.self.cycles-pp.__vfs_setxattr_noperm
0.07 ? 18% +0.0 0.10 ? 10% perf-profile.self.cycles-pp.xattr_resolve_name
0.06 ? 13% +0.0 0.10 ? 5% perf-profile.self.cycles-pp.xfs_attr3_leaf_flipflags
0.06 ? 11% +0.0 0.10 ? 10% perf-profile.self.cycles-pp.lockref_get_not_dead
0.06 ? 7% +0.0 0.10 ? 6% perf-profile.self.cycles-pp.rcu_all_qs
0.06 ? 17% +0.0 0.10 ? 10% perf-profile.self.cycles-pp.down_write
0.05 ? 44% +0.0 0.09 ? 10% perf-profile.self.cycles-pp.xfs_buf_reverify
0.10 ? 18% +0.0 0.14 ? 9% perf-profile.self.cycles-pp.xfs_verify_fsbext
0.08 ? 11% +0.0 0.12 ? 8% perf-profile.self.cycles-pp.__legitimize_mnt
0.07 ? 10% +0.0 0.11 ? 4% perf-profile.self.cycles-pp.xfs_defer_finish_noroll
0.06 ? 11% +0.0 0.10 ? 8% perf-profile.self.cycles-pp.xfs_buf_offset
0.06 ? 19% +0.0 0.10 ? 10% perf-profile.self.cycles-pp.filename_lookup
0.04 ? 71% +0.0 0.07 ? 10% perf-profile.self.cycles-pp.xfs_attr3_leaf_add
0.07 ? 10% +0.0 0.11 ? 14% perf-profile.self.cycles-pp.path_lookupat
0.06 ? 11% +0.0 0.10 ? 9% perf-profile.self.cycles-pp.chacha_permute
0.08 ? 6% +0.0 0.12 ? 6% perf-profile.self.cycles-pp.strncmp
0.08 ? 8% +0.0 0.12 ? 5% perf-profile.self.cycles-pp.xfs_contig_bits
0.07 ? 6% +0.0 0.11 ? 8% perf-profile.self.cycles-pp.up_write
0.02 ? 99% +0.0 0.06 ? 7% perf-profile.self.cycles-pp.xfs_attr_node_lookup
0.06 ? 6% +0.0 0.10 ? 10% perf-profile.self.cycles-pp.xfs_log_reserve
0.04 ? 45% +0.0 0.08 ? 11% perf-profile.self.cycles-pp.vfs_setxattr
0.03 ? 70% +0.0 0.07 ? 10% perf-profile.self.cycles-pp.map_id_up
0.04 ? 71% +0.0 0.08 ? 6% perf-profile.self.cycles-pp.xfs_xattri_finish_update
0.13 ? 8% +0.0 0.18 ? 2% perf-profile.self.cycles-pp.xfs_buf_item_format
0.07 ? 15% +0.0 0.12 ? 4% perf-profile.self.cycles-pp.check_heap_object
0.08 ? 8% +0.0 0.12 ? 8% perf-profile.self.cycles-pp.xfs_trans_reserve
0.17 ? 10% +0.0 0.22 ? 6% perf-profile.self.cycles-pp.xfs_trans_add_item
0.02 ? 99% +0.0 0.07 ? 8% perf-profile.self.cycles-pp.xfs_attr3_leaf_getvalue
0.11 ? 18% +0.0 0.15 ? 8% perf-profile.self.cycles-pp.walk_component
0.07 ? 20% +0.0 0.12 ? 9% perf-profile.self.cycles-pp.memcmp
0.08 ? 6% +0.0 0.12 ? 5% perf-profile.self.cycles-pp.step_into
0.06 ? 13% +0.0 0.10 ? 7% perf-profile.self.cycles-pp.xfs_attr3_leaf_toosmall
0.02 ?142% +0.0 0.06 ? 7% perf-profile.self.cycles-pp.xfs_attr_node_addname
0.11 ? 12% +0.0 0.16 ? 4% perf-profile.self.cycles-pp.__xfs_trans_commit
0.07 ? 26% +0.0 0.12 ? 5% perf-profile.self.cycles-pp.xfs_buf_set_ref
0.07 ? 16% +0.0 0.12 ? 5% perf-profile.self.cycles-pp.lookup_fast
0.08 ? 14% +0.0 0.12 ? 6% perf-profile.self.cycles-pp.xfs_isilocked
0.03 ? 70% +0.0 0.08 ? 8% perf-profile.self.cycles-pp.lgetxattr
0.04 ? 72% +0.0 0.09 ? 9% perf-profile.self.cycles-pp.xfs_attr3_leaf_hdr_to_disk
0.01 ?223% +0.0 0.06 ? 11% perf-profile.self.cycles-pp.xfs_defer_trans_roll
0.01 ?223% +0.0 0.06 ? 6% perf-profile.self.cycles-pp.xfs_attr_node_remove_attr
0.09 ? 7% +0.1 0.14 ? 9% perf-profile.self.cycles-pp.xfs_log_ticket_put
0.11 ? 8% +0.1 0.16 ? 5% perf-profile.self.cycles-pp.xfs_inode_item_format
0.01 ?223% +0.1 0.06 ? 9% perf-profile.self.cycles-pp.xfs_buf_trylock
0.10 ? 11% +0.1 0.15 ? 10% perf-profile.self.cycles-pp.getname_flags
0.02 ?141% +0.1 0.07 ? 5% perf-profile.self.cycles-pp.__vfs_setxattr_locked
0.11 ? 12% +0.1 0.16 ? 8% perf-profile.self.cycles-pp.xfs_iextents_copy
0.10 ? 15% +0.1 0.16 ? 7% perf-profile.self.cycles-pp.__kmalloc_node
0.08 ? 10% +0.1 0.13 ? 3% perf-profile.self.cycles-pp.setxattr
0.04 ? 72% +0.1 0.09 ? 11% perf-profile.self.cycles-pp.xfs_attr_leaf_entsize
0.01 ?223% +0.1 0.06 ? 14% perf-profile.self.cycles-pp.xfs_buf_unlock
0.00 +0.1 0.05 ? 8% perf-profile.self.cycles-pp.xfs_attr_get
0.12 ? 7% +0.1 0.18 ? 8% perf-profile.self.cycles-pp.__check_object_size
0.08 ? 10% +0.1 0.14 ? 12% perf-profile.self.cycles-pp.xfs_xattr_set
0.02 ?141% +0.1 0.07 ? 8% perf-profile.self.cycles-pp.xfs_trans_dup
0.00 +0.1 0.06 ? 13% perf-profile.self.cycles-pp.xfs_da_hashname
0.10 ? 11% +0.1 0.16 ? 8% perf-profile.self.cycles-pp.__virt_addr_valid
0.08 ? 10% +0.1 0.14 ? 16% perf-profile.self.cycles-pp.xattr_permission
0.01 ?223% +0.1 0.06 ? 17% perf-profile.self.cycles-pp.syscall_enter_from_user_mode
0.01 ?223% +0.1 0.06 ? 14% perf-profile.self.cycles-pp.__fdget
0.01 ?223% +0.1 0.06 ? 14% perf-profile.self.cycles-pp.check_stack_object
0.28 ? 7% +0.1 0.33 ? 8% perf-profile.self.cycles-pp.xfs_trans_buf_item_match
0.08 ? 8% +0.1 0.14 ? 7% perf-profile.self.cycles-pp.xfs_inode_item_size
0.12 ? 11% +0.1 0.18 ? 10% perf-profile.self.cycles-pp.xfs_inode_to_log_dinode
0.02 ?141% +0.1 0.07 ? 12% perf-profile.self.cycles-pp.xfs_da_state_alloc
0.01 ?223% +0.1 0.06 ? 7% perf-profile.self.cycles-pp.xfs_attr_finish_item
0.00 +0.1 0.06 ? 13% perf-profile.self.cycles-pp.path_setxattr
0.10 ? 10% +0.1 0.16 ? 8% perf-profile.self.cycles-pp.__check_heap_object
0.11 ? 8% +0.1 0.17 ? 10% perf-profile.self.cycles-pp.path_init
0.09 ? 5% +0.1 0.14 ? 3% perf-profile.self.cycles-pp.xfs_da3_node_hdr_from_disk
0.01 ?223% +0.1 0.07 ? 14% perf-profile.self.cycles-pp.__x64_sys_fsetxattr
0.12 ? 15% +0.1 0.18 ? 7% perf-profile.self.cycles-pp.kfree
0.00 +0.1 0.06 ? 16% perf-profile.self.cycles-pp.rht_key_get_hash
0.12 ? 4% +0.1 0.18 ? 5% perf-profile.self.cycles-pp._raw_spin_unlock_irqrestore
0.00 +0.1 0.06 ? 11% perf-profile.self.cycles-pp.xfs_mod_freecounter
0.13 ? 8% +0.1 0.19 ? 8% perf-profile.self.cycles-pp.xfs_attr_set
0.02 ?141% +0.1 0.08 ? 10% perf-profile.self.cycles-pp.fsetxattr
0.10 ? 13% +0.1 0.16 ? 4% perf-profile.self.cycles-pp.syscall_return_via_sysret
0.01 ?223% +0.1 0.07 ? 12% perf-profile.self.cycles-pp.path_getxattr
0.00 +0.1 0.07 ? 7% perf-profile.self.cycles-pp.xlog_grant_push_threshold
0.12 ? 11% +0.1 0.19 ? 10% perf-profile.self.cycles-pp.xfs_iext_get_extent
0.11 ? 11% +0.1 0.18 ? 5% perf-profile.self.cycles-pp.xfs_buf_item_size_segment
0.14 ? 4% +0.1 0.21 ? 5% perf-profile.self.cycles-pp.xfs_da3_node_set_type
0.13 ? 13% +0.1 0.20 ? 7% perf-profile.self.cycles-pp.__radix_tree_lookup
0.10 ? 8% +0.1 0.17 ? 4% perf-profile.self.cycles-pp.memcg_slab_post_alloc_hook
0.08 ? 10% +0.1 0.15 ? 6% perf-profile.self.cycles-pp.xlog_verify_grant_tail
0.12 ? 4% +0.1 0.19 ? 4% perf-profile.self.cycles-pp._IO_default_xsputn
0.12 ? 9% +0.1 0.20 ? 3% perf-profile.self.cycles-pp.rhashtable_jhash2
0.14 ? 9% +0.1 0.22 ? 5% perf-profile.self.cycles-pp.stress_xattr
0.12 ? 10% +0.1 0.20 ? 6% perf-profile.self.cycles-pp.getxattr
0.16 ? 7% +0.1 0.25 ? 3% perf-profile.self.cycles-pp.do_syscall_64
0.12 ? 11% +0.1 0.21 ? 6% perf-profile.self.cycles-pp.xfs_defer_finish_one
0.01 ?223% +0.1 0.10 ? 39% perf-profile.self.cycles-pp.xfs_attr_create_intent
0.13 ? 6% +0.1 0.22 ? 5% perf-profile.self.cycles-pp.copy_user_enhanced_fast_string
0.12 ? 11% +0.1 0.21 ? 4% perf-profile.self.cycles-pp.__entry_text_start
0.25 ? 9% +0.1 0.34 ? 6% perf-profile.self.cycles-pp.xfs_buf_item_format_segment
0.14 ? 11% +0.1 0.23 ? 7% perf-profile.self.cycles-pp.syscall_exit_to_user_mode
0.16 ? 13% +0.1 0.25 ? 6% perf-profile.self.cycles-pp.xfs_buf_get_map
0.12 ? 7% +0.1 0.22 ? 9% perf-profile.self.cycles-pp.xfs_attr3_leaf_add_work
0.17 ? 6% +0.1 0.27 ? 4% perf-profile.self.cycles-pp.entry_SYSRETQ_unsafe_stack
0.16 ? 12% +0.1 0.26 ? 2% perf-profile.self.cycles-pp.xfs_buf_item_size
0.17 ? 7% +0.1 0.27 ? 2% perf-profile.self.cycles-pp.__cond_resched
0.15 ? 12% +0.1 0.25 ? 7% perf-profile.self.cycles-pp.xfs_attr3_leaf_remove
0.14 ? 8% +0.1 0.24 ? 8% perf-profile.self.cycles-pp.xfs_attr_leaf_lasthash
0.18 ? 10% +0.1 0.28 ? 7% perf-profile.self.cycles-pp.__d_lookup_rcu
0.16 ? 9% +0.1 0.27 ? 6% perf-profile.self.cycles-pp.xfs_bmapi_update_map
0.20 ? 8% +0.1 0.31 ? 5% perf-profile.self.cycles-pp.xlog_prepare_iovec
0.19 ? 8% +0.1 0.30 ? 5% perf-profile.self.cycles-pp.entry_SYSCALL_64_after_hwframe
0.21 ? 13% +0.1 0.32 ? 5% perf-profile.self.cycles-pp.generic_permission
0.18 ? 10% +0.1 0.29 ? 7% perf-profile.self.cycles-pp.xfs_iread_extents
0.17 ? 9% +0.1 0.29 ? 4% perf-profile.self.cycles-pp.xfs_bmapi_trim_map
0.22 ? 11% +0.1 0.35 ? 4% perf-profile.self.cycles-pp._atomic_dec_and_lock
0.25 ? 9% +0.1 0.38 ? 6% perf-profile.self.cycles-pp.xfs_da_state_free
0.23 ? 7% +0.1 0.36 ? 7% perf-profile.self.cycles-pp.__might_sleep
0.18 ? 8% +0.1 0.32 ? 6% perf-profile.self.cycles-pp.xfs_buf_read_map
0.31 ? 7% +0.1 0.46 ? 6% perf-profile.self.cycles-pp.xfs_buf_item_log
0.26 ? 10% +0.2 0.41 ? 4% perf-profile.self.cycles-pp.xfs_errortag_test
0.30 ? 8% +0.2 0.46 ? 3% perf-profile.self.cycles-pp.xfs_buf_rele
0.26 ? 10% +0.2 0.42 ? 6% perf-profile.self.cycles-pp.memcg_slab_free_hook
0.31 ? 8% +0.2 0.50 ? 7% perf-profile.self.cycles-pp.memmove
0.33 ? 6% +0.2 0.54 ? 4% perf-profile.self.cycles-pp.xfs_trans_read_buf_map
0.35 ? 7% +0.2 0.56 ? 5% perf-profile.self.cycles-pp.xfs_da_read_buf
0.40 ? 7% +0.2 0.62 ? 5% perf-profile.self.cycles-pp.link_path_walk
0.42 ? 8% +0.2 0.65 ? 3% perf-profile.self.cycles-pp.xfs_iext_lookup_extent
0.41 ? 4% +0.2 0.66 ? 6% perf-profile.self.cycles-pp.__might_resched
0.26 ? 9% +0.3 0.52 ? 5% perf-profile.self.cycles-pp.__rhashtable_lookup
0.48 ? 7% +0.3 0.78 ? 3% perf-profile.self.cycles-pp.xfs_dabuf_map
0.54 ? 5% +0.3 0.87 ? 3% perf-profile.self.cycles-pp.strncpy_from_user
0.54 ? 5% +0.4 0.90 ? 4% perf-profile.self.cycles-pp.memset_erms
0.63 ? 8% +0.4 1.00 ? 5% perf-profile.self.cycles-pp.kmem_cache_free
0.67 ? 7% +0.4 1.05 ? 4% perf-profile.self.cycles-pp.xfs_da3_node_lookup_int
0.70 ? 5% +0.4 1.11 ? 4% perf-profile.self.cycles-pp.xfs_bmapi_read
0.58 ? 7% +0.4 1.00 ? 4% perf-profile.self.cycles-pp.xfs_attr3_leaf_hdr_from_disk
0.67 ? 6% +0.4 1.10 ? 2% perf-profile.self.cycles-pp.kmem_cache_alloc
0.52 ? 4% +0.4 0.95 ? 4% perf-profile.self.cycles-pp.xfs_attr3_leaf_lookup_int
0.12 ? 8% +0.5 0.58 ? 7% perf-profile.self.cycles-pp.xfs_log_space_wake
0.86 ? 3% +0.5 1.34 ? 3% perf-profile.self.cycles-pp._raw_spin_lock_irqsave
1.13 ? 6% +0.5 1.62 ? 4% perf-profile.self.cycles-pp.memcpy_erms
0.79 ? 7% +0.6 1.36 ? 4% perf-profile.self.cycles-pp.xfs_buf_find
2.80 ? 3% +0.6 3.39 ? 7% perf-profile.self.cycles-pp.xfs_log_ticket_ungrant
1.78 ? 3% +0.7 2.49 ? 13% perf-profile.self.cycles-pp.up_read
3.56 +0.9 4.44 ? 4% perf-profile.self.cycles-pp._raw_spin_lock
2.60 ? 5% +1.1 3.66 ? 10% perf-profile.self.cycles-pp.down_read
0.82 ? 7% +1.1 1.90 ? 2% perf-profile.self.cycles-pp.xlog_space_left
0.81 ? 12% +1.3 2.14 ? 4% perf-profile.self.cycles-pp.xfs_perag_put
3.41 ? 7% +1.4 4.81 ? 10% perf-profile.self.cycles-pp.xlog_cil_commit
1.26 ? 6% +2.0 3.28 ? 5% perf-profile.self.cycles-pp.xlog_grant_add_space
3.26 ? 10% +3.1 6.37 ? 6% perf-profile.self.cycles-pp.xfs_perag_get




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://01.org/lkp




Attachments:
(No filename) (74.87 kB)
config-5.19.0-rc2-00021-g016a23388cdc (166.41 kB)
config-5.19.0-rc2-00021-g016a23388cdc
job-script (8.48 kB)
job-script
job.yaml (5.84 kB)
job.yaml
reproduce (582.00 B)
reproduce
Download all attachments

2022-07-21 22:05:39

by Dave Chinner

[permalink] [raw]
Subject: Re: [xfs] 016a23388c: stress-ng.xattr.ops_per_sec 58.4% improvement

On Thu, Jul 21, 2022 at 10:30:21AM +0800, kernel test robot wrote:
>
>
> Greeting,
>
> FYI, we noticed a 58.4% improvement of stress-ng.xattr.ops_per_sec due to commit:
>
>
> commit: 016a23388cdcb2740deb1379dc408f21c84efb11 ("xfs: Add order IDs to log items in CIL")
> https://git.kernel.org/cgit/linux/kernel/git/next/linux-next.git master
>
> in testcase: stress-ng
> on test machine: 96 threads 2 sockets Ice Lake with 256G memory
> with following parameters:
>
> nr_threads: 10%
> disk: 1HDD
> testtime: 60s
> fs: xfs
> class: filesystem
> test: xattr
> cpufreq_governor: performance
> ucode: 0xb000280
>
>
>
>
>
>
> 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.
>
> =========================================================================================
> class/compiler/cpufreq_governor/disk/fs/kconfig/nr_threads/rootfs/tbox_group/test/testcase/testtime/ucode:
> filesystem/gcc-11/performance/1HDD/xfs/x86_64-rhel-8.3/10%/debian-11.1-x86_64-20220510.cgz/lkp-icl-2sp1/xattr/stress-ng/60s/0xb000280
>
> commit:
> df7a4a2134 ("xfs: convert CIL busy extents to per-cpu")
> 016a23388c ("xfs: Add order IDs to log items in CIL")

This bisect looks like it's identified the wrong commit. The reason
things went faster was:

> df7a4a2134b0a201 016a23388cdcb2740deb1379dc4
> ---------------- ---------------------------
> %stddev %change %stddev
> \ | \
.....
> 25.64 ? 8% -25.6 0.00 perf-profile.calltrace.cycles-pp.native_queued_spin_lock_slowpath._raw_spin_lock.xlog_cil_insert_items.xlog_cil_commit.__xfs_trans_commit

A huge amount of spinlock contention in the xlog_commit_cil() path
went away. The commit identified doesn't remove/change any
spinlocks, it actually adds more overhead to the critical section of
the above spinlock in preparation for removing said spinlocks.

That removal happens in the next commit in that series - c0fb4765c508 ("xfs:
convert CIL to unordered per cpu lists") - so I'd be expecting a
bisect to demonstrate that the spinlock contention goes away with
the commit that removed the spinlocks (as it does in all the testing
of this I've done over the past 2 years), not the commit this bisect
identified. Hence I think the bisect went wrong somewhere...

Cheers,

Dave.
--
Dave Chinner
[email protected]

2022-08-02 06:41:42

by Yin, Fengwei

[permalink] [raw]
Subject: Re: [LKP] Re: [xfs] 016a23388c: stress-ng.xattr.ops_per_sec 58.4% improvement

Hi Dave,

On 7/22/2022 6:01 AM, Dave Chinner wrote:
> A huge amount of spinlock contention in the xlog_commit_cil() path
> went away. The commit identified doesn't remove/change any
> spinlocks, it actually adds more overhead to the critical section of
> the above spinlock in preparation for removing said spinlocks.
>
> That removal happens in the next commit in that series - c0fb4765c508 ("xfs:
> convert CIL to unordered per cpu lists") - so I'd be expecting a
> bisect to demonstrate that the spinlock contention goes away with
> the commit that removed the spinlocks (as it does in all the testing
> of this I've done over the past 2 years), not the commit this bisect
> identified. Hence I think the bisect went wrong somewhere...

We did some investigation and got:

commit:
df7a4a2134b0a ("xfs: convert CIL busy extents to per-cpu")
016a23388cdcb ("xfs: Add order IDs to log items in CIL")
c0fb4765c5086 ("xfs: convert CIL to unordered per cpu lists")

df7a4a2134b0a201 016a23388cdcb2740deb1379dc4 c0fb4765c5086cfd00f1158f5f4
---------------- --------------------------- ---------------------------
%stddev %change %stddev %change %stddev
\ | \ | \
62.07 +0.0% 62.09 -0.0% 62.06 stress-ng.time.elapsed_time
62.07 +0.0% 62.09 -0.0% 62.06 stress-ng.time.elapsed_time.max
2237 +0.0% 2237 +0.0% 2237 stress-ng.time.file_system_inputs
1842 ± 4% +16.9% 2152 ± 3% +17.6% 2166 stress-ng.time.involuntary_context_switches
551.00 -0.3% 549.10 -0.3% 549.40 stress-ng.time.major_page_faults
6376 -1.1% 6305 ± 2% +0.6% 6416 stress-ng.time.maximum_resident_set_size
9704 -0.3% 9676 -0.1% 9691 stress-ng.time.minor_page_faults
4096 +0.0% 4096 +0.0% 4096 stress-ng.time.page_size
841.90 -2.4% 821.70 -2.4% 821.90 stress-ng.time.percent_of_cpu_this_job_got
512.83 -3.4% 495.24 -3.6% 494.18 stress-ng.time.system_time
10.05 ± 8% +52.3% 15.30 ± 3% +61.1% 16.19 ± 2% stress-ng.time.user_time
2325 ± 16% +66.5% 3873 ± 7% +70.3% 3962 ± 6% stress-ng.time.voluntary_context_switches
1544 ± 4% +54.4% 2385 +63.9% 2531 stress-ng.xattr.ops

Yes. commit c0fb4765c5086 ("xfs: convert CIL to unordered per cpu lists")
could bring performance gain also. But the most performance gain (54.4%)
is from commit 016a23388cdcb ("xfs: Add order IDs to log items in CIL").


Based on commit 016a23388cdcb and add following change:

diff --git a/fs/xfs/xfs_log_cil.c b/fs/xfs/xfs_log_cil.c
index 6bc540898e3a..7c6c91a0a12d 100644
--- a/fs/xfs/xfs_log_cil.c
+++ b/fs/xfs/xfs_log_cil.c
@@ -659,9 +659,14 @@ xlog_cil_insert_items(
continue;

lip->li_order_id = order;
- if (!list_empty(&lip->li_cil))
- continue;
- list_add_tail(&lip->li_cil, &cil->xc_cil);
+
+ /*
+ * Only move the item if it isn't already at the tail. This is
+ * to prevent a transient list_empty() state when reinserting
+ * an item that is already the only item in the CIL.
+ */
+ if (!list_is_last(&lip->li_cil, &cil->xc_cil))
+ list_move_tail(&lip->li_cil, &cil->xc_cil);
}

The performance will drop to the same level as commit df7a4a2134b0a
("xfs: convert CIL busy extents to per-cpu"):

commit:
016a23388cdcb2740deb1379dc408f21c84efb11
a8bef09e7d8e65207c8403e030a0965db43ce3de

016a23388cdcb274 a8bef09e7d8e65207c8403e030a
---------------- ---------------------------
%stddev %change %stddev
\ | \
62.06 -0.0% 62.05 stress-ng.time.elapsed_time
62.06 -0.0% 62.05 stress-ng.time.elapsed_time.max
2237 +0.0% 2237 stress-ng.time.file_system_inputs
2226 -16.7% 1855 ± 4% stress-ng.time.involuntary_context_switches
549.00 +0.5% 551.67 stress-ng.time.major_page_faults
6286 +0.1% 6292 stress-ng.time.maximum_resident_set_size
9636 +0.1% 9641 stress-ng.time.minor_page_faults
4096 +0.0% 4096 stress-ng.time.page_size
823.00 +3.0% 847.33 stress-ng.time.percent_of_cpu_this_job_got
496.02 +4.2% 516.61 stress-ng.time.system_time
15.08 -38.1% 9.33 ± 4% stress-ng.time.user_time
4034 ± 3% -43.0% 2299 ± 6% stress-ng.time.voluntary_context_switches
2368 -37.4% 1482 ± 4% stress-ng.xattr.ops



Regards
Yin, Fengwei

2022-08-03 01:17:50

by Dave Chinner

[permalink] [raw]
Subject: Re: [LKP] Re: [xfs] 016a23388c: stress-ng.xattr.ops_per_sec 58.4% improvement

On Tue, Aug 02, 2022 at 02:36:00PM +0800, Yin, Fengwei wrote:
> Hi Dave,
>
> On 7/22/2022 6:01 AM, Dave Chinner wrote:
> > A huge amount of spinlock contention in the xlog_commit_cil() path
> > went away. The commit identified doesn't remove/change any
> > spinlocks, it actually adds more overhead to the critical section of
> > the above spinlock in preparation for removing said spinlocks.
> >
> > That removal happens in the next commit in that series - c0fb4765c508 ("xfs:
> > convert CIL to unordered per cpu lists") - so I'd be expecting a
> > bisect to demonstrate that the spinlock contention goes away with
> > the commit that removed the spinlocks (as it does in all the testing
> > of this I've done over the past 2 years), not the commit this bisect
> > identified. Hence I think the bisect went wrong somewhere...
>
> We did some investigation and got:
>
> commit:
> df7a4a2134b0a ("xfs: convert CIL busy extents to per-cpu")
> 016a23388cdcb ("xfs: Add order IDs to log items in CIL")
> c0fb4765c5086 ("xfs: convert CIL to unordered per cpu lists")
>
> df7a4a2134b0a201 016a23388cdcb2740deb1379dc4 c0fb4765c5086cfd00f1158f5f4
> ---------------- --------------------------- ---------------------------
> %stddev %change %stddev %change %stddev
> \ | \ | \
> 62.07 +0.0% 62.09 -0.0% 62.06 stress-ng.time.elapsed_time
> 62.07 +0.0% 62.09 -0.0% 62.06 stress-ng.time.elapsed_time.max
> 2237 +0.0% 2237 +0.0% 2237 stress-ng.time.file_system_inputs
> 1842 ? 4% +16.9% 2152 ? 3% +17.6% 2166 stress-ng.time.involuntary_context_switches
> 551.00 -0.3% 549.10 -0.3% 549.40 stress-ng.time.major_page_faults
> 6376 -1.1% 6305 ? 2% +0.6% 6416 stress-ng.time.maximum_resident_set_size
> 9704 -0.3% 9676 -0.1% 9691 stress-ng.time.minor_page_faults
> 4096 +0.0% 4096 +0.0% 4096 stress-ng.time.page_size
> 841.90 -2.4% 821.70 -2.4% 821.90 stress-ng.time.percent_of_cpu_this_job_got
> 512.83 -3.4% 495.24 -3.6% 494.18 stress-ng.time.system_time
> 10.05 ? 8% +52.3% 15.30 ? 3% +61.1% 16.19 ? 2% stress-ng.time.user_time
> 2325 ? 16% +66.5% 3873 ? 7% +70.3% 3962 ? 6% stress-ng.time.voluntary_context_switches
> 1544 ? 4% +54.4% 2385 +63.9% 2531 stress-ng.xattr.ops
>
> Yes. commit c0fb4765c5086 ("xfs: convert CIL to unordered per cpu lists")
> could bring performance gain also. But the most performance gain (54.4%)
> is from commit 016a23388cdcb ("xfs: Add order IDs to log items in CIL").
>
>
> Based on commit 016a23388cdcb and add following change:
>
> diff --git a/fs/xfs/xfs_log_cil.c b/fs/xfs/xfs_log_cil.c
> index 6bc540898e3a..7c6c91a0a12d 100644
> --- a/fs/xfs/xfs_log_cil.c
> +++ b/fs/xfs/xfs_log_cil.c
> @@ -659,9 +659,14 @@ xlog_cil_insert_items(
> continue;
>
> lip->li_order_id = order;
> - if (!list_empty(&lip->li_cil))
> - continue;
> - list_add_tail(&lip->li_cil, &cil->xc_cil);
> +
> + /*
> + * Only move the item if it isn't already at the tail. This is
> + * to prevent a transient list_empty() state when reinserting
> + * an item that is already the only item in the CIL.
> + */
> + if (!list_is_last(&lip->li_cil, &cil->xc_cil))
> + list_move_tail(&lip->li_cil, &cil->xc_cil);
> }
>
> The performance will drop to the same level as commit df7a4a2134b0a
> ("xfs: convert CIL busy extents to per-cpu"):

Thanks for looking into this.

This looks like a case of the workload being right at the threshold
of catastrophic cache line contention breakdown on this workload.
i.e. a single extra exclusive cache miss inside the spin lock
critical region is sufficient overload the memory bus bandwidth and
so the cacheline contention on the lock from nothing to "all the
spare CPU time is spent contending on the spin lock cache line".

IOWs, the lock contention problem doesn't go away with this commit,
it just falls back under the critical threshold where the cache
coherency protocol runs out of memory bus bandwidth bouncing dirty
cachelines around all the CPU cores and so causes spinlock overhead
to go from linear cost to exponential cost.

That a single cacheline miss avoids all the spinlock contention is
just pure luck - it'll come back if other work is being done on the
machine that consumes enough memory bandwidth to push this back over
the edge. Hence the real fix for the spinlock contention problem is
still the patch I pointed out that removes the spinlocks
altogether...

Cheers,

Dave.
--
Dave Chinner
[email protected]

2022-08-03 14:24:22

by Yin, Fengwei

[permalink] [raw]
Subject: Re: [LKP] Re: [xfs] 016a23388c: stress-ng.xattr.ops_per_sec 58.4% improvement

Hi Dave,

On 8/3/2022 9:02 AM, Dave Chinner wrote:
> That a single cacheline miss avoids all the spinlock contention is
> just pure luck - it'll come back if other work is being done on the
> machine that consumes enough memory bandwidth to push this back over
> the edge.

Agree. We did see some strange performance boost which can't be connected
to the code change. And worried later unrelated change reduce the
mysterious performance gain (and report it as regression).

Regards
Yin, Fengwei