First cut of replay_trace for tdb.

ccan/tdb/open.c

@@ -379,9 +379,9 @@ int tdb_close(struct tdb_context *tdb)
 	struct tdb_context **i;
 	int ret = 0;
 
-	tdb_trace(tdb, "tdb_close");
+	tdb_trace(tdb, "tdb_close\n");
 	if (tdb->transaction) {
-		tdb_transaction_cancel(tdb);
+		tdb_transaction_cancel_internal(tdb);
 	}
 
 	if (tdb->map_ptr) {

ccan/tdb/tdb.c

@@ -65,8 +65,6 @@ static void tdb_increment_seqnum(struct tdb_context *tdb)
 		return;
 	}
 
-	tdb_trace(tdb, "tdb_increment_seqnum");
-
 	tdb_increment_seqnum_nonblock(tdb);
 
 	tdb_brlock(tdb, TDB_SEQNUM_OFS, F_UNLCK, F_SETLKW, 1, 1);
@@ -417,7 +415,7 @@ int tdb_delete(struct tdb_context *tdb, TDB_DATA key)
 	ret = tdb_delete_hash(tdb, key, hash);
 	tdb_trace(tdb, "tdb_delete ");
 	tdb_trace_record(tdb, key);
-	tdb_trace(tdb, "= %i\n", ret); 
+	tdb_trace(tdb, "= %s\n", ret ? "ENOENT" : "0"); 
 	return ret;
 }
 
@@ -693,8 +691,8 @@ int tdb_get_seqnum(struct tdb_context *tdb)
 {
 	tdb_off_t seqnum=0;
 
-	tdb_trace(tdb, "tdb_get_seqnum\n");
 	tdb_ofs_read(tdb, TDB_SEQNUM_OFS, &seqnum);
+	tdb_trace(tdb, "tdb_get_seqnum = %u\n", seqnum);
 	return seqnum;
 }
 
@@ -857,23 +855,25 @@ void tdb_trace(const struct tdb_context *tdb, const char *fmt, ...)
 {
 	char msg[256];
 	va_list args;
-	int len;
+	int len, err;
 
 	va_start(args, fmt);
 	len = vsprintf(msg, fmt, args);
 	va_end(args);
 
-	write(tdb->tracefd, msg, len);
+	err = write(tdb->tracefd, msg, len);
 }
 
 void tdb_trace_record(const struct tdb_context *tdb, TDB_DATA rec)
 {
 	char msg[20];
 	unsigned int i;
+	int err;
 
-	write(tdb->tracefd, msg, sprintf(msg, "%zu:", rec.dsize));
+	err = write(tdb->tracefd, msg, sprintf(msg, "%zu:", rec.dsize));
 	for (i = 0; i < rec.dsize; i++)
-		write(tdb->tracefd, msg, sprintf(msg, "%02x", rec.dptr[i]));
-	write(tdb->tracefd, " ", 1);
+		err += write(tdb->tracefd, msg, sprintf(msg, "%02x",
+							rec.dptr[i]));
+	err += write(tdb->tracefd, " ", 1);
 }
 #endif

ccan/tdb/tdb_private.h

@@ -49,6 +49,8 @@
 #endif
 #include "tdb.h"
 
+/* #define TDB_TRACE 1 */
+
 #if HAVE_GETPAGESIZE
 #define getpagesize() 0x2000
 #endif
@@ -225,6 +227,7 @@ int tdb_ofs_read(struct tdb_context *tdb, tdb_off_t offset, tdb_off_t *d);
 int tdb_ofs_write(struct tdb_context *tdb, tdb_off_t offset, tdb_off_t *d);
 int tdb_lock_record(struct tdb_context *tdb, tdb_off_t off);
 int tdb_unlock_record(struct tdb_context *tdb, tdb_off_t off);
+int tdb_transaction_cancel_internal(struct tdb_context *tdb);
 int tdb_rec_read(struct tdb_context *tdb, tdb_off_t offset, struct list_struct *rec);
 int tdb_rec_write(struct tdb_context *tdb, tdb_off_t offset, struct list_struct *rec);
 int tdb_do_delete(struct tdb_context *tdb, tdb_off_t rec_ptr, struct list_struct *rec);

ccan/tdb/tools/Makefile

