Change in osmo-msc[master]: Enable SMS-related log in VLR tests

This is merely a historical archive of years 2008-2021, before the migration to mailman3.

A maintained and still updated list archive can be found at https://lists.osmocom.org/hyperkitty/list/gerrit-log@lists.osmocom.org/.

Max gerrit-no-reply at lists.osmocom.org
Wed Jan 16 12:00:22 UTC 2019


Max has uploaded this change for review. ( https://gerrit.osmocom.org/12577


Change subject: Enable SMS-related log in VLR tests
......................................................................

Enable SMS-related log in VLR tests

The likely reason why it was disabled is due to
paging_cb_mmsms_est_req() logging pointers which results in unstable log
output. Fixing this allows us to track SMS-related regressions properly.

Change-Id: I44ae817d9edb73d182ff33ff5a2fd942e224e344
---
M src/libmsc/gsm_04_11.c
M tests/msc_vlr/msc_vlr_test_gsm_authen.err
M tests/msc_vlr/msc_vlr_test_gsm_ciph.err
M tests/msc_vlr/msc_vlr_test_ms_timeout.err
M tests/msc_vlr/msc_vlr_test_no_authen.err
M tests/msc_vlr/msc_vlr_test_reject_concurrency.err
M tests/msc_vlr/msc_vlr_test_umts_authen.err
M tests/msc_vlr/msc_vlr_tests.c
8 files changed, 590 insertions(+), 3 deletions(-)



  git pull ssh://gerrit.osmocom.org:29418/osmo-msc refs/changes/77/12577/1

diff --git a/src/libmsc/gsm_04_11.c b/src/libmsc/gsm_04_11.c
index 15a92d4..8ef26a7 100644
--- a/src/libmsc/gsm_04_11.c
+++ b/src/libmsc/gsm_04_11.c
@@ -135,8 +135,7 @@
 	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);
+	DEBUGP(DLSMS, "paging_cb_mmsms_est_req(hooknum=%u, event=%u)\n", hooknum, event);
 
 	if (hooknum != GSM_HOOK_RR_PAGING)
 		return -EINVAL;
diff --git a/tests/msc_vlr/msc_vlr_test_gsm_authen.err b/tests/msc_vlr/msc_vlr_test_gsm_authen.err
index fddfe07..2bf19e0 100644
--- a/tests/msc_vlr/msc_vlr_test_gsm_authen.err
+++ b/tests/msc_vlr/msc_vlr_test_gsm_authen.err
@@ -270,8 +270,17 @@
 DREF VLR subscr IMSI-901700000004620:MSISDN-46071 usage increases to: 2
   llist_count(&vsub->cs.requests) == 0
 DREF VLR subscr IMSI-901700000004620:MSISDN-46071 usage increases to: 3
+DLSMS Going to send a MT SMS
 DCC (ti 00 sub IMSI-901700000004620:MSISDN-46071 callref 40000001) New transaction
 DREF VLR subscr IMSI-901700000004620:MSISDN-46071 usage increases to: 4
+DLSMS SMC(0) instance created for network
+DLSMS SMR(0) instance created for network.
+DLSMS SMR(0) message SM-RL-DATA_REQ received in state IDLE
+DLSMS SMR(0) TX SMS RP-DATA
+DLSMS SMR(0) new RP state IDLE -> WAIT_FOR_RP_ACK
+DLSMS SMC(0) message MNSMS-EST-REQ received in state IDLE
+DLSMS SMC(0) new CP state IDLE -> MM_CONN_PENDING
+DLSMS Initiating Paging procedure for IMSI-901700000004620:MSISDN-46071 due to MMSMS_EST_REQ
 DMM Subscriber IMSI-901700000004620:MSISDN-46071 not paged yet, start paging.
   GERAN-A sends out paging request to IMSI 901700000004620, TMSI 0xffffffff, LAC 23
   strcmp(paging_expecting_imsi, imsi) == 0
@@ -354,7 +363,13 @@
 DMM RAN_conn(IMSI-901700000004620:MSISDN-46071:GERAN-A-0:PAGING_RESP){RAN_CONN_S_AUTH_CIPH}: Received Event RAN_CONN_E_ACCEPTED
 DPAG Paging success for IMSI-901700000004620:MSISDN-46071 (event=0)
 DPAG Calling paging cbfn.
+DLSMS paging_cb_mmsms_est_req(hooknum=1, event=0)
 DREF IMSI-901700000004620:MSISDN-46071: MSC conn use + trans_sms == 2 (0x22: dtap,trans_sms)
+DLSMS SMC(0) message MMSMS-EST-CNF received in state MM_CONN_PENDING
+DLSMS SMC(0) send CP data
+DLSMS SMC(0) new CP state MM_CONN_PENDING -> WAIT_CP_ACK
+DLSMS sending CP message (trans=0)
+DLSMS GSM4.11 TX 09 01 58 01 00 07 91 44 77 58 10 06 50 00 4c 00 05 80 64 70 f1 00 00 07 10 10 00 00 00 00 44 50 79 da 1e 1e e7 41 69 37 48 5e 9e a7 c9 65 37 3d 1d 66 83 c2 70 38 3b 3d 0e d3 d3 6f f7 1c 94 9e 83 c2 20 72 79 9e 96 87 c5 ec 32 a8 1d 96 af cb f4 b4 fb 0c 7a c3 e9 e9 b7 db 05 
 DMSC msc_tx 91 bytes to IMSI-901700000004620:MSISDN-46071 via GERAN-A
 - DTAP --GERAN-A--> MS: SMS:0x01: 09015801000791447758100650004c0005806470f1000007101000000000445079da1e1ee7416937485e9ea7c965373d1d6683c270383b3d0ed3d36ff71c949e83c22072799e9687c5ec32a81d96afcbf4b4fb0c7ac3e9e9b7db05
 - DTAP matches expected message
@@ -374,19 +389,39 @@
   MSC <--GERAN-A-- MS: SMS:0x04
 DREF IMSI-901700000004620:MSISDN-46071: MSC conn use + dtap == 2 (0x22: dtap,trans_sms)
 DRLL Dispatching 04.08 message SMS:0x04 (0x9:0x4)
+DLSMS receiving data (trans_id=0, msg_type=SMS:0x04)
 DMM RAN_conn(IMSI-901700000004620:MSISDN-46071:GERAN-A-0:PAGING_RESP){RAN_CONN_S_ACCEPTED}: Received Event RAN_CONN_E_COMMUNICATING
 DMM RAN_conn(IMSI-901700000004620:MSISDN-46071:GERAN-A-0:PAGING_RESP){RAN_CONN_S_ACCEPTED}: state_chg to RAN_CONN_S_COMMUNICATING
+DLSMS SMC(0) message MMSMS-DATA-IND (CP ACK) received in state WAIT_CP_ACK
+DLSMS SMC(0) received CP-ACK
+DLSMS SMC(0) new CP state WAIT_CP_ACK -> MM_ESTABLISHED
 DREF IMSI-901700000004620:MSISDN-46071: MSC conn use - dtap == 1 (0x20: trans_sms)
   llist_count(&net->ran_conns) == 1
 - MS also sends RP-ACK, MSC in turn sends CP-ACK for that
   MSC <--GERAN-A-- MS: SMS:0x01
 DREF IMSI-901700000004620:MSISDN-46071: MSC conn use + dtap == 2 (0x22: dtap,trans_sms)
 DRLL Dispatching 04.08 message SMS:0x01 (0x9:0x1)
+DLSMS receiving data (trans_id=0, msg_type=SMS:0x01)
 DMM RAN_conn(IMSI-901700000004620:MSISDN-46071:GERAN-A-0:PAGING_RESP){RAN_CONN_S_COMMUNICATING}: Received Event RAN_CONN_E_COMMUNICATING
+DLSMS SMC(0) message MMSMS-DATA-IND (CP DATA) received in state MM_ESTABLISHED
+DLSMS SMC(0) received CP-DATA
+DLSMS sending CP message (trans=0)
+DLSMS GSM4.11 TX 09 04 
 DMSC msc_tx 2 bytes to IMSI-901700000004620:MSISDN-46071 via GERAN-A
 - DTAP --GERAN-A--> MS: SMS:0x04: 0904
 - DTAP matches expected message
+DLSMS MNSMS-DATA/EST-IND
+DLSMS SMR(0) message MNSMS-DATA-IND received in state WAIT_FOR_RP_ACK
+DLSMS SMR(0) RX SMS RP-ACK
+DLSMS SMR(0) new RP state WAIT_FOR_RP_ACK -> IDLE
+DLSMS RX SMS RP-ACK (MO)
 DREF VLR subscr IMSI-901700000004620:MSISDN-46071 usage decreases to: 3
+DLSMS SMR(0) TX: MNSMS-REL-REQ
+DLSMS SMC(0) message MNSMS-REL-REQ received in state MM_ESTABLISHED
+DLSMS SMC(0) new CP state MM_ESTABLISHED -> IDLE
+DLSMS Got MMSMS_REL_REQ, destroying transaction.
+DLSMS SMR(0) clearing SMR instance
+DLSMS SMC(0) clearing instance
 DREF VLR subscr IMSI-901700000004620:MSISDN-46071 usage decreases to: 2
 DREF IMSI-901700000004620:MSISDN-46071: MSC conn use - trans_sms == 1 (0x2: dtap)
 DREF IMSI-901700000004620:MSISDN-46071: MSC conn use - dtap == 0 (0x0: )
@@ -757,8 +792,17 @@
 DREF VLR subscr IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100 usage increases to: 2
   llist_count(&vsub->cs.requests) == 0
 DREF VLR subscr IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100 usage increases to: 3
+DLSMS Going to send a MT SMS
 DCC (ti 00 sub IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100 callref 40000002) New transaction
 DREF VLR subscr IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100 usage increases to: 4
+DLSMS SMC(0) instance created for network
+DLSMS SMR(0) instance created for network.
+DLSMS SMR(0) message SM-RL-DATA_REQ received in state IDLE
+DLSMS SMR(0) TX SMS RP-DATA
+DLSMS SMR(0) new RP state IDLE -> WAIT_FOR_RP_ACK
+DLSMS SMC(0) message MNSMS-EST-REQ received in state IDLE
+DLSMS SMC(0) new CP state IDLE -> MM_CONN_PENDING
+DLSMS Initiating Paging procedure for IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100 due to MMSMS_EST_REQ
 DMM Subscriber IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100 not paged yet, start paging.
   GERAN-A sends out paging request to IMSI 901700000004620, TMSI 0x03020100, LAC 23
   paging_expecting_tmsi == 0x03020100
@@ -841,7 +885,13 @@
 DMM RAN_conn(IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100:GERAN-A-0:PAGING_RESP){RAN_CONN_S_AUTH_CIPH}: Received Event RAN_CONN_E_ACCEPTED
 DPAG Paging success for IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100 (event=0)
 DPAG Calling paging cbfn.
+DLSMS paging_cb_mmsms_est_req(hooknum=1, event=0)
 DREF IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100: MSC conn use + trans_sms == 2 (0x22: dtap,trans_sms)
+DLSMS SMC(0) message MMSMS-EST-CNF received in state MM_CONN_PENDING
+DLSMS SMC(0) send CP data
+DLSMS SMC(0) new CP state MM_CONN_PENDING -> WAIT_CP_ACK
+DLSMS sending CP message (trans=0)
+DLSMS GSM4.11 TX 09 01 58 01 00 07 91 44 77 58 10 06 50 00 4c 00 05 80 64 70 f1 00 00 07 10 10 00 00 00 00 44 50 79 da 1e 1e e7 41 69 37 48 5e 9e a7 c9 65 37 3d 1d 66 83 c2 70 38 3b 3d 0e d3 d3 6f f7 1c 94 9e 83 c2 20 72 79 9e 96 87 c5 ec 32 a8 1d 96 af cb f4 b4 fb 0c 7a c3 e9 e9 b7 db 05 
 DMSC msc_tx 91 bytes to IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100 via GERAN-A
 - DTAP --GERAN-A--> MS: SMS:0x01: 09015801000791447758100650004c0005806470f1000007101000000000445079da1e1ee7416937485e9ea7c965373d1d6683c270383b3d0ed3d36ff71c949e83c22072799e9687c5ec32a81d96afcbf4b4fb0c7ac3e9e9b7db05
 - DTAP matches expected message
@@ -861,19 +911,39 @@
   MSC <--GERAN-A-- MS: SMS:0x04
 DREF IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100: MSC conn use + dtap == 2 (0x22: dtap,trans_sms)
 DRLL Dispatching 04.08 message SMS:0x04 (0x9:0x4)
+DLSMS receiving data (trans_id=0, msg_type=SMS:0x04)
 DMM RAN_conn(IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100:GERAN-A-0:PAGING_RESP){RAN_CONN_S_ACCEPTED}: Received Event RAN_CONN_E_COMMUNICATING
 DMM RAN_conn(IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100:GERAN-A-0:PAGING_RESP){RAN_CONN_S_ACCEPTED}: state_chg to RAN_CONN_S_COMMUNICATING
+DLSMS SMC(0) message MMSMS-DATA-IND (CP ACK) received in state WAIT_CP_ACK
+DLSMS SMC(0) received CP-ACK
+DLSMS SMC(0) new CP state WAIT_CP_ACK -> MM_ESTABLISHED
 DREF IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100: MSC conn use - dtap == 1 (0x20: trans_sms)
   llist_count(&net->ran_conns) == 1
 - MS also sends RP-ACK, MSC in turn sends CP-ACK for that
   MSC <--GERAN-A-- MS: SMS:0x01
 DREF IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100: MSC conn use + dtap == 2 (0x22: dtap,trans_sms)
 DRLL Dispatching 04.08 message SMS:0x01 (0x9:0x1)
+DLSMS receiving data (trans_id=0, msg_type=SMS:0x01)
 DMM RAN_conn(IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100:GERAN-A-0:PAGING_RESP){RAN_CONN_S_COMMUNICATING}: Received Event RAN_CONN_E_COMMUNICATING
+DLSMS SMC(0) message MMSMS-DATA-IND (CP DATA) received in state MM_ESTABLISHED
+DLSMS SMC(0) received CP-DATA
+DLSMS sending CP message (trans=0)
+DLSMS GSM4.11 TX 09 04 
 DMSC msc_tx 2 bytes to IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100 via GERAN-A
 - DTAP --GERAN-A--> MS: SMS:0x04: 0904
 - DTAP matches expected message
