VIRT-PHY: Separate logging of L1 Control and L1 Data

L1 Data is quite verbose, while control is typically limited, so let's
make sure we log them as separate sub-systems

Change-Id: Idebc371a63508c593855486ff01b2ba6e8c2cfd1
This commit is contained in:
Harald Welte 2017-07-19 12:14:35 +02:00
parent 198dbda3c8
commit f7dafcc5d2
6 changed files with 37 additions and 7 deletions

View File

@ -5,6 +5,7 @@
/* L1CTL related messages */
enum virtphy_log_cat {
DL1C,
DL1P,
DVIRPHY,
DMAIN
};

View File

@ -70,7 +70,6 @@ void l1ctl_sap_rx_from_l23_inst_cb(struct l1ctl_sock_client *lsc, struct msgb *m
if (!msg)
return;
DEBUGPMS(DL1C, ms, "Message incoming from layer 2: %s\n", osmo_hexdump(msg->data, msg->len));
l1ctl_sap_handler(ms, msg);
}
@ -146,6 +145,20 @@ struct msgb *l1ctl_create_l2_msg(int msg_type, uint32_t fn, uint16_t snr, uint16
return msg;
}
static bool is_l1ctl_control(uint8_t msg_type)
{
switch (msg_type) {
case L1CTL_DATA_REQ:
case L1CTL_DATA_CONF:
case L1CTL_TRAFFIC_REQ:
case L1CTL_TRAFFIC_CONF:
case L1CTL_TRAFFIC_IND:
return false;
default:
return true;
}
}
/**
* @brief General handler for incoming L1CTL messages from layer 2/3.
*
@ -154,6 +167,7 @@ struct msgb *l1ctl_create_l2_msg(int msg_type, uint32_t fn, uint16_t snr, uint16
void l1ctl_sap_handler(struct l1_model_ms *ms, struct msgb *msg)
{
struct l1ctl_hdr *l1h;
int log_subsys;
if (!msg)
return;
@ -165,6 +179,13 @@ void l1ctl_sap_handler(struct l1_model_ms *ms, struct msgb *msg)
goto exit_msgbfree;
}
if (is_l1ctl_control(l1h->msg_type))
log_subsys = DL1C;
else
log_subsys = DL1P;
DEBUGPMS(log_subsys, ms, "Message incoming from layer 2: %s\n", osmo_hexdump(msg->data, msg->len));
switch (l1h->msg_type) {
case L1CTL_FBSB_REQ:
l1ctl_rx_fbsb_req(ms, msg);

View File

@ -64,7 +64,15 @@ static const struct log_info_cat default_categories[] = {
.description = "Layer 1 Control",
.color = "\033[1;31m",
.enabled = 1,
.loglevel = LOGL_DEBUG, },
.loglevel = LOGL_DEBUG,
},
[DL1P] = {
.name = "DL1P",
.description = "Layer 1 Data",
.color = "\033[1;31m",
.enabled = 1,
.loglevel = LOGL_DEBUG,
},
[DVIRPHY] = {
.name = "DVIRPHY",
.description = "Virtual Layer 1 Interface",

View File

@ -71,7 +71,7 @@ void l1ctl_rx_data_req(struct l1_model_ms *ms, struct msgb *msg)
ul->chan_nr, ul->link_id);
rsl_dec_chan_nr(ul->chan_nr, &rsl_chantype, &subslot, &timeslot);
DEBUGPMS(DL1C, ms,
DEBUGPMS(DL1P, ms,
"Received and handled from l23 - L1CTL_DATA_REQ (link_id=0x%02x, ul=%p, ul->payload=%p, data_ind=%p, data_ind->data=%p l3h=%p)\n",
ul->link_id, ul, ul->payload, data_ind, data_ind->data,
msg->l3h);
@ -107,7 +107,7 @@ void l1ctl_tx_data_ind(struct l1_model_ms *ms, struct msgb *msg, uint16_t arfcn,
memcpy(l1di->data, msgb_data(msg), msgb_length(msg));
DEBUGPMS(DL1C, ms, "Sending signaling-data to l23.\n");
DEBUGPMS(DL1P, ms, "Sending signaling-data to l23.\n");
l1ctl_sap_tx_to_l23_inst(ms, l1ctl_msg);
}

View File

@ -69,7 +69,7 @@ void l1ctl_rx_traffic_req(struct l1_model_ms *ms, struct msgb *msg)
uint32_t fn_sched = sched_fn_ul(ms->state.current_time, ul->chan_nr, ul->link_id);
rsl_dec_chan_nr(ul->chan_nr, &rsl_chantype, &subslot, &timeslot);
DEBUGPMS(DL1C, ms, "Received and handled from l23 - L1CTL_TRAFFIC_REQ\n");
DEBUGPMS(DL1P, ms, "Received and handled from l23 - L1CTL_TRAFFIC_REQ\n");
msg->l2h = tr->data;
@ -102,7 +102,7 @@ void l1ctl_tx_traffic_ind(struct l1_model_ms *ms, struct msgb *msg, uint16_t arf
/* TODO: traffic decoding and decryption */
memcpy(l1ti->data, msgb_data(msg), msgb_length(msg));
DEBUGPMS(DL1C, ms, "Sending to l23 - L1CTL_TRAFFIC_IND\n");
DEBUGPMS(DL1P, ms, "Sending to l23 - L1CTL_TRAFFIC_IND\n");
l1ctl_sap_tx_to_l23_inst(ms, l1ctl_msg);
}

View File

@ -37,7 +37,7 @@
#include <virtphy/logging.h>
#include <virtphy/virt_l1_sched.h>
#define DEFAULT_LOG_MASK "DL1C,1:DVIRPHY,1:DMAIN,1"
#define DEFAULT_LOG_MASK "DL1C,1:DL1P,1:DVIRPHY,1:DMAIN,1"
/* this exists once in the program, and contains the state that we
* only keep once: L1CTL server socket, GSMTAP/VirtUM socket */