+LDLIBS:=-lccan
+CFLAGS:=-I../../.. -Wall -g -pg -O3
+LDFLAGS:=-L../../..
+
+default: replay_trace tdbtorture
+
+clean:
+	rm -f replay_trace tdbtorture *.o

ccan/tdb/tools/tdbtorture.c

+/* this tests tdb by doing lots of ops from several simultaneous
+   writers - that stresses the locking code. 
+*/
+
+#include <ccan/tdb/tdb.h>
+#include <stdlib.h>
+#include <err.h>
+#include <getopt.h>
+#include <stdarg.h>
+#include <stdio.h>
+#include <string.h>
+#include <errno.h>
+#include <unistd.h>
+#include <sys/types.h>
+#include <fcntl.h>
+#include <time.h>
+#include <sys/wait.h>
+
+#define REOPEN_PROB 30
+#define DELETE_PROB 8
+#define STORE_PROB 4
+#define APPEND_PROB 6
+#define TRANSACTION_PROB 10
+#define TRANSACTION_PREPARE_PROB 2
+#define LOCKSTORE_PROB 5
+#define TRAVERSE_PROB 20
+#define TRAVERSE_READ_PROB 20
+#define CULL_PROB 100
+#define KEYLEN 3
+#define DATALEN 100
+
+static struct tdb_context *db;
+static int in_transaction;
+static int error_count;
+
+#ifdef PRINTF_ATTRIBUTE
+static void tdb_log(struct tdb_context *tdb, enum tdb_debug_level level, const char *format, ...) PRINTF_ATTRIBUTE(3,4);
+#endif
+static void tdb_log(struct tdb_context *tdb, enum tdb_debug_level level, const char *format, ...)
+{
+	va_list ap;
+    
+	error_count++;
+
+	va_start(ap, format);
+	vfprintf(stdout, format, ap);
+	va_end(ap);
+	fflush(stdout);
+#if 0
+	{
+		char *ptr;
+		asprintf(&ptr,"xterm -e gdb /proc/%d/exe %d", getpid(), getpid());
+		system(ptr);
+		free(ptr);
+	}
+#endif	
+}
+
+static void fatal(const char *why)
+{
+	perror(why);
+	error_count++;
+}
+
+static char *randbuf(int len)
+{
+	char *buf;
+	int i;
+	buf = (char *)malloc(len+1);
+
+	for (i=0;i<len;i++) {
+		buf[i] = 'a' + (rand() % 26);
+	}
+	buf[i] = 0;
+	return buf;
+}
+
+static int cull_traverse(struct tdb_context *tdb, TDB_DATA key, TDB_DATA dbuf,
+			 void *state)
+{
+#if CULL_PROB
+	if (random() % CULL_PROB == 0) {
+		tdb_delete(tdb, key);
+	}
+#endif
+	return 0;
+}
+
+static void addrec_db(void)
+{
+	int klen, dlen;
+	char *k, *d;
+	TDB_DATA key, data;
+
+	klen = 1 + (rand() % KEYLEN);
+	dlen = 1 + (rand() % DATALEN);
+
+	k = randbuf(klen);
+	d = randbuf(dlen);
+
+	key.dptr = (unsigned char *)k;
+	key.dsize = klen+1;
+
+	data.dptr = (unsigned char *)d;
+	data.dsize = dlen+1;
+
+#if TRANSACTION_PROB
+	if (in_transaction == 0 && random() % TRANSACTION_PROB == 0) {
+		if (tdb_transaction_start(db) != 0) {
+			fatal("tdb_transaction_start failed");
+		}
+		in_transaction++;
+		goto next;
+	}
+	if (in_transaction && random() % TRANSACTION_PROB == 0) {
+#if 0
+		if (random() % TRANSACTION_PREPARE_PROB == 0) {
+			if (tdb_transaction_prepare_commit(db) != 0) {
+				fatal("tdb_transaction_prepare_commit failed");
+			}
+		}
+#endif
+		if (tdb_transaction_commit(db) != 0) {
+			fatal("tdb_transaction_commit failed");
+		}
+		in_transaction--;
+		goto next;
+	}
+	if (in_transaction && random() % TRANSACTION_PROB == 0) {
+		if (tdb_transaction_cancel(db) != 0) {
+			fatal("tdb_transaction_cancel failed");
+		}
+		in_transaction--;
+		goto next;
+	}
+#endif
+
+#if REOPEN_PROB
+	if (in_transaction == 0 && random() % REOPEN_PROB == 0) {
+		tdb_reopen_all(0);
+		goto next;
+	} 
+#endif
+
+#if DELETE_PROB
+	if (random() % DELETE_PROB == 0) {
+		tdb_delete(db, key);
+		goto next;
+	}
+#endif
+
+#if STORE_PROB
+	if (random() % STORE_PROB == 0) {
+		if (tdb_store(db, key, data, TDB_REPLACE) != 0) {
+			fatal("tdb_store failed");
+		}
+		goto next;
+	}
+#endif
+
+#if APPEND_PROB
+	if (random() % APPEND_PROB == 0) {
+		if (tdb_append(db, key, data) != 0) {
+			fatal("tdb_append failed");
+		}
+		goto next;
+	}
+#endif
+
+#if LOCKSTORE_PROB
+	if (random() % LOCKSTORE_PROB == 0) {
+		tdb_chainlock(db, key);
+		data = tdb_fetch(db, key);
+		if (tdb_store(db, key, data, TDB_REPLACE) != 0) {
+			fatal("tdb_store failed");
+		}
+		if (data.dptr) free(data.dptr);
+		tdb_chainunlock(db, key);
+		goto next;
+	} 
+#endif
+
+#if TRAVERSE_PROB
+	if (random() % TRAVERSE_PROB == 0) {
+		tdb_traverse(db, cull_traverse, NULL);
+		goto next;
+	}
+#endif
+
+#if TRAVERSE_READ_PROB
+	if (random() % TRAVERSE_READ_PROB == 0) {
+		tdb_traverse_read(db, NULL, NULL);
+		goto next;
+	}
+#endif
+
+	data = tdb_fetch(db, key);
+	if (data.dptr) free(data.dptr);
+
+next:
+	free(k);
+	free(d);
+}
+
+static int traverse_fn(struct tdb_context *tdb, TDB_DATA key, TDB_DATA dbuf,
+                       void *state)
+{
+	tdb_delete(tdb, key);
+	return 0;
+}
+
+static void usage(void)
+{
+	printf("Usage: tdbtorture [-n NUM_PROCS] [-l NUM_LOOPS] [-s SEED] [-H HASH_SIZE]\n");
+	exit(0);
+}
+
+int main(int argc, char * const *argv)
+{
+	int i, seed = -1;
+	int num_procs = 3;
+	int num_loops = 5000;
+	int hash_size = 2;
+	int c;
+	extern char *optarg;
+	pid_t *pids;
+
+	struct tdb_logging_context log_ctx;
+	log_ctx.log_fn = tdb_log;
+
+	while ((c = getopt(argc, argv, "n:l:s:H:h")) != -1) {
+		switch (c) {
+		case 'n':
+			num_procs = strtol(optarg, NULL, 0);
+			break;
+		case 'l':
+			num_loops = strtol(optarg, NULL, 0);
+			break;
+		case 'H':
+			hash_size = strtol(optarg, NULL, 0);
+			break;
+		case 's':
+			seed = strtol(optarg, NULL, 0);
+			break;
+		default:
+			usage();
+		}
+	}
+
+	unlink("torture.tdb");
+
+	pids = (pid_t *)calloc(sizeof(pid_t), num_procs);
+	pids[0] = getpid();
+
+	for (i=0;i<num_procs-1;i++) {
+		if ((pids[i+1]=fork()) == 0) break;
+	}
+
+	db = tdb_open_ex("torture.tdb", hash_size, TDB_CLEAR_IF_FIRST, 
+			 O_RDWR | O_CREAT, 0600, &log_ctx, NULL);
+	if (!db) {
+		fatal("db open failed");
+	}
+
+	if (seed == -1) {
+		seed = (getpid() + time(NULL)) & 0x7FFFFFFF;
+	}
+
+	if (i == 0) {
+		printf("testing with %d processes, %d loops, %d hash_size, seed=%d\n", 
+		       num_procs, num_loops, hash_size, seed);
+	}
+
+	srand(seed + i);
+	srandom(seed + i);
+
+	for (i=0;i<num_loops && error_count == 0;i++) {
+		addrec_db();
+	}
+
+	if (error_count == 0) {
+		tdb_traverse_read(db, NULL, NULL);
+		tdb_traverse(db, traverse_fn, NULL);
+		tdb_traverse(db, traverse_fn, NULL);
+	}
+
+	tdb_close(db);
+
+	if (getpid() != pids[0]) {
+		return error_count;
+	}
+
+	for (i=1;i<num_procs;i++) {
+		int status, j;
+		pid_t pid;
+		if (error_count != 0) {
+			/* try and stop the test on any failure */
+			for (j=1;j<num_procs;j++) {
+				if (pids[j] != 0) {
+					kill(pids[j], SIGTERM);
+				}
+			}
+		}
+		pid = waitpid(-1, &status, 0);
+		if (pid == -1) {
+			perror("failed to wait for child\n");
+			exit(1);
+		}
+		for (j=1;j<num_procs;j++) {
+			if (pids[j] == pid) break;
+		}
+		if (j == num_procs) {
+			printf("unknown child %d exited!?\n", (int)pid);
+			exit(1);
+		}
+		if (WEXITSTATUS(status) != 0) {
+			printf("child %d exited with status %d\n",
+			       (int)pid, WEXITSTATUS(status));
+			error_count++;
+		}
+		pids[j] = 0;
+	}
+
+	free(pids);
+
+	if (error_count == 0) {
+		printf("OK\n");
+	}
+
+	return error_count;
+}

