optimization - minimization of number of std::string allocations for logging

master
Francisco 4 years ago committed by Francisco Paisana
parent 1ffc4cef86
commit 5a1bf28fe1

@ -133,13 +133,12 @@ public:
{} {}
virtual ~pdu() = default; virtual ~pdu() = default;
std::string to_string() void to_string(fmt::memory_buffer& buffer)
{ {
std::stringstream ss;
for (int i = 0; i < nof_subheaders; i++) { for (int i = 0; i < nof_subheaders; i++) {
ss << subheaders[i].to_string() << " "; subheaders[i].to_string(buffer);
fmt::format_to(buffer, " ");
} }
return ss.str();
} }
/* Resets the Read/Write position and remaining PDU length */ /* Resets the Read/Write position and remaining PDU length */
@ -289,11 +288,11 @@ class subh
public: public:
virtual ~subh() {} virtual ~subh() {}
virtual bool read_subheader(uint8_t** ptr) = 0; virtual bool read_subheader(uint8_t** ptr) = 0;
virtual void read_payload(uint8_t** ptr) = 0; virtual void read_payload(uint8_t** ptr) = 0;
virtual void write_subheader(uint8_t** ptr, bool is_last) = 0; virtual void write_subheader(uint8_t** ptr, bool is_last) = 0;
virtual void write_payload(uint8_t** ptr) = 0; virtual void write_payload(uint8_t** ptr) = 0;
virtual std::string to_string() = 0; virtual void to_string(fmt::memory_buffer& buffer) = 0;
pdu<SubH>* parent = nullptr; pdu<SubH>* parent = nullptr;
@ -357,8 +356,8 @@ public:
void set_padding(uint32_t padding_len); void set_padding(uint32_t padding_len);
void set_type(subh_type type_); void set_type(subh_type type_);
void init(); void init();
std::string to_string(); void to_string(fmt::memory_buffer& buffer);
bool set_next_mch_sched_info(uint8_t lcid, uint16_t mtch_stop); bool set_next_mch_sched_info(uint8_t lcid, uint16_t mtch_stop);
@ -396,7 +395,7 @@ public:
static uint32_t size_header_sdu(uint32_t nbytes); static uint32_t size_header_sdu(uint32_t nbytes);
bool update_space_ce(uint32_t nbytes, bool var_len = false); bool update_space_ce(uint32_t nbytes, bool var_len = false);
bool update_space_sdu(uint32_t nbytes); bool update_space_sdu(uint32_t nbytes);
std::string to_string(); void to_string(fmt::memory_buffer& buffer);
}; };
class rar_subh : public subh<rar_subh> class rar_subh : public subh<rar_subh>
@ -433,8 +432,8 @@ public:
void set_temp_crnti(uint16_t temp_rnti); void set_temp_crnti(uint16_t temp_rnti);
void set_sched_grant(uint8_t grant[RAR_GRANT_LEN]); void set_sched_grant(uint8_t grant[RAR_GRANT_LEN]);
void init(); void init();
std::string to_string(); void to_string(fmt::memory_buffer& buffer);
private: private:
uint8_t grant[RAR_GRANT_LEN]; uint8_t grant[RAR_GRANT_LEN];
@ -453,8 +452,8 @@ public:
bool has_backoff(); bool has_backoff();
uint8_t get_backoff(); uint8_t get_backoff();
bool write_packet(uint8_t* ptr); bool write_packet(uint8_t* ptr);
std::string to_string(); void to_string(fmt::memory_buffer& buffer);
private: private:
bool has_backoff_indicator; bool has_backoff_indicator;

