Messages in this thread | | | Subject | Re: [PATCH V2 2/2] trace,x86: Add nmi to the irq_vectors class | From | Daniel Bristot de Oliveira <> | Date | Mon, 8 Apr 2019 15:57:07 +0200 |
| |
On 4/8/19 3:46 PM, Steven Rostedt wrote: > On Mon, 8 Apr 2019 14:24:47 +0200 > Daniel Bristot de Oliveira <bristot@redhat.com> wrote: > >> NMI starts: >> f-4447 [000] d.Z. 1487.689290: nmi_entry: vector=2 >> f-4447 [000] d.Z. 1487.689291: default_do_nmi <-do_nmi >> f-4447 [000] d.Z. 1487.689291: nmi_handle <-default_do_nmi >> f-4447 [000] d.Z. 1487.689291: nmi_cpu_backtrace_handler <-nmi_handle >> >> It handles very fast: >> f-4447 [000] d.Z. 1487.689292: nmi_handler: nmi_cpu_backtrace_handler() >> delta_ns: 780 handled: 0 >> >> But some other functions continues running in the NMI context: >> [Dazed and confused, but trying to continue message ] >> f-4447 [000] d.Z. 1487.689292: _raw_spin_trylock <-default_do_nmi >> f-4447 [000] d.Z. 1487.689566: unknown_nmi_error <-default_do_nmi >> f-4447 [000] d.Z. 1487.689566: nmi_handle <-unknown_nmi_error >> f-4447 [000] d.Z. 1487.689567: printk <-unknown_nmi_error >> f-4447 [000] d.Z. 1487.689567: vprintk_func <-printk >> f-4447 [000] d.Z. 1487.689567: printk_safe_log_store <-vprintk_func >> f-4447 [000] d.Z. 1487.689569: arch_irq_work_raise <-irq_work_queue >> f-4447 [000] d.Z. 1487.689569: default_send_IPI_self <-arch_irq_work_raise >> f-4447 [000] d.Z. 1487.689569: __default_send_IPI_shortcut >> <-default_send_IPI_self > > Just to remove confusion. Your example is to show that the new > tracepoints would have shown that the NMI was long due to the printk? As > running printk from NMI (even with the delayed output) isn't a normal > path.
The example is "to show that the new tracepoints would have shown that the NMI was longer than what the existing tracepoint pointed." The example was not the best, I agree.. but... it serves to illustrate the idea.
-- Daniel
| |