Discussion:
[PATCH 3/6] gprs-ns/test: Add expire_nsvc_timer
Jacob Erlbeck
2014-10-08 10:05:15 UTC
Permalink
This function forces the expiration of the timer within struct
gprs_nsvc. It is meant to be used for controlled (and faster) timer
expiration in unit tests. The timer_mode of the expired timer is
returned (or -1 if the timer wasn't active).

Sponsored-by: On-Waves ehf
---
tests/gb/gprs_ns_test.c | 15 +++++++++++++++
1 file changed, 15 insertions(+)

diff --git a/tests/gb/gprs_ns_test.c b/tests/gb/gprs_ns_test.c
index 0b3a76c..d56bf9a 100644
--- a/tests/gb/gprs_ns_test.c
+++ b/tests/gb/gprs_ns_test.c
@@ -451,6 +451,21 @@ static void gprs_dump_nsi(struct gprs_ns_inst *nsi)
printf("\n");
}

+static int expire_nsvc_timer(struct gprs_nsvc *nsvc)
+{
+ int rc;
+
+ if (!osmo_timer_pending(&nsvc->timer))
+ return -1;
+
+ rc = nsvc->timer_mode;
+ osmo_timer_del(&nsvc->timer);
+
+ nsvc->timer.cb(nsvc->timer.data);
+
+ return rc;
+}
+
static void test_nsvc()
{
struct gprs_ns_inst *nsi = gprs_ns_instantiate(gprs_ns_callback, NULL);
--
1.9.1
Jacob Erlbeck
2014-10-08 10:05:17 UTC
Permalink
Currently gprs_nsvc_reset does not return any value.

This patch changes the function to return an integer, where a value
less than zero indicates an error. The value is taken from the
gprs_ns_tx_reset function. In case of failure, an error message is logged.

Sponsored-by: On-Waves ehf
---
include/osmocom/gprs/gprs_ns.h | 2 +-
src/gb/gprs_ns.c | 9 +++++++--
2 files changed, 8 insertions(+), 3 deletions(-)

diff --git a/include/osmocom/gprs/gprs_ns.h b/include/osmocom/gprs/gprs_ns.h
index b4af61b..e77ca42 100644
--- a/include/osmocom/gprs/gprs_ns.h
+++ b/include/osmocom/gprs/gprs_ns.h
@@ -172,7 +172,7 @@ struct gprs_nsvc *gprs_nsvc_by_nsei(struct gprs_ns_inst *nsi, uint16_t nsei);
struct gprs_nsvc *gprs_nsvc_by_nsvci(struct gprs_ns_inst *nsi, uint16_t nsvci);

/* Initiate a RESET procedure (including timer start, ...)*/
-void gprs_nsvc_reset(struct gprs_nsvc *nsvc, uint8_t cause);
+int gprs_nsvc_reset(struct gprs_nsvc *nsvc, uint8_t cause);

/* Add NS-specific VTY stuff */
int gprs_ns_vty_init(struct gprs_ns_inst *nsi);
diff --git a/src/gb/gprs_ns.c b/src/gb/gprs_ns.c
index ee2d7ec..cf7adaf 100644
--- a/src/gb/gprs_ns.c
+++ b/src/gb/gprs_ns.c
@@ -1495,20 +1495,25 @@ int gprs_ns_nsip_listen(struct gprs_ns_inst *nsi)
* will not only send a NS-RESET, but also set the state to BLOCKED and
* start the Tns-reset timer.
*/
-void gprs_nsvc_reset(struct gprs_nsvc *nsvc, uint8_t cause)
+int gprs_nsvc_reset(struct gprs_nsvc *nsvc, uint8_t cause)
{
+ int rc;
+
LOGP(DNS, LOGL_INFO, "NSEI=%u RESET procedure based on API request\n",
nsvc->nsei);

/* Mark NS-VC locally as blocked and dead */
nsvc->state = NSE_S_BLOCKED;
/* Send NS-RESET PDU */
- if (gprs_ns_tx_reset(nsvc, cause) < 0) {
+ rc = gprs_ns_tx_reset(nsvc, cause);
+ if (rc < 0) {
LOGP(DNS, LOGL_ERROR, "NSEI=%u, error resetting NS-VC\n",
nsvc->nsei);
}
/* Start Tns-reset */
nsvc_start_timer(nsvc, NSVC_TIMER_TNS_RESET);
+
+ return rc;
}

/*! \brief Establish a NS connection (from the BSS) to the SGSN
--
1.9.1
Holger Hans Peter Freyther
2014-10-09 05:49:39 UTC
Permalink
Post by Jacob Erlbeck
Currently gprs_nsvc_reset does not return any value.
This patch changes the function to return an integer, where a value
less than zero indicates an error. The value is taken from the
gprs_ns_tx_reset function. In case of failure, an error message is logged.
ah. Now update the unit test to print "failed" again or preferable
OSMO_ASSERT(rc < 0)?
Jacob Erlbeck
2014-10-08 10:05:14 UTC
Permalink
This records the PCU type of the last message sent to the remote peer
in the global variable sent_pdu_type, which can then be used in
assertions.

Note that sent_pdu_type will remain unchanged if no message has been
sent via sendto.

Sponsored-by: On-Waves ehf
---
tests/gb/gprs_ns_test.c | 4 ++++
1 file changed, 4 insertions(+)

diff --git a/tests/gb/gprs_ns_test.c b/tests/gb/gprs_ns_test.c
index 15e36ba..0b3a76c 100644
--- a/tests/gb/gprs_ns_test.c
+++ b/tests/gb/gprs_ns_test.c
@@ -32,6 +32,8 @@

#define SGSN_NSEI 0x0100

+static int sent_pdu_type = 0;
+
static int gprs_process_message(struct gprs_ns_inst *nsi, const char *text,
struct sockaddr_in *peer, const unsigned char* data,
size_t data_len);
@@ -265,6 +267,8 @@ ssize_t sendto(int sockfd, const void *buf, size_t len, int flags,
if (!real_sendto)
real_sendto = dlsym(RTLD_NEXT, "sendto");

+ sent_pdu_type = len > 0 ? ((uint8_t *)buf)[0] : -1;
+
if (dest_host == REMOTE_BSS_ADDR)
printf("MESSAGE to BSS, msg length %d\n%s\n\n", len, osmo_hexdump(buf, len));
else if (dest_host == REMOTE_SGSN_ADDR)
--
1.9.1
Holger Hans Peter Freyther
2014-10-09 05:44:22 UTC
Permalink
Post by Jacob Erlbeck
This records the PCU type of the last message sent to the remote peer
^-- PDU ;)
Jacob Erlbeck
2014-10-08 10:05:16 UTC
Permalink
This tests the behaviour for a certain combination of messages and
packet losses that can put the NS-VC object into an undefined state.

In that state, the peer's ALIVE messages are properly answered, but
the local test procedure has stopped, incoming unitdata PDUs are
answered by STATUS(NS-VC blocked) and the unblocking procedure is not
initiated.

Ticket: OW#1312
Sponsored-by: On-Waves ehf
---
tests/gb/gprs_ns_test.c | 64 +++++++++++++++++++++++++++++++
tests/gb/gprs_ns_test.ok | 99 ++++++++++++++++++++++++++++++++++++++++++++++++
2 files changed, 163 insertions(+)

diff --git a/tests/gb/gprs_ns_test.c b/tests/gb/gprs_ns_test.c
index d56bf9a..ad8e6d5 100644
--- a/tests/gb/gprs_ns_test.c
+++ b/tests/gb/gprs_ns_test.c
@@ -791,6 +791,69 @@ static void test_sgsn_reset()
nsi = NULL;
}

+static void test_sgsn_reset_invalid_state()
+{
+ struct gprs_ns_inst *nsi = gprs_ns_instantiate(gprs_ns_callback, NULL);
+ struct sockaddr_in sgsn_peer= {0};
+ struct gprs_nsvc *nsvc;
+ int retry;
+ uint8_t dummy_sdu[] = {0x01, 0x02, 0x03, 0x04};
+
+ sgsn_peer.sin_family = AF_INET;
+ sgsn_peer.sin_port = htons(32000);
+ sgsn_peer.sin_addr.s_addr = htonl(REMOTE_SGSN_ADDR);
+
+ gprs_dump_nsi(nsi);
+
+ printf("=== %s ===\n", __func__);
+ printf("--- Setup SGSN connection, BSS -> SGSN ---\n\n");
+
+ gprs_ns_nsip_connect(nsi, &sgsn_peer, SGSN_NSEI, SGSN_NSEI+1);
+ OSMO_ASSERT(sent_pdu_type == NS_PDUT_RESET);
+ send_ns_reset_ack(nsi, &sgsn_peer, SGSN_NSEI+1, SGSN_NSEI);
+ OSMO_ASSERT(sent_pdu_type == NS_PDUT_ALIVE);
+ send_ns_alive_ack(nsi, &sgsn_peer);
+ OSMO_ASSERT(sent_pdu_type == NS_PDUT_UNBLOCK);
+ send_ns_unblock_ack(nsi, &sgsn_peer);
+ gprs_dump_nsi(nsi);
+ nsvc = gprs_nsvc_by_nsvci(nsi, SGSN_NSEI+1);
+ OSMO_ASSERT(nsvc->state == NSE_S_ALIVE);
+ OSMO_ASSERT(nsvc->remote_state == NSE_S_ALIVE);
+
+ printf("--- Time out local test procedure ---\n\n");
+
+ OSMO_ASSERT(expire_nsvc_timer(nsvc) == NSVC_TIMER_TNS_TEST);
+ OSMO_ASSERT(expire_nsvc_timer(nsvc) == NSVC_TIMER_TNS_ALIVE);
+
+ for (retry = 1; retry <= nsi->timeout[NS_TOUT_TNS_ALIVE_RETRIES]; ++retry)
+ OSMO_ASSERT(expire_nsvc_timer(nsvc) == NSVC_TIMER_TNS_ALIVE);
+
+ OSMO_ASSERT(nsvc->state == NSE_S_BLOCKED);
+
+ printf("--- Remote test procedure continues ---\n\n");
+
+ send_ns_alive(nsi, &sgsn_peer);
+ OSMO_ASSERT(sent_pdu_type == NS_PDUT_RESET);
+
+ printf("--- Don't send a NS_RESET_ACK message (pretend it is lost) ---\n\n");
+
+ sent_pdu_type = -1;
+ send_ns_alive(nsi, &sgsn_peer);
+ /* Disabled, since it is not yet fixed
+ OSMO_ASSERT(sent_pdu_type == -1);
+ send_ns_reset_ack(nsi, &sgsn_peer, SGSN_NSEI+1, SGSN_NSEI);
+ OSMO_ASSERT(sent_pdu_type == NS_PDUT_ALIVE);
+ send_ns_alive_ack(nsi, &sgsn_peer);
+ OSMO_ASSERT(sent_pdu_type == NS_PDUT_UNBLOCK);
+ send_ns_unblock_ack(nsi, &sgsn_peer);
+ */
+
+ send_ns_unitdata(nsi, &sgsn_peer, 0x1234, dummy_sdu, sizeof(dummy_sdu));
+
+ gprs_ns_destroy(nsi);
+ nsi = NULL;
+}
+
static void test_sgsn_output()
{
struct gprs_ns_inst *nsi = gprs_ns_instantiate(gprs_ns_callback, NULL);
@@ -875,6 +938,7 @@ int main(int argc, char **argv)
test_bss_port_changes();
test_bss_reset_ack();
test_sgsn_reset();
+ test_sgsn_reset_invalid_state();
test_sgsn_output();
printf("===== NS protocol test END\n\n");

diff --git a/tests/gb/gprs_ns_test.ok b/tests/gb/gprs_ns_test.ok
index 0d4b7fb..66b1dbb 100644
--- a/tests/gb/gprs_ns_test.ok
+++ b/tests/gb/gprs_ns_test.ok
@@ -722,6 +722,105 @@ Current NS-VCIs:

Current NS-VCIs:

+=== test_sgsn_reset_invalid_state ===
+--- Setup SGSN connection, BSS -> SGSN ---
+
+MESSAGE to SGSN, msg length 12
+02 00 81 01 01 82 01 01 04 82 01 00
+
+PROCESSING RESET_ACK from 0x05060708:32000
+03 01 82 01 01 04 82 01 00
+
+MESSAGE to SGSN, msg length 1
+0a
+
+result (RESET_ACK) = 1
+
+PROCESSING ALIVE_ACK from 0x05060708:32000
+0b
+
+MESSAGE to SGSN, msg length 1
+06
+
+result (ALIVE_ACK) = 1
+
+PROCESSING UNBLOCK_ACK from 0x05060708:32000
+07
+
+==> got signal NS_UNBLOCK, NS-VC 0x0101/5.6.7.8:32000
+result (UNBLOCK_ACK) = 0
+
+Current NS-VCIs:
+ VCI 0x0101, NSEI 0x0100, peer 0x05060708:32000
+ NS-VC Block count : 1
+
+--- Time out local test procedure ---
+
+MESSAGE to SGSN, msg length 1
+0a
+
+MESSAGE to SGSN, msg length 1
+0a
+
+MESSAGE to SGSN, msg length 1
+0a
+
+MESSAGE to SGSN, msg length 1
+0a
+
+MESSAGE to SGSN, msg length 1
+0a
+
+MESSAGE to SGSN, msg length 1
+0a
+
+MESSAGE to SGSN, msg length 1
+0a
+
+MESSAGE to SGSN, msg length 1
+0a
+
+MESSAGE to SGSN, msg length 1
+0a
+
+MESSAGE to SGSN, msg length 1
+0a
+
+MESSAGE to SGSN, msg length 1
+0a
+
+==> got signal NS_ALIVE_EXP, NS-VC 0x0101/5.6.7.8:32000
+==> got signal NS_BLOCK, NS-VC 0x0101/5.6.7.8:32000
+--- Remote test procedure continues ---
+
+PROCESSING ALIVE from 0x05060708:32000
+0a
+
+MESSAGE to SGSN, msg length 12
+02 00 81 0a 01 82 01 01 04 82 01 00
+
+result (ALIVE) = 12
+
+--- Don't send a NS_RESET_ACK message (pretend it is lost) ---
+
+PROCESSING ALIVE from 0x05060708:32000
+0a
+
+MESSAGE to SGSN, msg length 1
+0b
+
+result (ALIVE) = 1
+
+PROCESSING UNITDATA from 0x05060708:32000
+00 00 12 34 01 02 03 04
+
+MESSAGE to SGSN, msg length 8
+08 00 81 03 01 82 01 01
+
+result (UNITDATA) = 8
+
+Current NS-VCIs:
+
--- Send message to SGSN ---

SENDING BSSGP RESET to NSEI 0x0100, BVCI 0x0000
--
1.9.1
Jacob Erlbeck
2014-10-08 10:05:18 UTC
Permalink
Currently the NS-VC's state is updated from within gprs_ns_tx_reset,
which can lead to an inconsistent state when the RESET_ACK is lost.
In this state, the NSE_S_RESET bit is set but the Tns-reset timer is
not started.

This patch moves the state update into gprs_nsvc_reset. This way, the
state flags are consistent with the timer.

Addresses:
SGSN -> BSS NS_ALIVE
BSS -> SGSN NS_ALIVE_ACK
BSS -> SGSN BVC_RESET
SGSN -> BSS NS_STATUS, Cause: NS-VC blocked, NS VCI: 0x65
and there is no BSS->SGSN NS_ALIVE

Ticket: OW#1213
Sponsored-by: On-Waves ehf
---
src/gb/gprs_ns.c | 9 ++++-----
tests/gb/gprs_ns_test.c | 2 --
tests/gb/gprs_ns_test.ok | 27 +++++++++++++++++++++++----
3 files changed, 27 insertions(+), 11 deletions(-)

diff --git a/src/gb/gprs_ns.c b/src/gb/gprs_ns.c
index cf7adaf..65d0494 100644
--- a/src/gb/gprs_ns.c
+++ b/src/gb/gprs_ns.c
@@ -348,8 +348,6 @@ int gprs_ns_tx_reset(struct gprs_nsvc *nsvc, uint8_t cause)
LOGP(DNS, LOGL_INFO, "NSEI=%u Tx NS RESET (NSVCI=%u, cause=%s)\n",
nsvc->nsei, nsvc->nsvci, gprs_ns_cause_str(cause));

- nsvc->state |= NSE_S_RESET;
-
msg->l2h = msgb_put(msg, sizeof(*nsh));
nsh = (struct gprs_ns_hdr *) msg->l2h;
nsh->pdu_type = NS_PDUT_RESET;
@@ -1250,8 +1248,8 @@ int gprs_ns_process_msg(struct gprs_ns_inst *nsi, struct msgb *msg,
* and should send a NS-RESET to make sure everything recovers
* fine. */
if ((*nsvc)->state == NSE_S_BLOCKED)
- rc = gprs_ns_tx_reset((*nsvc), NS_CAUSE_PDU_INCOMP_PSTATE);
- else
+ rc = gprs_nsvc_reset((*nsvc), NS_CAUSE_PDU_INCOMP_PSTATE);
+ else if (!((*nsvc)->state & NSE_S_RESET))
rc = gprs_ns_tx_alive_ack(*nsvc);
break;
case NS_PDUT_ALIVE_ACK:
@@ -1503,7 +1501,8 @@ int gprs_nsvc_reset(struct gprs_nsvc *nsvc, uint8_t cause)
nsvc->nsei);

/* Mark NS-VC locally as blocked and dead */
- nsvc->state = NSE_S_BLOCKED;
+ nsvc->state = NSE_S_BLOCKED | NSE_S_RESET;
+
/* Send NS-RESET PDU */
rc = gprs_ns_tx_reset(nsvc, cause);
if (rc < 0) {
diff --git a/tests/gb/gprs_ns_test.c b/tests/gb/gprs_ns_test.c
index ad8e6d5..2185ff8 100644
--- a/tests/gb/gprs_ns_test.c
+++ b/tests/gb/gprs_ns_test.c
@@ -839,14 +839,12 @@ static void test_sgsn_reset_invalid_state()

sent_pdu_type = -1;
send_ns_alive(nsi, &sgsn_peer);
- /* Disabled, since it is not yet fixed
OSMO_ASSERT(sent_pdu_type == -1);
send_ns_reset_ack(nsi, &sgsn_peer, SGSN_NSEI+1, SGSN_NSEI);
OSMO_ASSERT(sent_pdu_type == NS_PDUT_ALIVE);
send_ns_alive_ack(nsi, &sgsn_peer);
OSMO_ASSERT(sent_pdu_type == NS_PDUT_UNBLOCK);
send_ns_unblock_ack(nsi, &sgsn_peer);
- */

send_ns_unitdata(nsi, &sgsn_peer, 0x1234, dummy_sdu, sizeof(dummy_sdu));

diff --git a/tests/gb/gprs_ns_test.ok b/tests/gb/gprs_ns_test.ok
index 66b1dbb..1e0bf7f 100644
--- a/tests/gb/gprs_ns_test.ok
+++ b/tests/gb/gprs_ns_test.ok
@@ -806,18 +806,37 @@ result (ALIVE) = 12
PROCESSING ALIVE from 0x05060708:32000
0a

+result (ALIVE) = 0
+
+PROCESSING RESET_ACK from 0x05060708:32000
+03 01 82 01 01 04 82 01 00
+
MESSAGE to SGSN, msg length 1
+0a
+
+result (RESET_ACK) = 1
+
+PROCESSING ALIVE_ACK from 0x05060708:32000
0b

-result (ALIVE) = 1
+MESSAGE to SGSN, msg length 1
+06
+
+result (ALIVE_ACK) = 1
+
+PROCESSING UNBLOCK_ACK from 0x05060708:32000
+07
+
+==> got signal NS_UNBLOCK, NS-VC 0x0101/5.6.7.8:32000
+result (UNBLOCK_ACK) = 0

PROCESSING UNITDATA from 0x05060708:32000
00 00 12 34 01 02 03 04

-MESSAGE to SGSN, msg length 8
-08 00 81 03 01 82 01 01
+CALLBACK, event 0, msg length 4, bvci 0x1234
+01 02 03 04

-result (UNITDATA) = 8
+result (UNITDATA) = 0

Current NS-VCIs:
--
1.9.1
Holger Hans Peter Freyther
2014-10-09 05:52:17 UTC
Permalink
Post by Jacob Erlbeck
Currently the NS-VC's state is updated from within gprs_ns_tx_reset,
which can lead to an inconsistent state when the RESET_ACK is lost.
In this state, the NSE_S_RESET bit is set but the Tns-reset timer is
not started.
sent_pdu_type = -1;
send_ns_alive(nsi, &sgsn_peer);
- /* Disabled, since it is not yet fixed
OSMO_ASSERT(sent_pdu_type == -1);
send_ns_reset_ack(nsi, &sgsn_peer, SGSN_NSEI+1, SGSN_NSEI);
OSMO_ASSERT(sent_pdu_type == NS_PDUT_ALIVE);
send_ns_alive_ack(nsi, &sgsn_peer);
OSMO_ASSERT(sent_pdu_type == NS_PDUT_UNBLOCK);
send_ns_unblock_ack(nsi, &sgsn_peer);
- */
send_ns_unitdata(nsi, &sgsn_peer, 0x1234, dummy_sdu, sizeof(dummy_sdu));
I think it would be nice if you could directly ASSERT the unblocked
alive state of the NSI? It should be fairly to do?

All patches look great and it is nice incremental work. I am going
to merge them now. Please provide a follow-up patch that addresses
the points you think are valid.

holger

Holger Hans Peter Freyther
2014-10-09 05:43:12 UTC
Permalink
Currently gprs_ns_tx_reset is used to let the NS stack generate
NS_RESET message. This is not adjusting the nsvc state properly.
This patch uses gprs_nsvc_reset instead which starts the full reset
procedure.
Shall we patch gprs_nsvc_reset to return the error from the
gprs_ns_tx_reset call?
- rc = gprs_ns_tx_reset(nsvc, NS_CAUSE_OM_INTERVENTION);
- if (rc < 0)
- printf("Failed to send RESET to %s\n\n", gprs_ns_ll_str(nsvc));
- else {
- send_ns_reset_ack(nsi, nse[1], 0x2001, 0x2000);
- gprs_dump_nsi(nsi);
- }
+ gprs_nsvc_reset(nsvc, NS_CAUSE_OM_INTERVENTION);
e.g. we entered the "failed" path here and don't capture the
log output. of libosmogb.
Loading...