Groups | Search | Server Info | Keyboard shortcuts | Login | Register [http] [https] [nntp] [nntps]

Groups > linux.kernel > #1448171 > unrolled thread

[PATCH 00/19] x86/dumpstack: rewrite x86 stack dump code

Back to article view | Back to linux.kernel

Contents

  [PATCH 00/19] x86/dumpstack: rewrite x86 stack dump code Josh Poimboeuf <jpoimboe@redhat.com> - 2016-07-21 23:30 +0200
    [PATCH 05/19] x86/dumpstack: fix function graph tracing stack dump reliability issues Josh Poimboeuf <jpoimboe@redhat.com> - 2016-07-21 23:30 +0200
    [PATCH 04/19] x86/dumpstack: make printk_stack_address() more generally useful Josh Poimboeuf <jpoimboe@redhat.com> - 2016-07-21 23:30 +0200
    [PATCH 18/19] x86/dumpstack: print stack identifier on its own line Josh Poimboeuf <jpoimboe@redhat.com> - 2016-07-21 23:30 +0200
    [PATCH 13/19] x86/stacktrace: convert save_stack_trace_*() to the new unwinder Josh Poimboeuf <jpoimboe@redhat.com> - 2016-07-21 23:30 +0200
    [PATCH 19/19] x86/dumpstack: print any pt_regs found on the stack Josh Poimboeuf <jpoimboe@redhat.com> - 2016-07-21 23:30 +0200
      Re: [PATCH 19/19] x86/dumpstack: print any pt_regs found on the stack Andy Lutomirski <luto@amacapital.net> - 2016-07-22 00:40 +0200
        Re: [PATCH 19/19] x86/dumpstack: print any pt_regs found on the stack Josh Poimboeuf <jpoimboe@redhat.com> - 2016-07-22 05:40 +0200
          Re: [PATCH 19/19] x86/dumpstack: print any pt_regs found on the stack Andy Lutomirski <luto@amacapital.net> - 2016-07-22 07:20 +0200
            Re: [PATCH 19/19] x86/dumpstack: print any pt_regs found on the stack Josh Poimboeuf <jpoimboe@redhat.com> - 2016-07-22 18:00 +0200
              Re: [PATCH 19/19] x86/dumpstack: print any pt_regs found on the stack Andy Lutomirski <luto@amacapital.net> - 2016-07-22 23:50 +0200
                Re: [PATCH 19/19] x86/dumpstack: print any pt_regs found on the stack Josh Poimboeuf <jpoimboe@redhat.com> - 2016-07-23 00:30 +0200
                  Re: [PATCH 19/19] x86/dumpstack: print any pt_regs found on the stack Andy Lutomirski <luto@amacapital.net> - 2016-07-23 01:20 +0200
                    Re: [PATCH 19/19] x86/dumpstack: print any pt_regs found on the stack Andy Lutomirski <luto@amacapital.net> - 2016-07-23 01:40 +0200
                      Re: [PATCH 19/19] x86/dumpstack: print any pt_regs found on the stack Josh Poimboeuf <jpoimboe@redhat.com> - 2016-07-23 02:10 +0200
                    Re: [PATCH 19/19] x86/dumpstack: print any pt_regs found on the stack Josh Poimboeuf <jpoimboe@redhat.com> - 2016-07-23 01:40 +0200
    [PATCH 08/19] x86/dumpstack: don't disable preemption in show_stack_log_lvl() and dump_trace() Josh Poimboeuf <jpoimboe@redhat.com> - 2016-07-21 23:30 +0200
    [PATCH 14/19] oprofile/x86: convert x86_backtrace() to the new unwinder Josh Poimboeuf <jpoimboe@redhat.com> - 2016-07-21 23:30 +0200
    [PATCH 06/19] x86/dumpstack: remove extra brackets around "EOE" Josh Poimboeuf <jpoimboe@redhat.com> - 2016-07-21 23:30 +0200
    [PATCH 10/19] x86/dumpstack: add get_stack_info() interface Josh Poimboeuf <jpoimboe@redhat.com> - 2016-07-21 23:30 +0200
      Re: [PATCH 10/19] x86/dumpstack: add get_stack_info() interface Andy Lutomirski <luto@amacapital.net> - 2016-07-23 01:30 +0200
        Re: [PATCH 10/19] x86/dumpstack: add get_stack_info() interface Andy Lutomirski <luto@amacapital.net> - 2016-07-23 02:00 +0200
          Re: [PATCH 10/19] x86/dumpstack: add get_stack_info() interface Josh Poimboeuf <jpoimboe@redhat.com> - 2016-07-23 15:10 +0200
        Re: [PATCH 10/19] x86/dumpstack: add get_stack_info() interface Josh Poimboeuf <jpoimboe@redhat.com> - 2016-07-23 02:00 +0200
          Re: [PATCH 10/19] x86/dumpstack: add get_stack_info() interface Andy Lutomirski <luto@amacapital.net> - 2016-07-23 02:20 +0200
            Re: [PATCH 10/19] x86/dumpstack: add get_stack_info() interface Josh Poimboeuf <jpoimboe@redhat.com> - 2016-07-23 16:10 +0200
    [PATCH 01/19] x86/dumpstack: remove show_trace() Josh Poimboeuf <jpoimboe@redhat.com> - 2016-07-21 23:30 +0200
      Re: [PATCH 01/19] x86/dumpstack: remove show_trace() Andy Lutomirski <luto@amacapital.net> - 2016-07-22 00:00 +0200
    [PATCH 12/19] perf/x86: convert perf_callchain_kernel() to the new unwinder Josh Poimboeuf <jpoimboe@redhat.com> - 2016-07-21 23:30 +0200
    [PATCH 02/19] x86/dumpstack: add get_stack_pointer() and get_frame_pointer() Josh Poimboeuf <jpoimboe@redhat.com> - 2016-07-21 23:30 +0200
      Re: [PATCH 02/19] x86/dumpstack: add get_stack_pointer() and get_frame_pointer() Andy Lutomirski <luto@amacapital.net> - 2016-07-22 00:00 +0200
    [PATCH 11/19] x86/dumptrace: add new unwind interface and implementations Josh Poimboeuf <jpoimboe@redhat.com> - 2016-07-21 23:30 +0200
    [PATCH 09/19] x86/dumpstack: simplify in_exception_stack() Josh Poimboeuf <jpoimboe@redhat.com> - 2016-07-21 23:30 +0200
      Re: [PATCH 09/19] x86/dumpstack: simplify in_exception_stack() Andy Lutomirski <luto@amacapital.net> - 2016-07-22 00:10 +0200
    [PATCH 07/19] x86/dumpstack: add IRQ_USABLE_STACK_SIZE define Josh Poimboeuf <jpoimboe@redhat.com> - 2016-07-21 23:30 +0200
      Re: [PATCH 07/19] x86/dumpstack: add IRQ_USABLE_STACK_SIZE define Andy Lutomirski <luto@amacapital.net> - 2016-07-22 00:10 +0200
        Re: [PATCH 07/19] x86/dumpstack: add IRQ_USABLE_STACK_SIZE define Josh Poimboeuf <jpoimboe@redhat.com> - 2016-07-22 03:50 +0200
          Re: [PATCH 07/19] x86/dumpstack: add IRQ_USABLE_STACK_SIZE define Ingo Molnar <mingo@kernel.org> - 2016-07-22 10:30 +0200
    Re: [PATCH 00/19] x86/dumpstack: rewrite x86 stack dump code Linus Torvalds <torvalds@linux-foundation.org> - 2016-07-23 02:30 +0200
      Re: [PATCH 00/19] x86/dumpstack: rewrite x86 stack dump code Andy Lutomirski <luto@amacapital.net> - 2016-07-23 02:40 +0200
        Re: [PATCH 00/19] x86/dumpstack: rewrite x86 stack dump code Josh Poimboeuf <jpoimboe@redhat.com> - 2016-07-23 07:40 +0200
          Re: [PATCH 00/19] x86/dumpstack: rewrite x86 stack dump code Linus Torvalds <torvalds@linux-foundation.org> - 2016-07-23 07:50 +0200
            Re: [PATCH 00/19] x86/dumpstack: rewrite x86 stack dump code Josh Poimboeuf <jpoimboe@redhat.com> - 2016-07-23 15:00 +0200

Page 1 of 3  [1] 2 3  Next page →

#1448171 — [PATCH 00/19] x86/dumpstack: rewrite x86 stack dump code

The x86 stack dump code is a bit of a mess.  dump_trace() uses
callbacks, and each user of it seems to have slightly different
requirements, so there are several slightly different callbacks floating
around.

Also there are some upcoming features which will require more changes to
the stack dump code: reliable stack detection for live patching,
hardened user copy, and the DWARF unwinder.  Each of those features
would at least need more callbacks and/or callback interfaces, resulting
in a much bigger mess than what we have today.

Before doing all that, we should try to clean things up and replace
dump_trace() with something cleaner and more flexible.

The new unwinder is a simple state machine which was heavily inspired by
a suggestion from Andy Lutomirski:

  https://lkml.kernel.org/r/CALCETrUbNTqaM2LRyXGRx=kVLRPeY5A3Pc6k4TtQxF320rUT=w@mail.gmail.com

It's also similar to the libunwind API:

  http://www.nongnu.org/libunwind/man/libunwind(3).html

Some if its advantages:

- simplicity: no more callback sprawl and less code duplication.

- flexibility: allows the caller to stop and inspect the stack state at
  each step in the unwinding process.

- modularity: the unwinder code, console stack dump code, and stack
  metadata analysis code are all better separated so that changing one
  of them shouldn't have much of an impact on any of the others.


Josh Poimboeuf (19):
  x86/dumpstack: remove show_trace()
  x86/dumpstack: add get_stack_pointer() and get_frame_pointer()
  x86/dumpstack: remove unnecessary stack pointer arguments
  x86/dumpstack: make printk_stack_address() more generally useful
  x86/dumpstack: fix function graph tracing stack dump reliability
    issues
  x86/dumpstack: remove extra brackets around "EOE"
  x86/dumpstack: add IRQ_USABLE_STACK_SIZE define
  x86/dumpstack: don't disable preemption in show_stack_log_lvl() and
    dump_trace()
  x86/dumpstack: simplify in_exception_stack()
  x86/dumpstack: add get_stack_info() interface
  x86/dumptrace: add new unwind interface and implementations
  perf/x86: convert perf_callchain_kernel() to the new unwinder
  x86/stacktrace: convert save_stack_trace_*() to the new unwinder
  oprofile/x86: convert x86_backtrace() to the new unwinder
  x86/dumpstack: convert show_trace_log_lvl() to the new unwinder
  x86/dumpstack: remove dump_trace()
  x86/entry/dumpstack: encode pt_regs pointer in frame pointer
  x86/dumpstack: print stack identifier on its own line
  x86/dumpstack: print any pt_regs found on the stack

 arch/x86/entry/calling.h             |  21 +++
 arch/x86/entry/entry_64.S            |   7 +-
 arch/x86/events/core.c               |  32 +---
 arch/x86/include/asm/kdebug.h        |   2 -
 arch/x86/include/asm/page_64_types.h |  19 ++-
 arch/x86/include/asm/stacktrace.h    | 127 +++++++-------
 arch/x86/include/asm/unwind.h        |  91 ++++++++++
 arch/x86/kernel/Makefile             |   6 +
 arch/x86/kernel/cpu/common.c         |   2 +-
 arch/x86/kernel/dumpstack.c          | 269 +++++++++++++++---------------
 arch/x86/kernel/dumpstack_32.c       | 120 +++++++-------
 arch/x86/kernel/dumpstack_64.c       | 310 ++++++++++-------------------------
 arch/x86/kernel/setup_percpu.c       |   2 +-
 arch/x86/kernel/stacktrace.c         |  74 ++++-----
 arch/x86/kernel/unwind_frame.c       | 133 +++++++++++++++
 arch/x86/kernel/unwind_guess.c       |  40 +++++
 arch/x86/oprofile/backtrace.c        |  44 +++--
 17 files changed, 713 insertions(+), 586 deletions(-)
 create mode 100644 arch/x86/include/asm/unwind.h
 create mode 100644 arch/x86/kernel/unwind_frame.c
 create mode 100644 arch/x86/kernel/unwind_guess.c

-- 
2.7.4

[toc] | [next] | [standalone]

#1448173 — [PATCH 05/19] x86/dumpstack: fix function graph tracing stack dump reliability issues

When function graph tracing is enabled for a function, its return
address on the stack is replaced with the address of an ftrace handler
(return_to_handler).  When dumping the stack of a task with graph
tracing enabled, there are some subtle bugs:

- The fake return_to_handler() address can be reported as reliable.
  Instead, because it's not the real caller, it should be considered
  unreliable.

- In print_context_stack(), the real caller's return address is always
  reported as reliable, even if the return_to_handler() address wasn't
  referred to by a frame pointer.

In addition to fixing these bugs, convert print_ftrace_graph_addr() to a
more generic function which can be used outside of dump_trace()
callbacks.

Signed-off-by: Josh Poimboeuf <jpoimboe@redhat.com>
---
 arch/x86/include/asm/stacktrace.h | 13 ++++++++++
 arch/x86/kernel/dumpstack.c       | 50 +++++++++++++++++----------------------
 2 files changed, 35 insertions(+), 28 deletions(-)

diff --git a/arch/x86/include/asm/stacktrace.h b/arch/x86/include/asm/stacktrace.h
index 6f65995..5d3d258 100644
--- a/arch/x86/include/asm/stacktrace.h
+++ b/arch/x86/include/asm/stacktrace.h
@@ -14,6 +14,19 @@ extern int kstack_depth_to_print;
 struct thread_info;
 struct stacktrace_ops;
 
+#ifdef CONFIG_FUNCTION_GRAPH_TRACER
+
+unsigned long
+ftrace_graph_ret_addr(struct task_struct *task, int *idx, unsigned long addr);
+
+#else
+static inline unsigned long
+ftrace_graph_ret_addr(struct task_struct *task, int *idx, unsigned long addr)
+{
+	return addr;
+}
+#endif /* CONFIG_FUNCTION_GRAPH_TRACER */
+
 typedef unsigned long (*walk_stack_t)(struct task_struct *task,
 				      unsigned long *stack,
 				      unsigned long bp,
diff --git a/arch/x86/kernel/dumpstack.c b/arch/x86/kernel/dumpstack.c
index 692eecae..0a8694b 100644
--- a/arch/x86/kernel/dumpstack.c
+++ b/arch/x86/kernel/dumpstack.c
@@ -40,36 +40,25 @@ void printk_address(unsigned long address)
 }
 
 #ifdef CONFIG_FUNCTION_GRAPH_TRACER
-static void
-print_ftrace_graph_addr(unsigned long addr, void *data,
-			const struct stacktrace_ops *ops,
-			struct task_struct *task, int *graph)
+unsigned long
+ftrace_graph_ret_addr(struct task_struct *task, int *idx, unsigned long addr)
 {
-	unsigned long ret_addr;
-	int index;
+	int task_idx;
 
 	if (addr != (unsigned long)return_to_handler)
-		return;
+		return addr;
 
-	index = task->curr_ret_stack;
+	task_idx = task->curr_ret_stack;
 
-	if (!task->ret_stack || index < *graph)
-		return;
+	if (!task->ret_stack || task_idx < *idx)
+		return addr;
 
-	index -= *graph;
-	ret_addr = task->ret_stack[index].ret;
+	task_idx -= *idx;
+	(*idx)++;
 
-	ops->address(data, ret_addr, 1);
-
-	(*graph)++;
+	return task->ret_stack[task_idx].ret;
 }
-#else
-static inline void
-print_ftrace_graph_addr(unsigned long addr, void *data,
-			const struct stacktrace_ops *ops,
-			struct task_struct *task, int *graph)
-{ }
-#endif
+#endif /* CONFIG_FUNCTION_GRAPH_TRACER */
 
 /*
  * x86-64 can have up to three kernel stacks:
@@ -108,18 +97,23 @@ print_context_stack(struct task_struct *task,
 		stack = (unsigned long *)task_stack_page(task);
 
 	while (valid_stack_ptr(task, stack, sizeof(*stack), end)) {
-		unsigned long addr;
+		unsigned long addr = *stack;
 
 		addr = *stack;
 		if (__kernel_text_address(addr)) {
+			int reliable = 0;
+			unsigned long real_addr;
+
 			if ((unsigned long) stack == bp + sizeof(long)) {
-				ops->address(data, addr, 1);
+				reliable = 1;
 				frame = frame->next_frame;
 				bp = (unsigned long) frame;
-			} else {
-				ops->address(data, addr, 0);
 			}
-			print_ftrace_graph_addr(addr, data, ops, task, graph);
+
+			real_addr = ftrace_graph_ret_addr(task, graph, addr);
+			if (addr != real_addr)
+				ops->address(data, addr, 0);
+			ops->address(data, real_addr, reliable);
 		}
 		stack++;
 	}
@@ -142,11 +136,11 @@ print_context_stack_bp(struct task_struct *task,
 		if (!__kernel_text_address(addr))
 			break;
 
+		addr = ftrace_graph_ret_addr(task, graph, addr);
 		if (ops->address(data, addr, 1))
 			break;
 		frame = frame->next_frame;
 		ret_addr = &frame->return_address;
-		print_ftrace_graph_addr(addr, data, ops, task, graph);
 	}
 
 	return (unsigned long)frame;
-- 
2.7.4

[toc] | [prev] | [next] | [standalone]

#1448174 — [PATCH 04/19] x86/dumpstack: make printk_stack_address() more generally useful

Change printk_stack_address() to be useful when called by an unwinder
outside the context of dump_trace().

Specifically:

- printk_stack_address()'s 'data' argument is always used as the log
  level string.  Make that explicit.

- Call touch_nmi_watchdog().

Signed-off-by: Josh Poimboeuf <jpoimboe@redhat.com>
---
 arch/x86/kernel/dumpstack.c | 6 +++---
 1 file changed, 3 insertions(+), 3 deletions(-)

diff --git a/arch/x86/kernel/dumpstack.c b/arch/x86/kernel/dumpstack.c
index 75d21ac..692eecae 100644
--- a/arch/x86/kernel/dumpstack.c
+++ b/arch/x86/kernel/dumpstack.c
@@ -26,10 +26,11 @@ int kstack_depth_to_print = 3 * STACKSLOTS_PER_LINE;
 static int die_counter;
 
 static void printk_stack_address(unsigned long address, int reliable,
-		void *data)
+				 char *log_lvl)
 {
+	touch_nmi_watchdog();
 	printk("%s [<%p>] %s%pB\n",
-		(char *)data, (void *)address, reliable ? "" : "? ",
+		log_lvl, (void *)address, reliable ? "" : "? ",
 		(void *)address);
 }
 
@@ -163,7 +164,6 @@ static int print_trace_stack(void *data, char *name)
  */
 static int print_trace_address(void *data, unsigned long addr, int reliable)
 {
-	touch_nmi_watchdog();
 	printk_stack_address(addr, reliable, data);
 	return 0;
 }
