Always log context (interface/line/timeslot) when available

We always want to know as much context as possible.  Which exact
timeslot on which line of which interface ha logged something?

Change-Id: I3d8909b396928ed3c023b8ac47fa9ec72c99e681

3 files changed, 21 insertions, 12 deletions

diff --git a/src/intf_line.c b/src/intf_line.c
index 7b85b4c..305f5dd 100644
--- a/src/intf_line.c
+++ b/src/intf_line.c
@@ -143,13 +143,13 @@ _e1_rx_hdlcfs(struct e1_ts *ts, uint8_t *buf, int len)
 
 		if (rv > 0) {
 			int bytes_to_write = rv;
-			LOGP(DXFR, LOGL_DEBUG, "RX Message: %d %d [ %s]\n",
-				ts->id, rv, osmo_hexdump(ts->rx_buf, rv));
+			LOGPTS(ts, DXFR, LOGL_DEBUG, "RX Message: %d [ %s]\n",
+				rv, osmo_hexdump(ts->rx_buf, rv));
 			rv = write(ts->fd, ts->rx_buf, bytes_to_write);
 			if (rv < 0)
 				return rv;
 		} else  if (rv < 0 && ts->id == 4) {
-			LOGP(DXFR, LOGL_ERROR, "ERR RX: %d %d %d [ %s]\n",
+			LOGPTS(ts, DXFR, LOGL_ERROR, "ERR RX: %d %d %d [ %s]\n",
 				rv,oi,cl, osmo_hexdump(buf, len));
 		}
 
@@ -171,8 +171,8 @@ _e1_tx_hdlcfs(struct e1_ts *ts, uint8_t *buf, int len)
 		if (!ts->tx_len) {
 			rv = read(ts->fd, ts->tx_buf, sizeof(ts->tx_buf));
 			if (rv > 0) {
-				LOGP(DXFR, LOGL_DEBUG, "TX Message: %d %d [ %s]\n",
-					ts->id, rv, osmo_hexdump(ts->tx_buf, rv));
+				LOGPTS(ts, DXFR, LOGL_DEBUG, "TX Message: %d [ %s]\n",
+					rv, osmo_hexdump(ts->tx_buf, rv));
 				ts->tx_len = rv; 
 				ts->tx_ofs = 0;
 			} else if (rv < 0)
@@ -186,10 +186,10 @@ _e1_tx_hdlcfs(struct e1_ts *ts, uint8_t *buf, int len)
 		);
 
 		if (rv < 0)
-			LOGP(DXFR, LOGL_ERROR, "ERR TX: %d\n", rv);
+			LOGPTS(ts, DXFR, LOGL_ERROR, "ERR TX: %d\n", rv);
 
 		if (ts->tx_ofs < ts->tx_len) {
-			LOGP(DXFR, LOGL_DEBUG, "TX chunk %d/%d %d [ %s]\n",
+			LOGPTS(ts, DXFR, LOGL_DEBUG, "TX chunk %d/%d %d [ %s]\n",
 				ts->tx_ofs, ts->tx_len, cl, osmo_hexdump(&buf[ts->tx_ofs], rv));
 		}
 
@@ -269,7 +269,7 @@ e1_line_demux_in(struct e1_line *line, const uint8_t *buf, int size)
 	int ftr;
 
 	if (size <= 0) {
-		LOGP(DXFR, LOGL_ERROR, "IN ERROR: %d\n", size);
+		LOGPLI(line, DXFR, LOGL_ERROR, "IN ERROR: %d\n", size);
 		return -1;
 	}
 
diff --git a/src/log.h b/src/log.h
index 2a9b210..d46a5a7 100644
--- a/src/log.h
+++ b/src/log.h
@@ -31,4 +31,13 @@ enum {
 	DXFR,
 };
 
+#define LOGPIF(itf, ss, lvl, fmt, args...) \
+	LOGP(ss, lvl, "(I%u) " fmt, (itf)->id, ## args)
+
+#define LOGPLI(li, ss, lvl, fmt, args...) \
+	LOGP(ss, lvl, "(I%u:L%u) " fmt, (li)->intf->id, (li)->id, ## args)
+
+#define LOGPTS(ts, ss, lvl, fmt, args...) \
+	LOGP(ss, lvl, "(I%u:L%u:T%u) " fmt, (ts)->line->intf->id, (ts)->line->id, (ts)->id, ## args)
+
 extern const struct log_info log_info;
diff --git a/src/usb.c b/src/usb.c
index 5d38d32..578bc34 100644
--- a/src/usb.c
+++ b/src/usb.c
@@ -118,7 +118,7 @@ e1_usb_xfer_out(struct e1_usb_flow *flow, uint8_t *buf, int size)
 	int fts;
 
 	if (size <= 0) {
-		LOGP(DXFR, LOGL_ERROR, "OUT ERROR: %d\n", size);
+		LOGPLI(line, DXFR, LOGL_ERROR, "OUT ERROR: %d\n", size);
 		return -1;
 	}
 
@@ -144,10 +144,10 @@ e1_usb_xfer_fb(struct e1_usb_flow *flow, uint8_t *buf, int size)
 	struct e1_usb_line_data *ld = (struct e1_usb_line_data *) flow->line->drv_data;
 
 	if (size < 0) {
-		LOGP(DE1D, LOGL_ERROR, "Feedback transfer error\n");
+		LOGPLI(flow->line, DE1D, LOGL_ERROR, "Feedback transfer error\n");
 		return 0;
 	} else if (size != 3) {
-		LOGP(DE1D, LOGL_ERROR, "Feedback packet invalid size (%d)\n", size);
+		LOGPLI(flow->line, DE1D, LOGL_ERROR, "Feedback packet invalid size (%d)\n", size);
 		return 0;
 	}
 
@@ -193,7 +193,7 @@ _e1uf_xfr(struct libusb_transfer *xfr)
 
 	rv = libusb_submit_transfer(xfr);
 	if (rv)
-		LOGP(DE1D, LOGL_ERROR, "Failed to resubmit buffer for transfer\n");
+		LOGPLI(flow->line, DE1D, LOGL_ERROR, "Failed to resubmit buffer for transfer\n");
 }
 
 static struct e1_usb_flow *