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

[Joonas Lahtinen <joonas.lahtinen@linux.intel.com>]

On ke, 2015-11-18 at 17:41 +0000, Thomas Wood wrote:
> On 18 November 2015 at 15:44, Daniel Vetter <daniel@ffwll.ch> wrote:
> > On Mon, Nov 16, 2015 at 03:22:23PM +0200, Joonas Lahtinen wrote:
> > > Cc: Thomas Wood <thomas.wood@intel.com>
> > > Cc: Chris Wilson <chris@chris-wilson.co.uk>
> > > Cc: Damien Lespiau <damien.lespiau@intel.com>
> > > Signed-off-by: Joonas Lahtinen <joonas.lahtinen@linux.intel.com>
> > 
> > Given that we have all that in piglit already the commit message is
> > a bit
> > thin on justification. Why do we need this in igt too? How does
> > this
> > interact with the piglit dmesg capture?
> 

In short, it makes IGT be able to run the tests on its own with only
small additions to the current code, and the output can then be parsed
with piglit outside of the DUT. I will add a canonical option to
produce a CSV-like output. It's just about moving a small bit of the
test running logic to IGT to make it produce meaningful output on its
own.

> There are a few tests that rely on checking dmesg to determine if the
> test failed (such as gem_hangcheck_forcewake and
> kms_flip_event_leak).
> Although not implemented in this patch, it might be useful to use
> this
> feature to actually report a failure in those cases.
> 

Next version makes any test fail if kernel domain messages with
priority LOG_NOTICE or higher are output during test.

Regards, Joonas

