-fixes
[oweals/gnunet.git] / src / gns / gnunet-service-gns_resolver.c
index 4674cfd248d37794e41d127bad7e1cd45205cb6f..9959c43d57405e1acb2ed7ef6a95b3b243109c2e 100644 (file)
@@ -38,7 +38,6 @@
 #include "gns.h"
 #include "gnunet-service-gns_resolver.h"
 
-#define DHT_OPERATION_TIMEOUT  GNUNET_TIME_relative_multiply (GNUNET_TIME_UNIT_SECONDS, 3)
 #define DHT_LOOKUP_TIMEOUT DHT_OPERATION_TIMEOUT
 #define DHT_GNS_REPLICATION_LEVEL 5
 #define MAX_DNS_LABEL_LENGTH 63
@@ -64,11 +63,23 @@ static struct GNUNET_CONTAINER_Heap *dht_lookup_heap;
  */
 static unsigned long long max_allowed_background_queries;
 
+/**
+ * Wheather or not to ignore pending records
+ */
+static int ignore_pending_records;
+
 /**
  * Our local zone
  */
 static struct GNUNET_CRYPTO_ShortHashCode local_zone;
 
+/**
+ * a resolution identifier pool variable
+ * FIXME overflow?
+ * This is a non critical identifier useful for debugging
+ */
+static unsigned long long rid = 0;
+
 /**
  * Namestore calls this function if we have record for this name.
  * (or with rd_count=0 to indicate no matches)
@@ -95,22 +106,23 @@ process_pseu_lookup_ns(void* cls,
   if (rd_count > 0)
   {
     GNUNET_log(GNUNET_ERROR_TYPE_DEBUG,
-               "Name %s already taken in NS!\n", name);
+               "GNS_AUTO_PSEU: Name %s already taken in NS!\n", name);
     if (0 == strcmp(gph->name, name))
     {
       GNUNET_log(GNUNET_ERROR_TYPE_DEBUG,
-                 "Intelligent replacement not implemented\n", name);
+                 "GNS_AUTO_PSEU: Intelligent replacement not implemented\n",
+                 name);
       GNUNET_free(gph);
       return;
     }
 
     GNUNET_log(GNUNET_ERROR_TYPE_DEBUG,
-               "Trying delegated name %s\n", gph->name);
+               "GNS_AUTO_PSEU: Trying delegated name %s\n", gph->name);
     memcpy(gph->new_name, gph->name, strlen(gph->name)+1);
     GNUNET_NAMESTORE_lookup_record(namestore_handle,
                                    &gph->zone,
                                    gph->new_name,
-                                   GNUNET_GNS_RECORD_PSEU,
+                                   GNUNET_NAMESTORE_TYPE_ANY,
                                    &process_pseu_lookup_ns,
                                    gph);
     return;
@@ -118,12 +130,15 @@ process_pseu_lookup_ns(void* cls,
 
   /** name is free */
   GNUNET_log(GNUNET_ERROR_TYPE_DEBUG,
-             "Name %s not taken in NS! Adding\n", gph->new_name);
+             "GNS_AUTO_PSEU: Name %s not taken in NS! Adding\n", gph->new_name);
 
   new_pkey.expiration = GNUNET_TIME_absolute_get_forever ();
   new_pkey.data_size = sizeof(struct GNUNET_CRYPTO_ShortHashCode);
   new_pkey.data = &gph->new_zone;
   new_pkey.record_type = GNUNET_GNS_RECORD_PKEY;
+  new_pkey.flags = GNUNET_NAMESTORE_RF_AUTHORITY
+                 | GNUNET_NAMESTORE_RF_PRIVATE
+                 | GNUNET_NAMESTORE_RF_PENDING;
   GNUNET_NAMESTORE_record_create (namestore_handle,
                                   gph->key,
                                   gph->new_name,
@@ -153,7 +168,7 @@ process_pseu_result(struct GetPseuAuthorityHandle* gph, char* name)
   }
 
   GNUNET_log(GNUNET_ERROR_TYPE_DEBUG,
-             "Checking %s for collision in NS\n", gph->new_name);
+             "GNS_AUTO_PSEU: Checking %s for collision in NS\n", gph->new_name);
 
   /**
    * Check for collision
@@ -161,7 +176,7 @@ process_pseu_result(struct GetPseuAuthorityHandle* gph, char* name)
   GNUNET_NAMESTORE_lookup_record(namestore_handle,
                                  &gph->zone,
                                  gph->new_name,
-                                 GNUNET_GNS_RECORD_PSEU,
+                                 GNUNET_NAMESTORE_TYPE_ANY,
                                  &process_pseu_lookup_ns,
                                  gph);
 }
@@ -179,8 +194,9 @@ handle_auth_discovery_timeout(void *cls,
   struct GetPseuAuthorityHandle* gph = (struct GetPseuAuthorityHandle*)cls;
 
   GNUNET_log(GNUNET_ERROR_TYPE_DEBUG,
-             "dht lookup for query PSEU timed out.\n");
+             "GNS_GET_AUTH: dht lookup for query PSEU timed out.\n");
   GNUNET_DHT_get_stop (gph->get_handle);
+  gph->get_handle = NULL;
   process_pseu_result(gph, NULL);
 }
 
@@ -217,11 +233,13 @@ process_auth_discovery_dht_result(void* cls,
   size_t rd_size;
   int i;
 
-  GNUNET_log(GNUNET_ERROR_TYPE_DEBUG, "got dht result (size=%d)\n", size);
+  GNUNET_log(GNUNET_ERROR_TYPE_DEBUG,
+             "GNS_GET_AUTH: got dht result (size=%d)\n", size);
 
   if (data == NULL)
   {
-    GNUNET_log(GNUNET_ERROR_TYPE_ERROR, "got dht result null!\n", size);
+    GNUNET_log(GNUNET_ERROR_TYPE_ERROR,
+               "GNS_GET_AUTH: got dht result null!\n", size);
     GNUNET_break(0);
     GNUNET_free(gph);
     return;
@@ -231,6 +249,7 @@ process_auth_discovery_dht_result(void* cls,
 
   /* stop lookup and timeout task */
   GNUNET_DHT_get_stop (gph->get_handle);
+  gph->get_handle = NULL;
   GNUNET_SCHEDULER_cancel(gph->timeout);
 
   gph->get_handle = NULL;
@@ -250,7 +269,8 @@ process_auth_discovery_dht_result(void* cls,
                                                                num_records,
                                                                rd))
     {
-      GNUNET_log(GNUNET_ERROR_TYPE_ERROR, "Error deserializing data!\n");
+      GNUNET_log(GNUNET_ERROR_TYPE_ERROR,
+                 "GNS_GET_AUTH: Error deserializing data!\n");
       GNUNET_break(0);
       GNUNET_free(gph);
       return;
@@ -268,10 +288,73 @@ process_auth_discovery_dht_result(void* cls,
     }
   }
 
-  GNUNET_log(GNUNET_ERROR_TYPE_DEBUG, "no pseu in dht!\n");
+  GNUNET_log(GNUNET_ERROR_TYPE_DEBUG, "GNS_GET_AUTH: no pseu in dht!\n");
   process_pseu_result(gph, NULL);
 }
 
