diff --git a/bfdd/bfd.c b/bfdd/bfd.c index e1c662941b..49cb586db1 100644 --- a/bfdd/bfd.c +++ b/bfdd/bfd.c @@ -169,7 +169,9 @@ int bfd_session_enable(struct bfd_session *bs) /* Sanity check: don't leak open sockets. */ if (bs->sock != -1) { - zlog_debug("session-enable: previous socket open"); + if (bglobal.debug_peer_event) + zlog_debug("session-enable: previous socket open"); + close(bs->sock); bs->sock = -1; } @@ -318,9 +320,10 @@ void ptm_bfd_sess_up(struct bfd_session *bfd) if (old_state != bfd->ses_state) { bfd->stats.session_up++; - zlog_debug("state-change: [%s] %s -> %s", bs_to_string(bfd), - state_list[old_state].str, - state_list[bfd->ses_state].str); + if (bglobal.debug_peer_event) + zlog_debug("state-change: [%s] %s -> %s", + bs_to_string(bfd), state_list[old_state].str, + state_list[bfd->ses_state].str); } } @@ -357,10 +360,11 @@ void ptm_bfd_sess_dn(struct bfd_session *bfd, uint8_t diag) if (old_state != bfd->ses_state) { bfd->stats.session_down++; - zlog_debug("state-change: [%s] %s -> %s reason:%s", - bs_to_string(bfd), state_list[old_state].str, - state_list[bfd->ses_state].str, - get_diag_str(bfd->local_diag)); + if (bglobal.debug_peer_event) + zlog_debug("state-change: [%s] %s -> %s reason:%s", + bs_to_string(bfd), state_list[old_state].str, + state_list[bfd->ses_state].str, + get_diag_str(bfd->local_diag)); } } @@ -522,8 +526,7 @@ int bfd_session_update_label(struct bfd_session *bs, const char *nlabel) return -1; } - if (pl_new(nlabel, bs) == NULL) - return -1; + pl_new(nlabel, bs); return 0; } @@ -681,10 +684,6 @@ struct bfd_session *ptm_bfd_sess_new(struct bfd_peer_cfg *bpc) /* Get BFD session storage with its defaults. */ bfd = bfd_session_new(); - if (bfd == NULL) { - zlog_err("session-new: allocation failed"); - return NULL; - } /* * Store interface/VRF name in case we need to delay session @@ -758,7 +757,8 @@ struct bfd_session *bs_registrate(struct bfd_session *bfd) if (bfd->key.ifname[0] || bfd->key.vrfname[0] || bfd->sock == -1) bs_observer_add(bfd); - zlog_debug("session-new: %s", bs_to_string(bfd)); + if (bglobal.debug_peer_event) + zlog_debug("session-new: %s", bs_to_string(bfd)); control_notify_config(BCM_NOTIFY_CONFIG_ADD, bfd); @@ -782,7 +782,8 @@ int ptm_bfd_sess_del(struct bfd_peer_cfg *bpc) return -1; } - zlog_debug("session-delete: %s", bs_to_string(bs)); + if (bglobal.debug_peer_event) + zlog_debug("session-delete: %s", bs_to_string(bs)); control_notify_config(BCM_NOTIFY_CONFIG_DELETE, bs); @@ -849,8 +850,9 @@ static void bs_down_handler(struct bfd_session *bs, int nstate) break; default: - zlog_debug("state-change: unhandled neighbor state: %d", - nstate); + if (bglobal.debug_peer_event) + zlog_debug("state-change: unhandled neighbor state: %d", + nstate); break; } } @@ -877,8 +879,9 @@ static void bs_init_handler(struct bfd_session *bs, int nstate) break; default: - zlog_debug("state-change: unhandled neighbor state: %d", - nstate); + if (bglobal.debug_peer_event) + zlog_debug("state-change: unhandled neighbor state: %d", + nstate); break; } } @@ -908,11 +911,11 @@ static void bs_neighbour_admin_down_handler(struct bfd_session *bfd, if (old_state != bfd->ses_state) { bfd->stats.session_down++; - - zlog_debug("state-change: [%s] %s -> %s reason:%s", - bs_to_string(bfd), state_list[old_state].str, - state_list[bfd->ses_state].str, - get_diag_str(bfd->local_diag)); + if (bglobal.debug_peer_event) + zlog_debug("state-change: [%s] %s -> %s reason:%s", + bs_to_string(bfd), state_list[old_state].str, + state_list[bfd->ses_state].str, + get_diag_str(bfd->local_diag)); } } @@ -934,8 +937,9 @@ static void bs_up_handler(struct bfd_session *bs, int nstate) break; default: - zlog_debug("state-change: unhandled neighbor state: %d", - nstate); + if (bglobal.debug_peer_event) + zlog_debug("state-change: unhandled neighbor state: %d", + nstate); break; } } @@ -957,8 +961,9 @@ void bs_state_handler(struct bfd_session *bs, int nstate) break; default: - zlog_debug("state-change: [%s] is in invalid state: %d", - bs_to_string(bs), nstate); + if (bglobal.debug_peer_event) + zlog_debug("state-change: [%s] is in invalid state: %d", + bs_to_string(bs), nstate); break; } } @@ -1106,13 +1111,13 @@ static const char *get_diag_str(int diag) return "N/A"; } -const char *satostr(struct sockaddr_any *sa) +const char *satostr(const struct sockaddr_any *sa) { #define INETSTR_BUFCOUNT 8 static char buf[INETSTR_BUFCOUNT][INET6_ADDRSTRLEN]; static int bufidx; - struct sockaddr_in *sin = &sa->sa_sin; - struct sockaddr_in6 *sin6 = &sa->sa_sin6; + const struct sockaddr_in *sin = &sa->sa_sin; + const struct sockaddr_in6 *sin6 = &sa->sa_sin6; bufidx += (bufidx + 1) % INETSTR_BUFCOUNT; buf[bufidx][0] = 0; @@ -1433,12 +1438,14 @@ struct bfd_session *bfd_key_lookup(struct bfd_key key) memset(&bs.key.local, 0, sizeof(bs.key.local)); bsp = hash_lookup(bfd_key_hash, &bs); if (bsp) { - char addr_buf[INET6_ADDRSTRLEN]; - - inet_ntop(bs.key.family, &key.local, addr_buf, - sizeof(addr_buf)); - zlog_debug(" peer %s found, but loc-addr %s ignored", - peer_buf, addr_buf); + if (bglobal.debug_peer_event) { + char addr_buf[INET6_ADDRSTRLEN]; + inet_ntop(bs.key.family, &key.local, addr_buf, + sizeof(addr_buf)); + zlog_debug( + " peer %s found, but loc-addr %s ignored", + peer_buf, addr_buf); + } return bsp; } } @@ -1449,8 +1456,9 @@ struct bfd_session *bfd_key_lookup(struct bfd_key key) memset(bs.key.ifname, 0, sizeof(bs.key.ifname)); bsp = hash_lookup(bfd_key_hash, &bs); if (bsp) { - zlog_debug(" peer %s found, but ifp %s ignored", - peer_buf, key.ifname); + if (bglobal.debug_peer_event) + zlog_debug(" peer %s found, but ifp %s ignored", + peer_buf, key.ifname); return bsp; } } @@ -1460,14 +1468,15 @@ struct bfd_session *bfd_key_lookup(struct bfd_key key) memset(&bs.key.local, 0, sizeof(bs.key.local)); bsp = hash_lookup(bfd_key_hash, &bs); if (bsp) { - char addr_buf[INET6_ADDRSTRLEN]; - - inet_ntop(bs.key.family, &bs.key.local, addr_buf, - sizeof(addr_buf)); - zlog_debug( - " peer %s found, but ifp %s" - " and loc-addr %s ignored", - peer_buf, key.ifname, addr_buf); + if (bglobal.debug_peer_event) { + char addr_buf[INET6_ADDRSTRLEN]; + inet_ntop(bs.key.family, &bs.key.local, + addr_buf, sizeof(addr_buf)); + zlog_debug( + " peer %s found, but ifp %s" + " and loc-addr %s ignored", + peer_buf, key.ifname, addr_buf); + } return bsp; } } @@ -1485,10 +1494,11 @@ struct bfd_session *bfd_key_lookup(struct bfd_key key) /* change key */ if (ctx.result) { bsp = ctx.result; - zlog_debug( - " peer %s found, but ifp" - " and/or loc-addr params ignored", - peer_buf); + if (bglobal.debug_peer_event) + zlog_debug( + " peer %s found, but ifp" + " and/or loc-addr params ignored", + peer_buf); } return bsp; } @@ -1676,13 +1686,17 @@ void bfd_sessions_remove_manual(void) */ static int bfd_vrf_new(struct vrf *vrf) { - zlog_debug("VRF Created: %s(%u)", vrf->name, vrf->vrf_id); + if (bglobal.debug_zebra) + zlog_debug("VRF Created: %s(%u)", vrf->name, vrf->vrf_id); + return 0; } static int bfd_vrf_delete(struct vrf *vrf) { - zlog_debug("VRF Deletion: %s(%u)", vrf->name, vrf->vrf_id); + if (bglobal.debug_zebra) + zlog_debug("VRF Deletion: %s(%u)", vrf->name, vrf->vrf_id); + return 0; } @@ -1690,7 +1704,10 @@ static int bfd_vrf_update(struct vrf *vrf) { if (!vrf_is_enabled(vrf)) return 0; - zlog_debug("VRF update: %s(%u)", vrf->name, vrf->vrf_id); + + if (bglobal.debug_zebra) + zlog_debug("VRF update: %s(%u)", vrf->name, vrf->vrf_id); + /* a different name is given; update bfd list */ bfdd_sessions_enable_vrf(vrf); return 0; @@ -1707,7 +1724,10 @@ static int bfd_vrf_enable(struct vrf *vrf) vrf->info = (void *)bvrf; } else bvrf = vrf->info; - zlog_debug("VRF enable add %s id %u", vrf->name, vrf->vrf_id); + + if (bglobal.debug_zebra) + zlog_debug("VRF enable add %s id %u", vrf->name, vrf->vrf_id); + if (vrf->vrf_id == VRF_DEFAULT || vrf_get_backend() == VRF_BACKEND_NETNS) { if (!bvrf->bg_shop) @@ -1763,7 +1783,8 @@ static int bfd_vrf_disable(struct vrf *vrf) bfdd_zclient_unregister(vrf->vrf_id); } - zlog_debug("VRF disable %s id %d", vrf->name, vrf->vrf_id); + if (bglobal.debug_zebra) + zlog_debug("VRF disable %s id %d", vrf->name, vrf->vrf_id); /* Disable read/write poll triggering. */ THREAD_OFF(bvrf->bg_ev[0]); diff --git a/bfdd/bfd.h b/bfdd/bfd.h index a786bb71bc..93873eed94 100644 --- a/bfdd/bfd.h +++ b/bfdd/bfd.h @@ -393,7 +393,26 @@ struct bfd_global { struct obslist bg_obslist; struct zebra_privs_t bfdd_privs; + + /* Debug options. */ + /* Show all peer state changes events. */ + bool debug_peer_event; + /* + * Show zebra message exchanges: + * - Interface add/delete. + * - Local address add/delete. + * - VRF add/delete. + */ + bool debug_zebra; + /* + * Show network level debug information: + * - Echo packets without session. + * - Unavailable peer sessions. + * - Network system call failures. + */ + bool debug_network; }; + extern struct bfd_global bglobal; extern const struct bfd_diag_str_list diag_list[]; extern const struct bfd_state_str_list state_list[]; @@ -510,7 +529,7 @@ void bs_state_handler(struct bfd_session *bs, int nstate); void bs_echo_timer_handler(struct bfd_session *bs); void bs_final_handler(struct bfd_session *bs); void bs_set_slow_timers(struct bfd_session *bs); -const char *satostr(struct sockaddr_any *sa); +const char *satostr(const struct sockaddr_any *sa); const char *diag2str(uint8_t diag); int strtosa(const char *addr, struct sockaddr_any *sa); void integer2timestr(uint64_t time, char *buf, size_t buflen); diff --git a/bfdd/bfd_packet.c b/bfdd/bfd_packet.c index 79971fb3e2..68bdd89bb7 100644 --- a/bfdd/bfd_packet.c +++ b/bfdd/bfd_packet.c @@ -112,11 +112,16 @@ int _ptm_bfd_send(struct bfd_session *bs, uint16_t *port, const void *data, #endif /* HAVE_STRUCT_SOCKADDR_SA_LEN */ rv = sendto(sd, data, datalen, 0, sa, slen); if (rv <= 0) { - zlog_debug("packet-send: send failure: %s", strerror(errno)); + if (bglobal.debug_network) + zlog_debug("packet-send: send failure: %s", + strerror(errno)); return -1; } - if (rv < (ssize_t)datalen) - zlog_debug("packet-send: send partial: %s", strerror(errno)); + if (rv < (ssize_t)datalen) { + if (bglobal.debug_network) + zlog_debug("packet-send: send partial: %s", + strerror(errno)); + } return 0; } @@ -190,14 +195,16 @@ static int ptm_bfd_process_echo_pkt(struct bfd_vrf_global *bvrf, int s) /* Your discriminator not zero - use it to find session */ bfd = bfd_id_lookup(my_discr); if (bfd == NULL) { - zlog_debug("echo-packet: no matching session (id:%u)", - my_discr); + if (bglobal.debug_network) + zlog_debug("echo-packet: no matching session (id:%u)", + my_discr); return -1; } if (!CHECK_FLAG(bfd->flags, BFD_SESS_FLAG_ECHO_ACTIVE)) { - zlog_debug("echo-packet: echo disabled [%s] (id:%u)", - bs_to_string(bfd), my_discr); + if (bglobal.debug_network) + zlog_debug("echo-packet: echo disabled [%s] (id:%u)", + bs_to_string(bfd), my_discr); return -1; } @@ -313,8 +320,9 @@ ssize_t bfd_recv_ipv4(int sd, uint8_t *msgbuf, size_t msgbuflen, uint8_t *ttl, memcpy(&ttlval, CMSG_DATA(cm), sizeof(ttlval)); if (ttlval > 255) { - zlog_debug("ipv4-recv: invalid TTL: %u", - ttlval); + if (bglobal.debug_network) + zlog_debug("ipv4-recv: invalid TTL: %u", + ttlval); return -1; } *ttl = ttlval; @@ -420,8 +428,9 @@ ssize_t bfd_recv_ipv6(int sd, uint8_t *msgbuf, size_t msgbuflen, uint8_t *ttl, if (cm->cmsg_type == IPV6_HOPLIMIT) { memcpy(&ttlval, CMSG_DATA(cm), sizeof(ttlval)); if (ttlval > 255) { - zlog_debug("ipv6-recv: invalid TTL: %u", - ttlval); + if (bglobal.debug_network) + zlog_debug("ipv6-recv: invalid TTL: %u", + ttlval); return -1; } @@ -487,6 +496,10 @@ static void cp_debug(bool mhop, struct sockaddr_any *peer, char buf[512], peerstr[128], localstr[128], portstr[64], vrfstr[64]; va_list vl; + /* Don't to any processing if debug is disabled. */ + if (bglobal.debug_network == false) + return; + if (peer->sa_sin.sin_family) snprintf(peerstr, sizeof(peerstr), " peer:%s", satostr(peer)); else @@ -797,12 +810,14 @@ int bp_udp_send(int sd, uint8_t ttl, uint8_t *data, size_t datalen, /* Send echo back. */ wlen = sendmsg(sd, &msg, 0); if (wlen <= 0) { - zlog_debug("udp-send: loopback failure: (%d) %s", errno, - strerror(errno)); + if (bglobal.debug_network) + zlog_debug("udp-send: loopback failure: (%d) %s", errno, + strerror(errno)); return -1; } else if (wlen < (ssize_t)datalen) { - zlog_debug("udp-send: partial send: %zd expected %zu", wlen, - datalen); + if (bglobal.debug_network) + zlog_debug("udp-send: partial send: %zd expected %zu", + wlen, datalen); return -1; } diff --git a/bfdd/bfdd_nb_config.c b/bfdd/bfdd_nb_config.c index c1123c4c33..7b95bd23c6 100644 --- a/bfdd/bfdd_nb_config.c +++ b/bfdd/bfdd_nb_config.c @@ -107,8 +107,6 @@ static int bfd_session_create(enum nb_event event, const struct lyd_node *dnode, } bs = bfd_session_new(); - if (bs == NULL) - return NB_ERR_RESOURCE; /* Fill the session key. */ bfd_session_get_key(mhop, dnode, &bs->key); diff --git a/bfdd/bfdd_vty.c b/bfdd/bfdd_vty.c index 74ffd6d625..f539c6d270 100644 --- a/bfdd/bfdd_vty.c +++ b/bfdd/bfdd_vty.c @@ -738,6 +738,42 @@ DEFPY(bfd_show_peers_brief, bfd_show_peers_brief_cmd, return CMD_SUCCESS; } +DEFPY( + bfd_debug_peer, bfd_debug_peer_cmd, + "[no] debug bfd peer", + NO_STR + DEBUG_STR + "Bidirection Forwarding Detection\n" + "Peer events debugging\n") +{ + bglobal.debug_peer_event = !no; + return CMD_SUCCESS; +} + +DEFPY( + bfd_debug_zebra, bfd_debug_zebra_cmd, + "[no] debug bfd zebra", + NO_STR + DEBUG_STR + "Bidirection Forwarding Detection\n" + "Zebra events debugging\n") +{ + bglobal.debug_zebra = !no; + return CMD_SUCCESS; +} + +DEFPY( + bfd_debug_network, bfd_debug_network_cmd, + "[no] debug bfd network", + NO_STR + DEBUG_STR + "Bidirection Forwarding Detection\n" + "Network layer debugging\n") +{ + bglobal.debug_network = !no; + return CMD_SUCCESS; +} + /* * Function definitions. */ @@ -842,6 +878,9 @@ DEFUN_NOSH(show_debugging_bfd, "BFD daemon\n") { vty_out(vty, "BFD debugging status:\n"); + vty_out(vty, " Peer events debugging.\n"); + vty_out(vty, " Zebra events debugging.\n"); + vty_out(vty, " Network layer debugging.\n"); return CMD_SUCCESS; } @@ -863,6 +902,21 @@ static int bfdd_write_config(struct vty *vty) struct lyd_node *dnode; int written = 0; + if (bglobal.debug_peer_event) { + vty_out(vty, "debug bfd peer\n"); + written = 1; + } + + if (bglobal.debug_zebra) { + vty_out(vty, "debug bfd zebra\n"); + written = 1; + } + + if (bglobal.debug_network) { + vty_out(vty, "debug bfd network\n"); + written = 1; + } + dnode = yang_dnode_get(running_config->dnode, "/frr-bfdd:bfdd"); if (dnode) { nb_cli_show_dnode_cmds(vty, dnode, false); @@ -882,6 +936,14 @@ void bfdd_vty_init(void) install_element(ENABLE_NODE, &bfd_show_peers_brief_cmd); install_element(ENABLE_NODE, &show_debugging_bfd_cmd); + install_element(ENABLE_NODE, &bfd_debug_peer_cmd); + install_element(ENABLE_NODE, &bfd_debug_zebra_cmd); + install_element(ENABLE_NODE, &bfd_debug_network_cmd); + + install_element(CONFIG_NODE, &bfd_debug_peer_cmd); + install_element(CONFIG_NODE, &bfd_debug_zebra_cmd); + install_element(CONFIG_NODE, &bfd_debug_network_cmd); + /* Install BFD node and commands. */ install_node(&bfd_node, bfdd_write_config); install_default(BFD_NODE); diff --git a/bfdd/control.c b/bfdd/control.c index 4adc54a64a..3b954c64f8 100644 --- a/bfdd/control.c +++ b/bfdd/control.c @@ -168,8 +168,7 @@ int control_accept(struct thread *t) return 0; } - if (control_new(csock) == NULL) - close(csock); + control_new(csock); bglobal.bg_csockev = NULL; thread_add_read(master, control_accept, NULL, sd, &bglobal.bg_csockev); @@ -334,8 +333,6 @@ static int control_queue_enqueue(struct bfd_control_socket *bcs, struct bfd_control_buffer *bcb; bcq = control_queue_new(bcs); - if (bcq == NULL) - return -1; bcb = &bcq->bcq_bcb; bcb->bcb_left = sizeof(struct bfd_control_msg) + ntohl(bcm->bcm_length); @@ -656,8 +653,7 @@ static int notify_add_cb(struct bfd_peer_cfg *bpc, void *arg) if (bs == NULL) return -1; - if (control_notifypeer_new(bcs, bs) == NULL) - return -1; + control_notifypeer_new(bcs, bs); /* Notify peer status. */ _control_notify(bcs, bs); diff --git a/bfdd/event.c b/bfdd/event.c index 686f39cc0a..654928b9b3 100644 --- a/bfdd/event.c +++ b/bfdd/event.c @@ -48,10 +48,6 @@ void bfd_recvtimer_update(struct bfd_session *bs) return; tv_normalize(&tv); -#ifdef BFD_EVENT_DEBUG - zlog_debug("%s: sec = %ld, usec = %ld", __func__, tv.tv_sec, - tv.tv_usec); -#endif /* BFD_EVENT_DEBUG */ thread_add_timer_tv(master, bfd_recvtimer_cb, bs, &tv, &bs->recvtimer_ev); @@ -70,10 +66,6 @@ void bfd_echo_recvtimer_update(struct bfd_session *bs) return; tv_normalize(&tv); -#ifdef BFD_EVENT_DEBUG - zlog_debug("%s: sec = %ld, usec = %ld", __func__, tv.tv_sec, - tv.tv_usec); -#endif /* BFD_EVENT_DEBUG */ thread_add_timer_tv(master, bfd_echo_recvtimer_cb, bs, &tv, &bs->echo_recvtimer_ev); @@ -92,10 +84,6 @@ void bfd_xmttimer_update(struct bfd_session *bs, uint64_t jitter) return; tv_normalize(&tv); -#ifdef BFD_EVENT_DEBUG - zlog_debug("%s: sec = %ld, usec = %ld", __func__, tv.tv_sec, - tv.tv_usec); -#endif /* BFD_EVENT_DEBUG */ thread_add_timer_tv(master, bfd_xmt_cb, bs, &tv, &bs->xmttimer_ev); } @@ -113,10 +101,6 @@ void bfd_echo_xmttimer_update(struct bfd_session *bs, uint64_t jitter) return; tv_normalize(&tv); -#ifdef BFD_EVENT_DEBUG - zlog_debug("%s: sec = %ld, usec = %ld", __func__, tv.tv_sec, - tv.tv_usec); -#endif /* BFD_EVENT_DEBUG */ thread_add_timer_tv(master, bfd_echo_xmt_cb, bs, &tv, &bs->echo_xmttimer_ev); diff --git a/bfdd/ptm_adapter.c b/bfdd/ptm_adapter.c index eae2158acb..4c88922b8a 100644 --- a/bfdd/ptm_adapter.c +++ b/bfdd/ptm_adapter.c @@ -80,19 +80,17 @@ static void bfdd_client_deregister(struct stream *msg); /* * Functions */ -#ifdef BFD_DEBUG -static void debug_printbpc(const char *func, unsigned int line, - struct bfd_peer_cfg *bpc); - -static void debug_printbpc(const char *func, unsigned int line, - struct bfd_peer_cfg *bpc) +static void debug_printbpc(const struct bfd_peer_cfg *bpc, const char *fmt, ...) { - char addr[3][128]; - char timers[3][128]; - char cbit_str[10]; + char timers[3][128] = {}; + char addr[3][128] = {}; + char cbit_str[32]; + char msgbuf[256]; + va_list vl; - addr[0][0] = addr[1][0] = addr[2][0] = timers[0][0] = timers[1][0] = - timers[2][0] = 0; + /* Avoid debug calculations if it's disabled. */ + if (bglobal.debug_zebra == false) + return; snprintf(addr[0], sizeof(addr[0]), "peer:%s", satostr(&bpc->bpc_peer)); if (bpc->bpc_local.sa_sin.sin_family) @@ -107,29 +105,28 @@ static void debug_printbpc(const char *func, unsigned int line, snprintf(addr[2], sizeof(addr[2]), " vrf:%s", bpc->bpc_vrfname); if (bpc->bpc_has_recvinterval) - snprintf(timers[0], sizeof(timers[0]), " rx:%lu", + snprintf(timers[0], sizeof(timers[0]), " rx:%" PRIu64, bpc->bpc_recvinterval); if (bpc->bpc_has_txinterval) - snprintf(timers[1], sizeof(timers[1]), " tx:%lu", + snprintf(timers[1], sizeof(timers[1]), " tx:%" PRIu64, bpc->bpc_recvinterval); if (bpc->bpc_has_detectmultiplier) snprintf(timers[2], sizeof(timers[2]), " detect-multiplier:%d", bpc->bpc_detectmultiplier); - sprintf(cbit_str, "CB %x", bpc->bpc_cbit); + snprintf(cbit_str, sizeof(cbit_str), " cbit:0x%02x", bpc->bpc_cbit); - zlog_debug("%s:%d: %s %s%s%s%s%s%s %s", func, line, - bpc->bpc_mhop ? "multi-hop" : "single-hop", addr[0], addr[1], - addr[2], timers[0], timers[1], timers[2], cbit_str); + va_start(vl, fmt); + vsnprintf(msgbuf, sizeof(msgbuf), fmt, vl); + va_end(vl); + + zlog_debug("%s [mhop:%s %s%s%s%s%s%s%s]", msgbuf, + bpc->bpc_mhop ? "yes" : "no", addr[0], addr[1], addr[2], + timers[0], timers[1], timers[2], cbit_str); } -#define DEBUG_PRINTBPC(bpc) debug_printbpc(__FILE__, __LINE__, (bpc)) -#else -#define DEBUG_PRINTBPC(bpc) -#endif /* BFD_DEBUG */ - static int _ptm_msg_address(struct stream *msg, int family, const void *addr) { stream_putc(msg, family); @@ -315,10 +312,6 @@ static int _ptm_msg_read(struct stream *msg, int command, vrf_id_t vrf_id, STREAM_GETL(msg, pid); *pc = pc_new(pid); - if (*pc == NULL) { - zlog_debug("ptm-read: failed to allocate memory"); - return -1; - } /* Register/update peer information. */ _ptm_msg_read_address(msg, &bpc->bpc_peer); @@ -404,7 +397,6 @@ stream_failure: static void bfdd_dest_register(struct stream *msg, vrf_id_t vrf_id) { struct ptm_client *pc; - struct ptm_client_notification *pcn; struct bfd_session *bs; struct bfd_peer_cfg bpc; @@ -412,15 +404,16 @@ static void bfdd_dest_register(struct stream *msg, vrf_id_t vrf_id) if (_ptm_msg_read(msg, ZEBRA_BFD_DEST_REGISTER, vrf_id, &bpc, &pc) == -1) return; - DEBUG_PRINTBPC(&bpc); + debug_printbpc(&bpc, "ptm-add-dest: register peer"); /* Find or start new BFD session. */ bs = bs_peer_find(&bpc); if (bs == NULL) { bs = ptm_bfd_sess_new(&bpc); if (bs == NULL) { - zlog_debug( - "ptm-add-dest: failed to create BFD session"); + if (bglobal.debug_zebra) + zlog_debug( + "ptm-add-dest: failed to create BFD session"); return; } } else { @@ -431,11 +424,7 @@ static void bfdd_dest_register(struct stream *msg, vrf_id_t vrf_id) } /* Create client peer notification register. */ - pcn = pcn_new(pc, bs); - if (pcn == NULL) { - zlog_err("ptm-add-dest: failed to registrate notifications"); - return; - } + pcn_new(pc, bs); ptm_bfd_notify(bs, bs->ses_state); } @@ -451,12 +440,13 @@ static void bfdd_dest_deregister(struct stream *msg, vrf_id_t vrf_id) if (_ptm_msg_read(msg, ZEBRA_BFD_DEST_DEREGISTER, vrf_id, &bpc, &pc) == -1) return; - DEBUG_PRINTBPC(&bpc); + debug_printbpc(&bpc, "ptm-del-dest: deregister peer"); /* Find or start new BFD session. */ bs = bs_peer_find(&bpc); if (bs == NULL) { - zlog_debug("ptm-del-dest: failed to find BFD session"); + if (bglobal.debug_zebra) + zlog_debug("ptm-del-dest: failed to find BFD session"); return; } @@ -479,17 +469,12 @@ static void bfdd_dest_deregister(struct stream *msg, vrf_id_t vrf_id) */ static void bfdd_client_register(struct stream *msg) { - struct ptm_client *pc; uint32_t pid; /* Find or allocate process context data. */ STREAM_GETL(msg, pid); - pc = pc_new(pid); - if (pc == NULL) { - zlog_err("ptm-add-client: failed to register client: %u", pid); - return; - } + pc_new(pid); return; @@ -511,7 +496,9 @@ static void bfdd_client_deregister(struct stream *msg) pc = pc_lookup(pid); if (pc == NULL) { - zlog_debug("ptm-del-client: failed to find client: %u", pid); + if (bglobal.debug_zebra) + zlog_debug("ptm-del-client: failed to find client: %u", + pid); return; } @@ -546,7 +533,8 @@ static int bfdd_replay(ZAPI_CALLBACK_ARGS) break; default: - zlog_debug("ptm-replay: invalid message type %u", rcmd); + if (bglobal.debug_zebra) + zlog_debug("ptm-replay: invalid message type %u", rcmd); return -1; } @@ -674,6 +662,9 @@ void bfdd_sessions_disable_vrf(struct vrf *vrf) static int bfd_ifp_destroy(struct interface *ifp) { + if (bglobal.debug_zebra) + zlog_debug("zclient: delete interface %s", ifp->name); + bfdd_sessions_disable_interface(ifp); return 0; @@ -719,11 +710,18 @@ static void bfdd_sessions_enable_address(struct connected *ifc) static int bfdd_interface_address_update(ZAPI_CALLBACK_ARGS) { struct connected *ifc; + char buf[64]; ifc = zebra_interface_address_read(cmd, zclient->ibuf, vrf_id); if (ifc == NULL) return 0; + if (bglobal.debug_zebra) + zlog_debug("zclient: %s local address %s", + cmd == ZEBRA_INTERFACE_ADDRESS_ADD ? "add" + : "delete", + prefix2str(ifc->address, buf, sizeof(buf))); + bfdd_sessions_enable_address(ifc); return 0; @@ -731,6 +729,9 @@ static int bfdd_interface_address_update(ZAPI_CALLBACK_ARGS) static int bfd_ifp_create(struct interface *ifp) { + if (bglobal.debug_zebra) + zlog_debug("zclient: add interface %s", ifp->name); + bfdd_sessions_enable_interface(ifp); return 0; diff --git a/doc/user/bfd.rst b/doc/user/bfd.rst index e6a3c4977a..32397d1303 100644 --- a/doc/user/bfd.rst +++ b/doc/user/bfd.rst @@ -476,13 +476,36 @@ You can also clear packet counters per session with the following commands, only Session down events: 0 Zebra notifications: 4 -Logging / debugging -=================== +Debugging +========= -There are no fine grained debug controls for bfdd. Just enable debug logs. +By default only informational, warning and errors messages are going to be +displayed. If you want to get debug messages and other diagnostics then make +sure you have `debugging` level enabled: :: config log file /var/log/frr/frr.log debugging log syslog debugging + +You may also fine tune the debug messages by selecting one or more of the +debug levels: + +.. index:: [no] debug bfd network +.. clicmd:: [no] debug bfd network + + Toggle network events: show messages about socket failures and unexpected + BFD messages that may not belong to registered peers. + +.. index:: [no] debug bfd peer +.. clicmd:: [no] debug bfd peer + + Toggle peer event log messages: show messages about peer creation/removal + and state changes. + +.. index:: [no] debug bfd zebra +.. clicmd:: [no] debug bfd zebra + + Toggle zebra message events: show messages about interfaces, local + addresses, VRF and daemon peer registrations. diff --git a/tests/topotests/bfd-bgp-cbit-topo3/r1/bfdd.conf b/tests/topotests/bfd-bgp-cbit-topo3/r1/bfdd.conf new file mode 100644 index 0000000000..f35e772790 --- /dev/null +++ b/tests/topotests/bfd-bgp-cbit-topo3/r1/bfdd.conf @@ -0,0 +1,5 @@ +! +debug bfd network +debug bfd peer +debug bfd zebra +! diff --git a/tests/topotests/bfd-bgp-cbit-topo3/r3/bfdd.conf b/tests/topotests/bfd-bgp-cbit-topo3/r3/bfdd.conf new file mode 100644 index 0000000000..f35e772790 --- /dev/null +++ b/tests/topotests/bfd-bgp-cbit-topo3/r3/bfdd.conf @@ -0,0 +1,5 @@ +! +debug bfd network +debug bfd peer +debug bfd zebra +! diff --git a/tests/topotests/bfd-topo1/r1/bfdd.conf b/tests/topotests/bfd-topo1/r1/bfdd.conf index 131b01f0d9..4102000337 100644 --- a/tests/topotests/bfd-topo1/r1/bfdd.conf +++ b/tests/topotests/bfd-topo1/r1/bfdd.conf @@ -1,3 +1,8 @@ +! +debug bfd network +debug bfd peer +debug bfd zebra +! bfd peer 192.168.0.2 echo-mode diff --git a/tests/topotests/bfd-topo1/r2/bfdd.conf b/tests/topotests/bfd-topo1/r2/bfdd.conf index cb4357172b..412450ca1e 100644 --- a/tests/topotests/bfd-topo1/r2/bfdd.conf +++ b/tests/topotests/bfd-topo1/r2/bfdd.conf @@ -1,3 +1,8 @@ +! +debug bfd network +debug bfd peer +debug bfd zebra +! bfd peer 192.168.0.1 receive-interval 1000 diff --git a/tests/topotests/bfd-topo1/r3/bfdd.conf b/tests/topotests/bfd-topo1/r3/bfdd.conf index a5d38c8162..4cf20bb904 100644 --- a/tests/topotests/bfd-topo1/r3/bfdd.conf +++ b/tests/topotests/bfd-topo1/r3/bfdd.conf @@ -1,3 +1,8 @@ +! +debug bfd network +debug bfd peer +debug bfd zebra +! bfd peer 192.168.1.2 echo-interval 100 diff --git a/tests/topotests/bfd-topo1/r4/bfdd.conf b/tests/topotests/bfd-topo1/r4/bfdd.conf index 029dfba355..34b88c9a35 100644 --- a/tests/topotests/bfd-topo1/r4/bfdd.conf +++ b/tests/topotests/bfd-topo1/r4/bfdd.conf @@ -1,3 +1,8 @@ +! +debug bfd network +debug bfd peer +debug bfd zebra +! bfd peer 192.168.2.2 transmit-interval 2000 diff --git a/tests/topotests/bfd-topo2/r1/bfdd.conf b/tests/topotests/bfd-topo2/r1/bfdd.conf index 5c2571bdbd..f03135021e 100644 --- a/tests/topotests/bfd-topo2/r1/bfdd.conf +++ b/tests/topotests/bfd-topo2/r1/bfdd.conf @@ -1,3 +1,8 @@ +! +debug bfd network +debug bfd peer +debug bfd zebra +! bfd peer 2001:db8:4::1 multihop local-address 2001:db8:1::1 no shutdown diff --git a/tests/topotests/bfd-topo2/r2/bfdd.conf b/tests/topotests/bfd-topo2/r2/bfdd.conf new file mode 100644 index 0000000000..f35e772790 --- /dev/null +++ b/tests/topotests/bfd-topo2/r2/bfdd.conf @@ -0,0 +1,5 @@ +! +debug bfd network +debug bfd peer +debug bfd zebra +! diff --git a/tests/topotests/bfd-topo2/r3/bfdd.conf b/tests/topotests/bfd-topo2/r3/bfdd.conf new file mode 100644 index 0000000000..f35e772790 --- /dev/null +++ b/tests/topotests/bfd-topo2/r3/bfdd.conf @@ -0,0 +1,5 @@ +! +debug bfd network +debug bfd peer +debug bfd zebra +! diff --git a/tests/topotests/bfd-topo2/r4/bfdd.conf b/tests/topotests/bfd-topo2/r4/bfdd.conf index fdb4412446..0173dc9be2 100644 --- a/tests/topotests/bfd-topo2/r4/bfdd.conf +++ b/tests/topotests/bfd-topo2/r4/bfdd.conf @@ -1,3 +1,8 @@ +! +debug bfd network +debug bfd peer +debug bfd zebra +! bfd peer 2001:db8:1::1 multihop local-address 2001:db8:4::1 no shutdown diff --git a/tests/topotests/bfd-vrf-topo1/r1/bfdd.conf b/tests/topotests/bfd-vrf-topo1/r1/bfdd.conf index 3466e6a3ca..5e736a7fcc 100644 --- a/tests/topotests/bfd-vrf-topo1/r1/bfdd.conf +++ b/tests/topotests/bfd-vrf-topo1/r1/bfdd.conf @@ -1,3 +1,8 @@ +! +debug bfd network +debug bfd peer +debug bfd zebra +! bfd peer 192.168.0.2 vrf r1-cust1 echo-mode diff --git a/tests/topotests/bfd-vrf-topo1/r2/bfdd.conf b/tests/topotests/bfd-vrf-topo1/r2/bfdd.conf index 3481ea8c87..94f502c7d9 100644 --- a/tests/topotests/bfd-vrf-topo1/r2/bfdd.conf +++ b/tests/topotests/bfd-vrf-topo1/r2/bfdd.conf @@ -1,3 +1,8 @@ +! +debug bfd network +debug bfd peer +debug bfd zebra +! bfd peer 192.168.0.1 vrf r2-cust1 receive-interval 1000 diff --git a/tests/topotests/bfd-vrf-topo1/r3/bfdd.conf b/tests/topotests/bfd-vrf-topo1/r3/bfdd.conf index f6921b7818..76910ac927 100644 --- a/tests/topotests/bfd-vrf-topo1/r3/bfdd.conf +++ b/tests/topotests/bfd-vrf-topo1/r3/bfdd.conf @@ -1,3 +1,8 @@ +! +debug bfd network +debug bfd peer +debug bfd zebra +! bfd peer 192.168.1.2 vrf r3-cust1 echo-interval 100 diff --git a/tests/topotests/bfd-vrf-topo1/r4/bfdd.conf b/tests/topotests/bfd-vrf-topo1/r4/bfdd.conf index a56a3a0d37..63d0da7805 100644 --- a/tests/topotests/bfd-vrf-topo1/r4/bfdd.conf +++ b/tests/topotests/bfd-vrf-topo1/r4/bfdd.conf @@ -1,3 +1,8 @@ +! +debug bfd network +debug bfd peer +debug bfd zebra +! bfd peer 192.168.2.2 vrf r4-cust1 transmit-interval 2000