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