From 47b9f2d36f75bbe0b26848a8d5cf28311b69dbd9 Mon Sep 17 00:00:00 2001 From: staviq Date: Thu, 24 Aug 2023 02:00:16 +0200 Subject: [PATCH] log_enable/disable, LOG_TEE, basic usage doc --- common/log.h | 197 +++++++++++++++++++++++++++++++++++------ examples/main/main.cpp | 27 ++++-- 2 files changed, 193 insertions(+), 31 deletions(-) diff --git a/common/log.h b/common/log.h index cd7b43b4d..0f18c7c03 100644 --- a/common/log.h +++ b/common/log.h @@ -9,6 +9,41 @@ #include #include +// -------------------------------- +// +// Basic usage: +// +// -------- +// +// The LOG() and LOG_TEE() macros are ready to go by default +// they do not require any initialization. +// +// LOG() behaves exactly like printf, by default writing to a logfile. +// LOG_TEE() additionally, prints to the screen too ( mimics Unix tee command ). +// +// Default logfile is named +// "llama..log" +// Default LOG_TEE() secondary output target is +// stderr +// +// Logs can be dynamically disabled or enabled using functions: +// log_disable() +// and +// log_enable() +// +// A log target can be changed with: +// log_set_target( string ) +// creating and opening, or re-opening a file by string filename +// or +// log_set_target( FILE* ) +// allowing to point at stderr, stdout, or any valid FILE* file handler. +// +// -------- +// +// End of Basic usage. +// +// -------------------------------- + // Specifies a log target. // default uses log_handler() with "llama.log" log file // this can be changed, by defining LOG_TARGET @@ -55,6 +90,24 @@ #define LOG_TARGET log_handler() #endif +#ifndef LOG_TEE_TARGET +#define LOG_TEE_TARGET stderr +#endif + +#ifndef LOG_DEFAULT_FILE_NAME +// TODO: This should get a wrapper +// to let others have custom log names with automatic unique id +#define LOG_DEFAULT_FILE_NAME std::string().append("llama.").append(log_get_pid()).append(".log") +#endif + +// Utility for turning #define values into string literals +// so we can have a define for stderr and +// we can print "stderr" instead of literal stderr, etc. +#define _LOG_STRINGIZE(s) #s +#define LOG_STRINGIZE(s) _LOG_STRINGIZE(s) + +#define LOG_TEE_TARGET_STRING LOG_STRINGIZE(LOG_TEE_TARGET) + // Allows disabling timestamps. // in order to disable, define LOG_NO_TIMESTAMPS // like so: @@ -85,18 +138,66 @@ #define LOG_FLF_VAL #endif -#define _LOG(str, ...) \ - { \ - /*fprintf(stderr, "DBG:" str, ##__VA_ARGS__);*/ \ - fprintf(LOG_TARGET, LOG_TIMESTAMP_FMT LOG_FLF_FMT str "%c" LOG_TIMESTAMP_VAL LOG_FLF_VAL, ##__VA_ARGS__); \ - fflush(LOG_TARGET); /*fprintf(stderr, "DBGEND\n");*/ \ +// Utility for synchronizing log configuration state +// since std::optional was introduced only in c++17 +enum LogTriState +{ + LogTriStateSame, + LogTriStateFalse, + LogTriStateTrue +}; + +// INTERNAL, DO NOT USE +// USE LOG() INSTEAD +// +#define _LOG(str, ...) \ + { \ + /*fprintf(stderr, "DBG:" str, ##__VA_ARGS__);*/ \ + if (LOG_TARGET != nullptr) \ + { \ + fprintf(LOG_TARGET, LOG_TIMESTAMP_FMT LOG_FLF_FMT str "%c" LOG_TIMESTAMP_VAL LOG_FLF_VAL, ##__VA_ARGS__); \ + fflush(LOG_TARGET); /*fprintf(stderr, "DBGEND\n");*/ \ + } \ } -// This is a trick to bypass the silly -// "warning: ISO C++11 requires at least one argument for the "..." in a variadic macro" -// so we can gave a single macro which can be called just like printf. +// INTERNAL, DO NOT USE +// USE LOG_TEE() INSTEAD +// +#define _LOG_TEE(str, ...) \ + { \ + /*fprintf(stderr, "DBG:" str, ##__VA_ARGS__);*/ \ + if (LOG_TARGET != nullptr) \ + { \ + fprintf(LOG_TARGET, LOG_TIMESTAMP_FMT LOG_FLF_FMT str "%c" LOG_TIMESTAMP_VAL LOG_FLF_VAL, ##__VA_ARGS__); \ + fflush(LOG_TARGET); /*fprintf(stderr, "DBGEND\n");*/ \ + } \ + if (LOG_TARGET != nullptr && LOG_TARGET != stdout && LOG_TARGET != stderr && LOG_TEE_TARGET != nullptr) \ + { \ + fprintf(LOG_TEE_TARGET, LOG_TIMESTAMP_FMT LOG_FLF_FMT str "%c" LOG_TIMESTAMP_VAL LOG_FLF_VAL, ##__VA_ARGS__); \ + fflush(LOG_TEE_TARGET); /*fprintf(stderr, "DBGEND\n");*/ \ + } \ + } + +// The '\0' as a last argument, is a trick to bypass the silly +// "warning: ISO C++11 requires at least one argument for the "..." in a variadic macro" +// so we can have a single macro which can be called just like printf. + +// Main LOG macro. +// behaves like printf, and supports arguments the exact same way. +// #define LOG(...) _LOG(__VA_ARGS__, '\0') +// Main TEE macro. +// does the same as LOG +// and +// simultaneously writes stderr. +// +// Secondary target can be changed just like LOG_TARGET +// by defining LOG_TEE_TARGET +// +#define LOG_TEE(...) _LOG_TEE(__VA_ARGS__, '\0') + +// Utility to obtain "pid" like unique process id and use it when creating log files. inline std::string log_get_pid() { static std::string pid; @@ -113,36 +214,59 @@ inline std::string log_get_pid() return pid; } -#define LOG_DEFAULT_FILE_NAME std::string().append("llama.").append(log_get_pid()).append(".log") - -inline FILE *_log_handler1(bool change = false, std::string filename = LOG_DEFAULT_FILE_NAME, FILE *target = nullptr) +// INTERNAL, DO NOT USE +inline FILE *_log_handler1(bool change = false, LogTriState disable = LogTriStateSame, std::string filename = LOG_DEFAULT_FILE_NAME, FILE *target = nullptr) { // std::cerr << "\tFNM:" << filename << "TGT:" << (uint64_t)target << std::endl; static bool _initialized{false}; + static bool _disabled{(filename.empty() && target == nullptr)}; static std::string log_current_filename{filename}; static FILE *log_current_target{target}; static FILE *logfile = nullptr; - if (change && log_current_filename.compare(filename) != 0) [[unlikely]] + if (change) [[unlikely]] { - // std::cerr << "\t\tFNM changed, deinit" << std::endl; - _initialized = false; - } + if (disable == LogTriStateTrue) + { + // Disable primary target + _disabled = true; + } + // If previously disabled, only enable, and keep previous target + else if (disable == LogTriStateFalse) + { + _disabled = false; + } + // Otherwise, process the arguments + else + { + if (log_current_filename.compare(filename) != 0) + { + // std::cerr << "\t\tFNM changed, deinit" << std::endl; + _initialized = false; + } - if (change && log_current_target != target) [[unlikely]] - { - // std::cerr << "\t\tTGT changed, deinit" << std::endl; - _initialized = false; + if (log_current_target != target) + { + // std::cerr << "\t\tTGT changed, deinit" << std::endl; + _initialized = false; + } + } } - // std::cerr << "\tINIT:" << (_initialized ? "true" : "false") << std::endl; - if (_initialized) [[likely]] { // std::cerr << "\t\tIS Inited" << std::endl; // with fallback in case something went wrong // std::cerr << "\t\tEarly Done" << std::endl; - return logfile ? logfile : stderr; + if (_disabled) + { + // Log is disabled + return nullptr; + } + else + { + return logfile ? logfile : stderr; + } } else { @@ -197,17 +321,38 @@ inline FILE *_log_handler1(bool change = false, std::string filename = LOG_DEFAU fflush(stderr); } + // At this point we set init flag to true, and let the target fallback to stderr + // otherwise we would repeatedly fopen() which was already unsuccessful _initialized = true; } // std::cerr << "\tDone" << std::endl; return logfile ? logfile : stderr; } -inline FILE *_log_handler2(bool change = false, FILE *target = nullptr, std::string filename = LOG_DEFAULT_FILE_NAME) + +// INTERNAL, DO NOT USE +inline FILE *_log_handler2(bool change = false, LogTriState disable = LogTriStateSame, FILE *target = nullptr, std::string filename = LOG_DEFAULT_FILE_NAME) { - return _log_handler1(change, filename, target); + return _log_handler1(change, disable, filename, target); } -inline FILE *log_set_target(std::string filename) { return _log_handler1(true, filename); } -inline FILE *log_set_target(FILE *target) { return _log_handler2(true, target); } +// Disables logs entirely at runtime. +// Makes LOG() and LOG_TEE() produce no output, +// untill enabled back. +inline FILE *log_disable() +{ + return _log_handler1(true, LogTriStateTrue); +} + +// Enables logs at runtime. +inline FILE *log_enable() +{ + return _log_handler1(true, LogTriStateFalse); +} + +// Sets target fir logs, either by a file name or FILE* pointer (stdout, stderr, or any valid FILE*) +inline FILE *log_set_target(std::string filename) { return _log_handler1(true, LogTriStateSame, filename); } +inline FILE *log_set_target(FILE *target) { return _log_handler2(true, LogTriStateSame, target); } + +// INTERNAL, DO NOT USE inline FILE *log_handler() { return _log_handler1(); } \ No newline at end of file diff --git a/examples/main/main.cpp b/examples/main/main.cpp index eaaa63f81..ce48b30ca 100644 --- a/examples/main/main.cpp +++ b/examples/main/main.cpp @@ -61,15 +61,32 @@ void sigint_handler(int signo) { int main(int argc, char ** argv) { gpt_params params; - LOG("Hello World to default output!\n") + log_disable(); + LOG("01 Hello World to nobody, because logs are disabled!\n") + log_enable(); + LOG("02 Hello World to default output, which is \"%s\" ( Yaaay, arguments! )!\n", LOG_STRINGIZE(LOG_TARGET)) + LOG_TEE("03 Hello World to **both** default output and " LOG_TEE_TARGET_STRING "!\n") log_set_target(stderr); - LOG("Hello World to stderr!\n") + LOG("04 Hello World to stderr!\n") + LOG_TEE("05 Hello World TEE with double printing to stderr prevented!\n") log_set_target(LOG_DEFAULT_FILE_NAME); - LOG("Hello World to default log file!\n") + LOG("06 Hello World to default log file!\n") log_set_target(stdout); - LOG("Hello World to stdout!\n") + LOG("07 Hello World to stdout!\n") log_set_target(LOG_DEFAULT_FILE_NAME); - LOG("Hello World to default log file again!\n") + LOG("08 Hello World to default log file again!\n") + log_disable(); + LOG("09 Hello World _1_ into the void!\n") + log_enable(); + LOG("10 Hello World back from the void ( you should not see _1_ in the log or the output )!\n") + log_disable(); + log_set_target("llama.anotherlog.log"); + LOG("11 Hello World _2_ to nobody, new target was selected but logs are still disabled!\n") + log_enable(); + LOG("12 Hello World this time in a new file ( you should not see _2_ in the log or the output )?\n") + log_set_target("llama.yetanotherlog.log"); + LOG("13 Hello World this time in yet new file?\n") + if (gpt_params_parse(argc, argv, params) == false) { return 1;