+static void
+process_auth_discovery_ns_result(void* cls,
+                      const struct GNUNET_CRYPTO_RsaPublicKeyBinaryEncoded *key,
+                      struct GNUNET_TIME_Absolute expiration,
+                      const char *name, unsigned int rd_count,
+                      const struct GNUNET_NAMESTORE_RecordData *rd,
+                      const struct GNUNET_CRYPTO_RsaSignature *signature)
+{
+  uint32_t xquery;
+  struct GNUNET_CRYPTO_ShortHashCode name_hash;
+  GNUNET_HashCode lookup_key;
+  struct GNUNET_CRYPTO_HashAsciiEncoded lookup_key_string;
+  GNUNET_HashCode name_hash_double;
+  GNUNET_HashCode zone_hash_double;
+  int i;
+  struct GetPseuAuthorityHandle* gph = (struct GetPseuAuthorityHandle*)cls;
+  
+  /* no pseu found */
+  if (rd_count == 0)
+  {
+    /**
+     * check dht
+     */
+    GNUNET_CRYPTO_short_hash("+", strlen("+"), &name_hash);
+    GNUNET_CRYPTO_short_hash_double (&name_hash, &name_hash_double);
+    GNUNET_CRYPTO_short_hash_double (&gph->new_zone, &zone_hash_double);
+    GNUNET_CRYPTO_hash_xor(&name_hash_double, &zone_hash_double, &lookup_key);
+    GNUNET_CRYPTO_hash_to_enc (&lookup_key, &lookup_key_string);
+
+    GNUNET_log(GNUNET_ERROR_TYPE_DEBUG,
+               "GNS_AUTO_PSEU: starting dht lookup for %s with key: %s\n",
+               "+", (char*)&lookup_key_string);
+
+    gph->timeout = GNUNET_SCHEDULER_add_delayed(DHT_LOOKUP_TIMEOUT,
+                                         &handle_auth_discovery_timeout, gph);
+
+    xquery = htonl(GNUNET_GNS_RECORD_PSEU);
+    
+    GNUNET_assert(gph->get_handle == NULL);
+    gph->get_handle = GNUNET_DHT_get_start(dht_handle,
+                                           GNUNET_TIME_UNIT_FOREVER_REL,
+                                           GNUNET_BLOCK_TYPE_GNS_NAMERECORD,
+                                           &lookup_key,
+                                           DHT_GNS_REPLICATION_LEVEL,
+                                           GNUNET_DHT_RO_NONE,
+                                           &xquery,
+                                           sizeof(xquery),
+                                           &process_auth_discovery_dht_result,
+                                           gph);
+    return;
+  }
+  for (i=0; i<rd_count; i++)
+  {
+    if ((strcmp(name, "+") == 0) &&
+        (rd[i].record_type == GNUNET_GNS_RECORD_PSEU))
+    {
+      /* found pseu */
+      process_pseu_result(gph, (char*)rd[i].data);
+      return;
+    }
+  }
+}
+
 /**
  * Callback called by namestore for a zone to name
  * result
@@ -299,49 +382,21 @@ process_zone_to_name_discover(void *cls,
   if (rd_len != 0)
   {
     GNUNET_log(GNUNET_ERROR_TYPE_DEBUG,
-               "name for zone in our root %d\n", strlen(name));
+               "GNS_AUTO_PSEU: name for zone in our root %s\n", name);
     GNUNET_free(gph);
   }
   else
   {
-    /**
-     * No name found.
-     * check dht
-     */
-    uint32_t xquery;
-    struct GNUNET_CRYPTO_ShortHashCode name_hash;
-    GNUNET_HashCode lookup_key;
-    struct GNUNET_CRYPTO_HashAsciiEncoded lookup_key_string;
-    GNUNET_HashCode name_hash_double;
-    GNUNET_HashCode zone_hash_double;
-
-    GNUNET_CRYPTO_short_hash("+", strlen("+"), &name_hash);
-    GNUNET_CRYPTO_short_hash_double (&name_hash, &name_hash_double);
-    GNUNET_CRYPTO_short_hash_double (&gph->new_zone, &zone_hash_double);
-    GNUNET_CRYPTO_hash_xor(&name_hash_double, &zone_hash_double, &lookup_key);
-    GNUNET_CRYPTO_hash_to_enc (&lookup_key, &lookup_key_string);
-
-    GNUNET_log(GNUNET_ERROR_TYPE_DEBUG,
-               "starting dht lookup for %s with key: %s\n",
-               "+", (char*)&lookup_key_string);
-
-    //gph->timeout = GNUNET_SCHEDULER_add_delayed(DHT_LOOKUP_TIMEOUT,
-    //                                     &handle_auth_discovery_timeout, gph);
-
-    xquery = htonl(GNUNET_GNS_RECORD_PSEU);
-
-    gph->get_handle = GNUNET_DHT_get_start(dht_handle,
-                                           GNUNET_TIME_UNIT_FOREVER_REL,
-                                           GNUNET_BLOCK_TYPE_GNS_NAMERECORD,
-                                           &lookup_key,
-                                           DHT_GNS_REPLICATION_LEVEL,
-                                           GNUNET_DHT_RO_NONE,
-                                           &xquery,
-                                           sizeof(xquery),
-                                           &process_auth_discovery_dht_result,
-                                           gph);
 
+    GNUNET_NAMESTORE_lookup_record(namestore_handle,
+                                   &gph->new_zone,
+                                   "+",
+                                   GNUNET_GNS_RECORD_PSEU,
+                                   &process_auth_discovery_ns_result,
+                                   gph);
   }
+   
+
 }
 
 
@@ -351,7 +406,7 @@ process_zone_to_name_discover(void *cls,
  * @param name the name given by delegation
  * @param zone the authority
  * @param our_zone our local zone
- * @param the private key of our authority
+ * @param key the private key of our authority
  */
 static void process_discovered_authority(char* name,
                                     struct GNUNET_CRYPTO_ShortHashCode zone,
@@ -361,7 +416,8 @@ static void process_discovered_authority(char* name,
   struct GetPseuAuthorityHandle *gph;
   size_t namelen;
 
-  GNUNET_log(GNUNET_ERROR_TYPE_DEBUG, "New authority %s discovered\n",
+  GNUNET_log(GNUNET_ERROR_TYPE_DEBUG,
+             "GNS_AUTO_PSEU: New authority %s discovered\n",
              name);
 
   gph = GNUNET_malloc(sizeof(struct GetPseuAuthorityHandle));
@@ -386,13 +442,17 @@ static void process_discovered_authority(char* name,
  * @param nh the namestore handle
  * @param dh the dht handle
  * @param lz the local zone's hash
+ * @param max_bg_queries maximum number of parallel background queries in dht
+ * @param ignore_pending ignore records that still require user confirmation
+ *        on lookup
  * @return GNUNET_OK on success
  */
 int
 gns_resolver_init(struct GNUNET_NAMESTORE_Handle *nh,
                   struct GNUNET_DHT_Handle *dh,
                   struct GNUNET_CRYPTO_ShortHashCode lz,
-                  unsigned long long max_bg_queries)
+                  unsigned long long max_bg_queries,
+                  int ignore_pending)
 {
   namestore_handle = nh;
   dht_handle = dh;
@@ -400,6 +460,7 @@ gns_resolver_init(struct GNUNET_NAMESTORE_Handle *nh,
   dht_lookup_heap =
     GNUNET_CONTAINER_heap_create(GNUNET_CONTAINER_HEAP_ORDER_MIN);
   max_allowed_background_queries = max_bg_queries;
+  ignore_pending_records = ignore_pending;
 
   if ((namestore_handle != NULL) && (dht_handle != NULL))
   {
@@ -411,7 +472,7 @@ gns_resolver_init(struct GNUNET_NAMESTORE_Handle *nh,
 /**
  * Cleanup background lookups
  *
- * @param cks closure to iterator
+ * @param cls closure to iterator
  * @param node heap nodes
  * @param element the resolver handle
  * @param cost heap cost
@@ -424,13 +485,21 @@ cleanup_pending_background_queries(void* cls,
                                    GNUNET_CONTAINER_HeapCostType cost)
 {
   struct ResolverHandle *rh = (struct ResolverHandle *)element;
+  ResolverCleanupContinuation cont = cls;
   
   GNUNET_log(GNUNET_ERROR_TYPE_DEBUG,
-             "Terminating background lookup for %s\n",
-             rh->name);
+             "GNS_CLEANUP-%llu: Terminating background lookup for %s\n",
+             rh->id, rh->name);
   GNUNET_DHT_get_stop(rh->get_handle);
+  rh->get_handle = NULL;
   rh->proc(rh->proc_cls, rh, 0, NULL);
 
+  GNUNET_CONTAINER_heap_remove_node(node);
+
+  if (GNUNET_CONTAINER_heap_get_size(dht_lookup_heap) == 0)
+    cont();
+
+
   return GNUNET_YES;
 }
 
@@ -439,14 +508,18 @@ cleanup_pending_background_queries(void* cls,
  * Shutdown resolver
  */
 void
-gns_resolver_cleanup()
+gns_resolver_cleanup(ResolverCleanupContinuation cont)
 {
-  if (0 != GNUNET_CONTAINER_heap_get_size(dht_lookup_heap))
-  {
+  unsigned int s = GNUNET_CONTAINER_heap_get_size(dht_lookup_heap);
+  GNUNET_log(GNUNET_ERROR_TYPE_DEBUG,
+             "GNS_CLEANUP: %d pending background queries to terminate\n", s);
+
+  if (0 != s)
     GNUNET_CONTAINER_heap_iterate (dht_lookup_heap,
                                    &cleanup_pending_background_queries,
-                                   NULL);
-  }
+                                   cont);
+  else
+    cont();
 }
 
 
@@ -490,18 +563,19 @@ on_namestore_record_put_result(void *cls,
 {
   if (GNUNET_NO == success)
   {
-    GNUNET_log(GNUNET_ERROR_TYPE_DEBUG, "records already in namestore\n");
+    GNUNET_log(GNUNET_ERROR_TYPE_DEBUG,
+               "GNS_NS: records already in namestore\n");
     return;
   }
   else if (GNUNET_YES == success)
   {
     GNUNET_log(GNUNET_ERROR_TYPE_DEBUG,
-               "records successfully put in namestore\n");
+               "GNS_NS: records successfully put in namestore\n");
     return;
   }
 
   GNUNET_log(GNUNET_ERROR_TYPE_ERROR,
-             "Error putting records into namestore: %s\n", emsg);
+             "GNS_NS: Error putting records into namestore: %s\n", emsg);
 }
 
 static void
@@ -527,7 +601,8 @@ background_lookup_result_processor(void *cls,
 {
   //We could do sth verbose/more useful here but it doesn't make any difference
   GNUNET_log(GNUNET_ERROR_TYPE_DEBUG,
-             "background dht lookup finished.\n");
+             "GNS_BG: background dht lookup for finished. (%d results)\n",
+             rd_count);
 }
 
 /**
@@ -544,8 +619,8 @@ dht_lookup_timeout(void *cls, const struct GNUNET_SCHEDULER_TaskContext *tc)
   char new_name[MAX_DNS_NAME_LENGTH];
 
   GNUNET_log(GNUNET_ERROR_TYPE_DEBUG,
-             "dht lookup for query %s timed out.\n",
-             rh->name);
+             "GNS_PHASE_REC-%d: dht lookup for query %s (%ds)timed out.\n",
+             rh->id, rh->name, rh->timeout.rel_value);
   /**
    * Start resolution in bg
    */
@@ -555,8 +630,8 @@ dht_lookup_timeout(void *cls, const struct GNUNET_SCHEDULER_TaskContext *tc)
                   rh->name, GNUNET_GNS_TLD);
 
   GNUNET_log(GNUNET_ERROR_TYPE_DEBUG,
-             "Starting background lookup for %s type %d\n",
-             new_name, rlh->record_type);
+             "GNS_PHASE_REC-%d: Starting background lookup for %s type %d\n",
+             rh->id, new_name, rlh->record_type);
 
   gns_resolver_lookup_record(rh->authority,
                              rlh->record_type,
@@ -565,8 +640,10 @@ dht_lookup_timeout(void *cls, const struct GNUNET_SCHEDULER_TaskContext *tc)
                              GNUNET_TIME_UNIT_FOREVER_REL,
                              &background_lookup_result_processor,
                              NULL);
+  rh->timeout_task = GNUNET_SCHEDULER_NO_TASK;
   
   GNUNET_DHT_get_stop (rh->get_handle);
+  rh->get_handle = NULL;
   rh->proc(rh->proc_cls, rh, 0, NULL);
 }
 
@@ -605,20 +682,23 @@ process_record_result_dht(void* cls,
   char* rd_data = (char*)data;
   int i;
   int rd_size;
-  
-  GNUNET_log(GNUNET_ERROR_TYPE_DEBUG, "got dht result (size=%d)\n", size);
+
+  rh = (struct ResolverHandle *)cls;
+  GNUNET_log(GNUNET_ERROR_TYPE_DEBUG,
+             "GNS_PHASE_REC-%d: got dht result (size=%d)\n", rh->id, size);
   
   if (data == NULL)
     return;
 
   //FIXME maybe check expiration here, check block type
   
-  rh = (struct ResolverHandle *)cls;
+  
   rlh = (struct RecordLookupHandle *) rh->proc_cls;
   nrb = (struct GNSNameRecordBlock*)data;
   
   /* stop lookup and timeout task */
   GNUNET_DHT_get_stop (rh->get_handle);
+  rh->get_handle = NULL;
   
   if (rh->dht_heap_node != NULL)
   {
@@ -627,7 +707,10 @@ process_record_result_dht(void* cls,
   }
   
   if (rh->timeout_task != GNUNET_SCHEDULER_NO_TASK)
+  {
     GNUNET_SCHEDULER_cancel(rh->timeout_task);
+    rh->timeout_task = GNUNET_SCHEDULER_NO_TASK;
+  }
 
   rh->get_handle = NULL;
   name = (char*)&nrb[1];
@@ -643,21 +726,25 @@ process_record_result_dht(void* cls,
                                                                num_records,
                                                                rd))
     {
-      GNUNET_log(GNUNET_ERROR_TYPE_ERROR, "Error deserializing data!\n");
+      GNUNET_log(GNUNET_ERROR_TYPE_ERROR,
+                 "GNS_PHASE_REC-%d: Error deserializing data!\n", rh->id);
       return;
     }
 
     for (i=0; i<num_records; i++)
     {
       GNUNET_log(GNUNET_ERROR_TYPE_DEBUG,
-               "Got name: %s (wanted %s)\n", name, rh->name);
+               "GNS_PHASE_REC-%d: Got name: %s (wanted %s)\n",
+               rh->id, name, rh->name);
       GNUNET_log(GNUNET_ERROR_TYPE_DEBUG,
-               "Got type: %d\n",
-               rd[i].record_type);
+               "GNS_PHASE_REC-%d: Got type: %d\n",
+               rh->id, rd[i].record_type);
       GNUNET_log(GNUNET_ERROR_TYPE_DEBUG,
-               "Got data length: %d\n", rd[i].data_size);
+               "GNS_PHASE_REC-%d: Got data length: %d\n",
+               rh->id, rd[i].data_size);
       GNUNET_log(GNUNET_ERROR_TYPE_DEBUG,
-               "Got flag %d\n", rd[i].flags);
+               "GNS_PHASE_REC-%d: Got flag %d\n",
+               rh->id, rd[i].flags);
     
      if ((strcmp(name, rh->name) == 0) &&
          (rd[i].record_type == rlh->record_type))
@@ -718,8 +805,8 @@ resolve_record_dht(struct ResolverHandle *rh)
   GNUNET_CRYPTO_hash_to_enc (&lookup_key, &lookup_key_string);
   
   GNUNET_log(GNUNET_ERROR_TYPE_DEBUG,
-             "starting dht lookup for %s with key: %s\n",
-             rh->name, (char*)&lookup_key_string);
+             "GNS_PHASE_REC-%d: starting dht lookup for %s with key: %s\n",
+             rh->id, rh->name, (char*)&lookup_key_string);
 
   //rh->timeout_task = GNUNET_SCHEDULER_NO_TASK;
   rh->dht_heap_node = NULL;