+DLSMS MNSMS-DATA/EST-IND
+DLSMS SMR(0) message MNSMS-DATA-IND received in state WAIT_FOR_RP_ACK
+DLSMS SMR(0) RX SMS RP-ACK
+DLSMS SMR(0) new RP state WAIT_FOR_RP_ACK -> IDLE
+DLSMS RX SMS RP-ACK (MO)
 DREF VLR subscr IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100 usage decreases to: 3
+DLSMS SMR(0) TX: MNSMS-REL-REQ
+DLSMS SMC(0) message MNSMS-REL-REQ received in state MM_ESTABLISHED
+DLSMS SMC(0) new CP state MM_ESTABLISHED -> IDLE
+DLSMS Got MMSMS_REL_REQ, destroying transaction.
+DLSMS SMR(0) clearing SMR instance
+DLSMS SMC(0) clearing instance
 DREF VLR subscr IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100 usage decreases to: 2
 DREF IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100: MSC conn use - trans_sms == 1 (0x2: dtap)
 DREF IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100: MSC conn use - dtap == 0 (0x0: )
@@ -1854,8 +1924,17 @@
 DREF VLR subscr IMSI-901700000010650:MSISDN-42342 usage increases to: 2
   llist_count(&vsub->cs.requests) == 0
 DREF VLR subscr IMSI-901700000010650:MSISDN-42342 usage increases to: 3
+DLSMS Going to send a MT SMS
 DCC (ti 00 sub IMSI-901700000010650:MSISDN-42342 callref 40000003) New transaction
 DREF VLR subscr IMSI-901700000010650:MSISDN-42342 usage increases to: 4
+DLSMS SMC(0) instance created for network
+DLSMS SMR(0) instance created for network.
+DLSMS SMR(0) message SM-RL-DATA_REQ received in state IDLE
+DLSMS SMR(0) TX SMS RP-DATA
+DLSMS SMR(0) new RP state IDLE -> WAIT_FOR_RP_ACK
+DLSMS SMC(0) message MNSMS-EST-REQ received in state IDLE
+DLSMS SMC(0) new CP state IDLE -> MM_CONN_PENDING
+DLSMS Initiating Paging procedure for IMSI-901700000010650:MSISDN-42342 due to MMSMS_EST_REQ
 DMM Subscriber IMSI-901700000010650:MSISDN-42342 not paged yet, start paging.
   GERAN-A sends out paging request to IMSI 901700000010650, TMSI 0xffffffff, LAC 23
   strcmp(paging_expecting_imsi, imsi) == 0
@@ -1938,7 +2017,13 @@
 DMM RAN_conn(IMSI-901700000010650:MSISDN-42342:GERAN-A-0:PAGING_RESP){RAN_CONN_S_AUTH_CIPH}: Received Event RAN_CONN_E_ACCEPTED
 DPAG Paging success for IMSI-901700000010650:MSISDN-42342 (event=0)
 DPAG Calling paging cbfn.
+DLSMS paging_cb_mmsms_est_req(hooknum=1, event=0)
 DREF IMSI-901700000010650:MSISDN-42342: MSC conn use + trans_sms == 2 (0x22: dtap,trans_sms)
+DLSMS SMC(0) message MMSMS-EST-CNF received in state MM_CONN_PENDING
+DLSMS SMC(0) send CP data
+DLSMS SMC(0) new CP state MM_CONN_PENDING -> WAIT_CP_ACK
+DLSMS sending CP message (trans=0)
+DLSMS GSM4.11 TX 09 01 58 01 00 07 91 44 77 58 10 06 50 00 4c 00 05 80 24 43 f2 00 00 07 10 10 00 00 00 00 44 50 79 da 1e 1e e7 41 69 37 48 5e 9e a7 c9 65 37 3d 1d 66 83 c2 70 38 3b 3d 0e d3 d3 6f f7 1c 94 9e 83 c2 20 72 79 9e 96 87 c5 ec 32 a8 1d 96 af cb f4 b4 fb 0c 7a c3 e9 e9 b7 db 05 
 DMSC msc_tx 91 bytes to IMSI-901700000010650:MSISDN-42342 via GERAN-A
 - DTAP --GERAN-A--> MS: SMS:0x01: 09015801000791447758100650004c0005802443f2000007101000000000445079da1e1ee7416937485e9ea7c965373d1d6683c270383b3d0ed3d36ff71c949e83c22072799e9687c5ec32a81d96afcbf4b4fb0c7ac3e9e9b7db05
 - DTAP matches expected message
@@ -1958,19 +2043,39 @@
   MSC <--GERAN-A-- MS: SMS:0x04
 DREF IMSI-901700000010650:MSISDN-42342: MSC conn use + dtap == 2 (0x22: dtap,trans_sms)
 DRLL Dispatching 04.08 message SMS:0x04 (0x9:0x4)
+DLSMS receiving data (trans_id=0, msg_type=SMS:0x04)
 DMM RAN_conn(IMSI-901700000010650:MSISDN-42342:GERAN-A-0:PAGING_RESP){RAN_CONN_S_ACCEPTED}: Received Event RAN_CONN_E_COMMUNICATING
 DMM RAN_conn(IMSI-901700000010650:MSISDN-42342:GERAN-A-0:PAGING_RESP){RAN_CONN_S_ACCEPTED}: state_chg to RAN_CONN_S_COMMUNICATING
+DLSMS SMC(0) message MMSMS-DATA-IND (CP ACK) received in state WAIT_CP_ACK
+DLSMS SMC(0) received CP-ACK
+DLSMS SMC(0) new CP state WAIT_CP_ACK -> MM_ESTABLISHED
 DREF IMSI-901700000010650:MSISDN-42342: MSC conn use - dtap == 1 (0x20: trans_sms)
   llist_count(&net->ran_conns) == 1
 - MS also sends RP-ACK, MSC in turn sends CP-ACK for that
   MSC <--GERAN-A-- MS: SMS:0x01
 DREF IMSI-901700000010650:MSISDN-42342: MSC conn use + dtap == 2 (0x22: dtap,trans_sms)
 DRLL Dispatching 04.08 message SMS:0x01 (0x9:0x1)
+DLSMS receiving data (trans_id=0, msg_type=SMS:0x01)
 DMM RAN_conn(IMSI-901700000010650:MSISDN-42342:GERAN-A-0:PAGING_RESP){RAN_CONN_S_COMMUNICATING}: Received Event RAN_CONN_E_COMMUNICATING
+DLSMS SMC(0) message MMSMS-DATA-IND (CP DATA) received in state MM_ESTABLISHED
+DLSMS SMC(0) received CP-DATA
+DLSMS sending CP message (trans=0)
+DLSMS GSM4.11 TX 09 04 
 DMSC msc_tx 2 bytes to IMSI-901700000010650:MSISDN-42342 via GERAN-A
 - DTAP --GERAN-A--> MS: SMS:0x04: 0904
 - DTAP matches expected message
+DLSMS MNSMS-DATA/EST-IND
+DLSMS SMR(0) message MNSMS-DATA-IND received in state WAIT_FOR_RP_ACK
+DLSMS SMR(0) RX SMS RP-ACK
+DLSMS SMR(0) new RP state WAIT_FOR_RP_ACK -> IDLE
+DLSMS RX SMS RP-ACK (MO)
 DREF VLR subscr IMSI-901700000010650:MSISDN-42342 usage decreases to: 3
+DLSMS SMR(0) TX: MNSMS-REL-REQ
+DLSMS SMC(0) message MNSMS-REL-REQ received in state MM_ESTABLISHED
+DLSMS SMC(0) new CP state MM_ESTABLISHED -> IDLE
+DLSMS Got MMSMS_REL_REQ, destroying transaction.
+DLSMS SMR(0) clearing SMR instance
+DLSMS SMC(0) clearing instance
 DREF VLR subscr IMSI-901700000010650:MSISDN-42342 usage decreases to: 2
 DREF IMSI-901700000010650:MSISDN-42342: MSC conn use - trans_sms == 1 (0x2: dtap)
 DREF IMSI-901700000010650:MSISDN-42342: MSC conn use - dtap == 0 (0x0: )
diff --git a/tests/msc_vlr/msc_vlr_test_gsm_ciph.err b/tests/msc_vlr/msc_vlr_test_gsm_ciph.err
index 65e182c..8ed0d45 100644
--- a/tests/msc_vlr/msc_vlr_test_gsm_ciph.err
+++ b/tests/msc_vlr/msc_vlr_test_gsm_ciph.err
@@ -298,8 +298,17 @@
 DREF VLR subscr IMSI-901700000004620:MSISDN-46071 usage increases to: 2
   llist_count(&vsub->cs.requests) == 0
 DREF VLR subscr IMSI-901700000004620:MSISDN-46071 usage increases to: 3
+DLSMS Going to send a MT SMS
 DCC (ti 00 sub IMSI-901700000004620:MSISDN-46071 callref 40000001) New transaction
 DREF VLR subscr IMSI-901700000004620:MSISDN-46071 usage increases to: 4
+DLSMS SMC(0) instance created for network
+DLSMS SMR(0) instance created for network.
+DLSMS SMR(0) message SM-RL-DATA_REQ received in state IDLE
+DLSMS SMR(0) TX SMS RP-DATA
+DLSMS SMR(0) new RP state IDLE -> WAIT_FOR_RP_ACK
+DLSMS SMC(0) message MNSMS-EST-REQ received in state IDLE
+DLSMS SMC(0) new CP state IDLE -> MM_CONN_PENDING
+DLSMS Initiating Paging procedure for IMSI-901700000004620:MSISDN-46071 due to MMSMS_EST_REQ
 DMM Subscriber IMSI-901700000004620:MSISDN-46071 not paged yet, start paging.
   GERAN-A sends out paging request to IMSI 901700000004620, TMSI 0xffffffff, LAC 23
   strcmp(paging_expecting_imsi, imsi) == 0
@@ -407,7 +416,13 @@
 DMM RAN_conn(IMSI-901700000004620:MSISDN-46071:GERAN-A-0:PAGING_RESP){RAN_CONN_S_AUTH_CIPH}: Received Event RAN_CONN_E_ACCEPTED
 DPAG Paging success for IMSI-901700000004620:MSISDN-46071 (event=0)
 DPAG Calling paging cbfn.
+DLSMS paging_cb_mmsms_est_req(hooknum=1, event=0)
 DREF IMSI-901700000004620:MSISDN-46071: MSC conn use + trans_sms == 1 (0x20: trans_sms)
+DLSMS SMC(0) message MMSMS-EST-CNF received in state MM_CONN_PENDING
+DLSMS SMC(0) send CP data
+DLSMS SMC(0) new CP state MM_CONN_PENDING -> WAIT_CP_ACK
+DLSMS sending CP message (trans=0)
+DLSMS GSM4.11 TX 09 01 58 01 00 07 91 44 77 58 10 06 50 00 4c 00 05 80 64 70 f1 00 00 07 10 10 00 00 00 00 44 50 79 da 1e 1e e7 41 69 37 48 5e 9e a7 c9 65 37 3d 1d 66 83 c2 70 38 3b 3d 0e d3 d3 6f f7 1c 94 9e 83 c2 20 72 79 9e 96 87 c5 ec 32 a8 1d 96 af cb f4 b4 fb 0c 7a c3 e9 e9 b7 db 05 
 DMSC msc_tx 91 bytes to IMSI-901700000004620:MSISDN-46071 via GERAN-A
 - DTAP --GERAN-A--> MS: SMS:0x01: 09015801000791447758100650004c0005806470f1000007101000000000445079da1e1ee7416937485e9ea7c965373d1d6683c270383b3d0ed3d36ff71c949e83c22072799e9687c5ec32a81d96afcbf4b4fb0c7ac3e9e9b7db05
 - DTAP matches expected message
@@ -426,19 +441,39 @@
   MSC <--GERAN-A-- MS: SMS:0x04
 DREF IMSI-901700000004620:MSISDN-46071: MSC conn use + dtap == 2 (0x22: dtap,trans_sms)
 DRLL Dispatching 04.08 message SMS:0x04 (0x9:0x4)
+DLSMS receiving data (trans_id=0, msg_type=SMS:0x04)
 DMM RAN_conn(IMSI-901700000004620:MSISDN-46071:GERAN-A-0:PAGING_RESP){RAN_CONN_S_ACCEPTED}: Received Event RAN_CONN_E_COMMUNICATING
 DMM RAN_conn(IMSI-901700000004620:MSISDN-46071:GERAN-A-0:PAGING_RESP){RAN_CONN_S_ACCEPTED}: state_chg to RAN_CONN_S_COMMUNICATING
+DLSMS SMC(0) message MMSMS-DATA-IND (CP ACK) received in state WAIT_CP_ACK
+DLSMS SMC(0) received CP-ACK
+DLSMS SMC(0) new CP state WAIT_CP_ACK -> MM_ESTABLISHED
 DREF IMSI-901700000004620:MSISDN-46071: MSC conn use - dtap == 1 (0x20: trans_sms)
   llist_count(&net->ran_conns) == 1
 - MS also sends RP-ACK, MSC in turn sends CP-ACK for that
   MSC <--GERAN-A-- MS: SMS:0x01
 DREF IMSI-901700000004620:MSISDN-46071: MSC conn use + dtap == 2 (0x22: dtap,trans_sms)
 DRLL Dispatching 04.08 message SMS:0x01 (0x9:0x1)
+DLSMS receiving data (trans_id=0, msg_type=SMS:0x01)
 DMM RAN_conn(IMSI-901700000004620:MSISDN-46071:GERAN-A-0:PAGING_RESP){RAN_CONN_S_COMMUNICATING}: Received Event RAN_CONN_E_COMMUNICATING
+DLSMS SMC(0) message MMSMS-DATA-IND (CP DATA) received in state MM_ESTABLISHED
+DLSMS SMC(0) received CP-DATA
+DLSMS sending CP message (trans=0)
+DLSMS GSM4.11 TX 09 04 
 DMSC msc_tx 2 bytes to IMSI-901700000004620:MSISDN-46071 via GERAN-A
 - DTAP --GERAN-A--> MS: SMS:0x04: 0904
 - DTAP matches expected message