ccan/tdb/transaction.c

@@ -398,6 +398,58 @@ static const struct tdb_methods transaction_methods = {
 	transaction_brlock
 };
 
+int tdb_transaction_cancel_internal(struct tdb_context *tdb)
+{
+	int i;
+
+	if (tdb->transaction == NULL) {
+		TDB_LOG((tdb, TDB_DEBUG_ERROR, "tdb_transaction_cancel: no transaction\n"));
+		return -1;
+	}
+
+	if (tdb->transaction->nesting != 0) {
+		tdb->transaction->transaction_error = 1;
+		tdb->transaction->nesting--;
+		return 0;
+	}		
+
+	tdb->map_size = tdb->transaction->old_map_size;
+
+	/* free all the transaction blocks */
+	for (i=0;i<tdb->transaction->num_blocks;i++) {
+		if (tdb->transaction->blocks[i] != NULL) {
+			free(tdb->transaction->blocks[i]);
+		}
+	}
+	SAFE_FREE(tdb->transaction->blocks);
+
+	/* remove any global lock created during the transaction */
+	if (tdb->global_lock.count != 0) {
+		tdb_brlock(tdb, FREELIST_TOP, F_UNLCK, F_SETLKW, 0, 4*tdb->header.hash_size);
+		tdb->global_lock.count = 0;
+	}
+
+	/* remove any locks created during the transaction */
+	if (tdb->num_locks != 0) {
+		for (i=0;i<tdb->num_lockrecs;i++) {
+			tdb_brlock(tdb,FREELIST_TOP+4*tdb->lockrecs[i].list,
+				   F_UNLCK,F_SETLKW, 0, 1);
+		}
+		tdb->num_locks = 0;
+		tdb->num_lockrecs = 0;
+		SAFE_FREE(tdb->lockrecs);
+	}
+
+	/* restore the normal io methods */
+	tdb->methods = tdb->transaction->io_methods;
+
+	tdb_brlock(tdb, FREELIST_TOP, F_UNLCK, F_SETLKW, 0, 0);
+	tdb_transaction_unlock(tdb);
+	SAFE_FREE(tdb->transaction->hash_heads);
+	SAFE_FREE(tdb->transaction);
+	
+	return 0;
+}
 
 /*
   start a tdb transaction. No token is returned, as only a single
@@ -422,7 +474,7 @@ int tdb_transaction_start(struct tdb_context *tdb)
 				 tdb->transaction->nesting));
 			return 0;
 		} else {
-			tdb_transaction_cancel(tdb);
+			tdb_transaction_cancel_internal(tdb);
 			TDB_LOG((tdb, TDB_DEBUG_TRACE, "tdb_transaction_start: cancelling previous transaction\n"));
 		}
 	}
@@ -514,58 +566,9 @@ fail:
 */
 int tdb_transaction_cancel(struct tdb_context *tdb)
 {	
-	int i;
-
 	tdb_trace(tdb, "tdb_transaction_cancel\n");
-	if (tdb->transaction == NULL) {
-		TDB_LOG((tdb, TDB_DEBUG_ERROR, "tdb_transaction_cancel: no transaction\n"));
-		return -1;
-	}
-
-	if (tdb->transaction->nesting != 0) {
-		tdb->transaction->transaction_error = 1;
-		tdb->transaction->nesting--;
-		return 0;
-	}		
-
-	tdb->map_size = tdb->transaction->old_map_size;
-
-	/* free all the transaction blocks */
-	for (i=0;i<tdb->transaction->num_blocks;i++) {
-		if (tdb->transaction->blocks[i] != NULL) {
-			free(tdb->transaction->blocks[i]);
-		}
-	}
-	SAFE_FREE(tdb->transaction->blocks);
-
-	/* remove any global lock created during the transaction */
-	if (tdb->global_lock.count != 0) {
-		tdb_brlock(tdb, FREELIST_TOP, F_UNLCK, F_SETLKW, 0, 4*tdb->header.hash_size);
-		tdb->global_lock.count = 0;
-	}
-
-	/* remove any locks created during the transaction */
-	if (tdb->num_locks != 0) {
-		for (i=0;i<tdb->num_lockrecs;i++) {
-			tdb_brlock(tdb,FREELIST_TOP+4*tdb->lockrecs[i].list,
-				   F_UNLCK,F_SETLKW, 0, 1);
-		}
-		tdb->num_locks = 0;
-		tdb->num_lockrecs = 0;
-		SAFE_FREE(tdb->lockrecs);
-	}
-
-	/* restore the normal io methods */
-	tdb->methods = tdb->transaction->io_methods;
-
-	tdb_brlock(tdb, FREELIST_TOP, F_UNLCK, F_SETLKW, 0, 0);
-	tdb_transaction_unlock(tdb);
-	SAFE_FREE(tdb->transaction->hash_heads);
-	SAFE_FREE(tdb->transaction);
-	
-	return 0;
+	return tdb_transaction_cancel_internal(tdb);
 }
