laforge has submitted this change. ( https://gerrit.osmocom.org/c/osmo-msc/+/38410?usp=email ) Change subject: vlr: add a logging layer ...................................................................... vlr: add a logging layer To prepare the split off into a separate library, the logging can't use log category from a define. Use the same strategy as all the other osmo libraries and use a global array which is set on initialisation to define the logging categories. Change-Id: I6d87b38d6d7d704c7c7b2c90ad12187e4b953b8b --- M include/osmocom/vlr/vlr.h M src/libmsc/gsm_04_08.c M src/libmsc/msc_net_init.c M src/libvlr/vlr.c M src/libvlr/vlr_access_req_fsm.c M src/libvlr/vlr_access_req_fsm.h M src/libvlr/vlr_auth_fsm.c M src/libvlr/vlr_core.h M src/libvlr/vlr_lu_fsm.c M src/libvlr/vlr_lu_fsm.h M src/libvlr/vlr_sgs.c M src/libvlr/vlr_sgs_fsm.c M src/libvlr/vlr_sgs_fsm.h M tests/msc_vlr/msc_vlr_test_authen_reuse.err M tests/msc_vlr/msc_vlr_test_call.err M tests/msc_vlr/msc_vlr_test_gsm_authen.err M tests/msc_vlr/msc_vlr_test_gsm_ciph.err M tests/msc_vlr/msc_vlr_test_hlr_reject.err M tests/msc_vlr/msc_vlr_test_hlr_timeout.err M tests/msc_vlr/msc_vlr_test_ms_timeout.err M tests/msc_vlr/msc_vlr_test_no_authen.err M tests/msc_vlr/msc_vlr_test_reject_concurrency.err M tests/msc_vlr/msc_vlr_test_rest.err M tests/msc_vlr/msc_vlr_test_ss.err M tests/msc_vlr/msc_vlr_test_umts_authen.err M tests/msc_vlr/msc_vlr_tests.c 26 files changed, 317 insertions(+), 248 deletions(-) Approvals: laforge: Looks good to me, approved Jenkins Builder: Verified pespin: Looks good to me, but someone else must approve diff --git a/include/osmocom/vlr/vlr.h b/include/osmocom/vlr/vlr.h index b2f70d3..4fbf4f9 100644 --- a/include/osmocom/vlr/vlr.h +++ b/include/osmocom/vlr/vlr.h @@ -17,12 +17,6 @@ #include <osmocom/gsupclient/gsup_client.h> #include <osmocom/vlr/vlr_sgs.h> -#define LOGGSUPP(level, gsup, fmt, args...) \ - LOGP(DVLR, level, "GSUP(%s) " fmt, (gsup)->imsi, ## args) - -#define LOGVSUBP(level, vsub, fmt, args...) \ - LOGP(DVLR, level, "SUBSCR(%s) " fmt, vlr_subscr_name(vsub), ## args) - struct log_target; struct osmo_mobile_identity; @@ -498,3 +492,12 @@ enum gsm48_reject_value vlr_gmm_cause_to_reject_cause_domain(enum gsm48_gmm_cause gmm_cause, bool is_cs); enum gsm48_reject_value vlr_reject_causes_cs(enum gsm48_reject_value reject_cause); enum gsm48_reject_value vlr_reject_causes_ps(enum gsm48_reject_value reject_cause); + +/* logging */ +enum osmo_vlr_cat { + OSMO_VLR_LOGC_VLR, + OSMO_VLR_LOGC_SGS, + _OSMO_VLR_LOGC_MAX, +}; + +void osmo_vlr_set_log_cat(enum osmo_vlr_cat logc, int logc_num); diff --git a/src/libmsc/gsm_04_08.c b/src/libmsc/gsm_04_08.c index cf3df48..d9e0b5f 100644 --- a/src/libmsc/gsm_04_08.c +++ b/src/libmsc/gsm_04_08.c @@ -1538,7 +1538,7 @@ static void msc_vlr_subscr_update(struct vlr_subscr *subscr) { struct msub *msub = msub_for_vsub(subscr); - LOGVSUBP(LOGL_NOTICE, subscr, "VLR: update for IMSI=%s (MSISDN=%s)%s\n", + LOG_MSUB(msub, LOGL_NOTICE, "VLR: update for IMSI=%s (MSISDN=%s)%s\n", subscr->imsi, subscr->msisdn, msub ? "" : " (NO CONN!)"); msub_update_id(msub); } diff --git a/src/libmsc/msc_net_init.c b/src/libmsc/msc_net_init.c index ad0c19a..21f68cf 100644 --- a/src/libmsc/msc_net_init.c +++ b/src/libmsc/msc_net_init.c @@ -28,6 +28,7 @@ #include <osmocom/msc/gsm_data.h> #include <osmocom/vlr/vlr.h> +#include <osmocom/msc/debug.h> #include <osmocom/msc/gsup_client_mux.h> #include <osmocom/msc/gsm_04_11_gsup.h> #include <osmocom/msc/gsm_09_11.h> @@ -107,6 +108,8 @@ /* Allocate net->vlr so that the VTY may configure the VLR's data structures */ int msc_vlr_alloc(struct gsm_network *net) { + osmo_vlr_set_log_cat(OSMO_VLR_LOGC_VLR, DVLR); + osmo_vlr_set_log_cat(OSMO_VLR_LOGC_SGS, DSGS); net->vlr = vlr_alloc(net, &msc_vlr_ops); if (!net->vlr) return -ENOMEM; diff --git a/src/libvlr/vlr.c b/src/libvlr/vlr.c index 8a1b470..742660b 100644 --- a/src/libvlr/vlr.c +++ b/src/libvlr/vlr.c @@ -454,7 +454,7 @@ { llist_del(&vsub->list); vlr_stat_item_dec(vsub->vlr, VLR_STAT_SUBSCRIBER_COUNT); - DEBUGP(DVLR, "freeing VLR subscr %s (max total use count was %d)\n", vlr_subscr_name(vsub), + LOGVSUBP(LOGL_DEBUG, vsub, "freeing VLR subscr (max total use count was %d)\n", vsub->max_total_use_count); /* Make sure SGs timer Ts5 is removed */ @@ -478,7 +478,7 @@ for (tried = 0; tried < 100; tried++) { rc = osmo_get_rand_id((uint8_t *) &tmsi, sizeof(tmsi)); if (rc < 0) { - LOGP(DVLR, LOGL_ERROR, "osmo_get_rand_id() failed: %s\n", strerror(-rc)); + LOGVLR(LOGL_ERROR, "osmo_get_rand_id() failed: %s\n", strerror(-rc)); return rc; } @@ -486,7 +486,7 @@ int16_t nri_v; osmo_tmsi_nri_v_limit_by_ranges(&tmsi, vlr->cfg.nri_ranges, vlr->cfg.nri_bitlen); osmo_tmsi_nri_v_get(&nri_v, tmsi, vlr->cfg.nri_bitlen); - LOGP(DVLR, LOGL_DEBUG, "New NRI from range [%s] = 0x%x --> TMSI 0x%08x\n", + LOGVLR(LOGL_DEBUG, "New NRI from range [%s] = 0x%x --> TMSI 0x%08x\n", osmo_nri_ranges_to_str_c(OTC_SELECT, vlr->cfg.nri_ranges), nri_v, tmsi); } @@ -515,8 +515,8 @@ return 0; } - LOGP(DVLR, LOGL_ERROR, "subscr %s: unable to generate valid TMSI" - " after %d tries\n", vlr_subscr_name(vsub), tried); + LOGVSUBP(LOGL_ERROR, vsub, "Unable to generate valid TMSI" + " after %d tries\n", tried); return -1; } @@ -544,7 +544,7 @@ return NULL; vlr_subscr_get_src(vsub, use, file, line); vlr_subscr_set_imsi(vsub, imsi); - LOGP(DVLR, LOGL_INFO, "New subscr, IMSI: %s\n", vsub->imsi); + LOGVLR(LOGL_INFO, "New subscr, IMSI: %s\n", vsub->imsi); if (created) *created = true; return vsub; @@ -574,7 +574,7 @@ return NULL; vlr_subscr_get_src(vsub, use, file, line); vsub->tmsi = tmsi; - LOGP(DVLR, LOGL_INFO, "New subscr, TMSI: 0x%08x\n", vsub->tmsi); + LOGVLR(LOGL_INFO, "New subscr, TMSI: 0x%08x\n", vsub->tmsi); if (created) *created = true; return vsub; @@ -585,10 +585,9 @@ struct vlr_instance *vlr = exists->vlr; int i; int j; - LOGP(DVLR, LOGL_NOTICE, - "There is an existing subscriber for IMSI %s used by %s, replacing with new VLR subscr: %s used by %s\n", + LOGVSUBP(LOGL_NOTICE, vsub, + "There is an existing subscriber for IMSI %s used by %s, replacing with this VLR subscr, used by %s\n", exists->imsi, osmo_use_count_to_str_c(OTC_SELECT, &exists->use_count), - vlr_subscr_name(vsub), osmo_use_count_to_str_c(OTC_SELECT, &vsub->use_count)); /* Take over some state from the previous vsub */ @@ -638,13 +637,13 @@ /* Set the IMSI on the new subscriber, here. */ if (OSMO_STRLCPY_ARRAY(vsub->imsi, imsi) >= sizeof(vsub->imsi)) { - LOGP(DVLR, LOGL_NOTICE, "IMSI was truncated: full IMSI=%s, truncated IMSI=%s\n", + LOGVLR(LOGL_NOTICE, "IMSI was truncated: full IMSI=%s, truncated IMSI=%s\n", imsi, vsub->imsi); /* XXX Set truncated IMSI anyway, we currently cannot return an error from here. */ } vsub->id = atoll(vsub->imsi); - DEBUGP(DVLR, "set IMSI on subscriber; IMSI=%s id=%llu\n", + LOGVLR(LOGL_DEBUG, "set IMSI on subscriber; IMSI=%s id=%llu\n", vsub->imsi, vsub->id); } @@ -653,7 +652,7 @@ if (!vsub) return; OSMO_STRLCPY_ARRAY(vsub->imei, imei); - DEBUGP(DVLR, "set IMEI on subscriber; IMSI=%s IMEI=%s\n", + LOGVLR(LOGL_DEBUG, "set IMEI on subscriber; IMSI=%s IMEI=%s\n", vsub->imsi, vsub->imei); } @@ -662,7 +661,7 @@ if (!vsub) return; OSMO_STRLCPY_ARRAY(vsub->imeisv, imeisv); - DEBUGP(DVLR, "set IMEISV on subscriber; IMSI=%s IMEISV=%s\n", + LOGVLR(LOGL_DEBUG, "set IMEISV on subscriber; IMSI=%s IMEISV=%s\n", vsub->imsi, vsub->imeisv); /* Copy IMEISV to IMEI (additional SV digits get cut off) */ @@ -675,7 +674,7 @@ if (!vsub) return; OSMO_STRLCPY_ARRAY(vsub->msisdn, msisdn); - DEBUGP(DVLR, "set MSISDN on subscriber; IMSI=%s MSISDN=%s\n", + LOGVLR(LOGL_DEBUG, "set MSISDN on subscriber; IMSI=%s MSISDN=%s\n", vsub->imsi, vsub->msisdn); } @@ -690,7 +689,7 @@ } else { vsub->sgs.last_eutran_plmn_present = false; } - DEBUGP(DVLR, "set Last E-UTRAN PLMN ID on subscriber: %s\n", + LOGVLR(LOGL_DEBUG, "set Last E-UTRAN PLMN ID on subscriber: %s\n", vsub->sgs.last_eutran_plmn_present ? osmo_plmn_name(&vsub->sgs.last_eutran_plmn) : "(none)"); @@ -723,7 +722,7 @@ int vlr_subscr_changed(struct vlr_subscr *vsub) { /* FIXME */ - LOGP(DVLR, LOGL_ERROR, "Not implemented: %s\n", __func__); + LOGVLR(LOGL_ERROR, "Not implemented: %s\n", __func__); return 0; } @@ -735,8 +734,8 @@ if (osmo_clock_gettime(CLOCK_MONOTONIC, &now) == 0) { vsub->expire_lu = now.tv_sec + vlr_timer_secs(vsub->vlr, 3212); } else { - LOGP(DVLR, LOGL_ERROR, - "%s: Could not enable Location Update expiry: unable to read current time\n", vlr_subscr_name(vsub)); + LOGVSUBP(LOGL_ERROR, vsub, + "Could not enable Location Update expiry: unable to read current time\n"); /* Disable LU expiry for this subscriber. This subscriber will only be freed after an explicit IMSI detach. */ vsub->expire_lu = VLR_SUBSCRIBER_NO_EXPIRATION; } @@ -757,7 +756,7 @@ goto done; if (osmo_clock_gettime(CLOCK_MONOTONIC, &now) != 0) { - LOGP(DVLR, LOGL_ERROR, "Skipping Location Update expiry: Could not read current time\n"); + LOGVLR(LOGL_ERROR, "Skipping Location Update expiry: Could not read current time\n"); goto done; } @@ -765,7 +764,7 @@ if (vsub->expire_lu == VLR_SUBSCRIBER_NO_EXPIRATION || vsub->expire_lu > now.tv_sec) continue; - LOGP(DVLR, LOGL_DEBUG, "%s: Location Update expired\n", vlr_subscr_name(vsub)); + LOGVLR(LOGL_DEBUG, "%s: Location Update expired\n", vlr_subscr_name(vsub)); vlr_rate_ctr_inc(vlr, VLR_CTR_DETACH_BY_T3212); vlr_subscr_detach(vsub); } @@ -843,20 +842,20 @@ const struct osmo_gsup_message *gsup_msg) { if (OSMO_GSUP_IS_MSGT_REQUEST(gsup_msg->message_type)) { - LOGP(DVLR, LOGL_NOTICE, + LOGVLR(LOGL_NOTICE, "Unknown IMSI %s, discarding GSUP request " "of type 0x%02x\n", gsup_msg->imsi, gsup_msg->message_type); gsup_client_mux_tx_error_reply(vlr->gcm, gsup_msg, GMM_CAUSE_IMSI_UNKNOWN); } else if (OSMO_GSUP_IS_MSGT_ERROR(gsup_msg->message_type)) { - LOGP(DVLR, LOGL_NOTICE, + LOGVLR(LOGL_NOTICE, "Unknown IMSI %s, discarding GSUP error " "of type 0x%02x, cause '%s' (%d)\n", gsup_msg->imsi, gsup_msg->message_type, get_value_string(gsm48_gmm_cause_names, gsup_msg->cause), gsup_msg->cause); } else { - LOGP(DVLR, LOGL_NOTICE, + LOGVLR(LOGL_NOTICE, "Unknown IMSI %s, discarding GSUP response " "of type 0x%02x\n", gsup_msg->imsi, gsup_msg->message_type); @@ -1028,13 +1027,13 @@ gsm48_decode_bcd_number2(vsub->msisdn, sizeof(vsub->msisdn), gsup_msg->msisdn_enc, gsup_msg->msisdn_enc_len, 0); - LOGP(DVLR, LOGL_DEBUG, "IMSI:%s has MSISDN:%s\n", + LOGVLR(LOGL_DEBUG, "IMSI:%s has MSISDN:%s\n", vsub->imsi, vsub->msisdn); } if (gsup_msg->hlr_enc) { if (gsup_msg->hlr_enc_len > sizeof(vsub->hlr.buf)) { - LOGP(DVLR, LOGL_ERROR, "HLR-Number too long (%zu)\n", + LOGVLR(LOGL_ERROR, "HLR-Number too long (%zu)\n", gsup_msg->hlr_enc_len); vsub->hlr.len = 0; } else { @@ -1047,7 +1046,7 @@ if (gsup_msg->pdp_info_compl) { rc = vlr_subscr_pdp_data_clear(vsub); if (rc > 0) - LOGP(DVLR, LOGL_INFO, "Cleared existing PDP info\n"); + LOGVLR(LOGL_INFO, "Cleared existing PDP info\n"); } for (idx = 0; idx < gsup_msg->num_pdp_infos; idx++) { @@ -1689,3 +1688,26 @@ } else target->filter_map &= ~(1 << LOG_FLT_VLR_SUBSCR); } + +int g_vlr_log_cat[_OSMO_VLR_LOGC_MAX]; + +void osmo_vlr_set_log_cat(enum osmo_vlr_cat logc, int logc_num) +{ + if (logc < OSMO_VLR_LOGC_VLR || logc >= _OSMO_VLR_LOGC_MAX) + return; + + g_vlr_log_cat[logc] = logc_num; + + switch (logc) { + case OSMO_VLR_LOGC_VLR: + vlr_auth_fsm.log_subsys = logc_num; + vlr_parq_fsm_set_log_subsys(logc_num); + vlr_lu_fsm_set_log_subsys(logc_num); + break; + case OSMO_VLR_LOGC_SGS: + vlr_sgs_fsm_set_log_subsys(logc_num); + break; + default: + break; + } +} diff --git a/src/libvlr/vlr_access_req_fsm.c b/src/libvlr/vlr_access_req_fsm.c index 08adfbb..e0c223b 100644 --- a/src/libvlr/vlr_access_req_fsm.c +++ b/src/libvlr/vlr_access_req_fsm.c @@ -650,7 +650,7 @@ .num_states = ARRAY_SIZE(proc_arq_vlr_states), .allstate_event_mask = 0, .allstate_action = NULL, - .log_subsys = DVLR, + .log_subsys = DLGLOBAL, .event_names = proc_arq_vlr_event_names, .cleanup = proc_arq_vlr_cleanup, }; @@ -809,3 +809,8 @@ //OSMO_ASSERT(osmo_fsm_register(&upd_loc_child_vlr_fsm) == 0); OSMO_ASSERT(osmo_fsm_register(&proc_arq_vlr_fsm) == 0); } + +void vlr_parq_fsm_set_log_subsys(int log_subsys) +{ + proc_arq_vlr_fsm.log_subsys = log_subsys; +} diff --git a/src/libvlr/vlr_access_req_fsm.h b/src/libvlr/vlr_access_req_fsm.h index 8386da6..2555cf9 100644 --- a/src/libvlr/vlr_access_req_fsm.h +++ b/src/libvlr/vlr_access_req_fsm.h @@ -15,3 +15,5 @@ PR_ARQ_S_WAIT_CECK_CONF, PR_ARQ_S_DONE, }; + +void vlr_parq_fsm_set_log_subsys(int log_level); diff --git a/src/libvlr/vlr_auth_fsm.c b/src/libvlr/vlr_auth_fsm.c index 1182ee2..9f83d0f 100644 --- a/src/libvlr/vlr_auth_fsm.c +++ b/src/libvlr/vlr_auth_fsm.c @@ -610,7 +610,7 @@ .num_states = ARRAY_SIZE(auth_fsm_states), .allstate_event_mask = 0, .allstate_action = NULL, - .log_subsys = DVLR, + .log_subsys = DLGLOBAL, .event_names = fsm_auth_event_names, .cleanup = auth_fsm_cleanup, }; diff --git a/src/libvlr/vlr_core.h b/src/libvlr/vlr_core.h index ec11448..59c2cd1 100644 --- a/src/libvlr/vlr_core.h +++ b/src/libvlr/vlr_core.h @@ -10,3 +10,16 @@ int vlr_subscr_tx_req_check_imei(const struct vlr_subscr *vsub); void vlr_subscr_update_tuples(struct vlr_subscr *vsub, const struct osmo_gsup_message *gsup); + +/* Logging */ +extern int g_vlr_log_cat[_OSMO_VLR_LOGC_MAX]; + +#define LOGVLR(lvl, fmt, args...) LOGP(g_vlr_log_cat[OSMO_VLR_LOGC_VLR], lvl, fmt, ## args) +#define LOGSGS(lvl, fmt, args...) LOGP(g_vlr_log_cat[OSMO_VLR_LOGC_SGS], lvl, fmt, ## args) + +#define LOGGSUPP(level, gsup, fmt, args...) \ + LOGVLR(level, "GSUP(%s) " fmt, (gsup)->imsi, ## args) + +#define LOGVSUBP(level, vsub, fmt, args...) \ + LOGVLR(level, "SUBSCR(%s) " fmt, vlr_subscr_name(vsub), ## args) + diff --git a/src/libvlr/vlr_lu_fsm.c b/src/libvlr/vlr_lu_fsm.c index 5b63afd..9582b2c 100644 --- a/src/libvlr/vlr_lu_fsm.c +++ b/src/libvlr/vlr_lu_fsm.c @@ -150,7 +150,7 @@ .num_states = ARRAY_SIZE(upd_hlr_vlr_states), .allstate_event_mask = 0, .allstate_action = NULL, - .log_subsys = DVLR, + .log_subsys = DLGLOBAL, .event_names = upd_hlr_vlr_event_names, }; @@ -262,7 +262,7 @@ .num_states = ARRAY_SIZE(sub_pres_vlr_states), .allstate_event_mask = 0, .allstate_action = NULL, - .log_subsys = DVLR, + .log_subsys = DLGLOBAL, .event_names = sub_pres_vlr_event_names, }; @@ -601,7 +601,7 @@ .num_states = ARRAY_SIZE(lu_compl_vlr_states), .allstate_event_mask = 0, .allstate_action = NULL, - .log_subsys = DVLR, + .log_subsys = DLGLOBAL, .event_names = lu_compl_vlr_event_names, }; @@ -1492,7 +1492,7 @@ .num_states = ARRAY_SIZE(vlr_lu_fsm_states), .allstate_event_mask = 0, .allstate_action = NULL, - .log_subsys = DVLR, + .log_subsys = DLGLOBAL, .event_names = fsm_lu_event_names, .cleanup = fsm_lu_cleanup, }; @@ -1595,3 +1595,11 @@ OSMO_ASSERT(osmo_fsm_register(&sub_pres_vlr_fsm) == 0); OSMO_ASSERT(osmo_fsm_register(&lu_compl_vlr_fsm) == 0); } + +void vlr_lu_fsm_set_log_subsys(int log_subsys) +{ + vlr_lu_fsm.log_subsys = log_subsys; + upd_hlr_vlr_fsm.log_subsys = log_subsys; + sub_pres_vlr_fsm.log_subsys = log_subsys; + lu_compl_vlr_fsm.log_subsys = log_subsys; +} diff --git a/src/libvlr/vlr_lu_fsm.h b/src/libvlr/vlr_lu_fsm.h index b5c4a5e..86acd58 100644 --- a/src/libvlr/vlr_lu_fsm.h +++ b/src/libvlr/vlr_lu_fsm.h @@ -17,3 +17,4 @@ }; void vlr_lu_fsm_init(void); +void vlr_lu_fsm_set_log_subsys(int log_subsys); diff --git a/src/libvlr/vlr_sgs.c b/src/libvlr/vlr_sgs.c index a0147c0..020e72f 100644 --- a/src/libvlr/vlr_sgs.c +++ b/src/libvlr/vlr_sgs.c @@ -25,6 +25,8 @@ #include <osmocom/msc/debug.h> #include <osmocom/vlr/vlr.h> #include <osmocom/vlr/vlr_sgs.h> + +#include "vlr_core.h" #include "vlr_sgs_fsm.h" const struct value_string sgs_state_timer_names[] = { @@ -51,7 +53,7 @@ OSMO_ASSERT(vlr); - LOGP(DVLR, LOGL_INFO, "dropping all SGs associations.\n"); + LOGSGS(LOGL_INFO, "dropping all SGs associations.\n"); llist_for_each_entry(vsub, &vlr->subscribers, list) { osmo_fsm_inst_dispatch(vsub->sgs_fsm, SGS_UE_E_RX_RESET_FROM_MME, NULL); @@ -85,7 +87,7 @@ vsub = vlr_subscr_find_or_create_by_imsi(vlr, imsi, VSUB_USE_SGS_LU, NULL); if (!vsub) { - LOGP(DSGS, LOGL_ERROR, "VLR subscriber allocation failed\n"); + LOGSGS(LOGL_ERROR, "VLR subscriber allocation failed\n"); return -EINVAL; } @@ -168,7 +170,7 @@ evt = SGS_UE_E_RX_DETACH_IND_FROM_MME; break; default: - LOGP(DSGS, LOGL_ERROR, "(sub %s) invalid SGS IMSI detach type, detaching anyway...\n", + LOGSGS(LOGL_ERROR, "(sub %s) invalid SGS IMSI detach type, detaching anyway...\n", vlr_subscr_msisdn_or_name(vsub)); evt = SGS_UE_E_RX_DETACH_IND_FROM_MME; break; @@ -206,7 +208,7 @@ evt = SGS_UE_E_RX_DETACH_IND_FROM_MME; break; default: - LOGP(DSGS, LOGL_ERROR, "(sub %s) invalid SGS IMSI detach type, detaching anyway...\n", + LOGSGS(LOGL_ERROR, "(sub %s) invalid SGS IMSI detach type, detaching anyway...\n", vlr_subscr_msisdn_or_name(vsub)); evt = SGS_UE_E_RX_DETACH_IND_FROM_MME; break; @@ -253,7 +255,7 @@ /* On the reception of a paging rej the VLR is supposed to stop Ts5, also 3GPP TS 29.118, chapter 5.1.2.4 */ osmo_timer_del(&vsub->sgs.Ts5); - LOGP(DSGS, LOGL_DEBUG, "(sub %s) Paging via SGs interface rejected by MME, %s stopped, cause: %s!\n", + LOGSGS(LOGL_DEBUG, "(sub %s) Paging via SGs interface rejected by MME, %s stopped, cause: %s!\n", vlr_subscr_msisdn_or_name(vsub), vlr_sgs_state_timer_name(SGS_STATE_TS5), sgsap_sgs_cause_name(cause)); osmo_fsm_inst_dispatch(vsub->sgs_fsm, SGS_UE_E_RX_PAGING_FAILURE, &cause); @@ -295,7 +297,7 @@ /* On the reception of an UE unreachable the VLR is supposed to stop * Ts5, also 3GPP TS 29.118, chapter 5.1.2.5 */ osmo_timer_del(&vsub->sgs.Ts5); - LOGP(DSGS, LOGL_DEBUG, + LOGSGS(LOGL_DEBUG, "(sub %s) Paging via SGs interface not possible, UE unreachable, %s stopped, cause: %s\n", vlr_subscr_msisdn_or_name(vsub), vlr_sgs_state_timer_name(SGS_STATE_TS5), sgsap_sgs_cause_name(cause)); @@ -313,7 +315,7 @@ * failed. Other actions may check the status of Ts5 to see if a paging * is still ongoing or not. */ - LOGP(DSGS, LOGL_ERROR, "(sub %s) Paging via SGs interface timed out (%s expired)!\n", + LOGSGS(LOGL_ERROR, "(sub %s) Paging via SGs interface timed out (%s expired)!\n", vlr_subscr_msisdn_or_name(vsub), vlr_sgs_state_timer_name(SGS_STATE_TS5)); /* Balance ref count increment from vlr_sgs_pag() */ diff --git a/src/libvlr/vlr_sgs_fsm.c b/src/libvlr/vlr_sgs_fsm.c index c7a9fdd..e9b2c31 100644 --- a/src/libvlr/vlr_sgs_fsm.c +++ b/src/libvlr/vlr_sgs_fsm.c @@ -355,7 +355,7 @@ S(SGS_UE_E_RX_LU_FROM_A_IU_GS), .allstate_action = sgs_ue_fsm_allstate, .timer_cb = sgs_ue_fsm_timer_cb, - .log_subsys = DSGS, + .log_subsys = DLGLOBAL, .event_names = sgs_ue_fsm_event_names, }; @@ -366,6 +366,12 @@ OSMO_ASSERT(osmo_fsm_register(&sgs_ue_fsm) == 0); } +/*! Set the log level of the fsm */ +void vlr_sgs_fsm_set_log_subsys(int log_level) +{ + sgs_ue_fsm.log_subsys = log_level; +} + /*! Crate SGs FSM in struct vlr_subscr. * \param[in] vsub VLR subscriber for which the SGs FSM should be created. */ void vlr_sgs_fsm_create(struct vlr_subscr *vsub) diff --git a/src/libvlr/vlr_sgs_fsm.h b/src/libvlr/vlr_sgs_fsm.h index 6a09433..f36ed32 100644 --- a/src/libvlr/vlr_sgs_fsm.h +++ b/src/libvlr/vlr_sgs_fsm.h @@ -39,6 +39,7 @@ }; void vlr_sgs_fsm_init(void); +void vlr_sgs_fsm_set_log_subsys(int log_subsys); void vlr_sgs_fsm_create(struct vlr_subscr *vsub); void vlr_sgs_fsm_remove(struct vlr_subscr *vsub); void vlr_sgs_fsm_update_id(struct vlr_subscr *vsub); diff --git a/tests/msc_vlr/msc_vlr_test_authen_reuse.err b/tests/msc_vlr/msc_vlr_test_authen_reuse.err index 1f8afb0..a7222cf 100644 --- a/tests/msc_vlr/msc_vlr_test_authen_reuse.err +++ b/tests/msc_vlr/msc_vlr_test_authen_reuse.err @@ -86,7 +86,7 @@ <-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: 10010809710000000156f00804032443f20a0101 DREF VLR subscr IMSI-901700000010650 + vlr_gsup_rx: now used by 2 (active-conn,vlr_gsup_rx) DVLR IMSI:901700000010650 has MSISDN:42342 -DVLR SUBSCR(IMSI-901700000010650:MSISDN-42342) VLR: update for IMSI=901700000010650 (MSISDN=42342) +DMSC msub(IMSI-901700000010650:MSISDN-42342) VLR: update for IMSI=901700000010650 (MSISDN=42342) GSUP --> HLR: OSMO_GSUP_MSGT_INSERT_DATA_RESULT: 12010809710000000156f00a0101 DREF VLR subscr IMSI-901700000010650:MSISDN-42342 - vlr_gsup_rx: now used by 1 (active-conn) <-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: vlr_gsupc_read_cb() returns 0 @@ -107,7 +107,7 @@ DVLR lu_compl_vlr_fsm(IMSI-901700000010650:MSISDN-42342:GERAN-A:LU){LU_COMPL_VLR_S_INIT}: state_chg to LU_COMPL_VLR_S_WAIT_SUB_PRES DVLR lu_compl_vlr_fsm(IMSI-901700000010650:MSISDN-42342:GERAN-A:LU){LU_COMPL_VLR_S_WAIT_SUB_PRES}: Received Event LU_COMPL_VLR_E_SUB_PRES_COMPL DVLR lu_compl_vlr_fsm(IMSI-901700000010650:MSISDN-42342:GERAN-A:LU){LU_COMPL_VLR_S_WAIT_SUB_PRES}: lu_compl_vlr_new_tmsi() -DVLR SUBSCR(IMSI-901700000010650:MSISDN-42342:TMSInew-0x03020100) VLR: update for IMSI=901700000010650 (MSISDN=42342) +DMSC msub(IMSI-901700000010650:MSISDN-42342:TMSInew-0x03020100) VLR: update for IMSI=901700000010650 (MSISDN=42342) DVLR lu_compl_vlr_fsm(IMSI-901700000010650:MSISDN-42342:GERAN-A:LU){LU_COMPL_VLR_S_WAIT_SUB_PRES}: state_chg to LU_COMPL_VLR_S_WAIT_TMSI_CNF - sending LU Accept for IMSI-901700000010650:MSISDN-42342:TMSInew-0x03020100:GERAN-A:LU, with TMSI 0x03020100 DVLR upd_hlr_vlr_fsm(IMSI-901700000010650:GERAN-A:LU){UPD_HLR_VLR_S_DONE}: Deallocated @@ -149,7 +149,7 @@ DMM msc_a(IMSI-901700000010650:MSISDN-42342:TMSInew-0x03020100:GERAN-A:LU){MSC_A_ST_AUTH_CIPH}: TMSI Reallocation Completed DVLR vlr_lu_fsm(IMSI-901700000010650:MSISDN-42342:TMSInew-0x03020100:GERAN-A:LU){VLR_ULA_S_WAIT_LU_COMPL}: Received Event VLR_ULA_E_NEW_TMSI_ACK DVLR lu_compl_vlr_fsm(IMSI-901700000010650:MSISDN-42342:GERAN-A:LU){LU_COMPL_VLR_S_WAIT_TMSI_CNF}: Received Event LU_COMPL_VLR_E_NEW_TMSI_ACK -DVLR SUBSCR(IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100) VLR: update for IMSI=901700000010650 (MSISDN=42342) +DMSC msub(IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100) VLR: update for IMSI=901700000010650 (MSISDN=42342) DREF VLR subscr IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100 + attached: now used by 2 (active-conn,attached) DVLR lu_compl_vlr_fsm(IMSI-901700000010650:MSISDN-42342:GERAN-A:LU){LU_COMPL_VLR_S_WAIT_TMSI_CNF}: state_chg to LU_COMPL_VLR_S_DONE DVLR vlr_lu_fsm(IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100:GERAN-A:LU){VLR_ULA_S_WAIT_LU_COMPL}: Received Event VLR_ULA_E_LU_COMPL_SUCCESS @@ -500,7 +500,7 @@ DMSC dummy_msc_i(IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100:GERAN-A:NONE){0}: Deferring: will deallocate with msc_a(IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100:GERAN-A:NONE) DMSC msub(IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100) Free DREF VLR subscr IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100 - active-conn: now used by 0 (-) -DVLR freeing VLR subscr IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100 (max total use count was 4) +DVLR SUBSCR(IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100) freeing VLR subscr (max total use count was 4) DMSC msub_fsm{terminating}: Deferring: will deallocate with msc_a(IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100:GERAN-A:NONE) DMSC msc_a(IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100:GERAN-A:NONE){MSC_A_ST_RELEASED}: Deallocated, including all deferred deallocations - msub gone @@ -605,7 +605,7 @@ <-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: 10010809710000000156f00804032443f20a0101 DREF VLR subscr IMSI-901700000010650 + vlr_gsup_rx: now used by 2 (active-conn,vlr_gsup_rx) DVLR IMSI:901700000010650 has MSISDN:42342 -DVLR SUBSCR(IMSI-901700000010650:MSISDN-42342) VLR: update for IMSI=901700000010650 (MSISDN=42342) +DMSC msub(IMSI-901700000010650:MSISDN-42342) VLR: update for IMSI=901700000010650 (MSISDN=42342) GSUP --> HLR: OSMO_GSUP_MSGT_INSERT_DATA_RESULT: 12010809710000000156f00a0101 DREF VLR subscr IMSI-901700000010650:MSISDN-42342 - vlr_gsup_rx: now used by 1 (active-conn) <-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: vlr_gsupc_read_cb() returns 0 @@ -626,7 +626,7 @@ DVLR lu_compl_vlr_fsm(IMSI-901700000010650:MSISDN-42342:UTRAN-Iu:LU){LU_COMPL_VLR_S_INIT}: state_chg to LU_COMPL_VLR_S_WAIT_SUB_PRES DVLR lu_compl_vlr_fsm(IMSI-901700000010650:MSISDN-42342:UTRAN-Iu:LU){LU_COMPL_VLR_S_WAIT_SUB_PRES}: Received Event LU_COMPL_VLR_E_SUB_PRES_COMPL DVLR lu_compl_vlr_fsm(IMSI-901700000010650:MSISDN-42342:UTRAN-Iu:LU){LU_COMPL_VLR_S_WAIT_SUB_PRES}: lu_compl_vlr_new_tmsi() -DVLR SUBSCR(IMSI-901700000010650:MSISDN-42342:TMSInew-0x03020100) VLR: update for IMSI=901700000010650 (MSISDN=42342) +DMSC msub(IMSI-901700000010650:MSISDN-42342:TMSInew-0x03020100) VLR: update for IMSI=901700000010650 (MSISDN=42342) DVLR lu_compl_vlr_fsm(IMSI-901700000010650:MSISDN-42342:UTRAN-Iu:LU){LU_COMPL_VLR_S_WAIT_SUB_PRES}: state_chg to LU_COMPL_VLR_S_WAIT_TMSI_CNF - sending LU Accept for IMSI-901700000010650:MSISDN-42342:TMSInew-0x03020100:UTRAN-Iu:LU, with TMSI 0x03020100 DVLR upd_hlr_vlr_fsm(IMSI-901700000010650:UTRAN-Iu:LU){UPD_HLR_VLR_S_DONE}: Deallocated @@ -668,7 +668,7 @@ DMM msc_a(IMSI-901700000010650:MSISDN-42342:TMSInew-0x03020100:UTRAN-Iu:LU){MSC_A_ST_AUTH_CIPH}: TMSI Reallocation Completed DVLR vlr_lu_fsm(IMSI-901700000010650:MSISDN-42342:TMSInew-0x03020100:UTRAN-Iu:LU){VLR_ULA_S_WAIT_LU_COMPL}: Received Event VLR_ULA_E_NEW_TMSI_ACK DVLR lu_compl_vlr_fsm(IMSI-901700000010650:MSISDN-42342:UTRAN-Iu:LU){LU_COMPL_VLR_S_WAIT_TMSI_CNF}: Received Event LU_COMPL_VLR_E_NEW_TMSI_ACK -DVLR SUBSCR(IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100) VLR: update for IMSI=901700000010650 (MSISDN=42342) +DMSC msub(IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100) VLR: update for IMSI=901700000010650 (MSISDN=42342) DREF VLR subscr IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100 + attached: now used by 2 (active-conn,attached) DVLR lu_compl_vlr_fsm(IMSI-901700000010650:MSISDN-42342:UTRAN-Iu:LU){LU_COMPL_VLR_S_WAIT_TMSI_CNF}: state_chg to LU_COMPL_VLR_S_DONE DVLR vlr_lu_fsm(IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100:UTRAN-Iu:LU){VLR_ULA_S_WAIT_LU_COMPL}: Received Event VLR_ULA_E_LU_COMPL_SUCCESS @@ -1031,7 +1031,7 @@ DMSC dummy_msc_i(IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100:UTRAN-Iu:NONE){0}: Deferring: will deallocate with msc_a(IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100:UTRAN-Iu:NONE) DMSC msub(IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100) Free DREF VLR subscr IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100 - active-conn: now used by 0 (-) -DVLR freeing VLR subscr IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100 (max total use count was 4) +DVLR SUBSCR(IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100) freeing VLR subscr (max total use count was 4) DMSC msub_fsm{terminating}: Deferring: will deallocate with msc_a(IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100:UTRAN-Iu:NONE) DMSC msc_a(IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100:UTRAN-Iu:NONE){MSC_A_ST_RELEASED}: Deallocated, including all deferred deallocations - msub gone @@ -1126,7 +1126,7 @@ <-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: 10010809710000000156f00804032443f20a0101 DREF VLR subscr IMSI-901700000010650 + vlr_gsup_rx: now used by 2 (active-conn,vlr_gsup_rx) DVLR IMSI:901700000010650 has MSISDN:42342 -DVLR SUBSCR(IMSI-901700000010650:MSISDN-42342) VLR: update for IMSI=901700000010650 (MSISDN=42342) +DMSC msub(IMSI-901700000010650:MSISDN-42342) VLR: update for IMSI=901700000010650 (MSISDN=42342) GSUP --> HLR: OSMO_GSUP_MSGT_INSERT_DATA_RESULT: 12010809710000000156f00a0101 DREF VLR subscr IMSI-901700000010650:MSISDN-42342 - vlr_gsup_rx: now used by 1 (active-conn) <-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: vlr_gsupc_read_cb() returns 0 @@ -1147,7 +1147,7 @@ DVLR lu_compl_vlr_fsm(IMSI-901700000010650:MSISDN-42342:GERAN-A:LU){LU_COMPL_VLR_S_INIT}: state_chg to LU_COMPL_VLR_S_WAIT_SUB_PRES DVLR lu_compl_vlr_fsm(IMSI-901700000010650:MSISDN-42342:GERAN-A:LU){LU_COMPL_VLR_S_WAIT_SUB_PRES}: Received Event LU_COMPL_VLR_E_SUB_PRES_COMPL DVLR lu_compl_vlr_fsm(IMSI-901700000010650:MSISDN-42342:GERAN-A:LU){LU_COMPL_VLR_S_WAIT_SUB_PRES}: lu_compl_vlr_new_tmsi() -DVLR SUBSCR(IMSI-901700000010650:MSISDN-42342:TMSInew-0x03020100) VLR: update for IMSI=901700000010650 (MSISDN=42342) +DMSC msub(IMSI-901700000010650:MSISDN-42342:TMSInew-0x03020100) VLR: update for IMSI=901700000010650 (MSISDN=42342) DVLR lu_compl_vlr_fsm(IMSI-901700000010650:MSISDN-42342:GERAN-A:LU){LU_COMPL_VLR_S_WAIT_SUB_PRES}: state_chg to LU_COMPL_VLR_S_WAIT_TMSI_CNF - sending LU Accept for IMSI-901700000010650:MSISDN-42342:TMSInew-0x03020100:GERAN-A:LU, with TMSI 0x03020100 DVLR upd_hlr_vlr_fsm(IMSI-901700000010650:GERAN-A:LU){UPD_HLR_VLR_S_DONE}: Deallocated @@ -1189,7 +1189,7 @@ DMM msc_a(IMSI-901700000010650:MSISDN-42342:TMSInew-0x03020100:GERAN-A:LU){MSC_A_ST_AUTH_CIPH}: TMSI Reallocation Completed DVLR vlr_lu_fsm(IMSI-901700000010650:MSISDN-42342:TMSInew-0x03020100:GERAN-A:LU){VLR_ULA_S_WAIT_LU_COMPL}: Received Event VLR_ULA_E_NEW_TMSI_ACK DVLR lu_compl_vlr_fsm(IMSI-901700000010650:MSISDN-42342:GERAN-A:LU){LU_COMPL_VLR_S_WAIT_TMSI_CNF}: Received Event LU_COMPL_VLR_E_NEW_TMSI_ACK -DVLR SUBSCR(IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100) VLR: update for IMSI=901700000010650 (MSISDN=42342) +DMSC msub(IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100) VLR: update for IMSI=901700000010650 (MSISDN=42342) DREF VLR subscr IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100 + attached: now used by 2 (active-conn,attached) DVLR lu_compl_vlr_fsm(IMSI-901700000010650:MSISDN-42342:GERAN-A:LU){LU_COMPL_VLR_S_WAIT_TMSI_CNF}: state_chg to LU_COMPL_VLR_S_DONE DVLR vlr_lu_fsm(IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100:GERAN-A:LU){VLR_ULA_S_WAIT_LU_COMPL}: Received Event VLR_ULA_E_LU_COMPL_SUCCESS @@ -1646,7 +1646,7 @@ DMSC dummy_msc_i(IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100:GERAN-A:NONE){0}: Deferring: will deallocate with msc_a(IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100:GERAN-A:NONE) DMSC msub(IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100) Free DREF VLR subscr IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100 - active-conn: now used by 0 (-) -DVLR freeing VLR subscr IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100 (max total use count was 4) +DVLR SUBSCR(IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100) freeing VLR subscr (max total use count was 4) DMSC msub_fsm{terminating}: Deferring: will deallocate with msc_a(IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100:GERAN-A:NONE) DMSC msc_a(IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100:GERAN-A:NONE){MSC_A_ST_RELEASED}: Deallocated, including all deferred deallocations - msub gone @@ -1751,7 +1751,7 @@ <-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: 10010809710000000156f00804032443f20a0101 DREF VLR subscr IMSI-901700000010650 + vlr_gsup_rx: now used by 2 (active-conn,vlr_gsup_rx) DVLR IMSI:901700000010650 has MSISDN:42342 -DVLR SUBSCR(IMSI-901700000010650:MSISDN-42342) VLR: update for IMSI=901700000010650 (MSISDN=42342) +DMSC msub(IMSI-901700000010650:MSISDN-42342) VLR: update for IMSI=901700000010650 (MSISDN=42342) GSUP --> HLR: OSMO_GSUP_MSGT_INSERT_DATA_RESULT: 12010809710000000156f00a0101 DREF VLR subscr IMSI-901700000010650:MSISDN-42342 - vlr_gsup_rx: now used by 1 (active-conn) <-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: vlr_gsupc_read_cb() returns 0 @@ -1772,7 +1772,7 @@ DVLR lu_compl_vlr_fsm(IMSI-901700000010650:MSISDN-42342:UTRAN-Iu:LU){LU_COMPL_VLR_S_INIT}: state_chg to LU_COMPL_VLR_S_WAIT_SUB_PRES DVLR lu_compl_vlr_fsm(IMSI-901700000010650:MSISDN-42342:UTRAN-Iu:LU){LU_COMPL_VLR_S_WAIT_SUB_PRES}: Received Event LU_COMPL_VLR_E_SUB_PRES_COMPL DVLR lu_compl_vlr_fsm(IMSI-901700000010650:MSISDN-42342:UTRAN-Iu:LU){LU_COMPL_VLR_S_WAIT_SUB_PRES}: lu_compl_vlr_new_tmsi() -DVLR SUBSCR(IMSI-901700000010650:MSISDN-42342:TMSInew-0x03020100) VLR: update for IMSI=901700000010650 (MSISDN=42342) +DMSC msub(IMSI-901700000010650:MSISDN-42342:TMSInew-0x03020100) VLR: update for IMSI=901700000010650 (MSISDN=42342) DVLR lu_compl_vlr_fsm(IMSI-901700000010650:MSISDN-42342:UTRAN-Iu:LU){LU_COMPL_VLR_S_WAIT_SUB_PRES}: state_chg to LU_COMPL_VLR_S_WAIT_TMSI_CNF - sending LU Accept for IMSI-901700000010650:MSISDN-42342:TMSInew-0x03020100:UTRAN-Iu:LU, with TMSI 0x03020100 DVLR upd_hlr_vlr_fsm(IMSI-901700000010650:UTRAN-Iu:LU){UPD_HLR_VLR_S_DONE}: Deallocated @@ -1814,7 +1814,7 @@ DMM msc_a(IMSI-901700000010650:MSISDN-42342:TMSInew-0x03020100:UTRAN-Iu:LU){MSC_A_ST_AUTH_CIPH}: TMSI Reallocation Completed DVLR vlr_lu_fsm(IMSI-901700000010650:MSISDN-42342:TMSInew-0x03020100:UTRAN-Iu:LU){VLR_ULA_S_WAIT_LU_COMPL}: Received Event VLR_ULA_E_NEW_TMSI_ACK DVLR lu_compl_vlr_fsm(IMSI-901700000010650:MSISDN-42342:UTRAN-Iu:LU){LU_COMPL_VLR_S_WAIT_TMSI_CNF}: Received Event LU_COMPL_VLR_E_NEW_TMSI_ACK -DVLR SUBSCR(IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100) VLR: update for IMSI=901700000010650 (MSISDN=42342) +DMSC msub(IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100) VLR: update for IMSI=901700000010650 (MSISDN=42342) DREF VLR subscr IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100 + attached: now used by 2 (active-conn,attached) DVLR lu_compl_vlr_fsm(IMSI-901700000010650:MSISDN-42342:UTRAN-Iu:LU){LU_COMPL_VLR_S_WAIT_TMSI_CNF}: state_chg to LU_COMPL_VLR_S_DONE DVLR vlr_lu_fsm(IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100:UTRAN-Iu:LU){VLR_ULA_S_WAIT_LU_COMPL}: Received Event VLR_ULA_E_LU_COMPL_SUCCESS @@ -2289,7 +2289,7 @@ DMSC dummy_msc_i(IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100:UTRAN-Iu:NONE){0}: Deferring: will deallocate with msc_a(IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100:UTRAN-Iu:NONE) DMSC msub(IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100) Free DREF VLR subscr IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100 - active-conn: now used by 0 (-) -DVLR freeing VLR subscr IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100 (max total use count was 4) +DVLR SUBSCR(IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100) freeing VLR subscr (max total use count was 4) DMSC msub_fsm{terminating}: Deferring: will deallocate with msc_a(IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100:UTRAN-Iu:NONE) DMSC msc_a(IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100:UTRAN-Iu:NONE){MSC_A_ST_RELEASED}: Deallocated, including all deferred deallocations - msub gone @@ -2384,7 +2384,7 @@ <-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: 10010809710000000156f00804032443f20a0101 DREF VLR subscr IMSI-901700000010650 + vlr_gsup_rx: now used by 2 (active-conn,vlr_gsup_rx) DVLR IMSI:901700000010650 has MSISDN:42342 -DVLR SUBSCR(IMSI-901700000010650:MSISDN-42342) VLR: update for IMSI=901700000010650 (MSISDN=42342) +DMSC msub(IMSI-901700000010650:MSISDN-42342) VLR: update for IMSI=901700000010650 (MSISDN=42342) GSUP --> HLR: OSMO_GSUP_MSGT_INSERT_DATA_RESULT: 12010809710000000156f00a0101 DREF VLR subscr IMSI-901700000010650:MSISDN-42342 - vlr_gsup_rx: now used by 1 (active-conn) <-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: vlr_gsupc_read_cb() returns 0 @@ -2405,7 +2405,7 @@ DVLR lu_compl_vlr_fsm(IMSI-901700000010650:MSISDN-42342:GERAN-A:LU){LU_COMPL_VLR_S_INIT}: state_chg to LU_COMPL_VLR_S_WAIT_SUB_PRES DVLR lu_compl_vlr_fsm(IMSI-901700000010650:MSISDN-42342:GERAN-A:LU){LU_COMPL_VLR_S_WAIT_SUB_PRES}: Received Event LU_COMPL_VLR_E_SUB_PRES_COMPL DVLR lu_compl_vlr_fsm(IMSI-901700000010650:MSISDN-42342:GERAN-A:LU){LU_COMPL_VLR_S_WAIT_SUB_PRES}: lu_compl_vlr_new_tmsi() -DVLR SUBSCR(IMSI-901700000010650:MSISDN-42342:TMSInew-0x03020100) VLR: update for IMSI=901700000010650 (MSISDN=42342) +DMSC msub(IMSI-901700000010650:MSISDN-42342:TMSInew-0x03020100) VLR: update for IMSI=901700000010650 (MSISDN=42342) DVLR lu_compl_vlr_fsm(IMSI-901700000010650:MSISDN-42342:GERAN-A:LU){LU_COMPL_VLR_S_WAIT_SUB_PRES}: state_chg to LU_COMPL_VLR_S_WAIT_TMSI_CNF - sending LU Accept for IMSI-901700000010650:MSISDN-42342:TMSInew-0x03020100:GERAN-A:LU, with TMSI 0x03020100 DVLR upd_hlr_vlr_fsm(IMSI-901700000010650:GERAN-A:LU){UPD_HLR_VLR_S_DONE}: Deallocated @@ -2447,7 +2447,7 @@ DMM msc_a(IMSI-901700000010650:MSISDN-42342:TMSInew-0x03020100:GERAN-A:LU){MSC_A_ST_AUTH_CIPH}: TMSI Reallocation Completed DVLR vlr_lu_fsm(IMSI-901700000010650:MSISDN-42342:TMSInew-0x03020100:GERAN-A:LU){VLR_ULA_S_WAIT_LU_COMPL}: Received Event VLR_ULA_E_NEW_TMSI_ACK DVLR lu_compl_vlr_fsm(IMSI-901700000010650:MSISDN-42342:GERAN-A:LU){LU_COMPL_VLR_S_WAIT_TMSI_CNF}: Received Event LU_COMPL_VLR_E_NEW_TMSI_ACK -DVLR SUBSCR(IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100) VLR: update for IMSI=901700000010650 (MSISDN=42342) +DMSC msub(IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100) VLR: update for IMSI=901700000010650 (MSISDN=42342) DREF VLR subscr IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100 + attached: now used by 2 (active-conn,attached) DVLR lu_compl_vlr_fsm(IMSI-901700000010650:MSISDN-42342:GERAN-A:LU){LU_COMPL_VLR_S_WAIT_TMSI_CNF}: state_chg to LU_COMPL_VLR_S_DONE DVLR vlr_lu_fsm(IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100:GERAN-A:LU){VLR_ULA_S_WAIT_LU_COMPL}: Received Event VLR_ULA_E_LU_COMPL_SUCCESS @@ -2680,7 +2680,7 @@ DMSC dummy_msc_i(IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100:GERAN-A:NONE){0}: Deferring: will deallocate with msc_a(IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100:GERAN-A:NONE) DMSC msub(IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100) Free DREF VLR subscr IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100 - active-conn: now used by 0 (-) -DVLR freeing VLR subscr IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100 (max total use count was 4) +DVLR SUBSCR(IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100) freeing VLR subscr (max total use count was 4) DMSC msub_fsm{terminating}: Deferring: will deallocate with msc_a(IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100:GERAN-A:NONE) DMSC msc_a(IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100:GERAN-A:NONE){MSC_A_ST_RELEASED}: Deallocated, including all deferred deallocations - msub gone @@ -2785,7 +2785,7 @@ <-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: 10010809710000000156f00804032443f20a0101 DREF VLR subscr IMSI-901700000010650 + vlr_gsup_rx: now used by 2 (active-conn,vlr_gsup_rx) DVLR IMSI:901700000010650 has MSISDN:42342 -DVLR SUBSCR(IMSI-901700000010650:MSISDN-42342) VLR: update for IMSI=901700000010650 (MSISDN=42342) +DMSC msub(IMSI-901700000010650:MSISDN-42342) VLR: update for IMSI=901700000010650 (MSISDN=42342) GSUP --> HLR: OSMO_GSUP_MSGT_INSERT_DATA_RESULT: 12010809710000000156f00a0101 DREF VLR subscr IMSI-901700000010650:MSISDN-42342 - vlr_gsup_rx: now used by 1 (active-conn) <-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: vlr_gsupc_read_cb() returns 0 @@ -2806,7 +2806,7 @@ DVLR lu_compl_vlr_fsm(IMSI-901700000010650:MSISDN-42342:UTRAN-Iu:LU){LU_COMPL_VLR_S_INIT}: state_chg to LU_COMPL_VLR_S_WAIT_SUB_PRES DVLR lu_compl_vlr_fsm(IMSI-901700000010650:MSISDN-42342:UTRAN-Iu:LU){LU_COMPL_VLR_S_WAIT_SUB_PRES}: Received Event LU_COMPL_VLR_E_SUB_PRES_COMPL DVLR lu_compl_vlr_fsm(IMSI-901700000010650:MSISDN-42342:UTRAN-Iu:LU){LU_COMPL_VLR_S_WAIT_SUB_PRES}: lu_compl_vlr_new_tmsi() -DVLR SUBSCR(IMSI-901700000010650:MSISDN-42342:TMSInew-0x03020100) VLR: update for IMSI=901700000010650 (MSISDN=42342) +DMSC msub(IMSI-901700000010650:MSISDN-42342:TMSInew-0x03020100) VLR: update for IMSI=901700000010650 (MSISDN=42342) DVLR lu_compl_vlr_fsm(IMSI-901700000010650:MSISDN-42342:UTRAN-Iu:LU){LU_COMPL_VLR_S_WAIT_SUB_PRES}: state_chg to LU_COMPL_VLR_S_WAIT_TMSI_CNF - sending LU Accept for IMSI-901700000010650:MSISDN-42342:TMSInew-0x03020100:UTRAN-Iu:LU, with TMSI 0x03020100 DVLR upd_hlr_vlr_fsm(IMSI-901700000010650:UTRAN-Iu:LU){UPD_HLR_VLR_S_DONE}: Deallocated @@ -2848,7 +2848,7 @@ DMM msc_a(IMSI-901700000010650:MSISDN-42342:TMSInew-0x03020100:UTRAN-Iu:LU){MSC_A_ST_AUTH_CIPH}: TMSI Reallocation Completed DVLR vlr_lu_fsm(IMSI-901700000010650:MSISDN-42342:TMSInew-0x03020100:UTRAN-Iu:LU){VLR_ULA_S_WAIT_LU_COMPL}: Received Event VLR_ULA_E_NEW_TMSI_ACK DVLR lu_compl_vlr_fsm(IMSI-901700000010650:MSISDN-42342:UTRAN-Iu:LU){LU_COMPL_VLR_S_WAIT_TMSI_CNF}: Received Event LU_COMPL_VLR_E_NEW_TMSI_ACK -DVLR SUBSCR(IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100) VLR: update for IMSI=901700000010650 (MSISDN=42342) +DMSC msub(IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100) VLR: update for IMSI=901700000010650 (MSISDN=42342) DREF VLR subscr IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100 + attached: now used by 2 (active-conn,attached) DVLR lu_compl_vlr_fsm(IMSI-901700000010650:MSISDN-42342:UTRAN-Iu:LU){LU_COMPL_VLR_S_WAIT_TMSI_CNF}: state_chg to LU_COMPL_VLR_S_DONE DVLR vlr_lu_fsm(IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100:UTRAN-Iu:LU){VLR_ULA_S_WAIT_LU_COMPL}: Received Event VLR_ULA_E_LU_COMPL_SUCCESS @@ -3087,7 +3087,7 @@ DMSC dummy_msc_i(IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100:UTRAN-Iu:NONE){0}: Deferring: will deallocate with msc_a(IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100:UTRAN-Iu:NONE) DMSC msub(IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100) Free DREF VLR subscr IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100 - active-conn: now used by 0 (-) -DVLR freeing VLR subscr IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100 (max total use count was 4) +DVLR SUBSCR(IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100) freeing VLR subscr (max total use count was 4) DMSC msub_fsm{terminating}: Deferring: will deallocate with msc_a(IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100:UTRAN-Iu:NONE) DMSC msc_a(IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100:UTRAN-Iu:NONE){MSC_A_ST_RELEASED}: Deallocated, including all deferred deallocations - msub gone diff --git a/tests/msc_vlr/msc_vlr_test_call.err b/tests/msc_vlr/msc_vlr_test_call.err index 6fae30e..27852b3 100644 --- a/tests/msc_vlr/msc_vlr_test_call.err +++ b/tests/msc_vlr/msc_vlr_test_call.err @@ -97,7 +97,7 @@ <-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: 10010809710000000156f00804032443f20a0101 DREF VLR subscr IMSI-901700000010650 + vlr_gsup_rx: now used by 2 (active-conn,vlr_gsup_rx) DVLR IMSI:901700000010650 has MSISDN:42342 -DVLR SUBSCR(IMSI-901700000010650:MSISDN-42342) VLR: update for IMSI=901700000010650 (MSISDN=42342) +DMSC msub(IMSI-901700000010650:MSISDN-42342) VLR: update for IMSI=901700000010650 (MSISDN=42342) GSUP --> HLR: OSMO_GSUP_MSGT_INSERT_DATA_RESULT: 12010809710000000156f00a0101 DREF VLR subscr IMSI-901700000010650:MSISDN-42342 - vlr_gsup_rx: now used by 1 (active-conn) <-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: vlr_gsupc_read_cb() returns 0 @@ -118,7 +118,7 @@ DVLR lu_compl_vlr_fsm(IMSI-901700000010650:MSISDN-42342:UTRAN-Iu:LU){LU_COMPL_VLR_S_INIT}: state_chg to LU_COMPL_VLR_S_WAIT_SUB_PRES DVLR lu_compl_vlr_fsm(IMSI-901700000010650:MSISDN-42342:UTRAN-Iu:LU){LU_COMPL_VLR_S_WAIT_SUB_PRES}: Received Event LU_COMPL_VLR_E_SUB_PRES_COMPL DVLR lu_compl_vlr_fsm(IMSI-901700000010650:MSISDN-42342:UTRAN-Iu:LU){LU_COMPL_VLR_S_WAIT_SUB_PRES}: lu_compl_vlr_new_tmsi() -DVLR SUBSCR(IMSI-901700000010650:MSISDN-42342:TMSInew-0x03020100) VLR: update for IMSI=901700000010650 (MSISDN=42342) +DMSC msub(IMSI-901700000010650:MSISDN-42342:TMSInew-0x03020100) VLR: update for IMSI=901700000010650 (MSISDN=42342) DVLR lu_compl_vlr_fsm(IMSI-901700000010650:MSISDN-42342:UTRAN-Iu:LU){LU_COMPL_VLR_S_WAIT_SUB_PRES}: state_chg to LU_COMPL_VLR_S_WAIT_TMSI_CNF - sending LU Accept for IMSI-901700000010650:MSISDN-42342:TMSInew-0x03020100:UTRAN-Iu:LU, with TMSI 0x03020100 DVLR upd_hlr_vlr_fsm(IMSI-901700000010650:UTRAN-Iu:LU){UPD_HLR_VLR_S_DONE}: Deallocated @@ -136,7 +136,7 @@ DMM msc_a(IMSI-901700000010650:MSISDN-42342:TMSInew-0x03020100:UTRAN-Iu:LU){MSC_A_ST_AUTH_CIPH}: TMSI Reallocation Completed DVLR vlr_lu_fsm(IMSI-901700000010650:MSISDN-42342:TMSInew-0x03020100:UTRAN-Iu:LU){VLR_ULA_S_WAIT_LU_COMPL}: Received Event VLR_ULA_E_NEW_TMSI_ACK DVLR lu_compl_vlr_fsm(IMSI-901700000010650:MSISDN-42342:UTRAN-Iu:LU){LU_COMPL_VLR_S_WAIT_TMSI_CNF}: Received Event LU_COMPL_VLR_E_NEW_TMSI_ACK -DVLR SUBSCR(IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100) VLR: update for IMSI=901700000010650 (MSISDN=42342) +DMSC msub(IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100) VLR: update for IMSI=901700000010650 (MSISDN=42342) DREF VLR subscr IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100 + attached: now used by 2 (active-conn,attached) DVLR lu_compl_vlr_fsm(IMSI-901700000010650:MSISDN-42342:UTRAN-Iu:LU){LU_COMPL_VLR_S_WAIT_TMSI_CNF}: state_chg to LU_COMPL_VLR_S_DONE DVLR vlr_lu_fsm(IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100:UTRAN-Iu:LU){VLR_ULA_S_WAIT_LU_COMPL}: Received Event VLR_ULA_E_LU_COMPL_SUCCESS @@ -494,7 +494,7 @@ DMSC msc_a(IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100:UTRAN-Iu:CM_SERVICE_REQ){MSC_A_ST_RELEASED}: Deallocated, including all deferred deallocations - msub gone llist_count(&msub_list) == 0 -DVLR freeing VLR subscr IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100 (max total use count was 4) +DVLR SUBSCR(IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100) freeing VLR subscr (max total use count was 4) ===== test_call_mo: SUCCESS ===== test_call_mt @@ -596,7 +596,7 @@ <-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: 10010809710000000156f00804032443f20a0101 DREF VLR subscr IMSI-901700000010650 + vlr_gsup_rx: now used by 2 (active-conn,vlr_gsup_rx) DVLR IMSI:901700000010650 has MSISDN:42342 -DVLR SUBSCR(IMSI-901700000010650:MSISDN-42342) VLR: update for IMSI=901700000010650 (MSISDN=42342) +DMSC msub(IMSI-901700000010650:MSISDN-42342) VLR: update for IMSI=901700000010650 (MSISDN=42342) GSUP --> HLR: OSMO_GSUP_MSGT_INSERT_DATA_RESULT: 12010809710000000156f00a0101 DREF VLR subscr IMSI-901700000010650:MSISDN-42342 - vlr_gsup_rx: now used by 1 (active-conn) <-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: vlr_gsupc_read_cb() returns 0 @@ -617,7 +617,7 @@ DVLR lu_compl_vlr_fsm(IMSI-901700000010650:MSISDN-42342:UTRAN-Iu:LU){LU_COMPL_VLR_S_INIT}: state_chg to LU_COMPL_VLR_S_WAIT_SUB_PRES DVLR lu_compl_vlr_fsm(IMSI-901700000010650:MSISDN-42342:UTRAN-Iu:LU){LU_COMPL_VLR_S_WAIT_SUB_PRES}: Received Event LU_COMPL_VLR_E_SUB_PRES_COMPL DVLR lu_compl_vlr_fsm(IMSI-901700000010650:MSISDN-42342:UTRAN-Iu:LU){LU_COMPL_VLR_S_WAIT_SUB_PRES}: lu_compl_vlr_new_tmsi() -DVLR SUBSCR(IMSI-901700000010650:MSISDN-42342:TMSInew-0x03020100) VLR: update for IMSI=901700000010650 (MSISDN=42342) +DMSC msub(IMSI-901700000010650:MSISDN-42342:TMSInew-0x03020100) VLR: update for IMSI=901700000010650 (MSISDN=42342) DVLR lu_compl_vlr_fsm(IMSI-901700000010650:MSISDN-42342:UTRAN-Iu:LU){LU_COMPL_VLR_S_WAIT_SUB_PRES}: state_chg to LU_COMPL_VLR_S_WAIT_TMSI_CNF - sending LU Accept for IMSI-901700000010650:MSISDN-42342:TMSInew-0x03020100:UTRAN-Iu:LU, with TMSI 0x03020100 DVLR upd_hlr_vlr_fsm(IMSI-901700000010650:UTRAN-Iu:LU){UPD_HLR_VLR_S_DONE}: Deallocated @@ -635,7 +635,7 @@ DMM msc_a(IMSI-901700000010650:MSISDN-42342:TMSInew-0x03020100:UTRAN-Iu:LU){MSC_A_ST_AUTH_CIPH}: TMSI Reallocation Completed DVLR vlr_lu_fsm(IMSI-901700000010650:MSISDN-42342:TMSInew-0x03020100:UTRAN-Iu:LU){VLR_ULA_S_WAIT_LU_COMPL}: Received Event VLR_ULA_E_NEW_TMSI_ACK DVLR lu_compl_vlr_fsm(IMSI-901700000010650:MSISDN-42342:UTRAN-Iu:LU){LU_COMPL_VLR_S_WAIT_TMSI_CNF}: Received Event LU_COMPL_VLR_E_NEW_TMSI_ACK -DVLR SUBSCR(IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100) VLR: update for IMSI=901700000010650 (MSISDN=42342) +DMSC msub(IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100) VLR: update for IMSI=901700000010650 (MSISDN=42342) DREF VLR subscr IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100 + attached: now used by 2 (active-conn,attached) DVLR lu_compl_vlr_fsm(IMSI-901700000010650:MSISDN-42342:UTRAN-Iu:LU){LU_COMPL_VLR_S_WAIT_TMSI_CNF}: state_chg to LU_COMPL_VLR_S_DONE DVLR vlr_lu_fsm(IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100:UTRAN-Iu:LU){VLR_ULA_S_WAIT_LU_COMPL}: Received Event VLR_ULA_E_LU_COMPL_SUCCESS @@ -1014,7 +1014,7 @@ DMSC msc_a(IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100:UTRAN-Iu:PAGING_RESP){MSC_A_ST_RELEASED}: Deallocated, including all deferred deallocations - msub gone llist_count(&msub_list) == 0 -DVLR freeing VLR subscr IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100 (max total use count was 5) +DVLR SUBSCR(IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100) freeing VLR subscr (max total use count was 5) ===== test_call_mt: SUCCESS ===== test_call_mt2 @@ -1116,7 +1116,7 @@ <-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: 10010809710000000156f00804032443f20a0101 DREF VLR subscr IMSI-901700000010650 + vlr_gsup_rx: now used by 2 (active-conn,vlr_gsup_rx) DVLR IMSI:901700000010650 has MSISDN:42342 -DVLR SUBSCR(IMSI-901700000010650:MSISDN-42342) VLR: update for IMSI=901700000010650 (MSISDN=42342) +DMSC msub(IMSI-901700000010650:MSISDN-42342) VLR: update for IMSI=901700000010650 (MSISDN=42342) GSUP --> HLR: OSMO_GSUP_MSGT_INSERT_DATA_RESULT: 12010809710000000156f00a0101 DREF VLR subscr IMSI-901700000010650:MSISDN-42342 - vlr_gsup_rx: now used by 1 (active-conn) <-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: vlr_gsupc_read_cb() returns 0 @@ -1137,7 +1137,7 @@ DVLR lu_compl_vlr_fsm(IMSI-901700000010650:MSISDN-42342:UTRAN-Iu:LU){LU_COMPL_VLR_S_INIT}: state_chg to LU_COMPL_VLR_S_WAIT_SUB_PRES DVLR lu_compl_vlr_fsm(IMSI-901700000010650:MSISDN-42342:UTRAN-Iu:LU){LU_COMPL_VLR_S_WAIT_SUB_PRES}: Received Event LU_COMPL_VLR_E_SUB_PRES_COMPL DVLR lu_compl_vlr_fsm(IMSI-901700000010650:MSISDN-42342:UTRAN-Iu:LU){LU_COMPL_VLR_S_WAIT_SUB_PRES}: lu_compl_vlr_new_tmsi() -DVLR SUBSCR(IMSI-901700000010650:MSISDN-42342:TMSInew-0x03020100) VLR: update for IMSI=901700000010650 (MSISDN=42342) +DMSC msub(IMSI-901700000010650:MSISDN-42342:TMSInew-0x03020100) VLR: update for IMSI=901700000010650 (MSISDN=42342) DVLR lu_compl_vlr_fsm(IMSI-901700000010650:MSISDN-42342:UTRAN-Iu:LU){LU_COMPL_VLR_S_WAIT_SUB_PRES}: state_chg to LU_COMPL_VLR_S_WAIT_TMSI_CNF - sending LU Accept for IMSI-901700000010650:MSISDN-42342:TMSInew-0x03020100:UTRAN-Iu:LU, with TMSI 0x03020100 DVLR upd_hlr_vlr_fsm(IMSI-901700000010650:UTRAN-Iu:LU){UPD_HLR_VLR_S_DONE}: Deallocated @@ -1155,7 +1155,7 @@ DMM msc_a(IMSI-901700000010650:MSISDN-42342:TMSInew-0x03020100:UTRAN-Iu:LU){MSC_A_ST_AUTH_CIPH}: TMSI Reallocation Completed DVLR vlr_lu_fsm(IMSI-901700000010650:MSISDN-42342:TMSInew-0x03020100:UTRAN-Iu:LU){VLR_ULA_S_WAIT_LU_COMPL}: Received Event VLR_ULA_E_NEW_TMSI_ACK DVLR lu_compl_vlr_fsm(IMSI-901700000010650:MSISDN-42342:UTRAN-Iu:LU){LU_COMPL_VLR_S_WAIT_TMSI_CNF}: Received Event LU_COMPL_VLR_E_NEW_TMSI_ACK -DVLR SUBSCR(IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100) VLR: update for IMSI=901700000010650 (MSISDN=42342) +DMSC msub(IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100) VLR: update for IMSI=901700000010650 (MSISDN=42342) DREF VLR subscr IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100 + attached: now used by 2 (active-conn,attached) DVLR lu_compl_vlr_fsm(IMSI-901700000010650:MSISDN-42342:UTRAN-Iu:LU){LU_COMPL_VLR_S_WAIT_TMSI_CNF}: state_chg to LU_COMPL_VLR_S_DONE DVLR vlr_lu_fsm(IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100:UTRAN-Iu:LU){VLR_ULA_S_WAIT_LU_COMPL}: Received Event VLR_ULA_E_LU_COMPL_SUCCESS @@ -1487,7 +1487,7 @@ - msub gone llist_count(&msub_list) == 0 - Total time passed: 31.000069 s -DVLR freeing VLR subscr IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100 (max total use count was 5) +DVLR SUBSCR(IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100) freeing VLR subscr (max total use count was 5) ===== test_call_mt2: SUCCESS ===== test_call_mo_to_unknown @@ -1589,7 +1589,7 @@ <-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: 10010809710000000156f00804032443f20a0101 DREF VLR subscr IMSI-901700000010650 + vlr_gsup_rx: now used by 2 (active-conn,vlr_gsup_rx) DVLR IMSI:901700000010650 has MSISDN:42342 -DVLR SUBSCR(IMSI-901700000010650:MSISDN-42342) VLR: update for IMSI=901700000010650 (MSISDN=42342) +DMSC msub(IMSI-901700000010650:MSISDN-42342) VLR: update for IMSI=901700000010650 (MSISDN=42342) GSUP --> HLR: OSMO_GSUP_MSGT_INSERT_DATA_RESULT: 12010809710000000156f00a0101 DREF VLR subscr IMSI-901700000010650:MSISDN-42342 - vlr_gsup_rx: now used by 1 (active-conn) <-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: vlr_gsupc_read_cb() returns 0 @@ -1610,7 +1610,7 @@ DVLR lu_compl_vlr_fsm(IMSI-901700000010650:MSISDN-42342:UTRAN-Iu:LU){LU_COMPL_VLR_S_INIT}: state_chg to LU_COMPL_VLR_S_WAIT_SUB_PRES DVLR lu_compl_vlr_fsm(IMSI-901700000010650:MSISDN-42342:UTRAN-Iu:LU){LU_COMPL_VLR_S_WAIT_SUB_PRES}: Received Event LU_COMPL_VLR_E_SUB_PRES_COMPL DVLR lu_compl_vlr_fsm(IMSI-901700000010650:MSISDN-42342:UTRAN-Iu:LU){LU_COMPL_VLR_S_WAIT_SUB_PRES}: lu_compl_vlr_new_tmsi() -DVLR SUBSCR(IMSI-901700000010650:MSISDN-42342:TMSInew-0x03020100) VLR: update for IMSI=901700000010650 (MSISDN=42342) +DMSC msub(IMSI-901700000010650:MSISDN-42342:TMSInew-0x03020100) VLR: update for IMSI=901700000010650 (MSISDN=42342) DVLR lu_compl_vlr_fsm(IMSI-901700000010650:MSISDN-42342:UTRAN-Iu:LU){LU_COMPL_VLR_S_WAIT_SUB_PRES}: state_chg to LU_COMPL_VLR_S_WAIT_TMSI_CNF - sending LU Accept for IMSI-901700000010650:MSISDN-42342:TMSInew-0x03020100:UTRAN-Iu:LU, with TMSI 0x03020100 DVLR upd_hlr_vlr_fsm(IMSI-901700000010650:UTRAN-Iu:LU){UPD_HLR_VLR_S_DONE}: Deallocated @@ -1628,7 +1628,7 @@ DMM msc_a(IMSI-901700000010650:MSISDN-42342:TMSInew-0x03020100:UTRAN-Iu:LU){MSC_A_ST_AUTH_CIPH}: TMSI Reallocation Completed DVLR vlr_lu_fsm(IMSI-901700000010650:MSISDN-42342:TMSInew-0x03020100:UTRAN-Iu:LU){VLR_ULA_S_WAIT_LU_COMPL}: Received Event VLR_ULA_E_NEW_TMSI_ACK DVLR lu_compl_vlr_fsm(IMSI-901700000010650:MSISDN-42342:UTRAN-Iu:LU){LU_COMPL_VLR_S_WAIT_TMSI_CNF}: Received Event LU_COMPL_VLR_E_NEW_TMSI_ACK -DVLR SUBSCR(IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100) VLR: update for IMSI=901700000010650 (MSISDN=42342) +DMSC msub(IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100) VLR: update for IMSI=901700000010650 (MSISDN=42342) DREF VLR subscr IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100 + attached: now used by 2 (active-conn,attached) DVLR lu_compl_vlr_fsm(IMSI-901700000010650:MSISDN-42342:UTRAN-Iu:LU){LU_COMPL_VLR_S_WAIT_TMSI_CNF}: state_chg to LU_COMPL_VLR_S_DONE DVLR vlr_lu_fsm(IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100:UTRAN-Iu:LU){VLR_ULA_S_WAIT_LU_COMPL}: Received Event VLR_ULA_E_LU_COMPL_SUCCESS @@ -1941,7 +1941,7 @@ DMSC msc_a(IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100:UTRAN-Iu:CM_SERVICE_REQ){MSC_A_ST_RELEASED}: Deallocated, including all deferred deallocations - msub gone llist_count(&msub_list) == 0 -DVLR freeing VLR subscr IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100 (max total use count was 4) +DVLR SUBSCR(IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100) freeing VLR subscr (max total use count was 4) ===== test_call_mo_to_unknown: SUCCESS ===== test_call_mo_to_unknown_timeout @@ -2043,7 +2043,7 @@ <-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: 10010809710000000156f00804032443f20a0101 DREF VLR subscr IMSI-901700000010650 + vlr_gsup_rx: now used by 2 (active-conn,vlr_gsup_rx) DVLR IMSI:901700000010650 has MSISDN:42342 -DVLR SUBSCR(IMSI-901700000010650:MSISDN-42342) VLR: update for IMSI=901700000010650 (MSISDN=42342) +DMSC msub(IMSI-901700000010650:MSISDN-42342) VLR: update for IMSI=901700000010650 (MSISDN=42342) GSUP --> HLR: OSMO_GSUP_MSGT_INSERT_DATA_RESULT: 12010809710000000156f00a0101 DREF VLR subscr IMSI-901700000010650:MSISDN-42342 - vlr_gsup_rx: now used by 1 (active-conn) <-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: vlr_gsupc_read_cb() returns 0 @@ -2064,7 +2064,7 @@ DVLR lu_compl_vlr_fsm(IMSI-901700000010650:MSISDN-42342:UTRAN-Iu:LU){LU_COMPL_VLR_S_INIT}: state_chg to LU_COMPL_VLR_S_WAIT_SUB_PRES DVLR lu_compl_vlr_fsm(IMSI-901700000010650:MSISDN-42342:UTRAN-Iu:LU){LU_COMPL_VLR_S_WAIT_SUB_PRES}: Received Event LU_COMPL_VLR_E_SUB_PRES_COMPL DVLR lu_compl_vlr_fsm(IMSI-901700000010650:MSISDN-42342:UTRAN-Iu:LU){LU_COMPL_VLR_S_WAIT_SUB_PRES}: lu_compl_vlr_new_tmsi() -DVLR SUBSCR(IMSI-901700000010650:MSISDN-42342:TMSInew-0x03020100) VLR: update for IMSI=901700000010650 (MSISDN=42342) +DMSC msub(IMSI-901700000010650:MSISDN-42342:TMSInew-0x03020100) VLR: update for IMSI=901700000010650 (MSISDN=42342) DVLR lu_compl_vlr_fsm(IMSI-901700000010650:MSISDN-42342:UTRAN-Iu:LU){LU_COMPL_VLR_S_WAIT_SUB_PRES}: state_chg to LU_COMPL_VLR_S_WAIT_TMSI_CNF - sending LU Accept for IMSI-901700000010650:MSISDN-42342:TMSInew-0x03020100:UTRAN-Iu:LU, with TMSI 0x03020100 DVLR upd_hlr_vlr_fsm(IMSI-901700000010650:UTRAN-Iu:LU){UPD_HLR_VLR_S_DONE}: Deallocated @@ -2082,7 +2082,7 @@ DMM msc_a(IMSI-901700000010650:MSISDN-42342:TMSInew-0x03020100:UTRAN-Iu:LU){MSC_A_ST_AUTH_CIPH}: TMSI Reallocation Completed DVLR vlr_lu_fsm(IMSI-901700000010650:MSISDN-42342:TMSInew-0x03020100:UTRAN-Iu:LU){VLR_ULA_S_WAIT_LU_COMPL}: Received Event VLR_ULA_E_NEW_TMSI_ACK DVLR lu_compl_vlr_fsm(IMSI-901700000010650:MSISDN-42342:UTRAN-Iu:LU){LU_COMPL_VLR_S_WAIT_TMSI_CNF}: Received Event LU_COMPL_VLR_E_NEW_TMSI_ACK -DVLR SUBSCR(IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100) VLR: update for IMSI=901700000010650 (MSISDN=42342) +DMSC msub(IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100) VLR: update for IMSI=901700000010650 (MSISDN=42342) DREF VLR subscr IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100 + attached: now used by 2 (active-conn,attached) DVLR lu_compl_vlr_fsm(IMSI-901700000010650:MSISDN-42342:UTRAN-Iu:LU){LU_COMPL_VLR_S_WAIT_TMSI_CNF}: state_chg to LU_COMPL_VLR_S_DONE DVLR vlr_lu_fsm(IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100:UTRAN-Iu:LU){VLR_ULA_S_WAIT_LU_COMPL}: Received Event VLR_ULA_E_LU_COMPL_SUCCESS @@ -2392,7 +2392,7 @@ DMSC msc_a(IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100:UTRAN-Iu:CM_SERVICE_REQ){MSC_A_ST_RELEASED}: Deallocated, including all deferred deallocations - msub gone llist_count(&msub_list) == 0 -DVLR freeing VLR subscr IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100 (max total use count was 4) +DVLR SUBSCR(IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100) freeing VLR subscr (max total use count was 4) ===== test_call_mo_to_unknown_timeout: SUCCESS ===== test_codecs @@ -2445,7 +2445,7 @@ <-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: 10010809710000000156f00804036470f10a0101 DREF VLR subscr IMSI-901700000010650 + vlr_gsup_rx: now used by 2 (active-conn,vlr_gsup_rx) DVLR IMSI:901700000010650 has MSISDN:46071 -DVLR SUBSCR(IMSI-901700000010650:MSISDN-46071) VLR: update for IMSI=901700000010650 (MSISDN=46071) +DMSC msub(IMSI-901700000010650:MSISDN-46071) VLR: update for IMSI=901700000010650 (MSISDN=46071) GSUP --> HLR: OSMO_GSUP_MSGT_INSERT_DATA_RESULT: 12010809710000000156f00a0101 DREF VLR subscr IMSI-901700000010650:MSISDN-46071 - vlr_gsup_rx: now used by 1 (active-conn) <-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: vlr_gsupc_read_cb() returns 0 @@ -6902,6 +6902,6 @@ - ======================== SUCCESS: MT call: AMR picked by both MO and MT, but MO assigns a different payload type number llist_count(&msub_list) == 0 -DVLR freeing VLR subscr IMSI-901700000010650:MSISDN-46071 (max total use count was 5) +DVLR SUBSCR(IMSI-901700000010650:MSISDN-46071) freeing VLR subscr (max total use count was 5) ===== test_codecs: SUCCESS diff --git a/tests/msc_vlr/msc_vlr_test_gsm_authen.err b/tests/msc_vlr/msc_vlr_test_gsm_authen.err index 44c0a53..35bcb74 100644 --- a/tests/msc_vlr/msc_vlr_test_gsm_authen.err +++ b/tests/msc_vlr/msc_vlr_test_gsm_authen.err @@ -110,7 +110,7 @@ <-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: 10010809710000004026f00804036470f10a0101 DREF VLR subscr IMSI-901700000004620 + vlr_gsup_rx: now used by 2 (active-conn,vlr_gsup_rx) DVLR IMSI:901700000004620 has MSISDN:46071 -DVLR SUBSCR(IMSI-901700000004620:MSISDN-46071) VLR: update for IMSI=901700000004620 (MSISDN=46071) +DMSC msub(IMSI-901700000004620:MSISDN-46071) VLR: update for IMSI=901700000004620 (MSISDN=46071) GSUP --> HLR: OSMO_GSUP_MSGT_INSERT_DATA_RESULT: 12010809710000004026f00a0101 DREF VLR subscr IMSI-901700000004620:MSISDN-46071 - vlr_gsup_rx: now used by 1 (active-conn) <-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: vlr_gsupc_read_cb() returns 0 @@ -580,7 +580,7 @@ DMSC dummy_msc_i(IMSI-901700000004620:MSISDN-46071:GERAN-A:NONE){0}: Deferring: will deallocate with msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:NONE) DMSC msub(IMSI-901700000004620:MSISDN-46071) Free DREF VLR subscr IMSI-901700000004620:MSISDN-46071 - active-conn: now used by 0 (-) -DVLR freeing VLR subscr IMSI-901700000004620:MSISDN-46071 (max total use count was 6) +DVLR SUBSCR(IMSI-901700000004620:MSISDN-46071) freeing VLR subscr (max total use count was 6) DMSC msub_fsm{terminating}: Deferring: will deallocate with msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:NONE) DMSC msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:NONE){MSC_A_ST_RELEASED}: Deallocated, including all deferred deallocations - msub gone @@ -699,7 +699,7 @@ <-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: 10010809710000004026f00804036470f10a0101 DREF VLR subscr IMSI-901700000004620 + vlr_gsup_rx: now used by 2 (active-conn,vlr_gsup_rx) DVLR IMSI:901700000004620 has MSISDN:46071 -DVLR SUBSCR(IMSI-901700000004620:MSISDN-46071) VLR: update for IMSI=901700000004620 (MSISDN=46071) +DMSC msub(IMSI-901700000004620:MSISDN-46071) VLR: update for IMSI=901700000004620 (MSISDN=46071) GSUP --> HLR: OSMO_GSUP_MSGT_INSERT_DATA_RESULT: 12010809710000004026f00a0101 DREF VLR subscr IMSI-901700000004620:MSISDN-46071 - vlr_gsup_rx: now used by 1 (active-conn) <-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: vlr_gsupc_read_cb() returns 0 @@ -720,7 +720,7 @@ DVLR lu_compl_vlr_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){LU_COMPL_VLR_S_INIT}: state_chg to LU_COMPL_VLR_S_WAIT_SUB_PRES DVLR lu_compl_vlr_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){LU_COMPL_VLR_S_WAIT_SUB_PRES}: Received Event LU_COMPL_VLR_E_SUB_PRES_COMPL DVLR lu_compl_vlr_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){LU_COMPL_VLR_S_WAIT_SUB_PRES}: lu_compl_vlr_new_tmsi() -DVLR SUBSCR(IMSI-901700000004620:MSISDN-46071:TMSInew-0x03020100) VLR: update for IMSI=901700000004620 (MSISDN=46071) +DMSC msub(IMSI-901700000004620:MSISDN-46071:TMSInew-0x03020100) VLR: update for IMSI=901700000004620 (MSISDN=46071) DVLR lu_compl_vlr_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){LU_COMPL_VLR_S_WAIT_SUB_PRES}: state_chg to LU_COMPL_VLR_S_WAIT_TMSI_CNF - sending LU Accept for IMSI-901700000004620:MSISDN-46071:TMSInew-0x03020100:GERAN-A:LU, with TMSI 0x03020100 DVLR upd_hlr_vlr_fsm(IMSI-901700000004620:GERAN-A:LU){UPD_HLR_VLR_S_DONE}: Deallocated @@ -762,7 +762,7 @@ DMM msc_a(IMSI-901700000004620:MSISDN-46071:TMSInew-0x03020100:GERAN-A:LU){MSC_A_ST_AUTH_CIPH}: TMSI Reallocation Completed DVLR vlr_lu_fsm(IMSI-901700000004620:MSISDN-46071:TMSInew-0x03020100:GERAN-A:LU){VLR_ULA_S_WAIT_LU_COMPL}: Received Event VLR_ULA_E_NEW_TMSI_ACK DVLR lu_compl_vlr_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){LU_COMPL_VLR_S_WAIT_TMSI_CNF}: Received Event LU_COMPL_VLR_E_NEW_TMSI_ACK -DVLR SUBSCR(IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100) VLR: update for IMSI=901700000004620 (MSISDN=46071) +DMSC msub(IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100) VLR: update for IMSI=901700000004620 (MSISDN=46071) DREF VLR subscr IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100 + attached: now used by 2 (active-conn,attached) DVLR lu_compl_vlr_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){LU_COMPL_VLR_S_WAIT_TMSI_CNF}: state_chg to LU_COMPL_VLR_S_DONE DVLR vlr_lu_fsm(IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100:GERAN-A:LU){VLR_ULA_S_WAIT_LU_COMPL}: Received Event VLR_ULA_E_LU_COMPL_SUCCESS @@ -1239,7 +1239,7 @@ <-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: 10010809710000004026f00804036470f10a0101 DREF VLR subscr IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100 + vlr_gsup_rx: now used by 3 (attached,active-conn,vlr_gsup_rx) DVLR IMSI:901700000004620 has MSISDN:46071 -DVLR SUBSCR(IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100) VLR: update for IMSI=901700000004620 (MSISDN=46071) +DMSC msub(IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100) VLR: update for IMSI=901700000004620 (MSISDN=46071) GSUP --> HLR: OSMO_GSUP_MSGT_INSERT_DATA_RESULT: 12010809710000004026f00a0101 DREF VLR subscr IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100 - vlr_gsup_rx: now used by 2 (attached,active-conn) <-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: vlr_gsupc_read_cb() returns 0 @@ -1260,7 +1260,7 @@ DVLR lu_compl_vlr_fsm(IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100:GERAN-A:LU){LU_COMPL_VLR_S_INIT}: state_chg to LU_COMPL_VLR_S_WAIT_SUB_PRES DVLR lu_compl_vlr_fsm(IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100:GERAN-A:LU){LU_COMPL_VLR_S_WAIT_SUB_PRES}: Received Event LU_COMPL_VLR_E_SUB_PRES_COMPL DVLR lu_compl_vlr_fsm(IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100:GERAN-A:LU){LU_COMPL_VLR_S_WAIT_SUB_PRES}: lu_compl_vlr_new_tmsi() -DVLR SUBSCR(IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100:TMSInew-0x07060504) VLR: update for IMSI=901700000004620 (MSISDN=46071) +DMSC msub(IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100:TMSInew-0x07060504) VLR: update for IMSI=901700000004620 (MSISDN=46071) DVLR lu_compl_vlr_fsm(IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100:GERAN-A:LU){LU_COMPL_VLR_S_WAIT_SUB_PRES}: state_chg to LU_COMPL_VLR_S_WAIT_TMSI_CNF - sending LU Accept for IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100:TMSInew-0x07060504:GERAN-A:LU, with TMSI 0x07060504 DVLR upd_hlr_vlr_fsm(IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100:GERAN-A:LU){UPD_HLR_VLR_S_DONE}: Deallocated @@ -1302,7 +1302,7 @@ DMM msc_a(IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100:TMSInew-0x07060504:GERAN-A:LU){MSC_A_ST_AUTH_CIPH}: TMSI Reallocation Completed DVLR vlr_lu_fsm(IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100:TMSInew-0x07060504:GERAN-A:LU){VLR_ULA_S_WAIT_LU_COMPL}: Received Event VLR_ULA_E_NEW_TMSI_ACK DVLR lu_compl_vlr_fsm(IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100:GERAN-A:LU){LU_COMPL_VLR_S_WAIT_TMSI_CNF}: Received Event LU_COMPL_VLR_E_NEW_TMSI_ACK -DVLR SUBSCR(IMSI-901700000004620:MSISDN-46071:TMSI-0x07060504) VLR: update for IMSI=901700000004620 (MSISDN=46071) +DMSC msub(IMSI-901700000004620:MSISDN-46071:TMSI-0x07060504) VLR: update for IMSI=901700000004620 (MSISDN=46071) DVLR lu_compl_vlr_fsm(IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100:GERAN-A:LU){LU_COMPL_VLR_S_WAIT_TMSI_CNF}: state_chg to LU_COMPL_VLR_S_DONE DVLR vlr_lu_fsm(IMSI-901700000004620:MSISDN-46071:TMSI-0x07060504:GERAN-A:LU){VLR_ULA_S_WAIT_LU_COMPL}: Received Event VLR_ULA_E_LU_COMPL_SUCCESS DVLR lu_compl_vlr_fsm(IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100:GERAN-A:LU){LU_COMPL_VLR_S_DONE}: Terminating (cause = OSMO_FSM_TERM_PARENT) @@ -1411,7 +1411,7 @@ DMSC dummy_msc_i(IMSI-901700000004620:MSISDN-46071:TMSI-0x07060504:GERAN-A:NONE){0}: Deferring: will deallocate with msc_a(IMSI-901700000004620:MSISDN-46071:TMSI-0x07060504:GERAN-A:NONE) DMSC msub(IMSI-901700000004620:MSISDN-46071:TMSI-0x07060504) Free DREF VLR subscr IMSI-901700000004620:MSISDN-46071:TMSI-0x07060504 - active-conn: now used by 0 (-) -DVLR freeing VLR subscr IMSI-901700000004620:MSISDN-46071:TMSI-0x07060504 (max total use count was 6) +DVLR SUBSCR(IMSI-901700000004620:MSISDN-46071:TMSI-0x07060504) freeing VLR subscr (max total use count was 6) DMSC msub_fsm{terminating}: Deferring: will deallocate with msc_a(IMSI-901700000004620:MSISDN-46071:TMSI-0x07060504:GERAN-A:NONE) DMSC msc_a(IMSI-901700000004620:MSISDN-46071:TMSI-0x07060504:GERAN-A:NONE){MSC_A_ST_RELEASED}: Deallocated, including all deferred deallocations - msub gone @@ -1530,7 +1530,7 @@ <-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: 10010809710000004026f00804036470f10a0101 DREF VLR subscr IMSI-901700000004620 + vlr_gsup_rx: now used by 2 (active-conn,vlr_gsup_rx) DVLR IMSI:901700000004620 has MSISDN:46071 -DVLR SUBSCR(IMSI-901700000004620:MSISDN-46071) VLR: update for IMSI=901700000004620 (MSISDN=46071) +DMSC msub(IMSI-901700000004620:MSISDN-46071) VLR: update for IMSI=901700000004620 (MSISDN=46071) GSUP --> HLR: OSMO_GSUP_MSGT_INSERT_DATA_RESULT: 12010809710000004026f00a0101 DREF VLR subscr IMSI-901700000004620:MSISDN-46071 - vlr_gsup_rx: now used by 1 (active-conn) <-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: vlr_gsupc_read_cb() returns 0 @@ -1724,7 +1724,7 @@ DMSC dummy_msc_i(IMSI-901700000004620:MSISDN-46071:GERAN-A:NONE){0}: Deferring: will deallocate with msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:NONE) DMSC msub(IMSI-901700000004620:MSISDN-46071) Free DREF VLR subscr IMSI-901700000004620:MSISDN-46071 - active-conn: now used by 0 (-) -DVLR freeing VLR subscr IMSI-901700000004620:MSISDN-46071 (max total use count was 5) +DVLR SUBSCR(IMSI-901700000004620:MSISDN-46071) freeing VLR subscr (max total use count was 5) DMSC msub_fsm{terminating}: Deferring: will deallocate with msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:NONE) DMSC msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:NONE){MSC_A_ST_RELEASED}: Deallocated, including all deferred deallocations - msub gone @@ -1843,7 +1843,7 @@ <-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: 10010809710000004026f00804036470f10a0101 DREF VLR subscr IMSI-901700000004620 + vlr_gsup_rx: now used by 2 (active-conn,vlr_gsup_rx) DVLR IMSI:901700000004620 has MSISDN:46071 -DVLR SUBSCR(IMSI-901700000004620:MSISDN-46071) VLR: update for IMSI=901700000004620 (MSISDN=46071) +DMSC msub(IMSI-901700000004620:MSISDN-46071) VLR: update for IMSI=901700000004620 (MSISDN=46071) GSUP --> HLR: OSMO_GSUP_MSGT_INSERT_DATA_RESULT: 12010809710000004026f00a0101 DREF VLR subscr IMSI-901700000004620:MSISDN-46071 - vlr_gsup_rx: now used by 1 (active-conn) <-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: vlr_gsupc_read_cb() returns 0 @@ -1989,7 +1989,7 @@ DMSC dummy_msc_i(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){0}: Deferring: will deallocate with msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU) DMSC msub(IMSI-901700000004620:MSISDN-46071) Free DREF VLR subscr IMSI-901700000004620:MSISDN-46071 - active-conn: now used by 0 (-) -DVLR freeing VLR subscr IMSI-901700000004620:MSISDN-46071 (max total use count was 4) +DVLR SUBSCR(IMSI-901700000004620:MSISDN-46071) freeing VLR subscr (max total use count was 4) DMSC msub_fsm{terminating}: Deferring: will deallocate with msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU) DMSC msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){MSC_A_ST_RELEASED}: Deallocated, including all deferred deallocations - msub gone @@ -2108,7 +2108,7 @@ <-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: 10010809710000004026f00804036470f10a0101 DREF VLR subscr IMSI-901700000004620 + vlr_gsup_rx: now used by 2 (active-conn,vlr_gsup_rx) DVLR IMSI:901700000004620 has MSISDN:46071 -DVLR SUBSCR(IMSI-901700000004620:MSISDN-46071) VLR: update for IMSI=901700000004620 (MSISDN=46071) +DMSC msub(IMSI-901700000004620:MSISDN-46071) VLR: update for IMSI=901700000004620 (MSISDN=46071) GSUP --> HLR: OSMO_GSUP_MSGT_INSERT_DATA_RESULT: 12010809710000004026f00a0101 DREF VLR subscr IMSI-901700000004620:MSISDN-46071 - vlr_gsup_rx: now used by 1 (active-conn) <-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: vlr_gsupc_read_cb() returns 0 @@ -2255,7 +2255,7 @@ DMSC dummy_msc_i(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){0}: Deferring: will deallocate with msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU) DMSC msub(IMSI-901700000004620:MSISDN-46071) Free DREF VLR subscr IMSI-901700000004620:MSISDN-46071 - active-conn: now used by 0 (-) -DVLR freeing VLR subscr IMSI-901700000004620:MSISDN-46071 (max total use count was 4) +DVLR SUBSCR(IMSI-901700000004620:MSISDN-46071) freeing VLR subscr (max total use count was 4) DMSC msub_fsm{terminating}: Deferring: will deallocate with msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU) DMSC msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){MSC_A_ST_RELEASED}: Deallocated, including all deferred deallocations - msub gone @@ -2374,7 +2374,7 @@ <-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: 10010809710000004026f00804036470f10a0101 DREF VLR subscr IMSI-901700000004620 + vlr_gsup_rx: now used by 2 (active-conn,vlr_gsup_rx) DVLR IMSI:901700000004620 has MSISDN:46071 -DVLR SUBSCR(IMSI-901700000004620:MSISDN-46071) VLR: update for IMSI=901700000004620 (MSISDN=46071) +DMSC msub(IMSI-901700000004620:MSISDN-46071) VLR: update for IMSI=901700000004620 (MSISDN=46071) GSUP --> HLR: OSMO_GSUP_MSGT_INSERT_DATA_RESULT: 12010809710000004026f00a0101 DREF VLR subscr IMSI-901700000004620:MSISDN-46071 - vlr_gsup_rx: now used by 1 (active-conn) <-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: vlr_gsupc_read_cb() returns 0 @@ -2460,7 +2460,7 @@ DVLR vlr_lu_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){VLR_ULA_S_WAIT_LU_COMPL}: Received Event VLR_ULA_E_HLR_IMEI_ACK DVLR lu_compl_vlr_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){LU_COMPL_VLR_S_WAIT_IMEI_TMSI}: Received Event LU_COMPL_VLR_E_IMEI_CHECK_ACK DVLR lu_compl_vlr_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){LU_COMPL_VLR_S_WAIT_IMEI_TMSI}: lu_compl_vlr_new_tmsi() -DVLR SUBSCR(IMSI-901700000004620:MSISDN-46071:TMSInew-0x03020100) VLR: update for IMSI=901700000004620 (MSISDN=46071) +DMSC msub(IMSI-901700000004620:MSISDN-46071:TMSInew-0x03020100) VLR: update for IMSI=901700000004620 (MSISDN=46071) DVLR lu_compl_vlr_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){LU_COMPL_VLR_S_WAIT_IMEI_TMSI}: state_chg to LU_COMPL_VLR_S_WAIT_TMSI_CNF - sending LU Accept for IMSI-901700000004620:MSISDN-46071:TMSInew-0x03020100:GERAN-A:LU, with TMSI 0x03020100 DREF VLR subscr IMSI-901700000004620:MSISDN-46071:TMSInew-0x03020100 - vlr_gsup_rx: now used by 1 (active-conn) @@ -2501,7 +2501,7 @@ DMM msc_a(IMSI-901700000004620:MSISDN-46071:TMSInew-0x03020100:GERAN-A:LU){MSC_A_ST_AUTH_CIPH}: TMSI Reallocation Completed DVLR vlr_lu_fsm(IMSI-901700000004620:MSISDN-46071:TMSInew-0x03020100:GERAN-A:LU){VLR_ULA_S_WAIT_LU_COMPL}: Received Event VLR_ULA_E_NEW_TMSI_ACK DVLR lu_compl_vlr_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){LU_COMPL_VLR_S_WAIT_TMSI_CNF}: Received Event LU_COMPL_VLR_E_NEW_TMSI_ACK -DVLR SUBSCR(IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100) VLR: update for IMSI=901700000004620 (MSISDN=46071) +DMSC msub(IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100) VLR: update for IMSI=901700000004620 (MSISDN=46071) DREF VLR subscr IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100 + attached: now used by 2 (active-conn,attached) DVLR lu_compl_vlr_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){LU_COMPL_VLR_S_WAIT_TMSI_CNF}: state_chg to LU_COMPL_VLR_S_DONE DVLR vlr_lu_fsm(IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100:GERAN-A:LU){VLR_ULA_S_WAIT_LU_COMPL}: Received Event VLR_ULA_E_LU_COMPL_SUCCESS @@ -2609,7 +2609,7 @@ DMSC dummy_msc_i(IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100:GERAN-A:NONE){0}: Deferring: will deallocate with msc_a(IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100:GERAN-A:NONE) DMSC msub(IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100) Free DREF VLR subscr IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100 - active-conn: now used by 0 (-) -DVLR freeing VLR subscr IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100 (max total use count was 4) +DVLR SUBSCR(IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100) freeing VLR subscr (max total use count was 4) DMSC msub_fsm{terminating}: Deferring: will deallocate with msc_a(IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100:GERAN-A:NONE) DMSC msc_a(IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100:GERAN-A:NONE){MSC_A_ST_RELEASED}: Deallocated, including all deferred deallocations - msub gone @@ -2702,7 +2702,7 @@ <-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: 10010809710000000156f00804032443f20a0101 DREF VLR subscr IMSI-901700000010650 + vlr_gsup_rx: now used by 2 (active-conn,vlr_gsup_rx) DVLR IMSI:901700000010650 has MSISDN:42342 -DVLR SUBSCR(IMSI-901700000010650:MSISDN-42342) VLR: update for IMSI=901700000010650 (MSISDN=42342) +DMSC msub(IMSI-901700000010650:MSISDN-42342) VLR: update for IMSI=901700000010650 (MSISDN=42342) GSUP --> HLR: OSMO_GSUP_MSGT_INSERT_DATA_RESULT: 12010809710000000156f00a0101 DREF VLR subscr IMSI-901700000010650:MSISDN-42342 - vlr_gsup_rx: now used by 1 (active-conn) <-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: vlr_gsupc_read_cb() returns 0 @@ -3172,7 +3172,7 @@ DMSC dummy_msc_i(IMSI-901700000010650:MSISDN-42342:GERAN-A:NONE){0}: Deferring: will deallocate with msc_a(IMSI-901700000010650:MSISDN-42342:GERAN-A:NONE) DMSC msub(IMSI-901700000010650:MSISDN-42342) Free DREF VLR subscr IMSI-901700000010650:MSISDN-42342 - active-conn: now used by 0 (-) -DVLR freeing VLR subscr IMSI-901700000010650:MSISDN-42342 (max total use count was 6) +DVLR SUBSCR(IMSI-901700000010650:MSISDN-42342) freeing VLR subscr (max total use count was 6) DMSC msub_fsm{terminating}: Deferring: will deallocate with msc_a(IMSI-901700000010650:MSISDN-42342:GERAN-A:NONE) DMSC msc_a(IMSI-901700000010650:MSISDN-42342:GERAN-A:NONE){MSC_A_ST_RELEASED}: Deallocated, including all deferred deallocations - msub gone @@ -3315,7 +3315,7 @@ DMSC dummy_msc_i(IMSI-901700000004620:GERAN-A:LU){0}: Deferring: will deallocate with msc_a(IMSI-901700000004620:GERAN-A:LU) DMSC msub(IMSI-901700000004620) Free DREF VLR subscr IMSI-901700000004620 - active-conn: now used by 0 (-) -DVLR freeing VLR subscr IMSI-901700000004620 (max total use count was 3) +DVLR SUBSCR(IMSI-901700000004620) freeing VLR subscr (max total use count was 3) DMSC msub_fsm{terminating}: Deferring: will deallocate with msc_a(IMSI-901700000004620:GERAN-A:LU) DMSC msc_a(IMSI-901700000004620:GERAN-A:LU){MSC_A_ST_RELEASED}: Deallocated, including all deferred deallocations - msub gone diff --git a/tests/msc_vlr/msc_vlr_test_gsm_ciph.err b/tests/msc_vlr/msc_vlr_test_gsm_ciph.err index afea400..a373ec4 100644 --- a/tests/msc_vlr/msc_vlr_test_gsm_ciph.err +++ b/tests/msc_vlr/msc_vlr_test_gsm_ciph.err @@ -117,7 +117,7 @@ <-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: 10010809710000004026f00804036470f10a0101 DREF VLR subscr IMSI-901700000004620 + vlr_gsup_rx: now used by 2 (active-conn,vlr_gsup_rx) DVLR IMSI:901700000004620 has MSISDN:46071 -DVLR SUBSCR(IMSI-901700000004620:MSISDN-46071) VLR: update for IMSI=901700000004620 (MSISDN=46071) +DMSC msub(IMSI-901700000004620:MSISDN-46071) VLR: update for IMSI=901700000004620 (MSISDN=46071) GSUP --> HLR: OSMO_GSUP_MSGT_INSERT_DATA_RESULT: 12010809710000004026f00a0101 DREF VLR subscr IMSI-901700000004620:MSISDN-46071 - vlr_gsup_rx: now used by 1 (active-conn) <-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: vlr_gsupc_read_cb() returns 0 @@ -648,7 +648,7 @@ DMSC dummy_msc_i(IMSI-901700000004620:MSISDN-46071:GERAN-A:NONE){0}: Deferring: will deallocate with msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:NONE) DMSC msub(IMSI-901700000004620:MSISDN-46071) Free DREF VLR subscr IMSI-901700000004620:MSISDN-46071 - active-conn: now used by 0 (-) -DVLR freeing VLR subscr IMSI-901700000004620:MSISDN-46071 (max total use count was 6) +DVLR SUBSCR(IMSI-901700000004620:MSISDN-46071) freeing VLR subscr (max total use count was 6) DMSC msub_fsm{terminating}: Deferring: will deallocate with msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:NONE) DMSC msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:NONE){MSC_A_ST_RELEASED}: Deallocated, including all deferred deallocations - msub gone @@ -775,7 +775,7 @@ <-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: 10010809710000004026f00804036470f10a0101 DREF VLR subscr IMSI-901700000004620 + vlr_gsup_rx: now used by 2 (active-conn,vlr_gsup_rx) DVLR IMSI:901700000004620 has MSISDN:46071 -DVLR SUBSCR(IMSI-901700000004620:MSISDN-46071) VLR: update for IMSI=901700000004620 (MSISDN=46071) +DMSC msub(IMSI-901700000004620:MSISDN-46071) VLR: update for IMSI=901700000004620 (MSISDN=46071) GSUP --> HLR: OSMO_GSUP_MSGT_INSERT_DATA_RESULT: 12010809710000004026f00a0101 DREF VLR subscr IMSI-901700000004620:MSISDN-46071 - vlr_gsup_rx: now used by 1 (active-conn) <-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: vlr_gsupc_read_cb() returns 0 @@ -796,7 +796,7 @@ DVLR lu_compl_vlr_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){LU_COMPL_VLR_S_INIT}: state_chg to LU_COMPL_VLR_S_WAIT_SUB_PRES DVLR lu_compl_vlr_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){LU_COMPL_VLR_S_WAIT_SUB_PRES}: Received Event LU_COMPL_VLR_E_SUB_PRES_COMPL DVLR lu_compl_vlr_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){LU_COMPL_VLR_S_WAIT_SUB_PRES}: lu_compl_vlr_new_tmsi() -DVLR SUBSCR(IMSI-901700000004620:MSISDN-46071:TMSInew-0x03020100) VLR: update for IMSI=901700000004620 (MSISDN=46071) +DMSC msub(IMSI-901700000004620:MSISDN-46071:TMSInew-0x03020100) VLR: update for IMSI=901700000004620 (MSISDN=46071) DVLR lu_compl_vlr_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){LU_COMPL_VLR_S_WAIT_SUB_PRES}: state_chg to LU_COMPL_VLR_S_WAIT_TMSI_CNF - sending LU Accept for IMSI-901700000004620:MSISDN-46071:TMSInew-0x03020100:GERAN-A:LU, with TMSI 0x03020100 DVLR upd_hlr_vlr_fsm(IMSI-901700000004620:GERAN-A:LU){UPD_HLR_VLR_S_DONE}: Deallocated @@ -838,7 +838,7 @@ DMM msc_a(IMSI-901700000004620:MSISDN-46071:TMSInew-0x03020100:GERAN-A:LU){MSC_A_ST_AUTH_CIPH}: TMSI Reallocation Completed DVLR vlr_lu_fsm(IMSI-901700000004620:MSISDN-46071:TMSInew-0x03020100:GERAN-A:LU){VLR_ULA_S_WAIT_LU_COMPL}: Received Event VLR_ULA_E_NEW_TMSI_ACK DVLR lu_compl_vlr_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){LU_COMPL_VLR_S_WAIT_TMSI_CNF}: Received Event LU_COMPL_VLR_E_NEW_TMSI_ACK -DVLR SUBSCR(IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100) VLR: update for IMSI=901700000004620 (MSISDN=46071) +DMSC msub(IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100) VLR: update for IMSI=901700000004620 (MSISDN=46071) DREF VLR subscr IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100 + attached: now used by 2 (active-conn,attached) DVLR lu_compl_vlr_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){LU_COMPL_VLR_S_WAIT_TMSI_CNF}: state_chg to LU_COMPL_VLR_S_DONE DVLR vlr_lu_fsm(IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100:GERAN-A:LU){VLR_ULA_S_WAIT_LU_COMPL}: Received Event VLR_ULA_E_LU_COMPL_SUCCESS @@ -1353,7 +1353,7 @@ DMSC dummy_msc_i(IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100:GERAN-A:NONE){0}: Deferring: will deallocate with msc_a(IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100:GERAN-A:NONE) DMSC msub(IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100) Free DREF VLR subscr IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100 - active-conn: now used by 0 (-) -DVLR freeing VLR subscr IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100 (max total use count was 6) +DVLR SUBSCR(IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100) freeing VLR subscr (max total use count was 6) DMSC msub_fsm{terminating}: Deferring: will deallocate with msc_a(IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100:GERAN-A:NONE) DMSC msc_a(IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100:GERAN-A:NONE){MSC_A_ST_RELEASED}: Deallocated, including all deferred deallocations - msub gone @@ -1479,7 +1479,7 @@ <-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: 10010809710000004026f00804036470f10a0101 DREF VLR subscr IMSI-901700000004620 + vlr_gsup_rx: now used by 2 (active-conn,vlr_gsup_rx) DVLR IMSI:901700000004620 has MSISDN:46071 -DVLR SUBSCR(IMSI-901700000004620:MSISDN-46071) VLR: update for IMSI=901700000004620 (MSISDN=46071) +DMSC msub(IMSI-901700000004620:MSISDN-46071) VLR: update for IMSI=901700000004620 (MSISDN=46071) GSUP --> HLR: OSMO_GSUP_MSGT_INSERT_DATA_RESULT: 12010809710000004026f00a0101 DREF VLR subscr IMSI-901700000004620:MSISDN-46071 - vlr_gsup_rx: now used by 1 (active-conn) <-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: vlr_gsupc_read_cb() returns 0 @@ -1673,7 +1673,7 @@ DMSC dummy_msc_i(IMSI-901700000004620:MSISDN-46071:GERAN-A:NONE){0}: Deferring: will deallocate with msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:NONE) DMSC msub(IMSI-901700000004620:MSISDN-46071) Free DREF VLR subscr IMSI-901700000004620:MSISDN-46071 - active-conn: now used by 0 (-) -DVLR freeing VLR subscr IMSI-901700000004620:MSISDN-46071 (max total use count was 5) +DVLR SUBSCR(IMSI-901700000004620:MSISDN-46071) freeing VLR subscr (max total use count was 5) DMSC msub_fsm{terminating}: Deferring: will deallocate with msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:NONE) DMSC msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:NONE){MSC_A_ST_RELEASED}: Deallocated, including all deferred deallocations - msub gone @@ -1832,7 +1832,7 @@ <-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: 10010809710000004026f00804036470f10a0101 DREF VLR subscr IMSI-901700000004620 + vlr_gsup_rx: now used by 2 (active-conn,vlr_gsup_rx) DVLR IMSI:901700000004620 has MSISDN:46071 -DVLR SUBSCR(IMSI-901700000004620:MSISDN-46071) VLR: update for IMSI=901700000004620 (MSISDN=46071) +DMSC msub(IMSI-901700000004620:MSISDN-46071) VLR: update for IMSI=901700000004620 (MSISDN=46071) GSUP --> HLR: OSMO_GSUP_MSGT_INSERT_DATA_RESULT: 12010809710000004026f00a0101 DREF VLR subscr IMSI-901700000004620:MSISDN-46071 - vlr_gsup_rx: now used by 1 (active-conn) <-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: vlr_gsupc_read_cb() returns 0 @@ -1958,7 +1958,7 @@ DMSC dummy_msc_i(IMSI-901700000004620:MSISDN-46071:GERAN-A:NONE){0}: Deferring: will deallocate with msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:NONE) DMSC msub(IMSI-901700000004620:MSISDN-46071) Free DREF VLR subscr IMSI-901700000004620:MSISDN-46071 - active-conn: now used by 0 (-) -DVLR freeing VLR subscr IMSI-901700000004620:MSISDN-46071 (max total use count was 5) +DVLR SUBSCR(IMSI-901700000004620:MSISDN-46071) freeing VLR subscr (max total use count was 5) DMSC msub_fsm{terminating}: Deferring: will deallocate with msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:NONE) DMSC msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:NONE){MSC_A_ST_RELEASED}: Deallocated, including all deferred deallocations - msub gone @@ -2084,7 +2084,7 @@ <-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: 10010809710000004026f00804036470f10a0101 DREF VLR subscr IMSI-901700000004620 + vlr_gsup_rx: now used by 2 (active-conn,vlr_gsup_rx) DVLR IMSI:901700000004620 has MSISDN:46071 -DVLR SUBSCR(IMSI-901700000004620:MSISDN-46071) VLR: update for IMSI=901700000004620 (MSISDN=46071) +DMSC msub(IMSI-901700000004620:MSISDN-46071) VLR: update for IMSI=901700000004620 (MSISDN=46071) GSUP --> HLR: OSMO_GSUP_MSGT_INSERT_DATA_RESULT: 12010809710000004026f00a0101 DREF VLR subscr IMSI-901700000004620:MSISDN-46071 - vlr_gsup_rx: now used by 1 (active-conn) <-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: vlr_gsupc_read_cb() returns 0 @@ -2170,7 +2170,7 @@ DVLR vlr_lu_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){VLR_ULA_S_WAIT_LU_COMPL}: Received Event VLR_ULA_E_HLR_IMEI_ACK DVLR lu_compl_vlr_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){LU_COMPL_VLR_S_WAIT_IMEI_TMSI}: Received Event LU_COMPL_VLR_E_IMEI_CHECK_ACK DVLR lu_compl_vlr_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){LU_COMPL_VLR_S_WAIT_IMEI_TMSI}: lu_compl_vlr_new_tmsi() -DVLR SUBSCR(IMSI-901700000004620:MSISDN-46071:TMSInew-0x03020100) VLR: update for IMSI=901700000004620 (MSISDN=46071) +DMSC msub(IMSI-901700000004620:MSISDN-46071:TMSInew-0x03020100) VLR: update for IMSI=901700000004620 (MSISDN=46071) DVLR lu_compl_vlr_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){LU_COMPL_VLR_S_WAIT_IMEI_TMSI}: state_chg to LU_COMPL_VLR_S_WAIT_TMSI_CNF - sending LU Accept for IMSI-901700000004620:MSISDN-46071:TMSInew-0x03020100:GERAN-A:LU, with TMSI 0x03020100 DREF VLR subscr IMSI-901700000004620:MSISDN-46071:TMSInew-0x03020100 - vlr_gsup_rx: now used by 1 (active-conn) @@ -2211,7 +2211,7 @@ DMM msc_a(IMSI-901700000004620:MSISDN-46071:TMSInew-0x03020100:GERAN-A:LU){MSC_A_ST_AUTH_CIPH}: TMSI Reallocation Completed DVLR vlr_lu_fsm(IMSI-901700000004620:MSISDN-46071:TMSInew-0x03020100:GERAN-A:LU){VLR_ULA_S_WAIT_LU_COMPL}: Received Event VLR_ULA_E_NEW_TMSI_ACK DVLR lu_compl_vlr_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){LU_COMPL_VLR_S_WAIT_TMSI_CNF}: Received Event LU_COMPL_VLR_E_NEW_TMSI_ACK -DVLR SUBSCR(IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100) VLR: update for IMSI=901700000004620 (MSISDN=46071) +DMSC msub(IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100) VLR: update for IMSI=901700000004620 (MSISDN=46071) DREF VLR subscr IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100 + attached: now used by 2 (active-conn,attached) DVLR lu_compl_vlr_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){LU_COMPL_VLR_S_WAIT_TMSI_CNF}: state_chg to LU_COMPL_VLR_S_DONE DVLR vlr_lu_fsm(IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100:GERAN-A:LU){VLR_ULA_S_WAIT_LU_COMPL}: Received Event VLR_ULA_E_LU_COMPL_SUCCESS @@ -2319,7 +2319,7 @@ DMSC dummy_msc_i(IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100:GERAN-A:NONE){0}: Deferring: will deallocate with msc_a(IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100:GERAN-A:NONE) DMSC msub(IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100) Free DREF VLR subscr IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100 - active-conn: now used by 0 (-) -DVLR freeing VLR subscr IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100 (max total use count was 4) +DVLR SUBSCR(IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100) freeing VLR subscr (max total use count was 4) DMSC msub_fsm{terminating}: Deferring: will deallocate with msc_a(IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100:GERAN-A:NONE) DMSC msc_a(IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100:GERAN-A:NONE){MSC_A_ST_RELEASED}: Deallocated, including all deferred deallocations - msub gone @@ -2426,7 +2426,7 @@ <-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: 10010809710000000156f00804032443f20a0101 DREF VLR subscr IMSI-901700000010650 + vlr_gsup_rx: now used by 2 (active-conn,vlr_gsup_rx) DVLR IMSI:901700000010650 has MSISDN:42342 -DVLR SUBSCR(IMSI-901700000010650:MSISDN-42342) VLR: update for IMSI=901700000010650 (MSISDN=42342) +DMSC msub(IMSI-901700000010650:MSISDN-42342) VLR: update for IMSI=901700000010650 (MSISDN=42342) GSUP --> HLR: OSMO_GSUP_MSGT_INSERT_DATA_RESULT: 12010809710000000156f00a0101 DREF VLR subscr IMSI-901700000010650:MSISDN-42342 - vlr_gsup_rx: now used by 1 (active-conn) <-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: vlr_gsupc_read_cb() returns 0 @@ -2921,7 +2921,7 @@ DMSC dummy_msc_i(IMSI-901700000010650:MSISDN-42342:GERAN-A:NONE){0}: Deferring: will deallocate with msc_a(IMSI-901700000010650:MSISDN-42342:GERAN-A:NONE) DMSC msub(IMSI-901700000010650:MSISDN-42342) Free DREF VLR subscr IMSI-901700000010650:MSISDN-42342 - active-conn: now used by 0 (-) -DVLR freeing VLR subscr IMSI-901700000010650:MSISDN-42342 (max total use count was 6) +DVLR SUBSCR(IMSI-901700000010650:MSISDN-42342) freeing VLR subscr (max total use count was 6) DMSC msub_fsm{terminating}: Deferring: will deallocate with msc_a(IMSI-901700000010650:MSISDN-42342:GERAN-A:NONE) DMSC msc_a(IMSI-901700000010650:MSISDN-42342:GERAN-A:NONE){MSC_A_ST_RELEASED}: Deallocated, including all deferred deallocations - msub gone @@ -3039,7 +3039,7 @@ <-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: 10010809710000004026f00804032443f20a0101 DREF VLR subscr IMSI-901700000004620 + vlr_gsup_rx: now used by 2 (active-conn,vlr_gsup_rx) DVLR IMSI:901700000004620 has MSISDN:42342 -DVLR SUBSCR(IMSI-901700000004620:MSISDN-42342) VLR: update for IMSI=901700000004620 (MSISDN=42342) +DMSC msub(IMSI-901700000004620:MSISDN-42342) VLR: update for IMSI=901700000004620 (MSISDN=42342) GSUP --> HLR: OSMO_GSUP_MSGT_INSERT_DATA_RESULT: 12010809710000004026f00a0101 DREF VLR subscr IMSI-901700000004620:MSISDN-42342 - vlr_gsup_rx: now used by 1 (active-conn) <-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: vlr_gsupc_read_cb() returns 0 @@ -3570,7 +3570,7 @@ DMSC dummy_msc_i(IMSI-901700000004620:MSISDN-42342:GERAN-A:NONE){0}: Deferring: will deallocate with msc_a(IMSI-901700000004620:MSISDN-42342:GERAN-A:NONE) DMSC msub(IMSI-901700000004620:MSISDN-42342) Free DREF VLR subscr IMSI-901700000004620:MSISDN-42342 - active-conn: now used by 0 (-) -DVLR freeing VLR subscr IMSI-901700000004620:MSISDN-42342 (max total use count was 6) +DVLR SUBSCR(IMSI-901700000004620:MSISDN-42342) freeing VLR subscr (max total use count was 6) DMSC msub_fsm{terminating}: Deferring: will deallocate with msc_a(IMSI-901700000004620:MSISDN-42342:GERAN-A:NONE) DMSC msc_a(IMSI-901700000004620:MSISDN-42342:GERAN-A:NONE){MSC_A_ST_RELEASED}: Deallocated, including all deferred deallocations - msub gone @@ -3688,7 +3688,7 @@ <-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: 10010809710000004026f00804032443f20a0101 DREF VLR subscr IMSI-901700000004620 + vlr_gsup_rx: now used by 2 (active-conn,vlr_gsup_rx) DVLR IMSI:901700000004620 has MSISDN:42342 -DVLR SUBSCR(IMSI-901700000004620:MSISDN-42342) VLR: update for IMSI=901700000004620 (MSISDN=42342) +DMSC msub(IMSI-901700000004620:MSISDN-42342) VLR: update for IMSI=901700000004620 (MSISDN=42342) GSUP --> HLR: OSMO_GSUP_MSGT_INSERT_DATA_RESULT: 12010809710000004026f00a0101 DREF VLR subscr IMSI-901700000004620:MSISDN-42342 - vlr_gsup_rx: now used by 1 (active-conn) <-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: vlr_gsupc_read_cb() returns 0 @@ -4197,7 +4197,7 @@ DMSC dummy_msc_i(IMSI-901700000004620:MSISDN-42342:GERAN-A:NONE){0}: Deferring: will deallocate with msc_a(IMSI-901700000004620:MSISDN-42342:GERAN-A:NONE) DMSC msub(IMSI-901700000004620:MSISDN-42342) Free DREF VLR subscr IMSI-901700000004620:MSISDN-42342 - active-conn: now used by 0 (-) -DVLR freeing VLR subscr IMSI-901700000004620:MSISDN-42342 (max total use count was 6) +DVLR SUBSCR(IMSI-901700000004620:MSISDN-42342) freeing VLR subscr (max total use count was 6) DMSC msub_fsm{terminating}: Deferring: will deallocate with msc_a(IMSI-901700000004620:MSISDN-42342:GERAN-A:NONE) DMSC msc_a(IMSI-901700000004620:MSISDN-42342:GERAN-A:NONE){MSC_A_ST_RELEASED}: Deallocated, including all deferred deallocations - msub gone diff --git a/tests/msc_vlr/msc_vlr_test_hlr_reject.err b/tests/msc_vlr/msc_vlr_test_hlr_reject.err index 305e1b8..888ad1b 100644 --- a/tests/msc_vlr/msc_vlr_test_hlr_reject.err +++ b/tests/msc_vlr/msc_vlr_test_hlr_reject.err @@ -90,7 +90,7 @@ DMSC dummy_msc_i(IMSI-901700000004620:GERAN-A:LU){0}: Deferring: will deallocate with msc_a(IMSI-901700000004620:GERAN-A:LU) DMSC msub(IMSI-901700000004620) Free DREF VLR subscr IMSI-901700000004620 - active-conn: now used by 0 (-) -DVLR freeing VLR subscr IMSI-901700000004620 (max total use count was 4) +DVLR SUBSCR(IMSI-901700000004620) freeing VLR subscr (max total use count was 4) DMSC msub_fsm{terminating}: Deferring: will deallocate with msc_a(IMSI-901700000004620:GERAN-A:LU) DMSC msc_a(IMSI-901700000004620:GERAN-A:LU){MSC_A_ST_RELEASED}: Deallocated, including all deferred deallocations - msub gone @@ -189,7 +189,7 @@ DMSC dummy_msc_i(IMSI-901700000004620:GERAN-A:LU){0}: Deferring: will deallocate with msc_a(IMSI-901700000004620:GERAN-A:LU) DMSC msub(IMSI-901700000004620) Free DREF VLR subscr IMSI-901700000004620 - active-conn: now used by 0 (-) -DVLR freeing VLR subscr IMSI-901700000004620 (max total use count was 4) +DVLR SUBSCR(IMSI-901700000004620) freeing VLR subscr (max total use count was 4) DMSC msub_fsm{terminating}: Deferring: will deallocate with msc_a(IMSI-901700000004620:GERAN-A:LU) DMSC msc_a(IMSI-901700000004620:GERAN-A:LU){MSC_A_ST_RELEASED}: Deallocated, including all deferred deallocations - msub gone @@ -285,7 +285,7 @@ <-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: 10010809710000004026f00804036470f10a0101 DREF VLR subscr IMSI-901700000004620 + vlr_gsup_rx: now used by 2 (active-conn,vlr_gsup_rx) DVLR IMSI:901700000004620 has MSISDN:46071 -DVLR SUBSCR(IMSI-901700000004620:MSISDN-46071) VLR: update for IMSI=901700000004620 (MSISDN=46071) +DMSC msub(IMSI-901700000004620:MSISDN-46071) VLR: update for IMSI=901700000004620 (MSISDN=46071) GSUP --> HLR: OSMO_GSUP_MSGT_INSERT_DATA_RESULT: 12010809710000004026f00a0101 DREF VLR subscr IMSI-901700000004620:MSISDN-46071 - vlr_gsup_rx: now used by 1 (active-conn) <-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: vlr_gsupc_read_cb() returns 0 @@ -450,7 +450,7 @@ <-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: 10010809710000004026f00804036470f10a0101 DREF VLR subscr IMSI-901700000004620:MSISDN-46071 + vlr_gsup_rx: now used by 3 (attached,active-conn,vlr_gsup_rx) DVLR IMSI:901700000004620 has MSISDN:46071 -DVLR SUBSCR(IMSI-901700000004620:MSISDN-46071) VLR: update for IMSI=901700000004620 (MSISDN=46071) +DMSC msub(IMSI-901700000004620:MSISDN-46071) VLR: update for IMSI=901700000004620 (MSISDN=46071) GSUP --> HLR: OSMO_GSUP_MSGT_INSERT_DATA_RESULT: 12010809710000004026f00a0101 DREF VLR subscr IMSI-901700000004620:MSISDN-46071 - vlr_gsup_rx: now used by 2 (attached,active-conn) <-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: vlr_gsupc_read_cb() returns 0 @@ -522,7 +522,7 @@ DMSC msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){MSC_A_ST_RELEASED}: Deallocated, including all deferred deallocations - msub gone llist_count(&msub_list) == 0 -DVLR freeing VLR subscr IMSI-901700000004620:MSISDN-46071 (max total use count was 5) +DVLR SUBSCR(IMSI-901700000004620:MSISDN-46071) freeing VLR subscr (max total use count was 5) ===== test_hlr_rej_auth_info_net_fail_reuse_tuples: SUCCESS ===== test_hlr_rej_auth_info_net_fail_no_reuse_tuples @@ -614,7 +614,7 @@ <-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: 10010809710000004026f00804036470f10a0101 DREF VLR subscr IMSI-901700000004620 + vlr_gsup_rx: now used by 2 (active-conn,vlr_gsup_rx) DVLR IMSI:901700000004620 has MSISDN:46071 -DVLR SUBSCR(IMSI-901700000004620:MSISDN-46071) VLR: update for IMSI=901700000004620 (MSISDN=46071) +DMSC msub(IMSI-901700000004620:MSISDN-46071) VLR: update for IMSI=901700000004620 (MSISDN=46071) GSUP --> HLR: OSMO_GSUP_MSGT_INSERT_DATA_RESULT: 12010809710000004026f00a0101 DREF VLR subscr IMSI-901700000004620:MSISDN-46071 - vlr_gsup_rx: now used by 1 (active-conn) <-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: vlr_gsupc_read_cb() returns 0 @@ -789,7 +789,7 @@ DMSC msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){MSC_A_ST_RELEASED}: Deallocated, including all deferred deallocations - msub gone llist_count(&msub_list) == 0 -DVLR freeing VLR subscr IMSI-901700000004620:MSISDN-46071 (max total use count was 5) +DVLR SUBSCR(IMSI-901700000004620:MSISDN-46071) freeing VLR subscr (max total use count was 5) ===== test_hlr_rej_auth_info_net_fail_no_reuse_tuples: SUCCESS ===== test_hlr_rej_auth_info_unkown_imsi_no_reuse_tuples @@ -881,7 +881,7 @@ <-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: 10010809710000004026f00804036470f10a0101 DREF VLR subscr IMSI-901700000004620 + vlr_gsup_rx: now used by 2 (active-conn,vlr_gsup_rx) DVLR IMSI:901700000004620 has MSISDN:46071 -DVLR SUBSCR(IMSI-901700000004620:MSISDN-46071) VLR: update for IMSI=901700000004620 (MSISDN=46071) +DMSC msub(IMSI-901700000004620:MSISDN-46071) VLR: update for IMSI=901700000004620 (MSISDN=46071) GSUP --> HLR: OSMO_GSUP_MSGT_INSERT_DATA_RESULT: 12010809710000004026f00a0101 DREF VLR subscr IMSI-901700000004620:MSISDN-46071 - vlr_gsup_rx: now used by 1 (active-conn) <-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: vlr_gsupc_read_cb() returns 0 @@ -1057,7 +1057,7 @@ DMSC msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){MSC_A_ST_RELEASED}: Deallocated, including all deferred deallocations - msub gone llist_count(&msub_list) == 0 -DVLR freeing VLR subscr IMSI-901700000004620:MSISDN-46071 (max total use count was 5) +DVLR SUBSCR(IMSI-901700000004620:MSISDN-46071) freeing VLR subscr (max total use count was 5) ===== test_hlr_rej_auth_info_unkown_imsi_no_reuse_tuples: SUCCESS ===== test_hlr_acc_but_no_auth_tuples @@ -1151,7 +1151,7 @@ DMSC dummy_msc_i(IMSI-901700000004620:GERAN-A:LU){0}: Deferring: will deallocate with msc_a(IMSI-901700000004620:GERAN-A:LU) DMSC msub(IMSI-901700000004620) Free DREF VLR subscr IMSI-901700000004620 - active-conn: now used by 0 (-) -DVLR freeing VLR subscr IMSI-901700000004620 (max total use count was 4) +DVLR SUBSCR(IMSI-901700000004620) freeing VLR subscr (max total use count was 4) DMSC msub_fsm{terminating}: Deferring: will deallocate with msc_a(IMSI-901700000004620:GERAN-A:LU) DMSC msc_a(IMSI-901700000004620:GERAN-A:LU){MSC_A_ST_RELEASED}: Deallocated, including all deferred deallocations - msub gone @@ -1254,7 +1254,7 @@ DMSC dummy_msc_i(IMSI-901700000004620:GERAN-A:LU){0}: Deferring: will deallocate with msc_a(IMSI-901700000004620:GERAN-A:LU) DMSC msub(IMSI-901700000004620) Free DREF VLR subscr IMSI-901700000004620 - active-conn: now used by 0 (-) -DVLR freeing VLR subscr IMSI-901700000004620 (max total use count was 4) +DVLR SUBSCR(IMSI-901700000004620) freeing VLR subscr (max total use count was 4) DMSC msub_fsm{terminating}: Deferring: will deallocate with msc_a(IMSI-901700000004620:GERAN-A:LU) DMSC msc_a(IMSI-901700000004620:GERAN-A:LU){MSC_A_ST_RELEASED}: Deallocated, including all deferred deallocations - msub gone @@ -1374,6 +1374,6 @@ DMSC msc_a(IMSI-901700000004620:GERAN-A:LU){MSC_A_ST_RELEASED}: Deallocated, including all deferred deallocations - msub gone llist_count(&msub_list) == 0 -DVLR freeing VLR subscr IMSI-901700000004620 (max total use count was 5) +DVLR SUBSCR(IMSI-901700000004620) freeing VLR subscr (max total use count was 5) ===== test_hlr_no_insert_data: SUCCESS diff --git a/tests/msc_vlr/msc_vlr_test_hlr_timeout.err b/tests/msc_vlr/msc_vlr_test_hlr_timeout.err index 6a4daa5..6e68cc6 100644 --- a/tests/msc_vlr/msc_vlr_test_hlr_timeout.err +++ b/tests/msc_vlr/msc_vlr_test_hlr_timeout.err @@ -97,7 +97,7 @@ DMSC dummy_msc_i(IMSI-901700000004620:GERAN-A:LU){0}: Deferring: will deallocate with msc_a(IMSI-901700000004620:GERAN-A:LU) DMSC msub(IMSI-901700000004620) Free DREF VLR subscr IMSI-901700000004620 - active-conn: now used by 0 (-) -DVLR freeing VLR subscr IMSI-901700000004620 (max total use count was 3) +DVLR SUBSCR(IMSI-901700000004620) freeing VLR subscr (max total use count was 3) DMSC msub_fsm{terminating}: Deferring: will deallocate with msc_a(IMSI-901700000004620:GERAN-A:LU) DMSC msc_a(IMSI-901700000004620:GERAN-A:LU){MSC_A_ST_RELEASED}: Deallocated, including all deferred deallocations - msub gone @@ -155,7 +155,7 @@ <-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: 10010809710000004026f00804036470f10a0101 DREF VLR subscr IMSI-901700000004620 + vlr_gsup_rx: now used by 2 (active-conn,vlr_gsup_rx) DVLR IMSI:901700000004620 has MSISDN:46071 -DVLR SUBSCR(IMSI-901700000004620:MSISDN-46071) VLR: update for IMSI=901700000004620 (MSISDN=46071) +DMSC msub(IMSI-901700000004620:MSISDN-46071) VLR: update for IMSI=901700000004620 (MSISDN=46071) GSUP --> HLR: OSMO_GSUP_MSGT_INSERT_DATA_RESULT: 12010809710000004026f00a0101 DREF VLR subscr IMSI-901700000004620:MSISDN-46071 - vlr_gsup_rx: now used by 1 (active-conn) <-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: vlr_gsupc_read_cb() returns 0 @@ -223,7 +223,7 @@ DMSC dummy_msc_i(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){0}: Deferring: will deallocate with msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU) DMSC msub(IMSI-901700000004620:MSISDN-46071) Free DREF VLR subscr IMSI-901700000004620:MSISDN-46071 - active-conn: now used by 0 (-) -DVLR freeing VLR subscr IMSI-901700000004620:MSISDN-46071 (max total use count was 3) +DVLR SUBSCR(IMSI-901700000004620:MSISDN-46071) freeing VLR subscr (max total use count was 3) DMSC msub_fsm{terminating}: Deferring: will deallocate with msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU) DMSC msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){MSC_A_ST_RELEASED}: Deallocated, including all deferred deallocations - msub gone diff --git a/tests/msc_vlr/msc_vlr_test_ms_timeout.err b/tests/msc_vlr/msc_vlr_test_ms_timeout.err index c4a73e3..1acc262 100644 --- a/tests/msc_vlr/msc_vlr_test_ms_timeout.err +++ b/tests/msc_vlr/msc_vlr_test_ms_timeout.err @@ -116,7 +116,7 @@ DMSC dummy_msc_i(IMSI-901700000004620:GERAN-A:LU){0}: Deferring: will deallocate with msc_a(IMSI-901700000004620:GERAN-A:LU) DMSC msub(IMSI-901700000004620) Free DREF VLR subscr IMSI-901700000004620 - active-conn: now used by 0 (-) -DVLR freeing VLR subscr IMSI-901700000004620 (max total use count was 3) +DVLR SUBSCR(IMSI-901700000004620) freeing VLR subscr (max total use count was 3) DMSC msub_fsm{terminating}: Deferring: will deallocate with msc_a(IMSI-901700000004620:GERAN-A:LU) DMSC msc_a(IMSI-901700000004620:GERAN-A:LU){MSC_A_ST_RELEASED}: Deallocated, including all deferred deallocations - msub gone @@ -211,7 +211,7 @@ <-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: 10010809710000004026f00804036470f10a0101 DREF VLR subscr IMSI-901700000004620 + vlr_gsup_rx: now used by 2 (active-conn,vlr_gsup_rx) DVLR IMSI:901700000004620 has MSISDN:46071 -DVLR SUBSCR(IMSI-901700000004620:MSISDN-46071) VLR: update for IMSI=901700000004620 (MSISDN=46071) +DMSC msub(IMSI-901700000004620:MSISDN-46071) VLR: update for IMSI=901700000004620 (MSISDN=46071) GSUP --> HLR: OSMO_GSUP_MSGT_INSERT_DATA_RESULT: 12010809710000004026f00a0101 DREF VLR subscr IMSI-901700000004620:MSISDN-46071 - vlr_gsup_rx: now used by 1 (active-conn) <-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: vlr_gsupc_read_cb() returns 0 @@ -393,7 +393,7 @@ - msub gone llist_count(&msub_list) == 0 cm_service_result_sent == 2 -DVLR freeing VLR subscr IMSI-901700000004620:MSISDN-46071 (max total use count was 5) +DVLR SUBSCR(IMSI-901700000004620:MSISDN-46071) freeing VLR subscr (max total use count was 5) ===== test_ms_timeout_cm_auth_resp: SUCCESS ===== test_ms_timeout_paging @@ -446,7 +446,7 @@ <-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: 10010809710000004026f00804036470f10a0101 DREF VLR subscr IMSI-901700000004620 + vlr_gsup_rx: now used by 2 (active-conn,vlr_gsup_rx) DVLR IMSI:901700000004620 has MSISDN:46071 -DVLR SUBSCR(IMSI-901700000004620:MSISDN-46071) VLR: update for IMSI=901700000004620 (MSISDN=46071) +DMSC msub(IMSI-901700000004620:MSISDN-46071) VLR: update for IMSI=901700000004620 (MSISDN=46071) GSUP --> HLR: OSMO_GSUP_MSGT_INSERT_DATA_RESULT: 12010809710000004026f00a0101 DREF VLR subscr IMSI-901700000004620:MSISDN-46071 - vlr_gsup_rx: now used by 1 (active-conn) <-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: vlr_gsupc_read_cb() returns 0 @@ -698,7 +698,7 @@ DMSC dummy_msc_i(IMSI-901700000004620:MSISDN-46071:GERAN-A:NONE){0}: Deferring: will deallocate with msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:NONE) DMSC msub(IMSI-901700000004620:MSISDN-46071) Free DREF VLR subscr IMSI-901700000004620:MSISDN-46071 - active-conn: now used by 0 (-) -DVLR freeing VLR subscr IMSI-901700000004620:MSISDN-46071 (max total use count was 7) +DVLR SUBSCR(IMSI-901700000004620:MSISDN-46071) freeing VLR subscr (max total use count was 7) DMSC msub_fsm{terminating}: Deferring: will deallocate with msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:NONE) DMSC msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:NONE){MSC_A_ST_RELEASED}: Deallocated, including all deferred deallocations - msub gone @@ -847,7 +847,7 @@ DMSC dummy_msc_i(IMSI-901700000004620:GERAN-A:LU){0}: Deferring: will deallocate with msc_a(IMSI-901700000004620:GERAN-A:LU) DMSC msub(IMSI-901700000004620) Free DREF VLR subscr IMSI-901700000004620 - active-conn: now used by 0 (-) -DVLR freeing VLR subscr IMSI-901700000004620 (max total use count was 3) +DVLR SUBSCR(IMSI-901700000004620) freeing VLR subscr (max total use count was 3) DMSC msub_fsm{terminating}: Deferring: will deallocate with msc_a(IMSI-901700000004620:GERAN-A:LU) DMSC msc_a(IMSI-901700000004620:GERAN-A:LU){MSC_A_ST_RELEASED}: Deallocated, including all deferred deallocations - msub gone diff --git a/tests/msc_vlr/msc_vlr_test_no_authen.err b/tests/msc_vlr/msc_vlr_test_no_authen.err index 1cc55de..6a87910 100644 --- a/tests/msc_vlr/msc_vlr_test_no_authen.err +++ b/tests/msc_vlr/msc_vlr_test_no_authen.err @@ -47,7 +47,7 @@ <-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: 10010809710000004026f00804036470f10a0101 DREF VLR subscr IMSI-901700000004620 + vlr_gsup_rx: now used by 2 (active-conn,vlr_gsup_rx) DVLR IMSI:901700000004620 has MSISDN:46071 -DVLR SUBSCR(IMSI-901700000004620:MSISDN-46071) VLR: update for IMSI=901700000004620 (MSISDN=46071) +DMSC msub(IMSI-901700000004620:MSISDN-46071) VLR: update for IMSI=901700000004620 (MSISDN=46071) GSUP --> HLR: OSMO_GSUP_MSGT_INSERT_DATA_RESULT: 12010809710000004026f00a0101 DREF VLR subscr IMSI-901700000004620:MSISDN-46071 - vlr_gsup_rx: now used by 1 (active-conn) <-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: vlr_gsupc_read_cb() returns 0 @@ -447,7 +447,7 @@ DMSC dummy_msc_i(IMSI-901700000004620:MSISDN-46071:GERAN-A:NONE){0}: Deferring: will deallocate with msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:NONE) DMSC msub(IMSI-901700000004620:MSISDN-46071) Free DREF VLR subscr IMSI-901700000004620:MSISDN-46071 - active-conn: now used by 0 (-) -DVLR freeing VLR subscr IMSI-901700000004620:MSISDN-46071 (max total use count was 6) +DVLR SUBSCR(IMSI-901700000004620:MSISDN-46071) freeing VLR subscr (max total use count was 6) DMSC msub_fsm{terminating}: Deferring: will deallocate with msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:NONE) DMSC msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:NONE){MSC_A_ST_RELEASED}: Deallocated, including all deferred deallocations - msub gone @@ -503,7 +503,7 @@ <-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: 10010809710000004026f00804036470f10a0101 DREF VLR subscr IMSI-901700000004620 + vlr_gsup_rx: now used by 2 (active-conn,vlr_gsup_rx) DVLR IMSI:901700000004620 has MSISDN:46071 -DVLR SUBSCR(IMSI-901700000004620:MSISDN-46071) VLR: update for IMSI=901700000004620 (MSISDN=46071) +DMSC msub(IMSI-901700000004620:MSISDN-46071) VLR: update for IMSI=901700000004620 (MSISDN=46071) GSUP --> HLR: OSMO_GSUP_MSGT_INSERT_DATA_RESULT: 12010809710000004026f00a0101 DREF VLR subscr IMSI-901700000004620:MSISDN-46071 - vlr_gsup_rx: now used by 1 (active-conn) <-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: vlr_gsupc_read_cb() returns 0 @@ -544,7 +544,7 @@ DVLR lu_compl_vlr_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){LU_COMPL_VLR_S_INIT}: state_chg to LU_COMPL_VLR_S_WAIT_SUB_PRES DVLR lu_compl_vlr_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){LU_COMPL_VLR_S_WAIT_SUB_PRES}: Received Event LU_COMPL_VLR_E_SUB_PRES_COMPL DVLR lu_compl_vlr_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){LU_COMPL_VLR_S_WAIT_SUB_PRES}: lu_compl_vlr_new_tmsi() -DVLR SUBSCR(IMSI-901700000004620:MSISDN-46071:TMSInew-0x03020100) VLR: update for IMSI=901700000004620 (MSISDN=46071) +DMSC msub(IMSI-901700000004620:MSISDN-46071:TMSInew-0x03020100) VLR: update for IMSI=901700000004620 (MSISDN=46071) DVLR lu_compl_vlr_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){LU_COMPL_VLR_S_WAIT_SUB_PRES}: state_chg to LU_COMPL_VLR_S_WAIT_TMSI_CNF - sending LU Accept for IMSI-901700000004620:MSISDN-46071:TMSInew-0x03020100:GERAN-A:LU, with TMSI 0x03020100 DVLR upd_hlr_vlr_fsm(IMSI-901700000004620:GERAN-A:LU){UPD_HLR_VLR_S_DONE}: Deallocated @@ -586,7 +586,7 @@ DMM msc_a(IMSI-901700000004620:MSISDN-46071:TMSInew-0x03020100:GERAN-A:LU){MSC_A_ST_AUTH_CIPH}: TMSI Reallocation Completed DVLR vlr_lu_fsm(IMSI-901700000004620:MSISDN-46071:TMSInew-0x03020100:GERAN-A:LU){VLR_ULA_S_WAIT_LU_COMPL}: Received Event VLR_ULA_E_NEW_TMSI_ACK DVLR lu_compl_vlr_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){LU_COMPL_VLR_S_WAIT_TMSI_CNF}: Received Event LU_COMPL_VLR_E_NEW_TMSI_ACK -DVLR SUBSCR(IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100) VLR: update for IMSI=901700000004620 (MSISDN=46071) +DMSC msub(IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100) VLR: update for IMSI=901700000004620 (MSISDN=46071) DREF VLR subscr IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100 + attached: now used by 2 (active-conn,attached) DVLR lu_compl_vlr_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){LU_COMPL_VLR_S_WAIT_TMSI_CNF}: state_chg to LU_COMPL_VLR_S_DONE DVLR vlr_lu_fsm(IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100:GERAN-A:LU){VLR_ULA_S_WAIT_LU_COMPL}: Received Event VLR_ULA_E_LU_COMPL_SUCCESS @@ -946,7 +946,7 @@ <-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: 10010809710000004026f00804036470f10a0101 DREF VLR subscr IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100 + vlr_gsup_rx: now used by 3 (attached,active-conn,vlr_gsup_rx) DVLR IMSI:901700000004620 has MSISDN:46071 -DVLR SUBSCR(IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100) VLR: update for IMSI=901700000004620 (MSISDN=46071) +DMSC msub(IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100) VLR: update for IMSI=901700000004620 (MSISDN=46071) GSUP --> HLR: OSMO_GSUP_MSGT_INSERT_DATA_RESULT: 12010809710000004026f00a0101 DREF VLR subscr IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100 - vlr_gsup_rx: now used by 2 (attached,active-conn) <-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: vlr_gsupc_read_cb() returns 0 @@ -987,7 +987,7 @@ DVLR lu_compl_vlr_fsm(IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100:GERAN-A:LU){LU_COMPL_VLR_S_INIT}: state_chg to LU_COMPL_VLR_S_WAIT_SUB_PRES DVLR lu_compl_vlr_fsm(IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100:GERAN-A:LU){LU_COMPL_VLR_S_WAIT_SUB_PRES}: Received Event LU_COMPL_VLR_E_SUB_PRES_COMPL DVLR lu_compl_vlr_fsm(IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100:GERAN-A:LU){LU_COMPL_VLR_S_WAIT_SUB_PRES}: lu_compl_vlr_new_tmsi() -DVLR SUBSCR(IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100:TMSInew-0x07060504) VLR: update for IMSI=901700000004620 (MSISDN=46071) +DMSC msub(IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100:TMSInew-0x07060504) VLR: update for IMSI=901700000004620 (MSISDN=46071) DVLR lu_compl_vlr_fsm(IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100:GERAN-A:LU){LU_COMPL_VLR_S_WAIT_SUB_PRES}: state_chg to LU_COMPL_VLR_S_WAIT_TMSI_CNF - sending LU Accept for IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100:TMSInew-0x07060504:GERAN-A:LU, with TMSI 0x07060504 DVLR upd_hlr_vlr_fsm(IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100:GERAN-A:LU){UPD_HLR_VLR_S_DONE}: Deallocated @@ -1029,7 +1029,7 @@ DMM msc_a(IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100:TMSInew-0x07060504:GERAN-A:LU){MSC_A_ST_AUTH_CIPH}: TMSI Reallocation Completed DVLR vlr_lu_fsm(IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100:TMSInew-0x07060504:GERAN-A:LU){VLR_ULA_S_WAIT_LU_COMPL}: Received Event VLR_ULA_E_NEW_TMSI_ACK DVLR lu_compl_vlr_fsm(IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100:GERAN-A:LU){LU_COMPL_VLR_S_WAIT_TMSI_CNF}: Received Event LU_COMPL_VLR_E_NEW_TMSI_ACK -DVLR SUBSCR(IMSI-901700000004620:MSISDN-46071:TMSI-0x07060504) VLR: update for IMSI=901700000004620 (MSISDN=46071) +DMSC msub(IMSI-901700000004620:MSISDN-46071:TMSI-0x07060504) VLR: update for IMSI=901700000004620 (MSISDN=46071) DVLR lu_compl_vlr_fsm(IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100:GERAN-A:LU){LU_COMPL_VLR_S_WAIT_TMSI_CNF}: state_chg to LU_COMPL_VLR_S_DONE DVLR vlr_lu_fsm(IMSI-901700000004620:MSISDN-46071:TMSI-0x07060504:GERAN-A:LU){VLR_ULA_S_WAIT_LU_COMPL}: Received Event VLR_ULA_E_LU_COMPL_SUCCESS DVLR lu_compl_vlr_fsm(IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100:GERAN-A:LU){LU_COMPL_VLR_S_DONE}: Terminating (cause = OSMO_FSM_TERM_PARENT) @@ -1138,7 +1138,7 @@ DMSC dummy_msc_i(IMSI-901700000004620:MSISDN-46071:TMSI-0x07060504:GERAN-A:NONE){0}: Deferring: will deallocate with msc_a(IMSI-901700000004620:MSISDN-46071:TMSI-0x07060504:GERAN-A:NONE) DMSC msub(IMSI-901700000004620:MSISDN-46071:TMSI-0x07060504) Free DREF VLR subscr IMSI-901700000004620:MSISDN-46071:TMSI-0x07060504 - active-conn: now used by 0 (-) -DVLR freeing VLR subscr IMSI-901700000004620:MSISDN-46071:TMSI-0x07060504 (max total use count was 6) +DVLR SUBSCR(IMSI-901700000004620:MSISDN-46071:TMSI-0x07060504) freeing VLR subscr (max total use count was 6) DMSC msub_fsm{terminating}: Deferring: will deallocate with msc_a(IMSI-901700000004620:MSISDN-46071:TMSI-0x07060504:GERAN-A:NONE) DMSC msc_a(IMSI-901700000004620:MSISDN-46071:TMSI-0x07060504:GERAN-A:NONE){MSC_A_ST_RELEASED}: Deallocated, including all deferred deallocations - msub gone @@ -1194,7 +1194,7 @@ <-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: 10010809710000004026f00804036470f10a0101 DREF VLR subscr IMSI-901700000004620 + vlr_gsup_rx: now used by 2 (active-conn,vlr_gsup_rx) DVLR IMSI:901700000004620 has MSISDN:46071 -DVLR SUBSCR(IMSI-901700000004620:MSISDN-46071) VLR: update for IMSI=901700000004620 (MSISDN=46071) +DMSC msub(IMSI-901700000004620:MSISDN-46071) VLR: update for IMSI=901700000004620 (MSISDN=46071) GSUP --> HLR: OSMO_GSUP_MSGT_INSERT_DATA_RESULT: 12010809710000004026f00a0101 DREF VLR subscr IMSI-901700000004620:MSISDN-46071 - vlr_gsup_rx: now used by 1 (active-conn) <-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: vlr_gsupc_read_cb() returns 0 @@ -1390,7 +1390,7 @@ DMSC dummy_msc_i(IMSI-901700000004620:MSISDN-46071:GERAN-A:NONE){0}: Deferring: will deallocate with msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:NONE) DMSC msub(IMSI-901700000004620:MSISDN-46071) Free DREF VLR subscr IMSI-901700000004620:MSISDN-46071 - active-conn: now used by 0 (-) -DVLR freeing VLR subscr IMSI-901700000004620:MSISDN-46071 (max total use count was 5) +DVLR SUBSCR(IMSI-901700000004620:MSISDN-46071) freeing VLR subscr (max total use count was 5) DMSC msub_fsm{terminating}: Deferring: will deallocate with msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:NONE) DMSC msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:NONE){MSC_A_ST_RELEASED}: Deallocated, including all deferred deallocations - msub gone @@ -1446,7 +1446,7 @@ <-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: 10010809710000004026f00804036470f10a0101 DREF VLR subscr IMSI-901700000004620 + vlr_gsup_rx: now used by 2 (active-conn,vlr_gsup_rx) DVLR IMSI:901700000004620 has MSISDN:46071 -DVLR SUBSCR(IMSI-901700000004620:MSISDN-46071) VLR: update for IMSI=901700000004620 (MSISDN=46071) +DMSC msub(IMSI-901700000004620:MSISDN-46071) VLR: update for IMSI=901700000004620 (MSISDN=46071) GSUP --> HLR: OSMO_GSUP_MSGT_INSERT_DATA_RESULT: 12010809710000004026f00a0101 DREF VLR subscr IMSI-901700000004620:MSISDN-46071 - vlr_gsup_rx: now used by 1 (active-conn) <-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: vlr_gsupc_read_cb() returns 0 @@ -1534,7 +1534,7 @@ DVLR vlr_lu_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){VLR_ULA_S_WAIT_LU_COMPL}: Received Event VLR_ULA_E_HLR_IMEI_ACK DVLR lu_compl_vlr_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){LU_COMPL_VLR_S_WAIT_IMEI_TMSI}: Received Event LU_COMPL_VLR_E_IMEI_CHECK_ACK DVLR lu_compl_vlr_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){LU_COMPL_VLR_S_WAIT_IMEI_TMSI}: lu_compl_vlr_new_tmsi() -DVLR SUBSCR(IMSI-901700000004620:MSISDN-46071:TMSInew-0x03020100) VLR: update for IMSI=901700000004620 (MSISDN=46071) +DMSC msub(IMSI-901700000004620:MSISDN-46071:TMSInew-0x03020100) VLR: update for IMSI=901700000004620 (MSISDN=46071) DVLR lu_compl_vlr_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){LU_COMPL_VLR_S_WAIT_IMEI_TMSI}: state_chg to LU_COMPL_VLR_S_WAIT_TMSI_CNF - sending LU Accept for IMSI-901700000004620:MSISDN-46071:TMSInew-0x03020100:GERAN-A:LU, with TMSI 0x03020100 DREF VLR subscr IMSI-901700000004620:MSISDN-46071:TMSInew-0x03020100 - vlr_gsup_rx: now used by 1 (active-conn) @@ -1568,7 +1568,7 @@ DMM msc_a(IMSI-901700000004620:MSISDN-46071:TMSInew-0x03020100:GERAN-A:LU){MSC_A_ST_AUTH_CIPH}: TMSI Reallocation Completed DVLR vlr_lu_fsm(IMSI-901700000004620:MSISDN-46071:TMSInew-0x03020100:GERAN-A:LU){VLR_ULA_S_WAIT_LU_COMPL}: Received Event VLR_ULA_E_NEW_TMSI_ACK DVLR lu_compl_vlr_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){LU_COMPL_VLR_S_WAIT_TMSI_CNF}: Received Event LU_COMPL_VLR_E_NEW_TMSI_ACK -DVLR SUBSCR(IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100) VLR: update for IMSI=901700000004620 (MSISDN=46071) +DMSC msub(IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100) VLR: update for IMSI=901700000004620 (MSISDN=46071) DREF VLR subscr IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100 + attached: now used by 2 (active-conn,attached) DVLR lu_compl_vlr_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){LU_COMPL_VLR_S_WAIT_TMSI_CNF}: state_chg to LU_COMPL_VLR_S_DONE DVLR vlr_lu_fsm(IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100:GERAN-A:LU){VLR_ULA_S_WAIT_LU_COMPL}: Received Event VLR_ULA_E_LU_COMPL_SUCCESS @@ -1677,7 +1677,7 @@ DMSC dummy_msc_i(IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100:GERAN-A:NONE){0}: Deferring: will deallocate with msc_a(IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100:GERAN-A:NONE) DMSC msub(IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100) Free DREF VLR subscr IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100 - active-conn: now used by 0 (-) -DVLR freeing VLR subscr IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100 (max total use count was 4) +DVLR SUBSCR(IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100) freeing VLR subscr (max total use count was 4) DMSC msub_fsm{terminating}: Deferring: will deallocate with msc_a(IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100:GERAN-A:NONE) DMSC msc_a(IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100:GERAN-A:NONE){MSC_A_ST_RELEASED}: Deallocated, including all deferred deallocations - msub gone @@ -1753,7 +1753,7 @@ <-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: 10010809710000004026f00804036470f10a0101 DREF VLR subscr IMSI-901700000004620 + vlr_gsup_rx: now used by 2 (active-conn,vlr_gsup_rx) DVLR IMSI:901700000004620 has MSISDN:46071 -DVLR SUBSCR(IMSI-901700000004620:MSISDN-46071) VLR: update for IMSI=901700000004620 (MSISDN=46071) +DMSC msub(IMSI-901700000004620:MSISDN-46071) VLR: update for IMSI=901700000004620 (MSISDN=46071) GSUP --> HLR: OSMO_GSUP_MSGT_INSERT_DATA_RESULT: 12010809710000004026f00a0101 DREF VLR subscr IMSI-901700000004620:MSISDN-46071 - vlr_gsup_rx: now used by 1 (active-conn) <-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: vlr_gsupc_read_cb() returns 0 @@ -1899,7 +1899,7 @@ DMSC dummy_msc_i(IMSI-901700000004620:MSISDN-46071:GERAN-A:NONE){0}: Deferring: will deallocate with msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:NONE) DMSC msub(IMSI-901700000004620:MSISDN-46071) Free DREF VLR subscr IMSI-901700000004620:MSISDN-46071 - active-conn: now used by 0 (-) -DVLR freeing VLR subscr IMSI-901700000004620:MSISDN-46071 (max total use count was 5) +DVLR SUBSCR(IMSI-901700000004620:MSISDN-46071) freeing VLR subscr (max total use count was 5) DMSC msub_fsm{terminating}: Deferring: will deallocate with msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:NONE) DMSC msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:NONE){MSC_A_ST_RELEASED}: Deallocated, including all deferred deallocations - msub gone @@ -1983,7 +1983,7 @@ <-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: 10010809710000004026f00804036470f10a0101 DREF VLR subscr IMSI-901700000004620 + vlr_gsup_rx: now used by 2 (active-conn,vlr_gsup_rx) DVLR IMSI:901700000004620 has MSISDN:46071 -DVLR SUBSCR(IMSI-901700000004620:MSISDN-46071) VLR: update for IMSI=901700000004620 (MSISDN=46071) +DMSC msub(IMSI-901700000004620:MSISDN-46071) VLR: update for IMSI=901700000004620 (MSISDN=46071) GSUP --> HLR: OSMO_GSUP_MSGT_INSERT_DATA_RESULT: 12010809710000004026f00a0101 DREF VLR subscr IMSI-901700000004620:MSISDN-46071 - vlr_gsup_rx: now used by 1 (active-conn) <-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: vlr_gsupc_read_cb() returns 0 @@ -2132,7 +2132,7 @@ DMSC dummy_msc_i(IMSI-901700000004620:MSISDN-46071:GERAN-A:NONE){0}: Deferring: will deallocate with msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:NONE) DMSC msub(IMSI-901700000004620:MSISDN-46071) Free DREF VLR subscr IMSI-901700000004620:MSISDN-46071 - active-conn: now used by 0 (-) -DVLR freeing VLR subscr IMSI-901700000004620:MSISDN-46071 (max total use count was 5) +DVLR SUBSCR(IMSI-901700000004620:MSISDN-46071) freeing VLR subscr (max total use count was 5) DMSC msub_fsm{terminating}: Deferring: will deallocate with msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:NONE) DMSC msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:NONE){MSC_A_ST_RELEASED}: Deallocated, including all deferred deallocations - msub gone @@ -2208,7 +2208,7 @@ <-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: 10010809710000004026f00804036470f10a0101 DREF VLR subscr IMSI-901700000004620 + vlr_gsup_rx: now used by 2 (active-conn,vlr_gsup_rx) DVLR IMSI:901700000004620 has MSISDN:46071 -DVLR SUBSCR(IMSI-901700000004620:MSISDN-46071) VLR: update for IMSI=901700000004620 (MSISDN=46071) +DMSC msub(IMSI-901700000004620:MSISDN-46071) VLR: update for IMSI=901700000004620 (MSISDN=46071) GSUP --> HLR: OSMO_GSUP_MSGT_INSERT_DATA_RESULT: 12010809710000004026f00a0101 DREF VLR subscr IMSI-901700000004620:MSISDN-46071 - vlr_gsup_rx: now used by 1 (active-conn) <-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: vlr_gsupc_read_cb() returns 0 @@ -2249,7 +2249,7 @@ DVLR lu_compl_vlr_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){LU_COMPL_VLR_S_INIT}: state_chg to LU_COMPL_VLR_S_WAIT_SUB_PRES DVLR lu_compl_vlr_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){LU_COMPL_VLR_S_WAIT_SUB_PRES}: Received Event LU_COMPL_VLR_E_SUB_PRES_COMPL DVLR lu_compl_vlr_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){LU_COMPL_VLR_S_WAIT_SUB_PRES}: lu_compl_vlr_new_tmsi() -DVLR SUBSCR(IMSI-901700000004620:MSISDN-46071:TMSInew-0x03020100) VLR: update for IMSI=901700000004620 (MSISDN=46071) +DMSC msub(IMSI-901700000004620:MSISDN-46071:TMSInew-0x03020100) VLR: update for IMSI=901700000004620 (MSISDN=46071) DVLR lu_compl_vlr_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){LU_COMPL_VLR_S_WAIT_SUB_PRES}: state_chg to LU_COMPL_VLR_S_WAIT_TMSI_CNF - sending LU Accept for IMSI-901700000004620:MSISDN-46071:TMSInew-0x03020100:GERAN-A:LU, with TMSI 0x03020100 DVLR upd_hlr_vlr_fsm(IMSI-901700000004620:GERAN-A:LU){UPD_HLR_VLR_S_DONE}: Deallocated @@ -2291,7 +2291,7 @@ DMM msc_a(IMSI-901700000004620:MSISDN-46071:TMSInew-0x03020100:GERAN-A:LU){MSC_A_ST_AUTH_CIPH}: TMSI Reallocation Completed DVLR vlr_lu_fsm(IMSI-901700000004620:MSISDN-46071:TMSInew-0x03020100:GERAN-A:LU){VLR_ULA_S_WAIT_LU_COMPL}: Received Event VLR_ULA_E_NEW_TMSI_ACK DVLR lu_compl_vlr_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){LU_COMPL_VLR_S_WAIT_TMSI_CNF}: Received Event LU_COMPL_VLR_E_NEW_TMSI_ACK -DVLR SUBSCR(IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100) VLR: update for IMSI=901700000004620 (MSISDN=46071) +DMSC msub(IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100) VLR: update for IMSI=901700000004620 (MSISDN=46071) DREF VLR subscr IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100 + attached: now used by 2 (active-conn,attached) DVLR lu_compl_vlr_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){LU_COMPL_VLR_S_WAIT_TMSI_CNF}: state_chg to LU_COMPL_VLR_S_DONE DVLR vlr_lu_fsm(IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100:GERAN-A:LU){VLR_ULA_S_WAIT_LU_COMPL}: Received Event VLR_ULA_E_LU_COMPL_SUCCESS @@ -2410,7 +2410,7 @@ <-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: 10010809710000004026f00804036470f10a0101 DREF VLR subscr IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100 + vlr_gsup_rx: now used by 3 (attached,active-conn,vlr_gsup_rx) DVLR IMSI:901700000004620 has MSISDN:46071 -DVLR SUBSCR(IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100) VLR: update for IMSI=901700000004620 (MSISDN=46071) +DMSC msub(IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100) VLR: update for IMSI=901700000004620 (MSISDN=46071) GSUP --> HLR: OSMO_GSUP_MSGT_INSERT_DATA_RESULT: 12010809710000004026f00a0101 DREF VLR subscr IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100 - vlr_gsup_rx: now used by 2 (attached,active-conn) <-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: vlr_gsupc_read_cb() returns 0 @@ -2451,7 +2451,7 @@ DVLR lu_compl_vlr_fsm(IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100:GERAN-A:LU){LU_COMPL_VLR_S_INIT}: state_chg to LU_COMPL_VLR_S_WAIT_SUB_PRES DVLR lu_compl_vlr_fsm(IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100:GERAN-A:LU){LU_COMPL_VLR_S_WAIT_SUB_PRES}: Received Event LU_COMPL_VLR_E_SUB_PRES_COMPL DVLR lu_compl_vlr_fsm(IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100:GERAN-A:LU){LU_COMPL_VLR_S_WAIT_SUB_PRES}: lu_compl_vlr_new_tmsi() -DVLR SUBSCR(IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100:TMSInew-0x07060504) VLR: update for IMSI=901700000004620 (MSISDN=46071) +DMSC msub(IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100:TMSInew-0x07060504) VLR: update for IMSI=901700000004620 (MSISDN=46071) DVLR lu_compl_vlr_fsm(IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100:GERAN-A:LU){LU_COMPL_VLR_S_WAIT_SUB_PRES}: state_chg to LU_COMPL_VLR_S_WAIT_TMSI_CNF - sending LU Accept for IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100:TMSInew-0x07060504:GERAN-A:LU, with TMSI 0x07060504 DVLR upd_hlr_vlr_fsm(IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100:GERAN-A:LU){UPD_HLR_VLR_S_DONE}: Deallocated @@ -2493,7 +2493,7 @@ DMM msc_a(IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100:TMSInew-0x07060504:GERAN-A:LU){MSC_A_ST_AUTH_CIPH}: TMSI Reallocation Completed DVLR vlr_lu_fsm(IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100:TMSInew-0x07060504:GERAN-A:LU){VLR_ULA_S_WAIT_LU_COMPL}: Received Event VLR_ULA_E_NEW_TMSI_ACK DVLR lu_compl_vlr_fsm(IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100:GERAN-A:LU){LU_COMPL_VLR_S_WAIT_TMSI_CNF}: Received Event LU_COMPL_VLR_E_NEW_TMSI_ACK -DVLR SUBSCR(IMSI-901700000004620:MSISDN-46071:TMSI-0x07060504) VLR: update for IMSI=901700000004620 (MSISDN=46071) +DMSC msub(IMSI-901700000004620:MSISDN-46071:TMSI-0x07060504) VLR: update for IMSI=901700000004620 (MSISDN=46071) DVLR lu_compl_vlr_fsm(IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100:GERAN-A:LU){LU_COMPL_VLR_S_WAIT_TMSI_CNF}: state_chg to LU_COMPL_VLR_S_DONE DVLR vlr_lu_fsm(IMSI-901700000004620:MSISDN-46071:TMSI-0x07060504:GERAN-A:LU){VLR_ULA_S_WAIT_LU_COMPL}: Received Event VLR_ULA_E_LU_COMPL_SUCCESS DVLR lu_compl_vlr_fsm(IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100:GERAN-A:LU){LU_COMPL_VLR_S_DONE}: Terminating (cause = OSMO_FSM_TERM_PARENT) @@ -2602,7 +2602,7 @@ DMSC dummy_msc_i(IMSI-901700000004620:MSISDN-46071:TMSI-0x07060504:GERAN-A:NONE){0}: Deferring: will deallocate with msc_a(IMSI-901700000004620:MSISDN-46071:TMSI-0x07060504:GERAN-A:NONE) DMSC msub(IMSI-901700000004620:MSISDN-46071:TMSI-0x07060504) Free DREF VLR subscr IMSI-901700000004620:MSISDN-46071:TMSI-0x07060504 - active-conn: now used by 0 (-) -DVLR freeing VLR subscr IMSI-901700000004620:MSISDN-46071:TMSI-0x07060504 (max total use count was 4) +DVLR SUBSCR(IMSI-901700000004620:MSISDN-46071:TMSI-0x07060504) freeing VLR subscr (max total use count was 4) DMSC msub_fsm{terminating}: Deferring: will deallocate with msc_a(IMSI-901700000004620:MSISDN-46071:TMSI-0x07060504:GERAN-A:NONE) DMSC msc_a(IMSI-901700000004620:MSISDN-46071:TMSI-0x07060504:GERAN-A:NONE){MSC_A_ST_RELEASED}: Deallocated, including all deferred deallocations - msub gone @@ -2686,7 +2686,7 @@ <-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: 10010809710000004026f00804036470f10a0101 DREF VLR subscr IMSI-901700000004620 + vlr_gsup_rx: now used by 2 (active-conn,vlr_gsup_rx) DVLR IMSI:901700000004620 has MSISDN:46071 -DVLR SUBSCR(IMSI-901700000004620:MSISDN-46071) VLR: update for IMSI=901700000004620 (MSISDN=46071) +DMSC msub(IMSI-901700000004620:MSISDN-46071) VLR: update for IMSI=901700000004620 (MSISDN=46071) GSUP --> HLR: OSMO_GSUP_MSGT_INSERT_DATA_RESULT: 12010809710000004026f00a0101 DREF VLR subscr IMSI-901700000004620:MSISDN-46071 - vlr_gsup_rx: now used by 1 (active-conn) <-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: vlr_gsupc_read_cb() returns 0 @@ -2727,7 +2727,7 @@ DVLR lu_compl_vlr_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){LU_COMPL_VLR_S_INIT}: state_chg to LU_COMPL_VLR_S_WAIT_SUB_PRES DVLR lu_compl_vlr_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){LU_COMPL_VLR_S_WAIT_SUB_PRES}: Received Event LU_COMPL_VLR_E_SUB_PRES_COMPL DVLR lu_compl_vlr_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){LU_COMPL_VLR_S_WAIT_SUB_PRES}: lu_compl_vlr_new_tmsi() -DVLR SUBSCR(IMSI-901700000004620:MSISDN-46071:TMSInew-0x03020100) VLR: update for IMSI=901700000004620 (MSISDN=46071) +DMSC msub(IMSI-901700000004620:MSISDN-46071:TMSInew-0x03020100) VLR: update for IMSI=901700000004620 (MSISDN=46071) DVLR lu_compl_vlr_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){LU_COMPL_VLR_S_WAIT_SUB_PRES}: state_chg to LU_COMPL_VLR_S_WAIT_TMSI_CNF - sending LU Accept for IMSI-901700000004620:MSISDN-46071:TMSInew-0x03020100:GERAN-A:LU, with TMSI 0x03020100 DVLR upd_hlr_vlr_fsm(IMSI-901700000004620:GERAN-A:LU){UPD_HLR_VLR_S_DONE}: Deallocated @@ -2762,7 +2762,7 @@ DMM msc_a(IMSI-901700000004620:MSISDN-46071:TMSInew-0x03020100:GERAN-A:LU){MSC_A_ST_AUTH_CIPH}: TMSI Reallocation Completed DVLR vlr_lu_fsm(IMSI-901700000004620:MSISDN-46071:TMSInew-0x03020100:GERAN-A:LU){VLR_ULA_S_WAIT_LU_COMPL}: Received Event VLR_ULA_E_NEW_TMSI_ACK DVLR lu_compl_vlr_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){LU_COMPL_VLR_S_WAIT_TMSI_CNF}: Received Event LU_COMPL_VLR_E_NEW_TMSI_ACK -DVLR SUBSCR(IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100) VLR: update for IMSI=901700000004620 (MSISDN=46071) +DMSC msub(IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100) VLR: update for IMSI=901700000004620 (MSISDN=46071) DREF VLR subscr IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100 + attached: now used by 2 (active-conn,attached) DVLR lu_compl_vlr_fsm(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){LU_COMPL_VLR_S_WAIT_TMSI_CNF}: state_chg to LU_COMPL_VLR_S_DONE DVLR vlr_lu_fsm(IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100:GERAN-A:LU){VLR_ULA_S_WAIT_LU_COMPL}: Received Event VLR_ULA_E_LU_COMPL_SUCCESS @@ -2872,7 +2872,7 @@ DMSC dummy_msc_i(IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100:GERAN-A:NONE){0}: Deferring: will deallocate with msc_a(IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100:GERAN-A:NONE) DMSC msub(IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100) Free DREF VLR subscr IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100 - active-conn: now used by 0 (-) -DVLR freeing VLR subscr IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100 (max total use count was 4) +DVLR SUBSCR(IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100) freeing VLR subscr (max total use count was 4) DMSC msub_fsm{terminating}: Deferring: will deallocate with msc_a(IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100:GERAN-A:NONE) DMSC msc_a(IMSI-901700000004620:MSISDN-46071:TMSI-0x03020100:GERAN-A:NONE){MSC_A_ST_RELEASED}: Deallocated, including all deferred deallocations - msub gone @@ -2930,7 +2930,7 @@ <-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: 10010809710000004026f00804036470f10a0101 DREF VLR subscr IMSI-901700000004620 + vlr_gsup_rx: now used by 2 (active-conn,vlr_gsup_rx) DVLR IMSI:901700000004620 has MSISDN:46071 -DVLR SUBSCR(IMSI-901700000004620:MSISDN-46071) VLR: update for IMSI=901700000004620 (MSISDN=46071) +DMSC msub(IMSI-901700000004620:MSISDN-46071) VLR: update for IMSI=901700000004620 (MSISDN=46071) GSUP --> HLR: OSMO_GSUP_MSGT_INSERT_DATA_RESULT: 12010809710000004026f00a0101 DREF VLR subscr IMSI-901700000004620:MSISDN-46071 - vlr_gsup_rx: now used by 1 (active-conn) <-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: vlr_gsupc_read_cb() returns 0 @@ -3011,7 +3011,7 @@ DREF VLR subscr IMSI-901700000004620:MSISDN-46071 - vlr_subscr_cancel_attach_fsm: now used by 1 (attached) DVLR set Last E-UTRAN PLMN ID on subscriber: (none) DREF VLR subscr IMSI-901700000004620:MSISDN-46071 - attached: now used by 0 (-) -DVLR freeing VLR subscr IMSI-901700000004620:MSISDN-46071 (max total use count was 5) +DVLR SUBSCR(IMSI-901700000004620:MSISDN-46071) freeing VLR subscr (max total use count was 5) llist_count(&msub_list) == 0 ===== test_no_authen_subscr_expire: SUCCESS diff --git a/tests/msc_vlr/msc_vlr_test_reject_concurrency.err b/tests/msc_vlr/msc_vlr_test_reject_concurrency.err index 25ccdfb..cdf1b3c 100644 --- a/tests/msc_vlr/msc_vlr_test_reject_concurrency.err +++ b/tests/msc_vlr/msc_vlr_test_reject_concurrency.err @@ -112,7 +112,7 @@ <-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: 10010809710000004026f00804036470f10a0101 DREF VLR subscr IMSI-901700000004620 + vlr_gsup_rx: now used by 2 (active-conn,vlr_gsup_rx) DVLR IMSI:901700000004620 has MSISDN:46071 -DVLR SUBSCR(IMSI-901700000004620:MSISDN-46071) VLR: update for IMSI=901700000004620 (MSISDN=46071) +DMSC msub(IMSI-901700000004620:MSISDN-46071) VLR: update for IMSI=901700000004620 (MSISDN=46071) GSUP --> HLR: OSMO_GSUP_MSGT_INSERT_DATA_RESULT: 12010809710000004026f00a0101 DREF VLR subscr IMSI-901700000004620:MSISDN-46071 - vlr_gsup_rx: now used by 1 (active-conn) <-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: vlr_gsupc_read_cb() returns 0 @@ -185,7 +185,7 @@ DMSC msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){MSC_A_ST_RELEASED}: Deallocated, including all deferred deallocations - msub gone llist_count(&msub_list) == 0 -DVLR freeing VLR subscr IMSI-901700000004620:MSISDN-46071 (max total use count was 5) +DVLR SUBSCR(IMSI-901700000004620:MSISDN-46071) freeing VLR subscr (max total use count was 5) ===== test_reject_2nd_conn: SUCCESS ===== test_reject_lu_during_lu @@ -253,7 +253,7 @@ <-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: 10010809710000004026f00804036470f10a0101 DREF VLR subscr IMSI-901700000004620 + vlr_gsup_rx: now used by 2 (active-conn,vlr_gsup_rx) DVLR IMSI:901700000004620 has MSISDN:46071 -DVLR SUBSCR(IMSI-901700000004620:MSISDN-46071) VLR: update for IMSI=901700000004620 (MSISDN=46071) +DMSC msub(IMSI-901700000004620:MSISDN-46071) VLR: update for IMSI=901700000004620 (MSISDN=46071) GSUP --> HLR: OSMO_GSUP_MSGT_INSERT_DATA_RESULT: 12010809710000004026f00a0101 DREF VLR subscr IMSI-901700000004620:MSISDN-46071 - vlr_gsup_rx: now used by 1 (active-conn) <-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: vlr_gsupc_read_cb() returns 0 @@ -326,7 +326,7 @@ DMSC msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){MSC_A_ST_RELEASED}: Deallocated, including all deferred deallocations - msub gone llist_count(&msub_list) == 0 -DVLR freeing VLR subscr IMSI-901700000004620:MSISDN-46071 (max total use count was 5) +DVLR SUBSCR(IMSI-901700000004620:MSISDN-46071) freeing VLR subscr (max total use count was 5) ===== test_reject_lu_during_lu: SUCCESS ===== test_reject_cm_during_lu @@ -399,7 +399,7 @@ <-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: 10010809710000004026f00804036470f10a0101 DREF VLR subscr IMSI-901700000004620 + vlr_gsup_rx: now used by 2 (active-conn,vlr_gsup_rx) DVLR IMSI:901700000004620 has MSISDN:46071 -DVLR SUBSCR(IMSI-901700000004620:MSISDN-46071) VLR: update for IMSI=901700000004620 (MSISDN=46071) +DMSC msub(IMSI-901700000004620:MSISDN-46071) VLR: update for IMSI=901700000004620 (MSISDN=46071) GSUP --> HLR: OSMO_GSUP_MSGT_INSERT_DATA_RESULT: 12010809710000004026f00a0101 DREF VLR subscr IMSI-901700000004620:MSISDN-46071 - vlr_gsup_rx: now used by 1 (active-conn) <-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: vlr_gsupc_read_cb() returns 0 @@ -472,7 +472,7 @@ DMSC msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){MSC_A_ST_RELEASED}: Deallocated, including all deferred deallocations - msub gone llist_count(&msub_list) == 0 -DVLR freeing VLR subscr IMSI-901700000004620:MSISDN-46071 (max total use count was 5) +DVLR SUBSCR(IMSI-901700000004620:MSISDN-46071) freeing VLR subscr (max total use count was 5) ===== test_reject_cm_during_lu: SUCCESS ===== test_reject_paging_resp_during_lu @@ -539,7 +539,7 @@ <-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: 10010809710000004026f00804036470f10a0101 DREF VLR subscr IMSI-901700000004620 + vlr_gsup_rx: now used by 2 (active-conn,vlr_gsup_rx) DVLR IMSI:901700000004620 has MSISDN:46071 -DVLR SUBSCR(IMSI-901700000004620:MSISDN-46071) VLR: update for IMSI=901700000004620 (MSISDN=46071) +DMSC msub(IMSI-901700000004620:MSISDN-46071) VLR: update for IMSI=901700000004620 (MSISDN=46071) GSUP --> HLR: OSMO_GSUP_MSGT_INSERT_DATA_RESULT: 12010809710000004026f00a0101 DREF VLR subscr IMSI-901700000004620:MSISDN-46071 - vlr_gsup_rx: now used by 1 (active-conn) <-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: vlr_gsupc_read_cb() returns 0 @@ -612,7 +612,7 @@ DMSC msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:LU){MSC_A_ST_RELEASED}: Deallocated, including all deferred deallocations - msub gone llist_count(&msub_list) == 0 -DVLR freeing VLR subscr IMSI-901700000004620:MSISDN-46071 (max total use count was 5) +DVLR SUBSCR(IMSI-901700000004620:MSISDN-46071) freeing VLR subscr (max total use count was 5) ===== test_reject_paging_resp_during_lu: SUCCESS ===== test_reject_lu_during_cm @@ -668,7 +668,7 @@ <-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: 10010809710000004026f00804036470f10a0101 DREF VLR subscr IMSI-901700000004620 + vlr_gsup_rx: now used by 2 (active-conn,vlr_gsup_rx) DVLR IMSI:901700000004620 has MSISDN:46071 -DVLR SUBSCR(IMSI-901700000004620:MSISDN-46071) VLR: update for IMSI=901700000004620 (MSISDN=46071) +DMSC msub(IMSI-901700000004620:MSISDN-46071) VLR: update for IMSI=901700000004620 (MSISDN=46071) GSUP --> HLR: OSMO_GSUP_MSGT_INSERT_DATA_RESULT: 12010809710000004026f00a0101 DREF VLR subscr IMSI-901700000004620:MSISDN-46071 - vlr_gsup_rx: now used by 1 (active-conn) <-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: vlr_gsupc_read_cb() returns 0 @@ -847,7 +847,7 @@ DMSC dummy_msc_i(IMSI-901700000004620:MSISDN-46071:GERAN-A:CM_SERVICE_REQ){0}: Deferring: will deallocate with msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:CM_SERVICE_REQ) DMSC msub(IMSI-901700000004620:MSISDN-46071) Free DREF VLR subscr IMSI-901700000004620:MSISDN-46071 - active-conn: now used by 0 (-) -DVLR freeing VLR subscr IMSI-901700000004620:MSISDN-46071 (max total use count was 5) +DVLR SUBSCR(IMSI-901700000004620:MSISDN-46071) freeing VLR subscr (max total use count was 5) DMSC msub_fsm{terminating}: Deferring: will deallocate with msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:CM_SERVICE_REQ) DMSC msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:CM_SERVICE_REQ){MSC_A_ST_RELEASED}: Deallocated, including all deferred deallocations - msub gone @@ -907,7 +907,7 @@ <-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: 10010809710000004026f00804036470f10a0101 DREF VLR subscr IMSI-901700000004620 + vlr_gsup_rx: now used by 2 (active-conn,vlr_gsup_rx) DVLR IMSI:901700000004620 has MSISDN:46071 -DVLR SUBSCR(IMSI-901700000004620:MSISDN-46071) VLR: update for IMSI=901700000004620 (MSISDN=46071) +DMSC msub(IMSI-901700000004620:MSISDN-46071) VLR: update for IMSI=901700000004620 (MSISDN=46071) GSUP --> HLR: OSMO_GSUP_MSGT_INSERT_DATA_RESULT: 12010809710000004026f00a0101 DREF VLR subscr IMSI-901700000004620:MSISDN-46071 - vlr_gsup_rx: now used by 1 (active-conn) <-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: vlr_gsupc_read_cb() returns 0 @@ -1091,7 +1091,7 @@ DMSC dummy_msc_i(IMSI-901700000004620:MSISDN-46071:GERAN-A:CM_SERVICE_REQ){0}: Deferring: will deallocate with msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:CM_SERVICE_REQ) DMSC msub(IMSI-901700000004620:MSISDN-46071) Free DREF VLR subscr IMSI-901700000004620:MSISDN-46071 - active-conn: now used by 0 (-) -DVLR freeing VLR subscr IMSI-901700000004620:MSISDN-46071 (max total use count was 5) +DVLR SUBSCR(IMSI-901700000004620:MSISDN-46071) freeing VLR subscr (max total use count was 5) DMSC msub_fsm{terminating}: Deferring: will deallocate with msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:CM_SERVICE_REQ) DMSC msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:CM_SERVICE_REQ){MSC_A_ST_RELEASED}: Deallocated, including all deferred deallocations - msub gone @@ -1151,7 +1151,7 @@ <-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: 10010809710000004026f00804036470f10a0101 DREF VLR subscr IMSI-901700000004620 + vlr_gsup_rx: now used by 2 (active-conn,vlr_gsup_rx) DVLR IMSI:901700000004620 has MSISDN:46071 -DVLR SUBSCR(IMSI-901700000004620:MSISDN-46071) VLR: update for IMSI=901700000004620 (MSISDN=46071) +DMSC msub(IMSI-901700000004620:MSISDN-46071) VLR: update for IMSI=901700000004620 (MSISDN=46071) GSUP --> HLR: OSMO_GSUP_MSGT_INSERT_DATA_RESULT: 12010809710000004026f00a0101 DREF VLR subscr IMSI-901700000004620:MSISDN-46071 - vlr_gsup_rx: now used by 1 (active-conn) <-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: vlr_gsupc_read_cb() returns 0 @@ -1322,7 +1322,7 @@ DMSC msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:CM_SERVICE_REQ){MSC_A_ST_RELEASED}: Deallocated, including all deferred deallocations - msub gone llist_count(&msub_list) == 0 -DVLR freeing VLR subscr IMSI-901700000004620:MSISDN-46071 (max total use count was 5) +DVLR SUBSCR(IMSI-901700000004620:MSISDN-46071) freeing VLR subscr (max total use count was 5) ===== test_reject_paging_resp_during_cm: SUCCESS ===== test_reject_lu_during_paging_resp @@ -1378,7 +1378,7 @@ <-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: 10010809710000004026f00804036470f10a0101 DREF VLR subscr IMSI-901700000004620 + vlr_gsup_rx: now used by 2 (active-conn,vlr_gsup_rx) DVLR IMSI:901700000004620 has MSISDN:46071 -DVLR SUBSCR(IMSI-901700000004620:MSISDN-46071) VLR: update for IMSI=901700000004620 (MSISDN=46071) +DMSC msub(IMSI-901700000004620:MSISDN-46071) VLR: update for IMSI=901700000004620 (MSISDN=46071) GSUP --> HLR: OSMO_GSUP_MSGT_INSERT_DATA_RESULT: 12010809710000004026f00a0101 DREF VLR subscr IMSI-901700000004620:MSISDN-46071 - vlr_gsup_rx: now used by 1 (active-conn) <-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: vlr_gsupc_read_cb() returns 0 @@ -1624,7 +1624,7 @@ - msub gone - SMS is done llist_count(&msub_list) == 0 -DVLR freeing VLR subscr IMSI-901700000004620:MSISDN-46071 (max total use count was 6) +DVLR SUBSCR(IMSI-901700000004620:MSISDN-46071) freeing VLR subscr (max total use count was 6) ===== test_reject_lu_during_paging_resp: SUCCESS ===== test_accept_cm_during_paging_resp @@ -1680,7 +1680,7 @@ <-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: 10010809710000004026f00804036470f10a0101 DREF VLR subscr IMSI-901700000004620 + vlr_gsup_rx: now used by 2 (active-conn,vlr_gsup_rx) DVLR IMSI:901700000004620 has MSISDN:46071 -DVLR SUBSCR(IMSI-901700000004620:MSISDN-46071) VLR: update for IMSI=901700000004620 (MSISDN=46071) +DMSC msub(IMSI-901700000004620:MSISDN-46071) VLR: update for IMSI=901700000004620 (MSISDN=46071) GSUP --> HLR: OSMO_GSUP_MSGT_INSERT_DATA_RESULT: 12010809710000004026f00a0101 DREF VLR subscr IMSI-901700000004620:MSISDN-46071 - vlr_gsup_rx: now used by 1 (active-conn) <-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: vlr_gsupc_read_cb() returns 0 @@ -1947,7 +1947,7 @@ DMSC dummy_msc_i(IMSI-901700000004620:MSISDN-46071:GERAN-A:CM_SERVICE_REQ){0}: Deferring: will deallocate with msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:CM_SERVICE_REQ) DMSC msub(IMSI-901700000004620:MSISDN-46071) Free DREF VLR subscr IMSI-901700000004620:MSISDN-46071 - active-conn: now used by 0 (-) -DVLR freeing VLR subscr IMSI-901700000004620:MSISDN-46071 (max total use count was 6) +DVLR SUBSCR(IMSI-901700000004620:MSISDN-46071) freeing VLR subscr (max total use count was 6) DMSC msub_fsm{terminating}: Deferring: will deallocate with msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:CM_SERVICE_REQ) DMSC msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:CM_SERVICE_REQ){MSC_A_ST_RELEASED}: Deallocated, including all deferred deallocations - msub gone @@ -2007,7 +2007,7 @@ <-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: 10010809710000004026f00804036470f10a0101 DREF VLR subscr IMSI-901700000004620 + vlr_gsup_rx: now used by 2 (active-conn,vlr_gsup_rx) DVLR IMSI:901700000004620 has MSISDN:46071 -DVLR SUBSCR(IMSI-901700000004620:MSISDN-46071) VLR: update for IMSI=901700000004620 (MSISDN=46071) +DMSC msub(IMSI-901700000004620:MSISDN-46071) VLR: update for IMSI=901700000004620 (MSISDN=46071) GSUP --> HLR: OSMO_GSUP_MSGT_INSERT_DATA_RESULT: 12010809710000004026f00a0101 DREF VLR subscr IMSI-901700000004620:MSISDN-46071 - vlr_gsup_rx: now used by 1 (active-conn) <-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: vlr_gsupc_read_cb() returns 0 @@ -2250,6 +2250,6 @@ - msub gone - SMS is done llist_count(&msub_list) == 0 -DVLR freeing VLR subscr IMSI-901700000004620:MSISDN-46071 (max total use count was 6) +DVLR SUBSCR(IMSI-901700000004620:MSISDN-46071) freeing VLR subscr (max total use count was 6) ===== test_reject_paging_resp_during_paging_resp: SUCCESS diff --git a/tests/msc_vlr/msc_vlr_test_rest.err b/tests/msc_vlr/msc_vlr_test_rest.err index 3a6442e..6af2c2e 100644 --- a/tests/msc_vlr/msc_vlr_test_rest.err +++ b/tests/msc_vlr/msc_vlr_test_rest.err @@ -109,7 +109,7 @@ <-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: 10010809710000004026f00804036470f10a0101 DREF VLR subscr IMSI-901700000004620 + vlr_gsup_rx: now used by 2 (active-conn,vlr_gsup_rx) DVLR IMSI:901700000004620 has MSISDN:46071 -DVLR SUBSCR(IMSI-901700000004620:MSISDN-46071) VLR: update for IMSI=901700000004620 (MSISDN=46071) +DMSC msub(IMSI-901700000004620:MSISDN-46071) VLR: update for IMSI=901700000004620 (MSISDN=46071) GSUP --> HLR: OSMO_GSUP_MSGT_INSERT_DATA_RESULT: 12010809710000004026f00a0101 DREF VLR subscr IMSI-901700000004620:MSISDN-46071 - vlr_gsup_rx: now used by 1 (active-conn) <-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: vlr_gsupc_read_cb() returns 0 @@ -251,7 +251,7 @@ <-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: 10010809710000004026f00804036470f10a0101 DREF VLR subscr IMSI-901700000004620:MSISDN-46071 + vlr_gsup_rx: now used by 3 (attached,active-conn,vlr_gsup_rx) DVLR IMSI:901700000004620 has MSISDN:46071 -DVLR SUBSCR(IMSI-901700000004620:MSISDN-46071) VLR: update for IMSI=901700000004620 (MSISDN=46071) +DMSC msub(IMSI-901700000004620:MSISDN-46071) VLR: update for IMSI=901700000004620 (MSISDN=46071) GSUP --> HLR: OSMO_GSUP_MSGT_INSERT_DATA_RESULT: 12010809710000004026f00a0101 DREF VLR subscr IMSI-901700000004620:MSISDN-46071 - vlr_gsup_rx: now used by 2 (attached,active-conn) <-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: vlr_gsupc_read_cb() returns 0 @@ -396,7 +396,7 @@ DMSC dummy_msc_i(IMSI-901700000004620:MSISDN-46071:GERAN-A:NONE){0}: Deferring: will deallocate with msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:NONE) DMSC msub(IMSI-901700000004620:MSISDN-46071) Free DREF VLR subscr IMSI-901700000004620:MSISDN-46071 - active-conn: now used by 0 (-) -DVLR freeing VLR subscr IMSI-901700000004620:MSISDN-46071 (max total use count was 5) +DVLR SUBSCR(IMSI-901700000004620:MSISDN-46071) freeing VLR subscr (max total use count was 5) DMSC msub_fsm{terminating}: Deferring: will deallocate with msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:NONE) DMSC msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:NONE){MSC_A_ST_RELEASED}: Deallocated, including all deferred deallocations - msub gone @@ -486,7 +486,7 @@ <-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: 10010809710000004026f00804036470f10a0101 DREF VLR subscr IMSI-901700000004620:TMSI-0x23422342 + vlr_gsup_rx: now used by 2 (active-conn,vlr_gsup_rx) DVLR IMSI:901700000004620 has MSISDN:46071 -DVLR SUBSCR(IMSI-901700000004620:MSISDN-46071:TMSI-0x23422342) VLR: update for IMSI=901700000004620 (MSISDN=46071) +DMSC msub(IMSI-901700000004620:MSISDN-46071:TMSI-0x23422342) VLR: update for IMSI=901700000004620 (MSISDN=46071) GSUP --> HLR: OSMO_GSUP_MSGT_INSERT_DATA_RESULT: 12010809710000004026f00a0101 DREF VLR subscr IMSI-901700000004620:MSISDN-46071:TMSI-0x23422342 - vlr_gsup_rx: now used by 1 (active-conn) <-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: vlr_gsupc_read_cb() returns 0 @@ -579,6 +579,6 @@ DMSC msc_a(IMSI-901700000004620:MSISDN-46071:TMSI-0x23422342:GERAN-A:LU){MSC_A_ST_RELEASED}: Deallocated, including all deferred deallocations - msub gone llist_count(&msub_list) == 0 -DVLR freeing VLR subscr IMSI-901700000004620:MSISDN-46071 (max total use count was 5) +DVLR SUBSCR(IMSI-901700000004620:MSISDN-46071) freeing VLR subscr (max total use count was 5) ===== test_lu_unknown_tmsi: SUCCESS diff --git a/tests/msc_vlr/msc_vlr_test_ss.err b/tests/msc_vlr/msc_vlr_test_ss.err index 8a1bd82..78f0881 100644 --- a/tests/msc_vlr/msc_vlr_test_ss.err +++ b/tests/msc_vlr/msc_vlr_test_ss.err @@ -47,7 +47,7 @@ <-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: 10010809710000004026f00804036470f10a0101 DREF VLR subscr IMSI-901700000004620 + vlr_gsup_rx: now used by 2 (active-conn,vlr_gsup_rx) DVLR IMSI:901700000004620 has MSISDN:46071 -DVLR SUBSCR(IMSI-901700000004620:MSISDN-46071) VLR: update for IMSI=901700000004620 (MSISDN=46071) +DMSC msub(IMSI-901700000004620:MSISDN-46071) VLR: update for IMSI=901700000004620 (MSISDN=46071) GSUP --> HLR: OSMO_GSUP_MSGT_INSERT_DATA_RESULT: 12010809710000004026f00a0101 DREF VLR subscr IMSI-901700000004620:MSISDN-46071 - vlr_gsup_rx: now used by 1 (active-conn) <-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: vlr_gsupc_read_cb() returns 0 @@ -234,7 +234,7 @@ DMSC msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:CM_SERVICE_REQ){MSC_A_ST_RELEASED}: Deallocated, including all deferred deallocations - msub gone llist_count(&msub_list) == 0 -DVLR freeing VLR subscr IMSI-901700000004620:MSISDN-46071 (max total use count was 5) +DVLR SUBSCR(IMSI-901700000004620:MSISDN-46071) freeing VLR subscr (max total use count was 5) ===== test_ss_ussd_mo_geran: SUCCESS ===== test_ss_ussd_no_geran @@ -286,7 +286,7 @@ <-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: 10010809710000004026f00804036470f10a0101 DREF VLR subscr IMSI-901700000004620 + vlr_gsup_rx: now used by 2 (active-conn,vlr_gsup_rx) DVLR IMSI:901700000004620 has MSISDN:46071 -DVLR SUBSCR(IMSI-901700000004620:MSISDN-46071) VLR: update for IMSI=901700000004620 (MSISDN=46071) +DMSC msub(IMSI-901700000004620:MSISDN-46071) VLR: update for IMSI=901700000004620 (MSISDN=46071) GSUP --> HLR: OSMO_GSUP_MSGT_INSERT_DATA_RESULT: 12010809710000004026f00a0101 DREF VLR subscr IMSI-901700000004620:MSISDN-46071 - vlr_gsup_rx: now used by 1 (active-conn) <-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: vlr_gsupc_read_cb() returns 0 @@ -498,6 +498,6 @@ DMSC msc_a(IMSI-901700000004620:MSISDN-46071:GERAN-A:PAGING_RESP){MSC_A_ST_RELEASED}: Deallocated, including all deferred deallocations - msub gone llist_count(&msub_list) == 0 -DVLR freeing VLR subscr IMSI-901700000004620:MSISDN-46071 (max total use count was 5) +DVLR SUBSCR(IMSI-901700000004620:MSISDN-46071) freeing VLR subscr (max total use count was 5) ===== test_ss_ussd_no_geran: SUCCESS diff --git a/tests/msc_vlr/msc_vlr_test_umts_authen.err b/tests/msc_vlr/msc_vlr_test_umts_authen.err index cf402cc..07b6660 100644 --- a/tests/msc_vlr/msc_vlr_test_umts_authen.err +++ b/tests/msc_vlr/msc_vlr_test_umts_authen.err @@ -86,7 +86,7 @@ <-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: 10010809710000000156f00804032443f20a0101 DREF VLR subscr IMSI-901700000010650 + vlr_gsup_rx: now used by 2 (active-conn,vlr_gsup_rx) DVLR IMSI:901700000010650 has MSISDN:42342 -DVLR SUBSCR(IMSI-901700000010650:MSISDN-42342) VLR: update for IMSI=901700000010650 (MSISDN=42342) +DMSC msub(IMSI-901700000010650:MSISDN-42342) VLR: update for IMSI=901700000010650 (MSISDN=42342) GSUP --> HLR: OSMO_GSUP_MSGT_INSERT_DATA_RESULT: 12010809710000000156f00a0101 DREF VLR subscr IMSI-901700000010650:MSISDN-42342 - vlr_gsup_rx: now used by 1 (active-conn) <-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: vlr_gsupc_read_cb() returns 0 @@ -107,7 +107,7 @@ DVLR lu_compl_vlr_fsm(IMSI-901700000010650:MSISDN-42342:GERAN-A:LU){LU_COMPL_VLR_S_INIT}: state_chg to LU_COMPL_VLR_S_WAIT_SUB_PRES DVLR lu_compl_vlr_fsm(IMSI-901700000010650:MSISDN-42342:GERAN-A:LU){LU_COMPL_VLR_S_WAIT_SUB_PRES}: Received Event LU_COMPL_VLR_E_SUB_PRES_COMPL DVLR lu_compl_vlr_fsm(IMSI-901700000010650:MSISDN-42342:GERAN-A:LU){LU_COMPL_VLR_S_WAIT_SUB_PRES}: lu_compl_vlr_new_tmsi() -DVLR SUBSCR(IMSI-901700000010650:MSISDN-42342:TMSInew-0x03020100) VLR: update for IMSI=901700000010650 (MSISDN=42342) +DMSC msub(IMSI-901700000010650:MSISDN-42342:TMSInew-0x03020100) VLR: update for IMSI=901700000010650 (MSISDN=42342) DVLR lu_compl_vlr_fsm(IMSI-901700000010650:MSISDN-42342:GERAN-A:LU){LU_COMPL_VLR_S_WAIT_SUB_PRES}: state_chg to LU_COMPL_VLR_S_WAIT_TMSI_CNF - sending LU Accept for IMSI-901700000010650:MSISDN-42342:TMSInew-0x03020100:GERAN-A:LU, with TMSI 0x03020100 DVLR upd_hlr_vlr_fsm(IMSI-901700000010650:GERAN-A:LU){UPD_HLR_VLR_S_DONE}: Deallocated @@ -149,7 +149,7 @@ DMM msc_a(IMSI-901700000010650:MSISDN-42342:TMSInew-0x03020100:GERAN-A:LU){MSC_A_ST_AUTH_CIPH}: TMSI Reallocation Completed DVLR vlr_lu_fsm(IMSI-901700000010650:MSISDN-42342:TMSInew-0x03020100:GERAN-A:LU){VLR_ULA_S_WAIT_LU_COMPL}: Received Event VLR_ULA_E_NEW_TMSI_ACK DVLR lu_compl_vlr_fsm(IMSI-901700000010650:MSISDN-42342:GERAN-A:LU){LU_COMPL_VLR_S_WAIT_TMSI_CNF}: Received Event LU_COMPL_VLR_E_NEW_TMSI_ACK -DVLR SUBSCR(IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100) VLR: update for IMSI=901700000010650 (MSISDN=42342) +DMSC msub(IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100) VLR: update for IMSI=901700000010650 (MSISDN=42342) DREF VLR subscr IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100 + attached: now used by 2 (active-conn,attached) DVLR lu_compl_vlr_fsm(IMSI-901700000010650:MSISDN-42342:GERAN-A:LU){LU_COMPL_VLR_S_WAIT_TMSI_CNF}: state_chg to LU_COMPL_VLR_S_DONE DVLR vlr_lu_fsm(IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100:GERAN-A:LU){VLR_ULA_S_WAIT_LU_COMPL}: Received Event VLR_ULA_E_LU_COMPL_SUCCESS @@ -598,7 +598,7 @@ DMSC dummy_msc_i(IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100:GERAN-A:NONE){0}: Deferring: will deallocate with msc_a(IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100:GERAN-A:NONE) DMSC msub(IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100) Free DREF VLR subscr IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100 - active-conn: now used by 0 (-) -DVLR freeing VLR subscr IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100 (max total use count was 6) +DVLR SUBSCR(IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100) freeing VLR subscr (max total use count was 6) DMSC msub_fsm{terminating}: Deferring: will deallocate with msc_a(IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100:GERAN-A:NONE) DMSC msc_a(IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100:GERAN-A:NONE){MSC_A_ST_RELEASED}: Deallocated, including all deferred deallocations - msub gone @@ -703,7 +703,7 @@ <-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: 10010809710000000156f00804032443f20a0101 DREF VLR subscr IMSI-901700000010650 + vlr_gsup_rx: now used by 2 (active-conn,vlr_gsup_rx) DVLR IMSI:901700000010650 has MSISDN:42342 -DVLR SUBSCR(IMSI-901700000010650:MSISDN-42342) VLR: update for IMSI=901700000010650 (MSISDN=42342) +DMSC msub(IMSI-901700000010650:MSISDN-42342) VLR: update for IMSI=901700000010650 (MSISDN=42342) GSUP --> HLR: OSMO_GSUP_MSGT_INSERT_DATA_RESULT: 12010809710000000156f00a0101 DREF VLR subscr IMSI-901700000010650:MSISDN-42342 - vlr_gsup_rx: now used by 1 (active-conn) <-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: vlr_gsupc_read_cb() returns 0 @@ -724,7 +724,7 @@ DVLR lu_compl_vlr_fsm(IMSI-901700000010650:MSISDN-42342:UTRAN-Iu:LU){LU_COMPL_VLR_S_INIT}: state_chg to LU_COMPL_VLR_S_WAIT_SUB_PRES DVLR lu_compl_vlr_fsm(IMSI-901700000010650:MSISDN-42342:UTRAN-Iu:LU){LU_COMPL_VLR_S_WAIT_SUB_PRES}: Received Event LU_COMPL_VLR_E_SUB_PRES_COMPL DVLR lu_compl_vlr_fsm(IMSI-901700000010650:MSISDN-42342:UTRAN-Iu:LU){LU_COMPL_VLR_S_WAIT_SUB_PRES}: lu_compl_vlr_new_tmsi() -DVLR SUBSCR(IMSI-901700000010650:MSISDN-42342:TMSInew-0x03020100) VLR: update for IMSI=901700000010650 (MSISDN=42342) +DMSC msub(IMSI-901700000010650:MSISDN-42342:TMSInew-0x03020100) VLR: update for IMSI=901700000010650 (MSISDN=42342) DVLR lu_compl_vlr_fsm(IMSI-901700000010650:MSISDN-42342:UTRAN-Iu:LU){LU_COMPL_VLR_S_WAIT_SUB_PRES}: state_chg to LU_COMPL_VLR_S_WAIT_TMSI_CNF - sending LU Accept for IMSI-901700000010650:MSISDN-42342:TMSInew-0x03020100:UTRAN-Iu:LU, with TMSI 0x03020100 DVLR upd_hlr_vlr_fsm(IMSI-901700000010650:UTRAN-Iu:LU){UPD_HLR_VLR_S_DONE}: Deallocated @@ -766,7 +766,7 @@ DMM msc_a(IMSI-901700000010650:MSISDN-42342:TMSInew-0x03020100:UTRAN-Iu:LU){MSC_A_ST_AUTH_CIPH}: TMSI Reallocation Completed DVLR vlr_lu_fsm(IMSI-901700000010650:MSISDN-42342:TMSInew-0x03020100:UTRAN-Iu:LU){VLR_ULA_S_WAIT_LU_COMPL}: Received Event VLR_ULA_E_NEW_TMSI_ACK DVLR lu_compl_vlr_fsm(IMSI-901700000010650:MSISDN-42342:UTRAN-Iu:LU){LU_COMPL_VLR_S_WAIT_TMSI_CNF}: Received Event LU_COMPL_VLR_E_NEW_TMSI_ACK -DVLR SUBSCR(IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100) VLR: update for IMSI=901700000010650 (MSISDN=42342) +DMSC msub(IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100) VLR: update for IMSI=901700000010650 (MSISDN=42342) DREF VLR subscr IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100 + attached: now used by 2 (active-conn,attached) DVLR lu_compl_vlr_fsm(IMSI-901700000010650:MSISDN-42342:UTRAN-Iu:LU){LU_COMPL_VLR_S_WAIT_TMSI_CNF}: state_chg to LU_COMPL_VLR_S_DONE DVLR vlr_lu_fsm(IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100:UTRAN-Iu:LU){VLR_ULA_S_WAIT_LU_COMPL}: Received Event VLR_ULA_E_LU_COMPL_SUCCESS @@ -1229,7 +1229,7 @@ DMSC dummy_msc_i(IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100:UTRAN-Iu:NONE){0}: Deferring: will deallocate with msc_a(IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100:UTRAN-Iu:NONE) DMSC msub(IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100) Free DREF VLR subscr IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100 - active-conn: now used by 0 (-) -DVLR freeing VLR subscr IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100 (max total use count was 6) +DVLR SUBSCR(IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100) freeing VLR subscr (max total use count was 6) DMSC msub_fsm{terminating}: Deferring: will deallocate with msc_a(IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100:UTRAN-Iu:NONE) DMSC msc_a(IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100:UTRAN-Iu:NONE){MSC_A_ST_RELEASED}: Deallocated, including all deferred deallocations - msub gone @@ -1334,7 +1334,7 @@ <-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: 10010809710000000156f00804032443f20a0101 DREF VLR subscr IMSI-901700000010650 + vlr_gsup_rx: now used by 2 (active-conn,vlr_gsup_rx) DVLR IMSI:901700000010650 has MSISDN:42342 -DVLR SUBSCR(IMSI-901700000010650:MSISDN-42342) VLR: update for IMSI=901700000010650 (MSISDN=42342) +DMSC msub(IMSI-901700000010650:MSISDN-42342) VLR: update for IMSI=901700000010650 (MSISDN=42342) GSUP --> HLR: OSMO_GSUP_MSGT_INSERT_DATA_RESULT: 12010809710000000156f00a0101 DREF VLR subscr IMSI-901700000010650:MSISDN-42342 - vlr_gsup_rx: now used by 1 (active-conn) <-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: vlr_gsupc_read_cb() returns 0 @@ -1355,7 +1355,7 @@ DVLR lu_compl_vlr_fsm(IMSI-901700000010650:MSISDN-42342:UTRAN-Iu:LU){LU_COMPL_VLR_S_INIT}: state_chg to LU_COMPL_VLR_S_WAIT_SUB_PRES DVLR lu_compl_vlr_fsm(IMSI-901700000010650:MSISDN-42342:UTRAN-Iu:LU){LU_COMPL_VLR_S_WAIT_SUB_PRES}: Received Event LU_COMPL_VLR_E_SUB_PRES_COMPL DVLR lu_compl_vlr_fsm(IMSI-901700000010650:MSISDN-42342:UTRAN-Iu:LU){LU_COMPL_VLR_S_WAIT_SUB_PRES}: lu_compl_vlr_new_tmsi() -DVLR SUBSCR(IMSI-901700000010650:MSISDN-42342:TMSInew-0x03020100) VLR: update for IMSI=901700000010650 (MSISDN=42342) +DMSC msub(IMSI-901700000010650:MSISDN-42342:TMSInew-0x03020100) VLR: update for IMSI=901700000010650 (MSISDN=42342) DVLR lu_compl_vlr_fsm(IMSI-901700000010650:MSISDN-42342:UTRAN-Iu:LU){LU_COMPL_VLR_S_WAIT_SUB_PRES}: state_chg to LU_COMPL_VLR_S_WAIT_TMSI_CNF - sending LU Accept for IMSI-901700000010650:MSISDN-42342:TMSInew-0x03020100:UTRAN-Iu:LU, with TMSI 0x03020100 DVLR upd_hlr_vlr_fsm(IMSI-901700000010650:UTRAN-Iu:LU){UPD_HLR_VLR_S_DONE}: Deallocated @@ -1397,7 +1397,7 @@ DMM msc_a(IMSI-901700000010650:MSISDN-42342:TMSInew-0x03020100:UTRAN-Iu:LU){MSC_A_ST_AUTH_CIPH}: TMSI Reallocation Completed DVLR vlr_lu_fsm(IMSI-901700000010650:MSISDN-42342:TMSInew-0x03020100:UTRAN-Iu:LU){VLR_ULA_S_WAIT_LU_COMPL}: Received Event VLR_ULA_E_NEW_TMSI_ACK DVLR lu_compl_vlr_fsm(IMSI-901700000010650:MSISDN-42342:UTRAN-Iu:LU){LU_COMPL_VLR_S_WAIT_TMSI_CNF}: Received Event LU_COMPL_VLR_E_NEW_TMSI_ACK -DVLR SUBSCR(IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100) VLR: update for IMSI=901700000010650 (MSISDN=42342) +DMSC msub(IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100) VLR: update for IMSI=901700000010650 (MSISDN=42342) DREF VLR subscr IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100 + attached: now used by 2 (active-conn,attached) DVLR lu_compl_vlr_fsm(IMSI-901700000010650:MSISDN-42342:UTRAN-Iu:LU){LU_COMPL_VLR_S_WAIT_TMSI_CNF}: state_chg to LU_COMPL_VLR_S_DONE DVLR vlr_lu_fsm(IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100:UTRAN-Iu:LU){VLR_ULA_S_WAIT_LU_COMPL}: Received Event VLR_ULA_E_LU_COMPL_SUCCESS @@ -1860,7 +1860,7 @@ DMSC dummy_msc_i(IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100:UTRAN-Iu:NONE){0}: Deferring: will deallocate with msc_a(IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100:UTRAN-Iu:NONE) DMSC msub(IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100) Free DREF VLR subscr IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100 - active-conn: now used by 0 (-) -DVLR freeing VLR subscr IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100 (max total use count was 6) +DVLR SUBSCR(IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100) freeing VLR subscr (max total use count was 6) DMSC msub_fsm{terminating}: Deferring: will deallocate with msc_a(IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100:UTRAN-Iu:NONE) DMSC msc_a(IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100:UTRAN-Iu:NONE){MSC_A_ST_RELEASED}: Deallocated, including all deferred deallocations - msub gone @@ -1983,7 +1983,7 @@ <-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: 10010809710000000156f00804032443f20a0101 DREF VLR subscr IMSI-901700000010650 + vlr_gsup_rx: now used by 2 (active-conn,vlr_gsup_rx) DVLR IMSI:901700000010650 has MSISDN:42342 -DVLR SUBSCR(IMSI-901700000010650:MSISDN-42342) VLR: update for IMSI=901700000010650 (MSISDN=42342) +DMSC msub(IMSI-901700000010650:MSISDN-42342) VLR: update for IMSI=901700000010650 (MSISDN=42342) GSUP --> HLR: OSMO_GSUP_MSGT_INSERT_DATA_RESULT: 12010809710000000156f00a0101 DREF VLR subscr IMSI-901700000010650:MSISDN-42342 - vlr_gsup_rx: now used by 1 (active-conn) <-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: vlr_gsupc_read_cb() returns 0 @@ -2004,7 +2004,7 @@ DVLR lu_compl_vlr_fsm(IMSI-901700000010650:MSISDN-42342:GERAN-A:LU){LU_COMPL_VLR_S_INIT}: state_chg to LU_COMPL_VLR_S_WAIT_SUB_PRES DVLR lu_compl_vlr_fsm(IMSI-901700000010650:MSISDN-42342:GERAN-A:LU){LU_COMPL_VLR_S_WAIT_SUB_PRES}: Received Event LU_COMPL_VLR_E_SUB_PRES_COMPL DVLR lu_compl_vlr_fsm(IMSI-901700000010650:MSISDN-42342:GERAN-A:LU){LU_COMPL_VLR_S_WAIT_SUB_PRES}: lu_compl_vlr_new_tmsi() -DVLR SUBSCR(IMSI-901700000010650:MSISDN-42342:TMSInew-0x03020100) VLR: update for IMSI=901700000010650 (MSISDN=42342) +DMSC msub(IMSI-901700000010650:MSISDN-42342:TMSInew-0x03020100) VLR: update for IMSI=901700000010650 (MSISDN=42342) DVLR lu_compl_vlr_fsm(IMSI-901700000010650:MSISDN-42342:GERAN-A:LU){LU_COMPL_VLR_S_WAIT_SUB_PRES}: state_chg to LU_COMPL_VLR_S_WAIT_TMSI_CNF - sending LU Accept for IMSI-901700000010650:MSISDN-42342:TMSInew-0x03020100:GERAN-A:LU, with TMSI 0x03020100 DVLR upd_hlr_vlr_fsm(IMSI-901700000010650:GERAN-A:LU){UPD_HLR_VLR_S_DONE}: Deallocated @@ -2046,7 +2046,7 @@ DMM msc_a(IMSI-901700000010650:MSISDN-42342:TMSInew-0x03020100:GERAN-A:LU){MSC_A_ST_AUTH_CIPH}: TMSI Reallocation Completed DVLR vlr_lu_fsm(IMSI-901700000010650:MSISDN-42342:TMSInew-0x03020100:GERAN-A:LU){VLR_ULA_S_WAIT_LU_COMPL}: Received Event VLR_ULA_E_NEW_TMSI_ACK DVLR lu_compl_vlr_fsm(IMSI-901700000010650:MSISDN-42342:GERAN-A:LU){LU_COMPL_VLR_S_WAIT_TMSI_CNF}: Received Event LU_COMPL_VLR_E_NEW_TMSI_ACK -DVLR SUBSCR(IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100) VLR: update for IMSI=901700000010650 (MSISDN=42342) +DMSC msub(IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100) VLR: update for IMSI=901700000010650 (MSISDN=42342) DREF VLR subscr IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100 + attached: now used by 2 (active-conn,attached) DVLR lu_compl_vlr_fsm(IMSI-901700000010650:MSISDN-42342:GERAN-A:LU){LU_COMPL_VLR_S_WAIT_TMSI_CNF}: state_chg to LU_COMPL_VLR_S_DONE DVLR vlr_lu_fsm(IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100:GERAN-A:LU){VLR_ULA_S_WAIT_LU_COMPL}: Received Event VLR_ULA_E_LU_COMPL_SUCCESS @@ -2096,7 +2096,7 @@ - msub gone - LU was successful, and the conn has already been closed llist_count(&msub_list) == 0 -DVLR freeing VLR subscr IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100 (max total use count was 4) +DVLR SUBSCR(IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100) freeing VLR subscr (max total use count was 4) ===== test_umts_authen_resync_geran: SUCCESS ===== test_umts_authen_resync_utran @@ -2225,7 +2225,7 @@ <-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: 10010809710000000156f00804032443f20a0101 DREF VLR subscr IMSI-901700000010650 + vlr_gsup_rx: now used by 2 (active-conn,vlr_gsup_rx) DVLR IMSI:901700000010650 has MSISDN:42342 -DVLR SUBSCR(IMSI-901700000010650:MSISDN-42342) VLR: update for IMSI=901700000010650 (MSISDN=42342) +DMSC msub(IMSI-901700000010650:MSISDN-42342) VLR: update for IMSI=901700000010650 (MSISDN=42342) GSUP --> HLR: OSMO_GSUP_MSGT_INSERT_DATA_RESULT: 12010809710000000156f00a0101 DREF VLR subscr IMSI-901700000010650:MSISDN-42342 - vlr_gsup_rx: now used by 1 (active-conn) <-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: vlr_gsupc_read_cb() returns 0 @@ -2246,7 +2246,7 @@ DVLR lu_compl_vlr_fsm(IMSI-901700000010650:MSISDN-42342:UTRAN-Iu:LU){LU_COMPL_VLR_S_INIT}: state_chg to LU_COMPL_VLR_S_WAIT_SUB_PRES DVLR lu_compl_vlr_fsm(IMSI-901700000010650:MSISDN-42342:UTRAN-Iu:LU){LU_COMPL_VLR_S_WAIT_SUB_PRES}: Received Event LU_COMPL_VLR_E_SUB_PRES_COMPL DVLR lu_compl_vlr_fsm(IMSI-901700000010650:MSISDN-42342:UTRAN-Iu:LU){LU_COMPL_VLR_S_WAIT_SUB_PRES}: lu_compl_vlr_new_tmsi() -DVLR SUBSCR(IMSI-901700000010650:MSISDN-42342:TMSInew-0x03020100) VLR: update for IMSI=901700000010650 (MSISDN=42342) +DMSC msub(IMSI-901700000010650:MSISDN-42342:TMSInew-0x03020100) VLR: update for IMSI=901700000010650 (MSISDN=42342) DVLR lu_compl_vlr_fsm(IMSI-901700000010650:MSISDN-42342:UTRAN-Iu:LU){LU_COMPL_VLR_S_WAIT_SUB_PRES}: state_chg to LU_COMPL_VLR_S_WAIT_TMSI_CNF - sending LU Accept for IMSI-901700000010650:MSISDN-42342:TMSInew-0x03020100:UTRAN-Iu:LU, with TMSI 0x03020100 DVLR upd_hlr_vlr_fsm(IMSI-901700000010650:UTRAN-Iu:LU){UPD_HLR_VLR_S_DONE}: Deallocated @@ -2288,7 +2288,7 @@ DMM msc_a(IMSI-901700000010650:MSISDN-42342:TMSInew-0x03020100:UTRAN-Iu:LU){MSC_A_ST_AUTH_CIPH}: TMSI Reallocation Completed DVLR vlr_lu_fsm(IMSI-901700000010650:MSISDN-42342:TMSInew-0x03020100:UTRAN-Iu:LU){VLR_ULA_S_WAIT_LU_COMPL}: Received Event VLR_ULA_E_NEW_TMSI_ACK DVLR lu_compl_vlr_fsm(IMSI-901700000010650:MSISDN-42342:UTRAN-Iu:LU){LU_COMPL_VLR_S_WAIT_TMSI_CNF}: Received Event LU_COMPL_VLR_E_NEW_TMSI_ACK -DVLR SUBSCR(IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100) VLR: update for IMSI=901700000010650 (MSISDN=42342) +DMSC msub(IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100) VLR: update for IMSI=901700000010650 (MSISDN=42342) DREF VLR subscr IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100 + attached: now used by 2 (active-conn,attached) DVLR lu_compl_vlr_fsm(IMSI-901700000010650:MSISDN-42342:UTRAN-Iu:LU){LU_COMPL_VLR_S_WAIT_TMSI_CNF}: state_chg to LU_COMPL_VLR_S_DONE DVLR vlr_lu_fsm(IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100:UTRAN-Iu:LU){VLR_ULA_S_WAIT_LU_COMPL}: Received Event VLR_ULA_E_LU_COMPL_SUCCESS @@ -2338,7 +2338,7 @@ - msub gone - LU was successful, and the conn has already been closed llist_count(&msub_list) == 0 -DVLR freeing VLR subscr IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100 (max total use count was 4) +DVLR SUBSCR(IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100) freeing VLR subscr (max total use count was 4) ===== test_umts_authen_resync_utran: SUCCESS ===== test_umts_auth_ciph_resync_utran @@ -2467,7 +2467,7 @@ <-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: 10010809710000000156f00804032443f20a0101 DREF VLR subscr IMSI-901700000010650 + vlr_gsup_rx: now used by 2 (active-conn,vlr_gsup_rx) DVLR IMSI:901700000010650 has MSISDN:42342 -DVLR SUBSCR(IMSI-901700000010650:MSISDN-42342) VLR: update for IMSI=901700000010650 (MSISDN=42342) +DMSC msub(IMSI-901700000010650:MSISDN-42342) VLR: update for IMSI=901700000010650 (MSISDN=42342) GSUP --> HLR: OSMO_GSUP_MSGT_INSERT_DATA_RESULT: 12010809710000000156f00a0101 DREF VLR subscr IMSI-901700000010650:MSISDN-42342 - vlr_gsup_rx: now used by 1 (active-conn) <-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: vlr_gsupc_read_cb() returns 0 @@ -2488,7 +2488,7 @@ DVLR lu_compl_vlr_fsm(IMSI-901700000010650:MSISDN-42342:UTRAN-Iu:LU){LU_COMPL_VLR_S_INIT}: state_chg to LU_COMPL_VLR_S_WAIT_SUB_PRES DVLR lu_compl_vlr_fsm(IMSI-901700000010650:MSISDN-42342:UTRAN-Iu:LU){LU_COMPL_VLR_S_WAIT_SUB_PRES}: Received Event LU_COMPL_VLR_E_SUB_PRES_COMPL DVLR lu_compl_vlr_fsm(IMSI-901700000010650:MSISDN-42342:UTRAN-Iu:LU){LU_COMPL_VLR_S_WAIT_SUB_PRES}: lu_compl_vlr_new_tmsi() -DVLR SUBSCR(IMSI-901700000010650:MSISDN-42342:TMSInew-0x03020100) VLR: update for IMSI=901700000010650 (MSISDN=42342) +DMSC msub(IMSI-901700000010650:MSISDN-42342:TMSInew-0x03020100) VLR: update for IMSI=901700000010650 (MSISDN=42342) DVLR lu_compl_vlr_fsm(IMSI-901700000010650:MSISDN-42342:UTRAN-Iu:LU){LU_COMPL_VLR_S_WAIT_SUB_PRES}: state_chg to LU_COMPL_VLR_S_WAIT_TMSI_CNF - sending LU Accept for IMSI-901700000010650:MSISDN-42342:TMSInew-0x03020100:UTRAN-Iu:LU, with TMSI 0x03020100 DVLR upd_hlr_vlr_fsm(IMSI-901700000010650:UTRAN-Iu:LU){UPD_HLR_VLR_S_DONE}: Deallocated @@ -2530,7 +2530,7 @@ DMM msc_a(IMSI-901700000010650:MSISDN-42342:TMSInew-0x03020100:UTRAN-Iu:LU){MSC_A_ST_AUTH_CIPH}: TMSI Reallocation Completed DVLR vlr_lu_fsm(IMSI-901700000010650:MSISDN-42342:TMSInew-0x03020100:UTRAN-Iu:LU){VLR_ULA_S_WAIT_LU_COMPL}: Received Event VLR_ULA_E_NEW_TMSI_ACK DVLR lu_compl_vlr_fsm(IMSI-901700000010650:MSISDN-42342:UTRAN-Iu:LU){LU_COMPL_VLR_S_WAIT_TMSI_CNF}: Received Event LU_COMPL_VLR_E_NEW_TMSI_ACK -DVLR SUBSCR(IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100) VLR: update for IMSI=901700000010650 (MSISDN=42342) +DMSC msub(IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100) VLR: update for IMSI=901700000010650 (MSISDN=42342) DREF VLR subscr IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100 + attached: now used by 2 (active-conn,attached) DVLR lu_compl_vlr_fsm(IMSI-901700000010650:MSISDN-42342:UTRAN-Iu:LU){LU_COMPL_VLR_S_WAIT_TMSI_CNF}: state_chg to LU_COMPL_VLR_S_DONE DVLR vlr_lu_fsm(IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100:UTRAN-Iu:LU){VLR_ULA_S_WAIT_LU_COMPL}: Received Event VLR_ULA_E_LU_COMPL_SUCCESS @@ -2580,7 +2580,7 @@ - msub gone - LU was successful, and the conn has already been closed llist_count(&msub_list) == 0 -DVLR freeing VLR subscr IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100 (max total use count was 4) +DVLR SUBSCR(IMSI-901700000010650:MSISDN-42342:TMSI-0x03020100) freeing VLR subscr (max total use count was 4) ===== test_umts_auth_ciph_resync_utran: SUCCESS ===== test_umts_authen_too_short_res_geran @@ -2692,7 +2692,7 @@ DMSC dummy_msc_i(IMSI-901700000010650:GERAN-A:LU){0}: Deferring: will deallocate with msc_a(IMSI-901700000010650:GERAN-A:LU) DMSC msub(IMSI-901700000010650) Free DREF VLR subscr IMSI-901700000010650 - active-conn: now used by 0 (-) -DVLR freeing VLR subscr IMSI-901700000010650 (max total use count was 3) +DVLR SUBSCR(IMSI-901700000010650) freeing VLR subscr (max total use count was 3) DMSC msub_fsm{terminating}: Deferring: will deallocate with msc_a(IMSI-901700000010650:GERAN-A:LU) DMSC msc_a(IMSI-901700000010650:GERAN-A:LU){MSC_A_ST_RELEASED}: Deallocated, including all deferred deallocations - msub gone @@ -2808,7 +2808,7 @@ DMSC dummy_msc_i(IMSI-901700000010650:UTRAN-Iu:LU){0}: Deferring: will deallocate with msc_a(IMSI-901700000010650:UTRAN-Iu:LU) DMSC msub(IMSI-901700000010650) Free DREF VLR subscr IMSI-901700000010650 - active-conn: now used by 0 (-) -DVLR freeing VLR subscr IMSI-901700000010650 (max total use count was 3) +DVLR SUBSCR(IMSI-901700000010650) freeing VLR subscr (max total use count was 3) DMSC msub_fsm{terminating}: Deferring: will deallocate with msc_a(IMSI-901700000010650:UTRAN-Iu:LU) DMSC msc_a(IMSI-901700000010650:UTRAN-Iu:LU){MSC_A_ST_RELEASED}: Deallocated, including all deferred deallocations - msub gone @@ -2924,7 +2924,7 @@ DMSC dummy_msc_i(IMSI-901700000010650:GERAN-A:LU){0}: Deferring: will deallocate with msc_a(IMSI-901700000010650:GERAN-A:LU) DMSC msub(IMSI-901700000010650) Free DREF VLR subscr IMSI-901700000010650 - active-conn: now used by 0 (-) -DVLR freeing VLR subscr IMSI-901700000010650 (max total use count was 3) +DVLR SUBSCR(IMSI-901700000010650) freeing VLR subscr (max total use count was 3) DMSC msub_fsm{terminating}: Deferring: will deallocate with msc_a(IMSI-901700000010650:GERAN-A:LU) DMSC msc_a(IMSI-901700000010650:GERAN-A:LU){MSC_A_ST_RELEASED}: Deallocated, including all deferred deallocations - msub gone @@ -3040,7 +3040,7 @@ DMSC dummy_msc_i(IMSI-901700000010650:UTRAN-Iu:LU){0}: Deferring: will deallocate with msc_a(IMSI-901700000010650:UTRAN-Iu:LU) DMSC msub(IMSI-901700000010650) Free DREF VLR subscr IMSI-901700000010650 - active-conn: now used by 0 (-) -DVLR freeing VLR subscr IMSI-901700000010650 (max total use count was 3) +DVLR SUBSCR(IMSI-901700000010650) freeing VLR subscr (max total use count was 3) DMSC msub_fsm{terminating}: Deferring: will deallocate with msc_a(IMSI-901700000010650:UTRAN-Iu:LU) DMSC msc_a(IMSI-901700000010650:UTRAN-Iu:LU){MSC_A_ST_RELEASED}: Deallocated, including all deferred deallocations - msub gone @@ -3156,7 +3156,7 @@ DMSC dummy_msc_i(IMSI-901700000010650:GERAN-A:LU){0}: Deferring: will deallocate with msc_a(IMSI-901700000010650:GERAN-A:LU) DMSC msub(IMSI-901700000010650) Free DREF VLR subscr IMSI-901700000010650 - active-conn: now used by 0 (-) -DVLR freeing VLR subscr IMSI-901700000010650 (max total use count was 3) +DVLR SUBSCR(IMSI-901700000010650) freeing VLR subscr (max total use count was 3) DMSC msub_fsm{terminating}: Deferring: will deallocate with msc_a(IMSI-901700000010650:GERAN-A:LU) DMSC msc_a(IMSI-901700000010650:GERAN-A:LU){MSC_A_ST_RELEASED}: Deallocated, including all deferred deallocations - msub gone @@ -3272,7 +3272,7 @@ DMSC dummy_msc_i(IMSI-901700000010650:UTRAN-Iu:LU){0}: Deferring: will deallocate with msc_a(IMSI-901700000010650:UTRAN-Iu:LU) DMSC msub(IMSI-901700000010650) Free DREF VLR subscr IMSI-901700000010650 - active-conn: now used by 0 (-) -DVLR freeing VLR subscr IMSI-901700000010650 (max total use count was 3) +DVLR SUBSCR(IMSI-901700000010650) freeing VLR subscr (max total use count was 3) DMSC msub_fsm{terminating}: Deferring: will deallocate with msc_a(IMSI-901700000010650:UTRAN-Iu:LU) DMSC msc_a(IMSI-901700000010650:UTRAN-Iu:LU){MSC_A_ST_RELEASED}: Deallocated, including all deferred deallocations - msub gone diff --git a/tests/msc_vlr/msc_vlr_tests.c b/tests/msc_vlr/msc_vlr_tests.c index 7bf975c..c1ae650 100644 --- a/tests/msc_vlr/msc_vlr_tests.c +++ b/tests/msc_vlr/msc_vlr_tests.c @@ -1253,6 +1253,9 @@ msgb_ctx = msgb_talloc_ctx_init(msc_vlr_tests_ctx, 0); osmo_init_logging2(msc_vlr_tests_ctx, &info); + osmo_vlr_set_log_cat(OSMO_VLR_LOGC_VLR, DVLR); + osmo_vlr_set_log_cat(OSMO_VLR_LOGC_SGS, DSGS); + _log_lines = cmdline_opts.verbose; OSMO_ASSERT(osmo_stderr_target); -- To view, visit https://gerrit.osmocom.org/c/osmo-msc/+/38410?usp=email To unsubscribe, or for help writing mail filters, visit https://gerrit.osmocom.org/settings?usp=email Gerrit-MessageType: merged Gerrit-Project: osmo-msc Gerrit-Branch: master Gerrit-Change-Id: I6d87b38d6d7d704c7c7b2c90ad12187e4b953b8b Gerrit-Change-Number: 38410 Gerrit-PatchSet: 7 Gerrit-Owner: lynxis lazus &lt;lynxis(a)fe80.eu&gt; Gerrit-Reviewer: Jenkins Builder Gerrit-Reviewer: daniel &lt;dwillmann(a)sysmocom.de&gt; Gerrit-Reviewer: laforge &lt;laforge(a)osmocom.org&gt; Gerrit-Reviewer: pespin &lt;pespin(a)sysmocom.de&gt;