]> pd.if.org Git - nbds/commitdiff
fix resize and copy bugs
authorjdybnis <jdybnis@9ec2166a-aeea-11dd-8830-69e4bb380a4a>
Fri, 14 Nov 2008 08:54:38 +0000 (08:54 +0000)
committerjdybnis <jdybnis@9ec2166a-aeea-11dd-8830-69e4bb380a4a>
Fri, 14 Nov 2008 08:54:38 +0000 (08:54 +0000)
improve tracing

makefile
runtime/lwt.c
runtime/mem.c
struct/ht.c
test/CuTest.c
test/ht_test.c

index 3b167e6a5c7fb6b102a876c4a3c5de58c2489d78..939f8dd1bccb12c96ae5227ab73aeaafe08364bf 100644 (file)
--- a/makefile
+++ b/makefile
@@ -12,10 +12,10 @@ TESTS  := output/rcu_test output/list_test output/ht_test
 EXES   := $(TESTS) output/txn_test
 
 RUNTIME_SRCS   := runtime/runtime.c runtime/rcu.c runtime/lwt.c runtime/mem.c 
 EXES   := $(TESTS) output/txn_test
 
 RUNTIME_SRCS   := runtime/runtime.c runtime/rcu.c runtime/lwt.c runtime/mem.c 
-TEST_SRCS      := $(RUNTIME_SRCS) test/CuTest.c
+TEST_SRCS      := $(RUNTIME_SRCS) 
 rcu_test_SRCS  := $(TEST_SRCS)
 list_test_SRCS := $(TEST_SRCS) struct/list.c
 rcu_test_SRCS  := $(TEST_SRCS)
 list_test_SRCS := $(TEST_SRCS) struct/list.c
-ht_test_SRCS   := $(TEST_SRCS) struct/ht.c test/ht_test.c
+ht_test_SRCS   := $(TEST_SRCS) struct/ht.c test/ht_test.c test/CuTest.c
 txn_test_SRCS  := $(TEST_SRCS) struct/ht.c txn/txn.c
 
 tests: $(TESTS) 
 txn_test_SRCS  := $(TEST_SRCS) struct/ht.c txn/txn.c
 
 tests: $(TESTS) 
index 8f12974247136e4cd7327967cf917b2b43518417..be83e5fb1c31453463897f231d5318eb24f01cd9 100644 (file)
@@ -14,6 +14,8 @@
 #define LWT_BUFFER_SIZE (1 << LWT_BUFFER_SCALE)
 #define LWT_BUFFER_MASK (LWT_BUFFER_SIZE - 1)
 
 #define LWT_BUFFER_SIZE (1 << LWT_BUFFER_SCALE)
 #define LWT_BUFFER_MASK (LWT_BUFFER_SIZE - 1)
 
