X-Git-Url: https://gerrit.fd.io/r/gitweb?a=blobdiff_plain;f=src%2Fvlib%2Fmain.c;h=6369f39b09aeedea9d1fcc62035974a7f64ff027;hb=8b60fb0fe;hp=4223474367ec549182186ac6243eaf95d891def0;hpb=d7b306657d205fddd781e982aec5f3c3dc69fa88;p=vpp.git diff --git a/src/vlib/main.c b/src/vlib/main.c index 4223474367e..6369f39b09a 100644 --- a/src/vlib/main.c +++ b/src/vlib/main.c @@ -44,9 +44,6 @@ #include #include -#include - -CJ_GLOBAL_LOG_PROTOTYPE; /* Actually allocate a few extra slots of vector data to support speculative vector enqueues which overflow vector data in next frame. */ @@ -190,6 +187,31 @@ vlib_get_frame_to_node (vlib_main_t * vm, u32 to_node_index) return vlib_get_frame (vm, f); } +static inline void +vlib_validate_frame_indices (vlib_frame_t * f) +{ + if (CLIB_DEBUG > 0) + { + int i; + u32 *from = vlib_frame_vector_args (f); + + /* Check for bad buffer index values */ + for (i = 0; i < f->n_vectors; i++) + { + if (from[i] == 0) + { + clib_warning ("BUG: buffer index 0 at index %d", i); + ASSERT (0); + } + else if (from[i] == 0xfefefefe) + { + clib_warning ("BUG: frame poison pattern at index %d", i); + ASSERT (0); + } + } + } +} + void vlib_put_frame_to_node (vlib_main_t * vm, u32 to_node_index, vlib_frame_t * f) { @@ -199,6 +221,8 @@ vlib_put_frame_to_node (vlib_main_t * vm, u32 to_node_index, vlib_frame_t * f) if (f->n_vectors == 0) return; + vlib_validate_frame_indices (f); + to_node = vlib_get_node (vm, to_node_index); vec_add2 (vm->node_main.pending_frames, p, 1); @@ -432,6 +456,9 @@ vlib_put_next_frame_validate (vlib_main_t * vm, f = vlib_get_frame (vm, nf->frame); ASSERT (n_vectors_left <= VLIB_FRAME_SIZE); + + vlib_validate_frame_indices (f); + n_after = VLIB_FRAME_SIZE - n_vectors_left; n_before = f->n_vectors; @@ -541,41 +568,29 @@ vlib_put_next_frame (vlib_main_t * vm, never_inline void vlib_node_runtime_sync_stats (vlib_main_t * vm, vlib_node_runtime_t * r, - uword n_calls, uword n_vectors, uword n_clocks, - uword n_ticks0, uword n_ticks1) + uword n_calls, uword n_vectors, uword n_clocks) { vlib_node_t *n = vlib_get_node (vm, r->node_index); n->stats_total.calls += n_calls + r->calls_since_last_overflow; n->stats_total.vectors += n_vectors + r->vectors_since_last_overflow; n->stats_total.clocks += n_clocks + r->clocks_since_last_overflow; - n->stats_total.perf_counter0_ticks += n_ticks0 + - r->perf_counter0_ticks_since_last_overflow; - n->stats_total.perf_counter1_ticks += n_ticks1 + - r->perf_counter1_ticks_since_last_overflow; - n->stats_total.perf_counter_vectors += n_vectors + - r->perf_counter_vectors_since_last_overflow; n->stats_total.max_clock = r->max_clock; n->stats_total.max_clock_n = r->max_clock_n; r->calls_since_last_overflow = 0; r->vectors_since_last_overflow = 0; r->clocks_since_last_overflow = 0; - r->perf_counter0_ticks_since_last_overflow = 0ULL; - r->perf_counter1_ticks_since_last_overflow = 0ULL; - r->perf_counter_vectors_since_last_overflow = 0ULL; } always_inline void __attribute__ ((unused)) vlib_process_sync_stats (vlib_main_t * vm, vlib_process_t * p, - uword n_calls, uword n_vectors, uword n_clocks, - uword n_ticks0, uword n_ticks1) + uword n_calls, uword n_vectors, uword n_clocks) { vlib_node_runtime_t *rt = &p->node_runtime; vlib_node_t *n = vlib_get_node (vm, rt->node_index); - vlib_node_runtime_sync_stats (vm, rt, n_calls, n_vectors, n_clocks, - n_ticks0, n_ticks1); + vlib_node_runtime_sync_stats (vm, rt, n_calls, n_vectors, n_clocks); n->stats_total.suspends += p->n_suspends; p->n_suspends = 0; } @@ -601,7 +616,7 @@ vlib_node_sync_stats (vlib_main_t * vm, vlib_node_t * n) vec_elt_at_index (vm->node_main.nodes_by_type[n->type], n->runtime_index); - vlib_node_runtime_sync_stats (vm, rt, 0, 0, 0, 0, 0); + vlib_node_runtime_sync_stats (vm, rt, 0, 0, 0); /* Sync up runtime next frame vector counters with main node structure. */ { @@ -621,32 +636,21 @@ always_inline u32 vlib_node_runtime_update_stats (vlib_main_t * vm, vlib_node_runtime_t * node, uword n_calls, - uword n_vectors, uword n_clocks, - uword n_ticks0, uword n_ticks1) + uword n_vectors, uword n_clocks) { u32 ca0, ca1, v0, v1, cl0, cl1, r; - u32 ptick00, ptick01, ptick10, ptick11, pvec0, pvec1; cl0 = cl1 = node->clocks_since_last_overflow; ca0 = ca1 = node->calls_since_last_overflow; v0 = v1 = node->vectors_since_last_overflow; - ptick00 = ptick01 = node->perf_counter0_ticks_since_last_overflow; - ptick10 = ptick11 = node->perf_counter1_ticks_since_last_overflow; - pvec0 = pvec1 = node->perf_counter_vectors_since_last_overflow; ca1 = ca0 + n_calls; v1 = v0 + n_vectors; cl1 = cl0 + n_clocks; - ptick01 = ptick00 + n_ticks0; - ptick11 = ptick10 + n_ticks1; - pvec1 = pvec0 + n_vectors; node->calls_since_last_overflow = ca1; node->clocks_since_last_overflow = cl1; node->vectors_since_last_overflow = v1; - node->perf_counter0_ticks_since_last_overflow = ptick01; - node->perf_counter1_ticks_since_last_overflow = ptick11; - node->perf_counter_vectors_since_last_overflow = pvec1; node->max_clock_n = node->max_clock > n_clocks ? node->max_clock_n : n_vectors; @@ -654,42 +658,25 @@ vlib_node_runtime_update_stats (vlib_main_t * vm, r = vlib_node_runtime_update_main_loop_vector_stats (vm, node, n_vectors); - if (PREDICT_FALSE (ca1 < ca0 || v1 < v0 || cl1 < cl0) || (ptick01 < ptick00) - || (ptick11 < ptick10) || (pvec1 < pvec0)) + if (PREDICT_FALSE (ca1 < ca0 || v1 < v0 || cl1 < cl0)) { node->calls_since_last_overflow = ca0; node->clocks_since_last_overflow = cl0; node->vectors_since_last_overflow = v0; - node->perf_counter0_ticks_since_last_overflow = ptick00; - node->perf_counter1_ticks_since_last_overflow = ptick10; - node->perf_counter_vectors_since_last_overflow = pvec0; - vlib_node_runtime_sync_stats (vm, node, n_calls, n_vectors, n_clocks, - n_ticks0, n_ticks1); + vlib_node_runtime_sync_stats (vm, node, n_calls, n_vectors, n_clocks); } return r; } -always_inline void -vlib_node_runtime_perf_counter (vlib_main_t * vm, u64 * pmc0, u64 * pmc1, - vlib_node_runtime_t * node, - vlib_frame_t * frame, int before_or_after) -{ - *pmc0 = 0; - *pmc1 = 0; - if (PREDICT_FALSE (vec_len (vm->vlib_node_runtime_perf_counter_cbs) != 0)) - clib_call_callbacks (vm->vlib_node_runtime_perf_counter_cbs, vm, pmc0, - pmc1, node, frame, before_or_after); -} - always_inline void vlib_process_update_stats (vlib_main_t * vm, vlib_process_t * p, uword n_calls, uword n_vectors, uword n_clocks) { vlib_node_runtime_update_stats (vm, &p->node_runtime, - n_calls, n_vectors, n_clocks, 0ULL, 0ULL); + n_calls, n_vectors, n_clocks); } static clib_error_t * @@ -747,21 +734,44 @@ elog_save_buffer (vlib_main_t * vm, } void -elog_post_mortem_dump (void) +vlib_post_mortem_dump (void) { vlib_main_t *vm = &vlib_global_main; elog_main_t *em = &vm->elog_main; + u8 *filename; clib_error_t *error; - if (!vm->elog_post_mortem_dump) + if ((vm->elog_post_mortem_dump + vm->dispatch_pcap_postmortem) == 0) return; - filename = format (0, "/tmp/elog_post_mortem.%d%c", getpid (), 0); - error = elog_write_file (em, (char *) filename, 1 /* flush ring */ ); - if (error) - clib_error_report (error); - vec_free (filename); + if (vm->dispatch_pcap_postmortem) + { + clib_error_t *error; + pcap_main_t *pm = &vm->dispatch_pcap_main; + + pm->n_packets_to_capture = pm->n_packets_captured; + pm->file_name = (char *) format (0, "/tmp/dispatch_post_mortem.%d%c", + getpid (), 0); + error = pcap_write (pm); + pcap_close (pm); + if (error) + clib_error_report (error); + /* + * We're in the middle of crashing. Don't try to free the filename. + */ + } + + if (vm->elog_post_mortem_dump) + { + filename = format (0, "/tmp/elog_post_mortem.%d%c", getpid (), 0); + error = elog_write_file (em, (char *) filename, 1 /* flush ring */ ); + if (error) + clib_error_report (error); + /* + * We're in the middle of crashing. Don't try to free the filename. + */ + } } /* *INDENT-OFF* */ @@ -813,8 +823,8 @@ VLIB_CLI_COMMAND (elog_restart_cli, static) = { /* *INDENT-ON* */ static clib_error_t * -elog_resize (vlib_main_t * vm, - unformat_input_t * input, vlib_cli_command_t * cmd) +elog_resize_command_fn (vlib_main_t * vm, + unformat_input_t * input, vlib_cli_command_t * cmd) { elog_main_t *em = &vm->elog_main; u32 tmp; @@ -838,7 +848,7 @@ elog_resize (vlib_main_t * vm, VLIB_CLI_COMMAND (elog_resize_cli, static) = { .path = "event-logger resize", .short_help = "event-logger resize ", - .function = elog_resize, + .function = elog_resize_command_fn, }; /* *INDENT-ON* */ @@ -1139,7 +1149,6 @@ dispatch_node (vlib_main_t * vm, u64 t; vlib_node_main_t *nm = &vm->node_main; vlib_next_frame_t *nf; - u64 pmc_before[2], pmc_after[2], pmc_delta[2]; if (CLIB_DEBUG > 0) { @@ -1179,8 +1188,8 @@ dispatch_node (vlib_main_t * vm, last_time_stamp, frame ? frame->n_vectors : 0, /* is_after */ 0); - vlib_node_runtime_perf_counter (vm, &pmc_before[0], &pmc_before[1], - node, frame, 0 /* before */ ); + vlib_node_runtime_perf_counter (vm, node, frame, 0, last_time_stamp, + VLIB_NODE_RUNTIME_PERF_BEFORE); /* * Turn this on if you run into @@ -1199,26 +1208,27 @@ dispatch_node (vlib_main_t * vm, } if (PREDICT_FALSE (vm->dispatch_pcap_enable)) dispatch_pcap_trace (vm, node, frame); - n = node->function (vm, node, frame); + + if (PREDICT_TRUE (vm->dispatch_wrapper_fn == 0)) + n = node->function (vm, node, frame); + else + n = vm->dispatch_wrapper_fn (vm, node, frame); } else { if (PREDICT_FALSE (vm->dispatch_pcap_enable)) dispatch_pcap_trace (vm, node, frame); - n = node->function (vm, node, frame); + + if (PREDICT_TRUE (vm->dispatch_wrapper_fn == 0)) + n = node->function (vm, node, frame); + else + n = vm->dispatch_wrapper_fn (vm, node, frame); } t = clib_cpu_time_now (); - /* - * To validate accounting: pmc_delta = t - pmc_before; - * perf ticks should equal clocks/pkt... - */ - vlib_node_runtime_perf_counter (vm, &pmc_after[0], &pmc_after[1], node, - frame, 1 /* after */ ); - - pmc_delta[0] = pmc_after[0] - pmc_before[0]; - pmc_delta[1] = pmc_after[1] - pmc_before[1]; + vlib_node_runtime_perf_counter (vm, node, frame, n, t, + VLIB_NODE_RUNTIME_PERF_AFTER); vlib_elog_main_loop_event (vm, node->node_index, t, n, 1 /* is_after */ ); @@ -1228,9 +1238,7 @@ dispatch_node (vlib_main_t * vm, v = vlib_node_runtime_update_stats (vm, node, /* n_calls */ 1, /* n_vectors */ n, - /* n_clocks */ t - last_time_stamp, - pmc_delta[0] /* PMC0 */ , - pmc_delta[1] /* PMC1 */ ); + /* n_clocks */ t - last_time_stamp); /* When in interrupt mode and vector rate crosses threshold switch to polling mode. */ @@ -1327,7 +1335,7 @@ dispatch_pending_node (vlib_main_t * vm, uword pending_frame_index, { vlib_node_main_t *nm = &vm->node_main; vlib_frame_t *f; - vlib_next_frame_t *nf, nf_dummy; + vlib_next_frame_t *nf, nf_placeholder; vlib_node_runtime_t *n; vlib_frame_t *restore_frame; vlib_pending_frame_t *p; @@ -1341,8 +1349,8 @@ dispatch_pending_node (vlib_main_t * vm, uword pending_frame_index, f = vlib_get_frame (vm, p->frame); if (p->next_frame_index == VLIB_PENDING_FRAME_NO_NEXT_FRAME) { - /* No next frame: so use dummy on stack. */ - nf = &nf_dummy; + /* No next frame: so use placeholder on stack. */ + nf = &nf_placeholder; nf->flags = f->frame_flags & VLIB_NODE_FLAG_TRACE; nf->frame = NULL; } @@ -1469,6 +1477,8 @@ vlib_process_bootstrap (uword _a) vm = a->vm; p = a->process; + vlib_process_finish_switch_stack (vm); + f = a->frame; node = &p->node_runtime; @@ -1476,6 +1486,7 @@ vlib_process_bootstrap (uword _a) ASSERT (vlib_process_stack_is_valid (p)); + vlib_process_start_switch_stack (vm, 0); clib_longjmp (&p->return_longjmp, n); return n; @@ -1494,14 +1505,19 @@ vlib_process_startup (vlib_main_t * vm, vlib_process_t * p, vlib_frame_t * f) r = clib_setjmp (&p->return_longjmp, VLIB_PROCESS_RETURN_LONGJMP_RETURN); if (r == VLIB_PROCESS_RETURN_LONGJMP_RETURN) - r = clib_calljmp (vlib_process_bootstrap, pointer_to_uword (&a), - (void *) p->stack + (1 << p->log2_n_stack_bytes)); + { + vlib_process_start_switch_stack (vm, p); + r = clib_calljmp (vlib_process_bootstrap, pointer_to_uword (&a), + (void *) p->stack + (1 << p->log2_n_stack_bytes)); + } + else + vlib_process_finish_switch_stack (vm); return r; } static_always_inline uword -vlib_process_resume (vlib_process_t * p) +vlib_process_resume (vlib_main_t * vm, vlib_process_t * p) { uword r; p->flags &= ~(VLIB_PROCESS_IS_SUSPENDED_WAITING_FOR_CLOCK @@ -1509,7 +1525,12 @@ vlib_process_resume (vlib_process_t * p) | VLIB_PROCESS_RESUME_PENDING); r = clib_setjmp (&p->return_longjmp, VLIB_PROCESS_RETURN_LONGJMP_RETURN); if (r == VLIB_PROCESS_RETURN_LONGJMP_RETURN) - clib_longjmp (&p->resume_longjmp, VLIB_PROCESS_RESUME_LONGJMP_RESUME); + { + vlib_process_start_switch_stack (vm, p); + clib_longjmp (&p->resume_longjmp, VLIB_PROCESS_RESUME_LONGJMP_RESUME); + } + else + vlib_process_finish_switch_stack (vm); return r; } @@ -1539,6 +1560,9 @@ dispatch_process (vlib_main_t * vm, old_process_index = nm->current_process_index; nm->current_process_index = node->runtime_index; + vlib_node_runtime_perf_counter (vm, node_runtime, f, 0, last_time_stamp, + VLIB_NODE_RUNTIME_PERF_BEFORE); + n_vectors = vlib_process_startup (vm, p, f); nm->current_process_index = old_process_index; @@ -1578,6 +1602,9 @@ dispatch_process (vlib_main_t * vm, vlib_elog_main_loop_event (vm, node_runtime->node_index, t, is_suspend, /* is_after */ 1); + vlib_node_runtime_perf_counter (vm, node_runtime, f, n_vectors, t, + VLIB_NODE_RUNTIME_PERF_AFTER); + vlib_process_update_stats (vm, p, /* n_calls */ !is_suspend, /* n_vectors */ n_vectors, @@ -1628,7 +1655,10 @@ dispatch_suspended_process (vlib_main_t * vm, /* Save away current process for suspend. */ nm->current_process_index = node->runtime_index; - n_vectors = vlib_process_resume (p); + vlib_node_runtime_perf_counter (vm, node_runtime, f, 0, last_time_stamp, + VLIB_NODE_RUNTIME_PERF_BEFORE); + + n_vectors = vlib_process_resume (vm, p); t = clib_cpu_time_now (); nm->current_process_index = ~0; @@ -1661,6 +1691,9 @@ dispatch_suspended_process (vlib_main_t * vm, vlib_elog_main_loop_event (vm, node_runtime->node_index, t, !is_suspend, /* is_after */ 1); + vlib_node_runtime_perf_counter (vm, node_runtime, f, n_vectors, t, + VLIB_NODE_RUNTIME_PERF_AFTER); + vlib_process_update_stats (vm, p, /* n_calls */ !is_suspend, /* n_vectors */ n_vectors, @@ -1675,6 +1708,39 @@ vl_api_send_pending_rpc_requests (vlib_main_t * vm) { } +static_always_inline u64 +dispatch_pending_interrupts (vlib_main_t * vm, vlib_node_main_t * nm, + u64 cpu_time_now, + vlib_node_interrupt_t * interrupts) +{ + vlib_node_runtime_t *n; + + for (int i = 0; i < _vec_len (interrupts); i++) + { + vlib_node_interrupt_t *in; + in = vec_elt_at_index (interrupts, i); + n = vec_elt_at_index (nm->nodes_by_type[VLIB_NODE_TYPE_INPUT], + in->node_runtime_index); + n->interrupt_data = in->data; + cpu_time_now = dispatch_node (vm, n, VLIB_NODE_TYPE_INPUT, + VLIB_NODE_STATE_INTERRUPT, /* frame */ 0, + cpu_time_now); + } + return cpu_time_now; +} + +static inline void +pcap_postmortem_reset (vlib_main_t * vm) +{ + pcap_main_t *pm = &vm->dispatch_pcap_main; + + /* Reset the trace buffer and capture count */ + clib_spinlock_lock_if_init (&pm->lock); + vec_reset_length (pm->pcap_data); + pm->n_packets_captured = 0; + clib_spinlock_unlock_if_init (&pm->lock); +} + static_always_inline void vlib_main_or_worker_loop (vlib_main_t * vm, int is_main) @@ -1683,9 +1749,10 @@ vlib_main_or_worker_loop (vlib_main_t * vm, int is_main) vlib_thread_main_t *tm = vlib_get_thread_main (); uword i; u64 cpu_time_now; + f64 now; vlib_frame_queue_main_t *fqm; - u32 *last_node_runtime_indices = 0; u32 frame_queue_check_counter = 0; + vlib_node_interrupt_t *empty_int_list = 0; /* Initialize pending node vector. */ if (is_main) @@ -1704,10 +1771,12 @@ vlib_main_or_worker_loop (vlib_main_t * vm, int is_main) cpu_time_now = clib_cpu_time_now (); /* Pre-allocate interupt runtime indices and lock. */ - vec_alloc (nm->pending_interrupt_node_runtime_indices, 32); - vec_alloc (last_node_runtime_indices, 32); - if (!is_main) - clib_spinlock_init (&nm->pending_interrupt_lock); + vec_alloc (nm->pending_local_interrupts, 32); + vec_alloc (nm->pending_remote_interrupts, 32); + vec_alloc (empty_int_list, 32); + vec_alloc_aligned (nm->pending_remote_interrupts_notify, 1, + CLIB_CACHE_LINE_BYTES); + clib_spinlock_init (&nm->pending_interrupt_lock); /* Pre-allocate expired nodes. */ if (!nm->polling_threshold_vector_length) @@ -1717,6 +1786,7 @@ vlib_main_or_worker_loop (vlib_main_t * vm, int is_main) vm->cpu_id = clib_get_current_cpu_id (); vm->numa_node = clib_get_current_numa_node (); + os_set_numa_index (vm->numa_node); /* Start all processes. */ if (is_main) @@ -1747,33 +1817,45 @@ vlib_main_or_worker_loop (vlib_main_t * vm, int is_main) } if (!is_main) + vlib_worker_thread_barrier_check (); + + if (PREDICT_FALSE (vm->check_frame_queues + frame_queue_check_counter)) { - vlib_worker_thread_barrier_check (); - if (PREDICT_FALSE (vm->check_frame_queues + - frame_queue_check_counter)) - { - u32 processed = 0; + u32 processed = 0; - if (vm->check_frame_queues) - { - frame_queue_check_counter = 100; - vm->check_frame_queues = 0; - } + if (vm->check_frame_queues) + { + frame_queue_check_counter = 100; + vm->check_frame_queues = 0; + } - vec_foreach (fqm, tm->frame_queue_mains) - processed += vlib_frame_queue_dequeue (vm, fqm); + vec_foreach (fqm, tm->frame_queue_mains) + processed += vlib_frame_queue_dequeue (vm, fqm); - /* No handoff queue work found? */ - if (processed) - frame_queue_check_counter = 100; - else - frame_queue_check_counter--; - } - if (PREDICT_FALSE (vec_len (vm->worker_thread_main_loop_callbacks))) - clib_call_callbacks (vm->worker_thread_main_loop_callbacks, vm); + /* No handoff queue work found? */ + if (processed) + frame_queue_check_counter = 100; + else + frame_queue_check_counter--; } + if (PREDICT_FALSE (vec_len (vm->worker_thread_main_loop_callbacks))) + clib_call_callbacks (vm->worker_thread_main_loop_callbacks, vm, + cpu_time_now); + + /* + * When trying to understand aggravating, hard-to-reproduce + * bugs: reset / restart the pcap dispatch trace once per + * main thread dispatch cycle. All threads share the same + * (spinlock-protected) dispatch trace buffer. It might take + * a few tries to capture a good post-mortem trace of + * a multi-thread issue. Best we can do without a big refactor job. + */ + if (is_main && PREDICT_FALSE (vm->dispatch_pcap_postmortem != 0)) + pcap_postmortem_reset (vm); + /* Process pre-input nodes. */ + cpu_time_now = clib_cpu_time_now (); vec_foreach (n, nm->nodes_by_type[VLIB_NODE_TYPE_PRE_INPUT]) cpu_time_now = dispatch_node (vm, n, VLIB_NODE_TYPE_PRE_INPUT, @@ -1792,40 +1874,37 @@ vlib_main_or_worker_loop (vlib_main_t * vm, int is_main) if (PREDICT_TRUE (is_main && vm->queue_signal_pending == 0)) vm->queue_signal_callback (vm); - /* Next handle interrupts. */ - { - /* unlocked read, for performance */ - uword l = _vec_len (nm->pending_interrupt_node_runtime_indices); - uword i; - if (PREDICT_FALSE (l > 0)) - { - u32 *tmp; - if (!is_main) - { - clib_spinlock_lock (&nm->pending_interrupt_lock); - /* Re-read w/ lock held, in case another thread added an item */ - l = _vec_len (nm->pending_interrupt_node_runtime_indices); - } + /* handle local interruots */ + if (_vec_len (nm->pending_local_interrupts)) + { + vlib_node_interrupt_t *interrupts = nm->pending_local_interrupts; + nm->pending_local_interrupts = empty_int_list; + cpu_time_now = dispatch_pending_interrupts (vm, nm, cpu_time_now, + interrupts); + empty_int_list = interrupts; + vec_reset_length (empty_int_list); + } + + /* handle remote interruots */ + if (PREDICT_FALSE (_vec_len (nm->pending_remote_interrupts))) + { + vlib_node_interrupt_t *interrupts; + + /* at this point it is known that + * vec_len (nm->pending_local_interrupts) is zero so we quickly swap + * local and remote vector under the spinlock */ + clib_spinlock_lock (&nm->pending_interrupt_lock); + interrupts = nm->pending_remote_interrupts; + nm->pending_remote_interrupts = empty_int_list; + *nm->pending_remote_interrupts_notify = 0; + clib_spinlock_unlock (&nm->pending_interrupt_lock); + + cpu_time_now = dispatch_pending_interrupts (vm, nm, cpu_time_now, + interrupts); + empty_int_list = interrupts; + vec_reset_length (empty_int_list); + } - tmp = nm->pending_interrupt_node_runtime_indices; - nm->pending_interrupt_node_runtime_indices = - last_node_runtime_indices; - last_node_runtime_indices = tmp; - _vec_len (last_node_runtime_indices) = 0; - if (!is_main) - clib_spinlock_unlock (&nm->pending_interrupt_lock); - for (i = 0; i < l; i++) - { - n = vec_elt_at_index (nm->nodes_by_type[VLIB_NODE_TYPE_INPUT], - last_node_runtime_indices[i]); - cpu_time_now = - dispatch_node (vm, n, VLIB_NODE_TYPE_INPUT, - VLIB_NODE_STATE_INTERRUPT, - /* frame */ 0, - cpu_time_now); - } - } - } /* Input nodes may have added work to the pending vector. Process pending vector until there is nothing left. All pending vectors will be processed from input -> output. */ @@ -1925,6 +2004,33 @@ vlib_main_or_worker_loop (vlib_main_t * vm, int is_main) /* Record time stamp in case there are no enabled nodes and above calls do not update time stamp. */ cpu_time_now = clib_cpu_time_now (); + vm->loops_this_reporting_interval++; + now = clib_time_now_internal (&vm->clib_time, cpu_time_now); + /* Time to update loops_per_second? */ + if (PREDICT_FALSE (now >= vm->loop_interval_end)) + { + /* Next sample ends in 20ms */ + if (vm->loop_interval_start) + { + f64 this_loops_per_second; + + this_loops_per_second = + ((f64) vm->loops_this_reporting_interval) / (now - + vm->loop_interval_start); + + vm->loops_per_second = + vm->loops_per_second * vm->damping_constant + + (1.0 - vm->damping_constant) * this_loops_per_second; + if (vm->loops_per_second != 0.0) + vm->seconds_per_loop = 1.0 / vm->loops_per_second; + else + vm->seconds_per_loop = 0.0; + } + /* New interval starts now, and ends in 20ms */ + vm->loop_interval_start = now; + vm->loop_interval_end = now + 2e-4; + vm->loops_this_reporting_interval = 0; + } } } @@ -1953,10 +2059,25 @@ vlib_main_configure (vlib_main_t * vm, unformat_input_t * input) turn_on_mem_trace = 1; else if (unformat (input, "elog-events %d", - &vm->elog_main.event_ring_size)) - ; + &vm->configured_elog_ring_size)) + vm->configured_elog_ring_size = + 1 << max_log2 (vm->configured_elog_ring_size); else if (unformat (input, "elog-post-mortem-dump")) vm->elog_post_mortem_dump = 1; + else if (unformat (input, "buffer-alloc-success-rate %f", + &vm->buffer_alloc_success_rate)) + { + if (VLIB_BUFFER_ALLOC_FAULT_INJECTOR == 0) + return clib_error_return + (0, "Buffer fault injection not configured"); + } + else if (unformat (input, "buffer-alloc-success-seed %u", + &vm->buffer_alloc_success_seed)) + { + if (VLIB_BUFFER_ALLOC_FAULT_INJECTOR == 0) + return clib_error_return + (0, "Buffer fault injection not configured"); + } else return unformat_parse_error (input); } @@ -1973,7 +2094,7 @@ vlib_main_configure (vlib_main_t * vm, unformat_input_t * input) VLIB_EARLY_CONFIG_FUNCTION (vlib_main_configure, "vlib"); static void -dummy_queue_signal_callback (vlib_main_t * vm) +placeholder_queue_signal_callback (vlib_main_t * vm) { } @@ -2019,15 +2140,12 @@ vlib_main (vlib_main_t * volatile vm, unformat_input_t * input) clib_error_t *volatile error; vlib_node_main_t *nm = &vm->node_main; - vm->queue_signal_callback = dummy_queue_signal_callback; + vm->queue_signal_callback = placeholder_queue_signal_callback; - clib_time_init (&vm->clib_time); - - /* Turn on event log. */ - if (!vm->elog_main.event_ring_size) - vm->elog_main.event_ring_size = 128 << 10; - elog_init (&vm->elog_main, vm->elog_main.event_ring_size); - elog_enable_disable (&vm->elog_main, 1); + /* Reconfigure event log which is enabled very early */ + if (vm->configured_elog_ring_size && + vm->configured_elog_ring_size != vm->elog_main.event_ring_size) + elog_resize (&vm->elog_main, vm->configured_elog_ring_size); vl_api_set_elog_main (&vm->elog_main); (void) vl_api_set_elog_trace_api_messages (1); @@ -2120,9 +2238,26 @@ vlib_main (vlib_main_t * volatile vm, unformat_input_t * input) vec_validate (vm->processing_rpc_requests, 0); _vec_len (vm->processing_rpc_requests) = 0; + /* Default params for the buffer allocator fault injector, if configured */ + if (VLIB_BUFFER_ALLOC_FAULT_INJECTOR > 0) + { + vm->buffer_alloc_success_seed = 0xdeaddabe; + vm->buffer_alloc_success_rate = 0.80; + } + if ((error = vlib_call_all_config_functions (vm, input, 0 /* is_early */ ))) goto done; + /* + * Use exponential smoothing, with a half-life of 1 second + * reported_rate(t) = reported_rate(t-1) * K + rate(t)*(1-K) + * + * Sample every 20ms, aka 50 samples per second + * K = exp (-1.0/20.0); + * K = 0.95 + */ + vm->damping_constant = exp (-1.0 / 20.0); + /* Sort per-thread init functions before we start threads */ vlib_sort_init_exit_functions (&vm->worker_init_function_registrations); @@ -2223,6 +2358,11 @@ vlib_pcap_dispatch_trace_configure (vlib_pcap_dispatch_trace_args_t * a) vec_validate (tm->nodes, a->buffer_trace_node_index); tn = tm->nodes + a->buffer_trace_node_index; tn->limit += a->buffer_traces_to_capture; + if (a->post_mortem) + { + tm->filter_flag = FILTER_FLAG_POST_MORTEM; + tm->filter_count = ~0; + } tm->trace_enable = 1; })); /* *INDENT-ON* */ @@ -2236,7 +2376,8 @@ vlib_pcap_dispatch_trace_configure (vlib_pcap_dispatch_trace_args_t * a) vec_free (pm->pcap_data); memset (pm, 0, sizeof (*pm)); - vec_validate_aligned (vnet_trace_dummy, 2048, CLIB_CACHE_LINE_BYTES); + vec_validate_aligned (vnet_trace_placeholder, 2048, + CLIB_CACHE_LINE_BYTES); if (pm->lock == 0) clib_spinlock_init (&(pm->lock)); @@ -2247,14 +2388,23 @@ vlib_pcap_dispatch_trace_configure (vlib_pcap_dispatch_trace_args_t * a) pm->n_packets_captured = 0; pm->packet_type = PCAP_PACKET_TYPE_vpp; pm->n_packets_to_capture = a->packets_to_capture; + vm->dispatch_pcap_postmortem = a->post_mortem; /* *INDENT-OFF* */ - foreach_vlib_main (({this_vlib_main->dispatch_pcap_enable = 1;})); + foreach_vlib_main (({ this_vlib_main->dispatch_pcap_enable = 1;})); /* *INDENT-ON* */ } else { /* *INDENT-OFF* */ - foreach_vlib_main (({this_vlib_main->dispatch_pcap_enable = 0;})); + foreach_vlib_main (( + { + this_vlib_main->dispatch_pcap_enable = 0; + this_vlib_main->dispatch_pcap_postmortem = 0; + tm = &this_vlib_main->trace_main; + tm->filter_flag = 0; + tm->filter_count = 0; + tm->trace_enable = 0; + })); /* *INDENT-ON* */ vec_reset_length (vm->dispatch_buffer_trace_nodes); if (pm->n_packets_captured) @@ -2292,6 +2442,7 @@ dispatch_trace_command_fn (vlib_main_t * vm, int rv; int enable = 0; int status = 0; + int post_mortem = 0; u32 node_index = ~0, buffer_traces_to_capture = 100; /* Get a line of input. */ @@ -2321,6 +2472,8 @@ dispatch_trace_command_fn (vlib_main_t * vm, unformat_vlib_node, vm, &node_index, &buffer_traces_to_capture)) ; + else if (unformat (line_input, "post-mortem %=", &post_mortem, 1)) + ; else { return clib_error_return (0, "unknown input `%U'", @@ -2337,6 +2490,7 @@ dispatch_trace_command_fn (vlib_main_t * vm, a->packets_to_capture = max; a->buffer_trace_node_index = node_index; a->buffer_traces_to_capture = buffer_traces_to_capture; + a->post_mortem = post_mortem; rv = vlib_pcap_dispatch_trace_configure (a); @@ -2417,6 +2571,9 @@ dispatch_trace_command_fn (vlib_main_t * vm, * @cliexstart{vppctl pcap dispatch trace off} * captured 21 pkts... * saved to /tmp/dispatchTrace.pcap... + * Example of how to start a post-mortem dispatch trace: + * pcap dispatch trace on max 20000 buffer-trace + * dpdk-input 3000000000 post-mortem * @cliexend ?*/ /* *INDENT-OFF* */ @@ -2424,11 +2581,23 @@ VLIB_CLI_COMMAND (pcap_dispatch_trace_command, static) = { .path = "pcap dispatch trace", .short_help = "pcap dispatch trace [on|off] [max ] [file ] [status]\n" - " [buffer-trace ]", + " [buffer-trace ][post-mortem]", .function = dispatch_trace_command_fn, }; /* *INDENT-ON* */ +vlib_main_t * +vlib_get_main_not_inline (void) +{ + return vlib_get_main (); +} + +elog_main_t * +vlib_get_elog_main_not_inline () +{ + return &vlib_global_main.elog_main; +} + /* * fd.io coding-style-patch-verification: ON *