diff mbox series

[01/50] kallsyms/printk: Add loglvl to print_ip_sym()

Message ID 20191106030542.868541-2-dima@arista.com (mailing list archive)
State New, archived
Headers show
Series Add log level to show_stack() | expand

Commit Message

Dmitry Safonov Nov. 6, 2019, 3:04 a.m. UTC 
print_ip_sym() needs to have a log level parameter to comply with other
parts being printed. Otherwise, half of the expected backtrace would be
printed and other may be missing with some logging level.

The following callee(s) are using now the adjusted log level:
- microblaze/unwind: the same level as headers & userspace unwind.
  Note that pr_debug()'s there are for debugging the unwinder itself.
- nds32/traps: symbol addresses are printed with the same log level
  as backtrace headers.
- lockdep: ip for locking issues is printed with the same log level
  as other part of the warning.
- sched: ip where preemption was disabled is printed as error like
  the rest part of the message.
- ftrace: bug reports are now consistent in the log level being used.

Cc: Albert Ou <aou@eecs.berkeley.edu>
Cc: Ben Segall <bsegall@google.com>
Cc: Dietmar Eggemann <dietmar.eggemann@arm.com>
Cc: Greentime Hu <green.hu@gmail.com>
Cc: Greg Kroah-Hartman <gregkh@linuxfoundation.org>
Cc: Ingo Molnar <mingo@redhat.com>
Cc: James Hogan <jhogan@kernel.org>
Cc: Juri Lelli <juri.lelli@redhat.com>
Cc: Mel Gorman <mgorman@suse.de>
Cc: Michal Simek <monstr@monstr.eu>
Cc: Palmer Dabbelt <palmer@dabbelt.com>
Cc: Paul Burton <paulburton@kernel.org>
Cc: Paul Walmsley <paul.walmsley@sifive.com>
Cc: Peter Zijlstra <peterz@infradead.org>
Cc: Ralf Baechle <ralf@linux-mips.org>
Cc: Steven Rostedt <rostedt@goodmis.org>
Cc: Thomas Gleixner <tglx@linutronix.de>
Cc: Vincent Chen <deanbo422@gmail.com>
Cc: Vincent Guittot <vincent.guittot@linaro.org>
Cc: Will Deacon <will@kernel.org>
Cc: linux-mips@vger.kernel.org
Cc: linux-riscv@lists.infradead.org
Signed-off-by: Dmitry Safonov <dima@arista.com>
---
 arch/microblaze/kernel/unwind.c | 2 +-
 arch/mips/kernel/traps.c        | 4 ++--
 arch/nds32/kernel/traps.c       | 4 ++--
 arch/riscv/kernel/stacktrace.c  | 2 +-
 include/linux/kallsyms.h        | 4 ++--
 kernel/locking/lockdep.c        | 4 ++--
 kernel/sched/core.c             | 4 ++--
 kernel/trace/ftrace.c           | 8 ++++----
 8 files changed, 16 insertions(+), 16 deletions(-)

Comments

