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: I0cdf0069f67f561156c0f78ff322984733091002
Signed-off-by: Yuta Doi <yuta-d@witz-inc.co.jp>

2 files changed, 101 insertions, 20 deletions

diff --git a/src/hmi-debug.h b/src/hmi-debug.h
new file mode 100644
index 0000000..2a744ba
--- /dev/null
+++ b/src/hmi-debug.h
@@ -0,0 +1,70 @@
+/*
+ * Copyright (c) 2017 TOYOTA MOTOR CORPORATION
+ *
+ * Licensed under the Apache License, Version 2.0 (the "License");
+ * you may not use this file except in compliance with the License.
+ * You may obtain a copy of the License at
+ *
+ *      http://www.apache.org/licenses/LICENSE-2.0
+ *
+ * Unless required by applicable law or agreed to in writing, software
+ * distributed under the License is distributed on an "AS IS" BASIS,
+ * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+ * See the License for the specific language governing permissions and
+ * limitations under the License.
+ */
+
+#ifndef __HMI_DEBUG_H__
+#define __HMI_DEBUG_H__
+
+#include <time.h>
+#include <stdio.h>
+#include <stdarg.h>
+#include <string.h>
+#include <stdlib.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_DEBUG
+};
+
+#define __FILENAME__ (strrchr(__FILE__, '/') ? strrchr(__FILE__, '/') + 1 : __FILE__)
+
+#define HMI_ERROR(prefix, args,...) _HMI_LOG(LOG_LEVEL_ERROR, __FILENAME__, __FUNCTION__, __LINE__, prefix, args, ##__VA_ARGS__)
+#define HMI_WARNING(prefix, args,...) _HMI_LOG(LOG_LEVEL_WARNING, __FILENAME__, __FUNCTION__,__LINE__, prefix, args,##__VA_ARGS__)
+#define HMI_NOTICE(prefix, args,...) _HMI_LOG(LOG_LEVEL_NOTICE, __FILENAME__, __FUNCTION__,__LINE__, prefix, args,##__VA_ARGS__)
+#define HMI_INFO(prefix, args,...)  _HMI_LOG(LOG_LEVEL_INFO, __FILENAME__, __FUNCTION__,__LINE__, prefix, args,##__VA_ARGS__)
+#define HMI_DEBUG(prefix, args,...) _HMI_LOG(LOG_LEVEL_DEBUG, __FILENAME__, __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)?LOG_LEVEL_ERROR: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, %s(), Line:%d] >>> %s \n", time / 1000.0, prefix, ERROR_FLAG[level], file, func, line, message);
+    va_end(args);
+	free(message);
+}
+
+#endif  //__HMI_DEBUG_H__
\ No newline at end of file
diff --git a/src/libwindowmanager.cpp b/src/libwindowmanager.cpp
index c9f8927..efa9721 100644
--- a/src/libwindowmanager.cpp
+++ b/src/libwindowmanager.cpp
@@ -15,6 +15,7 @@
  */
 
 #include "libwindowmanager.h"
+#include "hmi-debug.h"
 
 #include <cassert>
 #include <cctype>
@@ -135,6 +136,7 @@ void onEvent(void *closure, const char *event, afb_wsj1_msg *msg) {
 
     // check API name in event
     if (0 != strncmp(wmAPI, event, strlen(wmAPI))) {
+        HMI_ERROR("libwm", "Unknown event: %s", event);
         return;
     }
 
@@ -143,7 +145,7 @@ void onEvent(void *closure, const char *event, afb_wsj1_msg *msg) {
         reinterpret_cast<LibWindowmanager::Impl *>(closure)->event(event, val);
     }
     else {
-        fprintf(stderr, "Not found key \"data\"\n");
+        HMI_ERROR("libwm", "Not found key \"data\"");
     }
 }
 
@@ -152,7 +154,7 @@ void onHangup(void *closure, afb_wsj1 *wsj1) {
     TRACE();
     UNUSED(closure);
     UNUSED(wsj1);
-    fputs("Hangup, the WindowManager vanished\n", stderr);
+    HMI_ERROR("libwm", "Hangup, the WindowManager vanished");
     exit(1);
 }
 
