diff --git a/zebra/redistribute.c b/zebra/redistribute.c index 11c1330398..2de0917a7e 100644 --- a/zebra/redistribute.c +++ b/zebra/redistribute.c @@ -290,6 +290,7 @@ void redistribute_delete(const struct route_node *rn, if (IS_ZEBRA_DEBUG_RIB) { uint8_t old_inst, new_inst; uint32_t table = 0; + struct vrf *vrf = vrf_lookup_by_id(vrfid); old_inst = new_inst = 0; @@ -302,8 +303,8 @@ void redistribute_delete(const struct route_node *rn, table = new_re->table; } - zlog_debug("(%u:%u):%pRN: Redist del: re %p (%u:%s), new re %p (%u:%s)", - vrfid, table, rn, old_re, old_inst, + zlog_debug("(%s:%u):%pRN: Redist del: re %p (%u:%s), new re %p (%u:%s)", + VRF_LOGNAME(vrf), table, rn, old_re, old_inst, old_re ? zebra_route_string(old_re->type) : "None", new_re, new_inst, new_re ? zebra_route_string(new_re->type) : "None"); diff --git a/zebra/zapi_msg.c b/zebra/zapi_msg.c index aecbba2ebc..c45c61a208 100644 --- a/zebra/zapi_msg.c +++ b/zebra/zapi_msg.c @@ -735,11 +735,13 @@ static int route_notify_internal(const struct route_node *rn, int type, client = zserv_find_client(type, instance); if (!client || !client->notify_owner) { - if (IS_ZEBRA_DEBUG_PACKET) - zlog_debug( - "Not Notifying Owner: %s about prefix %pRN(%u) %d vrf: %u", - zebra_route_string(type), rn, table_id, note, - vrf_id); + if (IS_ZEBRA_DEBUG_PACKET) { + struct vrf *vrf = vrf_lookup_by_id(vrf_id); + + zlog_debug("Not Notifying Owner: %s about prefix %pRN(%u) %d vrf: %s", + zebra_route_string(type), rn, table_id, note, + VRF_LOGNAME(vrf)); + } return 0; } @@ -2129,8 +2131,8 @@ static void zread_route_add(ZAPI_HANDLER_ARGS) vrf_id = zvrf_id(zvrf); if (IS_ZEBRA_DEBUG_RECV) - zlog_debug("%s: p=(%u:%u)%pFX, msg flags=0x%x, flags=0x%x", - __func__, vrf_id, api.tableid, &api.prefix, + zlog_debug("%s: p=(%s:%u)%pFX, msg flags=0x%x, flags=0x%x", + __func__, zvrf_name(zvrf), api.tableid, &api.prefix, (int)api.message, api.flags); /* Allocate new route. */ diff --git a/zebra/zebra_rib.c b/zebra/zebra_rib.c index 8bec32b85d..402a3104b9 100644 --- a/zebra/zebra_rib.c +++ b/zebra/zebra_rib.c @@ -316,12 +316,18 @@ static ssize_t printfrr_zebra_node(struct fbuf *buf, struct printfrr_eargs *ea, } #define rnode_debug(node, vrf_id, msg, ...) \ - zlog_debug("%s: (%u:%pZNt):%pZN: " msg, __func__, vrf_id, node, node, \ - ##__VA_ARGS__) + do { \ + struct vrf *vrf = vrf_lookup_by_id(vrf_id); \ + zlog_debug("%s: (%s:%pZNt):%pZN: " msg, __func__, \ + VRF_LOGNAME(vrf), node, node, ##__VA_ARGS__); \ + } while (0) #define rnode_info(node, vrf_id, msg, ...) \ - zlog_info("%s: (%u:%pZNt):%pZN: " msg, __func__, vrf_id, node, node, \ - ##__VA_ARGS__) + do { \ + struct vrf *vrf = vrf_lookup_by_id(vrf_id); \ + zlog_info("%s: (%s:%pZNt):%pZN: " msg, __func__, \ + VRF_LOGNAME(vrf), node, node, ##__VA_ARGS__); \ + } while (0) static char *_dump_re_status(const struct route_entry *re, char *buf, size_t len) @@ -4113,7 +4119,7 @@ void rib_delnode(struct route_node *rn, struct route_entry *re) * Helper that debugs a single nexthop within a route-entry */ static void _route_entry_dump_nh(const struct route_entry *re, - const char *straddr, + const char *straddr, const struct vrf *re_vrf, const struct nexthop *nexthop) { char nhname[PREFIX_STRLEN]; @@ -4168,35 +4174,32 @@ static void _route_entry_dump_nh(const struct route_entry *re, if (nexthop->weight) snprintf(wgt_str, sizeof(wgt_str), "wgt %d,", nexthop->weight); - zlog_debug("%s: %s %s[%u] %svrf %s(%u) %s%s with flags %s%s%s%s%s%s%s%s%s", - straddr, (nexthop->rparent ? " NH" : "NH"), nhname, - nexthop->ifindex, label_str, vrf ? vrf->name : "Unknown", - nexthop->vrf_id, + zlog_debug("%s(%s): %s %s[%u] %svrf %s(%u) %s%s with flags %s%s%s%s%s%s%s%s%s", + straddr, VRF_LOGNAME(re_vrf), + (nexthop->rparent ? " NH" : "NH"), nhname, nexthop->ifindex, + label_str, vrf ? vrf->name : "Unknown", nexthop->vrf_id, wgt_str, backup_str, - (CHECK_FLAG(nexthop->flags, NEXTHOP_FLAG_ACTIVE) - ? "ACTIVE " - : ""), - (CHECK_FLAG(re->status, ROUTE_ENTRY_INSTALLED) - ? "FIB " - : ""), + (CHECK_FLAG(nexthop->flags, NEXTHOP_FLAG_ACTIVE) ? "ACTIVE " + : ""), + (CHECK_FLAG(re->status, ROUTE_ENTRY_INSTALLED) ? "FIB " : ""), (CHECK_FLAG(nexthop->flags, NEXTHOP_FLAG_RECURSIVE) - ? "RECURSIVE " - : ""), - (CHECK_FLAG(nexthop->flags, NEXTHOP_FLAG_ONLINK) - ? "ONLINK " - : ""), + ? "RECURSIVE " + : ""), + (CHECK_FLAG(nexthop->flags, NEXTHOP_FLAG_ONLINK) ? "ONLINK " + : ""), (CHECK_FLAG(nexthop->flags, NEXTHOP_FLAG_DUPLICATE) - ? "DUPLICATE " - : ""), + ? "DUPLICATE " + : ""), (CHECK_FLAG(nexthop->flags, NEXTHOP_FLAG_RNH_FILTERED) - ? "FILTERED " : ""), + ? "FILTERED " + : ""), (CHECK_FLAG(nexthop->flags, NEXTHOP_FLAG_HAS_BACKUP) - ? "BACKUP " : ""), - (CHECK_FLAG(nexthop->flags, NEXTHOP_FLAG_SRTE) - ? "SRTE " : ""), - (CHECK_FLAG(nexthop->flags, NEXTHOP_FLAG_EVPN) - ? "EVPN " : "")); - + ? "BACKUP " + : ""), + (CHECK_FLAG(nexthop->flags, NEXTHOP_FLAG_SRTE) ? "SRTE " + : ""), + (CHECK_FLAG(nexthop->flags, NEXTHOP_FLAG_EVPN) ? "EVPN " + : "")); } /* This function dumps the contents of a given RE entry into @@ -4225,32 +4228,33 @@ void _route_entry_dump(const char *func, union prefixconstptr pp, is_srcdst ? prefix2str(src_pp, srcaddr, sizeof(srcaddr)) : "", VRF_LOGNAME(vrf), re->vrf_id); - zlog_debug("%s: uptime == %lu, type == %u, instance == %d, table == %d", - straddr, (unsigned long)re->uptime, re->type, re->instance, - re->table); - zlog_debug( - "%s: metric == %u, mtu == %u, distance == %u, flags == %sstatus == %s", - straddr, re->metric, re->mtu, re->distance, - zclient_dump_route_flags(re->flags, flags_buf, - sizeof(flags_buf)), - _dump_re_status(re, status_buf, sizeof(status_buf))); - zlog_debug("%s: tag == %u, nexthop_num == %u, nexthop_active_num == %u", - straddr, re->tag, nexthop_group_nexthop_num(&(re->nhe->nhg)), + zlog_debug("%s(%s): uptime == %lu, type == %u, instance == %d, table == %d", + straddr, VRF_LOGNAME(vrf), (unsigned long)re->uptime, + re->type, re->instance, re->table); + zlog_debug("%s(%s): metric == %u, mtu == %u, distance == %u, flags == %sstatus == %s", + straddr, VRF_LOGNAME(vrf), re->metric, re->mtu, re->distance, + zclient_dump_route_flags(re->flags, flags_buf, + sizeof(flags_buf)), + _dump_re_status(re, status_buf, sizeof(status_buf))); + zlog_debug("%s(%s): tag == %u, nexthop_num == %u, nexthop_active_num == %u", + straddr, VRF_LOGNAME(vrf), re->tag, + nexthop_group_nexthop_num(&(re->nhe->nhg)), nexthop_group_active_nexthop_num(&(re->nhe->nhg))); /* Dump nexthops */ for (ALL_NEXTHOPS(re->nhe->nhg, nexthop)) - _route_entry_dump_nh(re, straddr, nexthop); + _route_entry_dump_nh(re, straddr, vrf, nexthop); if (zebra_nhg_get_backup_nhg(re->nhe)) { - zlog_debug("%s: backup nexthops:", straddr); + zlog_debug("%s(%s): backup nexthops:", straddr, + VRF_LOGNAME(vrf)); nhg = zebra_nhg_get_backup_nhg(re->nhe); for (ALL_NEXTHOPS_PTR(nhg, nexthop)) - _route_entry_dump_nh(re, straddr, nexthop); + _route_entry_dump_nh(re, straddr, vrf, nexthop); } - zlog_debug("%s: dump complete", straddr); + zlog_debug("%s(%s): dump complete", straddr, VRF_LOGNAME(vrf)); } static int rib_meta_queue_gr_run_add(struct meta_queue *mq, void *data) @@ -4271,11 +4275,14 @@ static int rib_meta_queue_early_route_add(struct meta_queue *mq, void *data) listnode_add(mq->subq[META_QUEUE_EARLY_ROUTE], data); mq->size++; - if (IS_ZEBRA_DEBUG_RIB_DETAILED) - zlog_debug("Route %pFX(%u) (%s) queued for processing into sub-queue %s", - &ere->p, ere->re->vrf_id, + if (IS_ZEBRA_DEBUG_RIB_DETAILED) { + struct vrf *vrf = vrf_lookup_by_id(ere->re->vrf_id); + + zlog_debug("Route %pFX(%s) (%s) queued for processing into sub-queue %s", + &ere->p, VRF_LOGNAME(vrf), ere->deletion ? "delete" : "add", subqueue2str(META_QUEUE_EARLY_ROUTE)); + } return 0; } diff --git a/zebra/zserv.c b/zebra/zserv.c index a731f7f278..07e3996643 100644 --- a/zebra/zserv.c +++ b/zebra/zserv.c @@ -161,9 +161,11 @@ void zserv_log_message(const char *errmsg, struct stream *msg, if (errmsg) zlog_debug("%s", errmsg); if (hdr) { + struct vrf *vrf = vrf_lookup_by_id(hdr->vrf_id); + zlog_debug(" Length: %d", hdr->length); zlog_debug("Command: %s", zserv_command_string(hdr->command)); - zlog_debug(" VRF: %u", hdr->vrf_id); + zlog_debug(" VRF: %s(%u)", VRF_LOGNAME(vrf), hdr->vrf_id); } stream_hexdump(msg); } @@ -425,11 +427,13 @@ static void zserv_read(struct event *thread) } /* Debug packet information. */ - if (IS_ZEBRA_DEBUG_PACKET) - zlog_debug("zebra message[%s:%u:%u] comes from socket [%d]", + if (IS_ZEBRA_DEBUG_PACKET) { + struct vrf *vrf = vrf_lookup_by_id(hdr.vrf_id); + + zlog_debug("zebra message[%s:%s:%u] comes from socket [%d]", zserv_command_string(hdr.command), - hdr.vrf_id, hdr.length, - sock); + VRF_LOGNAME(vrf), hdr.length, sock); + } stream_set_getp(client->ibuf_work, 0); struct stream *msg = stream_dup(client->ibuf_work);