Correct log messages.

[loba.git] / process.cpp

diff --git a/process.cpp b/process.cpp
index 99bd0399e308d0281fb7c31074635aab069ec129..e5ba3cd0fa596d3cefcd56d9f9ba2e2d40897c02 100644 (file)
--- a/process.cpp
+++ b/process.cpp
@@ -1,7 +1,6 @@
 #include <algorithm>
 #include <tr1/functional>
 #include <iterator>
 #include <algorithm>
 #include <tr1/functional>
 #include <iterator>

-#include <numeric>

 #include <stdexcept>
 #include <sstream>
 #include <xbt/log.h>
 #include <stdexcept>
 #include <sstream>
 #include <xbt/log.h>


@@ -11,6 +10,7 @@ XBT_LOG_EXTERNAL_DEFAULT_CATEGORY(proc);
 
 #include "misc.h"
 #include "options.h"
 
 #include "misc.h"
 #include "options.h"

+#include "tracing.h"

 
 #include "process.h"
 
 
 #include "process.h"
 


@@ -18,9 +18,21 @@ double process::total_load_init = 0.0;
 double process::total_load_running = 0.0;
 double process::total_load_exit = 0.0;
 
 double process::total_load_running = 0.0;
 double process::total_load_exit = 0.0;
 

+namespace {
+
+    void sleep_until_date(double& date, double duration = 0.0)
+    {
+        double sleep_duration = date - MSG_get_clock();
+        if (sleep_duration > 0.0)
+            MSG_process_sleep(sleep_duration);
+        date = MSG_get_clock() + duration;
+    }
+
+}
+

 process::process(int argc, char* argv[])
 {
 process::process(int argc, char* argv[])
 {

-    if (argc < 2 || !(std::istringstream(argv[1]) >> load))
+    if (argc < 2 || !(std::istringstream(argv[1]) >> real_load))

         throw std::invalid_argument("bad or missing initial load parameter");
 
     neigh.assign(argv + 2, argv + argc);
         throw std::invalid_argument("bad or missing initial load parameter");
 
     neigh.assign(argv + 2, argv + argc);


@@ -33,15 +45,23 @@ process::process(int argc, char* argv[])
         rev_neigh.insert(std::make_pair(host, ptr));
     }
 
         rev_neigh.insert(std::make_pair(host, ptr));
     }
 

-    prev_load_broadcast = -1;   // force sending of load on first send()
-    expected_load = load;
-    total_load_running += load;
-    total_load_init += load;
+    comp = 0.0;
+
+    prev_load_broadcast = -1;   // force sending of load on first send_all()
+    expected_load = real_load;
+    total_load_running += real_load;
+    total_load_init += real_load;

 
     ctrl_close_pending = data_close_pending = neigh.size();
     close_received = false;
     finalizing = false;
 
 
     ctrl_close_pending = data_close_pending = neigh.size();
     close_received = false;
     finalizing = false;
 

+    comp_iter = lb_iter = 0;
+
+    compute_thread = new_msg_thread("compute",
+                                    std::tr1::bind(&process::compute_loop,
+                                                   this));
+

     e_xbt_log_priority_t logp = xbt_log_priority_verbose;
     if (!LOG_ISENABLED(logp))
         return;
     e_xbt_log_priority_t logp = xbt_log_priority_verbose;
     if (!LOG_ISENABLED(logp))
         return;


@@ -54,268 +74,186 @@ process::process(int argc, char* argv[])
                        std::tr1::mem_fn(&neighbor::get_name));
         oss << neigh.back().get_name();
     }
                        std::tr1::mem_fn(&neighbor::get_name));
         oss << neigh.back().get_name();
     }

-    LOG1(logp, "Got %s.", oss.str().c_str());
+    XBT_LOG(logp, "Got %s.", oss.str().c_str());

     print_loads(false, logp);
 }
 
 process::~process()
 {
     print_loads(false, logp);
 }
 
 process::~process()
 {

-    total_load_exit += load;
+    delete compute_thread;
+    total_load_exit += real_load;
+    if (opt::bookkeeping) {
+        XBT_INFO("Final load after %d:%d iterations: %g ; expected: %g",
+                 lb_iter, comp_iter, real_load, expected_load);
+    } else {
+        XBT_INFO("Final load after %d:%d iterations: %g",
+                 lb_iter, comp_iter, real_load);
+    }
+    XBT_VERB("Total computation for this process: %g", comp);

 }
 
 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) {
-        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;
-        }
+    XBT_INFO("Initial load: %g", real_load);
+    XBT_VERB("Starting...");
+    compute_thread->start();
+    load_balance_loop();
+    compute_thread->wait();
+    XBT_VERB("Done.");
+    return 0;
+}

 
 

