From 1c6ccf18c2e04459b1ac76ede4580b3ddcd27bbe Mon Sep 17 00:00:00 2001 From: Matt Whitlock Date: Sun, 7 Jun 2020 09:43:33 -0400 Subject: [PATCH] Always cache colored diagnostics and strip color codes as appropriate (#596) --- doc/MANUAL.adoc | 13 --- doc/NEWS.adoc | 5 ++ src/ArgsInfo.hpp | 3 + src/Context.hpp | 3 + src/Util.cpp | 34 ++++++++ src/Util.hpp | 13 +++ src/argprocessing.cpp | 65 +++++++-------- src/ccache.cpp | 86 ++++++++++++++----- test/run | 23 ++++-- test/suites/color_diagnostics.bash | 127 +++++++++++++++++++++++++++++ unittest/test_Util.cpp | 54 ++++++++++++ 11 files changed, 354 insertions(+), 72 deletions(-) create mode 100644 test/suites/color_diagnostics.bash diff --git a/doc/MANUAL.adoc b/doc/MANUAL.adoc index 6abf19661..c9361f9b9 100644 --- a/doc/MANUAL.adoc +++ b/doc/MANUAL.adoc @@ -1275,19 +1275,6 @@ Caveats * The direct mode fails to pick up new header files in some rare scenarios. See <<_the_direct_mode,THE DIRECT MODE>> above. -* When run via ccache, warning messages produced by GCC 4.9 and newer will only - be colored when the environment variable *GCC_COLORS* is set. An alternative - to setting *GCC_COLORS* is to pass `-fdiagnostics-color` explicitly when - compiling (but then color codes will also be present when redirecting stderr - to a file). -* If ccache guesses that the compiler may emit colored warnings, then a - compilation with stderr referring to a TTY will be considered different from - a compilation with a redirected stderr, thus not sharing cache entries. This - happens for Clang by default and for GCC when *GCC_COLORS* is set as - mentioned above. If you want to share cache hits, you can pass - `-f[no-]diagnostics-color` (GCC) or `-f[no-]color-diagnostics` (Clang) - explicitly when compiling (but then color codes will be either on or off for - both the TTY and the redirected case). Troubleshooting diff --git a/doc/NEWS.adoc b/doc/NEWS.adoc index af51928a5..53600cd85 100644 --- a/doc/NEWS.adoc +++ b/doc/NEWS.adoc @@ -47,6 +47,11 @@ High-level summary of changes (work in progress) - Added a new inode cache for file hashes, allowing computed hash values to be reused both within and between builds. +- Compiler diagnostic messages are now always cached in color, and ccache + strips the color codes on the fly when requested explicitly by command-line + option or when stderr does not refer to a TTY. This allows IDEs and terminals + to share cached compilation results. + - (More to be written.) diff --git a/src/ArgsInfo.hpp b/src/ArgsInfo.hpp index 26cd41abd..497ba2afd 100644 --- a/src/ArgsInfo.hpp +++ b/src/ArgsInfo.hpp @@ -68,6 +68,9 @@ struct ArgsInfo // (--serialize-diagnostics)? bool generating_diagnostics = false; + // Whether to strip color codes from diagnostic messages on output. + bool strip_diagnostics_colors = false; + // Have we seen -gsplit-dwarf? bool seen_split_dwarf = false; diff --git a/src/Context.hpp b/src/Context.hpp index 246b978fd..608d639c7 100644 --- a/src/Context.hpp +++ b/src/Context.hpp @@ -80,6 +80,9 @@ public: // Uses absolute path for some include files. bool has_absolute_include_headers = false; + // Have we tried and failed to get colored diagnostics? + bool diagnostics_color_failed = false; + // The name of the temporary preprocessed file. std::string i_tmpfile; diff --git a/src/Util.cpp b/src/Util.cpp index 2aa55b682..0bc2c4f98 100644 --- a/src/Util.cpp +++ b/src/Util.cpp @@ -26,6 +26,7 @@ #include #include +#include #ifdef HAVE_LINUX_FS_H # include @@ -193,6 +194,28 @@ dir_name(string_view path) } } +std::string +edit_ansi_csi_seqs(string_view string, const SubstringEditor& editor) +{ + static const std::regex csi_regex( + "\x1B\\[[\x30-\x3F]*[\x20-\x2F]*[\x40-\x7E]"); + std::string ret, substr; + ret.reserve(string.size()); + for (std::cregex_token_iterator itr( + string.begin(), string.end(), csi_regex, {-1, 0}); + itr != std::cregex_token_iterator{}; + ++itr) { + ret.append(itr->first, itr->second); + if (++itr == std::cregex_token_iterator{}) { + break; + } + substr.assign(itr->first, itr->second); + editor(itr->first - string.begin(), substr); + ret.append(substr); + } + return ret; +} + bool ends_with(string_view string, string_view suffix) { @@ -696,6 +719,17 @@ starts_with(string_view string, string_view prefix) return string.starts_with(prefix); } +std::string +strip_ansi_csi_seqs(string_view string, string_view strip_actions) +{ + return edit_ansi_csi_seqs( + string, [strip_actions](string_view::size_type, std::string& substr) { + if (strip_actions.find(substr.back()) != string_view::npos) { + substr.clear(); + } + }); +} + std::string strip_whitespace(const std::string& string) { diff --git a/src/Util.hpp b/src/Util.hpp index 1f7871324..65b1ac711 100644 --- a/src/Util.hpp +++ b/src/Util.hpp @@ -40,6 +40,8 @@ using SubdirVisitor = const ProgressReceiver& /*progress_receiver*/)>; using TraverseVisitor = std::function; +using SubstringEditor = + std::function; enum class UnlinkLog { log_failure, ignore_failure }; @@ -104,6 +106,12 @@ std::pair create_temp_fd(nonstd::string_view path_prefix); // Get directory name of path. nonstd::string_view dir_name(nonstd::string_view path); +// Returns a copy of string with any contained ANSI CSI sequences edited by the +// given SubstringEditor, which is invoked once for each ANSI CSI sequence +// encountered in string. The original string is not modified. +[[gnu::warn_unused_result]] std::string +edit_ansi_csi_seqs(nonstd::string_view string, const SubstringEditor& editor); + // Return true if suffix is a suffix of string. bool ends_with(nonstd::string_view string, nonstd::string_view suffix); @@ -295,6 +303,11 @@ std::vector split_into_strings(nonstd::string_view input, // Return true if prefix is a prefix of string. bool starts_with(nonstd::string_view string, nonstd::string_view prefix); +// Returns a copy of string with the specified ANSI CSI sequences removed. +[[gnu::warn_unused_result]] std::string +strip_ansi_csi_seqs(nonstd::string_view string, + nonstd::string_view strip_actions = "Km"); + // Strip whitespace from left and right side of a string. [[gnu::warn_unused_result]] std::string strip_whitespace(const std::string& string); diff --git a/src/argprocessing.cpp b/src/argprocessing.cpp index a5cf12e07..10cf355fa 100644 --- a/src/argprocessing.cpp +++ b/src/argprocessing.cpp @@ -32,6 +32,8 @@ using nonstd::string_view; namespace { +enum class ColorDiagnostics : int8_t { automatic, always, never = -1 }; + struct ArgumentProcessingState { bool found_c_opt = false; @@ -39,7 +41,7 @@ struct ArgumentProcessingState bool found_S_opt = false; bool found_pch = false; bool found_fpch_preprocess = false; - bool found_color_diagnostics = false; + ColorDiagnostics color_diagnostics = ColorDiagnostics::automatic; bool found_directives_only = false; bool found_rewrite_includes = false; @@ -656,26 +658,18 @@ process_arg(Context& ctx, return nullopt; } - if (args[i] == "-fcolor-diagnostics" || args[i] == "-fno-color-diagnostics" - || args[i] == "-fdiagnostics-color" - || args[i] == "-fdiagnostics-color=always" - || args[i] == "-fno-diagnostics-color" + if (args[i] == "-fcolor-diagnostics" || args[i] == "-fdiagnostics-color" + || args[i] == "-fdiagnostics-color=always") { + state.color_diagnostics = ColorDiagnostics::always; + return nullopt; + } + if (args[i] == "-fno-color-diagnostics" || args[i] == "-fno-diagnostics-color" || args[i] == "-fdiagnostics-color=never") { - state.common_args.push_back(args[i]); - state.found_color_diagnostics = true; + state.color_diagnostics = ColorDiagnostics::never; return nullopt; } - if (args[i] == "-fdiagnostics-color=auto") { - if (color_output_possible()) { - // Output is redirected, so color output must be forced. - state.common_args.push_back("-fdiagnostics-color=always"); - add_extra_arg(ctx, "-fdiagnostics-color=always"); - cc_log("Automatically forcing colors"); - } else { - state.common_args.push_back(args[i]); - } - state.found_color_diagnostics = true; + state.color_diagnostics = ColorDiagnostics::automatic; return nullopt; } @@ -1055,26 +1049,29 @@ process_args(Context& ctx, state.cpp_args.push_back(state.explicit_language); } + args_info.strip_diagnostics_colors = + state.color_diagnostics != ColorDiagnostics::automatic + ? state.color_diagnostics == ColorDiagnostics::never + : !color_output_possible(); // Since output is redirected, compilers will not color their output by - // default, so force it explicitly if it would be otherwise done. - if (!state.found_color_diagnostics && color_output_possible()) { - if (ctx.guessed_compiler == GuessedCompiler::clang) { - if (args_info.actual_language != "assembler") { - state.common_args.push_back("-fcolor-diagnostics"); - add_extra_arg(ctx, "-fcolor-diagnostics"); - cc_log("Automatically enabling colors"); - } - } else if (ctx.guessed_compiler == GuessedCompiler::gcc) { - // GCC has it since 4.9, but that'd require detecting what GCC version is - // used for the actual compile. However it requires also GCC_COLORS to be - // set (and not empty), so use that for detecting if GCC would use colors. - const char* gcc_colors = getenv("GCC_COLORS"); - if (gcc_colors && gcc_colors[0] != '\0') { - state.common_args.push_back("-fdiagnostics-color"); - add_extra_arg(ctx, "-fdiagnostics-color"); - cc_log("Automatically enabling colors"); + // default, so force it explicitly. + if (ctx.guessed_compiler == GuessedCompiler::clang) { + if (args_info.actual_language != "assembler") { + if (!config.run_second_cpp()) { + state.cpp_args.push_back("-fcolor-diagnostics"); } + state.compiler_only_args.push_back("-fcolor-diagnostics"); + add_extra_arg(ctx, "-fcolor-diagnostics"); + } + } else if (ctx.guessed_compiler == GuessedCompiler::gcc) { + if (!config.run_second_cpp()) { + state.cpp_args.push_back("-fdiagnostics-color"); } + state.compiler_only_args.push_back("-fdiagnostics-color"); + add_extra_arg(ctx, "-fdiagnostics-color"); + } else { + // Other compilers shouldn't output color, so no need to strip it. + args_info.strip_diagnostics_colors = false; } if (args_info.generating_dependencies) { diff --git a/src/ccache.cpp b/src/ccache.cpp index c24129620..c0727f51d 100644 --- a/src/ccache.cpp +++ b/src/ccache.cpp @@ -728,14 +728,63 @@ result_name_from_depfile(Context& ctx, struct hash* hash) return d; } +// Execute the compiler/preprocessor, with logic to retry without requesting +// colored diagnostics messages if that fails. +static int +execute(Context& ctx, + Args& args, + const std::string& stdout_path, + int stdout_fd, + const std::string& stderr_path, + int stderr_fd) +{ + if (ctx.diagnostics_color_failed + && ctx.guessed_compiler == GuessedCompiler::gcc) { + args.erase_with_prefix("-fdiagnostics-color"); + } + int status = + execute(args.to_argv().data(), stdout_fd, stderr_fd, &ctx.compiler_pid); + if (status != 0 && !ctx.diagnostics_color_failed + && ctx.guessed_compiler == GuessedCompiler::gcc) { + auto errors = Util::read_file(stderr_path); + if (errors.find("unrecognized command-line option") != std::string::npos + && errors.find("-fdiagnostics-color") != std::string::npos) { + // Old versions of GCC did not support colored diagnostics. + cc_log("-fdiagnostics-color is unsupported; trying again without it"); + if (ftruncate(stdout_fd, 0) < 0 || lseek(stdout_fd, 0, SEEK_SET) < 0) { + cc_log( + "Failed to truncate %s: %s", stdout_path.c_str(), strerror(errno)); + failed(STATS_ERROR); + } + if (ftruncate(stderr_fd, 0) < 0 || lseek(stderr_fd, 0, SEEK_SET) < 0) { + cc_log( + "Failed to truncate %s: %s", stderr_path.c_str(), strerror(errno)); + failed(STATS_ERROR); + } + ctx.diagnostics_color_failed = true; + return execute(ctx, args, stdout_path, stdout_fd, stderr_path, stderr_fd); + } + } + return status; +} + // Send cached stderr, if any, to stderr. static void -send_cached_stderr(const char* path_stderr) +send_cached_stderr(const std::string& path_stderr, bool strip_colors) { - int fd_stderr = open(path_stderr, O_RDONLY | O_BINARY); - if (fd_stderr != -1) { - copy_fd(fd_stderr, STDERR_FILENO); - close(fd_stderr); + if (strip_colors) { + try { + auto stripped = Util::strip_ansi_csi_seqs(Util::read_file(path_stderr)); + write_fd(STDERR_FILENO, stripped.data(), stripped.size()); + } catch (const Error&) { + // Fall through + } + } else { + int fd_stderr = open(path_stderr.c_str(), O_RDONLY | O_BINARY); + if (fd_stderr != -1) { + copy_fd(fd_stderr, STDERR_FILENO); + close(fd_stderr); + } } } @@ -876,8 +925,8 @@ to_cache(Context& ctx, int status; if (!ctx.config.depend_mode()) { - status = execute( - args.to_argv().data(), tmp_stdout_fd, tmp_stderr_fd, &ctx.compiler_pid); + status = + execute(ctx, args, tmp_stdout, tmp_stdout_fd, tmp_stderr, tmp_stderr_fd); args.pop_back(3); } else { // Use the original arguments (including dependency options) in depend @@ -888,10 +937,12 @@ to_cache(Context& ctx, add_prefix(ctx, depend_mode_args, ctx.config.prefix_command()); ctx.time_of_compilation = time(nullptr); - status = execute(depend_mode_args.to_argv().data(), + status = execute(ctx, + depend_mode_args, + tmp_stdout, tmp_stdout_fd, - tmp_stderr_fd, - &ctx.compiler_pid); + tmp_stderr, + tmp_stderr_fd); } MTR_END("execute", "compiler"); @@ -919,12 +970,8 @@ to_cache(Context& ctx, if (status != 0) { cc_log("Compiler gave exit status %d", status); - int fd = open(tmp_stderr.c_str(), O_RDONLY | O_BINARY); - if (fd != -1) { - // We can output stderr immediately instead of rerunning the compiler. - copy_fd(fd, STDERR_FILENO); - close(fd); - } + // We can output stderr immediately instead of rerunning the compiler. + send_cached_stderr(tmp_stderr, ctx.args_info.strip_diagnostics_colors); failed(STATS_STATUS, status); } @@ -1019,7 +1066,7 @@ to_cache(Context& ctx, } // Everything OK. - send_cached_stderr(tmp_stderr.c_str()); + send_cached_stderr(tmp_stderr, ctx.args_info.strip_diagnostics_colors); } // Find the result name by running the compiler in preprocessor mode and @@ -1066,8 +1113,7 @@ get_result_name_from_cpp(Context& ctx, Args& args, struct hash* hash) add_prefix(ctx, args, ctx.config.prefix_command_cpp()); cc_log("Running preprocessor"); MTR_BEGIN("execute", "preprocessor"); - status = - execute(args.to_argv().data(), stdout_fd, stderr_fd, &ctx.compiler_pid); + status = execute(ctx, args, stdout_path, stdout_fd, stderr_path, stderr_fd); MTR_END("execute", "preprocessor"); args.pop_back(args_added); } @@ -1725,7 +1771,7 @@ from_cache(Context& ctx, enum fromcache_call_mode mode) MTR_END("file", "file_get"); - send_cached_stderr(tmp_stderr.c_str()); + send_cached_stderr(tmp_stderr, ctx.args_info.strip_diagnostics_colors); cc_log("Succeeded getting cached result"); diff --git a/test/run b/test/run index 898b605e7..6eb0100d9 100755 --- a/test/run +++ b/test/run @@ -145,13 +145,13 @@ expect_stat() { } expect_file_exists() { - if [ ! -f "$1" ]; then + if [ ! -e "$1" ]; then test_failed "Expected $1 to exist, but it's missing" fi } expect_file_missing() { - if [ -f "$1" ]; then + if [ -e "$1" ]; then test_failed "Expected $1 to be missing, but it exists" fi } @@ -207,7 +207,7 @@ expect_file_content() { local file="$1" local content="$2" - if [ ! -f "$file" ]; then + if [ ! -e "$file" ]; then test_failed "$file not found" fi if [ "$(cat $file)" != "$content" ]; then @@ -219,14 +219,26 @@ expect_file_contains() { local file="$1" local string="$2" - if [ ! -f "$file" ]; then + if [ ! -e "$file" ]; then test_failed "$file not found" fi - if ! grep -q "$string" "$file"; then + if ! fgrep -q "$string" "$file"; then test_failed "File $file does not contain: $string. Actual content: $(cat $file)" fi } +expect_file_not_contains() { + local file="$1" + local string="$2" + + if [ ! -e "$file" ]; then + test_failed "$file not found" + fi + if fgrep -q "$string" "$file"; then + test_failed "File $file contains: $string. Actual content: $(cat $file)" + fi +} + expect_file_count() { local expected=$1 local pattern=$2 @@ -424,6 +436,7 @@ nocpp2 cpp1 multi_arch serialize_diagnostics +color_diagnostics sanitize_blacklist debug_prefix_map profiling diff --git a/test/suites/color_diagnostics.bash b/test/suites/color_diagnostics.bash new file mode 100644 index 000000000..0ac5aca95 --- /dev/null +++ b/test/suites/color_diagnostics.bash @@ -0,0 +1,127 @@ +if $COMPILER_TYPE_GCC ; then + color_diagnostics_enable='-fdiagnostics-color' + color_diagnostics_disable='-fno-diagnostics-color' +elif $COMPILER_TYPE_CLANG ; then + color_diagnostics_enable='-fcolor-diagnostics' + color_diagnostics_disable='-fno-color-diagnostics' +fi + +SUITE_color_diagnostics_PROBE() { + # Probe that real compiler actually supports colored diagnostics. + if [[ ! $color_diagnostics_enable || ! $color_diagnostics_disable ]] ; then + echo "compiler $COMPILER does not support colored diagnostics" + elif ! $REAL_COMPILER $color_diagnostics_enable -E - /dev/null 2>&1 ; then + echo "compiler $COMPILER (version: $compiler_version) does not support $color_diagnostics_enable" + elif ! $REAL_COMPILER $color_diagnostics_disable -E - /dev/null 2>&1 ; then + echo "compiler $COMPILER (version: $compiler_version) does not support $color_diagnostics_disable" + fi +} + +SUITE_color_diagnostics_SETUP() { + if $run_second_cpp ; then + export CCACHE_CPP2=1 + else + export CCACHE_NOCPP2=1 + fi + + unset GCC_COLORS +} + +color_diagnostics_expect_color() { + expect_file_contains "${1:?}" $'\033[' + expect_file_contains <(fgrep 'previous prototype' "$1") $'\033[' + expect_file_contains <(fgrep 'from preprocessor' "$1") $'\033[' +} + +color_diagnostics_expect_no_color() { + expect_file_not_contains "${1:?}" $'\033[' +} + +color_diagnostics_generate_code() { + generate_code "$@" + echo '#warning "Warning from preprocessor"' >>"$2" +} + +# Heap's permutation algorithm +color_diagnostics_generate_permutations() { + local -i i k="${1:?}-1" + if (( k )) ; then + color_diagnostics_generate_permutations "$k" + for (( i = 0 ; i < k ; ++i )) ; do + if (( k & 1 )) ; then + local tmp=${A[$i]} ; A[$i]=${A[$k]} ; A[$k]=$tmp + else + local tmp=${A[0]} ; A[0]=${A[$k]} ; A[$k]=$tmp + fi + color_diagnostics_generate_permutations "$k" + done + else + echo "${A[@]}" + fi +} + +color_diagnostics_run_on_pty() { + script --return --quiet --command "unset GCC_COLORS; ${1:?}" /dev/null test1.stderr + color_diagnostics_expect_no_color test1.stderr + + # Check that subsequently running on a TTY generates a cache hit. + color_diagnostics_run_on_pty "$CCACHE_COMPILE -Wmissing-prototypes -c -o test1.o test1.c" >test1.output + color_diagnostics_expect_color test1.output + expect_stat 'cache miss' 1 + expect_stat 'cache hit (preprocessed)' 1 + + # ------------------------------------------------------------------------- + TEST "Colored diagnostics automatically enabled when stderr is a TTY (run_second_cpp=$run_second_cpp)" + color_diagnostics_generate_code 1 test1.c + color_diagnostics_run_on_pty "$CCACHE_COMPILE -Wmissing-prototypes -c -o test1.o test1.c" >test1.output + color_diagnostics_expect_color test1.output + + # Check that subsequently running without a TTY generates a cache hit. + $CCACHE_COMPILE -Wmissing-prototypes -c -o test1.o test1.c 2>test1.stderr + color_diagnostics_expect_no_color test1.stderr + expect_stat 'cache miss' 1 + expect_stat 'cache hit (preprocessed)' 1 + + # ------------------------------------------------------------------------- + while read -r case ; do + TEST "Cache object shared across ${case} (run_second_cpp=$run_second_cpp)" + color_diagnostics_generate_code 1 test1.c + local each ; for each in ${case} ; do + case $each in + color,*) + local color_flag=$color_diagnostics_enable color_expect=color + ;; + nocolor,*) + local color_flag=$color_diagnostics_disable color_expect=no_color + ;; + esac + case $each in + *,tty) + color_diagnostics_run_on_pty "$CCACHE_COMPILE $color_flag -Wmissing-prototypes -c -o test1.o test1.c" >test1.output + color_diagnostics_expect_$color_expect test1.output + ;; + *,notty) + $CCACHE_COMPILE $color_flag -Wmissing-prototypes -c -o test1.o test1.c 2>test1.stderr + color_diagnostics_expect_$color_expect test1.stderr + ;; + esac + done + expect_stat 'cache miss' 1 + expect_stat 'cache hit (preprocessed)' 3 + done < <( + A=( {color,nocolor},{tty,notty} ) + color_diagnostics_generate_permutations "${#A[@]}" + ) +} + +SUITE_color_diagnostics() { + run_second_cpp=true color_diagnostics_test + run_second_cpp=false color_diagnostics_test +} diff --git a/unittest/test_Util.cpp b/unittest/test_Util.cpp index c04f9ca87..d74c044f9 100644 --- a/unittest/test_Util.cpp +++ b/unittest/test_Util.cpp @@ -129,6 +129,60 @@ TEST_CASE("Util::dir_name") CHECK(Util::dir_name("/foo/bar/f.txt") == "/foo/bar"); } +TEST_CASE("Util::{edit,strip}_ansi_csi_seqs") +{ + static constexpr auto input = + "Normal, " + "\x1B[K\x1B[1mbold\x1B[m, " + "\x1B[31mred\x1B[m, " + "\x1B[1;32mbold green\x1B[m.\n"; + + SECTION("Remove bold attributes") + { + CHECK(Util::edit_ansi_csi_seqs(input, + [](nonstd::string_view::size_type, + std::string& substr) + { + if (substr.size() > 3 && substr.back() == 'm') { + nonstd::string_view attrs = substr; + attrs.remove_prefix(2); // ESC [ + attrs.remove_suffix(1); // m + std::string edited; + edited.reserve(attrs.size()); + for (auto& attr : Util::split_into_views(attrs, ";")) { + if (attr != "1") { + if (!edited.empty()) { + edited += ';'; + } + edited.append(attr.begin(), attr.end()); + } + } + if (edited.empty()) { + substr.clear(); + } else { + substr.replace(2, attrs.size(), std::move(edited)); + } + } + }) == + "Normal, " + "\x1B[Kbold\x1B[m, " + "\x1B[31mred\x1B[m, " + "\x1B[32mbold green\x1B[m.\n"); + } + + SECTION("Strip SGR sequences only") + { + CHECK(Util::strip_ansi_csi_seqs(input, "m") + == "Normal, \x1B[Kbold, red, bold green.\n"); + } + + SECTION("Strip default set of CSI sequences") + { + CHECK(Util::strip_ansi_csi_seqs(input) + == "Normal, bold, red, bold green.\n"); + } +} + TEST_CASE("Util::ends_with") { CHECK(Util::ends_with("", "")); -- 2.47.3