logging.c 31.5 KB
Newer Older
1 2 3
/*
 * logging.c: internal logging and debugging
 *
4
 * Copyright (C) 2008, 2010-2011 Red Hat, Inc.
5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23
 *
 * This library is free software; you can redistribute it and/or
 * modify it under the terms of the GNU Lesser General Public
 * License as published by the Free Software Foundation; either
 * version 2.1 of the License, or (at your option) any later version.
 *
 * This library is distributed in the hope that it will be useful,
 * but WITHOUT ANY WARRANTY; without even the implied warranty of
 * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the GNU
 * Lesser General Public License for more details.
 *
 * You should have received a copy of the GNU Lesser General Public
 * License along with this library; if not, write to the Free Software
 * Foundation, Inc., 59 Temple Place, Suite 330, Boston, MA 02111-1307  USA
 *
 */

#include <config.h>

D
Daniel Veillard 已提交
24 25 26 27 28 29 30 31
#include <stdio.h>
#include <stdarg.h>
#include <stdlib.h>
#include <time.h>
#include <sys/time.h>
#include <sys/types.h>
#include <sys/stat.h>
#include <fcntl.h>
32
#include <unistd.h>
33
#include <signal.h>
D
Daniel Veillard 已提交
34
#if HAVE_SYSLOG_H
35
# include <syslog.h>
D
Daniel Veillard 已提交
36 37
#endif

38
#include "ignore-value.h"
39
#include "virterror_internal.h"
40
#include "logging.h"
D
Daniel Veillard 已提交
41 42
#include "memory.h"
#include "util.h"
43
#include "buf.h"
44
#include "threads.h"
45
#include "files.h"
46

47 48
#define VIR_FROM_THIS VIR_FROM_NONE

D
Daniel Veillard 已提交
49 50 51 52
/*
 * A logging buffer to keep some history over logs
 */

53 54
static int virLogSize = 64 * 1024;
static char *virLogBuffer = NULL;
D
Daniel Veillard 已提交
55 56 57 58 59 60 61 62 63 64 65 66 67 68 69 70 71 72 73 74 75 76 77
static int virLogLen = 0;
static int virLogStart = 0;
static int virLogEnd = 0;

/*
 * Filters are used to refine the rules on what to keep or drop
 * based on a matching pattern (currently a substring)
 */
struct _virLogFilter {
    const char *match;
    int priority;
};
typedef struct _virLogFilter virLogFilter;
typedef virLogFilter *virLogFilterPtr;

static virLogFilterPtr virLogFilters = NULL;
static int virLogNbFilters = 0;

/*
 * Outputs are used to emit the messages retained
 * after filtering, multiple output can be used simultaneously
 */
struct _virLogOutput {
78
    bool logVersion;
D
Daniel Veillard 已提交
79 80 81 82
    void *data;
    virLogOutputFunc f;
    virLogCloseFunc c;
    int priority;
83 84
    virLogDestination dest;
    const char *name;
D
Daniel Veillard 已提交
85 86 87 88 89 90 91 92 93 94
};
typedef struct _virLogOutput virLogOutput;
typedef virLogOutput *virLogOutputPtr;

static virLogOutputPtr virLogOutputs = NULL;
static int virLogNbOutputs = 0;

/*
 * Default priorities
 */
95
static virLogPriority virLogDefaultPriority = VIR_LOG_DEFAULT;
D
Daniel Veillard 已提交
96 97 98

static int virLogResetFilters(void);
static int virLogResetOutputs(void);
99 100 101
static int virLogOutputToFd(const char *category, int priority,
                            const char *funcname, long long linenr,
                            const char *str, int len, void *data);
D
Daniel Veillard 已提交
102 103 104 105

/*
 * Logs accesses must be serialized though a mutex
 */
106
virMutex virLogMutex;
D
Daniel Veillard 已提交
107

108
void virLogLock(void)
D
Daniel Veillard 已提交
109
{
110
    virMutexLock(&virLogMutex);
D
Daniel Veillard 已提交
111
}
112
void virLogUnlock(void)
D
Daniel Veillard 已提交
113
{
114
    virMutexUnlock(&virLogMutex);
D
Daniel Veillard 已提交
115 116
}

117 118
static const char *virLogOutputString(virLogDestination ldest) {
    switch (ldest) {
119 120 121 122 123 124
    case VIR_LOG_TO_STDERR:
        return "stderr";
    case VIR_LOG_TO_SYSLOG:
        return "syslog";
    case VIR_LOG_TO_FILE:
        return "file";
125
    }
126
    return "unknown";
127
}
D
Daniel Veillard 已提交
128 129 130

static const char *virLogPriorityString(virLogPriority lvl) {
    switch (lvl) {
131 132 133 134 135 136 137 138
    case VIR_LOG_DEBUG:
        return "debug";
    case VIR_LOG_INFO:
        return "info";
    case VIR_LOG_WARN:
        return "warning";
    case VIR_LOG_ERROR:
        return "error";
D
Daniel Veillard 已提交
139
    }
140
    return "unknown";
D
Daniel Veillard 已提交
141 142 143 144 145 146 147 148 149 150 151 152
}

static int virLogInitialized = 0;

/**
 * virLogStartup:
 *
 * Initialize the logging module
 *
 * Returns 0 if successful, and -1 in case or error
 */
