lapd_core: Improve debug output

The debug output of lapd core has no references to the dl objects,
since we have multiple links, seeing which action is for which
object is impossible. This commit adds pointer references (dl=%p)
to each log line.

Change-Id: I3024d1cbd58631e2abac4ce5822528e2e6e15fda

1 files changed, 190 insertions, 144 deletions

diff --git a/src/gsm/lapd_core.c b/src/gsm/lapd_core.c
index bf5c388a..84b1828d 100644
--- a/src/gsm/lapd_core.c
+++ b/src/gsm/lapd_core.c
@@ -197,7 +197,7 @@ static void lapd_start_t200(struct lapd_datalink *dl)
 {
 	if (osmo_timer_pending(&dl->t200))
 		return;
-	LOGP(DLLAPD, LOGL_INFO, "start T200\n");
+	LOGP(DLLAPD, LOGL_INFO, "start T200 (dl=%p)\n", dl);
 	osmo_timer_schedule(&dl->t200, dl->t200_sec, dl->t200_usec);
 }
 
@@ -205,7 +205,7 @@ static void lapd_start_t203(struct lapd_datalink *dl)
 {
 	if (osmo_timer_pending(&dl->t203))
 		return;
-	LOGP(DLLAPD, LOGL_INFO, "start T203\n");
+	LOGP(DLLAPD, LOGL_INFO, "start T203 (dl=%p)\n", dl);
 	osmo_timer_schedule(&dl->t203, dl->t203_sec, dl->t203_usec);
 }
 
@@ -213,7 +213,7 @@ static void lapd_stop_t200(struct lapd_datalink *dl)
 {
 	if (!osmo_timer_pending(&dl->t200))
 		return;
-	LOGP(DLLAPD, LOGL_INFO, "stop T200\n");
+	LOGP(DLLAPD, LOGL_INFO, "stop T200 (dl=%p)\n", dl);
 	osmo_timer_del(&dl->t200);
 }
 
@@ -221,14 +221,14 @@ static void lapd_stop_t203(struct lapd_datalink *dl)
 {
 	if (!osmo_timer_pending(&dl->t203))
 		return;
-	LOGP(DLLAPD, LOGL_INFO, "stop T203\n");
+	LOGP(DLLAPD, LOGL_INFO, "stop T203 (dl=%p)\n", dl);
 	osmo_timer_del(&dl->t203);
 }
 
 static void lapd_dl_newstate(struct lapd_datalink *dl, uint32_t state)
 {
-	LOGP(DLLAPD, LOGL_INFO, "new state %s -> %s\n",
-		lapd_state_names[dl->state], lapd_state_names[state]);
+	LOGP(DLLAPD, LOGL_INFO, "new state %s -> %s (dl=%p)\n",
+		lapd_state_names[dl->state], lapd_state_names[state], dl);
 
 	if (state != LAPD_STATE_MF_EST && dl->state == LAPD_STATE_MF_EST) {
 		/* stop T203 on leaving MF EST state, if running */
@@ -289,7 +289,8 @@ void lapd_dl_init(struct lapd_datalink *dl, uint8_t k, uint8_t v_range,
 	}
 
 	LOGP(DLLAPD, LOGL_INFO, "Init DL layer: sequence range = %d, k = %d, "
-		"history range = %d\n", dl->v_range, dl->k, dl->range_hist);
+		"history range = %d (dl=%p)\n", dl->v_range, dl->k,
+		dl->range_hist, dl);
 
 	lapd_dl_newstate(dl, LAPD_STATE_IDLE);
 
@@ -304,7 +305,7 @@ void lapd_dl_reset(struct lapd_datalink *dl)
 {
 	if (dl->state == LAPD_STATE_IDLE)
 		return;
-	LOGP(DLLAPD, LOGL_INFO, "Resetting LAPDm instance\n");
+	LOGP(DLLAPD, LOGL_INFO, "Resetting LAPDm instance (dl=%p)\n", dl);
 	/* enter idle state (and remove eventual cont_res) */
 	lapd_dl_newstate(dl, LAPD_STATE_IDLE);
 	/* flush buffer */
@@ -378,8 +379,9 @@ static int mdl_error(uint8_t cause, struct lapd_msg_ctx *lctx)
 	struct lapd_datalink *dl = lctx->dl;
 	struct osmo_dlsap_prim dp;
 
-	LOGP(DLLAPD, LOGL_NOTICE, "sending MDL-ERROR-IND cause %s\n",
-	     rsl_rlm_cause_name(cause));
+	LOGP(DLLAPD, LOGL_NOTICE,
+	     "sending MDL-ERROR-IND cause %d from state %s (dl=%p)\n",
+	     cause, lapd_state_names[dl->state], dl);
 	osmo_prim_init(&dp.oph, 0, PRIM_MDL_ERROR, PRIM_OP_INDICATION, NULL);
 	dp.u.error_ind.cause = cause;
 	return dl->send_dlsap(&dp, lctx);
@@ -534,6 +536,8 @@ static int lapd_reestablish(struct lapd_datalink *dl)
 	struct osmo_dlsap_prim dp;
 	struct msgb *msg;
 
+	LOGP(DLLAPD, LOGL_DEBUG, "lapd reestablish (dl=%p)\n", dl);
+
 	msg = lapd_msgb_alloc(0, "DUMMY");
 	osmo_prim_init(&dp.oph, 0, PRIM_DL_EST, PRIM_OP_REQUEST, msg);
 	
@@ -545,8 +549,8 @@ static void lapd_t200_cb(void *data)
 {
 	struct lapd_datalink *dl = data;
 
-	LOGP(DLLAPD, LOGL_INFO, "Timeout T200 (%p) state=%d\n", dl,
-		(int) dl->state);
+	LOGP(DLLAPD, LOGL_INFO, "Timeout T200 state=%s (dl=%p)\n",
+		lapd_state_names[dl->state], dl);
 
 	switch (dl->state) {
 	case LAPD_STATE_SABM_SENT:
@@ -615,7 +619,7 @@ static void lapd_t200_cb(void *data)
 				struct lapd_msg_ctx nctx;
 
 				LOGP(DLLAPD, LOGL_INFO, "retransmit last frame"
-					" V(S)=%d\n", vs);
+					" V(S)=%d (dl=%p)\n", vs, dl);
 				/* Create I frame (segment) from tx_hist */
 				memcpy(&nctx, &dl->lctx, sizeof(nctx));
 				/* keep nctx.ldp */
@@ -647,7 +651,7 @@ static void lapd_t200_cb(void *data)
 					lapd_send_rnr(&dl->lctx, 1, 1);
 				} else {
 					LOGP(DLLAPD, LOGL_INFO, "unhandled, "
-						"pls. fix\n");
+						"pls. fix (dl=%p)\n", dl);
 				}
 			}
 			/* restart T200 (PH-READY-TO-SEND) */
