[PATCH RFC] locking/lockdep: replace simple printk by pr_info
From: Corentin Labbe
Date: Mon Nov 12 2018 - 08:03:30 EST
While working on detector of new warn/err/crit/... messages, I found that the
following messages was printed with the warn loglevel:
[ 0.001607] Lock dependency validator: Copyright (c) 2006 Red Hat, Inc., Ingo Molnar
[ 0.001625] ... MAX_LOCKDEP_SUBCLASSES: 8
[ 0.001641] ... MAX_LOCK_DEPTH: 48
[ 0.001658] ... MAX_LOCKDEP_KEYS: 8191
[ 0.001673] ... CLASSHASH_SIZE: 4096
[ 0.001689] ... MAX_LOCKDEP_ENTRIES: 32768
[ 0.001704] ... MAX_LOCKDEP_CHAINS: 65536
[ 0.001719] ... CHAINHASH_SIZE: 32768
[ 0.001735] memory used by lock dependency info: 4623 kB
While the cause is still unknown to me, converting printk to pr_info fixed the issue.
Signed-off-by: Corentin Labbe <clabbe@xxxxxxxxxxxx>
---
kernel/locking/lockdep.c | 152 +++++++++++++++++++++++------------------------
1 file changed, 76 insertions(+), 76 deletions(-)
diff --git a/kernel/locking/lockdep.c b/kernel/locking/lockdep.c
index 1efada2..9454597 100644
--- a/kernel/locking/lockdep.c
+++ b/kernel/locking/lockdep.c
@@ -560,9 +560,9 @@ static void lockdep_print_held_locks(struct task_struct *p)
int i, depth = READ_ONCE(p->lockdep_depth);
if (!depth)
- printk("no locks held by %s/%d.\n", p->comm, task_pid_nr(p));
+ pr_info("no locks held by %s/%d.\n", p->comm, task_pid_nr(p));
else
- printk("%d lock%s held by %s/%d:\n", depth,
+ pr_info("%d lock%s held by %s/%d:\n", depth,
depth > 1 ? "s" : "", p->comm, task_pid_nr(p));
/*
* It's not reliable to print a task's held locks if it's not sleeping
@@ -571,14 +571,14 @@ static void lockdep_print_held_locks(struct task_struct *p)
if (p->state == TASK_RUNNING && p != current)
return;
for (i = 0; i < depth; i++) {
- printk(" #%d: ", i);
+ pr_info(" #%d: ", i);
print_lock(p->held_locks + i);
}
}
static void print_kernel_ident(void)
{
- printk("%s %.*s %s\n", init_utsname()->release,
+ pr_info("%s %.*s %s\n", init_utsname()->release,
(int)strcspn(init_utsname()->version, " "),
init_utsname()->version,
print_tainted());
@@ -806,7 +806,7 @@ register_lock_class(struct lockdep_map *lock, unsigned int subclass, int force)
if (verbose(class)) {
graph_unlock();
- printk("\nnew class %px: %s", class->key, class->name);
+ pr_info("\nnew class %px: %s", class->key, class->name);
if (class->name_version > 1)
printk(KERN_CONT "#%d", class->name_version);
printk(KERN_CONT "\n");
@@ -1085,7 +1085,7 @@ print_circular_bug_entry(struct lock_list *target, int depth)
{
if (debug_locks_silent)
return 0;
- printk("\n-> #%u", depth);
+ pr_info("\n-> #%u", depth);
print_lock_name(target->class);
printk(KERN_CONT ":\n");
print_stack_trace(&target->trace, 6);
@@ -1116,7 +1116,7 @@ print_circular_lock_scenario(struct held_lock *src,
* from the safe_class lock to the unsafe_class lock.
*/
if (parent != source) {
- printk("Chain exists of:\n ");
+ pr_info("Chain exists of:\n ");
__print_lock_name(source);
printk(KERN_CONT " --> ");
__print_lock_name(parent);
@@ -1125,22 +1125,22 @@ print_circular_lock_scenario(struct held_lock *src,
printk(KERN_CONT "\n\n");
}
- printk(" Possible unsafe locking scenario:\n\n");
- printk(" CPU0 CPU1\n");
- printk(" ---- ----\n");
- printk(" lock(");
+ pr_info(" Possible unsafe locking scenario:\n\n");
+ pr_info(" CPU0 CPU1\n");
+ pr_info(" ---- ----\n");
+ pr_info(" lock(");
__print_lock_name(target);
printk(KERN_CONT ");\n");
- printk(" lock(");
+ pr_info(" lock(");
__print_lock_name(parent);
printk(KERN_CONT ");\n");
- printk(" lock(");
+ pr_info(" lock(");
__print_lock_name(target);
printk(KERN_CONT ");\n");
- printk(" lock(");
+ pr_info(" lock(");
__print_lock_name(source);
printk(KERN_CONT ");\n");
- printk("\n *** DEADLOCK ***\n\n");
+ pr_info("\n *** DEADLOCK ***\n\n");
}
/*
@@ -1211,13 +1211,13 @@ static noinline int print_circular_bug(struct lock_list *this,
parent = get_lock_parent(parent);
}
- printk("\nother info that might help us debug this:\n\n");
+ pr_info("\nother info that might help us debug this:\n\n");
print_circular_lock_scenario(check_src, check_tgt,
first_parent);
lockdep_print_held_locks(curr);
- printk("\nstack backtrace:\n");
+ pr_info("\nstack backtrace:\n");
dump_stack();
return 0;
@@ -1389,7 +1389,7 @@ static void print_lock_class_header(struct lock_class *class, int depth)
{
int bit;
- printk("%*s->", depth, "");
+ pr_info("%*s->", depth, "");
print_lock_name(class);
#ifdef CONFIG_DEBUG_LOCKDEP
printk(KERN_CONT " ops: %lu", debug_class_ops_read(class));
@@ -1400,14 +1400,14 @@ static void print_lock_class_header(struct lock_class *class, int depth)
if (class->usage_mask & (1 << bit)) {
int len = depth;
- len += printk("%*s %s", depth, "", usage_str[bit]);
+ len += pr_info("%*s %s", depth, "", usage_str[bit]);
len += printk(KERN_CONT " at:\n");
print_stack_trace(class->usage_traces + bit, len);
}
}
- printk("%*s }\n", depth, "");
+ pr_info("%*s }\n", depth, "");
- printk("%*s ... key at: [<%px>] %pS\n",
+ pr_info("%*s ... key at: [<%px>] %pS\n",
depth, "", class->key, class->key);
}
@@ -1426,12 +1426,12 @@ print_shortest_lock_dependencies(struct lock_list *leaf,
do {
print_lock_class_header(entry->class, depth);
- printk("%*s ... acquired at:\n", depth, "");
+ pr_info("%*s ... acquired at:\n", depth, "");
print_stack_trace(&entry->trace, 2);
- printk("\n");
+ pr_info("\n");
if (depth == 0 && (entry != root)) {
- printk("lockdep:%s bad path found in chain graph\n", __func__);
+ pr_info("lockdep:%s bad path found in chain graph\n", __func__);
break;
}
@@ -1469,7 +1469,7 @@ print_irq_lock_scenario(struct lock_list *safe_entry,
* from the safe_class lock to the unsafe_class lock.
*/
if (middle_class != unsafe_class) {
- printk("Chain exists of:\n ");
+ pr_info("Chain exists of:\n ");
__print_lock_name(safe_class);
printk(KERN_CONT " --> ");
__print_lock_name(middle_class);
@@ -1478,24 +1478,24 @@ print_irq_lock_scenario(struct lock_list *safe_entry,
printk(KERN_CONT "\n\n");
}
- printk(" Possible interrupt unsafe locking scenario:\n\n");
- printk(" CPU0 CPU1\n");
- printk(" ---- ----\n");
- printk(" lock(");
+ pr_info(" Possible interrupt unsafe locking scenario:\n\n");
+ pr_info(" CPU0 CPU1\n");
+ pr_info(" ---- ----\n");
+ pr_info(" lock(");
__print_lock_name(unsafe_class);
printk(KERN_CONT ");\n");
- printk(" local_irq_disable();\n");
- printk(" lock(");
+ pr_info(" local_irq_disable();\n");
+ pr_info(" lock(");
__print_lock_name(safe_class);
printk(KERN_CONT ");\n");
- printk(" lock(");
+ pr_info(" lock(");
__print_lock_name(middle_class);
printk(KERN_CONT ");\n");
- printk(" <Interrupt>\n");
- printk(" lock(");
+ pr_info(" <Interrupt>\n");
+ pr_info(" lock(");
__print_lock_name(safe_class);
printk(KERN_CONT ");\n");
- printk("\n *** DEADLOCK ***\n\n");
+ pr_info("\n *** DEADLOCK ***\n\n");
}
static int
@@ -1722,17 +1722,17 @@ print_deadlock_scenario(struct held_lock *nxt,
struct lock_class *next = hlock_class(nxt);
struct lock_class *prev = hlock_class(prv);
- printk(" Possible unsafe locking scenario:\n\n");
- printk(" CPU0\n");
- printk(" ----\n");
- printk(" lock(");
+ pr_info(" Possible unsafe locking scenario:\n\n");
+ pr_info(" CPU0\n");
+ pr_info(" ----\n");
+ pr_info(" lock(");
__print_lock_name(prev);
printk(KERN_CONT ");\n");
- printk(" lock(");
+ pr_info(" lock(");
__print_lock_name(next);
printk(KERN_CONT ");\n");
- printk("\n *** DEADLOCK ***\n\n");
- printk(" May be due to missing lock nesting notation\n\n");
+ pr_info("\n *** DEADLOCK ***\n\n");
+ pr_info(" May be due to missing lock nesting notation\n\n");
}
static int
@@ -2052,7 +2052,7 @@ static u64 print_chain_key_iteration(int class_idx, u64 chain_key)
{
u64 new_chain_key = iterate_chain_key(chain_key, class_idx);
- printk(" class_idx:%d -> chain_key:%016Lx",
+ pr_info(" class_idx:%d -> chain_key:%016Lx",
class_idx,
(unsigned long long)new_chain_key);
return new_chain_key;
@@ -2066,7 +2066,7 @@ print_chain_keys_held_locks(struct task_struct *curr, struct held_lock *hlock_ne
int depth = curr->lockdep_depth;
int i;
- printk("depth: %u\n", depth + 1);
+ pr_info("depth: %u\n", depth + 1);
for (i = get_first_held_lock(curr, hlock_next); i < depth; i++) {
hlock = curr->held_locks + i;
chain_key = print_chain_key_iteration(hlock->class_idx, chain_key);
@@ -2084,13 +2084,13 @@ static void print_chain_keys_chain(struct lock_chain *chain)
u64 chain_key = 0;
int class_id;
- printk("depth: %u\n", chain->depth);
+ pr_info("depth: %u\n", chain->depth);
for (i = 0; i < chain->depth; i++) {
class_id = chain_hlocks[chain->base + i];
chain_key = print_chain_key_iteration(class_id + 1, chain_key);
print_lock_name(lock_classes + class_id);
- printk("\n");
+ pr_info("\n");
}
}
@@ -2269,7 +2269,7 @@ static inline int lookup_chain_cache_add(struct task_struct *curr,
return 0;
if (very_verbose(class)) {
- printk("\nhash chain already cached, key: "
+ pr_info("\nhash chain already cached, key: "
"%016Lx tail class: [%px] %s\n",
(unsigned long long)chain_key,
class->key, class->name);
@@ -2279,7 +2279,7 @@ static inline int lookup_chain_cache_add(struct task_struct *curr,
}
if (very_verbose(class)) {
- printk("\nnew hash chain, key: %016Lx tail class: [%px] %s\n",
+ pr_info("\nnew hash chain, key: %016Lx tail class: [%px] %s\n",
(unsigned long long)chain_key, class->key, class->name);
}
@@ -2422,17 +2422,17 @@ print_usage_bug_scenario(struct held_lock *lock)
{
struct lock_class *class = hlock_class(lock);
- printk(" Possible unsafe locking scenario:\n\n");
- printk(" CPU0\n");
- printk(" ----\n");
- printk(" lock(");
+ pr_info(" Possible unsafe locking scenario:\n\n");
+ pr_info(" CPU0\n");
+ pr_info(" ----\n");
+ pr_info(" lock(");
__print_lock_name(class);
printk(KERN_CONT ");\n");
- printk(" <Interrupt>\n");
- printk(" lock(");
+ pr_info(" <Interrupt>\n");
+ pr_info(" lock(");
__print_lock_name(class);
printk(KERN_CONT ");\n");
- printk("\n *** DEADLOCK ***\n\n");
+ pr_info("\n *** DEADLOCK ***\n\n");
}
static int
@@ -2605,17 +2605,17 @@ check_usage_backwards(struct task_struct *curr, struct held_lock *this,
void print_irqtrace_events(struct task_struct *curr)
{
- printk("irq event stamp: %u\n", curr->irq_events);
- printk("hardirqs last enabled at (%u): [<%px>] %pS\n",
+ pr_info("irq event stamp: %u\n", curr->irq_events);
+ pr_info("hardirqs last enabled at (%u): [<%px>] %pS\n",
curr->hardirq_enable_event, (void *)curr->hardirq_enable_ip,
(void *)curr->hardirq_enable_ip);
- printk("hardirqs last disabled at (%u): [<%px>] %pS\n",
+ pr_info("hardirqs last disabled at (%u): [<%px>] %pS\n",
curr->hardirq_disable_event, (void *)curr->hardirq_disable_ip,
(void *)curr->hardirq_disable_ip);
- printk("softirqs last enabled at (%u): [<%px>] %pS\n",
+ pr_info("softirqs last enabled at (%u): [<%px>] %pS\n",
curr->softirq_enable_event, (void *)curr->softirq_enable_ip,
(void *)curr->softirq_enable_ip);
- printk("softirqs last disabled at (%u): [<%px>] %pS\n",
+ pr_info("softirqs last disabled at (%u): [<%px>] %pS\n",
curr->softirq_disable_event, (void *)curr->softirq_disable_ip,
(void *)curr->softirq_disable_ip);
}
@@ -3076,7 +3076,7 @@ static int mark_lock(struct task_struct *curr, struct held_lock *this,
* We must printk outside of the graph_lock:
*/
if (ret == 2) {
- printk("\nmarked lock as {%s}:\n", usage_str[new_bit]);
+ pr_info("\nmarked lock as {%s}:\n", usage_str[new_bit]);
print_lock(this);
print_irqtrace_events(curr);
dump_stack();
@@ -3119,7 +3119,7 @@ static void __lockdep_init_map(struct lockdep_map *lock, const char *name,
* Sanity check, the lock-class key must be persistent:
*/
if (!static_obj(key)) {
- printk("BUG: key %px not in .data!\n", key);
+ pr_info("BUG: key %px not in .data!\n", key);
/*
* What it says above ^^^^^, I suggest you read it.
*/
@@ -3232,7 +3232,7 @@ static int __lock_acquire(struct lockdep_map *lock, unsigned int subclass,
debug_class_ops_inc(class);
if (very_verbose(class)) {
- printk("\nacquire class [%px] %s", class->key, class->name);
+ pr_info("\nacquire class [%px] %s", class->key, class->name);
if (class->name_version > 1)
printk(KERN_CONT "#%d", class->name_version);
printk(KERN_CONT "\n");
@@ -3759,11 +3759,11 @@ static void check_flags(unsigned long flags)
if (irqs_disabled_flags(flags)) {
if (DEBUG_LOCKS_WARN_ON(current->hardirqs_enabled)) {
- printk("possible reason: unannotated irqs-off.\n");
+ pr_info("possible reason: unannotated irqs-off.\n");
}
} else {
if (DEBUG_LOCKS_WARN_ON(!current->hardirqs_enabled)) {
- printk("possible reason: unannotated irqs-on.\n");
+ pr_info("possible reason: unannotated irqs-on.\n");
}
}
@@ -4258,17 +4258,17 @@ void lockdep_reset_lock(struct lockdep_map *lock)
void __init lockdep_init(void)
{
- printk("Lock dependency validator: Copyright (c) 2006 Red Hat, Inc., Ingo Molnar\n");
+ pr_info("Lock dependency validator: Copyright (c) 2006 Red Hat, Inc., Ingo Molnar\n");
- printk("... MAX_LOCKDEP_SUBCLASSES: %lu\n", MAX_LOCKDEP_SUBCLASSES);
- printk("... MAX_LOCK_DEPTH: %lu\n", MAX_LOCK_DEPTH);
- printk("... MAX_LOCKDEP_KEYS: %lu\n", MAX_LOCKDEP_KEYS);
- printk("... CLASSHASH_SIZE: %lu\n", CLASSHASH_SIZE);
- printk("... MAX_LOCKDEP_ENTRIES: %lu\n", MAX_LOCKDEP_ENTRIES);
- printk("... MAX_LOCKDEP_CHAINS: %lu\n", MAX_LOCKDEP_CHAINS);
- printk("... CHAINHASH_SIZE: %lu\n", CHAINHASH_SIZE);
+ pr_info("... MAX_LOCKDEP_SUBCLASSES: %lu\n", MAX_LOCKDEP_SUBCLASSES);
+ pr_info("... MAX_LOCK_DEPTH: %lu\n", MAX_LOCK_DEPTH);
+ pr_info("... MAX_LOCKDEP_KEYS: %lu\n", MAX_LOCKDEP_KEYS);
+ pr_info("... CLASSHASH_SIZE: %lu\n", CLASSHASH_SIZE);
+ pr_info("... MAX_LOCKDEP_ENTRIES: %lu\n", MAX_LOCKDEP_ENTRIES);
+ pr_info("... MAX_LOCKDEP_CHAINS: %lu\n", MAX_LOCKDEP_CHAINS);
+ pr_info("... CHAINHASH_SIZE: %lu\n", CHAINHASH_SIZE);
- printk(" memory used by lock dependency info: %lu kB\n",
+ pr_info(" memory used by lock dependency info: %lu kB\n",
(sizeof(struct lock_class) * MAX_LOCKDEP_KEYS +
sizeof(struct list_head) * CLASSHASH_SIZE +
sizeof(struct lock_list) * MAX_LOCKDEP_ENTRIES +
@@ -4280,7 +4280,7 @@ void __init lockdep_init(void)
) / 1024
);
- printk(" per task-struct memory footprint: %lu bytes\n",
+ pr_info(" per task-struct memory footprint: %lu bytes\n",
sizeof(struct held_lock) * MAX_LOCK_DEPTH);
}
@@ -4403,7 +4403,7 @@ EXPORT_SYMBOL_GPL(debug_show_all_locks);
void debug_show_held_locks(struct task_struct *task)
{
if (unlikely(!debug_locks)) {
- printk("INFO: lockdep is turned off.\n");
+ pr_info("INFO: lockdep is turned off.\n");
return;
}
lockdep_print_held_locks(task);
--
2.7.4