update for log module MT-safe 37/181437/5
authorJeonghoon Park <jh1979.park@samsung.com>
Thu, 14 Jun 2018 02:09:30 +0000 (11:09 +0900)
committerJeonghoon Park <jh1979.park@samsung.com>
Thu, 14 Jun 2018 03:38:14 +0000 (12:38 +0900)
Change-Id: I8c3b78c693f5f1e671edcc8ec57fea31e31d9b3f

daemon/include/ttd-log.h
daemon/src/tizen-things-daemon.c
daemon/src/ttd-log.c

index 1c0642c..4a8123a 100644 (file)
 #ifndef __TT_DAEMON_LOG_H__
 #define __TT_DAEMON_LOG_H__
 
-#include <dlog.h>
+typedef enum {
+       TTD_LOG_UNKNOWN = 0,
+       TTD_LOG_VERBOSE,
+       TTD_LOG_DEBUG,
+       TTD_LOG_INFO,
+       TTD_LOG_WARNING,
+       TTD_LOG_ERROR,
+       TTD_LOG_LEVEL_MAX
+} ttd_log_level_e;
+
+typedef enum {
+       TTD_LOG_TYPE_DLOG = 0,
+       TTD_LOG_TYPE_FILE,
+       TTD_LOG_TYPE_ALL,
+} ttd_log_type_e;
+
+int ttd_log_print(ttd_log_level_e level, const char *tag, const char *fmt, ...);
+int ttd_log_init(ttd_log_type_e type);
+void ttd_log_fini(void);
 
 #ifdef LOG_TAG
 #undef LOG_TAG
 #define LOG_TAG "TTD"
 
 #if !defined(_V)
-#define _V(fmt, arg...) log_print(DLOG_VERBOSE, LOG_TAG, "[%s : %d] " fmt "\n", __func__, __LINE__, ##arg)
+#define _V(fmt, arg...) ttd_log_print(TTD_LOG_VERBOSE, LOG_TAG, "[%s : %d] " fmt "\n", __func__, __LINE__, ##arg)
 #endif
 
 #if !defined(_D)
-#define _D(fmt, arg...) log_print(DLOG_DEBUG, LOG_TAG, "[%s : %d] " fmt "\n", __func__, __LINE__, ##arg)
+#define _D(fmt, arg...) ttd_log_print(TTD_LOG_DEBUG, LOG_TAG, "[%s : %d] " fmt "\n", __func__, __LINE__, ##arg)
 #endif
 
 #if !defined(_I)
-#define _I(fmt, arg...) log_print(DLOG_INFO, LOG_TAG, "[%s : %d] " fmt "\n", __func__, __LINE__, ##arg)
+#define _I(fmt, arg...) ttd_log_print(TTD_LOG_INFO, LOG_TAG, "[%s : %d] " fmt "\n", __func__, __LINE__, ##arg)
 #endif
 
 #if !defined(_W)
-#define _W(fmt, arg...) log_print(DLOG_WARN, LOG_TAG, "[%s : %d] " fmt "\n", __func__, __LINE__, ##arg)
+#define _W(fmt, arg...) ttd_log_print(TTD_LOG_WARNING, LOG_TAG, "[%s : %d] " fmt "\n", __func__, __LINE__, ##arg)
 #endif
 
 #if !defined(_E)
