diff options
author | Harald Welte <laforge@osmocom.org> | 2020-01-12 12:59:52 +0100 |
---|---|---|
committer | Harald Welte <laforge@osmocom.org> | 2020-01-12 13:31:35 +0100 |
commit | b5af0991b39f5dc5e90cd5e36379631d389816be (patch) | |
tree | 287832fa4ce3911fa5d43bddf249a66cb73a4ad1 | |
parent | 510ae993a035b686d0f36743c853d333436b225f (diff) |
introduce and use logging macros with context on E1 line / timeslot
Change-Id: I447a2360757fed97ed50f9db1e2efbf2f90e46a0
-rw-r--r-- | include/osmocom/abis/e1_input.h | 6 | ||||
-rw-r--r-- | src/e1_input.c | 30 | ||||
-rw-r--r-- | src/input/dahdi.c | 57 | ||||
-rw-r--r-- | src/input/misdn.c | 77 | ||||
-rw-r--r-- | src/input/rs232.c | 41 | ||||
-rw-r--r-- | src/input/unixsocket.c | 67 |
6 files changed, 123 insertions, 155 deletions
diff --git a/include/osmocom/abis/e1_input.h b/include/osmocom/abis/e1_input.h index e6d5154..de1c504 100644 --- a/include/osmocom/abis/e1_input.h +++ b/include/osmocom/abis/e1_input.h @@ -14,6 +14,12 @@ #define NUM_E1_TS 32 #define E1INP_USE_DEFAULT (-1) +#define LOGPITS(e1ts, ss, level, fmt, args ...) \ + LOGP(ss, level, "E1TS(%u:%u) " fmt, (e1ts)->line->num, (e1ts)->num, ## args) + +#define LOGPIL(e1l, ss, level, fmt, args ...) \ + LOGP(ss, level, "E1L(%u) " fmt, (e1l)->num, ## args) + enum e1inp_sign_type { E1INP_SIGN_NONE, E1INP_SIGN_OML, diff --git a/src/e1_input.c b/src/e1_input.c index 9e2f7b0..a707438 100644 --- a/src/e1_input.c +++ b/src/e1_input.c @@ -354,8 +354,7 @@ e1inp_line_create(uint8_t e1_nr, const char *driver_name) line = e1inp_line_find(e1_nr); if (line) { - LOGP(DLINP, LOGL_ERROR, "E1 Line %u already exists\n", - e1_nr); + LOGPIL(line, DLINP, LOGL_ERROR, "E1 Line %u already exists\n", e1_nr); return NULL; } @@ -375,7 +374,7 @@ e1inp_line_create(uint8_t e1_nr, const char *driver_name) line->rate_ctr = rate_ctr_group_alloc(line, &e1inp_ctr_g_d, line->num); if (!line->rate_ctr) { - LOGP(DLINP, LOGL_ERROR, "Cannot allocate counter group\n"); + LOGPIL(line, DLINP, LOGL_ERROR, "Cannot allocate counter group\n"); talloc_free(line); return NULL; } @@ -429,7 +428,7 @@ void e1inp_line_get(struct e1inp_line *line) { int old_refcnt = line->refcnt++; - LOGP(DLINP, LOGL_DEBUG, "Line '%s' (%p) reference count get: %d -> %d\n", + LOGPIL(line, DLINP, LOGL_DEBUG, "Line '%s' (%p) reference count get: %d -> %d\n", line->name, line, old_refcnt, line->refcnt); } @@ -437,7 +436,7 @@ void e1inp_line_put(struct e1inp_line *line) { int old_refcnt = line->refcnt--; - LOGP(DLINP, LOGL_DEBUG, "Line '%s' (%p) reference count put: %d -> %d\n", + LOGPIL(line, DLINP, LOGL_DEBUG, "Line '%s' (%p) reference count put: %d -> %d\n", line->name, line, old_refcnt, line->refcnt); if (line->refcnt == 0) { @@ -598,13 +597,13 @@ int e1inp_rx_ts(struct e1inp_ts *ts, struct msgb *msg, /* consult the list of signalling links */ link = e1inp_lookup_sign_link(ts, tei, sapi); if (!link) { - LOGP(DLMI, LOGL_ERROR, "didn't find signalling link for " + LOGPITS(ts, DLMI, LOGL_ERROR, "didn't find signalling link for " "tei %d, sapi %d\n", tei, sapi); msgb_free(msg); return -EINVAL; } if (!ts->line->ops->sign_link) { - LOGP(DLINP, LOGL_ERROR, "Fix your application, " + LOGPITS(ts, DLINP, LOGL_ERROR, "Fix your application, " "no action set for signalling messages.\n"); msgb_free(msg); return -ENOENT; @@ -624,7 +623,7 @@ int e1inp_rx_ts(struct e1inp_ts *ts, struct msgb *msg, break; default: ret = -EINVAL; - LOGP(DLMI, LOGL_ERROR, "unknown TS type %u\n", ts->type); + LOGPITS(ts, DLMI, LOGL_ERROR, "unknown TS type %u\n", ts->type); msgb_free(msg); break; } @@ -652,7 +651,7 @@ int e1inp_rx_ts_lapd(struct e1inp_ts *e1i_ts, struct msgb *msg) else tei = msg->data[1] >> 1; - DEBUGP(DLMI, "<= len = %d, sapi(%d) tei(%d)\n", msg->len, sapi, tei); + LOGPITS(e1i_ts, DLMI, LOGL_DEBUG, "<= len = %d, sapi(%d) tei(%d)\n", msg->len, sapi, tei); ret = lapd_receive(e1i_ts->lapd, msg, &error); if (ret < 0) { @@ -679,18 +678,18 @@ void e1inp_dlsap_up(struct osmo_dlsap_prim *dp, uint8_t tei, uint8_t sapi, switch (dp->oph.primitive) { case PRIM_DL_EST: - DEBUGP(DLMI, "DL_EST: sapi(%d) tei(%d)\n", sapi, tei); + LOGPITS(e1i_ts, DLMI, LOGL_DEBUG, "DL_EST: sapi(%d) tei(%d)\n", sapi, tei); e1inp_event(e1i_ts, S_L_INP_TEI_UP, tei, sapi); break; case PRIM_DL_REL: - DEBUGP(DLMI, "DL_REL: sapi(%d) tei(%d)\n", sapi, tei); + LOGPITS(e1i_ts, DLMI, LOGL_DEBUG, "DL_REL: sapi(%d) tei(%d)\n", sapi, tei); e1inp_event(e1i_ts, S_L_INP_TEI_DN, tei, sapi); break; case PRIM_DL_DATA: case PRIM_DL_UNIT_DATA: if (dp->oph.operation == PRIM_OP_INDICATION) { msg->l2h = msg->l3h; - DEBUGP(DLMI, "RX: %s sapi=%d tei=%d\n", + LOGPITS(e1i_ts, DLMI, LOGL_DEBUG, "RX: %s sapi=%d tei=%d\n", osmo_hexdump(msgb_l2(msg), msgb_l2len(msg)), sapi, tei); e1inp_rx_ts(e1i_ts, msg, tei, sapi); @@ -698,7 +697,7 @@ void e1inp_dlsap_up(struct osmo_dlsap_prim *dp, uint8_t tei, uint8_t sapi, } break; case PRIM_MDL_ERROR: - DEBUGP(DLMI, "MDL_EERROR: cause(%d)\n", dp->u.error_ind.cause); + LOGPITS(e1i_ts, DLMI, LOGL_DEBUG, "MDL_EERROR: cause(%d)\n", dp->u.error_ind.cause); break; default: printf("ERROR: unknown prim\n"); @@ -738,8 +737,7 @@ struct msgb *e1inp_tx_ts(struct e1inp_ts *e1i_ts, return NULL; len = subchan_mux_out(&e1i_ts->trau.mux, msg->data, 40); if (len != 40) { - LOGP(DLMI, LOGL_ERROR, - "cannot transmit, failed to mux\n"); + LOGPITS(e1i_ts, DLMI, LOGL_ERROR, "cannot transmit, failed to mux\n"); msgb_free(msg); return NULL; } @@ -754,7 +752,7 @@ struct msgb *e1inp_tx_ts(struct e1inp_ts *e1i_ts, msg = msgb_dequeue(&e1i_ts->hdlc.tx_queue); break; default: - LOGP(DLMI, LOGL_ERROR, "unsupported E1 TS type %u\n", e1i_ts->type); + LOGPITS(e1i_ts, DLMI, LOGL_ERROR, "unsupported E1 TS type %u\n", e1i_ts->type); return NULL; } return msg; diff --git a/src/input/dahdi.c b/src/input/dahdi.c index 4d01fe0..6da1a02 100644 --- a/src/input/dahdi.c +++ b/src/input/dahdi.c @@ -134,7 +134,7 @@ static void handle_dahdi_exception(struct e1inp_ts *ts) if (rc < 0) return; - LOGP(DLMI, LOGL_NOTICE, "Line %u(%s) / TS %u DAHDI EVENT %s\n", + LOGPITS(ts, DLMI, LOGL_NOTICE, "Line %u(%s) / TS %u DAHDI EVENT %s\n", ts->line->num, ts->line->name, ts->num, get_value_string(dahdi_evt_names, evt)); @@ -181,12 +181,12 @@ static int handle_ts1_read(struct osmo_fd *bfd) if (ret == -1) handle_dahdi_exception(e1i_ts); else if (ret < 0) { - LOGP(DLMI, LOGL_ERROR, "%s read failed %d (%s)\n", __func__, ret, strerror(errno)); + LOGPITS(e1i_ts, DLMI, LOGL_ERROR, "%s read failed %d (%s)\n", __func__, ret, strerror(errno)); return ret; } msgb_put(msg, ret - 2); if (ret <= 3) { - LOGP(DLMI, LOGL_ERROR, "%s read failed %d (%s)\n", __func__, ret, strerror(errno)); + LOGPITS(e1i_ts, DLMI, LOGL_ERROR, "%s read failed %d (%s)\n", __func__, ret, strerror(errno)); return ret; } @@ -199,7 +199,7 @@ static int ts_want_write(struct e1inp_ts *e1i_ts) * writeset, since it doesn't support poll() based * write flow control */ if (e1i_ts->type == E1INP_TS_TYPE_TRAU) { - LOGP(DLINP, LOGL_DEBUG, "Trying to write TRAU ts\n"); + LOGPITS(e1i_ts, DLINP, LOGL_DEBUG, "Trying to write TRAU ts\n"); return 0; } @@ -229,7 +229,7 @@ static void dahdi_write_msg(struct msgb *msg, void *cbdata) if (ret == -1) handle_dahdi_exception(e1i_ts); else if (ret < 0) - LOGP(DLMI, LOGL_NOTICE, "%s write failed %d\n", __func__, ret); + LOGPITS(e1i_ts, DLMI, LOGL_NOTICE, "%s write failed %d\n", __func__, ret); } static int handle_ts1_write(struct osmo_fd *bfd) @@ -249,7 +249,7 @@ static int handle_ts1_write(struct osmo_fd *bfd) return 0; } - DEBUGP(DLMI, "TX: %s\n", osmo_hexdump(msg->data, msg->len)); + LOGPITS(e1i_ts, DLMI, LOGL_ERROR, "TX: %s\n", osmo_hexdump(msg->data, msg->len)); lapd_transmit(e1i_ts->lapd, sign_link->tei, sign_link->sapi, msg); @@ -278,7 +278,7 @@ static void handle_hdlc_write(struct osmo_fd *bfd) if (ret == -1) handle_dahdi_exception(e1i_ts); else if (ret < 0) - LOGP(DLMI, LOGL_NOTICE, "%s write failed %d\n", __func__, ret); + LOGPITS(e1i_ts, DLMI, LOGL_NOTICE, "%s write failed %d\n", __func__, ret); } static int handle_hdlc_read(struct osmo_fd *bfd) @@ -296,12 +296,12 @@ static int handle_hdlc_read(struct osmo_fd *bfd) if (ret == -1) handle_dahdi_exception(e1i_ts); else if (ret < 0) { - LOGP(DLMI, LOGL_ERROR, "%s read failed %d (%s)\n", __func__, ret, strerror(errno)); + LOGPITS(e1i_ts, DLMI, LOGL_ERROR, "%s read failed %d (%s)\n", __func__, ret, strerror(errno)); return ret; } msgb_put(msg, ret - 2); if (ret <= 3) { - LOGP(DLMI, LOGL_ERROR, "%s read failed %d (%s)\n", __func__, ret, strerror(errno)); + LOGPITS(e1i_ts, DLMI, LOGL_ERROR, "%s read failed %d (%s)\n", __func__, ret, strerror(errno)); return ret; } @@ -351,13 +351,12 @@ static int handle_tsX_write(struct osmo_fd *bfd) ret = subchan_mux_out(mx, tx_buf, D_BCHAN_TX_GRAN); if (ret != D_BCHAN_TX_GRAN) { - LOGP(DLINP, LOGL_DEBUG, "Huh, got ret of %d\n", ret); + LOGPITS(e1i_ts, DLINP, LOGL_DEBUG, "Huh, got ret of %d\n", ret); if (ret < 0) return ret; } - DEBUGP(DLMIB, "BCHAN TX: %s\n", - osmo_hexdump(tx_buf, D_BCHAN_TX_GRAN)); + LOGPITS(e1i_ts, DLMIB, LOGL_DEBUG, "BCHAN TX: %s\n", osmo_hexdump(tx_buf, D_BCHAN_TX_GRAN)); if (invertbits) { flip_buf_bits(tx_buf, ret); @@ -365,7 +364,7 @@ static int handle_tsX_write(struct osmo_fd *bfd) ret = write(bfd->fd, tx_buf, ret); if (ret < D_BCHAN_TX_GRAN) - LOGP(DLINP, LOGL_DEBUG, "send returns %d instead of %d\n", + LOGPITS(e1i_ts, DLINP, LOGL_DEBUG, "send returns %d instead of %d\n", ret, D_BCHAN_TX_GRAN); return ret; @@ -386,8 +385,7 @@ static int handle_tsX_read(struct osmo_fd *bfd) ret = read(bfd->fd, msg->data, D_TSX_ALLOC_SIZE); if (ret < 0 || ret != D_TSX_ALLOC_SIZE) { - LOGP(DLINP, LOGL_DEBUG, "read error %d %s\n", - ret, strerror(errno)); + LOGPITS(e1i_ts, DLINP, LOGL_DEBUG, "read error %d %s\n", ret, strerror(errno)); return ret; } @@ -398,8 +396,7 @@ static int handle_tsX_read(struct osmo_fd *bfd) msgb_put(msg, ret); msg->l2h = msg->data; - DEBUGP(DLMIB, "BCHAN RX: %s\n", - osmo_hexdump(msgb_l2(msg), ret)); + LOGPITS(e1i_ts, DLMIB, LOGL_DEBUG, "BCHAN RX: %s\n", osmo_hexdump(msgb_l2(msg), ret)); ret = e1inp_rx_ts(e1i_ts, msg, 0, 0); /* physical layer indicates that data has been sent, * we thus can send some more data */ @@ -426,12 +423,11 @@ static int handle_ts_raw_write(struct osmo_fd *bfd) /* This might lead to a transmit underrun, as we call tx * from the rx path, as there's no select/poll on dahdi * */ - LOGP(DLINP, LOGL_NOTICE, "unexpected msg->len = %u, " + LOGPITS(e1i_ts, DLINP, LOGL_NOTICE, "unexpected msg->len = %u, " "expected %u\n", msg->len, D_BCHAN_TX_GRAN); } - DEBUGP(DLMIB, "RAW CHAN TX: %s\n", - osmo_hexdump(msg->data, msg->len)); + LOGPITS(e1i_ts, DLMIB, LOGL_DEBUG, "RAW CHAN TX: %s\n", osmo_hexdump(msg->data, msg->len)); if (0/*invertbits*/) { flip_buf_bits(msg->data, msg->len); @@ -439,8 +435,7 @@ static int handle_ts_raw_write(struct osmo_fd *bfd) ret = write(bfd->fd, msg->data, msg->len); if (ret < msg->len) - LOGP(DLINP, LOGL_DEBUG, "send returns %d instead of %d\n", - ret, msg->len); + LOGPITS(e1i_ts, DLINP, LOGL_DEBUG, "send returns %d instead of %d\n", ret, msg->len); msgb_free(msg); return ret; @@ -459,8 +454,7 @@ static int handle_ts_raw_read(struct osmo_fd *bfd) ret = read(bfd->fd, msg->data, D_TSX_ALLOC_SIZE); if (ret < 0 || ret != D_TSX_ALLOC_SIZE) { - LOGP(DLINP, LOGL_DEBUG, "read error %d %s\n", - ret, strerror(errno)); + LOGPITS(e1i_ts, DLINP, LOGL_DEBUG, "read error %d %s\n", ret, strerror(errno)); return ret; } @@ -471,8 +465,7 @@ static int handle_ts_raw_read(struct osmo_fd *bfd) msgb_put(msg, ret); msg->l2h = msg->data; - DEBUGP(DLMIB, "RAW CHAN RX: %s\n", - osmo_hexdump(msgb_l2(msg), ret)); + LOGPITS(e1i_ts, DLMIB, LOGL_DEBUG, "RAW CHAN RX: %s\n", osmo_hexdump(msgb_l2(msg), ret)); ret = e1inp_rx_ts(e1i_ts, msg, 0, 0); /* physical layer indicates that data has been sent, * we thus can send some more data */ @@ -530,8 +523,7 @@ static int dahdi_fd_cb(struct osmo_fd *bfd, unsigned int what) * write flow control */ break; default: - LOGP(DLINP, LOGL_NOTICE, - "unknown E1 TS type %u\n", e1i_ts->type); + LOGPITS(e1i_ts, DLINP, LOGL_NOTICE, "unknown E1 TS type %u\n", e1i_ts->type); break; } @@ -641,9 +633,8 @@ static int dahdi_e1_setup(struct e1inp_line *line) scfg = span_cfgs[line->port_nr]; if (!scfg) { - LOGP(DLMI, LOGL_ERROR, "Line %u(%s): DAHDI Port %u (Span %u) " - "doesn't exist\n", line->num, line->name, line->port_nr, - line->port_nr+1); + LOGPIL(line, DLMI, LOGL_ERROR, "Line %u(%s): DAHDI Port %u (Span %u) doesn't exist\n", + line->num, line->name, line->port_nr, line->port_nr+1); return -EIO; } @@ -733,9 +724,7 @@ static int dahdi_e1_setup(struct e1inp_line *line) ret = osmo_fd_register(bfd); if (ret < 0) { - LOGP(DLINP, LOGL_ERROR, - "could not register FD: %s\n", - strerror(ret)); + LOGPITS(e1i_ts, DLINP, LOGL_ERROR, "could not register FD: %s\n", strerror(ret)); return ret; } } diff --git a/src/input/misdn.c b/src/input/misdn.c index bdca9d5..fef1c0f 100644 --- a/src/input/misdn.c +++ b/src/input/misdn.c @@ -124,21 +124,21 @@ static int handle_ts1_read(struct osmo_fd *bfd) msgb_put(msg, ret); - DEBUGP(DLMI, "alen =%d, dev(%d) channel(%d) sapi(%d) tei(%d)\n", + LOGPITS(e1i_ts, DLMI, LOGL_DEBUG, "alen =%d, dev(%d) channel(%d) sapi(%d) tei(%d)\n", alen, l2addr.dev, l2addr.channel, l2addr.sapi, l2addr.tei); - DEBUGP(DLMI, "<= len = %d, prim(0x%x) id(0x%x): %s\n", + LOGPITS(e1i_ts, DLMI, LOGL_DEBUG, "<= len = %d, prim(0x%x) id(0x%x): %s\n", ret, hh->prim, hh->id, get_value_string(prim_names, hh->prim)); switch (hh->prim) { case DL_INFORMATION_IND: /* mISDN tells us which channel number is allocated for this * tuple of (SAPI, TEI). */ - DEBUGP(DLMI, "DL_INFORMATION_IND: use channel(%d) sapi(%d) tei(%d) for now\n", + LOGPITS(e1i_ts, DLMI, LOGL_DEBUG, "DL_INFORMATION_IND: use channel(%d) sapi(%d) tei(%d) for now\n", l2addr.channel, l2addr.sapi, l2addr.tei); link = e1inp_lookup_sign_link(e1i_ts, l2addr.tei, l2addr.sapi); if (!link) { - DEBUGPC(DLMI, "mISDN message for unknown sign_link\n"); + LOGPITS(e1i_ts, DLMI, LOGL_DEBUG, "mISDN message for unknown sign_link\n"); msgb_free(msg); return -EINVAL; } @@ -147,14 +147,14 @@ static int handle_ts1_read(struct osmo_fd *bfd) msgb_free(msg); break; case DL_ESTABLISH_IND: - DEBUGP(DLMI, "DL_ESTABLISH_IND: channel(%d) sapi(%d) tei(%d)\n", + LOGPITS(e1i_ts, DLMI, LOGL_DEBUG, "DL_ESTABLISH_IND: channel(%d) sapi(%d) tei(%d)\n", l2addr.channel, l2addr.sapi, l2addr.tei); /* For some strange reason, sometimes the DL_INFORMATION_IND tells * us the wrong channel, and we only get the real channel number * during the DL_ESTABLISH_IND */ link = e1inp_lookup_sign_link(e1i_ts, l2addr.tei, l2addr.sapi); if (!link) { - DEBUGPC(DLMI, "mISDN message for unknown sign_link\n"); + LOGPITS(e1i_ts, DLMI, LOGL_DEBUG, "mISDN message for unknown sign_link\n"); msgb_free(msg); return -EINVAL; } @@ -164,7 +164,7 @@ static int handle_ts1_read(struct osmo_fd *bfd) msgb_free(msg); break; case DL_RELEASE_IND: - DEBUGP(DLMI, "DL_RELEASE_IND: channel(%d) sapi(%d) tei(%d)\n", + LOGPITS(e1i_ts, DLMI, LOGL_DEBUG, "DL_RELEASE_IND: channel(%d) sapi(%d) tei(%d)\n", l2addr.channel, l2addr.sapi, l2addr.tei); ret = e1inp_event(e1i_ts, S_L_INP_TEI_DN, l2addr.tei, l2addr.sapi); msgb_free(msg); @@ -172,33 +172,33 @@ static int handle_ts1_read(struct osmo_fd *bfd) case DL_DATA_IND: case DL_UNITDATA_IND: msg->l2h = msg->data + MISDN_HEADER_LEN; - DEBUGP(DLMI, "RX: %s\n", osmo_hexdump(msgb_l2(msg), ret - MISDN_HEADER_LEN)); + LOGPITS(e1i_ts, DLMI, LOGL_DEBUG, "RX: %s\n", osmo_hexdump(msgb_l2(msg), ret - MISDN_HEADER_LEN)); if (mline->use_userspace_lapd) { - LOGP(DLMI, LOGL_ERROR, "DL_DATA_IND but userspace LAPD ?!?\n"); + LOGPITS(e1i_ts, DLMI, LOGL_ERROR, "DL_DATA_IND but userspace LAPD ?!?\n"); msgb_free(msg); return -EIO; } ret = e1inp_rx_ts(e1i_ts, msg, l2addr.tei, l2addr.sapi); break; case PH_ACTIVATE_IND: - DEBUGP(DLMI, "PH_ACTIVATE_IND: channel(%d) sapi(%d) tei(%d)\n", + LOGPITS(e1i_ts, DLMI, LOGL_DEBUG, "PH_ACTIVATE_IND: channel(%d) sapi(%d) tei(%d)\n", l2addr.channel, l2addr.sapi, l2addr.tei); msgb_free(msg); break; case PH_DEACTIVATE_IND: - DEBUGP(DLMI, "PH_DEACTIVATE_IND: channel(%d) sapi(%d) tei(%d)\n", + LOGPITS(e1i_ts, DLMI, LOGL_DEBUG, "PH_DEACTIVATE_IND: channel(%d) sapi(%d) tei(%d)\n", l2addr.channel, l2addr.sapi, l2addr.tei); msgb_free(msg); break; case PH_DATA_IND: if (!mline->use_userspace_lapd) { - LOGP(DLMI, LOGL_ERROR, "PH_DATA_IND but kernel LAPD ?!?\n"); + LOGPITS(e1i_ts, DLMI, LOGL_ERROR, "PH_DATA_IND but kernel LAPD ?!?\n"); return -EIO; } /* remove the Misdn Header */ msgb_pull(msg, MISDN_HEADER_LEN); /* hand into the LAPD code */ - DEBUGP(DLMI, "RX: %s\n", osmo_hexdump(msg->data, msg->len)); + LOGPITS(e1i_ts, DLMI, LOGL_DEBUG, "RX: %s\n", osmo_hexdump(msg->data, msg->len)); ret = e1inp_rx_ts_lapd(e1i_ts, msg); break; default: @@ -252,9 +252,8 @@ static int handle_ts1_write(struct osmo_fd *bfd) } if (mline->use_userspace_lapd) { - DEBUGP(DLMI, "TX %u/%u/%u: %s\n", - line->num, sign_link->tei, sign_link->sapi, - osmo_hexdump(msg->data, msg->len)); + LOGPITS(e1i_ts, DLMI, LOGL_DEBUG, "TX %u/%u/%u: %s\n", line->num, sign_link->tei, + sign_link->sapi, osmo_hexdump(msg->data, msg->len)); lapd_transmit(e1i_ts->lapd, sign_link->tei, sign_link->sapi, msg); ret = 0; @@ -265,7 +264,7 @@ static int handle_ts1_write(struct osmo_fd *bfd) hh = (struct mISDNhead *) msgb_push(msg, sizeof(*hh)); hh->prim = DL_DATA_REQ; - DEBUGP(DLMI, "TX channel(%d) TEI(%d) SAPI(%d): %s\n", + LOGPITS(e1i_ts, DLMI, LOGL_DEBUG, "TX channel(%d) TEI(%d) SAPI(%d): %s\n", sign_link->driver.misdn.channel, sign_link->tei, sign_link->sapi, osmo_hexdump(l2_data, msg->len - MISDN_HEADER_LEN)); @@ -295,13 +294,13 @@ static int handle_ts1_write(struct osmo_fd *bfd) static void misdn_write_msg(struct msgb *msg, void *cbdata) { struct osmo_fd *bfd = cbdata; -// struct e1inp_line *line = bfd->data; -// unsigned int ts_nr = bfd->priv_nr; -// struct e1inp_ts *e1i_ts = &line->ts[ts_nr-1]; + struct e1inp_line *line = bfd->data; + unsigned int ts_nr = bfd->priv_nr; + struct e1inp_ts *e1i_ts = &line->ts[ts_nr-1]; struct mISDNhead *hh; int ret; - DEBUGP(DLMI, "PH_DATA_REQ: len=%d %s\n", msg->len, + LOGPITS(e1i_ts, DLMI, LOGL_DEBUG, "PH_DATA_REQ: len=%d %s\n", msg->len, osmo_hexdump(msg->data, msg->len)); hh = (struct mISDNhead *) msgb_push(msg, MISDN_HEADER_LEN); @@ -310,7 +309,7 @@ static void misdn_write_msg(struct msgb *msg, void *cbdata) ret = write(bfd->fd, msg->data, msg->len); if (ret < 0) - LOGP(DLMI, LOGL_NOTICE, "write failed %d\n", ret); + LOGPITS(e1i_ts, DLMI, LOGL_NOTICE, "write failed %d\n", ret); msgb_free(msg); } @@ -332,13 +331,11 @@ static int handle_tsX_write(struct osmo_fd *bfd, int len) subchan_mux_out(mx, tx_buf+sizeof(*hh), len); - DEBUGP(DLMIB, "BCHAN TX: %s\n", - osmo_hexdump(tx_buf+sizeof(*hh), len)); + LOGPITS(e1i_ts, DLMIB, LOGL_DEBUG, "BCHAN TX: %s\n", osmo_hexdump(tx_buf+sizeof(*hh), len)); ret = send(bfd->fd, tx_buf, sizeof(*hh) + len, 0); if (ret < sizeof(*hh) + len) - DEBUGP(DLMIB, "send returns %d instead of %zu\n", ret, - sizeof(*hh) + len); + LOGPITS(e1i_ts, DLMIB, LOGL_DEBUG, "send returns %d instead of %zu\n", ret, sizeof(*hh) + len); return ret; } @@ -368,14 +365,13 @@ static int handle_tsX_read(struct osmo_fd *bfd) msgb_put(msg, ret); if (hh->prim != PH_CONTROL_IND) - DEBUGP(DLMIB, "<= BCHAN len = %d, prim(0x%x) id(0x%x): %s\n", - ret, hh->prim, hh->id, - get_value_string(prim_names, hh->prim)); + LOGPITS(e1i_ts, DLMIB, LOGL_DEBUG, "<= BCHAN len = %d, prim(0x%x) id(0x%x): %s\n", + ret, hh->prim, hh->id, get_value_string(prim_names, hh->prim)); switch (hh->prim) { case PH_DATA_IND: msg->l2h = msg->data + MISDN_HEADER_LEN; - DEBUGP(DLMIB, "BCHAN RX: %s\n", + LOGPITS(e1i_ts, DLMIB, LOGL_DEBUG, "BCHAN RX: %s\n", osmo_hexdump(msgb_l2(msg), ret - MISDN_HEADER_LEN)); /* the number of bytes received indicates that data to send */ handle_tsX_write(bfd, msgb_l2len(msg)); @@ -411,12 +407,10 @@ static int handle_ts_raw_write(struct osmo_fd *bfd, unsigned int len) /* This might lead to a transmit underrun, as we call tx * from the rx path, as there's no select/poll on dahdi * */ - LOGP(DLINP, LOGL_NOTICE, "unexpected msg->len = %u, " - "expected %u\n", msg->len, len); + LOGPITS(e1i_ts, DLINP, LOGL_NOTICE, "unexpected msg->len = %u, expected %u\n", msg->len, len); } - DEBUGP(DLMIB, "RAW CHAN TX: %s\n", - osmo_hexdump(msg->data, msg->len)); + LOGPITS(e1i_ts, DLMIB, LOGL_DEBUG, "RAW CHAN TX: %s\n", osmo_hexdump(msg->data, msg->len)); hh = (struct mISDNhead *) msgb_push(msg, sizeof(*hh)); hh->prim = PH_DATA_REQ; @@ -424,8 +418,7 @@ static int handle_ts_raw_write(struct osmo_fd *bfd, unsigned int len) ret = write(bfd->fd, msg->data, msg->len); if (ret < msg->len) - LOGP(DLINP, LOGL_DEBUG, "send returns %d instead of %d\n", - ret, msg->len); + LOGPITS(e1i_ts, DLINP, LOGL_DEBUG, "send returns %d instead of %d\n", ret, msg->len); msgb_free(msg); return ret; @@ -454,14 +447,13 @@ static int handle_ts_raw_read(struct osmo_fd *bfd) msgb_put(msg, ret); if (hh->prim != PH_CONTROL_IND) - DEBUGP(DLMIB, "<= RAW CHAN len = %d, prim(0x%x) id(0x%x): %s\n", - ret, hh->prim, hh->id, - get_value_string(prim_names, hh->prim)); + LOGPITS(e1i_ts, DLMIB, LOGL_DEBUG, "<= RAW CHAN len = %d, prim(0x%x) id(0x%x): %s\n", + ret, hh->prim, hh->id, get_value_string(prim_names, hh->prim)); switch (hh->prim) { case PH_DATA_IND: msg->l2h = msg->data + MISDN_HEADER_LEN; - DEBUGP(DLMIB, "RAW CHAN RX: %s\n", + LOGPITS(e1i_ts, DLMIB, LOGL_DEBUG, "RAW CHAN RX: %s\n", osmo_hexdump(msgb_l2(msg), ret - MISDN_HEADER_LEN)); /* the number of bytes received indicates that data to send */ handle_ts_raw_write(bfd, msgb_l2len(msg)); @@ -661,8 +653,7 @@ static int mi_e1_setup(struct e1inp_line *line, int release_l2) addr.channel = ts; break; default: - DEBUGP(DLMI, "unsupported E1 TS type: %u\n", - e1i_ts->type); + LOGPITS(e1i_ts, DLMI, LOGL_ERROR, "unsupported E1 TS type: %u\n", e1i_ts->type); break; } @@ -724,7 +715,7 @@ static int _mi_e1_line_update(struct e1inp_line *line) close(sk); return -ENODEV; } - //DEBUGP(DLMI,"%d device%s found\n", cnt, (cnt==1)?"":"s"); + //LOGPIL(line, DLMI, LOGL_DEBUG, "%d device%s found\n", cnt, (cnt==1)?"":"s"); printf("%d device%s found\n", cnt, (cnt==1)?"":"s"); #if 1 devinfo.id = line->port_nr; diff --git a/src/input/rs232.c b/src/input/rs232.c index c801ab2..dfbf97c 100644 --- a/src/input/rs232.c +++ b/src/input/rs232.c @@ -94,14 +94,14 @@ static int handle_ser_write(struct osmo_fd *bfd) /* no message after tx delay timer */ return 0; } - DEBUGP(DLMI, "rs232 TX: %s\n", osmo_hexdump(msg->data, msg->len)); + LOGPITS(e1i_ts, DLMI, LOGL_DEBUG, "rs232 TX: %s\n", osmo_hexdump(msg->data, msg->len)); rs232_build_msg(msg); /* send over serial line */ written = write(bfd->fd, msg->data, msg->len); if (written < msg->len) { - LOGP(DLMI, LOGL_ERROR, "rs232: short write\n"); + LOGPITS(e1i_ts, DLMI, LOGL_ERROR, "rs232: short write\n"); msgb_free(msg); return -1; } @@ -118,6 +118,7 @@ static int handle_ser_write(struct osmo_fd *bfd) static int handle_ser_read(struct osmo_fd *bfd) { struct serial_handle *sh = bfd->data; + struct e1inp_ts *e1i_ts = &sh->line->ts[0]; struct msgb *msg; int rc = 0; @@ -131,7 +132,7 @@ static int handle_ser_read(struct osmo_fd *bfd) if (msg->len < 2) { rc = read(bfd->fd, msg->tail, 2 - msg->len); if (rc < 0) { - LOGP(DLMI, LOGL_ERROR, "rs232: error reading from " + LOGPITS(e1i_ts, DLMI, LOGL_ERROR, "rs232: error reading from " "serial port: %s\n", strerror(errno)); msgb_free(msg); return rc; @@ -141,16 +142,14 @@ static int handle_ser_read(struct osmo_fd *bfd) if (msg->len >= 2) { /* parse CRAPD payload length */ if (msg->data[0] != 0) { - LOGP(DLMI, LOGL_ERROR, - "Suspicious header byte 0: 0x%02x\n", + LOGPITS(e1i_ts, DLMI, LOGL_ERROR, "Suspicious header byte 0: 0x%02x\n", msg->data[0]); } sh->rxmsg_bytes_missing = msg->data[0] << 8; sh->rxmsg_bytes_missing += msg->data[1]; if (sh->rxmsg_bytes_missing < CRAPD_HDR_LEN -2) { - LOGP(DLMI, LOGL_ERROR, - "Invalid length in hdr: %u\n", + LOGPITS(e1i_ts, DLMI, LOGL_ERROR, "Invalid length in hdr: %u\n", sh->rxmsg_bytes_missing); } } @@ -158,8 +157,8 @@ static int handle_ser_read(struct osmo_fd *bfd) /* try to read as many of the missing bytes as are available */ rc = read(bfd->fd, msg->tail, sh->rxmsg_bytes_missing); if (rc < 0) { - LOGP(DLMI, LOGL_ERROR, "rs232: error reading from " - "serial port: %s", strerror(errno)); + LOGPITS(e1i_ts, DLMI, LOGL_ERROR, "rs232: error reading from serial port: %s", + strerror(errno)); msgb_free(msg); return rc; } @@ -167,7 +166,6 @@ static int handle_ser_read(struct osmo_fd *bfd) sh->rxmsg_bytes_missing -= rc; if (sh->rxmsg_bytes_missing == 0) { - struct e1inp_ts *e1i_ts = &sh->line->ts[0]; /* we have one complete message now */ sh->rx_msg = NULL; @@ -175,15 +173,13 @@ static int handle_ser_read(struct osmo_fd *bfd) if (msg->len > CRAPD_HDR_LEN) msg->l2h = msg->data + CRAPD_HDR_LEN; - DEBUGP(DLMI, "rs232 RX: %s", - osmo_hexdump(msg->data, msg->len)); + LOGPITS(e1i_ts, DLMI, LOGL_DEBUG, "rs232 RX: %s", osmo_hexdump(msg->data, msg->len)); /* don't use e1inp_tx_ts() here, this header does not * contain any SAPI and TEI values. */ if (!e1i_ts->line->ops->sign_link) { - LOGP(DLMI, LOGL_ERROR, "rs232: no callback set, " - "skipping message.\n"); - return -EINVAL; + LOGPITS(e1i_ts, DLMI, LOGL_ERROR, "rs232: no callback set, skipping message.\n"); + return -EINVAL; } e1i_ts->line->ops->sign_link(msg); } @@ -226,8 +222,7 @@ rs232_setup(struct e1inp_line *line, const char *serial_port, unsigned int delay rc = open(serial_port, O_RDWR); if (rc < 0) { - LOGP(DLMI, LOGL_ERROR, "rs232: cannot open serial port: %s", - strerror(errno)); + LOGPIL(line, DLMI, LOGL_ERROR, "rs232: cannot open serial port: %s", strerror(errno)); return rc; } bfd->fd = rc; @@ -235,8 +230,7 @@ rs232_setup(struct e1inp_line *line, const char *serial_port, unsigned int delay /* set baudrate */ rc = tcgetattr(bfd->fd, &tio); if (rc < 0) { - LOGP(DLMI, LOGL_ERROR, "rs232: tcgetattr says: %s", - strerror(errno)); + LOGPIL(line, DLMI, LOGL_ERROR, "rs232: tcgetattr says: %s", strerror(errno)); return rc; } cfsetispeed(&tio, B19200); @@ -249,16 +243,14 @@ rs232_setup(struct e1inp_line *line, const char *serial_port, unsigned int delay tio.c_oflag &= ~(OPOST); rc = tcsetattr(bfd->fd, TCSADRAIN, &tio); if (rc < 0) { - LOGP(DLMI, LOGL_ERROR, "rs232: tcsetattr says: %s", - strerror(errno)); + LOGPIL(line, DLMI, LOGL_ERROR, "rs232: tcsetattr says: %s", strerror(errno)); return rc; } ser_handle = talloc_zero(tall_rs232_ctx, struct serial_handle); if (ser_handle == NULL) { close(bfd->fd); - LOGP(DLMI, LOGL_ERROR, "rs232: cannot allocate memory for " - "serial handler\n"); + LOGPIL(line, DLMI, LOGL_ERROR, "rs232: cannot allocate memory for serial handler\n"); return -ENOMEM; } ser_handle->line = line; @@ -271,8 +263,7 @@ rs232_setup(struct e1inp_line *line, const char *serial_port, unsigned int delay rc = osmo_fd_register(bfd); if (rc < 0) { close(bfd->fd); - LOGP(DLMI, LOGL_ERROR, "rs232: could not register FD: %s\n", - strerror(-rc)); + LOGPIL(line, DLMI, LOGL_ERROR, "rs232: could not register FD: %s\n", strerror(-rc)); return rc; } diff --git a/src/input/unixsocket.c b/src/input/unixsocket.c index bc4b357..1d25ddf 100644 --- a/src/input/unixsocket.c +++ b/src/input/unixsocket.c @@ -58,15 +58,13 @@ static int unixsocket_exception_cb(struct osmo_fd *bfd) { struct e1inp_line *line = bfd->data; - LOGP(DLINP, LOGL_ERROR, - "Socket connection failure, reconnecting... (line=%p, fd=%d)\n", - line, bfd->fd); + LOGPIL(line, DLINP, LOGL_ERROR, "Socket connection failure, reconnecting... (line=%p, fd=%d)\n", + line, bfd->fd); /* Unregister faulty file descriptor from select loop */ if(osmo_fd_is_registered(bfd)) { - LOGP(DLINP, LOGL_DEBUG, - "removing inactive socket from select loop... (line=%p, fd=%d)\n", - line, bfd->fd); + LOGPIL(line, DLINP, LOGL_DEBUG, "removing inactive socket from select loop... (line=%p, fd=%d)\n", + line, bfd->fd); osmo_fd_unregister(bfd); } @@ -98,22 +96,21 @@ static int unixsocket_read_cb(struct osmo_fd *bfd) goto fail; } else if (ret < 2) { /* packet must be at least 2 byte long to hold version + control/data header */ - LOGP(DLMI, LOGL_ERROR, "received to small packet: %d < 2", ret); + LOGPIL(line, DLMI, LOGL_ERROR, "received to small packet: %d < 2", ret); ret = -1; goto fail; } msgb_put(msg, ret); - LOGP(DLMI, LOGL_DEBUG, "rx msg: %s (fd=%d)\n", - osmo_hexdump_nospc(msg->data, msg->len), bfd->fd); + LOGPIL(line, DLMI, LOGL_DEBUG, "rx msg: %s (fd=%d)\n", osmo_hexdump_nospc(msg->data, msg->len), bfd->fd); /* check version header */ version = msgb_pull_u8(msg); controldata = msgb_pull_u8(msg); if (version != UNIXSOCKET_PROTO_VERSION) { - LOGP(DLMI, LOGL_ERROR, "received message with invalid version %d. valid: %d", - ret, UNIXSOCKET_PROTO_VERSION); + LOGPIL(line, DLMI, LOGL_ERROR, "received message with invalid version %d. valid: %d", + ret, UNIXSOCKET_PROTO_VERSION); ret = -1; goto fail; } @@ -122,11 +119,11 @@ static int unixsocket_read_cb(struct osmo_fd *bfd) case UNIXSOCKET_PROTO_DATA: return e1inp_rx_ts_lapd(&line->ts[0], msg); case UNIXSOCKET_PROTO_CONTROL: - LOGP(DLMI, LOGL_ERROR, "received (invalid) control message."); + LOGPIL(line, DLMI, LOGL_ERROR, "received (invalid) control message."); ret = -1; break; default: - LOGP(DLMI, LOGL_ERROR, "received invalid message."); + LOGPIL(line, DLMI, LOGL_ERROR, "received invalid message."); ret = -1; break; } @@ -156,8 +153,7 @@ static int unixsocket_write_cb(struct osmo_fd *bfd) msg = e1inp_tx_ts(e1i_ts, &sign_link); if (!msg) { /* no message after tx delay timer */ - LOGP(DLINP, LOGL_INFO, - "no message available (line=%p)\n", line); + LOGPITS(e1i_ts, DLINP, LOGL_INFO, "no message available (line=%p)\n", line); return 0; } @@ -166,8 +162,7 @@ static int unixsocket_write_cb(struct osmo_fd *bfd) osmo_timer_schedule(&e1i_ts->sign.tx_timer, 0, e1i_ts->sign.delay); - LOGP(DLINP, LOGL_DEBUG, "sending: %s (line=%p)\n", - msgb_hexdump(msg), line); + LOGPITS(e1i_ts, DLINP, LOGL_DEBUG, "sending: %s (line=%p)\n", msgb_hexdump(msg), line); lapd_transmit(e1i_ts->lapd, sign_link->tei, sign_link->sapi, msg); @@ -195,18 +190,20 @@ static int ts_want_write(struct e1inp_ts *e1i_ts) return 0; } -static void unixsocket_write_msg(struct msgb *msg, struct osmo_fd *bfd) { +static void unixsocket_write_msg(struct msgb *msg, struct osmo_fd *bfd) +{ + struct e1inp_line *line = bfd->data; int ret; - LOGP(DLMI, LOGL_DEBUG, "tx msg: %s (fd=%d)\n", - osmo_hexdump_nospc(msg->data, msg->len), bfd->fd); + LOGPIL(line, DLMI, LOGL_DEBUG, "tx msg: %s (fd=%d)\n", + osmo_hexdump_nospc(msg->data, msg->len), bfd->fd); ret = write(bfd->fd, msg->data, msg->len); msgb_free(msg); if (ret == -1) unixsocket_exception_cb(bfd); else if (ret < 0) - LOGP(DLMI, LOGL_NOTICE, "%s write failed %d\n", __func__, ret); + LOGPIL(line, DLMI, LOGL_NOTICE, "%s write failed %d\n", __func__, ret); } /*! @@ -234,14 +231,13 @@ static int unixsocket_line_update(struct e1inp_line *line) int ret = 0; int i; - LOGP(DLINP, LOGL_NOTICE, "line update (line=%p)\n", line); + LOGPIL(line, DLINP, LOGL_NOTICE, "line update (line=%p)\n", line); if (!line->driver_data) line->driver_data = talloc_zero(line, struct unixsocket_line); if (!line->driver_data) { - LOGP(DLINP, LOGL_ERROR, - "OOM in line update (line=%p)\n", line); + LOGPIL(line, DLINP, LOGL_ERROR, "OOM in line update (line=%p)\n", line); return -ENOMEM; } @@ -255,10 +251,10 @@ static int unixsocket_line_update(struct e1inp_line *line) ret = snprintf(un.sun_path, sizeof(un.sun_path), "%s%d", UNIXSOCKET_SOCK_PATH_DEFAULT, line->num); if (ret == -1) { - LOGP(DLINP, LOGL_ERROR, "Cannot create default socket path: %s\n", strerror(errno)); + LOGPIL(line, DLINP, LOGL_ERROR, "Cannot create default socket path: %s\n", strerror(errno)); return -errno; } else if (ret >= sizeof(un.sun_path)) { - LOGP(DLINP, LOGL_ERROR, "Default socket path exceeds %zd bytes: %s%d\n", + LOGPIL(line, DLINP, LOGL_ERROR, "Default socket path exceeds %zd bytes: %s%d\n", sizeof(un.sun_path), UNIXSOCKET_SOCK_PATH_DEFAULT, line->num); return -ENOSPC; } @@ -272,21 +268,18 @@ static int unixsocket_line_update(struct e1inp_line *line) * opening the socket fails. The caller may want to call this * function multiple times using config->fd.data as line * parameter. Freeing now would destroy that reference. */ - LOGP(DLINP, LOGL_ERROR, - "unable to open socket: %s (line=%p, fd=%d)\n", sock_path, - line, config->fd.fd); + LOGPIL(line, DLINP, LOGL_ERROR, "unable to open socket: %s (line=%p, fd=%d)\n", sock_path, + line, config->fd.fd); return ret; } - LOGP(DLINP, LOGL_DEBUG, - "successfully opend (new) socket: %s (line=%p, fd=%d, ret=%d)\n", - sock_path, line, config->fd.fd, ret); + LOGPIL(line, DLINP, LOGL_DEBUG, "successfully opend (new) socket: %s (line=%p, fd=%d, ret=%d)\n", + sock_path, line, config->fd.fd, ret); config->fd.fd = ret; /* Register socket in select loop */ if (osmo_fd_register(&config->fd) < 0) { - LOGP(DLINP, LOGL_ERROR, - "error registering new socket (line=%p, fd=%d)\n", - line, config->fd.fd); + LOGPIL(line, DLINP, LOGL_ERROR, "error registering new socket (line=%p, fd=%d)\n", + line, config->fd.fd); close(config->fd.fd); return -EIO; } @@ -330,13 +323,13 @@ void e1inp_ericsson_set_altc(struct e1inp_line *unixline, int superchannel) return; if (unixline->driver != &unixsocket_driver) { - LOGP(DLMI, LOGL_NOTICE, "altc is only supported by unixsocket\n"); + LOGPIL(unixline, DLMI, LOGL_NOTICE, "altc is only supported by unixsocket\n"); return; } config = unixline->driver_data; if (!config) { - LOGP(DLMI, LOGL_NOTICE, "e1inp driver not yet initialized.\n"); + LOGPIL(unixline, DLMI, LOGL_NOTICE, "e1inp driver not yet initialized.\n"); return; } |