Merge branch 'blender2.7'
[blender.git] / intern / clog / clog.c
1 /*
2  * This program is free software; you can redistribute it and/or
3  * modify it under the terms of the GNU General Public License
4  * as published by the Free Software Foundation; either version 2
5  * of the License, or (at your option) any later version.
6  *
7  * This program is distributed in the hope that it will be useful,
8  * but WITHOUT ANY WARRANTY; without even the implied warranty of
9  * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
10  * GNU General Public License for more details.
11  *
12  * You should have received a copy of the GNU General Public License
13  * along with this program; if not, write to the Free Software Foundation,
14  * Inc., 51 Franklin Street, Fifth Floor, Boston, MA 02110-1301, USA.
15  */
16
17 /** \file
18  * \ingroup clog
19  */
20
21 #include <stdarg.h>
22 #include <stdlib.h>
23 #include <string.h>
24 #include <stdint.h>
25 #include <assert.h>
26
27 /* Disable for small single threaded programs
28  * to avoid having to link with pthreads. */
29 #ifdef WITH_CLOG_PTHREADS
30 #  include <pthread.h>
31 #  include "atomic_ops.h"
32 #endif
33
34 /* For 'isatty' to check for color. */
35 #if defined(__unix__) || defined(__APPLE__) || defined(__HAIKU__)
36 #  include <unistd.h>
37 #  include <sys/time.h>
38 #endif
39
40 #if defined(_MSC_VER)
41 #  include <io.h>
42 #  include <windows.h>
43 #endif
44
45 /* For printing timestamp. */
46 #define __STDC_FORMAT_MACROS
47 #include <inttypes.h>
48
49
50 /* Only other dependency (could use regular malloc too). */
51 #include "MEM_guardedalloc.h"
52
53 /* own include. */
54 #include "CLG_log.h"
55
56 /* Local utility defines */
57 #define STREQ(a, b) (strcmp(a, b) == 0)
58 #define STREQLEN(a, b, n) (strncmp(a, b, n) == 0)
59
60 #ifdef _WIN32
61 #  define PATHSEP_CHAR '\\'
62 #else
63 #  define PATHSEP_CHAR '/'
64 #endif
65
66 /* -------------------------------------------------------------------- */
67 /** \name Internal Types
68  * \{ */
69
70 typedef struct CLG_IDFilter {
71         struct CLG_IDFilter *next;
72         /** Over alloc. */
73         char match[0];
74 } CLG_IDFilter;
75
76 typedef struct CLogContext {
77         /** Single linked list of types.  */
78         CLG_LogType *types;
79 #ifdef WITH_CLOG_PTHREADS
80         pthread_mutex_t types_lock;
81 #endif
82
83         /* exclude, include filters.  */
84         CLG_IDFilter *filters[2];
85         bool use_color;
86         bool use_basename;
87         bool use_timestamp;
88
89         /** Borrowed, not owned. */
90         int output;
91         FILE *output_file;
92
93         /** For timer (use_timestamp). */
94         uint64_t timestamp_tick_start;
95
96         /** For new types. */
97         struct {
98                 int level;
99         } default_type;
100
101         struct {
102                 void (*fatal_fn)(void *file_handle);
103                 void (*backtrace_fn)(void *file_handle);
104         } callbacks;
105 } CLogContext;
106
107 /** \} */
108
109 /* -------------------------------------------------------------------- */
110 /** \name Mini Buffer Functionality
111  *
112  * Use so we can do a single call to write.
113  * \{ */
114
115 #define CLOG_BUF_LEN_INIT 512
116
117 typedef struct CLogStringBuf {
118         char *data;
119         uint  len;
120         uint  len_alloc;
121         bool is_alloc;
122 } CLogStringBuf;
123
124 static void clg_str_init(CLogStringBuf *cstr, char *buf_stack, uint buf_stack_len)
125 {
126         cstr->data = buf_stack;
127         cstr->len_alloc = buf_stack_len;
128         cstr->len = 0;
129         cstr->is_alloc = false;
130 }
131
132 static void clg_str_free(CLogStringBuf *cstr)
133 {
134         if (cstr->is_alloc) {
135                 MEM_freeN(cstr->data);
136         }
137 }
138
139 static void clg_str_reserve(CLogStringBuf *cstr, const uint len)
140 {
141         if (len > cstr->len_alloc) {
142                 cstr->len_alloc *= 2;
143                 if (len > cstr->len_alloc) {
144                         cstr->len_alloc = len;
145                 }
146
147                 if (cstr->is_alloc) {
148                         cstr->data = MEM_reallocN(cstr->data, cstr->len_alloc);
149                 }
150                 else {
151                         /* Copy the static buffer. */
152                         char *data = MEM_mallocN(cstr->len_alloc, __func__);
153                         memcpy(data, cstr->data, cstr->len);
154                         cstr->data = data;
155                         cstr->is_alloc = true;
156                 }
157                 cstr->len_alloc = len;
158         }
159 }
160
161 static void clg_str_append_with_len(CLogStringBuf *cstr, const char *str, const uint len)
162 {
163         uint len_next = cstr->len + len;
164         clg_str_reserve(cstr, len_next);
165         char *str_dst = cstr->data + cstr->len;
166         memcpy(str_dst, str, len);
167 #if 0 /* no need. */
168         str_dst[len] = '\0';
169 #endif
170         cstr->len = len_next;
171 }
172
173 static void clg_str_append(CLogStringBuf *cstr, const char *str)
174 {
175         clg_str_append_with_len(cstr, str, strlen(str));
176 }
177
178 static void clg_str_vappendf(CLogStringBuf *cstr, const char *fmt, va_list args)
179 {
180         /* Use limit because windows may use '-1' for a formatting error. */
181         const uint len_max = 65535;
182         uint len_avail = (cstr->len_alloc - cstr->len);
183         if (len_avail == 0) {
184                 len_avail = CLOG_BUF_LEN_INIT;
185                 clg_str_reserve(cstr, len_avail);
186         }
187         while (true) {
188                 va_list args_cpy;
189                 va_copy(args_cpy, args);
190                 int retval = vsnprintf(cstr->data + cstr->len, len_avail, fmt, args_cpy);
191                 va_end(args_cpy);
192                 if (retval != -1) {
193                         cstr->len += retval;
194                         break;
195                 }
196                 else {
197                         len_avail *= 2;
198                         if (len_avail >= len_max) {
199                                 break;
200                         }
201                         clg_str_reserve(cstr, len_avail);
202                 }
203         }
204 }
205
206 /** \} */
207
208 /* -------------------------------------------------------------------- */
209 /** \name Internal Utilities
210  * \{ */
211
212 enum eCLogColor {
213         COLOR_DEFAULT,
214         COLOR_RED,
215         COLOR_GREEN,
216         COLOR_YELLOW,
217
218         COLOR_RESET,
219 };
220 #define COLOR_LEN (COLOR_RESET + 1)
221
222 static const char *clg_color_table[COLOR_LEN] = {NULL};
223
224 static void clg_color_table_init(bool use_color)
225 {
226         for (int i = 0; i < COLOR_LEN; i++) {
227                 clg_color_table[i] = "";
228         }
229         if (use_color) {
230 #ifdef _WIN32
231                 /* TODO */
232 #else
233                 clg_color_table[COLOR_DEFAULT]      = "\033[1;37m";
234                 clg_color_table[COLOR_RED]          = "\033[1;31m";
235                 clg_color_table[COLOR_GREEN]        = "\033[1;32m";
236                 clg_color_table[COLOR_YELLOW]       = "\033[1;33m";
237                 clg_color_table[COLOR_RESET]        = "\033[0m";
238 #endif
239         }
240 }
241
242 static const char *clg_severity_str[CLG_SEVERITY_LEN] = {
243         [CLG_SEVERITY_INFO] =       "INFO",
244         [CLG_SEVERITY_WARN] =       "WARN",
245         [CLG_SEVERITY_ERROR] =      "ERROR",
246         [CLG_SEVERITY_FATAL] =      "FATAL",
247 };
248
249 static const char *clg_severity_as_text(enum CLG_Severity severity)
250 {
251         bool ok = (unsigned int)severity < CLG_SEVERITY_LEN;
252         assert(ok);
253         if (ok) {
254                 return clg_severity_str[severity];
255         }
256         else {
257                 return "INVALID_SEVERITY";
258         }
259 }
260
261 static enum eCLogColor clg_severity_to_color(enum CLG_Severity severity)
262 {
263         assert((unsigned int)severity < CLG_SEVERITY_LEN);
264         enum eCLogColor color = COLOR_DEFAULT;
265         switch (severity) {
266                 case CLG_SEVERITY_INFO:
267                         color = COLOR_DEFAULT;
268                         break;
269                 case CLG_SEVERITY_WARN:
270                         color = COLOR_YELLOW;
271                         break;
272                 case CLG_SEVERITY_ERROR:
273                 case CLG_SEVERITY_FATAL:
274                         color = COLOR_RED;
275                         break;
276                 default:
277                         /* should never get here. */
278                         assert(false);
279         }
280         return color;
281 }
282
283 /** \} */
284
285 /* -------------------------------------------------------------------- */
286 /** \name Context Type Access
287  * \{ */
288
289 /**
290  * Filter the indentifier based on very basic globbing.
291  * - `foo` exact match of `foo`.
292  * - `foo.bar` exact match for `foo.bar`
293  * - `foo.*` match for `foo` & `foo.bar` & `foo.bar.baz`
294  * - `*` matches everything.
295  */
296 static bool clg_ctx_filter_check(CLogContext *ctx, const char *identifier)
297 {
298         const int identifier_len = strlen(identifier);
299         for (uint i = 0; i < 2; i++) {
300                 const CLG_IDFilter *flt = ctx->filters[i];
301                 while (flt != NULL) {
302                         const int len = strlen(flt->match);
303                         if (STREQ(flt->match, "*") ||
304                                 ((len == identifier_len) && (STREQ(identifier, flt->match))))
305                         {
306                                 return (bool)i;
307                         }
308                         if ((len >= 2) && (STREQLEN(".*", &flt->match[len - 2], 2))) {
309                                 if (((identifier_len == len - 2) && STREQLEN(identifier, flt->match, len - 2)) ||
310                                         ((identifier_len >= len - 1) && STREQLEN(identifier, flt->match, len - 1)))
311                                 {
312                                         return (bool)i;
313                                 }
314                         }
315                         flt = flt->next;
316                 }
317         }
318         return false;
319 }
320
321 /**
322  * \note This should never be called per logging call.
323  * Searching is only to get an initial handle.
324  */
325 static CLG_LogType *clg_ctx_type_find_by_name(CLogContext *ctx, const char *identifier)
326 {
327         for (CLG_LogType *ty = ctx->types; ty; ty = ty->next) {
328                 if (STREQ(identifier, ty->identifier)) {
329                         return ty;
330                 }
331         }
332         return NULL;
333 }
334
335 static CLG_LogType *clg_ctx_type_register(CLogContext *ctx, const char *identifier)
336 {
337         assert(clg_ctx_type_find_by_name(ctx, identifier) == NULL);
338         CLG_LogType *ty = MEM_callocN(sizeof(*ty), __func__);
339         ty->next = ctx->types;
340         ctx->types = ty;
341         strncpy(ty->identifier, identifier, sizeof(ty->identifier) - 1);
342         ty->ctx = ctx;
343         ty->level = ctx->default_type.level;
344
345         if (clg_ctx_filter_check(ctx, ty->identifier)) {
346                 ty->flag |= CLG_FLAG_USE;
347         }
348         return ty;
349 }
350
351 static void clg_ctx_fatal_action(CLogContext *ctx)
352 {
353         if (ctx->callbacks.fatal_fn != NULL) {
354                 ctx->callbacks.fatal_fn(ctx->output_file);
355         }
356         fflush(ctx->output_file);
357         abort();
358 }
359
360 static void clg_ctx_backtrace(CLogContext *ctx)
361 {
362         /* Note: we avoid writing fo 'FILE', for backtrace we make an exception,
363          * if necessary we could have a version of the callback that writes to file descriptor all at once. */
364         ctx->callbacks.backtrace_fn(ctx->output_file);
365         fflush(ctx->output_file);
366 }
367
368 static uint64_t clg_timestamp_ticks_get(void)
369 {
370         uint64_t tick;
371 #if defined(_MSC_VER)
372         tick = GetTickCount64();
373 #else
374         struct timeval tv;
375         gettimeofday(&tv, NULL);
376         tick = tv.tv_sec * 1000 + tv.tv_usec / 1000;
377 #endif
378         return tick;
379 }
380
381 /** \} */
382
383 /* -------------------------------------------------------------------- */
384 /** \name Logging API
385  * \{ */
386
387 static void write_timestamp(CLogStringBuf *cstr, const uint64_t timestamp_tick_start)
388 {
389         char timestamp_str[64];
390         const uint64_t timestamp = clg_timestamp_ticks_get() - timestamp_tick_start;
391         const uint timestamp_len = snprintf(
392                 timestamp_str, sizeof(timestamp_str), "%" PRIu64 ".%03u ",
393                 timestamp / 1000, (uint)(timestamp % 1000));
394         clg_str_append_with_len(cstr, timestamp_str, timestamp_len);
395 }
396
397 static void write_severity(CLogStringBuf *cstr, enum CLG_Severity severity, bool use_color)
398 {
399         assert((unsigned int)severity < CLG_SEVERITY_LEN);
400         if (use_color) {
401                 enum eCLogColor color = clg_severity_to_color(severity);
402                 clg_str_append(cstr, clg_color_table[color]);
403                 clg_str_append(cstr, clg_severity_as_text(severity));
404                 clg_str_append(cstr, clg_color_table[COLOR_RESET]);
405         }
406         else {
407                 clg_str_append(cstr, clg_severity_as_text(severity));
408         }
409 }
410
411 static void write_type(CLogStringBuf *cstr, CLG_LogType *lg)
412 {
413         clg_str_append(cstr, " (");
414         clg_str_append(cstr, lg->identifier);
415         clg_str_append(cstr, "): ");
416 }
417
418 static void write_file_line_fn(CLogStringBuf *cstr, const char *file_line, const char *fn, const bool use_basename)
419 {
420         uint file_line_len = strlen(file_line);
421         if (use_basename) {
422                 uint file_line_offset = file_line_len;
423                 while (file_line_offset-- > 0) {
424                         if (file_line[file_line_offset] == PATHSEP_CHAR) {
425                                 file_line_offset++;
426                                 break;
427                         }
428                 }
429                 file_line += file_line_offset;
430                 file_line_len -= file_line_offset;
431         }
432         clg_str_append_with_len(cstr, file_line, file_line_len);
433
434
435         clg_str_append(cstr, " ");
436         clg_str_append(cstr, fn);
437         clg_str_append(cstr, ": ");
438 }
439
440 void CLG_log_str(
441         CLG_LogType *lg, enum CLG_Severity severity, const char *file_line, const char *fn,
442         const char *message)
443 {
444         CLogStringBuf cstr;
445         char cstr_stack_buf[CLOG_BUF_LEN_INIT];
446         clg_str_init(&cstr, cstr_stack_buf, sizeof(cstr_stack_buf));
447
448         if (lg->ctx->use_timestamp) {
449                 write_timestamp(&cstr, lg->ctx->timestamp_tick_start);
450         }
451
452         write_severity(&cstr, severity, lg->ctx->use_color);
453         write_type(&cstr, lg);
454
455         {
456                 write_file_line_fn(&cstr, file_line, fn, lg->ctx->use_basename);
457                 clg_str_append(&cstr, message);
458         }
459         clg_str_append(&cstr, "\n");
460
461         /* could be optional */
462         int bytes_written = write(lg->ctx->output, cstr.data, cstr.len);
463         (void)bytes_written;
464
465         clg_str_free(&cstr);
466
467         if (lg->ctx->callbacks.backtrace_fn) {
468                 clg_ctx_backtrace(lg->ctx);
469         }
470
471         if (severity == CLG_SEVERITY_FATAL) {
472                 clg_ctx_fatal_action(lg->ctx);
473         }
474 }
475
476 void CLG_logf(
477         CLG_LogType *lg, enum CLG_Severity severity, const char *file_line, const char *fn,
478         const char *fmt, ...)
479 {
480         CLogStringBuf cstr;
481         char cstr_stack_buf[CLOG_BUF_LEN_INIT];
482         clg_str_init(&cstr, cstr_stack_buf, sizeof(cstr_stack_buf));
483
484         if (lg->ctx->use_timestamp) {
485                 write_timestamp(&cstr, lg->ctx->timestamp_tick_start);
486         }
487
488         write_severity(&cstr, severity, lg->ctx->use_color);
489         write_type(&cstr, lg);
490
491         {
492                 write_file_line_fn(&cstr, file_line, fn, lg->ctx->use_basename);
493
494                 va_list ap;
495                 va_start(ap, fmt);
496                 clg_str_vappendf(&cstr, fmt, ap);
497                 va_end(ap);
498         }
499         clg_str_append(&cstr, "\n");
500
501         /* could be optional */
502         int bytes_written = write(lg->ctx->output, cstr.data, cstr.len);
503         (void)bytes_written;
504
505         clg_str_free(&cstr);
506
507         if (lg->ctx->callbacks.backtrace_fn) {
508                 clg_ctx_backtrace(lg->ctx);
509         }
510
511         if (severity == CLG_SEVERITY_FATAL) {
512                 clg_ctx_fatal_action(lg->ctx);
513         }
514 }
515
516 /** \} */
517
518 /* -------------------------------------------------------------------- */
519 /** \name Logging Context API
520  * \{ */
521
522 static void CLG_ctx_output_set(CLogContext *ctx, void *file_handle)
523 {
524         ctx->output_file = file_handle;
525         ctx->output = fileno(ctx->output_file);
526 #if defined(__unix__) || defined(__APPLE__)
527         ctx->use_color = isatty(ctx->output);
528 #endif
529 }
530
531 static void CLG_ctx_output_use_basename_set(CLogContext *ctx, int value)
532 {
533         ctx->use_basename = (bool)value;
534 }
535
536 static void CLG_ctx_output_use_timestamp_set(CLogContext *ctx, int value)
537 {
538         ctx->use_timestamp = (bool)value;
539         if (ctx->use_timestamp) {
540                 ctx->timestamp_tick_start = clg_timestamp_ticks_get();
541         }
542 }
543
544 /** Action on fatal severity. */
545 static void CLG_ctx_fatal_fn_set(CLogContext *ctx, void (*fatal_fn)(void *file_handle))
546 {
547         ctx->callbacks.fatal_fn = fatal_fn;
548 }
549
550 static void CLG_ctx_backtrace_fn_set(CLogContext *ctx, void (*backtrace_fn)(void *file_handle))
551 {
552         ctx->callbacks.backtrace_fn = backtrace_fn;
553 }
554
555 static void clg_ctx_type_filter_append(CLG_IDFilter **flt_list, const char *type_match, int type_match_len)
556 {
557         if (type_match_len == 0) {
558                 return;
559         }
560         CLG_IDFilter *flt = MEM_callocN(sizeof(*flt) + (type_match_len + 1), __func__);
561         flt->next = *flt_list;
562         *flt_list = flt;
563         memcpy(flt->match, type_match, type_match_len);
564         /* no need to null terminate since we calloc'd */
565 }
566
567 static void CLG_ctx_type_filter_exclude(CLogContext *ctx, const char *type_match, int type_match_len)
568 {
569         clg_ctx_type_filter_append(&ctx->filters[0], type_match, type_match_len);
570 }
571
572 static void CLG_ctx_type_filter_include(CLogContext *ctx, const char *type_match, int type_match_len)
573 {
574         clg_ctx_type_filter_append(&ctx->filters[1], type_match, type_match_len);
575 }
576
577 static void CLG_ctx_level_set(CLogContext *ctx, int level)
578 {
579         ctx->default_type.level = level;
580         for (CLG_LogType *ty = ctx->types; ty; ty = ty->next) {
581                 ty->level = level;
582         }
583 }
584
585 static CLogContext *CLG_ctx_init(void)
586 {
587         CLogContext *ctx = MEM_callocN(sizeof(*ctx), __func__);
588 #ifdef WITH_CLOG_PTHREADS
589         pthread_mutex_init(&ctx->types_lock, NULL);
590 #endif
591         ctx->use_color = true;
592         ctx->default_type.level = 1;
593         CLG_ctx_output_set(ctx, stdout);
594
595         return ctx;
596 }
597
598 static void CLG_ctx_free(CLogContext *ctx)
599 {
600         while (ctx->types != NULL) {
601                 CLG_LogType *item = ctx->types;
602                 ctx->types = item->next;
603                 MEM_freeN(item);
604         }
605
606         for (uint i = 0; i < 2; i++) {
607                 while (ctx->filters[i] != NULL) {
608                         CLG_IDFilter *item = ctx->filters[i];
609                         ctx->filters[i] = item->next;
610                         MEM_freeN(item);
611                 }
612         }
613 #ifdef WITH_CLOG_PTHREADS
614         pthread_mutex_destroy(&ctx->types_lock);
615 #endif
616         MEM_freeN(ctx);
617 }
618
619 /** \} */
620
621 /* -------------------------------------------------------------------- */
622 /** \name Public Logging API
623  *
624  * Currently uses global context.
625  * \{ */
626
627 /* We could support multiple at once, for now this seems not needed. */
628 static struct CLogContext *g_ctx = NULL;
629
630 void CLG_init(void)
631 {
632         g_ctx = CLG_ctx_init();
633
634         clg_color_table_init(g_ctx->use_color);
635 }
636
637 void CLG_exit(void)
638 {
639         CLG_ctx_free(g_ctx);
640 }
641
642 void CLG_output_set(void *file_handle)
643 {
644         CLG_ctx_output_set(g_ctx, file_handle);
645 }
646
647 void CLG_output_use_basename_set(int value)
648 {
649         CLG_ctx_output_use_basename_set(g_ctx, value);
650 }
651
652 void CLG_output_use_timestamp_set(int value)
653 {
654         CLG_ctx_output_use_timestamp_set(g_ctx, value);
655 }
656
657 void CLG_fatal_fn_set(void (*fatal_fn)(void *file_handle))
658 {
659         CLG_ctx_fatal_fn_set(g_ctx, fatal_fn);
660 }
661
662 void CLG_backtrace_fn_set(void (*fatal_fn)(void *file_handle))
663 {
664         CLG_ctx_backtrace_fn_set(g_ctx, fatal_fn);
665 }
666
667 void CLG_type_filter_exclude(const char *type_match, int type_match_len)
668 {
669         CLG_ctx_type_filter_exclude(g_ctx, type_match, type_match_len);
670 }
671
672 void CLG_type_filter_include(const char *type_match, int type_match_len)
673 {
674         CLG_ctx_type_filter_include(g_ctx, type_match, type_match_len);
675 }
676
677 void CLG_level_set(int level)
678 {
679         CLG_ctx_level_set(g_ctx, level);
680 }
681
682
683 /** \} */
684
685 /* -------------------------------------------------------------------- */
686 /** \name Logging Reference API
687  * Use to avoid lookups each time.
688  * \{ */
689
690 void CLG_logref_init(CLG_LogRef *clg_ref)
691 {
692 #ifdef WITH_CLOG_PTHREADS
693         /* Only runs once when initializing a static type in most cases. */
694         pthread_mutex_lock(&g_ctx->types_lock);
695 #endif
696         if (clg_ref->type == NULL) {
697                 CLG_LogType *clg_ty = clg_ctx_type_find_by_name(g_ctx, clg_ref->identifier);
698                 if (clg_ty == NULL) {
699                         clg_ty = clg_ctx_type_register(g_ctx, clg_ref->identifier);
700                 }
701 #ifdef WITH_CLOG_PTHREADS
702                 atomic_cas_ptr((void **)&clg_ref->type, clg_ref->type, clg_ty);
703 #else
704                 clg_ref->type = clg_ty;
705 #endif
706         }
707 #ifdef WITH_CLOG_PTHREADS
708         pthread_mutex_unlock(&g_ctx->types_lock);
709 #endif
710 }
711
712 /** \} */