-        if (load > 0.0) {
-            ++comp_iter;
-            if (opt::log_rate && comp_iter % opt::log_rate == 0) {
-                if (opt::bookkeeping)
-                    INFO4("(%u:%u) current load: %g ; expected: %g",
-                          comp_iter, lb_iter, load, expected_load);
-                else
-                    INFO2("(%u) current load: %g",
-                          comp_iter, load);
-            }
+void process::load_balance_loop()
+{
+    using std::tr1::bind;
+    using std::tr1::placeholders::_1;
+
+    double next_iter_after_date = MSG_get_clock() + opt::min_lb_iter_duration;
+    while (still_running()) {
+        ++lb_iter;

 
 

+        if (opt::log_rate && lb_iter % opt::log_rate == 0) {

             if (opt::bookkeeping)
             if (opt::bookkeeping)

-                expected_load -= load_balance(expected_load);
+                XBT_INFO("(%u:%u) current load: %g ; expected: %g",
+                         lb_iter, comp_iter, real_load, expected_load);

             else
             else

-                load -= load_balance(load);
-
-            print_loads(true, xbt_log_priority_debug);
-
-            send();
-            compute();
-
-        } else {
-            // send load information, and load when bookkeeping
-            send();
+                XBT_INFO("(%u:%u) current load: %g",
+                         lb_iter, comp_iter, real_load);

         }
 
         }
 

-        if (opt::comp_maxiter && comp_iter >= opt::comp_maxiter)
-            break;
-        if (opt::lb_maxiter && lb_iter >= opt::lb_maxiter)
-            break;
-        if (opt::time_limit && MSG_get_clock() >= opt::time_limit) {
-            VERB2("Reached time limit: %g/%g", MSG_get_clock(), opt::time_limit);
-            break;
-        }
+        if (get_load() > 0.0)
+            load_balance();

 
 

-        // block on receiving unless there is something to compute or
-        // to send
-        bool wait = (load == 0 &&
-                     ((opt::bookkeeping ? expected_load : load)
-                      == prev_load_broadcast));
-        receive(wait);
+        print_loads(true, xbt_log_priority_debug);

 
 

-        // one of our neighbor is finalizing
-        if (opt::exit_on_close && close_received)
-            break;
+        // send
+        std::for_each(neigh.begin(), neigh.end(),
+                      bind(&process::ctrl_send, this, _1));

 
 

-        // have no load and cannot receive anything
-        if (load == 0.0 && !may_receive())
-            break;
+        sleep_until_date(next_iter_after_date, opt::min_lb_iter_duration);
+        ctrl_receive(0.0);

 
 

-        // 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.");
-            break;
-        }
+        comm.ctrl_flush(false);
+    }

 
 

+    XBT_VERB("Going to finalize for %s...", __func__);
+    XBT_DEBUG("send CTRL_CLOSE to %zu neighbor%s",
+              neigh.size(), ESSE(neigh.size()));
+    std::for_each(neigh.begin(), neigh.end(),
+                  bind(&process::ctrl_close, this, _1));
+    while (ctrl_close_pending) {
+        comm.ctrl_flush(false);
+        XBT_DEBUG("waiting for %d CTRL CLOSE", ctrl_close_pending);
+        ctrl_receive(-1.0);

     }
     }

-    VERB0("Going to finalize...");
-    finalize();
-
-    /* Open Questions :
-     * - definition of load on heterogeneous hosts ?
-     * - how to detect convergence ?
-     * - how to manage link failures ?
-     */
-
-    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);
-    return 0;
+    comm.ctrl_flush(true);

 }
 
 }
 

