log.h

/*
 * Licensed to the OpenAirInterface (OAI) Software Alliance under one or more
 * contributor license agreements.  See the NOTICE file distributed with
 * this work for additional information regarding copyright ownership.
 * The OpenAirInterface Software Alliance licenses this file to You under
 * the OAI Public License, Version 1.1  (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.openairinterface.org/?page_id=698
 *
 * 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.
 *-------------------------------------------------------------------------------
 * For more information about the OpenAirInterface (OAI) Software Alliance:
 *      contact@openairinterface.org
 */

/*! \file log.h
* \brief openair log generator (OLG) for
* \author Navid Nikaein
* \date 2009 - 2014
* \version 0.5
* @ingroup util

*/

#ifndef __LOG_H__
#    define __LOG_H__

/*--- INCLUDES ---------------------------------------------------------------*/
#include <unistd.h>
#include <stdio.h>
#include <stdlib.h>
#include <string.h>
#include <syslog.h>
#include <assert.h>
#include <sys/types.h>
#include <sys/stat.h>
#include <fcntl.h>
#include <stdarg.h>
#include <time.h>
#include <stdint.h>
#ifndef __STDC_FORMAT_MACROS
#define __STDC_FORMAT_MACROS
#endif
#include <inttypes.h>
#ifndef _GNU_SOURCE
#define _GNU_SOURCE
#endif
#include <pthread.h>
#include "T.h"
/*----------------------------------------------------------------------------*/