-- 
2.7.4

[toc] | [prev] | [next] | [standalone]

#1448175 — [PATCH 18/19] x86/dumpstack: print stack identifier on its own line

show_trace_log_lvl() prints the stack id (e.g. "<IRQ>") without a
newline so that any stack address printed after it will appear on the
same line.  That causes the first stack address to be vertically
misaligned with the rest, making it visually cluttered and slightly
confusing:

  Call Trace:
   <IRQ> [<ffffffff814431c3>] dump_stack+0x86/0xc3
   [<ffffffff8100828b>] perf_callchain_kernel+0x14b/0x160
   [<ffffffff811e915f>] get_perf_callchain+0x15f/0x2b0
   ...
   <EOI> [<ffffffff8189c6c3>] ? _raw_spin_unlock_irq+0x33/0x60
   [<ffffffff810e1c84>] finish_task_switch+0xb4/0x250
   [<ffffffff8106f7dc>] do_async_page_fault+0x2c/0xa0

It will look worse once we start printing pt_regs registers found in the
middle of the stack:

  <IRQ> RIP: 0010:[<ffffffff8189c6c3>]  [<ffffffff8189c6c3>] _raw_spin_unlock_irq+0x33/0x60
  RSP: 0018:ffff88007876f720  EFLAGS: 00000206
  RAX: ffff8800786caa40 RBX: ffff88007d5da140 RCX: 0000000000000007
  ...

Improve readability by adding a newline to the stack name:

  Call Trace:
   <IRQ>
   [<ffffffff814431c3>] dump_stack+0x86/0xc3
   [<ffffffff8100828b>] perf_callchain_kernel+0x14b/0x160
   [<ffffffff811e915f>] get_perf_callchain+0x15f/0x2b0
   ...
   <EOI>
   [<ffffffff8189c6c3>] ? _raw_spin_unlock_irq+0x33/0x60
   [<ffffffff810e1c84>] finish_task_switch+0xb4/0x250
   [<ffffffff8106f7dc>] do_async_page_fault+0x2c/0xa0

Now that "continued" lines are no longer needed, we can also remove the
hack of using the empty string (aka KERN_CONT) and replace it with
KERN_DEFAULT.

Signed-off-by: Josh Poimboeuf <jpoimboe@redhat.com>
---
 arch/x86/kernel/dumpstack.c | 8 ++++----
 1 file changed, 4 insertions(+), 4 deletions(-)

diff --git a/arch/x86/kernel/dumpstack.c b/arch/x86/kernel/dumpstack.c
index 198dc9e..0eedb01 100644
--- a/arch/x86/kernel/dumpstack.c
+++ b/arch/x86/kernel/dumpstack.c
@@ -124,7 +124,7 @@ void show_trace_log_lvl(struct task_struct *task, struct pt_regs *regs,
 
 		stack_type_str(stack_info.type, &str_begin, &str_end);
 		if (str_begin)
-			printk("%s <%s> ", log_lvl, str_begin);
+			printk("%s <%s>\n", log_lvl, str_begin);
 
 		/*
 		 * Scan the stack, printing any text addresses we find.  At the
@@ -176,7 +176,7 @@ void show_trace_log_lvl(struct task_struct *task, struct pt_regs *regs,
 		}
 
 		if (str_end)
-			printk("%s <%s> ", log_lvl, str_end);
+			printk("%s <%s>\n", log_lvl, str_end);
 	}
 }
 
@@ -193,12 +193,12 @@ void show_stack(struct task_struct *task, unsigned long *sp)
 		bp = (unsigned long)get_frame_pointer(current, NULL);
 	}
 
-	show_stack_log_lvl(task, NULL, sp, "");
+	show_stack_log_lvl(task, NULL, sp, KERN_DEFAULT);
 }
 
 void show_stack_regs(struct pt_regs *regs)
 {
-	show_stack_log_lvl(NULL, regs, NULL, "");
+	show_stack_log_lvl(NULL, regs, NULL, KERN_DEFAULT);
 }
 
 static arch_spinlock_t die_lock = __ARCH_SPIN_LOCK_UNLOCKED;
-- 
2.7.4

[toc] | [prev] | [next] | [standalone]

#1448177 — [PATCH 13/19] x86/stacktrace: convert save_stack_trace_*() to the new unwinder

Convert save_stack_trace_*() to the new unwinder.  dump_trace() has been
deprecated.

Signed-off-by: Josh Poimboeuf <jpoimboe@redhat.com>
---
 arch/x86/kernel/stacktrace.c | 74 +++++++++++++++++---------------------------
 1 file changed, 29 insertions(+), 45 deletions(-)

diff --git a/arch/x86/kernel/stacktrace.c b/arch/x86/kernel/stacktrace.c
index 785aef1..63342f2 100644
--- a/arch/x86/kernel/stacktrace.c
+++ b/arch/x86/kernel/stacktrace.c
@@ -8,80 +8,64 @@
 #include <linux/export.h>
 #include <linux/uaccess.h>
 #include <asm/stacktrace.h>
+#include <asm/unwind.h>
 
-static int save_stack_stack(void *data, const char *name)
+static int save_stack_address(struct stack_trace *trace, unsigned long addr,
+			      bool nosched)
 {
-	return 0;
-}
-
-static int
-__save_stack_address(void *data, unsigned long addr, bool reliable, bool nosched)
-{
-	struct stack_trace *trace = data;
-#ifdef CONFIG_FRAME_POINTER
-	if (!reliable)
-		return 0;
-#endif
 	if (nosched && in_sched_functions(addr))
 		return 0;
+
 	if (trace->skip > 0) {
 		trace->skip--;
 		return 0;
 	}
-	if (trace->nr_entries < trace->max_entries) {
-		trace->entries[trace->nr_entries++] = addr;
-		return 0;
-	} else {
-		return -1; /* no more room, stop walking the stack */
-	}
-}
 
-static int save_stack_address(void *data, unsigned long addr, int reliable)
-{
-	return __save_stack_address(data, addr, reliable, false);
+	if (trace->nr_entries >= trace->max_entries)
+		return -1;
+
+	trace->entries[trace->nr_entries++] = addr;
+	return 0;
 }
 
-static int
-save_stack_address_nosched(void *data, unsigned long addr, int reliable)
+static void __save_stack_trace(struct stack_trace *trace,
+			       struct task_struct *task, struct pt_regs *regs,
+			       bool nosched)
 {
-	return __save_stack_address(data, addr, reliable, true);
-}
+	struct unwind_state state;
+	unsigned long addr;
 
-static const struct stacktrace_ops save_stack_ops = {
-	.stack		= save_stack_stack,
-	.address	= save_stack_address,
-	.walk_stack	= print_context_stack,
-};
+	if (regs)
+		save_stack_address(trace, regs->ip, nosched);
 
-static const struct stacktrace_ops save_stack_ops_nosched = {
-	.stack		= save_stack_stack,
-	.address	= save_stack_address_nosched,
-	.walk_stack	= print_context_stack,
-};
+	for (unwind_start(&state, task, regs, NULL); !unwind_done(&state);
+	     unwind_next_frame(&state)) {
+		addr = unwind_get_return_address(&state);
+		if (save_stack_address(trace, addr, nosched))
+			break;
+	}
+
+	if (trace->nr_entries < trace->max_entries)
+		trace->entries[trace->nr_entries++] = ULONG_MAX;
+}
 
 /*
  * Save stack-backtrace addresses into a stack_trace buffer.
  */
 void save_stack_trace(struct stack_trace *trace)
 {
-	dump_trace(current, NULL, NULL, 0, &save_stack_ops, trace);
-	if (trace->nr_entries < trace->max_entries)
-		trace->entries[trace->nr_entries++] = ULONG_MAX;
+	__save_stack_trace(trace, NULL, NULL, false);
 }
 EXPORT_SYMBOL_GPL(save_stack_trace);
 
 void save_stack_trace_regs(struct pt_regs *regs, struct stack_trace *trace)
 {
-	dump_trace(current, regs, NULL, 0, &save_stack_ops, trace);
-	if (trace->nr_entries < trace->max_entries)
-		trace->entries[trace->nr_entries++] = ULONG_MAX;
+	__save_stack_trace(trace, NULL, regs, false);
 }
 
 void save_stack_trace_tsk(struct task_struct *tsk, struct stack_trace *trace)
 {
-	dump_trace(tsk, NULL, NULL, 0, &save_stack_ops_nosched, trace);
-	if (trace->nr_entries < trace->max_entries)
-		trace->entries[trace->nr_entries++] = ULONG_MAX;
+	__save_stack_trace(trace, tsk, NULL, true);
 }
 EXPORT_SYMBOL_GPL(save_stack_trace_tsk);
 
-- 
2.7.4

[toc] | [prev] | [next] | [standalone]

#1448178 — [PATCH 19/19] x86/dumpstack: print any pt_regs found on the stack

Now that we can find pt_regs registers in the middle of the stack due to
an interrupt or exception, we can print them.  Here's what it looks
like:

   ...
   [<ffffffff8106f7dc>] do_async_page_fault+0x2c/0xa0
   [<ffffffff8189f558>] async_page_fault+0x28/0x30
  RIP: 0010:[<ffffffff814529e2>]  [<ffffffff814529e2>] __clear_user+0x42/0x70
  RSP: 0018:ffff88007876fd38  EFLAGS: 00010202
  RAX: 0000000000000000 RBX: 0000000000000138 RCX: 0000000000000138
  RDX: 0000000000000000 RSI: 0000000000000008 RDI: 000000000061b640
  RBP: ffff88007876fd48 R08: 0000000dc2ced0d0 R09: 0000000000000000
  R10: 0000000000000001 R11: 0000000000000000 R12: 000000000061b640
  R13: 0000000000000000 R14: ffff880078770000 R15: ffff880079947200
   [<ffffffff814529e2>] ? __clear_user+0x42/0x70
   [<ffffffff814529c3>] ? __clear_user+0x23/0x70
   [<ffffffff81452a7b>] clear_user+0x2b/0x40
   ...

Signed-off-by: Josh Poimboeuf <jpoimboe@redhat.com>
---
 arch/x86/kernel/dumpstack.c | 8 ++++++++
 1 file changed, 8 insertions(+)

diff --git a/arch/x86/kernel/dumpstack.c b/arch/x86/kernel/dumpstack.c
index 0eedb01..4509866 100644
--- a/arch/x86/kernel/dumpstack.c
+++ b/arch/x86/kernel/dumpstack.c
@@ -173,6 +173,14 @@ void show_trace_log_lvl(struct task_struct *task, struct pt_regs *regs,
 			 * printed as unreliable.
 			 */
 			unwind_next_frame(&state);
+
+			/*
+			 * If the previous frame had pt_regs associated with it
+			 * due to an interrupt or exception, print them.
+			 */
+			regs = unwind_get_entry_regs(&state);
+			if (regs)
+				__show_regs(regs, 0);
 		}
 
 		if (str_end)
-- 
2.7.4

[toc] | [prev] | [next] | [standalone]

#1448230 — Re: [PATCH 19/19] x86/dumpstack: print any pt_regs found on the stack

On Thu, Jul 21, 2016 at 2:21 PM, Josh Poimboeuf <jpoimboe@redhat.com> wrote:
> Now that we can find pt_regs registers in the middle of the stack due to
> an interrupt or exception, we can print them.  Here's what it looks
> like:
>
>    ...
>    [<ffffffff8106f7dc>] do_async_page_fault+0x2c/0xa0
>    [<ffffffff8189f558>] async_page_fault+0x28/0x30
>   RIP: 0010:[<ffffffff814529e2>]  [<ffffffff814529e2>] __clear_user+0x42/0x70
>   RSP: 0018:ffff88007876fd38  EFLAGS: 00010202
>   RAX: 0000000000000000 RBX: 0000000000000138 RCX: 0000000000000138
>   RDX: 0000000000000000 RSI: 0000000000000008 RDI: 000000000061b640
>   RBP: ffff88007876fd48 R08: 0000000dc2ced0d0 R09: 0000000000000000
>   R10: 0000000000000001 R11: 0000000000000000 R12: 000000000061b640
>   R13: 0000000000000000 R14: ffff880078770000 R15: ffff880079947200
>    [<ffffffff814529e2>] ? __clear_user+0x42/0x70
>    [<ffffffff814529c3>] ? __clear_user+0x23/0x70
>    [<ffffffff81452a7b>] clear_user+0x2b/0x40
>    ...

This looks wrong.  Here are some theories:

(a) __clear_user is a reliable address that is indicated by RIP: ....
Then it's found again as an unreliable address as "?
__clear_user+0x42/0x70" by scanning the stack.  "?
__clear_user+0x23/0x70" is a genuine leftover artifact on the stack.
In this case, shouldn't "? __clear_user+0x42/0x70" have been
suppressed because it matched a reliable address?

(b) You actually intended for all the addresses to be printed, in
which case "? __clear_user+0x42/0x70" should have been
"__clear_user+0x42/0x70" and you have a bug.  In this case, it's
plausible that your state machine got a bit lost leading to "?
__clear_user+0x23/0x70" as well (i.e. it's not just an artifact --
it's a real frame and you didn't find it).

(c) Something else and I'm confused.

--Andy

[toc] | [prev] | [next] | [standalone]

#1448354 — Re: [PATCH 19/19] x86/dumpstack: print any pt_regs found on the stack

On Thu, Jul 21, 2016 at 03:32:32PM -0700, Andy Lutomirski wrote:
> On Thu, Jul 21, 2016 at 2:21 PM, Josh Poimboeuf <jpoimboe@redhat.com> wrote:
> > Now that we can find pt_regs registers in the middle of the stack due to
> > an interrupt or exception, we can print them.  Here's what it looks
> > like:
> >
> >    ...
> >    [<ffffffff8106f7dc>] do_async_page_fault+0x2c/0xa0
> >    [<ffffffff8189f558>] async_page_fault+0x28/0x30
> >   RIP: 0010:[<ffffffff814529e2>]  [<ffffffff814529e2>] __clear_user+0x42/0x70
> >   RSP: 0018:ffff88007876fd38  EFLAGS: 00010202
> >   RAX: 0000000000000000 RBX: 0000000000000138 RCX: 0000000000000138
> >   RDX: 0000000000000000 RSI: 0000000000000008 RDI: 000000000061b640
> >   RBP: ffff88007876fd48 R08: 0000000dc2ced0d0 R09: 0000000000000000
> >   R10: 0000000000000001 R11: 0000000000000000 R12: 000000000061b640
> >   R13: 0000000000000000 R14: ffff880078770000 R15: ffff880079947200
> >    [<ffffffff814529e2>] ? __clear_user+0x42/0x70
> >    [<ffffffff814529c3>] ? __clear_user+0x23/0x70
> >    [<ffffffff81452a7b>] clear_user+0x2b/0x40
> >    ...
> 
> This looks wrong.  Here are some theories:
> 
> (a) __clear_user is a reliable address that is indicated by RIP: ....
> Then it's found again as an unreliable address as "?
> __clear_user+0x42/0x70" by scanning the stack.  "?
> __clear_user+0x23/0x70" is a genuine leftover artifact on the stack.
> In this case, shouldn't "? __clear_user+0x42/0x70" have been
> suppressed because it matched a reliable address?
> 
> (b) You actually intended for all the addresses to be printed, in
> which case "? __clear_user+0x42/0x70" should have been
> "__clear_user+0x42/0x70" and you have a bug.  In this case, it's
> plausible that your state machine got a bit lost leading to "?
> __clear_user+0x23/0x70" as well (i.e. it's not just an artifact --
> it's a real frame and you didn't find it).
> 
> (c) Something else and I'm confused.

So there's a subtle difference between addresses reported by regs->ip
and normal return addresses.  For example:

   ...
   [<ffffffff8189ff4d>] smp_apic_timer_interrupt+0x3d/0x50
   [<ffffffff8189de6e>] apic_timer_interrupt+0x9e/0xb0
  RIP: 0010:[<ffffffff8129b350>]  [<ffffffff8129b350>] path_init+0x0/0x750
  RSP: 0018:ffff880036a3fd80  EFLAGS: 00000296
  RAX: ffff88003691aa40 RBX: ffff880036a3ff08 RCX: ffff880036a3ff08
  RDX: ffff880036a3ff08 RSI: 0000000000000041 RDI: ffff880036a3fdb0
  RBP: ffff880036a3fda0 R08: 0000000000000000 R09: 0000000000000010
  R10: 8080808080808080 R11: fefefefefefefeff R12: ffff880036a3fdb0
  R13: 0000000000000001 R14: ffff880036a3ff08 R15: 0000000000000000
   <EOI>
   [<ffffffff8129b350>] ? lookup_fast+0x3d0/0x3d0
   [<ffffffff8129c81b>] ? path_lookupat+0x1b/0x120
   [<ffffffff8129ddd1>] filename_lookup+0xb1/0x180
   ...