@@ -659,13 +663,13 @@ static void lapd_t200_cb(void *data)
 			if (!dl->reestablish)
 				break;
 			LOGP(DLLAPD, LOGL_NOTICE, "N200 reached, performing "
-				"reestablishment.\n");
+				"reestablishment. (dl=%p)\n", dl);
 			lapd_reestablish(dl);
 		}
 		break;
 	default:
 		LOGP(DLLAPD, LOGL_INFO, "T200 expired in unexpected "
-			"dl->state %d\n", (int) dl->state);
+			"dl->state %s (dl=%p)\n", lapd_state_names[dl->state], dl);
 	}
 }
 
@@ -674,12 +678,12 @@ static void lapd_t203_cb(void *data)
 {
 	struct lapd_datalink *dl = data;
 
-	LOGP(DLLAPD, LOGL_INFO, "Timeout T203 (%p) state=%d\n", dl,
-		(int) dl->state);
+	LOGP(DLLAPD, LOGL_INFO, "Timeout T203 state=%s (dl=%p)\n",
+	     lapd_state_names[dl->state], dl);
 
 	if (dl->state != LAPD_STATE_MF_EST) {
 		LOGP(DLLAPD, LOGL_ERROR, "T203 fired outside MF EST state, "
-			"please fix!\n");
+			"please fix! (dl=%p)\n", dl);
 		return;
 	}
 
@@ -689,11 +693,13 @@ static void lapd_t203_cb(void *data)
 	lapd_dl_newstate(dl, LAPD_STATE_TIMER_RECOV);
 	/* transmit a supervisory command with P bit set to 1 as follows: */
 	if (!dl->own_busy) {
-		LOGP(DLLAPD, LOGL_INFO, "transmit an RR poll command\n");
+		LOGP(DLLAPD, LOGL_INFO,
+		     "transmit an RR poll command (dl=%p)\n", dl);
 		/* Send RR with P=1 */
 		lapd_send_rr(&dl->lctx, 1, 1);
 	} else {
-		LOGP(DLLAPD, LOGL_INFO, "transmit an RNR poll command\n");
+		LOGP(DLLAPD, LOGL_INFO,
+		     "transmit an RNR poll command (dl=%p)\n", dl);
 		/* Send RNR with P=1 */
 		lapd_send_rnr(&dl->lctx, 1, 1);
 	}
@@ -743,7 +749,7 @@ static void lapd_acknowledge(struct lapd_msg_ctx *lctx)
 		 */
 		if (sub_mod(nr, dl->v_ack, dl->v_range)
 				> sub_mod(dl->v_send, dl->v_ack, dl->v_range)) {
-			LOGP(DLLAPD, LOGL_NOTICE, "N(R) sequence error\n");
+			LOGP(DLLAPD, LOGL_NOTICE, "N(R) sequence error (dl=%p)\n", dl);
 			mdl_error(MDL_CAUSE_SEQ_ERR, lctx);
 		}
 	}
@@ -756,7 +762,7 @@ static void lapd_acknowledge(struct lapd_msg_ctx *lctx)
 	if (t200_reset && !rej) {
 		if (dl->tx_hist[sub_mod(dl->v_send, 1, dl->range_hist)].msg) {
 			LOGP(DLLAPD, LOGL_INFO, "start T200, due to unacked I "
-				"frame(s)\n");
+				"frame(s) (dl=%p)\n", dl);
 			lapd_start_t200(dl);
 		}
 	}
@@ -789,13 +795,14 @@ static int lapd_rx_u(struct msgb *msg, struct lapd_msg_ctx *lctx)
 		prim = PRIM_DL_EST;
 		op = PRIM_OP_INDICATION;
 
-		LOGP(DLLAPD, LOGL_INFO, "SABM(E) received in state %s\n",
-			lapd_state_names[dl->state]);
+		LOGP(DLLAPD, LOGL_INFO, "SABM(E) received in state %s (dl=%p)\n",
+			lapd_state_names[dl->state], dl);
 		/* 5.7.1 */
 		dl->seq_err_cond = 0;
 		/* G.2.2 Wrong value of the C/R bit */
 		if (lctx->cr == dl->cr.rem2loc.resp) {
-			LOGP(DLLAPD, LOGL_ERROR, "SABM response error\n");
+			LOGP(DLLAPD, LOGL_ERROR,
+			     "SABM response error (dl=%p)\n", dl);
 			msgb_free(msg);
 			mdl_error(MDL_CAUSE_FRM_UNIMPL, lctx);
 			return -EINVAL;
@@ -805,7 +812,8 @@ static int lapd_rx_u(struct msgb *msg, struct lapd_msg_ctx *lctx)
 		 * set, AN MDL-ERROR-INDICATION is sent to MM.
 		 */
 		if (lctx->more || length > lctx->n201) {
-			LOGP(DLLAPD, LOGL_ERROR, "SABM too large error\n");
+			LOGP(DLLAPD, LOGL_ERROR,
+			     "SABM too large error (dl=%p)\n", dl);
 			msgb_free(msg);
 			mdl_error(MDL_CAUSE_UFRM_INC_PARAM, lctx);
 			return -EIO;
@@ -816,7 +824,7 @@ static int lapd_rx_u(struct msgb *msg, struct lapd_msg_ctx *lctx)
 			break;
 		case LAPD_STATE_MF_EST:
 			LOGP(DLLAPD, LOGL_INFO, "SABM command, multiple "
-				"frame established state\n");
+			     "frame established state (dl=%p)\n", dl);
 			/* If link is lost on the remote side, we start over
 			 * and send DL-ESTABLISH indication again. */
 			/* Additionally, continue in case of content resoltion
@@ -829,13 +837,13 @@ static int lapd_rx_u(struct msgb *msg, struct lapd_msg_ctx *lctx)
 				/* If no content resolution, this is a
 				 * re-establishment. */
 				LOGP(DLLAPD, LOGL_INFO,
-					"Remote reestablish\n");
+				     "Remote reestablish (dl=%p)\n", dl);
 				break;
 			}
 			if (!dl->cont_res) {
 				LOGP(DLLAPD, LOGL_INFO, "SABM command not "
-				     "allowed in state %s\n",
-				     lapd_state_names[dl->state]);
+				     "allowed in state %s (dl=%p)\n",
+				     lapd_state_names[dl->state], dl);
 				mdl_error(MDL_CAUSE_SABM_MF, lctx);
 				msgb_free(msg);
 				return 0;