+DLSMS MNSMS-DATA/EST-IND
+DLSMS SMR(0) message MNSMS-DATA-IND received in state WAIT_FOR_RP_ACK
+DLSMS SMR(0) RX SMS RP-ACK
+DLSMS SMR(0) new RP state WAIT_FOR_RP_ACK -> IDLE
+DLSMS RX SMS RP-ACK (MO)
 DREF VLR subscr IMSI-901700000004620:MSISDN-46071 usage decreases to: 3
+DLSMS SMR(0) TX: MNSMS-REL-REQ
+DLSMS SMC(0) message MNSMS-REL-REQ received in state MM_ESTABLISHED
+DLSMS SMC(0) new CP state MM_ESTABLISHED -> IDLE
+DLSMS Got MMSMS_REL_REQ, destroying transaction.
+DLSMS SMR(0) clearing SMR instance
+DLSMS SMC(0) clearing instance
 DREF VLR subscr IMSI-901700000004620:MSISDN-46071 usage decreases to: 2
 DREF IMSI-901700000004620:MSISDN-46071: MSC conn use - trans_sms == 1 (0x2: dtap)
 DREF IMSI-901700000004620:MSISDN-46071: MSC conn use - dtap == 0 (0x0: )
@@ -838,8 +873,17 @@
 DREF VLR subscr IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100 usage increases to: 2
   llist_count(&vsub->cs.requests) == 0
 DREF VLR subscr IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100 usage increases to: 3
+DLSMS Going to send a MT SMS
 DCC (ti 00 sub IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100 callref 40000002) New transaction
 DREF VLR subscr IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100 usage increases to: 4
+DLSMS SMC(0) instance created for network
+DLSMS SMR(0) instance created for network.
+DLSMS SMR(0) message SM-RL-DATA_REQ received in state IDLE
+DLSMS SMR(0) TX SMS RP-DATA
+DLSMS SMR(0) new RP state IDLE -> WAIT_FOR_RP_ACK
+DLSMS SMC(0) message MNSMS-EST-REQ received in state IDLE
+DLSMS SMC(0) new CP state IDLE -> MM_CONN_PENDING
+DLSMS Initiating Paging procedure for IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100 due to MMSMS_EST_REQ
 DMM Subscriber IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100 not paged yet, start paging.
   GERAN-A sends out paging request to IMSI 901700000004620, TMSI 0x03020100, LAC 23
   paging_expecting_tmsi == 0x03020100
@@ -947,7 +991,13 @@
 DMM RAN_conn(IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100:GERAN-A-0:PAGING_RESP){RAN_CONN_S_AUTH_CIPH}: Received Event RAN_CONN_E_ACCEPTED
 DPAG Paging success for IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100 (event=0)
 DPAG Calling paging cbfn.
+DLSMS paging_cb_mmsms_est_req(hooknum=1, event=0)
 DREF IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100: MSC conn use + trans_sms == 1 (0x20: trans_sms)
+DLSMS SMC(0) message MMSMS-EST-CNF received in state MM_CONN_PENDING
+DLSMS SMC(0) send CP data
+DLSMS SMC(0) new CP state MM_CONN_PENDING -> WAIT_CP_ACK
+DLSMS sending CP message (trans=0)
+DLSMS GSM4.11 TX 09 01 58 01 00 07 91 44 77 58 10 06 50 00 4c 00 05 80 64 70 f1 00 00 07 10 10 00 00 00 00 44 50 79 da 1e 1e e7 41 69 37 48 5e 9e a7 c9 65 37 3d 1d 66 83 c2 70 38 3b 3d 0e d3 d3 6f f7 1c 94 9e 83 c2 20 72 79 9e 96 87 c5 ec 32 a8 1d 96 af cb f4 b4 fb 0c 7a c3 e9 e9 b7 db 05 
 DMSC msc_tx 91 bytes to IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100 via GERAN-A
 - DTAP --GERAN-A--> MS: SMS:0x01: 09015801000791447758100650004c0005806470f1000007101000000000445079da1e1ee7416937485e9ea7c965373d1d6683c270383b3d0ed3d36ff71c949e83c22072799e9687c5ec32a81d96afcbf4b4fb0c7ac3e9e9b7db05
 - DTAP matches expected message
@@ -966,19 +1016,39 @@
   MSC <--GERAN-A-- MS: SMS:0x04
 DREF IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100: MSC conn use + dtap == 2 (0x22: dtap,trans_sms)
 DRLL Dispatching 04.08 message SMS:0x04 (0x9:0x4)
+DLSMS receiving data (trans_id=0, msg_type=SMS:0x04)
 DMM RAN_conn(IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100:GERAN-A-0:PAGING_RESP){RAN_CONN_S_ACCEPTED}: Received Event RAN_CONN_E_COMMUNICATING
 DMM RAN_conn(IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100:GERAN-A-0:PAGING_RESP){RAN_CONN_S_ACCEPTED}: state_chg to RAN_CONN_S_COMMUNICATING
+DLSMS SMC(0) message MMSMS-DATA-IND (CP ACK) received in state WAIT_CP_ACK
+DLSMS SMC(0) received CP-ACK
+DLSMS SMC(0) new CP state WAIT_CP_ACK -> MM_ESTABLISHED
 DREF IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100: MSC conn use - dtap == 1 (0x20: trans_sms)
   llist_count(&net->ran_conns) == 1
 - MS also sends RP-ACK, MSC in turn sends CP-ACK for that
   MSC <--GERAN-A-- MS: SMS:0x01
 DREF IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100: MSC conn use + dtap == 2 (0x22: dtap,trans_sms)
 DRLL Dispatching 04.08 message SMS:0x01 (0x9:0x1)
+DLSMS receiving data (trans_id=0, msg_type=SMS:0x01)
 DMM RAN_conn(IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100:GERAN-A-0:PAGING_RESP){RAN_CONN_S_COMMUNICATING}: Received Event RAN_CONN_E_COMMUNICATING
+DLSMS SMC(0) message MMSMS-DATA-IND (CP DATA) received in state MM_ESTABLISHED
+DLSMS SMC(0) received CP-DATA
+DLSMS sending CP message (trans=0)
+DLSMS GSM4.11 TX 09 04 
 DMSC msc_tx 2 bytes to IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100 via GERAN-A
 - DTAP --GERAN-A--> MS: SMS:0x04: 0904
 - DTAP matches expected message
+DLSMS MNSMS-DATA/EST-IND
+DLSMS SMR(0) message MNSMS-DATA-IND received in state WAIT_FOR_RP_ACK
+DLSMS SMR(0) RX SMS RP-ACK
+DLSMS SMR(0) new RP state WAIT_FOR_RP_ACK -> IDLE
+DLSMS RX SMS RP-ACK (MO)
 DREF VLR subscr IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100 usage decreases to: 3
+DLSMS SMR(0) TX: MNSMS-REL-REQ
+DLSMS SMC(0) message MNSMS-REL-REQ received in state MM_ESTABLISHED
+DLSMS SMC(0) new CP state MM_ESTABLISHED -> IDLE
+DLSMS Got MMSMS_REL_REQ, destroying transaction.
+DLSMS SMR(0) clearing SMR instance
+DLSMS SMC(0) clearing instance
 DREF VLR subscr IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100 usage decreases to: 2
 DREF IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100: MSC conn use - trans_sms == 1 (0x2: dtap)
 DREF IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100: MSC conn use - dtap == 0 (0x0: )
@@ -2046,8 +2116,17 @@
 DREF VLR subscr IMSI-901700000010650:MSISDN-42342 usage increases to: 2
   llist_count(&vsub->cs.requests) == 0
 DREF VLR subscr IMSI-901700000010650:MSISDN-42342 usage increases to: 3
+DLSMS Going to send a MT SMS
 DCC (ti 00 sub IMSI-901700000010650:MSISDN-42342 callref 40000003) New transaction
 DREF VLR subscr IMSI-901700000010650:MSISDN-42342 usage increases to: 4
+DLSMS SMC(0) instance created for network
+DLSMS SMR(0) instance created for network.
+DLSMS SMR(0) message SM-RL-DATA_REQ received in state IDLE
+DLSMS SMR(0) TX SMS RP-DATA
+DLSMS SMR(0) new RP state IDLE -> WAIT_FOR_RP_ACK
+DLSMS SMC(0) message MNSMS-EST-REQ received in state IDLE
+DLSMS SMC(0) new CP state IDLE -> MM_CONN_PENDING
+DLSMS Initiating Paging procedure for IMSI-901700000010650:MSISDN-42342 due to MMSMS_EST_REQ
 DMM Subscriber IMSI-901700000010650:MSISDN-42342 not paged yet, start paging.
   GERAN-A sends out paging request to IMSI 901700000010650, TMSI 0xffffffff, LAC 23
   strcmp(paging_expecting_imsi, imsi) == 0
@@ -2145,7 +2224,13 @@
 DMM RAN_conn(IMSI-901700000010650:MSISDN-42342:GERAN-A-0:PAGING_RESP){RAN_CONN_S_AUTH_CIPH}: Received Event RAN_CONN_E_ACCEPTED
 DPAG Paging success for IMSI-901700000010650:MSISDN-42342 (event=0)
 DPAG Calling paging cbfn.
+DLSMS paging_cb_mmsms_est_req(hooknum=1, event=0)
 DREF IMSI-901700000010650:MSISDN-42342: MSC conn use + trans_sms == 1 (0x20: trans_sms)
+DLSMS SMC(0) message MMSMS-EST-CNF received in state MM_CONN_PENDING
+DLSMS SMC(0) send CP data
+DLSMS SMC(0) new CP state MM_CONN_PENDING -> WAIT_CP_ACK
+DLSMS sending CP message (trans=0)
+DLSMS GSM4.11 TX 09 01 58 01 00 07 91 44 77 58 10 06 50 00 4c 00 05 80 24 43 f2 00 00 07 10 10 00 00 00 00 44 50 79 da 1e 1e e7 41 69 37 48 5e 9e a7 c9 65 37 3d 1d 66 83 c2 70 38 3b 3d 0e d3 d3 6f f7 1c 94 9e 83 c2 20 72 79 9e 96 87 c5 ec 32 a8 1d 96 af cb f4 b4 fb 0c 7a c3 e9 e9 b7 db 05 
 DMSC msc_tx 91 bytes to IMSI-901700000010650:MSISDN-42342 via GERAN-A
 - DTAP --GERAN-A--> MS: SMS:0x01: 09015801000791447758100650004c0005802443f2000007101000000000445079da1e1ee7416937485e9ea7c965373d1d6683c270383b3d0ed3d36ff71c949e83c22072799e9687c5ec32a81d96afcbf4b4fb0c7ac3e9e9b7db05
 - DTAP matches expected message
@@ -2164,19 +2249,39 @@
   MSC <--GERAN-A-- MS: SMS:0x04
 DREF IMSI-901700000010650:MSISDN-42342: MSC conn use + dtap == 2 (0x22: dtap,trans_sms)
 DRLL Dispatching 04.08 message SMS:0x04 (0x9:0x4)
+DLSMS receiving data (trans_id=0, msg_type=SMS:0x04)
 DMM RAN_conn(IMSI-901700000010650:MSISDN-42342:GERAN-A-0:PAGING_RESP){RAN_CONN_S_ACCEPTED}: Received Event RAN_CONN_E_COMMUNICATING
 DMM RAN_conn(IMSI-901700000010650:MSISDN-42342:GERAN-A-0:PAGING_RESP){RAN_CONN_S_ACCEPTED}: state_chg to RAN_CONN_S_COMMUNICATING
+DLSMS SMC(0) message MMSMS-DATA-IND (CP ACK) received in state WAIT_CP_ACK
+DLSMS SMC(0) received CP-ACK
+DLSMS SMC(0) new CP state WAIT_CP_ACK -> MM_ESTABLISHED
 DREF IMSI-901700000010650:MSISDN-42342: MSC conn use - dtap == 1 (0x20: trans_sms)
   llist_count(&net->ran_conns) == 1
 - MS also sends RP-ACK, MSC in turn sends CP-ACK for that
   MSC <--GERAN-A-- MS: SMS:0x01
 DREF IMSI-901700000010650:MSISDN-42342: MSC conn use + dtap == 2 (0x22: dtap,trans_sms)
 DRLL Dispatching 04.08 message SMS:0x01 (0x9:0x1)
+DLSMS receiving data (trans_id=0, msg_type=SMS:0x01)
 DMM RAN_conn(IMSI-901700000010650:MSISDN-42342:GERAN-A-0:PAGING_RESP){RAN_CONN_S_COMMUNICATING}: Received Event RAN_CONN_E_COMMUNICATING
+DLSMS SMC(0) message MMSMS-DATA-IND (CP DATA) received in state MM_ESTABLISHED
+DLSMS SMC(0) received CP-DATA
+DLSMS sending CP message (trans=0)
+DLSMS GSM4.11 TX 09 04 
 DMSC msc_tx 2 bytes to IMSI-901700000010650:MSISDN-42342 via GERAN-A
 - DTAP --GERAN-A--> MS: SMS:0x04: 0904
 - DTAP matches expected message
+DLSMS MNSMS-DATA/EST-IND
+DLSMS SMR(0) message MNSMS-DATA-IND received in state WAIT_FOR_RP_ACK
+DLSMS SMR(0) RX SMS RP-ACK
+DLSMS SMR(0) new RP state WAIT_FOR_RP_ACK -> IDLE
+DLSMS RX SMS RP-ACK (MO)
 DREF VLR subscr IMSI-901700000010650:MSISDN-42342 usage decreases to: 3
+DLSMS SMR(0) TX: MNSMS-REL-REQ
+DLSMS SMC(0) message MNSMS-REL-REQ received in state MM_ESTABLISHED
+DLSMS SMC(0) new CP state MM_ESTABLISHED -> IDLE
+DLSMS Got MMSMS_REL_REQ, destroying transaction.
+DLSMS SMR(0) clearing SMR instance
+DLSMS SMC(0) clearing instance
 DREF VLR subscr IMSI-901700000010650:MSISDN-42342 usage decreases to: 2
 DREF IMSI-901700000010650:MSISDN-42342: MSC conn use - trans_sms == 1 (0x2: dtap)
 DREF IMSI-901700000010650:MSISDN-42342: MSC conn use - dtap == 0 (0x0: )
