core: periodically show progress by elapsed simulation time, executed event count

This commit is contained in:
Peter D. Barnes, Jr.
2018-10-19 01:09:56 -04:00
parent 05cb0757bc
commit 1edcd5ecd4
5 changed files with 541 additions and 0 deletions

View File

@@ -0,0 +1,170 @@
/* -*- Mode:C++; c-file-style:"gnu"; indent-tabs-mode:nil; -*- */
/*
* Copyright (c) 2017 Lawrence Livermore National Laboratory
*
* This program is free software; you can redistribute it and/or modify
* it under the terms of the GNU General Public License version 2 as
* published by the Free Software Foundation;
*
* This program is distributed in the hope that it will be useful,
* but WITHOUT ANY WARRANTY; without even the implied warranty of
* MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the
* GNU General Public License for more details.
*
* You should have received a copy of the GNU General Public License
* along with this program; if not, write to the Free Software
* Foundation, Inc., 59 Temple Place, Suite 330, Boston, MA 02111-1307 USA
*
* Author: Gustavo Carneiro <gjc@inescporto.pt>
* Author: Peter D. Barnes, Jr. <pdbarnes@llnl.gov>
*/
/**
* \file
* \ingroup core-examples
* \ingroup logging
* Example program that demonstrates ShowProgress.
*/
/**
* Example program that demonstrates ShowProgress.
*
*/
#include "ns3/core-module.h"
#include <ctime>
#include <iomanip>
#include <string>
using namespace ns3;
NS_LOG_COMPONENT_DEFINE ("SampleShowProgress");
namespace {
class Timestamp
{
public:
Timestamp () :
last(0),
diff(0)
{
stamp ();
}
void stamp () {
time_t seconds = time (NULL);
diff = seconds - last;
last = seconds;
}
std::string string () {
std::string now = ctime ( &last );
now.resize(now.length () - 1); // trim trailing newline
return now;
}
time_t last;
time_t diff;
}; // class Timestamp
/**
* Execute a function periodically.
*/
class Hold : public SimpleRefCount<Hold>
{
public:
Hold (Time wait, Time interval)
{
m_wait = wait;
m_interval = interval;
m_rng = CreateObject<ExponentialRandomVariable> ();
m_rng->SetAttribute ("Mean", DoubleValue (wait.GetSeconds ()));
}
Hold (Ptr<RandomVariableStream> rng)
: m_rng (rng)
{
}
void Event (void)
{
double delta = m_rng->GetValue ();
Time delay = Seconds (delta);
NS_LOG_LOGIC ("event delay: " << delay);
Simulator::Schedule (delay, &Hold::Event, this);
// Switch work load every 10 * m_interval of simulation time
int64x64_t ratio = (Simulator::Now () / m_interval) / 10;
bool even = (ratio.GetHigh () % 2);
Time work = m_wait * (even ? 3 : 1);
m_condition.TimedWait ( work.GetNanoSeconds () );
}
private:
Ptr<RandomVariableStream> m_rng;
SystemCondition m_condition;
Time m_wait;
Time m_interval;
}; // class HOLD
} // unnamed namespace
int
main (int argc, char ** argv)
{
Time stop = Seconds (100);
Time interval = Seconds (1);
Time wait = MilliSeconds (10);
bool verbose = false;
CommandLine cmd;
cmd.AddValue ("stop", "Simulation duration in virtual time.", stop);
cmd.AddValue ("interval", "Approximate reporting interval, in wall clock time.", interval);
cmd.AddValue ("wait", "Wallclock time to burn on each event.", wait);
cmd.AddValue ("verbose", "Turn on verbose progress message.", verbose);
cmd.Parse (argc, argv);
std::cout << "\n"
<< cmd.GetName () << ":\n"
<< "\n"
<< "verbose progress message: " << (verbose ? "on\n" : "off\n")
<< "target reporting interval: " << interval.As (Time::S) << "\n"
<< "average event sleep time: " << wait.As (Time::MS) << "\n"
<< "total simulatino run time: " << stop.As (Time::S)
<< std::endl;
Ptr<Hold> h = Create<Hold> (wait, interval);
h->Event ();
Simulator::Stop (stop);
ShowProgress spinner (interval);
spinner.SetVerbose (verbose);
Timestamp ts;
ts.stamp ();
std::cout << std::endl;
std::cout << "Start wall clock: " << ts.string ()
<< " (" << ts.last << ")"
<< std::endl;
Simulator::Run ();
ts.stamp ();
std::cout << "Elapsed wall clock: " << ts.diff << "s" << std::endl;
Simulator::Destroy ();
}

View File

@@ -40,6 +40,10 @@ def build(bld):
obj = bld.create_ns3_program('test-string-value-formatting', ['core'])
obj.source = 'test-string-value-formatting.cc'
obj = bld.create_ns3_program('sample-show-progress',
['core'])
obj.source = 'sample-show-progress.cc'
if bld.env['ENABLE_THREADING'] and bld.env["ENABLE_REAL_TIME"]:
obj = bld.create_ns3_program('main-test-sync', ['network'])
obj.source = 'main-test-sync.cc'

