Add debug message macros controlled by environment variable

Add a HMI_DEBUG macro to print debug messages.
It is controlled by the USE_HMI_DEBUG environment variable.

Change-Id: I3bc5bf2f3b0e9f5ee06f340053f29ad36e7d9dbb
Signed-off-by: Yuta Doi <yuta-d@witz-inc.co.jp>

8 files changed, 150 insertions, 93 deletions

diff --git a/include/hmi-debug.h b/include/hmi-debug.h
new file mode 100644
index 0000000..e6a34cf
--- /dev/null
+++ b/include/hmi-debug.h
@@ -0,0 +1,50 @@
+#ifndef __HMI_DEBUG_H__
+#define __HMI_DEBUG_H__
+
+#include <time.h>
+#include <stdio.h>
+#include <afb/afb-binding.h>
+
+enum LOG_LEVEL{
+    LOG_LEVEL_NONE = 0,
+    LOG_LEVEL_ERROR,
+    LOG_LEVEL_WARNING,
+    LOG_LEVEL_NOTICE,
+    LOG_LEVEL_INFO,
+    LOG_LEVEL_DEBUG,
+    LOG_LEVEL_MAX = LOG_LEVEL_ERROR
+};
+
+#define HMI_ERROR(prefix, args,...) _HMI_LOG(LOG_LEVEL_ERROR, __FILE__, __FUNCTION__, __LINE__, prefix, args, ##__VA_ARGS__)
+#define HMI_WARNING(prefix, args,...) _HMI_LOG(LOG_LEVEL_WARNING, __FILE__, __FUNCTION__,__LINE__, prefix, args,##__VA_ARGS__)
+#define HMI_NOTICE(prefix, args,...) _HMI_LOG(LOG_LEVEL_NOTICE, __FILE__, __FUNCTION__,__LINE__, prefix, args,##__VA_ARGS__)
+#define HMI_INFO(prefix, args,...)  _HMI_LOG(LOG_LEVEL_INFO, __FILE__, __FUNCTION__,__LINE__, prefix, args,##__VA_ARGS__)
+#define HMI_DEBUG(prefix, args,...) _HMI_LOG(LOG_LEVEL_DEBUG, __FILE__, __FUNCTION__,__LINE__, prefix, args,##__VA_ARGS__)
+
+static char ERROR_FLAG[6][20] = {"NONE", "ERROR", "WARNING", "NOTICE", "INFO", "DEBUG"};
+
+static void _HMI_LOG(enum LOG_LEVEL level, const char* file, const char* func, const int line, const char* prefix, const char* log, ...)
+{
+    const int log_level = (getenv("USE_HMI_DEBUG") == NULL)?0:atoi(getenv("USE_HMI_DEBUG"));
+    if(log_level < level)
+    {
+        return;
+    }
+
+    char *message;
+    struct timespec tp;
+    unsigned int time;
+
+    clock_gettime(CLOCK_REALTIME, &tp);
+	time = (tp.tv_sec * 1000000L) + (tp.tv_nsec / 1000);
+
+	va_list args;
+	va_start(args, log);
+	if (log == NULL || vasprintf(&message, log, args) < 0)
+        message = NULL;
+    fprintf(stderr,  "[%10.3f] [%s %s] [%s:%d] >>> %s \n", time / 1000.0, prefix, ERROR_FLAG[level], func, line, message);
+    va_end(args);
+	free(message);
+}
+
+#endif  //__HMI_DEBUG_H__
\ No newline at end of file
diff --git a/src/afb_binding_api.cpp b/src/afb_binding_api.cpp
index b608a8a..88616d5 100644
--- a/src/afb_binding_api.cpp
+++ b/src/afb_binding_api.cpp
@@ -43,53 +43,53 @@ binding_api::result_type binding_api::requestsurface(
 
 binding_api::result_type binding_api::activatesurface(
    char const *drawing_name, char const *drawing_area) {
-   logdebug("%s drawing_name %s", __func__, drawing_name);
+  HMI_DEBUG("wm", "%s drawing_name %s, drawing_area %s", __func__, drawing_name, drawing_area);
   auto r = this->app->api_activate_surface(drawing_name, drawing_area);
    if (r != nullptr) {
-      logdebug("%s failed with error: %s", __func__, r);
+      HMI_DEBUG("wm", "%s failed with error: %s", __func__, r);
       return Err<json_object *>(r);
    }
    return Ok(json_object_new_object());
 }
 
 binding_api::result_type binding_api::deactivatesurface(char const* drawing_name) {
-   logdebug("%s drawing_name %s", __func__, drawing_name);
+   HMI_DEBUG("wm", "%s drawing_name %s", __func__, drawing_name);
    auto r = this->app->api_deactivate_surface(drawing_name);
    if (r != nullptr) {
-      logdebug("%s failed with error: %s", __func__, r);
+      HMI_DEBUG("wm", "%s failed with error: %s", __func__, r);
       return Err<json_object *>(r);
    }
    return Ok(json_object_new_object());
 }
 
 binding_api::result_type binding_api::enddraw(char const* drawing_name) {
-   logdebug("%s drawing_name %s", __func__, drawing_name);
+   HMI_DEBUG("wm", "%s drawing_name %s", __func__, drawing_name);
    auto r = this->app->api_enddraw(drawing_name);
    if (r != nullptr) {
-      logdebug("%s failed with error: %s", __func__, r);
+      HMI_DEBUG("wm", "%s failed with error: %s", __func__, r);
       return Err<json_object *>(r);
    }
    return Ok(json_object_new_object());
 }
 
 binding_api::result_type binding_api::list_drawing_names() {
-   logdebug("%s", __func__);
+   HMI_DEBUG("wm", "%s", __func__);
    json j = this->app->id_alloc.name2id;
    return Ok(json_tokener_parse(j.dump().c_str()));
 }
 
 binding_api::result_type binding_api::debug_layers() {
-   logdebug("%s", __func__);
+   HMI_DEBUG("wm", "%s", __func__);
    return Ok(json_tokener_parse(this->app->layers.to_json().dump().c_str()));
 }
 
 binding_api::result_type binding_api::debug_surfaces() {
-   logdebug("%s", __func__);
+   HMI_DEBUG("wm", "%s", __func__);
    return Ok(to_json(this->app->controller->sprops));
 }
 
 binding_api::result_type binding_api::debug_status() {
-   logdebug("%s", __func__);
+   HMI_DEBUG("wm", "%s", __func__);
    json_object *jr = json_object_new_object();
    json_object_object_add(jr, "surfaces",
                           to_json(this->app->controller->sprops));
@@ -98,7 +98,7 @@ binding_api::result_type binding_api::debug_status() {
 }
 
 binding_api::result_type binding_api::debug_terminate() {
-   logdebug("%s", __func__);
+   HMI_DEBUG("wm", "%s", __func__);
    if (getenv("WINMAN_DEBUG_TERMINATE") != nullptr) {
       raise(SIGKILL);  // XXX afb-daemon kills it's pgroup using TERM, which
                        // doesn't play well with perf
diff --git a/src/app.cpp b/src/app.cpp
index f4dbba6..4de7b03 100644
--- a/src/app.cpp
+++ b/src/app.cpp
@@ -36,6 +36,7 @@
 #include <regex>
 #include <thread>
 
+
 namespace wm {
 
 namespace {
@@ -53,7 +54,7 @@ result<json> file_to_json(char const *filename) {
 }
 
 struct result<layer_map> load_layer_map(char const *filename) {
-   logdebug("loading IDs from %s", filename);
+   HMI_DEBUG("wm", "loading IDs from %s", filename);
 
    auto j = file_to_json(filename);
    if (j.is_err()) {
@@ -66,6 +67,7 @@ struct result<layer_map> load_layer_map(char const *filename) {
 
 }  // namespace
 
+
 /**
  * App Impl
  */
@@ -87,11 +89,11 @@ App::App(wl::display *d)
          if (l.is_ok()) {
             this->layers = l.unwrap();
          } else {
-            logerror("%s", l.err().value());
+            HMI_ERROR("wm", "%s", l.err().value());
          }
       }
    } catch (std::exception &e) {
-      logerror("Loading of configuration failed: %s", e.what());
+      HMI_ERROR("wm", "Loading of configuration failed: %s", e.what());
    }
 }
 
@@ -101,7 +103,7 @@ int App::init() {
    }
 
    if (this->layers.mapping.empty()) {
-      logerror("No surface -> layer mapping loaded");
+      HMI_ERROR("wm", "No surface -> layer mapping loaded");
       return -1;
    }
 
@@ -147,7 +149,7 @@ int App::dispatch_events() {
 
    int ret = this->display->dispatch();
    if (ret == -1) {
-      logerror("wl_display_dipatch() returned error %d",
+      HMI_ERROR("wm", "wl_display_dipatch() returned error %d",
                this->display->get_error());
       return -1;
    }
@@ -186,12 +188,12 @@ optional<std::string> App::lookup_name(int id) {
  */
 int App::init_layers() {
    if (!this->controller) {
-      logerror("ivi_controller global not available");
+      HMI_ERROR("wm", "ivi_controller global not available");
       return -1;
    }
 
    if (this->outputs.empty()) {
-      logerror("no output was set up!");
+      HMI_ERROR("wm", "no output was set up!");
       return -1;
    }
 
@@ -216,7 +218,7 @@ int App::init_layers() {
       auto &l = layers[i.second.layer_id];
       l->set_destination_rectangle(0, 0, o->width, o->height);
       l->set_visibility(1);
-      logdebug("Setting up layer %s (%d) for surface role match \"%s\"",
+      HMI_DEBUG("wm", "Setting up layer %s (%d) for surface role match \"%s\"",
                i.second.name.c_str(), i.second.layer_id, i.second.role.c_str());
    }
 
@@ -230,14 +232,14 @@ int App::init_layers() {
 
 void App::surface_set_layout(int surface_id, optional<int> sub_surface_id) {
    if (!this->controller->surface_exists(surface_id)) {
-      logerror("Surface %d does not exist", surface_id);
+      HMI_ERROR("wm", "Surface %d does not exist", surface_id);
       return;
    }
 
    auto o_layer_id = this->layers.get_layer_id(surface_id);
 
    if (!o_layer_id) {
-      logerror("Surface %d is not associated with any layer!", surface_id);
+      HMI_ERROR("wm", "Surface %d is not associated with any layer!", surface_id);
       return;
    }
 
@@ -263,7 +265,7 @@ void App::surface_set_layout(int surface_id, optional<int> sub_surface_id) {
 
    if (sub_surface_id) {
       if (o_layer_id != this->layers.get_layer_id(*sub_surface_id)) {
-         logerror(
+         HMI_ERROR("wm",
             "surface_set_layout: layers of surfaces (%d and %d) don't match!",
             surface_id, *sub_surface_id);
          return;
@@ -283,7 +285,7 @@ void App::surface_set_layout(int surface_id, optional<int> sub_surface_id) {
 
       auto &ss = this->controller->surfaces[*sub_surface_id];
 
-      logdebug("surface_set_layout for sub surface %u on layer %u",
+      HMI_DEBUG("wm", "surface_set_layout for sub surface %u on layer %u",
                *sub_surface_id, layer_id);
 
       // configure surface to wxh dimensions
@@ -292,9 +294,10 @@ void App::surface_set_layout(int surface_id, optional<int> sub_surface_id) {
       ss->set_source_rectangle(0, 0, w, h);
       // set destination to the display rectangle
       ss->set_destination_rectangle(x + x_off, y + y_off, w, h);
+
    }
 
-   logdebug("surface_set_layout for surface %u on layer %u", surface_id,
+   HMI_DEBUG("wm", "surface_set_layout for surface %u on layer %u", surface_id,
             layer_id);
 
    // configure surface to wxh dimensions
@@ -305,7 +308,7 @@ void App::surface_set_layout(int surface_id, optional<int> sub_surface_id) {
    // set destination to the display rectangle
    s->set_destination_rectangle(x, y, w, h);
 
-   logdebug("Surface %u now on layer %u with rect { %d, %d, %d, %d }",
+   HMI_DEBUG("wm", "Surface %u now on layer %u with rect { %d, %d, %d, %d }",
             surface_id, layer_id, x, y, w, h);
 }
 
@@ -450,7 +453,7 @@ char const *App::api_deactivate_surface(char const *drawing_name) {
    // XXX: check against main_surface, main_surface_name is the configuration
    // item.
    if (*surface_id == this->layers.main_surface) {
-      logdebug("Refusing to deactivate main_surface %d", *surface_id);
+      HMI_DEBUG("wm", "Refusing to deactivate main_surface %d", *surface_id);
       return nullptr;
    }
 
@@ -499,7 +502,7 @@ char const *App::api_deactivate_surface(char const *drawing_name) {
 
 void App::enqueue_flushdraw(int surface_id) {
    this->check_flushdraw(surface_id);
-   logdebug("Enqueuing EndDraw for surface_id %d", surface_id);
+   HMI_DEBUG("wm", "Enqueuing EndDraw for surface_id %d", surface_id);
    this->pending_end_draw.push_back(surface_id);
 }
 
@@ -508,7 +511,7 @@ void App::check_flushdraw(int surface_id) {
                       std::end(this->pending_end_draw), surface_id);
    if (i != std::end(this->pending_end_draw)) {
       auto n = this->lookup_name(surface_id);
-      logerror("Application %s (%d) has pending EndDraw call(s)!",
+      HMI_ERROR("wm", "Application %s (%d) has pending EndDraw call(s)!",
                n ? n->c_str() : "unknown-name", surface_id);
       std::swap(this->pending_end_draw[std::distance(
                    std::begin(this->pending_end_draw), i)],
@@ -541,19 +544,19 @@ void App::api_ping() { this->dispatch_pending_events(); }
 void App::surface_created(uint32_t surface_id) {
    auto layer_id = this->layers.get_layer_id(surface_id);
    if (!layer_id) {
-      logdebug("Newly created surfce %d is not associated with any layer!",
+      HMI_DEBUG("wm", "Newly created surfce %d is not associated with any layer!",
                surface_id);
       return;
    }
 
-   logdebug("surface_id is %u, layer_id is %u", surface_id, *layer_id);
+   HMI_DEBUG("wm", "surface_id is %u, layer_id is %u", surface_id, *layer_id);
 
    this->controller->layers[*layer_id]->add_surface(
       this->controller->surfaces[surface_id].get());
 
    // activate the main_surface right away
    /*if (surface_id == static_cast<unsigned>(this->layers.main_surface)) {
-      logdebug("Activating main_surface (%d)", surface_id);
+      HMI_DEBUG("wm", "Activating main_surface (%d)", surface_id);
 
       this->api_activate_surface(
          this->lookup_name(surface_id).value_or("unknown-name").c_str());
@@ -561,7 +564,7 @@ void App::surface_created(uint32_t surface_id) {
 }
 
 void App::surface_removed(uint32_t surface_id) {
-   logdebug("surface_id is %u", surface_id);
+   HMI_DEBUG("wm", "surface_id is %u", surface_id);
 
    // We cannot normally deactivate the main_surface, so be explicit
    // about it:
@@ -621,7 +624,7 @@ result<int> App::api_request_surface(char const *drawing_name) {
       if (!this->layers.main_surface_name.empty() &&
           this->layers.main_surface_name == drawing_name) {
          this->layers.main_surface = id;
-         logdebug("Set main_surface id to %u", id);
+         HMI_DEBUG("wm", "Set main_surface id to %u", id);
       }
 
       return Ok<int>(id);
@@ -673,21 +676,21 @@ bool App::can_split(struct LayoutState const &state, int new_id) {
 
       auto const &layer = this->layers.get_layer(new_id_layer);
 
-      logdebug("layer info name: %s", layer->name.c_str());
+      HMI_DEBUG("wm", "layer info name: %s", layer->name.c_str());
 
       if (layer->layouts.empty()) {
          return false;
       }
 
       for (auto i = layer->layouts.cbegin(); i != layer->layouts.cend(); i++) {
-         logdebug("%d main_match '%s'", new_id_layer, i->main_match.c_str());
+         HMI_DEBUG("wm", "%d main_match '%s'", new_id_layer, i->main_match.c_str());
          auto rem = std::regex(i->main_match);
          if (std::regex_match(cur_id_str, rem)) {
             // build the second one only if the first already matched
-            logdebug("%d sub_match '%s'", new_id_layer, i->sub_match.c_str());
+            HMI_DEBUG("wm", "%d sub_match '%s'", new_id_layer, i->sub_match.c_str());
             auto res = std::regex(i->sub_match);
             if (std::regex_match(new_id_str, res)) {
-               logdebug("layout matched!");
+               HMI_DEBUG("wm", "layout matched!");
                return true;
             }
          }
diff --git a/src/app.hpp b/src/app.hpp
index 9f8b7ce..1029aac 100644
--- a/src/app.hpp
+++ b/src/app.hpp
@@ -33,6 +33,7 @@
 #include "policy.hpp"
 #include "result.hpp"
 #include "wayland.hpp"
+#include "hmi-debug.h"
 
 namespace wl {
 struct display;
@@ -76,7 +77,7 @@ struct id_allocator {
       this->id2name[sid] = name;
       // this->pending_surfaces.insert({sid});
       this->name2id[name] = sid;
-      logdebug("allocated new id %u with name %s", sid, name.c_str());
+      HMI_DEBUG("wm", "allocated new id %u with name %s", sid, name.c_str());
       return sid;
    }
 
diff --git a/src/layers.cpp b/src/layers.cpp
index 9219766..2150440 100644
--- a/src/layers.cpp
+++ b/src/layers.cpp
@@ -20,6 +20,7 @@
 #include "json_helper.hpp"
 #include "layers.hpp"
 #include "util.hpp"
+#include "hmi-debug.h"
 
 namespace wm {
 
@@ -44,7 +45,7 @@ layer::layer(nlohmann::json const &j) {
                      std::back_inserter(this->layouts), [this](json const &sl) {
                         struct split_layout l {
                            sl["name"], sl["main_match"], sl["sub_match"] };
-                        logdebug(
+                        HMI_DEBUG("wm",
                            "layer %d add split_layout \"%s\" (main: \"%s\") (sub: "
                            "\"%s\")", this->layer_id,
                            l.name.c_str(), l.main_match.c_str(),
@@ -114,11 +115,11 @@ optional<int> layer_map::get_layer_id(std::string const &role) {
    for (auto const &r : this->roles) {
       auto re = std::regex(r.first);
       if (std::regex_match(role, re)) {
-         logdebug("role %s matches layer %d", role.c_str(), r.second);
+         HMI_DEBUG("wm", "role %s matches layer %d", role.c_str(), r.second);
          return optional<int>(r.second);
       }
    }
-   logdebug("role %s does NOT match any layer", role.c_str());
+   HMI_DEBUG("wm", "role %s does NOT match any layer", role.c_str());
    return nullopt;
 }
 
diff --git a/src/main.cpp b/src/main.cpp
index c90eeb1..a8bb563 100755
--- a/src/main.cpp
+++ b/src/main.cpp
@@ -52,7 +52,7 @@ int display_event_callback(sd_event_source *evs, int /*fd*/, uint32_t events,
    ST();
 
    if ((events & EPOLLHUP) != 0) {
-      logerror("The compositor hung up, dying now.");
+      HMI_ERROR("wm", "The compositor hung up, dying now.");
       delete g_afb_instance;
       g_afb_instance = nullptr;
       goto error;
@@ -93,15 +93,15 @@ error:
 // |_.__/|_|_| |_|\__,_|_|_| |_|\__, |___|_|_| |_|_|\__| |  | |
 //                              |___/_____|             \_\/_/
 int binding_init_() {
-   lognotice("WinMan ver. %s", WINMAN_VERSION_STRING);
+   HMI_NOTICE("wm", "WinMan ver. %s", WINMAN_VERSION_STRING);
 
    if (g_afb_instance != nullptr) {
-      logerror("Wayland context already initialized?");
+      HMI_ERROR("wm", "Wayland context already initialized?");
       return 0;
    }
 
    if (getenv("XDG_RUNTIME_DIR") == nullptr) {
-      logerror("Environment variable XDG_RUNTIME_DIR not set");
+      HMI_ERROR("wm", "Environment variable XDG_RUNTIME_DIR not set");
       goto error;
    }
 
@@ -112,10 +112,10 @@ int binding_init_() {
       while (!g_afb_instance->display->ok()) {
          cnt++;
          if (20 <= cnt) {
-            logerror("Could not connect to compositor");
+            HMI_ERROR("wm", "Could not connect to compositor");
             goto error;
          }
-         logerror("Wait to start weston ...");
+         HMI_ERROR("wm", "Wait to start weston ...");
          sleep(1);
          delete g_afb_instance;
          g_afb_instance = new afb_instance;
@@ -123,7 +123,7 @@ int binding_init_() {
    }
 
    if (g_afb_instance->init() == -1) {
-      logerror("Could not connect to compositor");
+      HMI_ERROR("wm", "Could not connect to compositor");
       goto error;
    }
 
@@ -132,7 +132,7 @@ int binding_init_() {
                                 g_afb_instance->display->get_fd(), EPOLLIN,
                                 display_event_callback, g_afb_instance);
       if (ret < 0) {
-         logerror("Could not initialize afb_instance event handler: %d", -ret);
+         HMI_ERROR("wm", "Could not initialize afb_instance event handler: %d", -ret);
          goto error;
       }
    }
@@ -151,7 +151,7 @@ int binding_init() noexcept {
    try {
       return binding_init_();
    } catch (std::exception &e) {
-      logerror("Uncaught exception in binding_init(): %s", e.what());
+      HMI_ERROR("wm", "Uncaught exception in binding_init(): %s", e.what());
    }
    return -1;
 }
@@ -162,19 +162,19 @@ int binding_init() noexcept {
 
 namespace wm {
 void binding_api::send_event(char const *evname, char const *label) {
-   logdebug("%s: %s(%s)", __func__, evname, label);
+   HMI_DEBUG("wm", "%s: %s(%s)", __func__, evname, label);
 
    json_object *j = json_object_new_object();
    json_object_object_add(j, kKeyDrawingName, json_object_new_string(label));
 
    int ret = afb_event_push(g_afb_instance->app.map_afb_event[evname], j);
    if (ret != 0) {
-      logdebug("afb_event_push failed: %m");
+      HMI_DEBUG("wm", "afb_event_push failed: %m");
    }
 }
 
 void binding_api::send_event(char const *evname, char const *label, char const *area) {
-   logdebug("%s: %s(%s, %s)", __func__, evname, label, area);
+   HMI_DEBUG("wm", "%s: %s(%s, %s)", __func__, evname, label, area);
 
    json_object *j = json_object_new_object();
    json_object_object_add(j, kKeyDrawingName, json_object_new_string(label));
@@ -182,7 +182,7 @@ void binding_api::send_event(char const *evname, char const *label, char const *
 
    int ret = afb_event_push(g_afb_instance->app.map_afb_event[evname], j);
    if (ret != 0) {
-      logdebug("afb_event_push failed: %m");
+      HMI_DEBUG("wm", "afb_event_push failed: %m");
    }
 }
 } // namespace wm
diff --git a/src/policy.hpp b/src/policy.hpp
index ed5d6ba..d6aefc9 100644
--- a/src/policy.hpp
+++ b/src/policy.hpp
@@ -18,6 +18,7 @@
 #define TMCAGLWM_POLICY_HPP
 
 #include "layout.hpp"
+#include "hmi-debug.h"
 
 namespace wm {
 
@@ -25,7 +26,7 @@ class Policy {
 public:
    bool layout_is_valid(LayoutState const & /* layout */) {
       // We do not check for policy currently
-      logdebug("Policy check returns positive");
+      HMI_DEBUG("wm", "Policy check returns positive");
       return true;
    }
 };
diff --git a/src/wayland.cpp b/src/wayland.cpp
index 05e155f..c565a92 100644
--- a/src/wayland.cpp
+++ b/src/wayland.cpp
@@ -18,6 +18,7 @@
 
 #include "util.hpp"
 #include "wayland.hpp"
+#include "hmi-debug.h"
 
 //                                                                  _
 //  _ __   __ _ _ __ ___   ___  ___ _ __   __ _  ___ ___  __      _| |
@@ -110,7 +111,7 @@ void registry::global(uint32_t name, char const *iface, uint32_t v) {
    if (b != this->bindings.end()) {
       b->second(this->proxy.get(), name, v);
    }
-   logdebug("wl::registry @ %p global n %u i %s v %u", this->proxy.get(), name,
+   HMI_DEBUG("wm", "wl::registry @ %p global n %u i %s v %u", this->proxy.get(), name,
             iface, v);
 }
 
@@ -157,14 +158,14 @@ output::output(struct wl_registry *r, uint32_t name, uint32_t v)
 void output::geometry(int32_t x, int32_t y, int32_t pw, int32_t ph,
                       int32_t subpel, char const *make, char const *model,
                       int32_t tx) {
-   logdebug(
+   HMI_DEBUG("wm",
       "wl::output %s @ %p x %i y %i w %i h %i spel %x make %s model %s tx %i",
       __func__, this->proxy.get(), x, y, pw, ph, subpel, make, model, tx);
    this->transform = tx;
 }
 
 void output::mode(uint32_t flags, int32_t w, int32_t h, int32_t r) {
-   logdebug("wl::output %s @ %p f %x w %i h %i r %i", __func__,
+   HMI_DEBUG("wm", "wl::output %s @ %p f %x w %i h %i r %i", __func__,
             this->proxy.get(), flags, w, h, r);
    if ((flags & WL_OUTPUT_MODE_CURRENT) != 0u) {
       this->width = w;
@@ -174,7 +175,7 @@ void output::mode(uint32_t flags, int32_t w, int32_t h, int32_t r) {
 }
 
 void output::done() {
-   logdebug("wl::output %s @ %p done", __func__, this->proxy.get());
+   HMI_DEBUG("wm", "wl::output %s @ %p done", __func__, this->proxy.get());
    // Let's just disregard the flipped ones...
    if (this->transform == WL_OUTPUT_TRANSFORM_90 ||
        this->transform == WL_OUTPUT_TRANSFORM_270) {
@@ -183,7 +184,7 @@ void output::done() {
 }
 
 void output::scale(int32_t factor) {
-   logdebug("wl::output %s @ %p f %i", __func__, this->proxy.get(), factor);
+   HMI_DEBUG("wm", "wl::output %s @ %p f %i", __func__, this->proxy.get(), factor);
 }
 }  // namespace wl
 
@@ -251,15 +252,15 @@ void controller::surface_create(uint32_t id) {
 
 void controller::controller_screen(uint32_t id,
                                    struct ivi_controller_screen *screen) {
-   logdebug("genivi::controller @ %p screen %u (%x) @ %p", this->proxy.get(),
+   HMI_DEBUG("wm", "genivi::controller @ %p screen %u (%x) @ %p", this->proxy.get(),
             id, id, screen);
    this->screens[id] = std::make_unique<struct screen>(id, this, screen);
 }
 
 void controller::controller_layer(uint32_t id) {
-   logdebug("genivi::controller @ %p layer %u (%x)", this->proxy.get(), id, id);
+   HMI_DEBUG("wm", "genivi::controller @ %p layer %u (%x)", this->proxy.get(), id, id);
    if (this->layers.find(id) != this->layers.end()) {
-      logerror("Someone created a layer without asking US! (%d)", id);
+      HMI_ERROR("wm", "Someone created a layer without asking US! (%d)", id);
    } else {
       auto &l = this->layers[id] = std::make_unique<struct layer>(id, this);
       l->clear_surfaces();
@@ -267,7 +268,7 @@ void controller::controller_layer(uint32_t id) {
 }
 
 void controller::controller_surface(uint32_t id) {
-   logdebug("genivi::controller @ %p surface %u (%x)", this->proxy.get(), id,
+   HMI_DEBUG("wm", "genivi::controller @ %p surface %u (%x)", this->proxy.get(), id,
             id);
    if (this->surfaces.find(id) == this->surfaces.end()) {
       this->surfaces[id] = std::make_unique<struct surface>(id, this);
@@ -277,7 +278,7 @@ void controller::controller_surface(uint32_t id) {
 
 void controller::controller_error(int32_t object_id, int32_t object_type,
                                   int32_t error_code, const char *error_text) {
-   logdebug("genivi::controller @ %p error o %i t %i c %i text %s",
+   HMI_DEBUG("wm", "genivi::controller @ %p error o %i t %i c %i text %s",
             this->proxy.get(), object_id, object_type, error_code, error_text);
 }
 
@@ -356,7 +357,7 @@ layer::layer(uint32_t i, struct controller *c) : layer(i, 0, 0, c) {}
 layer::layer(uint32_t i, int32_t w, int32_t h, struct controller *c)
    : wayland_proxy(ivi_controller_layer_create(c->proxy.get(), i, w, h),
                    [c, i](ivi_controller_layer *l) {
-                      logdebug("~layer layer %i @ %p", i, l);
+                      HMI_DEBUG("wm", "~layer layer %i @ %p", i, l);
                       c->remove_proxy_to_id_mapping(l);
                       ivi_controller_layer_destroy(l, 1);
                    }),
@@ -418,18 +419,18 @@ void layer::set_render_order(std::vector<uint32_t> const &ro) {
 }
 
 void controller::layer_visibility(struct layer *l, int32_t visibility) {
-   logdebug("genivi::layer %s @ %d v %i", __func__, l->id, visibility);
+   HMI_DEBUG("wm", "genivi::layer %s @ %d v %i", __func__, l->id, visibility);
    this->lprops[l->id].visibility = visibility;
 }
 
 void controller::layer_opacity(struct layer *l, float opacity) {
-   logdebug("genivi::layer %s @ %d o %f", __func__, l->id, opacity);
+   HMI_DEBUG("wm", "genivi::layer %s @ %d o %f", __func__, l->id, opacity);
    this->lprops[l->id].opacity = opacity;
 }
 
 void controller::layer_source_rectangle(struct layer *l, int32_t x, int32_t y,
                                         int32_t width, int32_t height) {
-   logdebug("genivi::layer %s @ %d x %i y %i w %i h %i", __func__,
+   HMI_DEBUG("wm", "genivi::layer %s @ %d x %i y %i w %i h %i", __func__,
             l->id, x, y, width, height);
    this->lprops[l->id].src_rect = rect{width, height, x, y};
 }
@@ -437,30 +438,30 @@ void controller::layer_source_rectangle(struct layer *l, int32_t x, int32_t y,
 void controller::layer_destination_rectangle(struct layer *l, int32_t x,
                                              int32_t y, int32_t width,
                                              int32_t height) {
-   logdebug("genivi::layer %s @ %d x %i y %i w %i h %i", __func__,
+   HMI_DEBUG("wm", "genivi::layer %s @ %d x %i y %i w %i h %i", __func__,
             l->id, x, y, width, height);
    this->lprops[l->id].dst_rect = rect{width, height, x, y};
 }
 
 void controller::layer_configuration(struct layer *l, int32_t width,
                                      int32_t height) {
-   logdebug("genivi::layer %s @ %d w %i h %i", __func__, l->id,
+   HMI_DEBUG("wm", "genivi::layer %s @ %d w %i h %i", __func__, l->id,
             width, height);
    this->lprops[l->id].size = size{uint32_t(width), uint32_t(height)};
 }
 
 void controller::layer_orientation(struct layer *l, int32_t orientation) {
-   logdebug("genivi::layer %s @ %d o %i", __func__, l->id,
+   HMI_DEBUG("wm", "genivi::layer %s @ %d o %i", __func__, l->id,
             orientation);
    this->lprops[l->id].orientation = orientation;
 }
 
 void controller::layer_screen(struct layer *l, struct wl_output *screen) {
-   logdebug("genivi::layer %s @ %d s %p", __func__, l->id, screen);
+   HMI_DEBUG("wm", "genivi::layer %s @ %d s %p", __func__, l->id, screen);
 }
 
 void controller::layer_destroyed(struct layer *l) {
-   logdebug("genivi::layer %s @ %d", __func__, l->id);
+   HMI_DEBUG("wm", "genivi::layer %s @ %d", __func__, l->id);
    this->lprops.erase(l->id);
    this->layers.erase(l->id);
 }
@@ -570,7 +571,7 @@ constexpr struct ivi_controller_surface_listener surface_listener = {
 surface::surface(uint32_t i, struct controller *c)
    : wayland_proxy(ivi_controller_surface_create(c->proxy.get(), i),
                    [c, i](ivi_controller_surface *s) {
-                      logdebug("~surface surface %i @ %p", i, s);
+                      HMI_DEBUG("wm", "~surface surface %i @ %p", i, s);
                       c->remove_proxy_to_id_mapping(s);
                       ivi_controller_surface_destroy(s, 1);
                    }),
@@ -621,14 +622,14 @@ void surface::destroy(int32_t destroy_scene_object) {
 }
 
 void controller::surface_visibility(struct surface *s, int32_t visibility) {
-   logdebug("genivi::surface %s @ %d v %i", __func__, s->id,
+   HMI_DEBUG("wm", "genivi::surface %s @ %d v %i", __func__, s->id,
             visibility);
    this->sprops[s->id].visibility = visibility;
    this->chooks->surface_visibility(s->id, visibility);
 }
 
 void controller::surface_opacity(struct surface *s, float opacity) {
-   logdebug("genivi::surface %s @ %d o %f", __func__, s->id,
+   HMI_DEBUG("wm", "genivi::surface %s @ %d o %f", __func__, s->id,
             opacity);
    this->sprops[s->id].opacity = opacity;
 }
@@ -636,7 +637,7 @@ void controller::surface_opacity(struct surface *s, float opacity) {
 void controller::surface_source_rectangle(struct surface *s, int32_t x,
                                           int32_t y, int32_t width,
                                           int32_t height) {
-   logdebug("genivi::surface %s @ %d x %i y %i w %i h %i", __func__,
+   HMI_DEBUG("wm", "genivi::surface %s @ %d x %i y %i w %i h %i", __func__,
             s->id, x, y, width, height);
    this->sprops[s->id].src_rect = rect{width, height, x, y};
 }
@@ -644,7 +645,7 @@ void controller::surface_source_rectangle(struct surface *s, int32_t x,
 void controller::surface_destination_rectangle(struct surface *s, int32_t x,
                                                int32_t y, int32_t width,
                                                int32_t height) {
-   logdebug("genivi::surface %s @ %d x %i y %i w %i h %i", __func__,
+   HMI_DEBUG("wm", "genivi::surface %s @ %d x %i y %i w %i h %i", __func__,
             s->id, x, y, width, height);
    this->sprops[s->id].dst_rect = rect{width, height, x, y};
    this->chooks->surface_destination_rectangle(s->id, x, y, width, height);
@@ -652,39 +653,39 @@ void controller::surface_destination_rectangle(struct surface *s, int32_t x,
 
 void controller::surface_configuration(struct surface *s, int32_t width,
                                        int32_t height) {
-   logdebug("genivi::surface %s @ %d w %i h %i", __func__, s->id,
+   HMI_DEBUG("wm", "genivi::surface %s @ %d w %i h %i", __func__, s->id,
             width, height);
    this->sprops[s->id].size = size{uint32_t(width), uint32_t(height)};
 }
 
 void controller::surface_orientation(struct surface *s, int32_t orientation) {
-   logdebug("genivi::surface %s @ %d o %i", __func__, s->id,
+   HMI_DEBUG("wm", "genivi::surface %s @ %d o %i", __func__, s->id,
             orientation);
    this->sprops[s->id].orientation = orientation;
 }
 
 void controller::surface_pixelformat(struct surface * s,
                                      int32_t pixelformat) {
-   logdebug("genivi::surface %s @ %d f %i", __func__, s->id,
+   HMI_DEBUG("wm", "genivi::surface %s @ %d f %i", __func__, s->id,
             pixelformat);
 }
 
 void controller::surface_layer(struct surface * s,
                                struct ivi_controller_layer *layer) {
-   logdebug("genivi::surface %s @ %d l %u @ %p", __func__, s->id,
+   HMI_DEBUG("wm", "genivi::surface %s @ %d l %u @ %p", __func__, s->id,
             this->layer_proxy_to_id[uintptr_t(layer)], layer);
 }
 
 void controller::surface_stats(struct surface *s, uint32_t redraw_count,
                                uint32_t frame_count, uint32_t update_count,
                                uint32_t pid, const char *process_name) {
-   logdebug("genivi::surface %s @ %d r %u f %u u %u pid %u p %s", __func__,
+   HMI_DEBUG("wm", "genivi::surface %s @ %d r %u f %u u %u pid %u p %s", __func__,
             s->id, redraw_count, frame_count, update_count, pid,
             process_name);
 }
 
 void controller::surface_destroyed(struct surface *s) {
-   logdebug("genivi::surface %s @ %d", __func__, s->id);
+   HMI_DEBUG("wm", "genivi::surface %s @ %d", __func__, s->id);
    this->chooks->surface_removed(s->id);
    // XXX: do I need to actually remove the surface late, i.e. using add_task()?
    this->sprops.erase(s->id);
@@ -692,7 +693,7 @@ void controller::surface_destroyed(struct surface *s) {
 }
 
 void controller::surface_content(struct surface *s, int32_t content_state) {
-   logdebug("genivi::surface %s @ %d s %i", __func__, s->id,
+   HMI_DEBUG("wm", "genivi::surface %s @ %d s %i", __func__, s->id,
             content_state);
    if (content_state == IVI_CONTROLLER_SURFACE_CONTENT_STATE_CONTENT_REMOVED) {
       // XXX is this the right thing to do?
@@ -704,35 +705,35 @@ void controller::surface_content(struct surface *s, int32_t content_state) {
 
 void controller::add_proxy_to_id_mapping(struct ivi_controller_surface *p,
                                          uint32_t id) {
-   logdebug("Add surface proxy mapping for %p (%u)", p, id);
+   HMI_DEBUG("wm", "Add surface proxy mapping for %p (%u)", p, id);
    this->surface_proxy_to_id[uintptr_t(p)] = id;
    this->sprops[id].id = id;
 }
 
 void controller::remove_proxy_to_id_mapping(struct ivi_controller_surface *p) {
-   logdebug("Remove surface proxy mapping for %p", p);
+   HMI_DEBUG("wm", "Remove surface proxy mapping for %p", p);
    this->surface_proxy_to_id.erase(uintptr_t(p));
 }
 
 void controller::add_proxy_to_id_mapping(struct ivi_controller_layer *p,
                                          uint32_t id) {
-   logdebug("Add layer proxy mapping for %p (%u)", p, id);
+   HMI_DEBUG("wm", "Add layer proxy mapping for %p (%u)", p, id);
    this->layer_proxy_to_id[uintptr_t(p)] = id;
    this->lprops[id].id = id;
 }
 
 void controller::remove_proxy_to_id_mapping(struct ivi_controller_layer *p) {
-   logdebug("Remove layer proxy mapping for %p", p);
+   HMI_DEBUG("wm", "Remove layer proxy mapping for %p", p);
    this->layer_proxy_to_id.erase(uintptr_t(p));
 }
 
 void controller::add_proxy_to_id_mapping(struct wl_output *p, uint32_t id) {
-   logdebug("Add screen proxy mapping for %p (%u)", p, id);
+   HMI_DEBUG("wm", "Add screen proxy mapping for %p (%u)", p, id);
    this->screen_proxy_to_id[uintptr_t(p)] = id;
 }
 
 void controller::remove_proxy_to_id_mapping(struct wl_output *p) {
-   logdebug("Remove screen proxy mapping for %p", p);
+   HMI_DEBUG("wm", "Remove screen proxy mapping for %p", p);
    this->screen_proxy_to_id.erase(uintptr_t(p));
 }
 
@@ -745,7 +746,7 @@ void controller::remove_proxy_to_id_mapping(struct wl_output *p) {
 screen::screen(uint32_t i, struct controller *c,
                struct ivi_controller_screen *p)
    : wayland_proxy(p), controller_child(c, i) {
-   logdebug("genivi::screen @ %p id %u", p, i);
+   HMI_DEBUG("wm", "genivi::screen @ %p id %u", p, i);
 }
 
 void screen::clear() { ivi_controller_screen_clear(this->proxy.get()); }