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