LinuxLists.cc - [mm/gup] a308c71bf1: stress-ng.vm-splice.ops_per

2020-11-02 09:17:48

Subject: [mm/gup] a308c71bf1: stress-ng.vm-splice.ops_per_sec -95.6% regression

Greeting,

FYI, we

commit: https://git.kernel.org/cgit/linux/kernel/git/torvalds/linux.git master
machine: 96 threads Intel(R) Xeon(R) Gold 6252 CPU @ 2.10GHz with 192G memory
the issue, kindly add following tag
kernel test robot <[email protected]>
--------------------------------------------------------------------------------->
href="https://github.com/intel/lkp-tests.git">https://github.com/intel/lkp-tests.git
bin/lkp install job.yaml # job file is attached in this email
========================================================================
ufreq_governor/disk/kconfig/nr_threads/rootfs/tbox_group/testcase/testtime/ucode:
ormance/1HDD/x86_64-rhel-8.3/100%/debian-10.4-x86_64-20200603.cgz/lkp-csl-2sp5/stress-ng/30s/0x5002f01
("mm/ksm: Remove reuse_ksm_page()")
("mm/gup: Remove enfornced COW mechanism")
a308c71bf1e6e19cc2e4ced3185
---------------------------
%change %stddev
| \
+2.1% 19191 stress-ng.time.system_time
-35.9% 678.99 ± 4% stress-ng.time.user_time
+10.3% 1.716e+08 ± 4% stress-ng.time.voluntary_context_switches
-95.6% 1.49e+08 stress-ng.vm-splice.ops
-95.6% 4965911 stress-ng.vm-splice.ops_per_sec
-1.8 3.26 ± 4% mpstat.cpu.all.usr%
+2.0% 93.77 iostat.cpu.system
-36.2% 3.23 ± 4% iostat.cpu.user
+6.7% 30235 ± 2% proc-vmstat.nr_kernel_stack
+11.2% 13513 ± 5% proc-vmstat.nr_page_table_pages
+8.0% 2987 ± 5% slabinfo.PING.active_objs
+8.0% 2987 ± 5% slabinfo.PING.num_objs
+1.9% 93.00 vmstat.cpu.sy
+11.4% 1108222 ± 4% vmstat.system.cs
-14.9% 11524 ± 9% numa-vmstat.node0.nr_slab_reclaimable
+128.4% 93118 ± 61% numa-vmstat.node0.numa_other
+15.9% 14448 ± 6% numa-vmstat.node1.nr_slab_reclaimable
-14.9% 46101 ± 9% numa-meminfo.node0.KReclaimable
-14.9% 46101 ± 9% numa-meminfo.node0.SReclaimable
+73.2% 11588 ± 34% numa-meminfo.node1.Inactive
+73.2% 11588 ± 34% numa-meminfo.node1.Inactive(anon)
+15.9% 57793 ± 6% numa-meminfo.node1.KReclaimable
+15.9% 57793 ± 6% numa-meminfo.node1.SReclaimable
-35.0% 51.50 ± 8% sched_debug.cfs_rq:/.nr_spread_over.max
-22.7% 7.55 ± 9% sched_debug.cfs_rq:/.nr_spread_over.stddev
-19.1% 224.01 ± 11% sched_debug.cfs_rq:/.runnable_avg.stddev
-44.1% 231543 ± 45% sched_debug.cfs_rq:/.spread0.avg
-28.1% 863115 ± 23% sched_debug.cfs_rq:/.spread0.max
-48.0% 10.52 ± 18% sched_debug.cpu.clock.stddev
+13.1% 1594913 ± 5% sched_debug.cpu.nr_switches.avg
+13.1% 1593368 ± 5% sched_debug.cpu.sched_count.avg
+12.5% 1102701 ± 4% sched_debug.cpu.ttwu_count.avg
+13.9% 986450 ± 5% sched_debug.cpu.ttwu_local.avg
-6.3 31.86 ± 16% perf-profile.calltrace.cycles-pp.ksys_read.do_syscall_64.entry_SYSCALL_64_after_hwframe
-6.2 31.12 ± 16% perf-profile.calltrace.cycles-pp.vfs_read.ksys_read.do_syscall_64.entry_SYSCALL_64_after_hwframe
-5.7 27.65 ± 15% perf-profile.calltrace.cycles-pp.new_sync_read.vfs_read.ksys_read.do_syscall_64.entry_SYSCALL_64_after_hwframe
-5.6 26.93 ± 15% perf-profile.calltrace.cycles-pp.pipe_read.new_sync_read.vfs_read.ksys_read.do_syscall_64
-5.1 21.23 ± 14% perf-profile.calltrace.cycles-pp.__wake_up_common_lock.pipe_read.new_sync_read.vfs_read.ksys_read
-5.1 20.92 ± 14% perf-profile.calltrace.cycles-pp.__wake_up_common.__wake_up_common_lock.pipe_read.new_sync_read.vfs_read
-5.1 20.89 ± 14% perf-profile.calltrace.cycles-pp.autoremove_wake_function.__wake_up_common.__wake_up_common_lock.pipe_read.new_sync_read
-5.1 20.88 ± 14% perf-profile.calltrace.cycles-pp.try_to_wake_up.autoremove_wake_function.__wake_up_common.__wake_up_common_lock.pipe_read
-5.0 19.70 ± 15% perf-profile.calltrace.cycles-pp.ttwu_do_activate.try_to_wake_up.autoremove_wake_function.__wake_up_common.__wake_up_common_lock
-5.0 19.70 ± 15% perf-profile.calltrace.cycles-pp.enqueue_task_fair.ttwu_do_activate.try_to_wake_up.autoremove_wake_function.__wake_up_common
-5.0 19.32 ± 15% perf-profile.calltrace.cycles-pp.enqueue_entity.enqueue_task_fair.ttwu_do_activate.try_to_wake_up.autoremove_wake_function
+0.4 1.40 ± 16% perf-profile.calltrace.cycles-pp.arch_stack_walk.stack_trace_save_tsk.__account_scheduler_latency.update_stats_enqueue_sleeper.enqueue_entity
+0.4 1.48 ± 16% perf-profile.calltrace.cycles-pp.stack_trace_save_tsk.__account_scheduler_latency.update_stats_enqueue_sleeper.enqueue_entity.enqueue_task_fair
+0.5 11.60 ± 3% perf-profile.calltrace.cycles-pp.do_select.core_sys_select.kern_select.__x64_sys_select.do_syscall_64
-6.3 31.88 ± 16% perf-profile.children.cycles-pp.ksys_read
-6.3 31.20 ± 16% perf-profile.children.cycles-pp.vfs_read
-5.7 27.68 ± 15% perf-profile.children.cycles-pp.new_sync_read
-5.6 26.99 ± 15% perf-profile.children.cycles-pp.pipe_read
-5.1 20.90 ± 14% perf-profile.children.cycles-pp.autoremove_wake_function
+0.0 0.11 ± 4% perf-profile.children.cycles-pp.pick_next_entity
+0.0 0.31 ± 3% perf-profile.children.cycles-pp.load_new_mm_cr3
+0.1 0.45 ± 3% perf-profile.children.cycles-pp.switch_mm_irqs_off
+0.1 0.56 ± 2% perf-profile.children.cycles-pp.pick_next_task_fair
+0.1 0.11 ± 21% perf-profile.children.cycles-pp.__mutex_unlock_slowpath
+0.3 2.40 ± 4% perf-profile.children.cycles-pp.schedule
+0.5 11.71 ± 2% perf-profile.children.cycles-pp.do_select
+0.0 0.06 perf-profile.self.cycles-pp.finish_task_switch
+0.0 0.07 ± 7% perf-profile.self.cycles-pp.dequeue_task_fair
+0.0 0.26 ± 4% perf-profile.self.cycles-pp.__sched_text_start
+0.0 0.31 ± 3% perf-profile.self.cycles-pp.load_new_mm_cr3
+8.8% 12.53 perf-stat.i.MPKI
-20.3% 2.636e+10 ± 2% perf-stat.i.branch-instructions
+0.0 0.75 perf-stat.i.branch-miss-rate%
-27.3% 1.423e+08 ± 3% perf-stat.i.branch-misses
+13.0% 1115216 ± 4% perf-stat.i.context-switches
+43.7% 7.11 perf-stat.i.cpi
-20.9% 3.737e+10 ± 2% perf-stat.i.dTLB-loads
-22.3% 2.168e+10 ± 3% perf-stat.i.dTLB-stores
-29.2% 1.175e+08 ± 5% perf-stat.i.iTLB-load-misses
-21.1% 1.305e+11 ± 2% perf-stat.i.instructions
-20.7% 0.53 ± 2% perf-stat.i.ipc
-23.8% 0.91 ± 5% perf-stat.i.metric.K/sec
-21.0% 893.12 ± 3% perf-stat.i.metric.M/sec
+0.9 92.88 perf-stat.i.node-store-miss-rate%
+31.1% 2.66 ± 5% perf-stat.overall.MPKI
-0.0 0.54 perf-stat.overall.branch-miss-rate%
+28.4% 1.98 ± 2% perf-stat.overall.cpi
+0.0 0.00 ± 6% perf-stat.overall.dTLB-store-miss-rate%
-1.4 95.70 perf-stat.overall.iTLB-load-miss-rate%
+10.9% 1099 ± 2% perf-stat.overall.instructions-per-iTLB-miss
-22.0% 0.51 ± 2% perf-stat.overall.ipc
+2.0 89.39 perf-stat.overall.node-store-miss-rate%
-20.8% 2.592e+10 ± 3% perf-stat.ps.branch-instructions
-27.4% 1.412e+08 ± 3% perf-stat.ps.branch-misses
+11.5% 1119933 ± 4% perf-stat.ps.context-switches
-21.3% 3.674e+10 ± 3% perf-stat.ps.dTLB-loads
-22.7% 2.131e+10 ± 3% perf-stat.ps.dTLB-stores
-29.3% 1.168e+08 ± 5% perf-stat.ps.iTLB-load-misses
-21.6% 1.283e+11 ± 3% perf-stat.ps.instructions
-21.6% 2.741e+13 ± 3% perf-stat.total.instructions
+33.4% 8988 ± 12% softirqs.CPU14.SCHED
+36.0% 9217 ± 8% softirqs.CPU19.SCHED
+29.1% 9500 ± 14% softirqs.CPU2.SCHED
-19.5% 7811 ± 5% softirqs.CPU24.SCHED
-18.2% 7890 ± 3% softirqs.CPU25.SCHED
-18.1% 7737 ± 10% softirqs.CPU27.SCHED
-18.3% 7826 ± 5% softirqs.CPU30.SCHED
-16.8% 7882 ± 5% softirqs.CPU31.SCHED
-16.1% 8246 ± 7% softirqs.CPU32.SCHED
-15.0% 7922 ± 5% softirqs.CPU34.SCHED
-20.1% 8123 ± 3% softirqs.CPU35.SCHED
-15.6% 7772 ± 5% softirqs.CPU36.SCHED
-17.8% 7921 ± 7% softirqs.CPU37.SCHED
-16.0% 7896 ± 6% softirqs.CPU38.SCHED
-15.4% 7851 ± 6% softirqs.CPU39.SCHED
-21.6% 7786 ± 4% softirqs.CPU40.SCHED
-16.2% 7758 ± 6% softirqs.CPU41.SCHED
-16.7% 7901 ± 4% softirqs.CPU42.SCHED
-18.6% 7736 ± 5% softirqs.CPU43.SCHED
-17.4% 7926 ± 2% softirqs.CPU44.SCHED
-18.5% 7796 ± 5% softirqs.CPU46.SCHED
+26.9% 8353 ± 14% softirqs.CPU50.SCHED
+27.7% 8762 ± 16% softirqs.CPU55.SCHED
+31.4% 8537 ± 12% softirqs.CPU61.SCHED
+42.8% 8985 ± 20% softirqs.CPU69.SCHED
-20.1% 7439 ± 8% softirqs.CPU72.SCHED
-19.1% 7615 ± 5% softirqs.CPU74.SCHED
-15.9% 7863 ± 5% softirqs.CPU75.SCHED
-17.4% 7855 ± 5% softirqs.CPU76.SCHED
-16.8% 7851 ± 5% softirqs.CPU77.SCHED
-19.3% 7737 ± 5% softirqs.CPU78.SCHED
-17.2% 7765 ± 4% softirqs.CPU79.SCHED
-16.7% 7964 ± 5% softirqs.CPU80.SCHED
-15.3% 7927 ± 6% softirqs.CPU81.SCHED
-19.4% 7825 ± 6% softirqs.CPU82.SCHED
-19.8% 7827 ± 5% softirqs.CPU83.SCHED
-16.7% 7856 ± 5% softirqs.CPU84.SCHED
-15.7% 7863 ± 5% softirqs.CPU85.SCHED
-18.9% 7796 ± 4% softirqs.CPU88.SCHED
-17.6% 7654 ± 4% softirqs.CPU89.SCHED
-18.5% 7821 ± 5% softirqs.CPU90.SCHED
-18.6% 7752 ± 4% softirqs.CPU91.SCHED
-19.5% 7773 ± 5% softirqs.CPU92.SCHED
-17.5% 7949 ± 5% softirqs.CPU93.SCHED
-18.9% 7875 ± 5% softirqs.CPU94.SCHED
-22.6% 7821 ± 6% softirqs.CPU95.SCHED
-88.0% 208.50 ±173% interrupts.43:PCI-MSI.31981576-edge.i40e-eth0-TxRx-7
+73.0% 9730 ± 28% interrupts.CPU11.CAL:Function_call_interrupts
+500.0% 19155 ± 99% interrupts.CPU12.CAL:Function_call_interrupts
+387.9% 27579 ± 96% interrupts.CPU13.CAL:Function_call_interrupts
+206.3% 10382 ± 17% interrupts.CPU16.CAL:Function_call_interrupts
+781.8% 28328 ± 55% interrupts.CPU18.CAL:Function_call_interrupts
+261.3% 19884 ± 65% interrupts.CPU19.CAL:Function_call_interrupts
+37.2% 5908 ± 24% interrupts.CPU20.RES:Rescheduling_interrupts
+248.2% 12720 ± 12% interrupts.CPU21.CAL:Function_call_interrupts
+91.9% 9477 ± 52% interrupts.CPU22.CAL:Function_call_interrupts
-75.5% 5720 ± 41% interrupts.CPU25.CAL:Function_call_interrupts
-71.8% 6360 ± 35% interrupts.CPU26.CAL:Function_call_interrupts
-62.7% 8987 ± 57% interrupts.CPU27.CAL:Function_call_interrupts
+367.9% 28593 ± 55% interrupts.CPU27.RES:Rescheduling_interrupts
-69.3% 8675 ± 50% interrupts.CPU28.CAL:Function_call_interrupts
+402.4% 28060 ± 26% interrupts.CPU28.RES:Rescheduling_interrupts
-52.9% 9015 ± 61% interrupts.CPU29.CAL:Function_call_interrupts
+368.8% 23186 ± 70% interrupts.CPU29.RES:Rescheduling_interrupts
-73.4% 6694 ± 69% interrupts.CPU30.CAL:Function_call_interrupts
-63.0% 7620 ± 63% interrupts.CPU31.CAL:Function_call_interrupts
-30.6% 4620 ± 33% interrupts.CPU32.NMI:Non-maskable_interrupts
-30.6% 4620 ± 33% interrupts.CPU32.PMI:Performance_monitoring_interrupts
-70.4% 5906 ± 43% interrupts.CPU33.CAL:Function_call_interrupts
-68.5% 6813 ± 44% interrupts.CPU35.CAL:Function_call_interrupts
-63.7% 6560 ± 47% interrupts.CPU36.CAL:Function_call_interrupts
-60.0% 8913 ± 44% interrupts.CPU37.CAL:Function_call_interrupts
-63.7% 6173 ± 56% interrupts.CPU38.CAL:Function_call_interrupts
-62.8% 8375 ± 41% interrupts.CPU39.CAL:Function_call_interrupts
+100.0% 10743 ± 19% interrupts.CPU4.CAL:Function_call_interrupts
-63.8% 7530 ± 62% interrupts.CPU40.CAL:Function_call_interrupts
-67.6% 6125 ± 35% interrupts.CPU41.CAL:Function_call_interrupts
-66.3% 9688 ± 58% interrupts.CPU42.CAL:Function_call_interrupts
-72.2% 6561 ± 37% interrupts.CPU43.CAL:Function_call_interrupts
-72.1% 6136 ± 53% interrupts.CPU44.CAL:Function_call_interrupts
-47.7% 11326 ± 36% interrupts.CPU47.CAL:Function_call_interrupts
+170.1% 11653 ± 44% interrupts.CPU5.CAL:Function_call_interrupts
+176.8% 10988 ± 33% interrupts.CPU53.CAL:Function_call_interrupts
-33.5% 5672 ± 10% interrupts.CPU58.RES:Rescheduling_interrupts
+255.7% 16080 ± 32% interrupts.CPU61.CAL:Function_call_interrupts
+242.6% 13445 ± 39% interrupts.CPU63.CAL:Function_call_interrupts
+255.7% 11732 ± 44% interrupts.CPU69.CAL:Function_call_interrupts
-88.0% 208.25 ±173% interrupts.CPU7.43:PCI-MSI.31981576-edge.i40e-eth0-TxRx-7
-64.7% 7726 ± 47% interrupts.CPU73.CAL:Function_call_interrupts
-64.5% 8308 ± 66% interrupts.CPU74.CAL:Function_call_interrupts
+312.2% 27796 ± 38% interrupts.CPU75.RES:Rescheduling_interrupts
-72.8% 7728 ± 49% interrupts.CPU76.CAL:Function_call_interrupts
+354.3% 25062 ± 20% interrupts.CPU76.RES:Rescheduling_interrupts
+433.6% 25624 ± 55% interrupts.CPU77.RES:Rescheduling_interrupts
-67.8% 8348 ± 58% interrupts.CPU78.CAL:Function_call_interrupts
-67.7% 6863 ± 40% interrupts.CPU80.CAL:Function_call_interrupts
-66.8% 6996 ± 34% interrupts.CPU83.CAL:Function_call_interrupts
-52.4% 9306 ± 64% interrupts.CPU84.CAL:Function_call_interrupts
-58.4% 6902 ± 56% interrupts.CPU87.CAL:Function_call_interrupts
-75.4% 5363 ± 41% interrupts.CPU89.CAL:Function_call_interrupts
-52.0% 11718 ± 49% interrupts.CPU90.CAL:Function_call_interrupts
-74.0% 5389 ± 40% interrupts.CPU91.CAL:Function_call_interrupts
-63.7% 6587 ± 67% interrupts.CPU92.CAL:Function_call_interrupts
-56.8% 9925 ± 38% interrupts.CPU93.CAL:Function_call_interrupts
+368.6% 26505 ± 47% interrupts.CPU93.RES:Rescheduling_interrupts
-64.6% 7782 ± 68% interrupts.CPU94.CAL:Function_call_interrupts
+20.9% 1050234 ± 14% interrupts.RES:Rescheduling_interrupts

