- sync wait period with deamon
[oweals/gnunet.git] / src / regex / gnunet-regex-profiler.c
index b0beb0fab278789279e2dd4b81591b9d67c62ee9..83b8ec50f0d36e0222abde11f545f27d3d53fab8 100644 (file)
@@ -36,8 +36,9 @@
 #include "gnunet_dht_service.h"
 #include "gnunet_testbed_service.h"
 
-#define FIND_TIMEOUT GNUNET_TIME_relative_multiply(GNUNET_TIME_UNIT_SECONDS, 90)
-#define SEARCHES_IN_PARALLEL 2
+#define FIND_TIMEOUT \
+        GNUNET_TIME_relative_multiply(GNUNET_TIME_UNIT_SECONDS, 90)
+#define SEARCHES_IN_PARALLEL 100
 
 /**
  * DLL of operations
@@ -140,7 +141,7 @@ struct RegexPeer
   char *policy_file;
 
   /**
-   * Peers search string.
+   * Peer's search string.
    */
   const char *search_str;
 
@@ -301,15 +302,10 @@ static unsigned int linking_factor;
 static unsigned int num_links;
 
 /**
- * Number of times we try overlay connect operations
+ * Number of connect operations that have failed, candidates to retry
  */
 static unsigned int retry_links;
 
-/**
- * Continuous failures during overlay connect operations
- */
-static unsigned int cont_fails;
-
 /**
  * Global testing status
  */
@@ -350,6 +346,11 @@ static unsigned int peer_cnt;
  */
 static unsigned int peers_found;
 
+/**
+ * Index of peer to start next announce/search..
+ */
+static unsigned int next_search;
+
 /**
  * Search task identifier
  */
@@ -363,7 +364,7 @@ static GNUNET_SCHEDULER_TaskIdentifier search_timeout_task;
 /**
  * Search timeout in seconds.
  */
-static struct GNUNET_TIME_Relative search_timeout = { 60000 };
+static struct GNUNET_TIME_Relative search_timeout_time = { 60000 };
 
 /**
  * How long do we wait before starting the search?
@@ -392,6 +393,11 @@ static unsigned int max_path_compression;
  */
 static char * regex_prefix;
 
+/**
+ * What's the maximum regex reannounce period.
+ */
+static struct GNUNET_TIME_Relative reannounce_period_max;
+
 
 /******************************************************************************/
 /******************************  DECLARATIONS  ********************************/
@@ -459,6 +465,16 @@ static void
 do_collect_stats (void *cls, const struct GNUNET_SCHEDULER_TaskContext *tc);
 
 
+/**
+ * Start announcing the next regex in the DHT.
+ *
+ * @param cls Index of the next peer in the peers array.
+ * @param tc TaskContext.
+ */
+static void
+announce_next_regex (void *cls, const struct GNUNET_SCHEDULER_TaskContext *tc);
+
+
 /******************************************************************************/
 /********************************  SHUTDOWN  **********************************/
 /******************************************************************************/
@@ -555,7 +571,7 @@ do_shutdown (void *cls, const struct GNUNET_SCHEDULER_TaskContext *tc)
   if (NULL != cfg)
     GNUNET_CONFIGURATION_destroy (cfg);
 
-  GNUNET_SCHEDULER_shutdown ();        /* Stop scheduler to shutdown testbed run */
+  GNUNET_SCHEDULER_shutdown (); /* Stop scheduler to shutdown testbed run */
 }
 
 
@@ -697,13 +713,13 @@ stats_cb (void *cls,
   {
     peer->stats_op_handle =
       GNUNET_TESTBED_service_connect (NULL,
-                                     peer->peer_handle,
-                                     "statistics",
-                                     &stats_connect_cb,
-                                     peer,
-                                     &stats_ca,
-                                     &stats_da,
-                                     peer);
+                                      peer->peer_handle,
+                                      "statistics",
+                                      &stats_connect_cb,
+                                      peer,
+                                      &stats_ca,
+                                      &stats_da,
+                                      peer);
   }
 }
 
@@ -738,12 +754,12 @@ stats_connect_cb (void *cls,
   peer->stats_handle = ca_result;
 
   if (NULL == GNUNET_STATISTICS_get (peer->stats_handle, NULL, NULL,
-                                    GNUNET_TIME_UNIT_FOREVER_REL,
-                                    &stats_cb,
-                                    &stats_iterator, peer))
+                                     GNUNET_TIME_UNIT_FOREVER_REL,
+                                     &stats_cb,
+                                     &stats_iterator, peer))
   {
     GNUNET_log (GNUNET_ERROR_TYPE_ERROR,
-               "Could not get statistics of peer %u!\n", peer->id);
+                "Could not get statistics of peer %u!\n", peer->id);
   }
 }
 