@@ -848,8 +856,8 @@ static int lapd_rx_u(struct msgb *msg, struct lapd_msg_ctx *lctx)
 				if (memcmp(dl->cont_res->data, msg->data,
 								length)) {
 					LOGP(DLLAPD, LOGL_INFO, "Another SABM "
-						"with diffrent content - "
-						"ignoring!\n");
+					     "with diffrent content - "
+					     "ignoring! (dl=%p)\n", dl);
 					msgb_free(msg);
 					return 0;
 				}
@@ -872,8 +880,8 @@ static int lapd_rx_u(struct msgb *msg, struct lapd_msg_ctx *lctx)
 			/* check for contention resoultion */
 			if (dl->tx_hist[0].msg && dl->tx_hist[0].msg->len) {
 				LOGP(DLLAPD, LOGL_NOTICE, "SABM not allowed "
-				     "during contention resolution (state %s)\n",
-				     lapd_state_names[dl->state]);
+				     "during contention resolution (state=%s, dl=%p)\n",
+				     lapd_state_names[dl->state], dl);
 				mdl_error(MDL_CAUSE_SABM_INFO_NOTALL, lctx);
 			}
 			lapd_send_ua(lctx, length, msg->l3h);
@@ -899,7 +907,8 @@ static int lapd_rx_u(struct msgb *msg, struct lapd_msg_ctx *lctx)
 			dl->cont_res = lapd_msgb_alloc(length, "CONT RES");
 			memcpy(msgb_put(dl->cont_res, length), msg->l3h,
 				length);
-			LOGP(DLLAPD, LOGL_NOTICE, "Store content res.\n");
+			LOGP(DLLAPD, LOGL_NOTICE,
+			     "Store content res. (dl=%p)\n", dl);
 		}
 		/* send notification to L3 */
 		if (length == 0) {
@@ -913,11 +922,12 @@ static int lapd_rx_u(struct msgb *msg, struct lapd_msg_ctx *lctx)
 		}
 		break;
 	case LAPD_U_DM:
-		LOGP(DLLAPD, LOGL_INFO, "DM received in state %s\n",
-			lapd_state_names[dl->state]);
+		LOGP(DLLAPD, LOGL_INFO, "DM received in state %s (dl=%p)\n",
+			lapd_state_names[dl->state], dl);
 		/* G.2.2 Wrong value of the C/R bit */
 		if (lctx->cr == dl->cr.rem2loc.cmd) {
-			LOGP(DLLAPD, LOGL_ERROR, "DM command error\n");
+			LOGP(DLLAPD, LOGL_ERROR,
+			     "DM command error (dl=%p)\n", dl);
 			msgb_free(msg);
 			mdl_error(MDL_CAUSE_FRM_UNIMPL, lctx);
 			return -EINVAL;
@@ -935,12 +945,12 @@ static int lapd_rx_u(struct msgb *msg, struct lapd_msg_ctx *lctx)
 		case LAPD_STATE_MF_EST:
 			if (lctx->p_f) {
 				LOGP(DLLAPD, LOGL_INFO, "unsolicited DM "
-					"response\n");
+					"response (dl=%p)\n", dl);
 				mdl_error(MDL_CAUSE_UNSOL_DM_RESP, lctx);
 			} else {
 				LOGP(DLLAPD, LOGL_INFO, "unsolicited DM "
 					"response, multiple frame established "
-					"state\n");
+					"state (dl=%p)\n", dl);
 				mdl_error(MDL_CAUSE_UNSOL_DM_RESP_MF, lctx);
 				/* reestablish */
 				if (!dl->reestablish) {
@@ -948,7 +958,7 @@ static int lapd_rx_u(struct msgb *msg, struct lapd_msg_ctx *lctx)
 					return 0;
 				}
 				LOGP(DLLAPD, LOGL_NOTICE, "Performing "
-					"reestablishment.\n");
+					"reestablishment. (dl=%p)\n", dl);
 				lapd_reestablish(dl);
 			}
 			msgb_free(msg);
@@ -958,14 +968,14 @@ static int lapd_rx_u(struct msgb *msg, struct lapd_msg_ctx *lctx)
 			if (!lctx->p_f) {
 				LOGP(DLLAPD, LOGL_INFO, "unsolicited DM "
 					"response, multiple frame established "
-					"state\n");
+					"state (dl=%p)\n", dl);
 				mdl_error(MDL_CAUSE_UNSOL_DM_RESP_MF, lctx);
 				msgb_free(msg);
 				/* reestablish */
 				if (!dl->reestablish)
 					return 0;
 				LOGP(DLLAPD, LOGL_NOTICE, "Performing "
-					"reestablishment.\n");
+					"reestablishment. (dl=%p)\n", dl);
 				return lapd_reestablish(dl);
 			}
 			break;
@@ -983,7 +993,7 @@ static int lapd_rx_u(struct msgb *msg, struct lapd_msg_ctx *lctx)
 			/* 5.4.5 all other frame types shall be discarded */
 		default:
 			LOGP(DLLAPD, LOGL_INFO, "unsolicited DM response! "
-				"(discarding)\n");
+				"(discarding) (dl=%p)\n", dl);
 			msgb_free(msg);
 			return 0;
 		}
@@ -995,11 +1005,11 @@ static int lapd_rx_u(struct msgb *msg, struct lapd_msg_ctx *lctx)
 		msgb_free(msg);
 		break;
 	case LAPD_U_UI:
-		LOGP(DLLAPD, LOGL_INFO, "UI received\n");
+		LOGP(DLLAPD, LOGL_INFO, "UI received (dl=%p)\n", dl);
 		/* G.2.2 Wrong value of the C/R bit */
 		if (lctx->cr == dl->cr.rem2loc.resp) {
 			LOGP(DLLAPD, LOGL_ERROR, "UI indicates response "
-				"error\n");
+			     "error (dl=%p)\n", dl);
 			msgb_free(msg);
 			mdl_error(MDL_CAUSE_FRM_UNIMPL, lctx);
 			return -EINVAL;
@@ -1010,8 +1020,8 @@ static int lapd_rx_u(struct msgb *msg, struct lapd_msg_ctx *lctx)
 		 */
 		if (length > lctx->n201 || lctx->more) {
 			LOGP(DLLAPD, LOGL_ERROR, "UI too large error "
-				"(%d > N201(%d) or M=%d)\n", length,
-				lctx->n201, lctx->more);
+				"(%d > N201(%d) or M=%d) (dl=%p)\n", length,
+				lctx->n201, lctx->more, dl);
 			msgb_free(msg);
 			mdl_error(MDL_CAUSE_UFRM_INC_PARAM, lctx);
 			return -EIO;
@@ -1022,7 +1032,8 @@ static int lapd_rx_u(struct msgb *msg, struct lapd_msg_ctx *lctx)
 			/* 5.3.3 UI frames received with the length indicator
 			 * set to "0" shall be ignored
 			 */