stress-ng.time.system_time

+-------------------------------------------------------------------+
|
O O O O |
O O O O O |
O O |
O O |
O O |
|
|
|
|
..+.. .+...+..+... |
..+..+...+.. +... .+. +. +..|
+...+..+...+.. .+. .. +. |
+-------------------------------------------------------------------+

stress-ng.vm-splice.ops

+-----------------------------------------------------------------+
|
|
|
|
|
|
|
|
|
|
|
|
| O O O O O O O O O O O O O O O O O O |
0 +-----------------------------------------------------------------+

stress-ng.vm-splice.ops_per_sec

+-----------------------------------------------------------------+
|..+...+..+..+...+..+..+..+...+..+..+...+..+..+...+..+..+..+...+..|
|
|
|
|
|
|
|
|
|
|
|
| O O O O O O O O O O O O O O O O O O |
0 +-----------------------------------------------------------------+

have been estimated based on internal Intel analysis and are provided
purposes only. Any difference in system hardware or software
configuration may affect actual performance.

Attachments:

(No filename) (23.96 kB)
config-5.8.0-00003-ga308c71bf1e6e (172.07 kB)
job-script (7.95 kB)
job.yaml (5.59 kB)
reproduce (400.00 B)
Download all attachments

2020-11-04 20:35:58

