use of srslte::log* type for ASN1 logging. Initialization of the asn1 and rrc_asn1 loggers done now in both the ue and enb

lib/include/srslte/asn1/asn1_utils.h

@@ -22,6 +22,7 @@
 #ifndef SRSASN_COMMON_UTILS_H
 #define SRSASN_COMMON_UTILS_H
 
+#include "srslte/common/log.h"
 #include <algorithm>
 #include <array>
 #include <cmath>
@@ -49,14 +50,14 @@ constexpr Integer ceil_frac(Integer n, Integer d)
         logging
 ************************/
 
-typedef enum { LOG_LEVEL_INFO, LOG_LEVEL_DEBUG, LOG_LEVEL_WARN, LOG_LEVEL_ERROR } srsasn_logger_level_t;
+using srsasn_logger_level_t = srslte::LOG_LEVEL_ENUM;
-
+using srslte::LOG_LEVEL_DEBUG;
-typedef void (*log_handler_t)(srsasn_logger_level_t log_level, void* ctx, const char* str);
+using srslte::LOG_LEVEL_ERROR;
-
+using srslte::LOG_LEVEL_INFO;
-void vlog_print(log_handler_t handler, void* ctx, srsasn_logger_level_t log_level, const char* format, va_list args);
+using srslte::LOG_LEVEL_WARNING;
-
-void srsasn_log_register_handler(void* ctx, log_handler_t handler);
 
+void vlog_print(srslte::log* log_ptr, srsasn_logger_level_t log_level, const char* format, va_list args);
+void srsasn_log_register_handler(srslte::log* ctx);
 void srsasn_log_print(srsasn_logger_level_t log_level, const char* format, ...);
 
 /************************
@@ -68,13 +69,13 @@ enum SRSASN_CODE { SRSASN_SUCCESS, SRSASN_ERROR_ENCODE_FAIL, SRSASN_ERROR_DECODE
 void log_error_code(SRSASN_CODE code, const char* filename, int line);
 
 #define HANDLE_CODE(ret)                                                                                               \
-  {                                                                                                                    \
+  do {                                                                                                                 \
     SRSASN_CODE macrocode = ((ret));                                                                                   \
     if (macrocode != SRSASN_SUCCESS) {                                                                                 \
       log_error_code(macrocode, __FILE__, __LINE__);                                                                   \
       return macrocode;                                                                                                \
     }                                                                                                                  \
-  }
+  } while (0)
 
 /************************
         bit_ref
@@ -235,7 +236,7 @@ public:
   void push_back(const T& elem)
   {
     if (current_size >= MAX_N) {
-      srsasn_log_print(LOG_LEVEL_ERROR, "Maximum size %d achieved for bounded_array.\n", MAX_N);
+      srsasn_log_print(srslte::LOG_LEVEL_ERROR, "Maximum size %d achieved for bounded_array.\n", MAX_N);
     }
     data_[current_size++] = elem;
   }
@@ -598,7 +599,8 @@ public:
   fixed_octstring<N, aligned>& from_string(const std::string& hexstr)
   {
     if (hexstr.size() != 2 * N) {
-      srsasn_log_print(LOG_LEVEL_ERROR, "The provided hex string size is not valid (%d!=2*%d).\n", hexstr.size(), N);
+      srsasn_log_print(
+          srslte::LOG_LEVEL_ERROR, "The provided hex string size is not valid (%d!=2*%d).\n", hexstr.size(), N);
     } else {
       string_to_octstring(&octets_[0], hexstr);
     }
@@ -734,7 +736,7 @@ public:
   {
     if (s.size() != N) {
       srsasn_log_print(
-          LOG_LEVEL_ERROR, "The provided string size=%d does not match the bit string size=%d\n", s.size(), N);
+          srslte::LOG_LEVEL_ERROR, "The provided string size=%d does not match the bit string size=%d\n", s.size(), N);
     }
     memset(&octets_[0], 0, nof_octets());
     for (uint32_t i = 0; i < N; ++i)
@@ -791,7 +793,7 @@ public:
   derived_t&  from_string(const std::string& s)
   {
     if (s.size() < derived_t::lb or s.size() > derived_t::ub) {
-      srsasn_log_print(LOG_LEVEL_ERROR,
+      srsasn_log_print(srslte::LOG_LEVEL_ERROR,
                        "The provided string size=%d is not withing the bounds [%d, %d]\n",
                        s.size(),
                        derived_t::lb,
@@ -909,41 +911,6 @@ private:
 
 using dyn_bitstring = unbounded_bitstring<false, false>;
 
-// class dyn_bitstring
-//{
-// public:
-//  dyn_bitstring() = default;
-//  dyn_bitstring(uint32_t n_bits_);
-//  dyn_bitstring(const char* s);
-//
-//  bool operator==(const dyn_bitstring& other) const { return octets_ == other.octets_; }
-//  bool operator==(const char* other_str) const;
-//  bool get(uint32_t idx) const { return bitstring_get(&octets_[0], idx); }
-//  void set(uint32_t idx, bool value) { bitstring_set(&octets_[0], idx, value); }
-//
-//  void           resize(uint32_t new_size);
-//  uint32_t       length() const { return n_bits; }
-//  uint32_t       nof_octets() const { return (uint32_t)ceilf(length() / 8.0f); }
-//  std::string    to_string() const { return bitstring_to_string(&octets_[0], length()); }
-//  uint64_t       to_number() const { return bitstring_to_number(&octets_[0], length()); }
-//  dyn_bitstring& from_number(uint64_t val)
-//  {
-//    number_to_bitstring(&octets_[0], val, length());
-//    return *this;
-//  }
-//  const uint8_t* data() const { return &octets_[0]; }
-//  uint8_t*       data() { return &octets_[0]; }
-//
-//  SRSASN_CODE pack(bit_ref& bref, uint32_t lb = 0, uint32_t ub = 0) const;
-//  SRSASN_CODE pack(bit_ref& bref, bool ext, uint32_t lb = 0, uint32_t ub = 0) const;
-//  SRSASN_CODE unpack(bit_ref& bref, uint32_t lb = 0, uint32_t ub = 0);
-//  SRSASN_CODE unpack(bit_ref& bref, bool& ext, uint32_t lb = 0, uint32_t ub = 0);
-//
-// private:
-//  dyn_array<uint8_t> octets_;
-//  uint32_t           n_bits = 0;
-//};
-
 /*********************
   fixed sequence of
 *********************/
