log.h 14.5 KB
Newer Older
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
/*
 * 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.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.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
 */
21
22
23
24

/*! \file log.h
* \brief openair log generator (OLG) for
* \author Navid Nikaein
nikaeinn's avatar
nikaeinn committed
25
* \date 2009 - 2014
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
* \version 0.5
* @ingroup util

*/

#ifndef __LOG_H__
#    define __LOG_H__

/*--- INCLUDES ---------------------------------------------------------------*/
#ifdef USER_MODE
#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>
laurent's avatar
laurent committed
46
47
48
#include <time.h>
#include <stdint.h>
#include <inttypes.h>
laurent's avatar
laurent committed
49
#ifndef _GNU_SOURCE
50
#define _GNU_SOURCE
laurent's avatar
laurent committed
51
#endif
52
#include <pthread.h>
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
75
76
#else
#include "rtai_fifos.h"
#endif

/*----------------------------------------------------------------------------*/

#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
 * @{*/
77
#define MAX_LOG_ITEM 100 /*!< \brief the maximum length of a LOG item, what is LOG_ITEM ??? */
78
79
80
81
82
83
84
85
#define MAX_LOG_INFO 1000 /*!< \brief the maximum length of a 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
 * @{*/
86
87
88
89
90
91
92
93
94
95
96
# define  LOG_EMERG 0 /*!< \brief system is unusable */
# define  LOG_ALERT 1 /*!< \brief action must be taken immediately */
# define  LOG_CRIT  2 /*!< \brief critical conditions */
# define  LOG_ERR   3 /*!< \brief error conditions */
# define  LOG_WARNING 4 /*!< \brief warning conditions */
# define  LOG_NOTICE  5 /*!< \brief normal but significant condition */
# define  LOG_INFO  6 /*!< \brief informational */
# define  LOG_DEBUG 7 /*!< \brief debug-level messages */
# define  LOG_FILE        8 /*!< \brief message sequence chart -level  */
# define  LOG_TRACE 9 /*!< \brief trace-level messages */
#define NUM_LOG_LEVEL  10 /*!< \brief the number of message levels users have with LOG */
97
98
99
/* @}*/


laurent's avatar
laurent committed
100
101
102
103
104
105
106
107
108
109
110
111
112
113
114
115
116
117
118
119
120
121
122
123
124
125
126
127
128
129
130
131
132
133
134
135
136
137
138
139
140
141
142
143
144
145
146
147
148
149
150
151
152
153
154
155
156
157
158
159
160
161
162
163
164
165
166
167
168
169
170
171
172
173
174
175
176
177
178
179
180
181
182
183
184
185
186
187
188
189
190
191
192
193
194
195
196
197
198
199
200
201
202
203
204
205
206
207
208
209
210
211
212
213
214
215
216
217
218
219
220
221
222
223
224
225
226
227
228
229
230
231
232
233
234
235
236
237
238
239
240
241
242
243
244
245
246
247
248
249
250
251
252
253
254
255
256
257
258
259
260
261
262
263
264
265
266
267
268
269
270
271
272
273
274
275
276
/** @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 */

#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 LOG_LOCAL      0x01
#define LOG_REMOTE     0x02

#define FLAG_COLOR     0x001  /*!< \brief defaults */
#define FLAG_PID       0x002  /*!< \brief defaults */
#define FLAG_COMP      0x004
#define FLAG_THREAD    0x008  /*!< \brief all : 255/511 */
#define FLAG_LEVEL     0x010
#define FLAG_FUNCT     0x020
#define FLAG_FILE_LINE 0x040
#define FLAG_TIME      0x100

#define LOG_NONE        0x00
#define LOG_LOW         0x5
#define LOG_MED         0x15
#define LOG_HIGH        0x35
#define LOG_FULL        0x75

#define OAI_OK 0    /*!< \brief all ok */
#define OAI_ERR 1   /*!< \brief generic error */
#define OAI_ERR_READ_ONLY 2 /*!< \brief tried to write to read-only item */
#define OAI_ERR_NOTFOUND 3  /*!< \brief something wasn't found */
/* @}*/


//static char *log_level_highlight_start[] = {LOG_RED, LOG_RED, LOG_RED, LOG_RED, LOG_BLUE, "", "", "", LOG_GREEN}; /*!< \brief Optional start-format strings for highlighting */

//static char *log_level_highlight_end[]   = {LOG_RESET, LOG_RESET, LOG_RESET, LOG_RESET, LOG_RESET, "", "", "", LOG_RESET};  /*!< \brief Optional end-format strings for highlighting */

typedef enum {
    MIN_LOG_COMPONENTS = 0,
    PHY = MIN_LOG_COMPONENTS,
    MAC,
    EMU,
    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,
    MAX_LOG_COMPONENTS,
}
comp_name_t;

//#define msg printf

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


typedef struct  {
    const char *name;
    int         level;
    int         flag;
    int         interval;
    int         fd;
    int         filelog;
    char       *filelog_name;

    /* SR: make the log buffer component relative */
    char        log_buffer[MAX_LOG_TOTAL];
} log_component_t;

typedef struct  {
    unsigned int remote_ip;
    unsigned int audit_ip;
    int  remote_level;
    int  facility;
    int  audit_facility;
    int  format;
} log_config_t;


typedef struct {
    log_component_t         log_component[MAX_LOG_COMPONENTS];
    log_config_t            config;
    char*                   level2string[NUM_LOG_LEVEL];
    int                     level;
    int                     onlinelog;
    int                     flag;
    int                     syslog;
    int                     filelog;
    char*                   filelog_name;
} log_t;

typedef struct LOG_params {
    const char *file;
    const char *func;
    int line;
    int comp;
    int level;
    const char *format;
    char l_buff_info [MAX_LOG_INFO];
    int len;
} LOG_params;

#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


/*--- 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, ...);
void logRecord(const char *file, const char *func, int line,int comp, int level, const char *format, ...);
int  set_comp_log(int component, int level, int verbosity, int interval);
int  set_log(int component, int level, int interval);
void set_glog(int level, int verbosity);
void set_log_syslog(int enable);
void set_log_onlinelog(int enable);
void set_log_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);
void *log_thread_function(void * list);

277
278
279
280
281
/** @defgroup _logIt logIt function
 *  @ingroup _macro
 *  @brief Macro used to call tr_log_full_ex with file, function and line information
 * @{*/
#ifdef USER_MODE
282
//#define logIt(component, level, format, args...) do {logRecord(__FILE__, __FUNCTION__, __LINE__, component, level, format, ##args);} while(0);
283
284
285
286
#ifdef LOG_NO_THREAD
#define logIt(component, level, format, args...) logRecord_mt(__FILE__, __FUNCTION__, __LINE__, component, level, format, ##args)
#else //default
#define logIt(component, level, format, args...) logRecord(__FILE__, __FUNCTION__, __LINE__, component, level, format, ##args)
287
#endif
288
289
290
#else
#ifdef LOG_NO_THREAD
#define logIt(component, level, format, args...) logRecord_mt(NULL, __FUNCTION__, __LINE__, component, level, format, ##args)
291
#else // default
292
293
294
295
296
297
298
299
300
301
302
303
304
#define logIt(component, level, format, args...) logRecord(NULL, __FUNCTION__, __LINE__, component, level, format, ##args)
#endif
#endif
/* @}*/


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

// debugging macros
#ifdef USER_MODE
305
306
307
308
309
310
311
312
313
314
315
316
317
318
319
320
321
322
323
324
325
326
327
328
329
330
331
332
333
334
335
336
337
338
#  if T_TRACER
#    include "T.h"
#    define LOG_I(c, x...) T(T_LEGACY_ ## c ## _INFO, T_PRINTF(x))
#    define LOG_W(c, x...) T(T_LEGACY_ ## c ## _WARNING, T_PRINTF(x))
#    define LOG_E(c, x...) T(T_LEGACY_ ## c ## _ERROR, T_PRINTF(x))
#    define LOG_D(c, x...) T(T_LEGACY_ ## c ## _DEBUG, T_PRINTF(x))
#    define LOG_T(c, x...) T(T_LEGACY_ ## c ## _TRACE, T_PRINTF(x))
#    define LOG_G(c, x...) /* */
#    define LOG_A(c, x...) /* */
#    define LOG_C(c, x...) /* */
#    define LOG_N(c, x...) /* */
#    define LOG_F(c, x...) /* */
#  else /* T_TRACER */
#    define LOG_G(c, x...) logIt(c, LOG_EMERG, x)
#    define LOG_A(c, x...) logIt(c, LOG_ALERT, x)
#    define LOG_C(c, x...) logIt(c, LOG_CRIT,  x)
#    define LOG_E(c, x...) logIt(c, LOG_ERR, x)
#    define LOG_W(c, x...) logIt(c, LOG_WARNING, x)
#    define LOG_N(c, x...) logIt(c, LOG_NOTICE, x)
#    define LOG_I(c, x...) logIt(c, LOG_INFO, x)
#    define LOG_D(c, x...) logIt(c, LOG_DEBUG, x)
#    define LOG_F(c, x...) logIt(c, LOG_FILE, x)  // log to a file, useful for the MSC chart generation
#    define LOG_T(c, x...) logIt(c, LOG_TRACE, x)
#  endif /* T_TRACER */
#else /* USER_MODE */
#  define LOG_G(c, x...) printk(x)
#  define LOG_A(c, x...) printk(x)
#  define LOG_C(c, x...) printk(x)
#  define LOG_E(c, x...) printk(x)
#  define LOG_W(c, x...) printk(x)
#  define LOG_N(c, x...) printk(x)
#  define LOG_I(c, x...) printk(x)
#  define LOG_D(c, x...) printk(x)
#  define LOG_T(c, x...) printk(x)
339
340
341
342
343
344
345
346
#endif
/* @}*/


/** @defgroup _useful_functions useful functions in LOG
 *  @ingroup _macro
 *  @brief Macro of some useful functions defined by LOG
 * @{*/
347
348
349
#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 */
350
351
/* @}*/

laurent's avatar
laurent committed
352
353
354
355
static __inline__ uint64_t rdtsc(void) {
  uint64_t a, d;
  __asm__ volatile ("rdtsc" : "=a" (a), "=d" (d));
  return (d<<32) | a;
356
}
357

laurent's avatar
laurent committed
358
359
#define DEBUG_REALTIME 1
#if DEBUG_REALTIME
360

laurent's avatar
laurent committed
361
extern double cpuf;
362

laurent's avatar
laurent committed
363
364
365
366
367
368
369
370
371
372
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 ) {
Thomas Laurent's avatar
Thomas Laurent committed
373
374
375
376
      //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 );
laurent's avatar
laurent committed
377
378
379
380
381
382
    }
    last=cur;
    lastCPUTime=CPUTime;
    return cur;
}

