From 161fa356fbff795fe5945f353af486cf0a628428 Mon Sep 17 00:00:00 2001 From: Christian Franke Date: Fri, 16 Nov 2018 16:05:54 +0100 Subject: [PATCH] isisd: Add debug output for tx-queues To allow easier debugging of LSP transmission scheduling, add a debug mode where all tx-queue insertions/deletions are logged. Signed-off-by: Christian Franke --- isisd/isis_pdu.c | 11 +++++++---- isisd/isis_pdu.h | 3 ++- isisd/isis_tx_queue.c | 46 ++++++++++++++++++++++++++++++++----------- isisd/isis_tx_queue.h | 26 +++++++++++++++--------- isisd/isisd.c | 38 +++++++++++++++++++++++++++++++++++ isisd/isisd.h | 1 + 6 files changed, 99 insertions(+), 26 deletions(-) diff --git a/isisd/isis_pdu.c b/isisd/isis_pdu.c index 900ce9f922..4720b044ec 100644 --- a/isisd/isis_pdu.c +++ b/isisd/isis_pdu.c @@ -2182,9 +2182,9 @@ int send_l2_psnp(struct thread *thread) /* * ISO 10589 - 7.3.14.3 */ -void send_lsp(void *arg, struct isis_lsp *lsp, enum isis_tx_type tx_type) +void send_lsp(struct isis_circuit *circuit, struct isis_lsp *lsp, + enum isis_tx_type tx_type) { - struct isis_circuit *circuit = arg; int clear_srm = 1; int retval = ISIS_OK; @@ -2233,10 +2233,13 @@ void send_lsp(void *arg, struct isis_lsp *lsp, enum isis_tx_type tx_type) } if (isis->debugs & DEBUG_UPDATE_PACKETS) { - zlog_debug("ISIS-Upd (%s): Sending L%d LSP %s, seq 0x%08" PRIx32 + zlog_debug("ISIS-Upd (%s): Sending %sL%d LSP %s, seq 0x%08" PRIx32 ", cksum 0x%04" PRIx16 ", lifetime %" PRIu16 "s on %s", - circuit->area->area_tag, lsp->level, + circuit->area->area_tag, + (tx_type == TX_LSP_CIRCUIT_SCOPED) + ? "Circuit scoped " : "", + lsp->level, rawlspid_print(lsp->hdr.lsp_id), lsp->hdr.seqno, lsp->hdr.checksum, lsp->hdr.rem_lifetime, circuit->interface->name); diff --git a/isisd/isis_pdu.h b/isisd/isis_pdu.h index 0fa3b2c7ab..1e70a42f13 100644 --- a/isisd/isis_pdu.h +++ b/isisd/isis_pdu.h @@ -214,7 +214,8 @@ int send_l1_csnp(struct thread *thread); int send_l2_csnp(struct thread *thread); int send_l1_psnp(struct thread *thread); int send_l2_psnp(struct thread *thread); -void send_lsp(void *arg, struct isis_lsp *lsp, enum isis_tx_type tx_type); +void send_lsp(struct isis_circuit *circuit, + struct isis_lsp *lsp, enum isis_tx_type tx_type); void fill_fixed_hdr(uint8_t pdu_type, struct stream *stream); int send_hello(struct isis_circuit *circuit, int level); int isis_handle_pdu(struct isis_circuit *circuit, uint8_t *ssnpa); diff --git a/isisd/isis_tx_queue.c b/isisd/isis_tx_queue.c index fe67a3f4d1..46d1595f06 100644 --- a/isisd/isis_tx_queue.c +++ b/isisd/isis_tx_queue.c @@ -30,14 +30,16 @@ #include "dict.h" #include "isisd/isis_circuit.h" #include "isisd/isis_lsp.h" +#include "isisd/isis_misc.h" #include "isisd/isis_tx_queue.h" DEFINE_MTYPE_STATIC(ISISD, TX_QUEUE, "ISIS TX Queue") DEFINE_MTYPE_STATIC(ISISD, TX_QUEUE_ENTRY, "ISIS TX Queue Entry") struct isis_tx_queue { - void *arg; - void (*send_event)(void *arg, struct isis_lsp *, enum isis_tx_type); + struct isis_circuit *circuit; + void (*send_event)(struct isis_circuit *circuit, + struct isis_lsp *, enum isis_tx_type); struct hash *hash; }; @@ -72,14 +74,15 @@ static bool tx_queue_hash_cmp(const void *a, const void *b) return true; } -struct isis_tx_queue *isis_tx_queue_new(void *arg, - void(*send_event)(void *arg, - struct isis_lsp *, - enum isis_tx_type)) +struct isis_tx_queue *isis_tx_queue_new( + struct isis_circuit *circuit, + void(*send_event)(struct isis_circuit *circuit, + struct isis_lsp *, + enum isis_tx_type)) { struct isis_tx_queue *rv = XCALLOC(MTYPE_TX_QUEUE, sizeof(*rv)); - rv->arg = arg; + rv->circuit = circuit; rv->send_event = send_event; rv->hash = hash_create(tx_queue_hash_key, tx_queue_hash_cmp, NULL); @@ -121,19 +124,30 @@ static int tx_queue_send_event(struct thread *thread) e->retry = NULL; thread_add_timer(master, tx_queue_send_event, e, 5, &e->retry); - queue->send_event(queue->arg, e->lsp, e->type); + queue->send_event(queue->circuit, e->lsp, e->type); /* Don't access e here anymore, send_event might have destroyed it */ return 0; } -void isis_tx_queue_add(struct isis_tx_queue *queue, - struct isis_lsp *lsp, - enum isis_tx_type type) +void _isis_tx_queue_add(struct isis_tx_queue *queue, + struct isis_lsp *lsp, + enum isis_tx_type type, + const char *func, const char *file, + int line) { if (!queue) return; + if (isis->debugs & DEBUG_TX_QUEUE) { + zlog_debug("Add LSP %s to %s queue as %s LSP. (From %s %s:%d)", + rawlspid_print(lsp->hdr.lsp_id), + queue->circuit->interface->name, + (type == TX_LSP_CIRCUIT_SCOPED) ? + "circuit scoped" : "regular", + func, file, line); + } + struct isis_tx_queue_entry *e = tx_queue_find(queue, lsp); if (!e) { e = XCALLOC(MTYPE_TX_QUEUE_ENTRY, sizeof(*e)); @@ -152,7 +166,8 @@ void isis_tx_queue_add(struct isis_tx_queue *queue, thread_add_event(master, tx_queue_send_event, e, 0, &e->retry); } -void isis_tx_queue_del(struct isis_tx_queue *queue, struct isis_lsp *lsp) +void _isis_tx_queue_del(struct isis_tx_queue *queue, struct isis_lsp *lsp, + const char *func, const char *file, int line) { if (!queue) return; @@ -161,6 +176,13 @@ void isis_tx_queue_del(struct isis_tx_queue *queue, struct isis_lsp *lsp) if (!e) return; + if (isis->debugs & DEBUG_TX_QUEUE) { + zlog_debug("Remove LSP %s from %s queue. (From %s %s:%d)", + rawlspid_print(lsp->hdr.lsp_id), + queue->circuit->interface->name, + func, file, line); + } + if (e->retry) thread_cancel(e->retry); diff --git a/isisd/isis_tx_queue.h b/isisd/isis_tx_queue.h index ddecdf1e4f..7b01f1a3d4 100644 --- a/isisd/isis_tx_queue.h +++ b/isisd/isis_tx_queue.h @@ -29,18 +29,26 @@ enum isis_tx_type { struct isis_tx_queue; -struct isis_tx_queue *isis_tx_queue_new(void *arg, - void(*send_event)(void *arg, - struct isis_lsp *, - enum isis_tx_type)); +struct isis_tx_queue *isis_tx_queue_new( + struct isis_circuit *circuit, + void(*send_event)(struct isis_circuit *circuit, + struct isis_lsp *, + enum isis_tx_type) +); void isis_tx_queue_free(struct isis_tx_queue *queue); -void isis_tx_queue_add(struct isis_tx_queue *queue, - struct isis_lsp *lsp, - enum isis_tx_type type); - -void isis_tx_queue_del(struct isis_tx_queue *queue, struct isis_lsp *lsp); +#define isis_tx_queue_add(queue, lsp, type) \ + _isis_tx_queue_add((queue), (lsp), (type), \ + __func__, __FILE__, __LINE__) +void _isis_tx_queue_add(struct isis_tx_queue *queue, struct isis_lsp *lsp, + enum isis_tx_type type, const char *func, + const char *file, int line); + +#define isis_tx_queue_del(queue, lsp) \ + _isis_tx_queue_del((queue), (lsp), __func__, __FILE__, __LINE__) +void _isis_tx_queue_del(struct isis_tx_queue *queue, struct isis_lsp *lsp, + const char *func, const char *file, int line); unsigned long isis_tx_queue_len(struct isis_tx_queue *queue); diff --git a/isisd/isisd.c b/isisd/isisd.c index ce45ba65ec..279f7bfee1 100644 --- a/isisd/isisd.c +++ b/isisd/isisd.c @@ -720,6 +720,9 @@ void print_debug(struct vty *vty, int flags, int onoff) vty_out(vty, "IS-IS Adjacency related packets debugging is %s\n", onoffs); + if (flags & DEBUG_TX_QUEUE) + vty_out(vty, "IS-IS TX queue debugging is %s\n", + onoffs); if (flags & DEBUG_SNP_PACKETS) vty_out(vty, "IS-IS CSNP/PSNP packets debugging is %s\n", onoffs); @@ -771,6 +774,10 @@ static int config_write_debug(struct vty *vty) vty_out(vty, "debug " PROTO_NAME " adj-packets\n"); write++; } + if (flags & DEBUG_TX_QUEUE) { + vty_out(vty, "debug " PROTO_NAME " tx-queue\n"); + write++; + } if (flags & DEBUG_SNP_PACKETS) { vty_out(vty, "debug " PROTO_NAME " snp-packets\n"); write++; @@ -843,6 +850,33 @@ DEFUN (no_debug_isis_adj, return CMD_SUCCESS; } +DEFUN (debug_isis_tx_queue, + debug_isis_tx_queue_cmd, + "debug " PROTO_NAME " tx-queue", + DEBUG_STR + PROTO_HELP + "IS-IS TX queues\n") +{ + isis->debugs |= DEBUG_TX_QUEUE; + print_debug(vty, DEBUG_TX_QUEUE, 1); + + return CMD_SUCCESS; +} + +DEFUN (no_debug_isis_tx_queue, + no_debug_isis_tx_queue_cmd, + "no debug " PROTO_NAME " tx-queue", + NO_STR + UNDEBUG_STR + PROTO_HELP + "IS-IS TX queues\n") +{ + isis->debugs &= ~DEBUG_TX_QUEUE; + print_debug(vty, DEBUG_TX_QUEUE, 0); + + return CMD_SUCCESS; +} + DEFUN (debug_isis_snp, debug_isis_snp_cmd, "debug " PROTO_NAME " snp-packets", @@ -2061,6 +2095,8 @@ void isis_init() install_element(ENABLE_NODE, &debug_isis_adj_cmd); install_element(ENABLE_NODE, &no_debug_isis_adj_cmd); + install_element(ENABLE_NODE, &debug_isis_tx_queue_cmd); + install_element(ENABLE_NODE, &no_debug_isis_tx_queue_cmd); install_element(ENABLE_NODE, &debug_isis_snp_cmd); install_element(ENABLE_NODE, &no_debug_isis_snp_cmd); install_element(ENABLE_NODE, &debug_isis_upd_cmd); @@ -2082,6 +2118,8 @@ void isis_init() install_element(CONFIG_NODE, &debug_isis_adj_cmd); install_element(CONFIG_NODE, &no_debug_isis_adj_cmd); + install_element(CONFIG_NODE, &debug_isis_tx_queue_cmd); + install_element(CONFIG_NODE, &no_debug_isis_tx_queue_cmd); install_element(CONFIG_NODE, &debug_isis_snp_cmd); install_element(CONFIG_NODE, &no_debug_isis_snp_cmd); install_element(CONFIG_NODE, &debug_isis_upd_cmd); diff --git a/isisd/isisd.h b/isisd/isisd.h index fe9abff93c..95fdb971b1 100644 --- a/isisd/isisd.h +++ b/isisd/isisd.h @@ -214,6 +214,7 @@ extern struct thread_master *master; #define DEBUG_LSP_SCHED (1<<8) #define DEBUG_FABRICD_FLOODING (1<<9) #define DEBUG_BFD (1<<10) +#define DEBUG_TX_QUEUE (1<<11) #define lsp_debug(...) \ do { \ -- 2.39.5