Skip to content

Commit

Permalink
Add histogram support to stats (nanocurrency#2532)
Browse files Browse the repository at this point in the history
  • Loading branch information
cryptocode authored and deusmax committed Mar 16, 2021
1 parent 79c92db commit 9ee1063
Show file tree
Hide file tree
Showing 3 changed files with 228 additions and 9 deletions.
32 changes: 32 additions & 0 deletions nano/core_test/node.cpp
Original file line number Diff line number Diff line change
Expand Up @@ -2410,6 +2410,38 @@ TEST (node, stat_counting)
ASSERT_EQ (10, node1.stats.count (nano::stat::type::ledger, nano::stat::dir::in));
}

TEST (node, stat_histogram)
{
nano::system system (1);
auto & node1 (*system.nodes[0]);

// Specific bins
node1.stats.define_histogram (nano::stat::type::vote, nano::stat::detail::confirm_req, nano::stat::dir::in, { 1, 6, 10, 16 });
node1.stats.update_histogram (nano::stat::type::vote, nano::stat::detail::confirm_req, nano::stat::dir::in, 1, 50);
auto histogram_req (node1.stats.get_histogram (nano::stat::type::vote, nano::stat::detail::confirm_req, nano::stat::dir::in));
ASSERT_EQ (histogram_req->get_bins ()[0].value, 50);

// Uniform distribution (12 bins, width 1); also test clamping 100 to the last bin
node1.stats.define_histogram (nano::stat::type::vote, nano::stat::detail::confirm_ack, nano::stat::dir::in, { 1, 13 }, 12);
node1.stats.update_histogram (nano::stat::type::vote, nano::stat::detail::confirm_ack, nano::stat::dir::in, 1);
node1.stats.update_histogram (nano::stat::type::vote, nano::stat::detail::confirm_ack, nano::stat::dir::in, 8, 10);
node1.stats.update_histogram (nano::stat::type::vote, nano::stat::detail::confirm_ack, nano::stat::dir::in, 100);

auto histogram_ack (node1.stats.get_histogram (nano::stat::type::vote, nano::stat::detail::confirm_ack, nano::stat::dir::in));
ASSERT_EQ (histogram_ack->get_bins ()[0].value, 1);
ASSERT_EQ (histogram_ack->get_bins ()[7].value, 10);
ASSERT_EQ (histogram_ack->get_bins ()[11].value, 1);

// Uniform distribution (2 bins, width 5); add 1 to each bin
node1.stats.define_histogram (nano::stat::type::vote, nano::stat::detail::confirm_ack, nano::stat::dir::out, { 1, 11 }, 2);
node1.stats.update_histogram (nano::stat::type::vote, nano::stat::detail::confirm_ack, nano::stat::dir::out, 1, 1);
node1.stats.update_histogram (nano::stat::type::vote, nano::stat::detail::confirm_ack, nano::stat::dir::out, 6, 1);

auto histogram_ack_out (node1.stats.get_histogram (nano::stat::type::vote, nano::stat::detail::confirm_ack, nano::stat::dir::out));
ASSERT_EQ (histogram_ack_out->get_bins ()[0].value, 1);
ASSERT_EQ (histogram_ack_out->get_bins ()[1].value, 1);
}

TEST (node, online_reps)
{
nano::system system (1);
Expand Down
121 changes: 116 additions & 5 deletions nano/lib/stats.cpp
Original file line number Diff line number Diff line change
Expand Up @@ -119,14 +119,31 @@ class json_writer : public nano::stat_log_sink
tree.put ("created", tm_to_string (tm));
}

