From 8a064cd3a673eb806f60af459af6c892feb7ed95 Mon Sep 17 00:00:00 2001 From: Andre Puschmann Date: Mon, 16 Dec 2019 11:15:09 +0100 Subject: [PATCH] pass msg_type from caller when logging RRC message before the type of some message wasn't displayed correctly, like SIBs, for example because the logger didn't know the filed to retrieve the type string --- srsenb/hdr/stack/rrc/rrc.h | 6 +++++- srsenb/src/stack/rrc/rrc.cc | 28 +++++++++++++++++----------- srsue/hdr/stack/rrc/rrc.h | 6 +++++- srsue/src/stack/rrc/rrc.cc | 25 ++++++++++++++----------- 4 files changed, 41 insertions(+), 24 deletions(-) diff --git a/srsenb/hdr/stack/rrc/rrc.h b/srsenb/hdr/stack/rrc/rrc.h index 67f14f017..beb65b14c 100644 --- a/srsenb/hdr/stack/rrc/rrc.h +++ b/srsenb/hdr/stack/rrc/rrc.h @@ -190,7 +190,11 @@ public: // logging typedef enum { Rx = 0, Tx } direction_t; template - void log_rrc_message(const std::string& source, direction_t dir, const srslte::byte_buffer_t* pdu, const T& msg); + void log_rrc_message(const std::string& source, + direction_t dir, + const srslte::byte_buffer_t* pdu, + const T& msg, + const std::string& msg_type); // Notifier for user connect class connect_notifier diff --git a/srsenb/src/stack/rrc/rrc.cc b/srsenb/src/stack/rrc/rrc.cc index d23ffd52e..5b60f8f1b 100644 --- a/srsenb/src/stack/rrc/rrc.cc +++ b/srsenb/src/stack/rrc/rrc.cc @@ -175,16 +175,21 @@ template void rrc::log_rrc_message(const std::string& source, const direction_t dir, const srslte::byte_buffer_t* pdu, - const T& msg) + const T& msg, + const std::string& msg_type) { - const char* msg_type = msg.msg.c1().type().to_string().c_str(); if (rrc_log->get_level() == srslte::LOG_LEVEL_INFO) { - rrc_log->info("%s - %s %s (%d B)\n", source.c_str(), dir == Tx ? "Tx" : "Rx", msg_type, pdu->N_bytes); + rrc_log->info("%s - %s %s (%d B)\n", source.c_str(), dir == Tx ? "Tx" : "Rx", msg_type.c_str(), pdu->N_bytes); } else if (rrc_log->get_level() >= srslte::LOG_LEVEL_DEBUG) { asn1::json_writer json_writer; msg.to_json(json_writer); - rrc_log->debug_hex( - pdu->msg, pdu->N_bytes, "%s - %s %s (%d B)\n", source.c_str(), dir == Tx ? "Tx" : "Rx", msg_type, pdu->N_bytes); + rrc_log->debug_hex(pdu->msg, + pdu->N_bytes, + "%s - %s %s (%d B)\n", + source.c_str(), + dir == Tx ? "Tx" : "Rx", + msg_type.c_str(), + pdu->N_bytes); rrc_log->debug_long("Content:\n%s\n", json_writer.to_string().c_str()); } } @@ -595,7 +600,7 @@ bool rrc::is_paging_opportunity(uint32_t tti, uint32_t* payload_len) paging_rec->paging_record_list.size(), byte_buf_paging.N_bytes, N_bits); - log_rrc_message("PCCH-Message", Tx, &byte_buf_paging, pcch_msg); + log_rrc_message("PCCH-Message", Tx, &byte_buf_paging, pcch_msg, pcch_msg.msg.c1().type().to_string()); return true; } @@ -640,7 +645,7 @@ void rrc::parse_ul_ccch(uint16_t rnti, srslte::unique_byte_buffer_t pdu) return; } - log_rrc_message("SRB0", Rx, pdu.get(), ul_ccch_msg); + log_rrc_message("SRB0", Rx, pdu.get(), ul_ccch_msg, ul_ccch_msg.msg.c1().type().to_string()); auto user_it = users.find(rnti); switch (ul_ccch_msg.msg.c1().type()) { @@ -856,7 +861,8 @@ uint32_t rrc::generate_sibs() sib_buffer.push_back(std::move(sib)); // Log SIBs in JSON format - log_rrc_message("SIB payload", Tx, sib_buffer[msg_index].get(), msg[msg_index]); + log_rrc_message( + "SIB payload", Tx, sib_buffer[msg_index].get(), msg[msg_index], msg[msg_index].msg.c1().type().to_string()); } if (cfg.sibs[6].type() == asn1::rrc::sys_info_r8_ies_s::sib_type_and_info_item_c_::types::sib7) { @@ -1146,7 +1152,7 @@ void rrc::ue::parse_ul_dcch(uint32_t lcid, srslte::unique_byte_buffer_t pdu) return; } - parent->log_rrc_message(rb_id_text[lcid], Rx, pdu.get(), ul_dcch_msg); + parent->log_rrc_message(rb_id_text[lcid], Rx, pdu.get(), ul_dcch_msg, ul_dcch_msg.msg.c1().type().to_string()); // reuse PDU pdu->clear(); // FIXME: name collision with byte_buffer reset @@ -2144,7 +2150,7 @@ void rrc::ue::send_dl_ccch(dl_ccch_msg_s* dl_ccch_msg) char buf[32] = {}; sprintf(buf, "SRB0 - rnti=0x%x", rnti); - parent->log_rrc_message(buf, Tx, pdu.get(), *dl_ccch_msg); + parent->log_rrc_message(buf, Tx, pdu.get(), *dl_ccch_msg, dl_ccch_msg->msg.c1().type().to_string()); parent->rlc->write_sdu(rnti, RB_ID_SRB0, std::move(pdu)); } else { parent->rrc_log->error("Allocating pdu\n"); @@ -2170,7 +2176,7 @@ void rrc::ue::send_dl_dcch(dl_dcch_msg_s* dl_dcch_msg, srslte::unique_byte_buffe char buf[32] = {}; sprintf(buf, "SRB%d - rnti=0x%x", lcid, rnti); - parent->log_rrc_message(buf, Tx, pdu.get(), *dl_dcch_msg); + parent->log_rrc_message(buf, Tx, pdu.get(), *dl_dcch_msg, dl_dcch_msg->msg.c1().type().to_string()); parent->pdcp->write_sdu(rnti, lcid, std::move(pdu)); } else { diff --git a/srsue/hdr/stack/rrc/rrc.h b/srsue/hdr/stack/rrc/rrc.h index ba3fb4faa..d1f2514fd 100644 --- a/srsue/hdr/stack/rrc/rrc.h +++ b/srsue/hdr/stack/rrc/rrc.h @@ -299,7 +299,11 @@ public: typedef enum { Rx = 0, Tx } direction_t; template - void log_rrc_message(const std::string source, const direction_t dir, const srslte::byte_buffer_t* pdu, const T& msg); + void log_rrc_message(const std::string source, + const direction_t dir, + const srslte::byte_buffer_t* pdu, + const T& msg, + const std::string& msg_type); std::string print_mbms(); bool mbms_service_start(uint32_t serv, uint32_t port); diff --git a/srsue/src/stack/rrc/rrc.cc b/srsue/src/stack/rrc/rrc.cc index abf9c5b65..b1dc899cf 100644 --- a/srsue/src/stack/rrc/rrc.cc +++ b/srsue/src/stack/rrc/rrc.cc @@ -70,11 +70,14 @@ rrc::rrc(srslte::log* rrc_log_) : rrc::~rrc() = default; template -void rrc::log_rrc_message(const std::string source, const direction_t dir, const byte_buffer_t* pdu, const T& msg) +void rrc::log_rrc_message(const std::string source, + const direction_t dir, + const byte_buffer_t* pdu, + const T& msg, + const std::string& msg_type) { - const char* msg_type = msg.msg.c1().type().to_string().c_str(); if (rrc_log->get_level() == srslte::LOG_LEVEL_INFO) { - rrc_log->info("%s - %s %s (%d B)\n", source.c_str(), (dir == Rx) ? "Rx" : "Tx", msg_type, pdu->N_bytes); + rrc_log->info("%s - %s %s (%d B)\n", source.c_str(), (dir == Rx) ? "Rx" : "Tx", msg_type.c_str(), pdu->N_bytes); } else if (rrc_log->get_level() >= srslte::LOG_LEVEL_DEBUG) { asn1::json_writer json_writer; msg.to_json(json_writer); @@ -83,7 +86,7 @@ void rrc::log_rrc_message(const std::string source, const direction_t dir, const "%s - %s %s (%d B)\n", source.c_str(), (dir == Rx) ? "Rx" : "Tx", - msg_type, + msg_type.c_str(), pdu->N_bytes); rrc_log->debug_long("Content:\n%s\n", json_writer.to_string().c_str()); } @@ -1408,7 +1411,7 @@ void rrc::parse_pdu_bcch_dlsch(unique_byte_buffer_t pdu) return; } - log_rrc_message("BCCH-DLSCH", Rx, pdu.get(), dlsch_msg); + log_rrc_message("BCCH-DLSCH", Rx, pdu.get(), dlsch_msg, dlsch_msg.msg.c1().type().to_string()); if (dlsch_msg.msg.c1().type() == bcch_dl_sch_msg_type_c::c1_c_::types::sib_type1) { rrc_log->info("Processing SIB1 (1/1)\n"); @@ -1604,7 +1607,7 @@ void rrc::process_pcch(unique_byte_buffer_t pdu) return; } - log_rrc_message("PCCH", Rx, pdu.get(), pcch_msg); + log_rrc_message("PCCH", Rx, pdu.get(), pcch_msg, pcch_msg.msg.c1().type().to_string()); if (not ue_identity_configured) { rrc_log->warning("Received paging message but no ue-Identity is configured\n"); @@ -1651,7 +1654,7 @@ void rrc::parse_pdu_mch(uint32_t lcid, srslte::unique_byte_buffer_t pdu) } serving_cell->has_mcch = true; phy->set_config_mbsfn_mcch(srslte::make_mcch_msg(serving_cell->mcch)); - log_rrc_message("MCH", Rx, pdu.get(), serving_cell->mcch); + log_rrc_message("MCH", Rx, pdu.get(), serving_cell->mcch, serving_cell->mcch.msg.c1().type().to_string()); if (args.mbms_service_id >= 0) { rrc_log->info("Attempting to auto-start MBMS service %d\n", args.mbms_service_id); mbms_service_start(args.mbms_service_id, args.mbms_service_port); @@ -1697,7 +1700,7 @@ void rrc::send_ul_ccch_msg(const asn1::rrc::ul_ccch_msg_s& msg) mac->set_contention_id(uecri); uint32_t lcid = RB_ID_SRB0; - log_rrc_message(get_rb_name(lcid).c_str(), Tx, pdcp_buf.get(), msg); + log_rrc_message(get_rb_name(lcid).c_str(), Tx, pdcp_buf.get(), msg, msg.msg.c1().type().to_string()); rlc->write_sdu(lcid, std::move(pdcp_buf)); } @@ -1717,7 +1720,7 @@ void rrc::send_ul_dcch_msg(uint32_t lcid, const asn1::rrc::ul_dcch_msg_s& msg) pdcp_buf->N_bytes = (uint32_t)bref.distance_bytes(pdcp_buf->msg); pdcp_buf->set_timestamp(); - log_rrc_message(get_rb_name(lcid).c_str(), Tx, pdcp_buf.get(), msg); + log_rrc_message(get_rb_name(lcid).c_str(), Tx, pdcp_buf.get(), msg, msg.msg.c1().type().to_string()); pdcp->write_sdu(lcid, std::move(pdcp_buf)); } @@ -1766,7 +1769,7 @@ void rrc::parse_dl_ccch(unique_byte_buffer_t pdu) rrc_log->error("Failed to unpack DL-CCCH message\n"); return; } - log_rrc_message(get_rb_name(RB_ID_SRB0).c_str(), Rx, pdu.get(), dl_ccch_msg); + log_rrc_message(get_rb_name(RB_ID_SRB0).c_str(), Rx, pdu.get(), dl_ccch_msg, dl_ccch_msg.msg.c1().type().to_string()); dl_ccch_msg_type_c::c1_c_* c1 = &dl_ccch_msg.msg.c1(); switch (dl_ccch_msg.msg.c1().type().value) { @@ -1817,7 +1820,7 @@ void rrc::parse_dl_dcch(uint32_t lcid, unique_byte_buffer_t pdu) rrc_log->error("Failed to unpack DL-DCCH message\n"); return; } - log_rrc_message(get_rb_name(lcid).c_str(), Rx, pdu.get(), dl_dcch_msg); + log_rrc_message(get_rb_name(lcid).c_str(), Rx, pdu.get(), dl_dcch_msg, dl_dcch_msg.msg.c1().type().to_string()); dl_dcch_msg_type_c::c1_c_* c1 = &dl_dcch_msg.msg.c1(); switch (dl_dcch_msg.msg.c1().type().value) {