[PATCH i-g-t 0/2] printing log messages on test failure

[PATCH i-g-t 0/2] printing log messages on test failure

[Thomas Wood]

This series replaces the earlier one dealing with printing recent log messages
and avoids any issues with signal handlers by only printing the log on a test
failure.

Thomas Wood (2):
  lib: add a ring buffer for log entries
  lib: print recent log messages to stderr when a test or subtest fails

 lib/Makefile.am |   3 +-
 lib/igt_core.c  | 112 +++++++++++++++++++++++++++++++++++++++++++++++++-------
 2 files changed, 100 insertions(+), 15 deletions(-)

-- 
2.1.0

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

[PATCH i-g-t 1/2] lib: add a ring buffer for log entries

[Thomas Wood]

Signed-off-by: Thomas Wood <thomas.wood@intel.com>
---
 lib/Makefile.am |  3 ++-
 lib/igt_core.c  | 72 ++++++++++++++++++++++++++++++++++++++++++++++++---------
 2 files changed, 63 insertions(+), 12 deletions(-)

diff --git a/lib/Makefile.am b/lib/Makefile.am
index 3826a1c..a5a4390 100644
--- a/lib/Makefile.am
+++ b/lib/Makefile.am
@@ -11,7 +11,8 @@ noinst_HEADERS = check-ndebug.h
 AM_CPPFLAGS = -I$(top_srcdir)
 AM_CFLAGS = $(DRM_CFLAGS) $(CWARNFLAGS)  \
 	    -DIGT_DATADIR=\""$(abs_top_srcdir)/tests"\" \
-	    -DIGT_LOG_DOMAIN=\""$(subst _,-,$*)"\"
+	    -DIGT_LOG_DOMAIN=\""$(subst _,-,$*)"\" \
+	    -pthread
 
 
 LDADD = $(CAIRO_LIBS)
diff --git a/lib/igt_core.c b/lib/igt_core.c
index 7b47b32..b03b7df 100644
--- a/lib/igt_core.c
+++ b/lib/igt_core.c
@@ -47,9 +47,8 @@
 #include <sys/types.h>
 #ifdef __linux__
 #include <sys/syscall.h>
-#else
-#include <pthread.h>
 #endif
+#include <pthread.h>
 #include <sys/utsname.h>
 #include <termios.h>
 #include <errno.h>
@@ -238,6 +237,35 @@ enum {
 };
 
 static char* igt_log_domain_filter;
+static struct {
+	char *entries[256];
+	uint8_t start, end;
+} log_buffer;
+static pthread_mutex_t log_buffer_mutex = PTHREAD_MUTEX_INITIALIZER;
+
+static void _igt_log_buffer_append(char *line)
+{
+	pthread_mutex_lock(&log_buffer_mutex);
+
+	free(log_buffer.entries[log_buffer.end]);
+	log_buffer.entries[log_buffer.end] = line;
+	log_buffer.end++;
+	if (log_buffer.end == log_buffer.start)
+		log_buffer.start++;
+
+	pthread_mutex_unlock(&log_buffer_mutex);
+}
+
+static void _igt_log_buffer_reset(void)
+{
+	pthread_mutex_lock(&log_buffer_mutex);
+
+	log_buffer.start = log_buffer.end = 0;
+
+	pthread_mutex_unlock(&log_buffer_mutex);
+}
+
+
 
 __attribute__((format(printf, 1, 2)))
 static void kmsg(const char *format, ...)
@@ -718,6 +746,8 @@ bool __igt_run_subtest(const char *subtest_name)
 
 	kmsg(KERN_INFO "%s: starting subtest %s\n", command_str, subtest_name);
 
+	_igt_log_buffer_reset();
+
 	gettime(&subtest_time);
 	return (in_subtest = subtest_name);
 }
