/******************************************************************************** * Copyright (C) 2014-2019 GSI Helmholtzzentrum fuer Schwerionenforschung GmbH * * * * This software is distributed under the terms of the * * GNU Lesser General Public Licence (LGPL) version 3, * * copied verbatim in the file "LICENSE" * ********************************************************************************/ #include "Logger.h" #if FMT_VERSION < 60000 #include #else #include #endif #include // printf #include #include // std::back_inserter using namespace std; namespace fair { using VSpec = VerbositySpec; bool Logger::fColored = false; fstream Logger::fFileStream; Verbosity Logger::fVerbosity = Verbosity::low; Severity Logger::fConsoleSeverity = Severity::FAIR_MIN_SEVERITY > Severity::info ? Severity::FAIR_MIN_SEVERITY : Severity::info; Severity Logger::fMinSeverity = Severity::FAIR_MIN_SEVERITY > Severity::info ? Severity::FAIR_MIN_SEVERITY : Severity::info; Severity Logger::fFileSeverity = Severity::nolog; function Logger::fFatalCallback; unordered_map>> Logger::fCustomSinks; mutex Logger::fMtx; bool Logger::fIsDestructed = false; Logger::DestructionHelper fDestructionHelper; #if defined(__APPLE__) || defined(__FreeBSD__) const string Logger::fProcessName = getprogname(); #elif defined(_GNU_SOURCE) const string Logger::fProcessName = program_invocation_short_name; #else const string Logger::fProcessName = "?"; #endif const unordered_map Logger::fVerbosityMap = { { "veryhigh", Verbosity::veryhigh }, { "high", Verbosity::high }, { "medium", Verbosity::medium }, { "low", Verbosity::low }, { "verylow", Verbosity::verylow }, { "VERYHIGH", Verbosity::veryhigh }, { "HIGH", Verbosity::high }, { "MEDIUM", Verbosity::medium }, { "LOW", Verbosity::low }, { "VERYLOW", Verbosity::verylow }, { "user1", Verbosity::user1 }, { "user2", Verbosity::user2 }, { "user3", Verbosity::user3 }, { "user4", Verbosity::user4 } }; const unordered_map Logger::fSeverityMap = { { "nolog", Severity::nolog }, { "NOLOG", Severity::nolog }, { "fatal", Severity::fatal }, { "error", Severity::error }, { "ERROR", Severity::error }, { "alarm", Severity::alarm }, { "important", Severity::important }, { "warn", Severity::warn }, { "WARN", Severity::warn }, { "warning", Severity::warn }, { "WARNING", Severity::warn }, { "state", Severity::state }, { "STATE", Severity::state }, { "info", Severity::info }, { "INFO", Severity::info }, { "detail", Severity::detail }, { "debug", Severity::debug }, { "DEBUG", Severity::debug }, { "debug1", Severity::debug1 }, { "DEBUG1", Severity::debug1 }, { "debug2", Severity::debug2 }, { "DEBUG2", Severity::debug2 }, { "debug3", Severity::debug3 }, { "DEBUG3", Severity::debug3 }, { "debug4", Severity::debug4 }, { "DEBUG4", Severity::debug4 }, { "trace", Severity::trace }, { "TRACE", Severity::trace } }; const array Logger::fSeverityNames = { { "NOLOG", "TRACE", "DEBUG4", "DEBUG3", "DEBUG2", "DEBUG1", "DEBUG", "DETAIL", "INFO", "STATE", "WARN", "IMPORTANT", "ALARM", "ERROR", "FATAL" } }; const array Logger::fVerbosityNames = { { "verylow", "low", "medium", "high", "veryhigh", "user1", "user2", "user3", "user4" } }; map Logger::fVerbosities = { { Verbosity::verylow, VSpec::Make() }, { Verbosity::low, VSpec::Make(VSpec::Info::severity) }, { Verbosity::medium, VSpec::Make(VSpec::Info::timestamp_s, VSpec::Info::severity) }, { Verbosity::high, VSpec::Make(VSpec::Info::process_name, VSpec::Info::timestamp_s, VSpec::Info::severity) }, { Verbosity::veryhigh, VSpec::Make(VSpec::Info::process_name, VSpec::Info::timestamp_us, VSpec::Info::severity, VSpec::Info::file_line_function) }, { Verbosity::user1, VSpec::Make(VSpec::Info::severity) }, { Verbosity::user2, VSpec::Make(VSpec::Info::severity) }, { Verbosity::user3, VSpec::Make(VSpec::Info::severity) }, { Verbosity::user4, VSpec::Make(VSpec::Info::severity) } }; 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.file = file.substr(pos + 1); fInfos.line = line; fInfos.func = func; fInfos.severity_name = fSeverityNames.at(static_cast(severity)); fInfos.severity = severity; auto spec = fVerbosities[verbosity]; if ((!fColored && LoggingToConsole()) || LoggingToFile()) { for (const auto info : spec.fInfos) { switch (info) { case VSpec::Info::process_name: fmt::format_to(std::back_inserter(fBWPrefix), "[{}]", fInfos.process_name); break; case VSpec::Info::timestamp_us: FillTimeInfos(); fmt::format_to(std::back_inserter(fBWPrefix), "[{:%H:%M:%S}.{:06}]", fmt::localtime(fInfos.timestamp), fInfos.us.count()); break; case VSpec::Info::timestamp_s: FillTimeInfos(); fmt::format_to(std::back_inserter(fBWPrefix), "[{:%H:%M:%S}]", fmt::localtime(fInfos.timestamp)); break; case VSpec::Info::severity: fmt::format_to(std::back_inserter(fBWPrefix), "[{}]", fInfos.severity_name); break; case VSpec::Info::file_line_function: fmt::format_to(std::back_inserter(fBWPrefix), "[{}:{}:{}]", fInfos.file, fInfos.line, fInfos.func); break; case VSpec::Info::file_line: fmt::format_to(std::back_inserter(fBWPrefix), "[{}:{}]", fInfos.file, fInfos.line); break; case VSpec::Info::file: fmt::format_to(std::back_inserter(fBWPrefix), "[{}]", fInfos.file); break; default: break; } } if (spec.fSize > 0) { fmt::format_to(std::back_inserter(fBWPrefix), " "); } } if (fColored && LoggingToConsole()) { for (const auto info : spec.fInfos) { switch (info) { case VSpec::Info::process_name: fmt::format_to(std::back_inserter(fColorPrefix), "[{}]", ColorOut(Color::fgBlue, fInfos.process_name)); break; case VSpec::Info::timestamp_us: FillTimeInfos(); fmt::format_to(std::back_inserter(fColorPrefix), "[{}{:%H:%M:%S}.{:06}{}]", startColor(Color::fgCyan), fmt::localtime(fInfos.timestamp), fInfos.us.count(), endColor()); break; case VSpec::Info::timestamp_s: FillTimeInfos(); fmt::format_to(std::back_inserter(fColorPrefix), "[{}{:%H:%M:%S}{}]", startColor(Color::fgCyan), fmt::localtime(fInfos.timestamp), endColor()); break; case VSpec::Info::severity: fmt::format_to(std::back_inserter(fColorPrefix), "[{}]", GetColoredSeverityString(fInfos.severity)); break; case VSpec::Info::file_line_function: fmt::format_to(std::back_inserter(fColorPrefix), "[{}:{}:{}]", ColorOut(Color::fgBlue, fInfos.file), ColorOut(Color::fgYellow, fInfos.line), ColorOut(Color::fgBlue, fInfos.func)); break; case VSpec::Info::file_line: fmt::format_to(std::back_inserter(fColorPrefix), "[{}:{}]", ColorOut(Color::fgBlue, fInfos.file), ColorOut(Color::fgYellow, fInfos.line)); break; case VSpec::Info::file: fmt::format_to(std::back_inserter(fColorPrefix), "[{}]", ColorOut(Color::fgBlue, fInfos.file)); break; default: break; } } if (spec.fSize > 0) { fmt::format_to(std::back_inserter(fColorPrefix), " "); } } if (!fCustomSinks.empty()) { FillTimeInfos(); } } } Logger::~Logger() noexcept(false) { if (fIsDestructed) { printf("post-static destruction output: %s\n", fContent.str().c_str()); return; } for (auto& it : fCustomSinks) { if (LoggingCustom(it.second.first)) { lock_guard lock(fMtx); it.second.second(fContent.str(), fInfos); } } // "\n" + flush instead of endl makes output thread safe. if (LoggingToConsole()) { if (fColored) { fmt::print("{}{}\n", to_string(fColorPrefix), fContent.str()); } else { fmt::print("{}{}\n", to_string(fBWPrefix), fContent.str()); } cout << flush; } if (LoggingToFile()) { lock_guard lock(fMtx); if (fFileStream.is_open()) { fFileStream << fmt::format("{}{}\n", to_string(fBWPrefix), fContent.str()) << flush; } } if (fInfos.severity == Severity::fatal) { if (fFatalCallback) { fFatalCallback(); } } } void Logger::LogEmptyLine() { // do nothing, line break is added by the destructor // this call just to prevent any output to be added to the logger object } string Logger::GetColoredSeverityString(Severity severity) { switch (severity) { case Severity::nolog: return "\033[01;39mNOLOG\033[0m"; break; case Severity::fatal: return "\033[01;31mFATAL\033[0m"; break; case Severity::error: return "\033[01;31mERROR\033[0m"; break; case Severity::alarm: return "\033[01;33mALARM\033[0m"; break; case Severity::important: return "\033[01;32mIMPORTANT\033[0m"; break; case Severity::warn: return "\033[01;33mWARN\033[0m"; break; case Severity::state: return "\033[01;35mSTATE\033[0m"; break; case Severity::info: return "\033[01;32mINFO\033[0m"; break; case Severity::detail: return "\033[01;32mDETAIL\033[0m"; break; case Severity::debug: return "\033[01;34mDEBUG\033[0m"; break; case Severity::debug1: return "\033[01;34mDEBUG1\033[0m"; break; case Severity::debug2: return "\033[01;34mDEBUG2\033[0m"; break; case Severity::debug3: return "\033[01;34mDEBUG3\033[0m"; break; case Severity::debug4: return "\033[01;34mDEBUG4\033[0m"; break; case Severity::trace: return "\033[01;36mTRACE\033[0m"; break; default: return "UNKNOWN"; break; } } void Logger::SetConsoleSeverity(const Severity severity) { if (severity < Severity::FAIR_MIN_SEVERITY && severity != Severity::nolog) { cout << "Requested severity is higher than the enabled compile-time FAIR_MIN_SEVERITY (" << Severity::FAIR_MIN_SEVERITY << "), ignoring" << endl; return; } fConsoleSeverity = severity; UpdateMinSeverity(); } void Logger::SetConsoleSeverity(const string& severityStr) { if (fSeverityMap.count(severityStr)) { SetConsoleSeverity(fSeverityMap.at(severityStr)); } else { LOG(error) << "Unknown severity setting: '" << severityStr << "', setting to default 'info'."; SetConsoleSeverity(Severity::info); } } Severity Logger::GetConsoleSeverity() { return fConsoleSeverity; } void Logger::SetFileSeverity(const Severity severity) { if (severity < Severity::FAIR_MIN_SEVERITY && severity != Severity::nolog) { cout << "Requested severity is higher than the enabled compile-time FAIR_MIN_SEVERITY (" << Severity::FAIR_MIN_SEVERITY << "), ignoring" << endl; return; } fFileSeverity = severity; UpdateMinSeverity(); } void Logger::SetFileSeverity(const string& severityStr) { if (fSeverityMap.count(severityStr)) { SetFileSeverity(fSeverityMap.at(severityStr)); } else { LOG(error) << "Unknown severity setting: '" << severityStr << "', setting to default 'info'."; SetFileSeverity(Severity::info); } } void Logger::SetCustomSeverity(const string& key, const Severity severity) { try { if (severity < Severity::FAIR_MIN_SEVERITY && severity != Severity::nolog) { cout << "Requested severity is higher than the enabled compile-time FAIR_MIN_SEVERITY (" << Severity::FAIR_MIN_SEVERITY << "), ignoring" << endl; return; } fCustomSinks.at(key).first = severity; UpdateMinSeverity(); } catch (const out_of_range& oor) { LOG(error) << "No custom sink with id '" << key << "' found"; throw; } } void Logger::SetCustomSeverity(const string& key, const string& severityStr) { if (fSeverityMap.count(severityStr)) { SetCustomSeverity(key, fSeverityMap.at(severityStr)); } else { LOG(error) << "Unknown severity setting: '" << severityStr << "', setting to default 'info'."; SetCustomSeverity(key, Severity::info); } } Severity Logger::GetCustomSeverity(const std::string& key) { try { return fCustomSinks.at(key).first; } catch (const out_of_range& oor) { LOG(error) << "No custom sink with id '" << key << "' found"; throw; } } void Logger::CycleConsoleSeverityUp() { int current = static_cast(fConsoleSeverity); if (current == static_cast(fSeverityNames.size()) - 1) { SetConsoleSeverity(Severity::FAIR_MIN_SEVERITY); } else { SetConsoleSeverity(static_cast(current + 1)); } int newCurrent = static_cast(fConsoleSeverity); stringstream ss; for (int i = 0; i < static_cast(fSeverityNames.size()); ++i) { ss << (i == newCurrent ? "<" : " ") << fSeverityNames.at(i) << (i == newCurrent ? ">" : " "); } ss << "\n\n"; cout << ss.str() << flush; } void Logger::CycleConsoleSeverityDown() { int current = static_cast(fConsoleSeverity); if (current == static_cast(Severity::FAIR_MIN_SEVERITY)) { SetConsoleSeverity(static_cast(fSeverityNames.size() - 1)); } else { SetConsoleSeverity(static_cast(current - 1)); } int newCurrent = static_cast(fConsoleSeverity); stringstream ss; for (int i = 0; i < static_cast(fSeverityNames.size()); ++i) { ss << (i == newCurrent ? "<" : " ") << fSeverityNames.at(i) << (i == newCurrent ? ">" : " "); } ss << "\n\n"; cout << ss.str() << flush; } void Logger::CycleVerbosityUp() { int current = static_cast(fVerbosity); if (current == static_cast(fVerbosityNames.size() - 1)) { SetVerbosity(static_cast(0)); } else { SetVerbosity(static_cast(current + 1)); } int newCurrent = static_cast(fVerbosity); stringstream ss; for (int i = 0; i < static_cast(fVerbosityNames.size()); ++i) { ss << (i == newCurrent ? "<" : " ") << fVerbosityNames.at(i) << (i == newCurrent ? ">" : " "); } ss << "\n\n"; cout << ss.str() << flush; } void Logger::CycleVerbosityDown() { int current = static_cast(fVerbosity); if (current == 0) { SetVerbosity(static_cast(fVerbosityNames.size() - 1)); } else { SetVerbosity(static_cast(current - 1)); } int newCurrent = static_cast(fVerbosity); stringstream ss; for (int i = 0; i < static_cast(fVerbosityNames.size()); ++i) { ss << (i == newCurrent ? "<" : " ") << fVerbosityNames.at(i) << (i == newCurrent ? ">" : " "); } ss << "\n\n"; cout << ss.str() << flush; } void Logger::UpdateMinSeverity() { if (fFileSeverity == Severity::nolog) { fMinSeverity = fConsoleSeverity; } else { fMinSeverity = std::max(fConsoleSeverity, fFileSeverity); } for (auto& it : fCustomSinks) { if (fMinSeverity == Severity::nolog) { fMinSeverity = std::max(fMinSeverity, it.second.first); } else if (it.second.first != Severity::nolog) { fMinSeverity = std::min(fMinSeverity, it.second.first); } } } bool Logger::Logging(const string& severityStr) { if (fSeverityMap.count(severityStr)) { return Logging(fSeverityMap.at(severityStr)); } else { LOG(error) << "Unknown severity setting: '" << severityStr; return false; } } void Logger::SetVerbosity(const Verbosity verbosity) { fVerbosity = verbosity; } void Logger::SetVerbosity(const string& verbosityStr) { if (fVerbosityMap.count(verbosityStr)) { fVerbosity = fVerbosityMap.at(verbosityStr); } else { LOG(error) << "Unknown verbosity setting: '" << verbosityStr << "', setting to default 'low'."; fVerbosity = Verbosity::low; } } Verbosity Logger::GetVerbosity() { return fVerbosity; } void Logger::DefineVerbosity(const Verbosity verbosity, const VerbositySpec spec) { fVerbosities[verbosity] = spec; } void Logger::DefineVerbosity(const string& verbosityStr, const VerbositySpec spec) { if (fVerbosityMap.count(verbosityStr)) { DefineVerbosity(fVerbosityMap.at(verbosityStr), spec); } else { LOG(error) << "Unknown verbosity: '" << verbosityStr; } } void Logger::SetConsoleColor(const bool colored) { fColored = colored; } string Logger::InitFileSink(const Severity severity, const string& filename, bool customizeName) { lock_guard lock(fMtx); if (fFileStream.is_open()) { fFileStream.close(); } string fullName = filename; if (customizeName) { // TODO: customize file name auto now = chrono::system_clock::to_time_t(chrono::system_clock::now()); stringstream ss; ss << "_"; char tsstr[32]; if (strftime(tsstr, sizeof(tsstr), "%Y-%m-%d_%H_%M_%S", localtime(&now))) { ss << tsstr; } ss << ".log"; fullName += ss.str(); } fFileStream.open(fullName, fstream::out | fstream::app); if (fFileStream.is_open()) { if (severity < Severity::FAIR_MIN_SEVERITY && severity != Severity::nolog) { cout << "Requested file sink severity is higher than the enabled compile-time FAIR_MIN_SEVERITY (" << Severity::FAIR_MIN_SEVERITY << "), setting to " << Severity::FAIR_MIN_SEVERITY << endl; fFileSeverity = Severity::FAIR_MIN_SEVERITY; } else { fFileSeverity = severity; } UpdateMinSeverity(); } else { cout << "Error opening file: " << fullName; } return fullName; } string Logger::InitFileSink(const string& severityStr, const string& filename, bool customizeName) { if (fSeverityMap.count(severityStr)) { return InitFileSink(fSeverityMap.at(severityStr), filename, customizeName); } else { LOG(error) << "Unknown severity setting: '" << severityStr << "', setting to default 'info'."; return InitFileSink(Severity::info, filename); } } void Logger::RemoveFileSink() { lock_guard lock(fMtx); if (fFileStream.is_open()) { fFileStream.close(); fFileSeverity = Severity::nolog; UpdateMinSeverity(); } } bool Logger::LoggingToConsole() const { return (fInfos.severity >= fConsoleSeverity && fConsoleSeverity > Severity::nolog) || fInfos.severity == Severity::fatal; } bool Logger::LoggingToFile() const { return (fInfos.severity >= fFileSeverity && fFileSeverity > Severity::nolog) || fInfos.severity == Severity::fatal; } bool Logger::LoggingCustom(const Severity severity) const { return (fInfos.severity >= severity && severity > Severity::nolog) || fInfos.severity == Severity::fatal; } void Logger::OnFatal(function func) { fFatalCallback = func; } void Logger::AddCustomSink(const string& key, Severity severity, function func) { lock_guard lock(fMtx); if (fCustomSinks.count(key) == 0) { if (severity < Severity::FAIR_MIN_SEVERITY && severity != Severity::nolog) { cout << "Requested custom sink severity is higher than the enabled compile-time FAIR_MIN_SEVERITY (" << Severity::FAIR_MIN_SEVERITY << "), setting to " << Severity::FAIR_MIN_SEVERITY << endl; fCustomSinks.insert(make_pair(key, make_pair(Severity::FAIR_MIN_SEVERITY, func))); } else { fCustomSinks.insert(make_pair(key, make_pair(severity, func))); } UpdateMinSeverity(); } else { cout << "Logger::AddCustomSink: sink '" << key << "' already exists, will not add again. Remove first with Logger::RemoveCustomSink(const string& key)" << endl; throw runtime_error("Adding a sink with a key that already exists. Remove first."); } } void Logger::AddCustomSink(const string& key, const string& severityStr, function func) { if (fSeverityMap.count(severityStr)) { AddCustomSink(key, fSeverityMap.at(severityStr), func); } else { LOG(error) << "Unknown severity setting: '" << severityStr << "', setting to default 'info'."; AddCustomSink(key, Severity::info, func); } } void Logger::RemoveCustomSink(const string& key) { if (fCustomSinks.count(key) > 0) { fCustomSinks.erase(key); UpdateMinSeverity(); } else { cout << "Logger::RemoveCustomSink: sink '" << key << "' doesn't exists, will not remove." << endl; throw runtime_error("Trying to remove a sink with a key that does not exist."); } } Logger& Logger::operator<<(ios_base& (*manip) (ios_base&)) { fContent << manip; return *this; } Logger& Logger::operator<<(ostream& (*manip) (ostream&)) { fContent << manip; return *this; } void Logger::FillTimeInfos() { if (!fTimeCalculated) { chrono::time_point now = chrono::system_clock::now(); fInfos.timestamp = chrono::system_clock::to_time_t(now); fInfos.us = chrono::duration_cast(now.time_since_epoch()) % 1000000; fTimeCalculated = true; } } } // namespace fair