cellular-infrastructure
/
osmo-msc
mirror of https://gerrit.osmocom.org/osmo-msc
9
0
Fork 0
Code Issues Releases Wiki Activity

A5/n Ciph: request Classmark Update if missing 

When the VLR requests a Ciphering Mode with vlr_ops.set_ciph_mode(), and if we
need a ciph algo flag from a Classmark information that is not yet known
(usually CM 2 during LU), send a BSSMAP Classmark Request to get it.

To manage the intermission of the Classmark Request, add
- msc_classmark_request_then_cipher_mode_cmd(),
- state SUBSCR_CONN_S_WAIT_CLASSMARK_UPDATE,
- event SUBSCR_CONN_E_CLASSMARK_UPDATE.

From state AUTH_CIPH, switch to state WAIT_CLASSMARK_UPDATE. Once the BSSMAP
Classmark Response, is received, switch back to SUBSCR_CONN_S_AUTH_CIPH and
re-initiate Ciphering Mode.

To be able to re-enter the Ciphering Mode algo decision, factor it out into
msc_geran_set_cipher_mode().

Rationale:

In the following commit, essentially we stopped supporting A5/3 ciphering:

commit 71330720b6
"MSC: Intersect configured A5 algorithms with MS-supported ones"
Change-Id: Id124923ee52a357cb7d3e04d33f585214774f3a3

A5/3 was no longer supported because from that commit on, we strictly checked
the MS-supported ciphers, but we did not have Classmark 2 available during
Location Updating.

This patch changes that: when Classmark 2 is missing, actively request it by a
BSSMAP Classmark Request; continue Ciphering only after the Response. Always
request missing Classmark, even if a lesser cipher were configured available.

If the Classmark Update response fails to come in, cause an attach failure.
Instead, we could attempt to use a lesser cipher that is also enabled. That is
left as a future feature, should that become relevant. I think it's unlikely.

Technically, we could now end up requesting a Classmark Updating both during LU
(vlr_lu_fsm) and CM Service/Paging Response (proc_arq_fsm), but in practice the
only time we lack a Classmark is: during Location Updating with A5/3 enabled.
A5/1 support is indicated in CM1 which is always available, and A5/3 support is
indicated in CM2, which is always available during CM Service Request as well
as Paging Response. So this patch has practical relevance only for Location
Updating. For networks that permit only A5/3, this patch fixes Location
Updating. For networks that support A5/3 and A5/1, so far we always used A5/1
during LU, and after this patch we request CM2 and likely use A5/3 instead.

In msc_vlr_test_gsm_ciph, verify that requesting Classmark 2 for A5/3 works
during LU. Also verify that the lack of a Classmark Response results in attach
failure.

In msc_vlr_test_gsm_ciph, a hacky unit test fakes a situation where a CM2 is
missing during proc_arq_fsm and proves that that code path works, even though
the practical relevance is currently zero. It would only become interesting if
ciphering algorithms A5/4 and higher became relevant, because support of those
would be indicated in Classmark 3, which would always require a Classmark
Request.

Related: OS#3043
Depends: I4a2e1d3923e33912579c4180aa1ff8e8f5abb7e7 (libosmocore)
Change-Id: I73c7cb6a86624695bd9c0f59abb72e2fdc655131
This commit is contained in:
Neels Hofmeyr 2018-09-13 03:23:07 +02:00
parent d28ea6c8c3
commit 3117b701c8
14 changed files with 1757 additions and 75 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

2
include/osmocom/msc/a_iface.h
View File

@ -78,6 +78,8 @@ int a_iface_tx_assignment(const struct gsm_trans *trans);
/* Send clear command via A-interface */ /* Send clear command via A-interface */
int a_iface_tx_clear_cmd(struct gsm_subscriber_connection *conn); int a_iface_tx_clear_cmd(struct gsm_subscriber_connection *conn);
int a_iface_tx_classmark_request(const struct gsm_subscriber_connection *conn);
/* Clear all subscriber connections on a specified BSC /* Clear all subscriber connections on a specified BSC
* (Helper function for a_iface_bssap.c) */ * (Helper function for a_iface_bssap.c) */
void a_clear_all(struct osmo_sccp_user *scu, const struct osmo_sccp_addr *bsc_addr); void a_clear_all(struct osmo_sccp_user *scu, const struct osmo_sccp_addr *bsc_addr);

7
include/osmocom/msc/gsm_data.h
View File