@@ -1490,6 +1520,7 @@ void igt_log(const char *domain, enum igt_log_level level, const char *format, .
 void igt_vlog(const char *domain, enum igt_log_level level, const char *format, va_list args)
 {
 	FILE *file;
+	char *line, *formatted_line;
 	const char *program_name;
 	const char *igt_log_level_str[] = {
 		"DEBUG",
@@ -1510,18 +1541,33 @@ void igt_vlog(const char *domain, enum igt_log_level level, const char *format,
 	if (list_subtests)
 		return;
 
-	if (igt_log_level > level)
+	if (vasprintf(&line, format, args) == -1)
 		return;
 
+	if (asprintf(&formatted_line, "(%s:%d) %s%s%s: %s", program_name,
+		     getpid(), (domain) ? domain : "", (domain) ? "-" : "",
+		     igt_log_level_str[level], line) == -1) {
+		goto out;
+	}
+
+	/* append log buffer */
+	_igt_log_buffer_append(formatted_line);
+
+	/* check print log level */
+	if (igt_log_level > level)
+		goto out;
+
+	/* check domain filter */
 	if (igt_log_domain_filter) {
 		/* if null domain and filter is not "application", return */
 		if (!domain && strcmp(igt_log_domain_filter, "application"))
-			return;
+			goto out;
 		/* else if domain and filter do not match, return */
 		else if (domain && strcmp(igt_log_domain_filter, domain))
-			return;
+			goto out;
 	}
 
+	/* use stderr for warning messages and above */
 	if (level > IGT_LOG_WARN) {
 		file = stderr;
 		fflush(stdout);
@@ -1529,12 +1575,16 @@ void igt_vlog(const char *domain, enum igt_log_level level, const char *format,
 	else
 		file = stdout;
 
-	if (level != IGT_LOG_INFO) {
-		fprintf(file, "(%s:%d) %s%s%s: ", program_name, getpid(),
-			(domain) ? domain : "", (domain) ? "-" : "",
-			igt_log_level_str[level]);
-	}
-	vfprintf(file, format, args);
+	/* prepend all except information messages with process, domain and log
+	 * level information */
+	if (level != IGT_LOG_INFO)
+		fwrite(formatted_line, sizeof(char), strlen(formatted_line),
+		       file);
+	else
+		fwrite(line, sizeof(char), strlen(line), file);
+
+out:
+	free(line);
 }
 
 static void igt_alarm_handler(int signal)
-- 
2.1.0

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

[PATCH i-g-t 2/2] lib: print recent log messages to stderr when a test or subtest fails

[Thomas Wood]

Signed-off-by: Thomas Wood <thomas.wood@intel.com>
---
 lib/igt_core.c | 40 +++++++++++++++++++++++++++++++++++++---
 1 file changed, 37 insertions(+), 3 deletions(-)

diff --git a/lib/igt_core.c b/lib/igt_core.c
index b03b7df..596ab77 100644
--- a/lib/igt_core.c
+++ b/lib/igt_core.c
@@ -236,6 +236,9 @@ enum {
  OPT_HELP = 'h'
 };
 
+static int igt_exitcode = IGT_EXIT_SUCCESS;
+static const char *command_str;
+
 static char* igt_log_domain_filter;
 static struct {
 	char *entries[256];
@@ -265,7 +268,39 @@ static void _igt_log_buffer_reset(void)
 	pthread_mutex_unlock(&log_buffer_mutex);
 }
 
+static void _igt_log_buffer_dump(void)
+{
+	uint8_t i;
+
+	if (in_subtest)
+		fprintf(stderr, "Subtest %s failed.\n", in_subtest);
+	else
+		fprintf(stderr, "Test %s failed.\n", command_str);
+
+	if (log_buffer.start == log_buffer.end) {
+		fprintf(stderr, "No log.\n");
+		return;
+	}
+
+	pthread_mutex_lock(&log_buffer_mutex);
 
+	fprintf(stderr, "Log Start\n");
+
+	i = log_buffer.start;
+	do {
+		char *last_line = log_buffer.entries[i];
+		fprintf(stderr, "%s%s", last_line,
+			(last_line[strlen(last_line)-1] != '\n') ? "\n" : "");
+		i++;
+	} while (i != log_buffer.start && i != log_buffer.end);
+
+	/* reset the buffer */
+	log_buffer.start = log_buffer.end = 0;
+
+	pthread_mutex_unlock(&log_buffer_mutex);
+
+	fprintf(stderr, "Log End\n");
+}
 
 __attribute__((format(printf, 1, 2)))
 static void kmsg(const char *format, ...)
@@ -422,8 +457,6 @@ static void print_version(void)
 		uts.sysname, uts.release, uts.machine);
 }
 
-static const char *command_str;
-
 static void print_usage(const char *help_str, bool output_on_stderr)
 {
 	FILE *f = output_on_stderr ? stderr : stdout;
@@ -777,7 +810,6 @@ bool igt_only_list_subtests(void)
 static bool skipped_one = false;
 static bool succeeded_one = false;
 static bool failed_one = false;
-static int igt_exitcode = IGT_EXIT_SUCCESS;
 
 static void exit_subtest(const char *) __attribute__((noreturn));
 static void exit_subtest(const char *result)
@@ -910,6 +942,8 @@ void igt_fail(int exitcode)
 	if (test_child)
 		exit(exitcode);
 
+	_igt_log_buffer_dump();
+
 	if (in_subtest) {
 		if (exitcode == IGT_EXIT_TIMEOUT)
 			exit_subtest("TIMEOUT");
-- 
2.1.0

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