@ -70,9 +70,9 @@ struct gtpu_header_t {
std::vector<uint8_t> ext_buffer; std::vector<uint8_t> ext_buffer;
}; };
bool gtpu_read_header(srslte::byte_buffer_t* pdu, gtpu_header_t* header, srslog::basic_logger& logger); bool gtpu_read_header(srslte::byte_buffer_t* pdu, gtpu_header_t* header, srslog::basic_logger& logger);
bool gtpu_write_header(gtpu_header_t* header, srslte::byte_buffer_t* pdu, srslog::basic_logger& logger); bool gtpu_write_header(gtpu_header_t* header, srslte::byte_buffer_t* pdu, srslog::basic_logger& logger);
std::string gtpu_ntoa(uint32_t addr); void gtpu_ntoa(fmt::memory_buffer& buffer, uint32_t addr);
inline bool gtpu_supported_flags_check(gtpu_header_t* header, srslog::basic_logger& logger) inline bool gtpu_supported_flags_check(gtpu_header_t* header, srslog::basic_logger& logger)
{ {

@ -199,11 +199,10 @@ bool lcid_t::is_sdu() const
* SCH PDU * SCH PDU
*************************/ *************************/
std::string sch_pdu::to_string() void sch_pdu::to_string(fmt::memory_buffer& buffer)
{ {
std::stringstream ss; fmt::format_to(buffer, "{}", is_ul() ? "UL" : "DL");
ss << (is_ul() ? "UL " : "DL ") << pdu::to_string(); pdu::to_string(buffer);
return ss.str();
} }
void sch_pdu::parse_packet(uint8_t* ptr) void sch_pdu::parse_packet(uint8_t* ptr)
@ -897,19 +896,18 @@ void sch_subh::read_payload(uint8_t** ptr)
*ptr += nof_bytes; *ptr += nof_bytes;
} }
std::string sch_subh::to_string() void sch_subh::to_string(fmt::memory_buffer& buffer)
{ {
std::stringstream ss;
if (is_sdu()) { if (is_sdu()) {
ss << "LCID=" << lcid << " len=" << nof_bytes; fmt::format_to(buffer, "LCID={} len={}", lcid, nof_bytes);
} else if (type == SCH_SUBH_TYPE) { } else if (type == SCH_SUBH_TYPE) {
if (parent->is_ul()) { if (parent->is_ul()) {
switch ((ul_sch_lcid)lcid) { switch ((ul_sch_lcid)lcid) {
case ul_sch_lcid::CRNTI: case ul_sch_lcid::CRNTI:
ss << "CRNTI: rnti=0x" << std::hex << get_c_rnti() << std::dec; fmt::format_to(buffer, "CRNTI: rnti=0x{:x}", get_c_rnti());
break; break;
case ul_sch_lcid::PHR_REPORT: case ul_sch_lcid::PHR_REPORT:
ss << "PHR: ph=" << get_phr(); fmt::format_to(buffer, "PHR: ph={}", get_phr());
break; break;
case ul_sch_lcid::TRUNC_BSR: case ul_sch_lcid::TRUNC_BSR:
case ul_sch_lcid::SHORT_BSR: case ul_sch_lcid::SHORT_BSR:
@ -918,18 +916,18 @@ std::string sch_subh::to_string()
uint32_t buff_size_bytes[4] = {}; uint32_t buff_size_bytes[4] = {};
uint32_t lcg = get_bsr(buff_size_idx, buff_size_bytes); uint32_t lcg = get_bsr(buff_size_idx, buff_size_bytes);
if (ul_sch_ce_type() == ul_sch_lcid::LONG_BSR) { if (ul_sch_ce_type() == ul_sch_lcid::LONG_BSR) {
ss << "LBSR: b="; fmt::format_to(buffer, "LBSR: b=");
for (uint32_t i = 0; i < 4; i++) { for (uint32_t i = 0; i < 4; i++) {
ss << buff_size_idx[i] << " "; fmt::format_to(buffer, "{} ", buff_size_idx[i]);
} }
} else if (ul_sch_ce_type() == ul_sch_lcid::SHORT_BSR) { } else if (ul_sch_ce_type() == ul_sch_lcid::SHORT_BSR) {
ss << "SBSR: lcg=" << lcg << " b=" << buff_size_idx[lcg]; fmt::format_to(buffer, "SBSR: lcg={} b={}", lcg, buff_size_idx[lcg]);
} else { } else {
ss << "TBSR: lcg=" << lcg << " b=" << buff_size_idx[lcg]; fmt::format_to(buffer, "TBSR: lcg={} b={}", lcg, buff_size_idx[lcg]);
} }
} break; } break;
case ul_sch_lcid::PADDING: case ul_sch_lcid::PADDING:
ss << "PAD: len=" << get_payload_size(); fmt::format_to(buffer, "PAD: len={}", get_payload_size());
break; break;
default: default:
// do nothing // do nothing
@ -938,20 +936,20 @@ std::string sch_subh::to_string()
} else { } else {
switch ((dl_sch_lcid)lcid) { switch ((dl_sch_lcid)lcid) {
case dl_sch_lcid::CON_RES_ID: case dl_sch_lcid::CON_RES_ID:
ss << "CON_RES: id=0x" << std::hex << get_con_res_id() << std::dec; fmt::format_to(buffer, "CON_RES: id=0x{:x}", get_con_res_id());
break; break;
case dl_sch_lcid::TA_CMD: case dl_sch_lcid::TA_CMD:
ss << "TA: ta=" << std::to_string(get_ta_cmd()); fmt::format_to(buffer, "TA: ta={}", get_ta_cmd());
break; break;
case dl_sch_lcid::SCELL_ACTIVATION_4_OCTET: case dl_sch_lcid::SCELL_ACTIVATION_4_OCTET:
case dl_sch_lcid::SCELL_ACTIVATION: case dl_sch_lcid::SCELL_ACTIVATION:
ss << "SCELL_ACT"; fmt::format_to(buffer, "SCELL_ACT");
break; break;
case dl_sch_lcid::DRX_CMD: case dl_sch_lcid::DRX_CMD:
ss << "DRX"; fmt::format_to(buffer, "DRX");
break; break;
case dl_sch_lcid::PADDING: case dl_sch_lcid::PADDING:
ss << "PAD: len=" << get_payload_size(); fmt::format_to(buffer, "PAD: len={}", get_payload_size());
break; break;
default: default:
break; break;
@ -960,16 +958,15 @@ std::string sch_subh::to_string()
} else if (type == MCH_SUBH_TYPE) { } else if (type == MCH_SUBH_TYPE) {
switch ((mch_lcid)lcid) { switch ((mch_lcid)lcid) {
case mch_lcid::MCH_SCHED_INFO: case mch_lcid::MCH_SCHED_INFO:
ss << "MCH_SCHED_INFO"; fmt::format_to(buffer, "MCH_SCHED_INFO");
break; break;
case mch_lcid::PADDING: case mch_lcid::PADDING:
ss << "PAD: len=" << get_payload_size(); fmt::format_to(buffer, "PAD: len={}", get_payload_size());
break; break;
default: default:
break; break;
} }
} }
return ss.str();
} }
uint8_t sch_subh::buff_size_table(uint32_t buffer_size) uint8_t sch_subh::buff_size_table(uint32_t buffer_size)
@ -1000,11 +997,11 @@ uint8_t sch_subh::phr_report_table(float phr_value)
return (uint8_t)floor(phr_value + 23); return (uint8_t)floor(phr_value + 23);
} }
std::string rar_pdu::to_string() void rar_pdu::to_string(fmt::memory_buffer& buffer)
{ {
std::string msg("MAC PDU for RAR: "); std::string msg("MAC PDU for RAR: ");
msg += pdu::to_string(); fmt::format_to(buffer, "MAC PDU for RAR: ");
return msg; pdu::to_string(buffer);
} }
rar_pdu::rar_pdu(uint32_t max_rars_, srslog::basic_logger& logger) : pdu(max_rars_, logger) rar_pdu::rar_pdu(uint32_t max_rars_, srslog::basic_logger& logger) : pdu(max_rars_, logger)
@ -1065,20 +1062,17 @@ bool rar_pdu::write_packet(uint8_t* ptr)
return true; return true;
} }
std::string rar_subh::to_string() void rar_subh::to_string(fmt::memory_buffer& buffer)
{ {
std::stringstream ss;
if (type == RAPID) { if (type == RAPID) {
ss << "RAPID: " << preamble << ", Temp C-RNTI: " << temp_rnti << ", TA: " << ta << ", UL Grant: "; fmt::format_to(buffer, "RAPID: {}, Temp C-RNTI: {}, TA: {}, UL Grant: ", preamble, temp_rnti, ta);
} else { } else {
ss << "Backoff Indicator: " << int32_t(((rar_pdu*)parent)->get_backoff()) << " "; fmt::format_to(buffer, "Backoff Indicator: {} ", int32_t(((rar_pdu*)parent)->get_backoff()));
} }
char tmp[16]; char tmp[16];
srslte_vec_sprint_hex(tmp, sizeof(tmp), grant, RAR_GRANT_LEN); srslte_vec_sprint_hex(tmp, sizeof(tmp), grant, RAR_GRANT_LEN);
ss << tmp; fmt::format_to(buffer, "{}", tmp);
return ss.str();
} }
void rar_subh::init() void rar_subh::init()