@@ -764,13 +780,13 @@ do_collect_stats (void *cls, const struct GNUNET_SCHEDULER_TaskContext *tc)
 
   peer->stats_op_handle =
     GNUNET_TESTBED_service_connect (NULL,
-                                   peer->peer_handle,
-                                   "statistics",
-                                   &stats_connect_cb,
-                                   peer,
-                                   &stats_ca,
-                                   &stats_da,
-                                   peer);
+                                    peer->peer_handle,
+                                    "statistics",
+                                    &stats_connect_cb,
+                                    peer,
+                                    &stats_ca,
+                                    &stats_da,
+                                    peer);
 }
 
 
@@ -786,7 +802,7 @@ do_collect_stats (void *cls, const struct GNUNET_SCHEDULER_TaskContext *tc)
  * @param tc TaskContext.
  */
 static void
-find_next_string (void *cls, const struct GNUNET_SCHEDULER_TaskContext *tc);
+find_string (void *cls, const struct GNUNET_SCHEDULER_TaskContext *tc);
 
 
 /**
@@ -827,7 +843,7 @@ regex_found_handler (void *cls,
   {
     GNUNET_SCHEDULER_cancel (peer->timeout);
     peer->timeout = GNUNET_SCHEDULER_NO_TASK;
-    GNUNET_SCHEDULER_add_now (&find_next_string, NULL);
+    GNUNET_SCHEDULER_add_now (&announce_next_regex, NULL);
   }
 
   if (NULL == id)
@@ -836,20 +852,17 @@ regex_found_handler (void *cls,
     GNUNET_log (GNUNET_ERROR_TYPE_WARNING,
                 "String matching timed out for string %s on peer %u (%i/%i)\n",
                 peer->search_str, peer->id, peers_found, num_search_strings);
-
-    printf ("String matching timed out for string %s on peer %u (%i/%i)\n",
-            peer->search_str, peer->id, peers_found, num_search_strings);
-
     peer->search_str_matched = GNUNET_SYSERR;
   }
   else
   {
     prof_time = GNUNET_TIME_absolute_get_duration (peer->prof_start_time);
 
-    printf ("String %s successfully matched on peer %u after %s (%i/%i) (%u||)\n",
-            peer->search_str, peer->id, GNUNET_STRINGS_relative_time_to_string (prof_time, GNUNET_NO),
-            peers_found, num_search_strings, parallel_searches);
-    fflush (stdout);
+    GNUNET_log (GNUNET_ERROR_TYPE_INFO,
+                "String %s found on peer %u after %s (%i/%i) (%u||)\n",
+                peer->search_str, peer->id,
+                GNUNET_STRINGS_relative_time_to_string (prof_time, GNUNET_NO),
+                peers_found, num_search_strings, parallel_searches);
 
     peer->search_str_matched = GNUNET_YES;
 
@@ -883,13 +896,11 @@ regex_found_handler (void *cls,
     GNUNET_log (GNUNET_ERROR_TYPE_INFO,
                 "All strings successfully matched in %s\n",
                 GNUNET_STRINGS_relative_time_to_string (prof_time, GNUNET_NO));
-    printf ("All strings successfully matched.\n");
-    fflush (stdout);
 
     if (GNUNET_SCHEDULER_NO_TASK != search_timeout_task)
       GNUNET_SCHEDULER_cancel (search_timeout_task);
 
-    printf ("Collecting stats and shutting down.\n");
+    GNUNET_log (GNUNET_ERROR_TYPE_INFO, "Collecting stats and shutting down.\n");
     GNUNET_SCHEDULER_add_now (&do_collect_stats, NULL);
   }
 }
@@ -903,47 +914,26 @@ regex_found_handler (void *cls,
  * @param tc the task context
  */
 static void
-do_connect_by_string_timeout (void *cls,
+search_timeout (void *cls,
                               const struct GNUNET_SCHEDULER_TaskContext * tc)
 {
   GNUNET_log (GNUNET_ERROR_TYPE_INFO,
               "Finding matches to all strings did not succeed after %s.\n",
-              GNUNET_STRINGS_relative_time_to_string (search_timeout, GNUNET_NO));
+              GNUNET_STRINGS_relative_time_to_string (search_timeout_time,
+                                                      GNUNET_NO));
   GNUNET_log (GNUNET_ERROR_TYPE_INFO,
               "Found %i of %i strings\n", peers_found, num_search_strings);
 
-  printf ("Search timed out after %s. Collecting stats and shutting down.\n", 
-         GNUNET_STRINGS_relative_time_to_string (search_timeout, GNUNET_NO));
-  fflush (stdout);
+  GNUNET_log (GNUNET_ERROR_TYPE_INFO,
+              "Search timed out after %s."
+              "Collecting stats and shutting down.\n", 
+              GNUNET_STRINGS_relative_time_to_string (search_timeout_time,
+                                                      GNUNET_NO));
 
   GNUNET_SCHEDULER_add_now (&do_collect_stats, NULL);
 }
 
 
-/**
- * Connect by string task that is run to search for a string in the
- * NFA. It first connects to the mesh service and when a connection is
- * established it starts to search for the string.
- *
- * @param cls NULL
- * @param tc the task context
- */
-static void
-do_connect_by_string (void *cls,
-                      const struct GNUNET_SCHEDULER_TaskContext * tc)
-{
-  unsigned int i;
-
-  printf ("Starting string search.\n");
-  fflush (stdout);
-
-  search_timeout_task = GNUNET_SCHEDULER_add_delayed (search_timeout,
-                                                      &do_connect_by_string_timeout, NULL);
-  for (i = 0; i < SEARCHES_IN_PARALLEL; i++)
-    GNUNET_SCHEDULER_add_now (&find_next_string, NULL);
-}
-
-
 /**
  * Search timed out. It might still complete in the future,
  * but we should start another one.
@@ -960,24 +950,27 @@ find_timeout (void *cls, const struct GNUNET_SCHEDULER_TaskContext *tc)
 
   if ((tc->reason & GNUNET_SCHEDULER_REASON_SHUTDOWN) != 0)
     return;
-  GNUNET_SCHEDULER_add_now (&find_next_string, NULL);
+  GNUNET_log (GNUNET_ERROR_TYPE_WARNING,
+              "Searching for string \"%s\" on peer %d timed out. Starting new search.\n",
+              p->search_str,
+              p->id);
+  GNUNET_SCHEDULER_add_now (&announce_next_regex, NULL);
 }
 
 
 /**
- * Start searching for the next string in the DHT.
+ * Start searching for a string in the DHT.
  *
  * @param cls Index of the next peer in the peers array.
  * @param tc TaskContext.
  */
 static void
