Permalink
Browse files

Adds a logging framework (#671)

  • Loading branch information...
rahul003 authored and alsrgv committed Jan 4, 2019
1 parent 30706dc commit 6a933cd4c60f7eae5816aa380adefda5b70ef3cf
@@ -0,0 +1,95 @@
#include <chrono>
#include <algorithm>
#include <iostream>
#include <iomanip>

#include "logging.h"

namespace horovod {
namespace common {

LogMessage::LogMessage(const char* fname, int line, LogLevel severity)
: fname_(fname), line_(line), severity_(severity) {}

void LogMessage::GenerateLogMessage(bool log_time) {
bool use_cout = static_cast<int>(severity_) <= static_cast<int>(LogLevel::INFO);
std::ostream& os = use_cout ? std::cout : std::cerr;
if (log_time) {
auto now = std::chrono::system_clock::now();
auto as_time_t = std::chrono::system_clock::to_time_t(now);

auto duration = now.time_since_epoch();
auto seconds = std::chrono::duration_cast<std::chrono::seconds>(duration);
auto micros_remainder = std::chrono::duration_cast<std::chrono::microseconds>(duration - seconds);

const size_t time_buffer_size = 30;
char time_buffer[time_buffer_size];
strftime(time_buffer, time_buffer_size, "%Y-%m-%d %H:%M:%S",
localtime(&as_time_t));
os << "[" << time_buffer << "." << std::setw(6) << micros_remainder.count()
<< ": " << LOG_LEVELS[static_cast<int>(severity_)] << " "
<< fname_ << ":" << line_ << "] " << str() << std::endl;
} else {
os << "[" << LOG_LEVELS[static_cast<int>(severity_)] << " "
<< fname_ << ":" << line_ << "] " << str() << std::endl;
}
}

LogMessage::~LogMessage() {
static LogLevel min_log_level = MinLogLevelFromEnv();
static bool log_time = LogTimeFromEnv();
if (severity_ >= min_log_level) {
GenerateLogMessage(log_time);
}
}

LogMessageFatal::LogMessageFatal(const char* file, int line)
: LogMessage(file, line, LogLevel::FATAL) {}

LogMessageFatal::~LogMessageFatal() {
static bool log_time = LogTimeFromEnv();
GenerateLogMessage(log_time);
abort();
}

LogLevel ParseLogLevelStr(const char* env_var_val) {
std::string min_log_level(env_var_val);
std::transform(min_log_level.begin(), min_log_level.end(), min_log_level.begin(), ::tolower);
if (min_log_level == "trace") {
return LogLevel::TRACE;
} else if (min_log_level == "debug") {
return LogLevel::DEBUG;
} else if (min_log_level == "info") {
return LogLevel::INFO;
} else if (min_log_level == "warning") {
return LogLevel::WARNING;
} else if (min_log_level == "error") {
return LogLevel::ERROR;
} else if (min_log_level == "fatal") {
return LogLevel::FATAL;
} else {
return LogLevel::WARNING;
}
}

LogLevel MinLogLevelFromEnv() {
const char* env_var_val = getenv("HOROVOD_LOG_LEVEL");
if (env_var_val == nullptr) {
// default to WARNING
return LogLevel::WARNING;
}
return ParseLogLevelStr(env_var_val);
}

bool LogTimeFromEnv() {
const char* env_var_val = getenv("HOROVOD_LOG_HIDE_TIME");
if (env_var_val != nullptr &&
std::strtol(env_var_val, nullptr, 10) > 0) {
return false;
} else {
return true;
}
}

}
}
@@ -0,0 +1,59 @@
#include <sstream>
#include <string>

namespace horovod {
namespace common {

enum class LogLevel {
TRACE, DEBUG, INFO, WARNING, ERROR, FATAL
};

#define LOG_LEVELS "TDIWEF"

class LogMessage : public std::basic_ostringstream<char> {
public:
LogMessage(const char* fname, int line, LogLevel severity);
~LogMessage();

protected:
void GenerateLogMessage(bool log_time);

private:
const char* fname_;
int line_;
LogLevel severity_;
};

// LogMessageFatal ensures the process will exit in failure after
// logging this message.
class LogMessageFatal : public LogMessage {
public:
LogMessageFatal(const char* file, int line);
~LogMessageFatal();
};

#define _HVD_LOG_TRACE \
LogMessage(__FILE__, __LINE__, LogLevel::TRACE)
#define _HVD_LOG_DEBUG \
LogMessage(__FILE__, __LINE__, LogLevel::DEBUG)
#define _HVD_LOG_INFO \
LogMessage(__FILE__, __LINE__, LogLevel::INFO)
#define _HVD_LOG_WARNING \
LogMessage(__FILE__, __LINE__, LogLevel::WARNING)
#define _HVD_LOG_ERROR \
LogMessage(__FILE__, __LINE__, LogLevel::ERROR)
#define _HVD_LOG_FATAL \
LogMessageFatal(__FILE__, __LINE__)

#define _LOG(severity) _HVD_LOG_##severity

#define _LOG_RANK(severity, rank) _HVD_LOG_##severity << "[" << rank << "]: "

#define GET_LOG(_1, _2, NAME, ...) NAME
#define LOG(...) GET_LOG(__VA_ARGS__, _LOG_RANK, _LOG)(__VA_ARGS__)

LogLevel MinLogLevelFromEnv();
bool LogTimeFromEnv();

}
}
@@ -251,6 +251,20 @@ const std::vector<std::string>& MPIResponse::tensor_names() const {
return tensor_names_;
}

const std::string MPIResponse::tensor_names_string() const {
std::string result;
bool is_first_name = true;
for (auto const& s : tensor_names_) {
if (!is_first_name) {
result += ", ";
} else {
is_first_name = false;
}
result += s;
}
return result;
}

void MPIResponse::set_tensor_names(const std::vector<std::string>& value) {
tensor_names_ = value;
}
@@ -124,6 +124,7 @@ class MPIResponse {

// Empty if the type is DONE or SHUTDOWN.
const std::vector<std::string>& tensor_names() const;
const std::string tensor_names_string() const;
void set_tensor_names(const std::vector<std::string>& value);
void add_tensor_names(const std::string& value);

Oops, something went wrong.

0 comments on commit 6a933cd

Please sign in to comment.