isisd: add a slight delay to lsp_regenerate_schedule

isisd implements a holdoff interval and will refrain from regenerating
an lsp if the difference between the current time and its last refresh
is less than the holdoff interval. Instead, it will schedule a timer
to regenerate the lsp after the holdoff interval has passed.

This implementation has one disadvantage in the case where there is a
succession of calls to lsp_regenerate_schedule. In such a case, the
first call will trigger an immediate regeneration of the lsp, while the
other calls will only schedule the regeneration timer. This leads to
cases where it takes holdoff interval time for information to propagate,
just because the information was only available e.g. at the second call
of lsp_regenerate_schedule in such a succession of calls.

By not immediately regenerating an lsp if the last generation time
is sufficiently long ago, but instead scheduling the regeneration with a
very small delay, we allow all information from such a succession of
calls to be considered.

Signed-off-by: Christian Franke <chris@opensourcerouting.org>
Acked-by: Donald Sharp <sharpd@cumulusnetworks.com>

diff --git a/isisd/isis_circuit.c b/isisd/isis_circuit.c
index a49994a78bb908c2dde302ede8cb9d7ce6ac47c0..c4d2ba76b872aada410fb95ebe16fa179cb8b324 100644 (file)
--- a/isisd/isis_circuit.c
+++ b/isisd/isis_circuit.c
@@ -785,6 +785,8 @@ isis_circuit_down (struct isis_circuit *circuit)
       THREAD_TIMER_OFF (circuit->u.bc.t_run_dr[1]);
       THREAD_TIMER_OFF (circuit->u.bc.t_refresh_pseudo_lsp[0]);
       THREAD_TIMER_OFF (circuit->u.bc.t_refresh_pseudo_lsp[1]);
+      circuit->lsp_regenerate_pending[0] = 0;
+      circuit->lsp_regenerate_pending[1] = 0;
     }
   else if (circuit->circ_type == CIRCUIT_T_P2P)
     {

diff --git a/isisd/isis_events.c b/isisd/isis_events.c
index 3887b7c5a22e90f562475ea5004ce5bc22028b5c..79e5ab379d46ac741be45500d373762e01929f67 100644 (file)
--- a/isisd/isis_events.c
+++ b/isisd/isis_events.c
@@ -110,7 +110,10 @@ area_resign_level (struct isis_area *area, int level)
     }
 #endif /* HAVE_IPV6 */
 
+  sched_debug("ISIS (%s): Resigned from L%d - canceling LSP regeneration timer.",
+              area->area_tag, level);
   THREAD_TIMER_OFF (area->t_lsp_refresh[level - 1]);
+  area->lsp_regenerate_pending[level - 1] = 0;
 }
 
 void
@@ -245,6 +248,7 @@ circuit_resign_level (struct isis_circuit *circuit, int level)
       THREAD_TIMER_OFF (circuit->u.bc.t_send_lan_hello[idx]);
       THREAD_TIMER_OFF (circuit->u.bc.t_run_dr[idx]);
       THREAD_TIMER_OFF (circuit->u.bc.t_refresh_pseudo_lsp[idx]);
+      circuit->lsp_regenerate_pending[idx] = 0;
       circuit->u.bc.run_dr_elect[idx] = 0;
       list_delete (circuit->u.bc.lan_neighs[idx]);
       circuit->u.bc.lan_neighs[idx] = NULL;

diff --git a/isisd/isis_lsp.c b/isisd/isis_lsp.c
index 30e4fc49baaa1a56d8a3a61ccdbd566249726994..725288e31133860bb3f1a50e760be3dfe978ea25 100644 (file)
--- a/isisd/isis_lsp.c
+++ b/isisd/isis_lsp.c
@@ -1681,10 +1681,13 @@ lsp_generate (struct isis_area *area, int level)
   lsp_build (newlsp, area);
   /* time to calculate our checksum */
   lsp_seqnum_update (newlsp);
+  newlsp->last_generated = time(NULL);
   lsp_set_all_srmflags (newlsp);
 
   refresh_time = lsp_refresh_time (newlsp, rem_lifetime);
+
   THREAD_TIMER_OFF (area->t_lsp_refresh[level - 1]);
+  area->lsp_regenerate_pending[level - 1] = 0;
   if (level == IS_LEVEL_1)
     THREAD_TIMER_ON (master, area->t_lsp_refresh[level - 1],
                      lsp_l1_refresh, area, refresh_time);