@@ -2536,8 +2641,17 @@
 DREF VLR subscr IMSI-901700000004620:MSISDN-42342 usage increases to: 2
   llist_count(&vsub->cs.requests) == 0
 DREF VLR subscr IMSI-901700000004620:MSISDN-42342 usage increases to: 3
+DLSMS Going to send a MT SMS
 DCC (ti 00 sub IMSI-901700000004620:MSISDN-42342 callref 40000004) New transaction
 DREF VLR subscr IMSI-901700000004620:MSISDN-42342 usage increases to: 4
+DLSMS SMC(0) instance created for network
+DLSMS SMR(0) instance created for network.
+DLSMS SMR(0) message SM-RL-DATA_REQ received in state IDLE
+DLSMS SMR(0) TX SMS RP-DATA
+DLSMS SMR(0) new RP state IDLE -> WAIT_FOR_RP_ACK
+DLSMS SMC(0) message MNSMS-EST-REQ received in state IDLE
+DLSMS SMC(0) new CP state IDLE -> MM_CONN_PENDING
+DLSMS Initiating Paging procedure for IMSI-901700000004620:MSISDN-42342 due to MMSMS_EST_REQ
 DMM Subscriber IMSI-901700000004620:MSISDN-42342 not paged yet, start paging.
   GERAN-A sends out paging request to IMSI 901700000004620, TMSI 0xffffffff, LAC 23
   strcmp(paging_expecting_imsi, imsi) == 0
@@ -2645,7 +2759,13 @@
 DMM RAN_conn(IMSI-901700000004620:MSISDN-42342:GERAN-A-0:PAGING_RESP){RAN_CONN_S_AUTH_CIPH}: Received Event RAN_CONN_E_ACCEPTED
 DPAG Paging success for IMSI-901700000004620:MSISDN-42342 (event=0)
 DPAG Calling paging cbfn.
+DLSMS paging_cb_mmsms_est_req(hooknum=1, event=0)
 DREF IMSI-901700000004620:MSISDN-42342: MSC conn use + trans_sms == 1 (0x20: trans_sms)
+DLSMS SMC(0) message MMSMS-EST-CNF received in state MM_CONN_PENDING
+DLSMS SMC(0) send CP data
+DLSMS SMC(0) new CP state MM_CONN_PENDING -> WAIT_CP_ACK
+DLSMS sending CP message (trans=0)
+DLSMS GSM4.11 TX 09 01 58 01 00 07 91 44 77 58 10 06 50 00 4c 00 05 80 24 43 f2 00 00 07 10 10 00 00 00 00 44 50 79 da 1e 1e e7 41 69 37 48 5e 9e a7 c9 65 37 3d 1d 66 83 c2 70 38 3b 3d 0e d3 d3 6f f7 1c 94 9e 83 c2 20 72 79 9e 96 87 c5 ec 32 a8 1d 96 af cb f4 b4 fb 0c 7a c3 e9 e9 b7 db 05 
 DMSC msc_tx 91 bytes to IMSI-901700000004620:MSISDN-42342 via GERAN-A
 - DTAP --GERAN-A--> MS: SMS:0x01: 09015801000791447758100650004c0005802443f2000007101000000000445079da1e1ee7416937485e9ea7c965373d1d6683c270383b3d0ed3d36ff71c949e83c22072799e9687c5ec32a81d96afcbf4b4fb0c7ac3e9e9b7db05
 - DTAP matches expected message
@@ -2664,19 +2784,39 @@
   MSC <--GERAN-A-- MS: SMS:0x04
 DREF IMSI-901700000004620:MSISDN-42342: MSC conn use + dtap == 2 (0x22: dtap,trans_sms)
 DRLL Dispatching 04.08 message SMS:0x04 (0x9:0x4)
+DLSMS receiving data (trans_id=0, msg_type=SMS:0x04)
 DMM RAN_conn(IMSI-901700000004620:MSISDN-42342:GERAN-A-0:PAGING_RESP){RAN_CONN_S_ACCEPTED}: Received Event RAN_CONN_E_COMMUNICATING
 DMM RAN_conn(IMSI-901700000004620:MSISDN-42342:GERAN-A-0:PAGING_RESP){RAN_CONN_S_ACCEPTED}: state_chg to RAN_CONN_S_COMMUNICATING
+DLSMS SMC(0) message MMSMS-DATA-IND (CP ACK) received in state WAIT_CP_ACK
+DLSMS SMC(0) received CP-ACK
+DLSMS SMC(0) new CP state WAIT_CP_ACK -> MM_ESTABLISHED
 DREF IMSI-901700000004620:MSISDN-42342: MSC conn use - dtap == 1 (0x20: trans_sms)
   llist_count(&net->ran_conns) == 1
 - MS also sends RP-ACK, MSC in turn sends CP-ACK for that
   MSC <--GERAN-A-- MS: SMS:0x01
 DREF IMSI-901700000004620:MSISDN-42342: MSC conn use + dtap == 2 (0x22: dtap,trans_sms)
 DRLL Dispatching 04.08 message SMS:0x01 (0x9:0x1)
+DLSMS receiving data (trans_id=0, msg_type=SMS:0x01)
 DMM RAN_conn(IMSI-901700000004620:MSISDN-42342:GERAN-A-0:PAGING_RESP){RAN_CONN_S_COMMUNICATING}: Received Event RAN_CONN_E_COMMUNICATING
+DLSMS SMC(0) message MMSMS-DATA-IND (CP DATA) received in state MM_ESTABLISHED
+DLSMS SMC(0) received CP-DATA
+DLSMS sending CP message (trans=0)
+DLSMS GSM4.11 TX 09 04 
 DMSC msc_tx 2 bytes to IMSI-901700000004620:MSISDN-42342 via GERAN-A
 - DTAP --GERAN-A--> MS: SMS:0x04: 0904
 - DTAP matches expected message
+DLSMS MNSMS-DATA/EST-IND
+DLSMS SMR(0) message MNSMS-DATA-IND received in state WAIT_FOR_RP_ACK
+DLSMS SMR(0) RX SMS RP-ACK
+DLSMS SMR(0) new RP state WAIT_FOR_RP_ACK -> IDLE
+DLSMS RX SMS RP-ACK (MO)
 DREF VLR subscr IMSI-901700000004620:MSISDN-42342 usage decreases to: 3
+DLSMS SMR(0) TX: MNSMS-REL-REQ
+DLSMS SMC(0) message MNSMS-REL-REQ received in state MM_ESTABLISHED
+DLSMS SMC(0) new CP state MM_ESTABLISHED -> IDLE
+DLSMS Got MMSMS_REL_REQ, destroying transaction.
+DLSMS SMR(0) clearing SMR instance
+DLSMS SMC(0) clearing instance
 DREF VLR subscr IMSI-901700000004620:MSISDN-42342 usage decreases to: 2
 DREF IMSI-901700000004620:MSISDN-42342: MSC conn use - trans_sms == 1 (0x2: dtap)
 DREF IMSI-901700000004620:MSISDN-42342: MSC conn use - dtap == 0 (0x0: )
@@ -3036,8 +3176,17 @@
 DREF VLR subscr IMSI-901700000004620:MSISDN-42342 usage increases to: 2
   llist_count(&vsub->cs.requests) == 0
 DREF VLR subscr IMSI-901700000004620:MSISDN-42342 usage increases to: 3
+DLSMS Going to send a MT SMS
 DCC (ti 00 sub IMSI-901700000004620:MSISDN-42342 callref 40000005) New transaction
 DREF VLR subscr IMSI-901700000004620:MSISDN-42342 usage increases to: 4
+DLSMS SMC(0) instance created for network
+DLSMS SMR(0) instance created for network.
+DLSMS SMR(0) message SM-RL-DATA_REQ received in state IDLE
+DLSMS SMR(0) TX SMS RP-DATA
+DLSMS SMR(0) new RP state IDLE -> WAIT_FOR_RP_ACK
+DLSMS SMC(0) message MNSMS-EST-REQ received in state IDLE
+DLSMS SMC(0) new CP state IDLE -> MM_CONN_PENDING
+DLSMS Initiating Paging procedure for IMSI-901700000004620:MSISDN-42342 due to MMSMS_EST_REQ
 DMM Subscriber IMSI-901700000004620:MSISDN-42342 not paged yet, start paging.
   GERAN-A sends out paging request to IMSI 901700000004620, TMSI 0xffffffff, LAC 23
   strcmp(paging_expecting_imsi, imsi) == 0
@@ -3140,7 +3289,13 @@
 DMM RAN_conn(IMSI-901700000004620:MSISDN-42342:GERAN-A-0:PAGING_RESP){RAN_CONN_S_AUTH_CIPH}: Received Event RAN_CONN_E_ACCEPTED
 DPAG Paging success for IMSI-901700000004620:MSISDN-42342 (event=0)
 DPAG Calling paging cbfn.
+DLSMS paging_cb_mmsms_est_req(hooknum=1, event=0)
 DREF IMSI-901700000004620:MSISDN-42342: MSC conn use + trans_sms == 1 (0x20: trans_sms)
+DLSMS SMC(0) message MMSMS-EST-CNF received in state MM_CONN_PENDING
+DLSMS SMC(0) send CP data
+DLSMS SMC(0) new CP state MM_CONN_PENDING -> WAIT_CP_ACK
+DLSMS sending CP message (trans=0)
+DLSMS GSM4.11 TX 09 01 58 01 00 07 91 44 77 58 10 06 50 00 4c 00 05 80 24 43 f2 00 00 07 10 10 00 00 00 00 44 50 79 da 1e 1e e7 41 69 37 48 5e 9e a7 c9 65 37 3d 1d 66 83 c2 70 38 3b 3d 0e d3 d3 6f f7 1c 94 9e 83 c2 20 72 79 9e 96 87 c5 ec 32 a8 1d 96 af cb f4 b4 fb 0c 7a c3 e9 e9 b7 db 05 
 DMSC msc_tx 91 bytes to IMSI-901700000004620:MSISDN-42342 via GERAN-A
 - DTAP --GERAN-A--> MS: SMS:0x01: 09015801000791447758100650004c0005802443f2000007101000000000445079da1e1ee7416937485e9ea7c965373d1d6683c270383b3d0ed3d36ff71c949e83c22072799e9687c5ec32a81d96afcbf4b4fb0c7ac3e9e9b7db05
 - DTAP matches expected message
@@ -3159,19 +3314,39 @@
   MSC <--GERAN-A-- MS: SMS:0x04
 DREF IMSI-901700000004620:MSISDN-42342: MSC conn use + dtap == 2 (0x22: dtap,trans_sms)
 DRLL Dispatching 04.08 message SMS:0x04 (0x9:0x4)
+DLSMS receiving data (trans_id=0, msg_type=SMS:0x04)
 DMM RAN_conn(IMSI-901700000004620:MSISDN-42342:GERAN-A-0:PAGING_RESP){RAN_CONN_S_ACCEPTED}: Received Event RAN_CONN_E_COMMUNICATING
 DMM RAN_conn(IMSI-901700000004620:MSISDN-42342:GERAN-A-0:PAGING_RESP){RAN_CONN_S_ACCEPTED}: state_chg to RAN_CONN_S_COMMUNICATING
+DLSMS SMC(0) message MMSMS-DATA-IND (CP ACK) received in state WAIT_CP_ACK
+DLSMS SMC(0) received CP-ACK
+DLSMS SMC(0) new CP state WAIT_CP_ACK -> MM_ESTABLISHED
 DREF IMSI-901700000004620:MSISDN-42342: MSC conn use - dtap == 1 (0x20: trans_sms)
   llist_count(&net->ran_conns) == 1
 - MS also sends RP-ACK, MSC in turn sends CP-ACK for that
   MSC <--GERAN-A-- MS: SMS:0x01
 DREF IMSI-901700000004620:MSISDN-42342: MSC conn use + dtap == 2 (0x22: dtap,trans_sms)
 DRLL Dispatching 04.08 message SMS:0x01 (0x9:0x1)
+DLSMS receiving data (trans_id=0, msg_type=SMS:0x01)
 DMM RAN_conn(IMSI-901700000004620:MSISDN-42342:GERAN-A-0:PAGING_RESP){RAN_CONN_S_COMMUNICATING}: Received Event RAN_CONN_E_COMMUNICATING
+DLSMS SMC(0) message MMSMS-DATA-IND (CP DATA) received in state MM_ESTABLISHED
+DLSMS SMC(0) received CP-DATA
+DLSMS sending CP message (trans=0)
+DLSMS GSM4.11 TX 09 04 
 DMSC msc_tx 2 bytes to IMSI-901700000004620:MSISDN-42342 via GERAN-A
 - DTAP --GERAN-A--> MS: SMS:0x04: 0904
 - DTAP matches expected message
+DLSMS MNSMS-DATA/EST-IND
+DLSMS SMR(0) message MNSMS-DATA-IND received in state WAIT_FOR_RP_ACK
+DLSMS SMR(0) RX SMS RP-ACK
+DLSMS SMR(0) new RP state WAIT_FOR_RP_ACK -> IDLE
+DLSMS RX SMS RP-ACK (MO)
 DREF VLR subscr IMSI-901700000004620:MSISDN-42342 usage decreases to: 3
+DLSMS SMR(0) TX: MNSMS-REL-REQ
+DLSMS SMC(0) message MNSMS-REL-REQ received in state MM_ESTABLISHED
+DLSMS SMC(0) new CP state MM_ESTABLISHED -> IDLE
+DLSMS Got MMSMS_REL_REQ, destroying transaction.
+DLSMS SMR(0) clearing SMR instance
+DLSMS SMC(0) clearing instance
 DREF VLR subscr IMSI-901700000004620:MSISDN-42342 usage decreases to: 2
 DREF IMSI-901700000004620:MSISDN-42342: MSC conn use - trans_sms == 1 (0x2: dtap)
 DREF IMSI-901700000004620:MSISDN-42342: MSC conn use - dtap == 0 (0x0: )