-find_next_string (void *cls, const struct GNUNET_SCHEDULER_TaskContext *tc)
+find_string (void *cls, const struct GNUNET_SCHEDULER_TaskContext *tc)
 {
   if (0 != (tc->reason & GNUNET_SCHEDULER_REASON_SHUTDOWN) ||
       peer_cnt >= num_search_strings)
     return;
 
-  parallel_searches++;
   peers[peer_cnt].search_str = search_strings[peer_cnt];
   peers[peer_cnt].search_str_matched = GNUNET_NO;
   GNUNET_log (GNUNET_ERROR_TYPE_INFO,
@@ -1016,7 +1009,7 @@ arm_ca (void *cls, const struct GNUNET_CONFIGURATION_Handle *cfg)
 {
   struct RegexPeer *peer = cls;
 
-  peer->arm_handle = GNUNET_ARM_connect (cfg, NULL);
+  peer->arm_handle = GNUNET_ARM_connect (cfg, NULL, NULL);
 
   return peer->arm_handle;
 }
@@ -1037,108 +1030,105 @@ arm_da (void *cls, void *op_result)
 
   if (NULL != peer->arm_handle)
   {
-    GNUNET_ARM_disconnect (peer->arm_handle);
+    GNUNET_ARM_disconnect_and_free (peer->arm_handle);
     peer->arm_handle = NULL;
   }
 }
 
-
 /**
- * Start announcing the next regex in the DHT.
+ * Finish and free the operation used to start the regex daemon.
+ * operation_done calls ARM_disconnect, which cannot happen inside an
+ * ARM callback.
  *
- * @param cls Index of the next peer in the peers array.
- * @param tc TaskContext.
+ * @param cls Closure (Peer info)
+ * @param tc TaskContext
  */
-void
-announce_next_regex (void *cls, const struct GNUNET_SCHEDULER_TaskContext *tc);
+static void
+arm_op_done (void *cls, const struct GNUNET_SCHEDULER_TaskContext *tc)
+{
+  struct RegexPeer *peer = (struct RegexPeer *) cls;
+
+  GNUNET_TESTBED_operation_done (peer->op_handle);
+  peer->op_handle = NULL;
+}
 
 
 /**
- * Callback function invoked when ARM peration is complete: deamon is started.
- *
- * @param cls Closure (RegexPeer).
- * @param result Outcome of the operation.
+ * Callback called when arm has started the daemon we asked for.
+ * 
+ * @param cls           Closure ().
+ * @param arm           Arm handle.
+ * @param rs            Status of the request.
+ * @param service       Service we asked to start (deamon).
+ * @param result        Result of the request.
  */
 static void
-arm_start_cb (void *cls, enum GNUNET_ARM_ProcessStatus result)
+arm_start_cb (void *cls, struct GNUNET_ARM_Handle *arm,
+    enum GNUNET_ARM_RequestStatus rs, const char *service,
+    enum GNUNET_ARM_Result result)
 {
   struct RegexPeer *peer = (struct RegexPeer *) cls;
-  static unsigned int peer_cnt;
-  unsigned int next_p;
 
+  if (rs != GNUNET_ARM_REQUEST_SENT_OK)
+  {
+    GNUNET_log (GNUNET_ERROR_TYPE_WARNING, "ARM request was not sent: %u\n", rs);
+    GNUNET_abort ();
+  }
   switch (result)
   {
+      /**
+       * Asked to start it, but it's already starting.
+       */
+    case GNUNET_ARM_RESULT_IS_STARTING_ALREADY:
+      GNUNET_break (0); /* Shouldn't be starting, however it's not fatal. */
+      /* fallthrough */
+
       /**
        * Service is currently being started (due to client request).
        */
-    case GNUNET_ARM_PROCESS_STARTING:
-      GNUNET_TESTBED_operation_done (peer->op_handle);
-      peer->op_handle = NULL;
+    case GNUNET_ARM_RESULT_STARTING:
+      GNUNET_SCHEDULER_add_now (&arm_op_done, peer);
 
-      if (peer_cnt < (num_peers - 1))
       {
-        next_p = (++peer_cnt % num_peers);
+        long search_peer;
+        unsigned int i;
+        unsigned int me;
+
+        me = peer - peers;
+
+        /* Find a peer to look for a string matching the regex announced */
+        search_peer = GNUNET_CRYPTO_random_u32 (GNUNET_CRYPTO_QUALITY_WEAK,
+                                                num_peers);
+        for (i = 0; peers[search_peer].search_str != NULL; i++)
+        {
+          search_peer = (search_peer + 1) % num_peers;
+          if (i > num_peers)
+            GNUNET_abort (); /* we ran out of peers, must be a bug */
+        }
+        peers[search_peer].search_str = search_strings[me];
         GNUNET_SCHEDULER_add_delayed (GNUNET_TIME_relative_multiply(
-                                        GNUNET_TIME_UNIT_MILLISECONDS,
-                                        400),
-                                      &announce_next_regex,
-                                      (void *) (long) next_p);
+                                        reannounce_period_max,
+                                        2),
+                                      &find_string,
+                                      (void *) search_peer);
       }
-      else
+      if (next_search >= num_peers &&
+          GNUNET_SCHEDULER_NO_TASK == search_timeout_task)
       {
-        printf ("All daemons started. Waiting %s to start string searches\n",
-                GNUNET_STRINGS_relative_time_to_string (search_delay,
-                                                        GNUNET_NO));
-        fflush (stdout);
-        GNUNET_SCHEDULER_add_delayed (search_delay,
-                                      do_connect_by_string, 
-                                      NULL);
+        GNUNET_log (GNUNET_ERROR_TYPE_INFO, "All daemons started.\n");
+        /* FIXME start GLOBAL timeout to abort experiment */
+        search_timeout_task = GNUNET_SCHEDULER_add_delayed (search_timeout_time,
+                                                            &search_timeout,
+                                                            NULL);
       }
       break;
 
-      /**
-       * Service name is unknown to ARM.
-       */
-    case GNUNET_ARM_PROCESS_UNKNOWN:
-      /**
-       * Service is now down (due to client request).
-       */
-    case GNUNET_ARM_PROCESS_DOWN:
-      /**
-       * Service is already running.
-       */
-    case GNUNET_ARM_PROCESS_ALREADY_RUNNING:
-      /**
-       * Service is already being stopped by some other client.
-       */
-    case GNUNET_ARM_PROCESS_ALREADY_STOPPING:
-      /**
-       * Service is already down (no action taken)
-       */
-    case GNUNET_ARM_PROCESS_ALREADY_DOWN: 
-      /**
-       * ARM is currently being shut down (no more process starts)
-       */
-    case GNUNET_ARM_PROCESS_SHUTDOWN:
-      /**
-       * Error in communication with ARM
-       */
-    case GNUNET_ARM_PROCESS_COMMUNICATION_ERROR:
-      /**
-       * Timeout in communication with ARM
-       */
-    case GNUNET_ARM_PROCESS_COMMUNICATION_TIMEOUT:
-      /**
-      * Failure to perform operation
-      */
-    case GNUNET_ARM_PROCESS_FAILURE:
     default:
       GNUNET_log (GNUNET_ERROR_TYPE_WARNING, "ARM returned %d\n", result);
       GNUNET_abort ();
   }
 }
 
