From: Joel Rosdahl Date: Mon, 16 Aug 2021 06:10:21 +0000 (+0200) Subject: feat: Improve statistics summary X-Git-Tag: v4.4~13 X-Git-Url: http://git.ipfire.org/?a=commitdiff_plain;h=8892814e8a790d615e44262c0005513d6d49f9e1;p=thirdparty%2Fccache.git feat: Improve statistics summary The number of statistics counters has become very large, making the output “ccache -s” hard to overview. Improvements: - The -s/--show-stats option now prints a more condensed overview where the counters representing “uncacheable calls” are summed as “uncacheable” and “errors” counters. Note: Scripts should use --print-stats instead of trying to parse the output of --show-stats. - Added hit rate for direct/preprocessed hits/misses as well. - Added a new -v/--verbose option, which makes --show-stats and --show-log-stats show more details. --- diff --git a/doc/MANUAL.adoc b/doc/MANUAL.adoc index 5d634a645..e29d0a201 100644 --- a/doc/MANUAL.adoc +++ b/doc/MANUAL.adoc @@ -153,12 +153,17 @@ compiler's documentation. *--show-log-stats*:: Print statistics counters from the stats log in human-readable format. See - <>. + <>. Use `-v`/`--verbose` once or twice for + more details. *-s*, *--show-stats*:: Print a summary of configuration and statistics counters in human-readable - format. + format. Use `-v`/`--verbose` once or twice for more details. + +*-v*, *--verbose*:: + + Increase verbosity. The option can be given multiple times. *-V*, *--version*:: @@ -1199,7 +1204,7 @@ Incompressible data: 3.5 GB Notes: * The "`disk blocks`" size is the cache size when taking disk block size into - account. This value should match the "`cache size`" value from "`ccache + account. This value should match the "`Cache size`" value from "`ccache --show-stats`". The other size numbers refer to actual content sizes. * "`Compressed data`" refers to result and manifest files stored in the cache. * "`Incompressible data`" refers to files that are always stored uncompressed @@ -1221,121 +1226,106 @@ recompressed. == Cache statistics -`ccache -s` can show the following statistics: +`ccache --show-stats` shows a summary of statistics, including cache size, +cleanups (number of performed cleanups, either implicitly due to a cache size +limit being reached or due to explicit `ccache -c` calls), overall hit rate, hit +rate for <>/<> modes +and hit rate for primary and <> storage. + +The summary also includes counters called "`Errors`" and "`Uncacheable`", which +are sums of more detailed counters. To see those detailed counters, use the +`-v`/`--verbose` flag. The verbose mode can show the following counters: [options="header",cols="30%,70%"] |============================================================================== -| *Name* | *Description* +| *Counter* | *Description* -| autoconf compile/link | -Uncachable compilation or linking by an autoconf test. +| Autoconf compile/link | +Uncacheable compilation or linking by an Autoconf test. -| bad compiler arguments | +| Bad compiler arguments | Malformed compiler argument, e.g. missing a value for a compiler option that requires an argument or failure to read a file specified by a compiler option argument. -| cache file missing | -A file was unexpectedly missing from the cache. This only happens in rare -situations, e.g. if one ccache instance is about to get a file from the cache -while another instance removed the file as part of cache cleanup. - -| cache hit (direct) | -A result was successfully found using <>. - -| cache hit (preprocessed) | -A result was successfully found using <>. - -| cache miss | -No result was found. - -| cache size | -Current size of the cache. - -| called for link | +| Called for linking | The compiler was called for linking, not compiling. Ccache only supports compilation of a single file, i.e. calling the compiler with the `-c` option to produce a single object file from a single source file. -| called for preprocessing | +| Called for preprocessing | The compiler was called for preprocessing, not compiling. -| can't use precompiled header | -Preconditions for using <> were not -fulfilled. - -| can't use modules | +| Could not use modules | Preconditions for using <> were not fulfilled. -| ccache internal error | -Unexpected failure, e.g. due to problems reading/writing the cache. +| Could not use precompiled header | +Preconditions for using <> were not +fulfilled. -| cleanups performed | -Number of cleanups performed, either implicitly due to the cache size limit -being reached or due to explicit `ccache -c` calls. +| Could not write to output file | +The output path specified with `-o` is not a file (e.g. a directory or a device +node). -| compile failed | +| Compilation failed | The compilation failed. No result stored in the cache. -| compiler check failed | +| Compiler check failed | A compiler check program specified by <> (*CCACHE_COMPILERCHECK*) failed. -| compiler produced empty output | +| Compiler produced empty output | The compiler's output file (typically an object file) was empty after compilation. -| compiler produced no output | +| Compiler produced no output | The compiler's output file (typically an object file) was missing after compilation. -| compiler produced stdout | +| Compiler produced stdout | The compiler wrote data to standard output. This is something that compilers normally never do, so ccache is not designed to store such output in the cache. -| couldn't find the compiler | +| Could not find the compiler | The compiler to execute could not be found. -| error hashing extra file | +| Error hashing extra file | Failure reading a file specified by <> (*CCACHE_EXTRAFILES*). -| files in cache | -Current number of files in the cache. +| Forced recache | +<> was used to overwrite an existing result. -| multiple source files | +| Internal error | +Unexpected failure, e.g. due to problems reading/writing the cache. + +| Missing cache file | +A file was unexpectedly missing from the cache. This only happens in rare +situations, e.g. if one ccache instance is about to get a file from the cache +while another instance removed the file as part of cache cleanup. + +| Multiple source files | The compiler was called to compile multiple source files in one go. This is not supported by ccache. -| no input file | +| No input file | No input file was specified to the compiler. -| output to a non-regular file | -The output path specified with `-o` is not a file (e.g. a directory or a device -node). - -| output to stdout | +| Output to stdout | The compiler was instructed to write its output to standard output using `-o -`. This is not supported by ccache. -| preprocessor error | +| Preprocessing failed | Preprocessing the source code using the compiler's `-E` option failed. -| stats updated | -When statistics were updated the last time. - -| stats zeroed | -When `ccache -z` was called the last time. - -| unsupported code directive | +| Unsupported code directive | Code like the assembler `.incbin` directive was found. This is not supported by ccache. -| unsupported compiler option | +| Unsupported compiler option | A compiler option not supported by ccache was found. -| unsupported source language | +| Unsupported source language | A source language e.g. specified with `-x` was unsupported by ccache. |============================================================================== @@ -1618,10 +1608,10 @@ things to make it work properly: compiling. -- + -If you don't do this, either the non-precompiled version of the header file -will be used (if available) or ccache will fall back to running the real -compiler and increase the statistics counter "`preprocessor error`" (if the -non-precompiled header file is not available). +If you don't do this, either the non-precompiled version of the header file will +be used (if available) or ccache will fall back to running the real compiler and +increase the statistics counter "`Preprocessing failed`" (if the non-precompiled +header file is not available). == C++ modules @@ -1755,9 +1745,9 @@ A good way of monitoring how well ccache works is to run `ccache -s` before and after your build and then compare the statistics counters. Here are some common problems and what may be done to increase the hit rate: -* If "`cache hit (preprocessed)`" has been incremented instead of "`cache hit - (direct)`", ccache has fallen back to preprocessor mode, which is generally - slower. Some possible reasons are: +* If the counter for preprocessed cache hits has been incremented instead of the + one for direct cache hits, ccache has fallen back to preprocessor mode, which + is generally slower. Some possible reasons are: ** The source code has been modified in such a way that the preprocessor output is not affected. ** Compiler arguments that are hashed in the direct mode but not in the @@ -1798,24 +1788,24 @@ problems and what may be done to increase the hit rate: direct mode hash to be able to take relative include files into account and to produce a correct object file if the source code includes a `+__FILE__+` macro. -* If "`cache miss`" has been incremented even though the same code has been +* If a cache hit counter was not incremented even though the same code has been compiled and cached before, ccache has either detected that something has changed anyway or a cleanup has been performed (either explicitly or implicitly when a cache limit has been reached). Some perhaps unobvious things that may result in a cache miss are usage of `+__TIME__+`, `+__DATE__+` or `+__TIMESTAMP__+` macros, or use of automatically generated code that contains a timestamp, build counter or other volatile information. -* If "`multiple source files`" has been incremented, it's an indication that - the compiler has been invoked on several source code files at once. Ccache - doesn't support that. Compile the source code files separately if possible. -* If "`unsupported compiler option`" has been incremented, enable debug logging +* If "`Multiple source files`" has been incremented, it's an indication that the + compiler has been invoked on several source code files at once. Ccache doesn't + support that. Compile the source code files separately if possible. +* If "`Unsupported compiler option`" has been incremented, enable debug logging and check which compiler option was rejected. -* If "`preprocessor error`" has been incremented, one possible reason is that +* If "`Preprocessing failed`" has been incremented, one possible reason is that precompiled headers are being used. See _<>_ for how to remedy this. -* If "`can't use precompiled header`" has been incremented, see +* If "`Could not use precompiled header`" has been incremented, see _<>_. -* If "`can't use modules`" has been incremented, see _<>_. +* If "`Could not use modules`" has been incremented, see _<>_. === Corrupt object files diff --git a/src/core/Statistics.cpp b/src/core/Statistics.cpp index 10ad98d1a..3417424b9 100644 --- a/src/core/Statistics.cpp +++ b/src/core/Statistics.cpp @@ -22,23 +22,17 @@ #include #include #include +#include #include namespace core { using core::Statistic; -// Returns a formatted version of a statistics value, or the empty string if the -// statistics line shouldn't be printed. -using FormatFunction = std::string (*)(uint64_t value); - -static std::string format_size_times_1024(uint64_t value); -static std::string format_timestamp(uint64_t value); - -const unsigned FLAG_NOZERO = 1; // don't zero with the -z option -const unsigned FLAG_ALWAYS = 2; // always show, even if zero -const unsigned FLAG_NEVER = 4; // never show -const unsigned FLAG_NOSTATSLOG = 8; // don't show for statslog +const unsigned FLAG_NOZERO = 1U << 0; // don't zero with --zero-stats +const unsigned FLAG_NEVER = 1U << 1; // don't include in --print-stats +const unsigned FLAG_ERROR = 1U << 2; // include in error count +const unsigned FLAG_UNCACHEABLE = 1U << 3; // include in uncacheable count namespace { @@ -46,123 +40,113 @@ struct StatisticsField { StatisticsField(const Statistic statistic_, const char* const id_, - const char* const message_, - const unsigned flags_ = 0, - const FormatFunction format_ = nullptr) + const char* const description_, + const unsigned flags_ = 0) : statistic(statistic_), id(id_), - message(message_), - flags(flags_), - format(format_) + description(description_), + flags(flags_) { } const Statistic statistic; - const char* const id; // for --print-stats - const char* const message; // for --show-stats - const unsigned flags; // bitmask of FLAG_* values - const FormatFunction format; // nullptr -> use plain integer format + const char* const id; // for --print-stats + const char* const description; // for --show-stats --verbose + const unsigned flags; // bitmask of FLAG_* values }; } // namespace -#define STATISTICS_FIELD(id, ...) \ +#define FIELD(id, ...) \ { \ Statistic::id, #id, __VA_ARGS__ \ } -// Statistics fields in display order. const StatisticsField k_statistics_fields[] = { - STATISTICS_FIELD( - stats_zeroed_timestamp, "stats zeroed", FLAG_ALWAYS, format_timestamp), - STATISTICS_FIELD(direct_cache_hit, "cache hit (direct)", FLAG_ALWAYS), - STATISTICS_FIELD( - preprocessed_cache_hit, "cache hit (preprocessed)", FLAG_ALWAYS), - STATISTICS_FIELD(cache_miss, "cache miss", FLAG_ALWAYS), - STATISTICS_FIELD(direct_cache_miss, "cache miss (direct)"), - STATISTICS_FIELD(preprocessed_cache_miss, "cache miss (preprocessed)"), - STATISTICS_FIELD(primary_storage_hit, "primary storage hit"), - STATISTICS_FIELD(primary_storage_miss, "primary storage miss"), - STATISTICS_FIELD(secondary_storage_hit, "secondary storage hit"), - STATISTICS_FIELD(secondary_storage_miss, "secondary storage miss"), - STATISTICS_FIELD(secondary_storage_error, "secondary storage error"), - STATISTICS_FIELD(secondary_storage_timeout, "secondary storage timeout"), - STATISTICS_FIELD(recache, "forced recache"), - STATISTICS_FIELD(called_for_link, "called for link"), - STATISTICS_FIELD(called_for_preprocessing, "called for preprocessing"), - STATISTICS_FIELD(multiple_source_files, "multiple source files"), - STATISTICS_FIELD(compiler_produced_stdout, "compiler produced stdout"), - STATISTICS_FIELD(compiler_produced_no_output, "compiler produced no output"), - STATISTICS_FIELD(compiler_produced_empty_output, - "compiler produced empty output"), - STATISTICS_FIELD(compile_failed, "compile failed"), - STATISTICS_FIELD(internal_error, "ccache internal error"), - STATISTICS_FIELD(preprocessor_error, "preprocessor error"), - STATISTICS_FIELD(could_not_use_precompiled_header, - "can't use precompiled header"), - STATISTICS_FIELD(could_not_use_modules, "can't use modules"), - STATISTICS_FIELD(could_not_find_compiler, "couldn't find the compiler"), - STATISTICS_FIELD(missing_cache_file, "cache file missing"), - STATISTICS_FIELD(bad_compiler_arguments, "bad compiler arguments"), - STATISTICS_FIELD(unsupported_source_language, "unsupported source language"), - STATISTICS_FIELD(compiler_check_failed, "compiler check failed"), - STATISTICS_FIELD(autoconf_test, "autoconf compile/link"), - STATISTICS_FIELD(unsupported_compiler_option, "unsupported compiler option"), - STATISTICS_FIELD(unsupported_code_directive, "unsupported code directive"), - STATISTICS_FIELD(output_to_stdout, "output to stdout"), - STATISTICS_FIELD(bad_output_file, "could not write to output file"), - STATISTICS_FIELD(no_input_file, "no input file"), - STATISTICS_FIELD(error_hashing_extra_file, "error hashing extra file"), - STATISTICS_FIELD( - cleanups_performed, "cleanups performed", FLAG_NOSTATSLOG | FLAG_ALWAYS), - STATISTICS_FIELD(files_in_cache, - "files in cache", - FLAG_NOZERO | FLAG_NOSTATSLOG | FLAG_ALWAYS), - STATISTICS_FIELD(cache_size_kibibyte, - "cache size", - FLAG_NOZERO | FLAG_NOSTATSLOG | FLAG_ALWAYS, - format_size_times_1024), - STATISTICS_FIELD(obsolete_max_files, "OBSOLETE", FLAG_NOZERO | FLAG_NEVER), - STATISTICS_FIELD(obsolete_max_size, "OBSOLETE", FLAG_NOZERO | FLAG_NEVER), - STATISTICS_FIELD(none, nullptr), + // Field "none" intentionally omitted. + FIELD(autoconf_test, "Autoconf compile/link", FLAG_UNCACHEABLE), + FIELD(bad_compiler_arguments, "Bad compiler arguments", FLAG_UNCACHEABLE), + FIELD(bad_output_file, "Could not write to output file", FLAG_ERROR), + FIELD(cache_miss, nullptr), + FIELD(cache_size_kibibyte, nullptr, FLAG_NOZERO), + FIELD(called_for_link, "Called for linking", FLAG_UNCACHEABLE), + FIELD(called_for_preprocessing, "Called for preprocessing", FLAG_UNCACHEABLE), + FIELD(cleanups_performed, nullptr), + FIELD(compile_failed, "Compilation failed", FLAG_UNCACHEABLE), + FIELD(compiler_check_failed, "Compiler check failed", FLAG_ERROR), + FIELD(compiler_produced_empty_output, + "Compiler produced empty output", + FLAG_UNCACHEABLE), + FIELD(compiler_produced_no_output, + "Compiler produced no output", + FLAG_UNCACHEABLE), + FIELD(compiler_produced_stdout, "Compiler produced stdout", FLAG_UNCACHEABLE), + FIELD(could_not_find_compiler, "Could not find compiler", FLAG_ERROR), + FIELD(could_not_use_modules, "Could not use modules", FLAG_UNCACHEABLE), + FIELD(could_not_use_precompiled_header, + "Could not use precompiled header", + FLAG_UNCACHEABLE), + FIELD(direct_cache_hit, nullptr), + FIELD(direct_cache_miss, nullptr), + FIELD(error_hashing_extra_file, "Error hashing extra file", FLAG_ERROR), + FIELD(files_in_cache, nullptr, FLAG_NOZERO), + FIELD(internal_error, "Internal error", FLAG_ERROR), + FIELD(missing_cache_file, "Missing cache file", FLAG_ERROR), + FIELD(multiple_source_files, "Multiple source files", FLAG_UNCACHEABLE), + FIELD(no_input_file, "No input file", FLAG_UNCACHEABLE), + FIELD(obsolete_max_files, nullptr, FLAG_NOZERO | FLAG_NEVER), + FIELD(obsolete_max_size, nullptr, FLAG_NOZERO | FLAG_NEVER), + FIELD(output_to_stdout, "Output to stdout", FLAG_UNCACHEABLE), + FIELD(preprocessed_cache_hit, nullptr), + FIELD(preprocessed_cache_miss, nullptr), + FIELD(preprocessor_error, "Preprocessing failed", FLAG_UNCACHEABLE), + FIELD(primary_storage_hit, nullptr), + FIELD(primary_storage_miss, nullptr), + FIELD(recache, "Forced recache", FLAG_UNCACHEABLE), + FIELD(secondary_storage_error, nullptr), + FIELD(secondary_storage_hit, nullptr), + FIELD(secondary_storage_miss, nullptr), + FIELD(secondary_storage_timeout, nullptr), + FIELD(stats_zeroed_timestamp, nullptr), + FIELD( + unsupported_code_directive, "Unsupported code directive", FLAG_UNCACHEABLE), + FIELD(unsupported_compiler_option, + "Unsupported compiler option", + FLAG_UNCACHEABLE), + FIELD(unsupported_source_language, + "Unsupported source language", + FLAG_UNCACHEABLE), }; -static std::string -format_size(const uint64_t value) -{ - return FMT("{:>11}", Util::format_human_readable_size(value)); -} - -static std::string -format_size_times_1024(const uint64_t value) -{ - return format_size(value * 1024); -} +static_assert(sizeof(k_statistics_fields) / sizeof(k_statistics_fields[0]) + == static_cast(Statistic::END) - 1, + "incorrect number of fields"); static std::string format_timestamp(const uint64_t value) { - if (value > 0) { + if (value == 0) { + return "never"; + } else { const auto tm = Util::localtime(value); char buffer[100] = "?"; if (tm) { strftime(buffer, sizeof(buffer), "%c", &*tm); } - return std::string(" ") + buffer; - } else { - return {}; + return buffer; } } -static double -hit_rate(const core::StatisticsCounters& counters) +static std::string +percent(const uint64_t nominator, const uint64_t denominator) { - const uint64_t direct = counters.get(Statistic::direct_cache_hit); - const uint64_t preprocessed = counters.get(Statistic::preprocessed_cache_hit); - const uint64_t hit = direct + preprocessed; - const uint64_t miss = counters.get(Statistic::cache_miss); - const uint64_t total = hit + miss; - return total > 0 ? (100.0 * hit) / total : 0.0; + if (denominator == 0) { + return ""; + } else if (nominator >= denominator) { + return FMT("({:.1f} %)", (100.0 * nominator) / denominator); + } else { + return FMT("({:.2f} %)", (100.0 * nominator) / denominator); + } } Statistics::Statistics(const StatisticsCounters& counters) @@ -170,101 +154,189 @@ Statistics::Statistics(const StatisticsCounters& counters) { } -static std::vector -get_statistics_fields(const core::StatisticsCounters& counters, bool id) +std::vector +Statistics::get_statistics_ids() const { std::vector result; for (const auto& field : k_statistics_fields) { - if (counters.get(field.statistic) != 0 && !(field.flags & FLAG_NOZERO)) { - result.emplace_back(id ? field.id : field.message); + if (m_counters.get(field.statistic) != 0 && !(field.flags & FLAG_NOZERO)) { + result.emplace_back(field.id); } } std::sort(result.begin(), result.end()); return result; } -std::vector -Statistics::get_statistics_ids() const +uint64_t +Statistics::count_stats(const unsigned flags) const { - return get_statistics_fields(m_counters, true); + uint64_t sum = 0; + for (const auto& field : k_statistics_fields) { + if (field.flags & flags) { + sum += m_counters.get(field.statistic); + } + } + return sum; } -std::string -Statistics::format_config_header(const Config& config) +std::vector> +Statistics::get_stats(unsigned flags, const bool all) const { - std::string result; - - result += FMT("{:36}{}\n", "cache directory", config.cache_dir()); - result += FMT("{:36}{}\n", "primary config", config.primary_config_path()); - result += FMT( - "{:36}{}\n", "secondary config (readonly)", config.secondary_config_path()); - + std::vector> result; + for (const auto& field : k_statistics_fields) { + const auto count = m_counters.get(field.statistic); + if ((field.flags & flags) && (all || count > 0)) { + result.emplace_back(field.description, count); + } + } return result; } std::string -Statistics::format_human_readable(const time_t last_updated, +Statistics::format_human_readable(const Config& config, + const time_t last_updated, + const uint8_t verbosity, const bool from_log) const { - std::string result; - - if (last_updated > 0) { - const auto tm = Util::localtime(last_updated); - char timestamp[100] = "?"; - if (tm) { - strftime(timestamp, sizeof(timestamp), "%c", &*tm); + util::TextTable table; + using C = util::TextTable::Cell; + +#define S(x_) m_counters.get(Statistic::x_) + + const uint64_t d_hits = S(direct_cache_hit); + const uint64_t d_misses = S(direct_cache_miss); + const uint64_t p_hits = S(preprocessed_cache_hit); + const uint64_t p_misses = S(preprocessed_cache_miss); + const uint64_t hits = d_hits + p_hits; + const uint64_t misses = S(cache_miss); + + table.add_heading("Summary:"); + if (verbosity > 0 && !from_log) { + table.add_row({" Cache directory:", C(config.cache_dir()).colspan(4)}); + table.add_row( + {" Primary config:", C(config.primary_config_path()).colspan(4)}); + table.add_row( + {" Secondary config:", C(config.secondary_config_path()).colspan(4)}); + table.add_row( + {" Stats updated:", C(format_timestamp(last_updated)).colspan(4)}); + if (verbosity > 1) { + const uint64_t last_zeroed = S(stats_zeroed_timestamp); + table.add_row( + {" Stats zeroed:", C(format_timestamp(last_zeroed)).colspan(4)}); } - result += FMT("{:36}{}\n", "stats updated", timestamp); + } + table.add_row({ + " Hits:", + hits, + "/", + hits + misses, + percent(hits, hits + misses), + }); + table.add_row({ + " Direct:", + d_hits, + "/", + d_hits + d_misses, + percent(d_hits, d_hits + d_misses), + }); + table.add_row({ + " Preprocessed:", + p_hits, + "/", + p_hits + p_misses, + percent(p_hits, p_hits + p_misses), + }); + + const auto errors = count_stats(FLAG_ERROR); + const auto uncacheable = count_stats(FLAG_UNCACHEABLE); + if (verbosity > 1 || errors > 0) { + table.add_row({" Errors:", errors}); + } + if (verbosity > 1 || uncacheable > 0) { + table.add_row({" Uncacheable:", uncacheable}); } - // ...and display them. - for (size_t i = 0; k_statistics_fields[i].message; i++) { - const Statistic statistic = k_statistics_fields[i].statistic; - - if (k_statistics_fields[i].flags & FLAG_NEVER) { - continue; + const uint64_t g = 1'000'000'000; + const uint64_t pri_hits = S(primary_storage_hit); + const uint64_t pri_misses = S(primary_storage_miss); + const uint64_t pri_size = S(cache_size_kibibyte) * 1024; + const uint64_t cleanups = S(cleanups_performed); + table.add_heading("Primary storage:"); + table.add_row({ + " Hits:", + pri_hits, + "/", + pri_hits + pri_misses, + percent(pri_hits, pri_hits + pri_misses), + }); + if (!from_log) { + table.add_row({ + " Cache size (GB):", + C(FMT("{:.2f}", static_cast(pri_size) / g)).right_align(), + "/", + C(FMT("{:.2f}", static_cast(config.max_size()) / g)) + .right_align(), + percent(pri_size, config.max_size()), + }); + if (verbosity > 0) { + std::vector cells{" Files:", S(files_in_cache)}; + if (config.max_files() > 0) { + cells.emplace_back("/"); + cells.emplace_back(config.max_files()); + cells.emplace_back(percent(S(files_in_cache), config.max_files())); + } + table.add_row(cells); } - if (m_counters.get(statistic) == 0 - && !(k_statistics_fields[i].flags & FLAG_ALWAYS)) { - continue; + if (cleanups > 0) { + table.add_row({" Cleanups:", cleanups}); } + } - // don't show cache directory info if reading from a log - if (from_log && (k_statistics_fields[i].flags & FLAG_NOSTATSLOG)) { - continue; + const uint64_t sec_hits = S(secondary_storage_hit); + const uint64_t sec_misses = S(secondary_storage_miss); + const uint64_t sec_errors = S(secondary_storage_error); + const uint64_t sec_timeouts = S(secondary_storage_timeout); + + if (verbosity > 0 || sec_hits + sec_misses + sec_errors + sec_timeouts > 0) { + table.add_heading("Secondary storage:"); + table.add_row({ + " Hits:", + sec_hits, + "/", + sec_hits + sec_misses, + percent(sec_hits, sec_hits + pri_misses), + }); + if (verbosity > 1 || sec_errors > 0) { + table.add_row({" Errors:", sec_errors}); } - - const std::string value = - k_statistics_fields[i].format - ? k_statistics_fields[i].format(m_counters.get(statistic)) - : FMT("{:8}", m_counters.get(statistic)); - if (!value.empty()) { - result += FMT("{:32}{}\n", k_statistics_fields[i].message, value); - } - - if (statistic == Statistic::cache_miss) { - double percent = hit_rate(m_counters); - result += FMT("{:34}{:6.2f} %\n", "cache hit rate", percent); + if (verbosity > 1 || sec_timeouts > 0) { + table.add_row({" Timeouts:", sec_timeouts}); } } - return result; -} - -std::string -Statistics::format_config_footer(const Config& config) -{ - std::string result; + auto cmp_fn = [](const auto& e1, const auto& e2) { + return e1.first.compare(e2.first) < 0; + }; - if (config.max_files() != 0) { - result += FMT("{:32}{:8}\n", "max files", config.max_files()); + if (verbosity > 1 || (verbosity == 1 && errors > 0)) { + auto error_stats = get_stats(FLAG_ERROR, verbosity > 1); + std::sort(error_stats.begin(), error_stats.end(), cmp_fn); + table.add_heading("Errors:"); + for (const auto& descr_count : error_stats) { + table.add_row({FMT(" {}:", descr_count.first), descr_count.second}); + } } - if (config.max_size() != 0) { - result += - FMT("{:32}{}\n", "max cache size", format_size(config.max_size())); + + if (verbosity > 1 || (verbosity == 1 && uncacheable > 0)) { + auto uncacheable_stats = get_stats(FLAG_UNCACHEABLE, verbosity > 1); + std::sort(uncacheable_stats.begin(), uncacheable_stats.end(), cmp_fn); + table.add_heading("Uncacheable:"); + for (const auto& descr_count : uncacheable_stats) { + table.add_row({FMT(" {}:", descr_count.first), descr_count.second}); + } } - return result; + return table.render(); } std::string @@ -274,11 +346,10 @@ Statistics::format_machine_readable(const time_t last_updated) const lines.push_back(FMT("stats_updated_timestamp\t{}\n", last_updated)); - for (size_t i = 0; k_statistics_fields[i].message; i++) { - if (!(k_statistics_fields[i].flags & FLAG_NEVER)) { - lines.push_back(FMT("{}\t{}\n", - k_statistics_fields[i].id, - m_counters.get(k_statistics_fields[i].statistic))); + for (const auto& field : k_statistics_fields) { + if (!(field.flags & FLAG_NEVER)) { + lines.push_back( + FMT("{}\t{}\n", field.id, m_counters.get(field.statistic))); } } diff --git a/src/core/Statistics.hpp b/src/core/Statistics.hpp index 568023be0..3e9ed816d 100644 --- a/src/core/Statistics.hpp +++ b/src/core/Statistics.hpp @@ -36,14 +36,11 @@ public: // Return machine-readable strings representing the statistics counters. std::vector get_statistics_ids() const; - // Format config header in human-readable format. - static std::string format_config_header(const Config& config); - // Format cache statistics in human-readable format. - std::string format_human_readable(time_t last_updated, bool from_log) const; - - // Format config footer in human-readable format. - static std::string format_config_footer(const Config& config); + std::string format_human_readable(const Config& config, + time_t last_updated, + uint8_t verbosity, + bool from_log) const; // Format cache statistics in machine-readable format. std::string format_machine_readable(time_t last_updated) const; @@ -56,6 +53,10 @@ public: private: const StatisticsCounters m_counters; + + uint64_t count_stats(unsigned flags) const; + std::vector> get_stats(unsigned flags, + bool all) const; }; // --- Inline implementations --- diff --git a/src/core/mainoptions.cpp b/src/core/mainoptions.cpp index 5bd02986e..6d43c0eff 100644 --- a/src/core/mainoptions.cpp +++ b/src/core/mainoptions.cpp @@ -108,6 +108,7 @@ Common options: in human-readable format -s, --show-stats show summary of configuration and statistics counters in human-readable format + -v, --verbose increase verbosity -z, --zero-stats zero statistics counters -h, --help print this help text @@ -270,7 +271,7 @@ enum { TRIM_METHOD, }; -const char options_string[] = "cCd:k:hF:M:po:sVxX:z"; +const char options_string[] = "cCd:k:hF:M:po:svVxX:z"; const option long_options[] = { {"checksum-file", required_argument, nullptr, CHECKSUM_FILE}, {"cleanup", no_argument, nullptr, 'c'}, @@ -297,6 +298,7 @@ const option long_options[] = { {"trim-dir", required_argument, nullptr, TRIM_DIR}, {"trim-max-size", required_argument, nullptr, TRIM_MAX_SIZE}, {"trim-method", required_argument, nullptr, TRIM_METHOD}, + {"verbose", no_argument, nullptr, 'v'}, {"version", no_argument, nullptr, 'V'}, {"zero-stats", no_argument, nullptr, 'z'}, {nullptr, 0, nullptr, 0}}; @@ -307,6 +309,7 @@ process_main_options(int argc, const char* const* argv) int c; nonstd::optional trim_max_size; bool trim_lru_mtime = false; + uint8_t verbosity = 0; // First pass: Handle non-command options that affect command options. while ((c = getopt_long(argc, @@ -334,6 +337,10 @@ process_main_options(int argc, const char* const* argv) trim_lru_mtime = (arg == "ctime"); break; + case 'v': // --verbose + ++verbosity; + break; + case '?': // unknown option return EXIT_FAILURE; } @@ -357,6 +364,7 @@ process_main_options(int argc, const char* const* argv) case 'd': // --dir case TRIM_MAX_SIZE: case TRIM_METHOD: + case 'v': // --verbose // Already handled in the first pass. break; @@ -503,11 +511,15 @@ process_main_options(int argc, const char* const* argv) if (config.stats_log().empty()) { throw Fatal("No stats log has been configured"); } - PRINT(stdout, "{:36}{}\n", "stats log", config.stats_log()); Statistics statistics(StatsLog(config.stats_log()).read()); const auto timestamp = Stat::stat(config.stats_log(), Stat::OnError::log).mtime(); - PRINT_RAW(stdout, statistics.format_human_readable(timestamp, true)); + PRINT_RAW( + stdout, + statistics.format_human_readable(config, timestamp, verbosity, true)); + if (verbosity == 0) { + PRINT_RAW(stdout, "\nUse the -v/--verbose option for more details.\n"); + } break; } @@ -517,9 +529,12 @@ process_main_options(int argc, const char* const* argv) std::tie(counters, last_updated) = storage::primary::PrimaryStorage(config).get_all_statistics(); Statistics statistics(counters); - PRINT_RAW(stdout, statistics.format_config_header(config)); - PRINT_RAW(stdout, statistics.format_human_readable(last_updated, false)); - PRINT_RAW(stdout, statistics.format_config_footer(config)); + PRINT_RAW(stdout, + statistics.format_human_readable( + config, last_updated, verbosity, false)); + if (verbosity == 0) { + PRINT_RAW(stdout, "\nUse the -v/--verbose option for more details.\n"); + } break; } diff --git a/test/suites/upgrade.bash b/test/suites/upgrade.bash index 233bed369..69786c3b6 100644 --- a/test/suites/upgrade.bash +++ b/test/suites/upgrade.bash @@ -11,7 +11,7 @@ SUITE_upgrade() { else expected=$HOME/.cache/ccache fi - actual=$($CCACHE -s | sed -n 's/^cache directory *//p') + actual=$($CCACHE -k cache_dir) if [ "$actual" != "$expected" ]; then test_failed "expected cache directory $expected, actual $actual" fi @@ -21,7 +21,7 @@ SUITE_upgrade() { else expected=$HOME/.config/ccache/ccache.conf fi - actual=$($CCACHE -s | sed -n 's/^primary config *//p') + actual=$($CCACHE -sv | sed -n 's/ *Primary config: *//p') if [ "$actual" != "$expected" ]; then test_failed "expected primary config $expected actual $actual" fi @@ -36,13 +36,13 @@ SUITE_upgrade() { export XDG_CONFIG_HOME=/elsewhere/config expected=$XDG_CACHE_HOME/ccache - actual=$($CCACHE -s | sed -n 's/^cache directory *//p') + actual=$($CCACHE -k cache_dir) if [ "$actual" != "$expected" ]; then test_failed "expected cache directory $expected, actual $actual" fi expected=$XDG_CONFIG_HOME/ccache/ccache.conf - actual=$($CCACHE -s | sed -n 's/^primary config *//p') + actual=$($CCACHE -sv | sed -n 's/ *Primary config: *//p') if [ "$actual" != "$expected" ]; then test_failed "expected primary config $expected actual $actual" fi @@ -58,13 +58,13 @@ SUITE_upgrade() { mkdir $HOME/.ccache expected=$HOME/.ccache - actual=$($CCACHE -s | sed -n 's/^cache directory *//p') + actual=$($CCACHE -k cache_dir) if [ "$actual" != "$expected" ]; then test_failed "expected cache directory $expected, actual $actual" fi expected=$HOME/.ccache/ccache.conf - actual=$($CCACHE -s | sed -n 's/^primary config *//p') + actual=$($CCACHE -sv | sed -n 's/ *Primary config: *//p') if [ "$actual" != "$expected" ]; then test_failed "expected primary config $expected actual $actual" fi @@ -79,13 +79,13 @@ SUITE_upgrade() { export XDG_CONFIG_HOME=/elsewhere/config expected=$CCACHE_DIR - actual=$($CCACHE -s | sed -n 's/^cache directory *//p') + actual=$($CCACHE -k cache_dir) if [ "$actual" != "$expected" ]; then test_failed "expected cache directory $expected, actual $actual" fi expected=$CCACHE_DIR/ccache.conf - actual=$($CCACHE -s | sed -n 's/^primary config *//p') + actual=$($CCACHE -sv | sed -n 's/ *Primary config: *//p') if [ "$actual" != "$expected" ]; then test_failed "expected primary config $expected actual $actual" fi @@ -105,13 +105,13 @@ SUITE_upgrade() { echo 'cache_dir = /nowhere' > $CCACHE_CONFIGPATH2 expected=$XDG_CACHE_HOME/ccache - actual=$($CCACHE -s | sed -n 's/^cache directory *//p') + actual=$($CCACHE -k cache_dir) if [ "$actual" != "$expected" ]; then test_failed "expected cache directory $expected, actual $actual" fi expected=$XDG_CONFIG_HOME/ccache/ccache.conf - actual=$($CCACHE -s | sed -n 's/^primary config *//p') + actual=$($CCACHE -sv | sed -n 's/ *Primary config: *//p') if [ "$actual" != "$expected" ]; then test_failed "expected primary config $expected actual $actual" fi