diff --git a/src/host/virt_phy/src/gsmtapl1_if.c b/src/host/virt_phy/src/gsmtapl1_if.c index ac1c2b5f8..545402263 100644 --- a/src/host/virt_phy/src/gsmtapl1_if.c +++ b/src/host/virt_phy/src/gsmtapl1_if.c @@ -30,6 +30,7 @@ #include #include #include +#include #include #include #include @@ -39,6 +40,14 @@ #include #include +static char *pseudo_lchan_name(uint16_t arfcn, uint8_t ts, uint8_t ss, uint8_t sub_type) +{ + static char lname[64]; + snprintf(lname, sizeof(lname), "(arfcn=%u,ts=%u,ss=%u,type=%s)", + arfcn, ts, ss, get_value_string(gsmtap_gsm_channel_names, sub_type)); + return lname; +} + /** * Replace l11 header of given msgb by a gsmtap header and send it over the virt um. */ @@ -70,18 +79,16 @@ void gsmtapl1_tx_to_virt_um_inst(struct l1_model_ms *ms, uint32_t fn, struct msg outmsg->l1h = msgb_data(outmsg); gh = msgb_l1(outmsg); if (virt_um_write_msg(ms->vui, outmsg) == -1) { - LOGPMS(DVIRPHY, LOGL_ERROR, ms, "Gsmtap msg could not send to virt um - " - "(arfcn=%u, type=%u, subtype=%u, timeslot=%u, subslot=%u)\n", - gh->arfcn, gh->type, gh->sub_type, gh->timeslot, - gh->sub_slot); + LOGPMS(DVIRPHY, LOGL_ERROR, ms, "%s Tx go GSMTAP failed: %s\n", + pseudo_lchan_name(gh->arfcn, gh->timeslot, gh->sub_slot, gh->sub_type), + strerror(errno)); } else { - DEBUGPMS(DVIRPHY, ms, "Sending gsmtap msg to virt um - " - "(arfcn=%u, type=%u, subtype=%u, timeslot=%u, subslot=%u)\n", - gh->arfcn, gh->type, gh->sub_type, gh->timeslot, - gh->sub_slot); + DEBUGPMS(DVIRPHY, ms, "%s: Tx to GSMTAP: %s\n", + pseudo_lchan_name(gh->arfcn, gh->timeslot, gh->sub_slot, gh->sub_type), + osmo_hexdump(data, data_len)); } } else - LOGPMS(DVIRPHY, LOGL_ERROR, ms, "Gsmtap msg could not be created!\n"); + LOGPMS(DVIRPHY, LOGL_ERROR, ms, "GSMTAP msg could not be created!\n"); /* free message */ msgb_free(msg); @@ -118,9 +125,6 @@ static void l1ctl_from_virt_um(struct l1ctl_sock_client *lsc, struct msgb *msg, } /* generally ignore all messages coming from another arfcn than the camped one */ if (ms->state.serving_cell.arfcn != arfcn) { - LOGPMS(DVIRPHY, LOGL_NOTICE, ms, - "Ignoring gsmtap msg from virt um - msg arfcn=%d not equal synced arfcn=%d!\n", - arfcn, ms->state.serving_cell.arfcn); return; } @@ -155,8 +159,7 @@ static void l1ctl_from_virt_um(struct l1ctl_sock_client *lsc, struct msgb *msg, l1ctl_tx_data_ind(ms, msg, arfcn, link_id, chan_nr, fn, snr_db, signal_dbm, 0, 0); break; case GSMTAP_CHANNEL_RACH: - LOGPMS(DVIRPHY, LOGL_NOTICE, ms, - "Ignoring gsmtap msg from virt um - channel type is uplink only!\n"); + LOGPMS(DVIRPHY, LOGL_NOTICE, ms, "Ignoring unexpected RACH in downlink ?!?\n"); break; case GSMTAP_CHANNEL_SDCCH: case GSMTAP_CHANNEL_CCCH: @@ -165,12 +168,12 @@ static void l1ctl_from_virt_um(struct l1ctl_sock_client *lsc, struct msgb *msg, case GSMTAP_CHANNEL_PTCCH: case GSMTAP_CHANNEL_CBCH51: case GSMTAP_CHANNEL_CBCH52: - LOGPMS(DVIRPHY, LOGL_NOTICE, ms, - "Ignoring gsmtap msg from virt um - channel type not supported!\n"); + LOGPMS(DVIRPHY, LOGL_NOTICE, ms, "Ignoring unsupported channel type %s\n", + get_value_string(gsmtap_gsm_channel_names, gsmtap_chantype)); break; default: - LOGPMS(DVIRPHY, LOGL_NOTICE, ms, - "Ignoring gsmtap msg from virt um - channel type unknown.\n"); + LOGPMS(DVIRPHY, LOGL_NOTICE, ms, "Ignoring unknown channel type %s\n", + get_value_string(gsmtap_gsm_channel_names, gsmtap_chantype)); break; } } @@ -203,24 +206,25 @@ void gsmtapl1_rx_from_virt_um_inst_cb(struct virt_um_inst *vui, uint8_t rsl_chantype; /* rsl chan type (8.58, 9.3.1) */ uint8_t link_id; /* rsl link id tells if this is an ssociated or dedicated link */ uint8_t chan_nr; /* encoded rsl channel type, timeslot and mf subslot */ + struct gsm_time gtime; msg->l2h = msgb_pull(msg, sizeof(*gh)); chantype_gsmtap2rsl(gsmtap_chantype, &rsl_chantype, &link_id); /* see TS 08.58 -> 9.3.1 for channel number encoding */ chan_nr = rsl_enc_chan_nr(rsl_chantype, subslot, timeslot); + gsm_fn2gsmtime(>ime, fn); + + DEBUGP(DVIRPHY, "%s Rx from VirtUM: FN=%s chan_nr=0x%02x link_id=0x%02x\n", + pseudo_lchan_name(arfcn, timeslot, subslot, gsmtap_chantype), + osmo_dump_gsmtime(>ime), chan_nr, link_id); + /* generally ignore all uplink messages received */ if (arfcn & GSMTAP_ARFCN_F_UPLINK) { - LOGP(DVIRPHY, LOGL_NOTICE, "Ignoring gsmtap msg from virt um - uplink flag set!\n"); + LOGP(DVIRPHY, LOGL_NOTICE, "Ignoring unexpected uplink message in downlink!\n"); goto freemsg; } - DEBUGP(DVIRPHY, "Receiving gsmtap msg from virt um - " - "(arfcn=%u, framenumber=%u, type=%s, subtype=%s, timeslot=%u, subslot=%u, rsl_chan_type=0x%2x, link_id=0x%2x, chan_nr=0x%2x)\n", - arfcn, fn, get_value_string(gsmtap_type_names, gh->type), - get_value_string(gsmtap_gsm_channel_names, gsmtap_chantype), timeslot, - subslot, rsl_chantype, link_id, chan_nr); - /* dispatch the incoming DL message from GSMTAP to each of the registered L1CTL instances */ llist_for_each_entry(lsc, &lsi->clients, list) { l1ctl_from_virt_um(lsc, msg, fn, arfcn, timeslot, subslot, gsmtap_chantype, diff --git a/src/host/virt_phy/src/l1ctl_sap.c b/src/host/virt_phy/src/l1ctl_sap.c index d8960425b..c7c8e3e08 100644 --- a/src/host/virt_phy/src/l1ctl_sap.c +++ b/src/host/virt_phy/src/l1ctl_sap.c @@ -184,7 +184,7 @@ void l1ctl_sap_handler(struct l1_model_ms *ms, struct msgb *msg) else log_subsys = DL1P; - DEBUGPMS(log_subsys, ms, "Message incoming from layer 2: %s\n", osmo_hexdump(msg->data, msg->len)); + DEBUGPMS(log_subsys, ms, "Rx RAW from MS: %s\n", msgb_hexdump(msg)); switch (l1h->msg_type) { case L1CTL_FBSB_REQ: @@ -266,7 +266,7 @@ void l1ctl_rx_dm_est_req(struct l1_model_ms *ms, struct msgb *msg) rsl_dec_chan_nr(ul->chan_nr, &rsl_chantype, &subslot, ×lot); - DEBUGPMS(DL1C, ms, "Received and handled from l23 - L1CTL_DM_EST_REQ (chan_nr=0x%02x, tn=%u, ss=%u)\n", + LOGPMS(DL1C, LOGL_INFO, ms, "Rx L1CTL_DM_EST_REQ (chan_nr=0x%02x, tn=%u, ss=%u)\n", ul->chan_nr, timeslot, subslot); ms->state.dedicated.chan_type = rsl_chantype; @@ -301,7 +301,7 @@ void l1ctl_rx_dm_freq_req(struct l1_model_ms *ms, struct msgb *msg) struct l1ctl_info_ul *ul = (struct l1ctl_info_ul *) l1h->data; struct l1ctl_dm_freq_req *freq_req = (struct l1ctl_dm_freq_req *) ul->payload; - DEBUGPMS(DL1C, ms, "Received and ignored from l23 - L1CTL_DM_FREQ_REQ (arfcn0=%u, hsn=%u, maio=%u)\n", + LOGPMS(DL1C, LOGL_INFO, ms, "Rx L1CTL_DM_FREQ_REQ (arfcn0=%u, hsn=%u, maio=%u): IGNORED\n", ntohs(freq_req->h0.band_arfcn), freq_req->h1.hsn, freq_req->h1.maio); } @@ -326,11 +326,11 @@ void l1ctl_rx_crypto_req(struct l1_model_ms *ms, struct msgb *msg) struct l1ctl_crypto_req *cr = (struct l1ctl_crypto_req *) ul->payload; uint8_t key_len = msg->len - sizeof(*l1h) - sizeof(*ul) - sizeof(*cr); - DEBUGPMS(DL1C, ms, "Received and handled from l23 - L1CTL_CRYPTO_REQ (algo=A5/%u, len=%u)\n", + LOGPMS(DL1C, LOGL_INFO, ms, "Rx L1CTL_CRYPTO_REQ (algo=A5/%u, len=%u)\n", cr->algo, key_len); if (cr->algo && key_len != A5_KEY_LEN) { - LOGP(DL1C, LOGL_ERROR, "L1CTL_CRYPTO_REQ -> Invalid key\n"); + LOGPMS(DL1C, LOGL_ERROR, ms, "L1CTL_CRYPTO_REQ -> Invalid key\n"); return; } @@ -350,7 +350,7 @@ void l1ctl_rx_crypto_req(struct l1_model_ms *ms, struct msgb *msg) */ void l1ctl_rx_dm_rel_req(struct l1_model_ms *ms, struct msgb *msg) { - DEBUGPMS(DL1C, ms, "Received and handled from l23 - L1CTL_DM_REL_REQ\n"); + LOGPMS(DL1C, LOGL_INFO, ms, "Rx L1CTL_DM_REL_REQ\n"); ms->state.dedicated.chan_type = 0; ms->state.dedicated.tn = 0; @@ -379,7 +379,7 @@ void l1ctl_rx_param_req(struct l1_model_ms *ms, struct msgb *msg) struct l1ctl_info_ul *ul = (struct l1ctl_info_ul *)l1h->data; struct l1ctl_par_req *par_req = (struct l1ctl_par_req *)ul->payload; - DEBUGPMS(DL1C, ms, "Received and ignored from l23 - L1CTL_PARAM_REQ (ta=%d, tx_power=%d)\n", + LOGPMS(DL1C, LOGL_INFO, ms, "Rx L1CTL_PARAM_REQ (ta=%d, tx_power=%d)\n", par_req->ta, par_req->tx_power); } @@ -403,18 +403,18 @@ void l1ctl_rx_reset_req(struct l1_model_ms *ms, struct msgb *msg) switch (reset_req->type) { case L1CTL_RES_T_FULL: - DEBUGPMS(DL1C, ms, "Received and handled from l23 - L1CTL_RESET_REQ (type=FULL)\n"); + DEBUGPMS(DL1C, ms, "Rx L1CTL_RESET_REQ (type=FULL)\n"); ms->state.state = MS_STATE_IDLE_SEARCHING; virt_l1_sched_stop(ms); l1ctl_tx_reset(ms, L1CTL_RESET_CONF, reset_req->type); break; case L1CTL_RES_T_SCHED: virt_l1_sched_restart(ms, ms->state.downlink_time); - DEBUGPMS(DL1C, ms, "Received and handled from l23 - L1CTL_RESET_REQ (type=SCHED)\n"); + DEBUGPMS(DL1C, ms, "Rx L1CTL_RESET_REQ (type=SCHED)\n"); l1ctl_tx_reset(ms, L1CTL_RESET_CONF, reset_req->type); break; default: - LOGPMS(DL1C, LOGL_ERROR, ms, "Received and ignored from l23 - L1CTL_RESET_REQ (type=unknown)\n"); + LOGPMS(DL1C, LOGL_ERROR, ms, "Rx L1CTL_RESET_REQ (type=unknown): IGNORED\n"); break; } } @@ -438,7 +438,7 @@ void l1ctl_rx_ccch_mode_req(struct l1_model_ms *ms, struct msgb *msg) struct l1ctl_ccch_mode_req *ccch_mode_req = (struct l1ctl_ccch_mode_req *) l1h->data; uint8_t ccch_mode = ccch_mode_req->ccch_mode; - DEBUGPMS(DL1C, ms, "Received and handled from l23 - L1CTL_CCCH_MODE_REQ\n"); + LOGPMS(DL1C, LOGL_INFO, ms, "Rx L1CTL_CCCH_MODE_REQ (mode=%u)\n", ccch_mode); ms->state.serving_cell.ccch_mode = ccch_mode; @@ -465,7 +465,7 @@ void l1ctl_rx_tch_mode_req(struct l1_model_ms *ms, struct msgb *msg) l1_model_tch_mode_set(ms, tch_mode_req->tch_mode); ms->state.audio_mode = tch_mode_req->audio_mode; - DEBUGPMS(DL1C, ms, "Received and handled from l23 - L1CTL_TCH_MODE_REQ (tch_mode=0x%02x audio_mode=0x%02x)\n", + LOGPMS(DL1C, LOGL_INFO, ms, "Rx L1CTL_TCH_MODE_REQ (tch_mode=0x%02x audio_mode=0x%02x)\n", tch_mode_req->tch_mode, tch_mode_req->audio_mode); /* TODO: configure audio hardware for encoding / decoding / recording / playing voice */ @@ -491,8 +491,7 @@ void l1ctl_rx_neigh_pm_req(struct l1_model_ms *ms, struct msgb *msg) struct l1ctl_hdr *l1h = (struct l1ctl_hdr *) msg->data; struct l1ctl_neigh_pm_req *pm_req = (struct l1ctl_neigh_pm_req *) l1h->data; - DEBUGPMS(DL1C, ms, "Received and ignored from l23 - L1CTL_NEIGH_PM_REQ new list with %u entries\n", - pm_req->n); + LOGPMS(DL1C, LOGL_INFO, ms, "Rx L1CTL_NEIGH_PM_REQ (list with %u entries): IGNORED\n", pm_req->n); } /** @@ -519,7 +518,7 @@ void l1ctl_rx_sim_req(struct l1_model_ms *ms, struct msgb *msg) uint16_t len = msg->len - sizeof(struct l1ctl_hdr); uint8_t *data = msg->data + sizeof(struct l1ctl_hdr); - LOGPMS(DL1C, LOGL_ERROR, ms, "Received and ignored from l23 - SIM Request length: %u, data: %s\n", + LOGPMS(DL1C, LOGL_ERROR, ms, "Rx SIM Request (length: %u, data: %s): UNSUPPORTED\n", len, osmo_hexdump(data, sizeof(data))); } @@ -544,7 +543,7 @@ void l1ctl_tx_reset(struct l1_model_ms *ms, uint8_t msg_type, uint8_t reset_type struct l1ctl_reset *reset_resp = (struct l1ctl_reset *) msgb_put(msg, sizeof(*reset_resp)); reset_resp->type = reset_type; - DEBUGPMS(DL1C, ms, "Sending to l23 - %s (reset_type: %u)\n", getL1ctlPrimName(msg_type), reset_type); + LOGPMS(DL1C, LOGL_INFO, ms, "Tx %s (reset_type: %u)\n", getL1ctlPrimName(msg_type), reset_type); l1ctl_sap_tx_to_l23_inst(ms, msg); } @@ -566,7 +565,7 @@ void l1ctl_tx_ccch_mode_conf(struct l1_model_ms *ms, uint8_t ccch_mode) mode_conf = (struct l1ctl_ccch_mode_conf *) msgb_put(msg, sizeof(*mode_conf)); mode_conf->ccch_mode = ccch_mode; - DEBUGPMS(DL1C, ms, "Sending to l23 - L1CTL_CCCH_MODE_CONF (mode: %u)\n", ccch_mode); + LOGPMS(DL1C, LOGL_INFO, ms, "Tx L1CTL_CCCH_MODE_CONF (mode: %u)\n", ccch_mode); l1ctl_sap_tx_to_l23_inst(ms, msg); } @@ -589,7 +588,7 @@ void l1ctl_tx_tch_mode_conf(struct l1_model_ms *ms, uint8_t tch_mode, uint8_t au mode_conf->tch_mode = tch_mode; mode_conf->audio_mode = audio_mode; - DEBUGPMS(DL1C, ms, "Sending to l23 - L1CTL_TCH_MODE_CONF (tch_mode: %u, audio_mode: %u)\n", + LOGPMS(DL1C, LOGL_INFO, ms, "Tx L1CTL_TCH_MODE_CONF (tch_mode: %u, audio_mode: %u)\n", tch_mode, audio_mode); l1ctl_sap_tx_to_l23_inst(ms, msg); } diff --git a/src/host/virt_phy/src/virt_prim_data.c b/src/host/virt_phy/src/virt_prim_data.c index cf34e7aed..8931cf91e 100644 --- a/src/host/virt_phy/src/virt_prim_data.c +++ b/src/host/virt_phy/src/virt_prim_data.c @@ -71,13 +71,11 @@ 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, ×lot); - 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); - msg->l2h = data_ind->data; + LOGPMS(DL1P, LOGL_INFO, ms, "Rx L1CTL_DATA_REQ (chan_nr=0x%02x, link_id=0x%02x) %s\n", + ul->chan_nr, ul->link_id, osmo_hexdump(msg->l2h, msgb_l2len(msg))); + virt_l1_sched_schedule(ms, msg, fn_sched, timeslot, &virt_l1_sched_handler_cb); } @@ -107,7 +105,8 @@ 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(DL1P, ms, "Sending signaling-data to l23.\n"); + LOGPMS(DL1P, LOGL_INFO, ms, "TX L1CTL_DATA_IND (link_id=0x%02x) %s\n", link_id, + osmo_hexdump(msgb_data(msg), msgb_length(msg))); l1ctl_sap_tx_to_l23_inst(ms, l1ctl_msg); } @@ -124,5 +123,6 @@ void l1ctl_tx_data_conf(struct l1_model_ms *ms, uint32_t fn, uint16_t snr, uint1 struct msgb * l1ctl_msg; l1ctl_msg = l1ctl_create_l2_msg(L1CTL_DATA_CONF, fn, snr, arfcn); /* send confirm to layer23 */ + LOGPMS(DL1P, LOGL_INFO, ms, "Tx L1CTL_DATA_CONF\n"); l1ctl_sap_tx_to_l23_inst(ms, l1ctl_msg); } diff --git a/src/host/virt_phy/src/virt_prim_fbsb.c b/src/host/virt_phy/src/virt_prim_fbsb.c index 932f16363..c14a44856 100644 --- a/src/host/virt_phy/src/virt_prim_fbsb.c +++ b/src/host/virt_phy/src/virt_prim_fbsb.c @@ -57,8 +57,8 @@ void l1ctl_rx_fbsb_req(struct l1_model_ms *ms, struct msgb *msg) struct l1ctl_hdr *l1h = (struct l1ctl_hdr *) msg->data; struct l1ctl_fbsb_req *sync_req = (struct l1ctl_fbsb_req *) l1h->data; - DEBUGPMS(DL1C, ms, "Received and handled from l23 - L1CTL_FBSB_REQ (arfcn=%u, flags=0x%x)\n", - ntohs(sync_req->band_arfcn), sync_req->flags); + LOGPMS(DL1C, LOGL_INFO, ms, "Rx L1CTL_FBSB_REQ (arfcn=%u, flags=0x%x)\n", + ntohs(sync_req->band_arfcn), sync_req->flags); l1s->state = MS_STATE_IDLE_SYNCING; l1s->fbsb.arfcn = ntohs(sync_req->band_arfcn); @@ -126,7 +126,7 @@ void l1ctl_tx_fbsb_conf(struct l1_model_ms *ms, uint8_t res, uint16_t arfcn) resp->result = res; resp->bsic = bsic; - DEBUGPMS(DL1C, ms, "Sending to l23 - %s (res: %u)\n", getL1ctlPrimName(L1CTL_FBSB_CONF), res); + LOGPMS(DL1C, LOGL_INFO, ms, "Tx L1CTL_FBSB_CONF (res: %u)\n", res); l1ctl_sap_tx_to_l23_inst(ms, msg); } diff --git a/src/host/virt_phy/src/virt_prim_pm.c b/src/host/virt_phy/src/virt_prim_pm.c index 3202680c7..1cd3c03ec 100644 --- a/src/host/virt_phy/src/virt_prim_pm.c +++ b/src/host/virt_phy/src/virt_prim_pm.c @@ -91,7 +91,7 @@ void l1ctl_rx_pm_req(struct l1_model_ms *ms, struct msgb *msg) pm_req->range.band_arfcn_from = ntohs(pm_req->range.band_arfcn_from); pm_req->range.band_arfcn_to = ntohs(pm_req->range.band_arfcn_to); - DEBUGPMS(DL1C, ms, "Received from l23 - L1CTL_PM_REQ TYPE=%u, FROM=%d, TO=%d\n", + LOGPMS(DL1C, LOGL_INFO, ms, "Rx L1CTL_PM_REQ TYPE=%u, FROM=%d, TO=%d\n", pm_req->type, pm_req->range.band_arfcn_from, pm_req->range.band_arfcn_to); for (arfcn_next = pm_req->range.band_arfcn_from; @@ -108,13 +108,16 @@ void l1ctl_rx_pm_req(struct l1_model_ms *ms, struct msgb *msg) } /* no more space to hold mor pm info in msgb, flush to l23 */ if (msgb_tailroom(resp_msg) < sizeof(*pm_conf)) { + LOGPMS(DL1C, LOGL_INFO, ms, "Tx L1CTL_PM_CONF\n"); l1ctl_sap_tx_to_l23_inst(ms, resp_msg); resp_msg = l1ctl_msgb_alloc(L1CTL_PM_CONF); } } /* transmit the remaining part of pm response to l23 */ - if (resp_msg) + if (resp_msg) { + LOGPMS(DL1C, LOGL_INFO, ms, "Tx L1CTL_PM_CONF\n"); l1ctl_sap_tx_to_l23_inst(ms, resp_msg); + } } /** diff --git a/src/host/virt_phy/src/virt_prim_rach.c b/src/host/virt_phy/src/virt_prim_rach.c index c5bac731d..8fb0e2f71 100644 --- a/src/host/virt_phy/src/virt_prim_rach.c +++ b/src/host/virt_phy/src/virt_prim_rach.c @@ -82,7 +82,7 @@ void l1ctl_rx_rach_req(struct l1_model_ms *ms, struct msgb *msg) uint8_t ts = 1; /* FIXME mostly, ts 1 is used for rach, where can i get that info? System info? */ uint16_t offset = ntohs(rach_req->offset); - DEBUGPMS(DL1C, ms, "Received and handled from l23 - L1CTL_RACH_REQ (ra=0x%02x, offset=%d combined=%d)\n", + LOGPMS(DL1C, LOGL_INFO, ms, "Rx L1CTL_RACH_REQ (ra=0x%02x, offset=%d combined=%d)\n", rach_req->ra, offset, rach_req->combined); if (rach_req->ra == 0x03) @@ -123,7 +123,6 @@ void l1ctl_tx_rach_conf(struct l1_model_ms *ms, uint32_t fn, uint16_t arfcn) { struct msgb *msg = l1ctl_create_l2_msg(L1CTL_RACH_CONF, fn, 0, arfcn); - DEBUGPMS(DL1C, ms, "Sending to l23 - %s (fn: %u, arfcn: %u)\n", - getL1ctlPrimName(L1CTL_RACH_CONF), fn, arfcn); + LOGPMS(DL1C, LOGL_INFO, ms, "Tx L1CTL_RACH_CONF (fn: %u, arfcn: %u)\n", fn, arfcn); l1ctl_sap_tx_to_l23_inst(ms, msg); } diff --git a/src/host/virt_phy/src/virt_prim_traffic.c b/src/host/virt_phy/src/virt_prim_traffic.c index 46ba9f17e..6798bc1c7 100644 --- a/src/host/virt_phy/src/virt_prim_traffic.c +++ b/src/host/virt_phy/src/virt_prim_traffic.c @@ -69,7 +69,8 @@ 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, ×lot); - DEBUGPMS(DL1P, ms, "Received and handled from l23 - L1CTL_TRAFFIC_REQ\n"); + DEBUGPMS(DL1P, ms, "Rx L1CTL_TRAFFIC_REQ (chan_nr=0x%02x, link_id=0x%02x)\n", + ul->chan_nr, ul->link_id); msg->l2h = tr->data; @@ -102,7 +103,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(DL1P, ms, "Sending to l23 - L1CTL_TRAFFIC_IND\n"); + DEBUGPMS(DL1P, ms, "Tx L1CTL_TRAFFIC_IND (chan_nr=0x%02x, link_id=0x%02x)\n", chan_nr, link_id); l1ctl_sap_tx_to_l23_inst(ms, l1ctl_msg); } @@ -119,5 +120,6 @@ void l1ctl_tx_traffic_conf(struct l1_model_ms *ms, uint32_t fn, uint16_t snr, ui struct msgb * l1ctl_msg; l1ctl_msg = l1ctl_create_l2_msg(L1CTL_TRAFFIC_CONF, fn, snr, arfcn); /* send confirm to layer23 */ + DEBUGPMS(DL1P, ms, "Tx L1CTL_TRAFFIC_CONF\n"); l1ctl_sap_tx_to_l23_inst(ms, l1ctl_msg); }