- simplify start
[oweals/gnunet.git] / src / regex / gnunet-regex-profiler.c
index 41e454bbf689a04391f9a793332888596ae3170b..cc8d5af6b5e6d7f044799778f3b3c6f7e5c5f80d 100644 (file)
 #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 1
+#define FIND_TIMEOUT \
+        GNUNET_TIME_relative_multiply(GNUNET_TIME_UNIT_SECONDS, 90)
+#define ANNOUNCE_TIME \
+        GNUNET_TIME_relative_multiply(GNUNET_TIME_UNIT_MILLISECONDS, 200)
+#define SEARCHES_IN_PARALLEL 100
 
 /**
  * DLL of operations
@@ -345,6 +348,11 @@ static unsigned int peer_cnt;
  */
 static unsigned int peers_found;
 
+/**
+ * Index of peer to start next announce/search..
+ */
+static unsigned int search_index;
+
 /**
  * Search task identifier
  */
@@ -358,7 +366,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?
@@ -454,6 +462,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  **********************************/
 /******************************************************************************/
@@ -550,7 +568,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 */
 }
 
 
@@ -692,13 +710,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);
   }
 }
 
@@ -733,12 +751,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);
   }
 }
 
@@ -759,13 +777,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);
 }
 
 
@@ -781,7 +799,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);
 
 
 /**
@@ -822,7 +840,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)
@@ -831,20 +849,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 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);
-    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;
 
@@ -878,13 +893,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);
   }
 }
@@ -898,47 +911,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.
@@ -955,18 +947,22 @@ 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)
@@ -1011,7 +1007,8 @@ 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_alloc (cfg);
+  GNUNET_ARM_connect (peer->arm_handle, NULL, NULL);
 
   return peer->arm_handle;
 }
@@ -1037,103 +1034,99 @@ arm_da (void *cls, void *op_result)
   }
 }
 
-
 /**
- * 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))
+      if (search_index < (num_peers - 1))
       {
-        next_p = (++peer_cnt % num_peers);
-        GNUNET_SCHEDULER_add_delayed (GNUNET_TIME_relative_multiply(
-                                        GNUNET_TIME_UNIT_MILLISECONDS,
-                                        400),
-                                      &announce_next_regex,
-                                      (void *) (long) next_p);
+        long search_peer;
+        unsigned int i = 0;
+
+        /* 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 run out of peers, must be a bug */
+        }
+        peers[search_peer].search_str = search_strings[search_index];
+        GNUNET_SCHEDULER_add_delayed (ANNOUNCE_TIME,
+                                      &find_string,
+                                      (void *) search_peer);
       }
       else
       {
-        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."
+                    " Waiting %s to start string searches\n",
+                    GNUNET_STRINGS_relative_time_to_string (search_delay,
+                                                            GNUNET_NO));
+        /* 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
@@ -1160,11 +1153,10 @@ arm_connect_cb (void *cls, struct GNUNET_TESTBED_Operation *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);
 }
 
 
@@ -1178,50 +1170,38 @@ 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);
-
-    /* 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 (search_index = 0; search_index < SEARCHES_IN_PARALLEL; search_index++)
+    (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))
     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", search_index);
+  peers[search_index].op_handle =
     GNUNET_TESTBED_service_connect (NULL,
-                                    peers[next_p].peer_handle,
+                                    peers[search_index].peer_handle,
                                     "arm",
                                     &arm_connect_cb,
-                                    &peers[next_p],
+                                    &peers[search_index],
                                     &arm_ca,
                                     &arm_da,
-                                    &peers[next_p]);
+                                    &peers[search_index]);
+  parallel_searches++;
 }
 
 /**
@@ -1381,8 +1361,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);
@@ -1441,8 +1422,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 ();
@@ -1482,9 +1464,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
@@ -1492,7 +1474,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);
 
@@ -1535,10 +1518,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,
@@ -1620,8 +1603,9 @@ controller_event_cb (void *cls,
      {
        GNUNET_log (GNUNET_ERROR_TYPE_DEBUG,
                    _("An operation has failed while linking\n"));
-       printf ("F%u/%u ", retry_links + 1, established_links + 1);
-       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++;
      }
@@ -1633,22 +1617,24 @@ controller_event_cb (void *cls,
      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,
+                   "\n%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);
 
@@ -1658,11 +1644,14 @@ 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 - retry_links),
-                            GNUNET_STRINGS_relative_time_to_string (prof_time, GNUNET_NO),
+                            GNUNET_STRINGS_relative_time_to_string (prof_time,
+                                                                    GNUNET_NO),
                             retry_links,
                             max_path_compression,
                             num_search_strings);
@@ -1671,12 +1660,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);
      }
@@ -1795,7 +1783,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;
   }
@@ -1955,21 +1943,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);
@@ -1993,22 +1986,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;
   }
@@ -2026,14 +2021,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;
   }
@@ -2041,13 +2038,16 @@ 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;
   }
@@ -2081,7 +2081,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 },