From d89e1c592731e59d90b43c1f0c8b0b0e1cf21023 Mon Sep 17 00:00:00 2001 From: Neels Hofmeyr Date: Thu, 2 Mar 2017 02:37:39 +0100 Subject: Make the code work so that the msc_vlr tests pass Change-Id: Ie8814d856bbe4c111007a696a4d26576854c134f --- openbsc/include/openbsc/gsm_04_08.h | 1 - openbsc/include/openbsc/gsm_data.h | 26 ++-- openbsc/include/openbsc/gsm_subscriber.h | 1 - openbsc/include/openbsc/msc_ifaces.h | 9 +- openbsc/include/openbsc/osmo_msc.h | 6 +- openbsc/include/openbsc/vlr.h | 2 + openbsc/src/libcommon/gsm_data.c | 7 + openbsc/src/libmsc/a_iface.c | 8 ++ openbsc/src/libmsc/gsm_04_08.c | 92 ++++++------- openbsc/src/libmsc/gsm_04_11.c | 3 +- openbsc/src/libmsc/gsm_subscriber.c | 148 +++++---------------- openbsc/src/libmsc/iucs.c | 7 +- openbsc/src/libmsc/msc_ifaces.c | 14 +- openbsc/src/libmsc/osmo_msc.c | 60 ++------- openbsc/src/libmsc/silent_call.c | 2 +- openbsc/src/libmsc/subscr_conn.c | 35 +++-- openbsc/src/libmsc/transaction.c | 18 ++- openbsc/src/libmsc/vty_interface_layer3.c | 92 +------------ openbsc/src/osmo-msc/iucs_ranap.c | 17 +-- openbsc/src/osmo-msc/msc_main.c | 31 ++--- openbsc/tests/channel/channel_test.c | 9 +- openbsc/tests/libiudummy/iudummy.c | 9 +- openbsc/tests/msc_vlr/Makefile.am | 10 +- openbsc/tests/msc_vlr/msc_vlr_test_gsm_authen.err | 107 +++++---------- openbsc/tests/msc_vlr/msc_vlr_test_gsm_ciph.err | 79 ++++------- openbsc/tests/msc_vlr/msc_vlr_test_hlr_reject.err | 39 +----- openbsc/tests/msc_vlr/msc_vlr_test_hlr_timeout.err | 8 +- openbsc/tests/msc_vlr/msc_vlr_test_ms_timeout.err | 11 +- openbsc/tests/msc_vlr/msc_vlr_test_no_authen.c | 10 ++ openbsc/tests/msc_vlr/msc_vlr_test_no_authen.err | 78 ++++------- .../msc_vlr/msc_vlr_test_reject_concurrency.err | 105 +++++---------- openbsc/tests/msc_vlr/msc_vlr_test_rest.c | 1 - openbsc/tests/msc_vlr/msc_vlr_test_rest.err | 21 +-- openbsc/tests/msc_vlr/msc_vlr_test_umts_authen.err | 66 +++------ openbsc/tests/msc_vlr/msc_vlr_tests.c | 75 +++++++---- openbsc/tests/sms_queue/Makefile.am | 2 + 36 files changed, 415 insertions(+), 794 deletions(-) (limited to 'openbsc') diff --git a/openbsc/include/openbsc/gsm_04_08.h b/openbsc/include/openbsc/gsm_04_08.h index c70227e83..0cd8ea171 100644 --- a/openbsc/include/openbsc/gsm_04_08.h +++ b/openbsc/include/openbsc/gsm_04_08.h @@ -46,7 +46,6 @@ void gsm0408_clear_all_trans(struct gsm_network *net, int protocol); int gsm0408_dispatch(struct gsm_subscriber_connection *conn, struct msgb *msg); int gsm0408_rcvmsg(struct msgb *msg, uint8_t link_id); -int gsm0408_new_conn(struct gsm_subscriber_connection *conn); enum gsm_chan_t get_ctype_by_chreq(struct gsm_network *bts, uint8_t ra); /* don't use "enum gsm_chreq_reason_t" to avoid circular dependency */ int get_reason_by_chreq(uint8_t ra, int neci); diff --git a/openbsc/include/openbsc/gsm_data.h b/openbsc/include/openbsc/gsm_data.h index 1c9fe1b3d..6d7537577 100644 --- a/openbsc/include/openbsc/gsm_data.h +++ b/openbsc/include/openbsc/gsm_data.h @@ -104,6 +104,10 @@ enum ran_type { RAN_UTRAN_IU, /* 3G / Iu-interface (IuCS or IuPS) */ }; +extern const struct value_string ran_type_names[]; +static inline const char *ran_type_name(enum ran_type val) +{ return get_value_string(ran_type_names, val); } + struct gsm_classmark { bool classmark1_set; struct gsm48_classmark1 classmark1; @@ -128,23 +132,6 @@ struct gsm_subscriber_connection { * towards A/Iu */ uint32_t use_count; - /* temporary hack: while the same gsm_subscriber_connection is in use - * between libbsc and libmsc, we need to prevent a second free from - * within libbsc after bsc_api->compl_l3() returns. In - * gsm0408_rcvmsg(), compl_l3() is called, and if it returns - * BSC_API_CONN_POL_REJECT, the conn is discarded right away. This is - * the only instance where libbsc discards a gsm_subscriber_connection. - * If compl_l3() returns BSC_API_CONN_POL_ACCEPT and in all other API - * calls, ownership of the conn is in libmsc (in the osmo-nitb case) or - * in the osmo-bsc code (in the OsmoBSC standalone case). Our VLR - * however assumes full ownership of the conn and will discard it when - * nothing is pending. So in case we're still in compl_l3() and going - * to reject the conn, we must tell libmsc to not free it yet, since - * bsc_api.c will do so again/anyway. When the - * gsm_subscriber_connection structs are properly separated, this will - * go away magically. */ - bool owned_by_msc; - /* The MS has opened the conn with a CM Service Request, and we shall * keep it open for an actual request (or until timeout). */ bool received_cm_service_request; @@ -387,6 +374,11 @@ struct gsm_network { struct mncc_sock_state *mncc_state; mncc_recv_cb_t mncc_recv; struct llist_head upqueue; + /* + * TODO: Move the trans_list into the subscriber connection and + * create a pending list for MT transactions. These exist before + * we have a subscriber connection. + */ struct llist_head trans_list; struct bsc_api *bsc_api; diff --git a/openbsc/include/openbsc/gsm_subscriber.h b/openbsc/include/openbsc/gsm_subscriber.h index 0bc7d5160..e53d0eea4 100644 --- a/openbsc/include/openbsc/gsm_subscriber.h +++ b/openbsc/include/openbsc/gsm_subscriber.h @@ -52,7 +52,6 @@ int subscr_update(struct vlr_subscr *vsub, int reason); * Paging handling with authentication */ struct subscr_request *subscr_request_conn(struct vlr_subscr *vsub, - int channel_type, gsm_cbfn *cbfn, void *param); void subscr_remove_request(struct subscr_request *req); diff --git a/openbsc/include/openbsc/msc_ifaces.h b/openbsc/include/openbsc/msc_ifaces.h index 3f6754e03..2965c72c5 100644 --- a/openbsc/include/openbsc/msc_ifaces.h +++ b/openbsc/include/openbsc/msc_ifaces.h @@ -22,7 +22,7 @@ * the compiler complains about an undefined reference to iu_tx(). If you, * however, link against libiu as well as the osmo-iuh libs (etc.), iu_tx() is * available. A unit test may instead simply implement a dummy iu_tx() function - * and not link against osmo-iuh. + * and not link against osmo-iuh, see tests/libiudummy/. */ /* Each main linkage must implement this function (see comment above). */ @@ -35,6 +35,13 @@ extern int iu_tx(struct msgb *msg, uint8_t sapi); * " */ extern int a_tx(struct msgb *msg); +/* So far this is a dummy implemented in libmsc/a_iface.c. When A-interface + * gets implemented, it should be in a separate lib (like libiu), this function + * should move there, and the following comment should remain here: " + * Each main linkage must implement this function (see comment above). + * " */ +extern int a_page(const char *imsi, uint32_t tmsi, uint16_t lac); + int msc_tx_dtap(struct gsm_subscriber_connection *conn, struct msgb *msg); diff --git a/openbsc/include/openbsc/osmo_msc.h b/openbsc/include/openbsc/osmo_msc.h index 16979e7d3..1dd83220a 100644 --- a/openbsc/include/openbsc/osmo_msc.h +++ b/openbsc/include/openbsc/osmo_msc.h @@ -72,8 +72,8 @@ int msc_create_conn_fsm(struct gsm_subscriber_connection *conn, const char *id); int msc_vlr_alloc(struct gsm_network *net); int msc_vlr_start(struct gsm_network *net); -enum msc_compl_l3_rc msc_compl_l3(struct gsm_subscriber_connection *conn, - struct msgb *msg, uint16_t chosen_channel); +int msc_compl_l3(struct gsm_subscriber_connection *conn, + struct msgb *msg, uint16_t chosen_channel); void msc_close_connection(struct gsm_subscriber_connection *conn); bool msc_subscr_conn_is_accepted(struct gsm_subscriber_connection *conn); @@ -81,4 +81,6 @@ void msc_subscr_conn_communicating(struct gsm_subscriber_connection *conn); void msc_release_anchor(struct gsm_subscriber_connection *conn); +void msc_stop_paging(struct vlr_subscr *vsub); + #endif diff --git a/openbsc/include/openbsc/vlr.h b/openbsc/include/openbsc/vlr.h index c137e5007..b7f5ff9c2 100644 --- a/openbsc/include/openbsc/vlr.h +++ b/openbsc/include/openbsc/vlr.h @@ -156,6 +156,8 @@ struct vlr_subscr { /* pending requests */ bool is_paging; struct llist_head requests; + uint8_t lac; + enum ran_type attached_via_ran; } cs; }; diff --git a/openbsc/src/libcommon/gsm_data.c b/openbsc/src/libcommon/gsm_data.c index c522f1db5..968aa1be8 100644 --- a/openbsc/src/libcommon/gsm_data.c +++ b/openbsc/src/libcommon/gsm_data.c @@ -431,3 +431,10 @@ bool classmark_is_r99(struct gsm_classmark *cm) rev_lev = (cm->classmark2[0] >> 5) & 0x3; return rev_lev >= 2; } + +const struct value_string ran_type_names[] = { + OSMO_VALUE_STRING(RAN_UNKNOWN), + OSMO_VALUE_STRING(RAN_GERAN_A), + OSMO_VALUE_STRING(RAN_UTRAN_IU), + { 0, NULL } +}; diff --git a/openbsc/src/libmsc/a_iface.c b/openbsc/src/libmsc/a_iface.c index 1f471f97b..caf9d4b06 100644 --- a/openbsc/src/libmsc/a_iface.c +++ b/openbsc/src/libmsc/a_iface.c @@ -35,6 +35,14 @@ int a_tx(struct msgb *msg) return -1; } +int a_page(const char *imsi, uint32_t tmsi, uint16_t lac) +{ + LOGP(DMSC, LOGL_ERROR, "Paging to be sent to BSC, but A-interface" + " not implemented: IMSI %s TMSI 0x%08x LAC %u\n", + imsi, tmsi, lac); + return -1; +} + int msc_gsm0808_tx_cipher_mode(struct gsm_subscriber_connection *conn, int cipher, const uint8_t *key, int len, int include_imeisv) { diff --git a/openbsc/src/libmsc/gsm_04_08.c b/openbsc/src/libmsc/gsm_04_08.c index e1e3107de..02e6fa1d2 100644 --- a/openbsc/src/libmsc/gsm_04_08.c +++ b/openbsc/src/libmsc/gsm_04_08.c @@ -188,47 +188,23 @@ int gsm48_secure_channel(struct gsm_subscriber_connection *conn, int key_seq, /* Clear Request was received from MSC, release all transactions */ void gsm0408_clear_request(struct gsm_subscriber_connection *conn, uint32_t cause) { - struct gsm_trans *trans, *temp; - - /* avoid someone issuing a clear */ - conn->in_release = 1; - - /* - * Cancel any outstanding location updating request - * operation taking place on the subscriber connection. - */ - loc_updating_failure(conn, 0); - - /* We might need to cancel the paging response or such. */ - if (conn->sec_operation && conn->sec_operation->cb) { - conn->sec_operation->cb(GSM_HOOK_RR_SECURITY, GSM_SECURITY_AUTH_FAILED, - NULL, conn, conn->sec_operation->cb_data); + if (!conn) { + LOGP(DMM, LOGL_ERROR, + "%s: Conn clear request on NULL conn\n", + vlr_subscr_name(conn->vsub)); + return; } - release_security_operation(conn); - msc_release_anchor(conn); - - /* - * Free all transactions that are associated with the released - * connection. The transaction code will inform the CC or SMS - * facilities that will send the release indications. As part of - * the CC REL_IND the remote leg might be released and this will - * trigger the call to trans_free. This is something the llist - * macro can not handle and we will need to re-iterate the list. - * - * TODO: Move the trans_list into the subscriber connection and - * create a pending list for MT transactions. These exist before - * we have a subscriber connection. - */ -restart: - llist_for_each_entry_safe(trans, temp, &conn->network->trans_list, entry) { - if (trans->conn == conn) { - trans_free(trans); - goto restart; - } + if (!conn->conn_fsm) { + LOGP(DMM, LOGL_ERROR, + "%s: Conn clear request on uninitialized conn\n", + vlr_subscr_name(conn->vsub)); + msc_subscr_con_free(conn); + return; } - msc_subscr_con_free(conn); + /* TODO add cause item to msc_close_connection() */ + osmo_fsm_inst_dispatch(conn->conn_fsm, SUBSCR_CONN_E_CN_CLOSE, &cause); } /* clear all transactions globally; used in case of MNCC socket disconnect */ @@ -913,7 +889,7 @@ static int gsm48_rx_mm_auth_resp(struct gsm_subscriber_connection *conn, struct if (!conn->vsub) { LOGP(DMM, LOGL_ERROR, "MM AUTHENTICATION RESPONSE: invalid: no subscriber\n"); - msc_close_connection(conn); + gsm0408_clear_request(conn, GSM_CAUSE_AUTH_FAILED); return -EINVAL; } @@ -927,7 +903,7 @@ static int gsm48_rx_mm_auth_resp(struct gsm_subscriber_connection *conn, struct } if (rc) { - msc_close_connection(conn); + gsm0408_clear_request(conn, GSM_CAUSE_AUTH_FAILED); return -EINVAL; } @@ -952,7 +928,7 @@ static int gsm48_rx_mm_auth_fail(struct gsm_subscriber_connection *conn, struct if (!conn->vsub) { LOGP(DMM, LOGL_ERROR, "MM R99 AUTHENTICATION FAILURE: invalid: no subscriber\n"); - msc_close_connection(conn); + gsm0408_clear_request(conn, GSM_CAUSE_AUTH_FAILED); return -EINVAL; } @@ -961,7 +937,7 @@ static int gsm48_rx_mm_auth_fail(struct gsm_subscriber_connection *conn, struct "%s: MM R99 AUTHENTICATION FAILURE:" " l3 length invalid: %u\n", vlr_subscr_name(conn->vsub), msgb_l3len(msg)); - msc_close_connection(conn); + gsm0408_clear_request(conn, GSM_CAUSE_AUTH_FAILED); return -EINVAL; } @@ -984,7 +960,7 @@ static int gsm48_rx_mm_auth_fail(struct gsm_subscriber_connection *conn, struct "%s: MM R99 AUTHENTICATION FAILURE:" " invalid Synch Failure: missing AUTS IE\n", vlr_subscr_name(conn->vsub)); - msc_close_connection(conn); + gsm0408_clear_request(conn, GSM_CAUSE_AUTH_FAILED); return -EINVAL; } @@ -1001,7 +977,7 @@ static int gsm48_rx_mm_auth_fail(struct gsm_subscriber_connection *conn, struct " got IE 0x%02x of %u bytes\n", vlr_subscr_name(conn->vsub), GSM48_IE_AUTS, auts_tag, auts_len); - msc_close_connection(conn); + gsm0408_clear_request(conn, GSM_CAUSE_AUTH_FAILED); return -EINVAL; } @@ -1010,7 +986,7 @@ static int gsm48_rx_mm_auth_fail(struct gsm_subscriber_connection *conn, struct "%s: MM R99 AUTHENTICATION FAILURE:" " invalid Synch Failure msg: message truncated (%u)\n", vlr_subscr_name(conn->vsub), msgb_l3len(msg)); - msc_close_connection(conn); + gsm0408_clear_request(conn, GSM_CAUSE_AUTH_FAILED); return -EINVAL; } @@ -3358,7 +3334,8 @@ int mncc_tx_to_cc(struct gsm_network *net, int msg_type, void *arg) memcpy(&trans->cc.msg, data, sizeof(struct gsm_mncc)); /* Request a channel */ - trans->paging_request = subscr_request_conn(subscr, + trans->paging_request = subscr_request_conn( + vsub, setup_trig_pag_evt, trans); if (!trans->paging_request) { @@ -3555,11 +3532,6 @@ void msc_release_anchor(struct gsm_subscriber_connection *conn) subscr_con_put(conn); } -int gsm0408_new_conn(struct gsm_subscriber_connection *conn) -{ - return 0; -} - static bool msg_is_initially_permitted(const struct gsm48_hdr *hdr) { uint8_t pdisc = gsm48_hdr_pdisc(hdr); @@ -3641,6 +3613,16 @@ int gsm0408_dispatch(struct gsm_subscriber_connection *conn, struct msgb *msg) return -EACCES; } + if (conn->vsub && conn->vsub->cs.attached_via_ran != conn->via_ran) { + LOGP(DMM, LOGL_ERROR, + "%s: Illegal situation: RAN type mismatch:" + " attached via %s, received message via %s\n", + vlr_subscr_name(conn->vsub), + ran_type_name(conn->vsub->cs.attached_via_ran), + ran_type_name(conn->via_ran)); + return -EACCES; + } + #if 0 if (silent_call_reroute(conn, msg)) return silent_call_rx(conn, msg); @@ -3736,7 +3718,7 @@ static int msc_vlr_tx_lu_rej(void *msc_conn_ref, uint8_t cause) static int msc_vlr_tx_cm_serv_acc(void *msc_conn_ref) { struct gsm_subscriber_connection *conn = msc_conn_ref; - return gsm48_tx_mm_serv_ack(conn); + return msc_gsm48_tx_mm_serv_ack(conn); } /* VLR asks us to transmit a CM Service Reject */ @@ -3769,7 +3751,7 @@ static int msc_vlr_tx_cm_serv_rej(void *msc_conn_ref, enum vlr_proc_arq_result r break; }; - return gsm48_tx_mm_serv_rej(conn, cause); + return msc_gsm48_tx_mm_serv_rej(conn, cause); } /* VLR asks us to start using ciphering */ @@ -3797,9 +3779,8 @@ static int msc_vlr_set_ciph_mode(void *msc_conn_ref, return -EINVAL; } - /* TODO: MSCSPLIT: don't directly push BSC buttons */ - return gsm0808_cipher_mode(conn, ciph, tuple->vec.kc, 8, - retrieve_imeisv); + return msc_gsm0808_tx_cipher_mode(conn, ciph, tuple->vec.kc, 8, + retrieve_imeisv); } /* VLR informs us that the subscriber data has somehow been modified */ @@ -3815,6 +3796,7 @@ static void msc_vlr_subscr_assoc(void *msc_conn_ref, struct gsm_subscriber_connection *conn = msc_conn_ref; OSMO_ASSERT(!conn->vsub); conn->vsub = vlr_subscr_get(vsub); + conn->vsub->cs.attached_via_ran = conn->via_ran; } /* operations that we need to implement for libvlr */ diff --git a/openbsc/src/libmsc/gsm_04_11.c b/openbsc/src/libmsc/gsm_04_11.c index 1556d58e8..d2a9723bf 100644 --- a/openbsc/src/libmsc/gsm_04_11.c +++ b/openbsc/src/libmsc/gsm_04_11.c @@ -1009,8 +1009,7 @@ int gsm411_send_sms_subscr(struct vlr_subscr *vsub, /* if not, we have to start paging */ LOGP(DLSMS, LOGL_DEBUG, "Sending SMS: no connection open, start paging %s\n", vlr_subscr_name(vsub)); - res = subscr_request_conn(vsub, RSL_CHANNEED_SDCCH, paging_cb_send_sms, - sms); + res = subscr_request_conn(vsub, paging_cb_send_sms, sms); if (!res) { send_signal(S_SMS_UNKNOWN_ERROR, NULL, sms, GSM_PAGING_BUSY); sms_free(sms); diff --git a/openbsc/src/libmsc/gsm_subscriber.c b/openbsc/src/libmsc/gsm_subscriber.c index ef7260660..09c5e5d71 100644 --- a/openbsc/src/libmsc/gsm_subscriber.c +++ b/openbsc/src/libmsc/gsm_subscriber.c @@ -41,25 +41,14 @@ #include #include #include +#include +#include void *tall_sub_req_ctx; int gsm48_secure_channel(struct gsm_subscriber_connection *conn, int key_seq, gsm_cbfn *cb, void *cb_data); -static struct bsc_subscr *vlr_subscr_to_bsc_sub(struct llist_head *bsc_subscribers, - struct vlr_subscr *vsub) -{ - struct bsc_subscr *sub; - /* TODO MSC split -- creating a BSC subscriber directly from MSC data - * structures in RAM. At some point the MSC will send a message to the - * BSC instead. */ - sub = bsc_subscr_find_or_create_by_imsi(bsc_subscribers, vsub->imsi); - sub->tmsi = vsub->tmsi; - sub->lac = vsub->lac; - return sub; -} - /* A connection is established and the paging callbacks may run now. */ int subscr_paging_dispatch(unsigned int hooknum, unsigned int event, struct msgb *msg, void *data, void *param) @@ -68,36 +57,34 @@ int subscr_paging_dispatch(unsigned int hooknum, unsigned int event, struct gsm_subscriber_connection *conn = data; struct vlr_subscr *vsub = param; struct paging_signal_data sig_data; - struct bsc_subscr *bsub; - struct gsm_network *net; OSMO_ASSERT(vsub); - net = vsub->vlr->user_ctx; OSMO_ASSERT(hooknum == GSM_HOOK_RR_PAGING); OSMO_ASSERT(!(conn && (conn->vsub != vsub))); OSMO_ASSERT(!((event == GSM_PAGING_SUCCEEDED) && !conn)); LOGP(DPAG, LOGL_DEBUG, "Paging %s for %s (event=%d)\n", event == GSM_PAGING_SUCCEEDED ? "success" : "failure", - subscr_name(subscr), event); + vlr_subscr_name(vsub), event); - if (!subscr->is_paging) { + if (!vsub->cs.is_paging) { LOGP(DPAG, LOGL_ERROR, "Paging Response received for subscriber" " that is not paging.\n"); return -EINVAL; } + if (event == GSM_PAGING_SUCCEEDED) + msc_stop_paging(vsub); + /* Inform parts of the system we don't know */ - sig_data.vsub = vsub; - sig_data.conn = conn; + sig_data.vsub = vsub; + sig_data.conn = conn; sig_data.paging_result = event; - osmo_signal_dispatch( - SS_PAGING, - event == GSM_PAGING_SUCCEEDED ? - S_PAGING_SUCCEEDED : S_PAGING_EXPIRED, - &sig_data - ); + osmo_signal_dispatch(SS_PAGING, + event == GSM_PAGING_SUCCEEDED ? + S_PAGING_SUCCEEDED : S_PAGING_EXPIRED, + &sig_data); llist_for_each_entry_safe(request, tmp, &vsub->cs.requests, entry) { llist_del(&request->entry); @@ -115,99 +102,28 @@ int subscr_paging_dispatch(unsigned int hooknum, unsigned int event, return 0; } -static void paging_timeout_release(struct gsm_subscriber *subscr) -{ - DEBUGP(DPAG, "Paging timeout released for %s\n", subscr_name(subscr)); - osmo_timer_del(&subscr->paging_timeout); -} - -static void paging_timeout(void *data) -{ - struct gsm_subscriber *subscr = data; - DEBUGP(DPAG, "Paging timeout reached for %s\n", subscr_name(subscr)); - paging_timeout_release(subscr); - subscr_paging_dispatch(GSM_HOOK_RR_PAGING, GSM_PAGING_EXPIRED, - NULL, NULL, subscr); -} - -static void paging_timeout_start(struct gsm_subscriber *subscr) -{ - DEBUGP(DPAG, "Starting paging timeout for %s\n", subscr_name(subscr)); - subscr->paging_timeout.data = subscr; - subscr->paging_timeout.cb = paging_timeout; - osmo_timer_schedule(&subscr->paging_timeout, 10, 0); - /* TODO: configurable timeout duration? */ -} - - -static int subscr_paging_sec_cb(unsigned int hooknum, unsigned int event, - struct msgb *msg, void *data, void *param) -{ - int rc; - struct gsm_subscriber_connection *conn = data; - OSMO_ASSERT(conn); - - switch (event) { - case GSM_SECURITY_AUTH_FAILED: - LOGP(DPAG, LOGL_ERROR, - "Dropping Paging Response:" - " authorization failed for subscriber %s\n", - subscr_name(conn->subscr)); - rc = subscr_paging_dispatch( - GSM_HOOK_RR_PAGING, GSM_PAGING_EXPIRED, - msg, conn, conn->subscr); - break; - - case GSM_SECURITY_NOAVAIL: - case GSM_SECURITY_SUCCEEDED: - rc = subscr_paging_dispatch( - GSM_HOOK_RR_PAGING, GSM_PAGING_SUCCEEDED, - msg, conn, conn->subscr); - break; - - default: - LOGP(DPAG, LOGL_FATAL, - "Invalid authorization event: %d\n", event); - rc = -EINVAL; - } - - return rc; -} - -int subscr_rx_paging_response(struct msgb *msg, - struct gsm_subscriber_connection *conn) -{ - struct gsm48_hdr *gh; - struct gsm48_pag_resp *pr; - - /* Get key_seq from Paging Response headers */ - gh = msgb_l3(msg); - pr = (struct gsm48_pag_resp *)gh->data; - - paging_timeout_release(conn->subscr); - - /* Secure the connection */ - if (subscr_authorized(conn->subscr)) - return gsm48_secure_channel(conn, pr->key_seq, - subscr_paging_sec_cb, NULL); - - /* Not authorized. Failure. */ - subscr_paging_sec_cb(GSM_HOOK_RR_SECURITY, GSM_SECURITY_AUTH_FAILED, - msg, conn, NULL); - return -1; -} - -static int msc_paging_request(struct gsm_subscriber *subscr) +int msc_paging_request(struct vlr_subscr *vsub) { /* The subscriber was last seen in subscr->lac. Find out which * BSCs/RNCs are responsible and send them a paging request via open * SCCP connections (if any). */ /* TODO Implementing only RNC paging, since this is code on the iu branch. * Need to add BSC paging at some point. */ - return iu_page_cs(subscr->imsi, - subscr->tmsi == GSM_RESERVED_TMSI? - NULL : &subscr->tmsi, - subscr->lac); + switch (vsub->cs.attached_via_ran) { + case RAN_GERAN_A: + return a_page(vsub->imsi, vsub->tmsi, vsub->lac); + case RAN_UTRAN_IU: + return iu_page_cs(vsub->imsi, + vsub->tmsi == GSM_RESERVED_TMSI? + NULL : &vsub->tmsi, + vsub->lac); + default: + break; + } + + LOGP(DPAG, LOGL_ERROR, "%s: Cannot page, subscriber not attached\n", + vlr_subscr_name(vsub)); + return -EINVAL; } struct subscr_request *subscr_request_conn(struct vlr_subscr *vsub, @@ -215,11 +131,9 @@ struct subscr_request *subscr_request_conn(struct vlr_subscr *vsub, { int rc; struct subscr_request *request; - struct bsc_subscr *bsub; - struct gsm_network *net = vsub->vlr->user_ctx; /* Start paging.. we know it is async so we can do it before */ - if (!subscr->is_paging) { + if (!vsub->cs.is_paging) { LOGP(DMM, LOGL_DEBUG, "Subscriber %s not paged yet, start paging.\n", vlr_subscr_name(vsub)); rc = msc_paging_request(vsub); @@ -233,7 +147,7 @@ struct subscr_request *subscr_request_conn(struct vlr_subscr *vsub, vsub->cs.is_paging = true; } else { LOGP(DMM, LOGL_DEBUG, "Subscriber %s already paged.\n", - subscr_name(subscr)); + vlr_subscr_name(vsub)); } /* TODO: Stop paging in case of memory allocation failure */ diff --git a/openbsc/src/libmsc/iucs.c b/openbsc/src/libmsc/iucs.c index 469d3e0a7..8d763d223 100644 --- a/openbsc/src/libmsc/iucs.c +++ b/openbsc/src/libmsc/iucs.c @@ -185,13 +185,8 @@ int gsm0408_rcvmsg_iucs(struct gsm_network *network, struct msgb *msg, if (!conn) abort(); + /* ownership of conn hereby goes to the MSC: */ rc = msc_compl_l3(conn, msg, 0); - if (rc != MSC_CONN_ACCEPT) { - gsm0408_clear_request(conn, 0); - rc = -1; - } - else - rc = 0; } return rc; diff --git a/openbsc/src/libmsc/msc_ifaces.c b/openbsc/src/libmsc/msc_ifaces.c index 71f27a318..8cc91c614 100644 --- a/openbsc/src/libmsc/msc_ifaces.c +++ b/openbsc/src/libmsc/msc_ifaces.c @@ -28,6 +28,7 @@ #include #include #include +#include #include "../../bscconfig.h" @@ -38,6 +39,9 @@ extern struct msgb *ranap_new_msg_rab_assign_voice(uint8_t rab_id, static int msc_tx(struct gsm_subscriber_connection *conn, struct msgb *msg) { + DEBUGP(DMSC, "msc_tx %u bytes to %s via %s\n", + msg->len, vlr_subscr_name(conn->vsub), + ran_type_name(conn->via_ran)); switch (conn->via_ran) { case RAN_GERAN_A: msg->dst = conn; @@ -101,7 +105,7 @@ int msc_tx_common_id(struct gsm_subscriber_connection *conn) return 0; #ifdef BUILD_IU - return iu_tx_common_id(conn->iu.ue_ctx, conn->subscr->imsi); + return iu_tx_common_id(conn->iu.ue_ctx, conn->vsub->imsi); #else LOGP(DMM, LOGL_ERROR, "Cannot send CommonID: RAN_UTRAN_IU but IuCS support not built\n"); @@ -152,7 +156,7 @@ static void mgcp_response_rab_act_cs_crcx(struct mgcp_response *r, void *priv) if (rc) { LOGP(DMGCP, LOGL_ERROR, "Cannot parse MGCP response, for %s\n", - subscr_name(trans->subscr)); + vlr_subscr_name(trans->vsub)); goto rab_act_cs_error; } @@ -250,7 +254,7 @@ static void mgcp_bridge(struct gsm_trans *from, struct gsm_trans *to, if (mgcpgw_client_tx(mgcp, msg, mgcp_response_bridge_mdcx, from)) LOGP(DMGCP, LOGL_ERROR, "Failed to send MDCX message for %s\n", - subscr_name(from->subscr)); + vlr_subscr_name(from->vsub)); } static void mgcp_response_bridge_mdcx(struct mgcp_response *r, void *priv) @@ -277,7 +281,7 @@ static void mgcp_response_bridge_mdcx(struct mgcp_response *r, void *priv) default: LOGP(DMGCP, LOGL_ERROR, "Unexpected bridge state: %d for %s\n", - trans->bridge.state, subscr_name(trans->subscr)); + trans->bridge.state, vlr_subscr_name(trans->vsub)); break; } break; @@ -289,7 +293,7 @@ static void mgcp_response_bridge_mdcx(struct mgcp_response *r, void *priv) default: LOGP(DMGCP, LOGL_ERROR, "Unexpected bridge state: %d for %s\n", - trans->bridge.state, subscr_name(trans->subscr)); + trans->bridge.state, vlr_subscr_name(trans->vsub)); break; } } diff --git a/openbsc/src/libmsc/osmo_msc.c b/openbsc/src/libmsc/osmo_msc.c index 0511fc5dd..6ce837b8a 100644 --- a/openbsc/src/libmsc/osmo_msc.c +++ b/openbsc/src/libmsc/osmo_msc.c @@ -48,61 +48,17 @@ static int msc_clear_request(struct gsm_subscriber_connection *conn, uint32_t ca return 1; } -static bool keep_conn(struct gsm_subscriber_connection *conn) -{ - /* TODO: what about a silent call? */ - - if (!conn->conn_fsm) { - DEBUGP(DMM, "No conn_fsm, release conn\n"); - return false; - } - - switch (conn->conn_fsm->state) { - case SUBSCR_CONN_S_NEW: - case SUBSCR_CONN_S_ACCEPTED: - return true; - default: - return false; - } -} - /* receive a Level 3 Complete message and return MSC_CONN_ACCEPT or * MSC_CONN_REJECT */ -enum msc_compl_l3_rc msc_compl_l3(struct gsm_subscriber_connection *conn, - struct msgb *msg, uint16_t chosen_channel) +int msc_compl_l3(struct gsm_subscriber_connection *conn, + struct msgb *msg, uint16_t chosen_channel) { - gsm0408_new_conn(conn); gsm0408_dispatch(conn, msg); - /* NOTE: after the MSC split, returning BSC_API_CONN_POL_REJECT shall - * be replaced with a call to msc_subscr_con_free() */ - - if (!keep_conn(conn)) { - DEBUGP(DMM, "compl_l3: Discarding conn\n"); - return MSC_CONN_REJECT; - } - DEBUGP(DMM, "compl_l3: Keeping conn\n"); - conn->owned_by_msc = true; - DEBUGP(DMM, "%s owned_by_msc = true\n", - vlr_subscr_name(conn->vsub)); + /* Always return acceptance, because even if the conn was not accepted, + * we assumed ownership of it and the caller shall not interfere with + * that. We may even already have discarded the conn. */ return MSC_CONN_ACCEPT; - -#if 0 - /* - * If this is a silent call we want the channel to remain open as long as - * possible and this is why we accept this connection regardless of any - * pending transaction or ongoing operation. - */ - if (conn->silent_call) - return MSC_CONN_ACCEPT; - if (conn->loc_operation || conn->sec_operation || conn->anch_operation) - return MSC_CONN_ACCEPT; - if (trans_has_conn(conn)) - return MSC_CONN_ACCEPT; - - LOGP(DRR, LOGL_INFO, "MSC Complete L3: Rejecting connection.\n"); - return MSC_CONN_REJECT; -#endif } static void subscr_conn_bump(struct gsm_subscriber_connection *conn) @@ -334,3 +290,9 @@ void _subscr_con_put(struct gsm_subscriber_connection *conn, osmo_fsm_inst_dispatch(conn->conn_fsm, SUBSCR_CONN_E_MO_CLOSE, NULL); #endif } + +void msc_stop_paging(struct vlr_subscr *vsub) +{ + DEBUGP(DPAG, "Paging can stop for %s\n", vlr_subscr_name(vsub)); + /* tell BSCs and RNCs to stop paging? How? */ +} diff --git a/openbsc/src/libmsc/silent_call.c b/openbsc/src/libmsc/silent_call.c index c04582e69..7027dce11 100644 --- a/openbsc/src/libmsc/silent_call.c +++ b/openbsc/src/libmsc/silent_call.c @@ -131,7 +131,7 @@ int gsm_silent_call_start(struct vlr_subscr *vsub, void *data, int type) /* FIXME the VTY command allows selecting a silent call channel type. * This doesn't apply to the situation after MSCSPLIT with an * A-interface. */ - req = subscr_request_conn(vsub, type, paging_cb_silent, data); + req = subscr_request_conn(vsub, paging_cb_silent, data); return req != NULL; } diff --git a/openbsc/src/libmsc/subscr_conn.c b/openbsc/src/libmsc/subscr_conn.c index 9322ec1ca..86fe8d796 100644 --- a/openbsc/src/libmsc/subscr_conn.c +++ b/openbsc/src/libmsc/subscr_conn.c @@ -30,6 +30,7 @@ #include #include #include +#include #define SUBSCR_CONN_TIMEOUT 5 /* seconds */ @@ -52,8 +53,8 @@ const struct value_string subscr_conn_from_names[] = { { 0, NULL } }; -static void paging_resp(struct gsm_subscriber_connection *conn, - enum gsm_paging_event pe) +static void paging_event(struct gsm_subscriber_connection *conn, + enum gsm_paging_event pe) { subscr_paging_dispatch(GSM_HOOK_RR_PAGING, pe, NULL, conn, conn->vsub); } @@ -84,11 +85,17 @@ void subscr_conn_fsm_new(struct osmo_fsm_inst *fi, uint32_t event, void *data) case SUBSCR_CONN_E_MO_CLOSE: case SUBSCR_CONN_E_CN_CLOSE: + if (data) + LOGPFSM(fi, "Close event, cause %u\n", + *(uint32_t*)data); + /* will release further below, see + * 'if (fi->state != SUBSCR_CONN_S_ACCEPTED)' */ break; default: - LOGPFSM(fi, "Unexpected event: %d %s\n", - event, osmo_fsm_event_name(fi->fsm, event)); + LOGPFSML(fi, LOGL_ERROR, + "Unexpected event: %d %s\n", event, + osmo_fsm_event_name(fi->fsm, event)); break; } @@ -96,7 +103,7 @@ void subscr_conn_fsm_new(struct osmo_fsm_inst *fi, uint32_t event, void *data) if (from == SUBSCR_CONN_FROM_PAGING_RESP) { pe = (fi->state == SUBSCR_CONN_S_ACCEPTED)? GSM_PAGING_SUCCEEDED : GSM_PAGING_EXPIRED; - paging_resp(conn, pe); + paging_event(conn, pe); } /* FIXME rate counters */ @@ -105,13 +112,11 @@ void subscr_conn_fsm_new(struct osmo_fsm_inst *fi, uint32_t event, void *data) /* On failure, discard the conn */ if (fi->state != SUBSCR_CONN_S_ACCEPTED) { /* TODO: on MO_CLOSE or CN_CLOSE, first go to RELEASING and - * await BSC confirmation? */ + * await BSC/RNC confirmation? */ osmo_fsm_inst_state_chg(fi, SUBSCR_CONN_S_RELEASED, 0, 0); return; } - /* On success, handle pending requests and/or close conn */ - if (from == SUBSCR_CONN_FROM_CM_SERVICE_REQ) { conn->received_cm_service_request = true; LOGPFSM(fi, "received_cm_service_request = true\n"); @@ -237,23 +242,13 @@ static void subscr_conn_fsm_cleanup(struct osmo_fsm_inst *fi, LOGP(DMM, LOGL_ERROR, "%s: closing conn but still in use (%u)\n", vlr_subscr_name(conn->vsub), conn->use_count); - /* temporary hack, see owned_by_msc */ - if (!conn->owned_by_msc) { - DEBUGP(DMM, "%s leaving bsc_subscr_con_free() to bsc_api.c, owned_by_msc = false\n", - vlr_subscr_name(conn->vsub)); - return; - } - - if (conn->via_iface == IFACE_IU) + if (conn->via_ran == RAN_UTRAN_IU) iu_tx_release(conn->iu.ue_ctx, NULL); /* FIXME: keep the conn until the Iu Release Outcome is * received from the UE, or a timeout expires. For now, the log * says "unknown UE" for each release outcome. */ - DEBUGP(DMM, "%s calling bsc_subscr_con_free(), owned_by_msc = true\n", - vlr_subscr_name(conn->vsub)); - gsm0808_clear(conn); - bsc_subscr_con_free(conn); + msc_subscr_con_free(conn); } int subscr_conn_fsm_timeout(struct osmo_fsm_inst *fi) diff --git a/openbsc/src/libmsc/transaction.c b/openbsc/src/libmsc/transaction.c index 071acbc36..af9b30003 100644 --- a/openbsc/src/libmsc/transaction.c +++ b/openbsc/src/libmsc/transaction.c @@ -192,12 +192,24 @@ int trans_has_conn(const struct gsm_subscriber_connection *conn) return 0; } +/* + * Free all transactions that are associated with the released + * connection. The transaction code will inform the CC or SMS + * facilities that will send the release indications. + */ void trans_conn_closed(struct gsm_subscriber_connection *conn) { - struct gsm_trans *trans, *t2; + struct gsm_trans *trans; - llist_for_each_entry_safe(trans, t2, &conn->network->trans_list, entry) { - if (trans->conn == conn) + /* As part of the CC REL_IND the remote leg might be released and this + * will trigger the call to trans_free. This is something the llist + * macro can not handle and we will need to re-iterate the list. + */ +restart: + llist_for_each_entry(trans, &conn->network->trans_list, entry) { + if (trans->conn == conn) { trans_free(trans); + goto restart; + } } } diff --git a/openbsc/src/libmsc/vty_interface_layer3.c b/openbsc/src/libmsc/vty_interface_layer3.c index 804b5c70c..c783cf101 100644 --- a/openbsc/src/libmsc/vty_interface_layer3.c +++ b/openbsc/src/libmsc/vty_interface_layer3.c @@ -22,6 +22,7 @@ #include #include #include +#include #include #include @@ -900,7 +901,6 @@ DEFUN(logging_fltr_imsi, "Filter log messages by IMSI\n" "IMSI to be used as filter\n") { struct vlr_subscr *vlr_subscr; - struct bsc_subscr *bsc_subscr; struct gsm_network *gsmnet = gsmnet_from_vty(vty); struct log_target *tgt = osmo_log_vty2tgt(vty); const char *imsi = argv[0]; @@ -909,16 +909,14 @@ DEFUN(logging_fltr_imsi, return CMD_WARNING; vlr_subscr = vlr_subscr_find_by_imsi(gsmnet->vlr, imsi); - bsc_subscr = bsc_subscr_find_by_imsi(gsmnet->bsc_subscribers, imsi); - if (!vlr_subscr && !bsc_subscr) { + if (!vlr_subscr) { vty_out(vty, "%%no subscriber with IMSI(%s)%s", argv[0], VTY_NEWLINE); return CMD_WARNING; } log_set_filter_vlr_subscr(tgt, vlr_subscr); - log_set_filter_bsc_subscr(tgt, bsc_subscr); return CMD_SUCCESS; } @@ -966,92 +964,6 @@ static int config_write_hlr(struct vty *vty) return CMD_SUCCESS; } -static struct cmd_node nitb_node = { - NITB_NODE, - "%s(config-nitb)# ", - 1, -}; - -DEFUN(cfg_nitb, cfg_nitb_cmd, - "nitb", "Configure NITB options") -{ - vty->node = NITB_NODE; - return CMD_SUCCESS; -} - -/* Note: limit on the parameter length is set by internal vty code limitations */ -DEFUN(cfg_nitb_subscr_random, cfg_nitb_subscr_random_cmd, - "subscriber-create-on-demand random <1-9999999999> <2-9999999999>", - "Set random parameters for a new record when a subscriber is first seen.\n" - "Set random parameters for a new record when a subscriber is first seen.\n" - "Minimum for subscriber extension\n""Maximum for subscriber extension\n") -{ - vty_out(vty, "%% 'subscriber-create-on-demand' is no longer supported.%s" - "%% This is now up to osmo-hlr.%s", - VTY_NEWLINE, VTY_NEWLINE); - return CMD_WARNING; -} - -DEFUN(cfg_nitb_subscr_create, cfg_nitb_subscr_create_cmd, - "subscriber-create-on-demand [no-extension]", - "Make a new record when a subscriber is first seen.\n" - "Do not automatically assign extension to created subscribers\n") -{ - vty_out(vty, "%% 'subscriber-create-on-demand' is no longer supported.%s" - "%% This is now up to osmo-hlr.%s", - VTY_NEWLINE, VTY_NEWLINE); - return CMD_WARNING; -} - -DEFUN(cfg_nitb_no_subscr_create, cfg_nitb_no_subscr_create_cmd, - "no subscriber-create-on-demand", - NO_STR "Make a new record when a subscriber is first seen.\n") -{ - vty_out(vty, "%% 'subscriber-create-on-demand' is no longer supported.%s" - "%% This is now up to osmo-hlr.%s", - VTY_NEWLINE, VTY_NEWLINE); - return CMD_WARNING; -} - -DEFUN(cfg_nitb_assign_tmsi, cfg_nitb_assign_tmsi_cmd, - "assign-tmsi", - "Assign TMSI during Location Updating.\n") -{ - struct gsm_network *gsmnet = gsmnet_from_vty(vty); - gsmnet->vlr->cfg.assign_tmsi = true; - return CMD_SUCCESS; -} - -DEFUN(cfg_nitb_no_assign_tmsi, cfg_nitb_no_assign_tmsi_cmd, - "no assign-tmsi", - NO_STR "Assign TMSI during Location Updating.\n") -{ - struct gsm_network *gsmnet = gsmnet_from_vty(vty); - gsmnet->vlr->cfg.assign_tmsi = false; - return CMD_SUCCESS; -} - -static int config_write_nitb(struct vty *vty) -{ - struct gsm_network *gsmnet = gsmnet_from_vty(vty); - - vty_out(vty, "nitb%s", VTY_NEWLINE); - if (!gsmnet->auto_create_subscr) - vty_out(vty, " no subscriber-create-on-demand%s", VTY_NEWLINE); - else - vty_out(vty, " subscriber-create-on-demand%s%s", - gsmnet->auto_assign_exten ? "" : " no-extension", - VTY_NEWLINE); - - if (gsmnet->ext_min != GSM_MIN_EXTEN || gsmnet->ext_max != GSM_MAX_EXTEN) - vty_out(vty, " subscriber-create-on-demand random %"PRIu64" %" - PRIu64"%s", gsmnet->ext_min, gsmnet->ext_max, - VTY_NEWLINE); - vty_out(vty, " %sassign-tmsi%s", - gsmnet->vlr->cfg.assign_tmsi? "" : "no ", VTY_NEWLINE); - return CMD_SUCCESS; -} - int bsc_vty_init_extra(void) { osmo_signal_register_handler(SS_SCALL, scall_cbfn, NULL); diff --git a/openbsc/src/osmo-msc/iucs_ranap.c b/openbsc/src/osmo-msc/iucs_ranap.c index 34f5bfe59..09b81489b 100644 --- a/openbsc/src/osmo-msc/iucs_ranap.c +++ b/openbsc/src/osmo-msc/iucs_ranap.c @@ -30,6 +30,7 @@ #include #include #include +#include #include "iucs_ranap.h" @@ -44,9 +45,9 @@ static int iucs_rx_rab_assign(struct gsm_subscriber_connection *conn, rab_id = item->rAB_ID.buf[0]; - LOGP(DIUCS, LOGL_NOTICE, "Received RAB assignment event for %s" - " rab_id=%hhd\n", subscr_name(conn->subscr), rab_id); - /* TODO do stuff like in sgsn_ranap_rab_ass_resp() */ + LOGP(DIUCS, LOGL_NOTICE, + "Received RAB assignment event for %s rab_id=%hhd\n", + vlr_subscr_name(conn->vsub), rab_id); return 0; } @@ -56,13 +57,13 @@ int iucs_rx_sec_mode_compl(struct gsm_subscriber_connection *conn, { gsm_cbfn *cb; - OSMO_ASSERT(conn->via_iface == IFACE_IU); + OSMO_ASSERT(conn->via_ran == RAN_UTRAN_IU); if (!conn->sec_operation) { LOGP(DIUCS, LOGL_ERROR, "Received Security Mode Complete message, but no" " authentication/cipher operation in progress" - " for subscr %s\n", subscr_name(conn->subscr)); + " for subscr %s\n", vlr_subscr_name(conn->vsub)); return -EINVAL; } @@ -71,7 +72,7 @@ int iucs_rx_sec_mode_compl(struct gsm_subscriber_connection *conn, if (conn->iu.integrity_protection) LOGP(DIUCS, LOGL_NOTICE, "Integrity Protection" " was already enabled for %s\n", - subscr_name(conn->subscr)); + vlr_subscr_name(conn->vsub)); conn->iu.integrity_protection = INTEGRITY_PROTECTION_IK; @@ -99,13 +100,13 @@ int iucs_rx_ranap_event(struct gsm_network *network, case IU_EVENT_IU_RELEASE: case IU_EVENT_LINK_INVALIDATED: LOGP(DIUCS, LOGL_INFO, "IuCS release for %s\n", - subscr_name(conn->subscr)); + vlr_subscr_name(conn->vsub)); gsm0408_clear_request(conn, 0); return 0; case IU_EVENT_SECURITY_MODE_COMPLETE: LOGP(DIUCS, LOGL_INFO, "IuCS security mode complete for %s\n", - subscr_name(conn->subscr)); + vlr_subscr_name(conn->vsub)); return iucs_rx_sec_mode_compl(conn, (RANAP_SecurityModeCompleteIEs_t*)data); case IU_EVENT_RAB_ASSIGN: diff --git a/openbsc/src/osmo-msc/msc_main.c b/openbsc/src/osmo-msc/msc_main.c index 9d3efd702..f4b3b363b 100644 --- a/openbsc/src/osmo-msc/msc_main.c +++ b/openbsc/src/osmo-msc/msc_main.c @@ -260,10 +260,6 @@ void msc_network_shutdown(struct gsm_network *net) static struct gsm_network *msc_network = NULL; -/* TODO this is here to satisfy linking during intermediate development. Once - * libbsc is not linked to osmo-msc, this should go away. */ -struct gsm_network *bsc_gsmnet = NULL; - extern void *tall_vty_ctx; static void signal_handler(int signal) { @@ -305,12 +301,6 @@ static void db_sync_timer_cb(void *data) osmo_timer_schedule(&db_sync_timer, DB_SYNC_INTERVAL); } -static void subscr_expire_cb(void *data) -{ - /* TODO expire vlr_subscrs? */ - osmo_timer_schedule(&bsc_gsmnet->subscr_expire_timer, EXPIRE_INTERVAL); -} - extern int bsc_vty_go_parent(struct vty *vty); static struct vty_app_info msc_vty_info = { @@ -370,6 +360,11 @@ int main(int argc, char **argv) if (!msc_network) return -ENOMEM; + if (msc_vlr_alloc(msc_network)) { + fprintf(stderr, "Failed to allocate VLR\n"); + exit(1); + } + ctrl_vty_init(tall_msc_ctx); logging_vty_add_cmds(&log_info); msc_vty_init(msc_network); @@ -426,7 +421,7 @@ int main(int argc, char **argv) * A third-party MSC may well be able to handle a TCH/H TCH/F * mismatch. */ - bsc_gsmnet->dyn_ts_allow_tch_f = false; + msc_network->dyn_ts_allow_tch_f = false; /* start control interface after reading config for * ctrl_vty_get_bind_addr() */ @@ -448,7 +443,7 @@ TODO: we probably want some of the _net_ ctrl commands from bsc_base_ctrl_cmds_i #endif #if 0 - if (msc_ctrl_cmds_install(bsc_gsmnet) != 0) { + if (msc_ctrl_cmds_install(msc_network) != 0) { printf("Failed to initialize the MSC control commands.\n"); return -1; } @@ -466,19 +461,13 @@ TODO: we probably want some of the _net_ ctrl commands from bsc_base_ctrl_cmds_i } osmo_fsm_log_addr(true); - if (msc_vlr_start(bsc_gsmnet)) { + if (msc_vlr_start(msc_network)) { fprintf(stderr, "Failed to start VLR\n"); exit(1); } msc_subscr_conn_init(); - if (db_init(database_name)) { - printf("DB: Failed to init database. Please check the option settings.\n"); - return -1; - } - printf("DB: Database initialized.\n"); - if (db_prepare()) { printf("DB: Failed to prepare database.\n"); return 5; @@ -489,10 +478,6 @@ TODO: we probably want some of the _net_ ctrl commands from bsc_base_ctrl_cmds_i if (msc_cmdline_config.use_db_counter) osmo_timer_schedule(&db_sync_timer, DB_SYNC_INTERVAL); - msc_network->subscr_expire_timer.cb = subscr_expire_cb; - msc_network->subscr_expire_timer.data = NULL; - osmo_timer_schedule(&msc_network->subscr_expire_timer, EXPIRE_INTERVAL); - signal(SIGINT, &signal_handler); signal(SIGABRT, &signal_handler); signal(SIGUSR1, &signal_handler); diff --git a/openbsc/tests/channel/channel_test.c b/openbsc/tests/channel/channel_test.c index 76e86a094..fcb2a1e0c 100644 --- a/openbsc/tests/channel/channel_test.c +++ b/openbsc/tests/channel/channel_test.c @@ -31,11 +31,13 @@ #include #include -static int s_end = 0; static struct gsm_subscriber_connection s_conn; static void *s_data; static gsm_cbfn *s_cbfn = NULL; +#if 0 +static int s_end = 0; + /* our handler */ static int subscr_cb(unsigned int hook, unsigned int event, struct msgb *msg, void *data, void *param) { @@ -48,6 +50,7 @@ static int subscr_cb(unsigned int hook, unsigned int event, struct msgb *msg, vo s_end = true; return 0; } +#endif /* mock object for testing, directly invoke the cb... maybe later through the timer */ int paging_request(struct gsm_bts *bts, struct bsc_subscr *bsub, int type, gsm_cbfn *cbfn, void *data) @@ -84,10 +87,10 @@ void test_request_chan(void) struct vlr_subscr *vsub = vlr_subscr_alloc(network->vlr); vsub->lac = 23; - /* Ask for a channel... */ - struct subscr_request *sr; #warning _______________SKIPPING SOME TESTS____________________ #if 0 + /* Ask for a channel... */ + struct subscr_request *sr; sr = subscr_request_channel(vsub, RSL_CHANNEED_TCH_F, subscr_cb, (void*)0x2342L); OSMO_ASSERT(sr); OSMO_ASSERT(s_cbfn); diff --git a/openbsc/tests/libiudummy/iudummy.c b/openbsc/tests/libiudummy/iudummy.c index d2d0d5930..9dae94116 100644 --- a/openbsc/tests/libiudummy/iudummy.c +++ b/openbsc/tests/libiudummy/iudummy.c @@ -8,6 +8,7 @@ struct msgb; struct ue_conn_ctx; struct gsm_auth_tuple; +struct RANAP_Cause; int iu_tx(struct msgb *msg, uint8_t sapi) { @@ -26,7 +27,7 @@ int iu_tx_sec_mode_cmd(struct ue_conn_ctx *uectx, struct gsm_auth_tuple *tp, int iu_page_cs(const char *imsi, const uint32_t *tmsi, uint16_t lac) { LOGP(DLGLOBAL, LOGL_INFO, "iu_page_cs() dummy called, NOT paging\n"); - return 0; + return 23; } int iu_page_ps(const char *imsi, const uint32_t *ptmsi, uint16_t lac, uint8_t rac) @@ -54,3 +55,9 @@ int iu_tx_common_id(struct ue_conn_ctx *uectx, const char *imsi) LOGP(DLGLOBAL, LOGL_INFO, "iu_tx_common_id() dummy called, NOT sending CommonID\n"); return 0; } + +int iu_tx_release(struct ue_conn_ctx *ctx, const struct RANAP_Cause *cause) +{ + LOGP(DLGLOBAL, LOGL_INFO, "iu_tx_release() dummy called, NOT sending Release\n"); + return 0; +} diff --git a/openbsc/tests/msc_vlr/Makefile.am b/openbsc/tests/msc_vlr/Makefile.am index 3f6fd914f..4494d95ae 100644 --- a/openbsc/tests/msc_vlr/Makefile.am +++ b/openbsc/tests/msc_vlr/Makefile.am @@ -45,6 +45,8 @@ LDADD = \ $(top_builddir)/src/libvlr/libvlr.a \ $(top_builddir)/src/libbsc/libbsc.a \ $(top_builddir)/src/libtrau/libtrau.a \ + $(top_builddir)/src/libmgcp/libmgcp.a \ + $(top_builddir)/tests/libiudummy/libiudummy.a \ $(top_builddir)/src/libcommon/libcommon.a \ $(LIBSMPP34_LIBS) \ $(LIBOSMOCORE_LIBS) \ @@ -59,9 +61,11 @@ LDADD = \ LDFLAGS = \ -Wl,--wrap=gsup_client_create \ -Wl,--wrap=gsup_client_send \ - -Wl,--wrap=gsm0808_submit_dtap \ - -Wl,--wrap=paging_request \ - -Wl,--wrap=paging_request_stop \ + -Wl,--wrap=a_tx \ + -Wl,--wrap=a_page \ + -Wl,--wrap=iu_tx \ + -Wl,--wrap=iu_page_cs \ + -Wl,--wrap=msc_stop_paging \ -Wl,--wrap=gsm340_gen_scts \ -Wl,--wrap=RAND_bytes \ $(NULL) 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 diff --git a/openbsc/tests/msc_vlr/msc_vlr_test_gsm_ciph.err b/openbsc/tests/msc_vlr/msc_vlr_test_gsm_ciph.err index 8672418ea..959df09a4 100644 --- a/openbsc/tests/msc_vlr/msc_vlr_test_gsm_ciph.err +++ b/openbsc/tests/msc_vlr/msc_vlr_test_gsm_ciph.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 auth_request_sent == 1 cm_service_result_sent == 0 - needs auth, not yet accepted @@ -253,7 +248,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 @@ -262,7 +258,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 @@ -274,10 +269,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 @@ -312,8 +306,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 @@ -371,10 +363,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 @@ -397,7 +391,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 @@ -409,7 +404,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 @@ -428,8 +422,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_ciph: SUCCESS @@ -464,8 +456,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 @@ -613,7 +603,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 @@ -653,8 +642,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 auth_request_sent == 1 cm_service_result_sent == 0 - needs auth, not yet accepted @@ -727,7 +714,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 @@ -736,7 +724,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 @@ -748,10 +735,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 @@ -786,8 +772,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 @@ -845,10 +829,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 @@ -871,7 +857,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 @@ -883,7 +870,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 @@ -902,8 +888,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_ciph_tmsi: SUCCESS @@ -938,8 +922,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 @@ -1037,7 +1019,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 @@ -1083,7 +1066,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 @@ -1106,8 +1088,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_ciph_imei: SUCCESS @@ -1142,8 +1122,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 @@ -1288,7 +1266,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 @@ -1309,8 +1286,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_ciph_imeisv: SUCCESS @@ -1345,8 +1320,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 @@ -1444,7 +1417,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 @@ -1518,7 +1492,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 @@ -1541,8 +1514,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_ciph_tmsi_imei: SUCCESS diff --git a/openbsc/tests/msc_vlr/msc_vlr_test_hlr_reject.err b/openbsc/tests/msc_vlr/msc_vlr_test_hlr_reject.err index 9dad62556..a6c2d828c 100644 --- a/openbsc/tests/msc_vlr/msc_vlr_test_hlr_reject.err +++ b/openbsc/tests/msc_vlr/msc_vlr_test_hlr_reject.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 - HLR sends _SEND_AUTH_INFO_ERROR = unknown IMSI <-- GSUP rx OSMO_GSUP_MSGT_SEND_AUTH_INFO_ERROR: 09010809710000004026f0020102 @@ -45,6 +43,7 @@ DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_WAIT_AUTH}: Received Event VLR_ULA_E_ DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_WAIT_AUTH}: state_chg to VLR_ULA_S_DONE DVLR Subscr_Conn(901700000004620){SUBSCR_CONN_S_NEW}: Received Event SUBSCR_CONN_E_CN_CLOSE DVLR Subscr_Conn(901700000004620){SUBSCR_CONN_S_NEW}: SUBSCR_CONN_FROM_LU +DVLR Subscr_Conn(901700000004620){SUBSCR_CONN_S_NEW}: Close event, cause 1 DVLR Subscr_Conn(901700000004620){SUBSCR_CONN_S_NEW}: state_chg to SUBSCR_CONN_S_RELEASED DVLR Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Terminating (cause = OSMO_FSM_TERM_REGULAR) DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_DONE}: Terminating (cause = OSMO_FSM_TERM_PARENT) @@ -52,7 +51,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 IMSI:901700000004620 calling bsc_subscr_con_free(), owned_by_msc = true DRLL subscr IMSI:901700000004620: Freeing subscriber connection DREF VLR subscr IMSI:901700000004620 usage decreases to: 1 DVLR Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Freeing instance @@ -95,8 +93,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 - HLR sends _SEND_AUTH_INFO_ERROR = net fail <-- GSUP rx OSMO_GSUP_MSGT_SEND_AUTH_INFO_ERROR: 09010809710000004026f0020111 @@ -115,6 +111,7 @@ DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_WAIT_AUTH}: Received Event VLR_ULA_E_ DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_WAIT_AUTH}: state_chg to VLR_ULA_S_DONE DVLR Subscr_Conn(901700000004620){SUBSCR_CONN_S_NEW}: Received Event SUBSCR_CONN_E_CN_CLOSE DVLR Subscr_Conn(901700000004620){SUBSCR_CONN_S_NEW}: SUBSCR_CONN_FROM_LU +DVLR Subscr_Conn(901700000004620){SUBSCR_CONN_S_NEW}: Close event, cause 1 DVLR Subscr_Conn(901700000004620){SUBSCR_CONN_S_NEW}: state_chg to SUBSCR_CONN_S_RELEASED DVLR Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Terminating (cause = OSMO_FSM_TERM_REGULAR) DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_DONE}: Terminating (cause = OSMO_FSM_TERM_PARENT) @@ -122,7 +119,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 IMSI:901700000004620 calling bsc_subscr_con_free(), owned_by_msc = true DRLL subscr IMSI:901700000004620: Freeing subscriber connection DREF VLR subscr IMSI:901700000004620 usage decreases to: 1 DVLR Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Freeing instance @@ -167,8 +163,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: 0a010809710000004026f003222010585df1ae287f6e273dce07090d61320b21042d8b2c3e220861855fb81fc2a800 @@ -266,7 +260,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 @@ -307,8 +300,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 MSISDN:46071 usage decreases to: 2 -DMM compl_l3: Keeping conn -DMM MSISDN:46071 owned_by_msc = true lu_result_sent == 0 - HLR sends _SEND_AUTH_INFO_ERROR = net fail <-- GSUP rx OSMO_GSUP_MSGT_SEND_AUTH_INFO_ERROR: 09010809710000004026f0020111 @@ -405,7 +396,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 @@ -450,8 +440,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: 0a010809710000004026f003222010585df1ae287f6e273dce07090d61320b21042d8b2c3e220861855fb81fc2a800 @@ -549,7 +537,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 @@ -590,8 +577,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 MSISDN:46071 usage decreases to: 2 -DMM compl_l3: Keeping conn -DMM MSISDN:46071 owned_by_msc = true lu_result_sent == 0 - HLR sends _SEND_AUTH_INFO_ERROR = net fail <-- GSUP rx OSMO_GSUP_MSGT_SEND_AUTH_INFO_ERROR: 09010809710000004026f0020111 @@ -610,6 +595,7 @@ DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_WAIT_AUTH}: Received Event VLR_ULA_E_ DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_WAIT_AUTH}: state_chg to VLR_ULA_S_DONE DVLR Subscr_Conn(901700000004620){SUBSCR_CONN_S_NEW}: Received Event SUBSCR_CONN_E_CN_CLOSE DVLR Subscr_Conn(901700000004620){SUBSCR_CONN_S_NEW}: SUBSCR_CONN_FROM_LU +DVLR Subscr_Conn(901700000004620){SUBSCR_CONN_S_NEW}: Close event, cause 1 DVLR Subscr_Conn(901700000004620){SUBSCR_CONN_S_NEW}: state_chg to SUBSCR_CONN_S_RELEASED DVLR Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Terminating (cause = OSMO_FSM_TERM_REGULAR) DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_DONE}: Terminating (cause = OSMO_FSM_TERM_PARENT) @@ -617,7 +603,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 @@ -662,8 +647,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: 0a010809710000004026f003222010585df1ae287f6e273dce07090d61320b21042d8b2c3e220861855fb81fc2a800 @@ -761,7 +744,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 @@ -803,8 +785,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 MSISDN:46071 usage decreases to: 2 -DMM compl_l3: Keeping conn -DMM MSISDN:46071 owned_by_msc = true lu_result_sent == 0 - HLR sends _SEND_AUTH_INFO_ERROR = unknown IMSI <-- GSUP rx OSMO_GSUP_MSGT_SEND_AUTH_INFO_ERROR: 09010809710000004026f0020102 @@ -823,6 +803,7 @@ DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_WAIT_AUTH}: Received Event VLR_ULA_E_ DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_WAIT_AUTH}: state_chg to VLR_ULA_S_DONE DVLR Subscr_Conn(901700000004620){SUBSCR_CONN_S_NEW}: Received Event SUBSCR_CONN_E_CN_CLOSE DVLR Subscr_Conn(901700000004620){SUBSCR_CONN_S_NEW}: SUBSCR_CONN_FROM_LU +DVLR Subscr_Conn(901700000004620){SUBSCR_CONN_S_NEW}: Close event, cause 1 DVLR Subscr_Conn(901700000004620){SUBSCR_CONN_S_NEW}: state_chg to SUBSCR_CONN_S_RELEASED DVLR Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Terminating (cause = OSMO_FSM_TERM_REGULAR) DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_DONE}: Terminating (cause = OSMO_FSM_TERM_PARENT) @@ -830,7 +811,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 @@ -873,8 +853,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 but it lacks auth tuples <-- GSUP rx OSMO_GSUP_MSGT_SEND_AUTH_INFO_RESULT: 0a010809710000004026f0 @@ -892,6 +870,7 @@ DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_WAIT_AUTH}: Received Event VLR_ULA_E_ DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_WAIT_AUTH}: state_chg to VLR_ULA_S_DONE DVLR Subscr_Conn(901700000004620){SUBSCR_CONN_S_NEW}: Received Event SUBSCR_CONN_E_CN_CLOSE DVLR Subscr_Conn(901700000004620){SUBSCR_CONN_S_NEW}: SUBSCR_CONN_FROM_LU +DVLR Subscr_Conn(901700000004620){SUBSCR_CONN_S_NEW}: Close event, cause 1 DVLR Subscr_Conn(901700000004620){SUBSCR_CONN_S_NEW}: state_chg to SUBSCR_CONN_S_RELEASED DVLR Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Terminating (cause = OSMO_FSM_TERM_REGULAR) DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_DONE}: Terminating (cause = OSMO_FSM_TERM_PARENT) @@ -899,7 +878,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 IMSI:901700000004620 calling bsc_subscr_con_free(), owned_by_msc = true DRLL subscr IMSI:901700000004620: Freeing subscriber connection DREF VLR subscr IMSI:901700000004620 usage decreases to: 1 DVLR Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Freeing instance @@ -945,8 +923,6 @@ DVLR GSUP tx: 04010809710000004026f0 GSUP --> HLR: OSMO_GSUP_MSGT_UPDATE_LOCATION_REQUEST: 04010809710000004026f0 DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_INIT}: state_chg to UPD_HLR_VLR_S_WAIT_FOR_DATA 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 - HLR sends UPDATE_LOCATION_ERROR <-- GSUP rx OSMO_GSUP_MSGT_UPDATE_LOCATION_ERROR: 05010809710000004026f0020102 @@ -965,6 +941,7 @@ DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_WAIT_HLR_UPD}: Received Event VLR_ULA DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_WAIT_HLR_UPD}: state_chg to VLR_ULA_S_DONE DVLR Subscr_Conn(901700000004620){SUBSCR_CONN_S_NEW}: Received Event SUBSCR_CONN_E_CN_CLOSE DVLR Subscr_Conn(901700000004620){SUBSCR_CONN_S_NEW}: SUBSCR_CONN_FROM_LU +DVLR Subscr_Conn(901700000004620){SUBSCR_CONN_S_NEW}: Close event, cause 1 DVLR Subscr_Conn(901700000004620){SUBSCR_CONN_S_NEW}: state_chg to SUBSCR_CONN_S_RELEASED DVLR Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Terminating (cause = OSMO_FSM_TERM_REGULAR) DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_DONE}: Terminating (cause = OSMO_FSM_TERM_PARENT) @@ -972,7 +949,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 IMSI:901700000004620 calling bsc_subscr_con_free(), owned_by_msc = true DRLL subscr IMSI:901700000004620: Freeing subscriber connection DREF VLR subscr IMSI:901700000004620 usage decreases to: 1 DVLR Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Freeing instance @@ -1017,8 +993,6 @@ DVLR GSUP tx: 04010809710000004026f0 GSUP --> HLR: OSMO_GSUP_MSGT_UPDATE_LOCATION_REQUEST: 04010809710000004026f0 DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_INIT}: state_chg to UPD_HLR_VLR_S_WAIT_FOR_DATA 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 - HLR sends only _UPDATE_LOCATION_RESULT, no INSERT DATA <-- GSUP rx OSMO_GSUP_MSGT_UPDATE_LOCATION_RESULT: 06010809710000004026f0 @@ -1066,7 +1040,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 IMSI:901700000004620 calling bsc_subscr_con_free(), owned_by_msc = true DRLL subscr IMSI:901700000004620: Freeing subscriber connection DREF VLR subscr IMSI:901700000004620 usage decreases to: 2 DVLR Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Freeing instance diff --git a/openbsc/tests/msc_vlr/msc_vlr_test_hlr_timeout.err b/openbsc/tests/msc_vlr/msc_vlr_test_hlr_timeout.err index beca6981d..03491692c 100644 --- a/openbsc/tests/msc_vlr/msc_vlr_test_hlr_timeout.err +++ b/openbsc/tests/msc_vlr/msc_vlr_test_hlr_timeout.err @@ -26,8 +26,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 --- - HLR never replies @@ -49,6 +47,7 @@ DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_WAIT_AUTH}: Connection timed out DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_WAIT_AUTH}: state_chg to VLR_ULA_S_DONE DVLR Subscr_Conn(901700000004620){SUBSCR_CONN_S_NEW}: Received Event SUBSCR_CONN_E_CN_CLOSE DVLR Subscr_Conn(901700000004620){SUBSCR_CONN_S_NEW}: SUBSCR_CONN_FROM_LU +DVLR Subscr_Conn(901700000004620){SUBSCR_CONN_S_NEW}: Close event, cause 1 DVLR Subscr_Conn(901700000004620){SUBSCR_CONN_S_NEW}: state_chg to SUBSCR_CONN_S_RELEASED DVLR Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Terminating (cause = OSMO_FSM_TERM_REGULAR) DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_DONE}: Terminating (cause = OSMO_FSM_TERM_PARENT) @@ -60,7 +59,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 IMSI:901700000004620 calling bsc_subscr_con_free(), owned_by_msc = true DRLL subscr IMSI:901700000004620: Freeing subscriber connection DREF VLR subscr IMSI:901700000004620 usage decreases to: 0 DREF freeing VLR subscr IMSI:901700000004620 @@ -107,8 +105,6 @@ DVLR GSUP tx: 04010809710000004026f0 GSUP --> HLR: OSMO_GSUP_MSGT_UPDATE_LOCATION_REQUEST: 04010809710000004026f0 DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_INIT}: state_chg to UPD_HLR_VLR_S_WAIT_FOR_DATA 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 - HLR sends _INSERT_DATA_REQUEST, VLR responds with _INSERT_DATA_RESULT <-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: 10010809710000004026f00804036470f1 @@ -145,6 +141,7 @@ DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_WAIT_HLR_UPD}: Connection timed out DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_WAIT_HLR_UPD}: state_chg to VLR_ULA_S_DONE DVLR Subscr_Conn(901700000004620){SUBSCR_CONN_S_NEW}: Received Event SUBSCR_CONN_E_CN_CLOSE DVLR Subscr_Conn(901700000004620){SUBSCR_CONN_S_NEW}: SUBSCR_CONN_FROM_LU +DVLR Subscr_Conn(901700000004620){SUBSCR_CONN_S_NEW}: Close event, cause 1 DVLR Subscr_Conn(901700000004620){SUBSCR_CONN_S_NEW}: state_chg to SUBSCR_CONN_S_RELEASED DVLR Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Terminating (cause = OSMO_FSM_TERM_REGULAR) DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_DONE}: Terminating (cause = OSMO_FSM_TERM_PARENT) @@ -156,7 +153,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: 0 DREF freeing VLR subscr MSISDN:46071 diff --git a/openbsc/tests/msc_vlr/msc_vlr_test_ms_timeout.err b/openbsc/tests/msc_vlr/msc_vlr_test_ms_timeout.err index 7c7e01ffc..f82aa7a8d 100644 --- a/openbsc/tests/msc_vlr/msc_vlr_test_ms_timeout.err +++ b/openbsc/tests/msc_vlr/msc_vlr_test_ms_timeout.err @@ -26,8 +26,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: 0a010809710000004026f003222010585df1ae287f6e273dce07090d61320b21042d8b2c3e220861855fb81fc2a800 @@ -69,6 +67,7 @@ DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_WAIT_AUTH}: Connection timed out DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_WAIT_AUTH}: state_chg to VLR_ULA_S_DONE DVLR Subscr_Conn(901700000004620){SUBSCR_CONN_S_NEW}: Received Event SUBSCR_CONN_E_CN_CLOSE DVLR Subscr_Conn(901700000004620){SUBSCR_CONN_S_NEW}: SUBSCR_CONN_FROM_LU +DVLR Subscr_Conn(901700000004620){SUBSCR_CONN_S_NEW}: Close event, cause 1 DVLR Subscr_Conn(901700000004620){SUBSCR_CONN_S_NEW}: state_chg to SUBSCR_CONN_S_RELEASED DVLR Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Terminating (cause = OSMO_FSM_TERM_REGULAR) DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_DONE}: Terminating (cause = OSMO_FSM_TERM_PARENT) @@ -80,7 +79,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 IMSI:901700000004620 calling bsc_subscr_con_free(), owned_by_msc = true DRLL subscr IMSI:901700000004620: Freeing subscriber connection DREF VLR subscr IMSI:901700000004620 usage decreases to: 0 DREF freeing VLR subscr IMSI:901700000004620 @@ -124,8 +122,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 @@ -223,7 +219,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 @@ -259,8 +254,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 --- @@ -290,6 +283,7 @@ DVLR Process_Access_Request_VLR(901700000004620){PR_ARQ_S_DONE}: Process Access - sending CM Service Reject for MSISDN:46071, result VLR_PR_ARQ_RES_TIMEOUT DVLR Subscr_Conn(901700000004620){SUBSCR_CONN_S_NEW}: Received Event SUBSCR_CONN_E_CN_CLOSE DVLR Subscr_Conn(901700000004620){SUBSCR_CONN_S_NEW}: SUBSCR_CONN_FROM_CM_SERVICE_REQ +DVLR Subscr_Conn(901700000004620){SUBSCR_CONN_S_NEW}: Close event, cause 2 DVLR Subscr_Conn(901700000004620){SUBSCR_CONN_S_NEW}: state_chg to SUBSCR_CONN_S_RELEASED DVLR Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Terminating (cause = OSMO_FSM_TERM_REGULAR) DVLR Process_Access_Request_VLR(901700000004620){PR_ARQ_S_DONE}: Terminating (cause = OSMO_FSM_TERM_PARENT) @@ -300,7 +294,6 @@ DVLR VLR_Authenticate(901700000004620){VLR_SUB_AS_WAIT_RESP}: Deallocated 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 diff --git a/openbsc/tests/msc_vlr/msc_vlr_test_no_authen.c b/openbsc/tests/msc_vlr/msc_vlr_test_no_authen.c index fdafe3e4b..f5e2e2b62 100644 --- a/openbsc/tests/msc_vlr/msc_vlr_test_no_authen.c +++ b/openbsc/tests/msc_vlr/msc_vlr_test_no_authen.c @@ -27,6 +27,9 @@ void test_no_authen() { struct vlr_subscr *vsub; const char *imsi = "901700000004620"; + + /* No auth only works on GERAN */ + rx_from_ran = RAN_GERAN_A; comment_start(); @@ -68,6 +71,7 @@ void test_no_authen() btw("a USSD request is serviced"); dtap_expect_tx_ussd("Your extension is 46071\r"); ms_sends_msg("0b3b1c15a11302010002013b300b04010f0406aa510c061b017f0100"); + VERBOSE_ASSERT(dtap_tx_confirmed, == true, "%d"); btw("all requests serviced, conn has been released"); EXPECT_CONN_COUNT(0); @@ -155,6 +159,8 @@ void test_no_authen_tmsi() struct vlr_subscr *vsub; const char *imsi = "901700000004620"; + rx_from_ran = RAN_GERAN_A; + comment_start(); net->vlr->cfg.assign_tmsi = true; @@ -363,6 +369,8 @@ void test_no_authen_imei() struct vlr_subscr *vsub; const char *imsi = "901700000004620"; + rx_from_ran = RAN_GERAN_A; + comment_start(); net->vlr->cfg.check_imei_rqd = true; @@ -423,6 +431,8 @@ void test_no_authen_tmsi_imei() struct vlr_subscr *vsub; const char *imsi = "901700000004620"; + rx_from_ran = RAN_GERAN_A; + comment_start(); net->vlr->cfg.assign_tmsi = true; diff --git a/openbsc/tests/msc_vlr/msc_vlr_test_no_authen.err b/openbsc/tests/msc_vlr/msc_vlr_test_no_authen.err index 3c97c5e2a..e12c19855 100644 --- a/openbsc/tests/msc_vlr/msc_vlr_test_no_authen.err +++ b/openbsc/tests/msc_vlr/msc_vlr_test_no_authen.err @@ -28,8 +28,6 @@ DVLR GSUP tx: 04010809710000004026f0 GSUP --> HLR: OSMO_GSUP_MSGT_UPDATE_LOCATION_REQUEST: 04010809710000004026f0 DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_INIT}: state_chg to UPD_HLR_VLR_S_WAIT_FOR_DATA 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 - HLR sends _INSERT_DATA_REQUEST, VLR responds with _INSERT_DATA_RESULT <-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: 10010809710000004026f00804036470f1 @@ -99,7 +97,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 @@ -141,8 +138,6 @@ DVLR Subscr_Conn(901700000004620){SUBSCR_CONN_S_NEW}: state_chg to SUBSCR_CONN_S DVLR Subscr_Conn(901700000004620){SUBSCR_CONN_S_ACCEPTED}: received_cm_service_request = true DVLR Subscr_Conn(901700000004620){SUBSCR_CONN_S_ACCEPTED}: Received Event SUBSCR_CONN_E_BUMP 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 == 1 msc_subscr_conn_is_accepted() == true - a USSD request is serviced @@ -155,7 +150,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 @@ -164,11 +160,11 @@ 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 DVLR Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Deallocated + dtap_tx_confirmed == 1 - all requests serviced, conn has been released llist_count(&net->subscr_conns) == 0 --- @@ -176,10 +172,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 @@ -216,16 +211,16 @@ 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: 6 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: 5 DVLR Subscr_Conn(901700000004620){SUBSCR_CONN_S_ACCEPTED}: Received Event SUBSCR_CONN_E_BUMP DREF VLR subscr MSISDN:46071 usage decreases to: 4 -DMM compl_l3: Keeping conn -DMM MSISDN:46071 owned_by_msc = true dtap_tx_confirmed == 1 paging_stopped == 1 - SMS was delivered, no requests pending for subscr @@ -245,7 +240,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 @@ -257,7 +253,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 @@ -276,8 +271,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_no_authen: SUCCESS @@ -315,8 +308,6 @@ DVLR GSUP tx: 04010809710000004026f0 GSUP --> HLR: OSMO_GSUP_MSGT_UPDATE_LOCATION_REQUEST: 04010809710000004026f0 DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_INIT}: state_chg to UPD_HLR_VLR_S_WAIT_FOR_DATA 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 - HLR sends _INSERT_DATA_REQUEST, VLR responds with _INSERT_DATA_RESULT <-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: 10010809710000004026f00804036470f1 @@ -416,7 +407,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 @@ -462,8 +452,6 @@ DVLR Subscr_Conn(50462976){SUBSCR_CONN_S_NEW}: state_chg to SUBSCR_CONN_S_ACCEPT DVLR Subscr_Conn(50462976){SUBSCR_CONN_S_ACCEPTED}: received_cm_service_request = true DVLR Subscr_Conn(50462976){SUBSCR_CONN_S_ACCEPTED}: Received Event SUBSCR_CONN_E_BUMP 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 == 1 msc_subscr_conn_is_accepted() == true - a USSD request is serviced @@ -476,7 +464,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 @@ -485,7 +474,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 @@ -497,10 +485,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 @@ -537,16 +524,16 @@ 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: 6 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: 5 DVLR Subscr_Conn(50462976){SUBSCR_CONN_S_ACCEPTED}: Received Event SUBSCR_CONN_E_BUMP DREF VLR subscr MSISDN:46071 usage decreases to: 4 -DMM compl_l3: Keeping conn -DMM MSISDN:46071 owned_by_msc = true dtap_tx_confirmed == 1 paging_stopped == 1 - SMS was delivered, no requests pending for subscr @@ -566,7 +553,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 @@ -578,7 +566,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 @@ -615,8 +602,6 @@ DVLR GSUP tx: 04010809710000004026f0 GSUP --> HLR: OSMO_GSUP_MSGT_UPDATE_LOCATION_REQUEST: 04010809710000004026f0 DVLR upd_hlr_vlr_fsm(50462976){UPD_HLR_VLR_S_INIT}: state_chg to UPD_HLR_VLR_S_WAIT_FOR_DATA DREF VLR subscr MSISDN:46071 usage decreases to: 2 -DMM compl_l3: Keeping conn -DMM MSISDN:46071 owned_by_msc = true lu_result_sent == 0 - HLR sends _INSERT_DATA_REQUEST, VLR responds with _INSERT_DATA_RESULT <-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: 10010809710000004026f00804036470f1 @@ -715,7 +700,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 @@ -740,8 +724,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_no_authen_tmsi: SUCCESS @@ -779,8 +761,6 @@ DVLR GSUP tx: 04010809710000004026f0 GSUP --> HLR: OSMO_GSUP_MSGT_UPDATE_LOCATION_REQUEST: 04010809710000004026f0 DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_INIT}: state_chg to UPD_HLR_VLR_S_WAIT_FOR_DATA 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 - HLR sends _INSERT_DATA_REQUEST, VLR responds with _INSERT_DATA_RESULT <-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: 10010809710000004026f00804036470f1 @@ -831,7 +811,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 @@ -877,7 +858,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 @@ -900,8 +880,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_no_authen_imei: SUCCESS @@ -939,8 +917,6 @@ DVLR GSUP tx: 04010809710000004026f0 GSUP --> HLR: OSMO_GSUP_MSGT_UPDATE_LOCATION_REQUEST: 04010809710000004026f0 DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_INIT}: state_chg to UPD_HLR_VLR_S_WAIT_FOR_DATA 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 - HLR sends _INSERT_DATA_REQUEST, VLR responds with _INSERT_DATA_RESULT <-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: 10010809710000004026f00804036470f1 @@ -991,7 +967,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 @@ -1058,7 +1035,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 @@ -1082,8 +1058,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_no_authen_tmsi_imei: SUCCESS diff --git a/openbsc/tests/msc_vlr/msc_vlr_test_reject_concurrency.err b/openbsc/tests/msc_vlr/msc_vlr_test_reject_concurrency.err index 4e1c57d9a..830c83197 100644 --- a/openbsc/tests/msc_vlr/msc_vlr_test_reject_concurrency.err +++ b/openbsc/tests/msc_vlr/msc_vlr_test_reject_concurrency.err @@ -28,8 +28,6 @@ DVLR GSUP tx: 04010809710000004026f0 GSUP --> HLR: OSMO_GSUP_MSGT_UPDATE_LOCATION_REQUEST: 04010809710000004026f0 DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_INIT}: state_chg to UPD_HLR_VLR_S_WAIT_FOR_DATA 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 llist_count(&net->subscr_conns) == 1 - Another Location Update Request from the same subscriber on another connection is rejected @@ -51,6 +49,7 @@ DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_IDLE}: A Location Updating process is DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_IDLE}: state_chg to VLR_ULA_S_DONE DVLR Subscr_Conn(901700000004620){SUBSCR_CONN_S_NEW}: Received Event SUBSCR_CONN_E_CN_CLOSE DVLR Subscr_Conn(901700000004620){SUBSCR_CONN_S_NEW}: SUBSCR_CONN_FROM_LU +DVLR Subscr_Conn(901700000004620){SUBSCR_CONN_S_NEW}: Close event, cause 1 DVLR Subscr_Conn(901700000004620){SUBSCR_CONN_S_NEW}: state_chg to SUBSCR_CONN_S_RELEASED DVLR Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Terminating (cause = OSMO_FSM_TERM_REGULAR) DVLR vlr_lu_fsm(901700000004620){VLR_ULA_S_DONE}: Terminating (cause = OSMO_FSM_TERM_PARENT) @@ -58,14 +57,11 @@ 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 unknown leaving bsc_subscr_con_free() to bsc_api.c, owned_by_msc = false +DRLL Freeing subscriber connection with NULL subscriber DVLR Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Freeing instance DVLR Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Deallocated DREF VLR subscr IMSI:901700000004620 usage decreases to: 1 DRR 901700000004620: internal error during Location Updating attempt -DMM No conn_fsm, release conn -DMM compl_l3: Discarding conn -DRLL Freeing subscriber connection with NULL subscriber lu_result_sent == 2 llist_count(&net->subscr_conns) == 1 --- @@ -126,7 +122,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 @@ -172,8 +167,6 @@ DVLR GSUP tx: 04010809710000004026f0 GSUP --> HLR: OSMO_GSUP_MSGT_UPDATE_LOCATION_REQUEST: 04010809710000004026f0 DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_INIT}: state_chg to UPD_HLR_VLR_S_WAIT_FOR_DATA 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 llist_count(&net->subscr_conns) == 1 --- @@ -241,7 +234,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 @@ -287,8 +279,6 @@ DVLR GSUP tx: 04010809710000004026f0 GSUP --> HLR: OSMO_GSUP_MSGT_UPDATE_LOCATION_REQUEST: 04010809710000004026f0 DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_INIT}: state_chg to UPD_HLR_VLR_S_WAIT_FOR_DATA 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 llist_count(&net->subscr_conns) == 1 --- @@ -358,7 +348,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 @@ -404,8 +393,6 @@ DVLR GSUP tx: 04010809710000004026f0 GSUP --> HLR: OSMO_GSUP_MSGT_UPDATE_LOCATION_REQUEST: 04010809710000004026f0 DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_INIT}: state_chg to UPD_HLR_VLR_S_WAIT_FOR_DATA 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 llist_count(&net->subscr_conns) == 1 --- @@ -474,7 +461,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 @@ -522,8 +508,6 @@ DVLR GSUP tx: 04010809710000004026f0 GSUP --> HLR: OSMO_GSUP_MSGT_UPDATE_LOCATION_REQUEST: 04010809710000004026f0 DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_INIT}: state_chg to UPD_HLR_VLR_S_WAIT_FOR_DATA 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 llist_count(&net->subscr_conns) == 1 - HLR sends _INSERT_DATA_REQUEST, VLR responds with _INSERT_DATA_RESULT @@ -582,7 +566,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 @@ -624,8 +607,6 @@ DVLR Subscr_Conn(901700000004620){SUBSCR_CONN_S_NEW}: state_chg to SUBSCR_CONN_S DVLR Subscr_Conn(901700000004620){SUBSCR_CONN_S_ACCEPTED}: received_cm_service_request = true DVLR Subscr_Conn(901700000004620){SUBSCR_CONN_S_ACCEPTED}: Received Event SUBSCR_CONN_E_BUMP 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 == 1 msc_subscr_conn_is_accepted() == true - An erratic LU request on the same conn results in conn termination @@ -640,7 +621,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 @@ -685,8 +665,6 @@ DVLR GSUP tx: 04010809710000004026f0 GSUP --> HLR: OSMO_GSUP_MSGT_UPDATE_LOCATION_REQUEST: 04010809710000004026f0 DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_INIT}: state_chg to UPD_HLR_VLR_S_WAIT_FOR_DATA 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 llist_count(&net->subscr_conns) == 1 - HLR sends _INSERT_DATA_REQUEST, VLR responds with _INSERT_DATA_RESULT @@ -745,7 +723,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 @@ -787,8 +764,6 @@ DVLR Subscr_Conn(901700000004620){SUBSCR_CONN_S_NEW}: state_chg to SUBSCR_CONN_S DVLR Subscr_Conn(901700000004620){SUBSCR_CONN_S_ACCEPTED}: received_cm_service_request = true DVLR Subscr_Conn(901700000004620){SUBSCR_CONN_S_ACCEPTED}: Received Event SUBSCR_CONN_E_BUMP 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 == 1 msc_subscr_conn_is_accepted() == true - Another CM Service Request request on the same conn results in conn termination @@ -804,7 +779,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 @@ -849,8 +823,6 @@ DVLR GSUP tx: 04010809710000004026f0 GSUP --> HLR: OSMO_GSUP_MSGT_UPDATE_LOCATION_REQUEST: 04010809710000004026f0 DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_INIT}: state_chg to UPD_HLR_VLR_S_WAIT_FOR_DATA 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 llist_count(&net->subscr_conns) == 1 - HLR sends _INSERT_DATA_REQUEST, VLR responds with _INSERT_DATA_RESULT @@ -909,7 +881,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 @@ -951,8 +922,6 @@ DVLR Subscr_Conn(901700000004620){SUBSCR_CONN_S_NEW}: state_chg to SUBSCR_CONN_S DVLR Subscr_Conn(901700000004620){SUBSCR_CONN_S_ACCEPTED}: received_cm_service_request = true DVLR Subscr_Conn(901700000004620){SUBSCR_CONN_S_ACCEPTED}: Received Event SUBSCR_CONN_E_BUMP 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 == 1 msc_subscr_conn_is_accepted() == true --- @@ -975,7 +944,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 @@ -984,7 +954,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 @@ -1029,8 +998,6 @@ DVLR GSUP tx: 04010809710000004026f0 GSUP --> HLR: OSMO_GSUP_MSGT_UPDATE_LOCATION_REQUEST: 04010809710000004026f0 DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_INIT}: state_chg to UPD_HLR_VLR_S_WAIT_FOR_DATA 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 llist_count(&net->subscr_conns) == 1 - HLR sends _INSERT_DATA_REQUEST, VLR responds with _INSERT_DATA_RESULT @@ -1089,7 +1056,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 @@ -1104,10 +1070,9 @@ DREF VLR subscr MSISDN:46071 usage decreases to: 1 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 @@ -1140,16 +1105,16 @@ 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: 6 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: 5 DVLR Subscr_Conn(901700000004620){SUBSCR_CONN_S_ACCEPTED}: Received Event SUBSCR_CONN_E_BUMP DREF VLR subscr MSISDN:46071 usage decreases to: 4 -DMM compl_l3: Keeping conn -DMM MSISDN:46071 owned_by_msc = true dtap_tx_confirmed == 1 paging_stopped == 1 - conn is still open to wait for SMS ack dance @@ -1173,7 +1138,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 @@ -1185,7 +1151,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 @@ -1231,8 +1196,6 @@ DVLR GSUP tx: 04010809710000004026f0 GSUP --> HLR: OSMO_GSUP_MSGT_UPDATE_LOCATION_REQUEST: 04010809710000004026f0 DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_INIT}: state_chg to UPD_HLR_VLR_S_WAIT_FOR_DATA 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 llist_count(&net->subscr_conns) == 1 - HLR sends _INSERT_DATA_REQUEST, VLR responds with _INSERT_DATA_RESULT @@ -1291,7 +1254,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 @@ -1306,10 +1268,9 @@ DREF VLR subscr MSISDN:46071 usage decreases to: 1 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 @@ -1342,16 +1303,16 @@ 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: 6 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: 5 DVLR Subscr_Conn(901700000004620){SUBSCR_CONN_S_ACCEPTED}: Received Event SUBSCR_CONN_E_BUMP DREF VLR subscr MSISDN:46071 usage decreases to: 4 -DMM compl_l3: Keeping conn -DMM MSISDN:46071 owned_by_msc = true dtap_tx_confirmed == 1 paging_stopped == 1 - conn is still open to wait for SMS ack dance @@ -1376,7 +1337,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 @@ -1388,7 +1350,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 @@ -1434,8 +1395,6 @@ DVLR GSUP tx: 04010809710000004026f0 GSUP --> HLR: OSMO_GSUP_MSGT_UPDATE_LOCATION_REQUEST: 04010809710000004026f0 DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_INIT}: state_chg to UPD_HLR_VLR_S_WAIT_FOR_DATA 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 llist_count(&net->subscr_conns) == 1 - HLR sends _INSERT_DATA_REQUEST, VLR responds with _INSERT_DATA_RESULT @@ -1494,7 +1453,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 @@ -1509,10 +1467,9 @@ DREF VLR subscr MSISDN:46071 usage decreases to: 1 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 @@ -1545,16 +1502,16 @@ 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: 6 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: 5 DVLR Subscr_Conn(901700000004620){SUBSCR_CONN_S_ACCEPTED}: Received Event SUBSCR_CONN_E_BUMP DREF VLR subscr MSISDN:46071 usage decreases to: 4 -DMM compl_l3: Keeping conn -DMM MSISDN:46071 owned_by_msc = true dtap_tx_confirmed == 1 paging_stopped == 1 - conn is still open to wait for SMS ack dance @@ -1577,7 +1534,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 @@ -1589,7 +1547,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 diff --git a/openbsc/tests/msc_vlr/msc_vlr_test_rest.c b/openbsc/tests/msc_vlr/msc_vlr_test_rest.c index 24b05f13f..5ccc951be 100644 --- a/openbsc/tests/msc_vlr/msc_vlr_test_rest.c +++ b/openbsc/tests/msc_vlr/msc_vlr_test_rest.c @@ -48,7 +48,6 @@ void test_early_stage() OSMO_ASSERT(g_conn->vsub); /* mark as silent call so it sticks around */ g_conn->silent_call = 1; - g_conn->owned_by_msc = true; osmo_fsm_inst_state_chg(g_conn->conn_fsm, SUBSCR_CONN_S_ACCEPTED, 0, 0); EXPECT_CONN_COUNT(1); EXPECT_ACCEPTED(true); diff --git a/openbsc/tests/msc_vlr/msc_vlr_test_rest.err b/openbsc/tests/msc_vlr/msc_vlr_test_rest.err index 63170595f..b2ca91d41 100644 --- a/openbsc/tests/msc_vlr/msc_vlr_test_rest.err +++ b/openbsc/tests/msc_vlr/msc_vlr_test_rest.err @@ -26,7 +26,6 @@ msc_subscr_conn_is_accepted() == true DVLR Subscr_Conn(test){SUBSCR_CONN_S_ACCEPTED}: Received Event SUBSCR_CONN_E_CN_CLOSE DVLR Subscr_Conn(test){SUBSCR_CONN_S_ACCEPTED}: state_chg to SUBSCR_CONN_S_RELEASED DVLR Subscr_Conn(test){SUBSCR_CONN_S_RELEASED}: Terminating (cause = OSMO_FSM_TERM_REGULAR) -DMM unknown calling bsc_subscr_con_free(), owned_by_msc = true DRLL subscr unknown: Freeing subscriber connection DREF VLR subscr unknown usage decreases to: 0 DREF freeing VLR subscr unknown @@ -57,18 +56,16 @@ DVLR Process_Access_Request_VLR(901700000004620){PR_ARQ_S_DONE}: Process Access - sending CM Service Reject for unknown, result VLR_PR_ARQ_RES_UNIDENT_SUBSCR DVLR Subscr_Conn(901700000004620){SUBSCR_CONN_S_NEW}: Received Event SUBSCR_CONN_E_CN_CLOSE DVLR Subscr_Conn(901700000004620){SUBSCR_CONN_S_NEW}: SUBSCR_CONN_FROM_CM_SERVICE_REQ +DVLR Subscr_Conn(901700000004620){SUBSCR_CONN_S_NEW}: Close event, cause 2 DVLR Subscr_Conn(901700000004620){SUBSCR_CONN_S_NEW}: state_chg to SUBSCR_CONN_S_RELEASED DVLR Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Terminating (cause = OSMO_FSM_TERM_REGULAR) DVLR Process_Access_Request_VLR(901700000004620){PR_ARQ_S_DONE}: Terminating (cause = OSMO_FSM_TERM_PARENT) 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 unknown leaving bsc_subscr_con_free() to bsc_api.c, owned_by_msc = false +DRLL Freeing subscriber connection with NULL subscriber DVLR Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Freeing instance DVLR Subscr_Conn(901700000004620){SUBSCR_CONN_S_RELEASED}: Deallocated -DMM No conn_fsm, release conn -DMM compl_l3: Discarding conn -DRLL Freeing subscriber connection with NULL subscriber - conn was released llist_count(&net->subscr_conns) == 0 ===== test_cm_service_without_lu: SUCCESS @@ -106,8 +103,6 @@ DVLR GSUP tx: 04010809710000004026f0 GSUP --> HLR: OSMO_GSUP_MSGT_UPDATE_LOCATION_REQUEST: 04010809710000004026f0 DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_INIT}: state_chg to UPD_HLR_VLR_S_WAIT_FOR_DATA 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 - HLR sends _INSERT_DATA_REQUEST, VLR responds with _INSERT_DATA_RESULT <-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: 10010809710000004026f00804036470f1 @@ -177,7 +172,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 @@ -216,8 +210,6 @@ DVLR GSUP tx: 04010809710000004026f0 GSUP --> HLR: OSMO_GSUP_MSGT_UPDATE_LOCATION_REQUEST: 04010809710000004026f0 DVLR upd_hlr_vlr_fsm(901700000004620){UPD_HLR_VLR_S_INIT}: state_chg to UPD_HLR_VLR_S_WAIT_FOR_DATA DREF VLR subscr MSISDN:46071 usage decreases to: 2 -DMM compl_l3: Keeping conn -DMM MSISDN:46071 owned_by_msc = true lu_result_sent == 0 - HLR sends _INSERT_DATA_REQUEST, VLR responds with _INSERT_DATA_RESULT <-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: 10010809710000004026f00804036470f1 @@ -286,7 +278,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 @@ -307,8 +298,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_two_lu: SUCCESS @@ -335,11 +324,10 @@ DVLR New subscr, TMSI: 0x23422342 DREF VLR subscr TMSI:0x23422342 usage increases to: 2 DVLR vlr_lu_fsm(591536962){VLR_ULA_S_IDLE}: vlr_loc_upd_want_imsi() DVLR vlr_lu_fsm(591536962){VLR_ULA_S_IDLE}: state_chg to VLR_ULA_S_WAIT_IMSI -- DTAP --> MS: 051801 +DMSC msc_tx 3 bytes to TMSI:0x23422342 via RAN_GERAN_A +- DTAP --RAN_GERAN_A--> MS: 051801 - DTAP matches expected message DREF VLR subscr TMSI:0x23422342 usage decreases to: 1 -DMM compl_l3: Keeping conn -DMM TMSI:0x23422342 owned_by_msc = true lu_result_sent == 0 msc_subscr_conn_is_accepted() == false requests shall be thwarted @@ -438,7 +426,6 @@ DVLR vlr_lu_fsm(591536962){VLR_ULA_S_DONE}: Removing from parent Subscr_Conn(591 DVLR vlr_lu_fsm(591536962){VLR_ULA_S_DONE}: fsm_lu_cleanup called with cause OSMO_FSM_TERM_PARENT DVLR vlr_lu_fsm(591536962){VLR_ULA_S_DONE}: Freeing instance DVLR vlr_lu_fsm(591536962){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(591536962){SUBSCR_CONN_S_RELEASED}: Freeing instance diff --git a/openbsc/tests/msc_vlr/msc_vlr_test_umts_authen.err b/openbsc/tests/msc_vlr/msc_vlr_test_umts_authen.err index eb1cf4a31..19c260384 100644 --- a/openbsc/tests/msc_vlr/msc_vlr_test_umts_authen.err +++ b/openbsc/tests/msc_vlr/msc_vlr_test_umts_authen.err @@ -25,8 +25,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: 0a010809710000000156f00362201039fa2f4e3d523d8619a73b4f65c3e14d21049b36efdf2208059a4f668f6fbe39231027497388b6cb044648f396aa155b95ef2410f64735036e5871319c679f4742a75ea125108704f5ba55f30000d2ee44b22c8ea9192708e229c19e791f2e4103622010c187a53a5e6b9d573cac7c74451fd46d210485aa31302208d3d50a000bf04f6e23101159ec926a50e98c034a6b7d7c9f418d2410df3a03d9ca5335641efc8e36d76cd20b25101843a645b98d00005b2d666af46c45d927087db47cf7f81e4dc703622010efa9c29a9742148d5c9070348716e1bb210469d5f9fb22083df176f0c29f1a3d2310eb50e770ddcc3060101d2f43b6c2b884241076542abce5ff9345b0e8947f4c6e019c2510f9375e6d41e1000096e7fe4ff1c27e392708706f996719ba609c03622010f023d5a3b24726e0631b64b3840f82532104d570c03f2208ec011be8919883d62310c4e58af4ba43f3bcd904e16984f086d724100593f65e752e5cb7f473862bda05aa0a2510541ff1f077270000c5ea00d658bc7e9a27083fd26072eaa2a04d036220102f8f90c780d6a9c0c53da7ac57b6707e2104b072446f220823f39f9f425ad6e6231065af0527fda95b0dc5ae4aa515cdf32f2410537c3b35a3b13b08d08eeb28098f45cc25104bf4e564f75300009bc796706bc6574427080edb0eadbea94ac2 @@ -125,7 +123,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 @@ -162,8 +159,6 @@ DVLR VLR_Authenticate(901700000010650){VLR_SUB_AS_WAIT_RESP}: got auth tuple: us - ...autn=1843a645b98d00005b2d666af46c45d9 - ...expecting res=7db47cf7f81e4dc7 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 @@ -219,7 +214,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 @@ -228,7 +224,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 @@ -240,10 +235,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 @@ -279,8 +273,6 @@ DVLR VLR_Authenticate(901700000010650){VLR_SUB_AS_WAIT_RESP}: got auth tuple: us - ...autn=f9375e6d41e1000096e7fe4ff1c27e39 - ...expecting res=706f996719ba609c 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 @@ -320,10 +312,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 @@ -347,7 +341,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 @@ -359,7 +354,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 @@ -378,8 +372,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_umts_authen_geran: SUCCESS @@ -414,8 +406,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: 0a010809710000000156f00362201039fa2f4e3d523d8619a73b4f65c3e14d21049b36efdf2208059a4f668f6fbe39231027497388b6cb044648f396aa155b95ef2410f64735036e5871319c679f4742a75ea125108704f5ba55f30000d2ee44b22c8ea9192708e229c19e791f2e4103622010c187a53a5e6b9d573cac7c74451fd46d210485aa31302208d3d50a000bf04f6e23101159ec926a50e98c034a6b7d7c9f418d2410df3a03d9ca5335641efc8e36d76cd20b25101843a645b98d00005b2d666af46c45d927087db47cf7f81e4dc703622010efa9c29a9742148d5c9070348716e1bb210469d5f9fb22083df176f0c29f1a3d2310eb50e770ddcc3060101d2f43b6c2b884241076542abce5ff9345b0e8947f4c6e019c2510f9375e6d41e1000096e7fe4ff1c27e392708706f996719ba609c03622010f023d5a3b24726e0631b64b3840f82532104d570c03f2208ec011be8919883d62310c4e58af4ba43f3bcd904e16984f086d724100593f65e752e5cb7f473862bda05aa0a2510541ff1f077270000c5ea00d658bc7e9a27083fd26072eaa2a04d036220102f8f90c780d6a9c0c53da7ac57b6707e2104b072446f220823f39f9f425ad6e6231065af0527fda95b0dc5ae4aa515cdf32f2410537c3b35a3b13b08d08eeb28098f45cc25104bf4e564f75300009bc796706bc6574427080edb0eadbea94ac2 @@ -514,7 +504,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 @@ -551,8 +540,6 @@ DVLR VLR_Authenticate(901700000010650){VLR_SUB_AS_WAIT_RESP}: got auth tuple: us - ...autn=1843a645b98d00005b2d666af46c45d9 - ...expecting res=7db47cf7f81e4dc7 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 @@ -608,7 +595,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_UTRAN_IU +- DTAP --RAN_UTRAN_IU--> 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 @@ -617,7 +605,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 @@ -629,10 +616,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_UTRAN_IU 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 @@ -668,8 +654,6 @@ DVLR VLR_Authenticate(901700000010650){VLR_SUB_AS_WAIT_RESP}: got auth tuple: us - ...autn=f9375e6d41e1000096e7fe4ff1c27e39 - ...expecting res=706f996719ba609c 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 @@ -709,10 +693,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_UTRAN_IU +- DTAP --RAN_UTRAN_IU--> 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 @@ -736,7 +722,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_UTRAN_IU +- DTAP --RAN_UTRAN_IU--> MS: 0904 - DTAP matches expected message DREF VLR subscr MSISDN:42342 usage decreases to: 3 DREF VLR subscr MSISDN:42342 usage decreases to: 2 @@ -748,7 +735,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 @@ -767,8 +753,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_umts_authen_utran: SUCCESS @@ -803,8 +787,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: 0a010809710000000156f00362201039fa2f4e3d523d8619a73b4f65c3e14d21049b36efdf2208059a4f668f6fbe39231027497388b6cb044648f396aa155b95ef2410f64735036e5871319c679f4742a75ea125108704f5ba55f30000d2ee44b22c8ea9192708e229c19e791f2e41 @@ -930,7 +912,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 @@ -973,8 +954,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: 0a010809710000000156f00362201039fa2f4e3d523d8619a73b4f65c3e14d21049b36efdf2208059a4f668f6fbe39231027497388b6cb044648f396aa155b95ef2410f64735036e5871319c679f4742a75ea125108704f5ba55f30000d2ee44b22c8ea9192708e229c19e791f2e41 @@ -1100,7 +1079,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 diff --git a/openbsc/tests/msc_vlr/msc_vlr_tests.c b/openbsc/tests/msc_vlr/msc_vlr_tests.c index e437c7617..d8eada180 100644 --- a/openbsc/tests/msc_vlr/msc_vlr_tests.c +++ b/openbsc/tests/msc_vlr/msc_vlr_tests.c @@ -69,6 +69,7 @@ struct msgb *msgb_from_hex(const char *label, uint16_t size, const char *hex) void dtap_expect_tx(const char *hex) { + /* Has the previously expected dtap been received? */ OSMO_ASSERT(!dtap_tx_expected); if (!hex) return; @@ -251,33 +252,38 @@ void paging_expect_tmsi(uint32_t tmsi) paging_expecting_imsi = NULL; } -/* override, requires '-Wl,--wrap=paging_request' */ -int __real_paging_request(struct gsm_network *network, struct bsc_subscr *sub, - int type, gsm_cbfn *cbfn, void *data); -int __wrap_paging_request(struct gsm_network *network, struct bsc_subscr *sub, - int type, gsm_cbfn *cbfn, void *data) +int _paging_sent(enum ran_type via_ran, const char *imsi, uint32_t tmsi, uint32_t lac) { - log("BTS/BSC sends out paging request to %s for channel type %d", - bsc_subscr_name(sub), type); + log("%s sends out paging request to IMSI %s, TMSI 0x%08x, LAC %u", + ran_type_name(via_ran), imsi, tmsi, lac); OSMO_ASSERT(paging_expecting_imsi || (paging_expecting_tmsi != GSM_RESERVED_TMSI)); if (paging_expecting_imsi) - VERBOSE_ASSERT(strcmp(paging_expecting_imsi, sub->imsi), == 0, "%d"); - if (paging_expecting_tmsi != GSM_RESERVED_TMSI) - VERBOSE_ASSERT(paging_expecting_tmsi, == sub->tmsi, "0x%08x"); + VERBOSE_ASSERT(strcmp(paging_expecting_imsi, imsi), == 0, "%d"); + if (paging_expecting_tmsi != GSM_RESERVED_TMSI) { + VERBOSE_ASSERT(paging_expecting_tmsi, == tmsi, "0x%08x"); + } paging_sent = true; paging_stopped = false; return 1; } -/* override, requires '-Wl,--wrap=paging_request_stop' */ -void __real_paging_request_stop(struct gsm_bts *_bts, - struct vlr_subscr *vsub, - struct gsm_subscriber_connection *conn, - struct msgb *msg); -void __wrap_paging_request_stop(struct gsm_bts *_bts, - struct vlr_subscr *vsub, - struct gsm_subscriber_connection *conn, - struct msgb *msg) +/* override, requires '-Wl,--wrap=iu_page_cs' */ +int __real_iu_page_cs(const char *imsi, const uint32_t *tmsi, uint16_t lac); +int __wrap_iu_page_cs(const char *imsi, const uint32_t *tmsi, uint16_t lac) +{ + return _paging_sent(RAN_UTRAN_IU, imsi, tmsi ? *tmsi : GSM_RESERVED_TMSI, lac); +} + +/* override, requires '-Wl,--wrap=a_page' */ +int __real_a_page(const char *imsi, uint32_t tmsi, uint16_t lac); +int __wrap_a_page(const char *imsi, uint32_t tmsi, uint16_t lac) +{ + return _paging_sent(RAN_GERAN_A, imsi, tmsi, lac); +} + +/* override, requires '-Wl,--wrap=msc_stop_paging' */ +void __real_msc_stop_paging(struct vlr_subscr *vsub); +void __wrap_msc_stop_paging(struct vlr_subscr *vsub) { paging_stopped = true; } @@ -346,6 +352,11 @@ static struct log_info_cat test_categories[] = { .description = "Reference Counting", .enabled = 1, .loglevel = LOGL_DEBUG, }, + [DPAG] = { + .name = "DPAG", + .description = "Paging Subsystem", + .enabled = 1, .loglevel = LOGL_DEBUG, + }, }; static struct log_info info = { @@ -397,13 +408,11 @@ int __wrap_gsup_client_send(struct gsup_client *gsupc, struct msgb *msg) return 0; } -/* override, requires '-Wl,--wrap=gsm0808_submit_dtap' */ -int __real_gsm0808_submit_dtap(struct gsm_subscriber_connection *conn, - struct msgb *msg, int link_id, int allow_sacch); -int __wrap_gsm0808_submit_dtap(struct gsm_subscriber_connection *conn, - struct msgb *msg, int link_id, int allow_sacch) +int _validate_dtap(struct msgb *msg, enum ran_type to_ran) { - btw("DTAP --> MS: %s", osmo_hexdump_nospc(msg->data, msg->len)); + btw("DTAP --%s--> MS: %s", + ran_type_name(to_ran), + osmo_hexdump_nospc(msg->data, msg->len)); OSMO_ASSERT(dtap_tx_expected); if (msg->len != dtap_tx_expected->len @@ -423,6 +432,20 @@ int __wrap_gsm0808_submit_dtap(struct gsm_subscriber_connection *conn, return 0; } +/* override, requires '-Wl,--wrap=iu_tx' */ +int __real_iu_tx(struct msgb *msg, uint8_t sapi); +int __wrap_iu_tx(struct msgb *msg, uint8_t sapi) +{ + return _validate_dtap(msg, RAN_UTRAN_IU); +} + +/* override, requires '-Wl,--wrap=a_tx' */ +int __real_a_tx(struct msgb *msg, uint8_t sapi); +int __wrap_a_tx(struct msgb *msg, uint8_t sapi) +{ + return _validate_dtap(msg, RAN_GERAN_A); +} + static int fake_vlr_tx_lu_acc(void *msc_conn_ref, uint32_t send_tmsi) { struct gsm_subscriber_connection *conn = msc_conn_ref; @@ -662,6 +685,8 @@ int main(int argc, char **argv) net->vlr->ops.tx_auth_rej = fake_vlr_tx_auth_rej; net->vlr->ops.set_ciph_mode = fake_vlr_tx_ciph_mode_cmd; + clear_vlr(); + if (optind >= argc) run_tests(-1); else { diff --git a/openbsc/tests/sms_queue/Makefile.am b/openbsc/tests/sms_queue/Makefile.am index b2266ebb8..011d9fdc9 100644 --- a/openbsc/tests/sms_queue/Makefile.am +++ b/openbsc/tests/sms_queue/Makefile.am @@ -28,8 +28,10 @@ sms_queue_test_LDADD = \ $(top_builddir)/src/libvlr/libvlr.a \ $(top_builddir)/src/libbsc/libbsc.a \ $(top_builddir)/src/libtrau/libtrau.a \ + $(top_builddir)/src/libmgcp/libmgcp.a \ $(top_builddir)/src/libcommon/libcommon.a \ $(top_builddir)/src/libcommon-cs/libcommon-cs.a \ + $(top_builddir)/tests/libiudummy/libiudummy.a \ $(LIBSMPP34_LIBS) \ $(LIBOSMOCORE_LIBS) \ $(LIBOSMOGSM_LIBS) \ -- cgit v1.2.3