From 54fab314c0d8b56ef9e38c9e599decfb96ba05bf Mon Sep 17 00:00:00 2001 From: faluco Date: Tue, 30 Mar 2021 18:31:53 +0200 Subject: [PATCH] Enhance RRC eNB events: - Implement a common event "log_rrc" for all RRC events and discriminate by procedure using an enum. - Log events for connection, reestablishment, reconfig, reject and release. - Log the corresponding ASN1 message used by each procedure. - Redefine the JSON object for this event to match the new structure. Fixed a compilation error detected by the static analyzer in gcc9.3 where bounded_vector::data() was using taking the address of the internal buffer which confused it, prefer to use the data method of std::array. --- lib/include/srsran/adt/bounded_vector.h | 4 +- lib/include/srsran/common/enb_events.h | 11 +- lib/src/common/enb_events.cc | 66 ++++------ srsenb/hdr/stack/rrc/rrc_ue.h | 53 ++++++-- srsenb/src/stack/rrc/rrc_ue.cc | 168 ++++++++++++++++-------- 5 files changed, 192 insertions(+), 110 deletions(-) diff --git a/lib/include/srsran/adt/bounded_vector.h b/lib/include/srsran/adt/bounded_vector.h index becf2db74..0d6b7fd04 100644 --- a/lib/include/srsran/adt/bounded_vector.h +++ b/lib/include/srsran/adt/bounded_vector.h @@ -108,8 +108,8 @@ public: } T& front() { return (*this)[0]; } const T& front() const { return (*this)[0]; } - T* data() { return &buffer[0].get(); } - const T* data() const { return &buffer[0].get(); } + T* data() { return reinterpret_cast(buffer.data()); } + const T* data() const { return reinterpret_cast(buffer.data()); } // Iterators iterator begin() { return data(); } diff --git a/lib/include/srsran/common/enb_events.h b/lib/include/srsran/common/enb_events.h index 32bf39a97..de69a5125 100644 --- a/lib/include/srsran/common/enb_events.h +++ b/lib/include/srsran/common/enb_events.h @@ -29,11 +29,12 @@ class event_logger_interface public: virtual ~event_logger_interface() = default; - /// Logs into the underlying log channel the RRC connected event. - virtual void log_rrc_connected(uint32_t enb_cc_idx, const std::string& asn1, unsigned error_code, uint16_t rnti) = 0; - - /// Logs into the underlying log channel the RRC disconnected event. - virtual void log_rrc_disconnect(uint32_t enb_cc_idx, unsigned reason, uint16_t rnti) = 0; + /// Logs into the underlying log channel any RRC event. + virtual void log_rrc_event(uint32_t enb_cc_idx, + const std::string& asn1, + unsigned type, + unsigned additional_info, + uint16_t rnti) = 0; /// Logs into the underlying log channel the S1 context create event. virtual void log_s1_ctx_create(uint32_t enb_cc_idx, uint32_t mme_id, uint32_t enb_id, uint16_t rnti) = 0; diff --git a/lib/src/common/enb_events.cc b/lib/src/common/enb_events.cc index cc45fc7ce..160b0fe32 100644 --- a/lib/src/common/enb_events.cc +++ b/lib/src/common/enb_events.cc @@ -22,8 +22,12 @@ namespace { class null_event_logger : public event_logger_interface { public: - void log_rrc_connected(uint32_t enb_cc_idx, const std::string& asn1, unsigned error_code, uint16_t rnti) override {} - void log_rrc_disconnect(uint32_t enb_cc_idx, unsigned reason, uint16_t rnti) override {} + void log_rrc_event(uint32_t enb_cc_idx, + const std::string& asn1, + unsigned type, + unsigned additional_info, + uint16_t rnti) override + {} void log_s1_ctx_create(uint32_t enb_cc_idx, uint32_t mme_id, uint32_t enb_id, uint16_t rnti) override {} void log_s1_ctx_delete(uint32_t enb_cc_idx, uint32_t mme_id, uint32_t enb_id, uint16_t rnti) override {} void log_sector_start(uint32_t cc_idx, uint32_t pci, uint32_t cell_id) override {} @@ -63,28 +67,18 @@ DECLARE_METRIC_SET("event_data", mset_sector_event, metric_pci, metric_cell_iden using sector_event_t = srslog:: build_context_type; -/// Context for RRC connect. -DECLARE_METRIC("error_code", metric_error_code, uint32_t, ""); +/// Context for a RRC event. +DECLARE_METRIC("asn1_type", metric_asn1_type, uint32_t, ""); +DECLARE_METRIC("additional", metric_additional, uint32_t, ""); DECLARE_METRIC_SET("event_data", - mset_rrc_connect_event, + mset_rrc_event, metric_rnti, metric_asn1_length, metric_asn1_message, - metric_error_code); -using rrc_connect_event_t = srslog::build_context_type; - -/// Context for RRC disconnect. -DECLARE_METRIC("reason", metric_reason, uint32_t, ""); -DECLARE_METRIC_SET("event_data", mset_rrc_disconnect_event, metric_reason, metric_rnti); -using rrc_disconnect_event_t = srslog::build_context_type; + metric_asn1_type, + metric_additional); +using rrc_event_t = srslog:: + build_context_type; /// Context for S1 context create/delete. DECLARE_METRIC("mme_ue_s1ap_id", metric_ue_mme_id, uint32_t, ""); @@ -112,31 +106,23 @@ class logging_event_logger : public event_logger_interface public: explicit logging_event_logger(srslog::log_channel& c) : event_channel(c) {} - void log_rrc_connected(uint32_t enb_cc_idx, const std::string& asn1, unsigned error_code, uint16_t rnti) override - { - rrc_connect_event_t ctx(""); - - ctx.write("event"); - ctx.write(get_time_stamp()); - ctx.write(enb_cc_idx); - ctx.write("rrc_connect"); - ctx.get().write(rnti); - ctx.get().write(asn1.size()); - ctx.get().write(asn1); - ctx.get().write(error_code); - event_channel(ctx); - } - - void log_rrc_disconnect(uint32_t enb_cc_idx, unsigned reason, uint16_t rnti) override + void log_rrc_event(uint32_t enb_cc_idx, + const std::string& asn1, + unsigned type, + unsigned additional_info, + uint16_t rnti) override { - rrc_disconnect_event_t ctx(""); + rrc_event_t ctx(""); ctx.write("event"); ctx.write(get_time_stamp()); ctx.write(enb_cc_idx); - ctx.write("rrc_disconnect"); - ctx.get().write(reason); - ctx.get().write(rnti); + ctx.write("rrc_log"); + ctx.get().write(rnti); + ctx.get().write(asn1.size()); + ctx.get().write(asn1); + ctx.get().write(type); + ctx.get().write(additional_info); event_channel(ctx); } diff --git a/srsenb/hdr/stack/rrc/rrc_ue.h b/srsenb/hdr/stack/rrc/rrc_ue.h index feac3600a..c442194f3 100644 --- a/srsenb/hdr/stack/rrc/rrc_ue.h +++ b/srsenb/hdr/stack/rrc/rrc_ue.h @@ -50,11 +50,22 @@ public: ///< Helper to access a cell cfg based on ue_cc_idx enb_cell_common* get_ue_cc_cfg(uint32_t ue_cc_idx); + /// List of results a RRC procedure may produce. + enum class procedure_result_code { + none, + activity_timeout, + error_mme_not_connected, + error_unknown_rnti, + radio_conn_with_ue_lost, + msg3_timeout, + unspecified + }; + void send_connection_setup(); void send_connection_reest(uint8_t ncc); - void send_connection_reject(); + void send_connection_reject(procedure_result_code cause); void send_connection_release(); - void send_connection_reest_rej(); + void send_connection_reest_rej(procedure_result_code cause); void send_connection_reconf(srsran::unique_byte_buffer_t sdu = {}, bool phy_cfg_updated = true, const asn1::unbounded_octstring* nas_pdu = nullptr); @@ -64,11 +75,20 @@ public: void parse_ul_dcch(uint32_t lcid, srsran::unique_byte_buffer_t pdu); - /// List of results for a connection request. - enum class conn_request_result_t { success, error_mme_not_connected, error_unknown_rnti }; - - /// Possible causes for the RRC to transition to the idle state. - enum class rrc_idle_transition_cause { release, timeout, radio_conn_with_ue_lost, msg3_timeout, unspecified }; + /// List of generated RRC events. + enum class rrc_event_type { + con_request, + con_setup, + con_setup_complete, + con_reconf, + con_reconf_complete, + con_reest_req, + con_reest, + con_reest_complete, + con_reest_reject, + con_reject, + con_release + }; void handle_rrc_con_req(asn1::rrc::rrc_conn_request_s* msg); void handle_rrc_con_setup_complete(asn1::rrc::rrc_conn_setup_complete_s* msg, srsran::unique_byte_buffer_t pdu); @@ -101,9 +121,19 @@ public: bool is_allocated() const; bool is_crnti_set() const { return mac_ctrl.is_crnti_set(); } - void send_dl_ccch(asn1::rrc::dl_ccch_msg_s* dl_ccch_msg); + /** + * Sends the CCCH message to the underlying layer and optionally encodes it as an octet string if a valid string + * pointer is passed. + */ + void send_dl_ccch(asn1::rrc::dl_ccch_msg_s* dl_ccch_msg, std::string* octet_str = nullptr); + + /** + * Sends the DCCH message to the underlying layer and optionally encodes it as an octet string if a valid string + * pointer is passed. + */ bool send_dl_dcch(const asn1::rrc::dl_dcch_msg_s* dl_dcch_msg, - srsran::unique_byte_buffer_t pdu = srsran::unique_byte_buffer_t()); + srsran::unique_byte_buffer_t pdu = srsran::unique_byte_buffer_t(), + std::string* octet_str = nullptr); void save_ul_message(srsran::unique_byte_buffer_t pdu) { last_ul_msg = std::move(pdu); } @@ -156,9 +186,12 @@ private: bearer_cfg_handler bearer_list; security_cfg_handler ue_security_cfg; - /// Cached message of the last uplinl message. + /// Cached message of the last uplink message. srsran::unique_byte_buffer_t last_ul_msg; + /// Connection release result. + procedure_result_code con_release_result = procedure_result_code::none; + // controllers mac_controller mac_ctrl; diff --git a/srsenb/src/stack/rrc/rrc_ue.cc b/srsenb/src/stack/rrc/rrc_ue.cc index 56b729201..67036b947 100644 --- a/srsenb/src/stack/rrc/rrc_ue.cc +++ b/srsenb/src/stack/rrc/rrc_ue.cc @@ -117,27 +117,18 @@ void rrc::ue::activity_timer_expired(activity_timeout_type_t type) if (parent->s1ap->user_exists(rnti)) { if (type == UE_INACTIVITY_TIMEOUT) { parent->s1ap->user_release(rnti, asn1::s1ap::cause_radio_network_opts::user_inactivity); - event_logger::get().log_rrc_disconnect(ue_cell_list.get_ue_cc_idx(UE_PCELL_CC_IDX)->cell_common->enb_cc_idx, - static_cast(rrc_idle_transition_cause::timeout), - rnti); + con_release_result = procedure_result_code::activity_timeout; } else if (type == UE_REESTABLISH_TIMEOUT) { parent->s1ap->user_release(rnti, asn1::s1ap::cause_radio_network_opts::radio_conn_with_ue_lost); - event_logger::get().log_rrc_disconnect( - ue_cell_list.get_ue_cc_idx(UE_PCELL_CC_IDX)->cell_common->enb_cc_idx, - static_cast(rrc_idle_transition_cause::radio_conn_with_ue_lost), - rnti); + con_release_result = procedure_result_code::radio_conn_with_ue_lost; } else if (type == MSG3_RX_TIMEOUT) { // MSG3 timeout, no need to notify S1AP, just remove UE parent->rem_user_thread(rnti); - event_logger::get().log_rrc_disconnect(ue_cell_list.get_ue_cc_idx(UE_PCELL_CC_IDX)->cell_common->enb_cc_idx, - static_cast(rrc_idle_transition_cause::msg3_timeout), - rnti); + con_release_result = procedure_result_code::msg3_timeout; } else { // Unhandled activity timeout, just remove UE and log an error parent->rem_user_thread(rnti); - event_logger::get().log_rrc_disconnect(ue_cell_list.get_ue_cc_idx(UE_PCELL_CC_IDX)->cell_common->enb_cc_idx, - static_cast(rrc_idle_transition_cause::msg3_timeout), - rnti); + con_release_result = procedure_result_code::activity_timeout; parent->logger.error( "Unhandled reason for activity timer expiration. rnti=0x%x, cause %d", rnti, static_cast(type)); } @@ -232,9 +223,11 @@ void rrc::ue::parse_ul_dcch(uint32_t lcid, srsran::unique_byte_buffer_t pdu) switch (ul_dcch_msg.msg.c1().type()) { case ul_dcch_msg_type_c::c1_c_::types::rrc_conn_setup_complete: + save_ul_message(std::move(original_pdu)); handle_rrc_con_setup_complete(&ul_dcch_msg.msg.c1().rrc_conn_setup_complete(), std::move(pdu)); break; case ul_dcch_msg_type_c::c1_c_::types::rrc_conn_reest_complete: + save_ul_message(std::move(original_pdu)); handle_rrc_con_reest_complete(&ul_dcch_msg.msg.c1().rrc_conn_reest_complete(), std::move(pdu)); break; case ul_dcch_msg_type_c::c1_c_::types::ul_info_transfer: @@ -255,6 +248,7 @@ void rrc::ue::parse_ul_dcch(uint32_t lcid, srsran::unique_byte_buffer_t pdu) parent->s1ap->write_pdu(rnti, std::move(pdu)); break; case ul_dcch_msg_type_c::c1_c_::types::rrc_conn_recfg_complete: + save_ul_message(std::move(original_pdu)); handle_rrc_reconf_complete(&ul_dcch_msg.msg.c1().rrc_conn_recfg_complete(), std::move(pdu)); srsran::console("User 0x%x connected\n", rnti); state = RRC_STATE_REGISTERED; @@ -274,7 +268,7 @@ void rrc::ue::parse_ul_dcch(uint32_t lcid, srsran::unique_byte_buffer_t pdu) send_connection_reconf(std::move(pdu)); state = RRC_STATE_WAIT_FOR_CON_RECONF_COMPLETE; } else { - send_connection_reject(); + send_connection_reject(procedure_result_code::none); state = RRC_STATE_IDLE; } break; @@ -305,13 +299,16 @@ std::string rrc::ue::to_string(const activity_timeout_type_t& type) */ void rrc::ue::handle_rrc_con_req(rrc_conn_request_s* msg) { + // Log event. + event_logger::get().log_rrc_event(ue_cell_list.get_ue_cc_idx(UE_PCELL_CC_IDX)->cell_common->enb_cc_idx, + asn1::octstring_to_string(last_ul_msg->msg, last_ul_msg->N_bytes), + static_cast(rrc_event_type::con_request), + static_cast(procedure_result_code::none), + rnti); + if (not parent->s1ap->is_mme_connected()) { parent->logger.error("MME isn't connected. Sending Connection Reject"); - event_logger::get().log_rrc_connected(ue_cell_list.get_ue_cc_idx(UE_PCELL_CC_IDX)->cell_common->enb_cc_idx, - asn1::octstring_to_string(last_ul_msg->msg, last_ul_msg->N_bytes), - static_cast(conn_request_result_t::error_mme_not_connected), - rnti); - send_connection_reject(); + send_connection_reject(procedure_result_code::error_mme_not_connected); return; } @@ -365,13 +362,28 @@ void rrc::ue::send_connection_setup() // Configure PHY layer apply_setup_phy_config_dedicated(rr_cfg.phys_cfg_ded); // It assumes SCell has not been set before - send_dl_ccch(&dl_ccch_msg); + std::string octet_str; + send_dl_ccch(&dl_ccch_msg, &octet_str); + + // Log event. + event_logger::get().log_rrc_event(ue_cell_list.get_ue_cc_idx(UE_PCELL_CC_IDX)->cell_common->enb_cc_idx, + octet_str, + static_cast(rrc_event_type::con_setup), + static_cast(procedure_result_code::none), + rnti); apply_rr_cfg_ded_diff(current_ue_cfg.rr_cfg, rr_cfg); } void rrc::ue::handle_rrc_con_setup_complete(rrc_conn_setup_complete_s* msg, srsran::unique_byte_buffer_t pdu) { + // Log event. + event_logger::get().log_rrc_event(ue_cell_list.get_ue_cc_idx(UE_PCELL_CC_IDX)->cell_common->enb_cc_idx, + asn1::octstring_to_string(last_ul_msg->msg, last_ul_msg->N_bytes), + static_cast(rrc_event_type::con_setup_complete), + static_cast(procedure_result_code::none), + rnti); + // Inform PHY about the configuration completion parent->phy->complete_config(rnti); @@ -398,12 +410,6 @@ void rrc::ue::handle_rrc_con_setup_complete(rrc_conn_setup_complete_s* msg, srsr } state = RRC_STATE_WAIT_FOR_CON_RECONF_COMPLETE; - // Log event. - event_logger::get().log_rrc_connected(enb_cc_idx, - asn1::octstring_to_string(last_ul_msg->msg, last_ul_msg->N_bytes), - static_cast(conn_request_result_t::success), - rnti); - // 2> if the UE has radio link failure or handover failure information available if (msg->crit_exts.type().value == c1_or_crit_ext_opts::c1 and msg->crit_exts.c1().type().value == @@ -415,13 +421,22 @@ void rrc::ue::handle_rrc_con_setup_complete(rrc_conn_setup_complete_s* msg, srsr } } -void rrc::ue::send_connection_reject() +void rrc::ue::send_connection_reject(procedure_result_code cause) { mac_ctrl.handle_con_reject(); dl_ccch_msg_s dl_ccch_msg; dl_ccch_msg.msg.set_c1().set_rrc_conn_reject().crit_exts.set_c1().set_rrc_conn_reject_r8().wait_time = 10; - send_dl_ccch(&dl_ccch_msg); + + std::string octet_str; + send_dl_ccch(&dl_ccch_msg, &octet_str); + + // Log event. + event_logger::get().log_rrc_event(ue_cell_list.get_ue_cc_idx(UE_PCELL_CC_IDX)->cell_common->enb_cc_idx, + octet_str, + static_cast(rrc_event_type::con_reject), + static_cast(cause), + rnti); } /* @@ -429,13 +444,16 @@ void rrc::ue::send_connection_reject() */ void rrc::ue::handle_rrc_con_reest_req(rrc_conn_reest_request_s* msg) { + // Log event. + event_logger::get().log_rrc_event(ue_cell_list.get_ue_cc_idx(UE_PCELL_CC_IDX)->cell_common->enb_cc_idx, + asn1::octstring_to_string(last_ul_msg->msg, last_ul_msg->N_bytes), + static_cast(rrc_event_type::con_reest_req), + static_cast(procedure_result_code::none), + rnti); + if (not parent->s1ap->is_mme_connected()) { parent->logger.error("MME isn't connected. Sending Connection Reject"); - event_logger::get().log_rrc_connected(ue_cell_list.get_ue_cc_idx(UE_PCELL_CC_IDX)->cell_common->enb_cc_idx, - asn1::octstring_to_string(last_ul_msg->msg, last_ul_msg->N_bytes), - static_cast(conn_request_result_t::error_mme_not_connected), - rnti); - send_connection_reject(); + send_connection_reject(procedure_result_code::error_mme_not_connected); return; } parent->logger.debug("rnti=0x%x, phyid=0x%x, smac=0x%x, cause=%s", @@ -496,11 +514,7 @@ void rrc::ue::handle_rrc_con_reest_req(rrc_conn_reest_request_s* msg) set_activity_timeout(UE_INACTIVITY_TIMEOUT); } else { parent->logger.error("Received ConnectionReestablishment for rnti=0x%x without context", old_rnti); - event_logger::get().log_rrc_connected(ue_cell_list.get_ue_cc_idx(UE_PCELL_CC_IDX)->cell_common->enb_cc_idx, - asn1::octstring_to_string(last_ul_msg->msg, last_ul_msg->N_bytes), - static_cast(conn_request_result_t::error_unknown_rnti), - rnti); - send_connection_reest_rej(); + send_connection_reest_rej(procedure_result_code::error_unknown_rnti); } } else { parent->logger.error("Received ReestablishmentRequest from an rnti=0x%x not in IDLE", rnti); @@ -532,13 +546,28 @@ void rrc::ue::send_connection_reest(uint8_t ncc) // Configure PHY layer apply_setup_phy_config_dedicated(rr_cfg.phys_cfg_ded); // It assumes SCell has not been set before - send_dl_ccch(&dl_ccch_msg); + std::string octet_str; + send_dl_ccch(&dl_ccch_msg, &octet_str); apply_rr_cfg_ded_diff(current_ue_cfg.rr_cfg, rr_cfg); + + // Log event. + event_logger::get().log_rrc_event(ue_cell_list.get_ue_cc_idx(UE_PCELL_CC_IDX)->cell_common->enb_cc_idx, + octet_str, + static_cast(rrc_event_type::con_reest), + static_cast(procedure_result_code::none), + rnti); } void rrc::ue::handle_rrc_con_reest_complete(rrc_conn_reest_complete_s* msg, srsran::unique_byte_buffer_t pdu) { + // Log event. + event_logger::get().log_rrc_event(ue_cell_list.get_ue_cc_idx(UE_PCELL_CC_IDX)->cell_common->enb_cc_idx, + asn1::octstring_to_string(last_ul_msg->msg, last_ul_msg->N_bytes), + static_cast(rrc_event_type::con_reest_complete), + static_cast(procedure_result_code::none), + rnti); + // Inform PHY about the configuration completion parent->phy->complete_config(rnti); @@ -567,11 +596,6 @@ void rrc::ue::handle_rrc_con_reest_complete(rrc_conn_reest_complete_s* msg, srsr state = RRC_STATE_REESTABLISHMENT_COMPLETE; - event_logger::get().log_rrc_connected(ue_cell_list.get_ue_cc_idx(UE_PCELL_CC_IDX)->cell_common->enb_cc_idx, - asn1::octstring_to_string(last_ul_msg->msg, last_ul_msg->N_bytes), - 0, - rnti); - // 2> if the UE has radio link failure or handover failure information available if (msg->crit_exts.type().value == rrc_conn_reest_complete_s::crit_exts_c_::types_opts::rrc_conn_reest_complete_r8) { const auto& complete_r8 = msg->crit_exts.rrc_conn_reest_complete_r8(); @@ -583,13 +607,22 @@ void rrc::ue::handle_rrc_con_reest_complete(rrc_conn_reest_complete_s* msg, srsr send_connection_reconf(std::move(pdu)); } -void rrc::ue::send_connection_reest_rej() +void rrc::ue::send_connection_reest_rej(procedure_result_code cause) { mac_ctrl.handle_con_reject(); dl_ccch_msg_s dl_ccch_msg; dl_ccch_msg.msg.set_c1().set_rrc_conn_reest_reject().crit_exts.set_rrc_conn_reest_reject_r8(); - send_dl_ccch(&dl_ccch_msg); + + std::string octet_str; + send_dl_ccch(&dl_ccch_msg, &octet_str); + + // Log event. + event_logger::get().log_rrc_event(ue_cell_list.get_ue_cc_idx(UE_PCELL_CC_IDX)->cell_common->enb_cc_idx, + octet_str, + static_cast(rrc_event_type::con_reest_reject), + static_cast(cause), + rnti); } /* @@ -653,7 +686,15 @@ void rrc::ue::send_connection_reconf(srsran::unique_byte_buffer_t pdu, } // send DL-DCCH message to lower layers - send_dl_dcch(&dl_dcch_msg, std::move(pdu)); + std::string octet_str; + send_dl_dcch(&dl_dcch_msg, std::move(pdu), &octet_str); + + // Log event. + event_logger::get().log_rrc_event(ue_cell_list.get_ue_cc_idx(UE_PCELL_CC_IDX)->cell_common->enb_cc_idx, + octet_str, + static_cast(rrc_event_type::con_reconf), + static_cast(procedure_result_code::none), + rnti); state = RRC_STATE_WAIT_FOR_CON_RECONF_COMPLETE; } @@ -669,6 +710,13 @@ void rrc::ue::handle_rrc_reconf_complete(rrc_conn_recfg_complete_s* msg, srsran: return; } + // Log event. + event_logger::get().log_rrc_event(ue_cell_list.get_ue_cc_idx(UE_PCELL_CC_IDX)->cell_common->enb_cc_idx, + asn1::octstring_to_string(last_ul_msg->msg, last_ul_msg->N_bytes), + static_cast(rrc_event_type::con_reconf_complete), + static_cast(procedure_result_code::none), + rnti); + // Activate SCells and bearers in the MAC scheduler that were advertised in the RRC Reconf message mac_ctrl.handle_con_reconf_complete(); @@ -825,12 +873,15 @@ void rrc::ue::send_connection_release() } } - send_dl_dcch(&dl_dcch_msg); + std::string octet_str; + send_dl_dcch(&dl_dcch_msg, nullptr, &octet_str); // Log rrc release event. - event_logger::get().log_rrc_disconnect(ue_cell_list.get_ue_cc_idx(UE_PCELL_CC_IDX)->cell_common->enb_cc_idx, - static_cast(rrc_idle_transition_cause::release), - rnti); + event_logger::get().log_rrc_event(ue_cell_list.get_ue_cc_idx(UE_PCELL_CC_IDX)->cell_common->enb_cc_idx, + octet_str, + static_cast(rrc_event_type::con_release), + static_cast(con_release_result), + rnti); } /* @@ -1099,7 +1150,7 @@ void rrc::ue::update_scells() /********************** HELPERS ***************************/ -void rrc::ue::send_dl_ccch(dl_ccch_msg_s* dl_ccch_msg) +void rrc::ue::send_dl_ccch(dl_ccch_msg_s* dl_ccch_msg, std::string* octet_str) { // Allocate a new PDU buffer, pack the message and send to PDCP srsran::unique_byte_buffer_t pdu = srsran::make_byte_buffer(); @@ -1114,13 +1165,19 @@ 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, dl_ccch_msg->msg.c1().type().to_string()); + + // Encode the pdu as an octet string if the user passed a valid pointer. + if (octet_str) { + *octet_str = asn1::octstring_to_string(pdu->msg, pdu->N_bytes); + } + parent->rlc->write_sdu(rnti, RB_ID_SRB0, std::move(pdu)); } else { parent->logger.error("Allocating pdu"); } } -bool rrc::ue::send_dl_dcch(const dl_dcch_msg_s* dl_dcch_msg, srsran::unique_byte_buffer_t pdu) +bool rrc::ue::send_dl_dcch(const dl_dcch_msg_s* dl_dcch_msg, srsran::unique_byte_buffer_t pdu, std::string* octet_str) { if (!pdu) { pdu = srsran::make_byte_buffer(); @@ -1143,6 +1200,11 @@ bool rrc::ue::send_dl_dcch(const dl_dcch_msg_s* dl_dcch_msg, srsran::unique_byte sprintf(buf, "SRB%d - rnti=0x%x", lcid, rnti); parent->log_rrc_message(buf, Tx, pdu.get(), *dl_dcch_msg, dl_dcch_msg->msg.c1().type().to_string()); + // Encode the pdu as an octet string if the user passed a valid pointer. + if (octet_str) { + *octet_str = asn1::octstring_to_string(pdu->msg, pdu->N_bytes); + } + parent->pdcp->write_sdu(rnti, lcid, std::move(pdu)); } else { parent->logger.error("Allocating pdu");