Expand chan allocation logging

Log more data related to channel allocation:
- channel type
- number of paging attempts
- timers fired

Change-Id: Ib417a9c942c17b902dd80ff555cd9da5f91bff48

4 files changed, 14 insertions, 8 deletions

diff --git a/openbsc/src/libbsc/abis_rsl.c b/openbsc/src/libbsc/abis_rsl.c
index 8a6b111bb..cc190eb45 100644
--- a/openbsc/src/libbsc/abis_rsl.c
+++ b/openbsc/src/libbsc/abis_rsl.c
@@ -1659,7 +1659,9 @@ static int abis_rsl_rx_trx(struct msgb *msg)
 static void t3101_expired(void *data)
 {
 	struct gsm_lchan *lchan = data;
-
+	LOGP(DRSL, LOGL_NOTICE,
+	     "%s T3101 expired: no response to IMMEDIATE ASSIGN\n",
+	     gsm_lchan_name(lchan));
 	rsl_rf_chan_release(lchan, 1, SACCH_DEACTIVATE);
 }
 
@@ -1667,7 +1669,9 @@ static void t3101_expired(void *data)
 static void t3111_expired(void *data)
 {
 	struct gsm_lchan *lchan = data;
-
+	LOGP(DRSL, LOGL_NOTICE,
+	     "%s T3111 expired: releasing RF Channel\n",
+	     gsm_lchan_name(lchan));
 	rsl_rf_chan_release(lchan, 0, SACCH_NONE);
 }
 
diff --git a/openbsc/src/libbsc/bsc_api.c b/openbsc/src/libbsc/bsc_api.c
index 8a4c85ff3..7a48296ac 100644
--- a/openbsc/src/libbsc/bsc_api.c
+++ b/openbsc/src/libbsc/bsc_api.c
@@ -397,7 +397,8 @@ int gsm0808_assign_req(struct gsm_subscriber_connection *conn, int chan_mode, in
 			handle_mr_config(conn, conn->lchan, full_rate);
 
 		LOGP(DMSC, LOGL_NOTICE,
-		     "Sending ChanModify for speech: %s on channel %s\n",
+		     "Sending %s ChanModify for speech: %s on channel %s\n",
+		     gsm_lchan_name(conn->lchan),
 		     get_value_string(gsm48_chan_mode_names, chan_mode),
 		     get_value_string(gsm_chan_t_names, conn->lchan->type));
 		gsm48_lchan_modify(conn->lchan, chan_mode);
diff --git a/openbsc/src/libbsc/paging.c b/openbsc/src/libbsc/paging.c
index fcb4debd9..8c3063714 100644
--- a/openbsc/src/libbsc/paging.c
+++ b/openbsc/src/libbsc/paging.c
@@ -79,8 +79,9 @@ static void page_ms(struct gsm_paging_request *request)
 
 	log_set_context(BSC_CTX_SUBSCR, request->subscr);
 
-	LOGP(DPAG, LOGL_INFO, "Going to send paging commands: imsi: '%s' tmsi: '0x%x'\n",
-		request->subscr->imsi, request->subscr->tmsi);
+	LOGP(DPAG, LOGL_INFO, "Going to send paging commands: imsi: %s tmsi: "
+	     "0x%x for ch. type %d (attempt %d)\n", request->subscr->imsi,
+	     request->subscr->tmsi, request->chan_type, request->attempts);
 
 	if (request->subscr->tmsi == GSM_RESERVED_TMSI)
 		mi_len = gsm48_generate_mid_from_imsi(mi, request->subscr->imsi);
@@ -376,11 +377,11 @@ static void _paging_request_stop(struct gsm_bts *bts, struct gsm_subscriber *sub
 			req = NULL;
 
 			if (conn && cbfn) {
-				LOGP(DPAG, LOGL_DEBUG, "Stop paging on bts %d, calling cbfn.\n", bts->nr);
+				LOGP(DPAG, LOGL_DEBUG, "Stop paging %s on bts %d, calling cbfn.\n", subscr->imsi, bts->nr);
 				cbfn(GSM_HOOK_RR_PAGING, GSM_PAGING_SUCCEEDED,
 					  msg, conn, param);
 			} else
-				LOGP(DPAG, LOGL_DEBUG, "Stop paging on bts %d silently.\n", bts->nr);
+				LOGP(DPAG, LOGL_DEBUG, "Stop paging %s on bts %d silently.\n", subscr->imsi, bts->nr);
 			break;
 		}
 	}
diff --git a/openbsc/src/libmsc/gsm_04_08.c b/openbsc/src/libmsc/gsm_04_08.c
index e5402d0a6..1a64731e0 100644
--- a/openbsc/src/libmsc/gsm_04_08.c
+++ b/openbsc/src/libmsc/gsm_04_08.c
@@ -1483,7 +1483,7 @@ static int gsm48_rx_rr_app_info(struct gsm_subscriber_connection *conn, struct m
 	apdu_len = gh->data[1];
 	apdu_data = gh->data+2;
 
-	DEBUGP(DRR, "RX APPLICATION INFO id/flags=0x%02x apdu_len=%u apdu=%s",
+	DEBUGP(DRR, "RX APPLICATION INFO id/flags=0x%02x apdu_len=%u apdu=%s\n",
 		apdu_id_flags, apdu_len, osmo_hexdump(apdu_data, apdu_len));
 
 	return db_apdu_blob_store(conn->subscr, apdu_id_flags, apdu_len, apdu_data);