-
 /**
  * ARM connect callback. Called when we are connected to the arm service for
  * the peer in 'cls'. If successfull we start the regex deamon to start
@@ -1162,14 +1152,14 @@ arm_connect_cb (void *cls, struct GNUNET_TESTBED_Operation *op,
   }
 
   GNUNET_assert (NULL != peer->arm_handle);
+  GNUNET_log (GNUNET_ERROR_TYPE_ERROR, "[]%p - ()%p\n", peer->op_handle, op);
   GNUNET_assert (peer->op_handle == op);
   GNUNET_assert (peer->arm_handle == ca_result);
 
-  GNUNET_ARM_start_service (ca_result, "regexprofiler",
-                            GNUNET_OS_INHERIT_STD_NONE,
-                            GNUNET_TIME_UNIT_FOREVER_REL,
-                            &arm_start_cb,
-                            peer);
+  GNUNET_ARM_request_service_start (ca_result, "regexprofiler",
+                                    GNUNET_OS_INHERIT_STD_NONE,
+                                    GNUNET_TIME_UNIT_FOREVER_REL,
+                                    arm_start_cb, cls);
 }
 
 
@@ -1183,50 +1173,47 @@ arm_connect_cb (void *cls, struct GNUNET_TESTBED_Operation *op,
 static void
 do_announce (void *cls, const struct GNUNET_SCHEDULER_TaskContext *tc)
 {
-  printf ("Starting announce.\n");
-  fflush (stdout);
+  unsigned int i;
 
-    /* First connect to arm service, then announce. Next
-       announce will be in arm_connect_cb */
-    peers[0].op_handle =
-      GNUNET_TESTBED_service_connect (NULL,
-                                      peers[0].peer_handle,
-                                      "arm",
-                                      &arm_connect_cb,
-                                      &peers[0],
-                                      &arm_ca,
-                                      &arm_da,
-                                      &peers[0]);
+  GNUNET_log (GNUNET_ERROR_TYPE_INFO, "Starting announce.\n");
 
+  for (i = 0; i < SEARCHES_IN_PARALLEL; i++)
+  {
+    GNUNET_log (GNUNET_ERROR_TYPE_INFO,
+                "  scheduling announce %u\n",
+                i);
+    (void) GNUNET_SCHEDULER_add_now (&announce_next_regex, NULL);
+  }
 }
 
 
 /**
  * Start announcing the next regex in the DHT.
  *
- * @param cls Index of the next peer in the peers array.
+ * @param cls Closure (unused).
  * @param tc TaskContext.
  */
-void
+static void
 announce_next_regex (void *cls, const struct GNUNET_SCHEDULER_TaskContext *tc)
 {
-  long next_p = (long) cls;
-
-  if (0 != (tc->reason & GNUNET_SCHEDULER_REASON_SHUTDOWN))
+  if (0 != (tc->reason & GNUNET_SCHEDULER_REASON_SHUTDOWN) ||
+            next_search >= num_peers)
     return;
 
-  printf ("Starting daemon %ld\n", next_p);
-  fflush (stdout);
-
-  peers[next_p].op_handle =
+  /* First connect to arm service, then announce. Next
+   * a nnounce will be in arm_connect_cb */
+  GNUNET_log (GNUNET_ERROR_TYPE_INFO, "Starting daemon %u\n", next_search);
+  peers[next_search].op_handle =
     GNUNET_TESTBED_service_connect (NULL,
-                                    peers[next_p].peer_handle,
+                                    peers[next_search].peer_handle,
                                     "arm",
                                     &arm_connect_cb,
-                                    &peers[next_p],
+                                    &peers[next_search],
                                     &arm_ca,
                                     &arm_da,
-                                    &peers[next_p]);
+                                    &peers[next_search]);
+  next_search++;
+  parallel_searches++;
 }
 
 /**
@@ -1386,8 +1373,9 @@ peer_churn_cb (void *cls, const char *emsg)
   if (++started_peers == num_peers)
   {
     prof_time = GNUNET_TIME_absolute_get_duration (prof_start_time);
-    printf("All peers started successfully in %s\n",
-           GNUNET_STRINGS_relative_time_to_string (prof_time, GNUNET_NO));
+    GNUNET_log (GNUNET_ERROR_TYPE_INFO, 
+                "All peers started successfully in %s\n",
+                GNUNET_STRINGS_relative_time_to_string (prof_time, GNUNET_NO));
     result = GNUNET_OK;
 
     peer_handles = GNUNET_malloc (sizeof (struct GNUNET_TESTBED_Peer *) * num_peers);
@@ -1446,8 +1434,9 @@ peer_create_cb (void *cls, struct GNUNET_TESTBED_Peer *peer, const char *emsg)
   if (++created_peers == num_peers)
   {
     prof_time = GNUNET_TIME_absolute_get_duration (prof_start_time);
-    printf ("All peers created successfully in %s\n",
-            GNUNET_STRINGS_relative_time_to_string (prof_time, GNUNET_NO));
+    GNUNET_log (GNUNET_ERROR_TYPE_INFO,
+                "All peers created successfully in %s\n",
+                GNUNET_STRINGS_relative_time_to_string (prof_time, GNUNET_NO));
     /* Now peers are to be started */
     state = STATE_PEERS_STARTING;
     prof_start_time = GNUNET_TIME_absolute_get ();