-
 /*
   sync to disk
 */
@@ -856,7 +859,7 @@ int tdb_transaction_commit(struct tdb_context *tdb)
 
 	if (tdb->transaction->transaction_error) {
 		tdb->ecode = TDB_ERR_IO;
-		tdb_transaction_cancel(tdb);
+		tdb_transaction_cancel_internal(tdb);
 		TDB_LOG((tdb, TDB_DEBUG_ERROR, "tdb_transaction_commit: transaction error pending\n"));
 		return -1;
 	}
@@ -869,7 +872,7 @@ int tdb_transaction_commit(struct tdb_context *tdb)
 
 	/* check for a null transaction */
 	if (tdb->transaction->blocks == NULL) {
-		tdb_transaction_cancel(tdb);
+		tdb_transaction_cancel_internal(tdb);
 		return 0;
 	}
 
@@ -880,7 +883,7 @@ int tdb_transaction_commit(struct tdb_context *tdb)
 	if (tdb->num_locks || tdb->global_lock.count) {
 		tdb->ecode = TDB_ERR_LOCK;
 		TDB_LOG((tdb, TDB_DEBUG_ERROR, "tdb_transaction_commit: locks pending on commit\n"));
-		tdb_transaction_cancel(tdb);
+		tdb_transaction_cancel_internal(tdb);
 		return -1;
 	}
 
