linux-kernel - Re: [PATCH V2 2/2] trace,x86: Add nmi to the irq

lists.openwall.net		lists / announce owl-users owl-dev john-users john-dev passwdqc-users yescrypt popa3d-users / oss-security kernel-hardening musl sabotage tlsify passwords / crypt-dev xvendor / Bugtraq Full-Disclosure linux-kernel linux-netdev linux-ext4 linux-hardening linux-cve-announce PHC
Open Source and information security mailing list archives

Hash Suite: Windows password security audit tool. GUI, reports in PDF.

[<prev] [next>] [<thread-prev] [thread-next>] [day] [month] [year] [list]

Date:   Mon, 8 Apr 2019 15:57:07 +0200
From:   Daniel Bristot de Oliveira <bristot@...hat.com>
To:     Steven Rostedt <rostedt@...dmis.org>
Cc:     Thomas Gleixner <tglx@...utronix.de>,
        Linux Kernel Mailing List <linux-kernel@...r.kernel.org>,
        Ingo Molnar <mingo@...hat.com>,
        Peter Zijlstra <peterz@...radead.org>,
        Andy Lutomirski <luto@...nel.org>,
        Clark Williams <williams@...hat.com>, x86@...nel.org
Subject: Re: [PATCH V2 2/2] trace,x86: Add nmi to the irq_vectors class

On 4/8/19 3:46 PM, Steven Rostedt wrote:
> On Mon, 8 Apr 2019 14:24:47 +0200
> Daniel Bristot de Oliveira <bristot@...hat.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