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 	if(!*str)
181 		fatal_exit("strdup failed: out of memory");
182 	return 1;
183 }
184 
185 /** read creation entry */
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*
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 */
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 */
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 */
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 */
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  */
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 */
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 */
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 */
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 */
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 */
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
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