]> git.ipfire.org Git - thirdparty/unbound.git/commitdiff
lock order verify.
authorWouter Wijngaards <wouter@nlnetlabs.nl>
Thu, 15 Mar 2007 16:27:20 +0000 (16:27 +0000)
committerWouter Wijngaards <wouter@nlnetlabs.nl>
Thu, 15 Mar 2007 16:27:20 +0000 (16:27 +0000)
git-svn-id: file:///svn/unbound/trunk@182 be551aaa-1e26-0410-a405-d3ace91eadb9

Makefile.in
testcode/checklocks.c
testcode/checklocks.h
testcode/lock_verify.c [new file with mode: 0644]
util/log.c
util/log.h

index c7c5e7d6dadaa04b9c9841846e0a362b1b15042c..79ba56ca3b98ffdbbc219c97281dcb05b66b7408 100644 (file)
@@ -59,7 +59,9 @@ DAEMON_SRC=$(wildcard daemon/*.c) $(COMMON_SRC)
 DAEMON_OBJ=$(addprefix $(BUILD),$(DAEMON_SRC:.c=.o)) $(COMPAT_OBJ)
 TESTBOUND_SRC=testcode/testbound.c testcode/ldns-testpkts.c daemon/worker.c daemon/daemon.c testcode/replay.c testcode/fake_event.c $(filter-out util/netevent.c services/listen_dnsport.c services/outside_network.c, $(COMMON_SRC))
 TESTBOUND_OBJ=$(addprefix $(BUILD),$(TESTBOUND_SRC:.c=.o)) $(COMPAT_OBJ)
-ALL_SRC=$(COMMON_SRC) $(UNITTEST_SRC) $(DAEMON_SRC) $(TESTBOUND_SRC)
+LOCKVERIFY_SRC=testcode/lock_verify.c $(COMMON_SRC)
+LOCKVERIFY_OBJ=$(addprefix $(BUILD),$(LOCKVERIFY_SRC:.c=.o)) $(COMPAT_OBJ)
+ALL_SRC=$(COMMON_SRC) $(UNITTEST_SRC) $(DAEMON_SRC) $(TESTBOUND_SRC) $(LOCKVERIFY_SRC)
 ALL_OBJ=$(addprefix $(BUILD),$(ALL_SRC:.c=.o) $(addprefix compat/,$(LIBOBJS))) $(COMPAT_OBJ)
 
 COMPILE=$(LIBTOOL) --tag=CC --mode=compile $(CC) $(CPPFLAGS) $(CFLAGS)
@@ -73,7 +75,7 @@ $(BUILD)%.o:    $(srcdir)/%.c
 
 .PHONY:        clean realclean doc lint all 
 
-all:   $(COMMON_OBJ) unbound unittest testbound
+all:   $(COMMON_OBJ) unbound unittest testbound lock-verify
 
 unbound:       $(DAEMON_OBJ)
        $(INFO) Link $@
@@ -87,6 +89,10 @@ testbound:   $(TESTBOUND_OBJ)
        $(INFO) Link $@
        $Q$(LINK) -o $@ $^ $(LIBS)
 
+lock-verify:   $(LOCKVERIFY_OBJ)
+       $(INFO) Link $@
+       $Q$(LINK) -o $@ $^ $(LIBS)
+
 testcode/ldns-testpkts.c:      $(ldnsdir)/examples/ldns-testpkts.c \
                        $(ldnsdir)/examples/ldns-testpkts.h
        cp $(ldnsdir)/examples/ldns-testpkts.c testcode/ldns-testpkts.c
index e9b5718723f9c64c9f4e379e9d81172c8ac50d3d..86e0bb332141d739b6918a778ab71e280223037c 100644 (file)
@@ -58,6 +58,10 @@ static int key_created = 0;
 static ub_thread_key_t thr_debug_key;
 /** the list of threads, so all threads can be examined. NULL if unused. */
 static struct thr_check* thread_infos[THRDEBUG_MAX_THREADS];
+/** do we check locking order */
+int check_locking_order = 1;
+/** the pid of this runset, reasonably unique. */
+static pid_t check_lock_pid;
 
 /** print pretty lock error and exit */
 static void lock_error(struct checked_lock* lock, 
@@ -192,6 +196,45 @@ prot_store(struct checked_lock* lock)
        }
 }
 