@ -178,7 +178,7 @@ bool gtpu_read_header(srslte::byte_buffer_t* pdu, gtpu_header_t* header, srslog:
} }
// Helper function to return a string from IPv4 address for easy printing // Helper function to return a string from IPv4 address for easy printing
std::string gtpu_ntoa(uint32_t addr) void gtpu_ntoa(fmt::memory_buffer& buffer, uint32_t addr)
{ {
char tmp_str[INET_ADDRSTRLEN + 1] = {}; char tmp_str[INET_ADDRSTRLEN + 1] = {};
struct in_addr tmp_addr = {}; struct in_addr tmp_addr = {};
@ -186,9 +186,10 @@ std::string gtpu_ntoa(uint32_t addr)
tmp_addr.s_addr = addr; tmp_addr.s_addr = addr;
const char* tmp_ptr = inet_ntop(AF_INET, &tmp_addr, tmp_str, INET_ADDRSTRLEN); const char* tmp_ptr = inet_ntop(AF_INET, &tmp_addr, tmp_str, INET_ADDRSTRLEN);
if (tmp_ptr == NULL) { if (tmp_ptr == NULL) {
return std::string("Invalid IPv4 address"); fmt::format_to(buffer, "Invalid IPv4 address");
} else {
fmt::format_to(buffer, "{}", tmp_str);
} }
return std::string(tmp_str);
} }
} // namespace srslte } // namespace srslte