Sergey Senozhatsky Nov. 6, 2019, 4:38 a.m. UTC | #1 
On (19/11/06 03:04), Dmitry Safonov wrote:
[..]
>  #endif /*_LINUX_KALLSYMS_H*/
> diff --git a/kernel/locking/lockdep.c b/kernel/locking/lockdep.c
> index 233459c03b5a..914ff610b880 100644
> --- a/kernel/locking/lockdep.c
> +++ b/kernel/locking/lockdep.c
> @@ -3999,7 +3999,7 @@ static void print_unlock_imbalance_bug(struct task_struct *curr,
>  		curr->comm, task_pid_nr(curr));
>  	print_lockdep_cache(lock);
>  	pr_cont(") at:\n");
> -	print_ip_sym(ip);
> +	print_ip_sym(KERN_WARNING, ip);
>  	pr_warn("but there are no more locks to release!\n");
>  	pr_warn("\nother info that might help us debug this:\n");
>  	lockdep_print_held_locks(curr);
> @@ -4604,7 +4604,7 @@ static void print_lock_contention_bug(struct task_struct *curr,
>  		curr->comm, task_pid_nr(curr));
>  	print_lockdep_cache(lock);
>  	pr_cont(") at:\n");
> -	print_ip_sym(ip);
> +	print_ip_sym(KERN_WARNING, ip);
>  	pr_warn("but there are no locks held!\n");
>  	pr_warn("\nother info that might help us debug this:\n");
>  	lockdep_print_held_locks(curr);
> diff --git a/kernel/sched/core.c b/kernel/sched/core.c
> index dd05a378631a..774ff0d8dfe9 100644
> --- a/kernel/sched/core.c
> +++ b/kernel/sched/core.c
> @@ -3858,7 +3858,7 @@ static noinline void __schedule_bug(struct task_struct *prev)
>  	if (IS_ENABLED(CONFIG_DEBUG_PREEMPT)
>  	    && in_atomic_preempt_off()) {
>  		pr_err("Preemption disabled at:");
> -		print_ip_sym(preempt_disable_ip);
> +		print_ip_sym(KERN_ERR, preempt_disable_ip);
>  		pr_cont("\n");

Is this working with pr_cont()?

	-ss
Dmitry Safonov Nov. 6, 2019, 4:39 p.m. UTC | #2 
Hi Sergey,

On 11/6/19 4:38 AM, Sergey Senozhatsky wrote:
> On (19/11/06 03:04), Dmitry Safonov wrote:
> [..]
>> diff --git a/kernel/sched/core.c b/kernel/sched/core.c
>> index dd05a378631a..774ff0d8dfe9 100644
>> --- a/kernel/sched/core.c
>> +++ b/kernel/sched/core.c
>> @@ -3858,7 +3858,7 @@ static noinline void __schedule_bug(struct task_struct *prev)
>>  	if (IS_ENABLED(CONFIG_DEBUG_PREEMPT)
>>  	    && in_atomic_preempt_off()) {
>>  		pr_err("Preemption disabled at:");
>> -		print_ip_sym(preempt_disable_ip);
>> +		print_ip_sym(KERN_ERR, preempt_disable_ip);
>>  		pr_cont("\n");
> 
> Is this working with pr_cont()?

print_ip_sym() will cause log_store()..
And pr_cont("\n") will go here:
:	/* Skip empty continuation lines that couldn't be added - they just
flush */
:	if (!text_len && (lflags & LOG_CONT))
:		return 0;

So it doesn't do anything. I didn't want to change any behavior in the
patch, but seems that I can remove this pr_cont() while at here.

Thanks,
          Dmitry
Steven Rostedt Nov. 13, 2019, 3:49 p.m. UTC | #3 
On Wed,  6 Nov 2019 03:04:52 +0000
Dmitry Safonov <dima@arista.com> wrote:

> --- a/kernel/trace/ftrace.c
> +++ b/kernel/trace/ftrace.c
> @@ -2002,12 +2002,12 @@ void ftrace_bug(int failed, struct dyn_ftrace *rec)
>  	case -EFAULT:
>  		FTRACE_WARN_ON_ONCE(1);
>  		pr_info("ftrace faulted on modifying ");

Hmm, I wonder if I should change that from info to something more
important, as this is important information for debugging. But this has
nothing to do with this patch set.

> -		print_ip_sym(ip);
> +		print_ip_sym(KERN_INFO, ip);

Acked-by: Steven Rostedt (VMware) <rostedt@goodmis.org>

-- Steve

>  		break;
>  	case -EINVAL:
>  		FTRACE_WARN_ON_ONCE(1);
>  		pr_info("ftrace failed to modify ");
> -		print_ip_sym(ip);
> +		print_ip_sym(KERN_INFO, ip);
>  		print_ip_ins(" actual:   ", (unsigned char *)ip);
>  		pr_cont("\n");
>  		if (ftrace_expected) {
> @@ -2018,12 +2018,12 @@ void ftrace_bug(int failed, struct dyn_ftrace *rec)
>  	case -EPERM:
>  		FTRACE_WARN_ON_ONCE(1);
>  		pr_info("ftrace faulted on writing ");
> -		print_ip_sym(ip);
> +		print_ip_sym(KERN_INFO, ip);
>  		break;
>  	default:
>  		FTRACE_WARN_ON_ONCE(1);
>  		pr_info("ftrace faulted on unknown error ");
> -		print_ip_sym(ip);
> +		print_ip_sym(KERN_INFO, ip);
>  	}
>  	print_bug_type();
>  	if (rec) {
diff mbox series

Patch

diff --git a/arch/microblaze/kernel/unwind.c b/arch/microblaze/kernel/unwind.c
index 34c270cb11fc..4241cdd28ee7 100644
--- a/arch/microblaze/kernel/unwind.c
+++ b/arch/microblaze/kernel/unwind.c
@@ -254,7 +254,7 @@  static void microblaze_unwind_inner(struct task_struct *task,
 					task->comm);
 				break;
 			} else
-				print_ip_sym(pc);
+				print_ip_sym(KERN_INFO, pc);
 		}
 
 		/* Stop when we reach anything not part of the kernel */
diff --git a/arch/mips/kernel/traps.c b/arch/mips/kernel/traps.c
index 342e41de9d64..861e79868055 100644
--- a/arch/mips/kernel/traps.c
+++ b/arch/mips/kernel/traps.c
@@ -123,7 +123,7 @@  static void show_raw_backtrace(unsigned long reg29)
 			break;
 		}
 		if (__kernel_text_address(addr))
