bug: Move WARN_ON() "cut here" into exception handler

PATCH In review Kees Cook 5 participants 10 messages Aug 20, 2019 – Sep 10, 2019

Subsystems (2)

Library code Generic include/asm header files

lore

Share & tools

lore

Kees Cook

author

2019-08-20 16:47 UTC #0 lore raw

PATCH v2 7/7 bug: Move WARN_ON() "cut here" into exception handler

The original clean up of "cut here" missed the WARN_ON() case (that does not have a printk message), which was fixed recently by adding an explicit printk of "cut here". This had the downside of adding a printk() to every WARN_ON() caller, which reduces the utility of using an instruction exception to streamline the resulting code. By making this a new BUGFLAG, all of these can be removed and "cut here" can be handled by the exception handler.

This was very pronounced on PowerPC, but the effect can be seen on x86 as well. The resulting text size of a defconfig build shows some small savings from this patch:

text data bss dec hex filename

19691167        5134320 1646664 26472151        193eed7 vmlinux.before
19676362        5134260 1663048 26473670        193f4c6 vmlinux.after

This change also opens the door for creating something like BUG_MSG(), where a custom printk() before issuing BUG(), without confusing the "cut here" line.

Reported-by Christophe Leroy <[email protected]>

Fixes Fixes: 6b15f678fb7d ("include/asm-generic/bug.h: fix "cut here" for WARN_ON for __WARN_TAINT architectures")

Signed-off-by Kees Cook <[email protected]>

---
v2:
- rename BUGFLAG_PRINTK to BUGFLAG_NO_CUT_HERE (peterz, christophe)

---
 include/asm-generic/bug.h |  8 +++-----
 lib/bug.c                 | 11 +++++++++--
 2 files changed, 12 insertions(+), 7 deletions(-)

include/asm-generic/bug.h +3 -5

index 588dd59a5b72..a21e83f8a274 100644
@@ -10,6 +10,7 @@
 #define BUGFLAG_WARNING		(1 << 0)
 #define BUGFLAG_ONCE		(1 << 1)
 #define BUGFLAG_DONE		(1 << 2)
+#define BUGFLAG_NO_CUT_HERE	(1 << 3)	/* CUT_HERE already sent */
 #define BUGFLAG_TAINT(taint)	((taint) << 8)
 #define BUG_GET_TAINT(bug)	((bug)->flags >> 8)
 #endif

@@ -86,13 +87,10 @@ void warn_slowpath_fmt(const char *file, const int line, unsigned taint,
 	warn_slowpath_fmt(__FILE__, __LINE__, taint, arg)
 #else
 extern __printf(1, 2) void __warn_printk(const char *fmt, ...);
-#define __WARN() do {							\
-		printk(KERN_WARNING CUT_HERE);				\
-		__WARN_FLAGS(BUGFLAG_TAINT(TAINT_WARN));		\
-	} while (0)
+#define __WARN()		__WARN_FLAGS(BUGFLAG_TAINT(TAINT_WARN))
 #define __WARN_printf(taint, arg...) do {				\
 		__warn_printk(arg);					\
-		__WARN_FLAGS(BUGFLAG_TAINT(taint));			\
+		__WARN_FLAGS(BUGFLAG_NO_CUT_HERE | BUGFLAG_TAINT(taint));\
 	} while (0)
 #define WARN_ON_ONCE(condition) ({				\
 	int __ret_warn_on = !!(condition);			\

lib/bug.c +9 -2

index 1077366f496b..8c98af0bf585 100644
@@ -181,6 +181,15 @@ enum bug_trap_type report_bug(unsigned long bugaddr, struct pt_regs *regs)
 		}
 	}
 
