util/log.c

   1 /*
   2  * Logging support
   3  *
   4  *  Copyright (c) 2003 Fabrice Bellard
   5  *
   6  * This library is free software; you can redistribute it and/or
   7  * modify it under the terms of the GNU Lesser General Public
   8  * License as published by the Free Software Foundation; either
   9  * version 2 of the License, or (at your option) any later version.
  10  *
  11  * This library 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 GNU
  14  * Lesser General Public License for more details.
  15  *
  16  * You should have received a copy of the GNU Lesser General Public
  17  * License along with this library; if not, see <http://www.gnu.org/licenses/>.
  18  */
  19
  20 #include "qemu/osdep.h"
  21 #include "qemu/log.h"
  22 #include "qemu/range.h"
  23 #include "qemu/error-report.h"
  24 #include "qapi/error.h"
  25 #include "qemu/cutils.h"
  26 #include "trace/control.h"
  27 #include "qemu/thread.h"
  28 #include "qemu/lockable.h"
  29
  30 static char *logfilename;
  31 static QemuMutex qemu_logfile_mutex;
  32 QemuLogFile *qemu_logfile;
  33 int qemu_loglevel;
  34 static int log_append = 0;
  35 static GArray *debug_regions;
  36
  37 /* Return the number of characters emitted.  */
  38 int qemu_log(const char *fmt, ...)
  39 {
  40     int ret = 0;
  41     QemuLogFile *logfile;
  42
  43     rcu_read_lock();
  44     logfile = atomic_rcu_read(&qemu_logfile);
  45     if (logfile) {
  46         va_list ap;
  47         va_start(ap, fmt);
  48         ret = vfprintf(logfile->fd, fmt, ap);
  49         va_end(ap);
  50
  51         /* Don't pass back error results.  */
  52         if (ret < 0) {
  53             ret = 0;
  54         }
  55     }
  56     rcu_read_unlock();
  57     return ret;
  58 }
  59
  60 static void __attribute__((__constructor__)) qemu_logfile_init(void)
  61 {
  62     qemu_mutex_init(&qemu_logfile_mutex);
  63 }
  64
  65 static void qemu_logfile_free(QemuLogFile *logfile)
  66 {
  67     g_assert(logfile);
  68
  69     if (logfile->fd != stderr) {
  70         fclose(logfile->fd);
  71     }
  72     g_free(logfile);
  73 }
  74
  75 static bool log_uses_own_buffers;
  76
  77 /* enable or disable low levels log */
  78 void qemu_set_log(int log_flags)
  79 {
  80     bool need_to_open_file = false;
  81     QemuLogFile *logfile;
  82
  83     qemu_loglevel = log_flags;
  84 #ifdef CONFIG_TRACE_LOG
  85     qemu_loglevel |= LOG_TRACE;
  86 #endif
  87     /*
  88      * In all cases we only log if qemu_loglevel is set.
  89      * Also:
  90      *   If not daemonized we will always log either to stderr
  91      *     or to a file (if there is a logfilename).
  92      *   If we are daemonized,
  93      *     we will only log if there is a logfilename.
  94      */
  95     if (qemu_loglevel && (!is_daemonized() || logfilename)) {
  96         need_to_open_file = true;
  97     }
  98     QEMU_LOCK_GUARD(&qemu_logfile_mutex);
  99     if (qemu_logfile && !need_to_open_file) {
 100         logfile = qemu_logfile;
 101         atomic_rcu_set(&qemu_logfile, NULL);
 102         call_rcu(logfile, qemu_logfile_free, rcu);
 103     } else if (!qemu_logfile && need_to_open_file) {
 104         logfile = g_new0(QemuLogFile, 1);
 105         if (logfilename) {
 106             logfile->fd = fopen(logfilename, log_append ? "a" : "w");
 107             if (!logfile->fd) {
 108                 g_free(logfile);
 109                 perror(logfilename);
 110                 _exit(1);
 111             }
 112             /* In case we are a daemon redirect stderr to logfile */
 113             if (is_daemonized()) {
 114                 dup2(fileno(logfile->fd), STDERR_FILENO);
 115                 fclose(logfile->fd);
 116                 /* This will skip closing logfile in qemu_log_close() */
 117                 logfile->fd = stderr;
 118             }
 119         } else {
 120             /* Default to stderr if no log file specified */
 121             assert(!is_daemonized());
 122             logfile->fd = stderr;
 123         }
 124         /* must avoid mmap() usage of glibc by setting a buffer "by hand" */
 125         if (log_uses_own_buffers) {
 126             static char logfile_buf[4096];
 127
 128             setvbuf(logfile->fd, logfile_buf, _IOLBF, sizeof(logfile_buf));
 129         } else {
 130 #if defined(_WIN32)
 131             /* Win32 doesn't support line-buffering, so use unbuffered output. */
 132             setvbuf(logfile->fd, NULL, _IONBF, 0);
 133 #else
 134             setvbuf(logfile->fd, NULL, _IOLBF, 0);
 135 #endif
 136             log_append = 1;
 137         }
 138         atomic_rcu_set(&qemu_logfile, logfile);
 139     }
 140 }
 141
 142 void qemu_log_needs_buffers(void)
 143 {
 144     log_uses_own_buffers = true;
 145 }
 146
 147 /*
 148  * Allow the user to include %d in their logfile which will be
 149  * substituted with the current PID. This is useful for debugging many
 150  * nested linux-user tasks but will result in lots of logs.
 151  *
 152  * filename may be NULL. In that case, log output is sent to stderr
 153  */
 154 void qemu_set_log_filename(const char *filename, Error **errp)
 155 {
 156     g_free(logfilename);
 157     logfilename = NULL;
 158
 159     if (filename) {
 160             char *pidstr = strstr(filename, "%");
 161             if (pidstr) {
 162                 /* We only accept one %d, no other format strings */
 163                 if (pidstr[1] != 'd' || strchr(pidstr + 2, '%')) {
 164                     error_setg(errp, "Bad logfile format: %s", filename);
 165                     return;
 166                 } else {
 167                     logfilename = g_strdup_printf(filename, getpid());
 168                 }
 169             } else {
 170                 logfilename = g_strdup(filename);
 171             }
 172     }
 173
 174     qemu_log_close();
 175     qemu_set_log(qemu_loglevel);
 176 }
 177
 178 /* Returns true if addr is in our debug filter or no filter defined
 179  */
 180 bool qemu_log_in_addr_range(uint64_t addr)
 181 {
 182     if (debug_regions) {
 183         int i = 0;
 184         for (i = 0; i < debug_regions->len; i++) {
 185             Range *range = &g_array_index(debug_regions, Range, i);
 186             if (range_contains(range, addr)) {
 187                 return true;
 188             }
 189         }
 190         return false;
 191     } else {
 192         return true;
 193     }
 194 }
 195
 196
 197 void qemu_set_dfilter_ranges(const char *filter_spec, Error **errp)
 198 {
 199     gchar **ranges = g_strsplit(filter_spec, ",", 0);
 200     int i;
 201
 202     if (debug_regions) {
 203         g_array_unref(debug_regions);
 204         debug_regions = NULL;
 205     }
 206
 207     debug_regions = g_array_sized_new(FALSE, FALSE,
 208                                       sizeof(Range), g_strv_length(ranges));
 209     for (i = 0; ranges[i]; i++) {
 210         const char *r = ranges[i];
 211         const char *range_op, *r2, *e;
 212         uint64_t r1val, r2val, lob, upb;
 213         struct Range range;
 214
 215         range_op = strstr(r, "-");
 216         r2 = range_op ? range_op + 1 : NULL;
 217         if (!range_op) {
 218             range_op = strstr(r, "+");
 219             r2 = range_op ? range_op + 1 : NULL;
 220         }
 221         if (!range_op) {
 222             range_op = strstr(r, "..");
 223             r2 = range_op ? range_op + 2 : NULL;
 224         }
 225         if (!range_op) {
 226             error_setg(errp, "Bad range specifier");
 227             goto out;
 228         }
 229
 230         if (qemu_strtou64(r, &e, 0, &r1val)
 231             || e != range_op) {
 232             error_setg(errp, "Invalid number to the left of %.*s",
 233                        (int)(r2 - range_op), range_op);
 234             goto out;
 235         }
 236         if (qemu_strtou64(r2, NULL, 0, &r2val)) {
 237             error_setg(errp, "Invalid number to the right of %.*s",
 238                        (int)(r2 - range_op), range_op);
 239             goto out;
 240         }
 241
 242         switch (*range_op) {
 243         case '+':
 244             lob = r1val;
 245             upb = r1val + r2val - 1;
 246             break;
 247         case '-':
 248             upb = r1val;
 249             lob = r1val - (r2val - 1);
 250             break;
 251         case '.':
 252             lob = r1val;
 253             upb = r2val;
 254             break;
 255         default:
 256             g_assert_not_reached();
 257         }
 258         if (lob > upb) {
 259             error_setg(errp, "Invalid range");
 260             goto out;
 261         }
 262         range_set_bounds(&range, lob, upb);
 263         g_array_append_val(debug_regions, range);
 264     }
 265 out:
 266     g_strfreev(ranges);
 267 }
 268
 269 /* fflush() the log file */
 270 void qemu_log_flush(void)
 271 {
 272     QemuLogFile *logfile;
 273
 274     rcu_read_lock();
 275     logfile = atomic_rcu_read(&qemu_logfile);
 276     if (logfile) {
 277         fflush(logfile->fd);
 278     }
 279     rcu_read_unlock();
 280 }
 281
 282 /* Close the log file */
 283 void qemu_log_close(void)
 284 {
 285     QemuLogFile *logfile;
 286
 287     qemu_mutex_lock(&qemu_logfile_mutex);
 288     logfile = qemu_logfile;
 289
 290     if (logfile) {
 291         atomic_rcu_set(&qemu_logfile, NULL);
 292         call_rcu(logfile, qemu_logfile_free, rcu);
 293     }
 294     qemu_mutex_unlock(&qemu_logfile_mutex);
 295 }
 296
 297 const QEMULogItem qemu_log_items[] = {
 298     { CPU_LOG_TB_OUT_ASM, "out_asm",
 299       "show generated host assembly code for each compiled TB" },
 300     { CPU_LOG_TB_IN_ASM, "in_asm",
 301       "show target assembly code for each compiled TB" },
 302     { CPU_LOG_TB_OP, "op",
 303       "show micro ops for each compiled TB" },
 304     { CPU_LOG_TB_OP_OPT, "op_opt",
 305       "show micro ops after optimization" },
 306     { CPU_LOG_TB_OP_IND, "op_ind",
 307       "show micro ops before indirect lowering" },
 308     { CPU_LOG_INT, "int",
 309       "show interrupts/exceptions in short format" },
 310     { CPU_LOG_EXEC, "exec",
 311       "show trace before each executed TB (lots of logs)" },
 312     { CPU_LOG_TB_CPU, "cpu",
 313       "show CPU registers before entering a TB (lots of logs)" },
 314     { CPU_LOG_TB_FPU, "fpu",
 315       "include FPU registers in the 'cpu' logging" },
 316     { CPU_LOG_MMU, "mmu",
 317       "log MMU-related activities" },
 318     { CPU_LOG_PCALL, "pcall",
 319       "x86 only: show protected mode far calls/returns/exceptions" },
 320     { CPU_LOG_RESET, "cpu_reset",
 321       "show CPU state before CPU resets" },
 322     { LOG_UNIMP, "unimp",
 323       "log unimplemented functionality" },
 324     { LOG_GUEST_ERROR, "guest_errors",
 325       "log when the guest OS does something invalid (eg accessing a\n"
 326       "non-existent register)" },
 327     { CPU_LOG_PAGE, "page",
 328       "dump pages at beginning of user mode emulation" },
 329     { CPU_LOG_TB_NOCHAIN, "nochain",
 330       "do not chain compiled TBs so that \"exec\" and \"cpu\" show\n"
 331       "complete traces" },
 332 #ifdef CONFIG_PLUGIN
 333     { CPU_LOG_PLUGIN, "plugin", "output from TCG plugins\n"},
 334 #endif
 335     { LOG_STRACE, "strace",
 336       "log every user-mode syscall, its input, and its result" },
 337     { 0, NULL, NULL },
 338 };
 339
 340 /* takes a comma separated list of log masks. Return 0 if error. */
 341 int qemu_str_to_log_mask(const char *str)
 342 {
 343     const QEMULogItem *item;
 344     int mask = 0;
 345     char **parts = g_strsplit(str, ",", 0);
 346     char **tmp;
 347
 348     for (tmp = parts; tmp && *tmp; tmp++) {
 349         if (g_str_equal(*tmp, "all")) {
 350             for (item = qemu_log_items; item->mask != 0; item++) {
 351                 mask |= item->mask;
 352             }
 353 #ifdef CONFIG_TRACE_LOG
 354         } else if (g_str_has_prefix(*tmp, "trace:") && (*tmp)[6] != '\0') {
 355             trace_enable_events((*tmp) + 6);
 356             mask |= LOG_TRACE;
 357 #endif
 358         } else {
 359             for (item = qemu_log_items; item->mask != 0; item++) {
 360                 if (g_str_equal(*tmp, item->name)) {
 361                     goto found;
 362                 }
 363             }
 364             goto error;
 365         found:
 366             mask |= item->mask;
 367         }
 368     }
 369
 370     g_strfreev(parts);
 371     return mask;
 372
 373  error:
 374     g_strfreev(parts);
 375     return 0;
 376 }
 377
 378 void qemu_print_log_usage(FILE *f)
 379 {
 380     const QEMULogItem *item;
 381     fprintf(f, "Log items (comma separated):\n");
 382     for (item = qemu_log_items; item->mask != 0; item++) {
 383         fprintf(f, "%-15s %s\n", item->name, item->help);
 384     }
 385 #ifdef CONFIG_TRACE_LOG
 386     fprintf(f, "trace:PATTERN   enable trace events\n");
 387     fprintf(f, "\nUse \"-d trace:help\" to get a list of trace events.\n\n");
 388 #endif
 389 }