make unittests less verbose

Right now, the unittests are verbose and produce a lot of outputs. This
makes it difficult to debug them.

This patch sets different levels of logging: debug, info, warning and
error. By default, debug messages aren't showed anymore. That way, it
will be easier to see when something actually goes wrong in a test.

It's possible to display them again by setting the environment variable
UTC_MIN_LOG to DEBUG

Reviewed by: a1.gomes, hh4813.kim, sns.park

Change-Id: I6f4e8d61ff5ec24eaccec5240d3fa106edd8ff7c
Signed-off-by: Arnaud Renevier <a.renevier@samsung.com>

diff --git a/tizen_src/ewk/unittest/utc_blink_ewk_base.cpp b/tizen_src/ewk/unittest/utc_blink_ewk_base.cpp
index 1c266c5..7922356 100644 (file)
--- a/tizen_src/ewk/unittest/utc_blink_ewk_base.cpp
+++ b/tizen_src/ewk/unittest/utc_blink_ewk_base.cpp
@@ -59,7 +59,7 @@ std::string utc_blink_ewk_base::GetResourcePath(const char* resource_path) const
 bool utc_blink_ewk_base::CompareEvasImageWithResource(Evas_Object* image, const char* resource, int pixel_fuzziness) const
 {
   if (!image || !resource) {
-    utc_message("[CompareEvasImageWithResource] :: both image and resource can't be NULL");
+    utc_warning("[CompareEvasImageWithResource] :: both image and resource can't be NULL");
     return false;
   }
   std::string resource_absolute_path = GetResourcePath(resource);
@@ -75,13 +75,13 @@ bool utc_blink_ewk_base::CompareEvasImageWithResource(Evas_Object* image, const
 
   if (resource_w != image_w || resource_h != image_h) {
     evas_object_del(resource_image);
-    utc_message("[CompareEvasImageWithResource] :: image size differs: %dx%d (image) vs %dx%d (resource)", image_w, image_h, resource_w, resource_h);
+    utc_warning("[CompareEvasImageWithResource] :: image size differs: %dx%d (image) vs %dx%d (resource)", image_w, image_h, resource_w, resource_h);
     return false;
   }
 
   if (evas_object_image_colorspace_get(image) != evas_object_image_colorspace_get(resource_image)) {
     evas_object_del(resource_image);
-    utc_message("[CompareEvasImageWithResource] :: image colorspace differs");
+    utc_warning("[CompareEvasImageWithResource] :: image colorspace differs");
     return false;
   }
 
@@ -102,7 +102,7 @@ bool utc_blink_ewk_base::CompareEvasImageWithResource(Evas_Object* image, const
 
     default:
       evas_object_del(resource_image);
-      utc_message("[CompareEvasImageWithResource] :: unsupported colorspace");
+      utc_warning("[CompareEvasImageWithResource] :: unsupported colorspace");
       return false;
   }
 
@@ -122,11 +122,11 @@ bool utc_blink_ewk_base::CompareEvasImageWithResource(Evas_Object* image, const
     }
 
     if (total_diff > pixel_fuzziness) {
-      utc_message("[CompareEvasImageWithResource] :: maximum fuzziness (%d) exceeded at %d pixel: %d", pixel_fuzziness, i, total_diff);
+      utc_warning("[CompareEvasImageWithResource] :: maximum fuzziness (%d) exceeded at %d pixel: %d", pixel_fuzziness, i, total_diff);
       retval = false;
 
       for (int j = 0; j < bytes_per_pixel; ++j) {
-        utc_message("image: 0x%2X resource: 0x%2X", image_data[i + j], resource_data[i + j]);
+        utc_info("image: 0x%2X resource: 0x%2X", image_data[i + j], resource_data[i + j]);
       }
 
       break;
@@ -144,7 +144,7 @@ std::string utc_blink_ewk_base::GetResourceUrl(const char* resource_path) const
 {
     std::string retval("file://");
     retval.append(GetResourcePath(resource_path));
-    utc_message("Resource:\t\"%s\"",retval.c_str());
+    utc_debug("Resource:\t\"%s\"",retval.c_str());
     return retval;
 }
 
@@ -155,7 +155,7 @@ utc_blink_ewk_base::MainLoopResult utc_blink_ewk_base::EventLoopStart(double max
     if (!main_loop_running) {
         main_loop_result = utc_blink_ewk_base::NoOp;
 
-        utc_message("[EventLoopStart] :: timeout: %f", max_time);
+        utc_debug("[EventLoopStart] :: timeout: %f", max_time);
         main_loop_running = true;
         timeout = ecore_timer_add(max_time, timeout_cb, this);
         ecore_main_loop_begin();
@@ -175,7 +175,7 @@ utc_blink_ewk_base::MainLoopResult utc_blink_ewk_base::EventLoopStart(double max
 bool utc_blink_ewk_base::EventLoopWait(double time)
 {
     if (!main_loop_running) {
-        utc_message("[EventLoopWait] :: time %f", time);
+        utc_debug("[EventLoopWait] :: time %f", time);
         main_loop_running = true;
         timeout = ecore_timer_add(time, timeout_cb_event_loop_wait, this);
 
@@ -196,7 +196,7 @@ bool utc_blink_ewk_base::EventLoopWait(double time)
 bool utc_blink_ewk_base::EventLoopStop(utc_blink_ewk_base::MainLoopResult result)
 {
     if (main_loop_running && result != utc_blink_ewk_base::NoOp ) {
-        utc_message("[EventLoopStop] :: Setting result to: %s", (result == utc_blink_ewk_base::Success ? "Success" : "Failure"));
+        utc_debug("[EventLoopStop] :: Setting result to: %s", (result == utc_blink_ewk_base::Success ? "Success" : "Failure"));
         main_loop_running = false;
         main_loop_result = result;
         ecore_main_loop_quit();
@@ -242,33 +242,33 @@ void utc_blink_ewk_base::TearDown()
 
 void utc_blink_ewk_base::load_started_cb(void* data, Evas_Object* webview, void* event_info)
 {
-    utc_message("[load,started] :: data: %p, webview: %p, event_info: %p", data, webview, event_info);
+    utc_debug("[load,started] :: data: %p, webview: %p, event_info: %p", data, webview, event_info);
     utc_blink_ewk_base *ut = static_cast<utc_blink_ewk_base*>(data);
     ut->LoadStarted(webview);
 }
 
 void utc_blink_ewk_base::load_finished_cb(void* data, Evas_Object* webview, void* event_info)
 {
-    utc_message("[load,finished] :: data: %p, webview: %p, event_info: %p", data, webview, event_info);
+    utc_debug("[load,finished] :: data: %p, webview: %p, event_info: %p", data, webview, event_info);
     utc_blink_ewk_base *ut = static_cast<utc_blink_ewk_base*>(data);
     ut->LoadFinished(webview);
 }
 
 void utc_blink_ewk_base::load_error_cb(void* data, Evas_Object* webview, void* event_info)
 {
-    utc_message("[load,error] :: data: %p, webview: %p, event_info: %p", data, webview, event_info);
+    utc_debug("[load,error] :: data: %p, webview: %p, event_info: %p", data, webview, event_info);
     utc_blink_ewk_base *ut = static_cast<utc_blink_ewk_base*>(data);
     Ewk_Error *err = static_cast<Ewk_Error *>(event_info);
 
     if(!ut->LoadError(webview, err)) {
-        utc_message("[load,error] :: not handled by test, stopping main loop with Failure");
+        utc_warning("[load,error] :: not handled by test, stopping main loop with Failure");
         ut->EventLoopStop(utc_blink_ewk_base::Failure);
     }
 }
 
 void utc_blink_ewk_base::load_progress_cb(void* data, Evas_Object* webview, void* event_info)
 {
-    utc_message("[load,progress] :: data: %p, webview: %p, event_info: %p", data, webview, event_info);
+    utc_debug("[load,progress] :: data: %p, webview: %p, event_info: %p", data, webview, event_info);
     double progress = -1.0;
     if (event_info) {
         progress = *((double*)event_info);
@@ -280,14 +280,14 @@ void utc_blink_ewk_base::load_progress_cb(void* data, Evas_Object* webview, void
 
 void utc_blink_ewk_base::load_progress_started_cb(void* data, Evas_Object* webview, void* event_info)
 {
-    utc_message("[load,progress,started] :: data: %p, webview: %p, event_info: %p", data, webview, event_info);
+    utc_debug("[load,progress,started] :: data: %p, webview: %p, event_info: %p", data, webview, event_info);
     utc_blink_ewk_base *ut = static_cast<utc_blink_ewk_base*>(data);
     ut->LoadProgressStarted(webview);
 }
 
 void utc_blink_ewk_base::load_progress_finished_cb(void* data, Evas_Object* webview, void* event_info)
 {
-    utc_message("[load,progress,finished] :: data: %p, webview: %p, event_info: %p", data, webview, event_info);
+    utc_debug("[load,progress,finished] :: data: %p, webview: %p, event_info: %p", data, webview, event_info);
     utc_blink_ewk_base *ut = static_cast<utc_blink_ewk_base*>(data);
     ut->LoadProgressFinished(webview);
 }
@@ -296,7 +296,7 @@ void utc_blink_ewk_base::ConsoleMessage(Evas_Object*webview, const Ewk_Console_M
 {
   EXPECT_EQ(ewk_webview, webview);
   if (log_javascript)
-    utc_message("JavaScript::console (%p):\t\"%s\"", webview, ewk_console_message_text_get(msg));
+    fprintf(stdout, "JavaScript::console (%p):\t\"%s\"", webview, ewk_console_message_text_get(msg));
 }
 
 void utc_blink_ewk_base::console_message_cb(utc_blink_ewk_base* owner, Evas_Object* webview, Ewk_Console_Message* console)
@@ -307,11 +307,11 @@ void utc_blink_ewk_base::console_message_cb(utc_blink_ewk_base* owner, Evas_Obje
 
 Eina_Bool utc_blink_ewk_base::timeout_cb(void *data)
 {
-    utc_message("[timeout] :: data: %p", data);
+    utc_debug("[timeout] :: data: %p", data);
     utc_blink_ewk_base *ut = static_cast<utc_blink_ewk_base*>(data);
 
     if (!ut->TimeOut()) {
-        utc_message("[timeout] :: not handled by test, stopping main loop with Failure");
+        utc_warning("[timeout] :: not handled by test, stopping main loop with Failure");
         ut->EventLoopStop(utc_blink_ewk_base::Timeout);
     }
 
@@ -330,7 +330,7 @@ Eina_Bool utc_blink_ewk_base::timeout_cb_event_loop_wait(void *data)
 void utc_blink_ewk_base::EwkInit()
 {
     /* 1. Standard TETware test initialization message */
-    utc_message("[[ TET_MSG ]]:: ============ Startup ============");
+    utc_info("[[ TET_MSG ]]:: ============ Startup ============");
 
     ewk_window = elm_win_add(NULL, "TC Launcher", ELM_WIN_BASIC);
     elm_win_title_set(ewk_window, "TC Launcher");
@@ -358,7 +358,7 @@ void utc_blink_ewk_base::EwkInit()
 void utc_blink_ewk_base::EwkDeinit()
 {
     /* 1. Standard TETware test end/cleanup messages */
-    utc_message("[[ TET_MSG ]]:: ============ Cleanup ============");
+    utc_info("[[ TET_MSG ]]:: ============ Cleanup ============");
 
     /* 2. Freeing resources */
     if (ewk_webview)
@@ -373,3 +373,27 @@ void utc_blink_ewk_base::EwkDeinit()
     ewk_webview = NULL;
 }
 
+void utc_log(UtcLogSeverity severity, const char* format, ...) {
+  static UtcLogSeverity minLogSeverity = -1;
+  if (minLogSeverity == -1) {
+    char *env_severity = getenv("UTC_MIN_LOG");
+    if (env_severity && !strcmp(env_severity, "DEBUG")) {
+      minLogSeverity = UTC_LOG_DEBUG;
+    } else if (env_severity && !strcmp(env_severity, "INFO")) {
+      minLogSeverity = UTC_LOG_INFO;
+    } else if (env_severity && !strcmp(env_severity, "WARNING")) {
+      minLogSeverity = UTC_LOG_WARNING;
+    } else if (env_severity && !strcmp(env_severity, "ERROR")) {
+      minLogSeverity = UTC_LOG_ERROR;
+    } else {
+      minLogSeverity = UTC_LOG_INFO;
+    }
+  }
+  if (minLogSeverity > severity)
+    return;
+
+  va_list arglist;
+  va_start(arglist, format);
+  vfprintf(stderr, format, arglist );
+  va_end(arglist);
+}

diff --git a/tizen_src/ewk/unittest/utc_blink_ewk_base.h b/tizen_src/ewk/unittest/utc_blink_ewk_base.h
index 0b14fb4..8a5bae6 100644 (file)
--- a/tizen_src/ewk/unittest/utc_blink_ewk_base.h
+++ b/tizen_src/ewk/unittest/utc_blink_ewk_base.h
@@ -59,8 +59,6 @@
 /* Definitions and macros */
 #define DEFAULT_WIDTH_OF_WINDOW 480
 #define DEFAULT_HEIGHT_OF_WINDOW 800
-/* User macros */
-#define utc_message(msg, ...) fprintf(stderr, msg "\n", ##__VA_ARGS__)
 
 /* Compatibility macros only. Please use gtest macros instead. This will be removed. */
 #define utc_check_true(condition) EXPECT_TRUE(condition)
@@ -84,6 +82,21 @@
 #define utc_pass() SUCCEED()
 #define utc_fail() FAIL()
 
+
+typedef int UtcLogSeverity;
+const UtcLogSeverity UTC_LOG_DEBUG = 0;
+const UtcLogSeverity UTC_LOG_INFO = 1;
+const UtcLogSeverity UTC_LOG_WARNING = 2;
+const UtcLogSeverity UTC_LOG_ERROR = 3;
+void utc_log(UtcLogSeverity severity, const char* msg, ...);
+/* User macros */
+#define utc_debug(msg, ...) utc_log(UTC_LOG_DEBUG, msg "\n", ##__VA_ARGS__)
+#define utc_info(msg, ...) utc_log(UTC_LOG_INFO, msg "\n", ##__VA_ARGS__)
+#define utc_warning(msg, ...) utc_log(UTC_LOG_WARNING, msg "\n", ##__VA_ARGS__)
+#define utc_error(msg, ...) utc_log(UTC_LOG_ERROR, msg "\n", ##__VA_ARGS__)
+
+#define utc_message utc_warning
+
 class utc_blink_ewk_base: public ::testing::Test
 {
 public: