[MERGED] openbsc[master]: Improve GPRS logging

This is merely a historical archive of years 2008-2021, before the migration to mailman3.

A maintained and still updated list archive can be found at https://lists.osmocom.org/hyperkitty/list/gerrit-log@lists.osmocom.org/.

Harald Welte gerrit-no-reply at lists.osmocom.org
Wed Dec 21 10:27:24 UTC 2016


Harald Welte has submitted this change and it was merged.

Change subject: Improve GPRS logging
......................................................................


Improve GPRS logging

* log xid type as string instead of int
* log packet encryption status, algorithm and IOV-UI in debug mode
* print encryption parameters when dumping llme via vty
* log key propagation from MM to LLC

Related: OS#1794
Change-Id: I30c38fdeb0b88bb39bdb9928851300bc79e6aec6
---
M openbsc/include/openbsc/gprs_llc.h
M openbsc/src/gprs/gprs_gb_parse.c
M openbsc/src/gprs/gprs_llc.c
M openbsc/src/gprs/gprs_llc_parse.c
M openbsc/src/gprs/gprs_llc_vty.c
M openbsc/src/gprs/gprs_llc_xid.c
M openbsc/src/gprs/gprs_sgsn.c
7 files changed, 63 insertions(+), 20 deletions(-)

Approvals:
  Harald Welte: Looks good to me, approved
  Jenkins Builder: Verified



diff --git a/openbsc/include/openbsc/gprs_llc.h b/openbsc/include/openbsc/gprs_llc.h
index 8b01467..8bc2267 100644
--- a/openbsc/include/openbsc/gprs_llc.h
+++ b/openbsc/include/openbsc/gprs_llc.h
@@ -46,6 +46,8 @@
 	GPRS_LLC_XID_T_RESET		= 12,
 };
 
+extern const struct value_string gprs_llc_xid_type_names[];
+
 /* TS 04.64 Section 7.1.2 Table 7: LLC layer primitives (GMM/SNDCP/SMS/TOM) */
 /* TS 04.65 Section 5.1.2 Table 2: Service primitives used by SNDCP */
 enum gprs_llc_primitive {
@@ -270,7 +272,7 @@
 /* parse a GPRS LLC header, also check for invalid frames */
 int gprs_llc_hdr_parse(struct gprs_llc_hdr_parsed *ghp,
 		       uint8_t *llc_hdr, int len);
-void gprs_llc_hdr_dump(struct gprs_llc_hdr_parsed *gph);
+void gprs_llc_hdr_dump(struct gprs_llc_hdr_parsed *gph, struct gprs_llc_lle *lle);
 int gprs_llc_fcs(uint8_t *data, unsigned int len);
 
 
diff --git a/openbsc/src/gprs/gprs_gb_parse.c b/openbsc/src/gprs/gprs_gb_parse.c
index f11d93a..9befa39 100644
--- a/openbsc/src/gprs/gprs_gb_parse.c
+++ b/openbsc/src/gprs/gprs_gb_parse.c
@@ -398,7 +398,7 @@
 
 	/* parse LLC */
 	rc = gprs_llc_hdr_parse(ghp, llc, llc_len);
-	gprs_llc_hdr_dump(ghp);
+	gprs_llc_hdr_dump(ghp, NULL);
 	if (rc != 0) {
 		LOGP(DLLC, LOGL_NOTICE, "Error during LLC header parsing\n");
 		return 0;
diff --git a/openbsc/src/gprs/gprs_llc.c b/openbsc/src/gprs/gprs_llc.c
index 0215029..c2c3900 100644
--- a/openbsc/src/gprs/gprs_llc.c
+++ b/openbsc/src/gprs/gprs_llc.c
@@ -39,6 +39,7 @@
 #include <openbsc/gprs_llc.h>
 #include <openbsc/crc24.h>
 #include <openbsc/sgsn.h>
+#include <openbsc/gsm_subscriber.h>
 #include <openbsc/gprs_llc_xid.h>
 #include <openbsc/gprs_sndcp_comp.h>
 #include <openbsc/gprs_sndcp.h>
@@ -178,8 +179,10 @@
 				 * inquiry. There is a remainig risk of
 				 * malfunction! */
 				LOGP(DLLC, LOGL_NOTICE,
-				     "Ignoring XID-Field: XID: type=%d, data_len=%d, data=%s\n",
-				     xid_field->type, xid_field->data_len,
+				     "Ignoring XID-Field: XID: type %s, data_len=%d, data=%s\n",
+				     get_value_string(gprs_llc_xid_type_names,
+						      xid_field->type),
+				     xid_field->data_len,
 				     osmo_hexdump_nospc(xid_field->data,
 				     xid_field->data_len));
 			}
@@ -232,8 +235,10 @@
 				 * when a phone submits values which defer from
 				 * the default! */
 				LOGP(DLLC, LOGL_NOTICE,
-				     "Echoing XID-Field: XID: type=%d, data_len=%d, data=%s\n",
-				     xid_field->type, xid_field->data_len,
+				     "Echoing XID-Field: XID: type %s, data_len=%d, data=%s\n",
+				     get_value_string(gprs_llc_xid_type_names,
+						      xid_field->type),
+				     xid_field->data_len,
 				     osmo_hexdump_nospc(xid_field->data,
 							xid_field->data_len));
 				xid_field_response =
@@ -308,7 +313,6 @@
 	}
 }
 
