[Intel-gfx] [PATCH i-g-t] Add dmesg capture and dumping to tests and a test for it.

[Joonas Lahtinen]

On ma, 2015-11-16 at 14:06 +0000, Chris Wilson wrote:
> On Mon, Nov 16, 2015 at 03:22:23PM +0200, Joonas Lahtinen wrote:
> > Cc: Thomas Wood <thomas.wood at intel.com>
> > Cc: Chris Wilson <chris at chris-wilson.co.uk>
> > Cc: Damien Lespiau <damien.lespiau at intel.com>
> > Signed-off-by: Joonas Lahtinen <joonas.lahtinen at linux.intel.com>
> > ---
> >  lib/igt_core.c         | 113
> > ++++++++++++++++++++++++++++++++++++++++++++++---
> >  tests/Makefile.sources |   1 +
> >  tests/igt_capture.c    |  93
> > ++++++++++++++++++++++++++++++++++++++++
> >  3 files changed, 200 insertions(+), 7 deletions(-)
> >  create mode 100644 tests/igt_capture.c
> > 
> > diff --git a/lib/igt_core.c b/lib/igt_core.c
> > index 04a0ab2..e73175a 100644
> > --- a/lib/igt_core.c
> > +++ b/lib/igt_core.c
> > @@ -211,6 +211,8 @@
> >   * "--help" command line option.
> >   */
> >  
> > +#define IGT_KMSG_CAPTURE_DUMP_BUF_SIZE		4096
> > +
> >  static unsigned int exit_handler_count;
> >  const char *igt_interactive_debug;
> >  
> > @@ -247,6 +249,10 @@ enum {
> >  static int igt_exitcode = IGT_EXIT_SUCCESS;
> >  static const char *command_str;
> >  
> > +static int igt_kmsg_capture_fd;
> > +static char* igt_kmsg_capture_dump_buf;
> > +static pthread_mutex_t kmsg_mutex = PTHREAD_MUTEX_INITIALIZER;
> > +
> >  static char* igt_log_domain_filter;
> >  static struct {
> >  	char *entries[256];
> > @@ -312,6 +318,71 @@ static void _igt_log_buffer_dump(void)
> >  	pthread_mutex_unlock(&log_buffer_mutex);
> >  }
> >  
> > +static void _igt_kmsg_capture_reset(void)
> > +{
> > +	if (igt_kmsg_capture_fd == -1)
> > +		return;
> > +
> > +	pthread_mutex_lock(&kmsg_mutex);
> > +
> > +	lseek(igt_kmsg_capture_fd, 0, SEEK_END);
> > +
> > +	pthread_mutex_unlock(&kmsg_mutex);
> > +}
> 
> Since close() is signal-safe, you can avoid the mutex (which is not
> signal-safe, but we can hope not to generate reentrancy here!) by
> opening /dev/kmsg for each subtest, and close it again in
> exit_subtest().
> 

I actually put the mutex around that block while it was still using
FILE*, when I was trying to cope with one open /dev/kmsg for reading
and writing for duration of the whole run, so it's a left over (it was
doing SEEK_CUR and storing that value etc.). Your suggestion sounds
cleaner.

> Note that we also want to detect dmesg spew during igt when the tests
> report all is well. Having the full log associated with a fail,
> preferrably with --debug is good, but filtering the <prio> for errors
> is
> also useful.

Yes, exactly what I was thinking too, because there were tests in the
SKL hang cases where the test would seem to run OK, but kmsg was full
of errors.

I wasn't sure if I should enable the kmsg logging with own command line
flag (or environment variable, like Thomas added for disabling colors)
or by default, as I am not exactly sure how many consumers we have that
try to parse the IGT outputs. It would be a breaking change there.

Maybe filtering the dmesg by locality kernel, and further with priority
and then displaying the log if there are warning or more serious output
during the test, in that case make the test fail and dump the kmsg? I
think this is also what piglit does (status DMESG fail), so add an own
return value for that, too.

Regards, Joonas

> -Chris
> 
-- 
Joonas Lahtinen
Open Source Technology Center
Intel Corporation