+/** write lock trace info to file, while you hold those locks. */
+static void
+ordercheck_locklock(struct thr_check* thr, struct checked_lock* lock)
+{
+       int info[4];
+       if(!check_locking_order) return;
+       if(!thr->holding_first) return; /* no older lock, no info */
+       /* write: <lock id held> <lock id new> <file> <line> */
+       info[0] = thr->holding_first->create_thread;
+       info[1] = thr->holding_first->create_instance;
+       info[2] = lock->create_thread;
+       info[3] = lock->create_instance;
+       if(fwrite(info, 4*sizeof(int), 1, thr->order_info) != 1 ||
+               fwrite(lock->holder_file, strlen(lock->holder_file)+1, 1, 
+               thr->order_info) != 1 ||
+               fwrite(&lock->holder_line, sizeof(int), 1, 
+               thr->order_info) != 1)
+               log_err("fwrite: %s", strerror(errno));
+}
+
+/** write ordercheck lock creation details to file. */
+static void 
+ordercheck_lockcreate(struct thr_check* thr, struct checked_lock* lock)
+{
+       /* write: <ffff = create> <lock id> <file> <line> */
+       int cmd = -1;
+       if(!check_locking_order) return;
+
+       if( fwrite(&cmd, sizeof(int), 1, thr->order_info) != 1 ||
+               fwrite(&lock->create_thread, sizeof(int), 1, 
+                       thr->order_info) != 1 ||
+               fwrite(&lock->create_instance, sizeof(int), 1, 
+                       thr->order_info) != 1 ||
+               fwrite(lock->create_file, strlen(lock->create_file)+1, 1, 
+                       thr->order_info) != 1 ||
+               fwrite(&lock->create_line, sizeof(int), 1, 
+               thr->order_info) != 1)
+               log_err("fwrite: %s", strerror(errno));
+}
 
 /** alloc struct, init lock empty */
 void 