void write_entry (tm & tm, std::string const & type, std::string const & detail, std::string const & dir, uint64_t value) override
void write_entry (tm & tm, std::string const & type, std::string const & detail, std::string const & dir, uint64_t value, nano::stat_histogram * histogram) override
{
boost::property_tree::ptree entry;
entry.put ("time", boost::format ("%02d:%02d:%02d") % tm.tm_hour % tm.tm_min % tm.tm_sec);
entry.put ("type", type);
entry.put ("detail", detail);
entry.put ("dir", dir);
entry.put ("value", value);
if (histogram != nullptr)
{
boost::property_tree::ptree histogram_node;
for (auto const & bin : histogram->get_bins ())
{
boost::property_tree::ptree bin_node;
bin_node.put ("start_inclusive", bin.start_inclusive);
bin_node.put ("end_exclusive", bin.end_exclusive);
bin_node.put ("value", bin.value);

std::time_t time = std::chrono::system_clock::to_time_t (bin.timestamp);
struct tm local_tm = *localtime (&time);
bin_node.put ("time", boost::format ("%02d:%02d:%02d") % local_tm.tm_hour % local_tm.tm_min % local_tm.tm_sec);
histogram_node.push_back (std::make_pair ("", bin_node));
}
entry.put_child ("histogram", histogram_node);
}
entries.push_back (std::make_pair ("", entry));
}

Expand All @@ -150,7 +167,7 @@ class json_writer : public nano::stat_log_sink
std::ostringstream sstr;
};

/** File sink with rotation support */
/** File sink with rotation support. This writes one counter per line and does not include histogram values. */
class file_writer : public nano::stat_log_sink
{
public:
Expand Down Expand Up @@ -178,7 +195,7 @@ class file_writer : public nano::stat_log_sink
log << header << "," << boost::format ("%04d.%02d.%02d %02d:%02d:%02d") % (1900 + tm.tm_year) % (tm.tm_mon + 1) % tm.tm_mday % tm.tm_hour % tm.tm_min % tm.tm_sec << std::endl;
}

void write_entry (tm & tm, std::string const & type, std::string const & detail, std::string const & dir, uint64_t value) override
void write_entry (tm & tm, std::string const & type, std::string const & detail, std::string const & dir, uint64_t value, nano::stat_histogram *) override
{
log << boost::format ("%02d:%02d:%02d") % tm.tm_hour % tm.tm_min % tm.tm_sec << "," << type << "," << detail << "," << dir << "," << value << std::endl;
}
Expand All @@ -191,6 +208,80 @@ class file_writer : public nano::stat_log_sink
}
};

nano::stat_histogram::stat_histogram (std::initializer_list<uint64_t> intervals_a, size_t bin_count_a)
{
if (bin_count_a == 0)
{
assert (intervals_a.size () > 1);
uint64_t start_inclusive_l = *intervals_a.begin ();
for (auto it = std::next (intervals_a.begin ()); it != intervals_a.end (); ++it)
{
uint64_t end_exclusive_l = *it;
bins.emplace_back (start_inclusive_l, end_exclusive_l);
start_inclusive_l = end_exclusive_l;
}
}
else
{
assert (intervals_a.size () == 2);
uint64_t min_inclusive_l = *intervals_a.begin ();
uint64_t max_exclusive_l = *std::next (intervals_a.begin ());

auto domain_l = (max_exclusive_l - min_inclusive_l);
auto bin_size_l = (domain_l + bin_count_a - 1) / bin_count_a;
auto last_bin_size_l = (domain_l % bin_size_l);
auto next_start_l = min_inclusive_l;

for (size_t i = 0; i < bin_count_a; i++, next_start_l += bin_size_l)
{
bins.emplace_back (next_start_l, next_start_l + bin_size_l);
}
if (last_bin_size_l > 0)
{
bins.emplace_back (next_start_l, next_start_l + last_bin_size_l);
}
}
}

void nano::stat_histogram::add (uint64_t index_a, uint64_t addend_a)
{
nano::lock_guard<std::mutex> lk (histogram_mutex);
assert (!bins.empty ());

// The search for a bin is linear, but we're searching just a few
// contiguous items which are likely to be in cache.
bool found_l = false;
for (auto & bin : bins)
{
if (index_a >= bin.start_inclusive && index_a < bin.end_exclusive)
{
bin.value += addend_a;
bin.timestamp = std::chrono::system_clock::now ();
found_l = true;
break;
}
}

// Clamp into first or last bin if no suitable bin was found
if (!found_l)
{
if (index_a < bins.front ().start_inclusive)
{
bins.front ().value += addend_a;
}
else
{
bins.back ().value += addend_a;
}
}
}

