linux_module/lockcheck.c

   1 #include <linux/kernel.h>
   2 #include <linux/kthread.h>
   3 #include <linux/spinlock.h>
   4
   5 #include "palacios.h"
   6
   7 #include "lockcheck.h"
   8
   9 #define PRINT_LOCK_ALLOC  0
  10 #define PRINT_LOCK_FREE   0
  11 #define PRINT_LOCK_LOCK   0
  12 #define PRINT_LOCK_UNLOCK 0
  13
  14 // How far up the stack to track the caller
  15 // 0 => palacios_...
  16 // 1 => v3_lock...
  17 // 2 => caller of v3_lock..
  18 // ...
  19 #define STEP_BACK_DEPTH_FIRST 1
  20 #define STEP_BACK_DEPTH_LAST  4
  21 #define STEP_BACK_DEPTH       (STEP_BACK_DEPTH_LAST-STEP_BACK_DEPTH_FIRST+1)
  22
  23 // show when multiple locks are held simultaneously
  24 // This is the minimum number
  25 #define WARN_MULTIPLE_THRESHOLD 3
  26
  27 typedef struct {
  28   int  inuse;         // nonzero if this is in use
  29   void *lock;         // the lock
  30   void *allocator[STEP_BACK_DEPTH];
  31                       // who allocated this
  32   int   lockcount;    // how many times it's been locked/unlocked (lock=+1, unlock=-1)
  33   int   irqcount;     // how many times interrupts have been turned off (+1/-1)
  34   void *lastlocker[STEP_BACK_DEPTH];
  35                       // who last locked
  36   void *lastunlocker[STEP_BACK_DEPTH];
  37                       // who last unlocked
  38   void *lastirqlocker[STEP_BACK_DEPTH];
  39                       // who last locked
  40   unsigned long lastlockflags; // their flags
  41   void *lastirqunlocker[STEP_BACK_DEPTH]
  42                     ; // who last unlocked
  43   unsigned long lastunlockflags; // their flags
  44 } lockcheck_state_t;
  45
  46
  47 // This lock is currently used only to control
  48 // allocation of entries in the global state
  49 static spinlock_t lock;
  50 static lockcheck_state_t state[NUM_LOCKS];
  51
  52 static void printlock(char *prefix, lockcheck_state_t *l);
  53
  54
  55 typedef struct {
  56   u32 top;               // next open slot 0..
  57   void *lock[LOCK_STACK_DEPTH]; // the stack
  58   char irq[LOCK_STACK_DEPTH];   // locked with irqsave?
  59 } lock_stack_t;
  60
  61 static DEFINE_PER_CPU(lock_stack_t, lock_stack);
  62
  63 static lockcheck_state_t *get_lock_entry(void)
  64 {
  65   int i;
  66   unsigned long f;
  67   lockcheck_state_t *l;
  68
  69   spin_lock_irqsave(&lock,f);
  70
  71   for (i=0;i<NUM_LOCKS;i++) {
  72     l=&(state[i]);
  73     if (!(l->inuse)) {
  74       l->inuse=1;
  75       break;
  76     }
  77   }
  78
  79   spin_unlock_irqrestore(&lock,f);
  80
  81   if (i<NUM_LOCKS) {
  82     return l;
  83   } else {
  84     return 0;
  85   }
  86 }
  87
  88
  89 static lockcheck_state_t *find_lock_entry(void *lock)
  90 {
  91   int i;
  92   lockcheck_state_t *l;
  93
  94   for (i=0;i<NUM_LOCKS;i++) {
  95     l=&(state[i]);
  96     if (l->inuse && l->lock == lock) {
  97       return l;
  98     }
  99   }
 100   return 0;
 101 }
 102
 103
 104 static void free_lock_entry(lockcheck_state_t *l)
 105 {
 106   l->inuse=0;
 107 }
 108
 109
 110 static void lock_stack_print(void)
 111 {
 112   u32 i;
 113   char buf[64];
 114   lock_stack_t *mystack = &(get_cpu_var(lock_stack));
 115   u32 cpu = get_cpu();  put_cpu();
 116
 117   if ((mystack->top)>0) {
 118     for (i=mystack->top; i>0;i--) {
 119       snprintf(buf,64,"LOCK STACK (cpu=%u, index=%u, irq=%d)",cpu, i-1, (int)(mystack->irq[i-1]));
 120       printlock(buf,find_lock_entry(mystack->lock[i-1]));
 121     }
 122   }
 123   put_cpu_var(lock_stack);
 124 }
 125
 126
 127 static void lock_stack_lock(void *lock, char irq)
 128 {
 129   lock_stack_t *mystack = &(get_cpu_var(lock_stack));
 130   u32 cpu = get_cpu();  put_cpu();
 131
 132   if (mystack->top>=(LOCK_STACK_DEPTH-1)) {
 133     put_cpu_var(lock_stack);
 134     DEBUG("LOCKCHECK: Locking lock 0x%p on cpu %u exceeds stack limit of %d\n",lock,cpu,LOCK_STACK_DEPTH);
 135     lock_stack_print();
 136   } else {
 137     mystack->lock[mystack->top] = lock;
 138     mystack->irq[mystack->top] = irq;
 139     mystack->top++;
 140     put_cpu_var(lock_stack);
 141   }
 142 }
 143
 144 static void lock_stack_unlock(void *lock, char irq)
 145 {
 146   lock_stack_t *mystack = &(get_cpu_var(lock_stack));
 147   u32 cpu = get_cpu(); put_cpu();
 148
 149   if (mystack->top==0) {
 150     put_cpu_var(lock_stack);
 151     DEBUG("LOCKCHECK: Unlocking lock 0x%p on cpu %u when lock stack is empty\n",lock,cpu);
 152   } else {
 153     if (mystack->lock[mystack->top-1] != lock) {
 154       void *otherlock=mystack->lock[mystack->top-1];
 155       put_cpu_var(lock_stack);
 156       DEBUG("LOCKCHECK: Unlocking lock 0x%p on cpu %u when top of stack is lock 0x%p\n",lock,cpu, otherlock);
 157       lock_stack_print();
 158     } else {
 159       if (irq!=mystack->irq[mystack->top-1]) {
 160         char otherirq = mystack->irq[mystack->top-1];
 161         put_cpu_var(lock_stack);
 162         DEBUG("LOCKCHECK: Unlocking lock 0x%p on cpu %u with irq=%d, but was locked with irq=%d\n",lock,cpu,irq,otherirq);
 163         lock_stack_print();
 164       } else {
 165         mystack->top--;
 166         put_cpu_var(lock_stack);
 167       }
 168     }
 169   }
 170
 171 }
 172
 173 void palacios_lockcheck_init()
 174 {
 175   memset(state,0,sizeof(lockcheck_state_t)*NUM_LOCKS);
 176   spin_lock_init(&lock);
 177   DEBUG("LOCKCHECK: LOCK CHECKING INITED\n");
 178 }
 179
 180 //
 181 // This needs to be defined explictly since the intrinsic does not take a var
 182 //
 183 #define backtrace(t) \
 184   t[0]=__builtin_return_address(STEP_BACK_DEPTH_FIRST); \
 185   t[1]=__builtin_return_address(STEP_BACK_DEPTH_FIRST+1); \
 186   t[2]=__builtin_return_address(STEP_BACK_DEPTH_FIRST+2); \
 187   t[3]=__builtin_return_address(STEP_BACK_DEPTH_FIRST+3);
 188
 189 //
 190 // For printing a backtrace
 191 //
 192 //
 193 #define backtrace_format "%pS << %pS << %pS << %pS"
 194 #define backtrace_expand(t) ((t)[0]),((t)[1]),((t)[2]),((t)[3])
 195
 196
 197 static void clear_trace(void **trace)
 198 {
 199   int i;
 200
 201   for (i=0;i<STEP_BACK_DEPTH;i++) {
 202     trace[i]=0;
 203   }
 204 }
 205
 206
 207 static void printlock(char *prefix, lockcheck_state_t *l)
 208 {
 209   if (!l || !(l->lock) ) {
 210     DEBUG("LOCKCHECK: %s: lock 0x%p BOGUS\n",prefix,l);
 211     return;
 212   }
 213   if (l->lock) {
 214     DEBUG("LOCKCHECK: %s: lock 0x%p, allocator="
 215           backtrace_format
 216           ", lockcount=%d, lastlocker="
 217           backtrace_format
 218           ", lastunlocker="
 219           backtrace_format
 220           ", irqcount=%d, lastirqlocker="
 221           backtrace_format
 222           ", lastlockflags=%lu, lastirqunlocker="
 223           backtrace_format
 224           ", lastunlockflags=%lu\n",
 225           prefix,l->lock,
 226           backtrace_expand(l->allocator),
 227           l->lockcount,
 228           backtrace_expand(l->lastlocker),
 229           backtrace_expand(l->lastunlocker),
 230           l->irqcount,
 231           backtrace_expand(l->lastirqlocker),
 232           l->lastlockflags,
 233           backtrace_expand(l->lastirqunlocker),
 234           l->lastunlockflags);
 235   }
 236 }
 237
 238
 239
 240 static void find_multiple_locks_held(void)
 241 {
 242   int i;
 243   int have=0;
 244   lockcheck_state_t *l;
 245   char buf[64];
 246
 247   for (i=0;i<NUM_LOCKS;i++) {
 248     l=&(state[i]);
 249     if (l->inuse && l->lockcount>0) {
 250       have++;
 251       if (have>=WARN_MULTIPLE_THRESHOLD) {
 252         break;
 253       }
 254     }
 255   }
 256
 257   if (have>=WARN_MULTIPLE_THRESHOLD) {
 258     have=0;
 259     for (i=0;i<NUM_LOCKS;i++) {
 260       l=&(state[i]);
 261       if (l->inuse && l->lockcount>0) {
 262         snprintf(buf,64,"MULTIPLE LOCKS HELD (%d)",have);
 263         printlock(buf,l);
 264         have++;
 265       }
 266     }
 267   }
 268
 269 }
 270
 271 static void find_multiple_irqs_held(void)
 272 {
 273   int i;
 274   int have=0;
 275   lockcheck_state_t *l;
 276   char buf[64];
 277
 278   for (i=0;i<NUM_LOCKS;i++) {
 279     l=&(state[i]);
 280     if (l->inuse && l->irqcount>0) {
 281       have++;
 282       if (have>=WARN_MULTIPLE_THRESHOLD) {
 283         break;
 284       }
 285     }
 286   }
 287
 288   if (have>=WARN_MULTIPLE_THRESHOLD) {
 289     have=0;
 290     for (i=0;i<NUM_LOCKS;i++) {
 291       l=&(state[i]);
 292       if (l->inuse && l->irqcount>0) {
 293         snprintf(buf,64,"MULTIPLE IRQS HELD (%d)",have);
 294         printlock(buf,l);
 295         have++;
 296       }
 297     }
 298   }
 299
 300 }
 301
 302
 303 void palacios_lockcheck_deinit()
 304 {
 305   int i;
 306   lockcheck_state_t *l;
 307
 308   for (i=0;i<NUM_LOCKS;i++) {
 309     l=&(state[i]);
 310     if (l->lock) {
 311       printlock("ALLOCATED LOCK AT DEINIT",l);
 312       if ((l->lockcount)) {
 313         printlock("BAD LOCK COUNT AT DEINIT",l);
 314       }
 315       if ((l->irqcount)) {
 316         printlock("BAD IRQ COUNT AT DEINIT",l);
 317       }
 318     }
 319   }
 320   INFO("LOCKCHECK: DEINITED\n");
 321 }
 322
 323
 324 void palacios_lockcheck_alloc(void *lock)
 325 {
 326   lockcheck_state_t *l=get_lock_entry();
 327
 328   if (!l) {
 329     DEBUG("LOCKCHECK: UNABLE TO ALLOCATE TRACKING DATA FOR LOCK 0x%p\n",lock);
 330   }
 331   l->lock=lock;
 332   backtrace(l->allocator);
 333   l->lockcount=l->irqcount=0;
 334   clear_trace(l->lastlocker);
 335   clear_trace(l->lastunlocker);
 336   clear_trace(l->lastirqlocker);
 337   clear_trace(l->lastirqunlocker);
 338   //INFO("LOCKCHECK: LOCK ALLOCATE 0x%p\n",lock);
 339 #if PRINT_LOCK_ALLOC
 340   printlock("NEW LOCK", l);
 341 #endif
 342 }
 343
 344 void palacios_lockcheck_free(void *lock)
 345 {
 346   lockcheck_state_t *l=find_lock_entry(lock);
 347
 348   if (!l){
 349     DEBUG("LOCKCHECK: FREEING UNTRACKED LOCK 0x%p\n",lock);
 350     return;
 351   }
 352
 353   if ((l->lockcount)) {
 354     printlock("BAD LOCK COUNT AT FREE",l);
 355   }
 356
 357   if ((l->irqcount)) {
 358     printlock("BAD IRQ COUNT AT FREE",l);
 359   }
 360
 361 #if PRINT_LOCK_FREE
 362   printlock("FREE LOCK",l);
 363 #endif
 364
 365   free_lock_entry(l);
 366 }
 367
 368 void palacios_lockcheck_lock(void *lock)
 369 {
 370   lockcheck_state_t *l=find_lock_entry(lock);
 371
 372   if (!l) {
 373     DEBUG("LOCKCHECK: LOCKING UNTRACKED LOCK 0x%p\n",lock);
 374     return;
 375   }
 376
 377   if (l->lockcount!=0) {
 378     printlock("BAD LOCKCOUNT AT LOCK",l);
 379   }
 380   if (l->irqcount!=0) {
 381     printlock("BAD IRQCOUNT AT LOCK",l);
 382   }
 383
 384   l->lockcount++;
 385   backtrace(l->lastlocker);
 386
 387   find_multiple_locks_held();
 388
 389   lock_stack_lock(lock,0);
 390
 391 #if PRINT_LOCK_LOCK
 392   printlock("LOCK",l);
 393 #endif
 394
 395 }
 396 void palacios_lockcheck_unlock(void *lock)
 397 {
 398   lockcheck_state_t *l=find_lock_entry(lock);
 399
 400   if (!l) {
 401     DEBUG("LOCKCHECK: UNLOCKING UNTRACKED LOCK 0x%p\n",lock);
 402     return;
 403   }
 404
 405   if (l->lockcount!=1) {
 406     printlock("LOCKCHECK: BAD LOCKCOUNT AT UNLOCK",l);
 407   }
 408   if (l->irqcount!=0) {
 409     printlock("LOCKCHECK: BAD IRQCOUNT AT UNLOCK",l);
 410   }
 411
 412   lock_stack_unlock(lock,0);
 413
 414   l->lockcount--;
 415   backtrace(l->lastunlocker);
 416
 417 #if PRINT_LOCK_UNLOCK
 418   printlock("UNLOCK",l);
 419 #endif
 420
 421
 422 }
 423
 424 void palacios_lockcheck_lock_irqsave(void *lock,unsigned long flags)
 425 {
 426   lockcheck_state_t *l=find_lock_entry(lock);
 427
 428   if (!l) {
 429     DEBUG("LOCKCHECK: IRQ LOCKING UNTRACKED LOCK 0x%p\n",lock);
 430     return;
 431   }
 432
 433   if (l->lockcount!=0) {
 434     printlock("BAD LOCKCOUNT AT IRQ LOCK",l);
 435   }
 436   if (l->irqcount!=0) {
 437     printlock("BAD IRQCOUNT AT IRQ LOCK",l);
 438   }
 439
 440   l->irqcount++;
 441   l->lastlockflags=flags;
 442   backtrace(l->lastirqlocker);
 443
 444
 445   find_multiple_irqs_held();
 446
 447   lock_stack_lock(lock,1);
 448
 449 #if PRINT_LOCK_LOCK
 450   printlock("LOCK_IRQSAVE",l);
 451 #endif
 452
 453
 454
 455 }
 456
 457 void palacios_lockcheck_unlock_irqrestore(void *lock,unsigned long flags)
 458 {
 459   lockcheck_state_t *l=find_lock_entry(lock);
 460
 461   if (!l) {
 462     DEBUG("LOCKCHECK: IRQ UNLOCKING UNTRACKED LOCK 0x%p\n",lock);
 463     return;
 464   }
 465
 466   if (l->lockcount!=0) {
 467     printlock("LOCKCHECK: BAD LOCKCOUNT AT IRQ UNLOCK",l);
 468   }
 469   if (l->irqcount!=1) {
 470     printlock("LOCKCHECK: BAD IRQCOUNT AT IRQ UNLOCK",l);
 471   }
 472
 473   l->irqcount--;
 474   l->lastunlockflags = flags;
 475
 476   lock_stack_unlock(lock,1);
 477
 478   backtrace(l->lastirqunlocker);
 479
 480 #if PRINT_LOCK_UNLOCK
 481   printlock("UNLOCK_IRQRESTORE",l);
 482 #endif
 483
 484 }