int virLogStartup(void) {
153 154
    const char *pbm = NULL;

D
Daniel Veillard 已提交
155
    if (virLogInitialized)
156
        return -1;
157 158 159 160

    if (virMutexInit(&virLogMutex) < 0)
        return -1;

D
Daniel Veillard 已提交
161 162
    virLogInitialized = 1;
    virLogLock();
163
    if (VIR_ALLOC_N(virLogBuffer, virLogSize + 1) < 0) {
164 165 166 167 168 169
        /*
         * The debug buffer is not a critical component, allow startup
         * even in case of failure to allocate it in case of a
         * configuration mistake.
         */
        virLogSize = 64 * 1024;
170
        if (VIR_ALLOC_N(virLogBuffer, virLogSize + 1) < 0) {
171 172 173 174 175 176
            pbm = "Failed to allocate debug buffer: deactivating debug log\n";
            virLogSize = 0;
        } else {
            pbm = "Failed to allocate debug buffer: reduced to 64 kB\n";
        }
    }
D
Daniel Veillard 已提交
177 178 179
    virLogLen = 0;
    virLogStart = 0;
    virLogEnd = 0;
180
    virLogDefaultPriority = VIR_LOG_DEFAULT;
D
Daniel Veillard 已提交
181
    virLogUnlock();
182
    if (pbm)
183
        VIR_WARN("%s", pbm);
184
    return 0;
D
Daniel Veillard 已提交
185 186
}

187 188 189 190 191 192 193 194 195 196 197 198 199 200 201 202 203 204 205 206 207 208 209 210 211 212 213 214
/**
 * virLogSetBufferSize:
 * @size: size of the buffer in kilobytes or <= 0 to deactivate
 *
 * Dynamically set the size or deactivate the logging buffer used to keep
 * a trace of all recent debug output. Note that the content of the buffer
 * is lost if it gets reallocated.
 *
 * Return -1 in case of failure or 0 in case of success
 */
extern int
virLogSetBufferSize(int size) {
    int ret = 0;
    int oldsize;
    char *oldLogBuffer;
    const char *pbm = NULL;

    if (size < 0)
        size = 0;

    if ((virLogInitialized == 0) || (size * 1024 == virLogSize))
        return ret;

    virLogLock();

    oldsize = virLogSize;
    oldLogBuffer = virLogBuffer;

215
    if (INT_MAX / 1024 <= size) {
216 217 218 219 220 221
        pbm = "Requested log size of %d kB too large\n";
        ret = -1;
        goto error;
    }

    virLogSize = size * 1024;
222
    if (VIR_ALLOC_N(virLogBuffer, virLogSize + 1) < 0) {
223 224 225 226 227 228 229 230 231 232 233 234 235 236 237 238 239 240
        pbm = "Failed to allocate debug buffer of %d kB\n";
        virLogBuffer = oldLogBuffer;
        virLogSize = oldsize;
        ret = -1;
        goto error;
    }
    VIR_FREE(oldLogBuffer);
    virLogLen = 0;
    virLogStart = 0;
    virLogEnd = 0;

error:
    virLogUnlock();
    if (pbm)
        VIR_ERROR(pbm, size);
    return ret;
}

D
Daniel Veillard 已提交
241 242 243 244 245 246 247 248 249
/**
 * virLogReset:
 *
 * Reset the logging module to its default initial state
 *
 * Returns 0 if successful, and -1 in case or error
 */
int virLogReset(void) {
    if (!virLogInitialized)
250
        return virLogStartup();
D
Daniel Veillard 已提交
251 252 253 254 255 256 257

    virLogLock();
    virLogResetFilters();
    virLogResetOutputs();
    virLogLen = 0;
    virLogStart = 0;
    virLogEnd = 0;
258
    virLogDefaultPriority = VIR_LOG_DEFAULT;
D
Daniel Veillard 已提交
259
    virLogUnlock();
260
    return 0;
D
Daniel Veillard 已提交
261 262 263 264 265 266 267 268 269 270 271 272 273 274 275
}
/**
 * virLogShutdown:
 *
 * Shutdown the logging module
 */
void virLogShutdown(void) {
    if (!virLogInitialized)
        return;
    virLogLock();
    virLogResetFilters();
    virLogResetOutputs();
    virLogLen = 0;
    virLogStart = 0;
    virLogEnd = 0;
276
    VIR_FREE(virLogBuffer);
D
Daniel Veillard 已提交
277
    virLogUnlock();
278
    virMutexDestroy(&virLogMutex);
D
Daniel Veillard 已提交
279 280 281 282 283 284 285 286 287
    virLogInitialized = 0;
}

/*
 * Store a string in the ring buffer
 */
static void virLogStr(const char *str, int len) {
    int tmp;

288
    if ((str == NULL) || (virLogBuffer == NULL) || (virLogSize <= 0))
D
Daniel Veillard 已提交
289 290 291
        return;
    if (len <= 0)
        len = strlen(str);
E
Eric Blake 已提交
292
    if (len >= virLogSize)
D
Daniel Veillard 已提交
293 294 295 296 297 298
        return;
    virLogLock();

    /*
     * copy the data and reset the end, we cycle over the end of the buffer
     */
299 300
    if (virLogEnd + len >= virLogSize) {
        tmp = virLogSize - virLogEnd;
D
Daniel Veillard 已提交
301
        memcpy(&virLogBuffer[virLogEnd], str, tmp);
302
        memcpy(&virLogBuffer[0], &str[tmp], len - tmp);
D
Daniel Veillard 已提交
303 304 305 306 307
        virLogEnd = len - tmp;
    } else {
        memcpy(&virLogBuffer[virLogEnd], str, len);
        virLogEnd += len;
    }
E
Eric Blake 已提交
308
    virLogBuffer[virLogEnd] = 0;
D
Daniel Veillard 已提交
309 310 311 312
    /*
     * Update the log length, and if full move the start index
     */
    virLogLen += len;
313 314 315
    if (virLogLen > virLogSize) {
        tmp = virLogLen - virLogSize;
        virLogLen = virLogSize;
D
Daniel Veillard 已提交
316
        virLogStart += tmp;
317 318
        if (virLogStart >= virLogSize)
            virLogStart -= virLogSize;
D
Daniel Veillard 已提交
319 320 321 322
    }
    virLogUnlock();
}