@ -54,7 +54,9 @@ int mac_rar_pdu_unpack_test1()
srslte::rar_pdu rar_pdu_msg; srslte::rar_pdu rar_pdu_msg;
rar_pdu_msg.init_rx(sizeof(rar_pdu_tv1)); rar_pdu_msg.init_rx(sizeof(rar_pdu_tv1));
rar_pdu_msg.parse_packet(rar_pdu_tv1); rar_pdu_msg.parse_packet(rar_pdu_tv1);
std::cout << rar_pdu_msg.to_string() << std::endl; fmt::memory_buffer buffer;
rar_pdu_msg.to_string(buffer);
std::cout << fmt::to_string(buffer) << std::endl;
TESTASSERT(not rar_pdu_msg.has_backoff()); TESTASSERT(not rar_pdu_msg.has_backoff());
TESTASSERT(rar_pdu_msg.nof_subh() == 1); TESTASSERT(rar_pdu_msg.nof_subh() == 1);
@ -72,7 +74,9 @@ int mac_rar_pdu_unpack_test2()
srslte::rar_pdu rar_pdu_msg; srslte::rar_pdu rar_pdu_msg;
rar_pdu_msg.init_rx(sizeof(rar_pdu_tv2)); rar_pdu_msg.init_rx(sizeof(rar_pdu_tv2));
rar_pdu_msg.parse_packet(rar_pdu_tv2); rar_pdu_msg.parse_packet(rar_pdu_tv2);
std::cout << rar_pdu_msg.to_string() << std::endl; fmt::memory_buffer buffer;
rar_pdu_msg.to_string(buffer);
std::cout << fmt::to_string(buffer) << std::endl;
TESTASSERT(rar_pdu_msg.nof_subh() == 2); TESTASSERT(rar_pdu_msg.nof_subh() == 2);
TESTASSERT(rar_pdu_msg.has_backoff()); TESTASSERT(rar_pdu_msg.has_backoff());
@ -101,7 +105,9 @@ int mac_rar_pdu_unpack_test3()
TESTASSERT(rar_pdu_msg.parse_packet(rar_pdu) != SRSLTE_SUCCESS); TESTASSERT(rar_pdu_msg.parse_packet(rar_pdu) != SRSLTE_SUCCESS);
TESTASSERT(rar_pdu_msg.nof_subh() == 0); TESTASSERT(rar_pdu_msg.nof_subh() == 0);
std::cout << rar_pdu_msg.to_string() << std::endl; fmt::memory_buffer buffer;
rar_pdu_msg.to_string(buffer);
std::cout << fmt::to_string(buffer) << std::endl;
return SRSLTE_SUCCESS; return SRSLTE_SUCCESS;
} }
@ -500,8 +506,9 @@ int mac_sch_pdu_pack_test6()
for (uint32_t i = 0; i < 4; i++) { for (uint32_t i = 0; i < 4; i++) {
TESTASSERT(buff_size_rx[i] == buff_size_tx[i]); TESTASSERT(buff_size_rx[i] == buff_size_tx[i]);
} }
fmt::memory_buffer str_buffer;
mac_logger.info("%s", pdu.to_string().c_str()); pdu.to_string(str_buffer);
mac_logger.info("%s", str_buffer.data());
// log // log
mac_logger.info(buffer.msg, buffer.N_bytes, "MAC PDU (%d B):", buffer.N_bytes); mac_logger.info(buffer.msg, buffer.N_bytes, "MAC PDU (%d B):", buffer.N_bytes);
@ -530,7 +537,9 @@ int mac_sch_pdu_pack_test6()
// write PDU // write PDU
pdu.write_packet(mac_logger); pdu.write_packet(mac_logger);
mac_logger.info("%s", pdu.to_string().c_str()); str_buffer.clear();
pdu.to_string(str_buffer);
mac_logger.info("%s", str_buffer.data());
TESTASSERT(memcmp(buffer.msg, tv2, buffer.N_bytes) == 0); TESTASSERT(memcmp(buffer.msg, tv2, buffer.N_bytes) == 0);
@ -583,7 +592,9 @@ int mac_sch_pdu_pack_test6()
// write PDU // write PDU
pdu.write_packet(mac_logger); pdu.write_packet(mac_logger);
mac_logger.info("%s", pdu.to_string().c_str()); str_buffer.clear();
pdu.to_string(str_buffer);
mac_logger.info("%s", str_buffer.data());
TESTASSERT(memcmp(buffer.msg, tv3, buffer.N_bytes) == 0); TESTASSERT(memcmp(buffer.msg, tv3, buffer.N_bytes) == 0);
@ -999,7 +1010,9 @@ int mac_sch_pdu_unpack_test3()
} }
} }
std::cout << pdu.to_string() << std::endl; fmt::memory_buffer buffer;
pdu.to_string(buffer);
std::cout << fmt::to_string(buffer) << std::endl;
#if HAVE_PCAP #if HAVE_PCAP
pcap_handle->write_dl_crnti(tv, sizeof(tv), 0x1001, true, 1, 0); pcap_handle->write_dl_crnti(tv, sizeof(tv), 0x1001, true, 1, 0);