@@ -1704,6 +1707,8 @@ lsp_generate (struct isis_area *area, int level)
                   ntohs (newlsp->lsp_header->rem_lifetime),
                   refresh_time);
     }
+  sched_debug("ISIS (%s): Built L%d LSP. Set triggered regenerate to non-pending.",
+              area->area_tag, level);
 
   return ISIS_OK;
 }
@@ -1766,6 +1771,7 @@ lsp_regenerate (struct isis_area *area, int level)
   else if (level == IS_LEVEL_2)
     THREAD_TIMER_ON (master, area->t_lsp_refresh[level - 1],
                      lsp_l2_refresh, area, refresh_time);
+  area->lsp_regenerate_pending[level - 1] = 0;
 
   if (isis->debugs & DEBUG_UPDATE_PACKETS)
     {
@@ -1779,6 +1785,8 @@ lsp_regenerate (struct isis_area *area, int level)
                   ntohs (lsp->lsp_header->rem_lifetime),
                   refresh_time);
     }
+  sched_debug("ISIS (%s): Rebuilt L%d LSP. Set triggered regenerate to non-pending.",
+              area->area_tag, level);
 
   return ISIS_OK;
 }
@@ -1800,6 +1808,7 @@ lsp_l1_refresh (struct thread *thread)
   if ((area->is_type & IS_LEVEL_1) == 0)
     return ISIS_ERROR;
 
+  sched_debug("ISIS (%s): LSP L1 refresh timer expired. Refreshing LSP...", area->area_tag);
   return lsp_regenerate (area, IS_LEVEL_1);
 }
 
@@ -1817,6 +1826,7 @@ lsp_l2_refresh (struct thread *thread)
   if ((area->is_type & IS_LEVEL_2) == 0)
     return ISIS_ERROR;
 
+  sched_debug("ISIS (%s): LSP L2 refresh timer expired. Refreshing LSP...", area->area_tag);
   return lsp_regenerate (area, IS_LEVEL_2);
 }
 
@@ -1826,6 +1836,7 @@ lsp_regenerate_schedule (struct isis_area *area, int level, int all_pseudo)
   struct isis_lsp *lsp;
   u_char id[ISIS_SYS_ID_LEN + 2];
   time_t now, diff;
+  long timeout;
   struct listnode *cnode;
   struct isis_circuit *circuit;
   int lvl;
@@ -1833,6 +1844,9 @@ lsp_regenerate_schedule (struct isis_area *area, int level, int all_pseudo)
   if (area == NULL)
     return ISIS_ERROR;
 
+  sched_debug("ISIS (%s): Scheduling regeneration of %s LSPs, %sincluding PSNs",
+            area->area_tag, circuit_t2string(level), all_pseudo ? "" : "not ");
+
   memcpy (id, isis->sysid, ISIS_SYS_ID_LEN);
   LSP_PSEUDO_ID (id) = LSP_FRAGMENT (id) = 0;
   now = time (NULL);
@@ -1842,29 +1856,38 @@ lsp_regenerate_schedule (struct isis_area *area, int level, int all_pseudo)
       if (!((level & lvl) && (area->is_type & lvl)))
         continue;
 
+      sched_debug("ISIS (%s): Checking whether L%d needs to be scheduled",
+                  area->area_tag, lvl);
+
       if (area->lsp_regenerate_pending[lvl - 1])
-        continue;
+        {
+          struct timeval remain = thread_timer_remain(area->t_lsp_refresh[lvl - 1]);
+          sched_debug("ISIS (%s): Regeneration is already pending, nothing todo."
+                      " (Due in %lld.%03lld seconds)", area->area_tag,
+                      (long long)remain.tv_sec, (long long)remain.tv_usec / 1000);
+          continue;
+        }
 
       lsp = lsp_search (id, area->lspdb[lvl - 1]);
       if (!lsp)
-        continue;
+        {
+          sched_debug("ISIS (%s): We do not have any LSPs to regenerate, nothing todo.",
+                      area->area_tag);
+          continue;
+        }
 
       /*
        * Throttle avoidance
        */
+      sched_debug("ISIS (%s): Will schedule regen timer. Last run was: %lld, Now is: %lld",
+                  area->area_tag, (long long)lsp->last_generated, (long long)now);
       THREAD_TIMER_OFF (area->t_lsp_refresh[lvl - 1]);
       diff = now - lsp->last_generated;
       if (diff < area->lsp_gen_interval[lvl - 1])
         {
-          area->lsp_regenerate_pending[lvl - 1] = 1;
-          if (lvl == IS_LEVEL_1)
-            THREAD_TIMER_ON (master, area->t_lsp_refresh[lvl - 1],
-                             lsp_l1_refresh, area,
-                             area->lsp_gen_interval[lvl - 1] - diff);
-          else if (lvl == IS_LEVEL_2)
-            THREAD_TIMER_ON (master, area->t_lsp_refresh[lvl - 1],
-                             lsp_l2_refresh, area,
-                             area->lsp_gen_interval[lvl - 1] - diff);
+          timeout = 1000 * (area->lsp_gen_interval[lvl - 1] - diff);
+          sched_debug("ISIS (%s): Scheduling in %ld ms to match configured lsp_gen_interval",
+                      area->area_tag, timeout);
         }
       else
         {
@@ -1873,13 +1896,21 @@ lsp_regenerate_schedule (struct isis_area *area, int level, int all_pseudo)
            * directly. However if the lsp_regenerate call is queued for
            * later execution it works.
            */
-          area->lsp_regenerate_pending[lvl - 1] = 1;
-          if (lvl == IS_LEVEL_1)
-            THREAD_TIMER_ON (master, area->t_lsp_refresh[lvl - 1],
-                             lsp_l1_refresh, area, 0);
-          else if (lvl == IS_LEVEL_2)
-            THREAD_TIMER_ON (master, area->t_lsp_refresh[lvl - 1],
-                             lsp_l2_refresh, area, 0);
+          timeout = 100;
+          sched_debug("ISIS (%s): Last generation was more than lsp_gen_interval ago."
+                      " Scheduling for execution in %ld ms.", area->area_tag, timeout);
+        }
+
+      area->lsp_regenerate_pending[lvl - 1] = 1;
+      if (lvl == IS_LEVEL_1)
+        {
+          THREAD_TIMER_MSEC_ON(master, area->t_lsp_refresh[lvl - 1],
+                               lsp_l1_refresh, area, timeout);
+        }
+      else if (lvl == IS_LEVEL_2)
+        {
+          THREAD_TIMER_MSEC_ON(master, area->t_lsp_refresh[lvl - 1],
+                               lsp_l2_refresh, area, timeout);
         }
     }
 
@@ -2231,13 +2262,18 @@ lsp_regenerate_schedule_pseudo (struct isis_circuit *circuit, int level)
   struct isis_lsp *lsp;
   u_char lsp_id[ISIS_SYS_ID_LEN + 2];
   time_t now, diff;
+  long timeout;
   int lvl;
+  struct isis_area *area = circuit->area;
 
   if (circuit == NULL ||
       circuit->circ_type != CIRCUIT_T_BROADCAST ||
       circuit->state != C_STATE_UP)
     return ISIS_OK;
 
+  sched_debug("ISIS (%s): Scheduling regeneration of %s pseudo LSP for interface %s",
+              area->area_tag, circuit_t2string(level), circuit->interface->name);
+
   memcpy (lsp_id, isis->sysid, ISIS_SYS_ID_LEN);
   LSP_PSEUDO_ID (lsp_id) = circuit->circuit_id;
   LSP_FRAGMENT (lsp_id) = 0;
