aboutsummaryrefslogtreecommitdiffstats
path: root/openbsc/tests/msc_vlr/msc_vlr_test_gsm_authen.err
diff options
context:
space:
mode:
Diffstat (limited to 'openbsc/tests/msc_vlr/msc_vlr_test_gsm_authen.err')
-rw-r--r--openbsc/tests/msc_vlr/msc_vlr_test_gsm_authen.err107
1 files changed, 36 insertions, 71 deletions
diff --git a/openbsc/tests/msc_vlr/msc_vlr_test_gsm_authen.err b/openbsc/tests/msc_vlr/msc_vlr_test_gsm_authen.err
index f9a839bcd..3589139bf 100644
--- a/openbsc/tests/msc_vlr/msc_vlr_test_gsm_authen.err
+++ b/openbsc/tests/msc_vlr/msc_vlr_test_gsm_authen.err
@@ -25,8 +25,6 @@ DVLR GSUP tx: 08010809710000004026f0
GSUP --> HLR: OSMO_GSUP_MSGT_SEND_AUTH_INFO_REQUEST: 08010809710000004026f0
DVLR VLR_Authenticate(901700000004620){VLR_SUB_AS_NEEDS_AUTH}: state_chg to VLR_SUB_AS_NEEDS_AUTH_WAIT_AI
DREF VLR subscr IMSI:901700000004620 usage decreases to: 1
-DMM compl_l3: Keeping conn
-DMM IMSI:901700000004620 owned_by_msc = true
lu_result_sent == 0
- from HLR, rx _SEND_AUTH_INFO_RESULT; VLR sends Auth Req to MS
<-- GSUP rx OSMO_GSUP_MSGT_SEND_AUTH_INFO_RESULT: 0a010809710000004026f003222010585df1ae287f6e273dce07090d61320b21042d8b2c3e220861855fb81fc2a8000322201012aca96fb4ffdea5c985cbafa9b6e18b210420bde240220807fa7502e07e1c0003222010e7c03ba7cf0e2fde82b2dc4d63077d422104a29514ae2208e2b234f80788640003222010fa8f20b781b5881329d4fea26b1a3c5121045afc8d7222082392f14f709ae000032220100fd4cc8dbe8715d1f439e304edfd68dc2104bc8d1c5b2208da7cdd6bfe2d7000
@@ -143,7 +141,6 @@ DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_DONE}: Removing from parent Subscr_Co
DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_DONE}: fsm_lu_cleanup called with cause OSMO_FSM_TERM_PARENT
DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_DONE}: Freeing instance
DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_DONE}: Deallocated
-DMM MSISDN:46071 calling bsc_subscr_con_free(), owned_by_msc = true
DRLL subscr MSISDN:46071: Freeing subscriber connection
DREF VLR subscr MSISDN:46071 usage decreases to: 2
DVLR Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Freeing instance
@@ -179,8 +176,6 @@ DVLR VLR_Authenticate(901700000004620){VLR_SUB_AS_WAIT_RESP}: got auth tuple: us
- ...rand=12aca96fb4ffdea5c985cbafa9b6e18b
- ...expecting sres=20bde240
DREF VLR subscr MSISDN:46071 usage decreases to: 2
-DMM compl_l3: Keeping conn
-DMM MSISDN:46071 owned_by_msc = true
cm_service_result_sent == 0
auth_request_sent == 1
- needs auth, not yet accepted
@@ -236,7 +231,8 @@ DVLR Subscr_Conn(901700000004620){SUBSCR_CONN_S_ACCEPTED}: Received Event SUBSCR
DVLR Subscr_Conn(901700000004620){SUBSCR_CONN_S_ACCEPTED}: state_chg to SUBSCR_CONN_S_COMMUNICATING
DMM USSD: Own number requested
DMM MSISDN:46071: MSISDN = 46071
-- DTAP --> MS: 8b2a1c27a225020100302002013b301b04010f0416d9775d0e2ae3e965f73cfd7683d27310cd06bbc51a0d
+DMSC msc_tx 43 bytes to MSISDN:46071 via RAN_GERAN_A
+- DTAP --RAN_GERAN_A--> MS: 8b2a1c27a225020100302002013b301b04010f0416d9775d0e2ae3e965f73cfd7683d27310cd06bbc51a0d
- DTAP matches expected message
DVLR Subscr_Conn(901700000004620){SUBSCR_CONN_S_COMMUNICATING}: Received Event SUBSCR_CONN_E_BUMP
DVLR Subscr_Conn(901700000004620){SUBSCR_CONN_S_COMMUNICATING}: state_chg to SUBSCR_CONN_S_RELEASED
@@ -245,7 +241,6 @@ DVLR Process_Access_Request_VLR(901700000004620){PR_ARQ_S_DONE}: Terminating (ca
DVLR Process_Access_Request_VLR(901700000004620){PR_ARQ_S_DONE}: Removing from parent Subscr_Conn(901700000004620)
DVLR Process_Access_Request_VLR(901700000004620){PR_ARQ_S_DONE}: Freeing instance
DVLR Process_Access_Request_VLR(901700000004620){PR_ARQ_S_DONE}: Deallocated
-DMM MSISDN:46071 calling bsc_subscr_con_free(), owned_by_msc = true
DRLL subscr MSISDN:46071: Freeing subscriber connection
DREF VLR subscr MSISDN:46071 usage decreases to: 1
DVLR Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Freeing instance
@@ -257,10 +252,9 @@ DVLR Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Deallocated
DREF VLR subscr MSISDN:46071 usage increases to: 2
llist_count(&vsub->cs.requests) == 0
DREF VLR subscr MSISDN:46071 usage increases to: 3
-DMM Subscriber MSISDN:46071 not paged yet.
- BTS/BSC sends out paging request to IMSI:901700000004620 for channel type 1
- strcmp(paging_expecting_imsi, sub->imsi) == 0
-DREF BSC subscr IMSI:901700000004620 usage decreases to: 0
+DMM Subscriber MSISDN:46071 not paged yet, start paging.
+ RAN_GERAN_A sends out paging request to IMSI 901700000004620, TMSI 0xffffffff, LAC 0
+ strcmp(paging_expecting_imsi, imsi) == 0
DREF VLR subscr MSISDN:46071 usage increases to: 4
llist_count(&vsub->cs.requests) == 1
DREF VLR subscr MSISDN:46071 usage decreases to: 3
@@ -295,8 +289,6 @@ DVLR VLR_Authenticate(901700000004620){VLR_SUB_AS_WAIT_RESP}: got auth tuple: us
- ...rand=e7c03ba7cf0e2fde82b2dc4d63077d42
- ...expecting sres=a29514ae
DREF VLR subscr MSISDN:46071 usage decreases to: 4
-DMM compl_l3: Keeping conn
-DMM MSISDN:46071 owned_by_msc = true
auth_request_sent == 1
- needs auth, not yet accepted
msc_subscr_conn_is_accepted() == false
@@ -336,10 +328,12 @@ DVLR Process_Access_Request_VLR(901700000004620){PR_ARQ_S_DONE}: Process Access
DVLR Subscr_Conn(901700000004620){SUBSCR_CONN_S_NEW}: Received Event SUBSCR_CONN_E_ACCEPTED
DVLR Subscr_Conn(901700000004620){SUBSCR_CONN_S_NEW}: SUBSCR_CONN_FROM_PAGING_RESP
DVLR Subscr_Conn(901700000004620){SUBSCR_CONN_S_NEW}: state_chg to SUBSCR_CONN_S_ACCEPTED
-DREF BSC subscr IMSI:901700000004620 usage decreases to: 0
+DPAG Paging success for MSISDN:46071 (event=0)
+DPAG Calling paging cbfn.
DREF VLR subscr MSISDN:46071 usage increases to: 5
DMSC subscr MSISDN:46071: increased subscr_con use_count to 1
-- DTAP --> MS: 09015801000791447758100650004c0005806470f1000007101000000000445079da1e1ee7416937485e9ea7c965373d1d6683c270383b3d0ed3d36ff71c949e83c22072799e9687c5ec32a81d96afcbf4b4fb0c7ac3e9e9b7db05
+DMSC msc_tx 91 bytes to MSISDN:46071 via RAN_GERAN_A
+- DTAP --RAN_GERAN_A--> MS: 09015801000791447758100650004c0005806470f1000007101000000000445079da1e1ee7416937485e9ea7c965373d1d6683c270383b3d0ed3d36ff71c949e83c22072799e9687c5ec32a81d96afcbf4b4fb0c7ac3e9e9b7db05
- DTAP matches expected message
DREF VLR subscr MSISDN:46071 usage decreases to: 4
DVLR Subscr_Conn(901700000004620){SUBSCR_CONN_S_ACCEPTED}: Received Event SUBSCR_CONN_E_BUMP
@@ -363,7 +357,8 @@ DVLR Subscr_Conn(901700000004620){SUBSCR_CONN_S_COMMUNICATING}: Received Event S
rx from MS: pdisc=0x89 msg_type=0x01
DRLL Dispatching 04.08 message, pdisc=9
DVLR Subscr_Conn(901700000004620){SUBSCR_CONN_S_COMMUNICATING}: Received Event SUBSCR_CONN_E_COMMUNICATING
-- DTAP --> MS: 0904
+DMSC msc_tx 2 bytes to MSISDN:46071 via RAN_GERAN_A
+- DTAP --RAN_GERAN_A--> MS: 0904
- DTAP matches expected message
DREF VLR subscr MSISDN:46071 usage decreases to: 3
DREF VLR subscr MSISDN:46071 usage decreases to: 2
@@ -375,7 +370,6 @@ DVLR Process_Access_Request_VLR(901700000004620){PR_ARQ_S_DONE}: Terminating (ca
DVLR Process_Access_Request_VLR(901700000004620){PR_ARQ_S_DONE}: Removing from parent Subscr_Conn(901700000004620)
DVLR Process_Access_Request_VLR(901700000004620){PR_ARQ_S_DONE}: Freeing instance
DVLR Process_Access_Request_VLR(901700000004620){PR_ARQ_S_DONE}: Deallocated
-DMM MSISDN:46071 calling bsc_subscr_con_free(), owned_by_msc = true
DRLL subscr MSISDN:46071: Freeing subscriber connection
DREF VLR subscr MSISDN:46071 usage decreases to: 1
DVLR Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Freeing instance
@@ -394,8 +388,6 @@ DMM Subscriber MSISDN:46071 DETACHED
DREF VLR subscr MSISDN:46071 usage decreases to: 1
DREF VLR subscr MSISDN:46071 usage decreases to: 0
DREF freeing VLR subscr MSISDN:46071
-DMM No conn_fsm, release conn
-DMM compl_l3: Discarding conn
DRLL Freeing subscriber connection with NULL subscriber
llist_count(&net->subscr_conns) == 0
===== test_gsm_authen: SUCCESS
@@ -430,8 +422,6 @@ DVLR GSUP tx: 08010809710000004026f0
GSUP --> HLR: OSMO_GSUP_MSGT_SEND_AUTH_INFO_REQUEST: 08010809710000004026f0
DVLR VLR_Authenticate(901700000004620){VLR_SUB_AS_NEEDS_AUTH}: state_chg to VLR_SUB_AS_NEEDS_AUTH_WAIT_AI
DREF VLR subscr IMSI:901700000004620 usage decreases to: 1
-DMM compl_l3: Keeping conn
-DMM IMSI:901700000004620 owned_by_msc = true
lu_result_sent == 0
- from HLR, rx _SEND_AUTH_INFO_RESULT; VLR sends Auth Req to MS
<-- GSUP rx OSMO_GSUP_MSGT_SEND_AUTH_INFO_RESULT: 0a010809710000004026f003222010585df1ae287f6e273dce07090d61320b21042d8b2c3e220861855fb81fc2a8000322201012aca96fb4ffdea5c985cbafa9b6e18b210420bde240220807fa7502e07e1c0003222010e7c03ba7cf0e2fde82b2dc4d63077d422104a29514ae2208e2b234f80788640003222010fa8f20b781b5881329d4fea26b1a3c5121045afc8d7222082392f14f709ae000032220100fd4cc8dbe8715d1f439e304edfd68dc2104bc8d1c5b2208da7cdd6bfe2d7000
@@ -578,7 +568,6 @@ DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_DONE}: Removing from parent Subscr_Co
DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_DONE}: fsm_lu_cleanup called with cause OSMO_FSM_TERM_PARENT
DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_DONE}: Freeing instance
DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_DONE}: Deallocated
-DMM MSISDN:46071 calling bsc_subscr_con_free(), owned_by_msc = true
DRLL subscr MSISDN:46071: Freeing subscriber connection
DREF VLR subscr MSISDN:46071 usage decreases to: 1
DVLR Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Freeing instance
@@ -618,8 +607,6 @@ DVLR VLR_Authenticate(50462976){VLR_SUB_AS_WAIT_RESP}: got auth tuple: use_count
- ...rand=12aca96fb4ffdea5c985cbafa9b6e18b
- ...expecting sres=20bde240
DREF VLR subscr MSISDN:46071 usage decreases to: 2
-DMM compl_l3: Keeping conn
-DMM MSISDN:46071 owned_by_msc = true
cm_service_result_sent == 0
auth_request_sent == 1
- needs auth, not yet accepted
@@ -675,7 +662,8 @@ DVLR Subscr_Conn(50462976){SUBSCR_CONN_S_ACCEPTED}: Received Event SUBSCR_CONN_E
DVLR Subscr_Conn(50462976){SUBSCR_CONN_S_ACCEPTED}: state_chg to SUBSCR_CONN_S_COMMUNICATING
DMM USSD: Own number requested
DMM MSISDN:46071: MSISDN = 46071
-- DTAP --> MS: 8b2a1c27a225020100302002013b301b04010f0416d9775d0e2ae3e965f73cfd7683d27310cd06bbc51a0d
+DMSC msc_tx 43 bytes to MSISDN:46071 via RAN_GERAN_A
+- DTAP --RAN_GERAN_A--> MS: 8b2a1c27a225020100302002013b301b04010f0416d9775d0e2ae3e965f73cfd7683d27310cd06bbc51a0d
- DTAP matches expected message
DVLR Subscr_Conn(50462976){SUBSCR_CONN_S_COMMUNICATING}: Received Event SUBSCR_CONN_E_BUMP
DVLR Subscr_Conn(50462976){SUBSCR_CONN_S_COMMUNICATING}: state_chg to SUBSCR_CONN_S_RELEASED
@@ -684,7 +672,6 @@ DVLR Process_Access_Request_VLR(50462976){PR_ARQ_S_DONE}: Terminating (cause = O
DVLR Process_Access_Request_VLR(50462976){PR_ARQ_S_DONE}: Removing from parent Subscr_Conn(50462976)
DVLR Process_Access_Request_VLR(50462976){PR_ARQ_S_DONE}: Freeing instance
DVLR Process_Access_Request_VLR(50462976){PR_ARQ_S_DONE}: Deallocated
-DMM MSISDN:46071 calling bsc_subscr_con_free(), owned_by_msc = true
DRLL subscr MSISDN:46071: Freeing subscriber connection
DREF VLR subscr MSISDN:46071 usage decreases to: 1
DVLR Subscr_Conn(50462976){SUBSCR_CONN_S_RELEASED}: Freeing instance
@@ -696,10 +683,9 @@ DVLR Subscr_Conn(50462976){SUBSCR_CONN_S_RELEASED}: Deallocated
DREF VLR subscr MSISDN:46071 usage increases to: 2
llist_count(&vsub->cs.requests) == 0
DREF VLR subscr MSISDN:46071 usage increases to: 3
-DMM Subscriber MSISDN:46071 not paged yet.
- BTS/BSC sends out paging request to IMSI:901700000004620 for channel type 1
+DMM Subscriber MSISDN:46071 not paged yet, start paging.
+ RAN_GERAN_A sends out paging request to IMSI 901700000004620, TMSI 0x03020100, LAC 0
paging_expecting_tmsi == 0x03020100
-DREF BSC subscr IMSI:901700000004620 usage decreases to: 0
DREF VLR subscr MSISDN:46071 usage increases to: 4
llist_count(&vsub->cs.requests) == 1
DREF VLR subscr MSISDN:46071 usage decreases to: 3
@@ -734,8 +720,6 @@ DVLR VLR_Authenticate(50462976){VLR_SUB_AS_WAIT_RESP}: got auth tuple: use_count
- ...rand=e7c03ba7cf0e2fde82b2dc4d63077d42
- ...expecting sres=a29514ae
DREF VLR subscr MSISDN:46071 usage decreases to: 4
-DMM compl_l3: Keeping conn
-DMM MSISDN:46071 owned_by_msc = true
auth_request_sent == 1
- needs auth, not yet accepted
msc_subscr_conn_is_accepted() == false
@@ -775,10 +759,12 @@ DVLR Process_Access_Request_VLR(50462976){PR_ARQ_S_DONE}: Process Access Request
DVLR Subscr_Conn(50462976){SUBSCR_CONN_S_NEW}: Received Event SUBSCR_CONN_E_ACCEPTED
DVLR Subscr_Conn(50462976){SUBSCR_CONN_S_NEW}: SUBSCR_CONN_FROM_PAGING_RESP
DVLR Subscr_Conn(50462976){SUBSCR_CONN_S_NEW}: state_chg to SUBSCR_CONN_S_ACCEPTED
-DREF BSC subscr IMSI:901700000004620 usage decreases to: 0
+DPAG Paging success for MSISDN:46071 (event=0)
+DPAG Calling paging cbfn.
DREF VLR subscr MSISDN:46071 usage increases to: 5
DMSC subscr MSISDN:46071: increased subscr_con use_count to 1
-- DTAP --> MS: 09015801000791447758100650004c0005806470f1000007101000000000445079da1e1ee7416937485e9ea7c965373d1d6683c270383b3d0ed3d36ff71c949e83c22072799e9687c5ec32a81d96afcbf4b4fb0c7ac3e9e9b7db05
+DMSC msc_tx 91 bytes to MSISDN:46071 via RAN_GERAN_A
+- DTAP --RAN_GERAN_A--> MS: 09015801000791447758100650004c0005806470f1000007101000000000445079da1e1ee7416937485e9ea7c965373d1d6683c270383b3d0ed3d36ff71c949e83c22072799e9687c5ec32a81d96afcbf4b4fb0c7ac3e9e9b7db05
- DTAP matches expected message
DREF VLR subscr MSISDN:46071 usage decreases to: 4
DVLR Subscr_Conn(50462976){SUBSCR_CONN_S_ACCEPTED}: Received Event SUBSCR_CONN_E_BUMP
@@ -802,7 +788,8 @@ DVLR Subscr_Conn(50462976){SUBSCR_CONN_S_COMMUNICATING}: Received Event SUBSCR_C
rx from MS: pdisc=0x89 msg_type=0x01
DRLL Dispatching 04.08 message, pdisc=9
DVLR Subscr_Conn(50462976){SUBSCR_CONN_S_COMMUNICATING}: Received Event SUBSCR_CONN_E_COMMUNICATING
-- DTAP --> MS: 0904
+DMSC msc_tx 2 bytes to MSISDN:46071 via RAN_GERAN_A
+- DTAP --RAN_GERAN_A--> MS: 0904
- DTAP matches expected message
DREF VLR subscr MSISDN:46071 usage decreases to: 3
DREF VLR subscr MSISDN:46071 usage decreases to: 2
@@ -814,7 +801,6 @@ DVLR Process_Access_Request_VLR(50462976){PR_ARQ_S_DONE}: Terminating (cause = O
DVLR Process_Access_Request_VLR(50462976){PR_ARQ_S_DONE}: Removing from parent Subscr_Conn(50462976)
DVLR Process_Access_Request_VLR(50462976){PR_ARQ_S_DONE}: Freeing instance
DVLR Process_Access_Request_VLR(50462976){PR_ARQ_S_DONE}: Deallocated
-DMM MSISDN:46071 calling bsc_subscr_con_free(), owned_by_msc = true
DRLL subscr MSISDN:46071: Freeing subscriber connection
DREF VLR subscr MSISDN:46071 usage decreases to: 1
DVLR Subscr_Conn(50462976){SUBSCR_CONN_S_RELEASED}: Freeing instance
@@ -850,8 +836,6 @@ DVLR VLR_Authenticate(50462976){VLR_SUB_AS_WAIT_RESP}: got auth tuple: use_count
- ...rand=fa8f20b781b5881329d4fea26b1a3c51
- ...expecting sres=5afc8d72
DREF VLR subscr MSISDN:46071 usage decreases to: 2
-DMM compl_l3: Keeping conn
-DMM MSISDN:46071 owned_by_msc = true
auth_request_sent == 1
lu_result_sent == 0
- MS sends Authen Response, VLR accepts and sends GSUP LU Req to HLR
@@ -964,7 +948,6 @@ DVLR vlr_lu_fsm(50462976){VLR_ULA_S_DONE}: Removing from parent Subscr_Conn(5046
DVLR vlr_lu_fsm(50462976){VLR_ULA_S_DONE}: fsm_lu_cleanup called with cause OSMO_FSM_TERM_PARENT
DVLR vlr_lu_fsm(50462976){VLR_ULA_S_DONE}: Freeing instance
DVLR vlr_lu_fsm(50462976){VLR_ULA_S_DONE}: Deallocated
-DMM MSISDN:46071 calling bsc_subscr_con_free(), owned_by_msc = true
DRLL subscr MSISDN:46071: Freeing subscriber connection
DREF VLR subscr MSISDN:46071 usage decreases to: 1
DVLR Subscr_Conn(50462976){SUBSCR_CONN_S_RELEASED}: Freeing instance
@@ -989,8 +972,6 @@ DMM Subscriber MSISDN:46071 DETACHED
DREF VLR subscr MSISDN:46071 usage decreases to: 1
DREF VLR subscr MSISDN:46071 usage decreases to: 0
DREF freeing VLR subscr MSISDN:46071
-DMM No conn_fsm, release conn
-DMM compl_l3: Discarding conn
DRLL Freeing subscriber connection with NULL subscriber
llist_count(&net->subscr_conns) == 0
===== test_gsm_authen_tmsi: SUCCESS
@@ -1025,8 +1006,6 @@ DVLR GSUP tx: 08010809710000004026f0
GSUP --> HLR: OSMO_GSUP_MSGT_SEND_AUTH_INFO_REQUEST: 08010809710000004026f0
DVLR VLR_Authenticate(901700000004620){VLR_SUB_AS_NEEDS_AUTH}: state_chg to VLR_SUB_AS_NEEDS_AUTH_WAIT_AI
DREF VLR subscr IMSI:901700000004620 usage decreases to: 1
-DMM compl_l3: Keeping conn
-DMM IMSI:901700000004620 owned_by_msc = true
lu_result_sent == 0
- from HLR, rx _SEND_AUTH_INFO_RESULT; VLR sends Auth Req to MS
<-- GSUP rx OSMO_GSUP_MSGT_SEND_AUTH_INFO_RESULT: 0a010809710000004026f003222010585df1ae287f6e273dce07090d61320b21042d8b2c3e220861855fb81fc2a8000322201012aca96fb4ffdea5c985cbafa9b6e18b210420bde240220807fa7502e07e1c0003222010e7c03ba7cf0e2fde82b2dc4d63077d422104a29514ae2208e2b234f80788640003222010fa8f20b781b5881329d4fea26b1a3c5121045afc8d7222082392f14f709ae000032220100fd4cc8dbe8715d1f439e304edfd68dc2104bc8d1c5b2208da7cdd6bfe2d7000
@@ -1124,7 +1103,8 @@ DVLR sub_pres_vlr_fsm(901700000004620){SUB_PRES_VLR_S_DONE}: Freeing instance
DVLR sub_pres_vlr_fsm(901700000004620){SUB_PRES_VLR_S_DONE}: Deallocated
DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_WAIT_SUB_PRES}: Received Event LU_COMPL_VLR_E_SUB_PRES_COMPL
DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_WAIT_SUB_PRES}: state_chg to LU_COMPL_VLR_S_WAIT_IMEI
-- DTAP --> MS: 051802
+DMSC msc_tx 3 bytes to MSISDN:46071 via RAN_GERAN_A
+- DTAP --RAN_GERAN_A--> MS: 051802
- DTAP matches expected message
DREF VLR subscr MSISDN:46071 usage decreases to: 1
<-- GSUP rx OSMO_GSUP_MSGT_UPDATE_LOCATION_RESULT: vlr_gsupc_read_cb() returns 0
@@ -1170,7 +1150,6 @@ DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_DONE}: Removing from parent Subscr_Co
DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_DONE}: fsm_lu_cleanup called with cause OSMO_FSM_TERM_PARENT
DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_DONE}: Freeing instance
DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_DONE}: Deallocated
-DMM MSISDN:46071 calling bsc_subscr_con_free(), owned_by_msc = true
DRLL subscr MSISDN:46071: Freeing subscriber connection
DREF VLR subscr MSISDN:46071 usage decreases to: 1
DVLR Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Freeing instance
@@ -1193,8 +1172,6 @@ DMM Subscriber MSISDN:46071 DETACHED
DREF VLR subscr MSISDN:46071 usage decreases to: 1
DREF VLR subscr MSISDN:46071 usage decreases to: 0
DREF freeing VLR subscr MSISDN:46071
-DMM No conn_fsm, release conn
-DMM compl_l3: Discarding conn
DRLL Freeing subscriber connection with NULL subscriber
llist_count(&net->subscr_conns) == 0
===== test_gsm_authen_imei: SUCCESS
@@ -1229,8 +1206,6 @@ DVLR GSUP tx: 08010809710000004026f0
GSUP --> HLR: OSMO_GSUP_MSGT_SEND_AUTH_INFO_REQUEST: 08010809710000004026f0
DVLR VLR_Authenticate(901700000004620){VLR_SUB_AS_NEEDS_AUTH}: state_chg to VLR_SUB_AS_NEEDS_AUTH_WAIT_AI
DREF VLR subscr IMSI:901700000004620 usage decreases to: 1
-DMM compl_l3: Keeping conn
-DMM IMSI:901700000004620 owned_by_msc = true
lu_result_sent == 0
- from HLR, rx _SEND_AUTH_INFO_RESULT; VLR sends Auth Req to MS
<-- GSUP rx OSMO_GSUP_MSGT_SEND_AUTH_INFO_RESULT: 0a010809710000004026f003222010585df1ae287f6e273dce07090d61320b21042d8b2c3e220861855fb81fc2a8000322201012aca96fb4ffdea5c985cbafa9b6e18b210420bde240220807fa7502e07e1c0003222010e7c03ba7cf0e2fde82b2dc4d63077d422104a29514ae2208e2b234f80788640003222010fa8f20b781b5881329d4fea26b1a3c5121045afc8d7222082392f14f709ae000032220100fd4cc8dbe8715d1f439e304edfd68dc2104bc8d1c5b2208da7cdd6bfe2d7000
@@ -1328,7 +1303,8 @@ DVLR sub_pres_vlr_fsm(901700000004620){SUB_PRES_VLR_S_DONE}: Freeing instance
DVLR sub_pres_vlr_fsm(901700000004620){SUB_PRES_VLR_S_DONE}: Deallocated
DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_WAIT_SUB_PRES}: Received Event LU_COMPL_VLR_E_SUB_PRES_COMPL
DVLR lu_compl_vlr_fsm(901700000004620){LU_COMPL_VLR_S_WAIT_SUB_PRES}: state_chg to LU_COMPL_VLR_S_WAIT_IMEI_TMSI
-- DTAP --> MS: 051802
+DMSC msc_tx 3 bytes to MSISDN:46071 via RAN_GERAN_A
+- DTAP --RAN_GERAN_A--> MS: 051802
- DTAP matches expected message
DREF VLR subscr MSISDN:46071 usage decreases to: 1
<-- GSUP rx OSMO_GSUP_MSGT_UPDATE_LOCATION_RESULT: vlr_gsupc_read_cb() returns 0
@@ -1402,7 +1378,6 @@ DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_DONE}: Removing from parent Subscr_Co
DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_DONE}: fsm_lu_cleanup called with cause OSMO_FSM_TERM_PARENT
DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_DONE}: Freeing instance
DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_DONE}: Deallocated
-DMM MSISDN:46071 calling bsc_subscr_con_free(), owned_by_msc = true
DRLL subscr MSISDN:46071: Freeing subscriber connection
DREF VLR subscr MSISDN:46071 usage decreases to: 1
DVLR Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Freeing instance
@@ -1425,8 +1400,6 @@ DMM Subscriber MSISDN:46071 DETACHED
DREF VLR subscr MSISDN:46071 usage decreases to: 1
DREF VLR subscr MSISDN:46071 usage decreases to: 0
DREF freeing VLR subscr MSISDN:46071
-DMM No conn_fsm, release conn
-DMM compl_l3: Discarding conn
DRLL Freeing subscriber connection with NULL subscriber
llist_count(&net->subscr_conns) == 0
===== test_gsm_authen_tmsi_imei: SUCCESS
@@ -1461,8 +1434,6 @@ DVLR GSUP tx: 08010809710000000156f0
GSUP --> HLR: OSMO_GSUP_MSGT_SEND_AUTH_INFO_REQUEST: 08010809710000000156f0
DVLR VLR_Authenticate(901700000010650){VLR_SUB_AS_NEEDS_AUTH}: state_chg to VLR_SUB_AS_NEEDS_AUTH_WAIT_AI
DREF VLR subscr IMSI:901700000010650 usage decreases to: 1
-DMM compl_l3: Keeping conn
-DMM IMSI:901700000010650 owned_by_msc = true
lu_result_sent == 0
- from HLR, rx _SEND_AUTH_INFO_RESULT; VLR sends Auth Req to MS
<-- GSUP rx OSMO_GSUP_MSGT_SEND_AUTH_INFO_RESULT: 0a010809710000000156f00362201039fa2f4e3d523d8619a73b4f65c3e14d21049b36efdf2208059a4f668f6fbe39231027497388b6cb044648f396aa155b95ef2410f64735036e5871319c679f4742a75ea125108704f5ba55f30000d2ee44b22c8ea9192708e229c19e791f2e4103622010c187a53a5e6b9d573cac7c74451fd46d210485aa31302208d3d50a000bf04f6e23101159ec926a50e98c034a6b7d7c9f418d2410df3a03d9ca5335641efc8e36d76cd20b25101843a645b98d00005b2d666af46c45d927087db47cf7f81e4dc703622010efa9c29a9742148d5c9070348716e1bb210469d5f9fb22083df176f0c29f1a3d2310eb50e770ddcc3060101d2f43b6c2b884241076542abce5ff9345b0e8947f4c6e019c2510f9375e6d41e1000096e7fe4ff1c27e392708706f996719ba609c
@@ -1560,7 +1531,6 @@ DVLR vlr_lu_fsm(901700000010650){VLR_ULA_S_DONE}: Removing from parent Subscr_Co
DVLR vlr_lu_fsm(901700000010650){VLR_ULA_S_DONE}: fsm_lu_cleanup called with cause OSMO_FSM_TERM_PARENT
DVLR vlr_lu_fsm(901700000010650){VLR_ULA_S_DONE}: Freeing instance
DVLR vlr_lu_fsm(901700000010650){VLR_ULA_S_DONE}: Deallocated
-DMM MSISDN:42342 calling bsc_subscr_con_free(), owned_by_msc = true
DRLL subscr MSISDN:42342: Freeing subscriber connection
DREF VLR subscr MSISDN:42342 usage decreases to: 2
DVLR Subscr_Conn(901700000010650){SUBSCR_CONN_S_RELEASED}: Freeing instance
@@ -1596,8 +1566,6 @@ DVLR VLR_Authenticate(901700000010650){VLR_SUB_AS_WAIT_RESP}: got auth tuple: us
- ...rand=c187a53a5e6b9d573cac7c74451fd46d
- ...expecting sres=85aa3130
DREF VLR subscr MSISDN:42342 usage decreases to: 2
-DMM compl_l3: Keeping conn
-DMM MSISDN:42342 owned_by_msc = true
cm_service_result_sent == 0
auth_request_sent == 1
- needs auth, not yet accepted
@@ -1653,7 +1621,8 @@ DVLR Subscr_Conn(901700000010650){SUBSCR_CONN_S_ACCEPTED}: Received Event SUBSCR
DVLR Subscr_Conn(901700000010650){SUBSCR_CONN_S_ACCEPTED}: state_chg to SUBSCR_CONN_S_COMMUNICATING
DMM USSD: Own number requested
DMM MSISDN:42342: MSISDN = 42342
-- DTAP --> MS: 8b2a1c27a225020100302002013b301b04010f0416d9775d0e2ae3e965f73cfd7683d273104d36a3c91a0d
+DMSC msc_tx 43 bytes to MSISDN:42342 via RAN_GERAN_A
+- DTAP --RAN_GERAN_A--> MS: 8b2a1c27a225020100302002013b301b04010f0416d9775d0e2ae3e965f73cfd7683d273104d36a3c91a0d
- DTAP matches expected message
DVLR Subscr_Conn(901700000010650){SUBSCR_CONN_S_COMMUNICATING}: Received Event SUBSCR_CONN_E_BUMP
DVLR Subscr_Conn(901700000010650){SUBSCR_CONN_S_COMMUNICATING}: state_chg to SUBSCR_CONN_S_RELEASED
@@ -1662,7 +1631,6 @@ DVLR Process_Access_Request_VLR(901700000010650){PR_ARQ_S_DONE}: Terminating (ca
DVLR Process_Access_Request_VLR(901700000010650){PR_ARQ_S_DONE}: Removing from parent Subscr_Conn(901700000010650)
DVLR Process_Access_Request_VLR(901700000010650){PR_ARQ_S_DONE}: Freeing instance
DVLR Process_Access_Request_VLR(901700000010650){PR_ARQ_S_DONE}: Deallocated
-DMM MSISDN:42342 calling bsc_subscr_con_free(), owned_by_msc = true
DRLL subscr MSISDN:42342: Freeing subscriber connection
DREF VLR subscr MSISDN:42342 usage decreases to: 1
DVLR Subscr_Conn(901700000010650){SUBSCR_CONN_S_RELEASED}: Freeing instance
@@ -1674,10 +1642,9 @@ DVLR Subscr_Conn(901700000010650){SUBSCR_CONN_S_RELEASED}: Deallocated
DREF VLR subscr MSISDN:42342 usage increases to: 2
llist_count(&vsub->cs.requests) == 0
DREF VLR subscr MSISDN:42342 usage increases to: 3
-DMM Subscriber MSISDN:42342 not paged yet.
- BTS/BSC sends out paging request to IMSI:901700000010650 for channel type 1
- strcmp(paging_expecting_imsi, sub->imsi) == 0
-DREF BSC subscr IMSI:901700000010650 usage decreases to: 0
+DMM Subscriber MSISDN:42342 not paged yet, start paging.
+ RAN_GERAN_A sends out paging request to IMSI 901700000010650, TMSI 0xffffffff, LAC 0
+ strcmp(paging_expecting_imsi, imsi) == 0
DREF VLR subscr MSISDN:42342 usage increases to: 4
llist_count(&vsub->cs.requests) == 1
DREF VLR subscr MSISDN:42342 usage decreases to: 3
@@ -1712,8 +1679,6 @@ DVLR VLR_Authenticate(901700000010650){VLR_SUB_AS_WAIT_RESP}: got auth tuple: us
- ...rand=efa9c29a9742148d5c9070348716e1bb
- ...expecting sres=69d5f9fb
DREF VLR subscr MSISDN:42342 usage decreases to: 4
-DMM compl_l3: Keeping conn
-DMM MSISDN:42342 owned_by_msc = true
auth_request_sent == 1
- needs auth, not yet accepted
msc_subscr_conn_is_accepted() == false
@@ -1753,10 +1718,12 @@ DVLR Process_Access_Request_VLR(901700000010650){PR_ARQ_S_DONE}: Process Access
DVLR Subscr_Conn(901700000010650){SUBSCR_CONN_S_NEW}: Received Event SUBSCR_CONN_E_ACCEPTED
DVLR Subscr_Conn(901700000010650){SUBSCR_CONN_S_NEW}: SUBSCR_CONN_FROM_PAGING_RESP
DVLR Subscr_Conn(901700000010650){SUBSCR_CONN_S_NEW}: state_chg to SUBSCR_CONN_S_ACCEPTED
-DREF BSC subscr IMSI:901700000010650 usage decreases to: 0
+DPAG Paging success for MSISDN:42342 (event=0)
+DPAG Calling paging cbfn.
DREF VLR subscr MSISDN:42342 usage increases to: 5
DMSC subscr MSISDN:42342: increased subscr_con use_count to 1
-- DTAP --> MS: 09015801000791447758100650004c0005802443f2000007101000000000445079da1e1ee7416937485e9ea7c965373d1d6683c270383b3d0ed3d36ff71c949e83c22072799e9687c5ec32a81d96afcbf4b4fb0c7ac3e9e9b7db05
+DMSC msc_tx 91 bytes to MSISDN:42342 via RAN_GERAN_A
+- DTAP --RAN_GERAN_A--> MS: 09015801000791447758100650004c0005802443f2000007101000000000445079da1e1ee7416937485e9ea7c965373d1d6683c270383b3d0ed3d36ff71c949e83c22072799e9687c5ec32a81d96afcbf4b4fb0c7ac3e9e9b7db05
- DTAP matches expected message
DREF VLR subscr MSISDN:42342 usage decreases to: 4
DVLR Subscr_Conn(901700000010650){SUBSCR_CONN_S_ACCEPTED}: Received Event SUBSCR_CONN_E_BUMP
@@ -1780,7 +1747,8 @@ DVLR Subscr_Conn(901700000010650){SUBSCR_CONN_S_COMMUNICATING}: Received Event S
rx from MS: pdisc=0x89 msg_type=0x01
DRLL Dispatching 04.08 message, pdisc=9
DVLR Subscr_Conn(901700000010650){SUBSCR_CONN_S_COMMUNICATING}: Received Event SUBSCR_CONN_E_COMMUNICATING
-- DTAP --> MS: 0904
+DMSC msc_tx 2 bytes to MSISDN:42342 via RAN_GERAN_A
+- DTAP --RAN_GERAN_A--> MS: 0904
- DTAP matches expected message
DREF VLR subscr MSISDN:42342 usage decreases to: 3
DREF VLR subscr MSISDN:42342 usage decreases to: 2
@@ -1792,7 +1760,6 @@ DVLR Process_Access_Request_VLR(901700000010650){PR_ARQ_S_DONE}: Terminating (ca
DVLR Process_Access_Request_VLR(901700000010650){PR_ARQ_S_DONE}: Removing from parent Subscr_Conn(901700000010650)
DVLR Process_Access_Request_VLR(901700000010650){PR_ARQ_S_DONE}: Freeing instance
DVLR Process_Access_Request_VLR(901700000010650){PR_ARQ_S_DONE}: Deallocated
-DMM MSISDN:42342 calling bsc_subscr_con_free(), owned_by_msc = true
DRLL subscr MSISDN:42342: Freeing subscriber connection
DREF VLR subscr MSISDN:42342 usage decreases to: 1
DVLR Subscr_Conn(901700000010650){SUBSCR_CONN_S_RELEASED}: Freeing instance
@@ -1811,8 +1778,6 @@ DMM Subscriber MSISDN:42342 DETACHED
DREF VLR subscr MSISDN:42342 usage decreases to: 1
DREF VLR subscr MSISDN:42342 usage decreases to: 0
DREF freeing VLR subscr MSISDN:42342
-DMM No conn_fsm, release conn
-DMM compl_l3: Discarding conn
DRLL Freeing subscriber connection with NULL subscriber
llist_count(&net->subscr_conns) == 0
===== test_gsm_milenage_authen: SUCCESS