From 4813152691df910f9dbdb05d9e418be106c2cd14 Mon Sep 17 00:00:00 2001 From: Max Date: Wed, 16 Jan 2019 12:47:39 +0100 Subject: [PATCH] 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 --- src/libmsc/gsm_04_11.c | 3 +- tests/msc_vlr/msc_vlr_test_gsm_authen.err | 105 +++++++++++ tests/msc_vlr/msc_vlr_test_gsm_ciph.err | 175 ++++++++++++++++++ tests/msc_vlr/msc_vlr_test_ms_timeout.err | 63 +++++++ tests/msc_vlr/msc_vlr_test_no_authen.err | 70 +++++++ .../msc_vlr_test_reject_concurrency.err | 105 +++++++++++ tests/msc_vlr/msc_vlr_test_umts_authen.err | 70 +++++++ tests/msc_vlr/msc_vlr_tests.c | 2 +- 8 files changed, 590 insertions(+), 3 deletions(-) diff --git a/src/libmsc/gsm_04_11.c b/src/libmsc/gsm_04_11.c index 15a92d487..8ef26a709 100644 --- a/src/libmsc/gsm_04_11.c +++ b/src/libmsc/gsm_04_11.c @@ -135,8 +135,7 @@ static int paging_cb_mmsms_est_req(unsigned int hooknum, unsigned int event, 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 c69fde84b..6a6783325 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 @@ DMM RAN_conn(IMSI-901700000004620:MSISDN-46071:GERAN-A-0:CM_SERVICE_REQ){RAN_CON 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 @@ DVLR Process_Access_Request_VLR(IMSI-901700000004620:MSISDN-46071:GERAN-A-0:PAGI 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 @@ DREF VLR subscr IMSI-901700000004620:MSISDN-46071 usage decreases to: 4 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 @@ DMM RAN_conn(IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100:GERAN-A-0:CM_SERV 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 @@ DVLR Process_Access_Request_VLR(IMSI-901700000004620:MSISDN-46071:TMSI-0x0302010 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 @@ DREF VLR subscr IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100 usage decrease 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: ) @@ -2343,8 +2413,17 @@ DMM RAN_conn(IMSI-901700000010650:MSISDN-42342:GERAN-A-0:CM_SERVICE_REQ){RAN_CON 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 @@ -2427,7 +2506,13 @@ DVLR Process_Access_Request_VLR(IMSI-901700000010650:MSISDN-42342:GERAN-A-0:PAGI 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 @@ -2447,19 +2532,39 @@ DREF VLR subscr IMSI-901700000010650:MSISDN-42342 usage decreases to: 4 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 914683f59..af1138519 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 @@ DMM RAN_conn(IMSI-901700000004620:MSISDN-46071:GERAN-A-0:CM_SERVICE_REQ){RAN_CON 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 @@ DVLR Process_Access_Request_VLR(IMSI-901700000004620:MSISDN-46071:GERAN-A-0:PAGI 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 @@ DREF VLR subscr IMSI-901700000004620:MSISDN-46071 usage decreases to: 4 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 @@ DMM RAN_conn(IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100:GERAN-A-0:CM_SERV 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 @@ DVLR Process_Access_Request_VLR(IMSI-901700000004620:MSISDN-46071:TMSI-0x0302010 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 @@ DREF VLR subscr IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100 usage decrease 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: ) @@ -2086,8 +2156,17 @@ DMM RAN_conn(IMSI-901700000010650:MSISDN-42342:GERAN-A-0:CM_SERVICE_REQ){RAN_CON 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 @@ -2185,7 +2264,13 @@ DVLR Process_Access_Request_VLR(IMSI-901700000010650:MSISDN-42342:GERAN-A-0:PAGI 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 @@ -2204,19 +2289,39 @@ DREF VLR subscr IMSI-901700000010650:MSISDN-42342 usage decreases to: 4 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: ) @@ -2576,8 +2681,17 @@ DMM RAN_conn(IMSI-901700000004620:MSISDN-42342:GERAN-A-0:CM_SERVICE_REQ){RAN_CON 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 @@ -2685,7 +2799,13 @@ DVLR Process_Access_Request_VLR(IMSI-901700000004620:MSISDN-42342:GERAN-A-0:PAGI 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 @@ -2704,19 +2824,39 @@ DREF VLR subscr IMSI-901700000004620:MSISDN-42342 usage decreases to: 4 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: ) @@ -3076,8 +3216,17 @@ DMM RAN_conn(IMSI-901700000004620:MSISDN-42342:GERAN-A-0:CM_SERVICE_REQ){RAN_CON 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 @@ -3180,7 +3329,13 @@ DVLR Process_Access_Request_VLR(IMSI-901700000004620:MSISDN-42342:GERAN-A-0:PAGI 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 @@ -3199,19 +3354,39 @@ DREF VLR subscr IMSI-901700000004620:MSISDN-42342 usage decreases to: 4 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 537291924..e09389c0c 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 @@ DMM RAN_conn(IMSI-901700000004620:MSISDN-46071:GERAN-A-0:LU){RAN_CONN_S_RELEASED 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 @@ DREF VLR subscr IMSI-901700000004620: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 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 @@ DREF VLR subscr IMSI-901700000004620:MSISDN-46071 usage decreases to: 6 - 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 @@ DREF VLR subscr IMSI-901700000004620:MSISDN-46071 usage increases to: 2 --- - 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 @@ DREF VLR subscr IMSI-901700000004620:MSISDN-46071 usage increases to: 5 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 3f6d8cd0b..96d1ad76d 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 @@ DMM RAN_conn(IMSI-901700000004620:MSISDN-46071:GERAN-A-0:CM_SERVICE_REQ){RAN_CON 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 @@ DVLR Process_Access_Request_VLR(IMSI-901700000004620:MSISDN-46071:GERAN-A-0:PAGI 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 @@ DREF VLR subscr IMSI-901700000004620:MSISDN-46071 usage decreases to: 4 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 @@ DMM RAN_conn(IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100:GERAN-A-0:CM_SERV 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 @@ DVLR Process_Access_Request_VLR(IMSI-901700000004620:MSISDN-46071:TMSI-0x0302010 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 @@ DREF VLR subscr IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100 usage decrease 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 f5692b9cc..2147e8488 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 @@ DMM RAN_conn(IMSI-901700000004620:MSISDN-46071:GERAN-A-0:LU){RAN_CONN_S_RELEASED 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 @@ DVLR Process_Access_Request_VLR(IMSI-901700000004620:MSISDN-46071:GERAN-A-0:PAGI 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 @@ DREF IMSI-901700000004620:MSISDN-46071: MSC conn use - dtap == 1 (0x20: trans_sm 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 @@ DMM RAN_conn(IMSI-901700000004620:MSISDN-46071:GERAN-A-0:LU){RAN_CONN_S_RELEASED 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 @@ DVLR Process_Access_Request_VLR(IMSI-901700000004620:MSISDN-46071:GERAN-A-0:PAGI 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 @@ DREF IMSI-901700000004620:MSISDN-46071: MSC conn use - dtap == 2 (0x28: cm_servi 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 @@ DMM RAN_conn(IMSI-901700000004620:MSISDN-46071:GERAN-A-0:LU){RAN_CONN_S_RELEASED 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 @@ DVLR Process_Access_Request_VLR(IMSI-901700000004620:MSISDN-46071:GERAN-A-0:PAGI 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 @@ DREF IMSI-901700000004620:MSISDN-46071: MSC conn use - dtap == 1 (0x20: trans_sm 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 18addc353..ee9eeba49 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 @@ DMM RAN_conn(IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100:GERAN-A-0:CM_SERV 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 @@ DVLR Process_Access_Request_VLR(IMSI-901700000010650:MSISDN-42342:TMSI-0x0302010 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 @@ DREF VLR subscr IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100 usage decrease 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 @@ DMM RAN_conn(IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100:UTRAN-Iu-42:CM_SE 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 @@ DVLR Process_Access_Request_VLR(IMSI-901700000010650:MSISDN-42342:TMSI-0x0302010 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 @@ DREF VLR subscr IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100 usage decrease 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 44ecc5038..296f055fb 100644 --- a/tests/msc_vlr/msc_vlr_tests.c +++ b/tests/msc_vlr/msc_vlr_tests.c @@ -1023,9 +1023,9 @@ int main(int argc, char **argv) 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);