17 Mar
2015
17 Mar
'15
10:21 a.m.
Currently when using 'logging print extended-timestamp 1', the
subsecond part (milliseconds) of the printed timestamp is always 0.
This makes it difficult to correlate log entries with PCAP file
entries if there are many of them per second.
This patch changes _output in logging.c to use gettimeofday() instead
of time() when extended timestamps are enabled and replaces the '000'
by the milliseconds computed from tv_usec.
Sponsored-by: On-Waves ehf
---
src/logging.c | 11 +++++++----
1 file changed, 7 insertions(+), 4 deletions(-)
diff --git a/src/logging.c b/src/logging.c
index c007a45..20b0596 100644
--- a/src/logging.c
+++ b/src/logging.c
@@ -38,6 +38,7 @@
#include <strings.h>
#endif
#include <time.h>
+#include <sys/time.h>
#include <errno.h>
#include <osmocom/core/talloc.h>
@@ -254,11 +255,13 @@ static void _output(struct log_target *target, unsigned int subsys,
if (!cont) {
if (target->print_ext_timestamp) {
struct tm tm;
- time_t timep = time(NULL);
- localtime_r(&timep, &tm);
- ret = snprintf(buf + offset, rem, "%04d%02d%02d%02d%02d%02d000 ",
+ struct timeval tv;
+ gettimeofday(&tv, NULL);
+ localtime_r(&tv.tv_sec, &tm);
+ ret = snprintf(buf + offset, rem, "%04d%02d%02d%02d%02d%02d%03d ",
tm.tm_year + 1900, tm.tm_mon + 1, tm.tm_mday,
- tm.tm_hour, tm.tm_min, tm.tm_sec);
+ tm.tm_hour, tm.tm_min, tm.tm_sec,
+ (int)(tv.tv_usec / 1000));
if (ret < 0)
goto err;
OSMO_SNPRINTF_RET(ret, rem, offset, len);
--
1.9.1
17 Mar
17 Mar
10:21 a.m.
New subject: [PATCH 2/3] bssgp: Don't reply with STATUS when receiving a PtP STATUS message
Currently each incoming PtP BSSGP STATUS message is handled as 'not
yet implemented' and a BSSGP STATUS message (cause
BSSGP_CAUSE_PROTO_ERR_UNSPEC) is sent back to the peer. This will
cause endless messages loops if both peers use this BSSGP stack
implementation. This does not apply to signalling messages.
This commit changes the implementation of bssgp_rx_ptp() to just do
logging in this case.
Sponsored-by: On-Waves ehf
---
src/gb/gprs_bssgp.c | 2 ++
1 file changed, 2 insertions(+)
diff --git a/src/gb/gprs_bssgp.c b/src/gb/gprs_bssgp.c
index 851d01c..8708340 100644
--- a/src/gb/gprs_bssgp.c
+++ b/src/gb/gprs_bssgp.c
@@ -845,7 +845,9 @@ static int bssgp_rx_ptp(struct msgb *msg, struct tlv_parsed *tp,
break;
case BSSGP_PDUT_STATUS:
/* Some exception has occurred */
+ DEBUGP(DBSSGP, "BSSGP BVCI=%u Rx PTP BVC STATUS\n", bctx->bvci);
/* FIXME: send NM_STATUS.ind to NM */
+ break;
case BSSGP_PDUT_DOWNLOAD_BSS_PFC:
case BSSGP_PDUT_CREATE_BSS_PFC_ACK:
case BSSGP_PDUT_CREATE_BSS_PFC_NACK:
--
1.9.1
10:21 a.m.
New subject: [PATCH 3/3] bssgp: Handle BSSGP STATUS messages
Currently incoming BSSGP STATUS messages are just logged and no other
action is taken. This makes it impossible for higher layers to react
to failures which are indicated by corresponding STATUS messages
unless a timeout is triggered as a result of that failure later on.
This commit adds a bssgp_rx_status() function and calls it on
incoming STATUS messages. That function logs a message, increments the
new BSSGP_CTR_STATUS counter if the bctx context exists and invokes
an NM_STATUS status indication. The latter will allow the application
to handle failures immediately. Since all STATUS messages should be
handled, the function is already called in bssgp_rcvmsg and the
message is no longer handled in (and will not reach) bssgp_rx_sign
and bssgp_rx_ptp.
Ticket: OW#1414
Sponsored-by: On-Waves ehf
---
include/osmocom/gprs/gprs_bssgp.h | 2 +
src/gb/gprs_bssgp.c | 78 +++++++++++++++++++++++++++++++--------
tests/gb/gprs_bssgp_test.c | 35 ++++++++++++++++++
tests/gb/gprs_bssgp_test.ok | 4 ++
4 files changed, 103 insertions(+), 16 deletions(-)
diff --git a/include/osmocom/gprs/gprs_bssgp.h b/include/osmocom/gprs/gprs_bssgp.h
index f229253..e24b563 100644
--- a/include/osmocom/gprs/gprs_bssgp.h
+++ b/include/osmocom/gprs/gprs_bssgp.h
@@ -33,6 +33,7 @@ enum bssgp_prim {
PRIM_NM_BVC_RESET,
PRIM_NM_BVC_BLOCK,
PRIM_NM_BVC_UNBLOCK,
+ PRIM_NM_STATUS,
};
struct osmo_bssgp_prim {
@@ -117,6 +118,7 @@ enum bssgp_ctr {
BSSGP_CTR_BYTES_OUT,
BSSGP_CTR_BLOCKED,
BSSGP_CTR_DISCARDED,
+ BSSGP_CTR_STATUS,
};
diff --git a/src/gb/gprs_bssgp.c b/src/gb/gprs_bssgp.c
index 8708340..2f23290 100644
--- a/src/gb/gprs_bssgp.c
+++ b/src/gb/gprs_bssgp.c
@@ -46,6 +46,7 @@ static const struct rate_ctr_desc bssgp_ctr_description[] = {
{ "bytes.out", "Bytes at BSSGP Level (Out)" },
{ "blocked", "BVC Blocking count" },
{ "discarded", "BVC LLC Discarded count" },
+ { "status", "BVC Status count" },
};
static const struct rate_ctr_group_desc bssgp_ctrg_desc = {
@@ -516,6 +517,46 @@ static int bssgp_rx_llc_disc(struct msgb *msg, struct tlv_parsed
*tp,
return bssgp_prim_cb(&nmp.oph, NULL);
}
+int bssgp_rx_status(struct msgb *msg, struct tlv_parsed *tp,
+ uint16_t bvci, struct bssgp_bvc_ctx *bctx)
+{
+ struct osmo_bssgp_prim nmp;
+ enum gprs_bssgp_cause cause;
+
+ if (!TLVP_PRESENT(tp, BSSGP_IE_CAUSE)) {
+ LOGP(DBSSGP, LOGL_ERROR, "BSSGP BVCI=%u Rx STATUS "
+ "missing mandatory IE\n", bvci);
+ cause = BSSGP_CAUSE_PROTO_ERR_UNSPEC;
+ } else {
+ cause = *TLVP_VAL(tp, BSSGP_IE_CAUSE);
+ }
+
+ LOGP(DBSSGP, LOGL_NOTICE, "BSSGP BVCI=%u Rx BVC STATUS, cause=%s\n",
+ bvci, bssgp_cause_str(cause));
+
+ if (cause == BSSGP_CAUSE_BVCI_BLOCKED || cause == BSSGP_CAUSE_UNKNOWN_BVCI) {
+ if (!TLVP_PRESENT(tp, BSSGP_IE_BVCI))
+ LOGP(DBSSGP, LOGL_ERROR,
+ "BSSGP BVCI=%u Rx STATUS cause=%s "
+ "missing conditional BVCI IE\n",
+ bvci, bssgp_cause_str(cause));
+ }
+
+ if (bctx)
+ rate_ctr_inc(&bctx->ctrg->ctr[BSSGP_CTR_STATUS]);
+
+ /* send NM_STATUS to NM */
+ memset(&nmp, 0, sizeof(nmp));
+ nmp.nsei = msgb_nsei(msg);
+ nmp.bvci = bvci;
+ nmp.tp = tp;
+ osmo_prim_init(&nmp.oph, SAP_BSSGP_NM, PRIM_NM_STATUS,
+ PRIM_OP_INDICATION, msg);
+
+ return bssgp_prim_cb(&nmp.oph, NULL);
+}
+
+
/* One element (msgb) in a BSSGP Flow Control queue */
struct bssgp_fc_queue_element {
/* linked list of queue elements */
@@ -807,10 +848,12 @@ static int bssgp_rx_ptp(struct msgb *msg, struct tlv_parsed *tp,
uint8_t pdu_type = bgph->pdu_type;
int rc = 0;
+ OSMO_ASSERT(pdu_type != BSSGP_PDUT_STATUS);
+
/* If traffic is received on a BVC that is marked as blocked, the
* received PDU shall not be accepted and a STATUS PDU (Cause value:
* BVC Blocked) shall be sent to the peer entity on the signalling BVC */
- if (bctx->state & BVC_S_BLOCKED && pdu_type != BSSGP_PDUT_STATUS) {
+ if (bctx->state & BVC_S_BLOCKED) {
uint16_t bvci = msgb_bvci(msg);
return bssgp_tx_status(BSSGP_CAUSE_BVCI_BLOCKED, &bvci, msg);
}
@@ -844,9 +887,7 @@ static int bssgp_rx_ptp(struct msgb *msg, struct tlv_parsed *tp,
/* FIXME: Send FLOW_CONTROL_MS_ACK */
break;
case BSSGP_PDUT_STATUS:
- /* Some exception has occurred */
- DEBUGP(DBSSGP, "BSSGP BVCI=%u Rx PTP BVC STATUS\n", bctx->bvci);
- /* FIXME: send NM_STATUS.ind to NM */
+ /* This is already handled in bssgp_rcvmsg() */
break;
case BSSGP_PDUT_DOWNLOAD_BSS_PFC:
case BSSGP_PDUT_CREATE_BSS_PFC_ACK:
@@ -943,9 +984,7 @@ static int bssgp_rx_sign(struct msgb *msg, struct tlv_parsed *tp,
rc = bssgp_rx_bvc_reset(msg, tp, ns_bvci);
break;
case BSSGP_PDUT_STATUS:
- /* Some exception has occurred */
- DEBUGP(DBSSGP, "BSSGP BVCI=%u Rx BVC STATUS\n", bvci);
- /* FIXME: send NM_STATUS.ind to NM */
+ /* This is already handled in bssgp_rcvmsg() */
break;
/* those only exist in the SGSN -> BSS direction */
case BSSGP_PDUT_PAGING_PS:
@@ -1006,15 +1045,6 @@ int bssgp_rcvmsg(struct msgb *msg)
/* look-up or create the BTS context for this BVC */
bctx = btsctx_by_bvci_nsei(bvci, msgb_nsei(msg));
- /* Only a RESET PDU can create a new BVC context,
- * otherwise it must be registered if a BVCI is given */
- if (!bctx && bvci != BVCI_SIGNALLING &&
- pdu_type != BSSGP_PDUT_BVC_RESET) {
- LOGP(DBSSGP, LOGL_NOTICE, "NSEI=%u/BVCI=%u Rejecting PDU "
- "type %u for unknown BVCI\n", msgb_nsei(msg), bvci,
- pdu_type);
- return bssgp_tx_status(BSSGP_CAUSE_UNKNOWN_BVCI, &bvci, msg);
- }
if (bctx) {
log_set_context(GPRS_CTX_BVC, bctx);
@@ -1023,6 +1053,22 @@ int bssgp_rcvmsg(struct msgb *msg)
msgb_bssgp_len(msg));
}
+ /* Always handle STATUS PDUs, even if they contain an invalid BVCI or
+ * are otherwise unexpected */
+ if (pdu_type == BSSGP_PDUT_STATUS)
+ /* Some exception has occurred */
+ return bssgp_rx_status(msg, &tp, bvci, bctx);
+
+ /* Only a RESET PDU can create a new BVC context, otherwise it must be
+ * registered if a BVCI is given. */
+ if (!bctx && bvci != BVCI_SIGNALLING &&
+ pdu_type != BSSGP_PDUT_BVC_RESET) {
+ LOGP(DBSSGP, LOGL_NOTICE, "NSEI=%u/BVCI=%u Rejecting PDU "
+ "type %u for unknown BVCI\n", msgb_nsei(msg), bvci,
+ pdu_type);
+ return bssgp_tx_status(BSSGP_CAUSE_UNKNOWN_BVCI, &bvci, msg);
+ }
+
if (ns_bvci == BVCI_SIGNALLING)
rc = bssgp_rx_sign(msg, &tp, bctx);
else if (ns_bvci == BVCI_PTM)
diff --git a/tests/gb/gprs_bssgp_test.c b/tests/gb/gprs_bssgp_test.c
index a247326..3d1384b 100644
--- a/tests/gb/gprs_bssgp_test.c
+++ b/tests/gb/gprs_bssgp_test.c
@@ -125,6 +125,40 @@ static void test_bssgp_suspend_resume(void)
printf("----- %s END\n", __func__);
}
+static void send_bssgp_status(enum gprs_bssgp_cause cause, uint16_t *bvci)
+{
+ struct msgb *msg = bssgp_msgb_alloc();
+ uint8_t cause_ = cause;
+
+ msgb_v_put(msg, BSSGP_PDUT_STATUS);
+ msgb_tvlv_put(msg, BSSGP_IE_CAUSE, 1, &cause_);
+ if (bvci) {
+ uint16_t bvci_ = htons(*bvci);
+ msgb_tvlv_put(msg, BSSGP_IE_BVCI, 2, (uint8_t *) &bvci_);
+ }
+
+ msgb_bssgp_send_and_free(msg);
+}
+
+static void test_bssgp_status(void)
+{
+ uint16_t bvci;
+
+ printf("----- %s START\n", __func__);
+
+ send_bssgp_status(BSSGP_CAUSE_PROTO_ERR_UNSPEC, NULL);
+ OSMO_ASSERT(last_oph.primitive == PRIM_NM_STATUS);
+
+ /* Enforce prim != PRIM_NM_STATUS */
+ last_oph.primitive = PRIM_NM_LLC_DISCARDED;
+
+ bvci = 1234;
+ send_bssgp_status(BSSGP_CAUSE_UNKNOWN_BVCI, &bvci);
+ OSMO_ASSERT(last_oph.primitive == PRIM_NM_STATUS);
+
+ printf("----- %s END\n", __func__);
+}
+
static struct log_info info = {};
int main(int argc, char **argv)
@@ -146,6 +180,7 @@ int main(int argc, char **argv)
printf("===== BSSGP test START\n");
test_bssgp_suspend_resume();
+ test_bssgp_status();
printf("===== BSSGP test END\n\n");
exit(EXIT_SUCCESS);
diff --git a/tests/gb/gprs_bssgp_test.ok b/tests/gb/gprs_bssgp_test.ok
index c9ec83d..0392e6a 100644
--- a/tests/gb/gprs_bssgp_test.ok
+++ b/tests/gb/gprs_bssgp_test.ok
@@ -3,5 +3,9 @@
BSSGP primitive, SAP 16777219, prim = 3, op = 0, msg = 0b 1f 84 f0 12 34 56 1b 86 0f f1
80 20 37 00
BSSGP primitive, SAP 16777219, prim = 4, op = 0, msg = 0e 1f 84 f0 12 34 56 1b 86 0f f1
80 20 37 00 1d 81 01
----- test_bssgp_suspend_resume END
+----- test_bssgp_status START
+BSSGP primitive, SAP 16777221, prim = 11, op = 2, msg = 41 07 81 27
+BSSGP primitive, SAP 16777221, prim = 11, op = 2, msg = 41 07 81 05 04 82 04 d2
+----- test_bssgp_status END
===== BSSGP test END
--
1.9.1
3335
days inactive
3335
days old
2 comments
1 participants
participants (1)
-
Jacob Erlbeck