+	/*
+	 * BUG() and WARN_ON() families don't print a custom debug message
+	 * before triggering the exception handler, so we must add the
+	 * "cut here" line now. WARN() issues its own "cut here" before the
+	 * extra debugging message it writes before triggering the handler.
+	 */
+	if ((bug->flags & BUGFLAG_NO_CUT_HERE) == 0)
+		printk(KERN_DEFAULT CUT_HERE);
+
 	if (warning) {
 		/* this is a WARN_ON rather than BUG/BUG_ON */
 		__warn(file, line, (void *)bugaddr, BUG_GET_TAINT(bug), regs,

@@ -188,8 +197,6 @@ enum bug_trap_type report_bug(unsigned long bugaddr, struct pt_regs *regs)
 		return BUG_TRAP_TYPE_WARN;
 	}
 
-	printk(KERN_DEFAULT CUT_HERE);
-
 	if (file)
 		pr_crit("kernel BUG at %s:%u!\n", file, line);
 	else

Signature · 5 lines

2.17.1


-- 
Kees Cook

Andrew Morton

maintainer

2019-08-22 22:56 UTC #1 lore raw

Quoted 1 line · On Tue, 20 Aug 2019 09:47:55 -0700 Kees Cook <[email protected]> wrote:

Reply-To: [email protected]

Really?

Quoted 1 line

Subject: [PATCH v2 7/7] bug: Move WARN_ON() "cut here" into exception handler

It's strange to receive a standalone [7/7] patch.

Quoted 15 lines

Date:   Tue, 20 Aug 2019 09:47:55 -0700
Sender: [email protected]
The original clean up of "cut here" missed the WARN_ON() case (that does not have a printk message), which was fixed recently by adding an explicit printk of "cut here". This had the downside of adding a printk() to every WARN_ON() caller, which reduces the utility of using an instruction exception to streamline the resulting code. By making this a new BUGFLAG, all of these can be removed and "cut here" can be handled by the exception handler.
This was very pronounced on PowerPC, but the effect can be seen on x86 as well. The resulting text size of a defconfig build shows some small savings from this patch:

Quoted 7 lines

text data bss dec hex filename
19691167        5134320 1646664 26472151        193eed7 vmlinux.before
19676362        5134260 1663048 26473670        193f4c6 vmlinux.after
This change also opens the door for creating something like BUG_MSG(), where a custom printk() before issuing BUG(), without confusing the "cut here" line.

I can't get this to apply to anything, so I guess that [1/7]-[6/7] mattered ;)

Quoted 2 lines

Reported-by Christophe Leroy <[email protected]>
Fixes Fixes: 6b15f678fb7d ("include/asm-generic/bug.h: fix "cut here" for WARN_ON for __WARN_TAINT architectures")

I'm seeing double.

Quoted 1 line

Signed-off-by Kees Cook <[email protected]>

Christophe Leroy

2019-08-23 14:26 UTC #2 lore raw

Le 23/08/2019 à 00:56, Andrew Morton a écrit :

Quoted 5 lines · On Tue, 20 Aug 2019 09:47:55 -0700 Kees Cook <[email protected]> wrote:

Quoted 2 lines
Reply-To: [email protected]
Really?

That seems correct, that's the "[PATCH 7/7] bug: Move WARN_ON() "cut here" into exception handler" from the series at https://lkml.org/lkml/2019/8/19/1155

Quoted 4 lines

Quoted 2 lines
Subject: [PATCH v2 7/7] bug: Move WARN_ON() "cut here" into exception handler
It's strange to receive a standalone [7/7] patch.

Iaw the Reply_To, I understand it as an update of the 7th patch of the series.

Quoted 20 lines

Quoted 20 lines
Date:   Tue, 20 Aug 2019 09:47:55 -0700
Sender: [email protected]
The original clean up of "cut here" missed the WARN_ON() case (that does not have a printk message), which was fixed recently by adding an explicit printk of "cut here". This had the downside of adding a printk() to every WARN_ON() caller, which reduces the utility of using an instruction exception to streamline the resulting code. By making this a new BUGFLAG, all of these can be removed and "cut here" can be handled by the exception handler.
This was very pronounced on PowerPC, but the effect can be seen on x86 as well. The resulting text size of a defconfig build shows some small savings from this patch:
text data bss dec hex filename
19691167        5134320 1646664 26472151        193eed7 vmlinux.before
19676362        5134260 1663048 26473670        193f4c6 vmlinux.after

Quoted 6 lines

Quoted 3 lines
This change also opens the door for creating something like BUG_MSG(), where a custom printk() before issuing BUG(), without confusing the "cut here" line.
I can't get this to apply to anything, so I guess that [1/7]-[6/7] mattered ;)

On my side it applies cleanly on top of patch 1-6 of the series.

Christophe

Quoted 7 lines

Quoted 3 lines
Reported-by Christophe Leroy <[email protected]>
Fixes Fixes: 6b15f678fb7d ("include/asm-generic/bug.h: fix "cut here" for WARN_ON for __WARN_TAINT architectures")
I'm seeing double.
Quoted 1 line
Signed-off-by Kees Cook <[email protected]>

Kees Cook

author

2019-08-24 19:08 UTC #3 lore raw

Quoted 15 lines · Christophe Leroy

Le 23/08/2019 à 00:56, Andrew Morton a écrit :
Quoted 5 lines · On Tue, 20 Aug 2019 09:47:55 -0700 Kees Cook <[email protected]> wrote:
Quoted 2 lines
Reply-To: [email protected]
Really?
That seems correct, that's the "[PATCH 7/7] bug: Move WARN_ON() "cut here" into exception handler" from the series at
https://lkml.org/lkml/2019/8/19/1155
Quoted 1 line

Quoted 6 lines

Quoted 3 lines
Quoted 1 line
Subject: [PATCH v2 7/7] bug: Move WARN_ON() "cut here" into exception handler
It's strange to receive a standalone [7/7] patch.
Iaw the Reply_To, I understand it as an update of the 7th patch of the series.

Was trying to avoid the churn of resending the identical 1-6 patches (which are all just refactoring to make 7/7 not a mess).

I can resend the whole series, if that's preferred.

Quoted 4 lines

Quoted 4 lines
Quoted 2 lines
Reported-by Christophe Leroy <[email protected]>
Fixes Fixes: 6b15f678fb7d ("include/asm-generic/bug.h: fix "cut here" for WARN_ON for __WARN_TAINT architectures")
I'm seeing double.

Tracking down all these combinations has been tricky, which is why I did the patch 1-6 refactoring: it makes the call hierarchy much easier to examine (IMO).

-Kees

Signature · 1 line

Kees Cook

Christophe Leroy

2019-08-29 04:55 UTC #4 lore raw

Le 24/08/2019 à 21:08, Kees Cook a écrit :

Euh ... only received this mail yesterday. Same for the other answer.

Quoted 18 lines · Christophe Leroy

Quoted 17 lines
Le 23/08/2019 à 00:56, Andrew Morton a écrit :
Quoted 5 lines · On Tue, 20 Aug 2019 09:47:55 -0700 Kees Cook <[email protected]> wrote:
Quoted 2 lines
Reply-To: [email protected]
Really?
That seems correct, that's the "[PATCH 7/7] bug: Move WARN_ON() "cut here" into exception handler" from the series at
https://lkml.org/lkml/2019/8/19/1155
Quoted 3 lines
Quoted 2 lines
Subject: [PATCH v2 7/7] bug: Move WARN_ON() "cut here" into exception handler

Quoted 7 lines

Quoted 4 lines
Quoted 1 line
It's strange to receive a standalone [7/7] patch.
Iaw the Reply_To, I understand it as an update of the 7th patch of the series.
Was trying to avoid the churn of resending the identical 1-6 patches (which are all just refactoring to make 7/7 not a mess).

Yes but Reply-To: means the address we have to use to answer to this email.

I think you wanted to use In-reply-to:

Quoted 2 lines

I can resend the whole series, if that's preferred.

I guess not.

Quoted 9 lines

Quoted 5 lines
Quoted 5 lines
Quoted 3 lines
Reported-by Christophe Leroy <[email protected]>
Fixes Fixes: 6b15f678fb7d ("include/asm-generic/bug.h: fix "cut here" for WARN_ON for __WARN_TAINT architectures")
I'm seeing double.
Tracking down all these combinations has been tricky, which is why I did the patch 1-6 refactoring: it makes the call hierarchy much easier to examine (IMO).

But still, Andrew is seing double ... And me as well :)