by Linus Torvalds

[permalink] [raw]

Subject: Re: [mm/gup] a308c71bf1: stress-ng.vm-splice.ops_per_sec -95.6% regression

On Mon, Nov 2, 2020 at 1:15 AM kernel test robot <[email protected]> wrote:
>
> Greeting,
>
> FYI, we noticed a -95.6% regression of stress-ng.vm-splice.ops_per_sec due to commit:
>
> commit: a308c71bf1e6e19cc2e4ced31853ee0fc7cb439a ("mm/gup: Remove enfornced COW mechanism")
> https://git.kernel.org/cgit/linux/kernel/git/torvalds/linux.git master

Note that this is just the reverse of the previous 2000% improvement
reported by the test robot here:

https://lore.kernel.org/lkml/20200611040453.GK12456@shao2-debian/

and the explanation seems to remain the same:

https://lore.kernel.org/lkml/CAG48ez1v1b4X5LgFya6nvi33-TWwqna_dc5jGFVosqQhdn_Nkg@mail.gmail.com/

IOW, this is testing a special case (zero page lookup) that the "force
COW" patches happened to turn into a regular case (COW creating a
regular page from the zero page).

The question is whether we should care about the zero page for gup_fast lookup.

If we do care, then the proper fix is likely simply to allow the zero
page in fast-gup, the same way we already do in slow-gup.

