From 9eea0f9a98c6bec344284bfecc7c91c9d8dd7715 Mon Sep 17 00:00:00 2001 From: ccalvarin Date: Wed, 21 Mar 2018 15:32:30 -0700 Subject: Update the client's skeleton logging framework to use it for --client_debug. We are still unable to turn this on to write to files, but there are currently 2 logging systems in use in the client: the inactive one, and the print-to-stderr option triggered by --client_debug. Combine these, so we can use the same logging format for both. Also combine it with the VerboseLogging functionality - it was not documented anywhere and seems redundant. RELNOTES: None. PiperOrigin-RevId: 189979051 --- src/main/cpp/BUILD | 2 + src/main/cpp/blaze.cc | 104 ++++++------ src/main/cpp/blaze.h | 3 +- src/main/cpp/blaze_util.cc | 31 ++-- src/main/cpp/blaze_util.h | 7 - src/main/cpp/blaze_util_posix.cc | 18 +- src/main/cpp/blaze_util_windows.cc | 60 ++++--- src/main/cpp/main.cc | 3 +- src/main/cpp/option_processor.cc | 1 - src/main/cpp/util/bazel_log_handler.cc | 103 +++++++----- src/main/cpp/util/bazel_log_handler.h | 28 ++-- src/main/cpp/util/logging.cc | 20 ++- src/main/cpp/util/logging.h | 10 +- .../lib/runtime/BlazeServerStartupOptions.java | 4 +- src/test/cpp/util/logging_test.cc | 182 ++++++++++++++++++--- .../shell/integration/bazel_command_log_test.sh | 1 + src/test/shell/integration/client_test.sh | 8 +- 17 files changed, 379 insertions(+), 206 deletions(-) (limited to 'src') diff --git a/src/main/cpp/BUILD b/src/main/cpp/BUILD index 7f85db7770..1ec8912492 100644 --- a/src/main/cpp/BUILD +++ b/src/main/cpp/BUILD @@ -59,6 +59,7 @@ cc_library( deps = [ "//src/main/cpp/util", "//src/main/cpp/util:blaze_exit_code", + "//src/main/cpp/util:logging", ] + select({ "//src/conditions:windows": ["//src/main/native/windows:lib-file"], "//conditions:default": [], @@ -104,6 +105,7 @@ cc_binary( ":startup_options", ":workspace_layout", "//src/main/cpp/util", + "//src/main/cpp/util:bazel_log_handler", "//src/main/cpp/util:errors", "//src/main/cpp/util:logging", "//src/main/cpp/util:strings", diff --git a/src/main/cpp/blaze.cc b/src/main/cpp/blaze.cc index dc98060e75..60b0bcab71 100644 --- a/src/main/cpp/blaze.cc +++ b/src/main/cpp/blaze.cc @@ -57,6 +57,7 @@ #include "src/main/cpp/global_variables.h" #include "src/main/cpp/option_processor.h" #include "src/main/cpp/startup_options.h" +#include "src/main/cpp/util/bazel_log_handler.h" #include "src/main/cpp/util/errors.h" #include "src/main/cpp/util/exit_code.h" #include "src/main/cpp/util/file.h" @@ -459,8 +460,8 @@ static vector GetArgumentArray( result.push_back("-Dfile.encoding=ISO-8859-1"); if (globals->options->host_jvm_debug) { - fprintf(stderr, - "Running host JVM under debugger (listening on TCP port 5005).\n"); + BAZEL_LOG(USER) + << "Running host JVM under debugger (listening on TCP port 5005)."; // Start JVM so that it listens for a connection from a // JDWP-compliant debugger: result.push_back("-Xdebug"); @@ -718,10 +719,9 @@ static void StartStandalone(const WorkspaceLayout *workspace_layout, // Wall clock time since process startup. globals->startup_time = GetMillisecondsSinceProcessStart(); - if (VerboseLogging()) { - fprintf(stderr, "Starting %s in batch mode.\n", - globals->options->product_name.c_str()); - } + BAZEL_LOG(INFO) << "Starting " << globals->options->product_name + << " in batch mode."; + string command = globals->option_processor->GetCommand(); const vector command_arguments = globals->option_processor->GetCommandArguments(); @@ -816,8 +816,8 @@ static void StartServerAndConnect(const WorkspaceLayout *workspace_layout, if (server_pid > 0) { if (VerifyServerProcess(server_pid, globals->options->output_base)) { if (KillServerProcess(server_pid, globals->options->output_base)) { - fprintf(stderr, "Killed non-responsive server process (pid=%d)\n", - server_pid); + BAZEL_LOG(USER) << "Killed non-responsive server process (pid=" + << server_pid << ")"; SetRestartReasonIfNotSet(SERVER_UNRESPONSIVE); } else { SetRestartReasonIfNotSet(SERVER_VANISHED); @@ -833,9 +833,8 @@ static void StartServerAndConnect(const WorkspaceLayout *workspace_layout, BlazeServerStartup *server_startup; server_pid = StartServer(workspace_layout, &server_startup); - fprintf(stderr, "Starting local %s server and connecting to it...", - globals->options->product_name.c_str()); - fflush(stderr); + BAZEL_LOG(USER) << "Starting local " << globals->options->product_name + << " server and connecting to it..."; // Give the server two minutes to start up. That's enough to connect with a // debugger. @@ -852,6 +851,8 @@ static void StartServerAndConnect(const WorkspaceLayout *workspace_layout, } if (!globals->options->client_debug) { + // TODO(ccalvarin) Do we really need the dots? They're 10 years old, and + // there's something to be said about tradition, but in this case... fputc('.', stderr); fflush(stderr); } @@ -859,13 +860,14 @@ static void StartServerAndConnect(const WorkspaceLayout *workspace_layout, std::this_thread::sleep_until(next_attempt_time); if (!server_startup->IsStillAlive()) { globals->option_processor->PrintStartupOptionsProvenanceMessage(); - fprintf(stderr, "\nServer crashed during startup. "); if (globals->jvm_log_file_append) { // Don't dump the log if we were appending - the user should know where // to find it, and who knows how much content they may have accumulated. - fprintf(stderr, "See '%s'\n", globals->jvm_log_file.c_str()); + BAZEL_LOG(USER) << "\nServer crashed during startup. See " + << globals->jvm_log_file; } else { - fprintf(stderr, "Now printing '%s':\n", globals->jvm_log_file.c_str()); + BAZEL_LOG(USER) << "\nServer crashed during startup. Now printing " + << globals->jvm_log_file; WriteFileToStderrOrDie(globals->jvm_log_file.c_str()); } exit(blaze_exit_code::INTERNAL_ERROR); @@ -924,8 +926,9 @@ static void ActuallyExtractData(const string &argv0, embedded_binaries.c_str()); } - fprintf(stderr, "Extracting %s installation...\n", - globals->options->product_name.c_str()); + BAZEL_LOG(USER) << "Extracting " << globals->options->product_name + << " installation..."; + std::unique_ptr extractor( devtools_ijar::ZipExtractor::Create(argv0.c_str(), &processor)); if (extractor.get() == NULL) { @@ -1037,10 +1040,9 @@ static void ExtractData(const string &self_path) { // (in case we're running on Windows) so we need to wait for that to // finish and try renaming again. ++attempts; - fprintf(stderr, - "install base directory '%s' could not be renamed into place" - "after %d second(s), trying again\r", - tmp_install.c_str(), attempts); + BAZEL_LOG(USER) << "install base directory '" << tmp_install + << "' could not be renamed into place after " + << attempts << " second(s), trying again\r"; std::this_thread::sleep_for(std::chrono::seconds(1)); } } @@ -1241,19 +1243,15 @@ static ATTRIBUTE_NORETURN void SendServerRequest( // There's a distant possibility that the two paths look the same yet are // actually different because the two processes have different mount // tables. - if (VerboseLogging()) { - fprintf(stderr, "Server's cwd moved or deleted (%s).\n", - server_cwd.c_str()); - } + BAZEL_LOG(INFO) << "Server's cwd moved or deleted (" << server_cwd + << ")."; server->KillRunningServer(); } else { break; } } - if (VerboseLogging()) { - fprintf(stderr, "Connected (server pid=%d).\n", globals->server_pid); - } + BAZEL_LOG(INFO) << "Connected (server pid=" << globals->server_pid << ")."; // Wall clock time since process startup. globals->startup_time = GetMillisecondsSinceProcessStart(); @@ -1444,10 +1442,11 @@ int GetExitCodeForAbruptExit(const GlobalVariables &globals) { } int Main(int argc, const char *argv[], WorkspaceLayout *workspace_layout, - OptionProcessor *option_processor, - std::unique_ptr log_handler) { + OptionProcessor *option_processor) { // Logging must be set first to assure no log statements are missed. - blaze_util::SetLogHandler(std::move(log_handler)); + std::unique_ptr default_handler( + new blaze_util::BazelLogHandler()); + blaze_util::SetLogHandler(std::move(default_handler)); globals = new GlobalVariables(option_processor); blaze::SetupStdStreams(); @@ -1476,8 +1475,10 @@ int Main(int argc, const char *argv[], WorkspaceLayout *workspace_layout, globals->binary_path = CheckAndGetBinaryPath(argv[0]); ParseOptions(argc, argv); - blaze::SetDebugLog(globals->options->client_debug); - debug_log("Debug logging active"); + SetDebugLog(globals->options->client_debug); + // If client_debug was false, this is ignored, so it's accurate. + BAZEL_LOG(INFO) << "Debug logging requested, sending all client log " + "statements to stderr"; PrepareEnvironmentForJvm(); blaze::CreateSecureOutputRoot(globals->options->output_user_root); @@ -1537,13 +1538,13 @@ bool GrpcBlazeServer::TryConnect(command_server::CommandServer::Stub *client) { command_server::PingResponse response; request.set_cookie(request_cookie_); - debug_log("Trying to connect to server (timeout: %d secs)...", - connect_timeout_secs_); + BAZEL_LOG(INFO) << "Trying to connect to server (timeout: " + << connect_timeout_secs_ << " secs)..."; grpc::Status status = client->Ping(&context, request, &response); if (!status.ok() || response.cookie() != response_cookie_) { - debug_log("Connection to server failed: %s", - status.error_message().c_str()); + BAZEL_LOG(INFO) << "Connection to server failed: " + << status.error_message().c_str(); return false; } @@ -1692,8 +1693,8 @@ void GrpcBlazeServer::SendCancelMessage() { // There isn't a lot we can do if this request fails grpc::Status status = client_->Cancel(&context, request, &response); if (!status.ok()) { - fprintf(stderr, "\nCould not interrupt server (%s)\n\n", - status.error_message().c_str()); + BAZEL_LOG(USER) << "\nCould not interrupt server (" + << status.error_message().c_str() << ")\n"; } } @@ -1788,12 +1789,12 @@ unsigned int GrpcBlazeServer::Communicate() { while (reader->Read(&response)) { if (finished && !finished_warning_emitted) { - fprintf(stderr, "\nServer returned messages after reporting exit code\n"); + BAZEL_LOG(USER) << "\nServer returned messages after reporting exit code"; finished_warning_emitted = true; } if (response.cookie() != response_cookie_) { - fprintf(stderr, "\nServer response cookie invalid, exiting\n"); + BAZEL_LOG(USER) << "\nServer response cookie invalid, exiting"; return blaze_exit_code::INTERNAL_ERROR; } @@ -1824,7 +1825,8 @@ unsigned int GrpcBlazeServer::Communicate() { if (broken_pipe_name != nullptr && !pipe_broken) { pipe_broken = true; - fprintf(stderr, "\nCannot write to %s; exiting...\n\n", broken_pipe_name); + BAZEL_LOG(USER) << "\nCannot write to " << broken_pipe_name + << "; exiting...\n"; Cancel(); } @@ -1850,23 +1852,21 @@ unsigned int GrpcBlazeServer::Communicate() { grpc::Status status = reader->Finish(); if (!status.ok()) { - fprintf(stderr, - "\nServer terminated abruptly " - "(error code: %d, error message: '%s', log file: '%s')\n\n", - status.error_code(), status.error_message().c_str(), - globals->jvm_log_file.c_str()); + BAZEL_LOG(USER) << "\nServer terminated abruptly (error code: " + << status.error_code() << ", error message: '" + << status.error_message() << "', log file: '" + << globals->jvm_log_file << "')\n"; return GetExitCodeForAbruptExit(*globals); } else if (!finished) { - fprintf(stderr, - "\nServer finished RPC without an explicit exit code " - "(log file: '%s')\n\n", - globals->jvm_log_file.c_str()); + BAZEL_LOG(USER) + << "\nServer finished RPC without an explicit exit code (log file: '" + << globals->jvm_log_file << "')\n"; return GetExitCodeForAbruptExit(*globals); } else if (final_response.has_exec_request()) { const command_server::ExecRequest& request = final_response.exec_request(); if (request.argv_size() < 1) { - fprintf(stderr, - "\nServer requested exec() but did not pass a binary to execute\n\n"); + BAZEL_LOG(USER) + << "\nServer requested exec() but did not pass a binary to execute\n"; return blaze_exit_code::INTERNAL_ERROR; } diff --git a/src/main/cpp/blaze.h b/src/main/cpp/blaze.h index 7e3636d610..d5c467d464 100644 --- a/src/main/cpp/blaze.h +++ b/src/main/cpp/blaze.h @@ -21,8 +21,7 @@ namespace blaze { int Main(int argc, const char* argv[], WorkspaceLayout* workspace_layout, - OptionProcessor* option_processor, - std::unique_ptr log_handler); + OptionProcessor* option_processor); } // namespace blaze diff --git a/src/main/cpp/blaze_util.cc b/src/main/cpp/blaze_util.cc index f0a6f21e6d..e8d238a479 100644 --- a/src/main/cpp/blaze_util.cc +++ b/src/main/cpp/blaze_util.cc @@ -19,14 +19,16 @@ #include #include #include +#include #include "src/main/cpp/blaze_util_platform.h" #include "src/main/cpp/util/errors.h" #include "src/main/cpp/util/exit_code.h" #include "src/main/cpp/util/file.h" +#include "src/main/cpp/util/logging.h" #include "src/main/cpp/util/numbers.h" -#include "src/main/cpp/util/strings.h" #include "src/main/cpp/util/port.h" +#include "src/main/cpp/util/strings.h" using blaze_util::die; @@ -122,8 +124,6 @@ bool SearchNullaryOption(const vector& args, return result; } -bool VerboseLogging() { return !GetEnv("VERBOSE_BLAZE_CLIENT").empty(); } - // Read the Jvm version from a file descriptor. The read fd // should contains a similar output as the java -version output. string ReadJvmVersion(const string& version_string) { @@ -215,22 +215,17 @@ bool AwaitServerProcessTermination(int pid, const string& output_base, return true; } -static bool is_debug_log_enabled = false; - -void SetDebugLog(bool enabled) { is_debug_log_enabled = enabled; } - -void debug_log(const char *format, ...) { - if (!is_debug_log_enabled) { - return; +// For now, we don't have the client set up to log to a file. If --client_debug +// is passed, however, all BAZEL_LOG statements will be output to stderr. +// If/when we switch to logging these to a file, care will have to be taken to +// either log to both stderr and the file in the case of --client_debug, or be +// ok that these log lines will only go to one stream. +void SetDebugLog(bool enabled) { + if (enabled) { + blaze_util::SetLoggingOutputStreamToStderr(); + } else { + blaze_util::SetLoggingOutputStream(nullptr); } - - fprintf(stderr, "CLIENT: "); - va_list arglist; - va_start(arglist, format); - vfprintf(stderr, format, arglist); - va_end(arglist); - fprintf(stderr, "%s", "\n"); - fflush(stderr); } } // namespace blaze diff --git a/src/main/cpp/blaze_util.h b/src/main/cpp/blaze_util.h index c28e55fa14..011221871e 100644 --- a/src/main/cpp/blaze_util.h +++ b/src/main/cpp/blaze_util.h @@ -66,9 +66,6 @@ bool SearchNullaryOption(const std::vector& args, const std::string& flag_name, const bool default_value); -// Enable messages mostly of interest to developers. -bool VerboseLogging(); - // Read the JVM version from a string. The string should contain the output of a // "java -version" execution and is supposed to contain a string of the form // 'version "version-number"' in the first 255 bytes. If the string is found, @@ -123,10 +120,6 @@ std::string ToString(const T &value) { // Revisit once client logging is fixed (b/32939567). void SetDebugLog(bool enabled); -// Output debug information from client. -// Revisit once client logging is fixed (b/32939567). -void debug_log(const char *format, ...); - } // namespace blaze #endif // BAZEL_SRC_MAIN_CPP_BLAZE_UTIL_H_ diff --git a/src/main/cpp/blaze_util_posix.cc b/src/main/cpp/blaze_util_posix.cc index fff8028712..076985fce0 100644 --- a/src/main/cpp/blaze_util_posix.cc +++ b/src/main/cpp/blaze_util_posix.cc @@ -42,6 +42,7 @@ #include "src/main/cpp/util/errors.h" #include "src/main/cpp/util/exit_code.h" #include "src/main/cpp/util/file.h" +#include "src/main/cpp/util/logging.h" #include "src/main/cpp/util/md5.h" #include "src/main/cpp/util/numbers.h" @@ -165,21 +166,12 @@ const char** ConvertStringVectorToArgv(const vector& args) { return argv; } -void ExecuteProgram(const string &exe, const vector &args_vector) { - if (VerboseLogging()) { - string dbg; - for (const auto &s : args_vector) { - dbg.append(s); - dbg.append(" "); - } - - string cwd = blaze_util::GetCwd(); - fprintf(stderr, "Invoking binary %s in %s:\n %s\n", exe.c_str(), - cwd.c_str(), dbg.c_str()); - } +void ExecuteProgram(const string& exe, const vector& args_vector) { + BAZEL_LOG(INFO) << "Invoking binary " << exe << " in " + << blaze_util::GetCwd(); const char** argv = ConvertStringVectorToArgv(args_vector); - execv(exe.c_str(), const_cast(argv)); + execv(exe.c_str(), const_cast(argv)); } std::string ConvertPath(const std::string &path) { return path; } diff --git a/src/main/cpp/blaze_util_windows.cc b/src/main/cpp/blaze_util_windows.cc index 430533333f..d49e128e11 100644 --- a/src/main/cpp/blaze_util_windows.cc +++ b/src/main/cpp/blaze_util_windows.cc @@ -40,6 +40,7 @@ #include "src/main/cpp/util/exit_code.h" #include "src/main/cpp/util/file.h" #include "src/main/cpp/util/file_platform.h" +#include "src/main/cpp/util/logging.h" #include "src/main/cpp/util/md5.h" #include "src/main/cpp/util/numbers.h" #include "src/main/cpp/util/strings.h" @@ -1166,7 +1167,7 @@ static string GetMsysBash() { KEY_QUERY_VALUE, // _In_ REGSAM samDesired, &h_uninstall // _Out_ PHKEY phkResult )) { - debug_log("Cannot open HKCU\\%s", key); + BAZEL_LOG(INFO) << "Cannot open HKCU\\" << key; return string(); } AutoHandle auto_uninstall(h_uninstall); @@ -1191,7 +1192,7 @@ static string GetMsysBash() { 0, // _Out_opt_ LPDWORD lpcbSecurityDescriptor, 0 // _Out_opt_ PFILETIME lpftLastWriteTime )) { - debug_log("Cannot query HKCU\\%s", key); + BAZEL_LOG(INFO) << "Cannot query HKCU\\" << key; return string(); } @@ -1202,7 +1203,8 @@ static string GetMsysBash() { subkey_name, // _Out_ LPTSTR lpName, sizeof(subkey_name) // _In_ DWORD cchName )) { - debug_log("Cannot get %d subkey of HKCU\\%s", key_index, key); + BAZEL_LOG(INFO) << "Cannot get " << key_index << " subkey of HKCU\\" + << key; continue; // try next subkey } @@ -1213,7 +1215,8 @@ static string GetMsysBash() { KEY_QUERY_VALUE, // _In_ REGSAM samDesired, &h_subkey // _Out_ PHKEY phkResult )) { - debug_log("Failed to open subkey HKCU\\%s\\%s", key, subkey_name); + BAZEL_LOG(ERROR) << "Failed to open subkey HKCU\\" << key << "\\" + << subkey_name; continue; // try next subkey } AutoHandle auto_subkey(h_subkey); @@ -1229,14 +1232,15 @@ static string GetMsysBash() { value, // _Out_opt_ LPBYTE lpData, &value_length // _Inout_opt_ LPDWORD lpcbData )) { - debug_log("Failed to query DisplayName of HKCU\\%s\\%s", key, - subkey_name); + BAZEL_LOG(ERROR) << "Failed to query DisplayName of HKCU\\" << key << "\\" + << subkey_name; continue; // try next subkey } if (value_type == REG_SZ && 0 == memcmp(msys_display_name, value, sizeof(msys_display_name))) { - debug_log("Getting install location of HKCU\\%s\\%s", key, subkey_name); + BAZEL_LOG(INFO) << "Getting install location of HKCU\\" << key << "\\" + << subkey_name; BYTE path[REG_VALUE_BUFFER_SIZE]; DWORD path_length = sizeof(path); DWORD path_type; @@ -1248,27 +1252,28 @@ static string GetMsysBash() { path, // _Out_opt_ LPBYTE lpData, &path_length // _Inout_opt_ LPDWORD lpcbData )) { - debug_log("Failed to query InstallLocation of HKCU\\%s\\%s", key, - subkey_name); + BAZEL_LOG(ERROR) << "Failed to query InstallLocation of HKCU\\" << key + << "\\" << subkey_name; continue; // try next subkey } if (path_length == 0 || path_type != REG_SZ) { - debug_log("Zero-length (%d) install location or wrong type (%d)", - path_length, path_type); + BAZEL_LOG(ERROR) << "Zero-length (" << path_length + << ") install location or wrong type (" << path_type + << ")"; continue; // try next subkey } - debug_log("Install location of HKCU\\%s\\%s is %s", key, subkey_name, - path); + BAZEL_LOG(INFO) << "Install location of HKCU\\" << key << "\\" + << subkey_name << " is " << path; string path_as_string(path, path + path_length - 1); string bash_exe = path_as_string + "\\usr\\bin\\bash.exe"; if (!blaze_util::PathExists(bash_exe)) { - debug_log("%s does not exist", bash_exe.c_str()); + BAZEL_LOG(INFO) << bash_exe.c_str() << " does not exist"; continue; // try next subkey } - debug_log("Detected msys bash at %s", bash_exe.c_str()); + BAZEL_LOG(INFO) << "Detected msys bash at " << bash_exe.c_str(); return bash_exe; } } @@ -1288,12 +1293,12 @@ static string GetBashFromGitOnWin() { KEY_QUERY_VALUE, // _In_ REGSAM samDesired, &h_GitOnWin_uninstall // _Out_ PHKEY phkResult )) { - debug_log("Cannot open HKCU\\%s", key); + BAZEL_LOG(INFO) << "Cannot open HKCU\\" << key; return string(); } AutoHandle auto_h_GitOnWin_uninstall(h_GitOnWin_uninstall); - debug_log("Getting install location of HKLM\\%s", key); + BAZEL_LOG(INFO) << "Getting install location of HKLM\\" << key; BYTE path[REG_VALUE_BUFFER_SIZE]; DWORD path_length = sizeof(path); DWORD path_type; @@ -1304,25 +1309,26 @@ static string GetBashFromGitOnWin() { path, // _Out_opt_ LPBYTE lpData, &path_length // _Inout_opt_ LPDWORD lpcbData )) { - debug_log("Failed to query InstallLocation of HKLM\\%s", key); + BAZEL_LOG(ERROR) << "Failed to query InstallLocation of HKLM\\" << key; return string(); } if (path_length == 0 || path_type != REG_SZ) { - debug_log("Zero-length (%d) install location or wrong type (%d)", - path_length, path_type); + BAZEL_LOG(ERROR) << "Zero-length (" << path_length + << ") install location or wrong type (" << path_type + << ")"; return string(); } - debug_log("Install location of HKLM\\%s is %s", key, path); + BAZEL_LOG(INFO) << "Install location of HKLM\\" << key << " is " << path; string path_as_string(path, path + path_length - 1); string bash_exe = path_as_string + "\\usr\\bin\\bash.exe"; if (!blaze_util::PathExists(bash_exe)) { - debug_log("%s does not exist", bash_exe.c_str()); + BAZEL_LOG(ERROR) << "%s does not exist", bash_exe.c_str(); return string(); } - debug_log("Detected git-on-Windows bash at %s", bash_exe.c_str()); + BAZEL_LOG(INFO) << "Detected git-on-Windows bash at " << bash_exe.c_str(); return bash_exe; } @@ -1350,7 +1356,7 @@ static string GetBinaryFromPath(const string& binary_name) { found, // _Out_ LPTSTR lpBuffer, 0 // _Out_opt_ LPTSTR *lpFilePart )) { - debug_log("%s found on PATH: %s", binary_name.c_str(), found); + BAZEL_LOG(INFO) << binary_name.c_str() << " found on PATH: " << found; return string(found); } if (end == string::npos) { @@ -1359,7 +1365,7 @@ static string GetBinaryFromPath(const string& binary_name) { start = end + 1; } while (true); - debug_log("%s not found on PATH", binary_name.c_str()); + BAZEL_LOG(ERROR) << binary_name.c_str() << " not found on PATH"; return string(); } @@ -1384,8 +1390,8 @@ void DetectBashOrDie() { string bash = LocateBash(); uint64_t end = blaze::GetMillisecondsMonotonic(); - debug_log("BAZEL_SH detection took %lu msec, found %s", end - start, - bash.c_str()); + BAZEL_LOG(INFO) << "BAZEL_SH detection took " << end - start + << " msec, found " << bash.c_str(); if (!bash.empty()) { // Set process environment variable. diff --git a/src/main/cpp/main.cc b/src/main/cpp/main.cc index 81a599ae36..c88ea9ffd8 100644 --- a/src/main/cpp/main.cc +++ b/src/main/cpp/main.cc @@ -26,6 +26,5 @@ int main(int argc, const char *argv[]) { new blaze::StartupOptions(workspace_layout.get())); return blaze::Main(argc, argv, workspace_layout.get(), new blaze::OptionProcessor(workspace_layout.get(), - std::move(startup_options)), - nullptr /* TODO(b/32939567): Enable Bazel logging. */); + std::move(startup_options))); } diff --git a/src/main/cpp/option_processor.cc b/src/main/cpp/option_processor.cc index 4e0c45521b..158ecb99f3 100644 --- a/src/main/cpp/option_processor.cc +++ b/src/main/cpp/option_processor.cc @@ -462,7 +462,6 @@ std::vector OptionProcessor::GetBlazercAndEnvCommandArgs( // Pass the client environment to the server. for (const string& env_var : env) { - debug_log("--client_env=%s", env_var.c_str()); result.push_back("--client_env=" + env_var); } result.push_back("--client_cwd=" + blaze::ConvertPath(cwd)); diff --git a/src/main/cpp/util/bazel_log_handler.cc b/src/main/cpp/util/bazel_log_handler.cc index 77073bf1a3..b0ebeb49f7 100644 --- a/src/main/cpp/util/bazel_log_handler.cc +++ b/src/main/cpp/util/bazel_log_handler.cc @@ -16,7 +16,6 @@ #include #include -#include #include #include @@ -26,20 +25,24 @@ namespace blaze_util { BazelLogHandler::BazelLogHandler() - : output_dir_set_attempted_(false), + : output_stream_set_(false), + logging_deactivated_(false), buffer_stream_(new std::stringstream()), - logfile_stream_(nullptr) {} + output_stream_(), + owned_output_stream_() {} BazelLogHandler::~BazelLogHandler() { - // If we never wrote the logs to a file, dump the buffer to stderr, - // otherwise, flush the stream. - if (logfile_stream_ != nullptr) { - logfile_stream_->flush(); - } else if (buffer_stream_ != nullptr) { - std::cerr << buffer_stream_->rdbuf(); - } else { - std::cerr << "Illegal state - neither a logfile nor a logbuffer " - << "existed at program end." << std::endl; + if (!logging_deactivated_) { + // If SetLoggingOutputStream was never called, dump the buffer to stderr, + // otherwise, flush the stream. + if (output_stream_ != nullptr) { + output_stream_->flush(); + } else if (buffer_stream_ != nullptr) { + std::cerr << buffer_stream_->rdbuf(); + } else { + std::cerr << "Illegal state - neither a logfile nor a logbuffer " + << "existed at program end." << std::endl; + } } } @@ -47,48 +50,74 @@ void BazelLogHandler::HandleMessage(LogLevel level, const std::string& filename, int line, const std::string& message) { // Select the appropriate stream to log to. std::ostream* log_stream; - if (logfile_stream_ != nullptr) { - log_stream = logfile_stream_.get(); - } else { + if (logging_deactivated_) { + // Do nothing if the output stream was explicitly deactivated, unless the + // level is USER, in which case the message is meant to be user-visible + // regardless of logging settings. + if (level == LOGLEVEL_USER) { + std::cerr << message << std::endl; + } + return; + } else if (output_stream_ == nullptr) { log_stream = buffer_stream_.get(); + } else { + log_stream = output_stream_; } - *log_stream << "[bazel " << LogLevelName(level) << " " << filename << ":" - << line << "] " << message << "\n"; + (*log_stream) << "[bazel " << LogLevelName(level) << " " << filename << ":" + << line << "] " << message << std::endl; // If we have a fatal message, we should abort and leave a stack trace - // normal exit behavior will be lost, so print this log message out to // stderr and avoid loosing the information. if (level == LOGLEVEL_FATAL) { std::cerr << "[bazel " << LogLevelName(level) << " " << filename << ":" - << line << "] " << message << "\n"; + << line << "] " << message << std::endl; std::abort(); } } -void BazelLogHandler::SetOutputDir(const std::string& new_output_dir) { - // Disallow second calls to this, we only intend this to support setting - // output_base once it is created, not changing the log location. - BAZEL_CHECK(!output_dir_set_attempted_) - << "Tried to SetOutputDir a second time, to " << new_output_dir; - output_dir_set_attempted_ = true; +void BazelLogHandler::SetOutputStreamToStderr() { + // Disallow second calls to this, we only intend to support setting the output + // once, otherwise the buffering will not work as intended and the log will be + // fragmented. + BAZEL_CHECK(!output_stream_set_) << "Tried to set log output a second time"; + output_stream_set_ = true; + + FlushBufferToNewStreamAndSet(&std::cerr); +} + +void BazelLogHandler::SetOutputStream( + std::unique_ptr new_output_stream) { + // Disallow second calls to this, we only intend to support setting the output + // once, otherwise the buffering will not work as intended and the log will be + // fragmented. + BAZEL_CHECK(!output_stream_set_) << "Tried to set log output a second time"; + output_stream_set_ = true; + + if (new_output_stream == nullptr) { + logging_deactivated_ = true; + buffer_stream_ = nullptr; + return; + } + owned_output_stream_ = std::move(new_output_stream); + FlushBufferToNewStreamAndSet(owned_output_stream_.get()); +} - // Create a log file in the newly available directory, and flush the - // buffer to it. - const std::string logfile = JoinPath(new_output_dir, "bazel_client.log"); - logfile_stream_ = std::unique_ptr( - new std::ofstream(logfile, std::fstream::out)); - if (logfile_stream_->fail()) { +void BazelLogHandler::FlushBufferToNewStreamAndSet( + std::ostream* new_output_stream) { + // Flush the buffer to the new stream, and print new log lines to it. + output_stream_ = new_output_stream; + if (output_stream_->fail()) { // If opening the stream failed, continue buffering and have the logs // dump to stderr at shutdown. - logfile_stream_ = nullptr; - BAZEL_LOG(ERROR) << "Opening the log file failed, in directory " - << new_output_dir; + output_stream_ = nullptr; + BAZEL_LOG(ERROR) << "Provided stream failed."; } else { - // Transfer the contents of the buffer to the logfile's stream before - // replacing it. - *logfile_stream_ << buffer_stream_->rdbuf(); + // Transfer the contents of the buffer to the new stream, then remove the + // buffer. + (*output_stream_) << buffer_stream_->str(); buffer_stream_ = nullptr; - logfile_stream_->flush(); + output_stream_->flush(); } } diff --git a/src/main/cpp/util/bazel_log_handler.h b/src/main/cpp/util/bazel_log_handler.h index e9a09ae86c..43e89650e4 100644 --- a/src/main/cpp/util/bazel_log_handler.h +++ b/src/main/cpp/util/bazel_log_handler.h @@ -22,10 +22,10 @@ namespace blaze_util { // Handles logging for the Bazel client. -// In order to have the logfile in output_base, which does not exist or is -// unknown at the time of the client's creation, logs are buffered until -// SetOutputDir is called. At that point, all past log statements are dumped -// in the appropriate file, and all following statements are logged directly. +// In order to control where the log output goes based on the flags received at +// startup, logs are buffered until SetOutputStream is called. At that point, +// all past log statements are dumped in the appropriate stream, and all +// following statements are logged directly. class BazelLogHandler : public blaze_util::LogHandler { public: BazelLogHandler(); @@ -33,18 +33,20 @@ class BazelLogHandler : public blaze_util::LogHandler { void HandleMessage(blaze_util::LogLevel level, const std::string& filename, int line, const std::string& message) override; - - // Sets the output directory of the logfile. - // Can only be called once - all logs before this call will be buffered and - // dumped to the logfile once this is called. If this is never called, or if - // creating the logfile failed, the buffered logs will be dumped to stderr at - // destruction. - void SetOutputDir(const std::string& new_output_dir) override; + void SetOutputStream( + std::unique_ptr new_output_stream) override; + void SetOutputStreamToStderr() override; private: - bool output_dir_set_attempted_; + void FlushBufferToNewStreamAndSet(std::ostream* new_output_stream); + bool output_stream_set_; + bool logging_deactivated_; std::unique_ptr buffer_stream_; - std::unique_ptr logfile_stream_; + // The actual output_stream to which all logs will be sent. + std::ostream* output_stream_; + // A unique pts to the output_stream, if we need to keep ownership of the + // stream. In the case of stderr logging, this is null. + std::unique_ptr owned_output_stream_; }; } // namespace blaze_util diff --git a/src/main/cpp/util/logging.cc b/src/main/cpp/util/logging.cc index 7d0bd0bfd0..8ae4b5dbb3 100644 --- a/src/main/cpp/util/logging.cc +++ b/src/main/cpp/util/logging.cc @@ -23,9 +23,10 @@ namespace blaze_util { const char* LogLevelName(LogLevel level) { - static const char* level_names[] = {"INFO", "WARNING", "ERROR", "FATAL"}; - BAZEL_CHECK(static_cast(level) < 4) - << "LogLevelName: level out of range, there are only 4 levels."; + static const char* level_names[] = {"INFO", "USER", "WARNING", "ERROR", + "FATAL"}; + BAZEL_CHECK(static_cast(level) < 5) + << "LogLevelName: level out of range, there are only 5 levels."; return level_names[level]; } @@ -64,6 +65,10 @@ void LogMessage::Finish() { std::string message(message_.str()); if (log_handler_ != nullptr) { log_handler_->HandleMessage(level_, filename_, line_, message); + } else if (level_ == LOGLEVEL_USER) { + // Messages directed at the user should be printed even without a log + // handler. + std::cerr << message << std::endl; } else if (level_ == LOGLEVEL_FATAL) { // Expect the log_handler_ to handle FATAL calls, but we should still fail // as expected even if no log_handler_ is defined. For ease of debugging, @@ -82,9 +87,14 @@ void SetLogHandler(std::unique_ptr new_handler) { internal::log_handler_ = std::move(new_handler); } -void SetLogfileDirectory(const std::string& output_dir) { +void SetLoggingOutputStream(std::unique_ptr output_stream) { if (internal::log_handler_ != nullptr) { - internal::log_handler_->SetOutputDir(output_dir); + internal::log_handler_->SetOutputStream(std::move(output_stream)); + } +} +void SetLoggingOutputStreamToStderr() { + if (internal::log_handler_ != nullptr) { + internal::log_handler_->SetOutputStreamToStderr(); } } diff --git a/src/main/cpp/util/logging.h b/src/main/cpp/util/logging.h index 506ed59eb7..878a3e68df 100644 --- a/src/main/cpp/util/logging.h +++ b/src/main/cpp/util/logging.h @@ -28,6 +28,7 @@ namespace blaze_util { enum LogLevel { LOGLEVEL_INFO, + LOGLEVEL_USER, LOGLEVEL_WARNING, LOGLEVEL_ERROR, LOGLEVEL_FATAL, @@ -142,7 +143,9 @@ class LogHandler { virtual ~LogHandler() {} virtual void HandleMessage(LogLevel level, const std::string& filename, int line, const std::string& message) = 0; - virtual void SetOutputDir(const std::string& output_base) = 0; + + virtual void SetOutputStream(std::unique_ptr output_stream) = 0; + virtual void SetOutputStreamToStderr() = 0; }; // Sets the log handler that routes all log messages. @@ -150,8 +153,9 @@ class LogHandler { // at initialization time, and probably not from library code. void SetLogHandler(std::unique_ptr new_handler); -// Sets the current handler's output directory, given that the Handler cares. -void SetLogfileDirectory(const std::string& output_dir); +// Set the stream to which all log statements will be sent. +void SetLoggingOutputStream(std::unique_ptr output_stream); +void SetLoggingOutputStreamToStderr(); } // namespace blaze_util diff --git a/src/main/java/com/google/devtools/build/lib/runtime/BlazeServerStartupOptions.java b/src/main/java/com/google/devtools/build/lib/runtime/BlazeServerStartupOptions.java index a033e7da19..a640e6ff42 100644 --- a/src/main/java/com/google/devtools/build/lib/runtime/BlazeServerStartupOptions.java +++ b/src/main/java/com/google/devtools/build/lib/runtime/BlazeServerStartupOptions.java @@ -400,7 +400,9 @@ public class BlazeServerStartupOptions extends OptionsBase { category = "server startup", documentationCategory = OptionDocumentationCategory.BAZEL_CLIENT_OPTIONS, effectTags = {OptionEffectTag.AFFECTS_OUTPUTS, OptionEffectTag.BAZEL_MONITORING}, - help = "If true, log debug information from the client to stderr" + help = + "If true, log debug information from the client to stderr. Changing this option will not " + + "cause the server to restart." ) public boolean clientDebug; diff --git a/src/test/cpp/util/logging_test.cc b/src/test/cpp/util/logging_test.cc index 3288bdf0a2..5779030c68 100644 --- a/src/test/cpp/util/logging_test.cc +++ b/src/test/cpp/util/logging_test.cc @@ -11,6 +11,7 @@ // WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. // See the License for the specific language governing permissions and // limitations under the License. +#include #include #include #include @@ -21,14 +22,18 @@ #include "gtest/gtest.h" namespace blaze_util { +class LoggingTest : public ::testing::Test { + protected: + void SetUp() { + // Set the value of $TMP first, because CaptureStderr retrieves a temp + // directory path and on Windows, the corresponding function (GetTempPathA) + // reads $TMP. + blaze::SetEnv("TMP", blaze::GetEnv("TEST_TMPDIR")); + } +}; TEST(LoggingTest, BazelLogHandlerDumpsToCerrAtFail) { - // Set the value of $TMP first, because CaptureStderr retrieves a temp - // directory path and on Windows, the corresponding function (GetTempPathA) - // reads $TMP. - blaze::SetEnv("TMP", blaze::GetEnv("TEST_TMPDIR")); - // Set up logging now that $TMP is set, and be prepared to capture stderr at - // destruction. + // Set up logging and be prepared to capture stderr at destruction. testing::internal::CaptureStderr(); std::unique_ptr handler( new blaze_util::BazelLogHandler()); @@ -39,14 +44,19 @@ TEST(LoggingTest, BazelLogHandlerDumpsToCerrAtFail) { BAZEL_LOG(INFO) << teststring; // Check that stderr isn't getting anything yet. - std::string nothing = testing::internal::GetCapturedStderr(); - ASSERT_TRUE(nothing.find(teststring) == std::string::npos); + std::string stderr_output = testing::internal::GetCapturedStderr(); + EXPECT_TRUE(stderr_output.find(teststring) == std::string::npos) + << "stderr unexpectedly contains the log message, before log output was " + "set. Stderr contained: " + << stderr_output; testing::internal::CaptureStderr(); // Destruct the log handler and get the stderr remains. blaze_util::SetLogHandler(nullptr); - std::string output = testing::internal::GetCapturedStderr(); - ASSERT_TRUE(output.find(teststring) != std::string::npos); + stderr_output = testing::internal::GetCapturedStderr(); + EXPECT_TRUE(stderr_output.find(teststring) != std::string::npos) + << "stderr does not contain the expected message. Stderr contained: " + << stderr_output; } TEST(LoggingTest, LogLevelNamesMatch) { @@ -56,26 +66,156 @@ TEST(LoggingTest, LogLevelNamesMatch) { EXPECT_STREQ("FATAL", LogLevelName(LOGLEVEL_FATAL)); } +TEST(LoggingTest, BazelLogDoesNotDumpToStderrIfOuputStreamSetToNull) { + // Set up logging and be prepared to capture stderr at destruction. + testing::internal::CaptureStderr(); + std::unique_ptr handler( + new blaze_util::BazelLogHandler()); + blaze_util::SetLogHandler(std::move(handler)); + + // Log something. + std::string teststring = "test that the log message is lost."; + BAZEL_LOG(INFO) << teststring; + blaze_util::SetLoggingOutputStream(nullptr); + + // Destruct the log handler and check if stderr got anything. + blaze_util::SetLogHandler(nullptr); + std::string stderr_output = testing::internal::GetCapturedStderr(); + EXPECT_TRUE(stderr_output.find(teststring) == std::string::npos) + << "stderr unexpectedly contains the log message, even though log output " + "was explicitly set to null. Stderr contained: " + << stderr_output; +} + +TEST(LoggingTest, DirectLogsToBufferStreamWorks) { + // Set up logging and be prepared to capture stderr at destruction. + testing::internal::CaptureStderr(); + std::unique_ptr handler( + new blaze_util::BazelLogHandler()); + blaze_util::SetLogHandler(std::move(handler)); + + // Ask that the logs get output to a string buffer (keep a ptr to it so we can + // check its contents) + std::unique_ptr stringbuf(new std::stringstream()); + std::stringstream* stringbuf_ptr = stringbuf.get(); + blaze_util::SetLoggingOutputStream(std::move(stringbuf)); + + std::string teststring = "testing log getting directed to a stringbuffer."; + BAZEL_LOG(INFO) << teststring; + + // Check that output went to the buffer. + std::string output(stringbuf_ptr->str()); + EXPECT_TRUE(output.find(teststring) != std::string::npos) + << "log output is missing the log message, the output is: " << output; + + // Check that the output never went to stderr. + std::string stderr_output = testing::internal::GetCapturedStderr(); + EXPECT_TRUE(stderr_output.find(teststring) == std::string::npos) + << "stderr unexpectedly contains the log message that should have gone " + "to the specified string buffer. Stderr contained: " + << stderr_output; +} + +TEST(LoggingTest, BufferedLogsSentToSpecifiedStream) { + // Set up logging and be prepared to capture stderr at destruction. + testing::internal::CaptureStderr(); + std::unique_ptr handler( + new blaze_util::BazelLogHandler()); + blaze_util::SetLogHandler(std::move(handler)); + + std::string teststring = + "test sending logs to the buffer before setting the output stream"; + BAZEL_LOG(INFO) << teststring; + + // Check that stderr isn't getting anything yet. + std::string stderr_output = testing::internal::GetCapturedStderr(); + EXPECT_TRUE(stderr_output.find(teststring) == std::string::npos) + << "stderr unexpectedly contains the log message, before log output was " + "set. Stderr contained: " + << stderr_output; + testing::internal::CaptureStderr(); + + // Ask that the logs get output to a string buffer (keep a ptr to it so we can + // check its contents) + std::unique_ptr stringbuf(new std::stringstream()); + std::stringstream* stringbuf_ptr = stringbuf.get(); + blaze_util::SetLoggingOutputStream(std::move(stringbuf)); + + // Check that the buffered logs were sent. + std::string output(stringbuf_ptr->str()); + EXPECT_TRUE(output.find(teststring) != std::string::npos) + << "log output is missing the log message, the output is: " << output; + + // Check that the output did not go to stderr. + stderr_output = testing::internal::GetCapturedStderr(); + EXPECT_TRUE(stderr_output.find(teststring) == std::string::npos) + << "stderr unexpectedly contains the log message that should have gone " + "to the specified string buffer. Stderr contained: " + << stderr_output; +} + +TEST(LoggingTest, DirectLogsToCerrWorks) { + // Set up logging and be prepared to capture stderr at destruction. + testing::internal::CaptureStderr(); + std::unique_ptr handler( + new blaze_util::BazelLogHandler()); + blaze_util::SetLogHandler(std::move(handler)); + + // Ask that the logs get output to stderr + blaze_util::SetLoggingOutputStreamToStderr(); + + // Log something. + std::string teststring = "test that the log messages get directed to cerr"; + BAZEL_LOG(INFO) << teststring; + + // Cause the logs to be flushed, and capture them. + blaze_util::SetLogHandler(nullptr); + std::string stderr_output = testing::internal::GetCapturedStderr(); + EXPECT_TRUE(stderr_output.find(teststring) != std::string::npos) + << "stderr does not contain the expected log message. Stderr contained: " + << stderr_output; +} + +TEST(LoggingTest, BufferedLogsGetDirectedToCerr) { + // Set up logging and be prepared to capture stderr at destruction. + testing::internal::CaptureStderr(); + std::unique_ptr handler( + new blaze_util::BazelLogHandler()); + blaze_util::SetLogHandler(std::move(handler)); + + // Log something before telling the loghandler where to send it. + std::string teststring = "test that this message gets directed to cerr"; + BAZEL_LOG(INFO) << teststring; + + // Ask that the logs get output to stderr + blaze_util::SetLoggingOutputStreamToStderr(); + + // Cause the logs to be flushed, and capture them. + blaze_util::SetLogHandler(nullptr); + std::string stderr_output = testing::internal::GetCapturedStderr(); + EXPECT_TRUE(stderr_output.find(teststring) != std::string::npos) + << "stderr does not contain the expected log message. Stderr contained: " + << stderr_output; +} + TEST(LoggingTest, ImpossibleFile) { - // Set the value of $TMP first, because CaptureStderr retrieves a temp - // directory path and on Windows, the corresponding function (GetTempPathA) - // reads $TMP. - blaze::SetEnv("TMP", blaze::GetEnv("TEST_TMPDIR")); - // Set up logging now that $TMP is set, and be prepared to capture stderr at - // destruction. + // Set up logging and be prepared to capture stderr at destruction. testing::internal::CaptureStderr(); std::unique_ptr handler( new blaze_util::BazelLogHandler()); blaze_util::SetLogHandler(std::move(handler)); // Deliberately try to log to an impossible location, check that we error out. - blaze_util::SetLogfileDirectory("/this/doesnt/exist"); + std::unique_ptr bad_logfile_stream_( + new std::ofstream("/this/doesnt/exist.log", std::fstream::out)); + blaze_util::SetLoggingOutputStream(std::move(bad_logfile_stream_)); // Cause the logs to be flushed, and capture them. blaze_util::SetLogHandler(nullptr); - std::string output = testing::internal::GetCapturedStderr(); - ASSERT_TRUE(output.find("ERROR") != std::string::npos); - ASSERT_TRUE(output.find("/this/doesnt/exist") != std::string::npos); + std::string stderr_output = testing::internal::GetCapturedStderr(); + EXPECT_TRUE(stderr_output.find("ERROR") != std::string::npos); + EXPECT_TRUE(stderr_output.find("Provided stream failed") != std::string::npos) + << "stderr does not contain the expected error. Stderr contained: " + << stderr_output; } - } // namespace blaze_util diff --git a/src/test/shell/integration/bazel_command_log_test.sh b/src/test/shell/integration/bazel_command_log_test.sh index ca7a08da71..0730056a22 100755 --- a/src/test/shell/integration/bazel_command_log_test.sh +++ b/src/test/shell/integration/bazel_command_log_test.sh @@ -38,6 +38,7 @@ function strip_lines_from_bazel_cc() { -e '/^OpenJDK 64-Bit Server VM warning: ignoring option UseSeparateVSpacesInYoungGen; support was removed in 8.0/d' \ -e '/^Starting local Bazel server and connecting to it\.\.\.\.*$/d' \ -e '/^Starting local Blaze server and connecting to it\.\.\.\.*$/d' \ + -e '/^\.*$/d' \ -e '/^Killed non-responsive server process/d' \ -e '/server needs to be killed, because the startup options are different/d' \ -e '/^WARNING: Waiting for server process to terminate (waited 5 seconds, waiting at most 60)$/d' \ diff --git a/src/test/shell/integration/client_test.sh b/src/test/shell/integration/client_test.sh index 0fddd39f0f..24b04255ed 100755 --- a/src/test/shell/integration/client_test.sh +++ b/src/test/shell/integration/client_test.sh @@ -30,15 +30,15 @@ function tear_down() { function test_client_debug() { # Test that --client_debug sends log statements to stderr. bazel --client_debug version >&$TEST_log || fail "'bazel version' failed" - expect_log "Debug logging active" + expect_log "Debug logging requested" bazel --client_debug --batch version >&$TEST_log || fail "'bazel version' failed" - expect_log "Debug logging active" + expect_log "Debug logging requested" # Test that --client_debug is off by default. bazel version >&$TEST_log || fail "'bazel version' failed" - expect_not_log "Debug logging active" + expect_not_log "Debug logging requested" bazel --batch version >&$TEST_log || fail "'bazel version' failed" - expect_not_log "Debug logging active" + expect_not_log "Debug logging requested" } function test_client_debug_change_does_not_restart_server() { -- cgit v1.2.3