1 /*
2 * Copyright (C) 2019-2021 Alexandros Theodotou <alex@zrythm.org>
3 *
4 * This file is part of Zrythm
5 *
6 * Zrythm is free software: you can redistribute it and/or modify
7 * it under the terms of the GNU Affero General Public License as published by
8 * the Free Software Foundation, either version 3 of the License, or
9 * (at your option) any later version.
10 *
11 * Zrythm is distributed in the hope that it will be useful,
12 * but WITHOUT ANY WARRANTY; without even the implied warranty of
13 * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the
14 * GNU Affero General Public License for more details.
15 *
16 * You should have received a copy of the GNU Affero General Public License
17 * along with Zrythm. If not, see <https://www.gnu.org/licenses/>.
18 *
19 * This file incorporates work covered by the following copyright and
20 * permission notice:
21 *
22 * GLIB - Library of useful routines for C programming
23 * Copyright (C) 1995-1997 Peter Mattis, Spencer Kimball and Josh MacDonald
24 *
25 * This library is free software; you can redistribute it and/or
26 * modify it under the terms of the GNU General Public
27 * License as published by the Free Software Foundation; either
28 * version 3 of the License, or (at your option) any later version.
29 *
30 * This library is distributed in the hope that it will be useful,
31 * but WITHOUT ANY WARRANTY; without even the implied warranty of
32 * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the GNU
33 * General Public License for more details.
34 *
35 * You should have received a copy of the GNU General Public
36 * License along with this library; if not, see <http://www.gnu.org/licenses/>.
37 */
38
39 /* for dprintf */
40 #define _GNU_SOURCE
41
42 #include "zrythm-config.h"
43
44 #include <stdio.h>
45
46 #ifdef _WOE32
47 #include <process.h>
48 #endif
49
50 #include "audio/engine.h"
51 #include "gui/backend/event.h"
52 #include "gui/backend/event_manager.h"
53 #include "gui/widgets/dialogs/bug_report_dialog.h"
54 #include "gui/widgets/header.h"
55 #include "gui/widgets/main_window.h"
56 #include "project.h"
57 #include "utils/backtrace.h"
58 #include "utils/datetime.h"
59 #include "utils/flags.h"
60 #include "utils/io.h"
61 #include "utils/log.h"
62 #include "utils/mpmc_queue.h"
63 #include "utils/object_pool.h"
64 #include "utils/objects.h"
65 #include "utils/string.h"
66 #include "zrythm.h"
67 #include "zrythm_app.h"
68
69 #include <glib.h>
70 #include <glib/gi18n.h>
71 #include <glib/gprintf.h>
72 #include <glib/gstdio.h>
73
74 #include <zstd.h>
75
76 typedef enum
77 {
78 Z_UTILS_LOG_ERROR_FAILED,
79 } ZUtilsLogError;
80
81 #define Z_UTILS_LOG_ERROR \
82 z_utils_log_error_quark ()
83 GQuark z_utils_log_error_quark (void);
84 G_DEFINE_QUARK (
85 z-utils-log-error-quark, z_utils_log_error)
86
87 /** This is declared extern in log.h. */
88 Log * zlog = NULL;
89
90 #define MESSAGES_MAX 160000
91
92 /* string size big enough to hold level prefix */
93 #define STRING_BUFFER_SIZE \
94 (FORMAT_UNSIGNED_BUFSIZE + 32)
95
96 #define ALERT_LEVELS (G_LOG_LEVEL_ERROR | G_LOG_LEVEL_CRITICAL | G_LOG_LEVEL_WARNING)
97
98 #define CHAR_IS_SAFE(wc) (!((wc < 0x20 && wc != '\t' && wc != '\n' && wc != '\r') || \
99 (wc == 0x7f) || \
100 (wc >= 0x80 && wc < 0xa0)))
101
102 /* For a radix of 8 we need at most 3 output bytes for 1 input
103 * byte. Additionally we might need up to 2 output bytes for the
104 * readix prefix and 1 byte for the trailing NULL.
105 */
106 #define FORMAT_UNSIGNED_BUFSIZE ((GLIB_SIZEOF_LONG * 3) + 3)
107
108 /* these are emitted by the default log handler */
109 #define DEFAULT_LEVELS (G_LOG_LEVEL_ERROR | G_LOG_LEVEL_CRITICAL | G_LOG_LEVEL_WARNING | G_LOG_LEVEL_MESSAGE)
110 /* these are filtered by G_MESSAGES_DEBUG by the default log handler */
111 #define INFO_LEVELS (G_LOG_LEVEL_INFO | G_LOG_LEVEL_DEBUG)
112
113 static GLogLevelFlags g_log_msg_prefix = G_LOG_LEVEL_ERROR | G_LOG_LEVEL_WARNING | G_LOG_LEVEL_CRITICAL | G_LOG_LEVEL_DEBUG;
114
115 #ifdef _WOE32
116 static gboolean win32_keep_fatal_message = FALSE;
117 static gchar fatal_msg_buf[1000] = "Unspecified fatal error encountered, aborting.";
118 #endif
119
120 static GLogLevelFlags log_always_fatal = G_LOG_FATAL_MASK;
121
122 static char * tmp_log_file = NULL;
123
124 typedef struct LogEvent
125 {
126 char * message;
127
128 /** Backtrace, if warning or critical. */
129 char * backtrace;
130 GLogLevelFlags log_level;
131 } LogEvent;
132
133 #if !defined (GLIB_SUBPROJECT) && \
134 !defined (HAVE_G_GET_CONSOLE_CHARSET)
135 static gboolean
g_get_console_charset(const char ** charset)136 g_get_console_charset (const char ** charset)
137 {
138 return g_get_charset (charset);
139 }
140 #endif
141
142 static void
_log_abort(gboolean breakpoint)143 _log_abort (gboolean breakpoint)
144 {
145 gboolean debugger_present;
146
147 if (g_test_subprocess ())
148 {
149 /* If this is a test case subprocess then it probably caused
150 * this error message on purpose, so just exit() rather than
151 * abort()ing, to avoid triggering any system crash-reporting
152 * daemon.
153 */
154 _exit (1);
155 }
156
157 #ifdef G_OS_WIN32
158 debugger_present = IsDebuggerPresent ();
159 #else
160 /* Assume GDB is attached. */
161 debugger_present = TRUE;
162 #endif /* !G_OS_WIN32 */
163
164 /*g_warn_if_reached ();*/
165
166 if (debugger_present && breakpoint)
167 G_BREAKPOINT ();
168 else
169 g_abort ();
170 }
171
172 /**
173 * @note from GLib.
174 */
175 static void
escape_string(GString * string)176 escape_string (GString *string)
177 {
178 const char *p = string->str;
179 gunichar wc;
180
181 while (p < string->str + string->len)
182 {
183 gboolean safe;
184
185 wc = g_utf8_get_char_validated (p, -1);
186 if (wc == (gunichar)-1 || wc == (gunichar)-2)
187 {
188 gchar *tmp;
189 guint pos;
190
191 pos = p - string->str;
192
193 /* Emit invalid UTF-8 as hex escapes
194 */
195 tmp = g_strdup_printf ("\\x%02x", (guint)(guchar)*p);
196 g_string_erase (string, pos, 1);
197 g_string_insert (string, pos, tmp);
198
199 p = string->str + (pos + 4); /* Skip over escape sequence */
200
201 g_free (tmp);
202 continue;
203 }
204 if (wc == '\r')
205 {
206 safe = *(p + 1) == '\n';
207 }
208 else
209 {
210 safe = CHAR_IS_SAFE (wc);
211 }
212
213 if (!safe)
214 {
215 gchar *tmp;
216 guint pos;
217
218 pos = p - string->str;
219
220 /* Largest char we escape is 0x0a, so we don't have to worry
221 * about 8-digit \Uxxxxyyyy
222 */
223 tmp = g_strdup_printf ("\\u%04x", wc);
224 g_string_erase (string, pos, g_utf8_next_char (p) - p);
225 g_string_insert (string, pos, tmp);
226 g_free (tmp);
227
228 p = string->str + (pos + 6); /* Skip over escape sequence */
229 }
230 else
231 p = g_utf8_next_char (p);
232 }
233 }
234
235 /**
236 * @note from GLib.
237 */
238 static void
format_unsigned(gchar * buf,gulong num,guint radix)239 format_unsigned (gchar *buf,
240 gulong num,
241 guint radix)
242 {
243 gulong tmp;
244 gchar c;
245 gint i, n;
246
247 /* we may not call _any_ GLib functions here (or macros like g_return_if_fail()) */
248
249 if (radix != 8 && radix != 10 && radix != 16)
250 {
251 *buf = '\000';
252 return;
253 }
254
255 if (!num)
256 {
257 *buf++ = '0';
258 *buf = '\000';
259 return;
260 }
261
262 if (radix == 16)
263 {
264 *buf++ = '0';
265 *buf++ = 'x';
266 }
267 else if (radix == 8)
268 {
269 *buf++ = '0';
270 }
271
272 n = 0;
273 tmp = num;
274 while (tmp)
275 {
276 tmp /= radix;
277 n++;
278 }
279
280 i = n;
281
282 /* Again we can't use g_assert; actually this check should _never_ fail. */
283 if (n > FORMAT_UNSIGNED_BUFSIZE - 3)
284 {
285 *buf = '\000';
286 return;
287 }
288
289 while (num)
290 {
291 i--;
292 c = (num % radix);
293 if (c < 10)
294 buf[i] = c + '0';
295 else
296 buf[i] = c + 'a' - 10;
297 num /= radix;
298 }
299
300 buf[n] = '\000';
301 }
302
303 /**
304 * @note from GLib.
305 */
306 static FILE *
log_level_to_file(GLogLevelFlags log_level)307 log_level_to_file (GLogLevelFlags log_level)
308 {
309 if (log_level & (G_LOG_LEVEL_ERROR | G_LOG_LEVEL_CRITICAL |
310 G_LOG_LEVEL_WARNING | G_LOG_LEVEL_MESSAGE))
311 return stderr;
312 else
313 return stdout;
314 }
315
316 /**
317 * @note from GLib.
318 */
319 static const gchar *
log_level_to_color(GLogLevelFlags log_level,gboolean use_color)320 log_level_to_color (GLogLevelFlags log_level,
321 gboolean use_color)
322 {
323 /* we may not call _any_ GLib functions here */
324
325 if (!use_color)
326 return "";
327
328 if (log_level & G_LOG_LEVEL_ERROR)
329 return "\033[1;31m"; /* red */
330 else if (log_level & G_LOG_LEVEL_CRITICAL)
331 return "\033[1;35m"; /* magenta */
332 else if (log_level & G_LOG_LEVEL_WARNING)
333 return "\033[1;33m"; /* yellow */
334 else if (log_level & G_LOG_LEVEL_MESSAGE)
335 return "\033[1;32m"; /* green */
336 else if (log_level & G_LOG_LEVEL_INFO)
337 return "\033[1;32m"; /* green */
338 else if (log_level & G_LOG_LEVEL_DEBUG)
339 return "\033[1;32m"; /* green */
340
341 /* No color for custom log levels. */
342 return "";
343 }
344
345 /**
346 * @note from GLib.
347 */
348 static const gchar *
color_reset(gboolean use_color)349 color_reset (gboolean use_color)
350 {
351 /* we may not call _any_ GLib functions here */
352
353 if (!use_color)
354 return "";
355
356 return "\033[0m";
357 }
358
359 /**
360 * @note from GLib.
361 */
362 static FILE *
mklevel_prefix(gchar level_prefix[STRING_BUFFER_SIZE],GLogLevelFlags log_level,gboolean use_color)363 mklevel_prefix (
364 gchar level_prefix[STRING_BUFFER_SIZE],
365 GLogLevelFlags log_level,
366 gboolean use_color)
367 {
368 gboolean to_stdout = TRUE;
369
370 strcpy (
371 level_prefix,
372 log_level_to_color (log_level, use_color));
373
374 switch (log_level & G_LOG_LEVEL_MASK)
375 {
376 case G_LOG_LEVEL_ERROR:
377 strcat (level_prefix, "ERROR");
378 to_stdout = FALSE;
379 break;
380 case G_LOG_LEVEL_CRITICAL:
381 strcat (level_prefix, "CRITICAL");
382 to_stdout = FALSE;
383 break;
384 case G_LOG_LEVEL_WARNING:
385 strcat (level_prefix, "WARNING");
386 to_stdout = FALSE;
387 break;
388 case G_LOG_LEVEL_MESSAGE:
389 strcat (level_prefix, "Message");
390 to_stdout = FALSE;
391 break;
392 case G_LOG_LEVEL_INFO:
393 strcat (level_prefix, "INFO");
394 break;
395 case G_LOG_LEVEL_DEBUG:
396 strcat (level_prefix, "DEBUG");
397 break;
398 default:
399 if (log_level)
400 {
401 strcat (level_prefix, "LOG-");
402 format_unsigned (
403 level_prefix + 4,
404 (gulong) (log_level & G_LOG_LEVEL_MASK), 16);
405 }
406 else
407 strcat (level_prefix, "LOG");
408 break;
409 }
410
411 strcat (level_prefix, color_reset (use_color));
412
413 if (log_level & G_LOG_FLAG_RECURSION)
414 strcat (level_prefix, " (recursed)");
415 if (log_level & ALERT_LEVELS)
416 strcat (level_prefix, " **");
417
418 #ifdef G_OS_WIN32
419 if ((log_level & G_LOG_FLAG_FATAL) != 0 && !g_test_initialized ())
420 win32_keep_fatal_message = TRUE;
421 #endif
422 return to_stdout ? stdout : stderr;
423 }
424
425 /**
426 * @note from GLib.
427 */
428 static gchar*
strdup_convert(const gchar * string,const gchar * charset)429 strdup_convert (const gchar *string,
430 const gchar *charset)
431 {
432 if (!g_utf8_validate (string, -1, NULL))
433 {
434 GString *gstring = g_string_new ("[Invalid UTF-8] ");
435 guchar *p;
436
437 for (p = (guchar *)string; *p; p++)
438 {
439 if (CHAR_IS_SAFE(*p) &&
440 !(*p == '\r' && *(p + 1) != '\n') &&
441 *p < 0x80)
442 g_string_append_c (gstring, (char) *p);
443 else
444 g_string_append_printf (gstring, "\\x%02x", (guint)(guchar)*p);
445 }
446
447 return g_string_free (gstring, FALSE);
448 }
449 else
450 {
451 GError *err = NULL;
452
453 gchar *result = g_convert_with_fallback (string, -1, charset, "UTF-8", "?", NULL, NULL, &err);
454 if (result)
455 return result;
456 else
457 {
458 /* Not thread-safe, but doesn't matter if we print the warning twice
459 */
460 static gboolean warned = FALSE;
461 if (!warned)
462 {
463 warned = TRUE;
464 g_fprintf (stderr, "GLib: Cannot convert message: %s\n", err->message);
465 }
466 g_error_free (err);
467
468 return g_strdup (string);
469 }
470 }
471 }
472
473 /**
474 * @note from GLib.
475 */
476 static gchar *
log_writer_format_fields(GLogLevelFlags log_level,const GLogField * fields,gsize n_fields,gboolean use_color)477 log_writer_format_fields (
478 GLogLevelFlags log_level,
479 const GLogField *fields,
480 gsize n_fields,
481 gboolean use_color)
482 {
483 gsize i;
484 const gchar *message = NULL;
485 const gchar *log_domain = NULL;
486 const gchar *line = NULL;
487 const gchar *func = NULL;
488 /*const gchar *file = NULL;*/
489 gchar level_prefix[STRING_BUFFER_SIZE];
490 GString *gstring;
491 gint64 now;
492 time_t now_secs;
493 struct tm *now_tm;
494 gchar time_buf[128];
495
496 /* Extract some common fields. */
497 for (i = 0; (message == NULL || log_domain == NULL) && i < n_fields; i++)
498 {
499 const GLogField *field = &fields[i];
500
501 if (g_strcmp0 (field->key, "MESSAGE") == 0)
502 message = field->value;
503 else if (g_strcmp0 (field->key, "GLIB_DOMAIN") == 0)
504 log_domain = field->value;
505 /*else if (g_strcmp0 (field->key, "CODE_FILE") == 0)*/
506 /*file = field->value;*/
507 else if (g_strcmp0 (field->key, "CODE_FUNC") == 0)
508 func = field->value;
509 else if (g_strcmp0 (field->key, "CODE_LINE") == 0)
510 line = field->value;
511 }
512
513 /* Format things. */
514 mklevel_prefix (level_prefix, log_level, use_color);
515
516 gstring = g_string_new (NULL);
517 if (log_level & ALERT_LEVELS)
518 g_string_append (gstring, "\n");
519 if (!log_domain)
520 g_string_append (gstring, "** ");
521
522 if ((g_log_msg_prefix & (log_level & G_LOG_LEVEL_MASK)) ==
523 (log_level & G_LOG_LEVEL_MASK))
524 {
525 const gchar *prg_name = g_get_prgname ();
526 #ifdef _WOE32
527 gulong pid = (gulong) _getpid ();
528 #else
529 gulong pid = (gulong) getpid ();
530 #endif
531
532 if (prg_name == NULL)
533 g_string_append_printf (gstring, "(process:%lu): ", pid);
534 else
535 g_string_append_printf (gstring, "(%s:%lu): ", prg_name, pid);
536 }
537
538 if (log_domain != NULL)
539 {
540 g_string_append (gstring, log_domain);
541 g_string_append_c (gstring, '-');
542 }
543 g_string_append (gstring, level_prefix);
544
545 g_string_append (gstring, ": ");
546
547 /* Timestamp */
548 now = g_get_real_time ();
549 now_secs = (time_t) (now / 1000000);
550 now_tm = localtime (&now_secs);
551 strftime (time_buf, sizeof (time_buf), "%H:%M:%S", now_tm);
552
553 g_string_append_printf (gstring, "%s%s.%03d%s: ",
554 use_color ? "\033[34m" : "",
555 time_buf, (gint) ((now / 1000) % 1000),
556 color_reset (use_color));
557
558 /* EDIT: append file, func and line */
559 g_string_append_printf (
560 gstring, "%s(%s:%s)%s: ",
561 use_color ? "\033[90m" : "",
562 func, line,
563 color_reset (use_color));
564
565 if (message == NULL)
566 {
567 g_string_append (gstring, "(NULL) message");
568 }
569 else
570 {
571 GString *msg;
572 const gchar *charset;
573
574 msg = g_string_new (message);
575 escape_string (msg);
576
577 if (g_get_console_charset (&charset))
578 {
579 /* charset is UTF-8 already */
580 g_string_append (gstring, msg->str);
581 }
582 else
583 {
584 gchar *lstring = strdup_convert (msg->str, charset);
585 g_string_append (gstring, lstring);
586 g_free (lstring);
587 }
588
589 g_string_free (msg, TRUE);
590 }
591
592 return g_string_free (gstring, FALSE);
593 }
594
595 /**
596 * @note from GLib.
597 */
598 static GLogWriterOutput
log_writer_standard_streams(GLogLevelFlags log_level,const GLogField * fields,gsize n_fields,gpointer user_data)599 log_writer_standard_streams (
600 GLogLevelFlags log_level,
601 const GLogField *fields,
602 gsize n_fields,
603 gpointer user_data)
604 {
605 FILE *stream;
606 gchar *out = NULL; /* in the current locale’s character set */
607
608 g_return_val_if_fail (fields != NULL, G_LOG_WRITER_UNHANDLED);
609 g_return_val_if_fail (n_fields > 0, G_LOG_WRITER_UNHANDLED);
610
611 stream = log_level_to_file (log_level);
612 if (!stream || fileno (stream) < 0)
613 return G_LOG_WRITER_UNHANDLED;
614
615 out = log_writer_format_fields (log_level, fields, n_fields,
616 g_log_writer_supports_color (fileno (stream)));
617 g_fprintf (stream, "%s\n", out);
618 fflush (stream);
619 g_free (out);
620
621 return G_LOG_WRITER_HANDLED;
622 }
623
624 static bool
need_backtrace(const LogEvent * const ev)625 need_backtrace (
626 const LogEvent * const ev)
627 {
628 return
629 (ev->log_level == G_LOG_LEVEL_CRITICAL
630 || ev->log_level == G_LOG_LEVEL_WARNING)
631 &&
632 !string_contains_substr (
633 ev->message,
634 "assertion 'size >= 0' failed in "
635 "GtkScrollbar")
636 &&
637 !string_contains_substr (
638 ev->message,
639 "assertion 'size >= 0' failed in "
640 "GtkNotebook")
641 &&
642 !string_contains_substr (
643 ev->message,
644 "gtk_window_set_titlebar() called on a "
645 "realized window")
646 &&
647 !string_contains_substr (
648 ev->message, "attempt to allocate widget")
649 &&
650 !string_contains_substr (
651 ev->message,
652 "you are running a non-free operating system");
653 }
654
655 /**
656 * Write a log message to the log file and to each
657 * buffer.
658 */
659 static int
write_str(Log * self,GLogLevelFlags log_level,char * str)660 write_str (
661 Log * self,
662 GLogLevelFlags log_level,
663 char * str)
664 {
665 /* write to file */
666 if (self->logfile)
667 {
668 g_fprintf (
669 self->logfile, "%s\n", str);
670 fflush (self->logfile);
671 }
672 #if 0
673 else if (self->logfd > -1)
674 {
675 #ifdef __linux__
676 dprintf (
677 self->logfd, "%s\n", str);
678 #endif
679
680 #ifdef _WOE32
681 FlushFileBuffers (
682 (HANDLE) self->logfd);
683 #else
684 fsync (self->logfd);
685 #endif
686 }
687 #endif
688
689 #if 0
690 /* write to each buffer */
691 GtkTextIter iter;
692 gtk_text_buffer_get_end_iter (
693 self->messages_buf, &iter);
694 if (g_utf8_validate (str, -1, NULL))
695 {
696 gtk_text_buffer_insert (
697 self->messages_buf, &iter, str, -1);
698 }
699 else
700 {
701 g_message (
702 "Attempted to add a non-UTF8 string to "
703 "the log file: %s", str);
704 gtk_text_buffer_insert (
705 self->messages_buf, &iter,
706 "Non-UTF8 string!", -1);
707 }
708 gtk_text_buffer_get_end_iter (
709 self->messages_buf, &iter);
710 gtk_text_buffer_insert (
711 self->messages_buf, &iter, "\n", -1);
712 #endif
713
714 return 0;
715 }
716
717 /**
718 * Idle callback.
719 */
720 int
log_idle_cb(Log * self)721 log_idle_cb (
722 Log * self)
723 {
724 if (!self->mqueue)
725 return G_SOURCE_CONTINUE;
726
727 /* write queued messages */
728 LogEvent * ev;
729 while (
730 mpmc_queue_dequeue (
731 self->mqueue, (void *) &ev))
732 {
733 write_str (self, ev->log_level, ev->message);
734
735 if (ev->backtrace)
736 {
737 if (!ZRYTHM || ZRYTHM_TESTING)
738 {
739 g_message (
740 "Backtrace: %s", ev->backtrace);
741 }
742
743 gint64 time_now =
744 g_get_monotonic_time ();
745 if (ev->log_level ==
746 G_LOG_LEVEL_CRITICAL
747 && ZRYTHM_HAVE_UI
748 &&
749 (time_now - self->last_popup_time) >
750 8000000
751 )
752 {
753 self->last_popup_time = time_now;
754
755 char msg[500];
756 sprintf (
757 msg,
758 _("%s has encountered a "
759 "non-fatal error. It may "
760 "continue to run but "
761 "behavior will be undefined. "),
762 PROGRAM_NAME);
763 BugReportDialogWidget * dialog =
764 bug_report_dialog_new (
765 MAIN_WINDOW ?
766 GTK_WINDOW (MAIN_WINDOW) : NULL,
767 msg, ev->backtrace,
768 false);
769 gtk_dialog_run (GTK_DIALOG (dialog));
770 gtk_widget_destroy (
771 GTK_WIDGET (dialog));
772 }
773
774 /* write the backtrace to the log after
775 * showing the popup (if any) */
776 if (self->logfile)
777 {
778 g_fprintf (
779 self->logfile, "%s\n",
780 ev->backtrace);
781 fflush (self->logfile);
782 }
783 }
784
785 if (ev->log_level ==
786 G_LOG_LEVEL_WARNING &&
787 ZRYTHM_HAVE_UI &&
788 MAIN_WINDOW && MW_HEADER)
789 {
790 MW_HEADER->log_has_pending_warnings =
791 true;
792 EVENTS_PUSH (
793 ET_LOG_WARNING_STATE_CHANGED, NULL);
794 }
795
796 g_free_and_null (ev->backtrace);
797 g_free_and_null (ev->message);
798 object_pool_return (
799 LOG->obj_pool, ev);
800 }
801
802 return G_SOURCE_CONTINUE;
803 }
804
805 static gboolean
log_is_old_api(const GLogField * fields,gsize n_fields)806 log_is_old_api (const GLogField *fields,
807 gsize n_fields)
808 {
809 return (n_fields >= 1 &&
810 g_strcmp0 (fields[0].key, "GLIB_OLD_LOG_API") == 0 &&
811 g_strcmp0 (fields[0].value, "1") == 0);
812 }
813
814 static GLogWriterOutput
log_writer_default_custom(GLogLevelFlags log_level,const GLogField * fields,gsize n_fields,gpointer user_data)815 log_writer_default_custom (
816 GLogLevelFlags log_level,
817 const GLogField *fields,
818 gsize n_fields,
819 gpointer user_data)
820 {
821 Log * self = (Log *) user_data;
822
823 static gsize initialized = 0;
824 static gboolean stderr_is_journal = FALSE;
825
826 g_return_val_if_fail (fields != NULL, G_LOG_WRITER_UNHANDLED);
827 g_return_val_if_fail (n_fields > 0, G_LOG_WRITER_UNHANDLED);
828
829 /* Disable debug message output unless specified in G_MESSAGES_DEBUG. */
830 if (!(log_level & DEFAULT_LEVELS) &&
831 !(log_level >> G_LOG_LEVEL_USER_SHIFT))
832 {
833 const gchar * log_domain = NULL;
834 gsize i;
835
836 if ((log_level & INFO_LEVELS) == 0 ||
837 self->log_domains == NULL)
838 return G_LOG_WRITER_HANDLED;
839
840 for (i = 0; i < n_fields; i++)
841 {
842 if (g_strcmp0 (fields[i].key, "GLIB_DOMAIN") == 0)
843 {
844 log_domain = fields[i].value;
845 break;
846 }
847 }
848
849 if (strcmp (self->log_domains, "all") != 0 &&
850 (log_domain == NULL ||
851 !strstr (self->log_domains, log_domain)))
852 return G_LOG_WRITER_HANDLED;
853 }
854
855 /* Mark messages as fatal if they have a level set in
856 * g_log_set_always_fatal().
857 */
858 if ((log_level & log_always_fatal) && !log_is_old_api (fields, n_fields))
859 log_level |= G_LOG_FLAG_FATAL;
860
861 /* Try logging to the systemd journal as first choice. */
862 if (g_once_init_enter (&initialized))
863 {
864 stderr_is_journal = g_log_writer_is_journald (fileno (stderr));
865 g_once_init_leave (&initialized, TRUE);
866 }
867
868 if (stderr_is_journal &&
869 g_log_writer_journald (log_level, fields, n_fields, user_data) ==
870 G_LOG_WRITER_HANDLED)
871 goto handled;
872
873 /* FIXME: Add support for the Windows log. */
874
875 if (log_writer_standard_streams (
876 log_level, fields, n_fields, user_data) ==
877 G_LOG_WRITER_HANDLED)
878 goto handled;
879
880 return G_LOG_WRITER_UNHANDLED;
881
882 handled:
883 /* Abort if the message was fatal. */
884 if (log_level & G_LOG_FLAG_FATAL)
885 {
886 #ifdef G_OS_WIN32
887 if (!g_test_initialized ())
888 {
889 gchar *locale_msg = NULL;
890
891 locale_msg = g_locale_from_utf8 (fatal_msg_buf, -1, NULL, NULL, NULL);
892 MessageBox (NULL, locale_msg, NULL,
893 MB_ICONERROR | MB_SETFOREGROUND);
894 g_free (locale_msg);
895 }
896 #endif /* !G_OS_WIN32 */
897
898 _log_abort (!(log_level & G_LOG_FLAG_RECURSION));
899 }
900
901 return G_LOG_WRITER_HANDLED;
902 }
903
904 /**
905 * Log writer.
906 *
907 * If a message is logged from the GTK thread,
908 * the message is written immediately, otherwise it
909 * is saved to the queue.
910 *
911 * The queue is only popped when there is a new
912 * message in the GTK thread, so the messages will
913 * stay in the queue until then.
914 */
915 static GLogWriterOutput
log_writer(GLogLevelFlags log_level,const GLogField * fields,gsize n_fields,Log * self)916 log_writer (
917 GLogLevelFlags log_level,
918 const GLogField *fields,
919 gsize n_fields,
920 Log * self)
921 {
922 char * str =
923 log_writer_format_fields (
924 log_level, fields, n_fields, F_NO_USE_COLOR);
925
926 if (self->initialized)
927 {
928 /* queue the message */
929 LogEvent * ev =
930 (LogEvent *)
931 object_pool_get (self->obj_pool);
932 ev->log_level = log_level;
933 ev->message = str;
934
935 if (need_backtrace (ev))
936 {
937 ev->backtrace =
938 backtrace_get_with_lines (
939 "", 100, true);
940 }
941
942 int num_avail_objs =
943 object_pool_get_num_available (
944 self->obj_pool);
945 if (num_avail_objs < 200)
946 {
947 log_idle_cb (self);
948 }
949
950 mpmc_queue_push_back (
951 self->mqueue, (void *) ev);
952 }
953 else
954 {
955 #ifdef _WOE32
956 /* log file not ready yet, log to console */
957 fprintf (stderr, "%s\n", str);
958 #endif
959
960 /* also log to /tmp */
961 if (!tmp_log_file)
962 {
963 char * datetime =
964 datetime_get_for_filename ();
965 char * filename =
966 g_strdup_printf (
967 "zrythm_%s.log", datetime);
968 const char * tmpdir = g_get_tmp_dir ();
969 tmp_log_file =
970 g_build_filename (
971 tmpdir, filename, NULL);
972 g_free (filename);
973 g_free (datetime);
974 }
975 FILE * file = fopen (tmp_log_file, "a");
976 fprintf (file, "%s\n", str);
977 fclose (file);
978 }
979
980 /*(void) log_writer_standard_streams;*/
981
982 /* call the default log writer */
983 if (ZRYTHM && ZRYTHM_TESTING)
984 {
985 if (self->use_structured_for_console)
986 {
987 /* this is because the following doesn't
988 * send a trap when executed from non-gtk
989 * threads during testing */
990 return
991 g_log_writer_default (
992 log_level, fields, n_fields, self);
993 }
994 else
995 {
996 if (log_level <=
997 self->min_log_level_for_test_console)
998 {
999 g_log (
1000 G_LOG_DOMAIN, log_level,
1001 "%s", str);
1002 }
1003 return 0;
1004 }
1005 }
1006 else
1007 {
1008 return
1009 log_writer_default_custom (
1010 log_level, fields, n_fields, self);
1011 /*log_writer_standard_streams (*/
1012 /*log_level, fields, n_fields, self);*/
1013 }
1014 }
1015
1016 /**
1017 * Initializes logging to a file.
1018 *
1019 * This must be called from the GTK thread.
1020 *
1021 * @param secs Number of timeout seconds.
1022 */
1023 void
log_init_writer_idle(Log * self,unsigned int secs)1024 log_init_writer_idle (
1025 Log * self,
1026 unsigned int secs)
1027 {
1028 self->writer_source_id =
1029 g_timeout_add_seconds (
1030 secs, (GSourceFunc) log_idle_cb, self);
1031 }
1032
1033 static void *
create_log_event_obj(void)1034 create_log_event_obj (void)
1035 {
1036 return calloc (1, sizeof (LogEvent));
1037 }
1038
1039 static void
free_log_event_obj(LogEvent * ev)1040 free_log_event_obj (
1041 LogEvent * ev)
1042 {
1043 g_free_and_null (ev->message);
1044
1045 object_zero_and_free (ev);
1046 }
1047
1048 #define LINE_SIZE 800
1049 typedef struct Line
1050 {
1051 char line[LINE_SIZE]; // content
1052 size_t storage_sz; // allocation size of line memory
1053 size_t sz; // size of line, not including terminating null byte ('\0')
1054 } Line;
1055
1056 /**
1057 * Returns the last \ref n lines as a newly
1058 * allocated string.
1059 *
1060 * @note This must only be called from the GTK
1061 * thread.
1062 *
1063 * @param n Number of lines.
1064 */
1065 char *
log_get_last_n_lines(Log * self,int n)1066 log_get_last_n_lines (
1067 Log * self,
1068 int n)
1069 {
1070 g_return_val_if_fail (self->log_filepath, NULL);
1071
1072 /* call idle_cb to write queued messages */
1073 log_idle_cb (self);
1074
1075 FILE * fp = fopen (self->log_filepath, "r");
1076
1077 /* the following algorithm is from
1078 * https://stackoverflow.com/questions/54834969/print-last-few-lines-of-a-text-file
1079 * licensed under CC-BY-SA 4.0
1080 * authored by Bo R and edited
1081 * by Alexandros Theodotou */
1082
1083 /* keep an extra slot for the last failed
1084 * read at EOF */
1085 Line * lines =
1086 g_malloc0_n ((size_t) n + 1, sizeof (Line));
1087 int end = 0;
1088 int size = 0;
1089
1090 /* only keep track of the last couple of
1091 * lines */
1092 while (fgets (
1093 &lines[end].line[0],
1094 LINE_SIZE,
1095 fp))
1096 {
1097 lines[end].line[LINE_SIZE - 1] = '\0';
1098 lines[end].sz = strlen (lines[end].line);
1099 end++;
1100 if (end > n)
1101 {
1102 end = 0;
1103 }
1104 if (size < n)
1105 {
1106 size++;
1107 }
1108 }
1109
1110 // time to print them back
1111 int first = end - size;
1112 if (first < 0) {
1113 first += size + 1;
1114 }
1115 GString * str = g_string_new (NULL);
1116 for (int count = size; count; count--)
1117 {
1118 g_string_append (str, lines[first].line);
1119 first++;
1120 if (first > size)
1121 {
1122 first = 0;
1123 }
1124 }
1125
1126 /* clear up memory after use */
1127 free (lines);
1128
1129 fclose (fp);
1130
1131 return g_string_free (str, false);
1132 }
1133
1134 /**
1135 * Initializes logging to a file.
1136 *
1137 * This can be called from any thread.
1138 *
1139 * @param filepath If non-NULL, the given file
1140 * will be used, otherwise the default file
1141 * will be created.
1142 */
1143 void
log_init_with_file(Log * self,const char * filepath)1144 log_init_with_file (
1145 Log * self,
1146 const char * filepath)
1147 {
1148 /* open file to write to */
1149 if (filepath)
1150 {
1151 self->log_filepath = g_strdup (filepath);
1152 self->logfile =
1153 fopen (self->log_filepath, "a");
1154 g_return_if_fail (self->logfile);
1155 }
1156 else
1157 {
1158 char * str_datetime =
1159 datetime_get_for_filename ();
1160 char * user_log_dir =
1161 zrythm_get_dir (ZRYTHM_DIR_USER_LOG);
1162 self->log_filepath =
1163 g_strdup_printf (
1164 "%s%slog_%s.log",
1165 user_log_dir,
1166 G_DIR_SEPARATOR_S,
1167 str_datetime);
1168 io_mkdir (user_log_dir);
1169 self->logfile =
1170 fopen (self->log_filepath, "a");
1171 g_free (user_log_dir);
1172 g_free (str_datetime);
1173 g_return_if_fail (self->logfile);
1174 }
1175
1176 /* init buffers */
1177 /*self->messages_buf = gtk_text_buffer_new (NULL);*/
1178
1179 /* init the object pool for log events */
1180 self->obj_pool =
1181 object_pool_new (
1182 create_log_event_obj,
1183 (ObjectFreeFunc) free_log_event_obj,
1184 MESSAGES_MAX);
1185
1186 /* init the message queue */
1187 self->mqueue = mpmc_queue_new ();
1188 mpmc_queue_reserve (
1189 self->mqueue,
1190 (size_t) MESSAGES_MAX * sizeof (char *));
1191
1192 self->initialized = true;
1193 }
1194
1195 static guint
g_parse_debug_envvar(const gchar * envvar,const GDebugKey * keys,gint n_keys,guint default_value)1196 g_parse_debug_envvar (const gchar *envvar,
1197 const GDebugKey *keys,
1198 gint n_keys,
1199 guint default_value)
1200 {
1201 const gchar *value;
1202
1203 #ifdef OS_WIN32
1204 /* "fatal-warnings,fatal-criticals,all,help" is pretty short */
1205 gchar buffer[100];
1206
1207 if (GetEnvironmentVariable (envvar, buffer, 100) < 100)
1208 value = buffer;
1209 else
1210 return 0;
1211 #else
1212 value = getenv (envvar);
1213 #endif
1214
1215 if (value == NULL)
1216 return default_value;
1217
1218 return
1219 g_parse_debug_string (
1220 value, keys, (guint) n_keys);
1221 }
1222
1223 /**
1224 * Generates a compressed log file (for sending with
1225 * bug reports).
1226 *
1227 * @return Whether successful.
1228 */
1229 bool
log_generate_compressed_file(Log * self,char ** ret_dir,char ** ret_path,GError ** error)1230 log_generate_compressed_file (
1231 Log * self,
1232 char ** ret_dir,
1233 char ** ret_path,
1234 GError ** error)
1235 {
1236 g_return_val_if_fail (
1237 *ret_dir == NULL && *ret_path == NULL, false);
1238
1239 GError * err = NULL;
1240 char * log_file_tmpdir =
1241 g_dir_make_tmp (
1242 "zrythm-log-file-XXXXXX", &err);
1243 if (!log_file_tmpdir)
1244 {
1245 g_set_error_literal (
1246 error, Z_UTILS_LOG_ERROR,
1247 Z_UTILS_LOG_ERROR_FAILED,
1248 "Failed to create temporary dir");
1249 return false;
1250 }
1251
1252 /* get zstd-compressed text */
1253 char * log_txt =
1254 log_get_last_n_lines (LOG, 40000);
1255 size_t log_txt_sz = strlen (log_txt);
1256 size_t compress_bound =
1257 ZSTD_compressBound (log_txt_sz);
1258 char * dest = malloc (compress_bound);
1259 size_t dest_size =
1260 ZSTD_compress (
1261 dest, compress_bound,
1262 log_txt, log_txt_sz, 1);
1263 if (ZSTD_isError (dest_size))
1264 {
1265 free (dest);
1266
1267 g_set_error (
1268 error, Z_UTILS_LOG_ERROR,
1269 Z_UTILS_LOG_ERROR_FAILED,
1270 "Failed to compress log text: %s",
1271 ZSTD_getErrorName (dest_size));
1272
1273 g_free (log_file_tmpdir);
1274 return false;
1275 }
1276
1277 /* write to dest file */
1278 char * dest_filepath =
1279 g_build_filename (
1280 log_file_tmpdir, "log.txt.zst", NULL);
1281 bool ret =
1282 g_file_set_contents (
1283 dest_filepath, dest, (gssize) dest_size,
1284 error);
1285 g_free (dest);
1286 if (!ret)
1287 {
1288 g_free (log_file_tmpdir);
1289 g_free (dest_filepath);
1290 return false;
1291 }
1292
1293 *ret_dir = log_file_tmpdir;
1294 *ret_path = dest_filepath;
1295
1296 return true;
1297 }
1298
1299 /**
1300 * Creates the logger and sets the writer func.
1301 *
1302 * This can be called from any thread.
1303 */
1304 Log *
log_new(void)1305 log_new (void)
1306 {
1307 Log * self = object_new (Log);
1308
1309 const GDebugKey keys[] = {
1310 { "gc-friendly", 1 },
1311 {"fatal-warnings", G_LOG_LEVEL_WARNING | G_LOG_LEVEL_CRITICAL },
1312 {"fatal-criticals", G_LOG_LEVEL_CRITICAL }
1313 };
1314 GLogLevelFlags flags =
1315 g_parse_debug_envvar (
1316 "G_DEBUG", keys, G_N_ELEMENTS (keys), 0);
1317
1318 log_always_fatal |= flags & G_LOG_LEVEL_MASK;
1319
1320 self->log_domains =
1321 g_strdup (g_getenv ("G_MESSAGES_DEBUG"));
1322 self->use_structured_for_console = true;
1323 self->min_log_level_for_test_console =
1324 G_LOG_LEVEL_MESSAGE;
1325
1326 g_log_set_writer_func (
1327 (GLogWriterFunc) log_writer, self, NULL);
1328
1329 /* remove temporary log file if it exists */
1330 if (tmp_log_file)
1331 {
1332 io_remove (tmp_log_file);
1333 g_free_and_null (tmp_log_file);
1334 }
1335
1336 return self;
1337 }
1338
1339 /**
1340 * Stops logging and frees any allocated memory.
1341 */
1342 void
log_free(Log * self)1343 log_free (
1344 Log * self)
1345 {
1346 g_message ("%s: Tearing down...", __func__);
1347
1348 /* remove source func */
1349 if (self->writer_source_id)
1350 {
1351 g_source_remove (self->writer_source_id);
1352 }
1353
1354 /* clear the queue */
1355 log_idle_cb (self);
1356
1357 /* set back default log handler */
1358 g_log_set_writer_func (
1359 g_log_writer_default, NULL, NULL);
1360
1361 /* close log file */
1362 if (self->logfile)
1363 {
1364 fclose (self->logfile);
1365 self->logfile = NULL;
1366 }
1367
1368 /* free children */
1369 object_free_w_func_and_null (
1370 object_pool_free, self->obj_pool);
1371 object_free_w_func_and_null (
1372 mpmc_queue_free, self->mqueue);
1373 /*g_object_unref_and_null (self->messages_buf);*/
1374
1375 g_free_and_null (self->log_domains);
1376
1377 object_zero_and_free (self);
1378
1379 g_message ("%s: done", __func__);
1380 }
1381