ENTIRELY UNTESTED PATCH ATTACHED.

Rong - mind testing this? I don't think the zero-page _should_ be
something that real loads care about, but hey, maybe people do want to
do things like splice zeroes very efficiently..

And note the "untested" part of the patch. It _looks_ fairly obvious,
but maybe I'm missing something.

Linus

Attachments:

patch (632.00 B)

2020-11-05 08:31:20

by Xing Zhengjun

[permalink] [raw]

Subject: Re: [LKP] Re: [mm/gup] a308c71bf1: stress-ng.vm-splice.ops_per_sec -95.6% regression

On 11/5/2020 2:29 AM, Linus Torvalds wrote:
> On Mon, Nov 2, 2020 at 1:15 AM kernel test robot <[email protected]> wrote:
>>
>> Greeting,
>>
>> FYI, we noticed a -95.6% regression of stress-ng.vm-splice.ops_per_sec due to commit:
>>
>> commit: a308c71bf1e6e19cc2e4ced31853ee0fc7cb439a ("mm/gup: Remove enfornced COW mechanism")
>> https://git.kernel.org/cgit/linux/kernel/git/torvalds/linux.git master
>
> Note that this is just the reverse of the previous 2000% improvement
> reported by the test robot here:
>
> https://lore.kernel.org/lkml/20200611040453.GK12456@shao2-debian/
>
> and the explanation seems to remain the same:
>
> https://lore.kernel.org/lkml/CAG48ez1v1b4X5LgFya6nvi33-TWwqna_dc5jGFVosqQhdn_Nkg@mail.gmail.com/
>
> IOW, this is testing a special case (zero page lookup) that the "force
> COW" patches happened to turn into a regular case (COW creating a
> regular page from the zero page).
>
> The question is whether we should care about the zero page for gup_fast lookup.
>
> If we do care, then the proper fix is likely simply to allow the zero
> page in fast-gup, the same way we already do in slow-gup.
>
> ENTIRELY UNTESTED PATCH ATTACHED.
>
> Rong - mind testing this? I don't think the zero-page _should_ be
> something that real loads care about, but hey, maybe people do want to
> do things like splice zeroes very efficiently..