323 324 325
static void virLogDumpAllFD(const char *msg, int len) {
    int i, found = 0;

326 327 328
    if (len <= 0)
        len = strlen(msg);

329 330 331 332 333 334 335 336 337 338 339 340 341 342 343 344 345 346 347 348 349 350
    for (i = 0; i < virLogNbOutputs;i++) {
        if (virLogOutputs[i].f == virLogOutputToFd) {
            int fd = (long) virLogOutputs[i].data;

            if (fd >= 0) {
                ignore_value (safewrite(fd, msg, len));
                found = 1;
            }
        }
    }
    if (!found)
        ignore_value (safewrite(STDERR_FILENO, msg, len));
}

/**
 * virLogEmergencyDumpAll:
 * @signum: the signal number
 *
 * Emergency function called, possibly from a signal handler.
 * It need to output the debug ring buffer through the log
 * output which are safe to use from a signal handler.
 * In case none is found it is emitted to standard error.
D
Daniel Veillard 已提交
351
 */
352 353
void
virLogEmergencyDumpAll(int signum) {
354
    int len;
C
Christophe Fergeau 已提交
355
    int oldLogStart, oldLogLen;
D
Daniel Veillard 已提交
356

357
    switch (signum) {
D
Daniel Veillard 已提交
358
#ifdef SIGFPE
359 360 361
        case SIGFPE:
            virLogDumpAllFD( "Caught signal Floating-point exception", -1);
            break;
D
Daniel Veillard 已提交
362 363
#endif
#ifdef SIGSEGV
364 365 366
        case SIGSEGV:
            virLogDumpAllFD( "Caught Segmentation violation", -1);
            break;
D
Daniel Veillard 已提交
367 368
#endif
#ifdef SIGILL
369 370 371
        case SIGILL:
            virLogDumpAllFD( "Caught illegal instruction", -1);
            break;
D
Daniel Veillard 已提交
372 373
#endif
#ifdef SIGABRT
374 375 376
        case SIGABRT:
            virLogDumpAllFD( "Caught abort signal", -1);
            break;
D
Daniel Veillard 已提交
377 378
#endif
#ifdef SIGBUS
379 380 381
        case SIGBUS:
            virLogDumpAllFD( "Caught bus error", -1);
            break;
D
Daniel Veillard 已提交
382 383
#endif
#ifdef SIGUSR2
384 385 386
        case SIGUSR2:
            virLogDumpAllFD( "Caught User-defined signal 2", -1);
            break;
D
Daniel Veillard 已提交
387
#endif
388 389 390 391
        default:
            virLogDumpAllFD( "Caught unexpected signal", -1);
            break;
    }
392 393
    if ((virLogBuffer == NULL) || (virLogSize <= 0)) {
        virLogDumpAllFD(" internal log buffer deactivated\n", -1);
394
        return;
395
    }
396

397 398
    virLogDumpAllFD(" dumping internal log buffer:\n", -1);
    virLogDumpAllFD("\n\n    ====== start of log =====\n\n", -1);
399 400 401 402 403 404 405 406 407 408 409 410 411 412 413 414 415 416 417 418 419 420

    /*
     * Since we can't lock the buffer safely from a signal handler
     * we mark it as empty in case of concurrent access, and proceed
     * with the data, at worse we will output something a bit weird
     * if another thread start logging messages at the same time.
     * Note that virLogStr() uses virLogEnd for the computations and
     * writes to the buffer and only then updates virLogLen and virLogStart
     * so it's best to reset it first.
     */
    oldLogStart = virLogStart;
    oldLogLen = virLogLen;
    virLogEnd = 0;
    virLogLen = 0;
    virLogStart = 0;

    while (oldLogLen > 0) {
        if (oldLogStart + oldLogLen < virLogSize) {
            virLogBuffer[oldLogStart + oldLogLen] = 0;
            virLogDumpAllFD(&virLogBuffer[oldLogStart], oldLogLen);
            oldLogStart += oldLogLen;
            oldLogLen = 0;
D
Daniel Veillard 已提交
421
        } else {
422
            len = virLogSize - oldLogStart;
423
            virLogBuffer[virLogSize] = 0;
424 425 426
            virLogDumpAllFD(&virLogBuffer[oldLogStart], len);
            oldLogLen -= len;
            oldLogStart = 0;
D
Daniel Veillard 已提交
427 428
        }
    }
429
    virLogDumpAllFD("\n\n     ====== end of log =====\n\n", -1);
D
Daniel Veillard 已提交
430
}
431

D
Daniel Veillard 已提交
432 433 434 435 436 437 438 439 440 441 442
/**
 * virLogSetDefaultPriority:
 * @priority: the default priority level
 *
 * Set the default priority level, i.e. any logged data of a priority
 * equal or superior to this level will be logged, unless a specific rule
 * was defined for the log category of the message.
 *
 * Returns 0 if successful, -1 in case of error.
 */
int virLogSetDefaultPriority(int priority) {
443
    if ((priority < VIR_LOG_DEBUG) || (priority > VIR_LOG_ERROR)) {
444
        VIR_WARN("Ignoring invalid log level setting.");
445
        return -1;
446
    }
D
Daniel Veillard 已提交
447 448 449
    if (!virLogInitialized)
        virLogStartup();
    virLogDefaultPriority = priority;
450
    return 0;
D
Daniel Veillard 已提交
451 452 453 454 455 456 457 458 459 460 461 462 463 464 465 466
}

/**
 * virLogResetFilters:
 *
 * Removes the set of logging filters defined.
 *
 * Returns the number of filters removed
 */
