From: Dinesh Dutt Date: Mon, 26 Aug 2013 03:40:23 +0000 (+0000) Subject: ospf6d: add SPF logs, statistics, and display of SPF parameters X-Git-Tag: frr-2.0-rc1~1628^2~8 X-Git-Url: https://git.puffer.fish/?a=commitdiff_plain;h=a0edf6740e8203abec1ee3efa344a417c16fec7b;p=matthieu%2Ffrr.git ospf6d: add SPF logs, statistics, and display of SPF parameters Signed-off-by: Pradosh Mohapatra Reviewed-by: Scott Feldman [DL: adapted to rebase / readded randomly lost line] [DL: killed timeval_subtract] Signed-off-by: David Lamparter --- diff --git a/ospf6d/ospf6_area.c b/ospf6d/ospf6_area.c index 37e5c0045c..b09d9613c0 100644 --- a/ospf6d/ospf6_area.c +++ b/ospf6d/ospf6_area.c @@ -67,7 +67,8 @@ ospf6_area_lsdb_hook_add (struct ospf6_lsa *lsa) zlog_debug ("Schedule SPF Calculation for %s", OSPF6_AREA (lsa->lsdb->data)->name); } - ospf6_spf_schedule (OSPF6_PROCESS(OSPF6_AREA (lsa->lsdb->data)->ospf6)); + ospf6_spf_schedule (OSPF6_PROCESS(OSPF6_AREA (lsa->lsdb->data)->ospf6), + ospf6_lsadd_to_spf_reason(lsa)); break; case OSPF6_LSTYPE_INTRA_PREFIX: @@ -97,7 +98,8 @@ ospf6_area_lsdb_hook_remove (struct ospf6_lsa *lsa) zlog_debug ("Schedule SPF Calculation for %s", OSPF6_AREA (lsa->lsdb->data)->name); } - ospf6_spf_schedule (OSPF6_PROCESS(OSPF6_AREA (lsa->lsdb->data)->ospf6)); + ospf6_spf_schedule (OSPF6_PROCESS(OSPF6_AREA (lsa->lsdb->data)->ospf6), + ospf6_lsremove_to_spf_reason(lsa)); break; case OSPF6_LSTYPE_INTRA_PREFIX: diff --git a/ospf6d/ospf6_interface.c b/ospf6d/ospf6_interface.c index d1f5cba1c3..fee1632a1a 100644 --- a/ospf6d/ospf6_interface.c +++ b/ospf6d/ospf6_interface.c @@ -73,7 +73,7 @@ ospf6_interface_lookup_by_ifindex (int ifindex) /* schedule routing table recalculation */ static void -ospf6_interface_lsdb_hook (struct ospf6_lsa *lsa) +ospf6_interface_lsdb_hook (struct ospf6_lsa *lsa, unsigned int reason) { struct ospf6_interface *oi; @@ -86,7 +86,7 @@ ospf6_interface_lsdb_hook (struct ospf6_lsa *lsa) case OSPF6_LSTYPE_LINK: if (oi->state == OSPF6_INTERFACE_DR) OSPF6_INTRA_PREFIX_LSA_SCHEDULE_TRANSIT (oi); - ospf6_spf_schedule (oi->area->ospf6); + ospf6_spf_schedule (oi->area->ospf6, reason); break; default: @@ -94,6 +94,18 @@ ospf6_interface_lsdb_hook (struct ospf6_lsa *lsa) } } +static void +ospf6_interface_lsdb_hook_add (struct ospf6_lsa *lsa) +{ + ospf6_interface_lsdb_hook(lsa, ospf6_lsadd_to_spf_reason(lsa)); +} + +static void +ospf6_interface_lsdb_hook_remove (struct ospf6_lsa *lsa) +{ + ospf6_interface_lsdb_hook(lsa, ospf6_lsremove_to_spf_reason(lsa)); +} + static u_char ospf6_default_iftype(struct interface *ifp) { @@ -152,8 +164,8 @@ ospf6_interface_create (struct interface *ifp) oi->lsupdate_list = ospf6_lsdb_create (oi); oi->lsack_list = ospf6_lsdb_create (oi); oi->lsdb = ospf6_lsdb_create (oi); - oi->lsdb->hook_add = ospf6_interface_lsdb_hook; - oi->lsdb->hook_remove = ospf6_interface_lsdb_hook; + oi->lsdb->hook_add = ospf6_interface_lsdb_hook_add; + oi->lsdb->hook_remove = ospf6_interface_lsdb_hook_remove; oi->lsdb_self = ospf6_lsdb_create (oi); oi->route_connected = OSPF6_ROUTE_TABLE_CREATE (INTERFACE, CONNECTED_ROUTES); diff --git a/ospf6d/ospf6_intra.c b/ospf6d/ospf6_intra.c index e86e46bf73..4ad7521e93 100644 --- a/ospf6d/ospf6_intra.c +++ b/ospf6d/ospf6_intra.c @@ -46,7 +46,7 @@ #include "ospf6_abr.h" #include "ospf6_flood.h" #include "ospf6d.h" - +#include "ospf6_spf.h" unsigned char conf_debug_ospf6_brouter = 0; u_int32_t conf_debug_ospf6_brouter_specific_router_id; diff --git a/ospf6d/ospf6_spf.c b/ospf6d/ospf6_spf.c index 845e206c4a..3ef5485fde 100644 --- a/ospf6d/ospf6_spf.c +++ b/ospf6d/ospf6_spf.c @@ -377,6 +377,36 @@ ospf6_spf_table_finish (struct ospf6_route_table *result_table) } } +static const char *ospf6_spf_reason_str[] = + { + "R+", + "R-", + "N+", + "N-", + "L+", + "L-", + "R*", + "N*", + }; + +void ospf6_spf_reason_string (unsigned int reason, char *buf, int size) +{ + int bit; + int len = 0; + + if (!buf) + return; + + for (bit = 0; bit <= (sizeof(ospf6_spf_reason_str) / sizeof(char *)); bit++) + { + if ((reason & (1 << bit)) && (len < size)) + { + len += snprintf((buf + len), (size - len), "%s%s", + (len > 0) ? ", " : "", ospf6_spf_reason_str[bit]); + } + } +} + /* RFC2328 16.1. Calculating the shortest-path tree for an area */ /* RFC2740 3.8.1. Calculating the shortest path tree for an area */ void @@ -515,6 +545,8 @@ ospf6_spf_calculation_thread (struct thread *t) struct timeval start, end, runtime; struct listnode *node; struct ospf6_route *route; + int areas_processed = 0; + char rbuf[32]; ospf6 = (struct ospf6 *)THREAD_ARG (t); ospf6->t_spf_calc = NULL; @@ -536,6 +568,8 @@ ospf6_spf_calculation_thread (struct thread *t) ospf6_spf_calculation (ospf6->router_id, oa->spf_table, oa); ospf6_intra_route_calculation (oa); ospf6_intra_brouter_calculation (oa); + + areas_processed++; } if (ospf6->backbone) @@ -550,6 +584,7 @@ ospf6_spf_calculation_thread (struct thread *t) ospf6->backbone); ospf6_intra_route_calculation(ospf6->backbone); ospf6_intra_brouter_calculation(ospf6->backbone); + areas_processed++; } /* Redo summaries if required */ @@ -562,23 +597,36 @@ ospf6_spf_calculation_thread (struct thread *t) ospf6->ts_spf_duration = runtime; + ospf6_spf_reason_string(ospf6->spf_reason, rbuf, sizeof(rbuf)); + if (IS_OSPF6_DEBUG_SPF (PROCESS) || IS_OSPF6_DEBUG_SPF (TIME)) zlog_debug ("SPF runtime: %ld sec %ld usec", runtime.tv_sec, runtime.tv_usec); + zlog_info("SPF processing: # Areas: %d, SPF runtime: %ld sec %ld usec, " + "Reason: %s\n", areas_processed, runtime.tv_sec, runtime.tv_usec, + rbuf); + ospf6->last_spf_reason = ospf6->spf_reason; + ospf6_reset_spf_reason(ospf6); return 0; } /* Add schedule for SPF calculation. To avoid frequenst SPF calc, we set timer for SPF calc. */ void -ospf6_spf_schedule (struct ospf6 *ospf6) +ospf6_spf_schedule (struct ospf6 *ospf6, unsigned int reason) { unsigned long delay, elapsed, ht; struct timeval now, result; + ospf6_set_spf_reason(ospf6, reason); + if (IS_OSPF6_DEBUG_SPF(PROCESS) || IS_OSPF6_DEBUG_SPF (TIME)) - zlog_debug ("SPF: calculation timer scheduled"); + { + char rbuf[32]; + ospf6_spf_reason_string(reason, rbuf, sizeof(rbuf)); + zlog_debug ("SPF: calculation timer scheduled (reason %s)", rbuf); + } /* OSPF instance does not exist. */ if (ospf6 == NULL) diff --git a/ospf6d/ospf6_spf.h b/ospf6d/ospf6_spf.h index 6c40424fdb..b3481dc379 100644 --- a/ospf6d/ospf6_spf.h +++ b/ospf6d/ospf6_spf.h @@ -79,11 +79,77 @@ struct ospf6_vertex #define VERTEX_IS_TYPE(t, v) \ ((v)->type == OSPF6_VERTEX_TYPE_ ## t ? 1 : 0) +/* What triggered the SPF? */ +#define OSPF6_SPF_FLAGS_ROUTER_LSA_ADDED (1 << 0) +#define OSPF6_SPF_FLAGS_ROUTER_LSA_REMOVED (1 << 1) +#define OSPF6_SPF_FLAGS_NETWORK_LSA_ADDED (1 << 2) +#define OSPF6_SPF_FLAGS_NETWORK_LSA_REMOVED (1 << 3) +#define OSPF6_SPF_FLAGS_LINK_LSA_ADDED (1 << 4) +#define OSPF6_SPF_FLAGS_LINK_LSA_REMOVED (1 << 5) +#define OSPF6_SPF_FLAGS_ROUTER_LSA_ORIGINATED (1 << 6) +#define OSPF6_SPF_FLAGS_NETWORK_LSA_ORIGINATED (1 << 7) + +static inline void +ospf6_set_spf_reason (struct ospf6* ospf, unsigned int reason) +{ + ospf->spf_reason |= reason; +} + +static inline void +ospf6_reset_spf_reason (struct ospf6 *ospf) +{ + ospf->spf_reason = 0; +} + +static inline unsigned int +ospf6_lsadd_to_spf_reason (struct ospf6_lsa *lsa) +{ + unsigned int reason = 0; + + switch (ntohs (lsa->header->type)) + { + case OSPF6_LSTYPE_ROUTER: + reason = OSPF6_SPF_FLAGS_ROUTER_LSA_ADDED; + break; + case OSPF6_LSTYPE_NETWORK: + reason = OSPF6_SPF_FLAGS_NETWORK_LSA_ADDED; + break; + case OSPF6_LSTYPE_LINK: + reason = OSPF6_SPF_FLAGS_LINK_LSA_ADDED; + break; + default: + break; + } + return (reason); +} + +static inline unsigned int +ospf6_lsremove_to_spf_reason (struct ospf6_lsa *lsa) +{ + unsigned int reason = 0; + + switch (ntohs (lsa->header->type)) + { + case OSPF6_LSTYPE_ROUTER: + reason = OSPF6_SPF_FLAGS_ROUTER_LSA_REMOVED; + break; + case OSPF6_LSTYPE_NETWORK: + reason = OSPF6_SPF_FLAGS_NETWORK_LSA_REMOVED; + break; + case OSPF6_LSTYPE_LINK: + reason = OSPF6_SPF_FLAGS_LINK_LSA_REMOVED; + break; + default: + break; + } + return (reason); +} + extern void ospf6_spf_table_finish (struct ospf6_route_table *result_table); extern void ospf6_spf_calculation (u_int32_t router_id, struct ospf6_route_table *result_table, struct ospf6_area *oa); -extern void ospf6_spf_schedule (struct ospf6 *ospf); +extern void ospf6_spf_schedule (struct ospf6 *ospf, unsigned int reason); extern void ospf6_spf_display_subtree (struct vty *vty, const char *prefix, int rest, struct ospf6_vertex *v); @@ -92,6 +158,7 @@ extern void ospf6_spf_config_write (struct vty *vty); extern int config_write_ospf6_debug_spf (struct vty *vty); extern void install_element_ospf6_debug_spf (void); extern void ospf6_spf_init (void); +extern void ospf6_spf_reason_string (unsigned int reason, char *buf, int size); #endif /* OSPF6_SPF_H */ diff --git a/ospf6d/ospf6_top.c b/ospf6d/ospf6_top.c index 1f7cdc8542..f83e6ab5e4 100644 --- a/ospf6d/ospf6_top.c +++ b/ospf6d/ospf6_top.c @@ -615,7 +615,8 @@ ospf6_show (struct vty *vty, struct ospf6 *o) struct listnode *n; struct ospf6_area *oa; char router_id[16], duration[32]; - struct timeval now, running; + struct timeval now, running, result; + char buf[32], rbuf[32]; /* process id, router id */ inet_ntop (AF_INET, &o->router_id, router_id, sizeof (router_id)); @@ -631,6 +632,32 @@ ospf6_show (struct vty *vty, struct ospf6 *o) /* Redistribute configuration */ /* XXX */ + /* Show SPF parameters */ + vty_out(vty, " Initial SPF scheduling delay %d millisec(s)%s" + " Minimum hold time between consecutive SPFs %d millsecond(s)%s" + " Maximum hold time between consecutive SPFs %d millsecond(s)%s" + " Hold time multiplier is currently %d%s", + o->spf_delay, VNL, + o->spf_holdtime, VNL, + o->spf_max_holdtime, VNL, + o->spf_hold_multiplier, VNL); + + vty_out(vty, " SPF algorithm "); + if (o->ts_spf.tv_sec || o->ts_spf.tv_usec) + { + timersub(&now, &o->ts_spf, &result); + timerstring(&result, buf, sizeof(buf)); + ospf6_spf_reason_string(o->last_spf_reason, rbuf, sizeof(rbuf)); + vty_out(vty, "last executed %s ago, reason %s%s", buf, rbuf, VNL); + vty_out (vty, " Last SPF duration %ld sec %ld usec%s", + o->ts_spf_duration.tv_sec, o->ts_spf_duration.tv_usec, VNL); + } + else + vty_out(vty, "has not been run$%s", VNL); + threadtimer_string(now, o->t_spf_calc, buf, sizeof(buf)); + vty_out (vty, " SPF timer %s%s%s", + (o->t_spf_calc ? "due in " : "is "), buf, VNL); + if (CHECK_FLAG (o->flag, OSPF6_STUB_ROUTER)) vty_out (vty, " Router Is Stub Router%s", VNL); diff --git a/ospf6d/ospf6_top.h b/ospf6d/ospf6_top.h index 9d7cfd9199..866f92f988 100644 --- a/ospf6d/ospf6_top.h +++ b/ospf6d/ospf6_top.h @@ -70,9 +70,11 @@ struct ospf6 unsigned int spf_holdtime; /* SPF hold time. */ unsigned int spf_max_holdtime; /* SPF maximum-holdtime */ unsigned int spf_hold_multiplier; /* Adaptive multiplier for hold time */ + unsigned int spf_reason; /* reason bits while scheduling SPF */ struct timeval ts_spf; /* SPF calculation time stamp. */ struct timeval ts_spf_duration; /* Execution time of last SPF */ + unsigned int last_spf_reason; /* Last SPF reason */ /* Threads */ struct thread *t_spf_calc; /* SPF calculation timer. */ diff --git a/ospf6d/ospf6d.h b/ospf6d/ospf6d.h index 13699d612e..0c86386a70 100644 --- a/ospf6d/ospf6d.h +++ b/ospf6d/ospf6d.h @@ -101,6 +101,17 @@ extern struct thread_master *master; zlog_warn ("strftime error"); \ } while (0) +#define threadtimer_string(now, t, buf, size) \ + do { \ + struct timeval result; \ + if (!t) \ + snprintf(buf, size, "inactive"); \ + else { \ + timersub(&t->u.sands, &now, &result); \ + timerstring(&result, buf, size); \ + } \ +} while (0) + /* for commands */ #define OSPF6_AREA_STR "Area information\n" #define OSPF6_AREA_ID_STR "Area ID (as an IPv4 notation)\n"