In this case the irq hit right after path_lookupat() called into
path_init().  So the "path_init+0x0" printed by __show_regs() is right.

Note the backtrace reports the same address, but it instead describes it
as "lookup_fast+0x3d0", which is the end of lookup_fast().  That's
because normally, such an address after a call instruction at the end of
a function would indicate a tail call (e.g., to a noreturn function).
If that were the case, printing "path_init+0x0" would be completely
wrong, because path_init() just happens to be the function located
immediately after lookup_fast().

Maybe I could add some special logic to say: "if this return address was
from a call, use printk_stack_address(); else if it was from a pt_regs,
use printk_address()."  (The former prints the preceding function, the
latter prints the current function.)  Then we could remove the question
mark.

There's also the question of whether or not the address should be
printed again, after it's already been printed by __show_regs().  I
don't have a strong opinion either way.

-- 
Josh

[toc] | [prev] | [next] | [standalone]

#1448397 — Re: [PATCH 19/19] x86/dumpstack: print any pt_regs found on the stack

On Thu, Jul 21, 2016 at 8:30 PM, Josh Poimboeuf <jpoimboe@redhat.com> wrote:
> On Thu, Jul 21, 2016 at 03:32:32PM -0700, Andy Lutomirski wrote:
>> On Thu, Jul 21, 2016 at 2:21 PM, Josh Poimboeuf <jpoimboe@redhat.com> wrote:
>> > Now that we can find pt_regs registers in the middle of the stack due to
>> > an interrupt or exception, we can print them.  Here's what it looks
>> > like:
>> >
>> >    ...
>> >    [<ffffffff8106f7dc>] do_async_page_fault+0x2c/0xa0
>> >    [<ffffffff8189f558>] async_page_fault+0x28/0x30
>> >   RIP: 0010:[<ffffffff814529e2>]  [<ffffffff814529e2>] __clear_user+0x42/0x70
>> >   RSP: 0018:ffff88007876fd38  EFLAGS: 00010202
>> >   RAX: 0000000000000000 RBX: 0000000000000138 RCX: 0000000000000138
>> >   RDX: 0000000000000000 RSI: 0000000000000008 RDI: 000000000061b640
>> >   RBP: ffff88007876fd48 R08: 0000000dc2ced0d0 R09: 0000000000000000
>> >   R10: 0000000000000001 R11: 0000000000000000 R12: 000000000061b640
>> >   R13: 0000000000000000 R14: ffff880078770000 R15: ffff880079947200
>> >    [<ffffffff814529e2>] ? __clear_user+0x42/0x70
>> >    [<ffffffff814529c3>] ? __clear_user+0x23/0x70
>> >    [<ffffffff81452a7b>] clear_user+0x2b/0x40
>> >    ...
>>
>> This looks wrong.  Here are some theories:
>>
>> (a) __clear_user is a reliable address that is indicated by RIP: ....
>> Then it's found again as an unreliable address as "?
>> __clear_user+0x42/0x70" by scanning the stack.  "?
>> __clear_user+0x23/0x70" is a genuine leftover artifact on the stack.
>> In this case, shouldn't "? __clear_user+0x42/0x70" have been
>> suppressed because it matched a reliable address?
>>
>> (b) You actually intended for all the addresses to be printed, in
>> which case "? __clear_user+0x42/0x70" should have been
>> "__clear_user+0x42/0x70" and you have a bug.  In this case, it's
>> plausible that your state machine got a bit lost leading to "?
>> __clear_user+0x23/0x70" as well (i.e. it's not just an artifact --
>> it's a real frame and you didn't find it).
>>
>> (c) Something else and I'm confused.
>
> So there's a subtle difference between addresses reported by regs->ip
> and normal return addresses.  For example:
>
>    ...
>    [<ffffffff8189ff4d>] smp_apic_timer_interrupt+0x3d/0x50
>    [<ffffffff8189de6e>] apic_timer_interrupt+0x9e/0xb0
>   RIP: 0010:[<ffffffff8129b350>]  [<ffffffff8129b350>] path_init+0x0/0x750
>   RSP: 0018:ffff880036a3fd80  EFLAGS: 00000296
>   RAX: ffff88003691aa40 RBX: ffff880036a3ff08 RCX: ffff880036a3ff08
>   RDX: ffff880036a3ff08 RSI: 0000000000000041 RDI: ffff880036a3fdb0
>   RBP: ffff880036a3fda0 R08: 0000000000000000 R09: 0000000000000010
>   R10: 8080808080808080 R11: fefefefefefefeff R12: ffff880036a3fdb0
>   R13: 0000000000000001 R14: ffff880036a3ff08 R15: 0000000000000000
>    <EOI>
>    [<ffffffff8129b350>] ? lookup_fast+0x3d0/0x3d0
>    [<ffffffff8129c81b>] ? path_lookupat+0x1b/0x120
>    [<ffffffff8129ddd1>] filename_lookup+0xb1/0x180
>    ...
>
> In this case the irq hit right after path_lookupat() called into
> path_init().  So the "path_init+0x0" printed by __show_regs() is right.
>
> Note the backtrace reports the same address, but it instead describes it
> as "lookup_fast+0x3d0", which is the end of lookup_fast().  That's
> because normally, such an address after a call instruction at the end of
> a function would indicate a tail call (e.g., to a noreturn function).
> If that were the case, printing "path_init+0x0" would be completely
> wrong, because path_init() just happens to be the function located
> immediately after lookup_fast().
>
> Maybe I could add some special logic to say: "if this return address was
> from a call, use printk_stack_address(); else if it was from a pt_regs,
> use printk_address()."  (The former prints the preceding function, the
> latter prints the current function.)  Then we could remove the question
> mark.
>
> There's also the question of whether or not the address should be
> printed again, after it's already been printed by __show_regs().  I
> don't have a strong opinion either way.
>

IIRC we don't show the actual faulting function in the call trace, so
we probably shouldn't duplicate the entry after the show_regs.

That being said, I'm still confused by the question marks.  What
exactly is going on?  Is the code really doing the right thing wrt
resuming the unwind?  Is there a git tree with these patches applied
somewhere so I can look at it easily in context?

--Andy

[toc] | [prev] | [next] | [standalone]

#1448651 — Re: [PATCH 19/19] x86/dumpstack: print any pt_regs found on the stack

On Thu, Jul 21, 2016 at 10:13:03PM -0700, Andy Lutomirski wrote:
> On Thu, Jul 21, 2016 at 8:30 PM, Josh Poimboeuf <jpoimboe@redhat.com> wrote:
> > On Thu, Jul 21, 2016 at 03:32:32PM -0700, Andy Lutomirski wrote:
> >> On Thu, Jul 21, 2016 at 2:21 PM, Josh Poimboeuf <jpoimboe@redhat.com> wrote:
> >> > Now that we can find pt_regs registers in the middle of the stack due to
> >> > an interrupt or exception, we can print them.  Here's what it looks
> >> > like:
> >> >
> >> >    ...
> >> >    [<ffffffff8106f7dc>] do_async_page_fault+0x2c/0xa0
> >> >    [<ffffffff8189f558>] async_page_fault+0x28/0x30
> >> >   RIP: 0010:[<ffffffff814529e2>]  [<ffffffff814529e2>] __clear_user+0x42/0x70
> >> >   RSP: 0018:ffff88007876fd38  EFLAGS: 00010202
> >> >   RAX: 0000000000000000 RBX: 0000000000000138 RCX: 0000000000000138
> >> >   RDX: 0000000000000000 RSI: 0000000000000008 RDI: 000000000061b640
> >> >   RBP: ffff88007876fd48 R08: 0000000dc2ced0d0 R09: 0000000000000000
> >> >   R10: 0000000000000001 R11: 0000000000000000 R12: 000000000061b640
> >> >   R13: 0000000000000000 R14: ffff880078770000 R15: ffff880079947200
> >> >    [<ffffffff814529e2>] ? __clear_user+0x42/0x70
> >> >    [<ffffffff814529c3>] ? __clear_user+0x23/0x70
> >> >    [<ffffffff81452a7b>] clear_user+0x2b/0x40
> >> >    ...
> >>
> >> This looks wrong.  Here are some theories:
> >>
> >> (a) __clear_user is a reliable address that is indicated by RIP: ....
> >> Then it's found again as an unreliable address as "?
> >> __clear_user+0x42/0x70" by scanning the stack.  "?
> >> __clear_user+0x23/0x70" is a genuine leftover artifact on the stack.
> >> In this case, shouldn't "? __clear_user+0x42/0x70" have been
> >> suppressed because it matched a reliable address?
> >>
> >> (b) You actually intended for all the addresses to be printed, in
> >> which case "? __clear_user+0x42/0x70" should have been
> >> "__clear_user+0x42/0x70" and you have a bug.  In this case, it's
> >> plausible that your state machine got a bit lost leading to "?
> >> __clear_user+0x23/0x70" as well (i.e. it's not just an artifact --
> >> it's a real frame and you didn't find it).
> >>
> >> (c) Something else and I'm confused.
> >
> > So there's a subtle difference between addresses reported by regs->ip
> > and normal return addresses.  For example:
> >
> >    ...
> >    [<ffffffff8189ff4d>] smp_apic_timer_interrupt+0x3d/0x50
> >    [<ffffffff8189de6e>] apic_timer_interrupt+0x9e/0xb0
> >   RIP: 0010:[<ffffffff8129b350>]  [<ffffffff8129b350>] path_init+0x0/0x750
> >   RSP: 0018:ffff880036a3fd80  EFLAGS: 00000296
> >   RAX: ffff88003691aa40 RBX: ffff880036a3ff08 RCX: ffff880036a3ff08
> >   RDX: ffff880036a3ff08 RSI: 0000000000000041 RDI: ffff880036a3fdb0
> >   RBP: ffff880036a3fda0 R08: 0000000000000000 R09: 0000000000000010
> >   R10: 8080808080808080 R11: fefefefefefefeff R12: ffff880036a3fdb0
> >   R13: 0000000000000001 R14: ffff880036a3ff08 R15: 0000000000000000
> >    <EOI>
> >    [<ffffffff8129b350>] ? lookup_fast+0x3d0/0x3d0
> >    [<ffffffff8129c81b>] ? path_lookupat+0x1b/0x120
> >    [<ffffffff8129ddd1>] filename_lookup+0xb1/0x180
> >    ...
> >
> > In this case the irq hit right after path_lookupat() called into
> > path_init().  So the "path_init+0x0" printed by __show_regs() is right.
> >
> > Note the backtrace reports the same address, but it instead describes it
> > as "lookup_fast+0x3d0", which is the end of lookup_fast().  That's
> > because normally, such an address after a call instruction at the end of
> > a function would indicate a tail call (e.g., to a noreturn function).
> > If that were the case, printing "path_init+0x0" would be completely
> > wrong, because path_init() just happens to be the function located
> > immediately after lookup_fast().
> >
> > Maybe I could add some special logic to say: "if this return address was
> > from a call, use printk_stack_address(); else if it was from a pt_regs,
> > use printk_address()."  (The former prints the preceding function, the
> > latter prints the current function.)  Then we could remove the question
> > mark.
> >
> > There's also the question of whether or not the address should be
> > printed again, after it's already been printed by __show_regs().  I
> > don't have a strong opinion either way.
> >
> 
> IIRC we don't show the actual faulting function in the call trace, so
> we probably shouldn't duplicate the entry after the show_regs.

Just to clarify, that's true today for cases where the stack dump starts
from a handler which has regs.  It starts dumping based on regs->ip and
regs->bp, so the regs themselves aren't dumped.

But for cases where regs are in the middle of the stack, they aren't
detected today, and you'll still see the value of regs->ip dumped with a
question mark.

That said, with this patch, now that regs in the middle of the stack
*are* being printed, I can't think of a good reason to print the return
address twice: both in regs and the stack trace.  So removing it from
the stack trace is fine with me.

> That being said, I'm still confused by the question marks.  What
> exactly is going on?  Is the code really doing the right thing wrt
> resuming the unwind?  Is there a git tree with these patches applied
> somewhere so I can look at it easily in context?

show_trace_log_lvl() is doing two things in parallel: scanning all
kernel text addresses on the stack while simultaneously using the
unwinder to walk the frame pointers.  Only those scanned addresses which
are also found by the unwinder are printed without question marks.

The pt_regs aren't in a frame of their own; they're just data inside of
a bigger frame.  (You may recall that you objected to my proposal to put
them in their own frame :-))  So that's why the address stored in
regs->ip was printed with a question mark: it's not in the header of a
real frame; it's just data.

I pushed the code out at:

  https://github.com/jpoimboe/linux unwind-v1

See show_trace_log_lvl() in arch/x86/kernel/dumpstack.c.

-- 
Josh

[toc] | [prev] | [next] | [standalone]

#1448804 — Re: [PATCH 19/19] x86/dumpstack: print any pt_regs found on the stack

On Fri, Jul 22, 2016 at 8:57 AM, Josh Poimboeuf <jpoimboe@redhat.com> wrote:
> On Thu, Jul 21, 2016 at 10:13:03PM -0700, Andy Lutomirski wrote:
>> On Thu, Jul 21, 2016 at 8:30 PM, Josh Poimboeuf <jpoimboe@redhat.com> wrote:
>> > On Thu, Jul 21, 2016 at 03:32:32PM -0700, Andy Lutomirski wrote:
>> >> On Thu, Jul 21, 2016 at 2:21 PM, Josh Poimboeuf <jpoimboe@redhat.com> wrote:
>> >> > Now that we can find pt_regs registers in the middle of the stack due to
>> >> > an interrupt or exception, we can print them.  Here's what it looks
>> >> > like:
>> >> >
>> >> >    ...
>> >> >    [<ffffffff8106f7dc>] do_async_page_fault+0x2c/0xa0
>> >> >    [<ffffffff8189f558>] async_page_fault+0x28/0x30
>> >> >   RIP: 0010:[<ffffffff814529e2>]  [<ffffffff814529e2>] __clear_user+0x42/0x70
>> >> >   RSP: 0018:ffff88007876fd38  EFLAGS: 00010202
>> >> >   RAX: 0000000000000000 RBX: 0000000000000138 RCX: 0000000000000138
>> >> >   RDX: 0000000000000000 RSI: 0000000000000008 RDI: 000000000061b640
>> >> >   RBP: ffff88007876fd48 R08: 0000000dc2ced0d0 R09: 0000000000000000
>> >> >   R10: 0000000000000001 R11: 0000000000000000 R12: 000000000061b640
>> >> >   R13: 0000000000000000 R14: ffff880078770000 R15: ffff880079947200
>> >> >    [<ffffffff814529e2>] ? __clear_user+0x42/0x70
>> >> >    [<ffffffff814529c3>] ? __clear_user+0x23/0x70
>> >> >    [<ffffffff81452a7b>] clear_user+0x2b/0x40
>> >> >    ...
>> >>
>> >> This looks wrong.  Here are some theories:
>> >>
>> >> (a) __clear_user is a reliable address that is indicated by RIP: ....
>> >> Then it's found again as an unreliable address as "?
>> >> __clear_user+0x42/0x70" by scanning the stack.  "?
>> >> __clear_user+0x23/0x70" is a genuine leftover artifact on the stack.
>> >> In this case, shouldn't "? __clear_user+0x42/0x70" have been
>> >> suppressed because it matched a reliable address?
>> >>
>> >> (b) You actually intended for all the addresses to be printed, in
>> >> which case "? __clear_user+0x42/0x70" should have been
>> >> "__clear_user+0x42/0x70" and you have a bug.  In this case, it's
>> >> plausible that your state machine got a bit lost leading to "?
>> >> __clear_user+0x23/0x70" as well (i.e. it's not just an artifact --
>> >> it's a real frame and you didn't find it).
>> >>
>> >> (c) Something else and I'm confused.
>> >
>> > So there's a subtle difference between addresses reported by regs->ip
>> > and normal return addresses.  For example:
>> >
>> >    ...
>> >    [<ffffffff8189ff4d>] smp_apic_timer_interrupt+0x3d/0x50
>> >    [<ffffffff8189de6e>] apic_timer_interrupt+0x9e/0xb0
>> >   RIP: 0010:[<ffffffff8129b350>]  [<ffffffff8129b350>] path_init+0x0/0x750
>> >   RSP: 0018:ffff880036a3fd80  EFLAGS: 00000296
>> >   RAX: ffff88003691aa40 RBX: ffff880036a3ff08 RCX: ffff880036a3ff08
>> >   RDX: ffff880036a3ff08 RSI: 0000000000000041 RDI: ffff880036a3fdb0
>> >   RBP: ffff880036a3fda0 R08: 0000000000000000 R09: 0000000000000010
>> >   R10: 8080808080808080 R11: fefefefefefefeff R12: ffff880036a3fdb0
>> >   R13: 0000000000000001 R14: ffff880036a3ff08 R15: 0000000000000000
>> >    <EOI>
>> >    [<ffffffff8129b350>] ? lookup_fast+0x3d0/0x3d0
>> >    [<ffffffff8129c81b>] ? path_lookupat+0x1b/0x120
>> >    [<ffffffff8129ddd1>] filename_lookup+0xb1/0x180
>> >    ...
>> >
>> > In this case the irq hit right after path_lookupat() called into
>> > path_init().  So the "path_init+0x0" printed by __show_regs() is right.
>> >
>> > Note the backtrace reports the same address, but it instead describes it
>> > as "lookup_fast+0x3d0", which is the end of lookup_fast().  That's
>> > because normally, such an address after a call instruction at the end of
>> > a function would indicate a tail call (e.g., to a noreturn function).
>> > If that were the case, printing "path_init+0x0" would be completely
>> > wrong, because path_init() just happens to be the function located
>> > immediately after lookup_fast().
>> >
>> > Maybe I could add some special logic to say: "if this return address was
>> > from a call, use printk_stack_address(); else if it was from a pt_regs,
>> > use printk_address()."  (The former prints the preceding function, the
>> > latter prints the current function.)  Then we could remove the question
>> > mark.
>> >
>> > There's also the question of whether or not the address should be
>> > printed again, after it's already been printed by __show_regs().  I
>> > don't have a strong opinion either way.
>> >
>>
>> IIRC we don't show the actual faulting function in the call trace, so
>> we probably shouldn't duplicate the entry after the show_regs.
>
> Just to clarify, that's true today for cases where the stack dump starts
> from a handler which has regs.  It starts dumping based on regs->ip and
> regs->bp, so the regs themselves aren't dumped.
>
> But for cases where regs are in the middle of the stack, they aren't
> detected today, and you'll still see the value of regs->ip dumped with a
> question mark.
>
> That said, with this patch, now that regs in the middle of the stack
> *are* being printed, I can't think of a good reason to print the return
> address twice: both in regs and the stack trace.  So removing it from
> the stack trace is fine with me.
>
>> That being said, I'm still confused by the question marks.  What
>> exactly is going on?  Is the code really doing the right thing wrt
>> resuming the unwind?  Is there a git tree with these patches applied
>> somewhere so I can look at it easily in context?
>
> show_trace_log_lvl() is doing two things in parallel: scanning all
> kernel text addresses on the stack while simultaneously using the
> unwinder to walk the frame pointers.  Only those scanned addresses which
> are also found by the unwinder are printed without question marks.
>
> The pt_regs aren't in a frame of their own; they're just data inside of
> a bigger frame.  (You may recall that you objected to my proposal to put
> them in their own frame :-))  So that's why the address stored in
> regs->ip was printed with a question mark: it's not in the header of a
> real frame; it's just data.

