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

@@ -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);
 

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();
 

common/util/FileUtil.cpp

@@ -644,6 +644,26 @@ std::vector<fs::path> find_directories_in_dir(const fs::path& base_dir) {
   return dirs;
 }
 
+std::vector<fs::path> sort_filepaths(const std::vector<fs::path>& paths, const bool aescending) {
+  std::vector<std::string> 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<fs::path> 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)) {

common/util/FileUtil.h

@@ -64,6 +64,7 @@ std::vector<u8> decompress_dgo(const std::vector<u8>& data_in);
 FILE* open_file(const fs::path& path, const std::string& mode);
 std::vector<fs::path> find_files_recursively(const fs::path& base_dir, const std::regex& pattern);
 std::vector<fs::path> find_directories_in_dir(const fs::path& base_dir);
+std::vector<fs::path> sort_filepaths(const std::vector<fs::path>& 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 = "");

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

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;

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;

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;

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;

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;