+volatile int halt_ = 0;
+
 typedef struct lwt_record {
     uint64_t timestamp;
     const char *format;
 typedef struct lwt_record {
     uint64_t timestamp;
     const char *format;
@@ -58,7 +60,7 @@ static inline void dump_record (FILE *file, int thread_id, lwt_record_t *r, uint
     if (f != NULL && level <= f[1]) {
         char s[3] = {flag, level, '\0'};
         fprintf(file, "%09llu %d %s ", ((uint64_t)r->timestamp - offset) >> 6, thread_id, s);
     if (f != NULL && level <= f[1]) {
         char s[3] = {flag, level, '\0'};
         fprintf(file, "%09llu %d %s ", ((uint64_t)r->timestamp - offset) >> 6, thread_id, s);
-        const char *format = (const char *)(((uint64_t)r->format << 16) >> 16); // strip out the embedded flags
+        const char *format = (const char *)((size_t)r->format & MASK(48)); // strip out the embedded flags
         fprintf(file, format, r->value1, r->value2);
         fprintf(file, "\n");
     }
         fprintf(file, format, r->value1, r->value2);
         fprintf(file, "\n");
     }
@@ -81,6 +83,7 @@ static void dump_buffer (FILE *file, int thread_id, uint64_t offset)
 
 void lwt_dump (const char *file_name)
 {
 
 void lwt_dump (const char *file_name)
 {
+    halt_ = 1;
     uint64_t offset = (uint64_t)-1;
 
     for (int i = 0; i < MAX_NUM_THREADS; ++i) {
     uint64_t offset = (uint64_t)-1;
 
     for (int i = 0; i < MAX_NUM_THREADS; ++i) {
@@ -113,6 +116,8 @@ void lwt_dump (const char *file_name)
 }
 
 void lwt_trace_i (const char *format, size_t value1, size_t value2) {
 }
 
 void lwt_trace_i (const char *format, size_t value1, size_t value2) {
+    if (*(volatile int *)&halt_)
+        return;
     LOCALIZE_THREAD_LOCAL(tid_, int);
     lwt_buffer_t *tb = lwt_buf_[tid_];
     if (tb != NULL) {
     LOCALIZE_THREAD_LOCAL(tid_, int);
     lwt_buffer_t *tb = lwt_buf_[tid_];
     if (tb != NULL) {
index 708ef22ed94f5526b1b5cb23de73b1f21c8d73fc..754bb19d5ce293ad345a96801d4b49f89384f944 100644 (file)
@@ -98,7 +98,7 @@ void *nbd_malloc (size_t n) {
     assert(b_scale <= MAX_SCALE);
     TRACE("m0", "nbd_malloc(): size %llu scale %llu", n, b_scale);
     private_list_t *pri = &pri_free_list_[tid_][b_scale]; // our private free list
     assert(b_scale <= MAX_SCALE);
     TRACE("m0", "nbd_malloc(): size %llu scale %llu", n, b_scale);
     private_list_t *pri = &pri_free_list_[tid_][b_scale]; // our private free list
-    TRACE("m0", "nbd_malloc(): private free list %p first block %p", pri->list, pri->head);
+    TRACE("m0", "nbd_malloc(): private free list first block %p", pri->head, 0);
 
     // If our private free list is empty, try to find blocks on our public free list. If that fails,
     // allocate a new region.
 
     // If our private free list is empty, try to find blocks on our public free list. If that fails,
     // allocate a new region.
@@ -133,7 +133,7 @@ void *nbd_malloc (size_t n) {
 
             if (pubs[pri->next_pub] != NULL) {
                 block_t *stolen = SYNC_SWAP(&pubs[pri->next_pub], NULL);
 
             if (pubs[pri->next_pub] != NULL) {
                 block_t *stolen = SYNC_SWAP(&pubs[pri->next_pub], NULL);
-                TRACE("m0", "nbd_malloc(): stole list %p first block %p", stolen);
+                TRACE("m0", "nbd_malloc(): stole list %p", stolen, 0);
                 if (stolen == NULL)
                     continue;
                 pri->head = stolen;
                 if (stolen == NULL)
                     continue;
                 pri->head = stolen;
@@ -145,7 +145,7 @@ void *nbd_malloc (size_t n) {
 
     // Pull a block off of our private free list.
     block_t *b = pri->head;
 
     // Pull a block off of our private free list.
     block_t *b = pri->head;
-    TRACE("m0", "nbd_malloc(): take block %p off of of private list (new head is %p)", b, pri->next);
+    TRACE("m0", "nbd_malloc(): take block %p off of of private list (new head is %p)", b, b->next);
     assert(b);
     pri->head = b->next;
     pri->count++;
     assert(b);
     pri->head = b->next;
     pri->count++;
index 2eb376e4fd3d99f42505e85a1e0508eef06a3aeb..704443550f686776b5d98ff887163b7e8659c607 100644 (file)
@@ -25,7 +25,7 @@
 #define MIN_SCALE               (__builtin_ctz(ENTRIES_PER_BUCKET) + 2) // min 4 buckets
 #define MAX_BUCKETS_TO_PROBE    250
 
 #define MIN_SCALE               (__builtin_ctz(ENTRIES_PER_BUCKET) + 2) // min 4 buckets
 #define MAX_BUCKETS_TO_PROBE    250
 
-#define GET_PTR(x) (string_t *)((x) & MASK(48)) // low-order 48 bits is a pointer to a string_t
+#define GET_PTR(x) ((string_t *)((x) & MASK(48))) // low-order 48 bits is a pointer to a string_t
 
 typedef struct ht_entry {
     uint64_t key;
 
 typedef struct ht_entry {
     uint64_t key;
@@ -81,33 +81,31 @@ static inline int ht_key_equals (uint64_t a, uint32_t b_hash, const char *b_valu
 // Record if the entry being returned is empty. Otherwise the caller will have to waste time with
 // ht_key_equals() to confirm that it did not lose a race to fill an empty entry.
 static volatile entry_t *hti_lookup (hash_table_i_t *hti, uint32_t key_hash, const char *key_val, uint32_t key_len, int *is_empty) {
 // Record if the entry being returned is empty. Otherwise the caller will have to waste time with
 // ht_key_equals() to confirm that it did not lose a race to fill an empty entry.
 static volatile entry_t *hti_lookup (hash_table_i_t *hti, uint32_t key_hash, const char *key_val, uint32_t key_len, int *is_empty) {
-    TRACE("h0", "hti_lookup(key \"%s\" in hti %p)", key_val, hti);
+    TRACE("h0", "hti_lookup(key %p in hti %p)", key_val, hti);
     *is_empty = 0;
 
     // Probe one cache line at a time
     int ndx = key_hash & MASK(hti->scale); // the first entry to search
     *is_empty = 0;
 
     // Probe one cache line at a time
     int ndx = key_hash & MASK(hti->scale); // the first entry to search
-    int i;
-    for (i = 0; i < hti->max_probe; ++i) {
+    for (int i = 0; i < hti->max_probe; ++i) {
 
         // The start of the bucket is the first entry in the cache line.
         volatile entry_t *bucket = hti->table + (ndx & ~(ENTRIES_PER_BUCKET-1)); 
 
         // Start searching at the indexed entry. Then loop around to the begining of the cache line.
 
         // The start of the bucket is the first entry in the cache line.
         volatile entry_t *bucket = hti->table + (ndx & ~(ENTRIES_PER_BUCKET-1)); 
 
         // Start searching at the indexed entry. Then loop around to the begining of the cache line.
-        int j;
-        for (j = 0; j < ENTRIES_PER_BUCKET; ++j) {
+        for (int j = 0; j < ENTRIES_PER_BUCKET; ++j) {
             volatile entry_t *e = bucket + ((ndx + j) & (ENTRIES_PER_BUCKET-1));
 
             uint64_t e_key = e->key;
             if (e_key == DOES_NOT_EXIST) {
             volatile entry_t *e = bucket + ((ndx + j) & (ENTRIES_PER_BUCKET-1));
 
             uint64_t e_key = e->key;
             if (e_key == DOES_NOT_EXIST) {
-                TRACE("h0", "hti_lookup: empty entry %p found on probe %d", e, i*ENTRIES_PER_BUCKET+j+1);
-                // we tag the pointer so the caller can avoid an expensive ht_key_equals()
-                *is_empty = 1;
+                TRACE("h0", "hti_lookup: empty entry %p found", e, 0);
+                *is_empty = 1; // indicate an empty so the caller avoids an expensive ht_key_equals
                 return e;
             }
 
             if (ht_key_equals(e_key, key_hash, key_val, key_len)) {
                 return e;
             }
 
             if (ht_key_equals(e_key, key_hash, key_val, key_len)) {
-                TRACE("h0", "hti_lookup: entry %p found on probe %d", e, i*ENTRIES_PER_BUCKET+j+1);
-                TRACE("h0", "hti_lookup: with key \"%s\" value %p", GET_PTR(e_key)->val, e->value);
+                TRACE("h0", "hti_lookup: entry %p found value %p", e, e->value);
+                TRACE("h0", "hti_lookup: entry key %p len %llu", GET_PTR(e_key)->val, 
+                                                                 GET_PTR(e_key)->len);
                 return e;
             }
         }
                 return e;
             }
         }
@@ -153,9 +151,7 @@ static hash_table_i_t *hti_alloc (hash_table_t *parent, int scale) {
 //
 // Initiates a copy by creating a larger hash_table_i_t and installing it in <hti->next>.
 static void hti_start_copy (hash_table_i_t *hti) {
 //
 // Initiates a copy by creating a larger hash_table_i_t and installing it in <hti->next>.
 static void hti_start_copy (hash_table_i_t *hti) {
-    TRACE("h0", "hti_start_copy(hti %p hti->next %p)", hti, hti->next);
-    if (hti->next) 
-        return; // another thread beat us to it
+    TRACE("h0", "hti_start_copy(hti %p scale %llu)", hti, hti->scale);
 
     // heuristics to determine the size of the new table
     uint64_t count = ht_count(hti->ht);
 
     // heuristics to determine the size of the new table
     uint64_t count = ht_count(hti->ht);
@@ -164,7 +160,8 @@ static void hti_start_copy (hash_table_i_t *hti) {
     new_scale += (count > (1 << (new_scale - 2))); // double size again if more than 1/2 full
 
     // Allocate the new table and attempt to install it.
     new_scale += (count > (1 << (new_scale - 2))); // double size again if more than 1/2 full
 
     // Allocate the new table and attempt to install it.
-    hash_table_i_t *next = hti_alloc(hti->ht, hti->scale + 1);
+    hash_table_i_t *next = hti_alloc(hti->ht, new_scale);
+    TRACE("h0", "hti_start_copy: new hti %p scale %llu", next->scale, next->scale);
     hash_table_i_t *old_next = SYNC_CAS(&hti->next, NULL, next);
     if (old_next != NULL) {
         TRACE("h0", "hti_start_copy: lost race to install new hti; found %p", old_next, 0);
     hash_table_i_t *old_next = SYNC_CAS(&hti->next, NULL, next);
     if (old_next != NULL) {
         TRACE("h0", "hti_start_copy: lost race to install new hti; found %p", old_next, 0);
@@ -226,7 +223,7 @@ static int hti_copy_entry (hash_table_i_t *ht1, volatile entry_t *ht1_e, uint32_
     uint64_t key = ht1_e->key;
     string_t *key_string = GET_PTR(key);
     uint64_t value = STRIP_TAG(ht1_e_value);
     uint64_t key = ht1_e->key;
     string_t *key_string = GET_PTR(key);
     uint64_t value = STRIP_TAG(ht1_e_value);
-    TRACE("h0", "hti_copy_entry: key %p is %s", key, key_string->val);
+    TRACE("h0", "hti_copy_entry: key %p value %p", key, value);
 
     // We use 0 to indicate that <key_hash> isn't initiallized. Occasionally the <key_hash> will
     // really be 0 and we will waste time recomputing it. That is rare enough that it is OK. 
 
     // We use 0 to indicate that <key_hash> isn't initiallized. Occasionally the <key_hash> will
     // really be 0 and we will waste time recomputing it. That is rare enough that it is OK. 
@@ -239,7 +236,9 @@ static int hti_copy_entry (hash_table_i_t *ht1, volatile entry_t *ht1_e, uint32_
 
     // it is possible that there is not any room in the new table either
     if (EXPECT_FALSE(ht2_e == NULL)) {
 
     // it is possible that there is not any room in the new table either
     if (EXPECT_FALSE(ht2_e == NULL)) {
-        hti_start_copy(ht2); // initiate nested copy, if not already started
+        if (ht2->next == NULL) {
+            hti_start_copy(ht2); // initiate nested copy, if not already started
+        }
         return hti_copy_entry(ht1, ht1_e, key_hash, ht2->next); // recursive tail-call
     }
 
         return hti_copy_entry(ht1, ht1_e, key_hash, ht2->next); // recursive tail-call
     }
 
@@ -253,7 +252,7 @@ static int hti_copy_entry (hash_table_i_t *ht1, volatile entry_t *ht1_e, uint32_
         }
     }
     assert(ht_key_equals(ht2_e->key, key_hash, key_string->val, key_string->len));
         }
     }
     assert(ht_key_equals(ht2_e->key, key_hash, key_string->val, key_string->len));
-    TRACE("h0", "hti_copy_entry: key %p installed in new old hti %p", key_string->val, ht2);
+    TRACE("h0", "hti_copy_entry: key %p installed in new hti %p", key_string->val, ht2);
 
     // Copy the value to the entry in the new table.
     uint64_t old_ht2_e_value = SYNC_CAS(&ht2_e->value, DOES_NOT_EXIST, value);
 
     // Copy the value to the entry in the new table.
     uint64_t old_ht2_e_value = SYNC_CAS(&ht2_e->value, DOES_NOT_EXIST, value);
@@ -294,8 +293,8 @@ static int hti_copy_entry (hash_table_i_t *ht1, volatile entry_t *ht1_e, uint32_
 //
 static uint64_t hti_compare_and_set (hash_table_i_t *hti, uint32_t key_hash, const char *key_val, 
                                     uint32_t key_len, uint64_t expected, uint64_t new) {
 //
 static uint64_t hti_compare_and_set (hash_table_i_t *hti, uint32_t key_hash, const char *key_val, 
                                     uint32_t key_len, uint64_t expected, uint64_t new) {
-    TRACE("h0", "hti_compare_and_set(hti %p key \"%s\")", hti, key_val);
-    TRACE("h0", "hti_compare_and_set(new value %p; caller expects value %p)", new, expected);
+    TRACE("h0", "hti_compare_and_set: hti %p key %p", hti, key_val);
+    TRACE("h0", "hti_compare_and_set: new value %p expected old value %p", new, expected);
     assert(hti);
     assert(new != DOES_NOT_EXIST && !IS_TAGGED(new));
     assert(key_val);
     assert(hti);
     assert(new != DOES_NOT_EXIST && !IS_TAGGED(new));
     assert(key_val);
@@ -305,7 +304,9 @@ static uint64_t hti_compare_and_set (hash_table_i_t *hti, uint32_t key_hash, con
 
     // There is no room for <key>, grow the table and try again.
     if (e == NULL) {
 
     // There is no room for <key>, grow the table and try again.
     if (e == NULL) {
-        hti_start_copy(hti);
+        if (hti->next == NULL) {
+            hti_start_copy(hti);
+        }
         return COPIED_VALUE;
     }
 
         return COPIED_VALUE;
     }
 
@@ -319,22 +320,23 @@ static uint64_t hti_compare_and_set (hash_table_i_t *hti, uint32_t key_hash, con
         if (new == TOMBSTONE)
             return DOES_NOT_EXIST;
 
         if (new == TOMBSTONE)
             return DOES_NOT_EXIST;
 
-        // allocate <key>.
+        // Allocate <key>.
         string_t *key = nbd_malloc(sizeof(uint32_t) + key_len);
         key->len = key_len;
         memcpy(key->val, key_val, key_len);
 
         string_t *key = nbd_malloc(sizeof(uint32_t) + key_len);
         key->len = key_len;
         memcpy(key->val, key_val, key_len);
 
-        // CAS <key> into the table. 
-        uint64_t e_key = SYNC_CAS(&e->key, DOES_NOT_EXIST, ((uint64_t)(key_hash >> 16) << 48) | (uint64_t)key);
+        // Combine <key> pointer with bits from its hash, CAS it into the table. 
+        uint64_t temp = ((uint64_t)(key_hash >> 16) << 48) | (uint64_t)key; 
+        uint64_t e_key = SYNC_CAS(&e->key, DOES_NOT_EXIST, temp);
 
         // Retry if another thread stole the entry out from under us.
         if (e_key != DOES_NOT_EXIST) {
 
         // Retry if another thread stole the entry out from under us.
         if (e_key != DOES_NOT_EXIST) {
-            TRACE("h0", "hti_compare_and_set: key in entry %p is \"%s\"", e, GET_PTR(e_key)->val);
-            TRACE("h0", "hti_compare_and_set: lost race to install key \"%s\" in %p", key->val, e);
+            TRACE("h0", "hti_compare_and_set: lost race to install key %p in entry %p", key, e);
+            TRACE("h0", "hti_compare_and_set: found %p instead of NULL", GET_PTR(e_key), 0);
             nbd_free(key);
             return hti_compare_and_set(hti, key_hash, key_val, key_len, expected, new); // tail-call
         }
             nbd_free(key);
             return hti_compare_and_set(hti, key_hash, key_val, key_len, expected, new); // tail-call
         }
-        TRACE("h0", "hti_compare_and_set: installed key \"%s\" in entry %p", key_val, e);
+        TRACE("h0", "hti_compare_and_set: installed key %p in entry %p", key, e);
     }
 
     // If the entry is in the middle of a copy, the copy must be completed first.
     }
 
     // If the entry is in the middle of a copy, the copy must be completed first.
@@ -352,8 +354,8 @@ static uint64_t hti_compare_and_set (hash_table_i_t *hti, uint32_t key_hash, con
     int old_existed = (e_value != TOMBSTONE && e_value != DOES_NOT_EXIST);
     if (EXPECT_FALSE(expected != HT_EXPECT_WHATEVER && expected != e_value)) {
         if (EXPECT_FALSE(expected != (old_existed ? HT_EXPECT_EXISTS : HT_EXPECT_NOT_EXISTS))) {
     int old_existed = (e_value != TOMBSTONE && e_value != DOES_NOT_EXIST);
     if (EXPECT_FALSE(expected != HT_EXPECT_WHATEVER && expected != e_value)) {
         if (EXPECT_FALSE(expected != (old_existed ? HT_EXPECT_EXISTS : HT_EXPECT_NOT_EXISTS))) {
-            TRACE("h0", "hti_compare_and_set: value expected by caller for key \"%s\" not found; "
-                        "found value %p", key_val, e_value);
+            TRACE("h0", "hti_compare_and_set: value %p expected by caller not found; found value %p",
+                        expected, e_value);
             return e_value;
         }
     }
             return e_value;
         }
     }
@@ -420,6 +422,8 @@ uint64_t ht_get (hash_table_t *ht, const char *key_val, uint32_t key_len) {
 uint64_t ht_compare_and_set (hash_table_t *ht, const char *key_val, uint32_t key_len, 
                             uint64_t expected_val, uint64_t new_val) {
 
 uint64_t ht_compare_and_set (hash_table_t *ht, const char *key_val, uint32_t key_len, 
                             uint64_t expected_val, uint64_t new_val) {
 
+    TRACE("h0", "ht_compare_and_set: key %p len %u", key_val, key_len);
+    TRACE("h0", "ht_compare_and_set: expected val %p new val %p", expected_val, new_val);
     assert(key_val);
     assert(!IS_TAGGED(new_val) && new_val != DOES_NOT_EXIST);
 
     assert(key_val);
     assert(!IS_TAGGED(new_val) && new_val != DOES_NOT_EXIST);
 
@@ -432,6 +436,7 @@ uint64_t ht_compare_and_set (hash_table_t *ht, const char *key_val, uint32_t key
         int num_copied = 0;
         int x = hti->scan; 
 
         int num_copied = 0;
         int x = hti->scan; 
 
+        TRACE("h0", "ht_compare_and_set: help copy. scan is %llu, size is %llu", x, 1<<hti->scale);
         // Panic if we've been around the array twice and still haven't finished the copy.
         int panic = (x >= (1 << (hti->scale + 1))); 
         if (!panic) {
         // Panic if we've been around the array twice and still haven't finished the copy.
         int panic = (x >= (1 << (hti->scale + 1))); 
         if (!panic) {
@@ -446,6 +451,7 @@ uint64_t ht_compare_and_set (hash_table_t *ht, const char *key_val, uint32_t key
             // the table.
             e = hti->table + (x & MASK(hti->scale));
         } else {
             // the table.
             e = hti->table + (x & MASK(hti->scale));
         } else {
+            TRACE("h0", "ht_compare_and_set: help copy panic", 0, 0);
             // scan the whole table
             limit = (1 << hti->scale);
             e = hti->table;
             // scan the whole table
             limit = (1 << hti->scale);
             e = hti->table;
index fb4950d647b1c951e050bfdff24560835ad01f3b..2bcce6064fb37498ee4fd1b3b71ac44f8bb631ec 100644 (file)
@@ -140,6 +140,10 @@ static void CuFailInternal(CuTest* tc, const char* file, int line, CuString* str
 
        tc->failed = 1;
        tc->message = string->buffer;
 
        tc->failed = 1;
        tc->message = string->buffer;
+#ifdef ENABLE_TRACE
+    extern void lwt_dump(const char *);
+    lwt_dump(tc->name);
+#endif
        if (tc->jumpBuf != 0) longjmp(*(tc->jumpBuf), 0);
 }
 
        if (tc->jumpBuf != 0) longjmp(*(tc->jumpBuf), 0);
 }
 
index fd7652446706cd55a2a59dab1db106184a017f18..e1afc3479eb9ea1a97b03093e3c7161e44d1a6db 100644 (file)
@@ -9,6 +9,7 @@
 #include "common.h"
 #include "ht.h"
 #include "mem.h"
 #include "common.h"
 #include "ht.h"
 #include "mem.h"
+#include "lwt.h"
 
 #define ASSERT_EQUAL(x, y) CuAssertIntEquals(tc, x, y)
 
 
 #define ASSERT_EQUAL(x, y) CuAssertIntEquals(tc, x, y)
 
@@ -98,17 +99,18 @@ void *simple_worker (void *arg) {
     SYNC_ADD(wd->wait, -1);
     do { } while (*((volatile worker_data_t *)wd)->wait); // wait for all workers to be ready
 
     SYNC_ADD(wd->wait, -1);
     do { } while (*((volatile worker_data_t *)wd)->wait); // wait for all workers to be ready
 
-    int i, j;
-    for (j = 0; j < 10; ++j) {
-        for (i = d; i < iters; i+=2) {
-            char key[8];
+    for (int j = 0; j < 10; ++j) {
+        for (int i = d; i < iters; i+=2) {
+            char key[10];
             sprintf(key, "k%u", i); 
             sprintf(key, "k%u", i); 
-            ASSERT_EQUAL( DOES_NOT_EXIST, ht_add(ht, key, strlen(key)+1, d+1) );
+            TRACE("t0", "test ht_add() iteration (%llu, %llu)", j, i);
+            CuAssertIntEquals_Msg(tc, key, DOES_NOT_EXIST, ht_add(ht, key, strlen(key)+1, d+1) );
         }
         }
-        for (i = d; i < iters; i+=2) {
-            char key[8];
+        for (int i = d; i < iters; i+=2) {
+            char key[10];
             sprintf(key, "k%u", i); 
             sprintf(key, "k%u", i); 
-            ASSERT_EQUAL( d+1, ht_remove(ht, key, strlen(key)+1) );
+            TRACE("t0", "test ht_remove() iteration (%llu, %llu)", j, i);
+            CuAssertIntEquals_Msg(tc, key, d+1, ht_remove(ht, key, strlen(key)+1) );
         }
         rcu_update();
     }
         }
         rcu_update();
     }
@@ -159,7 +161,7 @@ void concurrent_insert (CuTest* tc) {
 int main (void) {
 
     nbd_init();
 int main (void) {
 
     nbd_init();
-    //lwt_set_trace_level("h4");
+    lwt_set_trace_level("h4t9");
 
     // Create and run test suite
        CuString *output = CuStringNew();
 
     // Create and run test suite
        CuString *output = CuStringNew();