Fixes Fixes:

Christophe

Quoted 3 lines

-Kees

Kees Cook

author

2019-08-29 16:12 UTC #5 lore raw

Quoted 1 line · Christophe Leroy

Euh ... only received this mail yesterday. Same for the other answer.

Yeah, my outbound mail was busted. :(

Quoted 5 lines

I think you wanted to use In-reply-to:
[...]
But still, Andrew is seing double ... And me as well :)
Fixes Fixes:

I had a lot of failures in that email. :)

Thank you Andrew for cleaning this up.

Signature · 1 line

Kees Cook

Christophe Leroy

Tested-by on v2 7/7

2019-08-23 14:56 UTC #6 lore raw

In reply to Kees Cook

In-Reply-To: [email protected]

Le 20/08/2019 à 18:47, Kees Cook a écrit :

Quoted 16 lines

The original clean up of "cut here" missed the WARN_ON() case (that does not have a printk message), which was fixed recently by adding an explicit printk of "cut here". This had the downside of adding a printk() to every WARN_ON() caller, which reduces the utility of using an instruction exception to streamline the resulting code. By making this a new BUGFLAG, all of these can be removed and "cut here" can be handled by the exception handler.
This was very pronounced on PowerPC, but the effect can be seen on x86 as well. The resulting text size of a defconfig build shows some small savings from this patch:
text data bss dec hex filename
19691167        5134320 1646664 26472151        193eed7 vmlinux.before
19676362        5134260 1663048 26473670        193f4c6 vmlinux.after