It wasn't the separate frame part I was objecting to -- it was their
encoding on the stack.  Maybe they should unwind as though they're a
separate frame.  For example, the unwind API could give the frame that
returns to apic_timer_interrupt+0x9e/0xb0 and then the next frame
could literally list regs->ip as its retaddr (and maybe that frame or
even the following one should be the one with non-NULL
unwind_get_entry_regs).

In some sense, the regs belong to the frame that got interrupted, not
the frame that did the interrupting.  But maybe that's backwards -- if
we have DWARF, then the regs correspond to the regs at the time of a
call, and those regs are reasonably likely to contain the arguments to
the called function.

But regardless of which way this goes, it seems quite awkward to me
that regs->ip never shows up as the return addr of any frame as
exposed by the unwind API.

--Andy

[toc] | [prev] | [next] | [standalone]

#1448812 — Re: [PATCH 19/19] x86/dumpstack: print any pt_regs found on the stack

On Fri, Jul 22, 2016 at 02:46:10PM -0700, Andy Lutomirski wrote:
> On Fri, Jul 22, 2016 at 8:57 AM, Josh Poimboeuf <jpoimboe@redhat.com> wrote:
> > On Thu, Jul 21, 2016 at 10:13:03PM -0700, Andy Lutomirski wrote:
> >> On Thu, Jul 21, 2016 at 8:30 PM, Josh Poimboeuf <jpoimboe@redhat.com> wrote:
> >> > On Thu, Jul 21, 2016 at 03:32:32PM -0700, Andy Lutomirski wrote:
> >> >> On Thu, Jul 21, 2016 at 2:21 PM, Josh Poimboeuf <jpoimboe@redhat.com> wrote:
> >> >> > Now that we can find pt_regs registers in the middle of the stack due to
> >> >> > an interrupt or exception, we can print them.  Here's what it looks
> >> >> > like:
> >> >> >
> >> >> >    ...
> >> >> >    [<ffffffff8106f7dc>] do_async_page_fault+0x2c/0xa0
> >> >> >    [<ffffffff8189f558>] async_page_fault+0x28/0x30
> >> >> >   RIP: 0010:[<ffffffff814529e2>]  [<ffffffff814529e2>] __clear_user+0x42/0x70
> >> >> >   RSP: 0018:ffff88007876fd38  EFLAGS: 00010202
> >> >> >   RAX: 0000000000000000 RBX: 0000000000000138 RCX: 0000000000000138
> >> >> >   RDX: 0000000000000000 RSI: 0000000000000008 RDI: 000000000061b640
> >> >> >   RBP: ffff88007876fd48 R08: 0000000dc2ced0d0 R09: 0000000000000000
> >> >> >   R10: 0000000000000001 R11: 0000000000000000 R12: 000000000061b640
> >> >> >   R13: 0000000000000000 R14: ffff880078770000 R15: ffff880079947200
> >> >> >    [<ffffffff814529e2>] ? __clear_user+0x42/0x70
> >> >> >    [<ffffffff814529c3>] ? __clear_user+0x23/0x70
> >> >> >    [<ffffffff81452a7b>] clear_user+0x2b/0x40
> >> >> >    ...
> >> >>
> >> >> This looks wrong.  Here are some theories:
> >> >>
> >> >> (a) __clear_user is a reliable address that is indicated by RIP: ....
> >> >> Then it's found again as an unreliable address as "?
> >> >> __clear_user+0x42/0x70" by scanning the stack.  "?
> >> >> __clear_user+0x23/0x70" is a genuine leftover artifact on the stack.
> >> >> In this case, shouldn't "? __clear_user+0x42/0x70" have been
> >> >> suppressed because it matched a reliable address?
> >> >>
> >> >> (b) You actually intended for all the addresses to be printed, in
> >> >> which case "? __clear_user+0x42/0x70" should have been
> >> >> "__clear_user+0x42/0x70" and you have a bug.  In this case, it's
> >> >> plausible that your state machine got a bit lost leading to "?
> >> >> __clear_user+0x23/0x70" as well (i.e. it's not just an artifact --
> >> >> it's a real frame and you didn't find it).
> >> >>
> >> >> (c) Something else and I'm confused.
> >> >
> >> > So there's a subtle difference between addresses reported by regs->ip
> >> > and normal return addresses.  For example:
> >> >
> >> >    ...
> >> >    [<ffffffff8189ff4d>] smp_apic_timer_interrupt+0x3d/0x50
> >> >    [<ffffffff8189de6e>] apic_timer_interrupt+0x9e/0xb0
> >> >   RIP: 0010:[<ffffffff8129b350>]  [<ffffffff8129b350>] path_init+0x0/0x750
> >> >   RSP: 0018:ffff880036a3fd80  EFLAGS: 00000296
> >> >   RAX: ffff88003691aa40 RBX: ffff880036a3ff08 RCX: ffff880036a3ff08
> >> >   RDX: ffff880036a3ff08 RSI: 0000000000000041 RDI: ffff880036a3fdb0
> >> >   RBP: ffff880036a3fda0 R08: 0000000000000000 R09: 0000000000000010
> >> >   R10: 8080808080808080 R11: fefefefefefefeff R12: ffff880036a3fdb0
> >> >   R13: 0000000000000001 R14: ffff880036a3ff08 R15: 0000000000000000
> >> >    <EOI>
> >> >    [<ffffffff8129b350>] ? lookup_fast+0x3d0/0x3d0
> >> >    [<ffffffff8129c81b>] ? path_lookupat+0x1b/0x120
> >> >    [<ffffffff8129ddd1>] filename_lookup+0xb1/0x180
> >> >    ...
> >> >
> >> > In this case the irq hit right after path_lookupat() called into
> >> > path_init().  So the "path_init+0x0" printed by __show_regs() is right.
> >> >
> >> > Note the backtrace reports the same address, but it instead describes it
> >> > as "lookup_fast+0x3d0", which is the end of lookup_fast().  That's
> >> > because normally, such an address after a call instruction at the end of
> >> > a function would indicate a tail call (e.g., to a noreturn function).
> >> > If that were the case, printing "path_init+0x0" would be completely
> >> > wrong, because path_init() just happens to be the function located
> >> > immediately after lookup_fast().
> >> >
> >> > Maybe I could add some special logic to say: "if this return address was
> >> > from a call, use printk_stack_address(); else if it was from a pt_regs,
> >> > use printk_address()."  (The former prints the preceding function, the
> >> > latter prints the current function.)  Then we could remove the question
> >> > mark.
> >> >
> >> > There's also the question of whether or not the address should be
> >> > printed again, after it's already been printed by __show_regs().  I
> >> > don't have a strong opinion either way.
> >> >
> >>
> >> IIRC we don't show the actual faulting function in the call trace, so
> >> we probably shouldn't duplicate the entry after the show_regs.
> >
> > Just to clarify, that's true today for cases where the stack dump starts
> > from a handler which has regs.  It starts dumping based on regs->ip and
> > regs->bp, so the regs themselves aren't dumped.
> >
> > But for cases where regs are in the middle of the stack, they aren't
> > detected today, and you'll still see the value of regs->ip dumped with a
> > question mark.
> >
> > That said, with this patch, now that regs in the middle of the stack
> > *are* being printed, I can't think of a good reason to print the return
> > address twice: both in regs and the stack trace.  So removing it from
> > the stack trace is fine with me.
> >
> >> That being said, I'm still confused by the question marks.  What
> >> exactly is going on?  Is the code really doing the right thing wrt
> >> resuming the unwind?  Is there a git tree with these patches applied
> >> somewhere so I can look at it easily in context?
> >
> > show_trace_log_lvl() is doing two things in parallel: scanning all
> > kernel text addresses on the stack while simultaneously using the
> > unwinder to walk the frame pointers.  Only those scanned addresses which
> > are also found by the unwinder are printed without question marks.
> >
> > The pt_regs aren't in a frame of their own; they're just data inside of
> > a bigger frame.  (You may recall that you objected to my proposal to put
> > them in their own frame :-))  So that's why the address stored in
> > regs->ip was printed with a question mark: it's not in the header of a
> > real frame; it's just data.
> 
> It wasn't the separate frame part I was objecting to -- it was their
> encoding on the stack.  Maybe they should unwind as though they're a
> separate frame.  For example, the unwind API could give the frame that
> returns to apic_timer_interrupt+0x9e/0xb0 and then the next frame
> could literally list regs->ip as its retaddr (and maybe that frame or
> even the following one should be the one with non-NULL
> unwind_get_entry_regs).

Having the unwinder treat the pt_regs as a "fake" frame is problematic:

- As I described above, you can't treat regs->ip as a normal return
  value anyway.

- Also, for exceptions and nested interrupts, the regs are stored on the
  interrupting stack.  But for non-nested interrupts, they're stored on
  the thread stack.  So the regs aren't always on the same stack as the
  corresponding encoded pt_regs pointer.  Another issue is that there's
  not always a frame after the regs.  For those reasons, creating a
  "fake" frame abstraction in the state machine is quite a bit trickier
  than just dealing with those details in the only place that cares
  about them: show_trace_log_lvl().

> In some sense, the regs belong to the frame that got interrupted, not
> the frame that did the interrupting.  But maybe that's backwards -- if
> we have DWARF, then the regs correspond to the regs at the time of a
> call, and those regs are reasonably likely to contain the arguments to
> the called function.
> 
> But regardless of which way this goes, it seems quite awkward to me
> that regs->ip never shows up as the return addr of any frame as
> exposed by the unwind API.

Again, regs->ip is special.  It's not a call return address and we
shouldn't force it to be.

-- 
Josh

[toc] | [prev] | [next] | [standalone]

#1448820 — Re: [PATCH 19/19] x86/dumpstack: print any pt_regs found on the stack

On Fri, Jul 22, 2016 at 3:20 PM, Josh Poimboeuf <jpoimboe@redhat.com> wrote:
> On Fri, Jul 22, 2016 at 02:46:10PM -0700, Andy Lutomirski wrote:
>> On Fri, Jul 22, 2016 at 8:57 AM, Josh Poimboeuf <jpoimboe@redhat.com> wrote:
>> > On Thu, Jul 21, 2016 at 10:13:03PM -0700, Andy Lutomirski wrote:
>> >> On Thu, Jul 21, 2016 at 8:30 PM, Josh Poimboeuf <jpoimboe@redhat.com> wrote:
>> >> > On Thu, Jul 21, 2016 at 03:32:32PM -0700, Andy Lutomirski wrote:
>> >> >> On Thu, Jul 21, 2016 at 2:21 PM, Josh Poimboeuf <jpoimboe@redhat.com> wrote:
>> >> >> > Now that we can find pt_regs registers in the middle of the stack due to
>> >> >> > an interrupt or exception, we can print them.  Here's what it looks
>> >> >> > like:
>> >> >> >
>> >> >> >    ...
>> >> >> >    [<ffffffff8106f7dc>] do_async_page_fault+0x2c/0xa0
>> >> >> >    [<ffffffff8189f558>] async_page_fault+0x28/0x30
>> >> >> >   RIP: 0010:[<ffffffff814529e2>]  [<ffffffff814529e2>] __clear_user+0x42/0x70
>> >> >> >   RSP: 0018:ffff88007876fd38  EFLAGS: 00010202
>> >> >> >   RAX: 0000000000000000 RBX: 0000000000000138 RCX: 0000000000000138
>> >> >> >   RDX: 0000000000000000 RSI: 0000000000000008 RDI: 000000000061b640
>> >> >> >   RBP: ffff88007876fd48 R08: 0000000dc2ced0d0 R09: 0000000000000000
>> >> >> >   R10: 0000000000000001 R11: 0000000000000000 R12: 000000000061b640
>> >> >> >   R13: 0000000000000000 R14: ffff880078770000 R15: ffff880079947200
>> >> >> >    [<ffffffff814529e2>] ? __clear_user+0x42/0x70
>> >> >> >    [<ffffffff814529c3>] ? __clear_user+0x23/0x70
>> >> >> >    [<ffffffff81452a7b>] clear_user+0x2b/0x40
>> >> >> >    ...
>> >> >>
>> >> >> This looks wrong.  Here are some theories:
>> >> >>
>> >> >> (a) __clear_user is a reliable address that is indicated by RIP: ....
>> >> >> Then it's found again as an unreliable address as "?
>> >> >> __clear_user+0x42/0x70" by scanning the stack.  "?
>> >> >> __clear_user+0x23/0x70" is a genuine leftover artifact on the stack.
>> >> >> In this case, shouldn't "? __clear_user+0x42/0x70" have been
>> >> >> suppressed because it matched a reliable address?
>> >> >>
>> >> >> (b) You actually intended for all the addresses to be printed, in
>> >> >> which case "? __clear_user+0x42/0x70" should have been
>> >> >> "__clear_user+0x42/0x70" and you have a bug.  In this case, it's
>> >> >> plausible that your state machine got a bit lost leading to "?
>> >> >> __clear_user+0x23/0x70" as well (i.e. it's not just an artifact --
>> >> >> it's a real frame and you didn't find it).
>> >> >>
>> >> >> (c) Something else and I'm confused.
>> >> >
>> >> > So there's a subtle difference between addresses reported by regs->ip
>> >> > and normal return addresses.  For example:
>> >> >
>> >> >    ...
>> >> >    [<ffffffff8189ff4d>] smp_apic_timer_interrupt+0x3d/0x50
>> >> >    [<ffffffff8189de6e>] apic_timer_interrupt+0x9e/0xb0
>> >> >   RIP: 0010:[<ffffffff8129b350>]  [<ffffffff8129b350>] path_init+0x0/0x750
>> >> >   RSP: 0018:ffff880036a3fd80  EFLAGS: 00000296
>> >> >   RAX: ffff88003691aa40 RBX: ffff880036a3ff08 RCX: ffff880036a3ff08
>> >> >   RDX: ffff880036a3ff08 RSI: 0000000000000041 RDI: ffff880036a3fdb0
>> >> >   RBP: ffff880036a3fda0 R08: 0000000000000000 R09: 0000000000000010
>> >> >   R10: 8080808080808080 R11: fefefefefefefeff R12: ffff880036a3fdb0
>> >> >   R13: 0000000000000001 R14: ffff880036a3ff08 R15: 0000000000000000
>> >> >    <EOI>
>> >> >    [<ffffffff8129b350>] ? lookup_fast+0x3d0/0x3d0
>> >> >    [<ffffffff8129c81b>] ? path_lookupat+0x1b/0x120
>> >> >    [<ffffffff8129ddd1>] filename_lookup+0xb1/0x180
>> >> >    ...
>> >> >
>> >> > In this case the irq hit right after path_lookupat() called into
>> >> > path_init().  So the "path_init+0x0" printed by __show_regs() is right.
>> >> >
>> >> > Note the backtrace reports the same address, but it instead describes it
>> >> > as "lookup_fast+0x3d0", which is the end of lookup_fast().  That's
>> >> > because normally, such an address after a call instruction at the end of
>> >> > a function would indicate a tail call (e.g., to a noreturn function).
>> >> > If that were the case, printing "path_init+0x0" would be completely
>> >> > wrong, because path_init() just happens to be the function located
>> >> > immediately after lookup_fast().
>> >> >
>> >> > Maybe I could add some special logic to say: "if this return address was
>> >> > from a call, use printk_stack_address(); else if it was from a pt_regs,
>> >> > use printk_address()."  (The former prints the preceding function, the
>> >> > latter prints the current function.)  Then we could remove the question
>> >> > mark.
>> >> >
>> >> > There's also the question of whether or not the address should be
>> >> > printed again, after it's already been printed by __show_regs().  I
>> >> > don't have a strong opinion either way.
>> >> >
>> >>
>> >> IIRC we don't show the actual faulting function in the call trace, so
>> >> we probably shouldn't duplicate the entry after the show_regs.
>> >
>> > Just to clarify, that's true today for cases where the stack dump starts
>> > from a handler which has regs.  It starts dumping based on regs->ip and
>> > regs->bp, so the regs themselves aren't dumped.
>> >
>> > But for cases where regs are in the middle of the stack, they aren't
>> > detected today, and you'll still see the value of regs->ip dumped with a
>> > question mark.
>> >
>> > That said, with this patch, now that regs in the middle of the stack
>> > *are* being printed, I can't think of a good reason to print the return
>> > address twice: both in regs and the stack trace.  So removing it from
>> > the stack trace is fine with me.
>> >
>> >> That being said, I'm still confused by the question marks.  What
>> >> exactly is going on?  Is the code really doing the right thing wrt
>> >> resuming the unwind?  Is there a git tree with these patches applied
>> >> somewhere so I can look at it easily in context?
>> >
>> > show_trace_log_lvl() is doing two things in parallel: scanning all
>> > kernel text addresses on the stack while simultaneously using the
>> > unwinder to walk the frame pointers.  Only those scanned addresses which
>> > are also found by the unwinder are printed without question marks.
>> >
>> > The pt_regs aren't in a frame of their own; they're just data inside of
>> > a bigger frame.  (You may recall that you objected to my proposal to put
>> > them in their own frame :-))  So that's why the address stored in
>> > regs->ip was printed with a question mark: it's not in the header of a
>> > real frame; it's just data.
>>
>> It wasn't the separate frame part I was objecting to -- it was their
>> encoding on the stack.  Maybe they should unwind as though they're a
>> separate frame.  For example, the unwind API could give the frame that
>> returns to apic_timer_interrupt+0x9e/0xb0 and then the next frame
>> could literally list regs->ip as its retaddr (and maybe that frame or
>> even the following one should be the one with non-NULL
>> unwind_get_entry_regs).
>
> Having the unwinder treat the pt_regs as a "fake" frame is problematic:
>
> - As I described above, you can't treat regs->ip as a normal return
>   value anyway.
>
> - Also, for exceptions and nested interrupts, the regs are stored on the
>   interrupting stack.  But for non-nested interrupts, they're stored on
>   the thread stack.  So the regs aren't always on the same stack as the
>   corresponding encoded pt_regs pointer.  Another issue is that there's
>   not always a frame after the regs.  For those reasons, creating a
>   "fake" frame abstraction in the state machine is quite a bit trickier
>   than just dealing with those details in the only place that cares
>   about them: show_trace_log_lvl().
>
>> In some sense, the regs belong to the frame that got interrupted, not
>> the frame that did the interrupting.  But maybe that's backwards -- if
>> we have DWARF, then the regs correspond to the regs at the time of a
>> call, and those regs are reasonably likely to contain the arguments to
>> the called function.
>>
>> But regardless of which way this goes, it seems quite awkward to me
>> that regs->ip never shows up as the return addr of any frame as
>> exposed by the unwind API.
>
> Again, regs->ip is special.  It's not a call return address and we
> shouldn't force it to be.

