libmsc/gsm_04_11.c: refactor MT SMS message handling

According to GSM TS 04.11, the SMC (Short Message Control) state
machine is a part of CM-sublayer of L3, that is responsible for
connection management (establisment and releasing), and SM-RP
(Relay Protocol) message delivery.

For some reason, the connection establisment request from SMC
(GSM411_MMSMS_EST_REQ) was not handled properly - it was
always assumed that connection is already established.

This is why the code initiating a MT (Mobile Terminated) SMS
transfer had to establish a radio connection with subscriber
manually.

Let's benefit from having the SMC state machine, and offload
connection establishment to it. This change makes the local
implementation closer to GSM TS 04.11, and facilitates the
further integration of GSUP transport.

NOTE: the expected unit test output is changed, because now we
always allocate a transaction first, and then establish a
connection, not vice versa.

Change-Id: I4a07ece80d8dd40b23da6bb1ffc9d3d745b54092

12 files changed, 337 insertions, 291 deletions

diff --git a/include/osmocom/msc/gsm_04_11.h b/include/osmocom/msc/gsm_04_11.h
index 0b9639fcc..a368d4662 100644
--- a/include/osmocom/msc/gsm_04_11.h
+++ b/include/osmocom/msc/gsm_04_11.h
@@ -27,6 +27,7 @@ struct sms_deliver {
 	uint8_t *smsc;
 };
 
+struct gsm_network;
 struct msgb;
 
 int gsm0411_rcv_sms(struct gsm_subscriber_connection *conn, struct msgb *msg);
@@ -37,9 +38,8 @@ struct gsm_sms *sms_from_text(struct vlr_subscr *receiver,
 			      const char *sender_msisdn,
 			      int dcs, const char *text);
 
