From 87d501fc106c3c96b30c3d93368cffa43442be26 Mon Sep 17 00:00:00 2001 From: pudepiedj Date: Tue, 27 Feb 2024 22:27:10 +0000 Subject: [PATCH] Enable log redirection --- examples/server/server.cpp | 18 +++++--- examples/server/utils.hpp | 90 +++++++++++++++++++++++++++++++++----- 2 files changed, 91 insertions(+), 17 deletions(-) diff --git a/examples/server/server.cpp b/examples/server/server.cpp index 1876a5d70..10c076262 100644 --- a/examples/server/server.cpp +++ b/examples/server/server.cpp @@ -306,7 +306,11 @@ struct llama_client_slot } void print_timings() const { - char buffer[512]; + char buffer[512]; + std::string stdout_target; + std::string stdout_reset; + std::string stderr_target; + std::string stderr_reset; double t_token = t_prompt_processing / num_prompt_tokens_processed; double n_tokens_second = 1e3 / t_prompt_processing * num_prompt_tokens_processed; printf("\033[72;0H]"); @@ -319,7 +323,7 @@ struct llama_client_slot {"t_prompt_processing", t_prompt_processing}, {"num_prompt_tokens_processed", num_prompt_tokens_processed}, {"t_token", t_token}, - {"n_tokens_second", n_tokens_second}, + {"n_tokens_second", n_tokens_second} }); t_token = t_token_generation / n_decoded; @@ -334,7 +338,7 @@ struct llama_client_slot {"t_token_generation", t_token_generation}, {"n_decoded", n_decoded}, {"t_token", t_token}, - {"n_tokens_second", n_tokens_second}, + {"n_tokens_second", n_tokens_second} }); printf("\033[5;0H]"); @@ -344,7 +348,7 @@ struct llama_client_slot {"task_id", task_id}, {"t_prompt_processing", t_prompt_processing}, {"t_token_generation", t_token_generation}, - {"t_total", t_prompt_processing + t_token_generation}, + {"t_total", t_prompt_processing + t_token_generation} }); } }; @@ -968,7 +972,7 @@ struct llama_server_context LOG_INFO("slot is processing task", { {"slot_id", slot->id}, - {"task_id", slot->task_id}, + {"task_id", slot->task_id} }); return true; @@ -2894,7 +2898,7 @@ static void log_server_request(const httplib::Request &req, const httplib::Respo {"status", res.status}, {"method", req.method}, {"path", req.path}, - {"params", req.params}, + {"params", req.params} }); LOG_VERBOSE("request", { @@ -2959,7 +2963,7 @@ int main(int argc, char **argv) {"n_threads", params.n_threads}, {"n_threads_batch", params.n_threads_batch}, {"total_threads", std::thread::hardware_concurrency()}, - {"system_info", llama_print_system_info()}, + {"system_info", llama_print_system_info()} }); httplib::Server svr; diff --git a/examples/server/utils.hpp b/examples/server/utils.hpp index 28c73c221..d8f03766e 100644 --- a/examples/server/utils.hpp +++ b/examples/server/utils.hpp @@ -33,9 +33,66 @@ extern bool server_log_json; } while (0) #endif -#define LOG_ERROR( MSG, ...) server_log("ERR", __func__, __LINE__, MSG, __VA_ARGS__) -#define LOG_WARNING(MSG, ...) server_log("WARN", __func__, __LINE__, MSG, __VA_ARGS__) -#define LOG_INFO( MSG, ...) server_log("INFO", __func__, __LINE__, MSG, __VA_ARGS__) +// ATTEMPT TO REFACTOR THE LOGGING BEHAVIOUR AND ALLOW REDIRECTION OF STDOUT, STDERR + +struct LogRedirection { + // Set default values for redirection targets and reset strings + std::string stdout_target = "stdout_log.log"; + std::string stdout_reset = "dev/tty"; + std::string stderr_target = "stderr_log.log"; + std::string stderr_reset = "dev/tty"; +}; + +LogRedirection log_settings; + +#define LOG_ERROR(MSG, ...) \ + server_log("ERR", __func__, __LINE__, MSG, __VA_ARGS__, \ + log_settings.stdout_target, log_settings.stdout_reset, \ + log_settings.stderr_target, log_settings.stderr_reset) + +#define LOG_WARNING(MSG, ...) \ + server_log("WARN", __func__, __LINE__, MSG, __VA_ARGS__, \ + log_settings.stdout_target, log_settings.stdout_reset, \ + log_settings.stderr_target, log_settings.stderr_reset) + +#define LOG_INFO(MSG, ...) \ + server_log("INFO", __func__, __LINE__, MSG, __VA_ARGS__, \ + log_settings.stdout_target, log_settings.stdout_reset, \ + log_settings.stderr_target, log_settings.stderr_reset) + +/* +// Example usage: +LogRedirection default_settings; // Use defaults +LogRedirection custom_settings; + +// Modify values for custom settings if needed +custom_settings.stdout_target = "/tmp/custom.log"; + +LOG_ERROR("Default error", "Details", default_settings); +LOG_ERROR("Custom error", "More info", custom_settings); + + +Yes, using the LogRedirection struct approach eliminates the need to explicitly declare the extra variables for redirection targets and reset strings each time you call LOG_ERROR. Here's how it works: + +1. Redirection Settings Encapsulated: The LogRedirection struct holds these settings, making them reusable and adaptable. +2. Default Values: The struct's members have default values defined, serving as fallbacks. +3. Macro Handles Settings: The LOG_ERROR macro takes a LogRedirection object and passes its members to the server_log function. + +Example: + +LOG_ERROR("Default error", {}); // Uses defaults from an empty LogRedirection object + +This compact usage is possible because: + +{} creates a temporary LogRedirection object with its members implicitly initialized to the default values. +The macro passes those defaults to server_log, achieving the desired behavior without requiring explicit variable declarations at every call. +Customization: + +When needed, you can create a LogRedirection object with specific values and pass it to LOG_ERROR for tailored logging behaviour: + +LogRedirection custom_settings = {.stdout_target = "/tmp/my_log.out"}; +LOG_ERROR("Custom error", "Details", custom_settings); +*/ // // parallel @@ -78,7 +135,7 @@ struct task_multi { std::vector results{}; }; -// TODO: can become bool if we can't find use of more states +// TODO: can become bool if we can't find use of more states; MAYBE there is a case for RESERVED to keep slots dedicated to chats? enum slot_state { IDLE, @@ -134,7 +191,20 @@ struct completion_token_output std::string text_to_send; }; -static inline void server_log(const char *level, const char *function, int line, const char *message, const nlohmann::ordered_json &extra) +static inline void server_log( + const char *level, + const char *function, + int line, + const char *message, + const nlohmann::ordered_json &extra, + // specify targets and resets for stdout and stderr; + // this allows different behaviour for LOG_ERROR, LOG_WARNING and LOG_INFO + // destination for stdout redirection e.g. a file or "dev/null" + std::string stdout_target = "dev/stdout", + std::string stderr_target = "dev/tty", // destination for stderr redirection + std::string stdout_reset = "dev/stderr", // reset for stdout e.g. "dev/tty" + std::string stderr_reset = "dev/tty" +) { std::stringstream ss_tid; ss_tid << std::this_thread::get_id(); @@ -143,8 +213,8 @@ static inline void server_log(const char *level, const char *function, int line, {"timestamp", time(nullptr)}, }; - // freopen("/dev/null", "w", stdout); - freopen("/dev/null", "w", stderr); // we assign stderr to dev/null effectively 'blackholing' the output because log.dump below is redirected too + freopen(stdout_target.c_str(), "a", stdout); + freopen(stderr_target.c_str(), "w", stderr); // we assign stderr to dev/null effectively 'blackholing' the output because log.dump below is redirected too if (server_log_json) { log.merge_patch( @@ -177,10 +247,10 @@ static inline void server_log(const char *level, const char *function, int line, const std::string str = ss.str(); printf("\033[85;0H%.*s\n", (int)str.size(), str.data()); - fflush(stderr); // was originally fflush(stdout) + fflush(stderr); // was originally fflush(stdout) - // freopen("/dev/tty", "a", stdout); // decide whether to restore stdout - // freopen("/dev/tty", "a", stderr); // decide whether to restore stderr both need automating + freopen(stdout_reset.c_str(), "a", stdout); // decide whether to restore stdout + freopen(stderr_reset.c_str(), "a", stderr); // decide whether to restore stderr (both need automating) } }