This is only mostly true.  If the exception was a trap, then it is
(e.g. if a function ends in int3, then regs->ip will be off the end).
But that's just me being pedantic.

More relevantly, regs->ip is a reliable address indicating a function
that will be returned to if we ever return, and both
show_trace_log_lvl() and the livepatch stuff should interpret it as
such.  Whether this means the unwinder should change or
show_trace_log_lvl() should change isn't a big deal, but I think one
of them should change so we get this right.

>
> --
> Josh



-- 
Andy Lutomirski
AMA Capital Management, LLC

[toc] | [prev] | [next] | [standalone]

#1448832 — Re: [PATCH 19/19] x86/dumpstack: print any pt_regs found on the stack

On Fri, Jul 22, 2016 at 4:30 PM, Josh Poimboeuf <jpoimboe@redhat.com> wrote:
> On Fri, Jul 22, 2016 at 04:18:04PM -0700, Andy Lutomirski wrote:
>> On Fri, Jul 22, 2016 at 3:20 PM, Josh Poimboeuf <jpoimboe@redhat.com> wrote:
>> > On Fri, Jul 22, 2016 at 02:46:10PM -0700, Andy Lutomirski wrote:
>> >> On Fri, Jul 22, 2016 at 8:57 AM, Josh Poimboeuf <jpoimboe@redhat.com> wrote:
>> >> > On Thu, Jul 21, 2016 at 10:13:03PM -0700, Andy Lutomirski wrote:
>> >> >> On Thu, Jul 21, 2016 at 8:30 PM, Josh Poimboeuf <jpoimboe@redhat.com> wrote:
>> >> >> > On Thu, Jul 21, 2016 at 03:32:32PM -0700, Andy Lutomirski wrote:
>> >> >> >> On Thu, Jul 21, 2016 at 2:21 PM, Josh Poimboeuf <jpoimboe@redhat.com> wrote:
>> >> >> >> > Now that we can find pt_regs registers in the middle of the stack due to
>> >> >> >> > an interrupt or exception, we can print them.  Here's what it looks
>> >> >> >> > like:
>> >> >> >> >
>> >> >> >> >    ...
>> >> >> >> >    [<ffffffff8106f7dc>] do_async_page_fault+0x2c/0xa0
>> >> >> >> >    [<ffffffff8189f558>] async_page_fault+0x28/0x30
>> >> >> >> >   RIP: 0010:[<ffffffff814529e2>]  [<ffffffff814529e2>] __clear_user+0x42/0x70
>> >> >> >> >   RSP: 0018:ffff88007876fd38  EFLAGS: 00010202
>> >> >> >> >   RAX: 0000000000000000 RBX: 0000000000000138 RCX: 0000000000000138
>> >> >> >> >   RDX: 0000000000000000 RSI: 0000000000000008 RDI: 000000000061b640
>> >> >> >> >   RBP: ffff88007876fd48 R08: 0000000dc2ced0d0 R09: 0000000000000000
>> >> >> >> >   R10: 0000000000000001 R11: 0000000000000000 R12: 000000000061b640
>> >> >> >> >   R13: 0000000000000000 R14: ffff880078770000 R15: ffff880079947200
>> >> >> >> >    [<ffffffff814529e2>] ? __clear_user+0x42/0x70
>> >> >> >> >    [<ffffffff814529c3>] ? __clear_user+0x23/0x70
>> >> >> >> >    [<ffffffff81452a7b>] clear_user+0x2b/0x40
>> >> >> >> >    ...
>> >> >> >>
>> >> >> >> This looks wrong.  Here are some theories:
>> >> >> >>
>> >> >> >> (a) __clear_user is a reliable address that is indicated by RIP: ....
>> >> >> >> Then it's found again as an unreliable address as "?
>> >> >> >> __clear_user+0x42/0x70" by scanning the stack.  "?
>> >> >> >> __clear_user+0x23/0x70" is a genuine leftover artifact on the stack.
>> >> >> >> In this case, shouldn't "? __clear_user+0x42/0x70" have been
>> >> >> >> suppressed because it matched a reliable address?
>> >> >> >>
>> >> >> >> (b) You actually intended for all the addresses to be printed, in
>> >> >> >> which case "? __clear_user+0x42/0x70" should have been
>> >> >> >> "__clear_user+0x42/0x70" and you have a bug.  In this case, it's
>> >> >> >> plausible that your state machine got a bit lost leading to "?
>> >> >> >> __clear_user+0x23/0x70" as well (i.e. it's not just an artifact --
>> >> >> >> it's a real frame and you didn't find it).
>> >> >> >>
>> >> >> >> (c) Something else and I'm confused.
>> >> >> >
>> >> >> > So there's a subtle difference between addresses reported by regs->ip
>> >> >> > and normal return addresses.  For example:
>> >> >> >
>> >> >> >    ...
>> >> >> >    [<ffffffff8189ff4d>] smp_apic_timer_interrupt+0x3d/0x50
>> >> >> >    [<ffffffff8189de6e>] apic_timer_interrupt+0x9e/0xb0
>> >> >> >   RIP: 0010:[<ffffffff8129b350>]  [<ffffffff8129b350>] path_init+0x0/0x750
>> >> >> >   RSP: 0018:ffff880036a3fd80  EFLAGS: 00000296
>> >> >> >   RAX: ffff88003691aa40 RBX: ffff880036a3ff08 RCX: ffff880036a3ff08
>> >> >> >   RDX: ffff880036a3ff08 RSI: 0000000000000041 RDI: ffff880036a3fdb0
>> >> >> >   RBP: ffff880036a3fda0 R08: 0000000000000000 R09: 0000000000000010
>> >> >> >   R10: 8080808080808080 R11: fefefefefefefeff R12: ffff880036a3fdb0
>> >> >> >   R13: 0000000000000001 R14: ffff880036a3ff08 R15: 0000000000000000
>> >> >> >    <EOI>
>> >> >> >    [<ffffffff8129b350>] ? lookup_fast+0x3d0/0x3d0
>> >> >> >    [<ffffffff8129c81b>] ? path_lookupat+0x1b/0x120
>> >> >> >    [<ffffffff8129ddd1>] filename_lookup+0xb1/0x180
>> >> >> >    ...
>> >> >> >
>> >> >> > In this case the irq hit right after path_lookupat() called into
>> >> >> > path_init().  So the "path_init+0x0" printed by __show_regs() is right.
>> >> >> >
>> >> >> > Note the backtrace reports the same address, but it instead describes it
>> >> >> > as "lookup_fast+0x3d0", which is the end of lookup_fast().  That's
>> >> >> > because normally, such an address after a call instruction at the end of
>> >> >> > a function would indicate a tail call (e.g., to a noreturn function).
>> >> >> > If that were the case, printing "path_init+0x0" would be completely
>> >> >> > wrong, because path_init() just happens to be the function located
>> >> >> > immediately after lookup_fast().
>> >> >> >
>> >> >> > Maybe I could add some special logic to say: "if this return address was
>> >> >> > from a call, use printk_stack_address(); else if it was from a pt_regs,
>> >> >> > use printk_address()."  (The former prints the preceding function, the
>> >> >> > latter prints the current function.)  Then we could remove the question
>> >> >> > mark.
>> >> >> >
>> >> >> > There's also the question of whether or not the address should be
>> >> >> > printed again, after it's already been printed by __show_regs().  I
>> >> >> > don't have a strong opinion either way.
>> >> >> >
>> >> >>
>> >> >> IIRC we don't show the actual faulting function in the call trace, so
>> >> >> we probably shouldn't duplicate the entry after the show_regs.
>> >> >
>> >> > Just to clarify, that's true today for cases where the stack dump starts
>> >> > from a handler which has regs.  It starts dumping based on regs->ip and
>> >> > regs->bp, so the regs themselves aren't dumped.
>> >> >
>> >> > But for cases where regs are in the middle of the stack, they aren't
>> >> > detected today, and you'll still see the value of regs->ip dumped with a
>> >> > question mark.
>> >> >
>> >> > That said, with this patch, now that regs in the middle of the stack
>> >> > *are* being printed, I can't think of a good reason to print the return
>> >> > address twice: both in regs and the stack trace.  So removing it from
>> >> > the stack trace is fine with me.
>> >> >
>> >> >> That being said, I'm still confused by the question marks.  What
>> >> >> exactly is going on?  Is the code really doing the right thing wrt
>> >> >> resuming the unwind?  Is there a git tree with these patches applied
>> >> >> somewhere so I can look at it easily in context?
>> >> >
>> >> > show_trace_log_lvl() is doing two things in parallel: scanning all
>> >> > kernel text addresses on the stack while simultaneously using the
>> >> > unwinder to walk the frame pointers.  Only those scanned addresses which
>> >> > are also found by the unwinder are printed without question marks.
>> >> >
>> >> > The pt_regs aren't in a frame of their own; they're just data inside of
>> >> > a bigger frame.  (You may recall that you objected to my proposal to put
>> >> > them in their own frame :-))  So that's why the address stored in
>> >> > regs->ip was printed with a question mark: it's not in the header of a
>> >> > real frame; it's just data.
>> >>
>> >> It wasn't the separate frame part I was objecting to -- it was their
>> >> encoding on the stack.  Maybe they should unwind as though they're a
>> >> separate frame.  For example, the unwind API could give the frame that
>> >> returns to apic_timer_interrupt+0x9e/0xb0 and then the next frame
>> >> could literally list regs->ip as its retaddr (and maybe that frame or
>> >> even the following one should be the one with non-NULL
>> >> unwind_get_entry_regs).
>> >
>> > Having the unwinder treat the pt_regs as a "fake" frame is problematic:
>> >
>> > - As I described above, you can't treat regs->ip as a normal return
>> >   value anyway.
>> >
>> > - Also, for exceptions and nested interrupts, the regs are stored on the
>> >   interrupting stack.  But for non-nested interrupts, they're stored on
>> >   the thread stack.  So the regs aren't always on the same stack as the
>> >   corresponding encoded pt_regs pointer.  Another issue is that there's
>> >   not always a frame after the regs.  For those reasons, creating a
>> >   "fake" frame abstraction in the state machine is quite a bit trickier
>> >   than just dealing with those details in the only place that cares
>> >   about them: show_trace_log_lvl().
>> >
>> >> In some sense, the regs belong to the frame that got interrupted, not
>> >> the frame that did the interrupting.  But maybe that's backwards -- if
>> >> we have DWARF, then the regs correspond to the regs at the time of a
>> >> call, and those regs are reasonably likely to contain the arguments to
>> >> the called function.
>> >>
>> >> But regardless of which way this goes, it seems quite awkward to me
>> >> that regs->ip never shows up as the return addr of any frame as
>> >> exposed by the unwind API.
>> >
>> > Again, regs->ip is special.  It's not a call return address and we
>> > shouldn't force it to be.
>>
>> This is only mostly true.  If the exception was a trap, then it is
>> (e.g. if a function ends in int3, then regs->ip will be off the end).
>> But that's just me being pedantic.
>>
>> More relevantly, regs->ip is a reliable address indicating a function
>> that will be returned to if we ever return, and both
>> show_trace_log_lvl() and the livepatch stuff should interpret it as
>> such.
>
> Actually livepatch doesn't care; once it sees that there are regs, it
> will bail because the stack is unreliable.

Would it be better for livepatch not to bail some day?

>
>> Whether this means the unwinder should change or
>> show_trace_log_lvl() should change isn't a big deal, but I think one
>> of them should change so we get this right.
>
> I have no problem doing so, but can you clarify what you mean?  Earlier
> you said:
>
>   "IIRC we don't show the actual faulting function in the call trace, so
>   we probably shouldn't duplicate the entry after the show_regs."
>
> Maybe I'm misunderstanding, but that seems to contradict what you're
> saying now.  So which is it?  Do you want the RIP address printed twice
> (both in the regs printout and in the stack trace)?  Or not?

I don't have a stong preference as to how many times it's printed.
But I think we need to get rid of the question mark.  I think that
means there are two options:

a) Teach show_stack_log_lvl() that regs->ip is a "reliable" entry and
print it again.  That will get confused if it's the first instruction
in a function, so maybe it's not so great.

b) Teach show_stack_log_lvl() that regs->ip is a thing that we just
printed (via show_regs) and skip the ? entry.

Option b probably makes more sense.  I think I'm starting to
understand all this, but maybe I'm still missing something.

--Andy

[toc] | [prev] | [next] | [standalone]

#1448844 — Re: [PATCH 19/19] x86/dumpstack: print any pt_regs found on the stack

