Optimize timestamps and colored severity output

This commit is contained in:
Alexey Rybalchenko 2019-08-21 14:43:33 +02:00 committed by Mohammad Al-Turany
parent a5f3e95238
commit afb468406a
2 changed files with 96 additions and 92 deletions

View File

@ -17,60 +17,53 @@ using namespace std;
namespace fair namespace fair
{ {
class ColoredSeverityWriter using VSpec = VerbositySpec;
{
public:
ColoredSeverityWriter(Severity severity) : fSeverity(severity) {}
friend ostream& operator<<(ostream& os, const ColoredSeverityWriter& w) string GetColoredSeverityString(Severity severity)
{ {
switch (w.fSeverity) { switch (severity) {
case Severity::nolog: case Severity::nolog:
return os << "\033[01;" << static_cast<int>(Logger::Color::fgDefault) << "m" << Logger::SeverityName(w.fSeverity) << "\033[0m"; return "\033[01;39mNOLOG\033[0m";
break; break;
case Severity::fatal: case Severity::fatal:
return os << "\033[01;" << static_cast<int>(Logger::Color::bgRed) << "m" << Logger::SeverityName(w.fSeverity) << "\033[0m"; return "\033[01;31mFATAL\033[0m";
break; break;
case Severity::error: case Severity::error:
return os << "\033[01;" << static_cast<int>(Logger::Color::fgRed) << "m" << Logger::SeverityName(w.fSeverity) << "\033[0m"; return "\033[01;39mERROR\033[0m";
break; break;
case Severity::warn: case Severity::warn:
return os << "\033[01;" << static_cast<int>(Logger::Color::fgYellow) << "m" << Logger::SeverityName(w.fSeverity) << "\033[0m"; return "\033[01;33mWARN\033[0m";
break; break;
case Severity::state: case Severity::state:
return os << "\033[01;" << static_cast<int>(Logger::Color::fgMagenta) << "m" << Logger::SeverityName(w.fSeverity) << "\033[0m"; return "\033[01;35mSTATE\033[0m";
break; break;
case Severity::info: case Severity::info:
return os << "\033[01;" << static_cast<int>(Logger::Color::fgGreen) << "m" << Logger::SeverityName(w.fSeverity) << "\033[0m"; return "\033[01;32mINFO\033[0m";
break; break;
case Severity::debug: case Severity::debug:
return os << "\033[01;" << static_cast<int>(Logger::Color::fgBlue) << "m" << Logger::SeverityName(w.fSeverity) << "\033[0m"; return "\033[01;34mDEBUG\033[0m";
break; break;
case Severity::debug1: case Severity::debug1:
return os << "\033[01;" << static_cast<int>(Logger::Color::fgBlue) << "m" << Logger::SeverityName(w.fSeverity) << "\033[0m"; return "\033[01;34mDEBUG1\033[0m";
break; break;
case Severity::debug2: case Severity::debug2:
return os << "\033[01;" << static_cast<int>(Logger::Color::fgBlue) << "m" << Logger::SeverityName(w.fSeverity) << "\033[0m"; return "\033[01;34mDEBUG2\033[0m";
break; break;
case Severity::debug3: case Severity::debug3:
return os << "\033[01;" << static_cast<int>(Logger::Color::fgBlue) << "m" << Logger::SeverityName(w.fSeverity) << "\033[0m"; return "\033[01;34mDEBUG3\033[0m";
break; break;
case Severity::debug4: case Severity::debug4:
return os << "\033[01;" << static_cast<int>(Logger::Color::fgBlue) << "m" << Logger::SeverityName(w.fSeverity) << "\033[0m"; return "\033[01;34mDEBUG4\033[0m";
break; break;
case Severity::trace: case Severity::trace:
return os << "\033[01;" << static_cast<int>(Logger::Color::fgCyan) << "m" << Logger::SeverityName(w.fSeverity) << "\033[0m"; return "\033[01;36mTRACE\033[0m";
break; break;
default: default:
return os << "UNKNOWN"; return "UNKNOWN";
break; break;
} }
} }
private:
Severity fSeverity;
};
bool Logger::fColored = false; bool Logger::fColored = false;
fstream Logger::fFileStream; fstream Logger::fFileStream;
Verbosity Logger::fVerbosity = Verbosity::low; Verbosity Logger::fVerbosity = Verbosity::low;
@ -170,41 +163,41 @@ const array<string, 9> Logger::fVerbosityNames =
} }
}; };
map<Verbosity, VerbositySpec> Logger::fVerbosities = map<Verbosity, VSpec> Logger::fVerbosities =
{ {
{ Verbosity::verylow, VerbositySpec::Make() }, { Verbosity::verylow, VSpec::Make() },
{ Verbosity::low, VerbositySpec::Make(VerbositySpec::Info::severity) }, { Verbosity::low, VSpec::Make(VSpec::Info::severity) },
{ Verbosity::medium, VerbositySpec::Make(VerbositySpec::Info::timestamp_s, VerbositySpec::Info::severity) }, { Verbosity::medium, VSpec::Make(VSpec::Info::timestamp_s, VSpec::Info::severity) },
{ Verbosity::high, VerbositySpec::Make(VerbositySpec::Info::process_name, VerbositySpec::Info::timestamp_s, VerbositySpec::Info::severity) }, { Verbosity::high, VSpec::Make(VSpec::Info::process_name, VSpec::Info::timestamp_s, VSpec::Info::severity) },
{ Verbosity::veryhigh, VerbositySpec::Make(VerbositySpec::Info::process_name, VerbositySpec::Info::timestamp_us, VerbositySpec::Info::severity, VerbositySpec::Info::file_line_function) }, { Verbosity::veryhigh, VSpec::Make(VSpec::Info::process_name, VSpec::Info::timestamp_us, VSpec::Info::severity, VSpec::Info::file_line_function) },
{ Verbosity::user1, VerbositySpec::Make(VerbositySpec::Info::severity) }, { Verbosity::user1, VSpec::Make(VSpec::Info::severity) },
{ Verbosity::user2, VerbositySpec::Make(VerbositySpec::Info::severity) }, { Verbosity::user2, VSpec::Make(VSpec::Info::severity) },
{ Verbosity::user3, VerbositySpec::Make(VerbositySpec::Info::severity) }, { Verbosity::user3, VSpec::Make(VSpec::Info::severity) },
{ Verbosity::user4, VerbositySpec::Make(VerbositySpec::Info::severity) } { Verbosity::user4, VSpec::Make(VSpec::Info::severity) }
}; };
string Logger::SeverityName(Severity severity)
{
return fSeverityNames.at(static_cast<size_t>(severity));
}
string Logger::VerbosityName(Verbosity verbosity)
{
return fVerbosityNames.at(static_cast<size_t>(verbosity));
}
Logger::Logger(Severity severity, const string& file, const string& line, const string& func) Logger::Logger(Severity severity, const string& file, const string& line, const string& func)
: Logger(severity, fVerbosity, file, line, func) : Logger(severity, fVerbosity, file, line, func)
{} {}
Logger::Logger(Severity severity, Verbosity verbosity, const string& file, const string& line, const string& func) void Logger::FillTimeInfos()
{ {
if (!fIsDestructed) { if (!fTimeCalculated) {
chrono::time_point<chrono::system_clock> now = chrono::system_clock::now(); chrono::time_point<chrono::system_clock> now = chrono::system_clock::now();
size_t pos = file.rfind("/");
fInfos.timestamp = chrono::system_clock::to_time_t(now); fInfos.timestamp = chrono::system_clock::to_time_t(now);
fInfos.us = chrono::duration_cast<chrono::microseconds>(now.time_since_epoch()) % 1000000; fInfos.us = chrono::duration_cast<chrono::microseconds>(now.time_since_epoch()) % 1000000;
fTimeCalculated = true;
}
}
Logger::Logger(Severity severity, Verbosity verbosity, const string& file, const string& line, const string& func)
: fTimeCalculated(false)
{
if (!fIsDestructed) {
size_t pos = file.rfind("/");
// fInfos.timestamp is filled conditionally
// fInfos.us is filled conditionally
fInfos.process_name = fProcessName; fInfos.process_name = fProcessName;
fInfos.file = file.substr(pos + 1); fInfos.file = file.substr(pos + 1);
fInfos.line = line; fInfos.line = line;
@ -217,25 +210,27 @@ Logger::Logger(Severity severity, Verbosity verbosity, const string& file, const
if ((!fColored && LoggingToConsole()) || LoggingToFile()) { if ((!fColored && LoggingToConsole()) || LoggingToFile()) {
for (const auto info : spec.fInfos) { for (const auto info : spec.fInfos) {
switch (info) { switch (info) {
case VerbositySpec::Info::process_name: case VSpec::Info::process_name:
fBWOut << fmt::format("[{}]", fInfos.process_name); fBWOut << fmt::format("[{}]", fInfos.process_name);
break; break;
case VerbositySpec::Info::timestamp_us: case VSpec::Info::timestamp_us:
FillTimeInfos();
fBWOut << fmt::format("[{:%H:%M:%S}.{:06}]", fmt::localtime(fInfos.timestamp), fInfos.us.count()); fBWOut << fmt::format("[{:%H:%M:%S}.{:06}]", fmt::localtime(fInfos.timestamp), fInfos.us.count());
break; break;
case VerbositySpec::Info::timestamp_s: case VSpec::Info::timestamp_s:
FillTimeInfos();
fBWOut << fmt::format("[{:%H:%M:%S}]", fmt::localtime(fInfos.timestamp)); fBWOut << fmt::format("[{:%H:%M:%S}]", fmt::localtime(fInfos.timestamp));
break; break;
case VerbositySpec::Info::severity: case VSpec::Info::severity:
fBWOut << fmt::format("[{}]", fInfos.severity_name); fBWOut << fmt::format("[{}]", fInfos.severity_name);
break; break;
case VerbositySpec::Info::file_line_function: case VSpec::Info::file_line_function:
fBWOut << fmt::format("[{}:{}:{}]", fInfos.file, fInfos.line, fInfos.func); fBWOut << fmt::format("[{}:{}:{}]", fInfos.file, fInfos.line, fInfos.func);
break; break;
case VerbositySpec::Info::file_line: case VSpec::Info::file_line:
fBWOut << fmt::format("[{}:{}]", fInfos.file, fInfos.line); fBWOut << fmt::format("[{}:{}]", fInfos.file, fInfos.line);
break; break;
case VerbositySpec::Info::file: case VSpec::Info::file:
fBWOut << fmt::format("[{}]", fInfos.file); fBWOut << fmt::format("[{}]", fInfos.file);
break; break;
default: default:
@ -251,25 +246,27 @@ Logger::Logger(Severity severity, Verbosity verbosity, const string& file, const
if (fColored && LoggingToConsole()) { if (fColored && LoggingToConsole()) {
for (const auto info : spec.fInfos) { for (const auto info : spec.fInfos) {
switch (info) { switch (info) {
case VerbositySpec::Info::process_name: case VSpec::Info::process_name:
fColorOut << fmt::format("[{}]", ColorOut(Color::fgBlue, fInfos.process_name)); fColorOut << fmt::format("[{}]", ColorOut(Color::fgBlue, fInfos.process_name));
break; break;
case VerbositySpec::Info::timestamp_us: case VSpec::Info::timestamp_us:
FillTimeInfos();
fColorOut << fmt::format("[{}{:%H:%M:%S}.{:06}{}]", startColor(Color::fgCyan), fmt::localtime(fInfos.timestamp), fInfos.us.count(), endColor()); fColorOut << fmt::format("[{}{:%H:%M:%S}.{:06}{}]", startColor(Color::fgCyan), fmt::localtime(fInfos.timestamp), fInfos.us.count(), endColor());
break; break;
case VerbositySpec::Info::timestamp_s: case VSpec::Info::timestamp_s:
FillTimeInfos();
fColorOut << fmt::format("[{}{:%H:%M:%S}{}]", startColor(Color::fgCyan), fmt::localtime(fInfos.timestamp), endColor()); fColorOut << fmt::format("[{}{:%H:%M:%S}{}]", startColor(Color::fgCyan), fmt::localtime(fInfos.timestamp), endColor());
break; break;
case VerbositySpec::Info::severity: case VSpec::Info::severity:
fColorOut << fmt::format("[{}]", ColoredSeverityWriter(fInfos.severity)); fColorOut << fmt::format("[{}]", GetColoredSeverityString(fInfos.severity));
break; break;
case VerbositySpec::Info::file_line_function: case VSpec::Info::file_line_function:
fColorOut << fmt::format("[{}:{}:{}]", ColorOut(Color::fgBlue, fInfos.file), ColorOut(Color::fgYellow, fInfos.line), ColorOut(Color::fgBlue, fInfos.func)); fColorOut << fmt::format("[{}:{}:{}]", ColorOut(Color::fgBlue, fInfos.file), ColorOut(Color::fgYellow, fInfos.line), ColorOut(Color::fgBlue, fInfos.func));
break; break;
case VerbositySpec::Info::file_line: case VSpec::Info::file_line:
fColorOut << fmt::format("[{}:{}]", ColorOut(Color::fgBlue, fInfos.file), ColorOut(Color::fgYellow, fInfos.line)); fColorOut << fmt::format("[{}:{}]", ColorOut(Color::fgBlue, fInfos.file), ColorOut(Color::fgYellow, fInfos.line));
break; break;
case VerbositySpec::Info::file: case VSpec::Info::file:
fColorOut << fmt::format("[{}]", ColorOut(Color::fgBlue, fInfos.file)); fColorOut << fmt::format("[{}]", ColorOut(Color::fgBlue, fInfos.file));
break; break;
default: default:
@ -282,6 +279,10 @@ Logger::Logger(Severity severity, Verbosity verbosity, const string& file, const
} }
} }
if (!fCustomSinks.empty()) {
FillTimeInfos();
}
} }
} }

View File

@ -293,8 +293,8 @@ class Logger
static void RemoveFileSink(); static void RemoveFileSink();
static std::string SeverityName(Severity); static std::string SeverityName(Severity s) { return fSeverityNames.at(static_cast<size_t>(s)); }
static std::string VerbosityName(Verbosity); static std::string VerbosityName(Verbosity v) { return fVerbosityNames.at(static_cast<size_t>(v)); }
static void OnFatal(std::function<void()> func); static void OnFatal(std::function<void()> func);
@ -365,6 +365,9 @@ class Logger
static void UpdateMinSeverity(); static void UpdateMinSeverity();
void FillTimeInfos();
bool fTimeCalculated;
static std::map<Verbosity, VerbositySpec> fVerbosities; static std::map<Verbosity, VerbositySpec> fVerbosities;
}; };