Skip to contentSkip to conversation

x86/dumpstack: Cleanups and user opcode bytes Code: section, v2

PATCH In review Borislav Petkov 4 participants 36 messages Mar 15, 2018 – Apr 18, 2018

Subsystems (4)
lore
Share & tools
lore

Borislav Petkov

author maintainer
#0 lore raw

cover x86/dumpstack: Cleanups and user opcode bytes Code: section, v2

From: Borislav Petkov <[email protected]>

Hi all,

here's v2 with the dumpstack cleanups. This one gets rid of code_bytes= as it was discussed last time. As a result, the code got even leaner and simpler. I like that. :)

Thx.

Borislav Petkov (9):
x86/dumstack: Remove code_bytes
x86/dumpstack: Unexport oops_begin()
x86/dumpstack: Carve out Code: dumping into a function x86/dumpstack: Improve opcodes dumping in the Code: section x86/dumpstack: Add loglevel argument to show_opcodes() x86/fault: Dump user opcode bytes on fatal faults x86/dumpstack: Add a show_ip() function
x86/dumpstack: Save first regs set for the executive summary x86/dumpstack: Explain the reasoning for the prologue and buffer size

 Documentation/admin-guide/kernel-parameters.txt |   5 -
 arch/x86/include/asm/stacktrace.h               |   2 +
 arch/x86/kernel/dumpstack.c                     | 138 ++++++++++++------------
 arch/x86/kernel/process_32.c                    |   4 +-
 arch/x86/mm/fault.c                             |   7 +-
 5 files changed, 78 insertions(+), 78 deletions(-)

Changelog:

v1:

Hi,

here's v2 of the dumpstack cleanups.

I've split them into more fine-grained pieces to show each change. The relevant parts are the saving of the executive registers of the first time we oops and dumping them in the end + opcode bytes for user faults. I've tested splats in a 80x25 screen and the registers, RIP and opcode bytes fit all in.

I'm adding exemplary dumps from 32-bit and 64-bit at the end of this mail.

I still have on my TODO list to experiment with console log levels and see whether we can do a best-of-both-worlds thing there.

v0:

Hi,

so I've been thinking about doing this for a while now: be able to dump the opcode bytes around the user rIP just like we do for kernel faults.

Why?

See patch 5's commit message. That's why I've marked it RFC.

The rest is cleanups: we're copying the opcodes byte-by-byte and that's just wasteful.

Also, we're using probe_kernel_read() underneath and it does __copy_from_user_inatomic() which makes copying user opcode bytes trivial.

With that, it looks like this:

[  696.837457] strsep[1733]: segfault at 40066b ip 00007fad558fccf8 sp 00007ffc5e662520 error 7 in libc-2.26.so[7fad55876000+1ad000]
[  696.837538] Code: 1b 48 89 fd 48 89 df e8 77 99 f9 ff 48 01 d8 80 38 00 75 17 48 c7 45 00 00 00 00 00 48 83 c4 08 48 89 d8 5b 5d c3 0f 1f 44 00 00 <c6> 00 00 48 83 c0 01 48 89 45 00 48 83 c4 08 48 89 d8 5b 5d c3

and the code matches, as expected:

0000000000086cc0 <__strsep_g@@GLIBC_2.2.5>:

   86cc0:       55                      push   %rbp
   86cc1:       53                      push   %rbx
   86cc2:       48 83 ec 08             sub    $0x8,%rsp
   86cc6:       48 8b 1f                mov    (%rdi),%rbx
   86cc9:       48 85 db                test   %rbx,%rbx
   86ccc:       74 1b                   je     86ce9 <__strsep_g@@GLIBC_2.2.5+0x29>
   86cce:       48 89 fd                mov    %rdi,%rbp
   86cd1:       48 89 df                mov    %rbx,%rdi
   86cd4:       e8 77 99 f9 ff          callq  20650 <*ABS*+0x854e0@plt>
   86cd9:       48 01 d8                add    %rbx,%rax
   86cdc:       80 38 00                cmpb   $0x0,(%rax)
   86cdf:       75 17                   jne    86cf8 <__strsep_g@@GLIBC_2.2.5+0x38>
   86ce1:       48 c7 45 00 00 00 00    movq   $0x0,0x0(%rbp)
   86ce8:       00 
   86ce9:       48 83 c4 08             add    $0x8,%rsp
   86ced:       48 89 d8                mov    %rbx,%rax
   86cf0:       5b                      pop    %rbx
   86cf1:       5d                      pop    %rbp
   86cf2:       c3                      retq   
   86cf3:       0f 1f 44 00 00          nopl   0x0(%rax,%rax,1)
   86cf8:       c6 00 00                movb   $0x0,(%rax)
   86cfb:       48 83 c0 01             add    $0x1,%rax
   86cff:       48 89 45 00             mov    %rax,0x0(%rbp)
   86d03:       48 83 c4 08             add    $0x8,%rsp
   86d07:       48 89 d8                mov    %rbx,%rax
   86d0a:       5b                      pop    %rbx
   86d0b:       5d                      pop    %rbp
   86d0c:       c3                      retq

Comments and suggestions are welcome!

Thx.

Example dumps (current version):

64-bit:

[   53.534957] sysrq: SysRq : Trigger a crash
[   53.536939] BUG: unable to handle kernel NULL pointer dereference at 0000000000000000
[   53.539982] PGD 79149067 P4D 79149067 PUD 793a5067 PMD 0 
[   53.540897] Oops: 0002 [#1] PREEMPT SMP
[   53.540897] CPU: 6 PID: 3700 Comm: bash Not tainted 4.16.0-rc5+ #11
[   53.540897] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.10.2-1 04/01/2014
[   53.540897] RIP: 0010:sysrq_handle_crash+0x17/0x20
[   53.540897] Code: d1 e8 6d 08 b7 ff 0f 1f 00 66 2e 0f 1f 84 00 00 00 00 00 0f 1f 44 00 00 e8 76 1f bd ff c7 05 a4 12 19 01 01 00 00 00 0f ae f8 <c6> 04 25 00 00 00 00 01 c3 0f 1f 44 00 00 e8 c6 1b c2 ff fb e9 80 
[   53.540897] RSP: 0018:ffffc9000053bdf0 EFLAGS: 00010246
[   53.540897] RAX: 0000000000000000 RBX: 0000000000000063 RCX: 0000000000000000
[   53.540897] RDX: 0000000000000000 RSI: ffffffff81101e0a RDI: 0000000000000063
[   53.540897] RBP: ffffffff822714c0 R08: 0000000000000185 R09: 00000000000829ad
[   53.540897] R10: 0000000000000000 R11: 0000000000000000 R12: 000000000000000a
[   53.540897] R13: 0000000000000000 R14: 0000000000000000 R15: 0000000000000000
[   53.540897] FS:  00007ffff7fdb700(0000) GS:ffff88007ed80000(0000) knlGS:0000000000000000
[   53.540897] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[   53.540897] CR2: 0000000000000000 CR3: 0000000079107000 CR4: 00000000000406e0
[   53.540897] Call Trace:
[   53.540897]  __handle_sysrq+0x9e/0x160
[   53.540897]  write_sysrq_trigger+0x2b/0x30
[   53.540897]  proc_reg_write+0x38/0x70
[   53.540897]  __vfs_write+0x36/0x160
[   53.540897]  ? __fd_install+0x69/0x110
[   53.540897]  ? preempt_count_add+0x74/0xb0
[   53.540897]  ? _raw_spin_lock+0x13/0x30
[   53.540897]  ? set_close_on_exec+0x41/0x80
[   53.540897]  ? preempt_count_sub+0xa8/0x100
[   53.540897]  vfs_write+0xc0/0x190
[   53.540897]  SyS_write+0x64/0xe0
[   53.540897]  ? trace_hardirqs_off_thunk+0x1a/0x1c
[   53.540897]  do_syscall_64+0x70/0x130
[   53.540897]  entry_SYSCALL_64_after_hwframe+0x42/0xb7
[   53.540897] RIP: 0033:0x7ffff74b9620
[   53.540897] Code: 73 01 c3 48 8b 0d 68 98 2c 00 f7 d8 64 89 01 48 83 c8 ff c3 66 0f 1f 44 00 00 83 3d bd f1 2c 00 00 75 10 b8 01 00 00 00 0f 05 <48> 3d 01 f0 ff ff 73 31 c3 48 83 ec 08 e8 ce 8f 01 00 48 89 04 24 
[   53.540897] RSP: 002b:00007fffffffe6f8 EFLAGS: 00000246 ORIG_RAX: 0000000000000001
[   53.540897] RAX: ffffffffffffffda RBX: 0000000000000002 RCX: 00007ffff74b9620
[   53.540897] RDX: 0000000000000002 RSI: 0000000000705408 RDI: 0000000000000001
[   53.540897] RBP: 0000000000705408 R08: 000000000000000a R09: 00007ffff7fdb700
[   53.540897] R10: 00007ffff77826a0 R11: 0000000000000246 R12: 00007ffff77842a0
[   53.540897] R13: 0000000000000002 R14: 0000000000000001 R15: 0000000000000000
[   53.540897] Modules linked in:
[   53.540897] CR2: 0000000000000000
[   53.576029] ---[ end trace 9b6fe8eba592293d ]---
[   53.578109] RIP: 0010:sysrq_handle_crash+0x17/0x20
[   53.580191] Code: d1 e8 6d 08 b7 ff 0f 1f 00 66 2e 0f 1f 84 00 00 00 00 00 0f 1f 44 00 00 e8 76 1f bd ff c7 05 a4 12 19 01 01 00 00 00 0f ae f8 <c6> 04 25 00 00 00 00 01 c3 0f 1f 44 00 00 e8 c6 1b c2 ff fb e9 80 
[   53.587244] RSP: 0018:ffffc9000053bdf0 EFLAGS: 00010246
[   53.587928] RAX: 0000000000000000 RBX: 0000000000000063 RCX: 0000000000000000
[   53.588929] RDX: 0000000000000000 RSI: ffffffff81101e0a RDI: 0000000000000063
[   53.589956] RBP: ffffffff822714c0 R08: 0000000000000185 R09: 00000000000829ad
[   53.590886] R10: 0000000000000000 R11: 0000000000000000 R12: 000000000000000a
[   53.591812] R13: 0000000000000000 R14: 0000000000000000 R15: 0000000000000000
[   53.592781] Kernel panic - not syncing: Fatal exception
[   53.594100] Kernel Offset: disabled
[   53.594571] ---[ end Kernel panic - not syncing: Fatal exception ]---
[   22.737752] strsep[3728]: segfault at 40066b ip 00007ffff7abe22b sp 00007fffffffea60 error 7 in libc-2.19.so[7ffff7a33000+19f000]
[   22.742487] Code: 48 89 fd 53 48 83 ec 08 48 8b 1f 48 85 db 74 67 0f b6 06 84 c0 74 33 80 7e 01 00 74 22 48 89 df e8 5a 8a ff ff 48 85 c0 74 20 <c6> 00 00 48 83 c0 01 48 89 45 00 48 89 d8 48 83 c4 08 5b 5d c3 0f

32-bit
------

[  151.053373] sysrq: SysRq : Trigger a crash
[  151.056586] BUG: unable to handle kernel NULL pointer dereference at 00000000
[  151.060237] *pde = 00000000 
[  151.060484] Oops: 0002 [#1] PREEMPT SMP
[  151.060484] CPU: 1 PID: 2070 Comm: bash Not tainted 4.16.0-rc5+ #12
[  151.060484] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.10.2-1 04/01/2014
[  151.060484] EIP: sysrq_handle_crash+0x1d/0x30
[  151.060484] Code: ff eb d6 e8 75 0f ba ff 90 8d 74 26 00 0f 1f 44 00 00 55 89 e5 e8 03 07 c0 ff c7 05 34 72 c1 c1 01 00 00 00 0f ae f8 0f 1f 00 <c6> 05 00 00 00 00 01 5d c3 8d 76 00 8d bc 27 00 00 00 00 0f 1f 44 
[  151.060484] EAX: 00000000 EBX: 0000000a ECX: 00000000 EDX: c1503f70
[  151.060484] ESI: 00000063 EDI: 00000000 EBP: f36d7e8c ESP: f36d7e8c
[  151.060484]  DS: 007b ES: 007b FS: 00d8 GS: 00e0 SS: 0068
[  151.060484] CR0: 80050033 CR2: 00000000 CR3: 33d64000 CR4: 000406d0
[  151.060484] Call Trace:
[  151.060484]  __handle_sysrq+0x93/0x130
[  151.060484]  ? sysrq_filter+0x3c0/0x3c0
[  151.060484]  write_sysrq_trigger+0x27/0x40
[  151.060484]  proc_reg_write+0x4d/0x80
[  151.060484]  ? proc_reg_poll+0x70/0x70
[  151.060484]  __vfs_write+0x38/0x160
[  151.060484]  ? preempt_count_sub+0xa0/0x110
[  151.060484]  ? __fd_install+0x51/0xd0
[  151.060484]  ? __sb_start_write+0x4c/0xc0
[  151.060484]  ? preempt_count_sub+0xa0/0x110
[  151.060484]  vfs_write+0x98/0x180
[  151.060484]  SyS_write+0x4f/0xb0
[  151.060484]  do_fast_syscall_32+0x99/0x200
[  151.060484]  entry_SYSENTER_32+0x53/0x86
[  151.060484] EIP: 0xb7f25b35
[  151.060484] Code: 89 e5 8b 55 08 8b 80 64 cd ff ff 85 d2 74 02 89 02 5d c3 8b 04 24 c3 8b 0c 24 c3 8b 1c 24 c3 90 90 51 52 55 89 e5 0f 34 cd 80 <5d> 5a 59 c3 90 90 90 90 8d 76 00 58 b8 77 00 00 00 cd 80 90 8d 76 
[  151.060484] EAX: ffffffda EBX: 00000001 ECX: 08b14a08 EDX: 00000002
[  151.060484] ESI: 00000002 EDI: b7ef0d80 EBP: 08b14a08 ESP: bfc53830
[  151.060484]  DS: 007b ES: 007b FS: 0000 GS: 0033 SS: 007b
[  151.060484] Modules linked in:
[  151.060484] CR2: 0000000000000000
[  151.128925] ---[ end trace 822f779813ab57e1 ]---
[  151.136624] EIP: sysrq_handle_crash+0x1d/0x30
[  151.136625] Code: ff eb d6 e8 75 0f ba ff 90 8d 74 26 00 0f 1f 44 00 00 55 89 e5 e8 03 07 c0 ff c7 05 34 72 c1 c1 01 00 00 00 0f ae f8 0f 1f 00 <c6> 05 00 00 00 00 01 5d c3 8d 76 00 8d bc 27 00 00 00 00 0f 1f 44 
[  151.136658] EAX: 00000000 EBX: 0000000a ECX: 00000000 EDX: c1503f70
[  151.136659] ESI: 00000063 EDI: 00000000 EBP: f36d7e8c ESP: c1c0d87c
[  151.136661]  DS: 007b ES: 007b FS: 00d8 GS: 00e0 SS: 0068
[  151.136662] Kernel panic - not syncing: Fatal exception
[  151.137001] Kernel Offset: disabled
[  151.140587] ---[ end Kernel panic - not syncing: Fatal exception ]---
[  103.241026] strsep32[2125]: segfault at 4336a7 ip b7df6758 sp bfc73fd0 error 7 in libc-2.26.so[b7d76000+1cd000]
[  103.252505] Code: 1d 83 ec 08 ff 74 24 1c 56 e8 14 d6 ff ff 01 f0 83 c4 10 80 38 00 75 12 c7 03 00 00 00 00 83 c4 04 89 f0 5b 5e c3 8d 74 26 00 <c6> 00 00 83 c0 01 89 03 83 c4 04 89 f0 5b 5e c3 66 90 66 90 66 90
Signature · 1 line
2.13.0
author maintainer
#1 lore raw

PATCH 1/9 x86/dumstack: Remove code_bytes

From: Borislav Petkov <[email protected]>

This was added by

86c418374223 ("[PATCH] i386: add option to show more code in oops reports")

long time ago but experience shows that 64 instruction bytes are plenty when deciphering an oops. So get rid of it.

Removing it will simplify further enhancements to the opcodes dumping machinery coming in the following patches.

---
 Documentation/admin-guide/kernel-parameters.txt |  5 -----
 arch/x86/kernel/dumpstack.c                     | 27 ++++---------------------
 2 files changed, 4 insertions(+), 28 deletions(-)
Documentation/admin-guide/kernel-parameters.txt +0 -5
index b37c1c30c16f..2c74c1694d9d 100644
@@ -587,11 +587,6 @@
 			Sets the size of memory pool for coherent, atomic dma
 			allocations, by default set to 256K.
 
-	code_bytes	[X86] How many bytes of object code to print
-			in an oops report.
-			Range: 0 - 8192
-			Default: 64
-
 	com20020=	[HW,NET] ARCnet - COM20020 chipset
 			Format:
 			<io>[,<irq>[,<nodeID>[,<backplane>[,<ckp>[,<timeout>]]]]]
arch/x86/kernel/dumpstack.c +4 -23
index 18fa9d74c182..593db796374d 100644
@@ -22,9 +22,10 @@
 #include <asm/stacktrace.h>
 #include <asm/unwind.h>
 
+#define OPCODE_BUFSIZE 64
+
 int panic_on_unrecovered_nmi;
 int panic_on_io_nmi;
-static unsigned int code_bytes = 64;
 static int die_counter;
 
 bool in_task_stack(unsigned long *stack, struct task_struct *task,
@@ -356,26 +357,6 @@ void die(const char *str, struct pt_regs *regs, long err)
 	oops_end(flags, regs, sig);
 }
 
-static int __init code_bytes_setup(char *s)
-{
-	ssize_t ret;
-	unsigned long val;
-
-	if (!s)
-		return -EINVAL;
-
-	ret = kstrtoul(s, 0, &val);
-	if (ret)
-		return ret;
-
-	code_bytes = val;
-	if (code_bytes > 8192)
-		code_bytes = 8192;
-
-	return 1;
-}
-__setup("code_bytes=", code_bytes_setup);
-
 void show_regs(struct pt_regs *regs)
 {
 	bool all = true;
@@ -393,8 +374,8 @@ void show_regs(struct pt_regs *regs)
 	 * time of the fault..
 	 */
 	if (!user_mode(regs)) {
-		unsigned int code_prologue = code_bytes * 43 / 64;
-		unsigned int code_len = code_bytes;
+		unsigned int code_prologue = OPCODE_BUFSIZE * 43 / 64;
+		unsigned int code_len = OPCODE_BUFSIZE;
 		unsigned char c;
 		u8 *ip;
 
Signature · 1 line
2.13.0
#2 lore raw

Re: [PATCH 1/9] x86/dumstack: Remove code_bytes

Quoted 6 lines · Borislav Petkov

From: Borislav Petkov <[email protected]>

This was added by

86c418374223 ("[PATCH] i386: add option to show more code in oops reports")

Quoted 7 lines

long time ago but experience shows that 64 instruction bytes are plenty when deciphering an oops. So get rid of it.

Removing it will simplify further enhancements to the opcodes dumping machinery coming in the following patches.

s/dumstack/dumpstack/ in the subject.

Signature · 1 line
Josh
author maintainer
#3 lore raw

PATCH 2/9 x86/dumpstack: Unexport oops_begin()

In reply to Borislav Petkov

From: Borislav Petkov <[email protected]>

The only user outside of arch/ is not a module since

86cd47334b00 ("ACPI, APEI, GHES, Prevent GHES to be built as module")

No functional changes.

---
 arch/x86/kernel/dumpstack.c | 1 -
 1 file changed, 1 deletion(-)
arch/x86/kernel/dumpstack.c +0 -1
index 593db796374d..579455c2b91e 100644
@@ -268,7 +268,6 @@ unsigned long oops_begin(void)
 	bust_spinlocks(1);
 	return flags;
 }
-EXPORT_SYMBOL_GPL(oops_begin);
 NOKPROBE_SYMBOL(oops_begin);
 
 void __noreturn rewind_stack_do_exit(int signr);
Signature · 1 line
2.13.0
author maintainer
#4 lore raw

PATCH 3/9 x86/dumpstack: Carve out Code: dumping into a function

In reply to Borislav Petkov

From: Borislav Petkov <[email protected]>

No functionality change, carve it out into a separate function for later changes.

---
 arch/x86/kernel/dumpstack.c | 57 ++++++++++++++++++++++++---------------------
 1 file changed, 30 insertions(+), 27 deletions(-)
arch/x86/kernel/dumpstack.c +30 -27
index 579455c2b91e..eb9d6c00a52f 100644
@@ -70,6 +70,35 @@ static void printk_stack_address(unsigned long address, int reliable,
 	printk("%s %s%pB\n", log_lvl, reliable ? "" : "? ", (void *)address);
 }
 
+static void show_opcodes(u8 *rip)
+{
+	unsigned int code_prologue = OPCODE_BUFSIZE * 43 / 64;
+	unsigned int code_len = OPCODE_BUFSIZE;
+	unsigned char c;
+	u8 *ip;
+	int i;
+
+	printk(KERN_DEFAULT "Code: ");
+
+	ip = (u8 *)rip - code_prologue;
+	if (ip < (u8 *)PAGE_OFFSET || probe_kernel_address(ip, c)) {
+		/* try starting at IP */
+		ip = (u8 *)rip;
+		code_len = code_len - code_prologue + 1;
+	}
+	for (i = 0; i < code_len; i++, ip++) {
+		if (ip < (u8 *)PAGE_OFFSET || probe_kernel_address(ip, c)) {
+			pr_cont(" Bad RIP value.");
+			break;
+		}
+		if (ip == (u8 *)rip)
+			pr_cont("<%02x> ", c);
+		else
+			pr_cont("%02x ", c);
+	}
+	pr_cont("\n");
+}
+
 void show_iret_regs(struct pt_regs *regs)
 {
 	printk(KERN_DEFAULT "RIP: %04x:%pS\n", (int)regs->cs, (void *)regs->ip);
@@ -359,7 +388,6 @@ void die(const char *str, struct pt_regs *regs, long err)
 void show_regs(struct pt_regs *regs)
 {
 	bool all = true;
-	int i;
 
 	show_regs_print_info(KERN_DEFAULT);
 
@@ -373,32 +401,7 @@ void show_regs(struct pt_regs *regs)
 	 * time of the fault..
 	 */
 	if (!user_mode(regs)) {
-		unsigned int code_prologue = OPCODE_BUFSIZE * 43 / 64;
-		unsigned int code_len = OPCODE_BUFSIZE;
-		unsigned char c;
-		u8 *ip;
-
 		show_trace_log_lvl(current, regs, NULL, KERN_DEFAULT);
-
-		printk(KERN_DEFAULT "Code: ");
-
-		ip = (u8 *)regs->ip - code_prologue;
-		if (ip < (u8 *)PAGE_OFFSET || probe_kernel_address(ip, c)) {
-			/* try starting at IP */
-			ip = (u8 *)regs->ip;
-			code_len = code_len - code_prologue + 1;
-		}
-		for (i = 0; i < code_len; i++, ip++) {
-			if (ip < (u8 *)PAGE_OFFSET ||
-					probe_kernel_address(ip, c)) {
-				pr_cont(" Bad RIP value.");
-				break;
-			}
-			if (ip == (u8 *)regs->ip)
-				pr_cont("<%02x> ", c);
-			else
-				pr_cont("%02x ", c);
-		}
+		show_opcodes((u8 *)regs->ip);
 	}
-	pr_cont("\n");
 }
Signature · 1 line
2.13.0
author maintainer
#5 lore raw

PATCH 4/9 x86/dumpstack: Improve opcodes dumping in the Code: section

In reply to Borislav Petkov

From: Borislav Petkov <[email protected]>

The code used to iterate byte-by-byte over the bytes around RIP and that is expensive: disabling pagefaults around it, copy_from_user, etc...

Make it read the whole buffer of OPCODE_BUFSIZE size in one go. Use a statically allocated 64 bytes buffer so that concurrent show_opcodes() do not interleave in the output even though in the majority of the cases we sync on die_lock. Except the #PF path which doesn't...

Also, do the PAGE_OFFSET check outside of the function because latter will be reused in other context.

---
 arch/x86/kernel/dumpstack.c | 34 ++++++++++++++++------------------
 1 file changed, 16 insertions(+), 18 deletions(-)
arch/x86/kernel/dumpstack.c +16 -18
index eb9d6c00a52f..3f781a8dddb8 100644
@@ -22,8 +22,6 @@
 #include <asm/stacktrace.h>
 #include <asm/unwind.h>
 
-#define OPCODE_BUFSIZE 64
-
 int panic_on_unrecovered_nmi;
 int panic_on_io_nmi;
 static int die_counter;
@@ -72,29 +70,25 @@ static void printk_stack_address(unsigned long address, int reliable,
 
 static void show_opcodes(u8 *rip)
 {
-	unsigned int code_prologue = OPCODE_BUFSIZE * 43 / 64;
-	unsigned int code_len = OPCODE_BUFSIZE;
-	unsigned char c;
+#define OPCODE_BUFSIZE 64
+	unsigned int code_prologue = OPCODE_BUFSIZE * 2 / 3;
+	u8 opcodes[OPCODE_BUFSIZE];
 	u8 *ip;
 	int i;
 
 	printk(KERN_DEFAULT "Code: ");
 
 	ip = (u8 *)rip - code_prologue;
-	if (ip < (u8 *)PAGE_OFFSET || probe_kernel_address(ip, c)) {
-		/* try starting at IP */
-		ip = (u8 *)rip;
-		code_len = code_len - code_prologue + 1;
+	if (probe_kernel_read(opcodes, ip, OPCODE_BUFSIZE)) {
+		pr_cont(" Bad RIP value.\n");
+		return;
 	}
-	for (i = 0; i < code_len; i++, ip++) {
-		if (ip < (u8 *)PAGE_OFFSET || probe_kernel_address(ip, c)) {
-			pr_cont(" Bad RIP value.");
-			break;
-		}
-		if (ip == (u8 *)rip)
-			pr_cont("<%02x> ", c);
+
+	for (i = 0; i < OPCODE_BUFSIZE; i++, ip++) {
+		if (ip == rip)
+			pr_cont("<%02x> ", opcodes[i]);
 		else
-			pr_cont("%02x ", c);
+			pr_cont("%02x ", opcodes[i]);
 	}
 	pr_cont("\n");
 }
@@ -402,6 +396,10 @@ void show_regs(struct pt_regs *regs)
 	 */
 	if (!user_mode(regs)) {
 		show_trace_log_lvl(current, regs, NULL, KERN_DEFAULT);
-		show_opcodes((u8 *)regs->ip);
+
+		if (regs->ip < PAGE_OFFSET)
+			pr_cont(" Bad RIP value.\n");
+		else
+			show_opcodes((u8 *)regs->ip);
 	}
 }
Signature · 1 line
2.13.0
#6 lore raw

Re: [PATCH 4/9] x86/dumpstack: Improve opcodes dumping in the Code: section

Quoted 32 lines · Borislav Petkov

From: Borislav Petkov <[email protected]>

The code used to iterate byte-by-byte over the bytes around RIP and that is expensive: disabling pagefaults around it, copy_from_user, etc...

Make it read the whole buffer of OPCODE_BUFSIZE size in one go. Use a statically allocated 64 bytes buffer so that concurrent show_opcodes() do not interleave in the output even though in the majority of the cases we sync on die_lock. Except the #PF path which doesn't...

Also, do the PAGE_OFFSET check outside of the function because latter will be reused in other context.

---
 arch/x86/kernel/dumpstack.c | 34 ++++++++++++++++------------------
 1 file changed, 16 insertions(+), 18 deletions(-)
arch/x86/kernel/dumpstack.c +0 -2
index eb9d6c00a52f..3f781a8dddb8 100644
@@ -22,8 +22,6 @@
 #include <asm/stacktrace.h>
 #include <asm/unwind.h>
 
-#define OPCODE_BUFSIZE 64
-
 int panic_on_unrecovered_nmi;
 int panic_on_io_nmi;
 static int die_counter;

arch/x86/kernel/dumpstack.c static void printk_stack_address(unsigned long address, int reliable, · line 75

Quoted 9 lines
arch/x86/kernel/dumpstack.c +3 -3
@@ -72,29 +70,25 @@ static void printk_stack_address(unsigned long address, int reliable,
 
 static void show_opcodes(u8 *rip)
 {
-	unsigned int code_prologue = OPCODE_BUFSIZE * 43 / 64;
-	unsigned int code_len = OPCODE_BUFSIZE;
-	unsigned char c;
+#define OPCODE_BUFSIZE 64
+	unsigned int code_prologue = OPCODE_BUFSIZE * 2 / 3;
+	u8 opcodes[OPCODE_BUFSIZE];

I liked OPCODE_BUFSIZE where it was before :-) Here it disrupts the readability of the function a bit IMO.

Signature · 1 line
Josh
author maintainer
#7 lore raw

Re: [PATCH 4/9] x86/dumpstack: Improve opcodes dumping in the Code: section

Quoted 2 lines · Josh Poimboeuf

I liked OPCODE_BUFSIZE where it was before :-) Here it disrupts the readability of the function a bit IMO.

My thinking is have it close by so that you don't have to go search for its definition.

But I don't have a strong opinion on where it should be so...

Signature · 4 lines
Regards/Gruss,
    Boris.

Good mailing practices for 400: avoid top-posting and trim the reply.
#8 lore raw

Re: [PATCH 4/9] x86/dumpstack: Improve opcodes dumping in the Code: section

Quoted 6 lines · Borislav Petkov
Quoted 2 lines · Josh Poimboeuf

I liked OPCODE_BUFSIZE where it was before :-) Here it disrupts the readability of the function a bit IMO.

My thinking is have it close by so that you don't have to go search for its definition.

But knowing the value of OPCODE_BUFSIZE isn't needed for understanding the rest of the function, so it seems like clutter to me. Besides, that's what the vim cscope plugin is for :-)

But I also don't have a strong opinion.

Signature · 1 line
Josh
#9 lore raw

RE: [PATCH 4/9] x86/dumpstack: Improve opcodes dumping in the Code: section

In reply to Borislav Petkov

From: Borislav Petkov

Quoted 9 lines

Sent: 15 March 2018 18:16

Quoted 2 lines · Josh Poimboeuf

I liked OPCODE_BUFSIZE where it was before :-) Here it disrupts the readability of the function a bit IMO.

My thinking is have it close by so that you don't have to go search for its definition.

But I don't have a strong opinion on where it should be so...

Is OPCODE_BUFSIZE even needed?
Maybe replace with 64 and use sizeof() and/or ARRAY_SIZE() elsewhere. Then no one has to check that the bound is appropriate for the array.

David

#10 lore raw

Re: [PATCH 4/9] x86/dumpstack: Improve opcodes dumping in the Code: section

In reply to Borislav Petkov
Quoted 44 lines · Borislav Petkov

From: Borislav Petkov <[email protected]>

The code used to iterate byte-by-byte over the bytes around RIP and that is expensive: disabling pagefaults around it, copy_from_user, etc...

Make it read the whole buffer of OPCODE_BUFSIZE size in one go. Use a statically allocated 64 bytes buffer so that concurrent show_opcodes() do not interleave in the output even though in the majority of the cases we sync on die_lock. Except the #PF path which doesn't...

Also, do the PAGE_OFFSET check outside of the function because latter will be reused in other context.

---
 arch/x86/kernel/dumpstack.c | 34 ++++++++++++++++------------------
 1 file changed, 16 insertions(+), 18 deletions(-)
arch/x86/kernel/dumpstack.c +3 -5
index eb9d6c00a52f..3f781a8dddb8 100644
@@ -22,8 +22,6 @@
 #include <asm/stacktrace.h>
 #include <asm/unwind.h>
 
-#define OPCODE_BUFSIZE 64
-
 int panic_on_unrecovered_nmi;
 int panic_on_io_nmi;
 static int die_counter;
@@ -72,29 +70,25 @@ static void printk_stack_address(unsigned long address, int reliable,
 
 static void show_opcodes(u8 *rip)
 {
-	unsigned int code_prologue = OPCODE_BUFSIZE * 43 / 64;
-	unsigned int code_len = OPCODE_BUFSIZE;
-	unsigned char c;
+#define OPCODE_BUFSIZE 64
+	unsigned int code_prologue = OPCODE_BUFSIZE * 2 / 3;
+	u8 opcodes[OPCODE_BUFSIZE];
 	u8 *ip;
 	int i;
 

arch/x86/kernel/dumpstack.c static void printk_stack_address(unsigned long address, int reliable, · line 84

Quoted 10 lines
arch/x86/kernel/dumpstack.c +3 -4
 	printk(KERN_DEFAULT "Code: ");
 
 	ip = (u8 *)rip - code_prologue;
-	if (ip < (u8 *)PAGE_OFFSET || probe_kernel_address(ip, c)) {
-		/* try starting at IP */
-		ip = (u8 *)rip;
-		code_len = code_len - code_prologue + 1;
+	if (probe_kernel_read(opcodes, ip, OPCODE_BUFSIZE)) {
+		pr_cont(" Bad RIP value.\n");
+		return;

As long as you're changing the code, might as well remove the leading space here, so it shows

	Code: Bad RIP value.

instead of

	Code:  Bad RIP value.
Signature · 1 line
Josh
#11 lore raw

Re: [PATCH 4/9] x86/dumpstack: Improve opcodes dumping in the Code: section

In reply to Borislav Petkov

arch/x86/kernel/dumpstack.c void show_regs(struct pt_regs *regs) · line 403

Quoted 10 lines · Borislav Petkov
arch/x86/kernel/dumpstack.c +5 -1
@@ -402,6 +396,10 @@ void show_regs(struct pt_regs *regs)
 	 */
 	if (!user_mode(regs)) {
 		show_trace_log_lvl(current, regs, NULL, KERN_DEFAULT);
-		show_opcodes((u8 *)regs->ip);
+
+		if (regs->ip < PAGE_OFFSET)
+			pr_cont(" Bad RIP value.\n");
+		else
+			show_opcodes((u8 *)regs->ip);

[ Oops, sorry about three reviews for the same patch... ]

I don't see the printk preceding the pr_cont() here. Shouldn't it be something like:

printk(KERN_DEFAULT "Code: Bad RIP value.\n")

?

Signature · 1 line
Josh
author maintainer
#12 lore raw

PATCH 5/9 x86/dumpstack: Add loglevel argument to show_opcodes()

In reply to Borislav Petkov

From: Borislav Petkov <[email protected]>

Will be used in the next patch.

---
 arch/x86/include/asm/stacktrace.h | 1 +
 arch/x86/kernel/dumpstack.c       | 6 +++---
 2 files changed, 4 insertions(+), 3 deletions(-)
arch/x86/include/asm/stacktrace.h +1 -0
index 133d9425fced..0630eeb18bbc 100644
@@ -111,4 +111,5 @@ static inline unsigned long caller_frame_pointer(void)
 	return (unsigned long)frame;
 }
 
+void show_opcodes(u8 *rip, const char *loglvl);
 #endif /* _ASM_X86_STACKTRACE_H */
arch/x86/kernel/dumpstack.c +3 -3
index 3f781a8dddb8..82562f327a99 100644
@@ -68,7 +68,7 @@ static void printk_stack_address(unsigned long address, int reliable,
 	printk("%s %s%pB\n", log_lvl, reliable ? "" : "? ", (void *)address);
 }
 
-static void show_opcodes(u8 *rip)
+void show_opcodes(u8 *rip, const char *loglvl)
 {
 #define OPCODE_BUFSIZE 64
 	unsigned int code_prologue = OPCODE_BUFSIZE * 2 / 3;
@@ -76,7 +76,7 @@ static void show_opcodes(u8 *rip)
 	u8 *ip;
 	int i;
 
-	printk(KERN_DEFAULT "Code: ");
+	printk("%sCode: ", loglvl);
 
 	ip = (u8 *)rip - code_prologue;
 	if (probe_kernel_read(opcodes, ip, OPCODE_BUFSIZE)) {
@@ -400,6 +400,6 @@ void show_regs(struct pt_regs *regs)
 		if (regs->ip < PAGE_OFFSET)
 			pr_cont(" Bad RIP value.\n");
 		else
-			show_opcodes((u8 *)regs->ip);
+			show_opcodes((u8 *)regs->ip, KERN_DEFAULT);
 	}
 }
Signature · 1 line
2.13.0
author maintainer
#13 lore raw

PATCH 6/9 x86/fault: Dump user opcode bytes on fatal faults

In reply to Borislav Petkov

From: Borislav Petkov <[email protected]>

Sometimes it is useful to see which user opcode bytes RIP points to when a fault happens: be it to rule out RIP corruption, to dump info early during boot, when doing core dumps is impossible due to not having writable fs yet.

Sometimes it is useful if debugging an issue and one doesn't have access to the executable which caused the fault in order to disassemble it.

That last aspect might have some security implications so show_unhandled_signals could be revisited for that or a new config option added.

---
 arch/x86/mm/fault.c | 7 +++++--
 1 file changed, 5 insertions(+), 2 deletions(-)
arch/x86/mm/fault.c +5 -2
index 26865147a507..b3c19f734442 100644
@@ -850,6 +850,8 @@ static inline void
 show_signal_msg(struct pt_regs *regs, unsigned long error_code,
 		unsigned long address, struct task_struct *tsk)
 {
+	const char *loglvl = task_pid_nr(tsk) > 1 ? KERN_INFO : KERN_EMERG;
+
 	if (!unhandled_signal(tsk, SIGSEGV))
 		return;
 
@@ -857,13 +859,14 @@ show_signal_msg(struct pt_regs *regs, unsigned long error_code,
 		return;
 
 	printk("%s%s[%d]: segfault at %lx ip %px sp %px error %lx",
-		task_pid_nr(tsk) > 1 ? KERN_INFO : KERN_EMERG,
-		tsk->comm, task_pid_nr(tsk), address,
+		loglvl, tsk->comm, task_pid_nr(tsk), address,
 		(void *)regs->ip, (void *)regs->sp, error_code);
 
 	print_vma_addr(KERN_CONT " in ", regs->ip);
 
 	printk(KERN_CONT "\n");
+
+	show_opcodes((u8 *)regs->ip, loglvl);
 }
 
 static void
Signature · 1 line
2.13.0
author maintainer
#14 lore raw

PATCH 7/9 x86/dumpstack: Add a show_ip() function

In reply to Borislav Petkov

From: Borislav Petkov <[email protected]>

Which shows the Istruction Pointer along with the insn bytes around it. Use it whenever we print rIP.

---
 arch/x86/include/asm/stacktrace.h |  1 +
 arch/x86/kernel/dumpstack.c       | 13 ++++++++++++-
 arch/x86/kernel/process_32.c      |  4 +---
 3 files changed, 14 insertions(+), 4 deletions(-)
arch/x86/include/asm/stacktrace.h +1 -0
index 0630eeb18bbc..b6dc698f992a 100644
@@ -112,4 +112,5 @@ static inline unsigned long caller_frame_pointer(void)
 }
 
 void show_opcodes(u8 *rip, const char *loglvl);
+void show_ip(struct pt_regs *regs, const char *loglvl);
 #endif /* _ASM_X86_STACKTRACE_H */
arch/x86/kernel/dumpstack.c +12 -1
index 82562f327a99..8cf2e2289d50 100644
@@ -93,9 +93,20 @@ void show_opcodes(u8 *rip, const char *loglvl)
 	pr_cont("\n");
 }
 
+void show_ip(struct pt_regs *regs, const char *loglvl)
+{
+#ifdef CONFIG_X86_32
+	printk("%sEIP: %pS\n", loglvl, (void *)regs->ip);
+#else
+	printk("%sRIP: %04x:%pS\n", loglvl, (int)regs->cs, (void *)regs->ip);
+#endif
+
+	show_opcodes((u8 *)regs->ip, loglvl);
+}
+
 void show_iret_regs(struct pt_regs *regs)
 {
-	printk(KERN_DEFAULT "RIP: %04x:%pS\n", (int)regs->cs, (void *)regs->ip);
+	show_ip(regs, KERN_DEFAULT);
 	printk(KERN_DEFAULT "RSP: %04x:%016lx EFLAGS: %08lx", (int)regs->ss,
 		regs->sp, regs->flags);
 }
arch/x86/kernel/process_32.c +1 -3
index 5224c6099184..3d1f1226b972 100644
@@ -76,9 +76,7 @@ void __show_regs(struct pt_regs *regs, int all)
 		savesegment(gs, gs);
 	}
 
-	printk(KERN_DEFAULT "EIP: %pS\n", (void *)regs->ip);
-	printk(KERN_DEFAULT "EFLAGS: %08lx CPU: %d\n", regs->flags,
-		raw_smp_processor_id());
+	show_ip(regs, KERN_DEFAULT);
 
 	printk(KERN_DEFAULT "EAX: %08lx EBX: %08lx ECX: %08lx EDX: %08lx\n",
 		regs->ax, regs->bx, regs->cx, regs->dx);
Signature · 1 line
2.13.0
#15 lore raw

Re: [PATCH 7/9] x86/dumpstack: Add a show_ip() function

Quoted 4 lines · Borislav Petkov

From: Borislav Petkov <[email protected]>

Which shows the Istruction Pointer along with the insn bytes around it. Use it whenever we print rIP.

s/Istruction/Instruction/

arch/x86/kernel/process_32.c void __show_regs(struct pt_regs *regs, int all) · line 79

Quoted 12 lines
arch/x86/kernel/process_32.c +1 -3
index 5224c6099184..3d1f1226b972 100644
@@ -76,9 +76,7 @@ void __show_regs(struct pt_regs *regs, int all)
 		savesegment(gs, gs);
 	}
 
-	printk(KERN_DEFAULT "EIP: %pS\n", (void *)regs->ip);
-	printk(KERN_DEFAULT "EFLAGS: %08lx CPU: %d\n", regs->flags,
-		raw_smp_processor_id());
+	show_ip(regs, KERN_DEFAULT);

Did you intentionally remove the printing of EFLAGS?

Signature · 1 line
Josh
author maintainer
#16 lore raw

Re: [PATCH 7/9] x86/dumpstack: Add a show_ip() function

Quoted 1 line · Josh Poimboeuf

Did you intentionally remove the printing of EFLAGS?

Blergh, EFLAGS were supposed to go down in the printk block. Good catch!

---

arch/x86/kernel/process_32.c +2 -2
index 3d1f1226b972..0ae659de21eb 100644
@@ -82,8 +82,8 @@ void __show_regs(struct pt_regs *regs, int all)
 		regs->ax, regs->bx, regs->cx, regs->dx);
 	printk(KERN_DEFAULT "ESI: %08lx EDI: %08lx EBP: %08lx ESP: %08lx\n",
 		regs->si, regs->di, regs->bp, sp);
-	printk(KERN_DEFAULT " DS: %04x ES: %04x FS: %04x GS: %04x SS: %04x\n",
-	       (u16)regs->ds, (u16)regs->es, (u16)regs->fs, gs, ss);
+	printk(KERN_DEFAULT "DS: %04x ES: %04x FS: %04x GS: %04x SS: %04x EFLAGS: %08lx\n",
+	       (u16)regs->ds, (u16)regs->es, (u16)regs->fs, gs, ss, regs->flags);
 
 	if (!all)
 		return;
Signature · 4 lines
Regards/Gruss,
    Boris.

Good mailing practices for 400: avoid top-posting and trim the reply.
author maintainer
#17 lore raw

PATCH 8/9 x86/dumpstack: Save first regs set for the executive summary

In reply to Borislav Petkov

From: Borislav Petkov <[email protected]>

Save the regs set when we call __die() for the first time and print it in oops_end().

---
 arch/x86/kernel/dumpstack.c | 33 ++++++++++++---------------------
 1 file changed, 12 insertions(+), 21 deletions(-)
arch/x86/kernel/dumpstack.c +12 -21
index 8cf2e2289d50..bb712ca99632 100644
@@ -26,6 +26,8 @@ int panic_on_unrecovered_nmi;
 int panic_on_io_nmi;
 static int die_counter;
 
+static struct pt_regs exec_summary_regs;
+
 bool in_task_stack(unsigned long *stack, struct task_struct *task,
 		   struct stack_info *info)
 {
@@ -321,6 +323,9 @@ void oops_end(unsigned long flags, struct pt_regs *regs, int signr)
 	raw_local_irq_restore(flags);
 	oops_exit();
 
+	/* Executive summary in case the oops scrolled away */
+	__show_regs(&exec_summary_regs, false);
+
 	if (!signr)
 		return;
 	if (in_interrupt())
@@ -339,10 +344,10 @@ NOKPROBE_SYMBOL(oops_end);
 
 int __die(const char *str, struct pt_regs *regs, long err)
 {
-#ifdef CONFIG_X86_32
-	unsigned short ss;
-	unsigned long sp;
-#endif
+	/* Save the regs of the first oops for the executive summary later. */
+	if (!die_counter)
+		exec_summary_regs = *regs;
+
 	printk(KERN_DEFAULT
 	       "%s: %04lx [#%d]%s%s%s%s%s\n", str, err & 0xffff, ++die_counter,
 	       IS_ENABLED(CONFIG_PREEMPT) ? " PREEMPT"         : "",
@@ -352,26 +357,14 @@ int __die(const char *str, struct pt_regs *regs, long err)
 	       IS_ENABLED(CONFIG_PAGE_TABLE_ISOLATION) ?
 	       (boot_cpu_has(X86_FEATURE_PTI) ? " PTI" : " NOPTI") : "");
 
+	show_regs(regs);
+
 	if (notify_die(DIE_OOPS, str, regs, err,
 			current->thread.trap_nr, SIGSEGV) == NOTIFY_STOP)
 		return 1;
 
 	print_modules();
-	show_regs(regs);
-#ifdef CONFIG_X86_32
-	if (user_mode(regs)) {
-		sp = regs->sp;
-		ss = regs->ss;
-	} else {
-		sp = kernel_stack_pointer(regs);
-		savesegment(ss, ss);
-	}
-	printk(KERN_EMERG "EIP: %pS SS:ESP: %04x:%08lx\n",
-	       (void *)regs->ip, ss, sp);
-#else
-	/* Executive summary in case the oops scrolled away */
-	printk(KERN_ALERT "RIP: %pS RSP: %016lx\n", (void *)regs->ip, regs->sp);
-#endif
+
 	return 0;
 }
 NOKPROBE_SYMBOL(__die);
@@ -410,7 +403,5 @@ void show_regs(struct pt_regs *regs)
 
 		if (regs->ip < PAGE_OFFSET)
 			pr_cont(" Bad RIP value.\n");
-		else
-			show_opcodes((u8 *)regs->ip, KERN_DEFAULT);
 	}
 }
Signature · 1 line
2.13.0
#18 lore raw

Re: [PATCH 8/9] x86/dumpstack: Save first regs set for the executive summary

arch/x86/kernel/dumpstack.c void oops_end(unsigned long flags, struct pt_regs *regs, int signr) · line 328

Quoted 7 lines · Borislav Petkov
arch/x86/kernel/dumpstack.c +3 -0
@@ -321,6 +323,9 @@ void oops_end(unsigned long flags, struct pt_regs *regs, int signr)
 	raw_local_irq_restore(flags);
 	oops_exit();
 
+	/* Executive summary in case the oops scrolled away */
+	__show_regs(&exec_summary_regs, false);
+

no_context() has the following line, right before it calls oops_end():

	/* Executive summary in case the body of the oops scrolled away */
	printk(KERN_DEFAULT "CR2: %016lx\n", address);

I think that line can now be removed, since the executive summary __show_regs() will include CR2.

arch/x86/kernel/dumpstack.c int __die(const char *str, struct pt_regs *regs, long err) · line 360

Quoted 12 lines
arch/x86/kernel/dumpstack.c +2 -1
@@ -352,26 +357,14 @@ int __die(const char *str, struct pt_regs *regs, long err)
 	       IS_ENABLED(CONFIG_PAGE_TABLE_ISOLATION) ?
 	       (boot_cpu_has(X86_FEATURE_PTI) ? " PTI" : " NOPTI") : "");
 
+	show_regs(regs);
+
 	if (notify_die(DIE_OOPS, str, regs, err,
 			current->thread.trap_nr, SIGSEGV) == NOTIFY_STOP)
 		return 1;
 
 	print_modules();
-	show_regs(regs);

Was moving the show_regs() call intentional? I didn't see it mentioned in the changelog.

arch/x86/kernel/dumpstack.c void show_regs(struct pt_regs *regs) · line 407

Quoted 8 lines
arch/x86/kernel/dumpstack.c +0 -2
@@ -410,7 +403,5 @@ void show_regs(struct pt_regs *regs)
 
 		if (regs->ip < PAGE_OFFSET)
 			pr_cont(" Bad RIP value.\n");
-		else
-			show_opcodes((u8 *)regs->ip, KERN_DEFAULT);
 	}
 }

Doesn't this hunk belong in the previous patch, which added the __show_regs -> show_ip() -> show_opcodes() call path?

Signature · 1 line
Josh
author maintainer
#19 lore raw

Re: [PATCH 8/9] x86/dumpstack: Save first regs set for the executive summary

Quoted 7 lines · Josh Poimboeuf

no_context() has the following line, right before it calls oops_end():

	/* Executive summary in case the body of the oops scrolled away */
	printk(KERN_DEFAULT "CR2: %016lx\n", address);

I think that line can now be removed, since the executive summary __show_regs() will include CR2.

Good idea. Done. It adds three more lines to the executive summary but I think they're worth it.

[ 4020.804801] Modules linked in:
[ 4020.840092] ---[ end trace 13285dfd393b58bd ]---
[ 4020.840828] RIP: 0010:sysrq_handle_crash+0x17/0x20
[ 4020.841731] Code: d1 e8 6d 08 b7 ff 0f 1f 00 66 2e 0f 1f 84 00 00 00 00 00 0f 1f 44 00 00 e8 76 1f bd ff c7 05 a4 12 19 01 01 00 00 00 0f ae f8 <c6> 04 25 00 00 00 00 01 c3 0f 1f 44 00 00 e8 c6 1b c2 ff fb e9 80 
[ 4020.845056] RSP: 0018:ffffc9000085bdf0 EFLAGS: 00010246
[ 4020.845760] RAX: 0000000000000000 RBX: 0000000000000063 RCX: 0000000000000000
[ 4020.846704] RDX: 0000000000000000 RSI: ffffffff81101e0a RDI: 0000000000000063
[ 4020.847630] RBP: ffffffff822714c0 R08: 0000000000000185 R09: 00000000000c303e
[ 4020.848658] R10: 0000000000000000 R11: 0000000000000000 R12: 000000000000000a
[ 4020.849678] R13: 0000000000000000 R14: 0000000000000000 R15: 0000000000000000
[ 4020.850644] FS:  00007ffff7fdb700(0000) GS:ffff88007ec40000(0000) knlGS:0000000000000000
[ 4020.851688] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 4020.852994] CR2: 0000000000000000 CR3: 000000007a0f9000 CR4: 00000000000406e0
[ 4020.854018] Kernel panic - not syncing: Fatal exception
[ 4020.855256] Kernel Offset: disabled
[ 4020.855730] ---[ end Kernel panic - not syncing: Fatal exception ]---
Quoted 10 lines
Quoted 10 lines
arch/x86/kernel/dumpstack.c +2 -0
@@ -352,26 +357,14 @@ int __die(const char *str, struct pt_regs *regs, long err)
 	       IS_ENABLED(CONFIG_PAGE_TABLE_ISOLATION) ?
 	       (boot_cpu_has(X86_FEATURE_PTI) ? " PTI" : " NOPTI") : "");
 