@@ -1487,9 +1476,9 @@ policy_filename_cb (void *cls, const char *filename)
 
   peer->policy_file = GNUNET_strdup (filename);
 
-  GNUNET_log (GNUNET_ERROR_TYPE_INFO, "Creating peer %i on host %s for policy file %s\n",
-              peer->id,
-              GNUNET_TESTBED_host_get_hostname (peer->host_handle),
+  GNUNET_log (GNUNET_ERROR_TYPE_INFO,
+              "Creating peer %i on host %s for policy file %s\n",
+              peer->id, GNUNET_TESTBED_host_get_hostname (peer->host_handle),
               filename);
 
   /* Set configuration options specific for this peer
@@ -1497,7 +1486,8 @@ policy_filename_cb (void *cls, const char *filename)
   peer->cfg = GNUNET_CONFIGURATION_dup (cfg);
   GNUNET_CONFIGURATION_set_value_number (peer->cfg, "REGEXPROFILER",
                                          "MAX_PATH_COMPRESSION",
-                                         (unsigned long long)max_path_compression);
+                                         (unsigned long long)
+                                         max_path_compression);
   GNUNET_CONFIGURATION_set_value_string (peer->cfg, "REGEXPROFILER",
                                          "POLICY_FILE", filename);
 
@@ -1540,10 +1530,10 @@ controller_event_cb (void *cls,
         static unsigned int slaves_started;
         unsigned int peer_cnt;
 
-        dll_op = event->details.operation_finished.op_cls;
+        dll_op = event->op_cls;
         GNUNET_CONTAINER_DLL_remove (dll_op_head, dll_op_tail, dll_op);
         GNUNET_free (dll_op);
-        op = event->details.operation_finished.operation;
+        op = event->op;
         if (NULL != event->details.operation_finished.emsg)
         {
           GNUNET_log (GNUNET_ERROR_TYPE_WARNING,
@@ -1623,10 +1613,11 @@ controller_event_cb (void *cls,
      /* Control reaches here when a peer linking operation fails */
      if (NULL != event->details.operation_finished.emsg)
      {
-       GNUNET_log (GNUNET_ERROR_TYPE_INFO,
+       GNUNET_log (GNUNET_ERROR_TYPE_DEBUG,
                    _("An operation has failed while linking\n"));
-       printf ("F%u ", retry_links);
-       printf ("\n%s\n ", event->details.operation_finished.emsg);
+       printf ("F%u/%u(%s)",
+               retry_links + 1, established_links + 1, 
+               event->details.operation_finished.emsg);
        fflush (stdout);
        retry_links++;
      }
@@ -1634,26 +1625,28 @@ controller_event_cb (void *cls,
      /* break; */
    case GNUNET_TESTBED_ET_CONNECT:
    {
-     char output_buffer[512];
+     char output_buffer[1024];
      size_t size;
 
      if (0 == established_links)
-       printf ("Establishing links .");
+       GNUNET_log (GNUNET_ERROR_TYPE_INFO, "Establishing links .");
      else
      {
-       printf (".");
-       fflush (stdout);
+       printf (".");fflush (stdout);
      }
      if (++established_links == num_links)
      {
-       fflush (stdout);
        prof_time = GNUNET_TIME_absolute_get_duration (prof_start_time);
-       printf ("\n%u links established in %s\n",
-               num_links,
-               GNUNET_STRINGS_relative_time_to_string (prof_time, GNUNET_NO));
+       GNUNET_log (GNUNET_ERROR_TYPE_INFO,
+                   "%u links established in %s\n",
+                   num_links,
+                   GNUNET_STRINGS_relative_time_to_string (prof_time,
+                                                           GNUNET_NO));
        prof_time = GNUNET_TIME_relative_divide(prof_time, num_links);
-       printf ("Average of %s per connection\n",
-               GNUNET_STRINGS_relative_time_to_string (prof_time, GNUNET_NO));
+       GNUNET_log (GNUNET_ERROR_TYPE_INFO,
+                   "Average of %s per connection\n",
+                   GNUNET_STRINGS_relative_time_to_string (prof_time,
+                                                           GNUNET_NO));
        result = GNUNET_OK;
        GNUNET_free (peer_handles);
 
@@ -1663,12 +1656,15 @@ controller_event_cb (void *cls,
            GNUNET_snprintf (output_buffer,
                             sizeof (output_buffer),
                             "# of peers: %u\n# of links established: %u\n"
-                            "Time to establish links: %s\nLinking failures: %u\n"
-                            "path compression length: %u\n# of search strings: %u\n",
+                            "Time to establish links: %s\n"
+                            "Linking failures: %u\n"
+                            "path compression length: %u\n"
+                            "# of search strings: %u\n",
                             num_peers,
-                            (established_links - cont_fails),
-                            GNUNET_STRINGS_relative_time_to_string (prof_time, GNUNET_NO),
-                            cont_fails,
+                            (established_links - retry_links),
+                            GNUNET_STRINGS_relative_time_to_string (prof_time,
+                                                                    GNUNET_NO),
+                            retry_links,
                             max_path_compression,
                             num_search_strings);
 
@@ -1676,12 +1672,11 @@ controller_event_cb (void *cls,
            GNUNET_log (GNUNET_ERROR_TYPE_WARNING, "Unable to write to file!\n");
        }
 
-       printf ("\nWaiting %s before starting to announce.\n",
-               GNUNET_STRINGS_relative_time_to_string (search_delay, GNUNET_NO));
-       fflush (stdout);
-
+       GNUNET_log (GNUNET_ERROR_TYPE_INFO,
+                   "\nWaiting %s before starting to announce.\n",
+                   GNUNET_STRINGS_relative_time_to_string (search_delay,
+                                                           GNUNET_NO));
        state = STATE_SEARCH_REGEX;
-
        search_task = GNUNET_SCHEDULER_add_delayed (search_delay,
                                                    &do_announce, NULL);
      }
@@ -1800,7 +1795,7 @@ status_cb (void *cls, const struct GNUNET_CONFIGURATION_Handle *config, int stat
   if (GNUNET_OK != status)
   {
     mc_proc = NULL;
-    printf("Oh, dear!\n");
+    GNUNET_log (GNUNET_ERROR_TYPE_ERROR, "Oh, dear!\n");
     abort_task = GNUNET_SCHEDULER_add_now (&do_abort, (void*) __LINE__);
     return;
   }
@@ -1960,21 +1955,26 @@ run (void *cls, char *const *args, const char *cfgfile,
 
   if (NULL == args[0])
   {
-    fprintf (stderr, _("No hosts-file specified on command line. Exiting.\n"));
+    GNUNET_log (GNUNET_ERROR_TYPE_ERROR,
+                _("No hosts-file specified on command line. Exiting.\n"));
     return;
   }
   if (NULL == args[1])
   {
-    fprintf (stderr, _("No policy directory specified on command line. Exiting.\n"));
+    GNUNET_log (GNUNET_ERROR_TYPE_ERROR,
+                _("No policy directory specified on command line. Exiting.\n"));
     return;
   }
   num_hosts = GNUNET_TESTBED_hosts_load_from_file (args[0], config, &hosts);
   if (0 == num_hosts)
   {
-    fprintf (stderr, _("No hosts loaded. Need at least one host\n"));
+    GNUNET_log (GNUNET_ERROR_TYPE_ERROR,
+                _("No hosts loaded. Need at least one host\n"));
     return;
   }
-  printf (_("Checking whether given hosts can start testbed. Please wait\n"));
+  GNUNET_log (GNUNET_ERROR_TYPE_INFO, 
+              _("Checking whether given hosts can start testbed."
+                "Please wait\n"));
   hc_handles = GNUNET_malloc (sizeof (struct
                                       GNUNET_TESTBED_HostHabitableCheckHandle *) 
                               * num_hosts);
@@ -1998,22 +1998,24 @@ run (void *cls, char *const *args, const char *cfgfile,
   }
   if (num_hosts != nhost)
   {
-    fprintf (stderr, _("Exiting\n"));
+    GNUNET_log (GNUNET_ERROR_TYPE_ERROR, _("Exiting\n"));
     shutdown_task = GNUNET_SCHEDULER_add_now (&do_shutdown, NULL);
     return;
   }
   if (NULL == config)
   {
-    fprintf (stderr, _("No configuration file given. Exiting\n"));
+    GNUNET_log (GNUNET_ERROR_TYPE_ERROR,
+                _("No configuration file given. Exiting\n"));
     shutdown_task = GNUNET_SCHEDULER_add_now (&do_shutdown, NULL);
     return;
   }
 
   if (GNUNET_OK !=
       GNUNET_CONFIGURATION_get_value_string (config, "REGEXPROFILER", "REGEX_PREFIX",
-                                            &regex_prefix))
+                                             &regex_prefix))
   {
-    fprintf (stderr, _("Configuration option (regex_prefix) missing. Exiting\n"));
+    GNUNET_log (GNUNET_ERROR_TYPE_ERROR,
+                _("Configuration option \"regex_prefix\" missing. Exiting\n"));
     shutdown_task = GNUNET_SCHEDULER_add_now (&do_shutdown, NULL);
     return;
   }
@@ -2031,14 +2033,16 @@ run (void *cls, char *const *args, const char *cfgfile,
                               data_filename);
   if (GNUNET_YES != GNUNET_DISK_directory_test (args[1], GNUNET_YES))
   {
-    fprintf (stderr, _("Specified policies directory does not exist. Exiting.\n"));
+    GNUNET_log (GNUNET_ERROR_TYPE_ERROR,
+                _("Specified policies directory does not exist. Exiting.\n"));
     shutdown_task = GNUNET_SCHEDULER_add_now (&do_shutdown, NULL);
     return;
   }
   policy_dir = args[1];
   if (GNUNET_YES != GNUNET_DISK_file_test (args[2]))
   {
-    fprintf (stderr, _("No search strings file given. Exiting.\n"));
+    GNUNET_log (GNUNET_ERROR_TYPE_ERROR,
+                _("No search strings file given. Exiting.\n"));
     shutdown_task = GNUNET_SCHEDULER_add_now (&do_shutdown, NULL);
     return;
   }
@@ -2046,20 +2050,33 @@ run (void *cls, char *const *args, const char *cfgfile,
   if (num_search_strings != nsearchstrs)
   {
     num_search_strings = nsearchstrs;
-    fprintf (stderr, _("Error loading search strings. Given file does not contain enough strings. Exiting.\n"));
+    GNUNET_log (GNUNET_ERROR_TYPE_ERROR,
+                _("Error loading search strings."
+                  "Given file does not contain enough strings. Exiting.\n"));
     shutdown_task = GNUNET_SCHEDULER_add_now (&do_shutdown, NULL);
     return;
   }
   if (0 >= num_search_strings || NULL == search_strings)
   {
-    fprintf (stderr, _("Error loading search strings. Exiting.\n"));
+    GNUNET_log (GNUNET_ERROR_TYPE_ERROR,
+                _("Error loading search strings. Exiting.\n"));
     shutdown_task = GNUNET_SCHEDULER_add_now (&do_shutdown, NULL);
     return;
   }
+  cfg = GNUNET_CONFIGURATION_dup (config);
+  if (GNUNET_OK !=
+      GNUNET_CONFIGURATION_get_value_time (cfg, "REGEXPROFILER",
+                                           "REANNOUNCE_PERIOD_MAX",
+                                           &reannounce_period_max))
+  {
+    GNUNET_log (GNUNET_ERROR_TYPE_ERROR, 
+                "reannounce_period_max not given. Using 10 minutes.\n");
+    reannounce_period_max =
+      GNUNET_TIME_relative_multiply (GNUNET_TIME_UNIT_MINUTES, 10);
+  }
   unsigned int i;
   for (i = 0; i < num_search_strings; i++)
     GNUNET_log (GNUNET_ERROR_TYPE_DEBUG, "search string: %s\n", search_strings[i]);
-  cfg = GNUNET_CONFIGURATION_dup (config);
   abort_task =
       GNUNET_SCHEDULER_add_delayed (GNUNET_TIME_relative_multiply
                                     (GNUNET_TIME_UNIT_SECONDS, 5), &do_abort,
@@ -2086,7 +2103,8 @@ main (int argc, char *const *argv)
       GNUNET_YES, &GNUNET_GETOPT_set_uint, &linking_factor },
     {'t', "matching-timeout", "TIMEOUT",
       gettext_noop ("wait TIMEOUT before considering a string match as failed"),
-      GNUNET_YES, &GNUNET_GETOPT_set_relative_time, &search_timeout },
+      GNUNET_YES, &GNUNET_GETOPT_set_relative_time, &search_timeout_time
+        },
     {'s', "search-delay", "DELAY",
       gettext_noop ("wait DELAY before starting string search"),
       GNUNET_YES, &GNUNET_GETOPT_set_relative_time, &search_delay },