@@ -888,7 +891,7 @@ int tdb_transaction_commit(struct tdb_context *tdb)
 	if (tdb_brlock_upgrade(tdb, FREELIST_TOP, 0) == -1) {
 		TDB_LOG((tdb, TDB_DEBUG_ERROR, "tdb_transaction_start: failed to upgrade hash locks\n"));
 		tdb->ecode = TDB_ERR_LOCK;
-		tdb_transaction_cancel(tdb);
+		tdb_transaction_cancel_internal(tdb);
 		return -1;
 	}
 
@@ -897,7 +900,7 @@ int tdb_transaction_commit(struct tdb_context *tdb)
 	if (tdb_brlock(tdb, GLOBAL_LOCK, F_WRLCK, F_SETLKW, 0, 1) == -1) {
 		TDB_LOG((tdb, TDB_DEBUG_ERROR, "tdb_transaction_commit: failed to get global lock\n"));
 		tdb->ecode = TDB_ERR_LOCK;
-		tdb_transaction_cancel(tdb);
+		tdb_transaction_cancel_internal(tdb);
 		return -1;
 	}
 
@@ -906,7 +909,7 @@ int tdb_transaction_commit(struct tdb_context *tdb)
 		if (transaction_setup_recovery(tdb, &magic_offset) == -1) {
 			TDB_LOG((tdb, TDB_DEBUG_FATAL, "tdb_transaction_commit: failed to setup recovery data\n"));
 			tdb_brlock(tdb, GLOBAL_LOCK, F_UNLCK, F_SETLKW, 0, 1);
-			tdb_transaction_cancel(tdb);
+			tdb_transaction_cancel_internal(tdb);
 			return -1;
 		}
 	}