Quoted 7 lines

This change also opens the door for creating something like BUG_MSG(), where a custom printk() before issuing BUG(), without confusing the "cut here" line.
Reported-by Christophe Leroy <[email protected]>
Fixes Fixes: 6b15f678fb7d ("include/asm-generic/bug.h: fix "cut here" for WARN_ON for __WARN_TAINT architectures")
Signed-off-by Kees Cook <[email protected]>

Tested-by Christophe Leroy <[email protected]>

Quoted 66 lines

---
v2:
- rename BUGFLAG_PRINTK to BUGFLAG_NO_CUT_HERE (peterz, christophe)

---
  include/asm-generic/bug.h |  8 +++-----
  lib/bug.c                 | 11 +++++++++--
  2 files changed, 12 insertions(+), 7 deletions(-)

include/asm-generic/bug.h +3 -5

index 588dd59a5b72..a21e83f8a274 100644
@@ -10,6 +10,7 @@
  #define BUGFLAG_WARNING		(1 << 0)
  #define BUGFLAG_ONCE		(1 << 1)
  #define BUGFLAG_DONE		(1 << 2)
+#define BUGFLAG_NO_CUT_HERE	(1 << 3)	/* CUT_HERE already sent */
  #define BUGFLAG_TAINT(taint)	((taint) << 8)
  #define BUG_GET_TAINT(bug)	((bug)->flags >> 8)
  #endif

@@ -86,13 +87,10 @@ void warn_slowpath_fmt(const char *file, const int line, unsigned taint,
  	warn_slowpath_fmt(__FILE__, __LINE__, taint, arg)
  #else
  extern __printf(1, 2) void __warn_printk(const char *fmt, ...);
-#define __WARN() do {							\
-		printk(KERN_WARNING CUT_HERE);				\
-		__WARN_FLAGS(BUGFLAG_TAINT(TAINT_WARN));		\
-	} while (0)
+#define __WARN()		__WARN_FLAGS(BUGFLAG_TAINT(TAINT_WARN))
  #define __WARN_printf(taint, arg...) do {				\
  		__warn_printk(arg);					\
-		__WARN_FLAGS(BUGFLAG_TAINT(taint));			\
+		__WARN_FLAGS(BUGFLAG_NO_CUT_HERE | BUGFLAG_TAINT(taint));\
  	} while (0)
  #define WARN_ON_ONCE(condition) ({				\
  	int __ret_warn_on = !!(condition);			\

lib/bug.c +9 -2

index 1077366f496b..8c98af0bf585 100644
@@ -181,6 +181,15 @@ enum bug_trap_type report_bug(unsigned long bugaddr, struct pt_regs *regs)
  		}
  	}
 