-int gsm411_send_sms_subscr(struct vlr_subscr *vsub,
-			   struct gsm_sms *sms);
-int gsm411_send_sms(struct gsm_subscriber_connection *conn,
+int gsm411_send_sms(struct gsm_network *net,
+		    struct vlr_subscr *vsub,
 		    struct gsm_sms *sms);
 void gsm411_sapi_n_reject(struct gsm_subscriber_connection *conn);
 
diff --git a/src/libmsc/gsm_04_11.c b/src/libmsc/gsm_04_11.c
index 14f9f57e5..88dc43337 100644
--- a/src/libmsc/gsm_04_11.c
+++ b/src/libmsc/gsm_04_11.c
@@ -127,6 +127,87 @@ static int gsm411_sendmsg(struct gsm_subscriber_connection *conn, struct msgb *m
 	return msc_tx_dtap(conn, msg);
 }
 
+/* Paging callback for MT SMS (Paging is triggered by SMC) */
+static int paging_cb_mmsms_est_req(unsigned int hooknum, unsigned int event,
+				   struct msgb *msg, void *_conn, void *_trans)
+{
+	struct gsm_subscriber_connection *conn = _conn;
+	struct gsm_trans *trans = _trans;
+	struct gsm_sms *sms = trans->sms.sms;
+	int rc = 0;
+
+	DEBUGP(DLSMS, "paging_cb_mmsms_est_req(hooknum=%u, event=%u, "
+		"conn=%p, trans=%p)\n", hooknum, event, conn, trans);
+
+	if (hooknum != GSM_HOOK_RR_PAGING)
+		return -EINVAL;
+
+	/* Paging procedure has finished */
+	trans->paging_request = NULL;
+
+	switch (event) {
+	case GSM_PAGING_SUCCEEDED:
+		/* Associate transaction with established connection */
+		trans->conn = msc_subscr_conn_get(conn, MSC_CONN_USE_TRANS_SMS);
+		/* FIXME: specify SACCH in case we already have active TCH */
+		trans->dlci = 0x03;
+		/* Confirm successful connection establishment */
+		gsm411_smc_recv(&trans->sms.smc_inst,
+			GSM411_MMSMS_EST_CNF, NULL, 0);
+		break;
+	case GSM_PAGING_EXPIRED:
+	case GSM_PAGING_BUSY:
+		/* Inform SMC about channel establishment failure */
+		gsm411_smc_recv(&trans->sms.smc_inst,
+			GSM411_MMSMS_REL_IND, NULL, 0);
+
+		/* Notify the SMSqueue and free stored SMS */
+		send_signal(S_SMS_UNKNOWN_ERROR, NULL, sms, event);
+		trans->sms.sms = NULL;
+		sms_free(sms);
+
+		/* Destroy this transaction */
+		trans_free(trans);
+		rc = -ETIMEDOUT;
+		break;
+	default:
+		LOGP(DLSMS, LOGL_ERROR, "Unhandled paging event: %d\n", event);
+	}
+
+	return rc;
+}
+
+static int gsm411_mmsms_est_req(struct gsm_trans *trans)
+{
+	/* Subscriber's data shall be associated */
+	OSMO_ASSERT(trans->vsub != NULL);
+
+	/* Check if connection is already established */
+	if (trans->conn != NULL) {
+		LOGP(DLSMS, LOGL_DEBUG, "Using an existing connection "
+			"for %s\n", vlr_subscr_name(trans->vsub));
+		return gsm411_smc_recv(&trans->sms.smc_inst,
+			GSM411_MMSMS_EST_CNF, NULL, 0);
+	}
+
+	/* Initiate Paging procedure */
+	LOGP(DLSMS, LOGL_DEBUG, "Initiating Paging procedure "
+		"for %s due to MMSMS_EST_REQ\n", vlr_subscr_name(trans->vsub));
+	trans->paging_request = subscr_request_conn(trans->vsub,
+		paging_cb_mmsms_est_req, trans, "MT SMS");
+	if (!trans->paging_request) {
+		LOGP(DLSMS, LOGL_ERROR, "Failed to initiate Paging "
+			"procedure for %s\n", vlr_subscr_name(trans->vsub));
+		/* Inform SMC about channel establishment failure */
+		gsm411_smc_recv(&trans->sms.smc_inst,
+			GSM411_MMSMS_REL_IND, NULL, 0);
+		trans_free(trans);
+		return -EIO;
+	}
+
+	return 0;
+}
+
 /* Prefix msg with a 04.08/04.11 CP header */
 static int gsm411_cp_sendmsg(struct msgb *msg, struct gsm_trans *trans,
 			     uint8_t msg_type)
@@ -154,8 +235,7 @@ static int gsm411_mm_send(struct gsm411_smc_inst *inst, int msg_type,
 
 	switch (msg_type) {
 	case GSM411_MMSMS_EST_REQ:
-		/* recycle msg */
-		rc = gsm411_smc_recv(inst, GSM411_MMSMS_EST_CNF, msg, 0);
+		rc = gsm411_mmsms_est_req(trans);
 		msgb_free(msg); /* upper layer does not free msg */
 		break;
 	case GSM411_MMSMS_DATA_REQ:
@@ -899,6 +979,120 @@ static int gsm411_mn_recv(struct gsm411_smc_inst *inst, int msg_type,
 	return rc;
 }
 
+static struct gsm_trans *gsm411_alloc_mt_trans(struct gsm_network *net,
+					       struct vlr_subscr *vsub)
+{
+	struct gsm_subscriber_connection *conn;
+	struct gsm_trans *trans;
+	int tid;
+
+	LOGP(DLSMS, LOGL_INFO, "Going to send a MT SMS\n");
+
+	/* Generate a new transaction ID */
+	tid = trans_assign_trans_id(net, vsub, GSM48_PDISC_SMS, 0);
+	if (tid == -1) {
+		LOGP(DLSMS, LOGL_ERROR, "No available transaction IDs\n");
+		return NULL;
+	}
+
+	/* Allocate a new transaction */
+	trans = trans_alloc(net, vsub, GSM48_PDISC_SMS, tid, new_callref++);
+	if (!trans) {
+		LOGP(DLSMS, LOGL_ERROR, "No memory for trans\n");
+		return NULL;
+	}
+
+	/* Init both SMC and SMR state machines */
+	gsm411_smc_init(&trans->sms.smc_inst, 0, 1,
+		gsm411_mn_recv, gsm411_mm_send);
+	gsm411_smr_init(&trans->sms.smr_inst, 0, 1,
+		gsm411_rl_recv, gsm411_mn_send);
+
+	/* Attempt to find an existing connection */
+	conn = connection_for_subscr(vsub);
+	if (conn) {
+		/* Associate transaction with connection */
+		trans->conn = msc_subscr_conn_get(conn, MSC_CONN_USE_TRANS_SMS);
+		/* Generate unique RP Message Reference */
+		trans->sms.sm_rp_mr = conn->next_rp_ref++;
+	}
+
+	return trans;
+}
+
+/* High-level function to send an SMS to a given subscriber */
+int gsm411_send_sms(struct gsm_network *net,
+		    struct vlr_subscr *vsub,
+		    struct gsm_sms *sms)
+{
+	uint8_t *data, *rp_ud_len;
+	struct gsm_trans *trans;
+	struct msgb *msg;
+	int rc;
+
+	/* Allocate a new transaction for MT SMS */
+	trans = gsm411_alloc_mt_trans(net, vsub);
+	if (!trans) {
+		send_signal(S_SMS_UNKNOWN_ERROR, NULL, sms, 0);
+		sms_free(sms);
+		return -ENOMEM;
+	}
+
+	/* Allocate a message buffer for to be encoded SMS */
+	msg = gsm411_msgb_alloc();
+	if (!msg) {
+		send_signal(S_SMS_UNKNOWN_ERROR, NULL, sms, 0);
+		trans_free(trans);
+		sms_free(sms);
+		return -ENOMEM;
+	}
+
+	/* Hardcode SMSC Originating Address for now */
+	data = (uint8_t *)msgb_put(msg, 8);
+	data[0] = 0x07;	/* originator length == 7 */
+	data[1] = 0x91; /* type of number: international, ISDN */
+	data[2] = 0x44; /* 447785016005 */
+	data[3] = 0x77;
+	data[4] = 0x58;
+	data[5] = 0x10;
+	data[6] = 0x06;
+	data[7] = 0x50;
+
+	/* Hardcoded Destination Address */
+	data = (uint8_t *)msgb_put(msg, 1);
+	data[0] = 0;	/* destination length == 0 */
+
+	/* obtain a pointer for the rp_ud_len, so we can fill it later */
+	rp_ud_len = (uint8_t *)msgb_put(msg, 1);
+
+	if (sms->is_report) {
+		/* generate the 03.40 SMS-STATUS-REPORT TPDU */
+		rc = gsm340_gen_sms_status_report_tpdu(msg, sms);
+	} else {
+		/* generate the 03.40 SMS-DELIVER TPDU */
+		rc = gsm340_gen_sms_deliver_tpdu(msg, sms);
+	}
+	if (rc < 0) {
+		send_signal(S_SMS_UNKNOWN_ERROR, trans, sms, 0);
+		sms_free(sms);
+		trans_free(trans);
+		msgb_free(msg);
+		return rc;
+	}
+
+	*rp_ud_len = rc;
+
+	/* Store a pointer to abstract SMS representation */
+	trans->sms.sms = sms;
+
+	rate_ctr_inc(&net->msc_ctrs->ctr[MSC_CTR_SMS_DELIVERED]);
+	db_sms_inc_deliver_attempts(trans->sms.sms);
+
+	return gsm411_rp_sendmsg(&trans->sms.smr_inst, msg,
+		GSM411_MT_RP_DATA_MT, trans->sms.sm_rp_mr,
+		GSM411_SM_RL_DATA_REQ);
+}
+
 /* Entry point for incoming GSM48_PDISC_SMS from abis_rsl.c */
 int gsm0411_rcv_sms(struct gsm_subscriber_connection *conn,
 		    struct msgb *msg)
@@ -985,159 +1179,6 @@ int gsm0411_rcv_sms(struct gsm_subscriber_connection *conn,
 	return rc;
 }
 
-/* Take a SMS in gsm_sms structure and send it through an already
- * existing conn. We also assume that the caller ensured this conn already
- * has a SAPI3 RLL connection! */
-int gsm411_send_sms(struct gsm_subscriber_connection *conn, struct gsm_sms *sms)
-{
-	struct msgb *msg = gsm411_msgb_alloc();
-	struct gsm_trans *trans;
-	uint8_t *data, *rp_ud_len;
-	uint8_t msg_ref = conn->next_rp_ref++;
-	int transaction_id;
-	int rc;
-
-	transaction_id =
-		trans_assign_trans_id(conn->network, conn->vsub,
-				      GSM48_PDISC_SMS, 0);
-	if (transaction_id == -1) {
-		LOGP(DLSMS, LOGL_ERROR, "No available transaction ids\n");
-		send_signal(S_SMS_UNKNOWN_ERROR, NULL, sms, 0);
-		sms_free(sms);
-		msgb_free(msg);
-		return -EBUSY;
-	}
-
-	DEBUGP(DLSMS, "%s()\n", __func__);
-
-	/* FIXME: allocate transaction with message reference */
-	trans = trans_alloc(conn->network, conn->vsub,
-			    GSM48_PDISC_SMS,
-			    transaction_id, new_callref++);
-	if (!trans) {
-		LOGP(DLSMS, LOGL_ERROR, "No memory for trans\n");
-		send_signal(S_SMS_UNKNOWN_ERROR, NULL, sms, 0);
-		sms_free(sms);
-		msgb_free(msg);
-		/* FIXME: send some error message */
-		return -ENOMEM;
-	}
-	gsm411_smc_init(&trans->sms.smc_inst, sms->id, 1,
-		gsm411_mn_recv, gsm411_mm_send);
-	gsm411_smr_init(&trans->sms.smr_inst, sms->id, 1,
-		gsm411_rl_recv, gsm411_mn_send);
-	trans->sms.sms = sms;
-
-	trans->conn = msc_subscr_conn_get(conn, MSC_CONN_USE_TRANS_SMS);
-	trans->dlci = 0x03;
-	/* FIXME: specify SACCH in case we already have active TCH */
-
-	/* Hardcode SMSC Originating Address for now */
-	data = (uint8_t *)msgb_put(msg, 8);
-	data[0] = 0x07;	/* originator length == 7 */
-	data[1] = 0x91; /* type of number: international, ISDN */
-	data[2] = 0x44; /* 447785016005 */
-	data[3] = 0x77;
-	data[4] = 0x58;
-	data[5] = 0x10;
-	data[6] = 0x06;
-	data[7] = 0x50;
-
-	/* Hardcoded Destination Address */
-	data = (uint8_t *)msgb_put(msg, 1);
-	data[0] = 0;	/* destination length == 0 */
-
-	/* obtain a pointer for the rp_ud_len, so we can fill it later */
-	rp_ud_len = (uint8_t *)msgb_put(msg, 1);
-
-	if (sms->is_report) {
-		/* generate the 03.40 SMS-STATUS-REPORT TPDU */
-		rc = gsm340_gen_sms_status_report_tpdu(msg, sms);
-	} else {
-		/* generate the 03.40 SMS-DELIVER TPDU */
-		rc = gsm340_gen_sms_deliver_tpdu(msg, sms);
-	}
-	if (rc < 0) {
-		send_signal(S_SMS_UNKNOWN_ERROR, trans, sms, 0);
-		sms_free(sms);
-		trans->sms.sms = NULL;
-		trans_free(trans);
-		msgb_free(msg);
-		return rc;
-	}
-
-	*rp_ud_len = rc;
-
-	DEBUGP(DLSMS, "TX: SMS DELIVER\n");
-
-	rate_ctr_inc(&conn->network->msc_ctrs->ctr[MSC_CTR_SMS_DELIVERED]);
-	db_sms_inc_deliver_attempts(trans->sms.sms);
-
-	return gsm411_rp_sendmsg(&trans->sms.smr_inst, msg,
-		GSM411_MT_RP_DATA_MT, msg_ref, GSM411_SM_RL_DATA_REQ);
-}
-
-/* paging callback. Here we get called if paging a subscriber has
- * succeeded or failed. */
-static int paging_cb_send_sms(unsigned int hooknum, unsigned int event,
-			      struct msgb *msg, void *_conn, void *_sms)
-{
-	struct gsm_subscriber_connection *conn = _conn;
-	struct gsm_sms *sms = _sms;
-	int rc = 0;
-
-	DEBUGP(DLSMS, "paging_cb_send_sms(hooknum=%u, event=%u, msg=%p,"
-		"conn=%p, sms=%p/id: %llu)\n", hooknum, event, msg, conn, sms, sms->id);
-
-	if (hooknum != GSM_HOOK_RR_PAGING)
-		return -EINVAL;
-
-	switch (event) {
-	case GSM_PAGING_SUCCEEDED:
-		gsm411_send_sms(conn, sms);
-		break;
-	case GSM_PAGING_EXPIRED:
-	case GSM_PAGING_BUSY:
-		send_signal(S_SMS_UNKNOWN_ERROR, NULL, sms, event);
-		sms_free(sms);
-		rc = -ETIMEDOUT;
-		break;
-	default:
-		LOGP(DLSMS, LOGL_ERROR, "Unhandled paging event: %d\n", event);
-	}
-
-	return rc;
-}
-
-/* high-level function to send a SMS to a given subscriber. The function
- * will take care of paging the subscriber, establishing the RLL SAPI3
- * connection, etc. */
-int gsm411_send_sms_subscr(struct vlr_subscr *vsub,
-			   struct gsm_sms *sms)
-{
-	struct gsm_subscriber_connection *conn;
-	void *res;
-
-	/* check if we already have an open conn to the subscriber.
-	 * if yes, send the SMS this way */
-	conn = connection_for_subscr(vsub);
-	if (conn) {
-		LOGP(DLSMS, LOGL_DEBUG, "Sending SMS via already open connection %p to %s\n",
-		     conn, vlr_subscr_name(vsub));
-		return gsm411_send_sms(conn, sms);
-	}
-
-	/* if not, we have to start paging */
-	LOGP(DLSMS, LOGL_DEBUG, "Sending SMS: no connection open, start paging %s\n",
-	     vlr_subscr_name(vsub));
-	res = subscr_request_conn(vsub, paging_cb_send_sms, sms, "send SMS");
-	if (!res) {
-		send_signal(S_SMS_UNKNOWN_ERROR, NULL, sms, GSM_PAGING_BUSY);
-		sms_free(sms);
-	}
-	return 0;
-}
-
 void _gsm411_sms_trans_free(struct gsm_trans *trans)
 {
 	/* cleanup SMS instance */
diff --git a/src/libmsc/msc_vty.c b/src/libmsc/msc_vty.c
index cdf31842b..4f3ac04c7 100644
--- a/src/libmsc/msc_vty.c
+++ b/src/libmsc/msc_vty.c
@@ -680,7 +680,7 @@ DEFUN(sms_send_pend,
 			break;
 
 		if (sms->receiver)
-			gsm411_send_sms_subscr(sms->receiver, sms);
+			gsm411_send_sms(gsmnet, sms->receiver, sms);
 
 		sms_id = sms->id + 1;
 	}
@@ -819,7 +819,7 @@ DEFUN(subscriber_send_pending_sms,
 
 	sms = db_sms_get_unsent_for_subscr(vsub, UINT_MAX);
 	if (sms)
-		gsm411_send_sms_subscr(sms->receiver, sms);
+		gsm411_send_sms(gsmnet, sms->receiver, sms);
 
 	vlr_subscr_put(vsub);
 
diff --git a/src/libmsc/smpp_openbsc.c b/src/libmsc/smpp_openbsc.c
index c12db5f3e..051372c08 100644
--- a/src/libmsc/smpp_openbsc.c
+++ b/src/libmsc/smpp_openbsc.c
@@ -268,7 +268,7 @@ int handle_smpp_submit(struct osmo_esme *esme, struct submit_sm_t *submit,
 		LOGP(DLSMS, LOGL_DEBUG, "SMPP SUBMIT-SM: Forwarding in "
 			"real time (Transaction/Forward mode)\n");
 		sms->smpp.transaction_mode = 1;
-		gsm411_send_sms_subscr(sms->receiver, sms);
+		gsm411_send_sms(net, sms->receiver, sms);
 		rc = 1; /* don't send any response yet */
 		break;
 	}
diff --git a/src/libmsc/sms_queue.c b/src/libmsc/sms_queue.c
index 252e52986..9907f4f94 100644
--- a/src/libmsc/sms_queue.c
+++ b/src/libmsc/sms_queue.c
@@ -186,7 +186,7 @@ static void sms_resend_pending(void *_data)
 			sms_queue_trigger(smsq);
 		} else {
 			pending->resend = 0;
-			gsm411_send_sms_subscr(sms->receiver, sms);
+			gsm411_send_sms(smsq->network, sms->receiver, sms);
 		}
 	}
 }
@@ -311,7 +311,7 @@ static void sms_submit_pending(void *_data)
 		attempted += 1;
 		smsq->pending += 1;
 		llist_add_tail(&pending->entry, &smsq->pending_sms);
-		gsm411_send_sms_subscr(sms->receiver, sms);
+		gsm411_send_sms(smsq->network, sms->receiver, sms);
 	} while (attempted < attempts && rounds < 1000);
 
 	LOGP(DLSMS, LOGL_DEBUG, "SMSqueue added %d messages in %d rounds\n", attempted, rounds);
@@ -349,7 +349,7 @@ static void sms_send_next(struct vlr_subscr *vsub)
 
 	smsq->pending += 1;
 	llist_add_tail(&pending->entry, &smsq->pending_sms);
-	gsm411_send_sms_subscr(sms->receiver, sms);
+	gsm411_send_sms(smsq->network, sms->receiver, sms);
 	return;
 
 no_pending_sms:
@@ -398,7 +398,6 @@ static int sub_ready_for_sm(struct gsm_network *net, struct vlr_subscr *vsub)
 {
 	struct gsm_sms *sms;
 	struct gsm_sms_pending *pending;
-	struct gsm_subscriber_connection *conn;
 
 	/*
 	 * The code used to be very clever and tried to submit
@@ -423,15 +422,12 @@ static int sub_ready_for_sm(struct gsm_network *net, struct vlr_subscr *vsub)
 		return 0;
 	}
 
-	conn = connection_for_subscr(vsub);
-	if (!conn)
-		return -1;
-
 	/* Now try to deliver any pending SMS to this sub */
 	sms = db_sms_get_unsent_for_subscr(vsub, UINT_MAX);
 	if (!sms)
 		return -1;
-	gsm411_send_sms(conn, sms);
+
+	gsm411_send_sms(net, vsub, sms);
 	return 0;
 }
 
diff --git a/tests/msc_vlr/msc_vlr_test_gsm_authen.err b/tests/msc_vlr/msc_vlr_test_gsm_authen.err
index 51f736765..fc701b2e2 100644
--- a/tests/msc_vlr/msc_vlr_test_gsm_authen.err
+++ b/tests/msc_vlr/msc_vlr_test_gsm_authen.err
@@ -275,18 +275,20 @@ DMM Subscr_Conn(CM_SERVICE_REQ:901700000004620){SUBSCR_CONN_S_RELEASED}: Dealloc
 DREF VLR subscr MSISDN:46071 usage increases to: 2
   llist_count(&vsub->cs.requests) == 0
 DREF VLR subscr MSISDN:46071 usage increases to: 3
+DCC (ti 00 sub MSISDN:46071 callref 40000001) New transaction
+DREF VLR subscr MSISDN:46071 usage increases to: 4
 DMM Subscriber MSISDN:46071 not paged yet, start paging.
   RAN_GERAN_A sends out paging request to IMSI 901700000004620, TMSI 0xffffffff, LAC 23
   strcmp(paging_expecting_imsi, imsi) == 0
-DREF VLR subscr MSISDN:46071 usage increases to: 4
+DREF VLR subscr MSISDN:46071 usage increases to: 5
   llist_count(&vsub->cs.requests) == 1
-DREF VLR subscr MSISDN:46071 usage decreases to: 3
+DREF VLR subscr MSISDN:46071 usage decreases to: 4
   paging_sent == 1
   paging_stopped == 0
 - the subscriber and its pending request should remain
-DREF VLR subscr MSISDN:46071 usage increases to: 4
+DREF VLR subscr MSISDN:46071 usage increases to: 5
   llist_count(&vsub->cs.requests) == 1
-DREF VLR subscr MSISDN:46071 usage decreases to: 3
+DREF VLR subscr MSISDN:46071 usage decreases to: 4
 - MS replies with Paging Response, and VLR sends Auth Request with third key
   MSC <--RAN_GERAN_A-- MS: GSM48_MT_RR_PAG_RESP
   new conn
@@ -299,8 +301,8 @@ DVLR Process_Access_Request_VLR(PAGING_RESP:901700000004620){PR_ARQ_S_INIT}: All
 DVLR Process_Access_Request_VLR(PAGING_RESP:901700000004620){PR_ARQ_S_INIT}: is child of Subscr_Conn(PAGING_RESP:901700000004620)
 DVLR Process_Access_Request_VLR(PAGING_RESP:901700000004620){PR_ARQ_S_INIT}: rev=GSM net=GERAN Auth (no Ciph)
 DVLR Process_Access_Request_VLR(PAGING_RESP:901700000004620){PR_ARQ_S_INIT}: Received Event PR_ARQ_E_START
-DREF VLR subscr MSISDN:46071 usage increases to: 4
 DREF VLR subscr MSISDN:46071 usage increases to: 5
+DREF VLR subscr MSISDN:46071 usage increases to: 6
 DVLR Process_Access_Request_VLR(PAGING_RESP:901700000004620){PR_ARQ_S_INIT}: proc_arq_vlr_fn_post_imsi()
 DVLR Process_Access_Request_VLR(PAGING_RESP:901700000004620){PR_ARQ_S_INIT}: state_chg to PR_ARQ_S_WAIT_AUTH
 DVLR VLR_Authenticate(PAGING_RESP:901700000004620){VLR_SUB_AS_NEEDS_AUTH}: Allocated
@@ -311,7 +313,7 @@ DVLR VLR_Authenticate(PAGING_RESP:901700000004620){VLR_SUB_AS_WAIT_RESP}: got au
 - sending GSM Auth Request for MSISDN:46071: tuple use_count=1 key_seq=2 auth_types=0x1 and...
 - ...rand=e7c03ba7cf0e2fde82b2dc4d63077d42
 - ...expecting sres=a29514ae
-DREF VLR subscr MSISDN:46071 usage decreases to: 4
+DREF VLR subscr MSISDN:46071 usage decreases to: 5
 DMM Subscr_Conn(PAGING_RESP:901700000004620){SUBSCR_CONN_S_NEW}: Received Event SUBSCR_CONN_E_COMPLETE_LAYER_3
 DMM Subscr_Conn(PAGING_RESP:901700000004620){SUBSCR_CONN_S_NEW}: state_chg to SUBSCR_CONN_S_AUTH_CIPH
 DREF MSISDN:46071: MSC conn use - compl_l3 == 0 (0x0: )
@@ -356,8 +358,6 @@ DVLR Process_Access_Request_VLR(PAGING_RESP:901700000004620){PR_ARQ_S_DONE}: Pro
 DMM Subscr_Conn(PAGING_RESP:901700000004620){SUBSCR_CONN_S_AUTH_CIPH}: Received Event SUBSCR_CONN_E_ACCEPTED
 DPAG Paging success for MSISDN:46071 (event=0)
 DPAG Calling paging cbfn.
-DCC (ti 00 sub MSISDN:46071 callref 40000001) New transaction
-DREF VLR subscr MSISDN:46071 usage increases to: 5
 DREF MSISDN:46071: MSC conn use + trans_sms == 2 (0x22: dtap,trans_sms)
 DMSC msc_tx 91 bytes to MSISDN:46071 via RAN_GERAN_A
 - DTAP --RAN_GERAN_A--> MS: SMS:0x01: 09015801000791447758100650004c0005806470f1000007101000000000445079da1e1ee7416937485e9ea7c965373d1d6683c270383b3d0ed3d36ff71c949e83c22072799e9687c5ec32a81d96afcbf4b4fb0c7ac3e9e9b7db05
@@ -762,18 +762,20 @@ DMM Subscr_Conn(CM_SERVICE_REQ:50462976){SUBSCR_CONN_S_RELEASED}: Deallocated
 DREF VLR subscr MSISDN:46071 usage increases to: 2
   llist_count(&vsub->cs.requests) == 0
 DREF VLR subscr MSISDN:46071 usage increases to: 3
+DCC (ti 00 sub MSISDN:46071 callref 40000002) New transaction
+DREF VLR subscr MSISDN:46071 usage increases to: 4
 DMM Subscriber MSISDN:46071 not paged yet, start paging.
   RAN_GERAN_A sends out paging request to IMSI 901700000004620, TMSI 0x03020100, LAC 23
   paging_expecting_tmsi == 0x03020100
-DREF VLR subscr MSISDN:46071 usage increases to: 4
+DREF VLR subscr MSISDN:46071 usage increases to: 5
   llist_count(&vsub->cs.requests) == 1
-DREF VLR subscr MSISDN:46071 usage decreases to: 3
+DREF VLR subscr MSISDN:46071 usage decreases to: 4
   paging_sent == 1
   paging_stopped == 0
 - the subscriber and its pending request should remain
-DREF VLR subscr MSISDN:46071 usage increases to: 4
+DREF VLR subscr MSISDN:46071 usage increases to: 5
   llist_count(&vsub->cs.requests) == 1
-DREF VLR subscr MSISDN:46071 usage decreases to: 3
+DREF VLR subscr MSISDN:46071 usage decreases to: 4
 - MS replies with Paging Response using TMSI, and VLR sends Auth Request with third key
   MSC <--RAN_GERAN_A-- MS: GSM48_MT_RR_PAG_RESP
   new conn
@@ -786,8 +788,8 @@ DVLR Process_Access_Request_VLR(PAGING_RESP:50462976){PR_ARQ_S_INIT}: Allocated
 DVLR Process_Access_Request_VLR(PAGING_RESP:50462976){PR_ARQ_S_INIT}: is child of Subscr_Conn(PAGING_RESP:50462976)
 DVLR Process_Access_Request_VLR(PAGING_RESP:50462976){PR_ARQ_S_INIT}: rev=GSM net=GERAN Auth (no Ciph)
 DVLR Process_Access_Request_VLR(PAGING_RESP:50462976){PR_ARQ_S_INIT}: Received Event PR_ARQ_E_START
-DREF VLR subscr MSISDN:46071 usage increases to: 4
 DREF VLR subscr MSISDN:46071 usage increases to: 5
+DREF VLR subscr MSISDN:46071 usage increases to: 6
 DVLR Process_Access_Request_VLR(PAGING_RESP:50462976){PR_ARQ_S_INIT}: proc_arq_vlr_fn_post_imsi()
 DVLR Process_Access_Request_VLR(PAGING_RESP:50462976){PR_ARQ_S_INIT}: state_chg to PR_ARQ_S_WAIT_AUTH
 DVLR VLR_Authenticate(PAGING_RESP:50462976){VLR_SUB_AS_NEEDS_AUTH}: Allocated
@@ -798,7 +800,7 @@ DVLR VLR_Authenticate(PAGING_RESP:50462976){VLR_SUB_AS_WAIT_RESP}: got auth tupl
 - sending GSM Auth Request for MSISDN:46071: tuple use_count=1 key_seq=2 auth_types=0x1 and...
 - ...rand=e7c03ba7cf0e2fde82b2dc4d63077d42
 - ...expecting sres=a29514ae
-DREF VLR subscr MSISDN:46071 usage decreases to: 4
+DREF VLR subscr MSISDN:46071 usage decreases to: 5
 DMM Subscr_Conn(PAGING_RESP:50462976){SUBSCR_CONN_S_NEW}: Received Event SUBSCR_CONN_E_COMPLETE_LAYER_3
 DMM Subscr_Conn(PAGING_RESP:50462976){SUBSCR_CONN_S_NEW}: state_chg to SUBSCR_CONN_S_AUTH_CIPH
 DREF MSISDN:46071: MSC conn use - compl_l3 == 0 (0x0: )
@@ -843,8 +845,6 @@ DVLR Process_Access_Request_VLR(PAGING_RESP:50462976){PR_ARQ_S_DONE}: Process Ac
 DMM Subscr_Conn(PAGING_RESP:50462976){SUBSCR_CONN_S_AUTH_CIPH}: Received Event SUBSCR_CONN_E_ACCEPTED
 DPAG Paging success for MSISDN:46071 (event=0)
 DPAG Calling paging cbfn.
-DCC (ti 00 sub MSISDN:46071 callref 40000002) New transaction
-DREF VLR subscr MSISDN:46071 usage increases to: 5
 DREF MSISDN:46071: MSC conn use + trans_sms == 2 (0x22: dtap,trans_sms)
 DMSC msc_tx 91 bytes to MSISDN:46071 via RAN_GERAN_A
 - DTAP --RAN_GERAN_A--> MS: SMS:0x01: 09015801000791447758100650004c0005806470f1000007101000000000445079da1e1ee7416937485e9ea7c965373d1d6683c270383b3d0ed3d36ff71c949e83c22072799e9687c5ec32a81d96afcbf4b4fb0c7ac3e9e9b7db05
@@ -1873,18 +1873,20 @@ DMM Subscr_Conn(CM_SERVICE_REQ:901700000010650){SUBSCR_CONN_S_RELEASED}: Dealloc
 DREF VLR subscr MSISDN:42342 usage increases to: 2
   llist_count(&vsub->cs.requests) == 0
 DREF VLR subscr MSISDN:42342 usage increases to: 3
+DCC (ti 00 sub MSISDN:42342 callref 40000003) New transaction
+DREF VLR subscr MSISDN:42342 usage increases to: 4
 DMM Subscriber MSISDN:42342 not paged yet, start paging.
   RAN_GERAN_A sends out paging request to IMSI 901700000010650, TMSI 0xffffffff, LAC 23
   strcmp(paging_expecting_imsi, imsi) == 0
-DREF VLR subscr MSISDN:42342 usage increases to: 4
+DREF VLR subscr MSISDN:42342 usage increases to: 5
   llist_count(&vsub->cs.requests) == 1
-DREF VLR subscr MSISDN:42342 usage decreases to: 3
+DREF VLR subscr MSISDN:42342 usage decreases to: 4
   paging_sent == 1
   paging_stopped == 0
 - the subscriber and its pending request should remain
-DREF VLR subscr MSISDN:42342 usage increases to: 4
+DREF VLR subscr MSISDN:42342 usage increases to: 5
   llist_count(&vsub->cs.requests) == 1
-DREF VLR subscr MSISDN:42342 usage decreases to: 3
+DREF VLR subscr MSISDN:42342 usage decreases to: 4
 - MS replies with Paging Response, and VLR sends Auth Request with third key
   MSC <--RAN_GERAN_A-- MS: GSM48_MT_RR_PAG_RESP
   new conn
@@ -1897,8 +1899,8 @@ DVLR Process_Access_Request_VLR(PAGING_RESP:901700000010650){PR_ARQ_S_INIT}: All
 DVLR Process_Access_Request_VLR(PAGING_RESP:901700000010650){PR_ARQ_S_INIT}: is child of Subscr_Conn(PAGING_RESP:901700000010650)
 DVLR Process_Access_Request_VLR(PAGING_RESP:901700000010650){PR_ARQ_S_INIT}: rev=GSM net=GERAN Auth (no Ciph)
 DVLR Process_Access_Request_VLR(PAGING_RESP:901700000010650){PR_ARQ_S_INIT}: Received Event PR_ARQ_E_START
-DREF VLR subscr MSISDN:42342 usage increases to: 4
 DREF VLR subscr MSISDN:42342 usage increases to: 5
+DREF VLR subscr MSISDN:42342 usage increases to: 6
 DVLR Process_Access_Request_VLR(PAGING_RESP:901700000010650){PR_ARQ_S_INIT}: proc_arq_vlr_fn_post_imsi()
 DVLR Process_Access_Request_VLR(PAGING_RESP:901700000010650){PR_ARQ_S_INIT}: state_chg to PR_ARQ_S_WAIT_AUTH
 DVLR VLR_Authenticate(PAGING_RESP:901700000010650){VLR_SUB_AS_NEEDS_AUTH}: Allocated
@@ -1909,7 +1911,7 @@ DVLR VLR_Authenticate(PAGING_RESP:901700000010650){VLR_SUB_AS_WAIT_RESP}: got au
 - sending GSM Auth Request for MSISDN:42342: tuple use_count=1 key_seq=2 auth_types=0x3 and...
 - ...rand=efa9c29a9742148d5c9070348716e1bb
 - ...expecting sres=69d5f9fb
-DREF VLR subscr MSISDN:42342 usage decreases to: 4
+DREF VLR subscr MSISDN:42342 usage decreases to: 5
 DMM Subscr_Conn(PAGING_RESP:901700000010650){SUBSCR_CONN_S_NEW}: Received Event SUBSCR_CONN_E_COMPLETE_LAYER_3
 DMM Subscr_Conn(PAGING_RESP:901700000010650){SUBSCR_CONN_S_NEW}: state_chg to SUBSCR_CONN_S_AUTH_CIPH
 DREF MSISDN:42342: MSC conn use - compl_l3 == 0 (0x0: )
@@ -1954,8 +1956,6 @@ DVLR Process_Access_Request_VLR(PAGING_RESP:901700000010650){PR_ARQ_S_DONE}: Pro
 DMM Subscr_Conn(PAGING_RESP:901700000010650){SUBSCR_CONN_S_AUTH_CIPH}: Received Event SUBSCR_CONN_E_ACCEPTED
 DPAG Paging success for MSISDN:42342 (event=0)
 DPAG Calling paging cbfn.
-DCC (ti 00 sub MSISDN:42342 callref 40000003) New transaction
-DREF VLR subscr MSISDN:42342 usage increases to: 5
 DREF MSISDN:42342: MSC conn use + trans_sms == 2 (0x22: dtap,trans_sms)
 DMSC msc_tx 91 bytes to MSISDN:42342 via RAN_GERAN_A
 - DTAP --RAN_GERAN_A--> MS: SMS:0x01: 09015801000791447758100650004c0005802443f2000007101000000000445079da1e1ee7416937485e9ea7c965373d1d6683c270383b3d0ed3d36ff71c949e83c22072799e9687c5ec32a81d96afcbf4b4fb0c7ac3e9e9b7db05
diff --git a/tests/msc_vlr/msc_vlr_test_gsm_ciph.err b/tests/msc_vlr/msc_vlr_test_gsm_ciph.err
index cc8659c87..9cc638743 100644
--- a/tests/msc_vlr/msc_vlr_test_gsm_ciph.err
+++ b/tests/msc_vlr/msc_vlr_test_gsm_ciph.err
@@ -303,18 +303,20 @@ DMM Subscr_Conn(CM_SERVICE_REQ:901700000004620){SUBSCR_CONN_S_RELEASED}: Dealloc
 DREF VLR subscr MSISDN:46071 usage increases to: 2
   llist_count(&vsub->cs.requests) == 0
 DREF VLR subscr MSISDN:46071 usage increases to: 3
+DCC (ti 00 sub MSISDN:46071 callref 40000001) New transaction
+DREF VLR subscr MSISDN:46071 usage increases to: 4
 DMM Subscriber MSISDN:46071 not paged yet, start paging.
   RAN_GERAN_A sends out paging request to IMSI 901700000004620, TMSI 0xffffffff, LAC 23
   strcmp(paging_expecting_imsi, imsi) == 0
-DREF VLR subscr MSISDN:46071 usage increases to: 4
+DREF VLR subscr MSISDN:46071 usage increases to: 5
   llist_count(&vsub->cs.requests) == 1
-DREF VLR subscr MSISDN:46071 usage decreases to: 3
+DREF VLR subscr MSISDN:46071 usage decreases to: 4
   paging_sent == 1
   paging_stopped == 0
 - the subscriber and its pending request should remain
-DREF VLR subscr MSISDN:46071 usage increases to: 4
+DREF VLR subscr MSISDN:46071 usage increases to: 5
   llist_count(&vsub->cs.requests) == 1
-DREF VLR subscr MSISDN:46071 usage decreases to: 3
+DREF VLR subscr MSISDN:46071 usage decreases to: 4
 - MS replies with Paging Response, and VLR sends Auth Request with third key
   MSC <--RAN_GERAN_A-- MS: GSM48_MT_RR_PAG_RESP
   new conn
@@ -327,8 +329,8 @@ DVLR Process_Access_Request_VLR(PAGING_RESP:901700000004620){PR_ARQ_S_INIT}: All
 DVLR Process_Access_Request_VLR(PAGING_RESP:901700000004620){PR_ARQ_S_INIT}: is child of Subscr_Conn(PAGING_RESP:901700000004620)
 DVLR Process_Access_Request_VLR(PAGING_RESP:901700000004620){PR_ARQ_S_INIT}: rev=GSM net=GERAN Auth+Ciph
 DVLR Process_Access_Request_VLR(PAGING_RESP:901700000004620){PR_ARQ_S_INIT}: Received Event PR_ARQ_E_START
-DREF VLR subscr MSISDN:46071 usage increases to: 4
 DREF VLR subscr MSISDN:46071 usage increases to: 5
+DREF VLR subscr MSISDN:46071 usage increases to: 6
 DVLR Process_Access_Request_VLR(PAGING_RESP:901700000004620){PR_ARQ_S_INIT}: proc_arq_vlr_fn_post_imsi()
 DVLR Process_Access_Request_VLR(PAGING_RESP:901700000004620){PR_ARQ_S_INIT}: state_chg to PR_ARQ_S_WAIT_AUTH
 DVLR VLR_Authenticate(PAGING_RESP:901700000004620){VLR_SUB_AS_NEEDS_AUTH}: Allocated
@@ -339,7 +341,7 @@ DVLR VLR_Authenticate(PAGING_RESP:901700000004620){VLR_SUB_AS_WAIT_RESP}: got au
 - sending GSM Auth Request for MSISDN:46071: tuple use_count=1 key_seq=2 auth_types=0x1 and...
 - ...rand=e7c03ba7cf0e2fde82b2dc4d63077d42
 - ...expecting sres=a29514ae
-DREF VLR subscr MSISDN:46071 usage decreases to: 4
+DREF VLR subscr MSISDN:46071 usage decreases to: 5
 DMM Subscr_Conn(PAGING_RESP:901700000004620){SUBSCR_CONN_S_NEW}: Received Event SUBSCR_CONN_E_COMPLETE_LAYER_3
 DMM Subscr_Conn(PAGING_RESP:901700000004620){SUBSCR_CONN_S_NEW}: state_chg to SUBSCR_CONN_S_AUTH_CIPH
 DREF MSISDN:46071: MSC conn use - compl_l3 == 0 (0x0: )
@@ -409,8 +411,6 @@ DVLR Process_Access_Request_VLR(PAGING_RESP:901700000004620){PR_ARQ_S_DONE}: Pro
 DMM Subscr_Conn(PAGING_RESP:901700000004620){SUBSCR_CONN_S_AUTH_CIPH}: Received Event SUBSCR_CONN_E_ACCEPTED
 DPAG Paging success for MSISDN:46071 (event=0)
 DPAG Calling paging cbfn.
-DCC (ti 00 sub MSISDN:46071 callref 40000001) New transaction
-DREF VLR subscr MSISDN:46071 usage increases to: 5
 DREF MSISDN:46071: MSC conn use + trans_sms == 1 (0x20: trans_sms)
 DMSC msc_tx 91 bytes to MSISDN:46071 via RAN_GERAN_A
 - DTAP --RAN_GERAN_A--> MS: SMS:0x01: 09015801000791447758100650004c0005806470f1000007101000000000445079da1e1ee7416937485e9ea7c965373d1d6683c270383b3d0ed3d36ff71c949e83c22072799e9687c5ec32a81d96afcbf4b4fb0c7ac3e9e9b7db05
@@ -843,18 +843,20 @@ DMM Subscr_Conn(CM_SERVICE_REQ:50462976){SUBSCR_CONN_S_RELEASED}: Deallocated
 DREF VLR subscr MSISDN:46071 usage increases to: 2
   llist_count(&vsub->cs.requests) == 0
 DREF VLR subscr MSISDN:46071 usage increases to: 3
+DCC (ti 00 sub MSISDN:46071 callref 40000002) New transaction
+DREF VLR subscr MSISDN:46071 usage increases to: 4
 DMM Subscriber MSISDN:46071 not paged yet, start paging.
   RAN_GERAN_A sends out paging request to IMSI 901700000004620, TMSI 0x03020100, LAC 23
   paging_expecting_tmsi == 0x03020100
-DREF VLR subscr MSISDN:46071 usage increases to: 4
+DREF VLR subscr MSISDN:46071 usage increases to: 5
   llist_count(&vsub->cs.requests) == 1
-DREF VLR subscr MSISDN:46071 usage decreases to: 3
+DREF VLR subscr MSISDN:46071 usage decreases to: 4
   paging_sent == 1
   paging_stopped == 0
 - the subscriber and its pending request should remain
-DREF VLR subscr MSISDN:46071 usage increases to: 4
+DREF VLR subscr MSISDN:46071 usage increases to: 5
   llist_count(&vsub->cs.requests) == 1
-DREF VLR subscr MSISDN:46071 usage decreases to: 3
+DREF VLR subscr MSISDN:46071 usage decreases to: 4
 - MS replies with Paging Response using TMSI, and VLR sends Auth Request with third key
   MSC <--RAN_GERAN_A-- MS: GSM48_MT_RR_PAG_RESP
   new conn
@@ -867,8 +869,8 @@ DVLR Process_Access_Request_VLR(PAGING_RESP:50462976){PR_ARQ_S_INIT}: Allocated
 DVLR Process_Access_Request_VLR(PAGING_RESP:50462976){PR_ARQ_S_INIT}: is child of Subscr_Conn(PAGING_RESP:50462976)
 DVLR Process_Access_Request_VLR(PAGING_RESP:50462976){PR_ARQ_S_INIT}: rev=GSM net=GERAN Auth+Ciph
 DVLR Process_Access_Request_VLR(PAGING_RESP:50462976){PR_ARQ_S_INIT}: Received Event PR_ARQ_E_START
-DREF VLR subscr MSISDN:46071 usage increases to: 4
 DREF VLR subscr MSISDN:46071 usage increases to: 5
+DREF VLR subscr MSISDN:46071 usage increases to: 6
 DVLR Process_Access_Request_VLR(PAGING_RESP:50462976){PR_ARQ_S_INIT}: proc_arq_vlr_fn_post_imsi()
 DVLR Process_Access_Request_VLR(PAGING_RESP:50462976){PR_ARQ_S_INIT}: state_chg to PR_ARQ_S_WAIT_AUTH
 DVLR VLR_Authenticate(PAGING_RESP:50462976){VLR_SUB_AS_NEEDS_AUTH}: Allocated
@@ -879,7 +881,7 @@ DVLR VLR_Authenticate(PAGING_RESP:50462976){VLR_SUB_AS_WAIT_RESP}: got auth tupl
 - sending GSM Auth Request for MSISDN:46071: tuple use_count=1 key_seq=2 auth_types=0x1 and...
 - ...rand=e7c03ba7cf0e2fde82b2dc4d63077d42
 - ...expecting sres=a29514ae
-DREF VLR subscr MSISDN:46071 usage decreases to: 4
+DREF VLR subscr MSISDN:46071 usage decreases to: 5
 DMM Subscr_Conn(PAGING_RESP:50462976){SUBSCR_CONN_S_NEW}: Received Event SUBSCR_CONN_E_COMPLETE_LAYER_3
 DMM Subscr_Conn(PAGING_RESP:50462976){SUBSCR_CONN_S_NEW}: state_chg to SUBSCR_CONN_S_AUTH_CIPH
 DREF MSISDN:46071: MSC conn use - compl_l3 == 0 (0x0: )
@@ -949,8 +951,6 @@ DVLR Process_Access_Request_VLR(PAGING_RESP:50462976){PR_ARQ_S_DONE}: Process Ac
 DMM Subscr_Conn(PAGING_RESP:50462976){SUBSCR_CONN_S_AUTH_CIPH}: Received Event SUBSCR_CONN_E_ACCEPTED
 DPAG Paging success for MSISDN:46071 (event=0)
 DPAG Calling paging cbfn.
-DCC (ti 00 sub MSISDN:46071 callref 40000002) New transaction
-DREF VLR subscr MSISDN:46071 usage increases to: 5
 DREF MSISDN:46071: MSC conn use + trans_sms == 1 (0x20: trans_sms)
 DMSC msc_tx 91 bytes to MSISDN:46071 via RAN_GERAN_A
 - DTAP --RAN_GERAN_A--> MS: SMS:0x01: 09015801000791447758100650004c0005806470f1000007101000000000445079da1e1ee7416937485e9ea7c965373d1d6683c270383b3d0ed3d36ff71c949e83c22072799e9687c5ec32a81d96afcbf4b4fb0c7ac3e9e9b7db05
@@ -2069,18 +2069,20 @@ DMM Subscr_Conn(CM_SERVICE_REQ:901700000010650){SUBSCR_CONN_S_RELEASED}: Dealloc
 DREF VLR subscr MSISDN:42342 usage increases to: 2
   llist_count(&vsub->cs.requests) == 0
 DREF VLR subscr MSISDN:42342 usage increases to: 3
+DCC (ti 00 sub MSISDN:42342 callref 40000003) New transaction
+DREF VLR subscr MSISDN:42342 usage increases to: 4
 DMM Subscriber MSISDN:42342 not paged yet, start paging.
   RAN_GERAN_A sends out paging request to IMSI 901700000010650, TMSI 0xffffffff, LAC 23
   strcmp(paging_expecting_imsi, imsi) == 0
-DREF VLR subscr MSISDN:42342 usage increases to: 4
+DREF VLR subscr MSISDN:42342 usage increases to: 5
   llist_count(&vsub->cs.requests) == 1
-DREF VLR subscr MSISDN:42342 usage decreases to: 3
+DREF VLR subscr MSISDN:42342 usage decreases to: 4
   paging_sent == 1
   paging_stopped == 0
 - the subscriber and its pending request should remain
-DREF VLR subscr MSISDN:42342 usage increases to: 4
+DREF VLR subscr MSISDN:42342 usage increases to: 5
   llist_count(&vsub->cs.requests) == 1
-DREF VLR subscr MSISDN:42342 usage decreases to: 3
+DREF VLR subscr MSISDN:42342 usage decreases to: 4
 - MS replies with Paging Response, and VLR sends *UMTS AKA* Auth Request with third key
   MSC <--RAN_GERAN_A-- MS: GSM48_MT_RR_PAG_RESP
   new conn
@@ -2093,8 +2095,8 @@ DVLR Process_Access_Request_VLR(PAGING_RESP:901700000010650){PR_ARQ_S_INIT}: All
 DVLR Process_Access_Request_VLR(PAGING_RESP:901700000010650){PR_ARQ_S_INIT}: is child of Subscr_Conn(PAGING_RESP:901700000010650)
 DVLR Process_Access_Request_VLR(PAGING_RESP:901700000010650){PR_ARQ_S_INIT}: rev=R99 net=GERAN Auth+Ciph
 DVLR Process_Access_Request_VLR(PAGING_RESP:901700000010650){PR_ARQ_S_INIT}: Received Event PR_ARQ_E_START
-DREF VLR subscr MSISDN:42342 usage increases to: 4
 DREF VLR subscr MSISDN:42342 usage increases to: 5
+DREF VLR subscr MSISDN:42342 usage increases to: 6
 DVLR Process_Access_Request_VLR(PAGING_RESP:901700000010650){PR_ARQ_S_INIT}: proc_arq_vlr_fn_post_imsi()
 DVLR Process_Access_Request_VLR(PAGING_RESP:901700000010650){PR_ARQ_S_INIT}: state_chg to PR_ARQ_S_WAIT_AUTH
 DVLR VLR_Authenticate(PAGING_RESP:901700000010650){VLR_SUB_AS_NEEDS_AUTH}: Allocated
@@ -2106,7 +2108,7 @@ DVLR VLR_Authenticate(PAGING_RESP:901700000010650){VLR_SUB_AS_WAIT_RESP}: got au
 - ...rand=54d8f19778056666b41c8c25e52eb60c
 - ...autn=53f3e5632b3d00008865dd54d49663f2
 - ...expecting res=86e848a9e7ad8cd5
-DREF VLR subscr MSISDN:42342 usage decreases to: 4
+DREF VLR subscr MSISDN:42342 usage decreases to: 5
 DMM Subscr_Conn(PAGING_RESP:901700000010650){SUBSCR_CONN_S_NEW}: Received Event SUBSCR_CONN_E_COMPLETE_LAYER_3
 DMM Subscr_Conn(PAGING_RESP:901700000010650){SUBSCR_CONN_S_NEW}: state_chg to SUBSCR_CONN_S_AUTH_CIPH
 DREF MSISDN:42342: MSC conn use - compl_l3 == 0 (0x0: )
@@ -2165,8 +2167,6 @@ DVLR Process_Access_Request_VLR(PAGING_RESP:901700000010650){PR_ARQ_S_DONE}: Pro
 DMM Subscr_Conn(PAGING_RESP:901700000010650){SUBSCR_CONN_S_AUTH_CIPH}: Received Event SUBSCR_CONN_E_ACCEPTED
 DPAG Paging success for MSISDN:42342 (event=0)
 DPAG Calling paging cbfn.
-DCC (ti 00 sub MSISDN:42342 callref 40000003) New transaction
-DREF VLR subscr MSISDN:42342 usage increases to: 5
 DREF MSISDN:42342: MSC conn use + trans_sms == 1 (0x20: trans_sms)
 DMSC msc_tx 91 bytes to MSISDN:42342 via RAN_GERAN_A
 - DTAP --RAN_GERAN_A--> MS: SMS:0x01: 09015801000791447758100650004c0005802443f2000007101000000000445079da1e1ee7416937485e9ea7c965373d1d6683c270383b3d0ed3d36ff71c949e83c22072799e9687c5ec32a81d96afcbf4b4fb0c7ac3e9e9b7db05
@@ -2559,18 +2559,20 @@ DMM Subscr_Conn(CM_SERVICE_REQ:901700000004620){SUBSCR_CONN_S_RELEASED}: Dealloc
 DREF VLR subscr MSISDN:42342 usage increases to: 2
   llist_count(&vsub->cs.requests) == 0
 DREF VLR subscr MSISDN:42342 usage increases to: 3
+DCC (ti 00 sub MSISDN:42342 callref 40000004) New transaction
+DREF VLR subscr MSISDN:42342 usage increases to: 4
 DMM Subscriber MSISDN:42342 not paged yet, start paging.
   RAN_GERAN_A sends out paging request to IMSI 901700000004620, TMSI 0xffffffff, LAC 23
   strcmp(paging_expecting_imsi, imsi) == 0
-DREF VLR subscr MSISDN:42342 usage increases to: 4
+DREF VLR subscr MSISDN:42342 usage increases to: 5
   llist_count(&vsub->cs.requests) == 1
-DREF VLR subscr MSISDN:42342 usage decreases to: 3
+DREF VLR subscr MSISDN:42342 usage decreases to: 4
   paging_sent == 1
   paging_stopped == 0
 - the subscriber and its pending request should remain
-DREF VLR subscr MSISDN:42342 usage increases to: 4
+DREF VLR subscr MSISDN:42342 usage increases to: 5
   llist_count(&vsub->cs.requests) == 1
-DREF VLR subscr MSISDN:42342 usage decreases to: 3
+DREF VLR subscr MSISDN:42342 usage decreases to: 4
 - MS replies with Paging Response, and VLR sends Auth Request with third key
   MSC <--RAN_GERAN_A-- MS: GSM48_MT_RR_PAG_RESP
   new conn
@@ -2583,8 +2585,8 @@ DVLR Process_Access_Request_VLR(PAGING_RESP:901700000004620){PR_ARQ_S_INIT}: All
 DVLR Process_Access_Request_VLR(PAGING_RESP:901700000004620){PR_ARQ_S_INIT}: is child of Subscr_Conn(PAGING_RESP:901700000004620)
 DVLR Process_Access_Request_VLR(PAGING_RESP:901700000004620){PR_ARQ_S_INIT}: rev=GSM net=GERAN Auth+Ciph
 DVLR Process_Access_Request_VLR(PAGING_RESP:901700000004620){PR_ARQ_S_INIT}: Received Event PR_ARQ_E_START
-DREF VLR subscr MSISDN:42342 usage increases to: 4
 DREF VLR subscr MSISDN:42342 usage increases to: 5
+DREF VLR subscr MSISDN:42342 usage increases to: 6
 DVLR Process_Access_Request_VLR(PAGING_RESP:901700000004620){PR_ARQ_S_INIT}: proc_arq_vlr_fn_post_imsi()
 DVLR Process_Access_Request_VLR(PAGING_RESP:901700000004620){PR_ARQ_S_INIT}: state_chg to PR_ARQ_S_WAIT_AUTH
 DVLR VLR_Authenticate(PAGING_RESP:901700000004620){VLR_SUB_AS_NEEDS_AUTH}: Allocated
@@ -2595,7 +2597,7 @@ DVLR VLR_Authenticate(PAGING_RESP:901700000004620){VLR_SUB_AS_WAIT_RESP}: got au
 - sending GSM Auth Request for MSISDN:42342: tuple use_count=1 key_seq=2 auth_types=0x1 and...
 - ...rand=e7c03ba7cf0e2fde82b2dc4d63077d42
 - ...expecting sres=a29514ae
-DREF VLR subscr MSISDN:42342 usage decreases to: 4
+DREF VLR subscr MSISDN:42342 usage decreases to: 5
 DMM Subscr_Conn(PAGING_RESP:901700000004620){SUBSCR_CONN_S_NEW}: Received Event SUBSCR_CONN_E_COMPLETE_LAYER_3
 DMM Subscr_Conn(PAGING_RESP:901700000004620){SUBSCR_CONN_S_NEW}: state_chg to SUBSCR_CONN_S_AUTH_CIPH
 DREF MSISDN:42342: MSC conn use - compl_l3 == 0 (0x0: )
@@ -2665,8 +2667,6 @@ DVLR Process_Access_Request_VLR(PAGING_RESP:901700000004620){PR_ARQ_S_DONE}: Pro
 DMM Subscr_Conn(PAGING_RESP:901700000004620){SUBSCR_CONN_S_AUTH_CIPH}: Received Event SUBSCR_CONN_E_ACCEPTED
 DPAG Paging success for MSISDN:42342 (event=0)
 DPAG Calling paging cbfn.
-DCC (ti 00 sub MSISDN:42342 callref 40000004) New transaction
-DREF VLR subscr MSISDN:42342 usage increases to: 5
 DREF MSISDN:42342: MSC conn use + trans_sms == 1 (0x20: trans_sms)
 DMSC msc_tx 91 bytes to MSISDN:42342 via RAN_GERAN_A
 - DTAP --RAN_GERAN_A--> MS: SMS:0x01: 09015801000791447758100650004c0005802443f2000007101000000000445079da1e1ee7416937485e9ea7c965373d1d6683c270383b3d0ed3d36ff71c949e83c22072799e9687c5ec32a81d96afcbf4b4fb0c7ac3e9e9b7db05
@@ -3059,18 +3059,20 @@ DMM Subscr_Conn(CM_SERVICE_REQ:901700000004620){SUBSCR_CONN_S_RELEASED}: Dealloc
 DREF VLR subscr MSISDN:42342 usage increases to: 2
   llist_count(&vsub->cs.requests) == 0
 DREF VLR subscr MSISDN:42342 usage increases to: 3
+DCC (ti 00 sub MSISDN:42342 callref 40000005) New transaction
+DREF VLR subscr MSISDN:42342 usage increases to: 4
 DMM Subscriber MSISDN:42342 not paged yet, start paging.
   RAN_GERAN_A sends out paging request to IMSI 901700000004620, TMSI 0xffffffff, LAC 23
   strcmp(paging_expecting_imsi, imsi) == 0
-DREF VLR subscr MSISDN:42342 usage increases to: 4
+DREF VLR subscr MSISDN:42342 usage increases to: 5
   llist_count(&vsub->cs.requests) == 1
-DREF VLR subscr MSISDN:42342 usage decreases to: 3
+DREF VLR subscr MSISDN:42342 usage decreases to: 4
   paging_sent == 1
   paging_stopped == 0
 - the subscriber and its pending request should remain
-DREF VLR subscr MSISDN:42342 usage increases to: 4
+DREF VLR subscr MSISDN:42342 usage increases to: 5
   llist_count(&vsub->cs.requests) == 1
-DREF VLR subscr MSISDN:42342 usage decreases to: 3
+DREF VLR subscr MSISDN:42342 usage decreases to: 4
 - MS replies with Paging Response, and VLR sends Auth Request with third key
   MSC <--RAN_GERAN_A-- MS: GSM48_MT_RR_PAG_RESP
   new conn
@@ -3083,8 +3085,8 @@ DVLR Process_Access_Request_VLR(PAGING_RESP:901700000004620){PR_ARQ_S_INIT}: All
 DVLR Process_Access_Request_VLR(PAGING_RESP:901700000004620){PR_ARQ_S_INIT}: is child of Subscr_Conn(PAGING_RESP:901700000004620)
 DVLR Process_Access_Request_VLR(PAGING_RESP:901700000004620){PR_ARQ_S_INIT}: rev=GSM net=GERAN Auth+Ciph
 DVLR Process_Access_Request_VLR(PAGING_RESP:901700000004620){PR_ARQ_S_INIT}: Received Event PR_ARQ_E_START
-DREF VLR subscr MSISDN:42342 usage increases to: 4
 DREF VLR subscr MSISDN:42342 usage increases to: 5
+DREF VLR subscr MSISDN:42342 usage increases to: 6
 DVLR Process_Access_Request_VLR(PAGING_RESP:901700000004620){PR_ARQ_S_INIT}: proc_arq_vlr_fn_post_imsi()
 DVLR Process_Access_Request_VLR(PAGING_RESP:901700000004620){PR_ARQ_S_INIT}: state_chg to PR_ARQ_S_WAIT_AUTH
 DVLR VLR_Authenticate(PAGING_RESP:901700000004620){VLR_SUB_AS_NEEDS_AUTH}: Allocated
@@ -3095,7 +3097,7 @@ DVLR VLR_Authenticate(PAGING_RESP:901700000004620){VLR_SUB_AS_WAIT_RESP}: got au
 - sending GSM Auth Request for MSISDN:42342: tuple use_count=1 key_seq=2 auth_types=0x1 and...
 - ...rand=e7c03ba7cf0e2fde82b2dc4d63077d42
 - ...expecting sres=a29514ae
-DREF VLR subscr MSISDN:42342 usage decreases to: 4
+DREF VLR subscr MSISDN:42342 usage decreases to: 5
 DMM Subscr_Conn(PAGING_RESP:901700000004620){SUBSCR_CONN_S_NEW}: Received Event SUBSCR_CONN_E_COMPLETE_LAYER_3
 DMM Subscr_Conn(PAGING_RESP:901700000004620){SUBSCR_CONN_S_NEW}: state_chg to SUBSCR_CONN_S_AUTH_CIPH
 DREF MSISDN:42342: MSC conn use - compl_l3 == 0 (0x0: )
@@ -3104,8 +3106,8 @@ DMM Subscr_Conn(PAGING_RESP:901700000004620){SUBSCR_CONN_S_AUTH_CIPH}: Awaiting
   auth_request_sent == 1
 ---
 - Fake a situation where Classmark 2 is unknown during proc_arq_fsm
-DREF VLR subscr MSISDN:42342 usage increases to: 5
-DREF VLR subscr MSISDN:42342 usage decreases to: 4
+DREF VLR subscr MSISDN:42342 usage increases to: 6
+DREF VLR subscr MSISDN:42342 usage decreases to: 5
 - MS sends Authen Response, VLR accepts and requests Ciphering
 - MS sends Authen Response, VLR accepts and requests Ciphering. Normally, we'd know Classmark 3, but this test removed it. Hence a Classmark Request is generated.
   MSC <--RAN_GERAN_A-- MS: GSM48_MT_MM_AUTH_RESP
@@ -3156,8 +3158,6 @@ DVLR Process_Access_Request_VLR(PAGING_RESP:901700000004620){PR_ARQ_S_DONE}: Pro
 DMM Subscr_Conn(PAGING_RESP:901700000004620){SUBSCR_CONN_S_AUTH_CIPH}: Received Event SUBSCR_CONN_E_ACCEPTED
 DPAG Paging success for MSISDN:42342 (event=0)
 DPAG Calling paging cbfn.
-DCC (ti 00 sub MSISDN:42342 callref 40000005) New transaction
-DREF VLR subscr MSISDN:42342 usage increases to: 5
 DREF MSISDN:42342: MSC conn use + trans_sms == 1 (0x20: trans_sms)
 DMSC msc_tx 91 bytes to MSISDN:42342 via RAN_GERAN_A
 - DTAP --RAN_GERAN_A--> MS: SMS:0x01: 09015801000791447758100650004c0005802443f2000007101000000000445079da1e1ee7416937485e9ea7c965373d1d6683c270383b3d0ed3d36ff71c949e83c22072799e9687c5ec32a81d96afcbf4b4fb0c7ac3e9e9b7db05
diff --git a/tests/msc_vlr/msc_vlr_test_ms_timeout.err b/tests/msc_vlr/msc_vlr_test_ms_timeout.err
index d2b7ef393..4874f93f4 100644
--- a/tests/msc_vlr/msc_vlr_test_ms_timeout.err
+++ b/tests/msc_vlr/msc_vlr_test_ms_timeout.err
@@ -471,32 +471,38 @@ DMM Subscr_Conn(LU:901700000004620){SUBSCR_CONN_S_RELEASED}: Deallocated
 DREF VLR subscr MSISDN:46071 usage increases to: 2
   llist_count(&vsub->cs.requests) == 0
 DREF VLR subscr MSISDN:46071 usage increases to: 3
+DCC (ti 00 sub MSISDN:46071 callref 40000001) New transaction
+DREF VLR subscr MSISDN:46071 usage increases to: 4
 DMM Subscriber MSISDN:46071 not paged yet, start paging.
   RAN_GERAN_A sends out paging request to IMSI 901700000004620, TMSI 0xffffffff, LAC 23
   strcmp(paging_expecting_imsi, imsi) == 0
-DREF VLR subscr MSISDN:46071 usage increases to: 4
+DREF VLR subscr MSISDN:46071 usage increases to: 5
   llist_count(&vsub->cs.requests) == 1
-DREF VLR subscr MSISDN:46071 usage decreases to: 3
+DREF VLR subscr MSISDN:46071 usage decreases to: 4
   paging_sent == 1
   paging_stopped == 0
 - time passes and no paging result is received
 - Total time passed: 9.000000 s
 - the paging timeout has not yet expired
   paging_stopped == 0
-DREF VLR subscr MSISDN:46071 usage increases to: 4
+DREF VLR subscr MSISDN:46071 usage increases to: 5
   vsub->cs.is_paging == 1
 - another request is added to the list but does not cause another paging
-DREF VLR subscr MSISDN:46071 usage increases to: 5
+DREF VLR subscr MSISDN:46071 usage increases to: 6
+DCC (ti 01 sub MSISDN:46071 callref 40000002) New transaction
+DREF VLR subscr MSISDN:46071 usage increases to: 7
 DMM Subscriber MSISDN:46071 already paged.
   llist_count(&vsub->cs.requests) == 2
-DREF VLR subscr MSISDN:46071 usage decreases to: 4
+DREF VLR subscr MSISDN:46071 usage decreases to: 6
   paging_sent == 0
 - the paging timeout expires, the paging as well as the requests are canceled
 - Total time passed: 11.000000 s
 DPAG Paging failure for MSISDN:46071 (event=1)
 DPAG Calling paging cbfn.
-DREF VLR subscr MSISDN:46071 usage decreases to: 3
+DREF VLR subscr MSISDN:46071 usage decreases to: 5
+DREF VLR subscr MSISDN:46071 usage decreases to: 4
 DPAG Calling paging cbfn.
+DREF VLR subscr MSISDN:46071 usage decreases to: 3
 DREF VLR subscr MSISDN:46071 usage decreases to: 2
 DREF VLR subscr MSISDN:46071 usage decreases to: 1
   paging_stopped == 1
@@ -506,12 +512,14 @@ DREF VLR subscr MSISDN:46071 usage increases to: 2
 ---
 - Now that the timeout has expired, another Paging is sent on request
 DREF VLR subscr MSISDN:46071 usage increases to: 3
+DCC (ti 00 sub MSISDN:46071 callref 40000003) New transaction
+DREF VLR subscr MSISDN:46071 usage increases to: 4
 DMM Subscriber MSISDN:46071 not paged yet, start paging.
   RAN_GERAN_A sends out paging request to IMSI 901700000004620, TMSI 0xffffffff, LAC 23
   strcmp(paging_expecting_imsi, imsi) == 0
-DREF VLR subscr MSISDN:46071 usage increases to: 4
+DREF VLR subscr MSISDN:46071 usage increases to: 5
   llist_count(&vsub->cs.requests) == 1
-DREF VLR subscr MSISDN:46071 usage decreases to: 3
+DREF VLR subscr MSISDN:46071 usage decreases to: 4
   paging_sent == 1
   paging_stopped == 0
 ---
@@ -522,10 +530,11 @@ DMM Subscr_Conn{SUBSCR_CONN_S_NEW}: Allocated
 DREF unknown: MSC conn use + compl_l3 == 1 (0x1: compl_l3)
 DRLL Dispatching 04.08 message GSM48_MT_MM_IMSI_DETACH_IND (0x5:0x1)
 DMM IMSI DETACH INDICATION: MI(IMSI)=901700000004620
-DREF VLR subscr MSISDN:46071 usage increases to: 4
+DREF VLR subscr MSISDN:46071 usage increases to: 5
 DMM IMSI DETACH for MSISDN:46071
 DPAG Paging failure for MSISDN:46071 (event=1)
 DPAG Calling paging cbfn.
+DREF VLR subscr MSISDN:46071 usage decreases to: 4
 DREF VLR subscr MSISDN:46071 usage decreases to: 3
 DREF VLR subscr MSISDN:46071 usage decreases to: 2
 DREF VLR subscr MSISDN:46071 usage increases to: 3
diff --git a/tests/msc_vlr/msc_vlr_test_no_authen.err b/tests/msc_vlr/msc_vlr_test_no_authen.err
index fb0582b5a..e8c2927e0 100644
--- a/tests/msc_vlr/msc_vlr_test_no_authen.err
+++ b/tests/msc_vlr/msc_vlr_test_no_authen.err
@@ -187,18 +187,20 @@ DMM Subscr_Conn(CM_SERVICE_REQ:901700000004620){SUBSCR_CONN_S_RELEASED}: Dealloc
 DREF VLR subscr MSISDN:46071 usage increases to: 2
   llist_count(&vsub->cs.requests) == 0
 DREF VLR subscr MSISDN:46071 usage increases to: 3
+DCC (ti 00 sub MSISDN:46071 callref 40000001) New transaction
+DREF VLR subscr MSISDN:46071 usage increases to: 4
 DMM Subscriber MSISDN:46071 not paged yet, start paging.
   RAN_GERAN_A sends out paging request to IMSI 901700000004620, TMSI 0xffffffff, LAC 23
   strcmp(paging_expecting_imsi, imsi) == 0
-DREF VLR subscr MSISDN:46071 usage increases to: 4
+DREF VLR subscr MSISDN:46071 usage increases to: 5
   llist_count(&vsub->cs.requests) == 1
-DREF VLR subscr MSISDN:46071 usage decreases to: 3
+DREF VLR subscr MSISDN:46071 usage decreases to: 4
   paging_sent == 1
   paging_stopped == 0
 - the subscriber and its pending request should remain
-DREF VLR subscr MSISDN:46071 usage increases to: 4
+DREF VLR subscr MSISDN:46071 usage increases to: 5
   llist_count(&vsub->cs.requests) == 1
-DREF VLR subscr MSISDN:46071 usage decreases to: 3
+DREF VLR subscr MSISDN:46071 usage decreases to: 4
 - MS replies with Paging Response, we deliver the SMS
   MSC <--RAN_GERAN_A-- MS: GSM48_MT_RR_PAG_RESP
   new conn
@@ -211,8 +213,8 @@ DVLR Process_Access_Request_VLR(PAGING_RESP:901700000004620){PR_ARQ_S_INIT}: All
 DVLR Process_Access_Request_VLR(PAGING_RESP:901700000004620){PR_ARQ_S_INIT}: is child of Subscr_Conn(PAGING_RESP:901700000004620)
 DVLR Process_Access_Request_VLR(PAGING_RESP:901700000004620){PR_ARQ_S_INIT}: rev=GSM net=GERAN (no Auth)
 DVLR Process_Access_Request_VLR(PAGING_RESP:901700000004620){PR_ARQ_S_INIT}: Received Event PR_ARQ_E_START
-DREF VLR subscr MSISDN:46071 usage increases to: 4
 DREF VLR subscr MSISDN:46071 usage increases to: 5
+DREF VLR subscr MSISDN:46071 usage increases to: 6
 DVLR Process_Access_Request_VLR(PAGING_RESP:901700000004620){PR_ARQ_S_INIT}: proc_arq_vlr_fn_post_imsi()
 DVLR Process_Access_Request_VLR(PAGING_RESP:901700000004620){PR_ARQ_S_INIT}: _proc_arq_vlr_node2()
 DVLR Process_Access_Request_VLR(PAGING_RESP:901700000004620){PR_ARQ_S_INIT}: _proc_arq_vlr_node2_post_ciph()
@@ -226,8 +228,6 @@ DVLR Process_Access_Request_VLR(PAGING_RESP:901700000004620){PR_ARQ_S_DONE}: Pro
 DMM Subscr_Conn(PAGING_RESP:901700000004620){SUBSCR_CONN_S_NEW}: Received Event SUBSCR_CONN_E_ACCEPTED
 DPAG Paging success for MSISDN:46071 (event=0)
 DPAG Calling paging cbfn.
-DCC (ti 00 sub MSISDN:46071 callref 40000001) New transaction
-DREF VLR subscr MSISDN:46071 usage increases to: 6
 DREF MSISDN:46071: MSC conn use + trans_sms == 2 (0x21: compl_l3,trans_sms)
 DMSC msc_tx 91 bytes to MSISDN:46071 via RAN_GERAN_A
 - DTAP --RAN_GERAN_A--> MS: SMS:0x01: 09015801000791447758100650004c0005806470f1000007101000000000445079da1e1ee7416937485e9ea7c965373d1d6683c270383b3d0ed3d36ff71c949e83c22072799e9687c5ec32a81d96afcbf4b4fb0c7ac3e9e9b7db05
@@ -546,18 +546,20 @@ DMM Subscr_Conn(CM_SERVICE_REQ:50462976){SUBSCR_CONN_S_RELEASED}: Deallocated
 DREF VLR subscr MSISDN:46071 usage increases to: 2
   llist_count(&vsub->cs.requests) == 0
 DREF VLR subscr MSISDN:46071 usage increases to: 3
+DCC (ti 00 sub MSISDN:46071 callref 40000002) New transaction
+DREF VLR subscr MSISDN:46071 usage increases to: 4
 DMM Subscriber MSISDN:46071 not paged yet, start paging.
   RAN_GERAN_A sends out paging request to IMSI 901700000004620, TMSI 0x03020100, LAC 23
   paging_expecting_tmsi == 0x03020100
-DREF VLR subscr MSISDN:46071 usage increases to: 4
+DREF VLR subscr MSISDN:46071 usage increases to: 5
   llist_count(&vsub->cs.requests) == 1
-DREF VLR subscr MSISDN:46071 usage decreases to: 3
+DREF VLR subscr MSISDN:46071 usage decreases to: 4
   paging_sent == 1
   paging_stopped == 0
 - the subscriber and its pending request should remain
-DREF VLR subscr MSISDN:46071 usage increases to: 4
+DREF VLR subscr MSISDN:46071 usage increases to: 5
   llist_count(&vsub->cs.requests) == 1
-DREF VLR subscr MSISDN:46071 usage decreases to: 3
+DREF VLR subscr MSISDN:46071 usage decreases to: 4
 - MS replies with Paging Response using TMSI, we deliver the SMS
   MSC <--RAN_GERAN_A-- MS: GSM48_MT_RR_PAG_RESP
   new conn
@@ -570,8 +572,8 @@ DVLR Process_Access_Request_VLR(PAGING_RESP:50462976){PR_ARQ_S_INIT}: Allocated
 DVLR Process_Access_Request_VLR(PAGING_RESP:50462976){PR_ARQ_S_INIT}: is child of Subscr_Conn(PAGING_RESP:50462976)
 DVLR Process_Access_Request_VLR(PAGING_RESP:50462976){PR_ARQ_S_INIT}: rev=GSM net=GERAN (no Auth)
 DVLR Process_Access_Request_VLR(PAGING_RESP:50462976){PR_ARQ_S_INIT}: Received Event PR_ARQ_E_START
-DREF VLR subscr MSISDN:46071 usage increases to: 4
 DREF VLR subscr MSISDN:46071 usage increases to: 5
+DREF VLR subscr MSISDN:46071 usage increases to: 6
 DVLR Process_Access_Request_VLR(PAGING_RESP:50462976){PR_ARQ_S_INIT}: proc_arq_vlr_fn_post_imsi()
 DVLR Process_Access_Request_VLR(PAGING_RESP:50462976){PR_ARQ_S_INIT}: _proc_arq_vlr_node2()
 DVLR Process_Access_Request_VLR(PAGING_RESP:50462976){PR_ARQ_S_INIT}: _proc_arq_vlr_node2_post_ciph()
@@ -585,8 +587,6 @@ DVLR Process_Access_Request_VLR(PAGING_RESP:50462976){PR_ARQ_S_DONE}: Process Ac
 DMM Subscr_Conn(PAGING_RESP:50462976){SUBSCR_CONN_S_NEW}: Received Event SUBSCR_CONN_E_ACCEPTED
 DPAG Paging success for MSISDN:46071 (event=0)
 DPAG Calling paging cbfn.
-DCC (ti 00 sub MSISDN:46071 callref 40000002) New transaction
-DREF VLR subscr MSISDN:46071 usage increases to: 6
 DREF MSISDN:46071: MSC conn use + trans_sms == 2 (0x21: compl_l3,trans_sms)
 DMSC msc_tx 91 bytes to MSISDN:46071 via RAN_GERAN_A
 - DTAP --RAN_GERAN_A--> MS: SMS:0x01: 09015801000791447758100650004c0005806470f1000007101000000000445079da1e1ee7416937485e9ea7c965373d1d6683c270383b3d0ed3d36ff71c949e83c22072799e9687c5ec32a81d96afcbf4b4fb0c7ac3e9e9b7db05
diff --git a/tests/msc_vlr/msc_vlr_test_reject_concurrency.err b/tests/msc_vlr/msc_vlr_test_reject_concurrency.err
index 0a964ac55..cf90a1c07 100644
--- a/tests/msc_vlr/msc_vlr_test_reject_concurrency.err
+++ b/tests/msc_vlr/msc_vlr_test_reject_concurrency.err
@@ -1260,12 +1260,14 @@ DMM Subscr_Conn(LU:901700000004620){SUBSCR_CONN_S_RELEASED}: Deallocated
 DREF VLR subscr MSISDN:46071 usage increases to: 2
   llist_count(&vsub->cs.requests) == 0
 DREF VLR subscr MSISDN:46071 usage increases to: 3
+DCC (ti 00 sub MSISDN:46071 callref 40000001) New transaction
+DREF VLR subscr MSISDN:46071 usage increases to: 4
 DMM Subscriber MSISDN:46071 not paged yet, start paging.
   RAN_GERAN_A sends out paging request to IMSI 901700000004620, TMSI 0xffffffff, LAC 23
   strcmp(paging_expecting_imsi, imsi) == 0
-DREF VLR subscr MSISDN:46071 usage increases to: 4
+DREF VLR subscr MSISDN:46071 usage increases to: 5
   llist_count(&vsub->cs.requests) == 1
-DREF VLR subscr MSISDN:46071 usage decreases to: 3
+DREF VLR subscr MSISDN:46071 usage decreases to: 4
   paging_sent == 1
   paging_stopped == 0
 - MS replies with Paging Response, we deliver the SMS
@@ -1280,8 +1282,8 @@ DVLR Process_Access_Request_VLR(PAGING_RESP:901700000004620){PR_ARQ_S_INIT}: All
 DVLR Process_Access_Request_VLR(PAGING_RESP:901700000004620){PR_ARQ_S_INIT}: is child of Subscr_Conn(PAGING_RESP:901700000004620)
 DVLR Process_Access_Request_VLR(PAGING_RESP:901700000004620){PR_ARQ_S_INIT}: rev=GSM net=GERAN (no Auth)
 DVLR Process_Access_Request_VLR(PAGING_RESP:901700000004620){PR_ARQ_S_INIT}: Received Event PR_ARQ_E_START
-DREF VLR subscr MSISDN:46071 usage increases to: 4
 DREF VLR subscr MSISDN:46071 usage increases to: 5
+DREF VLR subscr MSISDN:46071 usage increases to: 6
 DVLR Process_Access_Request_VLR(PAGING_RESP:901700000004620){PR_ARQ_S_INIT}: proc_arq_vlr_fn_post_imsi()
 DVLR Process_Access_Request_VLR(PAGING_RESP:901700000004620){PR_ARQ_S_INIT}: _proc_arq_vlr_node2()
 DVLR Process_Access_Request_VLR(PAGING_RESP:901700000004620){PR_ARQ_S_INIT}: _proc_arq_vlr_node2_post_ciph()
@@ -1295,8 +1297,6 @@ DVLR Process_Access_Request_VLR(PAGING_RESP:901700000004620){PR_ARQ_S_DONE}: Pro
 DMM Subscr_Conn(PAGING_RESP:901700000004620){SUBSCR_CONN_S_NEW}: Received Event SUBSCR_CONN_E_ACCEPTED
 DPAG Paging success for MSISDN:46071 (event=0)
 DPAG Calling paging cbfn.
-DCC (ti 00 sub MSISDN:46071 callref 40000001) New transaction
-DREF VLR subscr MSISDN:46071 usage increases to: 6
 DREF MSISDN:46071: MSC conn use + trans_sms == 2 (0x21: compl_l3,trans_sms)
 DMSC msc_tx 91 bytes to MSISDN:46071 via RAN_GERAN_A
 - DTAP --RAN_GERAN_A--> MS: SMS:0x01: 09015801000791447758100650004c0005806470f1000007101000000000445079da1e1ee7416937485e9ea7c965373d1d6683c270383b3d0ed3d36ff71c949e83c22072799e9687c5ec32a81d96afcbf4b4fb0c7ac3e9e9b7db05
@@ -1487,12 +1487,14 @@ DMM Subscr_Conn(LU:901700000004620){SUBSCR_CONN_S_RELEASED}: Deallocated
 DREF VLR subscr MSISDN:46071 usage increases to: 2
   llist_count(&vsub->cs.requests) == 0
 DREF VLR subscr MSISDN:46071 usage increases to: 3
+DCC (ti 00 sub MSISDN:46071 callref 40000002) New transaction
+DREF VLR subscr MSISDN:46071 usage increases to: 4
 DMM Subscriber MSISDN:46071 not paged yet, start paging.
   RAN_GERAN_A sends out paging request to IMSI 901700000004620, TMSI 0xffffffff, LAC 23
   strcmp(paging_expecting_imsi, imsi) == 0
-DREF VLR subscr MSISDN:46071 usage increases to: 4
+DREF VLR subscr MSISDN:46071 usage increases to: 5
   llist_count(&vsub->cs.requests) == 1
-DREF VLR subscr MSISDN:46071 usage decreases to: 3
+DREF VLR subscr MSISDN:46071 usage decreases to: 4
   paging_sent == 1
   paging_stopped == 0
 - MS replies with Paging Response, we deliver the SMS
@@ -1507,8 +1509,8 @@ DVLR Process_Access_Request_VLR(PAGING_RESP:901700000004620){PR_ARQ_S_INIT}: All
 DVLR Process_Access_Request_VLR(PAGING_RESP:901700000004620){PR_ARQ_S_INIT}: is child of Subscr_Conn(PAGING_RESP:901700000004620)
 DVLR Process_Access_Request_VLR(PAGING_RESP:901700000004620){PR_ARQ_S_INIT}: rev=GSM net=GERAN (no Auth)
 DVLR Process_Access_Request_VLR(PAGING_RESP:901700000004620){PR_ARQ_S_INIT}: Received Event PR_ARQ_E_START
-DREF VLR subscr MSISDN:46071 usage increases to: 4
 DREF VLR subscr MSISDN:46071 usage increases to: 5
+DREF VLR subscr MSISDN:46071 usage increases to: 6
 DVLR Process_Access_Request_VLR(PAGING_RESP:901700000004620){PR_ARQ_S_INIT}: proc_arq_vlr_fn_post_imsi()
 DVLR Process_Access_Request_VLR(PAGING_RESP:901700000004620){PR_ARQ_S_INIT}: _proc_arq_vlr_node2()
 DVLR Process_Access_Request_VLR(PAGING_RESP:901700000004620){PR_ARQ_S_INIT}: _proc_arq_vlr_node2_post_ciph()
@@ -1522,8 +1524,6 @@ DVLR Process_Access_Request_VLR(PAGING_RESP:901700000004620){PR_ARQ_S_DONE}: Pro
 DMM Subscr_Conn(PAGING_RESP:901700000004620){SUBSCR_CONN_S_NEW}: Received Event SUBSCR_CONN_E_ACCEPTED
 DPAG Paging success for MSISDN:46071 (event=0)
 DPAG Calling paging cbfn.
-DCC (ti 00 sub MSISDN:46071 callref 40000002) New transaction
-DREF VLR subscr MSISDN:46071 usage increases to: 6
 DREF MSISDN:46071: MSC conn use + trans_sms == 2 (0x21: compl_l3,trans_sms)
 DMSC msc_tx 91 bytes to MSISDN:46071 via RAN_GERAN_A
 - DTAP --RAN_GERAN_A--> MS: SMS:0x01: 09015801000791447758100650004c0005806470f1000007101000000000445079da1e1ee7416937485e9ea7c965373d1d6683c270383b3d0ed3d36ff71c949e83c22072799e9687c5ec32a81d96afcbf4b4fb0c7ac3e9e9b7db05
@@ -1734,12 +1734,14 @@ DMM Subscr_Conn(LU:901700000004620){SUBSCR_CONN_S_RELEASED}: Deallocated
 DREF VLR subscr MSISDN:46071 usage increases to: 2
   llist_count(&vsub->cs.requests) == 0
 DREF VLR subscr MSISDN:46071 usage increases to: 3
+DCC (ti 00 sub MSISDN:46071 callref 40000003) New transaction
+DREF VLR subscr MSISDN:46071 usage increases to: 4
 DMM Subscriber MSISDN:46071 not paged yet, start paging.
   RAN_GERAN_A sends out paging request to IMSI 901700000004620, TMSI 0xffffffff, LAC 23
   strcmp(paging_expecting_imsi, imsi) == 0
-DREF VLR subscr MSISDN:46071 usage increases to: 4
+DREF VLR subscr MSISDN:46071 usage increases to: 5
   llist_count(&vsub->cs.requests) == 1
-DREF VLR subscr MSISDN:46071 usage decreases to: 3
+DREF VLR subscr MSISDN:46071 usage decreases to: 4
   paging_sent == 1
   paging_stopped == 0
 - MS replies with Paging Response, we deliver the SMS
@@ -1754,8 +1756,8 @@ DVLR Process_Access_Request_VLR(PAGING_RESP:901700000004620){PR_ARQ_S_INIT}: All
 DVLR Process_Access_Request_VLR(PAGING_RESP:901700000004620){PR_ARQ_S_INIT}: is child of Subscr_Conn(PAGING_RESP:901700000004620)
 DVLR Process_Access_Request_VLR(PAGING_RESP:901700000004620){PR_ARQ_S_INIT}: rev=GSM net=GERAN (no Auth)
 DVLR Process_Access_Request_VLR(PAGING_RESP:901700000004620){PR_ARQ_S_INIT}: Received Event PR_ARQ_E_START
-DREF VLR subscr MSISDN:46071 usage increases to: 4
 DREF VLR subscr MSISDN:46071 usage increases to: 5
+DREF VLR subscr MSISDN:46071 usage increases to: 6
 DVLR Process_Access_Request_VLR(PAGING_RESP:901700000004620){PR_ARQ_S_INIT}: proc_arq_vlr_fn_post_imsi()
 DVLR Process_Access_Request_VLR(PAGING_RESP:901700000004620){PR_ARQ_S_INIT}: _proc_arq_vlr_node2()
 DVLR Process_Access_Request_VLR(PAGING_RESP:901700000004620){PR_ARQ_S_INIT}: _proc_arq_vlr_node2_post_ciph()
@@ -1769,8 +1771,6 @@ DVLR Process_Access_Request_VLR(PAGING_RESP:901700000004620){PR_ARQ_S_DONE}: Pro
 DMM Subscr_Conn(PAGING_RESP:901700000004620){SUBSCR_CONN_S_NEW}: Received Event SUBSCR_CONN_E_ACCEPTED
 DPAG Paging success for MSISDN:46071 (event=0)
 DPAG Calling paging cbfn.
-DCC (ti 00 sub MSISDN:46071 callref 40000003) New transaction
-DREF VLR subscr MSISDN:46071 usage increases to: 6
 DREF MSISDN:46071: MSC conn use + trans_sms == 2 (0x21: compl_l3,trans_sms)
 DMSC msc_tx 91 bytes to MSISDN:46071 via RAN_GERAN_A
 - DTAP --RAN_GERAN_A--> MS: SMS:0x01: 09015801000791447758100650004c0005806470f1000007101000000000445079da1e1ee7416937485e9ea7c965373d1d6683c270383b3d0ed3d36ff71c949e83c22072799e9687c5ec32a81d96afcbf4b4fb0c7ac3e9e9b7db05
diff --git a/tests/msc_vlr/msc_vlr_test_umts_authen.err b/tests/msc_vlr/msc_vlr_test_umts_authen.err
index 538a3d9cd..fdd3b0cc2 100644
--- a/tests/msc_vlr/msc_vlr_test_umts_authen.err
+++ b/tests/msc_vlr/msc_vlr_test_umts_authen.err
@@ -288,18 +288,20 @@ DMM Subscr_Conn(CM_SERVICE_REQ:901700000010650){SUBSCR_CONN_S_RELEASED}: Dealloc
 DREF VLR subscr MSISDN:42342 usage increases to: 2
   llist_count(&vsub->cs.requests) == 0
 DREF VLR subscr MSISDN:42342 usage increases to: 3
+DCC (ti 00 sub MSISDN:42342 callref 40000001) New transaction
+DREF VLR subscr MSISDN:42342 usage increases to: 4
 DMM Subscriber MSISDN:42342 not paged yet, start paging.
   RAN_GERAN_A sends out paging request to IMSI 901700000010650, TMSI 0x03020100, LAC 23
   strcmp(paging_expecting_imsi, imsi) == 0
-DREF VLR subscr MSISDN:42342 usage increases to: 4
+DREF VLR subscr MSISDN:42342 usage increases to: 5
   llist_count(&vsub->cs.requests) == 1
-DREF VLR subscr MSISDN:42342 usage decreases to: 3
+DREF VLR subscr MSISDN:42342 usage decreases to: 4
   paging_sent == 1
   paging_stopped == 0
 - the subscriber and its pending request should remain
-DREF VLR subscr MSISDN:42342 usage increases to: 4
+DREF VLR subscr MSISDN:42342 usage increases to: 5
   llist_count(&vsub->cs.requests) == 1
-DREF VLR subscr MSISDN:42342 usage decreases to: 3
+DREF VLR subscr MSISDN:42342 usage decreases to: 4
 - MS replies with Paging Response, and VLR sends Auth Request with third key
   MSC <--RAN_GERAN_A-- MS: GSM48_MT_RR_PAG_RESP
   new conn
@@ -312,8 +314,8 @@ DVLR Process_Access_Request_VLR(PAGING_RESP:901700000010650){PR_ARQ_S_INIT}: All
 DVLR Process_Access_Request_VLR(PAGING_RESP:901700000010650){PR_ARQ_S_INIT}: is child of Subscr_Conn(PAGING_RESP:901700000010650)
 DVLR Process_Access_Request_VLR(PAGING_RESP:901700000010650){PR_ARQ_S_INIT}: rev=R99 net=GERAN Auth (no Ciph)
 DVLR Process_Access_Request_VLR(PAGING_RESP:901700000010650){PR_ARQ_S_INIT}: Received Event PR_ARQ_E_START
-DREF VLR subscr MSISDN:42342 usage increases to: 4
 DREF VLR subscr MSISDN:42342 usage increases to: 5
+DREF VLR subscr MSISDN:42342 usage increases to: 6
 DVLR Process_Access_Request_VLR(PAGING_RESP:901700000010650){PR_ARQ_S_INIT}: proc_arq_vlr_fn_post_imsi()
 DVLR Process_Access_Request_VLR(PAGING_RESP:901700000010650){PR_ARQ_S_INIT}: state_chg to PR_ARQ_S_WAIT_AUTH
 DVLR VLR_Authenticate(PAGING_RESP:901700000010650){VLR_SUB_AS_NEEDS_AUTH}: Allocated
@@ -325,7 +327,7 @@ DVLR VLR_Authenticate(PAGING_RESP:901700000010650){VLR_SUB_AS_WAIT_RESP}: got au
 - ...rand=efa9c29a9742148d5c9070348716e1bb
 - ...autn=f9375e6d41e1000096e7fe4ff1c27e39
 - ...expecting res=706f996719ba609c
-DREF VLR subscr MSISDN:42342 usage decreases to: 4
+DREF VLR subscr MSISDN:42342 usage decreases to: 5
 DMM Subscr_Conn(PAGING_RESP:901700000010650){SUBSCR_CONN_S_NEW}: Received Event SUBSCR_CONN_E_COMPLETE_LAYER_3
 DMM Subscr_Conn(PAGING_RESP:901700000010650){SUBSCR_CONN_S_NEW}: state_chg to SUBSCR_CONN_S_AUTH_CIPH
 DREF MSISDN:42342: MSC conn use - compl_l3 == 0 (0x0: )
@@ -370,8 +372,6 @@ DVLR Process_Access_Request_VLR(PAGING_RESP:901700000010650){PR_ARQ_S_DONE}: Pro
 DMM Subscr_Conn(PAGING_RESP:901700000010650){SUBSCR_CONN_S_AUTH_CIPH}: Received Event SUBSCR_CONN_E_ACCEPTED
 DPAG Paging success for MSISDN:42342 (event=0)
 DPAG Calling paging cbfn.
-DCC (ti 00 sub MSISDN:42342 callref 40000001) New transaction
-DREF VLR subscr MSISDN:42342 usage increases to: 5
 DREF MSISDN:42342: MSC conn use + trans_sms == 2 (0x22: dtap,trans_sms)
 DMSC msc_tx 91 bytes to MSISDN:42342 via RAN_GERAN_A
 - DTAP --RAN_GERAN_A--> MS: SMS:0x01: 09015801000791447758100650004c0005802443f2000007101000000000445079da1e1ee7416937485e9ea7c965373d1d6683c270383b3d0ed3d36ff71c949e83c22072799e9687c5ec32a81d96afcbf4b4fb0c7ac3e9e9b7db05
@@ -778,18 +778,20 @@ DMM Subscr_Conn(CM_SERVICE_REQ:901700000010650){SUBSCR_CONN_S_RELEASED}: Dealloc
 DREF VLR subscr MSISDN:42342 usage increases to: 2
   llist_count(&vsub->cs.requests) == 0
 DREF VLR subscr MSISDN:42342 usage increases to: 3
+DCC (ti 00 sub MSISDN:42342 callref 40000002) New transaction
+DREF VLR subscr MSISDN:42342 usage increases to: 4
 DMM Subscriber MSISDN:42342 not paged yet, start paging.
   RAN_UTRAN_IU sends out paging request to IMSI 901700000010650, TMSI 0x03020100, LAC 23
   strcmp(paging_expecting_imsi, imsi) == 0
-DREF VLR subscr MSISDN:42342 usage increases to: 4
+DREF VLR subscr MSISDN:42342 usage increases to: 5
   llist_count(&vsub->cs.requests) == 1
-DREF VLR subscr MSISDN:42342 usage decreases to: 3
+DREF VLR subscr MSISDN:42342 usage decreases to: 4
   paging_sent == 1
   paging_stopped == 0
 - the subscriber and its pending request should remain
-DREF VLR subscr MSISDN:42342 usage increases to: 4
+DREF VLR subscr MSISDN:42342 usage increases to: 5
   llist_count(&vsub->cs.requests) == 1
-DREF VLR subscr MSISDN:42342 usage decreases to: 3
+DREF VLR subscr MSISDN:42342 usage decreases to: 4
 - MS replies with Paging Response, and VLR sends Auth Request with third key
   MSC <--RAN_UTRAN_IU-- MS: GSM48_MT_RR_PAG_RESP
   new conn
@@ -802,8 +804,8 @@ DVLR Process_Access_Request_VLR(PAGING_RESP:901700000010650){PR_ARQ_S_INIT}: All
 DVLR Process_Access_Request_VLR(PAGING_RESP:901700000010650){PR_ARQ_S_INIT}: is child of Subscr_Conn(PAGING_RESP:901700000010650)
 DVLR Process_Access_Request_VLR(PAGING_RESP:901700000010650){PR_ARQ_S_INIT}: rev=R99 net=UTRAN Auth+Ciph
 DVLR Process_Access_Request_VLR(PAGING_RESP:901700000010650){PR_ARQ_S_INIT}: Received Event PR_ARQ_E_START
-DREF VLR subscr MSISDN:42342 usage increases to: 4
 DREF VLR subscr MSISDN:42342 usage increases to: 5
+DREF VLR subscr MSISDN:42342 usage increases to: 6
 DVLR Process_Access_Request_VLR(PAGING_RESP:901700000010650){PR_ARQ_S_INIT}: proc_arq_vlr_fn_post_imsi()
 DVLR Process_Access_Request_VLR(PAGING_RESP:901700000010650){PR_ARQ_S_INIT}: state_chg to PR_ARQ_S_WAIT_AUTH
 DVLR VLR_Authenticate(PAGING_RESP:901700000010650){VLR_SUB_AS_NEEDS_AUTH}: Allocated
@@ -815,7 +817,7 @@ DVLR VLR_Authenticate(PAGING_RESP:901700000010650){VLR_SUB_AS_WAIT_RESP}: got au
 - ...rand=efa9c29a9742148d5c9070348716e1bb
 - ...autn=f9375e6d41e1000096e7fe4ff1c27e39
 - ...expecting res=706f996719ba609c
-DREF VLR subscr MSISDN:42342 usage decreases to: 4
+DREF VLR subscr MSISDN:42342 usage decreases to: 5
 DMM Subscr_Conn(PAGING_RESP:901700000010650){SUBSCR_CONN_S_NEW}: Received Event SUBSCR_CONN_E_COMPLETE_LAYER_3
 DMM Subscr_Conn(PAGING_RESP:901700000010650){SUBSCR_CONN_S_NEW}: state_chg to SUBSCR_CONN_S_AUTH_CIPH
 DREF MSISDN:42342: MSC conn use - compl_l3 == 0 (0x0: )
@@ -875,8 +877,6 @@ DVLR Process_Access_Request_VLR(PAGING_RESP:901700000010650){PR_ARQ_S_DONE}: Pro
 DMM Subscr_Conn(PAGING_RESP:901700000010650){SUBSCR_CONN_S_AUTH_CIPH}: Received Event SUBSCR_CONN_E_ACCEPTED
 DPAG Paging success for MSISDN:42342 (event=0)
 DPAG Calling paging cbfn.
-DCC (ti 00 sub MSISDN:42342 callref 40000002) New transaction
-DREF VLR subscr MSISDN:42342 usage increases to: 5
 DREF MSISDN:42342: MSC conn use + trans_sms == 1 (0x20: trans_sms)
 DMSC msc_tx 91 bytes to MSISDN:42342 via RAN_UTRAN_IU
 - DTAP --RAN_UTRAN_IU--> MS: SMS:0x01: 09015801000791447758100650004c0005802443f2000007101000000000445079da1e1ee7416937485e9ea7c965373d1d6683c270383b3d0ed3d36ff71c949e83c22072799e9687c5ec32a81d96afcbf4b4fb0c7ac3e9e9b7db05
diff --git a/tests/msc_vlr/msc_vlr_tests.c b/tests/msc_vlr/msc_vlr_tests.c
index 6cf927c2f..01f5974bf 100644
--- a/tests/msc_vlr/msc_vlr_tests.c
+++ b/tests/msc_vlr/msc_vlr_tests.c
@@ -319,7 +319,7 @@ void send_sms(struct vlr_subscr *receiver,
 	      char *str)
 {
 	struct gsm_sms *sms = sms_from_text(receiver, sender->msisdn, 0, str);
-	gsm411_send_sms_subscr(receiver, sms);
+	gsm411_send_sms(net, receiver, sms);
 }
 
 unsigned char next_rand_byte = 0;