View File

@@ -0,0 +1,222 @@
/* -*- Mode:C++; c-file-style:"gnu"; indent-tabs-mode:nil; -*- */
/*
* Copyright (c) 2017 Lawrence Livermore National Laboratory
*
* This program is free software; you can redistribute it and/or modify
* it under the terms of the GNU General Public License version 2 as
* published by the Free Software Foundation;
*
* This program is distributed in the hope that it will be useful,
* but WITHOUT ANY WARRANTY; without even the implied warranty of
* MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the
* GNU General Public License for more details.
*
* You should have received a copy of the GNU General Public License
* along with this program; if not, write to the Free Software
* Foundation, Inc., 59 Temple Place, Suite 330, Boston, MA 02111-1307 USA
*
* Author: Gustavo Carneiro <gjc@inescporto.pt>
* Author: Peter D. Barnes, Jr. <pdbarnes@llnl.gov>
*/
/**
* \file
* \ingroup core
* ns3::ShowProgress implementation.
*/
#include <iomanip>
#include "event-id.h"
#include "log.h"
#include "nstime.h"
#include "simulator.h"
#include "singleton.h"
#include "show-progress.h"
namespace ns3 {
NS_LOG_COMPONENT_DEFINE ("ShowProgress");
ShowProgress::ShowProgress (const Time interval /* = Seconds (1.0) */,
std::ostream & os /* = std::cout */)
: m_timer (),
m_interval (interval),
m_vtime (Seconds (1.0)),
m_event (),
m_eventCount (0),
m_printer (DefaultTimePrinter),
m_os (&os),
m_verbose (false),
m_repCount (0)
{
NS_LOG_FUNCTION (this << interval);
Start ();
}
void
ShowProgress::SetInterval (const Time interval)
{
NS_LOG_FUNCTION (this << interval);
const int64x64_t ratio = interval / m_interval;
m_interval = interval;
m_vtime = m_vtime * ratio;
Simulator::Cancel (m_event);
Start ();
} // ShowProgress::SetInterval
void
ShowProgress::SetTimePrinter (TimePrinter lp)
{
NS_LOG_FUNCTION (this << lp);
m_printer = lp;
}
void
ShowProgress::SetVerbose (bool verbose)
{
NS_LOG_FUNCTION (this << verbose);
m_verbose = verbose;
}
void
ShowProgress::SetStream (std::ostream & os)
{
m_os = &os;
}
void
ShowProgress::Start (void)
{
NS_LOG_FUNCTION (this);
m_event = Simulator::Schedule (m_vtime, &ShowProgress::Feedback, this);
m_timer.Start ();
} // ShowProgress::Start
void
ShowProgress::Feedback (void)
{
// Get elapsed wall clock time
Time elapsed = MilliSeconds (m_timer.End ());
NS_LOG_FUNCTION (this << elapsed);
// Don't do anything unless the elapsed time is positive.
if (elapsed <= Time (0))
{
m_vtime = m_vtime * MAXGAIN;
Start ();
return;
}
// Speed: how fast are we compared to real time
const int64x64_t speed = m_vtime / elapsed;
// Ratio: how much real time did we use,
// compared to reporting interval target
const int64x64_t ratio = elapsed / m_interval;
// Elapsed event count
uint64_t events = Simulator::GetEventCount ();
uint64_t nEvents = events - m_eventCount;
m_eventCount = events;
/**
* \internal Update algorithm
*
* We steer \c m_vtime to obtain updates approximately every
* \c m_interval in wall clock time. To smooth things out a little
* we impose a hysteresis band around \c m_interval where we
* don't change \c m_vtime. To avoid too rapid movements
* chasing spikes or dips in execution rate, we bound the
* change in \c m_vtime to a maximum factor.
*
* In mathematical terms, we compute the ratio of elapsed wall clock time
* compared to the target reporting interval:
* \f[ ratio = \frac{elapsed}{target interval)} \f]
*
* Graphically, the windows in ratio value and the corresponding
* updates to \c m_vtime are sketched in this figure:
* \verbatim
^
|
ratio | vtime update
|
|
| *= MAXGAIN
|
MAXGAIN -|-------------- *= min (ratio, MAXGAIN)
|
| *= ratio
|
HYSTERESIS -|=============================================
|
|
|
1 -| No change
|
|
|
1/ HYSTERESIS -|==============================================
|
| *= ratio
|
1/ MAXGAIN -|--------------- *= max (ratio, 1/ MAXGAIN)
|
| *= 1/MAXGAIN
|
\endverbatim
*
* As indicated, when ratio is outside the hysteresis band
* it amounts to multiplying \c m_vtime by the min/max of the ratio
* with the appropriate MAXGAIN factor.
*/
if (ratio > HYSTERESIS)
{
m_vtime = m_vtime / std::min (ratio, MAXGAIN);
}
else if (ratio < 1.0 / HYSTERESIS)
{
m_vtime = m_vtime / std::max (ratio, 1.0 / MAXGAIN);
}
// Save stream state
auto precision = m_os->precision ();
auto flags = m_os->flags ();
m_os->setf (std::ios::fixed, std:: ios::floatfield);
if (m_verbose)
{
(*m_os) << m_repCount
<< " [del: " << elapsed.As(Time::S)
<< "/ int: " << m_interval.As(Time::S)
<< " = rat: " << ratio
<< (ratio > HYSTERESIS ? " up" :
(ratio < 1.0 / HYSTERESIS ? " dn" : " --"))
<< ", vt: " << m_vtime.As(Time::S) << "] ";
}
m_repCount++;
// Print the current time
(*m_printer)(*m_os);
(*m_os) << " ("
<< std::setprecision (3) << std::setw (8) << speed.GetDouble () << "x real time) "
<< nEvents << " events processed"
<< std::endl
<< std::flush;
// Restore stream state
m_os->precision (precision);
m_os->flags (flags);
// And do it again
Start ();
} // ShowProgress::Feedback
} // namespace ns3