@@ -2245,39 +2281,74 @@ lsp_regenerate_schedule_pseudo (struct isis_circuit *circuit, int level)
 
   for (lvl = IS_LEVEL_1; lvl <= IS_LEVEL_2; lvl++)
     {
+      sched_debug("ISIS (%s): Checking whether L%d pseudo LSP needs to be scheduled",
+                  area->area_tag, lvl);
+
       if (!((level & lvl) && (circuit->is_type & lvl)))
-        continue;
+        {
+          sched_debug("ISIS (%s): Level is not active on circuit",
+                      area->area_tag);
+          continue;
+        }
 
-      if (circuit->u.bc.is_dr[lvl - 1] == 0 ||
-          circuit->lsp_regenerate_pending[lvl - 1])
-        continue;
+      if (circuit->u.bc.is_dr[lvl - 1] == 0)
+        {
+          sched_debug("ISIS (%s): This IS is not DR, nothing to do.",
+                      area->area_tag);
+          continue;
+        }
+
+      if (circuit->lsp_regenerate_pending[lvl - 1])
+        {
+          struct timeval remain =
+                  thread_timer_remain(circuit->u.bc.t_refresh_pseudo_lsp[lvl - 1]);
+          sched_debug("ISIS (%s): Regenerate is already pending, nothing todo."
+                      " (Due in %lld.%03lld seconds)", area->area_tag,
+                      (long long)remain.tv_sec, (long long)remain.tv_usec/1000);
+          continue;
+        }
 
       lsp = lsp_search (lsp_id, circuit->area->lspdb[lvl - 1]);
       if (!lsp)
-        continue;
+        {
+          sched_debug("ISIS (%s): Pseudonode LSP does not exist yet, nothing to regenerate.",
+                      area->area_tag);
+          continue;
+        }
 
       /*
        * Throttle avoidance
        */
+      sched_debug("ISIS (%s): Will schedule PSN regen timer. Last run was: %lld, Now is: %lld",
+                  area->area_tag, (long long)lsp->last_generated, (long long) now);
       THREAD_TIMER_OFF (circuit->u.bc.t_refresh_pseudo_lsp[lvl - 1]);
       diff = now - lsp->last_generated;
       if (diff < circuit->area->lsp_gen_interval[lvl - 1])
         {
-          circuit->lsp_regenerate_pending[lvl - 1] = 1;
-          if (lvl == IS_LEVEL_1)
-            THREAD_TIMER_ON (master,
-                             circuit->u.bc.t_refresh_pseudo_lsp[lvl - 1],
-                             lsp_l1_refresh_pseudo, circuit,
-                             circuit->area->lsp_gen_interval[lvl - 1] - diff);
-          else if (lvl == IS_LEVEL_2)
-            THREAD_TIMER_ON (master,
-                             circuit->u.bc.t_refresh_pseudo_lsp[lvl - 1],
-                             lsp_l2_refresh_pseudo, circuit,
-                             circuit->area->lsp_gen_interval[lvl - 1] - diff);
+          timeout = 1000 * (circuit->area->lsp_gen_interval[lvl - 1] - diff);
+          sched_debug("ISIS (%s): Sechduling in %ld ms to match configured lsp_gen_interval",
+                      area->area_tag, timeout);
         }
       else
         {
-          lsp_regenerate_pseudo (circuit, lvl);
+          timeout = 100;
+          sched_debug("ISIS (%s): Last generation was more than lsp_gen_interval ago."
+                      " Scheduling for execution in %ld ms.", area->area_tag, timeout);
+        }
+
+      circuit->lsp_regenerate_pending[lvl - 1] = 1;
+
+      if (lvl == IS_LEVEL_1)
+        {
+          THREAD_TIMER_MSEC_ON(master,
+                               circuit->u.bc.t_refresh_pseudo_lsp[lvl - 1],
+                               lsp_l1_refresh_pseudo, circuit, timeout);
+        }
+      else if (lvl == IS_LEVEL_2)
+        {
+          THREAD_TIMER_MSEC_ON(master,
+                               circuit->u.bc.t_refresh_pseudo_lsp[lvl - 1],
+                               lsp_l2_refresh_pseudo, circuit, timeout);
         }
     }
 

diff --git a/isisd/isisd.c b/isisd/isisd.c
index c05f94c755f41ddeb36c400d70fd977184f982c7..500d2b24cf83ad286a915ae12aff78dcc568a550 100644 (file)
--- a/isisd/isisd.c
+++ b/isisd/isisd.c
@@ -774,6 +774,8 @@ print_debug (struct vty *vty, int flags, int onoff)
     vty_out (vty, "IS-IS Packet dump debugging is %s%s", onoffs, VTY_NEWLINE);
   if (flags & DEBUG_LSP_GEN)
     vty_out (vty, "IS-IS LSP generation debugging is %s%s", onoffs, VTY_NEWLINE);
+  if (flags & DEBUG_LSP_SCHED)
+    vty_out (vty, "IS-IS LSP scheduling debugging is %s%s", onoffs, VTY_NEWLINE);
 }
 
 DEFUN (show_debugging,
@@ -866,6 +868,11 @@ config_write_debug (struct vty *vty)
       vty_out (vty, "debug isis lsp-gen%s", VTY_NEWLINE);
       write++;
     }
+  if (flags & DEBUG_LSP_SCHED)
+    {
+      vty_out (vty, "debug isis lsp-sched%s", VTY_NEWLINE);
+      write++;
+    }
 
   return write;
 }
@@ -1208,6 +1215,32 @@ DEFUN (no_debug_isis_lsp_gen,
   return CMD_SUCCESS;
 }
 
+DEFUN (debug_isis_lsp_sched,
+       debug_isis_lsp_sched_cmd,
+       "debug isis lsp-sched",
+       DEBUG_STR
+       "IS-IS information\n"
+       "IS-IS scheduling of LSP generation\n")
+{
+  isis->debugs |= DEBUG_LSP_SCHED;
+  print_debug (vty, DEBUG_LSP_SCHED, 1);
+
+  return CMD_SUCCESS;
+}
+
+DEFUN (no_debug_isis_lsp_sched,
+       no_debug_isis_lsp_sched_cmd,
+       "no debug isis lsp-gen",
+       UNDEBUG_STR
+       "IS-IS information\n"
+       "IS-IS scheduling of LSP generation\n")
+{
+  isis->debugs &= ~DEBUG_LSP_SCHED;
+  print_debug (vty, DEBUG_LSP_SCHED, 0);
+
+  return CMD_SUCCESS;
+}
+
 DEFUN (show_hostname,
        show_hostname_cmd,
        "show isis hostname",
@@ -3296,6 +3329,8 @@ isis_init ()
   install_element (ENABLE_NODE, &no_debug_isis_packet_dump_cmd);
   install_element (ENABLE_NODE, &debug_isis_lsp_gen_cmd);
   install_element (ENABLE_NODE, &no_debug_isis_lsp_gen_cmd);
+  install_element (ENABLE_NODE, &debug_isis_lsp_sched_cmd);
+  install_element (ENABLE_NODE, &no_debug_isis_lsp_sched_cmd);
 
   install_element (CONFIG_NODE, &debug_isis_adj_cmd);
   install_element (CONFIG_NODE, &no_debug_isis_adj_cmd);
@@ -3323,6 +3358,8 @@ isis_init ()
   install_element (CONFIG_NODE, &no_debug_isis_packet_dump_cmd);
   install_element (CONFIG_NODE, &debug_isis_lsp_gen_cmd);
   install_element (CONFIG_NODE, &no_debug_isis_lsp_gen_cmd);
+  install_element (CONFIG_NODE, &debug_isis_lsp_sched_cmd);
+  install_element (CONFIG_NODE, &no_debug_isis_lsp_sched_cmd);
 
   install_element (CONFIG_NODE, &router_isis_cmd);
   install_element (CONFIG_NODE, &no_router_isis_cmd);

diff --git a/isisd/isisd.h b/isisd/isisd.h
index 9a50c2db5f44c334c3df1c67ad7639d839121a3c..35d27dbe865bd0a3718b70238f1dcf60ac7a000b 100644 (file)
--- a/isisd/isisd.h
+++ b/isisd/isisd.h
@@ -99,6 +99,17 @@ struct isis_area
   struct flags flags;
   struct thread *t_tick;       /* LSP walker */
   struct thread *t_lsp_refresh[ISIS_LEVELS];
+  /* t_lsp_refresh is used in two ways:
+   * a) regular refresh of LSPs
+   * b) (possibly throttled) updates to LSPs
+   *
+   * The lsp_regenerate_pending flag tracks whether the timer is active
+   * for the a) or the b) case.
+   *
+   * It is of utmost importance to clear this flag when the timer is
+   * rescheduled for normal refresh, because otherwise, updates will
+   * be delayed until the next regular refresh.
+   */
   int lsp_regenerate_pending[ISIS_LEVELS];
 
   /*
@@ -169,6 +180,7 @@ extern struct thread_master *master;
 #define DEBUG_ZEBRA                      (1<<11)
 #define DEBUG_PACKET_DUMP                (1<<12)
 #define DEBUG_LSP_GEN                    (1<<13)
+#define DEBUG_LSP_SCHED                  (1<<14)
 
 #define lsp_debug(...) \
   do \
@@ -178,4 +190,12 @@ extern struct thread_master *master;
     } \
   while (0)
 
+#define sched_debug(...) \
+  do \
+    { \
+      if (isis->debugs & DEBUG_LSP_SCHED) \
+        zlog_debug(__VA_ARGS__); \
+    } \
+  while (0)
+
 #endif /* ISISD_H */