linux_module/lockcheck.c

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