[Intel-gfx] [PATCH] [RFC] lib: (somewhat) structured logging support

[Daniel Vetter]

Apparently there's a bit a need for more verbose output in testcases,
mostly for debugging purposes. At least gem_reset_stats and pm_rps
have a verbose mode.

On top of that we're currently not taking advantage of piglit's "warn"
state all that much. But I think it might be useful for testcases which
are notorious for some kinds of spurious failures, like e.g. the really
nasty timing checks in kms_flip. If we demote some of them to just
warnings we could run the overall tests more often.

Hence this patchs adds a new igt_log function with the three levels DEBUG,
INFO and WARN. Plus a bunch of convenience helpers to keep the test
code tidy.

The level can be set through an enviroment vairable IGT_LOG_LEVEL with
info being the default. Also tests can look at the selected log level in
case they want to run costly debug functions only when needed.

Comments highly welcome, I plan to roll this out over tests which can
use it (not all, imo that's too much churn) once we've settled on the
interfaces/semantics.

Signed-off-by: Daniel Vetter <daniel.vetter at ffwll.ch>
---
 lib/drmtest.c | 41 +++++++++++++++++++++++++++++++++++++++++
 lib/drmtest.h | 27 +++++++++++++++++++++++++++
 2 files changed, 68 insertions(+)

diff --git a/lib/drmtest.c b/lib/drmtest.c
index 46227c35cc8f..9f6e701fdfb6 100644
--- a/lib/drmtest.c
+++ b/lib/drmtest.c
@@ -937,6 +937,25 @@ out:
 	return ret;
 }
 
+enum igt_log_level igt_log_level = IGT_LOG_INFO;
+
+static void common_init(void)
+{
+	char *env = getenv("IGT_LOG_LEVEL");
+
+	if (!env)
+		return;
+
+	if (strcmp(env, "debug") == 0)
+		igt_log_level = IGT_LOG_DEBUG;
+	else if (strcmp(env, "info") == 0)
+		igt_log_level = IGT_LOG_INFO;
+	else if (strcmp(env, "warn") == 0)
+		igt_log_level = IGT_LOG_WARN;
+	else if (strcmp(env, "none") == 0)
+		igt_log_level = IGT_LOG_NONE;
+}
+
 void igt_subtest_init(int argc, char **argv)
 {
 	int ret;
@@ -951,11 +970,15 @@ void igt_subtest_init(int argc, char **argv)
 
 	/* reset opt parsing */
 	optind = 1;
+
+	common_init();
 }
 
 void igt_simple_init(void)
 {
 	print_version();
+
+	common_init();
 }
 
 /*
@@ -1387,6 +1410,24 @@ void igt_skip_on_simulation(void)
 	igt_require(!igt_run_in_simulation());
 }
 
+void igt_log(enum igt_log_level level, const char *format, ...)
+{
+	va_list args;
+
+	assert(format);
+
+	if (igt_log_level > level)
+		return;
+
+	va_start(args, format);
+	if (level == IGT_LOG_WARN) {
+		fflush(stdout);
+		vfprintf(stderr, format, args);
+	} else
+		vprintf(format, args);
+	va_end(args);
+}
+
 bool drmtest_dump_aub(void)
 {
 	static int dump_aub = -1;
diff --git a/lib/drmtest.h b/lib/drmtest.h
index c03983295393..b64529b69643 100644
--- a/lib/drmtest.h
+++ b/lib/drmtest.h
@@ -294,6 +294,33 @@ void igt_wait_helper(struct igt_helper_process *proc);
 #define igt_fork_helper(proc) \
 	for (; __igt_fork_helper(proc); exit(0))
 
+/* logging support */
+enum igt_log_level {
+	IGT_LOG_DEBUG,
+	IGT_LOG_INFO,
+	IGT_LOG_WARN,
+	IGT_LOG_NONE,
+};
+__attribute__((format(printf, 2, 3)))
+void igt_log(enum igt_log_level level, const char *format, ...);
+#define igt_debug(f...) igt_log(IGT_LOG_DEBUG, f)
+#define igt_info(f...) igt_log(IGT_LOG_INFO, f)
+#define igt_warn(f...) igt_log(IGT_LOG_WARN, f)
+extern enum igt_log_level igt_log_level;
+
+#define igt_warn_on(condition) do {\
+		if (condition) \
+			igt_warn("Warning on condition %s in fucntion %s, file %s:%i\n", \
+				 #condition, __func__, __FILE__, __LINE__); \
+	} while (0)
+#define igt_warn_on_f(condition, f...) do {\
+		if (condition) {\
+			igt_warn("Warning on condition %s in fucntion %s, file %s:%i\n", \
+				 #condition, __func__, __FILE__, __LINE__); \
+			igt_warn(f); \
+		} \
+	} while (0)
+
 /* check functions which auto-skip tests by calling igt_skip() */
 void gem_require_caching(int fd);
 static inline void gem_require_ring(int fd, int ring_id)
-- 
1.8.1.4