@@ -919,7 +922,7 @@ int tdb_transaction_commit(struct tdb_context *tdb)
 			tdb->ecode = TDB_ERR_IO;
 			TDB_LOG((tdb, TDB_DEBUG_FATAL, "tdb_transaction_commit: expansion failed\n"));
 			tdb_brlock(tdb, GLOBAL_LOCK, F_UNLCK, F_SETLKW, 0, 1);
-			tdb_transaction_cancel(tdb);
+			tdb_transaction_cancel_internal(tdb);
 			return -1;
 		}
 		tdb->map_size = tdb->transaction->old_map_size;
@@ -950,7 +953,7 @@ int tdb_transaction_commit(struct tdb_context *tdb)
 			tdb->methods = methods;
 			tdb_transaction_recover(tdb); 
 
-			tdb_transaction_cancel(tdb);
+			tdb_transaction_cancel_internal(tdb);
 			tdb_brlock(tdb, GLOBAL_LOCK, F_UNLCK, F_SETLKW, 0, 1);
 
 			TDB_LOG((tdb, TDB_DEBUG_FATAL, "tdb_transaction_commit: write failed\n"));
@@ -999,7 +1002,7 @@ int tdb_transaction_commit(struct tdb_context *tdb)
 
 	/* use a transaction cancel to free memory and remove the
 	   transaction locks */
-	tdb_transaction_cancel(tdb);
+	tdb_transaction_cancel_internal(tdb);
 
 	return 0;
 }

ccan/tdb/traverse.c

@@ -169,6 +169,11 @@ static int tdb_traverse_internal(struct tdb_context *tdb,
 		dbuf.dptr = key.dptr + rec.key_len;
 		dbuf.dsize = rec.data_len;
 
+		tdb_trace(tdb, "traverse ");
+		tdb_trace_record(tdb, key);
+		tdb_trace_record(tdb, dbuf);
+		tdb_trace(tdb, "\n");
+
 		/* Drop chain lock, call out */
 		if (tdb_unlock(tdb, tl->hash, tl->lock_rw) != 0) {
 			ret = -1;
@@ -212,9 +217,10 @@ int tdb_traverse_read(struct tdb_context *tdb,
 	}
 
 	tdb->traverse_read++;
+	tdb_trace(tdb, "tdb_traverse_read_start\n");
 	ret = tdb_traverse_internal(tdb, fn, private_data, &tl);
+	tdb_trace(tdb, "tdb_traverse_end = %i\n", ret);
 	tdb->traverse_read--;
-	tdb_trace(tdb, "tdb_traverse_read = %i\n", ret);
 
 	tdb_transaction_unlock(tdb);
 
@@ -243,9 +249,10 @@ int tdb_traverse(struct tdb_context *tdb,
 	}
 
 	tdb->traverse_write++;
+	tdb_trace(tdb, "tdb_traverse_start\n");
 	ret = tdb_traverse_internal(tdb, fn, private_data, &tl);
+	tdb_trace(tdb, "tdb_traverse_end = %i\n", ret);
 	tdb->traverse_write--;
-	tdb_trace(tdb, "tdb_traverse = %i\n", ret);
 
 	tdb_transaction_unlock(tdb);