I test the patch, the regression still existed.

=========================================================================================
tbox_group/testcase/rootfs/kconfig/compiler/nr_threads/disk/testtime/class/cpufreq_governor/ucode:

lkp-csl-2sp5/stress-ng/debian-10.4-x86_64-20200603.cgz/x86_64-rhel-8.3/gcc-9/100%/1HDD/30s/pipe/performance/0x5002f01

commit:
1a0cf26323c80e2f1c58fc04f15686de61bfab0c
a308c71bf1e6e19cc2e4ced31853ee0fc7cb439a
da5ba9980aa2211c1e2a89fc814abab2fea6f69d (debug patch)

1a0cf26323c80e2f a308c71bf1e6e19cc2e4ced3185 da5ba9980aa2211c1e2a89fc814
---------------- --------------------------- ---------------------------
%stddev %change %stddev %change %stddev
\ | \ | \
3.406e+09 -95.6% 1.49e+08 -96.4% 1.213e+08
stress-ng.vm-splice.ops
1.135e+08 -95.6% 4965911 -96.4% 4041777
stress-ng.vm-splice.ops_per_sec

>
> And note the "untested" part of the patch. It _looks_ fairly obvious,
> but maybe I'm missing something.
>
> Linus
>
>
> _______________________________________________
> LKP mailing list -- [email protected]
> To unsubscribe send an email to [email protected]
>