static int virLogResetFilters(void) {
    int i;

    for (i = 0; i < virLogNbFilters;i++)
        VIR_FREE(virLogFilters[i].match);
    VIR_FREE(virLogFilters);
    virLogNbFilters = 0;
467
    return i;
D
Daniel Veillard 已提交
468 469 470 471 472 473 474 475 476 477 478 479 480 481 482 483 484 485 486 487 488 489
}

/**
 * virLogDefineFilter:
 * @match: the pattern to match
 * @priority: the priority to give to messages matching the pattern
 * @flags: extra flag, currently unused
 *
 * Defines a pattern used for log filtering, it allow to select or
 * reject messages independently of the default priority.
 * The filter defines a rules that will apply only to messages matching
 * the pattern (currently if @match is a substring of the message category)
 *
 * Returns -1 in case of failure or the filter number if successful
 */
int virLogDefineFilter(const char *match, int priority,
                       int flags ATTRIBUTE_UNUSED) {
    int i;
    char *mdup = NULL;

    if ((match == NULL) || (priority < VIR_LOG_DEBUG) ||
        (priority > VIR_LOG_ERROR))
490
        return -1;
D
Daniel Veillard 已提交
491 492 493 494 495 496 497 498 499 500

    virLogLock();
    for (i = 0;i < virLogNbFilters;i++) {
        if (STREQ(virLogFilters[i].match, match)) {
            virLogFilters[i].priority = priority;
            goto cleanup;
        }
    }

    mdup = strdup(match);
501
    if (mdup == NULL) {
D
Daniel Veillard 已提交
502 503 504 505 506 507 508 509 510 511 512 513 514 515
        i = -1;
        goto cleanup;
    }
    i = virLogNbFilters;
    if (VIR_REALLOC_N(virLogFilters, virLogNbFilters + 1)) {
        i = -1;
        VIR_FREE(mdup);
        goto cleanup;
    }
    virLogFilters[i].match = mdup;
    virLogFilters[i].priority = priority;
    virLogNbFilters++;
cleanup:
    virLogUnlock();
516
    return i;
D
Daniel Veillard 已提交
517 518 519 520 521 522 523 524 525 526 527 528 529 530 531 532 533 534 535 536 537 538 539 540
}

/**
 * virLogFiltersCheck:
 * @input: the input string
 *
 * Check the input of the message against the existing filters. Currently
 * the match is just a substring check of the category used as the input
 * string, a more subtle approach could be used instead
 *
 * Returns 0 if not matched or the new priority if found.
 */
static int virLogFiltersCheck(const char *input) {
    int ret = 0;
    int i;

    virLogLock();
    for (i = 0;i < virLogNbFilters;i++) {
        if (strstr(input, virLogFilters[i].match)) {
            ret = virLogFilters[i].priority;
            break;
        }
    }
    virLogUnlock();
541
    return ret;
D
Daniel Veillard 已提交
542 543 544 545 546 547 548 549 550 551 552 553 554 555 556
}

/**
 * virLogResetOutputs:
 *
 * Removes the set of logging output defined.
 *
 * Returns the number of output removed
 */
static int virLogResetOutputs(void) {
    int i;

    for (i = 0;i < virLogNbOutputs;i++) {
        if (virLogOutputs[i].c != NULL)
            virLogOutputs[i].c(virLogOutputs[i].data);
557
        VIR_FREE(virLogOutputs[i].name);
D
Daniel Veillard 已提交
558 559 560 561
    }
    VIR_FREE(virLogOutputs);
    i = virLogNbOutputs;
    virLogNbOutputs = 0;
562
    return i;
D
Daniel Veillard 已提交
563 564 565 566 567
}

/**
 * virLogDefineOutput:
 * @f: the function to call to output a message
568
 * @c: the function to call to close the output (or NULL)
D
Daniel Veillard 已提交
569 570
 * @data: extra data passed as first arg to the function
 * @priority: minimal priority for this filter, use 0 for none
571 572
 * @dest: where to send output of this priority
 * @name: optional name data associated with an output
D
Daniel Veillard 已提交
573 574 575 576 577 578 579 580
 * @flags: extra flag, currently unused
 *
 * Defines an output function for log messages. Each message once
 * gone though filtering is emitted through each registered output.
 *
 * Returns -1 in case of failure or the output number if successful
 */
int virLogDefineOutput(virLogOutputFunc f, virLogCloseFunc c, void *data,
581 582
                       int priority, int dest, const char *name,
                       int flags ATTRIBUTE_UNUSED) {
D
Daniel Veillard 已提交
583
    int ret = -1;
584
    char *ndup = NULL;
D
Daniel Veillard 已提交
585 586

    if (f == NULL)
587
        return -1;
D
Daniel Veillard 已提交
588

589 590
    if (dest == VIR_LOG_TO_SYSLOG || dest == VIR_LOG_TO_FILE) {
        if (name == NULL)
591
            return -1;
592 593
        ndup = strdup(name);
        if (ndup == NULL)
594
            return -1;
595 596
    }

D
Daniel Veillard 已提交
597 598
    virLogLock();
    if (VIR_REALLOC_N(virLogOutputs, virLogNbOutputs + 1)) {
599
        VIR_FREE(ndup);
D
Daniel Veillard 已提交
600 601 602
        goto cleanup;
    }
    ret = virLogNbOutputs++;
603
    virLogOutputs[ret].logVersion = true;
D
Daniel Veillard 已提交
604 605 606 607
    virLogOutputs[ret].f = f;
    virLogOutputs[ret].c = c;
    virLogOutputs[ret].data = data;
    virLogOutputs[ret].priority = priority;
608 609
    virLogOutputs[ret].dest = dest;
    virLogOutputs[ret].name = ndup;
D
Daniel Veillard 已提交
610 611
cleanup:
    virLogUnlock();
612
    return ret;
D
Daniel Veillard 已提交
613 614
}

