[PATCH v2] kdb: Fix stack crawling on 'running' CPUs that aren't the master

[PATCH v2] kdb: Fix stack crawling on 'running' CPUs that aren't the master

[Douglas Anderson]

In kdb when you do 'btc' (back trace on CPU) it doesn't necessarily
give you the right info.  Specifically on many architectures
(including arm64, where I tested) you can't dump the stack of a
"running" process that isn't the process running on the current CPU.
This can be seen by this:

 echo SOFTLOCKUP > /sys/kernel/debug/provoke-crash/DIRECT
 # wait 2 seconds
 <sysrq>g

Here's what I see now on rk3399-gru-kevin.  I see the stack crawl for
the CPU that handled the sysrq but everything else just shows me stuck
in __switch_to() which is bogus:

======

[0]kdb> btc
btc: cpu status: Currently on cpu 0
Available cpus: 0, 1-3(I), 4, 5(I)
Stack traceback for pid 0
0xffffff801101a9c0        0        0  1    0   R  0xffffff801101b3b0 *swapper/0
Call trace:
 dump_backtrace+0x0/0x138
 ...
 kgdb_compiled_brk_fn+0x34/0x44
 ...
 sysrq_handle_dbg+0x34/0x5c
Stack traceback for pid 0
0xffffffc0f175a040        0        0  1    1   I  0xffffffc0f175aa30  swapper/1
Call trace:
 __switch_to+0x1e4/0x240
 0xffffffc0f65616c0
Stack traceback for pid 0
0xffffffc0f175d040        0        0  1    2   I  0xffffffc0f175da30  swapper/2
Call trace:
 __switch_to+0x1e4/0x240
 0xffffffc0f65806c0
Stack traceback for pid 0
0xffffffc0f175b040        0        0  1    3   I  0xffffffc0f175ba30  swapper/3
Call trace:
 __switch_to+0x1e4/0x240
 0xffffffc0f659f6c0
Stack traceback for pid 1474
0xffffffc0dde8b040     1474      727  1    4   R  0xffffffc0dde8ba30  bash
Call trace:
 __switch_to+0x1e4/0x240
 __schedule+0x464/0x618
 0xffffffc0dde8b040
Stack traceback for pid 0
0xffffffc0f17b0040        0        0  1    5   I  0xffffffc0f17b0a30  swapper/5
Call trace:
 __switch_to+0x1e4/0x240
 0xffffffc0f65dd6c0

===

The problem is that 'btc' eventually boils down to
  show_stack(task_struct, NULL);

...and show_stack() doesn't work for "running" CPUs because their
registers haven't been stashed.

