1 /*
2  * This file is part of mpv.
3  *
4  * mpv is free software; you can redistribute it and/or
5  * modify it under the terms of the GNU Lesser General Public
6  * License as published by the Free Software Foundation; either
7  * version 2.1 of the License, or (at your option) any later version.
8  *
9  * mpv is distributed in the hope that it will be useful,
10  * but WITHOUT ANY WARRANTY; without even the implied warranty of
11  * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
12  * GNU Lesser General Public License for more details.
13  *
14  * You should have received a copy of the GNU Lesser General Public
15  * License along with mpv.  If not, see <http://www.gnu.org/licenses/>.
16  */
17 
18 #include <stdio.h>
19 #include <stdlib.h>
20 #include <stdarg.h>
21 #include <string.h>
22 #include <unistd.h>
23 #include <assert.h>
24 #include <pthread.h>
25 #include <stdint.h>
26 
27 #include "mpv_talloc.h"
28 
29 #include "misc/bstr.h"
30 #include "osdep/atomic.h"
31 #include "common/common.h"
32 #include "common/global.h"
33 #include "misc/bstr.h"
34 #include "options/options.h"
35 #include "options/path.h"
36 #include "osdep/terminal.h"
37 #include "osdep/io.h"
38 #include "osdep/threads.h"
39 #include "osdep/timer.h"
40 
41 #include "libmpv/client.h"
42 
43 #include "msg.h"
44 #include "msg_control.h"
45 
46 #define TERM_BUF 100
47 
48 struct mp_log_root {
49     struct mpv_global *global;
50     pthread_mutex_t lock;
51     pthread_mutex_t log_file_lock;
52     pthread_cond_t log_file_wakeup;
53     // --- protected by lock
54     char **msg_levels;
55     bool use_terminal;  // make accesses to stderr/stdout
56     bool module;
57     bool show_time;
58     int blank_lines;    // number of lines usable by status
59     int status_lines;   // number of current status lines
60     bool color;
61     int verbose;
62     bool really_quiet;
63     bool force_stderr;
64     struct mp_log_buffer **buffers;
65     int num_buffers;
66     struct mp_log_buffer *early_buffer;
67     FILE *stats_file;
68     bstr buffer;
69     // --- must be accessed atomically
70     /* This is incremented every time the msglevels must be reloaded.
71      * (This is perhaps better than maintaining a globally accessible and
72      * synchronized mp_log tree.) */
73     atomic_ulong reload_counter;
74     // --- owner thread only (caller of mp_msg_init() etc.)
75     char *log_path;
76     char *stats_path;
77     pthread_t log_file_thread;
78     // --- owner thread only, but frozen while log_file_thread is running
79     FILE *log_file;
80     struct mp_log_buffer *log_file_buffer;
81     // --- protected by log_file_lock
82     bool log_file_thread_active; // also termination signal for the thread
83 };
84 
85 struct mp_log {
86     struct mp_log_root *root;
87     const char *prefix;
88     const char *verbose_prefix;
89     int max_level;              // minimum log level for this instance
90     int level;                  // minimum log level for any outputs
91     int terminal_level;         // minimum log level for terminal output
92     atomic_ulong reload_counter;
93     char *partial;
94 };
95 
96 struct mp_log_buffer {
97     struct mp_log_root *root;
98     pthread_mutex_t lock;
99     // --- protected by lock
100     struct mp_log_buffer_entry **entries;   // ringbuffer
101     int capacity;                           // total space in entries[]
102     int entry0;                             // first (oldest) entry index
103     int num_entries;                        // number of valid entries after entry0
104     uint64_t dropped;                       // number of skipped entries
105     bool silent;
106     // --- immutable
107     void (*wakeup_cb)(void *ctx);
108     void *wakeup_cb_ctx;
109     int level;
110 };
111 
112 static const struct mp_log null_log = {0};
113 struct mp_log *const mp_null_log = (struct mp_log *)&null_log;
114 
match_mod(const char * name,const char * mod)115 static bool match_mod(const char *name, const char *mod)
116 {
117     if (!strcmp(mod, "all"))
118         return true;
119     // Path prefix matches
120     bstr b = bstr0(name);
121     return bstr_eatstart0(&b, mod) && (bstr_eatstart0(&b, "/") || !b.len);
122 }
123 
update_loglevel(struct mp_log * log)124 static void update_loglevel(struct mp_log *log)
125 {
126     struct mp_log_root *root = log->root;
127     pthread_mutex_lock(&root->lock);
128     log->level = MSGL_STATUS + root->verbose; // default log level
129     if (root->really_quiet)
130         log->level = -1;
131     for (int n = 0; root->msg_levels && root->msg_levels[n * 2 + 0]; n++) {
132         if (match_mod(log->verbose_prefix, root->msg_levels[n * 2 + 0]))
133             log->level = mp_msg_find_level(root->msg_levels[n * 2 + 1]);
134     }
135     log->terminal_level = log->level;
136     for (int n = 0; n < log->root->num_buffers; n++) {
137         int buffer_level = log->root->buffers[n]->level;
138         if (buffer_level == MP_LOG_BUFFER_MSGL_LOGFILE)
139             buffer_level = MSGL_DEBUG;
140         if (buffer_level != MP_LOG_BUFFER_MSGL_TERM)
141             log->level = MPMAX(log->level, buffer_level);
142     }
143     if (log->root->log_file)
144         log->level = MPMAX(log->level, MSGL_DEBUG);
145     if (log->root->stats_file)
146         log->level = MPMAX(log->level, MSGL_STATS);
147     log->level = MPMIN(log->level, log->max_level);
148     atomic_store(&log->reload_counter, atomic_load(&log->root->reload_counter));
149     pthread_mutex_unlock(&root->lock);
150 }
151 
152 // Set (numerically) the maximum level that should still be output for this log
153 // instances. E.g. lev=MSGL_WARN => show only warnings and errors.
mp_msg_set_max_level(struct mp_log * log,int lev)154 void mp_msg_set_max_level(struct mp_log *log, int lev)
155 {
156     if (!log->root)
157         return;
158     pthread_mutex_lock(&log->root->lock);
159     log->max_level = MPCLAMP(lev, -1, MSGL_MAX);
160     pthread_mutex_unlock(&log->root->lock);
161     update_loglevel(log);
162 }
163 
164 // Get the current effective msg level.
165 // Thread-safety: see mp_msg().
mp_msg_level(struct mp_log * log)166 int mp_msg_level(struct mp_log *log)
167 {
168     struct mp_log_root *root = log->root;
169     if (!root)
170         return -1;
171     if (atomic_load_explicit(&log->reload_counter, memory_order_relaxed) !=
172         atomic_load_explicit(&root->reload_counter, memory_order_relaxed))
173     {
174         update_loglevel(log);
175     }
176     return log->level;
177 }
178 
179 // Reposition cursor and clear lines for outputting the status line. In certain
180 // cases, like term OSD and subtitle display, the status can consist of
181 // multiple lines.
prepare_status_line(struct mp_log_root * root,char * new_status)182 static void prepare_status_line(struct mp_log_root *root, char *new_status)
183 {
184     FILE *f = stderr;
185 
186     size_t new_lines = 1;
187     char *tmp = new_status;
188     while (1) {
189         tmp = strchr(tmp, '\n');
190         if (!tmp)
191             break;
192         new_lines++;
193         tmp++;
194     }
195 
196     size_t old_lines = root->status_lines;
197     if (!new_status[0] && old_lines == 0)
198         return; // nothing to clear
199 
200     size_t clear_lines = MPMIN(MPMAX(new_lines, old_lines), root->blank_lines);
201 
202     // clear the status line itself
203     fprintf(f, "\r\033[K");
204     // and clear all previous old lines
205     for (size_t n = 1; n < clear_lines; n++)
206         fprintf(f, "\033[A\r\033[K");
207     // skip "unused" blank lines, so that status is aligned to term bottom
208     for (size_t n = new_lines; n < clear_lines; n++)
209         fprintf(f, "\n");
210 
211     root->status_lines = new_lines;
212     root->blank_lines = MPMAX(root->blank_lines, new_lines);
213 }
214 
flush_status_line(struct mp_log_root * root)215 static void flush_status_line(struct mp_log_root *root)
216 {
217     // If there was a status line, don't overwrite it, but skip it.
218     if (root->status_lines)
219         fprintf(stderr, "\n");
220     root->status_lines = 0;
221     root->blank_lines = 0;
222 }
223 
mp_msg_flush_status_line(struct mp_log * log)224 void mp_msg_flush_status_line(struct mp_log *log)
225 {
226     if (log->root) {
227         pthread_mutex_lock(&log->root->lock);
228         flush_status_line(log->root);
229         pthread_mutex_unlock(&log->root->lock);
230     }
231 }
232 
mp_msg_set_term_title(struct mp_log * log,const char * title)233 void mp_msg_set_term_title(struct mp_log *log, const char *title)
234 {
235     if (log->root && title) {
236         // Lock because printf to terminal is not necessarily atomic.
237         pthread_mutex_lock(&log->root->lock);
238         fprintf(stderr, "\e]0;%s\007", title);
239         pthread_mutex_unlock(&log->root->lock);
240     }
241 }
242 
mp_msg_has_status_line(struct mpv_global * global)243 bool mp_msg_has_status_line(struct mpv_global *global)
244 {
245     struct mp_log_root *root = global->log->root;
246     pthread_mutex_lock(&root->lock);
247     bool r = root->status_lines > 0;
248     pthread_mutex_unlock(&root->lock);
249     return r;
250 }
251 
set_term_color(FILE * stream,int c)252 static void set_term_color(FILE *stream, int c)
253 {
254     if (c == -1) {
255         fprintf(stream, "\033[0m");
256     } else {
257         fprintf(stream, "\033[%d;3%dm", c >> 3, c & 7);
258     }
259 }
260 
261 
set_msg_color(FILE * stream,int lev)262 static void set_msg_color(FILE* stream, int lev)
263 {
264     static const int v_colors[] = {9, 1, 3, -1, -1, 2, 8, 8, 8, -1};
265     set_term_color(stream, v_colors[lev]);
266 }
267 
pretty_print_module(FILE * stream,const char * prefix,bool use_color,int lev)268 static void pretty_print_module(FILE* stream, const char *prefix, bool use_color, int lev)
269 {
270     // Use random color based on the name of the module
271     if (use_color) {
272         size_t prefix_len = strlen(prefix);
273         unsigned int mod = 0;
274         for (int i = 0; i < prefix_len; ++i)
275             mod = mod * 33 + prefix[i];
276         set_term_color(stream, (mod + 1) % 15 + 1);
277     }
278 
279     fprintf(stream, "%10s", prefix);
280     if (use_color)
281         set_term_color(stream, -1);
282     fprintf(stream, ": ");
283     if (use_color)
284         set_msg_color(stream, lev);
285 }
286 
test_terminal_level(struct mp_log * log,int lev)287 static bool test_terminal_level(struct mp_log *log, int lev)
288 {
289     return lev <= log->terminal_level && log->root->use_terminal &&
290            !(lev == MSGL_STATUS && terminal_in_background());
291 }
292 
print_terminal_line(struct mp_log * log,int lev,char * text,char * trail)293 static void print_terminal_line(struct mp_log *log, int lev,
294                                 char *text,  char *trail)
295 {
296     if (!test_terminal_level(log, lev))
297         return;
298 
299     struct mp_log_root *root = log->root;
300     FILE *stream = (root->force_stderr || lev == MSGL_STATUS) ? stderr : stdout;
301 
302     if (lev != MSGL_STATUS)
303         flush_status_line(root);
304 
305     if (root->color)
306         set_msg_color(stream, lev);
307 
308     if (root->show_time)
309         fprintf(stream, "[%10.6f] ", (mp_time_us() - MP_START_TIME) / 1e6);
310 
311     const char *prefix = log->prefix;
312     if ((lev >= MSGL_V) || root->verbose || root->module)
313         prefix = log->verbose_prefix;
314 
315     if (prefix) {
316         if (root->module) {
317             pretty_print_module(stream, prefix, root->color, lev);
318         } else {
319             fprintf(stream, "[%s] ", prefix);
320         }
321     }
322 
323     fprintf(stream, "%s%s", text, trail);
324 
325     if (root->color)
326         set_term_color(stream, -1);
327     fflush(stream);
328 }
329 
log_buffer_read(struct mp_log_buffer * buffer)330 static struct mp_log_buffer_entry *log_buffer_read(struct mp_log_buffer *buffer)
331 {
332     assert(buffer->num_entries);
333     struct mp_log_buffer_entry *res = buffer->entries[buffer->entry0];
334     buffer->entry0 = (buffer->entry0 + 1) % buffer->capacity;
335     buffer->num_entries -= 1;
336     return res;
337 }
338 
write_msg_to_buffers(struct mp_log * log,int lev,char * text)339 static void write_msg_to_buffers(struct mp_log *log, int lev, char *text)
340 {
341     struct mp_log_root *root = log->root;
342     for (int n = 0; n < root->num_buffers; n++) {
343         struct mp_log_buffer *buffer = root->buffers[n];
344         bool wakeup = false;
345         pthread_mutex_lock(&buffer->lock);
346         int buffer_level = buffer->level;
347         if (buffer_level == MP_LOG_BUFFER_MSGL_TERM)
348             buffer_level = log->terminal_level;
349         if (buffer_level == MP_LOG_BUFFER_MSGL_LOGFILE)
350             buffer_level = MPMAX(log->terminal_level, MSGL_DEBUG);
351         if (lev <= buffer_level && lev != MSGL_STATUS) {
352             if (buffer->level == MP_LOG_BUFFER_MSGL_LOGFILE) {
353                 // If the buffer is full, block until we can write again.
354                 bool dead = false;
355                 while (buffer->num_entries == buffer->capacity && !dead) {
356                     // Temporary unlock is OK; buffer->level is immutable, and
357                     // buffer can't go away because the global log lock is held.
358                     pthread_mutex_unlock(&buffer->lock);
359                     pthread_mutex_lock(&root->log_file_lock);
360                     if (root->log_file_thread_active) {
361                         pthread_cond_wait(&root->log_file_wakeup,
362                                           &root->log_file_lock);
363                     } else {
364                         dead = true;
365                     }
366                     pthread_mutex_unlock(&root->log_file_lock);
367                     pthread_mutex_lock(&buffer->lock);
368                 }
369             }
370             if (buffer->num_entries == buffer->capacity) {
371                 struct mp_log_buffer_entry *skip = log_buffer_read(buffer);
372                 talloc_free(skip);
373                 buffer->dropped += 1;
374             }
375             struct mp_log_buffer_entry *entry = talloc_ptrtype(NULL, entry);
376             *entry = (struct mp_log_buffer_entry) {
377                 .prefix = talloc_strdup(entry, log->verbose_prefix),
378                 .level = lev,
379                 .text = talloc_strdup(entry, text),
380             };
381             int pos = (buffer->entry0 + buffer->num_entries) % buffer->capacity;
382             buffer->entries[pos] = entry;
383             buffer->num_entries += 1;
384             if (buffer->wakeup_cb && !buffer->silent)
385                 wakeup = true;
386         }
387         pthread_mutex_unlock(&buffer->lock);
388         if (wakeup)
389             buffer->wakeup_cb(buffer->wakeup_cb_ctx);
390     }
391 }
392 
dump_stats(struct mp_log * log,int lev,char * text)393 static void dump_stats(struct mp_log *log, int lev, char *text)
394 {
395     struct mp_log_root *root = log->root;
396     if (lev == MSGL_STATS && root->stats_file)
397         fprintf(root->stats_file, "%"PRId64" %s\n", mp_time_us(), text);
398 }
399 
mp_msg_va(struct mp_log * log,int lev,const char * format,va_list va)400 void mp_msg_va(struct mp_log *log, int lev, const char *format, va_list va)
401 {
402     if (!mp_msg_test(log, lev))
403         return; // do not display
404 
405     struct mp_log_root *root = log->root;
406 
407     pthread_mutex_lock(&root->lock);
408 
409     root->buffer.len = 0;
410 
411     if (log->partial[0])
412         bstr_xappend_asprintf(root, &root->buffer, "%s", log->partial);
413     log->partial[0] = '\0';
414 
415     bstr_xappend_vasprintf(root, &root->buffer, format, va);
416 
417     char *text = root->buffer.start;
418 
419     if (lev == MSGL_STATS) {
420         dump_stats(log, lev, text);
421     } else if (lev == MSGL_STATUS && !test_terminal_level(log, lev)) {
422         /* discard */
423     } else {
424         if (lev == MSGL_STATUS)
425             prepare_status_line(root, text);
426 
427         // Split away each line. Normally we require full lines; buffer partial
428         // lines if they happen.
429         while (1) {
430             char *end = strchr(text, '\n');
431             if (!end)
432                 break;
433             char *next = &end[1];
434             char saved = next[0];
435             next[0] = '\0';
436             print_terminal_line(log, lev, text, "");
437             write_msg_to_buffers(log, lev, text);
438             next[0] = saved;
439             text = next;
440         }
441 
442         if (lev == MSGL_STATUS) {
443             if (text[0])
444                 print_terminal_line(log, lev, text, "\r");
445         } else if (text[0]) {
446             int size = strlen(text) + 1;
447             if (talloc_get_size(log->partial) < size)
448                 log->partial = talloc_realloc(NULL, log->partial, char, size);
449             memcpy(log->partial, text, size);
450         }
451     }
452 
453     pthread_mutex_unlock(&root->lock);
454 }
455 
destroy_log(void * ptr)456 static void destroy_log(void *ptr)
457 {
458     struct mp_log *log = ptr;
459     // This is not managed via talloc itself, because mp_msg calls must be
460     // thread-safe, while talloc is not thread-safe.
461     talloc_free(log->partial);
462 }
463 
464 // Create a new log context, which uses talloc_ctx as talloc parent, and parent
465 // as logical parent.
466 // The name is the prefix put before the output. It's usually prefixed by the
467 // parent's name. If the name starts with "/", the parent's name is not
468 // prefixed (except in verbose mode), and if it starts with "!", the name is
469 // not printed at all (except in verbose mode).
470 // If name is NULL, the parent's name/prefix is used.
471 // Thread-safety: fully thread-safe, but keep in mind that talloc is not (so
472 //                talloc_ctx must be owned by the current thread).
mp_log_new(void * talloc_ctx,struct mp_log * parent,const char * name)473 struct mp_log *mp_log_new(void *talloc_ctx, struct mp_log *parent,
474                           const char *name)
475 {
476     assert(parent);
477     struct mp_log *log = talloc_zero(talloc_ctx, struct mp_log);
478     if (!parent->root)
479         return log; // same as null_log
480     talloc_set_destructor(log, destroy_log);
481     log->root = parent->root;
482     log->partial = talloc_strdup(NULL, "");
483     log->max_level = MSGL_MAX;
484     if (name) {
485         if (name[0] == '!') {
486             name = &name[1];
487         } else if (name[0] == '/') {
488             name = &name[1];
489             log->prefix = talloc_strdup(log, name);
490         } else {
491             log->prefix = parent->prefix
492                     ? talloc_asprintf(log, "%s/%s", parent->prefix, name)
493                     : talloc_strdup(log, name);
494         }
495         log->verbose_prefix = parent->prefix
496                 ? talloc_asprintf(log, "%s/%s", parent->prefix, name)
497                 : talloc_strdup(log, name);
498         if (log->prefix && !log->prefix[0])
499             log->prefix = NULL;
500         if (!log->verbose_prefix[0])
501             log->verbose_prefix = "global";
502     } else {
503         log->prefix = talloc_strdup(log, parent->prefix);
504         log->verbose_prefix = talloc_strdup(log, parent->verbose_prefix);
505     }
506     return log;
507 }
508 
mp_msg_init(struct mpv_global * global)509 void mp_msg_init(struct mpv_global *global)
510 {
511     assert(!global->log);
512 
513     struct mp_log_root *root = talloc_zero(NULL, struct mp_log_root);
514     *root = (struct mp_log_root){
515         .global = global,
516         .reload_counter = ATOMIC_VAR_INIT(1),
517     };
518 
519     pthread_mutex_init(&root->lock, NULL);
520     pthread_mutex_init(&root->log_file_lock, NULL);
521     pthread_cond_init(&root->log_file_wakeup, NULL);
522 
523     struct mp_log dummy = { .root = root };
524     struct mp_log *log = mp_log_new(root, &dummy, "");
525 
526     global->log = log;
527 }
528 
log_file_thread(void * p)529 static void *log_file_thread(void *p)
530 {
531     struct mp_log_root *root = p;
532 
533     mpthread_set_name("log-file");
534 
535     pthread_mutex_lock(&root->log_file_lock);
536 
537     while (root->log_file_thread_active) {
538         struct mp_log_buffer_entry *e =
539             mp_msg_log_buffer_read(root->log_file_buffer);
540         if (e) {
541             pthread_mutex_unlock(&root->log_file_lock);
542             fprintf(root->log_file, "[%8.3f][%c][%s] %s",
543                     (mp_time_us() - MP_START_TIME) / 1e6,
544                     mp_log_levels[e->level][0], e->prefix, e->text);
545             fflush(root->log_file);
546             pthread_mutex_lock(&root->log_file_lock);
547             talloc_free(e);
548             // Multiple threads might be blocked if the log buffer was full.
549             pthread_cond_broadcast(&root->log_file_wakeup);
550         } else {
551             pthread_cond_wait(&root->log_file_wakeup, &root->log_file_lock);
552         }
553     }
554 
555     pthread_mutex_unlock(&root->log_file_lock);
556 
557     return NULL;
558 }
559 
wakeup_log_file(void * p)560 static void wakeup_log_file(void *p)
561 {
562     struct mp_log_root *root = p;
563 
564     pthread_mutex_lock(&root->log_file_lock);
565     pthread_cond_broadcast(&root->log_file_wakeup);
566     pthread_mutex_unlock(&root->log_file_lock);
567 }
568 
569 // Only to be called from the main thread.
terminate_log_file_thread(struct mp_log_root * root)570 static void terminate_log_file_thread(struct mp_log_root *root)
571 {
572     bool wait_terminate = false;
573 
574     pthread_mutex_lock(&root->log_file_lock);
575     if (root->log_file_thread_active) {
576         root->log_file_thread_active = false;
577         pthread_cond_broadcast(&root->log_file_wakeup);
578         wait_terminate = true;
579     }
580     pthread_mutex_unlock(&root->log_file_lock);
581 
582     if (wait_terminate)
583         pthread_join(root->log_file_thread, NULL);
584 
585     mp_msg_log_buffer_destroy(root->log_file_buffer);
586     root->log_file_buffer = NULL;
587 
588     if (root->log_file)
589         fclose(root->log_file);
590     root->log_file = NULL;
591 }
592 
593 // If opt is different from *current_path, update *current_path and return true.
594 // No lock must be held; passed values must be accessible without.
check_new_path(struct mpv_global * global,char * opt,char ** current_path)595 static bool check_new_path(struct mpv_global *global, char *opt,
596                            char **current_path)
597 {
598     void *tmp = talloc_new(NULL);
599     bool res = false;
600 
601     char *new_path = mp_get_user_path(tmp, global, opt);
602     if (!new_path)
603         new_path = "";
604 
605     char *old_path = *current_path ? *current_path : "";
606     if (strcmp(old_path, new_path) != 0) {
607         talloc_free(*current_path);
608         *current_path = NULL;
609         if (new_path && new_path[0])
610             *current_path = talloc_strdup(NULL, new_path);
611         res = true;
612     }
613 
614     talloc_free(tmp);
615 
616     return res;
617 }
618 
mp_msg_update_msglevels(struct mpv_global * global,struct MPOpts * opts)619 void mp_msg_update_msglevels(struct mpv_global *global, struct MPOpts *opts)
620 {
621     struct mp_log_root *root = global->log->root;
622 
623     pthread_mutex_lock(&root->lock);
624 
625     root->verbose = opts->verbose;
626     root->really_quiet = opts->msg_really_quiet;
627     root->module = opts->msg_module;
628     root->use_terminal = opts->use_terminal;
629     root->show_time = opts->msg_time;
630     if (root->use_terminal)
631         root->color = opts->msg_color && isatty(STDOUT_FILENO);
632 
633     m_option_type_msglevels.free(&root->msg_levels);
634     m_option_type_msglevels.copy(NULL, &root->msg_levels, &opts->msg_levels);
635 
636     atomic_fetch_add(&root->reload_counter, 1);
637     pthread_mutex_unlock(&root->lock);
638 
639     if (check_new_path(global, opts->log_file, &root->log_path)) {
640         terminate_log_file_thread(root);
641         if (root->log_path) {
642             root->log_file = fopen(root->log_path, "wb");
643             if (root->log_file) {
644                 root->log_file_buffer =
645                     mp_msg_log_buffer_new(global, 100, MP_LOG_BUFFER_MSGL_LOGFILE,
646                                           wakeup_log_file, root);
647                 root->log_file_thread_active = true;
648                 if (pthread_create(&root->log_file_thread, NULL, log_file_thread,
649                                    root))
650                 {
651                     root->log_file_thread_active = false;
652                     terminate_log_file_thread(root);
653                 }
654             } else {
655                 mp_err(global->log, "Failed to open log file '%s'\n",
656                        root->log_path);
657             }
658         }
659     }
660 
661     if (check_new_path(global, opts->dump_stats, &root->stats_path)) {
662         bool open_error = false;
663 
664         pthread_mutex_lock(&root->lock);
665         if (root->stats_file)
666             fclose(root->stats_file);
667         root->stats_file = NULL;
668         if (root->stats_path) {
669             root->stats_file = fopen(root->stats_path, "wb");
670             open_error = !root->stats_file;
671         }
672         pthread_mutex_unlock(&root->lock);
673 
674         if (open_error) {
675             mp_err(global->log, "Failed to open stats file '%s'\n",
676                    root->stats_path);
677         }
678     }
679 }
680 
mp_msg_force_stderr(struct mpv_global * global,bool force_stderr)681 void mp_msg_force_stderr(struct mpv_global *global, bool force_stderr)
682 {
683     struct mp_log_root *root = global->log->root;
684 
685     pthread_mutex_lock(&root->lock);
686     root->force_stderr = force_stderr;
687     pthread_mutex_unlock(&root->lock);
688 }
689 
690 // Only to be called from the main thread.
mp_msg_has_log_file(struct mpv_global * global)691 bool mp_msg_has_log_file(struct mpv_global *global)
692 {
693     struct mp_log_root *root = global->log->root;
694 
695     return !!root->log_file;
696 }
697 
mp_msg_uninit(struct mpv_global * global)698 void mp_msg_uninit(struct mpv_global *global)
699 {
700     struct mp_log_root *root = global->log->root;
701     terminate_log_file_thread(root);
702     mp_msg_log_buffer_destroy(root->early_buffer);
703     assert(root->num_buffers == 0);
704     if (root->stats_file)
705         fclose(root->stats_file);
706     talloc_free(root->stats_path);
707     talloc_free(root->log_path);
708     m_option_type_msglevels.free(&root->msg_levels);
709     pthread_mutex_destroy(&root->lock);
710     pthread_mutex_destroy(&root->log_file_lock);
711     pthread_cond_destroy(&root->log_file_wakeup);
712     talloc_free(root);
713     global->log = NULL;
714 }
715 
mp_msg_set_early_logging(struct mpv_global * global,bool enable)716 void mp_msg_set_early_logging(struct mpv_global *global, bool enable)
717 {
718     struct mp_log_root *root = global->log->root;
719     pthread_mutex_lock(&root->lock);
720 
721     if (enable != !!root->early_buffer) {
722         if (enable) {
723             pthread_mutex_unlock(&root->lock);
724             struct mp_log_buffer *buf =
725                 mp_msg_log_buffer_new(global, TERM_BUF, MP_LOG_BUFFER_MSGL_TERM,
726                                       NULL, NULL);
727             pthread_mutex_lock(&root->lock);
728             assert(!root->early_buffer); // no concurrent calls to this function
729             root->early_buffer = buf;
730         } else {
731             struct mp_log_buffer *buf = root->early_buffer;
732             root->early_buffer = NULL;
733             pthread_mutex_unlock(&root->lock);
734             mp_msg_log_buffer_destroy(buf);
735             return;
736         }
737     }
738 
739     pthread_mutex_unlock(&root->lock);
740 }
741 
mp_msg_log_buffer_new(struct mpv_global * global,int size,int level,void (* wakeup_cb)(void * ctx),void * wakeup_cb_ctx)742 struct mp_log_buffer *mp_msg_log_buffer_new(struct mpv_global *global,
743                                             int size, int level,
744                                             void (*wakeup_cb)(void *ctx),
745                                             void *wakeup_cb_ctx)
746 {
747     struct mp_log_root *root = global->log->root;
748 
749     pthread_mutex_lock(&root->lock);
750 
751     if (level == MP_LOG_BUFFER_MSGL_TERM) {
752         size = TERM_BUF;
753 
754         // The first thing which creates a terminal-level log buffer gets the
755         // early log buffer, if it exists. This is supposed to enable a script
756         // to grab log messages from before it was initialized. It's OK that
757         // this works only for 1 script and only once.
758         if (root->early_buffer) {
759             struct mp_log_buffer *buffer = root->early_buffer;
760             root->early_buffer = NULL;
761             buffer->wakeup_cb = wakeup_cb;
762             buffer->wakeup_cb_ctx = wakeup_cb_ctx;
763             pthread_mutex_unlock(&root->lock);
764             return buffer;
765         }
766     }
767 
768     assert(size > 0);
769 
770     struct mp_log_buffer *buffer = talloc_ptrtype(NULL, buffer);
771     *buffer = (struct mp_log_buffer) {
772         .root = root,
773         .level = level,
774         .entries = talloc_array(buffer, struct mp_log_buffer_entry *, size),
775         .capacity = size,
776         .wakeup_cb = wakeup_cb,
777         .wakeup_cb_ctx = wakeup_cb_ctx,
778     };
779 
780     pthread_mutex_init(&buffer->lock, NULL);
781 
782     MP_TARRAY_APPEND(root, root->buffers, root->num_buffers, buffer);
783 
784     atomic_fetch_add(&root->reload_counter, 1);
785     pthread_mutex_unlock(&root->lock);
786 
787     return buffer;
788 }
789 
mp_msg_log_buffer_set_silent(struct mp_log_buffer * buffer,bool silent)790 void mp_msg_log_buffer_set_silent(struct mp_log_buffer *buffer, bool silent)
791 {
792     pthread_mutex_lock(&buffer->lock);
793     buffer->silent = silent;
794     pthread_mutex_unlock(&buffer->lock);
795 }
796 
mp_msg_log_buffer_destroy(struct mp_log_buffer * buffer)797 void mp_msg_log_buffer_destroy(struct mp_log_buffer *buffer)
798 {
799     if (!buffer)
800         return;
801 
802     struct mp_log_root *root = buffer->root;
803 
804     pthread_mutex_lock(&root->lock);
805 
806     for (int n = 0; n < root->num_buffers; n++) {
807         if (root->buffers[n] == buffer) {
808             MP_TARRAY_REMOVE_AT(root->buffers, root->num_buffers, n);
809             goto found;
810         }
811     }
812 
813     abort();
814 
815 found:
816 
817     while (buffer->num_entries)
818         talloc_free(log_buffer_read(buffer));
819 
820     pthread_mutex_destroy(&buffer->lock);
821     talloc_free(buffer);
822 
823     atomic_fetch_add(&root->reload_counter, 1);
824     pthread_mutex_unlock(&root->lock);
825 }
826 
827 // Return a queued message, or if the buffer is empty, NULL.
828 // Thread-safety: one buffer can be read by a single thread only.
mp_msg_log_buffer_read(struct mp_log_buffer * buffer)829 struct mp_log_buffer_entry *mp_msg_log_buffer_read(struct mp_log_buffer *buffer)
830 {
831     struct mp_log_buffer_entry *res = NULL;
832 
833     pthread_mutex_lock(&buffer->lock);
834 
835     if (!buffer->silent && buffer->num_entries) {
836         if (buffer->dropped) {
837             res = talloc_ptrtype(NULL, res);
838             *res = (struct mp_log_buffer_entry) {
839                 .prefix = "overflow",
840                 .level = MSGL_FATAL,
841                 .text = talloc_asprintf(res,
842                     "log message buffer overflow: %"PRId64" messages skipped\n",
843                     buffer->dropped),
844             };
845             buffer->dropped = 0;
846         } else {
847             res = log_buffer_read(buffer);
848         }
849     }
850 
851     pthread_mutex_unlock(&buffer->lock);
852 
853     return res;
854 }
855 
856 // Thread-safety: fully thread-safe, but keep in mind that the lifetime of
857 //                log must be guaranteed during the call.
858 //                Never call this from signal handlers.
mp_msg(struct mp_log * log,int lev,const char * format,...)859 void mp_msg(struct mp_log *log, int lev, const char *format, ...)
860 {
861     va_list va;
862     va_start(va, format);
863     mp_msg_va(log, lev, format, va);
864     va_end(va);
865 }
866 
867 const char *const mp_log_levels[MSGL_MAX + 1] = {
868     [MSGL_FATAL]        = "fatal",
869     [MSGL_ERR]          = "error",
870     [MSGL_WARN]         = "warn",
871     [MSGL_INFO]         = "info",
872     [MSGL_STATUS]       = "status",
873     [MSGL_V]            = "v",
874     [MSGL_DEBUG]        = "debug",
875     [MSGL_TRACE]        = "trace",
876     [MSGL_STATS]        = "stats",
877 };
878 
879 const int mp_mpv_log_levels[MSGL_MAX + 1] = {
880     [MSGL_FATAL]        = MPV_LOG_LEVEL_FATAL,
881     [MSGL_ERR]          = MPV_LOG_LEVEL_ERROR,
882     [MSGL_WARN]         = MPV_LOG_LEVEL_WARN,
883     [MSGL_INFO]         = MPV_LOG_LEVEL_INFO,
884     [MSGL_STATUS]       = 0, // never used
885     [MSGL_V]            = MPV_LOG_LEVEL_V,
886     [MSGL_DEBUG]        = MPV_LOG_LEVEL_DEBUG,
887     [MSGL_TRACE]        = MPV_LOG_LEVEL_TRACE,
888     [MSGL_STATS]        = 0, // never used
889 };
890 
mp_msg_find_level(const char * s)891 int mp_msg_find_level(const char *s)
892 {
893     for (int n = 0; n < MP_ARRAY_SIZE(mp_log_levels); n++) {
894         if (mp_log_levels[n] && !strcmp(s, mp_log_levels[n]))
895             return n;
896     }
897     return -1;
898 }
899