-			LOGP(DLLAPD, LOGL_INFO, "length=0 (discarding)\n");
+			LOGP(DLLAPD, LOGL_INFO,
+			     "length=0 (discarding) (dl=%p)\n", dl);
 			msgb_free(msg);
 			return 0;
 		}
@@ -1034,8 +1045,8 @@ static int lapd_rx_u(struct msgb *msg, struct lapd_msg_ctx *lctx)
 		prim = PRIM_DL_REL;
 		op = PRIM_OP_INDICATION;
 
-		LOGP(DLLAPD, LOGL_INFO, "DISC received in state %s\n",
-			lapd_state_names[dl->state]);
+		LOGP(DLLAPD, LOGL_INFO, "DISC received in state %s (dl=%p)\n",
+			lapd_state_names[dl->state], dl);
 		/* flush tx and send buffers */
 		lapd_dl_flush_tx(dl);
 		lapd_dl_flush_send(dl);
@@ -1043,7 +1054,8 @@ static int lapd_rx_u(struct msgb *msg, struct lapd_msg_ctx *lctx)
 		dl->seq_err_cond = 0;
 		/* G.2.2 Wrong value of the C/R bit */
 		if (lctx->cr == dl->cr.rem2loc.resp) {
-			LOGP(DLLAPD, LOGL_ERROR, "DISC response error\n");
+			LOGP(DLLAPD, LOGL_ERROR,
+			     "DISC response error (dl=%p)\n", dl);
 			msgb_free(msg);
 			mdl_error(MDL_CAUSE_FRM_UNIMPL, lctx);
 			return -EINVAL;
@@ -1055,19 +1067,21 @@ static int lapd_rx_u(struct msgb *msg, struct lapd_msg_ctx *lctx)
 			 * parameters" is sent to the mobile management entity.
 			 */
 			LOGP(DLLAPD, LOGL_ERROR,
-				"U frame iwth incorrect parameters ");
+			     "U frame iwth incorrect parameters (dl=%p)\n", dl);
 			msgb_free(msg);
 			mdl_error(MDL_CAUSE_UFRM_INC_PARAM, lctx);
 			return -EIO;
 		}
 		switch (dl->state) {
 		case LAPD_STATE_IDLE:
-			LOGP(DLLAPD, LOGL_INFO, "DISC in idle state\n");
+			LOGP(DLLAPD, LOGL_INFO,
+			     "DISC in idle state (dl=%p)\n", dl);
 			/* send DM with F=P */
 			msgb_free(msg);
 			return lapd_send_dm(lctx);
 		case LAPD_STATE_SABM_SENT:
-			LOGP(DLLAPD, LOGL_INFO, "DISC in SABM state\n");
+			LOGP(DLLAPD, LOGL_INFO,
+			     "DISC in SABM state (dl=%p)\n", dl);
 			/* 5.4.6.2 send DM with F=P */
 			lapd_send_dm(lctx);
 			/* stop Timer T200 */
@@ -1079,10 +1093,12 @@ static int lapd_rx_u(struct msgb *msg, struct lapd_msg_ctx *lctx)
 				lctx);
 		case LAPD_STATE_MF_EST:
 		case LAPD_STATE_TIMER_RECOV:
-			LOGP(DLLAPD, LOGL_INFO, "DISC in est state\n");
+			LOGP(DLLAPD, LOGL_INFO,
+			     "DISC in est state (dl=%p)\n", dl);
 			break;
 		case LAPD_STATE_DISC_SENT:
-			LOGP(DLLAPD, LOGL_INFO, "DISC in disc state\n");
+			LOGP(DLLAPD, LOGL_INFO,
+			     "DISC in disc state (dl=%p)\n", dl);
 			prim = PRIM_DL_REL;
 			op = PRIM_OP_CONFIRM;
 			break;
@@ -1102,12 +1118,12 @@ static int lapd_rx_u(struct msgb *msg, struct lapd_msg_ctx *lctx)
 		msgb_free(msg);
 		break;
 	case LAPD_U_UA:
-		LOGP(DLLAPD, LOGL_INFO, "UA received in state %s\n",
-			lapd_state_names[dl->state]);
+		LOGP(DLLAPD, LOGL_INFO, "UA received in state %s (dl=%p)\n",
+			lapd_state_names[dl->state], dl);
 		/* G.2.2 Wrong value of the C/R bit */
 		if (lctx->cr == dl->cr.rem2loc.cmd) {
 			LOGP(DLLAPD, LOGL_ERROR, "UA indicates command "
-				"error\n");
+				"error (dl=%p)\n", dl);
 			msgb_free(msg);
 			mdl_error(MDL_CAUSE_FRM_UNIMPL, lctx);
 			return -EINVAL;
@@ -1117,7 +1133,8 @@ static int lapd_rx_u(struct msgb *msg, struct lapd_msg_ctx *lctx)
 		 * set, AN MDL-ERROR-INDICATION is sent to MM.
 		 */
 		if (lctx->more || length > lctx->n201) {
-			LOGP(DLLAPD, LOGL_ERROR, "UA too large error\n");
+			LOGP(DLLAPD, LOGL_ERROR,
+			     "UA too large error (dl=%p)\n", dl);
 			msgb_free(msg);
 			mdl_error(MDL_CAUSE_UFRM_INC_PARAM, lctx);
 			return -EIO;
@@ -1127,7 +1144,8 @@ static int lapd_rx_u(struct msgb *msg, struct lapd_msg_ctx *lctx)
 			/* 5.4.1.2 A UA response with the F bit set to "0"
 			 * shall be ignored.
 			 */
-			LOGP(DLLAPD, LOGL_INFO, "F=0 (discarding)\n");
+			LOGP(DLLAPD, LOGL_INFO,
+			     "F=0 (discarding) (dl=%p)\n", dl);
 			msgb_free(msg);
 			return 0;
 		}
@@ -1137,12 +1155,13 @@ static int lapd_rx_u(struct msgb *msg, struct lapd_msg_ctx *lctx)
 		case LAPD_STATE_MF_EST:
 		case LAPD_STATE_TIMER_RECOV:
 			LOGP(DLLAPD, LOGL_INFO, "unsolicited UA response! "
-				"(discarding)\n");
+				"(discarding) (dl=%p)\n", dl);
 			mdl_error(MDL_CAUSE_UNSOL_UA_RESP, lctx);
 			msgb_free(msg);
 			return 0;
 		case LAPD_STATE_DISC_SENT:
-			LOGP(DLLAPD, LOGL_INFO, "UA in disconnect state\n");
+			LOGP(DLLAPD, LOGL_INFO,
+			     "UA in disconnect state (dl=%p)\n", dl);
 			/* stop Timer T200 */
 			lapd_stop_t200(dl);
 			/* go to idle state */