On Fri, Jul 22, 2016 at 04:39:00PM -0700, Andy Lutomirski wrote:
> On Fri, Jul 22, 2016 at 4:30 PM, Josh Poimboeuf <jpoimboe@redhat.com> wrote:
> > On Fri, Jul 22, 2016 at 04:18:04PM -0700, Andy Lutomirski wrote:
> >> On Fri, Jul 22, 2016 at 3:20 PM, Josh Poimboeuf <jpoimboe@redhat.com> wrote:
> >> > On Fri, Jul 22, 2016 at 02:46:10PM -0700, Andy Lutomirski wrote:
> >> >> On Fri, Jul 22, 2016 at 8:57 AM, Josh Poimboeuf <jpoimboe@redhat.com> wrote:
> >> >> > On Thu, Jul 21, 2016 at 10:13:03PM -0700, Andy Lutomirski wrote:
> >> >> >> On Thu, Jul 21, 2016 at 8:30 PM, Josh Poimboeuf <jpoimboe@redhat.com> wrote:
> >> >> >> > On Thu, Jul 21, 2016 at 03:32:32PM -0700, Andy Lutomirski wrote:
> >> >> >> >> On Thu, Jul 21, 2016 at 2:21 PM, Josh Poimboeuf <jpoimboe@redhat.com> wrote:
> >> >> >> >> > Now that we can find pt_regs registers in the middle of the stack due to
> >> >> >> >> > an interrupt or exception, we can print them.  Here's what it looks
> >> >> >> >> > like:
> >> >> >> >> >
> >> >> >> >> >    ...
> >> >> >> >> >    [<ffffffff8106f7dc>] do_async_page_fault+0x2c/0xa0
> >> >> >> >> >    [<ffffffff8189f558>] async_page_fault+0x28/0x30
> >> >> >> >> >   RIP: 0010:[<ffffffff814529e2>]  [<ffffffff814529e2>] __clear_user+0x42/0x70
> >> >> >> >> >   RSP: 0018:ffff88007876fd38  EFLAGS: 00010202
> >> >> >> >> >   RAX: 0000000000000000 RBX: 0000000000000138 RCX: 0000000000000138
> >> >> >> >> >   RDX: 0000000000000000 RSI: 0000000000000008 RDI: 000000000061b640
> >> >> >> >> >   RBP: ffff88007876fd48 R08: 0000000dc2ced0d0 R09: 0000000000000000
> >> >> >> >> >   R10: 0000000000000001 R11: 0000000000000000 R12: 000000000061b640
> >> >> >> >> >   R13: 0000000000000000 R14: ffff880078770000 R15: ffff880079947200
> >> >> >> >> >    [<ffffffff814529e2>] ? __clear_user+0x42/0x70
> >> >> >> >> >    [<ffffffff814529c3>] ? __clear_user+0x23/0x70
> >> >> >> >> >    [<ffffffff81452a7b>] clear_user+0x2b/0x40
> >> >> >> >> >    ...
> >> >> >> >>
> >> >> >> >> This looks wrong.  Here are some theories:
> >> >> >> >>
> >> >> >> >> (a) __clear_user is a reliable address that is indicated by RIP: ....
> >> >> >> >> Then it's found again as an unreliable address as "?
> >> >> >> >> __clear_user+0x42/0x70" by scanning the stack.  "?
> >> >> >> >> __clear_user+0x23/0x70" is a genuine leftover artifact on the stack.
> >> >> >> >> In this case, shouldn't "? __clear_user+0x42/0x70" have been
> >> >> >> >> suppressed because it matched a reliable address?
> >> >> >> >>
> >> >> >> >> (b) You actually intended for all the addresses to be printed, in
> >> >> >> >> which case "? __clear_user+0x42/0x70" should have been
> >> >> >> >> "__clear_user+0x42/0x70" and you have a bug.  In this case, it's
> >> >> >> >> plausible that your state machine got a bit lost leading to "?
> >> >> >> >> __clear_user+0x23/0x70" as well (i.e. it's not just an artifact --
> >> >> >> >> it's a real frame and you didn't find it).
> >> >> >> >>
> >> >> >> >> (c) Something else and I'm confused.
> >> >> >> >
> >> >> >> > So there's a subtle difference between addresses reported by regs->ip
> >> >> >> > and normal return addresses.  For example:
> >> >> >> >
> >> >> >> >    ...
> >> >> >> >    [<ffffffff8189ff4d>] smp_apic_timer_interrupt+0x3d/0x50
> >> >> >> >    [<ffffffff8189de6e>] apic_timer_interrupt+0x9e/0xb0
> >> >> >> >   RIP: 0010:[<ffffffff8129b350>]  [<ffffffff8129b350>] path_init+0x0/0x750
> >> >> >> >   RSP: 0018:ffff880036a3fd80  EFLAGS: 00000296
> >> >> >> >   RAX: ffff88003691aa40 RBX: ffff880036a3ff08 RCX: ffff880036a3ff08
> >> >> >> >   RDX: ffff880036a3ff08 RSI: 0000000000000041 RDI: ffff880036a3fdb0
> >> >> >> >   RBP: ffff880036a3fda0 R08: 0000000000000000 R09: 0000000000000010
> >> >> >> >   R10: 8080808080808080 R11: fefefefefefefeff R12: ffff880036a3fdb0
> >> >> >> >   R13: 0000000000000001 R14: ffff880036a3ff08 R15: 0000000000000000
> >> >> >> >    <EOI>
> >> >> >> >    [<ffffffff8129b350>] ? lookup_fast+0x3d0/0x3d0
> >> >> >> >    [<ffffffff8129c81b>] ? path_lookupat+0x1b/0x120
> >> >> >> >    [<ffffffff8129ddd1>] filename_lookup+0xb1/0x180
> >> >> >> >    ...
> >> >> >> >
> >> >> >> > In this case the irq hit right after path_lookupat() called into
> >> >> >> > path_init().  So the "path_init+0x0" printed by __show_regs() is right.
> >> >> >> >
> >> >> >> > Note the backtrace reports the same address, but it instead describes it
> >> >> >> > as "lookup_fast+0x3d0", which is the end of lookup_fast().  That's
> >> >> >> > because normally, such an address after a call instruction at the end of
> >> >> >> > a function would indicate a tail call (e.g., to a noreturn function).
> >> >> >> > If that were the case, printing "path_init+0x0" would be completely
> >> >> >> > wrong, because path_init() just happens to be the function located
> >> >> >> > immediately after lookup_fast().
> >> >> >> >
> >> >> >> > Maybe I could add some special logic to say: "if this return address was
> >> >> >> > from a call, use printk_stack_address(); else if it was from a pt_regs,
> >> >> >> > use printk_address()."  (The former prints the preceding function, the
> >> >> >> > latter prints the current function.)  Then we could remove the question
> >> >> >> > mark.
> >> >> >> >
> >> >> >> > There's also the question of whether or not the address should be
> >> >> >> > printed again, after it's already been printed by __show_regs().  I
> >> >> >> > don't have a strong opinion either way.
> >> >> >> >
> >> >> >>
> >> >> >> IIRC we don't show the actual faulting function in the call trace, so
> >> >> >> we probably shouldn't duplicate the entry after the show_regs.
> >> >> >
> >> >> > Just to clarify, that's true today for cases where the stack dump starts
> >> >> > from a handler which has regs.  It starts dumping based on regs->ip and
> >> >> > regs->bp, so the regs themselves aren't dumped.
> >> >> >
> >> >> > But for cases where regs are in the middle of the stack, they aren't
> >> >> > detected today, and you'll still see the value of regs->ip dumped with a
> >> >> > question mark.
> >> >> >
> >> >> > That said, with this patch, now that regs in the middle of the stack
> >> >> > *are* being printed, I can't think of a good reason to print the return
> >> >> > address twice: both in regs and the stack trace.  So removing it from
> >> >> > the stack trace is fine with me.
> >> >> >
> >> >> >> That being said, I'm still confused by the question marks.  What
> >> >> >> exactly is going on?  Is the code really doing the right thing wrt
> >> >> >> resuming the unwind?  Is there a git tree with these patches applied
> >> >> >> somewhere so I can look at it easily in context?
> >> >> >
> >> >> > show_trace_log_lvl() is doing two things in parallel: scanning all
> >> >> > kernel text addresses on the stack while simultaneously using the
> >> >> > unwinder to walk the frame pointers.  Only those scanned addresses which
> >> >> > are also found by the unwinder are printed without question marks.
> >> >> >
> >> >> > The pt_regs aren't in a frame of their own; they're just data inside of
> >> >> > a bigger frame.  (You may recall that you objected to my proposal to put
> >> >> > them in their own frame :-))  So that's why the address stored in
> >> >> > regs->ip was printed with a question mark: it's not in the header of a
> >> >> > real frame; it's just data.
> >> >>
> >> >> It wasn't the separate frame part I was objecting to -- it was their
> >> >> encoding on the stack.  Maybe they should unwind as though they're a
> >> >> separate frame.  For example, the unwind API could give the frame that
> >> >> returns to apic_timer_interrupt+0x9e/0xb0 and then the next frame
> >> >> could literally list regs->ip as its retaddr (and maybe that frame or
> >> >> even the following one should be the one with non-NULL
> >> >> unwind_get_entry_regs).
> >> >
> >> > Having the unwinder treat the pt_regs as a "fake" frame is problematic:
> >> >
> >> > - As I described above, you can't treat regs->ip as a normal return
> >> >   value anyway.
> >> >
> >> > - Also, for exceptions and nested interrupts, the regs are stored on the
> >> >   interrupting stack.  But for non-nested interrupts, they're stored on
> >> >   the thread stack.  So the regs aren't always on the same stack as the
> >> >   corresponding encoded pt_regs pointer.  Another issue is that there's
> >> >   not always a frame after the regs.  For those reasons, creating a
> >> >   "fake" frame abstraction in the state machine is quite a bit trickier
> >> >   than just dealing with those details in the only place that cares
> >> >   about them: show_trace_log_lvl().
> >> >
> >> >> In some sense, the regs belong to the frame that got interrupted, not
> >> >> the frame that did the interrupting.  But maybe that's backwards -- if
> >> >> we have DWARF, then the regs correspond to the regs at the time of a
> >> >> call, and those regs are reasonably likely to contain the arguments to
> >> >> the called function.
> >> >>
> >> >> But regardless of which way this goes, it seems quite awkward to me
> >> >> that regs->ip never shows up as the return addr of any frame as
> >> >> exposed by the unwind API.
> >> >
> >> > Again, regs->ip is special.  It's not a call return address and we
> >> > shouldn't force it to be.
> >>
> >> This is only mostly true.  If the exception was a trap, then it is
> >> (e.g. if a function ends in int3, then regs->ip will be off the end).
> >> But that's just me being pedantic.
> >>
> >> More relevantly, regs->ip is a reliable address indicating a function
> >> that will be returned to if we ever return, and both
> >> show_trace_log_lvl() and the livepatch stuff should interpret it as
> >> such.
> >
> > Actually livepatch doesn't care; once it sees that there are regs, it
> > will bail because the stack is unreliable.
> 
> Would it be better for livepatch not to bail some day?

Not until we have a DWARF unwinder.

> >> Whether this means the unwinder should change or
> >> show_trace_log_lvl() should change isn't a big deal, but I think one
> >> of them should change so we get this right.
> >
> > I have no problem doing so, but can you clarify what you mean?  Earlier
> > you said:
> >
> >   "IIRC we don't show the actual faulting function in the call trace, so
> >   we probably shouldn't duplicate the entry after the show_regs."
> >
> > Maybe I'm misunderstanding, but that seems to contradict what you're
> > saying now.  So which is it?  Do you want the RIP address printed twice
> > (both in the regs printout and in the stack trace)?  Or not?
> 
> I don't have a stong preference as to how many times it's printed.
> But I think we need to get rid of the question mark.  I think that
> means there are two options:
> 
> a) Teach show_stack_log_lvl() that regs->ip is a "reliable" entry and
> print it again.  That will get confused if it's the first instruction
> in a function, so maybe it's not so great.

I proposed a fix for this above, so that it would print regs->ip one
way and a normal return address another way, to avoid the confusion:

> >> >> >> > Maybe I could add some special logic to say: "if this return address was
> >> >> >> > from a call, use printk_stack_address(); else if it was from a pt_regs,
> >> >> >> > use printk_address()."  (The former prints the preceding function, the
> >> >> >> > latter prints the current function.)  Then we could remove the question
> >> >> >> > mark.

> b) Teach show_stack_log_lvl() that regs->ip is a thing that we just
> printed (via show_regs) and skip the ? entry.
> 
> Option b probably makes more sense.  I think I'm starting to
> understand all this, but maybe I'm still missing something.

I also think b is a good option.  I'll do it for v2 unless others
disagree.

-- 
Josh

[toc] | [prev] | [next] | [standalone]

#1448834 — Re: [PATCH 19/19] x86/dumpstack: print any pt_regs found on the stack

On Fri, Jul 22, 2016 at 04:18:04PM -0700, Andy Lutomirski wrote:
> On Fri, Jul 22, 2016 at 3:20 PM, Josh Poimboeuf <jpoimboe@redhat.com> wrote:
> > On Fri, Jul 22, 2016 at 02:46:10PM -0700, Andy Lutomirski wrote:
> >> On Fri, Jul 22, 2016 at 8:57 AM, Josh Poimboeuf <jpoimboe@redhat.com> wrote:
> >> > On Thu, Jul 21, 2016 at 10:13:03PM -0700, Andy Lutomirski wrote:
> >> >> On Thu, Jul 21, 2016 at 8:30 PM, Josh Poimboeuf <jpoimboe@redhat.com> wrote:
> >> >> > On Thu, Jul 21, 2016 at 03:32:32PM -0700, Andy Lutomirski wrote:
> >> >> >> On Thu, Jul 21, 2016 at 2:21 PM, Josh Poimboeuf <jpoimboe@redhat.com> wrote:
> >> >> >> > Now that we can find pt_regs registers in the middle of the stack due to
> >> >> >> > an interrupt or exception, we can print them.  Here's what it looks
> >> >> >> > like:
> >> >> >> >
> >> >> >> >    ...
> >> >> >> >    [<ffffffff8106f7dc>] do_async_page_fault+0x2c/0xa0
> >> >> >> >    [<ffffffff8189f558>] async_page_fault+0x28/0x30
> >> >> >> >   RIP: 0010:[<ffffffff814529e2>]  [<ffffffff814529e2>] __clear_user+0x42/0x70
> >> >> >> >   RSP: 0018:ffff88007876fd38  EFLAGS: 00010202
> >> >> >> >   RAX: 0000000000000000 RBX: 0000000000000138 RCX: 0000000000000138
> >> >> >> >   RDX: 0000000000000000 RSI: 0000000000000008 RDI: 000000000061b640
> >> >> >> >   RBP: ffff88007876fd48 R08: 0000000dc2ced0d0 R09: 0000000000000000
> >> >> >> >   R10: 0000000000000001 R11: 0000000000000000 R12: 000000000061b640
> >> >> >> >   R13: 0000000000000000 R14: ffff880078770000 R15: ffff880079947200
> >> >> >> >    [<ffffffff814529e2>] ? __clear_user+0x42/0x70
> >> >> >> >    [<ffffffff814529c3>] ? __clear_user+0x23/0x70
> >> >> >> >    [<ffffffff81452a7b>] clear_user+0x2b/0x40
> >> >> >> >    ...
> >> >> >>
> >> >> >> This looks wrong.  Here are some theories:
> >> >> >>
> >> >> >> (a) __clear_user is a reliable address that is indicated by RIP: ....
> >> >> >> Then it's found again as an unreliable address as "?
> >> >> >> __clear_user+0x42/0x70" by scanning the stack.  "?
> >> >> >> __clear_user+0x23/0x70" is a genuine leftover artifact on the stack.
> >> >> >> In this case, shouldn't "? __clear_user+0x42/0x70" have been
> >> >> >> suppressed because it matched a reliable address?
> >> >> >>
> >> >> >> (b) You actually intended for all the addresses to be printed, in
> >> >> >> which case "? __clear_user+0x42/0x70" should have been
> >> >> >> "__clear_user+0x42/0x70" and you have a bug.  In this case, it's
> >> >> >> plausible that your state machine got a bit lost leading to "?
> >> >> >> __clear_user+0x23/0x70" as well (i.e. it's not just an artifact --
> >> >> >> it's a real frame and you didn't find it).
> >> >> >>
> >> >> >> (c) Something else and I'm confused.
> >> >> >
> >> >> > So there's a subtle difference between addresses reported by regs->ip
> >> >> > and normal return addresses.  For example:
> >> >> >
> >> >> >    ...
> >> >> >    [<ffffffff8189ff4d>] smp_apic_timer_interrupt+0x3d/0x50
> >> >> >    [<ffffffff8189de6e>] apic_timer_interrupt+0x9e/0xb0
> >> >> >   RIP: 0010:[<ffffffff8129b350>]  [<ffffffff8129b350>] path_init+0x0/0x750
> >> >> >   RSP: 0018:ffff880036a3fd80  EFLAGS: 00000296
> >> >> >   RAX: ffff88003691aa40 RBX: ffff880036a3ff08 RCX: ffff880036a3ff08
> >> >> >   RDX: ffff880036a3ff08 RSI: 0000000000000041 RDI: ffff880036a3fdb0
> >> >> >   RBP: ffff880036a3fda0 R08: 0000000000000000 R09: 0000000000000010
> >> >> >   R10: 8080808080808080 R11: fefefefefefefeff R12: ffff880036a3fdb0
> >> >> >   R13: 0000000000000001 R14: ffff880036a3ff08 R15: 0000000000000000
> >> >> >    <EOI>
> >> >> >    [<ffffffff8129b350>] ? lookup_fast+0x3d0/0x3d0
> >> >> >    [<ffffffff8129c81b>] ? path_lookupat+0x1b/0x120
> >> >> >    [<ffffffff8129ddd1>] filename_lookup+0xb1/0x180
> >> >> >    ...
> >> >> >
> >> >> > In this case the irq hit right after path_lookupat() called into
> >> >> > path_init().  So the "path_init+0x0" printed by __show_regs() is right.
> >> >> >
> >> >> > Note the backtrace reports the same address, but it instead describes it
> >> >> > as "lookup_fast+0x3d0", which is the end of lookup_fast().  That's
> >> >> > because normally, such an address after a call instruction at the end of
> >> >> > a function would indicate a tail call (e.g., to a noreturn function).
> >> >> > If that were the case, printing "path_init+0x0" would be completely
> >> >> > wrong, because path_init() just happens to be the function located
> >> >> > immediately after lookup_fast().
> >> >> >
> >> >> > Maybe I could add some special logic to say: "if this return address was
> >> >> > from a call, use printk_stack_address(); else if it was from a pt_regs,
> >> >> > use printk_address()."  (The former prints the preceding function, the
> >> >> > latter prints the current function.)  Then we could remove the question
> >> >> > mark.
> >> >> >
> >> >> > There's also the question of whether or not the address should be
> >> >> > printed again, after it's already been printed by __show_regs().  I
> >> >> > don't have a strong opinion either way.
> >> >> >
> >> >>
> >> >> IIRC we don't show the actual faulting function in the call trace, so
> >> >> we probably shouldn't duplicate the entry after the show_regs.
> >> >
> >> > Just to clarify, that's true today for cases where the stack dump starts
> >> > from a handler which has regs.  It starts dumping based on regs->ip and
> >> > regs->bp, so the regs themselves aren't dumped.
> >> >
> >> > But for cases where regs are in the middle of the stack, they aren't
> >> > detected today, and you'll still see the value of regs->ip dumped with a
> >> > question mark.
> >> >
> >> > That said, with this patch, now that regs in the middle of the stack
> >> > *are* being printed, I can't think of a good reason to print the return
> >> > address twice: both in regs and the stack trace.  So removing it from
> >> > the stack trace is fine with me.
> >> >
> >> >> That being said, I'm still confused by the question marks.  What
> >> >> exactly is going on?  Is the code really doing the right thing wrt
> >> >> resuming the unwind?  Is there a git tree with these patches applied
> >> >> somewhere so I can look at it easily in context?
> >> >
> >> > show_trace_log_lvl() is doing two things in parallel: scanning all
> >> > kernel text addresses on the stack while simultaneously using the
> >> > unwinder to walk the frame pointers.  Only those scanned addresses which
> >> > are also found by the unwinder are printed without question marks.
> >> >
> >> > The pt_regs aren't in a frame of their own; they're just data inside of
> >> > a bigger frame.  (You may recall that you objected to my proposal to put
> >> > them in their own frame :-))  So that's why the address stored in
> >> > regs->ip was printed with a question mark: it's not in the header of a
> >> > real frame; it's just data.
> >>
> >> It wasn't the separate frame part I was objecting to -- it was their
> >> encoding on the stack.  Maybe they should unwind as though they're a
> >> separate frame.  For example, the unwind API could give the frame that
> >> returns to apic_timer_interrupt+0x9e/0xb0 and then the next frame
> >> could literally list regs->ip as its retaddr (and maybe that frame or
> >> even the following one should be the one with non-NULL
> >> unwind_get_entry_regs).
> >
> > Having the unwinder treat the pt_regs as a "fake" frame is problematic:
> >
> > - As I described above, you can't treat regs->ip as a normal return
> >   value anyway.
> >
> > - Also, for exceptions and nested interrupts, the regs are stored on the
> >   interrupting stack.  But for non-nested interrupts, they're stored on
> >   the thread stack.  So the regs aren't always on the same stack as the
> >   corresponding encoded pt_regs pointer.  Another issue is that there's
> >   not always a frame after the regs.  For those reasons, creating a
> >   "fake" frame abstraction in the state machine is quite a bit trickier
> >   than just dealing with those details in the only place that cares
> >   about them: show_trace_log_lvl().
> >
> >> In some sense, the regs belong to the frame that got interrupted, not
> >> the frame that did the interrupting.  But maybe that's backwards -- if
> >> we have DWARF, then the regs correspond to the regs at the time of a
> >> call, and those regs are reasonably likely to contain the arguments to
> >> the called function.
> >>
> >> But regardless of which way this goes, it seems quite awkward to me
> >> that regs->ip never shows up as the return addr of any frame as
> >> exposed by the unwind API.
> >
> > Again, regs->ip is special.  It's not a call return address and we
> > shouldn't force it to be.
> 
> This is only mostly true.  If the exception was a trap, then it is
> (e.g. if a function ends in int3, then regs->ip will be off the end).
> But that's just me being pedantic.
> 
> More relevantly, regs->ip is a reliable address indicating a function
> that will be returned to if we ever return, and both
> show_trace_log_lvl() and the livepatch stuff should interpret it as
> such.