diff --git a/tests/msc_vlr/msc_vlr_test_ms_timeout.err b/tests/msc_vlr/msc_vlr_test_ms_timeout.err
index 5372919..e09389c 100644
--- a/tests/msc_vlr/msc_vlr_test_ms_timeout.err
+++ b/tests/msc_vlr/msc_vlr_test_ms_timeout.err
@@ -461,8 +461,17 @@
 DREF VLR subscr IMSI-901700000004620:MSISDN-46071 usage increases to: 2
   llist_count(&vsub->cs.requests) == 0
 DREF VLR subscr IMSI-901700000004620:MSISDN-46071 usage increases to: 3
+DLSMS Going to send a MT SMS
 DCC (ti 00 sub IMSI-901700000004620:MSISDN-46071 callref 40000001) New transaction
 DREF VLR subscr IMSI-901700000004620:MSISDN-46071 usage increases to: 4
+DLSMS SMC(0) instance created for network
+DLSMS SMR(0) instance created for network.
+DLSMS SMR(0) message SM-RL-DATA_REQ received in state IDLE
+DLSMS SMR(0) TX SMS RP-DATA
+DLSMS SMR(0) new RP state IDLE -> WAIT_FOR_RP_ACK
+DLSMS SMC(0) message MNSMS-EST-REQ received in state IDLE
+DLSMS SMC(0) new CP state IDLE -> MM_CONN_PENDING
+DLSMS Initiating Paging procedure for IMSI-901700000004620:MSISDN-46071 due to MMSMS_EST_REQ
 DMM Subscriber IMSI-901700000004620:MSISDN-46071 not paged yet, start paging.
   GERAN-A sends out paging request to IMSI 901700000004620, TMSI 0xffffffff, LAC 23
   strcmp(paging_expecting_imsi, imsi) == 0
@@ -479,8 +488,17 @@
   vsub->cs.is_paging == 1
 - another request is added to the list but does not cause another paging
 DREF VLR subscr IMSI-901700000004620:MSISDN-46071 usage increases to: 6
+DLSMS Going to send a MT SMS
 DCC (ti 01 sub IMSI-901700000004620:MSISDN-46071 callref 40000002) New transaction
 DREF VLR subscr IMSI-901700000004620:MSISDN-46071 usage increases to: 7
+DLSMS SMC(0) instance created for network
+DLSMS SMR(0) instance created for network.
+DLSMS SMR(0) message SM-RL-DATA_REQ received in state IDLE
+DLSMS SMR(0) TX SMS RP-DATA
+DLSMS SMR(0) new RP state IDLE -> WAIT_FOR_RP_ACK
+DLSMS SMC(0) message MNSMS-EST-REQ received in state IDLE
+DLSMS SMC(0) new CP state IDLE -> MM_CONN_PENDING
+DLSMS Initiating Paging procedure for IMSI-901700000004620:MSISDN-46071 due to MMSMS_EST_REQ
 DMM Subscriber IMSI-901700000004620:MSISDN-46071 already paged.
   llist_count(&vsub->cs.requests) == 2
 DREF VLR subscr IMSI-901700000004620:MSISDN-46071 usage decreases to: 6
@@ -489,10 +507,34 @@
 - Total time passed: 11.000000 s
 DPAG Paging failure for IMSI-901700000004620:MSISDN-46071 (event=1)
 DPAG Calling paging cbfn.
+DLSMS paging_cb_mmsms_est_req(hooknum=1, event=1)
+DLSMS SMC(0) message MMSMS-REL-IND received in state MM_CONN_PENDING
+DLSMS SMC(0) MM layer is released
+DLSMS SMC(0) new CP state MM_CONN_PENDING -> IDLE
+DLSMS MNSMS-ERROR-IND, no cause
+DLSMS SMR(0) message MNSMS-ERROR-IND received in state WAIT_FOR_RP_ACK
+DLSMS SMR(0) TX SMS MNSMS-ERROR-IND
+DLSMS SMR(0) new RP state WAIT_FOR_RP_ACK -> IDLE
+DLSMS SMR(0) TX: MNSMS-REL-REQ
+DLSMS SMC(0) message MNSMS-REL-REQ received in state IDLE
 DREF VLR subscr IMSI-901700000004620:MSISDN-46071 usage decreases to: 5
+DLSMS SMR(0) clearing SMR instance
+DLSMS SMC(0) clearing instance
 DREF VLR subscr IMSI-901700000004620:MSISDN-46071 usage decreases to: 4
 DPAG Calling paging cbfn.
+DLSMS paging_cb_mmsms_est_req(hooknum=1, event=1)
+DLSMS SMC(0) message MMSMS-REL-IND received in state MM_CONN_PENDING
+DLSMS SMC(0) MM layer is released
+DLSMS SMC(0) new CP state MM_CONN_PENDING -> IDLE
+DLSMS MNSMS-ERROR-IND, no cause
+DLSMS SMR(0) message MNSMS-ERROR-IND received in state WAIT_FOR_RP_ACK
+DLSMS SMR(0) TX SMS MNSMS-ERROR-IND
+DLSMS SMR(0) new RP state WAIT_FOR_RP_ACK -> IDLE
+DLSMS SMR(0) TX: MNSMS-REL-REQ
+DLSMS SMC(0) message MNSMS-REL-REQ received in state IDLE
 DREF VLR subscr IMSI-901700000004620:MSISDN-46071 usage decreases to: 3
+DLSMS SMR(0) clearing SMR instance
+DLSMS SMC(0) clearing instance
 DREF VLR subscr IMSI-901700000004620:MSISDN-46071 usage decreases to: 2
 DREF VLR subscr IMSI-901700000004620:MSISDN-46071 usage decreases to: 1
   paging_stopped == 1
@@ -502,8 +544,17 @@
 ---
 - Now that the timeout has expired, another Paging is sent on request
 DREF VLR subscr IMSI-901700000004620:MSISDN-46071 usage increases to: 3
+DLSMS Going to send a MT SMS
 DCC (ti 00 sub IMSI-901700000004620:MSISDN-46071 callref 40000003) New transaction
 DREF VLR subscr IMSI-901700000004620:MSISDN-46071 usage increases to: 4
+DLSMS SMC(0) instance created for network
+DLSMS SMR(0) instance created for network.
+DLSMS SMR(0) message SM-RL-DATA_REQ received in state IDLE
+DLSMS SMR(0) TX SMS RP-DATA
+DLSMS SMR(0) new RP state IDLE -> WAIT_FOR_RP_ACK
+DLSMS SMC(0) message MNSMS-EST-REQ received in state IDLE
+DLSMS SMC(0) new CP state IDLE -> MM_CONN_PENDING
+DLSMS Initiating Paging procedure for IMSI-901700000004620:MSISDN-46071 due to MMSMS_EST_REQ
 DMM Subscriber IMSI-901700000004620:MSISDN-46071 not paged yet, start paging.
   GERAN-A sends out paging request to IMSI 901700000004620, TMSI 0xffffffff, LAC 23
   strcmp(paging_expecting_imsi, imsi) == 0
@@ -524,7 +575,19 @@
 DMM IMSI DETACH for IMSI-901700000004620:MSISDN-46071
 DPAG Paging failure for IMSI-901700000004620:MSISDN-46071 (event=1)
 DPAG Calling paging cbfn.
+DLSMS paging_cb_mmsms_est_req(hooknum=1, event=1)
+DLSMS SMC(0) message MMSMS-REL-IND received in state MM_CONN_PENDING
+DLSMS SMC(0) MM layer is released
+DLSMS SMC(0) new CP state MM_CONN_PENDING -> IDLE
+DLSMS MNSMS-ERROR-IND, no cause
+DLSMS SMR(0) message MNSMS-ERROR-IND received in state WAIT_FOR_RP_ACK
+DLSMS SMR(0) TX SMS MNSMS-ERROR-IND
+DLSMS SMR(0) new RP state WAIT_FOR_RP_ACK -> IDLE
+DLSMS SMR(0) TX: MNSMS-REL-REQ
+DLSMS SMC(0) message MNSMS-REL-REQ received in state IDLE
 DREF VLR subscr IMSI-901700000004620:MSISDN-46071 usage decreases to: 4
+DLSMS SMR(0) clearing SMR instance
+DLSMS SMC(0) clearing instance
 DREF VLR subscr IMSI-901700000004620:MSISDN-46071 usage decreases to: 3
 DREF VLR subscr IMSI-901700000004620:MSISDN-46071 usage decreases to: 2
 DREF VLR subscr IMSI-901700000004620: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 3e28468..61ac09f 100644
--- a/tests/msc_vlr/msc_vlr_test_no_authen.err
+++ b/tests/msc_vlr/msc_vlr_test_no_authen.err
@@ -182,8 +182,17 @@
 DREF VLR subscr IMSI-901700000004620:MSISDN-46071 usage increases to: 2
   llist_count(&vsub->cs.requests) == 0
 DREF VLR subscr IMSI-901700000004620:MSISDN-46071 usage increases to: 3
+DLSMS Going to send a MT SMS
 DCC (ti 00 sub IMSI-901700000004620:MSISDN-46071 callref 40000001) New transaction
 DREF VLR subscr IMSI-901700000004620:MSISDN-46071 usage increases to: 4
+DLSMS SMC(0) instance created for network
+DLSMS SMR(0) instance created for network.
+DLSMS SMR(0) message SM-RL-DATA_REQ received in state IDLE
+DLSMS SMR(0) TX SMS RP-DATA
+DLSMS SMR(0) new RP state IDLE -> WAIT_FOR_RP_ACK
+DLSMS SMC(0) message MNSMS-EST-REQ received in state IDLE
+DLSMS SMC(0) new CP state IDLE -> MM_CONN_PENDING
+DLSMS Initiating Paging procedure for IMSI-901700000004620:MSISDN-46071 due to MMSMS_EST_REQ
 DMM Subscriber IMSI-901700000004620:MSISDN-46071 not paged yet, start paging.
   GERAN-A sends out paging request to IMSI 901700000004620, TMSI 0xffffffff, LAC 23
   strcmp(paging_expecting_imsi, imsi) == 0
@@ -224,7 +233,13 @@
 DMM RAN_conn(IMSI-901700000004620:MSISDN-46071:GERAN-A-0:PAGING_RESP){RAN_CONN_S_NEW}: Received Event RAN_CONN_E_ACCEPTED
 DPAG Paging success for IMSI-901700000004620:MSISDN-46071 (event=0)
 DPAG Calling paging cbfn.
+DLSMS paging_cb_mmsms_est_req(hooknum=1, event=0)
 DREF IMSI-901700000004620:MSISDN-46071: MSC conn use + trans_sms == 2 (0x21: compl_l3,trans_sms)
+DLSMS SMC(0) message MMSMS-EST-CNF received in state MM_CONN_PENDING
+DLSMS SMC(0) send CP data
+DLSMS SMC(0) new CP state MM_CONN_PENDING -> WAIT_CP_ACK
+DLSMS sending CP message (trans=0)
+DLSMS GSM4.11 TX 09 01 58 01 00 07 91 44 77 58 10 06 50 00 4c 00 05 80 64 70 f1 00 00 07 10 10 00 00 00 00 44 50 79 da 1e 1e e7 41 69 37 48 5e 9e a7 c9 65 37 3d 1d 66 83 c2 70 38 3b 3d 0e d3 d3 6f f7 1c 94 9e 83 c2 20 72 79 9e 96 87 c5 ec 32 a8 1d 96 af cb f4 b4 fb 0c 7a c3 e9 e9 b7 db 05 
 DMSC msc_tx 91 bytes to IMSI-901700000004620:MSISDN-46071 via GERAN-A
 - DTAP --GERAN-A--> MS: SMS:0x01: 09015801000791447758100650004c0005806470f1000007101000000000445079da1e1ee7416937485e9ea7c965373d1d6683c270383b3d0ed3d36ff71c949e83c22072799e9687c5ec32a81d96afcbf4b4fb0c7ac3e9e9b7db05
 - DTAP matches expected message
@@ -246,19 +261,39 @@
   MSC <--GERAN-A-- MS: SMS:0x04
 DREF IMSI-901700000004620:MSISDN-46071: MSC conn use + dtap == 2 (0x22: dtap,trans_sms)
 DRLL Dispatching 04.08 message SMS:0x04 (0x9:0x4)
+DLSMS receiving data (trans_id=0, msg_type=SMS:0x04)
 DMM RAN_conn(IMSI-901700000004620:MSISDN-46071:GERAN-A-0:PAGING_RESP){RAN_CONN_S_ACCEPTED}: Received Event RAN_CONN_E_COMMUNICATING
 DMM RAN_conn(IMSI-901700000004620:MSISDN-46071:GERAN-A-0:PAGING_RESP){RAN_CONN_S_ACCEPTED}: state_chg to RAN_CONN_S_COMMUNICATING
+DLSMS SMC(0) message MMSMS-DATA-IND (CP ACK) received in state WAIT_CP_ACK
+DLSMS SMC(0) received CP-ACK
+DLSMS SMC(0) new CP state WAIT_CP_ACK -> MM_ESTABLISHED
 DREF IMSI-901700000004620:MSISDN-46071: MSC conn use - dtap == 1 (0x20: trans_sms)
   llist_count(&net->ran_conns) == 1
 - MS also sends RP-ACK, MSC in turn sends CP-ACK for that
   MSC <--GERAN-A-- MS: SMS:0x01
 DREF IMSI-901700000004620:MSISDN-46071: MSC conn use + dtap == 2 (0x22: dtap,trans_sms)
 DRLL Dispatching 04.08 message SMS:0x01 (0x9:0x1)
+DLSMS receiving data (trans_id=0, msg_type=SMS:0x01)
 DMM RAN_conn(IMSI-901700000004620:MSISDN-46071:GERAN-A-0:PAGING_RESP){RAN_CONN_S_COMMUNICATING}: Received Event RAN_CONN_E_COMMUNICATING
+DLSMS SMC(0) message MMSMS-DATA-IND (CP DATA) received in state MM_ESTABLISHED
+DLSMS SMC(0) received CP-DATA
+DLSMS sending CP message (trans=0)
+DLSMS GSM4.11 TX 09 04 
 DMSC msc_tx 2 bytes to IMSI-901700000004620:MSISDN-46071 via GERAN-A
 - DTAP --GERAN-A--> MS: SMS:0x04: 0904
 - DTAP matches expected message
