Wanpeng Li hit a collision report; which contained:

[67170.324532] ======================
[67170.327923] [chain_key collision ]
[67170.331317] 4.6.0-rc3+ #5 Tainted: G        W  OE  
[67170.336184] ----------------------
[67170.339576] swapper/0/0: Hash chain already cached but the contents don't 
match!
[67170.346970] Held locks:depth: 2
[67170.350117]  class_idx:548 -> chain_key:0000000000000224 
(jiffies_lock){-.-.-.}, at: [<ffffffff811120db>] 
tick_do_update_jiffies64+0x3b/0x150
[67170.362842]  class_idx:549 -> chain_key:0000000000448225 
(jiffies_lock#2){---.--}, at: [<ffffffff81112221>] tick_sched_do_timer+0x31/0x50
[67170.375229] Locks in cached chain:depth: 2
[67170.379326]  class_idx:2222 -> chain_key:00000000000008ae 
(&us_interface_key[i]){+.+...}
[67170.387442]  class_idx:680 -> chain_key:000000000115c2a8 
(&dev->mutex){......}


Full splat at: http://pastebin.com/raw/Qbi49DBN

>From this its not at all clear there actually was a collision; the
hashes do not match. Is there something wrong with the print stuff?

Would some additional info like per the below make sense?


---
 kernel/locking/lockdep.c | 31 +++++++++++++++++++------------
 1 file changed, 19 insertions(+), 12 deletions(-)

diff --git a/kernel/locking/lockdep.c b/kernel/locking/lockdep.c
index 81f1a7107c0e..8d4a9d0cf14a 100644
--- a/kernel/locking/lockdep.c
+++ b/kernel/locking/lockdep.c
@@ -2004,13 +2004,14 @@ static inline int get_first_held_lock(struct 
task_struct *curr,
 /*
  * Returns the next chain_key iteration
  */
-static u64 print_chain_key_iteration(int class_idx, u64 chain_key)
+static u64 print_chain_key_iteration(int class_idx, u64 chain_key, u64 
prev_key)
 {
        u64 new_chain_key = iterate_chain_key(chain_key, class_idx);
 
-       printk(" class_idx:%d -> chain_key:%016Lx",
+       printk(" class_idx: %d -> chain_key: %016Lx (%016Lx)",
                class_idx,
-               (unsigned long long)new_chain_key);
+               (unsigned long long)new_chain_key,
+               (unsigned long long)prev_key);
        return new_chain_key;
 }
 
@@ -2025,7 +2026,8 @@ print_chain_keys_held_locks(struct task_struct *curr, 
struct held_lock *hlock_ne
        printk("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);
+               chain_key = print_chain_key_iteration(hlock->class_idx, 
chain_key,
+                                                     hlock->prev_chain_key);
 
                print_lock(hlock);
        }
@@ -2043,7 +2045,7 @@ static void print_chain_keys_chain(struct lock_chain 
*chain)
        printk("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);
+               chain_key = print_chain_key_iteration(class_id + 1, chain_key, 
0);
 
                print_lock_name(lock_classes + class_id);
                printk("\n");
@@ -2052,7 +2054,8 @@ static void print_chain_keys_chain(struct lock_chain 
*chain)
 
 static void print_collision(struct task_struct *curr,
                        struct held_lock *hlock_next,
-                       struct lock_chain *chain)
+                       struct lock_chain *chain,
+                       u64 chain_key)
 {
        printk("\n");
        printk("======================\n");
@@ -2061,11 +2064,14 @@ static void print_collision(struct task_struct *curr,
        printk("----------------------\n");
        printk("%s/%d: ", current->comm, task_pid_nr(current));
        printk("Hash chain already cached but the contents don't match!\n");
+       printk("chain->chain_key: %016Lx chain_key: %016Lx\n",
+                       (unsigned long long)chain->chain_key,
+                       (unsigned long long)chain_key);
 
-       printk("Held locks:");
+       printk("Held locks: ");
        print_chain_keys_held_locks(curr, hlock_next);
 
-       printk("Locks in cached chain:");
+       printk("Locks in cached chain: ");
        print_chain_keys_chain(chain);
 
        printk("\nstack backtrace:\n");
@@ -2081,7 +2087,8 @@ static void print_collision(struct task_struct *curr,
  */
 static int check_no_collision(struct task_struct *curr,
                        struct held_lock *hlock,
-                       struct lock_chain *chain)
+                       struct lock_chain *chain,
+                       u64 chain_key)
 {
 #ifdef CONFIG_DEBUG_LOCKDEP
        int i, j, id;
@@ -2089,7 +2096,7 @@ static int check_no_collision(struct task_struct *curr,
        i = get_first_held_lock(curr, hlock);
 
        if (DEBUG_LOCKS_WARN_ON(chain->depth != curr->lockdep_depth - (i - 1))) 
{
-               print_collision(curr, hlock, chain);
+               print_collision(curr, hlock, chain, chain_key);
                return 0;
        }
 
@@ -2097,7 +2104,7 @@ static int check_no_collision(struct task_struct *curr,
                id = curr->held_locks[i].class_idx - 1;
 
                if (DEBUG_LOCKS_WARN_ON(chain_hlocks[chain->base + j] != id)) {
-                       print_collision(curr, hlock, chain);
+                       print_collision(curr, hlock, chain, chain_key);
                        return 0;
                }
        }
@@ -2135,7 +2142,7 @@ static inline int lookup_chain_cache(struct task_struct 
*curr,
                if (chain->chain_key == chain_key) {
 cache_hit:
                        debug_atomic_inc(chain_lookup_hits);
-                       if (!check_no_collision(curr, hlock, chain))
+                       if (!check_no_collision(curr, hlock, chain, chain_key))
                                return 0;
 
                        if (very_verbose(class))

Reply via email to