615 616 617 618 619 620 621 622 623 624
static int
virLogFormatString(char **msg,
                   const char *funcname,
                   long long linenr,
                   struct tm *time_info,
                   struct timeval *cur_time,
                   int priority,
                   const char *str)
{
    int ret;
625 626 627 628 629 630 631 632

    /*
     * Be careful when changing the following log message formatting, we rely
     * on it when stripping libvirt debug messages from qemu log files. So when
     * changing this, you might also need to change the code there.
     * virLogFormatString() function name is mentioned there so it's sufficient
     * to just grep for it to find the right place.
     */
633 634 635 636 637 638 639 640 641 642 643 644 645 646 647 648 649 650 651 652 653 654 655 656 657 658 659 660 661 662 663 664 665 666 667 668 669 670 671
    if ((funcname != NULL)) {
        ret = virAsprintf(msg, "%02d:%02d:%02d.%03d: %d: %s : %s:%lld : %s\n",
                          time_info->tm_hour, time_info->tm_min,
                          time_info->tm_sec, (int) cur_time->tv_usec / 1000,
                          virThreadSelfID(),
                          virLogPriorityString(priority), funcname, linenr, str);
    } else {
        ret = virAsprintf(msg, "%02d:%02d:%02d.%03d: %d: %s : %s\n",
                          time_info->tm_hour, time_info->tm_min,
                          time_info->tm_sec, (int) cur_time->tv_usec / 1000,
                          virThreadSelfID(),
                          virLogPriorityString(priority), str);
    }
    return ret;
}

static int
virLogVersionString(char **msg,
                    struct tm *time_info,
                    struct timeval *cur_time)
{
#ifdef PACKAGER_VERSION
# ifdef PACKAGER
#  define LOG_VERSION_STRING \
    "libvirt version: " VERSION ", package: " PACKAGER_VERSION " (" PACKAGER ")"
# else
#  define LOG_VERSION_STRING \
    "libvirt version: " VERSION ", package: " PACKAGER_VERSION
# endif
#else
# define LOG_VERSION_STRING  \
    "libvirt version: " VERSION
#endif

    return virLogFormatString(msg, NULL, 0,
                              time_info, cur_time,
                              VIR_LOG_INFO, LOG_VERSION_STRING);
}

D
Daniel Veillard 已提交
672 673 674 675
/**
 * virLogMessage:
 * @category: where is that message coming from
 * @priority: the priority level
676 677
 * @funcname: the function emitting the (debug) message
 * @linenr: line where the message was emitted
D
Daniel Veillard 已提交
678 679 680 681 682 683 684
 * @flags: extra flags, 1 if coming from the error handler
 * @fmt: the string format
 * @...: the arguments
 *
 * Call the libvirt logger with some informations. Based on the configuration
 * the message may be stored, sent to output or just discarded
 */
685 686
void virLogMessage(const char *category, int priority, const char *funcname,
                   long long linenr, int flags, const char *fmt, ...) {
687
    static bool logVersionStderr = true;
D
Daniel Veillard 已提交
688
    char *str = NULL;
689
    char *msg = NULL;
D
Daniel Veillard 已提交
690 691
    struct timeval cur_time;
    struct tm time_info;
692
    int len, fprio, i, ret;
693
    int saved_errno = errno;
694
    int emit = 1;
E
Eric Blake 已提交
695
    va_list ap;
D
Daniel Veillard 已提交
696 697 698 699 700

    if (!virLogInitialized)
        virLogStartup();

    if (fmt == NULL)
701
        goto cleanup;
D
Daniel Veillard 已提交
702 703 704 705 706 707 708

    /*
     * check against list of specific logging patterns
     */
    fprio = virLogFiltersCheck(category);
    if (fprio == 0) {
        if (priority < virLogDefaultPriority)
709
            emit = 0;
710
    } else if (priority < fprio) {
711
        emit = 0;
712
    }
D
Daniel Veillard 已提交
713

714 715 716
    if ((emit == 0) && ((virLogBuffer == NULL) || (virLogSize <= 0)))
        goto cleanup;

D
Daniel Veillard 已提交
717 718 719
    /*
     * serialize the error message, add level and timestamp
     */
E
Eric Blake 已提交
720 721 722
    va_start(ap, fmt);
    if (virVasprintf(&str, fmt, ap) < 0) {
        va_end(ap);
723
        goto cleanup;
E
Eric Blake 已提交
724 725
    }
    va_end(ap);
D
Daniel Veillard 已提交
726 727 728
    gettimeofday(&cur_time, NULL);
    localtime_r(&cur_time.tv_sec, &time_info);

729 730 731
    ret = virLogFormatString(&msg, funcname, linenr,
                             &time_info, &cur_time,
                             priority, str);
732
    VIR_FREE(str);
733 734
    if (ret < 0)
        goto cleanup;
D
Daniel Veillard 已提交
735 736

    /*
737 738
     * Log based on defaults, first store in the history buffer,
     * then if emit push the message on the outputs defined, if none
D
Daniel Veillard 已提交
739 740 741 742 743 744 745
     * use stderr.
     * NOTE: the locking is a single point of contention for multiple
     *       threads, but avoid intermixing. Maybe set up locks per output
     *       to improve paralellism.
     */
    len = strlen(msg);
    virLogStr(msg, len);
746 747 748
    if (emit == 0)
        goto cleanup;

D
Daniel Veillard 已提交
749 750
    virLogLock();
    for (i = 0; i < virLogNbOutputs;i++) {
751 752 753 754 755 756 757 758 759 760
        if (priority >= virLogOutputs[i].priority) {
            if (virLogOutputs[i].logVersion) {
                char *ver = NULL;
                if (virLogVersionString(&ver, &time_info, &cur_time) >= 0)
                    virLogOutputs[i].f(category, VIR_LOG_INFO, __func__, __LINE__,
                                       ver, strlen(ver),
                                       virLogOutputs[i].data);
                VIR_FREE(ver);
                virLogOutputs[i].logVersion = false;
            }
761 762
            virLogOutputs[i].f(category, priority, funcname, linenr,
                               msg, len, virLogOutputs[i].data);
763
        }
D
Daniel Veillard 已提交
764
    }
765 766 767 768 769 770 771 772 773
    if ((virLogNbOutputs == 0) && (flags != 1)) {
        if (logVersionStderr) {
            char *ver = NULL;
            if (virLogVersionString(&ver, &time_info, &cur_time) >= 0)
                ignore_value (safewrite(STDERR_FILENO,
                                        ver, strlen(ver)));
            VIR_FREE(ver);
            logVersionStderr = false;
        }
774
        ignore_value (safewrite(STDERR_FILENO, msg, len));
775
    }
D
Daniel Veillard 已提交
776 777
    virLogUnlock();

778
cleanup:
779
    VIR_FREE(msg);
780
    errno = saved_errno;
D
Daniel Veillard 已提交
781 782
}