--
Zhengjun Xing

2020-11-05 18:39:40

by Linus Torvalds

[permalink] [raw]

Subject: Re: [LKP] Re: [mm/gup] a308c71bf1: stress-ng.vm-splice.ops_per_sec -95.6% regression

On Thu, Nov 5, 2020 at 12:29 AM Xing Zhengjun
<[email protected]> wrote:
>
> > Rong - mind testing this? I don't think the zero-page _should_ be
> > something that real loads care about, but hey, maybe people do want to
> > do things like splice zeroes very efficiently..
>
> I test the patch, the regression still existed.

Thanks.

So Jann's suspicion seems interesting but apparently not the reason
for this particular case.

For being such a _huge_ difference (20x improvement followed by a 20x
regression), it's surprising how little the numbers give a clue. The
big changes are things like
"interrupts.CPU19.CAL:Function_call_interrupts", but while those
change by hundreds of percent, most of the changes seem to just be
about them moving to different CPU's. IOW, we have things like

5652 ± 59% +387.9% 27579 ± 96%
interrupts.CPU13.CAL:Function_call_interrupts
28249 ± 32% -69.3% 8675 ± 50%
interrupts.CPU28.CAL:Function_call_interrupts

which isn't really much of a change at all despite the changes looking
very big - it's just the stats jumping from one CPU to another.

