logging.c 32.7 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 53 54 55 56 57 58 59 60 61 62 63 64 65 66 67 68 69 70 71 72 73 74 75 76 77 78 79 80 81 82 83 84 85 86 87 88 89
/*
 * Macro used to format the message as a string in virLogMessage
 * and borrowed from libxml2 (also used in virRaiseError)
 */
#define VIR_GET_VAR_STR(msg, str) {				\
    int       size, prev_size = -1;				\
    int       chars;						\
    char      *larger;						\
    va_list   ap;						\
                                                                \
    str = (char *) malloc(150);					\
    if (str != NULL) {						\
                                                                \
    size = 150;							\
                                                                \
    while (1) {							\
        va_start(ap, msg);					\
        chars = vsnprintf(str, size, msg, ap);			\
        va_end(ap);						\
        if ((chars > -1) && (chars < size)) {			\
            if (prev_size == chars) {				\
                break;						\
            } else {						\
                prev_size = chars;				\
            }							\
        }							\
        if (chars > -1)						\
            size += chars + 1;					\
        else							\
            size += 100;					\
        if ((larger = (char *) realloc(str, size)) == NULL) {	\
            break;						\
        }							\
        str = larger;						\
    }}								\
}

/*
 * A logging buffer to keep some history over logs
 */

90 91
static int virLogSize = 64 * 1024;
static char *virLogBuffer = NULL;
D
Daniel Veillard 已提交
92 93 94 95 96 97 98 99 100 101 102 103 104 105 106 107 108 109 110 111 112 113 114
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 {
115
    bool logVersion;
D
Daniel Veillard 已提交
116 117 118 119
    void *data;
    virLogOutputFunc f;
    virLogCloseFunc c;
    int priority;
120 121
    virLogDestination dest;
    const char *name;
D
Daniel Veillard 已提交
122 123 124 125 126 127 128 129 130 131
};
typedef struct _virLogOutput virLogOutput;
typedef virLogOutput *virLogOutputPtr;

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

/*
 * Default priorities
 */
132
static virLogPriority virLogDefaultPriority = VIR_LOG_DEFAULT;
D
Daniel Veillard 已提交
133 134 135

static int virLogResetFilters(void);
static int virLogResetOutputs(void);
136 137 138
static int virLogOutputToFd(const char *category, int priority,
                            const char *funcname, long long linenr,
                            const char *str, int len, void *data);
D
Daniel Veillard 已提交
139 140 141 142

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

145
void virLogLock(void)
D
Daniel Veillard 已提交
146
{
147
    virMutexLock(&virLogMutex);
D
Daniel Veillard 已提交
148
}
149
void virLogUnlock(void)
D
Daniel Veillard 已提交
150
{
151
    virMutexUnlock(&virLogMutex);
D
Daniel Veillard 已提交
152 153
}

154 155
static const char *virLogOutputString(virLogDestination ldest) {
    switch (ldest) {
156 157 158 159 160 161
    case VIR_LOG_TO_STDERR:
        return "stderr";
    case VIR_LOG_TO_SYSLOG:
        return "syslog";
    case VIR_LOG_TO_FILE:
        return "file";
162
    }
163
    return "unknown";
164
}
D
Daniel Veillard 已提交
165 166 167

static const char *virLogPriorityString(virLogPriority lvl) {
    switch (lvl) {
168 169 170 171 172 173 174 175
    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 已提交
176
    }
177
    return "unknown";
D
Daniel Veillard 已提交
178 179 180 181 182 183 184 185 186 187 188 189
}

static int virLogInitialized = 0;

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

D
Daniel Veillard 已提交
192
    if (virLogInitialized)
193
        return -1;
194 195 196 197

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

D
Daniel Veillard 已提交
198 199
    virLogInitialized = 1;
    virLogLock();
