Add some statistics and logging to aid in better debugging

That additional statistics is present in most of the bridge vendors:
 - Num TX and RX BPDU/TCN;
 - Num of transition to forwarding/blocking;
 - last 2 ports which caused topology change on the tree;
 - logged if TCN was sent/received in BPDU.

Signed-off-by: Satish Ashok <sashok@cumulusnetworks.com>
Signed-off-by: Vitalii Demianets <dvitasgs@gmail.com>
git-svn-id: svn://svn.code.sf.net/p/mstpd/code/trunk@51 fbe50366-0c72-4402-a84b-5d246361dba7

diff --git a/bridge_track.c b/bridge_track.c
index 51bc04ccefc75f6619c2bda82d9f3229d3ac7a4e..ed9019410fcaf0b135b16f8d43767351d787de81 100644 (file)
--- a/bridge_track.c
+++ b/bridge_track.c
@@ -470,9 +470,11 @@ void MSTP_OUT_set_state(per_tree_port_t *ptp, int new_state)
             break;
         case BR_STATE_FORWARDING:
             state_name = "forwarding";
+            ++(ifc->num_trans_fwd);
             break;
         case BR_STATE_BLOCKING:
             state_name = "blocking";
+            ++(ifc->num_trans_blk);
             break;
         default:
         case BR_STATE_DISABLED:
@@ -548,6 +550,7 @@ void MSTP_OUT_tx_bpdu(port_t * ifc, bpdu_t * bpdu, int size)
                     break;
                 case bpduTypeTCN:
                     bpdu_type = "STP-TCN";
+                    ++(ifc->num_tx_tcn);
                     break;
                 default:
                     bpdu_type = "STP-UnknownType";
@@ -563,7 +566,8 @@ void MSTP_OUT_tx_bpdu(port_t * ifc, bpdu_t * bpdu, int size)
             bpdu_type = "UnknownProto";
     }
 
-    LOG_PRTNAME(br, ifc, "sending %s BPDU", bpdu_type);
+    LOG_PRTNAME(br, ifc, "sending %s BPDU%s", bpdu_type,
+        (bpdu->flags & (1 << offsetTc)) ? ", tcFlag" : "");
 
     struct llc_header h;
     memcpy(h.dest_addr, bridge_group_address, ETH_ALEN);
@@ -577,7 +581,9 @@ void MSTP_OUT_tx_bpdu(port_t * ifc, bpdu_t * bpdu, int size)
         { .iov_base = &h, .iov_len = sizeof(h) },
         { .iov_base = bpdu, .iov_len = size }
     };
-
+    ++(ifc->num_tx_bpdu);
+    if(bpdu->flags & (1 << offsetTc))
+        ++(ifc->num_tx_tcn);
     packet_send(ifc->sysdeps.if_index, iov, 2, sizeof(h) + size);
 }
 

diff --git a/ctl_main.c b/ctl_main.c
index 67465c534f77d22a84399674c7b755de0f1781b0..97e0437489b6e380e629b1af6de99b1051d192ab 100644 (file)
--- a/ctl_main.c
+++ b/ctl_main.c
@@ -210,6 +210,10 @@ static int do_showbridge(const char *br_name, param_id_t param_id)
                    s.topology_change_count);
             printf("  topology change            %s\n",
                    BOOL_STR(s.topology_change));
+            printf("  topology change port       %s\n",
+                   s.topology_change_port);
+            printf("  last topology change port  %s\n",
+                   s.last_topology_change_port);
             break;
         case PARAM_ENABLED:
             printf("%s\n", BOOL_STR(s.enabled));
@@ -379,6 +383,8 @@ static int cmd_showtree(int argc, char *const *argv)
     printf("  time since topology change %u\n", s.time_since_topology_change);
     printf("  topology change count      %u\n", s.topology_change_count);
     printf("  topology change            %s\n", BOOL_STR(s.topology_change));
+    printf("  topology change port       %s\n", s.topology_change_port);
+    printf("  last topology change port  %s\n", s.last_topology_change_port);
 
     return 0;
 }
@@ -562,6 +568,12 @@ static int do_showport(int br_index, const char *bridge_name,
                        BOOL_STR(s.network_port));
                 printf("BA inconsistent      %s\n",
                        BOOL_STR(s.ba_inconsistent));
