lockdep: Use "WARNING" tag on lockdep splats

This commit changes lockdep splats to begin lines with "WARNING" and
to use pr_warn() instead of printk().  This change eases scripted
analysis of kernel console output.

Reported-by: Dmitry Vyukov <dvyukov@google.com>
Reported-by: Ingo Molnar <mingo@kernel.org>
Signed-off-by: Paul E. McKenney <paulmck@linux.vnet.ibm.com>
Acked-by: Dmitry Vyukov <dvyukov@google.com>
Reviewed-by: Josh Triplett <josh@joshtriplett.org>
This commit is contained in:
Paul E. McKenney 2017-01-31 07:45:13 -08:00
parent 5f0d5a3ae7
commit a5dd63efda
2 changed files with 48 additions and 47 deletions

View File

@ -1144,10 +1144,10 @@ print_circular_bug_header(struct lock_list *entry, unsigned int depth,
return 0; return 0;
printk("\n"); printk("\n");
printk("======================================================\n"); pr_warn("======================================================\n");
printk("[ INFO: possible circular locking dependency detected ]\n"); pr_warn("WARNING: possible circular locking dependency detected\n");
print_kernel_ident(); print_kernel_ident();
printk("-------------------------------------------------------\n"); pr_warn("------------------------------------------------------\n");
printk("%s/%d is trying to acquire lock:\n", printk("%s/%d is trying to acquire lock:\n",
curr->comm, task_pid_nr(curr)); curr->comm, task_pid_nr(curr));
print_lock(check_src); print_lock(check_src);
@ -1482,11 +1482,11 @@ print_bad_irq_dependency(struct task_struct *curr,
return 0; return 0;
printk("\n"); printk("\n");
printk("======================================================\n"); pr_warn("=====================================================\n");
printk("[ INFO: %s-safe -> %s-unsafe lock order detected ]\n", pr_warn("WARNING: %s-safe -> %s-unsafe lock order detected\n",
irqclass, irqclass); irqclass, irqclass);
print_kernel_ident(); print_kernel_ident();
printk("------------------------------------------------------\n"); pr_warn("-----------------------------------------------------\n");
printk("%s/%d [HC%u[%lu]:SC%u[%lu]:HE%u:SE%u] is trying to acquire:\n", printk("%s/%d [HC%u[%lu]:SC%u[%lu]:HE%u:SE%u] is trying to acquire:\n",
curr->comm, task_pid_nr(curr), curr->comm, task_pid_nr(curr),
curr->hardirq_context, hardirq_count() >> HARDIRQ_SHIFT, curr->hardirq_context, hardirq_count() >> HARDIRQ_SHIFT,
@ -1711,10 +1711,10 @@ print_deadlock_bug(struct task_struct *curr, struct held_lock *prev,
return 0; return 0;
printk("\n"); printk("\n");
printk("=============================================\n"); pr_warn("============================================\n");
printk("[ INFO: possible recursive locking detected ]\n"); pr_warn("WARNING: possible recursive locking detected\n");
print_kernel_ident(); print_kernel_ident();
printk("---------------------------------------------\n"); pr_warn("--------------------------------------------\n");
printk("%s/%d is trying to acquire lock:\n", printk("%s/%d is trying to acquire lock:\n",
curr->comm, task_pid_nr(curr)); curr->comm, task_pid_nr(curr));
print_lock(next); print_lock(next);
@ -2061,10 +2061,10 @@ static void print_collision(struct task_struct *curr,
struct lock_chain *chain) struct lock_chain *chain)
{ {
printk("\n"); printk("\n");
printk("======================\n"); pr_warn("============================\n");
printk("[chain_key collision ]\n"); pr_warn("WARNING: chain_key collision\n");
print_kernel_ident(); print_kernel_ident();
printk("----------------------\n"); pr_warn("----------------------------\n");
printk("%s/%d: ", current->comm, task_pid_nr(current)); printk("%s/%d: ", current->comm, task_pid_nr(current));
printk("Hash chain already cached but the contents don't match!\n"); printk("Hash chain already cached but the contents don't match!\n");
@ -2360,10 +2360,10 @@ print_usage_bug(struct task_struct *curr, struct held_lock *this,
return 0; return 0;
printk("\n"); printk("\n");
printk("=================================\n"); pr_warn("================================\n");
printk("[ INFO: inconsistent lock state ]\n"); pr_warn("WARNING: inconsistent lock state\n");
print_kernel_ident(); print_kernel_ident();
printk("---------------------------------\n"); pr_warn("--------------------------------\n");
printk("inconsistent {%s} -> {%s} usage.\n", printk("inconsistent {%s} -> {%s} usage.\n",
usage_str[prev_bit], usage_str[new_bit]); usage_str[prev_bit], usage_str[new_bit]);
@ -2425,10 +2425,10 @@ print_irq_inversion_bug(struct task_struct *curr,
return 0; return 0;
printk("\n"); printk("\n");
printk("=========================================================\n"); pr_warn("========================================================\n");
printk("[ INFO: possible irq lock inversion dependency detected ]\n"); pr_warn("WARNING: possible irq lock inversion dependency detected\n");
print_kernel_ident(); print_kernel_ident();
printk("---------------------------------------------------------\n"); pr_warn("--------------------------------------------------------\n");
printk("%s/%d just changed the state of lock:\n", printk("%s/%d just changed the state of lock:\n",
curr->comm, task_pid_nr(curr)); curr->comm, task_pid_nr(curr));
print_lock(this); print_lock(this);
@ -3170,10 +3170,10 @@ print_lock_nested_lock_not_held(struct task_struct *curr,
return 0; return 0;
printk("\n"); printk("\n");
printk("==================================\n"); pr_warn("==================================\n");
printk("[ BUG: Nested lock was not taken ]\n"); pr_warn("WARNING: Nested lock was not taken\n");
print_kernel_ident(); print_kernel_ident();
printk("----------------------------------\n"); pr_warn("----------------------------------\n");
printk("%s/%d is trying to lock:\n", curr->comm, task_pid_nr(curr)); printk("%s/%d is trying to lock:\n", curr->comm, task_pid_nr(curr));
print_lock(hlock); print_lock(hlock);
@ -3383,10 +3383,10 @@ print_unlock_imbalance_bug(struct task_struct *curr, struct lockdep_map *lock,
return 0; return 0;
printk("\n"); printk("\n");
printk("=====================================\n"); pr_warn("=====================================\n");
printk("[ BUG: bad unlock balance detected! ]\n"); pr_warn("WARNING: bad unlock balance detected!\n");
print_kernel_ident(); print_kernel_ident();
printk("-------------------------------------\n"); pr_warn("-------------------------------------\n");
printk("%s/%d is trying to release lock (", printk("%s/%d is trying to release lock (",
curr->comm, task_pid_nr(curr)); curr->comm, task_pid_nr(curr));
print_lockdep_cache(lock); print_lockdep_cache(lock);
@ -3880,10 +3880,10 @@ print_lock_contention_bug(struct task_struct *curr, struct lockdep_map *lock,
return 0; return 0;
printk("\n"); printk("\n");
printk("=================================\n"); pr_warn("=================================\n");
printk("[ BUG: bad contention detected! ]\n"); pr_warn("WARNING: bad contention detected!\n");
print_kernel_ident(); print_kernel_ident();
printk("---------------------------------\n"); pr_warn("---------------------------------\n");
printk("%s/%d is trying to contend lock (", printk("%s/%d is trying to contend lock (",
curr->comm, task_pid_nr(curr)); curr->comm, task_pid_nr(curr));
print_lockdep_cache(lock); print_lockdep_cache(lock);
@ -4244,10 +4244,10 @@ print_freed_lock_bug(struct task_struct *curr, const void *mem_from,
return; return;
printk("\n"); printk("\n");
printk("=========================\n"); pr_warn("=========================\n");
printk("[ BUG: held lock freed! ]\n"); pr_warn("WARNING: held lock freed!\n");
print_kernel_ident(); print_kernel_ident();
printk("-------------------------\n"); pr_warn("-------------------------\n");
printk("%s/%d is freeing memory %p-%p, with a lock still held there!\n", printk("%s/%d is freeing memory %p-%p, with a lock still held there!\n",
curr->comm, task_pid_nr(curr), mem_from, mem_to-1); curr->comm, task_pid_nr(curr), mem_from, mem_to-1);
print_lock(hlock); print_lock(hlock);
@ -4302,11 +4302,11 @@ static void print_held_locks_bug(void)
return; return;
printk("\n"); printk("\n");
printk("=====================================\n"); pr_warn("====================================\n");
printk("[ BUG: %s/%d still has locks held! ]\n", pr_warn("WARNING: %s/%d still has locks held!\n",
current->comm, task_pid_nr(current)); current->comm, task_pid_nr(current));
print_kernel_ident(); print_kernel_ident();
printk("-------------------------------------\n"); pr_warn("------------------------------------\n");
lockdep_print_held_locks(current); lockdep_print_held_locks(current);
printk("\nstack backtrace:\n"); printk("\nstack backtrace:\n");
dump_stack(); dump_stack();
@ -4371,7 +4371,7 @@ retry:
} while_each_thread(g, p); } while_each_thread(g, p);
printk("\n"); printk("\n");
printk("=============================================\n\n"); pr_warn("=============================================\n\n");
if (unlock) if (unlock)
read_unlock(&tasklist_lock); read_unlock(&tasklist_lock);
@ -4401,10 +4401,10 @@ asmlinkage __visible void lockdep_sys_exit(void)
if (!debug_locks_off()) if (!debug_locks_off())
return; return;
printk("\n"); printk("\n");
printk("================================================\n"); pr_warn("================================================\n");
printk("[ BUG: lock held when returning to user space! ]\n"); pr_warn("WARNING: lock held when returning to user space!\n");
print_kernel_ident(); print_kernel_ident();
printk("------------------------------------------------\n"); pr_warn("------------------------------------------------\n");
printk("%s/%d is leaving the kernel with locks still held!\n", printk("%s/%d is leaving the kernel with locks still held!\n",
curr->comm, curr->pid); curr->comm, curr->pid);
lockdep_print_held_locks(curr); lockdep_print_held_locks(curr);
@ -4421,13 +4421,13 @@ void lockdep_rcu_suspicious(const char *file, const int line, const char *s)
#endif /* #ifdef CONFIG_PROVE_RCU_REPEATEDLY */ #endif /* #ifdef CONFIG_PROVE_RCU_REPEATEDLY */
/* Note: the following can be executed concurrently, so be careful. */ /* Note: the following can be executed concurrently, so be careful. */
printk("\n"); printk("\n");
pr_err("===============================\n"); pr_warn("=============================\n");
pr_err("[ ERR: suspicious RCU usage. ]\n"); pr_warn("WARNING: suspicious RCU usage\n");
print_kernel_ident(); print_kernel_ident();
pr_err("-------------------------------\n"); pr_warn("-----------------------------\n");
pr_err("%s:%d %s!\n", file, line, s); printk("%s:%d %s!\n", file, line, s);
pr_err("\nother info that might help us debug this:\n\n"); printk("\nother info that might help us debug this:\n\n");
pr_err("\n%srcu_scheduler_active = %d, debug_locks = %d\n", printk("\n%srcu_scheduler_active = %d, debug_locks = %d\n",
!rcu_lockdep_current_cpu_online() !rcu_lockdep_current_cpu_online()
? "RCU used illegally from offline CPU!\n" ? "RCU used illegally from offline CPU!\n"
: !rcu_is_watching() : !rcu_is_watching()

View File

@ -102,10 +102,11 @@ void debug_rt_mutex_print_deadlock(struct rt_mutex_waiter *waiter)
return; return;
} }
printk("\n============================================\n"); pr_warn("\n");
printk( "[ BUG: circular locking deadlock detected! ]\n"); pr_warn("============================================\n");
printk("%s\n", print_tainted()); pr_warn("WARNING: circular locking deadlock detected!\n");
printk( "--------------------------------------------\n"); pr_warn("%s\n", print_tainted());
pr_warn("--------------------------------------------\n");
printk("%s/%d is deadlocking current task %s/%d\n\n", printk("%s/%d is deadlocking current task %s/%d\n\n",
task->comm, task_pid_nr(task), task->comm, task_pid_nr(task),
current->comm, task_pid_nr(current)); current->comm, task_pid_nr(current));