#ifdef __cplusplus
extern "C" {
#endif

/** @defgroup _LOG LOG Generator
 * @{*/
/* @}*/

/** @defgroup _macro Macro Definition
 *  @ingroup _LOG
 *  @brief these macros are used in the code of LOG
 * @{*/
/* @}*/

/** @defgroup _max_length Maximum Length of LOG
 *  @ingroup _macro
 *  @brief the macros that describe the maximum length of LOG
 * @{*/

#define MAX_LOG_TOTAL 1500 /*!< \brief the maximum length of a log */
/* @}*/

/** @defgroup _log_level Message levels defined by LOG
 *  @ingroup _macro
 *  @brief LOG defines 9 levels of messages for users. Importance of these levels decrease gradually from 0 to 8
 * @{*/

# define  OAILOG_ERR     0 /*!< \brief critical error conditions, impact on "must have" fuctinalities */
# define  OAILOG_FILE    1 /*!< \brief important informational messages, but everything OK  */
# define  OAILOG_WARNING 2 /*!< \brief warning conditions, shouldn't happen but doesn't impact "must have" functionalities */
# define  OAILOG_INFO    3 /*!< \brief informational messages most people don't need, shouldn't impact real-time behavior */
# define  OAILOG_DEBUG   4 /*!< \brief first level debug-level messages, for developers , may impact real-time behavior */
# define  OAILOG_TRACE   5 /*!< \brief  second level debug-level messages, for developers ,likely impact real-time behavior*/

#define NUM_LOG_LEVEL 6 /*!< \brief the number of message levels users have with LOG */
/* @}*/


/** @defgroup _log_format Defined log format
 *  @ingroup _macro
 *  @brief Macro of log formats defined by LOG
 * @{*/

/* .log_format = 0x13 uncolored standard messages
 * .log_format = 0x93 colored standard messages */
/* keep white space in first position; switching it to 0 allows colors to be disabled*/
#define LOG_RED "\033[1;31m"  /*!< \brief VT100 sequence for bold red foreground */
#define LOG_GREEN "\033[32m"  /*!< \brief VT100 sequence for green foreground */
#define LOG_ORANGE "\033[93m"   /*!< \brief VT100 sequence for orange foreground */
#define LOG_BLUE "\033[34m" /*!< \brief VT100 sequence for blue foreground */
#define LOG_CYBL "\033[40;36m"  /*!< \brief VT100 sequence for cyan foreground on black background */
#define LOG_RESET "\033[0m" /*!< \brief VT100 sequence for reset (black) foreground */
/* @}*/


/** @defgroup _syslog_conf Macros for write in syslog.conf
 *  @ingroup _macro
 *  @brief Macros used to write lines (local/remote) in syslog.conf
 * @{*/


#define FLAG_NOCOLOR   0x0001  /*!< \brief use colors in log messages, depending on level */
#define FLAG_THREAD    0x0008  /*!< \brief display thread name in log messages */
#define FLAG_LEVEL     0x0010  /*!< \brief display log level in log messages */
#define FLAG_FUNCT     0x0020
#define FLAG_FILE_LINE 0x0040
#define FLAG_TIME      0x0100

#define SET_LOG_OPTION(O)   g_log->flag = (g_log->flag | O)
#define CLEAR_LOG_OPTION(O) g_log->flag = (g_log->flag & (~O))

/** @defgroup macros to identify a debug entity
 *  @ingroup each macro is a bit mask where the unique bit set identifies an entity to be debugged
 *            it allows to dynamically activate or not blocks of code 
 *  @brief 
 * @{*/
#define DEBUG_PRACH        (1<<0)
#define DEBUG_RU           (1<<1)
#define DEBUG_UE_PHYPROC   (1<<2)
#define DEBUG_LTEESTIM     (1<<3)
#define DEBUG_CTRLSOCKET   (1<<10)
#define UE_TIMING          (1<<20)

#define SET_LOG_DEBUG(O)   g_log->debug_mask = (g_log->debug_mask | O)
#define CLEAR_LOG_DEBUG(O) g_log->debug_mask = (g_log->debug_mask & (~O))

#define SET_LOG_MATLAB(O)   g_log->matlab_mask = (g_log->matlab_mask | O)
#define CLEAR_LOG_MATLAB(O) g_log->matlab_mask = (g_log->matlab_mask & (~O))



typedef enum {
    MIN_LOG_COMPONENTS = 0,
    PHY = MIN_LOG_COMPONENTS,
    MAC,
    SIM,
    OCG,
    OMG,
    OPT,
    OTG,
    OTG_LATENCY,
    OTG_LATENCY_BG,
    OTG_GP,
    OTG_GP_BG,
    OTG_JITTER,
    RLC,
    PDCP,
    RRC,
    NAS,
    PERF,
    OIP,
    CLI,
    MSC,
    OCM,
    UDP_,
    GTPU,
    SPGW,
    S1AP,
    SCTP,
    HW,
    OSA,
    RAL_ENB,
    RAL_UE,
    ENB_APP,
    FLEXRAN_AGENT,
    TMR,
    USIM,
    LOCALIZE,
    RRH,
    X2AP,
    LOADER,
    MAX_LOG_PREDEF_COMPONENTS,
}
comp_name_t;

#define MAX_LOG_DYNALLOC_COMPONENTS 20
#define MAX_LOG_COMPONENTS (MAX_LOG_PREDEF_COMPONENTS + MAX_LOG_DYNALLOC_COMPONENTS)


typedef struct {
    char *name; /*!< \brief string name of item */
    int value;  /*!< \brief integer value of mapping */
} mapping;

typedef int(*log_write_func_t)(FILE *stream, const char *format, va_list ap );

typedef struct  {
    const char       *name;
    int              level;
    int              flag;
    int              interval;
    int              filelog;
    char             *filelog_name;
    FILE             *stream;
    log_write_func_t fwrite;
    /* SR: make the log buffer component relative */
    char             log_buffer[MAX_LOG_TOTAL];
} log_component_t;


typedef struct {
    log_component_t         log_component[MAX_LOG_COMPONENTS];
    char*                   level2string[NUM_LOG_LEVEL];
    int                     onlinelog;
    int                     flag;
    int                     filelog;
    char*                   filelog_name;
    uint64_t                debug_mask;
    uint64_t                matlab_mask;
} log_t;


#if defined(ENABLE_ITTI)
typedef enum log_instance_type_e {
    LOG_INSTANCE_UNKNOWN,
    LOG_INSTANCE_ENB,
    LOG_INSTANCE_UE,
} log_instance_type_t;

void log_set_instance_type (log_instance_type_t instance);
#endif


#ifdef LOG_MAIN
log_t *g_log;
#else
#ifdef __cplusplus
   extern "C" {
#endif
extern log_t *g_log;
#ifdef __cplusplus
}
#endif
#endif
/*--- INCLUDES ---------------------------------------------------------------*/
#    include "log_if.h"
/*----------------------------------------------------------------------------*/
int  logInit (void);
void logRecord_mt(const char *file, const char *func, int line,int comp, int level, const char *format, ...) __attribute__ ((format (printf, 6, 7)));

int  set_log(int component, int level, int interval);
void set_glog(int level);

void set_glog_onlinelog(int enable);
void set_glog_filelog(int enable);
void set_component_filelog(int comp);

int  map_str_to_int(mapping *map, const char *str);
char *map_int_to_str(mapping *map, int val);
void logClean (void);
int  is_newline( char *str, int size);

int register_log_component(char *name, char *fext, int compidx);

/* @}*/

/*!\fn int32_t write_file_matlab(const char *fname, const char *vname, void *data, int length, int dec, char format);
\brief Write output file from signal data
@param fname output file name
@param vname  output vector name (for MATLAB/OCTAVE)
@param data   point to data
@param length length of data vector to output
@param dec    decimation level
@param format data format (0 = real 16-bit, 1 = complex 16-bit,2 real 32-bit, 3 complex 32-bit,4 = real 8-bit, 5 = complex 8-bit)
*/
int32_t write_file_matlab(const char *fname, const char *vname, void *data, int length, int dec, char format);

/*----------------macro definitions for reading log configuration from the config module */
#define CONFIG_STRING_LOG_PREFIX                           "log_config"

#define LOG_CONFIG_STRING_GLOBAL_LOG_LEVEL                 "global_log_level"
#define LOG_CONFIG_STRING_GLOBAL_LOG_ONLINE                "global_log_online"
#define LOG_CONFIG_STRING_GLOBAL_LOG_INFILE                "global_log_infile"
#define LOG_CONFIG_STRING_GLOBAL_LOG_OPTIONS               "global_log_options"

#define LOG_CONFIG_LEVEL_FORMAT                            "%s_log_level"
#define LOG_CONFIG_LOGFILE_FORMAT                          "%s_log_infile"
#define LOG_CONFIG_DEBUG_FORMAT                            "%s_debug"
#define LOG_CONFIG_MATLAB_FORMAT                           "%s_matlab"

#define LOG_CONFIG_HELP_OPTIONS      " list of comma separated options to enable log module behavior. Available options: \n"\
                                     " nocolor:   disable color usage in log messages\n"\
				     " level:     add log level indication in log messages\n"\
				     " thread:    add threads names in log messages\n"
				     


                   
/*------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------*/
/*                                       LOG globalconfiguration parameters										                                                */
/*   optname                            help                                                paramflags       XXXptr	                   defXXXval				      type	 numelt	*/
/*------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------*/
#define LOG_GLOBALPARAMS_DESC { \
{LOG_CONFIG_STRING_GLOBAL_LOG_LEVEL,    "Default log level for all componemts\n",              0,  	      strptr:(char **)&gloglevel,    defstrval:log_level_names[2].name,    TYPE_STRING,    0}, \
{LOG_CONFIG_STRING_GLOBAL_LOG_ONLINE,   "Default console output option, for all components\n", 0,  	      iptr:&(g_log->onlinelog),      defintval:1,                          TYPE_INT,       0}, \
{LOG_CONFIG_STRING_GLOBAL_LOG_OPTIONS,  LOG_CONFIG_HELP_OPTIONS,                               0,  	      strlistptr:NULL,               defstrlistval:NULL,                   TYPE_STRINGLIST,0} \
}