+                printf("  Num TX BPDU        %-23u ", s.num_tx_bpdu);
+                printf("Num TX TCN           %u\n", s.num_tx_tcn);
+                printf("  Num RX BPDU        %-23u ", s.num_rx_bpdu);
+                printf("Num RX TCN           %u\n", s.num_rx_tcn);
+                printf("  Num Transition FWD %-23u ", s.num_trans_fwd);
+                printf("Num Transition BLK   %u\n", s.num_trans_blk);
             }
             else
             {

diff --git a/mstp.c b/mstp.c
index 1869e31610f860fab3da3a9452268d000d9d8931..9d76287a7f9806355a142e0bf25fe89da0d2c82e 100644 (file)
--- a/mstp.c
+++ b/mstp.c
@@ -108,6 +108,8 @@ static void tree_default_internal_vars(tree_t *tree)
     tree->time_since_topology_change = 0;
     tree->topology_change_count = 0;
     tree->topology_change = false; /* since all tcWhile are initialized to 0 */
+    strncpy(tree->topology_change_port, "None", IFNAMSIZ);
+    strncpy(tree->last_topology_change_port, "None", IFNAMSIZ);
 
     /* The following are initialized in BEGIN state:
      *  - rootPortId, rootPriority, rootTimes: in Port Role Selection SM
@@ -123,6 +125,12 @@ static void port_default_internal_vars(port_t *prt)
     assign(prt->rapidAgeingWhile, 0u);
     assign(prt->brAssuRcvdInfoWhile, 0u);
     prt->BaInconsistent = false;
+    prt->num_rx_bpdu = 0;
+    prt->num_rx_tcn = 0;
+    prt->num_tx_bpdu = 0;
+    prt->num_tx_tcn = 0;
+    prt->num_trans_fwd = 0;
+    prt->num_trans_blk = 0;
 
     /* The following are initialized in BEGIN state:
      * - mdelayWhile. mcheck, sendRSTP: in Port Protocol Migration SM
@@ -478,6 +486,10 @@ void MSTP_IN_set_port_enable(port_t *prt, bool up, int speed, int duplex)
             prt->portEnabled = true;
             prt->BpduGuardError = false;
             prt->BaInconsistent = false;
+            prt->num_rx_bpdu = 0;
+            prt->num_rx_tcn = 0;
+            prt->num_tx_bpdu = 0;
+            prt->num_tx_tcn = 0;
             changed = true;
             /* When port is enabled, initialize bridge assurance timer,
              * so that enough time is given before port is put in
@@ -551,6 +563,12 @@ void MSTP_IN_rx_bpdu(port_t *prt, bpdu_t *bpdu, int size)
     int mstis_size;
     bridge_t *br = prt->bridge;
 
+    ++(prt->num_rx_bpdu);
+    if(bpdu->flags & (1 << offsetTc))
+        ++(prt->num_rx_tcn);
+    if(bpdu->bpduType == bpduTypeTCN)
+        ++(prt->num_rx_tcn);
+
     if(prt->BpduGuardPort)
     {
         prt->BpduGuardError = true;
@@ -593,7 +611,9 @@ bpdu_validation_failed:
                 goto bpdu_validation_failed;
             /* Valid Config BPDU */
             bpdu->protocolVersion = protoSTP;
-            LOG_PRTNAME(br, prt, "received Config BPDU");
+            LOG_PRTNAME(br, prt, "received Config BPDU%s",
+                        (bpdu->flags & (1 << offsetTc)) ? ", tcFlag" : ""
+                       );
             break;
         case bpduTypeRST:
             if(protoRSTP == bpdu->protocolVersion)
@@ -602,7 +622,9 @@ bpdu_validation_failed:
                     goto bpdu_validation_failed;
                 /* Valid RST BPDU */
                 /* bpdu->protocolVersion = protoRSTP; */
-                LOG_PRTNAME(br, prt, "received RST BPDU");
+                LOG_PRTNAME(br, prt, "received RST BPDU%s",
+                            (bpdu->flags & (1 << offsetTc)) ? ", tcFlag" : ""
+                           );
                 break;
             }
             if(protoMSTP > bpdu->protocolVersion)
@@ -633,8 +655,10 @@ bpdu_validation_failed:
             bpdu->protocolVersion = protoMSTP;
             prt->rcvdBpduNumOfMstis = mstis_size
                                       / sizeof(msti_configuration_message_t);
-            LOG_PRTNAME(br, prt, "received MST BPDU with %d MSTIs",
-                        prt->rcvdBpduNumOfMstis);
+            LOG_PRTNAME(br, prt, "received MST BPDU%s with %d MSTIs",
+                        (bpdu->flags & (1 << offsetTc)) ? ", tcFlag" : "",
+                        prt->rcvdBpduNumOfMstis
+                       );
             break;
         default:
             goto bpdu_validation_failed;
@@ -663,6 +687,10 @@ void MSTP_IN_get_cist_bridge_status(bridge_t *br, CIST_BridgeStatus *status)
            cist->time_since_topology_change);
     assign(status->topology_change_count, cist->topology_change_count);
     status->topology_change = cist->topology_change;
+    strncpy(status->topology_change_port, cist->topology_change_port,
+            IFNAMSIZ);
+    strncpy(status->last_topology_change_port, cist->last_topology_change_port,
+            IFNAMSIZ);
     assign(status->designated_root, cist->rootPriority.RootID);
     assign(status->root_path_cost,
            __be32_to_cpu(cist->rootPriority.ExtRootPathCost));
@@ -690,6 +718,10 @@ void MSTP_IN_get_msti_bridge_status(tree_t *tree, MSTI_BridgeStatus *status)
            tree->time_since_topology_change);
     assign(status->topology_change_count, tree->topology_change_count);
     status->topology_change = tree->topology_change;
+    strncpy(status->topology_change_port, tree->topology_change_port,
+            IFNAMSIZ);
+    strncpy(status->last_topology_change_port, tree->last_topology_change_port,
+            IFNAMSIZ);
     assign(status->regional_root, tree->rootPriority.RRootID);
     assign(status->internal_path_cost,
            __be32_to_cpu(tree->rootPriority.IntRootPathCost));
@@ -966,6 +998,12 @@ void MSTP_IN_get_cist_port_status(port_t *prt, CIST_PortStatus *status)
     status->bpdu_guard_error = prt->BpduGuardError;
     status->network_port = prt->NetworkPort;
     status->ba_inconsistent = prt->BaInconsistent;
+    status->num_rx_bpdu = prt->num_rx_bpdu;
+    status->num_rx_tcn = prt->num_rx_tcn;
+    status->num_tx_bpdu = prt->num_tx_bpdu;
+    status->num_tx_tcn = prt->num_tx_tcn;
+    status->num_trans_fwd = prt->num_trans_fwd;
+    status->num_trans_blk = prt->num_trans_blk;
 }
 
 /* 12.8.2.2 Read MSTI Port Parameters */
@@ -1531,7 +1569,7 @@ void MSTP_IN_set_mst_config_id(bridge_t *br, __u16 revision, __u8 *name)
  * If hint_SetToYes == false, some tcWhile in this tree has just became zero,
  *  so we should check all other tcWhile's in this tree.
  */
-static void set_TopologyChange(tree_t *tree, bool hint_SetToYes)
+static void set_TopologyChange(tree_t *tree, bool hint_SetToYes, port_t *port)
 {
     per_tree_port_t *ptp;
     bool prev_tc_not_set = !tree->topology_change;
@@ -1542,6 +1580,9 @@ static void set_TopologyChange(tree_t *tree, bool hint_SetToYes)
         tree->time_since_topology_change = 0;
         if(prev_tc_not_set)
             ++(tree->topology_change_count);
+        strncpy(tree->topology_change_port, tree->last_topology_change_port,
+                IFNAMSIZ);
+        strncpy(tree->last_topology_change_port, port->sysdeps.name, IFNAMSIZ);
         return;
     }
 
@@ -1717,7 +1758,7 @@ static void newTcWhile(per_tree_port_t *ptp)
         per_tree_port_t *cist = GET_CIST_PTP_FROM_PORT(prt);
 
         ptp->tcWhile = cist->portTimes.Hello_Time + 1;
-        set_TopologyChange(tree, true);
+        set_TopologyChange(tree, true, prt);
 
         if(0 == ptp->MSTID)
             prt->newInfo = true;
@@ -1729,7 +1770,7 @@ static void newTcWhile(per_tree_port_t *ptp)
     times_t *times = &tree->rootTimes;
 
     ptp->tcWhile = times->Max_Age + times->Forward_Delay;
-    set_TopologyChange(tree, true);
+    set_TopologyChange(tree, true, prt);
 }
 
 /* 13.26.6 rcvInfo */
@@ -2736,7 +2777,7 @@ static void PTSM_tick(port_t *prt)
         if(ptp->tcWhile)
         {
             if(0 == --(ptp->tcWhile))
-                set_TopologyChange(ptp->tree, false);
+                set_TopologyChange(ptp->tree, false, prt);
         }
         if(ptp->rcvdInfoWhile)
             --(ptp->rcvdInfoWhile);
@@ -4540,7 +4581,7 @@ static void TCSM_to_INACTIVE(per_tree_port_t *ptp, bool begin)
 
     set_fdbFlush(ptp);
     assign(ptp->tcWhile, 0u);
-    set_TopologyChange(ptp->tree, false);
+    set_TopologyChange(ptp->tree, false, ptp->port);
     if(0 == ptp->MSTID) /* CIST */
         ptp->port->tcAck = false;
 
@@ -4636,7 +4677,7 @@ static void TCSM_to_ACKNOWLEDGED(per_tree_port_t *ptp)
     ptp->TCSM_state = TCSM_ACKNOWLEDGED;
 
     assign(ptp->tcWhile, 0u);
-    set_TopologyChange(ptp->tree, false);
+    set_TopologyChange(ptp->tree, false, ptp->port);
     ptp->port->rcvdTcAck = false;
 
     TCSM_run(ptp, false /* actual run */);

diff --git a/mstp.h b/mstp.h
index 31d42e2ed3ddcffe00abf0873ae6e81ec70c28d1..6443efccd0afc6775e30e550090d4edd74c7f58a 100644 (file)
--- a/mstp.h
+++ b/mstp.h
@@ -434,6 +434,8 @@ typedef struct
     unsigned int time_since_topology_change;
     unsigned int topology_change_count;
     bool topology_change;
+    char topology_change_port[IFNAMSIZ];
+    char last_topology_change_port[IFNAMSIZ];
 
     /* State machines */
     PRSSM_states_t PRSSM_state;
@@ -494,6 +496,12 @@ typedef struct
     bool deleted;
 
     sysdep_if_data_t sysdeps;
+    unsigned int num_rx_bpdu;
+    unsigned int num_rx_tcn;
+    unsigned int num_tx_bpdu;
+    unsigned int num_tx_tcn;
+    unsigned int num_trans_fwd;
+    unsigned int num_trans_blk;
 } port_t;
 
 typedef struct
@@ -589,6 +597,8 @@ typedef struct
     unsigned int time_since_topology_change;
     unsigned int topology_change_count;
     bool topology_change;
+    char topology_change_port[IFNAMSIZ];
+    char last_topology_change_port[IFNAMSIZ];
     bridge_identifier_t designated_root;
     unsigned int root_path_cost;
     port_identifier_t root_port_id;
@@ -615,6 +625,8 @@ typedef struct
     unsigned int time_since_topology_change;
     unsigned int topology_change_count;
     bool topology_change;
+    char topology_change_port[IFNAMSIZ];
+    char last_topology_change_port[IFNAMSIZ];
     bridge_identifier_t regional_root;
     unsigned int internal_path_cost;
     port_identifier_t root_port_id;
@@ -692,6 +704,12 @@ typedef struct
     bool bpdu_guard_error;
     bool network_port;
     bool ba_inconsistent;
+    unsigned int num_rx_bpdu;
+    unsigned int num_rx_tcn;
+    unsigned int num_tx_bpdu;
+    unsigned int num_tx_tcn;
+    unsigned int num_trans_fwd;
+    unsigned int num_trans_blk;
 } CIST_PortStatus;
 
 void MSTP_IN_get_cist_port_status(port_t *prt, CIST_PortStatus *status);