[PATCH] Drivers: hv: Change flag to write log level in panic msg to false

[PATCH] Drivers: hv: Change flag to write log level in panic msg to false

[Joseph Salisbury]

When the kernel panics, one page worth of kmsg data is written to an allocated
page.  The Hypervisor is notified of the page address trough the MSR.  This
panic information is collected on the host.  Since we are only collecting one
page of data, the full panic message may not be collected.

Each line of the panic message is prefixed with the log level of that
particular message in the form <N>, where N is the log level.   The typical
4 Kbytes contains anywhere from 50 to 100 lines with that log level prefix.

hv_dmsg_dump() makes a call to kmsg_dump_get_buffer().  The second argument in
the call is a bool described as: ‘@syslog: include the “<4>” Prefixes’.

With this change, we will not write the log level to the allocated page.  This
will provide additional room in the allocated page for more informative panic
information.

Requesting in stable kernels, since many kernels running in production are 
stable releases.

Cc: stable@vger.kernel.org
Signed-off-by: Joseph Salisbury <joseph.salisbury@microsoft.com>
---
 drivers/hv/vmbus_drv.c | 2 +-
 1 file changed, 1 insertion(+), 1 deletion(-)

diff --git a/drivers/hv/vmbus_drv.c b/drivers/hv/vmbus_drv.c
index 9147ee9d5f7d..d69f4efa3719 100644
--- a/drivers/hv/vmbus_drv.c
+++ b/drivers/hv/vmbus_drv.c
@@ -1368,7 +1368,7 @@ static void hv_kmsg_dump(struct kmsg_dumper *dumper,
 	 * Write dump contents to the page. No need to synchronize; panic should
 	 * be single-threaded.
 	 */
-	kmsg_dump_get_buffer(dumper, true, hv_panic_page, HV_HYP_PAGE_SIZE,
+	kmsg_dump_get_buffer(dumper, false, hv_panic_page, HV_HYP_PAGE_SIZE,
 			     &bytes_written);
 	if (bytes_written)
 		hyperv_report_panic_msg(panic_pa, bytes_written);
-- 
2.17.1

RE: [PATCH] Drivers: hv: Change flag to write log level in panic msg to false

[Michael Kelley]

From: Joseph Salisbury <joseph.salisbury@microsoft.com> Sent: Friday, June 26, 2020 10:48 AM
> 
> When the kernel panics, one page worth of kmsg data is written to an allocated
> page.  The Hypervisor is notified of the page address trough the MSR.  This
> panic information is collected on the host.  Since we are only collecting one
> page of data, the full panic message may not be collected.
> 
> Each line of the panic message is prefixed with the log level of that
> particular message in the form <N>, where N is the log level.   The typical
> 4 Kbytes contains anywhere from 50 to 100 lines with that log level prefix.
> 
> hv_dmsg_dump() makes a call to kmsg_dump_get_buffer().  The second argument in
> the call is a bool described as: ‘@syslog: include the “<4>” Prefixes’.
> 
> With this change, we will not write the log level to the allocated page.  This
> will provide additional room in the allocated page for more informative panic
> information.

Let me suggest tightening the commit message a bit, with focus on the "what"
and "why" rather than the details of the code change.  Also use imperative
voice per the Linux kernel guidelines:

When the kernel panics, one page of kmsg data may be collected and sent to
Hyper-V to aid in diagnosing the failure.  The collected kmsg data typically
contains 50 to 100 lines, each of which has a log level prefix that isn't very
useful from a diagnostic standpoint.  So tell kmsg_dump_get_buffer() to not
include the log level, enabling more information that *is* useful to fit in the page.

> 
> Requesting in stable kernels, since many kernels running in production are
> stable releases.
> 
> Cc: stable@vger.kernel.org
> Signed-off-by: Joseph Salisbury <joseph.salisbury@microsoft.com>
> ---
>  drivers/hv/vmbus_drv.c | 2 +-
>  1 file changed, 1 insertion(+), 1 deletion(-)
> 
> diff --git a/drivers/hv/vmbus_drv.c b/drivers/hv/vmbus_drv.c
> index 9147ee9d5f7d..d69f4efa3719 100644
> --- a/drivers/hv/vmbus_drv.c
> +++ b/drivers/hv/vmbus_drv.c
> @@ -1368,7 +1368,7 @@ static void hv_kmsg_dump(struct kmsg_dumper *dumper,
>  	 * Write dump contents to the page. No need to synchronize; panic should
>  	 * be single-threaded.
>  	 */
> -	kmsg_dump_get_buffer(dumper, true, hv_panic_page, HV_HYP_PAGE_SIZE,
> +	kmsg_dump_get_buffer(dumper, false, hv_panic_page, HV_HYP_PAGE_SIZE,
>  			     &bytes_written);
>  	if (bytes_written)
>  		hyperv_report_panic_msg(panic_pa, bytes_written);
> --
> 2.17.1

With the commit message changes,

Reviewed-by: Michael Kelley <mikelley@microsoft.com>

RE: [PATCH] Drivers: hv: Change flag to write log level in panic msg to false

[Joseph Salisbury]

Thanks for the feedback, Michael.  I'll send a v2.

Thanks,

Joe


-----Original Message-----
From: Michael Kelley <mikelley@microsoft.com> 
Sent: Friday, June 26, 2020 4:53 PM
To: Joseph Salisbury <Joseph.Salisbury@microsoft.com>; KY Srinivasan <kys@microsoft.com>; Haiyang Zhang <haiyangz@microsoft.com>; Stephen Hemminger <sthemmin@microsoft.com>; sashal@kernel.org; wei.liu@kernel.org
Cc: linux-hyperv@vger.kernel.org; linux-kernel@vger.kernel.org; stable@vger.kernel.org
Subject: RE: [PATCH] Drivers: hv: Change flag to write log level in panic msg to false

From: Joseph Salisbury <joseph.salisbury@microsoft.com> Sent: Friday, June 26, 2020 10:48 AM
> 
> When the kernel panics, one page worth of kmsg data is written to an 
> allocated page.  The Hypervisor is notified of the page address trough 
> the MSR.  This panic information is collected on the host.  Since we 
> are only collecting one page of data, the full panic message may not be collected.
> 
> Each line of the panic message is prefixed with the log level of that
> particular message in the form <N>, where N is the log level.   The typical
> 4 Kbytes contains anywhere from 50 to 100 lines with that log level prefix.
> 
> hv_dmsg_dump() makes a call to kmsg_dump_get_buffer().  The second 
> argument in the call is a bool described as: ‘@syslog: include the “<4>” Prefixes’.
> 
> With this change, we will not write the log level to the allocated 
> page.  This will provide additional room in the allocated page for 
> more informative panic information.

Let me suggest tightening the commit message a bit, with focus on the "what"
and "why" rather than the details of the code change.  Also use imperative voice per the Linux kernel guidelines:

When the kernel panics, one page of kmsg data may be collected and sent to Hyper-V to aid in diagnosing the failure.  The collected kmsg data typically contains 50 to 100 lines, each of which has a log level prefix that isn't very useful from a diagnostic standpoint.  So tell kmsg_dump_get_buffer() to not include the log level, enabling more information that *is* useful to fit in the page.

> 
> Requesting in stable kernels, since many kernels running in production 
> are stable releases.
> 
> Cc: stable@vger.kernel.org
> Signed-off-by: Joseph Salisbury <joseph.salisbury@microsoft.com>
> ---
>  drivers/hv/vmbus_drv.c | 2 +-
>  1 file changed, 1 insertion(+), 1 deletion(-)
> 
> diff --git a/drivers/hv/vmbus_drv.c b/drivers/hv/vmbus_drv.c index 
> 9147ee9d5f7d..d69f4efa3719 100644
> --- a/drivers/hv/vmbus_drv.c
> +++ b/drivers/hv/vmbus_drv.c
> @@ -1368,7 +1368,7 @@ static void hv_kmsg_dump(struct kmsg_dumper *dumper,
>  	 * Write dump contents to the page. No need to synchronize; panic should
>  	 * be single-threaded.
>  	 */
> -	kmsg_dump_get_buffer(dumper, true, hv_panic_page, HV_HYP_PAGE_SIZE,
> +	kmsg_dump_get_buffer(dumper, false, hv_panic_page, HV_HYP_PAGE_SIZE,
>  			     &bytes_written);
>  	if (bytes_written)
>  		hyperv_report_panic_msg(panic_pa, bytes_written);
> --
> 2.17.1

With the commit message changes,

Reviewed-by: Michael Kelley <mikelley@microsoft.com>

RE: [PATCH] Drivers: hv: Change flag to write log level in panic msg to false

[Michael Kelley]

From: Joseph Salisbury <Joseph.Salisbury@microsoft.com>  Sent: Friday, June 26, 2020 3:16 PM
> 
> Thanks for the feedback, Michael.  I'll send a v2.
> 
> Thanks,
> 
> Joe

A quick note:  The style on the Linux kernel mailing lists is to always reply
inline, after the text you are replying to.  This is quite different from the
style usually used inside Microsoft, which is called "top posting".

Michael

> 
> 
> -----Original Message-----
> From: Michael Kelley <mikelley@microsoft.com>
> Sent: Friday, June 26, 2020 4:53 PM
> To: Joseph Salisbury <Joseph.Salisbury@microsoft.com>; KY Srinivasan
> <kys@microsoft.com>; Haiyang Zhang <haiyangz@microsoft.com>; Stephen Hemminger
> <sthemmin@microsoft.com>; sashal@kernel.org; wei.liu@kernel.org
> Cc: linux-hyperv@vger.kernel.org; linux-kernel@vger.kernel.org; stable@vger.kernel.org
> Subject: RE: [PATCH] Drivers: hv: Change flag to write log level in panic msg to false
> 
> From: Joseph Salisbury <joseph.salisbury@microsoft.com> Sent: Friday, June 26, 2020 10:48
> AM
> >
> > When the kernel panics, one page worth of kmsg data is written to an
> > allocated page.  The Hypervisor is notified of the page address trough
> > the MSR.  This panic information is collected on the host.  Since we
> > are only collecting one page of data, the full panic message may not be collected.
> >
> > Each line of the panic message is prefixed with the log level of that
> > particular message in the form <N>, where N is the log level.   The typical
> > 4 Kbytes contains anywhere from 50 to 100 lines with that log level prefix.
> >
> > hv_dmsg_dump() makes a call to kmsg_dump_get_buffer().  The second
> > argument in the call is a bool described as: ‘@syslog: include the “<4>” Prefixes’.
> >
> > With this change, we will not write the log level to the allocated
> > page.  This will provide additional room in the allocated page for
> > more informative panic information.
> 
> Let me suggest tightening the commit message a bit, with focus on the "what"
> and "why" rather than the details of the code change.  Also use imperative voice per the
> Linux kernel guidelines:
> 
> When the kernel panics, one page of kmsg data may be collected and sent to Hyper-V to aid
> in diagnosing the failure.  The collected kmsg data typically contains 50 to 100 lines, each of
> which has a log level prefix that isn't very useful from a diagnostic standpoint.  So tell
> kmsg_dump_get_buffer() to not include the log level, enabling more information that *is*
> useful to fit in the page.
> 
> >
> > Requesting in stable kernels, since many kernels running in production
> > are stable releases.
> >
> > Cc: stable@vger.kernel.org
> > Signed-off-by: Joseph Salisbury <joseph.salisbury@microsoft.com>
> > ---
> >  drivers/hv/vmbus_drv.c | 2 +-
> >  1 file changed, 1 insertion(+), 1 deletion(-)
> >
> > diff --git a/drivers/hv/vmbus_drv.c b/drivers/hv/vmbus_drv.c index
> > 9147ee9d5f7d..d69f4efa3719 100644
> > --- a/drivers/hv/vmbus_drv.c
> > +++ b/drivers/hv/vmbus_drv.c
> > @@ -1368,7 +1368,7 @@ static void hv_kmsg_dump(struct kmsg_dumper *dumper,
> >  	 * Write dump contents to the page. No need to synchronize; panic should
> >  	 * be single-threaded.
> >  	 */
> > -	kmsg_dump_get_buffer(dumper, true, hv_panic_page, HV_HYP_PAGE_SIZE,
> > +	kmsg_dump_get_buffer(dumper, false, hv_panic_page, HV_HYP_PAGE_SIZE,
> >  			     &bytes_written);
> >  	if (bytes_written)
> >  		hyperv_report_panic_msg(panic_pa, bytes_written);
> > --
> > 2.17.1
> 
> With the commit message changes,
> 
> Reviewed-by: Michael Kelley <mikelley@microsoft.com>

RE: [PATCH] Drivers: hv: Change flag to write log level in panic msg to false

[Joseph Salisbury]

-----Original Message-----
From: Michael Kelley <mikelley@microsoft.com> 
Sent: Friday, June 26, 2020 6:24 PM
To: Joseph Salisbury <Joseph.Salisbury@microsoft.com>; KY Srinivasan <kys@microsoft.com>; Haiyang Zhang <haiyangz@microsoft.com>; Stephen Hemminger <sthemmin@microsoft.com>; sashal@kernel.org; wei.liu@kernel.org
Cc: linux-hyperv@vger.kernel.org; linux-kernel@vger.kernel.org; stable@vger.kernel.org
Subject: RE: [PATCH] Drivers: hv: Change flag to write log level in panic msg to false

From: Joseph Salisbury <Joseph.Salisbury@microsoft.com>  Sent: Friday, June 26, 2020 3:16 PM
> 
> Thanks for the feedback, Michael.  I'll send a v2.
> 
> Thanks,
> 
> Joe

A quick note:  The style on the Linux kernel mailing lists is to always reply inline, after the text you are replying to.  This is quite different from the style usually used inside Microsoft, which is called "top posting".

Michael

ACK, thanks!

Joe

> 
> 
> -----Original Message-----
> From: Michael Kelley <mikelley@microsoft.com>
> Sent: Friday, June 26, 2020 4:53 PM
> To: Joseph Salisbury <Joseph.Salisbury@microsoft.com>; KY Srinivasan 
> <kys@microsoft.com>; Haiyang Zhang <haiyangz@microsoft.com>; Stephen 
> Hemminger <sthemmin@microsoft.com>; sashal@kernel.org; 
> wei.liu@kernel.org
> Cc: linux-hyperv@vger.kernel.org; linux-kernel@vger.kernel.org; 
> stable@vger.kernel.org
> Subject: RE: [PATCH] Drivers: hv: Change flag to write log level in 
> panic msg to false
> 
> From: Joseph Salisbury <joseph.salisbury@microsoft.com> Sent: Friday, 
> June 26, 2020 10:48 AM
> >
> > When the kernel panics, one page worth of kmsg data is written to an 
> > allocated page.  The Hypervisor is notified of the page address 
> > trough the MSR.  This panic information is collected on the host.  
> > Since we are only collecting one page of data, the full panic message may not be collected.
> >
> > Each line of the panic message is prefixed with the log level of that
> > particular message in the form <N>, where N is the log level.   The typical
> > 4 Kbytes contains anywhere from 50 to 100 lines with that log level prefix.
> >
> > hv_dmsg_dump() makes a call to kmsg_dump_get_buffer().  The second 
> > argument in the call is a bool described as: ‘@syslog: include the “<4>” Prefixes’.
> >
> > With this change, we will not write the log level to the allocated 
> > page.  This will provide additional room in the allocated page for 
> > more informative panic information.
> 
> Let me suggest tightening the commit message a bit, with focus on the "what"
> and "why" rather than the details of the code change.  Also use 
> imperative voice per the Linux kernel guidelines:
> 
> When the kernel panics, one page of kmsg data may be collected and 
> sent to Hyper-V to aid in diagnosing the failure.  The collected kmsg 
> data typically contains 50 to 100 lines, each of which has a log level 
> prefix that isn't very useful from a diagnostic standpoint.  So tell
> kmsg_dump_get_buffer() to not include the log level, enabling more 
> information that *is* useful to fit in the page.
> 
> >
> > Requesting in stable kernels, since many kernels running in 
> > production are stable releases.
> >
> > Cc: stable@vger.kernel.org
> > Signed-off-by: Joseph Salisbury <joseph.salisbury@microsoft.com>
> > ---
> >  drivers/hv/vmbus_drv.c | 2 +-
> >  1 file changed, 1 insertion(+), 1 deletion(-)
> >
> > diff --git a/drivers/hv/vmbus_drv.c b/drivers/hv/vmbus_drv.c index
> > 9147ee9d5f7d..d69f4efa3719 100644
> > --- a/drivers/hv/vmbus_drv.c
> > +++ b/drivers/hv/vmbus_drv.c
> > @@ -1368,7 +1368,7 @@ static void hv_kmsg_dump(struct kmsg_dumper *dumper,
> >  	 * Write dump contents to the page. No need to synchronize; panic should
> >  	 * be single-threaded.
> >  	 */
> > -	kmsg_dump_get_buffer(dumper, true, hv_panic_page, HV_HYP_PAGE_SIZE,
> > +	kmsg_dump_get_buffer(dumper, false, hv_panic_page, 
> > +HV_HYP_PAGE_SIZE,
> >  			     &bytes_written);
> >  	if (bytes_written)
> >  		hyperv_report_panic_msg(panic_pa, bytes_written);
> > --
> > 2.17.1
> 
> With the commit message changes,
> 
> Reviewed-by: Michael Kelley <mikelley@microsoft.com>

Re: [PATCH] Drivers: hv: Change flag to write log level in panic msg to false

[Sasha Levin]

Hi

[This is an automated email]

This commit has been processed because it contains a -stable tag.
The stable tag indicates that it's relevant for the following trees: all

The bot has tested the following trees: v5.7.6, v5.4.49, v4.19.130, v4.14.186, v4.9.228, v4.4.228.

v5.7.6: Build OK!
v5.4.49: Failed to apply! Possible dependencies:
    53edce00ceb74 ("Drivers: hv: vmbus: Remove dependencies on guest page size")

v4.19.130: Failed to apply! Possible dependencies:
    53edce00ceb74 ("Drivers: hv: vmbus: Remove dependencies on guest page size")

v4.14.186: Failed to apply! Possible dependencies:
    4a5f3cde4d51c ("Drivers: hv: vmbus: Remove x86-isms from arch independent drivers")
    53edce00ceb74 ("Drivers: hv: vmbus: Remove dependencies on guest page size")
    7ed4325a44ea5 ("Drivers: hv: vmbus: Make panic reporting to be more useful")
    81b18bce48af3 ("Drivers: HV: Send one page worth of kmsg dump over Hyper-V during panic")
    8afc06dd75c06 ("Drivers: hv: vmbus: Fix the issue with freeing up hv_ctl_table_hdr")
    ddcaf3ca4c3c8 ("Drivers: hv: vmus: Fix the check for return value from kmsg get dump buffer")

v4.9.228: Failed to apply! Possible dependencies:
    4a5f3cde4d51c ("Drivers: hv: vmbus: Remove x86-isms from arch independent drivers")
    6ab42a66d2cc1 ("Drivers: hv: vmbus: Move Hypercall invocation code out of common code")
    73638cddaad86 ("Drivers: hv: vmbus: Move the check for hypercall page setup")
    76d36ab798204 ("hv: switch to cpuhp state machine for synic init/cleanup")
    81b18bce48af3 ("Drivers: HV: Send one page worth of kmsg dump over Hyper-V during panic")
    8730046c1498e ("Drivers: hv vmbus: Move Hypercall page setup out of common code")
    d058fa7e98ff0 ("Drivers: hv: vmbus: Move the crash notification function")

v4.4.228: Failed to apply! Possible dependencies:
    4a5f3cde4d51c ("Drivers: hv: vmbus: Remove x86-isms from arch independent drivers")
    619848bd07434 ("drivers:hv: Export a function that maps Linux CPU num onto Hyper-V proc num")
    6ab42a66d2cc1 ("Drivers: hv: vmbus: Move Hypercall invocation code out of common code")
    73638cddaad86 ("Drivers: hv: vmbus: Move the check for hypercall page setup")
    75ff3a8a9168d ("Drivers: hv: vmbus: avoid wait_for_completion() on crash")
    76d36ab798204 ("hv: switch to cpuhp state machine for synic init/cleanup")
    81b18bce48af3 ("Drivers: HV: Send one page worth of kmsg dump over Hyper-V during panic")
    8730046c1498e ("Drivers: hv vmbus: Move Hypercall page setup out of common code")
    a108393dbf764 ("drivers:hv: Export the API to invoke a hypercall on Hyper-V")
    d058fa7e98ff0 ("Drivers: hv: vmbus: Move the crash notification function")


NOTE: The patch will not be queued to stable trees until it is upstream.

How should we proceed with this patch?

-- 
Thanks
Sasha

Re: [PATCH] Drivers: hv: Change flag to write log level in panic msg to false

[Olaf Hering]

[-- Attachment #1: Type: text/plain, Size: 722 bytes --]

On Fri, Jun 26, Joseph Salisbury wrote:

> When the kernel panics, one page worth of kmsg data is written to an allocated
> page.  The Hypervisor is notified of the page address trough the MSR.  This
> panic information is collected on the host.  Since we are only collecting one
> page of data, the full panic message may not be collected.

Are the people who need to work with this tiny bit of information
satisfied already, or did they already miss info even with this patch?

I'm asking because kmsg_dump_get_buffer unconditionally includes the
timestamp (unless it is enabled). I do wonder if there should be an API
addition to omit the timestamp. Then even more dmesg output can be
written into the 4k buffer.

Olaf

[-- Attachment #2: signature.asc --]
[-- Type: application/pgp-signature, Size: 833 bytes --]

RE: [PATCH] Drivers: hv: Change flag to write log level in panic msg to false

[Michael Kelley]

From: Olaf Hering <olaf@aepfle.de>  Sent: Friday, July 10, 2020 2:25 AM
> 
> On Fri, Jun 26, Joseph Salisbury wrote:
> 
> > When the kernel panics, one page worth of kmsg data is written to an allocated
> > page.  The Hypervisor is notified of the page address trough the MSR.  This
> > panic information is collected on the host.  Since we are only collecting one
> > page of data, the full panic message may not be collected.
> 
> Are the people who need to work with this tiny bit of information
> satisfied already, or did they already miss info even with this patch?
> 
> I'm asking because kmsg_dump_get_buffer unconditionally includes the
> timestamp (unless it is enabled). I do wonder if there should be an API
> addition to omit the timestamp. Then even more dmesg output can be
> written into the 4k buffer.
> 

It would be nice to get even more dmesg output into the 4K buffer (or
have a buffer that's bigger than 4K) because there are still occurrences
where we don't get all of the call stack.  But I really don't want to eliminate
the timestamp because it is useful for knowing how long the VM has been
running and to understand what intervals of time there might be between
messages.  I thought about whether parsing the data to keep just the
first timestamp might be a useful compromise, but that seems fairly
messy and I'm not sure it's worth it.  Compressing the kmsg text is
another idea, but the compressed text would probably have problems
getting through our reporting systems.  So we've settled for this small
improvement for now.

Michael