#define LOG_OPTIONS_IDX   2
/*----------------------------------------------------------------------------------*/
/** @defgroup _debugging debugging macros
 *  @ingroup _macro
 *  @brief Macro used to call logIt function with different message levels
 * @{*/

// debugging macros(g_log->log_component[component].interval?logRecord_mt(__FILE__, __FUNCTION__, __LINE__, component, level, format, ##args):(void)0)
#  if T_TRACER 
     /* per component, level dependant macros */
#    define LOG_I(c, x...) do { if (T_stdout) { if( g_log->log_component[c].level >= OAILOG_INFO   ) logRecord_mt(__FILE__, __FUNCTION__, __LINE__,c, OAILOG_INFO, x)    ;} else { T(T_LEGACY_ ## c ## _INFO, T_PRINTF(x))    ;}} while (0) 
#    define LOG_W(c, x...) do { if (T_stdout) { if( g_log->log_component[c].level >= OAILOG_WARNING) logRecord_mt(__FILE__, __FUNCTION__, __LINE__,c, OAILOG_WARNING, x) ;} else { T(T_LEGACY_ ## c ## _WARNING, T_PRINTF(x)) ;}} while (0) 
#    define LOG_E(c, x...) do { if (T_stdout) { if( g_log->log_component[c].level >= OAILOG_ERR    ) logRecord_mt(__FILE__, __FUNCTION__, __LINE__,c, OAILOG_ERR, x)     ;} else { T(T_LEGACY_ ## c ## _ERROR, T_PRINTF(x))   ;}} while (0) 
#    define LOG_D(c, x...) do { if (T_stdout) { if( g_log->log_component[c].level >= OAILOG_DEBUG  ) logRecord_mt(__FILE__, __FUNCTION__, __LINE__,c, OAILOG_DEBUG, x)   ;} else { T(T_LEGACY_ ## c ## _DEBUG, T_PRINTF(x))   ;}} while (0) 
#    define LOG_T(c, x...) do { if (T_stdout) { if( g_log->log_component[c].level >= OAILOG_TRACE  ) logRecord_mt(__FILE__, __FUNCTION__, __LINE__,c, OAILOG_TRACE, x)   ;} else { T(T_LEGACY_ ## c ## _TRACE, T_PRINTF(x))   ;}} while (0) 
#    define LOG_F(c, x...) do { if (T_stdout) { if( g_log->log_component[c].level >= OAILOG_FILE   ) logRecord_mt(__FILE__, __FUNCTION__, __LINE__,c, OAILOG_FILE, x)  ;}}   while (0)  /* */
#    define nfapi_log(FILE, FNC, LN, COMP, LVL, F...)  do { if (T_stdout) { logRecord_mt(__FILE__, __FUNCTION__, __LINE__,COMP, LVL, F)  ;}}   while (0)  /* */
     /* bitmask dependant macros, to isolate debugging code */
