1 /*
2  * This software is licensed under the terms of the MIT License.
3  * See COPYING for further information.
4  * ---
5  * Copyright (c) 2011-2019, Lukas Weber <laochailan@web.de>.
6  * Copyright (c) 2012-2019, Andrei Alexeyev <akari@taisei-project.org>.
7  */
8 
9 #include "taisei.h"
10 
11 #include <SDL_bits.h>
12 #include <SDL_mutex.h>
13 
14 #include "log.h"
15 #include "util.h"
16 #include "list.h"
17 
18 typedef struct Logger {
19 	LIST_INTERFACE(struct Logger);
20 
21 	FormatterObj formatter;
22 	SDL_RWops *out;
23 	uint levels;
24 } Logger;
25 
26 static struct {
27 	Logger *outputs;
28 	size_t num_outputs;
29 	char *fmt_buf1;
30 	char *fmt_buf2;
31 	size_t fmt_buf_size;
32 	SDL_mutex *mutex;
33 	uint enabled_log_levels;
34 
35 #ifdef LOG_FATAL_MSGBOX
36 	char *err_appendix;
37 #endif
38 } logging;
39 
40 #define INIT_BUF_SIZE 0x100
41 #define MAX_BUF_SIZE 0x10000
42 
43 static const char *level_prefix_map[] = {
44 	[_LOG_DEBUG_ID] = "D",
45 	[_LOG_INFO_ID]  = "I",
46 	[_LOG_WARN_ID]  = "W",
47 	[_LOG_ERROR_ID] = "E",
48 	[_LOG_FATAL_ID] = "F",
49 };
50 
51 static const char *level_name_map[] = {
52 	[_LOG_DEBUG_ID] = "DEBUG",
53 	[_LOG_INFO_ID]  = "INFO",
54 	[_LOG_WARN_ID]  = "WARNING",
55 	[_LOG_ERROR_ID] = "ERROR",
56 	[_LOG_FATAL_ID] = "FATAL",
57 };
58 
59 attr_unused
60 static const char *level_ansi_style_map[] = {
61 	[_LOG_DEBUG_ID] = "\x1b[1;35m",
62 	[_LOG_INFO_ID]  = "\x1b[1;32m",
63 	[_LOG_WARN_ID]  = "\x1b[1;33m",
64 	[_LOG_ERROR_ID] = "\x1b[1;31m",
65 	[_LOG_FATAL_ID] = "\x1b[1;31m",
66 };
67 
68 #define INDEX_MAP(map, lvl) \
69 	uint idx = SDL_MostSignificantBitIndex32(lvl); \
70 	assert_nolog(idx < sizeof(map) / sizeof(*map)); \
71 	return map[idx];
72 
level_prefix(LogLevel lvl)73 static const char* level_prefix(LogLevel lvl) { INDEX_MAP(level_prefix_map, lvl) }
level_name(LogLevel lvl)74 static const char* level_name(LogLevel lvl) { INDEX_MAP(level_name_map, lvl) }
level_ansi_style_code(LogLevel lvl)75 attr_unused static const char* level_ansi_style_code(LogLevel lvl) { INDEX_MAP(level_ansi_style_map, lvl) }
76 
log_abort(const char * msg)77 noreturn static void log_abort(const char *msg) {
78 #ifdef LOG_FATAL_MSGBOX
79 	static const char *const title = "Taisei: fatal error";
80 
81 	if(msg) {
82 		if(logging.err_appendix) {
83 			char *m = strfmt("%s\n\n%s", msg, logging.err_appendix);
84 			SDL_ShowSimpleMessageBox(SDL_MESSAGEBOX_ERROR, title, m, NULL);
85 			free(m);
86 		} else {
87 			SDL_ShowSimpleMessageBox(SDL_MESSAGEBOX_ERROR, title, msg, NULL);
88 		}
89 	} else if(logging.err_appendix) {
90 		SDL_ShowSimpleMessageBox(SDL_MESSAGEBOX_ERROR, title, logging.err_appendix, NULL);
91 	}
92 #endif
93 
94 	log_shutdown();
95 
96 	// abort() doesn't clean up, but it lets us get a backtrace, which is more useful
97 	abort();
98 }
99 
log_set_gui_error_appendix(const char * message)100 void log_set_gui_error_appendix(const char *message) {
101 #ifdef LOG_FATAL_MSGBOX
102 	stralloc(&logging.err_appendix, message);
103 #endif
104 }
105 
realloc_buffers(size_t min_size)106 static void realloc_buffers(size_t min_size) {
107 	min_size = topow2_u64(min_size);
108 
109 	if(min_size > MAX_BUF_SIZE) {
110 		min_size = MAX_BUF_SIZE;
111 	}
112 
113 	if(logging.fmt_buf_size >= min_size) {
114 		return;
115 	}
116 
117 	logging.fmt_buf1 = realloc(logging.fmt_buf1, min_size);
118 	logging.fmt_buf2 = realloc(logging.fmt_buf2, min_size);
119 	logging.fmt_buf_size = min_size;
120 }
121 
add_debug_info(char ** buf)122 static void add_debug_info(char **buf) {
123 	IF_DEBUG({
124 		DebugInfo *debug_info = get_debug_info();
125 		DebugInfo *debug_meta = get_debug_meta();
126 
127 		char *dbg = strfmt(
128 			"%s\n\n\n"
129 			"Debug info: %s:%i:%s\n"
130 			"Debug info set at: %s:%i:%s\n"
131 			"Note: debug info may not be relevant to this issue\n",
132 			*buf,
133 			debug_info->file, debug_info->line, debug_info->func,
134 			debug_meta->file, debug_meta->line, debug_meta->func
135 		);
136 
137 		free(*buf);
138 		*buf = dbg;
139 	});
140 }
141 
log_internal(LogLevel lvl,const char * funcname,const char * filename,uint line,const char * fmt,va_list args)142 static void log_internal(LogLevel lvl, const char *funcname, const char *filename, uint line, const char *fmt, va_list args) {
143 	assert(fmt[strlen(fmt)-1] != '\n');
144 
145 	bool noabort = lvl & LOG_NOABORT_BIT;
146 	lvl &= logging.enabled_log_levels;
147 
148 	if(lvl == LOG_NONE) {
149 		return;
150 	}
151 
152 	SDL_LockMutex(logging.mutex);
153 
154 	va_list args_copy;
155 	va_copy(args_copy, args);
156 	int slen = vsnprintf(logging.fmt_buf1, logging.fmt_buf_size, fmt, args_copy);
157 	va_end(args_copy);
158 
159 	if(slen >= logging.fmt_buf_size) {
160 		realloc_buffers(slen + 1);
161 		va_copy(args_copy, args);
162 		slen = vsnprintf(logging.fmt_buf1, logging.fmt_buf_size, fmt, args_copy);
163 		va_end(args_copy);
164 	}
165 
166 	assert_nolog(slen >= 0);
167 
168 	if(lvl & LOG_FATAL) {
169 		add_debug_info(&logging.fmt_buf1);
170 	}
171 
172 	LogEntry entry = {
173 		.message = logging.fmt_buf1,
174 		.file = filename,
175 		.func = funcname,
176 		.line = line,
177 		.level = lvl,
178 		.time = SDL_GetTicks(),
179 	};
180 
181 	for(Logger *l = logging.outputs; l; l = l->next) {
182 		if(l->levels & lvl) {
183 			slen = l->formatter.format(&l->formatter, logging.fmt_buf2, logging.fmt_buf_size, &entry);
184 
185 			if(slen >= logging.fmt_buf_size) {
186 				char *tmp = strdup(logging.fmt_buf1);
187 				realloc_buffers(slen + 1);
188 				strcpy(logging.fmt_buf1, tmp);
189 				free(tmp);
190 				entry.message = logging.fmt_buf1;
191 
192 				attr_unused int old_slen = slen;
193 				slen = l->formatter.format(&l->formatter, logging.fmt_buf2, logging.fmt_buf_size, &entry);
194 				assert_nolog(old_slen == slen);
195 			}
196 
197 			assert_nolog(slen >= 0);
198 
199 			if(logging.fmt_buf_size < slen) {
200 				slen = logging.fmt_buf_size;
201 			}
202 
203 			SDL_RWwrite(l->out, logging.fmt_buf2, 1, slen);
204 		}
205 	}
206 
207 	if((lvl & LOG_FATAL) && !noabort) {
208 		log_abort(entry.message);
209 	}
210 
211 	SDL_UnlockMutex(logging.mutex);
212 }
213 
_taisei_log(LogLevel lvl,const char * funcname,const char * filename,uint line,const char * fmt,...)214 void _taisei_log(LogLevel lvl, const char *funcname, const char *filename, uint line, const char *fmt, ...) {
215 	va_list args;
216 	va_start(args, fmt);
217 	log_internal(lvl, funcname, filename, line, fmt, args);
218 	va_end(args);
219 }
220 
_taisei_log_fatal(LogLevel lvl,const char * funcname,const char * filename,uint line,const char * fmt,...)221 void _taisei_log_fatal(LogLevel lvl, const char *funcname, const char *filename, uint line, const char *fmt, ...) {
222 	va_list args;
223 	va_start(args, fmt);
224 	log_internal(lvl, funcname, filename, line, fmt, args);
225 	va_end(args);
226 
227 	// should usually not get here, log_internal will abort earlier if lvl is LOG_FATAL
228 	// that is unless LOG_FATAL is disabled for some reason
229 	log_abort(NULL);
230 }
231 
delete_logger(List ** loggers,List * logger,void * arg)232 static void* delete_logger(List **loggers, List *logger, void *arg) {
233 	Logger *l = (Logger*)logger;
234 
235 	if(l->formatter.free != NULL) {
236 		l->formatter.free(&l->formatter);
237 	}
238 
239 #if HAVE_STDIO_H
240 	if(l->out->type == SDL_RWOPS_STDFILE) {
241 		fflush(l->out->hidden.stdio.fp);
242 	}
243 #endif
244 
245 	SDL_RWclose(l->out);
246 	free(list_unlink(loggers, logger));
247 
248 	return NULL;
249 }
250 
log_init(LogLevel lvls)251 void log_init(LogLevel lvls) {
252 	logging.enabled_log_levels = lvls;
253 	logging.mutex = SDL_CreateMutex();
254 	realloc_buffers(INIT_BUF_SIZE);
255 }
256 
log_shutdown(void)257 void log_shutdown(void) {
258 	list_foreach(&logging.outputs, delete_logger, NULL);
259 	SDL_DestroyMutex(logging.mutex);
260 	free(logging.fmt_buf1);
261 	free(logging.fmt_buf2);
262 
263 #ifdef LOG_FATAL_MSGBOX
264 	free(logging.err_appendix);
265 #endif
266 
267 	memset(&logging, 0, sizeof(logging));
268 }
269 
log_initialized(void)270 bool log_initialized(void) {
271 	return logging.fmt_buf_size > 0;
272 }
273 
log_add_output(LogLevel levels,SDL_RWops * output,Formatter * formatter)274 void log_add_output(LogLevel levels, SDL_RWops *output, Formatter *formatter) {
275 	if(!output) {
276 		return;
277 	}
278 
279 	if(!(levels & logging.enabled_log_levels)) {
280 		SDL_RWclose(output);
281 		return;
282 	}
283 
284 	Logger *l = calloc(1, sizeof(Logger));
285 	l->levels = levels;
286 	l->out = output;
287 
288 	formatter(&l->formatter, l->out);
289 	assert(l->formatter.format != NULL);
290 
291 	list_append(&logging.outputs, l);
292 }
293 
chr2lvl(char c)294 static LogLevel chr2lvl(char c) {
295 	c = toupper(c);
296 
297 	for(int i = 0; i < sizeof(level_prefix_map) / sizeof(char*); ++i) {
298 		if(c == level_prefix_map[i][0]) {
299 			return (1 << i);
300 		} else if(c == 'A') {
301 			return LOG_ALL;
302 		}
303 	}
304 
305 	return 0;
306 }
307 
log_parse_levels(LogLevel lvls,const char * lvlmod)308 LogLevel log_parse_levels(LogLevel lvls, const char *lvlmod) {
309 	if(!lvlmod) {
310 		return lvls;
311 	}
312 
313 	bool enable = true;
314 
315 	for(const char *c = lvlmod; *c; ++c) {
316 		if(*c == '+') {
317 			enable = true;
318 		} else if(*c == '-') {
319 			enable = false;
320 		} else if(enable) {
321 			lvls |= chr2lvl(*c);
322 		} else {
323 			lvls &= ~chr2lvl(*c);
324 		}
325 	}
326 
327 	return lvls;
328 }
329 
ensure_newline(char * buf,size_t buf_size,size_t output_size)330 static void ensure_newline(char *buf, size_t buf_size, size_t output_size) {
331 	if(output_size >= buf_size) {
332 		*(strrchr(buf, '\0') - 1) = '\n';
333 	}
334 }
335 
log_fmtconsole_format_ansi(FormatterObj * obj,char * buf,size_t buf_size,LogEntry * entry)336 static int log_fmtconsole_format_ansi(FormatterObj *obj, char *buf, size_t buf_size, LogEntry *entry) {
337 	int r = snprintf(
338 		buf,
339 		buf_size,
340 		"\x1b[1;30m%-9d %s%s\x1b[1;30m: \x1b[1;34m%s\x1b[1;30m: \x1b[0m%s\n",
341 		entry->time,
342 		level_ansi_style_code(entry->level),
343 		level_prefix(entry->level),
344 		entry->func,
345 		entry->message
346 	);
347 	ensure_newline(buf, buf_size, r);
348 	return r;
349 }
350 
log_fmtconsole_format_plain(FormatterObj * obj,char * buf,size_t buf_size,LogEntry * entry)351 static int log_fmtconsole_format_plain(FormatterObj *obj, char *buf, size_t buf_size, LogEntry *entry) {
352 	int r = snprintf(
353 		buf,
354 		buf_size,
355 		"%-9d %s: %s: %s\n",
356 		entry->time,
357 		level_prefix(entry->level),
358 		entry->func,
359 		entry->message
360 	);
361 	ensure_newline(buf, buf_size, r);
362 	return r;
363 }
364 
365 #ifdef TAISEI_BUILDCONF_HAVE_POSIX
366 #include <unistd.h>
367 
output_supports_ansi_sequences(const SDL_RWops * output)368 static bool output_supports_ansi_sequences(const SDL_RWops *output) {
369 	if(!strcmp(env_get("TERM", "dumb"), "dumb")) {
370 		return false;
371 	}
372 
373 	if(output->type != SDL_RWOPS_STDFILE) {
374 		return false;
375 	}
376 
377 	return isatty(fileno(output->hidden.stdio.fp));
378 }
379 #else
output_supports_ansi_sequences(const SDL_RWops * output)380 static bool output_supports_ansi_sequences(const SDL_RWops *output) {
381 	// TODO: Handle it for windows. The windows console supports ANSI escapes, but requires special setup.
382 	return false;
383 }
384 #endif
385 
log_formatter_console(FormatterObj * obj,const SDL_RWops * output)386 void log_formatter_console(FormatterObj *obj, const SDL_RWops *output) {
387 	if(output_supports_ansi_sequences(output)) {
388 		obj->format = log_fmtconsole_format_ansi;
389 	} else {
390 		obj->format = log_fmtconsole_format_plain;
391 	}
392 }
393 
log_fmtfile_format(FormatterObj * obj,char * buf,size_t buf_size,LogEntry * entry)394 static int log_fmtfile_format(FormatterObj *obj, char *buf, size_t buf_size, LogEntry *entry) {
395 	int r = snprintf(
396 		buf,
397 		buf_size,
398 		"%d  %s  %s: %s\n",
399 		entry->time,
400 		level_name(entry->level),
401 		entry->func,
402 		entry->message
403 	);
404 	ensure_newline(buf, buf_size, r);
405 	return r;
406 }
407 
log_formatter_file(FormatterObj * obj,const SDL_RWops * output)408 void log_formatter_file(FormatterObj *obj, const SDL_RWops *output) {
409 	obj->format = log_fmtfile_format;
410 }
411