-double process::sum_of_to_send() const
+void process::compute_loop()

 {
     using std::tr1::bind;
     using std::tr1::placeholders::_1;
 {
     using std::tr1::bind;
     using std::tr1::placeholders::_1;

-    using std::tr1::placeholders::_2;

 
 

-    return std::accumulate(neigh.begin(), neigh.end(), 0.0,
-                           bind(std::plus<double>(),
-                                _1, bind(&neighbor::get_to_send, _2)));
-}
+    double next_iter_after_date = MSG_get_clock() + opt::min_comp_iter_duration;
+    while (still_running()) {
+        // receive
+        if (real_load > 0.0)
+            data_receive(0.0);
+        else
+            data_receive(opt::min_comp_iter_duration);

 
 

-double process::load_balance(double /*my_load*/)
-{
-    if (lb_iter == 1)           // warn only once
-        WARN0("process::load_balance() is a no-op!");
-    return 0.0;
-}
+        comm.data_flush(false);

 
 

-void process::compute()
-{
-    if (load > 0.0) {
-        double duration = opt::comp_cost(load);
-        m_task_t task = MSG_task_create("computation", duration, 0.0, NULL);
-        DEBUG2("compute %g flop%s", duration, ESSE(duration));
+        if (real_load == 0.0)
+            continue;
+
+        // send
+        std::for_each(neigh.begin(), neigh.end(),
+                      bind(&process::data_send, this, _1));
+
+        // compute
+        ++comp_iter;
+        double flops = opt::comp_cost(real_load);
+        m_task_t task = MSG_task_create("computation", flops, 0.0, NULL);
+        TRACE_msg_set_task_category(task, TRACE_CAT_COMP);
+        XBT_DEBUG("compute %g flop%s", flops, ESSE(flops));

         MSG_task_execute(task);
         MSG_task_execute(task);

+        comp += flops;

         MSG_task_destroy(task);
         MSG_task_destroy(task);

-    } else {
-        DEBUG0("nothing to compute !");
-    }
-}

 
 

-void process::send1_no_bookkeeping(neighbor& nb)
-{
-    if (load != prev_load_broadcast)
-        comm.send(nb.get_ctrl_mbox(), new message(message::INFO, load));
-    double load_to_send = nb.get_to_send();
-    if (load_to_send > 0.0) {
-        comm.send(nb.get_data_mbox(), new message(message::LOAD, load_to_send));
-        nb.set_to_send(0.0);
+        sleep_until_date(next_iter_after_date, opt::min_comp_iter_duration);

     }
     }

-}

 
 

-void process::send1_bookkeeping(neighbor& nb)
-{
-    if (expected_load != prev_load_broadcast)
-        comm.send(nb.get_ctrl_mbox(),
-                  new message(message::INFO, expected_load));
-    double load_to_send;
-    double new_debt;
-    double debt_to_send = nb.get_to_send();
-    if (debt_to_send > 0.0) {
-        comm.send(nb.get_ctrl_mbox(),
-                  new message(message::CREDIT, debt_to_send));
-        nb.set_to_send(0.0);
-        new_debt = nb.get_debt() + debt_to_send;
-    } else {
-        new_debt = nb.get_debt();
-    }
-    if (load <= new_debt) {
-        load_to_send = load;
-        nb.set_debt(new_debt - load_to_send);
-        load = 0.0;
-    } else {
-        load_to_send = new_debt;
-        nb.set_debt(0.0);
-        load -= load_to_send;
+    XBT_VERB("Going to finalize for %s...", __func__);
+    XBT_DEBUG("send DATA_CLOSE to %zu neighbor%s",
+              neigh.size(), ESSE(neigh.size()));
+    std::for_each(neigh.begin(), neigh.end(),
+                  bind(&process::data_close, this, _1));
+    while (data_close_pending) {
+        comm.data_flush(false);
+        XBT_DEBUG("waiting for %d DATA CLOSE", data_close_pending);
+        data_receive(-1.0);

     }
     }

-    if (load_to_send > 0.0)
-        comm.send(nb.get_data_mbox(), new message(message::LOAD, load_to_send));
+    comm.data_flush(true);

 }
 
 }
 