783
static int virLogOutputToFd(const char *category ATTRIBUTE_UNUSED,
D
Daniel Veillard 已提交
784
                            int priority ATTRIBUTE_UNUSED,
785 786 787
                            const char *funcname ATTRIBUTE_UNUSED,
                            long long linenr ATTRIBUTE_UNUSED,
                            const char *str, int len, void *data) {
D
Daniel Veillard 已提交
788 789 790 791
    int fd = (long) data;
    int ret;

    if (fd < 0)
792
        return -1;
D
Daniel Veillard 已提交
793
    ret = safewrite(fd, str, len);
794
    return ret;
D
Daniel Veillard 已提交
795 796 797 798 799
}

static void virLogCloseFd(void *data) {
    int fd = (long) data;

800
    VIR_FORCE_CLOSE(fd);
D
Daniel Veillard 已提交
801 802 803
}

static int virLogAddOutputToStderr(int priority) {
804 805
    if (virLogDefineOutput(virLogOutputToFd, NULL, (void *)2L, priority,
                           VIR_LOG_TO_STDERR, NULL, 0) < 0)
806 807
        return -1;
    return 0;
D
Daniel Veillard 已提交
808 809 810 811 812
}

static int virLogAddOutputToFile(int priority, const char *file) {
    int fd;

813
    fd = open(file, O_CREAT | O_APPEND | O_WRONLY, S_IRUSR | S_IWUSR);
D
Daniel Veillard 已提交
814
    if (fd < 0)
815
        return -1;
D
Daniel Veillard 已提交
816
    if (virLogDefineOutput(virLogOutputToFd, virLogCloseFd, (void *)(long)fd,
817
                           priority, VIR_LOG_TO_FILE, file, 0) < 0) {
818
        VIR_FORCE_CLOSE(fd);
819
        return -1;
D
Daniel Veillard 已提交
820
    }
821
    return 0;
D
Daniel Veillard 已提交
822 823 824
}

#if HAVE_SYSLOG_H
825 826 827 828 829 830
static int virLogOutputToSyslog(const char *category ATTRIBUTE_UNUSED,
                                int priority,
                                const char *funcname ATTRIBUTE_UNUSED,
                                long long linenr ATTRIBUTE_UNUSED,
                                const char *str, int len ATTRIBUTE_UNUSED,
                                void *data ATTRIBUTE_UNUSED) {
D
Daniel Veillard 已提交
831 832 833 834 835 836 837 838 839 840 841 842 843 844 845 846 847 848 849
    int prio;

    switch (priority) {
        case VIR_LOG_DEBUG:
            prio = LOG_DEBUG;
            break;
        case VIR_LOG_INFO:
            prio = LOG_INFO;
            break;
        case VIR_LOG_WARN:
            prio = LOG_WARNING;
            break;
        case VIR_LOG_ERROR:
            prio = LOG_ERR;
            break;
        default:
            prio = LOG_ERR;
    }
    syslog(prio, "%s", str);
850
    return len;
D
Daniel Veillard 已提交
851 852
}

853 854
static char *current_ident = NULL;

D
Daniel Veillard 已提交
855 856
static void virLogCloseSyslog(void *data ATTRIBUTE_UNUSED) {
    closelog();
857
    VIR_FREE(current_ident);
D
Daniel Veillard 已提交
858 859 860
}

static int virLogAddOutputToSyslog(int priority, const char *ident) {
861 862 863 864 865 866
    /*
     * ident needs to be kept around on Solaris
     */
    VIR_FREE(current_ident);
    current_ident = strdup(ident);
    if (current_ident == NULL)
867
        return -1;
868 869

    openlog(current_ident, 0, 0);
D
Daniel Veillard 已提交
870
    if (virLogDefineOutput(virLogOutputToSyslog, virLogCloseSyslog, NULL,
871
                           priority, VIR_LOG_TO_SYSLOG, ident, 0) < 0) {
D
Daniel Veillard 已提交
872
        closelog();
873
        VIR_FREE(current_ident);
874
        return -1;
D
Daniel Veillard 已提交
875
    }
876
    return 0;
D
Daniel Veillard 已提交
877 878 879 880 881 882 883 884 885 886 887 888 889 890 891 892 893 894 895 896 897 898 899 900 901 902 903 904 905 906 907 908 909
}
#endif /* HAVE_SYSLOG_H */