@@ -1156,11 +1175,11 @@ static int lapd_rx_u(struct msgb *msg, struct lapd_msg_ctx *lctx)
 			/* 5.4.5 all other frame types shall be discarded */
 		default:
 			LOGP(DLLAPD, LOGL_INFO, "unsolicited UA response! "
-				"(discarding)\n");
+				"(discarding) (dl=%p)\n", dl);
 			msgb_free(msg);
 			return 0;
 		}
-		LOGP(DLLAPD, LOGL_INFO, "UA in SABM state\n");
+		LOGP(DLLAPD, LOGL_INFO, "UA in SABM state (dl=%p)\n", dl);
 		/* stop Timer T200 */
 		lapd_stop_t200(dl);
 		/* compare UA with SABME if contention resolution is applied */
@@ -1169,7 +1188,7 @@ static int lapd_rx_u(struct msgb *msg, struct lapd_msg_ctx *lctx)
 			 || !!memcmp(dl->tx_hist[0].msg->data, msg->l3h,
 			 					length)) {
 				LOGP(DLLAPD, LOGL_INFO, "**** UA response "
-					"mismatches ****\n");
+					"mismatches **** (dl=%p)\n", dl);
 				rc = send_dl_simple(PRIM_DL_REL,
 					PRIM_OP_INDICATION, lctx);
 				msgb_free(msg);
@@ -1193,19 +1212,22 @@ static int lapd_rx_u(struct msgb *msg, struct lapd_msg_ctx *lctx)
 		msgb_free(msg);
 		break;
 	case LAPD_U_FRMR:
-		LOGP(DLLAPD, LOGL_NOTICE, "Frame reject received\n");
+		LOGP(DLLAPD, LOGL_NOTICE,
+		     "Frame reject received (dl=%p)\n", dl);
 		/* send MDL ERROR INIDCATION to L3 */
 		mdl_error(MDL_CAUSE_FRMR, lctx);
 		msgb_free(msg);
 		/* reestablish */
 		if (!dl->reestablish)
 			break;
-		LOGP(DLLAPD, LOGL_NOTICE, "Performing reestablishment.\n");
+		LOGP(DLLAPD, LOGL_NOTICE,
+		     "Performing reestablishment. (dl=%p)\n", dl);
 		rc = lapd_reestablish(dl);
 		break;
 	default:
 		/* G.3.1 */
-		LOGP(DLLAPD, LOGL_NOTICE, "Unnumbered frame not allowed.\n");
+		LOGP(DLLAPD, LOGL_NOTICE,
+		     "Unnumbered frame not allowed. (dl=%p)\n", dl);
 		msgb_free(msg);
 		mdl_error(MDL_CAUSE_FRM_UNIMPL, lctx);
 		return -EINVAL;
@@ -1225,7 +1247,7 @@ static int lapd_rx_s(struct msgb *msg, struct lapd_msg_ctx *lctx)
 		 * primitive with cause "S frame with incorrect
 		 * parameters" is sent to the mobile management entity. */
 		LOGP(DLLAPD, LOGL_ERROR,
-				"S frame with incorrect parameters\n");
+		     "S frame with incorrect parameters (dl=%p)\n", dl);
 		msgb_free(msg);
 		mdl_error(MDL_CAUSE_SFRM_INC_PARAM, lctx);
 		return -EIO;
@@ -1235,7 +1257,8 @@ static int lapd_rx_s(struct msgb *msg, struct lapd_msg_ctx *lctx)
 	 && lctx->p_f
 	 && dl->state != LAPD_STATE_TIMER_RECOV) {
 		/* 5.4.2.2: Inidcate error on supervisory reponse F=1 */
-		LOGP(DLLAPD, LOGL_NOTICE, "S frame response with F=1 error\n");
+		LOGP(DLLAPD, LOGL_NOTICE,
+		     "S frame response with F=1 error (dl=%p)\n", dl);
 		mdl_error(MDL_CAUSE_UNSOL_SPRV_RESP, lctx);
 	}
 
@@ -1248,14 +1271,15 @@ static int lapd_rx_s(struct msgb *msg, struct lapd_msg_ctx *lctx)
 		/* fall though */
 	case LAPD_STATE_SABM_SENT:
 	case LAPD_STATE_DISC_SENT:
-		LOGP(DLLAPD, LOGL_NOTICE, "S frame ignored in this state\n");
+		LOGP(DLLAPD, LOGL_NOTICE,
+		     "S frame ignored in this state (dl=%p)\n", dl);
 		msgb_free(msg);
 		return 0;
 	}
 	switch (lctx->s_u) {
 	case LAPD_S_RR:
-		LOGP(DLLAPD, LOGL_INFO, "RR received in state %s\n",
-			lapd_state_names[dl->state]);
+		LOGP(DLLAPD, LOGL_INFO, "RR received in state %s (dl=%p)\n",
+			lapd_state_names[dl->state], dl);
 		/* 5.5.3.1: Acknowlege all tx frames up the the N(R)-1 */
 		lapd_acknowledge(lctx);
 
@@ -1264,9 +1288,9 @@ static int lapd_rx_s(struct msgb *msg, struct lapd_msg_ctx *lctx)
 		 && lctx->p_f) {
 		 	if (!dl->own_busy && !dl->seq_err_cond) {
 				LOGP(DLLAPD, LOGL_INFO, "RR frame command "
-					"with polling bit set and we are not "
-					"busy, so we reply with RR frame "
-					"response\n");
+				     "with polling bit set and we are not "
+				     "busy, so we reply with RR frame "
+				      "response (dl=%p)\n", dl);
 				lapd_send_rr(lctx, 1, 0);
 				/* NOTE: In case of sequence error condition,
 				 * the REJ frame has been transmitted when
@@ -1275,8 +1299,9 @@ static int lapd_rx_s(struct msgb *msg, struct lapd_msg_ctx *lctx)
 				 */
 			} else if (dl->own_busy) {
 				LOGP(DLLAPD, LOGL_INFO, "RR frame command "
-					"with polling bit set and we are busy, "
-					"so we reply with RR frame response\n");
+				     "with polling bit set and we are busy, "
+				     "so we reply with RR frame response (dl=%p)\n",
+				     dl);
 				lapd_send_rnr(lctx, 1, 0);
 			}
 		} else if (lctx->cr == dl->cr.rem2loc.resp
@@ -1284,7 +1309,7 @@ static int lapd_rx_s(struct msgb *msg, struct lapd_msg_ctx *lctx)
 			&& dl->state == LAPD_STATE_TIMER_RECOV) {
 			LOGP(DLLAPD, LOGL_INFO, "RR response with F==1, "
 				"and we are in timer recovery state, so "
-				"we leave that state\n");
+				"we leave that state (dl=%p)\n", dl);
 			/* V(S) to the N(R) in the RR frame */
 			dl->v_send = lctx->n_recv;
 			/* stop Timer T200 */
