vbatts/llama.cpp
1
0
Fork 0
Code Issues Pull requests Projects Releases Packages Wiki Activity Actions

Enable log redirection

Browse source
This commit is contained in:
pudepiedj 2024-02-27 22:27:10 +00:00
parent e8c37fd893
commit 87d501fc10
2 changed files with 91 additions and 17 deletions
Download patch file Download diff file Expand all files Collapse all files

18
examples/server/server.cpp
View file

@ -306,7 +306,11 @@ struct llama_client_slot
} }
void print_timings() const { 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 t_token = t_prompt_processing / num_prompt_tokens_processed;
double n_tokens_second = 1e3 / t_prompt_processing * num_prompt_tokens_processed; double n_tokens_second = 1e3 / t_prompt_processing * num_prompt_tokens_processed;
printf("\033[72;0H]"); printf("\033[72;0H]");
@ -319,7 +323,7 @@ struct llama_client_slot
{"t_prompt_processing", t_prompt_processing}, {"t_prompt_processing", t_prompt_processing},
{"num_prompt_tokens_processed", num_prompt_tokens_processed}, {"num_prompt_tokens_processed", num_prompt_tokens_processed},
{"t_token", t_token}, {"t_token", t_token},
{"n_tokens_second", n_tokens_second}, {"n_tokens_second", n_tokens_second}
}); });
t_token = t_token_generation / n_decoded; t_token = t_token_generation / n_decoded;
@ -334,7 +338,7 @@ struct llama_client_slot
{"t_token_generation", t_token_generation}, {"t_token_generation", t_token_generation},
{"n_decoded", n_decoded}, {"n_decoded", n_decoded},
{"t_token", t_token}, {"t_token", t_token},
{"n_tokens_second", n_tokens_second}, {"n_tokens_second", n_tokens_second}
}); });
printf("\033[5;0H]"); printf("\033[5;0H]");
@ -344,7 +348,7 @@ struct llama_client_slot
{"task_id", task_id}, {"task_id", task_id},
{"t_prompt_processing", t_prompt_processing}, {"t_prompt_processing", t_prompt_processing},
{"t_token_generation", t_token_generation}, {"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", { LOG_INFO("slot is processing task", {
{"slot_id", slot->id}, {"slot_id", slot->id},
{"task_id", slot->task_id}, {"task_id", slot->task_id}
}); });
return true; return true;
@ -2894,7 +2898,7 @@ static void log_server_request(const httplib::Request &req, const httplib::Respo
{"status", res.status}, {"status", res.status},
{"method", req.method}, {"method", req.method},
{"path", req.path}, {"path", req.path},
{"params", req.params}, {"params", req.params}
}); });
LOG_VERBOSE("request", { LOG_VERBOSE("request", {
@ -2959,7 +2963,7 @@ int main(int argc, char **argv)
{"n_threads", params.n_threads}, {"n_threads", params.n_threads},
{"n_threads_batch", params.n_threads_batch}, {"n_threads_batch", params.n_threads_batch},
{"total_threads", std::thread::hardware_concurrency()}, {"total_threads", std::thread::hardware_concurrency()},
{"system_info", llama_print_system_info()}, {"system_info", llama_print_system_info()}
}); });
httplib::Server svr; httplib::Server svr;

90
examples/server/utils.hpp
View file

@ -33,9 +33,66 @@ extern bool server_log_json;
} while (0) } while (0)
#endif #endif
#define LOG_ERROR( MSG, ...) server_log("ERR", __func__, __LINE__, MSG, __VA_ARGS__) // ATTEMPT TO REFACTOR THE LOGGING BEHAVIOUR AND ALLOW REDIRECTION OF STDOUT, STDERR
#define LOG_WARNING(MSG, ...) server_log("WARN", __func__, __LINE__, MSG, __VA_ARGS__)
#define LOG_INFO( MSG, ...) server_log("INFO", __func__, __LINE__, MSG, __VA_ARGS__) 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 // parallel
@ -78,7 +135,7 @@ struct task_multi {
std::vector<task_result> results{}; std::vector<task_result> 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 enum slot_state
{ {
IDLE, IDLE,
@ -134,7 +191,20 @@ struct completion_token_output
std::string text_to_send; 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; std::stringstream ss_tid;
ss_tid << std::this_thread::get_id(); 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)}, {"timestamp", time(nullptr)},
}; };
// freopen("/dev/null", "w", stdout); freopen(stdout_target.c_str(), "a", stdout);
freopen("/dev/null", "w", stderr); // we assign stderr to dev/null effectively 'blackholing' the output because log.dump below is redirected too 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) { if (server_log_json) {
log.merge_patch( 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(); const std::string str = ss.str();
printf("\033[85;0H%.*s\n", (int)str.size(), str.data()); 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(stdout_reset.c_str(), "a", stdout); // decide whether to restore stdout
// freopen("/dev/tty", "a", stderr); // decide whether to restore stderr both need automating freopen(stderr_reset.c_str(), "a", stderr); // decide whether to restore stderr (both need automating)
} }
} }