diff --git a/common/msg.c b/common/msg.c index 256456e3a6..8e5ad26a11 100644 --- a/common/msg.c +++ b/common/msg.c @@ -47,6 +47,12 @@ #define TERM_BUF 100 #define FILE_BUF 100 +// logfile lines to accumulate during init before we know the log file name. +// thousands of logfile lines during init can happen (especially with many +// scripts, big config, etc), so we set 5000. If it cycles and messages are +// overwritten, then the first (virtual) log line indicates how many were lost. +#define EARLY_FILE_BUF 5000 + struct mp_log_root { struct mpv_global *global; pthread_mutex_t lock; @@ -66,6 +72,7 @@ struct mp_log_root { struct mp_log_buffer **buffers; int num_buffers; struct mp_log_buffer *early_buffer; + struct mp_log_buffer *early_filebuffer; FILE *stats_file; bstr buffer; // --- must be accessed atomically @@ -352,7 +359,8 @@ static void write_msg_to_buffers(struct mp_log *log, int lev, char *text) buffer_level = MPMAX(log->terminal_level, MSGL_DEBUG); if (lev <= buffer_level && lev != MSGL_STATUS) { if (buffer->level == MP_LOG_BUFFER_MSGL_LOGFILE) { - // If the buffer is full, block until we can write again. + // If the buffer is full, block until we can write again, + // unless there's no write thread (died, or early filebuffer) bool dead = false; while (buffer->num_entries == buffer->capacity && !dead) { // Temporary unlock is OK; buffer->level is immutable, and @@ -643,6 +651,31 @@ void mp_msg_update_msglevels(struct mpv_global *global, struct MPOpts *opts) if (root->log_path) { root->log_file = fopen(root->log_path, "wb"); if (root->log_file) { + + // if a logfile is created and the early filebuf still exists, + // flush and destroy the early buffer + pthread_mutex_lock(&root->lock); + struct mp_log_buffer *earlybuf = root->early_filebuffer; + if (earlybuf) + root->early_filebuffer = NULL; // but it still logs msgs + pthread_mutex_unlock(&root->lock); + + if (earlybuf) { + // flush, destroy before creating the normal logfile buf, + // as once the new one is created (specifically, its write + // thread), then MSGL_LOGFILE messages become blocking, but + // the early logfile buf is without dequeue - can deadlock. + // note: timestamp is unknown, we use 0.000 as indication. + // note: new messages while iterating are still flushed. + struct mp_log_buffer_entry *e; + while ((e = mp_msg_log_buffer_read(earlybuf))) { + fprintf(root->log_file, "[%8.3f][%c][%s] %s", 0.0, + mp_log_levels[e->level][0], e->prefix, e->text); + talloc_free(e); + } + mp_msg_log_buffer_destroy(earlybuf); // + remove from root + } + root->log_file_buffer = mp_msg_log_buffer_new(global, FILE_BUF, MP_LOG_BUFFER_MSGL_LOGFILE, wakeup_log_file, root); @@ -702,6 +735,7 @@ void mp_msg_uninit(struct mpv_global *global) struct mp_log_root *root = global->log->root; terminate_log_file_thread(root); mp_msg_log_buffer_destroy(root->early_buffer); + mp_msg_log_buffer_destroy(root->early_filebuffer); assert(root->num_buffers == 0); if (root->stats_file) fclose(root->stats_file); @@ -715,23 +749,42 @@ void mp_msg_uninit(struct mpv_global *global) global->log = NULL; } -void mp_msg_set_early_logging(struct mpv_global *global, bool enable) +// early logging store log messages before they have a known destination. +// there are two early log buffers which are similar logically, and both cease +// function (if still exist, independently) once the log destination is known, +// or mpv init is complete (typically, after all clients/scripts init is done). +// +// - "normal" early_buffer, holds early terminal-level logs, and is handed over +// to the first client which requests such log buffer, so that it sees older +// messages too. further clients which request a log buffer get a new one +// which accumulates messages starting at this point in time. +// +// - early_filebuffer - early log-file messages until a log file name is known. +// main cases where meaningful messages are accumulated before the filename +// is known are when log-file is set at mpv.conf, or from script/client init. +// once a file name is known, the early buffer is flushed and destroyed. +// unlike the "proper" log-file buffer, the early filebuffer is not backed by +// a write thread, and hence non-blocking (can overwrite old messages). +// it's also bigger than the actual file buffer (early: 5000, actual: 100). + +static void mp_msg_set_early_logging_raw(struct mpv_global *global, bool enable, + struct mp_log_buffer **root_logbuf, + int size, int level) { struct mp_log_root *root = global->log->root; pthread_mutex_lock(&root->lock); - if (enable != !!root->early_buffer) { + if (enable != !!*root_logbuf) { if (enable) { pthread_mutex_unlock(&root->lock); struct mp_log_buffer *buf = - mp_msg_log_buffer_new(global, TERM_BUF, MP_LOG_BUFFER_MSGL_TERM, - NULL, NULL); + mp_msg_log_buffer_new(global, size, level, NULL, NULL); pthread_mutex_lock(&root->lock); - assert(!root->early_buffer); // no concurrent calls to this function - root->early_buffer = buf; + assert(!*root_logbuf); // no concurrent calls to this function + *root_logbuf = buf; } else { - struct mp_log_buffer *buf = root->early_buffer; - root->early_buffer = NULL; + struct mp_log_buffer *buf = *root_logbuf; + *root_logbuf = NULL; pthread_mutex_unlock(&root->lock); mp_msg_log_buffer_destroy(buf); return; @@ -741,6 +794,18 @@ void mp_msg_set_early_logging(struct mpv_global *global, bool enable) pthread_mutex_unlock(&root->lock); } +void mp_msg_set_early_logging(struct mpv_global *global, bool enable) +{ + struct mp_log_root *root = global->log->root; + + mp_msg_set_early_logging_raw(global, enable, &root->early_buffer, + TERM_BUF, MP_LOG_BUFFER_MSGL_TERM); + + // normally MSGL_LOGFILE buffer gets a write thread, but not the early buf + mp_msg_set_early_logging_raw(global, enable, &root->early_filebuffer, + EARLY_FILE_BUF, MP_LOG_BUFFER_MSGL_LOGFILE); +} + struct mp_log_buffer *mp_msg_log_buffer_new(struct mpv_global *global, int size, int level, void (*wakeup_cb)(void *ctx), diff --git a/player/main.c b/player/main.c index 2f4bede898..1dde63e31f 100644 --- a/player/main.c +++ b/player/main.c @@ -137,8 +137,12 @@ void mp_update_logging(struct MPContext *mpctx, bool preinit) } } - if (mp_msg_has_log_file(mpctx->global) && !had_log_file) - mp_print_version(mpctx->log, false); // for log-file=... in config files + if (mp_msg_has_log_file(mpctx->global) && !had_log_file) { + // for log-file=... in config files. + // we did flush earlier messages, but they were in a cyclic buffer, so + // the version might have been overwritten. ensure we have it. + mp_print_version(mpctx->log, false); + } if (enabled && !preinit && mpctx->opts->consolecontrols) terminal_setup_getch(mpctx->input);