Message ID | 1447929323-19370-1-git-send-email-joonas.lahtinen@linux.intel.com (mailing list archive) |
---|---|
State | New, archived |
Headers | show |
On Thu, Nov 19, 2015 at 12:35:23PM +0200, Joonas Lahtinen wrote: > +static void _igt_kmsg_capture_reset(void) > +{ > + if (igt_kmsg_capture_fd != -1) > + close(igt_kmsg_capture_fd); > + > + igt_kmsg_capture_fd = open("/dev/kmsg", > + O_RDONLY | O_NONBLOCK); We should O_CLOEXEC as well. > + > + if (igt_kmsg_capture_fd == -1) > + return; > + > + lseek(igt_kmsg_capture_fd, 0, SEEK_END); > + > + if (igt_kmsg_capture_dump_buf == NULL) > + 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 we allocate first, then bail, we know if we have the fd we have the buffer as well. > +} > + > +static int _igt_kmsg_capture_dump(bool notify_empty, int show_priority) > +{ > + size_t nbytes; > + int nlines; > + int prefix; > + int facility; > + int priority; > + char *p; > + int c; > + > + if (igt_kmsg_capture_fd == -1 || > + igt_kmsg_capture_dump_buf == NULL) > + return 0; i.e. we can just do if (fd == -1) return 0; > + > + 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; > + > + sscanf(igt_kmsg_capture_dump_buf, "%d;", &prefix); > + priority = prefix & 0x7; > + > + if (priority > show_priority) > + continue; > + > + if (!nlines) > + fprintf(stderr, "**** KMSG ****\n"); > + > + p = strchr(igt_kmsg_capture_dump_buf, ';') + 1; > + while (p - igt_kmsg_capture_dump_buf < nbytes) { > + if (*p != '\\') { > + fputc(*p++, stderr); > + continue; > + } > + sscanf(p, "\\x%x", &c); > + fputc(c, stderr); > + p += 4; Maybe: /* Decode non-printable characters escaped by '\x01' */ int c = *p++; if (c == '\\') { if (p - igt_kmgs_capture_dump_buf > nbytes - 3) break; sscanf(p+1, "%x", &c); p += 3; } fputc(c, stderr); > + } > + nlines++; > + } while(errno == 0); > + > + if (nlines) { > + fprintf(stderr, "**** END ****\n"); > + } else { > + if (notify_empty) > + fprintf(stderr, "No kmsg.\n"); > + } > + > + if (errno != EAGAIN) > + fprintf(stderr, "Error: Incomplete kmsg!\n"); > + > + close(igt_kmsg_capture_fd); > + igt_kmsg_capture_fd = -1; > + > + free(igt_kmsg_capture_dump_buf); > + igt_kmsg_capture_dump_buf = NULL; Hmm, single-shot. I have in mind more of an automatic debug feature coupled with error detection like how we automatically go back and print the debug log if the test fails. As I understand it, with a FAIL (KMSG) we currently lose any lower priority output. The integration looks good to me otherwise. But someone else will have to vouch for test-runner/piglit handling of "FAIL (KMSG)" (I used WARN). -Chris
On to, 2015-11-19 at 11:32 +0000, Chris Wilson wrote: > On Thu, Nov 19, 2015 at 12:35:23PM +0200, Joonas Lahtinen wrote: > > +static void _igt_kmsg_capture_reset(void) > > +{ > > + if (igt_kmsg_capture_fd != -1) > > + close(igt_kmsg_capture_fd); > > + > > + igt_kmsg_capture_fd = open("/dev/kmsg", > > + O_RDONLY | O_NONBLOCK); > > We should O_CLOEXEC as well. > Fixed. > > + > > + if (igt_kmsg_capture_fd == -1) > > + return; > > + > > + lseek(igt_kmsg_capture_fd, 0, SEEK_END); > > + > > + if (igt_kmsg_capture_dump_buf == NULL) > > + 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 we allocate first, then bail, we know if we have the fd we have > the > buffer as well. > I was thinking we would still perform as much of the actions that would be done if we were able to dump the kmsg, for consistency. That is why the buffer allocation is handled separately. But maybe it's bit overkill. > > +} > > + > > +static int _igt_kmsg_capture_dump(bool notify_empty, int > > show_priority) > > +{ > > + size_t nbytes; > > + int nlines; > > + int prefix; > > + int facility; > > + int priority; > > + char *p; > > + int c; > > + > > + if (igt_kmsg_capture_fd == -1 || > > + igt_kmsg_capture_dump_buf == NULL) > > + return 0; > > i.e. we can just do if (fd == -1) return 0; > > > + > > + 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; > > + > > + sscanf(igt_kmsg_capture_dump_buf, "%d;", &prefix); > > + priority = prefix & 0x7; > > + > > + if (priority > show_priority) > > + continue; > > + > > + if (!nlines) > > + fprintf(stderr, "**** KMSG ****\n"); > > + > > + p = strchr(igt_kmsg_capture_dump_buf, ';') + 1; > > + while (p - igt_kmsg_capture_dump_buf < nbytes) { > > + if (*p != '\\') { > > + fputc(*p++, stderr); > > + continue; > > + } > > + sscanf(p, "\\x%x", &c); > > + fputc(c, stderr); > > + p += 4; > > Maybe: > /* Decode non-printable characters escaped by '\x01' */ > int c = *p++; > if (c == '\\') { > if (p - igt_kmgs_capture_dump_buf > nbytes - 3) > break; > sscanf(p+1, "%x", &c); > p += 3; > } > fputc(c, stderr); > I'll simplify this bit. > > + } > > + nlines++; > > + } while(errno == 0); > > + > > + if (nlines) { > > + fprintf(stderr, "**** END ****\n"); > > + } else { > > + if (notify_empty) > > + fprintf(stderr, "No kmsg.\n"); > > + } > > + > > + if (errno != EAGAIN) > > + fprintf(stderr, "Error: Incomplete kmsg!\n"); > > + > > + close(igt_kmsg_capture_fd); > > + igt_kmsg_capture_fd = -1; > > + > > + free(igt_kmsg_capture_dump_buf); > > + igt_kmsg_capture_dump_buf = NULL; > > Hmm, single-shot. > > I have in mind more of an automatic debug feature coupled with error > detection like how we automatically go back and print the debug log > if > the test fails. As I understand it, with a FAIL (KMSG) we currently > lose > any lower priority output. > Yeah, unless we allocate buffers and store when we start reading, it has to be dumped as we read. This also causes the one thing I don't like in the current implementation is that the KMSG appears before the debug output. The /dev/kmsg doesn't want to be seeked (even the documentation states that, attempted that initially regardless), so our only option is to allocate buffers dynamically or estimate maximum buffer size and go with that. > The integration looks good to me otherwise. But someone else will > have > to vouch for test-runner/piglit handling of "FAIL (KMSG)" (I used > WARN). I think we could make NOTICE and WARN cause WARN (KMSG) and rest a FAIL (KMSG) ? Regards, Joonas > -Chris >
diff --git a/lib/igt_core.c b/lib/igt_core.c index 04a0ab2..cb782dc 100644 --- a/lib/igt_core.c +++ b/lib/igt_core.c @@ -43,6 +43,7 @@ #include <getopt.h> #include <stdlib.h> #include <unistd.h> +#include <syslog.h> #include <sys/wait.h> #include <sys/types.h> #ifdef __linux__ @@ -211,6 +212,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 +250,9 @@ enum { static int igt_exitcode = IGT_EXIT_SUCCESS; static const char *command_str; +static int igt_kmsg_capture_fd = -1; +static char* igt_kmsg_capture_dump_buf = NULL; + static char* igt_log_domain_filter; static struct { char *entries[256]; @@ -312,6 +318,93 @@ 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) + close(igt_kmsg_capture_fd); + + igt_kmsg_capture_fd = open("/dev/kmsg", + O_RDONLY | O_NONBLOCK); + + if (igt_kmsg_capture_fd == -1) + return; + + lseek(igt_kmsg_capture_fd, 0, SEEK_END); + + if (igt_kmsg_capture_dump_buf == NULL) + 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"); +} + +static int _igt_kmsg_capture_dump(bool notify_empty, int show_priority) +{ + size_t nbytes; + int nlines; + int prefix; + int facility; + int priority; + char *p; + int c; + + if (igt_kmsg_capture_fd == -1 || + igt_kmsg_capture_dump_buf == NULL) + return 0; + + 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; + + sscanf(igt_kmsg_capture_dump_buf, "%d;", &prefix); + priority = prefix & 0x7; + + if (priority > show_priority) + continue; + + if (!nlines) + fprintf(stderr, "**** KMSG ****\n"); + + p = strchr(igt_kmsg_capture_dump_buf, ';') + 1; + while (p - igt_kmsg_capture_dump_buf < nbytes) { + if (*p != '\\') { + fputc(*p++, stderr); + continue; + } + sscanf(p, "\\x%x", &c); + fputc(c, stderr); + p += 4; + } + nlines++; + } while(errno == 0); + + if (nlines) { + fprintf(stderr, "**** END ****\n"); + } else { + if (notify_empty) + fprintf(stderr, "No kmsg.\n"); + } + + if (errno != EAGAIN) + fprintf(stderr, "Error: Incomplete kmsg!\n"); + + close(igt_kmsg_capture_fd); + igt_kmsg_capture_fd = -1; + + free(igt_kmsg_capture_dump_buf); + igt_kmsg_capture_dump_buf = NULL; + + return nlines; +} + __attribute__((format(printf, 1, 2))) static void kmsg(const char *format, ...) #define KERN_EMER "<0>" @@ -676,8 +769,10 @@ out: /* install exit handler, to ensure we clean up */ igt_install_exit_handler(common_exit_handler); - if (!test_with_subtests) + if (!test_with_subtests) { gettime(&subtest_time); + _igt_kmsg_capture_reset(); + } for (i = 0; (optind + i) < *argc; i++) argv[i + 1] = argv[optind + i]; @@ -796,8 +891,9 @@ 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); } @@ -931,6 +1027,9 @@ void __igt_skip_check(const char *file, const int line, */ void igt_success(void) { + if (_igt_kmsg_capture_dump(false, LOG_NOTICE)) + return igt_fail(IGT_EXIT_FAILURE_KMSG); + succeeded_one = true; if (in_subtest) exit_subtest("SUCCESS"); @@ -971,11 +1070,17 @@ void igt_fail(int exitcode) if (test_child) exit(exitcode); + /* Show kmsg if not already shown. */ + if (exitcode != IGT_EXIT_FAILURE_KMSG) + _igt_kmsg_capture_dump(true, LOG_DEBUG); + _igt_log_buffer_dump(); if (in_subtest) { if (exitcode == IGT_EXIT_TIMEOUT) exit_subtest("TIMEOUT"); + else if (exitcode == IGT_EXIT_FAILURE_KMSG) + exit_subtest("FAIL (KMSG)"); else exit_subtest("FAIL"); } else { @@ -1079,7 +1184,6 @@ void igt_exit(void) exit(IGT_EXIT_INVALID); } - if (igt_only_list_subtests()) exit(IGT_EXIT_SUCCESS); @@ -1105,6 +1209,9 @@ void igt_exit(void) case IGT_EXIT_SKIP: result = "SKIP"; break; + case IGT_EXIT_FAILURE_KMSG: + result = "FAIL (KMSG)"; + break; default: result = "FAIL"; } diff --git a/lib/igt_core.h b/lib/igt_core.h index a244fc3..3a9f41b 100644 --- a/lib/igt_core.h +++ b/lib/igt_core.h @@ -93,6 +93,13 @@ extern bool __igt_plain_output; */ #define IGT_EXIT_FAILURE 99 +/** + * IGT_EXIT_FAILURE_KMSG + * + * Exit status indicing printk warnings/errors during test + */ +#define IGT_EXIT_FAILURE_KMSG 98 + bool __igt_fixture(void); void __igt_fixture_complete(void); void __igt_fixture_end(void) __attribute__((noreturn)); diff --git a/lib/tests/.gitignore b/lib/tests/.gitignore index a4f1080..c49c178 100644 --- a/lib/tests/.gitignore +++ b/lib/tests/.gitignore @@ -1,5 +1,6 @@ # Please keep sorted alphabetically igt_assert +igt_capture igt_fork_helper igt_invalid_subtest_name igt_list_only diff --git a/lib/tests/Makefile.sources b/lib/tests/Makefile.sources index 777b9c1..d2b5e08 100644 --- a/lib/tests/Makefile.sources +++ b/lib/tests/Makefile.sources @@ -1,4 +1,5 @@ check_PROGRAMS = \ + igt_capture \ igt_no_exit \ igt_no_exit_list_only \ igt_fork_helper \ diff --git a/lib/tests/igt_capture.c b/lib/tests/igt_capture.c new file mode 100644 index 0000000..3a9c528 --- /dev/null +++ b/lib/tests/igt_capture.c @@ -0,0 +1,88 @@ +/* + * 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_core.h" +#include <stdio.h> + +static FILE* kmsg; + +static void +test_kmsg(bool fail) +{ + fputs("TEST (KMSG)\n", kmsg); + fflush(kmsg); + if (fail) + 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(true); + igt_subtest("kmsg-success") + test_kmsg(false); + igt_subtest("warn") + test_warn(); + igt_subtest("debug") + test_debug(); + igt_subtest("combined") + test_combined(); + + igt_fixture { + fclose(kmsg); + } +}