-#define _E(fmt, arg...) log_print(DLOG_ERROR, LOG_TAG, "[%s : %d] " fmt "\n", __func__, __LINE__, ##arg)
+#define _E(fmt, arg...) ttd_log_print(TTD_LOG_ERROR, LOG_TAG, "[%s : %d] " fmt "\n", __func__, __LINE__, ##arg)
 #endif
 
 #define retvm_if(expr, val, fmt, arg...) do { \
        if (expr) { \
                _E(fmt, ##arg); \
-               _E("(%s) -> %s() return", #expr, __FUNCTION__); \
+               _E("(%s) -> %s() return", #expr, __func__); \
                return val; \
        } \
 } while (0)
 
 #define retv_if(expr, val) do { \
        if (expr) { \
-               _E("(%s) -> %s() return", #expr, __FUNCTION__); \
+               _E("(%s) -> %s() return", #expr, __func__); \
                return (val); \
        } \
 } while (0)
 #define retm_if(expr, fmt, arg...) do { \
        if (expr) { \
                _E(fmt, ##arg); \
-               _E("(%s) -> %s() return", #expr, __FUNCTION__); \
+               _E("(%s) -> %s() return", #expr, __func__); \
                return; \
        } \
 } while (0)
 
 #define ret_if(expr) do { \
        if (expr) { \
-               _E("(%s) -> %s() return", #expr, __FUNCTION__); \
+               _E("(%s) -> %s() return", #expr, __func__); \
                return; \
        } \
 } while (0)
        } \
 }
 
-typedef enum {
-       LOG_TYPE_DLOG = 0,
-       LOG_TYPE_FILE,
-       LOG_TYPE_ALL,
-} log_type;
-
-int log_print(log_priority prio, const char *tag, const char *fmt, ...);
-int log_type_set(log_type type);
-void log_file_close(void);
-
 #endif /* __TT_DAEMON_LOG_H__ */
index f324c8c..880c1c2 100644 (file)
@@ -180,7 +180,7 @@ int main(int argc, char* argv[])
 
        d_data = calloc(1, sizeof(ttd_data));
 
-       log_type_set(LOG_TYPE_DLOG);
+       ttd_log_init(TTD_LOG_TYPE_ALL);
 
        d_data->mainloop = g_main_loop_new(NULL, FALSE);
 
@@ -216,7 +216,7 @@ int main(int argc, char* argv[])
        ttd_conn_mgr_fini();
        ttd_http_fini();
 
-       log_file_close();
+       ttd_log_fini();
 
        return 0;
 }
index 5019f57..4f0eece 100644 (file)
@@ -15,6 +15,8 @@
  */
 
 #include <glib.h>
+#include <sys/syscall.h>
+#include <unistd.h>
 #include <stdio.h>
 #include <stdarg.h>
 #include <stdlib.h>
 #include "ttd-log.h"
 #include "common-util.h"
 
+/*
+ * ttd log format
+ * [time][log_level][pid-tid] message([func : line] log)
+ */
+
 static FILE *log_fp = NULL;
-static log_type ltype = LOG_TYPE_DLOG;
-
-static const char log_prio_name[][DLOG_PRIO_MAX-1] = {
-       "UNKNOWN",
-       "DEFAULT", /**< Default */
-       "VERBOSE", /**< Verbose */
-       "DEBUG", /**< Debug */
-       "INFO", /**< Info */
-       "WARN", /**< Warning */
-       "ERROR", /**< Error */
-       "FATAL", /**< Fatal */
-       "SILENT" /**< Silent */
+static GMutex log_mutex;
+static ttd_log_type_e ltype = TTD_LOG_TYPE_DLOG;
+
+static const char log_prio_name[][TTD_LOG_LEVEL_MAX] = {
+       "U", /**< Unknown - DO NOT use */
+       "V", /**< Verbose */
+       "D", /**< Debug */
+       "I", /**< Info */
+       "W", /**< Warning */
+       "E", /**< Error */
 };
 
-static inline char* getFormattedTime(void)
+static inline long int __get_tid(void)
+{
+       return (long int)syscall(__NR_gettid);
+}
+
+static log_priority __level_to_dlog_prio(ttd_log_level_e level)
+{
+       log_priority prio = DLOG_UNKNOWN;
+       switch (level) {
+       case TTD_LOG_DEBUG:
+               prio = DLOG_DEBUG;
+               break;
+       case TTD_LOG_ERROR:
+               prio = DLOG_ERROR;
+               break;
+       case TTD_LOG_WARNING:
+               prio = DLOG_WARN;
+               break;
+       case TTD_LOG_VERBOSE:
+               prio = DLOG_VERBOSE;
+               break;
+       case TTD_LOG_INFO:
+               prio = DLOG_INFO;
+               break;
+       case TTD_LOG_UNKNOWN:
+       case TTD_LOG_LEVEL_MAX:
+       default:
+               prio = DLOG_UNKNOWN;
+       }
+       return prio;
+}
+
+static const char* getFormattedTime(void)
 {
        struct timespec time_s;
        struct tm *ptm;
@@ -56,8 +93,8 @@ static inline char* getFormattedTime(void)
                        "%04d-%02d-%02d %02d:%02d:%02d:%06ld"
                        , ptm->tm_year + 1900, ptm->tm_mon + 1, ptm->tm_mday
                        , ptm->tm_hour, ptm->tm_min, ptm->tm_sec
-                       , time_s.tv_nsec);
-       }
+                       , (long int)(time_s.tv_nsec / 1000));
+       } /* if failed, return last time */
 
        return res_time;
 }