Maybe there's some actual change in there, but it's very well hidden if so.

Yes, some of the numbers get worse:

868396 ± 3% +20.9% 1050234 ± 14%
interrupts.RES:Rescheduling_interrupts

so that's a 20% increase in rescheduling interrupts, But it's a 20%
increase, not a 500% one. So the fact that performance changes by 20x
is still very unclear to me.

We do have a lot of those numa-meminfo changes, but they could just
come from allocation patterns.

That said - another difference between the fast-cup code and the
regular gup code is that the fast-gup code does

if (pte_protnone(pte))
goto pte_unmap;

and the regular slow case does

if ((flags & FOLL_NUMA) && pte_protnone(pte))
goto no_page;

now, FOLL_NUMA is always set in the slow case if we don't have
FOLL_FORCE set, so this difference isn't "real", but it's one of those
cases where the zero-page might be marked for NUMA faulting, and doing
the forced COW might then cause it to be accessible.

Just out of curiosity, do the numbers change enormously if you just remove that

if (pte_protnone(pte))
goto pte_unmap;

test from the fast-cup case (top of the loop in gup_pte_range()) -
effectively making fast-gup basically act like FOLL_FORCE wrt numa
placement..

I'm not convinced that's a valid change in general, so this is just a
"to debug the odd performance numbers" issue.

Also out of curiosity: is the performance profile limited to just the
load, or is it a system profile (ie do you have "-a" on the perf
record line or not).

Linus

2020-11-06 05:18:01

by Xing Zhengjun

[permalink] [raw]

Subject: Re: [LKP] Re: [mm/gup] a308c71bf1: stress-ng.vm-splice.ops_per_sec -95.6% regression

