[igt-dev] [PATCH i-g-t 3/4] runner: New test runner

[Petri Latvala]

On Mon, May 07, 2018 at 08:34:16PM +0200, Daniel Vetter wrote:
> On Mon, Apr 30, 2018 at 12:28:47PM +0300, Petri Latvala wrote:
> > This is a new test runner to replace piglit. Piglit has been very
> > useful as a test runner, but certain improvements have been very
> > difficult if possible at all in a generic test running framework.
> > 
> > Important improvements over piglit:
> > 
> > - Faster to launch. Being able to make assumptions about what we're
> >   executing makes it possible to save significant amounts of time. For
> >   example, a testlist file's line "igt at somebinary@somesubtest" already
> >   has all the information we need to construct the correct command
> >   line to execute that particular subtest, instead of listing all
> >   subtests of all test binaries and mapping them to command
> >   lines. Same goes for the regexp filters command line flags -t and
> >   -x; If we use -x somebinaryname, we don't need to list subtests from
> >   somebinaryname, we already know none of them will get executed.
> > 
> > - Logs of incomplete tests. Piglit collects test output to memory and
> >   dumps them to a file when the test is complete. The new runner
> >   writes all output to disk immediately.
> > 
> > - Ability to execute multiple subtests in one binary execution. This
> >   was possible with piglit, but its semantics made it very hard to
> >   implement in practice. For example, having a testlist file not only
> >   selected a subset of tests to run, but also mandated that they be
> >   executed in the same order.
> > 
> > - Flexible timeout support. Instead of mandating a time tests cannot
> >   exceed, the new runner has a timeout on inactivity. Activity is
> >   any output on the test's stdout or stderr, or kernel activity via
> >   /dev/kmsg.
> > 
> > The runner is fairly piglit compatible. The command line is very
> > similar, with a few additions. IGT_TEST_ROOT environment flag is still
> > supported, but can also be set via command line (in place of igt.py in
> > piglit command line).
> > 
> > The results are a set of log files, processed into a piglit-compatible
> > results.json file (BZ2 compression TODO). There are some new fields in
> > the json for extra information:
> > 
> > - "igt-version" contains the IGT version line. In
> >   multiple-subtests-mode the version information is only printed once,
> >   so it needs to be duplicated to all subtest results this way.
> > - "dmesg-warnings" contains the dmesg lines that triggered a
> >   dmesg-warn/dmesg-fail state.
> 
> Hm, I thought agreement was that if we do a new test runner then we
> definitely don't want it to capture&analyze dmesg? That's why I've
> originally done
> 
> https://patchwork.freedesktop.org/series/39263/
> 
> which you then took over. Is that still part of the overall plan, just not
> yet there?


That patch series is facing a deadend, albeit constructed with plywood
so could be punched through with enough violence used.

With the test itself monitoring /dev/kmsg and stuffing things to igt
log buffer, we get a race condition for capturing the last few kernel
messages before the test exits. That could be worked around by holding
the exit until we have read all of it (like this runner needs to do
anyway) but that means all tests incur an overhead at
exit. Considering we've been optimizing out milliseconds from test
runtimes...

Another problem is that just stuffing kernel messages to IGT log
buffer doesn't give any data for (automatic) processing of incomplete
tests, as the buffer is only dumped on a failure. Martin is eagerly
waiting for the ability to classify incompletes based on their dmesg.

Driver-specific dmesg filters are hard to do from the test
itself. Opening the driver happens at an arbitrary point in time, if
at all, an arbitrary amount of times.

Good news though is that we're able to do both styles of kmsg monitors
later on, active at the same time.


> -Daniel
> 
> > - Runtime information will be different. Piglit takes a timestamp at
> >   the beginning and at the end of execution for runtime. The new
> >   runner uses the subtest output text. The binary execution time will
> >   also be included; The key "igt at somebinary" will have the runtime of
> >   the binary "somebinary", whereas "igt at somebinary@a" etc will have
> >   the runtime of the subtests. Substracting the subtest runtimes from
> >   the binary runtime yields the total time spent doing setup in
> >   igt_fixture blocks.
> > 
> > Signed-off-by: Petri Latvala <petri.latvala at intel.com>
> > Cc: Maarten Lankhorst <maarten.lankhorst at linux.intel.com>
> > Cc: Arkadiusz Hiler <arkadiusz.hiler at intel.com>
> > Cc: Tomi Sarvela <tomi.p.sarvela at intel.com>
> > Cc: Martin Peres <martin.peres at linux.intel.com>
> > ---
> 
> [ snip]
> 
> > +/*
> > + * This regexp controls the kmsg handling. All kernel log records that
> > + * have log level of warning or higher convert the result to
> > + * dmesg-warn/dmesg-fail unless they match this regexp.
> > + */
> > +
> > +#define _ "|"
> > +static const char igt_dmesg_whitelist[] =
> > +	"ACPI: button: The lid device is not compliant to SW_LID" _
> > +	"ACPI: .*: Unable to dock!" _
> > +	"IRQ [0-9]+: no longer affine to CPU[0-9]+" _
> > +	"IRQ fixup: irq [0-9]+ move in progress, old vector [0-9]+" _
> > +	/* i915 tests set module options, expected message */
> > +	"Setting dangerous option [a-z_]+ - tainting kernel" _
> > +	/* Raw printk() call, uses default log level (warn) */
> > +	"Suspending console\\(s\\) \\(use no_console_suspend to debug\\)" _
> > +	"atkbd serio[0-9]+: Failed to (deactivate|enable) keyboard on isa[0-9]+/serio[0-9]+" _
> > +	"cache: parent cpu[0-9]+ should not be sleeping" _
> > +	"hpet[0-9]+: lost [0-9]+ rtc interrupts" _
> > +	/* i915 selftests terminate normally with ENODEV from the
> > +	 * module load after the testing finishes, which produces this
> > +	 * message.
> > +	 */
> > +	"i915: probe of [0-9:.]+ failed with error -25" _
> > +	/* swiotbl warns even when asked not to */
> > +	"mock: DMA: Out of SW-IOMMU space for [0-9]+ bytes" _
> > +	"usb usb[0-9]+: root hub lost power or was reset"
> 
> The above really isn't stuff we should have in the runner :-)

Yep, forgot a TODO. Those belong in general-suppressions.txt and
i915-suppressions.txt. Or tests/intel-ci/dmesg-suppressions.txt.


-- 
Petri Latvala