#define IS_SPACE(cur)                                                   \
    ((*cur == ' ') || (*cur == '\t') || (*cur == '\n') ||               \
     (*cur == '\r') || (*cur == '\\'))

/**
 * virLogParseOutputs:
 * @outputs: string defining a (set of) output(s)
 *
 * The format for an output can be:
 *    x:stderr
 *       output goes to stderr
 *    x:syslog:name
 *       use syslog for the output and use the given name as the ident
 *    x:file:file_path
 *       output to a file, with the given filepath
 * In all case the x prefix is the minimal level, acting as a filter
 *    0: everything
 *    1: DEBUG
 *    2: INFO
 *    3: WARNING
 *    4: ERROR
 *
 * Multiple output can be defined in a single @output, they just need to be
 * separated by spaces.
 *
 * Returns the number of output parsed and installed or -1 in case of error
 */
int virLogParseOutputs(const char *outputs) {
    const char *cur = outputs, *str;
    char *name;
910
    char *abspath;
D
Daniel Veillard 已提交
911
    int prio;
912 913
    int ret = -1;
    int count = 0;
D
Daniel Veillard 已提交
914 915

    if (cur == NULL)
916
        return -1;
D
Daniel Veillard 已提交
917 918 919 920

    virSkipSpaces(&cur);
    while (*cur != 0) {
        prio= virParseNumber(&cur);
921
        if ((prio < VIR_LOG_DEBUG) || (prio > VIR_LOG_ERROR))
922
            goto cleanup;
D
Daniel Veillard 已提交
923
        if (*cur != ':')
924
            goto cleanup;
D
Daniel Veillard 已提交
925 926 927 928
        cur++;
        if (STREQLEN(cur, "stderr", 6)) {
            cur += 6;
            if (virLogAddOutputToStderr(prio) == 0)
929
                count++;
D
Daniel Veillard 已提交
930 931 932
        } else if (STREQLEN(cur, "syslog", 6)) {
            cur += 6;
            if (*cur != ':')
933
                goto cleanup;
D
Daniel Veillard 已提交
934 935 936 937 938
            cur++;
            str = cur;
            while ((*cur != 0) && (!IS_SPACE(cur)))
                cur++;
            if (str == cur)
939
                goto cleanup;
D
Daniel Veillard 已提交
940 941 942
#if HAVE_SYSLOG_H
            name = strndup(str, cur - str);
            if (name == NULL)
943
                goto cleanup;
D
Daniel Veillard 已提交
944
            if (virLogAddOutputToSyslog(prio, name) == 0)
945
                count++;
D
Daniel Veillard 已提交
946 947 948 949 950
            VIR_FREE(name);
#endif /* HAVE_SYSLOG_H */
        } else if (STREQLEN(cur, "file", 4)) {
            cur += 4;
            if (*cur != ':')
951
                goto cleanup;
D
Daniel Veillard 已提交
952 953 954 955 956
            cur++;
            str = cur;
            while ((*cur != 0) && (!IS_SPACE(cur)))
                cur++;
            if (str == cur)
957
                goto cleanup;
D
Daniel Veillard 已提交
958 959
            name = strndup(str, cur - str);
            if (name == NULL)
960
                goto cleanup;
961 962 963 964 965
            if (virFileAbsPath(name, &abspath) < 0) {
                VIR_FREE(name);
                return -1; /* skip warning here because setting was fine */
            }
            if (virLogAddOutputToFile(prio, abspath) == 0)
966
                count++;
D
Daniel Veillard 已提交
967
            VIR_FREE(name);
968
            VIR_FREE(abspath);
D
Daniel Veillard 已提交
969
        } else {
970
            goto cleanup;
D
Daniel Veillard 已提交
971 972 973
        }
        virSkipSpaces(&cur);
    }
974 975 976
    ret = count;
cleanup:
    if (ret == -1)
977
        VIR_WARN("Ignoring invalid log output setting.");
978
    return ret;
D
Daniel Veillard 已提交
979 980 981 982 983 984 985 986 987 988 989 990 991 992 993 994 995 996 997 998 999 1000 1001 1002
}

/**
 * virLogParseFilters:
 * @filters: string defining a (set of) filter(s)
 *
 * The format for a filter is:
 *    x:name
 *       where name is a match string
 * the x prefix is the minimal level where the messages should be logged
 *    1: DEBUG
 *    2: INFO
 *    3: WARNING
 *    4: ERROR
 *
 * Multiple filter can be defined in a single @filters, they just need to be
 * separated by spaces.
 *
 * Returns the number of filter parsed and installed or -1 in case of error
 */
int virLogParseFilters(const char *filters) {
    const char *cur = filters, *str;
    char *name;
    int prio;
1003 1004
    int ret = -1;
    int count = 0;
D
Daniel Veillard 已提交
1005 1006

    if (cur == NULL)
1007
        return -1;
D
Daniel Veillard 已提交
1008 1009 1010 1011

    virSkipSpaces(&cur);
    while (*cur != 0) {
        prio= virParseNumber(&cur);
1012
        if ((prio < VIR_LOG_DEBUG) || (prio > VIR_LOG_ERROR))
1013
            goto cleanup;
D
Daniel Veillard 已提交
1014
        if (*cur != ':')
1015
            goto cleanup;
D
Daniel Veillard 已提交
1016 1017 1018 1019 1020
        cur++;
        str = cur;
        while ((*cur != 0) && (!IS_SPACE(cur)))
            cur++;
        if (str == cur)
1021
            goto cleanup;
D
Daniel Veillard 已提交
1022 1023
        name = strndup(str, cur - str);
        if (name == NULL)
1024
            goto cleanup;
D
Daniel Veillard 已提交
1025
        if (virLogDefineFilter(name, prio, 0) >= 0)
1026
            count++;
D
Daniel Veillard 已提交
1027 1028 1029
        VIR_FREE(name);
        virSkipSpaces(&cur);
    }
1030 1031 1032
    ret = count;
cleanup:
    if (ret == -1)
1033
        VIR_WARN("Ignoring invalid log filter setting.");
1034
    return ret;
D
Daniel Veillard 已提交
1035
}
1036 1037 1038 1039 1040 1041 1042

