[LTP] [PATCH V3] lib: multiply the max_runtime if detect slow kconfigs

[Li Wang]

On Mon, Dec 16, 2024 at 9:00 PM Cyril Hrubis <chrubis@suse.cz> wrote:

> Hi!
> > > +   TST_KCONFIG_INIT("CONFIG_KASAN"),
> > > +   TST_KCONFIG_INIT("CONFIG_SLUB_RCU_DEBUG"),
> > > +   TST_KCONFIG_INIT("CONFIG_TRACE_IRQFLAGS"),
> > > +   TST_KCONFIG_INIT("CONFIG_LATENCYTOP"),
> > > +   TST_KCONFIG_INIT("CONFIG_DEBUG_NET"),
> > > +   TST_KCONFIG_INIT("CONFIG_EXT4_DEBUG"),
> > > +   TST_KCONFIG_INIT("CONFIG_QUOTA_DEBUG"),
> > > +   TST_KCONFIG_INIT("CONFIG_FAULT_INJECTION"),
> > > +   TST_KCONFIG_INIT("CONFIG_DEBUG_OBJECTS")
> > > +};
> > > +
> > > +int tst_has_slow_kconfig(void)
> > > +{
> > > +   unsigned int i;
> > > +
> > > +   tst_kconfig_read(slow_kconfigs, ARRAY_SIZE(slow_kconfigs));
> > > +
> > Maybe here TINFO message "checking for options which slow the execution?
> > Or print it (once) only if option detected? Because it's not obvious why
> we are
> > detecting it. Or after searching print what we did (4x prolonged
> runtime).
> >
> > > +   for (i = 0; i < ARRAY_SIZE(slow_kconfigs); i++) {
> > > +           if (slow_kconfigs[i].choice == 'y') {
> > > +                   tst_res(TINFO,
> > > +                           "%s kernel option detected",
> > > +                           slow_kconfigs[i].id);
> > > +                   return 1;
> > > +           }
> > > +   }
> > > +
> > > +   return 0;
> > > +}
> > > diff --git a/lib/tst_test.c b/lib/tst_test.c
> > > index 8db554dea..f4e667240 100644
> > > --- a/lib/tst_test.c
> > > +++ b/lib/tst_test.c
> > > @@ -555,6 +555,9 @@ static int multiply_runtime(int max_runtime)
> >
> > >     parse_mul(&runtime_mul, "LTP_RUNTIME_MUL", 0.0099, 100);
> >
> > > +   if (tst_has_slow_kconfig())
> > > +           max_runtime *= 4;
> > Maybe note here what we do? (TINFO)
>
> That really depends on how verbose we want to be, we already print the
> overall test timeout which is timeout + runtime. So it's somehow visible
> in the test runtime has been increased. Maybe we should make the info
> message in set_timeout() better by printing the runtime separately there
> if non-zero.
>

You mean we add one line print for the max_runtime separately?
That might be so verbose that sometimes the test invokes
tst_set_max_runtime()it will print twice in the logs.

# ./starvation
tst_tmpdir.c:316: TINFO: Using /tmp/LTP_staVoNT4a as tmpdir (xfs filesystem)
tst_test.c:1896: TINFO: LTP version: 20240930
tst_test.c:1900: TINFO: Tested kernel:
5.14.0-539.5812_1580643863.el9.x86_64 #1 SMP PREEMPT_DYNAMIC Mon Dec 9
18:03:26 UTC 2024 x86_64
tst_test.c:1731: TINFO: Timeout per run is 0h 00m 30s
starvation.c:98: TINFO: Setting affinity to CPU 0
starvation.c:52: TINFO: CPU did 120000000 loops in 75292us
tst_kconfig.c:88: TINFO: Parsing kernel config
'/lib/modules/5.14.0-539.5812_1580643863.el9.x86_64/build/.config'
tst_test.c:1739: TINFO: Updating max runtime to 0h 01m 15s
tst_test.c:1729: TINFO: Max_runtime is set to 75 seconds
tst_test.c:1731: TINFO: Timeout per run is 0h 01m 45s
starvation.c:150: TPASS: Haven't reproduced scheduller starvation.

Summary:
passed   1
failed   0
broken   0
skipped  0
warnings 0



-- 
Regards,
Li Wang