diff mbox

[RFC] lib: (somewhat) structured logging support

Message ID 1392214765-32469-1-git-send-email-daniel.vetter@ffwll.ch (mailing list archive)
State New, archived
Headers show

Commit Message

Daniel Vetter Feb. 12, 2014, 2:19 p.m. UTC
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@ffwll.ch>
---
 lib/drmtest.c | 41 +++++++++++++++++++++++++++++++++++++++++
 lib/drmtest.h | 27 +++++++++++++++++++++++++++
 2 files changed, 68 insertions(+)

Comments

Daniel Vetter Feb. 12, 2014, 2:44 p.m. UTC | #1
Forgotten to cc interested people ..
-Daniel

On Wed, Feb 12, 2014 at 3:19 PM, Daniel Vetter <daniel.vetter@ffwll.ch> wrote:
> 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@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
>
diff mbox

Patch

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)