On x86 things might work better (I haven't tested) because kdb has a
special case for x86 in kdb_show_stack() where it passes the stack
pointer to show_stack().  This wouldn't work on arm64 where the stack
crawling function seems needs the "fp" and "pc", not the "sp" which is
presumably why arm64's show_stack() function totally ignores the "sp"
parameter.

NOTE: we _can_ get a good stack dump for all the cpus if we manually
switch each one to the kdb master and do a back trace.  AKA:
  cpu 4
  bt
...will give the expected trace.  That's because now arm64's
dump_backtrace will now see that "tsk == current" and go through a
different path.

In this patch I fix the problems by catching a request to stack crawl
a task that's running on a CPU and then I ask that CPU to do the stack
crawl.

NOTE: this will (presumably) change what stack crawls are printed for
x86 machines.  Now kdb functions will show up in the stack crawl.
Presumably this is OK but if it's not we can go back and add a special
case for x86 again.

Signed-off-by: Douglas Anderson <dianders@chromium.org>
---

Changes in v2:
- Totally new approach; now arch agnostic.

 kernel/debug/debug_core.c |  5 +++++
 kernel/debug/debug_core.h |  1 +
 kernel/debug/kdb/kdb_bt.c | 44 ++++++++++++++++++++++++++++++---------
 3 files changed, 40 insertions(+), 10 deletions(-)

diff --git a/kernel/debug/debug_core.c b/kernel/debug/debug_core.c
index 5cc608de6883..a89c72714fe6 100644
--- a/kernel/debug/debug_core.c
+++ b/kernel/debug/debug_core.c
@@ -92,6 +92,8 @@ static int kgdb_use_con;
 bool dbg_is_early = true;
 /* Next cpu to become the master debug core */
 int dbg_switch_cpu;
+/* cpu number of slave we request a stack crawl of */
+int dbg_slave_dumpstack_cpu = -1;
 
 /* Use kdb or gdbserver mode */
 int dbg_kdb_mode = 1;
@@ -580,6 +582,9 @@ static int kgdb_cpu_enter(struct kgdb_state *ks, struct pt_regs *regs,
 				atomic_xchg(&kgdb_active, cpu);
 				break;
 			}
+		} else if (dbg_slave_dumpstack_cpu == cpu) {
+			dump_stack();
+			dbg_slave_dumpstack_cpu = -1;
 		} else if (kgdb_info[cpu].exception_state & DCPU_IS_SLAVE) {
 			if (!raw_spin_is_locked(&dbg_slave_lock))
 				goto return_normal;
diff --git a/kernel/debug/debug_core.h b/kernel/debug/debug_core.h
index b4a7c326d546..dca74d5caef2 100644
--- a/kernel/debug/debug_core.h
+++ b/kernel/debug/debug_core.h
@@ -62,6 +62,7 @@ extern int dbg_io_get_char(void);
 /* Switch from one cpu to another */
 #define DBG_SWITCH_CPU_EVENT -123456
 extern int dbg_switch_cpu;
+extern int dbg_slave_dumpstack_cpu;
 
 /* gdbstub interface functions */
 extern int gdb_serial_stub(struct kgdb_state *ks);
diff --git a/kernel/debug/kdb/kdb_bt.c b/kernel/debug/kdb/kdb_bt.c
index 7e2379aa0a1e..10095ae05826 100644
--- a/kernel/debug/kdb/kdb_bt.c
+++ b/kernel/debug/kdb/kdb_bt.c
@@ -10,6 +10,7 @@
  */
 
 #include <linux/ctype.h>
+#include <linux/delay.h>
 #include <linux/string.h>
 #include <linux/kernel.h>
 #include <linux/sched/signal.h>
@@ -22,20 +23,43 @@
 static void kdb_show_stack(struct task_struct *p, void *addr)
 {
 	int old_lvl = console_loglevel;
+	int time_left;
+	int cpu;
+
 	console_loglevel = CONSOLE_LOGLEVEL_MOTORMOUTH;
 	kdb_trap_printk++;
-	kdb_set_current_task(p);
-	if (addr) {
-		show_stack((struct task_struct *)p, addr);
-	} else if (kdb_current_regs) {
-#ifdef CONFIG_X86
-		show_stack(p, &kdb_current_regs->sp);
-#else
-		show_stack(p, NULL);
-#endif
+
+	if (!addr && kdb_task_has_cpu(p)) {
+		cpu = kdb_process_cpu(p);
+
+		if (cpu == raw_smp_processor_id()) {
+			dump_stack();
+			goto exit;
+		}
+
+		/*
+		 * In general architectures don't support dumping the stack
+		 * of a "running" process that's not the current one so if
+		 * we want to dump the stack of a running process that's not
+		 * the master then we'll set a global letting the slave
+		 * (which should be looping) know to dump its own stack.
+		 */
+		dbg_slave_dumpstack_cpu = cpu;
+		for (time_left = MSEC_PER_SEC; time_left; time_left--) {
+			udelay(1000);
+			if (dbg_slave_dumpstack_cpu == -1)
+				break;
+		}
+		if (dbg_slave_dumpstack_cpu != -1) {
+			kdb_printf("ERROR: Timeout dumping CPU %d stack\n",
+				   cpu);
+			dbg_slave_dumpstack_cpu = -1;
+		}
 	} else {
-		show_stack(p, NULL);
+		show_stack(p, addr);
 	}
+
+exit:
 	console_loglevel = old_lvl;
 	kdb_trap_printk--;
 }
-- 
2.22.0.770.g0f2c4a37fd-goog

Re: [PATCH v2] kdb: Fix stack crawling on 'running' CPUs that aren't the master

[Doug Anderson]

Jason / Daniel,

On Wed, Jul 31, 2019 at 11:38 AM Douglas Anderson <dianders@chromium.org> wrote:
>
> In kdb when you do 'btc' (back trace on CPU) it doesn't necessarily
> give you the right info.  Specifically on many architectures
> (including arm64, where I tested) you can't dump the stack of a
> "running" process that isn't the process running on the current CPU.
> This can be seen by this:
>
>  echo SOFTLOCKUP > /sys/kernel/debug/provoke-crash/DIRECT
>  # wait 2 seconds
>  <sysrq>g
>
> Here's what I see now on rk3399-gru-kevin.  I see the stack crawl for
> the CPU that handled the sysrq but everything else just shows me stuck
> in __switch_to() which is bogus:
>
> ======
>
> [0]kdb> btc
> btc: cpu status: Currently on cpu 0
> Available cpus: 0, 1-3(I), 4, 5(I)
> Stack traceback for pid 0
> 0xffffff801101a9c0        0        0  1    0   R  0xffffff801101b3b0 *swapper/0
> Call trace:
>  dump_backtrace+0x0/0x138
>  ...
>  kgdb_compiled_brk_fn+0x34/0x44
>  ...
>  sysrq_handle_dbg+0x34/0x5c
> Stack traceback for pid 0
> 0xffffffc0f175a040        0        0  1    1   I  0xffffffc0f175aa30  swapper/1
> Call trace:
>  __switch_to+0x1e4/0x240
>  0xffffffc0f65616c0
> Stack traceback for pid 0
> 0xffffffc0f175d040        0        0  1    2   I  0xffffffc0f175da30  swapper/2
> Call trace:
>  __switch_to+0x1e4/0x240
>  0xffffffc0f65806c0
> Stack traceback for pid 0
> 0xffffffc0f175b040        0        0  1    3   I  0xffffffc0f175ba30  swapper/3
> Call trace:
>  __switch_to+0x1e4/0x240
>  0xffffffc0f659f6c0
> Stack traceback for pid 1474
> 0xffffffc0dde8b040     1474      727  1    4   R  0xffffffc0dde8ba30  bash
> Call trace:
>  __switch_to+0x1e4/0x240
>  __schedule+0x464/0x618
>  0xffffffc0dde8b040
> Stack traceback for pid 0
> 0xffffffc0f17b0040        0        0  1    5   I  0xffffffc0f17b0a30  swapper/5
> Call trace:
>  __switch_to+0x1e4/0x240
>  0xffffffc0f65dd6c0
>
> ===
>
> The problem is that 'btc' eventually boils down to
>   show_stack(task_struct, NULL);
>
> ...and show_stack() doesn't work for "running" CPUs because their
> registers haven't been stashed.
>
> On x86 things might work better (I haven't tested) because kdb has a
> special case for x86 in kdb_show_stack() where it passes the stack
> pointer to show_stack().  This wouldn't work on arm64 where the stack
> crawling function seems needs the "fp" and "pc", not the "sp" which is
> presumably why arm64's show_stack() function totally ignores the "sp"
> parameter.
>
> NOTE: we _can_ get a good stack dump for all the cpus if we manually
> switch each one to the kdb master and do a back trace.  AKA:
>   cpu 4
>   bt
> ...will give the expected trace.  That's because now arm64's
> dump_backtrace will now see that "tsk == current" and go through a
> different path.
>
> In this patch I fix the problems by catching a request to stack crawl
> a task that's running on a CPU and then I ask that CPU to do the stack
> crawl.
>
> NOTE: this will (presumably) change what stack crawls are printed for
> x86 machines.  Now kdb functions will show up in the stack crawl.
> Presumably this is OK but if it's not we can go back and add a special
> case for x86 again.
>
> Signed-off-by: Douglas Anderson <dianders@chromium.org>
> ---
>
> Changes in v2:
> - Totally new approach; now arch agnostic.
>
>  kernel/debug/debug_core.c |  5 +++++
>  kernel/debug/debug_core.h |  1 +
>  kernel/debug/kdb/kdb_bt.c | 44 ++++++++++++++++++++++++++++++---------
>  3 files changed, 40 insertions(+), 10 deletions(-)

Did either of you have thoughts on this patch?

-Doug

Re: [PATCH v2] kdb: Fix stack crawling on 'running' CPUs that aren't the master

[Daniel Thompson]

On Mon, Aug 26, 2019 at 03:25:43PM -0700, Doug Anderson wrote:
> Jason / Daniel,
> 
> On Wed, Jul 31, 2019 at 11:38 AM Douglas Anderson <dianders@chromium.org> wrote:
> >
> > In kdb when you do 'btc' (back trace on CPU) it doesn't necessarily
> > give you the right info.  Specifically on many architectures
> > (including arm64, where I tested) you can't dump the stack of a
> > "running" process that isn't the process running on the current CPU.
> > This can be seen by this:
> >
> >  echo SOFTLOCKUP > /sys/kernel/debug/provoke-crash/DIRECT
> >  # wait 2 seconds
> >  <sysrq>g
> >
> > Here's what I see now on rk3399-gru-kevin.  I see the stack crawl for
> > the CPU that handled the sysrq but everything else just shows me stuck
> > in __switch_to() which is bogus:
> >
> > ======
> >
> > [0]kdb> btc
> > btc: cpu status: Currently on cpu 0
> > Available cpus: 0, 1-3(I), 4, 5(I)
> > Stack traceback for pid 0
> > 0xffffff801101a9c0        0        0  1    0   R  0xffffff801101b3b0 *swapper/0
> > Call trace:
> >  dump_backtrace+0x0/0x138
> >  ...
> >  kgdb_compiled_brk_fn+0x34/0x44
> >  ...
> >  sysrq_handle_dbg+0x34/0x5c
> > Stack traceback for pid 0
> > 0xffffffc0f175a040        0        0  1    1   I  0xffffffc0f175aa30  swapper/1
> > Call trace:
> >  __switch_to+0x1e4/0x240
> >  0xffffffc0f65616c0
> > Stack traceback for pid 0
> > 0xffffffc0f175d040        0        0  1    2   I  0xffffffc0f175da30  swapper/2
> > Call trace:
> >  __switch_to+0x1e4/0x240
> >  0xffffffc0f65806c0
> > Stack traceback for pid 0
> > 0xffffffc0f175b040        0        0  1    3   I  0xffffffc0f175ba30  swapper/3
> > Call trace:
> >  __switch_to+0x1e4/0x240
> >  0xffffffc0f659f6c0
> > Stack traceback for pid 1474
> > 0xffffffc0dde8b040     1474      727  1    4   R  0xffffffc0dde8ba30  bash
> > Call trace:
> >  __switch_to+0x1e4/0x240
> >  __schedule+0x464/0x618
> >  0xffffffc0dde8b040
> > Stack traceback for pid 0
> > 0xffffffc0f17b0040        0        0  1    5   I  0xffffffc0f17b0a30  swapper/5
> > Call trace:
> >  __switch_to+0x1e4/0x240
> >  0xffffffc0f65dd6c0
> >
> > ===
> >
> > The problem is that 'btc' eventually boils down to
> >   show_stack(task_struct, NULL);
> >
> > ...and show_stack() doesn't work for "running" CPUs because their
> > registers haven't been stashed.
> >
> > On x86 things might work better (I haven't tested) because kdb has a
> > special case for x86 in kdb_show_stack() where it passes the stack
> > pointer to show_stack().  This wouldn't work on arm64 where the stack
> > crawling function seems needs the "fp" and "pc", not the "sp" which is
> > presumably why arm64's show_stack() function totally ignores the "sp"
> > parameter.
> >
> > NOTE: we _can_ get a good stack dump for all the cpus if we manually
> > switch each one to the kdb master and do a back trace.  AKA:
> >   cpu 4
> >   bt
> > ...will give the expected trace.  That's because now arm64's
> > dump_backtrace will now see that "tsk == current" and go through a
> > different path.
> >
> > In this patch I fix the problems by catching a request to stack crawl
> > a task that's running on a CPU and then I ask that CPU to do the stack
> > crawl.
> >
> > NOTE: this will (presumably) change what stack crawls are printed for
> > x86 machines.  Now kdb functions will show up in the stack crawl.
> > Presumably this is OK but if it's not we can go back and add a special
> > case for x86 again.
> >
> > Signed-off-by: Douglas Anderson <dianders@chromium.org>
> > ---
> >
> > Changes in v2:
> > - Totally new approach; now arch agnostic.
> >
> >  kernel/debug/debug_core.c |  5 +++++
> >  kernel/debug/debug_core.h |  1 +
> >  kernel/debug/kdb/kdb_bt.c | 44 ++++++++++++++++++++++++++++++---------
> >  3 files changed, 40 insertions(+), 10 deletions(-)
> 
> Did either of you have thoughts on this patch?

Hi Doug

Sorry about this. It got backlogged during a recent holiday... it's still
on the list.

I took a quick look a week or so ago but at this point I haven't yet
tested out the behaviour on x86 and I wanted to do a closer review to
check I am happy with the barriering.


Daniel.

> 
> -Doug

Re: [PATCH v2] kdb: Fix stack crawling on 'running' CPUs that aren't the master

[Daniel Thompson]

On Wed, Jul 31, 2019 at 11:37:32AM -0700, Douglas Anderson wrote:
> In kdb when you do 'btc' (back trace on CPU) it doesn't necessarily
> give you the right info.  Specifically on many architectures
> (including arm64, where I tested) you can't dump the stack of a
> "running" process that isn't the process running on the current CPU.
> This can be seen by this:
> 
>  echo SOFTLOCKUP > /sys/kernel/debug/provoke-crash/DIRECT
>  # wait 2 seconds
>  <sysrq>g
> 
> Here's what I see now on rk3399-gru-kevin.  I see the stack crawl for
> the CPU that handled the sysrq but everything else just shows me stuck
> in __switch_to() which is bogus:
> 
> ======
> 
> [0]kdb> btc
> btc: cpu status: Currently on cpu 0
> Available cpus: 0, 1-3(I), 4, 5(I)
> Stack traceback for pid 0
> 0xffffff801101a9c0        0        0  1    0   R  0xffffff801101b3b0 *swapper/0
> Call trace:
>  dump_backtrace+0x0/0x138
>  ...
>  kgdb_compiled_brk_fn+0x34/0x44
>  ...
>  sysrq_handle_dbg+0x34/0x5c
> Stack traceback for pid 0
> 0xffffffc0f175a040        0        0  1    1   I  0xffffffc0f175aa30  swapper/1
> Call trace:
>  __switch_to+0x1e4/0x240
>  0xffffffc0f65616c0
> Stack traceback for pid 0
> 0xffffffc0f175d040        0        0  1    2   I  0xffffffc0f175da30  swapper/2
> Call trace:
>  __switch_to+0x1e4/0x240
>  0xffffffc0f65806c0
> Stack traceback for pid 0
> 0xffffffc0f175b040        0        0  1    3   I  0xffffffc0f175ba30  swapper/3
> Call trace:
>  __switch_to+0x1e4/0x240
>  0xffffffc0f659f6c0
> Stack traceback for pid 1474
> 0xffffffc0dde8b040     1474      727  1    4   R  0xffffffc0dde8ba30  bash
> Call trace:
>  __switch_to+0x1e4/0x240
>  __schedule+0x464/0x618
>  0xffffffc0dde8b040
> Stack traceback for pid 0
> 0xffffffc0f17b0040        0        0  1    5   I  0xffffffc0f17b0a30  swapper/5
> Call trace:
>  __switch_to+0x1e4/0x240
>  0xffffffc0f65dd6c0
> 
> ===
> 
> The problem is that 'btc' eventually boils down to
>   show_stack(task_struct, NULL);
> 
> ...and show_stack() doesn't work for "running" CPUs because their
> registers haven't been stashed.
> 
> On x86 things might work better (I haven't tested) because kdb has a
> special case for x86 in kdb_show_stack() where it passes the stack
> pointer to show_stack().  This wouldn't work on arm64 where the stack
> crawling function seems needs the "fp" and "pc", not the "sp" which is
> presumably why arm64's show_stack() function totally ignores the "sp"
> parameter.
> 
> NOTE: we _can_ get a good stack dump for all the cpus if we manually
> switch each one to the kdb master and do a back trace.  AKA:
>   cpu 4
>   bt
> ...will give the expected trace.  That's because now arm64's
> dump_backtrace will now see that "tsk == current" and go through a
> different path.
> 
> In this patch I fix the problems by catching a request to stack crawl
> a task that's running on a CPU and then I ask that CPU to do the stack
> crawl.
> 
> NOTE: this will (presumably) change what stack crawls are printed for
> x86 machines.  Now kdb functions will show up in the stack crawl.
> Presumably this is OK but if it's not we can go back and add a special
> case for x86 again.
> 
> Signed-off-by: Douglas Anderson <dianders@chromium.org>

I think this approach can be made work but there are problems as things
exist today, see below.


> ---
> 
> Changes in v2:
> - Totally new approach; now arch agnostic.
> 
>  kernel/debug/debug_core.c |  5 +++++
>  kernel/debug/debug_core.h |  1 +
>  kernel/debug/kdb/kdb_bt.c | 44 ++++++++++++++++++++++++++++++---------
>  3 files changed, 40 insertions(+), 10 deletions(-)
> 
> diff --git a/kernel/debug/debug_core.c b/kernel/debug/debug_core.c
> index 5cc608de6883..a89c72714fe6 100644
> --- a/kernel/debug/debug_core.c
> +++ b/kernel/debug/debug_core.c
> @@ -92,6 +92,8 @@ static int kgdb_use_con;
>  bool dbg_is_early = true;
>  /* Next cpu to become the master debug core */
>  int dbg_switch_cpu;
> +/* cpu number of slave we request a stack crawl of */
> +int dbg_slave_dumpstack_cpu = -1;
>  
>  /* Use kdb or gdbserver mode */
>  int dbg_kdb_mode = 1;
> @@ -580,6 +582,9 @@ static int kgdb_cpu_enter(struct kgdb_state *ks, struct pt_regs *regs,
>  				atomic_xchg(&kgdb_active, cpu);
>  				break;
>  			}
> +		} else if (dbg_slave_dumpstack_cpu == cpu) {

Couldn't this be encoded in the exception state?


> +			dump_stack();
> +			dbg_slave_dumpstack_cpu = -1;

>  		} else if (kgdb_info[cpu].exception_state & DCPU_IS_SLAVE) {
>  			if (!raw_spin_is_locked(&dbg_slave_lock))
>  				goto return_normal;
> diff --git a/kernel/debug/debug_core.h b/kernel/debug/debug_core.h
> index b4a7c326d546..dca74d5caef2 100644
> --- a/kernel/debug/debug_core.h
> +++ b/kernel/debug/debug_core.h
> @@ -62,6 +62,7 @@ extern int dbg_io_get_char(void);
>  /* Switch from one cpu to another */
>  #define DBG_SWITCH_CPU_EVENT -123456
>  extern int dbg_switch_cpu;
> +extern int dbg_slave_dumpstack_cpu;
>  
>  /* gdbstub interface functions */
>  extern int gdb_serial_stub(struct kgdb_state *ks);
> diff --git a/kernel/debug/kdb/kdb_bt.c b/kernel/debug/kdb/kdb_bt.c
> index 7e2379aa0a1e..10095ae05826 100644
> --- a/kernel/debug/kdb/kdb_bt.c
> +++ b/kernel/debug/kdb/kdb_bt.c
> @@ -10,6 +10,7 @@
>   */
>  
>  #include <linux/ctype.h>
> +#include <linux/delay.h>
>  #include <linux/string.h>
>  #include <linux/kernel.h>
>  #include <linux/sched/signal.h>
> @@ -22,20 +23,43 @@
>  static void kdb_show_stack(struct task_struct *p, void *addr)
>  {
>  	int old_lvl = console_loglevel;
> +	int time_left;
> +	int cpu;
> +
>  	console_loglevel = CONSOLE_LOGLEVEL_MOTORMOUTH;
>  	kdb_trap_printk++;
> -	kdb_set_current_task(p);
> -	if (addr) {
> -		show_stack((struct task_struct *)p, addr);
> -	} else if (kdb_current_regs) {
> -#ifdef CONFIG_X86
> -		show_stack(p, &kdb_current_regs->sp);
> -#else
> -		show_stack(p, NULL);
> -#endif
> +
> +	if (!addr && kdb_task_has_cpu(p)) {
> +		cpu = kdb_process_cpu(p);
> +
> +		if (cpu == raw_smp_processor_id()) {
> +			dump_stack();
> +			goto exit;

This goto is not for error recovery but looks like it is. Why can't we
use normal control flow here (extracting the remote stack dump logic
into a seperate function if the right margin is getting too close)?

In fact to be honest a function call would be useful anyway since I'd
rather have all the resulting horror in a single file (debug_core.c).


> +		}
> +
> +		/*
> +		 * In general architectures don't support dumping the stack
> +		 * of a "running" process that's not the current one so if
> +		 * we want to dump the stack of a running process that's not
> +		 * the master then we'll set a global letting the slave
> +		 * (which should be looping) know to dump its own stack.
> +		 */
> +		dbg_slave_dumpstack_cpu = cpu;
> +		for (time_left = MSEC_PER_SEC; time_left; time_left--) {
> +			udelay(1000);
> +			if (dbg_slave_dumpstack_cpu == -1)
> +				break;
> +		}

This timeout does not interact correctly with the pager (the timer does
not get reset when we sit in the pager loop waiting for user to tell us
to continue).


> +		if (dbg_slave_dumpstack_cpu != -1) {
> +			kdb_printf("ERROR: Timeout dumping CPU %d stack\n",
> +				   cpu);
> +			dbg_slave_dumpstack_cpu = -1;
> +		}
>  	} else {
> -		show_stack(p, NULL);
> +		show_stack(p, addr);
>  	}
> +
> +exit:
>  	console_loglevel = old_lvl;
>  	kdb_trap_printk--;
>  }
> -- 
> 2.22.0.770.g0f2c4a37fd-goog

Re: [PATCH v2] kdb: Fix stack crawling on 'running' CPUs that aren't the master

[Doug Anderson]

Hi,

On Fri, Aug 30, 2019 at 7:52 AM Daniel Thompson
<daniel.thompson@linaro.org> wrote:
>
> On Wed, Jul 31, 2019 at 11:37:32AM -0700, Douglas Anderson wrote:
> > In kdb when you do 'btc' (back trace on CPU) it doesn't necessarily
> > give you the right info.  Specifically on many architectures
> > (including arm64, where I tested) you can't dump the stack of a
> > "running" process that isn't the process running on the current CPU.
> > This can be seen by this:
> >
> >  echo SOFTLOCKUP > /sys/kernel/debug/provoke-crash/DIRECT
> >  # wait 2 seconds
> >  <sysrq>g
> >
> > Here's what I see now on rk3399-gru-kevin.  I see the stack crawl for
> > the CPU that handled the sysrq but everything else just shows me stuck
> > in __switch_to() which is bogus:
> >
> > ======
> >
> > [0]kdb> btc
> > btc: cpu status: Currently on cpu 0
> > Available cpus: 0, 1-3(I), 4, 5(I)
> > Stack traceback for pid 0
> > 0xffffff801101a9c0        0        0  1    0   R  0xffffff801101b3b0 *swapper/0
> > Call trace:
> >  dump_backtrace+0x0/0x138
> >  ...
> >  kgdb_compiled_brk_fn+0x34/0x44
> >  ...
> >  sysrq_handle_dbg+0x34/0x5c
> > Stack traceback for pid 0
> > 0xffffffc0f175a040        0        0  1    1   I  0xffffffc0f175aa30  swapper/1
> > Call trace:
> >  __switch_to+0x1e4/0x240
> >  0xffffffc0f65616c0
> > Stack traceback for pid 0
> > 0xffffffc0f175d040        0        0  1    2   I  0xffffffc0f175da30  swapper/2
> > Call trace:
> >  __switch_to+0x1e4/0x240
> >  0xffffffc0f65806c0
> > Stack traceback for pid 0
> > 0xffffffc0f175b040        0        0  1    3   I  0xffffffc0f175ba30  swapper/3
> > Call trace:
> >  __switch_to+0x1e4/0x240
> >  0xffffffc0f659f6c0
> > Stack traceback for pid 1474
> > 0xffffffc0dde8b040     1474      727  1    4   R  0xffffffc0dde8ba30  bash
> > Call trace:
> >  __switch_to+0x1e4/0x240
> >  __schedule+0x464/0x618
> >  0xffffffc0dde8b040
> > Stack traceback for pid 0
> > 0xffffffc0f17b0040        0        0  1    5   I  0xffffffc0f17b0a30  swapper/5
> > Call trace:
> >  __switch_to+0x1e4/0x240
> >  0xffffffc0f65dd6c0
> >
> > ===
> >
> > The problem is that 'btc' eventually boils down to
> >   show_stack(task_struct, NULL);
> >
> > ...and show_stack() doesn't work for "running" CPUs because their
> > registers haven't been stashed.
> >
> > On x86 things might work better (I haven't tested) because kdb has a
> > special case for x86 in kdb_show_stack() where it passes the stack
> > pointer to show_stack().  This wouldn't work on arm64 where the stack
> > crawling function seems needs the "fp" and "pc", not the "sp" which is
> > presumably why arm64's show_stack() function totally ignores the "sp"
> > parameter.
> >
> > NOTE: we _can_ get a good stack dump for all the cpus if we manually
> > switch each one to the kdb master and do a back trace.  AKA:
> >   cpu 4
> >   bt
> > ...will give the expected trace.  That's because now arm64's
> > dump_backtrace will now see that "tsk == current" and go through a
> > different path.
> >
> > In this patch I fix the problems by catching a request to stack crawl
> > a task that's running on a CPU and then I ask that CPU to do the stack
> > crawl.
> >
> > NOTE: this will (presumably) change what stack crawls are printed for
> > x86 machines.  Now kdb functions will show up in the stack crawl.
> > Presumably this is OK but if it's not we can go back and add a special
> > case for x86 again.
> >
> > Signed-off-by: Douglas Anderson <dianders@chromium.org>
>
> I think this approach can be made work but there are problems as things
> exist today, see below.
>
>
> > ---
> >
> > Changes in v2:
> > - Totally new approach; now arch agnostic.
> >
> >  kernel/debug/debug_core.c |  5 +++++
> >  kernel/debug/debug_core.h |  1 +
> >  kernel/debug/kdb/kdb_bt.c | 44 ++++++++++++++++++++++++++++++---------
> >  3 files changed, 40 insertions(+), 10 deletions(-)
> >
> > diff --git a/kernel/debug/debug_core.c b/kernel/debug/debug_core.c
> > index 5cc608de6883..a89c72714fe6 100644
> > --- a/kernel/debug/debug_core.c
> > +++ b/kernel/debug/debug_core.c
> > @@ -92,6 +92,8 @@ static int kgdb_use_con;
> >  bool dbg_is_early = true;
> >  /* Next cpu to become the master debug core */
> >  int dbg_switch_cpu;
> > +/* cpu number of slave we request a stack crawl of */
> > +int dbg_slave_dumpstack_cpu = -1;
> >
> >  /* Use kdb or gdbserver mode */
> >  int dbg_kdb_mode = 1;
> > @@ -580,6 +582,9 @@ static int kgdb_cpu_enter(struct kgdb_state *ks, struct pt_regs *regs,
> >                               atomic_xchg(&kgdb_active, cpu);
> >                               break;
> >                       }
> > +             } else if (dbg_slave_dumpstack_cpu == cpu) {
>
> Couldn't this be encoded in the exception state?

Yup, but it requires exporting the exception state from debug_core.c
(or exporting a function that sets this).  Ah, but below you said you
wanted the whole stack crawling on a CPU moved to debug_core.c, so
done.


> > +                     dump_stack();
> > +                     dbg_slave_dumpstack_cpu = -1;
>
> >               } else if (kgdb_info[cpu].exception_state & DCPU_IS_SLAVE) {
> >                       if (!raw_spin_is_locked(&dbg_slave_lock))
> >                               goto return_normal;
> > diff --git a/kernel/debug/debug_core.h b/kernel/debug/debug_core.h
> > index b4a7c326d546..dca74d5caef2 100644
> > --- a/kernel/debug/debug_core.h
> > +++ b/kernel/debug/debug_core.h
> > @@ -62,6 +62,7 @@ extern int dbg_io_get_char(void);
> >  /* Switch from one cpu to another */
> >  #define DBG_SWITCH_CPU_EVENT -123456
> >  extern int dbg_switch_cpu;
> > +extern int dbg_slave_dumpstack_cpu;
> >
> >  /* gdbstub interface functions */
> >  extern int gdb_serial_stub(struct kgdb_state *ks);
> > diff --git a/kernel/debug/kdb/kdb_bt.c b/kernel/debug/kdb/kdb_bt.c
> > index 7e2379aa0a1e..10095ae05826 100644
> > --- a/kernel/debug/kdb/kdb_bt.c
> > +++ b/kernel/debug/kdb/kdb_bt.c
> > @@ -10,6 +10,7 @@
> >   */
> >
> >  #include <linux/ctype.h>
> > +#include <linux/delay.h>
> >  #include <linux/string.h>
> >  #include <linux/kernel.h>
> >  #include <linux/sched/signal.h>
> > @@ -22,20 +23,43 @@
> >  static void kdb_show_stack(struct task_struct *p, void *addr)
> >  {
> >       int old_lvl = console_loglevel;
> > +     int time_left;
> > +     int cpu;
> > +
> >       console_loglevel = CONSOLE_LOGLEVEL_MOTORMOUTH;
> >       kdb_trap_printk++;
> > -     kdb_set_current_task(p);
> > -     if (addr) {
> > -             show_stack((struct task_struct *)p, addr);
> > -     } else if (kdb_current_regs) {
> > -#ifdef CONFIG_X86
> > -             show_stack(p, &kdb_current_regs->sp);
> > -#else
> > -             show_stack(p, NULL);
> > -#endif
> > +
> > +     if (!addr && kdb_task_has_cpu(p)) {
> > +             cpu = kdb_process_cpu(p);
> > +
> > +             if (cpu == raw_smp_processor_id()) {
> > +                     dump_stack();
> > +                     goto exit;
>
> This goto is not for error recovery but looks like it is. Why can't we
> use normal control flow here (extracting the remote stack dump logic
> into a seperate function if the right margin is getting too close)?
>
> In fact to be honest a function call would be useful anyway since I'd
> rather have all the resulting horror in a single file (debug_core.c).

Sure.  Done.


> > +             }
> > +
> > +             /*
> > +              * In general architectures don't support dumping the stack
> > +              * of a "running" process that's not the current one so if
> > +              * we want to dump the stack of a running process that's not
> > +              * the master then we'll set a global letting the slave
> > +              * (which should be looping) know to dump its own stack.
> > +              */
> > +             dbg_slave_dumpstack_cpu = cpu;
> > +             for (time_left = MSEC_PER_SEC; time_left; time_left--) {
> > +                     udelay(1000);
> > +                     if (dbg_slave_dumpstack_cpu == -1)
> > +                             break;
> > +             }
>
> This timeout does not interact correctly with the pager (the timer does
> not get reset when we sit in the pager loop waiting for user to tell us
> to continue).

Nice catch, thanks.  Probably the easiest thing to do is to get rid of
this timeout but put in a check to make sure that the CPU has the
"IN_SLAVE" flag set.  This was important since you otherwise could get
into this code path by doing "ps" to see what process was running on a
non-rounded-up CPU and then "btp <pid>".  v3 should handle this
without the timeout.


-Doug