ms: Rewrite MS release lifecycle

This commit changes lots of stuff in the MS release lifecycle, but
there's no really good way to split this into patches which make sense,
since all the chaos is intensively entangled.

Get rid of the ms_callback complex mess, it is not needed at all.

Previous MS release was strange due to the existance of previous
ms_callback.idle concept and MS storage: the MS signalled when it went
idle (no TBFs attached) and waited for somebody outside to free it,
while then arming itself the release timer to release itself if it was
not released by whoever.

The new lifecycle follows an easier (expected) approach: Whenever all
TBFs become detached from the MS and it becomes idle (use_count becomes
0), then it frees its reserved resources (TFI, etc.) and either:
* frees itself immediatelly under certain conditions (release timeout
  configured = 0 or MS garbage with TLLI=GSM_RESERVED_TMSI)
* Arms release_timer and frees itself when it triggers.

If during release_timer the MS is required again (for instance because a
new TBF with TLLI/IMSI of the MS is observed), then a TBF is attached to
the MS and it is considered to become active again, hence the release_timer
is stopped.

OS#6002
Change-Id: Ibe5115bc15bb4d76026918adc1be79469c2f4839
diff --git a/tests/ms/MsTest.cpp b/tests/ms/MsTest.cpp
index 40e8381..bc68c3d 100644
--- a/tests/ms/MsTest.cpp
+++ b/tests/ms/MsTest.cpp
@@ -120,96 +120,6 @@
 	printf("=== end %s ===\n", __func__);
 }
 
