Skip to content

Commit 296b211

Browse files
FabianEckermannFabian Eckermann
authored andcommitted
cu_cp,rrc: Improve logging
1 parent be81e3d commit 296b211

File tree

4 files changed

+40
-93
lines changed

4 files changed

+40
-93
lines changed

lib/rrc/ue/rrc_ue_helpers.cpp

Lines changed: 18 additions & 49 deletions
Original file line numberDiff line numberDiff line change
@@ -16,80 +16,49 @@ using namespace srsran;
1616
using namespace srs_cu_cp;
1717

1818
template <class T>
19-
void srsran::srs_cu_cp::log_rrc_message(const char* source,
19+
void srsran::srs_cu_cp::log_rrc_message(rrc_ue_logger& logger,
2020
const direction_t dir,
2121
byte_buffer_view pdu,
2222
const T& msg,
2323
const char* msg_type)
2424
{
25-
if (srslog::fetch_basic_logger("RRC").debug.enabled()) {
26-
asn1::json_writer json_writer;
27-
msg.to_json(json_writer);
28-
// TODO: remove serialization
25+
if (logger.get_basic_logger().debug.enabled()) {
26+
asn1::json_writer js;
27+
msg.to_json(js);
28+
logger.log_debug(pdu.begin(),
29+
pdu.end(),
30+
"{} {} {} ({} B)",
31+
(dir == Rx) ? "Rx" : "Tx",
32+
msg_type,
33+
msg.msg.c1().type().to_string(),
34+
pdu.length());
35+
logger.log_debug("Containerized {}: {}", msg.msg.c1().type().to_string(), js.to_string());
36+
} else if (logger.get_basic_logger().info.enabled()) {
2937
std::vector<uint8_t> bytes{pdu.begin(), pdu.end()};
30-
srslog::fetch_basic_logger("RRC").debug(
31-
bytes.data(), bytes.size(), "{} - {} {} ({} B)", source, (dir == Rx) ? "Rx" : "Tx", msg_type, pdu.length());
32-
srslog::fetch_basic_logger("RRC").debug("Content: {}", json_writer.to_string().c_str());
33-
} else if (srslog::fetch_basic_logger("RRC").info.enabled()) {
34-
std::vector<uint8_t> bytes{pdu.begin(), pdu.end()};
35-
srslog::fetch_basic_logger("RRC").info(bytes.data(), bytes.size(), "{} {}", source, msg_type);
38+
logger.log_info(pdu.begin(), pdu.end(), "{}", msg_type);
3639
}
3740
}
3841

39-
template void srsran::srs_cu_cp::log_rrc_message<asn1::rrc_nr::ul_ccch_msg_s>(const char* source,
42+
template void srsran::srs_cu_cp::log_rrc_message<asn1::rrc_nr::ul_ccch_msg_s>(rrc_ue_logger& logger,
4043
const direction_t dir,
4144
byte_buffer_view pdu,
4245
const asn1::rrc_nr::ul_ccch_msg_s& msg,
4346
const char* msg_type);
4447

45-
template void srsran::srs_cu_cp::log_rrc_message<asn1::rrc_nr::ul_dcch_msg_s>(const char* source,
48+
template void srsran::srs_cu_cp::log_rrc_message<asn1::rrc_nr::ul_dcch_msg_s>(rrc_ue_logger& logger,
4649
const direction_t dir,
4750
byte_buffer_view pdu,
4851
const asn1::rrc_nr::ul_dcch_msg_s& msg,
4952
const char* msg_type);
5053

51-
template void srsran::srs_cu_cp::log_rrc_message<asn1::rrc_nr::dl_ccch_msg_s>(const char* source,
54+
template void srsran::srs_cu_cp::log_rrc_message<asn1::rrc_nr::dl_ccch_msg_s>(rrc_ue_logger& logger,
5255
const direction_t dir,
5356
byte_buffer_view pdu,
5457
const asn1::rrc_nr::dl_ccch_msg_s& msg,
5558
const char* msg_type);
5659

57-
template void srsran::srs_cu_cp::log_rrc_message<asn1::rrc_nr::dl_dcch_msg_s>(const char* source,
60+
template void srsran::srs_cu_cp::log_rrc_message<asn1::rrc_nr::dl_dcch_msg_s>(rrc_ue_logger& logger,
5861
const direction_t dir,
5962
byte_buffer_view pdu,
6063
const asn1::rrc_nr::dl_dcch_msg_s& msg,
6164
const char* msg_type);
62-
template void
63-
srsran::srs_cu_cp::log_rrc_message<asn1::rrc_nr::cell_group_cfg_s>(const char* source,
64-
const direction_t dir,
65-
byte_buffer_view pdu,
66-
const asn1::rrc_nr::cell_group_cfg_s& msg,
67-
const char* msg_type);
68-
69-
template void
70-
srsran::srs_cu_cp::log_rrc_message<asn1::rrc_nr::radio_bearer_cfg_s>(const char* source,
71-
const direction_t dir,
72-
byte_buffer_view pdu,
73-
const asn1::rrc_nr::radio_bearer_cfg_s& msg,
74-
const char* msg_type);
75-
76-
template void srsran::srs_cu_cp::log_rrc_message<asn1::rrc_nr::ho_cmd_s>(const char* source,
77-
const direction_t dir,
78-
byte_buffer_view pdu,
79-
const asn1::rrc_nr::ho_cmd_s& msg,
80-
const char* msg_type);
81-
82-
void srsran::srs_cu_cp::log_rx_pdu_fail(ue_index_t ue_index,
83-
const char* source,
84-
byte_buffer_view pdu,
85-
const char* cause_str,
86-
bool log_hex)
87-
{
88-
if (log_hex) {
89-
std::vector<uint8_t> bytes{pdu.begin(), pdu.end()};
90-
srslog::fetch_basic_logger("RRC").error(
91-
bytes.data(), bytes.size(), "ue={} Rx {} PDU - discarding cause={}", ue_index, source, cause_str);
92-
} else {
93-
srslog::fetch_basic_logger("RRC").error("ue={} Rx {} PDU - discarding cause={}", ue_index, source, cause_str);
94-
}
95-
}

lib/rrc/ue/rrc_ue_helpers.h

Lines changed: 2 additions & 7 deletions
Original file line numberDiff line numberDiff line change
@@ -10,6 +10,7 @@
1010

1111
#pragma once
1212

13+
#include "rrc_ue_logger.h"
1314
#include "srsran/adt/byte_buffer.h"
1415
#include "srsran/asn1/asn1_utils.h"
1516
#include "srsran/cu_cp/cu_cp_types.h"
@@ -35,17 +36,11 @@ byte_buffer pack_into_pdu(const T& msg, const char* context_name = nullptr)
3536
typedef enum { Rx = 0, Tx } direction_t;
3637

3738
template <class T>
38-
void log_rrc_message(const char* source,
39+
void log_rrc_message(rrc_ue_logger& logger,
3940
const direction_t dir,
4041
byte_buffer_view pdu,
4142
const T& msg,
4243
const char* msg_type);
4344

44-
void log_rx_pdu_fail(ue_index_t ue_index,
45-
const char* source,
46-
byte_buffer_view pdu,
47-
const char* cause_str,
48-
bool log_hex = true);
49-
5045
} // namespace srs_cu_cp
5146
} // namespace srsran

lib/rrc/ue/rrc_ue_message_handlers.cpp

Lines changed: 16 additions & 29 deletions
Original file line numberDiff line numberDiff line change
@@ -32,16 +32,13 @@ void rrc_ue_impl::handle_ul_ccch_pdu(byte_buffer pdu)
3232
asn1::cbit_ref bref(pdu);
3333
if (ul_ccch_msg.unpack(bref) != asn1::SRSASN_SUCCESS or
3434
ul_ccch_msg.msg.type().value != ul_ccch_msg_type_c::types_opts::c1) {
35-
log_rx_pdu_fail(context.ue_index, "CCCH UL", pdu, "Failed to unpack message", true);
35+
logger.log_error(pdu.begin(), pdu.end(), "Failed to unpack CCCH UL PDU");
3636
return;
3737
}
3838
}
3939

4040
// Log Rx message
41-
fmt::memory_buffer fmtbuf, fmtbuf2;
42-
fmt::format_to(fmtbuf, "ue={}", context.ue_index);
43-
fmt::format_to(fmtbuf2, "CCCH UL {}", ul_ccch_msg.msg.c1().type().to_string());
44-
log_rrc_message(to_c_str(fmtbuf), Rx, pdu, ul_ccch_msg, to_c_str(fmtbuf2));
41+
log_rrc_message(logger, Rx, pdu, ul_ccch_msg, "CCCH UL");
4542

4643
// Handle message
4744
switch (ul_ccch_msg.msg.c1().type().value) {
@@ -52,7 +49,7 @@ void rrc_ue_impl::handle_ul_ccch_pdu(byte_buffer pdu)
5249
handle_rrc_reest_request(ul_ccch_msg.msg.c1().rrc_reest_request());
5350
break;
5451
default:
55-
log_rx_pdu_fail(context.ue_index, "CCCH UL", pdu, "Unsupported message type");
52+
logger.log_error("Unsupported CCCH UL message type");
5653
// TODO Remove user
5754
}
5855
}
@@ -128,16 +125,15 @@ void rrc_ue_impl::handle_pdu(const srb_id_t srb_id, byte_buffer rrc_pdu)
128125
asn1::cbit_ref bref(rrc_pdu);
129126
if (ul_dcch_msg.unpack(bref) != asn1::SRSASN_SUCCESS or
130127
ul_dcch_msg.msg.type().value != ul_dcch_msg_type_c::types_opts::c1) {
131-
log_rx_pdu_fail(context.ue_index, "DCCH UL", rrc_pdu, "Failed to unpack message", true);
128+
logger.log_error(rrc_pdu.begin(), rrc_pdu.end(), "Failed to unpack DCCH UL PDU");
132129
return;
133130
}
134131
}
135132

136133
// Log Rx message
137-
fmt::memory_buffer fmtbuf, fmtbuf2;
138-
fmt::format_to(fmtbuf, "ue={} {}", context.ue_index, srb_id);
139-
fmt::format_to(fmtbuf2, "DCCH UL {}", ul_dcch_msg.msg.c1().type().to_string());
140-
log_rrc_message(to_c_str(fmtbuf), Rx, rrc_pdu, ul_dcch_msg, to_c_str(fmtbuf2));
134+
fmt::memory_buffer fmtbuf;
135+
fmt::format_to(fmtbuf, "{} DCCH UL", srb_id);
136+
log_rrc_message(logger, Rx, rrc_pdu, ul_dcch_msg, to_c_str(fmtbuf));
141137

142138
switch (ul_dcch_msg.msg.c1().type().value) {
143139
case ul_dcch_msg_type_c::c1_c_::types_opts::options::ul_info_transfer:
@@ -169,7 +165,7 @@ void rrc_ue_impl::handle_pdu(const srb_id_t srb_id, byte_buffer rrc_pdu)
169165
handle_measurement_report(ul_dcch_msg.msg.c1().meas_report());
170166
break;
171167
default:
172-
log_rx_pdu_fail(context.ue_index, "DCCH UL", rrc_pdu, "Unsupported message type");
168+
logger.log_error("Unsupported DCCH UL message type");
173169
break;
174170
}
175171
// TODO: Handle message
@@ -180,12 +176,7 @@ void rrc_ue_impl::handle_ul_dcch_pdu(const srb_id_t srb_id, byte_buffer pdcp_pdu
180176
logger.log_debug(pdcp_pdu.begin(), pdcp_pdu.end(), "RX {} PDCP PDU", srb_id);
181177

182178
if (context.srbs.find(srb_id) == context.srbs.end()) {
183-
logger.log_error(pdcp_pdu.begin(),
184-
pdcp_pdu.end(),
185-
"Dropping UlDcchPdu. RX {} is not set up",
186-
context.ue_index,
187-
context.c_rnti,
188-
srb_id);
179+
logger.log_error(pdcp_pdu.begin(), pdcp_pdu.end(), "Dropping UlDcchPdu. Rx {} is not set up", srb_id);
189180
return;
190181
}
191182

@@ -197,13 +188,6 @@ void rrc_ue_impl::handle_ul_dcch_pdu(const srb_id_t srb_id, byte_buffer pdcp_pdu
197188
return;
198189
}
199190

200-
logger.log_debug(rrc_pdu.begin(),
201-
rrc_pdu.end(),
202-
"RX {} RRC PDU ({} B)",
203-
context.ue_index,
204-
context.c_rnti,
205-
srb_id,
206-
rrc_pdu.length());
207191
handle_pdu(srb_id, std::move(rrc_pdu));
208192
}
209193

@@ -385,10 +369,13 @@ byte_buffer rrc_ue_impl::get_rrc_handover_command(const rrc_reconfiguration_proc
385369
// pack Handover Command
386370
byte_buffer ho_cmd_pdu = pack_into_pdu(ho_cmd);
387371

388-
fmt::memory_buffer fmtbuf, fmtbuf2;
389-
fmt::format_to(fmtbuf, "ue={}", context.ue_index);
390-
fmt::format_to(fmtbuf2, "{}", ho_cmd.crit_exts.c1().type().to_string());
391-
log_rrc_message(to_c_str(fmtbuf), Tx, ho_cmd_pdu, ho_cmd, to_c_str(fmtbuf2));
372+
// Log message
373+
logger.log_debug(ho_cmd_pdu.begin(), ho_cmd_pdu.end(), "RrcHandoverCommand ({} B)", ho_cmd_pdu.length());
374+
if (logger.get_basic_logger().debug.enabled()) {
375+
asn1::json_writer js;
376+
ho_cmd.to_json(js);
377+
logger.log_debug("Containerized RrcHandoverCommand: {}", js.to_string());
378+
}
392379

393380
return ho_cmd_pdu;
394381
}

lib/rrc/ue/rrc_ue_message_senders.cpp

Lines changed: 4 additions & 8 deletions
Original file line numberDiff line numberDiff line change
@@ -21,10 +21,8 @@ void rrc_ue_impl::send_dl_ccch(const dl_ccch_msg_s& dl_ccch_msg)
2121
// pack DL CCCH msg
2222
byte_buffer pdu = pack_into_pdu(dl_ccch_msg);
2323

24-
fmt::memory_buffer fmtbuf, fmtbuf2;
25-
fmt::format_to(fmtbuf, "ue={}", context.ue_index);
26-
fmt::format_to(fmtbuf2, "CCCH DL {}", dl_ccch_msg.msg.c1().type().to_string());
27-
log_rrc_message(to_c_str(fmtbuf), Tx, pdu, dl_ccch_msg, to_c_str(fmtbuf2));
24+
// Log Tx message
25+
log_rrc_message(logger, Tx, pdu, dl_ccch_msg, "CCCH DL");
2826

2927
// send down the stack
3028
logger.log_debug(pdu.begin(), pdu.end(), "TX {} PDU", srb_id_t::srb0);
@@ -41,10 +39,8 @@ void rrc_ue_impl::send_dl_dcch(srb_id_t srb_id, const dl_dcch_msg_s& dl_dcch_msg
4139
// pack DL CCCH msg
4240
byte_buffer pdu = pack_into_pdu(dl_dcch_msg);
4341

44-
fmt::memory_buffer fmtbuf, fmtbuf2;
45-
fmt::format_to(fmtbuf, "ue={}", context.ue_index);
46-
fmt::format_to(fmtbuf2, "DCCH DL {}", dl_dcch_msg.msg.c1().type().to_string());
47-
log_rrc_message(to_c_str(fmtbuf), Tx, pdu, dl_dcch_msg, to_c_str(fmtbuf2));
42+
// Log Tx message
43+
log_rrc_message(logger, Tx, pdu, dl_dcch_msg, "DCCH DL");
4844

4945
// pack PDCP PDU and send down the stack
5046
byte_buffer pdcp_pdu = context.srbs.at(srb_id).pack_rrc_pdu(std::move(pdu));

0 commit comments

Comments
 (0)