@ -130,6 +130,13 @@ struct gsm_subscriber_connection {
uint16_t lac; uint16_t lac;
struct gsm_encr encr; struct gsm_encr encr;
/* "Temporary" storage for the case the VLR asked for Cipher Mode Command, but the MSC still
* wants to request a Classmark Update first. */
struct {
bool umts_aka;
bool retrieve_imeisv;
} geran_set_cipher_mode;
/* N(SD) expected in the received frame, per flow (TS 24.007 11.2.3.2.3.2.2) */ /* N(SD) expected in the received frame, per flow (TS 24.007 11.2.3.2.3.2.2) */
uint8_t n_sd_next[4]; uint8_t n_sd_next[4];

6
include/osmocom/msc/osmo_msc.h
View File

@ -16,6 +16,8 @@ enum subscr_conn_fsm_event {
SUBSCR_CONN_E_INVALID = 0, SUBSCR_CONN_E_INVALID = 0,
/* Accepted the initial Complete Layer 3 (starting to evaluate Authentication and Ciphering) */ /* Accepted the initial Complete Layer 3 (starting to evaluate Authentication and Ciphering) */
SUBSCR_CONN_E_COMPLETE_LAYER_3, SUBSCR_CONN_E_COMPLETE_LAYER_3,
/* Received Classmark Update, typically neede for Ciphering Mode Command */
SUBSCR_CONN_E_CLASSMARK_UPDATE,
/* LU or Process Access FSM has determined that this conn is good */ /* LU or Process Access FSM has determined that this conn is good */
SUBSCR_CONN_E_ACCEPTED, SUBSCR_CONN_E_ACCEPTED,
/* received first reply from MS in "real" CC, SMS, USSD communication */ /* received first reply from MS in "real" CC, SMS, USSD communication */
@ -33,6 +35,7 @@ enum subscr_conn_fsm_event {
enum subscr_conn_fsm_state { enum subscr_conn_fsm_state {
SUBSCR_CONN_S_NEW, SUBSCR_CONN_S_NEW,
SUBSCR_CONN_S_AUTH_CIPH, SUBSCR_CONN_S_AUTH_CIPH,
SUBSCR_CONN_S_WAIT_CLASSMARK_UPDATE,
SUBSCR_CONN_S_ACCEPTED, SUBSCR_CONN_S_ACCEPTED,
SUBSCR_CONN_S_COMMUNICATING, SUBSCR_CONN_S_COMMUNICATING,
SUBSCR_CONN_S_RELEASING, SUBSCR_CONN_S_RELEASING,
@ -62,6 +65,9 @@ int msc_compl_l3(struct gsm_subscriber_connection *conn,
struct msgb *msg, uint16_t chosen_channel); struct msgb *msg, uint16_t chosen_channel);
void msc_dtap(struct gsm_subscriber_connection *conn, uint8_t link_id, void msc_dtap(struct gsm_subscriber_connection *conn, uint8_t link_id,
struct msgb *msg); struct msgb *msg);
int msc_classmark_request_then_cipher_mode_cmd(struct gsm_subscriber_connection *conn, bool umts_aka,
bool retrieve_imeisv);
int msc_geran_set_cipher_mode(struct gsm_subscriber_connection *conn, bool umts_aka, bool retrieve_imeisv);
void msc_cipher_mode_compl(struct gsm_subscriber_connection *conn, void msc_cipher_mode_compl(struct gsm_subscriber_connection *conn,
struct msgb *msg, uint8_t alg_id); struct msgb *msg, uint8_t alg_id);
void msc_rx_sec_mode_compl(struct gsm_subscriber_connection *conn); void msc_rx_sec_mode_compl(struct gsm_subscriber_connection *conn);

10
src/libmsc/a_iface.c
View File

@ -422,6 +422,16 @@ int a_iface_tx_clear_cmd(struct gsm_subscriber_connection *conn)
return osmo_sccp_tx_data_msg(conn->a.scu, conn->a.conn_id, msg); return osmo_sccp_tx_data_msg(conn->a.scu, conn->a.conn_id, msg);
} }
int a_iface_tx_classmark_request(const struct gsm_subscriber_connection *conn)
{
struct msgb *msg;
LOGPCONN(conn, LOGL_INFO, "Tx BSSMAP CLASSMARK REQUEST to BSC\n");
msg = gsm0808_create_classmark_request();
return osmo_sccp_tx_data_msg(conn->a.scu, conn->a.conn_id, msg);
}
/* Callback function: Close all open connections */ /* Callback function: Close all open connections */
static void a_reset_cb(const void *priv) static void a_reset_cb(const void *priv)
{ {

134
src/libmsc/gsm_04_08.c
View File

@ -119,13 +119,16 @@ static bool classmark_is_r99(struct gsm_classmark *cm)
return classmark2_is_r99(cm->classmark2, cm->classmark2_len); return classmark2_is_r99(cm->classmark2, cm->classmark2_len);
} }
/* Determine if the given CLASSMARK (1/2/3) value permits a given A5/n cipher */ /* Determine if the given CLASSMARK (1/2/3) value permits a given A5/n cipher.
static bool classmark_supports_a5(const struct gsm_classmark *cm, uint8_t a5) * Return 1 when the given A5/n is permitted, 0 when not, and negative if the respective MS CLASSMARK is
* not known, where the negative number indicates the classmark type: -2 means Classmark 2 is not
* available. */
static int classmark_supports_a5(const struct gsm_classmark *cm, uint8_t a5)
{ {
switch (a5) { switch (a5) {
case 0: case 0:
/* all phones must implement A5/0, see 3GPP TS 43.020 4.9 */ /* all phones must implement A5/0, see 3GPP TS 43.020 4.9 */
return true; return 1;
case 1: case 1:
/* 3GPP TS 43.020 4.9 requires A5/1 to be suppored by all phones and actually states: /* 3GPP TS 43.020 4.9 requires A5/1 to be suppored by all phones and actually states:
* "The network shall not provide service to an MS which indicates that it does not * "The network shall not provide service to an MS which indicates that it does not
@ -134,25 +137,24 @@ static bool classmark_supports_a5(const struct gsm_classmark *cm, uint8_t a5)
/* See 3GPP TS 24.008 10.5.1.7 */ /* See 3GPP TS 24.008 10.5.1.7 */
if (!cm->classmark1_set) { if (!cm->classmark1_set) {
DEBUGP(DMSC, "CLASSMARK 1 unknown, assuming MS supports A5/1\n"); DEBUGP(DMSC, "CLASSMARK 1 unknown, assuming MS supports A5/1\n");
return true; return -1;
} else { } else {
if (cm->classmark1.a5_1) if (cm->classmark1.a5_1)
return false; /* Inverted logic for this bit! */ return 0; /* Inverted logic for this bit! */
else else
return true; return 1;
} }
break; break;
case 2: case 2:
case 3: case 3:
/* See 3GPP TS 24.008 10.5.1.6 */ /* See 3GPP TS 24.008 10.5.1.6 */
if (cm->classmark2_len < 3) { if (cm->classmark2_len < 3) {
DEBUGP(DMSC, "CLASSMARK 2 unknown, assuming MS doesn't support A5/%u\n", a5); return -2;
return false;
} else { } else {
if (cm->classmark2[2] & (1 << (a5-2))) if (cm->classmark2[2] & (1 << (a5-2)))
return true; return 1;
else else
return false; return 0;
} }
break; break;
case 4: case 4:
@ -161,13 +163,12 @@ static bool classmark_supports_a5(const struct gsm_classmark *cm, uint8_t a5)
case 7: case 7:
/* See 3GPP TS 24.008 10.5.1.7 */ /* See 3GPP TS 24.008 10.5.1.7 */
if (cm->classmark3_len < 1) { if (cm->classmark3_len < 1) {
DEBUGP(DMSC, "CLASSMARK 3 unknown, assuming MS doesn't support A5/%u\n", a5); return -3;
return false;
} else { } else {
if (cm->classmark3[0] & (1 << (a5-4))) if (cm->classmark3[0] & (1 << (a5-4)))
return true; return 1;
else else
return false; return 0;
} }
break; break;
default: default:
@ -1592,6 +1593,78 @@ static int msc_vlr_tx_cm_serv_rej(void *msc_conn_ref, enum gsm48_reject_value ca
osmo_static_assert(sizeof(((struct gsm0808_encrypt_info*)0)->key) >= sizeof(((struct osmo_auth_vector*)0)->kc), osmo_static_assert(sizeof(((struct gsm0808_encrypt_info*)0)->key) >= sizeof(((struct osmo_auth_vector*)0)->kc),
gsm0808_encrypt_info_key_fits_osmo_auth_vec_kc); gsm0808_encrypt_info_key_fits_osmo_auth_vec_kc);
int msc_geran_set_cipher_mode(struct gsm_subscriber_connection *conn, bool umts_aka, bool retrieve_imeisv)
{
struct gsm_network *net = conn->network;
struct gsm0808_encrypt_info ei;
int i, j = 0;
int request_classmark = 0;
int request_classmark_for_a5_n = 0;
struct gsm_auth_tuple *tuple = conn->vsub->last_tuple;
if (!conn || !conn->vsub || !conn->vsub->last_tuple) {
/* This should really never happen, because we checked this in msc_vlr_set_ciph_mode()
* already. */
LOGP(DMM, LOGL_ERROR, "Internal error: missing state during Ciphering Mode Command\n");
return -EINVAL;
}
for (i = 0; i < 8; i++) {
int supported;
/* A5/n permitted by osmo-msc.cfg? */
if (!(net->a5_encryption_mask & (1 << i)))
continue;
/* A5/n supported by MS? */
supported = classmark_supports_a5(&conn->vsub->classmark, i);
if (supported == 1) {
ei.perm_algo[j++] = vlr_ciph_to_gsm0808_alg_id(i);
/* A higher A5/n is supported, so no need to request a Classmark
* for support of a lesser A5/n. */
request_classmark = 0;
} else if (supported < 0) {
request_classmark = -supported;
request_classmark_for_a5_n = i;
}
}
ei.perm_algo_len = j;
if (request_classmark) {
/* The highest A5/n as from osmo-msc.cfg might be available, but we are
* still missing the Classmark information for that from the MS. First
* ask for that. */
LOGP(DMM, LOGL_DEBUG, "%s: to determine whether A5/%d is supported,"
" first ask for a Classmark Update to obtain Classmark %d\n",
vlr_subscr_name(conn->vsub), request_classmark_for_a5_n,
request_classmark);
return msc_classmark_request_then_cipher_mode_cmd(conn, umts_aka, retrieve_imeisv);
}
if (ei.perm_algo_len == 0) {
LOGP(DMM, LOGL_ERROR, "%s: cannot start ciphering, no intersection "
"between MSC-configured and MS-supported A5 algorithms\n",
vlr_subscr_name(conn->vsub));
return -ENOTSUP;
}
DEBUGP(DMM, "-> CIPHER MODE COMMAND %s\n", vlr_subscr_name(conn->vsub));
tuple = conn->vsub->last_tuple;
/* In case of UMTS AKA, the Kc for ciphering must be derived from the 3G auth
* tokens. tuple->vec.kc was calculated from the GSM algorithm and is not
* necessarily a match for the UMTS AKA tokens. */
if (umts_aka)
osmo_auth_c3(ei.key, tuple->vec.ck, tuple->vec.ik);
else
memcpy(ei.key, tuple->vec.kc, sizeof(tuple->vec.kc));
ei.key_len = sizeof(tuple->vec.kc);
return a_iface_tx_cipher_mode(conn, &ei, retrieve_imeisv);
}
/* VLR asks us to start using ciphering. /* VLR asks us to start using ciphering.
* (Keep non-static to allow regression testing on this function.) */ * (Keep non-static to allow regression testing on this function.) */
int msc_vlr_set_ciph_mode(void *msc_conn_ref, int msc_vlr_set_ciph_mode(void *msc_conn_ref,
@ -1620,38 +1693,7 @@ int msc_vlr_set_ciph_mode(void *msc_conn_ref,
switch (conn->via_ran) { switch (conn->via_ran) {
case RAN_GERAN_A: case RAN_GERAN_A:
DEBUGP(DMM, "-> CIPHER MODE COMMAND %s\n", return msc_geran_set_cipher_mode(conn, umts_aka, retrieve_imeisv);
vlr_subscr_name(conn->vsub));
{
struct gsm_network *net = conn->network;
struct gsm0808_encrypt_info ei;
int i, j = 0;
for (i = 0; i < 8; i++) {
if (net->a5_encryption_mask & (1 << i) &&
classmark_supports_a5(&conn->vsub->classmark, i))
ei.perm_algo[j++] = vlr_ciph_to_gsm0808_alg_id(i);
}
ei.perm_algo_len = j;
if (ei.perm_algo_len == 0) {
LOGP(DMM, LOGL_ERROR, "%s: cannot start ciphering, no intersection "
"between MSC-configured and MS-supported A5 algorithms\n",
vlr_subscr_name(conn->vsub));
return -ENOTSUP;
}
/* In case of UMTS AKA, the Kc for ciphering must be derived from the 3G auth
* tokens. tuple->vec.kc was calculated from the GSM algorithm and is not
* necessarily a match for the UMTS AKA tokens. */
if (umts_aka)
osmo_auth_c3(ei.key, tuple->vec.ck, tuple->vec.ik);
else
memcpy(ei.key, tuple->vec.kc, sizeof(tuple->vec.kc));
ei.key_len = sizeof(tuple->vec.kc);
return a_iface_tx_cipher_mode(conn, &ei, retrieve_imeisv);
}
case RAN_UTRAN_IU: case RAN_UTRAN_IU:
#ifdef BUILD_IU #ifdef BUILD_IU

4
src/libmsc/osmo_msc.c
View File

@ -167,6 +167,10 @@ void msc_classmark_chg(struct gsm_subscriber_connection *conn,
cm->classmark3_len = cm3_len; cm->classmark3_len = cm3_len;
memcpy(cm->classmark3, cm3, cm3_len); memcpy(cm->classmark3, cm3, cm3_len);
} }
/* bump subscr conn FSM in case it is waiting for a Classmark Update */
if (conn->fi->state == SUBSCR_CONN_S_WAIT_CLASSMARK_UPDATE)
osmo_fsm_inst_dispatch(conn->fi, SUBSCR_CONN_E_CLASSMARK_UPDATE, NULL);
} }
/* Receive a CIPHERING MODE COMPLETE from BSC */ /* Receive a CIPHERING MODE COMPLETE from BSC */

74
src/libmsc/subscr_conn.c
View File

@ -45,6 +45,7 @@
static const struct value_string subscr_conn_fsm_event_names[] = { static const struct value_string subscr_conn_fsm_event_names[] = {
OSMO_VALUE_STRING(SUBSCR_CONN_E_INVALID), OSMO_VALUE_STRING(SUBSCR_CONN_E_INVALID),
OSMO_VALUE_STRING(SUBSCR_CONN_E_COMPLETE_LAYER_3), OSMO_VALUE_STRING(SUBSCR_CONN_E_COMPLETE_LAYER_3),
OSMO_VALUE_STRING(SUBSCR_CONN_E_CLASSMARK_UPDATE),
OSMO_VALUE_STRING(SUBSCR_CONN_E_ACCEPTED), OSMO_VALUE_STRING(SUBSCR_CONN_E_ACCEPTED),
OSMO_VALUE_STRING(SUBSCR_CONN_E_COMMUNICATING), OSMO_VALUE_STRING(SUBSCR_CONN_E_COMMUNICATING),
OSMO_VALUE_STRING(SUBSCR_CONN_E_RELEASE_WHEN_UNUSED), OSMO_VALUE_STRING(SUBSCR_CONN_E_RELEASE_WHEN_UNUSED),
@ -163,6 +164,66 @@ void subscr_conn_fsm_auth_ciph(struct osmo_fsm_inst *fi, uint32_t event, void *d
} }
} }
int msc_classmark_request_then_cipher_mode_cmd(struct gsm_subscriber_connection *conn, bool umts_aka,
bool retrieve_imeisv)
{
int rc;
conn->geran_set_cipher_mode.umts_aka = umts_aka;
conn->geran_set_cipher_mode.retrieve_imeisv = retrieve_imeisv;
rc = a_iface_tx_classmark_request(conn);
if (rc) {
LOGP(DMM, LOGL_ERROR, "%s: cannot send BSSMAP Classmark Request\n",
vlr_subscr_name(conn->vsub));
return -EIO;
}
osmo_fsm_inst_state_chg(conn->fi, SUBSCR_CONN_S_WAIT_CLASSMARK_UPDATE, SUBSCR_CONN_TIMEOUT, 0);
return 0;
}
static void subscr_conn_fsm_wait_classmark_update(struct osmo_fsm_inst *fi, uint32_t event, void *data)
{
struct gsm_subscriber_connection *conn = fi->priv;
switch (event) {
case SUBSCR_CONN_E_CLASSMARK_UPDATE:
/* Theoretically, this event can be used for requesting Classmark in various situations.
* So far though, the only time we send a Classmark Request is during Ciphering. As soon
* as more such situations arise, we need to add state to indicate what action should
* follow after a Classmark Update is received (e.g.
* msc_classmark_request_then_cipher_mode_cmd() sets an enum value to indicate that
* Ciphering should continue afterwards). But right now, it is accurate to always
* continue with Ciphering: */
/* During Ciphering, we needed Classmark information. The Classmark Update has come in,
* go back into the Set Ciphering Command procedure. */
osmo_fsm_inst_state_chg(fi, SUBSCR_CONN_S_AUTH_CIPH, SUBSCR_CONN_TIMEOUT, 0);
if (msc_geran_set_cipher_mode(conn, conn->geran_set_cipher_mode.umts_aka,
conn->geran_set_cipher_mode.retrieve_imeisv)) {
LOGPFSML(fi, LOGL_ERROR,
"Sending Cipher Mode Command failed, aborting attach\n");
vlr_subscr_cancel_attach_fsm(conn->vsub, OSMO_FSM_TERM_ERROR,
GSM48_REJECT_NETWORK_FAILURE);
}
return;
case SUBSCR_CONN_E_UNUSED:
LOGPFSML(fi, LOGL_DEBUG, "Awaiting results for Auth+Ciph, overruling event %s\n",
osmo_fsm_event_name(fi->fsm, event));
return;
case SUBSCR_CONN_E_MO_CLOSE:
case SUBSCR_CONN_E_CN_CLOSE:
log_close_event(fi, event, data);
evaluate_acceptance_outcome(fi, false);
osmo_fsm_inst_state_chg(fi, SUBSCR_CONN_S_RELEASING, SUBSCR_CONN_TIMEOUT, 0);
return;
default:
OSMO_ASSERT(false);
}
}
static bool subscr_conn_fsm_has_active_transactions(struct osmo_fsm_inst *fi) static bool subscr_conn_fsm_has_active_transactions(struct osmo_fsm_inst *fi)
{ {
struct gsm_subscriber_connection *conn = fi->priv; struct gsm_subscriber_connection *conn = fi->priv;
@ -362,10 +423,21 @@ static const struct osmo_fsm_state subscr_conn_fsm_states[] = {
S(SUBSCR_CONN_E_MO_CLOSE) | S(SUBSCR_CONN_E_MO_CLOSE) |
S(SUBSCR_CONN_E_CN_CLOSE) | S(SUBSCR_CONN_E_CN_CLOSE) |
S(SUBSCR_CONN_E_UNUSED), S(SUBSCR_CONN_E_UNUSED),
.out_state_mask = S(SUBSCR_CONN_S_ACCEPTED) | .out_state_mask = S(SUBSCR_CONN_S_WAIT_CLASSMARK_UPDATE) |
S(SUBSCR_CONN_S_ACCEPTED) |
S(SUBSCR_CONN_S_RELEASING), S(SUBSCR_CONN_S_RELEASING),
.action = subscr_conn_fsm_auth_ciph, .action = subscr_conn_fsm_auth_ciph,
}, },
[SUBSCR_CONN_S_WAIT_CLASSMARK_UPDATE] = {
.name = OSMO_STRINGIFY(SUBSCR_CONN_S_WAIT_CLASSMARK_UPDATE),
.in_event_mask = S(SUBSCR_CONN_E_CLASSMARK_UPDATE) |
S(SUBSCR_CONN_E_MO_CLOSE) |
S(SUBSCR_CONN_E_CN_CLOSE) |
S(SUBSCR_CONN_E_UNUSED),
.out_state_mask = S(SUBSCR_CONN_S_AUTH_CIPH) |
S(SUBSCR_CONN_S_RELEASING),
.action = subscr_conn_fsm_wait_classmark_update,
},
[SUBSCR_CONN_S_ACCEPTED] = { [SUBSCR_CONN_S_ACCEPTED] = {
.name = OSMO_STRINGIFY(SUBSCR_CONN_S_ACCEPTED), .name = OSMO_STRINGIFY(SUBSCR_CONN_S_ACCEPTED),
/* allow everything to release for any odd behavior */ /* allow everything to release for any odd behavior */

1
tests/msc_vlr/Makefile.am
View File

@ -35,6 +35,7 @@ AM_LDFLAGS = \
-Wl,--wrap=msc_mgcp_call_assignment \ -Wl,--wrap=msc_mgcp_call_assignment \
-Wl,--wrap=a_iface_tx_cipher_mode \ -Wl,--wrap=a_iface_tx_cipher_mode \
-Wl,--wrap=ranap_iu_tx_sec_mode_cmd \ -Wl,--wrap=ranap_iu_tx_sec_mode_cmd \
-Wl,--wrap=osmo_sccp_tx_data_msg \
$(NULL) $(NULL)
LDADD = \ LDADD = \

405
tests/msc_vlr/msc_vlr_test_gsm_ciph.c
View File

@ -1053,8 +1053,11 @@ static void test_gsm_ciph_in_umts_env()
comment_end(); comment_end();
} }
static void test_a5_3_not_supported() static void test_a5_3_supported()
{ {
struct vlr_subscr *vsub;
const char *imsi = "901700000004620";
comment_start(); comment_start();
/* implicit: net->authentication_required = true; */ /* implicit: net->authentication_required = true; */
@ -1093,12 +1096,403 @@ static void test_a5_3_not_supported()
VERBOSE_ASSERT(auth_request_sent, == true, "%d"); VERBOSE_ASSERT(auth_request_sent, == true, "%d");
BTW("MS sends Authen Response, VLR accepts and wants to send Ciphering Mode Command to MS" BTW("MS sends Authen Response, VLR accepts and wants to send Ciphering Mode Command to MS"
" -- alas, no matching cipher can be found, abort and release"); " -- but needs Classmark 2 to determine whether A5/3 is supported");
cipher_mode_cmd_sent = false; cipher_mode_cmd_sent = false;
expect_bssap_clear();
ms_sends_msg("05542d8b2c3e"); ms_sends_msg("05542d8b2c3e");
OSMO_ASSERT(!cipher_mode_cmd_sent); OSMO_ASSERT(!cipher_mode_cmd_sent);
VERBOSE_ASSERT(lu_result_sent, == RES_REJECT, "%d"); VERBOSE_ASSERT(lu_result_sent, == RES_NONE, "%d");
btw("BSC sends back a BSSMAP Classmark Update, that triggers the Ciphering Mode Command in A5/3");
expect_cipher_mode_cmd("61855fb81fc2a800");
bss_sends_bssap_mgmt("541203505886130b6014042f6503b8800d2100");
OSMO_ASSERT(cipher_mode_cmd_sent);
VERBOSE_ASSERT(lu_result_sent, == RES_NONE, "%d");
btw("MS sends Ciphering Mode Complete, VLR accepts and sends GSUP LU Req to HLR");
gsup_expect_tx("04010809710000004026f0");
ms_sends_msg("0632");
VERBOSE_ASSERT(lu_result_sent, == RES_NONE, "%d");
btw("HLR sends _INSERT_DATA_REQUEST, VLR responds with _INSERT_DATA_RESULT");
gsup_rx("10010809710000004026f00804032443f2",
"12010809710000004026f0");
VERBOSE_ASSERT(lu_result_sent, == RES_NONE, "%d");
btw("HLR also sends GSUP _UPDATE_LOCATION_RESULT");
expect_bssap_clear();
gsup_rx("06010809710000004026f0", NULL);
VERBOSE_ASSERT(bssap_clear_sent, == true, "%d");
btw("LU was successful, and the conn has already been closed");
VERBOSE_ASSERT(lu_result_sent, == RES_ACCEPT, "%d");
bss_sends_clear_complete();
EXPECT_CONN_COUNT(0);
BTW("after a while, a new conn sends a CM Service Request. VLR responds with Auth Req, 2nd auth vector");
cm_service_result_sent = RES_NONE;
auth_request_sent = false;
auth_request_expect_rand = "12aca96fb4ffdea5c985cbafa9b6e18b";
ms_sends_msg("05247803305886089910070000006402");
OSMO_ASSERT(g_conn);
OSMO_ASSERT(g_conn->fi);
OSMO_ASSERT(g_conn->vsub);
VERBOSE_ASSERT(auth_request_sent, == true, "%d");
VERBOSE_ASSERT(cm_service_result_sent, == RES_NONE, "%d");
btw("needs auth, not yet accepted");
EXPECT_ACCEPTED(false);
thwart_rx_non_initial_requests();
btw("MS sends Authen Response, VLR accepts and requests Ciphering. We already know Classmark 3,"
" so no need to request Classmark Update.");
expect_cipher_mode_cmd("07fa7502e07e1c00");
ms_sends_msg("0554" "20bde240" /* 2nd vector's sres, s.a. */);
VERBOSE_ASSERT(cm_service_result_sent, == RES_NONE, "%d");
VERBOSE_ASSERT(cipher_mode_cmd_sent, == true, "%d");
btw("needs ciph, not yet accepted");
EXPECT_ACCEPTED(false);
thwart_rx_non_initial_requests();
btw("MS sends Ciphering Mode Complete, VLR accepts; above Ciphering is an implicit CM Service Accept");
ms_sends_msg("0632");
VERBOSE_ASSERT(cm_service_result_sent, == RES_NONE, "%d");
/* Release connection */
expect_bssap_clear(RAN_GERAN_A);
conn_conclude_cm_service_req(g_conn, RAN_GERAN_A);
btw("all requests serviced, conn has been released");
bss_sends_clear_complete();
EXPECT_CONN_COUNT(0);
BTW("an SMS is sent, MS is paged");
paging_expect_imsi(imsi);
paging_sent = false;
vsub = vlr_subscr_find_by_imsi(net->vlr, imsi);
OSMO_ASSERT(vsub);
VERBOSE_ASSERT(llist_count(&vsub->cs.requests), == 0, "%d");
send_sms(vsub, vsub,
"Privacy in residential applications is a desirable"
" marketing option.");
VERBOSE_ASSERT(llist_count(&vsub->cs.requests), == 1, "%d");
vlr_subscr_put(vsub);
vsub = NULL;
VERBOSE_ASSERT(paging_sent, == true, "%d");
VERBOSE_ASSERT(paging_stopped, == false, "%d");
btw("the subscriber and its pending request should remain");
vsub = vlr_subscr_find_by_imsi(net->vlr, imsi);
OSMO_ASSERT(vsub);
VERBOSE_ASSERT(llist_count(&vsub->cs.requests), == 1, "%d");
vlr_subscr_put(vsub);
btw("MS replies with Paging Response, and VLR sends Auth Request with third key");
auth_request_sent = false;
auth_request_expect_rand = "e7c03ba7cf0e2fde82b2dc4d63077d42";
ms_sends_msg("06270703305882089910070000006402");
VERBOSE_ASSERT(auth_request_sent, == true, "%d");
btw("needs auth, not yet accepted");
EXPECT_ACCEPTED(false);
thwart_rx_non_initial_requests();
btw("MS sends Authen Response, VLR accepts and requests Ciphering");
expect_cipher_mode_cmd("e2b234f807886400");
ms_sends_msg("0554" "a29514ae" /* 3rd vector's sres, s.a. */);
VERBOSE_ASSERT(cipher_mode_cmd_sent, == true, "%d");
btw("needs ciph, not yet accepted");
EXPECT_ACCEPTED(false);
thwart_rx_non_initial_requests();
btw("MS sends Ciphering Mode Complete, VLR accepts and sends pending SMS");
dtap_expect_tx("09" /* SMS messages */
"01" /* CP-DATA */
"58" /* length */
"01" /* Network to MS */
"00" /* reference */
/* originator (gsm411_send_sms() hardcodes this weird nr) */
"0791" "447758100650" /* 447785016005 */
"00" /* dest */
/* SMS TPDU */
"4c" /* len */
"00" /* SMS deliver */
"05802443f2" /* originating address 42342 */
"00" /* TP-PID */
"00" /* GSM default alphabet */
"071010" /* Y-M-D (from wrapped gsm340_gen_scts())*/
"000000" /* H-M-S */
"00" /* GMT+0 */
"44" /* data length */
"5079da1e1ee7416937485e9ea7c965373d1d6683c270383b3d0e"
"d3d36ff71c949e83c22072799e9687c5ec32a81d96afcbf4b4fb"
"0c7ac3e9e9b7db05");
ms_sends_msg("0632");
VERBOSE_ASSERT(dtap_tx_confirmed, == true, "%d");
VERBOSE_ASSERT(paging_stopped, == true, "%d");
btw("SMS was delivered, no requests pending for subscr");
vsub = vlr_subscr_find_by_imsi(net->vlr, imsi);
OSMO_ASSERT(vsub);
VERBOSE_ASSERT(llist_count(&vsub->cs.requests), == 0, "%d");
vlr_subscr_put(vsub);
btw("conn is still open to wait for SMS ack dance");
EXPECT_CONN_COUNT(1);
btw("MS replies with CP-ACK for received SMS");
ms_sends_msg("8904");
EXPECT_CONN_COUNT(1);
btw("MS also sends RP-ACK, MSC in turn sends CP-ACK for that");
dtap_expect_tx("0904");
expect_bssap_clear();
ms_sends_msg("890106020041020000");
VERBOSE_ASSERT(dtap_tx_confirmed, == true, "%d");
VERBOSE_ASSERT(bssap_clear_sent, == true, "%d");
btw("SMS is done, conn is gone");
bss_sends_clear_complete();
EXPECT_CONN_COUNT(0);
BTW("subscriber detaches");
expect_bssap_clear();
ms_sends_msg("050130089910070000006402");
VERBOSE_ASSERT(bssap_clear_sent, == true, "%d");
bss_sends_clear_complete();
EXPECT_CONN_COUNT(0);
clear_vlr();
comment_end();
}
/* During CM Service Request or Paging Response we already have Classmark 2 that indicates A5/3
* availablity. Here, in a hacky way remove the knowledge of Classmark 2 to tickle a code path where
* proc_arq_fsm needs a Classmark Update during Ciphering. Shouldn't happen in reality though. */
static void test_cm_service_needs_classmark_update()
{
struct vlr_subscr *vsub;
const char *imsi = "901700000004620";
comment_start();
/* A5/3 support is indicated in Classmark 3. By configuring A5/3, trigger the code paths that
* send a Classmark Request. */
net->a5_encryption_mask = (1 << 3); /* A5/3 */
/* implicit: net->authentication_required = true; */
btw("Location Update request causes a GSUP Send Auth Info request to HLR");
lu_result_sent = RES_NONE;
gsup_expect_tx("08010809710000004026f0");
ms_sends_msg("050802008168000130089910070000006402");
OSMO_ASSERT(gsup_tx_confirmed);
VERBOSE_ASSERT(lu_result_sent, == RES_NONE, "%d");
btw("from HLR, rx _SEND_AUTH_INFO_RESULT; VLR sends Auth Req to MS");
/* Based on a Ki of 000102030405060708090a0b0c0d0e0f */
auth_request_sent = false;
auth_request_expect_rand = "585df1ae287f6e273dce07090d61320b";
auth_request_expect_autn = NULL;
gsup_rx("0a"
/* imsi */
"0108" "09710000004026f0"
/* 5 auth vectors... */
/* TL TL rand */
"0322" "2010" "585df1ae287f6e273dce07090d61320b"
/* TL sres TL kc */
"2104" "2d8b2c3e" "2208" "61855fb81fc2a800"
"0322" "2010" "12aca96fb4ffdea5c985cbafa9b6e18b"
"2104" "20bde240" "2208" "07fa7502e07e1c00"
"0322" "2010" "e7c03ba7cf0e2fde82b2dc4d63077d42"
"2104" "a29514ae" "2208" "e2b234f807886400"
"0322" "2010" "fa8f20b781b5881329d4fea26b1a3c51"
"2104" "5afc8d72" "2208" "2392f14f709ae000"
"0322" "2010" "0fd4cc8dbe8715d1f439e304edfd68dc"
"2104" "bc8d1c5b" "2208" "da7cdd6bfe2d7000",
NULL);
VERBOSE_ASSERT(lu_result_sent, == RES_NONE, "%d");
VERBOSE_ASSERT(auth_request_sent, == true, "%d");
BTW("MS sends Authen Response, VLR accepts and wants to send Ciphering Mode Command to MS"
" -- but needs Classmark 2 to determine whether A5/3 is supported");
cipher_mode_cmd_sent = false;
ms_sends_msg("05542d8b2c3e");
OSMO_ASSERT(!cipher_mode_cmd_sent);
VERBOSE_ASSERT(lu_result_sent, == RES_NONE, "%d");
btw("BSC sends back a BSSMAP Classmark Update, that triggers the Ciphering Mode Command in A5/3");
expect_cipher_mode_cmd("61855fb81fc2a800");
bss_sends_bssap_mgmt("541203505886130b6014042f6503b8800d2100");
OSMO_ASSERT(cipher_mode_cmd_sent);
VERBOSE_ASSERT(lu_result_sent, == RES_NONE, "%d");
btw("MS sends Ciphering Mode Complete, VLR accepts and sends GSUP LU Req to HLR");
gsup_expect_tx("04010809710000004026f0");
ms_sends_msg("0632");
VERBOSE_ASSERT(lu_result_sent, == RES_NONE, "%d");
btw("HLR sends _INSERT_DATA_REQUEST, VLR responds with _INSERT_DATA_RESULT");
gsup_rx("10010809710000004026f00804032443f2",
"12010809710000004026f0");
VERBOSE_ASSERT(lu_result_sent, == RES_NONE, "%d");
btw("HLR also sends GSUP _UPDATE_LOCATION_RESULT");
expect_bssap_clear();
gsup_rx("06010809710000004026f0", NULL);
VERBOSE_ASSERT(bssap_clear_sent, == true, "%d");
btw("LU was successful, and the conn has already been closed");
VERBOSE_ASSERT(lu_result_sent, == RES_ACCEPT, "%d");
bss_sends_clear_complete();
EXPECT_CONN_COUNT(0);
BTW("after a while, a new conn sends a CM Service Request. VLR responds with Auth Req, 2nd auth vector");
cm_service_result_sent = RES_NONE;
auth_request_sent = false;
auth_request_expect_rand = "12aca96fb4ffdea5c985cbafa9b6e18b";
ms_sends_msg("05247803305886089910070000006402");
OSMO_ASSERT(g_conn);
OSMO_ASSERT(g_conn->fi);
OSMO_ASSERT(g_conn->vsub);
VERBOSE_ASSERT(auth_request_sent, == true, "%d");
VERBOSE_ASSERT(cm_service_result_sent, == RES_NONE, "%d");
btw("needs auth, not yet accepted");
EXPECT_ACCEPTED(false);
thwart_rx_non_initial_requests();
btw("MS sends Authen Response, VLR accepts and requests Ciphering. We already know Classmark 3,"
" so no need to request Classmark Update.");
expect_cipher_mode_cmd("07fa7502e07e1c00");
ms_sends_msg("0554" "20bde240" /* 2nd vector's sres, s.a. */);
VERBOSE_ASSERT(cm_service_result_sent, == RES_NONE, "%d");
VERBOSE_ASSERT(cipher_mode_cmd_sent, == true, "%d");
btw("needs ciph, not yet accepted");
EXPECT_ACCEPTED(false);
thwart_rx_non_initial_requests();
btw("MS sends Ciphering Mode Complete, VLR accepts; above Ciphering is an implicit CM Service Accept");
ms_sends_msg("0632");
VERBOSE_ASSERT(cm_service_result_sent, == RES_NONE, "%d");
/* Release connection */
expect_bssap_clear(RAN_GERAN_A);
conn_conclude_cm_service_req(g_conn, RAN_GERAN_A);
btw("all requests serviced, conn has been released");
bss_sends_clear_complete();
EXPECT_CONN_COUNT(0);
BTW("an SMS is sent, MS is paged");
paging_expect_imsi(imsi);
paging_sent = false;
vsub = vlr_subscr_find_by_imsi(net->vlr, imsi);
OSMO_ASSERT(vsub);
VERBOSE_ASSERT(llist_count(&vsub->cs.requests), == 0, "%d");
send_sms(vsub, vsub, "Privacy in residential applications is a desirable marketing option.");
VERBOSE_ASSERT(llist_count(&vsub->cs.requests), == 1, "%d");
vlr_subscr_put(vsub);
vsub = NULL;
VERBOSE_ASSERT(paging_sent, == true, "%d");
VERBOSE_ASSERT(paging_stopped, == false, "%d");
btw("the subscriber and its pending request should remain");
vsub = vlr_subscr_find_by_imsi(net->vlr, imsi);
OSMO_ASSERT(vsub);
VERBOSE_ASSERT(llist_count(&vsub->cs.requests), == 1, "%d");
vlr_subscr_put(vsub);
btw("MS replies with Paging Response, and VLR sends Auth Request with third key");
auth_request_sent = false;
auth_request_expect_rand = "e7c03ba7cf0e2fde82b2dc4d63077d42";
ms_sends_msg("06270703305882089910070000006402");
VERBOSE_ASSERT(auth_request_sent, == true, "%d");
BTW("Fake a situation where Classmark 2 is unknown during proc_arq_fsm");
vsub = vlr_subscr_find_by_imsi(net->vlr, imsi);
OSMO_ASSERT(vsub);
vsub->classmark.classmark2_len = 0;
vsub->classmark.classmark3_len = 0;
vlr_subscr_put(vsub);
btw("MS sends Authen Response, VLR accepts and requests Ciphering");
btw("MS sends Authen Response, VLR accepts and requests Ciphering."
" Normally, we'd know Classmark 3, but this test removed it."
" Hence a Classmark Request is generated.");
cipher_mode_cmd_sent = false;
ms_sends_msg("0554" "a29514ae" /* 3rd vector's sres, s.a. */);
OSMO_ASSERT(!cipher_mode_cmd_sent);
btw("BSC sends back a BSSMAP Classmark Update, that triggers the Ciphering Mode Command in A5/3");
expect_cipher_mode_cmd("e2b234f807886400");
bss_sends_bssap_mgmt("541203505886130b6014042f6503b8800d2100");
OSMO_ASSERT(cipher_mode_cmd_sent);
btw("needs ciph, not yet accepted");
EXPECT_ACCEPTED(false);
btw("MS sends Ciphering Mode Complete, VLR accepts and sends pending SMS");
dtap_expect_tx("09" /* SMS messages */
"01" /* CP-DATA */
"58" /* length */
"01" /* Network to MS */
"00" /* reference */
/* originator (gsm411_send_sms() hardcodes this weird nr) */
"0791" "447758100650" /* 447785016005 */
"00" /* dest */
/* SMS TPDU */
"4c" /* len */
"00" /* SMS deliver */
"05802443f2" /* originating address 42342 */
"00" /* TP-PID */
"00" /* GSM default alphabet */
"071010" /* Y-M-D (from wrapped gsm340_gen_scts())*/
"000000" /* H-M-S */
"00" /* GMT+0 */
"44" /* data length */
"5079da1e1ee7416937485e9ea7c965373d1d6683c270383b3d0e"
"d3d36ff71c949e83c22072799e9687c5ec32a81d96afcbf4b4fb"
"0c7ac3e9e9b7db05");
ms_sends_msg("0632");
VERBOSE_ASSERT(dtap_tx_confirmed, == true, "%d");
VERBOSE_ASSERT(paging_stopped, == true, "%d");
btw("SMS was delivered, no requests pending for subscr");
vsub = vlr_subscr_find_by_imsi(net->vlr, imsi);
OSMO_ASSERT(vsub);
VERBOSE_ASSERT(llist_count(&vsub->cs.requests), == 0, "%d");
vlr_subscr_put(vsub);
btw("conn is still open to wait for SMS ack dance");
EXPECT_CONN_COUNT(1);
btw("MS replies with CP-ACK for received SMS");
ms_sends_msg("8904");
EXPECT_CONN_COUNT(1);
btw("MS also sends RP-ACK, MSC in turn sends CP-ACK for that");
dtap_expect_tx("0904");
expect_bssap_clear();
ms_sends_msg("890106020041020000");
VERBOSE_ASSERT(dtap_tx_confirmed, == true, "%d");
VERBOSE_ASSERT(bssap_clear_sent, == true, "%d");
btw("SMS is done, conn is gone");
bss_sends_clear_complete();
EXPECT_CONN_COUNT(0);
BTW("subscriber detaches");
expect_bssap_clear();
ms_sends_msg("050130089910070000006402");
VERBOSE_ASSERT(bssap_clear_sent, == true, "%d");
bss_sends_clear_complete(); bss_sends_clear_complete();
EXPECT_CONN_COUNT(0); EXPECT_CONN_COUNT(0);
@ -1114,6 +1508,7 @@ msc_vlr_test_func_t msc_vlr_tests[] = {
test_ciph_imeisv, test_ciph_imeisv,
test_ciph_tmsi_imei, test_ciph_tmsi_imei,
test_gsm_ciph_in_umts_env, test_gsm_ciph_in_umts_env,
test_a5_3_not_supported, test_a5_3_supported,
test_cm_service_needs_classmark_update,
NULL NULL
}; };

927
tests/msc_vlr/msc_vlr_test_gsm_ciph.err
View File

@ -2260,7 +2260,7 @@ DMM Subscr_Conn{SUBSCR_CONN_S_RELEASED}: Deallocated
full talloc report on 'msgb' (total 0 bytes in 1 blocks) full talloc report on 'msgb' (total 0 bytes in 1 blocks)
talloc_total_blocks(tall_bsc_ctx) == 12 talloc_total_blocks(tall_bsc_ctx) == 12
===== test_a5_3_not_supported ===== test_a5_3_supported
- Location Update request causes a GSUP Send Auth Info request to HLR - Location Update request causes a GSUP Send Auth Info request to HLR
MSC <--RAN_GERAN_A-- MS: GSM48_MT_MM_LOC_UPD_REQUEST MSC <--RAN_GERAN_A-- MS: GSM48_MT_MM_LOC_UPD_REQUEST
new conn new conn
@ -2309,7 +2309,7 @@ DREF VLR subscr IMSI:901700000004620 usage decreases to: 1
lu_result_sent == 0 lu_result_sent == 0
auth_request_sent == 1 auth_request_sent == 1
--- ---
- MS sends Authen Response, VLR accepts and wants to send Ciphering Mode Command to MS -- alas, no matching cipher can be found, abort and release - MS sends Authen Response, VLR accepts and wants to send Ciphering Mode Command to MS -- but needs Classmark 2 to determine whether A5/3 is supported
MSC <--RAN_GERAN_A-- MS: GSM48_MT_MM_AUTH_RESP MSC <--RAN_GERAN_A-- MS: GSM48_MT_MM_AUTH_RESP
DREF IMSI:901700000004620: MSC conn use + dtap == 1 (0x2: dtap) DREF IMSI:901700000004620: MSC conn use + dtap == 1 (0x2: dtap)
DRLL Dispatching 04.08 message GSM48_MT_MM_AUTH_RESP (0x5:0x14) DRLL Dispatching 04.08 message GSM48_MT_MM_AUTH_RESP (0x5:0x14)
@ -2326,23 +2326,98 @@ DVLR VLR_Authenticate(LU:901700000004620){VLR_SUB_AS_AUTHENTICATED}: Deallocated
DVLR vlr_lu_fsm(LU:901700000004620){VLR_ULA_S_WAIT_AUTH}: Received Event VLR_ULA_E_AUTH_RES DVLR vlr_lu_fsm(LU:901700000004620){VLR_ULA_S_WAIT_AUTH}: Received Event VLR_ULA_E_AUTH_RES
DVLR vlr_lu_fsm(LU:901700000004620){VLR_ULA_S_WAIT_AUTH}: vlr_loc_upd_post_auth() DVLR vlr_lu_fsm(LU:901700000004620){VLR_ULA_S_WAIT_AUTH}: vlr_loc_upd_post_auth()
DVLR vlr_lu_fsm(LU:901700000004620){VLR_ULA_S_WAIT_AUTH}: Set Ciphering Mode DVLR vlr_lu_fsm(LU:901700000004620){VLR_ULA_S_WAIT_AUTH}: Set Ciphering Mode
DMM IMSI:901700000004620: to determine whether A5/3 is supported, first ask for a Classmark Update to obtain Classmark 2
BSC <--BSSAP-BSS-MANAGEMENT-- MSC: CLASSMARK REQ [L3]> 00 01 58
DMM Subscr_Conn(LU:901700000004620){SUBSCR_CONN_S_AUTH_CIPH}: state_chg to SUBSCR_CONN_S_WAIT_CLASSMARK_UPDATE
DVLR vlr_lu_fsm(LU:901700000004620){VLR_ULA_S_WAIT_AUTH}: state_chg to VLR_ULA_S_WAIT_CIPH
DREF IMSI:901700000004620: MSC conn use - dtap == 0 (0x0: )
DMM Subscr_Conn(LU:901700000004620){SUBSCR_CONN_S_WAIT_CLASSMARK_UPDATE}: Received Event SUBSCR_CONN_E_UNUSED
DMM Subscr_Conn(LU:901700000004620){SUBSCR_CONN_S_WAIT_CLASSMARK_UPDATE}: Awaiting results for Auth+Ciph, overruling event SUBSCR_CONN_E_UNUSED
lu_result_sent == 0
- BSC sends back a BSSMAP Classmark Update, that triggers the Ciphering Mode Command in A5/3
DMSC Looking for A subscriber: conn_id 0
DMM Subscr_Conn(LU:901700000004620){SUBSCR_CONN_S_WAIT_CLASSMARK_UPDATE}: Received Event SUBSCR_CONN_E_CLASSMARK_UPDATE
DMM Subscr_Conn(LU:901700000004620){SUBSCR_CONN_S_WAIT_CLASSMARK_UPDATE}: state_chg to SUBSCR_CONN_S_AUTH_CIPH
DMM -> CIPHER MODE COMMAND IMSI:901700000004620 DMM -> CIPHER MODE COMMAND IMSI:901700000004620
DMSC CLASSMARK 2 unknown, assuming MS doesn't support A5/3 - sending Ciphering Mode Command for IMSI:901700000004620: include_imeisv=0
DMM IMSI:901700000004620: cannot start ciphering, no intersection between MSC-configured and MS-supported A5 algorithms - ...perm algo: A5/3
- ERROR sending ciphering mode command: rc=-95 - ...key: 61855fb81fc2a800
DVLR vlr_lu_fsm(LU:901700000004620){VLR_ULA_S_WAIT_AUTH}: Failed to send Ciphering Mode Command lu_result_sent == 0
- sending LU Reject for IMSI:901700000004620, cause 17 - MS sends Ciphering Mode Complete, VLR accepts and sends GSUP LU Req to HLR
DVLR vlr_lu_fsm(LU:901700000004620){VLR_ULA_S_WAIT_AUTH}: state_chg to VLR_ULA_S_DONE MSC <--RAN_GERAN_A-- MS: GSM48_MT_RR_CIPH_M_COMPL
DMM Subscr_Conn(LU:901700000004620){SUBSCR_CONN_S_AUTH_CIPH}: Received Event SUBSCR_CONN_E_CN_CLOSE DRR IMSI:901700000004620: CIPHERING MODE COMPLETE
DMM Subscr_Conn(LU:901700000004620){SUBSCR_CONN_S_AUTH_CIPH}: state_chg to SUBSCR_CONN_S_RELEASING DVLR vlr_lu_fsm(LU:901700000004620){VLR_ULA_S_WAIT_CIPH}: Received Event VLR_ULA_E_CIPH_RES
DREF IMSI:901700000004620: MSC conn use + release == 2 (0x102: dtap,release) DVLR vlr_lu_fsm(LU:901700000004620){VLR_ULA_S_WAIT_CIPH}: vlr_loc_upd_post_ciph()
DVLR vlr_lu_fsm(LU:901700000004620){VLR_ULA_S_WAIT_CIPH}: vlr_loc_upd_node_4()
DVLR vlr_lu_fsm(LU:901700000004620){VLR_ULA_S_WAIT_CIPH}: state_chg to VLR_ULA_S_WAIT_HLR_UPD
DVLR upd_hlr_vlr_fsm(LU:901700000004620){UPD_HLR_VLR_S_INIT}: Allocated
DVLR upd_hlr_vlr_fsm(LU:901700000004620){UPD_HLR_VLR_S_INIT}: is child of vlr_lu_fsm(LU:901700000004620)
DVLR upd_hlr_vlr_fsm(LU:901700000004620){UPD_HLR_VLR_S_INIT}: Received Event UPD_HLR_VLR_E_START
DVLR GSUP tx: 04010809710000004026f0
GSUP --> HLR: OSMO_GSUP_MSGT_UPDATE_LOCATION_REQUEST: 04010809710000004026f0
DVLR upd_hlr_vlr_fsm(LU:901700000004620){UPD_HLR_VLR_S_INIT}: state_chg to UPD_HLR_VLR_S_WAIT_FOR_DATA
lu_result_sent == 0
- HLR sends _INSERT_DATA_REQUEST, VLR responds with _INSERT_DATA_RESULT
<-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: 10010809710000004026f00804032443f2
DVLR GSUP rx 17: 10010809710000004026f00804032443f2
DREF VLR subscr IMSI:901700000004620 usage increases to: 2 DREF VLR subscr IMSI:901700000004620 usage increases to: 2
DREF VLR subscr IMSI:901700000004620 usage decreases to: 1 DVLR IMSI:901700000004620 has MSISDN:42342
DVLR SUBSCR(MSISDN:42342) VLR: update for IMSI=901700000004620 (MSISDN=42342, used=2)
DVLR GSUP tx: 12010809710000004026f0
GSUP --> HLR: OSMO_GSUP_MSGT_INSERT_DATA_RESULT: 12010809710000004026f0
DREF VLR subscr MSISDN:42342 usage decreases to: 1
<-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: vlr_gsupc_read_cb() returns 0
lu_result_sent == 0
- HLR also sends GSUP _UPDATE_LOCATION_RESULT
<-- GSUP rx OSMO_GSUP_MSGT_UPDATE_LOCATION_RESULT: 06010809710000004026f0
DVLR GSUP rx 11: 06010809710000004026f0
DREF VLR subscr MSISDN:42342 usage increases to: 2
DVLR vlr_lu_fsm(LU:901700000004620){VLR_ULA_S_WAIT_HLR_UPD}: Received Event VLR_ULA_E_HLR_LU_RES
DVLR upd_hlr_vlr_fsm(LU:901700000004620){UPD_HLR_VLR_S_WAIT_FOR_DATA}: Received Event UPD_HLR_VLR_E_UPD_LOC_ACK
DVLR upd_hlr_vlr_fsm(LU:901700000004620){UPD_HLR_VLR_S_WAIT_FOR_DATA}: state_chg to UPD_HLR_VLR_S_DONE
DVLR upd_hlr_vlr_fsm(LU:901700000004620){UPD_HLR_VLR_S_DONE}: Terminating (cause = OSMO_FSM_TERM_REGULAR)
DVLR upd_hlr_vlr_fsm(LU:901700000004620){UPD_HLR_VLR_S_DONE}: Removing from parent vlr_lu_fsm(LU:901700000004620)
DVLR upd_hlr_vlr_fsm(LU:901700000004620){UPD_HLR_VLR_S_DONE}: Freeing instance
DVLR upd_hlr_vlr_fsm(LU:901700000004620){UPD_HLR_VLR_S_DONE}: Deallocated
DVLR vlr_lu_fsm(LU:901700000004620){VLR_ULA_S_WAIT_HLR_UPD}: Received Event VLR_ULA_E_UPD_HLR_COMPL
DVLR vlr_lu_fsm(LU:901700000004620){VLR_ULA_S_WAIT_HLR_UPD}: state_chg to VLR_ULA_S_WAIT_LU_COMPL
DVLR lu_compl_vlr_fsm(LU:901700000004620){LU_COMPL_VLR_S_INIT}: Allocated
DVLR lu_compl_vlr_fsm(LU:901700000004620){LU_COMPL_VLR_S_INIT}: is child of vlr_lu_fsm(LU:901700000004620)
DVLR lu_compl_vlr_fsm(LU:901700000004620){LU_COMPL_VLR_S_INIT}: Received Event LU_COMPL_VLR_E_START
DVLR lu_compl_vlr_fsm(LU:901700000004620){LU_COMPL_VLR_S_INIT}: state_chg to LU_COMPL_VLR_S_WAIT_SUB_PRES
DVLR sub_pres_vlr_fsm(LU:901700000004620){SUB_PRES_VLR_S_INIT}: Allocated
DVLR sub_pres_vlr_fsm(LU:901700000004620){SUB_PRES_VLR_S_INIT}: is child of lu_compl_vlr_fsm(LU:901700000004620)
DVLR sub_pres_vlr_fsm(LU:901700000004620){SUB_PRES_VLR_S_INIT}: Received Event SUB_PRES_VLR_E_START
DVLR sub_pres_vlr_fsm(LU:901700000004620){SUB_PRES_VLR_S_INIT}: state_chg to SUB_PRES_VLR_S_DONE
DVLR sub_pres_vlr_fsm(LU:901700000004620){SUB_PRES_VLR_S_DONE}: Terminating (cause = OSMO_FSM_TERM_REGULAR)
DVLR sub_pres_vlr_fsm(LU:901700000004620){SUB_PRES_VLR_S_DONE}: Removing from parent lu_compl_vlr_fsm(LU:901700000004620)
DVLR sub_pres_vlr_fsm(LU:901700000004620){SUB_PRES_VLR_S_DONE}: Freeing instance
DVLR sub_pres_vlr_fsm(LU:901700000004620){SUB_PRES_VLR_S_DONE}: Deallocated
DVLR lu_compl_vlr_fsm(LU:901700000004620){LU_COMPL_VLR_S_WAIT_SUB_PRES}: Received Event LU_COMPL_VLR_E_SUB_PRES_COMPL
- sending LU Accept for MSISDN:42342
DREF VLR subscr MSISDN:42342 usage increases to: 3
DVLR lu_compl_vlr_fsm(LU:901700000004620){LU_COMPL_VLR_S_WAIT_SUB_PRES}: state_chg to LU_COMPL_VLR_S_DONE
DVLR vlr_lu_fsm(LU:901700000004620){VLR_ULA_S_WAIT_LU_COMPL}: Received Event VLR_ULA_E_LU_COMPL_SUCCESS
DVLR lu_compl_vlr_fsm(LU:901700000004620){LU_COMPL_VLR_S_DONE}: Terminating (cause = OSMO_FSM_TERM_PARENT)
DVLR lu_compl_vlr_fsm(LU:901700000004620){LU_COMPL_VLR_S_DONE}: Removing from parent vlr_lu_fsm(LU:901700000004620)
DVLR lu_compl_vlr_fsm(LU:901700000004620){LU_COMPL_VLR_S_DONE}: Freeing instance
DVLR lu_compl_vlr_fsm(LU:901700000004620){LU_COMPL_VLR_S_DONE}: Deallocated
DVLR vlr_lu_fsm(LU:901700000004620){VLR_ULA_S_WAIT_LU_COMPL}: state_chg to VLR_ULA_S_DONE
DMM Subscr_Conn(LU:901700000004620){SUBSCR_CONN_S_AUTH_CIPH}: Received Event SUBSCR_CONN_E_ACCEPTED
DMM Subscr_Conn(LU:901700000004620){SUBSCR_CONN_S_AUTH_CIPH}: state_chg to SUBSCR_CONN_S_ACCEPTED
DMM Subscr_Conn(LU:901700000004620){SUBSCR_CONN_S_ACCEPTED}: Received Event SUBSCR_CONN_E_UNUSED
DMM Subscr_Conn(LU:901700000004620){SUBSCR_CONN_S_ACCEPTED}: state_chg to SUBSCR_CONN_S_RELEASING
DREF MSISDN:42342: MSC conn use + release == 1 (0x100: release)
DREF VLR subscr MSISDN:42342 usage increases to: 4
DREF VLR subscr MSISDN:42342 usage decreases to: 3
- BSSAP Clear --RAN_GERAN_A--> MS - BSSAP Clear --RAN_GERAN_A--> MS
DREF IMSI:901700000004620: MSC conn use - dtap == 1 (0x100: release) DREF VLR subscr MSISDN:42342 usage decreases to: 2
lu_result_sent == 2 <-- GSUP rx OSMO_GSUP_MSGT_UPDATE_LOCATION_RESULT: vlr_gsupc_read_cb() returns 0
bssap_clear_sent == 1
- LU was successful, and the conn has already been closed
lu_result_sent == 1
- BSS sends BSSMAP Clear Complete - BSS sends BSSMAP Clear Complete
DREF IMSI:901700000004620: MSC conn use - release == 0 (0x0: ) DREF MSISDN:42342: MSC conn use - release == 0 (0x0: )
DMM Subscr_Conn(LU:901700000004620){SUBSCR_CONN_S_RELEASING}: Received Event SUBSCR_CONN_E_UNUSED DMM Subscr_Conn(LU:901700000004620){SUBSCR_CONN_S_RELEASING}: Received Event SUBSCR_CONN_E_UNUSED
DMM Subscr_Conn(LU:901700000004620){SUBSCR_CONN_S_RELEASING}: state_chg to SUBSCR_CONN_S_RELEASED DMM Subscr_Conn(LU:901700000004620){SUBSCR_CONN_S_RELEASING}: state_chg to SUBSCR_CONN_S_RELEASED
DMM Subscr_Conn(LU:901700000004620){SUBSCR_CONN_S_RELEASED}: Terminating (cause = OSMO_FSM_TERM_REGULAR) DMM Subscr_Conn(LU:901700000004620){SUBSCR_CONN_S_RELEASED}: Terminating (cause = OSMO_FSM_TERM_REGULAR)
@ -2351,13 +2426,827 @@ DVLR vlr_lu_fsm(LU:901700000004620){VLR_ULA_S_DONE}: Removing from parent Subscr
DVLR vlr_lu_fsm(LU:901700000004620){VLR_ULA_S_DONE}: fsm_lu_cleanup called with cause OSMO_FSM_TERM_PARENT DVLR vlr_lu_fsm(LU:901700000004620){VLR_ULA_S_DONE}: fsm_lu_cleanup called with cause OSMO_FSM_TERM_PARENT
DVLR vlr_lu_fsm(LU:901700000004620){VLR_ULA_S_DONE}: Freeing instance DVLR vlr_lu_fsm(LU:901700000004620){VLR_ULA_S_DONE}: Freeing instance
DVLR vlr_lu_fsm(LU:901700000004620){VLR_ULA_S_DONE}: Deallocated DVLR vlr_lu_fsm(LU:901700000004620){VLR_ULA_S_DONE}: Deallocated
DRLL IMSI:901700000004620: Freeing subscriber connection DRLL MSISDN:42342: Freeing subscriber connection
DREF VLR subscr IMSI:901700000004620 usage decreases to: 0 DREF VLR subscr MSISDN:42342 usage decreases to: 1
DREF freeing VLR subscr IMSI:901700000004620
DMM Subscr_Conn(LU:901700000004620){SUBSCR_CONN_S_RELEASED}: Freeing instance DMM Subscr_Conn(LU:901700000004620){SUBSCR_CONN_S_RELEASED}: Freeing instance
DMM Subscr_Conn(LU:901700000004620){SUBSCR_CONN_S_RELEASED}: Deallocated DMM Subscr_Conn(LU:901700000004620){SUBSCR_CONN_S_RELEASED}: Deallocated
llist_count(&net->subscr_conns) == 0 llist_count(&net->subscr_conns) == 0
===== test_a5_3_not_supported: SUCCESS ---
- after a while, a new conn sends a CM Service Request. VLR responds with Auth Req, 2nd auth vector
MSC <--RAN_GERAN_A-- MS: GSM48_MT_MM_CM_SERV_REQ
new conn
DMM Subscr_Conn{SUBSCR_CONN_S_NEW}: Allocated
DREF unknown: MSC conn use + compl_l3 == 1 (0x1: compl_l3)
DRLL Dispatching 04.08 message GSM48_MT_MM_CM_SERV_REQ (0x5:0x24)
DMM <- CM SERVICE REQUEST serv_type=0x08 MI(IMSI)=901700000004620
DMM Subscr_Conn(CM_SERVICE_REQ:901700000004620){SUBSCR_CONN_S_NEW}: Updated ID
DVLR Process_Access_Request_VLR(CM_SERVICE_REQ:901700000004620){PR_ARQ_S_INIT}: Allocated
DVLR Process_Access_Request_VLR(CM_SERVICE_REQ:901700000004620){PR_ARQ_S_INIT}: is child of Subscr_Conn(CM_SERVICE_REQ:901700000004620)
DVLR Process_Access_Request_VLR(CM_SERVICE_REQ:901700000004620){PR_ARQ_S_INIT}: rev=GSM net=GERAN Auth+Ciph
DVLR Process_Access_Request_VLR(CM_SERVICE_REQ:901700000004620){PR_ARQ_S_INIT}: Received Event PR_ARQ_E_START
DREF VLR subscr MSISDN:42342 usage increases to: 2
DREF VLR subscr MSISDN:42342 usage increases to: 3
DVLR Process_Access_Request_VLR(CM_SERVICE_REQ:901700000004620){PR_ARQ_S_INIT}: proc_arq_vlr_fn_post_imsi()
DVLR Process_Access_Request_VLR(CM_SERVICE_REQ:901700000004620){PR_ARQ_S_INIT}: state_chg to PR_ARQ_S_WAIT_AUTH
DVLR VLR_Authenticate(CM_SERVICE_REQ:901700000004620){VLR_SUB_AS_NEEDS_AUTH}: Allocated
DVLR VLR_Authenticate(CM_SERVICE_REQ:901700000004620){VLR_SUB_AS_NEEDS_AUTH}: is child of Process_Access_Request_VLR(CM_SERVICE_REQ:901700000004620)
DVLR VLR_Authenticate(CM_SERVICE_REQ:901700000004620){VLR_SUB_AS_NEEDS_AUTH}: Received Event VLR_AUTH_E_START
DVLR VLR_Authenticate(CM_SERVICE_REQ:901700000004620){VLR_SUB_AS_NEEDS_AUTH}: state_chg to VLR_SUB_AS_WAIT_RESP
DVLR VLR_Authenticate(CM_SERVICE_REQ:901700000004620){VLR_SUB_AS_WAIT_RESP}: got auth tuple: use_count=1 key_seq=1 -- will use GSM AKA (is_r99=no, at->vec.auth_types=0x1)
- sending GSM Auth Request for MSISDN:42342: tuple use_count=1 key_seq=1 auth_types=0x1 and...
- ...rand=12aca96fb4ffdea5c985cbafa9b6e18b
- ...expecting sres=20bde240
DREF VLR subscr MSISDN:42342 usage decreases to: 2
DMM Subscr_Conn(CM_SERVICE_REQ:901700000004620){SUBSCR_CONN_S_NEW}: Received Event SUBSCR_CONN_E_COMPLETE_LAYER_3
DMM Subscr_Conn(CM_SERVICE_REQ:901700000004620){SUBSCR_CONN_S_NEW}: state_chg to SUBSCR_CONN_S_AUTH_CIPH
DREF MSISDN:42342: MSC conn use - compl_l3 == 0 (0x0: )
DMM Subscr_Conn(CM_SERVICE_REQ:901700000004620){SUBSCR_CONN_S_AUTH_CIPH}: Received Event SUBSCR_CONN_E_UNUSED
DMM Subscr_Conn(CM_SERVICE_REQ:901700000004620){SUBSCR_CONN_S_AUTH_CIPH}: Awaiting results for Auth+Ciph, overruling event SUBSCR_CONN_E_UNUSED
auth_request_sent == 1
cm_service_result_sent == 0
- needs auth, not yet accepted
msc_subscr_conn_is_accepted() == false
requests shall be thwarted
DRLL Dispatching 04.08 message GSM48_MT_CC_SETUP (0x3:0x5)
DRLL subscr MSISDN:42342: Message not permitted for initial conn: GSM48_MT_CC_SETUP
DRLL Dispatching 04.08 message unknown 0x33 (0x5:0x33)
DRLL subscr MSISDN:42342: Message not permitted for initial conn: unknown 0x33
DRLL Dispatching 04.08 message GSM48_MT_RR_SYSINFO_1 (0x6:0x19)
DRLL subscr MSISDN:42342: Message not permitted for initial conn: GSM48_MT_RR_SYSINFO_1
DRLL Dispatching 04.08 message SMS:0x01 (0x9:0x1)
DRLL subscr MSISDN:42342: Message not permitted for initial conn: SMS:0x01
- MS sends Authen Response, VLR accepts and requests Ciphering. We already know Classmark 3, so no need to request Classmark Update.
MSC <--RAN_GERAN_A-- MS: GSM48_MT_MM_AUTH_RESP
DREF MSISDN:42342: MSC conn use + dtap == 1 (0x2: dtap)
DRLL Dispatching 04.08 message GSM48_MT_MM_AUTH_RESP (0x5:0x14)
DMM MSISDN:42342: MM GSM AUTHENTICATION RESPONSE (sres = 20bde240)
DVLR VLR_Authenticate(CM_SERVICE_REQ:901700000004620){VLR_SUB_AS_WAIT_RESP}: Received Event VLR_AUTH_E_MS_AUTH_RESP
DVLR SUBSCR(MSISDN:42342) AUTH on GERAN received SRES/RES: 20bde240 (4 bytes)
DVLR SUBSCR(MSISDN:42342) AUTH established GSM security context
DVLR VLR_Authenticate(CM_SERVICE_REQ:901700000004620){VLR_SUB_AS_WAIT_RESP}: Authentication terminating with result PASSED
DVLR VLR_Authenticate(CM_SERVICE_REQ:901700000004620){VLR_SUB_AS_WAIT_RESP}: state_chg to VLR_SUB_AS_AUTHENTICATED
DVLR VLR_Authenticate(CM_SERVICE_REQ:901700000004620){VLR_SUB_AS_AUTHENTICATED}: Terminating (cause = OSMO_FSM_TERM_REGULAR)
DVLR VLR_Authenticate(CM_SERVICE_REQ:901700000004620){VLR_SUB_AS_AUTHENTICATED}: Removing from parent Process_Access_Request_VLR(CM_SERVICE_REQ:901700000004620)
DVLR VLR_Authenticate(CM_SERVICE_REQ:901700000004620){VLR_SUB_AS_AUTHENTICATED}: Freeing instance
DVLR VLR_Authenticate(CM_SERVICE_REQ:901700000004620){VLR_SUB_AS_AUTHENTICATED}: Deallocated
DVLR Process_Access_Request_VLR(CM_SERVICE_REQ:901700000004620){PR_ARQ_S_WAIT_AUTH}: Received Event PR_ARQ_E_AUTH_RES
DVLR Process_Access_Request_VLR(CM_SERVICE_REQ:901700000004620){PR_ARQ_S_WAIT_AUTH}: _proc_arq_vlr_node2()
DVLR Process_Access_Request_VLR(CM_SERVICE_REQ:901700000004620){PR_ARQ_S_WAIT_AUTH}: Set Ciphering Mode
DMM -> CIPHER MODE COMMAND MSISDN:42342
- sending Ciphering Mode Command for MSISDN:42342: include_imeisv=0
- ...perm algo: A5/3
- ...key: 07fa7502e07e1c00
DVLR Process_Access_Request_VLR(CM_SERVICE_REQ:901700000004620){PR_ARQ_S_WAIT_AUTH}: state_chg to PR_ARQ_S_WAIT_CIPH
DREF MSISDN:42342: MSC conn use - dtap == 0 (0x0: )
DMM Subscr_Conn(CM_SERVICE_REQ:901700000004620){SUBSCR_CONN_S_AUTH_CIPH}: Received Event SUBSCR_CONN_E_UNUSED
DMM Subscr_Conn(CM_SERVICE_REQ:901700000004620){SUBSCR_CONN_S_AUTH_CIPH}: Awaiting results for Auth+Ciph, overruling event SUBSCR_CONN_E_UNUSED
cm_service_result_sent == 0
cipher_mode_cmd_sent == 1
- needs ciph, not yet accepted
msc_subscr_conn_is_accepted() == false
requests shall be thwarted
DRLL Dispatching 04.08 message GSM48_MT_CC_SETUP (0x3:0x5)
DRLL subscr MSISDN:42342: Message not permitted for initial conn: GSM48_MT_CC_SETUP
DRLL Dispatching 04.08 message unknown 0x33 (0x5:0x33)
DRLL subscr MSISDN:42342: Message not permitted for initial conn: unknown 0x33
DRLL Dispatching 04.08 message GSM48_MT_RR_SYSINFO_1 (0x6:0x19)
DRLL subscr MSISDN:42342: Message not permitted for initial conn: GSM48_MT_RR_SYSINFO_1
DRLL Dispatching 04.08 message SMS:0x01 (0x9:0x1)
DRLL subscr MSISDN:42342: Message not permitted for initial conn: SMS:0x01
- MS sends Ciphering Mode Complete, VLR accepts; above Ciphering is an implicit CM Service Accept
MSC <--RAN_GERAN_A-- MS: GSM48_MT_RR_CIPH_M_COMPL
DRR MSISDN:42342: CIPHERING MODE COMPLETE
DVLR Process_Access_Request_VLR(CM_SERVICE_REQ:901700000004620){PR_ARQ_S_WAIT_CIPH}: Received Event PR_ARQ_E_CIPH_RES
DVLR Process_Access_Request_VLR(CM_SERVICE_REQ:901700000004620){PR_ARQ_S_WAIT_CIPH}: _proc_arq_vlr_node2_post_ciph()
DVLR Process_Access_Request_VLR(CM_SERVICE_REQ:901700000004620){PR_ARQ_S_WAIT_CIPH}: _proc_arq_vlr_node2_post_vlr()
DVLR Process_Access_Request_VLR(CM_SERVICE_REQ:901700000004620){PR_ARQ_S_WAIT_CIPH}: _proc_arq_vlr_post_pres()
DVLR Process_Access_Request_VLR(CM_SERVICE_REQ:901700000004620){PR_ARQ_S_WAIT_CIPH}: _proc_arq_vlr_post_trace()
DVLR Process_Access_Request_VLR(CM_SERVICE_REQ:901700000004620){PR_ARQ_S_WAIT_CIPH}: _proc_arq_vlr_post_imei()
DVLR Process_Access_Request_VLR(CM_SERVICE_REQ:901700000004620){PR_ARQ_S_WAIT_CIPH}: proc_arq_fsm_done(PASSED)
DVLR Process_Access_Request_VLR(CM_SERVICE_REQ:901700000004620){PR_ARQ_S_WAIT_CIPH}: state_chg to PR_ARQ_S_DONE
DVLR Process_Access_Request_VLR(CM_SERVICE_REQ:901700000004620){PR_ARQ_S_DONE}: Process Access Request result: PASSED
DMM Subscr_Conn(CM_SERVICE_REQ:901700000004620){SUBSCR_CONN_S_AUTH_CIPH}: Received Event SUBSCR_CONN_E_ACCEPTED
DREF MSISDN:42342: MSC conn use + cm_service == 1 (0x8: cm_service)
DMM Subscr_Conn(CM_SERVICE_REQ:901700000004620){SUBSCR_CONN_S_AUTH_CIPH}: state_chg to SUBSCR_CONN_S_ACCEPTED
DMM Subscr_Conn(CM_SERVICE_REQ:901700000004620){SUBSCR_CONN_S_ACCEPTED}: subscr_conn_fsm_has_active_transactions: still awaiting first request after a CM Service Request
cm_service_result_sent == 0
- Concluding CM Service Request
DREF MSISDN:42342: MSC conn use - cm_service == 0 (0x0: )
DMM Subscr_Conn(CM_SERVICE_REQ:901700000004620){SUBSCR_CONN_S_ACCEPTED}: Received Event SUBSCR_CONN_E_UNUSED
DMM Subscr_Conn(CM_SERVICE_REQ:901700000004620){SUBSCR_CONN_S_ACCEPTED}: state_chg to SUBSCR_CONN_S_RELEASING
DREF MSISDN:42342: MSC conn use + release == 1 (0x100: release)
DREF VLR subscr MSISDN:42342 usage increases to: 3
DREF VLR subscr MSISDN:42342 usage decreases to: 2
- BSSAP Clear --RAN_GERAN_A--> MS
bssap_clear_sent == 1
- all requests serviced, conn has been released
- BSS sends BSSMAP Clear Complete
DREF MSISDN:42342: MSC conn use - release == 0 (0x0: )
DMM Subscr_Conn(CM_SERVICE_REQ:901700000004620){SUBSCR_CONN_S_RELEASING}: Received Event SUBSCR_CONN_E_UNUSED
DMM Subscr_Conn(CM_SERVICE_REQ:901700000004620){SUBSCR_CONN_S_RELEASING}: state_chg to SUBSCR_CONN_S_RELEASED
DMM Subscr_Conn(CM_SERVICE_REQ:901700000004620){SUBSCR_CONN_S_RELEASED}: Terminating (cause = OSMO_FSM_TERM_REGULAR)
DVLR Process_Access_Request_VLR(CM_SERVICE_REQ:901700000004620){PR_ARQ_S_DONE}: Terminating (cause = OSMO_FSM_TERM_PARENT)
DVLR Process_Access_Request_VLR(CM_SERVICE_REQ:901700000004620){PR_ARQ_S_DONE}: Removing from parent Subscr_Conn(CM_SERVICE_REQ:901700000004620)
DVLR Process_Access_Request_VLR(CM_SERVICE_REQ:901700000004620){PR_ARQ_S_DONE}: Freeing instance
DVLR Process_Access_Request_VLR(CM_SERVICE_REQ:901700000004620){PR_ARQ_S_DONE}: Deallocated
DRLL MSISDN:42342: Freeing subscriber connection
DREF VLR subscr MSISDN:42342 usage decreases to: 1
DMM Subscr_Conn(CM_SERVICE_REQ:901700000004620){SUBSCR_CONN_S_RELEASED}: Freeing instance
DMM Subscr_Conn(CM_SERVICE_REQ:901700000004620){SUBSCR_CONN_S_RELEASED}: Deallocated
llist_count(&net->subscr_conns) == 0
---
- an SMS is sent, MS is paged
DREF VLR subscr MSISDN:42342 usage increases to: 2
llist_count(&vsub->cs.requests) == 0
DREF VLR subscr MSISDN:42342 usage increases to: 3
DMM Subscriber MSISDN:42342 not paged yet, start paging.
RAN_GERAN_A sends out paging request to IMSI 901700000004620, TMSI 0xffffffff, LAC 23
strcmp(paging_expecting_imsi, imsi) == 0
DREF VLR subscr MSISDN:42342 usage increases to: 4
llist_count(&vsub->cs.requests) == 1
DREF VLR subscr MSISDN:42342 usage decreases to: 3
paging_sent == 1
paging_stopped == 0
- the subscriber and its pending request should remain
DREF VLR subscr MSISDN:42342 usage increases to: 4
llist_count(&vsub->cs.requests) == 1
DREF VLR subscr MSISDN:42342 usage decreases to: 3
- MS replies with Paging Response, and VLR sends Auth Request with third key
MSC <--RAN_GERAN_A-- MS: GSM48_MT_RR_PAG_RESP
new conn
DMM Subscr_Conn{SUBSCR_CONN_S_NEW}: Allocated
DREF unknown: MSC conn use + compl_l3 == 1 (0x1: compl_l3)
DRLL Dispatching 04.08 message GSM48_MT_RR_PAG_RESP (0x6:0x27)
DRR PAGING RESPONSE: MI(IMSI)=901700000004620
DMM Subscr_Conn(PAGING_RESP:901700000004620){SUBSCR_CONN_S_NEW}: Updated ID
DVLR Process_Access_Request_VLR(PAGING_RESP:901700000004620){PR_ARQ_S_INIT}: Allocated
DVLR Process_Access_Request_VLR(PAGING_RESP:901700000004620){PR_ARQ_S_INIT}: is child of Subscr_Conn(PAGING_RESP:901700000004620)
DVLR Process_Access_Request_VLR(PAGING_RESP:901700000004620){PR_ARQ_S_INIT}: rev=GSM net=GERAN Auth+Ciph
DVLR Process_Access_Request_VLR(PAGING_RESP:901700000004620){PR_ARQ_S_INIT}: Received Event PR_ARQ_E_START
DREF VLR subscr MSISDN:42342 usage increases to: 4
DREF VLR subscr MSISDN:42342 usage increases to: 5
DVLR Process_Access_Request_VLR(PAGING_RESP:901700000004620){PR_ARQ_S_INIT}: proc_arq_vlr_fn_post_imsi()
DVLR Process_Access_Request_VLR(PAGING_RESP:901700000004620){PR_ARQ_S_INIT}: state_chg to PR_ARQ_S_WAIT_AUTH
DVLR VLR_Authenticate(PAGING_RESP:901700000004620){VLR_SUB_AS_NEEDS_AUTH}: Allocated
DVLR VLR_Authenticate(PAGING_RESP:901700000004620){VLR_SUB_AS_NEEDS_AUTH}: is child of Process_Access_Request_VLR(PAGING_RESP:901700000004620)
DVLR VLR_Authenticate(PAGING_RESP:901700000004620){VLR_SUB_AS_NEEDS_AUTH}: Received Event VLR_AUTH_E_START
DVLR VLR_Authenticate(PAGING_RESP:901700000004620){VLR_SUB_AS_NEEDS_AUTH}: state_chg to VLR_SUB_AS_WAIT_RESP
DVLR VLR_Authenticate(PAGING_RESP:901700000004620){VLR_SUB_AS_WAIT_RESP}: got auth tuple: use_count=1 key_seq=2 -- will use GSM AKA (is_r99=no, at->vec.auth_types=0x1)
- sending GSM Auth Request for MSISDN:42342: tuple use_count=1 key_seq=2 auth_types=0x1 and...
- ...rand=e7c03ba7cf0e2fde82b2dc4d63077d42
- ...expecting sres=a29514ae
DREF VLR subscr MSISDN:42342 usage decreases to: 4
DMM Subscr_Conn(PAGING_RESP:901700000004620){SUBSCR_CONN_S_NEW}: Received Event SUBSCR_CONN_E_COMPLETE_LAYER_3
DMM Subscr_Conn(PAGING_RESP:901700000004620){SUBSCR_CONN_S_NEW}: state_chg to SUBSCR_CONN_S_AUTH_CIPH
DREF MSISDN:42342: MSC conn use - compl_l3 == 0 (0x0: )
DMM Subscr_Conn(PAGING_RESP:901700000004620){SUBSCR_CONN_S_AUTH_CIPH}: Received Event SUBSCR_CONN_E_UNUSED
DMM Subscr_Conn(PAGING_RESP:901700000004620){SUBSCR_CONN_S_AUTH_CIPH}: Awaiting results for Auth+Ciph, overruling event SUBSCR_CONN_E_UNUSED
auth_request_sent == 1
- needs auth, not yet accepted
msc_subscr_conn_is_accepted() == false
requests shall be thwarted
DRLL Dispatching 04.08 message GSM48_MT_CC_SETUP (0x3:0x5)
DRLL subscr MSISDN:42342: Message not permitted for initial conn: GSM48_MT_CC_SETUP
DRLL Dispatching 04.08 message unknown 0x33 (0x5:0x33)
DRLL subscr MSISDN:42342: Message not permitted for initial conn: unknown 0x33
DRLL Dispatching 04.08 message GSM48_MT_RR_SYSINFO_1 (0x6:0x19)
DRLL subscr MSISDN:42342: Message not permitted for initial conn: GSM48_MT_RR_SYSINFO_1
DRLL Dispatching 04.08 message SMS:0x01 (0x9:0x1)
DRLL subscr MSISDN:42342: Message not permitted for initial conn: SMS:0x01
- MS sends Authen Response, VLR accepts and requests Ciphering
MSC <--RAN_GERAN_A-- MS: GSM48_MT_MM_AUTH_RESP
DREF MSISDN:42342: MSC conn use + dtap == 1 (0x2: dtap)
DRLL Dispatching 04.08 message GSM48_MT_MM_AUTH_RESP (0x5:0x14)
DMM MSISDN:42342: MM GSM AUTHENTICATION RESPONSE (sres = a29514ae)
DVLR VLR_Authenticate(PAGING_RESP:901700000004620){VLR_SUB_AS_WAIT_RESP}: Received Event VLR_AUTH_E_MS_AUTH_RESP
DVLR SUBSCR(MSISDN:42342) AUTH on GERAN received SRES/RES: a29514ae (4 bytes)
DVLR SUBSCR(MSISDN:42342) AUTH established GSM security context
DVLR VLR_Authenticate(PAGING_RESP:901700000004620){VLR_SUB_AS_WAIT_RESP}: Authentication terminating with result PASSED
DVLR VLR_Authenticate(PAGING_RESP:901700000004620){VLR_SUB_AS_WAIT_RESP}: state_chg to VLR_SUB_AS_AUTHENTICATED
DVLR VLR_Authenticate(PAGING_RESP:901700000004620){VLR_SUB_AS_AUTHENTICATED}: Terminating (cause = OSMO_FSM_TERM_REGULAR)
DVLR VLR_Authenticate(PAGING_RESP:901700000004620){VLR_SUB_AS_AUTHENTICATED}: Removing from parent Process_Access_Request_VLR(PAGING_RESP:901700000004620)
DVLR VLR_Authenticate(PAGING_RESP:901700000004620){VLR_SUB_AS_AUTHENTICATED}: Freeing instance
DVLR VLR_Authenticate(PAGING_RESP:901700000004620){VLR_SUB_AS_AUTHENTICATED}: Deallocated
DVLR Process_Access_Request_VLR(PAGING_RESP:901700000004620){PR_ARQ_S_WAIT_AUTH}: Received Event PR_ARQ_E_AUTH_RES
DVLR Process_Access_Request_VLR(PAGING_RESP:901700000004620){PR_ARQ_S_WAIT_AUTH}: _proc_arq_vlr_node2()
DVLR Process_Access_Request_VLR(PAGING_RESP:901700000004620){PR_ARQ_S_WAIT_AUTH}: Set Ciphering Mode
DMM -> CIPHER MODE COMMAND MSISDN:42342
- sending Ciphering Mode Command for MSISDN:42342: include_imeisv=0
- ...perm algo: A5/3
- ...key: e2b234f807886400
DVLR Process_Access_Request_VLR(PAGING_RESP:901700000004620){PR_ARQ_S_WAIT_AUTH}: state_chg to PR_ARQ_S_WAIT_CIPH
DREF MSISDN:42342: MSC conn use - dtap == 0 (0x0: )
DMM Subscr_Conn(PAGING_RESP:901700000004620){SUBSCR_CONN_S_AUTH_CIPH}: Received Event SUBSCR_CONN_E_UNUSED
DMM Subscr_Conn(PAGING_RESP:901700000004620){SUBSCR_CONN_S_AUTH_CIPH}: Awaiting results for Auth+Ciph, overruling event SUBSCR_CONN_E_UNUSED
cipher_mode_cmd_sent == 1
- needs ciph, not yet accepted
msc_subscr_conn_is_accepted() == false
requests shall be thwarted
DRLL Dispatching 04.08 message GSM48_MT_CC_SETUP (0x3:0x5)
DRLL subscr MSISDN:42342: Message not permitted for initial conn: GSM48_MT_CC_SETUP
DRLL Dispatching 04.08 message unknown 0x33 (0x5:0x33)
DRLL subscr MSISDN:42342: Message not permitted for initial conn: unknown 0x33
DRLL Dispatching 04.08 message GSM48_MT_RR_SYSINFO_1 (0x6:0x19)
DRLL subscr MSISDN:42342: Message not permitted for initial conn: GSM48_MT_RR_SYSINFO_1
DRLL Dispatching 04.08 message SMS:0x01 (0x9:0x1)
DRLL subscr MSISDN:42342: Message not permitted for initial conn: SMS:0x01
- MS sends Ciphering Mode Complete, VLR accepts and sends pending SMS
MSC <--RAN_GERAN_A-- MS: GSM48_MT_RR_CIPH_M_COMPL
DRR MSISDN:42342: CIPHERING MODE COMPLETE
DVLR Process_Access_Request_VLR(PAGING_RESP:901700000004620){PR_ARQ_S_WAIT_CIPH}: Received Event PR_ARQ_E_CIPH_RES
DVLR Process_Access_Request_VLR(PAGING_RESP:901700000004620){PR_ARQ_S_WAIT_CIPH}: _proc_arq_vlr_node2_post_ciph()
DVLR Process_Access_Request_VLR(PAGING_RESP:901700000004620){PR_ARQ_S_WAIT_CIPH}: _proc_arq_vlr_node2_post_vlr()
DVLR Process_Access_Request_VLR(PAGING_RESP:901700000004620){PR_ARQ_S_WAIT_CIPH}: _proc_arq_vlr_post_pres()
DVLR Process_Access_Request_VLR(PAGING_RESP:901700000004620){PR_ARQ_S_WAIT_CIPH}: _proc_arq_vlr_post_trace()
DVLR Process_Access_Request_VLR(PAGING_RESP:901700000004620){PR_ARQ_S_WAIT_CIPH}: _proc_arq_vlr_post_imei()
DVLR Process_Access_Request_VLR(PAGING_RESP:901700000004620){PR_ARQ_S_WAIT_CIPH}: proc_arq_fsm_done(PASSED)
DVLR Process_Access_Request_VLR(PAGING_RESP:901700000004620){PR_ARQ_S_WAIT_CIPH}: state_chg to PR_ARQ_S_DONE
DVLR Process_Access_Request_VLR(PAGING_RESP:901700000004620){PR_ARQ_S_DONE}: Process Access Request result: PASSED
DMM Subscr_Conn(PAGING_RESP:901700000004620){SUBSCR_CONN_S_AUTH_CIPH}: Received Event SUBSCR_CONN_E_ACCEPTED
DPAG Paging success for MSISDN:42342 (event=0)
DPAG Calling paging cbfn.
DCC (ti 00 sub MSISDN:42342 callref 40000004) New transaction
DREF VLR subscr MSISDN:42342 usage increases to: 5
DREF MSISDN:42342: MSC conn use + trans_sms == 1 (0x20: trans_sms)
DMSC msc_tx 91 bytes to MSISDN:42342 via RAN_GERAN_A
- DTAP --RAN_GERAN_A--> MS: SMS:0x01: 09015801000791447758100650004c0005802443f2000007101000000000445079da1e1ee7416937485e9ea7c965373d1d6683c270383b3d0ed3d36ff71c949e83c22072799e9687c5ec32a81d96afcbf4b4fb0c7ac3e9e9b7db05
- DTAP matches expected message
DREF VLR subscr MSISDN:42342 usage decreases to: 4
DMM Subscr_Conn(PAGING_RESP:901700000004620){SUBSCR_CONN_S_AUTH_CIPH}: state_chg to SUBSCR_CONN_S_ACCEPTED
DMM Subscr_Conn(PAGING_RESP:901700000004620){SUBSCR_CONN_S_ACCEPTED}: subscr_conn_fsm_has_active_transactions: connection still has active transaction: SMS
dtap_tx_confirmed == 1
paging_stopped == 1
- SMS was delivered, no requests pending for subscr
DREF VLR subscr MSISDN:42342 usage increases to: 5
llist_count(&vsub->cs.requests) == 0
DREF VLR subscr MSISDN:42342 usage decreases to: 4
- conn is still open to wait for SMS ack dance
llist_count(&net->subscr_conns) == 1
- MS replies with CP-ACK for received SMS
MSC <--RAN_GERAN_A-- MS: SMS:0x04
DREF MSISDN:42342: MSC conn use + dtap == 2 (0x22: dtap,trans_sms)
DRLL Dispatching 04.08 message SMS:0x04 (0x9:0x4)
DMM Subscr_Conn(PAGING_RESP:901700000004620){SUBSCR_CONN_S_ACCEPTED}: Received Event SUBSCR_CONN_E_COMMUNICATING
DMM Subscr_Conn(PAGING_RESP:901700000004620){SUBSCR_CONN_S_ACCEPTED}: state_chg to SUBSCR_CONN_S_COMMUNICATING
DREF MSISDN:42342: MSC conn use - dtap == 1 (0x20: trans_sms)
llist_count(&net->subscr_conns) == 1
- MS also sends RP-ACK, MSC in turn sends CP-ACK for that
MSC <--RAN_GERAN_A-- MS: SMS:0x01
DREF MSISDN:42342: MSC conn use + dtap == 2 (0x22: dtap,trans_sms)
DRLL Dispatching 04.08 message SMS:0x01 (0x9:0x1)
DMM Subscr_Conn(PAGING_RESP:901700000004620){SUBSCR_CONN_S_COMMUNICATING}: Received Event SUBSCR_CONN_E_COMMUNICATING
DMSC msc_tx 2 bytes to MSISDN:42342 via RAN_GERAN_A
- DTAP --RAN_GERAN_A--> MS: SMS:0x04: 0904
- DTAP matches expected message
DREF VLR subscr MSISDN:42342 usage decreases to: 3
DREF VLR subscr MSISDN:42342 usage decreases to: 2
DREF MSISDN:42342: MSC conn use - trans_sms == 1 (0x2: dtap)
DREF MSISDN:42342: MSC conn use - dtap == 0 (0x0: )
DMM Subscr_Conn(PAGING_RESP:901700000004620){SUBSCR_CONN_S_COMMUNICATING}: Received Event SUBSCR_CONN_E_UNUSED
DMM Subscr_Conn(PAGING_RESP:901700000004620){SUBSCR_CONN_S_COMMUNICATING}: state_chg to SUBSCR_CONN_S_RELEASING
DREF MSISDN:42342: MSC conn use + release == 1 (0x100: release)
DREF VLR subscr MSISDN:42342 usage increases to: 3
DREF VLR subscr MSISDN:42342 usage decreases to: 2
- BSSAP Clear --RAN_GERAN_A--> MS
dtap_tx_confirmed == 1
bssap_clear_sent == 1
- SMS is done, conn is gone
- BSS sends BSSMAP Clear Complete
DREF MSISDN:42342: MSC conn use - release == 0 (0x0: )
DMM Subscr_Conn(PAGING_RESP:901700000004620){SUBSCR_CONN_S_RELEASING}: Received Event SUBSCR_CONN_E_UNUSED
DMM Subscr_Conn(PAGING_RESP:901700000004620){SUBSCR_CONN_S_RELEASING}: state_chg to SUBSCR_CONN_S_RELEASED
DMM Subscr_Conn(PAGING_RESP:901700000004620){SUBSCR_CONN_S_RELEASED}: Terminating (cause = OSMO_FSM_TERM_REGULAR)
DVLR Process_Access_Request_VLR(PAGING_RESP:901700000004620){PR_ARQ_S_DONE}: Terminating (cause = OSMO_FSM_TERM_PARENT)
DVLR Process_Access_Request_VLR(PAGING_RESP:901700000004620){PR_ARQ_S_DONE}: Removing from parent Subscr_Conn(PAGING_RESP:901700000004620)
DVLR Process_Access_Request_VLR(PAGING_RESP:901700000004620){PR_ARQ_S_DONE}: Freeing instance
DVLR Process_Access_Request_VLR(PAGING_RESP:901700000004620){PR_ARQ_S_DONE}: Deallocated
DRLL MSISDN:42342: Freeing subscriber connection
DREF VLR subscr MSISDN:42342 usage decreases to: 1
DMM Subscr_Conn(PAGING_RESP:901700000004620){SUBSCR_CONN_S_RELEASED}: Freeing instance
DMM Subscr_Conn(PAGING_RESP:901700000004620){SUBSCR_CONN_S_RELEASED}: Deallocated
llist_count(&net->subscr_conns) == 0
---
- subscriber detaches
MSC <--RAN_GERAN_A-- MS: GSM48_MT_MM_IMSI_DETACH_IND
new conn
DMM Subscr_Conn{SUBSCR_CONN_S_NEW}: Allocated
DREF unknown: MSC conn use + compl_l3 == 1 (0x1: compl_l3)
DRLL Dispatching 04.08 message GSM48_MT_MM_IMSI_DETACH_IND (0x5:0x1)
DMM IMSI DETACH INDICATION: MI(IMSI)=901700000004620
DREF VLR subscr MSISDN:42342 usage increases to: 2
DMM IMSI DETACH for MSISDN:42342
DREF VLR subscr MSISDN:42342 usage increases to: 3
DREF VLR subscr MSISDN:42342 usage decreases to: 2
DREF VLR subscr MSISDN:42342 usage decreases to: 1
DREF VLR subscr MSISDN:42342 usage decreases to: 0
DREF freeing VLR subscr MSISDN:42342
DMM Subscr_Conn{SUBSCR_CONN_S_NEW}: Received Event SUBSCR_CONN_E_CN_CLOSE
DMM Subscr_Conn{SUBSCR_CONN_S_NEW}: state_chg to SUBSCR_CONN_S_RELEASING
DREF unknown: MSC conn use + release == 2 (0x101: compl_l3,release)
- BSSAP Clear --RAN_GERAN_A--> MS
DREF unknown: MSC conn use - compl_l3 == 1 (0x100: release)
bssap_clear_sent == 1
- BSS sends BSSMAP Clear Complete
DREF unknown: MSC conn use - release == 0 (0x0: )
DMM Subscr_Conn{SUBSCR_CONN_S_RELEASING}: Received Event SUBSCR_CONN_E_UNUSED
DMM Subscr_Conn{SUBSCR_CONN_S_RELEASING}: state_chg to SUBSCR_CONN_S_RELEASED
DMM Subscr_Conn{SUBSCR_CONN_S_RELEASED}: Terminating (cause = OSMO_FSM_TERM_REGULAR)
DRLL Freeing subscriber connection with NULL subscriber
DMM Subscr_Conn{SUBSCR_CONN_S_RELEASED}: Freeing instance
DMM Subscr_Conn{SUBSCR_CONN_S_RELEASED}: Deallocated
llist_count(&net->subscr_conns) == 0
===== test_a5_3_supported: SUCCESS
full talloc report on 'msgb' (total 0 bytes in 1 blocks)
talloc_total_blocks(tall_bsc_ctx) == 12
===== test_cm_service_needs_classmark_update
- Location Update request causes a GSUP Send Auth Info request to HLR
MSC <--RAN_GERAN_A-- MS: GSM48_MT_MM_LOC_UPD_REQUEST
new conn
DMM Subscr_Conn{SUBSCR_CONN_S_NEW}: Allocated
DREF unknown: MSC conn use + compl_l3 == 1 (0x1: compl_l3)
DRLL Dispatching 04.08 message GSM48_MT_MM_LOC_UPD_REQUEST (0x5:0x8)
DMM Subscr_Conn(LU:901700000004620){SUBSCR_CONN_S_NEW}: Updated ID
DMM LOCATION UPDATING REQUEST: MI(IMSI)=901700000004620 type=IMSI ATTACH
DMM LU/new-LAC: 1/23
DVLR vlr_lu_fsm(LU:901700000004620){VLR_ULA_S_IDLE}: Allocated
DVLR vlr_lu_fsm(LU:901700000004620){VLR_ULA_S_IDLE}: is child of Subscr_Conn(LU:901700000004620)
DVLR vlr_lu_fsm(LU:901700000004620){VLR_ULA_S_IDLE}: rev=GSM net=GERAN Auth+Ciph
DVLR vlr_lu_fsm(LU:901700000004620){VLR_ULA_S_IDLE}: Received Event VLR_ULA_E_UPDATE_LA
DREF VLR subscr unknown usage increases to: 1
DVLR set IMSI on subscriber; IMSI=901700000004620 id=901700000004620
DVLR New subscr, IMSI: 901700000004620
DREF VLR subscr IMSI:901700000004620 usage increases to: 2
DREF VLR subscr IMSI:901700000004620 usage decreases to: 1
DVLR vlr_lu_fsm(LU:901700000004620){VLR_ULA_S_IDLE}: vlr_loc_upd_node1()
DVLR vlr_lu_fsm(LU:901700000004620){VLR_ULA_S_IDLE}: state_chg to VLR_ULA_S_WAIT_AUTH
DVLR VLR_Authenticate(LU:901700000004620){VLR_SUB_AS_NEEDS_AUTH}: Allocated
DVLR VLR_Authenticate(LU:901700000004620){VLR_SUB_AS_NEEDS_AUTH}: is child of vlr_lu_fsm(LU:901700000004620)
DVLR VLR_Authenticate(LU:901700000004620){VLR_SUB_AS_NEEDS_AUTH}: Received Event VLR_AUTH_E_START
DVLR GSUP tx: 08010809710000004026f0
GSUP --> HLR: OSMO_GSUP_MSGT_SEND_AUTH_INFO_REQUEST: 08010809710000004026f0
DVLR VLR_Authenticate(LU:901700000004620){VLR_SUB_AS_NEEDS_AUTH}: state_chg to VLR_SUB_AS_NEEDS_AUTH_WAIT_AI
DMM Subscr_Conn(LU:901700000004620){SUBSCR_CONN_S_NEW}: Received Event SUBSCR_CONN_E_COMPLETE_LAYER_3
DMM Subscr_Conn(LU:901700000004620){SUBSCR_CONN_S_NEW}: state_chg to SUBSCR_CONN_S_AUTH_CIPH
DREF IMSI:901700000004620: MSC conn use - compl_l3 == 0 (0x0: )
DMM Subscr_Conn(LU:901700000004620){SUBSCR_CONN_S_AUTH_CIPH}: Received Event SUBSCR_CONN_E_UNUSED
DMM Subscr_Conn(LU:901700000004620){SUBSCR_CONN_S_AUTH_CIPH}: Awaiting results for Auth+Ciph, overruling event SUBSCR_CONN_E_UNUSED
lu_result_sent == 0
- from HLR, rx _SEND_AUTH_INFO_RESULT; VLR sends Auth Req to MS
<-- GSUP rx OSMO_GSUP_MSGT_SEND_AUTH_INFO_RESULT: 0a010809710000004026f003222010585df1ae287f6e273dce07090d61320b21042d8b2c3e220861855fb81fc2a8000322201012aca96fb4ffdea5c985cbafa9b6e18b210420bde240220807fa7502e07e1c0003222010e7c03ba7cf0e2fde82b2dc4d63077d422104a29514ae2208e2b234f80788640003222010fa8f20b781b5881329d4fea26b1a3c5121045afc8d7222082392f14f709ae000032220100fd4cc8dbe8715d1f439e304edfd68dc2104bc8d1c5b2208da7cdd6bfe2d7000
DVLR GSUP rx 191: 0a010809710000004026f003222010585df1ae287f6e273dce07090d61320b21042d8b2c3e220861855fb81fc2a8000322201012aca96fb4ffdea5c985cbafa9b6e18b210420bde240220807fa7502e07e1c0003222010e7c03ba7cf0e2fde82b2dc4d63077d422104a29514ae2208e2b234f80788640003222010fa8f20b781b5881329d4fea26b1a3c5121045afc8d7222082392f14f709ae000032220100fd4cc8dbe8715d1f439e304edfd68dc2104bc8d1c5b2208da7cdd6bfe2d7000
DREF VLR subscr IMSI:901700000004620 usage increases to: 2
DVLR VLR_Authenticate(LU:901700000004620){VLR_SUB_AS_NEEDS_AUTH_WAIT_AI}: Received Event VLR_AUTH_E_HLR_SAI_ACK
DVLR SUBSCR(IMSI:901700000004620) Received 5 auth tuples
DVLR VLR_Authenticate(LU:901700000004620){VLR_SUB_AS_NEEDS_AUTH_WAIT_AI}: state_chg to VLR_SUB_AS_WAIT_RESP
DVLR VLR_Authenticate(LU:901700000004620){VLR_SUB_AS_WAIT_RESP}: got auth tuple: use_count=1 key_seq=0 -- will use GSM AKA (is_r99=no, at->vec.auth_types=0x1)
- sending GSM Auth Request for IMSI:901700000004620: tuple use_count=1 key_seq=0 auth_types=0x1 and...
- ...rand=585df1ae287f6e273dce07090d61320b
- ...expecting sres=2d8b2c3e
DREF VLR subscr IMSI:901700000004620 usage decreases to: 1
<-- GSUP rx OSMO_GSUP_MSGT_SEND_AUTH_INFO_RESULT: vlr_gsupc_read_cb() returns 0
lu_result_sent == 0
auth_request_sent == 1
---
- MS sends Authen Response, VLR accepts and wants to send Ciphering Mode Command to MS -- but needs Classmark 2 to determine whether A5/3 is supported
MSC <--RAN_GERAN_A-- MS: GSM48_MT_MM_AUTH_RESP
DREF IMSI:901700000004620: MSC conn use + dtap == 1 (0x2: dtap)
DRLL Dispatching 04.08 message GSM48_MT_MM_AUTH_RESP (0x5:0x14)
DMM IMSI:901700000004620: MM GSM AUTHENTICATION RESPONSE (sres = 2d8b2c3e)
DVLR VLR_Authenticate(LU:901700000004620){VLR_SUB_AS_WAIT_RESP}: Received Event VLR_AUTH_E_MS_AUTH_RESP
DVLR SUBSCR(IMSI:901700000004620) AUTH on GERAN received SRES/RES: 2d8b2c3e (4 bytes)
DVLR SUBSCR(IMSI:901700000004620) AUTH established GSM security context
DVLR VLR_Authenticate(LU:901700000004620){VLR_SUB_AS_WAIT_RESP}: Authentication terminating with result PASSED
DVLR VLR_Authenticate(LU:901700000004620){VLR_SUB_AS_WAIT_RESP}: state_chg to VLR_SUB_AS_AUTHENTICATED
DVLR VLR_Authenticate(LU:901700000004620){VLR_SUB_AS_AUTHENTICATED}: Terminating (cause = OSMO_FSM_TERM_REGULAR)
DVLR VLR_Authenticate(LU:901700000004620){VLR_SUB_AS_AUTHENTICATED}: Removing from parent vlr_lu_fsm(LU:901700000004620)
DVLR VLR_Authenticate(LU:901700000004620){VLR_SUB_AS_AUTHENTICATED}: Freeing instance
DVLR VLR_Authenticate(LU:901700000004620){VLR_SUB_AS_AUTHENTICATED}: Deallocated
DVLR vlr_lu_fsm(LU:901700000004620){VLR_ULA_S_WAIT_AUTH}: Received Event VLR_ULA_E_AUTH_RES
DVLR vlr_lu_fsm(LU:901700000004620){VLR_ULA_S_WAIT_AUTH}: vlr_loc_upd_post_auth()
DVLR vlr_lu_fsm(LU:901700000004620){VLR_ULA_S_WAIT_AUTH}: Set Ciphering Mode
DMM IMSI:901700000004620: to determine whether A5/3 is supported, first ask for a Classmark Update to obtain Classmark 2
BSC <--BSSAP-BSS-MANAGEMENT-- MSC: CLASSMARK REQ [L3]> 00 01 58
DMM Subscr_Conn(LU:901700000004620){SUBSCR_CONN_S_AUTH_CIPH}: state_chg to SUBSCR_CONN_S_WAIT_CLASSMARK_UPDATE
DVLR vlr_lu_fsm(LU:901700000004620){VLR_ULA_S_WAIT_AUTH}: state_chg to VLR_ULA_S_WAIT_CIPH
DREF IMSI:901700000004620: MSC conn use - dtap == 0 (0x0: )
DMM Subscr_Conn(LU:901700000004620){SUBSCR_CONN_S_WAIT_CLASSMARK_UPDATE}: Received Event SUBSCR_CONN_E_UNUSED
DMM Subscr_Conn(LU:901700000004620){SUBSCR_CONN_S_WAIT_CLASSMARK_UPDATE}: Awaiting results for Auth+Ciph, overruling event SUBSCR_CONN_E_UNUSED
lu_result_sent == 0
- BSC sends back a BSSMAP Classmark Update, that triggers the Ciphering Mode Command in A5/3
DMSC Looking for A subscriber: conn_id 0
DMM Subscr_Conn(LU:901700000004620){SUBSCR_CONN_S_WAIT_CLASSMARK_UPDATE}: Received Event SUBSCR_CONN_E_CLASSMARK_UPDATE
DMM Subscr_Conn(LU:901700000004620){SUBSCR_CONN_S_WAIT_CLASSMARK_UPDATE}: state_chg to SUBSCR_CONN_S_AUTH_CIPH
DMM -> CIPHER MODE COMMAND IMSI:901700000004620
- sending Ciphering Mode Command for IMSI:901700000004620: include_imeisv=0
- ...perm algo: A5/3
- ...key: 61855fb81fc2a800
lu_result_sent == 0
- MS sends Ciphering Mode Complete, VLR accepts and sends GSUP LU Req to HLR
MSC <--RAN_GERAN_A-- MS: GSM48_MT_RR_CIPH_M_COMPL
DRR IMSI:901700000004620: CIPHERING MODE COMPLETE
DVLR vlr_lu_fsm(LU:901700000004620){VLR_ULA_S_WAIT_CIPH}: Received Event VLR_ULA_E_CIPH_RES
DVLR vlr_lu_fsm(LU:901700000004620){VLR_ULA_S_WAIT_CIPH}: vlr_loc_upd_post_ciph()
DVLR vlr_lu_fsm(LU:901700000004620){VLR_ULA_S_WAIT_CIPH}: vlr_loc_upd_node_4()
DVLR vlr_lu_fsm(LU:901700000004620){VLR_ULA_S_WAIT_CIPH}: state_chg to VLR_ULA_S_WAIT_HLR_UPD
DVLR upd_hlr_vlr_fsm(LU:901700000004620){UPD_HLR_VLR_S_INIT}: Allocated
DVLR upd_hlr_vlr_fsm(LU:901700000004620){UPD_HLR_VLR_S_INIT}: is child of vlr_lu_fsm(LU:901700000004620)
DVLR upd_hlr_vlr_fsm(LU:901700000004620){UPD_HLR_VLR_S_INIT}: Received Event UPD_HLR_VLR_E_START
DVLR GSUP tx: 04010809710000004026f0
GSUP --> HLR: OSMO_GSUP_MSGT_UPDATE_LOCATION_REQUEST: 04010809710000004026f0
DVLR upd_hlr_vlr_fsm(LU:901700000004620){UPD_HLR_VLR_S_INIT}: state_chg to UPD_HLR_VLR_S_WAIT_FOR_DATA
lu_result_sent == 0
- HLR sends _INSERT_DATA_REQUEST, VLR responds with _INSERT_DATA_RESULT
<-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: 10010809710000004026f00804032443f2
DVLR GSUP rx 17: 10010809710000004026f00804032443f2
DREF VLR subscr IMSI:901700000004620 usage increases to: 2
DVLR IMSI:901700000004620 has MSISDN:42342
DVLR SUBSCR(MSISDN:42342) VLR: update for IMSI=901700000004620 (MSISDN=42342, used=2)
DVLR GSUP tx: 12010809710000004026f0
GSUP --> HLR: OSMO_GSUP_MSGT_INSERT_DATA_RESULT: 12010809710000004026f0
DREF VLR subscr MSISDN:42342 usage decreases to: 1
<-- GSUP rx OSMO_GSUP_MSGT_INSERT_DATA_REQUEST: vlr_gsupc_read_cb() returns 0
lu_result_sent == 0
- HLR also sends GSUP _UPDATE_LOCATION_RESULT
<-- GSUP rx OSMO_GSUP_MSGT_UPDATE_LOCATION_RESULT: 06010809710000004026f0
DVLR GSUP rx 11: 06010809710000004026f0
DREF VLR subscr MSISDN:42342 usage increases to: 2
DVLR vlr_lu_fsm(LU:901700000004620){VLR_ULA_S_WAIT_HLR_UPD}: Received Event VLR_ULA_E_HLR_LU_RES
DVLR upd_hlr_vlr_fsm(LU:901700000004620){UPD_HLR_VLR_S_WAIT_FOR_DATA}: Received Event UPD_HLR_VLR_E_UPD_LOC_ACK
DVLR upd_hlr_vlr_fsm(LU:901700000004620){UPD_HLR_VLR_S_WAIT_FOR_DATA}: state_chg to UPD_HLR_VLR_S_DONE
DVLR upd_hlr_vlr_fsm(LU:901700000004620){UPD_HLR_VLR_S_DONE}: Terminating (cause = OSMO_FSM_TERM_REGULAR)
DVLR upd_hlr_vlr_fsm(LU:901700000004620){UPD_HLR_VLR_S_DONE}: Removing from parent vlr_lu_fsm(LU:901700000004620)
DVLR upd_hlr_vlr_fsm(LU:901700000004620){UPD_HLR_VLR_S_DONE}: Freeing instance
DVLR upd_hlr_vlr_fsm(LU:901700000004620){UPD_HLR_VLR_S_DONE}: Deallocated
DVLR vlr_lu_fsm(LU:901700000004620){VLR_ULA_S_WAIT_HLR_UPD}: Received Event VLR_ULA_E_UPD_HLR_COMPL
DVLR vlr_lu_fsm(LU:901700000004620){VLR_ULA_S_WAIT_HLR_UPD}: state_chg to VLR_ULA_S_WAIT_LU_COMPL
DVLR lu_compl_vlr_fsm(LU:901700000004620){LU_COMPL_VLR_S_INIT}: Allocated
DVLR lu_compl_vlr_fsm(LU:901700000004620){LU_COMPL_VLR_S_INIT}: is child of vlr_lu_fsm(LU:901700000004620)
DVLR lu_compl_vlr_fsm(LU:901700000004620){LU_COMPL_VLR_S_INIT}: Received Event LU_COMPL_VLR_E_START
DVLR lu_compl_vlr_fsm(LU:901700000004620){LU_COMPL_VLR_S_INIT}: state_chg to LU_COMPL_VLR_S_WAIT_SUB_PRES
DVLR sub_pres_vlr_fsm(LU:901700000004620){SUB_PRES_VLR_S_INIT}: Allocated
DVLR sub_pres_vlr_fsm(LU:901700000004620){SUB_PRES_VLR_S_INIT}: is child of lu_compl_vlr_fsm(LU:901700000004620)
DVLR sub_pres_vlr_fsm(LU:901700000004620){SUB_PRES_VLR_S_INIT}: Received Event SUB_PRES_VLR_E_START
DVLR sub_pres_vlr_fsm(LU:901700000004620){SUB_PRES_VLR_S_INIT}: state_chg to SUB_PRES_VLR_S_DONE
DVLR sub_pres_vlr_fsm(LU:901700000004620){SUB_PRES_VLR_S_DONE}: Terminating (cause = OSMO_FSM_TERM_REGULAR)
DVLR sub_pres_vlr_fsm(LU:901700000004620){SUB_PRES_VLR_S_DONE}: Removing from parent lu_compl_vlr_fsm(LU:901700000004620)
DVLR sub_pres_vlr_fsm(LU:901700000004620){SUB_PRES_VLR_S_DONE}: Freeing instance
DVLR sub_pres_vlr_fsm(LU:901700000004620){SUB_PRES_VLR_S_DONE}: Deallocated
DVLR lu_compl_vlr_fsm(LU:901700000004620){LU_COMPL_VLR_S_WAIT_SUB_PRES}: Received Event LU_COMPL_VLR_E_SUB_PRES_COMPL
- sending LU Accept for MSISDN:42342
DREF VLR subscr MSISDN:42342 usage increases to: 3
DVLR lu_compl_vlr_fsm(LU:901700000004620){LU_COMPL_VLR_S_WAIT_SUB_PRES}: state_chg to LU_COMPL_VLR_S_DONE
DVLR vlr_lu_fsm(LU:901700000004620){VLR_ULA_S_WAIT_LU_COMPL}: Received Event VLR_ULA_E_LU_COMPL_SUCCESS
DVLR lu_compl_vlr_fsm(LU:901700000004620){LU_COMPL_VLR_S_DONE}: Terminating (cause = OSMO_FSM_TERM_PARENT)
DVLR lu_compl_vlr_fsm(LU:901700000004620){LU_COMPL_VLR_S_DONE}: Removing from parent vlr_lu_fsm(LU:901700000004620)
DVLR lu_compl_vlr_fsm(LU:901700000004620){LU_COMPL_VLR_S_DONE}: Freeing instance
DVLR lu_compl_vlr_fsm(LU:901700000004620){LU_COMPL_VLR_S_DONE}: Deallocated
DVLR vlr_lu_fsm(LU:901700000004620){VLR_ULA_S_WAIT_LU_COMPL}: state_chg to VLR_ULA_S_DONE
DMM Subscr_Conn(LU:901700000004620){SUBSCR_CONN_S_AUTH_CIPH}: Received Event SUBSCR_CONN_E_ACCEPTED
DMM Subscr_Conn(LU:901700000004620){SUBSCR_CONN_S_AUTH_CIPH}: state_chg to SUBSCR_CONN_S_ACCEPTED
DMM Subscr_Conn(LU:901700000004620){SUBSCR_CONN_S_ACCEPTED}: Received Event SUBSCR_CONN_E_UNUSED
DMM Subscr_Conn(LU:901700000004620){SUBSCR_CONN_S_ACCEPTED}: state_chg to SUBSCR_CONN_S_RELEASING
DREF MSISDN:42342: MSC conn use + release == 1 (0x100: release)
DREF VLR subscr MSISDN:42342 usage increases to: 4
DREF VLR subscr MSISDN:42342 usage decreases to: 3
- BSSAP Clear --RAN_GERAN_A--> MS
DREF VLR subscr MSISDN:42342 usage decreases to: 2
<-- GSUP rx OSMO_GSUP_MSGT_UPDATE_LOCATION_RESULT: vlr_gsupc_read_cb() returns 0
bssap_clear_sent == 1
- LU was successful, and the conn has already been closed
lu_result_sent == 1
- BSS sends BSSMAP Clear Complete
DREF MSISDN:42342: MSC conn use - release == 0 (0x0: )
DMM Subscr_Conn(LU:901700000004620){SUBSCR_CONN_S_RELEASING}: Received Event SUBSCR_CONN_E_UNUSED
DMM Subscr_Conn(LU:901700000004620){SUBSCR_CONN_S_RELEASING}: state_chg to SUBSCR_CONN_S_RELEASED
DMM Subscr_Conn(LU:901700000004620){SUBSCR_CONN_S_RELEASED}: Terminating (cause = OSMO_FSM_TERM_REGULAR)
DVLR vlr_lu_fsm(LU:901700000004620){VLR_ULA_S_DONE}: Terminating (cause = OSMO_FSM_TERM_PARENT)
DVLR vlr_lu_fsm(LU:901700000004620){VLR_ULA_S_DONE}: Removing from parent Subscr_Conn(LU:901700000004620)
DVLR vlr_lu_fsm(LU:901700000004620){VLR_ULA_S_DONE}: fsm_lu_cleanup called with cause OSMO_FSM_TERM_PARENT
DVLR vlr_lu_fsm(LU:901700000004620){VLR_ULA_S_DONE}: Freeing instance
DVLR vlr_lu_fsm(LU:901700000004620){VLR_ULA_S_DONE}: Deallocated
DRLL MSISDN:42342: Freeing subscriber connection
DREF VLR subscr MSISDN:42342 usage decreases to: 1
DMM Subscr_Conn(LU:901700000004620){SUBSCR_CONN_S_RELEASED}: Freeing instance
DMM Subscr_Conn(LU:901700000004620){SUBSCR_CONN_S_RELEASED}: Deallocated
llist_count(&net->subscr_conns) == 0
---
- after a while, a new conn sends a CM Service Request. VLR responds with Auth Req, 2nd auth vector
MSC <--RAN_GERAN_A-- MS: GSM48_MT_MM_CM_SERV_REQ
new conn
DMM Subscr_Conn{SUBSCR_CONN_S_NEW}: Allocated
DREF unknown: MSC conn use + compl_l3 == 1 (0x1: compl_l3)
DRLL Dispatching 04.08 message GSM48_MT_MM_CM_SERV_REQ (0x5:0x24)
DMM <- CM SERVICE REQUEST serv_type=0x08 MI(IMSI)=901700000004620
DMM Subscr_Conn(CM_SERVICE_REQ:901700000004620){SUBSCR_CONN_S_NEW}: Updated ID
DVLR Process_Access_Request_VLR(CM_SERVICE_REQ:901700000004620){PR_ARQ_S_INIT}: Allocated
DVLR Process_Access_Request_VLR(CM_SERVICE_REQ:901700000004620){PR_ARQ_S_INIT}: is child of Subscr_Conn(CM_SERVICE_REQ:901700000004620)
DVLR Process_Access_Request_VLR(CM_SERVICE_REQ:901700000004620){PR_ARQ_S_INIT}: rev=GSM net=GERAN Auth+Ciph
DVLR Process_Access_Request_VLR(CM_SERVICE_REQ:901700000004620){PR_ARQ_S_INIT}: Received Event PR_ARQ_E_START
DREF VLR subscr MSISDN:42342 usage increases to: 2
DREF VLR subscr MSISDN:42342 usage increases to: 3
DVLR Process_Access_Request_VLR(CM_SERVICE_REQ:901700000004620){PR_ARQ_S_INIT}: proc_arq_vlr_fn_post_imsi()
DVLR Process_Access_Request_VLR(CM_SERVICE_REQ:901700000004620){PR_ARQ_S_INIT}: state_chg to PR_ARQ_S_WAIT_AUTH
DVLR VLR_Authenticate(CM_SERVICE_REQ:901700000004620){VLR_SUB_AS_NEEDS_AUTH}: Allocated
DVLR VLR_Authenticate(CM_SERVICE_REQ:901700000004620){VLR_SUB_AS_NEEDS_AUTH}: is child of Process_Access_Request_VLR(CM_SERVICE_REQ:901700000004620)
DVLR VLR_Authenticate(CM_SERVICE_REQ:901700000004620){VLR_SUB_AS_NEEDS_AUTH}: Received Event VLR_AUTH_E_START
DVLR VLR_Authenticate(CM_SERVICE_REQ:901700000004620){VLR_SUB_AS_NEEDS_AUTH}: state_chg to VLR_SUB_AS_WAIT_RESP
DVLR VLR_Authenticate(CM_SERVICE_REQ:901700000004620){VLR_SUB_AS_WAIT_RESP}: got auth tuple: use_count=1 key_seq=1 -- will use GSM AKA (is_r99=no, at->vec.auth_types=0x1)
- sending GSM Auth Request for MSISDN:42342: tuple use_count=1 key_seq=1 auth_types=0x1 and...
- ...rand=12aca96fb4ffdea5c985cbafa9b6e18b
- ...expecting sres=20bde240
DREF VLR subscr MSISDN:42342 usage decreases to: 2
DMM Subscr_Conn(CM_SERVICE_REQ:901700000004620){SUBSCR_CONN_S_NEW}: Received Event SUBSCR_CONN_E_COMPLETE_LAYER_3
DMM Subscr_Conn(CM_SERVICE_REQ:901700000004620){SUBSCR_CONN_S_NEW}: state_chg to SUBSCR_CONN_S_AUTH_CIPH
DREF MSISDN:42342: MSC conn use - compl_l3 == 0 (0x0: )
DMM Subscr_Conn(CM_SERVICE_REQ:901700000004620){SUBSCR_CONN_S_AUTH_CIPH}: Received Event SUBSCR_CONN_E_UNUSED
DMM Subscr_Conn(CM_SERVICE_REQ:901700000004620){SUBSCR_CONN_S_AUTH_CIPH}: Awaiting results for Auth+Ciph, overruling event SUBSCR_CONN_E_UNUSED
auth_request_sent == 1
cm_service_result_sent == 0
- needs auth, not yet accepted
msc_subscr_conn_is_accepted() == false
requests shall be thwarted
DRLL Dispatching 04.08 message GSM48_MT_CC_SETUP (0x3:0x5)
DRLL subscr MSISDN:42342: Message not permitted for initial conn: GSM48_MT_CC_SETUP
DRLL Dispatching 04.08 message unknown 0x33 (0x5:0x33)
DRLL subscr MSISDN:42342: Message not permitted for initial conn: unknown 0x33
DRLL Dispatching 04.08 message GSM48_MT_RR_SYSINFO_1 (0x6:0x19)
DRLL subscr MSISDN:42342: Message not permitted for initial conn: GSM48_MT_RR_SYSINFO_1
DRLL Dispatching 04.08 message SMS:0x01 (0x9:0x1)
DRLL subscr MSISDN:42342: Message not permitted for initial conn: SMS:0x01
- MS sends Authen Response, VLR accepts and requests Ciphering. We already know Classmark 3, so no need to request Classmark Update.
MSC <--RAN_GERAN_A-- MS: GSM48_MT_MM_AUTH_RESP
DREF MSISDN:42342: MSC conn use + dtap == 1 (0x2: dtap)
DRLL Dispatching 04.08 message GSM48_MT_MM_AUTH_RESP (0x5:0x14)
DMM MSISDN:42342: MM GSM AUTHENTICATION RESPONSE (sres = 20bde240)
DVLR VLR_Authenticate(CM_SERVICE_REQ:901700000004620){VLR_SUB_AS_WAIT_RESP}: Received Event VLR_AUTH_E_MS_AUTH_RESP
DVLR SUBSCR(MSISDN:42342) AUTH on GERAN received SRES/RES: 20bde240 (4 bytes)
DVLR SUBSCR(MSISDN:42342) AUTH established GSM security context
DVLR VLR_Authenticate(CM_SERVICE_REQ:901700000004620){VLR_SUB_AS_WAIT_RESP}: Authentication terminating with result PASSED
DVLR VLR_Authenticate(CM_SERVICE_REQ:901700000004620){VLR_SUB_AS_WAIT_RESP}: state_chg to VLR_SUB_AS_AUTHENTICATED
DVLR VLR_Authenticate(CM_SERVICE_REQ:901700000004620){VLR_SUB_AS_AUTHENTICATED}: Terminating (cause = OSMO_FSM_TERM_REGULAR)
DVLR VLR_Authenticate(CM_SERVICE_REQ:901700000004620){VLR_SUB_AS_AUTHENTICATED}: Removing from parent Process_Access_Request_VLR(CM_SERVICE_REQ:901700000004620)
DVLR VLR_Authenticate(CM_SERVICE_REQ:901700000004620){VLR_SUB_AS_AUTHENTICATED}: Freeing instance
DVLR VLR_Authenticate(CM_SERVICE_REQ:901700000004620){VLR_SUB_AS_AUTHENTICATED}: Deallocated
DVLR Process_Access_Request_VLR(CM_SERVICE_REQ:901700000004620){PR_ARQ_S_WAIT_AUTH}: Received Event PR_ARQ_E_AUTH_RES
DVLR Process_Access_Request_VLR(CM_SERVICE_REQ:901700000004620){PR_ARQ_S_WAIT_AUTH}: _proc_arq_vlr_node2()
DVLR Process_Access_Request_VLR(CM_SERVICE_REQ:901700000004620){PR_ARQ_S_WAIT_AUTH}: Set Ciphering Mode
DMM -> CIPHER MODE COMMAND MSISDN:42342
- sending Ciphering Mode Command for MSISDN:42342: include_imeisv=0
- ...perm algo: A5/3
- ...key: 07fa7502e07e1c00
DVLR Process_Access_Request_VLR(CM_SERVICE_REQ:901700000004620){PR_ARQ_S_WAIT_AUTH}: state_chg to PR_ARQ_S_WAIT_CIPH
DREF MSISDN:42342: MSC conn use - dtap == 0 (0x0: )
DMM Subscr_Conn(CM_SERVICE_REQ:901700000004620){SUBSCR_CONN_S_AUTH_CIPH}: Received Event SUBSCR_CONN_E_UNUSED
DMM Subscr_Conn(CM_SERVICE_REQ:901700000004620){SUBSCR_CONN_S_AUTH_CIPH}: Awaiting results for Auth+Ciph, overruling event SUBSCR_CONN_E_UNUSED
cm_service_result_sent == 0
cipher_mode_cmd_sent == 1
- needs ciph, not yet accepted
msc_subscr_conn_is_accepted() == false
requests shall be thwarted
DRLL Dispatching 04.08 message GSM48_MT_CC_SETUP (0x3:0x5)
DRLL subscr MSISDN:42342: Message not permitted for initial conn: GSM48_MT_CC_SETUP
DRLL Dispatching 04.08 message unknown 0x33 (0x5:0x33)
DRLL subscr MSISDN:42342: Message not permitted for initial conn: unknown 0x33
DRLL Dispatching 04.08 message GSM48_MT_RR_SYSINFO_1 (0x6:0x19)
DRLL subscr MSISDN:42342: Message not permitted for initial conn: GSM48_MT_RR_SYSINFO_1
DRLL Dispatching 04.08 message SMS:0x01 (0x9:0x1)
DRLL subscr MSISDN:42342: Message not permitted for initial conn: SMS:0x01
- MS sends Ciphering Mode Complete, VLR accepts; above Ciphering is an implicit CM Service Accept
MSC <--RAN_GERAN_A-- MS: GSM48_MT_RR_CIPH_M_COMPL
DRR MSISDN:42342: CIPHERING MODE COMPLETE
DVLR Process_Access_Request_VLR(CM_SERVICE_REQ:901700000004620){PR_ARQ_S_WAIT_CIPH}: Received Event PR_ARQ_E_CIPH_RES
DVLR Process_Access_Request_VLR(CM_SERVICE_REQ:901700000004620){PR_ARQ_S_WAIT_CIPH}: _proc_arq_vlr_node2_post_ciph()
DVLR Process_Access_Request_VLR(CM_SERVICE_REQ:901700000004620){PR_ARQ_S_WAIT_CIPH}: _proc_arq_vlr_node2_post_vlr()
DVLR Process_Access_Request_VLR(CM_SERVICE_REQ:901700000004620){PR_ARQ_S_WAIT_CIPH}: _proc_arq_vlr_post_pres()
DVLR Process_Access_Request_VLR(CM_SERVICE_REQ:901700000004620){PR_ARQ_S_WAIT_CIPH}: _proc_arq_vlr_post_trace()
DVLR Process_Access_Request_VLR(CM_SERVICE_REQ:901700000004620){PR_ARQ_S_WAIT_CIPH}: _proc_arq_vlr_post_imei()
DVLR Process_Access_Request_VLR(CM_SERVICE_REQ:901700000004620){PR_ARQ_S_WAIT_CIPH}: proc_arq_fsm_done(PASSED)
DVLR Process_Access_Request_VLR(CM_SERVICE_REQ:901700000004620){PR_ARQ_S_WAIT_CIPH}: state_chg to PR_ARQ_S_DONE
DVLR Process_Access_Request_VLR(CM_SERVICE_REQ:901700000004620){PR_ARQ_S_DONE}: Process Access Request result: PASSED
DMM Subscr_Conn(CM_SERVICE_REQ:901700000004620){SUBSCR_CONN_S_AUTH_CIPH}: Received Event SUBSCR_CONN_E_ACCEPTED
DREF MSISDN:42342: MSC conn use + cm_service == 1 (0x8: cm_service)
DMM Subscr_Conn(CM_SERVICE_REQ:901700000004620){SUBSCR_CONN_S_AUTH_CIPH}: state_chg to SUBSCR_CONN_S_ACCEPTED
DMM Subscr_Conn(CM_SERVICE_REQ:901700000004620){SUBSCR_CONN_S_ACCEPTED}: subscr_conn_fsm_has_active_transactions: still awaiting first request after a CM Service Request
cm_service_result_sent == 0
- Concluding CM Service Request
DREF MSISDN:42342: MSC conn use - cm_service == 0 (0x0: )
DMM Subscr_Conn(CM_SERVICE_REQ:901700000004620){SUBSCR_CONN_S_ACCEPTED}: Received Event SUBSCR_CONN_E_UNUSED
DMM Subscr_Conn(CM_SERVICE_REQ:901700000004620){SUBSCR_CONN_S_ACCEPTED}: state_chg to SUBSCR_CONN_S_RELEASING
DREF MSISDN:42342: MSC conn use + release == 1 (0x100: release)
DREF VLR subscr MSISDN:42342 usage increases to: 3
DREF VLR subscr MSISDN:42342 usage decreases to: 2
- BSSAP Clear --RAN_GERAN_A--> MS
bssap_clear_sent == 1
- all requests serviced, conn has been released
- BSS sends BSSMAP Clear Complete
DREF MSISDN:42342: MSC conn use - release == 0 (0x0: )
DMM Subscr_Conn(CM_SERVICE_REQ:901700000004620){SUBSCR_CONN_S_RELEASING}: Received Event SUBSCR_CONN_E_UNUSED
DMM Subscr_Conn(CM_SERVICE_REQ:901700000004620){SUBSCR_CONN_S_RELEASING}: state_chg to SUBSCR_CONN_S_RELEASED
DMM Subscr_Conn(CM_SERVICE_REQ:901700000004620){SUBSCR_CONN_S_RELEASED}: Terminating (cause = OSMO_FSM_TERM_REGULAR)
DVLR Process_Access_Request_VLR(CM_SERVICE_REQ:901700000004620){PR_ARQ_S_DONE}: Terminating (cause = OSMO_FSM_TERM_PARENT)
DVLR Process_Access_Request_VLR(CM_SERVICE_REQ:901700000004620){PR_ARQ_S_DONE}: Removing from parent Subscr_Conn(CM_SERVICE_REQ:901700000004620)
DVLR Process_Access_Request_VLR(CM_SERVICE_REQ:901700000004620){PR_ARQ_S_DONE}: Freeing instance
DVLR Process_Access_Request_VLR(CM_SERVICE_REQ:901700000004620){PR_ARQ_S_DONE}: Deallocated
DRLL MSISDN:42342: Freeing subscriber connection
DREF VLR subscr MSISDN:42342 usage decreases to: 1
DMM Subscr_Conn(CM_SERVICE_REQ:901700000004620){SUBSCR_CONN_S_RELEASED}: Freeing instance
DMM Subscr_Conn(CM_SERVICE_REQ:901700000004620){SUBSCR_CONN_S_RELEASED}: Deallocated
llist_count(&net->subscr_conns) == 0
---
- an SMS is sent, MS is paged
DREF VLR subscr MSISDN:42342 usage increases to: 2
llist_count(&vsub->cs.requests) == 0
DREF VLR subscr MSISDN:42342 usage increases to: 3
DMM Subscriber MSISDN:42342 not paged yet, start paging.
RAN_GERAN_A sends out paging request to IMSI 901700000004620, TMSI 0xffffffff, LAC 23
strcmp(paging_expecting_imsi, imsi) == 0
DREF VLR subscr MSISDN:42342 usage increases to: 4
llist_count(&vsub->cs.requests) == 1
DREF VLR subscr MSISDN:42342 usage decreases to: 3
paging_sent == 1
paging_stopped == 0
- the subscriber and its pending request should remain
DREF VLR subscr MSISDN:42342 usage increases to: 4
llist_count(&vsub->cs.requests) == 1
DREF VLR subscr MSISDN:42342 usage decreases to: 3
- MS replies with Paging Response, and VLR sends Auth Request with third key
MSC <--RAN_GERAN_A-- MS: GSM48_MT_RR_PAG_RESP
new conn
DMM Subscr_Conn{SUBSCR_CONN_S_NEW}: Allocated
DREF unknown: MSC conn use + compl_l3 == 1 (0x1: compl_l3)
DRLL Dispatching 04.08 message GSM48_MT_RR_PAG_RESP (0x6:0x27)
DRR PAGING RESPONSE: MI(IMSI)=901700000004620
DMM Subscr_Conn(PAGING_RESP:901700000004620){SUBSCR_CONN_S_NEW}: Updated ID
DVLR Process_Access_Request_VLR(PAGING_RESP:901700000004620){PR_ARQ_S_INIT}: Allocated
DVLR Process_Access_Request_VLR(PAGING_RESP:901700000004620){PR_ARQ_S_INIT}: is child of Subscr_Conn(PAGING_RESP:901700000004620)
DVLR Process_Access_Request_VLR(PAGING_RESP:901700000004620){PR_ARQ_S_INIT}: rev=GSM net=GERAN Auth+Ciph
DVLR Process_Access_Request_VLR(PAGING_RESP:901700000004620){PR_ARQ_S_INIT}: Received Event PR_ARQ_E_START
DREF VLR subscr MSISDN:42342 usage increases to: 4
DREF VLR subscr MSISDN:42342 usage increases to: 5
DVLR Process_Access_Request_VLR(PAGING_RESP:901700000004620){PR_ARQ_S_INIT}: proc_arq_vlr_fn_post_imsi()
DVLR Process_Access_Request_VLR(PAGING_RESP:901700000004620){PR_ARQ_S_INIT}: state_chg to PR_ARQ_S_WAIT_AUTH
DVLR VLR_Authenticate(PAGING_RESP:901700000004620){VLR_SUB_AS_NEEDS_AUTH}: Allocated
DVLR VLR_Authenticate(PAGING_RESP:901700000004620){VLR_SUB_AS_NEEDS_AUTH}: is child of Process_Access_Request_VLR(PAGING_RESP:901700000004620)
DVLR VLR_Authenticate(PAGING_RESP:901700000004620){VLR_SUB_AS_NEEDS_AUTH}: Received Event VLR_AUTH_E_START
DVLR VLR_Authenticate(PAGING_RESP:901700000004620){VLR_SUB_AS_NEEDS_AUTH}: state_chg to VLR_SUB_AS_WAIT_RESP
DVLR VLR_Authenticate(PAGING_RESP:901700000004620){VLR_SUB_AS_WAIT_RESP}: got auth tuple: use_count=1 key_seq=2 -- will use GSM AKA (is_r99=no, at->vec.auth_types=0x1)
- sending GSM Auth Request for MSISDN:42342: tuple use_count=1 key_seq=2 auth_types=0x1 and...
- ...rand=e7c03ba7cf0e2fde82b2dc4d63077d42
- ...expecting sres=a29514ae
DREF VLR subscr MSISDN:42342 usage decreases to: 4
DMM Subscr_Conn(PAGING_RESP:901700000004620){SUBSCR_CONN_S_NEW}: Received Event SUBSCR_CONN_E_COMPLETE_LAYER_3
DMM Subscr_Conn(PAGING_RESP:901700000004620){SUBSCR_CONN_S_NEW}: state_chg to SUBSCR_CONN_S_AUTH_CIPH
DREF MSISDN:42342: MSC conn use - compl_l3 == 0 (0x0: )
DMM Subscr_Conn(PAGING_RESP:901700000004620){SUBSCR_CONN_S_AUTH_CIPH}: Received Event SUBSCR_CONN_E_UNUSED
DMM Subscr_Conn(PAGING_RESP:901700000004620){SUBSCR_CONN_S_AUTH_CIPH}: Awaiting results for Auth+Ciph, overruling event SUBSCR_CONN_E_UNUSED
auth_request_sent == 1
---
- Fake a situation where Classmark 2 is unknown during proc_arq_fsm
DREF VLR subscr MSISDN:42342 usage increases to: 5
DREF VLR subscr MSISDN:42342 usage decreases to: 4
- MS sends Authen Response, VLR accepts and requests Ciphering
- MS sends Authen Response, VLR accepts and requests Ciphering. Normally, we'd know Classmark 3, but this test removed it. Hence a Classmark Request is generated.
MSC <--RAN_GERAN_A-- MS: GSM48_MT_MM_AUTH_RESP
DREF MSISDN:42342: MSC conn use + dtap == 1 (0x2: dtap)
DRLL Dispatching 04.08 message GSM48_MT_MM_AUTH_RESP (0x5:0x14)
DMM MSISDN:42342: MM GSM AUTHENTICATION RESPONSE (sres = a29514ae)
DVLR VLR_Authenticate(PAGING_RESP:901700000004620){VLR_SUB_AS_WAIT_RESP}: Received Event VLR_AUTH_E_MS_AUTH_RESP
DVLR SUBSCR(MSISDN:42342) AUTH on GERAN received SRES/RES: a29514ae (4 bytes)
DVLR SUBSCR(MSISDN:42342) AUTH established GSM security context
DVLR VLR_Authenticate(PAGING_RESP:901700000004620){VLR_SUB_AS_WAIT_RESP}: Authentication terminating with result PASSED
DVLR VLR_Authenticate(PAGING_RESP:901700000004620){VLR_SUB_AS_WAIT_RESP}: state_chg to VLR_SUB_AS_AUTHENTICATED
DVLR VLR_Authenticate(PAGING_RESP:901700000004620){VLR_SUB_AS_AUTHENTICATED}: Terminating (cause = OSMO_FSM_TERM_REGULAR)
DVLR VLR_Authenticate(PAGING_RESP:901700000004620){VLR_SUB_AS_AUTHENTICATED}: Removing from parent Process_Access_Request_VLR(PAGING_RESP:901700000004620)
DVLR VLR_Authenticate(PAGING_RESP:901700000004620){VLR_SUB_AS_AUTHENTICATED}: Freeing instance
DVLR VLR_Authenticate(PAGING_RESP:901700000004620){VLR_SUB_AS_AUTHENTICATED}: Deallocated
DVLR Process_Access_Request_VLR(PAGING_RESP:901700000004620){PR_ARQ_S_WAIT_AUTH}: Received Event PR_ARQ_E_AUTH_RES
DVLR Process_Access_Request_VLR(PAGING_RESP:901700000004620){PR_ARQ_S_WAIT_AUTH}: _proc_arq_vlr_node2()
DVLR Process_Access_Request_VLR(PAGING_RESP:901700000004620){PR_ARQ_S_WAIT_AUTH}: Set Ciphering Mode
DMM MSISDN:42342: to determine whether A5/3 is supported, first ask for a Classmark Update to obtain Classmark 2
BSC <--BSSAP-BSS-MANAGEMENT-- MSC: CLASSMARK REQ [L3]> 00 01 58
DMM Subscr_Conn(PAGING_RESP:901700000004620){SUBSCR_CONN_S_AUTH_CIPH}: state_chg to SUBSCR_CONN_S_WAIT_CLASSMARK_UPDATE
DVLR Process_Access_Request_VLR(PAGING_RESP:901700000004620){PR_ARQ_S_WAIT_AUTH}: state_chg to PR_ARQ_S_WAIT_CIPH
DREF MSISDN:42342: MSC conn use - dtap == 0 (0x0: )
DMM Subscr_Conn(PAGING_RESP:901700000004620){SUBSCR_CONN_S_WAIT_CLASSMARK_UPDATE}: Received Event SUBSCR_CONN_E_UNUSED
DMM Subscr_Conn(PAGING_RESP:901700000004620){SUBSCR_CONN_S_WAIT_CLASSMARK_UPDATE}: Awaiting results for Auth+Ciph, overruling event SUBSCR_CONN_E_UNUSED
- BSC sends back a BSSMAP Classmark Update, that triggers the Ciphering Mode Command in A5/3
DMSC Looking for A subscriber: conn_id 0
DMM Subscr_Conn(PAGING_RESP:901700000004620){SUBSCR_CONN_S_WAIT_CLASSMARK_UPDATE}: Received Event SUBSCR_CONN_E_CLASSMARK_UPDATE
DMM Subscr_Conn(PAGING_RESP:901700000004620){SUBSCR_CONN_S_WAIT_CLASSMARK_UPDATE}: state_chg to SUBSCR_CONN_S_AUTH_CIPH
DMM -> CIPHER MODE COMMAND MSISDN:42342
- sending Ciphering Mode Command for MSISDN:42342: include_imeisv=0
- ...perm algo: A5/3
- ...key: e2b234f807886400
- needs ciph, not yet accepted
msc_subscr_conn_is_accepted() == false
- MS sends Ciphering Mode Complete, VLR accepts and sends pending SMS
MSC <--RAN_GERAN_A-- MS: GSM48_MT_RR_CIPH_M_COMPL
DRR MSISDN:42342: CIPHERING MODE COMPLETE
DVLR Process_Access_Request_VLR(PAGING_RESP:901700000004620){PR_ARQ_S_WAIT_CIPH}: Received Event PR_ARQ_E_CIPH_RES
DVLR Process_Access_Request_VLR(PAGING_RESP:901700000004620){PR_ARQ_S_WAIT_CIPH}: _proc_arq_vlr_node2_post_ciph()
DVLR Process_Access_Request_VLR(PAGING_RESP:901700000004620){PR_ARQ_S_WAIT_CIPH}: _proc_arq_vlr_node2_post_vlr()
DVLR Process_Access_Request_VLR(PAGING_RESP:901700000004620){PR_ARQ_S_WAIT_CIPH}: _proc_arq_vlr_post_pres()
DVLR Process_Access_Request_VLR(PAGING_RESP:901700000004620){PR_ARQ_S_WAIT_CIPH}: _proc_arq_vlr_post_trace()
DVLR Process_Access_Request_VLR(PAGING_RESP:901700000004620){PR_ARQ_S_WAIT_CIPH}: _proc_arq_vlr_post_imei()
DVLR Process_Access_Request_VLR(PAGING_RESP:901700000004620){PR_ARQ_S_WAIT_CIPH}: proc_arq_fsm_done(PASSED)
DVLR Process_Access_Request_VLR(PAGING_RESP:901700000004620){PR_ARQ_S_WAIT_CIPH}: state_chg to PR_ARQ_S_DONE
DVLR Process_Access_Request_VLR(PAGING_RESP:901700000004620){PR_ARQ_S_DONE}: Process Access Request result: PASSED
DMM Subscr_Conn(PAGING_RESP:901700000004620){SUBSCR_CONN_S_AUTH_CIPH}: Received Event SUBSCR_CONN_E_ACCEPTED
DPAG Paging success for MSISDN:42342 (event=0)
DPAG Calling paging cbfn.
DCC (ti 00 sub MSISDN:42342 callref 40000005) New transaction
DREF VLR subscr MSISDN:42342 usage increases to: 5
DREF MSISDN:42342: MSC conn use + trans_sms == 1 (0x20: trans_sms)
DMSC msc_tx 91 bytes to MSISDN:42342 via RAN_GERAN_A
- DTAP --RAN_GERAN_A--> MS: SMS:0x01: 09015801000791447758100650004c0005802443f2000007101000000000445079da1e1ee7416937485e9ea7c965373d1d6683c270383b3d0ed3d36ff71c949e83c22072799e9687c5ec32a81d96afcbf4b4fb0c7ac3e9e9b7db05
- DTAP matches expected message
DREF VLR subscr MSISDN:42342 usage decreases to: 4
DMM Subscr_Conn(PAGING_RESP:901700000004620){SUBSCR_CONN_S_AUTH_CIPH}: state_chg to SUBSCR_CONN_S_ACCEPTED
DMM Subscr_Conn(PAGING_RESP:901700000004620){SUBSCR_CONN_S_ACCEPTED}: subscr_conn_fsm_has_active_transactions: connection still has active transaction: SMS
dtap_tx_confirmed == 1
paging_stopped == 1
- SMS was delivered, no requests pending for subscr
DREF VLR subscr MSISDN:42342 usage increases to: 5
llist_count(&vsub->cs.requests) == 0
DREF VLR subscr MSISDN:42342 usage decreases to: 4
- conn is still open to wait for SMS ack dance
llist_count(&net->subscr_conns) == 1
- MS replies with CP-ACK for received SMS
MSC <--RAN_GERAN_A-- MS: SMS:0x04
DREF MSISDN:42342: MSC conn use + dtap == 2 (0x22: dtap,trans_sms)
DRLL Dispatching 04.08 message SMS:0x04 (0x9:0x4)
DMM Subscr_Conn(PAGING_RESP:901700000004620){SUBSCR_CONN_S_ACCEPTED}: Received Event SUBSCR_CONN_E_COMMUNICATING
DMM Subscr_Conn(PAGING_RESP:901700000004620){SUBSCR_CONN_S_ACCEPTED}: state_chg to SUBSCR_CONN_S_COMMUNICATING
DREF MSISDN:42342: MSC conn use - dtap == 1 (0x20: trans_sms)
llist_count(&net->subscr_conns) == 1
- MS also sends RP-ACK, MSC in turn sends CP-ACK for that
MSC <--RAN_GERAN_A-- MS: SMS:0x01
DREF MSISDN:42342: MSC conn use + dtap == 2 (0x22: dtap,trans_sms)
DRLL Dispatching 04.08 message SMS:0x01 (0x9:0x1)
DMM Subscr_Conn(PAGING_RESP:901700000004620){SUBSCR_CONN_S_COMMUNICATING}: Received Event SUBSCR_CONN_E_COMMUNICATING
DMSC msc_tx 2 bytes to MSISDN:42342 via RAN_GERAN_A
- DTAP --RAN_GERAN_A--> MS: SMS:0x04: 0904
- DTAP matches expected message
DREF VLR subscr MSISDN:42342 usage decreases to: 3
DREF VLR subscr MSISDN:42342 usage decreases to: 2
DREF MSISDN:42342: MSC conn use - trans_sms == 1 (0x2: dtap)
DREF MSISDN:42342: MSC conn use - dtap == 0 (0x0: )
DMM Subscr_Conn(PAGING_RESP:901700000004620){SUBSCR_CONN_S_COMMUNICATING}: Received Event SUBSCR_CONN_E_UNUSED
DMM Subscr_Conn(PAGING_RESP:901700000004620){SUBSCR_CONN_S_COMMUNICATING}: state_chg to SUBSCR_CONN_S_RELEASING
DREF MSISDN:42342: MSC conn use + release == 1 (0x100: release)
DREF VLR subscr MSISDN:42342 usage increases to: 3
DREF VLR subscr MSISDN:42342 usage decreases to: 2
- BSSAP Clear --RAN_GERAN_A--> MS
dtap_tx_confirmed == 1
bssap_clear_sent == 1
- SMS is done, conn is gone
- BSS sends BSSMAP Clear Complete
DREF MSISDN:42342: MSC conn use - release == 0 (0x0: )
DMM Subscr_Conn(PAGING_RESP:901700000004620){SUBSCR_CONN_S_RELEASING}: Received Event SUBSCR_CONN_E_UNUSED
DMM Subscr_Conn(PAGING_RESP:901700000004620){SUBSCR_CONN_S_RELEASING}: state_chg to SUBSCR_CONN_S_RELEASED
DMM Subscr_Conn(PAGING_RESP:901700000004620){SUBSCR_CONN_S_RELEASED}: Terminating (cause = OSMO_FSM_TERM_REGULAR)
DVLR Process_Access_Request_VLR(PAGING_RESP:901700000004620){PR_ARQ_S_DONE}: Terminating (cause = OSMO_FSM_TERM_PARENT)
DVLR Process_Access_Request_VLR(PAGING_RESP:901700000004620){PR_ARQ_S_DONE}: Removing from parent Subscr_Conn(PAGING_RESP:901700000004620)
DVLR Process_Access_Request_VLR(PAGING_RESP:901700000004620){PR_ARQ_S_DONE}: Freeing instance
DVLR Process_Access_Request_VLR(PAGING_RESP:901700000004620){PR_ARQ_S_DONE}: Deallocated
DRLL MSISDN:42342: Freeing subscriber connection
DREF VLR subscr MSISDN:42342 usage decreases to: 1
DMM Subscr_Conn(PAGING_RESP:901700000004620){SUBSCR_CONN_S_RELEASED}: Freeing instance
DMM Subscr_Conn(PAGING_RESP:901700000004620){SUBSCR_CONN_S_RELEASED}: Deallocated
llist_count(&net->subscr_conns) == 0
---
- subscriber detaches
MSC <--RAN_GERAN_A-- MS: GSM48_MT_MM_IMSI_DETACH_IND
new conn
DMM Subscr_Conn{SUBSCR_CONN_S_NEW}: Allocated
DREF unknown: MSC conn use + compl_l3 == 1 (0x1: compl_l3)
DRLL Dispatching 04.08 message GSM48_MT_MM_IMSI_DETACH_IND (0x5:0x1)
DMM IMSI DETACH INDICATION: MI(IMSI)=901700000004620
DREF VLR subscr MSISDN:42342 usage increases to: 2
DMM IMSI DETACH for MSISDN:42342
DREF VLR subscr MSISDN:42342 usage increases to: 3
DREF VLR subscr MSISDN:42342 usage decreases to: 2
DREF VLR subscr MSISDN:42342 usage decreases to: 1
DREF VLR subscr MSISDN:42342 usage decreases to: 0
DREF freeing VLR subscr MSISDN:42342
DMM Subscr_Conn{SUBSCR_CONN_S_NEW}: Received Event SUBSCR_CONN_E_CN_CLOSE
DMM Subscr_Conn{SUBSCR_CONN_S_NEW}: state_chg to SUBSCR_CONN_S_RELEASING
DREF unknown: MSC conn use + release == 2 (0x101: compl_l3,release)
- BSSAP Clear --RAN_GERAN_A--> MS
DREF unknown: MSC conn use - compl_l3 == 1 (0x100: release)
bssap_clear_sent == 1
- BSS sends BSSMAP Clear Complete
DREF unknown: MSC conn use - release == 0 (0x0: )
DMM Subscr_Conn{SUBSCR_CONN_S_RELEASING}: Received Event SUBSCR_CONN_E_UNUSED
DMM Subscr_Conn{SUBSCR_CONN_S_RELEASING}: state_chg to SUBSCR_CONN_S_RELEASED
DMM Subscr_Conn{SUBSCR_CONN_S_RELEASED}: Terminating (cause = OSMO_FSM_TERM_REGULAR)
DRLL Freeing subscriber connection with NULL subscriber
DMM Subscr_Conn{SUBSCR_CONN_S_RELEASED}: Freeing instance
DMM Subscr_Conn{SUBSCR_CONN_S_RELEASED}: Deallocated
llist_count(&net->subscr_conns) == 0
===== test_cm_service_needs_classmark_update: SUCCESS
full talloc report on 'msgb' (total 0 bytes in 1 blocks) full talloc report on 'msgb' (total 0 bytes in 1 blocks)
talloc_total_blocks(tall_bsc_ctx) == 12 talloc_total_blocks(tall_bsc_ctx) == 12

70
tests/msc_vlr/msc_vlr_test_ms_timeout.c
View File

@ -292,9 +292,79 @@ static void test_ms_timeout_paging()
comment_end(); comment_end();
} }
static void test_classmark_update_timeout()
{
comment_start();
fake_time_start();
/* implicit: net->authentication_required = true; */
net->a5_encryption_mask = (1 << 3); /* A5/3 */
btw("Location Update request causes a GSUP Send Auth Info request to HLR");
lu_result_sent = RES_NONE;
gsup_expect_tx("08010809710000004026f0");
ms_sends_msg("050802008168000130089910070000006402");
OSMO_ASSERT(gsup_tx_confirmed);
VERBOSE_ASSERT(lu_result_sent, == RES_NONE, "%d");
btw("from HLR, rx _SEND_AUTH_INFO_RESULT; VLR sends Auth Req to MS");
/* Based on a Ki of 000102030405060708090a0b0c0d0e0f */
auth_request_sent = false;
auth_request_expect_rand = "585df1ae287f6e273dce07090d61320b";
auth_request_expect_autn = NULL;
gsup_rx("0a"
/* imsi */
"0108" "09710000004026f0"
/* TL TL rand */
"0322" "2010" "585df1ae287f6e273dce07090d61320b"
/* TL sres TL kc */
"2104" "2d8b2c3e" "2208" "61855fb81fc2a800"
,
NULL);
VERBOSE_ASSERT(lu_result_sent, == RES_NONE, "%d");
VERBOSE_ASSERT(auth_request_sent, == true, "%d");
BTW("MS sends Authen Response, VLR accepts and wants to send Ciphering Mode Command to MS"
" -- but needs Classmark 2 to determine whether A5/3 is supported");
cipher_mode_cmd_sent = false;
ms_sends_msg("05542d8b2c3e");
OSMO_ASSERT(!cipher_mode_cmd_sent);
VERBOSE_ASSERT(lu_result_sent, == RES_NONE, "%d");
BTW("But the BSSMAP Classmark Update never arrives");
btw("At first, we're still waiting");
fake_time_passes(0, 423);
EXPECT_CONN_COUNT(1);
VERBOSE_ASSERT(lu_result_sent, == RES_NONE, "%d");
fake_time_passes(1, 235);
EXPECT_CONN_COUNT(1);
VERBOSE_ASSERT(lu_result_sent, == RES_NONE, "%d");
fake_time_passes(1, 235);
EXPECT_CONN_COUNT(1);
VERBOSE_ASSERT(lu_result_sent, == RES_NONE, "%d");
fake_time_passes(1, 235);
EXPECT_CONN_COUNT(1);
VERBOSE_ASSERT(lu_result_sent, == RES_NONE, "%d");
fake_time_passes(1, 235);
EXPECT_CONN_COUNT(1);
VERBOSE_ASSERT(lu_result_sent, == RES_NONE, "%d");
expect_bssap_clear();
fake_time_passes(1, 235);
btw("SUBSCR_CONN_TIMEOUT has passed, conn is gone.");
VERBOSE_ASSERT(bssap_clear_sent, == true, "%d");
bss_sends_clear_complete();
EXPECT_CONN_COUNT(0);
VERBOSE_ASSERT(lu_result_sent, == RES_REJECT, "%d");
comment_end();
}
msc_vlr_test_func_t msc_vlr_tests[] = { msc_vlr_test_func_t msc_vlr_tests[] = {
test_ms_timeout_lu_auth_resp, test_ms_timeout_lu_auth_resp,
test_ms_timeout_cm_auth_resp, test_ms_timeout_cm_auth_resp,
test_ms_timeout_paging, test_ms_timeout_paging,
test_classmark_update_timeout,
NULL NULL
}; };

130
tests/msc_vlr/msc_vlr_test_ms_timeout.err
View File

@ -554,6 +554,136 @@ DMM Subscr_Conn{SUBSCR_CONN_S_RELEASED}: Deallocated
full talloc report on 'msgb' (total 0 bytes in 1 blocks) full talloc report on 'msgb' (total 0 bytes in 1 blocks)
talloc_total_blocks(tall_bsc_ctx) == 12 talloc_total_blocks(tall_bsc_ctx) == 12
===== test_classmark_update_timeout
- Total time passed: 0.000000 s
- Location Update request causes a GSUP Send Auth Info request to HLR
MSC <--RAN_GERAN_A-- MS: GSM48_MT_MM_LOC_UPD_REQUEST
new conn
DMM Subscr_Conn{SUBSCR_CONN_S_NEW}: Allocated
DREF unknown: MSC conn use + compl_l3 == 1 (0x1: compl_l3)
DRLL Dispatching 04.08 message GSM48_MT_MM_LOC_UPD_REQUEST (0x5:0x8)
DMM Subscr_Conn(LU:901700000004620){SUBSCR_CONN_S_NEW}: Updated ID
DMM LOCATION UPDATING REQUEST: MI(IMSI)=901700000004620 type=IMSI ATTACH
DMM LU/new-LAC: 1/23
DVLR vlr_lu_fsm(LU:901700000004620){VLR_ULA_S_IDLE}: Allocated
DVLR vlr_lu_fsm(LU:901700000004620){VLR_ULA_S_IDLE}: is child of Subscr_Conn(LU:901700000004620)
DVLR vlr_lu_fsm(LU:901700000004620){VLR_ULA_S_IDLE}: rev=GSM net=GERAN Auth+Ciph
DVLR vlr_lu_fsm(LU:901700000004620){VLR_ULA_S_IDLE}: Received Event VLR_ULA_E_UPDATE_LA
DREF VLR subscr unknown usage increases to: 1
DVLR set IMSI on subscriber; IMSI=901700000004620 id=901700000004620
DVLR New subscr, IMSI: 901700000004620
DREF VLR subscr IMSI:901700000004620 usage increases to: 2
DREF VLR subscr IMSI:901700000004620 usage decreases to: 1
DVLR vlr_lu_fsm(LU:901700000004620){VLR_ULA_S_IDLE}: vlr_loc_upd_node1()
DVLR vlr_lu_fsm(LU:901700000004620){VLR_ULA_S_IDLE}: state_chg to VLR_ULA_S_WAIT_AUTH
DVLR VLR_Authenticate(LU:901700000004620){VLR_SUB_AS_NEEDS_AUTH}: Allocated
DVLR VLR_Authenticate(LU:901700000004620){VLR_SUB_AS_NEEDS_AUTH}: is child of vlr_lu_fsm(LU:901700000004620)
DVLR VLR_Authenticate(LU:901700000004620){VLR_SUB_AS_NEEDS_AUTH}: Received Event VLR_AUTH_E_START
DVLR GSUP tx: 08010809710000004026f0
GSUP --> HLR: OSMO_GSUP_MSGT_SEND_AUTH_INFO_REQUEST: 08010809710000004026f0
DVLR VLR_Authenticate(LU:901700000004620){VLR_SUB_AS_NEEDS_AUTH}: state_chg to VLR_SUB_AS_NEEDS_AUTH_WAIT_AI
DMM Subscr_Conn(LU:901700000004620){SUBSCR_CONN_S_NEW}: Received Event SUBSCR_CONN_E_COMPLETE_LAYER_3
DMM Subscr_Conn(LU:901700000004620){SUBSCR_CONN_S_NEW}: state_chg to SUBSCR_CONN_S_AUTH_CIPH
DREF IMSI:901700000004620: MSC conn use - compl_l3 == 0 (0x0: )
DMM Subscr_Conn(LU:901700000004620){SUBSCR_CONN_S_AUTH_CIPH}: Received Event SUBSCR_CONN_E_UNUSED
DMM Subscr_Conn(LU:901700000004620){SUBSCR_CONN_S_AUTH_CIPH}: Awaiting results for Auth+Ciph, overruling event SUBSCR_CONN_E_UNUSED
lu_result_sent == 0
- from HLR, rx _SEND_AUTH_INFO_RESULT; VLR sends Auth Req to MS
<-- GSUP rx OSMO_GSUP_MSGT_SEND_AUTH_INFO_RESULT: 0a010809710000004026f003222010585df1ae287f6e273dce07090d61320b21042d8b2c3e220861855fb81fc2a800
DVLR GSUP rx 47: 0a010809710000004026f003222010585df1ae287f6e273dce07090d61320b21042d8b2c3e220861855fb81fc2a800
DREF VLR subscr IMSI:901700000004620 usage increases to: 2
DVLR VLR_Authenticate(LU:901700000004620){VLR_SUB_AS_NEEDS_AUTH_WAIT_AI}: Received Event VLR_AUTH_E_HLR_SAI_ACK
DVLR SUBSCR(IMSI:901700000004620) Received 1 auth tuples
DVLR VLR_Authenticate(LU:901700000004620){VLR_SUB_AS_NEEDS_AUTH_WAIT_AI}: state_chg to VLR_SUB_AS_WAIT_RESP
DVLR VLR_Authenticate(LU:901700000004620){VLR_SUB_AS_WAIT_RESP}: got auth tuple: use_count=1 key_seq=0 -- will use GSM AKA (is_r99=no, at->vec.auth_types=0x1)
- sending GSM Auth Request for IMSI:901700000004620: tuple use_count=1 key_seq=0 auth_types=0x1 and...
- ...rand=585df1ae287f6e273dce07090d61320b
- ...expecting sres=2d8b2c3e
DREF VLR subscr IMSI:901700000004620 usage decreases to: 1
<-- GSUP rx OSMO_GSUP_MSGT_SEND_AUTH_INFO_RESULT: vlr_gsupc_read_cb() returns 0
lu_result_sent == 0
auth_request_sent == 1
---
- MS sends Authen Response, VLR accepts and wants to send Ciphering Mode Command to MS -- but needs Classmark 2 to determine whether A5/3 is supported
MSC <--RAN_GERAN_A-- MS: GSM48_MT_MM_AUTH_RESP
DREF IMSI:901700000004620: MSC conn use + dtap == 1 (0x2: dtap)
DRLL Dispatching 04.08 message GSM48_MT_MM_AUTH_RESP (0x5:0x14)
DMM IMSI:901700000004620: MM GSM AUTHENTICATION RESPONSE (sres = 2d8b2c3e)
DVLR VLR_Authenticate(LU:901700000004620){VLR_SUB_AS_WAIT_RESP}: Received Event VLR_AUTH_E_MS_AUTH_RESP
DVLR SUBSCR(IMSI:901700000004620) AUTH on GERAN received SRES/RES: 2d8b2c3e (4 bytes)
DVLR SUBSCR(IMSI:901700000004620) AUTH established GSM security context
DVLR VLR_Authenticate(LU:901700000004620){VLR_SUB_AS_WAIT_RESP}: Authentication terminating with result PASSED
DVLR VLR_Authenticate(LU:901700000004620){VLR_SUB_AS_WAIT_RESP}: state_chg to VLR_SUB_AS_AUTHENTICATED
DVLR VLR_Authenticate(LU:901700000004620){VLR_SUB_AS_AUTHENTICATED}: Terminating (cause = OSMO_FSM_TERM_REGULAR)
DVLR VLR_Authenticate(LU:901700000004620){VLR_SUB_AS_AUTHENTICATED}: Removing from parent vlr_lu_fsm(LU:901700000004620)
DVLR VLR_Authenticate(LU:901700000004620){VLR_SUB_AS_AUTHENTICATED}: Freeing instance
DVLR VLR_Authenticate(LU:901700000004620){VLR_SUB_AS_AUTHENTICATED}: Deallocated
DVLR vlr_lu_fsm(LU:901700000004620){VLR_ULA_S_WAIT_AUTH}: Received Event VLR_ULA_E_AUTH_RES
DVLR vlr_lu_fsm(LU:901700000004620){VLR_ULA_S_WAIT_AUTH}: vlr_loc_upd_post_auth()
DVLR vlr_lu_fsm(LU:901700000004620){VLR_ULA_S_WAIT_AUTH}: Set Ciphering Mode
DMM IMSI:901700000004620: to determine whether A5/3 is supported, first ask for a Classmark Update to obtain Classmark 2
BSC <--BSSAP-BSS-MANAGEMENT-- MSC: CLASSMARK REQ [L3]> 00 01 58
DMM Subscr_Conn(LU:901700000004620){SUBSCR_CONN_S_AUTH_CIPH}: state_chg to SUBSCR_CONN_S_WAIT_CLASSMARK_UPDATE
DVLR vlr_lu_fsm(LU:901700000004620){VLR_ULA_S_WAIT_AUTH}: state_chg to VLR_ULA_S_WAIT_CIPH
DREF IMSI:901700000004620: MSC conn use - dtap == 0 (0x0: )
DMM Subscr_Conn(LU:901700000004620){SUBSCR_CONN_S_WAIT_CLASSMARK_UPDATE}: Received Event SUBSCR_CONN_E_UNUSED
DMM Subscr_Conn(LU:901700000004620){SUBSCR_CONN_S_WAIT_CLASSMARK_UPDATE}: Awaiting results for Auth+Ciph, overruling event SUBSCR_CONN_E_UNUSED
lu_result_sent == 0
---
- But the BSSMAP Classmark Update never arrives
- At first, we're still waiting
- Total time passed: 0.000423 s
llist_count(&net->subscr_conns) == 1
lu_result_sent == 0
- Total time passed: 1.000658 s
llist_count(&net->subscr_conns) == 1
lu_result_sent == 0
- Total time passed: 2.000893 s
llist_count(&net->subscr_conns) == 1
lu_result_sent == 0
- Total time passed: 3.001128 s
llist_count(&net->subscr_conns) == 1
lu_result_sent == 0
- Total time passed: 4.001363 s
llist_count(&net->subscr_conns) == 1
lu_result_sent == 0
- Total time passed: 5.001598 s
DMM Subscr_Conn(LU:901700000004620){SUBSCR_CONN_S_WAIT_CLASSMARK_UPDATE}: Timeout of T0
DMM Subscr_Conn(LU:901700000004620){SUBSCR_CONN_S_WAIT_CLASSMARK_UPDATE}: Received Event SUBSCR_CONN_E_CN_CLOSE
DMM Subscr_Conn(LU:901700000004620){SUBSCR_CONN_S_WAIT_CLASSMARK_UPDATE}: Close event, cause: CONGESTION
DMM Subscr_Conn(LU:901700000004620){SUBSCR_CONN_S_WAIT_CLASSMARK_UPDATE}: state_chg to SUBSCR_CONN_S_RELEASING
DREF IMSI:901700000004620: MSC conn use + release == 1 (0x100: release)
DREF VLR subscr IMSI:901700000004620 usage increases to: 2
- sending LU Reject for IMSI:901700000004620, cause 22
DVLR vlr_lu_fsm(LU:901700000004620){VLR_ULA_S_WAIT_CIPH}: state_chg to VLR_ULA_S_DONE
DMM Subscr_Conn(LU:901700000004620){SUBSCR_CONN_S_RELEASING}: Received Event SUBSCR_CONN_E_CN_CLOSE
DMM Subscr_Conn(LU:901700000004620){SUBSCR_CONN_S_RELEASING}: Event SUBSCR_CONN_E_CN_CLOSE not permitted
DREF VLR subscr IMSI:901700000004620 usage decreases to: 1
- BSSAP Clear --RAN_GERAN_A--> MS
- SUBSCR_CONN_TIMEOUT has passed, conn is gone.
bssap_clear_sent == 1
- BSS sends BSSMAP Clear Complete
DREF IMSI:901700000004620: MSC conn use - release == 0 (0x0: )
DMM Subscr_Conn(LU:901700000004620){SUBSCR_CONN_S_RELEASING}: Received Event SUBSCR_CONN_E_UNUSED
DMM Subscr_Conn(LU:901700000004620){SUBSCR_CONN_S_RELEASING}: state_chg to SUBSCR_CONN_S_RELEASED
DMM Subscr_Conn(LU:901700000004620){SUBSCR_CONN_S_RELEASED}: Terminating (cause = OSMO_FSM_TERM_REGULAR)
DVLR vlr_lu_fsm(LU:901700000004620){VLR_ULA_S_DONE}: Terminating (cause = OSMO_FSM_TERM_PARENT)
DVLR vlr_lu_fsm(LU:901700000004620){VLR_ULA_S_DONE}: Removing from parent Subscr_Conn(LU:901700000004620)
DVLR vlr_lu_fsm(LU:901700000004620){VLR_ULA_S_DONE}: fsm_lu_cleanup called with cause OSMO_FSM_TERM_PARENT
DVLR vlr_lu_fsm(LU:901700000004620){VLR_ULA_S_DONE}: Freeing instance
DVLR vlr_lu_fsm(LU:901700000004620){VLR_ULA_S_DONE}: Deallocated
DRLL IMSI:901700000004620: Freeing subscriber connection
DREF VLR subscr IMSI:901700000004620 usage decreases to: 0
DREF freeing VLR subscr IMSI:901700000004620
DMM Subscr_Conn(LU:901700000004620){SUBSCR_CONN_S_RELEASED}: Freeing instance
DMM Subscr_Conn(LU:901700000004620){SUBSCR_CONN_S_RELEASED}: Deallocated
llist_count(&net->subscr_conns) == 0
lu_result_sent == 2
===== test_classmark_update_timeout: SUCCESS
full talloc report on 'msgb' (total 0 bytes in 1 blocks)
talloc_total_blocks(tall_bsc_ctx) == 12
full talloc report on 'msgb' (total 0 bytes in 1 blocks) full talloc report on 'msgb' (total 0 bytes in 1 blocks)
talloc_total_blocks(tall_bsc_ctx) == 12 talloc_total_blocks(tall_bsc_ctx) == 12

61
tests/msc_vlr/msc_vlr_tests.c
View File

@ -35,6 +35,7 @@
#include <osmocom/msc/debug.h> #include <osmocom/msc/debug.h>
#include <osmocom/msc/gsm_04_08.h> #include <osmocom/msc/gsm_04_08.h>
#include <osmocom/msc/transaction.h> #include <osmocom/msc/transaction.h>
#include <osmocom/msc/a_iface_bssap.h>
#if BUILD_IU #if BUILD_IU
#include <osmocom/msc/iucs_ranap.h> #include <osmocom/msc/iucs_ranap.h>
@ -111,10 +112,10 @@ static void reset_l3_seq_nr()
struct msgb *msgb_from_hex(const char *label, uint16_t size, const char *hex) struct msgb *msgb_from_hex(const char *label, uint16_t size, const char *hex)
{ {
struct msgb *msg = msgb_alloc(size, label); struct msgb *msg = msgb_alloc_headroom(size, 4, label);
unsigned char *rc; unsigned char *rc;
msg->l2h = msg->head; msg->l2h = msg->data;
rc = msgb_put(msg, osmo_hexparse(hex, msg->head, msgb_tailroom(msg))); rc = msgb_put(msg, osmo_hexparse(hex, msg->data, msgb_tailroom(msg)));
OSMO_ASSERT(rc == msg->l2h); OSMO_ASSERT(rc == msg->l2h);
return msg; return msg;
} }
@ -240,7 +241,32 @@ void ms_sends_msg(const char *hex)
msg = msgb_from_hex("ms_sends_msg", 1024, hex); msg = msgb_from_hex("ms_sends_msg", 1024, hex);
msg->l1h = msg->l2h = msg->l3h = msg->data; msg->l1h = msg->l2h = msg->l3h = msg->data;
rx_from_ms(msg); rx_from_ms(msg);
talloc_free(msg); msgb_free(msg);
}
void bss_sends_bssap_mgmt(const char *hex)
{
struct msgb *msg;
struct bssmap_header *bh;
struct a_conn_info a_conn_info;
msg = msgb_from_hex("bss_sends_bssap_mgmt", 1024, hex);
msg->l3h = msg->data;
msg->l2h = msgb_push(msg, sizeof(*bh));
bh = (void*)msg->l2h;
bh->type = BSSAP_MSG_BSS_MANAGEMENT;
bh->length = msgb_l3len(msg);
if (g_conn && !conn_exists(g_conn))
g_conn = NULL;
OSMO_ASSERT(g_conn);
a_conn_info.network = net;
a_conn_info.conn_id = g_conn->a.conn_id;
a_sccp_rx_dt((struct osmo_sccp_user*)0x1, &a_conn_info, msg);
msgb_free(msg);
} }
static int ms_sends_msg_fake(uint8_t pdisc, uint8_t msg_type) static int ms_sends_msg_fake(uint8_t pdisc, uint8_t msg_type)
@ -363,6 +389,33 @@ void __wrap_msc_stop_paging(struct vlr_subscr *vsub)
paging_stopped = true; paging_stopped = true;
} }
/* override, requires '-Wl,--wrap=osmo_sccp_tx_data_msg' */
int __real_osmo_sccp_tx_data_msg(struct osmo_sccp_user *scu, uint32_t conn_id,
struct msgb *msg);
int __wrap_osmo_sccp_tx_data_msg(struct osmo_sccp_user *scu, uint32_t conn_id,
struct msgb *msg)
{
const char *proto_str;
const char *msg_str = gsm0808_bssmap_name(msg->l3h[2]);
switch (*msg->l3h) {
case BSSAP_MSG_BSS_MANAGEMENT:
proto_str = "BSSAP-BSS-MANAGEMENT";
break;
case BSSAP_MSG_DTAP:
proto_str = "BSSAP-DTAP";
break;
default:
proto_str = "";
msg_str = "";
break;
}
log("BSC <--%s-- MSC: %s %s", proto_str, msg_str, msgb_hexdump(msg));
msgb_free(msg);
return 0;
}
void clear_vlr() void clear_vlr()
{ {
struct vlr_subscr *vsub, *n; struct vlr_subscr *vsub, *n;

1
tests/msc_vlr/msc_vlr_tests.h
View File

@ -161,6 +161,7 @@ void dtap_expect_tx_ussd(char *ussd_text);
void paging_expect_imsi(const char *imsi); void paging_expect_imsi(const char *imsi);
void paging_expect_tmsi(uint32_t tmsi); void paging_expect_tmsi(uint32_t tmsi);
void bss_sends_bssap_mgmt(const char *hex);
void ms_sends_msg(const char *hex); void ms_sends_msg(const char *hex);
void ms_sends_security_mode_complete(); void ms_sends_security_mode_complete();
void gsup_rx(const char *rx_hex, const char *expect_tx_hex); void gsup_rx(const char *rx_hex, const char *expect_tx_hex);