-void process::send()
+bool process::still_running()

 {
 {

-    using std::tr1::bind;
-    using std::tr1::placeholders::_1;
+    static bool last_status = true;

 
 

-    if (opt::bookkeeping) {
-        std::for_each(neigh.begin(), neigh.end(),
-                      bind(&process::send1_bookkeeping, this, _1));
-        prev_load_broadcast = expected_load;
-    } else {
-        std::for_each(neigh.begin(), neigh.end(),
-                      bind(&process::send1_no_bookkeeping, this, _1));
-        prev_load_broadcast = load;
-    }
-    comm.flush(false);
-}
+    if (!last_status) {
+        /* nop */

 
 

-void process::receive(bool wait)
-{
-    message* msg;
-    m_host_t from;
+    } else if (opt::time_limit && MSG_get_clock() >= opt::time_limit) {
+        XBT_VERB("Reached time limit: %g/%g", MSG_get_clock(), opt::time_limit);
+        last_status = false;

 
 

-    while (may_receive() && comm.recv(msg, from, wait)) {
-        switch (msg->get_type()) {
-        case message::INFO: {
-            neighbor* n = rev_neigh[from];
-            n->set_load(msg->get_amount());
-            break;
-        }
-        case message::CREDIT:
-            expected_load += msg->get_amount();
-            break;
-        case message::LOAD: {
-            double ld = msg->get_amount();
-            load += ld;
-            if (finalizing)
-                total_load_running -= ld;
-            break;
-        }
-        case message::CTRL_CLOSE:
-            ctrl_close_pending--;
-            close_received = true;
-            break;
-        case message::DATA_CLOSE:
-            data_close_pending--;
-            close_received = true;
-            break;
-        }
-        delete msg;
-        wait = false;           // only wait on first recv
+    } else if (opt::lb_maxiter && lb_iter >= opt::lb_maxiter) {
+        XBT_VERB("Reached lb_maxiter: %d/%d", lb_iter, opt::lb_maxiter);
+        last_status = false;
+
+    } else if (opt::comp_maxiter && comp_iter >= opt::comp_maxiter) {
+        XBT_VERB("Reached comp_maxiter: %d/%d", comp_iter, opt::comp_maxiter);
+        last_status = false;
+
+    } else if (opt::exit_on_close && close_received) {
+        XBT_VERB("Close received");
+        last_status = false;
+
+    } else if (real_load == 0.0 && !data_close_pending) {
+        XBT_VERB("I'm a poor lonesome process, and I have no load...");
+        last_status = false;
+
+    } else 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() ?
+        XBT_VERB("No more load to balance in system.");
+        last_status = false;

     }
     }

-    comm.flush(false);
+
+    return last_status;

 }
 
 }
 

-void process::finalize1(neighbor& nb)
+void process::load_balance()

 {
 {

-    comm.send(nb.get_ctrl_mbox(), new message(message::CTRL_CLOSE, 0.0));
-    comm.send(nb.get_data_mbox(), new message(message::DATA_CLOSE, 0.0));
+    if (lb_iter == 1)           // warn only once
+        XBT_WARN("process::load_balance() is a no-op!");

 }
 
 }
 

-void process::finalize()
+void process::send(neighbor& nb, double amount)

 {
 {

-    using std::tr1::bind;
-    using std::tr1::placeholders::_1;
-
-    finalizing = true;
-    total_load_running -= load;
-
-    DEBUG2("send CLOSE to %lu neighbor%s",
-           (unsigned long )neigh.size(), ESSE(neigh.size()));
-    std::for_each(neigh.begin(), neigh.end(),
-                  bind(&process::finalize1, this, _1));
-
-    DEBUG2("wait for CLOSE from %lu neighbor%s",
-           (unsigned long )neigh.size(), ESSE(neigh.size()));
-    while (may_receive()) {
-        comm.flush(false);
-        receive(true);
-    }
-
-    comm.flush(true);
+    set_load(get_load() - amount);
+    nb.set_to_send(nb.get_to_send() + amount);
+    nb.set_load(nb.get_load() + amount);

 }
 
 #define print_loads_generic(vec, verbose, logp, cat)                    \
     if (_XBT_LOG_ISENABLEDV((*cat), logp)) {                            \
         using std::tr1::bind;                                           \
         using std::tr1::placeholders::_1;                               \
 }
 
 #define print_loads_generic(vec, verbose, logp, cat)                    \
     if (_XBT_LOG_ISENABLEDV((*cat), logp)) {                            \
         using std::tr1::bind;                                           \
         using std::tr1::placeholders::_1;                               \

-        XCLOG0(cat, logp, "Neighbor loads:");                           \
+        XBT_XCLOG(cat, logp, "Neighbor loads:");                        \

         std::for_each(vec.begin(), vec.end(),                           \
                       bind(&neighbor::print, _1, verbose, logp, cat));  \
     } else ((void)0)
         std::for_each(vec.begin(), vec.end(),                           \
                       bind(&neighbor::print, _1, verbose, logp, cat));  \
     } else ((void)0)


