1 #include <linux/kernel.h>
2 #include <linux/kthread.h>
3 #include <linux/spinlock.h>
4 #include <linux/sort.h>
11 // Number of outputs possible before output stops
12 // set to zero to remove the limit
13 #define OUTPUT_LIMIT 0
15 // Number of outputs to skip before
16 // printing and counting
20 // Whether or not to print these events
22 #define PRINT_LOCK_ALLOC 0
23 #define PRINT_LOCK_FREE 0
24 #define PRINT_LOCK_LOCK 0
25 #define PRINT_LOCK_UNLOCK 0
27 // How far up the stack to track the caller
30 // 2 => caller of v3_lock..
32 #define STEP_BACK_DEPTH_FIRST 1
33 #define STEP_BACK_DEPTH_LAST 4
34 #define STEP_BACK_DEPTH (STEP_BACK_DEPTH_LAST-STEP_BACK_DEPTH_FIRST+1)
36 // show when multiple locks are held simultaneously
37 // This is the minimum number
38 #define WARN_MULTIPLE_THRESHOLD 3
40 // Detect when last lock a processor holds is released
41 // but interrupts remain off, similarly for first acquire
42 #define CHECK_IRQ_LAST_RELEASE 0
43 #define CHECK_IRQ_FIRST_ACQUIRE 1
45 // Show hottest locks every this many locks or lock_irqsaves
46 // 0 indicates this should not be shown
47 #define HOT_LOCK_INTERVAL 1000
50 // Whether lockcheck should lock its own data structures during an
51 // event (alloc, dealloc, lock, unlock, etc) and the subsequent
52 // checking. If this is off, it will only lock on a lock allocation,
53 // in order to assure each lock has a distinct slot. If this is off,
54 // lockcheck may miss problems (or see additional problems) due to
55 // internal race conditions. However, if it is on, lockcheck is
56 // essentially adding a global lock acuire to each lock operation in
57 // palacios, which will perturb palacios.
63 int inuse; // nonzero if this is in use
64 void *lock; // the lock
65 void *holder; // current thread holding it
66 u32 holdingcpu; // on which cpu it acquired it
67 void *allocator[STEP_BACK_DEPTH];
69 int lockcount; // how many times it's been locked/unlocked (lock=+1, unlock=-1)
70 int irqcount; // how many times interrupts have been turned off (+1/-1)
71 void *lastlocker[STEP_BACK_DEPTH];
73 void *lastunlocker[STEP_BACK_DEPTH];
75 void *lastirqlocker[STEP_BACK_DEPTH];
77 unsigned long lastlockflags; // their flags
78 void *lastirqunlocker[STEP_BACK_DEPTH]
79 ; // who last unlocked
80 unsigned long lastunlockflags; // their flags
81 int hotlockcount; // how many times it's been locked
85 // This lock is currently used only to control
86 // allocation of entries in the global state
87 static spinlock_t mylock;
88 static lockcheck_state_t state[NUM_LOCKS];
89 static lockcheck_state_t *sorted_state[NUM_LOCKS];
93 static int globallockcount=0;
95 #define DEBUG_OUTPUT(fmt, args...) \
98 if (numout>=OUTPUT_SKIP) { \
99 if (OUTPUT_LIMIT==0 ||(numout-OUTPUT_SKIP)<OUTPUT_LIMIT) { \
100 DEBUG(fmt, ##args); \
102 if ((numout-OUTPUT_SKIP)==OUTPUT_LIMIT) { \
103 DEBUG("LOCKCHECK: Output limit hit - no further printouts\n"); \
109 #define DEBUG_DUMPSTACK() \
111 if (numout>=OUTPUT_SKIP) { \
112 if (OUTPUT_LIMIT==0 || (numout-OUTPUT_SKIP)<OUTPUT_LIMIT) { \
119 #define LOCK_DECL unsigned long f
120 #define LOCK() spin_lock_irqsave(&mylock,f)
121 #define UNLOCK() spin_unlock_irqrestore(&mylock,f)
122 #define LOCK_ALLOC_DECL
124 #define UNLOCK_ALLOC()
129 #define LOCK_ALLOC_DECL unsigned long f
130 #define LOCK_ALLOC() spin_lock_irqsave(&mylock,f)
131 #define UNLOCK_ALLOC() spin_unlock_irqrestore(&mylock,f)
134 static void printlock(char *prefix, lockcheck_state_t *l);
138 u32 top; // next open slot 0..
139 void *lock[LOCK_STACK_DEPTH]; // the stack
140 char irq[LOCK_STACK_DEPTH]; // locked with irqsave?
141 char irqoff[LOCK_STACK_DEPTH]; // if so, what was the flag?
144 static DEFINE_PER_CPU(lock_stack_t, lock_stack);
146 static lockcheck_state_t *get_lock_entry(void)
149 lockcheck_state_t *l;
153 for (i=0;i<NUM_LOCKS;i++) {
170 static lockcheck_state_t *find_lock_entry(void *lock)
173 lockcheck_state_t *l;
175 for (i=0;i<NUM_LOCKS;i++) {
177 if (l->inuse && l->lock == lock) {
185 static void free_lock_entry(lockcheck_state_t *l)
191 static void lock_stack_print(void)
195 lock_stack_t *mystack = &(get_cpu_var(lock_stack));
196 u32 cpu = get_cpu(); put_cpu();
198 if ((mystack->top)>0) {
199 for (i=mystack->top; i>0;i--) {
200 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]));
201 printlock(buf,find_lock_entry(mystack->lock[i-1]));
204 put_cpu_var(lock_stack);
208 static void lock_stack_lock(void *lock, char irq, unsigned long flags)
210 lock_stack_t *mystack = &(get_cpu_var(lock_stack));
211 u32 cpu = get_cpu(); put_cpu();
213 if (mystack->top>=(LOCK_STACK_DEPTH-1)) {
214 put_cpu_var(lock_stack);
215 DEBUG_OUTPUT("LOCKCHECK: Locking lock 0x%p on cpu %u exceeds stack limit of %d\n",lock,cpu,LOCK_STACK_DEPTH);
218 int oldtop = mystack->top;
219 mystack->lock[mystack->top] = lock;
220 mystack->irq[mystack->top] = irq;
221 mystack->irqoff[mystack->top] = irqs_disabled_flags(flags);
223 put_cpu_var(lock_stack);
224 if (CHECK_IRQ_FIRST_ACQUIRE && oldtop==0 && irqs_disabled_flags(flags) ) {
225 DEBUG_OUTPUT("LOCKCHECK: First lock on lock stack of processor %d but irqs were already disabled - stack trace follows\n", cpu);
234 static void lock_stack_unlock(void *lock, char irq, unsigned long flags)
236 lock_stack_t *mystack = &(get_cpu_var(lock_stack));
237 u32 cpu = get_cpu(); put_cpu();
239 if (mystack->top==0) {
240 put_cpu_var(lock_stack);
241 DEBUG_OUTPUT("LOCKCHECK: Unlocking lock 0x%p on cpu %u when lock stack is empty\n",lock,cpu);
243 if (mystack->lock[mystack->top-1] != lock) {
244 void *otherlock=mystack->lock[mystack->top-1];
245 put_cpu_var(lock_stack);
246 DEBUG_OUTPUT("LOCKCHECK: Unlocking lock 0x%p on cpu %u when top of stack is lock 0x%p\n",lock,cpu, otherlock);
249 if (irq!=mystack->irq[mystack->top-1]) {
250 char otherirq = mystack->irq[mystack->top-1];
251 put_cpu_var(lock_stack);
252 DEBUG_OUTPUT("LOCKCHECK: Unlocking lock 0x%p on cpu %u with irq=%d, but was locked with irq=%d\n",lock,cpu,irq,otherirq);
254 mystack = &(get_cpu_var(lock_stack));
256 put_cpu_var(lock_stack);
259 if (irqs_disabled_flags(flags)!=mystack->irqoff[mystack->top-1]) {
260 char otherirqoff = mystack->irqoff[mystack->top-1];
261 put_cpu_var(lock_stack);
262 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);
264 mystack = &(get_cpu_var(lock_stack));
266 put_cpu_var(lock_stack);
268 // irq, and irq states match - good
270 put_cpu_var(lock_stack);
273 // !irq - we are good
275 put_cpu_var(lock_stack);
281 mystack = &(get_cpu_var(lock_stack));
282 if (mystack->top == 0) {
283 put_cpu_var(lock_stack);
284 if (CHECK_IRQ_LAST_RELEASE && irqs_disabled()) {
285 DEBUG_OUTPUT("LOCKCHECK: Lock stack on cpu %u is now empty, but irqs are still disabled! Stack trace follows\n", cpu);
289 put_cpu_var(lock_stack);
295 // pointers are to the pointers in the sorted_state array
296 int compare(const void *a, const void *b)
298 lockcheck_state_t *l = *((lockcheck_state_t **)a);
299 lockcheck_state_t *r = *((lockcheck_state_t **)b);
301 return -(l->hotlockcount - r->hotlockcount);
304 static void hot_lock_show(void)
310 for (i=0;i<NUM_LOCKS;i++) {
311 if (state[i].inuse) {
312 sorted_state[n]=&(state[i]);
317 sort(sorted_state,n,sizeof(lockcheck_state_t *),compare,NULL);
320 snprintf(buf,64,"HOT LOCK (%d of %d) %d acquires", i,n,sorted_state[i]->hotlockcount);
321 printlock(buf,sorted_state[i]);
326 static void hot_lock_lock(void *lock)
328 lockcheck_state_t *l = find_lock_entry(lock);
335 if (HOT_LOCK_INTERVAL && !(globallockcount % HOT_LOCK_INTERVAL )) {
336 DEBUG_OUTPUT("LOCKCHECK: Hot locks after %d acquires Follow\n",globallockcount);
342 #define hot_lock_unlock(X) // nothing for now
346 void palacios_lockcheck_init()
348 memset(state,0,sizeof(lockcheck_state_t)*NUM_LOCKS);
349 spin_lock_init(&mylock);
350 DEBUG_OUTPUT("LOCKCHECK: LOCK CHECKING INITED (internal locking: %d, output limit: %d, output skip: %d)\n",LOCK_SELF,OUTPUT_LIMIT,OUTPUT_SKIP);
354 // This needs to be defined explictly since the intrinsic does not take a var
356 #define backtrace(t) \
357 t[0]=__builtin_return_address(STEP_BACK_DEPTH_FIRST); \
358 t[1]=__builtin_return_address(STEP_BACK_DEPTH_FIRST+1); \
359 t[2]=__builtin_return_address(STEP_BACK_DEPTH_FIRST+2); \
360 t[3]=__builtin_return_address(STEP_BACK_DEPTH_FIRST+3);
363 // For printing a backtrace
366 #define backtrace_format "%pS << %pS << %pS << %pS"
367 #define backtrace_expand(t) ((t)[0]),((t)[1]),((t)[2]),((t)[3])
370 static void clear_trace(void **trace)
374 for (i=0;i<STEP_BACK_DEPTH;i++) {
380 static void printlock(char *prefix, lockcheck_state_t *l)
382 if (!l || !(l->lock) ) {
383 DEBUG_OUTPUT("LOCKCHECK: %s: lock 0x%p BOGUS\n",prefix,l);
387 DEBUG_OUTPUT("LOCKCHECK: %s: lock 0x%p, holder %s on %u, allocator="
389 ", lockcount=%d, lastlocker="
393 ", irqcount=%d, lastirqlocker="
395 ", lastlockflags=%lu, lastirqunlocker="
397 ", lastunlockflags=%lu\n",
399 l->holder ? ((struct task_struct *)(l->holder))->comm : "none",
401 backtrace_expand(l->allocator),
403 backtrace_expand(l->lastlocker),
404 backtrace_expand(l->lastunlocker),
406 backtrace_expand(l->lastirqlocker),
408 backtrace_expand(l->lastirqunlocker),
415 static void find_multiple_locks_held(void)
419 lockcheck_state_t *l;
422 for (i=0;i<NUM_LOCKS;i++) {
424 if (l->inuse && l->lockcount>0) {
426 if (have>=WARN_MULTIPLE_THRESHOLD) {
432 if (have>=WARN_MULTIPLE_THRESHOLD) {
434 for (i=0;i<NUM_LOCKS;i++) {
436 if (l->inuse && l->lockcount>0) {
437 snprintf(buf,64,"MULTIPLE LOCKS HELD (%d)",have);
446 static void find_multiple_irqs_held(void)
450 lockcheck_state_t *l;
453 for (i=0;i<NUM_LOCKS;i++) {
455 if (l->inuse && l->irqcount>0) {
457 if (have>=WARN_MULTIPLE_THRESHOLD) {
463 if (have>=WARN_MULTIPLE_THRESHOLD) {
465 for (i=0;i<NUM_LOCKS;i++) {
467 if (l->inuse && l->irqcount>0) {
468 snprintf(buf,64,"MULTIPLE IRQS HELD (%d)",have);
478 void palacios_lockcheck_deinit()
481 lockcheck_state_t *l;
486 for (i=0;i<NUM_LOCKS;i++) {
489 printlock("ALLOCATED LOCK AT DEINIT",l);
490 if ((l->lockcount)) {
491 printlock("BAD LOCK COUNT AT DEINIT",l);
494 printlock("BAD IRQ COUNT AT DEINIT",l);
499 INFO("LOCKCHECK: DEINITED\n");
503 void palacios_lockcheck_alloc(void *lock)
505 lockcheck_state_t *l;
513 DEBUG_OUTPUT("LOCKCHECK: UNABLE TO ALLOCATE TRACKING DATA FOR LOCK 0x%p\n",lock);
516 backtrace(l->allocator);
517 l->lockcount=l->irqcount=0;
518 clear_trace(l->lastlocker);
519 clear_trace(l->lastunlocker);
520 clear_trace(l->lastirqlocker);
521 clear_trace(l->lastirqunlocker);
522 //INFO("LOCKCHECK: LOCK ALLOCATE 0x%p\n",lock);
524 printlock("NEW LOCK", l);
530 void palacios_lockcheck_free(void *lock)
532 lockcheck_state_t *l;
536 l=find_lock_entry(lock);
540 DEBUG_OUTPUT("LOCKCHECK: FREEING UNTRACKED LOCK 0x%p - stack trace follows\n",lock);
545 if ((l->lockcount)) {
546 printlock("BAD LOCK COUNT AT FREE",l);
550 printlock("BAD IRQ COUNT AT FREE",l);
554 printlock("FREE LOCK",l);
563 void palacios_lockcheck_lock(void *lock)
566 lockcheck_state_t *l;
571 l=find_lock_entry(lock);
575 DEBUG_OUTPUT("LOCKCHECK: LOCKING UNTRACKED LOCK 0x%p - stack follows\n",lock);
580 if (l->lockcount!=0) {
581 printlock("BAD LOCKCOUNT AT LOCK - stack follows",l);
584 if (l->irqcount!=0) {
585 printlock("BAD IRQCOUNT AT LOCK - stack follows",l);
591 l->holdingcpu=get_cpu(); put_cpu();
592 backtrace(l->lastlocker);
594 find_multiple_locks_held();
596 lock_stack_lock(lock,0,0);
607 void palacios_lockcheck_unlock(void *lock)
610 lockcheck_state_t *l;
614 l=find_lock_entry(lock);
618 DEBUG_OUTPUT("LOCKCHECK: UNLOCKING UNTRACKED LOCK 0x%p - stack follows\n",lock);
623 if (l->lockcount!=1) {
624 printlock("LOCKCHECK: BAD LOCKCOUNT AT UNLOCK - stack follows",l);
627 if (l->irqcount!=0) {
628 printlock("LOCKCHECK: BAD IRQCOUNT AT UNLOCK - stack follows",l);
632 lock_stack_unlock(lock,0,0);
634 hot_lock_unlock(lock);
639 backtrace(l->lastunlocker);
641 #if PRINT_LOCK_UNLOCK
642 printlock("UNLOCK",l);
649 void palacios_lockcheck_lock_irqsave(void *lock,unsigned long flags)
652 lockcheck_state_t *l;
656 l=find_lock_entry(lock);
660 DEBUG_OUTPUT("LOCKCHECK: IRQ LOCKING UNTRACKED LOCK 0x%p - stack follows\n",lock);
665 if (l->lockcount!=0) {
666 printlock("BAD LOCKCOUNT AT IRQ LOCK - stack follows",l);
669 if (l->irqcount!=0) {
670 printlock("BAD IRQCOUNT AT IRQ LOCK - stack follows",l);
676 l->holdingcpu=get_cpu(); put_cpu();
677 l->lastlockflags=flags;
678 backtrace(l->lastirqlocker);
680 find_multiple_irqs_held();
682 lock_stack_lock(lock,1,flags);
687 printlock("LOCK_IRQSAVE",l);
697 // This is separated into two components to avoid a race between
698 // the underlying spin_unlock_irqrestore and the next lockcheck_lock_irqsave
699 // If simply record the state after the unlock, we might see that the
700 // irqcount has already increased. Therefore, we will acquire the
701 // lockchecker lock in _pre and release it in _post. Note that when
702 // we release the lock in _post, we restore the flags provided by the
703 // code under test - NOT our original flags
705 // unlock_pre() - stores flags, takes mylock discard flags
706 // At this point, a lockcheck_lock cannot enter, since it's stuck on mylock
707 // spinunlock - restores lock, restores original flags
708 // unlock_post() - restores mylock WITH orig flags
710 void palacios_lockcheck_unlock_irqrestore_pre(void *lock,unsigned long flags)
714 LOCK(); // flags are discarded
715 // at this point, the actual spin unlock can run
716 // if another thread hits lockcheck_irqsave at this point, it
717 // will block on mylock
720 void palacios_lockcheck_unlock_irqrestore_post(void *lock,unsigned long flags)
723 lockcheck_state_t *l;
726 // when we unlock, want to restore the flags *the user wants*
730 // Note that we DO NOT take mylock here, since we already took it in
733 l=find_lock_entry(lock);
736 UNLOCK(); // release any waiting threads on lockcheck_lock_irqsave
737 DEBUG_OUTPUT("LOCKCHECK: IRQ UNLOCKING UNTRACKED LOCK 0x%p - stack follows\n",lock);
742 if (l->lockcount!=0) {
743 printlock("LOCKCHECK: BAD LOCKCOUNT AT IRQ UNLOCK - stack follows",l);
746 if (l->irqcount!=1) {
747 printlock("LOCKCHECK: BAD IRQCOUNT AT IRQ UNLOCK - stack follows",l);
754 l->lastunlockflags = flags;
756 lock_stack_unlock(lock,1,flags);
758 hot_lock_unlock(lock);
760 backtrace(l->lastirqunlocker);
762 #if PRINT_LOCK_UNLOCK
763 printlock("UNLOCK_IRQRESTORE",l);
765 UNLOCK(); // release any waiting threads on lockcheck_lock_irqsave