<p>laforge <strong>submitted</strong> this change.</p><p><a href="https://gerrit.osmocom.org/c/osmo-sgsn/+/21456">View Change</a></p><div style="white-space:pre-wrap">Approvals:
  Jenkins Builder: Verified
  laforge: Looks good to me, approved

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

<div style="display:none"> Gerrit-Project: osmo-sgsn </div>
<div style="display:none"> Gerrit-Branch: master </div>
<div style="display:none"> Gerrit-Change-Id: If445f18bc8390c338b5aeb9085951ea392e68b3a </div>
<div style="display:none"> Gerrit-Change-Number: 21456 </div>
<div style="display:none"> Gerrit-PatchSet: 4 </div>
<div style="display:none"> Gerrit-Owner: daniel <dwillmann@sysmocom.de> </div>
<div style="display:none"> Gerrit-Reviewer: Jenkins Builder </div>
<div style="display:none"> Gerrit-Reviewer: laforge <laforge@osmocom.org> </div>
<div style="display:none"> Gerrit-CC: pespin <pespin@sysmocom.de> </div>
<div style="display:none"> Gerrit-MessageType: merged </div>