@@ -1297,8 +1322,8 @@ static int lapd_rx_s(struct msgb *msg, struct lapd_msg_ctx *lctx)
 
 		break;
 	case LAPD_S_RNR:
-		LOGP(DLLAPD, LOGL_INFO, "RNR received in state %s\n",
-			lapd_state_names[dl->state]);
+		LOGP(DLLAPD, LOGL_INFO, "RNR received in state %s (dl=%p)\n",
+			lapd_state_names[dl->state], dl);
 		/* 5.5.3.1: Acknowlege all tx frames up the the N(R)-1 */
 		lapd_acknowledge(lctx);
 
@@ -1312,21 +1337,21 @@ static int lapd_rx_s(struct msgb *msg, struct lapd_msg_ctx *lctx)
 					LOGP(DLLAPD, LOGL_INFO, "RNR poll "
 						"command and we are not busy, "
 						"so we reply with RR final "
-						"response\n");
+						"response (dl=%p)\n", dl);
 					/* Send RR with F=1 */
 					lapd_send_rr(lctx, 1, 0);
 				} else {
 					LOGP(DLLAPD, LOGL_INFO, "RNR poll "
 						"command and we are busy, so "
 						"we reply with RNR final "
-						"response\n");
+						"response (dl=%p)\n", dl);
 					/* Send RNR with F=1 */
 					lapd_send_rnr(lctx, 1, 0);
 				}
 			} else if (dl->state == LAPD_STATE_TIMER_RECOV) {
 				LOGP(DLLAPD, LOGL_INFO, "RNR poll response "
 					"and we in timer recovery state, so "
-					"we leave that state\n");
+					"we leave that state (dl=%p)\n", dl);
 				/* 5.5.7 Clear timer recovery condition */
 				lapd_dl_newstate(dl, LAPD_STATE_MF_EST);
 				/* V(S) to the N(R) in the RNR frame */
@@ -1334,15 +1359,15 @@ static int lapd_rx_s(struct msgb *msg, struct lapd_msg_ctx *lctx)
 			}
 		} else
 			LOGP(DLLAPD, LOGL_INFO, "RNR not polling/final state "
-				"received\n");
+			     "received (dl=%p)\n", dl);
 
 		/* Send message, if possible due to acknowledged data */
 		lapd_send_i(lctx, __LINE__);
 
 		break;
 	case LAPD_S_REJ:
-		LOGP(DLLAPD, LOGL_INFO, "REJ received in state %s\n",
-			lapd_state_names[dl->state]);
+		LOGP(DLLAPD, LOGL_INFO, "REJ received in state %s (dl=%p)\n",
+			lapd_state_names[dl->state], dl);
 		/* 5.5.3.1: Acknowlege all tx frames up the the N(R)-1 */
 		lapd_acknowledge(lctx);
 
@@ -1362,7 +1387,7 @@ static int lapd_rx_s(struct msgb *msg, struct lapd_msg_ctx *lctx)
 						"state and not in own busy "
 						"condition received, so we "
 						"respond with RR final "
-						"response\n");
+						"response (dl=%p)\n", dl);
 					lapd_send_rr(lctx, 1, 0);
 					/* NOTE: In case of sequence error
 					 * condition, the REJ frame has been
@@ -1376,21 +1401,24 @@ static int lapd_rx_s(struct msgb *msg, struct lapd_msg_ctx *lctx)
 						"state and in own busy "
 						"condition received, so we "
 						"respond with RNR final "
-						"response\n");
+						"response (dl=%p)\n", dl);
 					lapd_send_rnr(lctx, 1, 0);
 				}
 			} else
 				LOGP(DLLAPD, LOGL_INFO, "REJ response or not "
 					"polling command not in timer recovery "
-					"state received\n");
+					"state received (dl=%p)\n", dl);
 			/* send MDL ERROR INIDCATION to L3 */
 			if (lctx->cr == dl->cr.rem2loc.resp && lctx->p_f) {
+				LOGP(DLLAPD, LOGL_ERROR,
+				     "unsolicited supervisory response! (dl=%p)\n",
+				     dl);
 				mdl_error(MDL_CAUSE_UNSOL_SPRV_RESP, lctx);
 			}
 
 		} else if (lctx->cr == dl->cr.rem2loc.resp && lctx->p_f) {
 			LOGP(DLLAPD, LOGL_INFO, "REJ poll response in timer "
-				"recovery state received\n");
+				"recovery state received (dl=%p)\n", dl);
 			/* Clear an existing peer receiver busy condition */
 			dl->peer_busy = 0;
 			/* V(S) and V(A) to the N(R) in the REJ frame */
@@ -1412,7 +1440,7 @@ static int lapd_rx_s(struct msgb *msg, struct lapd_msg_ctx *lctx)
 						"state and not in own busy "
 						"condition received, so we "
 						"respond with RR final "
-						"response\n");
+						"response (dl=%p)\n", dl);
 					lapd_send_rr(lctx, 1, 0);
 					/* NOTE: In case of sequence error
 					 * condition, the REJ frame has been
@@ -1426,13 +1454,13 @@ static int lapd_rx_s(struct msgb *msg, struct lapd_msg_ctx *lctx)
 						"state and in own busy "
 						"condition received, so we "
 						"respond with RNR final "
-						"response\n");
+						"response (dl=%p)\n", dl);
 					lapd_send_rnr(lctx, 1, 0);
 				}
 			} else
 				LOGP(DLLAPD, LOGL_INFO, "REJ response or not "
 					"polling command in timer recovery "
-					"state received\n");
+					"state received (dl=%p)\n", dl);
 		}
 
 		/* FIXME: 5.5.4.2 2) */
@@ -1443,7 +1471,8 @@ static int lapd_rx_s(struct msgb *msg, struct lapd_msg_ctx *lctx)
 		break;
 	default:
 		/* G.3.1 */
-		LOGP(DLLAPD, LOGL_ERROR, "Supervisory frame not allowed.\n");
+		LOGP(DLLAPD, LOGL_ERROR,
+		     "Supervisory frame not allowed. (dl=%p)\n", dl);
 		msgb_free(msg);
 		mdl_error(MDL_CAUSE_FRM_UNIMPL, lctx);
 		return -EINVAL;
@@ -1461,12 +1490,13 @@ static int lapd_rx_i(struct msgb *msg, struct lapd_msg_ctx *lctx)
 	int length = lctx->length;
 	int rc;
 