+DLSMS MNSMS-DATA/EST-IND
+DLSMS SMR(0) message MNSMS-DATA-IND received in state WAIT_FOR_RP_ACK
+DLSMS SMR(0) RX SMS RP-ACK
+DLSMS SMR(0) new RP state WAIT_FOR_RP_ACK -> IDLE
+DLSMS RX SMS RP-ACK (MO)
 DREF VLR subscr IMSI-901700000004620:MSISDN-46071 usage decreases to: 3
+DLSMS SMR(0) TX: MNSMS-REL-REQ
+DLSMS SMC(0) message MNSMS-REL-REQ received in state MM_ESTABLISHED
+DLSMS SMC(0) new CP state MM_ESTABLISHED -> IDLE
+DLSMS Got MMSMS_REL_REQ, destroying transaction.
+DLSMS SMR(0) clearing SMR instance
+DLSMS SMC(0) clearing instance
 DREF VLR subscr IMSI-901700000004620:MSISDN-46071 usage decreases to: 2
 DREF IMSI-901700000004620:MSISDN-46071: MSC conn use - trans_sms == 1 (0x2: dtap)
 DREF IMSI-901700000004620:MSISDN-46071: MSC conn use - dtap == 0 (0x0: )
@@ -541,8 +576,17 @@
 DREF VLR subscr IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100 usage increases to: 2
   llist_count(&vsub->cs.requests) == 0
 DREF VLR subscr IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100 usage increases to: 3
+DLSMS Going to send a MT SMS
 DCC (ti 00 sub IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100 callref 40000002) New transaction
 DREF VLR subscr IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100 usage increases to: 4
+DLSMS SMC(0) instance created for network
+DLSMS SMR(0) instance created for network.
+DLSMS SMR(0) message SM-RL-DATA_REQ received in state IDLE
+DLSMS SMR(0) TX SMS RP-DATA
+DLSMS SMR(0) new RP state IDLE -> WAIT_FOR_RP_ACK
+DLSMS SMC(0) message MNSMS-EST-REQ received in state IDLE
+DLSMS SMC(0) new CP state IDLE -> MM_CONN_PENDING
+DLSMS Initiating Paging procedure for IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100 due to MMSMS_EST_REQ
 DMM Subscriber IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100 not paged yet, start paging.
   GERAN-A sends out paging request to IMSI 901700000004620, TMSI 0x03020100, LAC 23
   paging_expecting_tmsi == 0x03020100
@@ -583,7 +627,13 @@
 DMM RAN_conn(IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100:GERAN-A-0:PAGING_RESP){RAN_CONN_S_NEW}: Received Event RAN_CONN_E_ACCEPTED
 DPAG Paging success for IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100 (event=0)
 DPAG Calling paging cbfn.
+DLSMS paging_cb_mmsms_est_req(hooknum=1, event=0)
 DREF IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100: MSC conn use + trans_sms == 2 (0x21: compl_l3,trans_sms)
+DLSMS SMC(0) message MMSMS-EST-CNF received in state MM_CONN_PENDING
+DLSMS SMC(0) send CP data
+DLSMS SMC(0) new CP state MM_CONN_PENDING -> WAIT_CP_ACK
+DLSMS sending CP message (trans=0)
+DLSMS GSM4.11 TX 09 01 58 01 00 07 91 44 77 58 10 06 50 00 4c 00 05 80 64 70 f1 00 00 07 10 10 00 00 00 00 44 50 79 da 1e 1e e7 41 69 37 48 5e 9e a7 c9 65 37 3d 1d 66 83 c2 70 38 3b 3d 0e d3 d3 6f f7 1c 94 9e 83 c2 20 72 79 9e 96 87 c5 ec 32 a8 1d 96 af cb f4 b4 fb 0c 7a c3 e9 e9 b7 db 05 
 DMSC msc_tx 91 bytes to IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100 via GERAN-A
 - DTAP --GERAN-A--> MS: SMS:0x01: 09015801000791447758100650004c0005806470f1000007101000000000445079da1e1ee7416937485e9ea7c965373d1d6683c270383b3d0ed3d36ff71c949e83c22072799e9687c5ec32a81d96afcbf4b4fb0c7ac3e9e9b7db05
 - DTAP matches expected message
@@ -605,19 +655,39 @@
   MSC <--GERAN-A-- MS: SMS:0x04
 DREF IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100: MSC conn use + dtap == 2 (0x22: dtap,trans_sms)
 DRLL Dispatching 04.08 message SMS:0x04 (0x9:0x4)
+DLSMS receiving data (trans_id=0, msg_type=SMS:0x04)
 DMM RAN_conn(IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100:GERAN-A-0:PAGING_RESP){RAN_CONN_S_ACCEPTED}: Received Event RAN_CONN_E_COMMUNICATING
 DMM RAN_conn(IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100:GERAN-A-0:PAGING_RESP){RAN_CONN_S_ACCEPTED}: state_chg to RAN_CONN_S_COMMUNICATING
+DLSMS SMC(0) message MMSMS-DATA-IND (CP ACK) received in state WAIT_CP_ACK
+DLSMS SMC(0) received CP-ACK
+DLSMS SMC(0) new CP state WAIT_CP_ACK -> MM_ESTABLISHED
 DREF IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100: MSC conn use - dtap == 1 (0x20: trans_sms)
   llist_count(&net->ran_conns) == 1
 - MS also sends RP-ACK, MSC in turn sends CP-ACK for that
   MSC <--GERAN-A-- MS: SMS:0x01
 DREF IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100: MSC conn use + dtap == 2 (0x22: dtap,trans_sms)
 DRLL Dispatching 04.08 message SMS:0x01 (0x9:0x1)
+DLSMS receiving data (trans_id=0, msg_type=SMS:0x01)
 DMM RAN_conn(IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100:GERAN-A-0:PAGING_RESP){RAN_CONN_S_COMMUNICATING}: Received Event RAN_CONN_E_COMMUNICATING
+DLSMS SMC(0) message MMSMS-DATA-IND (CP DATA) received in state MM_ESTABLISHED
+DLSMS SMC(0) received CP-DATA
+DLSMS sending CP message (trans=0)
+DLSMS GSM4.11 TX 09 04 
 DMSC msc_tx 2 bytes to IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100 via GERAN-A
 - DTAP --GERAN-A--> MS: SMS:0x04: 0904
 - DTAP matches expected message
+DLSMS MNSMS-DATA/EST-IND
+DLSMS SMR(0) message MNSMS-DATA-IND received in state WAIT_FOR_RP_ACK
+DLSMS SMR(0) RX SMS RP-ACK
+DLSMS SMR(0) new RP state WAIT_FOR_RP_ACK -> IDLE
+DLSMS RX SMS RP-ACK (MO)
 DREF VLR subscr IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100 usage decreases to: 3
+DLSMS SMR(0) TX: MNSMS-REL-REQ
+DLSMS SMC(0) message MNSMS-REL-REQ received in state MM_ESTABLISHED
+DLSMS SMC(0) new CP state MM_ESTABLISHED -> IDLE
+DLSMS Got MMSMS_REL_REQ, destroying transaction.
+DLSMS SMR(0) clearing SMR instance
+DLSMS SMC(0) clearing instance
 DREF VLR subscr IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100 usage decreases to: 2
 DREF IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100: MSC conn use - trans_sms == 1 (0x2: dtap)
 DREF IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100: MSC conn use - dtap == 0 (0x0: )
diff --git a/tests/msc_vlr/msc_vlr_test_reject_concurrency.err b/tests/msc_vlr/msc_vlr_test_reject_concurrency.err
index f5692b9..2147e84 100644
--- a/tests/msc_vlr/msc_vlr_test_reject_concurrency.err
+++ b/tests/msc_vlr/msc_vlr_test_reject_concurrency.err
@@ -1215,8 +1215,17 @@
 DREF VLR subscr IMSI-901700000004620:MSISDN-46071 usage increases to: 2
   llist_count(&vsub->cs.requests) == 0
 DREF VLR subscr IMSI-901700000004620:MSISDN-46071 usage increases to: 3
+DLSMS Going to send a MT SMS
 DCC (ti 00 sub IMSI-901700000004620:MSISDN-46071 callref 40000001) New transaction
 DREF VLR subscr IMSI-901700000004620:MSISDN-46071 usage increases to: 4
+DLSMS SMC(0) instance created for network
+DLSMS SMR(0) instance created for network.
+DLSMS SMR(0) message SM-RL-DATA_REQ received in state IDLE
+DLSMS SMR(0) TX SMS RP-DATA
+DLSMS SMR(0) new RP state IDLE -> WAIT_FOR_RP_ACK
+DLSMS SMC(0) message MNSMS-EST-REQ received in state IDLE
+DLSMS SMC(0) new CP state IDLE -> MM_CONN_PENDING
+DLSMS Initiating Paging procedure for IMSI-901700000004620:MSISDN-46071 due to MMSMS_EST_REQ
 DMM Subscriber IMSI-901700000004620:MSISDN-46071 not paged yet, start paging.
   GERAN-A sends out paging request to IMSI 901700000004620, TMSI 0xffffffff, LAC 23
   strcmp(paging_expecting_imsi, imsi) == 0
@@ -1253,7 +1262,13 @@
 DMM RAN_conn(IMSI-901700000004620:MSISDN-46071:GERAN-A-0:PAGING_RESP){RAN_CONN_S_NEW}: Received Event RAN_CONN_E_ACCEPTED
 DPAG Paging success for IMSI-901700000004620:MSISDN-46071 (event=0)
 DPAG Calling paging cbfn.
+DLSMS paging_cb_mmsms_est_req(hooknum=1, event=0)
 DREF IMSI-901700000004620:MSISDN-46071: MSC conn use + trans_sms == 2 (0x21: compl_l3,trans_sms)
+DLSMS SMC(0) message MMSMS-EST-CNF received in state MM_CONN_PENDING
+DLSMS SMC(0) send CP data
+DLSMS SMC(0) new CP state MM_CONN_PENDING -> WAIT_CP_ACK
+DLSMS sending CP message (trans=0)
+DLSMS GSM4.11 TX 09 01 58 01 00 07 91 44 77 58 10 06 50 00 4c 00 05 80 64 70 f1 00 00 07 10 10 00 00 00 00 44 50 79 da 1e 1e e7 41 69 37 48 5e 9e a7 c9 65 37 3d 1d 66 83 c2 70 38 3b 3d 0e d3 d3 6f f7 1c 94 9e 83 c2 20 72 79 9e 96 87 c5 ec 32 a8 1d 96 af cb f4 b4 fb 0c 7a c3 e9 e9 b7 db 05 
 DMSC msc_tx 91 bytes to IMSI-901700000004620:MSISDN-46071 via GERAN-A
 - DTAP --GERAN-A--> MS: SMS:0x01: 09015801000791447758100650004c0005806470f1000007101000000000445079da1e1ee7416937485e9ea7c965373d1d6683c270383b3d0ed3d36ff71c949e83c22072799e9687c5ec32a81d96afcbf4b4fb0c7ac3e9e9b7db05
 - DTAP matches expected message
@@ -1280,19 +1295,39 @@
   MSC <--GERAN-A-- MS: SMS:0x04
 DREF IMSI-901700000004620:MSISDN-46071: MSC conn use + dtap == 2 (0x22: dtap,trans_sms)
 DRLL Dispatching 04.08 message SMS:0x04 (0x9:0x4)
+DLSMS receiving data (trans_id=0, msg_type=SMS:0x04)
 DMM RAN_conn(IMSI-901700000004620:MSISDN-46071:GERAN-A-0:PAGING_RESP){RAN_CONN_S_ACCEPTED}: Received Event RAN_CONN_E_COMMUNICATING
 DMM RAN_conn(IMSI-901700000004620:MSISDN-46071:GERAN-A-0:PAGING_RESP){RAN_CONN_S_ACCEPTED}: state_chg to RAN_CONN_S_COMMUNICATING
+DLSMS SMC(0) message MMSMS-DATA-IND (CP ACK) received in state WAIT_CP_ACK
+DLSMS SMC(0) received CP-ACK
+DLSMS SMC(0) new CP state WAIT_CP_ACK -> MM_ESTABLISHED
 DREF IMSI-901700000004620:MSISDN-46071: MSC conn use - dtap == 1 (0x20: trans_sms)
   llist_count(&net->ran_conns) == 1
 - MS also sends RP-ACK, MSC in turn sends CP-ACK for that
   MSC <--GERAN-A-- MS: SMS:0x01
 DREF IMSI-901700000004620:MSISDN-46071: MSC conn use + dtap == 2 (0x22: dtap,trans_sms)
 DRLL Dispatching 04.08 message SMS:0x01 (0x9:0x1)
+DLSMS receiving data (trans_id=0, msg_type=SMS:0x01)
 DMM RAN_conn(IMSI-901700000004620:MSISDN-46071:GERAN-A-0:PAGING_RESP){RAN_CONN_S_COMMUNICATING}: Received Event RAN_CONN_E_COMMUNICATING
+DLSMS SMC(0) message MMSMS-DATA-IND (CP DATA) received in state MM_ESTABLISHED
+DLSMS SMC(0) received CP-DATA
+DLSMS sending CP message (trans=0)
+DLSMS GSM4.11 TX 09 04 
 DMSC msc_tx 2 bytes to IMSI-901700000004620:MSISDN-46071 via GERAN-A
 - DTAP --GERAN-A--> MS: SMS:0x04: 0904
 - DTAP matches expected message
+DLSMS MNSMS-DATA/EST-IND
+DLSMS SMR(0) message MNSMS-DATA-IND received in state WAIT_FOR_RP_ACK
+DLSMS SMR(0) RX SMS RP-ACK
+DLSMS SMR(0) new RP state WAIT_FOR_RP_ACK -> IDLE
+DLSMS RX SMS RP-ACK (MO)
 DREF VLR subscr IMSI-901700000004620:MSISDN-46071 usage decreases to: 3
+DLSMS SMR(0) TX: MNSMS-REL-REQ
+DLSMS SMC(0) message MNSMS-REL-REQ received in state MM_ESTABLISHED
+DLSMS SMC(0) new CP state MM_ESTABLISHED -> IDLE
+DLSMS Got MMSMS_REL_REQ, destroying transaction.
+DLSMS SMR(0) clearing SMR instance
+DLSMS SMC(0) clearing instance
 DREF VLR subscr IMSI-901700000004620:MSISDN-46071 usage decreases to: 2
 DREF IMSI-901700000004620:MSISDN-46071: MSC conn use - trans_sms == 1 (0x2: dtap)
 DREF IMSI-901700000004620:MSISDN-46071: MSC conn use - dtap == 0 (0x0: )
