From 5d7aa7cea139fa23151cdd55c6a2781caf583b34 Mon Sep 17 00:00:00 2001 From: Tyler Wilding Date: Tue, 8 Aug 2023 10:59:37 -0600 Subject: [PATCH] log: rotate log files with timestamps and add flag to disable ANSI colors (#2886) Rotates the log files with a timestamp instead of copying all files and incrementing an integer. Increases the amount of info you have when looking at user's log files (ie. when looking at all the files, the file creation dates are accurate). ![image](https://github.com/open-goal/jak-project/assets/13153231/61bcdf51-f0f6-4eee-b1e5-140aede5d19e) Also simplifies the API for setting the log file, and `gk` logs are now game specific with `jak1` or `jak2`. Which should be useful going forward. Lastly, added a flag to all CLIs to disable ansi colors for people that want to do so. Though at the same time, there is finally a workaround in jenkins to fix ANSI colors in the truncated log view -- so I'm not sure why anyone would want to get rid of the color information. You can even setup text editors to display the color info making log parsing much easier. Fixes #1917 --------- Co-authored-by: ManDude <7569514+ManDude@users.noreply.github.com> --- common/log/log.cpp | 65 ++++++++++++++++++++++++----------- common/log/log.h | 4 ++- common/util/FileUtil.cpp | 20 +++++++++++ common/util/FileUtil.h | 1 + common/util/term_util.h | 4 +++ decompiler/extractor/main.cpp | 7 +++- decompiler/main.cpp | 38 +++++++++++--------- game/main.cpp | 11 ++++-- goalc/main.cpp | 11 ++++-- lsp/main.cpp | 11 ++++-- 10 files changed, 124 insertions(+), 48 deletions(-) diff --git a/common/log/log.cpp b/common/log/log.cpp index 29d972edd7..1e00f39cd0 100644 --- a/common/log/log.cpp +++ b/common/log/log.cpp @@ -12,6 +12,7 @@ #endif #include "common/util/Assert.h" #include "common/util/FileUtil.h" +#include "common/util/string_util.h" namespace lg { struct Logger { @@ -23,6 +24,7 @@ struct Logger { level file_log_level = level::trace; level flush_level = level::trace; std::mutex mutex; + bool disable_colors = false; ~Logger() { // will run when program exits. @@ -68,7 +70,11 @@ void log_message(level log_level, LogTime& now, const char* message) { if (log_level >= gLogger.stdout_log_level || (log_level == level::die && gLogger.stdout_log_level == level::off_unless_die)) { fmt::print("{} [", time_string); - fmt::print(fg(log_colors[int(log_level)]), "{}", log_level_names[int(log_level)]); + if (gLogger.disable_colors) { + fmt::print("{}", log_level_names[int(log_level)]); + } else { + fmt::print(fg(log_colors[int(log_level)]), "{}", log_level_names[int(log_level)]); + } fmt::print("] {}\n", message); if (log_level >= gLogger.flush_level) { fflush(stdout); @@ -109,34 +115,49 @@ void log_print(const char* message) { } // namespace internal // how many extra log files for a single program should be kept? -constexpr int LOG_ROTATE_MAX = 5; +constexpr int LOG_ROTATE_MAX = 10; -void set_file(const std::string& filename, const bool should_rotate, const bool append) { +void set_file(const std::string& filename, + const bool should_rotate, + const bool append, + const std::string& dir) { ASSERT(!gLogger.fp); - file_util::create_dir_if_needed_for_file(filename); - - // rotate files. log.txt is the current one, log.1.txt is the previous one, etc. + std::string file_path; + if (!dir.empty()) { + file_path = file_util::combine_path(dir, filename); + } else { + file_path = file_util::get_file_path({"log", filename}); + } + std::string complete_filename = file_path; if (should_rotate) { - auto as_path = fs::path(filename); - auto stem = as_path.stem().string(); - auto ext = as_path.extension().string(); - auto dir = as_path.parent_path(); - for (int i = LOG_ROTATE_MAX; i-- > 0;) { - auto src_name = - i != 0 ? fmt::format("{}.{}{}", stem, i, ext) : fmt::format("{}{}", stem, ext); - auto src_path = dir / src_name; - if (file_util::file_exists(src_path.string())) { - auto dst_name = fmt::format("{}.{}{}", stem, i + 1, ext); - auto dst_path = dir / dst_name; - file_util::copy_file(src_path, dst_path); + complete_filename += "." + str_util::current_local_timestamp_no_colons() + ".log"; + // remove any log files with the old format + auto old_log_files = file_util::find_files_recursively( + fs::path(file_path).parent_path(), std::regex(fmt::format("{}\\.(\\d\\.)?log", filename))); + for (const auto& file : old_log_files) { + lg::info("removing {}", file.string()); + fs::remove(file); + } + // remove the oldest log file if there are more than LOG_ROTATE_MAX + auto existing_log_files = file_util::find_files_recursively( + fs::path(file_path).parent_path(), std::regex(fmt::format("{}.*\\.log", filename))); + // sort the names and remove them + existing_log_files = file_util::sort_filepaths(existing_log_files, true); + if (existing_log_files.size() > (LOG_ROTATE_MAX - 1)) { + lg::info("removing {} log files", existing_log_files.size() - (LOG_ROTATE_MAX - 1)); + for (int i = 0; i < existing_log_files.size() - (LOG_ROTATE_MAX - 1); i++) { + lg::info("removing {}", existing_log_files.at(i).string()); + fs::remove(existing_log_files.at(i)); } } + } else { + complete_filename += ".log"; } if (append) { - gLogger.fp = file_util::open_file(filename.c_str(), "a"); + gLogger.fp = file_util::open_file(complete_filename.c_str(), "a"); } else { - gLogger.fp = file_util::open_file(filename.c_str(), "w"); + gLogger.fp = file_util::open_file(complete_filename.c_str(), "w"); } ASSERT(gLogger.fp); } @@ -159,6 +180,10 @@ void set_max_debug_levels() { gLogger.file_log_level = level::trace; } +void disable_ansi_colors() { + gLogger.disable_colors = true; +} + void initialize() { ASSERT(!gLogger.initialized); diff --git a/common/log/log.h b/common/log/log.h index a0b85f7632..fdb8239a28 100644 --- a/common/log/log.h +++ b/common/log/log.h @@ -42,11 +42,13 @@ void log_print(const char* message); void set_file(const std::string& filename, const bool should_rotate = true, - const bool append = false); + const bool append = false, + const std::string& dir = ""); void set_flush_level(level log_level); void set_file_level(level log_level); void set_stdout_level(level log_level); void set_max_debug_levels(); +void disable_ansi_colors(); void initialize(); void finish(); diff --git a/common/util/FileUtil.cpp b/common/util/FileUtil.cpp index c836a06b90..05e6481450 100644 --- a/common/util/FileUtil.cpp +++ b/common/util/FileUtil.cpp @@ -644,6 +644,26 @@ std::vector find_directories_in_dir(const fs::path& base_dir) { return dirs; } +std::vector sort_filepaths(const std::vector& paths, const bool aescending) { + std::vector paths_as_strings = {}; + for (const auto& path : paths) { + paths_as_strings.push_back(path.string()); + } + std::sort(paths_as_strings.begin(), paths_as_strings.end(), + [aescending](const std::string& a, const std::string& b) { + if (aescending) { + return a < b; + } else { + return a > b; + } + }); + std::vector sorted_paths = {}; + for (const auto& path : paths_as_strings) { + sorted_paths.push_back(fs::path(path)); + } + return sorted_paths; +} + void copy_file(const fs::path& src, const fs::path& dst) { // Check that the src path exists if (!fs::exists(src)) { diff --git a/common/util/FileUtil.h b/common/util/FileUtil.h index 9331f55dd8..cef4fb185e 100644 --- a/common/util/FileUtil.h +++ b/common/util/FileUtil.h @@ -64,6 +64,7 @@ std::vector decompress_dgo(const std::vector& data_in); FILE* open_file(const fs::path& path, const std::string& mode); std::vector find_files_recursively(const fs::path& base_dir, const std::regex& pattern); std::vector find_directories_in_dir(const fs::path& base_dir); +std::vector sort_filepaths(const std::vector& paths, const bool aescending); /// Will overwrite the destination if it exists void copy_file(const fs::path& src, const fs::path& dst); std::string make_screenshot_filepath(const GameVersion game_version, const std::string& name = ""); diff --git a/common/util/term_util.h b/common/util/term_util.h index fbdf5e8250..5e57461aae 100644 --- a/common/util/term_util.h +++ b/common/util/term_util.h @@ -4,4 +4,8 @@ namespace term_util { void clear(); int row_count(); int col_count(); + +#define define_common_cli_arguments(cli_app_name) \ + bool _cli_flag_disable_ansi = false; \ + cli_app_name.add_flag("--disable-ansi", _cli_flag_disable_ansi, "Disable ANSI colors"); } // namespace term_util diff --git a/decompiler/extractor/main.cpp b/decompiler/extractor/main.cpp index d839c620dc..92dd4836a9 100644 --- a/decompiler/extractor/main.cpp +++ b/decompiler/extractor/main.cpp @@ -8,6 +8,7 @@ #include "common/util/FileUtil.h" #include "common/util/json_util.h" #include "common/util/read_iso_file.h" +#include "common/util/term_util.h" #include "common/util/unicode_util.h" #include "decompiler/Disasm/OpcodeInfo.h" @@ -258,6 +259,7 @@ int main(int argc, char** argv) { app.add_flag("-c,--compile", flag_compile, "Compile the game"); app.add_flag("-p,--play", flag_play, "Play the game"); app.add_flag("-f,--folder", flag_folder, "Extract from folder"); + define_common_cli_arguments(app); app.validate_positionals(); CLI11_PARSE(app, argc, argv); @@ -296,7 +298,10 @@ int main(int argc, char** argv) { } try { - lg::set_file(file_util::get_file_path({"log", "extractor.log"})); + lg::set_file("extractor"); + if (_cli_flag_disable_ansi) { + lg::disable_ansi_colors(); + } } catch (const std::exception& e) { lg::error("Failed to setup logging: {}", e.what()); return 1; diff --git a/decompiler/main.cpp b/decompiler/main.cpp index 6abd6713c3..1462cb2a4d 100644 --- a/decompiler/main.cpp +++ b/decompiler/main.cpp @@ -10,6 +10,7 @@ #include "common/util/diff.h" #include "common/util/os.h" #include "common/util/set_util.h" +#include "common/util/term_util.h" #include "common/util/unicode_util.h" #include "common/versions/versions.h" @@ -31,22 +32,6 @@ static void mem_log(const std::string& format, Args&&... args) { int main(int argc, char** argv) { ArgumentGuard u8_guard(argc, argv); - if (!file_util::setup_project_path(std::nullopt)) { - lg::error("Unable to setup project path"); - return 1; - } - - try { - lg::set_file(file_util::get_file_path({"log", "decompiler.log"})); - lg::set_file_level(lg::level::info); - lg::set_stdout_level(lg::level::info); - lg::set_flush_level(lg::level::info); - lg::initialize(); - } catch (const std::exception& e) { - lg::error("Failed to setup logging: {}", e.what()); - return 1; - } - fs::path config_path; fs::path in_folder; fs::path out_folder; @@ -73,10 +58,29 @@ int main(int argc, char** argv) { ->required(); app.add_option("--config-override", config_override, "JSON provided will be merged with the specified config, use to override options"); + define_common_cli_arguments(app); app.validate_positionals(); CLI11_PARSE(app, argc, argv); - // Validate arguments + if (!file_util::setup_project_path(std::nullopt)) { + lg::error("Unable to setup project path"); + return 1; + } + + try { + lg::set_file("decompiler"); + lg::set_file_level(lg::level::info); + lg::set_stdout_level(lg::level::info); + lg::set_flush_level(lg::level::info); + lg::initialize(); + if (_cli_flag_disable_ansi) { + lg::disable_ansi_colors(); + } + } catch (const std::exception& e) { + lg::error("Failed to setup logging: {}", e.what()); + return 1; + } + using namespace decompiler; Config config; diff --git a/game/main.cpp b/game/main.cpp index d32af6bbfe..e59ac4f9f9 100644 --- a/game/main.cpp +++ b/game/main.cpp @@ -14,6 +14,7 @@ #include "common/util/FileUtil.h" #include "common/util/dialogs.h" #include "common/util/os.h" +#include "common/util/term_util.h" #include "common/util/unicode_util.h" #include "common/versions/versions.h" @@ -33,8 +34,8 @@ __declspec(dllexport) int AmdPowerXpressRequestHighPerformance = 1; * Set up logging system to log to file. * @param verbose : should we print debug-level messages to stdout? */ -void setup_logging(bool verbose) { - lg::set_file(file_util::get_file_path({"log", "game.log"})); +void setup_logging(const std::string& game_name, bool verbose, bool disable_ansi_colors) { + lg::set_file(game_name); if (verbose) { lg::set_file_level(lg::level::debug); lg::set_stdout_level(lg::level::debug); @@ -44,6 +45,9 @@ void setup_logging(bool verbose) { lg::set_stdout_level(lg::level::warn); lg::set_flush_level(lg::level::warn); } + if (disable_ansi_colors) { + lg::disable_ansi_colors(); + } lg::initialize(); } @@ -117,6 +121,7 @@ int main(int argc, char** argv) { app.footer(game_arg_documentation()); app.add_option("Game Args", game_args, "Remaining arguments (after '--') that are passed-through to the game itself"); + define_common_cli_arguments(app); app.allow_extras(); CLI11_PARSE(app, argc, argv); @@ -187,7 +192,7 @@ int main(int argc, char** argv) { } try { - setup_logging(verbose_logging); + setup_logging(game_name, verbose_logging, _cli_flag_disable_ansi); } catch (const std::exception& e) { lg::error("Failed to setup logging: {}", e.what()); return 1; diff --git a/goalc/main.cpp b/goalc/main.cpp index cc80e2acf7..f514ba0808 100644 --- a/goalc/main.cpp +++ b/goalc/main.cpp @@ -7,6 +7,7 @@ #include "common/util/FileUtil.h" #include "common/util/diff.h" #include "common/util/string_util.h" +#include "common/util/term_util.h" #include "common/util/unicode_util.h" #include "common/versions/versions.h" @@ -16,11 +17,14 @@ #include "third-party/fmt/color.h" #include "third-party/fmt/core.h" -void setup_logging() { - lg::set_file(file_util::get_file_path({"log", "compiler.log"})); +void setup_logging(const bool disable_ansi_colors) { + lg::set_file("compiler"); lg::set_file_level(lg::level::info); lg::set_stdout_level(lg::level::info); lg::set_flush_level(lg::level::info); + if (disable_ansi_colors) { + lg::disable_ansi_colors(); + } lg::initialize(); } @@ -47,6 +51,7 @@ int main(int argc, char** argv) { app.add_option("-g,--game", game, "The game name: 'jak1' or 'jak2'"); app.add_option("--proj-path", project_path_override, "Specify the location of the 'data/' folder"); + define_common_cli_arguments(app); app.validate_positionals(); CLI11_PARSE(app, argc, argv); @@ -77,7 +82,7 @@ int main(int argc, char** argv) { } try { - setup_logging(); + setup_logging(_cli_flag_disable_ansi); } catch (const std::exception& e) { lg::error("Failed to setup logging: {}", e.what()); return 1; diff --git a/lsp/main.cpp b/lsp/main.cpp index de38b6c8cc..3fabc05ccf 100644 --- a/lsp/main.cpp +++ b/lsp/main.cpp @@ -14,6 +14,7 @@ #include "common/log/log.h" #include "common/util/unicode_util.h" +#include "common/util/term_util.h" #include "lsp/handlers/lsp_router.h" #include "lsp/state/workspace.h" @@ -33,9 +34,9 @@ socket port number is passed as --socket=${port} to the server process started. */ -void setup_logging(bool verbose, std::string log_file) { +void setup_logging(bool verbose, std::string log_file, bool disable_ansi_colors) { if (!log_file.empty()) { - lg::set_file(log_file, false, true); + lg::set_file(log_file, false, true, fs::path(log_file).parent_path().string()); } if (verbose) { lg::set_file_level(lg::level::debug); @@ -44,6 +45,9 @@ void setup_logging(bool verbose, std::string log_file) { lg::set_file_level(lg::level::info); lg::set_flush_level(lg::level::info); } + if (disable_ansi_colors) { + lg::disable_ansi_colors(); + } // We use stdout to communicate with the client, so don't use it at all! lg::set_stdout_level(lg::level::off); @@ -62,6 +66,7 @@ int main(int argc, char** argv) { "Don't launch an HTTP server and instead accept input on stdin"); app.add_flag("-v,--verbose", verbose, "Enable verbose logging"); app.add_option("-l,--log", logfile, "Log file path"); + define_common_cli_arguments(app); app.validate_positionals(); CLI11_PARSE(app, argc, argv); @@ -69,7 +74,7 @@ int main(int argc, char** argv) { LSPRouter lsp_router; appstate.verbose = verbose; try { - setup_logging(appstate.verbose, logfile); + setup_logging(appstate.verbose, logfile, _cli_flag_disable_ansi); } catch (const std::exception& e) { lg::error("Failed to setup logging: {}", e.what()); return 1;