-			print_ip_sym(addr);
+			print_ip_sym(KERN_DEFAULT, addr);
 	}
 	printk("\n");
 }
@@ -153,7 +153,7 @@  static void show_backtrace(struct task_struct *task, const struct pt_regs *regs)
 	}
 	printk("Call Trace:\n");
 	do {
-		print_ip_sym(pc);
+		print_ip_sym(KERN_DEFAULT, pc);
 		pc = unwind_stack(task, &sp, pc, &ra);
 	} while (pc);
 	pr_cont("\n");
diff --git a/arch/nds32/kernel/traps.c b/arch/nds32/kernel/traps.c
index f4d386b52622..40625760a125 100644
--- a/arch/nds32/kernel/traps.c
+++ b/arch/nds32/kernel/traps.c
@@ -108,7 +108,7 @@  static void __dump(struct task_struct *tsk, unsigned long *base_reg)
 			if (__kernel_text_address(ret_addr)) {
 				ret_addr = ftrace_graph_ret_addr(
 						tsk, &graph, ret_addr, NULL);
-				print_ip_sym(ret_addr);
+				print_ip_sym(KERN_EMERG, ret_addr);
 			}
 			if (--cnt < 0)
 				break;
@@ -124,7 +124,7 @@  static void __dump(struct task_struct *tsk, unsigned long *base_reg)
 
 				ret_addr = ftrace_graph_ret_addr(
 						tsk, &graph, ret_addr, NULL);
-				print_ip_sym(ret_addr);
+				print_ip_sym(KERN_EMERG, ret_addr);
 			}
 			if (--cnt < 0)
 				break;