@@ -336,6 +274,109 @@ void process::print_loads_p(bool verbose,
 
 #undef print_loads_generic
 
 
 #undef print_loads_generic
 

+void process::ctrl_send(neighbor& nb)
+{
+    double info_to_send = get_load();
+    if (info_to_send != prev_load_broadcast)
+        comm.ctrl_send(nb.get_ctrl_mbox(),
+                       new message(message::INFO, info_to_send));
+    if (opt::bookkeeping) {
+        double debt_to_send = nb.get_to_send();
+        if (debt_to_send > 0.0) {
+            nb.set_to_send(0.0);
+            nb.set_debt(nb.get_debt() + debt_to_send);
+            comm.ctrl_send(nb.get_ctrl_mbox(),
+                           new message(message::CREDIT, debt_to_send));
+        }
+    }
+}
+
+void process::data_send(neighbor& nb)
+{
+    double load_to_send;
+    if (opt::bookkeeping) {
+        if (real_load <= nb.get_debt()) {
+            load_to_send = real_load;
+            nb.set_debt(nb.get_debt() - load_to_send);
+            real_load = 0.0;
+        } else {
+            load_to_send = nb.get_debt();
+            nb.set_debt(0.0);
+            real_load -= load_to_send;
+        }
+    } else {
+        load_to_send = nb.get_to_send();
+        nb.set_to_send(0.0);
+    }
+    if (load_to_send > 0.0)
+        comm.data_send(nb.get_data_mbox(),
+                       new message(message::LOAD, load_to_send));
+}
+
+void process::ctrl_close(neighbor& nb)
+{
+    comm.ctrl_send(nb.get_ctrl_mbox(), new message(message::CTRL_CLOSE, 0.0));
+}
+
+void process::data_close(neighbor& nb)
+{
+    comm.data_send(nb.get_data_mbox(), new message(message::DATA_CLOSE, 0.0));
+}
+
+void process::ctrl_receive(double timeout)
+{
+    message* msg;
+    m_host_t from;
+
+    XBT_DEBUG("%sblocking receive on ctrl (%g)", "\0non-" + !timeout, timeout);
+    while (ctrl_close_pending && comm.ctrl_recv(msg, from, timeout)) {
+        handle_message(msg, from);
+        timeout = 0.0;
+    }
+}
+
+void process::data_receive(double timeout)
+{
+    message* msg;
+    m_host_t from;
+
+    XBT_DEBUG("%sblocking receive on data (%g)", "\0non-" + !timeout, timeout);
+    while (data_close_pending && comm.data_recv(msg, from, timeout)) {
+        handle_message(msg, from);
+        timeout = 0.0;
+    }
+}
+
+void process::handle_message(message* msg, m_host_t from)
+{
+    switch (msg->get_type()) {
+    case message::INFO: {
+        neighbor* n = rev_neigh[from];
+        n->set_load(msg->get_amount());
+        break;
+    }
+    case message::CREDIT:
+        expected_load += msg->get_amount();
+        break;
+    case message::LOAD: {
+        double ld = msg->get_amount();
+        real_load += ld;
+        if (finalizing)
+            total_load_running -= ld;
+        break;
+    }
+    case message::CTRL_CLOSE:
+        ctrl_close_pending--;
+        close_received = true;
+        break;
+    case message::DATA_CLOSE:
+        data_close_pending--;
+        close_received = true;
+        break;
+    }
+    delete msg;
+}
+

 // Local variables:
 // mode: c++
 // End:
 // Local variables:
 // mode: c++
 // End: