diff options
| -rw-r--r-- | lib/thread.c | 2 | ||||
| -rw-r--r-- | lib/thread.h | 1 | ||||
| -rw-r--r-- | ospfd/ospf_abr.c | 1 | ||||
| -rw-r--r-- | ospfd/ospf_asbr.c | 1 | ||||
| -rw-r--r-- | ospfd/ospf_ase.c | 9 | ||||
| -rw-r--r-- | ospfd/ospf_dump.c | 21 | ||||
| -rw-r--r-- | ospfd/ospf_lsa.c | 16 | ||||
| -rw-r--r-- | ospfd/ospf_spf.c | 115 | ||||
| -rw-r--r-- | ospfd/ospf_spf.h | 13 | ||||
| -rw-r--r-- | ospfd/ospf_vty.c | 3 | ||||
| -rw-r--r-- | ospfd/ospfd.h | 6 |
11 files changed, 161 insertions, 27 deletions
diff --git a/lib/thread.c b/lib/thread.c index 468edd90c..97448894e 100644 --- a/lib/thread.c +++ b/lib/thread.c @@ -102,7 +102,7 @@ timeval_cmp (struct timeval a, struct timeval b) ? a.tv_usec - b.tv_usec : a.tv_sec - b.tv_sec); } -static unsigned long +unsigned long timeval_elapsed (struct timeval a, struct timeval b) { return (((a.tv_sec - b.tv_sec) * TIMER_SECOND_MICRO) diff --git a/lib/thread.h b/lib/thread.h index dbf5f25b8..bc7eaef44 100644 --- a/lib/thread.h +++ b/lib/thread.h @@ -208,6 +208,7 @@ extern struct thread *thread_fetch (struct thread_master *, struct thread *); extern void thread_call (struct thread *); extern unsigned long thread_timer_remain_second (struct thread *); extern int thread_should_yield (struct thread *); +extern unsigned long timeval_elapsed (struct timeval a, struct timeval b); /* Internal libzebra exports */ extern void thread_getrusage (RUSAGE_T *); diff --git a/ospfd/ospf_abr.c b/ospfd/ospf_abr.c index 4bb70b6a9..ca1af2c4a 100644 --- a/ospfd/ospf_abr.c +++ b/ospfd/ospf_abr.c @@ -556,6 +556,7 @@ ospf_check_abr_status (struct ospf *ospf) if (new_flags != ospf->flags) { + ospf_flag_spf_reason (SPF_FLAG_ABR_STATUS_CHANGE); ospf_spf_calculate_schedule (ospf); if (IS_DEBUG_OSPF_EVENT) zlog_debug ("ospf_check_abr_status(): new router flags: %x",new_flags); diff --git a/ospfd/ospf_asbr.c b/ospfd/ospf_asbr.c index 7e9412c88..dbf7f11f5 100644 --- a/ospfd/ospf_asbr.c +++ b/ospfd/ospf_asbr.c @@ -264,6 +264,7 @@ ospf_asbr_status_update (struct ospf *ospf, u_char status) } /* Transition from/to status ASBR, schedule timer. */ + ospf_flag_spf_reason (SPF_FLAG_ASBR_STATUS_CHANGE); ospf_spf_calculate_schedule (ospf); ospf_router_lsa_update (ospf); } diff --git a/ospfd/ospf_ase.c b/ospfd/ospf_ase.c index 6a72e31dc..9038b3a5c 100644 --- a/ospfd/ospf_ase.c +++ b/ospfd/ospf_ase.c @@ -636,6 +636,7 @@ ospf_ase_calculate_timer (struct thread *t) struct route_node *rn; struct listnode *node; struct ospf_area *area; + struct timeval start_time, stop_time; ospf = THREAD_ARG (t); ospf->t_ase_calc = NULL; @@ -644,6 +645,8 @@ ospf_ase_calculate_timer (struct thread *t) { ospf->ase_calc = 0; + quagga_gettime(QUAGGA_CLK_MONOTONIC, &start_time); + /* Calculate external route for each AS-external-LSA */ LSDB_LOOP (EXTERNAL_LSDB (ospf), rn, lsa) ospf_ase_calculate_route (ospf, lsa); @@ -673,6 +676,12 @@ ospf_ase_calculate_timer (struct thread *t) ospf_route_table_free (ospf->old_external_route); ospf->old_external_route = ospf->new_external_route; ospf->new_external_route = route_table_init (); + + quagga_gettime(QUAGGA_CLK_MONOTONIC, &stop_time); + + zlog_info ("SPF Processing Time(usecs): External Routes: %d\n", + (stop_time.tv_sec - start_time.tv_sec)*1000000L+ + (stop_time.tv_usec - start_time.tv_usec)); } return 0; } diff --git a/ospfd/ospf_dump.c b/ospfd/ospf_dump.c index ef023366a..ebcc717ff 100644 --- a/ospfd/ospf_dump.c +++ b/ospfd/ospf_dump.c @@ -247,16 +247,21 @@ ospf_timeval_dump (struct timeval *t, char *buf, size_t size) #define HOUR_IN_SECONDS (60*MINUTE_IN_SECONDS) #define DAY_IN_SECONDS (24*HOUR_IN_SECONDS) #define WEEK_IN_SECONDS (7*DAY_IN_SECONDS) - unsigned long w, d, h, m, s, ms; + unsigned long w, d, h, m, s, ms, us; if (!t) return "inactive"; - w = d = h = m = s = ms = 0; + w = d = h = m = s = ms = us = 0; memset (buf, 0, size); - - ms = t->tv_usec / 1000; - + + us = t->tv_usec; + if (us >= 1000) + { + ms = us / 1000; + us %= 1000; + } + if (ms >= 1000) { t->tv_sec += ms / 1000; @@ -297,9 +302,11 @@ ospf_timeval_dump (struct timeval *t, char *buf, size_t size) snprintf (buf, size, "%ldh%02ldm%02lds", h, m, t->tv_sec); else if (m) snprintf (buf, size, "%ldm%02lds", m, t->tv_sec); - else + else if (ms) snprintf (buf, size, "%ld.%03lds", t->tv_sec, ms); - + else + snprintf (buf, size, "%ld usecs", t->tv_usec); + return buf; } diff --git a/ospfd/ospf_lsa.c b/ospfd/ospf_lsa.c index fef6b162f..31cbaaef2 100644 --- a/ospfd/ospf_lsa.c +++ b/ospfd/ospf_lsa.c @@ -2409,8 +2409,10 @@ ospf_router_lsa_install (struct ospf *ospf, struct ospf_lsa *new, ospf_refresher_register_lsa (ospf, new); } if (rt_recalc) - ospf_spf_calculate_schedule (ospf); - + { + ospf_flag_spf_reason (SPF_FLAG_ROUTER_LSA_INSTALL); + ospf_spf_calculate_schedule (ospf); + } return new; } @@ -2444,7 +2446,10 @@ ospf_network_lsa_install (struct ospf *ospf, ospf_refresher_register_lsa (ospf, new); } if (rt_recalc) - ospf_spf_calculate_schedule (ospf); + { + ospf_flag_spf_reason (SPF_FLAG_NETWORK_LSA_INSTALL); + ospf_spf_calculate_schedule (ospf); + } return new; } @@ -2467,11 +2472,10 @@ ospf_summary_lsa_install (struct ospf *ospf, struct ospf_lsa *new, /* This doesn't exist yet... */ ospf_summary_incremental_update(new); */ #else /* #if 0 */ + ospf_flag_spf_reason (SPF_FLAG_SUMMARY_LSA_INSTALL); ospf_spf_calculate_schedule (ospf); #endif /* #if 0 */ - if (IS_DEBUG_OSPF (lsa, LSA_INSTALL)) - zlog_debug ("ospf_summary_lsa_install(): SPF scheduled"); } if (IS_LSA_SELF (new)) @@ -2500,6 +2504,7 @@ ospf_summary_asbr_lsa_install (struct ospf *ospf, struct ospf_lsa *new, - RFC 2328 Section 16.5 implies it should be */ /* ospf_ase_calculate_schedule(); */ #else /* #if 0 */ + ospf_flag_spf_reason (SPF_FLAG_ASBR_SUMMARY_LSA_INSTALL); ospf_spf_calculate_schedule (ospf); #endif /* #if 0 */ } @@ -3022,6 +3027,7 @@ ospf_lsa_maxage_walker_remover (struct ospf *ospf, struct ospf_lsa *lsa) ospf_ase_incremental_update (ospf, lsa); break; default: + ospf_flag_spf_reason (SPF_FLAG_MAXAGE); ospf_spf_calculate_schedule (ospf); break; } diff --git a/ospfd/ospf_spf.c b/ospfd/ospf_spf.c index c40fc33ef..a7155bc64 100644 --- a/ospfd/ospf_spf.c +++ b/ospfd/ospf_spf.c @@ -46,6 +46,50 @@ Software Foundation, Inc., 59 Temple Place - Suite 330, Boston, MA #include "ospfd/ospf_abr.h" #include "ospfd/ospf_dump.h" +/* Variables to ensure a SPF scheduled log message is printed only once */ + +static unsigned int spf_reason_flags = 0; + +static void ospf_clear_spf_reason_flags () +{ + spf_reason_flags = 0; +} + +void ospf_flag_spf_reason (unsigned int reason) +{ + if (reason <= SPF_FLAG_MAX_VALUE) + spf_reason_flags |= reason; + else + spf_reason_flags |= SPF_FLAG_MISC; +} + +static void +ospf_get_spf_reason_str (char *buf) +{ + if (buf) + { + buf[0] = '\0'; + if (spf_reason_flags) + { + if (spf_reason_flags & SPF_FLAG_ROUTER_LSA_INSTALL) + strcat (buf, "R, "); + if (spf_reason_flags & SPF_FLAG_NETWORK_LSA_INSTALL) + strcat (buf, "N, "); + if (spf_reason_flags & SPF_FLAG_SUMMARY_LSA_INSTALL) + strcat (buf, "S, "); + if (spf_reason_flags & SPF_FLAG_ASBR_SUMMARY_LSA_INSTALL) + strcat (buf, "AS, "); + if (spf_reason_flags & SPF_FLAG_ABR_STATUS_CHANGE) + strcat (buf, "ABR, "); + if (spf_reason_flags & SPF_FLAG_ASBR_STATUS_CHANGE) + strcat (buf, "ASBR, "); + if (spf_reason_flags & SPF_FLAG_MAXAGE) + strcat (buf, "M, "); + } + buf[strlen(buf)-2] = '\0'; /* skip the last ", " */ + } +} + static void ospf_vertex_free (void *); /* List of allocated vertices, to simplify cleanup of SPF. * Not thread-safe obviously. If it ever needs to be, it'd have to be @@ -1232,27 +1276,28 @@ ospf_spf_calculate (struct ospf_area *area, struct route_table *new_table, /* Free candidate queue. */ pqueue_delete (candidate); - + ospf_vertex_dump (__func__, area->spf, 0, 1); /* Free nexthop information, canonical versions of which are attached * the first level of router vertices attached to the root vertex, see * ospf_nexthop_calculation. */ ospf_canonical_nexthops_free (area->spf); - - /* Free SPF vertices, but not the list. List has ospf_vertex_free - * as deconstructor. - */ - list_delete_all_node (&vertex_list); - + /* Increment SPF Calculation Counter. */ area->spf_calculation++; quagga_gettime (QUAGGA_CLK_MONOTONIC, &area->ospf->ts_spf); + area->ts_spf = area->ospf->ts_spf; if (IS_DEBUG_OSPF_EVENT) zlog_debug ("ospf_spf_calculate: Stop. %ld vertices", mtype_stats_alloc(MTYPE_OSPF_VERTEX)); + + /* Free SPF vertices, but not the list. List has ospf_vertex_free + * as deconstructor. + */ + list_delete_all_node (&vertex_list); } /* Timer for SPF calculation. */ @@ -1263,12 +1308,18 @@ ospf_spf_calculate_timer (struct thread *thread) struct route_table *new_table, *new_rtrs; struct ospf_area *area; struct listnode *node, *nnode; + struct timeval start_time, stop_time, spf_start_time; + int areas_processed = 0; + unsigned long ia_time, prune_time, rt_time; + unsigned long abr_time, total_spf_time, spf_time; + char rbuf[32]; /* reason_buf */ if (IS_DEBUG_OSPF_EVENT) zlog_debug ("SPF: Timer (SPF calculation expire)"); ospf->t_spf_calc = NULL; + quagga_gettime (QUAGGA_CLK_MONOTONIC, &spf_start_time); /* Allocate new table tree. */ new_table = route_table_init (); new_rtrs = route_table_init (); @@ -1283,21 +1334,36 @@ ospf_spf_calculate_timer (struct thread *thread) */ if (ospf->backbone && ospf->backbone == area) continue; - + ospf_spf_calculate (area, new_table, new_rtrs); + areas_processed++; } - + /* SPF for backbone, if required */ if (ospf->backbone) - ospf_spf_calculate (ospf->backbone, new_table, new_rtrs); - + { + ospf_spf_calculate (ospf->backbone, new_table, new_rtrs); + areas_processed++; + } + + quagga_gettime (QUAGGA_CLK_MONOTONIC, &stop_time); + spf_time = timeval_elapsed (stop_time, spf_start_time); + ospf_vl_shut_unapproved (ospf); + start_time = stop_time; /* saving a call */ + ospf_ia_routing (ospf, new_table, new_rtrs); + quagga_gettime (QUAGGA_CLK_MONOTONIC, &stop_time); + ia_time = timeval_elapsed (stop_time, start_time); + + quagga_gettime (QUAGGA_CLK_MONOTONIC, &start_time); ospf_prune_unreachable_networks (new_table); ospf_prune_unreachable_routers (new_rtrs); + quagga_gettime (QUAGGA_CLK_MONOTONIC, &stop_time); + prune_time = timeval_elapsed (stop_time, start_time); /* AS-external-LSA calculation should not be performed here. */ /* If new Router Route is installed, @@ -1307,9 +1373,13 @@ ospf_spf_calculate_timer (struct thread *thread) ospf_ase_calculate_timer_add (ospf); + quagga_gettime (QUAGGA_CLK_MONOTONIC, &start_time); + /* Update routing table. */ ospf_route_install (ospf, new_table); + quagga_gettime (QUAGGA_CLK_MONOTONIC, &stop_time); + rt_time = timeval_elapsed (stop_time, start_time); /* Update ABR/ASBR routing table */ if (ospf->old_rtrs) { @@ -1321,11 +1391,28 @@ ospf_spf_calculate_timer (struct thread *thread) ospf->old_rtrs = ospf->new_rtrs; ospf->new_rtrs = new_rtrs; + quagga_gettime (QUAGGA_CLK_MONOTONIC, &start_time); if (IS_OSPF_ABR (ospf)) ospf_abr_task (ospf); - if (IS_DEBUG_OSPF_EVENT) - zlog_debug ("SPF: calculation complete"); + quagga_gettime (QUAGGA_CLK_MONOTONIC, &stop_time); + abr_time = timeval_elapsed (stop_time, start_time); + + quagga_gettime (QUAGGA_CLK_MONOTONIC, &stop_time); + total_spf_time = timeval_elapsed (stop_time, spf_start_time); + ospf->ts_spf_duration.tv_sec = total_spf_time/1000000; + ospf->ts_spf_duration.tv_usec = total_spf_time % 1000000; + + ospf_get_spf_reason_str (rbuf); + + if (IS_OSPF_ABR (ospf)) + zlog_info ("SPF Processing Time(usecs): # Areas: %d, SPF Time: %ld, InterArea: %ld, Prune: %ld, RouteInstall: %ld, ABR: %ld, Total: %ld, Reason: %s\n", + areas_processed, spf_time, ia_time, prune_time, rt_time, abr_time, total_spf_time, rbuf); + else + zlog_info ("SPF Processing Time(usecs): SPF Time: %ld, InterArea: %ld, Prune: %ld, RouteInstall: %ld, Total: %ld, Reason: %s\n", + spf_time, ia_time, prune_time, rt_time, total_spf_time, rbuf); + + ospf_clear_spf_reason_flags (); return 0; } @@ -1389,6 +1476,8 @@ ospf_spf_calculate_schedule (struct ospf *ospf) if (IS_DEBUG_OSPF_EVENT) zlog_debug ("SPF: calculation timer delay = %ld", delay); + zlog_info ("SPF: Scheduled in %ld msec", delay); + ospf->t_spf_calc = thread_add_timer_msec (master, ospf_spf_calculate_timer, ospf, delay); } diff --git a/ospfd/ospf_spf.h b/ospfd/ospf_spf.h index c1316e4cc..c9c539ad7 100644 --- a/ospfd/ospf_spf.h +++ b/ospfd/ospf_spf.h @@ -64,4 +64,17 @@ extern void ospf_rtrs_free (struct route_table *); /* void ospf_spf_calculate_timer_add (); */ +/* What triggered the SPF ? Can have at most 32 reasons with this */ +#define SPF_FLAG_ROUTER_LSA_INSTALL 0x1 +#define SPF_FLAG_NETWORK_LSA_INSTALL 0x2 +#define SPF_FLAG_SUMMARY_LSA_INSTALL 0x4 +#define SPF_FLAG_ASBR_SUMMARY_LSA_INSTALL 0x8 +#define SPF_FLAG_MAXAGE 0x10 +#define SPF_FLAG_ABR_STATUS_CHANGE 0x20 +#define SPF_FLAG_ASBR_STATUS_CHANGE 0x40 +#define SPF_FLAG_MAX_VALUE 0x40 /* Update this when adding flags */ +#define SPF_FLAG_MISC 0x1000000 /* Keep this last */ + +extern void ospf_flag_spf_reason (unsigned int reason); + #endif /* _QUAGGA_OSPF_SPF_H */ diff --git a/ospfd/ospf_vty.c b/ospfd/ospf_vty.c index 8bfcaa829..561d81149 100644 --- a/ospfd/ospf_vty.c +++ b/ospfd/ospf_vty.c @@ -2749,6 +2749,9 @@ DEFUN (show_ip_ospf, vty_out (vty, "last executed %s ago%s", ospf_timeval_dump (&result, timebuf, sizeof (timebuf)), VTY_NEWLINE); + vty_out (vty, " Last SPF duration %s%s", + ospf_timeval_dump (&ospf->ts_spf_duration, timebuf, sizeof (timebuf)), + VTY_NEWLINE); } else vty_out (vty, "has not been run%s", VTY_NEWLINE); diff --git a/ospfd/ospfd.h b/ospfd/ospfd.h index 4242aa01b..bf70d0227 100644 --- a/ospfd/ospfd.h +++ b/ospfd/ospfd.h @@ -194,8 +194,9 @@ struct ospf struct route_table *external_lsas; /* Database of external LSAs, prefix is LSA's adv. network*/ - /* Time stamps. */ + /* Time stamps */ struct timeval ts_spf; /* SPF calculation time stamp. */ + struct timeval ts_spf_duration; /* Execution time of last SPF */ struct route_table *maxage_lsa; /* List of MaxAge LSA for deletion. */ int redistribute; /* Num of redistributed protocols. */ @@ -393,6 +394,9 @@ struct ospf_area /* Statistics field. */ u_int32_t spf_calculation; /* SPF Calculation Count. */ + /* Time stamps. */ + struct timeval ts_spf; /* SPF calculation time stamp. */ + /* Router count. */ u_int32_t abr_count; /* ABR router in this area. */ u_int32_t asbr_count; /* ASBR router in this area. */ |