Improve log messages.

[loba.git] / process.cpp

diff --git a/process.cpp b/process.cpp
index 338f20de49438d0e2f62708d529df4ecdafcbe39..ac9ab244dfd65103da9cfd2705f2948ad65372d3 100644 (file)
--- a/process.cpp
+++ b/process.cpp
@@ -65,10 +65,21 @@ process::~process()
 
 int process::run()
 {
 
 int process::run()
 {

+    double next_iter_after_date = 0.0;

     INFO1("Initial load: %g", load);
     VERB0("Starting...");
     comp_iter = lb_iter = 0;
     while (true) {
     INFO1("Initial load: %g", load);
     VERB0("Starting...");
     comp_iter = lb_iter = 0;
     while (true) {

+        if (opt::min_iter_duration) {
+            double now = MSG_get_clock();
+            if (now < next_iter_after_date){
+                double delay = next_iter_after_date - now;
+                DEBUG1("sleeping for %g s", delay);
+                MSG_process_sleep(next_iter_after_date - now);
+            }
+            next_iter_after_date = MSG_get_clock() + opt::min_iter_duration;
+        }
+

         if (load > 0.0) {
             ++comp_iter;
             if (opt::log_rate && comp_iter % opt::log_rate == 0) {
         if (load > 0.0) {
             ++comp_iter;
             if (opt::log_rate && comp_iter % opt::log_rate == 0) {


@@ -95,10 +106,18 @@ int process::run()
             send();
         }
 
             send();
         }
 

-        if (opt::comp_maxiter && comp_iter >= opt::comp_maxiter)
+        if (opt::comp_maxiter && comp_iter >= opt::comp_maxiter) {
+            VERB2("Reached comp_maxiter: %d/%d", comp_iter, opt::comp_maxiter);

             break;
             break;

-        if (opt::lb_maxiter && lb_iter >= opt::lb_maxiter)
+        }
+        if (opt::lb_maxiter && lb_iter >= opt::lb_maxiter) {
+            VERB2("Reached lb_maxiter: %d/%d", lb_iter, opt::lb_maxiter);

             break;
             break;

+        }
+        if (opt::time_limit && MSG_get_clock() >= opt::time_limit) {
+            VERB2("Reached time limit: %g/%g", MSG_get_clock(), opt::time_limit);
+            break;
+        }

 
         // block on receiving unless there is something to compute or
         // to send
 
         // block on receiving unless there is something to compute or
         // to send


@@ -108,22 +127,25 @@ int process::run()
         receive(wait);
 
         // one of our neighbor is finalizing
         receive(wait);
 
         // one of our neighbor is finalizing

-        if (opt::exit_on_close && close_received)
+        if (opt::exit_on_close && close_received) {
+            VERB0("Close received");

             break;
             break;

+        }

 
         // have no load and cannot receive anything
 
         // have no load and cannot receive anything

-        if (load == 0.0 && !may_receive())
+        if (load == 0.0 && !may_receive()) {
+            VERB0("I'm a poor lonesome process, and I have no load...");

             break;
             break;

+        }

 
         // fixme: this check should be implemented with a distributed
         // algorithm, and not a shared global variable!
         // fixme: should this chunk be moved before call to receive() ?
         if (100.0 * total_load_running / total_load_init <=
             opt::load_ratio_threshold) {
 
         // fixme: this check should be implemented with a distributed
         // algorithm, and not a shared global variable!
         // fixme: should this chunk be moved before call to receive() ?
         if (100.0 * total_load_running / total_load_init <=
             opt::load_ratio_threshold) {

-            VERB0("No more load to balance in system, stopping.");
+            VERB0("No more load to balance in system.");

             break;
         }
             break;
         }

-

     }
     VERB0("Going to finalize...");
     finalize();
     }
     VERB0("Going to finalize...");
     finalize();


@@ -135,10 +157,16 @@ int process::run()
      */
 
     VERB0("Done.");
      */
 
     VERB0("Done.");

-    INFO3("Final load after %d iteration%s: %g",
-          comp_iter, ESSE(comp_iter), load);
-    if (opt::bookkeeping)
-        INFO1("Expected load: %g", expected_load);
+    if (opt::bookkeeping) {
+        INFO4("Final load after %d:%d iterations: %g ; expected: %g",
+              comp_iter, lb_iter, load, expected_load);
+    } else {
+        INFO2("Final load after %d iterations: %g",
+              comp_iter, load);
+        if (comp_iter != lb_iter)
+            WARN2("comp_iter (%d) and lb_iter (%d) differ!",
+                  comp_iter, lb_iter);
+    }

     return 0;
 }
 
     return 0;
 }
 


@@ -156,7 +184,7 @@ double process::sum_of_to_send() const
 double process::load_balance(double /*my_load*/)
 {
     if (lb_iter == 1)           // warn only once
 double process::load_balance(double /*my_load*/)
 {
     if (lb_iter == 1)           // warn only once

-        WARN0("process::load_balance is a no-op!");
+        WARN0("process::load_balance() is a no-op!");

     return 0.0;
 }
 
     return 0.0;
 }
 


@@ -227,6 +255,7 @@ void process::send()
                       bind(&process::send1_no_bookkeeping, this, _1));
         prev_load_broadcast = load;
     }
                       bind(&process::send1_no_bookkeeping, this, _1));
         prev_load_broadcast = load;
     }

+    comm.flush(false);

 }
 
 void process::receive(bool wait)
 }
 
 void process::receive(bool wait)


@@ -234,7 +263,7 @@ void process::receive(bool wait)
     message* msg;
     m_host_t from;
 
     message* msg;
     m_host_t from;
 

-    if (may_receive() && comm.recv(msg, from, wait)) {
+    while (may_receive() && comm.recv(msg, from, wait)) {

         switch (msg->get_type()) {
         case message::INFO: {
             neighbor* n = rev_neigh[from];
         switch (msg->get_type()) {
         case message::INFO: {
             neighbor* n = rev_neigh[from];


@@ -261,7 +290,9 @@ void process::receive(bool wait)
             break;
         }
         delete msg;
             break;
         }
         delete msg;

+        wait = false;           // only wait on first recv

     }
     }

+    comm.flush(false);

 }
 
 void process::finalize1(neighbor& nb)
 }
 
 void process::finalize1(neighbor& nb)


@@ -285,8 +316,10 @@ void process::finalize()
 
     DEBUG2("wait for CLOSE from %lu neighbor%s",
            (unsigned long )neigh.size(), ESSE(neigh.size()));
 
     DEBUG2("wait for CLOSE from %lu neighbor%s",
            (unsigned long )neigh.size(), ESSE(neigh.size()));

-    while (may_receive())
+    while (may_receive()) {
+        comm.flush(false);

         receive(true);
         receive(true);

+    }

 
     comm.flush(true);
 }
 
     comm.flush(true);
 }