Merge pull request #5988 from xThaid/zebra_vrf_logs

zebra: Add vrf name and id to debugs
This commit is contained in:
David Lamparter 2020-04-14 12:52:31 +02:00 committed by GitHub
commit feaabe472d
No known key found for this signature in database
GPG Key ID: 4AEE18F83AFDEB23
4 changed files with 243 additions and 171 deletions

View File

@ -324,10 +324,7 @@ const char *vrf_id_to_name(vrf_id_t vrf_id)
struct vrf *vrf;
vrf = vrf_lookup_by_id(vrf_id);
if (vrf)
return vrf->name;
return "n/a";
return VRF_LOGNAME(vrf);
}
vrf_id_t vrf_name_to_id(const char *name)

View File

@ -718,14 +718,15 @@ static int netlink_route_change_read_unicast(struct nlmsghdr *h, ns_id_t ns_id,
if (IS_ZEBRA_DEBUG_KERNEL) {
char buf[PREFIX_STRLEN];
char buf2[PREFIX_STRLEN];
zlog_debug("%s %s%s%s vrf %u(%u) metric: %d Admin Distance: %d",
zlog_debug(
"%s %s%s%s vrf %s(%u) table_id: %u metric: %d Admin Distance: %d",
nl_msg_type_to_str(h->nlmsg_type),
prefix2str(&p, buf, sizeof(buf)),
src_p.prefixlen ? " from " : "",
src_p.prefixlen
? prefix2str(&src_p, buf2, sizeof(buf2))
src_p.prefixlen ? prefix2str(&src_p, buf2, sizeof(buf2))
: "",
vrf_id, table, metric, distance);
vrf_id_to_name(vrf_id), vrf_id, table, metric,
distance);
}
afi_t afi = AFI_IP;
@ -911,9 +912,8 @@ static int netlink_route_change_read_multicast(struct nlmsghdr *h,
ifp = if_lookup_by_index(iif, vrf);
zlog_debug(
"MCAST VRF: %s(%d) %s (%s,%s) IIF: %s(%d) OIF: %s jiffies: %lld",
(zvrf ? zvrf->vrf->name : "Unknown"), vrf,
nl_msg_type_to_str(h->nlmsg_type), sbuf, gbuf,
ifp ? ifp->name : "Unknown", iif, oif_list,
zvrf_name(zvrf), vrf, nl_msg_type_to_str(h->nlmsg_type),
sbuf, gbuf, ifp ? ifp->name : "Unknown", iif, oif_list,
m->lastused);
}
return 0;
@ -1122,9 +1122,12 @@ static void _netlink_route_build_singlepath(const struct prefix *p,
mpls_lse_t out_lse[MPLS_MAX_LABELS];
char label_buf[256];
int num_labels = 0;
struct vrf *vrf;
assert(nexthop);
vrf = vrf_lookup_by_id(nexthop->vrf_id);
/*
* label_buf is *only* currently used within debugging.
* As such when we assign it we are guarding it inside
@ -1177,9 +1180,10 @@ static void _netlink_route_build_singlepath(const struct prefix *p,
if (IS_ZEBRA_DEBUG_KERNEL)
zlog_debug(
" 5549: _netlink_route_build_singlepath() (%s): %pFX nexthop via %s %s if %u(%u)",
" 5549: _netlink_route_build_singlepath() (%s): %pFX nexthop via %s %s if %u vrf %s(%u)",
routedesc, p, ipv4_ll_buf, label_buf,
nexthop->ifindex, nexthop->vrf_id);
nexthop->ifindex, VRF_LOGNAME(vrf),
nexthop->vrf_id);
return;
}
@ -1202,9 +1206,10 @@ static void _netlink_route_build_singlepath(const struct prefix *p,
if (IS_ZEBRA_DEBUG_KERNEL)
zlog_debug(
"netlink_route_multipath() (%s): %pFX nexthop via %s %s if %u(%u)",
"netlink_route_multipath() (%s): %pFX nexthop via %s %s if %u vrf %s(%u)",
routedesc, p, inet_ntoa(nexthop->gate.ipv4),
label_buf, nexthop->ifindex, nexthop->vrf_id);
label_buf, nexthop->ifindex, VRF_LOGNAME(vrf),
nexthop->vrf_id);
}
if (nexthop->type == NEXTHOP_TYPE_IPV6
@ -1224,9 +1229,10 @@ static void _netlink_route_build_singlepath(const struct prefix *p,
if (IS_ZEBRA_DEBUG_KERNEL)
zlog_debug(
"netlink_route_multipath() (%s): %pFX nexthop via %s %s if %u(%u)",
"netlink_route_multipath() (%s): %pFX nexthop via %s %s if %u vrf %s(%u)",
routedesc, p, inet6_ntoa(nexthop->gate.ipv6),
label_buf, nexthop->ifindex, nexthop->vrf_id);
label_buf, nexthop->ifindex, VRF_LOGNAME(vrf),
nexthop->vrf_id);
}
/*
@ -1249,9 +1255,9 @@ static void _netlink_route_build_singlepath(const struct prefix *p,
if (IS_ZEBRA_DEBUG_KERNEL)
zlog_debug(
"netlink_route_multipath() (%s): %pFX nexthop via if %u(%u)",
"netlink_route_multipath() (%s): %pFX nexthop via if %u vrf %s(%u)",
routedesc, p, nexthop->ifindex,
nexthop->vrf_id);
VRF_LOGNAME(vrf), nexthop->vrf_id);
}
}
@ -1280,6 +1286,7 @@ _netlink_route_build_multipath(const struct prefix *p, const char *routedesc,
mpls_lse_t out_lse[MPLS_MAX_LABELS];
char label_buf[256];
int num_labels = 0;
struct vrf *vrf;
rtnh->rtnh_len = sizeof(*rtnh);
rtnh->rtnh_flags = 0;
@ -1288,6 +1295,8 @@ _netlink_route_build_multipath(const struct prefix *p, const char *routedesc,
assert(nexthop);
vrf = vrf_lookup_by_id(nexthop->vrf_id);
/*
* label_buf is *only* currently used within debugging.
* As such when we assign it we are guarding it inside
@ -1347,9 +1356,10 @@ _netlink_route_build_multipath(const struct prefix *p, const char *routedesc,
if (IS_ZEBRA_DEBUG_KERNEL)
zlog_debug(
" 5549: netlink_route_build_multipath() (%s): %pFX nexthop via %s %s if %u",
" 5549: netlink_route_build_multipath() (%s): %pFX nexthop via %s %s if %u vrf %s(%u)",
routedesc, p, ipv4_ll_buf, label_buf,
nexthop->ifindex);
nexthop->ifindex, VRF_LOGNAME(vrf),
nexthop->vrf_id);
return;
}
@ -1365,9 +1375,10 @@ _netlink_route_build_multipath(const struct prefix *p, const char *routedesc,
if (IS_ZEBRA_DEBUG_KERNEL)
zlog_debug(
"netlink_route_multipath() (%s): %pFX nexthop via %s %s if %u",
"netlink_route_multipath() (%s): %pFX nexthop via %s %s if %u vrf %s(%u)",
routedesc, p, inet_ntoa(nexthop->gate.ipv4),
label_buf, nexthop->ifindex);
label_buf, nexthop->ifindex, VRF_LOGNAME(vrf),
nexthop->vrf_id);
}
if (nexthop->type == NEXTHOP_TYPE_IPV6
|| nexthop->type == NEXTHOP_TYPE_IPV6_IFINDEX) {
@ -1382,9 +1393,10 @@ _netlink_route_build_multipath(const struct prefix *p, const char *routedesc,
if (IS_ZEBRA_DEBUG_KERNEL)
zlog_debug(
"netlink_route_multipath() (%s): %pFX nexthop via %s %s if %u",
"netlink_route_multipath() (%s): %pFX nexthop via %s %s if %u vrf %s(%u)",
routedesc, p, inet6_ntoa(nexthop->gate.ipv6),
label_buf, nexthop->ifindex);
label_buf, nexthop->ifindex, VRF_LOGNAME(vrf),
nexthop->vrf_id);
}
/*
@ -1404,8 +1416,9 @@ _netlink_route_build_multipath(const struct prefix *p, const char *routedesc,
if (IS_ZEBRA_DEBUG_KERNEL)
zlog_debug(
"netlink_route_multipath() (%s): %pFX nexthop via if %u",
routedesc, p, nexthop->ifindex);
"netlink_route_multipath() (%s): %pFX nexthop via if %u vrf %s(%u)",
routedesc, p, nexthop->ifindex,
VRF_LOGNAME(vrf), nexthop->vrf_id);
}
if (nexthop->weight)
@ -1461,9 +1474,9 @@ static void _netlink_route_debug(int cmd, const struct prefix *p,
if (IS_ZEBRA_DEBUG_KERNEL) {
char buf[PREFIX_STRLEN];
zlog_debug(
"netlink_route_multipath(): %s %s vrf %u(%u)",
"netlink_route_multipath(): %s %s vrf %s(%u) table_id: %u",
nl_msg_type_to_str(cmd),
prefix2str(p, buf, sizeof(buf)),
prefix2str(p, buf, sizeof(buf)), vrf_id_to_name(vrfid),
vrfid, tableid);
}
}
@ -2077,10 +2090,10 @@ static int netlink_nexthop(int cmd, struct zebra_dplane_ctx *ctx)
nexthop_done:
if (IS_ZEBRA_DEBUG_KERNEL)
zlog_debug("%s: ID (%u): %pNHv (%u) %s ",
__func__, id, nh, nh->vrf_id,
label_buf);
zlog_debug("%s: ID (%u): %pNHv vrf %s(%u) %s ",
__func__, id, nh,
vrf_id_to_name(nh->vrf_id),
nh->vrf_id, label_buf);
}
req.nhm.nh_protocol = zebra2proto(dplane_ctx_get_nhe_type(ctx));
@ -2881,9 +2894,11 @@ static int netlink_request_specific_mac_in_bridge(struct zebra_ns *zns,
addattr32(&req.n, sizeof(req), NDA_MASTER, br_if->ifindex);
if (IS_ZEBRA_DEBUG_KERNEL)
zlog_debug("%s: Tx family %s IF %s(%u) MAC %s vid %u", __func__,
nl_family_to_str(req.ndm.ndm_family), br_if->name,
br_if->ifindex,
zlog_debug(
"%s: Tx family %s IF %s(%u) vrf %s(%u) MAC %s vid %u",
__func__, nl_family_to_str(req.ndm.ndm_family),
br_if->name, br_if->ifindex,
vrf_id_to_name(br_if->vrf_id), br_if->vrf_id,
prefix_mac2str(mac, buf, sizeof(buf)), vid);
return netlink_request(&zns->netlink_cmd, &req.n);
@ -3000,6 +3015,7 @@ static int netlink_ipneigh_change(struct nlmsghdr *h, int len, ns_id_t ns_id)
struct interface *link_if;
struct ethaddr mac;
struct ipaddr ip;
struct vrf *vrf;
char buf[ETHER_ADDR_STRLEN];
char buf2[INET6_ADDRSTRLEN];
int mac_present = 0;
@ -3014,6 +3030,7 @@ static int netlink_ipneigh_change(struct nlmsghdr *h, int len, ns_id_t ns_id)
if (!ifp || !ifp->info)
return 0;
vrf = vrf_lookup_by_id(ifp->vrf_id);
zif = (struct zebra_if *)ifp->info;
/* Parse attributes and extract fields of interest. */
@ -3021,10 +3038,10 @@ static int netlink_ipneigh_change(struct nlmsghdr *h, int len, ns_id_t ns_id)
netlink_parse_rtattr(tb, NDA_MAX, NDA_RTA(ndm), len);
if (!tb[NDA_DST]) {
zlog_debug("%s family %s IF %s(%u) - no DST",
zlog_debug("%s family %s IF %s(%u) vrf %s(%u) - no DST",
nl_msg_type_to_str(h->nlmsg_type),
nl_family_to_str(ndm->ndm_family), ifp->name,
ndm->ndm_ifindex);
ndm->ndm_ifindex, VRF_LOGNAME(vrf), ifp->vrf_id);
return 0;
}
@ -3076,12 +3093,13 @@ static int netlink_ipneigh_change(struct nlmsghdr *h, int len, ns_id_t ns_id)
if (RTA_PAYLOAD(tb[NDA_LLADDR]) != ETH_ALEN) {
if (IS_ZEBRA_DEBUG_KERNEL)
zlog_debug(
"%s family %s IF %s(%u) - LLADDR is not MAC, len %lu",
"%s family %s IF %s(%u) vrf %s(%u) - LLADDR is not MAC, len %lu",
nl_msg_type_to_str(
h->nlmsg_type),
nl_family_to_str(
ndm->ndm_family),
ifp->name, ndm->ndm_ifindex,
VRF_LOGNAME(vrf), ifp->vrf_id,
(unsigned long)RTA_PAYLOAD(
tb[NDA_LLADDR]));
return 0;
@ -3096,10 +3114,10 @@ static int netlink_ipneigh_change(struct nlmsghdr *h, int len, ns_id_t ns_id)
if (IS_ZEBRA_DEBUG_KERNEL)
zlog_debug(
"Rx %s family %s IF %s(%u) IP %s MAC %s state 0x%x flags 0x%x",
"Rx %s family %s IF %s(%u) vrf %s(%u) IP %s MAC %s state 0x%x flags 0x%x",
nl_msg_type_to_str(h->nlmsg_type),
nl_family_to_str(ndm->ndm_family), ifp->name,
ndm->ndm_ifindex,
ndm->ndm_ifindex, VRF_LOGNAME(vrf), ifp->vrf_id,
ipaddr2str(&ip, buf2, sizeof(buf2)),
mac_present
? prefix_mac2str(&mac, buf, sizeof(buf))
@ -3121,10 +3139,10 @@ static int netlink_ipneigh_change(struct nlmsghdr *h, int len, ns_id_t ns_id)
}
if (IS_ZEBRA_DEBUG_KERNEL)
zlog_debug("Rx %s family %s IF %s(%u) IP %s",
zlog_debug("Rx %s family %s IF %s(%u) vrf %s(%u) IP %s",
nl_msg_type_to_str(h->nlmsg_type),
nl_family_to_str(ndm->ndm_family), ifp->name,
ndm->ndm_ifindex,
ndm->ndm_ifindex, VRF_LOGNAME(vrf), ifp->vrf_id,
ipaddr2str(&ip, buf2, sizeof(buf2)));
/* Process the delete - it may result in re-adding the neighbor if it is
@ -3278,9 +3296,10 @@ int netlink_neigh_read_specific_ip(struct ipaddr *ip,
zebra_dplane_info_from_zns(&dp_info, zns, true /*is_cmd*/);
if (IS_ZEBRA_DEBUG_KERNEL)
zlog_debug("%s: neigh request IF %s(%u) IP %s vrf_id %u",
zlog_debug("%s: neigh request IF %s(%u) IP %s vrf %s(%u)",
__func__, vlan_if->name, vlan_if->ifindex,
ipaddr2str(ip, buf, sizeof(buf)), vlan_if->vrf_id);
ipaddr2str(ip, buf, sizeof(buf)),
vrf_id_to_name(vlan_if->vrf_id), vlan_if->vrf_id);
ret = netlink_request_specific_neigh_in_vlan(zns, RTM_GETNEIGH, ip,
vlan_if->ifindex);

View File

@ -348,8 +348,8 @@ struct route_entry *rib_match_ipv4_multicast(vrf_id_t vrf_id,
char buf[BUFSIZ];
inet_ntop(AF_INET, &addr, buf, BUFSIZ);
zlog_debug("%s: %s: vrf: %u found %s, using %s",
__func__, buf, vrf_id,
zlog_debug("%s: %s: vrf: %s(%u) found %s, using %s", __func__,
buf, vrf_id_to_name(vrf_id), vrf_id,
mre ? (ure ? "MRIB+URIB" : "MRIB")
: ure ? "URIB" : "nothing",
re == ure ? "URIB" : re == mre ? "MRIB" : "none");
@ -659,13 +659,14 @@ void zebra_rib_evaluate_rn_nexthops(struct route_node *rn, uint32_t seq)
char buf1[PREFIX_STRLEN];
char buf2[PREFIX_STRLEN];
zlog_debug("%u:%s has Nexthop(%s) Type: %s depending on it, evaluating %u:%u",
zvrf->vrf->vrf_id,
zlog_debug(
"%s(%u):%s has Nexthop(%s) Type: %s depending on it, evaluating %u:%u",
zvrf_name(zvrf), zvrf_id(zvrf),
srcdest_rnode2str(rn, buf1,
sizeof(buf1)),
prefix2str(p, buf2, sizeof(buf2)),
rnh_type2str(rnh->type),
seq, rnh->seqno);
rnh_type2str(rnh->type), seq,
rnh->seqno);
}
/*
@ -753,8 +754,8 @@ static void rib_process_add_fib(struct zebra_vrf *zvrf, struct route_node *rn,
if (IS_ZEBRA_DEBUG_RIB) {
char buf[SRCDEST2STR_BUFFER];
srcdest_rnode2str(rn, buf, sizeof(buf));
zlog_debug("%u:%s: Adding route rn %p, re %p (%s)",
zvrf_id(zvrf), buf, rn, new,
zlog_debug("%s(%u):%s: Adding route rn %p, re %p (%s)",
zvrf_name(zvrf), zvrf_id(zvrf), buf, rn, new,
zebra_route_string(new->type));
}
@ -776,8 +777,8 @@ static void rib_process_del_fib(struct zebra_vrf *zvrf, struct route_node *rn,
if (IS_ZEBRA_DEBUG_RIB) {
char buf[SRCDEST2STR_BUFFER];
srcdest_rnode2str(rn, buf, sizeof(buf));
zlog_debug("%u:%s: Deleting route rn %p, re %p (%s)",
zvrf_id(zvrf), buf, rn, old,
zlog_debug("%s(%u):%s: Deleting route rn %p, re %p (%s)",
zvrf_name(zvrf), zvrf_id(zvrf), buf, rn, old,
zebra_route_string(old->type));
}
@ -829,15 +830,17 @@ static void rib_process_update_fib(struct zebra_vrf *zvrf,
srcdest_rnode2str(rn, buf, sizeof(buf));
if (new != old)
zlog_debug(
"%u:%s: Updating route rn %p, re %p (%s) old %p (%s)",
zvrf_id(zvrf), buf, rn, new,
"%s(%u):%s: Updating route rn %p, re %p (%s) old %p (%s)",
zvrf_name(zvrf), zvrf_id(zvrf),
buf, rn, new,
zebra_route_string(new->type),
old,
zebra_route_string(old->type));
else
zlog_debug(
"%u:%s: Updating route rn %p, re %p (%s)",
zvrf_id(zvrf), buf, rn, new,
"%s(%u):%s: Updating route rn %p, re %p (%s)",
zvrf_name(zvrf), zvrf_id(zvrf),
buf, rn, new,
zebra_route_string(new->type));
}
@ -867,15 +870,17 @@ static void rib_process_update_fib(struct zebra_vrf *zvrf,
srcdest_rnode2str(rn, buf, sizeof(buf));
if (new != old)
zlog_debug(
"%u:%s: Deleting route rn %p, re %p (%s) old %p (%s) - nexthop inactive",
zvrf_id(zvrf), buf, rn, new,
"%s(%u):%s: Deleting route rn %p, re %p (%s) old %p (%s) - nexthop inactive",
zvrf_name(zvrf), zvrf_id(zvrf),
buf, rn, new,
zebra_route_string(new->type),
old,
zebra_route_string(old->type));
else
zlog_debug(
"%u:%s: Deleting route rn %p, re %p (%s) - nexthop inactive",
zvrf_id(zvrf), buf, rn, new,
"%s(%u):%s: Deleting route rn %p, re %p (%s) - nexthop inactive",
zvrf_name(zvrf), zvrf_id(zvrf),
buf, rn, new,
zebra_route_string(new->type));
}
@ -990,6 +995,7 @@ static void rib_process(struct route_node *rn)
char buf[SRCDEST2STR_BUFFER];
rib_dest_t *dest;
struct zebra_vrf *zvrf = NULL;
struct vrf *vrf;
const struct prefix *p, *src_p;
srcdest_rnode_prefixes(rn, &p, &src_p);
@ -1003,11 +1009,14 @@ static void rib_process(struct route_node *rn)
vrf_id = zvrf_id(zvrf);
}
vrf = vrf_lookup_by_id(vrf_id);
if (IS_ZEBRA_DEBUG_RIB)
srcdest_rnode2str(rn, buf, sizeof(buf));
if (IS_ZEBRA_DEBUG_RIB_DETAILED)
zlog_debug("%u:%s: Processing rn %p", vrf_id, buf, rn);
zlog_debug("%s(%u):%s: Processing rn %p", VRF_LOGNAME(vrf),
vrf_id, buf, rn);
/*
* we can have rn's that have a NULL info pointer
@ -1021,10 +1030,10 @@ static void rib_process(struct route_node *rn)
RNODE_FOREACH_RE_SAFE (rn, re, next) {
if (IS_ZEBRA_DEBUG_RIB_DETAILED)
zlog_debug(
"%u:%s: Examine re %p (%s) status %x flags %x dist %d metric %d",
vrf_id, buf, re, zebra_route_string(re->type),
re->status, re->flags, re->distance,
re->metric);
"%s(%u):%s: Examine re %p (%s) status %x flags %x dist %d metric %d",
VRF_LOGNAME(vrf), vrf_id, buf, re,
zebra_route_string(re->type), re->status,
re->flags, re->distance, re->metric);
/* Currently selected re. */
if (CHECK_FLAG(re->flags, ZEBRA_FLAG_SELECTED)) {
@ -1065,9 +1074,11 @@ static void rib_process(struct route_node *rn)
if (re != old_selected) {
if (IS_ZEBRA_DEBUG_RIB)
zlog_debug(
"%s: %u:%s: imported via import-table but denied "
"%s: %s(%u):%s: imported via import-table but denied "
"by the ip protocol table route-map",
__func__, vrf_id, buf);
__func__,
VRF_LOGNAME(vrf),
vrf_id, buf);
rib_unlink(rn, re);
} else
SET_FLAG(re->status,
@ -1118,9 +1129,9 @@ static void rib_process(struct route_node *rn)
if (IS_ZEBRA_DEBUG_RIB_DETAILED) {
zlog_debug(
"%u:%s: After processing: old_selected %p new_selected %p old_fib %p new_fib %p",
vrf_id, buf, (void *)old_selected, (void *)new_selected,
(void *)old_fib, (void *)new_fib);
"%s(%u):%s: After processing: old_selected %p new_selected %p old_fib %p new_fib %p",
VRF_LOGNAME(vrf), vrf_id, buf, (void *)old_selected,
(void *)new_selected, (void *)old_fib, (void *)new_fib);
}
/* Buffer ROUTE_ENTRY_CHANGED here, because it will get cleared if
@ -1191,8 +1202,8 @@ static void zebra_rib_evaluate_mpls(struct route_node *rn)
if (CHECK_FLAG(dest->flags, RIB_DEST_UPDATE_LSPS)) {
if (IS_ZEBRA_DEBUG_MPLS)
zlog_debug(
"%u: Scheduling all LSPs upon RIB completion",
zvrf_id(zvrf));
"%s(%u): Scheduling all LSPs upon RIB completion",
zvrf_name(zvrf), zvrf_id(zvrf));
zebra_mpls_lsp_schedule(zvrf);
mpls_unmark_lsps_for_processing(rn);
}
@ -1299,6 +1310,9 @@ static bool rib_update_re_from_ctx(struct route_entry *re,
bool is_selected = false; /* Is 're' currently the selected re? */
bool changed_p = false; /* Change to nexthops? */
rib_dest_t *dest;
struct vrf *vrf;
vrf = vrf_lookup_by_id(re->vrf_id);
/* Note well: only capturing the prefix string if debug is enabled here;
* unconditional log messages will have to generate the string.
@ -1311,8 +1325,9 @@ static bool rib_update_re_from_ctx(struct route_entry *re,
is_selected = (re == dest->selected_fib);
if (IS_ZEBRA_DEBUG_RIB_DETAILED)
zlog_debug("update_from_ctx: %u:%s: %sSELECTED",
re->vrf_id, dest_str, (is_selected ? "" : "NOT "));
zlog_debug("update_from_ctx: %s(%u):%s: %sSELECTED",
VRF_LOGNAME(vrf), re->vrf_id, dest_str,
(is_selected ? "" : "NOT "));
/* Update zebra's nexthop FIB flag for each nexthop that was installed.
* If the installed set differs from the set requested by the rib/owner,
@ -1325,11 +1340,10 @@ static bool rib_update_re_from_ctx(struct route_entry *re,
* Let's assume the nexthops are ordered here to save time.
*/
if (nexthop_group_equal(&re->fib_ng, dplane_ctx_get_ng(ctx)) == false) {
if (IS_ZEBRA_DEBUG_RIB_DETAILED) {
if (IS_ZEBRA_DEBUG_RIB_DETAILED)
zlog_debug(
"%u:%s update_from_ctx: notif nh and fib nh mismatch",
re->vrf_id, dest_str);
}
"%s(%u):%s update_from_ctx: notif nh and fib nh mismatch",
VRF_LOGNAME(vrf), re->vrf_id, dest_str);
matched = false;
} else
@ -1338,8 +1352,9 @@ static bool rib_update_re_from_ctx(struct route_entry *re,
/* If the new FIB set matches the existing FIB set, we're done. */
if (matched) {
if (IS_ZEBRA_DEBUG_RIB)
zlog_debug("%u:%s update_from_ctx(): existing fib nhg, no change",
re->vrf_id, dest_str);
zlog_debug(
"%s(%u):%s update_from_ctx(): existing fib nhg, no change",
VRF_LOGNAME(vrf), re->vrf_id, dest_str);
goto done;
} else if (re->fib_ng.nexthop) {
@ -1347,8 +1362,9 @@ static bool rib_update_re_from_ctx(struct route_entry *re,
* Free stale fib list and move on to check the rib nhg.
*/
if (IS_ZEBRA_DEBUG_RIB)
zlog_debug("%u:%s update_from_ctx(): replacing fib nhg",
re->vrf_id, dest_str);
zlog_debug(
"%s(%u):%s update_from_ctx(): replacing fib nhg",
VRF_LOGNAME(vrf), re->vrf_id, dest_str);
nexthops_free(re->fib_ng.nexthop);
re->fib_ng.nexthop = NULL;
@ -1356,8 +1372,8 @@ static bool rib_update_re_from_ctx(struct route_entry *re,
changed_p = true;
} else {
if (IS_ZEBRA_DEBUG_RIB)
zlog_debug("%u:%s update_from_ctx(): no fib nhg",
re->vrf_id, dest_str);
zlog_debug("%s(%u):%s update_from_ctx(): no fib nhg",
VRF_LOGNAME(vrf), re->vrf_id, dest_str);
}
/*
@ -1437,8 +1453,9 @@ static bool rib_update_re_from_ctx(struct route_entry *re,
/* If all nexthops were processed, we're done */
if (matched) {
if (IS_ZEBRA_DEBUG_RIB)
zlog_debug("%u:%s update_from_ctx(): rib nhg matched, changed '%s'",
re->vrf_id, dest_str,
zlog_debug(
"%s(%u):%s update_from_ctx(): rib nhg matched, changed '%s'",
VRF_LOGNAME(vrf), re->vrf_id, dest_str,
(changed_p ? "true" : "false"));
goto done;
}
@ -1449,8 +1466,9 @@ no_nexthops:
* create a fib-specific nexthop-group
*/
if (IS_ZEBRA_DEBUG_RIB)
zlog_debug("%u:%s update_from_ctx(): changed %s, adding new fib nhg",
re->vrf_id, dest_str,
zlog_debug(
"%s(%u):%s update_from_ctx(): changed %s, adding new fib nhg",
VRF_LOGNAME(vrf), re->vrf_id, dest_str,
(changed_p ? "true" : "false"));
ctxnhg = dplane_ctx_get_ng(ctx);
@ -1489,9 +1507,11 @@ rib_find_rn_from_ctx(const struct zebra_dplane_ctx *ctx)
dplane_ctx_get_vrf(ctx), dplane_ctx_get_table(ctx));
if (table == NULL) {
if (IS_ZEBRA_DEBUG_DPLANE) {
zlog_debug("Failed to find route for ctx: no table for afi %d, safi %d, vrf %u",
zlog_debug(
"Failed to find route for ctx: no table for afi %d, safi %d, vrf %s(%u)",
dplane_ctx_get_afi(ctx),
dplane_ctx_get_safi(ctx),
vrf_id_to_name(dplane_ctx_get_vrf(ctx)),
dplane_ctx_get_vrf(ctx));
}
goto done;
@ -1515,6 +1535,7 @@ done:
static void rib_process_result(struct zebra_dplane_ctx *ctx)
{
struct zebra_vrf *zvrf = NULL;
struct vrf *vrf;
struct route_node *rn = NULL;
struct route_entry *re = NULL, *old_re = NULL, *rib;
bool is_update = false;
@ -1526,6 +1547,7 @@ static void rib_process_result(struct zebra_dplane_ctx *ctx)
bool fib_changed = false;
zvrf = vrf_info_lookup(dplane_ctx_get_vrf(ctx));
vrf = vrf_lookup_by_id(dplane_ctx_get_vrf(ctx));
dest_pfx = dplane_ctx_get_dest(ctx);
/* Note well: only capturing the prefix string if debug is enabled here;
@ -1538,8 +1560,10 @@ static void rib_process_result(struct zebra_dplane_ctx *ctx)
rn = rib_find_rn_from_ctx(ctx);
if (rn == NULL) {
if (IS_ZEBRA_DEBUG_DPLANE) {
zlog_debug("Failed to process dplane results: no route for %u:%s",
dplane_ctx_get_vrf(ctx), dest_str);
zlog_debug(
"Failed to process dplane results: no route for %s(%u):%s",
VRF_LOGNAME(vrf), dplane_ctx_get_vrf(ctx),
dest_str);
}
goto done;
}
@ -1550,9 +1574,10 @@ static void rib_process_result(struct zebra_dplane_ctx *ctx)
status = dplane_ctx_get_status(ctx);
if (IS_ZEBRA_DEBUG_DPLANE_DETAIL)
zlog_debug("%u:%s Processing dplane ctx %p, op %s result %s",
dplane_ctx_get_vrf(ctx), dest_str, ctx,
dplane_op2str(op), dplane_res2str(status));
zlog_debug(
"%s(%u):%s Processing dplane ctx %p, op %s result %s",
VRF_LOGNAME(vrf), dplane_ctx_get_vrf(ctx), dest_str,
ctx, dplane_op2str(op), dplane_res2str(status));
/*
* Update is a bit of a special case, where we may have both old and new
@ -1590,9 +1615,10 @@ static void rib_process_result(struct zebra_dplane_ctx *ctx)
if (re) {
if (re->dplane_sequence != seq) {
if (IS_ZEBRA_DEBUG_DPLANE_DETAIL)
zlog_debug("%u:%s Stale dplane result for re %p",
dplane_ctx_get_vrf(ctx),
dest_str, re);
zlog_debug(
"%s(%u):%s Stale dplane result for re %p",
VRF_LOGNAME(vrf),
dplane_ctx_get_vrf(ctx), dest_str, re);
} else
UNSET_FLAG(re->status, ROUTE_ENTRY_QUEUED);
}
@ -1600,9 +1626,11 @@ static void rib_process_result(struct zebra_dplane_ctx *ctx)
if (old_re) {
if (old_re->dplane_sequence != dplane_ctx_get_old_seq(ctx)) {
if (IS_ZEBRA_DEBUG_DPLANE_DETAIL)
zlog_debug("%u:%s Stale dplane result for old_re %p",
dplane_ctx_get_vrf(ctx),
dest_str, old_re);
zlog_debug(
"%s(%u):%s Stale dplane result for old_re %p",
VRF_LOGNAME(vrf),
dplane_ctx_get_vrf(ctx), dest_str,
old_re);
} else
UNSET_FLAG(old_re->status, ROUTE_ENTRY_QUEUED);
}
@ -1639,9 +1667,10 @@ static void rib_process_result(struct zebra_dplane_ctx *ctx)
if (!fib_changed) {
if (IS_ZEBRA_DEBUG_DPLANE_DETAIL)
zlog_debug("%u:%s no fib change for re",
dplane_ctx_get_vrf(
ctx),
zlog_debug(
"%s(%u):%s no fib change for re",
VRF_LOGNAME(vrf),
dplane_ctx_get_vrf(ctx),
dest_str);
}
@ -1677,10 +1706,10 @@ static void rib_process_result(struct zebra_dplane_ctx *ctx)
zsend_route_notify_owner(re, dest_pfx,
ZAPI_ROUTE_FAIL_INSTALL);
zlog_warn("%u:%s: Route install failed",
dplane_ctx_get_vrf(ctx),
prefix2str(dest_pfx,
dest_str, sizeof(dest_str)));
zlog_warn("%s(%u):%s: Route install failed",
VRF_LOGNAME(vrf), dplane_ctx_get_vrf(ctx),
prefix2str(dest_pfx, dest_str,
sizeof(dest_str)));
}
break;
case DPLANE_OP_ROUTE_DELETE:
@ -1706,10 +1735,10 @@ static void rib_process_result(struct zebra_dplane_ctx *ctx)
zsend_route_notify_owner_ctx(ctx,
ZAPI_ROUTE_REMOVE_FAIL);
zlog_warn("%u:%s: Route Deletion failure",
dplane_ctx_get_vrf(ctx),
prefix2str(dest_pfx,
dest_str, sizeof(dest_str)));
zlog_warn("%s(%u):%s: Route Deletion failure",
VRF_LOGNAME(vrf), dplane_ctx_get_vrf(ctx),
prefix2str(dest_pfx, dest_str,
sizeof(dest_str)));
}
/*
@ -1747,6 +1776,7 @@ static void rib_process_dplane_notify(struct zebra_dplane_ctx *ctx)
{
struct route_node *rn = NULL;
struct route_entry *re = NULL;
struct vrf *vrf;
struct nexthop *nexthop;
char dest_str[PREFIX_STRLEN] = "";
const struct prefix *dest_pfx, *src_pfx;
@ -1755,6 +1785,7 @@ static void rib_process_dplane_notify(struct zebra_dplane_ctx *ctx)
bool debug_p = IS_ZEBRA_DEBUG_DPLANE | IS_ZEBRA_DEBUG_RIB;
int start_count, end_count;
dest_pfx = dplane_ctx_get_dest(ctx);
vrf = vrf_lookup_by_id(dplane_ctx_get_vrf(ctx));
/* Note well: only capturing the prefix string if debug is enabled here;
* unconditional log messages will have to generate the string.
@ -1766,8 +1797,10 @@ static void rib_process_dplane_notify(struct zebra_dplane_ctx *ctx)
rn = rib_find_rn_from_ctx(ctx);
if (rn == NULL) {
if (debug_p) {
zlog_debug("Failed to process dplane notification: no routes for %u:%s",
dplane_ctx_get_vrf(ctx), dest_str);
zlog_debug(
"Failed to process dplane notification: no routes for %s(%u):%s",
VRF_LOGNAME(vrf), dplane_ctx_get_vrf(ctx),
dest_str);
}
goto done;
}
@ -1776,8 +1809,9 @@ static void rib_process_dplane_notify(struct zebra_dplane_ctx *ctx)
srcdest_rnode_prefixes(rn, &dest_pfx, &src_pfx);
if (debug_p)
zlog_debug("%u:%s Processing dplane notif ctx %p",
dplane_ctx_get_vrf(ctx), dest_str, ctx);
zlog_debug("%s(%u):%s Processing dplane notif ctx %p",
VRF_LOGNAME(vrf), dplane_ctx_get_vrf(ctx), dest_str,
ctx);
/*
* Take a pass through the routes, look for matches with the context
@ -1791,10 +1825,11 @@ static void rib_process_dplane_notify(struct zebra_dplane_ctx *ctx)
/* No match? Nothing we can do */
if (re == NULL) {
if (debug_p)
zlog_debug("%u:%s Unable to process dplane notification: no entry for type %s",
dplane_ctx_get_vrf(ctx), dest_str,
zebra_route_string(
dplane_ctx_get_type(ctx)));
zlog_debug(
"%s(%u):%s Unable to process dplane notification: no entry for type %s",
VRF_LOGNAME(vrf), dplane_ctx_get_vrf(ctx),
dest_str,
zebra_route_string(dplane_ctx_get_type(ctx)));
goto done;
}
@ -1824,14 +1859,18 @@ static void rib_process_dplane_notify(struct zebra_dplane_ctx *ctx)
if (CHECK_FLAG(re->status, ROUTE_ENTRY_INSTALLED))
UNSET_FLAG(re->status, ROUTE_ENTRY_INSTALLED);
if (debug_p)
zlog_debug("%u:%s dplane notif, uninstalled type %s route",
zlog_debug(
"%s(%u):%s dplane notif, uninstalled type %s route",
VRF_LOGNAME(vrf),
dplane_ctx_get_vrf(ctx), dest_str,
zebra_route_string(
dplane_ctx_get_type(ctx)));
} else {
/* At least report on the event. */
if (debug_p)
zlog_debug("%u:%s dplane notif, but type %s not selected_fib",
zlog_debug(
"%s(%u):%s dplane notif, but type %s not selected_fib",
VRF_LOGNAME(vrf),
dplane_ctx_get_vrf(ctx), dest_str,
zebra_route_string(
dplane_ctx_get_type(ctx)));
@ -1859,8 +1898,10 @@ static void rib_process_dplane_notify(struct zebra_dplane_ctx *ctx)
if (!fib_changed) {
if (debug_p)
zlog_debug("%u:%s dplane notification: rib_update returns FALSE",
dplane_ctx_get_vrf(ctx), dest_str);
zlog_debug(
"%s(%u):%s dplane notification: rib_update returns FALSE",
VRF_LOGNAME(vrf), dplane_ctx_get_vrf(ctx),
dest_str);
}
/*
@ -1879,8 +1920,10 @@ static void rib_process_dplane_notify(struct zebra_dplane_ctx *ctx)
*/
if (start_count > 0 && end_count > 0) {
if (debug_p)
zlog_debug("%u:%s applied nexthop changes from dplane notification",
dplane_ctx_get_vrf(ctx), dest_str);
zlog_debug(
"%s(%u):%s applied nexthop changes from dplane notification",
VRF_LOGNAME(vrf), dplane_ctx_get_vrf(ctx),
dest_str);
/* Changed nexthops - update kernel/others */
dplane_route_notif_update(rn, re,
@ -1888,8 +1931,10 @@ static void rib_process_dplane_notify(struct zebra_dplane_ctx *ctx)
} else if (start_count == 0 && end_count > 0) {
if (debug_p)
zlog_debug("%u:%s installed transition from dplane notification",
dplane_ctx_get_vrf(ctx), dest_str);
zlog_debug(
"%s(%u):%s installed transition from dplane notification",
VRF_LOGNAME(vrf), dplane_ctx_get_vrf(ctx),
dest_str);
/* We expect this to be the selected route, so we want
* to tell others about this transition.
@ -1904,8 +1949,10 @@ static void rib_process_dplane_notify(struct zebra_dplane_ctx *ctx)
} else if (start_count > 0 && end_count == 0) {
if (debug_p)
zlog_debug("%u:%s un-installed transition from dplane notification",
dplane_ctx_get_vrf(ctx), dest_str);
zlog_debug(
"%s(%u):%s un-installed transition from dplane notification",
VRF_LOGNAME(vrf), dplane_ctx_get_vrf(ctx),
dest_str);
/* Transition from _something_ installed to _nothing_
* installed.
@ -1970,8 +2017,8 @@ static void process_subq_route(struct listnode *lnode, uint8_t qindex)
char buf[SRCDEST2STR_BUFFER];
srcdest_rnode2str(rnode, buf, sizeof(buf));
zlog_debug("%u:%s: rn %p dequeued from sub-queue %u",
zvrf ? zvrf_id(zvrf) : 0, buf, rnode, qindex);
zlog_debug("%s(%u):%s: rn %p dequeued from sub-queue %u",
zvrf_name(zvrf), zvrf_id(zvrf), buf, rnode, qindex);
}
if (rnode->info)
@ -2383,9 +2430,9 @@ void rib_delnode(struct route_node *rn, struct route_entry *re)
if (IS_ZEBRA_DEBUG_RIB) {
char buf[SRCDEST2STR_BUFFER];
srcdest_rnode2str(rn, buf, sizeof(buf));
zlog_debug("%u:%s: Freeing route rn %p, re %p (%s)",
re->vrf_id, buf, rn, re,
zebra_route_string(re->type));
zlog_debug("%s(%u):%s: Freeing route rn %p, re %p (%s)",
vrf_id_to_name(re->vrf_id), re->vrf_id, buf,
rn, re, zebra_route_string(re->type));
}
rib_unlink(rn, re);
@ -2515,14 +2562,17 @@ void rib_lookup_and_dump(struct prefix_ipv4 *p, vrf_id_t vrf_id)
struct route_table *table;
struct route_node *rn;
struct route_entry *re;
struct vrf *vrf;
char prefix_buf[INET_ADDRSTRLEN];
vrf = vrf_lookup_by_id(vrf_id);
/* Lookup table. */
table = zebra_vrf_table(AFI_IP, SAFI_UNICAST, vrf_id);
if (!table) {
flog_err(EC_ZEBRA_TABLE_LOOKUP_FAILED,
"%s:%u zebra_vrf_table() returned NULL", __func__,
vrf_id);
"%s:%s(%u) zebra_vrf_table() returned NULL", __func__,
VRF_LOGNAME(vrf), vrf_id);
return;
}
@ -2531,7 +2581,8 @@ void rib_lookup_and_dump(struct prefix_ipv4 *p, vrf_id_t vrf_id)
/* No route for this prefix. */
if (!rn) {
zlog_debug("%s:%u lookup failed for %s", __func__, vrf_id,
zlog_debug("%s:%s(%u) lookup failed for %s", __func__,
VRF_LOGNAME(vrf), vrf_id,
prefix2str((struct prefix *)p, prefix_buf,
sizeof(prefix_buf)));
return;
@ -2542,9 +2593,8 @@ void rib_lookup_and_dump(struct prefix_ipv4 *p, vrf_id_t vrf_id)
/* let's go */
RNODE_FOREACH_RE (rn, re) {
zlog_debug("%s:%u rn %p, re %p: %s, %s",
__func__, vrf_id,
(void *)rn, (void *)re,
zlog_debug("%s:%s(%u) rn %p, re %p: %s, %s", __func__,
VRF_LOGNAME(vrf), vrf_id, (void *)rn, (void *)re,
(CHECK_FLAG(re->status, ROUTE_ENTRY_REMOVED)
? "removed"
: "NOT removed"),
@ -2567,9 +2617,11 @@ void rib_lookup_and_pushup(struct prefix_ipv4 *p, vrf_id_t vrf_id)
rib_dest_t *dest;
if (NULL == (table = zebra_vrf_table(AFI_IP, SAFI_UNICAST, vrf_id))) {
struct vrf *vrf = vrf_lookup_by_id(vrf_id);
flog_err(EC_ZEBRA_TABLE_LOOKUP_FAILED,
"%s:%u zebra_vrf_table() returned NULL", __func__,
vrf_id);
"%s:%s(%u) zebra_vrf_table() returned NULL", __func__,
VRF_LOGNAME(vrf), vrf_id);
return;
}
@ -2592,9 +2644,12 @@ void rib_lookup_and_pushup(struct prefix_ipv4 *p, vrf_id_t vrf_id)
if (dest->selected_fib) {
if (IS_ZEBRA_DEBUG_RIB) {
char buf[PREFIX_STRLEN];
struct vrf *vrf =
vrf_lookup_by_id(dest->selected_fib->vrf_id);
zlog_debug("%u:%s: freeing way for connected prefix",
dest->selected_fib->vrf_id,
zlog_debug(
"%s(%u):%s: freeing way for connected prefix",
VRF_LOGNAME(vrf), dest->selected_fib->vrf_id,
prefix2str(&rn->p, buf, sizeof(buf)));
route_entry_dump(&rn->p, NULL, dest->selected_fib);
}
@ -3091,8 +3146,7 @@ void rib_update_table(struct route_table *table, rib_update_event_t event)
table->info ? afi2str(
((rib_table_info_t *)table->info)->afi)
: "Unknown",
vrf ? vrf->name : "Unknown",
zvrf ? zvrf->table_id : 0,
VRF_LOGNAME(vrf), zvrf ? zvrf->table_id : 0,
rib_update_event2str(event));
}

View File

@ -193,7 +193,7 @@ struct zebra_vrf {
static inline vrf_id_t zvrf_id(struct zebra_vrf *zvrf)
{
if (!zvrf || !zvrf->vrf)
return VRF_UNKNOWN;
return VRF_DEFAULT;
return zvrf->vrf->vrf_id;
}
@ -206,6 +206,8 @@ static inline const char *zvrf_ns_name(struct zebra_vrf *zvrf)
static inline const char *zvrf_name(struct zebra_vrf *zvrf)
{
if (!zvrf || !zvrf->vrf)
return "Unknown";
return zvrf->vrf->name;
}