Skip to content
This repository has been archived by the owner on Mar 3, 2020. It is now read-only.

Commit

Permalink
clean up logs
Browse files Browse the repository at this point in the history
  • Loading branch information
@isabelsavannah
isabelsavannah committed Nov 30, 2018
1 parent 74a42dc commit fa475f0
Show file tree
Hide file tree
Showing 5 changed files with 25 additions and 21 deletions.
2 changes: 1 addition & 1 deletion audit/CMakeLists.txt
View file
Original file line number Diff line number Diff line change
Expand Up @@ -4,7 +4,7 @@ add_library(audit
audit.cpp
)

target_link_libraries(audit proto)
target_link_libraries(audit utils proto)
add_dependencies(audit jsoncpp)
target_include_directories(audit PRIVATE ${JSONCPP_INCLUDE_DIRS} ${PROTO_INCLUDE_DIR})
add_subdirectory(test)
33 changes: 20 additions & 13 deletions audit/audit.cpp
View file
Original file line number Diff line number Diff line change
Expand Up @@ -16,6 +16,8 @@
#include <boost/beast/core/detail/base64.hpp>
#include <boost/asio/ip/udp.hpp>
#include <boost/format.hpp>
#include <boost/system/error_code.hpp>
#include <utils/bytes_to_debug_string.hpp>

using namespace bzn;

Expand Down Expand Up @@ -60,26 +62,25 @@ audit::start()

if (this->monitor_endpoint)
{
LOG(info) << boost::format("Audit module running, will send stats to %1%:%2%")
LOG(info) << boost::format("audit module running, will send stats to %1%:%2%")
% this->monitor_endpoint->address().to_string()
% this->monitor_endpoint->port();
}
else
{
LOG(info) "Audit module running, but not sending stats anywhere because no monitor configured";
LOG(info) "audit module running, but not sending stats anywhere because no monitor configured";
}

LOG(debug) << "starting primary alive timer";
this->reset_primary_alive_timer();
});
}

void
audit::reset_primary_alive_timer()
{
LOG(debug) << "starting primary alive timer";
this->primary_dead_count = 0;

// We use the leader_alive_timer here because introducing a new timer would make the tests annoyingly complex
this->primary_alive_timer->cancel();
this->primary_alive_timer->expires_from_now(this->primary_timeout);
this->primary_alive_timer->async_wait(std::bind(&audit::handle_primary_alive_timeout, shared_from_this(), std::placeholders::_1));
Expand All @@ -88,11 +89,17 @@ audit::reset_primary_alive_timer()
void
audit::handle_primary_alive_timeout(const boost::system::error_code& ec)
{
if (ec)
if (ec && ec != boost::system::errc::operation_canceled)
{
LOG(debug) << "Primary alive timeout canceled " << ec.message();
LOG(error) << "primary alive timeout canceled " << ec.message();
return;
}
if (ec == boost::system::errc::operation_canceled)
{
LOG(trace) << "primary still alive";
return;
}


this->report_error(bzn::NO_PRIMARY_METRIC_NAME, str(boost::format("No primary alive [%1%]") % ++(this->primary_dead_count)));
this->primary_alive_timer->expires_from_now(this->primary_timeout);
Expand Down Expand Up @@ -120,7 +127,7 @@ audit::send_to_monitor(const std::string& stat)
return;
}

LOG(debug) << boost::format("Sending stat '%1%' to monitor at %2%:%3%")
LOG(trace) << boost::format("sending stat '%1%' to monitor at %2%:%3%")
% stat
% this->monitor_endpoint->address().to_string()
% this->monitor_endpoint->port();
Expand All @@ -146,10 +153,10 @@ audit::handle(const bzn_envelope& env, std::shared_ptr<bzn::session_base> sessio
audit_message message;
if (!message.ParseFromString(env.audit()))
{
LOG(error) << "Failed to parse audit message from " << env.sender();
LOG(error) << "failed to parse audit message from " << env.sender();
}

LOG(debug) << "Got audit message" << message.DebugString();
LOG(trace) << "got audit message" << message.DebugString();

if (message.has_pbft_commit())
{
Expand All @@ -165,7 +172,7 @@ audit::handle(const bzn_envelope& env, std::shared_ptr<bzn::session_base> sessio
}
else
{
LOG(error) << "Got an unknown audit message? ";
LOG(error) << "got an unknown audit message? " << message.DebugString();
}

session->close();
Expand All @@ -177,15 +184,15 @@ void audit::handle_primary_status(const primary_status& primary_status)

if (this->recorded_primaries.count(primary_status.view()) == 0)
{
LOG(info) << "audit recording that primary of view " << primary_status.view() << " is '" << primary_status.primary() << "'";
LOG(info) << "observed primary of view " << primary_status.view() << " to be '" << primary_status.primary() << "'";
this->send_to_monitor(bzn::PRIMARY_HEARD_METRIC_NAME+bzn::STATSD_COUNTER_FORMAT);
this->recorded_primaries[primary_status.view()] = primary_status.primary();
this->trim();
}
else if (this->recorded_primaries[primary_status.view()] != primary_status.primary())
{
std::string err = str(boost::format(
"Conflicting primary elected! '%1%' is the recorded primary of view %2%, but '%3%' claims to be the primary of the same view.")
"Conflicting primary detected! '%1%' is the recorded primary of view %2%, but '%3%' claims to be the primary of the same view.")
% this->recorded_primaries[primary_status.view()]
% primary_status.view()
% primary_status.primary());
Expand All @@ -204,7 +211,7 @@ audit::handle_pbft_commit(const pbft_commit_notification& commit)

if (this->recorded_pbft_commits.count(commit.sequence_number()) == 0)
{
LOG(info) << "audit recording that message '" << commit.operation() << "' is committed at sequence " << commit.sequence_number();
LOG(debug) << "observed that message '" << bytes_to_debug_string(commit.operation()) << "' is committed at sequence " << commit.sequence_number();
this->recorded_pbft_commits[commit.sequence_number()] = commit.operation();
this->trim();
}
Expand Down
2 changes: 1 addition & 1 deletion node/node.cpp
View file
Original file line number Diff line number Diff line change
Expand Up @@ -108,7 +108,7 @@ node::do_accept()
{
auto ep = self->acceptor_socket->remote_endpoint();

LOG(debug) << "connection from: " << ep.address() << ":" << ep.port();
LOG(trace) << "connection from: " << ep.address() << ":" << ep.port();

auto ws = self->websocket->make_unique_websocket_stream(
self->acceptor_socket->get_tcp_socket());
Expand Down
4 changes: 2 additions & 2 deletions node/session.cpp
View file
Original file line number Diff line number Diff line change
Expand Up @@ -78,7 +78,7 @@ session::do_read()
if (ec)
{
// don't log close of websocket...
if (ec != boost::beast::websocket::error::closed)
if (ec != boost::beast::websocket::error::closed && ec != boost::asio::error::eof)
{
LOG(error) << "websocket read failed: " << ec.message();
}
Expand Down Expand Up @@ -211,7 +211,7 @@ session::start_idle_timeout()
{
this->idle_timer->cancel();

LOG(debug) << "resetting " << this->ws_idle_timeout.count() << "ms idle timer";
LOG(trace) << "resetting " << this->ws_idle_timeout.count() << "ms idle timer";

this->idle_timer->expires_from_now(this->ws_idle_timeout);

Expand Down
5 changes: 1 addition & 4 deletions options/simple_options.cpp
View file
Original file line number Diff line number Diff line change
Expand Up @@ -112,7 +112,7 @@ simple_options::build_options()
po::options_description audit("Audit");
audit.add_options()
(AUDIT_ENABLED.c_str(),
po::value<bool>()->default_value(false),
po::value<bool>()->default_value(true),
"enable audit module")
(AUDIT_MEM_SIZE.c_str(),
po::value<size_t>()->default_value(10000),
Expand All @@ -127,9 +127,6 @@ simple_options::build_options()

po::options_description experimental("Experimental");
experimental.add_options()
(AUDIT_MEM_SIZE.c_str(),
po::value<size_t>()->default_value(10000),
"max size of audit datastructures")
(PBFT_ENABLED.c_str(),
po::value<bool>()->default_value(false),
"use pbft consensus instead of raft (experimental)")
Expand Down

0 comments on commit fa475f0

Please sign in to comment.