Actually livepatch doesn't care; once it sees that there are regs, it
will bail because the stack is unreliable.

> Whether this means the unwinder should change or
> show_trace_log_lvl() should change isn't a big deal, but I think one
> of them should change so we get this right.

I have no problem doing so, but can you clarify what you mean?  Earlier
you said:

  "IIRC we don't show the actual faulting function in the call trace, so
  we probably shouldn't duplicate the entry after the show_regs."

Maybe I'm misunderstanding, but that seems to contradict what you're
saying now.  So which is it?  Do you want the RIP address printed twice
(both in the regs printout and in the stack trace)?  Or not?

-- 
Josh

[toc] | [prev] | [next] | [standalone]

#1448179 — [PATCH 08/19] x86/dumpstack: don't disable preemption in show_stack_log_lvl() and dump_trace()

show_stack_log_lvl() and dump_trace() are already preemption safe:

- If they're running in irq or exception context, preemption is already
  disabled, and the percpu irq stack pointers can be trusted.

- If they're running with preemption enabled, they must be running on
  the task stack anyway, so it doesn't matter if they're comparing the
  stack pointer against the percpu irq stack pointer from this CPU or
  another one: either way it won't match.

Signed-off-by: Josh Poimboeuf <jpoimboe@redhat.com>
---
 arch/x86/kernel/dumpstack_32.c | 14 ++++++--------
 arch/x86/kernel/dumpstack_64.c | 29 ++++++++++-------------------
 2 files changed, 16 insertions(+), 27 deletions(-)

diff --git a/arch/x86/kernel/dumpstack_32.c b/arch/x86/kernel/dumpstack_32.c
index c533b8b..b07d5c9 100644
--- a/arch/x86/kernel/dumpstack_32.c
+++ b/arch/x86/kernel/dumpstack_32.c
@@ -24,16 +24,16 @@ static void *is_irq_stack(void *p, void *irq)
 }
 
 
-static void *is_hardirq_stack(unsigned long *stack, int cpu)
+static void *is_hardirq_stack(unsigned long *stack)
 {
-	void *irq = per_cpu(hardirq_stack, cpu);
+	void *irq = this_cpu_read(hardirq_stack);
 
 	return is_irq_stack(stack, irq);
 }
 
-static void *is_softirq_stack(unsigned long *stack, int cpu)
+static void *is_softirq_stack(unsigned long *stack);
 {
-	void *irq = per_cpu(softirq_stack, cpu);
+	void *irq = this_cpu_read(softirq_stack);
 
 	return is_irq_stack(stack, irq);
 }