200
    if (VIR_ALLOC_N(virLogBuffer, virLogSize + 1) < 0) {
201 202 203 204 205 206
        /*
         * 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;
207
        if (VIR_ALLOC_N(virLogBuffer, virLogSize + 1) < 0) {
208 209 210 211 212 213
            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 已提交
214 215 216
    virLogLen = 0;
    virLogStart = 0;
    virLogEnd = 0;
217
    virLogDefaultPriority = VIR_LOG_DEFAULT;
D
Daniel Veillard 已提交
218
    virLogUnlock();
219 220
    if (pbm)
        VIR_WARN0(pbm);
221
    return 0;
D
Daniel Veillard 已提交
222 223
}

224 225 226 227 228 229 230 231 232 233 234 235 236 237 238 239 240 241 242 243 244 245 246 247 248 249 250 251
/**
 * 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;

252
    if (INT_MAX / 1024 <= size) {
253 254 255 256 257 258
        pbm = "Requested log size of %d kB too large\n";
        ret = -1;
        goto error;
    }

    virLogSize = size * 1024;
259
    if (VIR_ALLOC_N(virLogBuffer, virLogSize + 1) < 0) {
260 261 262 263 264 265 266 267 268 269 270 271 272 273 274 275 276 277
        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 已提交
278 279 280 281 282 283 284 285 286
/**
 * 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)
287
        return virLogStartup();
D
Daniel Veillard 已提交
288 289 290 291 292 293 294

    virLogLock();
    virLogResetFilters();
    virLogResetOutputs();
    virLogLen = 0;
    virLogStart = 0;
    virLogEnd = 0;
295
    virLogDefaultPriority = VIR_LOG_DEFAULT;
D
Daniel Veillard 已提交
296
    virLogUnlock();
297
    return 0;
D
Daniel Veillard 已提交
298 299 300 301 302 303 304 305 306 307 308 309 310 311 312
}
/**
 * virLogShutdown:
 *
 * Shutdown the logging module
 */
void virLogShutdown(void) {
    if (!virLogInitialized)
        return;
    virLogLock();
    virLogResetFilters();
    virLogResetOutputs();
    virLogLen = 0;
    virLogStart = 0;
    virLogEnd = 0;
313
    VIR_FREE(virLogBuffer);
D
Daniel Veillard 已提交
314
    virLogUnlock();
315
    virMutexDestroy(&virLogMutex);
D
Daniel Veillard 已提交
316 317 318 319 320 321 322 323 324
    virLogInitialized = 0;
}

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

325
    if ((str == NULL) || (virLogBuffer == NULL) || (virLogSize <= 0))
D
Daniel Veillard 已提交
326 327 328
        return;
    if (len <= 0)
        len = strlen(str);
E
Eric Blake 已提交
329
    if (len >= virLogSize)
D
Daniel Veillard 已提交
330 331 332 333 334 335
        return;
    virLogLock();

    /*
     * copy the data and reset the end, we cycle over the end of the buffer
     */
336 337
    if (virLogEnd + len >= virLogSize) {
        tmp = virLogSize - virLogEnd;
D
Daniel Veillard 已提交
338
        memcpy(&virLogBuffer[virLogEnd], str, tmp);
339
        memcpy(&virLogBuffer[0], &str[tmp], len - tmp);
D
Daniel Veillard 已提交
340 341 342 343 344
        virLogEnd = len - tmp;
    } else {
        memcpy(&virLogBuffer[virLogEnd], str, len);
        virLogEnd += len;
    }
E
Eric Blake 已提交
345
    virLogBuffer[virLogEnd] = 0;
D
Daniel Veillard 已提交
346 347 348 349
    /*
     * Update the log length, and if full move the start index
     */
    virLogLen += len;
350 351 352
    if (virLogLen > virLogSize) {
        tmp = virLogLen - virLogSize;
        virLogLen = virLogSize;
D
Daniel Veillard 已提交
353
        virLogStart += tmp;
354 355
        if (virLogStart >= virLogSize)
            virLogStart -= virLogSize;
D
Daniel Veillard 已提交
356 357 358 359
    }
    virLogUnlock();
}