On 11/6/2020 2:37 AM, Linus Torvalds wrote:
> On Thu, Nov 5, 2020 at 12:29 AM Xing Zhengjun
> <[email protected]> wrote:
>>
>>> Rong - mind testing this? I don't think the zero-page _should_ be
>>> something that real loads care about, but hey, maybe people do want to
>>> do things like splice zeroes very efficiently..
>>
>> I test the patch, the regression still existed.
>
> Thanks.
>
> So Jann's suspicion seems interesting but apparently not the reason
> for this particular case.
>
> For being such a _huge_ difference (20x improvement followed by a 20x
> regression), it's surprising how little the numbers give a clue. The
> big changes are things like
> "interrupts.CPU19.CAL:Function_call_interrupts", but while those
> change by hundreds of percent, most of the changes seem to just be
> about them moving to different CPU's. IOW, we have things like
>
> 5652 ± 59% +387.9% 27579 ± 96%
> interrupts.CPU13.CAL:Function_call_interrupts
> 28249 ± 32% -69.3% 8675 ± 50%
> interrupts.CPU28.CAL:Function_call_interrupts
>
> which isn't really much of a change at all despite the changes looking
> very big - it's just the stats jumping from one CPU to another.
>
> Maybe there's some actual change in there, but it's very well hidden if so.
>
> Yes, some of the numbers get worse:
>
> 868396 ± 3% +20.9% 1050234 ± 14%
> interrupts.RES:Rescheduling_interrupts
>
> so that's a 20% increase in rescheduling interrupts, But it's a 20%
> increase, not a 500% one. So the fact that performance changes by 20x
> is still very unclear to me.
>
> We do have a lot of those numa-meminfo changes, but they could just
> come from allocation patterns.
>
> That said - another difference between the fast-cup code and the
> regular gup code is that the fast-gup code does
>
> if (pte_protnone(pte))
> goto pte_unmap;
>
> and the regular slow case does
>
> if ((flags & FOLL_NUMA) && pte_protnone(pte))
> goto no_page;
>
> now, FOLL_NUMA is always set in the slow case if we don't have
> FOLL_FORCE set, so this difference isn't "real", but it's one of those
> cases where the zero-page might be marked for NUMA faulting, and doing
> the forced COW might then cause it to be accessible.
>
> Just out of curiosity, do the numbers change enormously if you just remove that
>
> if (pte_protnone(pte))
> goto pte_unmap;
>
> test from the fast-cup case (top of the loop in gup_pte_range()) -
> effectively making fast-gup basically act like FOLL_FORCE wrt numa
> placement..

Based on the last debug patch, I removed the two lines code at the top
of the loop in gup_pte_range() as you mentioned, the regression still
existed.

=========================================================================================
tbox_group/testcase/rootfs/kconfig/compiler/nr_threads/disk/testtime/class/cpufreq_governor/ucode:

lkp-csl-2sp5/stress-ng/debian-10.4-x86_64-20200603.cgz/x86_64-rhel-8.3/gcc-9/100%/1HDD/30s/pipe/performance/0x5002f01

commit:
1a0cf26323c80e2f1c58fc04f15686de61bfab0c
a308c71bf1e6e19cc2e4ced31853ee0fc7cb439a
da5ba9980aa2211c1e2a89fc814abab2fea6f69d (last debug patch)
8803d304738b52f66f6b683be38c4f8b9cf4bff5 (to debug the odd
performance numbers)

1a0cf26323c80e2f a308c71bf1e6e19cc2e4ced3185 da5ba9980aa2211c1e2a89fc814
8803d304738b52f66f6b683be38
---------------- --------------------------- ---------------------------
---------------------------
%stddev %change %stddev %change
%stddev %change %stddev
\ | \ | \
| \
3.406e+09 -95.6% 1.49e+08 -96.4% 1.213e+08
-96.5% 1.201e+08 stress-ng.vm-splice.ops
1.135e+08 -95.6% 4965911 -96.4% 4041777
-96.5% 4002572 stress-ng.vm-splice.ops_per_sec

>
> I'm not convinced that's a valid change in general, so this is just a
> "to debug the odd performance numbers" issue.
>
> Also out of curiosity: is the performance profile limited to just the
> load, or is it a system profile (ie do you have "-a" on the perf
> record line or not).
>

In our test , "-a" is enabled on the perf record line.

> Linus
>

--
Zhengjun Xing