Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

move gelf logging to another thread #758

Merged
merged 3 commits into from
Mar 2, 2023
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
2 changes: 1 addition & 1 deletion libraries/libfc/include/fc/log/appender.hpp
Original file line number Diff line number Diff line change
Expand Up @@ -36,7 +36,7 @@ namespace fc {
public:
typedef std::shared_ptr<appender> ptr;

virtual void initialize( boost::asio::io_service& io_service ) = 0;
virtual void initialize() = 0;
virtual void log( const log_message& m ) = 0;
};
}
20 changes: 10 additions & 10 deletions libraries/libfc/include/fc/log/console_appender.hpp
Original file line number Diff line number Diff line change
Expand Up @@ -3,12 +3,12 @@
#include <fc/log/logger.hpp>
#include <vector>

namespace fc
namespace fc
{
class console_appender final : public appender
class console_appender final : public appender
{
public:
struct color
struct color
{
enum type {
red,
Expand All @@ -24,17 +24,17 @@ namespace fc

struct stream { enum type { std_out, std_error }; };

struct level_color
struct level_color
{
level_color( log_level l=log_level::all,
level_color( log_level l=log_level::all,
color::type c=color::console_default )
:level(l),color(c){}

log_level level;
console_appender::color::type color;
};

struct config
struct config
{
config()
:format( "${timestamp} ${thread_name} ${context} ${file}:${line} ${method} ${level}] ${message}" ),
Expand All @@ -52,10 +52,10 @@ namespace fc
console_appender();

~console_appender();
void initialize( boost::asio::io_service& io_service ) {}
virtual void log( const log_message& m );
void print( const std::string& text_to_print,
void initialize() override {}
virtual void log( const log_message& m ) override;

void print( const std::string& text_to_print,
color::type text_color = color::console_default );

void configure( const config& cfg );
Expand Down
2 changes: 1 addition & 1 deletion libraries/libfc/include/fc/log/dmlog_appender.hpp
Original file line number Diff line number Diff line change
Expand Up @@ -20,7 +20,7 @@ namespace fc {
explicit dmlog_appender( const std::optional<config>& args) ;

virtual ~dmlog_appender();
virtual void initialize( boost::asio::io_service& io_service ) override;
virtual void initialize() override;

virtual void log( const log_message& m ) override;

Expand Down
10 changes: 5 additions & 5 deletions libraries/libfc/include/fc/log/gelf_appender.hpp
Original file line number Diff line number Diff line change
Expand Up @@ -6,14 +6,14 @@

#include <regex>

namespace fc
namespace fc
{
// Log appender that sends log messages in JSON format over UDP
// https://www.graylog2.org/resources/gelf/specification
class gelf_appender final : public appender
class gelf_appender final : public appender
{
public:
struct config
struct config
{
static const std::vector<std::string> reserved_field_names;
static const std::regex user_field_name_pattern;
Expand All @@ -31,11 +31,11 @@ namespace fc
* In a single-threaded world with a boost::io_service that's not owned
* by this library, ugly things are required. Tough.
*/
void initialize(boost::asio::io_service& io_service) override;
void initialize() override;
virtual void log(const log_message& m) override;

private:
class impl;
private:
std::shared_ptr<impl> my;
};
} // namespace fc
Expand Down
2 changes: 1 addition & 1 deletion libraries/libfc/include/fc/log/logger_config.hpp
Original file line number Diff line number Diff line change
Expand Up @@ -54,7 +54,7 @@ namespace fc {
static logger get_logger( const fc::string& name );
static void update_logger( const fc::string& name, logger& log );

static void initialize_appenders( boost::asio::io_service& ios );
static void initialize_appenders();

static bool configure_logging( const logging_config& l );

Expand Down
2 changes: 1 addition & 1 deletion libraries/libfc/src/log/dmlog_appender.cpp
Original file line number Diff line number Diff line change
Expand Up @@ -56,7 +56,7 @@ namespace fc {
}
}

void dmlog_appender::initialize( boost::asio::io_service& io_service ) {}
void dmlog_appender::initialize() {}

void dmlog_appender::log( const log_message& m ) {
FILE* out = my->out;
Expand Down
59 changes: 48 additions & 11 deletions libraries/libfc/src/log/gelf_appender.cpp
Original file line number Diff line number Diff line change
Expand Up @@ -8,6 +8,7 @@
#include <fc/io/json.hpp>
#include <fc/crypto/city.hpp>
#include <fc/compress/zlib.hpp>
#include <fc/log/logger_config.hpp>

#include <boost/lexical_cast.hpp>
#include <iomanip>
Expand Down Expand Up @@ -42,10 +43,15 @@ namespace fc
class gelf_appender::impl
{
public:
using work_guard_t = boost::asio::executor_work_guard<boost::asio::io_context::executor_type>;
config cfg;
std::optional<boost::asio::ip::udp::endpoint> gelf_endpoint;
std::thread thread;
boost::asio::io_context io_context;
work_guard_t work_guard = boost::asio::make_work_guard(io_context);
udp_socket gelf_socket;


impl(const variant& c)
{
mutable_variant_object mvo;
Expand Down Expand Up @@ -73,6 +79,10 @@ namespace fc

~impl()
{
if (thread.joinable()) {
work_guard.reset();
thread.join();
}
}
};

Expand All @@ -81,7 +91,7 @@ namespace fc
{
}

void gelf_appender::initialize(boost::asio::io_service &io_service)
void gelf_appender::initialize()
{
try
{
Expand All @@ -100,14 +110,19 @@ namespace fc
string::size_type colon_pos = my->cfg.endpoint.find(':');
try
{
uint16_t port = boost::lexical_cast<uint16_t>(my->cfg.endpoint.substr(colon_pos + 1, my->cfg.endpoint.size()));
FC_ASSERT(colon_pos != std::string::npos, "The logging destination port is not specified");
string port = my->cfg.endpoint.substr(colon_pos + 1);

string hostname = my->cfg.endpoint.substr( 0, colon_pos );
auto endpoints = resolve(io_service, hostname, port);

boost::asio::ip::udp::resolver resolver{ my->io_context };
auto endpoints = resolver.resolve(hostname, port);

if (endpoints.empty())
FC_THROW_EXCEPTION(unknown_host_exception, "The logging destination host name can not be resolved: ${hostname}",
("hostname", hostname));
my->gelf_endpoint = endpoints.back();

my->gelf_endpoint = *endpoints.begin();
}
catch (const boost::bad_lexical_cast&)
{
Expand All @@ -117,9 +132,20 @@ namespace fc

if (my->gelf_endpoint)
{
my->gelf_socket.initialize(io_service);
my->gelf_socket.initialize(my->io_context);
my->gelf_socket.open();
std::cerr << "opened GELF socket to endpoint " << my->cfg.endpoint << "\n";

my->thread = std::thread([this] {
heifner marked this conversation as resolved.
Show resolved Hide resolved
try {
fc::set_os_thread_name("gelf");
my->io_context.run();
} catch (std::exception& ex) {
fprintf(stderr, "GELF logger caught exception at %s:%d : %s\n", __FILE__, __LINE__, ex.what());
} catch (...) {
fprintf(stderr, "GELF logger caught exception unknown exception %s:%d\n", __FILE__, __LINE__);
}
});
}
}
catch (...)
Expand All @@ -131,20 +157,15 @@ namespace fc
gelf_appender::~gelf_appender()
{}

void gelf_appender::log(const log_message& message)
void do_log(gelf_appender::impl* my, uint64_t time_ns, const log_message& message)
{
if (!my->gelf_endpoint)
return;

log_context context = message.get_context();

mutable_variant_object gelf_message;
gelf_message["version"] = "1.1";
gelf_message["host"] = my->cfg.host;
gelf_message["short_message"] = format_string(message.get_format(), message.get_data(), true);

// use now() instead of context.get_timestamp() because log_message construction can include user provided long running calls
const auto time_ns = time_point::now().time_since_epoch().count();
gelf_message["timestamp"] = time_ns / 1000000.;
gelf_message["_timestamp_ns"] = time_ns;

Expand Down Expand Up @@ -248,4 +269,20 @@ namespace fc
FC_ASSERT(number_of_packets_sent == total_number_of_packets);
}
}

void gelf_appender::log(const log_message& message) {
if (!my->gelf_endpoint)
return;

// use now() instead of context.get_timestamp() because log_message construction can include user provided long running calls
boost::asio::post(my->io_context, [impl = my.get(), time_ns = time_point::now().time_since_epoch().count(), message] () {
try {
do_log(impl, time_ns, message);
} catch (std::exception& ex) {
fprintf(stderr, "GELF logger caught exception at %s:%d : %s\n", __FILE__, __LINE__, ex.what());
} catch (...) {
fprintf(stderr, "GELF logger caught exception unknown exception %s:%d\n", __FILE__, __LINE__);
}
});
}
} // fc
4 changes: 2 additions & 2 deletions libraries/libfc/src/log/logger_config.cpp
Original file line number Diff line number Diff line change
Expand Up @@ -43,10 +43,10 @@ namespace fc {
}
}

void log_config::initialize_appenders( boost::asio::io_service& ios ) {
void log_config::initialize_appenders() {
std::lock_guard g( log_config::get().log_mutex );
for( auto& iter : log_config::get().appender_map )
iter.second->initialize( ios );
iter.second->initialize();
}

void configure_logging( const fc::path& lc ) {
Expand Down
6 changes: 3 additions & 3 deletions programs/keosd/main.cpp
Original file line number Diff line number Diff line change
Expand Up @@ -43,14 +43,14 @@ void logging_conf_handler() {
ilog("Received HUP. No log config found at ${p}, setting to default.", ("p", config_path.string()));
}
configure_logging(config_path);
fc::log_config::initialize_appenders(app().get_io_service());
fc::log_config::initialize_appenders();
}

void initialize_logging() {
auto config_path = app().get_logging_conf();
if (fc::exists(config_path))
fc::configure_logging(config_path); // intentionally allowing exceptions to escape
fc::log_config::initialize_appenders(app().get_io_service());
fc::log_config::initialize_appenders();

app().set_sighup_callback(logging_conf_handler);
}
Expand All @@ -75,7 +75,7 @@ int main(int argc, char** argv)
{
try {
appbase::scoped_app app;

app->set_version_string(eosio::version::version_client());
app->set_full_version_string(eosio::version::version_full());
bfs::path home = determine_home_directory();
Expand Down
4 changes: 2 additions & 2 deletions programs/nodeos/main.cpp
Original file line number Diff line number Diff line change
Expand Up @@ -75,7 +75,7 @@ void logging_conf_handler()
ilog( "Received HUP. No log config found at ${p}, setting to default.", ("p", config_path.string()) );
}
::detail::configure_logging( config_path );
fc::log_config::initialize_appenders( app().get_io_service() );
fc::log_config::initialize_appenders();
}

void initialize_logging()
Expand All @@ -89,7 +89,7 @@ void initialize_logging()
fc::configure_logging( ::detail::add_deep_mind_logger(cfg) );
}

fc::log_config::initialize_appenders( app().get_io_service() );
fc::log_config::initialize_appenders();

app().set_sighup_callback(logging_conf_handler);
}
Expand Down