@@ -1349,6 +1316,50 @@ private:
   separator_t sep;
 };
 
+/*******************
+  Test pack/unpack
+*******************/
+
+template <class Msg>
+int test_pack_unpack_consistency(const Msg& msg)
+{
+  uint8_t buf[2048], buf2[2048];
+  bzero(buf, sizeof(buf));
+  bzero(buf2, sizeof(buf2));
+  Msg           msg2;
+  asn1::bit_ref bref(&buf[0], sizeof(buf)), bref2(&buf[0], sizeof(buf)), bref3(&buf2[0], sizeof(buf2));
+
+  if (msg.pack(bref) != asn1::SRSASN_SUCCESS) {
+    log_error_code(SRSASN_ERROR_ENCODE_FAIL, __FILE__, __LINE__);
+    return -1;
+  }
+  if (msg2.unpack(bref2) != asn1::SRSASN_SUCCESS) {
+    log_error_code(SRSASN_ERROR_DECODE_FAIL, __FILE__, __LINE__);
+    return -1;
+  }
+  if (msg2.pack(bref3) != asn1::SRSASN_SUCCESS) {
+    log_error_code(SRSASN_ERROR_ENCODE_FAIL, __FILE__, __LINE__);
+    return -1;
+  }
+
+  // unpack and last pack done for the same number of bits
+  if (bref3.distance() != bref2.distance()) {
+    srsasn_log_print(LOG_LEVEL_ERROR, "[%s][%d] .\n", __FILE__, __LINE__);
+    return -1;
+  }
+
+  // ensure packed messages are the same
+  if (bref3.distance() != bref.distance()) {
+    srsasn_log_print(LOG_LEVEL_ERROR, "[%s][%d] .\n", __FILE__, __LINE__);
+    return -1;
+  }
+  if (memcmp(buf, buf2, bref.distance_bytes()) != 0) {
+    srsasn_log_print(LOG_LEVEL_ERROR, "[%s][%d] .\n", __FILE__, __LINE__);
+    return -1;
+  }
+  return SRSASN_SUCCESS;
+}
+
 } // namespace asn1
 
 #endif // SRSASN_COMMON_UTILS_H

lib/include/srslte/asn1/rrc_asn1.h