@@ -1437,8 +1472,17 @@
 DREF VLR subscr IMSI-901700000004620:MSISDN-46071 usage increases to: 2
   llist_count(&vsub->cs.requests) == 0
 DREF VLR subscr IMSI-901700000004620:MSISDN-46071 usage increases to: 3
+DLSMS Going to send a MT SMS
 DCC (ti 00 sub IMSI-901700000004620:MSISDN-46071 callref 40000002) New transaction
 DREF VLR subscr IMSI-901700000004620:MSISDN-46071 usage increases to: 4
+DLSMS SMC(0) instance created for network
+DLSMS SMR(0) instance created for network.
+DLSMS SMR(0) message SM-RL-DATA_REQ received in state IDLE
+DLSMS SMR(0) TX SMS RP-DATA
+DLSMS SMR(0) new RP state IDLE -> WAIT_FOR_RP_ACK
+DLSMS SMC(0) message MNSMS-EST-REQ received in state IDLE
+DLSMS SMC(0) new CP state IDLE -> MM_CONN_PENDING
+DLSMS Initiating Paging procedure for IMSI-901700000004620:MSISDN-46071 due to MMSMS_EST_REQ
 DMM Subscriber IMSI-901700000004620:MSISDN-46071 not paged yet, start paging.
   GERAN-A sends out paging request to IMSI 901700000004620, TMSI 0xffffffff, LAC 23
   strcmp(paging_expecting_imsi, imsi) == 0
@@ -1475,7 +1519,13 @@
 DMM RAN_conn(IMSI-901700000004620:MSISDN-46071:GERAN-A-0:PAGING_RESP){RAN_CONN_S_NEW}: Received Event RAN_CONN_E_ACCEPTED
 DPAG Paging success for IMSI-901700000004620:MSISDN-46071 (event=0)
 DPAG Calling paging cbfn.
+DLSMS paging_cb_mmsms_est_req(hooknum=1, event=0)
 DREF IMSI-901700000004620:MSISDN-46071: MSC conn use + trans_sms == 2 (0x21: compl_l3,trans_sms)
+DLSMS SMC(0) message MMSMS-EST-CNF received in state MM_CONN_PENDING
+DLSMS SMC(0) send CP data
+DLSMS SMC(0) new CP state MM_CONN_PENDING -> WAIT_CP_ACK
+DLSMS sending CP message (trans=0)
+DLSMS GSM4.11 TX 09 01 58 01 00 07 91 44 77 58 10 06 50 00 4c 00 05 80 64 70 f1 00 00 07 10 10 00 00 00 00 44 50 79 da 1e 1e e7 41 69 37 48 5e 9e a7 c9 65 37 3d 1d 66 83 c2 70 38 3b 3d 0e d3 d3 6f f7 1c 94 9e 83 c2 20 72 79 9e 96 87 c5 ec 32 a8 1d 96 af cb f4 b4 fb 0c 7a c3 e9 e9 b7 db 05 
 DMSC msc_tx 91 bytes to IMSI-901700000004620:MSISDN-46071 via GERAN-A
 - DTAP --GERAN-A--> MS: SMS:0x01: 09015801000791447758100650004c0005806470f1000007101000000000445079da1e1ee7416937485e9ea7c965373d1d6683c270383b3d0ed3d36ff71c949e83c22072799e9687c5ec32a81d96afcbf4b4fb0c7ac3e9e9b7db05
 - DTAP matches expected message
@@ -1508,19 +1558,39 @@
   MSC <--GERAN-A-- MS: SMS:0x04
 DREF IMSI-901700000004620:MSISDN-46071: MSC conn use + dtap == 3 (0x2a: dtap,cm_service,trans_sms)
 DRLL Dispatching 04.08 message SMS:0x04 (0x9:0x4)
+DLSMS receiving data (trans_id=0, msg_type=SMS:0x04)
 DMM RAN_conn(IMSI-901700000004620:MSISDN-46071:GERAN-A-0:CM_SERVICE_REQ){RAN_CONN_S_ACCEPTED}: Received Event RAN_CONN_E_COMMUNICATING
 DMM RAN_conn(IMSI-901700000004620:MSISDN-46071:GERAN-A-0:CM_SERVICE_REQ){RAN_CONN_S_ACCEPTED}: state_chg to RAN_CONN_S_COMMUNICATING
+DLSMS SMC(0) message MMSMS-DATA-IND (CP ACK) received in state WAIT_CP_ACK
+DLSMS SMC(0) received CP-ACK
+DLSMS SMC(0) new CP state WAIT_CP_ACK -> MM_ESTABLISHED
 DREF IMSI-901700000004620:MSISDN-46071: MSC conn use - dtap == 2 (0x28: cm_service,trans_sms)
   llist_count(&net->ran_conns) == 1
 - MS also sends RP-ACK, MSC in turn sends CP-ACK for that
   MSC <--GERAN-A-- MS: SMS:0x01
 DREF IMSI-901700000004620:MSISDN-46071: MSC conn use + dtap == 3 (0x2a: dtap,cm_service,trans_sms)
 DRLL Dispatching 04.08 message SMS:0x01 (0x9:0x1)
+DLSMS receiving data (trans_id=0, msg_type=SMS:0x01)
 DMM RAN_conn(IMSI-901700000004620:MSISDN-46071:GERAN-A-0:CM_SERVICE_REQ){RAN_CONN_S_COMMUNICATING}: Received Event RAN_CONN_E_COMMUNICATING
+DLSMS SMC(0) message MMSMS-DATA-IND (CP DATA) received in state MM_ESTABLISHED
+DLSMS SMC(0) received CP-DATA
+DLSMS sending CP message (trans=0)
+DLSMS GSM4.11 TX 09 04 
 DMSC msc_tx 2 bytes to IMSI-901700000004620:MSISDN-46071 via GERAN-A
 - DTAP --GERAN-A--> MS: SMS:0x04: 0904
 - DTAP matches expected message
+DLSMS MNSMS-DATA/EST-IND
+DLSMS SMR(0) message MNSMS-DATA-IND received in state WAIT_FOR_RP_ACK
+DLSMS SMR(0) RX SMS RP-ACK
+DLSMS SMR(0) new RP state WAIT_FOR_RP_ACK -> IDLE
+DLSMS RX SMS RP-ACK (MO)
 DREF VLR subscr IMSI-901700000004620:MSISDN-46071 usage decreases to: 3
+DLSMS SMR(0) TX: MNSMS-REL-REQ
+DLSMS SMC(0) message MNSMS-REL-REQ received in state MM_ESTABLISHED
+DLSMS SMC(0) new CP state MM_ESTABLISHED -> IDLE
+DLSMS Got MMSMS_REL_REQ, destroying transaction.
+DLSMS SMR(0) clearing SMR instance
+DLSMS SMC(0) clearing instance
 DREF VLR subscr IMSI-901700000004620:MSISDN-46071 usage decreases to: 2
 DREF IMSI-901700000004620:MSISDN-46071: MSC conn use - trans_sms == 2 (0xa: dtap,cm_service)
 DREF IMSI-901700000004620:MSISDN-46071: MSC conn use - dtap == 1 (0x8: cm_service)
@@ -1680,8 +1750,17 @@
 DREF VLR subscr IMSI-901700000004620:MSISDN-46071 usage increases to: 2
   llist_count(&vsub->cs.requests) == 0
 DREF VLR subscr IMSI-901700000004620:MSISDN-46071 usage increases to: 3
+DLSMS Going to send a MT SMS
 DCC (ti 00 sub IMSI-901700000004620:MSISDN-46071 callref 40000003) New transaction
 DREF VLR subscr IMSI-901700000004620:MSISDN-46071 usage increases to: 4
+DLSMS SMC(0) instance created for network
+DLSMS SMR(0) instance created for network.
+DLSMS SMR(0) message SM-RL-DATA_REQ received in state IDLE
+DLSMS SMR(0) TX SMS RP-DATA
+DLSMS SMR(0) new RP state IDLE -> WAIT_FOR_RP_ACK
+DLSMS SMC(0) message MNSMS-EST-REQ received in state IDLE
+DLSMS SMC(0) new CP state IDLE -> MM_CONN_PENDING
+DLSMS Initiating Paging procedure for IMSI-901700000004620:MSISDN-46071 due to MMSMS_EST_REQ
 DMM Subscriber IMSI-901700000004620:MSISDN-46071 not paged yet, start paging.
   GERAN-A sends out paging request to IMSI 901700000004620, TMSI 0xffffffff, LAC 23
   strcmp(paging_expecting_imsi, imsi) == 0
@@ -1718,7 +1797,13 @@
 DMM RAN_conn(IMSI-901700000004620:MSISDN-46071:GERAN-A-0:PAGING_RESP){RAN_CONN_S_NEW}: Received Event RAN_CONN_E_ACCEPTED
 DPAG Paging success for IMSI-901700000004620:MSISDN-46071 (event=0)
 DPAG Calling paging cbfn.
+DLSMS paging_cb_mmsms_est_req(hooknum=1, event=0)
 DREF IMSI-901700000004620:MSISDN-46071: MSC conn use + trans_sms == 2 (0x21: compl_l3,trans_sms)
+DLSMS SMC(0) message MMSMS-EST-CNF received in state MM_CONN_PENDING
+DLSMS SMC(0) send CP data
+DLSMS SMC(0) new CP state MM_CONN_PENDING -> WAIT_CP_ACK
+DLSMS sending CP message (trans=0)
+DLSMS GSM4.11 TX 09 01 58 01 00 07 91 44 77 58 10 06 50 00 4c 00 05 80 64 70 f1 00 00 07 10 10 00 00 00 00 44 50 79 da 1e 1e e7 41 69 37 48 5e 9e a7 c9 65 37 3d 1d 66 83 c2 70 38 3b 3d 0e d3 d3 6f f7 1c 94 9e 83 c2 20 72 79 9e 96 87 c5 ec 32 a8 1d 96 af cb f4 b4 fb 0c 7a c3 e9 e9 b7 db 05 
 DMSC msc_tx 91 bytes to IMSI-901700000004620:MSISDN-46071 via GERAN-A
 - DTAP --GERAN-A--> MS: SMS:0x01: 09015801000791447758100650004c0005806470f1000007101000000000445079da1e1ee7416937485e9ea7c965373d1d6683c270383b3d0ed3d36ff71c949e83c22072799e9687c5ec32a81d96afcbf4b4fb0c7ac3e9e9b7db05
 - DTAP matches expected message
@@ -1743,19 +1828,39 @@
   MSC <--GERAN-A-- MS: SMS:0x04
 DREF IMSI-901700000004620:MSISDN-46071: MSC conn use + dtap == 2 (0x22: dtap,trans_sms)
 DRLL Dispatching 04.08 message SMS:0x04 (0x9:0x4)
+DLSMS receiving data (trans_id=0, msg_type=SMS:0x04)
 DMM RAN_conn(IMSI-901700000004620:MSISDN-46071:GERAN-A-0:PAGING_RESP){RAN_CONN_S_ACCEPTED}: Received Event RAN_CONN_E_COMMUNICATING
 DMM RAN_conn(IMSI-901700000004620:MSISDN-46071:GERAN-A-0:PAGING_RESP){RAN_CONN_S_ACCEPTED}: state_chg to RAN_CONN_S_COMMUNICATING
+DLSMS SMC(0) message MMSMS-DATA-IND (CP ACK) received in state WAIT_CP_ACK
+DLSMS SMC(0) received CP-ACK
+DLSMS SMC(0) new CP state WAIT_CP_ACK -> MM_ESTABLISHED
 DREF IMSI-901700000004620:MSISDN-46071: MSC conn use - dtap == 1 (0x20: trans_sms)
   llist_count(&net->ran_conns) == 1
 - MS also sends RP-ACK, MSC in turn sends CP-ACK for that
   MSC <--GERAN-A-- MS: SMS:0x01
 DREF IMSI-901700000004620:MSISDN-46071: MSC conn use + dtap == 2 (0x22: dtap,trans_sms)
 DRLL Dispatching 04.08 message SMS:0x01 (0x9:0x1)
+DLSMS receiving data (trans_id=0, msg_type=SMS:0x01)
 DMM RAN_conn(IMSI-901700000004620:MSISDN-46071:GERAN-A-0:PAGING_RESP){RAN_CONN_S_COMMUNICATING}: Received Event RAN_CONN_E_COMMUNICATING
+DLSMS SMC(0) message MMSMS-DATA-IND (CP DATA) received in state MM_ESTABLISHED
+DLSMS SMC(0) received CP-DATA
+DLSMS sending CP message (trans=0)
+DLSMS GSM4.11 TX 09 04 
 DMSC msc_tx 2 bytes to IMSI-901700000004620:MSISDN-46071 via GERAN-A
 - DTAP --GERAN-A--> MS: SMS:0x04: 0904
 - DTAP matches expected message
+DLSMS MNSMS-DATA/EST-IND
+DLSMS SMR(0) message MNSMS-DATA-IND received in state WAIT_FOR_RP_ACK
+DLSMS SMR(0) RX SMS RP-ACK
+DLSMS SMR(0) new RP state WAIT_FOR_RP_ACK -> IDLE
+DLSMS RX SMS RP-ACK (MO)
 DREF VLR subscr IMSI-901700000004620:MSISDN-46071 usage decreases to: 3
+DLSMS SMR(0) TX: MNSMS-REL-REQ
+DLSMS SMC(0) message MNSMS-REL-REQ received in state MM_ESTABLISHED
+DLSMS SMC(0) new CP state MM_ESTABLISHED -> IDLE
+DLSMS Got MMSMS_REL_REQ, destroying transaction.
+DLSMS SMR(0) clearing SMR instance
+DLSMS SMC(0) clearing instance
 DREF VLR subscr IMSI-901700000004620:MSISDN-46071 usage decreases to: 2
 DREF IMSI-901700000004620:MSISDN-46071: MSC conn use - trans_sms == 1 (0x2: dtap)
 DREF IMSI-901700000004620:MSISDN-46071: MSC conn use - dtap == 0 (0x0: )
