[PATCH i-g-t v4] lib/igt_core: Add kmsg capture and dumping

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

Capture the output from /dev/kmsg during test execution independantly
of other concurrent watchers like Piglit test runner.

The captured output is analyzed and the whole output dumped if message
with priority LOG_WARNING or higher is emitted from any domain.

Also adding igt_capture to lib/tests which will fail subtests and
produce kmsg output which should be captured by the new code.

v4:
- Do not effect return value of test, just dump (Daniel)

v3:
- Use O_CLOEXEC and clarify hex decoding (Chris)

v2:
- Reopen/close the kmsg FD per each test (Chris)
- Better commit mesage (Daniel)
- Display failure due to kmsg only as FAIL (KMSG)

Cc: Thomas Wood <thomas.wood@intel.com>
Cc: Chris Wilson <chris@chris-wilson.co.uk>
Cc: Damien Lespiau <damien.lespiau@intel.com>
Cc: Daniel Vetter <daniel.vetter@ffwll.ch>
Acked-by: Daniel Vetter <daniel.vetter@ffwll.ch>
Signed-off-by: Joonas Lahtinen <joonas.lahtinen@linux.intel.com>
---
 lib/igt_core.c             | 129 +++++++++++++++++++++++++++++++++++++++++++--
 lib/tests/.gitignore       |   1 +
 lib/tests/Makefile.sources |   2 +
 lib/tests/igt_capture.c    |  89 +++++++++++++++++++++++++++++++
 4 files changed, 218 insertions(+), 3 deletions(-)
 create mode 100644 lib/tests/igt_capture.c

diff --git a/lib/igt_core.c b/lib/igt_core.c
index 84cf8d2..b1aa750 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_DUMP_BUF_SIZE		4096
+
 static unsigned int exit_handler_count;
 const char *igt_interactive_debug;
 
@@ -248,6 +251,10 @@ enum {
 static int igt_exitcode = IGT_EXIT_SUCCESS;
 static const char *command_str;
 
+static int igt_kmsg_capture_fd = -1;
+static int igt_kmsg_check_fd = -1;
+static char* igt_kmsg_dump_buf = NULL;
+
 static char* igt_log_domain_filter;
 static struct {
 	char *entries[256];
@@ -313,6 +320,112 @@ static void _igt_log_buffer_dump(void)
 	pthread_mutex_unlock(&log_buffer_mutex);
 }
 
+static void _igt_kmsg_reset(void)
+{
+	if (igt_kmsg_dump_buf == NULL)
+		igt_kmsg_dump_buf = malloc(IGT_KMSG_DUMP_BUF_SIZE);
+
+	if (igt_kmsg_dump_buf == NULL) {
+		igt_warn("Unable to allocate memory, "
+			 "can not dump kmsg.\n");
+		return;
+	}
+
+	if (igt_kmsg_capture_fd == -1)
+		igt_kmsg_capture_fd = open("/dev/kmsg",
+					   O_RDONLY | O_NONBLOCK | O_CLOEXEC);
+
+	if (igt_kmsg_capture_fd == -1)
+		goto err_capture;
+
+	if (igt_kmsg_check_fd == -1)
+		igt_kmsg_check_fd = open("/dev/kmsg",
+					 O_RDONLY | O_NONBLOCK | O_CLOEXEC);
+
+	if (igt_kmsg_check_fd == -1)
+		goto err_check;
+
+	lseek(igt_kmsg_capture_fd, 0, SEEK_END);
+	lseek(igt_kmsg_check_fd, 0, SEEK_END);
+	return;
+
+err_check:
+	close(igt_kmsg_capture_fd);
+	igt_kmsg_capture_fd = -1;
+err_capture:
+	free(igt_kmsg_dump_buf);
+	igt_kmsg_dump_buf = NULL;
+	return;
+}
+
+static int _igt_kmsg_dump(bool print, int filter_priority)
+{
+	size_t nbytes;
+	int nlines;
+	int prefix;
+	int priority;
+	char *p;
+	int fd;
+
+	fd = print ? igt_kmsg_capture_fd : igt_kmsg_check_fd;
+	if (fd == -1)
+		return 0;
+
+	nlines = 0;
+	do {
+		errno = 0;
+		nbytes = read(fd, igt_kmsg_dump_buf, IGT_KMSG_DUMP_BUF_SIZE);
+
+		if (nbytes == -1)
+			continue;
+
+		sscanf(igt_kmsg_dump_buf, "%d;", &prefix);
+		priority = prefix & 0x7;
+
+		if (priority > filter_priority)
+			continue;
+
+		nlines++;
+
+		if (!print)
+			continue;
+
+		if (nlines == 1)
+			fprintf(stderr, "**** KMSG ****\n");
+
+		p = strchr(igt_kmsg_dump_buf, ';') + 1;
+		while (p - igt_kmsg_dump_buf < nbytes) {
+			int c = *p++;
+			/* Decode non-printable characters escaped in
+			 * hex form (\x0f). */
+			if (c == '\\') {
+				igt_assert(*p++ == 'x');
+				igt_assert(sscanf(p, "%x", &c) == 1);
+				p += 2;
+			}
+			fputc(c, stderr);
+		}
+	} while(errno == 0);
+
+	if (print && nlines)
+		fprintf(stderr, "****  END  ****\n");
+
+	if (errno != EAGAIN)
+		fprintf(stderr, "Error: Incomplete kmsg!\n");
+
+	close(fd);
+
+	if (print) {
+		igt_kmsg_capture_fd = -1;
+		free(igt_kmsg_dump_buf);
+		igt_kmsg_dump_buf = NULL;
+	} else {
+		igt_kmsg_check_fd = -1;
+	}
+
+	return nlines;
+}
+
 __attribute__((format(printf, 1, 2)))
 static void kmsg(const char *format, ...)
 #define KERN_EMER	"<0>"
@@ -712,8 +825,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_reset();
+	}
 
 	for (i = 0; (optind + i) < *argc; i++)
 		argv[i + 1] = argv[optind + i];
