mono/utils/mono-logger.c

   1 /**
   2  * \file
   3  */
   4
   5 #include <string.h>
   6 #include <stdlib.h>
   7 #include <stdio.h>
   8 #include <glib.h>
   9
  10 #include "mono-compiler.h"
  11 #include "mono-logger-internals.h"
  12 #include <mono/utils/mono-threads-debug.h>
  13
  14
  15 typedef struct {
  16         GLogLevelFlags  level;
  17         MonoTraceMask   mask;
  18 } MonoLogLevelEntry;
  19
  20 GLogLevelFlags mono_internal_current_level      = (GLogLevelFlags)INT_MAX;
  21 MonoTraceMask  mono_internal_current_mask       = (MonoTraceMask)~0;
  22 gboolean mono_trace_log_header                  = FALSE;
  23
  24 static GQueue           *level_stack            = NULL;
  25 static const char       *mono_log_domain        = "Mono";
  26 static MonoPrintCallback print_callback, printerr_callback;
  27
  28 static MonoLogCallParm logCallback;
  29
  30 typedef struct {
  31    MonoLogCallback legacy_callback;
  32    gpointer user_data;
  33 } UserSuppliedLoggerUserData;
  34
  35 /**
  36  * mono_trace_init:
  37  *
  38  * Initializes the mono tracer.
  39  */
  40 void
  41 mono_trace_init (void)
  42 {
  43         if(level_stack == NULL) {
  44                 mono_internal_current_level = G_LOG_LEVEL_ERROR;
  45                 level_stack = g_queue_new();
  46
  47                 char *mask = g_getenv ("MONO_LOG_MASK");
  48                 char *level = g_getenv ("MONO_LOG_LEVEL");
  49                 char *header = g_getenv ("MONO_LOG_HEADER");
  50                 char *dest = g_getenv ("MONO_LOG_DEST");
  51
  52                 mono_trace_set_mask_string(mask);
  53                 mono_trace_set_level_string(level);
  54                 mono_trace_set_logheader_string(header);
  55                 mono_trace_set_logdest_string(dest);
  56
  57                 g_free (mask);
  58                 g_free (level);
  59                 g_free (header);
  60                 g_free (dest);
  61         }
  62 }
  63
  64 /**
  65  * mono_trace_cleanup:
  66  *
  67  * Releases the mono tracer.
  68  */
  69 void
  70 mono_trace_cleanup (void)
  71 {
  72         if(level_stack != NULL) {
  73                 while(!g_queue_is_empty (level_stack)) {
  74                         g_free (g_queue_pop_head (level_stack));
  75                 }
  76
  77                 logCallback.closer();
  78                 g_queue_free (level_stack);
  79                 level_stack = NULL;
  80         }
  81 }
  82
  83 /**
  84  * mono_tracev_inner:
  85  * \param level Verbose level of the specified message
  86  * \param mask Type of the specified message
  87  * Traces a new message, depending on the current logging level
  88  * and trace mask.
  89  */
  90 void
  91 mono_tracev_inner (GLogLevelFlags level, MonoTraceMask mask, const char *format, va_list args)
  92 {
  93         char *log_message;
  94         if (level_stack == NULL) {
  95                 mono_trace_init ();
  96                 if(level > mono_internal_current_level || !(mask & mono_internal_current_mask))
  97                         return;
  98         }
  99
 100         g_assert (logCallback.opener); // mono_trace_init should have provided us with one!
 101
 102         if (g_vasprintf (&log_message, format, args) < 0)
 103                 return;
 104         logCallback.writer (mono_log_domain, level, logCallback.header, log_message);
 105         g_free (log_message);
 106 }
 107
 108 /**
 109  * mono_trace_set_level:
 110  * \param level Verbose level to set
 111  * Sets the current logging level. Every subsequent call to
 112  * \c mono_trace will check the visibility of a message against this
 113  * value.
 114  */
 115 void
 116 mono_trace_set_level (GLogLevelFlags level)
 117 {
 118         if(level_stack == NULL)
 119                 mono_trace_init();
 120
 121         mono_internal_current_level = level;
 122 }
 123
 124 /**
 125  * mono_trace_set_mask:
 126  * \param mask Mask of visible message types.
 127  * Sets the current logging level. Every subsequent call to
 128  * \c mono_trace will check the visibility of a message against this
 129  * value.
 130  */
 131 void
 132 mono_trace_set_mask (MonoTraceMask mask)
 133 {
 134         if(level_stack == NULL)
 135                 mono_trace_init();
 136
 137         mono_internal_current_mask = mask;
 138 }
 139
 140 /**
 141  * mono_trace_set_logdest:
 142  * \param dest Destination for logging
 143  * Sets the current logging destination. This can be a file or, if supported,
 144  * syslog.
 145  */
 146 void
 147 mono_trace_set_logdest_string (const char *dest)
 148 {
 149         MonoLogCallParm logger;
 150
 151         if(level_stack == NULL)
 152                 mono_trace_init();
 153
 154 #if HOST_ANDROID
 155         logger.opener = mono_log_open_logcat;
 156         logger.writer = mono_log_write_logcat;
 157         logger.closer = mono_log_close_logcat;
 158         logger.dest   = (char*) dest;
 159 #elif defined (HOST_IOS)
 160         logger.opener = mono_log_open_asl;
 161         logger.writer = mono_log_write_asl;
 162         logger.closer = mono_log_close_asl;
 163         logger.dest   = (char*) dest;
 164 #else
 165         if (dest && !strcmp("flight-recorder", dest)) {
 166                 logger.opener = mono_log_open_recorder;
 167                 logger.writer = mono_log_write_recorder;
 168                 logger.closer = mono_log_close_recorder;
 169                 logger.dest   = (char *) dest;
 170
 171                 // Increase log level with flight recorder
 172                 if (mono_internal_current_level == G_LOG_LEVEL_ERROR || mono_internal_current_level == G_LOG_LEVEL_CRITICAL)
 173                         mono_trace_set_level (G_LOG_LEVEL_WARNING);
 174
 175         } else if (dest && !strcmp("syslog", dest)) {
 176                 logger.opener = mono_log_open_syslog;
 177                 logger.writer = mono_log_write_syslog;
 178                 logger.closer = mono_log_close_syslog;
 179                 logger.dest   = (char *) dest;
 180         } else {
 181                 logger.opener = mono_log_open_logfile;
 182                 logger.writer = mono_log_write_logfile;
 183                 logger.closer = mono_log_close_logfile;
 184                 logger.dest   = (char *) dest;
 185         }
 186 #endif
 187
 188         mono_trace_set_log_handler_internal(&logger, NULL);
 189 }
 190
 191 /**
 192  * mono_trace_set_logheader:
 193  * \param head Whether we want pid/date/time header on log messages
 194  * Sets the current logging header option.
 195  */
 196 void
 197 mono_trace_set_logheader_string(const char *head)
 198 {
 199         if (head == NULL) {
 200                 mono_trace_log_header = FALSE;
 201         } else {
 202                 mono_trace_log_header = TRUE;
 203         }
 204 }
 205
 206 /**
 207  * mono_trace_push:
 208  * \param level Verbose level to set
 209  * \param mask Mask of visible message types.
 210  * Saves the current values of level and mask then calls \c mono_trace_set
 211  * with the specified new values.
 212  */
 213 void
 214 mono_trace_push (GLogLevelFlags level, MonoTraceMask mask)
 215 {
 216         if(level_stack == NULL)
 217                 g_error("%s: cannot use mono_trace_push without calling mono_trace_init first.", __func__);
 218         else {
 219                 MonoLogLevelEntry *entry = (MonoLogLevelEntry *) g_malloc(sizeof(MonoLogLevelEntry));
 220                 entry->level    = mono_internal_current_level;
 221                 entry->mask             = mono_internal_current_mask;
 222
 223                 g_queue_push_head (level_stack, (gpointer)entry);
 224
 225                 /* Set the new level and mask
 226                  */
 227                 mono_internal_current_level = level;
 228                 mono_internal_current_mask  = mask;
 229         }
 230 }
 231
 232 /**
 233  * mono_trace_pop:
 234  *
 235  * Restores level and mask values saved from a previous call to mono_trace_push.
 236  */
 237 void
 238 mono_trace_pop (void)
 239 {
 240         if(level_stack == NULL)
 241                 g_error("%s: cannot use mono_trace_pop without calling mono_trace_init first.", __func__);
 242         else {
 243                 if(!g_queue_is_empty (level_stack)) {
 244                         MonoLogLevelEntry *entry = (MonoLogLevelEntry*)g_queue_pop_head (level_stack);
 245
 246                         /*      Restore previous level and mask
 247                          */
 248                         mono_internal_current_level = entry->level;
 249                         mono_internal_current_mask  = entry->mask;
 250
 251                         g_free (entry);
 252                 }
 253         }
 254 }
 255
 256
 257 void
 258 mono_trace_set_level_string (const char *value)
 259 {
 260         int i = 0;
 261         const char *valid_vals[] = {"error", "critical", "warning", "message", "info", "debug", NULL};
 262         const GLogLevelFlags valid_ids[] = {G_LOG_LEVEL_ERROR, G_LOG_LEVEL_CRITICAL, G_LOG_LEVEL_WARNING,
 263                                                                                 G_LOG_LEVEL_MESSAGE, G_LOG_LEVEL_INFO, G_LOG_LEVEL_DEBUG };
 264
 265         if(!value)
 266                 return;
 267
 268         while(valid_vals[i]) {
 269                 if(!strcmp(valid_vals[i], value)){
 270                         mono_trace_set_level(valid_ids[i]);
 271                         return;
 272                 }
 273                 i++;
 274         }
 275
 276         if(*value)
 277                 g_print("Unknown trace loglevel: %s\n", value);
 278 }
 279
 280 void
 281 mono_trace_set_mask_string (const char *value)
 282 {
 283         int i;
 284         const char *tok;
 285         guint32 flags = 0;
 286
 287         static const struct { const char * const flag; const MonoTraceMask mask; } flag_mask_map[] = {
 288                 { "asm", MONO_TRACE_ASSEMBLY },
 289                 { "type", MONO_TRACE_TYPE },
 290                 { "dll", MONO_TRACE_DLLIMPORT },
 291                 { "gc", MONO_TRACE_GC },
 292                 { "cfg", MONO_TRACE_CONFIG },
 293                 { "aot", MONO_TRACE_AOT },
 294                 { "security", MONO_TRACE_SECURITY },
 295                 { "threadpool", MONO_TRACE_THREADPOOL },
 296                 { "io-threadpool", MONO_TRACE_IO_SELECTOR },
 297                 { "io-selector", MONO_TRACE_IO_SELECTOR },
 298                 { "io-layer-process", MONO_TRACE_IO_LAYER_PROCESS },
 299                 { "io-layer-socket", MONO_TRACE_IO_LAYER_SOCKET },
 300                 { "io-layer-file", MONO_TRACE_IO_LAYER_FILE },
 301                 { "io-layer-console", MONO_TRACE_IO_LAYER_FILE },
 302                 { "io-layer-pipe", MONO_TRACE_IO_LAYER_FILE },
 303                 { "io-layer-event", MONO_TRACE_IO_LAYER_EVENT },
 304                 { "io-layer-semaphore", MONO_TRACE_IO_LAYER_SEMAPHORE },
 305                 { "io-layer-mutex", MONO_TRACE_IO_LAYER_MUTEX },
 306                 { "io-layer-handle", MONO_TRACE_IO_LAYER_HANDLE },
 307                 { "io-layer", (MonoTraceMask)(MONO_TRACE_IO_LAYER_PROCESS
 308                                | MONO_TRACE_IO_LAYER_SOCKET
 309                                | MONO_TRACE_IO_LAYER_FILE
 310                                | MONO_TRACE_IO_LAYER_EVENT
 311                                | MONO_TRACE_IO_LAYER_SEMAPHORE
 312                                | MONO_TRACE_IO_LAYER_MUTEX
 313                                | MONO_TRACE_IO_LAYER_HANDLE) },
 314                 { "w32handle", MONO_TRACE_IO_LAYER_HANDLE },
 315                 { "tailcall", MONO_TRACE_TAILCALL },
 316                 { "profiler", MONO_TRACE_PROFILER },
 317                 { "tiered", MONO_TRACE_TIERED },
 318                 { "all", (MonoTraceMask)~0 }, // FIXMEcxx there is a better way -- operator overloads of enums
 319                 { NULL, (MonoTraceMask)0 },
 320         };
 321
 322         if(!value)
 323                 return;
 324
 325         tok = value;
 326
 327         while (*tok) {
 328                 if (*tok == ',') {
 329                         tok++;
 330                         continue;
 331                 }
 332                 for (i = 0; flag_mask_map[i].flag; i++) {
 333                         size_t len = strlen (flag_mask_map[i].flag);
 334                         if (strncmp (tok, flag_mask_map[i].flag, len) == 0 && (tok[len] == 0 || tok[len] == ',')) {
 335                                 flags |= flag_mask_map[i].mask;
 336                                 tok += len;
 337                                 break;
 338                         }
 339                 }
 340                 if (!flag_mask_map[i].flag) {
 341                         g_print("Unknown trace flag: %s\n", tok);
 342                         break;
 343                 }
 344         }
 345
 346         mono_trace_set_mask ((MonoTraceMask) flags);
 347 }
 348
 349 /*
 350  * mono_trace_is_traced:
 351  *
 352  *   Returns whenever a message with @level and @mask will be printed or not.
 353  */
 354 gboolean
 355 mono_trace_is_traced (GLogLevelFlags level, MonoTraceMask mask)
 356 {
 357         return MONO_TRACE_IS_TRACED (level, mask);
 358 }
 359
 360 /**
 361  * log_level_get_name
 362  * @log_level severity level
 363  *
 364  * Convert log level into a string for legacy log handlers
 365  */
 366 static const char *
 367 log_level_get_name (GLogLevelFlags log_level)
 368 {
 369         switch (log_level & G_LOG_LEVEL_MASK) {
 370         case G_LOG_LEVEL_ERROR: return "error";
 371         case G_LOG_LEVEL_CRITICAL: return "critical";
 372         case G_LOG_LEVEL_WARNING: return "warning";
 373         case G_LOG_LEVEL_MESSAGE: return "message";
 374         case G_LOG_LEVEL_INFO: return "info";
 375         case G_LOG_LEVEL_DEBUG: return "debug";
 376         default: return "unknown";
 377         }
 378 }
 379
 380 /**
 381  * callback_adapter
 382  *
 383  *  @log_domain Message prefix
 384  *  @log_level Severity
 385  *  @message Message to be written
 386  *  @fatal Fatal flag - write then abort
 387  *  @user_data Argument passed to @callback
 388  *
 389  * This adapts the old callback writer exposed by MonoCallback to the newer method of
 390  * logging. We ignore the header request as legacy handlers never had headers.
 391  */
 392 static void
 393 callback_adapter (const char *domain, GLogLevelFlags level, mono_bool fatal, const char *message)
 394 {
 395         UserSuppliedLoggerUserData *ll = (UserSuppliedLoggerUserData*)logCallback.user_data;
 396
 397         ll->legacy_callback (domain, log_level_get_name(level), message, fatal, ll->user_data);
 398 }
 399
 400 static void
 401 eglib_log_adapter (const gchar *log_domain, GLogLevelFlags log_level, const gchar *message, gpointer user_data)
 402 {
 403         UserSuppliedLoggerUserData *ll = (UserSuppliedLoggerUserData*)logCallback.user_data;
 404
 405         ll->legacy_callback (log_domain, log_level_get_name (log_level), message, log_level & G_LOG_LEVEL_ERROR, ll->user_data);
 406 }
 407
 408 /**
 409  * legacy_opener
 410  *
 411  * Dummy routine for older style loggers
 412  */
 413 static void
 414 legacy_opener(const char *path, void *user_data)
 415 {
 416   /* nothing to do */
 417 }
 418
 419 /**
 420  * legacy_closer
 421  *
 422  * Cleanup routine for older style loggers
 423  */
 424 static void
 425 legacy_closer(void)
 426 {
 427         if (logCallback.user_data != NULL) {
 428                 g_free (logCallback.user_data); /* This is a UserSuppliedLoggerUserData struct */
 429                 logCallback.opener = NULL;
 430                 logCallback.writer = NULL;
 431                 logCallback.closer = NULL;
 432                 logCallback.user_data = NULL;
 433                 logCallback.header = FALSE;
 434         }
 435 }
 436
 437 /**
 438  *   mono_trace_set_log_handler:
 439  *
 440  *  @callback The callback that will replace the default logging handler
 441  *  @user_data Argument passed to @callback
 442  *
 443  * The log handler replaces the default runtime logger. All logging requests with be routed to it.
 444  * If the fatal argument in the callback is true, the callback must abort the current process. The runtime expects that
 445  * execution will not resume after a fatal error.
 446  */
 447 void
 448 mono_trace_set_log_handler (MonoLogCallback callback, void *user_data)
 449 {
 450         g_assert (callback);
 451
 452         if (logCallback.closer != NULL)
 453                 logCallback.closer();
 454         UserSuppliedLoggerUserData *ll = (UserSuppliedLoggerUserData*)g_malloc (sizeof (UserSuppliedLoggerUserData));
 455         ll->legacy_callback = callback;
 456         ll->user_data = user_data;
 457         logCallback.opener = legacy_opener;
 458         logCallback.writer = callback_adapter;
 459         logCallback.closer = legacy_closer;
 460         logCallback.user_data = ll;
 461         logCallback.dest = NULL;
 462
 463         g_log_set_default_handler (eglib_log_adapter, user_data);
 464 }
 465
 466 static void
 467 structured_log_adapter (const gchar *log_domain, GLogLevelFlags log_level, const gchar *message, gpointer user_data)
 468 {
 469         logCallback.writer (log_domain, log_level, logCallback.header, message);
 470 }
 471
 472 /**
 473  * mono_trace_set_log_handler_internal:
 474  * \param callback The callback that will replace the default logging handler
 475  * \param user_data Argument passed to \p callback
 476  * The log handler replaces the default runtime logger. All logging requests with be routed to it.
 477  * If the fatal argument in the callback is true, the callback must abort the current process. The runtime expects that
 478  * execution will not resume after a fatal error.
 479  */
 480 void
 481 mono_trace_set_log_handler_internal (MonoLogCallParm *callback, void *user_data)
 482 {
 483         g_assert (callback);
 484         if (logCallback.closer != NULL)
 485                 logCallback.closer();
 486         logCallback.opener = callback->opener;
 487         logCallback.writer = callback->writer;
 488         logCallback.closer = callback->closer;
 489         logCallback.header = mono_trace_log_header;
 490         logCallback.dest   = callback->dest;
 491         logCallback.opener (logCallback.dest, user_data);
 492
 493         g_log_set_default_handler (structured_log_adapter, user_data);
 494 }
 495
 496 static void
 497 print_handler (const char *string)
 498 {
 499         print_callback (string, TRUE);
 500 }
 501
 502 static void
 503 printerr_handler (const char *string)
 504 {
 505         printerr_callback (string, FALSE);
 506 }
 507
 508 /**
 509  * mono_trace_set_print_handler:
 510  * \param callback The callback that will replace the default runtime behavior for stdout output.
 511  * The print handler replaces the default runtime stdout output handler. This is used by free form output done by the runtime.
 512  */
 513 void
 514 mono_trace_set_print_handler (MonoPrintCallback callback)
 515 {
 516         g_assert (callback);
 517         print_callback = callback;
 518         g_set_print_handler (print_handler);
 519 }
 520
 521 /**
 522  * mono_trace_set_printerr_handler:
 523  * \param callback The callback that will replace the default runtime behavior for stderr output.
 524  * The print handler replaces the default runtime stderr output handler. This is used by free form output done by the runtime.
 525  */
 526 void
 527 mono_trace_set_printerr_handler (MonoPrintCallback callback)
 528 {
 529         g_assert (callback);
 530         printerr_callback = callback;
 531         g_set_printerr_handler (printerr_handler);
 532 }
 533
 534 static gchar
 535 conv_ascii_char (gchar s)
 536 {
 537         if (s < 0x20)
 538                 return '.';
 539         if (s > 0x7e)
 540                 return '.';
 541         return s;
 542 }
 543
 544 /* No memfree because only called during crash */
 545 void
 546 mono_dump_mem (gpointer d, int len)
 547 {
 548         guint8 *data = (guint8 *) d;
 549
 550         for (int off = 0; off < len; off += 0x10) {
 551                 g_async_safe_printf("%p  ", data + off);
 552
 553                 for (int i = 0; i < 0x10; i++) {
 554                         if ((i + off) >= len) {
 555                                 g_async_safe_printf("%s", "   ");
 556                         } else {
 557                                 g_async_safe_printf("%02x ", data [off + i]);
 558                         }
 559                 }
 560
 561                 g_async_safe_printf(" ");
 562
 563                 for (int i = 0; i < 0x10; i++) {
 564                         if ((i + off) >= len) {
 565                                 g_async_safe_printf("%s", " ");
 566                         } else {
 567                                 g_async_safe_printf("%c", conv_ascii_char (data [off + i]));
 568                         }
 569                 }
 570
 571                 g_async_safe_printf ("\n");
 572         }
 573 }