std::vector<nano::stat_histogram::bin> nano::stat_histogram::get_bins () const
{
nano::lock_guard<std::mutex> lk (histogram_mutex);
return bins;
}

nano::stat::stat (nano::stat_config config) :
config (config)
{
Expand Down Expand Up @@ -257,7 +348,7 @@ void nano::stat::log_counters_impl (stat_log_sink & sink)
std::string type = type_to_string (key);
std::string detail = detail_to_string (key);
std::string dir = dir_to_string (key);
sink.write_entry (local_tm, type, detail, dir, it.second->counter.get_value ());
sink.write_entry (local_tm, type, detail, dir, it.second->counter.get_value (), it.second->histogram.get ());
}
sink.entries ()++;
sink.finalize ();
Expand Down Expand Up @@ -294,13 +385,33 @@ void nano::stat::log_samples_impl (stat_log_sink & sink)
{
std::time_t time = std::chrono::system_clock::to_time_t (datapoint.get_timestamp ());
tm local_tm = *localtime (&time);
sink.write_entry (local_tm, type, detail, dir, datapoint.get_value ());
sink.write_entry (local_tm, type, detail, dir, datapoint.get_value (), nullptr);
}
}
sink.entries ()++;
sink.finalize ();
}

void nano::stat::define_histogram (stat::type type, stat::detail detail, stat::dir dir, std::initializer_list<uint64_t> intervals_a, size_t bin_count_a /*=0*/)
{
auto entry (get_entry (key_of (type, detail, dir)));
entry->histogram = std::make_unique<nano::stat_histogram> (intervals_a, bin_count_a);
}

void nano::stat::update_histogram (stat::type type, stat::detail detail, stat::dir dir, uint64_t index_a, uint64_t addend_a)
{
auto entry (get_entry (key_of (type, detail, dir)));
assert (entry->histogram != nullptr);
entry->histogram->add (index_a, addend_a);
}

nano::stat_histogram * nano::stat::get_histogram (stat::type type, stat::detail detail, stat::dir dir)
{
auto entry (get_entry (key_of (type, detail, dir)));
assert (entry->histogram != nullptr);
return entry->histogram.get ();
}

void nano::stat::update (uint32_t key_a, uint64_t value)
{
static file_writer log_count (config.log_counters_filename);
Expand Down
84 changes: 80 additions & 4 deletions nano/lib/stats.hpp
Original file line number Diff line number Diff line change
Expand Up @@ -6,6 +6,7 @@
#include <boost/circular_buffer.hpp>

#include <chrono>
#include <initializer_list>
#include <map>
#include <memory>
#include <mutex>
Expand Down Expand Up @@ -78,7 +79,43 @@ class stat_datapoint final
std::chrono::system_clock::time_point timestamp{ std::chrono::system_clock::now () };
};

/** Bookkeeping of statistics for a specific type/detail/direction combination */
/** Histogram values */
class stat_histogram final
{
public:
/**
* Create histogram given a set of intervals and an optional bin count
* @param intervals_a Inclusive-exclusive intervals, e.g. {1,5,8,15} produces bins [1,4] [5,7] [8, 14]
* @param bin_count_a If zero (default), \p intervals_a defines all the bins. If non-zero, \p intervals_a contains the total range, which is uniformly distributed into \p bin_count_a bins.
*/
stat_histogram (std::initializer_list<uint64_t> intervals_a, size_t bin_count_a = 0);

/** Add \p addend_a to the histogram bin into which \p index_a falls */
void add (uint64_t index_a, uint64_t addend_a);

/** Histogram bin with interval, current value and timestamp of last update */
class bin final
{
public:
bin (uint64_t start_inclusive_a, uint64_t end_exclusive_a) :
start_inclusive (start_inclusive_a), end_exclusive (end_exclusive_a)
{
}
uint64_t start_inclusive;
uint64_t end_exclusive;
uint64_t value{ 0 };
std::chrono::system_clock::time_point timestamp{ std::chrono::system_clock::now () };
};
std::vector<bin> get_bins () const;

private:
mutable std::mutex histogram_mutex;
std::vector<bin> bins;
};

