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
usage(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
read_header(FILE * in)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 */
readup_str(char ** str,FILE * in)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 if(!*str)
181 fatal_exit("strdup failed: out of memory");
182 return 1;
183 }
184
185 /** read creation entry */
read_create(rbtree_type * all,FILE * in)186 static void read_create(rbtree_type* all, FILE* in)
187 {
188 struct order_lock* o = calloc(1, sizeof(struct order_lock));
189 if(!o) fatal_exit("malloc failure");
190 if(fread(&o->id.thr, sizeof(int), 1, in) != 1 ||
191 fread(&o->id.instance, sizeof(int), 1, in) != 1 ||
192 !readup_str(&o->create_file, in) ||
193 fread(&o->create_line, sizeof(int), 1, in) != 1)
194 fatal_exit("fread failed");
195 o->smaller = rbtree_create(order_lock_cmp);
196 o->node.key = &o->id;
197 if(!rbtree_insert(all, &o->node)) {
198 /* already inserted */
199 struct order_lock* a = (struct order_lock*)rbtree_search(all,
200 &o->id);
201 log_assert(a);
202 a->create_file = o->create_file;
203 a->create_line = o->create_line;
204 free(o->smaller);
205 free(o);
206 o = a;
207 }
208 if(verb) printf("read create %u %u %s %d\n",
209 (unsigned)o->id.thr, (unsigned)o->id.instance,
210 o->create_file, o->create_line);
211 }
212
213 /** insert lock entry (empty) into list */
214 static struct order_lock*
insert_lock(rbtree_type * all,struct order_id * id)215 insert_lock(rbtree_type* all, struct order_id* id)
216 {
217 struct order_lock* o = calloc(1, sizeof(struct order_lock));
218 if(!o) fatal_exit("malloc failure");
219 o->smaller = rbtree_create(order_lock_cmp);
220 o->id = *id;
221 o->node.key = &o->id;
222 if(!rbtree_insert(all, &o->node))
223 fatal_exit("insert fail should not happen");
224 return o;
225 }
226
227 /** read lock entry */
read_lock(rbtree_type * all,FILE * in,int val)228 static void read_lock(rbtree_type* all, FILE* in, int val)
229 {
230 struct order_id prev_id, now_id;
231 struct lock_ref* ref;
232 struct order_lock* prev, *now;
233 ref = (struct lock_ref*)calloc(1, sizeof(struct lock_ref));
234 if(!ref) fatal_exit("malloc failure");
235 prev_id.thr = val;
236 if(fread(&prev_id.instance, sizeof(int), 1, in) != 1 ||
237 fread(&now_id.thr, sizeof(int), 1, in) != 1 ||
238 fread(&now_id.instance, sizeof(int), 1, in) != 1 ||
239 !readup_str(&ref->file, in) ||
240 fread(&ref->line, sizeof(int), 1, in) != 1)
241 fatal_exit("fread failed");
242 if(verb) printf("read lock %u %u %u %u %s %d\n",
243 (unsigned)prev_id.thr, (unsigned)prev_id.instance,
244 (unsigned)now_id.thr, (unsigned)now_id.instance,
245 ref->file, ref->line);
246 /* find the two locks involved */
247 prev = (struct order_lock*)rbtree_search(all, &prev_id);
248 now = (struct order_lock*)rbtree_search(all, &now_id);
249 /* if not there - insert 'em */
250 if(!prev) prev = insert_lock(all, &prev_id);
251 if(!now) now = insert_lock(all, &now_id);
252 ref->lock = prev;
253 ref->node.key = &prev->id;
254 if(!rbtree_insert(now->smaller, &ref->node)) {
255 free(ref->file);
256 free(ref);
257 }
258 }
259
260 /** read input file */
readinput(rbtree_type * all,char * file)261 static void readinput(rbtree_type* all, char* file)
262 {
263 FILE *in = fopen(file, "r");
264 int fst;
265 if(!in) {
266 perror(file);
267 exit(1);
268 }
269 printf("file %s", file);
270 if(!read_header(in)) {
271 fclose(in);
272 return;
273 }
274 while(fread(&fst, sizeof(fst), 1, in) == 1) {
275 if(fst == -1)
276 read_create(all, in);
277 else read_lock(all, in, fst);
278 }
279 fclose(in);
280 }
281
282 /** print cycle message */
found_cycle(struct lock_ref * visit,int level)283 static void found_cycle(struct lock_ref* visit, int level)
284 {
285 struct lock_ref* p;
286 int i = 0;
287 errors_detected++;
288 printf("Found inconsistent locking order of length %d\n", level);
289 printf("for lock %d %d created %s %d\n",
290 visit->lock->id.thr, visit->lock->id.instance,
291 visit->lock->create_file, visit->lock->create_line);
292 printf("sequence is:\n");
293 p = visit;
294 while(p) {
295 struct order_lock* next =
296 p->lock->dfs_next?p->lock->dfs_next->lock:visit->lock;
297 printf("[%d] is locked at line %s %d before lock %d %d\n",
298 i, p->file, p->line, next->id.thr, next->id.instance);
299 printf("[%d] lock %d %d is created at %s %d\n",
300 i, next->id.thr, next->id.instance,
301 next->create_file, next->create_line);
302 i++;
303 p = p->lock->dfs_next;
304 if(p && p->lock == visit->lock)
305 break;
306 }
307 }
308
309 /** Detect cycle by comparing visited now with all (unvisited) bigger nodes */
detect_cycle(struct lock_ref * visit,struct lock_ref * from)310 static int detect_cycle(struct lock_ref* visit, struct lock_ref* from)
311 {
312 struct lock_ref* p = from;
313 while(p) {
314 if(p->lock == visit->lock)
315 return 1;
316 p = p->lock->dfs_next;
317 }
318 return 0;
319 }
320
321 /** recursive function to depth first search for cycles.
322 * @param visit: the lock visited at this step.
323 * its dfs_next pointer gives the visited lock up in recursion.
324 * same as lookfor at level 0.
325 * @param level: depth of recursion. 0 is start.
326 * @param from: search for matches from unvisited node upwards.
327 */
search_cycle(struct lock_ref * visit,int level,struct lock_ref * from)328 static void search_cycle(struct lock_ref* visit, int level,
329 struct lock_ref* from)
330 {
331 struct lock_ref* ref;
332 /* check for cycle */
333 if(detect_cycle(visit, from) && level != 0) {
334 found_cycle(visit, level);
335 fatal_exit("found lock order cycle");
336 }
337 /* recurse */
338 if(!visit->lock->visited)
339 from = visit;
340 if(verb > 1) fprintf(stderr, "[%d] visit lock %u %u %s %d\n", level,
341 (unsigned)visit->lock->id.thr,
342 (unsigned)visit->lock->id.instance,
343 visit->lock->create_file, visit->lock->create_line);
344 RBTREE_FOR(ref, struct lock_ref*, visit->lock->smaller) {
345 ref->lock->dfs_next = visit;
346 search_cycle(ref, level+1, from);
347 }
348 visit->lock->visited = 1;
349 }
350
351 /** Check ordering of one lock */
check_order_lock(struct order_lock * lock)352 static void check_order_lock(struct order_lock* lock)
353 {
354 struct lock_ref start;
355 if(lock->visited) return;
356
357 start.node.key = &lock->id;
358 start.lock = lock;
359 start.file = lock->create_file;
360 start.line = lock->create_line;
361
362 if(!lock->create_file)
363 log_err("lock %u %u does not have create info",
364 (unsigned)lock->id.thr, (unsigned)lock->id.instance);
365
366 /* depth first search to find cycle with this lock at head */
367 lock->dfs_next = NULL;
368 search_cycle(&start, 0, &start);
369 }
370
371 /** Check ordering of locks */
check_order(rbtree_type * all_locks)372 static void check_order(rbtree_type* all_locks)
373 {
374 /* check each lock */
375 struct order_lock* lock;
376 int i=0;
377 RBTREE_FOR(lock, struct order_lock*, all_locks) {
378 if(verb)
379 printf("[%d/%d] Checking lock %d %d %s %d\n",
380 i, (int)all_locks->count,
381 lock->id.thr, lock->id.instance,
382 lock->create_file, lock->create_line);
383 else if (i % ((all_locks->count/75)<1?1:all_locks->count/75)
384 == 0)
385 fprintf(stderr, ".");
386 i++;
387 check_order_lock(lock);
388 }
389 fprintf(stderr, "\n");
390 }
391
392 /** delete lock ref */
dellockref(rbnode_type * node,void * ATTR_UNUSED (arg))393 static void dellockref(rbnode_type* node, void* ATTR_UNUSED(arg))
394 {
395 struct lock_ref* o = (struct lock_ref*)node;
396 if(!o) return;
397 free(o->file);
398 free(o);
399 }
400
401 /** delete lock node */
delnode(rbnode_type * node,void * ATTR_UNUSED (arg))402 static void delnode(rbnode_type* node, void* ATTR_UNUSED(arg))
403 {
404 struct order_lock* o = (struct order_lock*)node;
405 if(!o) return;
406 free(o->create_file);
407 if(o->smaller) {
408 traverse_postorder(o->smaller, &dellockref, NULL);
409 free(o->smaller);
410 }
411 free(o);
412 }
413
414 /** delete allocated memory */
locks_free(rbtree_type * all_locks)415 static void locks_free(rbtree_type* all_locks)
416 {
417 if(!all_locks)
418 return;
419 traverse_postorder(all_locks, &delnode, NULL);
420 free(all_locks);
421 }
422
423 /** main program to verify all traces passed */
424 int
main(int argc,char * argv[])425 main(int argc, char* argv[])
426 {
427 rbtree_type* all_locks;
428 int i;
429 time_t starttime = time(NULL);
430 #ifdef USE_THREAD_DEBUG
431 /* do not overwrite the ublocktrace files with the ones generated
432 * by this program (i.e. when the log code creates a lock) */
433 check_locking_order = 0;
434 #endif
435 if(argc <= 1) {
436 usage();
437 return 1;
438 }
439 checklock_start();
440 log_init(NULL, 0, NULL);
441 log_ident_set("lock-verify");
442 /* init */
443 all_locks = rbtree_create(order_lock_cmp);
444 errors_detected = 0;
445
446 /* read the input files */
447 for(i=1; i<argc; i++) {
448 readinput(all_locks, argv[i]);
449 }
450
451 /* check ordering */
452 check_order(all_locks);
453
454 /* do not free a thing, OS will do it */
455 printf("checked %d locks in %d seconds with %d errors.\n",
456 (int)all_locks->count, (int)(time(NULL)-starttime),
457 errors_detected);
458 locks_free(all_locks);
459 if(errors_detected) return 1;
460 return 0;
461 }
462