@ -24,6 +24,7 @@ namespace srsenb {
class harq_proc class harq_proc
{ {
public: public:
harq_proc();
void init(uint32_t id); void init(uint32_t id);
void reset(uint32_t tb_idx); void reset(uint32_t tb_idx);
uint32_t get_id() const; uint32_t get_id() const;
@ -45,6 +46,7 @@ protected:
enum ack_t { NACK, ACK }; enum ack_t { NACK, ACK };
srslog::basic_logger* logger;
bool ack_state[SRSLTE_MAX_TB]; bool ack_state[SRSLTE_MAX_TB];
bool active[SRSLTE_MAX_TB]; bool active[SRSLTE_MAX_TB];
std::array<bool, SRSLTE_MAX_TB> ndi = {}; std::array<bool, SRSLTE_MAX_TB> ndi = {};

@ -27,6 +27,8 @@ namespace srsenb {
* *
******************************************************/ ******************************************************/
harq_proc::harq_proc() : logger(&srslog::fetch_basic_logger("MAC")) {}
void harq_proc::init(uint32_t id_) void harq_proc::init(uint32_t id_)
{ {
id = id_; id = id_;
@ -76,19 +78,17 @@ tti_point harq_proc::get_tti() const
int harq_proc::set_ack_common(uint32_t tb_idx, bool ack_) int harq_proc::set_ack_common(uint32_t tb_idx, bool ack_)
{ {
if (is_empty(tb_idx)) { if (is_empty(tb_idx)) {
srslog::fetch_basic_logger("MAC").warning("Received ACK for inactive harq"); logger->warning("Received ACK for inactive harq");
return SRSLTE_ERROR; return SRSLTE_ERROR;
} }
ack_state[tb_idx] = ack_; ack_state[tb_idx] = ack_;
srslog::fetch_basic_logger("MAC").debug( logger->debug("ACK=%d received pid=%d, tb_idx=%d, n_rtx=%d, max_retx=%d", ack_, id, tb_idx, n_rtx[tb_idx], max_retx);
"ACK=%d received pid=%d, tb_idx=%d, n_rtx=%d, max_retx=%d", ack_, id, tb_idx, n_rtx[tb_idx], max_retx);
if (!ack_ && (n_rtx[tb_idx] + 1 >= max_retx)) { if (!ack_ && (n_rtx[tb_idx] + 1 >= max_retx)) {
srslog::fetch_basic_logger("MAC").info( logger->info("SCHED: discarding TB=%d pid=%d, tti=%d, maximum number of retx exceeded (%d)",
"SCHED: discarding TB=%d pid=%d, tti=%d, maximum number of retx exceeded (%d)", tb_idx,
tb_idx, id,
id, tti.to_uint(),
tti.to_uint(), max_retx);
max_retx);
active[tb_idx] = false; active[tb_idx] = false;
} else if (ack_) { } else if (ack_) {
active[tb_idx] = false; active[tb_idx] = false;

@ -255,7 +255,9 @@ void ue::process_pdu(uint8_t* pdu, uint32_t nof_bytes, srslte::pdu_queue::channe
mac_msg_ul.init_rx(nof_bytes, true); mac_msg_ul.init_rx(nof_bytes, true);
mac_msg_ul.parse_packet(pdu); mac_msg_ul.parse_packet(pdu);
logger.info("0x%x %s", rnti, mac_msg_ul.to_string().c_str()); fmt::memory_buffer buffer;
mac_msg_ul.to_string(buffer);
logger.info("0x%x %s", rnti, buffer.data());
if (pcap) { if (pcap) {
pcap->write_ul_crnti(pdu, nof_bytes, rnti, true, last_tti, UL_CC_IDX); pcap->write_ul_crnti(pdu, nof_bytes, rnti, true, last_tti, UL_CC_IDX);
@ -529,7 +531,9 @@ uint8_t* ue::generate_pdu(uint32_t ue_cc_idx,
} }
} }
ret = mac_msg_dl.write_packet(logger); ret = mac_msg_dl.write_packet(logger);
logger.info("0x%x %s", rnti, mac_msg_dl.to_string().c_str()); fmt::memory_buffer str_buffer;
mac_msg_dl.to_string(str_buffer);
logger.info("0x%x %s", rnti, str_buffer.data());
} else { } else {
logger.error( logger.error(
"Invalid parameters calling generate_pdu: cc_idx=%d, harq_pid=%d, tb_idx=%d", ue_cc_idx, harq_pid, tb_idx); "Invalid parameters calling generate_pdu: cc_idx=%d, harq_pid=%d, tb_idx=%d", ue_cc_idx, harq_pid, tb_idx);

@ -153,12 +153,14 @@ uint32_t gtpu::add_bearer(uint16_t rnti, uint32_t lcid, uint32_t addr, uint32_t
ue_teidin_db[rnti][lcid].push_back(teid_in); ue_teidin_db[rnti][lcid].push_back(teid_in);
fmt::memory_buffer buffer;
srslte::gtpu_ntoa(buffer, htonl(addr));
logger.info("New tunnel teid_in=0x%x, teid_out=0x%x, rnti=0x%x, lcid=%d, addr=%s", logger.info("New tunnel teid_in=0x%x, teid_out=0x%x, rnti=0x%x, lcid=%d, addr=%s",
teid_in, teid_in,
teid_out, teid_out,
rnti, rnti,
lcid, lcid,
srslte::gtpu_ntoa(htonl(addr)).c_str()); buffer.data());
if (props != nullptr) { if (props != nullptr) {
if (props->flush_before_teidin_present) { if (props->flush_before_teidin_present) {
@ -517,23 +519,29 @@ srslte::span<uint32_t> gtpu::get_lcid_teids(uint16_t rnti, uint32_t lcid)
void gtpu::log_message(tunnel& tun, bool is_rx, srslte::span<uint8_t> pdu, int pdcp_sn) void gtpu::log_message(tunnel& tun, bool is_rx, srslte::span<uint8_t> pdu, int pdcp_sn)
{ {
fmt::basic_memory_buffer<char, 1024> strbuf; struct iphdr* ip_pkt = (struct iphdr*)pdu.data();
struct iphdr* ip_pkt = (struct iphdr*)pdu.data();
if (ip_pkt->version != 4 && ip_pkt->version != 6) { if (ip_pkt->version != 4 && ip_pkt->version != 6) {
logger.error("%s SDU with invalid IP version %s SPGW", is_rx ? "Received" : "Sending", is_rx ? "from" : "to"); logger.error("%s SDU with invalid IP version %s SPGW", is_rx ? "Received" : "Sending", is_rx ? "from" : "to");
return; return;
} }
if (not logger.info.enabled()) {
return;
}
const char* dir = "Tx"; fmt::basic_memory_buffer<char, 1024> strbuf;
fmt::memory_buffer strbuf2; const char* dir = "Tx";
fmt::memory_buffer strbuf2, addrbuf;
srslte::gtpu_ntoa(addrbuf, htonl(tun.spgw_addr));
if (is_rx) { if (is_rx) {
dir = "Rx"; dir = "Rx";
fmt::format_to(strbuf2, "{}:0x{:0x} > ", srslte::gtpu_ntoa(htonl(tun.spgw_addr)), tun.teid_in); fmt::format_to(strbuf2, "{}:0x{:0x} > ", addrbuf.data(), tun.teid_in);
if (not tun.dl_enabled) { if (not tun.dl_enabled) {
fmt::format_to(strbuf2, "DL (buffered), "); fmt::format_to(strbuf2, "DL (buffered), ");
} else if (tun.fwd_teid_in_present) { } else if (tun.fwd_teid_in_present) {
tunnel& tx_tun = tunnels.at(tun.fwd_teid_in); tunnel& tx_tun = tunnels.at(tun.fwd_teid_in);
fmt::format_to(strbuf2, "{}:0x{:0x} (forwarded), ", srslte::gtpu_ntoa(htonl(tx_tun.spgw_addr)), tx_tun.teid_in); addrbuf.clear();
srslte::gtpu_ntoa(addrbuf, htonl(tx_tun.spgw_addr));
fmt::format_to(strbuf2, "{}:0x{:0x} (forwarded), ", addrbuf.data(), tx_tun.teid_in);
} else { } else {
fmt::format_to(strbuf2, "DL, "); fmt::format_to(strbuf2, "DL, ");
} }
@ -543,7 +551,7 @@ void gtpu::log_message(tunnel& tun, bool is_rx, srslte::span<uint8_t> pdu, int p
} else { } else {
fmt::format_to(strbuf2, "UL "); fmt::format_to(strbuf2, "UL ");
} }
fmt::format_to(strbuf2, "> {}:0x{:0x}, ", srslte::gtpu_ntoa(htonl(tun.spgw_addr)), tun.teid_in); fmt::format_to(strbuf2, "> {}:0x{:0x}, ", addrbuf.data(), tun.teid_in);
} }
fmt::format_to(strbuf, fmt::format_to(strbuf,
"{} S1-U SDU, {}rnti=0x{:0x}, lcid={}, n_bytes={}, IPv{}", "{} S1-U SDU, {}rnti=0x{:0x}, lcid={}, n_bytes={}, IPv{}",
@ -554,12 +562,16 @@ void gtpu::log_message(tunnel& tun, bool is_rx, srslte::span<uint8_t> pdu, int p
pdu.size(), pdu.size(),
(int)ip_pkt->version); (int)ip_pkt->version);
if (ip_pkt->version == 4) { if (ip_pkt->version == 4) {
fmt::format_to(strbuf, " {} > {}", srslte::gtpu_ntoa(ip_pkt->saddr), srslte::gtpu_ntoa(ip_pkt->daddr)); addrbuf.clear();
strbuf2.clear();
srslte::gtpu_ntoa(addrbuf, ip_pkt->saddr);
srslte::gtpu_ntoa(strbuf2, ip_pkt->daddr);
fmt::format_to(strbuf, " {} > {}", addrbuf.data(), strbuf2.data());
if (ntohs(ip_pkt->tot_len) != pdu.size()) { if (ntohs(ip_pkt->tot_len) != pdu.size()) {
logger.error("IP Len and PDU N_bytes mismatch"); logger.error("IP Len and PDU N_bytes mismatch");
} }
} }
logger.info(pdu.data(), pdu.size(), fmt::to_string(strbuf)); logger.info(pdu.data(), pdu.size(), "%s", strbuf.data());
} }
/**************************************************************************** /****************************************************************************

@ -206,8 +206,12 @@ void spgw::gtpu::handle_sgi_pdu(srslte::unique_byte_buffer_t msg)
// Logging PDU info // Logging PDU info
m_logger.debug("SGi PDU -- IP version %d, Total length %d", int(iph->version), ntohs(iph->tot_len)); m_logger.debug("SGi PDU -- IP version %d, Total length %d", int(iph->version), ntohs(iph->tot_len));
m_logger.debug("SGi PDU -- IP src addr %s", srslte::gtpu_ntoa(iph->saddr).c_str()); fmt::memory_buffer buffer;
m_logger.debug("SGi PDU -- IP dst addr %s", srslte::gtpu_ntoa(iph->daddr).c_str()); srslte::gtpu_ntoa(buffer, iph->saddr);
m_logger.debug("SGi PDU -- IP src addr %s", buffer.data());
buffer.clear();
srslte::gtpu_ntoa(buffer, iph->daddr);
m_logger.debug("SGi PDU -- IP dst addr %s", buffer.data());
// Find user and control tunnel // Find user and control tunnel
gtpu_fteid_it = m_ip_to_usr_teid.find(iph->daddr); gtpu_fteid_it = m_ip_to_usr_teid.find(iph->daddr);
@ -309,8 +313,12 @@ void spgw::gtpu::send_all_queued_packets(srslte::gtp_fteid_t
bool spgw::gtpu::modify_gtpu_tunnel(in_addr_t ue_ipv4, srslte::gtpc_f_teid_ie dw_user_fteid, uint32_t up_ctrl_teid) bool spgw::gtpu::modify_gtpu_tunnel(in_addr_t ue_ipv4, srslte::gtpc_f_teid_ie dw_user_fteid, uint32_t up_ctrl_teid)
{ {
m_logger.info("Modifying GTP-U Tunnel."); m_logger.info("Modifying GTP-U Tunnel.");
m_logger.info("UE IP %s", srslte::gtpu_ntoa(ue_ipv4).c_str()); fmt::memory_buffer buffer;
m_logger.info("Downlink eNB addr %s, U-TEID 0x%x", srslte::gtpu_ntoa(dw_user_fteid.ipv4).c_str(), dw_user_fteid.teid); srslte::gtpu_ntoa(buffer, ue_ipv4);
m_logger.info("UE IP %s", buffer.data());
buffer.clear();
srslte::gtpu_ntoa(buffer, dw_user_fteid.ipv4);
m_logger.info("Downlink eNB addr %s, U-TEID 0x%x", buffer.data(), dw_user_fteid.teid);
m_logger.info("Uplink C-TEID: 0x%x", up_ctrl_teid); m_logger.info("Uplink C-TEID: 0x%x", up_ctrl_teid);
m_ip_to_usr_teid[ue_ipv4] = dw_user_fteid; m_ip_to_usr_teid[ue_ipv4] = dw_user_fteid;
m_ip_to_ctr_teid[ue_ipv4] = up_ctrl_teid; m_ip_to_ctr_teid[ue_ipv4] = up_ctrl_teid;

@ -153,7 +153,11 @@ void demux::process_pdu(uint8_t* mac_pdu, uint32_t nof_bytes, srslte::pdu_queue:
// Unpack DLSCH MAC PDU // Unpack DLSCH MAC PDU
mac_msg.init_rx(nof_bytes); mac_msg.init_rx(nof_bytes);
mac_msg.parse_packet(mac_pdu); mac_msg.parse_packet(mac_pdu);
Info("%s", mac_msg.to_string().c_str()); {
fmt::memory_buffer buffer;
mac_msg.to_string(buffer);
Info("%s", buffer.data());
}
process_sch_pdu(&mac_msg); process_sch_pdu(&mac_msg);
pdus.deallocate(mac_pdu); pdus.deallocate(mac_pdu);
break; break;

@ -285,8 +285,10 @@ uint8_t* mux::pdu_get(srslte::byte_buffer_t* payload, uint32_t pdu_sz)
bsr_procedure->update_bsr_tti_end(&bsr); bsr_procedure->update_bsr_tti_end(&bsr);
// Generate MAC PDU and save to buffer // Generate MAC PDU and save to buffer
uint8_t* ret = pdu_msg.write_packet(logger); uint8_t* ret = pdu_msg.write_packet(logger);
Info("%s", pdu_msg.to_string().c_str()); fmt::memory_buffer buffer;
pdu_msg.to_string(buffer);
Info("%s", buffer.data());
Debug("Assembled MAC PDU msg size %d/%d bytes", pdu_msg.get_pdu_len() - pdu_msg.rem_size(), pdu_sz); Debug("Assembled MAC PDU msg size %d/%d bytes", pdu_msg.get_pdu_len() - pdu_msg.rem_size(), pdu_sz);
return ret; return ret;

Loading…
Cancel
Save