+	show_regs(regs);
+
 	if (notify_die(DIE_OOPS, str, regs, err,
 			current->thread.trap_nr, SIGSEGV) == NOTIFY_STOP)
 		return 1;
 
Quoted 4 lines

arch/x86/kernel/dumpstack.c int __die(const char *str, struct pt_regs *regs, long err) · line 360

Quoted 2 lines
arch/x86/kernel/dumpstack.c +0 -1
 	print_modules();
-	show_regs(regs);

Was moving the show_regs() call intentional?

Yes. It'd be prudent for registers to come out unconditionally and not some of the notifiers to make us exit early. Which kinda needs print_modules() to go up too. Fixed.

Quoted 1 line

I didn't see it mentioned in the changelog.

Fixed.

Quoted 2 lines

Doesn't this hunk belong in the previous patch, which added the __show_regs -> show_ip() -> show_opcodes() call path?

Yeah, and the PAGE_OFFSET check needs to happen in show_ip() too.

Thanks for the detailed review, here's the current splat format:

[   29.046500] sysrq: SysRq : Trigger a crash
[   29.048605] BUG: unable to handle kernel NULL pointer dereference at 0000000000000000
[   29.051639] PGD 79afd067 P4D 79afd067 PUD 7a1a2067 PMD 0 
[   29.052557] Oops: 0002 [#1] PREEMPT SMP
[   29.052557] CPU: 7 PID: 3693 Comm: bash Not tainted 4.16.0-rc5+ #8
[   29.052557] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.10.2-1 04/01/2014
[   29.052557] RIP: 0010:sysrq_handle_crash+0x17/0x20
[   29.052557] Code: d1 e8 6d 08 b7 ff 0f 1f 00 66 2e 0f 1f 84 00 00 00 00 00 0f 1f 44 00 00 e8 76 1f bd ff c7 05 a4 12 19 01 01 00 00 00 0f ae f8 <c6> 04 25 00 00 00 00 01 c3 0f 1f 44 00 00 e8 c6 1b c2 ff fb e9 80 
[   29.052557] RSP: 0018:ffffc900007cbdf0 EFLAGS: 00010246
[   29.052557] RAX: 0000000000000000 RBX: 0000000000000063 RCX: 0000000000000000
[   29.052557] RDX: 0000000000000000 RSI: ffffffff81101e0a RDI: 0000000000000063
[   29.052557] RBP: ffffffff822714c0 R08: 0000000000000185 R09: 000000000000b5a4
[   29.052557] R10: 0000000000000000 R11: 0000000000000000 R12: 000000000000000a
[   29.052557] R13: 0000000000000000 R14: 0000000000000000 R15: 0000000000000000
[   29.052557] FS:  00007ffff7fdb700(0000) GS:ffff88007edc0000(0000) knlGS:0000000000000000
[   29.052557] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[   29.052557] CR2: 0000000000000000 CR3: 00000000799e1000 CR4: 00000000000406e0
[   29.052557] Call Trace:
[   29.052557]  __handle_sysrq+0x9e/0x160
[   29.052557]  write_sysrq_trigger+0x2b/0x30
[   29.052557]  proc_reg_write+0x38/0x70
[   29.052557]  __vfs_write+0x36/0x160
[   29.052557]  ? __fd_install+0x69/0x110
[   29.052557]  ? preempt_count_add+0x74/0xb0
[   29.052557]  ? _raw_spin_lock+0x13/0x30
[   29.052557]  ? set_close_on_exec+0x41/0x80
[   29.052557]  ? preempt_count_sub+0xa8/0x100
[   29.052557]  vfs_write+0xc0/0x190
[   29.052557]  SyS_write+0x64/0xe0
[   29.052557]  ? trace_hardirqs_off_thunk+0x1a/0x1c
[   29.052557]  do_syscall_64+0x70/0x130
[   29.052557]  entry_SYSCALL_64_after_hwframe+0x42/0xb7
[   29.052557] RIP: 0033:0x7ffff74b9620
[   29.052557] Code: Bad RIP value.
[   29.052557] RSP: 002b:00007fffffffe6f8 EFLAGS: 00000246 ORIG_RAX: 0000000000000001
[   29.052557] RAX: ffffffffffffffda RBX: 0000000000000002 RCX: 00007ffff74b9620
[   29.052557] RDX: 0000000000000002 RSI: 0000000000705408 RDI: 0000000000000001
[   29.052557] RBP: 0000000000705408 R08: 000000000000000a R09: 00007ffff7fdb700
[   29.052557] R10: 00007ffff77826a0 R11: 0000000000000246 R12: 00007ffff77842a0
[   29.052557] R13: 0000000000000002 R14: 0000000000000001 R15: 0000000000000000
[   29.052557] Modules linked in:
[   29.085219] ---[ end trace c579921b8f40a393 ]---
[   29.085920] RIP: 0010:sysrq_handle_crash+0x17/0x20
[   29.086704] Code: d1 e8 6d 08 b7 ff 0f 1f 00 66 2e 0f 1f 84 00 00 00 00 00 0f 1f 44 00 00 e8 76 1f bd ff c7 05 a4 12 19 01 01 00 00 00 0f ae f8 <c6> 04 25 00 00 00 00 01 c3 0f 1f 44 00 00 e8 c6 1b c2 ff fb e9 80 
[   29.089439] RSP: 0018:ffffc900007cbdf0 EFLAGS: 00010246
[   29.090117] RAX: 0000000000000000 RBX: 0000000000000063 RCX: 0000000000000000
[   29.091039] RDX: 0000000000000000 RSI: ffffffff81101e0a RDI: 0000000000000063
[   29.091959] RBP: ffffffff822714c0 R08: 0000000000000185 R09: 000000000000b5a4
[   29.092935] R10: 0000000000000000 R11: 0000000000000000 R12: 000000000000000a
[   29.093948] R13: 0000000000000000 R14: 0000000000000000 R15: 0000000000000000
[   29.094885] FS:  00007ffff7fdb700(0000) GS:ffff88007edc0000(0000) knlGS:0000000000000000
[   29.095925] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[   29.096731] CR2: 0000000000000000 CR3: 00000000799e1000 CR4: 00000000000406e0
[   29.097784] Kernel panic - not syncing: Fatal exception
[   29.098882] Kernel Offset: disabled
[   29.099351] ---[ end Kernel panic - not syncing: Fatal exception ]---
Signature · 4 lines
Regards/Gruss,
    Boris.

Good mailing practices for 400: avoid top-posting and trim the reply.
#20 lore raw

Re: [PATCH 8/9] x86/dumpstack: Save first regs set for the executive summary

Quoted 32 lines · Borislav Petkov
[   29.046500] sysrq: SysRq : Trigger a crash
[   29.048605] BUG: unable to handle kernel NULL pointer dereference at 0000000000000000
[   29.051639] PGD 79afd067 P4D 79afd067 PUD 7a1a2067 PMD 0 
[   29.052557] Oops: 0002 [#1] PREEMPT SMP
[   29.052557] CPU: 7 PID: 3693 Comm: bash Not tainted 4.16.0-rc5+ #8
[   29.052557] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.10.2-1 04/01/2014
[   29.052557] RIP: 0010:sysrq_handle_crash+0x17/0x20
[   29.052557] Code: d1 e8 6d 08 b7 ff 0f 1f 00 66 2e 0f 1f 84 00 00 00 00 00 0f 1f 44 00 00 e8 76 1f bd ff c7 05 a4 12 19 01 01 00 00 00 0f ae f8 <c6> 04 25 00 00 00 00 01 c3 0f 1f 44 00 00 e8 c6 1b c2 ff fb e9 80 
[   29.052557] RSP: 0018:ffffc900007cbdf0 EFLAGS: 00010246
[   29.052557] RAX: 0000000000000000 RBX: 0000000000000063 RCX: 0000000000000000
[   29.052557] RDX: 0000000000000000 RSI: ffffffff81101e0a RDI: 0000000000000063
[   29.052557] RBP: ffffffff822714c0 R08: 0000000000000185 R09: 000000000000b5a4
[   29.052557] R10: 0000000000000000 R11: 0000000000000000 R12: 000000000000000a
[   29.052557] R13: 0000000000000000 R14: 0000000000000000 R15: 0000000000000000
[   29.052557] FS:  00007ffff7fdb700(0000) GS:ffff88007edc0000(0000) knlGS:0000000000000000
[   29.052557] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[   29.052557] CR2: 0000000000000000 CR3: 00000000799e1000 CR4: 00000000000406e0
[   29.052557] Call Trace:
[   29.052557]  __handle_sysrq+0x9e/0x160
[   29.052557]  write_sysrq_trigger+0x2b/0x30
[   29.052557]  proc_reg_write+0x38/0x70
[   29.052557]  __vfs_write+0x36/0x160
[   29.052557]  ? __fd_install+0x69/0x110
[   29.052557]  ? preempt_count_add+0x74/0xb0
[   29.052557]  ? _raw_spin_lock+0x13/0x30
[   29.052557]  ? set_close_on_exec+0x41/0x80
[   29.052557]  ? preempt_count_sub+0xa8/0x100
[   29.052557]  vfs_write+0xc0/0x190
[   29.052557]  SyS_write+0x64/0xe0
[   29.052557]  ? trace_hardirqs_off_thunk+0x1a/0x1c
[   29.052557]  do_syscall_64+0x70/0x130
[   29.052557]  entry_SYSCALL_64_after_hwframe+0x42/0xb7
Quoted 8 lines
[   29.052557] RIP: 0033:0x7ffff74b9620
[   29.052557] Code: Bad RIP value.
[   29.052557] RSP: 002b:00007fffffffe6f8 EFLAGS: 00000246 ORIG_RAX: 0000000000000001
[   29.052557] RAX: ffffffffffffffda RBX: 0000000000000002 RCX: 00007ffff74b9620
[   29.052557] RDX: 0000000000000002 RSI: 0000000000705408 RDI: 0000000000000001
[   29.052557] RBP: 0000000000705408 R08: 000000000000000a R09: 00007ffff7fdb700
[   29.052557] R10: 00007ffff77826a0 R11: 0000000000000246 R12: 00007ffff77842a0
[   29.052557] R13: 0000000000000002 R14: 0000000000000001 R15: 0000000000000000

Hm, the "Code: Bad RIP value" will always be shown for syscall regs, which will probably cause some unnecessary confusion/worry. Should we just skip printing it for the "regs->ip < PAGE_OFFSET" case?

Signature · 1 line
Josh
author maintainer
#21 lore raw

Re: [PATCH 8/9] x86/dumpstack: Save first regs set for the executive summary

Quoted 3 lines · Josh Poimboeuf

Hm, the "Code: Bad RIP value" will always be shown for syscall regs, which will probably cause some unnecessary confusion/worry. Should we just skip printing it for the "regs->ip < PAGE_OFFSET" case?

How about we remove that check altogether?

I mean, __copy_from_user_inatomic() by way of probe_kernel_read() should be able to handle every address.

And if it doesn't, it says so:

        if (probe_kernel_read(opcodes, ip, OPCODE_BUFSIZE)) {
                pr_cont("Bad RIP value.\n");

And if we *can* print opcode bytes, why not do so? It is one more hint when debugging, who knows, might prove useful...

Hmm?

Signature · 4 lines
Regards/Gruss,
    Boris.

Good mailing practices for 400: avoid top-posting and trim the reply.
#22 lore raw

Re: [PATCH 8/9] x86/dumpstack: Save first regs set for the executive summary

Quoted 12 lines · Borislav Petkov
Quoted 3 lines · Josh Poimboeuf

Hm, the "Code: Bad RIP value" will always be shown for syscall regs, which will probably cause some unnecessary confusion/worry. Should we just skip printing it for the "regs->ip < PAGE_OFFSET" case?

How about we remove that check altogether?

I mean, __copy_from_user_inatomic() by way of probe_kernel_read() should be able to handle every address.

And if it doesn't, it says so:

Quoted 8 lines
        if (probe_kernel_read(opcodes, ip, OPCODE_BUFSIZE)) {
                pr_cont("Bad RIP value.\n");

And if we *can* print opcode bytes, why not do so? It is one more hint when debugging, who knows, might prove useful...

Hmm?

Yeah, sounds good to me. I think an earlier version of your patches already printed the user space opcodes anyway.

Signature · 1 line
Josh
author maintainer
#23 lore raw

Re: [PATCH 8/9] x86/dumpstack: Save first regs set for the executive summary

Quoted 2 lines · Josh Poimboeuf

Yeah, sounds good to me. I think an earlier version of your patches already printed the user space opcodes anyway.

Right, which means it works already! :-P

Signature · 4 lines
Regards/Gruss,
    Boris.

Good mailing practices for 400: avoid top-posting and trim the reply.
#24 lore raw

Re: [PATCH 8/9] x86/dumpstack: Save first regs set for the executive summary

In reply to Borislav Petkov
Quoted 10 lines · Borislav Petkov
Quoted 7 lines · Josh Poimboeuf

no_context() has the following line, right before it calls oops_end():

      /* Executive summary in case the body of the oops scrolled away */
      printk(KERN_DEFAULT "CR2: %016lx\n", address);

I think that line can now be removed, since the executive summary __show_regs() will include CR2.

Good idea. Done.

NOOOO!

Guys, %cr2 CAN AND DOES CHANGE!

The reason we do that

        printk(KERN_DEFAULT "CR2: %016lx\n", address);

is because WE ARE NOT PRINTING OUT THE CURRENT CR2 REGISTER!

This is really damn important.

The "address" register contains the CR2 value as it was read *very* early in the page fault case, before we enabled interrupts, and before we did various random things that can cause further page faults and change CR2!

So the executive summary that does __show_regs() may end up showing something completely different than the actual faulting address, because we might have taken a vmalloc-space exception in the meantime, for example.

Do *NOT* get rid of that thing.

You're better off getting rid of the CR2 line from __show_regs(), because it can be dangerously confusing. It's not actually part of the saved register state at all, it's something entirely different. It's like showing the current eflags rather than the eflags saved on the faulting stack.

Linus

#25 lore raw

Re: [PATCH 8/9] x86/dumpstack: Save first regs set for the executive summary

Quoted 14 lines · Linus Torvalds
Quoted 10 lines · Borislav Petkov
Quoted 7 lines · Josh Poimboeuf

no_context() has the following line, right before it calls oops_end():

      /* Executive summary in case the body of the oops scrolled away */
      printk(KERN_DEFAULT "CR2: %016lx\n", address);

I think that line can now be removed, since the executive summary __show_regs() will include CR2.

Good idea. Done.

NOOOO!

Quoted 7 lines

Guys, %cr2 CAN AND DOES CHANGE!

The reason we do that

        printk(KERN_DEFAULT "CR2: %016lx\n", address);

is because WE ARE NOT PRINTING OUT THE CURRENT CR2 REGISTER!

Good point. I missed the fact that no_context() isn't printing the current CR2.

Quoted 12 lines

This is really damn important.

The "address" register contains the CR2 value as it was read *very* early in the page fault case, before we enabled interrupts, and before we did various random things that can cause further page faults and change CR2!

So the executive summary that does __show_regs() may end up showing something completely different than the actual faulting address, because we might have taken a vmalloc-space exception in the meantime, for example.

Quoted 7 lines

Do *NOT* get rid of that thing.

You're better off getting rid of the CR2 line from __show_regs(), because it can be dangerously confusing. It's not actually part of the saved register state at all, it's something entirely different. It's like showing the current eflags rather than the eflags saved on the faulting stack.

True, it's probably best to remove it. The only time we need CR2's value is presumably when it would have already been printed in no_context(), and so it primarily just adds confusion as you said.

Signature · 1 line
Josh
author maintainer
#26 lore raw

Re: [PATCH 8/9] x86/dumpstack: Save first regs set for the executive summary

In reply to Linus Torvalds
Quoted 5 lines · Linus Torvalds

The reason we do that

        printk(KERN_DEFAULT "CR2: %016lx\n", address);

is because WE ARE NOT PRINTING OUT THE CURRENT CR2 REGISTER!

Whoopsie!

Doh, __show_regs() reads CR2 again and there's a big fat window in-between...

Quoted 7 lines

This is really damn important.

The "address" register contains the CR2 value as it was read *very* early in the page fault case, before we enabled interrupts, and before we did various random things that can cause further page faults and change CR2!

Quoted 6 lines

So the executive summary that does __show_regs() may end up showing something completely different than the actual faulting address, because we might have taken a vmalloc-space exception in the meantime, for example.

Do *NOT* get rid of that thing.

Reverted.

Quoted 5 lines

You're better off getting rid of the CR2 line from __show_regs(), because it can be dangerously confusing. It's not actually part of the saved register state at all, it's something entirely different. It's like showing the current eflags rather than the eflags saved on the faulting stack.

Yeah, __show_regs() goes and gets a bunch of registers at the time __show_regs() runs. Which is ok for those which don't change in between but CR2 is special.

We probably could improve that situation by having a struct fault_regs or so wrapping pt_regs and adding a bunch of fields like CR2 etc. Fault handlers would then populate fault_regs at fault time while we're atomic and then hand this struct down to the printing path.

The printing path would fill out the rest and this way we won't have any of that monkey business anymore.

Thoughts?

Signature · 4 lines
Regards/Gruss,
    Boris.

Good mailing practices for 400: avoid top-posting and trim the reply.
#27 lore raw

Re: [PATCH 8/9] x86/dumpstack: Save first regs set for the executive summary

Quoted 15 lines · Borislav Petkov
Quoted 5 lines

You're better off getting rid of the CR2 line from __show_regs(), because it can be dangerously confusing. It's not actually part of the saved register state at all, it's something entirely different. It's like showing the current eflags rather than the eflags saved on the faulting stack.

Yeah, __show_regs() goes and gets a bunch of registers at the time __show_regs() runs. Which is ok for those which don't change in between but CR2 is special.

We probably could improve that situation by having a struct fault_regs or so wrapping pt_regs and adding a bunch of fields like CR2 etc. Fault handlers would then populate fault_regs at fault time while we're atomic and then hand this struct down to the printing path.

Quoted 4 lines

The printing path would fill out the rest and this way we won't have any of that monkey business anymore.

Thoughts?

It would be nice if we could save *all* the printed registers before they get a chance to change, but I don't know how feasible that is. Some of the registers change in entry code, like CR3 and GS.

Signature · 1 line
Josh
author maintainer
#28 lore raw

PATCH 9/9 x86/dumpstack: Explain the reasoning for the prologue and buffer size

In reply to Borislav Petkov

From: Borislav Petkov <[email protected]>

The whole reasoning behind the amount of opcode bytes dumped and prologue length isn't very clear so let's hold down some of the reasons for why it is done the way it is.

---
 arch/x86/kernel/dumpstack.c | 19 +++++++++++++++++++
 1 file changed, 19 insertions(+)
arch/x86/kernel/dumpstack.c +19 -0
index bb712ca99632..7ceba3c09ad7 100644
@@ -70,6 +70,25 @@ static void printk_stack_address(unsigned long address, int reliable,
 	printk("%s %s%pB\n", log_lvl, reliable ? "" : "? ", (void *)address);
 }
 
+/*
+ * The are a couple of reasons for the 2/3rd prologue, courtesy of Linus:
+ *
+ * In case where we don't have the exact kernel image (which, if we did, we can
+ * simply disassemble and navigate to the RIP), the purpose of the bigger
+ * prologue is to have more context and to be able to correlate the code from
+ * the different toolchains better.
+ *
+ * In addition, it helps in recreating the register allocation of the failing
+ * kernel and thus make sense of the register dump.
+ *
+ * What is more, the additional complication of a variable length insn arch like
+ * x86 warrants having longer byte sequence before rIP so that the disassembler
+ * can "sync" up properly and find instruction boundaries when decoding the
+ * opcode bytes.
+ *
+ * Thus, the 2/3rds prologue and 64 byte OPCODE_BUFSIZE is just a random
+ * guesstimate in attempt to achieve all of the above.
+ */
 void show_opcodes(u8 *rip, const char *loglvl)
 {
 #define OPCODE_BUFSIZE 64
Signature · 1 line
2.13.0
#29 lore raw

Re: [PATCH 9/9] x86/dumpstack: Explain the reasoning for the prologue and buffer size

Quoted 16 lines · Borislav Petkov

From: Borislav Petkov <[email protected]>

The whole reasoning behind the amount of opcode bytes dumped and prologue length isn't very clear so let's hold down some of the reasons for why it is done the way it is.

---
 arch/x86/kernel/dumpstack.c | 19 +++++++++++++++++++
 1 file changed, 19 insertions(+)
arch/x86/kernel/dumpstack.c +0 -0
index bb712ca99632..7ceba3c09ad7 100644

arch/x86/kernel/dumpstack.c static void printk_stack_address(unsigned long address, int reliable, · line 74

Quoted 5 lines
arch/x86/kernel/dumpstack.c +2 -0
@@ -70,6 +70,25 @@ static void printk_stack_address(unsigned long address, int reliable,
 	printk("%s %s%pB\n", log_lvl, reliable ? "" : "? ", (void *)address);
 }
 
+/*
+ * The are a couple of reasons for the 2/3rd prologue, courtesy of Linus:

s/The/There/

Quoted 23 lines
arch/x86/kernel/dumpstack.c +17 -0
+ *
+ * In case where we don't have the exact kernel image (which, if we did, we can
+ * simply disassemble and navigate to the RIP), the purpose of the bigger
+ * prologue is to have more context and to be able to correlate the code from
+ * the different toolchains better.
+ *
+ * In addition, it helps in recreating the register allocation of the failing
+ * kernel and thus make sense of the register dump.
+ *
+ * What is more, the additional complication of a variable length insn arch like
+ * x86 warrants having longer byte sequence before rIP so that the disassembler
+ * can "sync" up properly and find instruction boundaries when decoding the
+ * opcode bytes.
+ *
+ * Thus, the 2/3rds prologue and 64 byte OPCODE_BUFSIZE is just a random
+ * guesstimate in attempt to achieve all of the above.
+ */
 void show_opcodes(u8 *rip, const char *loglvl)
 {
 #define OPCODE_BUFSIZE 64
Signature · 1 line
2.13.0
Signature · 1 line
Josh
author maintainer
#30 lore raw

Re: [PATCH 9/9] x86/dumpstack: Explain the reasoning for the prologue and buffer size

Quoted 4 lines · Josh Poimboeuf
Quoted 2 lines

+/*
+ * The are a couple of reasons for the 2/3rd prologue, courtesy of Linus:

s/The/There/

Fixed, thanks.

Signature · 4 lines
Regards/Gruss,
    Boris.

Good mailing practices for 400: avoid top-posting and trim the reply.
#31 lore raw
In reply to Borislav Petkov
Quoted 4 lines · Borislav Petkov

here's v2 with the dumpstack cleanups. This one gets rid of code_bytes= as it was discussed last time. As a result, the code got even leaner and simpler. I like that. :)

This version looks ok to me. I'm sure there's room for tweaking here, but I'm not seeing anything alarming.

Linus

author maintainer
#32 lore raw
Quoted 2 lines · Linus Torvalds

This version looks ok to me. I'm sure there's room for tweaking here, but I'm not seeing anything alarming.

So I'm redoing the series ontop of 17-rc1 and I see a *lot* of output during testing. For example:

1) is from the userspace fault, 2) is the panic from sysrq but then you have 3) which is

	WARN_ON_ONCE(!cpu_online(new_cpu));

in set_task_cpu() and to top it all off, we have 4) coming from native_smp_send_reschedule():

static void native_smp_send_reschedule(int cpu)

{
        if (unlikely(cpu_is_offline(cpu))) {
                WARN(1, "sched: Unexpected reschedule of offline CPU#%d!\n", cpu);

so all the "fine tuning" we did to try to fit the most important splat on the screen is for shit because those loud WARNs simply pushed it all up into oblivion.

And the executive summary and registers are just as worthless in such a case.

We could start thinking about caching all that data from the very first splat, when we're not tainted yet and dump it last but then we can't even know what is going out last.

Not only because we can't guess from where stuff might warn and what could execute - the below splats case-in-point - also, and more importantly, we don't know how much of that data would actually go out as there are no guarantees *when* the machine will die and stop spewing to the serial port.

So maybe the most important splat coming out first is maybe a good thing because it has a higher chance of coming out before the box locks up completely.

So I guess we should keep hoping that serial console works and keeps on working...

Hmmm.

1.
---

[  211.766286] strsep[2240]: segfault at 40066b ip 00007f9d4e0a301b sp 00007ffcd158a1e0 error 7 in libc-2.24.so[7f9d4e01a000+195000]
[  211.778147] Code: 53 48 83 ec 08 48 8b 2f 48 85 ed 74 27 0f b6 06 48 89 fb 84 c0 74 34 80 7e 01 00 74 22 48 89 ef e8 7a 68 f9 ff 48 85 c0 74 21 <c6> 00 00 48 83 c0 01 48 89 03 48 83 c4 08 48 89 e8 5b 5d c3 90 0f 

2.
---

[  218.747919] sysrq: SysRq : Trigger a crash
[  218.752258] BUG: unable to handle kernel NULL pointer dereference at 0000000000000000
[  218.760044] PGD 8000000439bb8067 P4D 8000000439bb8067 PUD 4381ac067 PMD 0 
[  218.766888] Oops: 0002 [#1] PREEMPT SMP PTI
[  218.771052] CPU: 5 PID: 2200 Comm: bash Not tainted 4.17.0-rc1+ #1
[  218.777203] Hardware name: Dell Inc. Precision T3600/0PTTT9, BIOS A13 05/11/2014
[  218.784562] RIP: 0010:sysrq_handle_crash+0x41/0x80
[  218.789319] Code: e8 c4 17 c4 ff 48 c7 c2 87 b6 4a 81 be 01 00 00 00 48 c7 c7 c0 07 25 82 e8 2c 23 c2 ff c7 05 82 7a 39 01 01 00 00 00 0f ae f8 <c6> 04 25 00 00 00 00 01 c3 e8 61 43 c4 ff 84 c0 75 c4 48 c7 c2 50 
[  218.808148] RSP: 0018:ffffc90003d03de8 EFLAGS: 00010286
[  218.813338] RAX: 0000000000000000 RBX: 0000000000000063 RCX: 3e2d9cbd00000000
[  218.820422] RDX: ffff88043804cd38 RSI: 000000006cb322e4 RDI: 0000000000000000
[  218.827508] RBP: ffffc90003d03e10 R08: 000000003f352d81 R09: 0000000000000001
[  218.834595] R10: 0000000000000000 R11: 0000000000000000 R12: 0000000000000007
[  218.841680] R13: ffffffff822c09e0 R14: 0000000000000000 R15: 0000000000000000
[  218.848773] FS:  00007f4105bce280(0000) GS:ffff88043df40000(0000) knlGS:0000000000000000
[  218.856808] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[  218.862514] CR2: 0000000000000000 CR3: 0000000439428005 CR4: 00000000000606e0
[  218.869599] Call Trace:
[  218.872041]  __handle_sysrq+0xcd/0x210
[  218.875774]  write_sysrq_trigger+0x48/0x50
[  218.879853]  proc_reg_write+0x3c/0x60
[  218.883501]  __vfs_write+0x36/0x160
[  218.886986]  ? rcu_read_lock_sched_held+0x74/0x80
[  218.891666]  ? rcu_sync_lockdep_assert+0x2e/0x60
[  218.896268]  ? __sb_start_write+0x157/0x200
[  218.900425]  ? __sb_start_write+0x16d/0x200
[  218.904585]  vfs_write+0xbe/0x1b0
[  218.907886]  ksys_write+0x55/0xc0
[  218.911193]  do_syscall_64+0x64/0x200
[  218.914858]  entry_SYSCALL_64_after_hwframe+0x49/0xbe
[  218.919881] RIP: 0033:0x7f41050a9620
[  218.923429] Code: 73 01 c3 48 8b 0d 78 c8 2b 00 f7 d8 64 89 01 48 83 c8 ff c3 66 0f 1f 44 00 00 83 3d 29 21 2c 00 00 75 10 b8 01 00 00 00 0f 05 <48> 3d 01 f0 ff ff 73 31 c3 48 83 ec 08 e8 ae 9b 01 00 48 89 04 24 
[  218.942261] RSP: 002b:00007ffe8c2ad378 EFLAGS: 00000246 ORIG_RAX: 0000000000000001
[  218.949778] RAX: ffffffffffffffda RBX: 0000000000000002 RCX: 00007f41050a9620
[  218.956863] RDX: 0000000000000002 RSI: 00000000008fe408 RDI: 0000000000000001
[  218.963949] RBP: 00000000008fe408 R08: 00007f4105368760 R09: 00007f4105bce280
[  218.971047] R10: 0000000000000073 R11: 0000000000000246 R12: 0000000000000002
[  218.978138] R13: 0000000000000001 R14: 00007f4105367600 R15: 0000000000000002
[  218.985240] Modules linked in: binfmt_misc xfs nls_iso8859_15 nls_cp437 btrfs xor zstd_decompress zstd_compress xxhash raid6_pq sb_edac libcrc32c x86_pkg_temp_thermal coretemp kvm_intel kvm irqbypass crc32_pclmul snd_hda_codec_hdmi crc32c_intel ghash_clmulni_intel usbhid aesni_intel aes_x86_64 snd_hda_codec_realtek snd_hda_codec_generic crypto_simd cryptd snd_hda_intel glue_helper iTCO_wdt intel_cstate snd_hda_codec intel_uncore snd_hwdep dcdbas snd_hda_core dell_smm_hwmon iTCO_vendor_support intel_rapl_perf snd_pcm efi_pstore snd_timer serio_raw lpc_ich efivars i2c_i801 mfd_core snd soundcore button
[  219.038108] CR2: 0000000000000000
[  219.041499] ---[ end trace 75992131ce321254 ]---
[  219.046095] RIP: 0010:sysrq_handle_crash+0x41/0x80
[  219.050848] Code: e8 c4 17 c4 ff 48 c7 c2 87 b6 4a 81 be 01 00 00 00 48 c7 c7 c0 07 25 82 e8 2c 23 c2 ff c7 05 82 7a 39 01 01 00 00 00 0f ae f8 <c6> 04 25 00 00 00 00 01 c3 e8 61 43 c4 ff 84 c0 75 c4 48 c7 c2 50 
[  219.069577] RSP: 0018:ffffc90003d03de8 EFLAGS: 00010286
[  219.074770] RAX: 0000000000000000 RBX: 0000000000000063 RCX: 3e2d9cbd00000000
[  219.081842] RDX: ffff88043804cd38 RSI: 000000006cb322e4 RDI: 0000000000000000
[  219.088919] RBP: ffffc90003d03e10 R08: 000000003f352d81 R09: 0000000000000001
[  219.096000] R10: 0000000000000000 R11: 0000000000000000 R12: 0000000000000007
[  219.103077] R13: ffffffff822c09e0 R14: 0000000000000000 R15: 0000000000000000
[  219.110151] FS:  00007f4105bce280(0000) GS:ffff88043df40000(0000) knlGS:0000000000000000
[  219.118168] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[  219.124199] CR2: 0000000000000000 CR3: 0000000439428005 CR4: 00000000000606e0
[  219.131603] Kernel panic - not syncing: Fatal exception
[  219.137135] Kernel Offset: disabled
[  219.140909] ---[ end Kernel panic - not syncing: Fatal exception ]---

3.
---

[  219.147613] WARNING: CPU: 5 PID: 2200 at kernel/sched/core.c:1163 set_task_cpu+0x24e/0x2c0
[  219.157314] Modules linked in: binfmt_misc xfs nls_iso8859_15 nls_cp437 btrfs xor zstd_decompress zstd_compress xxhash raid6_pq sb_edac libcrc32c x86_pkg_temp_thermal coretemp kvm_intel kvm irqbypass crc32_pclmul snd_hda_codec_hdmi crc32c_intel ghash_clmulni_intel usbhid aesni_intel aes_x86_64 snd_hda_codec_realtek snd_hda_codec_generic crypto_simd cryptd snd_hda_intel glue_helper iTCO_wdt intel_cstate snd_hda_codec intel_uncore snd_hwdep dcdbas snd_hda_core dell_smm_hwmon iTCO_vendor_support intel_rapl_perf snd_pcm efi_pstore snd_timer serio_raw lpc_ich efivars i2c_i801 mfd_core snd soundcore button
[  219.214593] CPU: 5 PID: 2200 Comm: bash Tainted: G      D           4.17.0-rc1+ #1
[  219.223581] Hardware name: Dell Inc. Precision T3600/0PTTT9, BIOS A13 05/11/2014
[  219.232396] RIP: 0010:set_task_cpu+0x24e/0x2c0
[  219.238281] Code: 85 c0 0f 85 2a fe ff ff 0f 0b e9 23 fe ff ff 0f 0b e9 f7 fd ff ff f7 43 60 fd ff ff ff 0f 84 01 fe ff ff 0f 0b e9 fa fd ff ff <0f> 0b e9 12 fe ff ff e8 f6 c0 04 00 85 c0 0f 85 72 ff ff ff 48 c7 
[  219.260179] RSP: 0018:ffff88043df43d78 EFLAGS: 00010046
[  219.266967] RAX: 0000000000000000 RBX: ffff880439e81700 RCX: 0000000000000000
[  219.275649] RDX: 0000000000000000 RSI: 0000000000000000 RDI: ffff880439e81700
[  219.284264] RBP: 0000000000000000 R08: 0000000000000000 R09: 0000000000000000
[  219.292805] R10: 0000000000000000 R11: ffffffff822507c0 R12: ffff880439e81e78
[  219.301344] R13: 0000000000000000 R14: 0000000000000046 R15: 0000000000021b40
[  219.309884] FS:  00007f4105bce280(0000) GS:ffff88043df40000(0000) knlGS:0000000000000000
[  219.319375] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[  219.326549] CR2: 0000000000000000 CR3: 0000000439428005 CR4: 00000000000606e0
[  219.335106] Call Trace:
[  219.339018]  <IRQ>
[  219.342481]  try_to_wake_up+0x176/0x530
[  219.347751]  ? lock_acquire+0xa6/0x220
[  219.352928]  autoremove_wake_function+0xe/0x30
[  219.358773]  __wake_up_common+0x74/0x120
[  219.364114]  __wake_up_common_lock+0x7c/0xc0
[  219.369795]  ? tick_sched_do_timer+0x80/0x80
[  219.375482]  irq_work_run_list+0x49/0x70
[  219.380820]  update_process_times+0x3b/0x50
[  219.386416]  tick_sched_timer+0x37/0x70
[  219.391674]  __hrtimer_run_queues+0x114/0x590
[  219.397444]  hrtimer_interrupt+0xd5/0x220
[  219.402867]  ? trace_hardirqs_off_thunk+0x1a/0x1c
[  219.408983]  smp_apic_timer_interrupt+0x80/0x2e0
[  219.415014]  apic_timer_interrupt+0xf/0x20
[  219.420538]  </IRQ>
[  219.424076] RIP: 0010:panic+0x1fe/0x24c
[  219.429321] Code: a6 83 3d 28 97 7d 01 00 74 05 e8 c9 c9 02 00 48 c7 c6 60 31 84 82 48 c7 c7 90 e3 0a 82 e8 c4 68 07 00 e8 01 1e 06 00 fb 31 db <e8> f9 c7 0c 00 4c 39 eb 7c 1d 41 83 f4 01 48 8b 05 e9 96 7d 01 44 
[  219.450965] RSP: 0018:ffffc90003d03b90 EFLAGS: 00000246 ORIG_RAX: ffffffffffffff13
[  219.459921] RAX: 0000000000000039 RBX: 0000000000000000 RCX: 0000000000000001
[  219.468443] RDX: 0000000000000000 RSI: ffffffff81069a1f RDI: ffffffff81069a1f
[  219.476966] RBP: ffffc90003d03c08 R08: 0000000000000000 R09: 0000000000000000
[  219.485493] R10: ffffc90003d03ad0 R11: ffffffff8224e338 R12: 0000000000000000
[  219.494018] R13: 0000000000000000 R14: 000000000000000b R15: 0000000000000009
[  219.502549]  ? panic+0x1fb/0x24c
[  219.507175]  ? panic+0x1fb/0x24c
[  219.511771]  oops_end+0xbb/0xc0
[  219.516248]  no_context+0x17e/0x400
[  219.521044]  __do_page_fault+0x3f4/0x570
[  219.526260]  ? trace_hardirqs_off_caller+0x83/0xe0
[  219.532326]  do_page_fault+0x2c/0x2b0
[  219.537210]  page_fault+0x1e/0x30
[  219.541677] RIP: 0010:sysrq_handle_crash+0x41/0x80
[  219.547600] Code: e8 c4 17 c4 ff 48 c7 c2 87 b6 4a 81 be 01 00 00 00 48 c7 c7 c0 07 25 82 e8 2c 23 c2 ff c7 05 82 7a 39 01 01 00 00 00 0f ae f8 <c6> 04 25 00 00 00 00 01 c3 e8 61 43 c4 ff 84 c0 75 c4 48 c7 c2 50 
[  219.568890] RSP: 0018:ffffc90003d03de8 EFLAGS: 00010286
[  219.575381] RAX: 0000000000000000 RBX: 0000000000000063 RCX: 3e2d9cbd00000000
[  219.583774] RDX: ffff88043804cd38 RSI: 000000006cb322e4 RDI: 0000000000000000
[  219.592163] RBP: ffffc90003d03e10 R08: 000000003f352d81 R09: 0000000000000001
[  219.600544] R10: 0000000000000000 R11: 0000000000000000 R12: 0000000000000007
[  219.608918] R13: ffffffff822c09e0 R14: 0000000000000000 R15: 0000000000000000
[  219.617290]  ? sysrq_handle_crash+0x34/0x80
[  219.622727]  __handle_sysrq+0xcd/0x210
[  219.627731]  write_sysrq_trigger+0x48/0x50
[  219.633075]  proc_reg_write+0x3c/0x60
[  219.637980]  __vfs_write+0x36/0x160
[  219.642686]  ? rcu_read_lock_sched_held+0x74/0x80
[  219.648556]  ? rcu_sync_lockdep_assert+0x2e/0x60
[  219.654302]  ? __sb_start_write+0x157/0x200
[  219.659595]  ? __sb_start_write+0x16d/0x200
[  219.664866]  vfs_write+0xbe/0x1b0
[  219.669268]  ksys_write+0x55/0xc0
[  219.673602]  do_syscall_64+0x64/0x200
[  219.678202]  entry_SYSCALL_64_after_hwframe+0x49/0xbe
[  219.684177] RIP: 0033:0x7f41050a9620
[  219.688682] Code: 73 01 c3 48 8b 0d 78 c8 2b 00 f7 d8 64 89 01 48 83 c8 ff c3 66 0f 1f 44 00 00 83 3d 29 21 2c 00 00 75 10 b8 01 00 00 00 0f 05 <48> 3d 01 f0 ff ff 73 31 c3 48 83 ec 08 e8 ae 9b 01 00 48 89 04 24 
[  219.709570] RSP: 002b:00007ffe8c2ad378 EFLAGS: 00000246 ORIG_RAX: 0000000000000001
[  219.718195] RAX: ffffffffffffffda RBX: 0000000000000002 RCX: 00007f41050a9620
[  219.726391] RDX: 0000000000000002 RSI: 00000000008fe408 RDI: 0000000000000001
[  219.734584] RBP: 00000000008fe408 R08: 00007f4105368760 R09: 00007f4105bce280
[  219.742793] R10: 0000000000000073 R11: 0000000000000246 R12: 0000000000000002
[  219.750973] R13: 0000000000000001 R14: 00007f4105367600 R15: 0000000000000002
[  219.759145] irq event stamp: 80113
[  219.763626] hardirqs last  enabled at (80113): [<ffffffff810544f9>] __do_page_fault+0x2f9/0x570
[  219.773371] hardirqs last disabled at (80112): [<ffffffff81a01096>] error_entry+0x86/0x100
[  219.782690] softirqs last  enabled at (80104): [<ffffffff81c0039e>] __do_softirq+0x39e/0x504
[  219.792196] softirqs last disabled at (80095): [<ffffffff810719d5>] irq_exit+0xd5/0xe0
[  219.801181] ---[ end trace 75992131ce321255 ]---

4.
---

[  219.806912] ------------[ cut here ]------------
[  219.812640] sched: Unexpected reschedule of offline CPU#0!
[  219.819253] WARNING: CPU: 5 PID: 2200 at arch/x86/kernel/smp.c:128 native_smp_send_reschedule+0x34/0x40
[  219.829732] Modules linked in: binfmt_misc xfs nls_iso8859_15 nls_cp437 btrfs xor zstd_decompress zstd_compress xxhash raid6_pq sb_edac libcrc32c x86_pkg_temp_thermal coretemp kvm_intel kvm irqbypass crc32_pclmul snd_hda_codec_hdmi crc32c_intel ghash_clmulni_intel usbhid aesni_intel aes_x86_64 snd_hda_codec_realtek snd_hda_codec_generic crypto_simd cryptd snd_hda_intel glue_helper iTCO_wdt intel_cstate snd_hda_codec intel_uncore snd_hwdep dcdbas snd_hda_core dell_smm_hwmon iTCO_vendor_support intel_rapl_perf snd_pcm efi_pstore snd_timer serio_raw lpc_ich efivars i2c_i801 mfd_core snd soundcore button
[  219.886225] CPU: 5 PID: 2200 Comm: bash Tainted: G      D W         4.17.0-rc1+ #1
[  219.895022] Hardware name: Dell Inc. Precision T3600/0PTTT9, BIOS A13 05/11/2014
[  219.903655] RIP: 0010:native_smp_send_reschedule+0x34/0x40
[  219.910397] Code: 05 21 ea 30 01 73 15 48 8b 05 78 34 13 01 be fd 00 00 00 48 8b 40 30 e9 aa 63 bc 00 89 fe 48 c7 c7 88 66 0a 82 e8 ec c5 02 00 <0f> 0b c3 66 0f 1f 84 00 00 00 00 00 66 66 66 66 90 8b 05 55 73 80 
[  219.931962] RSP: 0018:ffff88043df43d60 EFLAGS: 00010082
[  219.938524] RAX: 0000000000000000 RBX: ffff88043de21b40 RCX: 0000000000010004
[  219.946918] RDX: 0000000080010004 RSI: ffffffff820ebfed RDI: 00000000ffffffff
[  219.955301] RBP: ffff880439e81700 R08: 0000000000000000 R09: 0000000000000000
[  219.963686] R10: afb504000afb5041 R11: ffffffff8224e338 R12: ffff880439e81e78
[  219.972069] R13: ffff88043df43db0 R14: 0000000000000046 R15: ffff88043de21b58
[  219.980459] FS:  00007f4105bce280(0000) GS:ffff88043df40000(0000) knlGS:0000000000000000
[  219.989801] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[  219.996819] CR2: 0000000000000000 CR3: 0000000439428005 CR4: 00000000000606e0
[  220.005216] Call Trace:
[  220.008992]  <IRQ>
[  220.012324]  check_preempt_curr+0x86/0xb0
[  220.017637]  ttwu_do_wakeup+0x19/0x270
[  220.022687]  try_to_wake_up+0x204/0x530
[  220.027820]  autoremove_wake_function+0xe/0x30
[  220.033553]  __wake_up_common+0x74/0x120
[  220.038771]  __wake_up_common_lock+0x7c/0xc0
[  220.044338]  ? tick_sched_do_timer+0x80/0x80
[  220.049829]  irq_work_run_list+0x49/0x70
[  220.054901]  update_process_times+0x3b/0x50
[  220.060230]  tick_sched_timer+0x37/0x70
[  220.065205]  __hrtimer_run_queues+0x114/0x590
[  220.070695]  hrtimer_interrupt+0xd5/0x220
[  220.075837]  ? trace_hardirqs_off_thunk+0x1a/0x1c
[  220.081669]  smp_apic_timer_interrupt+0x80/0x2e0
[  220.087412]  apic_timer_interrupt+0xf/0x20
[  220.092630]  </IRQ>
[  220.095903] RIP: 0010:panic+0x1fe/0x24c
[  220.100861] Code: a6 83 3d 28 97 7d 01 00 74 05 e8 c9 c9 02 00 48 c7 c6 60 31 84 82 48 c7 c7 90 e3 0a 82 e8 c4 68 07 00 e8 01 1e 06 00 fb 31 db <e8> f9 c7 0c 00 4c 39 eb 7c 1d 41 83 f4 01 48 8b 05 e9 96 7d 01 44 
[  220.122141] RSP: 0018:ffffc90003d03b90 EFLAGS: 00000246 ORIG_RAX: ffffffffffffff13
[  220.130970] RAX: 0000000000000039 RBX: 0000000000000000 RCX: 0000000000000001
[  220.139368] RDX: 0000000000000000 RSI: ffffffff81069a1f RDI: ffffffff81069a1f
[  220.147767] RBP: ffffc90003d03c08 R08: 0000000000000000 R09: 0000000000000000
[  220.156178] R10: ffffc90003d03ad0 R11: ffffffff8224e338 R12: 0000000000000000
[  220.164590] R13: 0000000000000000 R14: 000000000000000b R15: 0000000000000009
[  220.173012]  ? panic+0x1fb/0x24c
[  220.177561]  ? panic+0x1fb/0x24c
[  220.182108]  oops_end+0xbb/0xc0
[  220.186559]  no_context+0x17e/0x400
[  220.191290]  __do_page_fault+0x3f4/0x570
[  220.196374]  ? trace_hardirqs_off_caller+0x83/0xe0
[  220.202312]  do_page_fault+0x2c/0x2b0
[  220.207124]  page_fault+0x1e/0x30
[  220.211584] RIP: 0010:sysrq_handle_crash+0x41/0x80
[  220.217507] Code: e8 c4 17 c4 ff 48 c7 c2 87 b6 4a 81 be 01 00 00 00 48 c7 c7 c0 07 25 82 e8 2c 23 c2 ff c7 05 82 7a 39 01 01 00 00 00 0f ae f8 <c6> 04 25 00 00 00 00 01 c3 e8 61 43 c4 ff 84 c0 75 c4 48 c7 c2 50 
[  220.238815] RSP: 0018:ffffc90003d03de8 EFLAGS: 00010286
[  220.245319] RAX: 0000000000000000 RBX: 0000000000000063 RCX: 3e2d9cbd00000000
[  220.253709] RDX: ffff88043804cd38 RSI: 000000006cb322e4 RDI: 0000000000000000
[  220.262096] RBP: ffffc90003d03e10 R08: 000000003f352d81 R09: 0000000000000001
[  220.270477] R10: 0000000000000000 R11: 0000000000000000 R12: 0000000000000007
[  220.278855] R13: ffffffff822c09e0 R14: 0000000000000000 R15: 0000000000000000
[  220.287230]  ? sysrq_handle_crash+0x34/0x80
[  220.292677]  __handle_sysrq+0xcd/0x210
[  220.297690]  write_sysrq_trigger+0x48/0x50
[  220.303037]  proc_reg_write+0x3c/0x60
[  220.307920]  __vfs_write+0x36/0x160
[  220.312595]  ? rcu_read_lock_sched_held+0x74/0x80
[  220.318443]  ? rcu_sync_lockdep_assert+0x2e/0x60
[  220.324172]  ? __sb_start_write+0x157/0x200
[  220.329464]  ? __sb_start_write+0x16d/0x200
[  220.334745]  vfs_write+0xbe/0x1b0
[  220.339116]  ksys_write+0x55/0xc0
[  220.343401]  do_syscall_64+0x64/0x200
[  220.348014]  entry_SYSCALL_64_after_hwframe+0x49/0xbe
[  220.354001] RIP: 0033:0x7f41050a9620
[  220.358521] Code: 73 01 c3 48 8b 0d 78 c8 2b 00 f7 d8 64 89 01 48 83 c8 ff c3 66 0f 1f 44 00 00 83 3d 29 21 2c 00 00 75 10 b8 01 00 00 00 0f 05 <48> 3d 01 f0 ff ff 73 31 c3 48 83 ec 08 e8 ae 9b 01 00 48 89 04 24 
[  220.379421] RSP: 002b:00007ffe8c2ad378 EFLAGS: 00000246 ORIG_RAX: 0000000000000001
[  220.388042] RAX: ffffffffffffffda RBX: 0000000000000002 RCX: 00007f41050a9620
[  220.396231] RDX: 0000000000000002 RSI: 00000000008fe408 RDI: 0000000000000001
[  220.404413] RBP: 00000000008fe408 R08: 00007f4105368760 R09: 00007f4105bce280
[  220.412590] R10: 0000000000000073 R11: 0000000000000246 R12: 0000000000000002
[  220.420759] R13: 0000000000000001 R14: 00007f4105367600 R15: 0000000000000002
[  220.428933] irq event stamp: 80113
[  220.433409] hardirqs last  enabled at (80113): [<ffffffff810544f9>] __do_page_fault+0x2f9/0x570
[  220.443155] hardirqs last disabled at (80112): [<ffffffff81a01096>] error_entry+0x86/0x100
[  220.452472] softirqs last  enabled at (80104): [<ffffffff81c0039e>] __do_softirq+0x39e/0x504
[  220.461970] softirqs last disabled at (80095): [<ffffffff810719d5>] irq_exit+0xd5/0xe0
[  220.470953] ---[ end trace 75992131ce321256 ]---
Signature · 4 lines
Regards/Gruss,
    Boris.

Good mailing practices for 400: avoid top-posting and trim the reply.
#33 lore raw
Quoted 37 lines · Borislav Petkov
Quoted 2 lines · Linus Torvalds

This version looks ok to me. I'm sure there's room for tweaking here, but I'm not seeing anything alarming.

So I'm redoing the series ontop of 17-rc1 and I see a *lot* of output during testing. For example:

1) is from the userspace fault, 2) is the panic from sysrq but then you have 3) which is

	WARN_ON_ONCE(!cpu_online(new_cpu));

in set_task_cpu() and to top it all off, we have 4) coming from native_smp_send_reschedule():

static void native_smp_send_reschedule(int cpu)

{
        if (unlikely(cpu_is_offline(cpu))) {
                WARN(1, "sched: Unexpected reschedule of offline CPU#%d!\n", cpu);

so all the "fine tuning" we did to try to fit the most important splat on the screen is for shit because those loud WARNs simply pushed it all up into oblivion.

And the executive summary and registers are just as worthless in such a case.

We could start thinking about caching all that data from the very first splat, when we're not tainted yet and dump it last but then we can't even know what is going out last.

Not only because we can't guess from where stuff might warn and what could execute - the below splats case-in-point - also, and more importantly, we don't know how much of that data would actually go out as there are no guarantees *when* the machine will die and stop spewing to the serial port.

Quoted 8 lines

So maybe the most important splat coming out first is maybe a good thing because it has a higher chance of coming out before the box locks up completely.

So I guess we should keep hoping that serial console works and keeps on working...

Hmmm.

I don't think the stack tracing code could do anything better here. #3 and #4 seem like an issue with the scheduler, it doesn't realize the rest of the CPUs have all been taken offline due to the panic().

Signature · 1 line
Josh
author maintainer
#34 lore raw
Quoted 3 lines · Josh Poimboeuf

I don't think the stack tracing code could do anything better here. #3 and #4 seem like an issue with the scheduler, it doesn't realize the rest of the CPUs have all been taken offline due to the panic().

So maybe teach the WARN code to check whether a panic() has happened?

Signature · 4 lines
Regards/Gruss,
    Boris.

Good mailing practices for 400: avoid top-posting and trim the reply.
#35 lore raw
Quoted 6 lines · Borislav Petkov
Quoted 3 lines · Josh Poimboeuf

I don't think the stack tracing code could do anything better here. #3 and #4 seem like an issue with the scheduler, it doesn't realize the rest of the CPUs have all been taken offline due to the panic().

So maybe teach the WARN code to check whether a panic() has happened?

I get the feeling that disabling warnings could be papering over a real bug, but maybe we don't care about bugs in the post-panic state?

Ideally we could just leave interrupts disabled, but I don't know if that's generally feasible since it looks like sparc is waiting for keyboard interrupts to allow breaking out to the boot prom.

Signature · 1 line
Josh