common/src/debug.c

   1 /*
   2  * Copyright 2012  Samsung Electronics Co., Ltd
   3  *
   4  * Licensed under the Flora License, Version 1.0 (the "License");
   5  * you may not use this file except in compliance with the License.
   6  * You may obtain a copy of the License at
   7  *
   8  *        http://floralicense.org/license/
   9  *
  10  * Unless required by applicable law or agreed to in writing, software
  11  * distributed under the License is distributed on an "AS IS" BASIS,
  12  * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
  13  * See the License for the specific language governing permissions and
  14  * limitations under the License.
  15  */
  16
  17 #include <stdio.h>
  18 #include <stdarg.h>
  19 #include <stdbool.h>
  20 #include <sys/types.h>
  21 #include <sys/stat.h>
  22 #include <time.h>               // localtime_r
  23 #include <sys/time.h>   // gettimeofday
  24 #include <unistd.h>
  25 #include <string.h>             // strrchr
  26
  27 #undef PRINT_TID
  28
  29 #ifdef PRINT_TID
  30 #include <pthread.h>
  31 #endif
  32
  33 #ifndef __G_LIB_H__
  34         #define G_UNLIKELY(x) x
  35 #endif
  36
  37
  38 #include "debug.h"
  39
  40 enum {
  41         _DEBUG_OUTPUT_DIRECTION_CONSOLE = (1 << 0),
  42         _DEBUG_OUTPUT_DIRECTION_SYSLOG = (1 << 1),
  43         _DEBUG_OUTPUT_DIRECTION_FILE = (1 << 2),
  44         _DEBUG_OUTPUT_DIRECTION_DLOG = (1 << 3),
  45 };
  46
  47 // Configuration for output
  48 // console message slower than dlog about 30~40 ms
  49 #define _DEBUG_OUTPUT_DIRECTION (_DEBUG_OUTPUT_DIRECTION_DLOG)
  50
  51 #include <dlog.h>
  52
  53 #ifndef INI_PATH
  54 #define INI_PATH "/var/log"
  55 #endif
  56
  57 #ifndef _DEBUG_MODULE
  58 #define _DEBUG_MODULE "IVUG"
  59 #endif
  60
  61 #define _DEBUG_ERR_TRACE_FILE_NAME      INI_PATH"/"_DEBUG_MODULE"_FATAL.txt"
  62 #define _DEBUG_PREFIX "["_DEBUG_MODULE"]"
  63
  64 static bool bInit = false;
  65
  66 static char *get_time_string(unsigned long dwmSec)
  67 {
  68         static char buffer[30];
  69
  70         unsigned long msec=0;
  71         unsigned long sec=0;
  72         unsigned long min=0;
  73         unsigned long hour=0;
  74
  75 // Don't forget turn on compiler optimization options.
  76         sec = ( dwmSec / 1000 );
  77         msec = ( dwmSec % 1000 );
  78
  79         min = (sec / 60 );
  80         sec = (sec % 60 );
  81
  82         hour = (min / 60 );
  83         min = (min % 60 );
  84
  85         snprintf(buffer, (size_t)sizeof(buffer), "%1d:%02d:%02d.%03d",  (int)hour,(int)min,(int)sec,(int)msec);
  86
  87         return buffer;
  88 }
  89
  90
  91 /*Retrieves the number of milliseconds that have elapsed since the system was started*/
  92 static unsigned long get_sys_elapsed_time(void)
  93 {
  94         static struct timeval init_time = { 0 , 0 };
  95         static bool bFirst = false;
  96         struct timeval current_time;
  97
  98         if ( bFirst == false )
  99         {
 100                 bFirst = true;
 101                 gettimeofday(&init_time, NULL);
 102         }
 103
 104         gettimeofday(&current_time, NULL);
 105
 106         //      return  (current_time.tv_sec - init_time.tv_sec) * 1000UL +     (UINT32)((current_time.tv_usec - init_time.tv_usec) / 1000.0)   ;
 107         return  ((current_time.tv_sec * 1E3 + current_time.tv_usec / 1E3) - (init_time.tv_sec * 1E3 + init_time.tv_usec / 1E3));
 108 }
 109
 110 void _custom_debug_init()
 111 {
 112         get_sys_elapsed_time();
 113 }
 114
 115 void _custom_debug_deinit()
 116 {
 117
 118 }
 119
 120 void
 121 _custom_err_trace_write( const char *func_name, int line_num, const char *fmt, ... )
 122 {
 123         FILE *f    = NULL;
 124         va_list ap = {0};
 125         char buf[128];
 126
 127         time_t current_time;
 128         struct tm new_time;
 129
 130         current_time = time( NULL );
 131         localtime_r( &current_time, &new_time );
 132
 133         f = fopen( _DEBUG_ERR_TRACE_FILE_NAME, "a" );
 134         if( f == NULL )
 135         {
 136                 printf( "Failed to open file.[%s]\n", _DEBUG_ERR_TRACE_FILE_NAME );
 137                 return;
 138         }
 139
 140         fprintf( f, "[%.19s][%05d][%s]", asctime_r( &new_time, buf ), line_num, func_name );
 141
 142         va_start( ap, fmt );
 143         vfprintf( f, fmt, ap );
 144         va_end( ap );
 145
 146         fprintf( f, "\n" );
 147
 148         fclose( f );
 149 }
 150
 151 void
 152 _custom_err_trace_fvprintf( const char *func_name, int line_num, const char *fmt, va_list ap )
 153 {
 154         FILE *f    = NULL;
 155
 156         time_t current_time;
 157         struct tm new_time;
 158         char buf[128];
 159
 160         current_time = time( NULL );
 161         localtime_r( &current_time, &new_time );
 162
 163         f = fopen( _DEBUG_ERR_TRACE_FILE_NAME, "a" );
 164         if( f == NULL )
 165         {
 166                 printf( "Failed to open file.[%s]\n", _DEBUG_ERR_TRACE_FILE_NAME );
 167                 return;
 168         }
 169
 170         fprintf( f, "[%.19s][[F:%-16.16s L:%5d] ", asctime_r( &new_time, buf ), func_name, line_num );
 171         vfprintf( f, fmt, ap );
 172         fprintf( f, "\n" );
 173
 174         fclose( f );
 175 }
 176
 177 /*
 178 typedef enum log_priority {
 179         DLOG_UNKNOWN = 0,
 180         DLOG_DEFAULT,
 181         DLOG_VERBOSE,
 182         DLOG_DEBUG,
 183         DLOG_INFO,
 184         DLOG_WARN,
 185         DLOG_ERROR,
 186         DLOG_FATAL,
 187         DLOG_SILENT,
 188 } log_priority;
 189
 190 #define LOG(priority, tag, ...) \
 191 #define LOG_VA(priority, tag, fmt, args) \
 192 */
 193
 194 inline log_priority convert_to_dlog_priority(int msg_level)
 195 {
 196 /*
 197 DBG_MSG_LOW     = 0,
 198 DBG_MSG_MED             = 1,
 199 DBG_MSG_HIGH            = 2,
 200
 201 DBG_MSG_WARN            = 3,
 202 DBG_MSG_ERROR           = 4,
 203 DBG_MSG_FATAL           = 5,
 204
 205 DBG_MSG_CUST5           = 6,
 206 DBG_MSG_CUST6           = 7,
 207 DBG_MSG_CUST7           = 8,
 208 DBG_MSG_CUST8           = 9,
 209 DBG_MSG_CUST9           = 10,
 210 DBG_MSG_CUST10  = 11,
 211 DBG_MSG_CUST11  = 12,
 212 DBG_MSG_CUST12  = 13,
 213 DBG_MSG_CUST13  = 14,
 214 */
 215
 216         static log_priority priority[] = {
 217                 DLOG_VERBOSE,
 218                 DLOG_VERBOSE,
 219                 DLOG_WARN,              // MSG HIGH
 220                 DLOG_WARN,
 221                 DLOG_ERROR,
 222                 DLOG_FATAL,             // 5
 223         };
 224
 225         if ( msg_level <= DBG_MSG_FATAL)
 226                 return priority[msg_level];
 227
 228         return DLOG_DEBUG;
 229
 230 }
 231
 232
 233
 234 void __custom_debug_msg(debug_msg_type *debug_msg, const char *msg, ...)
 235 {
 236         va_list va;
 237
 238         static const char *level ;
 239
 240         if ( G_UNLIKELY(bInit == false) )
 241         {
 242                 _custom_debug_init();
 243                 bInit = true;
 244         }
 245
 246 #define DIRECORY_SPLITTER '/'
 247         const char*pFileName = NULL;
 248
 249         debug_msg->time = get_sys_elapsed_time();
 250
 251         pFileName  =   strrchr(debug_msg->fname, DIRECORY_SPLITTER);
 252         pFileName = (NULL == pFileName)?debug_msg->fname:(pFileName+1);
 253
 254         level = debug_msg->szlevel;
 255
 256         // File
 257         char *time_string = get_time_string(debug_msg->time);
 258
 259         va_start(va, msg);
 260
 261         if ( _DEBUG_OUTPUT_DIRECTION & _DEBUG_OUTPUT_DIRECTION_CONSOLE )
 262         {
 263
 264                 printf(_DEBUG_PREFIX"%s[F:%-16.16s L:%5d][%s:%s] ", time_string , pFileName, debug_msg->nline , debug_msg->szcategory, level );
 265                 vprintf(msg, va);
 266                 printf("\n");
 267         }
 268
 269         if ( _DEBUG_OUTPUT_DIRECTION & _DEBUG_OUTPUT_DIRECTION_DLOG )
 270         {
 271                 static char buf[2048];
 272
 273                 int i ;
 274 #ifdef PRINT_TID
 275                 i = snprintf(buf, 2048, "%s[F:%-16.16s L:%5d][%08x][%s] ",time_string , pFileName, debug_msg->nline , pthread_self(), level);
 276 #else
 277                 i = snprintf(buf, 2048, "%s[F:%-16.16s L:%5d][%s] ",time_string , pFileName, debug_msg->nline , level);
 278 #endif
 279                 vsnprintf( buf + i, 2048 - i, msg, va);
 280
 281 // Prevent Format string attack
 282                 print_log(convert_to_dlog_priority(debug_msg->msg_level), debug_msg->szcategory, "%s", buf);
 283 //              print_log(prio, _DEBUG_MODULE, "%s[F:%-16.16s L:%5d][%s:%s] ",time_string , pFileName, debug_msg->nline , szCategory[debug_msg->category], level );
 284 //              vprint_log(prio,_DEBUG_MODULE, msg, va);
 285         }
 286
 287 #if 0
 288         if ( _DEBUG_OUTPUT_DIRECTION & _DEBUG_OUTPUT_DIRECTION_FILE )
 289         {
 290                 fprintf(_DEBUG_PREFIX"%s[F:%-16.16s L:%5d][%s:%s] ",time_string , pFileName, debug_msg->nline , szCategory[debug_msg->category], level );
 291                 vprintf(msg, va);
 292                 fprintf("\n");
 293         }
 294 #endif
 295         va_end(va);
 296
 297 \r       if ( G_UNLIKELY(debug_msg->msg_level == DBG_MSG_FATAL) )
 298         {
 299                 fflush (stdout);
 300                 va_start(va, msg);
 301                 _custom_err_trace_fvprintf(pFileName, debug_msg->nline, msg, va);               // Save to file.
 302                 va_end(va);
 303                 assert(0);
 304         }
 305
 306 }
 307
 308
 309 #ifdef FMRADIO_FEATURE_ENABLE_GSTREAMER_LOGGING
 310
 311 enum {
 312         DEBUG_COLOR_DEFAULT     = 0,
 313         DEBUG_COLOR_BLACK               = 30,
 314         DEBUG_COLOR_RED                 = 31,
 315         DEBUG_COLOR_GREEN               = 32,
 316         DEBUG_COLOR_YELLOW              = 33,
 317         DEBUG_COLOR_BLUE                = 34,
 318         DEBUG_COLOR_MAGENTA     = 35,
 319         DEBUG_COLOR_CYAN                = 36,
 320         DEBUG_COLOR_WHITE               = 37,
 321 };
 322
 323 static gchar *custom_print_object(GObject *object)
 324 {
 325         if (object == NULL)
 326         {
 327                 return g_strdup("Unknown");
 328         }
 329 /*
 330         if (*(GType *) ptr == GST_TYPE_CAPS)
 331         {
 332                 return gst_caps_to_string((GstCaps *) ptr);
 333         }
 334
 335         if (*(GType *) ptr == GST_TYPE_STRUCTURE)
 336         {
 337                 return gst_structure_to_string((GstStructure *) ptr);
 338         }
 339 */
 340         if (GST_IS_PAD(object))
 341         {
 342                 return g_strdup_printf("%s:%s", GST_STR_NULL( GST_OBJECT_NAME( GST_PAD_PARENT(object))) , GST_STR_NULL( GST_PAD_NAME(object) ));
 343         }
 344
 345         if (GST_IS_ELEMENT(object))
 346         {
 347                 return g_strdup_printf("%s", GST_STR_NULL(GST_ELEMENT_NAME(object)));
 348         }
 349
 350         if (G_IS_OBJECT(object))
 351         {
 352                 return g_strdup_printf("%s(0x%0x)", G_OBJECT_TYPE_NAME(object), object);
 353         }
 354
 355         return g_strdup_printf("0x%08x", object);
 356 }
 357
 358 void custom_log_func(GstDebugCategory *category, GstDebugLevel level,
 359                 const gchar *file, const gchar *function, gint line,
 360                 GObject *object, GstDebugMessage *message, gpointer unused)
 361 {
 362         static const char *szLevel[] = {"LOW", "MED", "HIGH", "WARN", "ERROR", "FATAL"};
 363
 364         static const gint levelcolor[] = {
 365                 DEBUG_COLOR_DEFAULT,            /* GST_LEVEL_NONE */
 366                 DEBUG_COLOR_RED,                        /* GST_LEVEL_ERROR */
 367                 DEBUG_COLOR_YELLOW,             /* GST_LEVEL_WARNING */
 368                 DEBUG_COLOR_GREEN,                      /* GST_LEVEL_INFO */
 369                 DEBUG_COLOR_CYAN,                       /* GST_LEVEL_DEBUG */
 370                 DEBUG_COLOR_WHITE,                      /* GST_LEVEL_LOG */
 371         };
 372
 373         if (level > gst_debug_category_get_threshold(category))
 374                 return;
 375
 376         gchar *obj = custom_print_object(object);
 377
 378 #define DIRECORY_SPLITTER '/'
 379
 380         const char*pFileName = NULL;
 381
 382         pFileName  =   strrchr(file, DIRECORY_SPLITTER);
 383         pFileName = (NULL == pFileName) ? file:(pFileName+1);
 384
 385 // File
 386         char *time_string = get_time_string(get_sys_elapsed_time());
 387
 388         log_print_rel(LOG_CAMCORDER,LOG_CLASS_ERR,
 389                 _DEBUG_PREFIX "%s[F:%-16.16s L:%5d][%s][%s][%s] %s\n", time_string, pFileName, line,
 390                                 gst_debug_category_get_name(category), gst_debug_level_get_name(level),obj,
 391                                 gst_debug_message_get(message));
 392
 393         g_free(obj);
 394 }
 395
 396
 397 #endif // FMRADIO_FEATURE_ENABLE_GSTREAMER_LOGGING
 398
 399
 400