/**
* Bookkeeping of statistics for a specific type/detail/direction combination
*/
class stat_entry final
{
public:
Expand All @@ -102,6 +139,9 @@ class stat_entry final
/** Counting value for this entry, including the time of last update. This is never reset and only increases. */
stat_datapoint counter;

/** Optional histogram for this entry */
std::unique_ptr<stat_histogram> histogram;

/** Zero or more observers for samples. Called at the end of the sample interval. */
nano::observer_set<boost::circular_buffer<stat_datapoint> &> sample_observers;

Expand Down Expand Up @@ -133,8 +173,8 @@ class stat_log_sink
{
}

/** Write a counter or sampling entry to the log */
virtual void write_entry (tm & tm, std::string const & type, std::string const & detail, std::string const & dir, uint64_t value)
/** Write a counter or sampling entry to the log. Some log sinks may support writing histograms as well. */
virtual void write_entry (tm & tm, std::string const & type, std::string const & detail, std::string const & dir, uint64_t value, nano::stat_histogram * histogram)
{
}

Expand Down Expand Up @@ -389,7 +429,7 @@ class stat final
/** Increments the counter for \detail, but doesn't update at the type level */
void inc_detail_only (stat::type type, stat::detail detail, stat::dir dir = stat::dir::in)
{
add (type, detail, dir, 1);
add (type, detail, dir, 1, true);
}

/** Increments the given counter */
Expand All @@ -404,6 +444,42 @@ class stat final
add (type, detail::all, dir, value);
}

/**
* Define histogram bins. Values are clamped into the first and last bins, but a catch-all bin on one or both
* ends can be defined.
*
* Examples:
*
* // Uniform histogram, total range 12, and 12 bins (each bin has width 1)
* define_histogram (type::vote, detail::confirm_ack, dir::in, {1,13}, 12);
*
* // Specific bins matching closed intervals [1,4] [5,19] [20,99]
* define_histogram (type::vote, detail::something, dir::out, {1,5,20,100});
*
* // Logarithmic bins matching half-open intervals [1..10) [10..100) [100 1000)
* define_histogram(type::vote, detail::log, dir::out, {1,10,100,1000});
*/
void define_histogram (stat::type type, stat::detail detail, stat::dir dir, std::initializer_list<uint64_t> intervals_a, size_t bin_count_a = 0);

/**
* Update histogram
*
* Examples:
*
* // Add 1 to the bin representing a 4-item vbh
* stats.update_histogram(type::vote, detail::confirm_ack, dir::in, 4, 1)
*
* // Add 5 to the second bin where 17 falls
* stats.update_histogram(type::vote, detail::something, dir::in, 17, 5)
*
* // Add 3 to the last bin as the histogram clamps. You can also add a final bin with maximum end value to effectively prevent this.
* stats.update_histogram(type::vote, detail::log, dir::out, 1001, 3)
*/
void update_histogram (stat::type type, stat::detail detail, stat::dir dir, uint64_t index, uint64_t addend = 1);

/** Returns a non-owning histogram pointer, or nullptr if a histogram is not defined */
nano::stat_histogram * get_histogram (stat::type type, stat::detail detail, stat::dir dir);

/**
* Add \p value to stat. If sampling is configured, this will update the current sample and
* call any sample observers if the interval is over.
Expand Down

0 comments on commit 9ee1063

Please sign in to comment.