diff --git a/tests/msc_vlr/msc_vlr_test_umts_authen.err b/tests/msc_vlr/msc_vlr_test_umts_authen.err
index 18addc3..ee9eeba 100644
--- a/tests/msc_vlr/msc_vlr_test_umts_authen.err
+++ b/tests/msc_vlr/msc_vlr_test_umts_authen.err
@@ -287,8 +287,17 @@
 DREF VLR subscr IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100 usage increases to: 2
   llist_count(&vsub->cs.requests) == 0
 DREF VLR subscr IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100 usage increases to: 3
+DLSMS Going to send a MT SMS
 DCC (ti 00 sub IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100 callref 40000001) New transaction
 DREF VLR subscr IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100 usage increases to: 4
+DLSMS SMC(0) instance created for network
+DLSMS SMR(0) instance created for network.
+DLSMS SMR(0) message SM-RL-DATA_REQ received in state IDLE
+DLSMS SMR(0) TX SMS RP-DATA
+DLSMS SMR(0) new RP state IDLE -> WAIT_FOR_RP_ACK
+DLSMS SMC(0) message MNSMS-EST-REQ received in state IDLE
+DLSMS SMC(0) new CP state IDLE -> MM_CONN_PENDING
+DLSMS Initiating Paging procedure for IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100 due to MMSMS_EST_REQ
 DMM Subscriber IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100 not paged yet, start paging.
   GERAN-A sends out paging request to IMSI 901700000010650, TMSI 0x03020100, LAC 23
   strcmp(paging_expecting_imsi, imsi) == 0
@@ -372,7 +381,13 @@
 DMM RAN_conn(IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100:GERAN-A-0:PAGING_RESP){RAN_CONN_S_AUTH_CIPH}: Received Event RAN_CONN_E_ACCEPTED
 DPAG Paging success for IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100 (event=0)
 DPAG Calling paging cbfn.
+DLSMS paging_cb_mmsms_est_req(hooknum=1, event=0)
 DREF IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100: MSC conn use + trans_sms == 2 (0x22: dtap,trans_sms)
+DLSMS SMC(0) message MMSMS-EST-CNF received in state MM_CONN_PENDING
+DLSMS SMC(0) send CP data
+DLSMS SMC(0) new CP state MM_CONN_PENDING -> WAIT_CP_ACK
+DLSMS sending CP message (trans=0)
+DLSMS GSM4.11 TX 09 01 58 01 00 07 91 44 77 58 10 06 50 00 4c 00 05 80 24 43 f2 00 00 07 10 10 00 00 00 00 44 50 79 da 1e 1e e7 41 69 37 48 5e 9e a7 c9 65 37 3d 1d 66 83 c2 70 38 3b 3d 0e d3 d3 6f f7 1c 94 9e 83 c2 20 72 79 9e 96 87 c5 ec 32 a8 1d 96 af cb f4 b4 fb 0c 7a c3 e9 e9 b7 db 05 
 DMSC msc_tx 91 bytes to IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100 via GERAN-A
 - DTAP --GERAN-A--> MS: SMS:0x01: 09015801000791447758100650004c0005802443f2000007101000000000445079da1e1ee7416937485e9ea7c965373d1d6683c270383b3d0ed3d36ff71c949e83c22072799e9687c5ec32a81d96afcbf4b4fb0c7ac3e9e9b7db05
 - DTAP matches expected message
@@ -392,19 +407,39 @@
   MSC <--GERAN-A-- MS: SMS:0x04
 DREF IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100: MSC conn use + dtap == 2 (0x22: dtap,trans_sms)
 DRLL Dispatching 04.08 message SMS:0x04 (0x9:0x4)
+DLSMS receiving data (trans_id=0, msg_type=SMS:0x04)
 DMM RAN_conn(IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100:GERAN-A-0:PAGING_RESP){RAN_CONN_S_ACCEPTED}: Received Event RAN_CONN_E_COMMUNICATING
 DMM RAN_conn(IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100:GERAN-A-0:PAGING_RESP){RAN_CONN_S_ACCEPTED}: state_chg to RAN_CONN_S_COMMUNICATING
+DLSMS SMC(0) message MMSMS-DATA-IND (CP ACK) received in state WAIT_CP_ACK
+DLSMS SMC(0) received CP-ACK
+DLSMS SMC(0) new CP state WAIT_CP_ACK -> MM_ESTABLISHED
 DREF IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100: MSC conn use - dtap == 1 (0x20: trans_sms)
   llist_count(&net->ran_conns) == 1
 - MS also sends RP-ACK, MSC in turn sends CP-ACK for that
   MSC <--GERAN-A-- MS: SMS:0x01
 DREF IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100: MSC conn use + dtap == 2 (0x22: dtap,trans_sms)
 DRLL Dispatching 04.08 message SMS:0x01 (0x9:0x1)
+DLSMS receiving data (trans_id=0, msg_type=SMS:0x01)
 DMM RAN_conn(IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100:GERAN-A-0:PAGING_RESP){RAN_CONN_S_COMMUNICATING}: Received Event RAN_CONN_E_COMMUNICATING
+DLSMS SMC(0) message MMSMS-DATA-IND (CP DATA) received in state MM_ESTABLISHED
+DLSMS SMC(0) received CP-DATA
+DLSMS sending CP message (trans=0)
+DLSMS GSM4.11 TX 09 04 
 DMSC msc_tx 2 bytes to IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100 via GERAN-A
 - DTAP --GERAN-A--> MS: SMS:0x04: 0904
 - DTAP matches expected message
+DLSMS MNSMS-DATA/EST-IND
+DLSMS SMR(0) message MNSMS-DATA-IND received in state WAIT_FOR_RP_ACK
+DLSMS SMR(0) RX SMS RP-ACK
+DLSMS SMR(0) new RP state WAIT_FOR_RP_ACK -> IDLE
+DLSMS RX SMS RP-ACK (MO)
 DREF VLR subscr IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100 usage decreases to: 3
+DLSMS SMR(0) TX: MNSMS-REL-REQ
+DLSMS SMC(0) message MNSMS-REL-REQ received in state MM_ESTABLISHED
+DLSMS SMC(0) new CP state MM_ESTABLISHED -> IDLE
+DLSMS Got MMSMS_REL_REQ, destroying transaction.
+DLSMS SMR(0) clearing SMR instance
+DLSMS SMC(0) clearing instance
 DREF VLR subscr IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100 usage decreases to: 2
 DREF IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100: MSC conn use - trans_sms == 1 (0x2: dtap)
 DREF IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100: MSC conn use - dtap == 0 (0x0: )
@@ -777,8 +812,17 @@
 DREF VLR subscr IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100 usage increases to: 2
   llist_count(&vsub->cs.requests) == 0
 DREF VLR subscr IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100 usage increases to: 3
+DLSMS Going to send a MT SMS
 DCC (ti 00 sub IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100 callref 40000002) New transaction
 DREF VLR subscr IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100 usage increases to: 4
+DLSMS SMC(0) instance created for network
+DLSMS SMR(0) instance created for network.
+DLSMS SMR(0) message SM-RL-DATA_REQ received in state IDLE
+DLSMS SMR(0) TX SMS RP-DATA
+DLSMS SMR(0) new RP state IDLE -> WAIT_FOR_RP_ACK
+DLSMS SMC(0) message MNSMS-EST-REQ received in state IDLE
+DLSMS SMC(0) new CP state IDLE -> MM_CONN_PENDING
+DLSMS Initiating Paging procedure for IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100 due to MMSMS_EST_REQ
 DMM Subscriber IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100 not paged yet, start paging.
   UTRAN-Iu sends out paging request to IMSI 901700000010650, TMSI 0x03020100, LAC 23
   strcmp(paging_expecting_imsi, imsi) == 0
@@ -877,7 +921,13 @@
 DMM RAN_conn(IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100:UTRAN-Iu-42:PAGING_RESP){RAN_CONN_S_AUTH_CIPH}: Received Event RAN_CONN_E_ACCEPTED
 DPAG Paging success for IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100 (event=0)
 DPAG Calling paging cbfn.
+DLSMS paging_cb_mmsms_est_req(hooknum=1, event=0)
 DREF IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100: MSC conn use + trans_sms == 1 (0x20: trans_sms)
+DLSMS SMC(0) message MMSMS-EST-CNF received in state MM_CONN_PENDING
+DLSMS SMC(0) send CP data
+DLSMS SMC(0) new CP state MM_CONN_PENDING -> WAIT_CP_ACK
+DLSMS sending CP message (trans=0)
+DLSMS GSM4.11 TX 09 01 58 01 00 07 91 44 77 58 10 06 50 00 4c 00 05 80 24 43 f2 00 00 07 10 10 00 00 00 00 44 50 79 da 1e 1e e7 41 69 37 48 5e 9e a7 c9 65 37 3d 1d 66 83 c2 70 38 3b 3d 0e d3 d3 6f f7 1c 94 9e 83 c2 20 72 79 9e 96 87 c5 ec 32 a8 1d 96 af cb f4 b4 fb 0c 7a c3 e9 e9 b7 db 05 
 DMSC msc_tx 91 bytes to IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100 via UTRAN-Iu
 - DTAP --UTRAN-Iu--> MS: SMS:0x01: 09015801000791447758100650004c0005802443f2000007101000000000445079da1e1ee7416937485e9ea7c965373d1d6683c270383b3d0ed3d36ff71c949e83c22072799e9687c5ec32a81d96afcbf4b4fb0c7ac3e9e9b7db05
 - DTAP matches expected message
@@ -895,19 +945,39 @@
   MSC <--UTRAN-Iu-- MS: SMS:0x04
 DREF IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100: MSC conn use + dtap == 2 (0x22: dtap,trans_sms)
 DRLL Dispatching 04.08 message SMS:0x04 (0x9:0x4)
+DLSMS receiving data (trans_id=0, msg_type=SMS:0x04)
 DMM RAN_conn(IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100:UTRAN-Iu-42:PAGING_RESP){RAN_CONN_S_ACCEPTED}: Received Event RAN_CONN_E_COMMUNICATING
 DMM RAN_conn(IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100:UTRAN-Iu-42:PAGING_RESP){RAN_CONN_S_ACCEPTED}: state_chg to RAN_CONN_S_COMMUNICATING
+DLSMS SMC(0) message MMSMS-DATA-IND (CP ACK) received in state WAIT_CP_ACK
+DLSMS SMC(0) received CP-ACK
+DLSMS SMC(0) new CP state WAIT_CP_ACK -> MM_ESTABLISHED
 DREF IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100: MSC conn use - dtap == 1 (0x20: trans_sms)
   llist_count(&net->ran_conns) == 1
 - MS also sends RP-ACK, MSC in turn sends CP-ACK for that
   MSC <--UTRAN-Iu-- MS: SMS:0x01
 DREF IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100: MSC conn use + dtap == 2 (0x22: dtap,trans_sms)
 DRLL Dispatching 04.08 message SMS:0x01 (0x9:0x1)
+DLSMS receiving data (trans_id=0, msg_type=SMS:0x01)
 DMM RAN_conn(IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100:UTRAN-Iu-42:PAGING_RESP){RAN_CONN_S_COMMUNICATING}: Received Event RAN_CONN_E_COMMUNICATING
+DLSMS SMC(0) message MMSMS-DATA-IND (CP DATA) received in state MM_ESTABLISHED
+DLSMS SMC(0) received CP-DATA
+DLSMS sending CP message (trans=0)
+DLSMS GSM4.11 TX 09 04 
 DMSC msc_tx 2 bytes to IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100 via UTRAN-Iu
 - DTAP --UTRAN-Iu--> MS: SMS:0x04: 0904
 - DTAP matches expected message
+DLSMS MNSMS-DATA/EST-IND
+DLSMS SMR(0) message MNSMS-DATA-IND received in state WAIT_FOR_RP_ACK
+DLSMS SMR(0) RX SMS RP-ACK
+DLSMS SMR(0) new RP state WAIT_FOR_RP_ACK -> IDLE
+DLSMS RX SMS RP-ACK (MO)
 DREF VLR subscr IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100 usage decreases to: 3
+DLSMS SMR(0) TX: MNSMS-REL-REQ
+DLSMS SMC(0) message MNSMS-REL-REQ received in state MM_ESTABLISHED
+DLSMS SMC(0) new CP state MM_ESTABLISHED -> IDLE
+DLSMS Got MMSMS_REL_REQ, destroying transaction.
+DLSMS SMR(0) clearing SMR instance
+DLSMS SMC(0) clearing instance
 DREF VLR subscr IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100 usage decreases to: 2
 DREF IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100: MSC conn use - trans_sms == 1 (0x2: dtap)
 DREF IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100: MSC conn use - dtap == 0 (0x0: )
diff --git a/tests/msc_vlr/msc_vlr_tests.c b/tests/msc_vlr/msc_vlr_tests.c
index 44ecc50..296f055 100644
--- a/tests/msc_vlr/msc_vlr_tests.c
+++ b/tests/msc_vlr/msc_vlr_tests.c
@@ -1023,9 +1023,9 @@
 	log_set_print_timestamp(osmo_stderr_target, 0);
 	log_set_print_filename(osmo_stderr_target, 0);
 	log_set_print_category(osmo_stderr_target, 1);
+	log_set_category_filter(osmo_stderr_target, DLSMS, 1, LOGL_DEBUG);
 
 	if (cmdline_opts.verbose) {
-		log_set_category_filter(osmo_stderr_target, DLSMS, 1, LOGL_DEBUG);
 		log_set_print_filename2(osmo_stderr_target, LOG_FILENAME_BASENAME);
 		log_set_print_filename_pos(osmo_stderr_target, LOG_FILENAME_POS_LINE_END);
 		log_set_use_color(osmo_stderr_target, 1);

-- 
To view, visit https://gerrit.osmocom.org/12577
To unsubscribe, or for help writing mail filters, visit https://gerrit.osmocom.org/settings

Gerrit-Project: osmo-msc
Gerrit-Branch: master
Gerrit-MessageType: newchange
Gerrit-Change-Id: I44ae817d9edb73d182ff33ff5a2fd942e224e344
Gerrit-Change-Number: 12577
Gerrit-PatchSet: 1
Gerrit-Owner: Max <msuraev at sysmocom.de>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.osmocom.org/pipermail/gerrit-log/attachments/20190116/32109078/attachment.htm>


More information about the gerrit-log mailing list