360 361 362
static void virLogDumpAllFD(const char *msg, int len) {
    int i, found = 0;

363 364 365
    if (len <= 0)
        len = strlen(msg);

366 367 368 369 370 371 372 373 374 375 376 377 378 379 380 381 382 383 384 385 386 387
    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 已提交
388
 */
389 390
void
virLogEmergencyDumpAll(int signum) {
391
    int len;
392
    int oldLogStart, oldLogLen, oldLogEnd;
D
Daniel Veillard 已提交
393

394
    switch (signum) {
D
Daniel Veillard 已提交
395
#ifdef SIGFPE
396 397 398
        case SIGFPE:
            virLogDumpAllFD( "Caught signal Floating-point exception", -1);
            break;
D
Daniel Veillard 已提交
399 400
#endif
#ifdef SIGSEGV
401 402 403
        case SIGSEGV:
            virLogDumpAllFD( "Caught Segmentation violation", -1);
            break;
D
Daniel Veillard 已提交
404 405
#endif
#ifdef SIGILL
406 407 408
        case SIGILL:
            virLogDumpAllFD( "Caught illegal instruction", -1);
            break;
D
Daniel Veillard 已提交
409 410
#endif
#ifdef SIGABRT
411 412 413
        case SIGABRT:
            virLogDumpAllFD( "Caught abort signal", -1);
            break;
D
Daniel Veillard 已提交
414 415
#endif
#ifdef SIGBUS
416 417 418
        case SIGBUS:
            virLogDumpAllFD( "Caught bus error", -1);
            break;
D
Daniel Veillard 已提交
419 420
#endif
#ifdef SIGUSR2
421 422 423
        case SIGUSR2:
            virLogDumpAllFD( "Caught User-defined signal 2", -1);
            break;
D
Daniel Veillard 已提交
424
#endif
425 426 427 428
        default:
            virLogDumpAllFD( "Caught unexpected signal", -1);
            break;
    }
429 430
    if ((virLogBuffer == NULL) || (virLogSize <= 0)) {
        virLogDumpAllFD(" internal log buffer deactivated\n", -1);
431
        return;
432
    }
433

434 435
    virLogDumpAllFD(" dumping internal log buffer:\n", -1);
    virLogDumpAllFD("\n\n    ====== start of log =====\n\n", -1);
436 437 438 439 440 441 442 443 444 445 446 447 448 449 450 451 452 453 454 455 456 457 458

    /*
     * 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;
    oldLogEnd = virLogEnd;
    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 已提交
459
        } else {
460
            len = virLogSize - oldLogStart;
461
            virLogBuffer[virLogSize] = 0;
462 463 464
            virLogDumpAllFD(&virLogBuffer[oldLogStart], len);
            oldLogLen -= len;
            oldLogStart = 0;
D
Daniel Veillard 已提交
465 466
        }
    }
467
    virLogDumpAllFD("\n\n     ====== end of log =====\n\n", -1);
D
Daniel Veillard 已提交
468
}
469

D
Daniel Veillard 已提交
470 471 472 473 474 475 476 477 478 479 480
/**
 * 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) {
481
    if ((priority < VIR_LOG_DEBUG) || (priority > VIR_LOG_ERROR)) {
482
        VIR_WARN0("Ignoring invalid log level setting.");
483
        return -1;
484
    }
D
Daniel Veillard 已提交
485 486 487
    if (!virLogInitialized)
        virLogStartup();
    virLogDefaultPriority = priority;
488
    return 0;
D
Daniel Veillard 已提交
489 490 491 492 493 494 495 496 497 498 499 500 501 502 503 504
}

/**
 * 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;
505
    return i;
D
Daniel Veillard 已提交
506 507 508 509 510 511 512 513 514 515 516 517 518 519 520 521 522 523 524 525 526 527
}

/**
 * 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))
528
        return -1;
D
Daniel Veillard 已提交
529 530 531 532 533 534 535 536 537 538

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

    mdup = strdup(match);
539
    if (mdup == NULL) {
D
Daniel Veillard 已提交
540 541 542 543 544 545 546 547 548 549 550 551 552 553
        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();
554
    return i;
D
Daniel Veillard 已提交
555 556 557 558 559 560 561 562 563 564 565 566 567 568 569 570 571 572 573 574 575 576 577 578
}

/**
 * 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();
579
    return ret;
D
Daniel Veillard 已提交
580 581 582 583 584 585 586 587 588 589 590 591 592 593 594
}

/**
 * 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);
595
        VIR_FREE(virLogOutputs[i].name);
D
Daniel Veillard 已提交
596 597 598 599
    }
    VIR_FREE(virLogOutputs);
    i = virLogNbOutputs;
    virLogNbOutputs = 0;
600
    return i;
D
Daniel Veillard 已提交
601 602 603 604 605
}

/**
 * virLogDefineOutput:
 * @f: the function to call to output a message
606
 * @c: the function to call to close the output (or NULL)
D
Daniel Veillard 已提交
607 608
 * @data: extra data passed as first arg to the function
 * @priority: minimal priority for this filter, use 0 for none
609 610
 * @dest: where to send output of this priority
 * @name: optional name data associated with an output
D
Daniel Veillard 已提交
611 612 613 614 615 616 617 618
 * @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,
619 620
                       int priority, int dest, const char *name,
                       int flags ATTRIBUTE_UNUSED) {
D
Daniel Veillard 已提交
621
    int ret = -1;
622
    char *ndup = NULL;
D
Daniel Veillard 已提交
623 624

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

627 628
    if (dest == VIR_LOG_TO_SYSLOG || dest == VIR_LOG_TO_FILE) {
        if (name == NULL)
629
            return -1;
630 631
        ndup = strdup(name);
        if (ndup == NULL)
632
            return -1;
633 634
    }

D
Daniel Veillard 已提交
635 636
    virLogLock();
    if (VIR_REALLOC_N(virLogOutputs, virLogNbOutputs + 1)) {
637
        VIR_FREE(ndup);
D
Daniel Veillard 已提交
638 639 640
        goto cleanup;
    }
    ret = virLogNbOutputs++;
641
    virLogOutputs[ret].logVersion = true;
D
Daniel Veillard 已提交
642 643 644 645
    virLogOutputs[ret].f = f;
    virLogOutputs[ret].c = c;
    virLogOutputs[ret].data = data;
    virLogOutputs[ret].priority = priority;
646 647
    virLogOutputs[ret].dest = dest;
    virLogOutputs[ret].name = ndup;
D
Daniel Veillard 已提交
648 649
cleanup:
    virLogUnlock();
650
    return ret;
D
Daniel Veillard 已提交
651 652
}

653 654 655 656 657 658 659 660 661 662
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;
663 664 665 666 667 668 669 670

    /*
     * 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.
     */
671 672 673 674 675 676 677 678 679 680 681 682 683 684 685 686 687 688 689 690 691 692 693 694 695 696 697 698 699 700 701 702 703 704 705 706 707 708 709
    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 已提交
710 711 712 713
/**
 * virLogMessage:
 * @category: where is that message coming from
 * @priority: the priority level
714 715
 * @funcname: the function emitting the (debug) message
 * @linenr: line where the message was emitted
D
Daniel Veillard 已提交
716 717 718 719 720 721 722
 * @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
 */
723 724
void virLogMessage(const char *category, int priority, const char *funcname,
                   long long linenr, int flags, const char *fmt, ...) {
725
    static bool logVersionStderr = true;
D
Daniel Veillard 已提交
726
    char *str = NULL;
727
    char *msg = NULL;
D
Daniel Veillard 已提交
728 729
    struct timeval cur_time;
    struct tm time_info;
730
    int len, fprio, i, ret;
731
    int saved_errno = errno;
732
    int emit = 1;
D
Daniel Veillard 已提交
733 734 735 736 737

    if (!virLogInitialized)
        virLogStartup();

    if (fmt == NULL)
738
        goto cleanup;
D
Daniel Veillard 已提交
739 740 741 742 743 744 745

    /*
     * check against list of specific logging patterns
     */
    fprio = virLogFiltersCheck(category);
    if (fprio == 0) {
        if (priority < virLogDefaultPriority)
746
            emit = 0;
747
    } else if (priority < fprio) {
748
        emit = 0;
749
    }
D
Daniel Veillard 已提交
750

751 752 753
    if ((emit == 0) && ((virLogBuffer == NULL) || (virLogSize <= 0)))
        goto cleanup;

D
Daniel Veillard 已提交
754 755 756 757 758
    /*
     * serialize the error message, add level and timestamp
     */
    VIR_GET_VAR_STR(fmt, str);
    if (str == NULL)
759
        goto cleanup;
D
Daniel Veillard 已提交
760 761 762
    gettimeofday(&cur_time, NULL);
    localtime_r(&cur_time.tv_sec, &time_info);

763 764 765
    ret = virLogFormatString(&msg, funcname, linenr,
                             &time_info, &cur_time,
                             priority, str);
766
    VIR_FREE(str);
767 768
    if (ret < 0)
        goto cleanup;
D
Daniel Veillard 已提交
769 770

    /*
771 772
     * 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 已提交
773 774 775 776 777 778 779
     * 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);
780 781 782
    if (emit == 0)
        goto cleanup;

D
Daniel Veillard 已提交
783 784
    virLogLock();
    for (i = 0; i < virLogNbOutputs;i++) {
785 786 787 788 789 790 791 792 793 794
        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;
            }
795 796
            virLogOutputs[i].f(category, priority, funcname, linenr,
                               msg, len, virLogOutputs[i].data);
797
        }
D
Daniel Veillard 已提交
798
    }
799 800 801 802 803 804 805 806 807
    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;
        }
808
        ignore_value (safewrite(STDERR_FILENO, msg, len));
809
    }
D
Daniel Veillard 已提交
810 811
    virLogUnlock();

812
cleanup:
813
    VIR_FREE(msg);
814
    errno = saved_errno;
D
Daniel Veillard 已提交
815 816
}

817
static int virLogOutputToFd(const char *category ATTRIBUTE_UNUSED,
D
Daniel Veillard 已提交
818
                            int priority ATTRIBUTE_UNUSED,
819 820 821
                            const char *funcname ATTRIBUTE_UNUSED,
                            long long linenr ATTRIBUTE_UNUSED,
                            const char *str, int len, void *data) {
D
Daniel Veillard 已提交
822 823 824 825
    int fd = (long) data;
    int ret;

    if (fd < 0)
826
        return -1;
D
Daniel Veillard 已提交
827
    ret = safewrite(fd, str, len);
828
    return ret;
D
Daniel Veillard 已提交
829 830 831 832 833
}

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

834
    VIR_FORCE_CLOSE(fd);
D
Daniel Veillard 已提交
835 836 837
}

static int virLogAddOutputToStderr(int priority) {
838 839
    if (virLogDefineOutput(virLogOutputToFd, NULL, (void *)2L, priority,
                           VIR_LOG_TO_STDERR, NULL, 0) < 0)
840 841
        return -1;
    return 0;
D
Daniel Veillard 已提交
842 843 844 845 846
}

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

847
    fd = open(file, O_CREAT | O_APPEND | O_WRONLY, S_IRUSR | S_IWUSR);
D
Daniel Veillard 已提交
848
    if (fd < 0)
849
        return -1;
D
Daniel Veillard 已提交
850
    if (virLogDefineOutput(virLogOutputToFd, virLogCloseFd, (void *)(long)fd,
851
                           priority, VIR_LOG_TO_FILE, file, 0) < 0) {
852
        VIR_FORCE_CLOSE(fd);
853
        return -1;
D
Daniel Veillard 已提交
854
    }
855
    return 0;
D
Daniel Veillard 已提交
856 857 858
}

#if HAVE_SYSLOG_H
859 860 861 862 863 864
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 已提交
865 866 867 868 869 870 871 872 873 874 875 876 877 878 879 880 881 882 883
    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);
884
    return len;
D
Daniel Veillard 已提交
885 886
}

887 888
static char *current_ident = NULL;

D
Daniel Veillard 已提交
889 890
static void virLogCloseSyslog(void *data ATTRIBUTE_UNUSED) {
    closelog();
891
    VIR_FREE(current_ident);
D
Daniel Veillard 已提交
892 893 894
}

static int virLogAddOutputToSyslog(int priority, const char *ident) {
895 896 897 898 899 900
    /*
     * ident needs to be kept around on Solaris
     */
    VIR_FREE(current_ident);
    current_ident = strdup(ident);
    if (current_ident == NULL)
901
        return -1;
902 903

    openlog(current_ident, 0, 0);
D
Daniel Veillard 已提交
904
    if (virLogDefineOutput(virLogOutputToSyslog, virLogCloseSyslog, NULL,
905
                           priority, VIR_LOG_TO_SYSLOG, ident, 0) < 0) {
D
Daniel Veillard 已提交
906
        closelog();
907
        VIR_FREE(current_ident);
908
        return -1;
D
Daniel Veillard 已提交
909
    }
910
    return 0;
D
Daniel Veillard 已提交
911 912 913 914 915 916 917 918 919 920 921 922 923 924 925 926 927 928 929 930 931 932 933 934 935 936 937 938 939 940 941 942 943
}
#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;
944
    char *abspath;
D
Daniel Veillard 已提交
945
    int prio;
946 947
    int ret = -1;
    int count = 0;
D
Daniel Veillard 已提交
948 949

    if (cur == NULL)
950
        return -1;
D
Daniel Veillard 已提交
951 952 953 954

    virSkipSpaces(&cur);
    while (*cur != 0) {
        prio= virParseNumber(&cur);
955
        if ((prio < VIR_LOG_DEBUG) || (prio > VIR_LOG_ERROR))
956
            goto cleanup;
D
Daniel Veillard 已提交
957
        if (*cur != ':')
958
            goto cleanup;
D
Daniel Veillard 已提交
959 960 961 962
        cur++;
        if (STREQLEN(cur, "stderr", 6)) {
            cur += 6;
            if (virLogAddOutputToStderr(prio) == 0)
963
                count++;
D
Daniel Veillard 已提交
964 965 966
        } else if (STREQLEN(cur, "syslog", 6)) {
            cur += 6;
            if (*cur != ':')
967
                goto cleanup;
D
Daniel Veillard 已提交
968 969 970 971 972
            cur++;
            str = cur;
            while ((*cur != 0) && (!IS_SPACE(cur)))
                cur++;
            if (str == cur)
973
                goto cleanup;
D
Daniel Veillard 已提交
974 975 976
#if HAVE_SYSLOG_H
            name = strndup(str, cur - str);
            if (name == NULL)
977
                goto cleanup;
D
Daniel Veillard 已提交
978
            if (virLogAddOutputToSyslog(prio, name) == 0)
979
                count++;
D
Daniel Veillard 已提交
980 981 982 983 984
            VIR_FREE(name);
#endif /* HAVE_SYSLOG_H */
        } else if (STREQLEN(cur, "file", 4)) {
            cur += 4;
            if (*cur != ':')
985
                goto cleanup;
D
Daniel Veillard 已提交
986 987 988 989 990
            cur++;
            str = cur;
            while ((*cur != 0) && (!IS_SPACE(cur)))
                cur++;
            if (str == cur)
991
                goto cleanup;
D
Daniel Veillard 已提交
992 993
            name = strndup(str, cur - str);
            if (name == NULL)
994
                goto cleanup;
995 996 997 998 999
            if (virFileAbsPath(name, &abspath) < 0) {
                VIR_FREE(name);
                return -1; /* skip warning here because setting was fine */
            }
            if (virLogAddOutputToFile(prio, abspath) == 0)
1000
                count++;
D
Daniel Veillard 已提交
1001
            VIR_FREE(name);
1002
            VIR_FREE(abspath);
D
Daniel Veillard 已提交
1003
        } else {
1004
            goto cleanup;
D
Daniel Veillard 已提交
1005 1006 1007
        }
        virSkipSpaces(&cur);
    }
1008 1009 1010
    ret = count;
cleanup:
    if (ret == -1)
1011
        VIR_WARN0("Ignoring invalid log output setting.");
1012
    return ret;
D
Daniel Veillard 已提交
1013 1014 1015 1016 1017 1018 1019 1020 1021 1022 1023 1024 1025 1026 1027 1028 1029 1030 1031 1032 1033 1034 1035 1036
}

/**
 * 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;
1037 1038
    int ret = -1;
    int count = 0;
D
Daniel Veillard 已提交
1039 1040

    if (cur == NULL)
1041
        return -1;
D
Daniel Veillard 已提交
1042 1043 1044 1045

    virSkipSpaces(&cur);
    while (*cur != 0) {
        prio= virParseNumber(&cur);
1046
        if ((prio < VIR_LOG_DEBUG) || (prio > VIR_LOG_ERROR))
1047
            goto cleanup;
D
Daniel Veillard 已提交
1048
        if (*cur != ':')
1049
            goto cleanup;
D
Daniel Veillard 已提交
1050 1051 1052 1053 1054
        cur++;
        str = cur;
        while ((*cur != 0) && (!IS_SPACE(cur)))
            cur++;
        if (str == cur)
1055
            goto cleanup;
D
Daniel Veillard 已提交
1056 1057
        name = strndup(str, cur - str);
        if (name == NULL)
1058
            goto cleanup;
D
Daniel Veillard 已提交
1059
        if (virLogDefineFilter(name, prio, 0) >= 0)
1060
            count++;
D
Daniel Veillard 已提交
1061 1062 1063
        VIR_FREE(name);
        virSkipSpaces(&cur);
    }
1064 1065 1066
    ret = count;
cleanup:
    if (ret == -1)
1067
        VIR_WARN0("Ignoring invalid log filter setting.");
1068
    return ret;
D
Daniel Veillard 已提交
1069
}
1070 1071 1072 1073 1074 1075 1076

/**
 * virLogGetDefaultPriority:
 *
 * Returns the current logging priority level.
 */
int virLogGetDefaultPriority(void) {
1077
    return virLogDefaultPriority;
1078 1079
}

1080 1081 1082 1083 1084 1085 1086 1087 1088 1089 1090 1091 1092 1093 1094 1095 1096 1097
/**
 * 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++) {
        virBufferVSprintf(&filterbuf, "%d:%s ", virLogFilters[i].priority,
                          virLogFilters[i].match);
    }
    virLogUnlock();

1098 1099
    if (virBufferError(&filterbuf)) {
        virBufferFreeAndReset(&filterbuf);
1100
        return NULL;
1101
    }
1102 1103 1104 1105 1106 1107 1108 1109 1110 1111 1112 1113 1114 1115 1116 1117 1118 1119 1120 1121 1122 1123 1124 1125 1126 1127 1128 1129 1130 1131 1132 1133 1134 1135 1136 1137

    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)
            virBufferVSprintf(&outputbuf, " ");
        switch (dest) {
            case VIR_LOG_TO_SYSLOG:
            case VIR_LOG_TO_FILE:
                virBufferVSprintf(&outputbuf, "%d:%s:%s",
                                  virLogOutputs[i].priority,
                                  virLogOutputString(dest),
                                  virLogOutputs[i].name);
                break;
            default:
                virBufferVSprintf(&outputbuf, "%d:%s",
                                  virLogOutputs[i].priority,
                                  virLogOutputString(dest));
        }
    }
    virLogUnlock();

1138 1139
    if (virBufferError(&outputbuf)) {
        virBufferFreeAndReset(&outputbuf);
1140
        return NULL;
1141
    }
1142 1143 1144 1145

    return virBufferContentAndReset(&outputbuf);
}

1146 1147 1148 1149 1150 1151
/**
 * virLogGetNbFilters:
 *
 * Returns the current number of defined log filters.
 */
int virLogGetNbFilters(void) {
1152
    return virLogNbFilters;
1153 1154 1155 1156 1157 1158 1159 1160
}

/**
 * virLogGetNbOutputs:
 *
 * Returns the current number of defined log outputs.
 */
int virLogGetNbOutputs(void) {
1161
    return virLogNbOutputs;
1162
}
1163 1164 1165 1166 1167 1168 1169 1170 1171 1172 1173 1174 1175 1176 1177 1178 1179 1180 1181 1182 1183 1184 1185 1186 1187 1188

/**
 * 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
1189
        VIR_WARN0("Ignoring invalid log level setting");
1190 1191 1192 1193 1194 1195 1196 1197 1198 1199 1200 1201 1202 1203 1204 1205 1206 1207

    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)
1208
        virLogParseFilters(debugEnv);
1209 1210
    debugEnv = getenv("LIBVIRT_LOG_OUTPUTS");
    if (debugEnv && *debugEnv)
1211
        virLogParseOutputs(debugEnv);
1212
}