@@ -65,84 +102,126 @@ static inline char* getFormattedTime(void)
 static int __open_log_file(void)
 {
        const char *log_file = tzplatform_mkpath(TZ_SYS_VAR, "log/ttd.log");
-       _D("log file - %s", log_file);
-       log_fp = fopen(log_file, "a");
+       dlog_print(DLOG_DEBUG, LOG_TAG, "log file - %s\n", log_file);
+
        /* TODO : splits log file, if log file size is exceeded specified max size */
-       if (log_fp == NULL) {
-               dlog_print(DLOG_WARN, LOG_TAG, "%s\n", strerror(errno));
-               goto error;
+       g_mutex_lock(&log_mutex);
+       log_fp = fopen(log_file, "a");
+       if (!log_fp) {
+               g_mutex_unlock(&log_mutex);
+               dlog_print(DLOG_ERROR,
+                       LOG_TAG, "error[%s] to use log file, so use dlog as log system\n",
+                       strerror(errno));
+
+               ltype = TTD_LOG_TYPE_DLOG;
+               return -1;
        }
-
+       setvbuf(log_fp, (char *)NULL, _IOLBF, 0);
+       g_mutex_unlock(&log_mutex);
        return 0;
+}
+
+static void __close_log_file(void)
+{
+       g_mutex_lock(&log_mutex);
+       if (log_fp) {
+               fclose(log_fp);
+               log_fp = NULL;
+       }
+       g_mutex_unlock(&log_mutex);
+
+       dlog_print(DLOG_DEBUG, LOG_TAG, "close log file\n");
+}
 
-error:
-       dlog_print(DLOG_WARN, LOG_TAG,
-               "error to use log file, so use dlog as log system\n");
-       ltype = LOG_TYPE_DLOG;
+static void
+__write_log_to_file(const char *msg, ttd_log_level_e level, const char *tag)
+{
+       /* TODO : we need to logging tag ??? */
+
+       char *log_msg = NULL;
+
+       if (!msg)
+               return;
+
+       log_msg = g_strdup_printf("[%s][%s][%ld-%ld] %s",
+                       getFormattedTime(),
+                       log_prio_name[level],
+                       (long int)getpid(), __get_tid(),
+                       msg);
+
+       if (!log_msg) {
+               dlog_print(DLOG_ERROR, LOG_TAG, "failed to create log msg\n");
+               dlog_print(DLOG_ERROR, LOG_TAG, "%s", msg);
+       }
 
-       return -1;
+       g_mutex_lock(&log_mutex);
+       if (log_fp)
+               fprintf(log_fp, "%s", log_msg);
+       g_mutex_unlock(&log_mutex);
+       g_free(log_msg);
 }
 
-int log_type_set(log_type type)
+int ttd_log_init(ttd_log_type_e type)
 {
        ltype = type;
-       dlog_print(DLOG_DEBUG, LOG_TAG, "setting log type : [%d]\n", type);
+       g_mutex_init(&log_mutex);
+       dlog_print(DLOG_DEBUG, LOG_TAG, "initializing log type : [%d]\n", type);
        switch (type) {
-       case LOG_TYPE_FILE:
-       case LOG_TYPE_ALL:
+       case TTD_LOG_TYPE_FILE:
+       case TTD_LOG_TYPE_ALL:
                __open_log_file();
                break;
-       case LOG_TYPE_DLOG: /* nothing to do */
+       case TTD_LOG_TYPE_DLOG: /* nothing to do */
        default:
-               ltype = LOG_TYPE_DLOG;
+               ltype = TTD_LOG_TYPE_DLOG;
                break;
        }
        return 0;
 }
 
-void log_file_close(void)
+void ttd_log_fini(void)
 {
-       if (log_fp) {
-               fclose(log_fp);
-               log_fp = NULL;
-               dlog_print(DLOG_DEBUG, LOG_TAG, "close log file\n");
-       }
-
-       log_type_set(LOG_TYPE_DLOG);
+       __close_log_file();
+       g_mutex_clear(&log_mutex);
+       ltype = TTD_LOG_TYPE_DLOG;
 
        return;
 }
 
-int log_print(log_priority prio, const char *tag, const char *fmt, ...)
+int ttd_log_print(ttd_log_level_e level, const char *tag, const char *fmt, ...)
 {
        va_list ap;
 
        switch (ltype) {
-       case LOG_TYPE_FILE:
-               if (log_fp) {
-                       va_start(ap, fmt);
-                       fprintf(log_fp, "[%s] [%s]", getFormattedTime(), log_prio_name[prio]);
-                       vfprintf(log_fp, fmt, ap);
-                       va_end(ap);
-                       fflush(log_fp);
-               }
+       case TTD_LOG_TYPE_FILE:
+       {
+               char *msg = NULL;
+
+               va_start(ap, fmt);
+               msg = g_strdup_vprintf(fmt, ap);
+               va_end(ap);
+
+               __write_log_to_file(msg, level, tag);
+               g_free(msg);
+       }
                break;
-       case LOG_TYPE_ALL:
+       case TTD_LOG_TYPE_ALL:
+       {
+               char *msg = NULL;
+
                va_start(ap, fmt);
-               if (log_fp) {
-                       fprintf(log_fp, "[%s] [%s]", getFormattedTime(), log_prio_name[prio]);
-                       vfprintf(log_fp, fmt, ap);
-               }
-               dlog_vprint(prio, tag, fmt, ap);
+               msg = g_strdup_vprintf(fmt, ap);
                va_end(ap);
 
-               if (log_fp)
-                       fflush(log_fp);
+               dlog_print(__level_to_dlog_prio(level), tag, "%s", msg);
+               __write_log_to_file(msg, level, tag);
+               g_free(msg);
+       }
                break;
-       case LOG_TYPE_DLOG:
+       case TTD_LOG_TYPE_DLOG:
        default:
                va_start(ap, fmt);
-               dlog_vprint(prio, tag, fmt, ap);
+               dlog_vprint(__level_to_dlog_prio(level), tag, fmt, ap);
                va_end(ap);
                break;
        }