-	LOGP(DLLAPD, LOGL_INFO, "I received in state %s on SAPI(%u)\n",
-		lapd_state_names[dl->state], lctx->sapi);
+	LOGP(DLLAPD, LOGL_INFO, "I received in state %s on SAPI(%u) (dl=%p)\n",
+		lapd_state_names[dl->state], lctx->sapi, dl);
 		
 	/* G.2.2 Wrong value of the C/R bit */
 	if (lctx->cr == dl->cr.rem2loc.resp) {
-		LOGP(DLLAPD, LOGL_ERROR, "I frame response not allowed\n");
+		LOGP(DLLAPD, LOGL_ERROR,
+		     "I frame response not allowed (dl=%p)\n", dl);
 		msgb_free(msg);
 		mdl_error(MDL_CAUSE_FRM_UNIMPL, lctx);
 		return -EINVAL;
@@ -1477,7 +1507,8 @@ static int lapd_rx_i(struct msgb *msg, struct lapd_msg_ctx *lctx)
 		 * to a numerical value L>N201 or L=0, an MDL-ERROR-INDICATION
 		 * primitive with cause "I frame with incorrect length"
 		 * is sent to the mobile management entity. */
-		LOGP(DLLAPD, LOGL_ERROR, "I frame length not allowed\n");
+		LOGP(DLLAPD, LOGL_ERROR,
+		     "I frame length not allowed (dl=%p)\n", dl);
 		msgb_free(msg);
 		mdl_error(MDL_CAUSE_IFRM_INC_LEN, lctx);
 		return -EIO;
@@ -1488,7 +1519,8 @@ static int lapd_rx_i(struct msgb *msg, struct lapd_msg_ctx *lctx)
 	 * cause "I frame with incorrect use of M bit" is sent to the
 	 * mobile management entity. */
 	if (lctx->more && length < lctx->n201) {
-		LOGP(DLLAPD, LOGL_ERROR, "I frame with M bit too short\n");
+		LOGP(DLLAPD, LOGL_ERROR,
+		     "I frame with M bit too short (dl=%p)\n", dl);
 		msgb_free(msg);
 		mdl_error(MDL_CAUSE_IFRM_INC_MBITS, lctx);
 		return -EIO;
@@ -1503,7 +1535,8 @@ static int lapd_rx_i(struct msgb *msg, struct lapd_msg_ctx *lctx)
 		/* fall though */
 	case LAPD_STATE_SABM_SENT:
 	case LAPD_STATE_DISC_SENT:
-		LOGP(DLLAPD, LOGL_NOTICE, "I frame ignored in this state\n");
+		LOGP(DLLAPD, LOGL_NOTICE,
+		     "I frame ignored in this state (dl=%p)\n", dl);
 		msgb_free(msg);
 		return 0;
 	}
@@ -1511,7 +1544,7 @@ static int lapd_rx_i(struct msgb *msg, struct lapd_msg_ctx *lctx)
 	/* 5.7.1: N(s) sequence error */
 	if (ns != dl->v_recv) {
 		LOGP(DLLAPD, LOGL_NOTICE, "N(S) sequence error: N(S)=%u, "
-		     "V(R)=%u\n", ns, dl->v_recv);
+		     "V(R)=%u (dl=%p)\n", ns, dl->v_recv, dl);
 		/* discard data */
 		msgb_free(msg);
 		if (dl->seq_err_cond != 1) {
@@ -1545,7 +1578,8 @@ static int lapd_rx_i(struct msgb *msg, struct lapd_msg_ctx *lctx)
 
 	/* Increment receiver state */
 	dl->v_recv = inc_mod(dl->v_recv, dl->v_range);
-	LOGP(DLLAPD, LOGL_INFO, "incrementing V(R) to %u\n", dl->v_recv);
+	LOGP(DLLAPD, LOGL_INFO, "incrementing V(R) to %u (dl=%p)\n",
+	     dl->v_recv, dl);
 
 	/* 5.5.3.1: Acknowlege all transmitted frames up the the N(R)-1 */
 	lapd_acknowledge(lctx); /* V(A) is also set here */
@@ -1554,7 +1588,8 @@ static int lapd_rx_i(struct msgb *msg, struct lapd_msg_ctx *lctx)
 	if (!dl->own_busy) {
 		/* if the frame carries a complete segment */
 		if (!lctx->more && !dl->rcv_buffer) {
-			LOGP(DLLAPD, LOGL_INFO, "message in single I frame\n");
+			LOGP(DLLAPD, LOGL_INFO,
+			     "message in single I frame (dl=%p)\n", dl);
 			/* send a DATA INDICATION to L3 */
 			msgb_trim(msg, length);
 			rc = send_dl_l3(PRIM_DL_DATA, PRIM_OP_INDICATION, lctx,
@@ -1563,7 +1598,7 @@ static int lapd_rx_i(struct msgb *msg, struct lapd_msg_ctx *lctx)
 			/* create rcv_buffer */
 			if (!dl->rcv_buffer) {
 				LOGP(DLLAPD, LOGL_INFO, "message in multiple "
-					"I frames (first message)\n");
+				     "I frames (first message) (dl=%p)\n", dl);
 				dl->rcv_buffer = lapd_msgb_alloc(dl->maxf,
 					"LAPD RX");
 				dl->rcv_buffer->l3h = dl->rcv_buffer->data;
@@ -1571,7 +1606,7 @@ static int lapd_rx_i(struct msgb *msg, struct lapd_msg_ctx *lctx)
 			/* concat. rcv_buffer */
 			if (msgb_l3len(dl->rcv_buffer) + length > dl->maxf) {
 				LOGP(DLLAPD, LOGL_NOTICE, "Received frame "
-					"overflow!\n");
+					"overflow! (dl=%p)\n", dl);
 			} else {
 				memcpy(msgb_put(dl->rcv_buffer, length),
 					msg->l3h, length);
@@ -1579,14 +1614,14 @@ static int lapd_rx_i(struct msgb *msg, struct lapd_msg_ctx *lctx)
 			/* if the last segment was received */
 			if (!lctx->more) {
 				LOGP(DLLAPD, LOGL_INFO, "message in multiple "
-					"I frames (last message)\n");
+					"I frames (last message) (dl=%p)\n", dl);
 				rc = send_dl_l3(PRIM_DL_DATA,
 					PRIM_OP_INDICATION, lctx,
 					dl->rcv_buffer);
 				dl->rcv_buffer = NULL;
 			} else
 				LOGP(DLLAPD, LOGL_INFO, "message in multiple "
-					"I frames (next message)\n");
+					"I frames (next message) (dl=%p)\n", dl);
 			msgb_free(msg);
 
 		}
@@ -1599,11 +1634,13 @@ static int lapd_rx_i(struct msgb *msg, struct lapd_msg_ctx *lctx)
 		/* 5.5.2.1 */
 		/* check if we are not in own receiver busy */
 		if (!dl->own_busy) {
-			LOGP(DLLAPD, LOGL_INFO, "we are not busy, send RR\n");
+			LOGP(DLLAPD, LOGL_INFO,
+			     "we are not busy, send RR (dl=%p)\n", dl);
 			/* Send RR with F=1 */
 			rc = lapd_send_rr(lctx, 1, 0);
 		} else {
-			LOGP(DLLAPD, LOGL_INFO, "we are busy, send RNR\n");
+			LOGP(DLLAPD, LOGL_INFO,
+			     "we are busy, send RNR (dl=%p)\n", dl);
 			/* Send RNR with F=1 */
 			rc = lapd_send_rnr(lctx, 1, 0);
 		}
@@ -1621,14 +1658,16 @@ static int lapd_rx_i(struct msgb *msg, struct lapd_msg_ctx *lctx)
 
 			if (rc) {
 				LOGP(DLLAPD, LOGL_INFO, "we are not busy and "
-					"have no pending data, send RR\n");
+				     "have no pending data, send RR (dl=%p)\n",
+				     dl);
 				/* Send RR with F=0 */
 				return lapd_send_rr(lctx, 0, 0);
 			}
 			/* all I or one RR is sent, we are done */
 			return 0;
 		} else {
-			LOGP(DLLAPD, LOGL_INFO, "we are busy, send RNR\n");
+			LOGP(DLLAPD, LOGL_INFO,
+			     "we are busy, send RNR (dl=%p)\n", dl);
 			/* Send RNR with F=0 */
 			rc = lapd_send_rnr(lctx, 0, 0);
 		}