@@ -832,8 +947,9 @@ bool __igt_run_subtest(const char *subtest_name)
 	igt_debug("Starting subtest: %s\n", subtest_name);
 
 	_igt_log_buffer_reset();
-
+	_igt_kmsg_reset();
 	gettime(&subtest_time);
+
 	return (in_subtest = subtest_name);
 }
 
@@ -963,6 +1079,9 @@ void __igt_skip_check(const char *file, const int line,
  */
 void igt_success(void)
 {
+	if (_igt_kmsg_dump(false, LOG_WARNING))
+		_igt_kmsg_dump(true, LOG_DEBUG);
+
 	succeeded_one = true;
 	if (in_subtest)
 		exit_subtest("SUCCESS");
@@ -1005,6 +1124,11 @@ void igt_fail(int exitcode)
 
 	_igt_log_buffer_dump();
 
+	/* Show kmsg if not already shown. */
+	if (_igt_kmsg_dump(true, LOG_DEBUG) < 1)
+		fprintf(stderr, "No kmsg.\n");
+
+
 	if (in_subtest) {
 		if (exitcode == IGT_EXIT_TIMEOUT)
 			exit_subtest("TIMEOUT");
@@ -1111,7 +1235,6 @@ void igt_exit(void)
 		exit(IGT_EXIT_INVALID);
 	}
 
-
 	if (igt_only_list_subtests())
 		exit(IGT_EXIT_SUCCESS);
 
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..6506baf 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 \
@@ -32,4 +33,5 @@ XFAIL_TESTS = \
 	igt_simple_test_subtests \
 	igt_timeout \
 	igt_invalid_subtest_name \
+	igt_capture \
 	$(NULL)
diff --git a/lib/tests/igt_capture.c b/lib/tests/igt_capture.c
new file mode 100644
index 0000000..28ffce1
--- /dev/null
+++ b/lib/tests/igt_capture.c
@@ -0,0 +1,89 @@
+/*
+ * 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>
+#include <syslog.h>
+
+static FILE* kmsg;
+
+static void
+test_kmsg(bool fail)
+{
+	fprintf(kmsg, "<%d>TEST (KMSG)\n", LOG_WARNING);
+	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);
+	}
+}
-- 
2.4.3

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