@@ -733,7 +820,7 @@ resolve_record_dht(struct ResolverHandle *rh)
     {
 
     GNUNET_log(GNUNET_ERROR_TYPE_DEBUG,
-               "Adjusting timeout\n");
+               "GNS_PHASE_REC-%d: Adjusting timeout\n", rh->id);
     /*
      * Set timeout for authority lookup phase to 1/2
      */
@@ -755,7 +842,12 @@ resolve_record_dht(struct ResolverHandle *rh)
     {
       rh_heap_root = GNUNET_CONTAINER_heap_remove_root (dht_lookup_heap);
       GNUNET_DHT_get_stop(rh_heap_root->get_handle);
+      rh_heap_root->get_handle = NULL;
       rh_heap_root->dht_heap_node = NULL;
+      
+      GNUNET_log(GNUNET_ERROR_TYPE_DEBUG,
+           "GNS_PHASE_REC-%d: Replacing oldest background query for %s\n",
+                 rh->id, rh_heap_root->name);
       rh_heap_root->proc(rh_heap_root->proc_cls,
                          rh_heap_root,
                          0,
@@ -767,6 +859,8 @@ resolve_record_dht(struct ResolverHandle *rh)
   }
   
   xquery = htonl(rlh->record_type);
+  
+  GNUNET_assert(rh->get_handle == NULL);
   rh->get_handle = GNUNET_DHT_get_start(dht_handle, 
                        GNUNET_TIME_UNIT_FOREVER_REL,
                        GNUNET_BLOCK_TYPE_GNS_NAMERECORD,
@@ -813,19 +907,18 @@ process_record_result_ns(void* cls,
                      &zone);
   remaining_time = GNUNET_TIME_absolute_get_remaining (expiration);
   
-  if (rh->timeout_task != GNUNET_SCHEDULER_NO_TASK)
-    GNUNET_SCHEDULER_cancel(rh->timeout_task);
+  
 
   rh->status = 0;
   
   if (name != NULL)
   {
-    rh->status |= EXISTS;
+    rh->status |= RSL_RECORD_EXISTS;
   }
   
   if (remaining_time.rel_value == 0)
   {
-    rh->status |= EXPIRED;
+    rh->status |= RSL_RECORD_EXPIRED;
   }
   
   if (rd_count == 0)
@@ -834,11 +927,12 @@ process_record_result_ns(void* cls,
      * Lookup terminated and no results
      */
     GNUNET_log(GNUNET_ERROR_TYPE_DEBUG,
-               "Namestore lookup for %s terminated without results\n", name);
+      "GNS_PHASE_REC-%d: Namestore lookup for %s terminated without results\n",
+         rh->id, name);
 
     GNUNET_log(GNUNET_ERROR_TYPE_DEBUG,
-               "Record %s unknown in namestore\n",
-               rh->name);
+               "GNS_PHASE_REC-%d: Record %s unknown in namestore\n",
+               rh->id, rh->name);
     /**
      * Our zone and no result? Cannot resolve TT
      */
@@ -850,19 +944,30 @@ process_record_result_ns(void* cls,
   {
     
     GNUNET_log(GNUNET_ERROR_TYPE_DEBUG,
-               "Processing additional result %s from namestore\n", name);
+           "GNS_PHASE_REC-%d: Processing additional result %s from namestore\n",
+              rh->id, name);
     int i;
     for (i=0; i<rd_count;i++)
     {
 
       if (rd[i].record_type != rlh->record_type)
         continue;
+
+      if (ignore_pending_records &&
+          (rd[i].flags & GNUNET_NAMESTORE_RF_PENDING))
+      {
+        GNUNET_log(GNUNET_ERROR_TYPE_DEBUG,
+        "GNS_PHASE_REC-%d: Record %s is awaiting user confirmation. Skipping\n",
+        rh->id, name);
+        continue;
+      }
       
       if ((GNUNET_TIME_absolute_get_remaining (rd[i].expiration)).rel_value
           == 0)
       {
         GNUNET_log(GNUNET_ERROR_TYPE_DEBUG,
-                   "This record is expired. Skipping\n");
+                   "GNS_PHASE_REC-%d: This record is expired. Skipping\n",
+                   rh->id);
         continue;
       }
       
@@ -876,14 +981,14 @@ process_record_result_ns(void* cls,
     if (rh->answered == 0)
     {
       GNUNET_log(GNUNET_ERROR_TYPE_DEBUG, 
-                 "No answers found. This is odd!\n");
+                 "GNS_PHASE_REC-%d: No answers found. This is odd!\n", rh->id);
       rh->proc(rh->proc_cls, rh, 0, NULL);
       return;
     }
     
     GNUNET_log(GNUNET_ERROR_TYPE_DEBUG,
-               "Found %d answer(s) to query in %d records!\n",
-               rh->answered, rd_count);
+               "GNS_PHASE_REC-%d: Found %d answer(s) to query in %d records!\n",
+               rh->id, rh->answered, rd_count);
 
     rh->proc(rh->proc_cls, rh, rd_count, rd);
   }
