From 13065dccc45ef46ed48bcdda3c2aba5aad826281 Mon Sep 17 00:00:00 2001 From: Anubhab Date: Thu, 24 Jun 2021 18:59:48 +0530 Subject: [PATCH] Added logging functionality (spdlog) spdlog was added as a submodule All previous logging statements replaced with new logger .github/workflows/ci.yml was updated to initialise submodules recursively --- .github/workflows/ci.yml | 2 + .gitmodules | 3 ++ CMakeLists.txt | 11 ++++++ package/CMakeLists.txt | 6 ++- package/include/spdlog | 1 + package/src/benchmark.cpp | 18 +++++++++ package/src/countmon.cpp | 2 + package/src/countmon.h | 4 +- package/src/cpumon.cpp | 6 +-- package/src/cpumon.h | 5 ++- package/src/iomon.cpp | 27 ++++++++----- package/src/iomon.h | 5 ++- package/src/memmon.cpp | 4 +- package/src/memmon.h | 4 +- package/src/netmon.cpp | 17 +++++---- package/src/netmon.h | 4 +- package/src/nvidiamon.cpp | 75 ++++++++++++++++++++----------------- package/src/nvidiamon.h | 4 +- package/src/prmon.cpp | 55 +++++++++++++++++---------- package/src/prmonlogger.cpp | 28 ++++++++++++++ package/src/prmonlogger.h | 31 +++++++++++++++ package/src/prmonutils.cpp | 29 ++++++++------ package/src/registry.h | 5 ++- package/src/utils.cpp | 2 +- package/src/wallmon.cpp | 16 ++++---- package/src/wallmon.h | 4 +- submodules/spdlog | 1 + 27 files changed, 263 insertions(+), 106 deletions(-) create mode 100644 .gitmodules create mode 120000 package/include/spdlog create mode 100644 package/src/benchmark.cpp create mode 100644 package/src/prmonlogger.cpp create mode 100644 package/src/prmonlogger.h create mode 160000 submodules/spdlog diff --git a/.github/workflows/ci.yml b/.github/workflows/ci.yml index 0f1f746..93609a3 100644 --- a/.github/workflows/ci.yml +++ b/.github/workflows/ci.yml @@ -25,6 +25,8 @@ jobs: steps: # Checks-out our repository under $GITHUB_WORKSPACE, so our job can access it - uses: actions/checkout@v2 + with: + submodules: recursive # Sets up useful environment variables - name: Setup environment variables diff --git a/.gitmodules b/.gitmodules new file mode 100644 index 0000000..dd94e2d --- /dev/null +++ b/.gitmodules @@ -0,0 +1,3 @@ +[submodule "submodules/spdlog"] + path = submodules/spdlog + url = https://github.com/gabime/spdlog.git diff --git a/CMakeLists.txt b/CMakeLists.txt index 43bb2c1..2e7f563 100644 --- a/CMakeLists.txt +++ b/CMakeLists.txt @@ -29,6 +29,11 @@ endif() set(PROFILE_GPERFTOOLS "${PROFILE_GPERFTOOLS}" CACHE BOOL "Build with the GPerfTools profiler library" FORCE) +if(NOT BUILD_BENCHMARK_LOG) + set(BUILD_BENCHMARK_LOG OFF) +endif() +set(BUILD_BENCHMARK_LOG "${BUILD_BENCHMARK_LOG}" + CACHE BOOL "Build binary which benchmarks spdlog speed" FORCE) # Define a default build type when using a single-mode tool like make/ninja # We make this default to Release, unless profiling is enabled, in which @@ -92,9 +97,15 @@ install(FILES ${CMAKE_CURRENT_SOURCE_DIR}/LICENSE #--- project specific subdirectories ------------------------------------------- add_subdirectory(package) +#--- include directories ------------------------------------------- +target_include_directories(prmon PRIVATE ${PROJECT_SOURCE_DIR}/package/include) +if (BUILD_BENCHMARK_LOG) + target_include_directories(benchmark-log PRIVATE ${PROJECT_SOURCE_DIR}/package/include) +endif(BUILD_BENCHMARK_LOG) #--- create uninstall target --------------------------------------------------- include(cmake/prmonUninstall.cmake) #--- code format targets ------------------------------------------------------- include(cmake/clang-format.cmake) include(cmake/python-format.cmake) + diff --git a/package/CMakeLists.txt b/package/CMakeLists.txt index 886e01f..ae69c33 100644 --- a/package/CMakeLists.txt +++ b/package/CMakeLists.txt @@ -1,5 +1,6 @@ find_package(nlohmann_json REQUIRED) + add_executable(prmon src/prmon.cpp src/prmonutils.cpp src/utils.cpp @@ -10,8 +11,11 @@ add_executable(prmon src/prmon.cpp src/wallmon.cpp src/memmon.cpp src/nvidiamon.cpp + src/prmonlogger.cpp ) - +if (BUILD_BENCHMARK_LOG) + add_executable(benchmark-log src/benchmark.cpp) +endif(BUILD_BENCHMARK_LOG) # Some older versions of the nlohmann_json package don't define # this target (< 3.0.0 ?). The build on these platforms seems to # go ok even without this "link library" definition. diff --git a/package/include/spdlog b/package/include/spdlog new file mode 120000 index 0000000..61f316f --- /dev/null +++ b/package/include/spdlog @@ -0,0 +1 @@ +../../submodules/spdlog/include/spdlog \ No newline at end of file diff --git a/package/src/benchmark.cpp b/package/src/benchmark.cpp new file mode 100644 index 0000000..efffb8d --- /dev/null +++ b/package/src/benchmark.cpp @@ -0,0 +1,18 @@ +#include "spdlog/sinks/basic_file_sink.h" +#include "spdlog/sinks/stdout_color_sinks.h" +#include "spdlog/spdlog.h" + +int main() { + auto sink = std::make_shared(); + auto fsink = + std::make_shared("sample.log", true); + spdlog::sinks_init_list sink_list = {sink, fsink}; + auto logger = std::make_shared("benchmark", sink_list.begin(), + sink_list.end()); + logger->set_level(spdlog::level::warn); + const int maxN = 1e6; + for (int i = 0; i < maxN; ++i) { + logger->warn("Hello, benchmarking currently"); + } + return 0; +} diff --git a/package/src/countmon.cpp b/package/src/countmon.cpp index 7902eaf..5c4fa2f 100644 --- a/package/src/countmon.cpp +++ b/package/src/countmon.cpp @@ -10,6 +10,7 @@ #include #include +#include "prmonlogger.h" #include "utils.h" // Constructor; uses RAII pattern to be valid @@ -21,6 +22,7 @@ countmon::countmon() count_average_stats{}, count_total_stats{}, iterations{0L} { + log_init(MY_NAME); count_params.reserve(params.size()); for (const auto& param : params) { count_params.push_back(param.get_name()); diff --git a/package/src/countmon.h b/package/src/countmon.h index 6176217..c23e0f3 100644 --- a/package/src/countmon.h +++ b/package/src/countmon.h @@ -6,6 +6,7 @@ #ifndef PRMON_COUNTMON_H #define PRMON_COUNTMON_H 1 +#define MY_NAME "countmon" #include #include @@ -14,9 +15,10 @@ #include "Imonitor.h" #include "parameter.h" +#include "prmonlogger.h" #include "registry.h" -class countmon final : public Imonitor { +class countmon final : public Imonitor, public MessageBase { private: // Setup the parameters to monitor here const prmon::parameter_list params = {{"nprocs", "1", "1"}, diff --git a/package/src/cpumon.cpp b/package/src/cpumon.cpp index f3e0c6e..ff4deb2 100644 --- a/package/src/cpumon.cpp +++ b/package/src/cpumon.cpp @@ -12,10 +12,10 @@ #include #include "utils.h" - // Constructor; uses RAII pattern to be valid // after construction cpumon::cpumon() : cpu_params{}, cpu_stats{} { + log_init(MY_NAME); cpu_params.reserve(params.size()); for (const auto& param : params) { cpu_params.push_back(param.get_name()); @@ -74,8 +74,8 @@ void const cpumon::get_hardware_info(nlohmann::json& hw_json) { // If the command failed print an error and move on if (cmd_result.first) { - std::cerr << "Failed to execute 'lscpu' to get CPU information (code " - << cmd_result.first << ")" << std::endl; + error("Failed to execute 'lscpu' to get CPU information (code " + + std::to_string(cmd_result.first) + ")"); return; } diff --git a/package/src/cpumon.h b/package/src/cpumon.h index 08a6272..7f19391 100644 --- a/package/src/cpumon.h +++ b/package/src/cpumon.h @@ -6,6 +6,7 @@ #ifndef PRMON_CPUMON_H #define PRMON_CPUMON_H 1 +#define MY_NAME "cpumon" #include #include @@ -14,9 +15,9 @@ #include "Imonitor.h" #include "parameter.h" +#include "prmonlogger.h" #include "registry.h" - -class cpumon final : public Imonitor { +class cpumon final : public Imonitor, public MessageBase { private: // Setup the parameters to monitor here const prmon::parameter_list params = {{"utime", "s", ""}, {"stime", "s", ""}}; diff --git a/package/src/iomon.cpp b/package/src/iomon.cpp index a55f723..7fc155c 100644 --- a/package/src/iomon.cpp +++ b/package/src/iomon.cpp @@ -17,6 +17,7 @@ // Constructor; uses RAII pattern to be valid // after construction iomon::iomon() : io_params{}, io_stats{} { + log_init(MY_NAME); io_params.reserve(params.size()); for (const auto& param : params) { io_params.push_back(param.get_name()); @@ -49,20 +50,28 @@ void iomon::update_stats(const std::vector& pids) { #endif for (auto& stat : io_stats) { -#if IOMON_TEST == 1 // This code block randomly suppresses io stat values // to test recovery from the peak measured values - auto t = time(NULL); - auto m = (t + stat_counter) % 4; - std::cout << stat_counter << " " << t << " " << m << std::endl; - if (m == 0) stat.second = 0; - ++stat_counter; +#if IOMON_TEST == 1 + if (log_level <= spdlog::level::debug) { + auto t = time(NULL); + auto m = (t + stat_counter) % 4; + std::stringstream strm; + strm << stat_counter << " " << t << " " << m << std::endl; + debug(strm.str()); + if (m == 0) stat.second = 0; + ++stat_counter; + } #endif if (stat.second < io_max_stats[stat.first]) { // Uh oh - somehow the i/o stats dropped so some i/o was lost - std::clog << "prmon: Warning, detected drop in i/o values for " - << stat.first << " (" << io_max_stats[stat.first] << " became " - << stat.second << ")" << std::endl; + if (log_level <= spdlog::level::warn) { + std::stringstream strm; + strm << "prmon: Warning, detected drop in i/o values for " << stat.first + << " (" << io_max_stats[stat.first] << " became " << stat.second + << ")" << std::endl; + warning(strm.str()); + } stat.second = io_max_stats[stat.first]; } else { io_max_stats[stat.first] = stat.second; diff --git a/package/src/iomon.h b/package/src/iomon.h index f3e555e..88251c4 100644 --- a/package/src/iomon.h +++ b/package/src/iomon.h @@ -6,6 +6,7 @@ #ifndef PRMON_IOMON_H #define PRMON_IOMON_H 1 +#define MY_NAME "iomon" #include #include @@ -13,9 +14,9 @@ #include "Imonitor.h" #include "parameter.h" +#include "prmonlogger.h" #include "registry.h" - -class iomon final : public Imonitor { +class iomon final : public Imonitor, public MessageBase { private: // Setup the parameters to monitor here const prmon::parameter_list params = {{"rchar", "B", "B/s"}, diff --git a/package/src/memmon.cpp b/package/src/memmon.cpp index 4c59823..e915e2e 100644 --- a/package/src/memmon.cpp +++ b/package/src/memmon.cpp @@ -13,7 +13,6 @@ #include #include "utils.h" - // Constructor; uses RAII pattern to be valid // after construction memmon::memmon() @@ -23,6 +22,7 @@ memmon::memmon() mem_average_stats{}, mem_total_stats{}, iterations{0} { + log_init(MY_NAME); mem_params.reserve(params.size()); for (const auto& param : params) { mem_params.push_back(param.get_name()); @@ -93,7 +93,7 @@ void const memmon::get_hardware_info(nlohmann::json& hw_json) { // Read some information from /proc/meminfo std::ifstream memInfoFile{"/proc/meminfo"}; if (!memInfoFile.is_open()) { - std::cerr << "Failed to open /proc/meminfo" << std::endl; + error("Failed to open /proc/meminfo"); return; } diff --git a/package/src/memmon.h b/package/src/memmon.h index c637156..b50e724 100644 --- a/package/src/memmon.h +++ b/package/src/memmon.h @@ -6,6 +6,7 @@ #ifndef PRMON_MEMMON_H #define PRMON_MEMMON_H 1 +#define MY_NAME "memmon" #include #include @@ -13,9 +14,10 @@ #include "Imonitor.h" #include "parameter.h" +#include "prmonlogger.h" #include "registry.h" -class memmon final : public Imonitor { +class memmon final : public Imonitor, public MessageBase { private: // Default paramater list // const static std::vector default_memory_params{"vmem", "pss", diff --git a/package/src/netmon.cpp b/package/src/netmon.cpp index d482920..db59994 100644 --- a/package/src/netmon.cpp +++ b/package/src/netmon.cpp @@ -8,6 +8,7 @@ #include #include +#include #include "utils.h" @@ -16,6 +17,7 @@ // to the monitor relative differences netmon::netmon(std::vector netdevs) : interface_params{}, network_if_streams{} { + log_init(MY_NAME); interface_params.reserve(params.size()); for (const auto& param : params) interface_params.push_back(param.get_name()); @@ -51,9 +53,9 @@ std::vector const netmon::get_all_network_devs() { } closedir(d); } else { - std::cerr << "Failed to open " << netdir - << " to get list of network devices. " - << "No network data will be available" << std::endl; + error("Failed to open " + std::string(netdir) + + " to get list of network devices. " + + "No network data will be available"); } return devices; } @@ -94,10 +96,11 @@ void netmon::update_stats(const std::vector& pids) { if (i.second >= network_stats_last[i.first]) { network_net_counters[i.first] += i.second - network_stats_last[i.first]; } else { - std::clog - << "prmon: network statistics error, counter values dropped for " - << i.first << " (" << i.second << " < " << network_stats_last[i.first] - << ")" << std::endl; + std::stringstream strm; + strm << "prmon: network statistics error, counter values dropped for " + << i.first << " (" << i.second << " < " + << network_stats_last[i.first] << ")" << std::endl; + warning(strm.str()); } network_stats_last[i.first] = i.second; } diff --git a/package/src/netmon.h b/package/src/netmon.h index fe62f48..7eb81d5 100644 --- a/package/src/netmon.h +++ b/package/src/netmon.h @@ -9,6 +9,7 @@ #ifndef PRMON_NETMON_H #define PRMON_NETMON_H 1 +#define MY_NAME "netmon" #include #include @@ -20,9 +21,10 @@ #include "Imonitor.h" #include "parameter.h" +#include "prmonlogger.h" #include "registry.h" -class netmon final : public Imonitor { +class netmon final : public Imonitor, public MessageBase { private: // Setup the parameters to monitor here const prmon::parameter_list params = {{"rx_bytes", "B", "B/s"}, diff --git a/package/src/nvidiamon.cpp b/package/src/nvidiamon.cpp index b282df9..95e912b 100644 --- a/package/src/nvidiamon.cpp +++ b/package/src/nvidiamon.cpp @@ -12,10 +12,6 @@ #include "utils.h" -// This is not very nice, but we don't want to add more special runtime -// flags, pending a proper decision on logging (#106) -#define NVIDIA_DEBUG 0 - // Constructor; uses RAII pattern to be valid after construction nvidiamon::nvidiamon() : nvidia_stats{}, @@ -23,6 +19,7 @@ nvidiamon::nvidiamon() nvidia_average_stats{}, nvidia_total_stats{}, iterations{0L} { + log_init(MY_NAME); nvidia_params.reserve(params.size()); for (const auto& param : params) { nvidia_params.push_back(param.get_name()); @@ -46,19 +43,20 @@ void nvidiamon::update_stats(const std::vector& pids) { auto cmd_result = prmon::cmd_pipe_output(cmd); if (cmd_result.first) { // Failed - std::cerr << "Failed to execute 'nvidia-smi' to get GPU status (code " - << cmd_result.first << ")" << std::endl; + error("Failed to execute 'nvidia-smi' to get GPU status (code " + + std::to_string(cmd_result.first) + ")"); return; } - - if (NVIDIA_DEBUG) { - std::cout << "nvidiamon::update_stats got the following output (" - << cmd_result.second.size() << "): " << std::endl; + if (log_level <= spdlog::level::debug) { + std::stringstream strm; + strm << "nvidiamon::update_stats got the following output (" + << cmd_result.second.size() << "): " << std::endl; int i = 0; for (const auto& s : cmd_result.second) { - std::cout << i << " -> " << s << std::endl; + strm << i << " -> " << s << std::endl; ++i; } + debug(strm.str()); } // Loop over output @@ -74,10 +72,12 @@ void nvidiamon::update_stats(const std::vector& pids) { cmd_name; auto read_ok = !(instr.fail() || instr.bad()); // eof() is ok if (read_ok) { - if (NVIDIA_DEBUG) { - std::cout << "Good read: " << gpu_idx << " " << pid << " " << cg_type - << " " << sm << " " << mem << " " << enc << " " << dec << " " - << fb_mem << " " << cmd_name << std::endl; + if (log_level <= spdlog::level::debug) { + std::stringstream strm; + strm << "Good read: " << gpu_idx << " " << pid << " " << cg_type << " " + << sm << " " << mem << " " << enc << " " << dec << " " << fb_mem + << " " << cmd_name << std::endl; + debug(strm.str()); } // Filter on PID value, so we only add stats for our processes @@ -92,22 +92,29 @@ void nvidiamon::update_stats(const std::vector& pids) { } } } - } else if (NVIDIA_DEBUG) { - std::clog << "Bad read of line: " << s << std::endl; - std::cout << "Parsed to: " << gpu_idx << " " << pid << " " << cg_type - << " " << sm << " " << mem << " " << enc << " " << dec << " " - << fb_mem << " " << cmd_name << std::endl; - std::cout << "StringStream status: good()=" << instr.good(); - std::cout << " eof()=" << instr.eof(); - std::cout << " fail()=" << instr.fail(); - std::cout << " bad()=" << instr.bad() << std::endl; + } else { + if (log_level <= spdlog::level::debug) { + std::stringstream strm; + strm << "Bad read of line: " << s << std::endl; + strm << "Parsed to: " << gpu_idx << " " << pid << " " << cg_type << " " + << sm << " " << mem << " " << enc << " " << dec << " " << fb_mem + << " " << cmd_name << std::endl; + + strm << "StringStream status: good()=" << instr.good(); + strm << " eof()=" << instr.eof(); + strm << " fail()=" << instr.fail(); + strm << " bad()=" << instr.bad() << std::endl; + debug(strm.str()); + } } } - if (NVIDIA_DEBUG) { - std::cout << "Parsed: " << nvidia_stats["ngpus"] << " " - << nvidia_stats["gpusmpct"] << " " << nvidia_stats["gpumempct"] - << " " << nvidia_stats["gpufbmem"] << std::endl; + if (log_level <= spdlog::level::debug) { + std::stringstream strm; + strm << "Parsed: " << nvidia_stats["ngpus"] << " " + << nvidia_stats["gpusmpct"] << " " << nvidia_stats["gpumempct"] << " " + << nvidia_stats["gpufbmem"] << std::endl; + debug(strm.str()); } // Update the statistics with the new snapshot values @@ -157,12 +164,11 @@ bool nvidiamon::test_nvidia_smi() { } nvidiamon::ngpus = gpus; if (gpus == 0) { - std::clog << "Executed 'nvidia-smi -L', but no GPUs found" << std::endl; + warning("Executed 'nvidia-smi -L', but no GPUs found"); return false; } else if (gpus > 4) { - std::clog << "More than 4 GPUs found, so GPU process monitoring will be " - "unreliable" - << std::endl; + warning( + "More than 4 GPUs found, so GPU process monitoring will be unreliable"); } return true; } @@ -180,7 +186,7 @@ void const nvidiamon::get_hardware_info(nlohmann::json& hw_json) { "--format=csv,noheader,nounits"}; auto cmd_result = prmon::cmd_pipe_output(cmd); if (cmd_result.first) { - std::cerr << "Failed to get hardware details for GPUs" << std::endl; + error("Failed to get hardware details for GPUs"); return; } unsigned int sm_freq, total_mem; @@ -201,8 +207,7 @@ void const nvidiamon::get_hardware_info(nlohmann::json& hw_json) { hw_json["HW"]["gpu"][gpu_number]["sm_freq"] = sm_freq; hw_json["HW"]["gpu"][gpu_number]["total_mem"] = total_mem * MB_to_KB; } else { - std::clog << "Unexpected line from GPU hardware query: " << s - << std::endl; + warning("Unexpected line from GPU hardware query: " + s); } ++count; } diff --git a/package/src/nvidiamon.h b/package/src/nvidiamon.h index 302599d..1bbf0fa 100644 --- a/package/src/nvidiamon.h +++ b/package/src/nvidiamon.h @@ -5,6 +5,7 @@ #ifndef PRMON_NVIDIAMON_H #define PRMON_NVIDIAMON_H 1 +#define MY_NAME "nvidiamon" #include #include @@ -12,9 +13,10 @@ #include "Imonitor.h" #include "parameter.h" +#include "prmonlogger.h" #include "registry.h" -class nvidiamon final : public Imonitor { +class nvidiamon final : public Imonitor, public MessageBase { private: // const static std::vector default_nvidia_params{ // "ngpus", "gpusmpct", "gpumempct", "gpufbmem"}; diff --git a/package/src/prmon.cpp b/package/src/prmon.cpp index 6fd014a..33c4c10 100644 --- a/package/src/prmon.cpp +++ b/package/src/prmon.cpp @@ -25,6 +25,10 @@ #include "prmonVersion.h" #include "prmonutils.h" #include "registry.h" +#include "spdlog/sinks/basic_file_sink.h" +#include "spdlog/sinks/stdout_color_sinks.h" +#include "spdlog/spdlog.h" +#include "utils.h" #include "wallmon.h" bool prmon::sigusr1 = false; @@ -36,6 +40,9 @@ int ProcessMonitor(const pid_t mpid, const std::string filename, const std::vector disabled_monitors) { signal(SIGUSR1, prmon::SignalCallbackHandler); + // auto sink = std::make_shared(); + // auto logger = std::make_shared("test-logger", sink); + // spdlog::register_logger(logger); // This is the vector of all monitoring components std::unordered_map> monitors{}; @@ -54,17 +61,16 @@ int ProcessMonitor(const pid_t mpid, const std::string filename, monitors[class_name] = std::move(new_monitor_p); } } else { - std::cerr << "Registration of monitor " << class_name << " FAILED" - << std::endl; + spdlog::error("Registration of monitor " + class_name + " FAILED"); } } } + // The wallclock monitor is always needed as it is used for average stat // generation - wallmon cannot be disabled, but this is prechecked in // prmon::valid_monitor_disable before we get here if (monitors.count("wallmon") != 1) { - std::cerr << "Failed to initialise mandatory wallclock monitoring class" - << std::endl; + spdlog::error("Failed to initialise mandatory wallclock monitoring class"); exit(EXIT_FAILURE); } @@ -114,6 +120,7 @@ int ProcessMonitor(const pid_t mpid, const std::string filename, auto wallclock_monitor_p = static_cast(monitors["wallmon"].get()); while (kill(mpid, 0) == 0 && prmon::sigusr1 == false) { if (time(0) - lastIteration > interval) { + // logger->warn("Hello from PRMON!"); iteration++; // Reset lastIteration lastIteration = time(0); @@ -180,16 +187,15 @@ int ProcessMonitor(const pid_t mpid, const std::string filename, if (rename(tmp_json_file.str().c_str(), json_snapshot_file.str().c_str()) != 0) { perror("rename fails"); - std::cerr << tmp_json_file.str() << " " << json_snapshot_file.str() - << "\n"; + spdlog::error(tmp_json_file.str() + " " + json_snapshot_file.str()); } } } catch (const std::ifstream::failure& e) { // Serious problem reading one of the status files, usually // caused by a child exiting during the poll - just try again // next time - std::clog << "prmon ifstream exception: " << e.what() << " (ignored)" - << std::endl; + spdlog::warn("prmon ifstream exception: " + std::string(e.what()) + + " (ignored)"); } } std::this_thread::sleep_for(std::chrono::milliseconds(200)); @@ -210,9 +216,9 @@ int ProcessMonitor(const pid_t mpid, const std::string filename, if (wallclock_monitor_p->get_wallclock_clock_t() / (interval * sysconf(_SC_CLK_TCK)) < 1) { - std::clog << "Wallclock time of monitored process was less than the " - "monitoring interval, so average statistics will be unreliable" - << std::endl; + spdlog::warn( + "Wallclock time of monitored process was less than the monitoring " + "interval, so average statistics will be unreliable"); } return return_code; @@ -226,6 +232,15 @@ int main(int argc, char* argv[]) { const bool default_store_hw_info = true; const bool default_store_unit_info = false; + // Set up global default logger + spdlog::sinks_init_list s_list = {c_sink, f_sink}; + auto logger = + std::make_shared("prmon", s_list.begin(), s_list.end()); + logger->set_level(spdlog::level::warn); + logger->flush_on(spdlog::level::warn); + spdlog::set_default_logger(logger); + spdlog::info("global logger initialised!"); + pid_t pid = -1; bool got_pid = false; std::string filename{default_filename}; @@ -284,7 +299,7 @@ int main(int argc, char* argv[]) { do_help = 1; break; default: - std::cerr << "Use '--help' for usage " << std::endl; + spdlog::error("Use '--help' for usage "); return 1; } } @@ -349,26 +364,28 @@ int main(int argc, char* argv[]) { } if ((!got_pid && child_args == -1) || (got_pid && child_args > 0)) { - std::cerr << "One and only one PID or child program is required - "; + std::stringstream strm; + strm << "One and only one PID or child program is required - "; if (got_pid) - std::cerr << "found both"; + strm << "found both"; else - std::cerr << "found none"; - std::cerr << std::endl; + strm << "found none"; + spdlog::error(strm.str()); return EXIT_FAILURE; } if (got_pid) { if (pid < 2) { - std::cerr << "Bad PID to monitor.\n"; + spdlog::error("Bad PID to monitor."); return 1; } ProcessMonitor(pid, filename, jsonSummary, interval, store_hw_info, store_unit_info, netdevs, disabled_monitors); } else { if (child_args == argc) { - std::cerr << "Found marker for child program to execute, but with no " - "program argument.\n"; + spdlog::error( + "Found marker for child program to execute, but with no " + "program argument."); return 1; } pid_t child = fork(); diff --git a/package/src/prmonlogger.cpp b/package/src/prmonlogger.cpp new file mode 100644 index 0000000..0382cc8 --- /dev/null +++ b/package/src/prmonlogger.cpp @@ -0,0 +1,28 @@ +#include "prmonlogger.h" + +#include "spdlog/spdlog.h" + +void MessageBase::log_init(const std::string& classname, + const spdlog::level::level_enum& level) { + // Initialise sink list + spdlog::sinks_init_list s_list = {c_sink, f_sink}; + + // Use the sink list to create multi sink logger + logger = + std::make_shared(classname, s_list.begin(), s_list.end()); + log_level = level; + set_log_level(level); + logger->flush_on(level); + spdlog::register_logger(logger); + info(classname + " logger initialised!"); +} + +void MessageBase::set_log_level(const spdlog::level::level_enum& level) { + log_level = level; + logger->set_level(level); + logger->flush_on(level); +} +void MessageBase::debug(const std::string& message) { logger->debug(message); } +void MessageBase::info(const std::string& message) { logger->info(message); } +void MessageBase::warning(const std::string& message) { logger->warn(message); } +void MessageBase::error(const std::string& message) { logger->error(message); } \ No newline at end of file diff --git a/package/src/prmonlogger.h b/package/src/prmonlogger.h new file mode 100644 index 0000000..7c8b4fa --- /dev/null +++ b/package/src/prmonlogger.h @@ -0,0 +1,31 @@ +#ifndef PRMON_LOGGER_H +#define PRMON_LOGGER_H 1 + +#include "spdlog/sinks/basic_file_sink.h" +#include "spdlog/sinks/stdout_color_sinks.h" +#include "spdlog/spdlog.h" + +// Global sinks + +static const std::shared_ptr c_sink{ + std::make_shared()}; +static const std::shared_ptr f_sink{ + std::make_shared("prmon.log", true)}; + +class MessageBase { + std::shared_ptr logger; + + protected: + spdlog::level::level_enum log_level; + void log_init(const std::string& classname, + const spdlog::level::level_enum& level = spdlog::level::warn); + + public: + void set_log_level(const spdlog::level::level_enum& level); + void debug(const std::string& message); + void info(const std::string& message); + void warning(const std::string& message); + void error(const std::string& message); +}; + +#endif // PRMON_LOGGER_H \ No newline at end of file diff --git a/package/src/prmonutils.cpp b/package/src/prmonutils.cpp index 74bea02..93eb567 100644 --- a/package/src/prmonutils.cpp +++ b/package/src/prmonutils.cpp @@ -15,6 +15,7 @@ #include "Imonitor.h" #include "registry.h" +#include "spdlog/spdlog.h" namespace prmon { @@ -105,16 +106,24 @@ int reap_children() { if (status && pid > 0) { if (WIFEXITED(status)) { return_code = WEXITSTATUS(status); - std::clog << "Child process " << pid - << " had non-zero return value: " << return_code << std::endl; + std::stringstream strm; + strm << "Child process " << pid + << " had non-zero return value: " << return_code << std::endl; + spdlog::warn(strm.str()); } else if (WIFSIGNALED(status)) { - std::clog << "Child process " << pid << " exited from signal " - << WTERMSIG(status) << std::endl; + std::stringstream strm; + strm << "Child process " << pid << " exited from signal " + << WTERMSIG(status) << std::endl; + spdlog::warn(strm.str()); } else if (WIFSTOPPED(status)) { - std::clog << "Child process " << pid << " was stopped by signal" - << WSTOPSIG(status) << std::endl; + std::stringstream strm; + strm << "Child process " << pid << " was stopped by signal" + << WSTOPSIG(status) << std::endl; + spdlog::warn(strm.str()); } else if (WIFCONTINUED(status)) { - std::clog << "Child process " << pid << " was continued" << std::endl; + std::stringstream strm; + strm << "Child process " << pid << " was continued" << std::endl; + spdlog::warn(strm.str()); } } } @@ -125,8 +134,7 @@ int reap_children() { bool valid_monitor_disable(const std::string disable_name) { // First check this is not an attempt to disable the wallmon if (disable_name == "wallmon") { - std::cerr << "prmon: wallmon monitor cannot be disabled (ignored)" - << std::endl; + spdlog::error("wallmon monitor cannot be disabled (ignored)"); return false; } auto monitors = registry::Registry::list_registered(); @@ -135,8 +143,7 @@ bool valid_monitor_disable(const std::string disable_name) { return true; } } - std::cerr << "prmon: " << disable_name - << " is an invalid monitor name (ignored)" << std::endl; + spdlog::error(disable_name + " is an invalid monitor name (ignored)"); return false; } diff --git a/package/src/registry.h b/package/src/registry.h index 1e6b403..9e2a54f 100644 --- a/package/src/registry.h +++ b/package/src/registry.h @@ -14,6 +14,8 @@ #include #include +#include "spdlog/spdlog.h" + namespace registry { // Utility macros @@ -42,8 +44,7 @@ class Registry { return std::unique_ptr( ctors()[class_name](std::forward(pack)...)); } - std::cerr << "Registry: class " << class_name << " is not registered." - << std::endl; + spdlog::error("Registry: class " + class_name + " is not registered."); return std::unique_ptr(nullptr); } diff --git a/package/src/utils.cpp b/package/src/utils.cpp index e63d1cb..b0feba0 100644 --- a/package/src/utils.cpp +++ b/package/src/utils.cpp @@ -103,4 +103,4 @@ const void prmon::fill_units(nlohmann::json& unit_json, unit_json["Units"]["Avg"][param.get_name()] = param.get_avg_unit(); } return; -} +} \ No newline at end of file diff --git a/package/src/wallmon.cpp b/package/src/wallmon.cpp index 7e4ee63..53cf768 100644 --- a/package/src/wallmon.cpp +++ b/package/src/wallmon.cpp @@ -11,7 +11,6 @@ #include #include "utils.h" - // Constructor; uses RAII pattern to be valid // after construction wallmon::wallmon() @@ -19,6 +18,7 @@ wallmon::wallmon() start_time_clock_t{0}, current_clock_t{0}, got_mother_starttime{false} { + log_init(MY_NAME); walltime_param.reserve(params.size()); for (const auto& param : params) { walltime_param.push_back(param.get_name()); @@ -42,10 +42,12 @@ int wallmon::get_mother_starttime(pid_t mother_pid) { start_time_clock_t = std::stol(stat_entries[prmon::uptime_pos]); } else { // Some error happened! - std::clog << "Read only " << stat_entries.size() - << " from mother PID stat file" << std::endl; - std::clog << "Stream status of " << stat_fname.str() << " is " - << (proc_stat ? "good" : "bad") << std::endl; + std::stringstream strm; + strm << "Read only " << stat_entries.size() << " from mother PID stat file" + << std::endl; + strm << "Stream status of " << stat_fname.str() << " is " + << (proc_stat ? "good" : "bad") << std::endl; + warning(strm.str()); return 1; } @@ -55,7 +57,7 @@ int wallmon::get_mother_starttime(pid_t mother_pid) { void wallmon::update_stats(const std::vector& pids) { if (!got_mother_starttime && pids.size() > 0) { if (get_mother_starttime(pids[0])) { - std::clog << "Error while reading mother starttime" << std::endl; + warning("Error while reading mother starttime"); return; } else { got_mother_starttime = true; @@ -66,7 +68,7 @@ void wallmon::update_stats(const std::vector& pids) { float uptime_sec{}; proc_uptime >> uptime_sec; if (!proc_uptime) { - std::clog << "Error while reading /proc/uptime" << std::endl; + warning("Error while reading /proc/uptime"); return; } current_clock_t = uptime_sec * sysconf(_SC_CLK_TCK) - start_time_clock_t; diff --git a/package/src/wallmon.h b/package/src/wallmon.h index 9112b94..73ce5f4 100644 --- a/package/src/wallmon.h +++ b/package/src/wallmon.h @@ -9,6 +9,7 @@ #ifndef PRMON_WALLMON_H #define PRMON_WALLMON_H 1 +#define MY_NAME "wallmon" #include #include @@ -17,9 +18,10 @@ #include "Imonitor.h" #include "parameter.h" +#include "prmonlogger.h" #include "registry.h" -class wallmon final : public Imonitor { +class wallmon final : public Imonitor, public MessageBase { private: const prmon::parameter_list params = {{"wtime", "s", ""}}; diff --git a/submodules/spdlog b/submodules/spdlog new file mode 160000 index 0000000..12df172 --- /dev/null +++ b/submodules/spdlog @@ -0,0 +1 @@ +Subproject commit 12df172575bf43ed6b879dabff4ba59c72e738e3