@@ -200,13 +243,21 @@ checklock_init(enum check_lock_type type, struct checked_lock** lock,
 {
        struct checked_lock* e = (struct checked_lock*)calloc(1, 
                sizeof(struct checked_lock));
+       struct thr_check *thr = (struct thr_check*)pthread_getspecific(
+               thr_debug_key);
        if(!e)
                fatal_exit("%s %s %d: out of memory", func, file, line);
+       if(!thr)
+               fatal_exit("%s %s %d: lock_init no thread info", func, file,
+                       line);
        *lock = e;
        e->type = type;
        e->create_func = func;
        e->create_file = file;
        e->create_line = line;
+       e->create_thread = thr->num;
+       e->create_instance = thr->locks_created++;
+       ordercheck_lockcreate(thr, e);
        LOCKRET(pthread_mutex_init(&e->lock, NULL));
        switch(e->type) {
                case check_lock_mutex:
@@ -314,6 +365,7 @@ finish_acquire_lock(struct thr_check* thr, struct checked_lock* lock,
        lock->holder_func = func;
        lock->holder_file = file;
        lock->holder_line = line;
+       ordercheck_locklock(thr, lock);
        
        /* insert in thread lock list, as first */
        lock->prev_held_lock[thr->num] = NULL;
@@ -546,6 +598,26 @@ checklock_unlock(enum check_lock_type type, struct checked_lock* lock,
        }
 }
 
+/** open order info debug file, thr->num must be valid. */
+static void 
+open_lockorder(struct thr_check* thr)
+{
+       char buf[24];
+       time_t t;
+       snprintf(buf, sizeof(buf), "ublocktrace.%d", thr->num);
+       thr->order_info = fopen(buf, "w");
+       if(!thr->order_info)
+               fatal_exit("could not open %s: %s", buf, strerror(errno));
+       thr->locks_created = 0;
+       t = time(NULL);
+       /* write: <time_stamp> <runpid> <thread_num> */
+       if(fwrite(&t, sizeof(t), 1, thr->order_info) != 1 ||
+               fwrite(&thr->num, sizeof(thr->num), 1, thr->order_info) != 1 || 
+               fwrite(&check_lock_pid, sizeof(check_lock_pid), 1, 
+               thr->order_info) != 1)
+               log_err("fwrite: %s", strerror(errno));
+}
+
 /** checklock thread main, Inits thread structure. */
 static void* checklock_main(void* arg)
 {
@@ -558,8 +630,12 @@ static void* checklock_main(void* arg)
        log_assert(thread_infos[thr->num] == NULL);
        thread_infos[thr->num] = thr;
        LOCKRET(pthread_setspecific(thr_debug_key, thr));
+       if(check_locking_order)
+               open_lockorder(thr);
        ret = thr->func(thr->arg);
        thread_infos[thr->num] = NULL;
+       if(check_locking_order)
+               fclose(thr->order_info);
        free(thr);
        return ret;
 }
@@ -573,9 +649,12 @@ void checklock_start()
                if(!thisthr)
                        fatal_exit("thrcreate: out of memory");
                key_created = 1;
+               check_lock_pid = getpid();
                LOCKRET(pthread_key_create(&thr_debug_key, NULL));
                LOCKRET(pthread_setspecific(thr_debug_key, thisthr));
                thread_infos[0] = thisthr;
+               if(check_locking_order)
+                       open_lockorder(thisthr);
        }
 }
 
@@ -584,6 +663,8 @@ void checklock_stop()
 {
        if(key_created) {
                int i;
+               if(check_locking_order)
+                       fclose(thread_infos[0]->order_info);
                free(thread_infos[0]);
                thread_infos[0] = NULL;
                for(i = 0; i < THRDEBUG_MAX_THREADS; i++)
index d2f62873a4858be947419337ede3140e6417e38d..05ec7ca1d4bb82bb7592a13601d3fddb50626f9a 100644 (file)
@@ -77,6 +77,8 @@
 #define CHECK_JOIN_TIMEOUT 120 /* seconds */
 /** How many threads to allocate for */
 #define THRDEBUG_MAX_THREADS 32 /* threads */
+/** do we check locking order */
+extern int check_locking_order;
 
 /**
  * Protection memory area.
@@ -106,6 +108,10 @@ struct thr_check {
        void* arg;
        /** number of thread in list structure */
        int num;
+       /** instance number - how many locks have been created by thread */
+       int locks_created;
+       /** file to write locking order information to */
+       FILE* order_info;
        /** 
         * List of locks that this thread is holding, double
         * linked list. The first element is the most recent lock acquired.
@@ -128,6 +134,8 @@ struct checked_lock {
        const char* create_func, *create_file;
        /** where was this lock created */
        int create_line;
+       /** unique instance identifier */
+       int create_thread, create_instance;
        /** contention count */
        size_t contention_count;
        /** hold count (how many threads are holding this lock) */
diff --git a/testcode/lock_verify.c b/testcode/lock_verify.c
new file mode 100644 (file)
index 0000000..3e617a1
--- /dev/null
@@ -0,0 +1,216 @@
+/*
+ * testcode/lock_verify.c - verifier program for lock traces, checks order.
+ *
+ * Copyright (c) 2007, NLnet Labs. All rights reserved.
+ *
+ * This software is open source.
+ * 
+ * Redistribution and use in source and binary forms, with or without
+ * modification, are permitted provided that the following conditions
+ * are met:
+ * 
+ * Redistributions of source code must retain the above copyright notice,
+ * this list of conditions and the following disclaimer.
+ * 
+ * Redistributions in binary form must reproduce the above copyright notice,
+ * this list of conditions and the following disclaimer in the documentation
+ * and/or other materials provided with the distribution.
+ * 
+ * Neither the name of the NLNET LABS nor the names of its contributors may
+ * be used to endorse or promote products derived from this software without
+ * specific prior written permission.
+ * 
+ * THIS SOFTWARE IS PROVIDED BY THE COPYRIGHT HOLDERS AND CONTRIBUTORS
+ * "AS IS" AND ANY EXPRESS OR IMPLIED WARRANTIES, INCLUDING, BUT NOT LIMITED
+ * TO, THE IMPLIED WARRANTIES OF MERCHANTABILITY AND FITNESS FOR A PARTICULAR
+ * PURPOSE ARE DISCLAIMED. IN NO EVENT SHALL THE REGENTS OR CONTRIBUTORS BE
+ * LIABLE FOR ANY DIRECT, INDIRECT, INCIDENTAL, SPECIAL, EXEMPLARY, OR
+ * CONSEQUENTIAL DAMAGES (INCLUDING, BUT NOT LIMITED TO, PROCUREMENT OF
+ * SUBSTITUTE GOODS OR SERVICES; LOSS OF USE, DATA, OR PROFITS; OR BUSINESS
+ * INTERRUPTION) HOWEVER CAUSED AND ON ANY THEORY OF LIABILITY, WHETHER IN
+ * CONTRACT, STRICT LIABILITY, OR TORT (INCLUDING NEGLIGENCE OR OTHERWISE)
+ * ARISING IN ANY WAY OUT OF THE USE OF THIS SOFTWARE, EVEN IF ADVISED OF THE
+ * POSSIBILITY OF SUCH DAMAGE.
+ */
+
+/**
+ * \file
+ *
+ * This file checks the lock traces generated by checklock.c.
+ * Checks if locks are consistently locked in the same order.
+ * If not, this can lead to deadlock if threads execute the different
+ * ordering at the same time.
+ * 
+ */
+
+#include "config.h"
+#include "util/log.h"
+#include "util/rbtree.h"
+
+/* --- data structures --- */
+
+/** a lock */
+struct order_lock {
+       /** rbnode in all tree */
+       rbnode_t node;
+       /** the thread id that created it */
+       int thr;
+       /** the instance number of creation */
+       int instance;
+       /** the creation file */
+       char* create_file;
+       /** creation line */
+       int create_line;
+       /** set of all locks that are smaller than this one (locked earlier) */
+       rbtree_t* smaller;
+};
+
+/** reference to a lock in a rbtree set */
+struct lock_ref {
+       /** rbnode, key is an order_lock ptr */
+       rbnode_t node;
+};
+
+/** print program usage help */
+static void
+usage()
+{
+       printf("lock_verify <trace files>\n");
+}
+
+/** compare two order_locks */
+int order_lock_cmp(const void* e1, const void* e2)
+{
+       struct order_lock* o1 = (struct order_lock*)e1;
+       struct order_lock* o2 = (struct order_lock*)e2;
+       if(o1->thr < o2->thr) return -1;
+       if(o1->thr > o2->thr) return 1;
+       if(o1->instance < o2->instance) return -1;
+       if(o1->instance > o2->instance) return 1;
+       return 0;
+}
+
+/** read header entry */
+static void read_header(FILE* in)
+{
+       time_t t;
+       pid_t p;
+       int thrno;
+       static int have_values = 0;
+       static time_t the_time;
+       static pid_t the_pid;
+       static int threads[256];
+
+       if(fread(&t, sizeof(t), 1, in) != 1 ||  
+               fread(&thrno, sizeof(thrno), 1, in) != 1 ||
+               fread(&p, sizeof(p), 1, in) != 1) {
+               fatal_exit("fread: %s", strerror(errno));
+       }
+       /* check these values are sorta OK */
+       if(!have_values) {
+               the_time = t;
+               the_pid = p;
+               memset(threads, 0, 256*sizeof(int));
+               threads[thrno] = 1;
+               have_values = 1;
+               printf("Trace from pid %u on %s", (unsigned)p, ctime(&t));
+       } else {
+               if(the_pid != p)
+                       fatal_exit("different pids in input files");
+               if(threads[thrno])
+                       fatal_exit("same threadno in two files");
+               threads[thrno] = 1;
+               if( abs(the_time - t) > 3600)
+                       fatal_exit("input files from different times: %u %u",
+                               (unsigned)the_time, (unsigned)t);
+       }
+       printf("reading trace of thread %d\n", thrno);
+}
+
+/** read a string from file, false on error */
+static int readup_str(char** str, FILE* in)
+{
+#define STRMAX 1024
+       char buf[STRMAX];
+       int len = 0;
+       int c;
+       /* ends in zero */
+       while( (c = fgetc(in)) != 0) {
+               if(c == EOF)
+                       fatal_exit("eof in readstr, file too short");
+               buf[len++] = c;
+               if(len == STRMAX) {
+                       fatal_exit("string too long, bad file format");
+               }
+       }
+       buf[len] = 0;
+       *str = strdup(buf);
+       return 1;
+}
+
+/** read creation entry */
+static void read_create(rbtree_t* all, FILE* in)
+{
+       struct order_lock* o = calloc(1, sizeof(struct order_lock));
+       if(!o) fatal_exit("malloc failure");
+       if(fread(&o->thr, sizeof(int), 1, in) != 1 ||   
+          fread(&o->instance, sizeof(int), 1, in) != 1 ||      
+          !readup_str(&o->create_file, in) ||
+          fread(&o->create_line, sizeof(int), 1, in) != 1)
+               fatal_exit("fread: %s", strerror(errno));
+       o->smaller = rbtree_create(order_lock_cmp);
+       o->node.key = o;
+       rbtree_insert(all, &o->node);
+       printf("read create %s %d\n", o->create_file, o->create_line);
+}
+
+/** read lock entry */
+static void read_lock(rbtree_t* all, FILE* in, int val)
+{
+       
+}
+
+/** read input file */
+static void readinput(rbtree_t* all, char* file)
+{
+       FILE *in = fopen(file, "r");
+       int fst;
+       if(!in) {
+               perror(file);
+               exit(1);
+       }
+       printf("reading file %s\n", file);
+       read_header(in);
+       while(fread(&fst, sizeof(fst), 1, in) == 1) {
+               if(fst == -1)
+                       read_create(all, in);
+               else    read_lock(all, in, fst);
+       }
+       fclose(in);
+}
+
+/** main program to verify all traces passed */
+int
+main(int argc, char* argv[])
+{
+       rbtree_t* all_locks;
+       int i;
+       if(argc <= 1) {
+               usage();
+               return 1;
+       }
+       log_init(NULL);
+       log_ident_set("lock-verify");
+       /* init */
+       all_locks = rbtree_create(order_lock_cmp);
+
+       /* read the input files */
+       for(i=1; i<argc; i++) {
+               readinput(all_locks, argv[i]);
+       }
+
+       /* check ordering */
+
+       /* do not free a thing, OS will do it */
+       return 0;
+}
index 19361db71cc872cb3407663a3a1566c376f86ff9..0e95a278c710b1f9379916f1fdb61657c269f5bc 100644 (file)
@@ -51,6 +51,8 @@ static FILE* logfile = 0;
 static int key_created = 0;
 /** pthread key for thread ids in logfile */
 static ub_thread_key_t logkey;
+/** the identity of this executable/process */
+static const char* ident="unbound";
 
 void
 log_init(const char* filename)
@@ -85,11 +87,15 @@ void log_thread_set(int* num)
        ub_thread_key_set(logkey, num);
 }
 
+void log_ident_set(const char* id)
+{
+       ident = id;
+}
+
 void
 log_vmsg(const char* type, const char *format, va_list args)
 {
        char message[MAXSYSLOGMSGLEN];
-       const char* ident="unbound";
        unsigned int* tid = (unsigned int*)ub_thread_key_get(logkey);
        vsnprintf(message, sizeof(message), format, args);
        fprintf(logfile, "[%d] %s[%d:%x] %s: %s\n",
index c6fd5abf563d877ca93a0742c84f88e1ae3f01a3..dd126a5e07ff7ba87661ffbcf2ab02c090292015 100644 (file)
@@ -88,6 +88,12 @@ void log_init(const char* filename);
  */
 void log_thread_set(int* num);
 
+/**
+ * Set identity to print, default is 'unbound'. 
+ * @param id: string to print. Name of executable.
+ */
+void log_ident_set(const char* id);
+
 /**
  * Log informational message.
  * Pass printf formatted arguments. No trailing newline is needed.