bfdd: add debug fine tuning capabilities

Move most of the log messages to debug guards so they only get activated
if the user configured the proper debug level.

Current debug levels:
- Peer events.
- Zebra events.
- Network layer debugs.

Signed-off-by: Rafael Zalamena <rzalamena@opensourcerouting.org>

diff --git a/bfdd/bfd.c b/bfdd/bfd.c
index e1c662941bec9554e3a4ee87e848dd121b285b31..80bfae632f08bca9c488966170e42847c8b61162 100644 (file)
--- 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));
        }
 }
 
@@ -758,7 +762,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 +787,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 +855,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 +884,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 +916,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 +942,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 +966,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;
        }
 }
@@ -1433,12 +1443,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 +1461,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 +1473,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 +1499,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 +1691,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 +1709,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 +1729,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 +1788,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 a786bb71bc83837012447ad6f250e4c84499620f..1cc9ddb470b430245e6bfd987186000932540ffb 100644 (file)
--- 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[];

diff --git a/bfdd/bfd_packet.c b/bfdd/bfd_packet.c
index 79971fb3e25de10ba7ea1594ed6823a08125d322..68bdd89bb7a5e6c2cb99d3245d2ee2bb708fe0d6 100644 (file)
--- 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_vty.c b/bfdd/bfdd_vty.c
index 74ffd6d625b0a353cac3fc78e02c9c9190b5ce03..f539c6d2706e111dddc2c7e283a1f17adba01866 100644 (file)
--- 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/ptm_adapter.c b/bfdd/ptm_adapter.c
index eae2158acbd3a2b3f4d68c6703ac4a3bc3d7d1b7..0f1c4d06c0683d172359b5bb034d9944f086ca9e 100644 (file)
--- a/bfdd/ptm_adapter.c
+++ b/bfdd/ptm_adapter.c
@@ -419,8 +419,9 @@ static void bfdd_dest_register(struct stream *msg, vrf_id_t vrf_id)
        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 {
@@ -456,7 +457,8 @@ static void bfdd_dest_deregister(struct stream *msg, vrf_id_t vrf_id)
        /* 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;
        }
 
@@ -511,7 +513,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 +550,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 +679,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 +727,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 +746,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;