From 198dbda3c830e5a361d335a34305fb70a805986e Mon Sep 17 00:00:00 2001 From: Harald Welte Date: Wed, 19 Jul 2017 11:53:13 +0200 Subject: [PATCH] VIRT-PHY: Log MS context number whenever possible Now that we can have multiple MS connected to one virtphy instance, it is important to log some context whenever possible. To do so, we introduce a monotonically increasing MS number which gets assigned whenever we allocate a l1_model_ms and printed when the LOGPMS() or DEBUGPMS() macros are used. Change-Id: Id7d9507126a03def5bd7690f1dbe987f9a749e65 --- src/host/virt_phy/include/virtphy/logging.h | 11 ++++++-- src/host/virt_phy/include/virtphy/virt_l1_model.h | 1 + src/host/virt_phy/src/gsmtapl1_if.c | 14 +++++----- src/host/virt_phy/src/l1ctl_sap.c | 34 +++++++++++------------ src/host/virt_phy/src/l1ctl_sock.c | 12 ++++---- src/host/virt_phy/src/logging.c | 14 ++++++++-- src/host/virt_phy/src/virt_l1_model.c | 8 ++++++ src/host/virt_phy/src/virt_prim_data.c | 4 +-- src/host/virt_phy/src/virt_prim_fbsb.c | 4 +-- src/host/virt_phy/src/virt_prim_pm.c | 4 +-- src/host/virt_phy/src/virt_prim_rach.c | 4 +-- src/host/virt_phy/src/virt_prim_traffic.c | 4 +-- src/host/virt_phy/src/virtphy.c | 2 +- 13 files changed, 71 insertions(+), 45 deletions(-) diff --git a/src/host/virt_phy/include/virtphy/logging.h b/src/host/virt_phy/include/virtphy/logging.h index 6ca25253..c98986c6 100644 --- a/src/host/virt_phy/include/virtphy/logging.h +++ b/src/host/virt_phy/include/virtphy/logging.h @@ -2,8 +2,15 @@ #include -#define DL1C 0 -#define DVIRPHY 1 +/* L1CTL related messages */ +enum virtphy_log_cat { + DL1C, + DVIRPHY, + DMAIN +}; + +#define LOGPMS(ss, lvl, ms, fmt, args ...) LOGP(ss, lvl, "MS %04u: " fmt, ms->nr, ## args) +#define DEBUGPMS(ss, ms, fmt, args ...) DEBUGP(ss, "MS %04u: " fmt, ms->nr, ## args) extern const struct log_info ms_log_info; diff --git a/src/host/virt_phy/include/virtphy/virt_l1_model.h b/src/host/virt_phy/include/virtphy/virt_l1_model.h index 0cb53815..fa791270 100644 --- a/src/host/virt_phy/include/virtphy/virt_l1_model.h +++ b/src/host/virt_phy/include/virtphy/virt_l1_model.h @@ -93,6 +93,7 @@ struct l1_state_ms { }; struct l1_model_ms { + uint32_t nr; /* pointer to the L1CTL socket client associated with this specific MS */ struct l1ctl_sock_client *lsc; /* pointer to the (shared) GSMTAP/VirtUM socket to talk to BTS(s) */ diff --git a/src/host/virt_phy/src/gsmtapl1_if.c b/src/host/virt_phy/src/gsmtapl1_if.c index dfcd5a84..ac1c2b5f 100644 --- a/src/host/virt_phy/src/gsmtapl1_if.c +++ b/src/host/virt_phy/src/gsmtapl1_if.c @@ -70,18 +70,18 @@ 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) { - LOGP(DVIRPHY, LOGL_ERROR, "Gsmtap msg could not send to virt um - " + 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); } else { - DEBUGP(DVIRPHY, "Sending gsmtap msg to virt um - " + 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); } } else - LOGP(DVIRPHY, LOGL_ERROR, "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,7 +118,7 @@ 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) { - LOGP(DVIRPHY, LOGL_NOTICE, + 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,7 +155,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: - LOGP(DVIRPHY, LOGL_NOTICE, + LOGPMS(DVIRPHY, LOGL_NOTICE, ms, "Ignoring gsmtap msg from virt um - channel type is uplink only!\n"); break; case GSMTAP_CHANNEL_SDCCH: @@ -165,11 +165,11 @@ 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: - LOGP(DVIRPHY, LOGL_NOTICE, + LOGPMS(DVIRPHY, LOGL_NOTICE, ms, "Ignoring gsmtap msg from virt um - channel type not supported!\n"); break; default: - LOGP(DVIRPHY, LOGL_NOTICE, + LOGPMS(DVIRPHY, LOGL_NOTICE, ms, "Ignoring gsmtap msg from virt um - channel type unknown.\n"); break; } diff --git a/src/host/virt_phy/src/l1ctl_sap.c b/src/host/virt_phy/src/l1ctl_sap.c index be5557d3..6bd63c97 100644 --- a/src/host/virt_phy/src/l1ctl_sap.c +++ b/src/host/virt_phy/src/l1ctl_sap.c @@ -70,7 +70,7 @@ void l1ctl_sap_rx_from_l23_inst_cb(struct l1ctl_sock_client *lsc, struct msgb *m if (!msg) return; - DEBUGP(DL1C, "Message incoming from layer 2: %s\n", osmo_hexdump(msg->data, msg->len)); + DEBUGPMS(DL1C, ms, "Message incoming from layer 2: %s\n", osmo_hexdump(msg->data, msg->len)); l1ctl_sap_handler(ms, msg); } @@ -161,7 +161,7 @@ void l1ctl_sap_handler(struct l1_model_ms *ms, struct msgb *msg) l1h = (struct l1ctl_hdr *) msg->data; if (sizeof(*l1h) > msg->len) { - LOGP(DL1C, LOGL_NOTICE, "Malformed message: too short. %u\n", msg->len); + LOGPMS(DL1C, LOGL_NOTICE, ms, "Malformed message: too short. %u\n", msg->len); goto exit_msgbfree; } @@ -245,7 +245,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); - DEBUGP(DL1C, "Received and handled from l23 - L1CTL_DM_EST_REQ (chan_nr=0x%02x, tn=%u, ss=%u)\n", + DEBUGPMS(DL1C, ms, "Received and handled from l23 - 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; @@ -280,7 +280,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; - DEBUGP(DL1C, "Received and ignored from l23 - L1CTL_DM_FREQ_REQ (arfcn0=%u, hsn=%u, maio=%u)\n", + DEBUGPMS(DL1C, ms, "Received and ignored from l23 - L1CTL_DM_FREQ_REQ (arfcn0=%u, hsn=%u, maio=%u)\n", ntohs(freq_req->h0.band_arfcn), freq_req->h1.hsn, freq_req->h1.maio); } @@ -305,7 +305,7 @@ 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); - DEBUGP(DL1C, "Received and handled from l23 - L1CTL_CRYPTO_REQ (algo=A5/%u, len=%u)\n", + DEBUGPMS(DL1C, ms, "Received and handled from l23 - L1CTL_CRYPTO_REQ (algo=A5/%u, len=%u)\n", cr->algo, key_len); if (cr->algo && key_len != A5_KEY_LEN) { @@ -329,7 +329,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) { - DEBUGP(DL1C, "Received and handled from l23 - L1CTL_DM_REL_REQ\n"); + DEBUGPMS(DL1C, ms, "Received and handled from l23 - L1CTL_DM_REL_REQ\n"); ms->state.dedicated.chan_type = 0; ms->state.dedicated.tn = 0; @@ -358,7 +358,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; - DEBUGP(DL1C, "Received and ignored from l23 - L1CTL_PARAM_REQ (ta=%d, tx_power=%d)\n", + DEBUGPMS(DL1C, ms, "Received and ignored from l23 - L1CTL_PARAM_REQ (ta=%d, tx_power=%d)\n", par_req->ta, par_req->tx_power); } @@ -382,18 +382,18 @@ void l1ctl_rx_reset_req(struct l1_model_ms *ms, struct msgb *msg) switch (reset_req->type) { case L1CTL_RES_T_FULL: - DEBUGP(DL1C, "Received and handled from l23 - L1CTL_RESET_REQ (type=FULL)\n"); + DEBUGPMS(DL1C, ms, "Received and handled from l23 - 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); - DEBUGP(DL1C, "Received and handled from l23 - L1CTL_RESET_REQ (type=SCHED)\n"); + DEBUGPMS(DL1C, ms, "Received and handled from l23 - L1CTL_RESET_REQ (type=SCHED)\n"); l1ctl_tx_reset(ms, L1CTL_RESET_CONF, reset_req->type); break; default: - LOGP(DL1C, LOGL_ERROR, "Received and ignored from l23 - L1CTL_RESET_REQ (type=unknown)\n"); + LOGPMS(DL1C, LOGL_ERROR, ms, "Received and ignored from l23 - L1CTL_RESET_REQ (type=unknown)\n"); break; } } @@ -417,7 +417,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; - DEBUGP(DL1C, "Received and handled from l23 - L1CTL_CCCH_MODE_REQ\n"); + DEBUGPMS(DL1C, ms, "Received and handled from l23 - L1CTL_CCCH_MODE_REQ\n"); ms->state.serving_cell.ccch_mode = ccch_mode; @@ -444,7 +444,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; - DEBUGP(DL1C, "Received and handled from l23 - L1CTL_TCH_MODE_REQ (tch_mode=0x%02x audio_mode=0x%02x)\n", + DEBUGPMS(DL1C, ms, "Received and handled from l23 - 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 */ @@ -470,7 +470,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; - DEBUGP(DL1C, "Received and ignored from l23 - L1CTL_NEIGH_PM_REQ new list with %u entries\n", + DEBUGPMS(DL1C, ms, "Received and ignored from l23 - L1CTL_NEIGH_PM_REQ new list with %u entries\n", pm_req->n); } @@ -498,7 +498,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); - LOGP(DL1C, LOGL_ERROR, "Received and ignored from l23 - SIM Request length: %u, data: %s\n", + LOGPMS(DL1C, LOGL_ERROR, ms, "Received and ignored from l23 - SIM Request length: %u, data: %s\n", len, osmo_hexdump(data, sizeof(data))); } @@ -523,7 +523,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; - DEBUGP(DL1C, "Sending to l23 - %s (reset_type: %u)\n", getL1ctlPrimName(msg_type), reset_type); + DEBUGPMS(DL1C, ms, "Sending to l23 - %s (reset_type: %u)\n", getL1ctlPrimName(msg_type), reset_type); l1ctl_sap_tx_to_l23_inst(ms, msg); } @@ -545,7 +545,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; - DEBUGP(DL1C, "Sending to l23 - L1CTL_CCCH_MODE_CONF (mode: %u)\n", ccch_mode); + DEBUGPMS(DL1C, ms, "Sending to l23 - L1CTL_CCCH_MODE_CONF (mode: %u)\n", ccch_mode); l1ctl_sap_tx_to_l23_inst(ms, msg); } @@ -568,7 +568,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; - DEBUGP(DL1C, "Sending to l23 - L1CTL_TCH_MODE_CONF (tch_mode: %u, audio_mode: %u)\n", + DEBUGPMS(DL1C, ms, "Sending to l23 - 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/l1ctl_sock.c b/src/host/virt_phy/src/l1ctl_sock.c index d654c211..00f25a6b 100644 --- a/src/host/virt_phy/src/l1ctl_sock.c +++ b/src/host/virt_phy/src/l1ctl_sock.c @@ -93,7 +93,7 @@ static int l1ctl_sock_data_cb(struct osmo_fd *ofd, unsigned int what) return 0; } err_close: - perror("Failed to receive msg from l2. Connection will be closed.\n"); + LOGP(DL1C, LOGL_ERROR, "Failed to receive msg from l2. Connection will be closed.\n"); l1ctl_client_destroy(lsc); return 0; @@ -110,15 +110,14 @@ static int l1ctl_sock_accept_cb(struct osmo_fd *ofd, unsigned int what) fd = accept(ofd->fd, NULL, NULL); if (fd < 0) { - fprintf(stderr, "Failed to accept connection to l2.\n"); + LOGP(DL1C, LOGL_ERROR, "Failed to accept connection to l2.\n"); return -1; } - printf("Accepted client (fd=%u) from server (fd=%u)\n", fd, ofd->fd); lsc = talloc_zero(lsi, struct l1ctl_sock_client); if (!lsc) { close(fd); - fprintf(stderr, "Failed to allocate L1CTL client\n"); + LOGP(DL1C, LOGL_ERROR, "Failed to allocate L1CTL client\n"); return -1; } @@ -136,9 +135,9 @@ static int l1ctl_sock_accept_cb(struct osmo_fd *ofd, unsigned int what) } } - printf("Accepted L1CTL connection, lsc=%p, lsc->priv=%p\n", lsc, lsc->priv); + LOGP(DL1C, LOGL_INFO, "Accepted client (fd=%u) from server (fd=%u)\n", fd, ofd->fd); if (osmo_fd_register(&lsc->ofd) != 0) { - fprintf(stderr, "Failed to register the l2 connection fd.\n"); + LOGP(DL1C, LOGL_ERROR, "Failed to register the l2 connection fd.\n"); talloc_free(lsc); return -1; } @@ -166,6 +165,7 @@ struct l1ctl_sock_inst *l1ctl_sock_init( rc = osmo_sock_unix_init_ofd(&lsi->ofd, SOCK_STREAM, 0, path, OSMO_SOCK_F_BIND); if (rc < 0) { + LOGP(DL1C, LOGL_ERROR, "Error creating L1CTL listening socket\n"); talloc_free(lsi); return NULL; } diff --git a/src/host/virt_phy/src/logging.c b/src/host/virt_phy/src/logging.c index 7801beca..7fb2c238 100644 --- a/src/host/virt_phy/src/logging.c +++ b/src/host/virt_phy/src/logging.c @@ -71,7 +71,14 @@ static const struct log_info_cat default_categories[] = { .color = "\033[1;31m", .enabled = 1, .loglevel = LOGL_DEBUG, - } + }, + [DMAIN] = { + .name = "DMAIN", + .description = "Main Program / Data Structures", + .color = "\033[1;32m", + .enabled = 1, + .loglevel = LOGL_DEBUG, + }, }; const struct log_info ms_log_info = { @@ -107,5 +114,8 @@ int ms_log_init(char *cat_mask) const char *getL1ctlPrimName(uint8_t type) { - return l1ctlPrimNames[type]; + if (type <= ARRAY_SIZE(l1ctlPrimNames)) + return l1ctlPrimNames[type]; + else + return "Unknwon Primitive"; } diff --git a/src/host/virt_phy/src/virt_l1_model.c b/src/host/virt_phy/src/virt_l1_model.c index da0c3147..14676b01 100644 --- a/src/host/virt_phy/src/virt_l1_model.c +++ b/src/host/virt_phy/src/virt_l1_model.c @@ -1,5 +1,6 @@ /* (C) 2016 by Sebastian Stumpf + * (C) 2017 by Harald Welte * * All Rights Reserved * @@ -20,23 +21,30 @@ #include #include +#include #include +static uint32_t next_ms_nr; + struct l1_model_ms *l1_model_ms_init(void *ctx, struct l1ctl_sock_client *lsc, struct virt_um_inst *vui) { struct l1_model_ms *model = talloc_zero(ctx, struct l1_model_ms); if (!model) return NULL; + model->nr = next_ms_nr++; model->lsc = lsc; model->vui = vui; l1ctl_sap_init(model); + LOGPMS(DMAIN, LOGL_INFO, model, "allocated\n"); + return model; } void l1_model_ms_destroy(struct l1_model_ms *model) { + LOGPMS(DMAIN, LOGL_INFO, model, "destryed\n"); talloc_free(model); } diff --git a/src/host/virt_phy/src/virt_prim_data.c b/src/host/virt_phy/src/virt_prim_data.c index 4b07ca66..e03d0974 100644 --- a/src/host/virt_phy/src/virt_prim_data.c +++ b/src/host/virt_phy/src/virt_prim_data.c @@ -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, ×lot); - DEBUGP(DL1C, + DEBUGPMS(DL1C, 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)); - DEBUGP(DL1C, "Sending signaling-data to l23.\n"); + DEBUGPMS(DL1C, ms, "Sending signaling-data to l23.\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 59fda353..932f1636 100644 --- a/src/host/virt_phy/src/virt_prim_fbsb.c +++ b/src/host/virt_phy/src/virt_prim_fbsb.c @@ -57,7 +57,7 @@ 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; - DEBUGP(DL1C, "Received and handled from l23 - L1CTL_FBSB_REQ (arfcn=%u, flags=0x%x)\n", + 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); l1s->state = MS_STATE_IDLE_SYNCING; @@ -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; - DEBUGP(DL1C, "Sending to l23 - %s (res: %u)\n", getL1ctlPrimName(L1CTL_FBSB_CONF), res); + DEBUGPMS(DL1C, ms, "Sending to l23 - %s (res: %u)\n", getL1ctlPrimName(L1CTL_FBSB_CONF), 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 96b7f07c..3202680c 100644 --- a/src/host/virt_phy/src/virt_prim_pm.c +++ b/src/host/virt_phy/src/virt_prim_pm.c @@ -52,7 +52,7 @@ uint16_t prim_pm_set_sig_strength(struct l1_model_ms *ms, uint16_t arfcn, int16_ l1s->pm.timeout_s, l1s->pm.timeout_us); } l1s->pm.meas.arfcn_sig_lev_dbm[arfcn] = sig_lev - l1s->pm.meas.arfcn_sig_lev_red_dbm[arfcn]; - DEBUGP(DL1C, "Power measurement set for arfcn %u. Set signal level to %d (== rxlev: %u).\n", + DEBUGPMS(DL1C, ms, "Power measurement set for arfcn %u. Set signal level to %d (== rxlev: %u).\n", arfcn, l1s->pm.meas.arfcn_sig_lev_dbm[arfcn], dbm2rxlev(l1s->pm.meas.arfcn_sig_lev_dbm[arfcn])); return l1s->pm.meas.arfcn_sig_lev_dbm[arfcn]; @@ -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); - DEBUGP(DL1C, "Received from l23 - L1CTL_PM_REQ TYPE=%u, FROM=%d, TO=%d\n", + DEBUGPMS(DL1C, ms, "Received from l23 - 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; diff --git a/src/host/virt_phy/src/virt_prim_rach.c b/src/host/virt_phy/src/virt_prim_rach.c index 88e82064..c5bac731 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); - DEBUGP(DL1C, "Received and handled from l23 - L1CTL_RACH_REQ (ra=0x%02x, offset=%d combined=%d)\n", + DEBUGPMS(DL1C, ms, "Received and handled from l23 - 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,7 @@ 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); - DEBUGP(DL1C, "Sending to l23 - %s (fn: %u, arfcn: %u)\n", + DEBUGPMS(DL1C, ms, "Sending to l23 - %s (fn: %u, arfcn: %u)\n", getL1ctlPrimName(L1CTL_RACH_CONF), 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 9e87db9a..04f6749e 100644 --- a/src/host/virt_phy/src/virt_prim_traffic.c +++ b/src/host/virt_phy/src/virt_prim_traffic.c @@ -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, ×lot); - DEBUGP(DL1C, "Received and handled from l23 - L1CTL_TRAFFIC_REQ\n"); + DEBUGPMS(DL1C, 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)); - DEBUGP(DL1C, "Sending to l23 - L1CTL_TRAFFIC_IND\n"); + DEBUGPMS(DL1C, ms, "Sending to l23 - L1CTL_TRAFFIC_IND\n"); l1ctl_sap_tx_to_l23_inst(ms, l1ctl_msg); } diff --git a/src/host/virt_phy/src/virtphy.c b/src/host/virt_phy/src/virtphy.c index c7e11ca6..78a45f00 100644 --- a/src/host/virt_phy/src/virtphy.c +++ b/src/host/virt_phy/src/virtphy.c @@ -37,7 +37,7 @@ #include #include -#define DEFAULT_LOG_MASK "DL1C,1:DVIRPHY,1" +#define DEFAULT_LOG_MASK "DL1C,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 */ -- 2.11.4.GIT