Merge remote-tracking branch 'origin/episys-merge-nsa' into integration_2021_wk51_d

common/utils/LOG/log.c

@@ -43,6 +43,8 @@
 #include <string.h>
 #include <linux/prctl.h>
 #include "common/config/config_userapi.h"
+#include <time.h>
+#include <sys/time.h>
 
 // main log variables
 
@@ -508,6 +510,53 @@ char *log_getthreadname(char *threadname,
   }
 }
 
+#if LOG_MINIMAL
+#include <sys/syscall.h>
+void logMinimal(int comp, int level, const char *format, ...)
+{
+    struct timespec ts;
+    if (clock_gettime(CLOCK_MONOTONIC, &ts) == -1)
+        abort();
+
+    char buf[MAX_LOG_TOTAL];
+    int n = snprintf(buf, sizeof(buf), "%lu.%06lu %08lx [%s] %c ",
+                     ts.tv_sec,
+                     ts.tv_nsec / 1000,
+                     syscall(__NR_gettid),
+                     g_log->log_component[comp].name,
+                     level);
+    if (n < 0 || n >= sizeof(buf))
+    {
+        fprintf(stderr, "%s: n=%d\n", __func__, n);
+        return;
+    }
+
+    va_list args;
+    va_start(args, format);
+    int m = vsnprintf(buf + n, sizeof(buf) - n, format, args);
+    va_end(args);
+
+    if (m < 0)
+    {
+        fprintf(stderr, "%s: n=%d m=%d\n", __func__, n, m);
+        return;
+    }
+
+    int len = n + m;
+    if (len > sizeof(buf) - 1)
+    {
+        len = sizeof(buf) - 1;
+    }
+    if (buf[len - 1] != '\n')
+    {
+        buf[len++] = '\n';
+    }
+
+    __attribute__((unused))
+    int unused = write(STDOUT_FILENO, buf, len);
+}
+#endif // LOG_MINIMAL
+
 static int log_header(char *log_buffer,
 		              int buffsize,
 					  int comp,

common/utils/LOG/log.h

@@ -54,6 +54,12 @@
 #include "T.h"
 #include <common/utils/utils.h>
 /*----------------------------------------------------------------------------*/
+#include <assert.h>
+#ifdef NDEBUG
+#warning assert is disabled
+#endif
+#define NUM_ELEMENTS(ARRAY) (sizeof(ARRAY) / sizeof(ARRAY[0]))
+#define CHECK_INDEX(ARRAY, INDEX) assert((INDEX) < NUM_ELEMENTS(ARRAY))
 
 #ifdef __cplusplus
 extern "C" {
@@ -402,10 +408,32 @@ int32_t write_file_matlab(const char *fname, const char *vname, void *data, int
 #define LOG_DUMP_DOUBLE     1
 // debugging macros
 #define LOG_F  LOG_I           /* because  LOG_F was originaly to dump a message or buffer but is also used as a regular level...., to dump use LOG_DUMPMSG */
+
+#define LOG_MINIMAL 1 /* 1 for minimal logging: E, W and A */
+
+#if LOG_MINIMAL
+
+  void logMinimal(int component, int level, const char *format, ...) __attribute__((format(printf, 3, 4)));
+# define LOG_E(COMPONENT, ...) do if (1) logMinimal(COMPONENT, 'E', __VA_ARGS__); while (0)
+# define LOG_W(COMPONENT, ...) do if (1) logMinimal(COMPONENT, 'W', __VA_ARGS__); while (0)
+# define LOG_A(COMPONENT, ...) do if (1) logMinimal(COMPONENT, 'A', __VA_ARGS__); while (0) /* logs intended for analysis */
+# define LOG_I(COMPONENT, ...) do if (1) logMinimal(COMPONENT, 'I', __VA_ARGS__); while (0)
+# define LOG_D(COMPONENT, ...) do if (0) logMinimal(COMPONENT, 'D', __VA_ARGS__); while (0)
+# define LOG_T(COMPONENT, ...) do if (0) logMinimal(COMPONENT, 'T', __VA_ARGS__); while (0)
+
+# define LOG_M(FILE, VECTOR, DATA, LEN, DEC, FORMAT) ((void) 0)
+# define LOG_DUMPFLAG(D) 0
+# define LOG_DEBUGFLAG(D) 0
+# define LOG_DUMPMSG(C, B, S, X...) ((void) 0)
+# define VLOG(C, L, F, ARGS) ((void) 0)
+
+#else // LOG_MINIMAL
+
 #  if T_TRACER
 /* per component, level dependent macros */
 #    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_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_A LOG_I
 #    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_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)
@@ -425,6 +453,7 @@ int32_t write_file_matlab(const char *fname, const char *vname, void *data, int
 #    define LOG_E(c, x...) do { if( g_log->log_component[c].level >= OAILOG_ERR    ) logRecord_mt(__FILE__, __FUNCTION__, __LINE__,c, OAILOG_ERR, x)     ;}  while (0)
 #    define LOG_W(c, x...) do { if( g_log->log_component[c].level >= OAILOG_WARNING) logRecord_mt(__FILE__, __FUNCTION__, __LINE__,c, OAILOG_WARNING, x) ;}  while (0)
 #    define LOG_I(c, x...) do { if( g_log->log_component[c].level >= OAILOG_INFO   ) logRecord_mt(__FILE__, __FUNCTION__, __LINE__,c, OAILOG_INFO, x)    ;}  while (0)
+#    define LOG_A LOG_I
 #    define LOG_D(c, x...) do { if( g_log->log_component[c].level >= OAILOG_DEBUG  ) logRecord_mt(__FILE__, __FUNCTION__, __LINE__,c, OAILOG_DEBUG, x)   ;}  while (0)
 #    define LOG_T(c, x...) do { if( g_log->log_component[c].level >= OAILOG_TRACE  ) logRecord_mt(__FILE__, __FUNCTION__, __LINE__,c, OAILOG_TRACE, x)   ;}  while (0)
 #    define VLOG(c,l, f, args) do { if( g_log->log_component[c].level >= l  ) vlogRecord_mt(__FILE__, __FUNCTION__, __LINE__,c, l, f, args)   ; } while (0)
@@ -438,6 +467,8 @@ int32_t write_file_matlab(const char *fname, const char *vname, void *data, int
 #    define LOG_VAR(A,B) A B
 #    define T_ACTIVE(a) (0) 
 #  endif /* T_TRACER */
+#endif // LOG_MINIMAL
+
 /* avoid warnings for variables only used in LOG macro's but set outside debug section */
 #define GCC_NOTUSED   __attribute__((unused))
 #define LOG_USEDINLOG_VAR(A,B) GCC_NOTUSED A B

common/utils/ocp_itti/intertask_interface.cpp

@@ -438,9 +438,22 @@ extern "C" {
   void itti_send_terminate_message(task_id_t task_id) {
   }
 
+  static volatile bool shutting_down;
+
+  static void catch_sigterm(int) {
+    static const char msg[] = "\n** Caught SIGTERM, shutting down\n";
+    __attribute__((unused))
+    int unused = write(STDOUT_FILENO, msg, sizeof(msg) - 1);
+    shutting_down = true;
+  }
+
   void itti_wait_tasks_end(void) {
-    while(1)
-      sleep(24*3600);
+    shutting_down = false;
+    signal(SIGTERM, catch_sigterm);
+    while (! shutting_down)
+    {
+      sleep(24 * 3600);
+    }
   }
 
   void itti_update_lte_time(uint32_t frame, uint8_t slot) {}
@@ -455,4 +468,42 @@ extern "C" {
   int signal_mask(void) {
     return 0;
   }
+
+void log_scheduler(const char* label)
+{
+    int policy = sched_getscheduler(0);
+    struct sched_param param;
+    if (sched_getparam(0, &param) == -1)
+    {
+        LOG_E(HW, "sched_getparam: %s\n", strerror(errno));
+        abort();
+    }
+
+    cpu_set_t cpu_set;
+    if (sched_getaffinity(0, sizeof(cpu_set), &cpu_set) == -1)
+    {
+        LOG_E(HW, "sched_getaffinity: %s\n", strerror(errno));
+        abort();
+    }
+    int num_cpus = sysconf(_SC_NPROCESSORS_ONLN);
+    if (num_cpus < 1)
+    {
+        LOG_E(HW, "sysconf(_SC_NPROCESSORS_ONLN): %s\n", strerror(errno));
+        abort();
+    }
+    char buffer[num_cpus];
+    for (int i = 0; i < num_cpus; i++)
+    {
+        buffer[i] = CPU_ISSET(i, &cpu_set) ? 'Y' : '-';
+    }
+
+    LOG_A(HW, "Scheduler policy=%d priority=%d affinity=[%d]%.*s label=%s\n",
+          policy,
+          param.sched_priority,
+          num_cpus,
+          num_cpus,
+          buffer,
+          label);
 }
+} // extern "C"
+

common/utils/ocp_itti/intertask_interface.h

@@ -346,6 +346,8 @@ void *rrc_enb_process_msg(void *);
   TASK_DEF(TASK_DU_F1,    TASK_PRIORITY_MED,  200, NULL, NULL) \
   TASK_DEF(TASK_RRC_UE_SIM,   TASK_PRIORITY_MED,  200, NULL, NULL)  \
   TASK_DEF(TASK_RRC_GNB_SIM,  TASK_PRIORITY_MED,  200, NULL, NULL)  \
+  TASK_DEF(TASK_RRC_NSA_UE,   TASK_PRIORITY_MED,  200, NULL, NULL)  \
+  TASK_DEF(TASK_RRC_NSA_NRUE,   TASK_PRIORITY_MED,  200, NULL, NULL)  \
   TASK_DEF(TASK_NAS_NRUE,     TASK_PRIORITY_MED,  200, NULL, NULL)  \
   TASK_DEF(TASK_MAX,      TASK_PRIORITY_MED,  200, NULL, NULL)
 
@@ -362,6 +364,8 @@ typedef enum {
   FOREACH_TASK(TASK_ENUM)
 } task_id_t;
 
+extern uint16_t ue_idx_standalone;
+extern uint16_t node_number;
 
 typedef task_id_t thread_id_t;
 
@@ -586,6 +590,7 @@ int timer_remove(long timer_id);
 int signal_handle(int *end);
 int signal_mask(void);
 
+void log_scheduler(const char *label);
 #ifdef __cplusplus
 }
 #endif

common/utils/utils.c

@@ -2,6 +2,9 @@
 #include <stdio.h>
 #include <stdlib.h>
 #include <stdint.h>
+#include <unistd.h>
+#include <sched.h>
+#include <errno.h>
 #include "utils.h"
 
 void *calloc_or_fail(size_t size) {
@@ -22,6 +25,32 @@ void *malloc_or_fail(size_t size) {
   return ptr;
 }
 
+const char *hexdump(const void *data, size_t data_len, char *out, size_t out_len)
+{
+    char *p = out;
+    char *endp = out + out_len;
+    const uint8_t *q = data;
+    snprintf(p, endp - p, "[%zu]", data_len);
+    p += strlen(p);
+    for (size_t i = 0; i < data_len; ++i)
+    {
+        if (p >= endp)
+        {
+            static const char ellipses[] = "...";
+            char *s = endp - sizeof(ellipses);
+            if (s >= p)
+            {
+                strcpy(s, ellipses);
+            }
+            break;
+        }
+        snprintf(p, endp - p, " %02X", *q++);
+        p += strlen(p);
+    }
+    return out;
+}
+
+
 /****************************************************************************
  **                                                                        **
  ** Name:        hex_char_to_hex_value()                                   **
@@ -111,3 +140,32 @@ void *memcpy1(void *dst,const void *src,size_t n) {
   asm volatile("rep movsb" : "+D" (dst) : "c"(n), "S"(src) : "cc","memory");
   return(ret);
 }
+
+void set_priority(int priority)
+{
+  /* When running with a realtime scheduler, a buggy run-away process can take
+     down the host requiring a reboot to recover.  To avoid this scenario, we
+     use alarm(2) to set a maximum running time */
+  unsigned max_runtime_seconds = 10 * 60; /* default */
+  const char *env = getenv("MAX_RUNTIME_SECONDS");
+  if (env != NULL)
+  {
+    max_runtime_seconds = atoi(env);
+  }
+  unsigned was_alarm = alarm(max_runtime_seconds);
+  /* Normally, was_alarm should be 0 indicating there was no previous alarm set.
+     A non-zero value could indicate a mistake */
+  fprintf(stderr, "Set alarm for %u seconds, was %u (see $MAX_RUNTIME_SECONDS)\n",
+          max_runtime_seconds, was_alarm);
+
+  struct sched_param param =
+  {
+    .sched_priority = priority,
+  };
+  fprintf(stderr, "Calling sched_setscheduler(%d)\n", priority);
+  if (sched_setscheduler(0, SCHED_RR, &param) == -1)
+  {
+    fprintf(stderr, "sched_setscheduler: %s\n", strerror(errno));
+    abort();
+  }
+}

common/utils/utils.h

@@ -10,6 +10,7 @@ extern "C" {
 #define sizeofArray(a) (sizeof(a)/sizeof(*(a)))
 void *calloc_or_fail(size_t size);
 void *malloc_or_fail(size_t size);
+const char *hexdump(const void *data, size_t data_len, char *out, size_t out_len);
 
 // Converts an hexadecimal ASCII coded digit into its value. **
 int hex_char_to_hex_value (char c);
@@ -18,6 +19,7 @@ int hex_string_to_hex_value (uint8_t *hex_value, const char *hex_string, int siz
 
 void *memcpy1(void *dst,const void *src,size_t n);
 
+void set_priority(int priority);
 
 char *itoa(int i);