@@ -39,59 +39,21 @@ namespace rrc {
  *                        Functions for external logging
  ******************************************************************************/
 
-static log_handler_t log_handler;
+extern srslte::log* rrc_log_ptr;
-static void*         callback_ctx = NULL;
 
-inline void rrc_log_register_handler(void* ctx, log_handler_t handler)
+void rrc_log_register_handler(srslte::log* ctx);
-{
-  log_handler  = handler;
-  callback_ctx = ctx;
-}
 
-inline void rrc_log_print(srsasn_logger_level_t log_level, const char* format, ...)
+void rrc_log_print(srslte::LOG_LEVEL_ENUM log_level, const char* format, ...);
-{
-  va_list args;
-  va_start(args, format);
-  vlog_print(log_handler, callback_ctx, log_level, format, args);
-  va_end(args);
-}
 
-inline void log_invalid_access_choice_id(uint32_t val, uint32_t choice_id)
+void log_invalid_access_choice_id(uint32_t val, uint32_t choice_id);
-{
-  rrc_log_print(LOG_LEVEL_ERROR, "The access choice id is invalid (%d!=%d)\n", val, choice_id);
-}
 
-inline void assert_choice_type(uint32_t val, uint32_t choice_id)
+void assert_choice_type(uint32_t val, uint32_t choice_id);
-{
-  if (val != choice_id) {
-    log_invalid_access_choice_id(val, choice_id);
-  }
-}
 
-inline void
+void assert_choice_type(const std::string& access_type,
-assert_choice_type(const std::string& access_type, const std::string& current_type, const std::string& choice_type)
+                        const std::string& current_type,
-{
+                        const std::string& choice_type);
-  if (access_type != current_type) {
-    rrc_log_print(LOG_LEVEL_ERROR,
-                  "Invalid field access for choice type \"%s\" (\"%s\"!=\"%s\")\n",
-                  choice_type.c_str(),
-                  access_type.c_str(),
-                  current_type.c_str());
-  }
-}
 
-inline const char* convert_enum_idx(const char* array[], uint32_t nof_types, uint32_t enum_val, const char* enum_type)
+const char* convert_enum_idx(const char* array[], uint32_t nof_types, uint32_t enum_val, const char* enum_type);
-{
-  if (enum_val >= nof_types) {
-    if (enum_val == nof_types) {
-      rrc_log_print(LOG_LEVEL_ERROR, "The enum of type %s was not initialized.\n", enum_type);
-    } else {
-      rrc_log_print(LOG_LEVEL_ERROR, "The enum value=%d of type %s is not valid.\n", enum_val, enum_type);
-    }
-    return "";
-  }
-  return array[enum_val];
-}
 
 template <class ItemType>
 ItemType convert_enum_idx(ItemType* array, uint32_t nof_types, uint32_t enum_val, const char* enum_type)

lib/src/asn1/asn1_utils.cc

@@ -29,12 +29,35 @@ namespace asn1 {
         logging
 ************************/
 
-void vlog_print(log_handler_t handler, void* ctx, srsasn_logger_level_t log_level, const char* format, va_list args)
+// Global ASN1 Log
+static srslte::log* asn1_log_ptr = nullptr;
+
+// Demux of log level to respective log method
+void srs_log_call(srslte::LOG_LEVEL_ENUM log_level, srslte::log* log_ptr, const char* str)
 {
-  if (handler) {
+  switch (log_level) {
-    char* args_msg = NULL;
+    case LOG_LEVEL_ERROR:
+      log_ptr->error("%s", str);
+      break;
+    case LOG_LEVEL_WARNING:
+      log_ptr->warning("%s", str);
+      break;
+    case LOG_LEVEL_INFO:
+      log_ptr->info("%s", str);
+      break;
+    case LOG_LEVEL_DEBUG:
+      log_ptr->debug("%s", str);
+    default:
+      break;
+  }
+}
+
+void vlog_print(srslte::log* log_ptr, srsasn_logger_level_t log_level, const char* format, va_list args)
+{
+  if (log_ptr != nullptr) {
+    char* args_msg = nullptr;
     if (vasprintf(&args_msg, format, args) > 0) {
-      handler(log_level, ctx, args_msg);
+      srs_log_call(log_level, log_ptr, args_msg);
     }
     if (args_msg) {
       free(args_msg);
@@ -44,20 +67,16 @@ void vlog_print(log_handler_t handler, void* ctx, srsasn_logger_level_t log_leve
   }
 }
 
-static log_handler_t log_handler;
+void srsasn_log_register_handler(srslte::log* ctx)
-static void*         callback_ctx = NULL;
-
-void srsasn_log_register_handler(void* ctx, log_handler_t handler)
 {
-  log_handler  = handler;
+  asn1_log_ptr = ctx;
-  callback_ctx = ctx;
 }
 
-void srsasn_log_print(srsasn_logger_level_t log_level, const char* format, ...)
+void srsasn_log_print(srslte::LOG_LEVEL_ENUM log_level, const char* format, ...)
 {
   va_list args;
   va_start(args, format);
-  vlog_print(log_handler, callback_ctx, log_level, format, args);
+  vlog_print(asn1_log_ptr, log_level, format, args);
   va_end(args);
 }
 
@@ -75,7 +94,7 @@ void log_error_code(SRSASN_CODE code, const char* filename, int line)
       srsasn_log_print(LOG_LEVEL_ERROR, "[%s][%d] Decoding failure.\n", filename, line);
       break;
     default:
-      srsasn_log_print(LOG_LEVEL_WARN, "[%s][%d] SRSASN_CODE=%u not recognized.\n", filename, line, (uint32_t)code);
+      srsasn_log_print(LOG_LEVEL_WARNING, "[%s][%d] SRSASN_CODE=%u not recognized.\n", filename, line, (uint32_t)code);
   }
 }
 
@@ -910,7 +929,7 @@ std::string octstring_to_string(const uint8_t* ptr, uint32_t N)
 void string_to_octstring(uint8_t* ptr, const std::string& str)
 {
   if (str.size() % 2 != 0) {
-    srsasn_log_print(LOG_LEVEL_WARN, "The provided hex string size=%zu is not a multiple of 2\n.", str.size());
+    srsasn_log_print(LOG_LEVEL_WARNING, "The provided hex string size=%zu is not a multiple of 2\n.", str.size());
   }
   char cstr[] = "\0\0\0";
   for (uint32_t i = 0; i < str.size(); i += 2) {

lib/src/asn1/rrc_asn1.cc

@@ -26,12 +26,65 @@ using namespace asn1;
 using namespace asn1::rrc;
 
 /*******************************************************************************
- *                               Helper Functions
+ *                              Logging Utilities
  ******************************************************************************/
 
+srslte::log* asn1::rrc::rrc_log_ptr = nullptr;
+
+void asn1::rrc::rrc_log_register_handler(srslte::log* ctx)
+{
+  rrc_log_ptr = ctx;
+}
+
+void asn1::rrc::rrc_log_print(srslte::LOG_LEVEL_ENUM log_level, const char* format, ...)
+{
+  va_list args;
+  va_start(args, format);
+  vlog_print(rrc_log_ptr, log_level, format, args);
+  va_end(args);
+}
+
+void asn1::rrc::log_invalid_access_choice_id(uint32_t val, uint32_t choice_id)
+{
+  rrc_log_print(LOG_LEVEL_ERROR, "The access choice id is invalid (%d!=%d)\n", val, choice_id);
+}
+
+void asn1::rrc::assert_choice_type(uint32_t val, uint32_t choice_id)
+{
+  if (val != choice_id) {
+    log_invalid_access_choice_id(val, choice_id);
+  }
+}
+
+void asn1::rrc::assert_choice_type(const std::string& access_type,
+                                   const std::string& current_type,
+                                   const std::string& choice_type)
+{
+  if (access_type != current_type) {
+    rrc_log_print(LOG_LEVEL_ERROR,
+                  "Invalid field access for choice type \"%s\" (\"%s\"!=\"%s\")\n",
+                  choice_type.c_str(),
+                  access_type.c_str(),
+                  current_type.c_str());
+  }
+}
+
+const char* convert_enum_idx(const char* array[], uint32_t nof_types, uint32_t enum_val, const char* enum_type)
+{
+  if (enum_val >= nof_types) {
+    if (enum_val == nof_types) {
+      rrc_log_print(LOG_LEVEL_ERROR, "The enum of type %s was not initialized.\n", enum_type);
+    } else {
+      rrc_log_print(LOG_LEVEL_ERROR, "The enum value=%d of type %s is not valid.\n", enum_val, enum_type);
+    }
+    return "";
+  }
+  return array[enum_val];
+}
+
 #define rrc_asn1_warn_assert(cond, file, line)                                                                         \
   if ((cond)) {                                                                                                        \
-    rrc_log_print(LOG_LEVEL_WARN, "Assertion in [%s][%d] failed.\n", (file), (line));                                  \
+    rrc_log_print(LOG_LEVEL_WARNING, "Assertion in [%s][%d] failed.\n", (file), (line));                               \
   }
 
 static void log_invalid_choice_id(uint32_t val, const char* choice_type)

lib/src/asn1/rrc_asn1_enum.cc

@@ -26,7 +26,7 @@ using namespace asn1;
 using namespace asn1::rrc;
 
 /*******************************************************************************
- *                               Helper Functions
+ *                              Logging Utilities
  ******************************************************************************/
 
 static void invalid_enum_number(int value, const char* name)

lib/test/asn1/CMakeLists.txt

@@ -51,5 +51,5 @@ target_link_libraries(srslte_asn1_nas_test srslte_common srslte_phy srslte_asn1)
 add_test(srslte_asn1_nas_test srslte_asn1_nas_test)
 
 add_executable(rrc_asn1_test rrc_asn1_test.cc)
-target_link_libraries(rrc_asn1_test rrc_asn1)
+target_link_libraries(rrc_asn1_test rrc_asn1 srslte_common)
 add_test(rrc_asn1_test rrc_asn1_test)

lib/test/asn1/rrc_asn1_test.cc

@@ -19,72 +19,15 @@
 */
 
 #include "srslte/asn1/rrc_asn1.h"
+#include "srslte/common/test_common.h"
 #include <cstdio>
-#include <iostream>
-
-#define TESTASSERT(cond)                                                                                               \
-  {                                                                                                                    \
-    if (!(cond)) {                                                                                                     \
-      std::cout << "[" << __FUNCTION__ << "][Line " << __LINE__ << "]: FAIL at " << (#cond) << std::endl;              \
-      return -1;                                                                                                       \
-    }                                                                                                                  \
-  }
 
 using namespace asn1;
 using namespace asn1::rrc;
 
-struct ConsoleLogger {
+srslte::log_filter        asn_logger("ASN1");
-  ConsoleLogger(const std::string& layer_) : layer(layer_) {}
+srslte::log_filter        rrc_logger("RRC");
-
+srslte::scoped_tester_log test_logger("TEST");
-  void log(srsasn_logger_level_t log_level, const char* str)
-  {
-    switch (log_level) {
-      case LOG_LEVEL_DEBUG:
-        printf("[%s][D] %s", layer.c_str(), str);
-        break;
-      case LOG_LEVEL_INFO:
-        printf("[%s][I] %s", layer.c_str(), str);
-        break;
-      case LOG_LEVEL_WARN:
-        printf("[%s][W] %s", layer.c_str(), str);
-        break;
-      case LOG_LEVEL_ERROR:
-        printf("[%s][E] %s", layer.c_str(), str);
-        break;
-      default:
-        break;
-    }
-  }
-
-private:
-  std::string layer;
-};
-void print_console(srsasn_logger_level_t log_level, void* ctx, const char* str)
-{
-  ConsoleLogger* logger = (ConsoleLogger*)ctx;
-  logger->log(log_level, str);
-}
-
-struct TestLogger {
-  TestLogger(const std::string& layer_) : layer(layer_) {}
-  void log(srsasn_logger_level_t log_level, const char* str)
-  {
-    last_level = log_level;
-    last_str   = str;
-  }
-  std::string           layer;
-  srsasn_logger_level_t last_level;
-  std::string           last_str;
-};
-void test_print(srsasn_logger_level_t log_level, void* ctx, const char* str)
-{
-  TestLogger* logger = (TestLogger*)ctx;
-  logger->log(log_level, str);
-}
-
-ConsoleLogger asn_logger("ASN");
-ConsoleLogger rrc_logger("RRC");
-TestLogger    test_logger("TEST");
 
 // TESTS
 
@@ -96,13 +39,17 @@ int test_generic()
   TESTASSERT(choice_type1.type() == pusch_enhance_cfg_r14_c::types::nulltype);
 
   // test logger handler
-  rrc_log_register_handler(&test_logger, test_print);
+  {
+    srslte::nullsink_log null_log("NULL");
+    null_log.set_level(LOG_LEVEL_INFO);
+    rrc_log_register_handler(&null_log);
     std::string test_str = "This is a console test to see if the RRC logger is working fine\n";
     rrc_log_print(LOG_LEVEL_INFO, test_str.c_str());
-  TESTASSERT(test_logger.last_str == test_str);
+    TESTASSERT(null_log.last_log_msg == test_str);
-  TESTASSERT(test_logger.last_level == LOG_LEVEL_INFO);
+    TESTASSERT(null_log.last_log_level == LOG_LEVEL_INFO);
     // go back to original logger
-  rrc_log_register_handler(&rrc_logger, print_console);
+    rrc_log_register_handler(&rrc_logger);
+  }
 
   // Test deep copy of choice types
   sib_type14_r11_s::eab_param_r11_c_ choice2;
@@ -181,6 +128,8 @@ int test_mib_msg()
   //  bcch_bch_msg.to_json(j);
   //  std::cout << j.to_string() << std::endl;
 
+  TESTASSERT(test_pack_unpack_consistency(bcch_bch_msg) == SRSASN_SUCCESS);
+
   return 0;
 }
 
@@ -258,6 +207,8 @@ int test_bcch_dl_sch_msg()
   //  bcch_msg.to_json(j);
   //  std::cout << j.to_string() << std::endl;
 
+  TESTASSERT(test_pack_unpack_consistency(bcch_msg) == SRSASN_SUCCESS);
+
   return 0;
 }
 
@@ -289,6 +240,8 @@ int test_bcch_dl_sch_msg2()
   TESTASSERT(bref.distance(bref0) == bref2.distance(bit_ref(&rrc_msg2[0], sizeof(rrc_msg2))));
   TESTASSERT(memcmp(rrc_msg2, rrc_msg, rrc_msg_len) == 0);
 
+  TESTASSERT(test_pack_unpack_consistency(bcch_msg) == SRSASN_SUCCESS);
+
   return 0;
 }
 
@@ -322,6 +275,8 @@ int test_bcch_dl_sch_msg3()
   TESTASSERT(bref.distance(rrc_msg) == bref2.distance(rrc_msg2));
   TESTASSERT(memcmp(rrc_msg2, rrc_msg, bref.distance_bytes(rrc_msg)) == 0);
 
+  TESTASSERT(test_pack_unpack_consistency(bcch_msg) == SRSASN_SUCCESS);
+
   return 0;
 }
 
@@ -360,17 +315,13 @@ int test_dl_dcch_msg()
   //...
   TESTASSERT(drb->rlc_cfg_v1510.is_present());
 
-  uint8_t rrc_msg2[rrc_msg_len];
-  bit_ref bref2(&rrc_msg2[0], sizeof(rrc_msg2)), bref2_0(&rrc_msg2[0], sizeof(rrc_msg2));
-  dl_dcch_msg.pack(bref2); // FIXME: Should I generate a pack/unpack method for RLC-Config-v1510???
-  TESTASSERT(bref.distance(bref0) == bref2.distance(bref2_0));
-  TESTASSERT(memcmp(rrc_msg2, rrc_msg, rrc_msg_len) == 0);
-
   //  // test print
   //  json_writer j;
   //  dl_dcch_msg.to_json(j);
   //  std::cout << j.to_string() << std::endl;
 
+  TESTASSERT(test_pack_unpack_consistency(dl_dcch_msg) == SRSASN_SUCCESS);
+
   return 0;
 }
 
@@ -572,6 +523,8 @@ int failed_dl_ccch_unpack()
 
   TESTASSERT(msg.unpack(bref) == SRSASN_SUCCESS);
 
+  TESTASSERT(test_pack_unpack_consistency(msg) == SRSASN_SUCCESS);
+
   return 0;
 }
 
@@ -591,6 +544,8 @@ int unrecognized_ext_group_test()
   TESTASSERT(dl_sch_msg.msg.type() == bcch_dl_sch_msg_type_c::types::c1);
   TESTASSERT(dl_sch_msg.msg.c1().type() == bcch_dl_sch_msg_type_c::c1_c_::types::sys_info);
 
+  TESTASSERT(test_pack_unpack_consistency(dl_sch_msg) == SRSASN_SUCCESS);
+
   return 0;
 }
 
@@ -618,6 +573,8 @@ int v2x_test()
   //  sl_preconf.to_json(json_writer);
   //  printf("Content: %s\n", json_writer.to_string().c_str());
 
+  TESTASSERT(test_pack_unpack_consistency(sl_preconf) == SRSASN_SUCCESS);
+
   return SRSASN_SUCCESS;
 }
 
@@ -639,13 +596,19 @@ int test_rrc_conn_reconf_r15_2()
   dl_dcch_msg_s recfg_msg;
   TESTASSERT(recfg_msg.unpack(bref) == SRSASN_SUCCESS);
 
+  TESTASSERT(test_pack_unpack_consistency(recfg_msg) == SRSASN_SUCCESS);
+
   return SRSASN_SUCCESS;
 }
 
 int main()
 {
-  srsasn_log_register_handler(&asn_logger, print_console);
+  asn_logger.set_level(LOG_LEVEL_DEBUG);
-  rrc_log_register_handler(&rrc_logger, print_console);
+  rrc_logger.set_level(LOG_LEVEL_DEBUG);
+  test_logger.set_level(LOG_LEVEL_DEBUG);
+
+  srsasn_log_register_handler(&asn_logger);
+  rrc_log_register_handler(&rrc_logger);
 
   TESTASSERT(test_generic() == 0);
   TESTASSERT(test_json_printer() == 0);

srsenb/hdr/stack/enb_stack_lte.h

@@ -141,6 +141,7 @@ private:
   srslte::log_filter s1ap_log;
   srslte::log_filter gtpu_log;
   srslte::log_filter stack_log;
+  srslte::log_filter asn1_log, rrc_asn1_log;
 
   // RAT-specific interfaces
   phy_interface_stack_lte* phy = nullptr;

srsenb/src/stack/enb_stack_lte.cc

@@ -77,6 +77,8 @@ int enb_stack_lte::init(const stack_args_t& args_, const rrc_cfg_t& rrc_cfg_)
   gtpu_log.init("GTPU", logger);
   s1ap_log.init("S1AP", logger);
   stack_log.init("STACK", logger);
+  asn1_log.init("ASN1", logger);
+  rrc_asn1_log.init("ASN1::RRC", logger);
 
   // Init logs
   mac_log.set_level(args.log.mac_level);
@@ -85,7 +87,9 @@ int enb_stack_lte::init(const stack_args_t& args_, const rrc_cfg_t& rrc_cfg_)
   rrc_log.set_level(args.log.rrc_level);
   gtpu_log.set_level(args.log.gtpu_level);
   s1ap_log.set_level(args.log.s1ap_level);
-  stack_log.set_level("DEBUG");
+  stack_log.set_level(LOG_LEVEL_INFO);
+  asn1_log.set_level(LOG_LEVEL_INFO);
+  rrc_asn1_log.set_level(args.log.rrc_level);
 
   mac_log.set_hex_limit(args.log.mac_hex_limit);
   rlc_log.set_hex_limit(args.log.rlc_hex_limit);
@@ -94,6 +98,10 @@ int enb_stack_lte::init(const stack_args_t& args_, const rrc_cfg_t& rrc_cfg_)
   gtpu_log.set_hex_limit(args.log.gtpu_hex_limit);
   s1ap_log.set_hex_limit(args.log.s1ap_hex_limit);
   stack_log.set_hex_limit(128);
+  asn1_log.set_hex_limit(128);
+  asn1::srsasn_log_register_handler(&asn1_log);
+  rrc_asn1_log.set_hex_limit(args.log.rrc_hex_limit);
+  asn1::rrc::rrc_log_register_handler(&rrc_log);
 
   // Set up pcap and trace
   if (args.pcap.enable) {

srsenb/test/upper/rrc_mobility_test.cc

@@ -369,7 +369,7 @@ int test_mobility_class(mobility_test_params test_params)
   phy_dummy                         phy;
   test_dummies::s1ap_mobility_dummy s1ap;
   gtpu_dummy                        gtpu;
-  rrc_log.set_level(srslte::LOG_LEVEL_NONE);
+  rrc_log.set_level(srslte::LOG_LEVEL_INFO);
   rrc_log.set_hex_limit(1024);
   rrc.init(&cfg, &phy, &mac, &rlc, &pdcp, &s1ap, &gtpu, &timers, &rrc_log);
 
@@ -381,6 +381,7 @@ int test_mobility_class(mobility_test_params test_params)
   uint16_t rnti = 0x46;
   rrc.add_user(rnti);
 
+  rrc_log.set_level(srslte::LOG_LEVEL_NONE); // mute all the startup log
   // Do all the handshaking until the first RRC Connection Reconf
   test_helpers::bring_rrc_to_reconf_state(rrc, timers, rnti);
 

srsue/hdr/stack/rrc/rrc.h

@@ -67,18 +67,12 @@ namespace srsue {
 
 class cell_t
 {
- public:
+public:
-  bool is_valid() {
+  bool is_valid() { return phy_cell.earfcn != 0 && srslte_cell_isvalid(&phy_cell.cell); }
-    return phy_cell.earfcn != 0 && srslte_cell_isvalid(&phy_cell.cell);
+  bool equals(cell_t* x) { return equals(x->phy_cell.earfcn, x->phy_cell.cell.id); }
-  }
-  bool equals(cell_t *x) {
-    return equals(x->phy_cell.earfcn, x->phy_cell.cell.id);
-  }
   bool equals(uint32_t earfcn, uint32_t pci) { return earfcn == phy_cell.earfcn && pci == phy_cell.cell.id; }
   // NaN means an RSRP value has not yet been obtained. Keep then in the list and clean them if never updated
-  bool greater(cell_t *x) {
+  bool greater(cell_t* x) { return rsrp > x->rsrp || std::isnan(rsrp); }
-    return rsrp > x->rsrp || std::isnan(rsrp);
-  }
   bool plmn_equals(asn1::rrc::plmn_id_s plmn_id)
   {
     if (has_valid_sib1) {
@@ -92,7 +86,8 @@ class cell_t
     return false;
   }
 
-  uint32_t nof_plmns() {
+  uint32_t nof_plmns()
+  {
     if (has_valid_sib1) {
       return sib1.cell_access_related_info.plmn_id_list.size();
     } else {
@@ -109,7 +104,8 @@ class cell_t
     }
   }
 
-  uint16_t get_tac() {
+  uint16_t get_tac()
+  {
     if (has_valid_sib1) {
       return (uint16_t)sib1.cell_access_related_info.tac.to_number();
     } else {
@@ -117,7 +113,8 @@ class cell_t
     }
   }
 
-  cell_t() {
+  cell_t()
+  {
     phy_interface_rrc_lte::phy_cell_t tmp = {};
     cell_t(tmp, 0);
   }
@@ -136,13 +133,9 @@ class cell_t
     bzero(&sib13, sizeof(sib13));
   }
 
-  uint32_t get_earfcn() {
+  uint32_t get_earfcn() { return phy_cell.earfcn; }
-    return phy_cell.earfcn;
-  }
 
-  uint32_t get_pci() {
+  uint32_t get_pci() { return phy_cell.cell.id; }
-    return phy_cell.cell.id;
-  }
 
   void set_rsrp(float rsrp_)
   {
@@ -152,9 +145,7 @@ class cell_t
     gettimeofday(&last_update, nullptr);
   }
 
-  float get_rsrp() {
+  float get_rsrp() { return rsrp; }
-    return rsrp;
-  }
 
   void set_sib1(asn1::rrc::sib_type1_s* sib1_)
   {
@@ -178,7 +169,8 @@ class cell_t
   }
 
   // TODO: replace with TTI count
-  uint32_t timeout_secs(struct timeval now) {
+  uint32_t timeout_secs(struct timeval now)
+  {
     struct timeval t[3];
     memcpy(&t[2], &now, sizeof(struct timeval));
     memcpy(&t[1], &last_update, sizeof(struct timeval));
@@ -193,21 +185,14 @@ class cell_t
 
   uint32_t get_cell_id() { return (uint32_t)sib1.cell_access_related_info.cell_id.to_number(); }
 
-  bool has_sib1() {
+  bool has_sib1() { return has_valid_sib1; }
-    return has_valid_sib1;
+  bool has_sib2() { return has_valid_sib2; }
-  }
+  bool has_sib3() { return has_valid_sib3; }
-  bool has_sib2() {
+  bool has_sib13() { return has_valid_sib13; }
-    return has_valid_sib2;
-  }
-  bool has_sib3() {
-    return has_valid_sib3;
-  }
-  bool has_sib13() {
-    return has_valid_sib13;
-  }
 
-  bool has_sib(uint32_t index) {
+  bool has_sib(uint32_t index)
-    switch(index) {
+  {
+    switch (index) {
       case 0:
         return has_sib1();
       case 1:
@@ -220,14 +205,16 @@ class cell_t
     return false;
   }
 
-  void reset_sibs() {
+  void reset_sibs()
+  {
     has_valid_sib1  = false;
     has_valid_sib2  = false;
     has_valid_sib3  = false;
     has_valid_sib13 = false;
   }
 
-  uint16_t get_mcc() {
+  uint16_t get_mcc()
+  {
     uint16_t mcc;
     if (has_valid_sib1) {
       if (sib1.cell_access_related_info.plmn_id_list.size() > 0) {
@@ -239,11 +226,13 @@ class cell_t
     return 0;
   }
 
-  uint16_t get_mnc() {
+  uint16_t get_mnc()
+  {
     uint16_t mnc;
     if (has_valid_sib1) {
       if (sib1.cell_access_related_info.plmn_id_list.size() > 0) {
-        if (srslte::bytes_to_mnc(&sib1.cell_access_related_info.plmn_id_list[0].plmn_id.mnc[0], &mnc,
+        if (srslte::bytes_to_mnc(&sib1.cell_access_related_info.plmn_id_list[0].plmn_id.mnc[0],
+                                 &mnc,
                                  sib1.cell_access_related_info.plmn_id_list[0].plmn_id.mnc.size())) {
           return mnc;
         }
@@ -480,7 +469,7 @@ private:
   class rrc_meas
   {
   public:
-    void init(rrc *parent);
+    void init(rrc* parent);
     void reset();
     bool parse_meas_config(asn1::rrc::meas_cfg_s* meas_config);
     void new_phy_meas(uint32_t earfcn, uint32_t pci, float rsrp, float rsrq, uint32_t tti);
@@ -488,11 +477,11 @@ private:
     bool timer_expired(uint32_t timer_id);
     void ho_finish();
     void delete_report(uint32_t earfcn, uint32_t pci);
-  private:
 
+  private:
     const static int NOF_MEASUREMENTS = 3;
 
-    typedef enum {RSRP = 0, RSRQ = 1, BOTH = 2} quantity_t;
+    typedef enum { RSRP = 0, RSRQ = 1, BOTH = 2 } quantity_t;
 
     typedef struct {
       uint32_t pci;
@@ -513,7 +502,7 @@ private:
       quantity_t               trigger_quantity;
       quantity_t               report_quantity;
       asn1::rrc::eutra_event_s event;
-      enum {EVENT, PERIODIC} trigger_type;
+      enum { EVENT, PERIODIC } trigger_type;
     } report_cfg_t;
 
     typedef struct {
@@ -551,7 +540,7 @@ private:
     bool  s_measure_enabled = false;
     float s_measure_value   = 0.0;
 
-    void stop_reports(meas_t *m);
+    void    stop_reports(meas_t* m);
     void    stop_reports_object(uint32_t object_id);
     void    remove_meas_object(uint32_t object_id);
     void    remove_meas_report(uint32_t report_id);
@@ -559,8 +548,8 @@ private:
     void    remove_meas_id(std::map<uint32_t, meas_t>::iterator it);
     void    calculate_triggers(uint32_t tti);
     void    update_phy();
-    void L3_filter(meas_value_t *value, float rsrp[NOF_MEASUREMENTS]);
+    void    L3_filter(meas_value_t* value, float rsrp[NOF_MEASUREMENTS]);
-    bool find_earfcn_cell(uint32_t earfcn, uint32_t pci, meas_obj_t **object, int *cell_idx);
+    bool    find_earfcn_cell(uint32_t earfcn, uint32_t pci, meas_obj_t** object, int* cell_idx);
     float   range_to_value(quantity_t quant, uint8_t range);
     uint8_t value_to_range(quantity_t quant, float value);
     bool    process_event(asn1::rrc::eutra_event_s* event,
@@ -715,5 +704,4 @@ private:
 
 } // namespace srsue
 
-
 #endif // SRSUE_RRC_H

srsue/hdr/stack/ue_stack_lte.h

@@ -143,6 +143,8 @@ private:
   srslte::log_filter nas_log;
   srslte::log_filter usim_log;
   srslte::log_filter pool_log;
+  srslte::log_filter asn1_log;
+  srslte::log_filter rrc_asn1_log;
 
   // stack components
   srsue::mac                 mac;

srsue/src/stack/rrc/rrc.cc

@@ -65,26 +65,10 @@ rrc::rrc(srslte::log* rrc_log_) :
   connection_reest(this),
   serving_cell(unique_cell_t(new cell_t({}, 0.0)))
 {
-  // Do nothing
 }
 
 rrc::~rrc() = default;
 
-static void srslte_rrc_handler(asn1::srsasn_logger_level_t level, void* ctx, const char* str)
-{
-  rrc *r = (rrc *) ctx;
-  r->srslte_rrc_log(str); // FIXME use log level
-}
-
-void rrc::srslte_rrc_log(const char* str)
-{
-  if (rrc_log) {
-    rrc_log->warning("[ASN]: %s\n", str);
-  } else {
-    rrc_log->console("[ASN]: %s\n", str);
-  }
-}
-
 template <class T>
 void rrc::log_rrc_message(const std::string source, const direction_t dir, const byte_buffer_t* pdu, const T& msg)
 {
@@ -141,9 +125,6 @@ void rrc::init(phy_interface_rrc_lte* phy_,
 
   transaction_id = 0;
 
-  // Register logging handler with asn1 rrc
-  asn1::rrc::rrc_log_register_handler(this, srslte_rrc_handler);
-
   cell_clean_cnt = 0;
 
   pending_mob_reconf = false;

srsue/src/stack/ue_stack_lte.cc

@@ -88,6 +88,8 @@ int ue_stack_lte::init(const stack_args_t& args_, srslte::logger* logger_)
   rrc_log.init("RRC ", logger);
   nas_log.init("NAS ", logger);
   usim_log.init("USIM", logger);
+  asn1_log.init("ASN1", logger);
+  rrc_asn1_log.init("ASN1::RRC", logger);
 
   pool_log.init("POOL", logger);
   pool_log.set_level(srslte::LOG_LEVEL_ERROR);
@@ -99,6 +101,8 @@ int ue_stack_lte::init(const stack_args_t& args_, srslte::logger* logger_)
   rrc_log.set_level(args.log.rrc_level);
   nas_log.set_level(args.log.nas_level);
   usim_log.set_level(args.log.usim_level);
+  asn1_log.set_level(LOG_LEVEL_INFO);
+  rrc_asn1_log.set_level(args.log.rrc_level);
 
   mac_log.set_hex_limit(args.log.mac_hex_limit);
   rlc_log.set_hex_limit(args.log.rlc_hex_limit);
@@ -106,6 +110,10 @@ int ue_stack_lte::init(const stack_args_t& args_, srslte::logger* logger_)
   rrc_log.set_hex_limit(args.log.rrc_hex_limit);
   nas_log.set_hex_limit(args.log.nas_hex_limit);
   usim_log.set_hex_limit(args.log.usim_hex_limit);
+  asn1_log.set_hex_limit(128);
+  rrc_asn1_log.set_hex_limit(args.log.rrc_hex_limit);
+  asn1::srsasn_log_register_handler(&asn1_log);
+  asn1::rrc::rrc_log_register_handler(&rrc_log);
 
   // Set up pcap
   if (args.pcap.enable) {