> 
> > 
> > > ---
> > >  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);
> > > +}
> > > +
> > > +static void _igt_kmsg_capture_dump(void)
> > > +{
> > > +     size_t nbytes;
> > > +     int nlines;
> > > +     char *p;
> > > +     char *p0;
> > > +     int c;
> > > +
> > > +     if (igt_kmsg_capture_fd == -1 ||
> > > +         igt_kmsg_capture_dump_buf == NULL)
> > > +             return;
> > > +
> > > +     pthread_mutex_lock(&kmsg_mutex);
> > > +
> > > +
> > > +     nlines = 0;
> > > +     do {
> > > +             errno = 0;
> > > +             nbytes = read(igt_kmsg_capture_fd,
> > > +                           igt_kmsg_capture_dump_buf,
> > > +                           IGT_KMSG_CAPTURE_DUMP_BUF_SIZE);
> > > +
> > > +             if (nbytes == -1)
> > > +                     continue;
> > > +
> > > +             if (!nlines)
> > > +                     fprintf(stderr, "**** KMSG ****\n");
> > > +
> > > +             p = p0 = strchr(igt_kmsg_capture_dump_buf, ';') +
> > > 1;
> > > +             while (p - p0 < nbytes) {
> > > +                     if (*p != '\\') {
> > > +                             fputc(*p++, stderr);
> > > +                             continue;
> > > +                     }
> > > +                     sscanf(p, "\\x%x", &c);
> > > +                     fputc(c, stderr);
> > > +                     p += 4;
> > > +             }
> > > +             //fputs(strchr(igt_kmsg_capture_dump_buf, ';') + 1,
> > > stderr);
> > > +             nlines++;
> > > +     } while(errno == 0);
> > > +
> > > +     if (nlines)
> > > +             fprintf(stderr, "****  END  ****\n");
> > > +     else
> > > +             fprintf(stderr, "No kmsg.\n");
> > > +
> > > +     if (errno != EAGAIN)
> > > +             fprintf(stderr, "Incomplete kmsg.\n");
> > > +
> > > +     pthread_mutex_unlock(&kmsg_mutex);
> > > +}
> > > +
> > >  __attribute__((format(printf, 1, 2)))
> > >  static void kmsg(const char *format, ...)
> > >  #define KERN_EMER    "<0>"
> > > @@ -330,11 +401,15 @@ static void kmsg(const char *format, ...)
> > >       if (file == NULL)
> > >               return;
> > > 
> > > +     pthread_mutex_lock(&kmsg_mutex);
> > > +
> > >       va_start(ap, format);
> > >       vfprintf(file, format, ap);
> > >       va_end(ap);
> > > 
> > >       fclose(file);
> > > +
> > > +     pthread_mutex_unlock(&kmsg_mutex);
> > >  }
> > > 
> > >  static void gettime(struct timespec *ts)
> > > @@ -527,6 +602,15 @@ static int common_init(int *argc, char
> > > **argv,
> > >       int ret = 0;
> > >       const char *env;
> > > 
> > > +     igt_kmsg_capture_fd = open("/dev/kmsg", O_RDWR |
> > > O_NONBLOCK);
> > > +     if (igt_kmsg_capture_fd != -1) {
> > > +             igt_kmsg_capture_dump_buf =
> > > +                     malloc(IGT_KMSG_CAPTURE_DUMP_BUF_SIZE);
> > > +             if(igt_kmsg_capture_dump_buf == NULL)
> > > +                     igt_warn("Unable to allocate memory, "
> > > +                              "will not dump kmsg.\n");
> > > +     }
> > > +
> > >       if (!isatty(STDOUT_FILENO) || getenv("IGT_PLAIN_OUTPUT"))
> > >               __igt_plain_output = true;
> > > 
> > > @@ -796,6 +880,7 @@ bool __igt_run_subtest(const char
> > > *subtest_name)
> > >       igt_debug("Starting subtest: %s\n", subtest_name);
> > > 
> > >       _igt_log_buffer_reset();
> > > +     _igt_kmsg_capture_reset();
> > > 
> > >       gettime(&subtest_time);
> > >       return (in_subtest = subtest_name);
> > > @@ -972,6 +1057,7 @@ void igt_fail(int exitcode)
> > >               exit(exitcode);
> > > 
> > >       _igt_log_buffer_dump();
> > > +     _igt_kmsg_capture_dump();
> > > 
> > >       if (in_subtest) {
> > >               if (exitcode == IGT_EXIT_TIMEOUT)
> > > @@ -1072,16 +1158,21 @@ void __igt_fail_assert(const char
> > > *domain, const char *file, const int line,
> > >   */
> > >  void igt_exit(void)
> > >  {
> > > +     int status = IGT_EXIT_SUCCESS;
> > > +
> > >       igt_exit_called = true;
> > > 
> > >       if (run_single_subtest && !run_single_subtest_found) {
> > >               igt_warn("Unknown subtest: %s\n",
> > > run_single_subtest);
> > > -             exit(IGT_EXIT_INVALID);
> > > +             status = IGT_EXIT_INVALID;
> > > +             goto do_exit;
> > >       }
> > > 
> > > 
> > > -     if (igt_only_list_subtests())
> > > -             exit(IGT_EXIT_SUCCESS);
> > > +     if (igt_only_list_subtests()) {
> > > +             status = IGT_EXIT_SUCCESS;
> > > +             goto do_exit;
> > > +     }
> > > 
> > >       kmsg(KERN_INFO "%s: exiting, ret=%d\n", command_str,
> > > igt_exitcode);
> > >       igt_debug("Exiting with status code %d\n", igt_exitcode);
> > > @@ -1111,18 +1202,26 @@ void igt_exit(void)
> > > 
> > > 
> > >               printf("%s (%.3fs)\n", result, elapsed);
> > > -             exit(igt_exitcode);
> > > +             status = igt_exitcode;
> > > +             goto do_exit;
> > >       }
> > > 
> > >       /* Calling this without calling one of the above is a
> > > failure */
> > >       assert(skipped_one || succeeded_one || failed_one);
> > > 
> > >       if (failed_one)
> > > -             exit(igt_exitcode);
> > > +             status = igt_exitcode;
> > >       else if (succeeded_one)
> > > -             exit(IGT_EXIT_SUCCESS);
> > > +             status = IGT_EXIT_SUCCESS;
> > >       else
> > > -             exit(IGT_EXIT_SKIP);
> > > +             status = IGT_EXIT_SKIP;
> > > +do_exit:
> > > +     if (igt_kmsg_capture_fd != -1)
> > > +             close(igt_kmsg_capture_fd);
> > > +     if (igt_kmsg_capture_dump_buf != NULL)
> > > +             free(igt_kmsg_capture_dump_buf);
> > > +
> > > +     exit(status);
> > >  }
> > > 
> > >  /* fork support code */
> > > diff --git a/tests/Makefile.sources b/tests/Makefile.sources
> > > index 8fb2de8..25f0c4a 100644
> > > --- a/tests/Makefile.sources
> > > +++ b/tests/Makefile.sources
> > > @@ -62,6 +62,7 @@ TESTS_progs_M = \
> > >       gem_tiled_partial_pwrite_pread \
> > >       gem_userptr_blits \
> > >       gem_write_read_ring_switch \
> > > +     igt_capture \
> > >       kms_addfb_basic \
> > >       kms_atomic \
> > >       kms_cursor_crc \
> > > diff --git a/tests/igt_capture.c b/tests/igt_capture.c
> > > new file mode 100644
> > > index 0000000..fd008d0
> > > --- /dev/null
> > > +++ b/tests/igt_capture.c
> > > @@ -0,0 +1,93 @@
> > > +/*
> > > + * Copyright © 2015 Intel Corporation
> > > + *
> > > + * Permission is hereby granted, free of charge, to any person
> > > obtaining a
> > > + * copy of this software and associated documentation files (the
> > > "Software"),
> > > + * to deal in the Software without restriction, including
> > > without limitation
> > > + * the rights to use, copy, modify, merge, publish, distribute,
> > > sublicense,
> > > + * and/or sell copies of the Software, and to permit persons to
> > > whom the
> > > + * Software is furnished to do so, subject to the following
> > > conditions:
> > > + *
> > > + * The above copyright notice and this permission notice
> > > (including the next
> > > + * paragraph) shall be included in all copies or substantial
> > > portions of the
> > > + * Software.
> > > + *
> > > + * THE SOFTWARE IS PROVIDED "AS IS", WITHOUT WARRANTY OF ANY
> > > KIND, EXPRESS OR
> > > + * IMPLIED, INCLUDING BUT NOT LIMITED TO THE WARRANTIES OF
> > > MERCHANTABILITY,
> > > + * FITNESS FOR A PARTICULAR PURPOSE AND NONINFRINGEMENT.  IN NO
> > > EVENT SHALL
> > > + * THE AUTHORS OR COPYRIGHT HOLDERS BE LIABLE FOR ANY CLAIM,
> > > DAMAGES OR OTHER
> > > + * LIABILITY, WHETHER IN AN ACTION OF CONTRACT, TORT OR
> > > OTHERWISE, ARISING
> > > + * FROM, OUT OF OR IN CONNECTION WITH THE SOFTWARE OR THE USE OR
> > > OTHER DEALINGS
> > > + * IN THE SOFTWARE.
> > > + *
> > > + * Authors:
> > > + *    Joonas Lahtinen <joonas.lahtinen@linux.intel.com>
> > > + *
> > > + */
> > > +
> > > +#include "igt.h"
> > > +#include <unistd.h>
> > > +#include <stdlib.h>
> > > +#include <stdio.h>
> > > +#include <string.h>
> > > +#include <fcntl.h>
> > > +#include <inttypes.h>
> > > +#include <errno.h>
> > > +#include <sys/stat.h>
> > > +#include <sys/ioctl.h>
> > > +
> > > +static FILE* kmsg;
> > > +
> > > +static void
> > > +test_kmsg(void)
> > > +{
> > > +     fputs("TEST (KMSG)\n", kmsg);
> > > +     fflush(kmsg);
> > > +     igt_fail(IGT_EXIT_FAILURE);
> > > +}
> > > +
> > > +static void
> > > +test_warn(void)
> > > +{
> > > +     igt_warn("TEST (WARN)\n");
> > > +     igt_fail(IGT_EXIT_FAILURE);
> > > +}
> > > +
> > > +static void
> > > +test_debug(void)
> > > +{
> > > +     igt_debug("TEST (DEBUG)\n");
> > > +     igt_fail(IGT_EXIT_FAILURE);
> > > +}
> > > +
> > > +static void
> > > +test_combined(void)
> > > +{
> > > +     igt_warn("TEST #1 (WARN)\n");
> > > +     fputs("TEST #1\n", kmsg);
> > > +     igt_warn("TEST #2 (WARN)\n");
> > > +     fputs("TEST #2\n", kmsg);
> > > +     fflush(kmsg);
> > > +     igt_fail(IGT_EXIT_FAILURE);
> > > +}
> > > +
> > > +igt_main
> > > +{
> > > +     igt_fixture {
> > > +             kmsg = fopen("/dev/kmsg", "w");
> > > +             igt_require(kmsg != NULL);
> > > +     }
> > > +
> > > +     igt_subtest("kmsg")
> > > +             test_kmsg();
> > > +     igt_subtest("warn")
> > > +             test_warn();
> > > +     igt_subtest("debug")
> > > +             test_debug();
> > > +     igt_subtest("combined")
> > > +             test_combined();
> > > +
> > > +     igt_fixture {
> > > +             fclose(kmsg);
> > > +     }
> > > +}
> > > --
> > > 2.4.3
> > > 
> > > _______________________________________________
> > > Intel-gfx mailing list
> > > Intel-gfx@lists.freedesktop.org
> > > http://lists.freedesktop.org/mailman/listinfo/intel-gfx
> > 
> > --
> > Daniel Vetter
> > Software Engineer, Intel Corporation
> > http://blog.ffwll.ch
-- 
Joonas Lahtinen
Open Source Technology Center
Intel Corporation

_______________________________________________
Intel-gfx mailing list
Intel-gfx@lists.freedesktop.org
http://lists.freedesktop.org/mailman/listinfo/intel-gfx