@@ -42,7 +42,6 @@ void dump_trace(struct task_struct *task, struct pt_regs *regs,
 		unsigned long *stack, unsigned long bp,
 		const struct stacktrace_ops *ops, void *data)
 {
-	const unsigned cpu = get_cpu();
 	int graph = 0;
 	u32 *prev_esp;
 
@@ -53,9 +52,9 @@ void dump_trace(struct task_struct *task, struct pt_regs *regs,
 	for (;;) {
 		void *end_stack;
 
-		end_stack = is_hardirq_stack(stack, cpu);
+		end_stack = is_hardirq_stack(stack);
 		if (!end_stack)
-			end_stack = is_softirq_stack(stack, cpu);
+			end_stack = is_softirq_stack(stack);
 
 		bp = ops->walk_stack(task, stack, bp, ops, data,
 				     end_stack, &graph);
@@ -74,7 +73,6 @@ void dump_trace(struct task_struct *task, struct pt_regs *regs,
 			break;
 		touch_nmi_watchdog();
 	}
-	put_cpu();
 }
 EXPORT_SYMBOL(dump_trace);
 
diff --git a/arch/x86/kernel/dumpstack_64.c b/arch/x86/kernel/dumpstack_64.c
index 6a2d14e..634ed22 100644
--- a/arch/x86/kernel/dumpstack_64.c
+++ b/arch/x86/kernel/dumpstack_64.c
@@ -31,8 +31,8 @@ static char x86_stack_ids[][8] = {
 #endif
 };
 
-static unsigned long *in_exception_stack(unsigned cpu, unsigned long stack,
-					 unsigned *usedp, char **idp)
+static unsigned long *in_exception_stack(unsigned long stack, unsigned *usedp,
+					 char **idp)
 {
 	unsigned k;
 
@@ -41,7 +41,7 @@ static unsigned long *in_exception_stack(unsigned cpu, unsigned long stack,
 	 * 'stack' is in one of them:
 	 */
 	for (k = 0; k < N_EXCEPTION_STACKS; k++) {
-		unsigned long end = per_cpu(orig_ist, cpu).ist[k];
+		unsigned long end = this_cpu_ptr(&orig_ist)->ist[k];
 		/*
 		 * Is 'stack' above this exception frame's end?
 		 * If yes then skip to the next frame.
@@ -111,7 +111,7 @@ enum stack_type {
 };
 
 static enum stack_type
-analyze_stack(int cpu, struct task_struct *task, unsigned long *stack,
+analyze_stack(struct task_struct *task, unsigned long *stack,
 	      unsigned long **stack_end, unsigned long *irq_stack,
 	      unsigned *used, char **id)
 {
@@ -121,8 +121,7 @@ analyze_stack(int cpu, struct task_struct *task, unsigned long *stack,
 	if ((unsigned long)task_stack_page(task) == addr)
 		return STACK_IS_NORMAL;
 
-	*stack_end = in_exception_stack(cpu, (unsigned long)stack,
-					used, id);
+	*stack_end = in_exception_stack((unsigned long)stack, used, id);
 	if (*stack_end)
 		return STACK_IS_EXCEPTION;
 
@@ -149,8 +148,7 @@ void dump_trace(struct task_struct *task, struct pt_regs *regs,
 		unsigned long *stack, unsigned long bp,
 		const struct stacktrace_ops *ops, void *data)
 {
-	const unsigned cpu = get_cpu();
-	unsigned long *irq_stack = (unsigned long *)per_cpu(irq_stack_ptr, cpu);
+	unsigned long *irq_stack = (unsigned long *)this_cpu_read(irq_stack_ptr);
 	unsigned used = 0;
 	int graph = 0;
 	int done = 0;
@@ -169,8 +167,8 @@ void dump_trace(struct task_struct *task, struct pt_regs *regs,
 		enum stack_type stype;
 		char *id;
 
-		stype = analyze_stack(cpu, task, stack, &stack_end,
-				      irq_stack, &used, &id);
+		stype = analyze_stack(task, stack, &stack_end, irq_stack, &used,
+				      &id);
 
 		/* Default finish unless specified to continue */
 		done = 1;
@@ -225,7 +223,6 @@ void dump_trace(struct task_struct *task, struct pt_regs *regs,
 	 * This handles the process stack:
 	 */
 	bp = ops->walk_stack(task, stack, bp, ops, data, NULL, &graph);
-	put_cpu();
 }
 EXPORT_SYMBOL(dump_trace);
 
@@ -236,15 +233,10 @@ show_stack_log_lvl(struct task_struct *task, struct pt_regs *regs,
 	unsigned long *irq_stack_end;
 	unsigned long *irq_stack;
 	unsigned long *stack;
-	int cpu;
 	int i;
 
-	preempt_disable();
-	cpu = smp_processor_id();
-
-	irq_stack_end	= (unsigned long *)(per_cpu(irq_stack_ptr, cpu));
-	irq_stack	= (unsigned long *)(per_cpu(irq_stack_ptr, cpu) -
-			  IRQ_USABLE_STACK_SIZE);
+	irq_stack_end	= (unsigned long *)this_cpu_read(irq_stack_ptr);
+	irq_stack	= irq_stack_end - IRQ_USABLE_STACK_SIZE;
 
 	sp = sp ? : get_stack_pointer(task, regs);
 
@@ -275,7 +267,6 @@ show_stack_log_lvl(struct task_struct *task, struct pt_regs *regs,
 		stack++;
 		touch_nmi_watchdog();
 	}
-	preempt_enable();
 
 	pr_cont("\n");
 	show_trace_log_lvl(task, regs, sp, bp, log_lvl);
-- 
2.7.4

[toc] | [prev] | [next] | [standalone]

#1448180 — [PATCH 14/19] oprofile/x86: convert x86_backtrace() to the new unwinder

Convert oprofile's x86_backtrace() to the new unwinder.  dump_trace()
has been deprecated.

Cc: Robert Richter <rric@kernel.org>
Cc: oprofile-list@lists.sf.net
Signed-off-by: Josh Poimboeuf <jpoimboe@redhat.com>
---
 arch/x86/oprofile/backtrace.c | 42 +++++++++++++++++++-----------------------
 1 file changed, 19 insertions(+), 23 deletions(-)

diff --git a/arch/x86/oprofile/backtrace.c b/arch/x86/oprofile/backtrace.c
index c594768..6cda1f4 100644
--- a/arch/x86/oprofile/backtrace.c
+++ b/arch/x86/oprofile/backtrace.c
@@ -16,27 +16,7 @@
 
 #include <asm/ptrace.h>
 #include <asm/stacktrace.h>
-
-static int backtrace_stack(void *data, char *name)
-{
-	/* Yes, we want all stacks */
-	return 0;
-}
-
-static int backtrace_address(void *data, unsigned long addr, int reliable)
-{
-	unsigned int *depth = data;
-
-	if ((*depth)--)
-		oprofile_add_trace(addr);
-	return 0;
-}
-
-static struct stacktrace_ops backtrace_ops = {
-	.stack		= backtrace_stack,
-	.address	= backtrace_address,
-	.walk_stack	= print_context_stack,
-};
+#include <asm/unwind.h>
 
 #ifdef CONFIG_COMPAT
 static struct stack_frame_ia32 *
@@ -113,8 +93,24 @@ x86_backtrace(struct pt_regs * const regs, unsigned int depth)
 	struct stack_frame *head = (struct stack_frame *)frame_pointer(regs);
 
 	if (!user_mode(regs)) {
-		if (depth)
-			dump_trace(NULL, regs, NULL, 0, &backtrace_ops, &depth);
+		struct unwind_state state;
+		unsigned long addr;
+
+		if (!depth)
+			return;
+
+		oprofile_add_trace(regs->ip);
+
+		if (!--depth)
+			return;
+
+		for (unwind_start(&state, NULL, regs, NULL);
+		     !unwind_done(&state); unwind_next_frame(&state)) {
+			addr = unwind_get_return_address(&state);
+			oprofile_add_trace(addr);
+			if (!--depth)
+				break;
+		}
 		return;
 	}
 
-- 
2.7.4

[toc] | [prev] | [next] | [standalone]

#1448181 — [PATCH 06/19] x86/dumpstack: remove extra brackets around "EOE"

When starting the dump of an exception stack, it shows "<<EOE>>" instead
of "<EOE>".  print_trace_stack() already adds brackets, no need to add
them again.

Signed-off-by: Josh Poimboeuf <jpoimboe@redhat.com>
---
 arch/x86/kernel/dumpstack_64.c | 2 +-
 1 file changed, 1 insertion(+), 1 deletion(-)

diff --git a/arch/x86/kernel/dumpstack_64.c b/arch/x86/kernel/dumpstack_64.c
index 360f2e8..55cc88f 100644
--- a/arch/x86/kernel/dumpstack_64.c
+++ b/arch/x86/kernel/dumpstack_64.c
@@ -191,7 +191,7 @@ void dump_trace(struct task_struct *task, struct pt_regs *regs,
 
 			bp = ops->walk_stack(task, stack, bp, ops,
 					     data, stack_end, &graph);
-			ops->stack(data, "<EOE>");
+			ops->stack(data, "EOE");
 			/*
 			 * We link to the next stack via the
 			 * second-to-last pointer (index -2 to end) in the
-- 
2.7.4

[toc] | [prev] | [next] | [standalone]

#1448183 — [PATCH 10/19] x86/dumpstack: add get_stack_info() interface

valid_stack_ptr() is buggy: it assumes that all stacks are of size
THREAD_SIZE, which is not true for exception stacks.  So the
walk_stack() callbacks will need to know the location of the beginning
of the stack as well as the end.

Another issue is that in general the various features of a stack (type,
size, next stack pointer, description string) are scattered around in
various places throughout the stack dump code.

Encapsulate all that information in a single place with a new stack_info
struct and a get_stack_info() interface.

Signed-off-by: Josh Poimboeuf <jpoimboe@redhat.com>
---
 arch/x86/events/core.c            |   2 +-
 arch/x86/include/asm/stacktrace.h |  41 +++++++++-
 arch/x86/kernel/dumpstack.c       |  42 ++++++-----
 arch/x86/kernel/dumpstack_32.c    | 100 ++++++++++++++++++------
 arch/x86/kernel/dumpstack_64.c    | 155 ++++++++++++++++++++------------------
 arch/x86/kernel/stacktrace.c      |   2 +-
 6 files changed, 218 insertions(+), 124 deletions(-)

diff --git a/arch/x86/events/core.c b/arch/x86/events/core.c
index fad9788..f388f57 100644
--- a/arch/x86/events/core.c
+++ b/arch/x86/events/core.c
@@ -2248,7 +2248,7 @@ void arch_perf_update_userpage(struct perf_event *event,
  * callchain support
  */
 
-static int backtrace_stack(void *data, char *name)
+static int backtrace_stack(void *data, const char *name)
 {
 	return 0;
 }
diff --git a/arch/x86/include/asm/stacktrace.h b/arch/x86/include/asm/stacktrace.h
index 5d3d258..647ce3f 100644
--- a/arch/x86/include/asm/stacktrace.h
+++ b/arch/x86/include/asm/stacktrace.h
@@ -9,6 +9,39 @@
 #include <linux/uaccess.h>
 #include <linux/ptrace.h>
 
+enum stack_type {
+	STACK_TYPE_UNKNOWN,
+	STACK_TYPE_TASK,
+	STACK_TYPE_IRQ,
+	STACK_TYPE_SOFTIRQ,
+	STACK_TYPE_EXCEPTION,
+	STACK_TYPE_EXCEPTION_LAST = STACK_TYPE_EXCEPTION + N_EXCEPTION_STACKS-1,
+};
+
+struct stack_info {
+	enum stack_type type;
+	unsigned long *begin, *end, *next;
+};
+
+bool in_task_stack(unsigned long *stack, struct task_struct *task,
+		   struct stack_info *info, unsigned long *visit_mask);
+
+int get_stack_info(unsigned long *stack, struct task_struct *task,
+		   struct stack_info *info, unsigned long *visit_mask);
+
+void stack_type_str(enum stack_type type, const char **begin,
+		    const char **end);
+
+static inline bool on_stack(struct stack_info *info, void *addr, size_t len)
+{
+	void *begin = info->begin;
+	void *end   = info->end;
+
+	return (info->type != STACK_TYPE_UNKNOWN &&
+		addr >= begin && addr < end &&
+		addr + len > begin && addr + len <= end);
+}
+
 extern int kstack_depth_to_print;
 
 struct thread_info;
@@ -32,27 +65,27 @@ typedef unsigned long (*walk_stack_t)(struct task_struct *task,
 				      unsigned long bp,
 				      const struct stacktrace_ops *ops,
 				      void *data,
-				      unsigned long *end,
+				      struct stack_info *info,
 				      int *graph);
 
 extern unsigned long
 print_context_stack(struct task_struct *task,
 		    unsigned long *stack, unsigned long bp,
 		    const struct stacktrace_ops *ops, void *data,
-		    unsigned long *end, int *graph);
+		    struct stack_info *info, int *graph);
 
 extern unsigned long
 print_context_stack_bp(struct task_struct *task,
 		       unsigned long *stack, unsigned long bp,
 		       const struct stacktrace_ops *ops, void *data,
-		       unsigned long *end, int *graph);
+		       struct stack_info *info, int *graph);
 
 /* Generic stack tracer with callbacks */
 
 struct stacktrace_ops {
 	int (*address)(void *data, unsigned long address, int reliable);
 	/* On negative return stop dumping */
-	int (*stack)(void *data, char *name);
+	int (*stack)(void *data, const char *name);
 	walk_stack_t	walk_stack;
 };
 
diff --git a/arch/x86/kernel/dumpstack.c b/arch/x86/kernel/dumpstack.c
index 0a8694b..6ef8ab5 100644
--- a/arch/x86/kernel/dumpstack.c
+++ b/arch/x86/kernel/dumpstack.c
@@ -25,6 +25,25 @@ unsigned int code_bytes = 64;
 int kstack_depth_to_print = 3 * STACKSLOTS_PER_LINE;
 static int die_counter;
 
+bool in_task_stack(unsigned long *stack, struct task_struct *task,
+		   struct stack_info *info, unsigned long *visit_mask)
+{
+	unsigned long addr = (unsigned long)stack & ~(THREAD_SIZE - 1);
+
+	if ((unsigned long)task_stack_page(task) != addr)
+		return false;
+
+	if (visit_mask && test_and_set_bit(STACK_TYPE_TASK, visit_mask))
+		return false;
+
+	info->type	= STACK_TYPE_TASK;
+	info->begin	= task_stack_page(task);
+	info->end	= task_stack_page(task) + THREAD_SIZE;
+	info->next	= NULL;
+
+	return true;
+}
+
 static void printk_stack_address(unsigned long address, int reliable,
 				 char *log_lvl)
 {
@@ -67,24 +86,11 @@ ftrace_graph_ret_addr(struct task_struct *task, int *idx, unsigned long addr)
  * severe exception (double fault, nmi, stack fault, debug, mce) hardware stack
  */
 
-static inline int valid_stack_ptr(struct task_struct *task,
-			void *p, unsigned int size, void *end)
-{
-	void *t = task_stack_page(task);
-	if (end) {
-		if (p < end && p >= (end-THREAD_SIZE))
-			return 1;
-		else
-			return 0;
-	}
-	return p >= t && p < t + THREAD_SIZE - size;
-}
-
 unsigned long
 print_context_stack(struct task_struct *task,
 		unsigned long *stack, unsigned long bp,
 		const struct stacktrace_ops *ops, void *data,
-		unsigned long *end, int *graph)
+		struct stack_info *info, int *graph)
 {
 	struct stack_frame *frame = (struct stack_frame *)bp;
 
@@ -96,7 +102,7 @@ print_context_stack(struct task_struct *task,
 	    PAGE_SIZE)
 		stack = (unsigned long *)task_stack_page(task);
 
-	while (valid_stack_ptr(task, stack, sizeof(*stack), end)) {
+	while (on_stack(info, stack, sizeof(*stack))) {
 		unsigned long addr = *stack;
 
 		addr = *stack;
@@ -125,12 +131,12 @@ unsigned long
 print_context_stack_bp(struct task_struct *task,
 		       unsigned long *stack, unsigned long bp,
 		       const struct stacktrace_ops *ops, void *data,
-		       unsigned long *end, int *graph)
+		       struct stack_info *info, int *graph)
 {
 	struct stack_frame *frame = (struct stack_frame *)bp;
 	unsigned long *ret_addr = &frame->return_address;
 
-	while (valid_stack_ptr(task, ret_addr, sizeof(*ret_addr), end)) {
+	while (on_stack(info, stack, sizeof(*stack) * 2)) {
 		unsigned long addr = *ret_addr;
 
 		if (!__kernel_text_address(addr))
@@ -147,7 +153,7 @@ print_context_stack_bp(struct task_struct *task,
 }
 EXPORT_SYMBOL_GPL(print_context_stack_bp);
 
-static int print_trace_stack(void *data, char *name)
+static int print_trace_stack(void *data, const char *name)
 {
 	printk("%s <%s> ", (char *)data, name);
 	return 0;
diff --git a/arch/x86/kernel/dumpstack_32.c b/arch/x86/kernel/dumpstack_32.c
index b07d5c9..8f55ddb 100644
--- a/arch/x86/kernel/dumpstack_32.c
+++ b/arch/x86/kernel/dumpstack_32.c
@@ -16,61 +16,111 @@
 
 #include <asm/stacktrace.h>
 
-static void *is_irq_stack(void *p, void *irq)
+void stack_type_str(enum stack_type type, const char **begin, const char **end)
 {
-	if (p < irq || p >= (irq + THREAD_SIZE))
-		return NULL;
-	return irq + THREAD_SIZE;
+	switch (type) {
+	case STACK_TYPE_IRQ:
+	case STACK_TYPE_SOFTIRQ:
+		*begin = "IRQ";
+		*end   = "EOI";
+		break;
+	default:
+		*begin = NULL;
+		*end   = NULL;
+	}
 }
 
+static bool in_hardirq_stack(unsigned long *stack, struct stack_info *info,
+			     unsigned long *visit_mask)
+{
+	unsigned long *begin = (unsigned long *)this_cpu_read(hardirq_stack);
+	unsigned long *end   = begin + (THREAD_SIZE / sizeof(long));
+
+	if (stack < begin || stack >= end)
+		return false;
+
+	if (visit_mask && test_and_set_bit(STACK_TYPE_IRQ, visit_mask))
+		return false;
+
+	info->type	= STACK_TYPE_IRQ;
+	info->begin	= begin;
+	info->end	= end;
+	info->next	= (unsigned long *)*begin;
 
-static void *is_hardirq_stack(unsigned long *stack)
+	return true;
+}
+
+static bool in_softirq_stack(unsigned long *stack, struct stack_info *info,
+			     unsigned long *visit_mask)
 {
-	void *irq = this_cpu_read(hardirq_stack);
+	unsigned long *begin = (unsigned long *)this_cpu_read(softirq_stack);
+	unsigned long *end   = begin + (THREAD_SIZE / sizeof(long));
+
+	if (stack < begin || stack >= end)
+		return false;
+
+	if (visit_mask && test_and_set_bit(STACK_TYPE_SOFTIRQ, visit_mask))
+		return false;
+
+	info->type	= STACK_TYPE_SOFTIRQ;
+	info->begin	= begin;
+	info->end	= end;
+	info->next	= (unsigned long *)*begin;
 
-	return is_irq_stack(stack, irq);
+	return true;
 }
 
-static void *is_softirq_stack(unsigned long *stack);
+int get_stack_info(unsigned long *stack, struct task_struct *task,
+		   struct stack_info *info, unsigned long *visit_mask)
 {
-	void *irq = this_cpu_read(softirq_stack);
+	if (!task)
+		task = current;
 
-	return is_irq_stack(stack, irq);
+	if (task == current) {
+		if (in_hardirq_stack(stack, info, visit_mask))
+			return 0;
+
+		if (in_softirq_stack(stack, info, visit_mask))
+			return 0;
+	}
+
+	if (in_task_stack(stack, task, info, visit_mask))
+		return 0;
+
+	info->type = STACK_TYPE_UNKNOWN;
+	return -EINVAL;
 }
 
 void dump_trace(struct task_struct *task, struct pt_regs *regs,
 		unsigned long *stack, unsigned long bp,
 		const struct stacktrace_ops *ops, void *data)
 {
+	unsigned long visit_mask = 0;
 	int graph = 0;
-	u32 *prev_esp;
 
 	task = task ? : current;
 	stack = stack ? : get_stack_pointer(task, regs);
 	bp = bp ? : (unsigned long)get_frame_pointer(task, regs);
 
 	for (;;) {
-		void *end_stack;
+		const char *begin_str, *end_str;
+		struct stack_info info;
 
-		end_stack = is_hardirq_stack(stack);
-		if (!end_stack)
-			end_stack = is_softirq_stack(stack);
+		if (get_stack_info(stack, task, &info, &visit_mask))
+			break;
 
-		bp = ops->walk_stack(task, stack, bp, ops, data,
-				     end_stack, &graph);
+		stack_type_str(info.type, &begin_str, &end_str);
 
-		/* Stop if not on irq stack */
-		if (!end_stack)
+		if (begin_str && ops->stack(data, begin_str) < 0)
 			break;
 
-		/* The previous esp is saved on the bottom of the stack */
-		prev_esp = (u32 *)(end_stack - THREAD_SIZE);
-		stack = (unsigned long *)*prev_esp;
-		if (!stack)
-			break;
+		bp = ops->walk_stack(task, stack, bp, ops, data, &info, &graph);
 
-		if (ops->stack(data, "IRQ") < 0)
+		if (end_str && ops->stack(data, end_str) < 0)
 			break;
+
+		stack = info.next;
+
 		touch_nmi_watchdog();
 	}
 }
diff --git a/arch/x86/kernel/dumpstack_64.c b/arch/x86/kernel/dumpstack_64.c
index 0641d75..e1a5b6f 100644
--- a/arch/x86/kernel/dumpstack_64.c
+++ b/arch/x86/kernel/dumpstack_64.c
@@ -28,8 +28,27 @@ static unsigned long exception_stack_sizes[N_EXCEPTION_STACKS] = {
 	[DEBUG_STACK - 1]			= DEBUG_STKSZ
 };
 
-static unsigned long *in_exception_stack(unsigned long *s, char **name,
-					 unsigned long *visit_mask)
+void stack_type_str(enum stack_type type, const char **begin, const char **end)
+{
+	BUILD_BUG_ON(N_EXCEPTION_STACKS != 4);
+
+	switch (type) {
+	case STACK_TYPE_IRQ:
+		*begin = "IRQ";
+		*end   = "EOI";
+		break;
+	case STACK_TYPE_EXCEPTION ... STACK_TYPE_EXCEPTION_LAST:
+		*begin = exception_stack_names[type - STACK_TYPE_EXCEPTION];
+		*end   = "EOE";
+		break;
+	default:
+		*begin = NULL;
+		*end   = NULL;
+	}
+}
+
+static bool in_exception_stack(unsigned long *s, struct stack_info *info,
+			       unsigned long *visit_mask)
 {
 	unsigned long stack = (unsigned long)s;
 	unsigned long begin, end;
@@ -44,55 +63,62 @@ static unsigned long *in_exception_stack(unsigned long *s, char **name,
 		if (stack < begin || stack >= end)
 			continue;
 
-		if (test_and_set_bit(k, visit_mask))
+		if (visit_mask &&
+		    test_and_set_bit(STACK_TYPE_EXCEPTION + k, visit_mask))
 			return false;
 
-		*name = exception_stack_names[k];
-		return (unsigned long *)end;
+		info->type	= STACK_TYPE_EXCEPTION + k;
+		info->begin	= (unsigned long *)begin;
+		info->end	= (unsigned long *)end;
+		info->next	= (unsigned long *)info->end[-2];
+
+		return true;
 	}
 
-	return NULL;
+	return false;
 }
 
-static inline int
-in_irq_stack(unsigned long *stack, unsigned long *irq_stack,
-	     unsigned long *irq_stack_end)
+static bool in_irq_stack(unsigned long *stack, struct stack_info *info,
+			 unsigned long *visit_mask)
 {
-	return (stack >= irq_stack && stack < irq_stack_end);
-}
+	unsigned long *end   = (unsigned long *)this_cpu_read(irq_stack_ptr);
+	unsigned long *begin = end - (IRQ_USABLE_STACK_SIZE / sizeof(long));
 
-enum stack_type {
-	STACK_IS_UNKNOWN,
-	STACK_IS_NORMAL,
-	STACK_IS_EXCEPTION,
-	STACK_IS_IRQ,
-};
+	if (stack < begin || stack >= end)
+		return false;
 
-static enum stack_type
-analyze_stack(struct task_struct *task, unsigned long *stack,
-	      unsigned long **stack_end, unsigned long *irq_stack,
-	      unsigned long *visit_mask, char **name)
-{
-	unsigned long addr;
+	if (visit_mask && test_and_set_bit(STACK_TYPE_IRQ, visit_mask))
+		return false;
 
-	addr = ((unsigned long)stack & (~(THREAD_SIZE - 1)));
-	if ((unsigned long)task_stack_page(task) == addr)
-		return STACK_IS_NORMAL;
+	info->type	= STACK_TYPE_IRQ;
+	info->begin	= begin;
+	info->end	= end;
+	info->next	= (unsigned long *)end[-1];
 
-	*stack_end = in_exception_stack(stack, name, visit_mask);
-	if (*stack_end)
-		return STACK_IS_EXCEPTION;
+	return true;
+}
 
-	if (!irq_stack)
-		return STACK_IS_NORMAL;
+int get_stack_info(unsigned long *stack, struct task_struct *task,
+		   struct stack_info *info, unsigned long *visit_mask)
+{
+	if (!task)
+		task = current;
+
+	if (in_task_stack(stack, task, info, visit_mask))
+		return 0;
 
-	*stack_end = irq_stack;
-	irq_stack -= (IRQ_USABLE_STACK_SIZE / sizeof(long));
+	if (task != current)
+		goto unknown;
+
+	if (in_exception_stack(stack, info, visit_mask))
+		return 0;
 
-	if (in_irq_stack(stack, irq_stack, *stack_end))
-		return STACK_IS_IRQ;
+	if (in_irq_stack(stack, info, visit_mask))
+		return 0;
 
-	return STACK_IS_UNKNOWN;
+unknown:
+	info->type = STACK_TYPE_UNKNOWN;
+	return -EINVAL;
 }
 
 /*
@@ -106,8 +132,8 @@ void dump_trace(struct task_struct *task, struct pt_regs *regs,
 		unsigned long *stack, unsigned long bp,
 		const struct stacktrace_ops *ops, void *data)
 {
-	unsigned long *irq_stack = (unsigned long *)this_cpu_read(irq_stack_ptr);
 	unsigned long visit_mask = 0;
+	struct stack_info info;
 	int graph = 0;
 	int done = 0;
 
@@ -121,57 +147,37 @@ void dump_trace(struct task_struct *task, struct pt_regs *regs,
 	 * exceptions
 	 */
 	while (!done) {
-		unsigned long *stack_end;
-		enum stack_type stype;
-		char *name;
+		const char *begin_str, *end_str;
 
-		stype = analyze_stack(task, stack, &stack_end, irq_stack,
-				      &visit_mask, &name);
+		get_stack_info(stack, task, &info, &visit_mask);
 
 		/* Default finish unless specified to continue */
 		done = 1;
 
-		switch (stype) {
+		switch (info.type) {
 
 		/* Break out early if we are on the thread stack */
-		case STACK_IS_NORMAL:
+		case STACK_TYPE_TASK:
 			break;
 
-		case STACK_IS_EXCEPTION:
+		case STACK_TYPE_IRQ:
+		case STACK_TYPE_EXCEPTION ... STACK_TYPE_EXCEPTION_LAST:
+
+			stack_type_str(info.type, &begin_str, &end_str);
 
-			if (ops->stack(data, name) < 0)
+			if (ops->stack(data, begin_str) < 0)
 				break;
 
 			bp = ops->walk_stack(task, stack, bp, ops,
-					     data, stack_end, &graph);
-			ops->stack(data, "EOE");
-			/*
-			 * We link to the next stack via the
-			 * second-to-last pointer (index -2 to end) in the
-			 * exception stack:
-			 */
-			stack = (unsigned long *) stack_end[-2];
-			done = 0;
-			break;
+					     data, &info, &graph);
 
-		case STACK_IS_IRQ:
+			ops->stack(data, end_str);
 
-			if (ops->stack(data, "IRQ") < 0)
-				break;
-			bp = ops->walk_stack(task, stack, bp,
-				     ops, data, stack_end, &graph);
-			/*
-			 * We link to the next stack (which would be
-			 * the process stack normally) the last
-			 * pointer (index -1 to end) in the IRQ stack:
-			 */
-			stack = (unsigned long *) (stack_end[-1]);
-			irq_stack = NULL;
-			ops->stack(data, "EOI");
+			stack = info.next;
 			done = 0;
 			break;
 
-		case STACK_IS_UNKNOWN:
+		default:
 			ops->stack(data, "UNK");
 			break;
 		}
@@ -180,7 +186,7 @@ void dump_trace(struct task_struct *task, struct pt_regs *regs,
 	/*
 	 * This handles the process stack:
 	 */
-	bp = ops->walk_stack(task, stack, bp, ops, data, NULL, &graph);
+	bp = ops->walk_stack(task, stack, bp, ops, data, &info, &graph);
 }
 EXPORT_SYMBOL(dump_trace);
 
@@ -188,13 +194,12 @@ void
 show_stack_log_lvl(struct task_struct *task, struct pt_regs *regs,
 		   unsigned long *sp, unsigned long bp, char *log_lvl)
 {
-	unsigned long *irq_stack_end;
-	unsigned long *irq_stack;
+	unsigned long *irq_stack, *irq_stack_end;
 	unsigned long *stack;
 	int i;
 
-	irq_stack_end	= (unsigned long *)this_cpu_read(irq_stack_ptr);
-	irq_stack	= irq_stack_end - IRQ_USABLE_STACK_SIZE;
+	irq_stack_end = (unsigned long *)this_cpu_read(irq_stack_ptr);
+	irq_stack     = irq_stack_end - IRQ_USABLE_STACK_SIZE;
 
 	sp = sp ? : get_stack_pointer(task, regs);
 
diff --git a/arch/x86/kernel/stacktrace.c b/arch/x86/kernel/stacktrace.c
index 4738f5e..785aef1 100644
--- a/arch/x86/kernel/stacktrace.c
+++ b/arch/x86/kernel/stacktrace.c
@@ -9,7 +9,7 @@
 #include <linux/uaccess.h>
 #include <asm/stacktrace.h>
 
-static int save_stack_stack(void *data, char *name)
+static int save_stack_stack(void *data, const char *name)
 {
 	return 0;
 }
-- 
2.7.4

[toc] | [prev] | [next] | [standalone]

Page 1 of 3  [1] 2 3  Next page →

Back to top | Article view | linux.kernel

csiph-web