testcode/lock_verify.c

   1 /*
   2  * testcode/lock_verify.c - verifier program for lock traces, checks order.
   3  *
   4  * Copyright (c) 2007, NLnet Labs. All rights reserved.
   5  *
   6  * This software is open source.
   7  *
   8  * Redistribution and use in source and binary forms, with or without
   9  * modification, are permitted provided that the following conditions
  10  * are met:
  11  *
  12  * Redistributions of source code must retain the above copyright notice,
  13  * this list of conditions and the following disclaimer.
  14  *
  15  * Redistributions in binary form must reproduce the above copyright notice,
  16  * this list of conditions and the following disclaimer in the documentation
  17  * and/or other materials provided with the distribution.
  18  *
  19  * Neither the name of the NLNET LABS nor the names of its contributors may
  20  * be used to endorse or promote products derived from this software without
  21  * specific prior written permission.
  22  *
  23  * THIS SOFTWARE IS PROVIDED BY THE COPYRIGHT HOLDERS AND CONTRIBUTORS
  24  * "AS IS" AND ANY EXPRESS OR IMPLIED WARRANTIES, INCLUDING, BUT NOT
  25  * LIMITED TO, THE IMPLIED WARRANTIES OF MERCHANTABILITY AND FITNESS FOR
  26  * A PARTICULAR PURPOSE ARE DISCLAIMED. IN NO EVENT SHALL THE COPYRIGHT
  27  * HOLDER OR CONTRIBUTORS BE LIABLE FOR ANY DIRECT, INDIRECT, INCIDENTAL,
  28  * SPECIAL, EXEMPLARY, OR CONSEQUENTIAL DAMAGES (INCLUDING, BUT NOT LIMITED
  29  * TO, PROCUREMENT OF SUBSTITUTE GOODS OR SERVICES; LOSS OF USE, DATA, OR
  30  * PROFITS; OR BUSINESS INTERRUPTION) HOWEVER CAUSED AND ON ANY THEORY OF
  31  * LIABILITY, WHETHER IN CONTRACT, STRICT LIABILITY, OR TORT (INCLUDING
  32  * NEGLIGENCE OR OTHERWISE) ARISING IN ANY WAY OUT OF THE USE OF THIS
  33  * SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF SUCH DAMAGE.
  34  */
  35
  36 /**
  37  * \file
  38  *
  39  * This file checks the lock traces generated by checklock.c.
  40  * Checks if locks are consistently locked in the same order.
  41  * If not, this can lead to deadlock if threads execute the different
  42  * ordering at the same time.
  43  *
  44  */
  45
  46 #include "config.h"
  47 #ifdef HAVE_TIME_H
  48 #include <time.h>
  49 #endif
  50 #include "util/log.h"
  51 #include "util/rbtree.h"
  52 #include "util/locks.h"
  53 #include "util/fptr_wlist.h"
  54
  55 /* --- data structures --- */
  56 struct lock_ref;
  57
  58 /** keep track of lock id in lock-verify application
  59  * Also defined in smallapp/worker_cb.c for fptr_wlist encapsulation
  60  * breakage (the security tests break encapsulation for this test app) */
  61 struct order_id {
  62         /** the thread id that created it */
  63         int thr;
  64         /** the instance number of creation */
  65         int instance;
  66 };
  67
  68 /** a lock */
  69 struct order_lock {
  70         /** rbnode in all tree */
  71         rbnode_type node;
  72         /** lock id */
  73         struct order_id id;
  74         /** the creation file */
  75         char* create_file;
  76         /** creation line */
  77         int create_line;
  78         /** set of all locks that are smaller than this one (locked earlier) */
  79         rbtree_type* smaller;
  80         /** during depthfirstsearch, this is a linked list of the stack
  81          * of locks. points to the next lock bigger than this one. */
  82         struct lock_ref* dfs_next;
  83         /** if lock has been visited (all smaller locks have been compared to
  84          * this lock), only need to compare this with all unvisited(bigger)
  85          * locks */
  86         int visited;
  87 };
  88
  89 /** reference to a lock in a rbtree set */
  90 struct lock_ref {
  91         /** rbnode, key is an order_id ptr */
  92         rbnode_type node;
  93         /** the lock referenced */
  94         struct order_lock* lock;
  95         /** why is this ref */
  96         char* file;
  97         /** line number */
  98         int line;
  99 };
 100
 101 /** count of errors detected */
 102 static int errors_detected = 0;
 103 /** verbose? */
 104 static int verb = 0;
 105
 106 /** print program usage help */
 107 static void
 108 usage(void)
 109 {
 110         printf("lock_verify <trace files>\n");
 111 }
 112
 113 /** read header entry.
 114  * @param in: file to read header of.
 115  * @return: False if it does not belong to the rest. */
 116 static int
 117 read_header(FILE* in)
 118 {
 119         time_t t;
 120         pid_t p;
 121         int thrno;
 122         static int have_values = 0;
 123         static time_t the_time;
 124         static pid_t the_pid;
 125         static int threads[256];
 126
 127         if(fread(&t, sizeof(t), 1, in) != 1 ||
 128                 fread(&thrno, sizeof(thrno), 1, in) != 1 ||
 129                 fread(&p, sizeof(p), 1, in) != 1) {
 130                 fatal_exit("fread failed");
 131         }
 132         /* check these values are sorta OK */
 133         if(!have_values) {
 134                 the_time = t;
 135                 the_pid = p;
 136                 memset(threads, 0, 256*sizeof(int));
 137                 if(thrno >= 256) {
 138                         fatal_exit("Thread number too big. %d", thrno);
 139                 }
 140                 threads[thrno] = 1;
 141                 have_values = 1;
 142                 printf(" trace %d from pid %u on %s", thrno,
 143                         (unsigned)p, ctime(&t));
 144         } else {
 145                 if(the_pid != p) {
 146                         printf(" has pid %u, not %u. Skipped.\n",
 147                                 (unsigned)p, (unsigned)the_pid);
 148                         return 0;
 149                 }
 150                 if(threads[thrno])
 151                         fatal_exit("same threadno in two files");
 152                 threads[thrno] = 1;
 153                 if( abs((int)(the_time - t)) > 3600)
 154                         fatal_exit("input files from different times: %u %u",
 155                                 (unsigned)the_time, (unsigned)t);
 156                 printf(" trace of thread %u:%d\n", (unsigned)p, thrno);
 157         }
 158         return 1;
 159 }
 160
 161 /** max length of strings: filenames and function names. */
 162 #define STRMAX 1024
 163 /** read a string from file, false on error */
 164 static int readup_str(char** str, FILE* in)
 165 {
 166         char buf[STRMAX];
 167         int len = 0;
 168         int c;
 169         /* ends in zero */
 170         while( (c = fgetc(in)) != 0) {
 171                 if(c == EOF)
 172                         fatal_exit("eof in readstr, file too short");
 173                 buf[len++] = c;
 174                 if(len == STRMAX) {
 175                         fatal_exit("string too long, bad file format");
 176                 }
 177         }
 178         buf[len] = 0;
 179         *str = strdup(buf);
 180         return 1;
 181 }
 182
 183 /** read creation entry */
 184 static void read_create(rbtree_type* all, FILE* in)
 185 {
 186         struct order_lock* o = calloc(1, sizeof(struct order_lock));
 187         if(!o) fatal_exit("malloc failure");
 188         if(fread(&o->id.thr, sizeof(int), 1, in) != 1 ||
 189            fread(&o->id.instance, sizeof(int), 1, in) != 1 ||
 190            !readup_str(&o->create_file, in) ||
 191            fread(&o->create_line, sizeof(int), 1, in) != 1)
 192                 fatal_exit("fread failed");
 193         o->smaller = rbtree_create(order_lock_cmp);
 194         o->node.key = &o->id;
 195         if(!rbtree_insert(all, &o->node)) {
 196                 /* already inserted */
 197                 struct order_lock* a = (struct order_lock*)rbtree_search(all,
 198                         &o->id);
 199                 log_assert(a);
 200                 a->create_file = o->create_file;
 201                 a->create_line = o->create_line;
 202                 free(o->smaller);
 203                 free(o);
 204                 o = a;
 205         }
 206         if(verb) printf("read create %u %u %s %d\n",
 207                 (unsigned)o->id.thr, (unsigned)o->id.instance,
 208                 o->create_file, o->create_line);
 209 }
 210
 211 /** insert lock entry (empty) into list */
 212 static struct order_lock*
 213 insert_lock(rbtree_type* all, struct order_id* id)
 214 {
 215         struct order_lock* o = calloc(1, sizeof(struct order_lock));
 216         if(!o) fatal_exit("malloc failure");
 217         o->smaller = rbtree_create(order_lock_cmp);
 218         o->id = *id;
 219         o->node.key = &o->id;
 220         if(!rbtree_insert(all, &o->node))
 221                 fatal_exit("insert fail should not happen");
 222         return o;
 223 }
 224
 225 /** read lock entry */
 226 static void read_lock(rbtree_type* all, FILE* in, int val)
 227 {
 228         struct order_id prev_id, now_id;
 229         struct lock_ref* ref;
 230         struct order_lock* prev, *now;
 231         ref = (struct lock_ref*)calloc(1, sizeof(struct lock_ref));
 232         if(!ref) fatal_exit("malloc failure");
 233         prev_id.thr = val;
 234         if(fread(&prev_id.instance, sizeof(int), 1, in) != 1 ||
 235            fread(&now_id.thr, sizeof(int), 1, in) != 1 ||
 236            fread(&now_id.instance, sizeof(int), 1, in) != 1 ||
 237            !readup_str(&ref->file, in) ||
 238            fread(&ref->line, sizeof(int), 1, in) != 1)
 239                 fatal_exit("fread failed");
 240         if(verb) printf("read lock %u %u %u %u %s %d\n",
 241                 (unsigned)prev_id.thr, (unsigned)prev_id.instance,
 242                 (unsigned)now_id.thr, (unsigned)now_id.instance,
 243                 ref->file, ref->line);
 244         /* find the two locks involved */
 245         prev = (struct order_lock*)rbtree_search(all, &prev_id);
 246         now = (struct order_lock*)rbtree_search(all, &now_id);
 247         /* if not there - insert 'em */
 248         if(!prev) prev = insert_lock(all, &prev_id);
 249         if(!now) now = insert_lock(all, &now_id);
 250         ref->lock = prev;
 251         ref->node.key = &prev->id;
 252         if(!rbtree_insert(now->smaller, &ref->node)) {
 253                 free(ref->file);
 254                 free(ref);
 255         }
 256 }
 257
 258 /** read input file */
 259 static void readinput(rbtree_type* all, char* file)
 260 {
 261         FILE *in = fopen(file, "r");
 262         int fst;
 263         if(!in) {
 264                 perror(file);
 265                 exit(1);
 266         }
 267         printf("file %s", file);
 268         if(!read_header(in)) {
 269                 fclose(in);
 270                 return;
 271         }
 272         while(fread(&fst, sizeof(fst), 1, in) == 1) {
 273                 if(fst == -1)
 274                         read_create(all, in);
 275                 else    read_lock(all, in, fst);
 276         }
 277         fclose(in);
 278 }
 279
 280 /** print cycle message */
 281 static void found_cycle(struct lock_ref* visit, int level)
 282 {
 283         struct lock_ref* p;
 284         int i = 0;
 285         errors_detected++;
 286         printf("Found inconsistent locking order of length %d\n", level);
 287         printf("for lock %d %d created %s %d\n",
 288                 visit->lock->id.thr, visit->lock->id.instance,
 289                 visit->lock->create_file, visit->lock->create_line);
 290         printf("sequence is:\n");
 291         p = visit;
 292         while(p) {
 293                 struct order_lock* next =
 294                         p->lock->dfs_next?p->lock->dfs_next->lock:visit->lock;
 295                 printf("[%d] is locked at line %s %d before lock %d %d\n",
 296                         i, p->file, p->line, next->id.thr, next->id.instance);
 297                 printf("[%d] lock %d %d is created at %s %d\n",
 298                         i, next->id.thr, next->id.instance,
 299                         next->create_file, next->create_line);
 300                 i++;
 301                 p = p->lock->dfs_next;
 302                 if(p && p->lock == visit->lock)
 303                         break;
 304         }
 305 }
 306
 307 /** Detect cycle by comparing visited now with all (unvisited) bigger nodes */
 308 static int detect_cycle(struct lock_ref* visit, struct lock_ref* from)
 309 {
 310         struct lock_ref* p = from;
 311         while(p) {
 312                 if(p->lock == visit->lock)
 313                         return 1;
 314                 p = p->lock->dfs_next;
 315         }
 316         return 0;
 317 }
 318
 319 /** recursive function to depth first search for cycles.
 320  * @param visit: the lock visited at this step.
 321  *      its dfs_next pointer gives the visited lock up in recursion.
 322  *      same as lookfor at level 0.
 323  * @param level: depth of recursion. 0 is start.
 324  * @param from: search for matches from unvisited node upwards.
 325  */
 326 static void search_cycle(struct lock_ref* visit, int level,
 327         struct lock_ref* from)
 328 {
 329         struct lock_ref* ref;
 330         /* check for cycle */
 331         if(detect_cycle(visit, from) && level != 0) {
 332                 found_cycle(visit, level);
 333                 fatal_exit("found lock order cycle");
 334         }
 335         /* recurse */
 336         if(!visit->lock->visited)
 337                 from = visit;
 338         if(verb > 1) fprintf(stderr, "[%d] visit lock %u %u %s %d\n", level,
 339                         (unsigned)visit->lock->id.thr,
 340                         (unsigned)visit->lock->id.instance,
 341                         visit->lock->create_file, visit->lock->create_line);
 342         RBTREE_FOR(ref, struct lock_ref*, visit->lock->smaller) {
 343                 ref->lock->dfs_next = visit;
 344                 search_cycle(ref, level+1, from);
 345         }
 346         visit->lock->visited = 1;
 347 }
 348
 349 /** Check ordering of one lock */
 350 static void check_order_lock(struct order_lock* lock)
 351 {
 352         struct lock_ref start;
 353         if(lock->visited) return;
 354
 355         start.node.key = &lock->id;
 356         start.lock = lock;
 357         start.file = lock->create_file;
 358         start.line = lock->create_line;
 359
 360         if(!lock->create_file)
 361                 log_err("lock %u %u does not have create info",
 362                         (unsigned)lock->id.thr, (unsigned)lock->id.instance);
 363
 364         /* depth first search to find cycle with this lock at head */
 365         lock->dfs_next = NULL;
 366         search_cycle(&start, 0, &start);
 367 }
 368
 369 /** Check ordering of locks */
 370 static void check_order(rbtree_type* all_locks)
 371 {
 372         /* check each lock */
 373         struct order_lock* lock;
 374         int i=0;
 375         RBTREE_FOR(lock, struct order_lock*, all_locks) {
 376                 if(verb)
 377                     printf("[%d/%d] Checking lock %d %d %s %d\n",
 378                         i, (int)all_locks->count,
 379                         lock->id.thr, lock->id.instance,
 380                         lock->create_file, lock->create_line);
 381                 else if (i % ((all_locks->count/75)<1?1:all_locks->count/75)
 382                         == 0)
 383                     fprintf(stderr, ".");
 384                 i++;
 385                 check_order_lock(lock);
 386         }
 387         fprintf(stderr, "\n");
 388 }
 389
 390 /** main program to verify all traces passed */
 391 int
 392 main(int argc, char* argv[])
 393 {
 394         rbtree_type* all_locks;
 395         int i;
 396         time_t starttime = time(NULL);
 397 #ifdef USE_THREAD_DEBUG
 398         /* do not overwrite the ublocktrace files with the ones generated
 399          * by this program (i.e. when the log code creates a lock) */
 400         check_locking_order = 0;
 401 #endif
 402         if(argc <= 1) {
 403                 usage();
 404                 return 1;
 405         }
 406         log_init(NULL, 0, NULL);
 407         log_ident_set("lock-verify");
 408         /* init */
 409         all_locks = rbtree_create(order_lock_cmp);
 410         errors_detected = 0;
 411
 412         /* read the input files */
 413         for(i=1; i<argc; i++) {
 414                 readinput(all_locks, argv[i]);
 415         }
 416
 417         /* check ordering */
 418         check_order(all_locks);
 419
 420         /* do not free a thing, OS will do it */
 421         printf("checked %d locks in %d seconds with %d errors.\n",
 422                 (int)all_locks->count, (int)(time(NULL)-starttime),
 423                 errors_detected);
 424         if(errors_detected) return 1;
 425         return 0;
 426 }