diff --git a/common/log.cpp b/common/log.cpp index b6c9ff79..d019dd50 100644 --- a/common/log.cpp +++ b/common/log.cpp @@ -146,6 +146,7 @@ struct common_log { common_log(size_t capacity) { file = nullptr; + file_owned = false; prefix = false; timestamps = false; running = false; @@ -165,7 +166,7 @@ struct common_log { ~common_log() { pause(); - if (file) { + if (file && file_owned) { fclose(file); } } @@ -176,6 +177,7 @@ private: std::condition_variable cv; FILE * file; + bool file_owned; bool prefix; bool timestamps; @@ -330,19 +332,35 @@ public: void set_file(const char * path) { pause(); - if (file) { + if (file && file_owned) { fclose(file); } if (path) { file = fopen(path, "w"); + file_owned = true; } else { file = nullptr; + file_owned = false; } resume(); } + // Use an externally-owned FILE* (no fopen, no fclose on destruction). + void set_file_ptr(FILE * f) { + pause(); + + if (file && file_owned) { + fclose(file); + } + + file = f; + file_owned = false; + + resume(); + } + void set_colors(bool colors) { pause(); @@ -420,6 +438,13 @@ void common_log_set_file(struct common_log * log, const char * file) { log->set_file(file); } +// Share an externally-opened FILE* (e.g. log_handler's LOG_TARGET) so common_log +// tees to it without a second fopen() on the same path. common_log will not +// close it on destruction (the caller owns the handle). +void common_log_set_file_ptr(struct common_log * log, FILE * file) { + log->set_file_ptr(file); +} + void common_log_set_colors(struct common_log * log, log_colors colors) { if (colors == LOG_COLORS_AUTO) { log->set_colors(common_log_should_use_colors_auto()); diff --git a/common/log.h b/common/log.h index 783ccf92..7bd1978a 100644 --- a/common/log.h +++ b/common/log.h @@ -91,6 +91,9 @@ void common_log_add(struct common_log* log, enum ggml_log_level level, const cha // void common_log_set_file(struct common_log* log, const char* file); // not thread-safe +// Share an externally-opened FILE* (e.g. LOG_TARGET) so common_log tees to it +// without a second fopen() on the same path; common_log will not close it. +void common_log_set_file_ptr(struct common_log* log, FILE* file); // not thread-safe void common_log_set_colors(struct common_log* log, log_colors colors); // not thread-safe void common_log_set_prefix(struct common_log* log, bool prefix); // whether to output prefix to each log void common_log_set_timestamps(struct common_log* log, bool timestamps); // whether to output timestamps in the prefix @@ -441,6 +444,18 @@ inline std::string log_filename_generator_impl(LogTriState multilog, const std:: #define LOG_TEELN(str, ...) LOG_TEE_IMPL("%s" str, "", ##__VA_ARGS__, "\n") #endif +// True only when the log target was explicitly set via log_set_target() (e.g. +// by --log-file). LOG_TARGET is non-null by default (log_handler() lazily opens +// "llama.log"), so a null check cannot tell a user-requested file from the +// default. Tee callers should gate on this instead of `LOG_TARGET != nullptr`. +inline bool log_target_changed(bool mark_changed = false) { + static bool changed = false; + if (mark_changed) { + changed = true; + } + return changed; +} + // INTERNAL, DO NOT USE inline FILE *log_handler1_impl(bool change = false, LogTriState append = LogTriStateSame, LogTriState disable = LogTriStateSame, const std::string & filename = LOG_DEFAULT_FILE_NAME, FILE *target = nullptr) { @@ -561,8 +576,12 @@ inline FILE *log_enable_impl() #define log_set_target(target) log_set_target_impl(target) // INTERNAL, DO NOT USE -inline FILE *log_set_target_impl(const std::string & filename) { return log_handler1_impl(true, LogTriStateSame, LogTriStateSame, filename); } -inline FILE *log_set_target_impl(FILE *target) { return log_handler2_impl(true, LogTriStateSame, LogTriStateSame, target); } +// Mark log_target_changed() here (not inside log_handler1_impl): when --log-file +// is parsed before any LOG() call, this is the first invocation, so +// log_handler1_impl's static filename initializes to the requested name and its +// `!= filename` check never fires. +inline FILE *log_set_target_impl(const std::string & filename) { log_target_changed(true); return log_handler1_impl(true, LogTriStateSame, LogTriStateSame, filename); } +inline FILE *log_set_target_impl(FILE *target) { log_target_changed(true); return log_handler2_impl(true, LogTriStateSame, LogTriStateSame, target); } // INTERNAL, DO NOT USE inline FILE *log_handler() { return log_handler1_impl(); } diff --git a/examples/server/server-common.cpp b/examples/server/server-common.cpp index c8ec90d6..bf17d0e2 100644 --- a/examples/server/server-common.cpp +++ b/examples/server/server-common.cpp @@ -1,6 +1,7 @@ #include "server-common.h" #include +#include using raw_buffer = std::vector; @@ -33,6 +34,7 @@ void server_log(const char* level, const char* function, int line, const char* m {"timestamp", time(nullptr)}, }; + std::string out; if (server_log_json) { log.merge_patch({ {"level", level}, @@ -45,7 +47,7 @@ void server_log(const char* level, const char* function, int line, const char* m log.merge_patch(extra); } - printf("%s\n", log.dump(-1, ' ', false, json::error_handler_t::replace).c_str()); + out = log.dump(-1, ' ', false, json::error_handler_t::replace); } else { char buf[1024]; @@ -62,10 +64,19 @@ void server_log(const char* level, const char* function, int line, const char* m ss << " " << el.key() << "=" << value; } - const std::string str = ss.str(); - printf("%.*s\n", (int)str.size(), str.data()); + out = ss.str(); } + printf("%s\n", out.c_str()); fflush(stdout); + + // Mirror to --log-file when explicitly set (see log_target_changed()). + if (log_target_changed()) { + FILE * tgt = LOG_TARGET; + if (tgt != nullptr && tgt != stdout && tgt != stderr) { + fprintf(tgt, "%s\n", out.c_str()); + fflush(tgt); + } + } } // diff --git a/examples/server/server.cpp b/examples/server/server.cpp index 814f0d8d..6bf0ad13 100644 --- a/examples/server/server.cpp +++ b/examples/server/server.cpp @@ -17,6 +17,25 @@ // mime type for sending response #define MIMETYPE_JSON "application/json; charset=utf-8" +// Tee llama/ggml log output to --log-file (when set) and stderr. Gated on +// log_target_changed() so it's a no-op unless --log-file was passed (LOG_TARGET +// is non-null by default). The stdout/stderr guard mirrors LOG_TEE_IMPL and +// avoids doubled output when fopen() falls back to stderr. +static void llama_log_tee_callback(enum ggml_log_level level, const char * text, void * /*user_data*/) { + if (text == nullptr) { + return; + } + if (log_target_changed()) { + FILE * tgt = LOG_TARGET; + if (tgt != nullptr && tgt != stdout && tgt != stderr) { + fprintf(tgt, "%s", text); + fflush(tgt); + } + } + fputs(text, stderr); + fflush(stderr); +} + #ifndef NDEBUG // crash the server in debug mode, otherwise send an http 500 error @@ -466,6 +485,23 @@ int main(int argc, char ** argv) { // parse arguments from environment variables gpt_params_parse_from_env(params); + // Tee llama/ggml logs to --log-file; installed before model load so that + // load-time logs are captured too. + llama_log_set(llama_log_tee_callback, nullptr); + + // Route common_log (SLT_*/SRV_*/QUE_*/RES_*/bare LOG_* slot+queue output) to + // --log-file via its native file sink. The worker tees to stderr and file + // (common/log.cpp), so this captures every common_log line in one call + // instead of mirroring each macro. Share LOG_TARGET's already-opened FILE* + // so there's a single handle on the file (a second fopen would truncate and + // the two handles' writes would corrupt each other). + if (log_target_changed()) { + FILE * tgt = LOG_TARGET; + if (tgt != nullptr && tgt != stdout && tgt != stderr) { + common_log_set_file_ptr(common_log_main(), tgt); + } + } + // TODO: not great to use extern vars server_log_json = params.log_json; server_verbose = params.verbosity > 0;