@@ -902,6 +1007,13 @@ resolve_record_ns(struct ResolverHandle *rh)
 {
   struct RecordLookupHandle *rlh = (struct RecordLookupHandle *)rh->proc_cls;
   
+  /* We cancel here as to not include the ns lookup in the timeout */
+  if (rh->timeout_task != GNUNET_SCHEDULER_NO_TASK)
+  {
+    GNUNET_SCHEDULER_cancel(rh->timeout_task);
+    rh->timeout_task = GNUNET_SCHEDULER_NO_TASK;
+  }
+  
   /**
    * Try to resolve this record in our namestore.
    * The name to resolve is now in rh->authority_name
@@ -933,11 +1045,15 @@ dht_authority_lookup_timeout(void *cls,
   char new_name[MAX_DNS_NAME_LENGTH];
 
   GNUNET_log(GNUNET_ERROR_TYPE_DEBUG,
-             "dht lookup for query %s timed out.\n",
-             rh->name);
+         "GNS_PHASE_DELEGATE_DHT-%llu: dht lookup for query %s (%ds)timed out.\n",
+         rh->id, rh->authority_name, rh->timeout.rel_value);
 
-  rh->status |= TIMED_OUT;
+  rh->status |= RSL_TIMED_OUT;
 
+  rh->timeout_task = GNUNET_SCHEDULER_NO_TASK;
+  
+  GNUNET_DHT_get_stop (rh->get_handle);
+  rh->get_handle = NULL;
   
   if (strcmp(rh->name, "") == 0)
   {
@@ -953,14 +1069,16 @@ dht_authority_lookup_timeout(void *cls,
    * Start resolution in bg
    */
   GNUNET_snprintf(new_name, MAX_DNS_NAME_LENGTH,
-                  "%s.%s", rh->name, GNUNET_GNS_TLD);
+                  "%s.%s.%s", rh->name, rh->authority_name, GNUNET_GNS_TLD);
   //strcpy(new_name, rh->name);
   //strcpy(new_name+strlen(new_name), ".");
   //memcpy(new_name+strlen(new_name), GNUNET_GNS_TLD, strlen(GNUNET_GNS_TLD));
   
+  strcpy(rh->name, new_name);
+
   GNUNET_log(GNUNET_ERROR_TYPE_DEBUG,
-             "Starting background query for %s type %d\n",
-             new_name, rlh->record_type);
+        "GNS_PHASE_DELEGATE_DHT-%llu: Starting background query for %s type %d\n",
+        rh->id, rh->name, rlh->record_type);
 
   gns_resolver_lookup_record(rh->authority,
                              rlh->record_type,
@@ -970,22 +1088,30 @@ dht_authority_lookup_timeout(void *cls,
                              &background_lookup_result_processor,
                              NULL);
 
-  GNUNET_log(GNUNET_ERROR_TYPE_DEBUG,
-             "Terminating auth lookup\n");
-
-  GNUNET_DHT_get_stop (rh->get_handle);
-  
-  rh->timeout_task = GNUNET_SCHEDULER_NO_TASK;
-  
-  GNUNET_log(GNUNET_ERROR_TYPE_DEBUG,
-             "Terminating auth lookup\n");
-
   rh->proc(rh->proc_cls, rh, 0, NULL);
 }
 
 /* Prototype */
 static void resolve_delegation_dht(struct ResolverHandle *rh);
 
+/* Prototype */
+static void resolve_delegation_ns(struct ResolverHandle *rh);
+
+
+/**
+ * Namestore resolution for delegation finished. Processing result.
+ *
+ * @param cls the closure
+ * @param rh resolver handle
+ * @param rd_count number of results (always 0)
+ * @param rd record data (always NULL)
+ */
+static void
+handle_delegation_ns(void* cls, struct ResolverHandle *rh,
+                          unsigned int rd_count,
+                          const struct GNUNET_NAMESTORE_RecordData *rd);
+
+
 /**
  * Function called when we get a result from the dht
  * for our query. Recursively tries to resolve authorities
@@ -1022,15 +1148,15 @@ process_delegation_result_dht(void* cls,
   int rd_size;
   struct GNUNET_CRYPTO_ShortHashCode zone, name_hash;
   GNUNET_HashCode zone_hash_double, name_hash_double;
+
+  rh = (struct ResolverHandle *)cls;
   
-  GNUNET_log(GNUNET_ERROR_TYPE_DEBUG, "Got DHT result\n");
+  GNUNET_log(GNUNET_ERROR_TYPE_DEBUG,
+             "GNS_PHASE_DELEGATE_DHT-%llu: Got DHT result\n", rh->id);
 
   if (data == NULL)
     return;
   
-  //FIXME check expiration?
-  
-  rh = (struct ResolverHandle *)cls;
   nrb = (struct GNSNameRecordBlock*)data;
   
   /* stop dht lookup and timeout task */
@@ -1057,29 +1183,37 @@ process_delegation_result_dht(void* cls,
                                                                num_records,
                                                                rd))
     {
-      GNUNET_log(GNUNET_ERROR_TYPE_ERROR, "Error deserializing data!\n");
+      GNUNET_log(GNUNET_ERROR_TYPE_ERROR,
+                 "GNS_PHASE_DELEGATE_DHT-%llu: Error deserializing data!\n",
+                 rh->id);
       return;
     }
 
     GNUNET_log(GNUNET_ERROR_TYPE_DEBUG,
-               "Got name: %s (wanted %s)\n", name, rh->authority_name);
+               "GNS_PHASE_DELEGATE_DHT-%llu: Got name: %s (wanted %s)\n",
+               rh->id, name, rh->authority_name);
     for (i=0; i<num_records; i++)
     {
     
       GNUNET_log(GNUNET_ERROR_TYPE_DEBUG,
-                "Got name: %s (wanted %s)\n", name, rh->authority_name);
+                "GNS_PHASE_DELEGATE_DHT-%llu: Got name: %s (wanted %s)\n",
+                rh->id, name, rh->authority_name);
       GNUNET_log(GNUNET_ERROR_TYPE_DEBUG,
-                 "Got type: %d (wanted %d)\n",
-                 rd[i].record_type, GNUNET_GNS_RECORD_PKEY);
+                 "GNS_PHASE_DELEGATE_DHT-%llu: Got type: %d (wanted %d)\n",
+                 rh->id, rd[i].record_type, GNUNET_GNS_RECORD_PKEY);
       GNUNET_log(GNUNET_ERROR_TYPE_DEBUG,
-                 "Got data length: %d\n", rd[i].data_size);
+                 "GNS_PHASE_DELEGATE_DHT-%llu: Got data length: %d\n",
+                 rh->id, rd[i].data_size);
       GNUNET_log(GNUNET_ERROR_TYPE_DEBUG,
-                 "Got flag %d\n", rd[i].flags);
+                 "GNS_PHASE_DELEGATE_DHT-%llu: Got flag %d\n",
+                 rh->id, rd[i].flags);
 
       if ((strcmp(name, rh->authority_name) == 0) &&
           (rd[i].record_type == GNUNET_GNS_RECORD_PKEY))
       {
-        GNUNET_log(GNUNET_ERROR_TYPE_DEBUG, "Authority found in DHT\n");
+        GNUNET_log(GNUNET_ERROR_TYPE_DEBUG,
+                   "GNS_PHASE_DELEGATE_DHT-%llu: Authority found in DHT\n",
+                   rh->id);
         rh->answered = 1;
         memcpy(&rh->authority, rd[i].data, sizeof(struct GNUNET_CRYPTO_ShortHashCode));
         struct AuthorityChain *auth =
@@ -1129,17 +1263,39 @@ process_delegation_result_dht(void* cls,
      * delegate
      * FIXME in this case. should we ask namestore again?
      */
+    GNUNET_log(GNUNET_ERROR_TYPE_DEBUG,
+      "GNS_PHASE_DELEGATE_DHT-%llu: Answer from DHT for %s. Yet to resolve: %s\n",
+      rh->id, rh->authority_name, rh->name);
     if (strcmp(rh->name, "") == 0)
+    {
       rh->proc(rh->proc_cls, rh, 0, NULL);
+    }
     else
-      resolve_delegation_dht(rh);
+    {
+      rh->proc = &handle_delegation_ns;
+      resolve_delegation_ns(rh);
+    }
     return;
   }
   
   /**
    * No pkey but name exists
+   * promote back
    */
-  GNUNET_log(GNUNET_ERROR_TYPE_DEBUG, "DHT authority lookup found no match!\n");
+  GNUNET_log(GNUNET_ERROR_TYPE_DEBUG,
+             "GNS_PHASE_DELEGATE_DHT-%llu: Adding %s back to %s\n",
+             rh->id, rh->authority_name, rh->name);
+  if (strcmp(rh->name, "") == 0)
+    strcpy(rh->name, rh->authority_name);
+  else
+    GNUNET_snprintf(rh->name, MAX_DNS_NAME_LENGTH, "%s.%s",
+                  rh->name, rh->authority_name); //FIXME ret
+  
+  GNUNET_log(GNUNET_ERROR_TYPE_DEBUG,
+             "GNS_PHASE_DELEGATE_DHT-%llu: %s restored\n", rh->id, rh->name);
+  GNUNET_log(GNUNET_ERROR_TYPE_DEBUG,
+           "GNS_PHASE_DELEGATE_DHT-%llu: DHT authority lookup found no match!\n",
+           rh->id);
   rh->proc(rh->proc_cls, rh, 0, NULL);
 }
 
