linux_module/lockcheck.c

   1 /*
   2    Palacios lock-checking framework
   3    (c) Peter Dinda, 2013
   4  */
   5
   6 #include <linux/kernel.h>
   7 #include <linux/kthread.h>
   8 #include <linux/spinlock.h>
   9 #include <linux/sort.h>
  10 #include <linux/timer.h>
  11 #include <linux/time.h>
  12
  13 #include "palacios.h"
  14
  15 #include "lockcheck.h"
  16
  17
  18 // Number of outputs possible before output stops
  19 // set to zero to remove the limit
  20 #define OUTPUT_LIMIT      0
  21 //
  22 // Number of outputs to skip before
  23 // printing and counting
  24 #define OUTPUT_SKIP       0
  25
  26 //
  27 // Whether or not to print these events
  28 //
  29 #define PRINT_LOCK_ALLOC  0
  30 #define PRINT_LOCK_FREE   0
  31 #define PRINT_LOCK_LOCK   0
  32 #define PRINT_LOCK_UNLOCK 0
  33
  34 // How far up the stack to track the caller
  35 // 0 => palacios_...
  36 // 1 => v3_lock...
  37 // 2 => caller of v3_lock..
  38 // ...
  39 #define STEP_BACK_DEPTH_FIRST 1
  40 #define STEP_BACK_DEPTH_LAST  4
  41 #define STEP_BACK_DEPTH       (STEP_BACK_DEPTH_LAST-STEP_BACK_DEPTH_FIRST+1)
  42
  43 // show when multiple locks are held simultaneously
  44 // This is the minimum number
  45 #define WARN_MULTIPLE_THRESHOLD 3
  46
  47 // Detect when last lock a processor holds is released
  48 // but interrupts remain off, similarly for first acquire
  49 #define CHECK_IRQ_LAST_RELEASE   0
  50 #define CHECK_IRQ_FIRST_ACQUIRE  1
  51
  52 // Show hottest locks every this many locks or lock_irqsaves
  53 // 0 indicates this should not be shown
  54 #define HOT_LOCK_INTERVAL        100000
  55
  56 // How often the long lock timer checker should run
  57 // And how long a lock needs to be held before it complains
  58 // set to zero to deactivate
  59 #define LONG_LOCK_INTERVAL_MS    10
  60 #define LONG_LOCK_HELD_MS        20
  61
  62 //
  63 // Whether lockcheck should lock its own data structures during an
  64 // event (alloc, dealloc, lock, unlock, etc) and the subsequent
  65 // checking.  If this is off, it will only lock on a lock allocation,
  66 // in order to assure each lock has a distinct slot.  If this is off,
  67 // lockcheck may miss problems (or see additional problems) due to
  68 // internal race conditions.  However, if it is on, lockcheck is
  69 // essentially adding a global lock acuire to each lock operation in
  70 // palacios, which will perturb palacios.
  71 //
  72 #define LOCK_SELF 1
  73
  74
  75 typedef struct {
  76   int  inuse;         // nonzero if this is in use
  77   void *lock;         // the lock
  78   void *holder;       // current thread holding it
  79   u32   holdingcpu;   // on which cpu it acquired it
  80   void *allocator[STEP_BACK_DEPTH];
  81                       // who allocated this
  82   int   lockcount;    // how many times it's been locked/unlocked (lock=+1, unlock=-1)
  83   int   irqcount;     // how many times interrupts have been turned off (+1/-1)
  84   void *lastlocker[STEP_BACK_DEPTH];
  85                       // who last locked
  86   void *lastunlocker[STEP_BACK_DEPTH];
  87                       // who last unlocked
  88   void *lastirqlocker[STEP_BACK_DEPTH];
  89                       // who last locked
  90   unsigned long lastlockflags; // their flags
  91   unsigned long locktime;
  92                       // when it was locked
  93   void *lastirqunlocker[STEP_BACK_DEPTH]
  94                     ; // who last unlocked
  95   unsigned long lastunlockflags; // their flags
  96   int   hotlockcount; // how many times it's been locked
  97 } lockcheck_state_t;
  98
  99
 100 // This lock is currently used only to control
 101 // allocation of entries in the global state
 102 static spinlock_t mylock;
 103 static lockcheck_state_t state[NUM_LOCKS];
 104 static lockcheck_state_t *sorted_state[NUM_LOCKS];
 105
 106 static int numout=0;
 107
 108 static int globallockcount=0;
 109
 110 static struct timer_list  long_lock_timer;
 111
 112
 113 #define DEBUG_OUTPUT(fmt, args...)                                      \
 114 do {                                                                    \
 115   numout++;                                                             \
 116   if (numout>=OUTPUT_SKIP) {                                            \
 117     if (OUTPUT_LIMIT==0 ||(numout-OUTPUT_SKIP)<OUTPUT_LIMIT) {          \
 118       DEBUG(fmt, ##args);                                               \
 119     } else {                                                            \
 120       if ((numout-OUTPUT_SKIP)==OUTPUT_LIMIT) {                         \
 121         DEBUG("LOCKCHECK: Output limit hit - no further printouts\n");  \
 122       }                                                                 \
 123     }                                                                   \
 124   }                                                                     \
 125 } while (0)
 126
 127 #define DEBUG_DUMPSTACK()                                               \
 128 do {                                                                    \
 129   if (numout>=OUTPUT_SKIP) {                                            \
 130     if (OUTPUT_LIMIT==0 || (numout-OUTPUT_SKIP)<OUTPUT_LIMIT) {         \
 131       dump_stack();                                                     \
 132     }                                                                   \
 133   }                                                                     \
 134 } while (0)
 135
 136 #if LOCK_SELF
 137 #define LOCK_DECL unsigned long f
 138 #define LOCK() spin_lock_irqsave(&mylock,f)
 139 #define UNLOCK() spin_unlock_irqrestore(&mylock,f)
 140 #define LOCK_ALLOC_DECL
 141 #define LOCK_ALLOC()
 142 #define UNLOCK_ALLOC()
 143 #else
 144 #define LOCK_DECL
 145 #define LOCK()
 146 #define UNLOCK()
 147 #define LOCK_ALLOC_DECL unsigned long f
 148 #define LOCK_ALLOC() spin_lock_irqsave(&mylock,f)
 149 #define UNLOCK_ALLOC() spin_unlock_irqrestore(&mylock,f)
 150 #endif
 151
 152 static void printlock(char *prefix, lockcheck_state_t *l);
 153
 154 typedef struct {
 155   u32 top;               // next open slot 0..
 156   void *lock[LOCK_STACK_DEPTH]; // the stack
 157   char irq[LOCK_STACK_DEPTH];   // locked with irqsave?
 158   char irqoff[LOCK_STACK_DEPTH]; // if so, what was the flag?
 159 } lock_stack_t;
 160
 161 static DEFINE_PER_CPU(lock_stack_t, lock_stack);
 162
 163 static lockcheck_state_t *get_lock_entry(void)
 164 {
 165   int i;
 166   lockcheck_state_t *l;
 167   LOCK_ALLOC_DECL;
 168
 169   LOCK_ALLOC();
 170   for (i=0;i<NUM_LOCKS;i++) {
 171     l=&(state[i]);
 172     if (!(l->inuse)) {
 173       l->inuse=1;
 174       break;
 175     }
 176   }
 177   UNLOCK_ALLOC();
 178
 179   if (i<NUM_LOCKS) {
 180     return l;
 181   } else {
 182     return 0;
 183   }
 184 }
 185
 186
 187 static lockcheck_state_t *find_lock_entry(void *lock)
 188 {
 189   int i;
 190   lockcheck_state_t *l;
 191
 192   for (i=0;i<NUM_LOCKS;i++) {
 193     l=&(state[i]);
 194     if (l->inuse && l->lock == lock) {
 195       return l;
 196     }
 197   }
 198   return 0;
 199 }
 200
 201
 202 static void free_lock_entry(lockcheck_state_t *l)
 203 {
 204   l->inuse=0;
 205 }
 206
 207
 208 static void lock_stack_print(void)
 209 {
 210   u32 i;
 211   char buf[64];
 212   lock_stack_t *mystack = &(get_cpu_var(lock_stack));
 213   u32 cpu = get_cpu();  put_cpu();
 214
 215   if ((mystack->top)>0) {
 216     for (i=mystack->top; i>0;i--) {
 217       snprintf(buf,64,"LOCK STACK (cpu=%u, index=%u, irq=%d, irqoff=%d)",cpu, i-1, (int)(mystack->irq[i-1]), (int)(mystack->irqoff[i-1]));
 218       printlock(buf,find_lock_entry(mystack->lock[i-1]));
 219     }
 220   }
 221   put_cpu_var(lock_stack);
 222 }
 223
 224
 225 static void lock_stack_lock(void *lock, char irq, unsigned long flags)
 226 {
 227   lock_stack_t *mystack = &(get_cpu_var(lock_stack));
 228   u32 cpu = get_cpu();  put_cpu();
 229
 230   if (mystack->top>=(LOCK_STACK_DEPTH-1)) {
 231     put_cpu_var(lock_stack);
 232     DEBUG_OUTPUT("LOCKCHECK: Locking lock 0x%p on cpu %u exceeds stack limit of %d\n",lock,cpu,LOCK_STACK_DEPTH);
 233     lock_stack_print();
 234   } else {
 235     int oldtop = mystack->top;
 236     mystack->lock[mystack->top] = lock;
 237     mystack->irq[mystack->top] = irq;
 238     mystack->irqoff[mystack->top] = irqs_disabled_flags(flags);
 239     mystack->top++;
 240     put_cpu_var(lock_stack);
 241     if (CHECK_IRQ_FIRST_ACQUIRE && oldtop==0 && irqs_disabled_flags(flags) ) {
 242        DEBUG_OUTPUT("LOCKCHECK: First lock on lock stack of processor %d but irqs were already disabled - stack trace follows\n", cpu);
 243        DEBUG_DUMPSTACK();
 244     }
 245
 246   }
 247
 248
 249 }
 250
 251 static void lock_stack_unlock(void *lock, char irq, unsigned long flags)
 252 {
 253   lock_stack_t *mystack = &(get_cpu_var(lock_stack));
 254   u32 cpu = get_cpu(); put_cpu();
 255
 256   if (mystack->top==0) {
 257     put_cpu_var(lock_stack);
 258     DEBUG_OUTPUT("LOCKCHECK: Unlocking lock 0x%p on cpu %u when lock stack is empty\n",lock,cpu);
 259   } else {
 260     if (mystack->lock[mystack->top-1] != lock) {
 261       void *otherlock=mystack->lock[mystack->top-1];
 262       put_cpu_var(lock_stack);
 263       DEBUG_OUTPUT("LOCKCHECK: Unlocking lock 0x%p on cpu %u when top of stack is lock 0x%p\n",lock,cpu, otherlock);
 264       lock_stack_print();
 265     } else {
 266       if (irq!=mystack->irq[mystack->top-1]) {
 267         char otherirq = mystack->irq[mystack->top-1];
 268         put_cpu_var(lock_stack);
 269         DEBUG_OUTPUT("LOCKCHECK: Unlocking lock 0x%p on cpu %u with irq=%d, but was locked with irq=%d\n",lock,cpu,irq,otherirq);
 270         lock_stack_print();
 271         mystack = &(get_cpu_var(lock_stack));
 272         mystack->top--;
 273         put_cpu_var(lock_stack);
 274       } else {
 275         if (irq) {
 276           if (irqs_disabled_flags(flags)!=mystack->irqoff[mystack->top-1]) {
 277              char otherirqoff = mystack->irqoff[mystack->top-1];
 278              put_cpu_var(lock_stack);
 279              DEBUG_OUTPUT("LOCKCHECK: Unlocking lock 0x%p on cpu %u sets irqoff=%d but the matching lock returned irqoff=%d\n", lock, cpu, irqs_disabled_flags(flags), otherirqoff);
 280              lock_stack_print();
 281              mystack = &(get_cpu_var(lock_stack));
 282              mystack->top--;
 283              put_cpu_var(lock_stack);
 284           } else {
 285             // irq, and irq states match - good
 286             mystack->top--;
 287             put_cpu_var(lock_stack);
 288           }
 289         } else {
 290           // !irq - we are good
 291           mystack->top--;
 292           put_cpu_var(lock_stack);
 293         }
 294       }
 295     }
 296   }
 297
 298   mystack = &(get_cpu_var(lock_stack));
 299   if (mystack->top == 0) {
 300     put_cpu_var(lock_stack);
 301     if (CHECK_IRQ_LAST_RELEASE && irqs_disabled()) {
 302        DEBUG_OUTPUT("LOCKCHECK: Lock stack on cpu %u is now empty, but irqs are still disabled! Stack trace follows\n", cpu);
 303        DEBUG_DUMPSTACK();
 304     }
 305   } else {
 306     put_cpu_var(lock_stack);
 307   }
 308
 309 }
 310
 311
 312 // pointers are to the pointers in the sorted_state array
 313 int compare(const void *a, const void *b)
 314 {
 315   lockcheck_state_t *l = *((lockcheck_state_t **)a);
 316   lockcheck_state_t *r = *((lockcheck_state_t **)b);
 317
 318   return -(l->hotlockcount - r->hotlockcount);
 319 }
 320
 321 static void hot_lock_show(void)
 322 {
 323   int n, i;
 324   char buf[64];
 325
 326   n=0;
 327   for (i=0;i<NUM_LOCKS;i++) {
 328     if (state[i].inuse) {
 329       sorted_state[n]=&(state[i]);
 330       n++;
 331     }
 332   }
 333
 334   sort(sorted_state,n,sizeof(lockcheck_state_t *),compare,NULL);
 335
 336   for (i=0;i<n;i++) {
 337     snprintf(buf,64,"HOT LOCK (%d of %d) %d acquires", i,n,sorted_state[i]->hotlockcount);
 338     printlock(buf,sorted_state[i]);
 339   }
 340 }
 341
 342
 343 static void hot_lock_lock(void *lock)
 344 {
 345   lockcheck_state_t *l = find_lock_entry(lock);
 346
 347   if (!l) { return; }
 348
 349   l->hotlockcount++;
 350   globallockcount++;
 351
 352   if (HOT_LOCK_INTERVAL && !(globallockcount % HOT_LOCK_INTERVAL )) {
 353     DEBUG_OUTPUT("LOCKCHECK: Hot locks after %d acquires Follow\n",globallockcount);
 354     hot_lock_show();
 355   }
 356 }
 357
 358
 359 #define hot_lock_unlock(X) // nothing for now
 360
 361
 362 void long_lock_callback(unsigned long ignored)
 363 {
 364   // See if any lock has been held for too long
 365   // then print all the locks if it has
 366
 367   // Note that this function does not lock because the
 368   // idea is to try to catch a deadlock, which might
 369   // imply that we are stalled waiting on our lock already
 370
 371   int i;
 372   int have=0;
 373   lockcheck_state_t *l;
 374   char buf[64];
 375   unsigned long now;
 376
 377
 378   now = jiffies;
 379
 380   for (i=0;i<NUM_LOCKS;i++) {
 381     l=&(state[i]);
 382     if (l->inuse && (l->irqcount>0 || l->lockcount>0)) {
 383       if (jiffies_to_msecs(now-l->locktime)>LONG_LOCK_HELD_MS) {
 384         have++;
 385       }
 386     }
 387   }
 388
 389   if (have>0) {
 390     DEBUG_OUTPUT("LOCKCHECK: LONG LOCK: %d locks have been held longer than %u ms - Dump of all held locks Follows\n",have,LONG_LOCK_HELD_MS);
 391     have=0;
 392     for (i=0;i<NUM_LOCKS;i++) {
 393       l=&(state[i]);
 394       if (l->inuse && (l->irqcount>0 || l->lockcount>0)) {
 395         snprintf(buf,64,"LONG LOCK (%d - %s)",
 396                  have,
 397                  jiffies_to_msecs(now-l->locktime)>LONG_LOCK_HELD_MS ? "**OLD**" : "ok");
 398         printlock(buf,l);
 399         have++;
 400       }
 401     }
 402   }
 403
 404   // reset the timer to run again
 405
 406   mod_timer(&long_lock_timer,jiffies+msecs_to_jiffies(LONG_LOCK_INTERVAL_MS));
 407
 408 }
 409
 410
 411 void palacios_lockcheck_init()
 412 {
 413   memset(state,0,sizeof(lockcheck_state_t)*NUM_LOCKS);
 414   spin_lock_init(&mylock);
 415
 416 #if LONG_LOCK_INTERVAL_MS>0
 417   setup_timer(&long_lock_timer,long_lock_callback,0);
 418   mod_timer(&long_lock_timer, jiffies + msecs_to_jiffies(LONG_LOCK_INTERVAL_MS));
 419 #endif
 420
 421   DEBUG_OUTPUT("LOCKCHECK: LOCK CHECKING INITED (internal locking: %d, output limit: %d, output skip: %d)\n",LOCK_SELF,OUTPUT_LIMIT,OUTPUT_SKIP);
 422 }
 423
 424 //
 425 // This needs to be defined explictly since the intrinsic does not take a var
 426 //
 427 #define backtrace(t) \
 428   t[0]=__builtin_return_address(STEP_BACK_DEPTH_FIRST); \
 429   t[1]=__builtin_return_address(STEP_BACK_DEPTH_FIRST+1); \
 430   t[2]=__builtin_return_address(STEP_BACK_DEPTH_FIRST+2); \
 431   t[3]=__builtin_return_address(STEP_BACK_DEPTH_FIRST+3);
 432
 433 //
 434 // For printing a backtrace
 435 //
 436 //
 437 #define backtrace_format "%pS << %pS << %pS << %pS"
 438 #define backtrace_expand(t) ((t)[0]),((t)[1]),((t)[2]),((t)[3])
 439
 440
 441 static void clear_trace(void **trace)
 442 {
 443   int i;
 444
 445   for (i=0;i<STEP_BACK_DEPTH;i++) {
 446     trace[i]=0;
 447   }
 448 }
 449
 450
 451 static void printlock(char *prefix, lockcheck_state_t *l)
 452 {
 453   if (!l || !(l->lock) ) {
 454     DEBUG_OUTPUT("LOCKCHECK: %s: lock 0x%p BOGUS\n",prefix,l);
 455     return;
 456   }
 457   if (l->lock) {
 458     DEBUG_OUTPUT("LOCKCHECK: %s: lock 0x%p, holder %s on %u, allocator="
 459           backtrace_format
 460           ", lockcount=%d, lastlocker="
 461           backtrace_format
 462           ", lastunlocker="
 463           backtrace_format
 464           ", irqcount=%d, lastirqlocker="
 465           backtrace_format
 466           ", lastlockflags=%lu, lastirqunlocker="
 467           backtrace_format
 468           ", lastunlockflags=%lu"
 469           ", lockage=%ums\n",
 470           prefix,l->lock,
 471           l->holder ? ((struct task_struct *)(l->holder))->comm : "none",
 472           l->holdingcpu,
 473           backtrace_expand(l->allocator),
 474           l->lockcount,
 475           backtrace_expand(l->lastlocker),
 476           backtrace_expand(l->lastunlocker),
 477           l->irqcount,
 478           backtrace_expand(l->lastirqlocker),
 479           l->lastlockflags,
 480           backtrace_expand(l->lastirqunlocker),
 481           l->lastunlockflags,
 482           (l->lockcount>0) || (l->irqcount>0) ? jiffies_to_msecs(jiffies-l->locktime) : 0);
 483   }
 484 }
 485
 486
 487
 488
 489
 490
 491 static void find_multiple_locks_held(void)
 492 {
 493   int i;
 494   int have=0;
 495   lockcheck_state_t *l;
 496   char buf[64];
 497
 498   for (i=0;i<NUM_LOCKS;i++) {
 499     l=&(state[i]);
 500     if (l->inuse && l->lockcount>0) {
 501       have++;
 502       if (have>=WARN_MULTIPLE_THRESHOLD) {
 503         break;
 504       }
 505     }
 506   }
 507
 508   if (have>=WARN_MULTIPLE_THRESHOLD) {
 509     have=0;
 510     for (i=0;i<NUM_LOCKS;i++) {
 511       l=&(state[i]);
 512       if (l->inuse && l->lockcount>0) {
 513         snprintf(buf,64,"MULTIPLE LOCKS HELD (%d)",have);
 514         printlock(buf,l);
 515         have++;
 516       }
 517     }
 518   }
 519
 520 }
 521
 522 static void find_multiple_irqs_held(void)
 523 {
 524   int i;
 525   int have=0;
 526   lockcheck_state_t *l;
 527   char buf[64];
 528
 529   for (i=0;i<NUM_LOCKS;i++) {
 530     l=&(state[i]);
 531     if (l->inuse && l->irqcount>0) {
 532       have++;
 533       if (have>=WARN_MULTIPLE_THRESHOLD) {
 534         break;
 535       }
 536     }
 537   }
 538
 539   if (have>=WARN_MULTIPLE_THRESHOLD) {
 540     have=0;
 541     for (i=0;i<NUM_LOCKS;i++) {
 542       l=&(state[i]);
 543       if (l->inuse && l->irqcount>0) {
 544         snprintf(buf,64,"MULTIPLE IRQS HELD (%d)",have);
 545         printlock(buf,l);
 546         have++;
 547       }
 548     }
 549   }
 550
 551 }
 552
 553
 554 void palacios_lockcheck_deinit()
 555 {
 556   int i;
 557   lockcheck_state_t *l;
 558   LOCK_DECL;
 559
 560   LOCK();
 561
 562   for (i=0;i<NUM_LOCKS;i++) {
 563     l=&(state[i]);
 564     if (l->lock) {
 565       printlock("ALLOCATED LOCK AT DEINIT",l);
 566       if ((l->lockcount)) {
 567         printlock("BAD LOCK COUNT AT DEINIT",l);
 568       }
 569       if ((l->irqcount)) {
 570         printlock("BAD IRQ COUNT AT DEINIT",l);
 571       }
 572     }
 573   }
 574 #if LONG_LOCK_INTERVAL_MS>0
 575   del_timer(&long_lock_timer);
 576 #endif
 577   UNLOCK();
 578   INFO("LOCKCHECK: DEINITED\n");
 579 }
 580
 581
 582 void palacios_lockcheck_alloc(void *lock)
 583 {
 584   lockcheck_state_t *l;
 585   LOCK_DECL;
 586
 587   LOCK();
 588
 589   l=get_lock_entry();
 590
 591   if (!l) {
 592     DEBUG_OUTPUT("LOCKCHECK: UNABLE TO ALLOCATE TRACKING DATA FOR LOCK 0x%p\n",lock);
 593   }
 594   l->lock=lock;
 595   backtrace(l->allocator);
 596   l->lockcount=l->irqcount=0;
 597   clear_trace(l->lastlocker);
 598   clear_trace(l->lastunlocker);
 599   clear_trace(l->lastirqlocker);
 600   clear_trace(l->lastirqunlocker);
 601   //INFO("LOCKCHECK: LOCK ALLOCATE 0x%p\n",lock);
 602 #if PRINT_LOCK_ALLOC
 603   printlock("NEW LOCK", l);
 604 #endif
 605
 606   UNLOCK();
 607 }
 608
 609 void palacios_lockcheck_free(void *lock)
 610 {
 611   lockcheck_state_t *l;
 612   LOCK_DECL;
 613
 614   LOCK();
 615   l=find_lock_entry(lock);
 616
 617   if (!l){
 618     UNLOCK();
 619     DEBUG_OUTPUT("LOCKCHECK: FREEING UNTRACKED LOCK 0x%p - stack trace follows\n",lock);
 620     DEBUG_DUMPSTACK();
 621     return;
 622   }
 623
 624   if ((l->lockcount)) {
 625     printlock("BAD LOCK COUNT AT FREE",l);
 626   }
 627
 628   if ((l->irqcount)) {
 629     printlock("BAD IRQ COUNT AT FREE",l);
 630   }
 631
 632 #if PRINT_LOCK_FREE
 633   printlock("FREE LOCK",l);
 634 #endif
 635
 636   free_lock_entry(l);
 637
 638   UNLOCK();
 639
 640 }
 641
 642 void palacios_lockcheck_lock(void *lock)
 643 {
 644   LOCK_DECL;
 645   lockcheck_state_t *l;
 646
 647
 648   LOCK();
 649
 650   l=find_lock_entry(lock);
 651
 652   if (!l) {
 653     UNLOCK();
 654     DEBUG_OUTPUT("LOCKCHECK: LOCKING UNTRACKED LOCK 0x%p - stack follows\n",lock);
 655     DEBUG_DUMPSTACK();
 656     return;
 657   }
 658
 659   if (l->lockcount!=0) {
 660     printlock("BAD LOCKCOUNT AT LOCK - stack follows",l);
 661     DEBUG_DUMPSTACK();
 662   }
 663   if (l->irqcount!=0) {
 664     printlock("BAD IRQCOUNT AT LOCK - stack follows",l);
 665     DEBUG_DUMPSTACK();
 666   }
 667
 668   l->lockcount++;
 669   l->holder=current;
 670   l->holdingcpu=get_cpu(); put_cpu();
 671   l->locktime=jiffies;
 672   backtrace(l->lastlocker);
 673
 674   find_multiple_locks_held();
 675
 676   lock_stack_lock(lock,0,0);
 677
 678   hot_lock_lock(lock);
 679
 680 #if PRINT_LOCK_LOCK
 681   printlock("LOCK",l);
 682 #endif
 683
 684   UNLOCK();
 685
 686 }
 687 void palacios_lockcheck_unlock(void *lock)
 688 {
 689   LOCK_DECL;
 690   lockcheck_state_t *l;
 691
 692   LOCK();
 693
 694   l=find_lock_entry(lock);
 695
 696   if (!l) {
 697     UNLOCK();
 698     DEBUG_OUTPUT("LOCKCHECK: UNLOCKING UNTRACKED LOCK 0x%p - stack follows\n",lock);
 699     DEBUG_DUMPSTACK();
 700     return;
 701   }
 702
 703   if (l->lockcount!=1) {
 704     printlock("LOCKCHECK: BAD LOCKCOUNT AT UNLOCK - stack follows",l);
 705     DEBUG_DUMPSTACK();
 706   }
 707   if (l->irqcount!=0) {
 708     printlock("LOCKCHECK: BAD IRQCOUNT AT UNLOCK - stack follows",l);
 709     DEBUG_DUMPSTACK();
 710   }
 711
 712   lock_stack_unlock(lock,0,0);
 713
 714   hot_lock_unlock(lock);
 715
 716   l->holder=0;
 717   l->holdingcpu=0;
 718   l->lockcount--;
 719   backtrace(l->lastunlocker);
 720
 721 #if PRINT_LOCK_UNLOCK
 722   printlock("UNLOCK",l);
 723 #endif
 724
 725   UNLOCK();
 726
 727 }
 728
 729 void palacios_lockcheck_lock_irqsave(void *lock,unsigned long flags)
 730 {
 731   LOCK_DECL;
 732   lockcheck_state_t *l;
 733
 734   LOCK();
 735
 736   l=find_lock_entry(lock);
 737
 738   if (!l) {
 739     UNLOCK();
 740     DEBUG_OUTPUT("LOCKCHECK: IRQ LOCKING UNTRACKED LOCK 0x%p - stack follows\n",lock);
 741     DEBUG_DUMPSTACK();
 742     return;
 743   }
 744
 745   if (l->lockcount!=0) {
 746     printlock("BAD LOCKCOUNT AT IRQ LOCK - stack follows",l);
 747     DEBUG_DUMPSTACK();
 748   }
 749   if (l->irqcount!=0) {
 750     printlock("BAD IRQCOUNT AT IRQ LOCK - stack follows",l);
 751     DEBUG_DUMPSTACK();
 752   }
 753
 754   l->irqcount++;
 755   l->holder=current;
 756   l->holdingcpu=get_cpu(); put_cpu();
 757   l->lastlockflags=flags;
 758   l->locktime=jiffies;
 759   backtrace(l->lastirqlocker);
 760
 761   find_multiple_irqs_held();
 762
 763   lock_stack_lock(lock,1,flags);
 764
 765   hot_lock_lock(lock);
 766
 767 #if PRINT_LOCK_LOCK
 768   printlock("LOCK_IRQSAVE",l);
 769 #endif
 770
 771   UNLOCK();
 772
 773
 774 }
 775
 776
 777 //
 778 // This is separated into two components to avoid a race between
 779 // the underlying spin_unlock_irqrestore and the next lockcheck_lock_irqsave
 780 // If simply record the state after the unlock, we might see that the
 781 // irqcount has already increased.  Therefore, we will acquire the
 782 // lockchecker lock in _pre and release it in _post.  Note that when
 783 // we release the lock in _post, we restore the flags provided by the
 784 // code under test - NOT our original flags
 785 //
 786 // unlock_pre() - stores flags, takes mylock discard flags
 787 // At this point, a lockcheck_lock cannot enter, since it's stuck on mylock
 788 // spinunlock - restores lock, restores original flags
 789 // unlock_post() - restores mylock WITH orig flags
 790 //
 791 void palacios_lockcheck_unlock_irqrestore_pre(void *lock,unsigned long flags)
 792 {
 793   LOCK_DECL;
 794
 795   LOCK();  // flags are discarded
 796   // at this point, the actual spin unlock can run
 797   // if another thread hits lockcheck_irqsave at this point, it
 798   // will block on mylock
 799 }
 800
 801 void palacios_lockcheck_unlock_irqrestore_post(void *lock,unsigned long flags)
 802 {
 803   LOCK_DECL;
 804   lockcheck_state_t *l;
 805
 806 #if LOCK_SELF
 807   // when we unlock, want to restore the flags *the user wants*
 808   f = flags;
 809 #endif
 810
 811   // Note that we DO NOT take mylock here, since we already took it in
 812   // _pre
 813
 814   l=find_lock_entry(lock);
 815
 816   if (!l) {
 817     UNLOCK();  // release any waiting threads on lockcheck_lock_irqsave
 818     DEBUG_OUTPUT("LOCKCHECK: IRQ UNLOCKING UNTRACKED LOCK 0x%p - stack follows\n",lock);
 819     DEBUG_DUMPSTACK();
 820     return;
 821   }
 822
 823   if (l->lockcount!=0) {
 824     printlock("LOCKCHECK: BAD LOCKCOUNT AT IRQ UNLOCK - stack follows",l);
 825     DEBUG_DUMPSTACK();
 826   }
 827   if (l->irqcount!=1) {
 828     printlock("LOCKCHECK: BAD IRQCOUNT AT IRQ UNLOCK - stack follows",l);
 829     DEBUG_DUMPSTACK();
 830   }
 831
 832   l->holder=0;
 833   l->holdingcpu=0;
 834   l->irqcount--;
 835   l->lastunlockflags = flags;
 836
 837   lock_stack_unlock(lock,1,flags);
 838
 839   hot_lock_unlock(lock);
 840
 841   backtrace(l->lastirqunlocker);
 842
 843 #if PRINT_LOCK_UNLOCK
 844   printlock("UNLOCK_IRQRESTORE",l);
 845 #endif
 846   UNLOCK(); // release any waiting threads on lockcheck_lock_irqsave
 847
 848 }