/* * This file is part of mpv. * * mpv is free software; you can redistribute it and/or * modify it under the terms of the GNU Lesser General Public * License as published by the Free Software Foundation; either * version 2.1 of the License, or (at your option) any later version. * * mpv is distributed in the hope that it will be useful, * but WITHOUT ANY WARRANTY; without even the implied warranty of * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the * GNU Lesser General Public License for more details. * * You should have received a copy of the GNU Lesser General Public * License along with mpv. If not, see . */ #include #include #include #include #include #include #include #include #include "mpv_talloc.h" #include "misc/bstr.h" #include "osdep/atomic.h" #include "common/common.h" #include "common/global.h" #include "misc/ring.h" #include "misc/bstr.h" #include "options/options.h" #include "options/path.h" #include "osdep/terminal.h" #include "osdep/io.h" #include "osdep/timer.h" #include "libmpv/client.h" #include "msg.h" #include "msg_control.h" struct mp_log_root { struct mpv_global *global; // --- protected by mp_msg_lock char **msg_levels; bool use_terminal; // make accesses to stderr/stdout bool module; bool show_time; bool termosd; // use terminal control codes for status line int blank_lines; // number of lines usable by status int status_lines; // number of current status lines bool color; int verbose; bool really_quiet; bool force_stderr; struct mp_log_buffer **buffers; int num_buffers; FILE *log_file; FILE *stats_file; char *log_path; char *stats_path; // --- must be accessed atomically /* This is incremented every time the msglevels must be reloaded. * (This is perhaps better than maintaining a globally accessible and * synchronized mp_log tree.) */ atomic_ulong reload_counter; // --- protected by mp_msg_lock bstr buffer; }; struct mp_log { struct mp_log_root *root; const char *prefix; const char *verbose_prefix; int level; // minimum log level for any outputs int terminal_level; // minimum log level for terminal output atomic_ulong reload_counter; char *partial; }; struct mp_log_buffer { struct mp_log_root *root; struct mp_ring *ring; int level; void (*wakeup_cb)(void *ctx); void *wakeup_cb_ctx; }; // Protects some (not all) state in mp_log_root static pthread_mutex_t mp_msg_lock = PTHREAD_MUTEX_INITIALIZER; static const struct mp_log null_log = {0}; struct mp_log *const mp_null_log = (struct mp_log *)&null_log; static bool match_mod(const char *name, const char *mod) { if (!strcmp(mod, "all")) return true; // Path prefix matches bstr b = bstr0(name); return bstr_eatstart0(&b, mod) && (bstr_eatstart0(&b, "/") || !b.len); } static void update_loglevel(struct mp_log *log) { struct mp_log_root *root = log->root; pthread_mutex_lock(&mp_msg_lock); log->level = MSGL_STATUS + root->verbose; // default log level if (root->really_quiet) log->level -= 10; for (int n = 0; root->msg_levels && root->msg_levels[n * 2 + 0]; n++) { if (match_mod(log->verbose_prefix, root->msg_levels[n * 2 + 0])) log->level = mp_msg_find_level(root->msg_levels[n * 2 + 1]); } log->terminal_level = log->level; for (int n = 0; n < log->root->num_buffers; n++) log->level = MPMAX(log->level, log->root->buffers[n]->level); if (log->root->log_file) log->level = MPMAX(log->level, MSGL_DEBUG); if (log->root->stats_file) log->level = MPMAX(log->level, MSGL_STATS); atomic_store(&log->reload_counter, atomic_load(&log->root->reload_counter)); pthread_mutex_unlock(&mp_msg_lock); } // Return whether the message at this verbosity level would be actually printed. // Thread-safety: see mp_msg(). bool mp_msg_test(struct mp_log *log, int lev) { struct mp_log_root *root = log->root; if (!root) return false; if (atomic_load_explicit(&log->reload_counter, memory_order_relaxed) != atomic_load_explicit(&root->reload_counter, memory_order_relaxed)) { update_loglevel(log); } return lev <= log->level; } // Reposition cursor and clear lines for outputting the status line. In certain // cases, like term OSD and subtitle display, the status can consist of // multiple lines. static void prepare_status_line(struct mp_log_root *root, char *new_status) { FILE *f = stderr; size_t new_lines = 1; char *tmp = new_status; while (1) { tmp = strchr(tmp, '\n'); if (!tmp) break; new_lines++; tmp++; } size_t old_lines = root->status_lines; if (!new_status[0] && old_lines == 0) return; // nothing to clear size_t clear_lines = MPMIN(MPMAX(new_lines, old_lines), root->blank_lines); // clear the status line itself fprintf(f, "\r\033[K"); // and clear all previous old lines for (size_t n = 1; n < clear_lines; n++) fprintf(f, "\033[A\r\033[K"); // skip "unused" blank lines, so that status is aligned to term bottom for (size_t n = new_lines; n < clear_lines; n++) fprintf(f, "\n"); root->status_lines = new_lines; root->blank_lines = MPMAX(root->blank_lines, new_lines); } static void flush_status_line(struct mp_log_root *root) { // If there was a status line, don't overwrite it, but skip it. if (root->status_lines) fprintf(stderr, "\n"); root->status_lines = 0; root->blank_lines = 0; } void mp_msg_flush_status_line(struct mp_log *log) { pthread_mutex_lock(&mp_msg_lock); if (log->root) flush_status_line(log->root); pthread_mutex_unlock(&mp_msg_lock); } bool mp_msg_has_status_line(struct mpv_global *global) { pthread_mutex_lock(&mp_msg_lock); bool r = global->log->root->status_lines > 0; pthread_mutex_unlock(&mp_msg_lock); return r; } static void set_term_color(FILE *stream, int c) { if (c == -1) { fprintf(stream, "\033[0m"); } else { fprintf(stream, "\033[%d;3%dm", c >> 3, c & 7); } } static void set_msg_color(FILE* stream, int lev) { static const int v_colors[] = {9, 1, 3, -1, -1, 2, 8, 8, 8, -1}; set_term_color(stream, v_colors[lev]); } static void pretty_print_module(FILE* stream, const char *prefix, bool use_color, int lev) { // Use random color based on the name of the module if (use_color) { size_t prefix_len = strlen(prefix); unsigned int mod = 0; for (int i = 0; i < prefix_len; ++i) mod = mod * 33 + prefix[i]; set_term_color(stream, (mod + 1) % 15 + 1); } fprintf(stream, "%10s", prefix); if (use_color) set_term_color(stream, -1); fprintf(stream, ": "); if (use_color) set_msg_color(stream, lev); } static bool test_terminal_level(struct mp_log *log, int lev) { return lev <= log->terminal_level && log->root->use_terminal && !(lev == MSGL_STATUS && terminal_in_background()); } static void print_terminal_line(struct mp_log *log, int lev, char *text, char *trail) { if (!test_terminal_level(log, lev)) return; struct mp_log_root *root = log->root; FILE *stream = (root->force_stderr || lev == MSGL_STATUS) ? stderr : stdout; if (lev != MSGL_STATUS) flush_status_line(root); if (root->color) set_msg_color(stream, lev); if (root->show_time) fprintf(stream, "[%" PRId64 "] ", mp_time_us()); const char *prefix = log->prefix; if ((lev >= MSGL_V) || root->verbose || root->module) prefix = log->verbose_prefix; if (prefix) { if (root->module) { pretty_print_module(stream, prefix, root->color, lev); } else { fprintf(stream, "[%s] ", prefix); } } fprintf(stream, "%s%s", text, trail); if (root->color) set_term_color(stream, -1); fflush(stream); } static void write_log_file(struct mp_log *log, int lev, char *text) { struct mp_log_root *root = log->root; if (!root->log_file || lev > MPMAX(MSGL_DEBUG, log->terminal_level)) return; fprintf(root->log_file, "[%8.3f][%c][%s] %s", (mp_time_us() - MP_START_TIME) / 1e6, mp_log_levels[lev][0], log->verbose_prefix, text); fflush(root->log_file); } static void write_msg_to_buffers(struct mp_log *log, int lev, char *text) { struct mp_log_root *root = log->root; for (int n = 0; n < root->num_buffers; n++) { struct mp_log_buffer *buffer = root->buffers[n]; int buffer_level = buffer->level; if (buffer_level == MP_LOG_BUFFER_MSGL_TERM) buffer_level = log->terminal_level; if (lev <= buffer_level && lev != MSGL_STATUS) { // Assuming a single writer (serialized by msg lock) int avail = mp_ring_available(buffer->ring) / sizeof(void *); if (avail < 1) continue; struct mp_log_buffer_entry *entry = talloc_ptrtype(NULL, entry); if (avail > 1) { *entry = (struct mp_log_buffer_entry) { .prefix = talloc_strdup(entry, log->verbose_prefix), .level = lev, .text = talloc_strdup(entry, text), }; } else { // write overflow message to signal that messages might be lost *entry = (struct mp_log_buffer_entry) { .prefix = "overflow", .level = MSGL_FATAL, .text = "log message buffer overflow\n", }; } mp_ring_write(buffer->ring, (unsigned char *)&entry, sizeof(entry)); if (buffer->wakeup_cb) buffer->wakeup_cb(buffer->wakeup_cb_ctx); } } } static void dump_stats(struct mp_log *log, int lev, char *text) { struct mp_log_root *root = log->root; if (lev == MSGL_STATS && root->stats_file) fprintf(root->stats_file, "%"PRId64" %s\n", mp_time_us(), text); } void mp_msg_va(struct mp_log *log, int lev, const char *format, va_list va) { if (!mp_msg_test(log, lev)) return; // do not display pthread_mutex_lock(&mp_msg_lock); struct mp_log_root *root = log->root; root->buffer.len = 0; if (log->partial[0]) bstr_xappend_asprintf(root, &root->buffer, "%s", log->partial); log->partial[0] = '\0'; bstr_xappend_vasprintf(root, &root->buffer, format, va); char *text = root->buffer.start; if (lev == MSGL_STATS) { dump_stats(log, lev, text); } else if (lev == MSGL_STATUS && !test_terminal_level(log, lev)) { /* discard */ } else { if (lev == MSGL_STATUS && root->termosd) prepare_status_line(root, text); // Split away each line. Normally we require full lines; buffer partial // lines if they happen. while (1) { char *end = strchr(text, '\n'); if (!end) break; char *next = &end[1]; char saved = next[0]; next[0] = '\0'; print_terminal_line(log, lev, text, ""); write_log_file(log, lev, text); write_msg_to_buffers(log, lev, text); next[0] = saved; text = next; } if (lev == MSGL_STATUS) { if (text[0]) print_terminal_line(log, lev, text, root->termosd ? "\r" : "\n"); } else if (text[0]) { int size = strlen(text) + 1; if (talloc_get_size(log->partial) < size) log->partial = talloc_realloc(NULL, log->partial, char, size); memcpy(log->partial, text, size); } } pthread_mutex_unlock(&mp_msg_lock); } static void destroy_log(void *ptr) { struct mp_log *log = ptr; // This is not managed via talloc itself, because mp_msg calls must be // thread-safe, while talloc is not thread-safe. talloc_free(log->partial); } // Create a new log context, which uses talloc_ctx as talloc parent, and parent // as logical parent. // The name is the prefix put before the output. It's usually prefixed by the // parent's name. If the name starts with "/", the parent's name is not // prefixed (except in verbose mode), and if it starts with "!", the name is // not printed at all (except in verbose mode). // If name is NULL, the parent's name/prefix is used. // Thread-safety: fully thread-safe, but keep in mind that talloc is not (so // talloc_ctx must be owned by the current thread). struct mp_log *mp_log_new(void *talloc_ctx, struct mp_log *parent, const char *name) { assert(parent); struct mp_log *log = talloc_zero(talloc_ctx, struct mp_log); if (!parent->root) return log; // same as null_log talloc_set_destructor(log, destroy_log); log->root = parent->root; log->partial = talloc_strdup(NULL, ""); if (name) { if (name[0] == '!') { name = &name[1]; } else if (name[0] == '/') { name = &name[1]; log->prefix = talloc_strdup(log, name); } else { log->prefix = parent->prefix ? talloc_asprintf(log, "%s/%s", parent->prefix, name) : talloc_strdup(log, name); } log->verbose_prefix = parent->prefix ? talloc_asprintf(log, "%s/%s", parent->prefix, name) : talloc_strdup(log, name); if (log->prefix && !log->prefix[0]) log->prefix = NULL; if (!log->verbose_prefix[0]) log->verbose_prefix = "global"; } else { log->prefix = talloc_strdup(log, parent->prefix); log->verbose_prefix = talloc_strdup(log, parent->verbose_prefix); } return log; } void mp_msg_init(struct mpv_global *global) { assert(!global->log); struct mp_log_root *root = talloc_zero(NULL, struct mp_log_root); *root = (struct mp_log_root){ .global = global, .reload_counter = ATOMIC_VAR_INIT(1), }; struct mp_log dummy = { .root = root }; struct mp_log *log = mp_log_new(root, &dummy, ""); global->log = log; } // If opt is different from *current_path, reopen *file and update *current_path. // If there's an error, _append_ it to err_buf. // *current_path and *file are, rather trickily, only accessible under the // mp_msg_lock. static void reopen_file(char *opt, char **current_path, FILE **file, const char *type, struct mpv_global *global) { void *tmp = talloc_new(NULL); bool fail = false; char *new_path = mp_get_user_path(tmp, global, opt); if (!new_path) new_path = ""; pthread_mutex_lock(&mp_msg_lock); // for *current_path/*file char *old_path = *current_path ? *current_path : ""; if (strcmp(old_path, new_path) != 0) { if (*file) fclose(*file); *file = NULL; talloc_free(*current_path); *current_path = talloc_strdup(NULL, new_path); if (new_path[0]) { *file = fopen(new_path, "wb"); fail = !*file; } } pthread_mutex_unlock(&mp_msg_lock); if (fail) mp_err(global->log, "Failed to open %s file '%s'\n", type, new_path); talloc_free(tmp); } void mp_msg_update_msglevels(struct mpv_global *global, struct MPOpts *opts) { struct mp_log_root *root = global->log->root; pthread_mutex_lock(&mp_msg_lock); root->verbose = opts->verbose; root->really_quiet = opts->msg_really_quiet; root->module = opts->msg_module; root->use_terminal = opts->use_terminal; root->show_time = opts->msg_time; if (root->use_terminal) { root->color = opts->msg_color && isatty(STDOUT_FILENO); root->termosd = isatty(STDERR_FILENO); } m_option_type_msglevels.free(&root->msg_levels); m_option_type_msglevels.copy(NULL, &root->msg_levels, &opts->msg_levels); atomic_fetch_add(&root->reload_counter, 1); pthread_mutex_unlock(&mp_msg_lock); reopen_file(opts->log_file, &root->log_path, &root->log_file, "log", global); reopen_file(opts->dump_stats, &root->stats_path, &root->stats_file, "stats", global); } void mp_msg_force_stderr(struct mpv_global *global, bool force_stderr) { struct mp_log_root *root = global->log->root; pthread_mutex_lock(&mp_msg_lock); root->force_stderr = force_stderr; pthread_mutex_unlock(&mp_msg_lock); } bool mp_msg_has_log_file(struct mpv_global *global) { struct mp_log_root *root = global->log->root; pthread_mutex_lock(&mp_msg_lock); bool res = !!root->log_file; pthread_mutex_unlock(&mp_msg_lock); return res; } void mp_msg_uninit(struct mpv_global *global) { struct mp_log_root *root = global->log->root; if (root->stats_file) fclose(root->stats_file); talloc_free(root->stats_path); if (root->log_file) fclose(root->log_file); talloc_free(root->log_path); m_option_type_msglevels.free(&root->msg_levels); talloc_free(root); global->log = NULL; } struct mp_log_buffer *mp_msg_log_buffer_new(struct mpv_global *global, int size, int level, void (*wakeup_cb)(void *ctx), void *wakeup_cb_ctx) { struct mp_log_root *root = global->log->root; #if !HAVE_ATOMICS return NULL; #endif pthread_mutex_lock(&mp_msg_lock); struct mp_log_buffer *buffer = talloc_ptrtype(NULL, buffer); *buffer = (struct mp_log_buffer) { .root = root, .level = level, .ring = mp_ring_new(buffer, sizeof(void *) * size), .wakeup_cb = wakeup_cb, .wakeup_cb_ctx = wakeup_cb_ctx, }; if (!buffer->ring) abort(); MP_TARRAY_APPEND(root, root->buffers, root->num_buffers, buffer); atomic_fetch_add(&root->reload_counter, 1); pthread_mutex_unlock(&mp_msg_lock); return buffer; } void mp_msg_log_buffer_destroy(struct mp_log_buffer *buffer) { if (!buffer) return; pthread_mutex_lock(&mp_msg_lock); struct mp_log_root *root = buffer->root; for (int n = 0; n < root->num_buffers; n++) { if (root->buffers[n] == buffer) { MP_TARRAY_REMOVE_AT(root->buffers, root->num_buffers, n); goto found; } } abort(); found: while (1) { struct mp_log_buffer_entry *e = mp_msg_log_buffer_read(buffer); if (!e) break; talloc_free(e); } talloc_free(buffer); atomic_fetch_add(&root->reload_counter, 1); pthread_mutex_unlock(&mp_msg_lock); } // Return a queued message, or if the buffer is empty, NULL. // Thread-safety: one buffer can be read by a single thread only. struct mp_log_buffer_entry *mp_msg_log_buffer_read(struct mp_log_buffer *buffer) { void *ptr = NULL; int read = mp_ring_read(buffer->ring, (unsigned char *)&ptr, sizeof(ptr)); if (read == 0) return NULL; if (read != sizeof(ptr)) abort(); return ptr; } // Thread-safety: fully thread-safe, but keep in mind that the lifetime of // log must be guaranteed during the call. // Never call this from signal handlers. void mp_msg(struct mp_log *log, int lev, const char *format, ...) { va_list va; va_start(va, format); mp_msg_va(log, lev, format, va); va_end(va); } const char *const mp_log_levels[MSGL_MAX + 1] = { [MSGL_FATAL] = "fatal", [MSGL_ERR] = "error", [MSGL_WARN] = "warn", [MSGL_INFO] = "info", [MSGL_STATUS] = "status", [MSGL_V] = "v", [MSGL_DEBUG] = "debug", [MSGL_TRACE] = "trace", [MSGL_STATS] = "stats", }; const int mp_mpv_log_levels[MSGL_MAX + 1] = { [MSGL_FATAL] = MPV_LOG_LEVEL_FATAL, [MSGL_ERR] = MPV_LOG_LEVEL_ERROR, [MSGL_WARN] = MPV_LOG_LEVEL_WARN, [MSGL_INFO] = MPV_LOG_LEVEL_INFO, [MSGL_STATUS] = 0, // never used [MSGL_V] = MPV_LOG_LEVEL_V, [MSGL_DEBUG] = MPV_LOG_LEVEL_DEBUG, [MSGL_TRACE] = MPV_LOG_LEVEL_TRACE, [MSGL_STATS] = 0, // never used }; int mp_msg_find_level(const char *s) { for (int n = 0; n < MP_ARRAY_SIZE(mp_log_levels); n++) { if (mp_log_levels[n] && !strcmp(s, mp_log_levels[n])) return n; } return -1; }