@@ -1155,12 +1311,12 @@ expand_plus(char** dest, char* src, char* repl)
   unsigned int s_len = strlen(src)+1;
 
   GNUNET_log(GNUNET_ERROR_TYPE_DEBUG,
-             "Got %s to expand with %s\n", src, repl);
+             "GNS_POSTPROCESS: Got %s to expand with %s\n", src, repl);
 
   if (s_len < 3)
   {
     GNUNET_log(GNUNET_ERROR_TYPE_DEBUG,
-               "%s to short\n", src);
+               "GNS_POSTPROCESS: %s to short\n", src);
 
     /* no postprocessing */
     memcpy(*dest, src, s_len+1);
@@ -1170,14 +1326,14 @@ expand_plus(char** dest, char* src, char* repl)
   if (0 == strcmp(src+s_len-3, ".+"))
   {
     GNUNET_log(GNUNET_ERROR_TYPE_DEBUG,
-               "Expanding .+ in %s\n", src);
+               "GNS_POSTPROCESS: Expanding .+ in %s\n", src);
     memset(*dest, 0, s_len+strlen(repl)+strlen(GNUNET_GNS_TLD));
     strcpy(*dest, src);
     pos = *dest+s_len-2;
     strcpy(pos, repl);
     pos += strlen(repl);
     GNUNET_log(GNUNET_ERROR_TYPE_DEBUG,
-               "Expanded to %s\n", *dest);
+               "GNS_POSTPROCESS: Expanded to %s\n", *dest);
   }
   else
   {
@@ -1203,12 +1359,15 @@ finish_lookup(struct ResolverHandle *rh,
   char* pos;
   unsigned int offset;
 
+  if (rh->timeout_task != GNUNET_SCHEDULER_NO_TASK)
+    GNUNET_SCHEDULER_cancel(rh->timeout_task);
+
   if (rd_count > 0)
     memcpy(p_rd, rd, rd_count*sizeof(struct GNUNET_NAMESTORE_RecordData));
 
   for (i = 0; i < rd_count; i++)
   {
-
+    
     if (rd[i].record_type != GNUNET_GNS_RECORD_TYPE_NS &&
         rd[i].record_type != GNUNET_GNS_RECORD_TYPE_CNAME &&
         rd[i].record_type != GNUNET_GNS_RECORD_MX &&
@@ -1225,7 +1384,7 @@ finish_lookup(struct ResolverHandle *rh,
      */
     
     GNUNET_log(GNUNET_ERROR_TYPE_DEBUG,
-               "Postprocessing\n");
+               "GNS_POSTPROCESS: Postprocessing\n");
 
     if (strcmp(rh->name, "+") == 0)
       repl_string = rlh->name;
@@ -1254,8 +1413,8 @@ finish_lookup(struct ResolverHandle *rh,
       expand_plus(&pos, (char*)rd[i].data+offset, repl_string);
       offset += strlen(new_soa_data+offset)+1;
       /* cpy the 4 numbers serial refresh retry and expire */
-      memcpy(new_soa_data+offset, (char*)rd[i].data+offset, sizeof(uint32_t)*4);
-      offset += sizeof(uint32_t)*4;
+      memcpy(new_soa_data+offset, (char*)rd[i].data+offset, sizeof(uint32_t)*5);
+      offset += sizeof(uint32_t)*5;
       p_rd[i].data_size = offset;
       p_rd[i].data = new_soa_data;
     }
@@ -1293,8 +1452,8 @@ handle_record_dht(void* cls, struct ResolverHandle *rh,
   if (rd_count == 0)
   {
     GNUNET_log(GNUNET_ERROR_TYPE_DEBUG,
-               "No records for %s found in DHT. Aborting\n",
-               rh->name);
+               "GNS_PHASE_REC-%d: No records for %s found in DHT. Aborting\n",
+               rh->id, rh->name);
     /* give up, cannot resolve */
     finish_lookup(rh, rlh, 0, NULL);
     free_resolver_handle(rh);
@@ -1303,7 +1462,7 @@ handle_record_dht(void* cls, struct ResolverHandle *rh,
 
   /* results found yay */
   GNUNET_log(GNUNET_ERROR_TYPE_DEBUG,
-             "Record resolved from DHT!");
+             "GNS_PHASE_REC-%d: Record resolved from DHT!", rh->id);
 
   finish_lookup(rh, rlh, rd_count, rd);
   free_resolver_handle(rh);
@@ -1328,12 +1487,25 @@ handle_record_ns(void* cls, struct ResolverHandle *rh,
   rlh = (struct RecordLookupHandle*) cls;
   if (rd_count == 0)
   {
-    GNUNET_log(GNUNET_ERROR_TYPE_DEBUG, "Resolution status: %d!\n", rh->status);
+    GNUNET_log(GNUNET_ERROR_TYPE_DEBUG,
+               "GNS_PHASE_REC-%d: NS returned no records. (status: %d)!\n",
+               rh->id,
+               rh->status);
     
-    /* ns entry expired and not ours. try dht */
-    if (rh->status & (EXPIRED | !EXISTS) &&
+    /**
+     * There are 4 conditions that have to met for us to consult the DHT:
+     * 1. The entry in the DHT is RSL_RECORD_EXPIRED AND
+     * 2. No entry in the NS existed AND
+     * 3. The zone queried is not the local resolver's zone AND
+     * 4. The name that was looked up is '+'
+     *    because if it was any other canonical name we either already queried
+     *    the DHT for the authority in the authority lookup phase (and thus
+     *    would already have an entry in the NS for the record)
+     */
+    if (rh->status & (RSL_RECORD_EXPIRED | !RSL_RECORD_EXISTS) &&
         GNUNET_CRYPTO_short_hash_cmp(&rh->authority_chain_head->zone,
-                                     &local_zone))
+                                     &local_zone) &&
+        (strcmp(rh->name, "+") == 0))
     {
       rh->proc = &handle_record_dht;
       resolve_record_dht(rh);
@@ -1347,7 +1519,7 @@ handle_record_ns(void* cls, struct ResolverHandle *rh,
 
   /* results found yay */
   GNUNET_log(GNUNET_ERROR_TYPE_DEBUG,
-             "Record resolved from namestore!");
+             "GNS_PHASE_REC-%d: Record resolved from namestore!", rh->id);
 
   finish_lookup(rh, rlh, rd_count, rd);
 
@@ -1433,7 +1605,7 @@ is_tld(const char* name, const char* tld)
   offset = strlen(name)-strlen(tld);
   if (strcmp(name+offset, tld) != 0)
   {
-    GNUNET_log(GNUNET_ERROR_TYPE_INFO,
+    GNUNET_log(GNUNET_ERROR_TYPE_DEBUG,
                "%s is not in .%s TLD\n", name, tld);
     return GNUNET_NO;
   }
@@ -1456,21 +1628,22 @@ handle_delegation_dht(void* cls, struct ResolverHandle *rh,
   struct RecordLookupHandle* rlh;
   rlh = (struct RecordLookupHandle*) cls;
   
-  
 
   if (strcmp(rh->name, "") == 0)
   {
     if ((rlh->record_type == GNUNET_GNS_RECORD_PKEY))
     {
       GNUNET_log(GNUNET_ERROR_TYPE_DEBUG,
-                 "Resolved queried PKEY via DHT.\n");
+                 "GNS_PHASE_DELEGATE_DHT-%llu: Resolved queried PKEY via DHT.\n",
+                 rh->id);
       finish_lookup(rh, rlh, rd_count, rd);
       free_resolver_handle(rh);
       return;
     }
     /* We resolved full name for delegation. resolving record */
     GNUNET_log(GNUNET_ERROR_TYPE_DEBUG,
-      "Resolved full name for delegation via DHT. resolving record '' in ns\n");
+     "GNS_PHASE_DELEGATE_DHT-%llu: Resolved full name for delegation via DHT.\n",
+     rh->id);
     strcpy(rh->name, "+\0");
     rh->proc = &handle_record_ns;
     resolve_record_ns(rh);
@@ -1483,15 +1656,17 @@ handle_delegation_dht(void* cls, struct ResolverHandle *rh,
   if (is_canonical(rh->name))
   {
     GNUNET_log(GNUNET_ERROR_TYPE_DEBUG,
-               "Resolving canonical record %s in ns\n", rh->name);
+             "GNS_PHASE_DELEGATE_DHT-%llu: Resolving canonical record %s in ns\n",
+             rh->id,
+             rh->name);
     rh->proc = &handle_record_ns;
     resolve_record_ns(rh);
     return;
   }
   /* give up, cannot resolve */
   GNUNET_log(GNUNET_ERROR_TYPE_DEBUG,
            "Cannot fully resolve delegation for %s via DHT!\n",
            rh->name);
"GNS_PHASE_DELEGATE_DHT-%llu: Cannot fully resolve delegation for %s via DHT!\n",
rh->id, rh->name);
   finish_lookup(rh, rlh, 0, NULL);
   free_resolver_handle(rh);
 }
@@ -1513,6 +1688,7 @@ resolve_delegation_dht(struct ResolverHandle *rh)
   GNUNET_HashCode lookup_key;
   struct ResolverHandle *rh_heap_root;
   
+  pop_tld(rh->name, rh->authority_name); 
   GNUNET_CRYPTO_short_hash(rh->authority_name,
                      strlen(rh->authority_name),
                      &name_hash);
@@ -1539,6 +1715,11 @@ resolve_delegation_dht(struct ResolverHandle *rh)
       rh_heap_root = GNUNET_CONTAINER_heap_remove_root (dht_lookup_heap);
       GNUNET_DHT_get_stop(rh_heap_root->get_handle);
       rh_heap_root->dht_heap_node = NULL;
+      
+      GNUNET_log(GNUNET_ERROR_TYPE_DEBUG,
+        "GNS_PHASE_DELEGATE_DHT-%llu: Replacing oldest background query for %s\n",
+        rh->id, rh_heap_root->authority_name);
+      
       rh_heap_root->proc(rh_heap_root->proc_cls,
                          rh_heap_root,
                          0,
@@ -1550,7 +1731,8 @@ resolve_delegation_dht(struct ResolverHandle *rh)
   }
   
   xquery = htonl(GNUNET_GNS_RECORD_PKEY);
-
+  
+  GNUNET_assert(rh->get_handle == NULL);
   rh->get_handle = GNUNET_DHT_get_start(dht_handle,
                        GNUNET_TIME_UNIT_FOREVER_REL,
                        GNUNET_BLOCK_TYPE_GNS_NAMERECORD,
@@ -1580,20 +1762,27 @@ handle_delegation_ns(void* cls, struct ResolverHandle *rh,
 {
   struct RecordLookupHandle* rlh;
   rlh = (struct RecordLookupHandle*) cls;
+
+  GNUNET_log(GNUNET_ERROR_TYPE_DEBUG,
+             "GNS_PHASE_DELEGATE_NS-%llu: Resolution status: %d.\n",
+             rh->id, rh->status);
   
   if (strcmp(rh->name, "") == 0)
   {
     if ((rlh->record_type == GNUNET_GNS_RECORD_PKEY))
     {
+      GNUNET_assert(rd_count == 1);
       GNUNET_log(GNUNET_ERROR_TYPE_DEBUG,
-                 "Resolved queried PKEY in NS.\n");
+                 "GNS_PHASE_DELEGATE_NS-%llu: Resolved queried PKEY in NS.\n",
+                 rh->id);
       finish_lookup(rh, rlh, rd_count, rd);
       free_resolver_handle(rh);
       return;
     }
     /* We resolved full name for delegation. resolving record */
     GNUNET_log(GNUNET_ERROR_TYPE_DEBUG,
-               "Resolved full name for delegation. resolving record '+'\n");
+              "GNS_PHASE_DELEGATE_NS-%llu: Resolved full name for delegation.\n",
+              rh->id);
     strcpy(rh->name, "+\0");
     rh->proc = &handle_record_ns;
     resolve_record_ns(rh);
@@ -1606,14 +1795,16 @@ handle_delegation_ns(void* cls, struct ResolverHandle *rh,
    * and exists
    * or we are authority
    **/
-  if ((rh->status & (EXISTS | !EXPIRED)) ||
-      !GNUNET_CRYPTO_short_hash_cmp(&rh->authority_chain_head->zone,
-                             &rh->authority_chain_tail->zone))
+  if (((rh->status & RSL_RECORD_EXISTS) && (!(rh->status & RSL_RECORD_EXPIRED)))
+      || !GNUNET_CRYPTO_short_hash_cmp(&rh->authority_chain_head->zone,
+                                       &local_zone))
   {
     if (is_canonical(rh->name))
     {
       GNUNET_log(GNUNET_ERROR_TYPE_DEBUG,
-                 "Resolving canonical record %s\n", rh->name);
+                 "GNS_PHASE_DELEGATE_NS-%llu: Resolving canonical record %s\n",
+                 rh->id,
+                 rh->name);
       rh->proc = &handle_record_ns;
       resolve_record_ns(rh);
     }
@@ -1621,22 +1812,22 @@ handle_delegation_ns(void* cls, struct ResolverHandle *rh,
     {
       /* give up, cannot resolve */
       GNUNET_log(GNUNET_ERROR_TYPE_DEBUG,
-                 "Cannot fully resolve delegation for %s!\n",
-                 rh->name);
-      rlh->proc(rlh->proc_cls, 0, NULL);
+          "GNS_PHASE_DELEGATE_NS-%llu: Cannot fully resolve delegation for %s!\n",
+          rh->id,
+          rh->name);
+      finish_lookup(rh, rlh, rd_count, rd);
+      //rlh->proc(rlh->proc_cls, 0, NULL);
     }
     return;
   }
   
   GNUNET_log(GNUNET_ERROR_TYPE_DEBUG,
-             "Trying to resolve delegation for %s via DHT\n",
-             rh->name);
+      "GNS_PHASE_DELEGATE_NS-%llu: Trying to resolve delegation for %s via DHT\n",
+      rh->id, rh->name);
   rh->proc = &handle_delegation_dht;
   resolve_delegation_dht(rh);
 }
 
-/* Prototype */
-static void resolve_delegation_ns(struct ResolverHandle *rh);
 
 
 /**
@@ -1666,11 +1857,12 @@ process_delegation_result_ns(void* cls,
   struct GNUNET_TIME_Relative remaining_time;
   struct GNUNET_CRYPTO_ShortHashCode zone;
   char new_name[MAX_DNS_NAME_LENGTH];
-  
-  GNUNET_log(GNUNET_ERROR_TYPE_DEBUG, "Got %d records from authority lookup\n",
-             rd_count);
+  rh = (struct ResolverHandle *)cls; 
+  GNUNET_log(GNUNET_ERROR_TYPE_DEBUG,
+             "GNS_PHASE_DELEGATE_NS-%llu: Got %d records from authority lookup\n",
+             rh->id, rd_count);
 
-  rh = (struct ResolverHandle *)cls;
   GNUNET_CRYPTO_short_hash(key,
                      sizeof(struct GNUNET_CRYPTO_RsaPublicKeyBinaryEncoded),
                      &zone);
@@ -1680,12 +1872,18 @@ process_delegation_result_ns(void* cls,
   
   if (name != NULL)
   {
-    rh->status |= EXISTS;
+    GNUNET_log(GNUNET_ERROR_TYPE_DEBUG,
+               "GNS_PHASE_DELEGATE_NS-%llu: Records with name %s exist.\n",
+               rh->id, name);
+    rh->status |= RSL_RECORD_EXISTS;
   }
   
   if (remaining_time.rel_value == 0)
   {
-    rh->status |= EXPIRED;
+    GNUNET_log(GNUNET_ERROR_TYPE_DEBUG,
+               "GNS_PHASE_DELEGATE_NS-%llu: Record set %s expired.\n",
+               rh->id, name);
+    rh->status |= RSL_RECORD_EXPIRED;
   }
   
   /**
@@ -1706,22 +1904,25 @@ process_delegation_result_ns(void* cls,
     {
       /* simply promote back */
       GNUNET_log(GNUNET_ERROR_TYPE_DEBUG,
-                 "Promoting %s back to name\n", rh->authority_name);
+                 "GNS_PHASE_DELEGATE_NS-%llu: Promoting %s back to name\n",
+                 rh->id, rh->authority_name);
       strcpy(rh->name, rh->authority_name);
     }
     else
     {
       /* add back to existing name */
       GNUNET_log(GNUNET_ERROR_TYPE_DEBUG,
-                 "Adding %s back to %s\n",
-                 rh->authority_name, rh->name);
+                 "GNS_PHASE_DELEGATE_NS-%llu: Adding %s back to %s\n",
+                 rh->id, rh->authority_name, rh->name);
       //memset(new_name, 0, strlen(rh->name) + strlen(rh->authority_name) + 2);
-      strcpy(new_name, rh->name);
-      strcpy(new_name+strlen(new_name), ".");
-      strcpy(new_name+strlen(new_name), rh->authority_name);
+      GNUNET_snprintf(new_name, MAX_DNS_NAME_LENGTH, "%s.%s",
+                      rh->name, rh->authority_name);
+      //strcpy(new_name, rh->name);
+      //strcpy(new_name+strlen(new_name), ".");
+      //strcpy(new_name+strlen(new_name), rh->authority_name);
       strcpy(rh->name, new_name);
       GNUNET_log(GNUNET_ERROR_TYPE_DEBUG,
-                 "%s restored\n", rh->name);
+                 "GNS_PHASE_DELEGATE_NS-%llu: %s restored\n", rh->id, rh->name);
     }
     rh->proc(rh->proc_cls, rh, 0, NULL);
     return;
@@ -1738,15 +1939,28 @@ process_delegation_result_ns(void* cls,
   
     if (rd[i].record_type != GNUNET_GNS_RECORD_PKEY)
       continue;
+
+    if (ignore_pending_records &&
+        (rd[i].flags & GNUNET_NAMESTORE_RF_PENDING))
+    {
+      GNUNET_log(GNUNET_ERROR_TYPE_DEBUG,
+      "GNS_PHASE_DELEGATE_NS-%llu: PKEY for %s is pending user confirmation.\n",
+        name,
+        rh->id);
+      continue;
+    }
     
     if ((GNUNET_TIME_absolute_get_remaining (rd[i].expiration)).rel_value
          == 0)
     {
-      GNUNET_log(GNUNET_ERROR_TYPE_DEBUG, "This pkey is expired.\n");
+      GNUNET_log(GNUNET_ERROR_TYPE_DEBUG,
+                 "GNS_PHASE_DELEGATE_NS-%llu: This pkey is expired.\n",
+                 rh->id);
       if (remaining_time.rel_value == 0)
       {
         GNUNET_log(GNUNET_ERROR_TYPE_DEBUG,
-                   "This dht entry is expired.\n");
+                   "GNS_PHASE_DELEGATE_NS-%llu: This dht entry is expired.\n",
+                   rh->id);
         rh->authority_chain_head->fresh = 0;
         rh->proc(rh->proc_cls, rh, 0, NULL);
         return;
@@ -1759,7 +1973,8 @@ process_delegation_result_ns(void* cls,
      * Resolve rest of query with new authority
      */
     GNUNET_assert(rd[i].record_type == GNUNET_GNS_RECORD_PKEY);
-    memcpy(&rh->authority, rd[i].data, sizeof(struct GNUNET_CRYPTO_ShortHashCode));
+    memcpy(&rh->authority, rd[i].data,
+           sizeof(struct GNUNET_CRYPTO_ShortHashCode));
     struct AuthorityChain *auth = GNUNET_malloc(sizeof(struct AuthorityChain));
     auth->zone = rh->authority;
     memset(auth->name, 0, strlen(rh->authority_name)+1);
@@ -1768,12 +1983,17 @@ process_delegation_result_ns(void* cls,
                                  rh->authority_chain_tail,
                                  auth);
     
+    /** try to import pkey if private key available */
+    if (rh->priv_key)
+      process_discovered_authority((char*)name, auth->zone,
+                                   rh->authority_chain_tail->zone,
+                                   rh->priv_key);
     /**
      * We are done with PKEY resolution if name is empty
      * else resolve again with new authority
      */
     if (strcmp(rh->name, "") == 0)
-      rh->proc(rh->proc_cls, rh, 0, NULL);
+      rh->proc(rh->proc_cls, rh, rd_count, rd);
     else
       resolve_delegation_ns(rh);
     return;
@@ -1783,8 +2003,24 @@ process_delegation_result_ns(void* cls,
    * no answers found
    */
   GNUNET_log(GNUNET_ERROR_TYPE_DEBUG,
-             "Authority lookup successful but no PKEY... never get here\n");
-  rh->proc(rh->proc_cls, rh, 0, NULL);
+    "GNS_PHASE_DELEGATE_NS-%llu: Authority lookup and no PKEY...\n", rh->id);
+  /**
+   * If we have found some records for the LAST label
+   * we return the results. Else null.
+   */
+  if (strcmp(rh->name, "") == 0)
+  {
+    /* simply promote back */
+    GNUNET_log(GNUNET_ERROR_TYPE_DEBUG,
+               "GNS_PHASE_DELEGATE_NS-%llu: Promoting %s back to name\n",
+               rh->id, rh->authority_name);
+    strcpy(rh->name, rh->authority_name);
+    rh->proc(rh->proc_cls, rh, rd_count, rd);
+  }
+  else
+  {
+    rh->proc(rh->proc_cls, rh, 0, NULL);
+  }
 }
 
 
@@ -1797,12 +2033,13 @@ static void
 resolve_delegation_ns(struct ResolverHandle *rh)
 {
   GNUNET_log(GNUNET_ERROR_TYPE_DEBUG,
-             "Resolving delegation for %s\n", rh->name);
+             "GNS_PHASE_DELEGATE_NS-%llu: Resolving delegation for %s\n",
+             rh->id, rh->name);
   pop_tld(rh->name, rh->authority_name);
   GNUNET_NAMESTORE_lookup_record(namestore_handle,
                                  &rh->authority,
                                  rh->authority_name,
-                                 GNUNET_GNS_RECORD_PKEY,
+                                 GNUNET_GNS_RECORD_ANY,
                                  &process_delegation_result_ns,
                                  rh);
 
@@ -1833,6 +2070,8 @@ gns_resolver_lookup_record(struct GNUNET_CRYPTO_ShortHashCode zone,
   struct ResolverHandle *rh;
   struct RecordLookupHandle* rlh;
   char string_hash[MAX_DNS_LABEL_LENGTH];
+  char nzkey[MAX_DNS_LABEL_LENGTH];
+  char* nzkey_ptr = nzkey;
 
   GNUNET_log (GNUNET_ERROR_TYPE_DEBUG,
               "Starting resolution for %s (type=%d)!\n",
@@ -1851,14 +2090,18 @@ gns_resolver_lookup_record(struct GNUNET_CRYPTO_ShortHashCode zone,
   rh = GNUNET_malloc(sizeof (struct ResolverHandle));
 
   rh->authority = zone;
+  rh->id = rid++;
   rh->proc_cls = rlh;
   rh->priv_key = key;
   rh->timeout = timeout;
+  rh->get_handle = NULL;
   if (timeout.rel_value != GNUNET_TIME_UNIT_FOREVER_REL.rel_value)
   {
     /*
      * Set timeout for authority lookup phase to 1/2
      */
+    GNUNET_log (GNUNET_ERROR_TYPE_DEBUG,
+                "Timeout for lookup set to %ds\n", rh->timeout.rel_value);
     rh->timeout_task = GNUNET_SCHEDULER_add_delayed(
                                 GNUNET_TIME_relative_divide(timeout, 2),
                                                 &handle_lookup_timeout,
@@ -1899,8 +2142,10 @@ gns_resolver_lookup_record(struct GNUNET_CRYPTO_ShortHashCode zone,
 
       GNUNET_log (GNUNET_ERROR_TYPE_DEBUG,
                   "ZKEY is %s!\n", string_hash);
+      
+      GNUNET_STRINGS_utf8_toupper(string_hash, &nzkey_ptr);
 
-      if (GNUNET_OK != GNUNET_CRYPTO_short_hash_from_string(string_hash,
+      if (GNUNET_OK != GNUNET_CRYPTO_short_hash_from_string(nzkey,
                                                       &rh->authority))
       {
         GNUNET_log (GNUNET_ERROR_TYPE_ERROR,
@@ -2005,7 +2250,7 @@ process_zone_to_name_shorten(void *cls,
     free_resolver_handle(rh);
   }
   else if (GNUNET_CRYPTO_short_hash_cmp(&rh->authority_chain_head->zone,
-                                        &local_zone))
+                                        &local_zone) == 0)
   {
     /* our zone, just append .gnunet */
     answer_len = strlen(rh->name) + strlen(GNUNET_GNS_TLD) + 2;
@@ -2028,14 +2273,15 @@ process_zone_to_name_shorten(void *cls,
      * continue with next authority
      */
     next_authority = rh->authority_chain_head;
-    //                         strlen(next_authority->name) + 2);
-    memset(next_authority_name, 0, strlen(rh->name)+
-                      strlen(next_authority->name) + 2);
-    strcpy(next_authority_name, rh->name);
-    strcpy(next_authority_name+strlen(rh->name)+1, ".");
-    strcpy(next_authority_name+strlen(rh->name)+2, next_authority->name);
-  
+    
+    GNUNET_snprintf(next_authority_name, MAX_DNS_NAME_LENGTH,
+                    "%s.%s", rh->name, next_authority->name);
+    
     strcpy(rh->name, next_authority_name);
+    GNUNET_log(GNUNET_ERROR_TYPE_DEBUG,
+               "No PSEU found for authority %s. Promoting back: %s\n",
+               next_authority->name, rh->name);
+    
     GNUNET_CONTAINER_DLL_remove(rh->authority_chain_head,
                               rh->authority_chain_tail,
                               next_authority);
@@ -2048,6 +2294,26 @@ process_zone_to_name_shorten(void *cls,
   }
 }
 
+/**
+ * DHT resolution for delegation. Processing result.
+ *
+ * @param cls the closure
+ * @param rh resolver handle
+ * @param rd_count number of results
+ * @param rd record data
+ */
+static void
+handle_delegation_dht_bg_shorten(void* cls, struct ResolverHandle *rh,
+                          unsigned int rd_count,
+                          const struct GNUNET_NAMESTORE_RecordData *rd)
+{
+  
+  /* We resolved full name for delegation. resolving record */
+  GNUNET_log(GNUNET_ERROR_TYPE_DEBUG,
+    "GNS_SHORTEN: Resolved up to %s for delegation via DHT in background.\n",
+    rh->name);
+  free_resolver_handle(rh);
+}
 
 /**
  * Process result from namestore delegation lookup
@@ -2067,6 +2333,7 @@ handle_delegation_ns_shorten(void* cls,
   struct NameShortenHandle *nsh;
   char result[MAX_DNS_NAME_LENGTH];
   size_t answer_len;
+  struct ResolverHandle *rh_bg;
 
   nsh = (struct NameShortenHandle *)cls;
   
@@ -2104,32 +2371,147 @@ handle_delegation_ns_shorten(void* cls,
     return;
   }
   
+  /**
+   * we have to this before zone to name for rh might
+   * be freed by then
+   */
+  rh_bg = NULL;
+  if (!is_canonical(rh->name))
+  {
+    rh_bg = GNUNET_malloc(sizeof(struct ResolverHandle));
+    memcpy(rh_bg, rh, sizeof(struct ResolverHandle));
+    rh_bg->id = rid++;
+  }
+
   /* backtrack authorities for names */
   GNUNET_NAMESTORE_zone_to_name (namestore_handle,
                                  &rh->authority_chain_tail->zone, //ours
                                  &rh->authority_chain_head->zone,
                                  &process_zone_to_name_shorten,
                                  rh);
+  
+  if (rh_bg == NULL)
+  {
+    return;
+  }
+
+  /**
+   * If authority resolution is incomplete we can do a background lookup
+   * of the full name so that next time we can (likely) fully or at least
+   * further shorten the name
+   */
+  rh_bg->authority_chain_head = GNUNET_malloc(sizeof(struct AuthorityChain));
+  rh_bg->authority_chain_tail = rh_bg->authority_chain_head;
+  rh_bg->authority_chain_head->zone = rh_bg->authority;
+  
+  rh_bg->proc = &handle_delegation_dht_bg_shorten;
+  rh_bg->proc_cls = NULL;
+  
+  GNUNET_log(GNUNET_ERROR_TYPE_DEBUG,
+             "GNS_SHORTEN: Starting background lookup for %s\n",
+             rh_bg->name);
+
+  resolve_delegation_dht(rh_bg);
+
+}
+
+
+/**
+ * Callback calles by namestore for a zone to name
+ * result
+ *
+ * @param cls the closure
+ * @param zone_key the zone we queried
+ * @param expire the expiration time of the name
+ * @param name the name found or NULL
+ * @param rd_len number of records for the name
+ * @param rd the record data (PKEY) for the name
+ * @param signature the signature for the record data
+ */
+static void
+process_zone_to_name_zkey(void *cls,
+                 const struct GNUNET_CRYPTO_RsaPublicKeyBinaryEncoded *zone_key,
+                 struct GNUNET_TIME_Absolute expire,
+                 const char *name,
+                 unsigned int rd_len,
+                 const struct GNUNET_NAMESTORE_RecordData *rd,
+                 const struct GNUNET_CRYPTO_RsaSignature *signature)
+{
+  struct ResolverHandle *rh = cls;
+  struct NameShortenHandle *nsh = rh->proc_cls;
+  struct GNUNET_CRYPTO_ShortHashAsciiEncoded enc;
+  char new_name[MAX_DNS_NAME_LENGTH];
 
+  /* zkey not in our zone */
+  if (name == NULL)
+  {
+    /**
+     * In this case we have not given this PKEY a name (yet)
+     * It is either just not in our zone or not even cached
+     * Since we do not know at this point we will not try to shorten
+     * because PKEY import will happen if the user follows the zkey
+     * link.
+     */
+    GNUNET_CRYPTO_short_hash_to_enc ((struct GNUNET_CRYPTO_ShortHashCode*)rd,
+                                     &enc);
+    GNUNET_log(GNUNET_ERROR_TYPE_DEBUG,
+               "No name found for zkey %s returning verbatim!\n", enc);
+    if (strcmp(rh->name, "") != 0)
+      GNUNET_snprintf(new_name, MAX_DNS_NAME_LENGTH, "%s.%s.%s",
+                      rh->name, enc, GNUNET_GNS_TLD_ZKEY);
+    else
+      GNUNET_snprintf(new_name, MAX_DNS_NAME_LENGTH, "%s.%s",
+                      enc, GNUNET_GNS_TLD_ZKEY);
+    nsh->proc(nsh->proc_cls, new_name);
+    GNUNET_free(nsh);
+    free_resolver_handle(rh);
+    return;
+  }
+  
+  if (strcmp(rh->name, "") != 0)
+    GNUNET_snprintf(new_name, MAX_DNS_NAME_LENGTH, "%s.%s",
+                    rh->name, name);
+  else
+    strcpy(new_name, name);
+
+  GNUNET_log(GNUNET_ERROR_TYPE_DEBUG,
+             "Continue shorten for %s!\n", new_name);
+
+  strcpy(rh->name, new_name);
+  
+  rh->authority_chain_head = GNUNET_malloc(sizeof(struct AuthorityChain));
+  rh->authority_chain_tail = rh->authority_chain_head;
+  rh->authority_chain_head->zone = rh->authority;
+  
+  
+  /* Start delegation resolution in our namestore */
+  resolve_delegation_ns(rh);
 }
 
+
 /**
  * Shorten api from resolver
  *
  * @param zone the zone to use
  * @param name the name to shorten
+ * @param key optional private key for background lookups and PSEU import
  * @param proc the processor to call with result
- * @param cls closure to pass to proc
+ * @param proc_cls closure to pass to proc
  */
 void
 gns_resolver_shorten_name(struct GNUNET_CRYPTO_ShortHashCode zone,
                           const char* name,
+                          struct GNUNET_CRYPTO_RsaPrivateKey *key,
                           ShortenResultProcessor proc,
-                          void* cls)
+                          void* proc_cls)
 {
   struct ResolverHandle *rh;
   struct NameShortenHandle *nsh;
-  char string_hash[MAX_DNS_NAME_LENGTH]; //FIXME LABEL length when shorthash
+  char string_hash[MAX_DNS_LABEL_LENGTH];
+  struct GNUNET_CRYPTO_ShortHashCode zkey;
+  char nzkey[MAX_DNS_LABEL_LENGTH];
+  char* nzkey_ptr = nzkey;
+
 
   GNUNET_log (GNUNET_ERROR_TYPE_DEBUG,
               "Starting shorten for %s!\n", name);
@@ -2138,18 +2520,22 @@ gns_resolver_shorten_name(struct GNUNET_CRYPTO_ShortHashCode zone,
   {
     GNUNET_log (GNUNET_ERROR_TYPE_DEBUG,
                 "%s is canonical. Returning verbatim\n", name);
-    proc(cls, name);
+    proc(proc_cls, name);
     return;
   }
 
   nsh = GNUNET_malloc(sizeof (struct NameShortenHandle));
-  
 
   nsh->proc = proc;
-  nsh->proc_cls = cls;
+  nsh->proc_cls = proc_cls;
   
   rh = GNUNET_malloc(sizeof (struct ResolverHandle));
   rh->authority = zone;
+  rh->id = rid++;
+  rh->priv_key = key;
+  rh->proc = &handle_delegation_ns_shorten;
+  rh->proc_cls = nsh;
+  rh->id = rid++;
   
   GNUNET_log (GNUNET_ERROR_TYPE_DEBUG,
                 "Checking for TLD...\n");
@@ -2160,6 +2546,7 @@ gns_resolver_shorten_name(struct GNUNET_CRYPTO_ShortHashCode zone,
     /**
      * This is a zkey tld
      * build hash and use as initial authority
+     * FIXME sscanf
      */
     memset(rh->name, 0,
            strlen(name)-strlen(GNUNET_GNS_TLD_ZKEY));
@@ -2169,18 +2556,27 @@ gns_resolver_shorten_name(struct GNUNET_CRYPTO_ShortHashCode zone,
 
     GNUNET_log (GNUNET_ERROR_TYPE_DEBUG,
                 "ZKEY is %s!\n", string_hash);
+    
+    GNUNET_STRINGS_utf8_toupper(string_hash, &nzkey_ptr);
 
-    if (GNUNET_OK != GNUNET_CRYPTO_short_hash_from_string(string_hash,
-                                                          &rh->authority))
+    if (GNUNET_OK != GNUNET_CRYPTO_short_hash_from_string(nzkey,
+                                                          &zkey))
     {
       GNUNET_log (GNUNET_ERROR_TYPE_ERROR,
-                  "Cannot convert ZKEY %s to hash!\n", string_hash);
+                  "Cannot convert ZKEY %s to hash!\n", nzkey);
       GNUNET_free(rh);
       GNUNET_free(nsh);
-      proc(cls, name);
+      proc(proc_cls, name);
       return;
     }
 
+    GNUNET_NAMESTORE_zone_to_name (namestore_handle,
+                                   &zone, //ours
+                                   &zkey,
+                                   &process_zone_to_name_zkey,
+                                   rh);
+    return;
+
   }
   else
   {
@@ -2198,8 +2594,7 @@ gns_resolver_shorten_name(struct GNUNET_CRYPTO_ShortHashCode zone,
   rh->authority_chain_head = GNUNET_malloc(sizeof(struct AuthorityChain));
   rh->authority_chain_tail = rh->authority_chain_head;
   rh->authority_chain_head->zone = zone;
-  rh->proc = &handle_delegation_ns_shorten;
-  rh->proc_cls = nsh;
+  
   
   /* Start delegation resolution in our namestore */
   resolve_delegation_ns(rh);
@@ -2288,13 +2683,13 @@ handle_delegation_result_ns_get_auth(void* cls,
  * @param zone the root zone to look up for
  * @param name the name to lookup up
  * @param proc the processor to call when finished
- * @param cls the closure to pass to the processor
+ * @param proc_cls the closure to pass to the processor
  */
 void
 gns_resolver_get_authority(struct GNUNET_CRYPTO_ShortHashCode zone,
                            const char* name,
                            GetAuthorityResultProcessor proc,
-                           void* cls)
+                           void* proc_cls)
 {
   struct ResolverHandle *rh;
   struct GetNameAuthorityHandle *nah;
@@ -2305,6 +2700,7 @@ gns_resolver_get_authority(struct GNUNET_CRYPTO_ShortHashCode zone,
   nah = GNUNET_malloc(sizeof (struct GetNameAuthorityHandle));
   rh = GNUNET_malloc(sizeof (struct ResolverHandle));
   rh->authority = zone;
+  rh->id = rid++;
   
   if (strcmp(GNUNET_GNS_TLD, name) == 0)
   {
@@ -2329,7 +2725,7 @@ gns_resolver_get_authority(struct GNUNET_CRYPTO_ShortHashCode zone,
   rh->proc_cls = (void*)nah;
 
   nah->proc = proc;
-  nah->proc_cls = cls;
+  nah->proc_cls = proc_cls;
 
   /* Start delegation resolution in our namestore */
   resolve_delegation_ns(rh);