From 6e8ed2784eb8223771f38b2b96e451747a3d70e4 Mon Sep 17 00:00:00 2001 From: Daniel Willmann Date: Wed, 2 Dec 2020 13:54:21 +0100 Subject: gbproxy: Use LOG macros for NSE/BVC Change-Id: If445f18bc8390c338b5aeb9085951ea392e68b3a Related: SYS#5233 --- src/gbproxy/gb_proxy.c | 103 ++++++++++++++++++++----------------------- src/gbproxy/gb_proxy_patch.c | 22 +++++---- src/gbproxy/gb_proxy_tlli.c | 38 +++++++++------- 3 files changed, 86 insertions(+), 77 deletions(-) (limited to 'src') diff --git a/src/gbproxy/gb_proxy.c b/src/gbproxy/gb_proxy.c index 997085bbe..1602207b0 100644 --- a/src/gbproxy/gb_proxy.c +++ b/src/gbproxy/gb_proxy.c @@ -84,12 +84,12 @@ static void gbproxy_reset_imsi_acquisition(struct gbproxy_link_info* link_info); static int check_peer_nsei(struct gbproxy_peer *peer, uint16_t nsei) { + OSMO_ASSERT(peer); OSMO_ASSERT(peer->nse); if (peer->nse->nsei != nsei) { - LOGP(DGPRS, LOGL_NOTICE, "Peer entry doesn't match current NSEI " - "BVCI=%u via NSEI=%u (expected NSEI=%u)\n", - peer->bvci, nsei, peer->nse->nsei); + LOGPBVC(peer, LOGL_NOTICE, "Peer entry doesn't match current NSEI " + "via NSE(%05u/BSS)\n", nsei); rate_ctr_inc(&peer->ctrg->ctr[GBPROX_PEER_CTR_INV_NSEI]); return 0; } @@ -224,7 +224,7 @@ static void gbprox_update_current_raid(uint8_t *raid_enc, } if (osmo_plmn_cmp(&old_plmn, &state->local_plmn)) - LOGP(DGPRS, LOGL_NOTICE, + LOGPBVC(peer, LOGL_NOTICE, "Patching RAID %sactivated, msg: %s, " "local: %s, core: %s\n", state->local_plmn.mcc || state->local_plmn.mnc ? @@ -257,7 +257,7 @@ uint32_t gbproxy_make_bss_ptmsi(struct gbproxy_peer *peer, } if (bss_ptmsi == GSM_RESERVED_TMSI) - LOGP(DGPRS, LOGL_ERROR, "Failed to allocate a BSS P-TMSI: %d (%s)\n", rc, strerror(-rc)); + LOGPBVC(peer, LOGL_ERROR, "Failed to allocate a BSS P-TMSI: %d (%s)\n", rc, strerror(-rc)); return bss_ptmsi; } @@ -295,7 +295,7 @@ uint32_t gbproxy_make_sgsn_tlli(struct gbproxy_peer *peer, } if (!sgsn_tlli) - LOGP(DGPRS, LOGL_ERROR, "Failed to allocate an SGSN TLLI: %d (%s)\n", rc, strerror(-rc)); + LOGPBVC(peer, LOGL_ERROR, "Failed to allocate an SGSN TLLI: %d (%s)\n", rc, strerror(-rc)); return sgsn_tlli; } @@ -335,6 +335,7 @@ static int gbproxy_flush_stored_messages(struct gbproxy_peer *peer, { int rc; struct msgb *stored_msg; + OSMO_ASSERT(peer); OSMO_ASSERT(peer->nse); struct gbproxy_config *cfg = peer->nse->cfg; OSMO_ASSERT(cfg); @@ -358,7 +359,7 @@ static int gbproxy_flush_stored_messages(struct gbproxy_peer *peer, rc = gbproxy_update_link_state_after(peer, link_info, now, &tmp_parse_ctx); if (rc == 1) { - LOGP(DLLC, LOGL_NOTICE, "link_info deleted while flushing stored messages\n"); + LOGPBVC_CAT(peer, DLLC, LOGL_NOTICE, "link_info deleted while flushing stored messages\n"); msgb_free(stored_msg); return -1; } @@ -367,10 +368,9 @@ static int gbproxy_flush_stored_messages(struct gbproxy_peer *peer, msgb_bvci(stored_msg), link_info->sgsn_nsei); if (rc < 0) - LOGP(DLLC, LOGL_ERROR, - "NSEI=%d(BSS) failed to send stored message " + LOGPBVC_CAT(peer, DLLC, LOGL_ERROR, + "failed to send stored message " "(%s)\n", - tmp_parse_ctx.peer_nsei, tmp_parse_ctx.llc_msg_name ? tmp_parse_ctx.llc_msg_name : "BSSGP"); msgb_free(stored_msg); @@ -433,6 +433,7 @@ static int gbproxy_imsi_acquisition(struct gbproxy_peer *peer, struct gprs_gb_parse_context *parse_ctx) { struct msgb *stored_msg; + OSMO_ASSERT(peer); OSMO_ASSERT(peer->nse); struct gbproxy_config *cfg = peer->nse->cfg; OSMO_ASSERT(cfg); @@ -449,25 +450,23 @@ static int gbproxy_imsi_acquisition(struct gbproxy_peer *peer, case GSM48_MT_GMM_RA_UPD_REQ: case GSM48_MT_GMM_ATTACH_REQ: if (gbproxy_restart_imsi_acquisition(link_info)) { - LOGP(DLLC, LOGL_INFO, - "NSEI=%d(BSS) IMSI acquisition was in progress " + LOGPBVC_CAT(peer, DLLC, LOGL_INFO, + " IMSI acquisition was in progress " "when receiving an %s.\n", - msgb_nsei(msg), parse_ctx->llc_msg_name); + parse_ctx->llc_msg_name); } break; case GSM48_MT_GMM_DETACH_REQ: /* Nothing has been sent to the SGSN yet */ if (link_info->imsi_acq_pending) { - LOGP(DLLC, LOGL_INFO, - "NSEI=%d(BSS) IMSI acquisition was in progress " - "when receiving a DETACH_REQ.\n", - msgb_nsei(msg)); + LOGPBVC_CAT(peer, DLLC, LOGL_INFO, + "IMSI acquisition was in progress " + "when receiving a DETACH_REQ.\n"); } if (!parse_ctx->invalidate_tlli) { - LOGP(DLLC, LOGL_INFO, - "NSEI=%d(BSS) IMSI not yet acquired, " - "faking a DETACH_ACC.\n", - msgb_nsei(msg)); + LOGPBVC_CAT(peer, DLLC, LOGL_INFO, + "IMSI not yet acquired, " + "faking a DETACH_ACC.\n"); gbproxy_tx_detach_acc(peer, link_info, msgb_bvci(msg)); parse_ctx->invalidate_tlli = 1; } @@ -483,10 +482,9 @@ static int gbproxy_imsi_acquisition(struct gbproxy_peer *peer, gsm48_hdr_pdisc(parse_ctx->g48_hdr) == GSM48_PDISC_MM_GPRS && gsm48_hdr_msg_type(parse_ctx->g48_hdr) == GSM48_MT_GMM_ID_RESP; - LOGP(DLLC, LOGL_DEBUG, - "NSEI=%d(BSS) IMSI acquisition succeeded, " - "flushing stored messages\n", - msgb_nsei(msg)); + LOGPBVC_CAT(peer, DLLC, LOGL_DEBUG, + "IMSI acquisition succeeded, " + "flushing stored messages\n"); /* The IMSI is now available. If flushing the messages fails, * then link_info has been deleted and we should return * immediately. */ @@ -512,20 +510,19 @@ static int gbproxy_imsi_acquisition(struct gbproxy_peer *peer, struct msgb *msgb_drop; msgb_drop = msgb_dequeue_count(&link_info->stored_msgs, &link_info->stored_msgs_len); - LOGP(DLLC, LOGL_INFO, - "NSEI=%d(BSS) Dropping stored msgb from list " + LOGPBVC_CAT(peer, DLLC, LOGL_INFO, + "Dropping stored msgb from list " "(!acq imsi, length %d, max_len exceeded)\n", - msgb_nsei(msgb_drop), link_info->stored_msgs_len); + link_info->stored_msgs_len); msgb_free(msgb_drop); } } /* Enqueue unpatched messages */ - LOGP(DLLC, LOGL_INFO, - "NSEI=%d(BSS) IMSI acquisition in progress, " + LOGPBVC_CAT(peer, DLLC, LOGL_INFO, + "IMSI acquisition in progress, " "storing message (%s)\n", - msgb_nsei(msg), parse_ctx->llc_msg_name ? parse_ctx->llc_msg_name : "BSSGP"); stored_msg = bssgp_msgb_copy(msg, "process_bssgp_ul"); @@ -533,10 +530,9 @@ static int gbproxy_imsi_acquisition(struct gbproxy_peer *peer, &link_info->stored_msgs_len); if (!link_info->imsi_acq_pending) { - LOGP(DLLC, LOGL_INFO, - "NSEI=%d(BSS) IMSI is required but not available, " + LOGPBVC_CAT(peer, DLLC, LOGL_INFO, + "IMSI is required but not available, " "initiating identification procedure (%s)\n", - msgb_nsei(msg), parse_ctx->llc_msg_name ? parse_ctx->llc_msg_name : "BSSGP"); gbproxy_acquire_imsi(peer, link_info, msgb_bvci(msg)); @@ -986,9 +982,8 @@ static int gbprox_rx_ptp_from_sgsn(struct gbproxy_config *cfg, } if (peer->blocked) { - LOGP(DGPRS, LOGL_NOTICE, "Dropping PDU for " - "blocked BVCI=%u via NSEI=%u\n", - ns_bvci, nsei); + LOGPBVC(peer, LOGL_NOTICE, "Dropping PDU for " + "blocked BVC via NSE(%05u/SGSN)\n", nsei); rate_ctr_inc(&peer->ctrg->ctr[GBPROX_PEER_CTR_DROPPED]); return bssgp_tx_status(BSSGP_CAUSE_BVCI_BLOCKED, &ns_bvci, msg); } @@ -1059,9 +1054,9 @@ static int gbprox_rx_sig_from_bss(struct gbproxy_config *cfg, memcpy(from_peer->ra, TLVP_VAL(&tp, BSSGP_IE_ROUTEING_AREA), sizeof(from_peer->ra)); gsm48_parse_ra(&raid, from_peer->ra); - LOGP(DGPRS, LOGL_INFO, "NSEI=%u BSSGP SUSPEND/RESUME " - "RAI snooping: RAI %s behind BVCI=%u\n", - nsei, osmo_rai_name(&raid), from_peer->bvci); + LOGPBVC(from_peer, LOGL_INFO, "BSSGP SUSPEND/RESUME " + "RAI snooping: RAI %s\n", + osmo_rai_name(&raid)); /* FIXME: This only supports one BSS per RA */ break; case BSSGP_PDUT_BVC_RESET: @@ -1076,14 +1071,16 @@ static int gbprox_rx_sig_from_bss(struct gbproxy_config *cfg, struct gbproxy_nse *nse; /* Ensure the NSE peer is there and clear all PtP BVCs */ nse = gbproxy_nse_by_nsei_or_new(cfg, nsei); - if (!nse) + if (!nse) { LOGP(DGPRS, LOGL_ERROR, "Could not allocate NSE for NSEI=%u\n", nsei); + return bssgp_tx_status(BSSGP_CAUSE_PROTO_ERR_UNSPEC, 0, msg); + } gbproxy_cleanup_peers(cfg, nsei, 0); /* FIXME: only do this if SGSN is alive! */ - LOGP(DGPRS, LOGL_INFO, "NSEI=%u Tx fake " - "BVC RESET ACK of BVCI=0\n", nsei); + LOGPNSE(nse, LOGL_INFO, "Tx fake " + "BVC RESET ACK of BVCI=0\n"); return bssgp_tx_simple_bvci(BSSGP_PDUT_BVC_RESET_ACK, nsei, 0, ns_bvci); } @@ -1097,21 +1094,20 @@ static int gbprox_rx_sig_from_bss(struct gbproxy_config *cfg, } /* if a PTP-BVC is reset, and we don't know that * PTP-BVCI yet, we should allocate a new peer */ - LOGP(DGPRS, LOGL_INFO, "Allocationg new peer for BVCI=%u via NSEI=%u\n", bvci, nsei); from_peer = gbproxy_peer_alloc(nse, bvci); OSMO_ASSERT(from_peer); + LOGPBVC(from_peer, LOGL_INFO, "Allocated new peer\n"); } /* Could have moved to a different NSE */ if (!check_peer_nsei(from_peer, nsei)) { - struct gbproxy_nse *nse_old = from_peer->nse; struct gbproxy_nse *nse_new = gbproxy_nse_by_nsei(cfg, nsei); if (!nse_new) { LOGP(DGPRS, LOGL_NOTICE, "Got PtP BVC reset before signalling reset for " "BVCI=%u NSEI=%u\n", bvci, nsei); return bssgp_tx_status(BSSGP_CAUSE_PDU_INCOMP_STATE, NULL, msg); } - LOGP(DGPRS, LOGL_NOTICE, "Peer for BVCI=%u moved from NSEI=%u to NSEI=%u\n", bvci, nse_old->nsei, nsei); + LOGPBVC(from_peer, LOGL_NOTICE, "Peer moved to NSEI=%u\n", nsei); /* Move peer to different NSE */ gbproxy_peer_move(from_peer, nse_new); @@ -1127,8 +1123,8 @@ static int gbprox_rx_sig_from_bss(struct gbproxy_config *cfg, TLVP_VAL(&tp, BSSGP_IE_CELL_ID), sizeof(from_peer->ra)); gsm48_parse_ra(&raid, from_peer->ra); - LOGP(DGPRS, LOGL_INFO, "NSEI=%u/BVCI=%u Cell ID %s\n", - nsei, bvci, osmo_rai_name(&raid)); + LOGPBVC(from_peer, LOGL_INFO, "Cell ID %s\n", + osmo_rai_name(&raid)); } if (cfg->route_to_sgsn2) copy_to_sgsn2 = 1; @@ -1169,19 +1165,19 @@ static int gbprox_rx_paging(struct gbproxy_config *cfg, struct msgb *msg, struct /* FIXME: Handle paging logic to only page each matching NSE */ - LOGP(DGPRS, LOGL_INFO, "NSEI=%u(SGSN) BSSGP PAGING ", + LOGP(DGPRS, LOGL_INFO, "NSEI=%u(SGSN) BSSGP PAGING\n", nsei); if (TLVP_PRESENT(tp, BSSGP_IE_BVCI)) { uint16_t bvci = ntohs(tlvp_val16_unal(tp, BSSGP_IE_BVCI)); errctr = GBPROX_GLOB_CTR_OTHER_ERR; peer = gbproxy_peer_by_bvci(cfg, bvci); - LOGPC(DGPRS, LOGL_INFO, "routing by BVCI to peer BVCI=%u\n", bvci); if (!peer) { LOGP(DGPRS, LOGL_NOTICE, "NSEI=%u(SGSN) BSSGP PAGING: " "unable to route: BVCI=%u unknown\n", nsei, bvci); rate_ctr_inc(&cfg->ctrg->ctr[errctr]); return -EINVAL; } + LOGPBVC(peer, LOGL_INFO, "routing by BVCI\n"); return gbprox_relay2peer(msg, peer, ns_bvci); } else if (TLVP_PRESENT(tp, BSSGP_IE_ROUTEING_AREA)) { errctr = GBPROX_GLOB_CTR_INV_RAI; @@ -1189,7 +1185,7 @@ static int gbprox_rx_paging(struct gbproxy_config *cfg, struct msgb *msg, struct llist_for_each_entry(nse, &cfg->nse_peers, list) { llist_for_each_entry(peer, &nse->bts_peers, list) { if (!memcmp(peer->ra, TLVP_VAL(tp, BSSGP_IE_ROUTEING_AREA), 6)) { - LOGPC(DGPRS, LOGL_INFO, "routing by RAI to peer NSEI=%u\n", peer->bvci); + LOGPNSE(nse, LOGL_INFO, "routing to NSE (RAI match)"); gbprox_relay2nse(msg, nse, ns_bvci); n_nses++; /* Only send it once to each NSE */ @@ -1203,7 +1199,7 @@ static int gbprox_rx_paging(struct gbproxy_config *cfg, struct msgb *msg, struct llist_for_each_entry(nse, &cfg->nse_peers, list) { llist_for_each_entry(peer, &nse->bts_peers, list) { if (!memcmp(peer->ra, TLVP_VAL(tp, BSSGP_IE_LOCATION_AREA), 5)) { - LOGPC(DGPRS, LOGL_INFO, "routing by LAI to peer BVCI=%u\n", peer->bvci); + LOGPNSE(nse, LOGL_INFO, "routing to NSE (LAI match)\n"); gbprox_relay2nse(msg, nse, ns_bvci); n_nses++; /* Only send it once to each NSE */ @@ -1215,7 +1211,7 @@ static int gbprox_rx_paging(struct gbproxy_config *cfg, struct msgb *msg, struct /* iterate over all peers and dispatch the paging to each matching one */ llist_for_each_entry(nse, &cfg->nse_peers, list) { llist_for_each_entry(peer, &nse->bts_peers, list) { - LOGPC(DGPRS, LOGL_INFO, "broadcasting to peer BVCI=%u\n", peer->bvci); + LOGPNSE(nse, LOGL_INFO, "routing to NSE (broadcast)\n"); gbprox_relay2nse(msg, nse, ns_bvci); n_nses++; /* Only send it once to each NSE */ @@ -1223,7 +1219,6 @@ static int gbprox_rx_paging(struct gbproxy_config *cfg, struct msgb *msg, struct } } } else { - LOGPC(DGPRS, LOGL_INFO, "\n"); LOGP(DGPRS, LOGL_ERROR, "NSEI=%u(SGSN) BSSGP PAGING: " "unable to route, missing IE\n", nsei); rate_ctr_inc(&cfg->ctrg->ctr[errctr]); diff --git a/src/gbproxy/gb_proxy_patch.c b/src/gbproxy/gb_proxy_patch.c index 660165796..59157221f 100644 --- a/src/gbproxy/gb_proxy_patch.c +++ b/src/gbproxy/gb_proxy_patch.c @@ -36,6 +36,7 @@ extern void *tall_sgsn_ctx; static void gbproxy_patch_raid(struct gsm48_ra_id *raid_enc, struct gbproxy_peer *peer, int to_bss, const char *log_text) { + OSMO_ASSERT(peer); struct gbproxy_patch_state *state = &peer->patch_state; struct osmo_plmn_id old_plmn; struct gprs_ra_id raid; @@ -79,7 +80,7 @@ static void gbproxy_patch_raid(struct gsm48_ra_id *raid_enc, struct gbproxy_peer } } - LOGP(DGPRS, LOGL_DEBUG, + LOGPBVC(peer, LOGL_DEBUG, "Patching %s to %s: " "%s-%d-%d -> %s\n", log_text, @@ -104,6 +105,7 @@ static void gbproxy_patch_apn_ie(struct msgb *msg, size_t apn_len = hdr->apn_len; uint8_t *apn = hdr->apn; + OSMO_ASSERT(peer); OSMO_ASSERT(peer->nse); struct gbproxy_config *cfg = peer->nse->cfg; OSMO_ASSERT(cfg); @@ -114,7 +116,7 @@ static void gbproxy_patch_apn_ie(struct msgb *msg, if (cfg->core_apn_size == 0) { char str1[110]; /* Remove the IE */ - LOGP(DGPRS, LOGL_DEBUG, + LOGPBVC(peer, LOGL_DEBUG, "Patching %s to SGSN: Removing APN '%s'\n", log_text, osmo_apn_to_str(str1, apn, apn_len)); @@ -128,7 +130,7 @@ static void gbproxy_patch_apn_ie(struct msgb *msg, OSMO_ASSERT(cfg->core_apn_size <= 100); - LOGP(DGPRS, LOGL_DEBUG, + LOGPBVC(peer, LOGL_DEBUG, "Patching %s to SGSN: " "Replacing APN '%s' -> '%s'\n", log_text, @@ -156,6 +158,7 @@ static int gbproxy_patch_tlli(uint8_t *tlli_enc, to_bss ? GBPROX_PEER_CTR_TLLI_PATCHED_SGSN : GBPROX_PEER_CTR_TLLI_PATCHED_BSS; + OSMO_ASSERT(peer); memcpy(&tlli_be, tlli_enc, sizeof(tlli_be)); tlli = ntohl(tlli_be); @@ -163,7 +166,7 @@ static int gbproxy_patch_tlli(uint8_t *tlli_enc, if (tlli == new_tlli) return 0; - LOGP(DGPRS, LOGL_DEBUG, + LOGPBVC(peer, LOGL_DEBUG, "Patching %ss: " "Replacing %08x -> %08x\n", log_text, tlli, new_tlli); @@ -187,13 +190,15 @@ static int gbproxy_patch_ptmsi(uint8_t *ptmsi_enc, to_bss ? GBPROX_PEER_CTR_PTMSI_PATCHED_SGSN : GBPROX_PEER_CTR_PTMSI_PATCHED_BSS; + OSMO_ASSERT(peer); + memcpy(&ptmsi_be, ptmsi_enc, sizeof(ptmsi_be)); ptmsi = ntohl(ptmsi_be); if (ptmsi == new_ptmsi) return 0; - LOGP(DGPRS, LOGL_DEBUG, + LOGPBVC(peer, LOGL_DEBUG, "Patching %ss: " "Replacing %08x -> %08x\n", log_text, ptmsi, new_ptmsi); @@ -214,6 +219,7 @@ int gbproxy_patch_llc(struct msgb *msg, uint8_t *llc, size_t llc_len, struct gprs_llc_hdr_parsed *ghp = &parse_ctx->llc_hdr_parsed; int have_patched = 0; int fcs; + OSMO_ASSERT(peer); OSMO_ASSERT(peer->nse); struct gbproxy_config *cfg = peer->nse->cfg; OSMO_ASSERT(cfg); @@ -281,7 +287,7 @@ int gbproxy_patch_llc(struct msgb *msg, uint8_t *llc, size_t llc_len, /* Fix FCS */ fcs = gprs_llc_fcs(llc, ghp->crc_length); - LOGP(DLLC, LOGL_DEBUG, "Updated LLC message, CRC: %06x -> %06x\n", + LOGPBVC_CAT(peer, DLLC, LOGL_DEBUG, "Updated LLC message, CRC: %06x -> %06x\n", ghp->fcs, fcs); llc[llc_len - 3] = fcs & 0xff; @@ -401,8 +407,8 @@ void gbproxy_patch_bssgp(struct msgb *msg, uint8_t *bssgp, size_t bssgp_len, patch_error: OSMO_ASSERT(err_ctr >= 0); rate_ctr_inc(&peer->ctrg->ctr[err_ctr]); - LOGP(DGPRS, LOGL_ERROR, - "NSEI=%u(%s) failed to patch BSSGP message as requested: %s.\n", + LOGPBVC(peer, LOGL_ERROR, + "NSE(%05u/%s) failed to patch BSSGP message as requested: %s.\n", msgb_nsei(msg), parse_ctx->to_bss ? "SGSN" : "BSS", err_info); } diff --git a/src/gbproxy/gb_proxy_tlli.c b/src/gbproxy/gb_proxy_tlli.c index 948745943..b84d1ea4e 100644 --- a/src/gbproxy/gb_proxy_tlli.c +++ b/src/gbproxy/gb_proxy_tlli.c @@ -179,6 +179,7 @@ void gbproxy_attach_link_info(struct gbproxy_peer *peer, time_t now, int gbproxy_remove_stale_link_infos(struct gbproxy_peer *peer, time_t now) { + OSMO_ASSERT(peer); struct gbproxy_patch_state *state = &peer->patch_state; int exceeded_max_len = 0; int deleted_count = 0; @@ -199,7 +200,7 @@ int gbproxy_remove_stale_link_infos(struct gbproxy_peer *peer, time_t now) link_info = llist_entry(state->logical_links.prev, struct gbproxy_link_info, list); - LOGP(DGPRS, LOGL_INFO, + LOGPBVC(peer, LOGL_INFO, "Removing TLLI %08x from list " "(stale, length %d, max_len exceeded)\n", link_info->tlli.current, state->logical_link_count); @@ -221,7 +222,7 @@ int gbproxy_remove_stale_link_infos(struct gbproxy_peer *peer, time_t now) continue; } - LOGP(DGPRS, LOGL_INFO, + LOGPBVC(peer, LOGL_INFO, "Removing TLLI %08x from list " "(stale, age %d, max_age exceeded)\n", link_info->tlli.current, (int)age); @@ -278,10 +279,11 @@ void gbproxy_update_link_info(struct gbproxy_link_info *link_info, void gbproxy_reassign_tlli(struct gbproxy_tlli_state *tlli_state, struct gbproxy_peer *peer, uint32_t new_tlli) { + OSMO_ASSERT(peer); if (new_tlli == tlli_state->current) return; - LOGP(DGPRS, LOGL_INFO, + LOGPBVC(peer, LOGL_INFO, "The TLLI has been reassigned from %08x to %08x\n", tlli_state->current, new_tlli); @@ -354,11 +356,12 @@ static void gbproxy_touch_link_info(struct gbproxy_peer *peer, static int gbproxy_unregister_link_info(struct gbproxy_peer *peer, struct gbproxy_link_info *link_info) { + OSMO_ASSERT(peer); if (!link_info) return 1; if (link_info->tlli.ptmsi == GSM_RESERVED_TMSI && !link_info->imsi_len) { - LOGP(DGPRS, LOGL_INFO, + LOGPBVC(peer, LOGL_INFO, "Removing TLLI %08x from list (P-TMSI or IMSI are not set)\n", link_info->tlli.current); gbproxy_delete_link_info(peer, link_info); @@ -398,6 +401,7 @@ static void gbproxy_assign_imsi(struct gbproxy_peer *peer, int imsi_matches; struct gbproxy_link_info *other_link_info; enum gbproxy_match_id match_id; + OSMO_ASSERT(peer); OSMO_ASSERT(peer->nse); struct gbproxy_config *cfg = peer->nse->cfg; OSMO_ASSERT(cfg); @@ -410,9 +414,9 @@ static void gbproxy_assign_imsi(struct gbproxy_peer *peer, struct osmo_mobile_identity mi; if (osmo_mobile_identity_decode(&mi, parse_ctx->imsi, parse_ctx->imsi_len, false) || mi.type != GSM_MI_TYPE_IMSI) { - LOGP(DGPRS, LOGL_ERROR, "Failed to decode Mobile Identity\n"); + LOGPBVC(peer, LOGL_ERROR, "Failed to decode Mobile Identity\n"); } else { - LOGP(DGPRS, LOGL_INFO, + LOGPBVC(peer, LOGL_INFO, "Removing TLLI %08x from list (IMSI %s re-used)\n", other_link_info->tlli.current, mi.imsi); gbproxy_delete_link_info(peer, other_link_info); @@ -454,6 +458,7 @@ static int gbproxy_tlli_match(const struct gbproxy_tlli_state *a, static void gbproxy_remove_matching_link_infos( struct gbproxy_peer *peer, struct gbproxy_link_info *link_info) { + OSMO_ASSERT(peer); struct gbproxy_link_info *info, *nxt; struct gbproxy_patch_state *state = &peer->patch_state; @@ -467,7 +472,7 @@ static void gbproxy_remove_matching_link_infos( !gbproxy_tlli_match(&link_info->sgsn_tlli, &info->sgsn_tlli))) continue; - LOGP(DGPRS, LOGL_INFO, + LOGPBVC(peer, LOGL_INFO, "Removing TLLI %08x from list (P-TMSI/TLLI re-used)\n", info->tlli.current); gbproxy_delete_link_info(peer, info); @@ -518,6 +523,7 @@ struct gbproxy_link_info *gbproxy_update_link_state_ul( { struct gbproxy_link_info *link_info; int tlli_is_valid; + OSMO_ASSERT(peer); link_info = gbproxy_get_link_info_ul(peer, &tlli_is_valid, parse_ctx); @@ -525,7 +531,7 @@ struct gbproxy_link_info *gbproxy_update_link_state_ul( uint32_t sgsn_tlli; if (!link_info) { - LOGP(DGPRS, LOGL_INFO, "Adding TLLI %08x to list\n", + LOGPBVC(peer, LOGL_INFO, "Adding TLLI %08x to list\n", parse_ctx->tlli); link_info = gbproxy_link_info_alloc(peer); gbproxy_attach_link_info(peer, now, link_info); @@ -596,6 +602,7 @@ struct gbproxy_link_info *gbproxy_update_link_state_dl( struct gprs_gb_parse_context *parse_ctx) { struct gbproxy_link_info *link_info = NULL; + OSMO_ASSERT(peer); OSMO_ASSERT(peer->nse); struct gbproxy_config *cfg = peer->nse->cfg; OSMO_ASSERT(cfg); @@ -615,7 +622,7 @@ struct gbproxy_link_info *gbproxy_update_link_state_dl( if (new_bss_ptmsi == GSM_RESERVED_TMSI) new_bss_ptmsi = gbproxy_make_bss_ptmsi(peer, new_sgsn_ptmsi); - LOGP(DGPRS, LOGL_INFO, + LOGPBVC(peer, LOGL_INFO, "Got new PTMSI %08x from SGSN, using %08x for BSS\n", new_sgsn_ptmsi, new_bss_ptmsi); /* Setup PTMSIs */ @@ -629,7 +636,7 @@ struct gbproxy_link_info *gbproxy_update_link_state_dl( uint32_t new_ptmsi; gprs_parse_tmsi(parse_ctx->new_ptmsi_enc, &new_ptmsi); - LOGP(DGPRS, LOGL_INFO, + LOGPBVC(peer, LOGL_INFO, "Adding TLLI %08x to list (SGSN, new P-TMSI is %08x)\n", parse_ctx->tlli, new_ptmsi); @@ -644,7 +651,7 @@ struct gbproxy_link_info *gbproxy_update_link_state_dl( /* Unknown SGSN TLLI, create a new link_info */ uint32_t new_ptmsi; link_info = gbproxy_link_info_alloc(peer); - LOGP(DGPRS, LOGL_INFO, "Adding TLLI %08x to list (SGSN)\n", + LOGPBVC(peer, LOGL_INFO, "Adding TLLI %08x to list (SGSN)\n", parse_ctx->tlli); gbproxy_attach_link_info(peer, now, link_info); @@ -658,7 +665,7 @@ struct gbproxy_link_info *gbproxy_update_link_state_dl( /* A new P-TMSI has been signalled in the message */ gprs_parse_tmsi(parse_ctx->new_ptmsi_enc, &new_ptmsi); - LOGP(DGPRS, LOGL_INFO, + LOGPBVC(peer, LOGL_INFO, "Assigning new P-TMSI %08x\n", new_ptmsi); /* Setup P-TMSIs */ link_info->sgsn_tlli.ptmsi = new_ptmsi; @@ -686,6 +693,7 @@ int gbproxy_update_link_state_after( struct gprs_gb_parse_context *parse_ctx) { int rc = 0; + OSMO_ASSERT(peer); OSMO_ASSERT(peer->nse); struct gbproxy_config *cfg = peer->nse->cfg; OSMO_ASSERT(cfg); @@ -698,11 +706,11 @@ int gbproxy_update_link_state_after( (cfg->keep_link_infos == GBPROX_KEEP_IDENTIFIED && link_info->imsi_len > 0); if (keep_info) { - LOGP(DGPRS, LOGL_INFO, "Unregistering TLLI %08x\n", + LOGPBVC(peer, LOGL_INFO, "Unregistering TLLI %08x\n", link_info->tlli.current); rc = gbproxy_unregister_link_info(peer, link_info); } else { - LOGP(DGPRS, LOGL_INFO, "Removing TLLI %08x from list\n", + LOGPBVC(peer, LOGL_INFO, "Removing TLLI %08x from list\n", link_info->tlli.current); gbproxy_delete_link_info(peer, link_info); rc = 1; @@ -719,7 +727,7 @@ int gbproxy_update_link_state_after( new_sgsn_tlli = gprs_tmsi2tlli(new_sgsn_ptmsi, TLLI_LOCAL); if (new_bss_ptmsi != GSM_RESERVED_TMSI) new_bss_tlli = gprs_tmsi2tlli(new_bss_ptmsi, TLLI_LOCAL); - LOGP(DGPRS, LOGL_INFO, + LOGPBVC(peer, LOGL_INFO, "Assigning new TLLI %08x to SGSN, %08x to BSS\n", new_sgsn_tlli, new_bss_tlli); -- cgit v1.2.3