logging.c 32.6 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
    if (pbm)
220
        VIR_WARN("%s", 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;
C
Christophe Fergeau 已提交
392
    int oldLogStart, oldLogLen;
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

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

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

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

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

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

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

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

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

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

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

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

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

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

    /*
     * 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.
     */
670 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
    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 已提交
709 710 711 712
/**
 * virLogMessage:
 * @category: where is that message coming from
 * @priority: the priority level
713 714
 * @funcname: the function emitting the (debug) message
 * @linenr: line where the message was emitted
D
Daniel Veillard 已提交
715 716 717 718 719 720 721
 * @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
 */
722 723
void virLogMessage(const char *category, int priority, const char *funcname,
                   long long linenr, int flags, const char *fmt, ...) {
724
    static bool logVersionStderr = true;
D
Daniel Veillard 已提交
725
    char *str = NULL;
726
    char *msg = NULL;
D
Daniel Veillard 已提交
727 728
    struct timeval cur_time;
    struct tm time_info;
729
    int len, fprio, i, ret;
730
    int saved_errno = errno;
731
    int emit = 1;
D
Daniel Veillard 已提交
732 733 734 735 736

    if (!virLogInitialized)
        virLogStartup();

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

886 887
static char *current_ident = NULL;

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

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

    openlog(current_ident, 0, 0);
D
Daniel Veillard 已提交
903
    if (virLogDefineOutput(virLogOutputToSyslog, virLogCloseSyslog, NULL,
904
                           priority, VIR_LOG_TO_SYSLOG, ident, 0) < 0) {
D
Daniel Veillard 已提交
905
        closelog();
906
        VIR_FREE(current_ident);
907
        return -1;
D
Daniel Veillard 已提交
908
    }
909
    return 0;
D
Daniel Veillard 已提交
910 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
}
#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;
943
    char *abspath;
D
Daniel Veillard 已提交
944
    int prio;
945 946
    int ret = -1;
    int count = 0;
D
Daniel Veillard 已提交
947 948

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

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

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

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

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

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

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

1097 1098
    if (virBufferError(&filterbuf)) {
        virBufferFreeAndReset(&filterbuf);
1099
        return NULL;
1100
    }
1101 1102 1103 1104 1105 1106 1107 1108 1109 1110 1111 1112 1113 1114 1115 1116 1117 1118 1119

    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)
1120
            virBufferAsprintf(&outputbuf, " ");
1121 1122 1123
        switch (dest) {
            case VIR_LOG_TO_SYSLOG:
            case VIR_LOG_TO_FILE:
1124
                virBufferAsprintf(&outputbuf, "%d:%s:%s",
1125 1126 1127 1128 1129
                                  virLogOutputs[i].priority,
                                  virLogOutputString(dest),
                                  virLogOutputs[i].name);
                break;
            default:
1130
                virBufferAsprintf(&outputbuf, "%d:%s",
1131 1132 1133 1134 1135 1136
                                  virLogOutputs[i].priority,
                                  virLogOutputString(dest));
        }
    }
    virLogUnlock();

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

    return virBufferContentAndReset(&outputbuf);
}

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

/**
 * virLogGetNbOutputs:
 *
 * Returns the current number of defined log outputs.
 */
int virLogGetNbOutputs(void) {
1160
    return virLogNbOutputs;
1161
}
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

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

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