inconsistent-phase-stats_v0.1.0.patch - patch for DNS Rex v0.1.0 Do not include phases with zero duration and goal in the schedule. Before the change, phases with explicitly configured zero duration or goal were included in the schedule. Hence, such phases were included in the stats report. Moreover, if such phase was the first one, it may have non-zero stats (duration, rate, etc.) because interval stats are recorded before the phase is switched. The patch makes phases with zero goal and duration not included in the schedule. Note, that even before the patch, phases with no configured goal and duration were not included in the schedule. Index: src/base/Phase.cc =================================================================== --- src/base/Phase.cc (revision 12817) +++ src/base/Phase.cc (revision 12818) @@ -18,55 +18,55 @@ #include "base/Config.h" static Mutex mxSchedule; // protects phase schedule and related Phase members Base::Phase::Phase(): sendGapMean(-1), first(false), last(false) { } bool Base::Phase::started() const { const MutexLock lock(mxStats); return actualStart.known(); } bool Base::Phase::stopped() const { const MutexLock lock(mxStats); return stats.end.known(); } -void Base::Phase::start() { - restart(Nime::Now()); +void Base::Phase::start(const Nime &when) { + restart(when); } // called from locked CurrentPhase() via start() or Base::Phase::record() void Base::Phase::restart(const Nime &actual) { actualStart = actual; if (cfg.duration.known()) expectedEnd = actualStart + cfg.duration; } // called from locked CurrentPhase() -void Base::Phase::stop() { +void Base::Phase::stop(const Nime &when) { stats.start = actualStart; - stats.end = Nime::Now(); + stats.end = when; } // called from locked CurrentPhase() bool Base::Phase::over() const { // "first" phase waits for 1st xaction and "cool-down" phase never ends if (first || last) return false; const Nime now = Nime::Now(); // TODO: optimize to avoid calling so often if (expectedEnd.known() && now < expectedEnd) return false; if (cfg.goal >= 0 && stats.xacts.count() < cfg.goal) return false; return true; } // called from locked ReportSchedule() void Base::Phase::report() const { stats.print(std::cout, "phase-" + cfg.name + '.'); std::cout << std::endl; @@ -121,77 +121,82 @@ void Base::Phase::record(IntervalStats & // TODO: rewrite to avoid this lock, unlocked first access, re-start()? MutexLock lock(mxSchedule); first = false; // hack: we are no longer special restart(i.start); } stats.xactLevel = 0; stats += i; } #include typedef std::list Schedule; static Schedule TheSchedule; static Schedule::iterator TheCurrentPhase; void Base::StartSchedule() { MutexLock lock(mxSchedule); TheCurrentPhase = TheSchedule.begin(); - TheCurrentPhase->start(); + TheCurrentPhase->start(Nime::Now()); } void Base::StopSchedule() { MutexLock lock(mxSchedule); - TheCurrentPhase->stop(); // even if it is not over yet + TheCurrentPhase->stop(Nime::Now()); // even if it is not over yet } void Base::ReportScheduled() { MutexLock lock(mxSchedule); int stopped = 0, started = 0; typedef Schedule::iterator SI; for (SI i = TheSchedule.begin(); i != TheSchedule.end(); ++i) { if (i->started()) { ++started; i->report(); if (i->stopped()) ++stopped; } } std::cout << "phases.started.count: " << started << std::endl; std::cout << "phases.stopped.count: " << stopped << std::endl; std::cout << "phases.all.count: " << TheSchedule.size() << std::endl; } -// TODO: optimize using shared read lock and extract expensive CheckPhase() +// TODO: optimize using shared read lock Base::Phase &Base::CurrentPhase() { MutexLock lock(mxSchedule); + Must(TheCurrentPhase != TheSchedule.end()); + return *TheCurrentPhase; +} + +void Base::AdvancePhase(const Nime &when) { + MutexLock lock(mxSchedule); while (TheCurrentPhase != TheSchedule.end() && TheCurrentPhase->over()) { - TheCurrentPhase->stop(); + TheCurrentPhase->stop(when); ++TheCurrentPhase; - TheCurrentPhase->start(); + TheCurrentPhase->start(when); } Must(TheCurrentPhase != TheSchedule.end()); - return *TheCurrentPhase; } // called from the main thread only void Base::BuildSchedule() { if (Global::Config().phaseWarmUp.present()) { Phase p; p.cfg = Global::Config().phaseWarmUp; TheSchedule.push_back(p); } if (Global::Config().phaseFill.present()) { Phase p; p.cfg = Global::Config().phaseFill; TheSchedule.push_back(p); } if (Global::Config().phaseRampUp.present()) { Phase p; p.cfg = Global::Config().phaseRampUp; TheSchedule.push_back(p); } if (Global::Config().phaseMeas.present()) { Index: src/base/Phase.h =================================================================== --- src/base/Phase.h (revision 12817) +++ src/base/Phase.h (revision 12818) @@ -22,43 +22,44 @@ class Phase { bool started() const; bool stopped() const; void record(IntervalStats &i); void report() const; public: double delay(const double peakRate, const double nowSec) const; public: PhaseConfig cfg; // user-provided configuration double sendGapMean; // mean query interarrival time in seconds bool first; // whether this is the first phase, waiting for activity bool last; // whether this is the last, cool-down phase (read-only) protected: friend void StartSchedule(); friend void StopSchedule(); - friend Phase &CurrentPhase(); - void start(); + friend void AdvancePhase(const Nime &when); + void start(const Nime &when); void restart(const Nime &anActualStart); - void stop(); + void stop(const Nime &when); bool over() const; // whether this phase is done and needs to stop private: Nime actualStart; // known for started phases Nime expectedEnd; // known for started, time-based phases IntervalStats stats; mutable Mutex mxStats; // protects stats }; extern void BuildSchedule(); extern void StartSchedule(); extern void StopSchedule(); extern void ReportScheduled(); extern Phase &CurrentPhase(); +extern void AdvancePhase(const Nime &when); } // namespace Base #endif Index: src/base/Monitor.cc =================================================================== --- src/base/Monitor.cc (revision 12817) +++ src/base/Monitor.cc (revision 12818) @@ -58,40 +58,41 @@ void Monitor::run() { stats.id = i; stats.start = iStart; stats.end = iEnd; collect(stats); lineReport(cout << "i: ", stats); if (!stats.empty()) idleStart = iEnd; } if (!Global::StopRequested) clog << "idle timeout: no activity for " << idleTimeout << endl; } void Monitor::collect(IntervalStats &stats) { typedef Gauges::iterator GI; for (GI i = gauges.begin(); i != gauges.end(); ++i) (*i)->checkpoint(stats); Base::CurrentPhase().record(stats); + Base::AdvancePhase(stats.end); allStats.xactLevel = 0; allStats += stats; progress += stats.queries.count(); } // calculates messages/second rate as an integer static int irate(const int messages, const double seconds) { return static_cast(floor(messages/seconds + 0.5)); } int ClientXactLevel = 0; void Monitor::lineReport(std::ostream &os, const IntervalStats &stats) const { const Nime passed = stats.end - testStart; const double iSeconds = (stats.end - stats.start).secd(); const double mbps = (1024*1024/8)*iSeconds; // Mbits/sec factor