/**
 * virLogGetDefaultPriority:
 *
 * Returns the current logging priority level.
 */
int virLogGetDefaultPriority(void) {
1043
    return virLogDefaultPriority;
1044 1045
}

1046 1047 1048 1049 1050 1051 1052 1053 1054 1055 1056 1057 1058
/**
 * virLogGetFilters:
 *
 * Returns a string listing the current filters, in the format originally
 * specified in the config file or environment. Caller must free the
 * result.
 */
char *virLogGetFilters(void) {
    int i;
    virBuffer filterbuf = VIR_BUFFER_INITIALIZER;

    virLogLock();
    for (i = 0; i < virLogNbFilters; i++) {
1059
        virBufferAsprintf(&filterbuf, "%d:%s ", virLogFilters[i].priority,
1060 1061 1062 1063
                          virLogFilters[i].match);
    }
    virLogUnlock();

1064 1065
    if (virBufferError(&filterbuf)) {
        virBufferFreeAndReset(&filterbuf);
1066
        return NULL;
1067
    }
1068 1069 1070 1071 1072 1073 1074 1075 1076 1077 1078 1079 1080 1081 1082 1083 1084 1085 1086

    return virBufferContentAndReset(&filterbuf);
}

/**
 * virLogGetOutputs:
 *
 * Returns a string listing the current outputs, in the format originally
 * specified in the config file or environment. Caller must free the
 * result.
 */
char *virLogGetOutputs(void) {
    int i;
    virBuffer outputbuf = VIR_BUFFER_INITIALIZER;

    virLogLock();
    for (i = 0; i < virLogNbOutputs; i++) {
        int dest = virLogOutputs[i].dest;
        if (i)
1087
            virBufferAsprintf(&outputbuf, " ");
1088 1089 1090
        switch (dest) {
            case VIR_LOG_TO_SYSLOG:
            case VIR_LOG_TO_FILE:
1091
                virBufferAsprintf(&outputbuf, "%d:%s:%s",
1092 1093 1094 1095 1096
                                  virLogOutputs[i].priority,
                                  virLogOutputString(dest),
                                  virLogOutputs[i].name);
                break;
            default:
1097
                virBufferAsprintf(&outputbuf, "%d:%s",
1098 1099 1100 1101 1102 1103
                                  virLogOutputs[i].priority,
                                  virLogOutputString(dest));
        }
    }
    virLogUnlock();

1104 1105
    if (virBufferError(&outputbuf)) {
        virBufferFreeAndReset(&outputbuf);
1106
        return NULL;
1107
    }
1108 1109 1110 1111

    return virBufferContentAndReset(&outputbuf);
}

1112 1113 1114 1115 1116 1117
/**
 * virLogGetNbFilters:
 *
 * Returns the current number of defined log filters.
 */
int virLogGetNbFilters(void) {
1118
    return virLogNbFilters;
1119 1120 1121 1122 1123 1124 1125 1126
}

/**
 * virLogGetNbOutputs:
 *
 * Returns the current number of defined log outputs.
 */
int virLogGetNbOutputs(void) {
1127
    return virLogNbOutputs;
1128
}
1129 1130 1131 1132 1133 1134 1135 1136 1137 1138 1139 1140 1141 1142 1143 1144 1145 1146 1147 1148 1149 1150 1151 1152 1153 1154

/**
 * virLogParseDefaultPriority:
 * @priority: string defining the desired logging level
 *
 * Parses and sets the default log priority level. It can take a string or
 * number corresponding to the following levels:
 *    1: DEBUG
 *    2: INFO
 *    3: WARNING
 *    4: ERROR
 *
 * Returns the parsed log level or -1 on error.
 */
int virLogParseDefaultPriority(const char *priority) {
    int ret = -1;

    if (STREQ(priority, "1") || STREQ(priority, "debug"))
        ret = virLogSetDefaultPriority(VIR_LOG_DEBUG);
    else if (STREQ(priority, "2") || STREQ(priority, "info"))
        ret = virLogSetDefaultPriority(VIR_LOG_INFO);
    else if (STREQ(priority, "3") || STREQ(priority, "warning"))
        ret = virLogSetDefaultPriority(VIR_LOG_WARN);
    else if (STREQ(priority, "4") || STREQ(priority, "error"))
        ret = virLogSetDefaultPriority(VIR_LOG_ERROR);
    else
1155
        VIR_WARN("Ignoring invalid log level setting");
1156 1157 1158 1159 1160 1161 1162 1163 1164 1165 1166 1167 1168 1169 1170 1171 1172 1173

    return ret;
}

/**
 * virLogSetFromEnv:
 *
 * Sets virLogDefaultPriority, virLogFilters and virLogOutputs based on
 * environment variables.
 */
void virLogSetFromEnv(void) {
    char *debugEnv;

    debugEnv = getenv("LIBVIRT_DEBUG");
    if (debugEnv && *debugEnv)
        virLogParseDefaultPriority(debugEnv);
    debugEnv = getenv("LIBVIRT_LOG_FILTERS");
    if (debugEnv && *debugEnv)
1174
        virLogParseFilters(debugEnv);
1175 1176
    debugEnv = getenv("LIBVIRT_LOG_OUTPUTS");
    if (debugEnv && *debugEnv)
1177
        virLogParseOutputs(debugEnv);
1178
}