#    define LOG_DEBUG_BEGIN(D) if (g_log->debug_mask & D) {
#    define LOG_DEBUG_END   }
     /* bitmask dependant macros, to generate matlab files */
#    define LOG_M_BEGIN(D) if (g_log->matlab_mask & D) {
#    define LOG_M_END   }
#    define LOG_M(file, vector, data, len, dec, format) do { write_file_matlab(file, vector, data, len, dec, format);} while(0)/* */
     /* define variable only used in LOG macro's */
#    define LOG_VAR(A,B) A B
#  else /* T_TRACER: remove all debugging and tracing messages, except errors */
#    define LOG_I(c, x...) /* */
#    define LOG_W(c, x...) /* */
#    define LOG_E(c, x...) /* */
#    define LOG_D(c, x...) /* */
#    define LOG_T(c, x...) /* */
#    define LOG_F(c, x...) /* */
#    define nfapi_log(FILE, FNC, LN, COMP, LVL, FMT...) 
#    define LOG_DEBUG_BEGIN(D) if (0) {
#    define LOG_DEBUG_END   }
#    define LOG_M_BEGIN(D) if (0) {
#    define LOG_M_END   }
#    define LOG_M(file, vector, data, len, dec, format) 
#    define LOG_VAR(A,B)
#  endif /* T_TRACER */
/* avoid warnings for variables only used in LOG macro's but set outside debug section */
#define LOG_USEDINLOG_VAR(A,B) __attribute__((unused)) A B 

/* unfiltered macros, usefull for simulators or messages at init time, before log is configured */
#define LOG_UM(file, vector, data, len, dec, format) do { write_file_matlab(file, vector, data, len, dec, format);} while(0)

#define LOG_UI(c, x...) do {logRecord_mt(__FILE__, __FUNCTION__, __LINE__,c, OAILOG_INFO, x) ; } while(0)
/* @}*/


/** @defgroup _useful_functions useful functions in LOG
 *  @ingroup _macro
 *  @brief Macro of some useful functions defined by LOG
 * @{*/
#define LOG_ENTER(c) do {LOG_T(c, "Entering\n");}while(0) /*!< \brief Macro to log a message with severity DEBUG when entering a function */
#define LOG_EXIT(c) do {LOG_T(c,"Exiting\n"); return;}while(0)  /*!< \brief Macro to log a message with severity TRACE when exiting a function */
#define LOG_RETURN(c,x) do {uint32_t __rv;__rv=(unsigned int)(x);LOG_T(c,"Returning %08x\n", __rv);return((typeof(x))__rv);}while(0)  /*!< \brief Macro to log a function exit, including integer value, then to return a value to the calling function */
/* @}*/

