bgpd: Enhance path selection logs

Signed-off-by: Vivek Venkatraman <vivek@cumulusnetworks.com>
Reviewed-by:   Donald Sharp <sharpd@cumulusnetworks.com>
Reviewed-by:   Daniel Walton <dwalton@cumulusnetworks.com>

Ticket: CM-12390
Reviewed By: CCR-5136
Testing Done: Manual

(cherry picked from commit a6086ad408)

bgpd/bgp_mpath.c

@@ -467,6 +467,11 @@ bgp_info_mpath_update (struct bgp_node *rn, struct bgp_info *new_best,
       bgp_info_mpath_dequeue (old_best);
     }
 
+  if (debug)
+    zlog_debug("%s: starting mpath update, newbest %s num candidates %d old-mpath-count %d",
+               pfx_buf, new_best ? new_best->peer->host : "NONE",
+               listcount (mp_list), old_mpath_count);
+
   /*
    * We perform an ordered walk through both lists in parallel.
    * The reason for the ordered walk is that if there are paths
@@ -480,6 +485,8 @@ bgp_info_mpath_update (struct bgp_node *rn, struct bgp_info *new_best,
    */
   while (mp_node || cur_mpath)
     {
+      struct bgp_info *tmp_info;
+
       /*
        * We can bail out of this loop if all existing paths on the
        * multipath list have been visited (for cleanup purposes) and
@@ -490,6 +497,12 @@ bgp_info_mpath_update (struct bgp_node *rn, struct bgp_info *new_best,
 
       mp_next_node = mp_node ? listnextnode (mp_node) : NULL;
       next_mpath = cur_mpath ? bgp_info_mpath_next (cur_mpath) : NULL;
+      tmp_info = mp_node ? listgetdata (mp_node) : NULL;
+
+      if (debug)
+        zlog_debug("%s: comparing candidate %s with existing mpath %s",
+                   pfx_buf, tmp_info ? tmp_info->peer->host : "NONE",
+                   cur_mpath ? cur_mpath->peer->host : "NONE");
 
       /*
        * If equal, the path was a multipath and is still a multipath.
@@ -505,6 +518,12 @@ bgp_info_mpath_update (struct bgp_node *rn, struct bgp_info *new_best,
               bgp_info_mpath_enqueue (prev_mpath, cur_mpath);
               prev_mpath = cur_mpath;
               mpath_count++;
+              if (debug)
+                {
+                  bgp_info_path_with_addpath_rx_str(cur_mpath, path_buf);
+                  zlog_debug("%s: %s is still multipath, cur count %d",
+                             pfx_buf, path_buf, mpath_count);
+                }
             }
           else
             {
@@ -512,10 +531,11 @@ bgp_info_mpath_update (struct bgp_node *rn, struct bgp_info *new_best,
               if (debug)
                 {
                   bgp_info_path_with_addpath_rx_str(cur_mpath, path_buf);
-                  zlog_debug ("%s remove mpath nexthop %s %s", pfx_buf,
+                  zlog_debug ("%s: remove mpath %s nexthop %s, cur count %d",
+                              pfx_buf, path_buf,
                               inet_ntop (AF_INET, &cur_mpath->attr->nexthop,
                                          nh_buf[0], sizeof (nh_buf[0])),
-                              path_buf);
+                              mpath_count);
                 }
             }
           mp_node = mp_next_node;
@@ -538,10 +558,11 @@ bgp_info_mpath_update (struct bgp_node *rn, struct bgp_info *new_best,
           if (debug)
             {
               bgp_info_path_with_addpath_rx_str(cur_mpath, path_buf);
-              zlog_debug ("%s remove mpath nexthop %s %s", pfx_buf,
+              zlog_debug ("%s: remove mpath %s nexthop %s, cur count %d",
+                          pfx_buf, path_buf,
                           inet_ntop (AF_INET, &cur_mpath->attr->nexthop,
                                      nh_buf[0], sizeof (nh_buf[0])),
-                          path_buf);
+                          mpath_count);
             }
           cur_mpath = next_mpath;
         }
@@ -574,10 +595,11 @@ bgp_info_mpath_update (struct bgp_node *rn, struct bgp_info *new_best,
               if (debug)
                 {
                   bgp_info_path_with_addpath_rx_str(new_mpath, path_buf);
-                  zlog_debug ("%s add mpath nexthop %s %s", pfx_buf,
+                  zlog_debug ("%s: add mpath %s nexthop %s, cur count %d",
+                              pfx_buf, path_buf,
                               inet_ntop (AF_INET, &new_mpath->attr->nexthop,
                                          nh_buf[0], sizeof (nh_buf[0])),
-                              path_buf);
+                              mpath_count);
                 }
             }
           mp_node = mp_next_node;
@@ -586,6 +608,10 @@ bgp_info_mpath_update (struct bgp_node *rn, struct bgp_info *new_best,
 
   if (new_best)
     {
+      if (debug)
+        zlog_debug("%s: New mpath count (incl newbest) %d mpath-change %s",
+                   pfx_buf, mpath_count, mpath_changed ? "YES" : "NO");
+
       bgp_info_mpath_count_set (new_best, mpath_count-1);
       if (mpath_changed || (bgp_info_mpath_count (new_best) != old_mpath_count))
         SET_FLAG (new_best->flags, BGP_INFO_MULTIPATH_CHG);

bgpd/bgp_route.c

@@ -376,7 +376,11 @@ bgp_info_cmp (struct bgp *bgp, struct bgp_info *new, struct bgp_info *exist,
     }
 
   if (debug)
-    bgp_info_path_with_addpath_rx_str (exist, exist_buf);
+    {
+      bgp_info_path_with_addpath_rx_str (exist, exist_buf);
+      zlog_debug("%s: Comparing %s flags 0x%x with %s flags 0x%x",
+                 pfx_buf, new_buf, new->flags, exist_buf, exist->flags);
+    }
 
   newattr = new->attr;
   existattr = exist->attr;
@@ -705,6 +709,15 @@ bgp_info_cmp (struct bgp *bgp, struct bgp_info *new, struct bgp_info *exist,
        * TODO: If unequal cost ibgp multipath is enabled we can
        * mark the paths as equal here instead of returning
        */
+      if (debug)
+        {
+          if (ret == 1)
+            zlog_debug("%s: %s wins over %s after IGP metric comparison",
+                       pfx_buf, new_buf, exist_buf);
+          else
+            zlog_debug("%s: %s loses to %s after IGP metric comparison",
+                       pfx_buf, new_buf, exist_buf);
+        }
       return ret;
     }
 
@@ -1638,14 +1651,19 @@ bgp_best_selection (struct bgp *bgp, struct bgp_node *rn,
   /* Now that we know which path is the bestpath see if any of the other paths
    * qualify as multipaths
    */
+  if (debug)
+    {
+      if (new_select)
+        bgp_info_path_with_addpath_rx_str (new_select, path_buf);
+      else
+        sprintf (path_buf, "NONE");
+      zlog_debug("%s: After path selection, newbest is %s oldbest was %s",
+                 pfx_buf, path_buf,
+                 old_select ? old_select->peer->host : "NONE");
+    }
+
   if (do_mpath && new_select)
     {
-      if (debug)
-        {
-          bgp_info_path_with_addpath_rx_str (new_select, path_buf);
-          zlog_debug("%s: %s is the bestpath, now find multipaths", pfx_buf, path_buf);
-        }
-
       for (ri = rn->info; (ri != NULL) && (nextri = ri->next, 1); ri = nextri)
         {