Join ms_merge_and_clear_ms() and ms_merge_old_ms()

While at it, improve logging of the merge action

Change-Id: I39d9eac159448fc3c3a4db9e1b9c5364e906a78f
diff --git a/src/gprs_ms.c b/src/gprs_ms.c
index bf4d08a..f1b0c6a 100644
--- a/src/gprs_ms.c
+++ b/src/gprs_ms.c
@@ -402,9 +402,17 @@
 	ms->imsi[0] = '\0';
 }
 
-static void ms_merge_old_ms(struct GprsMs *ms, struct GprsMs *old_ms)
+/* Merge 'old_ms' object into 'ms' object.
+ * 'old_ms' may be freed during the call to this function, don't use the pointer to it afterwards */
+void ms_merge_and_clear_ms(struct GprsMs *ms, struct GprsMs *old_ms)
 {
+	char old_ms_name[128];
 	OSMO_ASSERT(old_ms != ms);
+	ms_ref(old_ms);
+
+	ms_name_buf(old_ms, old_ms_name, sizeof(old_ms_name));
+
+	LOGPMS(ms, DRLCMAC, LOGL_INFO, "Merge MS: %s\n", old_ms_name);
 
 	if (strlen(ms_imsi(ms)) == 0 && strlen(ms_imsi(old_ms)) != 0)
 		osmo_strlcpy(ms->imsi, ms_imsi(old_ms), sizeof(ms->imsi));
@@ -417,14 +425,6 @@
 
 	llc_queue_move_and_merge(&ms->llc_queue, &old_ms->llc_queue);
 
-	ms_reset(old_ms);
-}
-
-void ms_merge_and_clear_ms(struct GprsMs *ms, struct GprsMs *old_ms)
-{
-	OSMO_ASSERT(old_ms != ms);
-
-	ms_ref(old_ms);
 
 	/* Clean up the old MS object */
 	/* TODO: Use timer? */
@@ -433,7 +433,7 @@
 	if (ms_dl_tbf(old_ms) && !tbf_timers_pending((struct gprs_rlcmac_tbf *)ms_dl_tbf(old_ms), T_MAX))
 			tbf_free((struct gprs_rlcmac_tbf *)ms_dl_tbf(old_ms));
 
-	ms_merge_old_ms(ms, old_ms);
+	ms_reset(old_ms);
 
 	ms_unref(old_ms);
 }
diff --git a/tests/tbf/TbfTest.err b/tests/tbf/TbfTest.err
index fe7b628..6a7ca38 100644
--- a/tests/tbf/TbfTest.err
+++ b/tests/tbf/TbfTest.err
@@ -617,6 +617,7 @@
 Modifying MS object, TLLI = 0xf1000001, IMSI '001001000000001' -> '001001000000002'
 Modifying MS object, TLLI = 0xf1000002, IMSI '' -> '001001000000002'
 MS(TLLI=0xf1000002, IMSI=, TA=0, 45/0, DL) IMSI '001001000000002' was already assigned to another MS object: TLLI = 0xf1000001, that IMSI will be removed
+MS(TLLI=0xf1000002, IMSI=, TA=0, 45/0, DL) Merge MS: MS(TLLI=0xf1000001, IMSI=001001000000002, TA=0, 45/0, DL)
 TBF(TFI=0 TLLI=0xf1000001 DIR=DL STATE=FLOW) free
 PDCH(bts=0,trx=0,ts=4) Detaching TBF(TFI=0 TLLI=0xf1000001 DIR=DL STATE=FLOW), 2 TBFs, USFs = 00, TFIs = 00000003.
 MS(TLLI=0xf1000001, IMSI=001001000000002, TA=0, 45/0,) Detaching TBF: TBF(TFI=0 TLLI=0xf1000001 DIR=DL STATE=FLOW)
@@ -2314,6 +2315,7 @@
 IMSI 0011223344, old TBF TBF(TFI=0 TLLI=0xf1223344 DIR=DL STATE=FINISHED): moving DL TBF to new MS object
 MS(TLLI=0xf1223344, IMSI=0011223344, TA=7, 1/0, UL) Detaching TBF: TBF(TFI=0 TLLI=0xf1223344 DIR=DL STATE=FINISHED)
 MS(TLLI=0xf5667788, IMSI=, TA=7, 1/0, UL) Attaching DL TBF: TBF(TFI=0 TLLI=0xf5667788 DIR=DL STATE=FINISHED)
+MS(TLLI=0xf5667788, IMSI=, TA=7, 1/0, UL DL) Merge MS: MS(TLLI=0xf1223344, IMSI=0011223344, TA=7, 1/0, UL)
 TBF(TFI=0 TLLI=0xf1223344 DIR=UL STATE=FLOW) free
 PDCH(bts=0,trx=0,ts=7) Detaching TBF(TFI=0 TLLI=0xf1223344 DIR=UL STATE=FLOW), 2 TBFs, USFs = 03, TFIs = 00000003.
 MS(TLLI=0xf1223344, IMSI=0011223344, TA=7, 1/0,) Detaching TBF: TBF(TFI=0 TLLI=0xf1223344 DIR=UL STATE=FLOW)
@@ -2656,6 +2658,8 @@
 TBF(TFI=0 TLLI=0xffffffff DIR=UL STATE=FLOW) data_length=20, data=f1 22 33 44 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 
 TBF(TFI=0 TLLI=0xffffffff DIR=UL STATE=FLOW) Decoded premier TLLI=0xf1223344 of UL DATA TFI=0.
 Modifying MS object, UL TLLI: 0xffffffff -> 0xf1223344, not yet confirmed
+MS(TLLI=0xf1223344, IMSI=, TA=7, 0/0, UL) Merge MS: MS(TLLI=0xf1223344, IMSI=0011223344, TA=7, 1/0, DL)
+Modifying MS object, TLLI = 0xf1223344, MS class 0 -> 1
 TBF(TFI=0 TLLI=0xf1223344 DIR=DL STATE=ASSIGN) free
 PDCH(bts=0,trx=0,ts=7) Detaching TBF(TFI=0 TLLI=0xf1223344 DIR=DL STATE=ASSIGN), 1 TBFs, USFs = 01, TFIs = 00000001.
 MS(TLLI=0xf1223344, IMSI=0011223344, TA=7, 1/0,) Detaching TBF: TBF(TFI=0 TLLI=0xf1223344 DIR=DL STATE=ASSIGN)
@@ -2663,7 +2667,6 @@
 TBF(DL-TFI_0){ASSIGN}: Deallocated
 UL_ASS_TBF(DL-TFI_0){NONE}: Deallocated
 DL_ASS_TBF(DL-TFI_0){NONE}: Deallocated
-Modifying MS object, TLLI = 0xf1223344, MS class 0 -> 1
 MS(TLLI=0xf1223344, IMSI=0011223344, TA=7, 1/0,) Clearing MS object
 MS(TLLI=0xffffffff, IMSI=, TA=7, 1/0,) Destroying MS object
 TBF(TFI=0 TLLI=0xf1223344 DIR=UL STATE=FLOW) Assembling frames: (len=20)