-static enum {CB_UNKNOWN, CB_IS_IDLE, CB_IS_ACTIVE} last_cb = CB_UNKNOWN;
-static void ms_idle_cb(struct GprsMs *ms)
-{
-	OSMO_ASSERT(ms_is_idle(ms));
-	printf("  ms_idle() was called\n");
-	last_cb = CB_IS_IDLE;
-}
-static void ms_active_cb(struct GprsMs *ms)
-{
-	OSMO_ASSERT(!ms_is_idle(ms));
-	printf("  ms_active() was called\n");
-	last_cb = CB_IS_ACTIVE;
-}
-static struct gpr_ms_callback ms_cb = {
-	.ms_idle = ms_idle_cb,
-	.ms_active = ms_active_cb
-};
-static void test_ms_callback()
-{
-	uint32_t tlli = 0xffeeddbb;
-	gprs_rlcmac_dl_tbf *dl_tbf;
-	gprs_rlcmac_ul_tbf *ul_tbf;
-	struct gprs_rlcmac_bts *bts = bts_alloc(the_pcu, 0);
-	GprsMs *ms;
-	last_cb = CB_UNKNOWN;
-
-	printf("=== start %s ===\n", __func__);
-
-	ms = ms_alloc(bts);
-	ms_set_tlli(ms, tlli);
-	ms_set_callback(ms, &ms_cb);
-
-	OSMO_ASSERT(ms_is_idle(ms));
-
-	dl_tbf = alloc_dl_tbf(bts, ms);
-	ul_tbf = alloc_ul_tbf(bts, ms);
-
-	OSMO_ASSERT(last_cb == CB_UNKNOWN);
-
-	ms_attach_tbf(ms, ul_tbf);
-	OSMO_ASSERT(!ms_is_idle(ms));
-	OSMO_ASSERT(ms_ul_tbf(ms) == ul_tbf);
-	OSMO_ASSERT(ms_dl_tbf(ms) == NULL);
-	OSMO_ASSERT(last_cb == CB_IS_ACTIVE);
-
-	last_cb = CB_UNKNOWN;
-
-	ms_attach_tbf(ms, dl_tbf);
-	OSMO_ASSERT(!ms_is_idle(ms));
-	OSMO_ASSERT(ms_ul_tbf(ms) == ul_tbf);
-	OSMO_ASSERT(ms_dl_tbf(ms) == dl_tbf);
-	OSMO_ASSERT(last_cb == CB_UNKNOWN);
-
-	ms_detach_tbf(ms, ul_tbf);
-	OSMO_ASSERT(!ms_is_idle(ms));
-	OSMO_ASSERT(ms_ul_tbf(ms) == NULL);
-	OSMO_ASSERT(ms_dl_tbf(ms) == dl_tbf);
-	OSMO_ASSERT(last_cb == CB_UNKNOWN);
-
-	ms_detach_tbf(ms, dl_tbf);
-	OSMO_ASSERT(ms_is_idle(ms));
-	OSMO_ASSERT(ms_ul_tbf(ms) == NULL);
-	OSMO_ASSERT(ms_dl_tbf(ms) == NULL);
-	OSMO_ASSERT(last_cb == CB_IS_IDLE);
-
-	last_cb = CB_UNKNOWN;
-	talloc_free(ms);
-
-	talloc_free(dl_tbf);
-	talloc_free(ul_tbf);
-	talloc_free(bts);
-	printf("=== end %s ===\n", __func__);
-}
-
-static bool was_idle;
-static void ms_replace_tbf_idle_cb(struct GprsMs *ms)
-{
-	OSMO_ASSERT(ms_is_idle(ms));
-	printf("  ms_idle() was called\n");
-	was_idle = true;
-}
-static void ms_replace_tbf_active_cb(struct GprsMs *ms)
-{
-	OSMO_ASSERT(!ms_is_idle(ms));
-	printf("  ms_active() was called\n");
-}
-static struct gpr_ms_callback ms_replace_tbf_cb = {
-	.ms_idle = ms_replace_tbf_idle_cb,
-	.ms_active = ms_replace_tbf_active_cb
-};
 static void test_ms_replace_tbf()
 {
 	uint32_t tlli = 0xffeeddbb;
@@ -222,10 +132,8 @@
 
 	ms = ms_alloc(bts);
 	ms_confirm_tlli(ms, tlli);
-	ms_set_callback(ms, &ms_replace_tbf_cb);
 
 	OSMO_ASSERT(ms_is_idle(ms));
-	was_idle = false;
 
 	dl_tbf[0] = alloc_dl_tbf(bts, ms);
 	dl_tbf[1] = alloc_dl_tbf(bts, ms);
@@ -236,44 +144,34 @@
 	OSMO_ASSERT(ms_ul_tbf(ms) == NULL);
 	OSMO_ASSERT(ms_dl_tbf(ms) == dl_tbf[0]);
 	OSMO_ASSERT(llist_empty(&ms->old_tbfs));
-	OSMO_ASSERT(!was_idle);
 
 	ms_attach_tbf(ms, dl_tbf[1]);
 	OSMO_ASSERT(!ms_is_idle(ms));
 	OSMO_ASSERT(ms_ul_tbf(ms) == NULL);
 	OSMO_ASSERT(ms_dl_tbf(ms) == dl_tbf[1]);
 	OSMO_ASSERT(!llist_empty(&ms->old_tbfs));
-	OSMO_ASSERT(!was_idle);
 
 	ms_attach_tbf(ms, ul_tbf);
 	OSMO_ASSERT(!ms_is_idle(ms));
 	OSMO_ASSERT(ms_ul_tbf(ms) == ul_tbf);
 	OSMO_ASSERT(ms_dl_tbf(ms) == dl_tbf[1]);
 	OSMO_ASSERT(!llist_empty(&ms->old_tbfs));
-	OSMO_ASSERT(!was_idle);
 
 	ms_detach_tbf(ms, ul_tbf);
 	OSMO_ASSERT(!ms_is_idle(ms));
 	OSMO_ASSERT(ms_ul_tbf(ms) == NULL);
 	OSMO_ASSERT(ms_dl_tbf(ms) == dl_tbf[1]);
 	OSMO_ASSERT(!llist_empty(&ms->old_tbfs));
-	OSMO_ASSERT(!was_idle);
 
 	ms_detach_tbf(ms, dl_tbf[0]);
 	OSMO_ASSERT(!ms_is_idle(ms));
 	OSMO_ASSERT(ms_ul_tbf(ms) == NULL);
 	OSMO_ASSERT(ms_dl_tbf(ms) == dl_tbf[1]);
 	OSMO_ASSERT(llist_empty(&ms->old_tbfs));
-	OSMO_ASSERT(!was_idle);
 
 	ms_detach_tbf(ms, dl_tbf[1]);
-	OSMO_ASSERT(ms_is_idle(ms));
-	OSMO_ASSERT(ms_ul_tbf(ms) == NULL);
-	OSMO_ASSERT(ms_dl_tbf(ms) == NULL);
-	OSMO_ASSERT(llist_empty(&ms->old_tbfs));
-	OSMO_ASSERT(was_idle);
-
-	talloc_free(ms);
+	/* MS is gone now: */
+	OSMO_ASSERT(bts_get_ms_by_tlli(bts, tlli, GSM_RESERVED_TMSI) == NULL);
 
 	talloc_free(dl_tbf[0]);
 	talloc_free(dl_tbf[1]);
@@ -470,13 +368,11 @@
 	gprs_rlcmac_ul_tbf *ul_tbf;
 	struct gprs_rlcmac_bts *bts = bts_alloc(the_pcu, 0);
 	GprsMs *ms;
-	last_cb = CB_UNKNOWN;
 
 	printf("=== start %s ===\n", __func__);
 
 	ms = ms_alloc(bts);
 	ms_set_tlli(ms, tlli);
-	ms_set_callback(ms, &ms_cb);
 	ms_set_timeout(ms, 1);
 
 	OSMO_ASSERT(ms_is_idle(ms));
@@ -484,34 +380,27 @@
 	dl_tbf = alloc_dl_tbf(bts, ms);
 	ul_tbf = alloc_ul_tbf(bts, ms);
 
-	OSMO_ASSERT(last_cb == CB_UNKNOWN);
-
 	ms_attach_tbf(ms, ul_tbf);
 	OSMO_ASSERT(!ms_is_idle(ms));
-	OSMO_ASSERT(last_cb == CB_IS_ACTIVE);
-
-	last_cb = CB_UNKNOWN;
 
 	ms_attach_tbf(ms, dl_tbf);
 	OSMO_ASSERT(!ms_is_idle(ms));
-	OSMO_ASSERT(last_cb == CB_UNKNOWN);
 
 	ms_detach_tbf(ms, ul_tbf);
 	OSMO_ASSERT(!ms_is_idle(ms));
-	OSMO_ASSERT(last_cb == CB_UNKNOWN);
 
 	ms_detach_tbf(ms, dl_tbf);
-	OSMO_ASSERT(!ms_is_idle(ms));
-	OSMO_ASSERT(last_cb == CB_UNKNOWN);
+	/* test MS still exists and it's idle: */
+	OSMO_ASSERT(bts_get_ms_by_tlli(bts, tlli, GSM_RESERVED_TMSI) != NULL);
+	OSMO_ASSERT(ms_is_idle(ms));
+	OSMO_ASSERT(osmo_timer_pending(&ms->timer));
 
 	usleep(1100000);
 	osmo_timers_update();
 
-	OSMO_ASSERT(ms_is_idle(ms));
-	OSMO_ASSERT(last_cb == CB_IS_IDLE);
+	/* MS is gone now: */
+	OSMO_ASSERT(bts_get_ms_by_tlli(bts, tlli, GSM_RESERVED_TMSI) == NULL);
 
-	last_cb = CB_UNKNOWN;
-	talloc_free(ms);
 	talloc_free(dl_tbf);
 	talloc_free(ul_tbf);
 	talloc_free(bts);
@@ -651,7 +540,6 @@
 	osmo_tdef_set(the_pcu->T_defs, -2030, 0, OSMO_TDEF_S);
 
 	test_ms_state();
-	test_ms_callback();
 	test_ms_replace_tbf();
 	test_ms_change_tlli();
 	test_ms_storage();
diff --git a/tests/ms/MsTest.err b/tests/ms/MsTest.err
index 247e8bb..0cc351b 100644
--- a/tests/ms/MsTest.err
+++ b/tests/ms/MsTest.err
@@ -1,39 +1,22 @@
 Creating MS object
 Modifying MS object, UL TLLI: 0xffffffff -> 0xffeeddbb, not yet confirmed
 MS(TLLI-0xffeeddbb:TA-220:MSCLS-0-0) Attaching UL TBF: TBF(UL:STATE-NEW:GPRS:TLLI-0xffeeddbb)
-MS(TLLI-0xffeeddbb:TA-220:MSCLS-0-0): + ms_attach_ul_tbf: now used by 1 (ms_attach_ul_tbf)
-MS(TLLI-0xffeeddbb:TA-220:MSCLS-0-0:UL): - ms_attach_ul_tbf: now used by 0 (-)
+MS(TLLI-0xffeeddbb:TA-220:MSCLS-0-0:UL): + tbf: now used by 1 (tbf)
 MS(TLLI-0xffeeddbb:TA-220:MSCLS-0-0:UL) Attaching DL TBF: TBF(DL:STATE-NEW:GPRS:TLLI-0xffeeddbb)
-MS(TLLI-0xffeeddbb:TA-220:MSCLS-0-0:UL): + ms_attach_dl_tbf: now used by 1 (ms_attach_dl_tbf)
-MS(TLLI-0xffeeddbb:TA-220:MSCLS-0-0:UL:DL): - ms_attach_dl_tbf: now used by 0 (-)
 MS(TLLI-0xffeeddbb:TA-220:MSCLS-0-0:UL:DL) Detaching TBF: TBF(UL:STATE-NEW:GPRS:TLLI-0xffeeddbb)
 MS(TLLI-0xffeeddbb:TA-220:MSCLS-0-0:DL) Detaching TBF: TBF(DL:STATE-NEW:GPRS:TLLI-0xffeeddbb)
-MS(TLLI-0xffeeddbb:TA-220:MSCLS-0-0) Destroying MS object
-Creating MS object
-Modifying MS object, UL TLLI: 0xffffffff -> 0xffeeddbb, not yet confirmed
-MS(TLLI-0xffeeddbb:TA-220:MSCLS-0-0) Attaching UL TBF: TBF(UL:STATE-NEW:GPRS:TLLI-0xffeeddbb)
-MS(TLLI-0xffeeddbb:TA-220:MSCLS-0-0): + ms_attach_ul_tbf: now used by 1 (ms_attach_ul_tbf)
-MS(TLLI-0xffeeddbb:TA-220:MSCLS-0-0:UL): - ms_attach_ul_tbf: now used by 0 (-)
-MS(TLLI-0xffeeddbb:TA-220:MSCLS-0-0:UL) Attaching DL TBF: TBF(DL:STATE-NEW:GPRS:TLLI-0xffeeddbb)
-MS(TLLI-0xffeeddbb:TA-220:MSCLS-0-0:UL): + ms_attach_dl_tbf: now used by 1 (ms_attach_dl_tbf)
-MS(TLLI-0xffeeddbb:TA-220:MSCLS-0-0:UL:DL): - ms_attach_dl_tbf: now used by 0 (-)
-MS(TLLI-0xffeeddbb:TA-220:MSCLS-0-0:UL:DL) Detaching TBF: TBF(UL:STATE-NEW:GPRS:TLLI-0xffeeddbb)
-MS(TLLI-0xffeeddbb:TA-220:MSCLS-0-0:DL) Detaching TBF: TBF(DL:STATE-NEW:GPRS:TLLI-0xffeeddbb)
+MS(TLLI-0xffeeddbb:TA-220:MSCLS-0-0): - tbf: now used by 0 (-)
 MS(TLLI-0xffeeddbb:TA-220:MSCLS-0-0) Destroying MS object
 Creating MS object
 The MS object cannot fully confirm an unexpected TLLI: 0xffeeddbb, partly confirmed
 MS(TLLI-0xffeeddbb:TA-220:MSCLS-0-0) Attaching DL TBF: TBF(DL:STATE-NEW:GPRS:TLLI-0xffeeddbb)
-MS(TLLI-0xffeeddbb:TA-220:MSCLS-0-0): + ms_attach_dl_tbf: now used by 1 (ms_attach_dl_tbf)
-MS(TLLI-0xffeeddbb:TA-220:MSCLS-0-0:DL): - ms_attach_dl_tbf: now used by 0 (-)
+MS(TLLI-0xffeeddbb:TA-220:MSCLS-0-0:DL): + tbf: now used by 1 (tbf)
 MS(TLLI-0xffeeddbb:TA-220:MSCLS-0-0:DL) Attaching DL TBF: TBF(DL:STATE-NEW:GPRS:TLLI-0xffeeddbb)
-MS(TLLI-0xffeeddbb:TA-220:MSCLS-0-0:DL): + ms_attach_dl_tbf: now used by 1 (ms_attach_dl_tbf)
-MS(TLLI-0xffeeddbb:TA-220:MSCLS-0-0:DL): - ms_attach_dl_tbf: now used by 0 (-)
 MS(TLLI-0xffeeddbb:TA-220:MSCLS-0-0:DL) Attaching UL TBF: TBF(UL:STATE-NEW:GPRS:TLLI-0xffeeddbb)
-MS(TLLI-0xffeeddbb:TA-220:MSCLS-0-0:DL): + ms_attach_ul_tbf: now used by 1 (ms_attach_ul_tbf)
-MS(TLLI-0xffeeddbb:TA-220:MSCLS-0-0:UL:DL): - ms_attach_ul_tbf: now used by 0 (-)
 MS(TLLI-0xffeeddbb:TA-220:MSCLS-0-0:UL:DL) Detaching TBF: TBF(UL:STATE-NEW:GPRS:TLLI-0xffeeddbb)
 MS(TLLI-0xffeeddbb:TA-220:MSCLS-0-0:DL) Detaching TBF: TBF(DL:STATE-NEW:GPRS:TLLI-0xffeeddbb)
 MS(TLLI-0xffeeddbb:TA-220:MSCLS-0-0:DL) Detaching TBF: TBF(DL:STATE-NEW:GPRS:TLLI-0xffeeddbb)
+MS(TLLI-0xffeeddbb:TA-220:MSCLS-0-0): - tbf: now used by 0 (-)
 MS(TLLI-0xffeeddbb:TA-220:MSCLS-0-0) Destroying MS object
 Creating MS object
 Modifying MS object, UL TLLI: 0xffffffff -> 0xff001111, not yet confirmed
@@ -59,43 +42,39 @@
 Modifying MS object, UL TLLI: 0xffffffff -> 0xffeeddbc, not yet confirmed
 Modifying MS object, TLLI = 0xffeeddbc, IMSI '' -> '001001987654322'
 MS(IMSI-001001987654321:TLLI-0xffeeddbb:TA-220:MSCLS-0-0) Attaching UL TBF: TBF(UL:STATE-NEW:GPRS:IMSI-001001987654321:TLLI-0xffeeddbb)
-MS(IMSI-001001987654321:TLLI-0xffeeddbb:TA-220:MSCLS-0-0): + ms_attach_ul_tbf: now used by 1 (ms_attach_ul_tbf)
-MS(IMSI-001001987654321:TLLI-0xffeeddbb:TA-220:MSCLS-0-0:UL): - ms_attach_ul_tbf: now used by 0 (-)
+MS(IMSI-001001987654321:TLLI-0xffeeddbb:TA-220:MSCLS-0-0:UL): + tbf: now used by 1 (tbf)
 MS(IMSI-001001987654321:TLLI-0xffeeddbb:TA-220:MSCLS-0-0:UL) Detaching TBF: TBF(UL:STATE-NEW:GPRS:IMSI-001001987654321:TLLI-0xffeeddbb)
+MS(IMSI-001001987654321:TLLI-0xffeeddbb:TA-220:MSCLS-0-0): - tbf: now used by 0 (-)
 MS(IMSI-001001987654321:TLLI-0xffeeddbb:TA-220:MSCLS-0-0) Destroying MS object
 MS(IMSI-001001987654322:TLLI-0xffeeddbc:TA-220:MSCLS-0-0) Attaching UL TBF: TBF(UL:STATE-NEW:GPRS:IMSI-001001987654322:TLLI-0xffeeddbc)
-MS(IMSI-001001987654322:TLLI-0xffeeddbc:TA-220:MSCLS-0-0): + ms_attach_ul_tbf: now used by 1 (ms_attach_ul_tbf)
-MS(IMSI-001001987654322:TLLI-0xffeeddbc:TA-220:MSCLS-0-0:UL): - ms_attach_ul_tbf: now used by 0 (-)
+MS(IMSI-001001987654322:TLLI-0xffeeddbc:TA-220:MSCLS-0-0:UL): + tbf: now used by 1 (tbf)
 MS(IMSI-001001987654322:TLLI-0xffeeddbc:TA-220:MSCLS-0-0:UL) Detaching TBF: TBF(UL:STATE-NEW:GPRS:IMSI-001001987654322:TLLI-0xffeeddbc)
+MS(IMSI-001001987654322:TLLI-0xffeeddbc:TA-220:MSCLS-0-0): - tbf: now used by 0 (-)
 MS(IMSI-001001987654322:TLLI-0xffeeddbc:TA-220:MSCLS-0-0) Destroying MS object
 Creating MS object
 Modifying MS object, UL TLLI: 0xffffffff -> 0xffeeddbb, not yet confirmed
 MS(TLLI-0xffeeddbb:TA-220:MSCLS-0-0) Attaching UL TBF: TBF(UL:STATE-NEW:GPRS:TLLI-0xffeeddbb)
-MS(TLLI-0xffeeddbb:TA-220:MSCLS-0-0): + ms_attach_ul_tbf: now used by 1 (ms_attach_ul_tbf)
-MS(TLLI-0xffeeddbb:TA-220:MSCLS-0-0:UL): - ms_attach_ul_tbf: now used by 0 (-)
+MS(TLLI-0xffeeddbb:TA-220:MSCLS-0-0:UL): + tbf: now used by 1 (tbf)
 MS(TLLI-0xffeeddbb:TA-220:MSCLS-0-0:UL) Attaching DL TBF: TBF(DL:STATE-NEW:GPRS:TLLI-0xffeeddbb)
-MS(TLLI-0xffeeddbb:TA-220:MSCLS-0-0:UL): + ms_attach_dl_tbf: now used by 1 (ms_attach_dl_tbf)
-MS(TLLI-0xffeeddbb:TA-220:MSCLS-0-0:UL:DL): - ms_attach_dl_tbf: now used by 0 (-)
 MS(TLLI-0xffeeddbb:TA-220:MSCLS-0-0:UL:DL) Detaching TBF: TBF(UL:STATE-NEW:GPRS:TLLI-0xffeeddbb)
 MS(TLLI-0xffeeddbb:TA-220:MSCLS-0-0:DL) Detaching TBF: TBF(DL:STATE-NEW:GPRS:TLLI-0xffeeddbb)
-MS(TLLI-0xffeeddbb:TA-220:MSCLS-0-0): + release_timer: now used by 1 (release_timer)
+MS(TLLI-0xffeeddbb:TA-220:MSCLS-0-0): - tbf: now used by 0 (-)
 MS(TLLI-0xffeeddbb:TA-220:MSCLS-0-0) Release timer expired
-MS(TLLI-0xffeeddbb:TA-220:MSCLS-0-0): - release_timer: now used by 0 (-)
 MS(TLLI-0xffeeddbb:TA-220:MSCLS-0-0) Destroying MS object
 Creating MS object
 The MS object cannot fully confirm an unexpected TLLI: 0xffeeddbb, partly confirmed
 MS(TLLI-0xffeeddbb:TA-220:MSCLS-0-0) Attaching DL TBF: TBF(DL:STATE-NEW:GPRS:TLLI-0xffeeddbb)
-MS(TLLI-0xffeeddbb:TA-220:MSCLS-0-0): + ms_attach_dl_tbf: now used by 1 (ms_attach_dl_tbf)
-MS(TLLI-0xffeeddbb:TA-220:MSCLS-0-0:DL): - ms_attach_dl_tbf: now used by 0 (-)
+MS(TLLI-0xffeeddbb:TA-220:MSCLS-0-0:DL): + tbf: now used by 1 (tbf)
 MS(TLLI-0xffeeddbb:TA-220:MSCLS-0-0:DL) Destroying MS object
 MS(TLLI-0xffeeddbb:TA-220:MSCLS-0-0:DL) Detaching TBF: TBF(DL:STATE-NEW:GPRS:TLLI-0xffeeddbb)
+MS(TLLI-0xffeeddbb:TA-220:MSCLS-0-0): - tbf: now used by 0 (-)
 Creating MS object
 The MS object cannot fully confirm an unexpected TLLI: 0xdeadbeef, partly confirmed
 Creating MS object
 The MS object cannot fully confirm an unexpected TLLI: 0xdeadbef0, partly confirmed
 MS(TLLI-0xdeadbef0:TA-220:MSCLS-0-0) Attaching DL TBF: TBF(DL:STATE-NEW:GPRS:TLLI-0xdeadbef0)
-MS(TLLI-0xdeadbef0:TA-220:MSCLS-0-0): + ms_attach_dl_tbf: now used by 1 (ms_attach_dl_tbf)
-MS(TLLI-0xdeadbef0:TA-220:MSCLS-0-0:DL): - ms_attach_dl_tbf: now used by 0 (-)
+MS(TLLI-0xdeadbef0:TA-220:MSCLS-0-0:DL): + tbf: now used by 1 (tbf)
 MS(TLLI-0xdeadbeef:TA-220:MSCLS-0-0) Destroying MS object
 MS(TLLI-0xdeadbef0:TA-220:MSCLS-0-0:DL) Destroying MS object
 MS(TLLI-0xdeadbef0:TA-220:MSCLS-0-0:DL) Detaching TBF: TBF(DL:STATE-NEW:GPRS:TLLI-0xdeadbef0)
+MS(TLLI-0xdeadbef0:TA-220:MSCLS-0-0): - tbf: now used by 0 (-)
diff --git a/tests/ms/MsTest.ok b/tests/ms/MsTest.ok
index 98e345c..331bef0 100644
--- a/tests/ms/MsTest.ok
+++ b/tests/ms/MsTest.ok
@@ -1,20 +1,12 @@
 === start test_ms_state ===
 === end test_ms_state ===
-=== start test_ms_callback ===
-  ms_active() was called
-  ms_idle() was called
-=== end test_ms_callback ===
 === start test_ms_replace_tbf ===
-  ms_active() was called
-  ms_idle() was called
 === end test_ms_replace_tbf ===
 === start test_ms_change_tlli ===
 === end test_ms_change_tlli ===
 === start test_ms_storage ===
 === end test_ms_storage ===
 === start test_ms_timeout ===
-  ms_active() was called
-  ms_idle() was called
 === end test_ms_timeout ===
 === start test_ms_cs_selection ===
 === end test_ms_cs_selection ===