laurent's avatar
laurent committed
383
384
385
386
387
388
389
390
391
392
393
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;
}
394

laurent's avatar
laurent committed
395
typedef struct m {
laurent's avatar
laurent committed
396
397
398
    uint64_t iterations;
    uint64_t sum;
    uint64_t maxArray[11];
laurent's avatar
laurent committed
399
400
401
402
403
} Meas;

static inline void printMeas(char * txt, Meas *M, int period) {
    if (M->iterations%period == 0 ) {
        char txt2[512];
laurent's avatar
laurent committed
404
405
406
407
408
409
410
        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]);
411
        LOG_W(PHY,"%s",txt2);
laurent's avatar
laurent committed
412
413
    }
}
414

laurent's avatar
laurent committed
415
static inline int cmpint(const void* a, const void* b) {
laurent's avatar
laurent committed
416
417
    uint64_t* aa=(uint64_t*)a;
    uint64_t* bb=(uint64_t*)b;
laurent's avatar
laurent committed
418
419
    return (int)(*aa-*bb);
}
420

laurent's avatar
laurent committed
421
static inline void updateTimes(uint64_t start, Meas *M, int period, char * txt) {
laurent's avatar
laurent committed
422
    if (start!=0) {
laurent's avatar
laurent committed
423
        uint64_t end=rdtsc();
laurent's avatar
laurent committed
424
425
426
427
        long long diff=(end-start)/(cpuf*1000);
        M->maxArray[0]=diff;
        M->sum+=diff;
        M->iterations++;
laurent's avatar
laurent committed
428
        qsort(M->maxArray, 11, sizeof(uint64_t), cmpint);
laurent's avatar
laurent committed
429
430
431
        printMeas(txt,M,period);
    }
}
432

laurent's avatar
laurent committed
433
434
#define check(a) do { checkT(a,__FILE__,__LINE__); } while (0)
#define checkcpu(a) do { checkTCPU(a,__FILE__,__LINE__); } while (0)
laurent's avatar
laurent committed
435
#define initRefTimes(a) static __thread Meas a= {0}
laurent's avatar
laurent committed
436
#define pickTime(a) uint64_t a=rdtsc()
laurent's avatar
laurent committed
437
#define readTime(a) a
laurent's avatar
laurent committed
438
439
#define initStaticTime(a) static __thread uint64_t a={0}
#define pickStaticTime(a) do { a=rdtsc(); } while (0)
440

laurent's avatar
laurent committed
441
442
#else
#define check(a) do {} while (0)
laurent's avatar
laurent committed
443
#define checkcpu(a) do {} while (0)
laurent's avatar
laurent committed
444
445
446
447
448
449
450
#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)
451
452
#endif

453
454
455
456
457
458
459
#ifdef __cplusplus
}
#endif

#endif