Re: [ata] 0568e61225: stress-ng.copy-file.ops_per_sec -15.0% regression

[Oliver Sang <oliver.sang@intel.com>]

[-- Attachment #1: Type: text/plain, Size: 7849 bytes --]

Hi John,

On Fri, Aug 12, 2022 at 12:13:20PM +0100, John Garry wrote:
> On 12/08/2022 06:01, Oliver Sang wrote:
> > hi, Damien Le Moal,
> > 
> > On Tue, Aug 09, 2022 at 07:55:53AM -0700, Damien Le Moal wrote:
> > > On 2022/08/09 2:58, John Garry wrote:
> > > > On 08/08/2022 15:52, Damien Le Moal wrote:
> > > > > On 2022/08/05 1:05, kernel test robot wrote:
> > > > > > 
> > > > > > 
> > > > > > Greeting,
> > > > > > 
> > > > > > FYI, we noticed a -15.0% regression of stress-ng.copy-file.ops_per_sec due to commit:
> > > > > > 
> > > > > > 
> > > > > > commit: 0568e6122574dcc1aded2979cd0245038efe22b6 ("ata: libata-scsi: cap ata_device->max_sectors according to shost->max_sectors")
> > > > > > 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: f2fs
> > > > > > 	class: filesystem
> > > > > > 	test: copy-file
> > > > > > 	cpufreq_governor: performance
> > > > > > 	ucode: 0xb000280
> > > > > 
> > > > > Without knowing what the device adapter is, hard to say where the problem is. I
> > > > > suspect that with the patch applied, we may be ending up with a small default
> > > > > max_sectors value, causing overhead due to more commands than necessary.
> > > > > 
> > > > > Will check what I see with my test rig.
> > > > 
> > > > As far as I can see, this patch should not make a difference unless the
> > > > ATA shost driver is setting the max_sectors value unnecessarily low.
> > > 
> > > That is my hunch too, hence my question about which host driver is being used
> > > for this test... That is not apparent from the problem report.
> > 
> > we noticed the commit is already in mainline now, and in our tests, there is
> > still similar regression and also on other platforms.
> > could you guide us how to check "which host driver is being used for this
> > test"? hope to supply some useful information.
> > 
> 
> For me, a complete kernel log may help.

dmesg.xz is attached. also attached dmesg from parent (4cbfca5f77)


> 
> > > 
> > > > 
> > > > > 
> > > > > > 
> > > > > > 
> > > > > > 
> > > > > > 
> > > > > > If you fix the issue, kindly add following tag
> > > > > > Reported-by: kernel test robot <oliver.sang@intel.com>
> > > > > > 
> > > > > > 
> > > > > > Details are as below:
> > > > > > -------------------------------------------------------------------------------------------------->
> > > > > > 
> > > > > > 
> > > > > > To reproduce:
> > > > > > 
> > > > > >           git clone https://github.com/intel/lkp-tests.git
> > > > > >           cd lkp-tests
> > > > > >           sudo bin/lkp install job.yaml           # job file is attached in this email
> > > > > >           bin/lkp split-job --compatible job.yaml # generate the yaml file for lkp run
> > > > > >           sudo bin/lkp run generated-yaml-file
> > > > > > 
> > > > > >           # if come across any failure that blocks the test,
> > > > > >           # please remove ~/.lkp and /lkp dir to run from a clean state.
> > > > > > 
> > > > > > =========================================================================================
> > > > > > class/compiler/cpufreq_governor/disk/fs/kconfig/nr_threads/rootfs/tbox_group/test/testcase/testtime/ucode:
> > > > > >     filesystem/gcc-11/performance/1HDD/f2fs/x86_64-rhel-8.3/10%/debian-11.1-x86_64-20220510.cgz/lkp-icl-2sp1/copy-file/stress-ng/60s/0xb000280
> > > > > > 
> > > > > > commit:
> > > > > >     4cbfca5f77 ("scsi: scsi_transport_sas: cap shost opt_sectors according to DMA optimal limit")
> > > > > >     0568e61225 ("ata: libata-scsi: cap ata_device->max_sectors according to shost->max_sectors")
> > > > > > 
> > > > > > 4cbfca5f7750520f 0568e6122574dcc1aded2979cd0
> > > > > > ---------------- ---------------------------
> > > > > >            %stddev     %change         %stddev
> > > > > >                \          |                \
> > > > > >         1627           -14.9%       1385        stress-ng.copy-file.ops
> > > > > >        27.01           -15.0%      22.96        stress-ng.copy-file.ops_per_sec
> > > > > >      8935079           -11.9%    7870629        stress-ng.time.file_system_outputs
> > > > > >        14.88 ±  5%     -31.8%      10.14 ±  3%  stress-ng.time.percent_of_cpu_this_job_got
> > > > > >        50912           -14.7%      43413        vmstat.io.bo
> > > > > >        93.78            +1.4%      95.10        iostat.cpu.idle
> > > > > >         3.89           -31.6%       2.66        iostat.cpu.iowait
> > > > > >         4.01            -1.3        2.74        mpstat.cpu.all.iowait%
> > > > > >         0.23 ±  9%      -0.1        0.17 ± 11%  mpstat.cpu.all.sys%
> > > > > >         1.66 ± 37%      -1.2        0.51 ± 55%  perf-profile.calltrace.cycles-pp.f2fs_write_end.generic_perform_write.f2fs_buffered_write_iter.f2fs_file_write_iter.do_iter_readv_writev
> > > > > >         1.66 ± 37%      -1.1        0.59 ± 25%  perf-profile.children.cycles-pp.f2fs_write_end
> > > > > >         1.51 ± 40%      -1.1        0.45 ± 26%  perf-profile.children.cycles-pp.f2fs_dirty_data_folio
> > > > > >         1.21 ± 49%      -1.0        0.23 ± 33%  perf-profile.children.cycles-pp.f2fs_update_dirty_folio
> > > > > >         0.88 ± 56%      -0.8        0.04 ±111%  perf-profile.children.cycles-pp.native_queued_spin_lock_slowpath
> > > > > >         0.14 ± 26%      +0.1        0.25 ± 28%  perf-profile.children.cycles-pp.page_cache_ra_unbounded
> > > > > >         0.88 ± 56%      -0.8        0.04 ±112%  perf-profile.self.cycles-pp.native_queued_spin_lock_slowpath
> > > > > >      3164876 ±  9%     -20.2%    2524713 ±  7%  perf-stat.i.cache-misses
> > > > > >    4.087e+08            -4.6%  3.899e+08        perf-stat.i.dTLB-loads
> > > > > >       313050 ± 10%     -18.4%     255410 ±  6%  perf-stat.i.node-loads
> > > > > >       972573 ±  9%     -16.4%     812873 ±  6%  perf-stat.i.node-stores
> > > > > >      3114748 ±  9%     -20.2%    2484807 ±  7%  perf-stat.ps.cache-misses
> > > > > >    4.022e+08            -4.6%  3.837e+08        perf-stat.ps.dTLB-loads
> > > > > >       308178 ± 10%     -18.4%     251418 ±  6%  perf-stat.ps.node-loads
> > > > > >       956996 ±  9%     -16.4%     799948 ±  6%  perf-stat.ps.node-stores
> > > > > >       358486            -8.3%     328694        proc-vmstat.nr_active_file
> > > > > >      1121620           -11.9%     987816        proc-vmstat.nr_dirtied
> > > > > >       179906            -6.7%     167912        proc-vmstat.nr_dirty
> > > > > >      1151201            -1.7%    1131322        proc-vmstat.nr_file_pages
> > > > > >       100181            +9.9%     110078 ±  2%  proc-vmstat.nr_inactive_file
> > > > > >       846362           -14.6%     722471        proc-vmstat.nr_written
> > > > > >       358486            -8.3%     328694        proc-vmstat.nr_zone_active_file
> > > > > >       100181            +9.9%     110078 ±  2%  proc-vmstat.nr_zone_inactive_file
> > > > > >       180668            -6.8%     168456        proc-vmstat.nr_zone_write_pending
> > > > > >       556469            -3.5%     536985        proc-vmstat.pgactivate
> > > > > >      3385454           -14.6%    2889953        proc-vmstat.pgpgout
> > > > > > 
> > > > > > 
> > > > > > 
> > > > > > 
> > > > > > 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.
> > > > > > 
> > > > > > 
> > > > > 
> > > > > 
> > > > 
> > > 
> > > 
> > > -- 
> > > Damien Le Moal
> > > Western Digital Research
> > .
> 

[-- Attachment #2: dmesg.xz --]
[-- Type: application/x-xz, Size: 30176 bytes --]

[-- Attachment #3: dmesg-parent.xz --]
[-- Type: application/x-xz, Size: 30880 bytes --]