2020-06-05 19:48:55

by Pasha Tatashin

Subject: [PATCH] kexec: dump kmessage before machine_kexec

kmsg_dump(KMSG_DUMP_SHUTDOWN) is called before
machine_restart(), machine_halt(), machine_power_off(), the only one that
is missing is machine_kexec().

The dmesg output that it contains can be used to study the shutdown
performance of both kernel and systemd during kexec reboot.

Here is example of dmesg data collected after kexec:

root@dplat-cp22:~# cat /sys/fs/pstore/dmesg-ramoops-0 | tail
...
<6>[ 70.914592] psci: CPU3 killed (polled 0 ms)
<5>[ 70.915705] CPU4: shutdown
<6>[ 70.916643] psci: CPU4 killed (polled 4 ms)
<5>[ 70.917715] CPU5: shutdown
<6>[ 70.918725] psci: CPU5 killed (polled 0 ms)
<5>[ 70.919704] CPU6: shutdown
<6>[ 70.920726] psci: CPU6 killed (polled 4 ms)
<5>[ 70.921642] CPU7: shutdown
<6>[ 70.922650] psci: CPU7 killed (polled 0 ms)

Signed-off-by: Pavel Tatashin <[email protected]>
---
kernel/kexec_core.c | 2 ++
1 file changed, 2 insertions(+)

diff --git a/kernel/kexec_core.c b/kernel/kexec_core.c
index c19c0dad1ebe..50027f759a97 100644
--- a/kernel/kexec_core.c
+++ b/kernel/kexec_core.c
@@ -37,6 +37,7 @@
#include <linux/compiler.h>
#include <linux/hugetlb.h>
#include <linux/frame.h>
+#include <linux/kmsg_dump.h>

#include <asm/page.h>
#include <asm/sections.h>
@@ -1181,6 +1182,7 @@ int kernel_kexec(void)
machine_shutdown();
}

+ kmsg_dump(KMSG_DUMP_SHUTDOWN);
machine_kexec(kexec_image);

#ifdef CONFIG_KEXEC_JUMP
--
2.25.1

2020-06-05 21:29:27

by Kees Cook

Subject: Re: [PATCH] kexec: dump kmessage before machine_kexec

On Fri, Jun 05, 2020 at 03:46:42PM -0400, Pavel Tatashin wrote:
> kmsg_dump(KMSG_DUMP_SHUTDOWN) is called before
> machine_restart(), machine_halt(), machine_power_off(), the only one that
> is missing is machine_kexec().
>
> The dmesg output that it contains can be used to study the shutdown
> performance of both kernel and systemd during kexec reboot.
>
> Here is example of dmesg data collected after kexec:
>
> root@dplat-cp22:~# cat /sys/fs/pstore/dmesg-ramoops-0 | tail
> ...
> <6>[ 70.914592] psci: CPU3 killed (polled 0 ms)
> <5>[ 70.915705] CPU4: shutdown
> <6>[ 70.916643] psci: CPU4 killed (polled 4 ms)
> <5>[ 70.917715] CPU5: shutdown
> <6>[ 70.918725] psci: CPU5 killed (polled 0 ms)
> <5>[ 70.919704] CPU6: shutdown
> <6>[ 70.920726] psci: CPU6 killed (polled 4 ms)
> <5>[ 70.921642] CPU7: shutdown
> <6>[ 70.922650] psci: CPU7 killed (polled 0 ms)
>
> Signed-off-by: Pavel Tatashin <[email protected]>

Reviewed-by: Kees Cook <[email protected]>

--
Kees Cook

2020-06-08 08:08:54

by Petr Mladek

Subject: Re: [PATCH] kexec: dump kmessage before machine_kexec

On Fri 2020-06-05 15:46:42, Pavel Tatashin wrote:
> kmsg_dump(KMSG_DUMP_SHUTDOWN) is called before
> machine_restart(), machine_halt(), machine_power_off(), the only one that
> is missing is machine_kexec().
>
> The dmesg output that it contains can be used to study the shutdown
> performance of both kernel and systemd during kexec reboot.
>
> Here is example of dmesg data collected after kexec:
>
> root@dplat-cp22:~# cat /sys/fs/pstore/dmesg-ramoops-0 | tail
> ...
> <6>[ 70.914592] psci: CPU3 killed (polled 0 ms)
> <5>[ 70.915705] CPU4: shutdown
> <6>[ 70.916643] psci: CPU4 killed (polled 4 ms)
> <5>[ 70.917715] CPU5: shutdown
> <6>[ 70.918725] psci: CPU5 killed (polled 0 ms)
> <5>[ 70.919704] CPU6: shutdown
> <6>[ 70.920726] psci: CPU6 killed (polled 4 ms)
> <5>[ 70.921642] CPU7: shutdown
> <6>[ 70.922650] psci: CPU7 killed (polled 0 ms)
>
> Signed-off-by: Pavel Tatashin <[email protected]>

Reviewed-by: Petr Mladek <[email protected]>

Best Regards,
Petr

2020-06-08 08:10:28

by Bhupesh Sharma

Subject: Re: [PATCH] kexec: dump kmessage before machine_kexec

Hi Pavel,

On Sat, Jun 6, 2020 at 1:16 AM Pavel Tatashin <[email protected]> wrote:
>
> kmsg_dump(KMSG_DUMP_SHUTDOWN) is called before
> machine_restart(), machine_halt(), machine_power_off(), the only one that
> is missing is machine_kexec().
>
> The dmesg output that it contains can be used to study the shutdown
> performance of both kernel and systemd during kexec reboot.
>
> Here is example of dmesg data collected after kexec:
>
> root@dplat-cp22:~# cat /sys/fs/pstore/dmesg-ramoops-0 | tail
> ...
> <6>[ 70.914592] psci: CPU3 killed (polled 0 ms)
> <5>[ 70.915705] CPU4: shutdown
> <6>[ 70.916643] psci: CPU4 killed (polled 4 ms)
> <5>[ 70.917715] CPU5: shutdown
> <6>[ 70.918725] psci: CPU5 killed (polled 0 ms)
> <5>[ 70.919704] CPU6: shutdown
> <6>[ 70.920726] psci: CPU6 killed (polled 4 ms)
> <5>[ 70.921642] CPU7: shutdown
> <6>[ 70.922650] psci: CPU7 killed (polled 0 ms)
>
> Signed-off-by: Pavel Tatashin <[email protected]>
> ---
> kernel/kexec_core.c | 2 ++
> 1 file changed, 2 insertions(+)
>
> diff --git a/kernel/kexec_core.c b/kernel/kexec_core.c
> index c19c0dad1ebe..50027f759a97 100644
> --- a/kernel/kexec_core.c
> +++ b/kernel/kexec_core.c
> @@ -37,6 +37,7 @@
> #include <linux/compiler.h>
> #include <linux/hugetlb.h>
> #include <linux/frame.h>
> +#include <linux/kmsg_dump.h>
>
> #include <asm/page.h>
> #include <asm/sections.h>
> @@ -1181,6 +1182,7 @@ int kernel_kexec(void)
> machine_shutdown();
> }
>
> + kmsg_dump(KMSG_DUMP_SHUTDOWN);
> machine_kexec(kexec_image);
>
> #ifdef CONFIG_KEXEC_JUMP
> --
> 2.25.1

LGTM, so:

Reviewed-by: Bhupesh Sharma <[email protected]>

Thanks.