View File

@@ -0,0 +1,143 @@
/* -*- Mode:C++; c-file-style:"gnu"; indent-tabs-mode:nil; -*- */
/*
* Copyright (c) 2017 Lawrence Livermore National Laboratory
*
* This program is free software; you can redistribute it and/or modify
* it under the terms of the GNU General Public License version 2 as
* published by the Free Software Foundation;
*
* This program is distributed in the hope that it will be useful,
* but WITHOUT ANY WARRANTY; without even the implied warranty of
* MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the
* GNU General Public License for more details.
*
* You should have received a copy of the GNU General Public License
* along with this program; if not, write to the Free Software
* Foundation, Inc., 59 Temple Place, Suite 330, Boston, MA 02111-1307 USA
*
* Author: Gustavo Carneiro <gjc@inescporto.pt>
* Author: Peter D. Barnes, Jr. <pdbarnes@llnl.gov>
*/
#ifndef SHOW_PROGRESS_H
#define SHOW_PROGRESS_H
/**
* \file
* \ingroup core
* ns3::ShowProgress declaration.
*/
#include <iostream>
#include "nstime.h"
#include "system-wall-clock-ms.h"
namespace ns3 {
/**
* \ingroup core
* \ingroup debugging
*
* Periodically print a status message indicating simulator progress.
*
* Print a status message showing the simulator time and
* execution speed, relative to wall clock time, as well as the number
* of events executed each interval.
*
* The target update rate (and output stream) can be configured at construction.
*
* Example usage:
*
* \code
* int main (int arg, char ** argv)
* {
* // Create your model
*
* ShowProgress (Seconds (1), std::cerr);
* Simulator::Run ();
* Simulator::Destroy ();
* }
* \endcode
*
* Based on a python version by Gustavo Carneiro <gjcarneiro@gmail.com>,
* as released here:
* http://mailman.isi.edu/pipermail/ns-developers/2009-January/005201.html
*/
class ShowProgress
{
public:
/**
* Constructor.
* \param [in] interval The target wallclock interval to show progress.
* \param [in] os The stream to print on.
*/
ShowProgress (const Time interval = Seconds (1.0),
std::ostream & os = std::cout);
/**
* Set the target update interval, in wallclock time.
* \param [in] interval The target wallclock interval to show progress.
*/
void SetInterval (const Time interval);
/**
* Set the TimePrinter function to be used
* to prepend progress messages with the simulation time.
*
* The default is DefaultTimePrinter().
*
* \param [in] lp The TimePrinter function.
*/
void SetTimePrinter (TimePrinter lp);
/**
* Set the output stream to show progress on.
* \param [in] os The output stream; defaults to std::cerr.
*/
void SetStream (std::ostream & os);
/** Start the progress timer. */
void Start (void);
/**
* Set verbose mode to print real and virtual time intervals.
*
* \param [in] verbose \c true to turn on verbose mode
*/
void SetVerbose (bool verbose);
private:
/** Show execution progress. */
void Feedback (void);
/**
* Hysteresis factor.
* \see Feedback()
*/
const int64x64_t HYSTERESIS = 1.2;
/**
* Maximum growth factor.
* \see Feedback()
*/
const int64x64_t MAXGAIN = 2.0;
SystemWallClockMs m_timer; //!< Wallclock timer
Time m_interval; //!< The target update interval, in wallclock time
Time m_vtime; //!< The virtual time interval.
EventId m_event; //!< The next progress event.
uint64_t m_eventCount; //!< Simulator event count
TimePrinter m_printer; //!< The TimePrinter to use
std::ostream *m_os; //!< The output stream to use.
bool m_verbose; //!< Verbose mode flag
uint64_t m_repCount; //!< Count of progress lines printed
}; // class ShowProgress
} // namespace ns3
#endif /* SHOW_PROGRESS_H */

View File

@@ -214,6 +214,7 @@ def build(bld):
'model/des-metrics.cc',
'model/node-printer.cc',
'model/time-printer.cc',
'model/show-progress.cc',
]
core_test = bld.create_ns3_module_test_library('core')
@@ -329,6 +330,7 @@ def build(bld):
'model/des-metrics.h',
'model/node-printer.h',
'model/time-printer.h',
'model/show-progress.h',
]
if sys.platform == 'win32':