From d59016ae686c8113d26a96d8baf9b43cfa122622 Mon Sep 17 00:00:00 2001 From: Francisco Paisana Date: Wed, 11 Dec 2019 18:29:49 +0000 Subject: [PATCH] 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 | 107 +++++++------ lib/include/srslte/asn1/rrc_asn1.h | 56 ++----- lib/src/asn1/asn1_utils.cc | 47 ++++-- lib/src/asn1/rrc_asn1.cc | 57 ++++++- lib/src/asn1/rrc_asn1_enum.cc | 2 +- lib/test/asn1/CMakeLists.txt | 2 +- lib/test/asn1/rrc_asn1_test.cc | 115 +++++--------- srsenb/hdr/stack/enb_stack_lte.h | 1 + srsenb/src/stack/enb_stack_lte.cc | 10 +- srsenb/test/upper/rrc_mobility_test.cc | 3 +- srsue/hdr/stack/rrc/rrc.h | 210 ++++++++++++------------- srsue/hdr/stack/ue_stack_lte.h | 2 + srsue/src/stack/rrc/rrc.cc | 19 --- srsue/src/stack/ue_stack_lte.cc | 8 + 14 files changed, 318 insertions(+), 321 deletions(-) diff --git a/lib/include/srslte/asn1/asn1_utils.h b/lib/include/srslte/asn1/asn1_utils.h index be70f3f50..1e1e8035e 100644 --- a/lib/include/srslte/asn1/asn1_utils.h +++ b/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 #include #include @@ -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; - -typedef void (*log_handler_t)(srsasn_logger_level_t log_level, void* ctx, const char* str); - -void vlog_print(log_handler_t handler, void* ctx, srsasn_logger_level_t log_level, const char* format, va_list args); - -void srsasn_log_register_handler(void* ctx, log_handler_t handler); +using srsasn_logger_level_t = srslte::LOG_LEVEL_ENUM; +using srslte::LOG_LEVEL_DEBUG; +using srslte::LOG_LEVEL_ERROR; +using srslte::LOG_LEVEL_INFO; +using srslte::LOG_LEVEL_WARNING; +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& 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; -// 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 octets_; -// uint32_t n_bits = 0; -//}; - /********************* fixed sequence of *********************/ @@ -1349,6 +1316,50 @@ private: separator_t sep; }; +/******************* + Test pack/unpack +*******************/ + +template +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 diff --git a/lib/include/srslte/asn1/rrc_asn1.h b/lib/include/srslte/asn1/rrc_asn1.h index c61cfa29e..ef8e6edf5 100644 --- a/lib/include/srslte/asn1/rrc_asn1.h +++ b/lib/include/srslte/asn1/rrc_asn1.h @@ -39,59 +39,21 @@ namespace rrc { * Functions for external logging ******************************************************************************/ -static log_handler_t log_handler; -static void* callback_ctx = NULL; +extern srslte::log* rrc_log_ptr; -inline void rrc_log_register_handler(void* ctx, log_handler_t handler) -{ - log_handler = handler; - callback_ctx = ctx; -} +void rrc_log_register_handler(srslte::log* ctx); -inline void rrc_log_print(srsasn_logger_level_t 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); -} +void rrc_log_print(srslte::LOG_LEVEL_ENUM log_level, const char* format, ...); -inline 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); -} +void log_invalid_access_choice_id(uint32_t val, uint32_t choice_id); -inline void assert_choice_type(uint32_t val, uint32_t choice_id) -{ - if (val != choice_id) { - log_invalid_access_choice_id(val, choice_id); - } -} +void assert_choice_type(uint32_t val, uint32_t choice_id); -inline void -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()); - } -} +void assert_choice_type(const std::string& access_type, + const std::string& current_type, + const std::string& choice_type); -inline 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]; -} +const char* convert_enum_idx(const char* array[], uint32_t nof_types, uint32_t enum_val, const char* enum_type); template ItemType convert_enum_idx(ItemType* array, uint32_t nof_types, uint32_t enum_val, const char* enum_type) diff --git a/lib/src/asn1/asn1_utils.cc b/lib/src/asn1/asn1_utils.cc index 51762e8b9..47eb50383 100644 --- a/lib/src/asn1/asn1_utils.cc +++ b/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) { - char* args_msg = NULL; + switch (log_level) { + 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; -static void* callback_ctx = NULL; - -void srsasn_log_register_handler(void* ctx, log_handler_t handler) +void srsasn_log_register_handler(srslte::log* ctx) { - log_handler = handler; - callback_ctx = ctx; + asn1_log_ptr = 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) { diff --git a/lib/src/asn1/rrc_asn1.cc b/lib/src/asn1/rrc_asn1.cc index 7eaa9f2d9..8fa7f6154 100644 --- a/lib/src/asn1/rrc_asn1.cc +++ b/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) diff --git a/lib/src/asn1/rrc_asn1_enum.cc b/lib/src/asn1/rrc_asn1_enum.cc index e4d396ac7..59a66dd01 100644 --- a/lib/src/asn1/rrc_asn1_enum.cc +++ b/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) diff --git a/lib/test/asn1/CMakeLists.txt b/lib/test/asn1/CMakeLists.txt index 4fd15f39f..68fbbbb44 100644 --- a/lib/test/asn1/CMakeLists.txt +++ b/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) \ No newline at end of file diff --git a/lib/test/asn1/rrc_asn1_test.cc b/lib/test/asn1/rrc_asn1_test.cc index 34ba0d9df..29ef556b6 100644 --- a/lib/test/asn1/rrc_asn1_test.cc +++ b/lib/test/asn1/rrc_asn1_test.cc @@ -19,72 +19,15 @@ */ #include "srslte/asn1/rrc_asn1.h" +#include "srslte/common/test_common.h" #include -#include - -#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 { - ConsoleLogger(const std::string& layer_) : layer(layer_) {} - - 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"); +srslte::log_filter asn_logger("ASN1"); +srslte::log_filter rrc_logger("RRC"); +srslte::scoped_tester_log 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); - 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(test_logger.last_level == LOG_LEVEL_INFO); - // go back to original logger - rrc_log_register_handler(&rrc_logger, print_console); + { + 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(null_log.last_log_msg == test_str); + TESTASSERT(null_log.last_log_level == LOG_LEVEL_INFO); + // go back to original logger + 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); - rrc_log_register_handler(&rrc_logger, print_console); + asn_logger.set_level(LOG_LEVEL_DEBUG); + 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); diff --git a/srsenb/hdr/stack/enb_stack_lte.h b/srsenb/hdr/stack/enb_stack_lte.h index dba0f5e55..ab22b746a 100644 --- a/srsenb/hdr/stack/enb_stack_lte.h +++ b/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; diff --git a/srsenb/src/stack/enb_stack_lte.cc b/srsenb/src/stack/enb_stack_lte.cc index a9811f36b..48b9daddf 100644 --- a/srsenb/src/stack/enb_stack_lte.cc +++ b/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) { diff --git a/srsenb/test/upper/rrc_mobility_test.cc b/srsenb/test/upper/rrc_mobility_test.cc index d556c4ee5..304e38d07 100644 --- a/srsenb/test/upper/rrc_mobility_test.cc +++ b/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, >pu, &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); diff --git a/srsue/hdr/stack/rrc/rrc.h b/srsue/hdr/stack/rrc/rrc.h index 444e08c97..24c760f62 100644 --- a/srsue/hdr/stack/rrc/rrc.h +++ b/srsue/hdr/stack/rrc/rrc.h @@ -67,18 +67,12 @@ namespace srsue { class cell_t { - public: - bool is_valid() { - 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); - } +public: + bool is_valid() { 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(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) { - return rsrp > x->rsrp || std::isnan(rsrp); - } + bool greater(cell_t* x) { 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,16 +113,17 @@ class cell_t } } - cell_t() { + cell_t() + { phy_interface_rrc_lte::phy_cell_t tmp = {}; cell_t(tmp, 0); } cell_t(phy_interface_rrc_lte::phy_cell_t phy_cell, float rsrp_) { gettimeofday(&last_update, nullptr); - this->has_valid_sib1 = false; - this->has_valid_sib2 = false; - this->has_valid_sib3 = false; + this->has_valid_sib1 = false; + this->has_valid_sib2 = false; + this->has_valid_sib3 = false; this->has_valid_sib13 = false; this->phy_cell = phy_cell; rsrp = rsrp_; @@ -136,13 +133,9 @@ class cell_t bzero(&sib13, sizeof(sib13)); } - uint32_t get_earfcn() { - return phy_cell.earfcn; - } + uint32_t get_earfcn() { return phy_cell.earfcn; } - uint32_t get_pci() { - return phy_cell.cell.id; - } + uint32_t get_pci() { return phy_cell.cell.id; } void set_rsrp(float rsrp_) { @@ -152,9 +145,7 @@ class cell_t gettimeofday(&last_update, nullptr); } - float get_rsrp() { - return rsrp; - } + float get_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() { - return has_valid_sib1; - } - bool has_sib2() { - return has_valid_sib2; - } - bool has_sib3() { - return has_valid_sib3; - } - bool has_sib13() { - return has_valid_sib13; - } + bool has_sib1() { return has_valid_sib1; } + bool has_sib2() { return has_valid_sib2; } + bool has_sib3() { return has_valid_sib3; } + bool has_sib13() { return has_valid_sib13; } - bool has_sib(uint32_t index) { - switch(index) { + bool has_sib(uint32_t index) + { + switch (index) { case 0: return has_sib1(); case 1: @@ -220,14 +205,16 @@ class cell_t return false; } - void reset_sibs() { - has_valid_sib1 = false; - has_valid_sib2 = false; - has_valid_sib3 = false; + 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; } @@ -313,11 +302,11 @@ public: void log_rrc_message(const std::string source, const direction_t dir, const srslte::byte_buffer_t* pdu, const T& msg); std::string print_mbms(); - bool mbms_service_start(uint32_t serv, uint32_t port); + bool mbms_service_start(uint32_t serv, uint32_t port); // NAS interface void write_sdu(srslte::unique_byte_buffer_t sdu); - void enable_capabilities(); + void enable_capabilities(); uint16_t get_mcc(); uint16_t get_mnc(); bool plmn_search() final; @@ -356,7 +345,7 @@ private: typedef struct { enum { PDU, PCCH, PDU_MCH, RLF, PDU_BCCH_DLSCH, STOP } command; srslte::unique_byte_buffer_t pdu; - uint16_t lcid; + uint16_t lcid; } cmd_msg_t; bool running = false; @@ -380,12 +369,12 @@ private: void send_ul_ccch_msg(const asn1::rrc::ul_ccch_msg_s& msg); void send_ul_dcch_msg(uint32_t lcid, const asn1::rrc::ul_dcch_msg_s& msg); - srslte::bit_buffer_t bit_buf; + srslte::bit_buffer_t bit_buf; - rrc_state_t state = RRC_STATE_IDLE, last_state = RRC_STATE_IDLE; - uint8_t transaction_id = 0; - srslte::s_tmsi_t ue_identity; - bool ue_identity_configured = false; + rrc_state_t state = RRC_STATE_IDLE, last_state = RRC_STATE_IDLE; + uint8_t transaction_id = 0; + srslte::s_tmsi_t ue_identity; + bool ue_identity_configured = false; bool drb_up = false; @@ -396,12 +385,12 @@ private: uint32_t cell_clean_cnt = 0; - uint16_t ho_src_rnti = 0; - cell_t ho_src_cell = {}; - srslte::phy_cfg_t current_phy_cfg, previous_phy_cfg = {}; - srslte::mac_cfg_t current_mac_cfg, previous_mac_cfg = {}; - bool pending_mob_reconf = false; - asn1::rrc::rrc_conn_recfg_s mob_reconf = {}; + uint16_t ho_src_rnti = 0; + cell_t ho_src_cell = {}; + srslte::phy_cfg_t current_phy_cfg, previous_phy_cfg = {}; + srslte::mac_cfg_t current_mac_cfg, previous_mac_cfg = {}; + bool pending_mob_reconf = false; + asn1::rrc::rrc_conn_recfg_s mob_reconf = {}; uint8_t k_rrc_enc[32] = {}; uint8_t k_rrc_int[32] = {}; @@ -454,33 +443,33 @@ private: typedef std::unique_ptr unique_cell_t; std::vector neighbour_cells; unique_cell_t serving_cell = nullptr; - void set_serving_cell(uint32_t cell_idx); + void set_serving_cell(uint32_t cell_idx); void set_serving_cell(phy_interface_rrc_lte::phy_cell_t phy_cell); - unique_cell_t remove_neighbour_cell(const uint32_t earfcn, const uint32_t pci); - cell_t* get_neighbour_cell_handle(const uint32_t earfcn, const uint32_t pci); - bool has_neighbour_cell(const uint32_t earfcn, const uint32_t pci); - int find_neighbour_cell(uint32_t earfcn, uint32_t pci); - bool add_neighbour_cell(uint32_t earfcn, uint32_t pci, float rsrp); - bool add_neighbour_cell(phy_interface_rrc_lte::phy_cell_t phy_cell, float rsrp); - bool add_neighbour_cell(unique_cell_t new_cell); - void sort_neighbour_cells(); - void clean_neighbours(); - void delete_last_neighbour(); - std::string print_neighbour_cells(); + unique_cell_t remove_neighbour_cell(const uint32_t earfcn, const uint32_t pci); + cell_t* get_neighbour_cell_handle(const uint32_t earfcn, const uint32_t pci); + bool has_neighbour_cell(const uint32_t earfcn, const uint32_t pci); + int find_neighbour_cell(uint32_t earfcn, uint32_t pci); + bool add_neighbour_cell(uint32_t earfcn, uint32_t pci, float rsrp); + bool add_neighbour_cell(phy_interface_rrc_lte::phy_cell_t phy_cell, float rsrp); + bool add_neighbour_cell(unique_cell_t new_cell); + void sort_neighbour_cells(); + void clean_neighbours(); + void delete_last_neighbour(); + std::string print_neighbour_cells(); - bool initiated = false; - asn1::rrc::reest_cause_e m_reest_cause = asn1::rrc::reest_cause_e::nulltype; + bool initiated = false; + asn1::rrc::reest_cause_e m_reest_cause = asn1::rrc::reest_cause_e::nulltype; uint16_t m_reest_rnti = 0; - uint16_t m_reest_source_pci = 0; - bool reestablishment_started = false; + uint16_t m_reest_source_pci = 0; + bool reestablishment_started = false; bool reestablishment_successful = false; // Measurements sub-class 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; @@ -507,13 +496,13 @@ private: } meas_obj_t; typedef struct { - uint32_t interval; - uint32_t max_cell; - uint32_t amount; - quantity_t trigger_quantity; - quantity_t report_quantity; + uint32_t interval; + uint32_t max_cell; + uint32_t amount; + 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 { @@ -534,9 +523,9 @@ private: std::map cell_values; // Value for each PCI in this object } meas_t; - std::map objects; - std::map reports_cfg; - std::map active; + std::map objects; + std::map reports_cfg; + std::map active; rrc* parent = nullptr; srslte::log* log_h = nullptr; @@ -551,16 +540,16 @@ private: bool s_measure_enabled = false; float s_measure_value = 0.0; - 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); - void remove_meas_id(uint32_t measId); + 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); + void remove_meas_id(uint32_t measId); void remove_meas_id(std::map::iterator it); void calculate_triggers(uint32_t tti); void update_phy(); - 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); + 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); 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, @@ -577,15 +566,15 @@ private: // Measurement object from phy typedef struct { - float rsrp; - float rsrq; + float rsrp; + float rsrq; uint32_t tti; uint32_t earfcn; uint32_t pci; } phy_meas_t; - void process_phy_meas(); - void process_new_phy_meas(phy_meas_t meas); + void process_phy_meas(); + void process_new_phy_meas(phy_meas_t meas); srslte::block_queue phy_meas_q; // Cell selection/reselection functions/variables @@ -601,8 +590,8 @@ private: cell_resel_cfg_t cell_resel_cfg = {}; - float get_srxlev(float Qrxlevmeas); - float get_squal(float Qqualmeas); + float get_srxlev(float Qrxlevmeas); + float get_squal(float Qqualmeas); /******************** * RRC Procedures @@ -695,15 +684,15 @@ private: void handle_sib3(); void handle_sib13(); - void handle_con_setup(asn1::rrc::rrc_conn_setup_s* setup); - void handle_con_reest(asn1::rrc::rrc_conn_reest_s* setup); - void handle_rrc_con_reconfig(uint32_t lcid, asn1::rrc::rrc_conn_recfg_s* reconfig); - void handle_ue_capability_enquiry(const asn1::rrc::ue_cap_enquiry_s& enquiry); - void add_srb(asn1::rrc::srb_to_add_mod_s* srb_cnfg); - void add_drb(asn1::rrc::drb_to_add_mod_s* drb_cnfg); - void release_drb(uint32_t drb_id); + void handle_con_setup(asn1::rrc::rrc_conn_setup_s* setup); + void handle_con_reest(asn1::rrc::rrc_conn_reest_s* setup); + void handle_rrc_con_reconfig(uint32_t lcid, asn1::rrc::rrc_conn_recfg_s* reconfig); + void handle_ue_capability_enquiry(const asn1::rrc::ue_cap_enquiry_s& enquiry); + void add_srb(asn1::rrc::srb_to_add_mod_s* srb_cnfg); + void add_drb(asn1::rrc::drb_to_add_mod_s* drb_cnfg); + void release_drb(uint32_t drb_id); uint32_t get_lcid_for_eps_bearer(const uint32_t& eps_bearer_id); - void add_mrb(uint32_t lcid, uint32_t port); + void add_mrb(uint32_t lcid, uint32_t port); // Helpers for setting default values void set_phy_default_pucch_srs(); @@ -715,5 +704,4 @@ private: } // namespace srsue - #endif // SRSUE_RRC_H diff --git a/srsue/hdr/stack/ue_stack_lte.h b/srsue/hdr/stack/ue_stack_lte.h index 48c3d9feb..cf1e1d1dc 100644 --- a/srsue/hdr/stack/ue_stack_lte.h +++ b/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; diff --git a/srsue/src/stack/rrc/rrc.cc b/srsue/src/stack/rrc/rrc.cc index 031589b88..55ba76fbd 100644 --- a/srsue/src/stack/rrc/rrc.cc +++ b/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 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; diff --git a/srsue/src/stack/ue_stack_lte.cc b/srsue/src/stack/ue_stack_lte.cc index 9f887f8ec..c8f2bd25c 100644 --- a/srsue/src/stack/ue_stack_lte.cc +++ b/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) {