Re: [PATCH] oprofile-tests increase iterations for anon_remap test
Will Schmidt <[email protected]>
| Newsgroups | gmane.linux.oprofile |
|---|---|
| Message-ID | <[email protected]> |
On Tue, 2018-07-24 at 15:14 -0400, William Cohen wrote:
> On 07/24/2018 01:58 PM, Will Schmidt wrote:
> > On Tue, 2018-07-24 at 13:54 +0200, Michael Petlan wrote:
> >> Hi,
> >>
> >> I am afraid that this change causes the workload to time-out on slower systems.
> >>
> >> spawn -ignore SIGHUP rm -f /tmp/operf_run.VRlD
> >> spawn -ignore SIGHUP rm -f /tmp/operf_output.E0Bz
> >> spawn -ignore SIGHUP rm -f /tmp/operf_create_stop_script.dRZg
> >> spawn -ignore SIGHUP rm -f /tmp/operf_stop_operf.PSCD
> >> spawn -ignore SIGHUP hide ./oprofile_data
> >> spawn -ignore SIGHUP ophelp -r
> >> ppc64 POWER8
> >> spawn -ignore SIGHUP ls workloads/anon_remap_src/anon_remap_bin
> >> workloads/anon_remap_src/anon_remap_bin
> >> spawn -ignore SIGHUP operf --callgraph --lazy-conversion --events CYCLES:1500000:0:1:1, workloads/anon_remap_src/anon_remap_bin
> >> operf: Profiler started
> >> WARNING: program timed out.
> >> FAIL: operf check callgraph output: operf --callgraph --lazy-conversion --events CYCLES:1500000:0:1:1, workloads/anon_remap_src/anon_remap_bin
> >>
> >> Maybe 20000 could be enough, or we'd need to bump the timeout limit too.
> >> You did not encounter any timeout when testing this, did you?
> >
> > I did not.
> > I'd give preference to increasing the timeout, but I'm not opposed to
> > either option - backing the count down to 20k or increasing the timeout.
> > I still had some errors at 20k, but not as frequently as with the
> > original 2k value.
> >
> > Thanks,
> > -Will
> >
> >>
> >> Michael
> >>
> >> On Thu, 5 Jul 2018, Will Schmidt wrote:
> >>> Hi,
> >>>
> >>> We've noticed the anon_remap.c testcase failing on some of our systems.
> >>> From a verbose test run log, we note that the anon_remap_bin workload is
> >>> getting just a small number of the overall samples.
> >>> Results vary greatly depending on the system size and speed.
>
> Hi,
>
> I was thinking about this a bit more. I Look at the results that I
> got for a recent run on x86_64 and there are thousands of samples:
>
> CPU: Intel Skylake microarchitecture, speed 4000 MHz (estimated)
> Counted cpu_clk_unhalted events () with a unit mask of 0x00 (Core
> cycles when at least one thread on the physical core is not in halt
> state) count 2000003
> Counted inst_retired events () with a unit mask of 0x00 (Number of
> instructions retired. General Counter - architectural event) count
> 2000003
> samples % samples % image name app name
> symbol name
> 3781 50.5752 3499 48.3956 anon (tgid:19565
> range:0x7f00d3dc8000-0x7f00d51c9fff) /home/wcohen/research/profiling/oprofile/oprofile-tests/testsuite/workloads/anon_remap_src/anon_remap_bin anon (tgid:19565 range:0x7f00d3dc8000-0x7f00d51c9fff)
>
> However, for the below one almost all the sample are attributed to the
> kernel. That doesn't look correct. This is on ppc? What do things
> look like when using "perf record" and "perf report"? I wonder if
> there is some other issue that is causing the low number of asmples in
> the anon region. Could the perf subsystem be using some other value
> to mark anon regions on ppc? Could you give a bit more backgroun on
> the environment used to run the test, so others can replicate it?
Yes.
This was initially reported per testing results of rhel 7.5 on a (ppc)
power8 system. Subsequently reported from oprofile-test runs of rhel
7.* in power9 environments. I do not have the detailed system specs
recorded, but believe it was on the order of a 24core config running in
smt4 or smt8 mode.
After increasing the iteration values, per the patch that was submitted,
the debug report does indicate a healthy number of hits to the anon
region. Still a lot (majority) of samples in the kernel region.
> samples % image name app name symbol name
> 36247 87.9824 /no-vmlinux /no-vmlinux /no-vmlinux
> 4939 11.9884 anon (tgid:32357 range:0x100000270000-0x100001690000) /home/willschm/oprofile-tests/testsuite/workloads/anon_remap_src/anon_remap_bin anon (tgid:32357 range:0x100000270000-0x100001690000)
> 3 0.0073 /usr/bin/bash /usr/bin/bash /usr/bin/bash
And for reference the before numbers were reported as
> >>>> samples % app name symbol name
> >>>> 5031 99.7620 /no-vmlinux /no-vmlinux
> >>>> 5 0.0991 /usr/bin/bash /usr/bin/bash
> >>>> 1 0.0198 /home/willschm/oprofile-tests/testsuite/workloads/anon_remap_src/anon_remap_bin 00000017.plt_call.memcpy@@GLIBC_2.17
> >>>> 1 0.0198 /home/willschm/oprofile-tests/testsuite/workloads/anon_remap_src/anon_remap_bin initialize_anon_func
So with those numbers at hand, I would have expected that if things were
statistically flat, and just the testcase 'iter' value changing, we
should have seen a few hundred samples in the before numbers.
I am suspicious of a lucky/unlucky factor coming into play when trying
to hit the 'anon' region of a single threaded test on a many-processor
system like we've got here.
Running just the test against just operf (operf ./a.out ; opreport )
shows
samples| %|
------------------
3057771 99.8165 anon (tgid:16816 range:0x100000270000-0x10000168ffff)
4583 0.1496 kallsyms
823 0.0269 anon_remap_bin
190 0.0062 libc-2.17.so
...
so no obvious issue with detecting 'anon' sections there.
thanks
-Wm
> -Will
>
> >>>
> >>>> samples % app name symbol name
> >>>> 5031 99.7620 /no-vmlinux /no-vmlinux
> >>>> 5 0.0991 /usr/bin/bash /usr/bin/bash
> >>>> 1 0.0198 /home/willschm/oprofile-tests/testsuite/workloads/anon_remap_src/anon_remap_bin 00000017.plt_call.memcpy@@GLIBC_2.17
> >>>> 1 0.0198 /home/willschm/oprofile-tests/testsuite/workloads/anon_remap_src/anon_remap_bin initialize_anon_func
> >>>
> >>> The (anon_remap.c) testcase itself will take an argument to override the
> >>> default number of iterations, but as far as I can tell the test harness
> >>> does not handle passing arguments to the test itself.
> >>> I've instead increased the default iteration to a much higher
> >>> value, this seems sufficient to allow the test to pass.
> >>>
> >>> Signed-off-by: Will Schmidt <[email protected]>
> >>>
> >>> --
> >>>
> >>> anon_remap.c | 2 +-
> >>> 1 file changed, 1 insertion(+), 1 deletion(-)
> >>>
> >>>
> >>> diff --git a/testsuite/workloads/anon_remap_src/anon_remap.c b/testsuite/workloads/anon_remap_src/anon_remap.c
> >>> index 293476d..bbff472 100644
> >>> --- a/testsuite/workloads/anon_remap_src/anon_remap.c
> >>> +++ b/testsuite/workloads/anon_remap_src/anon_remap.c
> >>> @@ -102,11 +102,11 @@ main(int argc, char *argv[])
> >>> int iter_max;
> >>>
> >>> if (argc == 2)
> >>> iter_max = atoi(argv[1]);
> >>> else
> >>> - iter_max = 2000;
> >>> + iter_max = 40000;
> >>>
> >>> page_size = (size_t)sysconf(_SC_PAGESIZE);
> >>> initial_buffer_size = (MINIMUM_BUFFER_SIZE / page_size + 1) * page_size;
> >>> /* remapped_buffer_size must be larger than initial_buffer_size */
> >>> remapped_buffer_size = initial_buffer_size * 2;
> >>>
> >>>
> >>>
> >>> ------------------------------------------------------------------------------
> >>> Check out the vibrant tech community on one of the world's most
> >>> engaging tech sites, Slashdot.org! http://sdm.link/slashdot
> >>> _______________________________________________
> >>> oprofile-list mailing list
> >>> [email protected]
> >>> https://lists.sourceforge.net/lists/listinfo/oprofile-list
> >>>
> >>
> >
> >
> >
> > ------------------------------------------------------------------------------
> > Check out the vibrant tech community on one of the world's most
> > engaging tech sites, Slashdot.org! http://sdm.link/slashdot
> > _______________________________________________
> > oprofile-list mailing list
> > [email protected]
> > https://lists.sourceforge.net/lists/listinfo/oprofile-list
> >
>
------------------------------------------------------------------------------
Check out the vibrant tech community on one of the world's most
engaging tech sites, Slashdot.org! http://sdm.link/slashdot