Branch data Line data Source code
1 : : /* -*- mode: C++; c-basic-offset: 4; indent-tabs-mode: nil; -*- */
2 : : // SPDX-License-Identifier: MIT OR LGPL-2.0-or-later
3 : : // SPDX-FileCopyrightText: 2008 litl, LLC
4 : :
5 : : #include <config.h>
6 : :
7 : : #include <errno.h>
8 : : #include <stdarg.h>
9 : : #include <stdio.h> // for FILE, fprintf, fflush, fopen, fputs, fseek
10 : : #include <string.h> // for strchr, strcmp
11 : :
12 : : #ifdef _WIN32
13 : : # include <io.h>
14 : : # include <process.h>
15 : : # ifndef F_OK
16 : : # define F_OK 0
17 : : # endif
18 : : #else
19 : : # include <unistd.h> // for getpid
20 : : #endif
21 : :
22 : : #include <array>
23 : : #include <atomic> // for atomic_bool
24 : : #include <memory> // for unique_ptr
25 : : #include <string> // for string
26 : :
27 : : #include <glib.h>
28 : :
29 : : #include "gjs/auto.h"
30 : : #include "util/log.h"
31 : : #include "util/misc.h"
32 : :
33 : : static std::atomic_bool s_initialized = ATOMIC_VAR_INIT(false);
34 : : static bool s_debug_log_enabled = false;
35 : : static bool s_print_thread = false;
36 : : static std::unique_ptr<LogFile> s_log_file;
37 : 0 : static Gjs::AutoPointer<GTimer, GTimer, g_timer_destroy> s_timer;
38 : : static std::array<bool, GJS_DEBUG_LAST> s_enabled_topics;
39 : :
40 : 0 : static const char* topic_to_prefix(GjsDebugTopic topic) {
41 [ # # # # : 0 : switch (topic) {
# # # # #
# # # # #
# # # # #
# # ]
42 : 0 : case GJS_DEBUG_GI_USAGE:
43 : 0 : return "JS GI USE";
44 : 0 : case GJS_DEBUG_MEMORY:
45 : 0 : return "JS MEMORY";
46 : 0 : case GJS_DEBUG_CONTEXT:
47 : 0 : return "JS CTX";
48 : 0 : case GJS_DEBUG_IMPORTER:
49 : 0 : return "JS IMPORT";
50 : 0 : case GJS_DEBUG_NATIVE:
51 : 0 : return "JS NATIVE";
52 : 0 : case GJS_DEBUG_CAIRO:
53 : 0 : return "JS CAIRO";
54 : 0 : case GJS_DEBUG_KEEP_ALIVE:
55 : 0 : return "JS KP ALV";
56 : 0 : case GJS_DEBUG_MAINLOOP:
57 : 0 : return "JS MAINLOOP";
58 : 0 : case GJS_DEBUG_GREPO:
59 : 0 : return "JS G REPO";
60 : 0 : case GJS_DEBUG_GNAMESPACE:
61 : 0 : return "JS G NS";
62 : 0 : case GJS_DEBUG_GOBJECT:
63 : 0 : return "JS G OBJ";
64 : 0 : case GJS_DEBUG_GFUNCTION:
65 : 0 : return "JS G FUNC";
66 : 0 : case GJS_DEBUG_GFUNDAMENTAL:
67 : 0 : return "JS G FNDMTL";
68 : 0 : case GJS_DEBUG_GCLOSURE:
69 : 0 : return "JS G CLSR";
70 : 0 : case GJS_DEBUG_GBOXED:
71 : 0 : return "JS G BXD";
72 : 0 : case GJS_DEBUG_GENUM:
73 : 0 : return "JS G ENUM";
74 : 0 : case GJS_DEBUG_GPARAM:
75 : 0 : return "JS G PRM";
76 : 0 : case GJS_DEBUG_GERROR:
77 : 0 : return "JS G ERR";
78 : 0 : case GJS_DEBUG_GINTERFACE:
79 : 0 : return "JS G IFACE";
80 : 0 : case GJS_DEBUG_GTYPE:
81 : 0 : return "JS GTYPE";
82 : 0 : default:
83 : 0 : return "???";
84 : : }
85 : : }
86 : :
87 : 0 : static GjsDebugTopic prefix_to_topic(const char* prefix) {
88 [ # # ]: 0 : for (unsigned i = 0; i < GJS_DEBUG_LAST; i++) {
89 : 0 : auto topic = static_cast<GjsDebugTopic>(i);
90 [ # # ]: 0 : if (g_str_equal(topic_to_prefix(topic), prefix))
91 : 0 : return topic;
92 : : }
93 : :
94 : 0 : return GJS_DEBUG_LAST;
95 : : }
96 : :
97 : 341 : void gjs_log_init() {
98 : 341 : bool expected = false;
99 [ + + ]: 341 : if (!s_initialized.compare_exchange_strong(expected, true))
100 : 100 : return;
101 : :
102 [ - + ]: 241 : if (gjs_environment_variable_is_set("GJS_DEBUG_TIMESTAMP"))
103 : 0 : s_timer = g_timer_new();
104 : :
105 : 241 : s_print_thread = gjs_environment_variable_is_set("GJS_DEBUG_THREAD");
106 : :
107 : 241 : const char* debug_output = g_getenv("GJS_DEBUG_OUTPUT");
108 [ + - + - ]: 241 : if (debug_output && g_str_equal(debug_output, "stderr")) {
109 : 241 : s_debug_log_enabled = true;
110 [ # # ]: 0 : } else if (debug_output) {
111 : 0 : std::string log_file;
112 : : char* c;
113 : :
114 : : /* Allow debug-%u.log for per-pid logfiles as otherwise log
115 : : * messages from multiple processes can overwrite each other.
116 : : *
117 : : * (printf below should be safe as we check '%u' is the only format
118 : : * string)
119 : : */
120 : 0 : c = strchr(const_cast<char*>(debug_output), '%');
121 [ # # # # : 0 : if (c && c[1] == 'u' && !strchr(c + 1, '%')) {
# # ]
122 : 0 : Gjs::AutoChar file_name;
123 : : #if defined(__clang__) || __GNUC__ > 4 || (__GNUC__ == 4 && __GNUC_MINOR__ >= 6)
124 : : _Pragma("GCC diagnostic push")
125 : : _Pragma("GCC diagnostic ignored \"-Wformat-nonliteral\"")
126 : : #endif
127 : 0 : file_name = g_strdup_printf(debug_output, getpid());
128 : : #if defined(__clang__) || __GNUC__ > 4 || (__GNUC__ == 4 && __GNUC_MINOR__ >= 6)
129 : : _Pragma("GCC diagnostic pop")
130 : : #endif
131 : 0 : log_file = file_name.get();
132 : 0 : } else {
133 : 0 : log_file = debug_output;
134 : : }
135 : :
136 : : /* avoid truncating in case we're using shared logfile */
137 : 0 : s_log_file = std::make_unique<LogFile>(log_file.c_str());
138 [ # # ]: 0 : if (s_log_file->has_error()) {
139 : 0 : fprintf(stderr, "Failed to open log file `%s': %s\n",
140 : 0 : log_file.c_str(), g_strerror(errno));
141 : : }
142 : :
143 : 0 : s_debug_log_enabled = true;
144 : 0 : }
145 : :
146 [ + + ]: 241 : if (!s_log_file)
147 : 100 : s_log_file = std::make_unique<LogFile>(nullptr, stderr);
148 : :
149 [ + - ]: 241 : if (s_debug_log_enabled) {
150 : 241 : auto* topics = g_getenv("GJS_DEBUG_TOPICS");
151 : 241 : s_enabled_topics.fill(topics == nullptr);
152 [ + - ]: 241 : if (topics) {
153 : 241 : Gjs::AutoStrv prefixes{g_strsplit(topics, ";", -1)};
154 [ - + ]: 241 : for (unsigned i = 0; prefixes[i] != NULL; i++) {
155 : 0 : GjsDebugTopic topic = prefix_to_topic(prefixes[i]);
156 [ # # ]: 0 : if (topic != GJS_DEBUG_LAST)
157 : 0 : s_enabled_topics[topic] = true;
158 : : }
159 : 241 : }
160 : : }
161 : : }
162 : :
163 : 239 : void gjs_log_cleanup() {
164 : 239 : bool expected = true;
165 [ - + ]: 239 : if (!s_initialized.compare_exchange_strong(expected, false))
166 : 0 : return;
167 : :
168 : 239 : s_timer = nullptr;
169 : 239 : s_enabled_topics.fill(false);
170 : : }
171 : :
172 : : #define PREFIX_LENGTH 12
173 : :
174 : : static void
175 : 0 : write_to_stream(FILE *logfp,
176 : : const char *prefix,
177 : : const char *s)
178 : : {
179 : : /* seek to end to avoid truncating in case we're using shared logfile */
180 : 0 : (void)fseek(logfp, 0, SEEK_END);
181 : :
182 : 0 : fprintf(logfp, "%*s: %s", PREFIX_LENGTH, prefix, s);
183 [ # # # # : 0 : if (!g_str_has_suffix(s, "\n"))
# # ]
184 : 0 : fputs("\n", logfp);
185 : 0 : fflush(logfp);
186 : 0 : }
187 : :
188 : : void
189 : 54431 : gjs_debug(GjsDebugTopic topic,
190 : : const char *format,
191 : : ...)
192 : : {
193 : : va_list args;
194 : : char *s;
195 : :
196 [ + - + - : 54431 : if (!s_debug_log_enabled || !s_enabled_topics[topic])
+ - ]
197 : 54431 : return;
198 : :
199 : 0 : va_start (args, format);
200 : 0 : s = g_strdup_vprintf (format, args);
201 : 0 : va_end (args);
202 : :
203 [ # # ]: 0 : if (s_timer) {
204 : : static gdouble previous = 0.0;
205 : 0 : gdouble total = g_timer_elapsed(s_timer, NULL) * 1000.0;
206 : 0 : gdouble since = total - previous;
207 : : const char *ts_suffix;
208 : : char *s2;
209 : :
210 [ # # ]: 0 : if (since > 50.0) {
211 : 0 : ts_suffix = "!! ";
212 [ # # ]: 0 : } else if (since > 100.0) {
213 : 0 : ts_suffix = "!!! ";
214 [ # # ]: 0 : } else if (since > 200.0) {
215 : 0 : ts_suffix = "!!!!";
216 : : } else {
217 : 0 : ts_suffix = " ";
218 : : }
219 : :
220 : 0 : s2 = g_strdup_printf("%g %s%s",
221 : : total, ts_suffix, s);
222 : 0 : g_free(s);
223 : 0 : s = s2;
224 : :
225 : 0 : previous = total;
226 : : }
227 : :
228 [ # # ]: 0 : if (s_print_thread) {
229 : 0 : char *s2 = g_strdup_printf("(thread %p) %s", g_thread_self(), s);
230 : 0 : g_free(s);
231 : 0 : s = s2;
232 : : }
233 : :
234 : 0 : write_to_stream(s_log_file->fp(), topic_to_prefix(topic), s);
235 : :
236 : 0 : g_free(s);
237 : : }
|