diff --git a/arch/riscv/kernel/stacktrace.c b/arch/riscv/kernel/stacktrace.c
index 0940681d2f68..a76892b48fff 100644
--- a/arch/riscv/kernel/stacktrace.c
+++ b/arch/riscv/kernel/stacktrace.c
@@ -98,7 +98,7 @@  static void notrace walk_stackframe(struct task_struct *task,
 
 static bool print_trace_address(unsigned long pc, void *arg)
 {
-	print_ip_sym(pc);
+	print_ip_sym(KERN_DEFAULT, pc);
 	return false;
 }
 
diff --git a/include/linux/kallsyms.h b/include/linux/kallsyms.h
index 657a83b943f0..98338dc6b5d2 100644
--- a/include/linux/kallsyms.h
+++ b/include/linux/kallsyms.h
@@ -165,9 +165,9 @@  static inline int kallsyms_show_value(void)
 
 #endif /*CONFIG_KALLSYMS*/
 
-static inline void print_ip_sym(unsigned long ip)
+static inline void print_ip_sym(const char *loglvl, unsigned long ip)
 {
-	printk("[<%px>] %pS\n", (void *) ip, (void *) ip);
+	printk("%s[<%px>] %pS\n", loglvl, (void *) ip, (void *) ip);
 }
 
 #endif /*_LINUX_KALLSYMS_H*/
diff --git a/kernel/locking/lockdep.c b/kernel/locking/lockdep.c
index 233459c03b5a..914ff610b880 100644
--- a/kernel/locking/lockdep.c
+++ b/kernel/locking/lockdep.c
@@ -3999,7 +3999,7 @@  static void print_unlock_imbalance_bug(struct task_struct *curr,
 		curr->comm, task_pid_nr(curr));
 	print_lockdep_cache(lock);
 	pr_cont(") at:\n");
-	print_ip_sym(ip);
+	print_ip_sym(KERN_WARNING, ip);
 	pr_warn("but there are no more locks to release!\n");
 	pr_warn("\nother info that might help us debug this:\n");
 	lockdep_print_held_locks(curr);
@@ -4604,7 +4604,7 @@  static void print_lock_contention_bug(struct task_struct *curr,
 		curr->comm, task_pid_nr(curr));
 	print_lockdep_cache(lock);
 	pr_cont(") at:\n");
-	print_ip_sym(ip);
+	print_ip_sym(KERN_WARNING, ip);
 	pr_warn("but there are no locks held!\n");
 	pr_warn("\nother info that might help us debug this:\n");
 	lockdep_print_held_locks(curr);
diff --git a/kernel/sched/core.c b/kernel/sched/core.c
index dd05a378631a..774ff0d8dfe9 100644
--- a/kernel/sched/core.c
+++ b/kernel/sched/core.c
@@ -3858,7 +3858,7 @@  static noinline void __schedule_bug(struct task_struct *prev)
 	if (IS_ENABLED(CONFIG_DEBUG_PREEMPT)
 	    && in_atomic_preempt_off()) {
 		pr_err("Preemption disabled at:");
-		print_ip_sym(preempt_disable_ip);
+		print_ip_sym(KERN_ERR, preempt_disable_ip);
 		pr_cont("\n");
 	}
 	if (panic_on_warn)
@@ -6774,7 +6774,7 @@  void ___might_sleep(const char *file, int line, int preempt_offset)
 	if (IS_ENABLED(CONFIG_DEBUG_PREEMPT)
 	    && !preempt_count_equals(preempt_offset)) {
 		pr_err("Preemption disabled at:");
-		print_ip_sym(preempt_disable_ip);
+		print_ip_sym(KERN_ERR, preempt_disable_ip);
 		pr_cont("\n");
 	}
 	dump_stack();
diff --git a/kernel/trace/ftrace.c b/kernel/trace/ftrace.c
index f296d89be757..04a95cdf414f 100644
--- a/kernel/trace/ftrace.c
+++ b/kernel/trace/ftrace.c
@@ -2002,12 +2002,12 @@  void ftrace_bug(int failed, struct dyn_ftrace *rec)
 	case -EFAULT:
 		FTRACE_WARN_ON_ONCE(1);
 		pr_info("ftrace faulted on modifying ");
-		print_ip_sym(ip);
+		print_ip_sym(KERN_INFO, ip);
 		break;
 	case -EINVAL:
 		FTRACE_WARN_ON_ONCE(1);
 		pr_info("ftrace failed to modify ");
-		print_ip_sym(ip);
+		print_ip_sym(KERN_INFO, ip);
 		print_ip_ins(" actual:   ", (unsigned char *)ip);
 		pr_cont("\n");
 		if (ftrace_expected) {
@@ -2018,12 +2018,12 @@  void ftrace_bug(int failed, struct dyn_ftrace *rec)
 	case -EPERM:
 		FTRACE_WARN_ON_ONCE(1);
 		pr_info("ftrace faulted on writing ");
-		print_ip_sym(ip);
+		print_ip_sym(KERN_INFO, ip);
 		break;
 	default:
 		FTRACE_WARN_ON_ONCE(1);
 		pr_info("ftrace faulted on unknown error ");
-		print_ip_sym(ip);
+		print_ip_sym(KERN_INFO, ip);
 	}
 	print_bug_type();
 	if (rec) {