static __inline__ uint64_t rdtsc(void) {
  uint32_t a, d;
  __asm__ volatile ("rdtsc" : "=a" (a), "=d" (d));
  return (((uint64_t)d)<<32) | ((uint64_t)a);
}

#define DEBUG_REALTIME 1
#if DEBUG_REALTIME

extern double cpuf;

static inline uint64_t checkTCPU(int timeout, char * file, int line) {
    static uint64_t __thread lastCPUTime=0;
    static uint64_t __thread last=0;
    uint64_t cur=rdtsc();
    struct timespec CPUt;
    clock_gettime(CLOCK_THREAD_CPUTIME_ID, &CPUt);
    uint64_t CPUTime=CPUt.tv_sec*1000*1000+CPUt.tv_nsec/1000;
    double microCycles=(double)(cpuf*1000);
    int duration=(int)((cur-last)/microCycles);
    if ( last!=0 && duration > timeout ) {
      //struct timespec ts;
      //clock_gettime(CLOCK_MONOTONIC, &ts);
      printf("%s:%d lte-ue delay %d (exceed %d), CPU for this period: %lld\n", file, line,
               duration, timeout, (long long)CPUTime-lastCPUTime );
    }
    last=cur;
    lastCPUTime=CPUTime;
    return cur;
}

static inline unsigned long long checkT(int timeout, char * file, int line) {
    static unsigned long long __thread last=0;
    unsigned long long cur=rdtsc();
    int microCycles=(int)(cpuf*1000);
    int duration=(int)((cur-last)/microCycles);
    if ( last!=0 && duration > timeout )
        printf("%s:%d lte-ue delay %d (exceed %d)\n", file, line,
               duration, timeout);
    last=cur;
    return cur;
}

typedef struct m {
    uint64_t iterations;
    uint64_t sum;
    uint64_t maxArray[11];
} Meas;

static inline void printMeas(char * txt, Meas *M, int period) {
    if (M->iterations%period == 0 ) {
        char txt2[512];
        sprintf(txt2,"%s avg=%" PRIu64 " iterations=%" PRIu64 " max=%" 
                PRIu64 ":%" PRIu64 ":%" PRIu64 ":%" PRIu64 ":%" PRIu64 ":%" PRIu64 ":%" PRIu64 ":%" PRIu64 ":%" PRIu64 ":%" PRIu64 "\n",
                txt,
                M->sum/M->iterations,
                M->iterations,
                M->maxArray[1],M->maxArray[2], M->maxArray[3],M->maxArray[4], M->maxArray[5], 
                M->maxArray[6],M->maxArray[7], M->maxArray[8],M->maxArray[9],M->maxArray[10]);
#if DISABLE_LOG_X
        printf("%s",txt2);
#else
        LOG_W(PHY, "%s",txt2);
#endif
    }
}

static inline int cmpint(const void* a, const void* b) {
    uint64_t* aa=(uint64_t*)a;
    uint64_t* bb=(uint64_t*)b;
    return (int)(*aa-*bb);
}

static inline void updateTimes(uint64_t start, Meas *M, int period, char * txt) {
    if (start!=0) {
        uint64_t end=rdtsc();
        long long diff=(end-start)/(cpuf*1000);
        M->maxArray[0]=diff;
        M->sum+=diff;
        M->iterations++;
        qsort(M->maxArray, 11, sizeof(uint64_t), cmpint);
        printMeas(txt,M,period);
    }
}

#define check(a) do { checkT(a,__FILE__,__LINE__); } while (0)
#define checkcpu(a) do { checkTCPU(a,__FILE__,__LINE__); } while (0)
#define initRefTimes(a) static __thread Meas a= {0}
#define pickTime(a) uint64_t a=rdtsc()
#define readTime(a) a
#define initStaticTime(a) static __thread uint64_t a={0}
#define pickStaticTime(a) do { a=rdtsc(); } while (0)

#else
#define check(a) do {} while (0)
#define checkcpu(a) do {} while (0)
#define initRefTimes(a) do {} while (0)
#define initStaticTime(a) do {} while (0)
#define pickTime(a) do {} while (0)
#define readTime(a) 0
#define pickStaticTime(a) do {} while (0)
#define updateTimes(a,b,c,d) do {} while (0)
#define printMeas(a,b,c) do {} while (0)
#endif

#ifdef __cplusplus
}
#endif

#endif