-
 /* Set of LL-XID negotiation (See also: TS 101 351, Section 7.2.2.4) */
 int gprs_ll_xid_req(struct gprs_llc_lle *lle,
 		    struct gprs_llc_xid_field *l3_xid_field)
@@ -319,6 +323,7 @@
 	int xid_bytes_len;
 	uint8_t *xid;
 	struct msgb *msg;
+	const char *ftype;
 
 	/* Generate XID */
 	xid_bytes_len =
@@ -331,7 +336,13 @@
 		msg = msgb_alloc_headroom(4096, 1024, "LLC_XID");
 		xid = msgb_put(msg, xid_bytes_len);
 		memcpy(xid, xid_bytes, xid_bytes_len);
-		LOGP(DLLC, LOGL_NOTICE, "Sending XID request to phone...\n");
+		if (l3_xid_field)
+			ftype = get_value_string(gprs_llc_xid_type_names,
+						 l3_xid_field->type);
+		else
+			ftype = "NULL";
+		LOGP(DLLC, LOGL_NOTICE, "Sending XID type %s (%d bytes) request"
+		     " to phone...\n", ftype, xid_bytes_len);
 		gprs_llc_tx_xid(lle, msg, 1);
 	} else {
 		LOGP(DLLC, LOGL_ERROR,
@@ -858,7 +869,7 @@
 {
 	struct gprs_llc_hdr *lh = (struct gprs_llc_hdr *) msgb_llch(msg);
 	struct gprs_llc_hdr_parsed llhp;
-	struct gprs_llc_lle *lle;
+	struct gprs_llc_lle *lle = NULL;
 	bool drop_cipherable = false;
 	int rc = 0;
 
@@ -866,7 +877,6 @@
 
 	memset(&llhp, 0, sizeof(llhp));
 	rc = gprs_llc_hdr_parse(&llhp, (uint8_t *) lh, TLVP_LEN(tv, BSSGP_IE_LLC_PDU));
-	gprs_llc_hdr_dump(&llhp);
 	if (rc < 0) {
 		LOGP(DLLC, LOGL_NOTICE, "Error during LLC header parsing\n");
 		return rc;
@@ -899,7 +909,7 @@
 		}
 		return 0;
 	}
-
+	gprs_llc_hdr_dump(&llhp, lle);
 	/* reset age computation */
 	lle->llme->age_timestamp = GPRS_LLME_RESET_AGE;
 
diff --git a/openbsc/src/gprs/gprs_llc_parse.c b/openbsc/src/gprs/gprs_llc_parse.c
index b1f1a56..a5a7a71 100644
--- a/openbsc/src/gprs/gprs_llc_parse.c
+++ b/openbsc/src/gprs/gprs_llc_parse.c
@@ -67,11 +67,19 @@
 	return fcs_calc;
 }
 
-void gprs_llc_hdr_dump(struct gprs_llc_hdr_parsed *gph)
+void gprs_llc_hdr_dump(struct gprs_llc_hdr_parsed *gph, struct gprs_llc_lle *lle)
 {
-	DEBUGP(DLLC, "LLC SAPI=%u %c %c FCS=0x%06x",
-		gph->sapi, gph->is_cmd ? 'C' : 'R', gph->ack_req ? 'A' : ' ',
-		gph->fcs);
+	const char *gea;
+	uint32_t iov_ui = 0;
+	if (lle) {
+		gea = get_value_string(gprs_cipher_names, lle->llme->algo);
+		iov_ui = lle->llme->iov_ui;
+	} else
+		gea = "GEA?";
+	DEBUGP(DLLC, "LLC SAPI=%u %c %c %c %s IOV-UI=0x%06x FCS=0x%06x ",
+	       gph->sapi, gph->is_cmd ? 'C' : 'R', gph->ack_req ? 'A' : ' ',
+	       gph->is_encrypted ? 'E' : 'U',
+	       gea, iov_ui, gph->fcs);
 
 	if (gph->cmd)
 		DEBUGPC(DLLC, "CMD=%s ", get_value_string(llc_cmd_strs, gph->cmd));
diff --git a/openbsc/src/gprs/gprs_llc_vty.c b/openbsc/src/gprs/gprs_llc_vty.c
index f399b27..e97416b 100644
--- a/openbsc/src/gprs/gprs_llc_vty.c
+++ b/openbsc/src/gprs/gprs_llc_vty.c
@@ -73,9 +73,11 @@
 	struct timespec now_tp = {0};
 	clock_gettime(CLOCK_MONOTONIC, &now_tp);
 
-	vty_out(vty, "TLLI %08x (Old TLLI %08x) BVCI=%u NSEI=%u Age=%d: State %s%s",
-		llme->tlli, llme->old_tlli, llme->bvci, llme->nsei,
-		llme->age_timestamp == GPRS_LLME_RESET_AGE ? 0 :
+	vty_out(vty, "TLLI %08x (Old TLLI %08x) BVCI=%u NSEI=%u %s: "
+		"IOV-UI=0x%06x CKSN=%d Age=%d: State %s%s", llme->tlli,
+		llme->old_tlli, llme->bvci, llme->nsei,
+		get_value_string(gprs_cipher_names, llme->algo), llme->iov_ui,
+		llme->cksn, llme->age_timestamp == GPRS_LLME_RESET_AGE ? 0 :
 		(int)(now_tp.tv_sec - (time_t)llme->age_timestamp),
 		get_value_string(gprs_llc_state_strs, llme->state), VTY_NEWLINE);
 
diff --git a/openbsc/src/gprs/gprs_llc_xid.c b/openbsc/src/gprs/gprs_llc_xid.c
index 4b1685e..fe63171 100644
--- a/openbsc/src/gprs/gprs_llc_xid.c
+++ b/openbsc/src/gprs/gprs_llc_xid.c
@@ -35,6 +35,23 @@
 #include <openbsc/sgsn.h>
 #include <openbsc/gprs_llc_xid.h>
 
+const struct value_string gprs_llc_xid_type_names[] = {
+	{ GPRS_LLC_XID_T_VERSION,	"VERSION"},
+	{ GPRS_LLC_XID_T_IOV_UI,	"IOV_UI"},
+	{ GPRS_LLC_XID_T_IOV_I,		"IOV_I"},
+	{ GPRS_LLC_XID_T_T200,		"T200"},
+	{ GPRS_LLC_XID_T_N200,		"N200"},
+	{ GPRS_LLC_XID_T_N201_U,	"N201_"},
+	{ GPRS_LLC_XID_T_N201_I,	"N201_I"},
+	{ GPRS_LLC_XID_T_mD,		"mD"},
+	{ GPRS_LLC_XID_T_mU,		"mU"},
+	{ GPRS_LLC_XID_T_kD,		"kD"},
+	{ GPRS_LLC_XID_T_kU,		"kU"},
+	{ GPRS_LLC_XID_T_L3_PAR,	"L3_PAR"},
+	{ GPRS_LLC_XID_T_RESET,		"RESET"},
+	{ 0, NULL },
+};
+
 /* Parse XID parameter field */
 static int decode_xid_field(struct gprs_llc_xid_field *xid_field,
 			    const uint8_t *src, uint8_t src_len)
@@ -249,8 +266,10 @@
 		if (xid_field->data_len) {
 			OSMO_ASSERT(xid_field->data);
 			LOGP(DLLC, logl,
-			     "XID: type=%d, data_len=%d, data=%s\n",
-			     xid_field->type, xid_field->data_len,
+			     "XID: type %s, data_len=%d, data=%s\n",
+			     get_value_string(gprs_llc_xid_type_names,
+					      xid_field->type),
+			     xid_field->data_len,
 			     osmo_hexdump_nospc(xid_field->data,
 						xid_field->data_len));
 		} else {
diff --git a/openbsc/src/gprs/gprs_sgsn.c b/openbsc/src/gprs/gprs_sgsn.c
index e5a54d9..e85e1a9 100644
--- a/openbsc/src/gprs/gprs_sgsn.c
+++ b/openbsc/src/gprs/gprs_sgsn.c
@@ -225,6 +225,8 @@
 	ctx->mm_state = GMM_DEREGISTERED;
 	ctx->auth_triplet.key_seq = GSM_KEY_SEQ_INVAL;
 	ctx->ciph_algo = sgsn->cfg.cipher;
+	LOGMMCTXP(LOGL_DEBUG, ctx, "Allocated with %s cipher.\n",
+		  get_value_string(gprs_cipher_names, ctx->ciph_algo));
 	ctx->ctrg = rate_ctr_group_alloc(ctx, &mmctx_ctrg_desc, tlli);
 	INIT_LLIST_HEAD(&ctx->pdp_list);
 

-- 
To view, visit https://gerrit.osmocom.org/1461
To unsubscribe, visit https://gerrit.osmocom.org/settings

Gerrit-MessageType: merged
Gerrit-Change-Id: I30c38fdeb0b88bb39bdb9928851300bc79e6aec6
Gerrit-PatchSet: 2
Gerrit-Project: openbsc
Gerrit-Branch: master
Gerrit-Owner: Max <msuraev at sysmocom.de>
Gerrit-Reviewer: Harald Welte <laforge at gnumonks.org>
Gerrit-Reviewer: Jenkins Builder



More information about the gerrit-log mailing list