+	/*
+	 * BUG() and WARN_ON() families don't print a custom debug message
+	 * before triggering the exception handler, so we must add the
+	 * "cut here" line now. WARN() issues its own "cut here" before the
+	 * extra debugging message it writes before triggering the handler.
+	 */
+	if ((bug->flags & BUGFLAG_NO_CUT_HERE) == 0)
+		printk(KERN_DEFAULT CUT_HERE);
+
  	if (warning) {
  		/* this is a WARN_ON rather than BUG/BUG_ON */
  		__warn(file, line, (void *)bugaddr, BUG_GET_TAINT(bug), regs,

@@ -188,8 +197,6 @@ enum bug_trap_type report_bug(unsigned long bugaddr, struct pt_regs *regs)
  		return BUG_TRAP_TYPE_WARN;
  	}
 
-	printk(KERN_DEFAULT CUT_HERE);
-
  	if (file)
  		pr_crit("kernel BUG at %s:%u!\n", file, line);
  	else

Sergey Senozhatsky

2019-09-09 16:05 UTC #7 lore raw

In reply to Kees Cook

On (08/20/19 09:47), Kees Cook wrote:
[..]

lib/bug.c enum bug_trap_type report_bug(unsigned long bugaddr, struct pt_regs *regs) · line 191

Quoted 12 lines

lib/bug.c +8 -0

@@ -181,6 +181,15 @@ enum bug_trap_type report_bug(unsigned long bugaddr, struct pt_regs *regs)
 		}
 	}
 
+	/*
+	 * BUG() and WARN_ON() families don't print a custom debug message
+	 * before triggering the exception handler, so we must add the
+	 * "cut here" line now. WARN() issues its own "cut here" before the
+	 * extra debugging message it writes before triggering the handler.
+	 */
+	if ((bug->flags & BUGFLAG_NO_CUT_HERE) == 0)
+		printk(KERN_DEFAULT CUT_HERE);

Shouldn't this be pr_warn() or pr_crit()?

-ss

Kees Cook

author

2019-09-10 08:59 UTC #8 lore raw

Quoted 6 lines · Sergey Senozhatsky

On (08/20/19 09:47), Kees Cook wrote:
[..]
Quoted 4 lines
(quoted diff) +0 -0
@@ -181,6 +181,15 @@ enum bug_trap_type report_bug(unsigned long bugaddr, struct pt_regs *regs)
 		}
 	}
 

Quoted 10 lines

lib/bug.c enum bug_trap_type report_bug(unsigned long bugaddr, struct pt_regs *regs) · line 191

Quoted 8 lines

lib/bug.c +8 -0

+	/*
+	 * BUG() and WARN_ON() families don't print a custom debug message
+	 * before triggering the exception handler, so we must add the
+	 * "cut here" line now. WARN() issues its own "cut here" before the
+	 * extra debugging message it writes before triggering the handler.
+	 */
+	if ((bug->flags & BUGFLAG_NO_CUT_HERE) == 0)
+		printk(KERN_DEFAULT CUT_HERE);

Shouldn't this be pr_warn() or pr_crit()?

The pr_* helpers here would (potentially) add unwanted prefixes, so those aren't used. KERN_DEFAULT is used here because that's how it's always been printed. I didn't want to change that for this refactoring work. I'm not opposed to it, generally speaking, though. :)

Signature · 1 line

Kees Cook

Sergey Senozhatsky

2019-09-10 09:16 UTC #9 lore raw

Quoted 14 lines · Kees Cook

Quoted 12 lines · Sergey Senozhatsky
On (08/20/19 09:47), Kees Cook wrote:
[..]
lib/bug.c enum bug_trap_type report_bug(unsigned long bugaddr, struct pt_regs *regs) · line 191
Quoted 8 lines
lib/bug.c +8 -0
+	/*
+	 * BUG() and WARN_ON() families don't print a custom debug message
+	 * before triggering the exception handler, so we must add the
+	 * "cut here" line now. WARN() issues its own "cut here" before the
+	 * extra debugging message it writes before triggering the handler.
+	 */
+	if ((bug->flags & BUGFLAG_NO_CUT_HERE) == 0)
+		printk(KERN_DEFAULT CUT_HERE);
Shouldn't this be pr_warn() or pr_crit()?

Quoted 4 lines

The pr_* helpers here would (potentially) add unwanted prefixes, so those aren't used. KERN_DEFAULT is used here because that's how it's always been printed. I didn't want to change that for this refactoring work. I'm not opposed to it, generally speaking, though. :)

I just glanced through CUT_HERE users

warn_slowpath_fmt()    pr_warn(CUT_HERE)
__warn_printk()        pr_warn(CUT_HERE)
rdma_restrack_clean()  pr_err("restrack: %s", CUT_HERE)
rdma_restrack_clean()  pr_err("restrack: %s", CUT_HERE)

+ oops/panic end markers are of pr_warn() or pr_crit() log levels. So I thought that maybe we can make it more or less similar.

But if it has always been this way (KERN_DEFAULT) then OK.

-ss