@@ -1656,7 +1695,8 @@ int lapd_ph_data_ind(struct msgb *msg, struct lapd_msg_ctx *lctx)
 		rc = lapd_rx_i(msg, lctx);
 		break;
 	default:
-		LOGP(DLLAPD, LOGL_NOTICE, "unknown LAPD format\n");
+		LOGP(DLLAPD, LOGL_NOTICE,
+		     "unknown LAPD format (dl=%p)\n", lctx->dl);
 		msgb_free(msg);
 		rc = -EINVAL;
 	}
@@ -1695,9 +1735,10 @@ static int lapd_est_req(struct osmo_dlsap_prim *dp, struct lapd_msg_ctx *lctx)
 
 	if (msg->len)
 		LOGP(DLLAPD, LOGL_INFO, "perform establishment with content "
-			"(SABM)\n");
+			"(SABM) (dl=%p)\n", dl);
 	else
-		LOGP(DLLAPD, LOGL_INFO, "perform normal establishm. (SABM)\n");
+		LOGP(DLLAPD, LOGL_INFO,
+		     "perform normal establishm. (SABM), (dl=%p)\n", dl);
 
 	/* Flush send-queue */
 	/* Clear send-buffer */
@@ -1753,13 +1794,14 @@ static int lapd_data_req(struct osmo_dlsap_prim *dp, struct lapd_msg_ctx *lctx)
 
 	if (msgb_l3len(msg) == 0) {
 		LOGP(DLLAPD, LOGL_ERROR,
-			"writing an empty message is not possible.\n");
+		     "writing an empty message is not possible. (dl=%p)\n", dl);
 		msgb_free(msg);
 		return -1;
 	}
 
 	LOGP(DLLAPD, LOGL_INFO,
-	     "writing message to send-queue: l3len: %d\n", msgb_l3len(msg));
+	     "writing message to send-queue: l3len: %d (dl=%p)\n",
+	     msgb_l3len(msg), dl);
 
 	/* Write data into the send queue */
 	msgb_enqueue(&dl->send_queue, msg);
@@ -1782,17 +1824,19 @@ static int lapd_send_i(struct lapd_msg_ctx *lctx, int line)
 	struct lapd_msg_ctx nctx;
 
 
-	LOGP(DLLAPD, LOGL_INFO, "%s() called from line %d\n", __func__, line);
+	LOGP(DLLAPD, LOGL_INFO,
+	     "%s() called from line %d (dl=%p)\n", __func__, line, dl);
 
 	next_frame:
 
 	if (dl->peer_busy) {
-		LOGP(DLLAPD, LOGL_INFO, "peer busy, not sending\n");
+		LOGP(DLLAPD, LOGL_INFO, "peer busy, not sending (dl=%p)\n", dl);
 		return rc;
 	}
 
 	if (dl->state == LAPD_STATE_TIMER_RECOV) {
-		LOGP(DLLAPD, LOGL_INFO, "timer recovery, not sending\n");
+		LOGP(DLLAPD, LOGL_INFO,
+		     "timer recovery, not sending (dl=%p)\n", dl);
 		return rc;
 	}
 
@@ -1804,8 +1848,8 @@ static int lapd_send_i(struct lapd_msg_ctx *lctx, int line)
 	 * 5.5.7. */
 	if (dl->v_send == add_mod(dl->v_ack, k, dl->v_range)) {
 		LOGP(DLLAPD, LOGL_INFO, "k frames outstanding, not sending "
-			"more (k=%u V(S)=%u V(A)=%u)\n", k, dl->v_send,
-			dl->v_ack);
+			"more (k=%u V(S)=%u V(A)=%u) (dl=%p)\n", k, dl->v_send,
+			dl->v_ack, dl);
 		return rc;
 	}
 
@@ -1822,7 +1866,7 @@ static int lapd_send_i(struct lapd_msg_ctx *lctx, int line)
 			if (!dl->send_buffer)
 				return rc;
 			LOGP(DLLAPD, LOGL_INFO, "get message from "
-				"send-queue\n");
+				"send-queue (dl=%p)\n", dl);
 		}
 
 		/* How much is left in the send-buffer? */
@@ -1832,9 +1876,9 @@ static int lapd_send_i(struct lapd_msg_ctx *lctx, int line)
 		if (length > lctx->n201)
 			length = lctx->n201;
 		LOGP(DLLAPD, LOGL_INFO, "msg-len %d sent %d left %d N201 %d "
-			"length %d first byte %02x\n",
+			"length %d first byte %02x (dl=%p)\n",
 			msgb_l3len(dl->send_buffer), dl->send_out, left,
-			lctx->n201, length, dl->send_buffer->l3h[0]);
+			lctx->n201, length, dl->send_buffer->l3h[0], dl);
 		/* If message in send-buffer is completely sent */
 		if (left == 0) {
 			msgb_free(dl->send_buffer);
@@ -1842,8 +1886,8 @@ static int lapd_send_i(struct lapd_msg_ctx *lctx, int line)
 			goto next_message;
 		}
 
-		LOGP(DLLAPD, LOGL_INFO, "send I frame %sV(S)=%d\n",
-			(left > length) ? "segment " : "", dl->v_send);
+		LOGP(DLLAPD, LOGL_INFO, "send I frame %sV(S)=%d (dl=%p)\n",
+			(left > length) ? "segment " : "", dl->v_send, dl);
 
 		/* Create I frame (segment) and transmit-buffer content */