@@ -175,23 +177,25 @@ LibWindowmanager::Impl::~Impl() {
 
 int LibWindowmanager::Impl::init(int port, char const *token) {
     TRACE();
+    HMI_DEBUG("libwm", "called");
+
     char *uribuf = nullptr;
     int rc = -1;
 
     if (this->loop != nullptr && this->wsj1 != nullptr) {
-        fputs("LibWindowmanager instance is already initialized!\n", stderr);
+        HMI_ERROR("libwm", "LibWindowmanager instance is already initialized!");
         rc = -EALREADY;
         goto fail;
     }
 
     if (token == nullptr) {
-        fputs("Token is invalid\n", stderr);
+        HMI_ERROR("libwm", "Token is invalid");
         rc = -EINVAL;
         goto fail;
     }
 
     if (port < 1 || port > 0xffff) {
-        fputs("Port is invalid\n", stderr);
+        HMI_ERROR("libwm", "Port is invalid");
         rc = -EINVAL;
         goto fail;
     }
@@ -199,7 +203,7 @@ int LibWindowmanager::Impl::init(int port, char const *token) {
     /* get the default event loop */
     rc = sd_event_default(&this->loop);
     if (rc < 0) {
-        fprintf(stderr, "Connection to default event loop failed: %s\n",
+        HMI_ERROR("libwm", "Connection to default event loop failed: %s",
                 strerror(-rc));
         goto fail;
     }
@@ -212,7 +216,7 @@ int LibWindowmanager::Impl::init(int port, char const *token) {
     if (this->wsj1 == nullptr) {
         sd_event_unref(this->loop);
         this->loop = nullptr;
-        fprintf(stderr, "Connection to %s failed: %m\n", uribuf);
+        HMI_ERROR("libwm", "Connection to %s failed: %m", uribuf);
         rc = -errno;
         goto fail;
     }
@@ -227,6 +231,7 @@ fail:
 
 int LibWindowmanager::Impl::requestSurface(json_object *object) {
     TRACE();
+    HMI_DEBUG("libwm", "called");
 
     json_object *val;
     const char *tmp_label;
@@ -234,7 +239,7 @@ int LibWindowmanager::Impl::requestSurface(json_object *object) {
         tmp_label = json_object_get_string(val);
     }
     else {
-        fprintf(stderr, "Not found key \"%s\"\n", this->kKeyDrawingName);
+        HMI_DEBUG("libwm", "Not found key \"%s\"", this->kKeyDrawingName);
         return -EINVAL;
     }
 
@@ -243,12 +248,13 @@ int LibWindowmanager::Impl::requestSurface(json_object *object) {
     const char *label = std::string(tmp_label).c_str();
 
     if (this->labels.find(label) != this->labels.end()) {
-        fputs("Surface label already known!\n", stderr);
+        HMI_ERROR("libwm", "Surface label already known!");
         return -EINVAL;
     }
 
     // Store application name first
     // because it may not return from setenv
+    HMI_DEBUG("libwm", "Insert application name: %s\n", label);
     this->labels.insert(this->labels.end(), label);
 
     int rc = -1;
@@ -262,7 +268,7 @@ int LibWindowmanager::Impl::requestSurface(json_object *object) {
                     id = json_object_get_int(val);
                 }
                 else {
-                    fprintf(stderr, "Not found key \"response\"\n");
+                    HMI_ERROR("libwm", "Not found key \"response\"");
                     rc = -EINVAL;
                     return;
                 }
@@ -270,13 +276,13 @@ int LibWindowmanager::Impl::requestSurface(json_object *object) {
                 asprintf(&buf, "%d", id);
                 printf("setenv(\"QT_IVI_SURFACE_ID\", %s, 1)\n", buf);
                 if (setenv("QT_IVI_SURFACE_ID", buf, 1) != 0) {
-                    fprintf(stderr, "putenv failed: %m\n");
+                    HMI_ERROR("libwm", "putenv failed: %m");
                     rc = -errno;
                 } else {
                     rc = id;  // Single point of success
                 }
             } else {
-                fprintf(stderr, "Could not get surface ID from WM: %s\n",
+                HMI_ERROR("libwm", "Could not get surface ID from WM: %s",
                         j != nullptr ? json_object_to_json_string_ext(
                                 j, JSON_C_TO_STRING_PRETTY)
                           : "no-info");
@@ -289,6 +295,7 @@ int LibWindowmanager::Impl::requestSurface(json_object *object) {
     }
 
     if (rc < 0) {
+        HMI_ERROR("libwm", "Erase application name: %s", label);
         this->labels.erase(label);
     }
 
@@ -297,9 +304,10 @@ int LibWindowmanager::Impl::requestSurface(json_object *object) {
 
 int LibWindowmanager::Impl::activateSurface(json_object *object) {
     TRACE();
+    HMI_DEBUG("libwm", "called");
     return this->api_call("ActivateSurface", object, [](bool ok, json_object *j) {
         if (!ok) {
-            fprintf(stderr, "API Call activate_surface() failed: %s\n",
+            HMI_ERROR("libwm", "API Call activate_surface() failed: %s",
                     j != nullptr ? json_object_to_json_string_ext(
                                        j, JSON_C_TO_STRING_PRETTY)
                   : "no-info");
@@ -309,9 +317,10 @@ int LibWindowmanager::Impl::activateSurface(json_object *object) {
 
 int LibWindowmanager::Impl::deactivateSurface(json_object *object) {
     TRACE();
+    HMI_DEBUG("libwm", "called");
     return this->api_call("DeactivateSurface", object, [](bool ok, json_object *j) {
         if (!ok) {
-            fprintf(stderr, "API Call deactivate_surface() failed: %s\n",
+            HMI_ERROR("libwm", "API Call deactivate_surface() failed: %s",
                     j != nullptr ? json_object_to_json_string_ext(
                                        j, JSON_C_TO_STRING_PRETTY)
                   : "no-info");
@@ -321,9 +330,10 @@ int LibWindowmanager::Impl::deactivateSurface(json_object *object) {
 
 int LibWindowmanager::Impl::endDraw(json_object *object) {
     TRACE();
+    HMI_DEBUG("libwm", "called");
     return this->api_call("EndDraw", object, [](bool ok, json_object *j) {
         if (!ok) {
-            fprintf(stderr, "API Call endDraw() failed: %s\n",
+            HMI_ERROR("libwm", "API Call endDraw() failed: %s",
                     j != nullptr ? json_object_to_json_string_ext(
                                        j, JSON_C_TO_STRING_PRETTY)
                   : "no-info");
@@ -337,13 +347,15 @@ static void _on_reply_static(void *closure, struct afb_wsj1_msg *msg)
 
 void LibWindowmanager::Impl::set_event_handler(enum EventType et, handler_fun func) {
     TRACE();
+    HMI_DEBUG("libwm", "called");
+
     // Subscribe event
     struct json_object* j = json_object_new_object();
     json_object_object_add(j, "event", json_object_new_int(et));
 
     int ret = afb_wsj1_call_j(this->wsj1, wmAPI, "wm_subscribe", j, _on_reply_static, this);
     if (0 > ret) {
-        fprintf(stderr, "calling %s/wm_subscribe failed\n", wmAPI);
+        HMI_ERROR("libwm", "Failed to subscribe event: %s", kListEventName[et].c_str());
     }
 
     // Set event handler
@@ -440,8 +452,7 @@ int LibWindowmanager::Impl::api_call(
     }
 
     if (rc < 0) {
-        fprintf(
-            stderr, "calling %s/%s(%s) failed: %m\n", wmAPI, verb,
+        HMI_ERROR("libwm", "calling %s/%s(%s) failed: %m", wmAPI, verb,
             json_object_to_json_string_ext(object, JSON_C_TO_STRING_PRETTY));
         // Call the reply handler regardless with a NULL json_object*
         onReply(false, nullptr);
@@ -454,7 +465,7 @@ void LibWindowmanager::Impl::event(char const *et, json_object *object) {
     TRACE();
     auto oet = make_event_type(et);
     if (!oet.first) {
-        fprintf(stderr, "Unknown event type string '%s'\n", et);
+        HMI_ERROR("libwm", "Unknown event type string '%s'", et);
         return;
     }
 
@@ -466,7 +477,7 @@ void LibWindowmanager::Impl::event(char const *et, json_object *object) {
             label = json_object_get_string(val);
         }
         else {
-            fprintf(stderr, "Not found key \"%s\"\n", this->kKeyDrawingName);
+            HMI_ERROR("libwm", "Not found key \"%s\"\n", this->kKeyDrawingName);
             return;
         }