From: Joel Rosdahl Date: Mon, 3 Aug 2020 05:04:31 +0000 (+0200) Subject: C++-ify logging routines X-Git-Tag: v4.0~233 X-Git-Url: http://git.ipfire.org/?a=commitdiff_plain;h=05acfffbe50bcd8f2d18d1f1d4e7a45c9b1de26d;p=thirdparty%2Fccache.git C++-ify logging routines - Simplified and C++-ified logging code. - Added Logging::log and Logging::bulk_log functions corresponding to the old cc_log and cc_bulklog functions. The new functions pass their arguments to fmt::format. - Replacements: * init_log → Logging::init * cc_log → Logging::log * cc_bulklog → Logging::bulk_log * cc_log_argv → Logging::log plus Util::format_argv_for_logging * cc_dump_debug_log_buffer -> Logging::dump_log - A legacy cc_log implementation is still available so that logging can be converted gradually to the new functionality. --- diff --git a/src/CMakeLists.txt b/src/CMakeLists.txt index 7457b5595..27c3f1fe3 100644 --- a/src/CMakeLists.txt +++ b/src/CMakeLists.txt @@ -13,6 +13,7 @@ set( Decompressor.cpp Hash.cpp Lockfile.cpp + Logging.cpp MiniTrace.cpp NullCompressor.cpp NullDecompressor.cpp @@ -36,7 +37,6 @@ set( execute.cpp hashutil.cpp language.cpp - logging.cpp manifest.cpp stats.cpp version.cpp) diff --git a/src/Context.cpp b/src/Context.cpp index c2f25d754..015827685 100644 --- a/src/Context.cpp +++ b/src/Context.cpp @@ -19,10 +19,10 @@ #include "Context.hpp" #include "Counters.hpp" +#include "Logging.hpp" #include "SignalHandler.hpp" #include "Util.hpp" #include "hashutil.hpp" -#include "logging.hpp" #include "stats.hpp" #include @@ -49,7 +49,7 @@ Context::~Context() // Dump log buffer last to not lose any logs. if (config.debug()) { std::string path = fmt::format("{}.ccache-log", args_info.output_obj); - cc_dump_debug_log_buffer(path.c_str()); + Logging::dump_log(path); } } diff --git a/src/Hash.cpp b/src/Hash.cpp index 2812c2d75..9d6079c65 100644 --- a/src/Hash.cpp +++ b/src/Hash.cpp @@ -19,7 +19,7 @@ #include "Hash.hpp" #include "Fd.hpp" -#include "logging.hpp" +#include "Logging.hpp" using nonstd::string_view; diff --git a/src/InodeCache.cpp b/src/InodeCache.cpp index 249afc4c2..6c4d7b8e0 100644 --- a/src/InodeCache.cpp +++ b/src/InodeCache.cpp @@ -22,10 +22,10 @@ #include "Fd.hpp" #include "Finalizer.hpp" #include "Hash.hpp" +#include "Logging.hpp" #include "Stat.hpp" #include "TemporaryFile.hpp" #include "Util.hpp" -#include "logging.hpp" #include #include diff --git a/src/Lockfile.cpp b/src/Lockfile.cpp index 4e27bef36..e33a98d22 100644 --- a/src/Lockfile.cpp +++ b/src/Lockfile.cpp @@ -18,8 +18,8 @@ #include "Lockfile.hpp" +#include "Logging.hpp" #include "Util.hpp" -#include "logging.hpp" #ifdef _WIN32 # include "Win32Util.hpp" diff --git a/src/logging.cpp b/src/Logging.cpp similarity index 52% rename from src/logging.cpp rename to src/Logging.cpp index 5d34d6895..db895ca7e 100644 --- a/src/logging.cpp +++ b/src/Logging.cpp @@ -17,7 +17,7 @@ // this program; if not, write to the Free Software Foundation, Inc., 51 // Franklin Street, Fifth Floor, Boston, MA 02110-1301 USA -#include "logging.hpp" +#include "Logging.hpp" #include "Config.hpp" #include "File.hpp" @@ -44,6 +44,8 @@ # include #endif +using nonstd::string_view; + namespace { // Destination for g_config.log_file. @@ -58,39 +60,28 @@ bool use_syslog; // Buffer used for logs in debug mode. std::string debug_log_buffer; +// Whether debug logging is enabled via configuration or environment variable. bool debug_log_enabled = false; -} // namespace - -// Initialize logging. Call only once. -void -init_log(const Config& config) +// Print error message to stderr about failure writing to the log file and exit +// with failure. +[[noreturn]] void +print_fatal_error_and_exit() { - debug_log_enabled = config.debug(); - -#ifdef HAVE_SYSLOG - if (config.log_file() == "syslog") { - use_syslog = true; - openlog("ccache", LOG_PID, LOG_USER); - return; // Don't open logfile - } -#endif - - logfile_path = config.log_file(); - logfile.open(logfile_path, "a"); -#ifndef _WIN32 - if (logfile) { - Util::set_cloexec_flag(fileno(*logfile)); - } -#endif + // Note: Can't call fatal() since that would lead to recursion. + fprintf(stderr, + "ccache: error: Failed to write to %s: %s\n", + logfile_path.c_str(), + strerror(errno)); + exit(EXIT_FAILURE); } -static void -log_prefix(bool log_updated_time) +void +do_log(string_view message, bool bulk) { static char prefix[200]; -#ifdef HAVE_GETTIMEOFDAY - if (log_updated_time) { + + if (!bulk) { char timestamp[100]; struct timeval tv; gettimeofday(&tv, nullptr); @@ -107,137 +98,111 @@ log_prefix(bool log_updated_time) static_cast(tv.tv_usec), static_cast(getpid())); } -#else - snprintf(prefix, sizeof(prefix), "[%-5d] ", static_cast(getpid())); -#endif - if (logfile) { - fputs(prefix, *logfile); + + if (logfile + && (fputs(prefix, *logfile) == EOF + || fwrite(message.data(), message.length(), 1, *logfile) != 1 + || fputc('\n', *logfile) == EOF + || (!bulk && fflush(*logfile) == EOF))) { + print_fatal_error_and_exit(); } #ifdef HAVE_SYSLOG if (use_syslog) { - // prefix information will be added by syslog + // Note: No log prefix since syslog will add a prefix of its own. + syslog( + LOG_DEBUG, "%.*s", static_cast(message.length()), message.data()); + // Note: No trailing newline. } #endif if (debug_log_enabled) { debug_log_buffer += prefix; + debug_log_buffer.append(message.data(), message.length()); + debug_log_buffer += '\n'; } } -static void warn_log_fail() ATTR_NORETURN; +} // namespace -// Warn about failure writing to the log file and then exit. -static void -warn_log_fail() -{ - // Note: Can't call fatal() since that would lead to recursion. - fprintf(stderr, - "ccache: error: Failed to write to %s: %s\n", - logfile_path.c_str(), - strerror(errno)); - exit(EXIT_FAILURE); -} +namespace Logging { -static void -vlog(const char* format, va_list ap, bool log_updated_time) +// Initialize logging. Call only once. +void +init(const Config& config) { - if (!(debug_log_enabled || logfile || use_syslog)) { - return; - } + debug_log_enabled = config.debug(); - va_list aq; - va_copy(aq, ap); - log_prefix(log_updated_time); - if (logfile) { - int rc1 = vfprintf(*logfile, format, ap); - int rc2 = fprintf(*logfile, "\n"); - if (rc1 < 0 || rc2 < 0) { - warn_log_fail(); - } - } #ifdef HAVE_SYSLOG - if (use_syslog) { - vsyslog(LOG_DEBUG, format, ap); + if (config.log_file() == "syslog") { + use_syslog = true; + openlog("ccache", LOG_PID, LOG_USER); + return; // Don't open logfile } #endif - if (debug_log_enabled) { - char buf[8192]; - int len = vsnprintf(buf, sizeof(buf), format, aq); - if (len >= 0) { - debug_log_buffer.append( - buf, std::min(static_cast(len), sizeof(buf) - 1)); - debug_log_buffer += "\n"; + + if (!config.log_file().empty()) { + logfile_path = config.log_file(); + logfile.open(logfile_path, "a"); + if (logfile) { + Util::set_cloexec_flag(fileno(*logfile)); + } else { + print_fatal_error_and_exit(); } } - va_end(aq); } -// Write a message to the log file (adding a newline) and flush. -void -cc_log(const char* format, ...) +bool +enabled() { - va_list ap; - va_start(ap, format); - vlog(format, ap, true); - va_end(ap); - if (logfile) { - fflush(*logfile); - } + return debug_log_enabled || logfile || use_syslog; } -// Write a message to the log file (adding a newline) without flushing and with -// a reused timestamp. void -cc_bulklog(const char* format, ...) +log(string_view message) { - va_list ap; - va_start(ap, format); - vlog(format, ap, false); - va_end(ap); + if (!enabled()) { + return; + } + do_log(message, false); } -// Log an executed command to the CCACHE_LOGFILE location. void -cc_log_argv(const char* prefix, const char* const* argv) +bulk_log(string_view message) { - if (!(debug_log_enabled || logfile || use_syslog)) { + if (!enabled()) { return; } - - std::string argv_as_string = Util::format_argv_for_logging(argv); - - log_prefix(true); - if (logfile) { - fputs(prefix, *logfile); - fwrite(argv_as_string.data(), argv_as_string.length(), 1, *logfile); - fputc('\n', *logfile); - int rc = fflush(*logfile); - if (rc) { - warn_log_fail(); - } - } -#ifdef HAVE_SYSLOG - if (use_syslog) { - syslog(LOG_DEBUG, "%s", Util::format_argv_for_logging(argv).c_str()); - } -#endif - if (debug_log_enabled) { - debug_log_buffer += prefix; - debug_log_buffer += argv_as_string; - debug_log_buffer += '\n'; - } + do_log(message, true); } -// Copy the current log memory buffer to an output file. void -cc_dump_debug_log_buffer(const char* path) +dump_log(const std::string& path) { - if (!debug_log_enabled) { + if (!enabled()) { return; } File file(path, "w"); if (file) { - (void)fwrite(debug_log_buffer.data(), 1, debug_log_buffer.length(), *file); + (void)fwrite(debug_log_buffer.data(), debug_log_buffer.length(), 1, *file); } else { - cc_log("Failed to open %s: %s", path, strerror(errno)); + log("Failed to open {}: {}", path, strerror(errno)); + } +} + +} // namespace Logging + +void +cc_log(const char* format, ...) +{ + if (!Logging::enabled()) { + return; } + + va_list ap; + va_start(ap, format); + + char buffer[16384]; + int size = vsnprintf(buffer, sizeof(buffer), format, ap); + Logging::log(string_view(buffer, size)); + + va_end(ap); } diff --git a/src/Logging.hpp b/src/Logging.hpp new file mode 100644 index 000000000..f074b0265 --- /dev/null +++ b/src/Logging.hpp @@ -0,0 +1,80 @@ +// Copyright (C) 2020 Joel Rosdahl and other contributors +// +// See doc/AUTHORS.adoc for a complete list of contributors. +// +// This program is free software; you can redistribute it and/or modify it +// under the terms of the GNU General Public License as published by the Free +// Software Foundation; either version 3 of the License, or (at your option) +// any later version. +// +// This program is distributed in the hope that it will be useful, but WITHOUT +// ANY WARRANTY; without even the implied warranty of MERCHANTABILITY or +// FITNESS FOR A PARTICULAR PURPOSE. See the GNU General Public License for +// more details. +// +// You should have received a copy of the GNU General Public License along with +// this program; if not, write to the Free Software Foundation, Inc., 51 +// Franklin Street, Fifth Floor, Boston, MA 02110-1301 USA + +#pragma once + +#include "system.hpp" + +#include "FormatNonstdStringView.hpp" + +#include "third_party/fmt/core.h" +#include "third_party/nonstd/optional.hpp" +#include "third_party/nonstd/string_view.hpp" + +#include +#include + +class Config; + +namespace Logging { + +// Initialize global logging state. Must be called once before using the other +// logging functions. +void init(const Config& config); + +// Return whether logging is enabled to at least one destination. +bool enabled(); + +// Log `message` (plus a newline character). +void log(nonstd::string_view message); + +// Log `message` (plus a newline character) without flushing and with a reused +// timestamp. +void bulk_log(nonstd::string_view message); + +// Write the current log memory buffer `path`. +void dump_log(const std::string& path); + +// Log a message (plus a newline character). `args` are forwarded to +// `fmt::format`. +template +inline void +log(T&&... args) +{ + if (!enabled()) { + return; + } + log(nonstd::string_view(fmt::format(std::forward(args)...))); +} + +// Log a message (plus a newline character) without flushing and with a reused +// timestamp. `args` are forwarded to `fmt::format`. +template +inline void +bulk_log(T&&... args) +{ + if (!enabled()) { + return; + } + bulk_log(nonstd::string_view(fmt::format(std::forward(args)...))); +} + +} // namespace Logging + +// Legacy API. +void cc_log(const char* format, ...) ATTR_FORMAT(printf, 1, 2); diff --git a/src/Result.cpp b/src/Result.cpp index b5d76a2dc..02b8e30e5 100644 --- a/src/Result.cpp +++ b/src/Result.cpp @@ -25,10 +25,10 @@ #include "Context.hpp" #include "Fd.hpp" #include "File.hpp" +#include "Logging.hpp" #include "Stat.hpp" #include "Util.hpp" #include "exceptions.hpp" -#include "logging.hpp" #include "stats.hpp" // Result data format diff --git a/src/ResultDumper.cpp b/src/ResultDumper.cpp index e6cd1129f..7c740afd8 100644 --- a/src/ResultDumper.cpp +++ b/src/ResultDumper.cpp @@ -20,7 +20,7 @@ #include "CacheEntryReader.hpp" #include "Context.hpp" -#include "logging.hpp" +#include "Logging.hpp" using nonstd::optional; diff --git a/src/ResultRetriever.cpp b/src/ResultRetriever.cpp index fbf7bed18..37d30f5f2 100644 --- a/src/ResultRetriever.cpp +++ b/src/ResultRetriever.cpp @@ -19,7 +19,7 @@ #include "ResultRetriever.hpp" #include "Context.hpp" -#include "logging.hpp" +#include "Logging.hpp" #include "third_party/nonstd/string_view.hpp" diff --git a/src/Stat.cpp b/src/Stat.cpp index 7b398ba69..ae6215447 100644 --- a/src/Stat.cpp +++ b/src/Stat.cpp @@ -18,7 +18,7 @@ #include "Stat.hpp" -#include "logging.hpp" +#include "Logging.hpp" #include "third_party/fmt/core.h" diff --git a/src/Util.cpp b/src/Util.cpp index 3692cc0a1..c7a6e6e11 100644 --- a/src/Util.cpp +++ b/src/Util.cpp @@ -22,8 +22,8 @@ #include "Context.hpp" #include "Fd.hpp" #include "FormatNonstdStringView.hpp" +#include "Logging.hpp" #include "TemporaryFile.hpp" -#include "logging.hpp" #include #include diff --git a/src/ZstdCompressor.cpp b/src/ZstdCompressor.cpp index 37ea7e3f2..1524808ca 100644 --- a/src/ZstdCompressor.cpp +++ b/src/ZstdCompressor.cpp @@ -18,8 +18,8 @@ #include "ZstdCompressor.hpp" +#include "Logging.hpp" #include "exceptions.hpp" -#include "logging.hpp" const uint8_t k_default_zstd_compression_level = 1; diff --git a/src/argprocessing.cpp b/src/argprocessing.cpp index 773bdedc0..b471128c5 100644 --- a/src/argprocessing.cpp +++ b/src/argprocessing.cpp @@ -20,9 +20,9 @@ #include "Context.hpp" #include "FormatNonstdStringView.hpp" +#include "Logging.hpp" #include "compopt.hpp" #include "language.hpp" -#include "logging.hpp" #include diff --git a/src/ccache.cpp b/src/ccache.cpp index 682576b64..8ba561b8a 100644 --- a/src/ccache.cpp +++ b/src/ccache.cpp @@ -26,6 +26,7 @@ #include "File.hpp" #include "FormatNonstdStringView.hpp" #include "Hash.hpp" +#include "Logging.hpp" #include "MiniTrace.hpp" #include "ProgressBar.hpp" #include "Result.hpp" @@ -45,7 +46,6 @@ #include "execute.hpp" #include "hashutil.hpp" #include "language.hpp" -#include "logging.hpp" #include "manifest.hpp" #include "stats.hpp" @@ -66,6 +66,7 @@ #include #include +using Logging::log; using nonstd::nullopt; using nonstd::optional; using nonstd::string_view; @@ -1826,7 +1827,7 @@ initialize(Context& ctx, int argc, const char* const* argv) { bool primary_config_exists = set_up_config(ctx.config); set_up_context(ctx, argc, argv); - init_log(ctx.config); + Logging::init(ctx.config); // Set default umask for all files created by ccache from now on (if // configured to). This is intentionally done after calling init_log so that @@ -1874,8 +1875,7 @@ configuration_logger(const std::string& key, const std::string& value, const std::string& origin) { - cc_bulklog( - "Config: (%s) %s = %s", origin.c_str(), key.c_str(), value.c_str()); + Logging::bulk_log("Config: ({}) {} = {}", origin, key, value); } static void @@ -1932,7 +1932,7 @@ cache_compilation(int argc, const char* const* argv) Args saved_orig_args(std::move(ctx->orig_args)); auto execv_argv = saved_orig_args.to_argv(); - cc_log_argv("Executing ", execv_argv.data()); + log("Executing {}", Util::format_argv_for_logging(execv_argv.data())); ctx.reset(); // Dump debug logs last thing before executing. execv(execv_argv[0], const_cast(execv_argv.data())); fatal("execv of {} failed: {}", execv_argv[0], strerror(errno)); @@ -1968,7 +1968,7 @@ do_cache_compilation(Context& ctx, const char* const* argv) set_up_uncached_err(); MTR_END("main", "set_up_uncached_err"); - cc_log_argv("Command line: ", argv); + log("Command line: {}", Util::format_argv_for_logging(argv)); cc_log("Hostname: %s", Util::get_hostname()); cc_log("Working directory: %s", ctx.actual_cwd.c_str()); if (ctx.apparent_cwd != ctx.actual_cwd) { diff --git a/src/cleanup.cpp b/src/cleanup.cpp index 5f5e9ab50..158cf7725 100644 --- a/src/cleanup.cpp +++ b/src/cleanup.cpp @@ -22,8 +22,8 @@ #include "CacheFile.hpp" #include "Config.hpp" #include "Context.hpp" +#include "Logging.hpp" #include "Util.hpp" -#include "logging.hpp" #include "stats.hpp" #ifdef INODE_CACHE_SUPPORTED diff --git a/src/compress.cpp b/src/compress.cpp index 7e602d7b8..fff80e183 100644 --- a/src/compress.cpp +++ b/src/compress.cpp @@ -23,10 +23,10 @@ #include "CacheEntryWriter.hpp" #include "Context.hpp" #include "File.hpp" +#include "Logging.hpp" #include "Result.hpp" #include "StdMakeUnique.hpp" #include "ThreadPool.hpp" -#include "logging.hpp" #include "manifest.hpp" #include "stats.hpp" diff --git a/src/execute.cpp b/src/execute.cpp index 72e08cbd6..78759d3fa 100644 --- a/src/execute.cpp +++ b/src/execute.cpp @@ -22,16 +22,17 @@ #include "Config.hpp" #include "Context.hpp" #include "Fd.hpp" +#include "Logging.hpp" #include "SignalHandler.hpp" #include "Stat.hpp" #include "TemporaryFile.hpp" #include "Util.hpp" -#include "logging.hpp" #ifdef _WIN32 # include "Win32Util.hpp" #endif +using Logging::log; using nonstd::string_view; #ifdef _WIN32 @@ -157,7 +158,7 @@ win32execute(const char* path, int execute(const char* const* argv, Fd&& fd_out, Fd&& fd_err, pid_t* pid) { - cc_log_argv("Executing ", argv); + log("Executing {}", Util::format_argv_for_logging(argv)); { SignalHandlerBlocker signal_handler_blocker; diff --git a/src/hashutil.cpp b/src/hashutil.cpp index 83306194d..26689ca94 100644 --- a/src/hashutil.cpp +++ b/src/hashutil.cpp @@ -22,10 +22,10 @@ #include "Config.hpp" #include "Context.hpp" #include "Hash.hpp" +#include "Logging.hpp" #include "Stat.hpp" #include "ccache.hpp" #include "execute.hpp" -#include "logging.hpp" #include "macroskip.hpp" #include "stats.hpp" @@ -56,6 +56,7 @@ # include #endif +using Logging::log; using nonstd::string_view; namespace { @@ -397,7 +398,8 @@ hash_command_output(Hash& hash, } auto argv = args.to_argv(); - cc_log_argv("Executing compiler check command ", argv.data()); + log("Executing compiler check command {}", + Util::format_argv_for_logging(argv.data())); #ifdef _WIN32 PROCESS_INFORMATION pi; diff --git a/src/logging.hpp b/src/logging.hpp deleted file mode 100644 index e65a3535e..000000000 --- a/src/logging.hpp +++ /dev/null @@ -1,31 +0,0 @@ -// Copyright (C) 2020 Joel Rosdahl and other contributors -// -// See doc/AUTHORS.adoc for a complete list of contributors. -// -// This program is free software; you can redistribute it and/or modify it -// under the terms of the GNU General Public License as published by the Free -// Software Foundation; either version 3 of the License, or (at your option) -// any later version. -// -// This program is distributed in the hope that it will be useful, but WITHOUT -// ANY WARRANTY; without even the implied warranty of MERCHANTABILITY or -// FITNESS FOR A PARTICULAR PURPOSE. See the GNU General Public License for -// more details. -// -// You should have received a copy of the GNU General Public License along with -// this program; if not, write to the Free Software Foundation, Inc., 51 -// Franklin Street, Fifth Floor, Boston, MA 02110-1301 USA - -#pragma once - -#include "system.hpp" - -#include - -class Config; - -void init_log(const Config& config); -void cc_log(const char* format, ...) ATTR_FORMAT(printf, 1, 2); -void cc_bulklog(const char* format, ...) ATTR_FORMAT(printf, 1, 2); -void cc_log_argv(const char* prefix, const char* const* argv); -void cc_dump_debug_log_buffer(const char* path); diff --git a/src/manifest.cpp b/src/manifest.cpp index b0b7d4cd8..afb0bea89 100644 --- a/src/manifest.cpp +++ b/src/manifest.cpp @@ -27,10 +27,10 @@ #include "Digest.hpp" #include "File.hpp" #include "Hash.hpp" +#include "Logging.hpp" #include "StdMakeUnique.hpp" #include "ccache.hpp" #include "hashutil.hpp" -#include "logging.hpp" // Manifest data format // ==================== diff --git a/src/stats.cpp b/src/stats.cpp index c57aaa2f5..01d470037 100644 --- a/src/stats.cpp +++ b/src/stats.cpp @@ -26,9 +26,9 @@ #include "Context.hpp" #include "Counters.hpp" #include "Lockfile.hpp" +#include "Logging.hpp" #include "cleanup.hpp" #include "hashutil.hpp" -#include "logging.hpp" #include "third_party/fmt/core.h"