From a7d91a8c79f0b8b468de52d95d9f44a7ae95535a Mon Sep 17 00:00:00 2001 From: Donatas Abraitis Date: Tue, 22 Mar 2022 21:45:47 +0200 Subject: [PATCH] bgpd: Print hostname along with IP for most useful debug messages Examples: ``` %ADJCHANGE: neighbor 192.168.0.1(exit1-debian-11) in vrf default Up 192.168.0.1(exit1-debian-11) graceful restart stalepath timer expired 192.168.0.1(exit1-debian-11) sending route-refresh (BoRR) for IPv4/unicast 192.168.0.1(exit1-debian-11) graceful restart timer started for 120 sec 192.168.0.1(exit1-debian-11) graceful restart stalepath timer started for 120 sec 192.168.0.1(exit1-debian-11) graceful restart timer stopped %MAXPFXEXCEED: No. of IPv4 Unicast prefix received from 192.168.0.1(exit1-debian-11) 9 exceed, limit 1 ``` Signed-off-by: Donatas Abraitis --- bgpd/bgp_fsm.c | 75 ++++++++++++++++++++------------------ bgpd/bgp_packet.c | 92 ++++++++++++++++++++++++++++------------------- bgpd/bgp_route.c | 11 +++--- bgpd/bgpd.c | 18 +++++----- bgpd/bgpd.h | 5 +++ 5 files changed, 117 insertions(+), 84 deletions(-) diff --git a/bgpd/bgp_fsm.c b/bgpd/bgp_fsm.c index f8de3b8dc4..f755089bba 100644 --- a/bgpd/bgp_fsm.c +++ b/bgpd/bgp_fsm.c @@ -677,7 +677,8 @@ static void bgp_llgr_stale_timer_expire(struct thread *thread) * stale routes from the neighbor that it is retaining. */ if (bgp_debug_neighbor_events(peer)) - zlog_debug("%s Long-lived stale timer (%s) expired", peer->host, + zlog_debug("%s(%s) Long-lived stale timer (%s) expired", + peer->host, bgp_peer_hostname(peer), get_afi_safi_str(afi, safi, false)); UNSET_FLAG(peer->af_sflags[afi][safi], PEER_STATUS_LLGR_WAIT); @@ -719,8 +720,10 @@ static void bgp_set_llgr_stale(struct peer *peer, afi_t afi, safi_t safi) if (bgp_debug_neighbor_events(peer)) zlog_debug( - "%s Long-lived set stale community (LLGR_STALE) for: %pFX", - peer->host, &dest->p); + "%s(%s) Long-lived set stale community (LLGR_STALE) for: %pFX", + peer->host, + bgp_peer_hostname(peer), + &dest->p); attr = *pi->attr; bgp_attr_add_llgr_community(&attr); @@ -747,8 +750,10 @@ static void bgp_set_llgr_stale(struct peer *peer, afi_t afi, safi_t safi) if (bgp_debug_neighbor_events(peer)) zlog_debug( - "%s Long-lived set stale community (LLGR_STALE) for: %pFX", - peer->host, &dest->p); + "%s(%s) Long-lived set stale community (LLGR_STALE) for: %pFX", + peer->host, + bgp_peer_hostname(peer), + &dest->p); attr = *pi->attr; bgp_attr_add_llgr_community(&attr); @@ -772,9 +777,10 @@ static void bgp_graceful_restart_timer_expire(struct thread *thread) peer = THREAD_ARG(thread); if (bgp_debug_neighbor_events(peer)) { - zlog_debug("%s graceful restart timer expired", peer->host); - zlog_debug("%s graceful restart stalepath timer stopped", - peer->host); + zlog_debug("%s(%s) graceful restart timer expired", peer->host, + bgp_peer_hostname(peer)); + zlog_debug("%s(%s) graceful restart stalepath timer stopped", + peer->host, bgp_peer_hostname(peer)); } FOREACH_AFI_SAFI (afi, safi) { @@ -800,8 +806,8 @@ static void bgp_graceful_restart_timer_expire(struct thread *thread) if (bgp_debug_neighbor_events(peer)) zlog_debug( - "%s Long-lived stale timer (%s) started for %d sec", - peer->host, + "%s(%s) Long-lived stale timer (%s) started for %d sec", + peer->host, bgp_peer_hostname(peer), get_afi_safi_str(afi, safi, false), peer->llgr[afi][safi].stale_time); @@ -836,8 +842,8 @@ static void bgp_graceful_stale_timer_expire(struct thread *thread) peer = THREAD_ARG(thread); if (bgp_debug_neighbor_events(peer)) - zlog_debug("%s graceful restart stalepath timer expired", - peer->host); + zlog_debug("%s(%s) graceful restart stalepath timer expired", + peer->host, bgp_peer_hostname(peer)); /* NSF delete stale route */ FOREACH_AFI_SAFI_NSF (afi, safi) @@ -1390,11 +1396,10 @@ int bgp_stop(struct peer *peer) zlog_info( "%%ADJCHANGE: neighbor %s(%s) in vrf %s Down %s", - peer->host, - (peer->hostname) ? peer->hostname : "Unknown", + peer->host, bgp_peer_hostname(peer), vrf ? ((vrf->vrf_id != VRF_DEFAULT) - ? vrf->name - : VRF_DEFAULT_NAME) + ? vrf->name + : VRF_DEFAULT_NAME) : "", peer_down_str[(int)peer->last_reset]); } @@ -1404,17 +1409,19 @@ int bgp_stop(struct peer *peer) BGP_TIMER_OFF(peer->t_gr_stale); if (bgp_debug_neighbor_events(peer)) zlog_debug( - "%s graceful restart stalepath timer stopped", - peer->host); + "%s(%s) graceful restart stalepath timer stopped", + peer->host, bgp_peer_hostname(peer)); } if (CHECK_FLAG(peer->sflags, PEER_STATUS_NSF_WAIT)) { if (bgp_debug_neighbor_events(peer)) { zlog_debug( - "%s graceful restart timer started for %d sec", - peer->host, peer->v_gr_restart); + "%s(%s) graceful restart timer started for %d sec", + peer->host, bgp_peer_hostname(peer), + peer->v_gr_restart); zlog_debug( - "%s graceful restart stalepath timer started for %d sec", - peer->host, peer->bgp->stalepath_time); + "%s(%s) graceful restart stalepath timer started for %d sec", + peer->host, bgp_peer_hostname(peer), + peer->bgp->stalepath_time); } BGP_TIMER_ON(peer->t_gr_restart, bgp_graceful_restart_timer_expire, @@ -1435,8 +1442,8 @@ int bgp_stop(struct peer *peer) if (bgp_debug_neighbor_events(peer)) zlog_debug( - "%s: route-refresh restart stalepath timer stopped", - peer->host); + "%s(%s) route-refresh restart stalepath timer stopped", + peer->host, bgp_peer_hostname(peer)); } /* If peer reset before receiving EOR, decrement EOR count and @@ -2092,12 +2099,12 @@ static int bgp_establish(struct peer *peer) /* bgp log-neighbor-changes of neighbor Up */ if (CHECK_FLAG(peer->bgp->flags, BGP_FLAG_LOG_NEIGHBOR_CHANGES)) { struct vrf *vrf = vrf_lookup_by_id(peer->bgp->vrf_id); - zlog_info( - "%%ADJCHANGE: neighbor %s(%s) in vrf %s Up", peer->host, - (peer->hostname) ? peer->hostname : "Unknown", - vrf ? ((vrf->vrf_id != VRF_DEFAULT) ? vrf->name - : VRF_DEFAULT_NAME) - : ""); + zlog_info("%%ADJCHANGE: neighbor %s(%s) in vrf %s Up", + peer->host, bgp_peer_hostname(peer), + vrf ? ((vrf->vrf_id != VRF_DEFAULT) + ? vrf->name + : VRF_DEFAULT_NAME) + : ""); } /* assign update-group/subgroup */ update_group_adjust_peer_afs(peer); @@ -2182,16 +2189,16 @@ static int bgp_establish(struct peer *peer) BGP_TIMER_OFF(peer->t_gr_stale); if (bgp_debug_neighbor_events(peer)) zlog_debug( - "%s graceful restart stalepath timer stopped", - peer->host); + "%s(%s) graceful restart stalepath timer stopped", + peer->host, bgp_peer_hostname(peer)); } } if (peer->t_gr_restart) { BGP_TIMER_OFF(peer->t_gr_restart); if (bgp_debug_neighbor_events(peer)) - zlog_debug("%s graceful restart timer stopped", - peer->host); + zlog_debug("%s(%s) graceful restart timer stopped", + peer->host, bgp_peer_hostname(peer)); } /* Reset uptime, turn on keepalives, send current table. */ diff --git a/bgpd/bgp_packet.c b/bgpd/bgp_packet.c index 09db041780..424659136e 100644 --- a/bgpd/bgp_packet.c +++ b/bgpd/bgp_packet.c @@ -483,8 +483,10 @@ void bgp_generate_updgrp_packets(struct thread *thread) if (bgp_debug_neighbor_events( peer)) zlog_debug( - "%s sending route-refresh (EoRR) for %s/%s", + "%s(%s) sending route-refresh (EoRR) for %s/%s", peer->host, + bgp_peer_hostname( + peer), afi2str(afi), safi2str(safi)); } @@ -913,9 +915,12 @@ void bgp_route_refresh_send(struct peer *peer, afi_t afi, safi_t safi, stream_putc(s, ORF_COMMON_PART_REMOVE_ALL); if (bgp_debug_neighbor_events(peer)) zlog_debug( - "%s sending REFRESH_REQ to remove ORF(%d) (%s) for afi/safi: %s/%s", - peer->host, orf_type, - (when_to_refresh == REFRESH_DEFER + "%s(%s) sending REFRESH_REQ to remove ORF(%d) (%s) for afi/safi: %s/%s", + peer->host, + bgp_peer_hostname(peer), + orf_type, + (when_to_refresh == + REFRESH_DEFER ? "defer" : "immediate"), iana_afi2str(pkt_afi), @@ -930,9 +935,12 @@ void bgp_route_refresh_send(struct peer *peer, afi_t afi, safi_t safi, ORF_COMMON_PART_DENY); if (bgp_debug_neighbor_events(peer)) zlog_debug( - "%s sending REFRESH_REQ with pfxlist ORF(%d) (%s) for afi/safi: %s/%s", - peer->host, orf_type, - (when_to_refresh == REFRESH_DEFER + "%s(%s) sending REFRESH_REQ with pfxlist ORF(%d) (%s) for afi/safi: %s/%s", + peer->host, + bgp_peer_hostname(peer), + orf_type, + (when_to_refresh == + REFRESH_DEFER ? "defer" : "immediate"), iana_afi2str(pkt_afi), @@ -949,9 +957,10 @@ void bgp_route_refresh_send(struct peer *peer, afi_t afi, safi_t safi, if (bgp_debug_neighbor_events(peer)) { if (!orf_refresh) - zlog_debug("%s sending REFRESH_REQ for afi/safi: %s/%s", - peer->host, iana_afi2str(pkt_afi), - iana_safi2str(pkt_safi)); + zlog_debug( + "%s(%s) sending REFRESH_REQ for afi/safi: %s/%s", + peer->host, bgp_peer_hostname(peer), + iana_afi2str(pkt_afi), iana_safi2str(pkt_safi)); } /* Add packet to the peer. */ @@ -995,8 +1004,8 @@ void bgp_capability_send(struct peer *peer, afi_t afi, safi_t safi, if (bgp_debug_neighbor_events(peer)) zlog_debug( - "%s sending CAPABILITY has %s MP_EXT CAP for afi/safi: %s/%s", - peer->host, + "%s(%s) sending CAPABILITY has %s MP_EXT CAP for afi/safi: %s/%s", + peer->host, bgp_peer_hostname(peer), action == CAPABILITY_ACTION_SET ? "Advertising" : "Removing", iana_afi2str(pkt_afi), iana_safi2str(pkt_safi)); @@ -1551,8 +1560,9 @@ static void bgp_refresh_stalepath_timer_expire(struct thread *thread) bgp_clear_stale_route(peer, afi, safi); if (bgp_debug_neighbor_events(peer)) - zlog_debug("%s: route-refresh (BoRR) timer for %s/%s expired", - peer->host, afi2str(afi), safi2str(safi)); + zlog_debug( + "%s(%s) route-refresh (BoRR) timer expired for afi/safi: %d/%d", + peer->host, bgp_peer_hostname(peer), afi, safi); bgp_timer_set(peer); } @@ -1708,7 +1718,8 @@ static int bgp_update_receive(struct peer *peer, bgp_size_t size) peer->host); if (ret && bgp_debug_update(peer, NULL, NULL, 1)) { - zlog_debug("%s rcvd UPDATE w/ attr: %s", peer->host, + zlog_debug("%s(%s) rcvd UPDATE w/ attr: %s", peer->host, + bgp_peer_hostname(peer), peer->rcvd_attr_str); peer->rcvd_attr_printed = 1; } @@ -1738,8 +1749,9 @@ static int bgp_update_receive(struct peer *peer, bgp_size_t size) } if (BGP_DEBUG(update, UPDATE_IN)) - zlog_debug("%s rcvd UPDATE wlen %d attrlen %d alen %d", - peer->host, withdraw_len, attribute_len, update_len); + zlog_debug("%s(%s) rcvd UPDATE wlen %d attrlen %d alen %d", + peer->host, bgp_peer_hostname(peer), withdraw_len, + attribute_len, update_len); /* Parse any given NLRIs */ for (int i = NLRI_UPDATE; i < NLRI_TYPE_MAX; i++) { @@ -2273,18 +2285,18 @@ static int bgp_route_refresh_receive(struct peer *peer, bgp_size_t size) PEER_STATUS_EOR_RECEIVED)) { if (bgp_debug_neighbor_events(peer)) zlog_debug( - "%s rcvd route-refresh (BoRR) for %s/%s before EoR", - peer->host, afi2str(afi), - safi2str(safi)); + "%s(%s) rcvd route-refresh (BoRR) for %s/%s before EoR", + peer->host, bgp_peer_hostname(peer), + afi2str(afi), safi2str(safi)); return BGP_PACKET_NOOP; } if (peer->t_refresh_stalepath) { if (bgp_debug_neighbor_events(peer)) zlog_debug( - "%s rcvd route-refresh (BoRR) for %s/%s, whereas BoRR already received", - peer->host, afi2str(afi), - safi2str(safi)); + "%s(%s) rcvd route-refresh (BoRR) for %s/%s, whereas BoRR already received", + peer->host, bgp_peer_hostname(peer), + afi2str(afi), safi2str(safi)); return BGP_PACKET_NOOP; } @@ -2312,14 +2324,16 @@ static int bgp_route_refresh_receive(struct peer *peer, bgp_size_t size) if (bgp_debug_neighbor_events(peer)) zlog_debug( - "%s rcvd route-refresh (BoRR) for %s/%s, triggering timer for %u seconds", - peer->host, afi2str(afi), safi2str(safi), + "%s(%s) rcvd route-refresh (BoRR) for %s/%s, triggering timer for %u seconds", + peer->host, bgp_peer_hostname(peer), + afi2str(afi), safi2str(safi), peer->bgp->stalepath_time); } else if (subtype == BGP_ROUTE_REFRESH_EORR) { if (!peer->t_refresh_stalepath) { zlog_err( - "%s rcvd route-refresh (EoRR) for %s/%s, whereas no BoRR received", - peer->host, afi2str(afi), safi2str(safi)); + "%s(%s) rcvd route-refresh (EoRR) for %s/%s, whereas no BoRR received", + peer->host, bgp_peer_hostname(peer), + afi2str(afi), safi2str(safi)); return BGP_PACKET_NOOP; } @@ -2331,15 +2345,18 @@ static int bgp_route_refresh_receive(struct peer *peer, bgp_size_t size) if (bgp_debug_neighbor_events(peer)) zlog_debug( - "%s rcvd route-refresh (EoRR) for %s/%s, stopping BoRR timer", - peer->host, afi2str(afi), safi2str(safi)); + "%s(%s) rcvd route-refresh (EoRR) for %s/%s, stopping BoRR timer", + peer->host, bgp_peer_hostname(peer), + afi2str(afi), safi2str(safi)); if (peer->nsf[afi][safi]) bgp_clear_stale_route(peer, afi, safi); } else { if (bgp_debug_neighbor_events(peer)) - zlog_debug("%s rcvd route-refresh (REQUEST) for %s/%s", - peer->host, afi2str(afi), safi2str(safi)); + zlog_debug( + "%s(%s) rcvd route-refresh (REQUEST) for %s/%s", + peer->host, bgp_peer_hostname(peer), + afi2str(afi), safi2str(safi)); /* In response to a "normal route refresh request" from the * peer, the speaker MUST send a BoRR message. @@ -2354,9 +2371,10 @@ static int bgp_route_refresh_receive(struct peer *peer, bgp_size_t size) PEER_STATUS_EOR_SEND)) { if (bgp_debug_neighbor_events(peer)) zlog_debug( - "%s rcvd route-refresh (REQUEST) for %s/%s before EoR", - peer->host, afi2str(afi), - safi2str(safi)); + "%s(%s) rcvd route-refresh (REQUEST) for %s/%s before EoR", + peer->host, + bgp_peer_hostname(peer), + afi2str(afi), safi2str(safi)); return BGP_PACKET_NOOP; } @@ -2365,9 +2383,9 @@ static int bgp_route_refresh_receive(struct peer *peer, bgp_size_t size) if (bgp_debug_neighbor_events(peer)) zlog_debug( - "%s sending route-refresh (BoRR) for %s/%s", - peer->host, afi2str(afi), - safi2str(safi)); + "%s(%s) sending route-refresh (BoRR) for %s/%s", + peer->host, bgp_peer_hostname(peer), + afi2str(afi), safi2str(safi)); /* Set flag Ready-To-Send to know when we can send EoRR * message. diff --git a/bgpd/bgp_route.c b/bgpd/bgp_route.c index 78e4964d9f..7762af1b34 100644 --- a/bgpd/bgp_route.c +++ b/bgpd/bgp_route.c @@ -3433,9 +3433,9 @@ bool bgp_maximum_prefix_overflow(struct peer *peer, afi_t afi, safi_t safi, return false; zlog_info( - "%%MAXPFXEXCEED: No. of %s prefix received from %s %u exceed, limit %u", - get_afi_safi_str(afi, safi, false), peer->host, pcount, - peer->pmax[afi][safi]); + "%%MAXPFXEXCEED: No. of %s prefix received from %s(%s) %u exceed, limit %u", + get_afi_safi_str(afi, safi, false), peer->host, + bgp_peer_hostname(peer), pcount, peer->pmax[afi][safi]); SET_FLAG(peer->af_sflags[afi][safi], PEER_STATUS_PREFIX_LIMIT); if (CHECK_FLAG(peer->af_flags[afi][safi], @@ -3473,8 +3473,9 @@ bool bgp_maximum_prefix_overflow(struct peer *peer, afi_t afi, safi_t safi, if (bgp_debug_neighbor_events(peer)) zlog_debug( - "%s Maximum-prefix restart timer started for %d secs", - peer->host, peer->v_pmax_restart); + "%s(%s) Maximum-prefix restart timer started for %d secs", + peer->host, bgp_peer_hostname(peer), + peer->v_pmax_restart); BGP_TIMER_ON(peer->t_pmax_restart, bgp_maximum_prefix_restart_timer, diff --git a/bgpd/bgpd.c b/bgpd/bgpd.c index 38a106359e..caf64600ce 100644 --- a/bgpd/bgpd.c +++ b/bgpd/bgpd.c @@ -2347,15 +2347,15 @@ void peer_nsf_stop(struct peer *peer) if (peer->t_gr_restart) { BGP_TIMER_OFF(peer->t_gr_restart); if (bgp_debug_neighbor_events(peer)) - zlog_debug("%s graceful restart timer stopped", - peer->host); + zlog_debug("%s(%s) graceful restart timer stopped", + peer->host, bgp_peer_hostname(peer)); } if (peer->t_gr_stale) { BGP_TIMER_OFF(peer->t_gr_stale); if (bgp_debug_neighbor_events(peer)) zlog_debug( - "%s graceful restart stalepath timer stopped", - peer->host); + "%s(%s) graceful restart stalepath timer stopped", + peer->host, bgp_peer_hostname(peer)); } bgp_clear_route_all(peer); } @@ -4294,8 +4294,9 @@ static void peer_flag_modify_action(struct peer *peer, uint32_t flag) BGP_TIMER_OFF(peer->t_pmax_restart); if (bgp_debug_neighbor_events(peer)) zlog_debug( - "%s Maximum-prefix restart timer canceled", - peer->host); + "%s(%s) Maximum-prefix restart timer canceled", + peer->host, + bgp_peer_hostname(peer)); } if (BGP_IS_VALID_STATE_FOR_NOTIF(peer->status)) { @@ -7185,8 +7186,9 @@ static bool peer_maximum_prefix_clear_overflow(struct peer *peer) if (peer->t_pmax_restart) { BGP_TIMER_OFF(peer->t_pmax_restart); if (bgp_debug_neighbor_events(peer)) - zlog_debug("%s Maximum-prefix restart timer cancelled", - peer->host); + zlog_debug( + "%s(%s) Maximum-prefix restart timer cancelled", + peer->host, bgp_peer_hostname(peer)); } BGP_EVENT_ADD(peer, BGP_Start); return true; diff --git a/bgpd/bgpd.h b/bgpd/bgpd.h index a9475f39a7..2a34ce6a14 100644 --- a/bgpd/bgpd.h +++ b/bgpd/bgpd.h @@ -2469,6 +2469,11 @@ static inline bool bgp_in_graceful_shutdown(struct bgp *bgp) !!CHECK_FLAG(bm->flags, BM_FLAG_GRACEFUL_SHUTDOWN)); } +static inline const char *bgp_peer_hostname(struct peer *peer) +{ + return peer->hostname ? peer->hostname : "Unknown"; +} + /* For benefit of rfapi */ extern struct peer *peer_new(struct bgp *bgp);